- √ - Wiregate unerreichbar übers Netzwerk

[NilsS]

Hi,

hatte auch schonmal so nen Aussetzer beim Wiregate, dabei ist mir avahi-daemon mit hoher CPU Last aufgefallen. Ein SSH Tunnel der darüber aktiv war hatte vorher sehr viel Packetverluste, danach ging garnichts mehr bis zum Stecker ziehen. Ist bisher 2 mal aufgetreten mit abstand von ungefähr 4 Monaten. Das letzte mal im Juni.

[greentux]

Da mir solche Sachen wie Avahi suspekt sind, hab ich das eh disabled.

[makki]

Naja, das Wiregate war ja noch pingbar. Allerdings mit grausamen Packet Losses und Pingzeiten > 10 Sekunden.

Naja, das kann aber genausogut was ganz anderes sein.. Selbst ein Bug im jahrzehntealten Cisco 7206VXR schafft solche Phänomene.. (ich kämpfe gerade mit einem GigE-Upstream wo ganz blöd die falschen 0,03% Packerl hops gehen..)
-> Jeder der meint ein Problem zu haben bekommt gerne den frischen Kernel (3.5.1), ich glaube nur nicht wirklich dran..

-> Gebt mir nachvollziehbaren Stoff

Makki

[arosy]

-> Gebt mir nachvollziehbaren Stoff

Wenn du schon so bettelst...

Mich hat es gestern getroffen, Reaktion des WG äußerst träge. Ein von 20 Ping kam durch. WG hatte PL32 und hängt am GS724TP.
Was mir auffiel war das zu dem Zeitpunkt die DNS Auflösung weder lokal noch extern funktionierte.
Nach einem Reboot war alles wieder normal.

[makki]

Ja, ich würds ja gern wissen, wo des pudels Kern liegt..
- Reicht ein abstecken des eth evtl auch ?
- Zweimal abstecken, für sagen wir mal 2 minuten ?

Ich mag ja nicht behaupten das es kein WG-Problem ist -- (aber das riecht mir halt nach einer router/switch/arp-Nummer weil ich davon 5 hierstehen habe, die seit teils > 12Monaten gehen)

Um das wirklich zu wissen müsste man in ARP&co des Hosts, Switch schauen (+wireshark dazu) - unrealistisch diesen Punkt zu treffen..

Makki

[greentux]

Also ich hatte es heute wieder und habe versucht, etwas Systematik reinzubringen, versucht...

Problem: Pingzeiten vom Filegrab zum WG um die 1000ms +/- 300ms mit Packetloss. Also Mist. SSH drauf ging nicht mehr. Webservices auch nicht.

Dann ran an die Konsole:
Sah gut aus (ohne Login)...
- List 1Wire -> prima, passt
- Restart Services -> restart, aber keine Besserung
- Netzwerk abgezogen, abgesteckt (1 tiefer Ton 2 Sekunden nach anstecken)
- Switch off/on (tiefer Ton wie oben)
grübel. nix.
- Fritzbox rebootet -> keine Besserung
- bis dahin uptime 9d, also keine Resets

Also WG rebootet. Danach kam man wieder drauf.
Auffällig:
- Diagramme waren alle da (1 Wire)
- Diagramme mit Daten vom Web (Heizungskessel) hörten 4 Uhr in der früh auf
- Diagramme via USB (eHZ mit IR) funktionierten

Also Logs geschaut:
messages

Nov 16 04:02:48 wiregate497 /usr/sbin/wiregated.pl: INFO - *** reading config
Nov 16 04:02:48 wiregate497 /usr/sbin/wiregated.pl: INFO - connected to eibd local:/tmp/eib
Nov 16 04:52:49 wiregate497 /usr/sbin/wiregated.pl: INFO - *** reading config
Nov 16 04:52:50 wiregate497 /usr/sbin/wiregated.pl: INFO - connected to eibd local:/tmp/eib
Nov 16 04:54:50 wiregate497 /usr/sbin/wiregated.pl: INFO - *** reading config
Nov 16 04:54:50 wiregate497 /usr/sbin/wiregated.pl: INFO - connected to eibd local:/tmp/eib
Nov 16 05:31:52 wiregate497 /usr/sbin/wiregated.pl: INFO - *** reading config
Nov 16 05:31:52 wiregate497 /usr/sbin/wiregated.pl: INFO - connected to eibd local:/tmp/eib
Nov 16 05:33:52 wiregate497 /usr/sbin/wiregated.pl: INFO - *** reading config

Im collectd sieht man, das 4 Uhr die Benutzung des Speichers (used) von 100 auf etwa 70 MB sinkt.
Gleichzeitig zeigt das Load Diagramm keine 1 Min Spitzen mehr, die bis 2 hochgehen.

