Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Sometimes when stopping advertisement it still advertises and hangs process #5

Open
Apollon77 opened this issue Jan 1, 2025 · 0 comments
Open

Sometimes when stopping advertisement it still advertises and hangs process #5

Apollon77 opened this issue Jan 1, 2025 · 0 comments

Comments

@Apollon77
Copy link
Collaborator

I m using Bleno in matter.js and the onoff-advanced" example uses Bleno to support Device commissioning with BLE.

When the device is stopped I call "Bleno.disconnect()" but then sometimes the process still "hangs" and does not stop. I need to kill manually.

Versions:
matter.js-monorepo@ /home/ingof/official-matter.js
└─┬ @matter/[email protected] -> ./packages/nodejs-ble
├─┬ @stoprocent/[email protected]
│ └── @stoprocent/[email protected]
└─┬ @stoprocent/[email protected]
└── @stoprocent/[email protected]

(do not ask me why npm installs different hci-socket versions)

Log then shows:

2025-01-01 15:52:33.523 DEBUG  BlenoBleServer       advertisingStart: success
  gatt handles = [
  gatt   {},
  gatt   {
  gatt     "type": "service",
  gatt     "uuid": "1800",
  gatt     "startHandle": 1,
  gatt     "endHandle": 5
  gatt   },
  gatt   {
  gatt     "type": "characteristic",
  gatt     "uuid": "2a00",
  gatt     "properties": 2,
  gatt     "secure": 0,
  gatt     "startHandle": 2,
  gatt     "valueHandle": 3
  gatt   },
  gatt   {
  gatt     "type": "characteristicValue",
  gatt     "handle": 3,
  gatt     "value": "Buffer('4d6174746572207465737420646576696365', 'hex')"
  gatt   },
  gatt   {
  gatt     "type": "characteristic",
  gatt     "uuid": "2a01",
  gatt     "properties": 2,
  gatt     "secure": 0,
  gatt     "startHandle": 4,
  gatt     "valueHandle": 5
  gatt   },
  gatt   {
  gatt     "type": "characteristicValue",
  gatt     "handle": 5,
  gatt     "value": "Buffer('8000', 'hex')"
  gatt   },
  gatt   {
  gatt     "type": "service",
  gatt     "uuid": "1801",
  gatt     "startHandle": 6,
  gatt     "endHandle": 9
  gatt   },
  gatt   {
  gatt     "type": "characteristic",
  gatt     "uuid": "2a05",
  gatt     "properties": 32,
  gatt     "secure": 0,
  gatt     "startHandle": 7,
  gatt     "valueHandle": 8
  gatt   },
  gatt   {
  gatt     "type": "characteristicValue",
  gatt     "handle": 8,
  gatt     "value": "Buffer('00000000', 'hex')"
  gatt   },
  gatt   {
  gatt     "type": "descriptor",
  gatt     "handle": 9,
  gatt     "uuid": "2902",
  gatt     "properties": 14,
  gatt     "secure": 0,
  gatt     "value": "Buffer('0000', 'hex')"
  gatt   },
  gatt   {
  gatt     "type": "service",
  gatt     "uuid": "fff6",
  gatt     "startHandle": 10,
  gatt     "endHandle": 17
  gatt   },
  gatt   {
  gatt     "type": "characteristic",
  gatt     "uuid": "18EE2EF5263D4559959F4F9C429F9D11",
  gatt     "properties": 8,
  gatt     "secure": 0,
  gatt     "startHandle": 11,
  gatt     "valueHandle": 12
  gatt   },
  gatt   {
  gatt     "type": "characteristicValue",
  gatt     "handle": 12,
  gatt     "value": null
  gatt   },
  gatt   {
  gatt     "type": "characteristic",
  gatt     "uuid": "18EE2EF5263D4559959F4F9C429F9D12",
  gatt     "properties": 32,
  gatt     "secure": 0,
  gatt     "startHandle": 13,
  gatt     "valueHandle": 14
  gatt   },
  gatt   {
  gatt     "type": "characteristicValue",
  gatt     "handle": 14,
  gatt     "value": null
  gatt   },
  gatt   {
  gatt     "type": "descriptor",
  gatt     "handle": 15,
  gatt     "uuid": "2902",
  gatt     "properties": 14,
  gatt     "secure": 0,
  gatt     "value": "Buffer('0000', 'hex')"
  gatt   },
  gatt   {
  gatt     "type": "characteristic",
  gatt     "uuid": "64630238877245F2B87D748A83218F04",
  gatt     "properties": 2,
  gatt     "secure": 0,
  gatt     "startHandle": 16,
  gatt     "valueHandle": 17
  gatt   },
  gatt   {
  gatt     "type": "characteristicValue",
  gatt     "handle": 17,
  gatt     "value": null
  gatt   }
  gatt ] +60s
  bleno servicesSet +3ms
