6490: meshd crasht, sobald das Gäste WLAN aktiviert wird (seit 7.20)

[f666]

Servus,

nach dem Update von 7.12 auf 7.27 startet der Watchdog meine Box durchgängig neu, sobald das Gäste WLAN eingeschaltet wird.
Ursache ist ein abgestürzter meshd. Mit der 7.20 funktioniert es auch nicht.

Ich schreibe hier in der Hoffnung, dass jemand anderes das auch hatte und eine Lösung weiß.

Die Box wurde nach einem Werksreset neu aufgesetzt, hat nichts gebracht. Auch die Aktivierung des WLANs zusätzlich auf 5GHz bringt nichts (siehe Fehlermeldung auf der Konsole):

terminate called after throwing an instance of 'std::logic_error'
  what(): ChannelList covers multiple frequency bands: 1(2412000 kHz) 2(2417000 kHz) 3(2422000 kHz) 4(2427000 kHz) 5(2432000 kHz) 6(2437000 kHz) 7(2442000 kHz) 8(2447000 kHz) 9(2452000 kHz) 10(2457000 kHz) 11(2462000 kHz) 12(2467000 kHz) 13(2472000 kHz) 36(5180000 kHz) 40(5200000 kHz) 44(5220000 kHz) 48(5240000 kHz) 52(5260000 kHz) 56(5280000 kHz) 60(5300000 kHz) 64(5320000 kHz) 100(5500000 kHz) 104(5520000 kHz) 108(5540000 kHz) 112(5560000 kHz) 116(5580000 kHz) 120(5600000 kHz) 124(5620000 kHz) 128(5640000 kHz) 132(5660000 kHz) 136(5680000 kHz) 140(5700000 kHz)

