Skip to content

BLE advertisements stop after BLE operation #24268

@SteWers

Description

@SteWers

PROBLEM DESCRIPTION

BLE advertisements running fine until a BLE operation is issued. 120 sec later BLE restarts, because of no adverts. Details can be seen in the attached logs.

@Staars: I hope, you have a clue to fix this easily. I tried to figure it out, but I had no success.

REQUESTED INFORMATION

  • Read the Contributing Guide and Policy and the Code of Conduct
  • Searched the problem in issues
  • Searched the problem in discussions
  • Searched the problem in the docs
  • Searched the problem in the chat
  • Device used: ESP32 dev board and other
  • Tasmota binary firmware version number used: Latest dev 15.2.0.2 (bluetooth)
    • Pre-compiled
    • Self-compiled
  • Set weblog to 4 and then, when you experience your issue, provide the output of the Console log:
17:15:33.879	BLE: scans:14,advertisements:4934,devices:9,resets:0,BLEStop:0,BLERunning:1,BLERunningScan:1,BLELoopCount:2916,BLEOpCount:0
17:15:34.825	BLE: scans:14,advertisements:4942,devices:9,resets:0,BLEStop:0,BLERunning:1,BLERunningScan:1,BLELoopCount:2926,BLEOpCount:0
17:15:35.504	M32: A4C138B33A3D: Frame 146, last 145
17:15:35.520	M32: A4C138B33A3D: ATC:pvvx at slot 1
17:15:35.817	BLE: scans:14,advertisements:4959,devices:9,resets:0,BLEStop:0,BLERunning:1,BLERunningScan:1,BLELoopCount:2936,BLEOpCount:0
17:15:36.121	M32: A4C138C7A601: No payload
17:15:36.121	M32: A4C138C7A601: Frame 170, last 170
17:15:36.121	M32: A4C138C7A601: MIParsePacket returned 0
17:15:36.845	BLE: scans:14,advertisements:4978,devices:9,resets:0,BLEStop:0,BLERunning:1,BLERunningScan:1,BLELoopCount:2946,BLEOpCount:0
17:15:37.868	BLE: scans:14,advertisements:4998,devices:9,resets:0,BLEStop:0,BLERunning:1,BLERunningScan:1,BLELoopCount:2956,BLEOpCount:0
17:15:38.549	BLE: Scan ended
17:15:38.553	M32: Scan complete
17:15:38.556	BLE: scancompleteCallbacks 0 0
17:15:38.585	BLE: BLETask: Startscan
17:15:38.896	BLE: scans:15,advertisements:5015,devices:9,resets:0,BLEStop:0,BLERunning:1,BLERunningScan:1,BLELoopCount:2965,BLEOpCount:0
17:15:39.864	BLE: scans:15,advertisements:5032,devices:9,resets:0,BLEStop:0,BLERunning:1,BLERunningScan:1,BLELoopCount:2975,BLEOpCount:0
17:15:39.867	M32: Kick off readOneSensor
17:15:39.869	M32: Kick off tele sending
17:15:40.535	M32: A4C138B33A3D: Frame 146, last 146
17:15:40.535	M32: A4C138B33A3D: ATC:pvvx at slot 1
17:15:40.943	BLE: scans:15,advertisements:5052,devices:9,resets:0,BLEStop:0,BLERunning:1,BLERunningScan:1,BLELoopCount:2985,BLEOpCount:0
17:15:40.943	RSL: SENSOR = {"Time":"2025-12-27T17:15:39","ATCfa90c2":{"mac":"a4c138fa90c2","Temperature":15.6,"Humidity":48.9,"DewPoint":4.9,"HeatIndex":14.5,"Btn":0,"Battery":100,"RSSI":-76},"ATCb33a3d":{"mac":"a4c138b33a3d","Temperature":21.1,"Humidity":51.8,"DewPoint":10.8,"HeatIndex":20.6,"Btn":0,"Battery":90,"RSSI":-74},"TempUnit":"C"}
17:15:40.943	M32: genericSensorReadFn slot 0 res -1
17:15:40.943	M32: genericSensorReadFn slot 1 res -1
17:15:40.943	M32: Got a newOperation
17:15:40.943	M32: MI s:2 op:{"BLEOperation":{"opid":"0","stat":"0","state":"IDLE","MAC":"A4C138C7A601","u":"84213762","svc":"ebe0ccb0-7a0a-4b0c-8a1a-6ff2997da3a6","notifychar":"ebe0ccc1-7a0a-4b0c-8a1a-6ff2997da3a6"}}
17:15:40.943	M32: genericSensorReadFn slot 2 res 1
17:15:40.943	M32: readOneSensor reading for slot 2 res 1
17:15:41.040	BLE: BLETask: new currentOperation
17:15:41.040	BLE: BLETask: attempt connect A4:C1:38:C7:A6:01
17:15:41.867	BLE: scans:15,advertisements:5054,devices:9,resets:0,BLEStop:0,BLERunning:1,BLERunningScan:1,BLELoopCount:2987,BLEOpCount:1
17:15:41.867	RSL: SENSOR = {"Time":"2025-12-27T17:15:40","LYWSD03c7a601":{"mac":"a4c138c7a601","RSSI":-88},"LYWSD03f84f90":{"mac":"a4c138f84f90","RSSI":-95}}
17:15:41.868	M32: readOneSensor - already active reading 2
17:15:42.828	BLE: scans:15,advertisements:5054,devices:9,resets:0,BLEStop:0,BLERunning:1,BLERunningScan:1,BLELoopCount:2987,BLEOpCount:1
17:15:42.828	M32: readOneSensor - already active reading 2
17:15:43.838	BLE: scans:15,advertisements:5054,devices:9,resets:0,BLEStop:0,BLERunning:1,BLERunningScan:1,BLELoopCount:2987,BLEOpCount:1
17:15:43.840	M32: readOneSensor - already active reading 2
17:15:44.827	BLE: scans:15,advertisements:5054,devices:9,resets:0,BLEStop:0,BLERunning:1,BLERunningScan:1,BLELoopCount:2987,BLEOpCount:1
17:15:44.827	M32: readOneSensor - already active reading 2
17:15:45.856	BLE: scans:15,advertisements:5054,devices:9,resets:0,BLEStop:0,BLERunning:1,BLERunningScan:1,BLELoopCount:2987,BLEOpCount:1
17:15:45.856	M32: readOneSensor - already active reading 2
17:15:46.818	BLE: scans:15,advertisements:5054,devices:9,resets:0,BLEStop:0,BLERunning:1,BLERunningScan:1,BLELoopCount:2987,BLEOpCount:1
17:15:46.818	M32: readOneSensor - already active reading 2
17:15:47.813	BLE: scans:15,advertisements:5054,devices:9,resets:0,BLEStop:0,BLERunning:1,BLERunningScan:1,BLELoopCount:2987,BLEOpCount:1
17:15:47.828	M32: readOneSensor - already active reading 2
17:15:48.817	BLE: scans:15,advertisements:5054,devices:9,resets:0,BLEStop:0,BLERunning:1,BLERunningScan:1,BLELoopCount:2987,BLEOpCount:1
17:15:48.817	M32: readOneSensor - already active reading 2
17:15:49.852	BLE: scans:15,advertisements:5054,devices:9,resets:0,BLEStop:0,BLERunning:1,BLERunningScan:1,BLELoopCount:2987,BLEOpCount:1
17:15:49.852	M32: readOneSensor - already active reading 2
17:15:50.903	RSL: STATE = {"Time":"2025-12-27T17:15:49","Uptime":"0T00:05:20","UptimeSec":320,"Heap":74,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":19,"MqttCount":0,"Berry":{"HeapUsed":3,"Objects":42},"Wifi":{"AP":1,"SSId":"Metropole-F","BSSId":"CC:CE:1E:2D:6D:49","Channel":1,"Mode":"HT40","RSSI":58,"Signal":-71,"LinkCount":1,"Downtime":"0T00:00:06"},"Hostname":"tasmota-EEF56C-5484","IPAddress":"10.7.2.179"}
17:15:50.905	BLE: scans:15,advertisements:5054,devices:9,resets:0,BLEStop:0,BLERunning:1,BLERunningScan:1,BLELoopCount:2987,BLEOpCount:1
17:15:50.907	RSL: BLE = {"Time":"2025-12-27T17:15:49","BLEDevices":{"total":9,"58B03E5BA7D8":{"i":0,"r":-93},"94E6BAC45883":{"i":1,"r":-84},"58B03EEFE847":{"i":2,"r":-98},"A4C138FA90C2":{"i":3,"r":-76},"52579C455DF8":{"i":4,"r":-97},"A4C138B33A3D":{"i":5,"r":-74},"98063CEE1011":{"i":6,"r":-100},"A4C138C7A601":{"i":7,"r":-88},"A4C138F84F90":{"i":8,"r":-95}}}
17:15:50.910	RSL: BLE = {"Time":"2025-12-27T17:15:49","BLE":{"scans":15,"adverts":5054,"devices":9,"resets":0}}
17:15:50.912	M32: readOneSensor - already active reading 2
17:15:51.619	BLE: onDisconnect A4:C1:38:C7:A6:01
17:15:51.619	BLE: A4C138C7A601: Failed to connect to device low level rc 0x23E
17:15:51.619	BLE: A4C138C7A601: Failed to connect to device
17:15:51.768	BLE: BLETask: op failed -11
17:15:51.768	BLE: runTaskDoneOperation: add to completedOperations
17:15:51.869	BLE: scans:15,advertisements:5054,devices:9,resets:0,BLEStop:0,BLERunning:1,BLERunningScan:1,BLELoopCount:2988,BLEOpCount:1
17:15:51.869	BLE: op->completecallback is 1074940108 opid 0
17:15:51.871	M32: MI op complete context 5050002
17:15:51.873	M32: A4C138C7A601: Operation failed -11
17:15:51.876	BLE: op->completecallback 0 opid 0
17:15:51.876	BLE: some to show
17:15:51.876	BLE: completed 1
17:15:51.876	BLE: mqttOperation removed opid 0
17:15:51.876	RSL: BLE = {"BLEOperation":{"opid":"0","stat":"-11","state":"FAILCONNECT","MAC":"A4C138C7A601","u":"84213762","svc":"ebe0ccb0-7a0a-4b0c-8a1a-6ff2997da3a6","notifychar":"ebe0ccc1-7a0a-4b0c-8a1a-6ff2997da3a6"}}
17:15:51.876	M32: Got a newOperation
17:15:51.876	M32: MI s:3 op:{"BLEOperation":{"opid":"0","stat":"0","state":"IDLE","MAC":"A4C138F84F90","u":"84213763","svc":"ebe0ccb0-7a0a-4b0c-8a1a-6ff2997da3a6","notifychar":"ebe0ccc1-7a0a-4b0c-8a1a-6ff2997da3a6"}}
17:15:51.876	M32: genericSensorReadFn slot 3 res 1
17:15:51.876	M32: readOneSensor reading for slot 3 res 1
17:15:52.005	BLE: BLETask: new currentOperation
17:15:52.007	BLE: BLETask: attempt connect A4:C1:38:F8:4F:90
17:15:52.848	BLE: scans:15,advertisements:5054,devices:9,resets:0,BLEStop:0,BLERunning:1,BLERunningScan:1,BLELoopCount:2990,BLEOpCount:2
17:15:52.856	M32: readOneSensor - already active reading 3
17:15:53.855	BLE: scans:15,advertisements:5054,devices:9,resets:0,BLEStop:0,BLERunning:1,BLERunningScan:1,BLELoopCount:2990,BLEOpCount:2
17:15:53.855	M32: readOneSensor - already active reading 3
17:15:54.864	BLE: scans:15,advertisements:5054,devices:9,resets:0,BLEStop:0,BLERunning:1,BLERunningScan:1,BLELoopCount:2990,BLEOpCount:2
17:15:54.864	M32: readOneSensor - already active reading 3
17:15:55.829	BLE: scans:15,advertisements:5054,devices:9,resets:0,BLEStop:0,BLERunning:1,BLERunningScan:1,BLELoopCount:2990,BLEOpCount:2
17:15:55.829	M32: readOneSensor - already active reading 3
17:15:56.826	BLE: scans:15,advertisements:5054,devices:9,resets:0,BLEStop:0,BLERunning:1,BLERunningScan:1,BLELoopCount:2990,BLEOpCount:2
17:15:56.826	M32: readOneSensor - already active reading 3
17:15:57.829	BLE: scans:15,advertisements:5054,devices:9,resets:0,BLEStop:0,BLERunning:1,BLERunningScan:1,BLELoopCount:2990,BLEOpCount:2
17:15:57.829	M32: readOneSensor - already active reading 3
17:15:58.856	BLE: scans:15,advertisements:5054,devices:9,resets:0,BLEStop:0,BLERunning:1,BLERunningScan:1,BLELoopCount:2990,BLEOpCount:2
17:15:58.856	EQ3: poll cycle starting
17:15:58.856	M32: readOneSensor - already active reading 3
17:15:59.883	BLE: scans:15,advertisements:5054,devices:9,resets:0,BLEStop:0,BLERunning:1,BLERunningScan:1,BLELoopCount:2990,BLEOpCount:2
17:15:59.883	M32: readOneSensor - already active reading 3
17:16:00.847	BLE: scans:15,advertisements:5054,devices:9,resets:0,BLEStop:0,BLERunning:1,BLERunningScan:1,BLELoopCount:2990,BLEOpCount:2
17:16:00.847	M32: readOneSensor - already active reading 3
17:16:01.858	BLE: scans:15,advertisements:5054,devices:9,resets:0,BLEStop:0,BLERunning:1,BLERunningScan:1,BLELoopCount:2990,BLEOpCount:2
17:16:01.858	M32: readOneSensor - already active reading 3
17:16:02.859	BLE: scans:15,advertisements:5054,devices:9,resets:0,BLEStop:0,BLERunning:1,BLERunningScan:1,BLELoopCount:2990,BLEOpCount:2
17:16:02.861	M32: readOneSensor - already active reading 3
17:16:03.883	BLE: scans:15,advertisements:5054,devices:9,resets:0,BLEStop:0,BLERunning:1,BLERunningScan:1,BLELoopCount:2990,BLEOpCount:2
17:16:03.883	M32: readOneSensor - already active reading 3
17:16:04.841	BLE: scans:15,advertisements:5054,devices:9,resets:0,BLEStop:0,BLERunning:1,BLERunningScan:1,BLELoopCount:2990,BLEOpCount:2
17:16:04.850	M32: readOneSensor - already active reading 3
17:16:05.845	BLE: scans:15,advertisements:5054,devices:9,resets:0,BLEStop:0,BLERunning:1,BLERunningScan:1,BLELoopCount:2990,BLEOpCount:2
17:16:05.845	M32: readOneSensor - already active reading 3
17:16:06.853	BLE: scans:15,advertisements:5054,devices:9,resets:0,BLEStop:0,BLERunning:1,BLERunningScan:1,BLELoopCount:2990,BLEOpCount:2
17:16:06.853	M32: readOneSensor - already active reading 3
17:16:07.871	BLE: scans:15,advertisements:5054,devices:9,resets:0,BLEStop:0,BLERunning:1,BLERunningScan:1,BLELoopCount:2990,BLEOpCount:2
17:16:07.871	M32: readOneSensor - already active reading 3
17:16:08.898	BLE: scans:15,advertisements:5054,devices:9,resets:0,BLEStop:0,BLERunning:1,BLERunningScan:1,BLELoopCount:2990,BLEOpCount:2
17:16:08.898	M32: readOneSensor - already active reading 3
17:16:09.869	BLE: scans:15,advertisements:5054,devices:9,resets:0,BLEStop:0,BLERunning:1,BLERunningScan:1,BLELoopCount:2990,BLEOpCount:2
17:16:09.873	M32: readOneSensor - already active reading 3
17:16:10.871	BLE: scans:15,advertisements:5054,devices:9,resets:0,BLEStop:0,BLERunning:1,BLERunningScan:1,BLELoopCount:2990,BLEOpCount:2
17:16:10.871	M32: readOneSensor - already active reading 3
17:16:11.872	BLE: scans:15,advertisements:5054,devices:9,resets:0,BLEStop:0,BLERunning:1,BLERunningScan:1,BLELoopCount:2990,BLEOpCount:2
17:16:11.875	M32: readOneSensor - already active reading 3
17:16:12.893	BLE: scans:15,advertisements:5054,devices:9,resets:0,BLEStop:0,BLERunning:1,BLERunningScan:1,BLELoopCount:2990,BLEOpCount:2
17:16:12.893	M32: readOneSensor - already active reading 3
17:16:13.865	BLE: scans:15,advertisements:5054,devices:9,resets:0,BLEStop:0,BLERunning:1,BLERunningScan:1,BLELoopCount:2990,BLEOpCount:2
17:16:13.866	M32: readOneSensor - already active reading 3
17:16:14.848	BLE: scans:15,advertisements:5054,devices:9,resets:0,BLEStop:0,BLERunning:1,BLERunningScan:1,BLELoopCount:2990,BLEOpCount:2
17:16:14.864	M32: readOneSensor - already active reading 3
17:16:15.865	BLE: scans:15,advertisements:5054,devices:9,resets:0,BLEStop:0,BLERunning:1,BLERunningScan:1,BLELoopCount:2990,BLEOpCount:2
17:16:15.868	M32: readOneSensor - already active reading 3
17:16:16.891	BLE: scans:15,advertisements:5054,devices:9,resets:0,BLEStop:0,BLERunning:1,BLERunningScan:1,BLELoopCount:2990,BLEOpCount:2
17:16:16.891	M32: readOneSensor - already active reading 3
17:16:17.908	BLE: scans:15,advertisements:5054,devices:9,resets:0,BLEStop:0,BLERunning:1,BLERunningScan:1,BLELoopCount:2990,BLEOpCount:2
17:16:17.908	M32: readOneSensor - already active reading 3
17:16:18.864	BLE: scans:15,advertisements:5054,devices:9,resets:0,BLEStop:0,BLERunning:1,BLERunningScan:1,BLELoopCount:2990,BLEOpCount:2
17:16:18.867	M32: readOneSensor - already active reading 3
17:16:19.854	BLE: scans:15,advertisements:5054,devices:9,resets:0,BLEStop:0,BLERunning:1,BLERunningScan:1,BLELoopCount:2990,BLEOpCount:2
17:16:19.854	M32: readOneSensor - already active reading 3
17:16:20.882	BLE: scans:15,advertisements:5054,devices:9,resets:0,BLEStop:0,BLERunning:1,BLERunningScan:1,BLELoopCount:2990,BLEOpCount:2
17:16:20.882	M32: readOneSensor - already active reading 3
17:16:21.847	BLE: scans:15,advertisements:5054,devices:9,resets:0,BLEStop:0,BLERunning:1,BLERunningScan:1,BLELoopCount:2990,BLEOpCount:2
17:16:21.851	M32: readOneSensor - already active reading 3
17:16:21.980	BLE: A4C138F84F90: Failed to connect to device low level rc 0xD
17:16:21.984	BLE: A4C138F84F90: Failed to connect to device
17:16:22.083	BLE: BLETask: op failed -11
17:16:22.086	BLE: runTaskDoneOperation: add to completedOperations
17:16:22.876	BLE: scans:15,advertisements:5054,devices:9,resets:0,BLEStop:0,BLERunning:1,BLERunningScan:1,BLELoopCount:2998,BLEOpCount:2
17:16:22.876	BLE: op->completecallback is 1074940108 opid 1
17:16:22.876	M32: MI op complete context 5050003
17:16:22.895	M32: A4C138F84F90: Operation failed -11
17:16:22.895	BLE: op->completecallback 0 opid 1
17:16:22.895	BLE: some to show
17:16:22.895	BLE: completed 1
17:16:22.895	BLE: mqttOperation removed opid 1
17:16:22.895	RSL: BLE = {"BLEOperation":{"opid":"1","stat":"-11","state":"FAILCONNECT","MAC":"A4C138F84F90","u":"84213763","svc":"ebe0ccb0-7a0a-4b0c-8a1a-6ff2997da3a6","notifychar":"ebe0ccc1-7a0a-4b0c-8a1a-6ff2997da3a6"}}
17:16:23.870	BLE: scans:15,advertisements:5054,devices:9,resets:0,BLEStop:0,BLERunning:1,BLERunningScan:1,BLELoopCount:3008,BLEOpCount:2
17:16:24.868	BLE: scans:15,advertisements:5054,devices:9,resets:0,BLEStop:0,BLERunning:1,BLERunningScan:1,BLELoopCount:3018,BLEOpCount:2
17:16:25.871	BLE: scans:15,advertisements:5054,devices:9,resets:0,BLEStop:0,BLERunning:1,BLERunningScan:1,BLELoopCount:3028,BLEOpCount:217:17:50.490	BLE: scans:15,advertisements:5054,devices:9,resets:0,BLEStop:0,BLERunning:1,BLERunningScan:1,BLELoopCount:3865,BLEOpCount:2
17:17:51.485	BLE: scans:15,advertisements:5054,devices:9,resets:0,BLEStop:0,BLERunning:1,BLERunningScan:1,BLELoopCount:3875,BLEOpCount:2
17:17:52.488	BLE: scans:15,advertisements:5054,devices:9,resets:0,BLEStop:0,BLERunning:1,BLERunningScan:1,BLELoopCount:3885,BLEOpCount:2
17:17:52.500	BLE: scan stall? no adverts > 120s, restart BLE
17:17:52.526	BLE: BLETask: Restart NimBLE - restart Tasmota in 10 if not complt
17:17:52.533	BLE: Task:Stopping NimBLE
17:17:52.533	BLE: deleted client
17:17:52.899	BLE: BLETask:Starting NimBLE
17:17:53.043	BLE: BLETask: Startscan
17:17:53.043	M32: A4C138B33A3D: Frame 160, last 146
17:17:53.043	M32: A4C138B33A3D: ATC:pvvx at slot 1
17:17:53.541	BLE: scans:15,advertisements:5062,devices:9,resets:1,BLEStop:0,BLERunning:1,BLERunningScan:1,BLELoopCount:3891,BLEOpCount:2
17:17:53.541	RSL: BLE = {"blerestart":"no adverts in 120s"}
17:17:53.541	BLE: Failure! Restarting BLE Stack because no adverts in 120s
17:17:54.505	BLE: scans:15,advertisements:5079,devices:9,resets:1,BLEStop:0,BLERunning:1,BLERunningScan:1,BLELoopCount:3901,BLEOpCount:2
17:17:55.490	BLE: scans:15,advertisements:5101,devices:9,resets:1,BLEStop:0,BLERunning:1,BLERunningScan:1,BLELoopCount:3911,BLEOpCount:2
17:17:56.524	BLE: scans:15,advertisements:5115,devices:9,resets:1,BLEStop:0,BLERunning:1,BLERunningScan:1,BLELoopCount:3921,BLEOpCount:2

TO REPRODUCE

Steps to reproduce the behavior:

  • Run the latest bluetooth dev
  • Wait until a driver issues a BLE operation
  • See a BLE restart after 120 sec

EXPECTED BEHAVIOUR

Advertisements should be received continuously even after a BLE operation

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions