Outbound queue not transmitted when syncing

Hi,

I have 2 message queues (data.qo and debug.qo). A note is queued in the data queue approximately every 2 hours. A note is also queued in the debug queue at the same time. When there are 2 or more notes in the data queue, a synchronization is forced. The notecard is in periodic mode with an output interval set to 4 h + 10%.

In the screenshot of the event log we can see that at 5h18, I received 2 notes from the data queue and 2 notes from the debug queue as expected but at 9h08, I received 2 notes from the data queue and nothing from the debug queue. It wasn’t until 9h46 that I got the debug queue notes even though the captured timestamp is earlier than the 9h08 sync time.

The 9h08 sync is a requested sync (because there were 2 notes in the data queue) and the 9h46 sync is an outgoing sync due.

Can we explain why the debug queue was not forwarded at 9h08?

Thanks

Hi,

The same problem occurred today with another device. This time, at 13h47 there is only an entry for the session queue and the notes for the data and debug queues have been transmitted at 15h43.

Hi @Alec ,

Sorry that it’s take a while to look into this. I’d like to reproduce this locally if I can. Couple questions:

  1. What is your initial hub.set command (without the product uid)?
  2. When you force a sync after you accumulate >= 2 notes, what command(s) are you using to do so?

Thanks,
Rob

Hi @RobLauer ,

The “hub.set” is done in 2 parts. First, I set the “mode” to “periodic” and after, the power manager code is doing another set for the “inbound” and “outbound” values based on the battery charge.

To force a sync, I set the parameter “sync” to true in the command “note.add”.

Note that I’m using 2 notecards for many months, both using GSM without any problem. Now, I have 8 devices at another location using Cat-M1 and I noticed the problem few times but most of the time, it works as expected…

Thanks

Hi @Alec,

Regarding the data.qo vs debug.qo Notefiles not syncing at the same time, a note.add with sync:true on a specific Notefile (data.qo) will not sync Notes on the other Notefile (debug.qo). Therefore, I would recommend using a hub.sync command to manually initiate a full sync with Notehub instead (i.e. to force all Notefiles to sync).

I’m guessing that between this and your periodic syncs is where you are seeing the disparities, but I’d love to know for sure that this is the case if you can test it out.

Thanks,
Rob

Hi @RobLauer

Are you sure syncing on a note.add will not sync the other notefile since it’s working most of the time (and it’s not a sync on periodic timeout) ? And also, in the second screenshot, the sync of 13h17 doesn’t sync the data queue even if there are 2 notes waiting…

I can however try it but it will take some time to prepare a new build.

Thanks,

Alain

Hey @Alec,

Just checked with the team here. As @RobLauer mentioned, setting sync: true on a note.add request only guarantees a sync of that individual file.

In most conditions syncing one note will also sync all other queued notes, but it’s not guaranteed. For example the Notecard could temporarily lose connection to Notehub.

I’m guessing that’s why your notes almost always sync at the same time, but occasionally have a bit of a time difference. I’d try hub.sync and see if that fixes the discrepancy.

Thanks,
TJ

Hi @tjvantoll ,

I understand now that syncing on a note.add will not guarantees that all note files will sync but what about the sync at 13h17 in the second screenshot (posted earlier)? No note is synced at all. Can it also be a temporarily connection problem with the Notehub ?

I will change for the hub.sync command in the next build.

Thanks

Almost a year later with a new hardware but the same logic:
2 messages each 2 hours and a sync request each 4 hours. The outbound timeout is 4h30. The sync is now done with the command “hub.sync” but similar problems are still occurring.

You can see below the normal behavior with lines 1 to 5:
2 messages at 8h (lines 1 and 2)
2 messages at 10h (line 3 and 4)
sync request at 10h (line 5)

later,
2 messages at 12h (lines 6 and 7)
2 messages at 14h (line 8 and 9)
sync request at 14h (line 10)

but the sync request synced nothing. The uploaded time of lines 6 to 9 is not 14h but 14h35, matching the time of a “periodic outbound sync” (line 12)

