Battery Level Sometimes 0% With DC Current Module for Solar Power

Support
1

I have a wisblock (19007/4631) in rak’s updated unify solar enclosure with their dc current sensor inline of the solar panel and for some reason it’s making the battery level and voltage readings alternate between their actual values and 0. It’s is most easily seen in the Apple client (ignore the gap in the middle, my node was offline).

image
image1192×782 139 KB

On the DC Current module, Vin+ is connected to the red wire coming from the solar panel and Vin- is connected to the red wire going to P2 (solar) on the 19007. Both black wires (one from the solar panel and one from P2) are connected to Gnd.

image
image1850×1000 75.5 KB

image
image1920×1080 152 KB

(note: this setup pic with the usb connected is the only one I had available to show wiring/port connectivity. battery level readings in top screenshot are under normal operation with only solar power; no usb)

Running meshtastic fw 2.3.7 alpha and sensors/modules are populated as follows:

  • IO - rak1600 DC Current Sensor 3A Texas Instruments INA219BID
  • Slot A - rak12500 GPS/GNSS sensor
  • Slot B - Empty
  • Slot C - rak1906 Environment Sensor BOSCH BME680
  • Slot D - Empty

The telemetry module configuration:

image
image1068×1284 108 KB

No other buttons, modules, sensors, screens, or pins are physically connected or configured outside of the default values.

2

Either the firmware cannot reproducibly determine a voltage or the app determines the voltage incorrectly. What do the logs say and what voltage do other nodes show? Is the error also present on Android?

3

Either the android client isn’t affected (I believe this is the case) or I’m not catching it at the right timing. Android doesn’t show historical like the Apple client, but I have yet to see it in realtime stats when connected directly to the node in question or viewing from other nodes.

Connected directly to the node with the Apple client, the device metrics reflect an accurate sample and then a second sample with zeros or nulls within the same 60s sample period.

image
image1260×83 5.79 KB

If I grep the serial console for that specific time, I can see telemetry for the accurate sample (@ 18:53:07).

INFO  | 18:53:07 7251 [DeviceTelemetryModule] (Sending): air_util_tx=0.532722, channel_utilization=17.608334, battery_level=101, voltage=3.925000

But I see nothing in this timeframe that would indicate the null values (unless I’m missing it). So perhaps this is just an Apple client issue creating a secondary sample with nulls across the line (battery, voltage, channel utilization, airtime, and uptime)?

