Skip to content

nimble loss of pairing on heavily used device #370

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
Closed
geeksville opened this issue Sep 8, 2020 · 2 comments
Closed

nimble loss of pairing on heavily used device #370

geeksville opened this issue Sep 8, 2020 · 2 comments
Assignees
@geeksville
Labels
bug Something isn't working

Comments

@geeksville
Copy link
Member

seems to have wrong nimble version - causing bogus re-pairing messages.

Shutdown BT: 234464 heap size
wakeCause 4
Trigger powerFSM 2
Transition powerFSM transition=Wake timer, from=LS to=DARK
Looking for GPS lock
Setting bluetooth enable=1
Pre BT: 234464 heap size
Starting bluetooth
GPS fix type 0
Ignoring invalid GPS month=0, year=1336, unixtime=1297431932
Update DB node 0xabdddf38, rx_time=0
Node status update: 6 online, 7 total
BLE task running
registered service 0x1800 with handle=1
registered service 0x1801 with handle=6
registered service 6ba1b218-15a8-461f-9fa8-5dcae273eafd with handle=10
registered service cb0b9a0b-a84c-4c0d-bdbb-442e3144ee30 with handle=18
failed to configure restored IRK
BLE advertisting type=0, Private=0, Device Address: 39:24:62:ab:dd:df

connection established; status=0 handle=0 our_ota_addr_type=0 our_ota_addr=00:24:62:ab:dd:df
 our_id_addr_type=0 our_id_addr=00:24:62:ab:dd:df
 peer_ota_addr_type=0 peer_ota_addr=00:4e:70:ba:7f:ad
 peer_id_addr_type=0 peer_id_addr=00:7c:d9:5c:ba:2e
 conn_itvl=36 conn_latency=0 supervision_timeout=500 encrypted=0 authenticated=0 bonded=0

encryption change event; status=0 handle=0 our_ota_addr_type=0 our_ota_addr=00:24:62:ab:dd:df
 our_id_addr_type=0 our_id_addr=00:24:62:ab:dd:df
 peer_ota_addr_type=0 peer_ota_addr=00:4e:70:ba:7f:ad
 peer_id_addr_type=0 peer_id_addr=00:7c:d9:5c:ba:2e
 conn_itvl=36 conn_latency=0 supervision_timeout=500 encrypted=1 authenticated=1 bonded=1

connection updated; status=0 handle=0 our_ota_addr_type=0 our_ota_addr=00:24:62:ab:dd:df
 our_id_addr_type=0 our_id_addr=00:24:62:ab:dd:df
 peer_ota_addr_type=0 peer_ota_addr=00:4e:70:ba:7f:ad
 peer_id_addr_type=0 peer_id_addr=00:7c:d9:5c:ba:2e
 conn_itvl=6 conn_latency=0 supervision_timeout=500 encrypted=1 authenticated=1 bonded=1

mtu update event; conn_handle=0 cid=4 mtu=512
connection updated; status=0 handle=0 our_ota_addr_type=0 our_ota_addr=00:24:62:ab:dd:df
 our_id_addr_type=0 our_id_addr=00:24:62:ab:dd:df
 peer_ota_addr_type=0 peer_ota_addr=00:4e:70:ba:7f:ad
 peer_id_addr_type=0 peer_id_addr=00:7c:d9:5c:ba:2e
 conn_itvl=36 conn_latency=0 supervision_timeout=500 encrypted=1 authenticated=1 bonded=1

