gauteh / sfy

🌊 A lightweight wave buoy for near-shore deployments.
MIT License
39 stars 6 forks source link

Possible deadlock: panic-loop or critical-section deadlock #84

Closed gauteh closed 1 year ago

gauteh commented 1 year ago

❯ make gdb-debug
gdb-multiarch --command=debug.gdb target/thumbv7em-none-eabihf/debug/sfy-artemis
GNU gdb (Ubuntu 8.1.1-0ubuntu1) 8.1.1
Copyright (C) 2018 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.  Type "show copying"
and "show warranty" for details.
This GDB was configured as "x86_64-linux-gnu".
Type "show configuration" for configuration details.
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>.
Find the GDB manual and other documentation resources online at:
<http://www.gnu.org/software/gdb/documentation/>.
For help, type "help".
Type "apropos word" to search for commands related to "word"...
Reading symbols from target/thumbv7em-none-eabihf/debug/sfy-artemis...done.
critical_section::_critical_section_acquire () at src/lib.rs:111
111             unsafe fn _critical_section_acquire() -> u8 {
Attaching to GDB server for RTT | defmt output..
(gdb) l
106                     }
107                 };
108             }
109         } else if #[cfg(cortex_m)] {
110             #[no_mangle]
111             unsafe fn _critical_section_acquire() -> u8 {
112                 let primask = cortex_m::register::primask::read();
113                 cortex_m::interrupt::disable();
114                 primask.is_active() as _
115             }
(gdb) l
116
117             #[no_mangle]
118             unsafe fn _critical_section_release(token: u8) {
119                 if token != 0 {
120                     cortex_m::interrupt::enable()
121                 }
122             }
123         } else if #[cfg(target_arch = "avr")] {
124             #[no_mangle]
125             unsafe fn _critical_section_acquire() -> u8 {
(gdb) c
Continuing.

Program received signal SIGTRAP, Trace/breakpoint trap.
critical_section::_critical_section_acquire () at src/lib.rs:111
111             unsafe fn _critical_section_acquire() -> u8 {
(gdb) c
Continuing.

Program received signal SIGTRAP, Trace/breakpoint trap.
critical_section::_critical_section_acquire () at src/lib.rs:111
111             unsafe fn _critical_section_acquire() -> u8 {
(gdb) r
The program being debugged has been started already.
Start it from the beginning? (y or n) n
Program not restarted.
(gdb) l
106                     }
107                 };
108             }
109         } else if #[cfg(cortex_m)] {
110             #[no_mangle]
111             unsafe fn _critical_section_acquire() -> u8 {
112                 let primask = cortex_m::register::primask::read();
113                 cortex_m::interrupt::disable();
114                 primask.is_active() as _
115             }
(gdb) p
The history is empty.
(gdb) l
116
117             #[no_mangle]
118             unsafe fn _critical_section_release(token: u8) {
119                 if token != 0 {
120                     cortex_m::interrupt::enable()
121                 }
122             }
123         } else if #[cfg(target_arch = "avr")] {
124             #[no_mangle]
125             unsafe fn _critical_section_acquire() -> u8 {
(gdb) l
126                 let mut sreg: u8;
127                 llvm_asm!(
128                     "in $0, 0x3F
129                      cli"
130                     : "=r"(sreg)
131                     ::: "volatile"
132                 );
133                 sreg
134             }
135
(gdb) l
136             #[no_mangle]
137             unsafe fn _critical_section_release(token: u8) {
138                 if token & 0x80 == 0x80 {
139                     llvm_asm!("sei" :::: "volatile");
140                 }
141             }
142         } else if #[cfg(target_arch = "riscv32")] {
143             #[no_mangle]
144             unsafe fn _critical_section_acquire() -> u8 {
145                 let interrupts_active = riscv::register::mstatus::read().mie();
(gdb) where
#0  critical_section::_critical_section_acquire () at src/lib.rs:111
#1  0x0003bcb0 in critical_section::acquire () at src/lib.rs:46
#2  <defmt_rtt::Logger as defmt::traits::Logger>::acquire () at src/lib.rs:46
#3  defmt_rtt::_defmt_acquire () at src/lib.rs:35
#4  0x000195c6 in defmt::export::acquire ()
    at /home/gauteh/.cargo/registry/src/github.com-1ecc6299db9ec823/defmt-0.3.2/src/export/mod.rs:55
#5  rust_begin_unwind (info=0x10000154 <sfy_artemis::IMU+84>) at sfy-artemis/src/main.rs:438
#6  0x000425ee in core::panicking::panic_fmt () at library/core/src/panicking.rs:142
#7  0x0003bd5a in <defmt_rtt::Logger as defmt::traits::Logger>::acquire () at src/lib.rs:49
#8  defmt_rtt::_defmt_acquire () at src/lib.rs:35
#9  0x000195c6 in defmt::export::acquire ()
    at /home/gauteh/.cargo/registry/src/github.com-1ecc6299db9ec823/defmt-0.3.2/src/export/mod.rs:55
#10 rust_begin_unwind (info=0x10000154 <sfy_artemis::IMU+84>) at sfy-artemis/src/main.rs:438
#11 0x000425ee in core::panicking::panic_fmt () at library/core/src/panicking.rs:142
#12 0x0003bd5a in <defmt_rtt::Logger as defmt::traits::Logger>::acquire () at src/lib.rs:49
#13 defmt_rtt::_defmt_acquire () at src/lib.rs:35
#14 0x000195c6 in defmt::export::acquire ()
    at /home/gauteh/.cargo/registry/src/github.com-1ecc6299db9ec823/defmt-0.3.2/src/export/mod.rs:55
#15 rust_begin_unwind (info=0x10000154 <sfy_artemis::IMU+84>) at sfy-artemis/src/main.rs:438
#16 0x000425ee in core::panicking::panic_fmt () at library/core/src/panicking.rs:142
#17 0x0003bd5a in <defmt_rtt::Logger as defmt::traits::Logger>::acquire () at src/lib.rs:49
#18 defmt_rtt::_defmt_acquire () at src/lib.rs:35
#19 0x000195c6 in defmt::export::acquire ()
    at /home/gauteh/.cargo/registry/src/github.com-1ecc6299db9ec823/defmt-0.3.2/src/export/mod.rs:55
#20 rust_begin_unwind (info=0x10000154 <sfy_artemis::IMU+84>) at sfy-artemis/src/main.rs:438
#21 0x000425ee in core::panicking::panic_fmt () at library/core/src/panicking.rs:142
#22 0x0003bd5a in <defmt_rtt::Logger as defmt::traits::Logger>::acquire () at src/lib.rs:49
#23 defmt_rtt::_defmt_acquire () at src/lib.rs:35
#24 0x000195c6 in defmt::export::acquire ()
    at /home/gauteh/.cargo/registry/src/github.com-1ecc6299db9ec823/defmt-0.3.2/src/export/mod.rs:55
#25 rust_begin_unwind (info=0x10000154 <sfy_artemis::IMU+84>) at sfy-artemis/src/main.rs:438
#26 0x000425ee in core::panicking::panic_fmt () at library/core/src/panicking.rs:142
#27 0x0003bd5a in <defmt_rtt::Logger as defmt::traits::Logger>::acquire () at src/lib.rs:49
#28 defmt_rtt::_defmt_acquire () at src/lib.rs:35
---Type <return> to continue, or q <return> to quit---
#29 0x000195c6 in defmt::export::acquire ()
    at /home/gauteh/.cargo/registry/src/github.com-1ecc6299db9ec823/defmt-0.3.2/src/export/mod.rs:55
#30 rust_begin_unwind (info=0x10000154 <sfy_artemis::IMU+84>) at sfy-artemis/src/main.rs:438
#31 0x000425ee in core::panicking::panic_fmt () at library/core/src/panicking.rs:142
(gdb) r
The program being debugged has been started already.
Start it from the beginning? (y or n) y
Starting program: /home/gauteh/met/sfy/sfy-code/sfy-buoy/target/thumbv7em-none-eabihf/debug/sfy-artemis
Attaching to GDB server for RTT | defmt output..
0 hello from sfy (v1f03b55) (sn: WAVEBUG18)!
└─ sfy_artemis::__cortex_m_rt_main @ sfy-artemis/src/main.rs:95
0 INFO  Opening SD card..
└─ sfy::storage::{impl#2}::open @ src/storage/mod.rs:81
0 INFO  Initialize SD-card (re-clock SPI)..
└─ sfy::storage::{impl#2}::open @ src/storage/mod.rs:84
0 INFO  SD card size: 15193 mb
└─ sfy::storage::{impl#2}::open @ src/storage/mod.rs:89
0 DEBUG Searching for free collection, testing: 0.2
└─ sfy::storage::{impl#2}::find_first_free_collection @ src/storage/mod.rs:117
0 DEBUG Searching for free collection, testing: 1.2
└─ sfy::storage::{impl#2}::find_first_free_collection @ src/storage/mod.rs:117
0 DEBUG Searching for free collection, testing: 2.2
└─ sfy::storage::{impl#2}::find_first_free_collection @ src/storage/mod.rs:117
0 DEBUG Searching for free collection, testing: 3.2
└─ sfy::storage::{impl#2}::find_first_free_collection @ src/storage/mod.rs:117
0 DEBUG Searching for free collection, testing: 4.2
└─ sfy::storage::{impl#2}::find_first_free_collection @ src/storage/mod.rs:117
0 DEBUG Searching for free collection, testing: 5.2
└─ sfy::storage::{impl#2}::find_first_free_collection @ src/storage/mod.rs:117
0 DEBUG Searching for free collection, testing: 6.2
└─ sfy::storage::{impl#2}::find_first_free_collection @ src/storage/mod.rs:117
0 DEBUG Searching for free collection, testing: 7.2
└─ sfy::storage::{impl#2}::find_first_free_collection @ src/storage/mod.rs:117
0 DEBUG Searching for free collection, testing: 8.2
└─ sfy::storage::{impl#2}::find_first_free_collection @ src/storage/mod.rs:117
0 DEBUG Searching for free collection, testing: 9.2
└─ sfy::storage::{impl#2}::find_first_free_collection @ src/storage/mod.rs:117
0 DEBUG Searching for free collection, testing: 10.2
└─ sfy::storage::{impl#2}::find_first_free_collection @ src/storage/mod.rs:117
0 DEBUG Searching for free collection, testing: 11.2
└─ sfy::storage::{impl#2}::find_first_free_collection @ src/storage/mod.rs:117
0 DEBUG Searching for free collection, testing: 12.2
└─ sfy::storage::{impl#2}::find_first_free_collection @ src/storage/mod.rs:117
0 DEBUG Searching for free collection, testing: 13.2
└─ sfy::storage::{impl#2}::find_first_free_collection @ src/storage/mod.rs:117
0 DEBUG Searching for free collection, testing: 14.2
└─ sfy::storage::{impl#2}::find_first_free_collection @ src/storage/mod.rs:117
0 DEBUG Searching for free collection, testing: 15.2
└─ sfy::storage::{impl#2}::find_first_free_collection @ src/storage/mod.rs:117
0 DEBUG Searching for free collection, testing: 16.2
└─ sfy::storage::{impl#2}::find_first_free_collection @ src/storage/mod.rs:117
0 DEBUG Searching for free collection, testing: 17.2
└─ sfy::storage::{impl#2}::find_first_free_collection @ src/storage/mod.rs:117
0 DEBUG Searching for free collection, testing: 18.2
└─ sfy::storage::{impl#2}::find_first_free_collection @ src/storage/mod.rs:117
0 DEBUG Searching for free collection, testing: 19.2
└─ sfy::storage::{impl#2}::find_first_free_collection @ src/storage/mod.rs:117
0 DEBUG Searching for free collection, testing: 20.2
└─ sfy::storage::{impl#2}::find_first_free_collection @ src/storage/mod.rs:117
0 DEBUG Searching for free collection, testing: 21.2
└─ sfy::storage::{impl#2}::find_first_free_collection @ src/storage/mod.rs:117
0 DEBUG Searching for free collection, testing: 22.2
└─ sfy::storage::{impl#2}::find_first_free_collection @ src/storage/mod.rs:117
0 DEBUG Searching for free collection, testing: 23.2
└─ sfy::storage::{impl#2}::find_first_free_collection @ src/storage/mod.rs:117
0 DEBUG Searching for free collection, testing: 24.2
└─ sfy::storage::{impl#2}::find_first_free_collection @ src/storage/mod.rs:117
0 DEBUG Searching for free collection, testing: 25.2
└─ sfy::storage::{impl#2}::find_first_free_collection @ src/storage/mod.rs:117
0 DEBUG Searching for free collection, testing: 26.2
└─ sfy::storage::{impl#2}::find_first_free_collection @ src/storage/mod.rs:117
0 DEBUG Searching for free collection, testing: 27.2
└─ sfy::storage::{impl#2}::find_first_free_collection @ src/storage/mod.rs:117
0 DEBUG Searching for free collection, testing: 28.2
└─ sfy::storage::{impl#2}::find_first_free_collection @ src/storage/mod.rs:117
0 DEBUG Searching for free collection, testing: 29.2
└─ sfy::storage::{impl#2}::find_first_free_collection @ src/storage/mod.rs:117
0 DEBUG Searching for free collection, testing: 30.2
└─ sfy::storage::{impl#2}::find_first_free_collection @ src/storage/mod.rs:117
0 DEBUG Searching for free collection, testing: 31.2
└─ sfy::storage::{impl#2}::find_first_free_collection @ src/storage/mod.rs:117
0 DEBUG Searching for free collection, testing: 32.2
└─ sfy::storage::{impl#2}::find_first_free_collection @ src/storage/mod.rs:117
0 DEBUG Searching for free collection, testing: 33.2
└─ sfy::storage::{impl#2}::find_first_free_collection @ src/storage/mod.rs:117
0 DEBUG Searching for free collection, testing: 34.2
└─ sfy::storage::{impl#2}::find_first_free_collection @ src/storage/mod.rs:117
0 DEBUG Searching for free collection, testing: 35.2
└─ sfy::storage::{impl#2}::find_first_free_collection @ src/storage/mod.rs:117
0 DEBUG Searching for free collection, testing: 36.2
└─ sfy::storage::{impl#2}::find_first_free_collection @ src/storage/mod.rs:117
0 DEBUG Searching for free collection, testing: 37.2
└─ sfy::storage::{impl#2}::find_first_free_collection @ src/storage/mod.rs:117
0 DEBUG Searching for free collection, testing: 38.2
└─ sfy::storage::{impl#2}::find_first_free_collection @ src/storage/mod.rs:117
0 DEBUG Searching for free collection, testing: 39.2
└─ sfy::storage::{impl#2}::find_first_free_collection @ src/storage/mod.rs:117
0 INFO  Starting new collection: 39
└─ sfy::storage::{impl#2}::open @ src/storage/mod.rs:99
0 WARN  resetting: consuming any left-over response and perform a new handshake.
└─ blues_notecard::{impl#3}::reset @ /home/gauteh/.cargo/git/checkouts/notecard-rs-852fd70ea39a9daa/9f010f3/src/lib.rs:404
0 INFO  Notecard version: Version { body: VersionInner { org: "Blues Wireless", product: "Notecard", version: "notecard-3.5.1", ver_major: 3, ver_minor: 5, ver_patch: 1, ver_build: 15259, built: "Aug 12 2022 13:42:05" }, version: "notecard-3.5.1.15259", device: "dev:867648043595550", name: "Blues Wireless Notecard", board: "1.11", sku: "NOTE-WBEX-500", api: 3 }
└─ sfy::note::{impl#0}::new @ src/note.rs:96
0 DEBUG setting up templates..
└─ sfy::note::{impl#0}::setup_templates @ src/note.rs:136
0 DEBUG setting up template for AxlPacketMeta
└─ sfy::note::{impl#0}::setup_templates @ src/note.rs:161
0 INFO  initializing initial sync ..
└─ sfy::note::{impl#0}::new @ src/note.rs:101
0 INFO  Location: Location { status: "GPS inactive {gps-inactive} {gps}", mode: "periodic", lat: Some(61.351557), lon: Some(5.399144416666667), time: Some(1663433563), max: None }, Time: Ok(Time { time: Some(1663433717), area: Some("Vestland"), zone: Some("CEST,Europe/Oslo"), minutes: Some(120), lat: Some(61.34505749999996), lon: Some(5.408714843750019), country: Some("NO") })
└─ sfy::{impl#2}::check_retrieve @ src/lib.rs:162
0 INFO  Got time, setting RTC.
└─ sfy::{impl#2}::check_retrieve @ src/lib.rs:168
0 INFO  Got location, setting position.
└─ sfy::{impl#2}::check_retrieve @ src/lib.rs:189
0 INFO  Both time and location retrieved.
└─ sfy::{impl#2}::check_retrieve @ src/lib.rs:206
1663433717 DEBUG setting up imu driver..
└─ sfy::waves::{impl#2}::new @ src/waves/mod.rs:134
1663433717 DEBUG imu frequency: 208.0
└─ sfy::waves::{impl#2}::new @ src/waves/mod.rs:142
1663433717 DEBUG output frequency: 52.0
└─ sfy::waves::{impl#2}::new @ src/waves/mod.rs:143
1663433717 DEBUG booting imu..
└─ sfy::waves::{impl#2}::new @ src/waves/mod.rs:158
1663433717 DEBUG cleared buffer: 0, new timestamp: 1663433717000, new offset: 0
└─ sfy::waves::{impl#2}::take_buf @ src/waves/mod.rs:315
1663433717 DEBUG enabling FIFO mode
└─ sfy::waves::{impl#2}::enable_fifo @ src/waves/mod.rs:243
1663433717 TRACE card.status: Status { status: "{normal}", usb: false, storage: 2, time: Some(1663427763), connected: false }
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:359
1663433717 TRACE hub.sync_status: SyncStatus { status: Some("starting communications {wait-module} {connecting}"), time: None, sync: None, completed: None, requested: Some(1) }
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:362
1663433717 TRACE card.wireless: Ok(Wireless { status: "{modem-off}", mode: Some("auto"), count: Some(2), net: Some(WirelessNet { iccid: Some("89011703278306866438"), imsi: Some("310170830686643"), imei: Some("867648043595550"), modem: Some("EG91EXGAR08A05M1G_01.001.01.001"), band: Some("LTE BAND 8"), rat: Some("lte"), rssir: Some(-71), rssi: Some(-71), rsrp: Some(-97), sinr: Some(144), rsrq: Some(-9), bars: Some(2), mcc: Some(242), mnc: Some(2), lac: Some(2302), cid: Some(34723099), updated: Some(1663433147) }) })
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:367
1663433722 TRACE card.status: Status { status: "{normal}", usb: false, storage: 2, time: Some(1663427763), connected: false }
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:359
1663433722 TRACE hub.sync_status: SyncStatus { status: Some("modem now ON {modem-on}"), time: None, sync: None, completed: None, requested: Some(6) }
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:362
1663433722 TRACE card.wireless: Ok(Wireless { status: "{modem-on}", mode: Some("auto"), count: Some(2), net: Some(WirelessNet { iccid: Some("89011703278306866438"), imsi: Some("310170830686643"), imei: Some("867648043595550"), modem: Some("EG91EXGAR08A05M1G_01.001.01.001"), band: Some("LTE BAND 8"), rat: Some("lte"), rssir: Some(-71), rssi: Some(-71), rsrp: Some(-97), sinr: Some(144), rsrq: Some(-9), bars: Some(2), mcc: Some(242), mnc: Some(2), lac: Some(2302), cid: Some(34723099), updated: Some(1663433147) }) })
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:367
1663433727 TRACE card.status: Status { status: "{normal}", usb: false, storage: 2, time: Some(1663427763), connected: false }
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:359
1663433727 TRACE hub.sync_status: SyncStatus { status: Some("modem now ON {modem-on}"), time: None, sync: None, completed: None, requested: Some(11) }
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:362
1663433727 TRACE card.wireless: Ok(Wireless { status: "{modem-on}", mode: Some("auto"), count: Some(2), net: Some(WirelessNet { iccid: Some("89011703278306866438"), imsi: Some("310170830686643"), imei: Some("867648043595550"), modem: Some("EG91EXGAR08A05M1G_01.001.01.001"), band: Some("LTE BAND 8"), rat: Some("lte"), rssir: Some(-71), rssi: Some(-71), rsrp: Some(-97), sinr: Some(144), rsrq: Some(-9), bars: Some(2), mcc: Some(242), mnc: Some(2), lac: Some(2302), cid: Some(34723099), updated: Some(1663433147) }) })
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:367
1663433732 TRACE card.status: Status { status: "{normal}", usb: false, storage: 2, time: Some(1663427763), connected: false }
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:359
1663433732 TRACE hub.sync_status: SyncStatus { status: Some("modem now ON {modem-on}"), time: None, sync: None, completed: None, requested: Some(16) }
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:362
1663433732 TRACE card.wireless: Ok(Wireless { status: "{modem-on}", mode: Some("auto"), count: Some(2), net: Some(WirelessNet { iccid: Some("89011703278306866438"), imsi: Some("310170830686643"), imei: Some("867648043595550"), modem: Some("EG91EXGAR08A05M1G_01.001.01.001"), band: Some("LTE BAND 8"), rat: Some("lte"), rssir: Some(-71), rssi: Some(-71), rsrp: Some(-97), sinr: Some(144), rsrq: Some(-9), bars: Some(2), mcc: Some(242), mnc: Some(2), lac: Some(2302), cid: Some(34723099), updated: Some(1663433147) }) })
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:367
1663433737 TRACE card.status: Status { status: "{normal}", usb: false, storage: 2, time: Some(1663427763), connected: false }
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:359
1663433737 TRACE hub.sync_status: SyncStatus { status: Some("idle {disconnected}"), time: None, sync: None, completed: None, requested: Some(21) }
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:362
1663433737 TRACE card.wireless: Ok(Wireless { status: "{cell-registration-wait}", mode: Some("auto"), count: Some(2), net: Some(WirelessNet { iccid: Some("89011703278306866438"), imsi: Some("310170830686643"), imei: Some("867648043595550"), modem: Some("EG91EXGAR08A05M1G_01.001.01.001"), band: Some("LTE BAND 8"), rat: Some("lte"), rssir: Some(-71), rssi: Some(-71), rsrp: Some(-97), sinr: Some(144), rsrq: Some(-9), bars: Some(2), mcc: Some(242), mnc: Some(2), lac: Some(2302), cid: Some(34723099), updated: Some(1663433147) }) })
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:367
1663433737 DEBUG cleared buffer: 3072, new timestamp: 1663433737920, new offset: 1
└─ sfy::waves::{impl#2}::take_buf @ src/waves/mod.rs:315
1663433737 DEBUG Storing package: AxlPacket(timestamp: 1663433717000, offset: 0, storage_id: None, position_time: 1663433563, lon: 5.399144416666667, lat: 61.351557, freq: 52.0, data (length): 3072)) (queue length: 0)
└─ sfy::{impl#4}::drain_queue @ src/lib.rs:334
1663433737 INFO  Writing package to card id: 3900, size: 10240, timestamp: 1663433717000, collection: 39.2, fileid: 0, offset: 0
└─ sfy::storage::{impl#2}::store::{closure#0} @ src/storage/mod.rs:219
1663433739 DEBUG sending package: queue sz: 1
└─ sfy::note::{impl#0}::drain_queue @ src/note.rs:342
1663433743 INFO  Sent data package: Some(3900), bytes: 8192 (note: Add { total: None, template: Some(true) })
└─ sfy::note::{impl#0}::send @ src/note.rs:209
1663433743 TRACE card.status: Status { status: "{normal}", usb: false, storage: 3, time: Some(1663427763), connected: false }
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:359
1663433743 TRACE hub.sync_status: SyncStatus { status: Some("idle {disconnected}"), time: None, sync: Some(true), completed: None, requested: Some(27) }
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:362
1663433743 TRACE card.wireless: Ok(Wireless { status: "{cell-registration-wait}", mode: Some("auto"), count: Some(2), net: Some(WirelessNet { iccid: Some("89011703278306866438"), imsi: Some("310170830686643"), imei: Some("867648043595550"), modem: Some("EG91EXGAR08A05M1G_01.001.01.001"), band: Some("LTE BAND 8"), rat: Some("lte"), rssir: Some(-71), rssi: Some(-71), rsrp: Some(-97), sinr: Some(144), rsrq: Some(-9), bars: Some(2), mcc: Some(242), mnc: Some(2), lac: Some(2302), cid: Some(34723099), updated: Some(1663433147) }) })
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:367
1663433743 TRACE card.status: Status { status: "{normal}", usb: false, storage: 3, time: Some(1663427763), connected: false }
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:359
1663433743 TRACE hub.sync_status: SyncStatus { status: Some("idle {disconnected}"), time: None, sync: Some(true), completed: None, requested: Some(28) }
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:362
1663433743 TRACE card.wireless: Ok(Wireless { status: "{cell-registration-wait}", mode: Some("auto"), count: Some(2), net: Some(WirelessNet { iccid: Some("89011703278306866438"), imsi: Some("310170830686643"), imei: Some("867648043595550"), modem: Some("EG91EXGAR08A05M1G_01.001.01.001"), band: Some("LTE BAND 8"), rat: Some("lte"), rssir: Some(-71), rssi: Some(-71), rsrp: Some(-97), sinr: Some(144), rsrq: Some(-9), bars: Some(2), mcc: Some(242), mnc: Some(2), lac: Some(2302), cid: Some(34723099), updated: Some(1663433147) }) })
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:367
1663433748 TRACE card.status: Status { status: "{normal}", usb: false, storage: 3, time: Some(1663427763), connected: false }
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:359
1663433748 TRACE hub.sync_status: SyncStatus { status: Some("modem now OFF {modem-off}"), time: None, sync: Some(true), completed: None, requested: Some(33) }
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:362
1663433748 TRACE card.wireless: Ok(Wireless { status: "{modem-off}", mode: Some("auto"), count: Some(2), net: Some(WirelessNet { iccid: Some("89011703278306866438"), imsi: Some("310170830686643"), imei: Some("867648043595550"), modem: Some("EG91EXGAR08A05M1G_01.001.01.001"), band: Some("LTE BAND 8"), rat: Some("lte"), rssir: Some(-71), rssi: Some(-71), rsrp: Some(-97), sinr: Some(144), rsrq: Some(-9), bars: Some(2), mcc: Some(242), mnc: Some(2), lac: Some(2302), cid: Some(34723099), updated: Some(1663433147) }) })
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:367
1663433753 TRACE card.status: Status { status: "{normal}", usb: false, storage: 3, time: Some(1663427763), connected: false }
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:359
1663433753 TRACE hub.sync_status: SyncStatus { status: Some("starting communications {wait-module} {connecting}"), time: None, sync: Some(true), completed: None, requested: Some(38) }
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:362
1663433753 TRACE card.wireless: Ok(Wireless { status: "{modem-off}", mode: Some("auto"), count: Some(2), net: Some(WirelessNet { iccid: Some("89011703278306866438"), imsi: Some("310170830686643"), imei: Some("867648043595550"), modem: Some("EG91EXGAR08A05M1G_01.001.01.001"), band: Some("LTE BAND 8"), rat: Some("lte"), rssir: Some(-71), rssi: Some(-71), rsrp: Some(-97), sinr: Some(144), rsrq: Some(-9), bars: Some(2), mcc: Some(242), mnc: Some(2), lac: Some(2302), cid: Some(34723099), updated: Some(1663433147) }) })
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:367
1663433758 TRACE card.status: Status { status: "{normal}", usb: false, storage: 3, time: Some(1663427763), connected: false }
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:359
1663433758 TRACE hub.sync_status: SyncStatus { status: Some("modem now ON {modem-on}"), time: None, sync: Some(true), completed: None, requested: Some(43) }
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:362
1663433758 TRACE card.wireless: Ok(Wireless { status: "{modem-on}", mode: Some("auto"), count: Some(2), net: Some(WirelessNet { iccid: Some("89011703278306866438"), imsi: Some("310170830686643"), imei: Some("867648043595550"), modem: Some("EG91EXGAR08A05M1G_01.001.01.001"), band: Some("LTE BAND 8"), rat: Some("lte"), rssir: Some(-71), rssi: Some(-71), rsrp: Some(-97), sinr: Some(144), rsrq: Some(-9), bars: Some(2), mcc: Some(242), mnc: Some(2), lac: Some(2302), cid: Some(34723099), updated: Some(1663433147) }) })
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:367
1663433758 DEBUG cleared buffer: 3072, new timestamp: 1663433758840, new offset: 0
└─ sfy::waves::{impl#2}::take_buf @ src/waves/mod.rs:315
1663433758 DEBUG Storing package: AxlPacket(timestamp: 1663433737920, offset: 1, storage_id: None, position_time: 1663433563, lon: 5.399144416666667, lat: 61.351557, freq: 52.0, data (length): 3072)) (queue length: 0)
└─ sfy::{impl#4}::drain_queue @ src/lib.rs:334
1663433758 INFO  Writing package to card id: 3901, size: 10240, timestamp: 1663433737920, collection: 39.2, fileid: 1, offset: 10240
└─ sfy::storage::{impl#2}::store::{closure#0} @ src/storage/mod.rs:219
1663433760 DEBUG sending package: queue sz: 1
└─ sfy::note::{impl#0}::drain_queue @ src/note.rs:342
1663433764 INFO  Sent data package: Some(3901), bytes: 8192 (note: Add { total: None, template: Some(true) })
└─ sfy::note::{impl#0}::send @ src/note.rs:209
1663433764 TRACE card.status: Status { status: "{normal}", usb: false, storage: 4, time: Some(1663427763), connected: false }
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:359
1663433764 TRACE hub.sync_status: SyncStatus { status: Some("modem now ON {modem-on}"), time: None, sync: Some(true), completed: None, requested: Some(48) }
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:362
1663433764 TRACE card.wireless: Ok(Wireless { status: "{modem-on}", mode: Some("auto"), count: Some(2), net: Some(WirelessNet { iccid: Some("89011703278306866438"), imsi: Some("310170830686643"), imei: Some("867648043595550"), modem: Some("EG91EXGAR08A05M1G_01.001.01.001"), band: Some("LTE BAND 8"), rat: Some("lte"), rssir: Some(-71), rssi: Some(-71), rsrp: Some(-97), sinr: Some(144), rsrq: Some(-9), bars: Some(2), mcc: Some(242), mnc: Some(2), lac: Some(2302), cid: Some(34723099), updated: Some(1663433147) }) })
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:367
1663433764 TRACE card.status: Status { status: "{normal}", usb: false, storage: 4, time: Some(1663427763), connected: false }
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:359
1663433764 TRACE hub.sync_status: SyncStatus { status: Some("modem now ON {modem-on}"), time: None, sync: Some(true), completed: None, requested: Some(48) }
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:362
1663433764 TRACE card.wireless: Ok(Wireless { status: "{modem-on}", mode: Some("auto"), count: Some(2), net: Some(WirelessNet { iccid: Some("89011703278306866438"), imsi: Some("310170830686643"), imei: Some("867648043595550"), modem: Some("EG91EXGAR08A05M1G_01.001.01.001"), band: Some("LTE BAND 8"), rat: Some("lte"), rssir: Some(-71), rssi: Some(-71), rsrp: Some(-97), sinr: Some(144), rsrq: Some(-9), bars: Some(2), mcc: Some(242), mnc: Some(2), lac: Some(2302), cid: Some(34723099), updated: Some(1663433147) }) })
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:367
1663433769 TRACE card.status: Status { status: "{normal}", usb: false, storage: 4, time: Some(1663427763), connected: true }
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:359
1663433769 TRACE hub.sync_status: SyncStatus { status: Some("get notebox change summary"), time: None, sync: Some(true), completed: None, requested: Some(53) }
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:362
1663433769 TRACE card.wireless: Ok(Wireless { status: "{network-up}", mode: Some("auto"), count: Some(2), net: Some(WirelessNet { iccid: Some("89011703278306866438"), imsi: Some("310170830686643"), imei: Some("867648043595550"), modem: Some("EG91EXGAR08A05M1G_01.001.01.001"), band: Some("LTE BAND 28"), rat: Some("lte"), rssir: Some(-67), rssi: Some(-67), rsrp: Some(-91), sinr: Some(201), rsrq: Some(-7), bars: Some(2), mcc: Some(242), mnc: Some(2), lac: Some(2302), cid: Some(32163097), updated: Some(1663433768) }) })
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:367
1663433774 TRACE card.status: Status { status: "{normal}", usb: false, storage: 4, time: Some(1663427763), connected: true }
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:359
1663433774 TRACE hub.sync_status: SyncStatus { status: Some("merge notefile: axl.qo"), time: None, sync: Some(true), completed: None, requested: Some(58) }
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:362
1663433774 TRACE card.wireless: Ok(Wireless { status: "{network-up}", mode: Some("auto"), count: Some(2), net: Some(WirelessNet { iccid: Some("89011703278306866438"), imsi: Some("310170830686643"), imei: Some("867648043595550"), modem: Some("EG91EXGAR08A05M1G_01.001.01.001"), band: Some("LTE BAND 28"), rat: Some("lte"), rssir: Some(-67), rssi: Some(-67), rsrp: Some(-91), sinr: Some(201), rsrq: Some(-7), bars: Some(2), mcc: Some(242), mnc: Some(2), lac: Some(2302), cid: Some(32163097), updated: Some(1663433768) }) })
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:367
1663433779 INFO  Location: Location { status: "GPS inactive {gps-inactive} {gps}", mode: "periodic", lat: Some(61.351557), lon: Some(5.399144416666667), time: Some(1663433563), max: None }, Time: Ok(Time { time: Some(1663433779), area: Some("Vestland"), zone: Some("CEST,Europe/Oslo"), minutes: Some(120), lat: Some(61.34427749999997), lon: Some(5.406277343750006), country: Some("NO") })
└─ sfy::{impl#2}::check_retrieve @ src/lib.rs:162
1663433779 INFO  Got time, setting RTC.
└─ sfy::{impl#2}::check_retrieve @ src/lib.rs:168
1663433779 INFO  Got location, setting position.
└─ sfy::{impl#2}::check_retrieve @ src/lib.rs:189
1663433779 INFO  Both time and location retrieved.
└─ sfy::{impl#2}::check_retrieve @ src/lib.rs:206
1663433779 TRACE card.status: Status { status: "{normal}", usb: false, storage: 2, time: Some(1663427763), connected: false }
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:359
1663433779 TRACE hub.sync_status: SyncStatus { status: Some("idle {disconnected}"), time: None, sync: None, completed: None, requested: Some(64) }
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:362
1663433779 TRACE card.wireless: Ok(Wireless { status: "{modem-on}", mode: Some("auto"), count: Some(2), net: Some(WirelessNet { iccid: Some("89011703278306866438"), imsi: Some("310170830686643"), imei: Some("867648043595550"), modem: Some("EG91EXGAR08A05M1G_01.001.01.001"), band: Some("LTE BAND 28"), rat: Some("lte"), rssir: Some(-67), rssi: Some(-67), rsrp: Some(-91), sinr: Some(152), rsrq: Some(-7), bars: Some(2), mcc: Some(242), mnc: Some(2), lac: Some(2302), cid: Some(32163097), updated: Some(1663433776) }) })
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:367
1663433779 DEBUG axl buf is full, waiting to be cleared..
└─ sfy::waves::{impl#2}::read_and_filter @ src/waves/mod.rs:368
1663433779 DEBUG cleared buffer: 3072, new timestamp: 1663433779380, new offset: 1
└─ sfy::waves::{impl#2}::take_buf @ src/waves/mod.rs:315
1663433779 DEBUG Storing package: AxlPacket(timestamp: 1663433758840, offset: 0, storage_id: None, position_time: 1663433563, lon: 5.399144416666667, lat: 61.351557, freq: 52.0, data (length): 3072)) (queue length: 0)
└─ sfy::{impl#4}::drain_queue @ src/lib.rs:334
1663433779 INFO  Writing package to card id: 3902, size: 10240, timestamp: 1663433758840, collection: 39.2, fileid: 2, offset: 20480
└─ sfy::storage::{impl#2}::store::{closure#0} @ src/storage/mod.rs:219
1663433780 DEBUG sending package: queue sz: 1
└─ sfy::note::{impl#0}::drain_queue @ src/note.rs:342
1663433784 INFO  Sent data package: Some(3902), bytes: 8192 (note: Add { total: None, template: Some(true) })
└─ sfy::note::{impl#0}::send @ src/note.rs:209
1663433784 TRACE card.status: Status { status: "{normal}", usb: false, storage: 3, time: Some(1663427763), connected: false }
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:359
1663433784 TRACE hub.sync_status: SyncStatus { status: Some("idle {disconnected}"), time: None, sync: Some(true), completed: None, requested: Some(69) }
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:362
1663433784 TRACE card.wireless: Ok(Wireless { status: "{modem-on}", mode: Some("auto"), count: Some(2), net: Some(WirelessNet { iccid: Some("89011703278306866438"), imsi: Some("310170830686643"), imei: Some("867648043595550"), modem: Some("EG91EXGAR08A05M1G_01.001.01.001"), band: Some("LTE BAND 28"), rat: Some("lte"), rssir: Some(-67), rssi: Some(-67), rsrp: Some(-91), sinr: Some(152), rsrq: Some(-7), bars: Some(2), mcc: Some(242), mnc: Some(2), lac: Some(2302), cid: Some(32163097), updated: Some(1663433776) }) })
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:367
1663433785 TRACE card.status: Status { status: "{normal}", usb: false, storage: 3, time: Some(1663427763), connected: false }
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:359
1663433785 TRACE hub.sync_status: SyncStatus { status: Some("idle {disconnected}"), time: None, sync: Some(true), completed: None, requested: Some(69) }
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:362
1663433785 TRACE card.wireless: Ok(Wireless { status: "{modem-on}", mode: Some("auto"), count: Some(2), net: Some(WirelessNet { iccid: Some("89011703278306866438"), imsi: Some("310170830686643"), imei: Some("867648043595550"), modem: Some("EG91EXGAR08A05M1G_01.001.01.001"), band: Some("LTE BAND 28"), rat: Some("lte"), rssir: Some(-67), rssi: Some(-67), rsrp: Some(-91), sinr: Some(152), rsrq: Some(-7), bars: Some(2), mcc: Some(242), mnc: Some(2), lac: Some(2302), cid: Some(32163097), updated: Some(1663433776) }) })
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:367
1663433790 TRACE card.status: Status { status: "{normal}", usb: false, storage: 3, time: Some(1663427763), connected: false }
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:359
1663433790 TRACE hub.sync_status: SyncStatus { status: Some("modem now OFF {modem-off}"), time: None, sync: Some(true), completed: None, requested: Some(74) }
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:362
1663433790 TRACE card.wireless: Ok(Wireless { status: "{modem-off}", mode: Some("auto"), count: Some(2), net: Some(WirelessNet { iccid: Some("89011703278306866438"), imsi: Some("310170830686643"), imei: Some("867648043595550"), modem: Some("EG91EXGAR08A05M1G_01.001.01.001"), band: Some("LTE BAND 28"), rat: Some("lte"), rssir: Some(-67), rssi: Some(-67), rsrp: Some(-91), sinr: Some(152), rsrq: Some(-7), bars: Some(2), mcc: Some(242), mnc: Some(2), lac: Some(2302), cid: Some(32163097), updated: Some(1663433776) }) })
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:367
1663433795 TRACE card.status: Status { status: "{normal}", usb: false, storage: 3, time: Some(1663427763), connected: false }
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:359
1663433795 TRACE hub.sync_status: SyncStatus { status: Some("starting communications {wait-module} {connecting}"), time: Some(1663433791), sync: Some(true), completed: Some(4), requested: None }
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:362
1663433795 TRACE card.wireless: Ok(Wireless { status: "{modem-on}", mode: Some("auto"), count: Some(2), net: Some(WirelessNet { iccid: Some("89011703278306866438"), imsi: Some("310170830686643"), imei: Some("867648043595550"), modem: Some("EG91EXGAR08A05M1G_01.001.01.001"), band: Some("LTE BAND 28"), rat: Some("lte"), rssir: Some(-67), rssi: Some(-67), rsrp: Some(-91), sinr: Some(152), rsrq: Some(-7), bars: Some(2), mcc: Some(242), mnc: Some(2), lac: Some(2302), cid: Some(32163097), updated: Some(1663433776) }) })
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:367
1663433800 TRACE card.status: Status { status: "{normal}", usb: false, storage: 3, time: Some(1663427763), connected: false }
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:359
1663433800 TRACE hub.sync_status: SyncStatus { status: Some("modem now ON {modem-on}"), time: Some(1663433791), sync: Some(true), completed: Some(9), requested: None }
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:362
1663433800 TRACE card.wireless: Ok(Wireless { status: "{modem-on}", mode: Some("auto"), count: Some(2), net: Some(WirelessNet { iccid: Some("89011703278306866438"), imsi: Some("310170830686643"), imei: Some("867648043595550"), modem: Some("EG91EXGAR08A05M1G_01.001.01.001"), band: Some("LTE BAND 28"), rat: Some("lte"), rssir: Some(-67), rssi: Some(-67), rsrp: Some(-91), sinr: Some(152), rsrq: Some(-7), bars: Some(2), mcc: Some(242), mnc: Some(2), lac: Some(2302), cid: Some(32163097), updated: Some(1663433776) }) })
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:367
1663433800 DEBUG cleared buffer: 3072, new timestamp: 1663433800300, new offset: 1
└─ sfy::waves::{impl#2}::take_buf @ src/waves/mod.rs:315
1663433800 DEBUG Storing package: AxlPacket(timestamp: 1663433779380, offset: 1, storage_id: None, position_time: 1663433563, lon: 5.399144416666667, lat: 61.351557, freq: 52.0, data (length): 3072)) (queue length: 0)
└─ sfy::{impl#4}::drain_queue @ src/lib.rs:334
1663433800 INFO  Writing package to card id: 3903, size: 10240, timestamp: 1663433779380, collection: 39.2, fileid: 3, offset: 30720
└─ sfy::storage::{impl#2}::store::{closure#0} @ src/storage/mod.rs:219
1663433801 DEBUG sending package: queue sz: 1
└─ sfy::note::{impl#0}::drain_queue @ src/note.rs:342
1663433805 INFO  Sent data package: Some(3903), bytes: 8192 (note: Add { total: None, template: Some(true) })
└─ sfy::note::{impl#0}::send @ src/note.rs:209
1663433805 TRACE card.status: Status { status: "{normal}", usb: false, storage: 3, time: Some(1663427763), connected: false }
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:359
1663433805 TRACE hub.sync_status: SyncStatus { status: Some("modem now ON {modem-on}"), time: Some(1663433791), sync: Some(true), completed: Some(15), requested: None }
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:362
1663433805 TRACE card.wireless: Ok(Wireless { status: "{modem-on}", mode: Some("auto"), count: Some(2), net: Some(WirelessNet { iccid: Some("89011703278306866438"), imsi: Some("310170830686643"), imei: Some("867648043595550"), modem: Some("EG91EXGAR08A05M1G_01.001.01.001"), band: Some("LTE BAND 28"), rat: Some("lte"), rssir: Some(-67), rssi: Some(-67), rsrp: Some(-91), sinr: Some(152), rsrq: Some(-7), bars: Some(2), mcc: Some(242), mnc: Some(2), lac: Some(2302), cid: Some(32163097), updated: Some(1663433776) }) })
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:367
1663433805 TRACE card.status: Status { status: "{normal}", usb: false, storage: 3, time: Some(1663427763), connected: false }
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:359
1663433806 TRACE hub.sync_status: SyncStatus { status: Some("modem now ON {modem-on}"), time: Some(1663433791), sync: Some(true), completed: Some(15), requested: None }
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:362
1663433806 TRACE card.wireless: Ok(Wireless { status: "{modem-on}", mode: Some("auto"), count: Some(2), net: Some(WirelessNet { iccid: Some("89011703278306866438"), imsi: Some("310170830686643"), imei: Some("867648043595550"), modem: Some("EG91EXGAR08A05M1G_01.001.01.001"), band: Some("LTE BAND 28"), rat: Some("lte"), rssir: Some(-67), rssi: Some(-67), rsrp: Some(-91), sinr: Some(152), rsrq: Some(-7), bars: Some(2), mcc: Some(242), mnc: Some(2), lac: Some(2302), cid: Some(32163097), updated: Some(1663433776) }) })
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:367
1663433810 TRACE card.status: Status { status: "{normal}", usb: false, storage: 3, time: Some(1663427763), connected: false }
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:359
1663433810 TRACE hub.sync_status: SyncStatus { status: Some("modem now ON {modem-on}"), time: Some(1663433791), sync: Some(true), completed: Some(20), requested: None }
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:362
1663433811 TRACE card.wireless: Ok(Wireless { status: "{modem-on}", mode: Some("auto"), count: Some(2), net: Some(WirelessNet { iccid: Some("89011703278306866438"), imsi: Some("310170830686643"), imei: Some("867648043595550"), modem: Some("EG91EXGAR08A05M1G_01.001.01.001"), band: Some("LTE BAND 28"), rat: Some("lte"), rssir: Some(-67), rssi: Some(-67), rsrp: Some(-91), sinr: Some(152), rsrq: Some(-7), bars: Some(2), mcc: Some(242), mnc: Some(2), lac: Some(2302), cid: Some(32163097), updated: Some(1663433776) }) })
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:367
1663433815 TRACE card.status: Status { status: "{normal}", usb: false, storage: 3, time: Some(1663427763), connected: false }
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:359
1663433816 TRACE hub.sync_status: SyncStatus { status: Some("connected {connected-closed}"), time: Some(1663433791), sync: Some(true), completed: Some(25), requested: None }
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:362
1663433816 TRACE card.wireless: Ok(Wireless { status: "{modem-on}", mode: Some("auto"), count: Some(2), net: Some(WirelessNet { iccid: Some("89011703278306866438"), imsi: Some("310170830686643"), imei: Some("867648043595550"), modem: Some("EG91EXGAR08A05M1G_01.001.01.001"), band: Some("LTE BAND 28"), rat: Some("lte"), rssir: Some(-67), rssi: Some(-67), rsrp: Some(-91), sinr: Some(152), rsrq: Some(-7), bars: Some(2), mcc: Some(242), mnc: Some(2), lac: Some(2302), cid: Some(32163097), updated: Some(1663433776) }) })
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:367
1663433820 TRACE card.status: Status { status: "{normal}", usb: false, storage: 3, time: Some(1663427763), connected: false }
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:359
1663433821 TRACE hub.sync_status: SyncStatus { status: Some("connected {connected-closed}"), time: Some(1663433791), sync: Some(true), completed: Some(30), requested: None }
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:362
1663433821 TRACE card.wireless: Ok(Wireless { status: "{modem-on}", mode: Some("auto"), count: Some(2), net: Some(WirelessNet { iccid: Some("89011703278306866438"), imsi: Some("310170830686643"), imei: Some("867648043595550"), modem: Some("EG91EXGAR08A05M1G_01.001.01.001"), band: Some("LTE BAND 28"), rat: Some("lte"), rssir: Some(-67), rssi: Some(-67), rsrp: Some(-91), sinr: Some(152), rsrq: Some(-7), bars: Some(2), mcc: Some(242), mnc: Some(2), lac: Some(2302), cid: Some(32163097), updated: Some(1663433776) }) })
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:367
1663433821 DEBUG cleared buffer: 3072, new timestamp: 1663433821220, new offset: 1
└─ sfy::waves::{impl#2}::take_buf @ src/waves/mod.rs:315
1663433821 DEBUG Storing package: AxlPacket(timestamp: 1663433800300, offset: 1, storage_id: None, position_time: 1663433563, lon: 5.399144416666667, lat: 61.351557, freq: 52.0, data (length): 3072)) (queue length: 0)
└─ sfy::{impl#4}::drain_queue @ src/lib.rs:334
1663433821 INFO  Writing package to card id: 3904, size: 10240, timestamp: 1663433800300, collection: 39.2, fileid: 4, offset: 40960
└─ sfy::storage::{impl#2}::store::{closure#0} @ src/storage/mod.rs:219
1663433822 DEBUG sending package: queue sz: 1
└─ sfy::note::{impl#0}::drain_queue @ src/note.rs:342
1663433826 INFO  Sent data package: Some(3904), bytes: 8192 (note: Add { total: None, template: Some(true) })
└─ sfy::note::{impl#0}::send @ src/note.rs:209
1663433826 TRACE card.status: Status { status: "{normal}", usb: false, storage: 4, time: Some(1663427763), connected: false }
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:359
1663433826 TRACE hub.sync_status: SyncStatus { status: Some("connected {connected-closed}"), time: Some(1663433791), sync: Some(true), completed: Some(36), requested: None }
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:362
1663433826 TRACE card.wireless: Ok(Wireless { status: "{modem-on}", mode: Some("auto"), count: Some(2), net: Some(WirelessNet { iccid: Some("89011703278306866438"), imsi: Some("310170830686643"), imei: Some("867648043595550"), modem: Some("EG91EXGAR08A05M1G_01.001.01.001"), band: Some("LTE BAND 28"), rat: Some("lte"), rssir: Some(-67), rssi: Some(-67), rsrp: Some(-91), sinr: Some(152), rsrq: Some(-7), bars: Some(2), mcc: Some(242), mnc: Some(2), lac: Some(2302), cid: Some(32163097), updated: Some(1663433776) }) })
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:367
1663433826 TRACE card.status: Status { status: "{normal}", usb: false, storage: 4, time: Some(1663427763), connected: false }
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:359
1663433826 TRACE hub.sync_status: SyncStatus { status: Some("connected {connected-closed}"), time: Some(1663433791), sync: Some(true), completed: Some(36), requested: None }
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:362
1663433827 TRACE card.wireless: Ok(Wireless { status: "{modem-on}", mode: Some("auto"), count: Some(2), net: Some(WirelessNet { iccid: Some("89011703278306866438"), imsi: Some("310170830686643"), imei: Some("867648043595550"), modem: Some("EG91EXGAR08A05M1G_01.001.01.001"), band: Some("LTE BAND 28"), rat: Some("lte"), rssir: Some(-67), rssi: Some(-67), rsrp: Some(-91), sinr: Some(152), rsrq: Some(-7), bars: Some(2), mcc: Some(242), mnc: Some(2), lac: Some(2302), cid: Some(32163097), updated: Some(1663433776) }) })
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:367
1663433831 TRACE card.status: Status { status: "{normal}", usb: false, storage: 4, time: Some(1663427763), connected: false }
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:359
1663433831 TRACE hub.sync_status: SyncStatus { status: Some("connected {connected-closed}"), time: Some(1663433791), sync: Some(true), completed: Some(41), requested: None }
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:362
1663433832 TRACE card.wireless: Ok(Wireless { status: "{modem-on}", mode: Some("auto"), count: Some(2), net: Some(WirelessNet { iccid: Some("89011703278306866438"), imsi: Some("310170830686643"), imei: Some("867648043595550"), modem: Some("EG91EXGAR08A05M1G_01.001.01.001"), band: Some("LTE BAND 28"), rat: Some("lte"), rssir: Some(-67), rssi: Some(-67), rsrp: Some(-91), sinr: Some(152), rsrq: Some(-7), bars: Some(2), mcc: Some(242), mnc: Some(2), lac: Some(2302), cid: Some(32163097), updated: Some(1663433776) }) })
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:367
1663433836 TRACE card.status: Status { status: "{normal}", usb: false, storage: 4, time: Some(1663427763), connected: false }
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:359
1663433837 TRACE hub.sync_status: SyncStatus { status: Some("connected {connected-closed}"), time: Some(1663433791), sync: Some(true), completed: Some(46), requested: None }
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:362
1663433837 TRACE card.wireless: Ok(Wireless { status: "{modem-on}", mode: Some("auto"), count: Some(2), net: Some(WirelessNet { iccid: Some("89011703278306866438"), imsi: Some("310170830686643"), imei: Some("867648043595550"), modem: Some("EG91EXGAR08A05M1G_01.001.01.001"), band: Some("LTE BAND 28"), rat: Some("lte"), rssir: Some(-67), rssi: Some(-67), rsrp: Some(-91), sinr: Some(152), rsrq: Some(-7), bars: Some(2), mcc: Some(242), mnc: Some(2), lac: Some(2302), cid: Some(32163097), updated: Some(1663433776) }) })
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:367
1663433841 INFO  Location: Location { status: "GPS search (27 sec, 0/0 dB SNR, 0/0 sats, HDOP 0.00) {gps-active} {gps}", mode: "periodic", lat: Some(61.351557), lon: Some(5.399144416666667), time: Some(1663433563), max: None }, Time: Ok(Time { time: Some(1663433842), area: Some("Vestland"), zone: Some("CEST,Europe/Oslo"), minutes: Some(120), lat: Some(61.34427749999997), lon: Some(5.406277343750006), country: Some("NO") })
└─ sfy::{impl#2}::check_retrieve @ src/lib.rs:162
1663433841 INFO  Got time, setting RTC.
└─ sfy::{impl#2}::check_retrieve @ src/lib.rs:168
1663433841 INFO  Got location, setting position.
└─ sfy::{impl#2}::check_retrieve @ src/lib.rs:189
1663433841 INFO  Both time and location retrieved.
└─ sfy::{impl#2}::check_retrieve @ src/lib.rs:206
1663433842 TRACE card.status: Status { status: "{normal}", usb: false, storage: 4, time: Some(1663427763), connected: false }
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:359
1663433842 DEBUG axl buf is full, waiting to be cleared..
└─ sfy::waves::{impl#2}::read_and_filter @ src/waves/mod.rs:368
1663433842 DEBUG cleared buffer: 3072, new timestamp: 1663433842220, new offset: 1
└─ sfy::waves::{impl#2}::take_buf @ src/waves/mod.rs:315
1663433842 TRACE hub.sync_status: SyncStatus { status: Some("connected {connected-closed}"), time: Some(1663433791), sync: Some(true), completed: Some(51), requested: None }
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:362
1663433842 TRACE card.wireless: Ok(Wireless { status: "{modem-on}", mode: Some("auto"), count: Some(2), net: Some(WirelessNet { iccid: Some("89011703278306866438"), imsi: Some("310170830686643"), imei: Some("867648043595550"), modem: Some("EG91EXGAR08A05M1G_01.001.01.001"), band: Some("LTE BAND 28"), rat: Some("lte"), rssir: Some(-67), rssi: Some(-67), rsrp: Some(-91), sinr: Some(152), rsrq: Some(-7), bars: Some(2), mcc: Some(242), mnc: Some(2), lac: Some(2302), cid: Some(32163097), updated: Some(1663433776) }) })
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:367
1663433842 DEBUG Storing package: AxlPacket(timestamp: 1663433821220, offset: 1, storage_id: None, position_time: 1663433563, lon: 5.399144416666667, lat: 61.351557, freq: 52.0, data (length): 3072)) (queue length: 0)
└─ sfy::{impl#4}::drain_queue @ src/lib.rs:334
1663433842 INFO  Writing package to card id: 3905, size: 10240, timestamp: 1663433821220, collection: 39.2, fileid: 5, offset: 51200
└─ sfy::storage::{impl#2}::store::{closure#0} @ src/storage/mod.rs:219
1663433843 DEBUG sending package: queue sz: 1
└─ sfy::note::{impl#0}::drain_queue @ src/note.rs:342
1663433847 INFO  Sent data package: Some(3905), bytes: 8192 (note: Add { total: None, template: Some(true) })
└─ sfy::note::{impl#0}::send @ src/note.rs:209
1663433847 TRACE card.status: Status { status: "{normal}", usb: false, storage: 5, time: Some(1663427763), connected: false }
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:359
1663433847 TRACE hub.sync_status: SyncStatus { status: Some("connected {connected-closed}"), time: Some(1663433791), sync: Some(true), completed: Some(57), requested: None }
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:362
1663433847 TRACE card.wireless: Ok(Wireless { status: "{modem-on}", mode: Some("auto"), count: Some(2), net: Some(WirelessNet { iccid: Some("89011703278306866438"), imsi: Some("310170830686643"), imei: Some("867648043595550"), modem: Some("EG91EXGAR08A05M1G_01.001.01.001"), band: Some("LTE BAND 28"), rat: Some("lte"), rssir: Some(-67), rssi: Some(-67), rsrp: Some(-91), sinr: Some(152), rsrq: Some(-7), bars: Some(2), mcc: Some(242), mnc: Some(2), lac: Some(2302), cid: Some(32163097), updated: Some(1663433776) }) })
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:367
1663433847 TRACE card.status: Status { status: "{normal}", usb: false, storage: 5, time: Some(1663427763), connected: false }
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:359
1663433847 TRACE hub.sync_status: SyncStatus { status: Some("connected {connected-closed}"), time: Some(1663433791), sync: Some(true), completed: Some(57), requested: None }
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:362
1663433848 TRACE card.wireless: Ok(Wireless { status: "{modem-on}", mode: Some("auto"), count: Some(2), net: Some(WirelessNet { iccid: Some("89011703278306866438"), imsi: Some("310170830686643"), imei: Some("867648043595550"), modem: Some("EG91EXGAR08A05M1G_01.001.01.001"), band: Some("LTE BAND 28"), rat: Some("lte"), rssir: Some(-67), rssi: Some(-67), rsrp: Some(-91), sinr: Some(152), rsrq: Some(-7), bars: Some(2), mcc: Some(242), mnc: Some(2), lac: Some(2302), cid: Some(32163097), updated: Some(1663433776) }) })
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:367
1663433852 TRACE card.status: Status { status: "{normal}", usb: false, storage: 5, time: Some(1663427763), connected: false }
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:359
1663433852 TRACE hub.sync_status: SyncStatus { status: Some("connected {connected-closed}"), time: Some(1663433791), sync: Some(true), completed: Some(62), requested: None }
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:362
1663433853 TRACE card.wireless: Ok(Wireless { status: "{modem-on}", mode: Some("auto"), count: Some(2), net: Some(WirelessNet { iccid: Some("89011703278306866438"), imsi: Some("310170830686643"), imei: Some("867648043595550"), modem: Some("EG91EXGAR08A05M1G_01.001.01.001"), band: Some("LTE BAND 28"), rat: Some("lte"), rssir: Some(-67), rssi: Some(-67), rsrp: Some(-91), sinr: Some(152), rsrq: Some(-7), bars: Some(2), mcc: Some(242), mnc: Some(2), lac: Some(2302), cid: Some(32163097), updated: Some(1663433776) }) })
└─ sfy::note::{impl#0}::check_and_sync @ src/note.rs:367

Program received signal SIGTRAP, Trace/breakpoint trap.
[Switching to Thread 57005]
0xdeadbeee in ?? ()
(gdb)