search

lorabasics / basicstation

LoRa Basics™ Station - The LoRaWAN Gateway Software
https://doc.sm.tc/station
Other
340 stars 178 forks source link

Timesync with SX1302 HAL 2.1.0 with basic station. #109

Closed AbhishekLakhara0209 closed 2 years ago

AbhishekLakhara0209 commented 3 years ago

We have manually added support of SX1302 HAL 2.1.0 with basic station. We are facing issue of time sync. We are not getting proper pps time.

is new HAL of SX1302 supported by basic station?

Also we are planning to use fine time stamp feature in basic station so is it supported with current basic station version?

Are you planning to add support for SX1302 HAL 2.1.0 with basic station?

beitler commented 3 years ago

Thanks for reaching out. Can you please provide more detail on what you did, what you are trying to achieve and what the exact error condition is? Concretely:

We have manually added support of SX1302 HAL 2.1.0 with basic station. We are facing issue of time sync. We are not getting proper pps time.

What is the issue with time sync? Do you get error messages? How do they look like? What do you mean with 'we are not getting proper pps time'? Did this issue not address your problem?

is new HAL of SX1302 supported by basic station?

Currently, Basic Station runs against sx1302_hal version 1.0.5.

Also we are planning to use fine time stamp feature in basic station so is it supported with current basic station version?

How does your setup look like? Which hardware do you use to achieve fine time stamp? Are you using sx1303?

Are you planning to add support for SX1302 HAL 2.1.0 with basic station?

Support for newer sx1302_hal versions will be added. Which feature of the sx1302_hal 2.1.0 are you looking for?

AbhishekLakhara0209 commented 3 years ago

Can you please provide more detail on what you did, what you are trying to achieve and what the exact error condition is?

We have linked latest HAL of SX1302 with basic station as we want to run latest HAL with basic station.

What is the issue with time sync? Do you get error messages? How do they look like? What do you mean with 'we are not getting proper pps time'?

Please find below logs snippet. We have used SX1303 concentrator board with raspberry pi (version b+ V1.2) and for gps we have used UBX7. We have run the setup for more than 2-3 hours and observed that GPS was locked and also LNS sending the time sync request but we are getting the same logs line "Time sync rejected: quality=114 threshold=100" more than hours. 

021-06-15 07:09:44.391 [SYN:DEBU] Timesync #4179 sent to server
2021-06-15 07:09:44.414 [AIO:XDEB] [4|WS] < {"msgtype":"timesync","txtime":7719378049,"gpstime":1307776198073377}
2021-06-15 07:09:44.414 [SYN:VERB] Timesync LNS: tx/rx:0x1CC14F1BD..0x1CC1CEC82 (522ms949us) us/gps:0x1CC1E0284/0x4A56A5FBB5C21 (pps offset=486084) - 1 solutions
2021-06-15 07:09:44.416 [SYN:ERRO] Timesync LNS: Too much drift between last PPS and inferred PPS: 1000041us
2021-06-15 07:09:44.416 [AIO:XDEB] [4|WS] < {"msgtype":"timesync","txtime":7719449426,"gpstime":1307776198073680}
2021-06-15 07:09:44.416 [SYN:VERB] Timesync LNS: tx/rx:0x1CC16088E..0x1CC1CF1CA (452ms924us) us/gps:0x1CC1E0284/0x4A56A5FBB5D50 (pps offset=486084) - 1 solutions
2021-06-15 07:09:44.416 [SYN:ERRO] Timesync LNS: Too much drift between last PPS and inferred PPS: 1000041us
2021-06-15 07:09:44.417 [AIO:XDEB] [4|WS] < {"msgtype":"timesync","txtime":7719520747,"gpstime":1307776198073815}
2021-06-15 07:09:44.417 [SYN:VERB] Timesync LNS: tx/rx:0x1CC171F27..0x1CC1CF577 (382ms544us) us/gps:0x1CC1E0284/0x4A56A5FBB5DD7 (pps offset=486084) - 1 solutions
2021-06-15 07:09:44.417 [SYN:ERRO] Timesync LNS: Too much drift between last PPS and inferred PPS: 1000041us
2021-06-15 07:09:44.417 [AIO:XDEB] [4|WS] < {"msgtype":"timesync","txtime":7719592031,"gpstime":1307776198075562}
2021-06-15 07:09:44.417 [SYN:VERB] Timesync LNS: tx/rx:0x1CC18359B..0x1CC1CF69C (311ms553us) us/gps:0x0/0x4A56A5FBB64AA (pps offset=486084) - 0 solutions
2021-06-15 07:09:44.417 [AIO:XDEB] [4|WS] < {"msgtype":"timesync","txtime":7719663342,"gpstime":1307776198075729}
2021-06-15 07:09:44.417 [SYN:VERB] Timesync LNS: tx/rx:0x1CC194C2A..0x1CC1CF749 (240ms415us) us/gps:0x0/0x4A56A5FBB6551 (pps offset=486084) - 0 solutions
2021-06-15 07:09:44.417 [AIO:XDEB] [4|WS] < {"msgtype":"timesync","txtime":7719734693,"gpstime":1307776198075849}
2021-06-15 07:09:44.417 [SYN:VERB] Timesync LNS: tx/rx:0x1CC1A62E1..0x1CC1CF7F3 (169ms234us) us/gps:0x0/0x4A56A5FBB65C9 (pps offset=486084) - 0 solutions
2021-06-15 07:09:44.417 [AIO:XDEB] [4|WS] < {"msgtype":"timesync","txtime":7719805984,"gpstime":1307776198075957}
2021-06-15 07:09:44.418 [SYN:VERB] Timesync LNS: tx/rx:0x1CC1B795C..0x1CC1CF899 (98ms109us) us/gps:0x0/0x4A56A5FBB6635 (pps offset=486084) - 0 solutions
2021-06-15 07:09:44.418 [AIO:XDEB] [4|WS] < {"msgtype":"timesync","txtime":7719877262,"gpstime":1307776198076067}
2021-06-15 07:09:44.418 [SYN:VERB] Timesync LNS: tx/rx:0x1CC1C8FCA..0x1CC1CF93C (26ms994us) us/gps:0x0/0x4A56A5FBB66A3 (pps offset=486084) - 0 solutions
2021-06-15 07:09:44.462 [AIO:XDEB] [4|WS] > {"msgtype":"timesync","txtime":7719948546}
2021-06-15 07:09:44.462 [SYN:DEBU] Timesync #4180 sent to server
2021-06-15 07:09:44.504 [AIO:XDEB] [4|WS] < {"msgtype":"timesync","txtime":7719948546,"gpstime":1307776198129680}
2021-06-15 07:09:44.504 [SYN:VERB] Timesync LNS: tx/rx:0x1CC1DA63E..0x1CC1E4A36 (41ms976us) us/gps:0x0/0x4A56A5FBC3810 (pps offset=486084) - 0 solutions
2021-06-15 07:09:44.533 [AIO:XDEB] [4|WS] > {"msgtype":"timesync","txtime":7720019843}
2021-06-15 07:09:44.533 [SYN:DEBU] Timesync #4181 sent to server
2021-06-15 07:09:44.536 [AIO:XDEB] [4|WS] < {"msgtype":"timesync","txtime":7720019843,"gpstime":1307776198196320}
2021-06-15 07:09:44.536 [SYN:VERB] Timesync LNS: tx/rx:0x1CC1EBCBF..0x1CC1EC792 (2ms771us) us/gps:0x0/0x4A56A5FBD3C60 (pps offset=486084) - 0 solutions
2021-06-15 07:09:44.669 [SYN:CRIT] pps_xtime=24206852507116980,pps_xticks=80341147352901044
2021-06-15 07:09:44.670 [SYN:INFO] Time sync qualities: min=302 q90=349 max=489 (previous q90=355)
2021-06-15 07:09:44.670 [SYN:ERRO] No PPS pulse for ~-53 secs
2021-06-15 07:09:44.706 [GPS:XDEB] GPS: $GLGSV,3,1,09,68,18,072,22,69,20,125,,73,60,210,10,74,48,309,18*6B
2021-06-15 07:09:44.739 [GPS:XDEB] GPS: $GLGSV,3,2,09,75,01,334,,80,18,171,,83,18,034,,84,41,329,*68
2021-06-15 07:09:44.822 [GPS:XDEB] GPS: $GLGSV,3,3,09,85,14,270,*51
2021-06-15 07:09:44.872 [GPS:XDEB] GPS: $GNGLL,2232.17140,N,07255.61330,E,070943.00,A,A*7E
2021-06-15 07:09:44.922 [GPS:DEBU] UBX cksum=C473 vs found=C473
2021-06-15 07:09:44.922 [GPS:DEBU] NAV-TIMEGPS tow(ms)=198602000.476126 week=7 leapsecs=7 status=0 tacc=118622322
2021-06-15 07:09:46.771 [SYN:CRIT] pps_xtime=24206852643334708,pps_xticks=13735155604499966516
2021-06-15 07:09:46.771 [SYN:ERRO] No PPS pulse for ~-51 secs
2021-06-15 07:09:48.873 [SYN:ERRO] No PPS pulse for ~-49 secs
2021-06-15 07:09:49.534 [SYN:DEBU] Timesync #4182 sent to server
2021-06-15 07:09:49.536 [AIO:XDEB] [4|WS] < {"msgtype":"timesync","txtime":7725020143,"gpstime":1307776203196468}
2021-06-15 07:09:49.536 [SYN:VERB] Timesync LNS: tx/rx:0x1CC6B092B..0x1CC6B139A (2ms671us) us/gps:0x0/0x4A56A60098834 (pps offset=486084) - 0 solutions
2021-06-15 07:09:49.605 [AIO:XDEB] [4|WS] > {"msgtype":"timesync","txtime":7725091456}
2021-06-15 07:09:49.605 [SYN:DEBU] Timesync #4183 sent to server
2021-06-15 07:09:49.607 [AIO:XDEB] [4|WS] < {"msgtype":"timesync","txtime":7725091456,"gpstime":1307776203267646}
2021-06-15 07:09:49.607 [SYN:VERB] Timesync LNS: tx/rx:0x1CC6C1FBC..0x1CC6C2957 (2ms459us) us/gps:0x0/0x4A56A600A9E3E (pps offset=486084) - 0 solutions
2021-06-15 07:09:49.676 [AIO:XDEB] [4|WS] > {"msgtype":"timesync","txtime":7725162745}
2021-06-15 07:09:49.676 [SYN:DEBU] Timesync #4184 sent to server
2021-06-15 07:09:49.679 [AIO:XDEB] [4|WS] < {"msgtype":"timesync","txtime":7725162745,"gpstime":1307776203339034}
2021-06-15 07:09:49.679 [SYN:VERB] Timesync LNS: tx/rx:0x1CC6D3635..0x1CC6D4061 (2ms604us) us/gps:0x0/0x4A56A600BB51A (pps offset=486084) - 0 solutions
2021-06-15 07:09:49.706 [GPS:XDEB] GPS: $GLGSV,3,1,09,68,18,072,23,69,20,125,,73,59,209,10,74,48,308,18*69
2021-06-15 07:09:49.739 [GPS:XDEB] GPS: $GLGSV,3,2,09,75,02,334,,80,18,171,,83,18,034,,84,41,329,*6B
2021-06-15 07:09:49.748 [AIO:XDEB] [4|WS] > {"msgtype":"timesync","txtime":7725234050}
2021-06-15 07:09:49.748 [SYN:DEBU] Timesync #4185 sent to server
2021-06-15 07:09:49.751 [AIO:XDEB] [4|WS] < {"msgtype":"timesync","txtime":7725234050,"gpstime":1307776203411003}
2021-06-15 07:09:49.751 [SYN:VERB] Timesync LNS: tx/rx:0x1CC6E4CBE..0x1CC6E598F (3ms281us) us/gps:0x0/0x4A56A600CCE3B (pps offset=486084) - 0 solutions
2021-06-15 07:09:49.819 [AIO:XDEB] [4|WS] > {"msgtype":"timesync","txtime":7725305392}
2021-06-15 07:09:49.819 [SYN:DEBU] Timesync #4186 sent to server
2021-06-15 07:09:49.823 [GPS:XDEB] GPS: $GLGSV,3,3,09,85,14,270,*51
2021-06-15 07:09:49.873 [GPS:XDEB] GPS: $GNGLL,2232.17192,N,07255.61376,E,070948.00,A,A*78
2021-06-15 07:09:49.890 [AIO:XDEB] [4|WS] > {"msgtype":"timesync","txtime":7725376685}
2021-06-15 07:09:49.890 [SYN:DEBU] Timesync #4187 sent to server
^C2021-06-15 07:09:49.926 [any:XDEB] RX mod=LORA f=865062500 bw=-864529059 sz=28 dr=12 4012A2BB010078000202D9D16DC6E44A6A81DD4E86A634ADE4962E30
2021-06-15 07:09:49.927 [S2E:VERB] RX 865.0625MHz DR0 SF12/BW125 snr=-9.8 rssi=-131 xtime=0x560000BD22B1A8 - updf mhdr=40 DevAddr=01BBA212 FCtrl=00 FCnt=120 FOpts=[] 0202D9D1..34AD mic=808359652 (28 bytes)
2021-06-15 07:09:49.927 [AIO:XDEB] [4|WS] > {"msgtype":"updf","MHdr":64,"DevAddr":29073938,"FCtrl":0,"FCnt":120,"FOpts":"","FPort":2,"FRMPayload":"02D9D16DC6E44A6A81DD4E86A634AD","MIC":808359652,"RefTime":0.000000,"DR":0,"Freq":865062500,"upinfo":{"rctx":0,"xtime":24206851170283944,"gpstime":-49091190,"fts":-1,"rssi":-131,"snr":-9.75,"rxtime":1623740989.927471}}
2021-06-15 07:09:49.927 [GPS:DEBU] UBX cksum=06CE vs found=06CE
2021-06-15 07:09:49.927 [GPS:DEBU] NAV-TIMEGPS tow(ms)=198607000.-475342 week=65528 leapsecs=248 status=255 tacc=118622322
2021-06-15 07:09:49.961 [AIO:XDEB] [4|WS] > {"msgtype":"timesync","txtime":7725447965}
2021-06-15 07:09:49.962 [SYN:DEBU] Timesync #4188 sent to server

