L54ag 4.12 mit AES: Reset wenn Client verschwindet

[thomasgiger]

In unserem Netz werden die L54ag als AP im Point-to-Multipoint Modus eingesetzt. Firmware ist 4.12 am L54ag mit AES PSK Verschlüsselung. Die Stations sind madwifi Linux Clients mit wpa_supplicant für die AES Unterstützung.

Weil unsere Kunden nur mit Sichtverbindung zu den Stationen angebunden werden und zudem der Kunde gehalten ist, den Client immer eingeschaltet zu lassen, ist das folgende Problem erst recht spät aufgefallen:

Wenn einer der Clients aus der Zelle "verschwindet", macht das als AP dienende L54ag einen Warm- oder Kaltstart. Aufgefallen war schon früher, dass alle Assoziationen neu erstellt werden - die Firmware 4.12 meldet das ja schön per email. Durch Zufall bin ich aber dahintergekommen, dass auch das WLAN Log bei 1 beginnt. Das L54ag hat also resettet!

Glücklicherweise tun das die LANCOM Geräte ja sehr schnell, sodass sich noch niemand beschwert hat - die ETSI Gedenkminute ist, wenn man sie hat, jedenfalls deutlich länger. Wenn man aber nicht gerade in Egalistan lebt, kommt auf den Reset aber wohl erst mal ein Scan und in dieser Kombination ist es wohl wirklich ein zeitliches Problem.

Da es um einen Reset geht, habe ich keine Daten vom Zustand vorher. Ich habe mich immer davor gedrückt, das CLI zu verwenden. Wenn mir also jemand verrät, was ich tracen soll (und wie der Befehl genau lautet), lässt sich das Problem einfach reproduzieren. Ich muss nur einen der Clients neu starten und schon geht auch das L54ag durch einen Bootzyklus.

Client Seite: es ist denkbar, dass diese Sache nur mit madwifi-Clients passiert. Andererseits passiert der Reboot auch, wenn ich den Client einfach nur ausschalte. Es kann also kein Problem der Abmeldung des Client sein - er meldet sich gar nicht ab. Insofern ist das wiederum nicht madwifi-typisch.

PS: Auf 5.0 will ich nicht upgraden, da erwarten uns wahrscheinlich noch mehr Probleme ...

PS: Das Problem könnte in Verbindung mit dem anderen Thread "Spontaner Firmwarewechsel" stehen. Wenn nämlich diese Reboots bei instabilen Verbindungen (im unserem Büro-Versuchsaufbau) nur häufig genug passieren - würde dann das L54ag auch "sicherheitshalber" auf eine frühere Firmware wechseln?

[alf29]

Moin,

Also allgemein ist das sicher nicht so, denn so etwas höre ich hier zum
ersten Mal...Wenn das Gerät nicht gerade einen kompletten Kaltstart
mit Speichertest hingelegt hat (das wäre noch ungewöhnlicher), dann müßte
man mit einem 'show bootlog' die Ursache sehen.

PS: Auf 5.0 will ich nicht upgraden, da erwarten uns wahrscheinlich noch mehr Probleme ...

Wenn kein Kunde sie benutzt, werden die Probleme auch nicht gefunden :-/ Die
angeblichen P2P-Probleme mit WPA kann ich bei mir nicht nachstellen, und bisher
hat mir niemand, der Probleme hat, die geforderten Informationen liefern können...

PS: Das Problem könnte in Verbindung mit dem anderen Thread "Spontaner Firmwarewechsel" stehen. Wenn nämlich diese Reboots bei instabilen Verbindungen (im unserem Büro-Versuchsaufbau) nur häufig genug passieren - würde dann das L54ag auch "sicherheitshalber" auf eine frühere Firmware wechseln?

Der Bootlader im LANCOM schaltet die Firmware um, wenn die aktive Firmware
zehnmal hintereinander innerhalb des Firmsafe-Timeouts mit einer os_panic
abgestürzt ist. Da dieser Zähler im RAM geführt wird, müssen das also alles
Kaltstarts sein - d.h. im Bootlog muß etwas stehen.

