2019-10-22T19:16:15.584Z,1571771775.584 [Default:E.Execute](INFO): Executing command restart logs 2019-10-22T19:16:15.586Z,1571771775.586 [Default:E.Execute] Stopped 2019-10-22T19:16:15.590Z,1571771775.590 [Default](INFO): Completed Default 2019-10-22T19:16:15.591Z,1571771775.591 [Default] Stopped 2019-10-22T19:16:15.591Z,1571771775.591 [Default](DEBUG): Aggregate::uninitialize Default 2019-10-22T19:16:15.591Z,1571771775.591 [Default:B.GoToSurface] Stopped 2019-10-22T19:16:15.591Z,1571771775.591 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2019-10-22T19:16:15.623Z,1571771775.623 [CommandLine](IMPORTANT): got command restart logs 2019-10-22T19:16:16.002Z,1571771776.002 [MissionManager](IMPORTANT): Started mission Default 2019-10-22T19:16:16.003Z,1571771776.003 [Default] Running Loop=1 2019-10-22T19:16:16.003Z,1571771776.003 [Default](DEBUG): Aggregate::initialize Default 2019-10-22T19:16:16.003Z,1571771776.003 [Default:B.GoToSurface] Running Loop=1 2019-10-22T19:16:16.003Z,1571771776.003 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2019-10-22T19:16:16.003Z,1571771776.003 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2019-10-22T19:16:16.003Z,1571771776.003 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2019-10-22T19:16:16.004Z,1571771776.004 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2019-10-22T19:16:16.004Z,1571771776.004 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2019-10-22T19:16:16.004Z,1571771776.004 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2019-10-22T19:16:16.005Z,1571771776.005 [Default:A.Wait] Running Loop=1 2019-10-22T19:16:16.005Z,1571771776.005 [Default:A.Wait](DEBUG): Initialize Wait Component. 2019-10-22T19:16:29.319Z,1571771789.319 [Default:A.Wait](INFO): Done Waiting. 2019-10-22T19:16:29.319Z,1571771789.319 [Default:A.Wait] Stopped 2019-10-22T19:16:29.319Z,1571771789.319 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2019-10-22T19:16:29.735Z,1571771789.735 [Default:CheckIn] Running Loop=1 2019-10-22T19:16:29.735Z,1571771789.735 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-10-22T19:16:29.735Z,1571771789.735 [Default:CheckIn:Read_GPS] Running Loop=1 2019-10-22T19:16:31.306Z,1571771791.306 [NAL9602](DEBUG): Fix Requested 2019-10-22T19:16:31.704Z,1571771791.704 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,191632.00,A,3648.16022,N,12147.28851,W,0.389,340.94,221019,,,A*7A 2019-10-22T19:16:31.706Z,1571771791.706 [NAL9602](INFO): GPS fix at 20191022T191632: (36.802670, -121.788142) 2019-10-22T19:16:31.734Z,1571771791.734 [Default:CheckIn:Read_GPS] Stopped 2019-10-22T19:16:31.735Z,1571771791.735 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-10-22T19:16:42.334Z,1571771802.334 [DataOverHttps](INFO): Sending 215 bytes from file Logs/20191022T191615/Courier0000.lzma 2019-10-22T19:16:46.974Z,1571771806.974 [DataOverHttps](INFO): Moved sent file to Logs/20191022T191615/Courier0000.lzma.bak 2019-10-22T19:16:46.974Z,1571771806.974 [DataOverHttps](INFO): SBD MOMSN=11946202 2019-10-22T19:17:02.400Z,1571771822.400 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2019-10-22T19:17:02.475Z,1571771822.475 [NAL9602](FAULT): received: +CSQ:0 OK44, 2, 0, 0, 0 OK 2019-10-22T19:17:02.475Z,1571771822.475 [NAL9602] Data Fault, FailCount= 1 2019-10-22T19:17:02.475Z,1571771822.475 [NAL9602](ERROR): Data Fault 2019-10-22T19:17:02.579Z,1571771822.579 [CBIT](ERROR): Data Fault in component: NAL9602 2019-10-22T19:17:02.805Z,1571771822.805 [NAL9602](INFO): Powering down 2019-10-22T19:17:03.672Z,1571771823.672 [CBIT](INFO): Clearing failed state for component NAL9602 2019-10-22T19:17:03.672Z,1571771823.672 [NAL9602] No Fault, FailCount= 1 2019-10-22T19:17:09.918Z,1571771829.918 [DataOverHttps](INFO): Sending 247 bytes from file Logs/20191021T090721/Express0865.lzma 2019-10-22T19:17:11.925Z,1571771831.925 [DataOverHttps](INFO): Moved sent file to Logs/20191021T090721/Express0865.lzma.bak 2019-10-22T19:17:11.925Z,1571771831.925 [DataOverHttps](INFO): SBD MOMSN=11946206 2019-10-22T19:17:33.101Z,1571771853.101 [NAL9602](INFO): Powering up NAL9602 2019-10-22T19:17:37.246Z,1571771857.246 [DataOverHttps](INFO): Sending 298 bytes from file Logs/20191022T191615/Express0001.lzma 2019-10-22T19:17:39.252Z,1571771859.252 [DataOverHttps](INFO): Moved sent file to Logs/20191022T191615/Express0001.lzma.bak 2019-10-22T19:17:39.252Z,1571771859.252 [DataOverHttps](INFO): SBD MOMSN=11946211 2019-10-22T19:17:44.013Z,1571771864.013 [NAL9602](INFO): NAL9602 initialized 2019-10-22T19:17:46.530Z,1571771866.530 [Default:CheckIn:Read_Iridium] Stopped 2019-10-22T19:17:46.530Z,1571771866.530 [Default:CheckIn:C.Wait] Running Loop=1 2019-10-22T19:17:46.530Z,1571771866.530 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-10-22T19:18:15.124Z,1571771895.124 [NAL9602](INFO): Not Powering down - fast GPS 2019-10-22T19:22:47.055Z,1571772167.055 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-10-22T19:22:47.055Z,1571772167.055 [Default:CheckIn:C.Wait] Stopped 2019-10-22T19:22:47.055Z,1571772167.055 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-10-22T19:22:47.055Z,1571772167.055 [Default:CheckIn:D] Running Loop=1 2019-10-22T19:22:47.436Z,1571772167.436 [Default:CheckIn:D] Stopped 2019-10-22T19:22:47.436Z,1571772167.436 [Default:CheckIn:E] Running Loop=1 2019-10-22T19:22:47.858Z,1571772167.858 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 6.523882 min 2019-10-22T19:22:47.858Z,1571772167.858 [Default:CheckIn:E] Stopped 2019-10-22T19:22:47.859Z,1571772167.859 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-10-22T19:22:47.859Z,1571772167.859 [Default:CheckIn] Stopped 2019-10-22T19:22:47.859Z,1571772167.859 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-10-22T19:22:47.859Z,1571772167.859 [Default:CheckIn](INFO): Running loop #2 2019-10-22T19:22:47.859Z,1571772167.859 [Default:CheckIn] Running Loop=2 2019-10-22T19:22:47.859Z,1571772167.859 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-10-22T19:22:47.859Z,1571772167.859 [Default:CheckIn:Read_GPS] Running Loop=1 2019-10-22T19:22:49.454Z,1571772169.454 [NAL9602](DEBUG): Fix Requested 2019-10-22T19:22:49.836Z,1571772169.836 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,192249.00,A,3648.16532,N,12147.29235,W,0.389,335.34,221019,,,A*74 2019-10-22T19:22:49.839Z,1571772169.839 [NAL9602](INFO): GPS fix at 20191022T192249: (36.802755, -121.788206) 2019-10-22T19:22:49.903Z,1571772169.903 [Default:CheckIn:Read_GPS] Stopped 2019-10-22T19:22:49.903Z,1571772169.903 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-10-22T19:22:51.861Z,1571772171.861 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-10-22T19:22:58.830Z,1571772178.830 [DataOverHttps](INFO): Sending 65 bytes from file Logs/20191022T191615/Courier0003.lzma 2019-10-22T19:23:00.840Z,1571772180.840 [DataOverHttps](INFO): Moved sent file to Logs/20191022T191615/Courier0003.lzma.bak 2019-10-22T19:23:00.841Z,1571772180.841 [DataOverHttps](INFO): SBD MOMSN=11946222 2019-10-22T19:23:22.560Z,1571772202.560 [NAL9602](INFO): Not Powering down - fast GPS 2019-10-22T19:23:24.902Z,1571772204.902 [DataOverHttps](INFO): Sending 206 bytes from file Logs/20191022T191615/Express0004.lzma 2019-10-22T19:23:26.908Z,1571772206.908 [DataOverHttps](INFO): Moved sent file to Logs/20191022T191615/Express0004.lzma.bak 2019-10-22T19:23:26.908Z,1571772206.908 [DataOverHttps](INFO): SBD MOMSN=11946225 2019-10-22T19:23:35.926Z,1571772215.926 [Default:CheckIn:Read_Iridium] Stopped 2019-10-22T19:23:35.926Z,1571772215.926 [Default:CheckIn:C.Wait] Running Loop=1 2019-10-22T19:23:35.926Z,1571772215.926 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-10-22T19:26:38.931Z,1571772398.931 [RDI_Pathfinder](ERROR): only read 3 of 4 data items 2019-10-22T19:26:38.931Z,1571772398.931 [RDI_Pathfinder](ERROR): Failed to parse: :RA, 0.00, 0.00, 0.00, 0.00 2019-10-22T19:28:13.875Z,1571772493.875 [RDI_Pathfinder](ERROR): only read 3 of 4 data items 2019-10-22T19:28:13.875Z,1571772493.875 [RDI_Pathfinder](ERROR): Failed to parse: :RA, 0.00, 0.00, 0.00, 0.00 2019-10-22T19:28:36.528Z,1571772516.528 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-10-22T19:28:36.528Z,1571772516.528 [Default:CheckIn:C.Wait] Stopped 2019-10-22T19:28:36.528Z,1571772516.528 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-10-22T19:28:36.529Z,1571772516.529 [Default:CheckIn:D] Running Loop=1 2019-10-22T19:28:36.902Z,1571772516.902 [Default:CheckIn:D] Stopped 2019-10-22T19:28:36.902Z,1571772516.902 [Default:CheckIn:E] Running Loop=1 2019-10-22T19:28:37.319Z,1571772517.319 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 12.348322 min 2019-10-22T19:28:37.319Z,1571772517.319 [Default:CheckIn:E] Stopped 2019-10-22T19:28:37.319Z,1571772517.319 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-10-22T19:28:37.319Z,1571772517.319 [Default:CheckIn] Stopped 2019-10-22T19:28:37.319Z,1571772517.319 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-10-22T19:28:37.319Z,1571772517.319 [Default:CheckIn](INFO): Running loop #3 2019-10-22T19:28:37.319Z,1571772517.319 [Default:CheckIn] Running Loop=3 2019-10-22T19:28:37.320Z,1571772517.320 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-10-22T19:28:37.320Z,1571772517.320 [Default:CheckIn:Read_GPS] Running Loop=1 2019-10-22T19:28:38.914Z,1571772518.914 [NAL9602](DEBUG): Fix Requested 2019-10-22T19:28:39.299Z,1571772519.299 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,192839.00,A,3648.15856,N,12147.29201,W,0.739,335.34,221019,,,A*7D 2019-10-22T19:28:39.301Z,1571772519.301 [NAL9602](INFO): GPS fix at 20191022T192839: (36.802643, -121.788200) 2019-10-22T19:28:39.373Z,1571772519.373 [Default:CheckIn:Read_GPS] Stopped 2019-10-22T19:28:39.373Z,1571772519.373 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-10-22T19:28:44.566Z,1571772524.566 [DataOverHttps](INFO): Sending 64 bytes from file Logs/20191022T191615/Courier0006.lzma 2019-10-22T19:28:46.576Z,1571772526.576 [DataOverHttps](INFO): Moved sent file to Logs/20191022T191615/Courier0006.lzma.bak 2019-10-22T19:28:46.576Z,1571772526.576 [DataOverHttps](INFO): SBD MOMSN=11946272 2019-10-22T19:29:11.758Z,1571772551.758 [DataOverHttps](INFO): Sending 196 bytes from file Logs/20191022T191615/Express0007.lzma 2019-10-22T19:29:13.764Z,1571772553.764 [DataOverHttps](INFO): Moved sent file to Logs/20191022T191615/Express0007.lzma.bak 2019-10-22T19:29:13.764Z,1571772553.764 [DataOverHttps](INFO): SBD MOMSN=11946275 2019-10-22T19:29:21.066Z,1571772561.066 [Default:CheckIn:Read_Iridium] Stopped 2019-10-22T19:29:21.067Z,1571772561.067 [Default:CheckIn:C.Wait] Running Loop=1 2019-10-22T19:29:21.067Z,1571772561.067 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-10-22T19:32:31.304Z,1571772751.304 [NAL9602](INFO): SBD MO Status=2, MOMSN=9744, MT Status=2, MTMSN=0 2019-10-22T19:32:31.304Z,1571772751.304 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-10-22T19:33:04.848Z,1571772784.848 [RDI_Pathfinder](ERROR): Failed to parse: :RA, 0.00, 0.00, 0.00, 0.00, 0.00 2019-10-22T19:33:27.442Z,1571772807.442 [NAL9602](INFO): SBD MO Status=2, MOMSN=9744, MT Status=2, MTMSN=0 2019-10-22T19:33:27.442Z,1571772807.442 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-10-22T19:33:41.582Z,1571772821.582 [NAL9602](INFO): SBD MO Status=2, MOMSN=9744, MT Status=2, MTMSN=0 2019-10-22T19:33:41.582Z,1571772821.582 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-10-22T19:33:41.985Z,1571772821.985 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-10-22T19:34:12.692Z,1571772852.692 [NAL9602](INFO): Not Powering down - fast GPS 2019-10-22T19:34:21.614Z,1571772861.614 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-10-22T19:34:21.614Z,1571772861.614 [Default:CheckIn:C.Wait] Stopped 2019-10-22T19:34:21.614Z,1571772861.614 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-10-22T19:34:21.615Z,1571772861.615 [Default:CheckIn:D] Running Loop=1 2019-10-22T19:34:22.035Z,1571772862.035 [Default:CheckIn:D] Stopped 2019-10-22T19:34:22.035Z,1571772862.035 [Default:CheckIn:E] Running Loop=1 2019-10-22T19:34:22.411Z,1571772862.411 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 18.100535 min 2019-10-22T19:34:22.411Z,1571772862.411 [Default:CheckIn:E] Stopped 2019-10-22T19:34:22.411Z,1571772862.411 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-10-22T19:34:22.411Z,1571772862.411 [Default:CheckIn] Stopped 2019-10-22T19:34:22.411Z,1571772862.411 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-10-22T19:34:22.411Z,1571772862.411 [Default:CheckIn](INFO): Running loop #4 2019-10-22T19:34:22.411Z,1571772862.411 [Default:CheckIn] Running Loop=4 2019-10-22T19:34:22.411Z,1571772862.411 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-10-22T19:34:22.412Z,1571772862.412 [Default:CheckIn:Read_GPS] Running Loop=1 2019-10-22T19:34:24.010Z,1571772864.010 [NAL9602](DEBUG): Fix Requested 2019-10-22T19:34:24.402Z,1571772864.402 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,193424.00,A,3648.16678,N,12147.27831,W,0.175,335.34,221019,,,A*74 2019-10-22T19:34:24.404Z,1571772864.404 [NAL9602](INFO): GPS fix at 20191022T193424: (36.802780, -121.787972) 2019-10-22T19:34:24.493Z,1571772864.493 [Default:CheckIn:Read_GPS] Stopped 2019-10-22T19:34:24.493Z,1571772864.493 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-10-22T19:34:30.682Z,1571772870.682 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20191022T191615/Courier0009.lzma 2019-10-22T19:34:32.692Z,1571772872.692 [DataOverHttps](INFO): Moved sent file to Logs/20191022T191615/Courier0009.lzma.bak 2019-10-22T19:34:32.692Z,1571772872.692 [DataOverHttps](INFO): SBD MOMSN=11946280 2019-10-22T19:34:56.338Z,1571772896.338 [DataOverHttps](INFO): Sending 196 bytes from file Logs/20191022T191615/Express0010.lzma 2019-10-22T19:34:58.344Z,1571772898.344 [DataOverHttps](INFO): Moved sent file to Logs/20191022T191615/Express0010.lzma.bak 2019-10-22T19:34:58.344Z,1571772898.344 [DataOverHttps](INFO): SBD MOMSN=11946283 2019-10-22T19:35:05.346Z,1571772905.346 [Default:CheckIn:Read_Iridium] Stopped 2019-10-22T19:35:05.350Z,1571772905.350 [Default:CheckIn:C.Wait] Running Loop=1 2019-10-22T19:35:05.351Z,1571772905.351 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-10-22T19:35:05.707Z,1571772905.707 [NAL9602](INFO): SBD MO Status=2, MOMSN=9744, MT Status=2, MTMSN=0 2019-10-22T19:35:05.707Z,1571772905.707 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-10-22T19:35:12.225Z,1571772912.225 [RDI_Pathfinder](ERROR): Failed to parse: :RA, 0.00, 0.00, 0.00, 0.00, 0.00 2019-10-22T19:35:52.170Z,1571772952.170 [NAL9602](INFO): SBD MO Status=2, MOMSN=9744, MT Status=2, MTMSN=0 2019-10-22T19:35:52.170Z,1571772952.170 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-10-22T19:39:25.902Z,1571773165.902 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-10-22T19:39:56.600Z,1571773196.600 [NAL9602](INFO): Not Powering down - fast GPS 2019-10-22T19:40:05.937Z,1571773205.937 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-10-22T19:40:05.937Z,1571773205.937 [Default:CheckIn:C.Wait] Stopped 2019-10-22T19:40:05.937Z,1571773205.937 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-10-22T19:40:05.937Z,1571773205.937 [Default:CheckIn:D] Running Loop=1 2019-10-22T19:40:06.340Z,1571773206.340 [Default:CheckIn:D] Stopped 2019-10-22T19:40:06.340Z,1571773206.340 [Default:CheckIn:E] Running Loop=1 2019-10-22T19:40:06.732Z,1571773206.732 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 23.838953 min 2019-10-22T19:40:06.732Z,1571773206.732 [Default:CheckIn:E] Stopped 2019-10-22T19:40:06.732Z,1571773206.732 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-10-22T19:40:06.732Z,1571773206.732 [Default:CheckIn] Stopped 2019-10-22T19:40:06.732Z,1571773206.732 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-10-22T19:40:06.732Z,1571773206.732 [Default:CheckIn](INFO): Running loop #5 2019-10-22T19:40:06.733Z,1571773206.733 [Default:CheckIn] Running Loop=5 2019-10-22T19:40:06.733Z,1571773206.733 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-10-22T19:40:06.733Z,1571773206.733 [Default:CheckIn:Read_GPS] Running Loop=1 2019-10-22T19:40:08.342Z,1571773208.342 [NAL9602](DEBUG): Fix Requested 2019-10-22T19:40:08.738Z,1571773208.738 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194009.00,A,3648.16172,N,12147.28766,W,0.058,0.00,221019,,,A*7B 2019-10-22T19:40:08.741Z,1571773208.741 [NAL9602](INFO): GPS fix at 20191022T194009: (36.802695, -121.788128) 2019-10-22T19:40:08.811Z,1571773208.811 [Default:CheckIn:Read_GPS] Stopped 2019-10-22T19:40:08.811Z,1571773208.811 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-10-22T19:40:15.637Z,1571773215.637 [DataOverHttps](INFO): Sending 64 bytes from file Logs/20191022T191615/Courier0012.lzma 2019-10-22T19:40:17.648Z,1571773217.648 [DataOverHttps](INFO): Moved sent file to Logs/20191022T191615/Courier0012.lzma.bak 2019-10-22T19:40:17.648Z,1571773217.648 [DataOverHttps](INFO): SBD MOMSN=11946295 2019-10-22T19:40:44.074Z,1571773244.074 [DataOverHttps](INFO): Sending 196 bytes from file Logs/20191022T191615/Express0013.lzma 2019-10-22T19:40:46.080Z,1571773246.080 [DataOverHttps](INFO): Moved sent file to Logs/20191022T191615/Express0013.lzma.bak 2019-10-22T19:40:46.080Z,1571773246.080 [DataOverHttps](INFO): SBD MOMSN=11946298 2019-10-22T19:40:53.246Z,1571773253.246 [Default:CheckIn:Read_Iridium] Stopped 2019-10-22T19:40:53.246Z,1571773253.246 [Default:CheckIn:C.Wait] Running Loop=1 2019-10-22T19:40:53.246Z,1571773253.246 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-10-22T19:41:34.022Z,1571773294.022 [NAL9602](INFO): SBD MO Status=2, MOMSN=9744, MT Status=2, MTMSN=0 2019-10-22T19:41:34.022Z,1571773294.022 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-10-22T19:41:46.938Z,1571773306.938 [NAL9602](INFO): SBD MO Status=2, MOMSN=9744, MT Status=2, MTMSN=0 2019-10-22T19:41:46.939Z,1571773306.939 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-10-22T19:43:21.074Z,1571773401.074 [NAL9602](INFO): SBD MO Status=0, MOMSN=9744, MT Status=0, MTMSN=0 2019-10-22T19:43:21.074Z,1571773401.074 [NAL9602](INFO): No messages in MT queue 2019-10-22T19:43:51.770Z,1571773431.770 [NAL9602](INFO): Not Powering down - fast GPS 2019-10-22T19:45:53.826Z,1571773553.826 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-10-22T19:45:53.827Z,1571773553.827 [Default:CheckIn:C.Wait] Stopped 2019-10-22T19:45:53.827Z,1571773553.827 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-10-22T19:45:53.827Z,1571773553.827 [Default:CheckIn:D] Running Loop=1 2019-10-22T19:45:54.223Z,1571773554.223 [Default:CheckIn:D] Stopped 2019-10-22T19:45:54.223Z,1571773554.223 [Default:CheckIn:E] Running Loop=1 2019-10-22T19:45:54.639Z,1571773554.639 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 29.637000 min 2019-10-22T19:45:54.639Z,1571773554.639 [Default:CheckIn:E] Stopped 2019-10-22T19:45:54.639Z,1571773554.639 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-10-22T19:45:54.639Z,1571773554.639 [Default:CheckIn] Stopped 2019-10-22T19:45:54.639Z,1571773554.639 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-10-22T19:45:54.640Z,1571773554.640 [Default:CheckIn](INFO): Running loop #6 2019-10-22T19:45:54.640Z,1571773554.640 [Default:CheckIn] Running Loop=6 2019-10-22T19:45:54.640Z,1571773554.640 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-10-22T19:45:54.640Z,1571773554.640 [Default:CheckIn:Read_GPS] Running Loop=1 2019-10-22T19:45:56.222Z,1571773556.222 [NAL9602](DEBUG): Fix Requested 2019-10-22T19:45:56.614Z,1571773556.614 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194557.00,A,3648.16725,N,12147.28455,W,0.078,319.64,221019,,,A*79 2019-10-22T19:45:56.616Z,1571773556.616 [NAL9602](INFO): GPS fix at 20191022T194557: (36.802788, -121.788076) 2019-10-22T19:45:56.674Z,1571773556.674 [Default:CheckIn:Read_GPS] Stopped 2019-10-22T19:45:56.675Z,1571773556.675 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-10-22T19:46:06.754Z,1571773566.754 [DataOverHttps](INFO): Sending 64 bytes from file Logs/20191022T191615/Courier0015.lzma 2019-10-22T19:46:08.760Z,1571773568.760 [DataOverHttps](INFO): Moved sent file to Logs/20191022T191615/Courier0015.lzma.bak 2019-10-22T19:46:08.760Z,1571773568.760 [DataOverHttps](INFO): SBD MOMSN=11946309 2019-10-22T19:46:32.534Z,1571773592.534 [DataOverHttps](INFO): Sending 118 bytes from file Logs/20191022T191615/Express0016.lzma 2019-10-22T19:46:36.793Z,1571773596.793 [DataOverHttps](INFO): Moved sent file to Logs/20191022T191615/Express0016.lzma.bak 2019-10-22T19:46:36.793Z,1571773596.793 [DataOverHttps](INFO): SBD MOMSN=11946317 2019-10-22T19:46:42.753Z,1571773602.753 [Default:CheckIn:Read_Iridium] Stopped 2019-10-22T19:46:42.753Z,1571773602.753 [Default:CheckIn:C.Wait] Running Loop=1 2019-10-22T19:46:42.753Z,1571773602.753 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-10-22T19:47:17.856Z,1571773637.856 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2019-10-22T19:47:17.856Z,1571773637.856 [RDI_Pathfinder](ERROR): Failed to parse: :TS2585427,35.0, -0.1, 0.0,1448.9, 0 2019-10-22T19:50:32.146Z,1571773832.146 [NAL9602](INFO): SBD MO Status=2, MOMSN=9745, MT Status=2, MTMSN=0 2019-10-22T19:50:32.146Z,1571773832.146 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-10-22T19:50:59.213Z,1571773859.213 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-10-22T19:51:29.912Z,1571773889.912 [NAL9602](INFO): Not Powering down - fast GPS 2019-10-22T19:51:43.274Z,1571773903.274 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-10-22T19:51:43.274Z,1571773903.274 [Default:CheckIn:C.Wait] Stopped 2019-10-22T19:51:43.274Z,1571773903.274 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-10-22T19:51:43.275Z,1571773903.275 [Default:CheckIn:D] Running Loop=1 2019-10-22T19:51:43.691Z,1571773903.691 [Default:CheckIn:D] Stopped 2019-10-22T19:51:43.691Z,1571773903.691 [Default:CheckIn:E] Running Loop=1 2019-10-22T19:51:44.076Z,1571773904.076 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 35.461471 min 2019-10-22T19:51:44.076Z,1571773904.076 [Default:CheckIn:E] Stopped 2019-10-22T19:51:44.076Z,1571773904.076 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-10-22T19:51:44.077Z,1571773904.077 [Default:CheckIn] Stopped 2019-10-22T19:51:44.077Z,1571773904.077 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-10-22T19:51:44.077Z,1571773904.077 [Default:CheckIn](INFO): Running loop #7 2019-10-22T19:51:44.077Z,1571773904.077 [Default:CheckIn] Running Loop=7 2019-10-22T19:51:44.077Z,1571773904.077 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-10-22T19:51:44.077Z,1571773904.077 [Default:CheckIn:Read_GPS] Running Loop=1 2019-10-22T19:51:45.687Z,1571773905.687 [NAL9602](DEBUG): Fix Requested 2019-10-22T19:51:46.079Z,1571773906.079 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,195146.00,A,3648.16624,N,12147.28681,W,0.292,60.01,221019,,,A*4F 2019-10-22T19:51:46.081Z,1571773906.081 [NAL9602](INFO): GPS fix at 20191022T195146: (36.802771, -121.788113) 2019-10-22T19:51:46.191Z,1571773906.191 [Default:CheckIn:Read_GPS] Stopped 2019-10-22T19:51:46.191Z,1571773906.191 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-10-22T19:51:53.276Z,1571773913.276 [DataOverHttps](INFO): Sending 64 bytes from file Logs/20191022T191615/Courier0018.lzma 2019-10-22T19:51:55.284Z,1571773915.284 [DataOverHttps](INFO): Moved sent file to Logs/20191022T191615/Courier0018.lzma.bak 2019-10-22T19:51:55.284Z,1571773915.284 [DataOverHttps](INFO): SBD MOMSN=11946320 2019-10-22T19:52:06.476Z,1571773926.476 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2019-10-22T19:52:06.476Z,1571773926.476 [RDI_Pathfinder](ERROR): Failed to parse: :TS,19102213034327,35.0, -0.11448.9, 0 2019-10-22T19:52:16.925Z,1571773936.925 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2019-10-22T19:52:17.002Z,1571773937.002 [NAL9602](FAULT): received: +CSQ:1 OK45, 2, 0, 0, 0 OK 2019-10-22T19:52:17.002Z,1571773937.002 [NAL9602] Data Fault, FailCount= 1 2019-10-22T19:52:17.003Z,1571773937.003 [NAL9602](ERROR): Data Fault 2019-10-22T19:52:17.094Z,1571773937.094 [CBIT](ERROR): Data Fault in component: NAL9602 2019-10-22T19:52:17.337Z,1571773937.337 [NAL9602](INFO): Powering down 2019-10-22T19:52:18.183Z,1571773938.183 [CBIT](INFO): Clearing failed state for component NAL9602 2019-10-22T19:52:18.183Z,1571773938.183 [NAL9602] No Fault, FailCount= 1 2019-10-22T19:52:18.698Z,1571773938.698 [DataOverHttps](INFO): Sending 195 bytes from file Logs/20191022T191615/Express0019.lzma 2019-10-22T19:52:21.673Z,1571773941.673 [DataOverHttps](INFO): Moved sent file to Logs/20191022T191615/Express0019.lzma.bak 2019-10-22T19:52:21.673Z,1571773941.673 [DataOverHttps](INFO): SBD MOMSN=11946323 2019-10-22T19:52:27.894Z,1571773947.894 [Default:CheckIn:Read_Iridium] Stopped 2019-10-22T19:52:27.895Z,1571773947.895 [Default:CheckIn:C.Wait] Running Loop=1 2019-10-22T19:52:27.895Z,1571773947.895 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-10-22T19:52:47.633Z,1571773967.633 [NAL9602](INFO): Powering up NAL9602 2019-10-22T19:52:58.550Z,1571773978.550 [NAL9602](INFO): NAL9602 initialized 2019-10-22T19:53:29.676Z,1571774009.676 [NAL9602](INFO): Not Powering down - fast GPS 2019-10-22T19:57:28.437Z,1571774248.437 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-10-22T19:57:28.437Z,1571774248.437 [Default:CheckIn:C.Wait] Stopped 2019-10-22T19:57:28.437Z,1571774248.437 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-10-22T19:57:28.437Z,1571774248.437 [Default:CheckIn:D] Running Loop=1 2019-10-22T19:57:28.857Z,1571774248.857 [Default:CheckIn:D] Stopped 2019-10-22T19:57:28.857Z,1571774248.857 [Default:CheckIn:E] Running Loop=1 2019-10-22T19:57:29.279Z,1571774249.279 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 41.214233 min 2019-10-22T19:57:29.279Z,1571774249.279 [Default:CheckIn:E] Stopped 2019-10-22T19:57:29.279Z,1571774249.279 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-10-22T19:57:29.279Z,1571774249.279 [Default:CheckIn] Stopped 2019-10-22T19:57:29.279Z,1571774249.279 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-10-22T19:57:29.279Z,1571774249.279 [Default:CheckIn](INFO): Running loop #8 2019-10-22T19:57:29.280Z,1571774249.280 [Default:CheckIn] Running Loop=8 2019-10-22T19:57:29.280Z,1571774249.280 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-10-22T19:57:29.280Z,1571774249.280 [Default:CheckIn:Read_GPS] Running Loop=1 2019-10-22T19:57:30.857Z,1571774250.857 [NAL9602](DEBUG): Fix Requested 2019-10-22T19:57:31.252Z,1571774251.252 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,195730.00,A,3648.16859,N,12147.29159,W,0.078,0.00,221019,,,A*7E 2019-10-22T19:57:31.263Z,1571774251.263 [NAL9602](INFO): GPS fix at 20191022T195730: (36.802810, -121.788193) 2019-10-22T19:57:31.371Z,1571774251.371 [Default:CheckIn:Read_GPS] Stopped 2019-10-22T19:57:31.371Z,1571774251.371 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-10-22T19:57:32.989Z,1571774252.989 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-10-22T19:57:36.908Z,1571774256.908 [DataOverHttps](INFO): Sending 64 bytes from file Logs/20191022T191615/Courier0021.lzma 2019-10-22T19:57:38.916Z,1571774258.916 [DataOverHttps](INFO): Moved sent file to Logs/20191022T191615/Courier0021.lzma.bak 2019-10-22T19:57:38.916Z,1571774258.916 [DataOverHttps](INFO): SBD MOMSN=11946333 2019-10-22T19:58:03.390Z,1571774283.390 [DataOverHttps](INFO): Sending 161 bytes from file Logs/20191022T191615/Express0022.lzma 2019-10-22T19:58:03.713Z,1571774283.713 [NAL9602](INFO): Not Powering down - fast GPS 2019-10-22T19:58:05.396Z,1571774285.396 [DataOverHttps](INFO): Moved sent file to Logs/20191022T191615/Express0022.lzma.bak 2019-10-22T19:58:05.396Z,1571774285.396 [DataOverHttps](INFO): SBD MOMSN=11946336 2019-10-22T19:58:12.651Z,1571774292.651 [Default:CheckIn:Read_Iridium] Stopped 2019-10-22T19:58:12.651Z,1571774292.651 [Default:CheckIn:C.Wait] Running Loop=1 2019-10-22T19:58:12.651Z,1571774292.651 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-10-22T20:02:54.195Z,1571774574.195 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2019-10-22T20:02:54.197Z,1571774574.197 [BPC1](INFO): Received data from all battery sticks. 2019-10-22T20:03:13.198Z,1571774593.198 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-10-22T20:03:13.198Z,1571774593.198 [Default:CheckIn:C.Wait] Stopped 2019-10-22T20:03:13.199Z,1571774593.199 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-10-22T20:03:13.199Z,1571774593.199 [Default:CheckIn:D] Running Loop=1 2019-10-22T20:03:13.627Z,1571774593.627 [Default:CheckIn:D] Stopped 2019-10-22T20:03:13.627Z,1571774593.627 [Default:CheckIn:E] Running Loop=1 2019-10-22T20:03:13.988Z,1571774593.988 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 46.960396 min 2019-10-22T20:03:13.988Z,1571774593.988 [Default:CheckIn:E] Stopped 2019-10-22T20:03:13.989Z,1571774593.989 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-10-22T20:03:13.989Z,1571774593.989 [Default:CheckIn] Stopped 2019-10-22T20:03:13.989Z,1571774593.989 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-10-22T20:03:13.989Z,1571774593.989 [Default:CheckIn](INFO): Running loop #9 2019-10-22T20:03:13.989Z,1571774593.989 [Default:CheckIn] Running Loop=9 2019-10-22T20:03:13.989Z,1571774593.989 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-10-22T20:03:13.989Z,1571774593.989 [Default:CheckIn:Read_GPS] Running Loop=1 2019-10-22T20:03:15.594Z,1571774595.594 [NAL9602](DEBUG): Fix Requested 2019-10-22T20:03:15.995Z,1571774595.995 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,200315.00,A,3648.16525,N,12147.28370,W,0.175,138.56,221019,,,A*79 2019-10-22T20:03:15.997Z,1571774595.997 [NAL9602](INFO): GPS fix at 20191022T200315: (36.802754, -121.788062) 2019-10-22T20:03:16.046Z,1571774596.046 [Default:CheckIn:Read_GPS] Stopped 2019-10-22T20:03:16.047Z,1571774596.047 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-10-22T20:03:22.501Z,1571774602.501 [DataOverHttps](INFO): Sending 222 bytes from file Logs/20191022T191615/Courier0024.lzma 2019-10-22T20:03:24.512Z,1571774604.512 [DataOverHttps](INFO): Moved sent file to Logs/20191022T191615/Courier0024.lzma.bak 2019-10-22T20:03:24.512Z,1571774604.512 [DataOverHttps](INFO): SBD MOMSN=11946340 2019-10-22T20:03:30.222Z,1571774610.222 [NAL9602](INFO): SBD MO Status=0, MOMSN=9745, MT Status=0, MTMSN=0 2019-10-22T20:03:30.222Z,1571774610.222 [NAL9602](INFO): No messages in MT queue 2019-10-22T20:03:51.866Z,1571774631.866 [DataOverHttps](INFO): Sending 194 bytes from file Logs/20191022T191615/Express0025.lzma 2019-10-22T20:03:53.876Z,1571774633.876 [DataOverHttps](INFO): Moved sent file to Logs/20191022T191615/Express0025.lzma.bak 2019-10-22T20:03:53.876Z,1571774633.876 [DataOverHttps](INFO): SBD MOMSN=11946343 2019-10-22T20:04:00.932Z,1571774640.932 [NAL9602](INFO): Not Powering down - fast GPS 2019-10-22T20:04:00.988Z,1571774640.988 [Default:CheckIn:Read_Iridium] Stopped 2019-10-22T20:04:00.988Z,1571774640.988 [Default:CheckIn:C.Wait] Running Loop=1 2019-10-22T20:04:00.988Z,1571774640.988 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-10-22T20:09:01.557Z,1571774941.557 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-10-22T20:09:01.557Z,1571774941.557 [Default:CheckIn:C.Wait] Stopped 2019-10-22T20:09:01.557Z,1571774941.557 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-10-22T20:09:01.558Z,1571774941.558 [Default:CheckIn:D] Running Loop=1 2019-10-22T20:09:01.983Z,1571774941.983 [Default:CheckIn:D] Stopped 2019-10-22T20:09:01.983Z,1571774941.983 [Default:CheckIn:E] Running Loop=1 2019-10-22T20:09:02.367Z,1571774942.367 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 52.766333 min 2019-10-22T20:09:02.367Z,1571774942.367 [Default:CheckIn:E] Stopped 2019-10-22T20:09:02.367Z,1571774942.367 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-10-22T20:09:02.368Z,1571774942.368 [Default:CheckIn] Stopped 2019-10-22T20:09:02.368Z,1571774942.368 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-10-22T20:09:02.368Z,1571774942.368 [Default:CheckIn](INFO): Running loop #10 2019-10-22T20:09:02.368Z,1571774942.368 [Default:CheckIn] Running Loop=10 2019-10-22T20:09:02.368Z,1571774942.368 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-10-22T20:09:02.368Z,1571774942.368 [Default:CheckIn:Read_GPS] Running Loop=1 2019-10-22T20:09:03.946Z,1571774943.946 [NAL9602](DEBUG): Fix Requested 2019-10-22T20:09:04.334Z,1571774944.334 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,200904.00,A,3648.16991,N,12147.28589,W,0.136,248.67,221019,,,A*71 2019-10-22T20:09:04.336Z,1571774944.336 [NAL9602](INFO): GPS fix at 20191022T200904: (36.802832, -121.788098) 2019-10-22T20:09:04.382Z,1571774944.382 [Default:CheckIn:Read_GPS] Stopped 2019-10-22T20:09:04.383Z,1571774944.383 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-10-22T20:09:08.473Z,1571774948.473 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20191022T191615/Courier0027.lzma 2019-10-22T20:09:10.484Z,1571774950.484 [DataOverHttps](INFO): Moved sent file to Logs/20191022T191615/Courier0027.lzma.bak 2019-10-22T20:09:10.484Z,1571774950.484 [DataOverHttps](INFO): SBD MOMSN=11946359 2019-10-22T20:09:33.906Z,1571774973.906 [DataOverHttps](INFO): Sending 119 bytes from file Logs/20191022T191615/Express0028.lzma 2019-10-22T20:09:35.912Z,1571774975.912 [DataOverHttps](INFO): Moved sent file to Logs/20191022T191615/Express0028.lzma.bak 2019-10-22T20:09:35.912Z,1571774975.912 [DataOverHttps](INFO): SBD MOMSN=11946362 2019-10-22T20:09:44.377Z,1571774984.377 [Default:CheckIn:Read_Iridium] Stopped 2019-10-22T20:09:44.378Z,1571774984.378 [Default:CheckIn:C.Wait] Running Loop=1 2019-10-22T20:09:44.378Z,1571774984.378 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-10-22T20:10:19.898Z,1571775019.898 [NAL9602](INFO): SBD MO Status=2, MOMSN=9746, MT Status=2, MTMSN=0 2019-10-22T20:10:19.898Z,1571775019.898 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-10-22T20:11:09.588Z,1571775069.588 [NAL9602](INFO): SBD MO Status=2, MOMSN=9746, MT Status=2, MTMSN=0 2019-10-22T20:11:09.588Z,1571775069.588 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-10-22T20:11:41.506Z,1571775101.506 [NAL9602](INFO): SBD MO Status=2, MOMSN=9746, MT Status=2, MTMSN=0 2019-10-22T20:11:41.506Z,1571775101.506 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-10-22T20:12:04.546Z,1571775124.546 [NAL9602](INFO): SBD MO Status=2, MOMSN=9746, MT Status=2, MTMSN=0 2019-10-22T20:12:04.546Z,1571775124.546 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-10-22T20:12:30.823Z,1571775150.823 [NAL9602](INFO): SBD MO Status=2, MOMSN=9746, MT Status=2, MTMSN=0 2019-10-22T20:12:30.823Z,1571775150.823 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-10-22T20:13:10.034Z,1571775190.034 [RDI_Pathfinder](ERROR): Failed to parse: :B,-32768,-32768,V 2019-10-22T20:13:33.472Z,1571775213.472 [RDI_Pathfinder](ERROR): only read 3 of 4 data items 2019-10-22T20:13:33.472Z,1571775213.472 [RDI_Pathfinder](ERROR): Failed to parse: :RA, 0.00, 0.00, 0.00, 0.00 2019-10-22T20:14:06.150Z,1571775246.150 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-10-22T20:14:36.846Z,1571775276.846 [NAL9602](INFO): Not Powering down - fast GPS 2019-10-22T20:14:44.972Z,1571775284.972 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-10-22T20:14:44.972Z,1571775284.972 [Default:CheckIn:C.Wait] Stopped 2019-10-22T20:14:44.972Z,1571775284.972 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-10-22T20:14:44.972Z,1571775284.972 [Default:CheckIn:D] Running Loop=1 2019-10-22T20:14:45.360Z,1571775285.360 [Default:CheckIn:D] Stopped 2019-10-22T20:14:45.360Z,1571775285.360 [Default:CheckIn:E] Running Loop=1 2019-10-22T20:14:45.779Z,1571775285.779 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 58.489290 min 2019-10-22T20:14:45.779Z,1571775285.779 [Default:CheckIn:E] Stopped 2019-10-22T20:14:45.779Z,1571775285.779 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-10-22T20:14:45.779Z,1571775285.779 [Default:CheckIn] Stopped 2019-10-22T20:14:45.780Z,1571775285.780 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-10-22T20:14:45.780Z,1571775285.780 [Default:CheckIn](INFO): Running loop #11 2019-10-22T20:14:45.780Z,1571775285.780 [Default:CheckIn] Running Loop=11 2019-10-22T20:14:45.780Z,1571775285.780 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-10-22T20:14:45.780Z,1571775285.780 [Default:CheckIn:Read_GPS] Running Loop=1 2019-10-22T20:14:47.370Z,1571775287.370 [NAL9602](DEBUG): Fix Requested 2019-10-22T20:14:47.762Z,1571775287.762 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,201448.00,A,3648.17174,N,12147.28371,W,0.097,248.67,221019,,,A*7C 2019-10-22T20:14:47.764Z,1571775287.764 [NAL9602](INFO): GPS fix at 20191022T201448: (36.802862, -121.788062) 2019-10-22T20:14:47.817Z,1571775287.817 [Default:CheckIn:Read_GPS] Stopped 2019-10-22T20:14:47.817Z,1571775287.817 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-10-22T20:14:56.678Z,1571775296.678 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20191022T191615/Courier0030.lzma 2019-10-22T20:14:58.684Z,1571775298.684 [DataOverHttps](INFO): Moved sent file to Logs/20191022T191615/Courier0030.lzma.bak 2019-10-22T20:14:58.684Z,1571775298.684 [DataOverHttps](INFO): SBD MOMSN=11946367 2019-10-22T20:15:18.465Z,1571775318.465 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2019-10-22T20:15:18.546Z,1571775318.546 [NAL9602](FAULT): received: +CSQ:0 OK46, 2, 0, 0, 0 OK 2019-10-22T20:15:18.546Z,1571775318.546 [NAL9602] Data Fault, FailCount= 1 2019-10-22T20:15:18.546Z,1571775318.546 [NAL9602](ERROR): Data Fault 2019-10-22T20:15:18.767Z,1571775318.767 [CBIT](ERROR): Data Fault in component: NAL9602 2019-10-22T20:15:18.877Z,1571775318.877 [NAL9602](INFO): Powering down 2019-10-22T20:15:19.851Z,1571775319.851 [CBIT](INFO): Clearing failed state for component NAL9602 2019-10-22T20:15:19.851Z,1571775319.851 [NAL9602] No Fault, FailCount= 1 2019-10-22T20:15:26.466Z,1571775326.466 [DataOverHttps](INFO): Sending 197 bytes from file Logs/20191022T191615/Express0031.lzma 2019-10-22T20:15:28.473Z,1571775328.473 [DataOverHttps](INFO): Moved sent file to Logs/20191022T191615/Express0031.lzma.bak 2019-10-22T20:15:28.473Z,1571775328.473 [DataOverHttps](INFO): SBD MOMSN=11946370 2019-10-22T20:15:35.510Z,1571775335.510 [Default:CheckIn:Read_Iridium] Stopped 2019-10-22T20:15:35.510Z,1571775335.510 [Default:CheckIn:C.Wait] Running Loop=1 2019-10-22T20:15:35.510Z,1571775335.510 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-10-22T20:15:49.209Z,1571775349.209 [NAL9602](INFO): Powering up NAL9602 2019-10-22T20:16:00.167Z,1571775360.167 [NAL9602](INFO): NAL9602 initialized 2019-10-22T20:16:31.220Z,1571775391.220 [NAL9602](INFO): Not Powering down - fast GPS 2019-10-22T20:20:36.082Z,1571775636.082 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-10-22T20:20:36.082Z,1571775636.082 [Default:CheckIn:C.Wait] Stopped 2019-10-22T20:20:36.083Z,1571775636.083 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-10-22T20:20:36.083Z,1571775636.083 [Default:CheckIn:D] Running Loop=1 2019-10-22T20:20:36.503Z,1571775636.503 [Default:CheckIn:D] Stopped 2019-10-22T20:20:36.503Z,1571775636.503 [Default:CheckIn:E] Running Loop=1 2019-10-22T20:20:36.884Z,1571775636.884 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 64.341667 min 2019-10-22T20:20:36.884Z,1571775636.884 [Default:CheckIn:E] Stopped 2019-10-22T20:20:36.884Z,1571775636.884 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-10-22T20:20:36.884Z,1571775636.884 [Default:CheckIn] Stopped 2019-10-22T20:20:36.884Z,1571775636.884 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-10-22T20:20:36.884Z,1571775636.884 [Default:CheckIn](INFO): Running loop #12 2019-10-22T20:20:36.884Z,1571775636.884 [Default:CheckIn] Running Loop=12 2019-10-22T20:20:36.884Z,1571775636.884 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-10-22T20:20:36.885Z,1571775636.885 [Default:CheckIn:Read_GPS] Running Loop=1 2019-10-22T20:20:38.491Z,1571775638.491 [NAL9602](DEBUG): Fix Requested 2019-10-22T20:20:38.531Z,1571775638.531 [RDI_Pathfinder](ERROR): only read 2 of 4 data items 2019-10-22T20:20:38.531Z,1571775638.531 [RDI_Pathfinder](ERROR): Failed to parse: :BS,-3768,-32768,V 2019-10-22T20:20:40.893Z,1571775640.893 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-10-22T20:20:41.718Z,1571775641.718 [NAL9602](DEBUG): Fix Requested 2019-10-22T20:20:44.546Z,1571775644.546 [NAL9602](DEBUG): Fix Requested 2019-10-22T20:20:47.370Z,1571775647.370 [NAL9602](DEBUG): Fix Requested 2019-10-22T20:20:50.202Z,1571775650.202 [NAL9602](DEBUG): Fix Requested 2019-10-22T20:20:53.435Z,1571775653.435 [NAL9602](DEBUG): Fix Requested 2019-10-22T20:20:56.266Z,1571775656.266 [NAL9602](DEBUG): Fix Requested 2019-10-22T20:20:59.502Z,1571775659.502 [NAL9602](DEBUG): Fix Requested 2019-10-22T20:21:02.318Z,1571775662.318 [NAL9602](DEBUG): Fix Requested 2019-10-22T20:21:02.711Z,1571775662.711 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,202102.00,A,3648.16304,N,12147.28347,W,0.058,198.39,221019,,,A*73 2019-10-22T20:21:02.717Z,1571775662.717 [NAL9602](INFO): GPS fix at 20191022T202102: (36.802717, -121.788058) 2019-10-22T20:21:02.769Z,1571775662.769 [Default:CheckIn:Read_GPS] Stopped 2019-10-22T20:21:02.769Z,1571775662.769 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-10-22T20:21:14.734Z,1571775674.734 [DataOverHttps](INFO): Sending 64 bytes from file Logs/20191022T191615/Courier0033.lzma 2019-10-22T20:21:16.740Z,1571775676.740 [DataOverHttps](INFO): Moved sent file to Logs/20191022T191615/Courier0033.lzma.bak 2019-10-22T20:21:16.740Z,1571775676.740 [DataOverHttps](INFO): SBD MOMSN=11946385 2019-10-22T20:21:33.833Z,1571775693.833 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2019-10-22T20:21:33.834Z,1571775693.834 [RDI_Pathfinder](ERROR): Failed to parse: :TS,19102213331027,35.0, -0.1, .9, 0 2019-10-22T20:21:35.508Z,1571775695.508 [NAL9602](INFO): Not Powering down - fast GPS 2019-10-22T20:21:42.342Z,1571775702.342 [DataOverHttps](INFO): Sending 237 bytes from file Logs/20191022T191615/Express0034.lzma 2019-10-22T20:21:44.348Z,1571775704.348 [DataOverHttps](INFO): Moved sent file to Logs/20191022T191615/Express0034.lzma.bak 2019-10-22T20:21:44.348Z,1571775704.348 [DataOverHttps](INFO): SBD MOMSN=11946388 2019-10-22T20:21:52.471Z,1571775712.471 [Default:CheckIn:Read_Iridium] Stopped 2019-10-22T20:21:52.471Z,1571775712.471 [Default:CheckIn:C.Wait] Running Loop=1 2019-10-22T20:21:52.471Z,1571775712.471 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-10-22T20:24:35.646Z,1571775875.646 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2019-10-22T20:24:35.646Z,1571775875.646 [RDI_Pathfinder](ERROR): Failed to parse: :TS,19102213361127,35.0, 0.51 2019-10-22T20:24:55.458Z,1571775895.458 [RDI_Pathfinder](ERROR): Failed to parse: 68,-32768,-32768,V 2019-10-22T20:24:58.668Z,1571775898.668 [RDI_Pathfinder](ERROR): only read 1 of 4 data items 2019-10-22T20:24:58.668Z,1571775898.668 [RDI_Pathfinder](ERROR): Failed to parse: :RA, 0.00, 0.0.50 2019-10-22T20:26:12.363Z,1571775972.363 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-10-22T20:26:15.383Z,1571775975.383 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.247456 2019-10-22T20:26:47.511Z,1571776007.511 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-10-22T20:26:53.014Z,1571776013.014 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-10-22T20:26:53.014Z,1571776013.014 [Default:CheckIn:C.Wait] Stopped 2019-10-22T20:26:53.014Z,1571776013.014 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-10-22T20:26:53.015Z,1571776013.015 [Default:CheckIn:D] Running Loop=1 2019-10-22T20:26:53.438Z,1571776013.438 [Default:CheckIn:D] Stopped 2019-10-22T20:26:53.438Z,1571776013.438 [Default:CheckIn:E] Running Loop=1 2019-10-22T20:26:53.832Z,1571776013.832 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 70.623910 min 2019-10-22T20:26:53.832Z,1571776013.832 [Default:CheckIn:E] Stopped 2019-10-22T20:26:53.833Z,1571776013.833 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-10-22T20:26:53.833Z,1571776013.833 [Default:CheckIn] Stopped 2019-10-22T20:26:53.833Z,1571776013.833 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-10-22T20:26:53.833Z,1571776013.833 [Default:CheckIn](INFO): Running loop #13 2019-10-22T20:26:53.833Z,1571776013.833 [Default:CheckIn] Running Loop=13 2019-10-22T20:26:53.833Z,1571776013.833 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-10-22T20:26:53.833Z,1571776013.833 [Default:CheckIn:Read_GPS] Running Loop=1 2019-10-22T20:26:55.426Z,1571776015.426 [NAL9602](DEBUG): Fix Requested 2019-10-22T20:26:55.822Z,1571776015.822 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,202655.00,A,3648.16689,N,12147.30147,W,0.408,198.39,221019,,,A*7C 2019-10-22T20:26:55.825Z,1571776015.825 [NAL9602](INFO): GPS fix at 20191022T202655: (36.802782, -121.788358) 2019-10-22T20:26:55.873Z,1571776015.873 [Default:CheckIn:Read_GPS] Stopped 2019-10-22T20:26:55.873Z,1571776015.873 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-10-22T20:27:22.659Z,1571776042.659 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-10-22T20:27:22.878Z,1571776042.878 [NAL9602](INFO): SBD MO Status=0, MOMSN=9746, MT Status=0, MTMSN=0 2019-10-22T20:27:22.878Z,1571776042.878 [NAL9602](INFO): No messages in MT queue 2019-10-22T20:27:53.588Z,1571776073.588 [NAL9602](INFO): Not Powering down - fast GPS 2019-10-22T20:27:57.799Z,1571776077.799 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-10-22T20:28:32.939Z,1571776112.939 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-10-22T20:29:08.087Z,1571776148.087 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-10-22T20:29:43.236Z,1571776183.236 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-10-22T20:30:18.383Z,1571776218.383 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-10-22T20:30:53.523Z,1571776253.523 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-10-22T20:31:28.663Z,1571776288.663 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-10-22T20:32:03.815Z,1571776323.815 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-10-22T20:32:38.959Z,1571776358.959 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-10-22T20:33:14.099Z,1571776394.099 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-10-22T20:33:49.247Z,1571776429.247 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-10-22T20:34:24.403Z,1571776464.403 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-10-22T20:34:59.543Z,1571776499.543 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-10-22T20:35:34.699Z,1571776534.699 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-10-22T20:36:09.839Z,1571776569.839 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-10-22T20:36:45.007Z,1571776605.007 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-10-22T20:37:20.147Z,1571776640.147 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-10-22T20:37:22.473Z,1571776642.473 [RDI_Pathfinder](ERROR): only read 2 of 4 data items 2019-10-22T20:37:22.473Z,1571776642.473 [RDI_Pathfinder](ERROR): Failed to parse: :BS,-32768,-3768,V 2019-10-22T20:37:55.315Z,1571776675.315 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-10-22T20:38:16.575Z,1571776696.575 [Micromodem](INFO): Nmea in: V,2.0.32731*14 2019-10-22T20:38:16.576Z,1571776696.576 [Micromodem](ERROR): Response from modem failed NMEA checksum: V,2.0.32731*14 expected 0 2019-10-22T20:38:30.455Z,1571776710.455 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-10-22T20:38:52.263Z,1571776732.263 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003300 2019-10-22T20:39:02.978Z,1571776742.978 [DataOverHttps](INFO): Sending 64 bytes from file Logs/20191022T191615/Courier0036.lzma 2019-10-22T20:39:04.984Z,1571776744.984 [DataOverHttps](INFO): Moved sent file to Logs/20191022T191615/Courier0036.lzma.bak 2019-10-22T20:39:04.984Z,1571776744.984 [DataOverHttps](INFO): SBD MOMSN=11946422 2019-10-22T20:39:30.206Z,1571776770.206 [DataOverHttps](INFO): Sending 118 bytes from file Logs/20191022T191615/Express0037.lzma 2019-10-22T20:39:32.212Z,1571776772.212 [DataOverHttps](INFO): Moved sent file to Logs/20191022T191615/Express0037.lzma.bak 2019-10-22T20:39:32.212Z,1571776772.212 [DataOverHttps](INFO): SBD MOMSN=11946425 2019-10-22T20:39:39.420Z,1571776779.420 [Default:CheckIn:Read_Iridium] Stopped 2019-10-22T20:39:39.421Z,1571776779.421 [Default:CheckIn:C.Wait] Running Loop=1 2019-10-22T20:39:39.421Z,1571776779.421 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-10-22T20:42:16.600Z,1571776936.600 [Micromodem](INFO): Nmea in: $C0.46*42 2019-10-22T20:42:16.600Z,1571776936.600 [Micromodem](ERROR): Response from modem failed NMEA checksum: $C0.46*42 expected 5F 2019-10-22T20:43:32.179Z,1571777012.179 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2019-10-22T20:43:32.179Z,1571777012.179 [RDI_Pathfinder](ERROR): Failed to parse: :TS,19102213550827,35.0, -0.1, 0.0,144 2019-10-22T20:44:40.104Z,1571777080.104 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-10-22T20:44:40.105Z,1571777080.105 [Default:CheckIn:C.Wait] Stopped 2019-10-22T20:44:40.105Z,1571777080.105 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-10-22T20:44:40.105Z,1571777080.105 [Default:CheckIn:D] Running Loop=1 2019-10-22T20:44:40.474Z,1571777080.474 [Default:CheckIn:D] Stopped 2019-10-22T20:44:40.506Z,1571777080.506 [Default:CheckIn:E] Running Loop=1 2019-10-22T20:44:40.919Z,1571777080.919 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 88.407845 min 2019-10-22T20:44:40.920Z,1571777080.920 [Default:CheckIn:E] Stopped 2019-10-22T20:44:40.920Z,1571777080.920 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-10-22T20:44:40.920Z,1571777080.920 [Default:CheckIn] Stopped 2019-10-22T20:44:40.920Z,1571777080.920 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-10-22T20:44:40.920Z,1571777080.920 [Default:CheckIn](INFO): Running loop #14 2019-10-22T20:44:40.920Z,1571777080.920 [Default:CheckIn] Running Loop=14 2019-10-22T20:44:40.920Z,1571777080.920 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-10-22T20:44:40.920Z,1571777080.920 [Default:CheckIn:Read_GPS] Running Loop=1 2019-10-22T20:44:42.494Z,1571777082.494 [NAL9602](DEBUG): Fix Requested 2019-10-22T20:44:42.846Z,1571777082.846 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,204443.00,A,3648.16041,N,12147.29593,W,1.400,20.23,221019,,,A*48 2019-10-22T20:44:42.848Z,1571777082.848 [NAL9602](INFO): GPS fix at 20191022T204443: (36.802673, -121.788265) 2019-10-22T20:44:42.925Z,1571777082.925 [Default:CheckIn:Read_GPS] Stopped 2019-10-22T20:44:42.925Z,1571777082.925 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-10-22T20:44:59.193Z,1571777099.193 [DataOverHttps](INFO): Sending 64 bytes from file Logs/20191022T191615/Courier0039.lzma 2019-10-22T20:45:01.208Z,1571777101.208 [DataOverHttps](INFO): Moved sent file to Logs/20191022T191615/Courier0039.lzma.bak 2019-10-22T20:45:01.208Z,1571777101.208 [DataOverHttps](INFO): SBD MOMSN=11946428 2019-10-22T20:45:45.526Z,1571777145.526 [DataOverHttps](INFO): Sending 120 bytes from file Logs/20191022T191615/Express0040.lzma 2019-10-22T20:45:47.532Z,1571777147.532 [DataOverHttps](INFO): Moved sent file to Logs/20191022T191615/Express0040.lzma.bak 2019-10-22T20:45:47.532Z,1571777147.532 [DataOverHttps](INFO): SBD MOMSN=11946432 2019-10-22T20:46:02.884Z,1571777162.884 [Default:CheckIn:Read_Iridium] Stopped 2019-10-22T20:46:02.885Z,1571777162.885 [Default:CheckIn:C.Wait] Running Loop=1 2019-10-22T20:46:02.885Z,1571777162.885 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-10-22T20:47:23.698Z,1571777243.698 [RDI_Pathfinder](ERROR): Failed to parse: :SA, +0.00, +0.00, 0.00 2019-10-22T20:49:45.020Z,1571777385.020 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-10-22T20:50:15.734Z,1571777415.734 [NAL9602](INFO): Not Powering down - fast GPS 2019-10-22T20:51:03.524Z,1571777463.524 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-10-22T20:51:03.524Z,1571777463.524 [Default:CheckIn:C.Wait] Stopped 2019-10-22T20:51:03.524Z,1571777463.524 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-10-22T20:51:03.524Z,1571777463.524 [Default:CheckIn:D] Running Loop=1 2019-10-22T20:51:03.839Z,1571777463.839 [Default:CheckIn:D] Stopped 2019-10-22T20:51:03.839Z,1571777463.839 [Default:CheckIn:E] Running Loop=1 2019-10-22T20:51:04.259Z,1571777464.259 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 94.797266 min 2019-10-22T20:51:04.259Z,1571777464.259 [Default:CheckIn:E] Stopped 2019-10-22T20:51:04.259Z,1571777464.259 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-10-22T20:51:04.259Z,1571777464.259 [Default:CheckIn] Stopped 2019-10-22T20:51:04.259Z,1571777464.259 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-10-22T20:51:04.259Z,1571777464.259 [Default:CheckIn](INFO): Running loop #15 2019-10-22T20:51:04.259Z,1571777464.259 [Default:CheckIn] Running Loop=15 2019-10-22T20:51:04.259Z,1571777464.259 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-10-22T20:51:04.260Z,1571777464.260 [Default:CheckIn:Read_GPS] Running Loop=1 2019-10-22T20:51:05.835Z,1571777465.835 [NAL9602](DEBUG): Fix Requested 2019-10-22T20:51:06.231Z,1571777466.231 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,205106.00,A,3648.16321,N,12147.30338,W,0.952,238.61,221019,,,A*71 2019-10-22T20:51:06.233Z,1571777466.233 [NAL9602](INFO): GPS fix at 20191022T205106: (36.802720, -121.788390) 2019-10-22T20:51:06.292Z,1571777466.292 [Default:CheckIn:Read_GPS] Stopped 2019-10-22T20:51:06.292Z,1571777466.292 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-10-22T20:51:23.820Z,1571777483.820 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2019-10-22T20:51:23.820Z,1571777483.820 [RDI_Pathfinder](ERROR): Failed to parse: :TS,19102214030027,35.0, -0.1, 48.9, 0 2019-10-22T20:51:25.130Z,1571777485.130 [DataOverHttps](INFO): Sending 64 bytes from file Logs/20191022T191615/Courier0042.lzma 2019-10-22T20:51:27.136Z,1571777487.136 [DataOverHttps](INFO): Moved sent file to Logs/20191022T191615/Courier0042.lzma.bak 2019-10-22T20:51:27.137Z,1571777487.137 [DataOverHttps](INFO): SBD MOMSN=11946443 2019-10-22T20:51:36.725Z,1571777496.725 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2019-10-22T20:51:36.798Z,1571777496.798 [NAL9602](FAULT): received: +CSQ:0 OK46, 0, 0, 0, 0 OK 2019-10-22T20:51:36.799Z,1571777496.799 [NAL9602] Data Fault, FailCount= 1 2019-10-22T20:51:36.799Z,1571777496.799 [NAL9602](ERROR): Data Fault 2019-10-22T20:51:36.931Z,1571777496.931 [CBIT](ERROR): Data Fault in component: NAL9602 2019-10-22T20:51:37.143Z,1571777497.143 [NAL9602](INFO): Powering down 2019-10-22T20:51:38.039Z,1571777498.039 [CBIT](INFO): Clearing failed state for component NAL9602 2019-10-22T20:51:38.039Z,1571777498.039 [NAL9602] No Fault, FailCount= 1 2019-10-22T20:52:07.471Z,1571777527.471 [NAL9602](INFO): Powering up NA