search

meshtastic / firmware

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

[Bug]: BLE connection failing, every second attempt #4208

Closed todd-herbert closed 4 months ago

todd-herbert commented 4 months ago

Category

BLE

Hardware

Heltec Wireless Paper

Firmware Version

2.3.15.b5d771831

Description

When attempting to begin a Bluetooth connection, from Android App 2.3.13: every second connection attempt fails. This seems to alternate: one successful connection, one failed connection. A full-erase has had no impact.

App displays "Module Config 12/13". Similar behavior observed by @mverch67.

Relevant log output

//\ E S H T /\ S T / C

INFO  | ??:??:?? 0 Booted, wake cause 0 (boot count 1), reset_reason=reset
DEBUG | ??:??:?? 0 Filesystem files (16384/1048576 Bytes):
DEBUG | ??:??:?? 0  /prefs/channels.proto (57 Bytes)      
DEBUG | ??:??:?? 0  /prefs/db.proto (314 Bytes)
[   390][I][esp32-hal-i2c.c:75] i2cInit(): Initialising I2C Master: sda=41 scl=42 freq=100000
DEBUG | ??:??:?? 0 Using analog input 20 for battery level
INFO  | ??:??:?? 0 ADCmod: ADC Characterization based on Two Point values and fitting curve coefficients stored in eFuse
INFO  | ??:??:?? 0 Scanning for i2c devices...
[   420][W][Wire.cpp:301] begin(): Bus already started in Master Mode.
DEBUG | ??:??:?? 0 Scanning for I2C devices on port 1
INFO  | ??:??:?? 0 No I2C devices found
DEBUG | ??:??:?? 0 acc_info = 0
INFO  | ??:??:?? 0 Meshtastic hwvendor=49, swver=2.3.15.b5d771831
DEBUG | ??:??:?? 0 Setting random seed 3832451721
DEBUG | ??:??:?? 0 Total heap: 293544
DEBUG | ??:??:?? 0 Free heap: 257832
DEBUG | ??:??:?? 0 Total PSRAM: 0
DEBUG | ??:??:?? 0 Free PSRAM: 0
DEBUG | ??:??:?? 0 NVS: UsedEntries 86, FreeEntries 544, AllEntries 630, NameSpaces 3
DEBUG | ??:??:?? 0 Setup Preferences in Flash Storage
DEBUG | ??:??:?? 0 Number of Device Reboots: 5
ESP_ERROR_CHECK_WITHOUT_ABORT failed: esp_err_t 0x105 (ESP_ERR_NOT_FOUND) at 0x40380f33
  #0  0x40380f33 in _esp_error_check_failed_without_abort at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/esp_system/esp_err.c:37

file: "src/platform/esp32/BleOta.cpp" line 16
func: static const esp_partition_t* BleOta::findEspOtaAppPartition()
expression: esp_ota_get_partition_description(part, &app_desc)
ESP_ERROR_CHECK_WITHOUT_ABORT failed: esp_err_t 0x102 (ESP_ERR_INVALID_ARG) at 0x40380f33
  #0  0x40380f33 in _esp_error_check_failed_without_abort at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/esp_system/esp_err.c:37