Gruß Alfred

[thomasgiger]

Das Bootlog des L54ag, das den letzten Neustart heute hingelegt hat, sieht so aus:

Code: Alles auswählen

> show bootlog
Boot log (8192 Bytes):
t .@aT.([p
00406150:  00 28 5A 58 00 40 40 F4  00 00 00 00 00 00 00 00 | .(ZX.@@. ........
00406160:  00 00 00 00 00 00 00 00  00 40 61 90 00 40 61 78 | ........ .@a..@ax
00406170:  00 18 F2 B8 00 28 5A D0  00 18 D9 90 00 00 00 00 | .....(Z. ........
00406180:  00 00 00 00 00 00 00 00  00 40 61 94 00 18 D9 90 | ........ .@a.....
00406190:  00 18 F2 28 00 00 00 00  00 00 00 00 00 00 00 00 | ...(.... ........
004061A0:  00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00 | ........ ........
004061B0:  00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00 | ........ ........
004061C0:  00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00 | ........ ........
largest available memory block: 9519552 bytes


DEVICE:           LANCOM L-54ag Wireless
HW-RELEASE:       C
VERSION:          4.12.0031 / 31.03.2005

****

6/28/2005 17:51:16   System boot after os_panic

DEVICE:           LANCOM L-54ag Wireless
HW-RELEASE:       C
VERSION:          4.12.0031 / 31.03.2005

****

7/10/2005 19:45:31   os_panic
Task name = WE

Type=free list corrupt (backward chain)
Code=0x006d3a00 Task=0x004009ec Nest=0x00000000
MMUSTS  = 0x00000000  CPSR      = 0x00000000  SPSR    = 0x00000000
FLTADDR = 0x00000000  D-FLTADDR = 0x00000000  MMUBASE = 0x00000000
 R00 = 0x002bab48  R01 = 0x006d3a00  R02 = 0x002ba9e0  R03 = 0x00000855 
 R04 = 0x003af640  R05 = 0x006d3a60  R06 = 0x00000060  R07 = 0x00000000 
 R08 = 0x006d3a20  R09 = 0x00000000  R10 = 0x00000000  R11 = 0x00402940 
 R12 = 0x00000020  R13 = 0x00402930  R14 = 0x0019043c 
 possible error location iosmem.c : 2133

Memory dump (256 bytes):
Adr:= 006D3A00
Len:= 00000100
006D3A00:  00 6D 3A 60 00 6D 39 20  00 00 00 03 00 6D 4F C1 | .m:`.m9  .....mO.
006D3A10:  36 36 36 36 36 36 36 36  36 36 36 36 25 57 70 A9 | 66666666 6666%Wp.
006D3A20:  00 42 57 CC 00 00 29 7C  07 04 19 59 00 19 17 F8 | .BW...)| ...Y....
006D3A30:  00 45 C8 C0 00 42 6D 00  00 42 6D 00 00 08 00 00 | .E...Bm. .Bm.....
006D3A40:  00 00 00 16 00 00 00 01  00 4B 77 DC 00 00 FF FF | ........ .Kw.....
006D3A50:  00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00 | ........ ........
006D3A60:  00 6D 3A A0 00 6D 3A 00  00 00 00 02 00 44 7C 40 | .m:..m:. .....D|@
006D3A70:  01 00 00 00 00 00 96 00  00 00 00 00 00 00 00 00 | ........ ........
006D3A80:  44 45 46 41 55 4C 54 20  28 41 43 43 45 50 54 2D | DEFAULT  (ACCEPT-
006D3A90:  41 4C 4C 29 00 42 6D 00  00 42 6D 00 00 08 00 00 | ALL).Bm. .Bm.....
006D3AA0:  00 6D 3A E0 00 6D 3A 60  00 00 00 02 00 44 7C 40 | .m:..m:` .....D|@
006D3AB0:  00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00 | ........ ........
006D3AC0:  44 45 46 41 55 4C 54 20  28 41 43 43 45 50 54 2D | DEFAULT  (ACCEPT-
006D3AD0:  41 4C 4C 29 00 42 6D 00  00 42 6D 00 00 08 00 00 | ALL).Bm. .Bm.....
006D3AE0:  00 6D 3B 20 00 6D 3A A0  00 00 00 02 00 44 7C 40 | .m; .m:. .....D|@
006D3AF0:  00 00 00 00 00 00 00 00  00 42 6D 00 00 00 00 00 | ........ .Bm.....

Stack dump (256 bytes):
Adr:= 00402930
Len:= 00000100
00402930:  00 6D 3A 00 00 40 29 64  00 40 29 44 00 19 04 D8 | .m:..@)d .@)D....
00402940:  00 19 04 34 00 00 08 01  00 00 00 2C 57 45 54 49 | ...4.... ...,WETI
00402950:  00 00 00 00 00 00 00 00  00 40 29 7C 00 40 29 68 | ........ .@)|.@)h
00402960:  00 19 0B B0 00 19 04 68  00 00 08 01 00 00 01 2C | .......h .......,
00402970:  00 40 29 98 00 40 29 80  00 19 32 D4 00 19 0B 90 | .@)..@). ..2.....
00402980:  00 6D 46 20 00 5F 00 00  00 00 00 00 00 40 2A 18 | .mF ._.. .....@*.
00402990:  00 40 29 9C 00 27 51 F8  00 19 32 C0 00 5D E5 74 | .@)..'Q. ..2..].t
004029A0:  00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00 | ........ ........
004029B0:  00 00 00 00 00 00 00 01  00 8A 00 00 00 00 00 00 | ........ ........
004029C0:  00 5D E5 62 00 65 78 40  00 40 2A 1C 00 00 00 00 | .].b.ex@ .@*.....
004029D0:  00 6D 46 20 00 48 04 B8  00 48 04 40 00 40 09 EC | .mF .H.. .H.@.@..
004029E0:  00 18 CA E0 00 40 09 EC  00 00 00 00 00 00 00 02 | .....@.. ........
004029F0:  00 00 00 00 00 40 2A 1C  00 00 00 02 00 00 00 00 | .....@*. ........
00402A00:  00 6D 46 20 00 3E 49 88  00 40 2A 1C 00 40 2A 48 | .mF .>I. .@*..@*H
00402A10:  00 40 2A 1C 00 27 76 B0  00 27 4A 08 00 00 00 00 | .@*..'v. .'J.....
00402A20:  00 6D 65 20 57 45 00 00  57 45 50 4D 00 38 4A 24 | .me WE.. WEPM.8J$
largest available memory block: 9567936 bytes


DEVICE:           LANCOM L-54ag Wireless
HW-RELEASE:       C
VERSION:          4.12.0031 / 31.03.2005

****

7/10/2005 19:45:36   System boot after os_panic

DEVICE:           LANCOM L-54ag Wireless
HW-RELEASE:       C
VERSION:          4.12.0031 / 31.03.2005

****

7/16/2005 13:37:33   os_panic
Task name = SF

Type=data abort
Code=0x002bab98 Task=0x0045c8c0 Nest=0x00000000
MMUSTS  = 0x0000000d  CPSR      = 0x68000097  SPSR    = 0x6800001f
FLTADDR = 0x001900a4  D-FLTADDR = 0x32342e24  MMUBASE = 0x00478000
 R00 = 0x32342e18  R01 = 0x002bab98  R02 = 0x002ba9e0  R03 = 0x00000a6d 
 R04 = 0x32342e18  R05 = 0x003af880  R06 = 0x003f47c8  R07 = 0x003f47c4 
 R08 = 0x00000000  R09 = 0x006d4040  R10 = 0x0045c8c0  R11 = 0x0045d844 
 R12 = 0x0045d848  R13 = 0x0045d824  R14 = 0x001908f8 

Memory dump (256 bytes):
Adr:= 002BAB98
Len:= 00000100
002BAB98:  78 49 6F 73 4D 65 6D 46  72 65 00 00 78 49 6F 73 | xIosMemF re..xIos
002BABA8:  4D 65 6D 46 72 65 20 28  63 6F 6C 6C 65 63 74 29 | MemFre ( collect)
002BABB8:  00 00 00 00 4F 75 74 20  6F 66 20 52 41 4D 00 00 | ....Out  of RAM..
002BABC8:  0A 20 20 66 72 65 65 20  70 42 61 73 65 42 6C 6F | .  free  pBaseBlo
002BABD8:  63 6B 20 28 25 70 29 2E  2E 2E 20 00 61 74 74 65 | ck (%p). .. .atte
002BABE8:  6D 70 74 20 74 6F 20 63  68 61 6E 67 65 20 6F 77 | mpt to c hange ow
002BABF8:  6E 65 72 20 6F 66 20 66  72 65 65 20 62 6C 6F 63 | ner of f ree bloc
002BAC08:  6B 00 00 00 0A 66 72 65  65 69 6E 67 20 75 6E 75 | k....fre eing unu
002BAC18:  73 65 64 20 6D 65 6D 6F  72 79 3A 20 25 6C 75 20 | sed memo ry: %lu 
002BAC28:  62 79 74 65 73 00 00 00  69 6F 73 6D 73 67 2E 68 | bytes... iosmsg.h
002BAC38:  00 00 00 00 69 6F 73 6D  73 67 2E 63 00 00 00 00 | ....iosm sg.c....
002BAC48:  4D 73 67 20 69 73 20 71  75 65 75 65 64 00 00 00 | Msg is q ueued...
002BAC58:  61 49 6F 73 4D 73 67 47  65 74 20 63 61 6C 6C 65 | aIosMsgG et calle
002BAC68:  64 20 69 6E 20 69 6E 74  72 00 00 00 61 49 6F 73 | d in int r...aIos
002BAC78:  4D 73 67 47 65 74 3A 20  47 65 74 20 6F 6E 20 66 | MsgGet:  Get on f
002BAC88:  72 65 65 20 6D 73 67 21  00 00 00 00 61 49 6F 73 | ree msg! ....aIos

