meshtastic / firmware

Meshtastic device firmware
https://meshtastic.org
GNU General Public License v3.0
3k stars 718 forks source link

[Bug]: Processing neighborinfo slow, saving neighborinfo db causes >1s lockup #3516

Closed prokrypt closed 3 months ago

prokrypt commented 3 months ago

Category

Other

Hardware

Not Applicable

Firmware Version

2.3.2 & 2.3.3

Description

On my nrf52 router, I had noticed it was sometimes rebroadcasting packets after my esp32 client did, so I looked into it...

Tested and video'd on a Nano G2 Ultra (nrf52). Same thing happens on Nano G1 Explorer (esp32) but for less than a second (~600ms). https://github.com/meshtastic/firmware/assets/1832555/8ed11918-eaf1-4dcc-ac1c-d1af0cc66f5c

Relevant log output

DEBUG | 03:56:25 190 [RadioIf] (bw=250, sf=11, cr=4/5) packet symLen=8 ms, payloadSize=87, time 886 ms
DEBUG | 03:56:25 190 [RadioIf] Lora RX (id=0x087d7448 fr=0xe4 to=0xff, WantAck=0, HopLim=6 Ch=0x8 encrypted rxSNR=5.75 rxRSSI=-24 hopStart=6)
DEBUG | 03:56:25 190 [RadioIf] AirTime - Packet received : 886ms
DEBUG | 03:56:25 190 [Router] Add packet record (id=0x087d7448 fr=0xe4 to=0xff, WantAck=0, HopLim=6 Ch=0x8 encrypted rxSNR=5.75 rxRSSI=-24 hopStart=6)
DEBUG | 03:56:25 190 [Router] Using channel 0 (hash 0x8)
DEBUG | 03:56:25 190 [Router] Expanding short PSK #1
DEBUG | 03:56:25 190 [Router] Using AES128 key!
DEBUG | 03:56:25 190 [Router] nRF52 encrypt fr=f71e47e4, num=87d7448, numBytes=71!
DEBUG | 03:56:25 190 [Router] decoded message (id=0x087d7448 fr=0xe4 to=0xff, WantAck=0, HopLim=6 Ch=0x0 Portnum=71 rxtime=1711857385 rxSNR=5.75 rxRSSI=-24 hopStart=6)
DEBUG | 03:56:25 190 [Router] handleReceived(REMOTE) (id=0x087d7448 fr=0xe4 to=0xff, WantAck=0, HopLim=6 Ch=0x0 Portnum=71 rxtime=1711857385 rxSNR=5.75 rxRSSI=-24 hopStart=6)
DEBUG | 03:56:25 190 [Router] Module 'neighborinfo' wantsPacket=1
INFO  | 03:56:25 190 [Router] Received neighborinfo from=0xf71e47e4, id=0x87d7448, portnum=71, payloadlen=67
DEBUG | 03:56:25 190 [Router] RECEIVED NEIGHBORINFO PACKET from Node 0xf71e47e4 to Node 0x57865c0a (last sent by 0xf71e47e4)
DEBUG | 03:56:25 190 [Router] Packet contains 4 neighbors
DEBUG | 03:56:25 190 [Router] Neighbor 0: node_id=0x4e9f554b, snr=6.25
DEBUG | 03:56:25 190 [Router] Neighbor 1: node_id=0x3e1c8f95, snr=6.75
DEBUG | 03:56:25 190 [Router] Neighbor 2: node_id=0x57865c0a, snr=6.00
DEBUG | 03:56:25 190 [Router] Neighbor 3: node_id=0xe1353816, snr=6.25
INFO  | 03:56:25 190 [Router] Saving /prefs/neighbors.proto
DEBUG | 03:56:27 192 [Router] Module 'neighborinfo' considered
DEBUG | 03:56:27 192 [Router] Module 'routing' wantsPacket=1

log

GUVWAF commented 3 months ago

Fixed by #3519.