Which feature of the sx1302_hal 2.1.0 are you looking for?

We are looking for the fine time stamp functionality and time sync with LNS.

We have ran the packet forwarder for the SX1303 concentrator and raspberry pi as host and we have not found any issue related to time sync or any other.

we have also ran the basic station with SX1301 concentrator board with raspberry pi as a host and we have observed same time sync issue. Please find below logs

2021-06-16 09:13:28.630 [S2E:VERB]   Dev/test settings: nocca=0 nodc=0 nodwell=0
2021-06-16 09:13:32.833 [SYN:INFO] First PPS pulse acquired
2021-06-16 09:13:32.833 [SYN:INFO] Obtained initial PPS offset (316569) - starting timesync with LNS
2021-06-16 09:13:32.828 [SYN:INFO] Time sync: ustime=0x1C613A98F utc=0x5C4DE813149B6 gpsOffset=0x0 ppsOffset=316569 syncQual=67
2021-06-16 09:13:32.828 [SYN:INFO] Time sync: MCU/SX130X#0 ustime=0x1C613A83E xtime=0x300000064ABFB pps_xtime=0x3000000580A96
2021-06-16 09:13:32.828 [SYN:INFO] Time sync: Last PPS     ustime=0x1C613A83E xtime=0x300000064ABFB pps_ustime=0x1C60706D9 pps_xtime=0x3000000580A96
2021-06-16 09:13:32.828 [SYN:DEBU] Timesync #2 sent to server
2021-06-16 09:13:32.830 [SYN:VERB] Timesync LNS: tx/rx:0x1C60ED5B4..0x1C60EDFA8 (2ms548us) us/gps:0x0/0x4A5803844613A (pps offset=316569) - 0 solutions
2021-06-16 09:13:32.899 [SYN:DEBU] Timesync #3 sent to server
2021-06-16 09:13:32.907 [SYN:VERB] Timesync LNS: tx/rx:0x1C60FEBE9..0x1C6100CBC (8ms403us) us/gps:0x0/0x4A58038458E3C (pps offset=316569) - 0 solutions
2021-06-16 09:13:32.970 [SYN:DEBU] Timesync #4 sent to server
2021-06-16 09:13:32.978 [SYN:VERB] Timesync LNS: tx/rx:0x1C6110217..0x1C61121D7 (8ms128us) us/gps:0x0/0x4A58038469966 (pps offset=316569) - 0 solutions
2021-06-16 09:13:33.041 [SYN:DEBU] Timesync #5 sent to server
2021-06-16 09:13:33.052 [SYN:VERB] Timesync LNS: tx/rx:0x1C6121844..0x1C6124099 (10ms325us) us/gps:0x0/0x4A5803847B349 (pps offset=316569) - 0 solutions
2021-06-16 09:13:33.113 [SYN:DEBU] Timesync #6 sent to server
2021-06-16 09:13:33.121 [SYN:VERB] Timesync LNS: tx/rx:0x1C6132EDF..0x1C6134DDF (7ms936us) us/gps:0x0/0x4A5803848C419 (pps offset=316569) - 0 solutions
2021-06-16 09:13:33.184 [SYN:DEBU] Timesync #7 sent to server
2021-06-16 09:13:33.194 [SYN:VERB] Timesync LNS: tx/rx:0x1C614459B..0x1C6146DF7 (10ms332us) us/gps:0x0/0x4A5803849DE14 (pps offset=316569) - 0 solutions
2021-06-16 09:13:33.256 [SYN:DEBU] Timesync #8 sent to server
2021-06-16 09:13:33.258 [SYN:VERB] Timesync LNS: tx/rx:0x1C6155BCE..0x1C61566F6 (2ms856us) us/gps:0x0/0x4A580384AE8CA (pps offset=316569) - 0 solutions
2021-06-16 09:13:33.327 [SYN:DEBU] Timesync #9 sent to server
2021-06-16 09:13:33.330 [SYN:VERB] Timesync LNS: tx/rx:0x1C616731F..0x1C6167DAC (2ms701us) us/gps:0x0/0x4A580384BFFB4 (pps offset=316569) - 0 solutions
2021-06-16 09:13:33.398 [SYN:DEBU] Timesync #10 sent to server
2021-06-16 09:13:33.404 [SYN:VERB] Timesync LNS: tx/rx:0x1C6178A12..0x1C617A21D (6ms155us) us/gps:0x0/0x4A580384D1C60 (pps offset=316569) - 0 solutions
2021-06-16 09:13:33.470 [SYN:DEBU] Timesync #11 sent to server
2021-06-16 09:13:33.474 [SYN:VERB] Timesync LNS: tx/rx:0x1C618A042..0x1C618B0E6 (4ms260us) us/gps:0x0/0x4A580384E2D26 (pps offset=316569) - 0 solutions
2021-06-16 09:13:38.470 [SYN:DEBU] Timesync #12 sent to server
2021-06-16 09:13:38.474 [SYN:VERB] Timesync LNS: tx/rx:0x1C664ECEB..0x1C664FC92 (4ms7us) us/gps:0x0/0x4A580389A79BF (pps offset=316569) - 0 solutions
2021-06-16 09:13:38.541 [SYN:DEBU] Timesync #13 sent to server
2021-06-16 09:13:38.547 [SYN:VERB] Timesync LNS: tx/rx:0x1C666032A..0x1C6661951 (5ms671us) us/gps:0x0/0x4A580389B909B (pps offset=316569) - 0 solutions
2021-06-16 09:13:38.612 [SYN:DEBU] Timesync #14 sent to server
2021-06-16 09:13:38.621 [SYN:VERB] Timesync LNS: tx/rx:0x1C6671952..0x1C6673BBC (8ms810us) us/gps:0x0/0x4A580389CB59F (pps offset=316569) - 0 solutions
2021-06-16 09:13:38.684 [SYN:DEBU] Timesync #15 sent to server
2021-06-16 09:13:38.692 [SYN:VERB] Timesync LNS: tx/rx:0x1C6682F76..0x1C6685106 (8ms592us) us/gps:0x0/0x4A580389DC605 (pps offset=316569) - 0 solutions
2021-06-16 09:13:38.755 [SYN:DEBU] Timesync #16 sent to server
2021-06-16 09:13:38.763 [SYN:VERB] Timesync LNS: tx/rx:0x1C66945E1..0x1C6696564 (8ms67us) us/gps:0x0/0x4A580389EDEBD (pps offset=316569) - 0 solutions
2021-06-16 09:13:38.826 [SYN:DEBU] Timesync #17 sent to server
2021-06-16 09:13:38.837 [SYN:VERB] Timesync LNS: tx/rx:0x1C66A5C29..0x1C66A88C7 (11ms422us) 
.
.
.
2021-06-16 09:14:01.648 [SYN:VERB] Timesync LNS: tx/rx:0x1C7BE5A82..0x1C7C698C4 (540ms226us) us/gps:0x0/0x4A58039FC0235 (pps offset=316569) - 0 solutions
2021-06-16 09:14:01.648 [SYN:VERB] Timesync LNS: tx/rx:0x1C7BF70A0..0x1C7C69985 (469ms221us) us/gps:0x0/0x4A58039FC02FE (pps offset=316569) - 0 solutions
2021-06-16 09:14:01.648 [SYN:VERB] Timesync LNS: tx/rx:0x1C7C0871F..0x1C7C699FE (398ms47us) us/gps:0x0/0x4A58039FC0343 (pps offset=316569) - 0 solutions
2021-06-16 09:14:01.657 [SYN:VERB] Timesync LNS: tx/rx:0x1C7C19DE7..0x1C7C6BADD (335ms94us) us/gps:0x0/0x4A58039FC1FBE (pps offset=316569) - 0 solutions
2021-06-16 09:14:01.657 [SYN:VERB] Timesync LNS: tx/rx:0x1C7C2B4BB..0x1C7C6BB97 (263ms900us) us/gps:0x0/0x4A58039FC203D (pps offset=316569) - 0 solutions
2021-06-16 09:14:01.657 [SYN:VERB] Timesync LNS: tx/rx:0x1C7C3CB94..0x1C7C6BC0E (192ms634us) us/gps:0x0/0x4A58039FC20C5 (pps offset=316569) - 0 solutions
2021-06-16 09:14:01.657 [SYN:VERB] Timesync LNS: tx/rx:0x1C7C4E2AD..0x1C7C6BC82 (121ms301us) us/gps:0x0/0x4A58039FC2105 (pps offset=316569) - 0 solutions
2021-06-16 09:14:01.657 [SYN:VERB] Timesync LNS: tx/rx:0x1C7C5F939..0x1C7C6BCF6 (50ms109us) us/gps:0x0/0x4A58039FC2139 (pps offset=316569) - 0 solutions
2021-06-16 09:14:01.679 [SYN:DEBU] Timesync #61 sent to server
2021-06-16 09:14:01.683 [S2E:VERB] RX 865.985MHz DR5 SF7/BW125 snr=8.0 rssi=-105 xtime=0x30000021CB5D3 - updf mhdr=40 DevAddr=018BA6DA FCtrl=00 FCnt=116 FOpts=[] 027A3191..98AF mic=1032852566 (34 bytes)
2021-06-16 09:14:01.685 [SYN:VERB] Timesync LNS: tx/rx:0x1C7C70FA5..0x1C7C72833 (6ms286us) us/gps:0x0/0x4A58039FCA1D4 (pps offset=316569) - 0 solutions
2021-06-16 09:14:06.679 [SYN:DEBU] Timesync #62 sent to server
2021-06-16 09:14:06.682 [SYN:VERB] Timesync LNS: tx/rx:0x1C8135BC7..0x1C81366B9 (2ms802us) us/gps:0x0/0x4A5803A48E697 (pps offset=316569) - 0 solutions
2021-06-16 09:14:06.750 [SYN:DEBU] Timesync #63 sent to server
2021-06-16 09:14:06.752 [SYN:VERB] Timesync LNS: tx/rx:0x1C8147200..0x1C8147BA8 (2ms472us) us/gps:0x0/0x4A5803A49FC7C (pps offset=316569) - 0 solutions
2021-06-16 09:14:06.821 [SYN:DEBU] Timesync #64 sent to server
2021-06-16 09:14:06.827 [SYN:VERB] Timesync LNS: tx/rx:0x1C815888B..0x1C8159F89 (5ms886us) us/gps:0x0/0x4A5803A4B1B01 (pps offset=316569) - 0 solutions
2021-06-16 09:14:06.893 [SYN:DEBU] Timesync #65 sent to server
2021-06-16 09:14:06.896 [SYN:VERB] Timesync LNS: tx/rx:0x1C8169EE8..0x1C816ABE1 (3ms321us) us/gps:0x0/0x4A5803A4C2934 (pps offset=316569) - 0 solutions
2021-06-16 09:14:06.964 [SYN:DEBU] Timesync #66 sent to server
2021-06-16 09:14:06.973 [SYN:VERB] Timesync LNS: tx/rx:0x1C817B5AC..0x1C817DA40 (9ms364us) us/gps:0x0/0x4A5803A4D55AB (pps offset=316569) - 0 solutions
2021-06-16 09:14:07.035 [SYN:DEBU] Timesync #67 sent to server
2021-06-16 09:14:07.048 [SYN:VERB] Timesync LNS: tx/rx:0x1C818CC06..0x1C818FDC7 (12ms737us) us/gps:0x0/0x4A5803A4E78EE (pps offset=316569) - 0 solutions
:
:
:
:
2021-06-16 09:14:12.975 [SYN:VERB] Timesync LNS: tx/rx:0x1C8733A04..0x1C8736F4B (13ms639us) us/gps:0x0/0x4A5803AA8EAFE (pps offset=316569) - 0 solutions
2021-06-16 09:14:16.400 [SYN:INFO] MCU/SX130X drift stats: min: +0.0ppm  q50: -0.6ppm  q80: +1.1ppm  max: -7.3ppm - threshold q90: +1.4ppm
2021-06-16 09:14:16.400 [SYN:INFO] Mean MCU drift vs SX130X#0: 0.0ppm
2021-06-16 09:14:17.962 [SYN:DEBU] Timesync #82 sent to server
2021-06-16 09:14:17.966 [SYN:VERB] Timesync LNS: tx/rx:0x1C8BF861C..0x1C8BF9850 (4ms660us) us/gps:0x0/0x4A5803AF5107A (pps offset=316569) - 0 solutions
2021-06-16 09:14:18.033 [SYN:DEBU] Timesync #83 sent to server
2021-06-16 09:14:18.041 [SYN:VERB] Timesync LNS: tx/rx:0x1C8C09C4A..0x1C8C0BC0A (8ms128us) us/gps:0x0/0x4A5803AF63B10 (pps offset=316569) - 0 solutions
2021-06-16 09:14:18.104 [SYN:DEBU] Timesync #84 sent to server
2021-06-16 09:14:18.114 [SYN:VERB] Timesync LNS: tx/rx:0x1C8C1B32F..0x1C8C1D966 (9ms783us) us/gps:0x0/0x4A5803AF7459E (pps offset=316569) - 0 solutions
2021-06-16 09:14:18.176 [SYN:DEBU] Timesync #85 sent to server
2021-06-16 09:14:18.181 [SYN:VERB] Timesync LNS: tx/rx:0x1C8C2C97C..0x1C8C2DDDD (5ms217us) us/gps:0x0/0x4A5803AF85834 (pps offset=316569) - 0 solutions
2021-06-16 09:14:18.247 [SYN:DEBU] Timesync #86 sent to server
2021-06-16 09:14:18.251 [SYN:VERB] Timesync LNS: tx/rx:0x1C8C3E023..0x1C8C3F1B1 (4ms494us) us/gps:0x0/0x4A5803AF96B04 (pps offset=316569) - 0 solutions
2021-06-16 09:14:18.318 [SYN:DEBU] Timesync #87 sent to server
2021-06-16 09:14:18.323 [SYN:VERB] Timesync LNS: tx/rx:0x1C8C4F68E..0x1C8C50A7E (5ms104us) us/gps:0x0/0x4A5803AFA8140 (pps offset=316569) - 0 solutions
2021-06-16 09:14:18.389 [SYN:DEBU] Timesync #88 sent to server
2021-06-16 09:14:18.395 [SYN:VERB] Timesync LNS: tx/rx:0x1C8C60CB9..0x1C8C621F9 (5ms440us) us/gps:0x0/0x4A5803AFB9ED7 (pps offset=316569) - 0 solutions
2021-06-16 0
:
:
:
:
2021-06-16 09:14:41.181 [SYN:VERB] Timesync LNS: tx/rx:0x1CA21A818..0x1CA21D1C8 (10ms672us) us/gps:0x0/0x4A5803C574DDD (pps offset=316569) - 0 solutions
2021-06-16 09:14:41.291 [S2E:VERB] RX 865.985MHz DR0 SF12/BW125 snr=10.0 rssi=-88 xtime=0x300000478E54C - updf mhdr=40 DevAddr=0082967E FCtrl=00 FCnt=4 FOpts=[] 02A1EF18..D435 mic=-1834787077 (48 bytes)
2021-06-16 09:14:45.600 [SYN:VERB] Time sync rejected: quality=145 threshold=100
2021-06-16 09:14:46.170 [SYN:DEBU] Timesync #132 sent to server
2021-06-16 09:14:46.173 [SYN:VERB] Timesync LNS: tx/rx:0x1CA6DF427..0x1CA6E001E (3ms63us) us/gps:0x0/0x4A5803CA37DC4 (pps offset=316569) - 0 solutions
2021-06-16 09:14:46.242 [SYN:DEBU] Timesync #133 sent to server
2021-06-16 09:14:46.245 [SYN:VERB] Timesync LNS: tx/rx:0x1CA6F0B46..0x1CA6F18F9 (3ms507us) us/gps:0x0/0x4A5803CA4944F (pps offset=316569) - 0 solutions
2021-06-16 09:14:46.313 [SYN:DEBU] Timesync #134 sent to server
2021-06-16 09:14:46.317 [SYN:VERB] Timesync LNS: tx/rx:0x1CA7021BF..0x1CA703046 (3ms719us) us/gps:0x0/0x4A5803CA5AC96 (pps offset=316569) - 0 solutions
2021-06-16 09:14:49.802 [SYN:ERRO] Repeated excessive clock drifts between MCU/SX130X#0 (3 retries): 2.2ppm (threshold 2.0ppm)
2021-06-16 09:14:50.853 [SYN:VERB] Time sync rejected: quality=114 threshold=100
2021-06-16 09:14:51.812 [SYN:DEBU] Timesync #142 sent to server
2021-06-16 09:14:51.815 [SYN:VERB] Timesync LNS: tx/rx:0x1CAC40AE1..0x1CAC41624 (2ms883us) us/gps:0x0/0x4A5803CF994E1 (pps offset=316569) - 0 solutions
2021-06-16 09:14:51.884 [SYN:DEBU] Timesync #143 sent to server
2021-06-16 09:14:51.886 [SYN:VERB] Timesync LNS: tx/rx:0x1CAC52158..0x1CAC52C48 (2ms800us) us/gps:0x0/0x4A5803CFAAB2E (pps offset=316569) - 0 solutions
2021-06-16 09:14:51.955 [SYN:DEBU] Timesync #144 sent to server
2021-06-16 09:14:51.959 [SYN:VERB] Timesync LNS: tx/rx:0x1CAC637EC..0x1CAC6482F (4ms163us) us/gps:0x0/0x4A5803CFBC3E8 (pps offset=316569) - 0 solutions
2021-06-16 09:14:52.026 [SYN:DEBU] Timesync #145 sent to server
2021-06-16 09:14:52.954 [SYN:ERRO] No PPS pulse for ~11 secs

