2019-10-24T17:55:36.529Z,1571939736.529 [CommandLine](IMPORTANT): got command restart logs 2019-10-24T17:59:51.042Z,1571939991.042 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-10-24T17:59:51.042Z,1571939991.042 [Default:CheckIn:C.Wait] Stopped 2019-10-24T17:59:51.042Z,1571939991.042 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-10-24T17:59:51.043Z,1571939991.043 [Default:CheckIn:D] Running Loop=1 2019-10-24T17:59:51.438Z,1571939991.438 [Default:CheckIn:D] Stopped 2019-10-24T17:59:51.438Z,1571939991.438 [Default:CheckIn:E] Running Loop=1 2019-10-24T17:59:51.818Z,1571939991.818 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 24.515279 min 2019-10-24T17:59:51.818Z,1571939991.818 [Default:CheckIn:E] Stopped 2019-10-24T17:59:51.818Z,1571939991.818 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-10-24T17:59:51.818Z,1571939991.818 [Default:CheckIn] Stopped 2019-10-24T17:59:51.818Z,1571939991.818 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-10-24T17:59:51.818Z,1571939991.818 [Default:CheckIn](INFO): Running loop #5 2019-10-24T17:59:51.818Z,1571939991.818 [Default:CheckIn] Running Loop=5 2019-10-24T17:59:51.818Z,1571939991.818 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-10-24T17:59:51.818Z,1571939991.818 [Default:CheckIn:Read_GPS] Running Loop=1 2019-10-24T17:59:53.814Z,1571939993.814 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175826.00,A,3647.81173,N,12149.40996,W,27.933,85.96,241019,,,D*70 2019-10-24T17:59:53.816Z,1571939993.816 [NAL9602](INFO): GPS fix at 20191024T175826: (36.796862, -121.823499) 2019-10-24T17:59:53.871Z,1571939993.871 [Default:CheckIn:Read_GPS] Stopped 2019-10-24T17:59:53.871Z,1571939993.871 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-10-24T18:00:01.852Z,1571940001.852 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20191024T165414/Courier0018.lzma 2019-10-24T18:00:03.858Z,1571940003.858 [DataOverHttps](INFO): Moved sent file to Logs/20191024T165414/Courier0018.lzma.bak 2019-10-24T18:00:03.858Z,1571940003.858 [DataOverHttps](INFO): SBD MOMSN=11951368 2019-10-24T18:00:17.651Z,1571940017.651 [NAL9602](INFO): SBD MO Status=0, MOMSN=17397, MT Status=0, MTMSN=0 2019-10-24T18:00:17.651Z,1571940017.651 [NAL9602](INFO): No messages in MT queue 2019-10-24T18:00:20.876Z,1571940020.876 [DataOverHttps](INFO): Sending 213 bytes from file Logs/20191024T175536/Courier0000.lzma 2019-10-24T18:00:22.882Z,1571940022.882 [DataOverHttps](INFO): Moved sent file to Logs/20191024T175536/Courier0000.lzma.bak 2019-10-24T18:00:22.882Z,1571940022.882 [DataOverHttps](INFO): SBD MOMSN=11951370 2019-10-24T18:00:39.964Z,1571940039.964 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20191024T175536/Courier0003.lzma 2019-10-24T18:00:41.970Z,1571940041.970 [DataOverHttps](INFO): Moved sent file to Logs/20191024T175536/Courier0003.lzma.bak 2019-10-24T18:00:41.970Z,1571940041.970 [DataOverHttps](INFO): SBD MOMSN=11951374 2019-10-24T18:00:48.354Z,1571940048.354 [NAL9602](INFO): Not Powering down - fast GPS 2019-10-24T18:00:58.948Z,1571940058.948 [DataOverHttps](INFO): Sending 96 bytes from file Logs/20191024T165414/Express0019.lzma 2019-10-24T18:01:00.954Z,1571940060.954 [DataOverHttps](INFO): Moved sent file to Logs/20191024T165414/Express0019.lzma.bak 2019-10-24T18:01:00.954Z,1571940060.954 [DataOverHttps](INFO): SBD MOMSN=11951376 2019-10-24T18:01:18.193Z,1571940078.193 [DataOverHttps](INFO): Sending 344 bytes from file Logs/20191024T175536/Express0001.lzma 2019-10-24T18:01:20.198Z,1571940080.198 [DataOverHttps](INFO): Moved sent file to Logs/20191024T175536/Express0001.lzma.bak 2019-10-24T18:01:20.198Z,1571940080.198 [DataOverHttps](INFO): SBD MOMSN=11951379 2019-10-24T18:01:37.216Z,1571940097.216 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20191024T175536/Express0004.lzma 2019-10-24T18:01:39.826Z,1571940099.826 [DataOverHttps](INFO): Moved sent file to Logs/20191024T175536/Express0004.lzma.bak 2019-10-24T18:01:39.827Z,1571940099.827 [DataOverHttps](INFO): SBD MOMSN=11951383 2019-10-24T18:01:40.905Z,1571940100.905 [Default:CheckIn:Read_Iridium] Stopped 2019-10-24T18:01:40.906Z,1571940100.906 [Default:CheckIn:C.Wait] Running Loop=1 2019-10-24T18:01:40.906Z,1571940100.906 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-10-24T18:06:41.523Z,1571940401.523 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-10-24T18:06:41.523Z,1571940401.523 [Default:CheckIn:C.Wait] Stopped 2019-10-24T18:06:41.523Z,1571940401.523 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-10-24T18:06:41.524Z,1571940401.524 [Default:CheckIn:D] Running Loop=1 2019-10-24T18:06:41.927Z,1571940401.927 [Default:CheckIn:D] Stopped 2019-10-24T18:06:41.927Z,1571940401.927 [Default:CheckIn:E] Running Loop=1 2019-10-24T18:06:42.336Z,1571940402.336 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 31.356755 min 2019-10-24T18:06:42.336Z,1571940402.336 [Default:CheckIn:E] Stopped 2019-10-24T18:06:42.336Z,1571940402.336 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-10-24T18:06:42.336Z,1571940402.336 [Default:CheckIn] Stopped 2019-10-24T18:06:42.336Z,1571940402.336 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-10-24T18:06:42.336Z,1571940402.336 [Default:CheckIn](INFO): Running loop #6 2019-10-24T18:06:42.336Z,1571940402.336 [Default:CheckIn] Running Loop=6 2019-10-24T18:06:42.336Z,1571940402.336 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-10-24T18:06:42.337Z,1571940402.337 [Default:CheckIn:Read_GPS] Running Loop=1 2019-10-24T18:06:44.336Z,1571940404.336 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180516.00,A,3648.50524,N,12147.14712,W,5.929,95.33,241019,,,D*49 2019-10-24T18:06:44.338Z,1571940404.338 [NAL9602](INFO): GPS fix at 20191024T180516: (36.808421, -121.785785) 2019-10-24T18:06:44.363Z,1571940404.363 [Default:CheckIn:Read_GPS] Stopped 2019-10-24T18:06:44.363Z,1571940404.363 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-10-24T18:06:51.416Z,1571940411.416 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20191024T175536/Courier0006.lzma 2019-10-24T18:06:53.422Z,1571940413.422 [DataOverHttps](INFO): Moved sent file to Logs/20191024T175536/Courier0006.lzma.bak 2019-10-24T18:06:53.423Z,1571940413.423 [DataOverHttps](INFO): SBD MOMSN=11951386 2019-10-24T18:07:10.488Z,1571940430.488 [DataOverHttps](INFO): Sending 137 bytes from file Logs/20191024T175536/Express0007.lzma 2019-10-24T18:07:11.459Z,1571940431.459 [NAL9602](INFO): SBD MO Status=2, MOMSN=17398, MT Status=2, MTMSN=0 2019-10-24T18:07:11.460Z,1571940431.460 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-10-24T18:07:12.494Z,1571940432.494 [DataOverHttps](INFO): Moved sent file to Logs/20191024T175536/Express0007.lzma.bak 2019-10-24T18:07:12.494Z,1571940432.494 [DataOverHttps](INFO): SBD MOMSN=11951389 2019-10-24T18:07:14.305Z,1571940434.305 [Default:CheckIn:Read_Iridium] Stopped 2019-10-24T18:07:14.306Z,1571940434.306 [Default:CheckIn:C.Wait] Running Loop=1 2019-10-24T18:07:14.306Z,1571940434.306 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-10-24T18:07:28.023Z,1571940448.023 [NAL9602](INFO): SBD MO Status=0, MOMSN=17398, MT Status=0, MTMSN=0 2019-10-24T18:07:28.023Z,1571940448.023 [NAL9602](INFO): No messages in MT queue 2019-10-24T18:07:58.758Z,1571940478.758 [NAL9602](INFO): Not Powering down - fast GPS 2019-10-24T18:12:14.968Z,1571940734.968 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-10-24T18:12:14.968Z,1571940734.968 [Default:CheckIn:C.Wait] Stopped 2019-10-24T18:12:14.968Z,1571940734.968 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-10-24T18:12:14.968Z,1571940734.968 [Default:CheckIn:D] Running Loop=1 2019-10-24T18:12:15.359Z,1571940735.359 [Default:CheckIn:D] Stopped 2019-10-24T18:12:15.359Z,1571940735.359 [Default:CheckIn:E] Running Loop=1 2019-10-24T18:12:15.774Z,1571940735.774 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 36.913957 min 2019-10-24T18:12:15.774Z,1571940735.774 [Default:CheckIn:E] Stopped 2019-10-24T18:12:15.774Z,1571940735.774 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-10-24T18:12:15.774Z,1571940735.774 [Default:CheckIn] Stopped 2019-10-24T18:12:15.774Z,1571940735.774 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-10-24T18:12:15.774Z,1571940735.774 [Default:CheckIn](INFO): Running loop #7 2019-10-24T18:12:15.774Z,1571940735.774 [Default:CheckIn] Running Loop=7 2019-10-24T18:12:15.774Z,1571940735.774 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-10-24T18:12:15.774Z,1571940735.774 [Default:CheckIn:Read_GPS] Running Loop=1 2019-10-24T18:12:17.774Z,1571940737.774 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181049.00,A,3648.14840,N,12147.22233,W,0.039,203.83,241019,,,A*75 2019-10-24T18:12:17.776Z,1571940737.776 [NAL9602](INFO): GPS fix at 20191024T181049: (36.802473, -121.787039) 2019-10-24T18:12:17.801Z,1571940737.801 [Default:CheckIn:Read_GPS] Stopped 2019-10-24T18:12:17.801Z,1571940737.801 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-10-24T18:12:25.652Z,1571940745.652 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20191024T175536/Courier0009.lzma 2019-10-24T18:12:27.659Z,1571940747.659 [DataOverHttps](INFO): Moved sent file to Logs/20191024T175536/Courier0009.lzma.bak 2019-10-24T18:12:27.659Z,1571940747.659 [DataOverHttps](INFO): SBD MOMSN=11951411 2019-10-24T18:12:39.583Z,1571940759.583 [NAL9602](INFO): SBD MO Status=2, MOMSN=17399, MT Status=2, MTMSN=0 2019-10-24T18:12:39.584Z,1571940759.584 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-10-24T18:12:44.596Z,1571940764.596 [DataOverHttps](INFO): Sending 136 bytes from file Logs/20191024T175536/Express0010.lzma 2019-10-24T18:12:46.603Z,1571940766.603 [DataOverHttps](INFO): Moved sent file to Logs/20191024T175536/Express0010.lzma.bak 2019-10-24T18:12:46.603Z,1571940766.603 [DataOverHttps](INFO): SBD MOMSN=11951414 2019-10-24T18:12:48.501Z,1571940768.501 [Default:CheckIn:Read_Iridium] Stopped 2019-10-24T18:12:48.501Z,1571940768.501 [Default:CheckIn:C.Wait] Running Loop=1 2019-10-24T18:12:48.501Z,1571940768.501 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-10-24T18:12:49.273Z,1571940769.273 [NAL9602](INFO): SBD MO Status=0, MOMSN=17399, MT Status=0, MTMSN=0 2019-10-24T18:12:49.273Z,1571940769.273 [NAL9602](INFO): No messages in MT queue 2019-10-24T18:13:19.978Z,1571940799.978 [NAL9602](INFO): Not Powering down - fast GPS 2019-10-24T18:17:49.092Z,1571941069.092 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-10-24T18:17:49.092Z,1571941069.092 [Default:CheckIn:C.Wait] Stopped 2019-10-24T18:17:49.092Z,1571941069.092 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-10-24T18:17:49.092Z,1571941069.092 [Default:CheckIn:D] Running Loop=1 2019-10-24T18:17:49.470Z,1571941069.470 [Default:CheckIn:D] Stopped 2019-10-24T18:17:49.470Z,1571941069.470 [Default:CheckIn:E] Running Loop=1 2019-10-24T18:17:49.890Z,1571941069.890 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 42.482467 min 2019-10-24T18:17:49.890Z,1571941069.890 [Default:CheckIn:E] Stopped 2019-10-24T18:17:49.890Z,1571941069.890 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-10-24T18:17:49.890Z,1571941069.890 [Default:CheckIn] Stopped 2019-10-24T18:17:49.890Z,1571941069.890 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-10-24T18:17:49.890Z,1571941069.890 [Default:CheckIn](INFO): Running loop #8 2019-10-24T18:17:49.890Z,1571941069.890 [Default:CheckIn] Running Loop=8 2019-10-24T18:17:49.891Z,1571941069.891 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-10-24T18:17:49.891Z,1571941069.891 [Default:CheckIn:Read_GPS] Running Loop=1 2019-10-24T18:17:51.872Z,1571941071.872 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181623.00,A,3648.14130,N,12147.22930,W,0.019,210.05,241019,,,A*77 2019-10-24T18:17:51.874Z,1571941071.874 [NAL9602](INFO): GPS fix at 20191024T181623: (36.802355, -121.787155) 2019-10-24T18:17:51.932Z,1571941071.932 [Default:CheckIn:Read_GPS] Stopped 2019-10-24T18:17:51.932Z,1571941071.932 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-10-24T18:17:59.924Z,1571941079.924 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20191024T175536/Courier0012.lzma 2019-10-24T18:18:01.930Z,1571941081.930 [DataOverHttps](INFO): Moved sent file to Logs/20191024T175536/Courier0012.lzma.bak 2019-10-24T18:18:01.931Z,1571941081.931 [DataOverHttps](INFO): SBD MOMSN=11951428 2019-10-24T18:18:05.515Z,1571941085.515 [NAL9602](INFO): SBD MO Status=0, MOMSN=17400, MT Status=0, MTMSN=0 2019-10-24T18:18:05.516Z,1571941085.516 [NAL9602](INFO): No messages in MT queue 2019-10-24T18:18:18.957Z,1571941098.957 [DataOverHttps](INFO): Sending 120 bytes from file Logs/20191024T175536/Express0013.lzma 2019-10-24T18:18:20.962Z,1571941100.962 [DataOverHttps](INFO): Moved sent file to Logs/20191024T175536/Express0013.lzma.bak 2019-10-24T18:18:20.963Z,1571941100.963 [DataOverHttps](INFO): SBD MOMSN=11951436 2019-10-24T18:18:22.925Z,1571941102.925 [Default:CheckIn:Read_Iridium] Stopped 2019-10-24T18:18:22.925Z,1571941102.925 [Default:CheckIn:C.Wait] Running Loop=1 2019-10-24T18:18:22.925Z,1571941102.925 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-10-24T18:18:36.222Z,1571941116.222 [NAL9602](INFO): Not Powering down - fast GPS 2019-10-24T18:23:23.495Z,1571941403.495 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-10-24T18:23:23.495Z,1571941403.495 [Default:CheckIn:C.Wait] Stopped 2019-10-24T18:23:23.495Z,1571941403.495 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-10-24T18:23:23.496Z,1571941403.496 [Default:CheckIn:D] Running Loop=1 2019-10-24T18:23:23.904Z,1571941403.904 [Default:CheckIn:D] Stopped 2019-10-24T18:23:23.905Z,1571941403.905 [Default:CheckIn:E] Running Loop=1 2019-10-24T18:23:24.292Z,1571941404.292 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 48.056380 min 2019-10-24T18:23:24.292Z,1571941404.292 [Default:CheckIn:E] Stopped 2019-10-24T18:23:24.292Z,1571941404.292 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-10-24T18:23:24.292Z,1571941404.292 [Default:CheckIn] Stopped 2019-10-24T18:23:24.293Z,1571941404.293 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-10-24T18:23:24.293Z,1571941404.293 [Default:CheckIn](INFO): Running loop #9 2019-10-24T18:23:24.293Z,1571941404.293 [Default:CheckIn] Running Loop=9 2019-10-24T18:23:24.293Z,1571941404.293 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-10-24T18:23:24.293Z,1571941404.293 [Default:CheckIn:Read_GPS] Running Loop=1 2019-10-24T18:23:26.300Z,1571941406.300 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182157.00,A,3648.14380,N,12147.23000,W,0.019,19.86,241019,,,D*47 2019-10-24T18:23:26.302Z,1571941406.302 [NAL9602](INFO): GPS fix at 20191024T182157: (36.802397, -121.787167) 2019-10-24T18:23:26.325Z,1571941406.325 [Default:CheckIn:Read_GPS] Stopped 2019-10-24T18:23:26.326Z,1571941406.326 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-10-24T18:23:33.708Z,1571941413.708 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20191024T175536/Courier0015.lzma 2019-10-24T18:23:35.714Z,1571941415.714 [DataOverHttps](INFO): Moved sent file to Logs/20191024T175536/Courier0015.lzma.bak 2019-10-24T18:23:35.714Z,1571941415.714 [DataOverHttps](INFO): SBD MOMSN=11951444 2019-10-24T18:23:54.244Z,1571941434.244 [DataOverHttps](INFO): Sending 121 bytes from file Logs/20191024T175536/Express0016.lzma 2019-10-24T18:23:56.250Z,1571941436.250 [DataOverHttps](INFO): Moved sent file to Logs/20191024T175536/Express0016.lzma.bak 2019-10-24T18:23:56.250Z,1571941436.250 [DataOverHttps](INFO): SBD MOMSN=11951447 2019-10-24T18:23:58.251Z,1571941438.251 [Default:CheckIn:Read_Iridium] Stopped 2019-10-24T18:23:58.251Z,1571941438.251 [Default:CheckIn:C.Wait] Running Loop=1 2019-10-24T18:23:58.251Z,1571941438.251 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-10-24T18:24:02.659Z,1571941442.659 [NAL9602](INFO): SBD MO Status=0, MOMSN=17401, MT Status=0, MTMSN=0 2019-10-24T18:24:02.659Z,1571941442.659 [NAL9602](INFO): No messages in MT queue 2019-10-24T18:24:33.362Z,1571941473.362 [NAL9602](INFO): Not Powering down - fast GPS 2019-10-24T18:28:58.833Z,1571941738.833 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-10-24T18:28:58.833Z,1571941738.833 [Default:CheckIn:C.Wait] Stopped 2019-10-24T18:28:58.833Z,1571941738.833 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-10-24T18:28:58.833Z,1571941738.833 [Default:CheckIn:D] Running Loop=1 2019-10-24T18:28:59.221Z,1571941739.221 [Default:CheckIn:D] Stopped 2019-10-24T18:28:59.221Z,1571941739.221 [Default:CheckIn:E] Running Loop=1 2019-10-24T18:28:59.629Z,1571941739.629 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 53.644999 min 2019-10-24T18:28:59.629Z,1571941739.629 [Default:CheckIn:E] Stopped 2019-10-24T18:28:59.629Z,1571941739.629 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-10-24T18:28:59.629Z,1571941739.629 [Default:CheckIn] Stopped 2019-10-24T18:28:59.629Z,1571941739.629 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-10-24T18:28:59.630Z,1571941739.630 [Default:CheckIn](INFO): Running loop #10 2019-10-24T18:28:59.630Z,1571941739.630 [Default:CheckIn] Running Loop=10 2019-10-24T18:28:59.630Z,1571941739.630 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-10-24T18:28:59.630Z,1571941739.630 [Default:CheckIn:Read_GPS] Running Loop=1 2019-10-24T18:29:01.620Z,1571941741.620 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182731.00,A,3648.14469,N,12147.22988,W,0.058,19.86,241019,,,D*4C 2019-10-24T18:29:01.622Z,1571941741.622 [NAL9602](INFO): GPS fix at 20191024T182731: (36.802411, -121.787165) 2019-10-24T18:29:01.673Z,1571941741.673 [Default:CheckIn:Read_GPS] Stopped 2019-10-24T18:29:01.673Z,1571941741.673 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-10-24T18:29:09.244Z,1571941749.244 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20191024T175536/Courier0018.lzma 2019-10-24T18:29:11.250Z,1571941751.250 [DataOverHttps](INFO): Moved sent file to Logs/20191024T175536/Courier0018.lzma.bak 2019-10-24T18:29:11.250Z,1571941751.250 [DataOverHttps](INFO): SBD MOMSN=11951509 2019-10-24T18:29:21.011Z,1571941761.011 [NAL9602](INFO): SBD MO Status=0, MOMSN=17402, MT Status=0, MTMSN=0 2019-10-24T18:29:21.011Z,1571941761.011 [NAL9602](INFO): No messages in MT queue 2019-10-24T18:29:28.264Z,1571941768.264 [DataOverHttps](INFO): Sending 120 bytes from file Logs/20191024T175536/Express0019.lzma 2019-10-24T18:29:30.270Z,1571941770.270 [DataOverHttps](INFO): Moved sent file to Logs/20191024T175536/Express0019.lzma.bak 2019-10-24T18:29:30.270Z,1571941770.270 [DataOverHttps](INFO): SBD MOMSN=11951515 2019-10-24T18:29:31.957Z,1571941771.957 [Default:CheckIn:Read_Iridium] Stopped 2019-10-24T18:29:31.957Z,1571941771.957 [Default:CheckIn:C.Wait] Running Loop=1 2019-10-24T18:29:31.957Z,1571941771.957 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-10-24T18:29:51.714Z,1571941791.714 [NAL9602](INFO): Not Powering down - fast GPS 2019-10-24T18:34:32.531Z,1571942072.531 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-10-24T18:34:32.531Z,1571942072.531 [Default:CheckIn:C.Wait] Stopped 2019-10-24T18:34:32.531Z,1571942072.531 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-10-24T18:34:32.531Z,1571942072.531 [Default:CheckIn:D] Running Loop=1 2019-10-24T18:34:32.941Z,1571942072.941 [Default:CheckIn:D] Stopped 2019-10-24T18:34:32.941Z,1571942072.941 [Default:CheckIn:E] Running Loop=1 2019-10-24T18:34:33.325Z,1571942073.325 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 59.206991 min 2019-10-24T18:34:33.326Z,1571942073.326 [Default:CheckIn:E] Stopped 2019-10-24T18:34:33.326Z,1571942073.326 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-10-24T18:34:33.326Z,1571942073.326 [Default:CheckIn] Stopped 2019-10-24T18:34:33.326Z,1571942073.326 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-10-24T18:34:33.326Z,1571942073.326 [Default:CheckIn](INFO): Running loop #11 2019-10-24T18:34:33.326Z,1571942073.326 [Default:CheckIn] Running Loop=11 2019-10-24T18:34:33.326Z,1571942073.326 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-10-24T18:34:33.326Z,1571942073.326 [Default:CheckIn:Read_GPS] Running Loop=1 2019-10-24T18:34:35.331Z,1571942075.331 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183305.00,A,3648.16912,N,12147.27842,W,0.369,205.39,241019,,,D*75 2019-10-24T18:34:35.333Z,1571942075.333 [NAL9602](INFO): GPS fix at 20191024T183305: (36.802819, -121.787974) 2019-10-24T18:34:35.357Z,1571942075.357 [Default:CheckIn:Read_GPS] Stopped 2019-10-24T18:34:35.357Z,1571942075.357 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-10-24T18:34:43.316Z,1571942083.316 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20191024T175536/Courier0021.lzma 2019-10-24T18:34:45.322Z,1571942085.322 [DataOverHttps](INFO): Moved sent file to Logs/20191024T175536/Courier0021.lzma.bak 2019-10-24T18:34:45.322Z,1571942085.322 [DataOverHttps](INFO): SBD MOMSN=11951554 2019-10-24T18:34:57.947Z,1571942097.947 [NAL9602](INFO): SBD MO Status=2, MOMSN=17403, MT Status=2, MTMSN=0 2019-10-24T18:34:57.948Z,1571942097.948 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-10-24T18:35:02.356Z,1571942102.356 [DataOverHttps](INFO): Sending 135 bytes from file Logs/20191024T175536/Express0022.lzma 2019-10-24T18:35:04.635Z,1571942104.635 [DataOverHttps](INFO): Moved sent file to Logs/20191024T175536/Express0022.lzma.bak 2019-10-24T18:35:04.635Z,1571942104.635 [DataOverHttps](INFO): SBD MOMSN=11951560 2019-10-24T18:35:06.076Z,1571942106.076 [Default:CheckIn:Read_Iridium] Stopped 2019-10-24T18:35:06.076Z,1571942106.076 [Default:CheckIn:C.Wait] Running Loop=1 2019-10-24T18:35:06.077Z,1571942106.077 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-10-24T18:35:25.028Z,1571942125.028 [NAL9602](INFO): SBD MO Status=0, MOMSN=17403, MT Status=0, MTMSN=0 2019-10-24T18:35:25.028Z,1571942125.028 [NAL9602](INFO): No messages in MT queue 2019-10-24T18:35:55.715Z,1571942155.715 [NAL9602](INFO): Not Powering down - fast GPS 2019-10-24T18:40:06.628Z,1571942406.628 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-10-24T18:40:06.628Z,1571942406.628 [Default:CheckIn:C.Wait] Stopped 2019-10-24T18:40:06.628Z,1571942406.628 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-10-24T18:40:06.628Z,1571942406.628 [Default:CheckIn:D] Running Loop=1 2019-10-24T18:40:07.046Z,1571942407.046 [Default:CheckIn:D] Stopped 2019-10-24T18:40:07.046Z,1571942407.046 [Default:CheckIn:E] Running Loop=1 2019-10-24T18:40:07.449Z,1571942407.449 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 64.775411 min 2019-10-24T18:40:07.449Z,1571942407.449 [Default:CheckIn:E] Stopped 2019-10-24T18:40:07.449Z,1571942407.449 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-10-24T18:40:07.449Z,1571942407.449 [Default:CheckIn] Stopped 2019-10-24T18:40:07.449Z,1571942407.449 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-10-24T18:40:07.449Z,1571942407.449 [Default:CheckIn](INFO): Running loop #12 2019-10-24T18:40:07.449Z,1571942407.449 [Default:CheckIn] Running Loop=12 2019-10-24T18:40:07.449Z,1571942407.449 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-10-24T18:40:07.450Z,1571942407.450 [Default:CheckIn:Read_GPS] Running Loop=1 2019-10-24T18:40:09.433Z,1571942409.433 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183838.00,A,3648.16911,N,12147.28291,W,0.175,205.39,241019,,,A*72 2019-10-24T18:40:09.435Z,1571942409.435 [NAL9602](INFO): GPS fix at 20191024T183838: (36.802819, -121.788049) 2019-10-24T18:40:09.486Z,1571942409.486 [Default:CheckIn:Read_GPS] Stopped 2019-10-24T18:40:09.486Z,1571942409.486 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-10-24T18:40:17.464Z,1571942417.464 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20191024T175536/Courier0024.lzma 2019-10-24T18:40:19.471Z,1571942419.471 [DataOverHttps](INFO): Moved sent file to Logs/20191024T175536/Courier0024.lzma.bak 2019-10-24T18:40:19.471Z,1571942419.471 [DataOverHttps](INFO): SBD MOMSN=11951585 2019-10-24T18:40:37.156Z,1571942437.156 [DataOverHttps](INFO): Sending 120 bytes from file Logs/20191024T175536/Express0025.lzma 2019-10-24T18:40:39.162Z,1571942439.162 [DataOverHttps](INFO): Moved sent file to Logs/20191024T175536/Express0025.lzma.bak 2019-10-24T18:40:39.162Z,1571942439.162 [DataOverHttps](INFO): SBD MOMSN=11951588 2019-10-24T18:40:40.993Z,1571942440.993 [Default:CheckIn:Read_Iridium] Stopped 2019-10-24T18:40:40.993Z,1571942440.993 [Default:CheckIn:C.Wait] Running Loop=1 2019-10-24T18:40:40.994Z,1571942440.994 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-10-24T18:43:35.106Z,1571942615.106 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2019-10-24T18:43:35.108Z,1571942615.108 [BPC1](INFO): Received data from all battery sticks. 2019-10-24T18:43:39.523Z,1571942619.523 [NAL9602](INFO): SBD MO Status=2, MOMSN=17404, MT Status=2, MTMSN=0 2019-10-24T18:43:39.523Z,1571942619.523 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-10-24T18:44:05.795Z,1571942645.795 [NAL9602](INFO): SBD MO Status=0, MOMSN=17404, MT Status=0, MTMSN=0 2019-10-24T18:44:05.795Z,1571942645.795 [NAL9602](INFO): No messages in MT queue 2019-10-24T18:44:36.502Z,1571942676.502 [NAL9602](INFO): Not Powering down - fast GPS 2019-10-24T18:45:41.577Z,1571942741.577 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-10-24T18:45:41.577Z,1571942741.577 [Default:CheckIn:C.Wait] Stopped 2019-10-24T18:45:41.577Z,1571942741.577 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-10-24T18:45:41.578Z,1571942741.578 [Default:CheckIn:D] Running Loop=1 2019-10-24T18:45:41.979Z,1571942741.979 [Default:CheckIn:D] Stopped 2019-10-24T18:45:41.979Z,1571942741.979 [Default:CheckIn:E] Running Loop=1 2019-10-24T18:45:42.368Z,1571942742.368 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 70.357625 min 2019-10-24T18:45:42.368Z,1571942742.368 [Default:CheckIn:E] Stopped 2019-10-24T18:45:42.368Z,1571942742.368 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-10-24T18:45:42.368Z,1571942742.368 [Default:CheckIn] Stopped 2019-10-24T18:45:42.368Z,1571942742.368 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-10-24T18:45:42.369Z,1571942742.369 [Default:CheckIn](INFO): Running loop #13 2019-10-24T18:45:42.369Z,1571942742.369 [Default:CheckIn] Running Loop=13 2019-10-24T18:45:42.369Z,1571942742.369 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-10-24T18:45:42.369Z,1571942742.369 [Default:CheckIn:Read_GPS] Running Loop=1 2019-10-24T18:45:44.376Z,1571942744.376 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184413.00,A,3648.17557,N,12147.26886,W,0.952,215.63,241019,,,A*7E 2019-10-24T18:45:44.378Z,1571942744.378 [NAL9602](INFO): GPS fix at 20191024T184413: (36.802926, -121.787814) 2019-10-24T18:45:44.402Z,1571942744.402 [Default:CheckIn:Read_GPS] Stopped 2019-10-24T18:45:44.402Z,1571942744.402 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-10-24T18:45:52.360Z,1571942752.360 [DataOverHttps](INFO): Sending 222 bytes from file Logs/20191024T175536/Courier0027.lzma 2019-10-24T18:45:54.366Z,1571942754.366 [DataOverHttps](INFO): Moved sent file to Logs/20191024T175536/Courier0027.lzma.bak 2019-10-24T18:45:54.367Z,1571942754.367 [DataOverHttps](INFO): SBD MOMSN=11951620 2019-10-24T18:46:02.563Z,1571942762.563 [NAL9602](INFO): SBD MO Status=2, MOMSN=17405, MT Status=2, MTMSN=0 2019-10-24T18:46:02.563Z,1571942762.563 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-10-24T18:46:11.416Z,1571942771.416 [DataOverHttps](INFO): Sending 134 bytes from file Logs/20191024T175536/Express0028.lzma 2019-10-24T18:46:13.422Z,1571942773.422 [DataOverHttps](INFO): Moved sent file to Logs/20191024T175536/Express0028.lzma.bak 2019-10-24T18:46:13.423Z,1571942773.423 [DataOverHttps](INFO): SBD MOMSN=11951626 2019-10-24T18:46:15.113Z,1571942775.113 [Default:CheckIn:Read_Iridium] Stopped 2019-10-24T18:46:15.113Z,1571942775.113 [Default:CheckIn:C.Wait] Running Loop=1 2019-10-24T18:46:15.113Z,1571942775.113 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-10-24T18:46:18.715Z,1571942778.715 [NAL9602](INFO): SBD MO Status=0, MOMSN=17405, MT Status=0, MTMSN=0 2019-10-24T18:46:18.715Z,1571942778.715 [NAL9602](INFO): No messages in MT queue 2019-10-24T18:46:49.418Z,1571942809.418 [NAL9602](INFO): Not Powering down - fast GPS 2019-10-24T18:51:15.713Z,1571943075.713 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-10-24T18:51:15.713Z,1571943075.713 [Default:CheckIn:C.Wait] Stopped 2019-10-24T18:51:15.713Z,1571943075.713 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-10-24T18:51:15.714Z,1571943075.714 [Default:CheckIn:D] Running Loop=1 2019-10-24T18:51:16.119Z,1571943076.119 [Default:CheckIn:D] Stopped 2019-10-24T18:51:16.119Z,1571943076.119 [Default:CheckIn:E] Running Loop=1 2019-10-24T18:51:16.538Z,1571943076.538 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 75.926619 min 2019-10-24T18:51:16.538Z,1571943076.538 [Default:CheckIn:E] Stopped 2019-10-24T18:51:16.538Z,1571943076.538 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-10-24T18:51:16.538Z,1571943076.538 [Default:CheckIn] Stopped 2019-10-24T18:51:16.538Z,1571943076.538 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-10-24T18:51:16.538Z,1571943076.538 [Default:CheckIn](INFO): Running loop #14 2019-10-24T18:51:16.538Z,1571943076.538 [Default:CheckIn] Running Loop=14 2019-10-24T18:51:16.538Z,1571943076.538 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-10-24T18:51:16.538Z,1571943076.538 [Default:CheckIn:Read_GPS] Running Loop=1 2019-10-24T18:51:18.512Z,1571943078.512 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184946.00,A,3648.18167,N,12147.27152,W,0.078,215.63,241019,,,A*7B 2019-10-24T18:51:18.514Z,1571943078.514 [NAL9602](INFO): GPS fix at 20191024T184946: (36.803028, -121.787859) 2019-10-24T18:51:18.539Z,1571943078.539 [Default:CheckIn:Read_GPS] Stopped 2019-10-24T18:51:18.539Z,1571943078.539 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-10-24T18:51:25.860Z,1571943085.860 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20191024T175536/Courier0030.lzma 2019-10-24T18:51:27.866Z,1571943087.866 [DataOverHttps](INFO): Moved sent file to Logs/20191024T175536/Courier0030.lzma.bak 2019-10-24T18:51:27.866Z,1571943087.866 [DataOverHttps](INFO): SBD MOMSN=11951696 2019-10-24T18:51:44.924Z,1571943104.924 [DataOverHttps](INFO): Sending 121 bytes from file Logs/20191024T175536/Express0031.lzma 2019-10-24T18:51:46.930Z,1571943106.930 [DataOverHttps](INFO): Moved sent file to Logs/20191024T175536/Express0031.lzma.bak 2019-10-24T18:51:46.930Z,1571943106.930 [DataOverHttps](INFO): SBD MOMSN=11951701 2019-10-24T18:51:48.881Z,1571943108.881 [Default:CheckIn:Read_Iridium] Stopped 2019-10-24T18:51:48.881Z,1571943108.881 [Default:CheckIn:C.Wait] Running Loop=1 2019-10-24T18:51:48.881Z,1571943108.881 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-10-24T18:52:34.103Z,1571943154.103 [NAL9602](INFO): SBD MO Status=2, MOMSN=17406, MT Status=2, MTMSN=0 2019-10-24T18:52:34.103Z,1571943154.103 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-10-24T18:53:12.069Z,1571943192.069 [NAL9602](INFO): SBD MO Status=0, MOMSN=17406, MT Status=0, MTMSN=0 2019-10-24T18:53:12.069Z,1571943192.069 [NAL9602](INFO): No messages in MT queue 2019-10-24T18:53:42.778Z,1571943222.778 [NAL9602](INFO): Not Powering down - fast GPS 2019-10-24T18:56:49.476Z,1571943409.476 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-10-24T18:56:49.477Z,1571943409.477 [Default:CheckIn:C.Wait] Stopped 2019-10-24T18:56:49.477Z,1571943409.477 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-10-24T18:56:49.477Z,1571943409.477 [Default:CheckIn:D] Running Loop=1 2019-10-24T18:56:49.885Z,1571943409.885 [Default:CheckIn:D] Stopped 2019-10-24T18:56:49.885Z,1571943409.885 [Default:CheckIn:E] Running Loop=1 2019-10-24T18:56:50.297Z,1571943410.297 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 81.489396 min 2019-10-24T18:56:50.298Z,1571943410.298 [Default:CheckIn:E] Stopped 2019-10-24T18:56:50.298Z,1571943410.298 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-10-24T18:56:50.298Z,1571943410.298 [Default:CheckIn] Stopped 2019-10-24T18:56:50.298Z,1571943410.298 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-10-24T18:56:50.298Z,1571943410.298 [Default:CheckIn](INFO): Running loop #15 2019-10-24T18:56:50.298Z,1571943410.298 [Default:CheckIn] Running Loop=15 2019-10-24T18:56:50.298Z,1571943410.298 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-10-24T18:56:50.298Z,1571943410.298 [Default:CheckIn:Read_GPS] Running Loop=1 2019-10-24T18:56:52.280Z,1571943412.280 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,185519.00,A,3648.17107,N,12147.28017,W,0.000,264.66,241019,,,A*76 2019-10-24T18:56:52.282Z,1571943412.282 [NAL9602](INFO): GPS fix at 20191024T185519: (36.802851, -121.788003) 2019-10-24T18:56:52.327Z,1571943412.327 [Default:CheckIn:Read_GPS] Stopped 2019-10-24T18:56:52.327Z,1571943412.327 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-10-24T18:56:59.560Z,1571943419.560 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20191024T175536/Courier0033.lzma 2019-10-24T18:57:01.566Z,1571943421.566 [DataOverHttps](INFO): Moved sent file to Logs/20191024T175536/Courier0033.lzma.bak 2019-10-24T18:57:01.566Z,1571943421.566 [DataOverHttps](INFO): SBD MOMSN=11951794 2019-10-24T18:57:16.115Z,1571943436.115 [NAL9602](INFO): SBD MO Status=0, MOMSN=17407, MT Status=0, MTMSN=0 2019-10-24T18:57:16.115Z,1571943436.115 [NAL9602](INFO): No messages in MT queue 2019-10-24T18:57:18.688Z,1571943438.688 [DataOverHttps](INFO): Sending 121 bytes from file Logs/20191024T175536/Express0034.lzma 2019-10-24T18:57:20.694Z,1571943440.694 [DataOverHttps](INFO): Moved sent file to Logs/20191024T175536/Express0034.lzma.bak 2019-10-24T18:57:20.695Z,1571943440.695 [DataOverHttps](INFO): SBD MOMSN=11951797 2019-10-24T18:57:22.605Z,1571943442.605 [Default:CheckIn:Read_Iridium] Stopped 2019-10-24T18:57:22.605Z,1571943442.605 [Default:CheckIn:C.Wait] Running Loop=1 2019-10-24T18:57:22.605Z,1571943442.605 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-10-24T18:57:46.818Z,1571943466.818 [NAL9602](INFO): Not Powering down - fast GPS 2019-10-24T19:02:23.223Z,1571943743.223 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-10-24T19:02:23.223Z,1571943743.223 [Default:CheckIn:C.Wait] Stopped 2019-10-24T19:02:23.223Z,1571943743.223 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-10-24T19:02:23.223Z,1571943743.223 [Default:CheckIn:D] Running Loop=1 2019-10-24T19:02:23.617Z,1571943743.617 [Default:CheckIn:D] Stopped 2019-10-24T19:02:23.617Z,1571943743.617 [Default:CheckIn:E] Running Loop=1 2019-10-24T19:02:24.019Z,1571943744.019 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 87.051595 min 2019-10-24T19:02:24.019Z,1571943744.019 [Default:CheckIn:E] Stopped 2019-10-24T19:02:24.019Z,1571943744.019 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-10-24T19:02:24.020Z,1571943744.020 [Default:CheckIn] Stopped 2019-10-24T19:02:24.020Z,1571943744.020 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-10-24T19:02:24.020Z,1571943744.020 [Default:CheckIn](INFO): Running loop #16 2019-10-24T19:02:24.020Z,1571943744.020 [Default:CheckIn] Running Loop=16 2019-10-24T19:02:24.020Z,1571943744.020 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-10-24T19:02:24.020Z,1571943744.020 [Default:CheckIn:Read_GPS] Running Loop=1 2019-10-24T19:02:26.020Z,1571943746.020 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190053.00,A,3648.17041,N,12147.28095,W,0.875,264.66,241019,,,A*7A 2019-10-24T19:02:26.032Z,1571943746.032 [NAL9602](INFO): GPS fix at 20191024T190053: (36.802840, -121.788016) 2019-10-24T19:02:26.058Z,1571943746.058 [Default:CheckIn:Read_GPS] Stopped 2019-10-24T19:02:26.058Z,1571943746.058 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-10-24T19:02:33.632Z,1571943753.632 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20191024T175536/Courier0036.lzma 2019-10-24T19:02:35.638Z,1571943755.638 [DataOverHttps](INFO): Moved sent file to Logs/20191024T175536/Courier0036.lzma.bak 2019-10-24T19:02:35.638Z,1571943755.638 [DataOverHttps](INFO): SBD MOMSN=11951831 2019-10-24T19:02:41.771Z,1571943761.771 [NAL9602](INFO): SBD MO Status=0, MOMSN=17408, MT Status=0, MTMSN=0 2019-10-24T19:02:41.772Z,1571943761.772 [NAL9602](INFO): No messages in MT queue 2019-10-24T19:02:52.656Z,1571943772.656 [DataOverHttps](INFO): Sending 121 bytes from file Logs/20191024T175536/Express0037.lzma 2019-10-24T19:02:54.663Z,1571943774.663 [DataOverHttps](INFO): Moved sent file to Logs/20191024T175536/Express0037.lzma.bak 2019-10-24T19:02:54.663Z,1571943774.663 [DataOverHttps](INFO): SBD MOMSN=11951834 2019-10-24T19:02:56.353Z,1571943776.353 [Default:CheckIn:Read_Iridium] Stopped 2019-10-24T19:02:56.354Z,1571943776.354 [Default:CheckIn:C.Wait] Running Loop=1 2019-10-24T19:02:56.354Z,1571943776.354 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-10-24T19:03:12.490Z,1571943792.490 [NAL9602](INFO): Not Powering down - fast GPS 2019-10-24T19:07:56.941Z,1571944076.941 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-10-24T19:07:56.941Z,1571944076.941 [Default:CheckIn:C.Wait] Stopped 2019-10-24T19:07:56.941Z,1571944076.941 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-10-24T19:07:56.942Z,1571944076.942 [Default:CheckIn:D] Running Loop=1 2019-10-24T19:07:57.367Z,1571944077.367 [Default:CheckIn:D] Stopped 2019-10-24T19:07:57.367Z,1571944077.367 [Default:CheckIn:E] Running Loop=1 2019-10-24T19:07:57.812Z,1571944077.812 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 92.614087 min 2019-10-24T19:07:57.812Z,1571944077.812 [Default:CheckIn:E] Stopped 2019-10-24T19:07:57.812Z,1571944077.812 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-10-24T19:07:57.812Z,1571944077.812 [Default:CheckIn] Stopped 2019-10-24T19:07:57.812Z,1571944077.812 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-10-24T19:07:57.812Z,1571944077.812 [Default:CheckIn](INFO): Running loop #17 2019-10-24T19:07:57.812Z,1571944077.812 [Default:CheckIn] Running Loop=17 2019-10-24T19:07:57.812Z,1571944077.812 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-10-24T19:07:57.813Z,1571944077.813 [Default:CheckIn:Read_GPS] Running Loop=1 2019-10-24T19:07:59.754Z,1571944079.754 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190626.00,A,3648.16726,N,12147.28119,W,0.194,264.66,241019,,,A*7A 2019-10-24T19:07:59.756Z,1571944079.756 [NAL9602](INFO): GPS fix at 20191024T190626: (36.802788, -121.788020) 2019-10-24T19:07:59.780Z,1571944079.780 [Default:CheckIn:Read_GPS] Stopped 2019-10-24T19:07:59.780Z,1571944079.780 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-10-24T19:08:07.852Z,1571944087.852 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20191024T175536/Courier0039.lzma 2019-10-24T19:08:09.859Z,1571944089.859 [DataOverHttps](INFO): Moved sent file to Logs/20191024T175536/Courier0039.lzma.bak 2019-10-24T19:08:09.859Z,1571944089.859 [DataOverHttps](INFO): SBD MOMSN=11951861 2019-10-24T19:08:27.324Z,1571944107.324 [DataOverHttps](INFO): Sending 121 bytes from file Logs/20191024T175536/Express0040.lzma 2019-10-24T19:08:29.354Z,1571944109.354 [DataOverHttps](INFO): Moved sent file to Logs/20191024T175536/Express0040.lzma.bak 2019-10-24T19:08:29.354Z,1571944109.354 [DataOverHttps](INFO): SBD MOMSN=11951864 2019-10-24T19:08:31.293Z,1571944111.293 [Default:CheckIn:Read_Iridium] Stopped 2019-10-24T19:08:31.293Z,1571944111.293 [Default:CheckIn:C.Wait] Running Loop=1 2019-10-24T19:08:31.293Z,1571944111.293 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-10-24T19:13:01.938Z,1571944381.938 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-10-24T19:13:31.865Z,1571944411.865 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-10-24T19:13:31.865Z,1571944411.865 [Default:CheckIn:C.Wait] Stopped 2019-10-24T19:13:31.865Z,1571944411.865 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-10-24T19:13:31.865Z,1571944411.865 [Default:CheckIn:D] Running Loop=1 2019-10-24T19:13:32.270Z,1571944412.270 [Default:CheckIn:D] Stopped 2019-10-24T19:13:32.270Z,1571944412.270 [Default:CheckIn:E] Running Loop=1 2019-10-24T19:13:32.642Z,1571944412.642 [NAL9602](INFO): Not Powering down - fast GPS 2019-10-24T19:13:32.694Z,1571944412.694 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 98.195809 min 2019-10-24T19:13:32.694Z,1571944412.694 [Default:CheckIn:E] Stopped 2019-10-24T19:13:32.694Z,1571944412.694 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-10-24T19:13:32.695Z,1571944412.695 [Default:CheckIn] Stopped 2019-10-24T19:13:32.695Z,1571944412.695 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-10-24T19:13:32.695Z,1571944412.695 [Default:CheckIn](INFO): Running loop #18 2019-10-24T19:13:32.695Z,1571944412.695 [Default:CheckIn] Running Loop=18 2019-10-24T19:13:32.695Z,1571944412.695 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-10-24T19:13:32.695Z,1571944412.695 [Default:CheckIn:Read_GPS] Running Loop=1 2019-10-24T19:13:34.668Z,1571944414.668 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,191200.00,A,3648.17029,N,12147.27233,W,0.156,131.12,241019,,,A*78 2019-10-24T19:13:34.670Z,1571944414.670 [NAL9602](INFO): GPS fix at 20191024T191200: (36.802838, -121.787872) 2019-10-24T19:13:34.694Z,1571944414.694 [Default:CheckIn:Read_GPS] Stopped 2019-10-24T19:13:34.694Z,1571944414.694 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-10-24T19:13:42.784Z,1571944422.784 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20191024T175536/Courier0042.lzma 2019-10-24T19:13:44.790Z,1571944424.790 [DataOverHttps](INFO): Moved sent file to Logs/20191024T175536/Courier0042.lzma.bak 2019-10-24T19:13:44.791Z,1571944424.791 [DataOverHttps](INFO): SBD MOMSN=11951944 2019-10-24T19:14:03.041Z,1571944443.041 [DataOverHttps](INFO): Sending 221 bytes from file Logs/20191024T175536/Express0043.lzma 2019-10-24T19:14:05.047Z,1571944445.047 [DataOverHttps](INFO): Moved sent file to Logs/20191024T175536/Express0043.lzma.bak 2019-10-24T19:14:05.048Z,1571944445.048 [DataOverHttps](INFO): SBD MOMSN=11951947 2019-10-24T19:14:05.362Z,1571944445.362 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2019-10-24T19:14:05.437Z,1571944445.437 [NAL9602](FAULT): received: +CSQ:0 OK408, 0, 0, 0, 0 OK 2019-10-24T19:14:05.437Z,1571944445.437 [NAL9602] Data Fault, FailCount= 1 2019-10-24T19:14:05.437Z,1571944445.437 [NAL9602](ERROR): Data Fault 2019-10-24T19:14:05.507Z,1571944445.507 [CBIT](ERROR): Data Fault in component: NAL9602 2019-10-24T19:14:05.770Z,1571944445.770 [NAL9602](INFO): Powering down 2019-10-24T19:14:06.170Z,1571944446.170 [NAL9602](FAULT): LCB fault: Software Overcurrent. 2019-10-24T19:14:06.170Z,1571944446.170 [NAL9602] Hardware Fault, FailCount= 1 2019-10-24T19:14:06.170Z,1571944446.170 [NAL9602](ERROR): Hardware Fault 2019-10-24T19:14:06.644Z,1571944446.644 [CBIT](INFO): Clearing failed state for component NAL9602 2019-10-24T19:14:06.644Z,1571944446.644 [NAL9602] No Fault, FailCount= 1 2019-10-24T19:14:07.020Z,1571944447.020 [Default:CheckIn:Read_Iridium] Stopped 2019-10-24T19:14:07.021Z,1571944447.021 [Default:CheckIn:C.Wait] Running Loop=1 2019-10-24T19:14:07.021Z,1571944447.021 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-10-24T19:14:36.066Z,1571944476.066 [NAL9602](INFO): Powering up NAL9602 2019-10-24T19:14:46.984Z,1571944486.984 [NAL9602](INFO): NAL9602 initialized 2019-10-24T19:15:18.086Z,1571944518.086 [NAL9602](INFO): Not Powering down - fast GPS 2019-10-24T19:19:07.589Z,1571944747.589 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-10-24T19:19:07.589Z,1571944747.589 [Default:CheckIn:C.Wait] Stopped 2019-10-24T19:19:07.589Z,1571944747.589 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-10-24T19:19:07.589Z,1571944747.589 [Default:CheckIn:D] Running Loop=1 2019-10-24T19:19:07.996Z,1571944747.996 [Default:CheckIn:D] Stopped 2019-10-24T19:19:07.996Z,1571944747.996 [Default:CheckIn:E] Running Loop=1 2019-10-24T19:19:08.384Z,1571944748.384 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 103.791243 min 2019-10-24T19:19:08.384Z,1571944748.384 [Default:CheckIn:E] Stopped 2019-10-24T19:19:08.384Z,1571944748.384 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-10-24T19:19:08.384Z,1571944748.384 [Default:CheckIn] Stopped 2019-10-24T19:19:08.384Z,1571944748.384 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-10-24T19:19:08.384Z,1571944748.384 [Default:CheckIn](INFO): Running loop #19 2019-10-24T19:19:08.384Z,1571944748.384 [Default:CheckIn] Running Loop=19 2019-10-24T19:19:08.384Z,1571944748.384 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-10-24T19:19:08.385Z,1571944748.385 [Default:CheckIn:Read_GPS] Running Loop=1 2019-10-24T19:19:12.806Z,1571944752.806 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-10-24T19:19:31.806Z,1571944771.806 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,191756.00,A,3648.17279,N,12147.28679,W,0.233,5.69,241019,,,A*76 2019-10-24T19:19:31.808Z,1571944771.808 [NAL9602](INFO): GPS fix at 20191024T191756: (36.802880, -121.788113) 2019-10-24T19:19:31.834Z,1571944771.834 [Default:CheckIn:Read_GPS] Stopped 2019-10-24T19:19:31.834Z,1571944771.834 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-10-24T19:19:38.840Z,1571944778.840 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20191024T175536/Courier0045.lzma 2019-10-24T19:19:40.846Z,1571944780.846 [DataOverHttps](INFO): Moved sent file to Logs/20191024T175536/Courier0045.lzma.bak 2019-10-24T19:19:40.847Z,1571944780.847 [DataOverHttps](INFO): SBD MOMSN=11951978 2019-10-24T19:19:59.453Z,1571944799.453 [DataOverHttps](INFO): Sending 279 bytes from file Logs/20191024T175536/Express0046.lzma 2019-10-24T19:20:01.458Z,1571944801.458 [DataOverHttps](INFO): Moved sent file to Logs/20191024T175536/Express0046.lzma.bak 2019-10-24T19:20:01.458Z,1571944801.458 [DataOverHttps](INFO): SBD MOMSN=11951982 2019-10-24T19:20:03.087Z,1571944803.087 [Default:CheckIn:Read_Iridium] Stopped 2019-10-24T19:20:03.088Z,1571944803.088 [Default:CheckIn:C.Wait] Running Loop=1 2019-10-24T19:20:03.088Z,1571944803.088 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-10-24T19:20:04.252Z,1571944804.252 [NAL9602](INFO): Not Powering down - fast GPS 2019-10-24T19:25:03.643Z,1571945103.643 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-10-24T19:25:03.643Z,1571945103.643 [Default:CheckIn:C.Wait] Stopped 2019-10-24T19:25:03.644Z,1571945103.644 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-10-24T19:25:03.644Z,1571945103.644 [Default:CheckIn:D] Running Loop=1 2019-10-24T19:25:04.053Z,1571945104.053 [Default:CheckIn:D] Stopped 2019-10-24T19:25:04.053Z,1571945104.053 [Default:CheckIn:E] Running Loop=1 2019-10-24T19:25:04.460Z,1571945104.460 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 109.725521 min 2019-10-24T19:25:04.460Z,1571945104.460 [Default:CheckIn:E] Stopped 2019-10-24T19:25:04.461Z,1571945104.461 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-10-24T19:25:04.461Z,1571945104.461 [Default:CheckIn] Stopped 2019-10-24T19:25:04.461Z,1571945104.461 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-10-24T19:25:04.461Z,1571945104.461 [Default:CheckIn](INFO): Running loop #20 2019-10-24T19:25:04.461Z,1571945104.461 [Default:CheckIn] Running Loop=20 2019-10-24T19:25:04.461Z,1571945104.461 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-10-24T19:25:04.461Z,1571945104.461 [Default:CheckIn:Read_GPS] Running Loop=1 2019-10-24T19:25:06.448Z,1571945106.448 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,192331.00,A,3648.17071,N,12147.28716,W,0.194,0.00,241019,,,A*76 2019-10-24T19:25:06.450Z,1571945106.450 [NAL9602](INFO): GPS fix at 20191024T192331: (36.802845, -121.788119) 2019-10-24T19:25:06.498Z,1571945106.498 [Default:CheckIn:Read_GPS] Stopped 2019-10-24T19:25:06.498Z,1571945106.498 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-10-24T19:25:13.896Z,1571945113.896 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20191024T175536/Courier0048.lzma 2019-10-24T19:25:15.904Z,1571945115.904 [DataOverHttps](INFO): Moved sent file to Logs/20191024T175536/Courier0048.lzma.bak 2019-10-24T19:25:15.904Z,1571945115.904 [DataOverHttps](INFO): SBD MOMSN=11952004 2019-10-24T19:25:33.024Z,1571945133.024 [DataOverHttps](INFO): Sending 120 bytes from file Logs/20191024T175536/Express0049.lzma 2019-10-24T19:25:35.030Z,1571945135.030 [DataOverHttps](INFO): Moved sent file to Logs/20191024T175536/Express0049.lzma.bak 2019-10-24T19:25:35.031Z,1571945135.031 [DataOverHttps](INFO): SBD MOMSN=11952007 2019-10-24T19:25:36.781Z,1571945136.781 [Default:CheckIn:Read_Iridium] Stopped 2019-10-24T19:25:36.781Z,1571945136.781 [Default:CheckIn:C.Wait] Running Loop=1 2019-10-24T19:25:36.781Z,1571945136.781 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-10-24T19:30:09.045Z,1571945409.045 [NAL9602](INFO): SBD MO Status=2, MOMSN=17409, MT Status=2, MTMSN=0 2019-10-24T19:30:09.045Z,1571945409.045 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-10-24T19:30:09.458Z,1571945409.458 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-10-24T19:30:37.358Z,1571945437.358 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-10-24T19:30:37.358Z,1571945437.358 [Default:CheckIn:C.Wait] Stopped 2019-10-24T19:30:37.358Z,1571945437.358 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-10-24T19:30:37.358Z,1571945437.358 [Default:CheckIn:D] Running Loop=1 2019-10-24T19:30:37.767Z,1571945437.767 [Default:CheckIn:D] Stopped 2019-10-24T19:30:37.767Z,1571945437.767 [Default:CheckIn:E] Running Loop=1 2019-10-24T19:30:38.162Z,1571945438.162 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 115.287419 min 2019-10-24T19:30:38.162Z,1571945438.162 [Default:CheckIn:E] Stopped 2019-10-24T19:30:38.162Z,1571945438.162 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-10-24T19:30:38.163Z,1571945438.163 [Default:CheckIn] Stopped 2019-10-24T19:30:38.163Z,1571945438.163 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-10-24T19:30:38.163Z,1571945438.163 [Default:CheckIn](INFO): Running loop #21 2019-10-24T19:30:38.163Z,1571945438.163 [Default:CheckIn] Running Loop=21 2019-10-24T19:30:38.163Z,1571945438.163 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-10-24T19:30:38.163Z,1571945438.163 [Default:CheckIn:Read_GPS] Running Loop=1 2019-10-24T19:30:40.164Z,1571945440.164 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,192904.00,A,3648.17449,N,12147.28398,W,0.350,256.54,241019,,,A*7D 2019-10-24T19:30:40.166Z,1571945440.166 [NAL9602](INFO): GPS fix at 20191024T192904: (36.802908, -121.788066) 2019-10-24T19:30:40.190Z,1571945440.190 [Default:CheckIn:Read_GPS] Stopped 2019-10-24T19:30:40.190Z,1571945440.190 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-10-24T19:30:56.772Z,1571945456.772 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20191024T175536/Courier0051.lzma 2019-10-24T19:30:58.778Z,1571945458.778 [DataOverHttps](INFO): Moved sent file to Logs/20191024T175536/Courier0051.lzma.bak 2019-10-24T19:30:58.779Z,1571945458.779 [DataOverHttps](INFO): SBD MOMSN=11952017 2019-10-24T19:31:12.076Z,1571945472.076 [NAL9602](INFO): Not Powering down - fast GPS 2019-10-24T19:31:16.417Z,1571945476.417 [DataOverHttps](INFO): Sending 199 bytes from file Logs/20191024T175536/Express0052.lzma 2019-10-24T19:31:18.422Z,1571945478.422 [DataOverHttps](INFO): Moved sent file to Logs/20191024T175536/Express0052.lzma.bak 2019-10-24T19:31:18.423Z,1571945478.423 [DataOverHttps](INFO): SBD MOMSN=11952029 2019-10-24T19:31:20.189Z,1571945480.189 [Default:CheckIn:Read_Iridium] Stopped 2019-10-24T19:31:20.189Z,1571945480.189 [Default:CheckIn:C.Wait] Running Loop=1 2019-10-24T19:31:20.189Z,1571945480.189 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-10-24T19:36:20.810Z,1571945780.810 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-10-24T19:36:20.810Z,1571945780.810 [Default:CheckIn:C.Wait] Stopped 2019-10-24T19:36:20.810Z,1571945780.810 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-10-24T19:36:20.810Z,1571945780.810 [Default:CheckIn:D] Running Loop=1 2019-10-24T19:36:21.219Z,1571945781.219 [Default:CheckIn:D] Stopped 2019-10-24T19:36:21.219Z,1571945781.219 [Default:CheckIn:E] Running Loop=1 2019-10-24T19:36:21.631Z,1571945781.631 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 121.011621 min 2019-10-24T19:36:21.631Z,1571945781.631 [Default:CheckIn:E] Stopped 2019-10-24T19:36:21.631Z,1571945781.631 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-10-24T19:36:21.631Z,1571945781.631 [Default:CheckIn] Stopped 2019-10-24T19:36:21.631Z,1571945781.631 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-10-24T19:36:21.631Z,1571945781.631 [Default:CheckIn](INFO): Running loop #22 2019-10-24T19:36:21.631Z,1571945781.631 [Default:CheckIn] Running Loop=22 2019-10-24T19:36:21.631Z,1571945781.631 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-10-24T19:36:21.632Z,1571945781.632 [Default:CheckIn:Read_GPS] Running Loop=1 2019-10-24T19:36:23.620Z,1571945783.620 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,193447.00,A,3648.17109,N,12147.28587,W,0.097,328.93,241019,,,A*74 2019-10-24T19:36:23.622Z,1571945783.622 [NAL9602](INFO): GPS fix at 20191024T193447: (36.802852, -121.788098) 2019-10-24T19:36:23.669Z,1571945783.670 [Default:CheckIn:Read_GPS] Stopped 2019-10-24T19:36:23.670Z,1571945783.670 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-10-24T19:36:30.712Z,1571945790.712 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20191024T175536/Courier0054.lzma 2019-10-24T19:36:32.718Z,1571945792.718 [DataOverHttps](INFO): Moved sent file to Logs/20191024T175536/Courier0054.lzma.bak 2019-10-24T19:36:32.719Z,1571945792.719 [DataOverHttps](INFO): SBD MOMSN=11952058 2019-10-24T19:36:49.803Z,1571945809.803 [DataOverHttps](INFO): Sending 120 bytes from file Logs/20191024T175536/Express0055.lzma 2019-10-24T19:36:51.810Z,1571945811.810 [DataOverHttps](INFO): Moved sent file to Logs/20191024T175536/Express0055.lzma.bak 2019-10-24T19:36:51.810Z,1571945811.810 [DataOverHttps](INFO): SBD MOMSN=11952061 2019-10-24T19:36:53.645Z,1571945813.645 [Default:CheckIn:Read_Iridium] Stopped 2019-10-24T19:36:53.645Z,1571945813.645 [Default:CheckIn:C.Wait] Running Loop=1 2019-10-24T19:36:53.645Z,1571945813.645 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-10-24T19:37:25.919Z,1571945845.919 [NAL9602](INFO): SBD MO Status=2, MOMSN=17409, MT Status=2, MTMSN=0 2019-10-24T19:37:25.919Z,1571945845.919 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-10-24T19:38:26.147Z,1571945906.147 [NAL9602](INFO): SBD MO Status=2, MOMSN=17409, MT Status=2, MTMSN=0 2019-10-24T19:38:26.147Z,1571945906.147 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-10-24T19:41:25.542Z,1571946085.542 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-10-24T19:41:54.258Z,1571946114.258 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-10-24T19:41:54.258Z,1571946114.258 [Default:CheckIn:C.Wait] Stopped 2019-10-24T19:41:54.258Z,1571946114.258 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-10-24T19:41:54.258Z,1571946114.258 [Default:CheckIn:D] Running Loop=1 2019-10-24T19:41:54.650Z,1571946114.650 [Default:CheckIn:D] Stopped 2019-10-24T19:41:54.650Z,1571946114.650 [Default:CheckIn:E] Running Loop=1 2019-10-24T19:41:55.059Z,1571946115.059 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 126.568807 min 2019-10-24T19:41:55.059Z,1571946115.059 [Default:CheckIn:E] Stopped 2019-10-24T19:41:55.059Z,1571946115.059 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-10-24T19:41:55.060Z,1571946115.060 [Default:CheckIn] Stopped 2019-10-24T19:41:55.060Z,1571946115.060 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-10-24T19:41:55.060Z,1571946115.060 [Default:CheckIn](INFO): Running loop #23 2019-10-24T19:41:55.060Z,1571946115.060 [Default:CheckIn] Running Loop=23 2019-10-24T19:41:55.060Z,1571946115.060 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-10-24T19:41:55.060Z,1571946115.060 [Default:CheckIn:Read_GPS] Running Loop=1 2019-10-24T19:41:57.052Z,1571946117.052 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194020.00,A,3648.17349,N,12147.27681,W,0.447,346.08,241019,,,A*79 2019-10-24T19:41:57.055Z,1571946117.055 [NAL9602](INFO): GPS fix at 20191024T194020: (36.802892, -121.787947) 2019-10-24T19:41:57.098Z,1571946117.098 [Default:CheckIn:Read_GPS] Stopped 2019-10-24T19:41:57.098Z,1571946117.098 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-10-24T19:42:06.316Z,1571946126.316 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20191024T175536/Courier0057.lzma 2019-10-24T19:42:08.322Z,1571946128.322 [DataOverHttps](INFO): Moved sent file to Logs/20191024T175536/Courier0057.lzma.bak 2019-10-24T19:42:08.322Z,1571946128.322 [DataOverHttps](INFO): SBD MOMSN=11952085 2019-10-24T19:42:25.381Z,1571946145.381 [DataOverHttps](INFO): Sending 198 bytes from file Logs/20191024T175536/Express0058.lzma 2019-10-24T19:42:27.387Z,1571946147.387 [DataOverHttps](INFO): Moved sent file to Logs/20191024T175536/Express0058.lzma.bak 2019-10-24T19:42:27.387Z,1571946147.387 [DataOverHttps](INFO): SBD MOMSN=11952127 2019-10-24T19:42:29.013Z,1571946149.013 [Default:CheckIn:Read_Iridium] Stopped 2019-10-24T19:42:29.013Z,1571946149.013 [Default:CheckIn:C.Wait] Running Loop=1 2019-10-24T19:42:29.014Z,1571946149.014 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-10-24T19:42:29.386Z,1571946149.386 [NAL9602](INFO): Not Powering down - fast GPS 2019-10-24T19:47:29.612Z,1571946449.612 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-10-24T19:47:29.612Z,1571946449.612 [Default:CheckIn:C.Wait] Stopped 2019-10-24T19:47:29.612Z,1571946449.612 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-10-24T19:47:29.612Z,1571946449.612 [Default:CheckIn:D] Running Loop=1 2019-10-24T19:47:29.990Z,1571946449.990 [Default:CheckIn:D] Stopped 2019-10-24T19:47:29.990Z,1571946449.990 [Default:CheckIn:E] Running Loop=1 2019-10-24T19:47:30.399Z,1571946450.399 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 132.157813 min 2019-10-24T19:47:30.400Z,1571946450.400 [Default:CheckIn:E] Stopped 2019-10-24T19:47:30.400Z,1571946450.400 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-10-24T19:47:30.400Z,1571946450.400 [Default:CheckIn] Stopped 2019-10-24T19:47:30.400Z,1571946450.400 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-10-24T19:47:30.400Z,1571946450.400 [Default:CheckIn](INFO): Running loop #24 2019-10-24T19:47:30.400Z,1571946450.400 [Default:CheckIn] Running Loop=24 2019-10-24T19:47:30.400Z,1571946450.400 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-10-24T19:47:30.400Z,1571946450.400 [Default:CheckIn:Read_GPS] Running Loop=1 2019-10-24T19:47:32.390Z,1571946452.390 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194555.00,A,3648.16987,N,12147.28472,W,0.175,346.08,241019,,,A*72 2019-10-24T19:47:32.392Z,1571946452.392 [NAL9602](INFO): GPS fix at 20191024T194555: (36.802831, -121.788079) 2019-10-24T19:47:32.442Z,1571946452.442 [Default:CheckIn:Read_GPS] Stopped 2019-10-24T19:47:32.442Z,1571946452.442 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-10-24T19:47:40.192Z,1571946460.192 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20191024T175536/Courier0060.lzma 2019-10-24T19:47:42.198Z,1571946462.198 [DataOverHttps](INFO): Moved sent file to Logs/20191024T175536/Courier0060.lzma.bak 2019-10-24T19:47:42.199Z,1571946462.199 [DataOverHttps](INFO): SBD MOMSN=11952141 2019-10-24T19:47:59.228Z,1571946479.228 [DataOverHttps](INFO): Sending 121 bytes from file Logs/20191024T175536/Express0061.lzma 2019-10-24T19:48:01.235Z,1571946481.235 [DataOverHttps](INFO): Moved sent file to Logs/20191024T175536/Express0061.lzma.bak 2019-10-24T19:48:01.235Z,1571946481.235 [DataOverHttps](INFO): SBD MOMSN=11952144 2019-10-24T19:48:03.106Z,1571946483.106 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2019-10-24T19:48:03.185Z,1571946483.185 [NAL9602](FAULT): received: +CSQ:0 OK409, 2, 0, 0, 0 OK 2019-10-24T19:48:03.185Z,1571946483.185 [NAL9602] Data Fault, FailCount= 1 2019-10-24T19:48:03.185Z,1571946483.185 [NAL9602](ERROR): Data Fault 2019-10-24T19:48:03.354Z,1571946483.354 [Default:CheckIn:Read_Iridium] Stopped 2019-10-24T19:48:03.354Z,1571946483.354 [Default:CheckIn:C.Wait] Running Loop=1 2019-10-24T19:48:03.354Z,1571946483.354 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-10-24T19:48:03.398Z,1571946483.398 [CBIT](ERROR): Data Fault in component: NAL9602 2019-10-24T19:48:03.510Z,1571946483.510 [NAL9602](INFO): Powering down 2019-10-24T19:48:04.507Z,1571946484.507 [CBIT](INFO): Clearing failed state for component NAL9602 2019-10-24T19:48:04.507Z,1571946484.507 [NAL9602] No Fault, FailCount= 1 2019-10-24T19:48:33.814Z,1571946513.814 [NAL9602](INFO): Powering up NAL9602 2019-10-24T19:48:44.722Z,1571946524.722 [NAL9602](INFO): NAL9602 initialized 2019-10-24T19:49:15.826Z,1571946555.826 [NAL9602](INFO): Not Powering down - fast GPS 2019-10-24T19:51:04.132Z,1571946664.132 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2019-10-24T19:51:04.134Z,1571946664.134 [BPC1](INFO): Received data from all battery sticks. 2019-10-24T19:53:03.725Z,1571946783.725 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-10-24T19:53:03.725Z,1571946783.725 [Default:CheckIn:C.Wait] Stopped 2019-10-24T19:53:03.725Z,1571946783.725 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-10-24T19:53:03.725Z,1571946783.725 [Default:CheckIn:D] Running Loop=1 2019-10-24T19:53:04.116Z,1571946784.116 [Default:CheckIn:D] Stopped 2019-10-24T19:53:04.117Z,1571946784.117 [Default:CheckIn:E] Running Loop=1 2019-10-24T19:53:04.527Z,1571946784.527 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 137.726579 min 2019-10-24T19:53:04.527Z,1571946784.527 [Default:CheckIn:E] Stopped 2019-10-24T19:53:04.527Z,1571946784.527 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-10-24T19:53:04.528Z,1571946784.528 [Default:CheckIn] Stopped 2019-10-24T19:53:04.528Z,1571946784.528 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-10-24T19:53:04.528Z,1571946784.528 [Default:CheckIn](INFO): Running loop #25 2019-10-24T19:53:04.528Z,1571946784.528 [Default:CheckIn] Running Loop=25 2019-10-24T19:53:04.528Z,1571946784.528 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-10-24T19:53:04.528Z,1571946784.528 [Default:CheckIn:Read_GPS] Running Loop=1 2019-10-24T19:53:08.938Z,1571946788.938 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-10-24T19:55:04.084Z,1571946904.084 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,195325.00,A,3648.16604,N,12147.28170,W,0.058,0.00,241019,,,A*76 2019-10-24T19:55:04.086Z,1571946904.086 [NAL9602](INFO): GPS fix at 20191024T195325: (36.802767, -121.788028) 2019-10-24T19:55:04.110Z,1571946904.110 [Default:CheckIn:Read_GPS] Stopped 2019-10-24T19:55:04.110Z,1571946904.110 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-10-24T19:55:11.984Z,1571946911.984 [DataOverHttps](INFO): Sending 80 bytes from file Logs/20191024T175536/Courier0063.lzma 2019-10-24T19:55:13.990Z,1571946913.990 [DataOverHttps](INFO): Moved sent file to Logs/20191024T175536/Courier0063.lzma.bak 2019-10-24T19:55:13.991Z,1571946913.991 [DataOverHttps](INFO): SBD MOMSN=11952168 2019-10-24T19:55:31.021Z,1571946931.021 [DataOverHttps](INFO): Sending 239 bytes from file Logs/20191024T175536/Express0064.lzma 2019-10-24T19:55:33.026Z,1571946933.026 [DataOverHttps](INFO): Moved sent file to Logs/20191024T175536/Express0064.lzma.bak 2019-10-24T19:55:33.027Z,1571946933.027 [DataOverHttps](INFO): SBD MOMSN=11952171 2019-10-24T19:55:34.821Z,1571946934.821 [Default:CheckIn:Read_Iridium] Stopped 2019-10-24T19:55:34.821Z,1571946934.821 [Default:CheckIn:C.Wait] Running Loop=1 2019-10-24T19:55:34.821Z,1571946934.821 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-10-24T19:55:36.400Z,1571946936.400 [NAL9602](INFO): Not Powering down - fast GPS 2019-10-24T20:00:35.390Z,1571947235.390 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-10-24T20:00:35.390Z,1571947235.390 [Default:CheckIn:C.Wait] Stopped 2019-10-24T20:00:35.390Z,1571947235.390 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-10-24T20:00:35.390Z,1571947235.390 [Default:CheckIn:D] Running Loop=1 2019-10-24T20:00:35.779Z,1571947235.779 [Default:CheckIn:D] Stopped 2019-10-24T20:00:35.779Z,1571947235.779 [Default:CheckIn:E] Running Loop=1 2019-10-24T20:00:36.191Z,1571947236.191 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 145.254297 min 2019-10-24T20:00:36.192Z,1571947236.192 [Default:CheckIn:E] Stopped 2019-10-24T20:00:36.192Z,1571947236.192 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-10-24T20:00:36.192Z,1571947236.192 [Default:CheckIn] Stopped 2019-10-24T20:00:36.192Z,1571947236.192 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-10-24T20:00:36.192Z,1571947236.192 [Default:CheckIn](INFO): Running loop #26 2019-10-24T20:00:36.192Z,1571947236.192 [Default:CheckIn] Running Loop=26 2019-10-24T20:00:36.192Z,1571947236.192 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-10-24T20:00:36.192Z,1571947236.192 [Default:CheckIn:Read_GPS] Running Loop=1 2019-10-24T20:00:38.182Z,1571947238.181 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,195859.00,A,3648.17624,N,12147.27545,W,0.428,0.00,241019,,,A*7B 2019-10-24T20:00:38.184Z,1571947238.184 [NAL9602](INFO): GPS fix at 20191024T195859: (36.802937, -121.787924) 2019-10-24T20:00:38.228Z,1571947238.228 [Default:CheckIn:Read_GPS] Stopped 2019-10-24T20:00:38.232Z,1571947238.232 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-10-24T20:00:46.000Z,1571947246.000 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20191024T175536/Courier0066.lzma 2019-10-24T20:00:48.007Z,1571947248.007 [DataOverHttps](INFO): Moved sent file to Logs/20191024T175536/Courier0066.lzma.bak 2019-10-24T20:00:48.007Z,1571947248.007 [DataOverHttps](INFO): SBD MOMSN=11952181 2019-10-24T20:01:04.956Z,1571947264.956 [DataOverHttps](INFO): Sending 121 bytes from file Logs/20191024T175536/Express0067.lzma 2019-10-24T20:01:06.963Z,1571947266.963 [DataOverHttps](INFO): Moved sent file to Logs/20191024T175536/Express0067.lzma.bak 2019-10-24T20:01:06.963Z,1571947266.963 [DataOverHttps](INFO): SBD MOMSN=11952189 2019-10-24T20:01:08.925Z,1571947268.925 [Default:CheckIn:Read_Iridium] Stopped 2019-10-24T20:01:08.925Z,1571947268.925 [Default:CheckIn:C.Wait] Running Loop=1 2019-10-24T20:01:08.925Z,1571947268.925 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-10-24T20:03:01.197Z,1571947381.197 [NAL9602](INFO): SBD MO Status=2, MOMSN=17409, MT Status=2, MTMSN=0 2019-10-24T20:03:01.197Z,1571947381.197 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-10-24T20:03:26.255Z,1571947406.255 [NAL9602](INFO): SBD MO Status=2, MOMSN=17409, MT Status=2, MTMSN=0 2019-10-24T20:03:26.255Z,1571947406.255 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-10-24T20:03:45.239Z,1571947425.239 [NAL9602](INFO): SBD MO Status=2, MOMSN=17409, MT Status=2, MTMSN=0 2019-10-24T20:03:45.240Z,1571947425.240 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-10-24T20:04:09.082Z,1571947449.082 [NAL9602](INFO): SBD MO Status=2, MOMSN=17409, MT Status=2, MTMSN=0 2019-10-24T20:04:09.082Z,1571947449.082 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-10-24T20:05:40.782Z,1571947540.782 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-10-24T20:06:09.497Z,1571947569.497 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-10-24T20:06:09.497Z,1571947569.497 [Default:CheckIn:C.Wait] Stopped 2019-10-24T20:06:09.497Z,1571947569.497 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-10-24T20:06:09.497Z,1571947569.497 [Default:CheckIn:D] Running Loop=1 2019-10-24T20:06:09.904Z,1571947569.904 [Default:CheckIn:D] Stopped 2019-10-24T20:06:09.904Z,1571947569.904 [Default:CheckIn:E] Running Loop=1 2019-10-24T20:06:10.312Z,1571947570.312 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 150.823031 min 2019-10-24T20:06:10.312Z,1571947570.312 [Default:CheckIn:E] Stopped 2019-10-24T20:06:10.312Z,1571947570.312 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-10-24T20:06:10.312Z,1571947570.312 [Default:CheckIn] Stopped 2019-10-24T20:06:10.312Z,1571947570.312 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-10-24T20:06:10.313Z,1571947570.313 [Default:CheckIn](INFO): Running loop #27 2019-10-24T20:06:10.313Z,1571947570.313 [Default:CheckIn] Running Loop=27 2019-10-24T20:06:10.313Z,1571947570.313 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-10-24T20:06:10.313Z,1571947570.313 [Default:CheckIn:Read_GPS] Running Loop=1 2019-10-24T20:06:12.296Z,1571947572.296 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,200433.00,A,3648.17446,N,12147.27437,W,0.428,0.00,241019,,,A*76 2019-10-24T20:06:12.298Z,1571947572.298 [NAL9602](INFO): GPS fix at 20191024T200433: (36.802908, -121.787906) 2019-10-24T20:06:12.350Z,1571947572.350 [Default:CheckIn:Read_GPS] Stopped 2019-10-24T20:06:12.350Z,1571947572.350 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-10-24T20:06:20.260Z,1571947580.260 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20191024T175536/Courier0069.lzma 2019-10-24T20:06:22.266Z,1571947582.266 [DataOverHttps](INFO): Moved sent file to Logs/20191024T175536/Courier0069.lzma.bak 2019-10-24T20:06:22.267Z,1571947582.267 [DataOverHttps](INFO): SBD MOMSN=11952246 2019-10-24T20:06:39.260Z,1571947599.260 [DataOverHttps](INFO): Sending 197 bytes from file Logs/20191024T175536/Express0070.lzma 2019-10-24T20:06:41.267Z,1571947601.267 [DataOverHttps](INFO): Moved sent file to Logs/20191024T175536/Express0070.lzma.bak 2019-10-24T20:06:41.267Z,1571947601.267 [DataOverHttps](INFO): SBD MOMSN=11952249 2019-10-24T20:06:43.026Z,1571947603.026 [Default:CheckIn:Read_Iridium] Stopped 2019-10-24T20:06:43.027Z,1571947603.027 [Default:CheckIn:C.Wait] Running Loop=1 2019-10-24T20:06:43.027Z,1571947603.027 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-10-24T20:06:44.610Z,1571947604.610 [NAL9602](INFO): Not Powering down - fast GPS 2019-10-24T20:11:43.613Z,1571947903.613 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-10-24T20:11:43.613Z,1571947903.613 [Default:CheckIn:C.Wait] Stopped 2019-10-24T20:11:43.613Z,1571947903.613 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-10-24T20:11:43.613Z,1571947903.613 [Default:CheckIn:D] Running Loop=1 2019-10-24T20:11:44.010Z,1571947904.010 [Default:CheckIn:D] Stopped 2019-10-24T20:11:44.010Z,1571947904.010 [Default:CheckIn:E] Running Loop=1 2019-10-24T20:11:44.430Z,1571947904.430 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 156.391471 min 2019-10-24T20:11:44.430Z,1571947904.430 [Default:CheckIn:E] Stopped 2019-10-24T20:11:44.430Z,1571947904.430 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-10-24T20:11:44.431Z,1571947904.431 [Default:CheckIn] Stopped 2019-10-24T20:11:44.431Z,1571947904.431 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-10-24T20:11:44.431Z,1571947904.431 [Default:CheckIn](INFO): Running loop #28 2019-10-24T20:11:44.431Z,1571947904.431 [Default:CheckIn] Running Loop=28 2019-10-24T20:11:44.431Z,1571947904.431 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-10-24T20:11:44.431Z,1571947904.431 [Default:CheckIn:Read_GPS] Running Loop=1 2019-10-24T20:11:46.410Z,1571947906.410 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,201007.00,A,3648.16844,N,12147.27822,W,0.097,0.00,241019,,,A*73 2019-10-24T20:11:46.412Z,1571947906.412 [NAL9602](INFO): GPS fix at 20191024T201007: (36.802807, -121.787970) 2019-10-24T20:11:46.435Z,1571947906.435 [Default:CheckIn:Read_GPS] Stopped 2019-10-24T20:11:46.436Z,1571947906.436 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-10-24T20:11:54.456Z,1571947914.456 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20191024T175536/Courier0072.lzma 2019-10-24T20:11:56.463Z,1571947916.463 [DataOverHttps](INFO): Moved sent file to Logs/20191024T175536/Courier0072.lzma.bak 2019-10-24T20:11:56.463Z,1571947916.463 [DataOverHttps](INFO): SBD MOMSN=11952322 2019-10-24T20:12:16.860Z,1571947936.860 [DataOverHttps](INFO): Sending 121 bytes from file Logs/20191024T175536/Express0073.lzma 2019-10-24T20:12:17.134Z,1571947937.134 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2019-10-24T20:12:17.209Z,1571947937.209 [NAL9602](FAULT): received: +CSQ:0 OK409, 2, 0, 0, 0 OK 2019-10-24T20:12:17.209Z,1571947937.209 [NAL9602] Data Fault, FailCount= 1 2019-10-24T20:12:17.209Z,1571947937.209 [NAL9602](ERROR): Data Fault 2019-10-24T20:12:17.246Z,1571947937.246 [CBIT](ERROR): Data Fault in component: NAL9602 2019-10-24T20:12:17.534Z,1571947937.534 [NAL9602](INFO): Powering down 2019-10-24T20:12:18.384Z,1571947938.384 [CBIT](INFO): Clearing failed state for component NAL9602 2019-10-24T20:12:18.385Z,1571947938.385 [NAL9602] No Fault, FailCount= 1 2019-10-24T20:12:18.866Z,1571947938.866 [DataOverHttps](INFO): Moved sent file to Logs/20191024T175536/Express0073.lzma.bak 2019-10-24T20:12:18.867Z,1571947938.867 [DataOverHttps](INFO): SBD MOMSN=11952327 2019-10-24T20:12:20.797Z,1571947940.797 [Default:CheckIn:Read_Iridium] Stopped 2019-10-24T20:12:20.797Z,1571947940.797 [Default:CheckIn:C.Wait] Running Loop=1 2019-10-24T20:12:20.798Z,1571947940.798 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-10-24T20:12:47.832Z,1571947967.832 [NAL9602](INFO): Powering up NAL9602 2019-10-24T20:12:58.740Z,1571947978.740 [NAL9602](INFO): NAL9602 initialized 2019-10-24T20:13:29.854Z,1571948009.854 [NAL9602](INFO): Not Powering down - fast GPS 2019-10-24T20:17:21.374Z,1571948241.374 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-10-24T20:17:21.374Z,1571948241.374 [Default:CheckIn:C.Wait] Stopped 2019-10-24T20:17:21.374Z,1571948241.374 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-10-24T20:17:21.374Z,1571948241.374 [Default:CheckIn:D] Running Loop=1 2019-10-24T20:17:21.781Z,1571948241.781 [Default:CheckIn:D] Stopped 2019-10-24T20:17:21.781Z,1571948241.781 [Default:CheckIn:E] Running Loop=1 2019-10-24T20:17:22.197Z,1571948242.197 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 162.020996 min 2019-10-24T20:17:22.197Z,1571948242.197 [Default:CheckIn:E] Stopped 2019-10-24T20:17:22.198Z,1571948242.198 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-10-24T20:17:22.198Z,1571948242.198 [Default:CheckIn] Stopped 2019-10-24T20:17:22.198Z,1571948242.198 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-10-24T20:17:22.198Z,1571948242.198 [Default:CheckIn](INFO): Running loop #29 2019-10-24T20:17:22.198Z,1571948242.198 [Default:CheckIn] Running Loop=29 2019-10-24T20:17:22.198Z,1571948242.198 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-10-24T20:17:22.198Z,1571948242.198 [Default:CheckIn:Read_GPS] Running Loop=1 2019-10-24T20:17:26.202Z,1571948246.202 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-10-24T20:17:27.405Z,1571948247.405 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,201546.00,A,3648.16883,N,12147.27915,W,0.408,0.00,241019,,,A*7F 2019-10-24T20:17:27.407Z,1571948247.407 [NAL9602](INFO): GPS fix at 20191024T201546: (36.802814, -121.787986) 2019-10-24T20:17:27.431Z,1571948247.431 [Default:CheckIn:Read_GPS] Stopped 2019-10-24T20:17:27.431Z,1571948247.431 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-10-24T20:17:33.236Z,1571948253.236 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20191024T175536/Courier0075.lzma 2019-10-24T20:17:35.242Z,1571948255.242 [DataOverHttps](INFO): Moved sent file to Logs/20191024T175536/Courier0075.lzma.bak 2019-10-24T20:17:35.243Z,1571948255.243 [DataOverHttps](INFO): SBD MOMSN=11952456 2019-10-24T20:17:52.357Z,1571948272.357 [DataOverHttps](INFO): Sending 237 bytes from file Logs/20191024T175536/Express0076.lzma 2019-10-24T20:17:54.362Z,1571948274.362 [DataOverHttps](INFO): Moved sent file to Logs/20191024T175536/Express0076.lzma.bak 2019-10-24T20:17:54.363Z,1571948274.363 [DataOverHttps](INFO): SBD MOMSN=11952459 2019-10-24T20:17:56.126Z,1571948276.126 [Default:CheckIn:Read_Iridium] Stopped 2019-10-24T20:17:56.127Z,1571948276.127 [Default:CheckIn:C.Wait] Running Loop=1 2019-10-24T20:17:56.127Z,1571948276.127 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-10-24T20:17:59.722Z,1571948279.722 [NAL9602](INFO): Not Powering down - fast GPS 2019-10-24T20:22:56.725Z,1571948576.725 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-10-24T20:22:56.726Z,1571948576.726 [Default:CheckIn:C.Wait] Stopped 2019-10-24T20:22:56.726Z,1571948576.726 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-10-24T20:22:56.726Z,1571948576.726 [Default:CheckIn:D] Running Loop=1 2019-10-24T20:22:57.141Z,1571948577.141 [Default:CheckIn:D] Stopped 2019-10-24T20:22:57.141Z,1571948577.141 [Default:CheckIn:E] Running Loop=1 2019-10-24T20:22:57.543Z,1571948577.543 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 167.610319 min 2019-10-24T20:22:57.543Z,1571948577.543 [Default:CheckIn:E] Stopped 2019-10-24T20:22:57.543Z,1571948577.543 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-10-24T20:22:57.544Z,1571948577.544 [Default:CheckIn] Stopped 2019-10-24T20:22:57.544Z,1571948577.544 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-10-24T20:22:57.544Z,1571948577.544 [Default:CheckIn](INFO): Running loop #30 2019-10-24T20:22:57.544Z,1571948577.544 [Default:CheckIn] Running Loop=30 2019-10-24T20:22:57.544Z,1571948577.544 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-10-24T20:22:57.544Z,1571948577.544 [Default:CheckIn:Read_GPS] Running Loop=1 2019-10-24T20:22:59.531Z,1571948579.531 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,202118.00,A,3648.16772,N,12147.28681,W,0.641,0.00,241019,,,A*70 2019-10-24T20:22:59.534Z,1571948579.534 [NAL9602](INFO): GPS fix at 20191024T202118: (36.802795, -121.788113) 2019-10-24T20:22:59.583Z,1571948579.583 [Default:CheckIn:Read_GPS] Stopped 2019-10-24T20:22:59.583Z,1571948579.583 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-10-24T20:23:07.268Z,1571948587.268 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20191024T175536/Courier0078.lzma 2019-10-24T20:23:09.794Z,1571948589.794 [DataOverHttps](INFO): Moved sent file to Logs/20191024T175536/Courier0078.lzma.bak 2019-10-24T20:23:09.794Z,1571948589.794 [DataOverHttps](INFO): SBD MOMSN=11952471 2019-10-24T20:23:26.308Z,1571948606.308 [DataOverHttps](INFO): Sending 121 bytes from file Logs/20191024T175536/Express0079.lzma 2019-10-24T20:23:28.315Z,1571948608.315 [DataOverHttps](INFO): Moved sent file to Logs/20191024T175536/Express0079.lzma.bak 2019-10-24T20:23:28.315Z,1571948608.315 [DataOverHttps](INFO): SBD MOMSN=11952479 2019-10-24T20:23:30.301Z,1571948610.301 [Default:CheckIn:Read_Iridium] Stopped 2019-10-24T20:23:30.301Z,1571948610.301 [Default:CheckIn:C.Wait] Running Loop=1 2019-10-24T20:23:30.302Z,1571948610.302 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-10-24T20:28:02.154Z,1571948882.154 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-10-24T20:28:30.880Z,1571948910.880 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-10-24T20:28:30.880Z,1571948910.880 [Default:CheckIn:C.Wait] Stopped 2019-10-24T20:28:30.880Z,1571948910.880 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-10-24T20:28:30.880Z,1571948910.880 [Default:CheckIn:D] Running Loop=1 2019-10-24T20:28:31.273Z,1571948911.273 [Default:CheckIn:D] Stopped 2019-10-24T20:28:31.273Z,1571948911.273 [Default:CheckIn:E] Running Loop=1 2019-10-24T20:28:31.679Z,1571948911.679 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 173.179199 min 2019-10-24T20:28:31.679Z,1571948911.679 [Default:CheckIn:E] Stopped 2019-10-24T20:28:31.679Z,1571948911.679 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-10-24T20:28:31.679Z,1571948911.679 [Default:CheckIn] Stopped 2019-10-24T20:28:31.679Z,1571948911.679 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-10-24T20:28:31.679Z,1571948911.679 [Default:CheckIn](INFO): Running loop #31 2019-10-24T20:28:31.679Z,1571948911.679 [Default:CheckIn] Running Loop=31 2019-10-24T20:28:31.679Z,1571948911.679 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-10-24T20:28:31.679Z,1571948911.679 [Default:CheckIn:Read_GPS] Running Loop=1 2019-10-24T20:28:33.672Z,1571948913.672 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,202652.00,A,3648.16995,N,12147.28203,W,0.447,0.00,241019,,,A*74 2019-10-24T20:28:33.685Z,1571948913.685 [NAL9602](INFO): GPS fix at 20191024T202652: (36.802833, -121.788034) 2019-10-24T20:28:33.710Z,1571948913.710 [Default:CheckIn:Read_GPS] Stopped 2019-10-24T20:28:33.710Z,1571948913.710 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-10-24T20:28:41.704Z,1571948921.704 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20191024T175536/Courier0081.lzma 2019-10-24T20:28:43.711Z,1571948923.711 [DataOverHttps](INFO): Moved sent file to Logs/20191024T175536/Courier0081.lzma.bak 2019-10-24T20:28:43.711Z,1571948923.711 [DataOverHttps](INFO): SBD MOMSN=11952487 2019-10-24T20:29:01.289Z,1571948941.289 [DataOverHttps](INFO): Sending 198 bytes from file Logs/20191024T175536/Express0082.lzma 2019-10-24T20:29:03.294Z,1571948943.294 [DataOverHttps](INFO): Moved sent file to Logs/20191024T175536/Express0082.lzma.bak 2019-10-24T20:29:03.295Z,1571948943.295 [DataOverHttps](INFO): SBD MOMSN=11952490 2019-10-24T20:29:05.218Z,1571948945.218 [Default:CheckIn:Read_Iridium] Stopped 2019-10-24T20:29:05.219Z,1571948945.219 [Default:CheckIn:C.Wait] Running Loop=1 2019-10-24T20:29:05.219Z,1571948945.219 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-10-24T20:29:05.580Z,1571948945.580 [NAL9602](INFO): Not Powering down - fast GPS 2019-10-24T20:34:05.779Z,1571949245.779 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-10-24T20:34:05.779Z,1571949245.779 [Default:CheckIn:C.Wait] Stopped 2019-10-24T20:34:05.779Z,1571949245.779 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-10-24T20:34:05.779Z,1571949245.779 [Default:CheckIn:D] Running Loop=1 2019-10-24T20:34:06.237Z,1571949246.237 [Default:CheckIn:D] Stopped 2019-10-24T20:34:06.238Z,1571949246.238 [Default:CheckIn:E] Running Loop=1 2019-10-24T20:34:06.601Z,1571949246.601 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 178.761930 min 2019-10-24T20:34:06.602Z,1571949246.602 [Default:CheckIn:E] Stopped 2019-10-24T20:34:06.602Z,1571949246.602 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-10-24T20:34:06.602Z,1571949246.602 [Default:CheckIn] Stopped 2019-10-24T20:34:06.602Z,1571949246.602 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-10-24T20:34:06.602Z,1571949246.602 [Default:CheckIn](INFO): Running loop #32 2019-10-24T20:34:06.602Z,1571949246.602 [Default:CheckIn] Running Loop=32 2019-10-24T20:34:06.602Z,1571949246.602 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-10-24T20:34:06.602Z,1571949246.602 [Default:CheckIn:Read_GPS] Running Loop=1 2019-10-24T20:34:39.341Z,1571949279.341 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2019-10-24T20:34:39.417Z,1571949279.417 [NAL9602](FAULT): received: +CSQ:0 OK409, 2, 0, 0, 0 OK 2019-10-24T20:34:39.417Z,1571949279.417 [NAL9602] Data Fault, FailCount= 1 2019-10-24T20:34:39.417Z,1571949279.417 [NAL9602](ERROR): Data Fault 2019-10-24T20:34:39.454Z,1571949279.454 [CBIT](ERROR): Data Fault in component: NAL9602 2019-10-24T20:34:39.690Z,1571949279.690 [NAL9602](INFO): Powering down 2019-10-24T20:34:40.543Z,1571949280.543 [CBIT](INFO): Clearing failed state for component NAL9602 2019-10-24T20:34:40.543Z,1571949280.543 [NAL9602] No Fault, FailCount= 1 2019-10-24T20:35:09.990Z,1571949309.990 [NAL9602](INFO): Powering up NAL9602 2019-10-24T20:35:20.906Z,1571949320.906 [NAL9602](INFO): NAL9602 initialized 2019-10-24T20:39:06.763Z,1571949546.763 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-10-24T20:34:06.6Z 2019-10-24T20:39:06.763Z,1571949546.763 [Default:CheckIn:Read_GPS] Stopped 2019-10-24T20:39:06.763Z,1571949546.763 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-10-24T20:39:11.178Z,1571949551.178 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-10-24T20:39:14.580Z,1571949554.580 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20191024T175536/Courier0084.lzma 2019-10-24T20:39:16.586Z,1571949556.586 [DataOverHttps](INFO): Moved sent file to Logs/20191024T175536/Courier0084.lzma.bak 2019-10-24T20:39:16.587Z,1571949556.587 [DataOverHttps](INFO): SBD MOMSN=11952508 2019-10-24T20:39:33.508Z,1571949573.508 [DataOverHttps](INFO): Sending 166 bytes from file Logs/20191024T175536/Express0085.lzma 2019-10-24T20:39:35.514Z,1571949575.514 [DataOverHttps](INFO): Moved sent file to Logs/20191024T175536/Express0085.lzma.bak 2019-10-24T20:39:35.515Z,1571949575.515 [DataOverHttps](INFO): SBD MOMSN=11952510 2019-10-24T20:39:37.473Z,1571949577.473 [Default:CheckIn:Read_Iridium] Stopped 2019-10-24T20:39:37.473Z,1571949577.473 [Default:CheckIn:C.Wait] Running Loop=1 2019-10-24T20:39:37.473Z,1571949577.473 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-10-24T20:39:41.886Z,1571949581.886 [NAL9602](INFO): Not Powering down - fast GPS 2019-10-24T20:44:38.042Z,1571949878.042 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-10-24T20:44:38.042Z,1571949878.042 [Default:CheckIn:C.Wait] Stopped 2019-10-24T20:44:38.042Z,1571949878.042 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-10-24T20:44:38.042Z,1571949878.042 [Default:CheckIn:D] Running Loop=1 2019-10-24T20:44:38.457Z,1571949878.457 [Default:CheckIn:D] Stopped 2019-10-24T20:44:38.457Z,1571949878.457 [Default:CheckIn:E] Running Loop=1 2019-10-24T20:44:38.862Z,1571949878.862 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 189.298926 min 2019-10-24T20:44:38.862Z,1571949878.862 [Default:CheckIn:E] Stopped 2019-10-24T20:44:38.862Z,1571949878.862 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-10-24T20:44:38.862Z,1571949878.862 [Default:CheckIn] Stopped 2019-10-24T20:44:38.863Z,1571949878.863 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-10-24T20:44:38.863Z,1571949878.863 [Default:CheckIn](INFO): Running loop #33 2019-10-24T20:44:38.863Z,1571949878.863 [Default:CheckIn] Running Loop=33 2019-10-24T20:44:38.863Z,1571949878.863 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-10-24T20:44:38.863Z,1571949878.863 [Default:CheckIn:Read_GPS] Running Loop=1 2019-10-24T20:44:40.436Z,1571949880.436 [NAL9602](FAULT): GPS failed to acquire within timeout. 2019-10-24T20:44:40.436Z,1571949880.436 [NAL9602] Data Fault, FailCount= 2 2019-10-24T20:44:40.436Z,1571949880.436 [NAL9602](ERROR): Data Fault 2019-10-24T20:44:40.485Z,1571949880.485 [CBIT](ERROR): Data Fault in component: NAL9602 2019-10-24T20:44:40.842Z,1571949880.842 [NAL9602](INFO): Powering down 2019-10-24T20:44:41.691Z,1571949881.691 [CBIT](INFO): Clearing failed state for component NAL9602 2019-10-24T20:44:41.692Z,1571949881.692 [NAL9602] No Fault, FailCount= 2 2019-10-24T20:45:11.142Z,1571949911.142 [NAL9602](INFO): Powering up NAL9602 2019-10-24T20:45:22.060Z,1571949922.060 [NAL9602](INFO): NAL9602 initialized 2019-10-24T20:46:09.134Z,1571949969.134 [CommandLine](IMPORTANT): got command quit 2019-10-24T20:46:10.141Z,1571949970.141 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2019-10-24T20:46:10.141Z,1571949970.141 [CommandLine ThreadHandler](INFO): Thread cancelled. 2019-10-24T20:46:10.165Z,1571949970.165 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2019-10-24T20:46:10.165Z,1571949970.165 [CommandLine ThreadHandler](INFO): Thread cancelled. 2019-10-24T20:46:10.166Z,1571949970.166 [CommandLine](INFO): Join timeout helper Thread ID is 3795 2019-10-24T20:46:10.166Z,1571949970.166 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2019-10-24T20:46:10.166Z,1571949970.166 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2019-10-24T20:46:10.167Z,1571949970.167 [NavChartDb](INFO): Join timeout helper Thread ID is 3796 2019-10-24T20:46:10.397Z,1571949970.397 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2019-10-24T20:46:10.397Z,1571949970.397 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2019-10-24T20:46:10.405Z,1571949970.405 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2019-10-24T20:46:10.405Z,1571949970.405 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2019-10-24T20:46:10.405Z,1571949970.405 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 3797 2019-10-24T20:46:10.817Z,1571949970.817 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2019-10-24T20:46:10.817Z,1571949970.817 [WetLabsBB2FL](INFO): Powering down 2019-10-24T20:46:10.818Z,1571949970.818 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2019-10-24T20:46:10.829Z,1571949970.829 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler 2019-10-24T20:46:10.829Z,1571949970.829 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2019-10-24T20:46:10.829Z,1571949970.829 [CTD_Seabird](INFO): Join timeout helper Thread ID is 3798 2019-10-24T20:46:11.581Z,1571949971.581 [CTD_Seabird](INFO): Powering down 2019-10-24T20:46:11.593Z,1571949971.593 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread. 2019-10-24T20:46:11.593Z,1571949971.593 [CTD_Seabird](INFO): Powering down 2019-10-24T20:46:11.605Z,1571949971.605 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2019-10-24T20:46:11.621Z,1571949971.621 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2019-10-24T20:46:11.621Z,1571949971.621 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2019-10-24T20:46:11.621Z,1571949971.621 [Radio_Surface](INFO): Join timeout helper Thread ID is 3799 2019-10-24T20:46:11.989Z,1571949971.989 [Radio_Surface](INFO): Powering down 2019-10-24T20:46:11.990Z,1571949971.990 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2019-10-24T20:46:11.990Z,1571949971.990 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2019-10-24T20:46:12.009Z,1571949972.009 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler 2019-10-24T20:46:12.009Z,1571949972.009 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2019-10-24T20:46:12.010Z,1571949972.010 [DataOverHttps](INFO): Join timeout helper Thread ID is 3800 2019-10-24T20:46:12.125Z,1571949972.125 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread. 2019-10-24T20:46:12.125Z,1571949972.125 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2019-10-24T20:46:12.130Z,1571949972.130 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2019-10-24T20:46:12.130Z,1571949972.130 [logger ThreadHandler](INFO): Thread cancelled. 2019-10-24T20:46:12.130Z,1571949972.130 [logger](INFO): Join timeout helper Thread ID is 3801 2019-10-24T20:46:12.157Z,1571949972.157 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2019-10-24T20:46:12.159Z,1571949972.159 [logger ThreadHandler](INFO): Thread cancelled. 2019-10-24T20:46:12.168Z,1571949972.168 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2019-10-24T20:46:12.169Z,1571949972.169 [CommandLine ThreadHandler](INFO): Thread cancelled. 2019-10-24T20:46:12.169Z,1571949972.169 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2019-10-24T20:46:12.169Z,1571949972.169 [controlThread ThreadHandler](INFO): Thread cancelled. 2019-10-24T20:46:12.170Z,1571949972.170 [controlThread](INFO): Join timeout helper Thread ID is 3802 2019-10-24T20:46:12.194Z,1571949972.194 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2019-10-24T20:46:12.194Z,1571949972.194 [controlThread](DEBUG): Uninitializing ControlThread 2019-10-24T20:46:12.194Z,1571949972.194 [AHRS_M2](INFO): Powering down 2019-10-24T20:46:12.265Z,1571949972.265 [NAL9602](INFO): Powering down 2019-10-24T20:46:12.267Z,1571949972.267 [Aanderaa_O2](INFO): Powering down 2019-10-24T20:46:12.269Z,1571949972.269 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator. 2019-10-24T20:46:12.270Z,1571949972.270 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator. 2019-10-24T20:46:12.270Z,1571949972.270 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2019-10-24T20:46:12.271Z,1571949972.271 [MissionManager](INFO): Uninitializing Mission Default 2019-10-24T20:46:12.271Z,1571949972.271 [Default] Stopped 2019-10-24T20:46:12.271Z,1571949972.271 [Default](DEBUG): Aggregate::uninitialize Default 2019-10-24T20:46:12.271Z,1571949972.271 [Default:B.GoToSurface] Stopped 2019-10-24T20:46:12.271Z,1571949972.271 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2019-10-24T20:46:12.271Z,1571949972.271 [Default:CheckIn] Stopped 2019-10-24T20:46:12.271Z,1571949972.271 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-10-24T20:46:12.272Z,1571949972.272 [Default:CheckIn:Read_GPS] Stopped 2019-10-24T20:46:12.274Z,1571949972.274 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2019-10-24T20:46:12.274Z,1571949972.274 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2019-10-24T20:46:12.274Z,1571949972.274 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2019-10-24T20:46:12.275Z,1571949972.275 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2019-10-24T20:46:12.275Z,1571949972.275 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2019-10-24T20:46:12.275Z,1571949972.275 [BuoyancyServo](INFO): Powering down 2019-10-24T20:46:12.289Z,1571949972.289 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2019-10-24T20:46:12.289Z,1571949972.289 [ElevatorServo](INFO): Powering down 2019-10-24T20:46:12.290Z,1571949972.290 [MassServo](DEBUG): Uninitialize Mass Servo. 2019-10-24T20:46:12.290Z,1571949972.290 [MassServo](INFO): Powering down 2019-10-24T20:46:12.291Z,1571949972.291 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2019-10-24T20:46:12.291Z,1571949972.291 [RudderServo](INFO): Powering down 2019-10-24T20:46:12.292Z,1571949972.292 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2019-10-24T20:46:12.292Z,1571949972.292 [ThrusterServo](INFO): Powering down 2019-10-24T20:46:12.293Z,1571949972.293 [SBIT](DEBUG): Uninitialize SBIT Component. 2019-10-24T20:46:12.293Z,1571949972.293 [IBIT](DEBUG): Uninitialize IBIT Component. 2019-10-24T20:46:12.293Z,1571949972.293 [CBIT](DEBUG): Uninitialize CBIT Component. 2019-10-24T20:46:12.293Z,1571949972.293 [CBIT](DEBUG): Powering off loads. 2019-10-24T20:46:12.305Z,1571949972.305 [CBIT](DEBUG): Disabling WDT. 2019-10-24T20:46:12.317Z,1571949972.317 [CBIT](DEBUG): Opening all GF detection circuits. 2019-10-24T20:46:12.318Z,1571949972.318 [controlThread ThreadHandler](INFO): Thread cancelled. 2019-10-24T20:46:12.400Z,1571949972.400 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2019-10-24T20:46:12.406Z,1571949972.406 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2019-10-24T20:46:12.436Z,1571949972.436 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2019-10-24T20:46:12.439Z,1571949972.439 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2019-10-24T20:46:12.475Z,1571949972.475 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2019-10-24T20:46:12.548Z,1571949972.548 [logger ThreadHandler](INFO): Thread cancelled.