is close to last optimisation attempt. Removing RSSI task for STA 08:D4:2B:1F:3F:0E
2021-07-08 08:12:07.574 - SC: Adding (w) OPTIMISATION RCPI STA 08:D4:2B:1F:3F:0E from F0:B0:14:42:EB:61 mode AUTO to <no target selected> to queue!
2021-07-08 08:12:07.575 - SC: [context_is_obsolete:670] RCPI (-54dBm) is close to last optimisation attempt. Removing RSSI task for STA 08:D4:2B:1F:3F:0E
2021-07-08 08:12:13.335 - NexusNodeService: Getting topology of F0:B0:14:42:EB:5F
2021-07-08 08:12:19.046 - SC: Adding (w) OPTIMISATION RCPI STA 80:58:F8:13:1F:0B from 34:81:C4:B1:28:74 mode AUTO to <no target selected> to queue!
2021-07-08 08:12:19.046 - SC: [context_is_obsolete:670] RCPI (-53dBm) is close to last optimisation attempt. Removing RSSI task for STA 80:58:F8:13:1F:0B
2021-07-08 08:14:13.384 - NexusNodeService: Getting topology of F0:B0:14:42:EB:5F
2021-07-08 08:14:41.748 - SC: Adding (w) OPTIMISATION RCPI STA AC:CF:85:2A:42:74 from 34:81:C4:B1:28:74 mode AUTO to <no target selected> to queue!
2021-07-08 08:14:41.748 - SC: [context_is_obsolete:670] RCPI (-51dBm) is close to last optimisation attempt. Removing RSSI task for STA AC:CF:85:2A:42:74
2021-07-08 08:14:41.749 - SC: Adding (w) OPTIMISATION RCPI STA 80:58:F8:13:1F:0B from 34:81:C4:B1:28:74 mode AUTO to <no target selected> to queue!
2021-07-08 08:14:41.749 - SC: [context_is_obsolete:670] RCPI (-48dBm) is close to last optimisation attempt. Removing RSSI task for STA 80:58:F8:13:1F:0B
2021-07-08 08:14:41.749 - SC: Adding (w) OPTIMISATION RCPI STA E0:D4:E8:21:08:C7 from 34:81:C4:B1:28:74 mode AUTO to <no target selected> to queue!
2021-07-08 08:14:41.750 - SC: [context_is_obsolete:670] RCPI (-48dBm) is close to last optimisation attempt. Removing RSSI task for STA E0:D4:E8:21:08:C7
2021-07-08 08:14:41.750 - SC: Adding (w) OPTIMISATION RCPI STA F8:F1:E6:48:2A:83 from 34:81:C4:B1:28:74 mode AUTO to <no target selected> to queue!
2021-07-08 08:14:41.750 - SC: [context_is_obsolete:670] RCPI (-39dBm) is close to last optimisation attempt. Removing RSSI task for STA F8:F1:E6:48:2A:83
2021-07-08 08:14:43.326 - topology_manager: Updating topology
2021-07-08 08:14:43.350 - NexusNodeService: Getting topology of F0:B0:14:42:EB:5F
2021-07-08 08:14:43.351 - NexusNodeService: Getting topology of 34:31:C4:27:20:8E
2021-07-08 08:14:43.351 - NexusNodeService: Getting topology of 34:81:C4:B1:28:72
2021-07-08 08:17:19.293 - SC: Adding (w) OPTIMISATION RCPI STA E0:D4:E8:21:08:C7 from 34:81:C4:B1:28:74 mode AUTO to <no target selected> to queue!
2021-07-08 08:17:19.293 - SC: [context_is_obsolete:670] RCPI (-48dBm) is close to last optimisation attempt. Removing RSSI task for STA E0:D4:E8:21:08:C7
2021-07-08 08:17:36.415 - SC: Adding (w) OPTIMISATION RCPI STA E0:D4:E8:21:08:C7 from 34:81:C4:B1:28:74 mode AUTO to <no target selected> to queue!
2021-07-08 08:17:36.415 - SC: [context_is_obsolete:670] RCPI (-48dBm) is close to last optimisation attempt. Removing RSSI task for STA E0:D4:E8:21:08:C7
2021-07-08 08:18:28.913 - SC: Adding (w) OPTIMISATION RCPI STA 08:CC:27:4A:4A:2E from C8:0E:14:88:DE:FE mode AUTO to <no target selected> to queue!
2021-07-08 08:18:28.913 - SC: dispatching OPTIMISATION RCPI task for STA 08:CC:27:4A:4A:2E with current RX RCPI: -42 dBm, age: 9 ms
2021-07-08 08:18:30.922 - WSS_select_target: [rate_link:130] Path (from client) C8:0E:14:88:DE:FE <-> 08:CC:27:4A:4A:2E scored RX 44417 and TX 44417
2021-07-08 08:18:30.922 - WSS_select_target: [rate_link:205] Path evaluation returned score of 44417 while last hop score is 44417
2021-07-08 08:18:30.925 - WSS_select_target: [rate_link:130] Path (from client) F0:B0:14:42:EB:61 <-> 08:CC:27:4A:4A:2E -> F0:B0:14:42:EB:5F <-> C8:0E:14:88:14:88 scored RX 0 and TX 71182
2021-07-08 08:18:30.925 - WSS_select_target: [rate_link:205] Path evaluation returned score of 71182 while last hop score is 56945
2021-07-08 08:18:30.925 - WSS_select_target: [select_target:351] Selected target F0:B0:14:42:EB:61 for STA 08:CC:27:4A:4A:2E out of 1 viable options
Jul  8 08:18:31 meshd[2820]: 2021-07-08 08:18:31(1) [Aborted] meshd([2820]) CRASHED at raise+0x92 (/lib//libc.so.0 at 00049f20) accessing 00000b04
Jul  8 08:18:31 meshd[2820]: SIGNO 6 ERRNO 0 CODE -6
Jul  8 08:18:31 meshd[2820]: UPTIME: 2807
Jul  8 08:18:31 meshd[2820]: Version: 07.27
Jul  8 08:18:31 meshd[2820]: Watchdog triggered 8 seconds ago
Jul  8 08:18:31 meshd[2820]: No bugmsg
Jul  8 08:18:31 meshd[2820]: eax: 00000000  ebx: 00000002  ecx: bff9183c
Jul  8 08:18:31 meshd[2820]: edx: 00000000  esi: 00000008  edi: b7182c74
Jul  8 08:18:31 meshd[2820]: ebp: bff91858  esp: bff91834  eip: b710af20
Jul  8 08:18:31 meshd[2820]: cs :     0073  ds :     007b  es :     007b
Jul  8 08:18:31 meshd[2820]: fs :     0000  gs :     0033  ss :     007b
Jul  8 08:18:31 meshd[2820]: err: 00000000  oms: 00000000  tno: 00000000
Jul  8 08:18:31 meshd[2820]: esp: bff91834  cr2: 00000000
Jul  8 08:18:31 meshd[2820]: eflags [00000246] PF ZF IF
Jul  8 08:18:31 meshd[2820]: FA 00000b04
Jul  8 08:18:31 meshd[2820]: PC b710af20 raise+0x92 (/lib//libc.so.0 at 00049f20)
Jul  8 08:18:31 meshd[2820]: PC Code: 4d e0 53 89 c3 b8 af 00 00 00 cd 80 <5b 83 c4 14> 89 d8 5b 5e 5f 5d c3 55 89 e5 53 52 e8 74 69 fc ff 81 c3 3f
Jul  8 08:18:31 meshd[2820]: LR b7106166 abort+0x66 (/lib//libc.so.0 at 00045166)
Jul  8 08:18:31 meshd[2820]: LR Code: c7 04 24 06 00 00 00 e8 28 4d 00 00 <89 34 24 e8> b4 a9 01 00 83 c4 10 8a 83 4f 69 01 00 3c 01 75 31 8d 55 d4
Jul  8 08:18:31 meshd[2820]: [bt] b710af20 raise+0x92 (/lib//libc.so.0 at 00049e8e/0x49f20)
Jul  8 08:18:31 meshd[2820]:                         Code: 4d e0 53 89 c3 b8 af 00 00 00 cd 80 <5b 83 c4 14> 89 d8 5b 5e 5f 5d c3 55 89 e5 53 52 e8 74 69 fc ff 81 c3 3f
Jul  8 08:18:31 meshd[2820]: [bt] b7106166 abort+0x66 (/lib//libc.so.0 at 00045100/0x45166)
Jul  8 08:18:31 meshd[2820]:                         Code: c7 04 24 06 00 00 00 e8 28 4d 00 00 <89 34 24 e8> b4 a9 01 00 83 c4 10 8a 83 4f 69 01 00 3c 01 75 31 8d 55 d4
Jul  8 08:18:31 meshd[2820]: [bt] b72c6b02 avmcppterminatehandler::terminate_handler()+0x140 (/lib//libavmcppterminatehandler.so.1 at 000009c2/0xb02)
Jul  8 08:18:31 meshd[2820]:                         Code: ff ff e8 17 fe ff ff e8 2e fc ff ff <4a 75 41 83> ec 0c 50 e8 3a fc ff ff 89 c6 8d 83 98 ec ff ff 89 04 24 e8
Jul  8 08:18:31 meshd[2820]: [bt] b722226e [b722225b] <0+0xb722225b>+0x13 (/usr/lib//libstdc++.so.6 at 0007225b/0x7226e)
Jul  8 08:18:31 meshd[2820]:                         Code: d2 ff ff 81 c3 9b fd 09 00 ff 55 08 <e8 5d 7e ff> ff 83 ec 0c 50 e8 44 a8 ff ff e8 4f 7e ff ff 55 e8 16 d2 ff
Jul  8 08:18:31 meshd[2820]: [bt] b72222d0 0+0xb72222d0 (/usr/lib//libstdc++.so.6 at 000722d0)
Jul  8 08:18:31 meshd[2820]:                         Code: 85 ff ff 83 ec 0c 50 e8 8b ff ff ff <55 89 e5 53> 50 e8 cb d1 ff ff 81 c3 26 fd 09 00 ff 55 08 e8 a8 c0 ff ff
Jul  8 08:18:31 meshd[2820]: [bt] b7222517 __cxa_rethrow (/usr/lib//libstdc++.so.6 at 00072517)
Jul  8 08:18:31 meshd[2820]:                         Code: 34 24 e8 ae a5 ff ff e8 79 be ff ff <55 89 e5 57> 56 53 e8 83 cf ff ff 81 c3 de fa 09 00 83 ec 0c e8 20 96 ff
Jul  8 08:18:31 meshd[2820]: [bt] b7607cfc avm::ChannelList::get_detailed_frequency_band() const+0x462 (/usr/lib//libmesh_shared.so.0 at 0005589a/0x55cfc)
Jul  8 08:18:31 meshd[2820]:                         Code: ff b3 c8 01 00 00 56 e8 e4 70 ff ff <b0 04 52 52> 8d 95 d4 fe ff ff ff b5 dc fe ff ff 88 85 bc fe ff ff 52 e8
Jul  8 08:18:31 meshd[2820]: [bt] b7607dc2 avm::ChannelList::get_frequency_band() const+0x1a (/usr/lib//libmesh_shared.so.0 at 00055da8/0x55dc2)
Jul  8 08:18:31 meshd[2820]:                         Code: 00 83 ec 10 ff 75 08 e8 b6 70 ff ff <83 c4 10 3c> 03 b2 02 77 05 84 c0 0f 95 c2 88 d0 8b 5d fc c9 c3 55 89 e5
Jul  8 08:18:31 meshd[2820]: [bt] b754ab00 avm::mesh::WLANSteeringStateSelectTarget::log_traget_selection_kpi(avm::MACAddress const&, avm::mesh::WLANInterface const&, avm::mesh::WLANInterface const&)+0x8e (/usr/lib//libmeshd.so.0 at 00123a72/0x123b00)
Jul  8 08:18:31 meshd[2820]:                         Code: 80 09 f3 ff 89 04 24 e8 10 13 f3 ff <8d 55 e0 8d> 4d dc 88 45 c6 89 14 24 89 4d b4 89 55 b8 e8 61 33 f3 ff 8b
Jul  8 08:18:31 meshd[2820]: [bt] b754c676 avm::mesh::WLANSteeringStateSelectTarget::select_target()+0xe72 (/usr/lib//libmeshd.so.0 at 00124804/0x125676)
Jul  8 08:18:31 meshd[2820]:                         Code: ff ff b5 58 fe ff ff e8 c2 19 f3 ff <8b 85 1c fe> ff ff 5e 5f 6a 00 ff 70 04 e8 e6 0e 00 00 e9 78 ff ff ff 8b
Jul  8 08:18:31 meshd[2820]: [bt] b754cd0e avm::mesh::WLANSteeringStateSelectTarget::on_entry()+0x148 (/usr/lib//libmeshd.so.0 at 00125bc6/0x125d0e)
Jul  8 08:18:31 meshd[2820]:                         Code: 0a f5 f2 ff 89 3c 24 e8 c2 f5 f2 ff <8b 45 e4 65> 33 05 14 00 00 00 74 30 e8 c6 ec 00 00 eb 16 eb 02 eb 12 89
Jul  8 08:18:31 meshd[2820]: [bt] b7545c9b [b7545bd5] <0+0xb7545bd5>+0xc6 (/usr/lib//libmeshd.so.0 at 0011ebd5/0x11ec9b)
Jul  8 08:18:31 meshd[2820]:                         Code: e0 89 46 04 8b 10 89 04 24 ff 52 10 <8b 46 04 83> c4 10 85 c0 74 0d 52 52 6a 01 50 e8 a9 72 f3 ff 83 c4 10 83
Jul  8 08:18:31 meshd[2820]: [bt] b7552556 [b75523db] <0+0xb75523db>+0x17b (/usr/lib//libmeshd.so.0 at 0012b3db/0x12b556)
Jul  8 08:18:31 meshd[2820]:                         Code: b4 5a 6a 00 ff 70 04 e8 7c 36 ff ff <8d 45 c8 83> c4 10 83 ec 0c 50 e8 13 b9 f2 ff 8b 45 e4 65 33 05 14 00 00
Jul  8 08:18:31 meshd[2820]: [bt] b7554ecf [b7554863] <0+0xb7554863>+0x66c (/usr/lib//libmeshd.so.0 at 0012d863/0x12decf)
Jul  8 08:18:31 meshd[2820]:                         Code: 0c ff b5 e8 fc ff ff e8 09 d5 ff ff <8d 85 30 fd> ff ff 89 04 24 e8 9b 8f f2 ff 8d 85 20 fd ff ff 89 04 24 e8
Jul  8 08:18:31 meshd[2820]: [bt] b76ef735 [b76ef506] <0+0xb76ef506>+0x22f (/usr/sbin/meshd at 0005b506/0x5b735)
Jul  8 08:18:31 meshd[2820]:                         Code: 50 50 8d 46 04 ff 75 bc 50 ff 56 10 <89 3c 24 e8> 1b b5 fc ff 8b 45 e4 65 33 05 14 00 00 00 74 18 e8 59 f3 01
Jul  8 08:18:31 meshd[2820]: [bt] b76ef8d3 [b76ef506] <0+0xb76ef506>+0x3cd (/usr/sbin/meshd at 0005b506/0x5b8d3)
Jul  8 08:18:31 meshd[2820]:                         Code: 51 51 ff 32 ff 70 08 e8 8b fd ff ff <83 c4 10 eb> db 8b 47 08 83 ec 0c 8b 10 50 ff 52 18 83 c4 10 84 c0 0f 84
Jul  8 08:18:31 meshd[2820]: [bt] b76dd228 [b76dd16d] <0+0xb76dd16d>+0xbb (/usr/sbin/meshd at 0004916d/0x49228)
Jul  8 08:18:31 meshd[2820]:                         Code: 83 c6 10 52 52 56 50 e8 42 25 01 00 <83 c4 10 eb> 13 89 c6 83 ec 0c 57 e8 0c bc 00 00 89 34 24 e8 68 3d fd ff
Jul  8 08:18:31 meshd[2820]: [bt] b7604db7 avm::async::FuturePool::process_futures()+0x97 (/usr/lib//libmesh_shared.so.0 at 00052d20/0x52db7)
Jul  8 08:18:31 meshd[2820]:                         Code: 8b 47 08 83 ec 0c 8b 08 50 ff 51 0c <83 c4 0c 57> 56 ff 75 cc e8 1c 8e ff ff 8b 7d d4 83 c4 0c eb 91 8b 3f eb
Jul  8 08:18:31 meshd[2820]: [bt] b7648480 avm::daemon::Mainloop::run(std::chrono::duration<long long, std::ratio<1ll, 1000ll> >)+0x6c (/usr/lib//libmesh_shared.so.0 at 00096414/0x96480)
Jul  8 08:18:31 meshd[2820]:                         Code: 0c 8d 70 28 89 34 24 e8 b8 5f fb ff <83 c4 10 84> c0 74 10 8b 45 08 c7 00 01 00 00 00 c7 40 04 00 00 00 00 8b
Jul  8 08:18:31 meshd[2820]: [bt] b76b29fb [b76b26e1] <main+0x147a>+0x31a (/usr/sbin/meshd at 0001e6e1/0x1e9fb)
Jul  8 08:18:31 meshd[2820]:                         Code: 50 ff b5 80 f6 ff ff e8 ad df ff ff <8b 83 6c 19> 00 00 83 c4 0c 8b b5 88 f6 ff ff 8b bd 8c f6 ff ff 85 c0 74
Jul  8 08:18:31 meshd[2820]: [bt] finished.
Jul  8 08:18:33 plcd[1811]: event=Client disconnected. str1= str2= str3=

Beim AVM Support habe ich bereits ein Ticket aufgemacht mit dem Konsolenlog und den Supportdateien. Allerdings bestehen die auf einen erneuten Werksreset und wollen wieder die Supportdateien (und die Seriennummer, ....). Alles neu Einrichten kostet mich 2h.
Ergo: Der Supporter hat seine Checkliste ausgepackt und die passenden Textbausteine angeklickt. Keine wirkliche Hilfe.

 

[prisrak1]

einfach Disable AVM watchdog - und gut ist. Bei (fast) allen KD-Modellen ist es das Problem in der v.2.27.

 

[f666]

Hm, selbst wenn ich den Watchdog deaktiviere, ist der meshd trotzdem tot. Wenn ich den manuell neu starte, stürzt er nach Sekunden bis Minuten wieder ab.

Die Firmware ist nicht gefreezt, nur manuell mit ssh und telnet ergänzt.

 

[prisrak1]

bei mir mit Freetz und kein Problem, dann liegts an AVM eben.

 

[frank_m24]

nur manuell mit ssh und telnet ergänzt.

Waren das statisch gelinkte Binaries, oder waren da Bibliotheken mit im Lieferumfang?

 

[f666]

/usr/sbin/telnetd ist der Symlink auf die ../../bin/busybox. sshd ist statisch aus dem YourFritz Repository.
Nach meinem Verständnis sollte der AVM Teil der FW unberührt nebenher laufen.

Die Fehlermeldung ("ChannelList covers multiple frequency bands") kommt in der /usr/lib/mesh_shared.so vor.

Wo bleibt nach einem Werksreset noch was übrig, was eine nicht Freetz Firmware beeinflusst? Höchstens im NVRAM auf dem ARM Core.
Ich kann mir da bisher keinen Reim darauf machen.

 

[sonyKatze]

Recover.exe? Aber ja:

[AVM besteht] auf einen erneuten Werksreset […] Alles neu Einrichten kostet mich 2h.

Keine Ahnung, was die Fehlermeldung bedeutet, aber der WLAN-Chip ist ja auch ein eigener Chip. Vielleicht ist dort eine Variable gesetzt, die so wild ist, das AVM nicht soweit geht, den Chip zurückzusetzen.