Web requests: sending images mostly fails

Troubleshooting
1

Hello,

I am trying to send jpeg images to the Notehub with web.post requests. This was working sometime ago, however as of (at least) today is not.
The weird thing is that I do not even see _web.qo events on the relevant device, this is not the issue with routing (at least from what I can see).

I am experiencing this problems in my main app code running on the nrf52840 and my sample code running on the PC host. There are some differences in the hardware connections and response behaviours of the web.post request.

Both app and sample code are using the same custom Zephyr driver using note-c library as base, however with different UART drivers.

Application

  • Communication is done via 9600 baud uart
  • Main uFL is connected to Molex’s cellular quad band patch antenna 146185
  • I am sending jpeg image in 1024 byte chunks.
  • Before sending I put notecard into continuous mode, wait for it to connect, request sync, wait for it to complete.

Response from the web.post request is most of the time {"total":X}, where X is a number that starts at 1 and increments with every request. Sometimes this number drops. "total" is not documented in the API.

I can vary the size of the image by changing jpeg compression:

  • At smaller image sizes (around 50 kB) I get through by sending all chunks, none of the responses have "err" field. There is no _web.qo event on the Notehub.
    There is no “_web.qo” event on the Notehub after that.
  • At bigger image sizes, above 120kB, I have same behavior as above, but at some point I get some memory errors:
[00:05:12.354,278] <err> note_help: {
        "err":  "cannot interpret JSON: cannot allocate 5360 bytes {memory} {io}"
}

or this (not complete string, I have written it from the memory):

[00:05:12.354,278] <err> note_help: {
        "err":  "file too large, ...."
}

Sample

  • Communication is done via 115200 baud uart
  • NOtecard is in placed in the Notecarrier-AF v1.7, main antenna is used
  • I am sending jpeg image in 1024 byte chunks.
  • Before sending I put notecard into continuous mode, wait for it to connect, request sync, wait for it to complete.

The behavior is mostly the same. It sometimes works, in that case the response is {"result": 100}.

Common code in both cases, the caller ensure that that chunks are always of the equal size, except the last one:

#define ENCODED_BUF_SIZE (1024 * 9)
struct context {
	char encoded_buf[ENCODED_BUF_SIZE];
	size_t offset;
	size_t total;
};

static struct context prv_ctx;

void streamer_prepare(size_t total)
{
	prv_ctx.total = total;
	prv_ctx.offset = 0;
}

int streamer_send(const void *data, size_t len)
{
	__ASSERT(ENCODED_BUF_SIZE >= JB64EncodeLen(len), "data too big to send");

	JB64Encode(prv_ctx.encoded_buf, data, len);

	J *req = NoteNewRequest("web.post");
	JAddStringToObject(req, "payload", prv_ctx.encoded_buf);
	JAddStringToObject(req, "route", "ImageRouter");
	JAddStringToObject(req, "name", "/notehub-images");
	JAddStringToObject(req, "content", "images/jpeg");
	JAddNumberToObject(req, "offset", prv_ctx.offset);
	JAddNumberToObject(req, "total", prv_ctx.total);
	JAddBoolToObject(req, "verify", true);

	int rc = notecard_helper_transaction_with_retry(req, 5);

	if (rc == 0) {
		prv_ctx.offset += len;
	}

	return rc;
}
  • Notecard version:
[00:00:10.156,341] <inf> cell: {
        "version":      "notecard-4.1.1.4015681",
        "device":       "dev:864475040539180",
        "name": "Blues Wireless Notecard",
        "sku":  "NOTE-NBGL-500",
        "board":        "1.11",
        "api":  4,
        "body": {
                "org":  "Blues Wireless",
                "product":      "Notecard",
                "version":      "notecard-4.1.1",
                "ver_major":    4,
                "ver_minor":    1,
                "ver_patch":    1,
                "ver_build":    4015681,
                "built":        "Dec  5 2022 12:54:58"
        }
}
2

Hi @MarkoSagadin,

I don’t see anything explicitly wrong in what you’ve laid out here. I do wonder though if your cellular connection is relatively weak - possibly leading to these posts “stacking up” on the Notecard and maxing out available memory (although the image sizes are so small, this shouldn’t be an issue).

Just a curiosity though, can you send me the results of {"req":"card.wireless"} just to see how robust your connection is?

Also, can you share your full code with me so I can try to reproduce this locally? Feel free to DM me here.

Thanks,
Rob

3

Hi Rob,