16.50 Uhr heute gabs dann nen

Nov 16 16:50:50 wiregate497 kernel: [827189.788811] ------------[ cut here ]------------
Nov 16 16:50:50 wiregate497 kernel: [827189.793809] WARNING: at drivers/usb/serial/usb-serial.c:393 serial_write+0x5e/0x7d [usbserial]()
Nov 16 16:50:50 wiregate497 kernel: [827189.803601] Modules linked in: tcp_diag inet_diag tun w83627hf hwmon_vid fuse loop ecb aes_i586 aes_generic ac snd_cs5535audio snd_ac97_codec ac97_bus parport_pc parport evdev snd_pcm snd_seq snd_timer snd_seq_device button processor snd geode_aes tpm_tis ftdi_sio tpm soundcore tpm_bios snd_page_alloc geode_rng cs5535_gpio rng_core psmouse usbserial pcspkr serio_raw usbhid ext2 hid mbcache dm_mirror dm_region_hash dm_log dm_snapshot dm_mod ide_gd_mod ide_pci_generic cs5536 amd74xx ide_core ata_generic ehci_hcd ohci_hcd libata usbcore nls_base via_rhine scsi_mod mii thermal fan thermal_sys [last unloaded: scsi_wait_scan]
Nov 16 16:50:50 wiregate497 kernel: [827189.848291] Pid: 5, comm: events/0 Tainted: G        W  2.6.32-wiregate-1.31 #1
Nov 16 16:50:50 wiregate497 kernel: [827189.860358] Call Trace:
Nov 16 16:50:50 wiregate497 kernel: [827189.866349]  [<d0b0d5d5>] ? serial_write+0x5e/0x7d [usbserial]
Nov 16 16:50:50 wiregate497 kernel: [827189.872537]  [<d0b0d5d5>] ? serial_write+0x5e/0x7d [usbserial]
Nov 16 16:50:50 wiregate497 kernel: [827189.878623]  [<c10253c5>] ? warn_slowpath_common+0x5e/0x8a
Nov 16 16:50:50 wiregate497 kernel: [827189.884730]  [<c10253fb>] ? warn_slowpath_null+0xa/0xc
Nov 16 16:50:50 wiregate497 kernel: [827189.890786]  [<d0b0d5d5>] ? serial_write+0x5e/0x7d [usbserial]
Nov 16 16:50:50 wiregate497 kernel: [827189.896909]  [<c1166323>] ? tty_put_char+0x22/0x25
Nov 16 16:50:50 wiregate497 kernel: [827189.902999]  [<c11691de>] ? process_echoes+0x175/0x25c
Nov 16 16:50:50 wiregate497 kernel: [827189.909099]  [<c116a2c2>] ? n_tty_receive_buf+0x33b/0xda0
Nov 16 16:50:50 wiregate497 kernel: [827189.915219]  [<c1137983>] ? soft_cursor+0x19b/0x1a8
Nov 16 16:50:50 wiregate497 kernel: [827189.921322]  [<c113725c>] ? bit_cursor+0x481/0x496
Nov 16 16:50:50 wiregate497 kernel: [827189.927374]  [<c102014e>] ? dequeue_entity+0x10/0x116
Nov 16 16:50:50 wiregate497 kernel: [827189.933412]  [<c1001edb>] ? __switch_to+0xbc/0x143
Nov 16 16:50:50 wiregate497 kernel: [827189.939450]  [<c10200f7>] ? set_next_entity+0x29/0x51
Nov 16 16:50:50 wiregate497 kernel: [827189.945574]  [<c1021f1d>] ? finish_task_switch+0x27/0x82
Nov 16 16:50:50 wiregate497 kernel: [827189.951710]  [<c116c8dc>] ? flush_to_ldisc+0xcf/0x161
Nov 16 16:50:50 wiregate497 kernel: [827189.957798]  [<c1034fd1>] ? worker_thread+0x12e/0x1a4
Nov 16 16:50:50 wiregate497 kernel: [827189.964008]  [<c116c80d>] ? flush_to_ldisc+0x0/0x161
Nov 16 16:50:50 wiregate497 kernel: [827189.969970]  [<c1037760>] ? autoremove_wake_function+0x0/0x2d
Nov 16 16:50:50 wiregate497 kernel: [827189.975842]  [<c1034ea3>] ? worker_thread+0x0/0x1a4
Nov 16 16:50:50 wiregate497 kernel: [827189.981551]  [<c10373b9>] ? kthread+0x60/0x65
Nov 16 16:50:50 wiregate497 kernel: [827189.987076]  [<c1037359>] ? kthread+0x0/0x65
Nov 16 16:50:50 wiregate497 kernel: [827189.992371]  [<c10037eb>] ? kernel_thread_helper+0x7/0x10
Nov 16 16:50:50 wiregate497 kernel: [827189.997564] ---[ end trace 52fd7e399c7d0a8b ]---
Nov 16 16:50:50 wiregate497 kernel: [827190.002622] ------------[ cut here ]------------