Stack dump (256 bytes):
Adr:= 0045D824
Len:= 00000100
0045D824:  00 6D 39 20 32 34 2E 18  00 3A F8 80 00 3F 47 C8 | .m9 24.. .:...?G.
0045D834:  00 3F 47 C4 00 45 D8 5C  00 45 D8 48 00 19 08 F8 | .?G..E.\ .E.H....
0045D844:  00 19 00 94 00 45 D8 74  32 34 2E 38 00 45 D8 74 | .....E.t 24.8.E.t
0045D854:  00 45 D8 60 00 19 0D A4  00 19 08 DC 00 5E 15 3C | .E.`.... .....^.<
0045D864:  00 00 00 00 00 45 D8 8C  00 45 D8 78 00 20 0C 58 | .....E.. .E.x. .X
0045D874:  00 19 0D 80 00 5E 15 28  00 5E 15 28 00 45 D8 A8 | .....^.( .^.(.E..
0045D884:  00 45 D8 90 00 24 14 50  00 20 0C 28 00 5E 15 28 | .E...$.P . .(.^.(
0045D894:  00 5E 15 28 00 3F 47 C8  00 45 D8 D0 00 45 D8 AC | .^.(.?G. .E...E..
0045D8A4:  00 24 15 40 00 24 14 3C  00 00 00 48 00 00 00 80 | .$.@.$.< ...H....
0045D8B4:  00 5E 15 28 00 00 00 04  49 54 41 47 00 2F EA C0 | .^.(.... ITAG./..
0045D8C4:  00 45 D8 E8 00 45 D8 D4  00 24 60 48 00 24 15 0C | .E...E.. .$`H.$..
0045D8D4:  00 3F 47 70 49 54 00 00  00 45 D9 1C 00 45 D8 EC | .?GpIT.. .E...E..
0045D8E4:  00 24 75 54 00 24 60 10  00 18 EE 40 00 35 60 0C | .$uT.$`. ...@.5`.
0045D8F4:  00 6D 40 40 49 54 00 00  49 54 41 47 00 2F EA C0 | .m@@IT.. ITAG./..
0045D904:  00 00 00 00 00 00 00 00  00 00 00 00 00 45 D9 40 | ........ .....E.@
0045D914:  00 45 D9 20 00 24 79 CC  00 24 74 A8 00 00 03 E8 | .E. .$y. .$t.....
largest available memory block: 9609152 bytes