file: "src/platform/esp32/BleOta.cpp" line 30
func: static String BleOta::getOtaAppVersion()
expression: esp_ota_get_partition_description(part, &app_desc)
DEBUG | ??:??:?? 0 No OTA firmware available
INFO  | ??:??:?? 0 Initializing NodeDB
INFO  | ??:??:?? 0 Loading /prefs/db.proto
INFO  | ??:??:?? 0 Loaded /prefs/db.proto successfully
INFO  | ??:??:?? 0 Loaded saved devicestate version 22, with nodecount: 1
[   601][E][vfs_api.cpp:105] open(): /littlefs/prefs/config.proto does not exist, no permits for creation
INFO  | ??:??:?? 0 File /prefs/config.proto not found
INFO  | ??:??:?? 0 Installing default LocalConfig
INFO  | ??:??:?? 0 Setting default channel and radio preferences!
DEBUG | ??:??:?? 0 Expanding short PSK #1
INFO  | ??:??:?? 0 Wanted region 0, using UNSET
[   639][E][vfs_api.cpp:105] open(): /littlefs/prefs/module.proto does not exist, no permits for creation
INFO  | ??:??:?? 0 File /prefs/module.proto not found
INFO  | ??:??:?? 0 Installing default ModuleConfig
INFO  | ??:??:?? 0 Loading /prefs/channels.proto
INFO  | ??:??:?? 0 Loaded /prefs/channels.proto successfully
INFO  | ??:??:?? 0 Loaded saved channelFile version 22
[   692][E][vfs_api.cpp:105] open(): /littlefs/oem/oem.proto does not exist, no permits for creation
INFO  | ??:??:?? 0 File /oem/oem.proto not found
DEBUG | ??:??:?? 0 cleanupMeshDB purged 0 entries
DEBUG | ??:??:?? 0 Using nodenum 0x75cebb38 
DEBUG | ??:??:?? 0 Number of Device Reboots: 5
DEBUG | ??:??:?? 0 Expanding short PSK #1
INFO  | ??:??:?? 0 Wanted region 0, using UNSET
INFO  | ??:??:?? 0 Saving /prefs/db.proto
DEBUG | ??:??:?? 0 Using GPIO00 for button
DEBUG | ??:??:?? 0 SPI.begin(SCK=9, MISO=11, MOSI=10, NSS=8)
DEBUG | ??:??:?? 0 Set Timezone to GMT0
DEBUG | ??:??:?? 0 Read RTC time as 0
DEBUG | ??:??:?? 0 NeighborInfoModule is disabled
DEBUG | ??:??:?? 0 Rescanning for I2C keyboard
DEBUG | ??:??:?? 0 Scanning for I2C devices on port 1
DEBUG | ??:??:?? 0 Scanning address 0x1f
DEBUG | ??:??:?? 0 Scanning address 0x55
DEBUG | ??:??:?? 0 Scanning address 0x5f
INFO  | ??:??:?? 0 External Notification Module Disabled
INFO  | ??:??:?? 0 Doing EInk init
[   867][E][esp32-hal-spi.c:215] spiAttachMISO(): HSPI Does not have default pins on ESP32S3!
DEBUG | ??:??:?? 5 initialized, determineMode(): refresh=FAST, reason=FLAGGED_DEMAND_FAST, frameFlags=0x9
DEBUG | ??:??:?? 5 Updating E-Paper... done
INFO  | ??:??:?? 6 Turning on screen
DEBUG | ??:??:?? 6 haveGlyphs=1
DEBUG | ??:??:?? 6 determineMode(): refresh=FAST, reason=FLAGGED_DEMAND_FAST, frameFlags=0xb
DEBUG | ??:??:?? 6 Updating E-Paper... done
DEBUG | ??:??:?? 6 Module wants a UI Frame
DEBUG | ??:??:?? 6 Module wants a UI Frame
DEBUG | ??:??:?? 6 SX126xInterface(cs=8, irq=14, rst=12, busy=13)
DEBUG | ??:??:?? 6 SX126X_DIO3_TCXO_VOLTAGE defined, using DIO3 as TCXO reference voltage at 1.800000 V
INFO  | ??:??:?? 6 Starting meshradio init...
DEBUG | ??:??:?? 6 (bw=250, sf=11, cr=4/5) packet symLen=8 ms, payloadSize=0, time 231 ms
DEBUG | ??:??:?? 6 (bw=250, sf=11, cr=4/5) packet symLen=8 ms, payloadSize=253, time 2115 ms
INFO  | ??:??:?? 6 Radio freq=906.875, config.lora.frequency_offset=0.000
INFO  | ??:??:?? 6 Set radio: region=UNSET, name=LongFast, config=0, ch=19, power=30
INFO  | ??:??:?? 6 Radio myRegion->freqStart -> myRegion->freqEnd: 902.000000 -> 928.000000 (26.000000 mhz)
INFO  | ??:??:?? 6 Radio myRegion->numChannels: 104 x 250.000kHz
INFO  | ??:??:?? 7 Radio channel_num: 20
INFO  | ??:??:?? 7 Radio frequency: 906.875000
INFO  | ??:??:?? 7 Slot time: 42 msec
INFO  | ??:??:?? 7 Set radio: final power level=22
INFO  | ??:??:?? 7 SX126x init result 0
INFO  | ??:??:?? 7 Frequency set to 906.875000
INFO  | ??:??:?? 7 Bandwidth set to 250.000000
INFO  | ??:??:?? 7 Power output set to 22
DEBUG | ??:??:?? 7 Current limit set to 140.000000
DEBUG | ??:??:?? 7 Current limit set result 0
DEBUG | ??:??:?? 7 Setting DIO2 as RF switch
DEBUG | ??:??:?? 7 SX126X_RXEN not defined, defaulting to RADIOLIB_NC
DEBUG | ??:??:?? 7 SX126X_TXEN not defined, defaulting to RADIOLIB_NC
DEBUG | ??:??:?? 7 Using MCU pin -1 as RXEN and pin -1 as TXEN to control RF switching
INFO  | ??:??:?? 7 Set RX gain to boosted mode; result: 0
INFO  | ??:??:?? 7 SX1262 Radio init succeeded, using SX1262 radio
INFO  | ??:??:?? 7 Not using WIFI
DEBUG | ??:??:?? 7 (bw=250, sf=11, cr=4/5) packet symLen=8 ms, payloadSize=237, time 2000 ms
DEBUG | ??:??:?? 7 LoRA bitrate = 118.500000 bytes / sec
INFO  | ??:??:?? 7 PowerFSM init, USB power=1
DEBUG | ??:??:?? 7 Enter state: BOOT
[  7191][D][esp32-hal-cpu.c:244] setCpuFrequencyMhz(): PLL: 480 / 6 = 80 Mhz, APB: 80000000 Hz
DEBUG | ??:??:?? 7 [Power] Battery: usbPower=0, isCharging=0, batMv=3760, batPct=55
DEBUG | ??:??:?? 7 [Screen] Screen: Started...
DEBUG | ??:??:?? 7 [Screen] haveGlyphs=1
DEBUG | ??:??:?? 7 [Screen] determineMode(): refresh=SKIPPED, reason=FRAME_MATCHED_PREVIOUS, frameFlags=0x3
INFO  | ??:??:?? 7 [RangeTestModule] Range Test Module - Disabled
DEBUG | ??:??:?? 8 [Screen] haveGlyphs=1
DEBUG | ??:??:?? 8 [Screen] determineMode(): refresh=SKIPPED, reason=FRAME_MATCHED_PREVIOUS, frameFlags=0x3
DEBUG | ??:??:?? 9 [Screen] haveGlyphs=1
DEBUG | ??:??:?? 9 [Screen] determineMode(): refresh=SKIPPED, reason=FRAME_MATCHED_PREVIOUS, frameFlags=0x3
INFO  | ??:??:?? 10 [PowerFSM] Loss of power in Powered
DEBUG | ??:??:?? 10 [Screen] haveGlyphs=1
DEBUG | ??:??:?? 10 [Screen] determineMode(): refresh=SKIPPED, reason=FRAME_MATCHED_PREVIOUS, frameFlags=0x3
INFO  | ??:??:?? 10 [PowerFSM] Loss of power in Powered
INFO  | ??:??:?? 10 [PowerFSM] Initialise the NimBLE bluetooth module
DEBUG | ??:??:?? 10 [PowerFSM] Enter state: ON
DEBUG | ??:??:?? 10 [Screen] haveGlyphs=1
DEBUG | ??:??:?? 10 [Screen] refresh=SKIPPED, reason=EXCEEDED_RATELIMIT_FAST, frameFlags=0x3
DEBUG | ??:??:?? 10 [Screen] refresh=SKIPPED, reason=EXCEEDED_RATELIMIT_FAST, frameFlags=0x3
INFO  | ??:??:?? 10 BLE authentication complete
DEBUG | ??:??:?? 11 [Screen] haveGlyphs=1
DEBUG | ??:??:?? 11 [Screen] determineMode(): refresh=SKIPPED, reason=FRAME_MATCHED_PREVIOUS, frameFlags=0x3
INFO  | ??:??:?? 12 [Screen] Done with boot screen...
DEBUG | ??:??:?? 12 [Screen] showing standard frames
DEBUG | ??:??:?? 12 [Screen] Showing 0 module frames
DEBUG | ??:??:?? 12 [Screen] Total frame count: 103
DEBUG | ??:??:?? 12 [Screen] Added modules.  numframes: 0
DEBUG | ??:??:?? 12 [Screen] Finished building frames. numframes: 2
DEBUG | ??:??:?? 12 [Screen] determineMode(): refresh=FULL, reason=FLAGGED_COSMETIC, frameFlags=0x5
DEBUG | ??:??:?? 12 [Screen] Updating E-Paper... To Radio onwrite
INFO  | ??:??:?? 12 [Screen] Client wants config, nonce=3
DEBUG | ??:??:?? 12 [Screen] done
DEBUG | ??:??:?? 12 [Screen] Async full-refresh begins (dropping frames)
DEBUG | ??:??:?? 12 [Screen] Got 2 files in manifest
INFO  | ??:??:?? 12 [Screen] Starting API client config
DEBUG | ??:??:?? 12 [Screen] refresh=SKIPPED, reason=EXCEEDED_RATELIMIT_FAST, frameFlags=0x3
INFO  | ??:??:?? 13 getFromRadio=STATE_SEND_MY_INFO
DEBUG | ??:??:?? 13 encoding toPhone packet to phone variant=3, 14 bytes
INFO  | ??:??:?? 13 getFromRadio=STATE_SEND_OWN_NODEINFO
DEBUG | ??:??:?? 13 encoding toPhone packet to phone variant=4, 56 bytes
INFO  | ??:??:?? 13 getFromRadio=STATE_SEND_METADATA
DEBUG | ??:??:?? 13 encoding toPhone packet to phone variant=13, 33 bytes
INFO  | ??:??:?? 13 getFromRadio=STATE_SEND_CHANNELS
DEBUG | ??:??:?? 13 encoding toPhone packet to phone variant=10, 13 bytes
INFO  | ??:??:?? 13 getFromRadio=STATE_SEND_CHANNELS
DEBUG | ??:??:?? 13 encoding toPhone packet to phone variant=10, 6 bytes
INFO  | ??:??:?? 13 getFromRadio=STATE_SEND_CHANNELS
DEBUG | ??:??:?? 13 encoding toPhone packet to phone variant=10, 6 bytes
INFO  | ??:??:?? 13 getFromRadio=STATE_SEND_CHANNELS
DEBUG | ??:??:?? 13 encoding toPhone packet to phone variant=10, 6 bytes
INFO  | ??:??:?? 13 getFromRadio=STATE_SEND_CHANNELS
DEBUG | ??:??:?? 13 encoding toPhone packet to phone variant=10, 6 bytes
INFO  | ??:??:?? 13 getFromRadio=STATE_SEND_CHANNELS
DEBUG | ??:??:?? 13 encoding toPhone packet to phone variant=10, 6 bytes
INFO  | ??:??:?? 13 getFromRadio=STATE_SEND_CHANNELS
DEBUG | ??:??:?? 13 encoding toPhone packet to phone variant=10, 6 bytes
INFO  | ??:??:?? 14 getFromRadio=STATE_SEND_CHANNELS
DEBUG | ??:??:?? 14 encoding toPhone packet to phone variant=10, 6 bytes
INFO  | ??:??:?? 14 getFromRadio=STATE_SEND_CONFIG
DEBUG | ??:??:?? 14 encoding toPhone packet to phone variant=5, 11 bytes
INFO  | ??:??:?? 14 getFromRadio=STATE_SEND_CONFIG
DEBUG | ??:??:?? 14 encoding toPhone packet to phone variant=5, 20 bytes
INFO  | ??:??:?? 14 getFromRadio=STATE_SEND_CONFIG
DEBUG | ??:??:?? 14 encoding toPhone packet to phone variant=5, 17 bytes
INFO  | ??:??:?? 14 getFromRadio=STATE_SEND_CONFIG
DEBUG | ??:??:?? 14 encoding toPhone packet to phone variant=5, 29 bytes
INFO  | ??:??:?? 14 getFromRadio=STATE_SEND_CONFIG
DEBUG | ??:??:?? 14 encoding toPhone packet to phone variant=5, 7 bytes
INFO  | ??:??:?? 14 getFromRadio=STATE_SEND_CONFIG
DEBUG | ??:??:?? 14 [SerialConsole] encoding toPhone packet to phone variant=5, 14 bytes
INFO  | ??:??:?? 14 getFromRadio=STATE_SEND_CONFIG
DEBUG | ??:??:?? 14 encoding toPhone packet to phone variant=5, 10 bytes
INFO  | ??:??:?? 14 getFromRadio=STATE_SEND_MODULECONFIG
DEBUG | ??:??:?? 14 encoding toPhone packet to phone variant=9, 53 bytes
INFO  | ??:??:?? 14 getFromRadio=STATE_SEND_MODULECONFIG
DEBUG | ??:??:?? 14 encoding toPhone packet to phone variant=9, 4 bytes
INFO  | ??:??:?? 14 getFromRadio=STATE_SEND_MODULECONFIG
DEBUG | ??:??:?? 14 encoding toPhone packet to phone variant=9, 4 bytes
INFO  | ??:??:?? 15 getFromRadio=STATE_SEND_MODULECONFIG
DEBUG | ??:??:?? 15 encoding toPhone packet to phone variant=9, 4 bytes
INFO  | ??:??:?? 15 getFromRadio=STATE_SEND_MODULECONFIG
DEBUG | ??:??:?? 15 encoding toPhone packet to phone variant=9, 4 bytes
INFO  | ??:??:?? 15 getFromRadio=STATE_SEND_MODULECONFIG
DEBUG | ??:??:?? 15 encoding toPhone packet to phone variant=9, 13 bytes
INFO  | ??:??:?? 15 getFromRadio=STATE_SEND_MODULECONFIG
DEBUG | ??:??:?? 15 encoding toPhone packet to phone variant=9, 4 bytes
INFO  | ??:??:?? 15 getFromRadio=STATE_SEND_MODULECONFIG
DEBUG | ??:??:?? 15 encoding toPhone packet to phone variant=9, 4 bytes
INFO  | ??:??:?? 15 getFromRadio=STATE_SEND_MODULECONFIG
DEBUG | ??:??:?? 15 encoding toPhone packet to phone variant=9, 4 bytes
INFO  | ??:??:?? 15 getFromRadio=STATE_SEND_MODULECONFIG
DEBUG | ??:??:?? 15 encoding toPhone packet to phone variant=9, 7 bytes
INFO  | ??:??:?? 15 getFromRadio=STATE_SEND_MODULECONFIG
DEBUG | ??:??:?? 15 encoding toPhone packet to phone variant=9, 14 bytes
INFO  | ??:??:?? 15 getFromRadio=STATE_SEND_MODULECONFIG
DEBUG | ??:??:?? 15 encoding toPhone packet to phone variant=9, 8 bytes
INFO  | ??:??:?? 15 getFromRadio=STATE_SEND_MODULECONFIG
DEBUG | ??:??:?? 15 encoding toPhone packet to phone variant=9, 4 bytes
INFO  | ??:??:?? 16 getFromRadio=STATE_SEND_OTHER_NODEINFOS
INFO  | ??:??:?? 16 Done sending nodeinfos
INFO  | ??:??:?? 16 getFromRadio=STATE_SEND_FILEMANIFEST
DEBUG | ??:??:?? 16 File: /prefs/channels.proto (57) bytes
DEBUG | ??:??:?? 16 encoding toPhone packet to phone variant=15, 27 bytes
INFO  | ??:??:?? 16 getFromRadio=STATE_SEND_FILEMANIFEST
DEBUG | ??:??:?? 16 File: /prefs/db.proto (314) bytes
DEBUG | ??:??:?? 16 encoding toPhone packet to phone variant=15, 22 bytes
INFO  | ??:??:?? 16 getFromRadio=STATE_SEND_FILEMANIFEST
DEBUG | ??:??:?? 16 no FromRadio packet available
DEBUG | ??:??:?? 16 [EInkDynamicDisplay] Async full-refresh complete
DEBUG | ??:??:?? 16 [Screen] determineMode(): refresh=SKIPPED, reason=FRAME_MATCHED_PREVIOUS, frameFlags=0x3
thebentern commented 4 months ago

Closed by #4209