later,
2 messages at 16h (lines 13 and 14)
2 messages at 18h (line 15 and 16)
sync request at 18h (line 17)

but again, the sync request synced nothing as we can see with the uploaded time of the messages. Instead, there are 5 “periodic outbound sync” (lines 18 to 22) within 12 minutes having the last one finally syncing the messages (lines 13 to 16).

These useless syncs are a real problem for me since they drain the batteries (the blue event is before the event log capture).

I have the same problems with my 4 others devices. The notecard firmware version is 2.3.1.2014013.

@Alec what is the device UID of the device above, and are the times shown UTC ?
Thanks
Sean

Thanks @Alec - I’ll take a look on Notehub to see if I can find any diagnostics.

In the mean time there are two methods that could help to gather more diagnostics from the Notecard side.

If you set the environment variable “_log” to the value “all” the Notecard records events of interest in the _log.qo Notefile. This clearly uses extra data, but is easily disabled afterward by deleting the environment variable. The env var can be set and cleared on Notehub at the device, fleet or project level.

The seconds, and more invasive method to capture diagnostics via the Notecard’s AUX UART using the trace +req command, using a terminal emulator (115kbaud, 8N1). I’m not sure if you are familiar with this, and whether the AUX UART is accessible on your hardware. The AUX-EN pin would have to be pulled to 3v3 to enable the AUX UART.

The trace information will almost certainly pinpoint the root cause of the problem, if it is possible to capture that. The _log env var is helpful, but less likely to pinpoint the root cause.

I was able to find the sync session at 10/31 14:00 UTC. There is no error shown, but the sync appears to be truncated - that is the Notecard started, but did not complete the sync.

I did notice that the start of the sync shows that the Notecard is operating with a very low signal level:


2022-10-31T14:00:13Z e15eda77a3a8a2c1 Request #0 (445b json, 313b wire) <removed_for_privacy>,"J":"310,410,11302,187158287,-67,67,-102,-20,emtc","(debug.qo,data.qo)","T":"NOTE-NBGL500","U":2014013}

This shows the RSSI = -67dBm, RSRP= -102 RSRQ = -20. This is indicative of the device being at the very edge of the cell

Such low signals will tend to make syncs less reliable

Thanks @seant. Are there the same conditions for the sync at 17h59? And what about the outbound syncs at 19hxx?

I’ve set the variable _log for my fleet.

Thank you

The RSRP and RSRQ are low for most of the sessions I check in your Notecard’s log, including today:

2022-10-31T17:59:48Z 4551c69104963c8a Request #0 (444b json, 312b wire) <snip>"J":"310,410,11302,187158287,-66,82,-98,-18,emtc","N":4461,"O":15687,"Q":1667236451,"R":"face-up","S":"explicit sync request (debug.qo,data.qo)","T":"NOTE-NBGL500","U":2014013}

RSRP = -98, RSRQ = -18

2022-10-31T19:06:49Z 2797d29194bec2c0 Request #0 (449b json, 317b wire) <snip>,"J":"310,410,11302,187158287,-70,83,-99,-18,emtc","N":4462,"O":15750,"Q":1667236451,"R":"face-up","S":"periodic outbound sync due (debug.qo,data.qo)","T":"NOTE-NBGL500","U":2014013}

RSRP = -99, RSRQ = -18

2022-11-01T14:00:15Z 63dda23d9998d5f6 Request #0 (445b json, 312b wire) <snip>,"J":"310,410,11302,187158287,-65,71,-100,-20,emtc","N":4434,"O":14125,"Q":1667236451,"R":"face-up","S":"explicit sync request (debug.qo,data.qo)","T":"NOTE-NBGL500","U":2014013}

RSRP = -100, RSRQ = -20

Could you query {"req":"card.wireless"} from the Notecard (if it is nearby) since this will show more information, including the frequency band ?

I don’t have access to the device (1500km away). I will ask a guy on site if the device can be moved to see if the signal could be better.

Thank you