2019-05-08T18:54:39.479Z,1557341679.479 [CommandLine](IMPORTANT): got command restart logs 2019-05-08T18:54:44.834Z,1557341684.834 [Default:A.Wait](INFO): Done Waiting. 2019-05-08T18:54:44.834Z,1557341684.834 [Default:A.Wait] Stopped 2019-05-08T18:54:44.834Z,1557341684.834 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2019-05-08T18:54:45.230Z,1557341685.230 [Default:CheckIn] Running Loop=1 2019-05-08T18:54:45.230Z,1557341685.230 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-05-08T18:54:45.230Z,1557341685.230 [Default:CheckIn:Read_GPS] Running Loop=1 2019-05-08T18:54:46.830Z,1557341686.830 [NAL9602](DEBUG): Fix Requested 2019-05-08T18:54:47.222Z,1557341687.222 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,185312.00,A,3648.15052,N,12147.19848,W,0.039,0.00,080519,,,D*7D 2019-05-08T18:54:47.224Z,1557341687.224 [NAL9602](INFO): GPS fix at 20190508T185312: (36.802509, -121.786641) 2019-05-08T18:54:47.254Z,1557341687.254 [Default:CheckIn:Read_GPS] Stopped 2019-05-08T18:54:47.254Z,1557341687.254 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-05-08T18:54:53.298Z,1557341693.298 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190508T181315/Courier0022.lzma 2019-05-08T18:54:54.104Z,1557341694.104 [DataOverHttps](INFO): Moved sent file to Logs/20190508T181315/Courier0022.lzma.bak 2019-05-08T18:54:54.104Z,1557341694.104 [DataOverHttps](INFO): SBD MOMSN=10975874 2019-05-08T18:55:05.903Z,1557341705.903 [DataOverHttps](INFO): Sending 212 bytes from file Logs/20190508T185439/Courier0000.lzma 2019-05-08T18:55:06.708Z,1557341706.708 [DataOverHttps](INFO): Moved sent file to Logs/20190508T185439/Courier0000.lzma.bak 2019-05-08T18:55:06.708Z,1557341706.708 [DataOverHttps](INFO): SBD MOMSN=10975876 2019-05-08T18:55:09.162Z,1557341709.162 [NAL9602](INFO): SBD MO Status=0, MOMSN=3885, MT Status=0, MTMSN=0 2019-05-08T18:55:09.162Z,1557341709.162 [NAL9602](INFO): No messages in MT queue 2019-05-08T18:55:19.935Z,1557341719.935 [DataOverHttps](INFO): Sending 897 bytes from file Logs/20190508T181315/Express0023.lzma 2019-05-08T18:55:20.740Z,1557341720.740 [DataOverHttps](INFO): Moved sent file to Logs/20190508T181315/Express0023.lzma.bak 2019-05-08T18:55:20.740Z,1557341720.740 [DataOverHttps](INFO): SBD MOMSN=10975880 2019-05-08T18:55:33.652Z,1557341733.652 [DataOverHttps](INFO): Sending 384 bytes from file Logs/20190508T185439/Express0001.lzma 2019-05-08T18:55:34.452Z,1557341734.452 [DataOverHttps](INFO): Moved sent file to Logs/20190508T185439/Express0001.lzma.bak 2019-05-08T18:55:34.452Z,1557341734.452 [DataOverHttps](INFO): SBD MOMSN=10975890 2019-05-08T18:55:35.474Z,1557341735.474 [Default:CheckIn:Read_Iridium] Stopped 2019-05-08T18:55:35.475Z,1557341735.475 [Default:CheckIn:C.Wait] Running Loop=1 2019-05-08T18:55:35.475Z,1557341735.475 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-05-08T18:55:39.872Z,1557341739.872 [NAL9602](INFO): Not Powering down - fast GPS 2019-05-08T18:57:00.708Z,1557341820.708 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2019-05-08T18:57:00.708Z,1557341820.708 [RDI_Pathfinder](ERROR): Failed to parse: :TS,19050812043 0.0,1448.9, 0 2019-05-08T19:00:36.032Z,1557342036.032 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-05-08T19:00:36.032Z,1557342036.032 [Default:CheckIn:C.Wait] Stopped 2019-05-08T19:00:36.032Z,1557342036.032 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-05-08T19:00:36.033Z,1557342036.033 [Default:CheckIn:D] Running Loop=1 2019-05-08T19:00:36.445Z,1557342036.445 [Default:CheckIn:D] Stopped 2019-05-08T19:00:36.445Z,1557342036.445 [Default:CheckIn:E] Running Loop=1 2019-05-08T19:00:36.842Z,1557342036.842 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 6.082444 min 2019-05-08T19:00:36.842Z,1557342036.842 [Default:CheckIn:E] Stopped 2019-05-08T19:00:36.842Z,1557342036.842 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-05-08T19:00:36.842Z,1557342036.842 [Default:CheckIn] Stopped 2019-05-08T19:00:36.843Z,1557342036.843 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-05-08T19:00:36.843Z,1557342036.843 [Default:CheckIn](INFO): Running loop #2 2019-05-08T19:00:36.843Z,1557342036.843 [Default:CheckIn] Running Loop=2 2019-05-08T19:00:36.843Z,1557342036.843 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-05-08T19:00:36.843Z,1557342036.843 [Default:CheckIn:Read_GPS] Running Loop=1 2019-05-08T19:00:38.442Z,1557342038.442 [NAL9602](DEBUG): Fix Requested 2019-05-08T19:00:38.834Z,1557342038.834 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,185904.00,A,3648.14974,N,12147.19779,W,0.156,0.00,080519,,,D*79 2019-05-08T19:00:38.836Z,1557342038.836 [NAL9602](INFO): GPS fix at 20190508T185904: (36.802496, -121.786630) 2019-05-08T19:00:38.887Z,1557342038.887 [Default:CheckIn:Read_GPS] Stopped 2019-05-08T19:00:38.888Z,1557342038.888 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-05-08T19:00:45.182Z,1557342045.182 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20190508T185439/Courier0003.lzma 2019-05-08T19:00:45.988Z,1557342045.988 [DataOverHttps](INFO): Moved sent file to Logs/20190508T185439/Courier0003.lzma.bak 2019-05-08T19:00:45.988Z,1557342045.988 [DataOverHttps](INFO): SBD MOMSN=10975946 2019-05-08T19:00:58.431Z,1557342058.431 [DataOverHttps](INFO): Sending 739 bytes from file Logs/20190508T185439/Express0004.lzma 2019-05-08T19:00:59.236Z,1557342059.236 [DataOverHttps](INFO): Moved sent file to Logs/20190508T185439/Express0004.lzma.bak 2019-05-08T19:00:59.236Z,1557342059.236 [DataOverHttps](INFO): SBD MOMSN=10975949 2019-05-08T19:01:00.273Z,1557342060.273 [Default:CheckIn:Read_Iridium] Stopped 2019-05-08T19:01:00.273Z,1557342060.273 [Default:CheckIn:C.Wait] Running Loop=1 2019-05-08T19:01:00.273Z,1557342060.273 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-05-08T19:01:03.886Z,1557342063.886 [NAL9602](INFO): SBD MO Status=0, MOMSN=3886, MT Status=0, MTMSN=0 2019-05-08T19:01:03.886Z,1557342063.886 [NAL9602](INFO): No messages in MT queue 2019-05-08T19:01:34.588Z,1557342094.588 [NAL9602](INFO): Not Powering down - fast GPS 2019-05-08T19:02:24.705Z,1557342144.705 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2019-05-08T19:02:24.705Z,1557342144.705 [RDI_Pathfinder](ERROR): Failed to parse: :TS2100148,35.0, -0.1, 0.0,1448.9, 0 2019-05-08T19:03:00.693Z,1557342180.693 [RDI_Pathfinder](ERROR): only read 0 of 4 data items 2019-05-08T19:03:00.693Z,1557342180.693 [RDI_Pathfinder](ERROR): Failed to parse: :RA, 0.008,V 2019-05-08T19:06:00.856Z,1557342360.856 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-05-08T19:06:00.856Z,1557342360.856 [Default:CheckIn:C.Wait] Stopped 2019-05-08T19:06:00.856Z,1557342360.856 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-05-08T19:06:00.856Z,1557342360.856 [Default:CheckIn:D] Running Loop=1 2019-05-08T19:06:01.261Z,1557342361.261 [Default:CheckIn:D] Stopped 2019-05-08T19:06:01.261Z,1557342361.261 [Default:CheckIn:E] Running Loop=1 2019-05-08T19:06:01.677Z,1557342361.677 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 11.496043 min 2019-05-08T19:06:01.677Z,1557342361.677 [Default:CheckIn:E] Stopped 2019-05-08T19:06:01.678Z,1557342361.678 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-05-08T19:06:01.678Z,1557342361.678 [Default:CheckIn] Stopped 2019-05-08T19:06:01.678Z,1557342361.678 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-05-08T19:06:01.678Z,1557342361.678 [Default:CheckIn](INFO): Running loop #3 2019-05-08T19:06:01.678Z,1557342361.678 [Default:CheckIn] Running Loop=3 2019-05-08T19:06:01.678Z,1557342361.678 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-05-08T19:06:01.678Z,1557342361.678 [Default:CheckIn:Read_GPS] Running Loop=1 2019-05-08T19:06:03.270Z,1557342363.270 [NAL9602](DEBUG): Fix Requested 2019-05-08T19:06:03.662Z,1557342363.662 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190428.00,A,3648.14035,N,12147.20597,W,0.058,264.98,080519,,,D*74 2019-05-08T19:06:03.664Z,1557342363.664 [NAL9602](INFO): GPS fix at 20190508T190428: (36.802339, -121.786766) 2019-05-08T19:06:03.698Z,1557342363.698 [Default:CheckIn:Read_GPS] Stopped 2019-05-08T19:06:03.698Z,1557342363.698 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-05-08T19:06:05.024Z,1557342365.024 [NAL9602](ERROR): parseGSV uart error: serial buffer full 2019-05-08T19:06:09.677Z,1557342369.677 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20190508T185439/Courier0006.lzma 2019-05-08T19:06:10.476Z,1557342370.476 [DataOverHttps](INFO): Moved sent file to Logs/20190508T185439/Courier0006.lzma.bak 2019-05-08T19:06:10.476Z,1557342370.476 [DataOverHttps](INFO): SBD MOMSN=10975993 2019-05-08T19:06:22.771Z,1557342382.771 [DataOverHttps](INFO): Sending 654 bytes from file Logs/20190508T185439/Express0007.lzma 2019-05-08T19:06:23.576Z,1557342383.576 [DataOverHttps](INFO): Moved sent file to Logs/20190508T185439/Express0007.lzma.bak 2019-05-08T19:06:23.576Z,1557342383.576 [DataOverHttps](INFO): SBD MOMSN=10975996 2019-05-08T19:06:24.849Z,1557342384.849 [Default:CheckIn:Read_Iridium] Stopped 2019-05-08T19:06:24.849Z,1557342384.849 [Default:CheckIn:C.Wait] Running Loop=1 2019-05-08T19:06:24.850Z,1557342384.850 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-05-08T19:06:30.484Z,1557342390.484 [RDI_Pathfinder](ERROR): Failed to parse: :SA, +0.00, +0.00, 0.00 2019-05-08T19:06:42.596Z,1557342402.596 [NAL9602](INFO): SBD MO Status=2, MOMSN=3887, MT Status=2, MTMSN=0 2019-05-08T19:06:42.597Z,1557342402.597 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-05-08T19:07:11.713Z,1557342431.713 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2019-05-08T19:07:11.713Z,1557342431.713 [RDI_Pathfinder](ERROR): Failed to parse: :TS,19050812144848,35.0, -0.1, 0.0,1448.9A, 0.00, 0.00, 0.00, 0.00, 0.00 2019-05-08T19:07:26.628Z,1557342446.628 [NAL9602](INFO): SBD MO Status=0, MOMSN=3887, MT Status=0, MTMSN=0 2019-05-08T19:07:26.628Z,1557342446.628 [NAL9602](INFO): No messages in MT queue 2019-05-08T19:07:57.352Z,1557342477.352 [NAL9602](INFO): Not Powering down - fast GPS 2019-05-08T19:10:06.685Z,1557342606.685 [RDI_Pathfinder](ERROR): only read 3 of 4 data items 2019-05-08T19:10:06.685Z,1557342606.685 [RDI_Pathfinder](ERROR): Failed to parse: :RA, 0.00, 0.00, 0.00, 0.00 2019-05-08T19:10:31.699Z,1557342631.699 [RDI_Pathfinder](ERROR): Failed to parse: 00, 0.00, 0.00, 0.00, 0.00 2019-05-08T19:11:25.434Z,1557342685.434 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-05-08T19:11:25.434Z,1557342685.434 [Default:CheckIn:C.Wait] Stopped 2019-05-08T19:11:25.434Z,1557342685.434 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-05-08T19:11:25.435Z,1557342685.435 [Default:CheckIn:D] Running Loop=1 2019-05-08T19:11:25.853Z,1557342685.853 [Default:CheckIn:D] Stopped 2019-05-08T19:11:25.853Z,1557342685.853 [Default:CheckIn:E] Running Loop=1 2019-05-08T19:11:26.246Z,1557342686.246 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 16.905910 min 2019-05-08T19:11:26.246Z,1557342686.246 [Default:CheckIn:E] Stopped 2019-05-08T19:11:26.246Z,1557342686.246 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-05-08T19:11:26.246Z,1557342686.246 [Default:CheckIn] Stopped 2019-05-08T19:11:26.246Z,1557342686.246 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-05-08T19:11:26.247Z,1557342686.247 [Default:CheckIn](INFO): Running loop #4 2019-05-08T19:11:26.247Z,1557342686.247 [Default:CheckIn] Running Loop=4 2019-05-08T19:11:26.247Z,1557342686.247 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-05-08T19:11:26.247Z,1557342686.247 [Default:CheckIn:Read_GPS] Running Loop=1 2019-05-08T19:11:27.859Z,1557342687.859 [NAL9602](DEBUG): Fix Requested 2019-05-08T19:11:28.254Z,1557342688.254 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190953.00,A,3648.13912,N,12147.20810,W,0.019,319.26,080519,,,D*77 2019-05-08T19:11:28.260Z,1557342688.260 [NAL9602](INFO): GPS fix at 20190508T190953: (36.802319, -121.786802) 2019-05-08T19:11:28.359Z,1557342688.359 [Default:CheckIn:Read_GPS] Stopped 2019-05-08T19:11:28.359Z,1557342688.359 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-05-08T19:11:29.876Z,1557342689.876 [NAL9602](ERROR): parseGSV uart error: serial buffer full 2019-05-08T19:11:34.518Z,1557342694.518 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20190508T185439/Courier0009.lzma 2019-05-08T19:11:35.324Z,1557342695.324 [DataOverHttps](INFO): Moved sent file to Logs/20190508T185439/Courier0009.lzma.bak 2019-05-08T19:11:35.324Z,1557342695.324 [DataOverHttps](INFO): SBD MOMSN=10976063 2019-05-08T19:11:39.550Z,1557342699.550 [NAL9602](INFO): SBD MO Status=0, MOMSN=3888, MT Status=0, MTMSN=0 2019-05-08T19:11:39.550Z,1557342699.550 [NAL9602](INFO): No messages in MT queue 2019-05-08T19:11:47.936Z,1557342707.936 [DataOverHttps](INFO): Sending 572 bytes from file Logs/20190508T185439/Express0010.lzma 2019-05-08T19:11:48.692Z,1557342708.692 [DataOverHttps](INFO): Moved sent file to Logs/20190508T185439/Express0010.lzma.bak 2019-05-08T19:11:48.692Z,1557342708.692 [DataOverHttps](INFO): SBD MOMSN=10976066 2019-05-08T19:11:49.686Z,1557342709.686 [Default:CheckIn:Read_Iridium] Stopped 2019-05-08T19:11:49.686Z,1557342709.686 [Default:CheckIn:C.Wait] Running Loop=1 2019-05-08T19:11:49.686Z,1557342709.686 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-05-08T19:11:51.698Z,1557342711.698 [RDI_Pathfinder](ERROR): only read 3 of 4 data items 2019-05-08T19:11:51.698Z,1557342711.698 [RDI_Pathfinder](ERROR): Failed to parse: :RA, 0.00, 0.00, 0.00, 0.00 2019-05-08T19:12:10.256Z,1557342730.256 [NAL9602](INFO): Not Powering down - fast GPS 2019-05-08T19:16:50.254Z,1557343010.254 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-05-08T19:16:50.254Z,1557343010.254 [Default:CheckIn:C.Wait] Stopped 2019-05-08T19:16:50.254Z,1557343010.254 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-05-08T19:16:50.255Z,1557343010.255 [Default:CheckIn:D] Running Loop=1 2019-05-08T19:16:50.674Z,1557343010.674 [Default:CheckIn:D] Stopped 2019-05-08T19:16:50.674Z,1557343010.674 [Default:CheckIn:E] Running Loop=1 2019-05-08T19:16:51.074Z,1557343011.074 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 22.319592 min 2019-05-08T19:16:51.074Z,1557343011.074 [Default:CheckIn:E] Stopped 2019-05-08T19:16:51.074Z,1557343011.074 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-05-08T19:16:51.075Z,1557343011.075 [Default:CheckIn] Stopped 2019-05-08T19:16:51.075Z,1557343011.075 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-05-08T19:16:51.075Z,1557343011.075 [Default:CheckIn](INFO): Running loop #5 2019-05-08T19:16:51.075Z,1557343011.075 [Default:CheckIn] Running Loop=5 2019-05-08T19:16:51.075Z,1557343011.075 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-05-08T19:16:51.075Z,1557343011.075 [Default:CheckIn:Read_GPS] Running Loop=1 2019-05-08T19:16:52.666Z,1557343012.666 [NAL9602](DEBUG): Fix Requested 2019-05-08T19:16:53.059Z,1557343013.059 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,191518.00,A,3648.13582,N,12147.21711,W,2.430,230.50,080519,,,D*79 2019-05-08T19:16:53.061Z,1557343013.061 [NAL9602](INFO): GPS fix at 20190508T191518: (36.802264, -121.786952) 2019-05-08T19:16:53.089Z,1557343013.089 [Default:CheckIn:Read_GPS] Stopped 2019-05-08T19:16:53.089Z,1557343013.089 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-05-08T19:16:55.099Z,1557343015.099 [NAL9602](ERROR): parseGSV uart error: serial buffer full 2019-05-08T19:16:59.434Z,1557343019.434 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20190508T185439/Courier0012.lzma 2019-05-08T19:17:00.240Z,1557343020.240 [DataOverHttps](INFO): Moved sent file to Logs/20190508T185439/Courier0012.lzma.bak 2019-05-08T19:17:00.240Z,1557343020.240 [DataOverHttps](INFO): SBD MOMSN=10976169 2019-05-08T19:17:10.833Z,1557343030.833 [NAL9602](INFO): SBD MO Status=0, MOMSN=3889, MT Status=0, MTMSN=0 2019-05-08T19:17:10.833Z,1557343030.833 [NAL9602](INFO): No messages in MT queue 2019-05-08T19:17:12.639Z,1557343032.639 [DataOverHttps](INFO): Sending 556 bytes from file Logs/20190508T185439/Express0013.lzma 2019-05-08T19:17:13.444Z,1557343033.444 [DataOverHttps](INFO): Moved sent file to Logs/20190508T185439/Express0013.lzma.bak 2019-05-08T19:17:13.444Z,1557343033.444 [DataOverHttps](INFO): SBD MOMSN=10976173 2019-05-08T19:17:14.552Z,1557343034.552 [Default:CheckIn:Read_Iridium] Stopped 2019-05-08T19:17:14.552Z,1557343034.552 [Default:CheckIn:C.Wait] Running Loop=1 2019-05-08T19:17:14.552Z,1557343034.552 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-05-08T19:17:41.538Z,1557343061.538 [NAL9602](INFO): Not Powering down - fast GPS 2019-05-08T19:22:15.077Z,1557343335.077 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-05-08T19:22:15.077Z,1557343335.077 [Default:CheckIn:C.Wait] Stopped 2019-05-08T19:22:15.077Z,1557343335.077 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-05-08T19:22:15.078Z,1557343335.078 [Default:CheckIn:D] Running Loop=1 2019-05-08T19:22:15.480Z,1557343335.480 [Default:CheckIn:D] Stopped 2019-05-08T19:22:15.480Z,1557343335.480 [Default:CheckIn:E] Running Loop=1 2019-05-08T19:22:15.896Z,1557343335.896 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 27.733018 min 2019-05-08T19:22:15.896Z,1557343335.896 [Default:CheckIn:E] Stopped 2019-05-08T19:22:15.896Z,1557343335.896 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-05-08T19:22:15.896Z,1557343335.896 [Default:CheckIn] Stopped 2019-05-08T19:22:15.897Z,1557343335.897 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-05-08T19:22:15.897Z,1557343335.897 [Default:CheckIn](INFO): Running loop #6 2019-05-08T19:22:15.897Z,1557343335.897 [Default:CheckIn] Running Loop=6 2019-05-08T19:22:15.897Z,1557343335.897 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-05-08T19:22:15.897Z,1557343335.897 [Default:CheckIn:Read_GPS] Running Loop=1 2019-05-08T19:22:17.490Z,1557343337.490 [NAL9602](DEBUG): Fix Requested 2019-05-08T19:22:17.879Z,1557343337.879 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,192043.00,A,3648.17134,N,12147.28047,W,1.166,290.14,080519,,,D*7E 2019-05-08T19:22:17.881Z,1557343337.881 [NAL9602](INFO): GPS fix at 20190508T192043: (36.802856, -121.788008) 2019-05-08T19:22:17.909Z,1557343337.909 [Default:CheckIn:Read_GPS] Stopped 2019-05-08T19:22:17.909Z,1557343337.909 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-05-08T19:22:24.022Z,1557343344.022 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20190508T185439/Courier0015.lzma 2019-05-08T19:22:24.828Z,1557343344.828 [DataOverHttps](INFO): Moved sent file to Logs/20190508T185439/Courier0015.lzma.bak 2019-05-08T19:22:24.828Z,1557343344.828 [DataOverHttps](INFO): SBD MOMSN=10976226 2019-05-08T19:22:37.423Z,1557343357.423 [DataOverHttps](INFO): Sending 573 bytes from file Logs/20190508T185439/Express0016.lzma 2019-05-08T19:22:38.228Z,1557343358.228 [DataOverHttps](INFO): Moved sent file to Logs/20190508T185439/Express0016.lzma.bak 2019-05-08T19:22:38.228Z,1557343358.228 [DataOverHttps](INFO): SBD MOMSN=10976229 2019-05-08T19:22:39.377Z,1557343359.377 [Default:CheckIn:Read_Iridium] Stopped 2019-05-08T19:22:39.377Z,1557343359.377 [Default:CheckIn:C.Wait] Running Loop=1 2019-05-08T19:22:39.377Z,1557343359.377 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-05-08T19:22:43.774Z,1557343363.774 [NAL9602](INFO): SBD MO Status=2, MOMSN=3890, MT Status=2, MTMSN=0 2019-05-08T19:22:43.774Z,1557343363.774 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-05-08T19:27:17.346Z,1557343637.346 [RDI_Pathfinder](ERROR): only read 3 of 4 data items 2019-05-08T19:27:17.347Z,1557343637.347 [RDI_Pathfinder](ERROR): Failed to parse: :RA, 0.00, 0.00, 0.00, 0.00 2019-05-08T19:27:20.515Z,1557343640.515 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-05-08T19:27:39.973Z,1557343659.973 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-05-08T19:27:39.973Z,1557343659.973 [Default:CheckIn:C.Wait] Stopped 2019-05-08T19:27:39.973Z,1557343659.973 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-05-08T19:27:39.974Z,1557343659.974 [Default:CheckIn:D] Running Loop=1 2019-05-08T19:27:40.360Z,1557343660.360 [Default:CheckIn:D] Stopped 2019-05-08T19:27:40.361Z,1557343660.361 [Default:CheckIn:E] Running Loop=1 2019-05-08T19:27:40.742Z,1557343660.742 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 33.147697 min 2019-05-08T19:27:40.742Z,1557343660.742 [Default:CheckIn:E] Stopped 2019-05-08T19:27:40.742Z,1557343660.742 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-05-08T19:27:40.742Z,1557343660.742 [Default:CheckIn] Stopped 2019-05-08T19:27:40.742Z,1557343660.742 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-05-08T19:27:40.743Z,1557343660.743 [Default:CheckIn](INFO): Running loop #7 2019-05-08T19:27:40.743Z,1557343660.743 [Default:CheckIn] Running Loop=7 2019-05-08T19:27:40.743Z,1557343660.743 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-05-08T19:27:40.743Z,1557343660.743 [Default:CheckIn:Read_GPS] Running Loop=1 2019-05-08T19:27:42.359Z,1557343662.359 [NAL9602](DEBUG): Fix Requested 2019-05-08T19:27:42.738Z,1557343662.738 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,192607.00,A,3648.16902,N,12147.27326,W,0.253,121.23,080519,,,A*73 2019-05-08T19:27:42.740Z,1557343662.740 [NAL9602](INFO): GPS fix at 20190508T192607: (36.802817, -121.787888) 2019-05-08T19:27:42.781Z,1557343662.781 [Default:CheckIn:Read_GPS] Stopped 2019-05-08T19:27:42.781Z,1557343662.781 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-05-08T19:27:45.689Z,1557343665.689 [RDI_Pathfinder](ERROR): only read 2 of 4 data items 2019-05-08T19:27:45.690Z,1557343665.690 [RDI_Pathfinder](ERROR): Failed to parse: :BS,-32768,-32768V 2019-05-08T19:27:49.606Z,1557343669.606 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20190508T185439/Courier0018.lzma 2019-05-08T19:27:50.412Z,1557343670.412 [DataOverHttps](INFO): Moved sent file to Logs/20190508T185439/Courier0018.lzma.bak 2019-05-08T19:27:50.412Z,1557343670.412 [DataOverHttps](INFO): SBD MOMSN=10976293 2019-05-08T19:28:02.871Z,1557343682.871 [DataOverHttps](INFO): Sending 680 bytes from file Logs/20190508T185439/Express0019.lzma 2019-05-08T19:28:03.676Z,1557343683.676 [DataOverHttps](INFO): Moved sent file to Logs/20190508T185439/Express0019.lzma.bak 2019-05-08T19:28:03.676Z,1557343683.676 [DataOverHttps](INFO): SBD MOMSN=10976296 2019-05-08T19:28:05.041Z,1557343685.041 [Default:CheckIn:Read_Iridium] Stopped 2019-05-08T19:28:05.041Z,1557343685.041 [Default:CheckIn:C.Wait] Running Loop=1 2019-05-08T19:28:05.042Z,1557343685.042 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-05-08T19:28:15.516Z,1557343695.516 [NAL9602](INFO): Not Powering down - fast GPS 2019-05-08T19:30:13.503Z,1557343813.503 [RDI_Pathfinder](ERROR): only read 1 of 4 data items 2019-05-08T19:30:13.503Z,1557343813.503 [RDI_Pathfinder](ERROR): Failed to parse: :RA, 0.00, 0.8.78 2019-05-08T19:33:05.644Z,1557343985.644 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-05-08T19:33:05.644Z,1557343985.644 [Default:CheckIn:C.Wait] Stopped 2019-05-08T19:33:05.644Z,1557343985.644 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-05-08T19:33:05.645Z,1557343985.645 [Default:CheckIn:D] Running Loop=1 2019-05-08T19:33:06.059Z,1557343986.059 [Default:CheckIn:D] Stopped 2019-05-08T19:33:06.059Z,1557343986.059 [Default:CheckIn:E] Running Loop=1 2019-05-08T19:33:06.428Z,1557343986.428 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 38.575997 min 2019-05-08T19:33:06.428Z,1557343986.428 [Default:CheckIn:E] Stopped 2019-05-08T19:33:06.428Z,1557343986.428 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-05-08T19:33:06.429Z,1557343986.429 [Default:CheckIn] Stopped 2019-05-08T19:33:06.429Z,1557343986.429 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-05-08T19:33:06.429Z,1557343986.429 [Default:CheckIn](INFO): Running loop #8 2019-05-08T19:33:06.429Z,1557343986.429 [Default:CheckIn] Running Loop=8 2019-05-08T19:33:06.429Z,1557343986.429 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-05-08T19:33:06.429Z,1557343986.429 [Default:CheckIn:Read_GPS] Running Loop=1 2019-05-08T19:33:08.042Z,1557343988.042 [NAL9602](DEBUG): Fix Requested 2019-05-08T19:33:08.438Z,1557343988.438 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,193133.00,A,3648.16653,N,12147.28240,W,0.564,151.16,080519,,,A*75 2019-05-08T19:33:08.452Z,1557343988.452 [NAL9602](INFO): GPS fix at 20190508T193133: (36.802776, -121.788040) 2019-05-08T19:33:08.500Z,1557343988.500 [Default:CheckIn:Read_GPS] Stopped 2019-05-08T19:33:08.500Z,1557343988.500 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-05-08T19:33:14.778Z,1557343994.778 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20190508T185439/Courier0021.lzma 2019-05-08T19:33:15.584Z,1557343995.584 [DataOverHttps](INFO): Moved sent file to Logs/20190508T185439/Courier0021.lzma.bak 2019-05-08T19:33:15.584Z,1557343995.584 [DataOverHttps](INFO): SBD MOMSN=10976352 2019-05-08T19:33:30.847Z,1557344010.847 [DataOverHttps](INFO): Sending 555 bytes from file Logs/20190508T185439/Express0022.lzma 2019-05-08T19:33:31.652Z,1557344011.652 [DataOverHttps](INFO): Moved sent file to Logs/20190508T185439/Express0022.lzma.bak 2019-05-08T19:33:31.652Z,1557344011.652 [DataOverHttps](INFO): SBD MOMSN=10976355 2019-05-08T19:33:32.699Z,1557344012.699 [Default:CheckIn:Read_Iridium] Stopped 2019-05-08T19:33:32.699Z,1557344012.699 [Default:CheckIn:C.Wait] Running Loop=1 2019-05-08T19:33:32.699Z,1557344012.699 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-05-08T19:33:39.121Z,1557344019.121 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2019-05-08T19:33:39.202Z,1557344019.202 [NAL9602](FAULT): received: +CSQ:0 OK90, 2, 0, 0, 0 OK 2019-05-08T19:33:39.202Z,1557344019.202 [NAL9602] Data Fault, FailCount= 1 2019-05-08T19:33:39.203Z,1557344019.203 [NAL9602](ERROR): Data Fault 2019-05-08T19:33:39.242Z,1557344019.242 [CBIT](ERROR): Data Fault in component: NAL9602 2019-05-08T19:33:39.524Z,1557344019.524 [NAL9602](INFO): Powering down 2019-05-08T19:33:40.402Z,1557344020.402 [CBIT](INFO): Clearing failed state for component NAL9602 2019-05-08T19:33:40.403Z,1557344020.403 [NAL9602] No Fault, FailCount= 1 2019-05-08T19:34:09.824Z,1557344049.824 [NAL9602](INFO): Powering up NAL9602 2019-05-08T19:34:20.732Z,1557344060.732 [NAL9602](INFO): NAL9602 initialized 2019-05-08T19:34:51.854Z,1557344091.854 [NAL9602](INFO): Not Powering down - fast GPS 2019-05-08T19:35:17.342Z,1557344117.342 [RDI_Pathfinder](ERROR): Failed to parse: :BE,-32768,-32768,-32768,V 2019-05-08T19:36:37.330Z,1557344197.330 [RDI_Pathfinder](ERROR): only read 3 of 4 data items 2019-05-08T19:36:37.330Z,1557344197.330 [RDI_Pathfinder](ERROR): Failed to parse: :RA, 0.00, 0.00, 0.00, 0.00 2019-05-08T19:38:33.264Z,1557344313.264 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-05-08T19:38:33.264Z,1557344313.264 [Default:CheckIn:C.Wait] Stopped 2019-05-08T19:38:33.265Z,1557344313.265 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-05-08T19:38:33.265Z,1557344313.265 [Default:CheckIn:D] Running Loop=1 2019-05-08T19:38:33.682Z,1557344313.682 [Default:CheckIn:D] Stopped 2019-05-08T19:38:33.682Z,1557344313.682 [Default:CheckIn:E] Running Loop=1 2019-05-08T19:38:34.064Z,1557344314.064 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 44.036389 min 2019-05-08T19:38:34.064Z,1557344314.064 [Default:CheckIn:E] Stopped 2019-05-08T19:38:34.064Z,1557344314.064 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-05-08T19:38:34.064Z,1557344314.064 [Default:CheckIn] Stopped 2019-05-08T19:38:34.064Z,1557344314.064 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-05-08T19:38:34.064Z,1557344314.064 [Default:CheckIn](INFO): Running loop #9 2019-05-08T19:38:34.064Z,1557344314.064 [Default:CheckIn] Running Loop=9 2019-05-08T19:38:34.064Z,1557344314.064 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-05-08T19:38:34.065Z,1557344314.065 [Default:CheckIn:Read_GPS] Running Loop=1 2019-05-08T19:38:35.682Z,1557344315.682 [NAL9602](DEBUG): Fix Requested 2019-05-08T19:38:36.067Z,1557344316.067 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,193701.00,A,3648.16672,N,12147.28955,W,0.078,121.69,080519,,,A*79 2019-05-08T19:38:36.069Z,1557344316.069 [NAL9602](INFO): GPS fix at 20190508T193701: (36.802779, -121.788159) 2019-05-08T19:38:36.092Z,1557344316.092 [Default:CheckIn:Read_GPS] Stopped 2019-05-08T19:38:36.092Z,1557344316.092 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-05-08T19:38:38.084Z,1557344318.084 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-05-08T19:38:42.002Z,1557344322.002 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20190508T185439/Courier0024.lzma 2019-05-08T19:38:42.808Z,1557344322.808 [DataOverHttps](INFO): Moved sent file to Logs/20190508T185439/Courier0024.lzma.bak 2019-05-08T19:38:42.808Z,1557344322.808 [DataOverHttps](INFO): SBD MOMSN=10976396 2019-05-08T19:38:55.183Z,1557344335.183 [DataOverHttps](INFO): Sending 602 bytes from file Logs/20190508T185439/Express0025.lzma 2019-05-08T19:38:55.988Z,1557344335.988 [DataOverHttps](INFO): Moved sent file to Logs/20190508T185439/Express0025.lzma.bak 2019-05-08T19:38:55.988Z,1557344335.988 [DataOverHttps](INFO): SBD MOMSN=10976399 2019-05-08T19:38:57.111Z,1557344337.111 [Default:CheckIn:Read_Iridium] Stopped 2019-05-08T19:38:57.111Z,1557344337.111 [Default:CheckIn:C.Wait] Running Loop=1 2019-05-08T19:38:57.111Z,1557344337.111 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-05-08T19:39:08.785Z,1557344348.785 [NAL9602](INFO): Not Powering down - fast GPS 2019-05-08T19:43:38.689Z,1557344618.689 [RDI_Pathfinder](ERROR): Failed to parse: :BI,-32768,-32768,-32768,-32768,V 2019-05-08T19:43:57.696Z,1557344637.696 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-05-08T19:43:57.696Z,1557344637.696 [Default:CheckIn:C.Wait] Stopped 2019-05-08T19:43:57.696Z,1557344637.696 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-05-08T19:43:57.696Z,1557344637.696 [Default:CheckIn:D] Running Loop=1 2019-05-08T19:43:58.099Z,1557344638.099 [Default:CheckIn:D] Stopped 2019-05-08T19:43:58.099Z,1557344638.099 [Default:CheckIn:E] Running Loop=1 2019-05-08T19:43:58.518Z,1557344638.518 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 49.443335 min 2019-05-08T19:43:58.518Z,1557344638.518 [Default:CheckIn:E] Stopped 2019-05-08T19:43:58.518Z,1557344638.518 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-05-08T19:43:58.518Z,1557344638.518 [Default:CheckIn] Stopped 2019-05-08T19:43:58.518Z,1557344638.518 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-05-08T19:43:58.522Z,1557344638.522 [Default:CheckIn](INFO): Running loop #10 2019-05-08T19:43:58.522Z,1557344638.522 [Default:CheckIn] Running Loop=10 2019-05-08T19:43:58.523Z,1557344638.523 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-05-08T19:43:58.523Z,1557344638.523 [Default:CheckIn:Read_GPS] Running Loop=1 2019-05-08T19:44:00.094Z,1557344640.094 [NAL9602](DEBUG): Fix Requested 2019-05-08T19:44:00.490Z,1557344640.490 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194225.00,A,3648.15867,N,12147.28014,W,0.311,121.69,080519,,,A*74 2019-05-08T19:44:00.492Z,1557344640.492 [NAL9602](INFO): GPS fix at 20190508T194225: (36.802644, -121.788002) 2019-05-08T19:44:00.527Z,1557344640.527 [Default:CheckIn:Read_GPS] Stopped 2019-05-08T19:44:00.527Z,1557344640.527 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-05-08T19:44:06.634Z,1557344646.634 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20190508T185439/Courier0027.lzma 2019-05-08T19:44:07.432Z,1557344647.432 [DataOverHttps](INFO): Moved sent file to Logs/20190508T185439/Courier0027.lzma.bak 2019-05-08T19:44:07.432Z,1557344647.432 [DataOverHttps](INFO): SBD MOMSN=10976456 2019-05-08T19:44:20.323Z,1557344660.323 [DataOverHttps](INFO): Sending 638 bytes from file Logs/20190508T185439/Express0028.lzma 2019-05-08T19:44:21.128Z,1557344661.128 [DataOverHttps](INFO): Moved sent file to Logs/20190508T185439/Express0028.lzma.bak 2019-05-08T19:44:21.128Z,1557344661.128 [DataOverHttps](INFO): SBD MOMSN=10976459 2019-05-08T19:44:22.435Z,1557344662.435 [Default:CheckIn:Read_Iridium] Stopped 2019-05-08T19:44:22.435Z,1557344662.435 [Default:CheckIn:C.Wait] Running Loop=1 2019-05-08T19:44:22.435Z,1557344662.435 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-05-08T19:47:46.342Z,1557344866.342 [NAL9602](INFO): SBD MO Status=2, MOMSN=3890, MT Status=2, MTMSN=0 2019-05-08T19:47:46.342Z,1557344866.342 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-05-08T19:49:06.329Z,1557344946.329 [NAL9602](INFO): SBD MO Status=2, MOMSN=3890, MT Status=2, MTMSN=0 2019-05-08T19:49:06.330Z,1557344946.330 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-05-08T19:49:06.732Z,1557344946.732 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-05-08T19:49:22.927Z,1557344962.927 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-05-08T19:49:22.928Z,1557344962.928 [Default:CheckIn:C.Wait] Stopped 2019-05-08T19:49:22.928Z,1557344962.928 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-05-08T19:49:22.928Z,1557344962.928 [Default:CheckIn:D] Running Loop=1 2019-05-08T19:49:23.336Z,1557344963.336 [Default:CheckIn:D] Stopped 2019-05-08T19:49:23.336Z,1557344963.336 [Default:CheckIn:E] Running Loop=1 2019-05-08T19:49:23.758Z,1557344963.758 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 54.863940 min 2019-05-08T19:49:23.758Z,1557344963.758 [Default:CheckIn:E] Stopped 2019-05-08T19:49:23.758Z,1557344963.758 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-05-08T19:49:23.758Z,1557344963.758 [Default:CheckIn] Stopped 2019-05-08T19:49:23.758Z,1557344963.758 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-05-08T19:49:23.762Z,1557344963.762 [Default:CheckIn](INFO): Running loop #11 2019-05-08T19:49:23.762Z,1557344963.762 [Default:CheckIn] Running Loop=11 2019-05-08T19:49:23.763Z,1557344963.763 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-05-08T19:49:23.763Z,1557344963.763 [Default:CheckIn:Read_GPS] Running Loop=1 2019-05-08T19:49:25.330Z,1557344965.330 [NAL9602](DEBUG): Fix Requested 2019-05-08T19:49:25.730Z,1557344965.730 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194750.00,A,3648.16507,N,12147.28311,W,0.175,342.29,080519,,,A*7E 2019-05-08T19:49:25.732Z,1557344965.732 [NAL9602](INFO): GPS fix at 20190508T194750: (36.802751, -121.788052) 2019-05-08T19:49:25.766Z,1557344965.766 [Default:CheckIn:Read_GPS] Stopped 2019-05-08T19:49:25.766Z,1557344965.766 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-05-08T19:49:31.738Z,1557344971.738 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20190508T185439/Courier0030.lzma 2019-05-08T19:49:32.544Z,1557344972.544 [DataOverHttps](INFO): Moved sent file to Logs/20190508T185439/Courier0030.lzma.bak 2019-05-08T19:49:32.544Z,1557344972.544 [DataOverHttps](INFO): SBD MOMSN=10976501 2019-05-08T19:49:44.495Z,1557344984.495 [DataOverHttps](INFO): Sending 644 bytes from file Logs/20190508T185439/Express0031.lzma 2019-05-08T19:49:45.276Z,1557344985.276 [DataOverHttps](INFO): Moved sent file to Logs/20190508T185439/Express0031.lzma.bak 2019-05-08T19:49:45.276Z,1557344985.276 [DataOverHttps](INFO): SBD MOMSN=10976504 2019-05-08T19:49:46.461Z,1557344986.461 [Default:CheckIn:Read_Iridium] Stopped 2019-05-08T19:49:46.462Z,1557344986.462 [Default:CheckIn:C.Wait] Running Loop=1 2019-05-08T19:49:46.462Z,1557344986.462 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-05-08T19:49:58.560Z,1557344998.560 [NAL9602](INFO): Not Powering down - fast GPS 2019-05-08T19:52:32.486Z,1557345152.486 [RDI_Pathfinder](ERROR): only read 2 of 4 data items 2019-05-08T19:52:32.486Z,1557345152.486 [RDI_Pathfinder](ERROR): Failed to parse: :RA, 0.00, 0.00,6 2019-05-08T19:54:47.041Z,1557345287.041 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-05-08T19:54:47.041Z,1557345287.041 [Default:CheckIn:C.Wait] Stopped 2019-05-08T19:54:47.041Z,1557345287.041 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-05-08T19:54:47.044Z,1557345287.044 [Default:CheckIn:D] Running Loop=1 2019-05-08T19:54:47.440Z,1557345287.440 [Default:CheckIn:D] Stopped 2019-05-08T19:54:47.441Z,1557345287.441 [Default:CheckIn:E] Running Loop=1 2019-05-08T19:54:47.837Z,1557345287.837 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 60.265698 min 2019-05-08T19:54:47.837Z,1557345287.837 [Default:CheckIn:E] Stopped 2019-05-08T19:54:47.837Z,1557345287.837 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-05-08T19:54:47.838Z,1557345287.838 [Default:CheckIn] Stopped 2019-05-08T19:54:47.838Z,1557345287.838 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-05-08T19:54:47.838Z,1557345287.838 [Default:CheckIn](INFO): Running loop #12 2019-05-08T19:54:47.838Z,1557345287.838 [Default:CheckIn] Running Loop=12 2019-05-08T19:54:47.838Z,1557345287.838 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-05-08T19:54:47.838Z,1557345287.838 [Default:CheckIn:Read_GPS] Running Loop=1 2019-05-08T19:54:49.434Z,1557345289.434 [NAL9602](DEBUG): Fix Requested 2019-05-08T19:54:49.834Z,1557345289.834 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,195315.00,A,3648.15475,N,12147.28238,W,0.544,342.29,080519,,,A*71 2019-05-08T19:54:49.836Z,1557345289.836 [NAL9602](INFO): GPS fix at 20190508T195315: (36.802579, -121.788040) 2019-05-08T19:54:49.859Z,1557345289.859 [Default:CheckIn:Read_GPS] Stopped 2019-05-08T19:54:49.859Z,1557345289.859 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-05-08T19:54:55.834Z,1557345295.834 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20190508T185439/Courier0033.lzma 2019-05-08T19:54:56.643Z,1557345296.643 [DataOverHttps](INFO): Moved sent file to Logs/20190508T185439/Courier0033.lzma.bak 2019-05-08T19:54:56.644Z,1557345296.644 [DataOverHttps](INFO): SBD MOMSN=10976556 2019-05-08T19:55:09.079Z,1557345309.079 [DataOverHttps](INFO): Sending 572 bytes from file Logs/20190508T185439/Express0034.lzma 2019-05-08T19:55:09.884Z,1557345309.884 [DataOverHttps](INFO): Moved sent file to Logs/20190508T185439/Express0034.lzma.bak 2019-05-08T19:55:09.884Z,1557345309.884 [DataOverHttps](INFO): SBD MOMSN=10976559 2019-05-08T19:55:10.861Z,1557345310.861 [Default:CheckIn:Read_Iridium] Stopped 2019-05-08T19:55:10.861Z,1557345310.861 [Default:CheckIn:C.Wait] Running Loop=1 2019-05-08T19:55:10.861Z,1557345310.861 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-05-08T19:57:24.565Z,1557345444.565 [NAL9602](INFO): SBD MO Status=2, MOMSN=3890, MT Status=2, MTMSN=0 2019-05-08T19:57:24.566Z,1557345444.566 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-05-08T19:57:49.225Z,1557345469.225 [NAL9602](INFO): SBD MO Status=2, MOMSN=3890, MT Status=2, MTMSN=0 2019-05-08T19:57:49.226Z,1557345469.226 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-05-08T19:58:13.072Z,1557345493.072 [NAL9602](INFO): SBD MO Status=2, MOMSN=3890, MT Status=2, MTMSN=0 2019-05-08T19:58:13.072Z,1557345493.072 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-05-08T19:58:42.150Z,1557345522.150 [NAL9602](INFO): SBD MO Status=2, MOMSN=3890, MT Status=2, MTMSN=0 2019-05-08T19:58:42.150Z,1557345522.150 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-05-08T19:59:00.329Z,1557345540.329 [NAL9602](INFO): SBD MO Status=0, MOMSN=3890, MT Status=0, MTMSN=0 2019-05-08T19:59:00.329Z,1557345540.329 [NAL9602](INFO): No messages in MT queue 2019-05-08T19:59:31.028Z,1557345571.028 [NAL9602](INFO): Not Powering down - fast GPS 2019-05-08T20:00:11.472Z,1557345611.472 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-05-08T20:00:11.472Z,1557345611.472 [Default:CheckIn:C.Wait] Stopped 2019-05-08T20:00:11.472Z,1557345611.472 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-05-08T20:00:11.472Z,1557345611.472 [Default:CheckIn:D] Running Loop=1 2019-05-08T20:00:11.873Z,1557345611.873 [Default:CheckIn:D] Stopped 2019-05-08T20:00:11.873Z,1557345611.873 [Default:CheckIn:E] Running Loop=1 2019-05-08T20:00:12.266Z,1557345612.266 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 65.672909 min 2019-05-08T20:00:12.283Z,1557345612.283 [Default:CheckIn:E] Stopped 2019-05-08T20:00:12.283Z,1557345612.283 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-05-08T20:00:12.284Z,1557345612.284 [Default:CheckIn] Stopped 2019-05-08T20:00:12.284Z,1557345612.284 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-05-08T20:00:12.285Z,1557345612.285 [Default:CheckIn](INFO): Running loop #13 2019-05-08T20:00:12.285Z,1557345612.285 [Default:CheckIn] Running Loop=13 2019-05-08T20:00:12.285Z,1557345612.285 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-05-08T20:00:12.285Z,1557345612.285 [Default:CheckIn:Read_GPS] Running Loop=1 2019-05-08T20:00:13.866Z,1557345613.866 [NAL9602](DEBUG): Fix Requested 2019-05-08T20:00:14.266Z,1557345614.266 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,195839.00,A,3648.15812,N,12147.28194,W,0.330,342.29,080519,,,A*79 2019-05-08T20:00:14.268Z,1557345614.268 [NAL9602](INFO): GPS fix at 20190508T195839: (36.802635, -121.788032) 2019-05-08T20:00:14.291Z,1557345614.291 [Default:CheckIn:Read_GPS] Stopped 2019-05-08T20:00:14.292Z,1557345614.292 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-05-08T20:00:20.227Z,1557345620.227 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20190508T185439/Courier0036.lzma 2019-05-08T20:00:21.032Z,1557345621.032 [DataOverHttps](INFO): Moved sent file to Logs/20190508T185439/Courier0036.lzma.bak 2019-05-08T20:00:21.032Z,1557345621.032 [DataOverHttps](INFO): SBD MOMSN=10976606 2019-05-08T20:00:33.415Z,1557345633.415 [DataOverHttps](INFO): Sending 556 bytes from file Logs/20190508T185439/Express0037.lzma 2019-05-08T20:00:34.220Z,1557345634.220 [DataOverHttps](INFO): Moved sent file to Logs/20190508T185439/Express0037.lzma.bak 2019-05-08T20:00:34.220Z,1557345634.220 [DataOverHttps](INFO): SBD MOMSN=10976623 2019-05-08T20:00:35.289Z,1557345635.289 [Default:CheckIn:Read_Iridium] Stopped 2019-05-08T20:00:35.289Z,1557345635.289 [Default:CheckIn:C.Wait] Running Loop=1 2019-05-08T20:00:35.289Z,1557345635.289 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-05-08T20:00:46.174Z,1557345646.174 [NAL9602](INFO): SBD MO Status=0, MOMSN=3891, MT Status=0, MTMSN=0 2019-05-08T20:00:46.174Z,1557345646.174 [NAL9602](INFO): No messages in MT queue 2019-05-08T20:01:16.876Z,1557345676.876 [NAL9602](INFO): Not Powering down - fast GPS 2019-05-08T20:04:37.321Z,1557345877.321 [RDI_Pathfinder](ERROR): only read 0 of 4 data items 2019-05-08T20:04:37.321Z,1557345877.321 [RDI_Pathfinder](ERROR): Failed to parse: :BS-32768,-32768,32768,-32768,-32768,V 2019-05-08T20:05:14.471Z,1557345914.471 [RDI_Pathfinder](ERROR): only read 3 of 4 data items 2019-05-08T20:05:14.471Z,1557345914.471 [RDI_Pathfinder](ERROR): Failed to parse: :RA, 0.00, 0.00, 0.00, 0.00 2019-05-08T20:05:35.880Z,1557345935.880 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-05-08T20:05:35.880Z,1557345935.880 [Default:CheckIn:C.Wait] Stopped 2019-05-08T20:05:35.880Z,1557345935.880 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-05-08T20:05:35.880Z,1557345935.880 [Default:CheckIn:D] Running Loop=1 2019-05-08T20:05:36.286Z,1557345936.286 [Default:CheckIn:D] Stopped 2019-05-08T20:05:36.286Z,1557345936.286 [Default:CheckIn:E] Running Loop=1 2019-05-08T20:05:36.716Z,1557345936.716 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 71.079785 min 2019-05-08T20:05:36.716Z,1557345936.716 [Default:CheckIn:E] Stopped 2019-05-08T20:05:36.716Z,1557345936.716 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-05-08T20:05:36.716Z,1557345936.716 [Default:CheckIn] Stopped 2019-05-08T20:05:36.716Z,1557345936.716 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-05-08T20:05:36.716Z,1557345936.716 [Default:CheckIn](INFO): Running loop #14 2019-05-08T20:05:36.716Z,1557345936.716 [Default:CheckIn] Running Loop=14 2019-05-08T20:05:36.717Z,1557345936.717 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-05-08T20:05:36.717Z,1557345936.717 [Default:CheckIn:Read_GPS] Running Loop=1 2019-05-08T20:05:38.286Z,1557345938.286 [NAL9602](DEBUG): Fix Requested 2019-05-08T20:05:38.678Z,1557345938.678 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,200403.00,A,3648.17196,N,12147.28823,W,0.564,331.68,080519,,,A*77 2019-05-08T20:05:38.680Z,1557345938.680 [NAL9602](INFO): GPS fix at 20190508T200403: (36.802866, -121.788137) 2019-05-08T20:05:38.704Z,1557345938.704 [Default:CheckIn:Read_GPS] Stopped 2019-05-08T20:05:38.704Z,1557345938.704 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-05-08T20:05:44.714Z,1557345944.714 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20190508T185439/Courier0039.lzma 2019-05-08T20:05:45.520Z,1557345945.520 [DataOverHttps](INFO): Moved sent file to Logs/20190508T185439/Courier0039.lzma.bak 2019-05-08T20:05:45.520Z,1557345945.520 [DataOverHttps](INFO): SBD MOMSN=10976666 2019-05-08T20:05:57.467Z,1557345957.467 [DataOverHttps](INFO): Sending 557 bytes from file Logs/20190508T185439/Express0040.lzma 2019-05-08T20:05:58.276Z,1557345958.276 [DataOverHttps](INFO): Moved sent file to Logs/20190508T185439/Express0040.lzma.bak 2019-05-08T20:05:58.277Z,1557345958.277 [DataOverHttps](INFO): SBD MOMSN=10976670 2019-05-08T20:05:59.421Z,1557345959.421 [Default:CheckIn:Read_Iridium] Stopped 2019-05-08T20:05:59.421Z,1557345959.421 [Default:CheckIn:C.Wait] Running Loop=1 2019-05-08T20:05:59.421Z,1557345959.421 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-05-08T20:06:43.818Z,1557346003.818 [NAL9602](INFO): SBD MO Status=2, MOMSN=3892, MT Status=2, MTMSN=0 2019-05-08T20:06:43.818Z,1557346003.818 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-05-08T20:07:25.026Z,1557346045.026 [NAL9602](INFO): SBD MO Status=2, MOMSN=3892, MT Status=2, MTMSN=0 2019-05-08T20:07:25.026Z,1557346045.026 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-05-08T20:07:52.093Z,1557346072.093 [NAL9602](INFO): SBD MO Status=2, MOMSN=3892, MT Status=2, MTMSN=0 2019-05-08T20:07:52.094Z,1557346072.094 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-05-08T20:08:05.026Z,1557346085.026 [NAL9602](INFO): SBD MO Status=0, MOMSN=3892, MT Status=0, MTMSN=0 2019-05-08T20:08:05.026Z,1557346085.026 [NAL9602](INFO): No messages in MT queue 2019-05-08T20:08:35.724Z,1557346115.724 [NAL9602](INFO): Not Powering down - fast GPS 2019-05-08T20:10:59.986Z,1557346259.986 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-05-08T20:10:59.986Z,1557346259.986 [Default:CheckIn:C.Wait] Stopped 2019-05-08T20:10:59.986Z,1557346259.986 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-05-08T20:10:59.986Z,1557346259.986 [Default:CheckIn:D] Running Loop=1 2019-05-08T20:11:00.394Z,1557346260.394 [Default:CheckIn:D] Stopped 2019-05-08T20:11:00.395Z,1557346260.395 [Default:CheckIn:E] Running Loop=1 2019-05-08T20:11:00.802Z,1557346260.802 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 76.481600 min 2019-05-08T20:11:00.802Z,1557346260.802 [Default:CheckIn:E] Stopped 2019-05-08T20:11:00.802Z,1557346260.802 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-05-08T20:11:00.802Z,1557346260.802 [Default:CheckIn] Stopped 2019-05-08T20:11:00.802Z,1557346260.802 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-05-08T20:11:00.803Z,1557346260.803 [Default:CheckIn](INFO): Running loop #15 2019-05-08T20:11:00.803Z,1557346260.803 [Default:CheckIn] Running Loop=15 2019-05-08T20:11:00.803Z,1557346260.803 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-05-08T20:11:00.803Z,1557346260.803 [Default:CheckIn:Read_GPS] Running Loop=1 2019-05-08T20:11:02.394Z,1557346262.394 [NAL9602](DEBUG): Fix Requested 2019-05-08T20:11:02.788Z,1557346262.788 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,200927.00,A,3648.16368,N,12147.27905,W,0.253,331.68,080519,,,A*77 2019-05-08T20:11:02.790Z,1557346262.790 [NAL9602](INFO): GPS fix at 20190508T200927: (36.802728, -121.787984) 2019-05-08T20:11:02.813Z,1557346262.813 [Default:CheckIn:Read_GPS] Stopped 2019-05-08T20:11:02.813Z,1557346262.813 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-05-08T20:11:06.849Z,1557346266.849 [RDI_Pathfinder](ERROR): Failed to parse: : +0.00, +0.00, +0.00, 0.00,4711.03 2019-05-08T20:11:09.074Z,1557346269.074 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20190508T185439/Courier0042.lzma 2019-05-08T20:11:09.880Z,1557346269.880 [DataOverHttps](INFO): Moved sent file to Logs/20190508T185439/Courier0042.lzma.bak 2019-05-08T20:11:09.880Z,1557346269.880 [DataOverHttps](INFO): SBD MOMSN=10976735 2019-05-08T20:11:18.141Z,1557346278.141 [NAL9602](INFO): SBD MO Status=0, MOMSN=3893, MT Status=0, MTMSN=0 2019-05-08T20:11:18.142Z,1557346278.142 [NAL9602](INFO): No messages in MT queue 2019-05-08T20:11:22.261Z,1557346282.261 [DataOverHttps](INFO): Sending 561 bytes from file Logs/20190508T185439/Express0043.lzma 2019-05-08T20:11:23.064Z,1557346283.064 [DataOverHttps](INFO): Moved sent file to Logs/20190508T185439/Express0043.lzma.bak 2019-05-08T20:11:23.064Z,1557346283.064 [DataOverHttps](INFO): SBD MOMSN=10976738 2019-05-08T20:11:24.230Z,1557346284.230 [Default:CheckIn:Read_Iridium] Stopped 2019-05-08T20:11:24.230Z,1557346284.230 [Default:CheckIn:C.Wait] Running Loop=1 2019-05-08T20:11:24.230Z,1557346284.230 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-05-08T20:11:48.840Z,1557346308.840 [NAL9602](INFO): Not Powering down - fast GPS 2019-05-08T20:14:46.694Z,1557346486.694 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude 2019-05-08T20:14:46.694Z,1557346486.694 [RDI_Pathfinder](ERROR): Failed to parse: :BD, +0.00, +0.00,31.92 2019-05-08T20:16:24.825Z,1557346584.825 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-05-08T20:16:24.825Z,1557346584.825 [Default:CheckIn:C.Wait] Stopped 2019-05-08T20:16:24.825Z,1557346584.825 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-05-08T20:16:24.826Z,1557346584.826 [Default:CheckIn:D] Running Loop=1 2019-05-08T20:16:25.225Z,1557346585.225 [Default:CheckIn:D] Stopped 2019-05-08T20:16:25.225Z,1557346585.225 [Default:CheckIn:E] Running Loop=1 2019-05-08T20:16:25.677Z,1557346585.677 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 81.895443 min 2019-05-08T20:16:25.678Z,1557346585.678 [Default:CheckIn:E] Stopped 2019-05-08T20:16:25.678Z,1557346585.678 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-05-08T20:16:25.678Z,1557346585.678 [Default:CheckIn] Stopped 2019-05-08T20:16:25.678Z,1557346585.678 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-05-08T20:16:25.678Z,1557346585.678 [Default:CheckIn](INFO): Running loop #16 2019-05-08T20:16:25.678Z,1557346585.678 [Default:CheckIn] Running Loop=16 2019-05-08T20:16:25.679Z,1557346585.679 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-05-08T20:16:25.679Z,1557346585.679 [Default:CheckIn:Read_GPS] Running Loop=1 2019-05-08T20:16:27.226Z,1557346587.226 [NAL9602](DEBUG): Fix Requested 2019-05-08T20:16:27.622Z,1557346587.622 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,201452.00,A,3648.16517,N,12147.28035,W,0.661,331.68,080519,,,A*77 2019-05-08T20:16:27.624Z,1557346587.624 [NAL9602](INFO): GPS fix at 20190508T201452: (36.802753, -121.788006) 2019-05-08T20:16:27.657Z,1557346587.657 [Default:CheckIn:Read_GPS] Stopped 2019-05-08T20:16:27.658Z,1557346587.658 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-05-08T20:16:33.946Z,1557346593.946 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20190508T185439/Courier0045.lzma 2019-05-08T20:16:34.752Z,1557346594.752 [DataOverHttps](INFO): Moved sent file to Logs/20190508T185439/Courier0045.lzma.bak 2019-05-08T20:16:34.752Z,1557346594.752 [DataOverHttps](INFO): SBD MOMSN=10976776 2019-05-08T20:16:47.267Z,1557346607.267 [DataOverHttps](INFO): Sending 554 bytes from file Logs/20190508T185439/Express0046.lzma 2019-05-08T20:16:48.068Z,1557346608.068 [DataOverHttps](INFO): Moved sent file to Logs/20190508T185439/Express0046.lzma.bak 2019-05-08T20:16:48.068Z,1557346608.068 [DataOverHttps](INFO): SBD MOMSN=10976779 2019-05-08T20:16:49.093Z,1557346609.093 [Default:CheckIn:Read_Iridium] Stopped 2019-05-08T20:16:49.093Z,1557346609.093 [Default:CheckIn:C.Wait] Running Loop=1 2019-05-08T20:16:49.093Z,1557346609.093 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-05-08T20:16:54.714Z,1557346614.714 [NAL9602](INFO): SBD MO Status=2, MOMSN=3894, MT Status=2, MTMSN=0 2019-05-08T20:16:54.714Z,1557346614.714 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-05-08T20:17:29.487Z,1557346649.487 [RDI_Pathfinder](ERROR): Failed to parse: : +0.00, +0.00, +0.00, 0.00,5093.85 2019-05-08T20:17:29.858Z,1557346649.858 [NAL9602](INFO): SBD MO Status=0, MOMSN=3894, MT Status=0, MTMSN=0 2019-05-08T20:17:29.858Z,1557346649.858 [NAL9602](INFO): No messages in MT queue 2019-05-08T20:18:00.565Z,1557346680.565 [NAL9602](INFO): Not Powering down - fast GPS 2019-05-08T20:20:48.642Z,1557346848.642 [RDI_Pathfinder](ERROR): Failed to parse: :RA, 0.00, 0.00, 0.00, 0.00, 0.00 2019-05-08T20:21:49.673Z,1557346909.673 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-05-08T20:21:49.673Z,1557346909.673 [Default:CheckIn:C.Wait] Stopped 2019-05-08T20:21:49.673Z,1557346909.673 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-05-08T20:21:49.674Z,1557346909.674 [Default:CheckIn:D] Running Loop=1 2019-05-08T20:21:50.067Z,1557346910.067 [Default:CheckIn:D] Stopped 2019-05-08T20:21:50.067Z,1557346910.067 [Default:CheckIn:E] Running Loop=1 2019-05-08T20:21:50.486Z,1557346910.486 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 87.309473 min 2019-05-08T20:21:50.486Z,1557346910.486 [Default:CheckIn:E] Stopped 2019-05-08T20:21:50.486Z,1557346910.486 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-05-08T20:21:50.486Z,1557346910.486 [Default:CheckIn] Stopped 2019-05-08T20:21:50.486Z,1557346910.486 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-05-08T20:21:50.486Z,1557346910.486 [Default:CheckIn](INFO): Running loop #17 2019-05-08T20:21:50.486Z,1557346910.486 [Default:CheckIn] Running Loop=17 2019-05-08T20:21:50.486Z,1557346910.486 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-05-08T20:21:50.487Z,1557346910.487 [Default:CheckIn:Read_GPS] Running Loop=1 2019-05-08T20:21:52.066Z,1557346912.066 [NAL9602](DEBUG): Fix Requested 2019-05-08T20:21:52.458Z,1557346912.458 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,202017.00,A,3648.16114,N,12147.27915,W,0.505,331.68,080519,,,A*73 2019-05-08T20:21:52.461Z,1557346912.461 [NAL9602](INFO): GPS fix at 20190508T202017: (36.802686, -121.787986) 2019-05-08T20:21:52.494Z,1557346912.494 [Default:CheckIn:Read_GPS] Stopped 2019-05-08T20:21:52.494Z,1557346912.494 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-05-08T20:21:58.314Z,1557346918.314 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20190508T185439/Courier0048.lzma 2019-05-08T20:21:59.120Z,1557346919.120 [DataOverHttps](INFO): Moved sent file to Logs/20190508T185439/Courier0048.lzma.bak 2019-05-08T20:21:59.120Z,1557346919.120 [DataOverHttps](INFO): SBD MOMSN=10976840 2019-05-08T20:22:16.235Z,1557346936.235 [DataOverHttps](INFO): Sending 557 bytes from file Logs/20190508T185439/Express0049.lzma 2019-05-08T20:22:17.040Z,1557346937.040 [DataOverHttps](INFO): Moved sent file to Logs/20190508T185439/Express0049.lzma.bak 2019-05-08T20:22:17.040Z,1557346937.040 [DataOverHttps](INFO): SBD MOMSN=10976861 2019-05-08T20:22:18.388Z,1557346938.388 [Default:CheckIn:Read_Iridium] Stopped 2019-05-08T20:22:18.388Z,1557346938.388 [Default:CheckIn:C.Wait] Running Loop=1 2019-05-08T20:22:18.388Z,1557346938.388 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-05-08T20:25:31.462Z,1557347131.462 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2019-05-08T20:25:31.463Z,1557347131.463 [RDI_Pathfinder](ERROR): Failed to parse: :TS,19050813330748,35.0, 5.61 2019-05-08T20:26:47.041Z,1557347207.041 [RDI_Pathfinder](ERROR): only read 3 of 4 data items 2019-05-08T20:26:47.041Z,1557347207.041 [RDI_Pathfinder](ERROR): Failed to parse: :RA, 0.00, 0.00, 0.00, 0.00 2019-05-08T20:26:54.672Z,1557347214.672 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-05-08T20:27:18.948Z,1557347238.948 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-05-08T20:27:18.948Z,1557347238.948 [Default:CheckIn:C.Wait] Stopped 2019-05-08T20:27:18.948Z,1557347238.948 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-05-08T20:27:18.950Z,1557347238.950 [Default:CheckIn:D] Running Loop=1 2019-05-08T20:27:19.367Z,1557347239.367 [Default:CheckIn:D] Stopped 2019-05-08T20:27:19.367Z,1557347239.367 [Default:CheckIn:E] Running Loop=1 2019-05-08T20:27:19.743Z,1557347239.743 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 92.797803 min 2019-05-08T20:27:19.743Z,1557347239.743 [Default:CheckIn:E] Stopped 2019-05-08T20:27:19.744Z,1557347239.744 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-05-08T20:27:19.744Z,1557347239.744 [Default:CheckIn] Stopped 2019-05-08T20:27:19.744Z,1557347239.744 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-05-08T20:27:19.744Z,1557347239.744 [Default:CheckIn](INFO): Running loop #18 2019-05-08T20:27:19.744Z,1557347239.744 [Default:CheckIn] Running Loop=18 2019-05-08T20:27:19.744Z,1557347239.744 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-05-08T20:27:19.744Z,1557347239.744 [Default:CheckIn:Read_GPS] Running Loop=1 2019-05-08T20:27:21.354Z,1557347241.354 [NAL9602](DEBUG): Fix Requested 2019-05-08T20:27:21.760Z,1557347241.760 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,202546.00,A,3648.16307,N,12147.28359,W,0.408,111.06,080519,,,A*7B 2019-05-08T20:27:21.762Z,1557347241.762 [NAL9602](INFO): GPS fix at 20190508T202546: (36.802718, -121.788060) 2019-05-08T20:27:21.786Z,1557347241.786 [Default:CheckIn:Read_GPS] Stopped 2019-05-08T20:27:21.786Z,1557347241.786 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-05-08T20:27:32.058Z,1557347252.058 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20190508T185439/Courier0051.lzma 2019-05-08T20:27:32.864Z,1557347252.864 [DataOverHttps](INFO): Moved sent file to Logs/20190508T185439/Courier0051.lzma.bak 2019-05-08T20:27:32.865Z,1557347252.865 [DataOverHttps](INFO): SBD MOMSN=10976882 2019-05-08T20:27:45.999Z,1557347265.999 [DataOverHttps](INFO): Sending 658 bytes from file Logs/20190508T185439/Express0052.lzma 2019-05-08T20:27:46.804Z,1557347266.804 [DataOverHttps](INFO): Moved sent file to Logs/20190508T185439/Express0052.lzma.bak 2019-05-08T20:27:46.804Z,1557347266.804 [DataOverHttps](INFO): SBD MOMSN=10976885 2019-05-08T20:27:48.805Z,1557347268.805 [Default:CheckIn:Read_Iridium] Stopped 2019-05-08T20:27:48.805Z,1557347268.805 [Default:CheckIn:C.Wait] Running Loop=1 2019-05-08T20:27:48.805Z,1557347268.805 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-05-08T20:27:54.460Z,1557347274.460 [NAL9602](INFO): Not Powering down - fast GPS 2019-05-08T20:28:32.845Z,1557347312.845 [Micromodem](ERROR): Response from modem failed NMEA checksum: $CAREV,202822,AUV, $CAREV,202832,AUV,2.0.27690*1C 2019-05-08T20:32:49.405Z,1557347569.405 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-05-08T20:32:49.405Z,1557347569.405 [Default:CheckIn:C.Wait] Stopped 2019-05-08T20:32:49.405Z,1557347569.405 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-05-08T20:32:49.406Z,1557347569.406 [Default:CheckIn:D] Running Loop=1 2019-05-08T20:32:49.809Z,1557347569.809 [Default:CheckIn:D] Stopped 2019-05-08T20:32:49.809Z,1557347569.809 [Default:CheckIn:E] Running Loop=1 2019-05-08T20:32:50.224Z,1557347570.224 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 98.305176 min 2019-05-08T20:32:50.224Z,1557347570.224 [Default:CheckIn:E] Stopped 2019-05-08T20:32:50.225Z,1557347570.225 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-05-08T20:32:50.225Z,1557347570.225 [Default:CheckIn] Stopped 2019-05-08T20:32:50.225Z,1557347570.225 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-05-08T20:32:50.225Z,1557347570.225 [Default:CheckIn](INFO): Running loop #19 2019-05-08T20:32:50.225Z,1557347570.225 [Default:CheckIn] Running Loop=19 2019-05-08T20:32:50.225Z,1557347570.225 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-05-08T20:32:50.225Z,1557347570.225 [Default:CheckIn:Read_GPS] Running Loop=1 2019-05-08T20:32:51.814Z,1557347571.814 [NAL9602](DEBUG): Fix Requested 2019-05-08T20:32:52.202Z,1557347572.202 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,203117.00,A,3648.15791,N,12147.28524,W,0.505,111.06,080519,,,A*72 2019-05-08T20:32:52.204Z,1557347572.204 [NAL9602](INFO): GPS fix at 20190508T203117: (36.802632, -121.788087) 2019-05-08T20:32:52.227Z,1557347572.227 [Default:CheckIn:Read_GPS] Stopped 2019-05-08T20:32:52.227Z,1557347572.227 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-05-08T20:32:58.277Z,1557347578.277 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20190508T185439/Courier0054.lzma 2019-05-08T20:32:59.076Z,1557347579.076 [DataOverHttps](INFO): Moved sent file to Logs/20190508T185439/Courier0054.lzma.bak 2019-05-08T20:32:59.076Z,1557347579.076 [DataOverHttps](INFO): SBD MOMSN=10976956 2019-05-08T20:33:11.432Z,1557347591.432 [DataOverHttps](INFO): Sending 567 bytes from file Logs/20190508T185439/Express0055.lzma 2019-05-08T20:33:12.236Z,1557347592.236 [DataOverHttps](INFO): Moved sent file to Logs/20190508T185439/Express0055.lzma.bak 2019-05-08T20:33:12.236Z,1557347592.236 [DataOverHttps](INFO): SBD MOMSN=10976959 2019-05-08T20:33:13.403Z,1557347593.403 [Default:CheckIn:Read_Iridium] Stopped 2019-05-08T20:33:13.403Z,1557347593.403 [Default:CheckIn:C.Wait] Running Loop=1 2019-05-08T20:33:13.403Z,1557347593.403 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-05-08T20:33:22.652Z,1557347602.652 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2019-05-08T20:33:22.726Z,1557347602.726 [NAL9602](FAULT): received: +CSQ:0 OK94, 0, 0, 0, 0 OK 2019-05-08T20:33:22.726Z,1557347602.726 [NAL9602] Data Fault, FailCount= 1 2019-05-08T20:33:22.727Z,1557347602.727 [NAL9602](ERROR): Data Fault 2019-05-08T20:33:22.771Z,1557347602.771 [CBIT](ERROR): Data Fault in component: NAL9602 2019-05-08T20:33:23.058Z,1557347603.058 [NAL9602](INFO): Powering down 2019-05-08T20:33:23.903Z,1557347603.903 [CBIT](INFO): Clearing failed state for component NAL9602 2019-05-08T20:33:23.903Z,1557347603.903 [NAL9602] No Fault, FailCount= 1 2019-05-08T20:33:36.005Z,1557347616.005 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2019-05-08T20:33:36.005Z,1557347616.005 [RDI_Pathfinder](ERROR): Failed to parse: :TS,19050813411248,35.0, -0.1,448.9, 0 2019-05-08T20:33:53.368Z,1557347633.368 [NAL9602](INFO): Powering up NAL9602 2019-05-08T20:34:04.269Z,1557347644.269 [NAL9602](INFO): NAL9602 initialized 2019-05-08T20:34:35.376Z,1557347675.376 [NAL9602](INFO): Not Powering down - fast GPS 2019-05-08T20:38:13.985Z,1557347893.985 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-05-08T20:38:13.985Z,1557347893.985 [Default:CheckIn:C.Wait] Stopped 2019-05-08T20:38:13.985Z,1557347893.985 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-05-08T20:38:13.986Z,1557347893.986 [Default:CheckIn:D] Running Loop=1 2019-05-08T20:38:14.391Z,1557347894.391 [Default:CheckIn:D] Stopped 2019-05-08T20:38:14.391Z,1557347894.391 [Default:CheckIn:E] Running Loop=1 2019-05-08T20:38:14.806Z,1557347894.806 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 103.714852 min 2019-05-08T20:38:14.806Z,1557347894.806 [Default:CheckIn:E] Stopped 2019-05-08T20:38:14.806Z,1557347894.806 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-05-08T20:38:14.806Z,1557347894.806 [Default:CheckIn] Stopped 2019-05-08T20:38:14.807Z,1557347894.807 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-05-08T20:38:14.807Z,1557347894.807 [Default:CheckIn](INFO): Running loop #20 2019-05-08T20:38:14.807Z,1557347894.807 [Default:CheckIn] Running Loop=20 2019-05-08T20:38:14.807Z,1557347894.807 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-05-08T20:38:14.807Z,1557347894.807 [Default:CheckIn:Read_GPS] Running Loop=1 2019-05-08T20:38:16.390Z,1557347896.390 [NAL9602](DEBUG): Fix Requested 2019-05-08T20:38:19.208Z,1557347899.208 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-05-08T20:38:20.027Z,1557347900.027 [NAL9602](DEBUG): Fix Requested 2019-05-08T20:38:22.458Z,1557347902.458 [NAL9602](DEBUG): Fix Requested 2019-05-08T20:38:25.686Z,1557347905.686 [NAL9602](DEBUG): Fix Requested 2019-05-08T20:38:28.514Z,1557347908.514 [NAL9602](DEBUG): Fix Requested 2019-05-08T20:38:31.746Z,1557347911.746 [NAL9602](DEBUG): Fix Requested 2019-05-08T20:38:34.570Z,1557347914.570 [NAL9602](DEBUG): Fix Requested 2019-05-08T20:38:34.966Z,1557347914.966 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,203659.00,A,3648.16085,N,12147.27392,W,0.039,0.00,080519,,,A*77 2019-05-08T20:38:34.968Z,1557347914.968 [NAL9602](INFO): GPS fix at 20190508T203659: (36.802681, -121.787899) 2019-05-08T20:38:34.992Z,1557347914.992 [Default:CheckIn:Read_GPS] Stopped 2019-05-08T20:38:34.992Z,1557347914.992 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-05-08T20:38:41.259Z,1557347921.259 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20190508T185439/Courier0057.lzma 2019-05-08T20:38:42.056Z,1557347922.056 [DataOverHttps](INFO): Moved sent file to Logs/20190508T185439/Courier0057.lzma.bak 2019-05-08T20:38:42.056Z,1557347922.056 [DataOverHttps](INFO): SBD MOMSN=10976969 2019-05-08T20:38:55.031Z,1557347935.031 [DataOverHttps](INFO): Sending 705 bytes from file Logs/20190508T185439/Express0058.lzma 2019-05-08T20:38:55.836Z,1557347935.836 [DataOverHttps](INFO): Moved sent file to Logs/20190508T185439/Express0058.lzma.bak 2019-05-08T20:38:55.836Z,1557347935.836 [DataOverHttps](INFO): SBD MOMSN=10976972 2019-05-08T20:38:56.870Z,1557347936.870 [Default:CheckIn:Read_Iridium] Stopped 2019-05-08T20:38:56.874Z,1557347936.874 [Default:CheckIn:C.Wait] Running Loop=1 2019-05-08T20:38:56.874Z,1557347936.874 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-05-08T20:39:03.714Z,1557347943.714 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2019-05-08T20:39:03.714Z,1557347943.714 [RDI_Pathfinder](ERROR): Failed to parse: :TS,19050813464048,35.0, -0.1, 0.0,14 2019-05-08T20:39:07.332Z,1557347947.332 [NAL9602](INFO): Not Powering down - fast GPS 2019-05-08T20:39:34.821Z,1557347974.821 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2019-05-08T20:39:34.822Z,1557347974.822 [RDI_Pathfinder](ERROR): Failed to parse: :TS3471148,35.0, -0.1, 0.0,1448.9, 0 2019-05-08T20:40:32.977Z,1557348032.977 [Micromodem](ERROR): Response from modem failed NMEA checksum: $CAREV,204022,AUV,2.0.2769 $CAREV,204032,AUV,2.0.27690*12 2019-05-08T20:43:57.465Z,1557348237.465 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-05-08T20:43:57.465Z,1557348237.465 [Default:CheckIn:C.Wait] Stopped 2019-05-08T20:43:57.465Z,1557348237.465 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-05-08T20:43:57.466Z,1557348237.466 [Default:CheckIn:D] Running Loop=1 2019-05-08T20:43:57.865Z,1557348237.865 [Default:CheckIn:D] Stopped 2019-05-08T20:43:57.866Z,1557348237.866 [Default:CheckIn:E] Running Loop=1 2019-05-08T20:43:58.307Z,1557348238.307 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 109.439445 min 2019-05-08T20:43:58.307Z,1557348238.307 [Default:CheckIn:E] Stopped 2019-05-08T20:43:58.307Z,1557348238.307 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-05-08T20:43:58.307Z,1557348238.307 [Default:CheckIn] Stopped 2019-05-08T20:43:58.307Z,1557348238.307 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-05-08T20:43:58.308Z,1557348238.308 [Default:CheckIn](INFO): Running loop #21 2019-05-08T20:43:58.308Z,1557348238.308 [Default:CheckIn] Running Loop=21 2019-05-08T20:43:58.308Z,1557348238.308 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-05-08T20:43:58.308Z,1557348238.308 [Default:CheckIn:Read_GPS] Running Loop=1 2019-05-08T20:43:59.862Z,1557348239.862 [NAL9602](DEBUG): Fix Requested 2019-05-08T20:44:00.276Z,1557348240.276 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,204225.00,A,3648.16221,N,12147.29175,W,0.156,0.00,080519,,,A*7E 2019-05-08T20:44:00.278Z,1557348240.278 [NAL9602](INFO): GPS fix at 20190508T204225: (36.802703, -121.788196) 2019-05-08T20:44:00.311Z,1557348240.311 [Default:CheckIn:Read_GPS] Stopped 2019-05-08T20:44:00.311Z,1557348240.311 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-05-08T20:44:05.611Z,1557348245.611 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20190508T185439/Courier0060.lzma 2019-05-08T20:44:06.396Z,1557348246.396 [DataOverHttps](INFO): Moved sent file to Logs/20190508T185439/Courier0060.lzma.bak 2019-05-08T20:44:06.396Z,1557348246.396 [DataOverHttps](INFO): SBD MOMSN=10977040 2019-05-08T20:44:18.767Z,1557348258.767 [DataOverHttps](INFO): Sending 555 bytes from file Logs/20190508T185439/Express0061.lzma 2019-05-08T20:44:19.572Z,1557348259.572 [DataOverHttps](INFO): Moved sent file to Logs/20190508T185439/Express0061.lzma.bak 2019-05-08T20:44:19.572Z,1557348259.572 [DataOverHttps](INFO): SBD MOMSN=10977043 2019-05-08T20:44:20.881Z,1557348260.881 [Default:CheckIn:Read_Iridium] Stopped 2019-05-08T20:44:20.881Z,1557348260.881 [Default:CheckIn:C.Wait] Running Loop=1 2019-05-08T20:44:20.881Z,1557348260.881 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-05-08T20:45:43.698Z,1557348343.698 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2019-05-08T20:45:43.699Z,1557348343.699 [RDI_Pathfinder](ERROR): Failed to parse: :TS,19050813532048,35.0, -0.1, 0.0 0 2019-05-08T20:49:02.455Z,1557348542.455 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-05-08T20:49:21.480Z,1557348561.480 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-05-08T20:49:21.481Z,1557348561.481 [Default:CheckIn:C.Wait] Stopped 2019-05-08T20:49:21.481Z,1557348561.481 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-05-08T20:49:21.481Z,1557348561.481 [Default:CheckIn:D] Running Loop=1 2019-05-08T20:49:21.877Z,1557348561.877 [Default:CheckIn:D] Stopped 2019-05-08T20:49:21.877Z,1557348561.877 [Default:CheckIn:E] Running Loop=1 2019-05-08T20:49:22.328Z,1557348562.328 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 114.839640 min 2019-05-08T20:49:22.329Z,1557348562.329 [Default:CheckIn:E] Stopped 2019-05-08T20:49:22.329Z,1557348562.329 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-05-08T20:49:22.329Z,1557348562.329 [Default:CheckIn] Stopped 2019-05-08T20:49:22.329Z,1557348562.329 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-05-08T20:49:22.329Z,1557348562.329 [Default:CheckIn](INFO): Running loop #22 2019-05-08T20:49:22.329Z,1557348562.329 [Default:CheckIn] Running Loop=22 2019-05-08T20:49:22.329Z,1557348562.329 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-05-08T20:49:22.329Z,1557348562.329 [Default:CheckIn:Read_GPS] Running Loop=1 2019-05-08T20:49:23.882Z,1557348563.882 [NAL9602](DEBUG): Fix Requested 2019-05-08T20:49:24.301Z,1557348564.301 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,204749.00,A,3648.16103,N,12147.28785,W,0.117,0.00,080519,,,A*7F 2019-05-08T20:49:24.304Z,1557348564.304 [NAL9602](INFO): GPS fix at 20190508T204749: (36.802684, -121.788131) 2019-05-08T20:49:24.327Z,1557348564.327 [Default:CheckIn:Read_GPS] Stopped 2019-05-08T20:49:24.327Z,1557348564.327 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-05-08T20:49:30.186Z,1557348570.186 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20190508T185439/Courier0063.lzma 2019-05-08T20:49:30.992Z,1557348570.992 [DataOverHttps](INFO): Moved sent file to Logs/20190508T185439/Courier0063.lzma.bak 2019-05-08T20:49:30.992Z,1557348570.992 [DataOverHttps](INFO): SBD MOMSN=10977053 2019-05-08T20:49:43.959Z,1557348583.959 [DataOverHttps](INFO): Sending 641 bytes from file Logs/20190508T185439/Express0064.lzma 2019-05-08T20:49:44.764Z,1557348584.764 [DataOverHttps](INFO): Moved sent file to Logs/20190508T185439/Express0064.lzma.bak 2019-05-08T20:49:44.764Z,1557348584.764 [DataOverHttps](INFO): SBD MOMSN=10977056 2019-05-08T20:49:46.113Z,1557348586.113 [Default:CheckIn:Read_Iridium] Stopped 2019-05-08T20:49:46.113Z,1557348586.113 [Default:CheckIn:C.Wait] Running Loop=1 2019-05-08T20:49:46.113Z,1557348586.113 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-05-08T20:49:56.612Z,1557348596.612 [NAL9602](INFO): Not Powering down - fast GPS 2019-05-08T20:54:46.704Z,1557348886.704 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-05-08T20:54:46.704Z,1557348886.704 [Default:CheckIn:C.Wait] Stopped 2019-05-08T20:54:46.704Z,1557348886.704 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-05-08T20:54:46.704Z,1557348886.704 [Default:CheckIn:D] Running Loop=1 2019-05-08T20:54:47.109Z,1557348887.109 [Default:CheckIn:D] Stopped 2019-05-08T20:54:47.109Z,1557348887.109 [Default:CheckIn:E] Running Loop=1 2019-05-08T20:54:47.516Z,1557348887.516 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 120.260181 min 2019-05-08T20:54:47.516Z,1557348887.516 [Default:CheckIn:E] Stopped 2019-05-08T20:54:47.516Z,1557348887.516 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-05-08T20:54:47.516Z,1557348887.516 [Default:CheckIn] Stopped 2019-05-08T20:54:47.516Z,1557348887.516 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-05-08T20:54:47.516Z,1557348887.516 [Default:CheckIn](INFO): Running loop #23 2019-05-08T20:54:47.516Z,1557348887.516 [Default:CheckIn] Running Loop=23 2019-05-08T20:54:47.516Z,1557348887.516 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-05-08T20:54:47.516Z,1557348887.516 [Default:CheckIn:Read_GPS] Running Loop=1 2019-05-08T20:54:49.102Z,1557348889.102 [NAL9602](DEBUG): Fix Requested 2019-05-08T20:54:49.494Z,1557348889.494 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,205314.00,A,3648.15550,N,12147.30085,W,0.272,0.00,080519,,,A*7D 2019-05-08T20:54:49.496Z,1557348889.496 [NAL9602](INFO): GPS fix at 20190508T205314: (36.802592, -121.788348) 2019-05-08T20:54:49.530Z,1557348889.530 [Default:CheckIn:Read_GPS] Stopped 2019-05-08T20:54:49.530Z,1557348889.530 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-05-08T20:54:55.274Z,1557348895.274 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20190508T185439/Courier0066.lzma 2019-05-08T20:54:56.080Z,1557348896.080 [DataOverHttps](INFO): Moved sent file to Logs/20190508T185439/Courier0066.lzma.bak 2019-05-08T20:54:56.080Z,1557348896.080 [DataOverHttps](INFO): SBD MOMSN=10977136 2019-05-08T20:55:08.440Z,1557348908.440 [DataOverHttps](INFO): Sending 561 bytes from file Logs/20190508T185439/Express0067.lzma 2019-05-08T20:55:09.248Z,1557348909.248 [DataOverHttps](INFO): Moved sent file to Logs/20190508T185439/Express0067.lzma.bak 2019-05-08T20:55:09.249Z,1557348909.249 [DataOverHttps](INFO): SBD MOMSN=10977139 2019-05-08T20:55:10.177Z,1557348910.177 [Default:CheckIn:Read_Iridium] Stopped 2019-05-08T20:55:10.177Z,1557348910.177 [Default:CheckIn:C.Wait] Running Loop=1 2019-05-08T20:55:10.177Z,1557348910.177 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-05-08T20:55:20.279Z,1557348920.279 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2019-05-08T20:55:20.362Z,1557348920.362 [NAL9602](FAULT): received: +CSQ:0 OK94, 0, 0, 0, 0 OK 2019-05-08T20:55:20.362Z,1557348920.362 [NAL9602] Data Fault, FailCount= 1 2019-05-08T20:55:20.363Z,1557348920.363 [NAL9602](ERROR): Data Fault 2019-05-08T20:55:20.467Z,1557348920.467 [CBIT](ERROR): Data Fault in component: NAL9602 2019-05-08T20:55:20.656Z,1557348920.656 [NAL9602](INFO): Powering down 2019-05-08T20:55:21.558Z,1557348921.558 [CBIT](INFO): Clearing failed state for component NAL9602 2019-05-08T20:55:21.558Z,1557348921.558 [NAL9602] No Fault, FailCount= 1 2019-05-08T20:55:50.961Z,1557348950.961 [NAL9602](INFO): Powering up NAL9602 2019-05-08T20:56:01.873Z,1557348961.873 [NAL9602](INFO): NAL9602 initialized 2019-05-08T20:56:32.976Z,1557348992.976 [NAL9602](INFO): Not Powering down - fast GPS 2019-05-08T20:56:54.812Z,1557349014.812 [RDI_Pathfinder](ERROR): only read 3 of 4 data items 2019-05-08T20:56:54.812Z,1557349014.812 [RDI_Pathfinder](ERROR): Failed to parse: :RA, 0.00, 0.00, 0.00, 0.00 2019-05-08T20:57:00.490Z,1557349020.490 [RDI_Pathfinder](ERROR): Failed to parse: :SA, +0.00, +0.00, 0.00 2019-05-08T20:59:22.300Z,1557349162.300 [RDI_Pathfinder](ERROR): only read 3 of 4 data items 2019-05-08T20:59:22.300Z,1557349162.300 [RDI_Pathfinder](ERROR): Failed to parse: :RA, 0.00, 0.00, 0.00, 0.00, BI,-32768,-32768,-32768,-32768,V 2019-05-08T21:00:10.761Z,1557349210.761 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-05-08T21:00:10.761Z,1557349210.761 [Default:CheckIn:C.Wait] Stopped 2019-05-08T21:00:10.761Z,1557349210.761 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-05-08T21:00:10.762Z,1557349210.762 [Default:CheckIn:D] Running Loop=1 2019-05-08T21:00:11.158Z,1557349211.158 [Default:CheckIn:D] Stopped 2019-05-08T21:00:11.158Z,1557349211.158 [Default:CheckIn:E] Running Loop=1 2019-05-08T21:00:11.573Z,1557349211.573 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 125.660986 min 2019-05-08T21:00:11.573Z,1557349211.573 [Default:CheckIn:E] Stopped 2019-05-08T21:00:11.574Z,1557349211.574 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-05-08T21:00:11.574Z,1557349211.574 [Default:CheckIn] Stopped 2019-05-08T21:00:11.574Z,1557349211.574 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-05-08T21:00:11.574Z,1557349211.574 [Default:CheckIn](INFO): Running loop #24 2019-05-08T21:00:11.574Z,1557349211.574 [Default:CheckIn] Running Loop=24 2019-05-08T21:00:11.574Z,1557349211.574 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-05-08T21:00:11.574Z,1557349211.574 [Default:CheckIn:Read_GPS] Running Loop=1 2019-05-08T21:00:13.170Z,1557349213.170 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:00:15.177Z,1557349215.177 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-05-08T21:00:15.998Z,1557349215.998 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:00:18.418Z,1557349218.418 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:00:21.654Z,1557349221.654 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:00:24.478Z,1557349224.478 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:00:27.710Z,1557349227.710 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:00:30.538Z,1557349230.538 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:00:33.774Z,1557349233.774 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:00:36.627Z,1557349236.627 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:00:39.430Z,1557349239.430 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:00:42.654Z,1557349242.654 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:00:43.489Z,1557349243.489 [RDI_Pathfinder](ERROR): only read 0 of 4 data items 2019-05-08T21:00:43.489Z,1557349243.489 [RDI_Pathfinder](ERROR): Failed to parse: :RA, 686.58 2019-05-08T21:00:45.489Z,1557349245.489 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:00:48.718Z,1557349248.718 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:00:51.550Z,1557349251.550 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:00:54.782Z,1557349254.782 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:00:57.610Z,1557349257.610 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:01:00.434Z,1557349260.434 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:01:03.670Z,1557349263.670 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:01:06.494Z,1557349266.494 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:01:09.734Z,1557349269.734 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:01:12.554Z,1557349272.554 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:01:15.382Z,1557349275.382 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:01:18.614Z,1557349278.614 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:01:18.641Z,1557349278.641 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2019-05-08T21:01:18.641Z,1557349278.641 [RDI_Pathfinder](ERROR): Failed to parse: :TS,19050814085548,31, 0.0,1448.9, 0 2019-05-08T21:01:21.446Z,1557349281.446 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:01:24.678Z,1557349284.678 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:01:27.502Z,1557349287.502 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:01:30.738Z,1557349290.738 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:01:33.558Z,1557349293.558 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:01:36.394Z,1557349296.394 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:01:39.622Z,1557349299.622 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:01:42.450Z,1557349302.450 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:01:45.686Z,1557349305.686 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:01:48.510Z,1557349308.510 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:01:51.742Z,1557349311.742 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:01:54.574Z,1557349314.574 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:01:57.398Z,1557349317.398 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:02:00.634Z,1557349320.634 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:02:03.462Z,1557349323.462 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:02:06.686Z,1557349326.686 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:02:09.518Z,1557349329.518 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:02:12.746Z,1557349332.746 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:02:15.578Z,1557349335.578 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:02:18.812Z,1557349338.812 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:02:21.639Z,1557349341.639 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:02:24.486Z,1557349344.486 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:02:27.702Z,1557349347.702 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:02:30.531Z,1557349350.531 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:02:30.919Z,1557349350.919 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,210055.00,A,3648.17050,N,12147.26535,W,0.641,0.00,080519,,,A*75 2019-05-08T21:02:30.921Z,1557349350.921 [NAL9602](INFO): GPS fix at 20190508T210055: (36.802842, -121.787756) 2019-05-08T21:02:30.954Z,1557349350.954 [Default:CheckIn:Read_GPS] Stopped 2019-05-08T21:02:30.959Z,1557349350.959 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-05-08T21:02:36.930Z,1557349356.930 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20190508T185439/Courier0069.lzma 2019-05-08T21:02:37.736Z,1557349357.736 [DataOverHttps](INFO): Moved sent file to Logs/20190508T185439/Courier0069.lzma.bak 2019-05-08T21:02:37.736Z,1557349357.736 [DataOverHttps](INFO): SBD MOMSN=10977200 2019-05-08T21:02:43.481Z,1557349363.481 [RDI_Pathfinder](ERROR): only read 1 of 4 data items 2019-05-08T21:02:43.482Z,1557349363.482 [RDI_Pathfinder](ERROR): Failed to parse: :RA, 0.00, 806.52 2019-05-08T21:02:50.963Z,1557349370.963 [DataOverHttps](INFO): Sending 829 bytes from file Logs/20190508T185439/Express0070.lzma 2019-05-08T21:02:51.768Z,1557349371.768 [DataOverHttps](INFO): Moved sent file to Logs/20190508T185439/Express0070.lzma.bak 2019-05-08T21:02:51.768Z,1557349371.768 [DataOverHttps](INFO): SBD MOMSN=10977203 2019-05-08T21:02:52.780Z,1557349372.780 [Default:CheckIn:Read_Iridium] Stopped 2019-05-08T21:02:52.780Z,1557349372.780 [Default:CheckIn:C.Wait] Running Loop=1 2019-05-08T21:02:52.780Z,1557349372.780 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-05-08T21:03:03.664Z,1557349383.664 [NAL9602](INFO): Not Powering down - fast GPS 2019-05-08T21:07:53.381Z,1557349673.381 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-05-08T21:07:53.381Z,1557349673.381 [Default:CheckIn:C.Wait] Stopped 2019-05-08T21:07:53.381Z,1557349673.381 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-05-08T21:07:53.381Z,1557349673.381 [Default:CheckIn:D] Running Loop=1 2019-05-08T21:07:53.747Z,1557349673.747 [Default:CheckIn:D] Stopped 2019-05-08T21:07:53.747Z,1557349673.747 [Default:CheckIn:E] Running Loop=1 2019-05-08T21:07:54.155Z,1557349674.155 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 133.370809 min 2019-05-08T21:07:54.155Z,1557349674.155 [Default:CheckIn:E] Stopped 2019-05-08T21:07:54.155Z,1557349674.155 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-05-08T21:07:54.155Z,1557349674.155 [Default:CheckIn] Stopped 2019-05-08T21:07:54.155Z,1557349674.155 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-05-08T21:07:54.155Z,1557349674.155 [Default:CheckIn](INFO): Running loop #25 2019-05-08T21:07:54.155Z,1557349674.155 [Default:CheckIn] Running Loop=25 2019-05-08T21:07:54.156Z,1557349674.156 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-05-08T21:07:54.156Z,1557349674.156 [Default:CheckIn:Read_GPS] Running Loop=1 2019-05-08T21:07:55.766Z,1557349675.766 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:07:56.154Z,1557349676.154 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,210621.00,A,3648.16258,N,12147.28494,W,0.039,0.00,080519,,,A*76 2019-05-08T21:07:56.156Z,1557349676.156 [NAL9602](INFO): GPS fix at 20190508T210621: (36.802710, -121.788082) 2019-05-08T21:07:56.209Z,1557349676.209 [Default:CheckIn:Read_GPS] Stopped 2019-05-08T21:07:56.209Z,1557349676.209 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-05-08T21:08:02.302Z,1557349682.302 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20190508T185439/Courier0072.lzma 2019-05-08T21:08:03.108Z,1557349683.108 [DataOverHttps](INFO): Moved sent file to Logs/20190508T185439/Courier0072.lzma.bak 2019-05-08T21:08:03.108Z,1557349683.108 [DataOverHttps](INFO): SBD MOMSN=10977253 2019-05-08T21:08:15.617Z,1557349695.617 [DataOverHttps](INFO): Sending 557 bytes from file Logs/20190508T185439/Express0073.lzma 2019-05-08T21:08:16.408Z,1557349696.408 [DataOverHttps](INFO): Moved sent file to Logs/20190508T185439/Express0073.lzma.bak 2019-05-08T21:08:16.408Z,1557349696.408 [DataOverHttps](INFO): SBD MOMSN=10977256 2019-05-08T21:08:17.666Z,1557349697.666 [Default:CheckIn:Read_Iridium] Stopped 2019-05-08T21:08:17.666Z,1557349697.666 [Default:CheckIn:C.Wait] Running Loop=1 2019-05-08T21:08:17.666Z,1557349697.666 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-05-08T21:08:38.268Z,1557349718.268 [NAL9602](INFO): SBD MO Status=2, MOMSN=3895, MT Status=2, MTMSN=0 2019-05-08T21:08:38.268Z,1557349718.268 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-05-08T21:09:08.546Z,1557349748.546 [NAL9602](INFO): SBD MO Status=2, MOMSN=3895, MT Status=2, MTMSN=0 2019-05-08T21:09:08.546Z,1557349748.546 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-05-08T21:10:16.825Z,1557349816.825 [NAL9602](INFO): SBD MO Status=2, MOMSN=3895, MT Status=2, MTMSN=0 2019-05-08T21:10:16.826Z,1557349816.826 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-05-08T21:10:53.587Z,1557349853.587 [NAL9602](INFO): SBD MO Status=2, MOMSN=3895, MT Status=2, MTMSN=0 2019-05-08T21:10:53.587Z,1557349853.587 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-05-08T21:10:57.642Z,1557349857.642 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2019-05-08T21:10:57.642Z,1557349857.642 [RDI_Pathfinder](ERROR): Failed to parse: :TS,19050814183448,35.0, -00,1448.9, 0 2019-05-08T21:11:04.097Z,1557349864.097 [NAL9602](INFO): SBD MO Status=0, MOMSN=3895, MT Status=0, MTMSN=0 2019-05-08T21:11:04.098Z,1557349864.098 [NAL9602](INFO): No messages in MT queue 2019-05-08T21:11:34.809Z,1557349894.809 [NAL9602](INFO): Not Powering down - fast GPS 2019-05-08T21:13:18.292Z,1557349998.292 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-05-08T21:13:18.292Z,1557349998.292 [Default:CheckIn:C.Wait] Stopped 2019-05-08T21:13:18.292Z,1557349998.292 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-05-08T21:13:18.293Z,1557349998.293 [Default:CheckIn:D] Running Loop=1 2019-05-08T21:13:18.650Z,1557349998.650 [Default:CheckIn:D] Stopped 2019-05-08T21:13:18.650Z,1557349998.650 [Default:CheckIn:E] Running Loop=1 2019-05-08T21:13:19.051Z,1557349999.051 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 138.785856 min 2019-05-08T21:13:19.051Z,1557349999.051 [Default:CheckIn:E] Stopped 2019-05-08T21:13:19.051Z,1557349999.051 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-05-08T21:13:19.051Z,1557349999.051 [Default:CheckIn] Stopped 2019-05-08T21:13:19.051Z,1557349999.051 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-05-08T21:13:19.051Z,1557349999.051 [Default:CheckIn](INFO): Running loop #26 2019-05-08T21:13:19.051Z,1557349999.051 [Default:CheckIn] Running Loop=26 2019-05-08T21:13:19.051Z,1557349999.051 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-05-08T21:13:19.051Z,1557349999.051 [Default:CheckIn:Read_GPS] Running Loop=1 2019-05-08T21:13:20.654Z,1557350000.654 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:13:21.050Z,1557350001.050 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,211146.00,A,3648.15340,N,12147.29598,W,0.097,0.00,080519,,,A*72 2019-05-08T21:13:21.052Z,1557350001.052 [NAL9602](INFO): GPS fix at 20190508T211146: (36.802557, -121.788266) 2019-05-08T21:13:21.092Z,1557350001.092 [Default:CheckIn:Read_GPS] Stopped 2019-05-08T21:13:21.092Z,1557350001.092 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-05-08T21:13:26.774Z,1557350006.774 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20190508T185439/Courier0075.lzma 2019-05-08T21:13:27.580Z,1557350007.580 [DataOverHttps](INFO): Moved sent file to Logs/20190508T185439/Courier0075.lzma.bak 2019-05-08T21:13:27.580Z,1557350007.580 [DataOverHttps](INFO): SBD MOMSN=10977308 2019-05-08T21:13:39.743Z,1557350019.743 [DataOverHttps](INFO): Sending 560 bytes from file Logs/20190508T185439/Express0076.lzma 2019-05-08T21:13:40.536Z,1557350020.536 [DataOverHttps](INFO): Moved sent file to Logs/20190508T185439/Express0076.lzma.bak 2019-05-08T21:13:40.536Z,1557350020.536 [DataOverHttps](INFO): SBD MOMSN=10977312 2019-05-08T21:13:41.686Z,1557350021.686 [Default:CheckIn:Read_Iridium] Stopped 2019-05-08T21:13:41.686Z,1557350021.686 [Default:CheckIn:C.Wait] Running Loop=1 2019-05-08T21:13:41.686Z,1557350021.686 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-05-08T21:14:23.687Z,1557350063.687 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2019-05-08T21:14:23.687Z,1557350063.687 [RDI_Pathfinder](ERROR): Failed to parse: :TS,19050814220048,35.0, -0.1, 0.0 0 2019-05-08T21:15:43.693Z,1557350143.693 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2019-05-08T21:15:43.693Z,1557350143.693 [RDI_Pathfinder](ERROR): Failed to parse: :TS,19050814232048,35.0, -0.1, 0.0,14 2019-05-08T21:16:54.807Z,1557350214.807 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2019-05-08T21:16:54.807Z,1557350214.807 [RDI_Pathfinder](ERROR): Failed to parse: :TS35.0, -0.1, 0.0,1448.9, 0 2019-05-08T21:17:48.502Z,1557350268.502 [NAL9602](INFO): SBD MO Status=2, MOMSN=3896, MT Status=2, MTMSN=0 2019-05-08T21:17:48.502Z,1557350268.502 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-05-08T21:18:22.838Z,1557350302.838 [NAL9602](INFO): SBD MO Status=2, MOMSN=3896, MT Status=2, MTMSN=0 2019-05-08T21:18:22.838Z,1557350302.838 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-05-08T21:18:23.248Z,1557350303.248 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-05-08T21:18:41.455Z,1557350321.455 [RDI_Pathfinder](ERROR): Failed to parse: :B 0.00, +0.00, 0.00,8763.77 2019-05-08T21:18:42.276Z,1557350322.276 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-05-08T21:18:42.276Z,1557350322.276 [Default:CheckIn:C.Wait] Stopped 2019-05-08T21:18:42.276Z,1557350322.276 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-05-08T21:18:42.276Z,1557350322.276 [Default:CheckIn:D] Running Loop=1 2019-05-08T21:18:42.681Z,1557350322.681 [Default:CheckIn:D] Stopped 2019-05-08T21:18:42.681Z,1557350322.681 [Default:CheckIn:E] Running Loop=1 2019-05-08T21:18:43.073Z,1557350323.073 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 144.186361 min 2019-05-08T21:18:43.073Z,1557350323.073 [Default:CheckIn:E] Stopped 2019-05-08T21:18:43.073Z,1557350323.073 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-05-08T21:18:43.073Z,1557350323.073 [Default:CheckIn] Stopped 2019-05-08T21:18:43.073Z,1557350323.073 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-05-08T21:18:43.074Z,1557350323.074 [Default:CheckIn](INFO): Running loop #27 2019-05-08T21:18:43.074Z,1557350323.074 [Default:CheckIn] Running Loop=27 2019-05-08T21:18:43.074Z,1557350323.074 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-05-08T21:18:43.074Z,1557350323.074 [Default:CheckIn:Read_GPS] Running Loop=1 2019-05-08T21:18:44.662Z,1557350324.662 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:18:45.062Z,1557350325.062 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,211710.00,A,3648.16181,N,12147.28629,W,0.175,19.57,080519,,,A*44 2019-05-08T21:18:45.064Z,1557350325.064 [NAL9602](INFO): GPS fix at 20190508T211710: (36.802697, -121.788105) 2019-05-08T21:18:45.087Z,1557350325.087 [Default:CheckIn:Read_GPS] Stopped 2019-05-08T21:18:45.087Z,1557350325.087 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-05-08T21:18:51.362Z,1557350331.362 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20190508T185439/Courier0078.lzma 2019-05-08T21:18:52.168Z,1557350332.168 [DataOverHttps](INFO): Moved sent file to Logs/20190508T185439/Courier0078.lzma.bak 2019-05-08T21:18:52.168Z,1557350332.168 [DataOverHttps](INFO): SBD MOMSN=10977363 2019-05-08T21:19:05.739Z,1557350345.739 [DataOverHttps](INFO): Sending 634 bytes from file Logs/20190508T185439/Express0079.lzma 2019-05-08T21:19:06.544Z,1557350346.544 [DataOverHttps](INFO): Moved sent file to Logs/20190508T185439/Express0079.lzma.bak 2019-05-08T21:19:06.544Z,1557350346.544 [DataOverHttps](INFO): SBD MOMSN=10977366 2019-05-08T21:19:07.777Z,1557350347.777 [Default:CheckIn:Read_Iridium] Stopped 2019-05-08T21:19:07.777Z,1557350347.777 [Default:CheckIn:C.Wait] Running Loop=1 2019-05-08T21:19:07.777Z,1557350347.777 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-05-08T21:19:17.420Z,1557350357.420 [NAL9602](INFO): Not Powering down - fast GPS 2019-05-08T21:24:08.220Z,1557350648.220 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-05-08T21:24:08.221Z,1557350648.221 [Default:CheckIn:C.Wait] Stopped 2019-05-08T21:24:08.221Z,1557350648.221 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-05-08T21:24:08.222Z,1557350648.222 [Default:CheckIn:D] Running Loop=1 2019-05-08T21:24:08.630Z,1557350648.630 [Default:CheckIn:D] Stopped 2019-05-08T21:24:08.630Z,1557350648.630 [Default:CheckIn:E] Running Loop=1 2019-05-08T21:24:09.034Z,1557350649.034 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 149.618848 min 2019-05-08T21:24:09.034Z,1557350649.034 [Default:CheckIn:E] Stopped 2019-05-08T21:24:09.047Z,1557350649.047 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-05-08T21:24:09.047Z,1557350649.047 [Default:CheckIn] Stopped 2019-05-08T21:24:09.047Z,1557350649.047 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-05-08T21:24:09.047Z,1557350649.047 [Default:CheckIn](INFO): Running loop #28 2019-05-08T21:24:09.047Z,1557350649.047 [Default:CheckIn] Running Loop=28 2019-05-08T21:24:09.047Z,1557350649.047 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-05-08T21:24:09.047Z,1557350649.047 [Default:CheckIn:Read_GPS] Running Loop=1 2019-05-08T21:24:10.607Z,1557350650.607 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:24:10.995Z,1557350650.995 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,212236.00,A,3648.16225,N,12147.28986,W,0.097,19.57,080519,,,A*4C 2019-05-08T21:24:10.997Z,1557350650.997 [NAL9602](INFO): GPS fix at 20190508T212236: (36.802704, -121.788164) 2019-05-08T21:24:11.047Z,1557350651.047 [Default:CheckIn:Read_GPS] Stopped 2019-05-08T21:24:11.047Z,1557350651.047 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-05-08T21:24:28.834Z,1557350668.834 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20190508T185439/Courier0081.lzma 2019-05-08T21:24:29.640Z,1557350669.640 [DataOverHttps](INFO): Moved sent file to Logs/20190508T185439/Courier0081.lzma.bak 2019-05-08T21:24:29.640Z,1557350669.640 [DataOverHttps](INFO): SBD MOMSN=10977418 2019-05-08T21:25:04.393Z,1557350704.393 [DataOverHttps](INFO): Sending 559 bytes from file Logs/20190508T185439/Express0082.lzma 2019-05-08T21:25:05.188Z,1557350705.188 [DataOverHttps](INFO): Moved sent file to Logs/20190508T185439/Express0082.lzma.bak 2019-05-08T21:25:05.188Z,1557350705.188 [DataOverHttps](INFO): SBD MOMSN=10977452 2019-05-08T21:25:07.468Z,1557350707.468 [Default:CheckIn:Read_Iridium] Stopped 2019-05-08T21:25:07.468Z,1557350707.468 [Default:CheckIn:C.Wait] Running Loop=1 2019-05-08T21:25:07.468Z,1557350707.468 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-05-08T21:25:26.213Z,1557350726.213 [NAL9602](INFO): SBD MO Status=2, MOMSN=3896, MT Status=2, MTMSN=0 2019-05-08T21:25:26.214Z,1557350726.214 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-05-08T21:25:51.343Z,1557350751.343 [NAL9602](INFO): SBD MO Status=2, MOMSN=3896, MT Status=2, MTMSN=0 2019-05-08T21:25:51.344Z,1557350751.344 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-05-08T21:26:12.338Z,1557350772.338 [NAL9602](INFO): SBD MO Status=0, MOMSN=3896, MT Status=0, MTMSN=0 2019-05-08T21:26:12.338Z,1557350772.338 [NAL9602](INFO): No messages in MT queue 2019-05-08T21:26:15.686Z,1557350775.686 [RDI_Pathfinder](ERROR): DVL uart error: serial timeout 2019-05-08T21:26:15.686Z,1557350775.686 [RDI_Pathfinder] Communications Fault, FailCount= 1 2019-05-08T21:26:15.686Z,1557350775.686 [RDI_Pathfinder](ERROR): Communications Fault 2019-05-08T21:26:15.687Z,1557350775.687 [RDI_Pathfinder](ERROR): Failed to parse: 2019-05-08T21:26:15.711Z,1557350775.711 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder 2019-05-08T21:26:16.063Z,1557350776.063 [RDI_Pathfinder](INFO): Powering down 2019-05-08T21:26:16.891Z,1557350776.891 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder 2019-05-08T21:26:16.891Z,1557350776.891 [RDI_Pathfinder] No Fault, FailCount= 1 2019-05-08T21:26:30.152Z,1557350790.152 [RDI_Pathfinder](ERROR): Failed to parse:Pathfinder 2019-05-08T21:26:43.044Z,1557350803.044 [NAL9602](INFO): Not Powering down - fast GPS 2019-05-08T21:28:04.763Z,1557350884.763 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2019-05-08T21:28:17.616Z,1557350897.616 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2019-05-08T21:28:17.618Z,1557350897.618 [BPC1](INFO): Received data from all battery sticks. 2019-05-08T21:30:07.905Z,1557351007.905 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-05-08T21:30:07.905Z,1557351007.905 [Default:CheckIn:C.Wait] Stopped 2019-05-08T21:30:07.905Z,1557351007.905 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-05-08T21:30:07.906Z,1557351007.906 [Default:CheckIn:D] Running Loop=1 2019-05-08T21:30:08.309Z,1557351008.309 [Default:CheckIn:D] Stopped 2019-05-08T21:30:08.309Z,1557351008.309 [Default:CheckIn:E] Running Loop=1 2019-05-08T21:30:08.722Z,1557351008.722 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 155.613509 min 2019-05-08T21:30:08.722Z,1557351008.722 [Default:CheckIn:E] Stopped 2019-05-08T21:30:08.722Z,1557351008.722 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-05-08T21:30:08.722Z,1557351008.722 [Default:CheckIn] Stopped 2019-05-08T21:30:08.722Z,1557351008.722 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-05-08T21:30:08.723Z,1557351008.723 [Default:CheckIn](INFO): Running loop #29 2019-05-08T21:30:08.723Z,1557351008.723 [Default:CheckIn] Running Loop=29 2019-05-08T21:30:08.723Z,1557351008.723 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-05-08T21:30:08.723Z,1557351008.723 [Default:CheckIn:Read_GPS] Running Loop=1 2019-05-08T21:30:10.318Z,1557351010.318 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:30:10.707Z,1557351010.707 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,212835.00,A,3648.16308,N,12147.28877,W,0.408,0.00,080519,,,A*7C 2019-05-08T21:30:10.709Z,1557351010.709 [NAL9602](INFO): GPS fix at 20190508T212835: (36.802718, -121.788146) 2019-05-08T21:30:10.733Z,1557351010.733 [Default:CheckIn:Read_GPS] Stopped 2019-05-08T21:30:10.733Z,1557351010.733 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-05-08T21:30:14.566Z,1557351014.566 [DataOverHttps](INFO): Sending 221 bytes from file Logs/20190508T185439/Courier0084.lzma 2019-05-08T21:30:15.116Z,1557351015.116 [DataOverHttps](INFO): Moved sent file to Logs/20190508T185439/Courier0084.lzma.bak 2019-05-08T21:30:15.116Z,1557351015.116 [DataOverHttps](INFO): SBD MOMSN=10977467 2019-05-08T21:30:27.320Z,1557351027.320 [DataOverHttps](INFO): Sending 585 bytes from file Logs/20190508T185439/Express0085.lzma 2019-05-08T21:30:28.124Z,1557351028.124 [DataOverHttps](INFO): Moved sent file to Logs/20190508T185439/Express0085.lzma.bak 2019-05-08T21:30:28.124Z,1557351028.124 [DataOverHttps](INFO): SBD MOMSN=10977470 2019-05-08T21:30:29.535Z,1557351029.535 [Default:CheckIn:Read_Iridium] Stopped 2019-05-08T21:30:29.535Z,1557351029.535 [Default:CheckIn:C.Wait] Running Loop=1 2019-05-08T21:30:29.535Z,1557351029.535 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-05-08T21:30:37.950Z,1557351037.950 [NAL9602](INFO): SBD MO Status=2, MOMSN=3897, MT Status=2, MTMSN=0 2019-05-08T21:30:37.950Z,1557351037.950 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-05-08T21:31:12.290Z,1557351072.290 [NAL9602](INFO): SBD MO Status=2, MOMSN=3897, MT Status=2, MTMSN=0 2019-05-08T21:31:12.290Z,1557351072.290 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-05-08T21:31:37.395Z,1557351097.395 [RDI_Pathfinder](ERROR): Failed to parse: +0.00, +0.00, +0.00, 0.00,306.00 2019-05-08T21:32:48.479Z,1557351168.479 [RDI_Pathfinder](ERROR): only read 2 of 4 data items 2019-05-08T21:32:48.479Z,1557351168.479 [RDI_Pathfinder](ERROR): Failed to parse: :RA, 0.00, 0.00, 0.00 +0.00, +0.00, +0.00, 0.00,376.99 2019-05-08T21:33:39.349Z,1557351219.349 [NAL9602](INFO): SBD MO Status=2, MOMSN=3897, MT Status=2, MTMSN=0 2019-05-08T21:33:39.350Z,1557351219.350 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-05-08T21:34:05.606Z,1557351245.606 [NAL9602](INFO): SBD MO Status=0, MOMSN=3897, MT Status=0, MTMSN=0 2019-05-08T21:34:05.606Z,1557351245.606 [NAL9602](INFO): No messages in MT queue 2019-05-08T21:34:36.306Z,1557351276.306 [NAL9602](INFO): Not Powering down - fast GPS 2019-05-08T21:35:30.068Z,1557351330.068 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-05-08T21:35:30.069Z,1557351330.069 [Default:CheckIn:C.Wait] Stopped 2019-05-08T21:35:30.069Z,1557351330.069 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-05-08T21:35:30.074Z,1557351330.074 [Default:CheckIn:D] Running Loop=1 2019-05-08T21:35:30.481Z,1557351330.481 [Default:CheckIn:D] Stopped 2019-05-08T21:35:30.481Z,1557351330.481 [Default:CheckIn:E] Running Loop=1 2019-05-08T21:35:30.875Z,1557351330.875 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 160.983040 min 2019-05-08T21:35:30.875Z,1557351330.875 [Default:CheckIn:E] Stopped 2019-05-08T21:35:30.875Z,1557351330.875 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-05-08T21:35:30.875Z,1557351330.875 [Default:CheckIn] Stopped 2019-05-08T21:35:30.875Z,1557351330.875 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-05-08T21:35:30.875Z,1557351330.875 [Default:CheckIn](INFO): Running loop #30 2019-05-08T21:35:30.875Z,1557351330.875 [Default:CheckIn] Running Loop=30 2019-05-08T21:35:30.875Z,1557351330.875 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-05-08T21:35:30.876Z,1557351330.876 [Default:CheckIn:Read_GPS] Running Loop=1 2019-05-08T21:35:32.478Z,1557351332.478 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:35:32.874Z,1557351332.874 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,213358.00,A,3648.16489,N,12147.27974,W,0.447,136.85,080519,,,A*7C 2019-05-08T21:35:32.876Z,1557351332.876 [NAL9602](INFO): GPS fix at 20190508T213358: (36.802748, -121.787996) 2019-05-08T21:35:32.900Z,1557351332.900 [Default:CheckIn:Read_GPS] Stopped 2019-05-08T21:35:32.900Z,1557351332.900 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-05-08T21:35:38.914Z,1557351338.914 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20190508T185439/Courier0087.lzma 2019-05-08T21:35:39.720Z,1557351339.720 [DataOverHttps](INFO): Moved sent file to Logs/20190508T185439/Courier0087.lzma.bak 2019-05-08T21:35:39.720Z,1557351339.720 [DataOverHttps](INFO): SBD MOMSN=10977546 2019-05-08T21:35:52.239Z,1557351352.239 [DataOverHttps](INFO): Sending 553 bytes from file Logs/20190508T185439/Express0088.lzma 2019-05-08T21:35:53.044Z,1557351353.044 [DataOverHttps](INFO): Moved sent file to Logs/20190508T185439/Express0088.lzma.bak 2019-05-08T21:35:53.044Z,1557351353.044 [DataOverHttps](INFO): SBD MOMSN=10977549 2019-05-08T21:35:54.043Z,1557351354.043 [Default:CheckIn:Read_Iridium] Stopped 2019-05-08T21:35:54.043Z,1557351354.043 [Default:CheckIn:C.Wait] Running Loop=1 2019-05-08T21:35:54.043Z,1557351354.043 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-05-08T21:37:05.119Z,1557351425.119 [NAL9602](INFO): SBD MO Status=2, MOMSN=3898, MT Status=2, MTMSN=0 2019-05-08T21:37:05.120Z,1557351425.120 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-05-08T21:38:21.453Z,1557351501.453 [NAL9602](INFO): SBD MO Status=2, MOMSN=3898, MT Status=2, MTMSN=0 2019-05-08T21:38:21.454Z,1557351501.454 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-05-08T21:38:49.329Z,1557351529.329 [NAL9602](INFO): SBD MO Status=2, MOMSN=3898, MT Status=2, MTMSN=0 2019-05-08T21:38:49.330Z,1557351529.330 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-05-08T21:39:22.477Z,1557351562.477 [RDI_Pathfinder](ERROR): only read 0 of 4 data items 2019-05-08T21:39:22.477Z,1557351562.477 [RDI_Pathfinder](ERROR): Failed to parse: :BS-32768,-32768,V 2019-05-08T21:39:58.449Z,1557351598.449 [RDI_Pathfinder](ERROR): only read 2 of 4 data items 2019-05-08T21:39:58.449Z,1557351598.449 [RDI_Pathfinder](ERROR): Failed to parse: :BS,-3278,-32768,V 2019-05-08T21:40:35.577Z,1557351635.577 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-05-08T21:40:42.460Z,1557351642.460 [RDI_Pathfinder](ERROR): only read 0 of 4 data items 2019-05-08T21:40:42.460Z,1557351642.460 [RDI_Pathfinder](ERROR): Failed to parse: :RA 0.00, 0.00, 0.00, 0.00 2019-05-08T21:40:54.597Z,1557351654.597 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-05-08T21:40:54.597Z,1557351654.597 [Default:CheckIn:C.Wait] Stopped 2019-05-08T21:40:54.597Z,1557351654.597 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-05-08T21:40:54.598Z,1557351654.598 [Default:CheckIn:D] Running Loop=1 2019-05-08T21:40:54.993Z,1557351654.993 [Default:CheckIn:D] Stopped 2019-05-08T21:40:54.993Z,1557351654.993 [Default:CheckIn:E] Running Loop=1 2019-05-08T21:40:55.413Z,1557351655.413 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 166.391569 min 2019-05-08T21:40:55.414Z,1557351655.414 [Default:CheckIn:E] Stopped 2019-05-08T21:40:55.414Z,1557351655.414 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-05-08T21:40:55.414Z,1557351655.414 [Default:CheckIn] Stopped 2019-05-08T21:40:55.414Z,1557351655.414 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-05-08T21:40:55.414Z,1557351655.414 [Default:CheckIn](INFO): Running loop #31 2019-05-08T21:40:55.414Z,1557351655.414 [Default:CheckIn] Running Loop=31 2019-05-08T21:40:55.415Z,1557351655.415 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-05-08T21:40:55.415Z,1557351655.415 [Default:CheckIn:Read_GPS] Running Loop=1 2019-05-08T21:40:57.006Z,1557351657.006 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:40:57.398Z,1557351657.398 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,213922.00,A,3648.17238,N,12147.28214,W,0.408,194.97,080519,,,A*74 2019-05-08T21:40:57.400Z,1557351657.400 [NAL9602](INFO): GPS fix at 20190508T213922: (36.802873, -121.788036) 2019-05-08T21:40:57.457Z,1557351657.457 [Default:CheckIn:Read_GPS] Stopped 2019-05-08T21:40:57.457Z,1557351657.457 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-05-08T21:41:03.418Z,1557351663.418 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20190508T185439/Courier0090.lzma 2019-05-08T21:41:04.224Z,1557351664.224 [DataOverHttps](INFO): Moved sent file to Logs/20190508T185439/Courier0090.lzma.bak 2019-05-08T21:41:04.224Z,1557351664.224 [DataOverHttps](INFO): SBD MOMSN=10977572 2019-05-08T21:41:16.663Z,1557351676.663 [DataOverHttps](INFO): Sending 648 bytes from file Logs/20190508T185439/Express0091.lzma 2019-05-08T21:41:17.909Z,1557351677.909 [DataOverHttps](INFO): Moved sent file to Logs/20190508T185439/Express0091.lzma.bak 2019-05-08T21:41:17.910Z,1557351677.910 [DataOverHttps](INFO): SBD MOMSN=10977575 2019-05-08T21:41:18.505Z,1557351678.505 [Default:CheckIn:Read_Iridium] Stopped 2019-05-08T21:41:18.505Z,1557351678.505 [Default:CheckIn:C.Wait] Running Loop=1 2019-05-08T21:41:18.506Z,1557351678.506 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-05-08T21:41:29.376Z,1557351689.376 [NAL9602](INFO): Not Powering down - fast GPS 2019-05-08T21:46:19.070Z,1557351979.070 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-05-08T21:46:19.070Z,1557351979.070 [Default:CheckIn:C.Wait] Stopped 2019-05-08T21:46:19.071Z,1557351979.071 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-05-08T21:46:19.071Z,1557351979.071 [Default:CheckIn:D] Running Loop=1 2019-05-08T21:46:19.498Z,1557351979.498 [Default:CheckIn:D] Stopped 2019-05-08T21:46:19.499Z,1557351979.499 [Default:CheckIn:E] Running Loop=1 2019-05-08T21:46:19.893Z,1557351979.893 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 171.800000 min 2019-05-08T21:46:19.893Z,1557351979.893 [Default:CheckIn:E] Stopped 2019-05-08T21:46:19.893Z,1557351979.893 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-05-08T21:46:19.893Z,1557351979.893 [Default:CheckIn] Stopped 2019-05-08T21:46:19.894Z,1557351979.894 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-05-08T21:46:19.894Z,1557351979.894 [Default:CheckIn](INFO): Running loop #32 2019-05-08T21:46:19.894Z,1557351979.894 [Default:CheckIn] Running Loop=32 2019-05-08T21:46:19.894Z,1557351979.894 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-05-08T21:46:19.894Z,1557351979.894 [Default:CheckIn:Read_GPS] Running Loop=1 2019-05-08T21:46:21.482Z,1557351981.482 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:46:21.882Z,1557351981.882 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,214447.00,A,3648.16036,N,12147.29024,W,0.233,194.97,080519,,,A*7E 2019-05-08T21:46:21.884Z,1557351981.884 [NAL9602](INFO): GPS fix at 20190508T214447: (36.802673, -121.788171) 2019-05-08T21:46:21.907Z,1557351981.907 [Default:CheckIn:Read_GPS] Stopped 2019-05-08T21:46:21.908Z,1557351981.908 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-05-08T21:46:27.518Z,1557351987.518 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20190508T185439/Courier0093.lzma 2019-05-08T21:46:28.328Z,1557351988.328 [DataOverHttps](INFO): Moved sent file to Logs/20190508T185439/Courier0093.lzma.bak 2019-05-08T21:46:28.328Z,1557351988.328 [DataOverHttps](INFO): SBD MOMSN=10977664 2019-05-08T21:46:40.571Z,1557352000.571 [DataOverHttps](INFO): Sending 557 bytes from file Logs/20190508T185439/Express0094.lzma 2019-05-08T21:46:41.376Z,1557352001.376 [DataOverHttps](INFO): Moved sent file to Logs/20190508T185439/Express0094.lzma.bak 2019-05-08T21:46:41.376Z,1557352001.376 [DataOverHttps](INFO): SBD MOMSN=10977667 2019-05-08T21:46:42.657Z,1557352002.657 [Default:CheckIn:Read_Iridium] Stopped 2019-05-08T21:46:42.657Z,1557352002.657 [Default:CheckIn:C.Wait] Running Loop=1 2019-05-08T21:46:42.657Z,1557352002.657 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-05-08T21:46:52.332Z,1557352012.332 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2019-05-08T21:46:52.406Z,1557352012.406 [NAL9602](FAULT): received: +CSQ:0 OK98, 2, 0, 0, 0 OK 2019-05-08T21:46:52.406Z,1557352012.406 [NAL9602] Data Fault, FailCount= 1 2019-05-08T21:46:52.407Z,1557352012.407 [NAL9602](ERROR): Data Fault 2019-05-08T21:46:52.490Z,1557352012.490 [CBIT](ERROR): Data Fault in component: NAL9602 2019-05-08T21:46:52.732Z,1557352012.732 [NAL9602](INFO): Powering down 2019-05-08T21:46:53.578Z,1557352013.578 [CBIT](INFO): Clearing failed state for component NAL9602 2019-05-08T21:46:53.578Z,1557352013.578 [NAL9602] No Fault, FailCount= 1 2019-05-08T21:47:23.040Z,1557352043.040 [NAL9602](INFO): Powering up NAL9602 2019-05-08T21:47:33.946Z,1557352053.946 [NAL9602](INFO): NAL9602 initialized 2019-05-08T21:48:05.061Z,1557352085.061 [NAL9602](INFO): Not Powering down - fast GPS 2019-05-08T21:51:04.443Z,1557352264.443 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2019-05-08T21:51:04.443Z,1557352264.443 [RDI_Pathfinder](ERROR): Failed to parse: :TS,19050814584133,35.0, -0.1, .9, 0 2019-05-08T21:51:43.249Z,1557352303.249 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-05-08T21:51:43.249Z,1557352303.249 [Default:CheckIn:C.Wait] Stopped 2019-05-08T21:51:43.249Z,1557352303.249 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-05-08T21:51:43.249Z,1557352303.249 [Default:CheckIn:D] Running Loop=1 2019-05-08T21:51:43.645Z,1557352303.645 [Default:CheckIn:D] Stopped 2019-05-08T21:51:43.645Z,1557352303.645 [Default:CheckIn:E] Running Loop=1 2019-05-08T21:51:44.075Z,1557352304.075 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 177.202441 min 2019-05-08T21:51:44.076Z,1557352304.076 [Default:CheckIn:E] Stopped 2019-05-08T21:51:44.076Z,1557352304.076 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-05-08T21:51:44.076Z,1557352304.076 [Default:CheckIn] Stopped 2019-05-08T21:51:44.077Z,1557352304.077 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-05-08T21:51:44.078Z,1557352304.078 [Default:CheckIn](INFO): Running loop #33 2019-05-08T21:51:44.078Z,1557352304.078 [Default:CheckIn] Running Loop=33 2019-05-08T21:51:44.079Z,1557352304.079 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-05-08T21:51:44.079Z,1557352304.079 [Default:CheckIn:Read_GPS] Running Loop=1 2019-05-08T21:51:45.654Z,1557352305.654 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:51:48.064Z,1557352308.064 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-05-08T21:51:48.886Z,1557352308.886 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:51:51.714Z,1557352311.714 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:51:54.534Z,1557352314.534 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:51:57.370Z,1557352317.370 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:52:00.602Z,1557352320.602 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:52:03.430Z,1557352323.430 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:52:06.659Z,1557352326.659 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:52:09.494Z,1557352329.494 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:52:12.726Z,1557352332.726 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:52:15.550Z,1557352335.550 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:52:18.378Z,1557352338.378 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:52:21.606Z,1557352341.606 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:52:24.434Z,1557352344.434 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:52:27.666Z,1557352347.666 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:52:30.498Z,1557352350.498 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:52:33.730Z,1557352353.730 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:52:36.558Z,1557352356.558 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:52:39.386Z,1557352359.386 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:52:42.629Z,1557352362.629 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:52:45.442Z,1557352365.442 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:52:48.678Z,1557352368.678 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:52:51.510Z,1557352371.510 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:52:54.738Z,1557352374.738 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:52:57.562Z,1557352377.562 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:53:00.390Z,1557352380.390 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:53:03.619Z,1557352383.619 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:53:06.454Z,1557352386.454 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:53:09.682Z,1557352389.682 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:53:12.510Z,1557352392.510 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:53:15.746Z,1557352395.746 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:53:18.580Z,1557352398.580 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:53:21.402Z,1557352401.402 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:53:23.826Z,1557352403.826 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:53:26.654Z,1557352406.654 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:53:29.478Z,1557352409.478 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:53:32.710Z,1557352412.710 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:53:35.542Z,1557352415.542 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:53:38.774Z,1557352418.774 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:53:41.598Z,1557352421.598 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:53:44.474Z,1557352424.474 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:53:47.658Z,1557352427.658 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:53:50.486Z,1557352430.486 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:53:53.718Z,1557352433.718 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:53:56.550Z,1557352436.550 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:53:59.778Z,1557352439.778 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:54:02.606Z,1557352442.606 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:54:05.438Z,1557352445.438 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:54:08.670Z,1557352448.670 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:54:11.498Z,1557352451.498 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:54:14.738Z,1557352454.738 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:54:17.554Z,1557352457.554 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:54:20.790Z,1557352460.790 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:54:23.614Z,1557352463.614 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:54:26.442Z,1557352466.442 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:54:29.678Z,1557352469.678 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:54:32.502Z,1557352472.502 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:54:35.734Z,1557352475.734 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:54:38.562Z,1557352478.562 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:54:41.394Z,1557352481.394 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:54:44.622Z,1557352484.622 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:54:47.446Z,1557352487.446 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:54:50.690Z,1557352490.690 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:54:53.510Z,1557352493.510 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:54:56.742Z,1557352496.742 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:54:59.574Z,1557352499.574 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:55:02.398Z,1557352502.398 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:55:05.634Z,1557352505.634 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:55:08.478Z,1557352508.478 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:55:11.699Z,1557352511.699 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:55:14.526Z,1557352514.526 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:55:17.754Z,1557352517.754 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:55:20.578Z,1557352520.578 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:55:23.406Z,1557352523.406 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:55:26.642Z,1557352526.642 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:55:29.470Z,1557352529.470 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:55:32.702Z,1557352532.702 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:55:35.530Z,1557352535.530 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:55:38.758Z,1557352538.758 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:55:41.594Z,1557352541.594 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:55:44.410Z,1557352544.410 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:55:47.650Z,1557352547.650 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:55:50.478Z,1557352550.478 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:55:53.706Z,1557352553.706 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:55:56.534Z,1557352556.534 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:55:59.766Z,1557352559.766 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:56:02.590Z,1557352562.590 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:56:05.422Z,1557352565.422 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:56:08.658Z,1557352568.658 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:56:11.482Z,1557352571.482 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:56:14.715Z,1557352574.715 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:56:17.557Z,1557352577.557 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:56:20.786Z,1557352580.786 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:56:23.606Z,1557352583.606 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:56:26.430Z,1557352586.430 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:56:29.662Z,1557352589.662 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:56:32.490Z,1557352592.490 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:56:35.726Z,1557352595.726 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:56:38.554Z,1557352598.554 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:56:41.778Z,1557352601.778 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:56:44.255Z,1557352604.255 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-05-08T21:51:44.1Z 2019-05-08T21:56:44.255Z,1557352604.255 [Default:CheckIn:Read_GPS] Stopped 2019-05-08T21:56:44.255Z,1557352604.255 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-05-08T21:56:44.610Z,1557352604.610 [NAL9602](DEBUG): Fix Requested 2019-05-08T21:56:50.258Z,1557352610.258 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190508T185439/Courier0096.lzma 2019-05-08T21:56:51.070Z,1557352611.070 [DataOverHttps](INFO): Moved sent file to Logs/20190508T185439/Courier0096.lzma.bak 2019-05-08T21:56:51.070Z,1557352611.070 [DataOverHttps](INFO): SBD MOMSN=10977771 2019-05-08T21:57:03.000Z,1557352624.000 [DataOverHttps](INFO): Sending 1023 bytes from file Logs/20190508T185439/Express0097.lzma 2019-05-08T21:57:04.804Z,1557352624.804 [DataOverHttps](INFO): Moved sent file to Logs/20190508T185439/Express0097.lzma.bak 2019-05-08T21:57:04.804Z,1557352624.804 [DataOverHttps](INFO): SBD MOMSN=10977773 2019-05-08T21:57:05.824Z,1557352625.824 [Default:CheckIn:Read_Iridium] Stopped 2019-05-08T21:57:05.824Z,1557352625.824 [Default:CheckIn:C.Wait] Running Loop=1 2019-05-08T21:57:05.824Z,1557352625.824 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-05-08T21:57:17.508Z,1557352637.508 [NAL9602](INFO): Not Powering down - fast GPS 2019-05-08T22:00:56.732Z,1557352856.732 [CommandLine](IMPORTANT): got command restart application 2019-05-08T22:00:57.738Z,1557352857.738 [Supervisor](INFO): Stop Mission called by Supervisor::terminate 2019-05-08T22:00:57.739Z,1557352857.739 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2019-05-08T22:00:57.739Z,1557352857.739 [CommandLine ThreadHandler](INFO): Thread cancelled. 2019-05-08T22:00:57.886Z,1557352857.886 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2019-05-08T22:00:57.886Z,1557352857.886 [CommandLine ThreadHandler](INFO): Thread cancelled. 2019-05-08T22:00:57.887Z,1557352857.887 [CommandLine](INFO): Join timeout helper Thread ID is 1848 2019-05-08T22:00:57.888Z,1557352857.888 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2019-05-08T22:00:57.888Z,1557352857.888 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2019-05-08T22:00:57.888Z,1557352857.888 [NavChartDb](INFO): Join timeout helper Thread ID is 1849 2019-05-08T22:00:57.898Z,1557352857.898 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2019-05-08T22:00:57.899Z,1557352857.899 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2019-05-08T22:00:57.906Z,1557352857.906 [ComponentRegistry](INFO): Shutting down WetLabsSeaOWL_UV_A ThreadHandler 2019-05-08T22:00:57.906Z,1557352857.906 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled. 2019-05-08T22:00:57.907Z,1557352857.907 [WetLabsSeaOWL_UV_A](INFO): Join timeout helper Thread ID is 1850 2019-05-08T22:00:58.087Z,1557352858.087 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Uninitializing protected caller thread. 2019-05-08T22:00:58.087Z,1557352858.087 [WetLabsSeaOWL_UV_A](INFO): Powering down 2019-05-08T22:00:58.088Z,1557352858.088 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled. 2019-05-08T22:00:58.092Z,1557352858.092 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler 2019-05-08T22:00:58.092Z,1557352858.092 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled. 2019-05-08T22:00:58.096Z,1557352858.096 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 1851 2019-05-08T22:00:58.231Z,1557352858.231 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread. 2019-05-08T22:00:58.231Z,1557352858.231 [CTD_NeilBrown](INFO): Powering down 2019-05-08T22:00:58.242Z,1557352858.242 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled. 2019-05-08T22:00:58.254Z,1557352858.254 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2019-05-08T22:00:58.254Z,1557352858.254 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2019-05-08T22:00:58.255Z,1557352858.255 [Radio_Surface](INFO): Join timeout helper Thread ID is 1852 2019-05-08T22:00:58.486Z,1557352858.486 [Radio_Surface](INFO): Powering down 2019-05-08T22:00:58.487Z,1557352858.487 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2019-05-08T22:00:58.488Z,1557352858.488 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2019-05-08T22:00:58.495Z,1557352858.495 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler 2019-05-08T22:00:58.495Z,1557352858.495 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2019-05-08T22:00:58.496Z,1557352858.496 [DataOverHttps](INFO): Join timeout helper Thread ID is 1853 2019-05-08T22:00:58.554Z,1557352858.554 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread. 2019-05-08T22:00:58.555Z,1557352858.555 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2019-05-08T22:00:58.563Z,1557352858.563 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2019-05-08T22:00:58.563Z,1557352858.563 [logger ThreadHandler](INFO): Thread cancelled. 2019-05-08T22:00:58.564Z,1557352858.564 [logger](INFO): Join timeout helper Thread ID is 1854 2019-05-08T22:00:58.615Z,1557352858.615 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2019-05-08T22:00:58.616Z,1557352858.616 [logger ThreadHandler](INFO): Thread cancelled. 2019-05-08T22:00:58.619Z,1557352858.619 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2019-05-08T22:00:58.619Z,1557352858.619 [CommandLine ThreadHandler](INFO): Thread cancelled. 2019-05-08T22:00:58.619Z,1557352858.619 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2019-05-08T22:00:58.619Z,1557352858.619 [controlThread ThreadHandler](INFO): Thread cancelled. 2019-05-08T22:00:58.620Z,1557352858.620 [controlThread](INFO): Join timeout helper Thread ID is 1855 2019-05-08T22:00:58.882Z,1557352858.882 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2019-05-08T22:00:58.883Z,1557352858.883 [controlThread](DEBUG): Uninitializing ControlThread 2019-05-08T22:00:58.883Z,1557352858.883 [AHRS_M2](INFO): Powering down 2019-05-08T22:00:58.955Z,1557352858.955 [DUSBL_Hydroid](INFO): Powering down 2019-05-08T22:00:59.027Z,1557352859.027 [Micromodem](INFO): Powering down 2019-05-08T22:00:59.123Z,1557352859.123 [NAL9602](INFO): Powering down 2019-05-08T22:00:59.194Z,1557352859.194 [RDI_Pathfinder](INFO): Powering down 2019-05-08T22:00:59.196Z,1557352859.196 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator. 2019-05-08T22:00:59.197Z,1557352859.197 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator. 2019-05-08T22:00:59.197Z,1557352859.197 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2019-05-08T22:00:59.197Z,1557352859.197 [MissionManager](INFO): Uninitializing Mission Default 2019-05-08T22:00:59.198Z,1557352859.198 [Default] Stopped 2019-05-08T22:00:59.198Z,1557352859.198 [Default](DEBUG): Aggregate::uninitialize Default 2019-05-08T22:00:59.198Z,1557352859.198 [Default:B.GoToSurface] Stopped 2019-05-08T22:00:59.198Z,1557352859.198 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2019-05-08T22:00:59.198Z,1557352859.198 [Default:CheckIn] Stopped 2019-05-08T22:00:59.198Z,1557352859.198 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-05-08T22:00:59.198Z,1557352859.198 [Default:CheckIn:C.Wait] Stopped 2019-05-08T22:00:59.198Z,1557352859.198 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-05-08T22:00:59.201Z,1557352859.201 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2019-05-08T22:00:59.201Z,1557352859.201 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2019-05-08T22:00:59.201Z,1557352859.201 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2019-05-08T22:00:59.202Z,1557352859.202 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2019-05-08T22:00:59.202Z,1557352859.202 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2019-05-08T22:00:59.202Z,1557352859.202 [BuoyancyServo](INFO): Powering down 2019-05-08T22:00:59.214Z,1557352859.214 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2019-05-08T22:00:59.214Z,1557352859.214 [ElevatorServo](INFO): Powering down 2019-05-08T22:00:59.215Z,1557352859.215 [MassServo](DEBUG): Uninitialize Mass Servo. 2019-05-08T22:00:59.215Z,1557352859.215 [MassServo](INFO): Powering down 2019-05-08T22:00:59.216Z,1557352859.216 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2019-05-08T22:00:59.216Z,1557352859.216 [RudderServo](INFO): Powering down 2019-05-08T22:00:59.217Z,1557352859.217 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2019-05-08T22:00:59.217Z,1557352859.217 [ThrusterServo](INFO): Powering down 2019-05-08T22:00:59.218Z,1557352859.218 [SBIT](DEBUG): Uninitialize SBIT Component. 2019-05-08T22:00:59.218Z,1557352859.218 [IBIT](DEBUG): Uninitialize IBIT Component. 2019-05-08T22:00:59.219Z,1557352859.219 [CBIT](DEBUG): Uninitialize CBIT Component. 2019-05-08T22:00:59.219Z,1557352859.219 [CBIT](DEBUG): Powering off loads. 2019-05-08T22:00:59.230Z,1557352859.230 [CBIT](DEBUG): Disabling WDT. 2019-05-08T22:00:59.242Z,1557352859.242 [CBIT](DEBUG): Opening all GF detection circuits. 2019-05-08T22:00:59.243Z,1557352859.243 [controlThread ThreadHandler](INFO): Thread cancelled. 2019-05-08T22:00:59.295Z,1557352859.295 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2019-05-08T22:00:59.303Z,1557352859.303 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2019-05-08T22:00:59.354Z,1557352859.354 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled. 2019-05-08T22:00:59.356Z,1557352859.356 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled. 2019-05-08T22:00:59.431Z,1557352859.431 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2019-05-08T22:00:59.500Z,1557352859.500 [logger ThreadHandler](INFO): Thread cancelled.