DEVICE:           LANCOM L-54ag Wireless
HW-RELEASE:       C
VERSION:          4.12.0031 / 31.03.2005

****

7/16/2005 13:37:38   System boot after os_panic

DEVICE:           LANCOM L-54ag Wireless
HW-RELEASE:       C
VERSION:          4.12.0031 / 31.03.2005

[thomasgiger]

Der Bootlader im LANCOM schaltet die Firmware um, wenn die aktive Firmware zehnmal hintereinander innerhalb des Firmsafe-Timeouts mit einer os_panic abgestürzt ist.

Gut, dann glaube ich dass der Thread "Spontaner Wechsel der Firmware" dasselbe Problem im Hintergrund hat. Es ist nämlich so, dass durch die wechselnden Verhältnisse im Büro (wir "verstecken" die L54ag und madwifi Clients voreinander, um ein RSL kleiner -55 dBm zu erreichen) immer wieder mal ein madwifi-Client rausfliegt. Das erzeugt dann einen Reset am L54ag.

Hatte ja auch in dem anderen Thread geschrieben, dass dem Firmwarewechsel auffällig viele Assoziationen vorangegangen waren, die ich per mail signalisiert bekam. Mir war damals bloss nicht aufgefallen, dass das in Folge eines Resets passiert.

Wie auch immer: Dieses Problem lässt sich auf ALLEN unseren L54ag mit 4.12 Firmware und AES PSK zu madwifi-Clients reproduzieren. Kann sein, dass es nur mit madwifi-Clients passiert, aber das LCOS sollte es überleben - was immer madwifi Böses macht. Unkritisch ist es für uns bloss, weil unsere Outdoor Links viel stabiler sind als die Testumgebung im Büro.

[alf29]

Moin,

Hm, das ist einer der Crashes, die mit einem zerstörten Heap zusammen hängen -
die sind immer besonders nett zu suchen, weil's üblicherweise immer jemand ganz
anders trifft...einmal knallt es tatsächlich im EAPOL, ein anderes Mal aber in
der Stateful Inspection Firewall...

Es gab in dern 4er-Versionen einen Bug, daß ein am WPA/EAPOL beteiligter
BLock manchmal zweimal freigegeben wurde. Ob der schon in der 4.12 raus
war, weiß ich nicht mehr 100%, aus der 5.00 ist er aber definitv raus. Wäre also
mal interessant, ob das auch mit LCOS 5.00 auftritt...

Gruß Alfred

[thomasgiger]

Ein Upgrade auf 5.00 werde ich zuerst in der Indoor-Simulation ausprobieren. Dort fallen die Clients ja auch öfter raus als im Outdoor-Betrieb.

Übrigens noch ein Nachtrag:

Der Crash des L54ag tritt anscheinend doch nicht IMMER auf. Der Kunde hat seine madwifi-CPE jetzt ein zweites Mal neu gestartet und das L54ag hat's überlebt. Dazu folgendes WLAN-Log:

Code: Alles auswählen