BLE fromRadio called omlen=1, ourlen=0
Trigger powerFSM 9
Transition powerFSM transition=Contact from phone, from=DARK to=DARK
Client wants config, nonce=9
Reset nodeinfo read pointer
subscribe event; conn_handle=0 attr_handle=16 reason=1 prevn=0 curn=1 previ=0 curi=0
getFromRadio, state=2
encoding toPhone packet to phone variant=3, 51 bytes
BLE fromRadio called omlen=1, ourlen=51
getFromRadio, state=3
encoding toPhone packet to phone variant=6, 62 bytes
BLE fromRadio called omlen=1, ourlen=62
getFromRadio, state=4
Sending nodeinfo: num=0xabdddf38, lastseen=315967913, id=!2462abdddf38, name=Bob b
encoding toPhone packet to phone variant=4, 53 bytes
BLE fromRadio called omlen=1, ourlen=53
getFromRadio, state=4
Sending nodeinfo: num=0x28b200b4, lastseen=316593914, id=!246f28b200b4, name=Bob b
encoding toPhone packet to phone variant=4, 58 bytes
BLE fromRadio called omlen=1, ourlen=58
getFromRadio, state=4
Sending nodeinfo: num=0x918af760, lastseen=316497304, id=!5002918af760, name=ryan
encoding toPhone packet to phone variant=4, 56 bytes
BLE fromRadio called omlen=1, ourlen=56
getFromRadio, state=4
Sending nodeinfo: num=0x336ab5e5, lastseen=1597965319, id=!c44f336ab5e5, name=Unknown b5e5
encoding toPhone packet to phone variant=4, 64 bytes
BLE fromRadio called omlen=1, ourlen=64
getFromRadio, state=4
Sending nodeinfo: num=0x918af71c, lastseen=316494981, id=!5002918af71c, name=Unknown f71c
encoding toPhone packet to phone variant=4, 66 bytes
BLE fromRadio called omlen=1, ourlen=66
getFromRadio, state=4
Sending nodeinfo: num=0x4ec5d56, lastseen=0, id=!fd1004ec5d56, name=Unknown 5d56
encoding toPhone packet to phone variant=4, 58 bytes
BLE fromRadio called omlen=1, ourlen=58
getFromRadio, state=4
Sending nodeinfo: num=0xabf84098, lastseen=315966200, id=!2462abf84098, name=Unknown 4098
encoding toPhone packet to phone variant=4, 66 bytes
BLE fromRadio called omlen=1, ourlen=66
getFromRadio, state=4
Done sending nodeinfos
getFromRadio, state=5
encoding toPhone packet to phone variant=8, 2 bytes
BLE fromRadio called omlen=1, ourlen=2
BLE fromRadio called omlen=1, ourlen=0
GPS fix type 0
Ignoring invalid GPS month=0, year=1336, unixtime=1297431922
Update DB node 0xabdddf38, rx_time=0
Node status update: 6 online, 7 total
GPS fix type 0
Ignoring invalid GPS month=0, year=1336, unixtime=1297431932
Update DB node 0xabdddf38, rx_time=0
Node status update: 6 online, 7 total
GPS fix type 0
Ignoring invalid GPS month=0, year=1336, unixtime=1297431921
Update DB node 0xabdddf38, rx_time=0
Node status update: 6 online, 7 total
GPS fix type 0
Ignoring invalid GPS month=0, year=1336, unixtime=1297431932
Update DB node 0xabdddf38, rx_time=0
Node status update: 6 online, 7 total
GPS fix type 0
Ignoring invalid GPS month=0, year=1336, unixtime=1297431932
Update DB node 0xabdddf38, rx_time=0
Node status update: 6 online, 7 total
GPS fix type 0
Ignoring invalid GPS month=0, year=1336, unixtime=1297431932
Update DB node 0xabdddf38, rx_time=0
Node status update: 6 online, 7 total
GPS fix type 0
Ignoring invalid GPS month=0, year=1336, unixtime=1297431932
Update DB node 0xabdddf38, rx_time=0
Node status update: 6 online, 7 total
GPS fix type 0
Ignoring invalid GPS month=0, year=1336, unixtime=1297431932
Update DB node 0xabdddf38, rx_time=0
Node status update: 6 online, 7 total
GPS fix type 0
Ignoring invalid GPS month=0, year=1336, unixtime=1297431932
Update DB node 0xabdddf38, rx_time=0
Node status update: 6 online, 7 total
subscribe event; conn_handle=0 attr_handle=16 reason=2 prevn=1 curn=0 previ=0 curi=0
disconnect; reason=552 handle=0 our_ota_addr_type=0 our_ota_addr=00:24:62:ab:dd:df
 our_id_addr_type=0 our_id_addr=00:24:62:ab:dd:df
 peer_ota_addr_type=0 peer_ota_addr=00:4e:70:ba:7f:ad
 peer_id_addr_type=0 peer_id_addr=00:4e:70:ba:7f:ad
 conn_itvl=36 conn_latency=0 supervision_timeout=500 encrypted=1 authenticated=1 bonded=1