(base) ➜  ~ grep 18:53 meshtastic.log
DEBUG | 18:53:00 7244 [RadioIf] Completed sending (id=0x2d6af534 fr=0x6b to=0xff, WantAck=0, H(base) ➜  ~ grep 18:53 meshtastic.log
DEBUG | 18:53:00 7244 [RadioIf] Completed sending (id=0x2d6af534 fr=0x6b to=0xff, WantAck=0, HopLim=3 Ch=0x8 encrypted rxtime=1714589577 rxSNR=6.5 rxRSSI=-44 hopStart=4 priority=64)
DEBUG | 18:53:02 7246 [Power] Battery: usbPower=1, isCharging=1, batMv=3925, batPct=73
INFO  | 18:53:07 7251 [DeviceTelemetryModule] (Sending): air_util_tx=0.532722, channel_utilization=17.608334, battery_level=101, voltage=3.925000
DEBUG | 18:53:07 7251 [DeviceTelemetryModule] updateTelemetry LOCAL
DEBUG | 18:53:07 7251 [DeviceTelemetryModule] Node status update: 17 online, 17 total
INFO  | 18:53:07 7251 [DeviceTelemetryModule] Sending packet to mesh
DEBUG | 18:53:07 7251 [DeviceTelemetryModule] Update DB node 0x743cd480, rx_time=1714589587
DEBUG | 18:53:07 7251 [DeviceTelemetryModule] handleReceived(LOCAL) (id=0x52bc91dc fr=0x80 to=0xff, WantAck=0, HopLim=4 Ch=0x0 Portnum=67 rxtime=1714589587 priority=10)
DEBUG | 18:53:07 7251 [DeviceTelemetryModule] No modules interested in portnum=67, src=LOCAL
DEBUG | 18:53:07 7251 [DeviceTelemetryModule] localSend to channel 0
DEBUG | 18:53:07 7251 [DeviceTelemetryModule] Add packet record (id=0x52bc91dc fr=0x80 to=0xff, WantAck=0, HopLim=4 Ch=0x0 Portnum=67 rxtime=1714589587 priority=10)
DEBUG | 18:53:07 7251 [DeviceTelemetryModule] Expanding short PSK #1
DEBUG | 18:53:07 7251 [DeviceTelemetryModule] Using AES128 key!
DEBUG | 18:53:07 7251 [DeviceTelemetryModule] nRF52 encrypt fr=743cd480, num=52bc91dc, numBytes=28!
DEBUG | 18:53:07 7251 [DeviceTelemetryModule] enqueuing for send (id=0x52bc91dc fr=0x80 to=0xff, WantAck=0, HopLim=4 Ch=0x8 encrypted rxtime=1714589587 hopStart=4 priority=10)
DEBUG | 18:53:07 7251 [DeviceTelemetryModule] txGood=71,rxGood=501,rxBad=2
DEBUG | 18:53:07 7251 [DeviceTelemetryModule] Using channel 0 (hash 0x8)
DEBUG | 18:53:07 7251 [DeviceTelemetryModule] Expanding short PSK #1
DEBUG | 18:53:07 7251 [DeviceTelemetryModule] Using AES128 key!
DEBUG | 18:53:07 7251 [DeviceTelemetryModule] nRF52 encrypt fr=743cd480, num=52bc91dc, numBytes=28!
DEBUG | 18:53:07 7251 [DeviceTelemetryModule] decoded message (id=0x52bc91dc fr=0x80 to=0xff, WantAck=0, HopLim=4 Ch=0x0 Portnum=67 rxtime=1714589587 hopStart=4 priority=10)
INFO  | 18:53:07 7251 Telling client we have new packets 1105
INFO  | 18:53:07 7251 BLE notify fromNum
INFO  | 18:53:07 7251 getFromRadio=STATE_SEND_PACKETS
DEBUG | 18:53:07 7251 encoding toPhone packet to phone variant=11, 12 bytes
INFO  | 18:53:07 7251 [RadioIf] getFromRadio=STATE_SEND_PACKETS
DEBUG | 18:53:07 7251 [RadioIf] phone downloaded packet (id=0x52bc91dc fr=0x80 to=0xff, WantAck=0, HopLim=4 Ch=0x0 Portnum=67 rxtime=1714589587 hopStart=4 priority=10)
DEBUG | 18:53:07 7251 [RadioIf] encoding toPhone packet to phone variant=2, 58 bytes
DEBUG | 18:53:07 7251 [RadioIf] Starting low level send (id=0x52bc91dc fr=0x80 to=0xff, WantAck=0, HopLim=4 Ch=0x8 encrypted rxtime=1714589587 hopStart=4 priority=10)
DEBUG | 18:53:07 7251 [RadioIf] (bw=250, sf=11, cr=4/5) packet symLen=8 ms, payloadSize=44, time 559 ms
DEBUG | 18:53:07 7251 [RadioIf] AirTime - Packet transmitted : 559ms
INFO  | 18:53:07 7252 toRadioWriteCb data 0x2001c00a, len 16
DEBUG | 18:53:07 7252 PACKET FROM PHONE (id=0x00000000 fr=0x80 to=0x80, WantAck=0, HopLim=0 Ch=0x0 Portnum=3)
WARN  | 18:53:07 7252 phone tried to pick a nodenum, we don't allow that.
DEBUG | 18:53:07 7252 Enqueued local (id=0x52bc91dd fr=0x00 to=0x80, WantAck=0, HopLim=0 Ch=0x0 Portnum=3 rxtime=1714589587)
INFO  | 18:53:07 7252 Telling client we have new packets 1106
INFO  | 18:53:07 7252 BLE notify fromNum
DEBUG | 18:53:07 7252 [Router] Add packet record (id=0x52bc91dd fr=0x00 to=0x80, WantAck=0, HopLim=0 Ch=0x0 Portnum=3 rxtime=1714589587)
DEBUG | 18:53:07 7252 [Router] handleReceived(REMOTE) (id=0x52bc91dd fr=0x00 to=0x80, WantAck=0, HopLim=0 Ch=0x0 Portnum=3 rxtime=1714589587)
DEBUG | 18:53:07 7252 [Router] Module 'position' wantsPacket=1
INFO  | 18:53:07 7252 [Router] Received position from=0x0, id=0x52bc91dd, portnum=3, payloadlen=0
DEBUG | 18:53:07 7252 [Router] Incoming update from MYSELF
DEBUG | 18:53:07 7252 [Router] Setting local position: latitude=0, longitude=0, time=0
INFO  | 18:53:07 7252 [Router] POSITION node=743cd480 l=0 latI=0 lonI=0 msl=0 hae=0 geo=0 pdop=0 hdop=0 vdop=0 siv=0 fxq=0 fxt=0 pts=0 time=0
INFO  | 18:53:07 7252 [Router] updatePosition REMOTE node=0x743cd480 time=0, latI=0, lonI=0
DEBUG | 18:53:07 7252 [Router] Node status update: 17 online, 17 total
DEBUG | 18:53:07 7252 [Router] Module 'position' considered
DEBUG | 18:53:07 7252 [Router] Module 'routing' wantsPacket=1
INFO  | 18:53:07 7252 [Router] Received routing from=0x0, id=0x52bc91dd, portnum=3, payloadlen=0
DEBUG | 18:53:07 7252 [Router] Routing sniffing (id=0x52bc91dd fr=0x00 to=0x80, WantAck=0, HopLim=0 Ch=0x0 Portnum=3 rxtime=1714589587)
DEBUG | 18:53:07 7252 [Router] Module 'routing' considered
INFO  | 18:53:08 7252 getFromRadio=STATE_SEND_PACKETS
DEBUG | 18:53:08 7252 encoding toPhone packet to phone variant=11, 12 bytes
DEBUG | 18:53:08 7252 [RadioIf] Completed sending (id=0x52bc91dc fr=0x80 to=0xff, WantAck=0, HopLim=4 Ch=0x8 encrypted rxtime=1714589587 hopStart=4 priority=10)
DEBUG | 18:53:10 7254 [RadioIf] (bw=250, sf=11, cr=4/5) packet symLen=8 ms, payloadSize=44, time 559 ms
DEBUG | 18:53:10 7254 [RadioIf] Lora RX (id=0x52bc91dc fr=0x80 to=0xff, WantAck=0, HopLim=3 Ch=0x8 encrypted rxSNR=6 rxRSSI=-38 hopStart=4)
DEBUG | 18:53:10 7254 [RadioIf] AirTime - Packet received : 559ms
DEBUG | 18:53:10 7254 [Router] Rx someone rebroadcasting for us (id=0x52bc91dc fr=0x80 to=0xff, WantAck=0, HopLim=3 Ch=0x8 encrypted rxSNR=6 rxRSSI=-38 hopStart=4)
DEBUG | 18:53:10 7254 [Router] didn't find pending packet
DEBUG | 18:53:10 7254 [Router] Found existing packet record for fr=0x743cd480,to=0xffffffff,id=0x52bc91dc
DEBUG | 18:53:10 7254 [Router] Found existing packet record for fr=0x743cd480,to=0xffffffff,id=0x52bc91dc
DEBUG | 18:53:10 7254 [Router] Add packet record (id=0x52bc91dc fr=0x80 to=0xff, WantAck=0, HopLim=3 Ch=0x8 encrypted rxSNR=6 rxRSSI=-38 hopStart=4)
DEBUG | 18:53:10 7254 [Router] Ignoring incoming msg, because we've already seen it (id=0x52bc91dc fr=0x80 to=0xff, WantAck=0, HopLim=3 Ch=0x8 encrypted rxSNR=6 rxRSSI=-38 hopStart=4)
DEBUG | 18:53:10 7254 [Router] cancelSending id=0x52bc91dc, removed=0
DEBUG | 18:53:10 7254 [Router] Incoming message was filtered 0x743cd480
DEBUG | 18:53:22 7266 [Power] Battery: usbPower=1, isCharging=1, batMv=3925, batPct=73
INFO  | 18:53:27 7271 toRadioWriteCb data 0x2001c00a, len 16
DEBUG | 18:53:27 7271 PACKET FROM PHONE (id=0x00000000 fr=0x80 to=0x80, WantAck=0, HopLim=0 Ch=0x0 Portnum=3)
WARN  | 18:53:27 7271 phone tried to pick a nodenum, we don't allow that.
DEBUG | 18:53:27 7271 Enqueued local (id=0x52bc91de fr=0x00 to=0x80, WantAck=0, HopLim=0 Ch=0x0 Portnum=3 rxtime=1714589607)
INFO  | 18:53:27 7271 Telling client we have new packets 1107
INFO  | 18:53:27 7271 BLE notify fromNum
DEBUG | 18:53:27 7271 [Router] Add packet record (id=0x52bc91de fr=0x00 to=0x80, WantAck=0, HopLim=0 Ch=0x0 Portnum=3 rxtime=1714589607)
DEBUG | 18:53:27 7271 [Router] handleReceived(REMOTE) (id=0x52bc91de fr=0x00 to=0x80, WantAck=0, HopLim=0 Ch=0x0 Portnum=3 rxtime=1714589607)
DEBUG | 18:53:27 7271 [Router] Module 'position' wantsPacket=1
INFO  | 18:53:27 7271 [Router] Received position from=0x0, id=0x52bc91de, portnum=3, payloadlen=0
DEBUG | 18:53:27 7271 [Router] Incoming update from MYSELF
DEBUG | 18:53:27 7271 [Router] Setting local position: latitude=0, longitude=0, time=0
INFO  | 18:53:27 7271 [Router] POSITION node=743cd480 l=0 latI=0 lonI=0 msl=0 hae=0 geo=0 pdop=0 hdop=0 vdop=0 siv=0 fxq=0 fxt=0 pts=0 time=0
INFO  | 18:53:27 7271 [Router] updatePosition REMOTE node=0x743cd480 time=0, latI=0, lonI=0
DEBUG | 18:53:27 7271 [Router] Node status update: 17 online, 17 total
DEBUG | 18:53:27 7271 [Router] Module 'position' considered
DEBUG | 18:53:27 7271 [Router] Module 'routing' wantsPacket=1
INFO  | 18:53:27 7271 [Router] Received routing from=0x0, id=0x52bc91de, portnum=3, payloadlen=0
DEBUG | 18:53:27 7271 [Router] Routing sniffing (id=0x52bc91de fr=0x00 to=0x80, WantAck=0, HopLim=0 Ch=0x0 Portnum=3 rxtime=1714589607)
DEBUG | 18:53:27 7271 [Router] Module 'routing' considered
INFO  | 18:53:27 7271 getFromRadio=STATE_SEND_PACKETS
DEBUG | 18:53:27 7271 encoding toPhone packet to phone variant=11, 12 bytes
DEBUG | 18:53:28 7272 [RadioIf] (bw=250, sf=11, cr=4/5) packet symLen=8 ms, payloadSize=68, time 739 ms
DEBUG | 18:53:28 7272 [RadioIf] Lora RX (id=0x5702636f fr=0x61 to=0xff, WantAck=0, HopLim=1 Ch=0x8 encrypted rxSNR=6 rxRSSI=-39)
DEBUG | 18:53:28 7272 [RadioIf] AirTime - Packet received : 739ms
DEBUG | 18:53:28 7272 [Router] Add packet record (id=0x5702636f fr=0x61 to=0xff, WantAck=0, HopLim=1 Ch=0x8 encrypted rxSNR=6 rxRSSI=-39)
DEBUG | 18:53:28 7272 [Router] Using channel 0 (hash 0x8)
DEBUG | 18:53:28 7272 [Router] Expanding short PSK #1
DEBUG | 18:53:28 7272 [Router] Using AES128 key!
DEBUG | 18:53:28 7272 [Router] nRF52 encrypt fr=fc371761, num=5702636f, numBytes=52!
DEBUG | 18:53:28 7272 [Router] decoded message (id=0x5702636f fr=0x61 to=0xff, WantAck=0, HopLim=1 Ch=0x0 Portnum=4 rxtime=1714589608 rxSNR=6 rxRSSI=-39)
DEBUG | 18:53:28 7272 [Router] handleReceived(REMOTE) (id=0x5702636f fr=0x61 to=0xff, WantAck=0, HopLim=1 Ch=0x0 Portnum=4 rxtime=1714589608 rxSNR=6 rxRSSI=-39)
DEBUG | 18:53:28 7272 [Router] Module 'nodeinfo' wantsPacket=1
INFO  | 18:53:28 7272 [Router] Received nodeinfo from=0xfc371761, id=0x5702636f, portnum=4, payloadlen=48
DEBUG | 18:53:28 7272 [Router] old user ********, channel=0
DEBUG | 18:53:28 7272 [Router] updating changed=0 user ********, channel=0
DEBUG | 18:53:28 7272 [Router] Module 'nodeinfo' considered
DEBUG | 18:53:28 7272 [Router] Module 'routing' wantsPacket=1
INFO  | 18:53:28 7272 [Router] Received routing from=0xfc371761, id=0x5702636f, portnum=4, payloadlen=48
DEBUG | 18:53:28 7272 [Router] Routing sniffing (id=0x5702636f fr=0x61 to=0xff, WantAck=0, HopLim=1 Ch=0x0 Portnum=4 rxtime=1714589608 rxSNR=6 rxRSSI=-39)
INFO  | 18:53:28 7272 [Router] Rebroadcasting received floodmsg to neighbors
DEBUG | 18:53:28 7272 [Router] Expanding short PSK #1
DEBUG | 18:53:28 7272 [Router] Using AES128 key!
DEBUG | 18:53:28 7272 [Router] nRF52 encrypt fr=fc371761, num=5702636f, numBytes=52!
DEBUG | 18:53:28 7272 [Router] enqueuing for send (id=0x5702636f fr=0x61 to=0xff, WantAck=0, HopLim=0 Ch=0x8 encrypted rxtime=1714589608 rxSNR=6 rxRSSI=-39)
DEBUG | 18:53:28 7272 [Router] txGood=72,rxGood=503,rxBad=2
DEBUG | 18:53:28 7272 [Router] rx_snr found. hop_limit:0 rx_snr:6.000000
DEBUG | 18:53:28 7272 [Router] rx_snr found in packet. Setting tx delay:3150
DEBUG | 18:53:28 7272 [Router] Delivering rx packet (id=0x5702636f fr=0x61 to=0xff, WantAck=0, HopLim=1 Ch=0x0 Portnum=4 rxtime=1714589608 rxSNR=6 rxRSSI=-39)
DEBUG | 18:53:28 7272 [Router] Update DB node 0xfc371761, rx_time=1714589608
DEBUG | 18:53:28 7272 [Router] Forwarding to phone (id=0x5702636f fr=0x61 to=0xff, WantAck=0, HopLim=1 Ch=0x0 Portnum=4 rxtime=1714589608 rxSNR=6 rxRSSI=-39)
DEBUG | 18:53:28 7272 [Router] Module 'routing' considered
INFO  | 18:53:28 7272 Telling client we have new packets 1108
INFO  | 18:53:28 7272 BLE notify fromNum
INFO  | 18:53:28 7272 getFromRadio=STATE_SEND_PACKETS
DEBUG | 18:53:28 7272 phone downloaded packet (id=0x5702636f fr=0x61 to=0xff, WantAck=0, HopLim=1 Ch=0x0 Portnum=4 rxtime=1714589608 rxSNR=6 rxRSSI=-39)
DEBUG | 18:53:28 7272 encoding toPhone packet to phone variant=2, 94 bytes
DEBUG | 18:53:29 7273 [RadioIf] (bw=250, sf=11, cr=4/5) packet symLen=8 ms, payloadSize=68, time 739 ms
DEBUG | 18:53:29 7273 [RadioIf] Lora RX (id=0x5702636f fr=0x61 to=0xff, WantAck=0, HopLim=0 Ch=0x8 encrypted rxSNR=5.75 rxRSSI=-53)
DEBUG | 18:53:29 7273 [RadioIf] AirTime - Packet received : 739ms
DEBUG | 18:53:29 7273 [Router] Found existing packet record for fr=0xfc371761,to=0xffffffff,id=0x5702636f
DEBUG | 18:53:29 7273 [Router] Found existing packet record for fr=0xfc371761,to=0xffffffff,id=0x5702636f
DEBUG | 18:53:29 7273 [Router] Add packet record (id=0x5702636f fr=0x61 to=0xff, WantAck=0, HopLim=0 Ch=0x8 encrypted rxSNR=5.75 rxRSSI=-53)
DEBUG | 18:53:29 7273 [Router] Ignoring incoming msg, because we've already seen it (id=0x5702636f fr=0x61 to=0xff, WantAck=0, HopLim=0 Ch=0x8 encrypted rxSNR=5.75 rxRSSI=-53)
DEBUG | 18:53:29 7273 [Router] cancelSending id=0x5702636f, removed=1
DEBUG | 18:53:29 7273 [Router] Incoming message was filtered 0xfc371761
DEBUG | 18:53:30 7274 [RadioIf] (bw=250, sf=11, cr=4/5) packet symLen=8 ms, payloadSize=48, time 591 ms
DEBUG | 18:53:30 7274 [RadioIf] Lora RX (id=0x6796d50b fr=0x25 to=0xff, WantAck=0, HopLim=2 Ch=0x8 encrypted rxSNR=6.25 rxRSSI=-40 hopStart=3)
DEBUG | 18:53:30 7274 [RadioIf] AirTime - Packet received : 591ms
DEBUG | 18:53:30 7274 [Router] Add packet record (id=0x6796d50b fr=0x25 to=0xff, WantAck=0, HopLim=2 Ch=0x8 encrypted rxSNR=6.25 rxRSSI=-40 hopStart=3)
DEBUG | 18:53:30 7274 [Router] Using channel 0 (hash 0x8)
DEBUG | 18:53:30 7274 [Router] Expanding short PSK #1
DEBUG | 18:53:30 7274 [Router] Using AES128 key!
DEBUG | 18:53:30 7274 [Router] nRF52 encrypt fr=221f9c25, num=6796d50b, numBytes=32!
DEBUG | 18:53:30 7274 [Router] decoded message (id=0x6796d50b fr=0x25 to=0xff, WantAck=0, HopLim=2 Ch=0x0 Portnum=67 rxtime=1714589610 rxSNR=6.25 rxRSSI=-40 hopStart=3)
DEBUG | 18:53:30 7274 [Router] handleReceived(REMOTE) (id=0x6796d50b fr=0x25 to=0xff, WantAck=0, HopLim=2 Ch=0x0 Portnum=67 rxtime=1714589610 rxSNR=6.25 rxRSSI=-40 hopStart=3)
DEBUG | 18:53:30 7274 [Router] Module 'DeviceTelemetry' wantsPacket=1
INFO  | 18:53:30 7274 [Router] Received DeviceTelemetry from=0x221f9c25, id=0x6796d50b, portnum=67, payloadlen=28
INFO  | 18:53:30 7274 [Router] (Received from DC01): air_util_tx=0.724056, channel_utilization=6.163333, battery_level=87, voltage=4.035000
DEBUG | 18:53:30 7274 [Router] updateTelemetry REMOTE node=0x221f9c25 
DEBUG | 18:53:30 7274 [Router] Node status update: 17 online, 17 total
DEBUG | 18:53:30 7274 [Router] Module 'DeviceTelemetry' considered
DEBUG | 18:53:30 7274 [Router] Module 'EnvironmentTelemetry' wantsPacket=1
INFO  | 18:53:30 7274 [Router] Received EnvironmentTelemetry from=0x221f9c25, id=0x6796d50b, portnum=67, payloadlen=28
DEBUG | 18:53:30 7274 [Router] Module 'EnvironmentTelemetry' considered
DEBUG | 18:53:30 7274 [Router] Module 'PowerTelemetry' wantsPacket=1
INFO  | 18:53:30 7274 [Router] Received PowerTelemetry from=0x221f9c25, id=0x6796d50b, portnum=67, payloadlen=28
DEBUG | 18:53:30 7274 [Router] Module 'PowerTelemetry' considered
DEBUG | 18:53:30 7274 [Router] Module 'routing' wantsPacket=1
INFO  | 18:53:30 7274 [Router] Received routing from=0x221f9c25, id=0x6796d50b, portnum=67, payloadlen=28
DEBUG | 18:53:30 7274 [Router] Routing sniffing (id=0x6796d50b fr=0x25 to=0xff, WantAck=0, HopLim=2 Ch=0x0 Portnum=67 rxtime=1714589610 rxSNR=6.25 rxRSSI=-40 hopStart=3)
INFO  | 18:53:30 7274 [Router] Rebroadcasting received floodmsg to neighbors
DEBUG | 18:53:30 7274 [Router] Expanding short PSK #1
DEBUG | 18:53:30 7274 [Router] Using AES128 key!
DEBUG | 18:53:30 7274 [Router] nRF52 encrypt fr=221f9c25, num=6796d50b, numBytes=32!
DEBUG | 18:53:30 7274 [Router] enqueuing for send (id=0x6796d50b fr=0x25 to=0xff, WantAck=0, HopLim=1 Ch=0x8 encrypted rxtime=1714589610 rxSNR=6.25 rxRSSI=-40 hopStart=3)
DEBUG | 18:53:30 7274 [Router] txGood=72,rxGood=505,rxBad=2
DEBUG | 18:53:30 7274 [Router] rx_snr found. hop_limit:1 rx_snr:6.250000
DEBUG | 18:53:30 7274 [Router] rx_snr found in packet. Setting tx delay:1218
DEBUG | 18:53:30 7274 [Router] Delivering rx packet (id=0x6796d50b fr=0x25 to=0xff, WantAck=0, HopLim=2 Ch=0x0 Portnum=67 rxtime=1714589610 rxSNR=6.25 rxRSSI=-40 hopStart=3)
DEBUG | 18:53:30 7274 [Router] Update DB node 0x221f9c25, rx_time=1714589610
DEBUG | 18:53:30 7274 [Router] Forwarding to phone (id=0x6796d50b fr=0x25 to=0xff, WantAck=0, HopLim=2 Ch=0x0 Portnum=67 rxtime=1714589610 rxSNR=6.25 rxRSSI=-40 hopStart=3)
DEBUG | 18:53:30 7274 [Router] Module 'routing' considered
INFO  | 18:53:30 7274 Telling client we have new packets 1109
INFO  | 18:53:30 7274 BLE notify fromNum
INFO  | 18:53:30 7274 getFromRadio=STATE_SEND_PACKETS
DEBUG | 18:53:30 7274 phone downloaded packet (id=0x6796d50b fr=0x25 to=0xff, WantAck=0, HopLim=2 Ch=0x0 Portnum=67 rxtime=1714589610 rxSNR=6.25 rxRSSI=-40 hopStart=3)
DEBUG | 18:53:30 7274 encoding toPhone packet to phone variant=2, 76 bytes
DEBUG | 18:53:31 7276 [RadioIf] Starting low level send (id=0x6796d50b fr=0x25 to=0xff, WantAck=0, HopLim=1 Ch=0x8 encrypted rxtime=1714589610 rxSNR=6.25 rxRSSI=-40 hopStart=3 priority=64)
DEBUG | 18:53:31 7276 [RadioIf] (bw=250, sf=11, cr=4/5) packet symLen=8 ms, payloadSize=48, time 591 ms
DEBUG | 18:53:31 7276 [RadioIf] AirTime - Packet transmitted : 591ms
DEBUG | 18:53:32 7276 [RadioIf] Completed sending (id=0x6796d50b fr=0x25 to=0xff, WantAck=0, HopLim=1 Ch=0x8 encrypted rxtime=1714589610 rxSNR=6.25 rxRSSI=-40 hopStart=3 priority=64)
INFO  | 18:53:34 7278 [PowerTelemetryModule] (Sending): ch1_voltage=65.535004, ch1_current=0.000000, ch2_voltage=65.535004, ch2_current=0.000000, ch3_voltage=65.535004, ch3_current=0.000000
INFO  | 18:53:34 7278 [PowerTelemetryModule] Sending packet to phone
INFO  | 18:53:34 7278 Telling client we have new packets 1110
INFO  | 18:53:34 7278 BLE notify fromNum
INFO  | 18:53:34 7278 getFromRadio=STATE_SEND_PACKETS
DEBUG | 18:53:34 7278 phone downloaded packet (id=0x52bc91df fr=0x80 to=0xff, WantAck=0, HopLim=4 Ch=0x0 Portnum=67 rxtime=1714589614 priority=10)
DEBUG | 18:53:34 7278 encoding toPhone packet to phone variant=2, 54 bytes
INFO  | 18:53:34 7278 [EnvironmentTelemetryModule] (Sending): barometric_pressure=1012.343933, current=-0.100000, gas_resistance=204.739899, relative_humidity=27.971136, temperature=34.317326, voltage=4.152000
INFO  | 18:53:34 7278 [EnvironmentTelemetryModule] Sending packet to phone
INFO  | 18:53:34 7278 Telling client we have new packets 1111
INFO  | 18:53:34 7278 BLE notify fromNum
INFO  | 18:53:34 7279 getFromRadio=STATE_SEND_PACKETS
DEBUG | 18:53:34 7279 phone downloaded packet (id=0x52bc91e0 fr=0x80 to=0xff, WantAck=0, HopLim=4 Ch=0x0 Portnum=67 rxtime=1714589614 priority=10)
DEBUG | 18:53:34 7279 encoding toPhone packet to phone variant=2, 69 bytes
DEBUG | 18:53:35 7279 [RadioIf] (bw=250, sf=11, cr=4/5) packet symLen=8 ms, payloadSize=48, time 591 ms
DEBUG | 18:53:35 7279 [RadioIf] Lora RX (id=0x6796d50b fr=0x25 to=0xff, WantAck=0, HopLim=0 Ch=0x8 encrypted rxSNR=6 rxRSSI=-25 hopStart=3)
DEBUG | 18:53:35 7279 [RadioIf] AirTime - Packet received : 591ms
DEBUG | 18:53:35 7279 [Router] Found existing packet record for fr=0x221f9c25,to=0xffffffff,id=0x6796d50b
DEBUG | 18:53:35 7279 [Router] Found existing packet record for fr=0x221f9c25,to=0xffffffff,id=0x6796d50b
DEBUG | 18:53:35 7279 [Router] Add packet record (id=0x6796d50b fr=0x25 to=0xff, WantAck=0, HopLim=0 Ch=0x8 encrypted rxSNR=6 rxRSSI=-25 hopStart=3)
DEBUG | 18:53:35 7279 [Router] Ignoring incoming msg, because we've already seen it (id=0x6796d50b fr=0x25 to=0xff, WantAck=0, HopLim=0 Ch=0x8 encrypted rxSNR=6 rxRSSI=-25 hopStart=3)
DEBUG | 18:53:35 7279 [Router] cancelSending id=0x6796d50b, removed=0
DEBUG | 18:53:35 7279 [Router] Incoming message was filtered 0x221f9c25
INFO  | 18:53:37 7281 toRadioWriteCb data 0x2001c00a, len 16
DEBUG | 18:53:37 7281 PACKET FROM PHONE (id=0x00000000 fr=0x80 to=0x80, WantAck=0, HopLim=0 Ch=0x0 Portnum=3)
WARN  | 18:53:37 7281 phone tried to pick a nodenum, we don't allow that.
DEBUG | 18:53:37 7281 Enqueued local (id=0x52bc91e1 fr=0x00 to=0x80, WantAck=0, HopLim=0 Ch=0x0 Portnum=3 rxtime=1714589617)
INFO  | 18:53:37 7281 Telling client we have new packets 1112
INFO  | 18:53:37 7281 BLE notify fromNum
DEBUG | 18:53:37 7281 [Router] Add packet record (id=0x52bc91e1 fr=0x00 to=0x80, WantAck=0, HopLim=0 Ch=0x0 Portnum=3 rxtime=1714589617)
DEBUG | 18:53:37 7281 [Router] recentPackets size=91
DEBUG | 18:53:37 7281 [Router] recentPackets size=83 (after clearing expired packets)
DEBUG | 18:53:37 7281 [Router] handleReceived(REMOTE) (id=0x52bc91e1 fr=0x00 to=0x80, WantAck=0, HopLim=0 Ch=0x0 Portnum=3 rxtime=1714589617)
DEBUG | 18:53:37 7281 [Router] Module 'position' wantsPacket=1
INFO  | 18:53:37 7281 [Router] Received position from=0x0, id=0x52bc91e1, portnum=3, payloadlen=0
DEBUG | 18:53:37 7281 [Router] Incoming update from MYSELF
DEBUG | 18:53:37 7281 [Router] Setting local position: latitude=0, longitude=0, time=0
INFO  | 18:53:37 7281 [Router] POSITION node=743cd480 l=0 latI=0 lonI=0 msl=0 hae=0 geo=0 pdop=0 hdop=0 vdop=0 siv=0 fxq=0 fxt=0 pts=0 time=0
INFO  | 18:53:37 7281 [Router] updatePosition REMOTE node=0x743cd480 time=0, latI=0, lonI=0
DEBUG | 18:53:37 7281 [Router] Node status update: 17 online, 17 total
DEBUG | 18:53:37 7281 [Router] Module 'position' considered
DEBUG | 18:53:37 7281 [Router] Module 'routing' wantsPacket=1
INFO  | 18:53:37 7281 [Router] Received routing from=0x0, id=0x52bc91e1, portnum=3, payloadlen=0
DEBUG | 18:53:37 7281 [Router] Routing sniffing (id=0x52bc91e1 fr=0x00 to=0x80, WantAck=0, HopLim=0 Ch=0x0 Portnum=3 rxtime=1714589617)
DEBUG | 18:53:37 7281 [Router] Module 'routing' considered
INFO  | 18:53:37 7281 getFromRadio=STATE_SEND_PACKETS
DEBUG | 18:53:37 7281 encoding toPhone packet to phone variant=11, 12 bytes
DEBUG | 18:53:40 7285 [RadioIf] (bw=250, sf=11, cr=4/5) packet symLen=8 ms, payloadSize=48, time 591 ms
DEBUG | 18:53:40 7285 [RadioIf] Lora RX (id=0x2507cb0b fr=0x58 to=0xff, WantAck=0, HopLim=1 Ch=0x8 encrypted rxSNR=6 rxRSSI=-39 hopStart=3)
DEBUG | 18:53:40 7285 [RadioIf] AirTime - Packet received : 591ms
DEBUG | 18:53:40 7285 [Router] Add packet record (id=0x2507cb0b fr=0x58 to=0xff, WantAck=0, HopLim=1 Ch=0x8 encrypted rxSNR=6 rxRSSI=-39 hopStart=3)
DEBUG | 18:53:40 7285 [Router] Using channel 0 (hash 0x8)
DEBUG | 18:53:40 7285 [Router] Expanding short PSK #1
DEBUG | 18:53:40 7285 [Router] Using AES128 key!
DEBUG | 18:53:40 7285 [Router] nRF52 encrypt fr=562be058, num=2507cb0b, numBytes=32!
DEBUG | 18:53:41 7285 [Router] decoded message (id=0x2507cb0b fr=0x58 to=0xff, WantAck=0, HopLim=1 Ch=0x0 Portnum=67 rxtime=1714589620 rxSNR=6 rxRSSI=-39 hopStart=3)
DEBUG | 18:53:41 7285 [Router] handleReceived(REMOTE) (id=0x2507cb0b fr=0x58 to=0xff, WantAck=0, HopLim=1 Ch=0x0 Portnum=67 rxtime=1714589620 rxSNR=6 rxRSSI=-39 hopStart=3)
DEBUG | 18:53:41 7285 [Router] Module 'DeviceTelemetry' wantsPacket=1
INFO  | 18:53:41 7285 [Router] Received DeviceTelemetry from=0x562be058, id=0x2507cb0b, portnum=67, payloadlen=28
INFO  | 18:53:41 7285 [Router] (Received from CW02): air_util_tx=0.316250, channel_utilization=3.695000, battery_level=90, voltage=4.063000
DEBUG | 18:53:41 7285 [Router] updateTelemetry REMOTE node=0x562be058 
DEBUG | 18:53:41 7285 [Router] Node status update: 17 online, 17 total
DEBUG | 18:53:41 7285 [Router] Module 'DeviceTelemetry' considered
DEBUG | 18:53:41 7285 [Router] Module 'EnvironmentTelemetry' wantsPacket=1
INFO  | 18:53:41 7285 [Router] Received EnvironmentTelemetry from=0x562be058, id=0x2507cb0b, portnum=67, payloadlen=28
DEBUG | 18:53:41 7285 [Router] Module 'EnvironmentTelemetry' considered
DEBUG | 18:53:41 7285 [Router] Module 'PowerTelemetry' wantsPacket=1
INFO  | 18:53:41 7285 [Router] Received PowerTelemetry from=0x562be058, id=0x2507cb0b, portnum=67, payloadlen=28
DEBUG | 18:53:41 7285 [Router] Module 'PowerTelemetry' considered
DEBUG | 18:53:41 7285 [Router] Module 'routing' wantsPacket=1
INFO  | 18:53:41 7285 [Router] Received routing from=0x562be058, id=0x2507cb0b, portnum=67, payloadlen=28
DEBUG | 18:53:41 7285 [Router] Routing sniffing (id=0x2507cb0b fr=0x58 to=0xff, WantAck=0, HopLim=1 Ch=0x0 Portnum=67 rxtime=1714589620 rxSNR=6 rxRSSI=-39 hopStart=3)
INFO  | 18:53:41 7285 [Router] Rebroadcasting received floodmsg to neighbors
DEBUG | 18:53:41 7285 [Router] Expanding short PSK #1
DEBUG | 18:53:41 7285 [Router] Using AES128 key!
DEBUG | 18:53:41 7285 [Router] nRF52 encrypt fr=562be058, num=2507cb0b, numBytes=32!
DEBUG | 18:53:41 7285 [Router] enqueuing for send (id=0x2507cb0b fr=0x58 to=0xff, WantAck=0, HopLim=0 Ch=0x8 encrypted rxtime=1714589620 rxSNR=6 rxRSSI=-39 hopStart=3)
DEBUG | 18:53:41 7285 [Router] txGood=73,rxGood=507,rxBad=2
DEBUG | 18:53:41 7285 [Router] rx_snr found. hop_limit:0 rx_snr:6.000000
DEBUG | 18:53:41 7285 [Router] rx_snr found in packet. Setting tx delay:2772
DEBUG | 18:53:41 7285 [Router] Delivering rx packet (id=0x2507cb0b fr=0x58 to=0xff, WantAck=0, HopLim=1 Ch=0x0 Portnum=67 rxtime=1714589620 rxSNR=6 rxRSSI=-39 hopStart=3)
DEBUG | 18:53:41 7285 [Router] Update DB node 0x562be058, rx_time=1714589620
DEBUG | 18:53:41 7285 [Router] Forwarding to phone (id=0x2507cb0b fr=0x58 to=0xff, WantAck=0, HopLim=1 Ch=0x0 Portnum=67 rxtime=1714589620 rxSNR=6 rxRSSI=-39 hopStart=3)
DEBUG | 18:53:41 7285 [Router] Module 'routing' considered
INFO  | 18:53:41 7285 Telling client we have new packets 1113
INFO  | 18:53:41 7285 BLE notify fromNum
INFO  | 18:53:41 7285 getFromRadio=STATE_SEND_PACKETS
DEBUG | 18:53:41 7285 phone downloaded packet (id=0x2507cb0b fr=0x58 to=0xff, WantAck=0, HopLim=1 Ch=0x0 Portnum=67 rxtime=1714589620 rxSNR=6 rxRSSI=-39 hopStart=3)
DEBUG | 18:53:41 7285 encoding toPhone packet to phone variant=2, 76 bytes
DEBUG | 18:53:42 7286 [Power] Battery: usbPower=1, isCharging=1, batMv=3925, batPct=73
DEBUG | 18:53:42 7286 [RadioIf] (bw=250, sf=11, cr=4/5) packet symLen=8 ms, payloadSize=48, time 591 ms
DEBUG | 18:53:42 7286 [RadioIf] Lora RX (id=0x2507cb0b fr=0x58 to=0xff, WantAck=0, HopLim=0 Ch=0x8 encrypted rxSNR=6.25 rxRSSI=-25 hopStart=3)
DEBUG | 18:53:42 7286 [RadioIf] AirTime - Packet received : 591ms
DEBUG | 18:53:42 7286 [Router] Found existing packet record for fr=0x562be058,to=0xffffffff,id=0x2507cb0b
DEBUG | 18:53:42 7286 [Router] Found existing packet record for fr=0x562be058,to=0xffffffff,id=0x2507cb0b
DEBUG | 18:53:42 7286 [Router] Add packet record (id=0x2507cb0b fr=0x58 to=0xff, WantAck=0, HopLim=0 Ch=0x8 encrypted rxSNR=6.25 rxRSSI=-25 hopStart=3)
DEBUG | 18:53:42 7286 [Router] Ignoring incoming msg, because we've already seen it (id=0x2507cb0b fr=0x58 to=0xff, WantAck=0, HopLim=0 Ch=0x8 encrypted rxSNR=6.25 rxRSSI=-25 hopStart=3)
DEBUG | 18:53:42 7286 [Router] cancelSending id=0x2507cb0b, removed=1
DEBUG | 18:53:42 7286 [Router] Incoming message was filtered 0x562be058
INFO  | 18:53:57 7301 toRadioWriteCb data 0x2001c00a, len 16
DEBUG | 18:53:57 7301 PACKET FROM PHONE (id=0x00000000 fr=0x80 to=0x80, WantAck=0, HopLim=0 Ch=0x0 Portnum=3)
WARN  | 18:53:57 7301 phone tried to pick a nodenum, we don't allow that.
DEBUG | 18:53:57 7301 Enqueued local (id=0x52bc91e2 fr=0x00 to=0x80, WantAck=0, HopLim=0 Ch=0x0 Portnum=3 rxtime=1714589637)
INFO  | 18:53:57 7301 Telling client we have new packets 1114
INFO  | 18:53:57 7301 BLE notify fromNum
DEBUG | 18:53:57 7301 [Router] Add packet record (id=0x52bc91e2 fr=0x00 to=0x80, WantAck=0, HopLim=0 Ch=0x0 Portnum=3 rxtime=1714589637)
DEBUG | 18:53:57 7301 [Router] handleReceived(REMOTE) (id=0x52bc91e2 fr=0x00 to=0x80, WantAck=0, HopLim=0 Ch=0x0 Portnum=3 rxtime=1714589637)
DEBUG | 18:53:57 7301 [Router] Module 'position' wantsPacket=1
INFO  | 18:53:57 7301 [Router] Received position from=0x0, id=0x52bc91e2, portnum=3, payloadlen=0
DEBUG | 18:53:57 7301 [Router] Incoming update from MYSELF
DEBUG | 18:53:57 7301 [Router] Setting local position: latitude=0, longitude=0, time=0
INFO  | 18:53:57 7301 [Router] POSITION node=743cd480 l=0 latI=0 lonI=0 msl=0 hae=0 geo=0 pdop=0 hdop=0 vdop=0 siv=0 fxq=0 fxt=0 pts=0 time=0
INFO  | 18:53:57 7301 [Router] updatePosition REMOTE node=0x743cd480 time=0, latI=0, lonI=0
DEBUG | 18:53:57 7301 [Router] Node status update: 17 online, 17 total
DEBUG | 18:53:57 7301 [Router] Module 'position' considered
DEBUG | 18:53:57 7301 [Router] Module 'routing' wantsPacket=1
INFO  | 18:53:57 7301 [Router] Received routing from=0x0, id=0x52bc91e2, portnum=3, payloadlen=0
DEBUG | 18:53:57 7301 [Router] Routing sniffing (id=0x52bc91e2 fr=0x00 to=0x80, WantAck=0, HopLim=0 Ch=0x0 Portnum=3 rxtime=1714589637)
DEBUG | 18:53:57 7301 [Router] Module 'routing' considered
INFO  | 18:53:57 7301 getFromRadio=STATE_SEND_PACKETS
DEBUG | 18:53:57 7301 encoding toPhone packet to phone variant=11, 12 bytes
1 Like
4

Tracking this issue as a bug here 🐞 [Bug]: Power Metrics Telemetry not reported correctly for INA219BID · Issue #3820 · meshtastic/firmware · GitHub