In Syslog haben wir um 4 Uhr rum:

Nov 16 03:29:55 wiregate497 collectd[2336]: processes plugin: Failed to open `/proc/29422/cmdline': No such file or directory.
Nov 16 03:54:45 wiregate497 collectd[2336]: processes plugin: Failed to open `/proc/26201/cmdline': No such file or directory.
Nov 16 03:55:25 wiregate497 ntpd[2316]: kernel time sync status change 4001
Nov 16 03:58:35 wiregate497 collectd[2336]: processes plugin: Failed to open `/proc/30823/cmdline': No such file or directory.
Nov 16 04:02:42 wiregate497 monit[2683]: 'wiregated.alive' timestamp test failed for /tmp/wiregated.alive
Nov 16 04:02:48 wiregate497 /usr/sbin/wiregated.pl: INFO - *** reading config
Nov 16 04:02:48 wiregate497 /usr/sbin/wiregated.pl: INFO - connected to eibd local:/tmp/eib
Nov 16 04:03:42 wiregate497 monit[2683]: 'wiregated.pl' process PID changed to 2916
Nov 16 04:03:42 wiregate497 monit[2683]: 'wiregated.alive' timestamp passed
Nov 16 04:04:42 wiregate497 monit[2683]: 'wiregated.pl' PID has not changed
Nov 16 04:21:30 wiregate497 ovpn-wiregate-central[2192]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Nov 16 04:23:06 wiregate497 ovpn-wiregate-central[2192]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Nov 16 04:27:20 wiregate497 ovpn-wiregate-central[2192]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Nov 16 04:28:53 wiregate497 ovpn-wiregate-central[2192]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Nov 16 04:30:08 wiregate497 ovpn-wiregate-central[2192]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Nov 16 04:31:43 wiregate497 ovpn-wiregate-central[2192]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Nov 16 04:33:03 wiregate497 ovpn-wiregate-central[2192]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts

Und einige:

Nov 16 05:32:46 wiregate497 monit[2683]: 'wiregated.pl' process PID changed to 1162
Nov 16 05:32:46 wiregate497 monit[2683]: 'wiregated.alive' timestamp passed
Nov 16 05:33:01 wiregate497 ovpn-wiregate-central[2192]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Nov 16 05:33:46 wiregate497 monit[2683]: 'wiregated.pl' PID has not changed
Nov 16 05:33:46 wiregate497 monit[2683]: 'wiregated.alive' timestamp test failed for /tmp/wiregated.alive
Nov 16 05:33:52 wiregate497 /usr/sbin/wiregated.pl: INFO - *** reading config
Nov 16 05:33:52 wiregate497 /usr/sbin/wiregated.pl: INFO - connected to eibd local:/tmp/eib
Nov 16 05:34:42 wiregate497 ovpn-wiregate-central[2192]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Nov 16 05:34:46 wiregate497 monit[2683]: 'wiregated.pl' process PID changed to 3461
Nov 16 05:34:46 wiregate497 monit[2683]: 'wiregated.alive' timestamp passed
Nov 16 05:35:46 wiregate497 monit[2683]: 'wiregated.pl' PID has not changed

die vermutlich von dem restarteten eibd herkommen.

Das wiregat_plugin.log zeigt, das Punkt 4 Uhr finito war mit Netz.

2012-11-16 03:58:49.287,ETA_PU2KNX_Connector.pl,112/10111/12130/0/1110 - GA 10/5/61 DPT:9.001 - Wert lesen: 40
2012-11-16 03:58:49.299,ETA_PU2KNX_Connector.pl,112/10201/0/0/12015 - GA 10/0/170 DPT:14.051 - Wert lesen: 3316.5
2012-11-16 03:58:49.311,ETA_PU2KNX_Connector.pl,112/10241/0/11149/2001 - GA 10/0/2 DPT:1.001 - Wert lesen: 0
2012-11-16 03:58:49.465,ETA_PU2KNX_Connector.pl,Anzahl Fehlermeldungen: 0
2012-11-16 03:58:49.492,ETA_PU2KNX_Connector.pl,1353034729.47263,1.8s,
2012-11-16 03:59:40.912,Eta,,21s,500 Can't connect to 192.168.179.15:8080 (connect: Connection timed out) at (eval 51440) line 53.

2012-11-16 04:00:12.189,Eta_draw_gauge,280,31.2s,
2012-11-16 04:00:33.215,Eta_errors,,21s,500 Can't connect to 192.168.179.15:8080 (connect: Connection timed out) at (eval 51442) line 30.

2012-11-16 04:00:54.602,ETA_PU2KNX_Connector.pl,,5.1s,
syntax error at line 1, column 0, byte 0 at /usr/lib/perl5/XML/Parser.pm line 187

Was ich lerne ist zumindest, das das ETA Plugin noch etwas robuster werden muss ggü. Netzausfällen.

Tja. vl. hilfts was. On request auch VPN.

[makki]

@greentux: Wann war das das letzte mal davor? Nur so fürs Gefühl..

Ich kenne das Phänomen, habe aber keinerlei Ansatzpunkt was der Auslöser sein könnte; HW ist es 99% sicher nicht..
-> würde dir gerne mal einen neuen Kernel draufschieben (installieren: ich, reboot zu passenden Zeitpunkt: selbst..)
Wenn man meint zu wissen was man da tut: Kannst dir auch selber installieren, sofern PL33 drauf ist (das macht platz in /boot und den remount=rw von /boot)

apt-get install linux-image-3.5.1-wiregate

Für jegliche sonstige Hinweise, was zu dem Zeitpunkt im LAN passiert sein könnte, bin ich auch dankbar! Es muss was seltenes sein..
Die Sachen nach 4h halte ich mal für folge-fehler (warum auch immer der usbserial da spuckt dürfte nicht mit zu tun haben..)

Makki

[greentux]

VPN on, reboot jederzeit möglich...

[makki]

Done.. reboot bitte selber, ich mach das nur sehr ungern remote, da Seiteneffekte unbekannt (Plugins, ...)

Das mit dem USB ist schon auch komisch, hat nach meinem dafürhalten nicht mit dem Netzwerkproblem hier zu tun..
So wie ich das sehe fliegt eher die KNX-USB-SS ab und reisst den USB mit sich; dem FTDI kann ich unbedenklichlichkeit ausstellen, weil selber 5 davon aktiv hier seit Jahren..
Aber das ist wiegesagt ein anderes Thema.. da mach ma vielleicht hier weiter, fühlt sich sehr ähnlich an..

Makki

[greentux]

Reset done. Mal sehen.

[Shoko]

So, heute war's wieder soweit, das Wiregate war nicht mehr übers Netz zu erreichen (den RRDs nach zu urteilen ab 6:20).

Der neue Kernel ist schon drauf, ich hab schon neu gebooted und das Wartungs-VPN geöffnet (Wiregate 362) falls ihr mal draufsehen wollt.

Grüße
Michael

[makki]

Nichts relevantes zu sehen (war heute Mittag schonmal gucken..)

Aber - bitte nicht böse verstehen - an irgendwas muss es ja nun liegen; Die SW ist jetzt eher mal bis zum Gegenbeweis raus.. Also eher was anderes.. ich liebe ja HW-defekte weil die so schön einfach zu beheben sind, nur treten die nicht sporadisch nach Wochen/Monaten auf und sind allgemein schon verdammt selten..

Nur so blind ins blaue: Nachdem ich grad heute bei aufräumen wieder über diese erstklassige Präsentation gestolpert bin (wenn man den Vortrag dazu kennt ists noch witziger- 168A auf PEN ist schon ne Hausnummer
http://www.knx.de/kolloquium2012/dl....9.pdf&gruppe=1

Ein Zangenamperemeter haben wir ja*, einfach mal nachmessen, ob auf jeder Netzwerk/Busleitung/PE/PAS exakt 0,000 A fliessen, ist nur einer von vielen Ansätzen, hab ich aber schon öfters gehört..
Wenn man sich das aufmerksam durchsieht, geht das ganz einfach: eine Leuchte wo PE/N vertauscht ist genügt, es löst ggfs. noch nichtmal zwangsweise der (optionale) RCD(FI) aus aber die EMV-Suppe ist "perfekt versalzen"

Makki

*) Der vereidigte Sachverständigte sagte, das man zur Beweisführung natürlich eher besseres Equipment nimmt, es zur ersten Diagnose aber auch locker das 25€-Teil tut..

[perf]

Ich habe dieses Problem jetzt ein paar Mal in den letzten Wochen erlebt. Besteht das Problem noch für andere? Hilft der neue Kernel? (scheint nicht so für Shoko)

Bei mir wird das durch ein Restart des Netzwerkes "gelöst", aber das ist ja keine Lösung.

/etc/init.d/networking restart

/Per