We have run this setup for more than 2hours

AbhishekLakhara0209 commented 3 years ago

Hi @beitler,

Any update on this?

beitler commented 2 years ago

Hi @AbhishekLakhara0209 ,

the logs indicate that there is something wrong with your setup.

For example:

2021-06-16 09:14:51.959 [SYN:VERB] Timesync LNS: tx/rx:0x1CAC637EC..0x1CAC6482F (4ms163us) us/gps:0x0/0x4A5803CFBC3E8 (pps offset=316569) - 0 solutions

Which translates into:

txtime (PPS-aligned) :          7696s 955372us
rxtime (PPS-aligned) :          7696s 959535us
gpstime (from server):    1307870104s 372200us
us diff:                             -585253us

This shows that the sub-second offset between the local PPS and the server's GPS time is off by more than half a second. Hence, either the gateway's PPS is off or the server's GPStime is not synchronized. The consequence is that station is unable to infer the GPS time associated to the last observed PPS due to the misalignment between the locally observed PPS and the server's reported GPS time.

2021-06-16 09:14:52.954 [SYN:ERRO] No PPS pulse for ~11 secs

This indicates that the PPS on your gateway is unstable. Make sure you have good skyview. PPS should be stable for reliable gateway operation.

In summary, please review your setup: make sure that the server is synchronized with millisecond precision (NTP should suffice) and make sure your gateway's GPS antenna has good view of the sky.