Index Zeit Interface Ereignis Adresse Grund 
17 16.7.2005 22:22:50 WLAN-1-2 Key exchange with peer 00:0b:6b:34:7b:44 successfully 000b6b347b44  
16 16.7.2005 22:22:50 WLAN-1-2 Associated WLAN station 00:0b:6b:34:7b:44 [] 000b6b347b44  
15 16.7.2005 22:22:50 WLAN-1-2 Authenticated WLAN station 00:0b:6b:34:7b:44 [] 000b6b347b44  
14 16.7.2005 13:37:56 WLAN-1 Performing thermal recalibration (cool-down) 000000000000  
13 16.7.2005 13:37:45 WLAN-1-2 Key exchange with peer 00:0b:6b:34:7b:44 successfully 000b6b347b44  
12 16.7.2005 13:37:44 WLAN-1-2 Associated WLAN station 00:0b:6b:34:7b:44 [] 000b6b347b44  
11 16.7.2005 13:37:44 WLAN-1-2 Authenticated WLAN station 00:0b:6b:34:7b:44 [] 000b6b347b44  
10 16.7.2005 13:37:42 WLAN-1-2 Key exchange with peer 00:0b:6b:34:5e:cb successfully 000b6b345ecb  
9 16.7.2005 13:37:41 WLAN-1-2 Key exchange with peer 00:0b:6b:34:7b:3b successfully 000b6b347b3b  
8 16.7.2005 13:37:40 WLAN-1-2 Associated WLAN station 00:0b:6b:34:5e:cb [] 000b6b345ecb  
7 16.7.2005 13:37:40 WLAN-1-2 Authenticated WLAN station 00:0b:6b:34:5e:cb [] 000b6b345ecb  
6 16.7.2005 13:37:40 WLAN-1-2 Associated WLAN station 00:0b:6b:34:7b:3b [] 000b6b347b3b  
5 16.7.2005 13:37:40 WLAN-1-2 Authenticated WLAN station 00:0b:6b:34:7b:3b [] 000b6b347b3b  
4 16.7.2005 13:37:40 WLAN-1 Deauthenticated WLAN station 00:0b:6b:34:7b:44 [] () 000b6b347b44 Deauthenticated because sending station is leavin 
3 16.7.2005 13:37:40 WLAN-1-2 Rejected Association from WLAN station 00:0b:6b:34:7b:44 [] 000b6b347b44  
2 16.7.2005 13:37:40 WLAN-1-2 Authenticated WLAN station 00:0b:6b:34:7b:44 [] 000b6b347b44  
1 16.7.2005 13:37:38 WLAN-1 Started WLAN BSS ID 00:0b:6b:34:d2:c8 000b6b34d2c8 

...:7B:44 ist die madwifi-CPE, die um 13:37 und um 22:22 kurz ohne Strom war. Beim ersten Reset hat das L54ag parallel resettet, beim zweiten aber nicht.

Andererseits muss die "Trefferquote" aber so hoch sein, dass bei schlechten Verbindungen 10 Neustarts innerhalb des Firmsafe Timeouts möglich sind.

[thomasgiger]

Mit Firmware 5.00 konnte ich das Problem nicht mehr austesten - statt dessen gibt's ja jetzt die 5.02. Dabei zeigt sich folgendes:

Mit FW 5.02 treten erst gar nicht die häufigen "Authenticated" und "Associated" auf Events im WLAN-Log auf, obwohl sich an den Clients nichts geändert hat - es ist weiterhin die Büroumgebung, in der schon mal jemand vor der Antenne der Clients rumtanzt. Im Gegenteil: die FW 4.12 hatte den Kontakt zu den Clients auch am Wochenende häufig kurzzeitig verloren, wenn gar niemand im Büro war.

Da alles weitere (Absturz des LCOS und wenn's zu häufig passiert, Wechsel der Firmware zurück zu 3.42) eine Folge dieses Phänomens ist, kann ich jetzt noch nicht sagen, ob FW 5.02 das Problem ursächlich behebt oder nur indirekt.