2025-01-01 15:52:33.526 DEBUG  BlenoBleServer       servicesSet: success
  hci onSocketData: 040e0401092000 +4ms
  hci 	event type = 4 +0ms
  hci 	sub event type = 14 +0ms
  hci 		ncmd = 1 +0ms
  hci 		cmd = 8201 +0ms
  hci 		status = 0 +0ms
  hci 		result =  +0ms
  hci onSocketData: 040e0401082000 +0ms
  hci 	event type = 4 +0ms
  hci 	sub event type = 14 +1ms
  hci 		ncmd = 1 +0ms
  hci 		cmd = 8200 +0ms
  hci 		status = 0 +0ms
  hci 		result =  +0ms
2025-01-01 15:52:51.902 DEBUG  MdnsScanner          Adding operational device 689A73D614F8AE99-00000000D24ED231._matter._tcp.local in cache (interface wlan0, ttl=4500) with TXT data: T: 0 ICD: 0
2025-01-01 15:52:52.512 DEBUG  MdnsScanner          Added IPs for operational device A9F43BC071B7A9C2-E52BB762CBAF409F._matter._tcp.local to cache (interface wlan0): type: udp ip: 192.168.178.127 port: 5540 type: udp ip: 2a02:8071:2c87:399c:21f:eeff:fe00:156d port: 5540 type: udp ip: fd00::21f:eeff:fe00:156d port: 5540
2025-01-01 15:52:52.618 DEBUG  MdnsScanner          Added IPs for operational device A9F43BC071B7A9C2-09D3274E3B734737._matter._tcp.local to cache (interface wlan0): type: udp ip: fddc:3d12:3702:1:4282:3432:81b1:2017 port: 5540
  hci set advertise enable - writing: 010a200100 +60s
  hci onSocketData: 040e04010a2000 +2ms
  hci 	event type = 4 +0ms
  hci 	sub event type = 14 +0ms
  hci 		ncmd = 1 +0ms
  hci 		cmd = 8202 +0ms
  hci 		status = 0 +1ms
  hci 		result =  +0ms
  bleno advertisingStop +60s
2025-01-01 15:53:33.515 DEBUG  BlenoBleServer       advertisingStop
  gap startAdvertisingWithEIRData: advertisement data = 0201060b16f6ff00000ff1ff008000, scan data =  +60s
  hci set scan response data - writing: 010920200000000000000000000000000000000000000000000000000000000000000000 +2ms
  hci set advertisement data - writing: 010820200f0201060b16f6ff00000ff1ff00800000000000000000000000000000000000 +0ms
  hci set advertise enable - writing: 010a200101 +1ms
  hci set scan response data - writing: 010920200000000000000000000000000000000000000000000000000000000000000000 +0ms
  hci set advertisement data - writing: 010820200f0201060b16f6ff00000ff1ff00800000000000000000000000000000000000 +1ms
  hci onSocketData: 040e0401092000 +0ms
  hci 	event type = 4 +0ms
  hci 	sub event type = 14 +1ms
  hci 		ncmd = 1 +0ms
  hci 		cmd = 8201 +0ms
  hci 		status = 0 +0ms
  hci 		result =  +0ms
  hci onSocketData: 040e0401082000 +1ms
  hci 	event type = 4 +0ms
  hci 	sub event type = 14 +0ms
  hci 		ncmd = 1 +0ms
  hci 		cmd = 8200 +1ms
  hci 		status = 0 +0ms
  hci 		result =  +0ms
  hci onSocketData: 040e04010a2000 +0ms
  hci 	event type = 4 +1ms
  hci 	sub event type = 14 +0ms
  hci 		ncmd = 1 +0ms
  hci 		cmd = 8202 +0ms
  hci 		status = 0 +0ms
  hci 		result =  +0ms
  bleno advertisingStart: null +8ms