GPS fix type 0
Ignoring invalid GPS month=0, year=1336, unixtime=1297431932
Update DB node 0xabdddf38, rx_time=0
Node status update: 6 online, 7 total
connection established; status=0 handle=0 our_ota_addr_type=0 our_ota_addr=01:24:62:ab:dd:df
 our_id_addr_type=0 our_id_addr=01:24:62:ab:dd:df
 peer_ota_addr_type=1 peer_ota_addr=00:40:db:b7:63:d7
 peer_id_addr_type=1 peer_id_addr=00:40:db:b7:63:d7
 conn_itvl=36 conn_latency=0 supervision_timeout=500 encrypted=0 authenticated=0 bonded=0

GPS fix type 0
Ignoring invalid GPS month=0, year=1336, unixtime=1297431932
Update DB node 0xabdddf38, rx_time=0
Node status update: 6 online, 7 total
connection updated; status=0 handle=0 our_ota_addr_type=0 our_ota_addr=01:24:62:ab:dd:df
 our_id_addr_type=0 our_id_addr=01:24:62:ab:dd:df
 peer_ota_addr_type=1 peer_ota_addr=00:40:db:b7:63:d7
 peer_id_addr_type=1 peer_id_addr=00:40:db:b7:63:d7
 conn_itvl=6 conn_latency=0 supervision_timeout=500 encrypted=0 authenticated=0 bonded=0

mtu update event; conn_handle=0 cid=4 mtu=512
connection updated; status=0 handle=0 our_ota_addr_type=0 our_ota_addr=01:24:62:ab:dd:df
 our_id_addr_type=0 our_id_addr=01:24:62:ab:dd:df
 peer_ota_addr_type=1 peer_ota_addr=00:40:db:b7:63:d7
 peer_id_addr_type=1 peer_id_addr=00:40:db:b7:63:d7
 conn_itvl=36 conn_latency=0 supervision_timeout=500 encrypted=0 authenticated=0 bonded=0

PASSKEY_ACTION_EVENT started 
*** Enter passkey 426544 on the peer side ***
Trigger powerFSM 7
Transition powerFSM transition=Bluetooth pairing, from=DARK to=ON
ble_sm_inject_io result: 0
Turning on screen
showing bluetooth screen
GPS fix type 0
Ignoring invalid GPS month=0, year=1336, unixtime=1297431932
Update DB node 0xabdddf38, rx_time=0
Node status update: 6 online, 7 total
GPS fix type 0
Ignoring invalid GPS month=0, year=1336, unixtime=1297431932
Update DB node 0xabdddf38, rx_time=0
Node status update: 6 online, 7 total
GPS fix type 0
Ignoring invalid GPS month=0, year=1336, unixtime=1297431932
Sending position to mesh
Update DB node 0xabdddf38, rx_time=0
Node status update: 6 online, 7 total
Providing time to mesh 0
Adding packet record (id=0x51c065be Fr0x38 To0xff, WantAck0, HopLim3 Payload:Position)
enqueuing for send (id=0x51c065be Fr0x38 To0xff, WantAck0, HopLim3 encrypted)
txGood=5,rxGood=2,rxBad=5
Starting low level send (id=0x51c065be Fr0x38 To0xff, WantAck0, HopLim3 encrypted)
Completed sending (id=0x51c065be Fr0x38 To0xff, WantAck0, HopLim3 encrypted)
@geeksville geeksville self-assigned this Sep 8, 2020
@geeksville geeksville added the bug Something isn't working label Sep 8, 2020
@geeksville
Copy link
Member Author

see note about failed IRK

@geeksville
Copy link
Member Author

root cause fixed in meshtastic/esp-nimble@465f26e

geeksville added a commit to meshtastic/arduino-esp32-archive that referenced this issue Sep 9, 2020
@geeksville
Update to pull in my nimble pairing fix
2814f11 
for meshtastic/firmware#370
@geeksville geeksville changed the title my build environment is messed up nimble loss of pairing on heavily used device Sep 9, 2020
@geeksville geeksville mentioned this issue Sep 10, 2020
Closed
Dafeman pushed a commit to Dafeman/Meshtastic-device that referenced this issue Sep 14, 2020
@geeksville @Dafeman
fix meshtastic#370 by pulling in my bugfix to ESP32-Nimble
ad60169
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@geeksville geeksville

Labels
bug Something isn't working
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
1 participant
@geeksville