thats weird, reading through the documentation I would not expect that web.post requests can be temporary stored on the Notecard itself. I see that web.post requests that Notecard is connected to the Notehub, so that they are even accepted (I have seen that error before).

I now send card.wireless requests while sending image chunks.

Responses look almost identical all the time:

[00:02:32.286,773] <dbg> note: zephyr_log_print: {"apn":"teal","status":"{modem-on}","mode":"auto","count":4,"net":{"iccid":"89011703278306871198","imsi":"310170830687119","imei":"864475040539180","modem":"BG95M3LAR02A03_01.006.01.006","band":"GSM 1800","rat":"gsm","internal":true,"rssir":-57,"rssi":-58,"sinr":-20,"bars":4,"mcc":293,"mnc":41,"lac":39,"cid":2383,"updated":1686235292}}

Rssi and rssis can sometimes be: "rssir":-69,"rssi":-70

Your comment about requests being stored on the Notecard got me an idea that I can force another sync, after sending the image packets.

I wait for the sync to complete for 100 seconds.
Below is the complete log for that sync that happened after sending image chunks. Sync did not happen in that time, however after some time later (few minuts) image did came over Notehub.
Extra detail: After sending first hub.sync.statusthe reponse tells me that I am not connected.

[00:03:44.953,826] <inf> events: cellular_env_var_update_event
[00:03:44.953,826] <inf> schedular: New sampling interval same as old, not updating
[00:03:44.953,887] <inf> note_help: Starting sync, retry period 5000 ms
[00:03:44.954,132] <dbg> note: zephyr_log_print: {"req":"hub.sync","allow":true}
[00:03:45.009,338] <dbg> note: zephyr_log_print: {}
[00:03:45.009,704] <dbg> note: zephyr_log_print: {"req":"hub.status"}
[00:03:45.118,011] <dbg> note: zephyr_log_print: {"status":"idle (since 2023-06-08T14:40:49Z) {disconnected} {idle}"}
[00:03:45.118,103] <inf> note_help: hub status: idle (since 2023-06-08T14:40:49Z) {disconnected} {idle}
[00:03:45.118,164] <inf> note_help: Checking sync status
[00:03:45.118,286] <dbg> note: zephyr_log_print: {"req":"hub.sync.status"}
[00:03:45.204,956] <dbg> note: zephyr_log_print: {"sync":true,"requested":1}
[00:03:45.205,047] <inf> note_help: Not synced yet, 19 tries left
[00:03:50.205,139] <inf> note_help: Checking wireless connection
[00:03:50.205,352] <dbg> note: zephyr_log_print: {"req":"card.wireless"}
[00:03:51.683,929] <dbg> note: zephyr_log_print: {"apn":"teal","status":"{modem-off}","mode":"auto","count":4,"net":{"iccid":"89011703278306871198","imsi":"310170830687119","imei":"864475040539180","modem":"BG95M3LAR02A03_01.006.01.006","band":"GSM 1800","rat":"gsm","internal":true,"rssir":-57,"rssi":-58,"sinr":-20,"bars":4,"mcc":293,"mnc":41,"lac":39,"cid":2383,"updated":1686235292}}
[00:03:51.684,448] <dbg> note: zephyr_log_print: {"req":"hub.status"}
[00:03:51.792,724] <dbg> note: zephyr_log_print: {"status":"idle (since 2023-06-08T14:40:49Z) {disconnected} {idle}"}
[00:03:51.792,816] <inf> note_help: hub status: idle (since 2023-06-08T14:40:49Z) {disconnected} {idle}
[00:03:51.792,846] <inf> note_help: Checking sync status
[00:03:51.792,968] <dbg> note: zephyr_log_print: {"req":"hub.sync.status"}
[00:03:52.393,615] <dbg> note: zephyr_log_print: {"status":"disconnected (was {connected}) via close of notebox {notehub-disconnected}","sync":true,"requested":7}
[00:03:52.393,707] <inf> note_help: Not synced yet, 18 tries left
[00:03:57.393,798] <inf> note_help: Checking wireless connection
[00:03:57.394,012] <dbg> note: zephyr_log_print: {"req":"card.wireless"}
[00:03:57.806,182] <dbg> note: zephyr_log_print: {"apn":"teal","status":"{modem-on}","mode":"auto","count":4,"net":{"iccid":"89011703278306871198","imsi":"310170830687119","imei":"864475040539180","modem":"BG95M3LAR02A03_01.006.01.006","band":"GSM 1800","rat":"gsm","internal":true,"rssir":-57,"rssi":-58,"sinr":-20,"bars":4,"mcc":293,"mnc":41,"lac":39,"cid":2383,"updated":1686235292}}
[00:03:57.806,701] <dbg> note: zephyr_log_print: {"req":"hub.status"}
[00:03:57.912,902] <dbg> note: zephyr_log_print: {"status":"5s starting communications {wait-module} {connecting}"}
[00:03:57.912,963] <inf> note_help: hub status: 5s starting communications {wait-module} {connecting}
[00:03:57.913,024] <inf> note_help: Checking sync status
[00:03:57.913,146] <dbg> note: zephyr_log_print: {"req":"hub.sync.status"}
[00:03:58.037,689] <dbg> note: zephyr_log_print: {"status":"modem now ON {modem-on}","sync":true,"requested":12}
[00:03:58.037,780] <inf> note_help: Not synced yet, 17 tries left
[00:04:03.037,872] <inf> note_help: Checking wireless connection
[00:04:03.038,085] <dbg> note: zephyr_log_print: {"req":"card.wireless"}
[00:04:03.443,878] <dbg> note: zephyr_log_print: {"apn":"teal","status":"{modem-on}","mode":"auto","count":4,"net":{"iccid":"89011703278306871198","imsi":"310170830687119","imei":"864475040539180","modem":"BG95M3LAR02A03_01.006.01.006","band":"GSM 1800","rat":"gsm","internal":true,"rssir":-57,"rssi":-58,"sinr":-20,"bars":4,"mcc":293,"mnc":41,"lac":39,"cid":2383,"updated":1686235292}}
[00:04:03.444,366] <dbg> note: zephyr_log_print: {"req":"hub.status"}
[00:04:03.571,044] <dbg> note: zephyr_log_print: {"status":"4s waiting for wireless service {wait-service} {connecting}"}
[00:04:03.571,105] <inf> note_help: hub status: 4s waiting for wireless service {wait-service} {connecting}
[00:04:03.571,166] <inf> note_help: Checking sync status
[00:04:03.571,289] <dbg> note: zephyr_log_print: {"req":"hub.sync.status"}
[00:04:03.730,438] <dbg> note: zephyr_log_print: {"status":"waiting for wireless service {wait-service} {connecting}","sync":true,"requested":18}
[00:04:03.730,529] <inf> note_help: Not synced yet, 16 tries left
[00:04:08.730,590] <inf> note_help: Checking wireless connection
[00:04:08.730,804] <dbg> note: zephyr_log_print: {"req":"card.wireless"}
[00:04:09.182,708] <dbg> note: zephyr_log_print: {"apn":"teal","status":"{cell-registration-wait}","mode":"auto","count":4,"net":{"iccid":"89011703278306871198","imsi":"310170830687119","imei":"864475040539180","modem":"BG95M3LAR02A03_01.006.01.006","band":"GSM 1800","rat":"gsm","internal":true,"rssir":-57,"rssi":-58,"sinr":-20,"bars":4,"mcc":293,"mnc":41,"lac":39,"cid":2383,"updated":1686235292}}
[00:04:09.183,227] <dbg> note: zephyr_log_print: {"req":"hub.status"}
[00:04:09.296,752] <dbg> note: zephyr_log_print: {"status":"10s waiting for wireless service {wait-service} {connecting}"}
[00:04:09.296,844] <inf> note_help: hub status: 10s waiting for wireless service {wait-service} {connecting}
[00:04:09.296,875] <inf> note_help: Checking sync status
[00:04:09.296,997] <dbg> note: zephyr_log_print: {"req":"hub.sync.status"}
[00:04:09.466,583] <dbg> note: zephyr_log_print: {"status":"waiting for wireless service 2 sec [----] {cell-registration-wait}","sync":true,"requested":24}
[00:04:09.466,705] <inf> note_help: Not synced yet, 15 tries left
[00:04:14.466,766] <inf> note_help: Checking wireless connection
[00:04:14.466,979] <dbg> note: zephyr_log_print: {"req":"card.wireless"}
[00:04:14.893,432] <dbg> note: zephyr_log_print: {"apn":"teal","status":"{cell-registration-wait}","mode":"auto","count":4,"net":{"iccid":"89011703278306871198","imsi":"310170830687119","imei":"864475040539180","modem":"BG95M3LAR02A03_01.006.01.006","band":"GSM 1800","rat":"gsm","internal":true,"rssir":-57,"rssi":-48,"sinr":-20,"bars":4,"mcc":293,"mnc":41,"lac":39,"cid":12233,"updated":1686235430}}
[00:04:14.893,951] <dbg> note: zephyr_log_print: {"req":"hub.status"}
[00:04:15.007,568] <dbg> note: zephyr_log_print: {"status":"15s waiting for wireless service {wait-service} {connecting}"}
[00:04:15.007,629] <inf> note_help: hub status: 15s waiting for wireless service {wait-service} {connecting}
[00:04:15.007,690] <inf> note_help: Checking sync status
[00:04:15.007,812] <dbg> note: zephyr_log_print: {"req":"hub.sync.status"}
[00:04:15.177,429] <dbg> note: zephyr_log_print: {"status":"waiting for wireless service 8 sec [++++] {cell-registration-wait}","sync":true,"requested":29}
[00:04:15.177,520] <inf> note_help: Not synced yet, 14 tries left
[00:04:20.177,612] <inf> note_help: Checking wireless connection
[00:04:20.177,825] <dbg> note: zephyr_log_print: {"req":"card.wireless"}
[00:04:20.610,809] <dbg> note: zephyr_log_print: {"apn":"teal","status":"{cell-registration-wait}","mode":"auto","count":4,"net":{"iccid":"89011703278306871198","imsi":"310170830687119","imei":"864475040539180","modem":"BG95M3LAR02A03_01.006.01.006","band":"GSM 1800","rat":"gsm","internal":true,"rssir":-57,"rssi":-48,"sinr":-20,"bars":4,"mcc":293,"mnc":41,"lac":39,"cid":12233,"updated":1686235430}}
[00:04:20.611,328] <dbg> note: zephyr_log_print: {"req":"hub.status"}
[00:04:20.724,884] <dbg> note: zephyr_log_print: {"status":"21s waiting for wireless service {wait-service} {connecting}"}
[00:04:20.724,975] <inf> note_help: hub status: 21s waiting for wireless service {wait-service} {connecting}
[00:04:20.725,006] <inf> note_help: Checking sync status
[00:04:20.725,128] <dbg> note: zephyr_log_print: {"req":"hub.sync.status"}
[00:04:20.898,681] <dbg> note: zephyr_log_print: {"status":"waiting for wireless service 13 sec [++++] {cell-registration-wait}","sync":true,"requested":35}
[00:04:20.898,773] <inf> note_help: Not synced yet, 13 tries left
[00:04:25.898,834] <inf> note_help: Checking wireless connection
[00:04:25.899,047] <dbg> note: zephyr_log_print: {"req":"card.wireless"}
[00:04:26.302,825] <dbg> note: zephyr_log_print: {"apn":"teal","status":"{network-up}","mode":"auto","count":4,"net":{"iccid":"89011703278306871198","imsi":"310170830687119","imei":"864475040539180","modem":"BG95M3LAR02A03_01.006.01.006","band":"GSM 900","rat":"gsm","internal":true,"rssir":-69,"rssi":-70,"sinr":-20,"bars":4,"mcc":293,"mnc":41,"lac":39,"cid":12233,"updated":1686235442}}
[00:04:26.303,344] <dbg> note: zephyr_log_print: {"req":"hub.status"}
[00:04:26.391,754] <dbg> note: zephyr_log_print: {"status":"connected (session open) {connected}"}
[00:04:26.391,815] <inf> note_help: hub status: connected (session open) {connected}
[00:04:26.391,876] <inf> note_help: Checking sync status
[00:04:26.391,998] <dbg> note: zephyr_log_print: {"req":"hub.sync.status"}
[00:04:26.559,478] <dbg> note: zephyr_log_print: {"status":"IP connect: waiting for connection for 0 sec (sent:167 rcvd:203)","sync":true,"requested":41}
[00:04:26.559,570] <inf> note_help: Not synced yet, 12 tries left
[00:04:31.559,661] <inf> note_help: Checking wireless connection
[00:04:31.559,875] <dbg> note: zephyr_log_print: {"req":"card.wireless"}
[00:04:31.965,759] <dbg> note: zephyr_log_print: {"apn":"teal","status":"{network-up}","mode":"auto","count":4,"net":{"iccid":"89011703278306871198","imsi":"310170830687119","imei":"864475040539180","modem":"BG95M3LAR02A03_01.006.01.006","band":"GSM 900","rat":"gsm","internal":true,"rssir":-69,"rssi":-70,"sinr":-20,"bars":4,"mcc":293,"mnc":41,"lac":39,"cid":12233,"updated":1686235442}}
[00:04:31.966,278] <dbg> note: zephyr_log_print: {"req":"hub.status"}
[00:04:32.054,718] <dbg> note: zephyr_log_print: {"status":"connected (session open) {connected}"}
[00:04:32.054,809] <inf> note_help: hub status: connected (session open) {connected}
[00:04:32.054,840] <inf> note_help: Checking sync status
[00:04:32.054,962] <dbg> note: zephyr_log_print: {"req":"hub.sync.status"}
[00:04:32.218,200] <dbg> note: zephyr_log_print: {"status":"IP connect: waiting for connection for 6 sec (sent:0 rcvd:0)","sync":true,"requested":46}
[00:04:32.218,322] <inf> note_help: Not synced yet, 11 tries left
[00:04:37.218,383] <inf> note_help: Checking wireless connection
[00:04:37.218,597] <dbg> note: zephyr_log_print: {"req":"card.wireless"}
[00:04:37.624,694] <dbg> note: zephyr_log_print: {"apn":"teal","status":"{network-up}","mode":"auto","count":4,"net":{"iccid":"89011703278306871198","imsi":"310170830687119","imei":"864475040539180","modem":"BG95M3LAR02A03_01.006.01.006","band":"GSM 900","rat":"gsm","internal":true,"rssir":-69,"rssi":-70,"sinr":-20,"bars":4,"mcc":293,"mnc":41,"lac":39,"cid":12233,"updated":1686235442}}
[00:04:37.625,213] <dbg> note: zephyr_log_print: {"req":"hub.status"}
[00:04:37.713,653] <dbg> note: zephyr_log_print: {"status":"connected (session open) {connected}"}
[00:04:37.713,714] <inf> note_help: hub status: connected (session open) {connected}
[00:04:37.713,775] <inf> note_help: Checking sync status
[00:04:37.713,897] <dbg> note: zephyr_log_print: {"req":"hub.sync.status"}
[00:04:37.878,204] <dbg> note: zephyr_log_print: {"status":"IP connect: waiting for connection for 11 sec (sent:0 rcvd:0)","sync":true,"requested":52}
[00:04:37.878,295] <inf> note_help: Not synced yet, 10 tries left
[00:04:42.878,387] <inf> note_help: Checking wireless connection
[00:04:42.878,601] <dbg> note: zephyr_log_print: {"req":"card.wireless"}
[00:04:43.284,606] <dbg> note: zephyr_log_print: {"apn":"teal","status":"{network-up}","mode":"auto","count":4,"net":{"iccid":"89011703278306871198","imsi":"310170830687119","imei":"864475040539180","modem":"BG95M3LAR02A03_01.006.01.006","band":"GSM 900","rat":"gsm","internal":true,"rssir":-69,"rssi":-70,"sinr":-20,"bars":4,"mcc":293,"mnc":41,"lac":39,"cid":12233,"updated":1686235442}}
[00:04:43.285,125] <dbg> note: zephyr_log_print: {"req":"hub.status"}
[00:04:43.373,565] <dbg> note: zephyr_log_print: {"status":"connected (session open) {connected}"}
[00:04:43.373,657] <inf> note_help: hub status: connected (session open) {connected}
[00:04:43.373,687] <inf> note_help: Checking sync status
[00:04:43.373,840] <dbg> note: zephyr_log_print: {"req":"hub.sync.status"}
[00:04:43.538,177] <dbg> note: zephyr_log_print: {"status":"IP connect: waiting for connection for 18 sec (sent:0 rcvd:0)","sync":true,"requested":58}
[00:04:43.538,299] <inf> note_help: Not synced yet, 9 tries left
[00:04:48.538,360] <inf> note_help: Checking wireless connection
[00:04:48.538,574] <dbg> note: zephyr_log_print: {"req":"card.wireless"}
[00:04:48.947,479] <dbg> note: zephyr_log_print: {"apn":"teal","status":"{network-up}","mode":"auto","count":4,"net":{"iccid":"89011703278306871198","imsi":"310170830687119","imei":"864475040539180","modem":"BG95M3LAR02A03_01.006.01.006","band":"GSM 900","rat":"gsm","internal":true,"rssir":-69,"rssi":-70,"sinr":-20,"bars":4,"mcc":293,"mnc":41,"lac":39,"cid":12233,"updated":1686235442}}
[00:04:48.947,998] <dbg> note: zephyr_log_print: {"req":"hub.status"}
[00:04:49.036,468] <dbg> note: zephyr_log_print: {"status":"connected (session open) {connected}"}
[00:04:49.036,529] <inf> note_help: hub status: connected (session open) {connected}
[00:04:49.036,590] <inf> note_help: Checking sync status
[00:04:49.036,712] <dbg> note: zephyr_log_print: {"req":"hub.sync.status"}
[00:04:49.201,049] <dbg> note: zephyr_log_print: {"status":"IP connect: waiting for connection for 24 sec (sent:0 rcvd:0)","sync":true,"requested":63}
[00:04:49.201,141] <inf> note_help: Not synced yet, 8 tries left
[00:04:54.201,232] <inf> note_help: Checking wireless connection
[00:04:54.201,446] <dbg> note: zephyr_log_print: {"req":"card.wireless"}
[00:04:54.607,543] <dbg> note: zephyr_log_print: {"apn":"teal","status":"{network-up}","mode":"auto","count":4,"net":{"iccid":"89011703278306871198","imsi":"310170830687119","imei":"864475040539180","modem":"BG95M3LAR02A03_01.006.01.006","band":"GSM 900","rat":"gsm","internal":true,"rssir":-69,"rssi":-70,"sinr":-20,"bars":4,"mcc":293,"mnc":41,"lac":39,"cid":12233,"updated":1686235442}}
[00:04:54.608,062] <dbg> note: zephyr_log_print: {"req":"hub.status"}
[00:04:54.696,441] <dbg> note: zephyr_log_print: {"status":"connected (session open) {connected}"}
[00:04:54.696,533] <inf> note_help: hub status: connected (session open) {connected}
[00:04:54.696,563] <inf> note_help: Checking sync status
[00:04:54.696,716] <dbg> note: zephyr_log_print: {"req":"hub.sync.status"}
[00:04:54.860,992] <dbg> note: zephyr_log_print: {"status":"IP connect: waiting for connection for 29 sec (sent:0 rcvd:0)","sync":true,"requested":69}
[00:04:54.861,114] <inf> note_help: Not synced yet, 7 tries left
[00:04:59.861,175] <inf> note_help: Checking wireless connection
[00:04:59.861,389] <dbg> note: zephyr_log_print: {"req":"card.wireless"}
[00:05:00.267,913] <dbg> note: zephyr_log_print: {"apn":"teal","status":"{network-up}","mode":"auto","count":4,"net":{"iccid":"89011703278306871198","imsi":"310170830687119","imei":"864475040539180","modem":"BG95M3LAR02A03_01.006.01.006","band":"GSM 900","rat":"gsm","internal":true,"rssir":-69,"rssi":-70,"sinr":-20,"bars":4,"mcc":293,"mnc":41,"lac":39,"cid":12233,"updated":1686235442}}
[00:05:00.268,432] <dbg> note: zephyr_log_print: {"req":"hub.status"}
[00:05:00.356,964] <dbg> note: zephyr_log_print: {"status":"connected (session open) {connected}"}
[00:05:00.357,055] <inf> note_help: hub status: connected (session open) {connected}
[00:05:00.357,086] <inf> note_help: Checking sync status
[00:05:00.357,208] <dbg> note: zephyr_log_print: {"req":"hub.sync.status"}
[00:05:00.521,606] <dbg> note: zephyr_log_print: {"status":"IP connect: waiting for connection for 35 sec (sent:0 rcvd:0)","sync":true,"requested":75}
[00:05:00.521,697] <inf> note_help: Not synced yet, 6 tries left
[00:05:05.521,789] <inf> note_help: Checking wireless connection
[00:05:05.522,003] <dbg> note: zephyr_log_print: {"req":"card.wireless"}
[00:05:05.928,344] <dbg> note: zephyr_log_print: {"apn":"teal","status":"{network-up}","mode":"auto","count":4,"net":{"iccid":"89011703278306871198","imsi":"310170830687119","imei":"864475040539180","modem":"BG95M3LAR02A03_01.006.01.006","band":"GSM 900","rat":"gsm","internal":true,"rssir":-69,"rssi":-70,"sinr":-20,"bars":4,"mcc":293,"mnc":41,"lac":39,"cid":12233,"updated":1686235442}}
[00:05:05.928,863] <dbg> note: zephyr_log_print: {"req":"hub.status"}
[00:05:06.017,242] <dbg> note: zephyr_log_print: {"status":"connected (session open) {connected}"}
[00:05:06.017,333] <inf> note_help: hub status: connected (session open) {connected}
[00:05:06.017,364] <inf> note_help: Checking sync status
[00:05:06.017,486] <dbg> note: zephyr_log_print: {"req":"hub.sync.status"}
[00:05:06.181,915] <dbg> note: zephyr_log_print: {"status":"IP connect: waiting for connection for 40 sec (sent:0 rcvd:0)","sync":true,"requested":80}
[00:05:06.182,037] <inf> note_help: Not synced yet, 5 tries left
[00:05:11.182,098] <inf> note_help: Checking wireless connection
[00:05:11.182,312] <dbg> note: zephyr_log_print: {"req":"card.wireless"}
[00:05:11.588,287] <dbg> note: zephyr_log_print: {"apn":"teal","status":"{network-up}","mode":"auto","count":4,"net":{"iccid":"89011703278306871198","imsi":"310170830687119","imei":"864475040539180","modem":"BG95M3LAR02A03_01.006.01.006","band":"GSM 900","rat":"gsm","internal":true,"rssir":-69,"rssi":-70,"sinr":-20,"bars":4,"mcc":293,"mnc":41,"lac":39,"cid":12233,"updated":1686235442}}
[00:05:11.588,806] <dbg> note: zephyr_log_print: {"req":"hub.status"}
[00:05:11.677,185] <dbg> note: zephyr_log_print: {"status":"connected (session open) {connected}"}
[00:05:11.677,246] <inf> note_help: hub status: connected (session open) {connected}
[00:05:11.677,307] <inf> note_help: Checking sync status
[00:05:11.677,429] <dbg> note: zephyr_log_print: {"req":"hub.sync.status"}
[00:05:11.841,796] <dbg> note: zephyr_log_print: {"status":"IP connect: waiting for connection for 46 sec (sent:0 rcvd:0)","sync":true,"requested":86}
[00:05:11.841,888] <inf> note_help: Not synced yet, 4 tries left
[00:05:16.841,979] <inf> note_help: Checking wireless connection
[00:05:16.842,193] <dbg> note: zephyr_log_print: {"req":"card.wireless"}
[00:05:17.248,199] <dbg> note: zephyr_log_print: {"apn":"teal","status":"{network-up}","mode":"auto","count":4,"net":{"iccid":"89011703278306871198","imsi":"310170830687119","imei":"864475040539180","modem":"BG95M3LAR02A03_01.006.01.006","band":"GSM 900","rat":"gsm","internal":true,"rssir":-69,"rssi":-70,"sinr":-20,"bars":4,"mcc":293,"mnc":41,"lac":39,"cid":12233,"updated":1686235442}}
[00:05:17.248,718] <dbg> note: zephyr_log_print: {"req":"hub.status"}
[00:05:17.337,127] <dbg> note: zephyr_log_print: {"status":"connected (session open) {connected}"}
[00:05:17.337,219] <inf> note_help: hub status: connected (session open) {connected}
[00:05:17.337,249] <inf> note_help: Checking sync status
[00:05:17.337,371] <dbg> note: zephyr_log_print: {"req":"hub.sync.status"}
[00:05:17.501,770] <dbg> note: zephyr_log_print: {"status":"IP connect: waiting for connection for 52 sec (sent:0 rcvd:0)","sync":true,"requested":92}
[00:05:17.501,892] <inf> note_help: Not synced yet, 3 tries left
[00:05:22.501,953] <inf> note_help: Checking wireless connection
[00:05:22.502,166] <dbg> note: zephyr_log_print: {"req":"card.wireless"}
[00:05:22.908,142] <dbg> note: zephyr_log_print: {"apn":"teal","status":"{network-up}","mode":"auto","count":4,"net":{"iccid":"89011703278306871198","imsi":"310170830687119","imei":"864475040539180","modem":"BG95M3LAR02A03_01.006.01.006","band":"GSM 900","rat":"gsm","internal":true,"rssir":-69,"rssi":-70,"sinr":-20,"bars":4,"mcc":293,"mnc":41,"lac":39,"cid":12233,"updated":1686235442}}
[00:05:22.908,660] <dbg> note: zephyr_log_print: {"req":"hub.status"}
[00:05:22.997,131] <dbg> note: zephyr_log_print: {"status":"connected (session open) {connected}"}
[00:05:22.997,222] <inf> note_help: hub status: connected (session open) {connected}
[00:05:22.997,253] <inf> note_help: Checking sync status
[00:05:22.997,375] <dbg> note: zephyr_log_print: {"req":"hub.sync.status"}
[00:05:23.161,682] <dbg> note: zephyr_log_print: {"status":"IP connect: waiting for connection for 57 sec (sent:0 rcvd:0)","sync":true,"requested":97}
[00:05:23.161,773] <inf> note_help: Not synced yet, 2 tries left
[00:05:28.161,865] <inf> note_help: Checking wireless connection
[00:05:28.162,078] <dbg> note: zephyr_log_print: {"req":"card.wireless"}
[00:05:28.568,054] <dbg> note: zephyr_log_print: {"apn":"teal","status":"{network-up}","mode":"auto","count":4,"net":{"iccid":"89011703278306871198","imsi":"310170830687119","imei":"864475040539180","modem":"BG95M3LAR02A03_01.006.01.006","band":"GSM 900","rat":"gsm","internal":true,"rssir":-69,"rssi":-70,"sinr":-20,"bars":4,"mcc":293,"mnc":41,"lac":39,"cid":12233,"updated":1686235442}}
[00:05:28.568,572] <dbg> note: zephyr_log_print: {"req":"hub.status"}
[00:05:28.656,982] <dbg> note: zephyr_log_print: {"status":"connected (session open) {connected}"}
[00:05:28.657,073] <inf> note_help: hub status: connected (session open) {connected}
[00:05:28.657,104] <inf> note_help: Checking sync status
[00:05:28.657,226] <dbg> note: zephyr_log_print: {"req":"hub.sync.status"}
[00:05:28.822,662] <dbg> note: zephyr_log_print: {"status":"IP connect: waiting for connection for 63 sec (sent:0 rcvd:0)","sync":true,"requested":103}
[00:05:28.822,784] <inf> note_help: Not synced yet, 1 tries left
[00:05:33.822,845] <inf> note_help: Checking wireless connection
[00:05:33.823,059] <dbg> note: zephyr_log_print: {"req":"card.wireless"}
[00:05:34.229,003] <dbg> note: zephyr_log_print: {"apn":"teal","status":"{network-up}","mode":"auto","count":4,"net":{"iccid":"89011703278306871198","imsi":"310170830687119","imei":"864475040539180","modem":"BG95M3LAR02A03_01.006.01.006","band":"GSM 900","rat":"gsm","internal":true,"rssir":-69,"rssi":-70,"sinr":-20,"bars":4,"mcc":293,"mnc":41,"lac":39,"cid":12233,"updated":1686235442}}
[00:05:34.229,522] <dbg> note: zephyr_log_print: {"req":"hub.status"}
[00:05:34.317,962] <dbg> note: zephyr_log_print: {"status":"connected (session open) {connected}"}
[00:05:34.318,023] <inf> note_help: hub status: connected (session open) {connected}
[00:05:34.318,084] <inf> note_help: Checking sync status
[00:05:34.318,206] <dbg> note: zephyr_log_print: {"req":"hub.sync.status"}
[00:05:34.483,581] <dbg> note: zephyr_log_print: {"status":"IP connect: waiting for connection for 68 sec (sent:0 rcvd:0)","sync":true,"requested":109}
[00:05:34.483,673] <inf> note_help: Not synced yet, 0 tries left
[00:05:39.483,764] <inf> note_help: Checking wireless connection
[00:05:39.483,978] <dbg> note: zephyr_log_print: {"req":"card.wireless"}
[00:05:39.889,923] <dbg> note: zephyr_log_print: {"apn":"teal","status":"{network-up}","mode":"auto","count":4,"net":{"iccid":"89011703278306871198","imsi":"310170830687119","imei":"864475040539180","modem":"BG95M3LAR02A03_01.006.01.006","band":"GSM 900","rat":"gsm","internal":true,"rssir":-69,"rssi":-70,"sinr":-20,"bars":4,"mcc":293,"mnc":41,"lac":39,"cid":12233,"updated":1686235442}}
[00:05:39.890,380] <err> cell: Could not sync notes, skipping image
[00:05:39.890,686] <dbg> note: zephyr_log_print: {"req":"hub.set","mode":"periodic"}
[00:05:40.236,755] <dbg> note: zephyr_log_print: {}

Regarding the bug reproduction: I need to discuss this internally.