[Fli4l_dev] Informationen zum Weekly-Tarball vom 26.4.2013 [27286]

Mo Mai 6 15:33:37 CEST 2013

Hallo zusammen,

Am 29.04.2013 16:30, schrieb Matthias Prager:
> 
> Jetzt warte ich nur darauf, dass die Verbindung absemmelt :-)
> 

Es ist soweit, nach knapp 7 Tagen ist die Verbindung wieder abgerissen.
Diesmal habe ich aber mehr Diagnosemöglichkeiten am Start:

fli4lctl status gibt aus 'offline'. Das Webinterface meint das
ebenfalls. Ich kann mich per ssh ganz normal einloggen und sehe
folgendes in dmesg:

> ------------[ cut here ]------------
> WARNING: at net/sched/sch_generic.c:254 dev_watchdog+0xce/0x122()
> Hardware name:
> NETDEV WATCHDOG: eth1 (e1000e): transmit queue 0 timed out
> Modules linked in: nf_conntrack_netlink nfnetlink xt_nat evdev xt_dscp xt_mark xt_IMQ iptable_mangle imq cls_fw sch_sfq sch_htb xt_CT nf_nat_ftp nf_conntrack_ftp ipt_MASQUERADE xt_conntrack xt_length xt_TCPMSS xt_tcpudp xt_comment ipt_REJECT xt_LOG xt_limit iptable_raw iptable_nat nf_conntrack_ipv4 nf_defrag_ipv4 nf_nat_ipv4 nf_nat nf_conntrack iptable_filter ip_tables x_tables pppoe pppox ppp_generic slhc 8021q garp stp llc e1000e button ipv6 rtc_cmos nls_iso8859_1 ums_usbat ums_sddr55 ums_sddr09 ums_realtek ums_onetouch ums_karma ums_jumpshot ums_isd200 ums_freecom ums_eneub6250 ums_datafab ums_cypress ums_alauda usb_storage ahci libahci ata_piix ata_generic sr_mod cdrom sd_mod isofs ext4 mbcache jbd2 crc16 hid_generic usbhid hid uhci_hcd ohci_hcd ehci_hcd xhci_hcd usbcore usb_common libata scsi_mod pcspkr
> Pid: 0, comm: swapper/1 Not tainted 3.8.7 #1
> Call Trace:
>  [<c102145a>] warn_slowpath_common+0x77/0x8c
>  [<c11ba59b>] ? dev_watchdog+0xce/0x122
>  [<c11ba59b>] ? dev_watchdog+0xce/0x122
>  [<c10214eb>] warn_slowpath_fmt+0x2e/0x30
>  [<c11ba59b>] dev_watchdog+0xce/0x122
>  [<c11ba4cd>] ? netif_tx_unlock+0x3e/0x3e
>  [<c102a656>] call_timer_fn.isra.34+0x19/0x70
>  [<c102a7ca>] run_timer_softirq+0x11d/0x14f
>  [<c10266ef>] __do_softirq+0x7b/0x120
>  [<c1026674>] ? __tasklet_hi_schedule_first+0x25/0x25
>  <IRQ>  [<c1026845>] ? irq_exit+0x35/0x82
>  [<c1017414>] ? smp_apic_timer_interrupt+0x64/0x71
>  [<c121c3bd>] ? apic_timer_interrupt+0x2d/0x40
>  [<c10080d4>] ? mwait_idle+0x49/0x4e
>  [<c100864b>] ? cpu_idle+0x50/0x6a
>  [<c1214385>] ? start_secondary+0x19d/0x1a3
> ---[ end trace a2890196de2aafdf ]---
> e1000e 0000:01:00.0 eth1: Reset adapter

Ergo scheint die zweite (onboard) Intel Netzwerkkarte abzustürzen.
Ich habe auch einen tcpdump, allerdings nur mit dem pppoe Teil,
welcher bis kurz vor dem Crash die ganz regulären echo Pakete
aufzeigt und dann nichts mehr. Auf der Userspace-Seite bekommt
pppd natürlich mit, dass nichts mehr durch geht und kappt die
logische Verbindung. Die darauf folgenden Einwahlversuche quittiert
es dann konsequenterweise mit 'Timeout waiting for PADO packets'
Meldungen. Der adapter reset für eth1 hat also scheinbar die
Karte nicht wieder zum leben erweckt.

Auch interessant finde ich den Output von lspci:
> 01:00.0 Ethernet controller [0200]: Intel Corporation 82574L Gigabit Network Connection [8086:10d3] (rev ff) (prog-if ff)
> 	!!! Unknown header type 7f
> 	Kernel driver in use: e1000e
> 
> 02:00.0 Ethernet controller [0200]: Intel Corporation 82574L Gigabit Network Connection [8086:10d3]
> 	Subsystem: Intel Corporation Device [8086:202c]
> 	Flags: bus master, fast devsel, latency 0, IRQ 16
> 	Memory at 80120000 (32-bit, non-prefetchable) [size=128K]
> 	Memory at 80100000 (32-bit, non-prefetchable) [size=128K]
> 	I/O ports at 2000 [size=32]
> 	Memory at 80140000 (32-bit, non-prefetchable) [size=16K]
> 	Capabilities: [c8] Power Management version 2
> 	Capabilities: [d0] MSI: Enable- Count=1/1 Maskable- 64bit+
> 	Capabilities: [e0] Express Endpoint, MSI 00
> 	Capabilities: [a0] MSI-X: Enable+ Count=5 Masked-
> 	Capabilities: [100] Advanced Error Reporting
> 	Capabilities: [140] Device Serial Number 00-22-4d-ff-ff-7a-cc-8b
> 	Kernel driver in use: e1000e

Der Adapter fürs lokale Netz (02:00.0) verhält sich ganz normal,
während der am WAN-Port (01:00.0) sich in irgendeinem komischen
Modus befindet.

Auf dem Router läuft momentan r27181 mit Kernel 3.8.7 auf einem
Intel D2500CC Mainboard mit zwei 82574L (e1000e) Netzwerkkarten
onboard. Aber das Problem existiert schon seit ein paar Versionen.
100% sicher bin ich mir bei r23749 mit Kernel 3.2.29. Aber
ich meine mit r24320 und Kernel 3.6.6 lief es auch noch ohne
Aussetzer.

Ich habe ihn noch nicht neu gestartet, um mehr Infos extrahieren
zu können.

Die Interrupts sehen auch normal aus (Auszug):
>  42:   42827916   42880557   PCI-MSI-edge      eth0-rx-0
>  43:   54244980   54309532   PCI-MSI-edge      eth0-tx-0
>  44:          1          1   PCI-MSI-edge      eth0
>  45:   52965338   52970657   PCI-MSI-edge      eth1-rx-0
>  46:   53434629   53494205   PCI-MSI-edge      eth1-tx-0
>  47:          2          2   PCI-MSI-edge      eth1

Somit lässt sich denke ich sagen, dass es kein Problem am 
Einwahlsystem ist(/gibt), was ja auch schon mal beruhigend ist.

So wie das für mich aussieht, ist dies ein Upstream Kernel
Problem. Ich würde gerne die betroffenen Kernel-Versionen
näher eingrenzen, aber da die Zeit zum reproduzieren so lange
ist und man nur recht unzuverlässig sagen kann, ob das
Problem wirklich nicht auftritt gestaltet sich das schwierig :-/

@Christoph: soll ich dazu ein Ticket im Bugtracker aufmachen,
auch wenn es ja kein originäres fli4l-Problem ist?

Viele Grüße
Matthias