2025-01-01 15:53:33.524 DEBUG  BlenoBleServer       advertisingStart: success
  gatt handles = [
  gatt   {},
  gatt   {
  gatt     "type": "service",
  gatt     "uuid": "1800",
  gatt     "startHandle": 1,
  gatt     "endHandle": 5
  gatt   },
  gatt   {
  gatt     "type": "characteristic",
  gatt     "uuid": "2a00",
  gatt     "properties": 2,
  gatt     "secure": 0,
  gatt     "startHandle": 2,
  gatt     "valueHandle": 3
  gatt   },
  gatt   {
  gatt     "type": "characteristicValue",
  gatt     "handle": 3,
  gatt     "value": "Buffer('4d6174746572207465737420646576696365', 'hex')"
  gatt   },
  gatt   {
  gatt     "type": "characteristic",
  gatt     "uuid": "2a01",
  gatt     "properties": 2,
  gatt     "secure": 0,
  gatt     "startHandle": 4,
  gatt     "valueHandle": 5
  gatt   },
  gatt   {
  gatt     "type": "characteristicValue",
  gatt     "handle": 5,
  gatt     "value": "Buffer('8000', 'hex')"
  gatt   },
  gatt   {
  gatt     "type": "service",
  gatt     "uuid": "1801",
  gatt     "startHandle": 6,
  gatt     "endHandle": 9
  gatt   },
  gatt   {
  gatt     "type": "characteristic",
  gatt     "uuid": "2a05",
  gatt     "properties": 32,
  gatt     "secure": 0,
  gatt     "startHandle": 7,
  gatt     "valueHandle": 8
  gatt   },
  gatt   {
  gatt     "type": "characteristicValue",
  gatt     "handle": 8,
  gatt     "value": "Buffer('00000000', 'hex')"
  gatt   },
  gatt   {
  gatt     "type": "descriptor",
  gatt     "handle": 9,
  gatt     "uuid": "2902",
  gatt     "properties": 14,
  gatt     "secure": 0,
  gatt     "value": "Buffer('0000', 'hex')"
  gatt   },
  gatt   {
  gatt     "type": "service",
  gatt     "uuid": "fff6",
  gatt     "startHandle": 10,
  gatt     "endHandle": 17
  gatt   },
  gatt   {
  gatt     "type": "characteristic",
  gatt     "uuid": "18EE2EF5263D4559959F4F9C429F9D11",
  gatt     "properties": 8,
  gatt     "secure": 0,
  gatt     "startHandle": 11,
  gatt     "valueHandle": 12
  gatt   },
  gatt   {
  gatt     "type": "characteristicValue",
  gatt     "handle": 12,
  gatt     "value": null
  gatt   },
  gatt   {
  gatt     "type": "characteristic",
  gatt     "uuid": "18EE2EF5263D4559959F4F9C429F9D12",
  gatt     "properties": 32,
  gatt     "secure": 0,
  gatt     "startHandle": 13,
  gatt     "valueHandle": 14
  gatt   },
  gatt   {
  gatt     "type": "characteristicValue",
  gatt     "handle": 14,
  gatt     "value": null
  gatt   },
  gatt   {
  gatt     "type": "descriptor",
  gatt     "handle": 15,
  gatt     "uuid": "2902",
  gatt     "properties": 14,
  gatt     "secure": 0,
  gatt     "value": "Buffer('0000', 'hex')"
  gatt   },
  gatt   {
  gatt     "type": "characteristic",
  gatt     "uuid": "64630238877245F2B87D748A83218F04",
  gatt     "properties": 2,
  gatt     "secure": 0,
  gatt     "startHandle": 16,
  gatt     "valueHandle": 17
  gatt   },
  gatt   {
  gatt     "type": "characteristicValue",
  gatt     "handle": 17,
  gatt     "value": null
  gatt   }
  gatt ] +60s
  bleno servicesSet +2ms