AbhishekLakhara0209 commented 2 years ago

@beitler, Thanks for the update. I have gone through the code of timesync related functionality, we have observed that pps_xtick is changing when we enable below condition. file name : ral_lgw.c 

int ral_getTimesync (u1_t pps_en, sL_t last_xtime, timesync_t timesync){
.
.
.
#if defined(CFG_sx1302)
        sx1302_gps_enable(false); // Observed mis-behaviour when we enable this conditions.
#else
        lgw_reg_w(LGW_GPS_EN, 0);       // PPS latch holds current
#endif
.
.
.
#if defined(CFG_sx1302)
        sx1302_gps_enable(true); // Observed mis-behaviour when we enable this conditions.
#else
        lgw_reg_w(LGW_GPS_EN, 1);
#endif

}

what is the meaning of this condition?

Why we are enabling/disabling the GPS?

Please find below logs of issue:

value of stats->mcu_drifts[19] : (4)
value of drift_ppm(4),stats->drift_thres(139) 
2021-07-16 07:12:52.711 [SYN:INFO] pps_xticks : (201150634) **//pps_xticks and xtick has no major difference.**
2021-07-16 07:12:52.711 [SYN:INFO] xticks     : (201861763)
2021-07-16 07:12:52.711 [SYN:INFO] timesync->xtime     : (34339947360561795)
2021-07-16 07:12:52.711 [SYN:INFO] timesync->ustime    : (7787483238)
2021-07-16 07:12:52.711 [SYN:INFO] timesync->pps_xtime : (34339947359850666)
2021-07-16 07:12:52.711 [SYN:INFO] t0                  : (7787483091)
2021-07-16 07:12:52.711 [SYN:INFO] t1                  : (7787483386)
2021-07-16 07:12:52.711 [SYN:INFO] (t1-t0)             : (295)
2021-07-16 07:12:52.716 [SYN:INFO] MCU/SX130X drift stats: min: -0.3ppm  q50: -5.0ppm  q80: +11.3ppm  max: -16.1ppm - threshold q90: +13.9ppm
2021-07-16 07:12:52.716 [SYN:INFO] Mean MCU drift vs SX130X#0: 0.4ppm
value of syncQual[26] : (296)
value of quality (296), syncQual_thres (296)
value of stats->mcu_drifts[0] : (6)
value of drift_ppm(6),stats->drift_thres(139) 
xtime and pps_xtime diff is hige, (7995392) 
2021-07-16 07:12:54.406 [SYN:INFO] pps_xticks : (68932906) **//pps_xticks value changes suddenly.**
2021-07-16 07:12:54.406 [SYN:INFO] xticks     : (203557116)
2021-07-16 07:12:54.406 [SYN:INFO] timesync->xtime     : (34339947362257148)
2021-07-16 07:12:54.406 [SYN:INFO] timesync->ustime    : (7789178592)
2021-07-16 07:12:54.406 [SYN:INFO] timesync->pps_xtime : (34339947227632938)
2021-07-16 07:12:54.407 [SYN:INFO] t0                  : (7789178444)
2021-07-16 07:12:54.407 [SYN:INFO] t1                  : (7789178740)
2021-07-16 07:12:54.407 [SYN:INFO] (t1-t0)             : (296)
value of syncQual[27] : (223)

If we commented the condition of enable/disable gps from ral_getTimesync API then we have not observed this kind of issue.

Note: GPS was locked at that moment.

beitler commented 2 years ago

Please pull the latest release 2.0.6 which improved the handling of the timestamp for the sx1302_hal. This should resolve the issues you described.