2022-10-25 17:56:58.420 [RAL:XDEB] [CRC OK] 905.300MHz 13.00/-25.2 SF10/BW125 (mod=16/dr=10/bw=4) xtick=013c5e3d (20733501) 23 bytes: 00000000000000000085070000180000000A00F1726627 2022-10-25 17:56:58.421 [S2E:VERB] RX 905.3MHz DR0 SF10/BW125 snr=13.0 rssi=-25 xtime=0xB40000013C5E3D - jreq MHdr=00 JoinEui=::0 DevEui=0:18:0:785 DevNonce=10 MIC=661025521 2022-10-25 17:56:58.421 [AIO:XDEB] [3|WS] > {"msgtype":"jreq","MHdr":0,"JoinEui":"00-00-00-00-00-00-00-00","DevEui":"00-00-00-18-00-00-07-85","DevNonce":10,"MIC":661025521,"RefTime":1666720618.417484,"DR":0,"Freq":905300000,"upinfo":{"rctx":0,"xtime":50665495828651581,"gpstime":0,"fts":-1,"rssi":-25,"snr":13,"rxtime":1666720618.421447}} 2022-10-25 17:56:58.421 [AIO:XDEB] [3] socket write bytes=302 2022-10-25 17:56:58.470 [SYN:XDEB] SYNC: ustime=0x000353D29594 (Q=658): xticks=0x013d41d1 xtime=0xB40000013D41D1 - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:56:58.470 [SYN:WARN] Repeated excessive clock drifts between MCU/SX130X#0 (18 retries): 197.1ppm (threshold 100.0ppm) 2022-10-25 17:56:59.521 [SYN:XDEB] SYNC: ustime=0x000353E29E57 (Q=640): xticks=0x014d49dc xtime=0xB40000014D49DC - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:57:00.326 [AIO:XDEB] [3] socket read bytes=241 2022-10-25 17:57:00.326 [AIO:XDEB] [3|WS] < {"msgtype":"dnmsg","DevEui":"00-00-00-00-00-00-00-01","dC":0,"diid":65369,"pdu":"20ea0397c9180a55a6eb5715c901c1498d","priority":25,"rctx":0,"MuxTime":1666720620.319972,"RxDelay":1,"RX1DR":10,"RX1Freq":927500000,"xtime":50665495832651581} 2022-10-25 17:57:00.327 [S2E:DEBU] ::1 diid=65369 [ant#0] - next TX start ahead by 3s80ms (17:57:03.408082) 2022-10-25 17:57:00.572 [SYN:XDEB] SYNC: ustime=0x000353F2A6E9 (Q=626): xticks=0x015d51a8 xtime=0xB40000015D51A8 - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:57:00.572 [SYN:INFO] MCU/SX130X drift stats: min: +195.6ppm q50: +198.2ppm q80: +201.6ppm max: +210.7ppm - threshold q90: +202.1ppm 2022-10-25 17:57:00.572 [SYN:INFO] Mean MCU drift vs SX130X#0: 198.9ppm 2022-10-25 17:57:01.617 [SYN:XDEB] SYNC: ustime=0x00035402AFC9 (Q=654): xticks=0x016d59f1 xtime=0xB40000016D59F1 - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:57:01.618 [SYN:WARN] Repeated excessive clock drifts between MCU/SX130X#0 (21 retries): 193.3ppm (threshold 100.0ppm) 2022-10-25 17:57:02.668 [SYN:XDEB] SYNC: ustime=0x00035412B883 (Q=630): xticks=0x017d61b9 xtime=0xB40000017D61B9 - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:57:03.383 [S2E:VERB] ::1 diid=65369 [ant#0] - starting TX in 19ms903us: 927.5MHz 26.0dBm ant#0(0) DR10 SF10/BW500 frame=20EA0397C9180A55A6EB5715..01C1498D (17 bytes) 2022-10-25 17:57:03.383 [HAL:XDEB] [lgw_send:1350] --- IN 2022-10-25 17:57:03.383 [HAL:XDEB] [lgw_usb_set_write_mode:436] setting USB write mode to BULK 2022-10-25 17:57:03.383 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5209, offs:0 leng:1 value:0x00 2022-10-25 17:57:03.383 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5209 (offs:0 leng:1) 2022-10-25 17:57:03.383 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5220, offs:0 leng:2 value:0x01 2022-10-25 17:57:03.383 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5220 (offs:0 leng:2) 2022-10-25 17:57:03.383 [HAL:XDEB] [sx1302_send:2460] INFO: selecting TX Gain LUT index 14 2022-10-25 17:57:03.383 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x5223 2022-10-25 17:57:03.383 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x5224 2022-10-25 17:57:03.383 [HAL:XDEB] [sx1302_send:2468] INFO: Applying IQ offset (i:0, q:0) 2022-10-25 17:57:03.383 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x520D 2022-10-25 17:57:03.383 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5222, offs:0 leng:2 value:0x00 2022-10-25 17:57:03.383 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5222 (offs:0 leng:2) 2022-10-25 17:57:03.383 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x5225 2022-10-25 17:57:03.383 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x5226 2022-10-25 17:57:03.383 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x5227 2022-10-25 17:57:03.383 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x520C 2022-10-25 17:57:03.383 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5228, offs:0 leng:4 value:0x08 2022-10-25 17:57:03.383 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5228 (offs:0 leng:4) 2022-10-25 17:57:03.383 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x5229 2022-10-25 17:57:03.383 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5260, offs:4 leng:4 value:0x06 2022-10-25 17:57:03.383 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5260 (offs:4 leng:4) 2022-10-25 17:57:03.383 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x5267 2022-10-25 17:57:03.383 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x5266 2022-10-25 17:57:03.383 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5260, offs:0 leng:4 value:0x0A 2022-10-25 17:57:03.383 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5260 (offs:0 leng:4) 2022-10-25 17:57:03.383 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5269, offs:4 leng:3 value:0x07 2022-10-25 17:57:03.383 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5269 (offs:4 leng:3) 2022-10-25 17:57:03.383 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5261, offs:0 leng:3 value:0x01 2022-10-25 17:57:03.383 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5261 (offs:0 leng:3) 2022-10-25 17:57:03.383 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5262, offs:6 leng:1 value:0x01 2022-10-25 17:57:03.383 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5262 (offs:6 leng:1) 2022-10-25 17:57:03.383 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5262, offs:4 leng:2 value:0x02 2022-10-25 17:57:03.383 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5262 (offs:4 leng:2) 2022-10-25 17:57:03.383 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5265, offs:7 leng:1 value:0x01 2022-10-25 17:57:03.383 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5265 (offs:7 leng:1) 2022-10-25 17:57:03.383 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5269, offs:0 leng:1 value:0x00 2022-10-25 17:57:03.383 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5269 (offs:0 leng:1) 2022-10-25 17:57:03.383 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5269, offs:1 leng:1 value:0x01 2022-10-25 17:57:03.383 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5269 (offs:1 leng:1) 2022-10-25 17:57:03.383 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5262, offs:1 leng:1 value:0x00 2022-10-25 17:57:03.383 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5262 (offs:1 leng:1) 2022-10-25 17:57:03.383 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5262, offs:0 leng:1 value:0x00 2022-10-25 17:57:03.384 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5262 (offs:0 leng:1) 2022-10-25 17:57:03.384 [HAL:XDEB] [sx1302_send:2608] Setting LoRa syncword 0x34 2022-10-25 17:57:03.384 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x526D, offs:0 leng:5 value:0x06 2022-10-25 17:57:03.384 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x526D (offs:0 leng:5) 2022-10-25 17:57:03.384 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x526E, offs:0 leng:5 value:0x08 2022-10-25 17:57:03.384 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x526E (offs:0 leng:5) 2022-10-25 17:57:03.384 [HAL:XDEB] [sx1302_send:2621] Disable Fine Sync 2022-10-25 17:57:03.384 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5262, offs:7 leng:1 value:0x00 2022-10-25 17:57:03.384 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5262 (offs:7 leng:1) 2022-10-25 17:57:03.384 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x5263 2022-10-25 17:57:03.384 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5261, offs:6 leng:2 value:0x00 2022-10-25 17:57:03.384 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5261 (offs:6 leng:2) 2022-10-25 17:57:03.384 [HAL:XDEB] [sx1302_send:2638] Low datarate optimization DISABLED 2022-10-25 17:57:03.384 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5261, offs:4 leng:2 value:0x00 2022-10-25 17:57:03.384 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5261 (offs:4 leng:2) 2022-10-25 17:57:03.384 [HAL:XDEB] [sx1302_tx_set_start_delay:2264] INFO: tx_start_delay=47709 (48000, radio_bw_delay=21, filter_delay=254, modem_delay=16) 2022-10-25 17:57:03.384 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5207, offs:0 leng:1 value:0x01 2022-10-25 17:57:03.384 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5207 (offs:0 leng:1) 2022-10-25 17:57:03.385 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5207, offs:0 leng:1 value:0x00 2022-10-25 17:57:03.385 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5207 (offs:0 leng:1) 2022-10-25 17:57:03.385 [HAL:XDEB] [sx1302_send:2751] Start Tx: Freq:927500000 SF10 size:17 preamb:8 2022-10-25 17:57:03.385 [HAL:XDEB] [sx1302_send:2761] --> programming trig delay at 25732011 (823424323) 2022-10-25 17:57:03.385 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x5204 2022-10-25 17:57:03.385 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x5203 2022-10-25 17:57:03.385 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x5202 2022-10-25 17:57:03.385 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x5201 2022-10-25 17:57:03.385 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5200, offs:1 leng:1 value:0x00 2022-10-25 17:57:03.385 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5200 (offs:1 leng:1) 2022-10-25 17:57:03.385 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5200, offs:1 leng:1 value:0x01 2022-10-25 17:57:03.385 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5200 (offs:1 leng:1) 2022-10-25 17:57:03.385 [HAL:XDEB] [lgw_usb_flush:466] INFO: flushing USB write buffer 2022-10-25 17:57:03.387 [HAL:XDEB] [lgw_usb_set_write_mode:436] setting USB write mode to SINGLE 2022-10-25 17:57:03.387 [HAL:XDEB] [lgw_send:1484] --- OUT 2022-10-25 17:57:03.408 [HAL:XDEB] [lgw_status:1496] --- IN 2022-10-25 17:57:03.408 [HAL:XDEB] [lgw_status:1523] --- OUT 2022-10-25 17:57:03.408 [AIO:XDEB] [3|WS] > {"msgtype":"dntxed","seqno":65369,"diid":65369,"DR":10,"Freq":927500000,"DevEui":"00-00-00-00-00-00-00-01","rctx":0,"xtime":50665495833651581,"txtime":14296.149474,"gpstime":0} 2022-10-25 17:57:03.408 [S2E:INFO] TX ::1 diid=65369 [ant#0] - dntxed: 927.5MHz 26.0dBm ant#0(0) DR10 SF10/BW500 frame=20EA0397C9180A55A6EB5715..01C1498D (17 bytes) 2022-10-25 17:57:03.408 [AIO:XDEB] [3] socket write bytes=184 2022-10-25 17:57:03.485 [S2E:DEBU] Tx done diid=65369 2022-10-25 17:57:03.719 [SYN:XDEB] SYNC: ustime=0x00035422C0F3 (Q=587): xticks=0x018d6978 xtime=0xB40000018D6978 - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:57:04.770 [SYN:XDEB] SYNC: ustime=0x00035432C94C (Q=582): xticks=0x019d7111 xtime=0xB40000019D7111 - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:57:04.770 [SYN:WARN] Repeated excessive clock drifts between MCU/SX130X#0 (24 retries): 193.3ppm (threshold 100.0ppm) 2022-10-25 17:57:05.820 [SYN:XDEB] SYNC: ustime=0x00035442D1BA (Q=583): xticks=0x01ad78c3 xtime=0xB4000001AD78C3 - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:57:06.835 [AIO:XDEB] [3] socket read bytes=2 2022-10-25 17:57:06.835 [AIO:XDEB] [3|WS] < PING () 2022-10-25 17:57:06.835 [AIO:XDEB] [3|WS] > PONG 2022-10-25 17:57:06.835 [AIO:XDEB] [3] socket write bytes=6 2022-10-25 17:57:06.871 [SYN:XDEB] SYNC: ustime=0x00035452DA16 (Q=600): xticks=0x01bd806f xtime=0xB4000001BD806F - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:57:07.922 [SYN:XDEB] SYNC: ustime=0x00035462E25B (Q=550): xticks=0x01cd87ec xtime=0xB4000001CD87EC - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:57:07.922 [SYN:WARN] Repeated excessive clock drifts between MCU/SX130X#0 (27 retries): 191.8ppm (threshold 100.0ppm) 2022-10-25 17:57:08.973 [SYN:XDEB] SYNC: ustime=0x00035472EAB7 (Q=549): xticks=0x01dd8f88 xtime=0xB4000001DD8F88 - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) export STATION_TLSDBG=42022-10-25 17:57:10.023 [SYN:XDEB] SYNC: ustime=0x00035482F304 (Q=583): xticks=0x01ed9711 xtime=0xB4000001ED9711 - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:57:10.023 [SYN:INFO] Time sync qualities: min=549 q90=660 max=667 (previous q90=2147483647) 2022-10-25 17:57:11.075 [SYN:XDEB] SYNC: ustime=0x00035492FDC4 (Q=550): xticks=0x01fda113 xtime=0xB4000001FDA113 - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:57:11.075 [SYN:WARN] Repeated excessive clock drifts between MCU/SX130X#0 (30 retries): 191.0ppm (threshold 100.0ppm) 2022-10-25 17:57:12.125 [SYN:XDEB] SYNC: ustime=0x000354A30646 (Q=616): xticks=0x020da8bc xtime=0xB40000020DA8BC - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:57:13.176 [SYN:XDEB] SYNC: ustime=0x000354B30EDC (Q=643): xticks=0x021db0cd xtime=0xB40000021DB0CD - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:57:14.227 [SYN:XDEB] SYNC: ustime=0x000354C31742 (Q=542): xticks=0x022db860 xtime=0xB40000022DB860 - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:57:14.227 [SYN:WARN] Repeated excessive clock drifts between MCU/SX130X#0 (33 retries): 189.8ppm (threshold 100.0ppm) 2022-10-25 17:57:15.278 [SYN:XDEB] SYNC: ustime=0x000354D31FCC (Q=653): xticks=0x023dbffe xtime=0xB40000023DBFFE - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:57:16.328 [SYN:XDEB] SYNC: ustime=0x000354E3285D (Q=595): xticks=0x024dc7eb xtime=0xB40000024DC7EB - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:57:17.379 [SYN:XDEB] SYNC: ustime=0x000354F330E0 (Q=642): xticks=0x025dcf98 xtime=0xB40000025DCF98 - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:57:17.379 [SYN:WARN] Repeated excessive clock drifts between MCU/SX130X#0 (36 retries): 190.2ppm (threshold 100.0ppm) 2022-10-25 17:57:18.430 [SYN:XDEB] SYNC: ustime=0x000355033983 (Q=602): xticks=0x026dd799 xtime=0xB40000026DD799 - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:57:19.481 [SYN:XDEB] SYNC: ustime=0x0003551341FE (Q=612): xticks=0x027ddf55 xtime=0xB40000027DDF55 - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:57:20.531 [SYN:XDEB] SYNC: ustime=0x000355234A77 (Q=598): xticks=0x028de723 xtime=0xB40000028DE723 - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:57:20.531 [SYN:WARN] Repeated excessive clock drifts between MCU/SX130X#0 (39 retries): 188.4ppm (threshold 100.0ppm) 2022-10-25 17:57:21.582 [SYN:XDEB] SYNC: ustime=0x000355335317 (Q=624): xticks=0x029deef9 xtime=0xB40000029DEEF9 - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:57:21.582 [SYN:INFO] MCU/SX130X drift stats: min: +188.4ppm q50: +191.3ppm q80: +193.3ppm max: +194.9ppm - threshold q90: +193.8ppm 2022-10-25 17:57:21.582 [SYN:INFO] Mean MCU drift vs SX130X#0: 191.1ppm 2022-10-25 17:57:22.629 [SYN:XDEB] SYNC: ustime=0x000355435C02 (Q=664): xticks=0x02adf73b xtime=0xB4000002ADF73B - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:57:22.629 [SYN:VERB] Time sync rejected: quality=664 threshold=660 2022-10-25 17:57:24.730 [SYN:XDEB] SYNC: ustime=0x000355636A33 (Q=598): xticks=0x02ce03fc xtime=0xB4000002CE03FC - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:57:25.781 [SYN:XDEB] SYNC: ustime=0x0003557372C2 (Q=635): xticks=0x02de0bc2 xtime=0xB4000002DE0BC2 - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:57:25.781 [SYN:WARN] Repeated excessive clock drifts between MCU/SX130X#0 (42 retries): 187.4ppm (threshold 100.0ppm) 2022-10-25 17:57:26.831 [SYN:XDEB] SYNC: ustime=0x000355837B82 (Q=630): xticks=0x02ee13cf xtime=0xB4000002EE13CF - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:57:27.883 [SYN:XDEB] SYNC: ustime=0x00035593882D (Q=605): xticks=0x02fe1fce xtime=0xB4000002FE1FCE - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:57:28.934 [SYN:XDEB] SYNC: ustime=0x000355A3909E (Q=592): xticks=0x030e2799 xtime=0xB40000030E2799 - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:57:28.934 [SYN:WARN] Repeated excessive clock drifts between MCU/SX130X#0 (45 retries): 185.9ppm (threshold 100.0ppm) 2022-10-25 17:57:29.985 [SYN:XDEB] SYNC: ustime=0x000355B39930 (Q=607): xticks=0x031e2f6f xtime=0xB40000031E2F6F - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:57:31.035 [SYN:XDEB] SYNC: ustime=0x000355C3A1AB (Q=603): xticks=0x032e3737 xtime=0xB40000032E3737 - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:57:32.086 [SYN:XDEB] SYNC: ustime=0x000355D3AA2D (Q=618): xticks=0x033e3efa xtime=0xB40000033E3EFA - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:57:32.086 [SYN:WARN] Repeated excessive clock drifts between MCU/SX130X#0 (48 retries): 185.4ppm (threshold 100.0ppm) 2022-10-25 17:57:33.137 [SYN:XDEB] SYNC: ustime=0x000355E3B2AD (Q=585): xticks=0x034e46db xtime=0xB40000034E46DB - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:57:34.188 [SYN:XDEB] SYNC: ustime=0x000355F3BB35 (Q=658): xticks=0x035e4e90 xtime=0xB40000035E4E90 - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:57:35.239 [SYN:XDEB] SYNC: ustime=0x00035603C3DE (Q=653): xticks=0x036e568b xtime=0xB40000036E568B - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:57:35.239 [SYN:WARN] Repeated excessive clock drifts between MCU/SX130X#0 (51 retries): 184.7ppm (threshold 100.0ppm) 2022-10-25 17:57:36.289 [SYN:XDEB] SYNC: ustime=0x00035613CC9B (Q=627): xticks=0x037e5ea8 xtime=0xB40000037E5EA8 - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:57:37.341 [SYN:XDEB] SYNC: ustime=0x00035623D998 (Q=642): xticks=0x038e6b12 xtime=0xB40000038E6B12 - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:57:38.392 [SYN:XDEB] SYNC: ustime=0x00035633E21F (Q=594): xticks=0x039e72da xtime=0xB40000039E72DA - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:57:38.392 [SYN:WARN] Repeated excessive clock drifts between MCU/SX130X#0 (54 retries): 183.3ppm (threshold 100.0ppm) 2022-10-25 17:57:38.719 [AIO:XDEB] [3] socket read bytes=2 2022-10-25 17:57:38.719 [AIO:XDEB] [3|WS] < PING () 2022-10-25 17:57:38.719 [AIO:XDEB] [3|WS] > PONG 2022-10-25 17:57:38.719 [AIO:XDEB] [3] socket write bytes=6 2022-10-25 17:57:39.444 [SYN:XDEB] SYNC: ustime=0x00035643EE22 (Q=770): xticks=0x03ae7e1d xtime=0xB4000003AE7E1D - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:57:39.444 [SYN:VERB] Time sync rejected: quality=770 threshold=660 2022-10-25 17:57:41.544 [SYN:XDEB] SYNC: ustime=0x00035663FC72 (Q=553): xticks=0x03ce8b3c xtime=0xB4000003CE8B3C - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:57:42.595 [SYN:XDEB] SYNC: ustime=0x0003567404B1 (Q=550): xticks=0x03de92cc xtime=0xB4000003DE92CC - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:57:43.647 [SYN:XDEB] SYNC: ustime=0x000356840FB8 (Q=625): xticks=0x03ee9cff xtime=0xB4000003EE9CFF - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:57:43.647 [SYN:INFO] Time sync qualities: min=542 q90=658 max=770 (previous q90=660) 2022-10-25 17:57:43.647 [SYN:WARN] Repeated excessive clock drifts between MCU/SX130X#0 (57 retries): 182.1ppm (threshold 100.0ppm) 2022-10-25 17:57:44.697 [SYN:XDEB] SYNC: ustime=0x000356941880 (Q=622): xticks=0x03fea528 xtime=0xB4000003FEA528 - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:57:45.748 [SYN:XDEB] SYNC: ustime=0x000356A420E0 (Q=549): xticks=0x040eacfc xtime=0xB40000040EACFC - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:57:46.799 [SYN:XDEB] SYNC: ustime=0x000356B429A4 (Q=683): xticks=0x041eb50e xtime=0xB40000041EB50E - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:57:46.799 [SYN:VERB] Time sync rejected: quality=683 threshold=658 2022-10-25 17:57:48.900 [SYN:XDEB] SYNC: ustime=0x000356D4381F (Q=554): xticks=0x043ec23b xtime=0xB40000043EC23B - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:57:48.900 [SYN:INFO] MCU/SX130X drift stats: min: +180.0ppm q50: +184.7ppm q80: +186.5ppm max: +187.4ppm - threshold q90: +187.3ppm 2022-10-25 17:57:48.900 [SYN:INFO] Mean MCU drift vs SX130X#0: 184.2ppm 2022-10-25 17:57:48.895 [SYN:WARN] Repeated excessive clock drifts between MCU/SX130X#0 (60 retries): 180.0ppm (threshold 100.0ppm) 2022-10-25 17:57:49.946 [SYN:XDEB] SYNC: ustime=0x000356E440D5 (Q=598): xticks=0x044eca37 xtime=0xB40000044ECA37 - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:57:50.996 [SYN:XDEB] SYNC: ustime=0x000356F4495D (Q=635): xticks=0x045ed202 xtime=0xB40000045ED202 - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:57:52.047 [SYN:XDEB] SYNC: ustime=0x000357045204 (Q=664): xticks=0x046eda0e xtime=0xB40000046EDA0E - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:57:52.047 [SYN:VERB] Time sync rejected: quality=664 threshold=658 2022-10-25 17:57:54.148 [SYN:XDEB] SYNC: ustime=0x00035724605A (Q=663): xticks=0x048ee706 xtime=0xB40000048EE706 - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:57:54.148 [SYN:VERB] Time sync rejected: quality=663 threshold=658 2022-10-25 17:57:56.249 [SYN:XDEB] SYNC: ustime=0x000357446E8B (Q=594): xticks=0x04aef407 xtime=0xB4000004AEF407 - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:57:56.249 [SYN:WARN] Repeated excessive clock drifts between MCU/SX130X#0 (63 retries): 178.2ppm (threshold 100.0ppm) 2022-10-25 17:57:57.300 [SYN:XDEB] SYNC: ustime=0x00035754773A (Q=649): xticks=0x04befbfa xtime=0xB4000004BEFBFA - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:57:58.350 [SYN:XDEB] SYNC: ustime=0x000357647FC6 (Q=612): xticks=0x04cf03f2 xtime=0xB4000004CF03F2 - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:57:59.401 [SYN:XDEB] SYNC: ustime=0x00035774882A (Q=585): xticks=0x04df0bc3 xtime=0xB4000004DF0BC3 - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:57:59.401 [SYN:WARN] Repeated excessive clock drifts between MCU/SX130X#0 (66 retries): 177.2ppm (threshold 100.0ppm) 2022-10-25 17:58:00.452 [SYN:XDEB] SYNC: ustime=0x0003578490CE (Q=643): xticks=0x04ef13a1 xtime=0xB4000004EF13A1 - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:58:01.503 [SYN:XDEB] SYNC: ustime=0x00035794993E (Q=566): xticks=0x04ff1b94 xtime=0xB4000004FF1B94 - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:58:02.553 [SYN:XDEB] SYNC: ustime=0x000357A4A18C (Q=578): xticks=0x050f233a xtime=0xB40000050F233A - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:58:02.553 [SYN:WARN] Repeated excessive clock drifts between MCU/SX130X#0 (69 retries): 176.4ppm (threshold 100.0ppm) 2022-10-25 17:58:03.604 [SYN:XDEB] SYNC: ustime=0x000357B4AA24 (Q=639): xticks=0x051f2b26 xtime=0xB40000051F2B26 - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:58:04.655 [SYN:XDEB] SYNC: ustime=0x000357C4B2B2 (Q=595): xticks=0x052f3320 xtime=0xB40000052F3320 - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:58:05.706 [SYN:XDEB] SYNC: ustime=0x000357D4BB24 (Q=593): xticks=0x053f3aeb xtime=0xB40000053F3AEB - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:58:05.706 [SYN:WARN] Repeated excessive clock drifts between MCU/SX130X#0 (72 retries): 175.6ppm (threshold 100.0ppm) 2022-10-25 17:58:06.757 [SYN:XDEB] SYNC: ustime=0x000357E4C7E0 (Q=643): xticks=0x054f46eb xtime=0xB40000054F46EB - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:58:07.808 [SYN:XDEB] SYNC: ustime=0x000357F4D064 (Q=595): xticks=0x055f4eee xtime=0xB40000055F4EEE - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:58:08.859 [SYN:XDEB] SYNC: ustime=0x00035804D8DA (Q=613): xticks=0x056f56ba xtime=0xB40000056F56BA - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:58:08.859 [SYN:WARN] Repeated excessive clock drifts between MCU/SX130X#0 (75 retries): 174.9ppm (threshold 100.0ppm) 2022-10-25 17:58:09.910 [SYN:XDEB] SYNC: ustime=0x00035814E177 (Q=603): xticks=0x057f5ec0 xtime=0xB40000057F5EC0 - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:58:10.600 [AIO:XDEB] [3] socket read bytes=2 2022-10-25 17:58:10.600 [AIO:XDEB] [3|WS] < PING () 2022-10-25 17:58:10.600 [AIO:XDEB] [3|WS] > PONG 2022-10-25 17:58:10.600 [AIO:XDEB] [3] socket write bytes=6 2022-10-25 17:58:10.960 [SYN:XDEB] SYNC: ustime=0x00035824E9FD (Q=625): xticks=0x058f669b xtime=0xB40000058F669B - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:58:12.011 [SYN:XDEB] SYNC: ustime=0x00035834F29C (Q=654): xticks=0x059f6e8e xtime=0xB40000059F6E8E - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:58:12.011 [SYN:WARN] Repeated excessive clock drifts between MCU/SX130X#0 (78 retries): 174.3ppm (threshold 100.0ppm) 2022-10-25 17:58:13.062 [SYN:XDEB] SYNC: ustime=0x00035844FB61 (Q=628): xticks=0x05af76bd xtime=0xB4000005AF76BD - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:58:14.113 [SYN:XDEB] SYNC: ustime=0x000358550411 (Q=691): xticks=0x05bf7eb8 xtime=0xB4000005BF7EB8 - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:58:14.113 [SYN:VERB] Time sync rejected: quality=691 threshold=658 2022-10-25 17:58:16.214 [SYN:XDEB] SYNC: ustime=0x000358751252 (Q=603): xticks=0x05df8bf0 xtime=0xB4000005DF8BF0 - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:58:16.214 [SYN:INFO] MCU/SX130X drift stats: min: +172.9ppm q50: +176.3ppm q80: +178.2ppm max: +180.0ppm - threshold q90: +180.0ppm 2022-10-25 17:58:16.214 [SYN:INFO] Mean MCU drift vs SX130X#0: 176.3ppm 2022-10-25 17:58:17.261 [SYN:XDEB] SYNC: ustime=0x000358851F1D (Q=637): xticks=0x05ef980b xtime=0xB4000005EF980B - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:58:17.261 [SYN:WARN] Repeated excessive clock drifts between MCU/SX130X#0 (81 retries): 172.8ppm (threshold 100.0ppm) 2022-10-25 17:58:18.311 [SYN:XDEB] SYNC: ustime=0x0003589527DF (Q=639): xticks=0x05ffa05d xtime=0xB4000005FFA05D - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:58:19.362 [SYN:XDEB] SYNC: ustime=0x000358A5306B (Q=598): xticks=0x060fa83b xtime=0xB40000060FA83B - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:58:19.362 [SYN:INFO] Time sync qualities: min=549 q90=664 max=691 (previous q90=658) 2022-10-25 17:58:20.413 [SYN:XDEB] SYNC: ustime=0x000358B53922 (Q=655): xticks=0x061fb076 xtime=0xB40000061FB076 - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:58:20.413 [SYN:WARN] Repeated excessive clock drifts between MCU/SX130X#0 (84 retries): 171.5ppm (threshold 100.0ppm) 2022-10-25 17:58:21.465 [SYN:XDEB] SYNC: ustime=0x000358C5461F (Q=648): xticks=0x062fbca2 xtime=0xB40000062FBCA2 - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:58:22.516 [SYN:XDEB] SYNC: ustime=0x000358D54EC1 (Q=645): xticks=0x063fc4ab xtime=0xB40000063FC4AB - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:58:23.567 [SYN:XDEB] SYNC: ustime=0x000358E5576A (Q=655): xticks=0x064fccb9 xtime=0xB40000064FCCB9 - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:58:23.567 [SYN:WARN] Repeated excessive clock drifts between MCU/SX130X#0 (87 retries): 171.3ppm (threshold 100.0ppm) 2022-10-25 17:58:24.617 [SYN:XDEB] SYNC: ustime=0x000358F56012 (Q=591): xticks=0x065fd4ec xtime=0xB40000065FD4EC - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:58:25.668 [SYN:XDEB] SYNC: ustime=0x00035905688E (Q=618): xticks=0x066fdcc5 xtime=0xB40000066FDCC5 - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 15:31:06.835 [HAL:INFO] [lgw_com_open:88] Opening USB communication interface 2022-10-25 15:31:06.837 [HAL:INFO] [lgw_usb_open:162] INFO: Configuring TTY 2022-10-25 15:31:06.837 [HAL:INFO] [lgw_usb_open:171] INFO: Flushing TTY 2022-10-25 15:31:06.837 [HAL:INFO] [lgw_usb_open:180] INFO: Setting TTY in blocking mode 2022-10-25 15:31:06.837 [HAL:INFO] [lgw_usb_open:195] INFO: Connect to MCU 2022-10-25 15:31:06.838 [HAL:INFO] [lgw_usb_open:203] INFO: Concentrator MCU version is V01.00.00 2022-10-25 15:31:06.838 [HAL:INFO] [lgw_usb_open:210] INFO: MCU status: sys_time:5566062 temperature:25.6oC 2022-10-25 15:31:06.839 [HAL:INFO] [lgw_connect:1192] chip version is 0x10 (v1.0) 2022-10-25 15:31:09.069 [HAL:INFO] [timestamp_counter_mode:431] using legacy timestamp 2022-10-25 15:31:09.294 [RAL:INFO] Concentrator started (2s458ms) 2022-10-25 15:31:09.294 [S2E:INFO] Configuring for region: US915 -- 923.0MHz..928.0MHz 2022-10-25 15:31:09.294 [S2E:INFO] DR0 SF10/BW125 2022-10-25 15:31:09.294 [S2E:INFO] DR1 SF9/BW125 2022-10-25 15:31:09.294 [S2E:INFO] DR2 SF8/BW125 2022-10-25 15:31:09.294 [S2E:INFO] DR3 SF7/BW125 2022-10-25 15:31:09.294 [S2E:INFO] DR4 SF8/BW500 2022-10-25 15:31:09.294 [S2E:INFO] DR5 FSK 2022-10-25 15:31:09.294 [S2E:INFO] DR6 FSK 2022-10-25 15:31:09.294 [S2E:INFO] DR7 FSK 2022-10-25 15:31:09.294 [S2E:INFO] DR8 SF12/BW500 2022-10-25 15:31:09.294 [S2E:INFO] DR9 SF11/BW500 2022-10-25 15:31:09.294 [S2E:INFO] DR10 SF10/BW500 2022-10-25 15:31:09.294 [S2E:INFO] DR11 SF9/BW500 2022-10-25 15:31:09.294 [S2E:INFO] DR12 SF8/BW500 2022-10-25 15:31:09.294 [S2E:INFO] DR13 SF7/BW500 2022-10-25 15:31:09.294 [S2E:INFO] DR14 FSK 2022-10-25 15:31:09.294 [S2E:INFO] DR15 FSK 2022-10-25 15:31:09.295 [S2E:INFO] TX power: 26.0 dBm EIRP 2022-10-25 15:31:09.295 [S2E:INFO] JoinEui list: 0 entries 2022-10-25 15:31:09.295 [S2E:INFO] NetID filter: FFFFFFFF-FFFFFFFF-FFFFFFFF-FFFFFFFF 2022-10-25 15:31:09.295 [S2E:INFO] Dev/test settings: nocca=1 nodc=1 nodwell=1 2022-10-25 15:31:09.295 [S2E:INFO] Beaconing every 2m8s on 923.3MHz(8) @ DR8 (frame layout 5/11/23) 2022-10-25 15:31:09.295 [S2E:INFO] Beaconing suspend - missing GPS data: time 2022-10-25 15:31:13.501 [SYN:WARN] Repeated excessive clock drifts between MCU/SX130X#0 (3 retries): -120.4ppm (threshold 100.0ppm) 2022-10-25 15:31:16.653 [SYN:WARN] Repeated excessive clock drifts between MCU/SX130X#0 (6 retries): -119.9ppm (threshold 100.0ppm) 2022-10-25 15:31:19.806 [SYN:WARN] Repeated excessive clock drifts between MCU/SX130X#0 (9 retries): -114.4ppm (threshold 100.0ppm) 2022-10-25 15:31:22.958 [SYN:WARN] Repeated excessive clock drifts between MCU/SX130X#0 (12 retries): -115.4ppm (threshold 100.0ppm) 2022-10-25 15:31:26.111 [SYN:WARN] Repeated excessive clock drifts between MCU/SX130X#0 (15 retries): -114.7ppm (threshold 100.0ppm) 2022-10-25 15:31:29.263 [SYN:WARN] Repeated excessive clock drifts between MCU/SX130X#0 (18 retries): -111.6ppm (threshold 100.0ppm) 2022-10-25 15:31:31.364 [SYN:INFO] MCU/SX130X drift stats: min: -111.6ppm q50: -115.9ppm q80: -120.2ppm max: -130.9ppm - threshold q90: -121.1ppm 2022-10-25 15:31:31.364 [SYN:INFO] Mean MCU drift vs SX130X#0: -116.6ppm 2022-10-25 15:31:32.418 [SYN:WARN] Repeated excessive clock drifts between MCU/SX130X#0 (21 retries): -112.9ppm (threshold 100.0ppm) 2022-10-25 15:31:34.045 [RAL:DEBU] [CRC FAIL] 904.900MHz -8.75/-98.3 SF10/BW125 (mod=16/dr=10/bw=4) xtick=0185b122 (25538850) 23 bytes: 000000C600000003300707006397040C00618628E6AFDF 2022-10-25 15:31:34.047 [S2E:VERB] RX 905.3MHz DR0 SF10/BW125 snr=12.8 rssi=-36 xtime=0x2B00000185B137 - jreq MHdr=00 JoinEui=::0 DevEui=0:18:0:785 DevNonce=2 MIC=-542120223 2022-10-25 15:31:35.571 [SYN:WARN] Repeated excessive clock drifts between MCU/SX130X#0 (24 retries): -112.1ppm (threshold 100.0ppm) 2022-10-25 15:31:35.949 [S2E:DEBU] ::1 diid=15474 [ant#0] - next TX start ahead by 3s82ms (15:31:39.032591) 2022-10-25 15:31:38.723 [SYN:WARN] Repeated excessive clock drifts between MCU/SX130X#0 (27 retries): -111.9ppm (thresho2022-10-25 17:58:26.719 [SYN:XDEB] SYNC: ustime=0x000359157107 (Q=607): xticks=0x067fe4d3 xtime=0xB40000067FE4D3 - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:58:26.719 [SYN:WARN] Repeated excessive clock drifts between MCU/SX130X#0 (90 retries): 169.9ppm (threshold 100.0ppm) 2022-10-25 17:58:27.770 [SYN:XDEB] SYNC: ustime=0x0003592579C6 (Q=670): xticks=0x068fecbb xtime=0xB40000068FECBB - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:58:27.770 [SYN:VERB] Time sync rejected: quality=670 threshold=664 2022-10-25 17:58:29.870 [SYN:XDEB] SYNC: ustime=0x000359458805 (Q=590): xticks=0x06aff9f1 xtime=0xB4000006AFF9F1 - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:58:30.921 [SYN:XDEB] SYNC: ustime=0x00035955906F (Q=584): xticks=0x06c001d0 xtime=0xB4000006C001D0 - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:58:31.972 [SYN:XDEB] SYNC: ustime=0x0003596598CA (Q=557): xticks=0x06d009a1 xtime=0xB4000006D009A1 - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:58:31.972 [SYN:WARN] Repeated excessive clock drifts between MCU/SX130X#0 (93 retries): 168.7ppm (threshold 100.0ppm) 2022-10-25 17:58:33.023 [SYN:XDEB] SYNC: ustime=0x00035975A155 (Q=629): xticks=0x06e0117a xtime=0xB4000006E0117A - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:58:34.073 [SYN:XDEB] SYNC: ustime=0x00035985A9EF (Q=636): xticks=0x06f0197c xtime=0xB4000006F0197C - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:58:34.643 [HAL:XDEB] [rx_buffer_fetch:154] ----------------- 2022-10-25 17:58:34.644 [HAL:XDEB] [rx_buffer_fetch:155] rx_buffer_fetch: nb_bytes to be fetched: 47 (47 0) 2022-10-25 17:58:34.644 [HAL:XDEB] [rx_buffer_fetch:165] RX BUFFER: A5C018008308800A0080635C0C260000000126A2F4A9A054A6DD87F12FBAF4511C0038BBBB000244F618DF2289002E 2022-10-25 17:58:34.644 [HAL:XDEB] [rx_buffer_fetch:177] INFO: syncword found at idx 0 2022-10-25 17:58:34.645 [HAL:XDEB] [lgw_usb_get_temperature:500] temperature:28.7oC 2022-10-25 17:58:34.645 [HAL:XDEB] [rx_buffer_pop:244] INFO: pkt syncword found at index 0 2022-10-25 17:58:34.645 [HAL:XDEB] [rx_buffer_pop:275] Packet checksum OK (0x2E) 2022-10-25 17:58:34.645 [HAL:XDEB] [rx_buffer_pop:311] ----------------- 2022-10-25 17:58:34.645 [HAL:XDEB] [rx_buffer_pop:312] modem: 8 2022-10-25 17:58:34.645 [HAL:XDEB] [rx_buffer_pop:313] chan: 0 2022-10-25 17:58:34.645 [HAL:XDEB] [rx_buffer_pop:314] size: 24 2022-10-25 17:58:34.645 [HAL:XDEB] [rx_buffer_pop:315] crc_en: 1 2022-10-25 17:58:34.645 [HAL:XDEB] [rx_buffer_pop:316] crc_err: 0 2022-10-25 17:58:34.645 [HAL:XDEB] [rx_buffer_pop:317] sync_err: 0 2022-10-25 17:58:34.645 [HAL:XDEB] [rx_buffer_pop:318] hdr_err: 0 2022-10-25 17:58:34.645 [HAL:XDEB] [rx_buffer_pop:319] timing_set: 0 2022-10-25 17:58:34.645 [HAL:XDEB] [rx_buffer_pop:320] codr: 1 2022-10-25 17:58:34.645 [HAL:XDEB] [rx_buffer_pop:321] datr: 8 2022-10-25 17:58:34.645 [HAL:XDEB] [rx_buffer_pop:322] num_ts: 0 2022-10-25 17:58:34.645 [HAL:XDEB] [rx_buffer_pop:331] ----------------- 2022-10-25 17:58:34.645 [HAL:XDEB] [sx1302_parse:1946] [0 0x11] 2022-10-25 17:58:34.645 [HAL:XDEB] [sx1302_parse:1959] Note: LoRa packet (modem 8 chan 0) 2022-10-25 17:58:34.645 [HAL:XDEB] [sx1302_parse:1981] Payload CRC check OK (0x8922) 2022-10-25 17:58:34.645 [HAL:XDEB] [legacy_timestamp_correction:205] FTIME OFF : filtering_delay %lu 2022-10-25 17:58:34.645 [HAL:XDEB] [legacy_timestamp_correction:206] FTIME OFF : fft_delay_state3 %lu 2022-10-25 17:58:34.645 [HAL:XDEB] [legacy_timestamp_correction:207] FTIME OFF : fft_delay %lu 2022-10-25 17:58:34.645 [HAL:XDEB] [legacy_timestamp_correction:208] FTIME OFF : demap_delay %lu 2022-10-25 17:58:34.645 [HAL:XDEB] [legacy_timestamp_correction:209] FTIME OFF : decode_delay %lu 2022-10-25 17:58:34.645 [HAL:XDEB] [legacy_timestamp_correction:210] FTIME OFF : timestamp correction -874 2022-10-25 17:58:34.645 [HAL:XDEB] [sx1302_rssi_get_temperature_offset:2283] INFO: RSSI temperature compensation: 2022-10-25 17:58:34.645 [HAL:XDEB] [sx1302_rssi_get_temperature_offset:2284] coeff_a: 0.000 2022-10-25 17:58:34.645 [HAL:XDEB] [sx1302_rssi_get_temperature_offset:2285] coeff_b: 0.000 2022-10-25 17:58:34.645 [HAL:XDEB] [sx1302_rssi_get_temperature_offset:2286] coeff_c: 20.410 2022-10-25 17:58:34.645 [HAL:XDEB] [sx1302_rssi_get_temperature_offset:2287] coeff_d: 2162.560 2022-10-25 17:58:34.645 [HAL:XDEB] [sx1302_rssi_get_temperature_offset:2288] coeff_e: 0.000 2022-10-25 17:58:34.645 [HAL:XDEB] [lgw_receive:1320] INFO: RSSI temperature offset applied: 1.203 dB (current temperature 28.7 C) 2022-10-25 17:58:34.645 [HAL:XDEB] [lgw_receive:1323] INFO: nb pkt found:1 left:0 2022-10-25 17:58:34.645 [HAL:XDEB] [lgw_receive:1337] --- OUT 2022-10-25 17:58:34.645 [RAL:XDEB] [CRC OK] 903.900MHz 14.00/-27.2 SF8/BW125 (mod=16/dr=8/bw=4) xtick=06f8c448 (116966472) 24 bytes: 80635C0C260000000126A2F4A9A054A6DD87F12FBAF4511C 2022-10-25 17:58:34.647 [S2E:VERB] RX 903.9MHz DR2 SF8/BW125 snr=14.0 rssi=-27 xtime=0xB4000006F8C448 - updf mhdr=80 DevAddr=260C5C63 FCtrl=00 FCnt=0 FOpts=[] 0126A2F4..F12F mic=475133114 (24 bytes) 2022-10-25 17:58:34.647 [AIO:XDEB] [3|WS] > {"msgtype":"updf","MHdr":128,"DevAddr":638344291,"FCtrl":0,"FCnt":0,"FOpts":"","FPort":1,"FRMPayload":"26A2F4A9A054A6DD87F12F","MIC":475133114,"RefTime":1666720714.643853,"DR":2,"Freq":903900000,"upinfo":{"rctx":0,"xtime":50665495924884552,"gpstime":0,"fts":-1,"rssi":-27,"snr":14,"rxtime":1666720714.647221}} 2022-10-25 17:58:34.647 [AIO:XDEB] [3] socket write bytes=317 2022-10-25 17:58:35.124 [SYN:XDEB] SYNC: ustime=0x00035995B27B (Q=615): xticks=0x0700217f xtime=0xB400000700217F - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:58:35.124 [SYN:WARN] Repeated excessive clock drifts between MCU/SX130X#0 (96 retries): 168.1ppm (threshold 100.0ppm) 2022-10-25 17:58:35.149 [AIO:XDEB] [3] socket read bytes=282 2022-10-25 17:58:35.149 [AIO:XDEB] [3|WS] < {"msgtype":"dnmsg","DevEui":"00-00-00-00-00-00-00-01","dC":0,"diid":8,"pdu":"60635c0c26b0000000f1f3cf9032ab17fad3f2f0d1d2b0cec0ff368eec2e71d7561d9709e95e71","priority":25,"rctx":0,"MuxTime":1666720715.1489255,"RxDelay":1,"RX1DR":12,"RX1Freq":923300000,"xtime":50665495928884552} 2022-10-25 17:58:35.149 [S2E:DEBU] ::1 diid=8 [ant#0] - next TX start ahead by 4s472ms (17:58:39.622111) 2022-10-25 17:58:36.175 [SYN:XDEB] SYNC: ustime=0x000359A5BB30 (Q=639): xticks=0x07102996 xtime=0xB4000007102996 - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:58:37.226 [SYN:XDEB] SYNC: ustime=0x000359B5C3D0 (Q=641): xticks=0x072031a3 xtime=0xB40000072031A3 - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:58:38.277 [SYN:XDEB] SYNC: ustime=0x000359C5CC70 (Q=643): xticks=0x073039ae xtime=0xB40000073039AE - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:58:38.277 [SYN:WARN] Repeated excessive clock drifts between MCU/SX130X#0 (99 retries): 167.5ppm (threshold 100.0ppm) 2022-10-25 17:58:39.328 [SYN:XDEB] SYNC: ustime=0x000359D5D9BC (Q=595): xticks=0x07404681 xtime=0xB4000007404681 - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:58:39.329 [SYN:INFO] MCU/SX130X drift stats: min: +167.0ppm q50: +169.9ppm q80: +171.8ppm max: +172.8ppm - threshold q90: +172.1ppm 2022-10-25 17:58:39.329 [SYN:INFO] Mean MCU drift vs SX130X#0: 169.8ppm 2022-10-25 17:58:39.598 [S2E:VERB] ::1 diid=8 [ant#0] - starting TX in 19ms900us: 923.3MHz 26.0dBm ant#0(0) DR12 SF8/BW500 frame=60635C0C26B0000000F1F3CF..09E95E71 (39 bytes) 2022-10-25 17:58:39.598 [HAL:XDEB] [lgw_send:1350] --- IN 2022-10-25 17:58:39.598 [HAL:XDEB] [lgw_usb_set_write_mode:436] setting USB write mode to BULK 2022-10-25 17:58:39.598 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5209, offs:0 leng:1 value:0x00 2022-10-25 17:58:39.598 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5209 (offs:0 leng:1) 2022-10-25 17:58:39.598 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5220, offs:0 leng:2 value:0x01 2022-10-25 17:58:39.598 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5220 (offs:0 leng:2) 2022-10-25 17:58:39.598 [HAL:XDEB] [sx1302_send:2460] INFO: selecting TX Gain LUT index 14 2022-10-25 17:58:39.598 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x5223 2022-10-25 17:58:39.598 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x5224 2022-10-25 17:58:39.598 [HAL:XDEB] [sx1302_send:2468] INFO: Applying IQ offset (i:0, q:0) 2022-10-25 17:58:39.598 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x520D 2022-10-25 17:58:39.598 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5222, offs:0 leng:2 value:0x00 2022-10-25 17:58:39.598 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5222 (offs:0 leng:2) 2022-10-25 17:58:39.598 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x5225 2022-10-25 17:58:39.598 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x5226 2022-10-25 17:58:39.598 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x5227 2022-10-25 17:58:39.598 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x520C 2022-10-25 17:58:39.598 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5228, offs:0 leng:4 value:0x08 2022-10-25 17:58:39.598 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5228 (offs:0 leng:4) 2022-10-25 17:58:39.598 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x5229 2022-10-25 17:58:39.598 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5260, offs:4 leng:4 value:0x06 2022-10-25 17:58:39.598 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5260 (offs:4 leng:4) 2022-10-25 17:58:39.598 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x5267 2022-10-25 17:58:39.598 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x5266 2022-10-25 17:58:39.598 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5260, offs:0 leng:4 value:0x08 2022-10-25 17:58:39.598 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5260 (offs:0 leng:4) 2022-10-25 17:58:39.598 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5269, offs:4 leng:3 value:0x06 2022-10-25 17:58:39.598 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5269 (offs:4 leng:3) 2022-10-25 17:58:39.598 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5261, offs:0 leng:3 value:0x01 2022-10-25 17:58:39.598 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5261 (offs:0 leng:3) 2022-10-25 17:58:39.598 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5262, offs:6 leng:1 value:0x01 2022-10-25 17:58:39.598 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5262 (offs:6 leng:1) 2022-10-25 17:58:39.598 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5262, offs:4 leng:2 value:0x02 2022-10-25 17:58:39.598 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5262 (offs:4 leng:2) 2022-10-25 17:58:39.598 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5265, offs:7 leng:1 value:0x01 2022-10-25 17:58:39.598 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5265 (offs:7 leng:1) 2022-10-25 17:58:39.598 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5269, offs:0 leng:1 value:0x00 2022-10-25 17:58:39.598 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5269 (offs:0 leng:1) 2022-10-25 17:58:39.598 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5269, offs:1 leng:1 value:0x01 2022-10-25 17:58:39.599 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5269 (offs:1 leng:1) 2022-10-25 17:58:39.599 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5262, offs:1 leng:1 value:0x00 2022-10-25 17:58:39.599 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5262 (offs:1 leng:1) 2022-10-25 17:58:39.599 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5262, offs:0 leng:1 value:0x00 2022-10-25 17:58:39.599 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5262 (offs:0 leng:1) 2022-10-25 17:58:39.599 [HAL:XDEB] [sx1302_send:2608] Setting LoRa syncword 0x34 2022-10-25 17:58:39.599 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x526D, offs:0 leng:5 value:0x06 2022-10-25 17:58:39.599 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x526D (offs:0 leng:5) 2022-10-25 17:58:39.599 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x526E, offs:0 leng:5 value:0x08 2022-10-25 17:58:39.599 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x526E (offs:0 leng:5) 2022-10-25 17:58:39.599 [HAL:XDEB] [sx1302_send:2621] Disable Fine Sync 2022-10-25 17:58:39.599 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5262, offs:7 leng:1 value:0x00 2022-10-25 17:58:39.599 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5262 (offs:7 leng:1) 2022-10-25 17:58:39.599 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x5263 2022-10-25 17:58:39.599 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5261, offs:6 leng:2 value:0x00 2022-10-25 17:58:39.599 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5261 (offs:6 leng:2) 2022-10-25 17:58:39.599 [HAL:XDEB] [sx1302_send:2638] Low datarate optimization DISABLED 2022-10-25 17:58:39.599 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5261, offs:4 leng:2 value:0x00 2022-10-25 17:58:39.599 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5261 (offs:4 leng:2) 2022-10-25 17:58:39.599 [HAL:XDEB] [sx1302_tx_set_start_delay:2264] INFO: tx_start_delay=47837 (48000, radio_bw_delay=21, filter_delay=126, modem_delay=16) 2022-10-25 17:58:39.599 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5207, offs:0 leng:1 value:0x01 2022-10-25 17:58:39.599 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5207 (offs:0 leng:1) 2022-10-25 17:58:39.599 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5207, offs:0 leng:1 value:0x00 2022-10-25 17:58:39.599 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5207 (offs:0 leng:1) 2022-10-25 17:58:39.599 [HAL:XDEB] [sx1302_send:2751] Start Tx: Freq:923300000 SF8 size:39 preamb:8 2022-10-25 17:58:39.599 [HAL:XDEB] [sx1302_send:2761] --> programming trig delay at 121964978 (3902879267) 2022-10-25 17:58:39.599 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x5204 2022-10-25 17:58:39.599 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x5203 2022-10-25 17:58:39.599 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x5202 2022-10-25 17:58:39.599 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x5201 2022-10-25 17:58:39.599 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5200, offs:1 leng:1 value:0x00 2022-10-25 17:58:39.599 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5200 (offs:1 leng:1) 2022-10-25 17:58:39.599 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5200, offs:1 leng:1 value:0x01 2022-10-25 17:58:39.599 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5200 (offs:1 leng:1) 2022-10-25 17:58:39.599 [HAL:XDEB] [lgw_usb_flush:466] INFO: flushing USB write buffer 2022-10-25 17:58:39.601 [HAL:XDEB] [lgw_usb_set_write_mode:436] setting USB write mode to SINGLE 2022-10-25 17:58:39.601 [HAL:XDEB] [lgw_send:1484] --- OUT 2022-10-25 17:58:39.623 [HAL:XDEB] [lgw_status:1496] --- IN 2022-10-25 17:58:39.623 [HAL:XDEB] [lgw_status:1523] --- OUT 2022-10-25 17:58:39.623 [S2E:ERRO] ::1 diid=8 [ant#0] - radio is not emitting frame - abandoning TX, trying alternative 2022-10-25 17:58:39.623 [HAL:XDEB] [lgw_abort_tx:1534] --- IN 2022-10-25 17:58:39.623 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5200, offs:0 leng:1 value:0x00 2022-10-25 17:58:39.623 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5200 (offs:0 leng:1) 2022-10-25 17:58:39.623 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5200, offs:1 leng:1 value:0x00 2022-10-25 17:58:39.624 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5200 (offs:1 leng:1) 2022-10-25 17:58:39.624 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5200, offs:2 leng:1 value:0x00 2022-10-25 17:58:39.624 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5200 (offs:2 leng:1) 2022-10-25 17:58:39.625 [HAL:XDEB] [lgw_abort_tx:1545] --- OUT 2022-10-25 17:58:39.625 [S2E:VERB] ::1 diid=8 [ant#0] - class A has no more alternate TX time 2022-10-25 17:58:39.625 [S2E:WARN] ::1 diid=8 [ant#0] - unable to place frame 2022-10-25 17:58:40.375 [SYN:XDEB] SYNC: ustime=0x000359E5E288 (Q=645): xticks=0x07504eaa xtime=0xB4000007504EAA - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:58:41.426 [SYN:XDEB] SYNC: ustime=0x000359F5EB26 (Q=638): xticks=0x076056b9 xtime=0xB40000076056B9 - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:58:41.426 [SYN:WARN] Repeated excessive clock drifts between MCU/SX130X#0 (102 retries): 166.7ppm (threshold 100.0ppm) 2022-10-25 17:58:42.477 [SYN:XDEB] SYNC: ustime=0x00035A05F3DE (Q=630): xticks=0x07705eff xtime=0xB4000007705EFF - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:58:42.478 [AIO:XDEB] [3] socket read bytes=2 2022-10-25 17:58:42.478 [AIO:XDEB] [3|WS] < PING () 2022-10-25 17:58:42.478 [AIO:XDEB] [3|WS] > PONG 2022-10-25 17:58:42.479 [AIO:XDEB] [3] socket write bytes=6 2022-10-25 17:58:42.862 [HAL:XDEB] [rx_buffer_fetch:154] ----------------- 2022-10-25 17:58:42.862 [HAL:XDEB] [rx_buffer_fetch:155] rx_buffer_fetch: nb_bytes to be fetched: 47 (47 0) 2022-10-25 17:58:42.862 [HAL:XDEB] [rx_buffer_fetch:165] RX BUFFER: A5C018018308800E0080635C0C260000000126A2F4A9A054A6DD87F12FBAF4511C003FBCBC0000840EC5EE2289004E 2022-10-25 17:58:42.862 [HAL:XDEB] [rx_buffer_fetch:177] INFO: syncword found at idx 0 2022-10-25 17:58:42.863 [HAL:XDEB] [lgw_usb_get_temperature:500] temperature:28.7oC 2022-10-25 17:58:42.863 [HAL:XDEB] [rx_buffer_pop:244] INFO: pkt syncword found at index 0 2022-10-25 17:58:42.863 [HAL:XDEB] [rx_buffer_pop:275] Packet checksum OK (0x4E) 2022-10-25 17:58:42.863 [HAL:XDEB] [rx_buffer_pop:311] ----------------- 2022-10-25 17:58:42.863 [HAL:XDEB] [rx_buffer_pop:312] modem: 8 2022-10-25 17:58:42.863 [HAL:XDEB] [rx_buffer_pop:313] chan: 1 2022-10-25 17:58:42.863 [HAL:XDEB] [rx_buffer_pop:314] size: 24 2022-10-25 17:58:42.863 [HAL:XDEB] [rx_buffer_pop:315] crc_en: 1 2022-10-25 17:58:42.863 [HAL:XDEB] [rx_buffer_pop:316] crc_err: 0 2022-10-25 17:58:42.863 [HAL:XDEB] [rx_buffer_pop:317] sync_err: 0 2022-10-25 17:58:42.863 [HAL:XDEB] [rx_buffer_pop:318] hdr_err: 0 2022-10-25 17:58:42.863 [HAL:XDEB] [rx_buffer_pop:319] timing_set: 0 2022-10-25 17:58:42.863 [HAL:XDEB] [rx_buffer_pop:320] codr: 1 2022-10-25 17:58:42.863 [HAL:XDEB] [rx_buffer_pop:321] datr: 8 2022-10-25 17:58:42.863 [HAL:XDEB] [rx_buffer_pop:322] num_ts: 0 2022-10-25 17:58:42.863 [HAL:XDEB] [rx_buffer_pop:331] ----------------- 2022-10-25 17:58:42.863 [HAL:XDEB] [sx1302_parse:1946] [1 0x11] 2022-10-25 17:58:42.863 [HAL:XDEB] [sx1302_parse:1959] Note: LoRa packet (modem 8 chan 1) 2022-10-25 17:58:42.863 [HAL:XDEB] [sx1302_parse:1981] Payload CRC check OK (0x8922) 2022-10-25 17:58:42.863 [HAL:XDEB] [legacy_timestamp_correction:205] FTIME OFF : filtering_delay %lu 2022-10-25 17:58:42.863 [HAL:XDEB] [legacy_timestamp_correction:206] FTIME OFF : fft_delay_state3 %lu 2022-10-25 17:58:42.863 [HAL:XDEB] [legacy_timestamp_correction:207] FTIME OFF : fft_delay %lu 2022-10-25 17:58:42.863 [HAL:XDEB] [legacy_timestamp_correction:208] FTIME OFF : demap_delay %lu 2022-10-25 17:58:42.863 [HAL:XDEB] [legacy_timestamp_correction:209] FTIME OFF : decode_delay %lu 2022-10-25 17:58:42.863 [HAL:XDEB] [legacy_timestamp_correction:210] FTIME OFF : timestamp correction -874 2022-10-25 17:58:42.863 [HAL:XDEB] [sx1302_rssi_get_temperature_offset:2283] INFO: RSSI temperature compensation: 2022-10-25 17:58:42.863 [HAL:XDEB] [sx1302_rssi_get_temperature_offset:2284] coeff_a: 0.000 2022-10-25 17:58:42.863 [HAL:XDEB] [sx1302_rssi_get_temperature_offset:2285] coeff_b: 0.000 2022-10-25 17:58:42.863 [HAL:XDEB] [sx1302_rssi_get_temperature_offset:2286] coeff_c: 20.410 2022-10-25 17:58:42.863 [HAL:XDEB] [sx1302_rssi_get_temperature_offset:2287] coeff_d: 2162.560 2022-10-25 17:58:42.863 [HAL:XDEB] [sx1302_rssi_get_temperature_offset:2288] coeff_e: 0.000 2022-10-25 17:58:42.863 [HAL:XDEB] [lgw_receive:1320] INFO: RSSI temperature offset applied: 1.203 dB (current temperature 28.7 C) 2022-10-25 17:58:42.863 [HAL:XDEB] [lgw_receive:1323] INFO: nb pkt found:1 left:0 2022-10-25 17:58:42.864 [HAL:XDEB] [lgw_receive:1337] --- OUT 2022-10-25 17:58:42.864 [RAL:XDEB] [CRC OK] 904.100MHz 15.75/-26.2 SF8/BW125 (mod=16/dr=8/bw=4) xtick=0776250a (125183242) 24 bytes: 80635C0C260000000126A2F4A9A054A6DD87F12FBAF4511C 2022-10-25 17:58:42.865 [S2E:VERB] RX 904.1MHz DR2 SF8/BW125 snr=15.8 rssi=-26 xtime=0xB400000776250A - updf mhdr=80 DevAddr=260C5C63 FCtrl=00 FCnt=0 FOpts=[] 0126A2F4..F12F mic=475133114 (24 bytes) 2022-10-25 17:58:42.865 [AIO:XDEB] [3|WS] > {"msgtype":"updf","MHdr":128,"DevAddr":638344291,"FCtrl":0,"FCnt":0,"FOpts":"","FPort":1,"FRMPayload":"26A2F4A9A054A6DD87F12F","MIC":475133114,"RefTime":1666720722.867304,"DR":2,"Freq":904100000,"upinfo":{"rctx":0,"xtime":50665495933101322,"gpstime":0,"fts":-1,"rssi":-26,"snr":15.75,"rxtime":1666720722.865343}} 2022-10-25 17:58:42.865 [AIO:XDEB] [3] socket write bytes=320 2022-10-25 17:58:43.383 [AIO:XDEB] [3] socket read bytes=283 2022-10-25 17:58:43.383 [AIO:XDEB] [3|WS] < {"msgtype":"dnmsg","DevEui":"00-00-00-00-00-00-00-01","dC":0,"diid":22,"pdu":"60635c0c26b001000016067c53238c412abc2c34ecec3319f760720e400d48a3ea7934aa4e5754","priority":25,"rctx":0,"MuxTime":1666720723.3856866,"RxDelay":1,"RX1DR":12,"RX1Freq":923900000,"xtime":50665495937101322} 2022-10-25 17:58:43.383 [S2E:DEBU] ::1 diid=22 [ant#0] - next TX start ahead by 4s451ms (17:58:47.834954) 2022-10-25 17:58:43.528 [SYN:XDEB] SYNC: ustime=0x00035A15FC62 (Q=609): xticks=0x078066e7 xtime=0xB40000078066E7 - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:58:44.579 [SYN:XDEB] SYNC: ustime=0x00035A260718 (Q=598): xticks=0x07907120 xtime=0xB4000007907120 - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:58:44.579 [SYN:WARN] Repeated excessive clock drifts between MCU/SX130X#0 (105 retries): 165.6ppm (threshold 100.0ppm) 2022-10-25 17:58:45.630 [SYN:XDEB] SYNC: ustime=0x00035A360FB4 (Q=608): xticks=0x07a0791d xtime=0xB4000007A0791D - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:58:46.681 [SYN:XDEB] SYNC: ustime=0x00035A461835 (Q=622): xticks=0x07b08106 xtime=0xB4000007B08106 - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:58:47.731 [SYN:XDEB] SYNC: ustime=0x00035A5620C8 (Q=643): xticks=0x07c08906 xtime=0xB4000007C08906 - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:58:47.731 [SYN:WARN] Repeated excessive clock drifts between MCU/SX130X#0 (108 retries): 165.1ppm (threshold 100.0ppm) 2022-10-25 17:58:47.815 [S2E:VERB] ::1 diid=22 [ant#0] - starting TX in 19ms904us: 923.9MHz 26.0dBm ant#0(0) DR12 SF8/BW500 frame=60635C0C26B001000016067C..AA4E5754 (39 bytes) 2022-10-25 17:58:47.815 [HAL:XDEB] [lgw_send:1350] --- IN 2022-10-25 17:58:47.815 [HAL:XDEB] [lgw_usb_set_write_mode:436] setting USB write mode to BULK 2022-10-25 17:58:47.815 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5209, offs:0 leng:1 value:0x00 2022-10-25 17:58:47.815 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5209 (offs:0 leng:1) 2022-10-25 17:58:47.815 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5220, offs:0 leng:2 value:0x01 2022-10-25 17:58:47.815 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5220 (offs:0 leng:2) 2022-10-25 17:58:47.815 [HAL:XDEB] [sx1302_send:2460] INFO: selecting TX Gain LUT index 14 2022-10-25 17:58:47.815 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x5223 2022-10-25 17:58:47.815 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x5224 2022-10-25 17:58:47.815 [HAL:XDEB] [sx1302_send:2468] INFO: Applying IQ offset (i:0, q:0) 2022-10-25 17:58:47.815 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x520D 2022-10-25 17:58:47.815 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5222, offs:0 leng:2 value:0x00 2022-10-25 17:58:47.815 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5222 (offs:0 leng:2) 2022-10-25 17:58:47.815 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x5225 2022-10-25 17:58:47.815 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x5226 2022-10-25 17:58:47.815 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x5227 2022-10-25 17:58:47.815 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x520C 2022-10-25 17:58:47.815 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5228, offs:0 leng:4 value:0x08 2022-10-25 17:58:47.815 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5228 (offs:0 leng:4) 2022-10-25 17:58:47.815 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x5229 2022-10-25 17:58:47.815 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5260, offs:4 leng:4 value:0x06 2022-10-25 17:58:47.815 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5260 (offs:4 leng:4) 2022-10-25 17:58:47.815 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x5267 2022-10-25 17:58:47.815 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x5266 2022-10-25 17:58:47.815 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5260, offs:0 leng:4 value:0x08 2022-10-25 17:58:47.815 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5260 (offs:0 leng:4) 2022-10-25 17:58:47.815 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5269, offs:4 leng:3 value:0x06 2022-10-25 17:58:47.815 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5269 (offs:4 leng:3) 2022-10-25 17:58:47.815 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5261, offs:0 leng:3 value:0x01 2022-10-25 17:58:47.815 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5261 (offs:0 leng:3) 2022-10-25 17:58:47.815 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5262, offs:6 leng:1 value:0x01 2022-10-25 17:58:47.815 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5262 (offs:6 leng:1) 2022-10-25 17:58:47.815 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5262, offs:4 leng:2 value:0x02 2022-10-25 17:58:47.815 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5262 (offs:4 leng:2) 2022-10-25 17:58:47.815 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5265, offs:7 leng:1 value:0x01 2022-10-25 17:58:47.815 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5265 (offs:7 leng:1) 2022-10-25 17:58:47.815 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5269, offs:0 leng:1 value:0x00 2022-10-25 17:58:47.815 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5269 (offs:0 leng:1) 2022-10-25 17:58:47.815 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5269, offs:1 leng:1 value:0x01 2022-10-25 17:58:47.815 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5269 (offs:1 leng:1) 2022-10-25 17:58:47.815 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5262, offs:1 leng:1 value:0x00 2022-10-25 17:58:47.815 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5262 (offs:1 leng:1) 2022-10-25 17:58:47.815 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5262, offs:0 leng:1 value:0x00 2022-10-25 17:58:47.815 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5262 (offs:0 leng:1) 2022-10-25 17:58:47.815 [HAL:XDEB] [sx1302_send:2608] Setting LoRa syncword 0x34 2022-10-25 17:58:47.815 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x526D, offs:0 leng:5 value:0x06 2022-10-25 17:58:47.815 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x526D (offs:0 leng:5) 2022-10-25 17:58:47.815 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x526E, offs:0 leng:5 value:0x08 2022-10-25 17:58:47.815 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x526E (offs:0 leng:5) 2022-10-25 17:58:47.815 [HAL:XDEB] [sx1302_send:2621] Disable Fine Sync 2022-10-25 17:58:47.816 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5262, offs:7 leng:1 value:0x00 2022-10-25 17:58:47.816 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5262 (offs:7 leng:1) 2022-10-25 17:58:47.816 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x5263 2022-10-25 17:58:47.816 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5261, offs:6 leng:2 value:0x00 2022-10-25 17:58:47.816 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5261 (offs:6 leng:2) 2022-10-25 17:58:47.816 [HAL:XDEB] [sx1302_send:2638] Low datarate optimization DISABLED 2022-10-25 17:58:47.816 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5261, offs:4 leng:2 value:0x00 2022-10-25 17:58:47.816 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5261 (offs:4 leng:2) 2022-10-25 17:58:47.816 [HAL:XDEB] [sx1302_tx_set_start_delay:2264] INFO: tx_start_delay=47837 (48000, radio_bw_delay=21, filter_delay=126, modem_delay=16) 2022-10-25 17:58:47.816 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5207, offs:0 leng:1 value:0x01 2022-10-25 17:58:47.816 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5207 (offs:0 leng:1) 2022-10-25 17:58:47.816 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5207, offs:0 leng:1 value:0x00 2022-10-25 17:58:47.816 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5207 (offs:0 leng:1) 2022-10-25 17:58:47.816 [HAL:XDEB] [sx1302_send:2751] Start Tx: Freq:923900000 SF8 size:39 preamb:8 2022-10-25 17:58:47.816 [HAL:XDEB] [sx1302_send:2761] --> programming trig delay at 130181748 (4165815907) 2022-10-25 17:58:47.816 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x5204 2022-10-25 17:58:47.816 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x5203 2022-10-25 17:58:47.816 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x5202 2022-10-25 17:58:47.816 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x5201 2022-10-25 17:58:47.816 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5200, offs:1 leng:1 value:0x00 2022-10-25 17:58:47.816 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5200 (offs:1 leng:1) 2022-10-25 17:58:47.816 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5200, offs:1 leng:1 value:0x01 2022-10-25 17:58:47.816 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5200 (offs:1 leng:1) 2022-10-25 17:58:47.816 [HAL:XDEB] [lgw_usb_flush:466] INFO: flushing USB write buffer 2022-10-25 17:58:47.818 [HAL:XDEB] [lgw_usb_set_write_mode:436] setting USB write mode to SINGLE 2022-10-25 17:58:47.818 [HAL:XDEB] [lgw_send:1484] --- OUT 2022-10-25 17:58:47.840 [HAL:XDEB] [lgw_status:1496] --- IN 2022-10-25 17:58:47.840 [HAL:XDEB] [lgw_status:1523] --- OUT 2022-10-25 17:58:47.840 [S2E:ERRO] ::1 diid=22 [ant#0] - radio is not emitting frame - abandoning TX, trying alternative 2022-10-25 17:58:47.840 [HAL:XDEB] [lgw_abort_tx:1534] --- IN 2022-10-25 17:58:47.840 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5200, offs:0 leng:1 value:0x00 2022-10-25 17:58:47.840 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5200 (offs:0 leng:1) 2022-10-25 17:58:47.840 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5200, offs:1 leng:1 value:0x00 2022-10-25 17:58:47.841 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5200 (offs:1 leng:1) 2022-10-25 17:58:47.841 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5200, offs:2 leng:1 value:0x00 2022-10-25 17:58:47.841 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5200 (offs:2 leng:1) 2022-10-25 17:58:47.842 [HAL:XDEB] [lgw_abort_tx:1545] --- OUT 2022-10-25 17:58:47.842 [S2E:VERB] ::1 diid=22 [ant#0] - class A has no more alternate TX time 2022-10-25 17:58:47.842 [S2E:WARN] ::1 diid=22 [ant#0] - unable to place frame 2022-10-25 17:58:48.782 [SYN:XDEB] SYNC: ustime=0x00035A662979 (Q=609): xticks=0x07d0913e xtime=0xB4000007D0913E - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:58:49.833 [SYN:XDEB] SYNC: ustime=0x00035A763201 (Q=633): xticks=0x07e09930 xtime=0xB4000007E09930 - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:58:50.884 [SYN:XDEB] SYNC: ustime=0x00035A863A9C (Q=651): xticks=0x07f0a132 xtime=0xB4000007F0A132 - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:58:50.884 [SYN:WARN] Repeated excessive clock drifts between MCU/SX130X#0 (111 retries): 164.4ppm (threshold 100.0ppm) 2022-10-25 17:58:51.078 [HAL:XDEB] [rx_buffer_fetch:154] ----------------- 2022-10-25 17:58:51.079 [HAL:XDEB] [rx_buffer_fetch:155] rx_buffer_fetch: nb_bytes to be fetched: 94 (94 0) 2022-10-25 17:58:51.079 [HAL:XDEB] [rx_buffer_fetch:165] RX BUFFER: A5C01802830880060080635C0C260000000126A2F4A9A054A6DD87F12FBAF4511C0027BCBB00116C1971FE228900EEA5C0180483090040031000500476568C080176E8FCF9C01DACDD84412BBA975D1C01DB857D1042841971FE22EA00D0 2022-10-25 17:58:51.079 [HAL:XDEB] [rx_buffer_fetch:177] INFO: syncword found at idx 0 2022-10-25 17:58:51.080 [HAL:XDEB] [lgw_receive:1291] WARNING: not enough space allocated, fetched 2 packet(s), 1 will be left in RX buffer 2022-10-25 17:58:51.080 [HAL:XDEB] [lgw_usb_get_temperature:500] temperature:28.7oC 2022-10-25 17:58:51.080 [HAL:XDEB] [rx_buffer_pop:244] INFO: pkt syncword found at index 0 2022-10-25 17:58:51.080 [HAL:XDEB] [rx_buffer_pop:275] Packet checksum OK (0xEE) 2022-10-25 17:58:51.080 [HAL:XDEB] [rx_buffer_pop:311] ----------------- 2022-10-25 17:58:51.080 [HAL:XDEB] [rx_buffer_pop:312] modem: 8 2022-10-25 17:58:51.080 [HAL:XDEB] [rx_buffer_pop:313] chan: 2 2022-10-25 17:58:51.080 [HAL:XDEB] [rx_buffer_pop:314] size: 24 2022-10-25 17:58:51.080 [HAL:XDEB] [rx_buffer_pop:315] crc_en: 1 2022-10-25 17:58:51.080 [HAL:XDEB] [rx_buffer_pop:316] crc_err: 0 2022-10-25 17:58:51.080 [HAL:XDEB] [rx_buffer_pop:317] sync_err: 0 2022-10-25 17:58:51.080 [HAL:XDEB] [rx_buffer_pop:318] hdr_err: 0 2022-10-25 17:58:51.080 [HAL:XDEB] [rx_buffer_pop:319] timing_set: 0 2022-10-25 17:58:51.080 [HAL:XDEB] [rx_buffer_pop:320] codr: 1 2022-10-25 17:58:51.080 [HAL:XDEB] [rx_buffer_pop:321] datr: 8 2022-10-25 17:58:51.080 [HAL:XDEB] [rx_buffer_pop:322] num_ts: 0 2022-10-25 17:58:51.080 [HAL:XDEB] [rx_buffer_pop:331] ----------------- 2022-10-25 17:58:51.080 [HAL:XDEB] [sx1302_parse:1946] [2 0x11] 2022-10-25 17:58:51.080 [HAL:XDEB] [sx1302_parse:1959] Note: LoRa packet (modem 8 chan 2) 2022-10-25 17:58:51.080 [HAL:XDEB] [sx1302_parse:1981] Payload CRC check OK (0x8922) 2022-10-25 17:58:51.080 [HAL:XDEB] [legacy_timestamp_correction:205] FTIME OFF : filtering_delay %lu 2022-10-25 17:58:51.080 [HAL:XDEB] [legacy_timestamp_correction:206] FTIME OFF : fft_delay_state3 %lu 2022-10-25 17:58:51.080 [HAL:XDEB] [legacy_timestamp_correction:207] FTIME OFF : fft_delay %lu 2022-10-25 17:58:51.080 [HAL:XDEB] [legacy_timestamp_correction:208] FTIME OFF : demap_delay %lu 2022-10-25 17:58:51.080 [HAL:XDEB] [legacy_timestamp_correction:209] FTIME OFF : decode_delay %lu 2022-10-25 17:58:51.080 [HAL:XDEB] [legacy_timestamp_correction:210] FTIME OFF : timestamp correction -874 2022-10-25 17:58:51.080 [HAL:XDEB] [sx1302_rssi_get_temperature_offset:2283] INFO: RSSI temperature compensation: 2022-10-25 17:58:51.080 [HAL:XDEB] [sx1302_rssi_get_temperature_offset:2284] coeff_a: 0.000 2022-10-25 17:58:51.080 [HAL:XDEB] [sx1302_rssi_get_temperature_offset:2285] coeff_b: 0.000 2022-10-25 17:58:51.081 [HAL:XDEB] [sx1302_rssi_get_temperature_offset:2286] coeff_c: 20.410 2022-10-25 17:58:51.081 [HAL:XDEB] [sx1302_rssi_get_temperature_offset:2287] coeff_d: 2162.560 2022-10-25 17:58:51.081 [HAL:XDEB] [sx1302_rssi_get_temperature_offset:2288] coeff_e: 0.000 2022-10-25 17:58:51.081 [HAL:XDEB] [lgw_receive:1320] INFO: RSSI temperature offset applied: 1.203 dB (current temperature 28.7 C) 2022-10-25 17:58:51.081 [HAL:XDEB] [lgw_receive:1323] INFO: nb pkt found:1 left:1 2022-10-25 17:58:51.081 [HAL:XDEB] [lgw_receive:1337] --- OUT 2022-10-25 17:58:51.081 [RAL:XDEB] [CRC OK] 904.300MHz 9.75/-27.2 SF8/BW125 (mod=16/dr=8/bw=4) xtick=07f38561 (133399905) 24 bytes: 80635C0C260000000126A2F4A9A054A6DD87F12FBAF4511C 2022-10-25 17:58:51.081 [HAL:XDEB] [sx1302_fetch:1886] Note: remaining 1 packets in RX buffer, do not fetch sx1302 yet... 2022-10-25 17:58:51.082 [HAL:XDEB] [lgw_usb_get_temperature:500] temperature:28.7oC 2022-10-25 17:58:51.082 [HAL:XDEB] [rx_buffer_pop:244] INFO: pkt syncword found at index 47 2022-10-25 17:58:51.082 [HAL:XDEB] [rx_buffer_pop:275] Packet checksum OK (0xD0) 2022-10-25 17:58:51.082 [HAL:XDEB] [rx_buffer_pop:311] ----------------- 2022-10-25 17:58:51.082 [HAL:XDEB] [rx_buffer_pop:312] modem: 9 2022-10-25 17:58:51.082 [HAL:XDEB] [rx_buffer_pop:313] chan: 4 2022-10-25 17:58:51.082 [HAL:XDEB] [rx_buffer_pop:314] size: 24 2022-10-25 17:58:51.082 [HAL:XDEB] [rx_buffer_pop:315] crc_en: 1 2022-10-25 17:58:51.082 [HAL:XDEB] [rx_buffer_pop:316] crc_err: 1 2022-10-25 17:58:51.082 [HAL:XDEB] [rx_buffer_pop:317] sync_err: 0 2022-10-25 17:58:51.082 [HAL:XDEB] [rx_buffer_pop:318] hdr_err: 0 2022-10-25 17:58:51.082 [HAL:XDEB] [rx_buffer_pop:319] timing_set: 0 2022-10-25 17:58:51.082 [HAL:XDEB] [rx_buffer_pop:320] codr: 1 2022-10-25 17:58:51.082 [HAL:XDEB] [rx_buffer_pop:321] datr: 8 2022-10-25 17:58:51.082 [HAL:XDEB] [rx_buffer_pop:322] num_ts: 0 2022-10-25 17:58:51.082 [HAL:XDEB] [rx_buffer_pop:331] ----------------- 2022-10-25 17:58:51.082 [HAL:XDEB] [sx1302_parse:1946] [4 0x11] 2022-10-25 17:58:51.082 [HAL:XDEB] [sx1302_parse:1959] Note: LoRa packet (modem 9 chan 4) 2022-10-25 17:58:51.082 [HAL:XDEB] [legacy_timestamp_correction:205] FTIME OFF : filtering_delay %lu 2022-10-25 17:58:51.082 [HAL:XDEB] [legacy_timestamp_correction:206] FTIME OFF : fft_delay_state3 %lu 2022-10-25 17:58:51.082 [HAL:XDEB] [legacy_timestamp_correction:207] FTIME OFF : fft_delay %lu 2022-10-25 17:58:51.082 [HAL:XDEB] [legacy_timestamp_correction:208] FTIME OFF : demap_delay %lu 2022-10-25 17:58:51.082 [HAL:XDEB] [legacy_timestamp_correction:209] FTIME OFF : decode_delay %lu 2022-10-25 17:58:51.082 [HAL:XDEB] [legacy_timestamp_correction:210] FTIME OFF : timestamp correction -874 2022-10-25 17:58:51.082 [HAL:XDEB] [sx1302_rssi_get_temperature_offset:2283] INFO: RSSI temperature compensation: 2022-10-25 17:58:51.082 [HAL:XDEB] [sx1302_rssi_get_temperature_offset:2284] coeff_a: 0.000 2022-10-25 17:58:51.082 [HAL:XDEB] [sx1302_rssi_get_temperature_offset:2285] coeff_b: 0.000 2022-10-25 17:58:51.082 [HAL:XDEB] [sx1302_rssi_get_temperature_offset:2286] coeff_c: 20.410 2022-10-25 17:58:51.082 [HAL:XDEB] [sx1302_rssi_get_temperature_offset:2287] coeff_d: 2162.560 2022-10-25 17:58:51.082 [HAL:XDEB] [sx1302_rssi_get_temperature_offset:2288] coeff_e: 0.000 2022-10-25 17:58:51.082 [HAL:XDEB] [lgw_receive:1320] INFO: RSSI temperature offset applied: 1.203 dB (current temperature 28.7 C) 2022-10-25 17:58:51.082 [HAL:XDEB] [lgw_receive:1323] INFO: nb pkt found:1 left:0 2022-10-25 17:58:51.082 [HAL:XDEB] [lgw_receive:1337] --- OUT 2022-10-25 17:58:51.082 [RAL:DEBU] [CRC FAIL] 904.700MHz -9.25/-89.2 SF8/BW125 (mod=16/dr=8/bw=4) xtick=07f38562 (133399906) 24 bytes: 1000500476568C080176E8FCF9C01DACDD84412BBA975D1C 2022-10-25 17:58:51.084 [S2E:VERB] RX 904.3MHz DR2 SF8/BW125 snr=9.8 rssi=-27 xtime=0xB4000007F38561 - updf mhdr=80 DevAddr=260C5C63 FCtrl=00 FCnt=0 FOpts=[] 0126A2F4..F12F mic=475133114 (24 bytes) 2022-10-25 17:58:51.084 [AIO:XDEB] [3|WS] > {"msgtype":"updf","MHdr":128,"DevAddr":638344291,"FCtrl":0,"FCnt":0,"FOpts":"","FPort":1,"FRMPayload":"26A2F4A9A054A6DD87F12F","MIC":475133114,"RefTime":1666720731.084833,"DR":2,"Freq":904300000,"upinfo":{"rctx":0,"xtime":50665495941317985,"gpstime":0,"fts":-1,"rssi":-27,"snr":9.75,"rxtime":1666720731.084211}} 2022-10-25 17:58:51.084 [AIO:XDEB] [3] socket write bytes=319 2022-10-25 17:58:51.600 [AIO:XDEB] [3] socket read bytes=283 2022-10-25 17:58:51.600 [AIO:XDEB] [3|WS] < {"msgtype":"dnmsg","DevEui":"00-00-00-00-00-00-00-01","dC":0,"diid":33,"pdu":"60635c0c26b0020000bb98b8c27158ea8ff1aa2fee5b3b2be4d7b88f1257c41137e573e86df4fb","priority":25,"rctx":0,"MuxTime":1666720731.6012723,"RxDelay":1,"RX1DR":12,"RX1Freq":924500000,"xtime":50665495945317985} 2022-10-25 17:58:51.600 [S2E:DEBU] ::1 diid=33 [ant#0] - next TX start ahead by 4s451ms (17:58:56.051617) 2022-10-25 17:58:51.935 [SYN:XDEB] SYNC: ustime=0x00035A96434B (Q=619): xticks=0x0800a95d xtime=0xB400000800A95D - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:58:51.935 [SYN:INFO] Time sync qualities: min=557 q90=655 max=670 (previous q90=664) 2022-10-25 17:58:52.986 [SYN:XDEB] SYNC: ustime=0x00035AA64D39 (Q=603): xticks=0x0810b2cd xtime=0xB400000810B2CD - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:58:54.036 [SYN:XDEB] SYNC: ustime=0x00035AB6559C (Q=576): xticks=0x0820bab5 xtime=0xB400000820BAB5 - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:58:54.036 [SYN:WARN] Repeated excessive clock drifts between MCU/SX130X#0 (114 retries): 163.4ppm (threshold 100.0ppm) 2022-10-25 17:58:55.087 [SYN:XDEB] SYNC: ustime=0x00035AC65E0D (Q=572): xticks=0x0830c298 xtime=0xB400000830C298 - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:58:56.031 [S2E:VERB] ::1 diid=33 [ant#0] - starting TX in 19ms910us: 924.5MHz 26.0dBm ant#0(0) DR12 SF8/BW500 frame=60635C0C26B0020000BB98B8..E86DF4FB (39 bytes) 2022-10-25 17:58:56.031 [HAL:XDEB] [lgw_send:1350] --- IN 2022-10-25 17:58:56.031 [HAL:XDEB] [lgw_usb_set_write_mode:436] setting USB write mode to BULK 2022-10-25 17:58:56.031 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5209, offs:0 leng:1 value:0x00 2022-10-25 17:58:56.031 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5209 (offs:0 leng:1) 2022-10-25 17:58:56.031 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5220, offs:0 leng:2 value:0x01 2022-10-25 17:58:56.031 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5220 (offs:0 leng:2) 2022-10-25 17:58:56.031 [HAL:XDEB] [sx1302_send:2460] INFO: selecting TX Gain LUT index 14 2022-10-25 17:58:56.031 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x5223 2022-10-25 17:58:56.031 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x5224 2022-10-25 17:58:56.031 [HAL:XDEB] [sx1302_send:2468] INFO: Applying IQ offset (i:0, q:0) 2022-10-25 17:58:56.031 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x520D 2022-10-25 17:58:56.031 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5222, offs:0 leng:2 value:0x00 2022-10-25 17:58:56.031 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5222 (offs:0 leng:2) 2022-10-25 17:58:56.031 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x5225 2022-10-25 17:58:56.031 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x5226 2022-10-25 17:58:56.031 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x5227 2022-10-25 17:58:56.031 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x520C 2022-10-25 17:58:56.032 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5228, offs:0 leng:4 value:0x08 2022-10-25 17:58:56.032 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5228 (offs:0 leng:4) 2022-10-25 17:58:56.032 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x5229 2022-10-25 17:58:56.032 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5260, offs:4 leng:4 value:0x06 2022-10-25 17:58:56.032 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5260 (offs:4 leng:4) 2022-10-25 17:58:56.032 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x5267 2022-10-25 17:58:56.032 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x5266 2022-10-25 17:58:56.032 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5260, offs:0 leng:4 value:0x08 2022-10-25 17:58:56.032 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5260 (offs:0 leng:4) 2022-10-25 17:58:56.032 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5269, offs:4 leng:3 value:0x06 2022-10-25 17:58:56.032 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5269 (offs:4 leng:3) 2022-10-25 17:58:56.032 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5261, offs:0 leng:3 value:0x01 2022-10-25 17:58:56.032 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5261 (offs:0 leng:3) 2022-10-25 17:58:56.032 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5262, offs:6 leng:1 value:0x01 2022-10-25 17:58:56.032 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5262 (offs:6 leng:1) 2022-10-25 17:58:56.032 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5262, offs:4 leng:2 value:0x02 2022-10-25 17:58:56.032 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5262 (offs:4 leng:2) 2022-10-25 17:58:56.032 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5265, offs:7 leng:1 value:0x01 2022-10-25 17:58:56.032 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5265 (offs:7 leng:1) 2022-10-25 17:58:56.032 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5269, offs:0 leng:1 value:0x00 2022-10-25 17:58:56.032 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5269 (offs:0 leng:1) 2022-10-25 17:58:56.032 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5269, offs:1 leng:1 value:0x01 2022-10-25 17:58:56.032 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5269 (offs:1 leng:1) 2022-10-25 17:58:56.032 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5262, offs:1 leng:1 value:0x00 2022-10-25 17:58:56.032 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5262 (offs:1 leng:1) 2022-10-25 17:58:56.032 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5262, offs:0 leng:1 value:0x00 2022-10-25 17:58:56.032 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5262 (offs:0 leng:1) 2022-10-25 17:58:56.032 [HAL:XDEB] [sx1302_send:2608] Setting LoRa syncword 0x34 2022-10-25 17:58:56.032 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x526D, offs:0 leng:5 value:0x06 2022-10-25 17:58:56.032 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x526D (offs:0 leng:5) 2022-10-25 17:58:56.032 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x526E, offs:0 leng:5 value:0x08 2022-10-25 17:58:56.032 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x526E (offs:0 leng:5) 2022-10-25 17:58:56.032 [HAL:XDEB] [sx1302_send:2621] Disable Fine Sync 2022-10-25 17:58:56.032 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5262, offs:7 leng:1 value:0x00 2022-10-25 17:58:56.032 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5262 (offs:7 leng:1) 2022-10-25 17:58:56.032 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x5263 2022-10-25 17:58:56.032 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5261, offs:6 leng:2 value:0x00 2022-10-25 17:58:56.032 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5261 (offs:6 leng:2) 2022-10-25 17:58:56.032 [HAL:XDEB] [sx1302_send:2638] Low datarate optimization DISABLED 2022-10-25 17:58:56.032 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5261, offs:4 leng:2 value:0x00 2022-10-25 17:58:56.032 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5261 (offs:4 leng:2) 2022-10-25 17:58:56.032 [HAL:XDEB] [sx1302_tx_set_start_delay:2264] INFO: tx_start_delay=47837 (48000, radio_bw_delay=21, filter_delay=126, modem_delay=16) 2022-10-25 17:58:56.032 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5207, offs:0 leng:1 value:0x01 2022-10-25 17:58:56.032 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5207 (offs:0 leng:1) 2022-10-25 17:58:56.032 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5207, offs:0 leng:1 value:0x00 2022-10-25 17:58:56.032 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5207 (offs:0 leng:1) 2022-10-25 17:58:56.032 [HAL:XDEB] [sx1302_send:2751] Start Tx: Freq:924500000 SF8 size:39 preamb:8 2022-10-25 17:58:56.032 [HAL:XDEB] [sx1302_send:2761] --> programming trig delay at 138398411 (133781827) 2022-10-25 17:58:56.032 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x5204 2022-10-25 17:58:56.032 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x5203 2022-10-25 17:58:56.032 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x5202 2022-10-25 17:58:56.032 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x5201 2022-10-25 17:58:56.032 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5200, offs:1 leng:1 value:0x00 2022-10-25 17:58:56.032 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5200 (offs:1 leng:1) 2022-10-25 17:58:56.032 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5200, offs:1 leng:1 value:0x01 2022-10-25 17:58:56.032 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5200 (offs:1 leng:1) 2022-10-25 17:58:56.032 [HAL:XDEB] [lgw_usb_flush:466] INFO: flushing USB write buffer 2022-10-25 17:58:56.034 [HAL:XDEB] [lgw_usb_set_write_mode:436] setting USB write mode to SINGLE 2022-10-25 17:58:56.034 [HAL:XDEB] [lgw_send:1484] --- OUT 2022-10-25 17:58:56.056 [HAL:XDEB] [lgw_status:1496] --- IN 2022-10-25 17:58:56.056 [HAL:XDEB] [lgw_status:1523] --- OUT 2022-10-25 17:58:56.057 [S2E:ERRO] ::1 diid=33 [ant#0] - radio is not emitting frame - abandoning TX, trying alternative 2022-10-25 17:58:56.057 [HAL:XDEB] [lgw_abort_tx:1534] --- IN 2022-10-25 17:58:56.057 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5200, offs:0 leng:1 value:0x00 2022-10-25 17:58:56.057 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5200 (offs:0 leng:1) 2022-10-25 17:58:56.057 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5200, offs:1 leng:1 value:0x00 2022-10-25 17:58:56.057 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5200 (offs:1 leng:1) 2022-10-25 17:58:56.057 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5200, offs:2 leng:1 value:0x00 2022-10-25 17:58:56.057 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5200 (offs:2 leng:1) 2022-10-25 17:58:56.059 [HAL:XDEB] [lgw_abort_tx:1545] --- OUT 2022-10-25 17:58:56.059 [S2E:VERB] ::1 diid=33 [ant#0] - class A has no more alternate TX time 2022-10-25 17:58:56.059 [S2E:WARN] ::1 diid=33 [ant#0] - unable to place frame 2022-10-25 17:58:56.138 [SYN:XDEB] SYNC: ustime=0x00035AD6665B (Q=576): xticks=0x0840ca60 xtime=0xB400000840CA60 - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:58:57.188 [SYN:XDEB] SYNC: ustime=0x00035AE66EBA (Q=601): xticks=0x0850d22f xtime=0xB400000850D22F - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:58:57.189 [SYN:WARN] Repeated excessive clock drifts between MCU/SX130X#0 (117 retries): 162.7ppm (threshold 100.0ppm) 2022-10-25 17:58:58.239 [SYN:XDEB] SYNC: ustime=0x00035AF67771 (Q=653): xticks=0x0860da78 xtime=0xB400000860DA78 - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:58:59.290 [SYN:XDEB] SYNC: ustime=0x00035B068021 (Q=659): xticks=0x0870e26b xtime=0xB400000870E26B - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:58:59.290 [SYN:VERB] Time sync rejected: quality=659 threshold=655 2022-10-25 17:58:59.293 [HAL:XDEB] [rx_buffer_fetch:154] ----------------- 2022-10-25 17:58:59.293 [HAL:XDEB] [rx_buffer_fetch:155] rx_buffer_fetch: nb_bytes to be fetched: 94 (94 0) 2022-10-25 17:58:59.294 [HAL:XDEB] [rx_buffer_fetch:165] RX BUFFER: A5C01802830A205B028003DC0C265380080946A2F4A99381A28DE73D2FBA67481C01D17E751020F40B1D0E329B008AA5C01806830860F80F80635C0C260000000126A2F4A9A054A6DD87F12FBAF4511C003ABEBD0012B4241D0E228900FA 2022-10-25 17:58:59.294 [HAL:XDEB] [rx_buffer_fetch:177] INFO: syncword found at idx 0 2022-10-25 17:58:59.294 [HAL:XDEB] [lgw_receive:1291] WARNING: not enough space allocated, fetched 2 packet(s), 1 will be left in RX buffer 2022-10-25 17:58:59.295 [HAL:XDEB] [lgw_usb_get_temperature:500] temperature:28.7oC 2022-10-25 17:58:59.295 [HAL:XDEB] [rx_buffer_pop:244] INFO: pkt syncword found at index 0 2022-10-25 17:58:59.295 [HAL:XDEB] [rx_buffer_pop:275] Packet checksum OK (0x8A) 2022-10-25 17:58:59.295 [HAL:XDEB] [rx_buffer_pop:311] ----------------- 2022-10-25 17:58:59.295 [HAL:XDEB] [rx_buffer_pop:312] modem: 10 2022-10-25 17:58:59.295 [HAL:XDEB] [rx_buffer_pop:313] chan: 2 2022-10-25 17:58:59.295 [HAL:XDEB] [rx_buffer_pop:314] size: 24 2022-10-25 17:58:59.295 [HAL:XDEB] [rx_buffer_pop:315] crc_en: 1 2022-10-25 17:58:59.295 [HAL:XDEB] [rx_buffer_pop:316] crc_err: 1 2022-10-25 17:58:59.295 [HAL:XDEB] [rx_buffer_pop:317] sync_err: 0 2022-10-25 17:58:59.295 [HAL:XDEB] [rx_buffer_pop:318] hdr_err: 0 2022-10-25 17:58:59.295 [HAL:XDEB] [rx_buffer_pop:319] timing_set: 0 2022-10-25 17:58:59.295 [HAL:XDEB] [rx_buffer_pop:320] codr: 1 2022-10-25 17:58:59.295 [HAL:XDEB] [rx_buffer_pop:321] datr: 8 2022-10-25 17:58:59.295 [HAL:XDEB] [rx_buffer_pop:322] num_ts: 0 2022-10-25 17:58:59.295 [HAL:XDEB] [rx_buffer_pop:331] ----------------- 2022-10-25 17:58:59.295 [HAL:XDEB] [sx1302_parse:1946] [2 0x11] 2022-10-25 17:58:59.295 [HAL:XDEB] [sx1302_parse:1959] Note: LoRa packet (modem 10 chan 2) 2022-10-25 17:58:59.295 [HAL:XDEB] [legacy_timestamp_correction:205] FTIME OFF : filtering_delay %lu 2022-10-25 17:58:59.295 [HAL:XDEB] [legacy_timestamp_correction:206] FTIME OFF : fft_delay_state3 %lu 2022-10-25 17:58:59.295 [HAL:XDEB] [legacy_timestamp_correction:207] FTIME OFF : fft_delay %lu 2022-10-25 17:58:59.295 [HAL:XDEB] [legacy_timestamp_correction:208] FTIME OFF : demap_delay %lu 2022-10-25 17:58:59.295 [HAL:XDEB] [legacy_timestamp_correction:209] FTIME OFF : decode_delay %lu 2022-10-25 17:58:59.295 [HAL:XDEB] [legacy_timestamp_correction:210] FTIME OFF : timestamp correction -874 2022-10-25 17:58:59.295 [HAL:XDEB] [sx1302_rssi_get_temperature_offset:2283] INFO: RSSI temperature compensation: 2022-10-25 17:58:59.295 [HAL:XDEB] [sx1302_rssi_get_temperature_offset:2284] coeff_a: 0.000 2022-10-25 17:58:59.295 [HAL:XDEB] [sx1302_rssi_get_temperature_offset:2285] coeff_b: 0.000 2022-10-25 17:58:59.295 [HAL:XDEB] [sx1302_rssi_get_temperature_offset:2286] coeff_c: 20.410 2022-10-25 17:58:59.295 [HAL:XDEB] [sx1302_rssi_get_temperature_offset:2287] coeff_d: 2162.560 2022-10-25 17:58:59.295 [HAL:XDEB] [sx1302_rssi_get_temperature_offset:2288] coeff_e: 0.000 2022-10-25 17:58:59.295 [HAL:XDEB] [lgw_receive:1320] INFO: RSSI temperature offset applied: 1.203 dB (current temperature 28.7 C) 2022-10-25 17:58:59.295 [HAL:XDEB] [lgw_receive:1323] INFO: nb pkt found:1 left:1 2022-10-25 17:58:59.295 [HAL:XDEB] [lgw_receive:1337] --- OUT 2022-10-25 17:58:59.295 [RAL:DEBU] [CRC FAIL] 904.300MHz -11.75/-97.2 SF8/BW125 (mod=16/dr=8/bw=4) xtick=0870e4f5 (141616373) 24 bytes: 8003DC0C265380080946A2F4A99381A28DE73D2FBA67481C 2022-10-25 17:58:59.295 [HAL:XDEB] [sx1302_fetch:1886] Note: remaining 1 packets in RX buffer, do not fetch sx1302 yet... 2022-10-25 17:58:59.296 [HAL:XDEB] [lgw_usb_get_temperature:500] temperature:28.7oC 2022-10-25 17:58:59.296 [HAL:XDEB] [rx_buffer_pop:244] INFO: pkt syncword found at index 47 2022-10-25 17:58:59.296 [HAL:XDEB] [rx_buffer_pop:275] Packet checksum OK (0xFA) 2022-10-25 17:58:59.296 [HAL:XDEB] [rx_buffer_pop:311] ----------------- 2022-10-25 17:58:59.296 [HAL:XDEB] [rx_buffer_pop:312] modem: 8 2022-10-25 17:58:59.296 [HAL:XDEB] [rx_buffer_pop:313] chan: 6 2022-10-25 17:58:59.296 [HAL:XDEB] [rx_buffer_pop:314] size: 24 2022-10-25 17:58:59.296 [HAL:XDEB] [rx_buffer_pop:315] crc_en: 1 2022-10-25 17:58:59.296 [HAL:XDEB] [rx_buffer_pop:316] crc_err: 0 2022-10-25 17:58:59.296 [HAL:XDEB] [rx_buffer_pop:317] sync_err: 0 2022-10-25 17:58:59.296 [HAL:XDEB] [rx_buffer_pop:318] hdr_err: 0 2022-10-25 17:58:59.296 [HAL:XDEB] [rx_buffer_pop:319] timing_set: 0 2022-10-25 17:58:59.296 [HAL:XDEB] [rx_buffer_pop:320] codr: 1 2022-10-25 17:58:59.296 [HAL:XDEB] [rx_buffer_pop:321] datr: 8 2022-10-25 17:58:59.296 [HAL:XDEB] [rx_buffer_pop:322] num_ts: 0 2022-10-25 17:58:59.296 [HAL:XDEB] [rx_buffer_pop:331] ----------------- 2022-10-25 17:58:59.296 [HAL:XDEB] [sx1302_parse:1946] [6 0x11] 2022-10-25 17:58:59.296 [HAL:XDEB] [sx1302_parse:1959] Note: LoRa packet (modem 8 chan 6) 2022-10-25 17:58:59.296 [HAL:XDEB] [sx1302_parse:1981] Payload CRC check OK (0x8922) 2022-10-25 17:58:59.296 [HAL:XDEB] [legacy_timestamp_correction:205] FTIME OFF : filtering_delay %lu 2022-10-25 17:58:59.296 [HAL:XDEB] [legacy_timestamp_correction:206] FTIME OFF : fft_delay_state3 %lu 2022-10-25 17:58:59.296 [HAL:XDEB] [legacy_timestamp_correction:207] FTIME OFF : fft_delay %lu 2022-10-25 17:58:59.296 [HAL:XDEB] [legacy_timestamp_correction:208] FTIME OFF : demap_delay %lu 2022-10-25 17:58:59.296 [HAL:XDEB] [legacy_timestamp_correction:209] FTIME OFF : decode_delay %lu 2022-10-25 17:58:59.296 [HAL:XDEB] [legacy_timestamp_correction:210] FTIME OFF : timestamp correction -874 2022-10-25 17:58:59.296 [HAL:XDEB] [sx1302_rssi_get_temperature_offset:2283] INFO: RSSI temperature compensation: 2022-10-25 17:58:59.296 [HAL:XDEB] [sx1302_rssi_get_temperature_offset:2284] coeff_a: 0.000 2022-10-25 17:58:59.296 [HAL:XDEB] [sx1302_rssi_get_temperature_offset:2285] coeff_b: 0.000 2022-10-25 17:58:59.296 [HAL:XDEB] [sx1302_rssi_get_temperature_offset:2286] coeff_c: 20.410 2022-10-25 17:58:59.296 [HAL:XDEB] [sx1302_rssi_get_temperature_offset:2287] coeff_d: 2162.560 2022-10-25 17:58:59.296 [HAL:XDEB] [sx1302_rssi_get_temperature_offset:2288] coeff_e: 0.000 2022-10-25 17:58:59.296 [HAL:XDEB] [lgw_receive:1320] INFO: RSSI temperature offset applied: 1.203 dB (current temperature 28.7 C) 2022-10-25 17:58:59.296 [HAL:XDEB] [lgw_receive:1323] INFO: nb pkt found:1 left:0 2022-10-25 17:58:59.296 [HAL:XDEB] [lgw_receive:1337] --- OUT 2022-10-25 17:58:59.296 [RAL:XDEB] [CRC OK] 905.100MHz 14.50/-25.2 SF8/BW125 (mod=16/dr=8/bw=4) xtick=0870e5bb (141616571) 24 bytes: 80635C0C260000000126A2F4A9A054A6DD87F12FBAF4511C 2022-10-25 17:58:59.298 [S2E:VERB] RX 905.1MHz DR2 SF8/BW125 snr=14.5 rssi=-25 xtime=0xB400000870E5BB - updf mhdr=80 DevAddr=260C5C63 FCtrl=00 FCnt=0 FOpts=[] 0126A2F4..F12F mic=475133114 (24 bytes) 2022-10-25 17:58:59.298 [AIO:XDEB] [3|WS] > {"msgtype":"updf","MHdr":128,"DevAddr":638344291,"FCtrl":0,"FCnt":0,"FOpts":"","FPort":1,"FRMPayload":"26A2F4A9A054A6DD87F12F","MIC":475133114,"RefTime":1666720739.297964,"DR":2,"Freq":905100000,"upinfo":{"rctx":0,"xtime":50665495949534651,"gpstime":0,"fts":-1,"rssi":-25,"snr":14.5,"rxtime":1666720739.298370}} 2022-10-25 17:58:59.298 [AIO:XDEB] [3] socket write bytes=319 2022-10-25 17:58:59.824 [AIO:XDEB] [3] socket read bytes=283 2022-10-25 17:58:59.824 [AIO:XDEB] [3|WS] < {"msgtype":"dnmsg","DevEui":"00-00-00-00-00-00-00-01","dC":0,"diid":52,"pdu":"60635c0c26b003000089ab7feebc4c4dc06c0d7a0430fe5a58dfc01235e3c69e81de9b962844f9","priority":25,"rctx":0,"MuxTime":1666720739.8240132,"RxDelay":1,"RX1DR":12,"RX1Freq":926900000,"xtime":50665495953534651} 2022-10-25 17:58:59.824 [S2E:DEBU] ::1 diid=52 [ant#0] - next TX start ahead by 4s444ms (17:59:04.268283) 2022-10-25 17:59:01.391 [SYN:XDEB] SYNC: ustime=0x00035B268E49 (Q=604): xticks=0x0890efb2 xtime=0xB400000890EFB2 - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:59:02.442 [SYN:XDEB] SYNC: ustime=0x00035B3696B6 (Q=607): xticks=0x08a0f77f xtime=0xB4000008A0F77F - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:59:02.442 [SYN:INFO] MCU/SX130X drift stats: min: +161.5ppm q50: +164.6ppm q80: +166.0ppm max: +166.9ppm - threshold q90: +166.7ppm 2022-10-25 17:59:02.442 [SYN:INFO] Mean MCU drift vs SX130X#0: 164.3ppm 2022-10-25 17:59:02.438 [SYN:WARN] Repeated excessive clock drifts between MCU/SX130X#0 (120 retries): 161.5ppm (threshold 100.0ppm) 2022-10-25 17:59:03.490 [SYN:XDEB] SYNC: ustime=0x00035B46A3BF (Q=612): xticks=0x08b10426 xtime=0xB4000008B10426 - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:59:04.244 [S2E:VERB] ::1 diid=52 [ant#0] - starting TX in 19ms911us: 926.9MHz 26.0dBm ant#0(0) DR12 SF8/BW500 frame=60635C0C26B003000089AB7F..962844F9 (39 bytes) 2022-10-25 17:59:04.244 [HAL:XDEB] [lgw_send:1350] --- IN 2022-10-25 17:59:04.244 [HAL:XDEB] [lgw_usb_set_write_mode:436] setting USB write mode to BULK 2022-10-25 17:59:04.244 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5209, offs:0 leng:1 value:0x00 2022-10-25 17:59:04.244 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5209 (offs:0 leng:1) 2022-10-25 17:59:04.244 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5220, offs:0 leng:2 value:0x01 2022-10-25 17:59:04.244 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5220 (offs:0 leng:2) 2022-10-25 17:59:04.244 [HAL:XDEB] [sx1302_send:2460] INFO: selecting TX Gain LUT index 14 2022-10-25 17:59:04.244 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x5223 2022-10-25 17:59:04.244 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x5224 2022-10-25 17:59:04.244 [HAL:XDEB] [sx1302_send:2468] INFO: Applying IQ offset (i:0, q:0) 2022-10-25 17:59:04.244 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x520D 2022-10-25 17:59:04.244 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5222, offs:0 leng:2 value:0x00 2022-10-25 17:59:04.244 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5222 (offs:0 leng:2) 2022-10-25 17:59:04.244 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x5225 2022-10-25 17:59:04.244 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x5226 2022-10-25 17:59:04.244 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x5227 2022-10-25 17:59:04.244 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x520C 2022-10-25 17:59:04.244 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5228, offs:0 leng:4 value:0x08 2022-10-25 17:59:04.244 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5228 (offs:0 leng:4) 2022-10-25 17:59:04.244 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x5229 2022-10-25 17:59:04.244 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5260, offs:4 leng:4 value:0x06 2022-10-25 17:59:04.244 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5260 (offs:4 leng:4) 2022-10-25 17:59:04.244 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x5267 2022-10-25 17:59:04.244 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x5266 2022-10-25 17:59:04.244 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5260, offs:0 leng:4 value:0x08 2022-10-25 17:59:04.244 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5260 (offs:0 leng:4) 2022-10-25 17:59:04.245 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5269, offs:4 leng:3 value:0x06 2022-10-25 17:59:04.245 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5269 (offs:4 leng:3) 2022-10-25 17:59:04.245 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5261, offs:0 leng:3 value:0x01 2022-10-25 17:59:04.245 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5261 (offs:0 leng:3) 2022-10-25 17:59:04.245 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5262, offs:6 leng:1 value:0x01 2022-10-25 17:59:04.245 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5262 (offs:6 leng:1) 2022-10-25 17:59:04.245 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5262, offs:4 leng:2 value:0x02 2022-10-25 17:59:04.245 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5262 (offs:4 leng:2) 2022-10-25 17:59:04.245 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5265, offs:7 leng:1 value:0x01 2022-10-25 17:59:04.245 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5265 (offs:7 leng:1) 2022-10-25 17:59:04.245 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5269, offs:0 leng:1 value:0x00 2022-10-25 17:59:04.245 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5269 (offs:0 leng:1) 2022-10-25 17:59:04.245 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5269, offs:1 leng:1 value:0x01 2022-10-25 17:59:04.245 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5269 (offs:1 leng:1) 2022-10-25 17:59:04.245 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5262, offs:1 leng:1 value:0x00 2022-10-25 17:59:04.245 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5262 (offs:1 leng:1) 2022-10-25 17:59:04.245 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5262, offs:0 leng:1 value:0x00 2022-10-25 17:59:04.245 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5262 (offs:0 leng:1) 2022-10-25 17:59:04.245 [HAL:XDEB] [sx1302_send:2608] Setting LoRa syncword 0x34 2022-10-25 17:59:04.245 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x526D, offs:0 leng:5 value:0x06 2022-10-25 17:59:04.245 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x526D (offs:0 leng:5) 2022-10-25 17:59:04.245 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x526E, offs:0 leng:5 value:0x08 2022-10-25 17:59:04.245 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x526E (offs:0 leng:5) 2022-10-25 17:59:04.245 [HAL:XDEB] [sx1302_send:2621] Disable Fine Sync 2022-10-25 17:59:04.245 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5262, offs:7 leng:1 value:0x00 2022-10-25 17:59:04.245 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5262 (offs:7 leng:1) 2022-10-25 17:59:04.245 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x5263 2022-10-25 17:59:04.245 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5261, offs:6 leng:2 value:0x00 2022-10-25 17:59:04.245 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5261 (offs:6 leng:2) 2022-10-25 17:59:04.245 [HAL:XDEB] [sx1302_send:2638] Low datarate optimization DISABLED 2022-10-25 17:59:04.245 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5261, offs:4 leng:2 value:0x00 2022-10-25 17:59:04.245 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5261 (offs:4 leng:2) 2022-10-25 17:59:04.245 [HAL:XDEB] [sx1302_tx_set_start_delay:2264] INFO: tx_start_delay=47837 (48000, radio_bw_delay=21, filter_delay=126, modem_delay=16) 2022-10-25 17:59:04.245 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5207, offs:0 leng:1 value:0x01 2022-10-25 17:59:04.245 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5207 (offs:0 leng:1) 2022-10-25 17:59:04.245 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5207, offs:0 leng:1 value:0x00 2022-10-25 17:59:04.245 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5207 (offs:0 leng:1) 2022-10-25 17:59:04.245 [HAL:XDEB] [sx1302_send:2751] Start Tx: Freq:926900000 SF8 size:39 preamb:8 2022-10-25 17:59:04.245 [HAL:XDEB] [sx1302_send:2761] --> programming trig delay at 146615077 (396715139) 2022-10-25 17:59:04.245 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x5204 2022-10-25 17:59:04.245 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x5203 2022-10-25 17:59:04.245 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x5202 2022-10-25 17:59:04.245 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x5201 2022-10-25 17:59:04.245 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5200, offs:1 leng:1 value:0x00 2022-10-25 17:59:04.245 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5200 (offs:1 leng:1) 2022-10-25 17:59:04.245 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5200, offs:1 leng:1 value:0x01 2022-10-25 17:59:04.245 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5200 (offs:1 leng:1) 2022-10-25 17:59:04.245 [HAL:XDEB] [lgw_usb_flush:466] INFO: flushing USB write buffer 2022-10-25 17:59:04.247 [HAL:XDEB] [lgw_usb_set_write_mode:436] setting USB write mode to SINGLE 2022-10-25 17:59:04.247 [HAL:XDEB] [lgw_send:1484] --- OUT 2022-10-25 17:59:04.269 [HAL:XDEB] [lgw_status:1496] --- IN 2022-10-25 17:59:04.269 [HAL:XDEB] [lgw_status:1523] --- OUT 2022-10-25 17:59:04.269 [S2E:ERRO] ::1 diid=52 [ant#0] - radio is not emitting frame - abandoning TX, trying alternative 2022-10-25 17:59:04.269 [HAL:XDEB] [lgw_abort_tx:1534] --- IN 2022-10-25 17:59:04.269 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5200, offs:0 leng:1 value:0x00 2022-10-25 17:59:04.270 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5200 (offs:0 leng:1) 2022-10-25 17:59:04.270 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5200, offs:1 leng:1 value:0x00 2022-10-25 17:59:04.270 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5200 (offs:1 leng:1) 2022-10-25 17:59:04.270 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5200, offs:2 leng:1 value:0x00 2022-10-25 17:59:04.270 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5200 (offs:2 leng:1) 2022-10-25 17:59:04.272 [HAL:XDEB] [lgw_abort_tx:1545] --- OUT 2022-10-25 17:59:04.272 [S2E:VERB] ::1 diid=52 [ant#0] - class A has no more alternate TX time 2022-10-25 17:59:04.272 [S2E:WARN] ::1 diid=52 [ant#0] - unable to place frame 2022-10-25 17:59:04.540 [SYN:XDEB] SYNC: ustime=0x00035B56AC29 (Q=594): xticks=0x08c10bf0 xtime=0xB4000008C10BF0 - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:59:05.591 [SYN:XDEB] SYNC: ustime=0x00035B66B481 (Q=576): xticks=0x08d113c5 xtime=0xB4000008D113C5 - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:59:05.591 [SYN:WARN] Repeated excessive clock drifts between MCU/SX130X#0 (123 retries): 160.7ppm (threshold 100.0ppm) 2022-10-25 17:59:06.642 [SYN:XDEB] SYNC: ustime=0x00035B76BCE9 (Q=577): xticks=0x08e11ba8 xtime=0xB4000008E11BA8 - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:59:07.516 [HAL:XDEB] [rx_buffer_fetch:154] ----------------- 2022-10-25 17:59:07.516 [HAL:XDEB] [rx_buffer_fetch:155] rx_buffer_fetch: nb_bytes to be fetched: 47 (47 0) 2022-10-25 17:59:07.516 [HAL:XDEB] [rx_buffer_fetch:165] RX BUFFER: A5C018018308800E0080635C0C260000000126A2F4A9A054A6DD87F12FBAF4511C003DBCBC00003C39C91D22890062 2022-10-25 17:59:07.516 [HAL:XDEB] [rx_buffer_fetch:177] INFO: syncword found at idx 0 2022-10-25 17:59:07.517 [HAL:XDEB] [lgw_usb_get_temperature:500] temperature:28.7oC 2022-10-25 17:59:07.517 [HAL:XDEB] [rx_buffer_pop:244] INFO: pkt syncword found at index 0 2022-10-25 17:59:07.517 [HAL:XDEB] [rx_buffer_pop:275] Packet checksum OK (0x62) 2022-10-25 17:59:07.517 [HAL:XDEB] [rx_buffer_pop:311] ----------------- 2022-10-25 17:59:07.517 [HAL:XDEB] [rx_buffer_pop:312] modem: 8 2022-10-25 17:59:07.517 [HAL:XDEB] [rx_buffer_pop:313] chan: 1 2022-10-25 17:59:07.517 [HAL:XDEB] [rx_buffer_pop:314] size: 24 2022-10-25 17:59:07.517 [HAL:XDEB] [rx_buffer_pop:315] crc_en: 1 2022-10-25 17:59:07.517 [HAL:XDEB] [rx_buffer_pop:316] crc_err: 0 2022-10-25 17:59:07.517 [HAL:XDEB] [rx_buffer_pop:317] sync_err: 0 2022-10-25 17:59:07.517 [HAL:XDEB] [rx_buffer_pop:318] hdr_err: 0 2022-10-25 17:59:07.517 [HAL:XDEB] [rx_buffer_pop:319] timing_set: 0 2022-10-25 17:59:07.517 [HAL:XDEB] [rx_buffer_pop:320] codr: 1 2022-10-25 17:59:07.517 [HAL:XDEB] [rx_buffer_pop:321] datr: 8 2022-10-25 17:59:07.517 [HAL:XDEB] [rx_buffer_pop:322] num_ts: 0 2022-10-25 17:59:07.517 [HAL:XDEB] [rx_buffer_pop:331] ----------------- 2022-10-25 17:59:07.517 [HAL:XDEB] [sx1302_parse:1946] [1 0x11] 2022-10-25 17:59:07.517 [HAL:XDEB] [sx1302_parse:1959] Note: LoRa packet (modem 8 chan 1) 2022-10-25 17:59:07.517 [HAL:XDEB] [sx1302_parse:1981] Payload CRC check OK (0x8922) 2022-10-25 17:59:07.517 [HAL:XDEB] [legacy_timestamp_correction:205] FTIME OFF : filtering_delay %lu 2022-10-25 17:59:07.517 [HAL:XDEB] [legacy_timestamp_correction:206] FTIME OFF : fft_delay_state3 %lu 2022-10-25 17:59:07.517 [HAL:XDEB] [legacy_timestamp_correction:207] FTIME OFF : fft_delay %lu 2022-10-25 17:59:07.517 [HAL:XDEB] [legacy_timestamp_correction:208] FTIME OFF : demap_delay %lu 2022-10-25 17:59:07.517 [HAL:XDEB] [legacy_timestamp_correction:209] FTIME OFF : decode_delay %lu 2022-10-25 17:59:07.517 [HAL:XDEB] [legacy_timestamp_correction:210] FTIME OFF : timestamp correction -874 2022-10-25 17:59:07.518 [HAL:XDEB] [sx1302_rssi_get_temperature_offset:2283] INFO: RSSI temperature compensation: 2022-10-25 17:59:07.518 [HAL:XDEB] [sx1302_rssi_get_temperature_offset:2284] coeff_a: 0.000 2022-10-25 17:59:07.518 [HAL:XDEB] [sx1302_rssi_get_temperature_offset:2285] coeff_b: 0.000 2022-10-25 17:59:07.518 [HAL:XDEB] [sx1302_rssi_get_temperature_offset:2286] coeff_c: 20.410 2022-10-25 17:59:07.518 [HAL:XDEB] [sx1302_rssi_get_temperature_offset:2287] coeff_d: 2162.560 2022-10-25 17:59:07.518 [HAL:XDEB] [sx1302_rssi_get_temperature_offset:2288] coeff_e: 0.000 2022-10-25 17:59:07.518 [HAL:XDEB] [lgw_receive:1320] INFO: RSSI temperature offset applied: 1.203 dB (current temperature 28.7 C) 2022-10-25 17:59:07.518 [HAL:XDEB] [lgw_receive:1323] INFO: nb pkt found:1 left:0 2022-10-25 17:59:07.518 [HAL:XDEB] [lgw_receive:1337] --- OUT 2022-10-25 17:59:07.518 [RAL:XDEB] [CRC OK] 904.100MHz 15.25/-26.2 SF8/BW125 (mod=16/dr=8/bw=4) xtick=08ee465f (149833311) 24 bytes: 80635C0C260000000126A2F4A9A054A6DD87F12FBAF4511C 2022-10-25 17:59:07.519 [S2E:VERB] RX 904.1MHz DR2 SF8/BW125 snr=15.2 rssi=-26 xtime=0xB4000008EE465F - updf mhdr=80 DevAddr=260C5C63 FCtrl=00 FCnt=0 FOpts=[] 0126A2F4..F12F mic=475133114 (24 bytes) 2022-10-25 17:59:07.519 [AIO:XDEB] [3|WS] > {"msgtype":"updf","MHdr":128,"DevAddr":638344291,"FCtrl":0,"FCnt":0,"FOpts":"","FPort":1,"FRMPayload":"26A2F4A9A054A6DD87F12F","MIC":475133114,"RefTime":1666720747.521744,"DR":2,"Freq":904100000,"upinfo":{"rctx":0,"xtime":50665495957751391,"gpstime":0,"fts":-1,"rssi":-26,"snr":15.25,"rxtime":1666720747.519367}} 2022-10-25 17:59:07.519 [AIO:XDEB] [3] socket write bytes=320 2022-10-25 17:59:07.693 [SYN:XDEB] SYNC: ustime=0x00035B86C551 (Q=625): xticks=0x08f12374 xtime=0xB4000008F12374 - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:59:08.027 [AIO:XDEB] [3] socket read bytes=283 2022-10-25 17:59:08.027 [AIO:XDEB] [3|WS] < {"msgtype":"dnmsg","DevEui":"00-00-00-00-00-00-00-01","dC":0,"diid":68,"pdu":"60635c0c26b004000025f975013577a919412e03a0bc16bb4f23e67d76b2bb0dfceba1a63db9a1","priority":25,"rctx":0,"MuxTime":1666720748.0299976,"RxDelay":1,"RX1DR":12,"RX1Freq":923900000,"xtime":50665495961751391} 2022-10-25 17:59:08.027 [S2E:DEBU] ::1 diid=68 [ant#0] - next TX start ahead by 4s453ms (17:59:12.481224) 2022-10-25 17:59:08.743 [SYN:XDEB] SYNC: ustime=0x00035B96CDBA (Q=573): xticks=0x09012b74 xtime=0xB4000009012B74 - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:59:08.743 [SYN:WARN] Repeated excessive clock drifts between MCU/SX130X#0 (126 retries): 160.0ppm (threshold 100.0ppm) 2022-10-25 17:59:09.794 [SYN:XDEB] SYNC: ustime=0x00035BA6D666 (Q=688): xticks=0x09113367 xtime=0xB4000009113367 - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:59:09.794 [SYN:VERB] Time sync rejected: quality=688 threshold=655 2022-10-25 17:59:11.895 [SYN:XDEB] SYNC: ustime=0x00035BC6E4A2 (Q=600): xticks=0x093140c8 xtime=0xB40000093140C8 - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:59:12.461 [S2E:VERB] ::1 diid=68 [ant#0] - starting TX in 19ms911us: 923.9MHz 26.0dBm ant#0(0) DR12 SF8/BW500 frame=60635C0C26B004000025F975..A63DB9A1 (39 bytes) 2022-10-25 17:59:12.461 [HAL:XDEB] [lgw_send:1350] --- IN 2022-10-25 17:59:12.461 [HAL:XDEB] [lgw_usb_set_write_mode:436] setting USB write mode to BULK 2022-10-25 17:59:12.461 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5209, offs:0 leng:1 value:0x00 2022-10-25 17:59:12.461 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5209 (offs:0 leng:1) 2022-10-25 17:59:12.461 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5220, offs:0 leng:2 value:0x01 2022-10-25 17:59:12.461 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5220 (offs:0 leng:2) 2022-10-25 17:59:12.461 [HAL:XDEB] [sx1302_send:2460] INFO: selecting TX Gain LUT index 14 2022-10-25 17:59:12.461 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x5223 2022-10-25 17:59:12.461 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x5224 2022-10-25 17:59:12.461 [HAL:XDEB] [sx1302_send:2468] INFO: Applying IQ offset (i:0, q:0) 2022-10-25 17:59:12.461 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x520D 2022-10-25 17:59:12.461 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5222, offs:0 leng:2 value:0x00 2022-10-25 17:59:12.461 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5222 (offs:0 leng:2) 2022-10-25 17:59:12.461 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x5225 2022-10-25 17:59:12.461 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x5226 2022-10-25 17:59:12.461 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x5227 2022-10-25 17:59:12.461 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x520C 2022-10-25 17:59:12.461 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5228, offs:0 leng:4 value:0x08 2022-10-25 17:59:12.461 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5228 (offs:0 leng:4) 2022-10-25 17:59:12.461 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x5229 2022-10-25 17:59:12.461 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5260, offs:4 leng:4 value:0x06 2022-10-25 17:59:12.461 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5260 (offs:4 leng:4) 2022-10-25 17:59:12.461 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x5267 2022-10-25 17:59:12.461 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x5266 2022-10-25 17:59:12.461 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5260, offs:0 leng:4 value:0x08 2022-10-25 17:59:12.461 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5260 (offs:0 leng:4) 2022-10-25 17:59:12.461 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5269, offs:4 leng:3 value:0x06 2022-10-25 17:59:12.461 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5269 (offs:4 leng:3) 2022-10-25 17:59:12.461 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5261, offs:0 leng:3 value:0x01 2022-10-25 17:59:12.461 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5261 (offs:0 leng:3) 2022-10-25 17:59:12.461 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5262, offs:6 leng:1 value:0x01 2022-10-25 17:59:12.461 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5262 (offs:6 leng:1) 2022-10-25 17:59:12.461 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5262, offs:4 leng:2 value:0x02 2022-10-25 17:59:12.461 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5262 (offs:4 leng:2) 2022-10-25 17:59:12.461 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5265, offs:7 leng:1 value:0x01 2022-10-25 17:59:12.461 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5265 (offs:7 leng:1) 2022-10-25 17:59:12.461 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5269, offs:0 leng:1 value:0x00 2022-10-25 17:59:12.461 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5269 (offs:0 leng:1) 2022-10-25 17:59:12.461 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5269, offs:1 leng:1 value:0x01 2022-10-25 17:59:12.461 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5269 (offs:1 leng:1) 2022-10-25 17:59:12.461 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5262, offs:1 leng:1 value:0x00 2022-10-25 17:59:12.462 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5262 (offs:1 leng:1) 2022-10-25 17:59:12.462 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5262, offs:0 leng:1 value:0x00 2022-10-25 17:59:12.462 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5262 (offs:0 leng:1) 2022-10-25 17:59:12.462 [HAL:XDEB] [sx1302_send:2608] Setting LoRa syncword 0x34 2022-10-25 17:59:12.462 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x526D, offs:0 leng:5 value:0x06 2022-10-25 17:59:12.462 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x526D (offs:0 leng:5) 2022-10-25 17:59:12.462 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x526E, offs:0 leng:5 value:0x08 2022-10-25 17:59:12.462 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x526E (offs:0 leng:5) 2022-10-25 17:59:12.462 [HAL:XDEB] [sx1302_send:2621] Disable Fine Sync 2022-10-25 17:59:12.462 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5262, offs:7 leng:1 value:0x00 2022-10-25 17:59:12.462 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5262 (offs:7 leng:1) 2022-10-25 17:59:12.462 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x5263 2022-10-25 17:59:12.462 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5261, offs:6 leng:2 value:0x00 2022-10-25 17:59:12.462 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5261 (offs:6 leng:2) 2022-10-25 17:59:12.462 [HAL:XDEB] [sx1302_send:2638] Low datarate optimization DISABLED 2022-10-25 17:59:12.462 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5261, offs:4 leng:2 value:0x00 2022-10-25 17:59:12.462 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5261 (offs:4 leng:2) 2022-10-25 17:59:12.462 [HAL:XDEB] [sx1302_tx_set_start_delay:2264] INFO: tx_start_delay=47837 (48000, radio_bw_delay=21, filter_delay=126, modem_delay=16) 2022-10-25 17:59:12.462 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5207, offs:0 leng:1 value:0x01 2022-10-25 17:59:12.462 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5207 (offs:0 leng:1) 2022-10-25 17:59:12.462 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5207, offs:0 leng:1 value:0x00 2022-10-25 17:59:12.462 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5207 (offs:0 leng:1) 2022-10-25 17:59:12.462 [HAL:XDEB] [sx1302_send:2751] Start Tx: Freq:923900000 SF8 size:39 preamb:8 2022-10-25 17:59:12.462 [HAL:XDEB] [sx1302_send:2761] --> programming trig delay at 154831817 (659650819) 2022-10-25 17:59:12.462 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x5204 2022-10-25 17:59:12.462 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x5203 2022-10-25 17:59:12.462 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x5202 2022-10-25 17:59:12.462 [HAL:XDEB] [reg_w:1124] ==> DIRECT WRITE @ 0x5201 2022-10-25 17:59:12.462 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5200, offs:1 leng:1 value:0x00 2022-10-25 17:59:12.462 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5200 (offs:1 leng:1) 2022-10-25 17:59:12.462 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5200, offs:1 leng:1 value:0x01 2022-10-25 17:59:12.462 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5200 (offs:1 leng:1) 2022-10-25 17:59:12.462 [HAL:XDEB] [lgw_usb_flush:466] INFO: flushing USB write buffer 2022-10-25 17:59:12.464 [HAL:XDEB] [lgw_usb_set_write_mode:436] setting USB write mode to SINGLE 2022-10-25 17:59:12.464 [HAL:XDEB] [lgw_send:1484] --- OUT 2022-10-25 17:59:12.486 [HAL:XDEB] [lgw_status:1496] --- IN 2022-10-25 17:59:12.486 [HAL:XDEB] [lgw_status:1523] --- OUT 2022-10-25 17:59:12.486 [S2E:ERRO] ::1 diid=68 [ant#0] - radio is not emitting frame - abandoning TX, trying alternative 2022-10-25 17:59:12.486 [HAL:XDEB] [lgw_abort_tx:1534] --- IN 2022-10-25 17:59:12.486 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5200, offs:0 leng:1 value:0x00 2022-10-25 17:59:12.486 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5200 (offs:0 leng:1) 2022-10-25 17:59:12.486 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5200, offs:1 leng:1 value:0x00 2022-10-25 17:59:12.487 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5200 (offs:1 leng:1) 2022-10-25 17:59:12.487 [HAL:XDEB] [lgw_usb_rmw:302] ==> RMW register @ 0x5200, offs:2 leng:1 value:0x00 2022-10-25 17:59:12.487 [HAL:XDEB] [reg_w:1128] ==> READ MODIFY WRITE @ 0x5200 (offs:2 leng:1) 2022-10-25 17:59:12.488 [HAL:XDEB] [lgw_abort_tx:1545] --- OUT 2022-10-25 17:59:12.488 [S2E:VERB] ::1 diid=68 [ant#0] - class A has no more alternate TX time 2022-10-25 17:59:12.488 [S2E:WARN] ::1 diid=68 [ant#0] - unable to place frame 2022-10-25 17:59:12.946 [SYN:XDEB] SYNC: ustime=0x00035BD6ED00 (Q=577): xticks=0x094148ac xtime=0xB40000094148AC - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:59:13.996 [SYN:XDEB] SYNC: ustime=0x00035BE6F56E (Q=632): xticks=0x0951507b xtime=0xB400000951507B - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:59:13.996 [SYN:WARN] Repeated excessive clock drifts between MCU/SX130X#0 (129 retries): 159.0ppm (threshold 100.0ppm) 2022-10-25 17:59:14.360 [AIO:XDEB] [3] socket read bytes=2 2022-10-25 17:59:14.361 [AIO:XDEB] [3|WS] < PING () 2022-10-25 17:59:14.361 [AIO:XDEB] [3|WS] > PONG 2022-10-25 17:59:14.361 [AIO:XDEB] [3] socket write bytes=6 2022-10-25 17:59:15.047 [SYN:XDEB] SYNC: ustime=0x00035BF6FE0B (Q=596): xticks=0x096158ac xtime=0xB40000096158AC - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:59:15.725 [HAL:XDEB] [rx_buffer_fetch:154] ----------------- 2022-10-25 17:59:15.725 [HAL:XDEB] [rx_buffer_fetch:155] rx_buffer_fetch: nb_bytes to be fetched: 94 (94 0) 2022-10-25 17:59:15.725 [HAL:XDEB] [rx_buffer_fetch:165] RX BUFFER: A5C01804830CA0D80C80635C0C26008C0001356254A9A951A6DD843D2BB8C7919C01E0867F4031143A752D22B9005DA5C018068308A0F80F80635C0C260000000126A2F4A9A054A6DD87F12FBAF4511C0038BEBD0012443C752D22890057 2022-10-25 17:59:15.725 [HAL:XDEB] [rx_buffer_fetch:177] INFO: syncword found at idx 0 2022-10-25 17:59:15.726 [HAL:XDEB] [lgw_receive:1291] WARNING: not enough space allocated, fetched 2 packet(s), 1 will be left in RX buffer 2022-10-25 17:59:15.726 [HAL:XDEB] [lgw_usb_get_temperature:500] temperature:28.7oC 2022-10-25 17:59:15.726 [HAL:XDEB] [rx_buffer_pop:244] INFO: pkt syncword found at index 0 2022-10-25 17:59:15.726 [HAL:XDEB] [rx_buffer_pop:275] Packet checksum OK (0x5D) 2022-10-25 17:59:15.726 [HAL:XDEB] [rx_buffer_pop:311] ----------------- 2022-10-25 17:59:15.726 [HAL:XDEB] [rx_buffer_pop:312] modem: 12 2022-10-25 17:59:15.726 [HAL:XDEB] [rx_buffer_pop:313] chan: 4 2022-10-25 17:59:15.726 [HAL:XDEB] [rx_buffer_pop:314] size: 24 2022-10-25 17:59:15.726 [HAL:XDEB] [rx_buffer_pop:315] crc_en: 1 2022-10-25 17:59:15.726 [HAL:XDEB] [rx_buffer_pop:316] crc_err: 1 2022-10-25 17:59:15.726 [HAL:XDEB] [rx_buffer_pop:317] sync_err: 0 2022-10-25 17:59:15.727 [HAL:XDEB] [rx_buffer_pop:318] hdr_err: 0 2022-10-25 17:59:15.727 [HAL:XDEB] [rx_buffer_pop:319] timing_set: 0 2022-10-25 17:59:15.727 [HAL:XDEB] [rx_buffer_pop:320] codr: 1 2022-10-25 17:59:15.727 [HAL:XDEB] [rx_buffer_pop:321] datr: 8 2022-10-25 17:59:15.727 [HAL:XDEB] [rx_buffer_pop:322] num_ts: 0 2022-10-25 17:59:15.727 [HAL:XDEB] [rx_buffer_pop:331] ----------------- 2022-10-25 17:59:15.727 [HAL:XDEB] [sx1302_parse:1946] [4 0x11] 2022-10-25 17:59:15.727 [HAL:XDEB] [sx1302_parse:1959] Note: LoRa packet (modem 12 chan 4) 2022-10-25 17:59:15.727 [HAL:XDEB] [legacy_timestamp_correction:205] FTIME OFF : filtering_delay %lu 2022-10-25 17:59:15.727 [HAL:XDEB] [legacy_timestamp_correction:206] FTIME OFF : fft_delay_state3 %lu 2022-10-25 17:59:15.727 [HAL:XDEB] [legacy_timestamp_correction:207] FTIME OFF : fft_delay %lu 2022-10-25 17:59:15.727 [HAL:XDEB] [legacy_timestamp_correction:208] FTIME OFF : demap_delay %lu 2022-10-25 17:59:15.727 [HAL:XDEB] [legacy_timestamp_correction:209] FTIME OFF : decode_delay %lu 2022-10-25 17:59:15.727 [HAL:XDEB] [legacy_timestamp_correction:210] FTIME OFF : timestamp correction -874 2022-10-25 17:59:15.727 [HAL:XDEB] [sx1302_rssi_get_temperature_offset:2283] INFO: RSSI temperature compensation: 2022-10-25 17:59:15.727 [HAL:XDEB] [sx1302_rssi_get_temperature_offset:2284] coeff_a: 0.000 2022-10-25 17:59:15.727 [HAL:XDEB] [sx1302_rssi_get_temperature_offset:2285] coeff_b: 0.000 2022-10-25 17:59:15.727 [HAL:XDEB] [sx1302_rssi_get_temperature_offset:2286] coeff_c: 20.410 2022-10-25 17:59:15.727 [HAL:XDEB] [sx1302_rssi_get_temperature_offset:2287] coeff_d: 2162.560 2022-10-25 17:59:15.727 [HAL:XDEB] [sx1302_rssi_get_temperature_offset:2288] coeff_e: 0.000 2022-10-25 17:59:15.727 [HAL:XDEB] [lgw_receive:1320] INFO: RSSI temperature offset applied: 1.203 dB (current temperature 28.7 C) 2022-10-25 17:59:15.727 [HAL:XDEB] [lgw_receive:1323] INFO: nb pkt found:1 left:1 2022-10-25 17:59:15.727 [HAL:XDEB] [lgw_receive:1337] --- OUT 2022-10-25 17:59:15.727 [RAL:DEBU] [CRC FAIL] 904.700MHz -8.00/-87.2 SF8/BW125 (mod=16/dr=8/bw=4) xtick=096ba666 (158049894) 24 bytes: 80635C0C26008C0001356254A9A951A6DD843D2BB8C7919C 2022-10-25 17:59:15.727 [HAL:XDEB] [sx1302_fetch:1886] Note: remaining 1 packets in RX buffer, do not fetch sx1302 yet... 2022-10-25 17:59:15.728 [HAL:XDEB] [lgw_usb_get_temperature:500] temperature:28.7oC 2022-10-25 17:59:15.728 [HAL:XDEB] [rx_buffer_pop:244] INFO: pkt syncword found at index 47 2022-10-25 17:59:15.728 [HAL:XDEB] [rx_buffer_pop:275] Packet checksum OK (0x57) 2022-10-25 17:59:15.728 [HAL:XDEB] [rx_buffer_pop:311] ----------------- 2022-10-25 17:59:15.728 [HAL:XDEB] [rx_buffer_pop:312] modem: 8 2022-10-25 17:59:15.728 [HAL:XDEB] [rx_buffer_pop:313] chan: 6 2022-10-25 17:59:15.728 [HAL:XDEB] [rx_buffer_pop:314] size: 24 2022-10-25 17:59:15.728 [HAL:XDEB] [rx_buffer_pop:315] crc_en: 1 2022-10-25 17:59:15.728 [HAL:XDEB] [rx_buffer_pop:316] crc_err: 0 2022-10-25 17:59:15.728 [HAL:XDEB] [rx_buffer_pop:317] sync_err: 0 2022-10-25 17:59:15.728 [HAL:XDEB] [rx_buffer_pop:318] hdr_err: 0 2022-10-25 17:59:15.728 [HAL:XDEB] [rx_buffer_pop:319] timing_set: 0 2022-10-25 17:59:15.728 [HAL:XDEB] [rx_buffer_pop:320] codr: 1 2022-10-25 17:59:15.728 [HAL:XDEB] [rx_buffer_pop:321] datr: 8 2022-10-25 17:59:15.728 [HAL:XDEB] [rx_buffer_pop:322] num_ts: 0 2022-10-25 17:59:15.728 [HAL:XDEB] [rx_buffer_pop:331] ----------------- 2022-10-25 17:59:15.728 [HAL:XDEB] [sx1302_parse:1946] [6 0x11] 2022-10-25 17:59:15.728 [HAL:XDEB] [sx1302_parse:1959] Note: LoRa packet (modem 8 chan 6) 2022-10-25 17:59:15.728 [HAL:XDEB] [sx1302_parse:1981] Payload CRC check OK (0x8922) 2022-10-25 17:59:15.728 [HAL:XDEB] [legacy_timestamp_correction:205] FTIME OFF : filtering_delay %lu 2022-10-25 17:59:15.728 [HAL:XDEB] [legacy_timestamp_correction:206] FTIME OFF : fft_delay_state3 %lu 2022-10-25 17:59:15.728 [HAL:XDEB] [legacy_timestamp_correction:207] FTIME OFF : fft_delay %lu 2022-10-25 17:59:15.728 [HAL:XDEB] [legacy_timestamp_correction:208] FTIME OFF : demap_delay %lu 2022-10-25 17:59:15.728 [HAL:XDEB] [legacy_timestamp_correction:209] FTIME OFF : decode_delay %lu 2022-10-25 17:59:15.728 [HAL:XDEB] [legacy_timestamp_correction:210] FTIME OFF : timestamp correction -874 2022-10-25 17:59:15.728 [HAL:XDEB] [sx1302_rssi_get_temperature_offset:2283] INFO: RSSI temperature compensation: 2022-10-25 17:59:15.728 [HAL:XDEB] [sx1302_rssi_get_temperature_offset:2284] coeff_a: 0.000 2022-10-25 17:59:15.728 [HAL:XDEB] [sx1302_rssi_get_temperature_offset:2285] coeff_b: 0.000 2022-10-25 17:59:15.728 [HAL:XDEB] [sx1302_rssi_get_temperature_offset:2286] coeff_c: 20.410 2022-10-25 17:59:15.728 [HAL:XDEB] [sx1302_rssi_get_temperature_offset:2287] coeff_d: 2162.560 2022-10-25 17:59:15.728 [HAL:XDEB] [sx1302_rssi_get_temperature_offset:2288] coeff_e: 0.000 2022-10-25 17:59:15.728 [HAL:XDEB] [lgw_receive:1320] INFO: RSSI temperature offset applied: 1.203 dB (current temperature 28.7 C) 2022-10-25 17:59:15.728 [HAL:XDEB] [lgw_receive:1323] INFO: nb pkt found:1 left:0 2022-10-25 17:59:15.728 [HAL:XDEB] [lgw_receive:1337] --- OUT 2022-10-25 17:59:15.728 [RAL:XDEB] [CRC OK] 905.100MHz 14.00/-25.2 SF8/BW125 (mod=16/dr=8/bw=4) xtick=096ba678 (158049912) 24 bytes: 80635C0C260000000126A2F4A9A054A6DD87F12FBAF4511C 2022-10-25 17:59:15.730 [S2E:VERB] RX 905.1MHz DR2 SF8/BW125 snr=14.0 rssi=-25 xtime=0xB40000096BA678 - updf mhdr=80 DevAddr=260C5C63 FCtrl=00 FCnt=0 FOpts=[] 0126A2F4..F12F mic=475133114 (24 bytes) 2022-10-25 17:59:15.731 [AIO:XDEB] [3|WS] > {"msgtype":"updf","MHdr":128,"DevAddr":638344291,"FCtrl":0,"FCnt":0,"FOpts":"","FPort":1,"FRMPayload":"26A2F4A9A054A6DD87F12F","MIC":475133114,"RefTime":1666720755.732481,"DR":2,"Freq":905100000,"upinfo":{"rctx":0,"xtime":50665495965967992,"gpstime":0,"fts":-1,"rssi":-25,"snr":14,"rxtime":1666720755.731047}} 2022-10-25 17:59:15.731 [AIO:XDEB] [3] socket write bytes=317 2022-10-25 17:59:16.098 [SYN:XDEB] SYNC: ustime=0x00035C07069B (Q=654): xticks=0x0971609e xtime=0xB400000971609E - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:59:17.149 [SYN:XDEB] SYNC: ustime=0x00035C170F2C (Q=595): xticks=0x098168cf xtime=0xB40000098168CF - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:59:17.149 [SYN:WARN] Repeated excessive clock drifts between MCU/SX130X#0 (132 retries): 158.1ppm (threshold 100.0ppm) 2022-10-25 17:59:18.200 [SYN:XDEB] SYNC: ustime=0x00035C2719AD (Q=639): xticks=0x099172b3 xtime=0xB40000099172B3 - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:59:19.251 [SYN:XDEB] SYNC: ustime=0x00035C372246 (Q=637): xticks=0x09a17acd xtime=0xB4000009A17ACD - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:59:20.302 [SYN:XDEB] SYNC: ustime=0x00035C472ACA (Q=599): xticks=0x09b182e5 xtime=0xB4000009B182E5 - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:59:20.302 [SYN:WARN] Repeated excessive clock drifts between MCU/SX130X#0 (135 retries): 157.4ppm (threshold 100.0ppm) 2022-10-25 17:59:21.352 [SYN:XDEB] SYNC: ustime=0x00035C57336B (Q=620): xticks=0x09c18b00 xtime=0xB4000009C18B00 - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:59:22.403 [SYN:XDEB] SYNC: ustime=0x00035C673BED (Q=617): xticks=0x09d19303 xtime=0xB4000009D19303 - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:59:23.454 [SYN:XDEB] SYNC: ustime=0x00035C774467 (Q=623): xticks=0x09e19af5 xtime=0xB4000009E19AF5 - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:59:23.454 [SYN:WARN] Repeated excessive clock drifts between MCU/SX130X#0 (138 retries): 156.8ppm (threshold 100.0ppm) 2022-10-25 17:59:23.948 [HAL:XDEB] [rx_buffer_fetch:154] ----------------- 2022-10-25 17:59:23.948 [HAL:XDEB] [rx_buffer_fetch:155] rx_buffer_fetch: nb_bytes to be fetched: 94 (94 0) 2022-10-25 17:59:23.948 [HAL:XDEB] [rx_buffer_fetch:165] RX BUFFER: A5C01805830AA0B60D80605C0C260000000126A2F4A9A054AEDD82FD2FBAF4DD1801D680771142244D213D228900B1A5C018018308800E0080635C0C260000000126A2F4A9A054A6DD87F12FBAF4511C0040BCBC00006C4D213D22890021 2022-10-25 17:59:23.948 [HAL:XDEB] [rx_buffer_fetch:177] INFO: syncword found at idx 0 2022-10-25 17:59:23.949 [HAL:XDEB] [lgw_receive:1291] WARNING: not enough space allocated, fetched 2 packet(s), 1 will be left in RX buffer 2022-10-25 17:59:23.949 [HAL:XDEB] [lgw_usb_get_temperature:500] temperature:28.8oC 2022-10-25 17:59:23.949 [HAL:XDEB] [rx_buffer_pop:244] INFO: pkt syncword found at index 0 2022-10-25 17:59:23.949 [HAL:XDEB] [rx_buffer_pop:275] Packet checksum OK (0xB1) 2022-10-25 17:59:23.949 [HAL:XDEB] [rx_buffer_pop:311] ----------------- 2022-10-25 17:59:23.949 [HAL:XDEB] [rx_buffer_pop:312] modem: 10 2022-10-25 17:59:23.949 [HAL:XDEB] [rx_buffer_pop:313] chan: 5 2022-10-25 17:59:23.949 [HAL:XDEB] [rx_buffer_pop:314] size: 24 2022-10-25 17:59:23.949 [HAL:XDEB] [rx_buffer_pop:315] crc_en: 1 2022-10-25 17:59:23.949 [HAL:XDEB] [rx_buffer_pop:316] crc_err: 1 2022-10-25 17:59:23.949 [HAL:XDEB] [rx_buffer_pop:317] sync_err: 0 2022-10-25 17:59:23.949 [HAL:XDEB] [rx_buffer_pop:318] hdr_err: 0 2022-10-25 17:59:23.949 [HAL:XDEB] [rx_buffer_pop:319] timing_set: 0 2022-10-25 17:59:23.949 [HAL:XDEB] [rx_buffer_pop:320] codr: 1 2022-10-25 17:59:23.949 [HAL:XDEB] [rx_buffer_pop:321] datr: 8 2022-10-25 17:59:23.949 [HAL:XDEB] [rx_buffer_pop:322] num_ts: 0 2022-10-25 17:59:23.949 [HAL:XDEB] [rx_buffer_pop:331] ----------------- 2022-10-25 17:59:23.949 [HAL:XDEB] [sx1302_parse:1946] [5 0x11] 2022-10-25 17:59:23.949 [HAL:XDEB] [sx1302_parse:1959] Note: LoRa packet (modem 10 chan 5) 2022-10-25 17:59:23.949 [HAL:XDEB] [legacy_timestamp_correction:205] FTIME OFF : filtering_delay %lu 2022-10-25 17:59:23.949 [HAL:XDEB] [legacy_timestamp_correction:206] FTIME OFF : fft_delay_state3 %lu 2022-10-25 17:59:23.949 [HAL:XDEB] [legacy_timestamp_correction:207] FTIME OFF : fft_delay %lu 2022-10-25 17:59:23.949 [HAL:XDEB] [legacy_timestamp_correction:208] FTIME OFF : demap_delay %lu 2022-10-25 17:59:23.949 [HAL:XDEB] [legacy_timestamp_correction:209] FTIME OFF : decode_delay %lu 2022-10-25 17:59:23.949 [HAL:XDEB] [legacy_timestamp_correction:210] FTIME OFF : timestamp correction -874 2022-10-25 17:59:23.949 [HAL:XDEB] [sx1302_rssi_get_temperature_offset:2283] INFO: RSSI temperature compensation: 2022-10-25 17:59:23.949 [HAL:XDEB] [sx1302_rssi_get_temperature_offset:2284] coeff_a: 0.000 2022-10-25 17:59:23.949 [HAL:XDEB] [sx1302_rssi_get_temperature_offset:2285] coeff_b: 0.000 2022-10-25 17:59:23.949 [HAL:XDEB] [sx1302_rssi_get_temperature_offset:2286] coeff_c: 20.410 2022-10-25 17:59:23.949 [HAL:XDEB] [sx1302_rssi_get_temperature_offset:2287] coeff_d: 2162.560 2022-10-25 17:59:23.949 [HAL:XDEB] [sx1302_rssi_get_temperature_offset:2288] coeff_e: 0.000 2022-10-25 17:59:23.949 [HAL:XDEB] [lgw_receive:1320] INFO: RSSI temperature offset applied: 1.206 dB (current temperature 28.8 C) 2022-10-25 17:59:23.949 [HAL:XDEB] [lgw_receive:1323] INFO: nb pkt found:1 left:1 2022-10-25 17:59:23.950 [HAL:XDEB] [lgw_receive:1337] --- OUT 2022-10-25 17:59:23.950 [RAL:DEBU] [CRC FAIL] 904.900MHz -10.50/-95.2 SF8/BW125 (mod=16/dr=8/bw=4) xtick=09e906ff (166266623) 24 bytes: 80605C0C260000000126A2F4A9A054AEDD82FD2FBAF4DD18 2022-10-25 17:59:23.950 [HAL:XDEB] [sx1302_fetch:1886] Note: remaining 1 packets in RX buffer, do not fetch sx1302 yet... 2022-10-25 17:59:23.950 [HAL:XDEB] [lgw_usb_get_temperature:500] temperature:28.8oC 2022-10-25 17:59:23.950 [HAL:XDEB] [rx_buffer_pop:244] INFO: pkt syncword found at index 47 2022-10-25 17:59:23.950 [HAL:XDEB] [rx_buffer_pop:275] Packet checksum OK (0x21) 2022-10-25 17:59:23.950 [HAL:XDEB] [rx_buffer_pop:311] ----------------- 2022-10-25 17:59:23.950 [HAL:XDEB] [rx_buffer_pop:312] modem: 8 2022-10-25 17:59:23.951 [HAL:XDEB] [rx_buffer_pop:313] chan: 1 2022-10-25 17:59:23.951 [HAL:XDEB] [rx_buffer_pop:314] size: 24 2022-10-25 17:59:23.951 [HAL:XDEB] [rx_buffer_pop:315] crc_en: 1 2022-10-25 17:59:23.951 [HAL:XDEB] [rx_buffer_pop:316] crc_err: 0 2022-10-25 17:59:23.951 [HAL:XDEB] [rx_buffer_pop:317] sync_err: 0 2022-10-25 17:59:23.951 [HAL:XDEB] [rx_buffer_pop:318] hdr_err: 0 2022-10-25 17:59:23.951 [HAL:XDEB] [rx_buffer_pop:319] timing_set: 0 2022-10-25 17:59:23.951 [HAL:XDEB] [rx_buffer_pop:320] codr: 1 2022-10-25 17:59:23.951 [HAL:XDEB] [rx_buffer_pop:321] datr: 8 2022-10-25 17:59:23.951 [HAL:XDEB] [rx_buffer_pop:322] num_ts: 0 2022-10-25 17:59:23.951 [HAL:XDEB] [rx_buffer_pop:331] ----------------- 2022-10-25 17:59:23.951 [HAL:XDEB] [sx1302_parse:1946] [1 0x11] 2022-10-25 17:59:23.951 [HAL:XDEB] [sx1302_parse:1959] Note: LoRa packet (modem 8 chan 1) 2022-10-25 17:59:23.951 [HAL:XDEB] [sx1302_parse:1981] Payload CRC check OK (0x8922) 2022-10-25 17:59:23.951 [HAL:XDEB] [legacy_timestamp_correction:205] FTIME OFF : filtering_delay %lu 2022-10-25 17:59:23.951 [HAL:XDEB] [legacy_timestamp_correction:206] FTIME OFF : fft_delay_state3 %lu 2022-10-25 17:59:23.951 [HAL:XDEB] [legacy_timestamp_correction:207] FTIME OFF : fft_delay %lu 2022-10-25 17:59:23.951 [HAL:XDEB] [legacy_timestamp_correction:208] FTIME OFF : demap_delay %lu 2022-10-25 17:59:23.951 [HAL:XDEB] [legacy_timestamp_correction:209] FTIME OFF : decode_delay %lu 2022-10-25 17:59:23.951 [HAL:XDEB] [legacy_timestamp_correction:210] FTIME OFF : timestamp correction -874 2022-10-25 17:59:23.951 [HAL:XDEB] [sx1302_rssi_get_temperature_offset:2283] INFO: RSSI temperature compensation: 2022-10-25 17:59:23.951 [HAL:XDEB] [sx1302_rssi_get_temperature_offset:2284] coeff_a: 0.000 2022-10-25 17:59:23.951 [HAL:XDEB] [sx1302_rssi_get_temperature_offset:2285] coeff_b: 0.000 2022-10-25 17:59:23.951 [HAL:XDEB] [sx1302_rssi_get_temperature_offset:2286] coeff_c: 20.410 2022-10-25 17:59:23.951 [HAL:XDEB] [sx1302_rssi_get_temperature_offset:2287] coeff_d: 2162.560 2022-10-25 17:59:23.951 [HAL:XDEB] [sx1302_rssi_get_temperature_offset:2288] coeff_e: 0.000 2022-10-25 17:59:23.951 [HAL:XDEB] [lgw_receive:1320] INFO: RSSI temperature offset applied: 1.206 dB (current temperature 28.8 C) 2022-10-25 17:59:23.951 [HAL:XDEB] [lgw_receive:1323] INFO: nb pkt found:1 left:0 2022-10-25 17:59:23.951 [HAL:XDEB] [lgw_receive:1337] --- OUT 2022-10-25 17:59:23.951 [RAL:XDEB] [CRC OK] 904.100MHz 16.00/-26.2 SF8/BW125 (mod=16/dr=8/bw=4) xtick=09e90701 (166266625) 24 bytes: 80635C0C260000000126A2F4A9A054A6DD87F12FBAF4511C 2022-10-25 17:59:23.952 [S2E:VERB] RX 904.1MHz DR2 SF8/BW125 snr=16.0 rssi=-26 xtime=0xB4000009E90701 - updf mhdr=80 DevAddr=260C5C63 FCtrl=00 FCnt=0 FOpts=[] 0126A2F4..F12F mic=475133114 (24 bytes) 2022-10-25 17:59:23.952 [AIO:XDEB] [3|WS] > {"msgtype":"updf","MHdr":128,"DevAddr":638344291,"FCtrl":0,"FCnt":0,"FOpts":"","FPort":1,"FRMPayload":"26A2F4A9A054A6DD87F12F","MIC":475133114,"RefTime":1666720763.953030,"DR":2,"Freq":904100000,"upinfo":{"rctx":0,"xtime":50665495974184705,"gpstime":0,"fts":-1,"rssi":-26,"snr":16,"rxtime":1666720763.952886}} 2022-10-25 17:59:23.953 [AIO:XDEB] [3] socket write bytes=317 2022-10-25 17:59:24.505 [SYN:XDEB] SYNC: ustime=0x00035C874D0D (Q=638): xticks=0x09f1a319 xtime=0xB4000009F1A319 - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:59:25.555 [SYN:XDEB] SYNC: ustime=0x00035C97559D (Q=615): xticks=0x0a01ab39 xtime=0xB400000A01AB39 - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:59:25.555 [SYN:INFO] Time sync qualities: min=572 q90=654 max=688 (previous q90=655) 2022-10-25 17:59:25.555 [SYN:INFO] MCU/SX130X drift stats: min: +156.3ppm q50: +158.6ppm q80: +160.5ppm max: +161.0ppm - threshold q90: +161.0ppm 2022-10-25 17:59:25.555 [SYN:INFO] Mean MCU drift vs SX130X#0: 158.7ppm 2022-10-25 17:59:26.603 [SYN:XDEB] SYNC: ustime=0x00035CA75E96 (Q=641): xticks=0x0a11b3aa xtime=0xB400000A11B3AA - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:59:26.603 [SYN:WARN] Repeated excessive clock drifts between MCU/SX130X#0 (141 retries): 156.1ppm (threshold 100.0ppm) 2022-10-25 17:59:27.653 [SYN:XDEB] SYNC: ustime=0x00035CB7674D (Q=620): xticks=0x0a21bc00 xtime=0xB400000A21BC00 - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:59:28.704 [SYN:XDEB] SYNC: ustime=0x00035CC76FCD (Q=593): xticks=0x0a31c3fb xtime=0xB400000A31C3FB - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:59:29.755 [SYN:XDEB] SYNC: ustime=0x00035CD7784E (Q=638): xticks=0x0a41cc1d xtime=0xB400000A41CC1D - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:59:29.755 [SYN:WARN] Repeated excessive clock drifts between MCU/SX130X#0 (144 retries): 155.2ppm (threshold 100.0ppm) 2022-10-25 17:59:30.806 [SYN:XDEB] SYNC: ustime=0x00035CE7810F (Q=660): xticks=0x0a51d428 xtime=0xB400000A51D428 - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:59:30.806 [SYN:VERB] Time sync rejected: quality=660 threshold=654 2022-10-25 17:59:32.164 [HAL:XDEB] [rx_buffer_fetch:154] ----------------- 2022-10-25 17:59:32.164 [HAL:XDEB] [rx_buffer_fetch:155] rx_buffer_fetch: nb_bytes to be fetched: 47 (47 0) 2022-10-25 17:59:32.164 [HAL:XDEB] [rx_buffer_fetch:165] RX BUFFER: A5C018008308800A0080635C0C260000000126A2F4A9A054A6DD87F12FBAF4511C0037BBBB00028C5BCD4C228900FC 2022-10-25 17:59:32.164 [HAL:XDEB] [rx_buffer_fetch:177] INFO: syncword found at idx 0 2022-10-25 17:59:32.165 [HAL:XDEB] [lgw_usb_get_temperature:500] temperature:28.8oC 2022-10-25 17:59:32.165 [HAL:XDEB] [rx_buffer_pop:244] INFO: pkt syncword found at index 0 2022-10-25 17:59:32.165 [HAL:XDEB] [rx_buffer_pop:275] Packet checksum OK (0xFC) 2022-10-25 17:59:32.165 [HAL:XDEB] [rx_buffer_pop:311] ----------------- 2022-10-25 17:59:32.165 [HAL:XDEB] [rx_buffer_pop:312] modem: 8 2022-10-25 17:59:32.165 [HAL:XDEB] [rx_buffer_pop:313] chan: 0 2022-10-25 17:59:32.165 [HAL:XDEB] [rx_buffer_pop:314] size: 24 2022-10-25 17:59:32.165 [HAL:XDEB] [rx_buffer_pop:315] crc_en: 1 2022-10-25 17:59:32.165 [HAL:XDEB] [rx_buffer_pop:316] crc_err: 0 2022-10-25 17:59:32.165 [HAL:XDEB] [rx_buffer_pop:317] sync_err: 0 2022-10-25 17:59:32.165 [HAL:XDEB] [rx_buffer_pop:318] hdr_err: 0 2022-10-25 17:59:32.165 [HAL:XDEB] [rx_buffer_pop:319] timing_set: 0 2022-10-25 17:59:32.165 [HAL:XDEB] [rx_buffer_pop:320] codr: 1 2022-10-25 17:59:32.165 [HAL:XDEB] [rx_buffer_pop:321] datr: 8 2022-10-25 17:59:32.165 [HAL:XDEB] [rx_buffer_pop:322] num_ts: 0 2022-10-25 17:59:32.165 [HAL:XDEB] [rx_buffer_pop:331] ----------------- 2022-10-25 17:59:32.165 [HAL:XDEB] [sx1302_parse:1946] [0 0x11] 2022-10-25 17:59:32.165 [HAL:XDEB] [sx1302_parse:1959] Note: LoRa packet (modem 8 chan 0) 2022-10-25 17:59:32.165 [HAL:XDEB] [sx1302_parse:1981] Payload CRC check OK (0x8922) 2022-10-25 17:59:32.165 [HAL:XDEB] [legacy_timestamp_correction:205] FTIME OFF : filtering_delay %lu 2022-10-25 17:59:32.165 [HAL:XDEB] [legacy_timestamp_correction:206] FTIME OFF : fft_delay_state3 %lu 2022-10-25 17:59:32.165 [HAL:XDEB] [legacy_timestamp_correction:207] FTIME OFF : fft_delay %lu 2022-10-25 17:59:32.166 [HAL:XDEB] [legacy_timestamp_correction:208] FTIME OFF : demap_delay %lu 2022-10-25 17:59:32.166 [HAL:XDEB] [legacy_timestamp_correction:209] FTIME OFF : decode_delay %lu 2022-10-25 17:59:32.166 [HAL:XDEB] [legacy_timestamp_correction:210] FTIME OFF : timestamp correction -874 2022-10-25 17:59:32.166 [HAL:XDEB] [sx1302_rssi_get_temperature_offset:2283] INFO: RSSI temperature compensation: 2022-10-25 17:59:32.166 [HAL:XDEB] [sx1302_rssi_get_temperature_offset:2284] coeff_a: 0.000 2022-10-25 17:59:32.166 [HAL:XDEB] [sx1302_rssi_get_temperature_offset:2285] coeff_b: 0.000 2022-10-25 17:59:32.166 [HAL:XDEB] [sx1302_rssi_get_temperature_offset:2286] coeff_c: 20.410 2022-10-25 17:59:32.166 [HAL:XDEB] [sx1302_rssi_get_temperature_offset:2287] coeff_d: 2162.560 2022-10-25 17:59:32.166 [HAL:XDEB] [sx1302_rssi_get_temperature_offset:2288] coeff_e: 0.000 2022-10-25 17:59:32.166 [HAL:XDEB] [lgw_receive:1320] INFO: RSSI temperature offset applied: 1.206 dB (current temperature 28.8 C) 2022-10-25 17:59:32.166 [HAL:XDEB] [lgw_receive:1323] INFO: nb pkt found:1 left:0 2022-10-25 17:59:32.166 [HAL:XDEB] [lgw_receive:1337] --- OUT 2022-10-25 17:59:32.166 [RAL:XDEB] [CRC OK] 903.900MHz 13.75/-27.2 SF8/BW125 (mod=16/dr=8/bw=4) xtick=0a666772 (174483314) 24 bytes: 80635C0C260000000126A2F4A9A054A6DD87F12FBAF4511C 2022-10-25 17:59:32.167 [S2E:VERB] RX 903.9MHz DR2 SF8/BW125 snr=13.8 rssi=-27 xtime=0xB400000A666772 - updf mhdr=80 DevAddr=260C5C63 FCtrl=00 FCnt=0 FOpts=[] 0126A2F4..F12F mic=475133114 (24 bytes) 2022-10-25 17:59:32.167 [AIO:XDEB] [3|WS] > {"msgtype":"updf","MHdr":128,"DevAddr":638344291,"FCtrl":0,"FCnt":0,"FOpts":"","FPort":1,"FRMPayload":"26A2F4A9A054A6DD87F12F","MIC":475133114,"RefTime":1666720772.170031,"DR":2,"Freq":903900000,"upinfo":{"rctx":0,"xtime":50665495982401394,"gpstime":0,"fts":-1,"rssi":-27,"snr":13.75,"rxtime":1666720772.167489}} 2022-10-25 17:59:32.167 [AIO:XDEB] [3] socket write bytes=320 2022-10-25 17:59:32.906 [SYN:XDEB] SYNC: ustime=0x00035D078F34 (Q=586): xticks=0x0a71e177 xtime=0xB400000A71E177 - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:59:33.957 [SYN:XDEB] SYNC: ustime=0x00035D17979F (Q=596): xticks=0x0a81e97e xtime=0xB400000A81E97E - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:59:35.008 [SYN:XDEB] SYNC: ustime=0x00035D27A014 (Q=608): xticks=0x0a91f157 xtime=0xB400000A91F157 - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:59:35.008 [SYN:WARN] Repeated excessive clock drifts between MCU/SX130X#0 (147 retries): 154.2ppm (threshold 100.0ppm) 2022-10-25 17:59:36.059 [SYN:XDEB] SYNC: ustime=0x00035D37A8B7 (Q=600): xticks=0x0aa1f984 xtime=0xB400000AA1F984 - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:59:37.110 [SYN:XDEB] SYNC: ustime=0x00035D47B13F (Q=638): xticks=0x0ab20186 xtime=0xB400000AB20186 - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:59:38.160 [SYN:XDEB] SYNC: ustime=0x00035D57B9C8 (Q=597): xticks=0x0ac209a3 xtime=0xB400000AC209A3 - PPS: pps_xticks=0x00000000 (0) pps_xtime=0x0 (pps_en=0) 2022-10-25 17:59:38.160 [SYN:WARN] Repeated excessive clock drifts between MCU/SX130X#0 (150 retries): 153.5ppm (threshold 100.0ppm)