FHEM Forum

FHEM - Hardware => Einplatinencomputer => Thema gestartet von: JWRu am 03 November 2020, 23:15:43

Titel: RasPi-Zero-W - Probleme mit Bluetooth - XiaomiBTLESens oder (le)presenced?
Beitrag von: JWRu am 03 November 2020, 23:15:43
Ich habe auf meinem RasPi-Zero-W (Buster) sporadische "Hänger". Es handelt sich um ein Minimalsystem, auf dem nur zwei XiaomiBTLESens-Devices und presenced und lepresenced laufen.
Benutzt wird ein Bluetooth-Dongle, on-board BT ist deaktiviert.
Der "Hänger" äußert sich in plötzlich ansteigender Systemlast (siehe angehängtes Bild). FHEM wird langsam, ist aber noch ansprechbar - ssh funktioniert auch noch.

Im FHEM-Log findet sich nur das:
grep: Schreibfehler: Datenübergabe unterbrochen (broken pipe)
grep: Schreibfehler: Datenübergabe unterbrochen (broken pipe)
grep: Schreibfehler: Datenübergabe unterbrochen (broken pipe)
grep: Schreibfehler: Datenübergabe unterbrochen (broken pipe)
grep: Schreibfehler: Datenübergabe unterbrochen (broken pipe)
grep: Schreibfehler: Datenübergabe unterbrochen (broken pipe)
grep: Schreibfehler: Datenübergabe unterbrochen (broken pipe)
grep: Schreibfehler: Datenübergabe unterbrochen (broken pipe)
grep: Schreibfehler: Datenübergabe unterbrochen (broken pipe)
grep: Schreibfehler: Datenübergabe unterbrochen (broken pipe)