2025-01-01 15:53:33.526 DEBUG  BlenoBleServer       servicesSet: success
  hci onSocketData: 040e0401092000 +3ms
  hci 	event type = 4 +0ms
  hci 	sub event type = 14 +1ms
  hci 		ncmd = 1 +0ms
  hci 		cmd = 8201 +0ms
  hci 		status = 0 +0ms
  hci 		result =  +0ms
  hci onSocketData: 040e0401082000 +0ms
  hci 	event type = 4 +0ms
  hci 	sub event type = 14 +0ms
  hci 		ncmd = 1 +0ms
  hci 		cmd = 8200 +0ms
  hci 		status = 0 +1ms
  hci 		result =  +0ms



====>>>> Here the stop should happen
^C2025-01-01 15:54:10.844 NOTICE Runtime              Shutting down
2025-01-01 15:54:10.855 NOTICE Node                 1735741330373 going offline
2025-01-01 15:54:10.856 DEBUG  OccurrenceManager    Recorded event #3003: {"eventId":1,"clusterId":40,"endpointId":0,"epochTimestamp":1735743250856,"priority":2,"payload":"undefined"}
2025-01-01 15:54:10.858 DEBUG  Transaction          Transaction offline#18 locked 1735741330373.generalDiagnostics.state
2025-01-01 15:54:10.864 DEBUG  Transaction          Transaction offline#18 committed and unlocked 1 resource
2025-01-01 15:54:10.866 DEBUG  DeviceCommissioner   Commissioning mode ended, stop announcements.
  hci set advertise enable - writing: 010a200100 +37s
  hci onSocketData: 040e04010a2000 +2ms
  hci 	event type = 4 +0ms
  hci 	sub event type = 14 +0ms
  hci 		ncmd = 1 +0ms
  hci 		cmd = 8202 +0ms
  hci 		status = 0 +0ms
  hci 		result =  +0ms
  bleno advertisingStop +37s
2025-01-01 15:54:10.869 DEBUG  BlenoBleServer       advertisingStop
2025-01-01 15:54:10.870 INFO   DeviceCommissioner   All announcements stopped
  bleno disconnect +5ms
  bleno disconnect +2ms
2025-01-01 15:54:10.878 NOTICE Node                 1735741330373 is offline
Server is offline
2025-01-01 15:54:10.889 DEBUG  Transaction          Transaction reactor<1735741330373.descriptor.#updatePartsList>#1e waiting on reactor<1735741330373.descriptor.#updatePartsList>#1d
2025-01-01 15:54:10.890 DEBUG  Transaction          Transaction reactor<1735741330373.descriptor.#updatePartsList>#1d locked 1735741330373.descriptor.state
2025-01-01 15:54:10.892 DEBUG  Transaction          Transaction reactor<1735741330373.descriptor.#updatePartsList>#1d committed and unlocked 1 resource
2025-01-01 15:54:10.893 DEBUG  Transaction          Transaction reactor<1735741330373.descriptor.#updatePartsList>#1e locked 1735741330373.descriptor.state
2025-01-01 15:54:10.894 DEBUG  Transaction          Transaction reactor<1735741330373.descriptor.#updatePartsList>#1e committed and unlocked 1 resource
2025-01-01 15:54:10.905 INFO   ServerNodeStore      Closed 1735741330373 storage at .device-14wifi/1735741330373
  hci set advertise enable - writing: 010a200100 +38ms

The code does basically when stopping

Bleno.stopAdvertising(); // corresponds to log "BlenoBleServer       advertisingStop"
Bleno.disconnect()

As you see Bleno is also disconnecting (whyever it is logged twice) ... but after this it still logs an advertise enable ...

PS: It would halp a lot to understand deps when the package.json published in github would be in sync with current version ... for all 3 projects (chi.socket, bleno and noble)the package.json is highly outdated at least from a version perspective
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
1 participant
@Apollon77