2019-04-11T18:57:32.680Z,1555009052.680 [CommandLine](IMPORTANT): got command restart logs 2019-04-11T18:57:36.579Z,1555009056.579 [RDI_Pathfinder](ERROR): only read 3 of 4 data items 2019-04-11T18:57:36.579Z,1555009056.579 [RDI_Pathfinder](ERROR): Failed to parse: :RA, 0.00, 0.00, 0.00, 0.00 2019-04-11T18:57:41.776Z,1555009061.776 [DataOverHttps](INFO): Sending 788 bytes from file Logs/20190411T165118/Express0056.lzma 2019-04-11T18:57:42.581Z,1555009062.581 [DataOverHttps](INFO): Moved sent file to Logs/20190411T165118/Express0056.lzma.bak 2019-04-11T18:57:42.581Z,1555009062.581 [DataOverHttps](INFO): SBD MOMSN=10555435 2019-04-11T18:57:43.027Z,1555009063.027 [NAL9602](INFO): SBD MO Status=2, MOMSN=3498, MT Status=2, MTMSN=0 2019-04-11T18:57:43.027Z,1555009063.027 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-04-11T18:57:51.109Z,1555009071.109 [NAL9602](INFO): SBD MO Status=0, MOMSN=3498, MT Status=0, MTMSN=0 2019-04-11T18:57:51.109Z,1555009071.109 [NAL9602](INFO): No messages in MT queue 2019-04-11T18:57:55.227Z,1555009075.227 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190411T165118/Courier0058.lzma 2019-04-11T18:57:56.033Z,1555009076.033 [DataOverHttps](INFO): Moved sent file to Logs/20190411T165118/Courier0058.lzma.bak 2019-04-11T18:57:56.033Z,1555009076.033 [DataOverHttps](INFO): SBD MOMSN=10555437 2019-04-11T18:58:08.671Z,1555009088.671 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190411T185732/Courier0000.lzma 2019-04-11T18:58:09.477Z,1555009089.477 [DataOverHttps](INFO): Moved sent file to Logs/20190411T185732/Courier0000.lzma.bak 2019-04-11T18:58:09.477Z,1555009089.477 [DataOverHttps](INFO): SBD MOMSN=10555440 2019-04-11T18:58:21.267Z,1555009101.267 [DataOverHttps](INFO): Sending 146 bytes from file Logs/20190411T165118/Express0059.lzma 2019-04-11T18:58:21.809Z,1555009101.809 [NAL9602](INFO): Not Powering down - fast GPS 2019-04-11T18:58:22.073Z,1555009102.073 [DataOverHttps](INFO): Moved sent file to Logs/20190411T165118/Express0059.lzma.bak 2019-04-11T18:58:22.073Z,1555009102.073 [DataOverHttps](INFO): SBD MOMSN=10555443 2019-04-11T18:58:33.711Z,1555009113.711 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190411T185732/Express0001.lzma 2019-04-11T18:58:34.517Z,1555009114.517 [DataOverHttps](INFO): Moved sent file to Logs/20190411T185732/Express0001.lzma.bak 2019-04-11T18:58:34.517Z,1555009114.517 [DataOverHttps](INFO): SBD MOMSN=10555445 2019-04-11T18:58:35.184Z,1555009115.184 [Default:CheckIn:Read_Iridium] Stopped 2019-04-11T18:58:35.185Z,1555009115.185 [Default:CheckIn:C.Wait] Running Loop=1 2019-04-11T18:58:35.185Z,1555009115.185 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-04-11T18:59:34.579Z,1555009174.579 [RDI_Pathfinder](ERROR): Failed to parse: :RA, 0.00, 0.00, 0.00, 0.00, 0.00 2019-04-11T19:00:17.391Z,1555009217.391 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2019-04-11T19:00:17.391Z,1555009217.391 [RDI_Pathfinder](ERROR): Failed to parse: :TS,19041112090123,35.0, -0.1, 0.0 2019-04-11T19:02:12.564Z,1555009332.564 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2019-04-11T19:02:12.564Z,1555009332.564 [RDI_Pathfinder](ERROR): Failed to parse: :TS,19041112105723,35.0, -0.1,448.9, 0 2019-04-11T19:02:52.938Z,1555009372.938 [RDI_Pathfinder](ERROR): only read 3 of 4 data items 2019-04-11T19:02:52.939Z,1555009372.939 [RDI_Pathfinder](ERROR): Failed to parse: :RA, 0.00, 0.00, 0.00, 0.00 2019-04-11T19:03:35.762Z,1555009415.762 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-04-11T19:03:35.762Z,1555009415.762 [Default:CheckIn:C.Wait] Stopped 2019-04-11T19:03:35.762Z,1555009415.762 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-04-11T19:03:35.763Z,1555009415.763 [Default:CheckIn:D] Running Loop=1 2019-04-11T19:03:36.200Z,1555009416.200 [Default:CheckIn:D] Stopped 2019-04-11T19:03:36.200Z,1555009416.200 [Default:CheckIn:E] Running Loop=1 2019-04-11T19:03:36.583Z,1555009416.583 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 14.155889 min 2019-04-11T19:03:36.583Z,1555009416.583 [Default:CheckIn:E] Stopped 2019-04-11T19:03:36.583Z,1555009416.583 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-04-11T19:03:36.583Z,1555009416.583 [Default:CheckIn] Stopped 2019-04-11T19:03:36.583Z,1555009416.583 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-04-11T19:03:36.583Z,1555009416.583 [Default:CheckIn](INFO): Running loop #3 2019-04-11T19:03:36.584Z,1555009416.584 [Default:CheckIn] Running Loop=3 2019-04-11T19:03:36.584Z,1555009416.584 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-04-11T19:03:36.584Z,1555009416.584 [Default:CheckIn:Read_GPS] Running Loop=1 2019-04-11T19:03:38.180Z,1555009418.180 [NAL9602](DEBUG): Fix Requested 2019-04-11T19:03:38.567Z,1555009418.567 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190337.00,A,3648.50715,N,12147.21408,W,9.816,57.52,110419,,,A*4D 2019-04-11T19:03:38.569Z,1555009418.569 [NAL9602](INFO): GPS fix at 20190411T190337: (36.808453, -121.786901) 2019-04-11T19:03:38.605Z,1555009418.605 [RDI_Pathfinder](ERROR): only read 3 of 4 data items 2019-04-11T19:03:38.605Z,1555009418.605 [RDI_Pathfinder](ERROR): Failed to parse: :RA, 0.00, 0.00, 0.00, 0.00 2019-04-11T19:03:38.622Z,1555009418.622 [Default:CheckIn:Read_GPS] Stopped 2019-04-11T19:03:38.622Z,1555009418.622 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-04-11T19:03:39.817Z,1555009419.817 [NAL9602](ERROR): parseGSV uart error: serial buffer full 2019-04-11T19:03:44.214Z,1555009424.214 [DataOverHttps](INFO): Sending 212 bytes from file Logs/20190411T185732/Courier0003.lzma 2019-04-11T19:03:45.001Z,1555009425.001 [DataOverHttps](INFO): Moved sent file to Logs/20190411T185732/Courier0003.lzma.bak 2019-04-11T19:03:45.001Z,1555009425.001 [DataOverHttps](INFO): SBD MOMSN=10555544 2019-04-11T19:03:57.536Z,1555009437.536 [DataOverHttps](INFO): Sending 912 bytes from file Logs/20190411T185732/Express0004.lzma 2019-04-11T19:03:58.341Z,1555009438.341 [DataOverHttps](INFO): Moved sent file to Logs/20190411T185732/Express0004.lzma.bak 2019-04-11T19:03:58.341Z,1555009438.341 [DataOverHttps](INFO): SBD MOMSN=10555547 2019-04-11T19:03:59.242Z,1555009439.242 [Default:CheckIn:Read_Iridium] Stopped 2019-04-11T19:03:59.242Z,1555009439.242 [Default:CheckIn:C.Wait] Running Loop=1 2019-04-11T19:03:59.243Z,1555009439.243 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-04-11T19:03:59.631Z,1555009439.631 [RDI_Pathfinder](ERROR): Failed to parse: :RA, 0.00, 0.00, 0.00, 0.00, 0.00 2019-04-11T19:04:02.880Z,1555009442.880 [NAL9602](INFO): SBD MO Status=0, MOMSN=3499, MT Status=0, MTMSN=0 2019-04-11T19:04:02.880Z,1555009442.880 [NAL9602](INFO): No messages in MT queue 2019-04-11T19:04:33.557Z,1555009473.557 [NAL9602](INFO): Not Powering down - fast GPS 2019-04-11T19:08:16.206Z,1555009696.206 [RDI_Pathfinder](ERROR): Failed to parse: :BE,-32768,-32768,-32768,V 2019-04-11T19:08:59.822Z,1555009739.822 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-04-11T19:08:59.822Z,1555009739.822 [Default:CheckIn:C.Wait] Stopped 2019-04-11T19:08:59.822Z,1555009739.822 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-04-11T19:08:59.823Z,1555009739.823 [Default:CheckIn:D] Running Loop=1 2019-04-11T19:09:00.224Z,1555009740.224 [Default:CheckIn:D] Stopped 2019-04-11T19:09:00.224Z,1555009740.224 [Default:CheckIn:E] Running Loop=1 2019-04-11T19:09:00.634Z,1555009740.634 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 19.556283 min 2019-04-11T19:09:00.634Z,1555009740.634 [Default:CheckIn:E] Stopped 2019-04-11T19:09:00.634Z,1555009740.634 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-04-11T19:09:00.635Z,1555009740.635 [Default:CheckIn] Stopped 2019-04-11T19:09:00.635Z,1555009740.635 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-04-11T19:09:00.635Z,1555009740.635 [Default:CheckIn](INFO): Running loop #4 2019-04-11T19:09:00.635Z,1555009740.635 [Default:CheckIn] Running Loop=4 2019-04-11T19:09:00.635Z,1555009740.635 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-04-11T19:09:00.635Z,1555009740.635 [Default:CheckIn:Read_GPS] Running Loop=1 2019-04-11T19:09:02.235Z,1555009742.235 [NAL9602](DEBUG): Fix Requested 2019-04-11T19:09:02.629Z,1555009742.629 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190901.00,A,3648.17210,N,12147.20505,W,2.099,217.62,110419,,,A*7D 2019-04-11T19:09:02.631Z,1555009742.631 [NAL9602](INFO): GPS fix at 20190411T190901: (36.802868, -121.786751) 2019-04-11T19:09:02.686Z,1555009742.686 [Default:CheckIn:Read_GPS] Stopped 2019-04-11T19:09:02.686Z,1555009742.686 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-04-11T19:09:03.845Z,1555009743.845 [NAL9602](ERROR): parseGSV uart error: serial buffer full 2019-04-11T19:09:08.367Z,1555009748.367 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20190411T185732/Courier0006.lzma 2019-04-11T19:09:09.173Z,1555009749.173 [DataOverHttps](INFO): Moved sent file to Logs/20190411T185732/Courier0006.lzma.bak 2019-04-11T19:09:09.173Z,1555009749.173 [DataOverHttps](INFO): SBD MOMSN=10555553 2019-04-11T19:09:15.565Z,1555009755.565 [NAL9602](INFO): SBD MO Status=0, MOMSN=3500, MT Status=0, MTMSN=0 2019-04-11T19:09:15.565Z,1555009755.565 [NAL9602](INFO): No messages in MT queue 2019-04-11T19:09:20.633Z,1555009760.633 [DataOverHttps](INFO): Sending 565 bytes from file Logs/20190411T185732/Express0007.lzma 2019-04-11T19:09:21.437Z,1555009761.437 [DataOverHttps](INFO): Moved sent file to Logs/20190411T185732/Express0007.lzma.bak 2019-04-11T19:09:21.437Z,1555009761.437 [DataOverHttps](INFO): SBD MOMSN=10555556 2019-04-11T19:09:22.046Z,1555009762.046 [Default:CheckIn:Read_Iridium] Stopped 2019-04-11T19:09:22.046Z,1555009762.046 [Default:CheckIn:C.Wait] Running Loop=1 2019-04-11T19:09:22.046Z,1555009762.046 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-04-11T19:09:46.263Z,1555009786.263 [NAL9602](INFO): Not Powering down - fast GPS 2019-04-11T19:11:11.938Z,1555009871.938 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2019-04-11T19:11:11.939Z,1555009871.939 [RDI_Pathfinder](ERROR): Failed to parse: :TS,19041112195623,35.0, 0.0,1448.9, 0 2019-04-11T19:12:12.942Z,1555009932.942 [RDI_Pathfinder](ERROR): only read 3 of 4 data items 2019-04-11T19:12:12.942Z,1555009932.942 [RDI_Pathfinder](ERROR): Failed to parse: :RA, 0.00, 0.00, 0.00, 0.00 2019-04-11T19:14:22.650Z,1555010062.650 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-04-11T19:14:22.650Z,1555010062.650 [Default:CheckIn:C.Wait] Stopped 2019-04-11T19:14:22.650Z,1555010062.650 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-04-11T19:14:22.650Z,1555010062.650 [Default:CheckIn:D] Running Loop=1 2019-04-11T19:14:23.026Z,1555010063.026 [Default:CheckIn:D] Stopped 2019-04-11T19:14:23.026Z,1555010063.026 [Default:CheckIn:E] Running Loop=1 2019-04-11T19:14:23.439Z,1555010063.439 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 24.936328 min 2019-04-11T19:14:23.439Z,1555010063.439 [Default:CheckIn:E] Stopped 2019-04-11T19:14:23.439Z,1555010063.439 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-04-11T19:14:23.439Z,1555010063.439 [Default:CheckIn] Stopped 2019-04-11T19:14:23.439Z,1555010063.439 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-04-11T19:14:23.439Z,1555010063.439 [Default:CheckIn](INFO): Running loop #5 2019-04-11T19:14:23.439Z,1555010063.439 [Default:CheckIn] Running Loop=5 2019-04-11T19:14:23.440Z,1555010063.440 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-04-11T19:14:23.440Z,1555010063.440 [Default:CheckIn:Read_GPS] Running Loop=1 2019-04-11T19:14:25.035Z,1555010065.035 [NAL9602](DEBUG): Fix Requested 2019-04-11T19:14:25.427Z,1555010065.427 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,191424.00,A,3648.14772,N,12147.22005,W,0.194,183.67,110419,,,A*76 2019-04-11T19:14:25.429Z,1555010065.429 [NAL9602](INFO): GPS fix at 20190411T191424: (36.802462, -121.787001) 2019-04-11T19:14:25.485Z,1555010065.485 [Default:CheckIn:Read_GPS] Stopped 2019-04-11T19:14:25.485Z,1555010065.485 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-04-11T19:14:27.057Z,1555010067.057 [NAL9602](ERROR): parseGSV uart error: serial buffer full 2019-04-11T19:14:36.331Z,1555010076.331 [NAL9602](INFO): SBD MO Status=0, MOMSN=3501, MT Status=0, MTMSN=0 2019-04-11T19:14:36.331Z,1555010076.331 [NAL9602](INFO): No messages in MT queue 2019-04-11T19:14:45.182Z,1555010085.182 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20190411T185732/Courier0009.lzma 2019-04-11T19:14:45.981Z,1555010085.981 [DataOverHttps](INFO): Moved sent file to Logs/20190411T185732/Courier0009.lzma.bak 2019-04-11T19:14:45.981Z,1555010085.981 [DataOverHttps](INFO): SBD MOMSN=10555716 2019-04-11T19:14:58.124Z,1555010098.124 [DataOverHttps](INFO): Sending 552 bytes from file Logs/20190411T185732/Express0010.lzma 2019-04-11T19:14:58.929Z,1555010098.929 [DataOverHttps](INFO): Moved sent file to Logs/20190411T185732/Express0010.lzma.bak 2019-04-11T19:14:58.929Z,1555010098.929 [DataOverHttps](INFO): SBD MOMSN=10555719 2019-04-11T19:14:59.786Z,1555010099.786 [Default:CheckIn:Read_Iridium] Stopped 2019-04-11T19:14:59.787Z,1555010099.787 [Default:CheckIn:C.Wait] Running Loop=1 2019-04-11T19:14:59.787Z,1555010099.787 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-04-11T19:15:07.033Z,1555010107.033 [NAL9602](INFO): Not Powering down - fast GPS 2019-04-11T19:20:00.406Z,1555010400.406 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-04-11T19:20:00.406Z,1555010400.406 [Default:CheckIn:C.Wait] Stopped 2019-04-11T19:20:00.407Z,1555010400.407 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-04-11T19:20:00.407Z,1555010400.407 [Default:CheckIn:D] Running Loop=1 2019-04-11T19:20:00.777Z,1555010400.777 [Default:CheckIn:D] Stopped 2019-04-11T19:20:00.777Z,1555010400.777 [Default:CheckIn:E] Running Loop=1 2019-04-11T19:20:01.186Z,1555010401.186 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 30.565505 min 2019-04-11T19:20:01.187Z,1555010401.187 [Default:CheckIn:E] Stopped 2019-04-11T19:20:01.187Z,1555010401.187 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-04-11T19:20:01.187Z,1555010401.187 [Default:CheckIn] Stopped 2019-04-11T19:20:01.187Z,1555010401.187 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-04-11T19:20:01.187Z,1555010401.187 [Default:CheckIn](INFO): Running loop #6 2019-04-11T19:20:01.187Z,1555010401.187 [Default:CheckIn] Running Loop=6 2019-04-11T19:20:01.188Z,1555010401.188 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-04-11T19:20:01.188Z,1555010401.188 [Default:CheckIn:Read_GPS] Running Loop=1 2019-04-11T19:20:02.787Z,1555010402.787 [NAL9602](DEBUG): Fix Requested 2019-04-11T19:20:03.197Z,1555010403.197 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,192002.00,A,3648.14228,N,12147.22799,W,0.078,193.97,110419,,,D*75 2019-04-11T19:20:03.204Z,1555010403.204 [NAL9602](INFO): GPS fix at 20190411T192002: (36.802371, -121.787133) 2019-04-11T19:20:03.322Z,1555010403.322 [Default:CheckIn:Read_GPS] Stopped 2019-04-11T19:20:03.322Z,1555010403.322 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-04-11T19:20:04.986Z,1555010404.986 [NAL9602](ERROR): parseGSV uart error: serial buffer full 2019-04-11T19:20:09.595Z,1555010409.595 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20190411T185732/Courier0012.lzma 2019-04-11T19:20:10.401Z,1555010410.401 [DataOverHttps](INFO): Moved sent file to Logs/20190411T185732/Courier0012.lzma.bak 2019-04-11T19:20:10.401Z,1555010410.401 [DataOverHttps](INFO): SBD MOMSN=10555724 2019-04-11T19:20:22.184Z,1555010422.184 [DataOverHttps](INFO): Sending 575 bytes from file Logs/20190411T185732/Express0013.lzma 2019-04-11T19:20:22.989Z,1555010422.989 [DataOverHttps](INFO): Moved sent file to Logs/20190411T185732/Express0013.lzma.bak 2019-04-11T19:20:22.989Z,1555010422.989 [DataOverHttps](INFO): SBD MOMSN=10555727 2019-04-11T19:20:23.596Z,1555010423.596 [Default:CheckIn:Read_Iridium] Stopped 2019-04-11T19:20:23.596Z,1555010423.596 [Default:CheckIn:C.Wait] Running Loop=1 2019-04-11T19:20:23.596Z,1555010423.596 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-04-11T19:20:33.656Z,1555010433.656 [NAL9602](INFO): SBD MO Status=2, MOMSN=3502, MT Status=2, MTMSN=0 2019-04-11T19:20:33.656Z,1555010433.656 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-04-11T19:21:03.961Z,1555010463.961 [NAL9602](INFO): SBD MO Status=0, MOMSN=3502, MT Status=0, MTMSN=0 2019-04-11T19:21:03.962Z,1555010463.962 [NAL9602](INFO): No messages in MT queue 2019-04-11T19:21:34.658Z,1555010494.658 [NAL9602](INFO): Not Powering down - fast GPS 2019-04-11T19:25:24.155Z,1555010724.155 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-04-11T19:25:24.155Z,1555010724.155 [Default:CheckIn:C.Wait] Stopped 2019-04-11T19:25:24.155Z,1555010724.155 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-04-11T19:25:24.180Z,1555010724.180 [Default:CheckIn:D] Running Loop=1 2019-04-11T19:25:24.586Z,1555010724.586 [Default:CheckIn:D] Stopped 2019-04-11T19:25:24.586Z,1555010724.586 [Default:CheckIn:E] Running Loop=1 2019-04-11T19:25:25.011Z,1555010725.011 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 35.962317 min 2019-04-11T19:25:25.015Z,1555010725.015 [Default:CheckIn:E] Stopped 2019-04-11T19:25:25.015Z,1555010725.015 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-04-11T19:25:25.016Z,1555010725.016 [Default:CheckIn] Stopped 2019-04-11T19:25:25.016Z,1555010725.016 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-04-11T19:25:25.016Z,1555010725.016 [Default:CheckIn](INFO): Running loop #7 2019-04-11T19:25:25.016Z,1555010725.016 [Default:CheckIn] Running Loop=7 2019-04-11T19:25:25.016Z,1555010725.016 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-04-11T19:25:25.016Z,1555010725.016 [Default:CheckIn:Read_GPS] Running Loop=1 2019-04-11T19:25:26.563Z,1555010726.563 [NAL9602](DEBUG): Fix Requested 2019-04-11T19:25:26.960Z,1555010726.960 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,192526.00,A,3648.17493,N,12147.27938,W,0.039,247.26,110419,,,D*76 2019-04-11T19:25:26.962Z,1555010726.962 [NAL9602](INFO): GPS fix at 20190411T192526: (36.802915, -121.787990) 2019-04-11T19:25:26.989Z,1555010726.989 [Default:CheckIn:Read_GPS] Stopped 2019-04-11T19:25:26.989Z,1555010726.989 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-04-11T19:25:28.990Z,1555010728.990 [NAL9602](ERROR): parseGSV uart error: serial buffer full 2019-04-11T19:25:32.827Z,1555010732.827 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20190411T185732/Courier0015.lzma 2019-04-11T19:25:33.633Z,1555010733.633 [DataOverHttps](INFO): Moved sent file to Logs/20190411T185732/Courier0015.lzma.bak 2019-04-11T19:25:33.633Z,1555010733.633 [DataOverHttps](INFO): SBD MOMSN=10555825 2019-04-11T19:25:38.676Z,1555010738.676 [NAL9602](INFO): SBD MO Status=0, MOMSN=3503, MT Status=0, MTMSN=0 2019-04-11T19:25:38.676Z,1555010738.676 [NAL9602](INFO): No messages in MT queue 2019-04-11T19:25:45.188Z,1555010745.188 [DataOverHttps](INFO): Sending 552 bytes from file Logs/20190411T185732/Express0016.lzma 2019-04-11T19:25:45.965Z,1555010745.965 [DataOverHttps](INFO): Moved sent file to Logs/20190411T185732/Express0016.lzma.bak 2019-04-11T19:25:45.965Z,1555010745.965 [DataOverHttps](INFO): SBD MOMSN=10555828 2019-04-11T19:25:46.790Z,1555010746.790 [Default:CheckIn:Read_Iridium] Stopped 2019-04-11T19:25:46.791Z,1555010746.791 [Default:CheckIn:C.Wait] Running Loop=1 2019-04-11T19:25:46.791Z,1555010746.791 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-04-11T19:26:08.236Z,1555010768.236 [RDI_Pathfinder](ERROR): Failed to parse: :BE,-32768,-32768,-32768,V 2019-04-11T19:26:09.401Z,1555010769.401 [NAL9602](INFO): Not Powering down - fast GPS 2019-04-11T19:27:45.564Z,1555010865.564 [RDI_Pathfinder](ERROR): Failed to parse: :BI,-32768,-32768,-32768,-32768,V 2019-04-11T19:28:46.197Z,1555010926.197 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude 2019-04-11T19:28:46.197Z,1555010926.197 [RDI_Pathfinder](ERROR): Failed to parse: :BD, +0.0 +0.00, +0.00, 0.00,1940.85 2019-04-11T19:30:03.413Z,1555011003.413 [RDI_Pathfinder](ERROR): Failed to parse: :SA, +0.00, +0.00, 0.00 2019-04-11T19:30:47.403Z,1555011047.403 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-04-11T19:30:47.403Z,1555011047.403 [Default:CheckIn:C.Wait] Stopped 2019-04-11T19:30:47.403Z,1555011047.403 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-04-11T19:30:47.404Z,1555011047.404 [Default:CheckIn:D] Running Loop=1 2019-04-11T19:30:47.802Z,1555011047.802 [Default:CheckIn:D] Stopped 2019-04-11T19:30:47.802Z,1555011047.802 [Default:CheckIn:E] Running Loop=1 2019-04-11T19:30:48.244Z,1555011048.244 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 41.349264 min 2019-04-11T19:30:48.244Z,1555011048.244 [Default:CheckIn:E] Stopped 2019-04-11T19:30:48.244Z,1555011048.244 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-04-11T19:30:48.244Z,1555011048.244 [Default:CheckIn] Stopped 2019-04-11T19:30:48.244Z,1555011048.244 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-04-11T19:30:48.245Z,1555011048.245 [Default:CheckIn](INFO): Running loop #8 2019-04-11T19:30:48.245Z,1555011048.245 [Default:CheckIn] Running Loop=8 2019-04-11T19:30:48.245Z,1555011048.245 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-04-11T19:30:48.245Z,1555011048.245 [Default:CheckIn:Read_GPS] Running Loop=1 2019-04-11T19:30:49.811Z,1555011049.811 [NAL9602](DEBUG): Fix Requested 2019-04-11T19:30:50.197Z,1555011050.197 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,193049.00,A,3648.17636,N,12147.27780,W,0.039,2.28,110419,,,A*73 2019-04-11T19:30:50.200Z,1555011050.200 [NAL9602](INFO): GPS fix at 20190411T193049: (36.802939, -121.787963) 2019-04-11T19:30:50.223Z,1555011050.223 [Default:CheckIn:Read_GPS] Stopped 2019-04-11T19:30:50.223Z,1555011050.223 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-04-11T19:30:51.825Z,1555011051.825 [NAL9602](ERROR): parseGSV uart error: serial buffer full 2019-04-11T19:30:56.051Z,1555011056.051 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20190411T185732/Courier0018.lzma 2019-04-11T19:30:56.857Z,1555011056.857 [DataOverHttps](INFO): Moved sent file to Logs/20190411T185732/Courier0018.lzma.bak 2019-04-11T19:30:56.857Z,1555011056.857 [DataOverHttps](INFO): SBD MOMSN=10555833 2019-04-11T19:31:03.552Z,1555011063.552 [RDI_Pathfinder](ERROR): Failed to parse: :RA, 0.00, 0.00, 0.00, 0.00, 0.00 2019-04-11T19:31:08.356Z,1555011068.356 [DataOverHttps](INFO): Sending 558 bytes from file Logs/20190411T185732/Express0019.lzma 2019-04-11T19:31:09.161Z,1555011069.161 [DataOverHttps](INFO): Moved sent file to Logs/20190411T185732/Express0019.lzma.bak 2019-04-11T19:31:09.161Z,1555011069.161 [DataOverHttps](INFO): SBD MOMSN=10555836 2019-04-11T19:31:10.026Z,1555011070.026 [Default:CheckIn:Read_Iridium] Stopped 2019-04-11T19:31:10.026Z,1555011070.026 [Default:CheckIn:C.Wait] Running Loop=1 2019-04-11T19:31:10.026Z,1555011070.026 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-04-11T19:32:37.263Z,1555011157.263 [NAL9602](INFO): SBD MO Status=2, MOMSN=3504, MT Status=2, MTMSN=0 2019-04-11T19:32:37.263Z,1555011157.263 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-04-11T19:32:55.843Z,1555011175.843 [NAL9602](INFO): SBD MO Status=2, MOMSN=3504, MT Status=2, MTMSN=0 2019-04-11T19:32:55.843Z,1555011175.843 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-04-11T19:33:08.775Z,1555011188.775 [NAL9602](INFO): SBD MO Status=0, MOMSN=3504, MT Status=0, MTMSN=0 2019-04-11T19:33:08.775Z,1555011188.775 [NAL9602](INFO): No messages in MT queue 2019-04-11T19:33:39.481Z,1555011219.481 [NAL9602](INFO): Not Powering down - fast GPS 2019-04-11T19:36:10.626Z,1555011370.626 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-04-11T19:36:10.626Z,1555011370.626 [Default:CheckIn:C.Wait] Stopped 2019-04-11T19:36:10.626Z,1555011370.626 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-04-11T19:36:10.627Z,1555011370.627 [Default:CheckIn:D] Running Loop=1 2019-04-11T19:36:11.006Z,1555011371.006 [Default:CheckIn:D] Stopped 2019-04-11T19:36:11.006Z,1555011371.006 [Default:CheckIn:E] Running Loop=1 2019-04-11T19:36:11.411Z,1555011371.411 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 46.735994 min 2019-04-11T19:36:11.411Z,1555011371.411 [Default:CheckIn:E] Stopped 2019-04-11T19:36:11.411Z,1555011371.411 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-04-11T19:36:11.411Z,1555011371.411 [Default:CheckIn] Stopped 2019-04-11T19:36:11.411Z,1555011371.411 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-04-11T19:36:11.411Z,1555011371.411 [Default:CheckIn](INFO): Running loop #9 2019-04-11T19:36:11.411Z,1555011371.411 [Default:CheckIn] Running Loop=9 2019-04-11T19:36:11.412Z,1555011371.412 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-04-11T19:36:11.412Z,1555011371.412 [Default:CheckIn:Read_GPS] Running Loop=1 2019-04-11T19:36:13.011Z,1555011373.011 [NAL9602](DEBUG): Fix Requested 2019-04-11T19:36:13.403Z,1555011373.403 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,193612.00,A,3648.17996,N,12147.27542,W,0.156,229.79,110419,,,A*75 2019-04-11T19:36:13.405Z,1555011373.405 [NAL9602](INFO): GPS fix at 20190411T193612: (36.802999, -121.787924) 2019-04-11T19:36:13.459Z,1555011373.459 [Default:CheckIn:Read_GPS] Stopped 2019-04-11T19:36:13.459Z,1555011373.459 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-04-11T19:36:15.034Z,1555011375.034 [NAL9602](ERROR): parseGSV uart error: serial buffer full 2019-04-11T19:36:19.179Z,1555011379.179 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20190411T185732/Courier0021.lzma 2019-04-11T19:36:19.993Z,1555011379.993 [DataOverHttps](INFO): Moved sent file to Logs/20190411T185732/Courier0021.lzma.bak 2019-04-11T19:36:19.993Z,1555011379.993 [DataOverHttps](INFO): SBD MOMSN=10555998 2019-04-11T19:36:25.563Z,1555011385.563 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2019-04-11T19:36:25.563Z,1555011385.563 [RDI_Pathfinder](ERROR): Failed to parse: :TS,19041112451023,35.0, -0.1, 0.0, 0 2019-04-11T19:36:27.955Z,1555011387.955 [NAL9602](INFO): SBD MO Status=0, MOMSN=3505, MT Status=0, MTMSN=0 2019-04-11T19:36:27.955Z,1555011387.955 [NAL9602](INFO): No messages in MT queue 2019-04-11T19:36:31.644Z,1555011391.644 [DataOverHttps](INFO): Sending 555 bytes from file Logs/20190411T185732/Express0022.lzma 2019-04-11T19:36:32.449Z,1555011392.449 [DataOverHttps](INFO): Moved sent file to Logs/20190411T185732/Express0022.lzma.bak 2019-04-11T19:36:32.449Z,1555011392.449 [DataOverHttps](INFO): SBD MOMSN=10556001 2019-04-11T19:36:33.286Z,1555011393.286 [Default:CheckIn:Read_Iridium] Stopped 2019-04-11T19:36:33.286Z,1555011393.286 [Default:CheckIn:C.Wait] Running Loop=1 2019-04-11T19:36:33.286Z,1555011393.286 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-04-11T19:36:42.929Z,1555011402.929 [RDI_Pathfinder](ERROR): only read 3 of 4 data items 2019-04-11T19:36:42.929Z,1555011402.929 [RDI_Pathfinder](ERROR): Failed to parse: :RA, 0.00, 0.00, 0.00, 0.00 2019-04-11T19:36:58.662Z,1555011418.662 [NAL9602](INFO): Not Powering down - fast GPS 2019-04-11T19:41:33.809Z,1555011693.809 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-04-11T19:41:33.809Z,1555011693.809 [Default:CheckIn:C.Wait] Stopped 2019-04-11T19:41:33.809Z,1555011693.809 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-04-11T19:41:33.809Z,1555011693.809 [Default:CheckIn:D] Running Loop=1 2019-04-11T19:41:34.248Z,1555011694.248 [Default:CheckIn:D] Stopped 2019-04-11T19:41:34.248Z,1555011694.248 [Default:CheckIn:E] Running Loop=1 2019-04-11T19:41:34.611Z,1555011694.611 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 52.123356 min 2019-04-11T19:41:34.612Z,1555011694.612 [Default:CheckIn:E] Stopped 2019-04-11T19:41:34.612Z,1555011694.612 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-04-11T19:41:34.612Z,1555011694.612 [Default:CheckIn] Stopped 2019-04-11T19:41:34.612Z,1555011694.612 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-04-11T19:41:34.612Z,1555011694.612 [Default:CheckIn](INFO): Running loop #10 2019-04-11T19:41:34.612Z,1555011694.612 [Default:CheckIn] Running Loop=10 2019-04-11T19:41:34.612Z,1555011694.612 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-04-11T19:41:34.612Z,1555011694.612 [Default:CheckIn:Read_GPS] Running Loop=1 2019-04-11T19:41:36.219Z,1555011696.219 [NAL9602](DEBUG): Fix Requested 2019-04-11T19:41:36.615Z,1555011696.615 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194135.00,A,3648.17402,N,12147.27556,W,0.214,209.60,110419,,,A*7A 2019-04-11T19:41:36.617Z,1555011696.617 [NAL9602](INFO): GPS fix at 20190411T194135: (36.802900, -121.787926) 2019-04-11T19:41:36.659Z,1555011696.659 [Default:CheckIn:Read_GPS] Stopped 2019-04-11T19:41:36.659Z,1555011696.659 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-04-11T19:41:37.833Z,1555011697.833 [NAL9602](ERROR): parseGSV uart error: serial buffer full 2019-04-11T19:41:42.211Z,1555011702.211 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20190411T185732/Courier0024.lzma 2019-04-11T19:41:43.017Z,1555011703.017 [DataOverHttps](INFO): Moved sent file to Logs/20190411T185732/Courier0024.lzma.bak 2019-04-11T19:41:43.017Z,1555011703.017 [DataOverHttps](INFO): SBD MOMSN=10556006 2019-04-11T19:41:54.605Z,1555011714.605 [DataOverHttps](INFO): Sending 553 bytes from file Logs/20190411T185732/Express0025.lzma 2019-04-11T19:41:55.409Z,1555011715.409 [DataOverHttps](INFO): Moved sent file to Logs/20190411T185732/Express0025.lzma.bak 2019-04-11T19:41:55.409Z,1555011715.409 [DataOverHttps](INFO): SBD MOMSN=10556011 2019-04-11T19:41:56.043Z,1555011716.043 [Default:CheckIn:Read_Iridium] Stopped 2019-04-11T19:41:56.043Z,1555011716.043 [Default:CheckIn:C.Wait] Running Loop=1 2019-04-11T19:41:56.043Z,1555011716.043 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-04-11T19:42:22.674Z,1555011742.674 [NAL9602](INFO): SBD MO Status=0, MOMSN=3506, MT Status=0, MTMSN=0 2019-04-11T19:42:22.675Z,1555011742.675 [NAL9602](INFO): No messages in MT queue 2019-04-11T19:42:53.372Z,1555011773.372 [NAL9602](INFO): Not Powering down - fast GPS 2019-04-11T19:45:53.579Z,1555011953.579 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2019-04-11T19:45:53.579Z,1555011953.579 [RDI_Pathfinder](ERROR): Failed to parse: :TS,19041112543823,35.0, -0.1, 0.0,10 2019-04-11T19:46:56.608Z,1555012016.608 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-04-11T19:46:56.608Z,1555012016.608 [Default:CheckIn:C.Wait] Stopped 2019-04-11T19:46:56.608Z,1555012016.608 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-04-11T19:46:56.608Z,1555012016.608 [Default:CheckIn:D] Running Loop=1 2019-04-11T19:46:57.017Z,1555012017.017 [Default:CheckIn:D] Stopped 2019-04-11T19:46:57.017Z,1555012017.017 [Default:CheckIn:E] Running Loop=1 2019-04-11T19:46:57.438Z,1555012017.438 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 57.502840 min 2019-04-11T19:46:57.439Z,1555012017.439 [Default:CheckIn:E] Stopped 2019-04-11T19:46:57.439Z,1555012017.439 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-04-11T19:46:57.439Z,1555012017.439 [Default:CheckIn] Stopped 2019-04-11T19:46:57.439Z,1555012017.439 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-04-11T19:46:57.439Z,1555012017.439 [Default:CheckIn](INFO): Running loop #11 2019-04-11T19:46:57.439Z,1555012017.439 [Default:CheckIn] Running Loop=11 2019-04-11T19:46:57.440Z,1555012017.440 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-04-11T19:46:57.440Z,1555012017.440 [Default:CheckIn:Read_GPS] Running Loop=1 2019-04-11T19:46:59.015Z,1555012019.015 [NAL9602](DEBUG): Fix Requested 2019-04-11T19:46:59.409Z,1555012019.409 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194658.00,A,3648.17653,N,12147.27712,W,0.214,207.09,110419,,,A*73 2019-04-11T19:46:59.411Z,1555012019.411 [NAL9602](INFO): GPS fix at 20190411T194658: (36.802942, -121.787952) 2019-04-11T19:46:59.446Z,1555012019.446 [Default:CheckIn:Read_GPS] Stopped 2019-04-11T19:46:59.446Z,1555012019.446 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-04-11T19:47:01.049Z,1555012021.049 [NAL9602](ERROR): parseGSV uart error: serial buffer full 2019-04-11T19:47:05.155Z,1555012025.155 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20190411T185732/Courier0027.lzma 2019-04-11T19:47:05.953Z,1555012025.953 [DataOverHttps](INFO): Moved sent file to Logs/20190411T185732/Courier0027.lzma.bak 2019-04-11T19:47:05.953Z,1555012025.953 [DataOverHttps](INFO): SBD MOMSN=10556143 2019-04-11T19:47:17.195Z,1555012037.195 [NAL9602](INFO): SBD MO Status=0, MOMSN=3507, MT Status=0, MTMSN=0 2019-04-11T19:47:17.195Z,1555012037.195 [NAL9602](INFO): No messages in MT queue 2019-04-11T19:47:18.664Z,1555012038.664 [DataOverHttps](INFO): Sending 551 bytes from file Logs/20190411T185732/Express0028.lzma 2019-04-11T19:47:19.469Z,1555012039.469 [DataOverHttps](INFO): Moved sent file to Logs/20190411T185732/Express0028.lzma.bak 2019-04-11T19:47:19.469Z,1555012039.469 [DataOverHttps](INFO): SBD MOMSN=10556146 2019-04-11T19:47:20.483Z,1555012040.483 [Default:CheckIn:Read_Iridium] Stopped 2019-04-11T19:47:20.483Z,1555012040.483 [Default:CheckIn:C.Wait] Running Loop=1 2019-04-11T19:47:20.483Z,1555012040.483 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-04-11T19:47:47.893Z,1555012067.893 [NAL9602](INFO): Not Powering down - fast GPS 2019-04-11T19:52:21.045Z,1555012341.045 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-04-11T19:52:21.045Z,1555012341.045 [Default:CheckIn:C.Wait] Stopped 2019-04-11T19:52:21.045Z,1555012341.045 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-04-11T19:52:21.046Z,1555012341.046 [Default:CheckIn:D] Running Loop=1 2019-04-11T19:52:21.456Z,1555012341.456 [Default:CheckIn:D] Stopped 2019-04-11T19:52:21.456Z,1555012341.456 [Default:CheckIn:E] Running Loop=1 2019-04-11T19:52:21.871Z,1555012341.871 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 62.910156 min 2019-04-11T19:52:21.871Z,1555012341.871 [Default:CheckIn:E] Stopped 2019-04-11T19:52:21.872Z,1555012341.872 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-04-11T19:52:21.872Z,1555012341.872 [Default:CheckIn] Stopped 2019-04-11T19:52:21.872Z,1555012341.872 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-04-11T19:52:21.872Z,1555012341.872 [Default:CheckIn](INFO): Running loop #12 2019-04-11T19:52:21.872Z,1555012341.872 [Default:CheckIn] Running Loop=12 2019-04-11T19:52:21.872Z,1555012341.872 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-04-11T19:52:21.872Z,1555012341.872 [Default:CheckIn:Read_GPS] Running Loop=1 2019-04-11T19:52:23.451Z,1555012343.451 [NAL9602](DEBUG): Fix Requested 2019-04-11T19:52:23.850Z,1555012343.850 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,195223.00,A,3648.17362,N,12147.28005,W,0.175,265.88,110419,,,A*7A 2019-04-11T19:52:23.852Z,1555012343.852 [NAL9602](INFO): GPS fix at 20190411T195223: (36.802894, -121.788001) 2019-04-11T19:52:23.875Z,1555012343.875 [Default:CheckIn:Read_GPS] Stopped 2019-04-11T19:52:23.875Z,1555012343.875 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-04-11T19:52:25.874Z,1555012345.874 [NAL9602](ERROR): parseGSV uart error: serial buffer full 2019-04-11T19:52:29.695Z,1555012349.695 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20190411T185732/Courier0030.lzma 2019-04-11T19:52:30.501Z,1555012350.501 [DataOverHttps](INFO): Moved sent file to Logs/20190411T185732/Courier0030.lzma.bak 2019-04-11T19:52:30.501Z,1555012350.501 [DataOverHttps](INFO): SBD MOMSN=10556215 2019-04-11T19:52:42.328Z,1555012362.328 [DataOverHttps](INFO): Sending 555 bytes from file Logs/20190411T185732/Express0031.lzma 2019-04-11T19:52:43.134Z,1555012363.134 [DataOverHttps](INFO): Moved sent file to Logs/20190411T185732/Express0031.lzma.bak 2019-04-11T19:52:43.134Z,1555012363.134 [DataOverHttps](INFO): SBD MOMSN=10556218 2019-04-11T19:52:44.047Z,1555012364.047 [NAL9602](INFO): SBD MO Status=0, MOMSN=3508, MT Status=0, MTMSN=0 2019-04-11T19:52:44.048Z,1555012364.048 [NAL9602](INFO): No messages in MT queue 2019-04-11T19:52:44.079Z,1555012364.079 [Default:CheckIn:Read_Iridium] Stopped 2019-04-11T19:52:44.079Z,1555012364.079 [Default:CheckIn:C.Wait] Running Loop=1 2019-04-11T19:52:44.079Z,1555012364.079 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-04-11T19:53:14.746Z,1555012394.746 [NAL9602](INFO): Not Powering down - fast GPS 2019-04-11T19:54:14.568Z,1555012454.568 [RDI_Pathfinder](ERROR): only read 3 of 4 data items 2019-04-11T19:54:14.568Z,1555012454.568 [RDI_Pathfinder](ERROR): Failed to parse: :RA, 0.00, 0.00, 0.00, 0.00 2019-04-11T19:57:44.658Z,1555012664.658 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-04-11T19:57:44.658Z,1555012664.658 [Default:CheckIn:C.Wait] Stopped 2019-04-11T19:57:44.658Z,1555012664.658 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-04-11T19:57:44.658Z,1555012664.658 [Default:CheckIn:D] Running Loop=1 2019-04-11T19:57:45.074Z,1555012665.074 [Default:CheckIn:D] Stopped 2019-04-11T19:57:45.074Z,1555012665.074 [Default:CheckIn:E] Running Loop=1 2019-04-11T19:57:45.517Z,1555012665.517 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 68.303792 min 2019-04-11T19:57:45.517Z,1555012665.517 [Default:CheckIn:E] Stopped 2019-04-11T19:57:45.517Z,1555012665.517 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-04-11T19:57:45.517Z,1555012665.517 [Default:CheckIn] Stopped 2019-04-11T19:57:45.517Z,1555012665.517 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-04-11T19:57:45.517Z,1555012665.517 [Default:CheckIn](INFO): Running loop #13 2019-04-11T19:57:45.517Z,1555012665.517 [Default:CheckIn] Running Loop=13 2019-04-11T19:57:45.518Z,1555012665.518 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-04-11T19:57:45.518Z,1555012665.518 [Default:CheckIn:Read_GPS] Running Loop=1 2019-04-11T19:57:47.059Z,1555012667.059 [NAL9602](DEBUG): Fix Requested 2019-04-11T19:57:47.453Z,1555012667.453 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,195746.00,A,3648.16532,N,12147.28065,W,0.097,199.64,110419,,,A*77 2019-04-11T19:57:47.455Z,1555012667.455 [NAL9602](INFO): GPS fix at 20190411T195746: (36.802755, -121.788011) 2019-04-11T19:57:47.493Z,1555012667.493 [Default:CheckIn:Read_GPS] Stopped 2019-04-11T19:57:47.493Z,1555012667.493 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-04-11T19:57:49.074Z,1555012669.074 [NAL9602](ERROR): parseGSV uart error: serial buffer full 2019-04-11T19:57:53.340Z,1555012673.340 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20190411T185732/Courier0033.lzma 2019-04-11T19:57:54.127Z,1555012674.127 [DataOverHttps](INFO): Moved sent file to Logs/20190411T185732/Courier0033.lzma.bak 2019-04-11T19:57:54.127Z,1555012674.127 [DataOverHttps](INFO): SBD MOMSN=10556258 2019-04-11T19:58:08.016Z,1555012688.016 [DataOverHttps](INFO): Sending 552 bytes from file Logs/20190411T185732/Express0034.lzma 2019-04-11T19:58:08.821Z,1555012688.821 [DataOverHttps](INFO): Moved sent file to Logs/20190411T185732/Express0034.lzma.bak 2019-04-11T19:58:08.821Z,1555012688.821 [DataOverHttps](INFO): SBD MOMSN=10556261 2019-04-11T19:58:09.706Z,1555012689.706 [Default:CheckIn:Read_Iridium] Stopped 2019-04-11T19:58:09.706Z,1555012689.706 [Default:CheckIn:C.Wait] Running Loop=1 2019-04-11T19:58:09.707Z,1555012689.707 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-04-11T19:59:50.687Z,1555012790.687 [NAL9602](INFO): SBD MO Status=2, MOMSN=3509, MT Status=2, MTMSN=0 2019-04-11T19:59:50.687Z,1555012790.687 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-04-11T20:01:59.609Z,1555012919.609 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2019-04-11T20:01:59.609Z,1555012919.609 [RDI_Pathfinder](ERROR): Failed to parse: :TS,19041113104423,35.0, -0.1, 0.0,1448.9A, 0.00, 0.00, 0.00, 0.00, 0.00 2019-04-11T20:02:49.682Z,1555012969.682 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-04-11T20:03:10.313Z,1555012990.313 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-04-11T20:03:10.314Z,1555012990.314 [Default:CheckIn:C.Wait] Stopped 2019-04-11T20:03:10.314Z,1555012990.314 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-04-11T20:03:10.315Z,1555012990.315 [Default:CheckIn:D] Running Loop=1 2019-04-11T20:03:10.775Z,1555012990.775 [Default:CheckIn:D] Stopped 2019-04-11T20:03:10.776Z,1555012990.776 [Default:CheckIn:E] Running Loop=1 2019-04-11T20:03:11.124Z,1555012991.124 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 73.732145 min 2019-04-11T20:03:11.124Z,1555012991.124 [Default:CheckIn:E] Stopped 2019-04-11T20:03:11.124Z,1555012991.124 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-04-11T20:03:11.124Z,1555012991.124 [Default:CheckIn] Stopped 2019-04-11T20:03:11.124Z,1555012991.124 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-04-11T20:03:11.124Z,1555012991.124 [Default:CheckIn](INFO): Running loop #14 2019-04-11T20:03:11.124Z,1555012991.124 [Default:CheckIn] Running Loop=14 2019-04-11T20:03:11.124Z,1555012991.124 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-04-11T20:03:11.125Z,1555012991.125 [Default:CheckIn:Read_GPS] Running Loop=1 2019-04-11T20:03:12.723Z,1555012992.723 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:03:13.115Z,1555012993.115 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,200312.00,A,3648.16125,N,12147.29459,W,0.233,225.79,110419,,,A*71 2019-04-11T20:03:13.117Z,1555012993.117 [NAL9602](INFO): GPS fix at 20190411T200312: (36.802687, -121.788243) 2019-04-11T20:03:13.144Z,1555012993.144 [Default:CheckIn:Read_GPS] Stopped 2019-04-11T20:03:13.144Z,1555012993.144 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-04-11T20:03:14.733Z,1555012994.733 [NAL9602](ERROR): parseGSV uart error: serial buffer full 2019-04-11T20:03:18.963Z,1555012998.963 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20190411T185732/Courier0036.lzma 2019-04-11T20:03:19.769Z,1555012999.769 [DataOverHttps](INFO): Moved sent file to Logs/20190411T185732/Courier0036.lzma.bak 2019-04-11T20:03:19.769Z,1555012999.769 [DataOverHttps](INFO): SBD MOMSN=10556326 2019-04-11T20:03:31.573Z,1555013011.573 [DataOverHttps](INFO): Sending 678 bytes from file Logs/20190411T185732/Express0037.lzma 2019-04-11T20:03:32.377Z,1555013012.377 [DataOverHttps](INFO): Moved sent file to Logs/20190411T185732/Express0037.lzma.bak 2019-04-11T20:03:32.377Z,1555013012.377 [DataOverHttps](INFO): SBD MOMSN=10556356 2019-04-11T20:03:33.356Z,1555013013.356 [Default:CheckIn:Read_Iridium] Stopped 2019-04-11T20:03:33.356Z,1555013013.356 [Default:CheckIn:C.Wait] Running Loop=1 2019-04-11T20:03:33.357Z,1555013013.357 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-04-11T20:03:34.562Z,1555013014.562 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2019-04-11T20:03:34.562Z,1555013014.562 [RDI_Pathfinder](ERROR): Failed to parse: :TS,1904111312192-0.1, 0.0,1448.9, 0 2019-04-11T20:03:45.433Z,1555013025.433 [NAL9602](INFO): Not Powering down - fast GPS 2019-04-11T20:05:38.570Z,1555013138.570 [RDI_Pathfinder](ERROR): only read 2 of 4 data items 2019-04-11T20:05:38.570Z,1555013138.570 [RDI_Pathfinder](ERROR): Failed to parse: :BS,-32768,-32768V 2019-04-11T20:05:55.556Z,1555013155.556 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2019-04-11T20:05:55.556Z,1555013155.556 [RDI_Pathfinder](ERROR): Failed to parse: :TS,19041113140, -0.1, 0.0,1448.9, 0 2019-04-11T20:08:16.554Z,1555013296.554 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2019-04-11T20:08:16.554Z,1555013296.554 [RDI_Pathfinder](ERROR): Failed to parse: :TS,19041113170123,35.0, -0.,1448.9, 0 2019-04-11T20:08:33.916Z,1555013313.916 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-04-11T20:08:33.916Z,1555013313.916 [Default:CheckIn:C.Wait] Stopped 2019-04-11T20:08:33.916Z,1555013313.916 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-04-11T20:08:33.917Z,1555013313.917 [Default:CheckIn:D] Running Loop=1 2019-04-11T20:08:34.330Z,1555013314.330 [Default:CheckIn:D] Stopped 2019-04-11T20:08:34.330Z,1555013314.330 [Default:CheckIn:E] Running Loop=1 2019-04-11T20:08:34.723Z,1555013314.723 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 79.124715 min 2019-04-11T20:08:34.723Z,1555013314.723 [Default:CheckIn:E] Stopped 2019-04-11T20:08:34.723Z,1555013314.723 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-04-11T20:08:34.723Z,1555013314.723 [Default:CheckIn] Stopped 2019-04-11T20:08:34.723Z,1555013314.723 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-04-11T20:08:34.723Z,1555013314.723 [Default:CheckIn](INFO): Running loop #15 2019-04-11T20:08:34.723Z,1555013314.723 [Default:CheckIn] Running Loop=15 2019-04-11T20:08:34.724Z,1555013314.724 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-04-11T20:08:34.724Z,1555013314.724 [Default:CheckIn:Read_GPS] Running Loop=1 2019-04-11T20:08:36.331Z,1555013316.331 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:08:36.723Z,1555013316.723 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,200835.00,A,3648.16265,N,12147.29031,W,1.205,135.25,110419,,,A*7D 2019-04-11T20:08:36.725Z,1555013316.725 [NAL9602](INFO): GPS fix at 20190411T200835: (36.802711, -121.788172) 2019-04-11T20:08:36.772Z,1555013316.772 [Default:CheckIn:Read_GPS] Stopped 2019-04-11T20:08:36.772Z,1555013316.772 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-04-11T20:08:38.746Z,1555013318.746 [NAL9602](ERROR): parseGSV uart error: serial buffer full 2019-04-11T20:08:42.635Z,1555013322.635 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20190411T185732/Courier0039.lzma 2019-04-11T20:08:43.441Z,1555013323.441 [DataOverHttps](INFO): Moved sent file to Logs/20190411T185732/Courier0039.lzma.bak 2019-04-11T20:08:43.441Z,1555013323.441 [DataOverHttps](INFO): SBD MOMSN=10556507 2019-04-11T20:08:55.100Z,1555013335.100 [DataOverHttps](INFO): Sending 551 bytes from file Logs/20190411T185732/Express0040.lzma 2019-04-11T20:08:55.905Z,1555013335.905 [DataOverHttps](INFO): Moved sent file to Logs/20190411T185732/Express0040.lzma.bak 2019-04-11T20:08:55.905Z,1555013335.905 [DataOverHttps](INFO): SBD MOMSN=10556510 2019-04-11T20:08:56.547Z,1555013336.547 [Default:CheckIn:Read_Iridium] Stopped 2019-04-11T20:08:56.547Z,1555013336.547 [Default:CheckIn:C.Wait] Running Loop=1 2019-04-11T20:08:56.547Z,1555013336.547 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-04-11T20:09:07.425Z,1555013347.425 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2019-04-11T20:09:07.939Z,1555013347.939 [NAL9602](FAULT): received: 2019-04-11T20:09:07.940Z,1555013347.940 [NAL9602] Data Fault, FailCount= 1 2019-04-11T20:09:07.940Z,1555013347.940 [NAL9602](ERROR): Data Fault 2019-04-11T20:09:07.982Z,1555013347.982 [CBIT](ERROR): Data Fault in component: NAL9602 2019-04-11T20:09:08.073Z,1555013348.073 [NAL9602](INFO): Powering down 2019-04-11T20:09:08.405Z,1555013348.405 [NAL9602](FAULT): LCB fault: Software Overcurrent. 2019-04-11T20:09:08.405Z,1555013348.405 [NAL9602] Hardware Fault, FailCount= 1 2019-04-11T20:09:08.405Z,1555013348.405 [NAL9602](ERROR): Hardware Fault 2019-04-11T20:09:08.847Z,1555013348.847 [CBIT](INFO): Clearing failed state for component NAL9602 2019-04-11T20:09:08.847Z,1555013348.847 [NAL9602] No Fault, FailCount= 1 2019-04-11T20:09:38.297Z,1555013378.297 [NAL9602](INFO): Powering up NAL9602 2019-04-11T20:09:49.241Z,1555013389.241 [NAL9602](INFO): NAL9602 initialized 2019-04-11T20:10:20.344Z,1555013420.344 [NAL9602](INFO): Not Powering down - fast GPS 2019-04-11T20:13:57.302Z,1555013637.302 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-04-11T20:13:57.302Z,1555013637.302 [Default:CheckIn:C.Wait] Stopped 2019-04-11T20:13:57.302Z,1555013637.302 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-04-11T20:13:57.302Z,1555013637.302 [Default:CheckIn:D] Running Loop=1 2019-04-11T20:13:57.706Z,1555013637.706 [Default:CheckIn:D] Stopped 2019-04-11T20:13:57.706Z,1555013637.706 [Default:CheckIn:E] Running Loop=1 2019-04-11T20:13:58.109Z,1555013638.109 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 84.514331 min 2019-04-11T20:13:58.109Z,1555013638.109 [Default:CheckIn:E] Stopped 2019-04-11T20:13:58.109Z,1555013638.109 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-04-11T20:13:58.109Z,1555013638.109 [Default:CheckIn] Stopped 2019-04-11T20:13:58.110Z,1555013638.110 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-04-11T20:13:58.110Z,1555013638.110 [Default:CheckIn](INFO): Running loop #16 2019-04-11T20:13:58.110Z,1555013638.110 [Default:CheckIn] Running Loop=16 2019-04-11T20:13:58.110Z,1555013638.110 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-04-11T20:13:58.110Z,1555013638.110 [Default:CheckIn:Read_GPS] Running Loop=1 2019-04-11T20:13:59.707Z,1555013639.707 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:14:02.117Z,1555013642.117 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-04-11T20:14:02.939Z,1555013642.939 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:14:05.363Z,1555013645.363 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:14:08.207Z,1555013648.207 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:14:10.211Z,1555013650.211 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:14:13.439Z,1555013653.439 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:14:16.267Z,1555013656.267 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:14:19.503Z,1555013659.503 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:14:22.331Z,1555013662.331 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:14:25.563Z,1555013665.563 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:14:28.391Z,1555013668.391 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:14:31.619Z,1555013671.619 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:14:34.447Z,1555013674.447 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:14:37.679Z,1555013677.679 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:14:40.511Z,1555013680.511 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:14:43.343Z,1555013683.343 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:14:46.183Z,1555013686.183 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:14:48.207Z,1555013688.207 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:14:50.203Z,1555013690.203 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:14:53.435Z,1555013693.435 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:14:56.267Z,1555013696.267 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:14:59.499Z,1555013699.499 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:15:02.319Z,1555013702.319 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:15:05.571Z,1555013705.571 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:15:08.379Z,1555013708.379 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:15:11.215Z,1555013711.215 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:15:13.639Z,1555013713.639 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:15:16.471Z,1555013716.471 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:15:19.695Z,1555013719.695 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:15:22.539Z,1555013722.539 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:15:25.351Z,1555013725.351 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:15:25.371Z,1555013725.371 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2019-04-11T20:15:25.371Z,1555013725.371 [RDI_Pathfinder](ERROR): Failed to parse: :TS,19041113240923,35.0, -0.1, 0.0,14 +0.00, 0.00,4738.02 2019-04-11T20:15:28.211Z,1555013728.211 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:15:30.199Z,1555013730.199 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:15:32.219Z,1555013732.219 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:15:35.451Z,1555013735.451 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:15:38.296Z,1555013738.296 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:15:41.124Z,1555013741.124 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:15:43.544Z,1555013743.544 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:15:46.376Z,1555013746.376 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:15:49.608Z,1555013749.608 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:15:52.431Z,1555013752.431 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:15:55.664Z,1555013755.664 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:15:58.492Z,1555013758.492 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:16:01.331Z,1555013761.331 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:16:04.200Z,1555013764.200 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:16:06.192Z,1555013766.192 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:16:08.227Z,1555013768.227 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:16:10.216Z,1555013770.216 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:16:13.460Z,1555013773.460 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:16:16.299Z,1555013776.299 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:16:19.508Z,1555013779.508 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:16:22.328Z,1555013782.328 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:16:25.560Z,1555013785.560 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:16:28.388Z,1555013788.388 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:16:31.619Z,1555013791.619 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:16:34.460Z,1555013794.460 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:16:37.692Z,1555013797.692 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:16:40.508Z,1555013800.508 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:16:43.336Z,1555013803.336 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:16:46.203Z,1555013806.203 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:16:48.228Z,1555013808.228 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:16:50.203Z,1555013810.203 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:16:53.440Z,1555013813.440 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:16:56.264Z,1555013816.264 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:16:59.496Z,1555013819.496 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:17:02.324Z,1555013822.324 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:17:05.556Z,1555013825.556 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:17:08.384Z,1555013828.384 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:17:11.212Z,1555013831.212 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:17:13.636Z,1555013833.636 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:17:16.467Z,1555013836.467 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:17:19.696Z,1555013839.696 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:17:22.555Z,1555013842.555 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:17:25.352Z,1555013845.352 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:17:28.208Z,1555013848.208 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:17:30.200Z,1555013850.200 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:17:33.440Z,1555013853.440 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:17:36.260Z,1555013856.260 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:17:39.492Z,1555013859.492 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:17:42.329Z,1555013862.329 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:17:45.562Z,1555013865.562 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:17:48.380Z,1555013868.380 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:17:51.208Z,1555013871.208 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:17:54.460Z,1555013874.460 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:17:57.288Z,1555013877.288 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:18:00.523Z,1555013880.523 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:18:03.354Z,1555013883.354 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:18:06.199Z,1555013886.199 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:18:08.217Z,1555013888.217 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:18:11.428Z,1555013891.428 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:18:14.263Z,1555013894.263 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:18:17.490Z,1555013897.490 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:18:20.347Z,1555013900.347 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:18:23.548Z,1555013903.548 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:18:26.375Z,1555013906.375 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:18:29.213Z,1555013909.213 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:18:31.638Z,1555013911.638 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:18:34.471Z,1555013914.471 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:18:37.688Z,1555013917.688 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:18:40.516Z,1555013920.516 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:18:43.344Z,1555013923.344 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:18:46.199Z,1555013926.199 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:18:48.211Z,1555013928.211 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:18:50.212Z,1555013930.212 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:18:53.456Z,1555013933.456 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:18:56.272Z,1555013936.272 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:18:58.379Z,1555013938.379 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-04-11T20:13:58.1Z 2019-04-11T20:18:58.379Z,1555013938.379 [Default:CheckIn:Read_GPS] Stopped 2019-04-11T20:18:58.408Z,1555013938.408 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-04-11T20:19:05.739Z,1555013945.739 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190411T185732/Courier0042.lzma 2019-04-11T20:19:06.309Z,1555013946.309 [DataOverHttps](INFO): Moved sent file to Logs/20190411T185732/Courier0042.lzma.bak 2019-04-11T20:19:06.309Z,1555013946.309 [DataOverHttps](INFO): SBD MOMSN=10556619 2019-04-11T20:19:28.998Z,1555013968.998 [DataOverHttps](INFO): Sending 1114 bytes from file Logs/20190411T185732/Express0043.lzma 2019-04-11T20:19:29.801Z,1555013969.801 [DataOverHttps](INFO): Moved sent file to Logs/20190411T185732/Express0043.lzma.bak 2019-04-11T20:19:29.801Z,1555013969.801 [DataOverHttps](INFO): SBD MOMSN=10556621 2019-04-11T20:19:29.945Z,1555013969.945 [NAL9602](INFO): Not Powering down - fast GPS 2019-04-11T20:19:30.798Z,1555013970.798 [Default:CheckIn:Read_Iridium] Stopped 2019-04-11T20:19:30.799Z,1555013970.799 [Default:CheckIn:C.Wait] Running Loop=1 2019-04-11T20:19:30.799Z,1555013970.799 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-04-11T20:24:31.442Z,1555014271.442 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-04-11T20:24:31.442Z,1555014271.442 [Default:CheckIn:C.Wait] Stopped 2019-04-11T20:24:31.442Z,1555014271.442 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-04-11T20:24:31.442Z,1555014271.442 [Default:CheckIn:D] Running Loop=1 2019-04-11T20:24:31.787Z,1555014271.787 [Default:CheckIn:D] Stopped 2019-04-11T20:24:31.787Z,1555014271.787 [Default:CheckIn:E] Running Loop=1 2019-04-11T20:24:32.203Z,1555014272.203 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 95.082340 min 2019-04-11T20:24:32.203Z,1555014272.203 [Default:CheckIn:E] Stopped 2019-04-11T20:24:32.203Z,1555014272.203 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-04-11T20:24:32.203Z,1555014272.203 [Default:CheckIn] Stopped 2019-04-11T20:24:32.203Z,1555014272.203 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-04-11T20:24:32.203Z,1555014272.203 [Default:CheckIn](INFO): Running loop #17 2019-04-11T20:24:32.203Z,1555014272.203 [Default:CheckIn] Running Loop=17 2019-04-11T20:24:32.204Z,1555014272.204 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-04-11T20:24:32.204Z,1555014272.204 [Default:CheckIn:Read_GPS] Running Loop=1 2019-04-11T20:24:33.755Z,1555014273.755 [NAL9602](FAULT): GPS failed to acquire within timeout. 2019-04-11T20:24:33.755Z,1555014273.755 [NAL9602] Data Fault, FailCount= 1 2019-04-11T20:24:33.755Z,1555014273.755 [NAL9602](ERROR): Data Fault 2019-04-11T20:24:33.795Z,1555014273.795 [CBIT](ERROR): Data Fault in component: NAL9602 2019-04-11T20:24:34.172Z,1555014274.172 [NAL9602](INFO): Powering down 2019-04-11T20:24:34.993Z,1555014274.993 [CBIT](INFO): Clearing failed state for component NAL9602 2019-04-11T20:24:34.993Z,1555014274.993 [NAL9602] No Fault, FailCount= 1 2019-04-11T20:24:58.011Z,1555014298.011 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2019-04-11T20:25:02.863Z,1555014302.863 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:25:04.454Z,1555014304.454 [NAL9602](INFO): Powering up NAL9602 2019-04-11T20:25:12.572Z,1555014312.572 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:25:15.366Z,1555014315.366 [NAL9602](INFO): NAL9602 initialized 2019-04-11T20:25:16.183Z,1555014316.183 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:25:22.678Z,1555014322.678 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:25:32.772Z,1555014332.772 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:25:42.458Z,1555014342.458 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:25:52.148Z,1555014352.148 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:26:01.858Z,1555014361.858 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:26:11.577Z,1555014371.577 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:26:21.247Z,1555014381.247 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:26:31.342Z,1555014391.342 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:26:41.430Z,1555014401.430 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:26:51.552Z,1555014411.552 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:27:01.229Z,1555014421.229 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:27:11.339Z,1555014431.339 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:27:21.429Z,1555014441.429 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:29:32.349Z,1555014572.349 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-04-11T20:24:32.2Z 2019-04-11T20:29:32.349Z,1555014572.349 [Default:CheckIn:Read_GPS] Stopped 2019-04-11T20:29:32.349Z,1555014572.349 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-04-11T20:29:38.003Z,1555014578.003 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190411T185732/Courier0045.lzma 2019-04-11T20:29:38.809Z,1555014578.809 [DataOverHttps](INFO): Moved sent file to Logs/20190411T185732/Courier0045.lzma.bak 2019-04-11T20:29:38.809Z,1555014578.809 [DataOverHttps](INFO): SBD MOMSN=10556744 2019-04-11T20:29:50.924Z,1555014590.924 [DataOverHttps](INFO): Sending 941 bytes from file Logs/20190411T185732/Express0046.lzma 2019-04-11T20:29:51.729Z,1555014591.729 [DataOverHttps](INFO): Moved sent file to Logs/20190411T185732/Express0046.lzma.bak 2019-04-11T20:29:51.729Z,1555014591.729 [DataOverHttps](INFO): SBD MOMSN=10556746 2019-04-11T20:29:52.626Z,1555014592.626 [Default:CheckIn:Read_Iridium] Stopped 2019-04-11T20:29:52.626Z,1555014592.626 [Default:CheckIn:C.Wait] Running Loop=1 2019-04-11T20:29:52.626Z,1555014592.626 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-04-11T20:29:57.847Z,1555014597.847 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:30:05.530Z,1555014605.530 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2019-04-11T20:30:05.530Z,1555014605.530 [RDI_Pathfinder](ERROR): Failed to parse: :TS,19041113385023,35.0, -0.1, 0.0,1448.9A, 0.00, 0.00, 0.00, 0.00, 0.00 2019-04-11T20:30:07.529Z,1555014607.529 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:30:17.239Z,1555014617.239 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:30:18.426Z,1555014618.426 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-04-11T20:30:26.922Z,1555014626.922 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:30:36.653Z,1555014636.653 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:30:46.744Z,1555014646.744 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:30:49.141Z,1555014649.141 [NAL9602](INFO): Not Powering down - fast GPS 2019-04-11T20:30:56.873Z,1555014656.873 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:31:06.542Z,1555014666.542 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:31:16.236Z,1555014676.236 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:31:26.342Z,1555014686.342 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:31:36.028Z,1555014696.028 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:31:45.720Z,1555014705.720 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:31:55.818Z,1555014715.818 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:32:05.531Z,1555014725.531 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:32:15.614Z,1555014735.614 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:32:22.514Z,1555014742.514 [RDI_Pathfinder](ERROR): only read 3 of 4 data items 2019-04-11T20:32:22.515Z,1555014742.515 [RDI_Pathfinder](ERROR): Failed to parse: :RA, 0.00, 0.00, 0.00, 0.00 2019-04-11T20:34:22.885Z,1555014862.885 [RDI_Pathfinder](ERROR): only read 3 of 4 data items 2019-04-11T20:34:22.885Z,1555014862.885 [RDI_Pathfinder](ERROR): Failed to parse: :RA, 0.00, 0.00, 0.00, 0.00 2019-04-11T20:34:47.538Z,1555014887.538 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:34:53.295Z,1555014893.295 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-04-11T20:34:53.295Z,1555014893.295 [Default:CheckIn:C.Wait] Stopped 2019-04-11T20:34:53.295Z,1555014893.295 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-04-11T20:34:53.295Z,1555014893.295 [Default:CheckIn:D] Running Loop=1 2019-04-11T20:34:53.597Z,1555014893.597 [Default:CheckIn:D] Stopped 2019-04-11T20:34:53.597Z,1555014893.597 [Default:CheckIn:E] Running Loop=1 2019-04-11T20:34:54.007Z,1555014894.007 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 105.445841 min 2019-04-11T20:34:54.007Z,1555014894.007 [Default:CheckIn:E] Stopped 2019-04-11T20:34:54.007Z,1555014894.007 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-04-11T20:34:54.007Z,1555014894.007 [Default:CheckIn] Stopped 2019-04-11T20:34:54.007Z,1555014894.007 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-04-11T20:34:54.008Z,1555014894.008 [Default:CheckIn](INFO): Running loop #18 2019-04-11T20:34:54.008Z,1555014894.008 [Default:CheckIn] Running Loop=18 2019-04-11T20:34:54.008Z,1555014894.008 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-04-11T20:34:54.008Z,1555014894.008 [Default:CheckIn:Read_GPS] Running Loop=1 2019-04-11T20:34:55.603Z,1555014895.603 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:34:57.633Z,1555014897.633 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:35:07.331Z,1555014907.331 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:35:17.426Z,1555014917.426 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:35:26.698Z,1555014926.698 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2019-04-11T20:35:26.779Z,1555014926.779 [NAL9602](FAULT): received: +CSQ:0 OK5,17,51,45,156,*48 OK 2019-04-11T20:35:26.779Z,1555014926.779 [NAL9602] Data Fault, FailCount= 2 2019-04-11T20:35:26.780Z,1555014926.780 [NAL9602](ERROR): Data Fault 2019-04-11T20:35:26.819Z,1555014926.819 [CBIT](ERROR): Data Fault in component: NAL9602 2019-04-11T20:35:27.099Z,1555014927.099 [NAL9602](INFO): Powering down 2019-04-11T20:35:27.526Z,1555014927.526 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:35:27.963Z,1555014927.963 [CBIT](INFO): Clearing failed state for component NAL9602 2019-04-11T20:35:27.963Z,1555014927.963 [NAL9602] No Fault, FailCount= 2 2019-04-11T20:35:37.629Z,1555014937.629 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:35:47.332Z,1555014947.332 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:35:57.408Z,1555014957.408 [NAL9602](INFO): Powering up NAL9602 2019-04-11T20:35:57.434Z,1555014957.434 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:36:07.119Z,1555014967.119 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:36:08.309Z,1555014968.309 [NAL9602](INFO): NAL9602 initialized 2019-04-11T20:36:09.118Z,1555014969.118 [NAL9602](FAULT): GPS failed to acquire within timeout. 2019-04-11T20:36:09.118Z,1555014969.118 [NAL9602] Data Fault, FailCount= 3 2019-04-11T20:36:09.118Z,1555014969.118 [NAL9602](ERROR): Data Fault 2019-04-11T20:36:09.150Z,1555014969.150 [CBIT](ERROR): Data Fault in component: NAL9602 2019-04-11T20:36:09.517Z,1555014969.517 [NAL9602](INFO): Powering down 2019-04-11T20:36:10.382Z,1555014970.382 [CBIT](INFO): Clearing failed state for component NAL9602 2019-04-11T20:36:10.382Z,1555014970.382 [NAL9602] No Fault, FailCount= 3 2019-04-11T20:36:17.227Z,1555014977.227 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:36:26.915Z,1555014986.915 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:36:37.009Z,1555014997.009 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:36:39.821Z,1555014999.821 [NAL9602](INFO): Powering up NAL9602 2019-04-11T20:36:47.117Z,1555015007.117 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:36:50.729Z,1555015010.729 [NAL9602](INFO): NAL9602 initialized 2019-04-11T20:36:51.547Z,1555015011.547 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:36:57.230Z,1555015017.230 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:37:06.916Z,1555015026.916 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:39:37.590Z,1555015177.590 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:39:47.693Z,1555015187.693 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:39:54.203Z,1555015194.203 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-04-11T20:34:54.0Z 2019-04-11T20:39:54.203Z,1555015194.203 [Default:CheckIn:Read_GPS] Stopped 2019-04-11T20:39:54.203Z,1555015194.203 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-04-11T20:39:57.802Z,1555015197.802 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:39:58.190Z,1555015198.190 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-04-11T20:40:00.011Z,1555015200.011 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190411T185732/Courier0048.lzma 2019-04-11T20:40:00.817Z,1555015200.817 [DataOverHttps](INFO): Moved sent file to Logs/20190411T185732/Courier0048.lzma.bak 2019-04-11T20:40:00.817Z,1555015200.817 [DataOverHttps](INFO): SBD MOMSN=10556847 2019-04-11T20:40:07.506Z,1555015207.506 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:40:12.570Z,1555015212.570 [DataOverHttps](INFO): Sending 1048 bytes from file Logs/20190411T185732/Express0049.lzma 2019-04-11T20:40:13.373Z,1555015213.373 [DataOverHttps](INFO): Moved sent file to Logs/20190411T185732/Express0049.lzma.bak 2019-04-11T20:40:13.373Z,1555015213.373 [DataOverHttps](INFO): SBD MOMSN=10556849 2019-04-11T20:40:13.966Z,1555015213.966 [Default:CheckIn:Read_Iridium] Stopped 2019-04-11T20:40:13.966Z,1555015213.966 [Default:CheckIn:C.Wait] Running Loop=1 2019-04-11T20:40:13.966Z,1555015213.966 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-04-11T20:40:17.589Z,1555015217.589 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:40:27.299Z,1555015227.299 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:40:28.885Z,1555015228.885 [NAL9602](INFO): Not Powering down - fast GPS 2019-04-11T20:40:36.983Z,1555015236.983 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:40:47.084Z,1555015247.084 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:40:56.780Z,1555015256.780 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:41:06.486Z,1555015266.486 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:41:16.577Z,1555015276.577 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:41:26.278Z,1555015286.278 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:41:35.968Z,1555015295.968 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:41:46.072Z,1555015306.072 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:41:56.187Z,1555015316.187 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:43:47.304Z,1555015427.304 [BPC1](ERROR): BPC1B: No match for serial number 1717 in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file). 2019-04-11T20:44:27.668Z,1555015467.668 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:44:37.769Z,1555015477.769 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:44:47.867Z,1555015487.867 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:44:57.965Z,1555015497.965 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:45:07.665Z,1555015507.665 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:45:14.546Z,1555015514.546 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-04-11T20:45:14.546Z,1555015514.546 [Default:CheckIn:C.Wait] Stopped 2019-04-11T20:45:14.546Z,1555015514.546 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-04-11T20:45:14.547Z,1555015514.547 [Default:CheckIn:D] Running Loop=1 2019-04-11T20:45:14.949Z,1555015514.949 [Default:CheckIn:D] Stopped 2019-04-11T20:45:14.949Z,1555015514.949 [Default:CheckIn:E] Running Loop=1 2019-04-11T20:45:15.370Z,1555015515.370 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 115.801701 min 2019-04-11T20:45:15.370Z,1555015515.370 [Default:CheckIn:E] Stopped 2019-04-11T20:45:15.371Z,1555015515.371 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-04-11T20:45:15.371Z,1555015515.371 [Default:CheckIn] Stopped 2019-04-11T20:45:15.371Z,1555015515.371 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-04-11T20:45:15.371Z,1555015515.371 [Default:CheckIn](INFO): Running loop #19 2019-04-11T20:45:15.371Z,1555015515.371 [Default:CheckIn] Running Loop=19 2019-04-11T20:45:15.371Z,1555015515.371 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-04-11T20:45:15.371Z,1555015515.371 [Default:CheckIn:Read_GPS] Running Loop=1 2019-04-11T20:45:16.955Z,1555015516.955 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:45:17.778Z,1555015517.778 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:45:27.468Z,1555015527.468 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:45:37.179Z,1555015537.179 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:45:47.281Z,1555015547.281 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:45:48.045Z,1555015548.045 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2019-04-11T20:45:48.120Z,1555015548.120 [NAL9602](FAULT): received: +CSQ:0 OK5,17,51,45,156,*48 OK 2019-04-11T20:45:48.120Z,1555015548.120 [NAL9602] Data Fault, FailCount= 4 2019-04-11T20:45:48.120Z,1555015548.120 [NAL9602](ERROR): Data Fault 2019-04-11T20:45:48.228Z,1555015548.228 [CBIT](ERROR): Data Fault in component: NAL9602 2019-04-11T20:45:48.449Z,1555015548.449 [NAL9602](INFO): Powering down 2019-04-11T20:45:49.391Z,1555015549.391 [CBIT](INFO): Clearing failed state for component NAL9602 2019-04-11T20:45:49.392Z,1555015549.392 [NAL9602] No Fault, FailCount= 4 2019-04-11T20:45:57.385Z,1555015557.385 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:46:07.049Z,1555015567.049 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:46:16.757Z,1555015576.757 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:46:18.754Z,1555015578.754 [NAL9602](INFO): Powering up NAL9602 2019-04-11T20:46:27.256Z,1555015587.256 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:46:29.661Z,1555015589.661 [NAL9602](INFO): NAL9602 initialized 2019-04-11T20:46:30.483Z,1555015590.483 [NAL9602](DEBUG): Fix Requested 2019-04-11T20:46:34.539Z,1555015594.539 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2019-04-11T20:46:34.539Z,1555015594.539 [RDI_Pathfinder](ERROR): Failed to parse: :TS,19041113551923,35.0, 0.0,1448.9, 0 2019-04-11T20:46:37.373Z,1555015597.373 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:46:47.049Z,1555015607.049 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:47:22.581Z,1555015642.581 [NAL9602](INFO): SBD MO Status=2, MOMSN=3509, MT Status=2, MTMSN=0 2019-04-11T20:47:22.581Z,1555015642.581 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-04-11T20:48:55.550Z,1555015735.550 [RDI_Pathfinder](ERROR): only read 3 of 4 data items 2019-04-11T20:48:55.550Z,1555015735.550 [RDI_Pathfinder](ERROR): Failed to parse: :RA, 0.00, 0.00, 0.00, 0.00 2019-04-11T20:49:19.367Z,1555015759.367 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:49:29.460Z,1555015769.460 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:49:39.562Z,1555015779.562 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:49:49.657Z,1555015789.657 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:49:56.158Z,1555015796.158 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude 2019-04-11T20:49:56.158Z,1555015796.158 [RDI_Pathfinder](ERROR): Failed to parse: :BD, +0.00, +0.00, , 0.00,6809.01 2019-04-11T20:49:59.759Z,1555015799.759 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:50:09.865Z,1555015809.865 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:50:15.536Z,1555015815.536 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-04-11T20:45:15.4Z 2019-04-11T20:50:15.536Z,1555015815.536 [Default:CheckIn:Read_GPS] Stopped 2019-04-11T20:50:15.536Z,1555015815.536 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-04-11T20:50:17.550Z,1555015817.550 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190411T185732/Courier0051.lzma 2019-04-11T20:50:18.249Z,1555015818.249 [DataOverHttps](INFO): Moved sent file to Logs/20190411T185732/Courier0051.lzma.bak 2019-04-11T20:50:18.249Z,1555015818.249 [DataOverHttps](INFO): SBD MOMSN=10557058 2019-04-11T20:50:19.336Z,1555015819.336 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-04-11T20:50:19.766Z,1555015819.766 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:50:29.849Z,1555015829.849 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:50:30.333Z,1555015830.333 [DataOverHttps](INFO): Sending 1139 bytes from file Logs/20190411T185732/Express0052.lzma 2019-04-11T20:50:31.137Z,1555015831.137 [DataOverHttps](INFO): Moved sent file to Logs/20190411T185732/Express0052.lzma.bak 2019-04-11T20:50:31.137Z,1555015831.137 [DataOverHttps](INFO): SBD MOMSN=10557060 2019-04-11T20:50:31.943Z,1555015831.943 [Default:CheckIn:Read_Iridium] Stopped 2019-04-11T20:50:31.943Z,1555015831.943 [Default:CheckIn:C.Wait] Running Loop=1 2019-04-11T20:50:31.943Z,1555015831.943 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-04-11T20:50:39.962Z,1555015839.962 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:50:49.661Z,1555015849.661 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:50:50.045Z,1555015850.045 [NAL9602](INFO): Not Powering down - fast GPS 2019-04-11T20:50:59.372Z,1555015859.372 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:51:09.462Z,1555015869.462 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:51:19.564Z,1555015879.564 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:51:29.656Z,1555015889.656 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:51:39.753Z,1555015899.753 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2019-04-11T20:51:57.160Z,1555015917.160 [RDI_Pathfinder](ERROR): only read 3 of 4 data items 2019-04-11T20:51:57.161Z,1555015917.161 [RDI_Pathfinder](ERROR): Failed to parse: :BS,-32768,-32768,-32768-32768,-32768,-32768,V 2019-04-11T20:52:54.579Z,1555015974.579 [BPC1](ERROR): BPC1B: No match for serial number 1717 in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file). 2019-04-11T20:53:18.345Z,1555015998.345 [RDI_Pathfinder](ERROR): Failed to parse: :TS,19041114020323,35.0, -0.1, 0.0,1448.9, 0 2019-04-11T20:53:30.468Z,1555016010.468 [BPC1](INFO): Calculating totals. Valid battery stick count: 52. Valid reserve battery stick count: 4. 2019-04-11T20:53:30.470Z,1555016010.470 [BPC1](ERROR): Failed to receive data from all sticks prior to timeout. Will not retry this scan cycle. 2019-04-11T20:54:18.530Z,1555016058.530 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2019-04-11T20:54:18.530Z,1555016058.530 [RDI_Pathfinder](ERROR): Failed to parse: :TS4030323,35.0, -0.1, 0.0,1448.9, 0 2019-04-11T20:55:32.485Z,1555016132.485 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-04-11T20:55:32.486Z,1555016132.486 [Default:CheckIn:C.Wait] Stopped 2019-04-11T20:55:32.486Z,1555016132.486 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-04-11T20:55:32.487Z,1555016132.487 [Default:CheckIn:D] Running Loop=1 2019-04-11T20:55:32.878Z,1555016132.878 [Default:CheckIn:D] Stopped 2019-04-11T20:55:32.878Z,1555016132.878 [Default:CheckIn:E] Running Loop=1 2019-04-11T20:55:33.294Z,1555016133.294 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 126.100529 min 2019-04-11T20:55:33.295Z,1555016133.295 [Default:CheckIn:E] Stopped 2019-04-11T20:55:33.295Z,1555016133.295 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-04-11T20:55:33.295Z,1555016133.295 [Default:CheckIn] Stopped 2019-04-11T20:55:33.295Z,1555016133.295 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-04-11T20:55:33.295Z,1555016133.295 [Default:CheckIn](INFO): Running loop #20 2019-04-11T20:55:33.295Z,1555016133.295 [Default:CheckIn] Running Loop=20 2019-04-11T20:55:33.295Z,1555016133.295 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-04-11T20:55:33.296Z,1555016133.296 [Default:CheckIn:Read_GPS] Running Loop=1 2019-04-11T20:55:34.866Z,1555016134.866 [NAL9602](FAULT): GPS failed to acquire within timeout. 2019-04-11T20:55:34.866Z,1555016134.866 [NAL9602] Data Fault, FailCount= 5 2019-04-11T20:55:34.866Z,1555016134.866 [NAL9602](ERROR): Data Fault 2019-04-11T20:55:34.903Z,1555016134.903 [CBIT](ERROR): Data Fault in component: NAL9602 2019-04-11T20:55:34.904Z,1555016134.904 [CBIT](CRITICAL): Data Fault in component: NAL9602 2019-04-11T20:55:35.269Z,1555016135.269 [NAL9602](INFO): Powering down 2019-04-11T20:55:35.310Z,1555016135.310 [CommandLine](FAULT): Scheduling is paused 2019-04-11T20:55:35.311Z,1555016135.311 [CBIT](INFO): Critical error at 20190411T205534 2019-04-11T20:57:34.903Z,1555016254.903 [CBIT](INFO): Clearing failed state for component NAL9602 2019-04-11T20:57:34.903Z,1555016254.903 [NAL9602] No Fault, FailCount= 5 2019-04-11T20:57:35.261Z,1555016255.261 [NAL9602](INFO): Powering up NAL9602 2019-04-11T20:57:46.167Z,1555016266.167 [NAL9602](INFO): NAL9602 initialized 2019-04-11T20:57:46.987Z,1555016266.987 [NAL9602](DEBUG): Fix Requested 2019-04-11T21:00:33.477Z,1555016433.477 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-04-11T20:55:33.3Z 2019-04-11T21:00:33.477Z,1555016433.477 [Default:CheckIn:Read_GPS] Stopped 2019-04-11T21:00:33.478Z,1555016433.478 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-04-11T21:00:35.672Z,1555016435.671 [DataOverHttps](INFO): Sending 236 bytes from file Logs/20190411T185732/Courier0054.lzma 2019-04-11T21:00:36.401Z,1555016436.401 [DataOverHttps](INFO): Moved sent file to Logs/20190411T185732/Courier0054.lzma.bak 2019-04-11T21:00:36.401Z,1555016436.401 [DataOverHttps](INFO): SBD MOMSN=10557200 2019-04-11T21:00:48.142Z,1555016448.142 [DataOverHttps](INFO): Sending 1046 bytes from file Logs/20190411T185732/Express0055.lzma 2019-04-11T21:00:48.933Z,1555016448.933 [DataOverHttps](INFO): Moved sent file to Logs/20190411T185732/Express0055.lzma.bak 2019-04-11T21:00:48.933Z,1555016448.933 [DataOverHttps](INFO): SBD MOMSN=10557203 2019-04-11T21:00:49.886Z,1555016449.886 [Default:CheckIn:Read_Iridium] Stopped 2019-04-11T21:00:49.886Z,1555016449.886 [Default:CheckIn:C.Wait] Running Loop=1 2019-04-11T21:00:49.886Z,1555016449.886 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-04-11T21:01:14.530Z,1555016474.530 [RDI_Pathfinder](ERROR): only read 3 of 4 data items 2019-04-11T21:01:14.530Z,1555016474.530 [RDI_Pathfinder](ERROR): Failed to parse: :RA, 0.00, 0.00, 0.00, 0.00 2019-04-11T21:02:33.289Z,1555016553.289 [RDI_Pathfinder](ERROR): only read 0 of 4 data items 2019-04-11T21:02:33.289Z,1555016553.289 [RDI_Pathfinder](ERROR): Failed to parse: :RA, 0.0064 2019-04-11T21:02:38.536Z,1555016558.536 [RDI_Pathfinder](ERROR): Failed to parse: :BE,-32768,-32768,-32768,V 2019-04-11T21:02:49.025Z,1555016569.025 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-04-11T21:03:19.725Z,1555016599.725 [NAL9602](INFO): Not Powering down - fast GPS 2019-04-11T21:03:37.146Z,1555016617.146 [RDI_Pathfinder](ERROR): Failed to parse: 68,-32768,-32768,V 2019-04-11T21:05:50.463Z,1555016750.463 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-04-11T21:05:50.463Z,1555016750.463 [Default:CheckIn:C.Wait] Stopped 2019-04-11T21:05:50.463Z,1555016750.463 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-04-11T21:05:50.464Z,1555016750.464 [Default:CheckIn:D] Running Loop=1 2019-04-11T21:05:50.854Z,1555016750.854 [Default:CheckIn:D] Stopped 2019-04-11T21:05:50.854Z,1555016750.854 [Default:CheckIn:E] Running Loop=1 2019-04-11T21:05:51.255Z,1555016751.255 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 136.400130 min 2019-04-11T21:05:51.268Z,1555016751.268 [Default:CheckIn:E] Stopped 2019-04-11T21:05:51.269Z,1555016751.269 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-04-11T21:05:51.269Z,1555016751.269 [Default:CheckIn] Stopped 2019-04-11T21:05:51.269Z,1555016751.269 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-04-11T21:05:51.269Z,1555016751.269 [Default:CheckIn](INFO): Running loop #21 2019-04-11T21:05:51.269Z,1555016751.269 [Default:CheckIn] Running Loop=21 2019-04-11T21:05:51.269Z,1555016751.269 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-04-11T21:05:51.269Z,1555016751.269 [Default:CheckIn:Read_GPS] Running Loop=1 2019-04-11T21:05:52.859Z,1555016752.859 [NAL9602](DEBUG): Fix Requested 2019-04-11T21:05:52.877Z,1555016752.877 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2019-04-11T21:05:52.877Z,1555016752.877 [RDI_Pathfinder](ERROR): Failed to parse: :TS,19041114143723,35.0, -0.1, 8.9, 0 2019-04-11T21:06:23.954Z,1555016783.954 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2019-04-11T21:06:24.031Z,1555016784.031 [NAL9602](FAULT): received: +CSQ:0 OK09, 2, 0, 0, 0 OK 2019-04-11T21:06:24.032Z,1555016784.032 [NAL9602] Data Fault, FailCount= 1 2019-04-11T21:06:24.032Z,1555016784.032 [NAL9602](ERROR): Data Fault 2019-04-11T21:06:24.071Z,1555016784.071 [CBIT](ERROR): Data Fault in component: NAL9602 2019-04-11T21:06:24.355Z,1555016784.355 [NAL9602](INFO): Powering down 2019-04-11T21:06:25.206Z,1555016785.206 [CBIT](INFO): Clearing failed state for component NAL9602 2019-04-11T21:06:25.206Z,1555016785.206 [NAL9602] No Fault, FailCount= 1 2019-04-11T21:06:54.657Z,1555016814.657 [NAL9602](INFO): Powering up NAL9602 2019-04-11T21:07:05.561Z,1555016825.561 [NAL9602](INFO): NAL9602 initialized 2019-04-11T21:07:06.383Z,1555016826.383 [NAL9602](DEBUG): Fix Requested 2019-04-11T21:09:20.555Z,1555016960.555 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2019-04-11T21:09:20.555Z,1555016960.555 [RDI_Pathfinder](ERROR): Failed to parse: :TS,19041114180523,35.0, -0.11448.9, 0 2019-04-11T21:10:17.134Z,1555017017.134 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2019-04-11T21:10:17.135Z,1555017017.135 [RDI_Pathfinder](ERROR): Failed to parse: :TS,19041114190223,35.0, -0.1, 0.0,1448:RA, 0.00, 0.00, 0.00, 0.00, 0.00 2019-04-11T21:10:51.480Z,1555017051.480 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-04-11T21:05:51.3Z 2019-04-11T21:10:51.480Z,1555017051.480 [Default:CheckIn:Read_GPS] Stopped 2019-04-11T21:10:51.481Z,1555017051.481 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-04-11T21:10:55.465Z,1555017055.465 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-04-11T21:10:57.395Z,1555017057.395 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190411T185732/Courier0057.lzma 2019-04-11T21:10:58.201Z,1555017058.201 [DataOverHttps](INFO): Moved sent file to Logs/20190411T185732/Courier0057.lzma.bak 2019-04-11T21:10:58.201Z,1555017058.201 [DataOverHttps](INFO): SBD MOMSN=10557315 2019-04-11T21:11:09.853Z,1555017069.853 [DataOverHttps](INFO): Sending 1021 bytes from file Logs/20190411T185732/Express0058.lzma 2019-04-11T21:11:10.657Z,1555017070.657 [DataOverHttps](INFO): Moved sent file to Logs/20190411T185732/Express0058.lzma.bak 2019-04-11T21:11:10.657Z,1555017070.657 [DataOverHttps](INFO): SBD MOMSN=10557317 2019-04-11T21:11:11.253Z,1555017071.253 [Default:CheckIn:Read_Iridium] Stopped 2019-04-11T21:11:11.253Z,1555017071.253 [Default:CheckIn:C.Wait] Running Loop=1 2019-04-11T21:11:11.253Z,1555017071.253 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-04-11T21:11:26.173Z,1555017086.173 [NAL9602](INFO): Not Powering down - fast GPS 2019-04-11T21:16:11.838Z,1555017371.838 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-04-11T21:16:11.838Z,1555017371.838 [Default:CheckIn:C.Wait] Stopped 2019-04-11T21:16:11.838Z,1555017371.838 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-04-11T21:16:11.838Z,1555017371.838 [Default:CheckIn:D] Running Loop=1 2019-04-11T21:16:12.242Z,1555017372.242 [Default:CheckIn:D] Stopped 2019-04-11T21:16:12.242Z,1555017372.242 [Default:CheckIn:E] Running Loop=1 2019-04-11T21:16:12.653Z,1555017372.653 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 146.756592 min 2019-04-11T21:16:12.653Z,1555017372.653 [Default:CheckIn:E] Stopped 2019-04-11T21:16:12.653Z,1555017372.653 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-04-11T21:16:12.653Z,1555017372.653 [Default:CheckIn] Stopped 2019-04-11T21:16:12.653Z,1555017372.653 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-04-11T21:16:12.653Z,1555017372.653 [Default:CheckIn](INFO): Running loop #22 2019-04-11T21:16:12.653Z,1555017372.653 [Default:CheckIn] Running Loop=22 2019-04-11T21:16:12.654Z,1555017372.654 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-04-11T21:16:12.654Z,1555017372.654 [Default:CheckIn:Read_GPS] Running Loop=1 2019-04-11T21:16:14.227Z,1555017374.227 [NAL9602](FAULT): GPS failed to acquire within timeout. 2019-04-11T21:16:14.227Z,1555017374.227 [NAL9602] Data Fault, FailCount= 2 2019-04-11T21:16:14.227Z,1555017374.227 [NAL9602](ERROR): Data Fault 2019-04-11T21:16:14.269Z,1555017374.269 [CBIT](ERROR): Data Fault in component: NAL9602 2019-04-11T21:16:14.625Z,1555017374.625 [NAL9602](INFO): Powering down 2019-04-11T21:16:15.484Z,1555017375.484 [CBIT](INFO): Clearing failed state for component NAL9602 2019-04-11T21:16:15.484Z,1555017375.484 [NAL9602] No Fault, FailCount= 2 2019-04-11T21:16:44.929Z,1555017404.929 [NAL9602](INFO): Powering up NAL9602 2019-04-11T21:16:55.838Z,1555017415.838 [NAL9602](INFO): NAL9602 initialized 2019-04-11T21:16:56.659Z,1555017416.659 [NAL9602](DEBUG): Fix Requested 2019-04-11T21:18:23.543Z,1555017503.543 [RDI_Pathfinder](ERROR): Failed to parse: :BE,-32768,-32768,-32768,V 2019-04-11T21:20:04.153Z,1555017604.153 [RDI_Pathfinder](ERROR): only read 3 of 4 data items 2019-04-11T21:20:04.154Z,1555017604.154 [RDI_Pathfinder](ERROR): Failed to parse: :BS,-32768,-32768,-3:BE,-32768,-32768,-32768,V 2019-04-11T21:21:12.845Z,1555017672.845 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-04-11T21:16:12.7Z 2019-04-11T21:21:12.845Z,1555017672.845 [Default:CheckIn:Read_GPS] Stopped 2019-04-11T21:21:12.846Z,1555017672.846 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-04-11T21:21:14.407Z,1555017674.407 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190411T185732/Courier0060.lzma 2019-04-11T21:21:15.141Z,1555017675.141 [DataOverHttps](INFO): Moved sent file to Logs/20190411T185732/Courier0060.lzma.bak 2019-04-11T21:21:15.141Z,1555017675.141 [DataOverHttps](INFO): SBD MOMSN=10557409 2019-04-11T21:21:20.692Z,1555017680.692 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2019-04-11T21:21:20.693Z,1555017680.693 [RDI_Pathfinder](ERROR): Failed to parse: :TS,19041114300523,35.0, -0.1, .9, 0 2019-04-11T21:21:26.665Z,1555017686.665 [DataOverHttps](INFO): Sending 1148 bytes from file Logs/20190411T185732/Express0061.lzma 2019-04-11T21:21:27.469Z,1555017687.469 [DataOverHttps](INFO): Moved sent file to Logs/20190411T185732/Express0061.lzma.bak 2019-04-11T21:21:27.469Z,1555017687.469 [DataOverHttps](INFO): SBD MOMSN=10557411 2019-04-11T21:21:28.367Z,1555017688.367 [Default:CheckIn:Read_Iridium] Stopped 2019-04-11T21:21:28.367Z,1555017688.367 [Default:CheckIn:C.Wait] Running Loop=1 2019-04-11T21:21:28.367Z,1555017688.367 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-04-11T21:21:59.037Z,1555017719.037 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-04-11T21:22:29.742Z,1555017749.742 [NAL9602](INFO): Not Powering down - fast GPS 2019-04-11T21:23:04.507Z,1555017784.507 [RDI_Pathfinder](ERROR): Failed to parse: :BE,-32768,-32768,-32768,V 2019-04-11T21:24:45.503Z,1555017885.503 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2019-04-11T21:24:45.503Z,1555017885.503 [RDI_Pathfinder](ERROR): Failed to parse: :TS,19041114333023,35.0, -0.1, 0.0,14 2019-04-11T21:26:28.936Z,1555017988.936 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-04-11T21:26:28.936Z,1555017988.936 [Default:CheckIn:C.Wait] Stopped 2019-04-11T21:26:28.936Z,1555017988.936 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-04-11T21:26:28.936Z,1555017988.936 [Default:CheckIn:D] Running Loop=1 2019-04-11T21:26:29.394Z,1555017989.394 [Default:CheckIn:D] Stopped 2019-04-11T21:26:29.394Z,1555017989.394 [Default:CheckIn:E] Running Loop=1 2019-04-11T21:26:29.743Z,1555017989.743 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 157.042448 min 2019-04-11T21:26:29.743Z,1555017989.743 [Default:CheckIn:E] Stopped 2019-04-11T21:26:29.743Z,1555017989.743 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-04-11T21:26:29.743Z,1555017989.743 [Default:CheckIn] Stopped 2019-04-11T21:26:29.743Z,1555017989.743 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-04-11T21:26:29.743Z,1555017989.743 [Default:CheckIn](INFO): Running loop #23 2019-04-11T21:26:29.743Z,1555017989.743 [Default:CheckIn] Running Loop=23 2019-04-11T21:26:29.744Z,1555017989.744 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-04-11T21:26:29.744Z,1555017989.744 [Default:CheckIn:Read_GPS] Running Loop=1 2019-04-11T21:26:31.355Z,1555017991.355 [NAL9602](DEBUG): Fix Requested 2019-04-11T21:27:02.485Z,1555018022.485 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2019-04-11T21:27:02.559Z,1555018022.559 [NAL9602](FAULT): received: +CSQ:0 OK09, 2, 0, 0, 0 OK 2019-04-11T21:27:02.559Z,1555018022.559 [NAL9602] Data Fault, FailCount= 3 2019-04-11T21:27:02.559Z,1555018022.559 [NAL9602](ERROR): Data Fault 2019-04-11T21:27:02.644Z,1555018022.644 [CBIT](ERROR): Data Fault in component: NAL9602 2019-04-11T21:27:02.869Z,1555018022.869 [NAL9602](INFO): Powering down 2019-04-11T21:27:03.688Z,1555018023.688 [CBIT](INFO): Clearing failed state for component NAL9602 2019-04-11T21:27:03.688Z,1555018023.688 [NAL9602] No Fault, FailCount= 3 2019-04-11T21:27:33.153Z,1555018053.153 [NAL9602](INFO): Powering up NAL9602 2019-04-11T21:27:44.052Z,1555018064.052 [NAL9602](INFO): NAL9602 initialized 2019-04-11T21:27:44.860Z,1555018064.860 [NAL9602](FAULT): GPS failed to acquire within timeout. 2019-04-11T21:27:44.860Z,1555018064.860 [NAL9602] Data Fault, FailCount= 4 2019-04-11T21:27:44.860Z,1555018064.860 [NAL9602](ERROR): Data Fault 2019-04-11T21:27:44.925Z,1555018064.925 [CBIT](ERROR): Data Fault in component: NAL9602 2019-04-11T21:27:45.263Z,1555018065.263 [NAL9602](INFO): Powering down 2019-04-11T21:27:46.152Z,1555018066.152 [CBIT](INFO): Clearing failed state for component NAL9602 2019-04-11T21:27:46.152Z,1555018066.152 [NAL9602] No Fault, FailCount= 4 2019-04-11T21:27:46.493Z,1555018066.493 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2019-04-11T21:27:46.493Z,1555018066.493 [RDI_Pathfinder](ERROR): Failed to parse: :TS,19041114363123,35.0, -0.1, .9, 0 2019-04-11T21:28:15.569Z,1555018095.569 [NAL9602](INFO): Powering up NAL9602 2019-04-11T21:28:26.471Z,1555018106.471 [NAL9602](INFO): NAL9602 initialized 2019-04-11T21:28:27.299Z,1555018107.299 [NAL9602](DEBUG): Fix Requested 2019-04-11T21:28:28.521Z,1555018108.521 [RDI_Pathfinder](ERROR): only read 2 of 4 data items 2019-04-11T21:28:28.521Z,1555018108.521 [RDI_Pathfinder](ERROR): Failed to parse: :BS,-32768,-32768, 2019-04-11T21:29:21.849Z,1555018161.849 [RDI_Pathfinder](ERROR): Failed to parse: :0, 0.00, 0.00, 0.00, 0.00 2019-04-11T21:31:08.519Z,1555018268.519 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2019-04-11T21:31:08.519Z,1555018268.519 [RDI_Pathfinder](ERROR): Failed to parse: :TS4395323,35.0, -0.1, 0.0,1448.9, 0 2019-04-11T21:31:29.922Z,1555018289.922 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-04-11T21:26:29.7Z 2019-04-11T21:31:29.923Z,1555018289.923 [Default:CheckIn:Read_GPS] Stopped 2019-04-11T21:31:29.923Z,1555018289.923 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-04-11T21:31:33.966Z,1555018293.966 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-04-11T21:31:35.543Z,1555018295.543 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190411T185732/Courier0063.lzma 2019-04-11T21:31:36.349Z,1555018296.349 [DataOverHttps](INFO): Moved sent file to Logs/20190411T185732/Courier0063.lzma.bak 2019-04-11T21:31:36.349Z,1555018296.349 [DataOverHttps](INFO): SBD MOMSN=10557500 2019-04-11T21:31:47.534Z,1555018307.534 [DataOverHttps](INFO): Sending 1072 bytes from file Logs/20190411T185732/Express0064.lzma 2019-04-11T21:31:48.337Z,1555018308.337 [DataOverHttps](INFO): Moved sent file to Logs/20190411T185732/Express0064.lzma.bak 2019-04-11T21:31:48.337Z,1555018308.337 [DataOverHttps](INFO): SBD MOMSN=10557502 2019-04-11T21:31:48.936Z,1555018308.936 [Default:CheckIn:Read_Iridium] Stopped 2019-04-11T21:31:48.936Z,1555018308.936 [Default:CheckIn:C.Wait] Running Loop=1 2019-04-11T21:31:48.936Z,1555018308.936 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-04-11T21:32:04.670Z,1555018324.670 [NAL9602](INFO): Not Powering down - fast GPS 2019-04-11T21:33:08.521Z,1555018388.521 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2019-04-11T21:33:08.521Z,1555018388.521 [RDI_Pathfinder](ERROR): Failed to parse: :TS,19041114415323,35.0, -0.1, 0.0,1448.9,, 0.00, 0.00, 0.00, 0.00, 0.00 2019-04-11T21:33:21.855Z,1555018401.855 [RDI_Pathfinder](ERROR): Failed to parse: :BE,-32768,-32768,-32768,V 2019-04-11T21:33:51.768Z,1555018431.768 [RDI_Pathfinder](ERROR): Failed to parse: :SA, +0.00, +0.00, 0.00 2019-04-11T21:34:22.855Z,1555018462.855 [RDI_Pathfinder](ERROR): Failed to parse: :BE,-32768,-32768,-32768,V 2019-04-11T21:35:02.856Z,1555018502.856 [RDI_Pathfinder](ERROR): only read 3 of 4 data items 2019-04-11T21:35:02.857Z,1555018502.857 [RDI_Pathfinder](ERROR): Failed to parse: :RA, 0.00, 0.00, 0.00, 0.00 2019-04-11T21:36:49.542Z,1555018609.542 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-04-11T21:36:49.542Z,1555018609.542 [Default:CheckIn:C.Wait] Stopped 2019-04-11T21:36:49.542Z,1555018609.542 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-04-11T21:36:49.543Z,1555018609.543 [Default:CheckIn:D] Running Loop=1 2019-04-11T21:36:49.920Z,1555018609.920 [Default:CheckIn:D] Stopped 2019-04-11T21:36:49.920Z,1555018609.920 [Default:CheckIn:E] Running Loop=1 2019-04-11T21:36:50.339Z,1555018610.339 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 167.384554 min 2019-04-11T21:36:50.340Z,1555018610.340 [Default:CheckIn:E] Stopped 2019-04-11T21:36:50.340Z,1555018610.340 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-04-11T21:36:50.340Z,1555018610.340 [Default:CheckIn] Stopped 2019-04-11T21:36:50.340Z,1555018610.340 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-04-11T21:36:50.340Z,1555018610.340 [Default:CheckIn](INFO): Running loop #24 2019-04-11T21:36:50.340Z,1555018610.340 [Default:CheckIn] Running Loop=24 2019-04-11T21:36:50.340Z,1555018610.340 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-04-11T21:36:50.340Z,1555018610.340 [Default:CheckIn:Read_GPS] Running Loop=1 2019-04-11T21:36:51.927Z,1555018611.927 [NAL9602](DEBUG): Fix Requested 2019-04-11T21:41:50.533Z,1555018910.533 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-04-11T21:36:50.3Z 2019-04-11T21:41:50.533Z,1555018910.533 [Default:CheckIn:Read_GPS] Stopped 2019-04-11T21:41:50.533Z,1555018910.533 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-04-11T21:41:52.588Z,1555018912.588 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190411T185732/Courier0066.lzma 2019-04-11T21:41:53.325Z,1555018913.325 [DataOverHttps](INFO): Moved sent file to Logs/20190411T185732/Courier0066.lzma.bak 2019-04-11T21:41:53.325Z,1555018913.325 [DataOverHttps](INFO): SBD MOMSN=10557597 2019-04-11T21:41:54.269Z,1555018914.269 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-04-11T21:42:04.700Z,1555018924.700 [DataOverHttps](INFO): Sending 975 bytes from file Logs/20190411T185732/Express0067.lzma 2019-04-11T21:42:05.505Z,1555018925.505 [DataOverHttps](INFO): Moved sent file to Logs/20190411T185732/Express0067.lzma.bak 2019-04-11T21:42:05.505Z,1555018925.505 [DataOverHttps](INFO): SBD MOMSN=10557599 2019-04-11T21:42:06.460Z,1555018926.460 [Default:CheckIn:Read_Iridium] Stopped 2019-04-11T21:42:06.460Z,1555018926.460 [Default:CheckIn:C.Wait] Running Loop=1 2019-04-11T21:42:06.460Z,1555018926.460 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-04-11T21:42:24.973Z,1555018944.973 [NAL9602](INFO): Not Powering down - fast GPS 2019-04-11T21:46:52.862Z,1555019212.862 [RDI_Pathfinder](ERROR): only read 2 of 4 data items 2019-04-11T21:46:52.862Z,1555019212.862 [RDI_Pathfinder](ERROR): Failed to parse: :RA, 0.00, 0.00, 0.00, BI-32768,-32768,-32768,V 2019-04-11T21:47:06.988Z,1555019226.988 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-04-11T21:47:06.988Z,1555019226.988 [Default:CheckIn:C.Wait] Stopped 2019-04-11T21:47:06.988Z,1555019226.988 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-04-11T21:47:06.988Z,1555019226.988 [Default:CheckIn:D] Running Loop=1 2019-04-11T21:47:07.402Z,1555019227.402 [Default:CheckIn:D] Stopped 2019-04-11T21:47:07.402Z,1555019227.402 [Default:CheckIn:E] Running Loop=1 2019-04-11T21:47:07.799Z,1555019227.799 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 177.675911 min 2019-04-11T21:47:07.799Z,1555019227.799 [Default:CheckIn:E] Stopped 2019-04-11T21:47:07.799Z,1555019227.799 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-04-11T21:47:07.799Z,1555019227.799 [Default:CheckIn] Stopped 2019-04-11T21:47:07.799Z,1555019227.799 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-04-11T21:47:07.799Z,1555019227.799 [Default:CheckIn](INFO): Running loop #25 2019-04-11T21:47:07.799Z,1555019227.799 [Default:CheckIn] Running Loop=25 2019-04-11T21:47:07.800Z,1555019227.800 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-04-11T21:47:07.800Z,1555019227.800 [Default:CheckIn:Read_GPS] Running Loop=1 2019-04-11T21:47:09.390Z,1555019229.390 [NAL9602](FAULT): GPS failed to acquire within timeout. 2019-04-11T21:47:09.390Z,1555019229.390 [NAL9602] Data Fault, FailCount= 5 2019-04-11T21:47:09.390Z,1555019229.390 [NAL9602](ERROR): Data Fault 2019-04-11T21:47:09.483Z,1555019229.483 [CBIT](ERROR): Data Fault in component: NAL9602 2019-04-11T21:47:09.484Z,1555019229.484 [CBIT](CRITICAL): Data Fault in component: NAL9602 2019-04-11T21:47:09.788Z,1555019229.788 [NAL9602](INFO): Powering down 2019-04-11T21:47:09.818Z,1555019229.818 [CBIT](INFO): Critical error at 20190411T214709 2019-04-11T21:47:17.493Z,1555019237.493 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2019-04-11T21:47:17.493Z,1555019237.493 [RDI_Pathfinder](ERROR): Failed to parse: :TS,19041114560223,35.0, -0.1, 0.0,10 2019-04-11T21:49:09.415Z,1555019349.415 [CBIT](INFO): Clearing failed state for component NAL9602 2019-04-11T21:49:09.415Z,1555019349.415 [NAL9602] No Fault, FailCount= 5 2019-04-11T21:49:09.777Z,1555019349.777 [NAL9602](INFO): Powering up NAL9602 2019-04-11T21:49:20.694Z,1555019360.694 [NAL9602](INFO): NAL9602 initialized 2019-04-11T21:49:21.511Z,1555019361.511 [NAL9602](DEBUG): Fix Requested 2019-04-11T21:50:52.823Z,1555019452.823 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2019-04-11T21:50:52.823Z,1555019452.823 [RDI_Pathfinder](ERROR): Failed to parse: :TS,19041114593723,35. 0.0,1448.9, 0 2019-04-11T21:52:07.977Z,1555019527.977 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-04-11T21:47:07.8Z 2019-04-11T21:52:07.977Z,1555019527.977 [Default:CheckIn:Read_GPS] Stopped 2019-04-11T21:52:07.978Z,1555019527.978 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-04-11T21:52:13.299Z,1555019533.299 [DataOverHttps](INFO): Sending 69 bytes from file Logs/20190411T185732/Courier0069.lzma 2019-04-11T21:52:14.115Z,1555019534.115 [DataOverHttps](INFO): Moved sent file to Logs/20190411T185732/Courier0069.lzma.bak 2019-04-11T21:52:14.116Z,1555019534.116 [DataOverHttps](INFO): SBD MOMSN=10557686 2019-04-11T21:52:25.705Z,1555019545.705 [DataOverHttps](INFO): Sending 1072 bytes from file Logs/20190411T185732/Express0070.lzma 2019-04-11T21:52:26.509Z,1555019546.509 [DataOverHttps](INFO): Moved sent file to Logs/20190411T185732/Express0070.lzma.bak 2019-04-11T21:52:26.509Z,1555019546.509 [DataOverHttps](INFO): SBD MOMSN=10557689 2019-04-11T21:52:27.391Z,1555019547.391 [Default:CheckIn:Read_Iridium] Stopped 2019-04-11T21:52:27.391Z,1555019547.391 [Default:CheckIn:C.Wait] Running Loop=1 2019-04-11T21:52:27.391Z,1555019547.391 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-04-11T21:52:58.908Z,1555019578.908 [CommandLine](IMPORTANT): got command quit 2019-04-11T21:52:59.916Z,1555019579.916 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2019-04-11T21:52:59.916Z,1555019579.916 [CommandLine ThreadHandler](INFO): Thread cancelled. 2019-04-11T21:52:59.995Z,1555019579.995 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2019-04-11T21:52:59.995Z,1555019579.995 [CommandLine ThreadHandler](INFO): Thread cancelled. 2019-04-11T21:52:59.996Z,1555019579.996 [CommandLine](INFO): Join timeout helper Thread ID is 8318 2019-04-11T21:52:59.997Z,1555019579.997 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2019-04-11T21:52:59.997Z,1555019579.997 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2019-04-11T21:52:59.997Z,1555019579.997 [NavChartDb](INFO): Join timeout helper Thread ID is 8319 2019-04-11T21:53:00.212Z,1555019580.212 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2019-04-11T21:53:00.212Z,1555019580.212 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2019-04-11T21:53:00.228Z,1555019580.228 [ComponentRegistry](INFO): Shutting down WetLabsSeaOWL_UV_A ThreadHandler 2019-04-11T21:53:00.228Z,1555019580.228 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled. 2019-04-11T21:53:00.229Z,1555019580.229 [WetLabsSeaOWL_UV_A](INFO): Join timeout helper Thread ID is 8320 2019-04-11T21:53:00.623Z,1555019580.623 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Uninitializing protected caller thread. 2019-04-11T21:53:00.624Z,1555019580.624 [WetLabsSeaOWL_UV_A](INFO): Powering down 2019-04-11T21:53:00.624Z,1555019580.624 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled. 2019-04-11T21:53:00.639Z,1555019580.639 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler 2019-04-11T21:53:00.639Z,1555019580.639 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled. 2019-04-11T21:53:00.640Z,1555019580.640 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 8321 2019-04-11T21:53:00.800Z,1555019580.800 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread. 2019-04-11T21:53:00.800Z,1555019580.800 [CTD_NeilBrown](INFO): Powering down 2019-04-11T21:53:00.811Z,1555019580.811 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled. 2019-04-11T21:53:00.827Z,1555019580.827 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2019-04-11T21:53:00.827Z,1555019580.827 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2019-04-11T21:53:00.828Z,1555019580.828 [Radio_Surface](INFO): Join timeout helper Thread ID is 8322 2019-04-11T21:53:00.859Z,1555019580.859 [Radio_Surface](INFO): Powering down 2019-04-11T21:53:00.860Z,1555019580.860 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2019-04-11T21:53:00.861Z,1555019580.861 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2019-04-11T21:53:00.868Z,1555019580.868 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler 2019-04-11T21:53:00.868Z,1555019580.868 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2019-04-11T21:53:00.869Z,1555019580.869 [DataOverHttps](INFO): Join timeout helper Thread ID is 8323 2019-04-11T21:53:01.219Z,1555019581.219 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread. 2019-04-11T21:53:01.220Z,1555019581.220 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2019-04-11T21:53:01.228Z,1555019581.228 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2019-04-11T21:53:01.228Z,1555019581.228 [logger ThreadHandler](INFO): Thread cancelled. 2019-04-11T21:53:01.229Z,1555019581.229 [logger](INFO): Join timeout helper Thread ID is 8324 2019-04-11T21:53:01.239Z,1555019581.239 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2019-04-11T21:53:01.240Z,1555019581.240 [logger ThreadHandler](INFO): Thread cancelled. 2019-04-11T21:53:01.248Z,1555019581.248 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2019-04-11T21:53:01.248Z,1555019581.248 [CommandLine ThreadHandler](INFO): Thread cancelled. 2019-04-11T21:53:01.248Z,1555019581.248 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2019-04-11T21:53:01.248Z,1555019581.248 [controlThread ThreadHandler](INFO): Thread cancelled. 2019-04-11T21:53:01.249Z,1555019581.249 [controlThread](INFO): Join timeout helper Thread ID is 8325 2019-04-11T21:53:01.271Z,1555019581.271 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2019-04-11T21:53:01.272Z,1555019581.272 [controlThread](DEBUG): Uninitializing ControlThread 2019-04-11T21:53:01.272Z,1555019581.272 [AHRS_M2](INFO): Powering down 2019-04-11T21:53:01.344Z,1555019581.344 [DUSBL_Hydroid](INFO): Powering down 2019-04-11T21:53:01.416Z,1555019581.416 [Micromodem](INFO): Powering down 2019-04-11T21:53:01.512Z,1555019581.512 [NAL9602](INFO): Powering down 2019-04-11T21:53:01.583Z,1555019581.583 [RDI_Pathfinder](INFO): Powering down 2019-04-11T21:53:01.585Z,1555019581.585 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator. 2019-04-11T21:53:01.586Z,1555019581.586 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator. 2019-04-11T21:53:01.586Z,1555019581.586 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2019-04-11T21:53:01.587Z,1555019581.587 [MissionManager](INFO): Uninitializing Mission Default 2019-04-11T21:53:01.587Z,1555019581.587 [Default] Stopped 2019-04-11T21:53:01.587Z,1555019581.587 [Default](DEBUG): Aggregate::uninitialize Default 2019-04-11T21:53:01.587Z,1555019581.587 [Default:B.GoToSurface] Stopped 2019-04-11T21:53:01.587Z,1555019581.587 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2019-04-11T21:53:01.587Z,1555019581.587 [Default:CheckIn] Stopped 2019-04-11T21:53:01.587Z,1555019581.587 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-04-11T21:53:01.587Z,1555019581.587 [Default:CheckIn:C.Wait] Stopped 2019-04-11T21:53:01.587Z,1555019581.587 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-04-11T21:53:01.590Z,1555019581.590 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2019-04-11T21:53:01.590Z,1555019581.590 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2019-04-11T21:53:01.590Z,1555019581.590 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2019-04-11T21:53:01.591Z,1555019581.591 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2019-04-11T21:53:01.591Z,1555019581.591 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2019-04-11T21:53:01.591Z,1555019581.591 [BuoyancyServo](INFO): Powering down 2019-04-11T21:53:01.603Z,1555019581.603 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2019-04-11T21:53:01.603Z,1555019581.603 [ElevatorServo](INFO): Powering down 2019-04-11T21:53:01.604Z,1555019581.604 [MassServo](DEBUG): Uninitialize Mass Servo. 2019-04-11T21:53:01.604Z,1555019581.604 [MassServo](INFO): Powering down 2019-04-11T21:53:01.605Z,1555019581.605 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2019-04-11T21:53:01.605Z,1555019581.605 [RudderServo](INFO): Powering down 2019-04-11T21:53:01.606Z,1555019581.606 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2019-04-11T21:53:01.606Z,1555019581.606 [ThrusterServo](INFO): Powering down 2019-04-11T21:53:01.607Z,1555019581.607 [SBIT](DEBUG): Uninitialize SBIT Component. 2019-04-11T21:53:01.607Z,1555019581.607 [IBIT](DEBUG): Uninitialize IBIT Component. 2019-04-11T21:53:01.608Z,1555019581.608 [CBIT](DEBUG): Uninitialize CBIT Component. 2019-04-11T21:53:01.608Z,1555019581.608 [CBIT](DEBUG): Powering off loads. 2019-04-11T21:53:01.619Z,1555019581.619 [CBIT](DEBUG): Disabling WDT. 2019-04-11T21:53:01.631Z,1555019581.631 [CBIT](DEBUG): Opening all GF detection circuits. 2019-04-11T21:53:01.632Z,1555019581.632 [controlThread ThreadHandler](INFO): Thread cancelled. 2019-04-11T21:53:01.686Z,1555019581.686 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2019-04-11T21:53:01.695Z,1555019581.695 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2019-04-11T21:53:01.734Z,1555019581.734 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled. 2019-04-11T21:53:01.736Z,1555019581.736 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled. 2019-04-11T21:53:01.790Z,1555019581.790 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2019-04-11T21:53:01.859Z,1555019581.859 [logger ThreadHandler](INFO): Thread cancelled.