Im RasPi-Syslog findet sich das:
17:38:14 WeRu-RasPi-Z lepresenced[400]: [tid:2] main::bluetooth_dump_thread: Received '< HCI Command: Remote Name Request (0x01|0x0019) plen 10', telling hcidump and hcitool to restart...
Nov  3 17:38:14 WeRu-RasPi-Z lepresenced[400]: [tid:2] main::bluetooth_dump_thread: restarting hcidump...
Nov  3 17:38:19 WeRu-RasPi-Z lepresenced[400]: [tid:1] main::bluetooth_scan_thread: restarting hcitool...
Nov  3 17:38:21 WeRu-RasPi-Z lepresenced[400]: [tid:2] main::bluetooth_dump_thread: Received '< HCI Command: Remote Name Request (0x01|0x0019) plen 10', telling hcidump and hcitool to restart...
Nov  3 17:38:21 WeRu-RasPi-Z lepresenced[400]: [tid:2] main::bluetooth_dump_thread: restarting hcidump...
Nov  3 17:38:26 WeRu-RasPi-Z lepresenced[400]: [tid:1] main::bluetooth_scan_thread: restarting hcitool...
Nov  3 17:38:29 WeRu-RasPi-Z lepresenced[400]: [tid:2] main::bluetooth_dump_thread: Received '< HCI Command: Remote Name Request (0x01|0x0019) plen 10', telling hcidump and hcitool to restart...
Nov  3 17:38:29 WeRu-RasPi-Z lepresenced[400]: [tid:2] main::bluetooth_dump_thread: restarting hcidump...
Nov  3 17:38:34 WeRu-RasPi-Z lepresenced[400]: [tid:1] main::bluetooth_scan_thread: restarting hcitool...
Nov  3 17:38:38 WeRu-RasPi-Z lepresenced[400]: [tid:2] main::bluetooth_dump_thread: Received '< HCI Command: Remote Name Request (0x01|0x0019) plen 10', telling hcidump and hcitool to restart...
Nov  3 17:38:38 WeRu-RasPi-Z lepresenced[400]: [tid:2] main::bluetooth_dump_thread: restarting hcidump...
Nov  3 17:38:38 WeRu-RasPi-Z lepresenced[400]: [tid:1] main::bluetooth_scan_thread: restarting hcitool...
Nov  3 17:38:55 WeRu-RasPi-Z kernel: [512497.812376] Bluetooth: hci0: advertising data len corrected
Nov  3 17:39:11 WeRu-RasPi-Z lepresenced[400]: [tid:2] main::bluetooth_dump_thread: Received '< HCI Command: LE Set Scan Enable (0x08|0x000c) plen 2', telling hcidump and hcitool to restart...
Nov  3 17:39:11 WeRu-RasPi-Z lepresenced[400]: [tid:2] main::bluetooth_dump_thread: restarting hcidump...
Nov  3 17:39:12 WeRu-RasPi-Z kernel: [512513.668422] 8<--- cut here ---
Nov  3 17:39:12 WeRu-RasPi-Z kernel: [512513.674064] Unable to handle kernel NULL pointer dereference at virtual address 00000012
Nov  3 17:39:12 WeRu-RasPi-Z kernel: [512513.686947] pgd = c54660b9
Nov  3 17:39:12 WeRu-RasPi-Z kernel: [512513.692189] [00000012] *pgd=00000000
Nov  3 17:39:12 WeRu-RasPi-Z kernel: [512513.698215] Internal error: Oops: 17 [#1] ARM
Nov  3 17:39:12 WeRu-RasPi-Z kernel: [512513.704985] Modules linked in: algif_hash ecb algif_skcipher af_alg rpcsec_gss_krb5 aes_arm aes_generic cmac bnep 8021q garp stp llc brcmfmac brcmutil btusb btrtl btintel btbcm sha256_generic libsha256 bluetooth ecdh_generic ecc libaes cfg80211 rfkill raspberrypi_hwmon bcm2835_codec(C) bcm2835_v4l2(C) bcm2835_isp(C) v4l2_mem2mem bcm2835_mmal_vchiq(C) snd_bcm2835(C) videobuf2_vmalloc videobuf2_dma_contig videobuf2_memops videobuf2_v4l2 snd_pcm videobuf2_common snd_timer snd videodev vc_sm_cma(C) mc uio_pdrv_genirq uio fixed ip_tables x_tables ipv6 nf_defrag_ipv6
Nov  3 17:39:12 WeRu-RasPi-Z kernel: [512513.773908] CPU: 0 PID: 28760 Comm: kworker/u3:2 Tainted: G         C        5.4.51+ #1333
Nov  3 17:39:12 WeRu-RasPi-Z kernel: [512513.788293] Hardware name: BCM2835
Nov  3 17:39:12 WeRu-RasPi-Z kernel: [512513.795420] Workqueue: hci0 hci_rx_work [bluetooth]
Nov  3 17:39:12 WeRu-RasPi-Z kernel: [512513.803967] PC is at hci_connect_le_scan_cleanup+0x14/0x12c [bluetooth]
Nov  3 17:39:12 WeRu-RasPi-Z kernel: [512513.814304] LR is at create_le_conn_complete+0xd0/0xd8 [bluetooth]
Nov  3 17:39:12 WeRu-RasPi-Z kernel: [512513.823789] pc : [<bf56de10>]    lr : [<bf57067c>]    psr: 60000013
Nov  3 17:39:12 WeRu-RasPi-Z kernel: [512513.833331] sp : d6003de0  ip : d6003e00  fp : d6003dfc
Nov  3 17:39:12 WeRu-RasPi-Z kernel: [512513.841873] r10: d4768700  r9 : d37c9300  r8 : d47687d4
Nov  3 17:39:12 WeRu-RasPi-Z kernel: [512513.850288] r7 : 00000000  r6 : d4768008  r5 : d4768000  r4 : d4768888
Nov  3 17:39:12 WeRu-RasPi-Z kernel: [512513.860017] r3 : bf5705ac  r2 : 00000000  r1 : 00000000  r0 : 00000000
Nov  3 17:39:12 WeRu-RasPi-Z kernel: [512513.869714] Flags: nZCv  IRQs on  FIQs on  Mode SVC_32  ISA ARM  Segment user
Nov  3 17:39:12 WeRu-RasPi-Z kernel: [512513.880178] Control: 00c5387d  Table: 14698008  DAC: 00000055
Nov  3 17:39:12 WeRu-RasPi-Z kernel: [512513.889296] Process kworker/u3:2 (pid: 28760, stack limit = 0xe46021ca)
Nov  3 17:39:12 WeRu-RasPi-Z kernel: [512513.899288] Stack: (0xd6003de0 to 0xd6004000)
Nov  3 17:39:12 WeRu-RasPi-Z kernel: [512513.906931] 3de0: d4768888 d4768000 d4768008 00000000 d6003e1c d6003e00 bf57067c bf56de08
Nov  3 17:39:12 WeRu-RasPi-Z kernel: [512513.921406] 3e00: d4768000 d37c9300 d37c9180 0000000e d6003ecc d6003e20 bf577d98 bf5705b8
Nov  3 17:39:12 WeRu-RasPi-Z kernel: [512513.935914] 3e20: d6003e68 d6003e6c c0013580 00000000 c0a47028 00000003 d6003e84 d6003e48
Nov  3 17:39:12 WeRu-RasPi-Z kernel: [512513.950457] 3e40: c00135d0 c00148a8 c00135d0 00000000 bf5679f0 d6003f0c d6003ed0 00000000
Nov  3 17:39:12 WeRu-RasPi-Z kernel: [512513.965162] 3e60: 007c9300 c060200d bf5705ac 00000000 d47687d4 00000000 d6003eac d6003e88
Nov  3 17:39:12 WeRu-RasPi-Z kernel: [512513.980147] 3e80: c00d9884 bf58b424 00000000 d3482400 00000000 d4768000 d6003ecc 8d34f39a
Nov  3 17:39:12 WeRu-RasPi-Z kernel: [512513.995300] 3ea0: bf58b424 d47686fc d47686fc d4768888 d4768000 d47687d4 d37c9300 d4768700
Nov  3 17:39:12 WeRu-RasPi-Z kernel: [512514.010677] 3ec0: d6003f0c d6003ed0 bf567b4c bf577a44 d44e0300 00000000 d6003f0c d476800c
Nov  3 17:39:12 WeRu-RasPi-Z kernel: [512514.026367] 3ee0: c00d9884 d47686fc d3dcff60 00000060 00000000 d44e0300 00000000 d4768700
Nov  3 17:39:12 WeRu-RasPi-Z kernel: [512514.042193] 3f00: d6003f44 d6003f10 c003e2f8 bf5679bc c003e998 d75fe600 d6003f44 d3dcff60
Nov  3 17:39:12 WeRu-RasPi-Z kernel: [512514.058143] 3f20: d75fe600 d3dcff74 d75fe614 c0a578c0 00000088 d75fe600 d6003f7c d6003f48
Nov  3 17:39:12 WeRu-RasPi-Z kernel: [512514.074176] 3f40: c003e90c c003e1d0 d6003f7c d6003f58 c00433d0 d358c340 d6379140 00000000
Nov  3 17:39:12 WeRu-RasPi-Z kernel: [512514.090206] 3f60: d3dcff60 c003e8d8 d6029e88 d358c358 d6003fac d6003f80 c0044134 c003e8e4
Nov  3 17:39:12 WeRu-RasPi-Z kernel: [512514.106240] 3f80: ffffffff d6379140 c0044018 00000000 00000000 00000000 00000000 00000000
Nov  3 17:39:12 WeRu-RasPi-Z kernel: [512514.122271] 3fa0: 00000000 d6003fb0 c00090ac c0044024 00000000 00000000 00000000 00000000
Nov  3 17:39:12 WeRu-RasPi-Z kernel: [512514.138305] 3fc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
Nov  3 17:39:12 WeRu-RasPi-Z kernel: [512514.154342] 3fe0: 00000000 00000000 00000000 00000000 00000013 00000000 00000000 00000000
Nov  3 17:39:12 WeRu-RasPi-Z kernel: [512514.170387] Backtrace:
Nov  3 17:39:12 WeRu-RasPi-Z kernel: [512514.177575] [<bf56ddfc>] (hci_connect_le_scan_cleanup [bluetooth]) from [<bf57067c>] (create_le_conn_complete+0xd0/0xd8 [bluetooth])
Nov  3 17:39:12 WeRu-RasPi-Z kernel: [512514.197259]  r7:00000000 r6:d4768008 r5:d4768000 r4:d4768888
Nov  3 17:39:12 WeRu-RasPi-Z kernel: [512514.207698] [<bf5705ac>] (create_le_conn_complete [bluetooth]) from [<bf577d98>] (hci_event_packet+0x360/0x2ed4 [bluetooth])
Nov  3 17:39:12 WeRu-RasPi-Z kernel: [512514.226527]  r7:0000000e r6:d37c9180 r5:d37c9300 r4:d4768000
Nov  3 17:39:12 WeRu-RasPi-Z kernel: [512514.236812] [<bf577a38>] (hci_event_packet [bluetooth]) from [<bf567b4c>] (hci_rx_work+0x19c/0x278 [bluetooth])
Nov  3 17:39:12 WeRu-RasPi-Z kernel: [512514.254407]  r10:d4768700 r9:d37c9300 r8:d47687d4 r7:d4768000 r6:d4768888 r5:d47686fc
Nov  3 17:39:12 WeRu-RasPi-Z kernel: [512514.269601]  r4:d47686fc
Nov  3 17:39:12 WeRu-RasPi-Z kernel: [512514.276231] [<bf5679b0>] (hci_rx_work [bluetooth]) from [<c003e2f8>] (process_one_work+0x134/0x3f4)
Nov  3 17:39:12 WeRu-RasPi-Z kernel: [512514.292436]  r10:d4768700 r9:00000000 r8:d44e0300 r7:00000000 r6:00000060 r5:d3dcff60
Nov  3 17:39:12 WeRu-RasPi-Z kernel: [512514.307324]  r4:d47686fc
Nov  3 17:39:12 WeRu-RasPi-Z kernel: [512514.313327] [<c003e1c4>] (process_one_work) from [<c003e90c>] (worker_thread+0x34/0x540)
Nov  3 17:39:12 WeRu-RasPi-Z kernel: [512514.328282]  r10:d75fe600 r9:00000088 r8:c0a578c0 r7:d75fe614 r6:d3dcff74 r5:d75fe600
Nov  3 17:39:12 WeRu-RasPi-Z kernel: [512514.343030]  r4:d3dcff60
Nov  3 17:39:12 WeRu-RasPi-Z kernel: [512514.348989] [<c003e8d8>] (worker_thread) from [<c0044134>] (kthread+0x11c/0x154)
Nov  3 17:39:12 WeRu-RasPi-Z kernel: [512514.363268]  r10:d358c358 r9:d6029e88 r8:c003e8d8 r7:d3dcff60 r6:00000000 r5:d6379140
Nov  3 17:39:12 WeRu-RasPi-Z kernel: [512514.378030]  r4:d358c340
Nov  3 17:39:12 WeRu-RasPi-Z kernel: [512514.383961] [<c0044018>] (kthread) from [<c00090ac>] (ret_from_fork+0x14/0x28)
Nov  3 17:39:12 WeRu-RasPi-Z kernel: [512514.394736] Exception stack(0xd6003fb0 to 0xd6003ff8)
Nov  3 17:39:12 WeRu-RasPi-Z kernel: [512514.403222] 3fa0:                                     00000000 00000000 00000000 00000000
Nov  3 17:39:12 WeRu-RasPi-Z kernel: [512514.418040] 3fc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
Nov  3 17:39:12 WeRu-RasPi-Z kernel: [512514.433042] 3fe0: 00000000 00000000 00000000 00000000 00000013 00000000
Nov  3 17:39:12 WeRu-RasPi-Z kernel: [512514.443195]  r10:00000000 r9:00000000 r8:00000000 r7:00000000 r6:00000000 r5:c0044018
Nov  3 17:39:12 WeRu-RasPi-Z kernel: [512514.457601]  r4:d6379140 r3:ffffffff
Nov  3 17:39:12 WeRu-RasPi-Z kernel: [512514.464559] Code: e92dd8f0 e24cb004 e52de004 e8bd4000 (e5d05012)
Nov  3 17:39:12 WeRu-RasPi-Z kernel: [512514.474463] ---[ end trace 763c99bf348ad4fd ]---


Seltsam ist, dass ich nach einem Reboot nicht mehr per ssh auf das System komme (connection refused). Wenn ich den RasPi aus- und wieder einschalte, läuft alles wieder normal.
Titel: Antw:RasPi-Zero-W - Probleme mit Bluetooth - XiaomiBTLESens oder (le)presenced?
Beitrag von: Wernieman am 04 November 2020, 11:16:00
Nov  3 17:39:12 WeRu-RasPi-Z kernel: [512513.674064] Unable to handle kernel NULL pointer dereference at virtual address 00000012
Du hast einen kernel-Dump. Würde auf Hardwareprobleme tippen. Deshalb hilft Dir auch kein "restart", da dann nicht die komplette Hardware resetet wird. Das geschieht erst durch "Strom weg/da"
Titel: Antw:RasPi-Zero-W - Probleme mit Bluetooth - XiaomiBTLESens oder (le)presenced?
Beitrag von: Otto123 am 04 November 2020, 12:07:06
Ich habe jetzt nicht verstanden, ob FHEM auf dem Pi läuft. Wenn ja, dann schau mal bitte hier der erste Satz und der Link darin.
https://wiki.fhem.de/wiki/Fhem.service_(systemd_unit_file)#Startreihenfolge_beeinflussen

Gruß Otto
Titel: Antw:RasPi-Zero-W - Probleme mit Bluetooth - XiaomiBTLESens oder (le)presenced?
Beitrag von: JWRu am 04 November 2020, 12:35:20
Vielen Dank für den Tipp!
Mit FHEM gab es eigentlich kein Problem.
Ich vermute, dass das Problem davon verursacht wurde, dass lepresenced, presenced und XiaomiBTLESens auf denselben BT-Adapter (Dongle) zugegriffen haben.
Das hat im Sekundentakt zu solchen Meldungen geführt:
Nov  3 17:38:29 WeRu-RasPi-Z lepresenced[400]: [tid:2] main::bluetooth_dump_thread: Received '< HCI Command: Remote Name Request (0x01|0x0019) plen 10', telling hcidump and hcitool to restart...
Nov  3 17:38:29 WeRu-RasPi-Z lepresenced[400]: [tid:2] main::bluetooth_dump_thread: restarting hcidump...
Nov  3 17:38:34 WeRu-RasPi-Z lepresenced[400]: [tid:1] main::bluetooth_scan_thread: restarting hcitool...


Da es einen ganz frischen Bugfix für pi-bluetooth gibt, habe ich jetzt den on-board-Adapter aktivieren können und lasse presenced und XiaomiBTLESens darauf laufen.
Seitdem sind die Meldungen verschwunden.

Außerdem habe ich mal ein apt-get upgrade gemacht - dabei wurden auch einige Dinge bezüglich Bluetooth aktualisiert.


Nachtrag:
Gibt es eine Möglichkeit, hcix fest einem Bluetooth-Adapter zuzuordnen (z.B. über die MAC-Adresse)?
Beispielsweise hci0 immer on-Board, hci1 Dongle.