2020-01-06T19:54:38.906Z,1578340478.906 [CommandLine](IMPORTANT): got command restart logs 2020-01-06T19:54:40.839Z,1578340480.839 [DataOverHttps](INFO): Moved sent file to Logs/20200106T184918/Courier0027.lzma.bak 2020-01-06T19:54:40.839Z,1578340480.839 [DataOverHttps](INFO): SBD MOMSN=12185452 2020-01-06T19:55:08.710Z,1578340508.710 [NAL9602](INFO): Not Powering down - fast GPS 2020-01-06T19:55:43.122Z,1578340543.122 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2020-01-06T19:56:14.246Z,1578340574.246 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2020-01-06T19:56:45.378Z,1578340605.378 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2020-01-06T19:57:16.506Z,1578340636.506 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2020-01-06T19:57:41.606Z,1578340661.606 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.767380 2020-01-06T19:58:12.750Z,1578340692.750 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2020-01-06T19:58:23.904Z,1578340703.904 [NAL9602](INFO): SBD MO Status=2, MOMSN=18943, MT Status=2, MTMSN=0 2020-01-06T19:58:23.904Z,1578340703.904 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2020-01-06T19:58:43.874Z,1578340723.874 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2020-01-06T19:58:54.256Z,1578340734.256 [NAL9602](INFO): SBD MO Status=2, MOMSN=18943, MT Status=2, MTMSN=0 2020-01-06T19:58:54.256Z,1578340734.256 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2020-01-06T19:59:14.997Z,1578340754.997 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2020-01-06T19:59:29.449Z,1578340769.449 [NAL9602](INFO): SBD MO Status=1, MOMSN=18943, MT Status=0, MTMSN=0 2020-01-06T19:59:29.502Z,1578340769.502 [NAL9602](INFO): Sent 25 bytes from file Logs/20200106T184918/Courier0030.lzma 2020-01-06T19:59:29.502Z,1578340769.502 [NAL9602](INFO): Packets left to send: 0 2020-01-06T19:59:40.415Z,1578340780.415 [NAL9602](INFO): SBD MO Status=1, MOMSN=18944, MT Status=0, MTMSN=0 2020-01-06T19:59:40.478Z,1578340780.478 [NAL9602](INFO): Sent 25 bytes from file Logs/20200106T195438/Courier0000.lzma 2020-01-06T19:59:40.478Z,1578340780.478 [NAL9602](INFO): Packets left to send: 0 2020-01-06T19:59:46.134Z,1578340786.134 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2020-01-06T19:59:50.588Z,1578340790.588 [NAL9602](INFO): SBD MO Status=1, MOMSN=18945, MT Status=0, MTMSN=0 2020-01-06T19:59:50.638Z,1578340790.638 [NAL9602](INFO): Sent 132 bytes from file Logs/20200106T184918/Express0028.lzma 2020-01-06T19:59:50.638Z,1578340790.638 [NAL9602](INFO): Packets left to send: 0 2020-01-06T20:00:01.579Z,1578340801.579 [NAL9602](INFO): SBD MO Status=2, MOMSN=18946, MT Status=2, MTMSN=0 2020-01-06T20:00:01.580Z,1578340801.580 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2020-01-06T20:00:17.266Z,1578340817.266 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2020-01-06T20:00:22.248Z,1578340822.248 [NAL9602](INFO): SBD MO Status=1, MOMSN=18946, MT Status=0, MTMSN=0 2020-01-06T20:00:22.298Z,1578340822.298 [NAL9602](INFO): Sent 96 bytes from file Logs/20200106T184918/Express0031.lzma 2020-01-06T20:00:22.298Z,1578340822.298 [NAL9602](INFO): Packets left to send: 0 2020-01-06T20:00:43.723Z,1578340843.723 [NAL9602](INFO): SBD MO Status=1, MOMSN=18947, MT Status=0, MTMSN=0 2020-01-06T20:00:43.782Z,1578340843.782 [NAL9602](INFO): Sent 25 bytes from file Logs/20200106T195438/Express0001.lzma 2020-01-06T20:00:43.782Z,1578340843.782 [NAL9602](INFO): Packets left to send: 0 2020-01-06T20:00:48.410Z,1578340848.410 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2020-01-06T20:01:00.675Z,1578340860.675 [NAL9602](INFO): SBD MO Status=2, MOMSN=18948, MT Status=2, MTMSN=0 2020-01-06T20:01:00.676Z,1578340860.676 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2020-01-06T20:01:05.639Z,1578340865.639 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2020-01-06T20:01:07.670Z,1578340867.670 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2020-01-06T20:01:11.703Z,1578340871.703 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2020-01-06T20:01:19.534Z,1578340879.534 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2020-01-06T20:01:19.782Z,1578340879.782 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2020-01-06T20:01:28.271Z,1578340888.271 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2020-01-06T20:01:36.756Z,1578340896.756 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2020-01-06T20:01:45.252Z,1578340905.252 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2020-01-06T20:01:47.668Z,1578340907.668 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2020-01-06T20:01:50.658Z,1578340910.658 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2020-01-06T20:01:54.122Z,1578340914.122 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2020-01-06T20:02:02.609Z,1578340922.609 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2020-01-06T20:02:05.031Z,1578340925.031 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2020-01-06T20:02:21.782Z,1578340941.782 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2020-01-06T20:02:23.088Z,1578340943.088 [NAL9602](INFO): SBD MO Status=2, MOMSN=18948, MT Status=2, MTMSN=0 2020-01-06T20:02:23.088Z,1578340943.088 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2020-01-06T20:02:40.862Z,1578340960.862 [NAL9602](INFO): SBD MO Status=0, MOMSN=18948, MT Status=0, MTMSN=0 2020-01-06T20:02:40.956Z,1578340960.956 [Default:CheckIn:Read_Iridium] Stopped 2020-01-06T20:02:40.957Z,1578340960.957 [Default:CheckIn:C.Wait] Running Loop=1 2020-01-06T20:02:40.957Z,1578340960.957 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-01-06T20:02:52.906Z,1578340972.906 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2020-01-06T20:03:11.570Z,1578340991.570 [NAL9602](INFO): Not Powering down - fast GPS 2020-01-06T20:03:24.029Z,1578341004.029 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2020-01-06T20:03:33.786Z,1578341013.786 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003382 2020-01-06T20:07:41.462Z,1578341261.462 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-01-06T20:07:41.462Z,1578341261.462 [Default:CheckIn:C.Wait] Stopped 2020-01-06T20:07:41.462Z,1578341261.462 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-01-06T20:07:41.462Z,1578341261.462 [Default:CheckIn:D] Running Loop=1 2020-01-06T20:07:41.877Z,1578341261.877 [Default:CheckIn:D] Stopped 2020-01-06T20:07:41.877Z,1578341261.877 [Default:CheckIn:E] Running Loop=1 2020-01-06T20:07:42.291Z,1578341262.291 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 41.217989 min 2020-01-06T20:07:42.291Z,1578341262.291 [Default:CheckIn:E] Stopped 2020-01-06T20:07:42.291Z,1578341262.291 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-01-06T20:07:42.291Z,1578341262.291 [Default:CheckIn] Stopped 2020-01-06T20:07:42.291Z,1578341262.291 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-01-06T20:07:42.291Z,1578341262.291 [Default:CheckIn](INFO): Running loop #6 2020-01-06T20:07:42.291Z,1578341262.291 [Default:CheckIn] Running Loop=6 2020-01-06T20:07:42.291Z,1578341262.291 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-01-06T20:07:42.292Z,1578341262.292 [Default:CheckIn:Read_GPS] Running Loop=1 2020-01-06T20:07:44.272Z,1578341264.272 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,200406.00,A,3648.25721,N,12147.14379,W,4.840,191.50,060120,,,D*7B 2020-01-06T20:07:44.274Z,1578341264.274 [NAL9602](INFO): GPS fix at 20200106T200406: (36.804287, -121.785730) 2020-01-06T20:07:44.330Z,1578341264.330 [Default:CheckIn:Read_GPS] Stopped 2020-01-06T20:07:44.330Z,1578341264.330 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-01-06T20:07:52.469Z,1578341272.469 [DataOverHttps](INFO): Sending 210 bytes from file Logs/20200106T195438/Courier0003.lzma 2020-01-06T20:07:54.475Z,1578341274.475 [DataOverHttps](INFO): Moved sent file to Logs/20200106T195438/Courier0003.lzma.bak 2020-01-06T20:07:54.475Z,1578341274.475 [DataOverHttps](INFO): SBD MOMSN=12185469 2020-01-06T20:08:10.528Z,1578341290.528 [NAL9602](INFO): SBD MO Status=0, MOMSN=18949, MT Status=0, MTMSN=0 2020-01-06T20:08:10.528Z,1578341290.528 [NAL9602](INFO): No messages in MT queue 2020-01-06T20:08:11.422Z,1578341291.422 [DataOverHttps](INFO): Sending 343 bytes from file Logs/20200106T195438/Express0004.lzma 2020-01-06T20:08:13.427Z,1578341293.427 [DataOverHttps](INFO): Moved sent file to Logs/20200106T195438/Express0004.lzma.bak 2020-01-06T20:08:13.427Z,1578341293.427 [DataOverHttps](INFO): SBD MOMSN=12185472 2020-01-06T20:08:14.589Z,1578341294.589 [Default:CheckIn:Read_Iridium] Stopped 2020-01-06T20:08:14.590Z,1578341294.590 [Default:CheckIn:C.Wait] Running Loop=1 2020-01-06T20:08:14.590Z,1578341294.590 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-01-06T20:08:41.230Z,1578341321.230 [NAL9602](INFO): Not Powering down - fast GPS 2020-01-06T20:13:15.174Z,1578341595.174 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-01-06T20:13:15.174Z,1578341595.174 [Default:CheckIn:C.Wait] Stopped 2020-01-06T20:13:15.174Z,1578341595.174 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-01-06T20:13:15.174Z,1578341595.174 [Default:CheckIn:D] Running Loop=1 2020-01-06T20:13:15.583Z,1578341595.583 [Default:CheckIn:D] Stopped 2020-01-06T20:13:15.583Z,1578341595.583 [Default:CheckIn:E] Running Loop=1 2020-01-06T20:13:15.978Z,1578341595.978 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 46.779753 min 2020-01-06T20:13:15.978Z,1578341595.978 [Default:CheckIn:E] Stopped 2020-01-06T20:13:15.978Z,1578341595.978 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-01-06T20:13:15.978Z,1578341595.978 [Default:CheckIn] Stopped 2020-01-06T20:13:15.978Z,1578341595.978 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-01-06T20:13:15.979Z,1578341595.979 [Default:CheckIn](INFO): Running loop #7 2020-01-06T20:13:15.979Z,1578341595.979 [Default:CheckIn] Running Loop=7 2020-01-06T20:13:15.979Z,1578341595.979 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-01-06T20:13:15.979Z,1578341595.979 [Default:CheckIn:Read_GPS] Running Loop=1 2020-01-06T20:13:17.973Z,1578341597.973 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,200939.00,A,3648.13802,N,12147.20597,W,0.039,325.90,060120,,,D*73 2020-01-06T20:13:17.975Z,1578341597.975 [NAL9602](INFO): GPS fix at 20200106T200939: (36.802300, -121.786766) 2020-01-06T20:13:17.999Z,1578341597.999 [Default:CheckIn:Read_GPS] Stopped 2020-01-06T20:13:17.999Z,1578341597.999 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-01-06T20:13:25.297Z,1578341605.297 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20200106T195438/Courier0006.lzma 2020-01-06T20:13:27.303Z,1578341607.303 [DataOverHttps](INFO): Moved sent file to Logs/20200106T195438/Courier0006.lzma.bak 2020-01-06T20:13:27.303Z,1578341607.303 [DataOverHttps](INFO): SBD MOMSN=12185475 2020-01-06T20:13:46.413Z,1578341626.413 [DataOverHttps](INFO): Sending 135 bytes from file Logs/20200106T195438/Express0007.lzma 2020-01-06T20:13:48.419Z,1578341628.419 [DataOverHttps](INFO): Moved sent file to Logs/20200106T195438/Express0007.lzma.bak 2020-01-06T20:13:48.419Z,1578341628.419 [DataOverHttps](INFO): SBD MOMSN=12185478 2020-01-06T20:13:49.914Z,1578341629.914 [Default:CheckIn:Read_Iridium] Stopped 2020-01-06T20:13:49.915Z,1578341629.915 [Default:CheckIn:C.Wait] Running Loop=1 2020-01-06T20:13:49.915Z,1578341629.915 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-01-06T20:13:54.744Z,1578341634.744 [NAL9602](INFO): SBD MO Status=2, MOMSN=18950, MT Status=2, MTMSN=0 2020-01-06T20:13:54.744Z,1578341634.744 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2020-01-06T20:14:04.436Z,1578341644.436 [NAL9602](INFO): SBD MO Status=0, MOMSN=18950, MT Status=0, MTMSN=0 2020-01-06T20:14:04.436Z,1578341644.436 [NAL9602](INFO): No messages in MT queue 2020-01-06T20:14:35.134Z,1578341675.134 [NAL9602](INFO): Not Powering down - fast GPS 2020-01-06T20:18:50.547Z,1578341930.547 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-01-06T20:18:50.547Z,1578341930.547 [Default:CheckIn:C.Wait] Stopped 2020-01-06T20:18:50.547Z,1578341930.547 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-01-06T20:18:50.547Z,1578341930.547 [Default:CheckIn:D] Running Loop=1 2020-01-06T20:18:50.964Z,1578341930.964 [Default:CheckIn:D] Stopped 2020-01-06T20:18:50.964Z,1578341930.964 [Default:CheckIn:E] Running Loop=1 2020-01-06T20:18:51.341Z,1578341931.341 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 52.369051 min 2020-01-06T20:18:51.341Z,1578341931.341 [Default:CheckIn:E] Stopped 2020-01-06T20:18:51.342Z,1578341931.342 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-01-06T20:18:51.342Z,1578341931.342 [Default:CheckIn] Stopped 2020-01-06T20:18:51.342Z,1578341931.342 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-01-06T20:18:51.342Z,1578341931.342 [Default:CheckIn](INFO): Running loop #8 2020-01-06T20:18:51.342Z,1578341931.342 [Default:CheckIn] Running Loop=8 2020-01-06T20:18:51.342Z,1578341931.342 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-01-06T20:18:51.342Z,1578341931.342 [Default:CheckIn:Read_GPS] Running Loop=1 2020-01-06T20:18:53.344Z,1578341933.344 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,201514.00,A,3648.18125,N,12147.27746,W,0.603,302.26,060120,,,D*78 2020-01-06T20:18:53.346Z,1578341933.346 [NAL9602](INFO): GPS fix at 20200106T201514: (36.803021, -121.787958) 2020-01-06T20:18:53.370Z,1578341933.370 [Default:CheckIn:Read_GPS] Stopped 2020-01-06T20:18:53.370Z,1578341933.370 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-01-06T20:19:00.973Z,1578341940.973 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20200106T195438/Courier0009.lzma 2020-01-06T20:19:02.979Z,1578341942.979 [DataOverHttps](INFO): Moved sent file to Logs/20200106T195438/Courier0009.lzma.bak 2020-01-06T20:19:02.979Z,1578341942.979 [DataOverHttps](INFO): SBD MOMSN=12185481 2020-01-06T20:19:17.176Z,1578341957.176 [NAL9602](INFO): SBD MO Status=0, MOMSN=18951, MT Status=0, MTMSN=0 2020-01-06T20:19:17.176Z,1578341957.176 [NAL9602](INFO): No messages in MT queue 2020-01-06T20:19:20.269Z,1578341960.269 [DataOverHttps](INFO): Sending 135 bytes from file Logs/20200106T195438/Express0010.lzma 2020-01-06T20:19:22.275Z,1578341962.275 [DataOverHttps](INFO): Moved sent file to Logs/20200106T195438/Express0010.lzma.bak 2020-01-06T20:19:22.275Z,1578341962.275 [DataOverHttps](INFO): SBD MOMSN=12185484 2020-01-06T20:19:23.674Z,1578341963.674 [Default:CheckIn:Read_Iridium] Stopped 2020-01-06T20:19:23.675Z,1578341963.675 [Default:CheckIn:C.Wait] Running Loop=1 2020-01-06T20:19:23.675Z,1578341963.675 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-01-06T20:19:47.886Z,1578341987.886 [NAL9602](INFO): Not Powering down - fast GPS 2020-01-06T20:24:24.249Z,1578342264.249 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-01-06T20:24:24.249Z,1578342264.249 [Default:CheckIn:C.Wait] Stopped 2020-01-06T20:24:24.249Z,1578342264.249 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-01-06T20:24:24.249Z,1578342264.249 [Default:CheckIn:D] Running Loop=1 2020-01-06T20:24:24.656Z,1578342264.656 [Default:CheckIn:D] Stopped 2020-01-06T20:24:24.656Z,1578342264.656 [Default:CheckIn:E] Running Loop=1 2020-01-06T20:24:25.067Z,1578342265.067 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 57.930961 min 2020-01-06T20:24:25.067Z,1578342265.067 [Default:CheckIn:E] Stopped 2020-01-06T20:24:25.067Z,1578342265.067 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-01-06T20:24:25.067Z,1578342265.067 [Default:CheckIn] Stopped 2020-01-06T20:24:25.067Z,1578342265.067 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-01-06T20:24:25.067Z,1578342265.067 [Default:CheckIn](INFO): Running loop #9 2020-01-06T20:24:25.068Z,1578342265.068 [Default:CheckIn] Running Loop=9 2020-01-06T20:24:25.068Z,1578342265.068 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-01-06T20:24:25.068Z,1578342265.068 [Default:CheckIn:Read_GPS] Running Loop=1 2020-01-06T20:24:27.050Z,1578342267.050 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,202047.00,A,3648.16979,N,12147.26706,W,0.428,210.00,060120,,,D*7F 2020-01-06T20:24:27.052Z,1578342267.052 [NAL9602](INFO): GPS fix at 20200106T202047: (36.802830, -121.787784) 2020-01-06T20:24:27.075Z,1578342267.075 [Default:CheckIn:Read_GPS] Stopped 2020-01-06T20:24:27.075Z,1578342267.075 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-01-06T20:24:34.739Z,1578342274.739 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20200106T195438/Courier0012.lzma 2020-01-06T20:24:36.743Z,1578342276.743 [DataOverHttps](INFO): Moved sent file to Logs/20200106T195438/Courier0012.lzma.bak 2020-01-06T20:24:36.743Z,1578342276.743 [DataOverHttps](INFO): SBD MOMSN=12185487 2020-01-06T20:24:48.472Z,1578342288.472 [NAL9602](INFO): SBD MO Status=2, MOMSN=18952, MT Status=2, MTMSN=0 2020-01-06T20:24:48.472Z,1578342288.472 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2020-01-06T20:24:55.897Z,1578342295.897 [DataOverHttps](INFO): Sending 120 bytes from file Logs/20200106T195438/Express0013.lzma 2020-01-06T20:24:57.903Z,1578342297.903 [DataOverHttps](INFO): Moved sent file to Logs/20200106T195438/Express0013.lzma.bak 2020-01-06T20:24:57.903Z,1578342297.903 [DataOverHttps](INFO): SBD MOMSN=12185490 2020-01-06T20:24:59.417Z,1578342299.417 [Default:CheckIn:Read_Iridium] Stopped 2020-01-06T20:24:59.418Z,1578342299.418 [Default:CheckIn:C.Wait] Running Loop=1 2020-01-06T20:24:59.418Z,1578342299.418 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-01-06T20:26:19.772Z,1578342379.772 [NAL9602](INFO): SBD MO Status=0, MOMSN=18952, MT Status=0, MTMSN=0 2020-01-06T20:26:19.772Z,1578342379.772 [NAL9602](INFO): No messages in MT queue 2020-01-06T20:26:50.477Z,1578342410.477 [NAL9602](INFO): Not Powering down - fast GPS 2020-01-06T20:29:59.985Z,1578342599.985 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-01-06T20:29:59.985Z,1578342599.985 [Default:CheckIn:C.Wait] Stopped 2020-01-06T20:29:59.985Z,1578342599.985 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-01-06T20:29:59.985Z,1578342599.985 [Default:CheckIn:D] Running Loop=1 2020-01-06T20:30:00.464Z,1578342600.464 [Default:CheckIn:D] Stopped 2020-01-06T20:30:00.464Z,1578342600.464 [Default:CheckIn:E] Running Loop=1 2020-01-06T20:30:00.788Z,1578342600.788 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 63.527763 min 2020-01-06T20:30:00.788Z,1578342600.788 [Default:CheckIn:E] Stopped 2020-01-06T20:30:00.788Z,1578342600.788 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-01-06T20:30:00.788Z,1578342600.788 [Default:CheckIn] Stopped 2020-01-06T20:30:00.788Z,1578342600.788 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-01-06T20:30:00.788Z,1578342600.788 [Default:CheckIn](INFO): Running loop #10 2020-01-06T20:30:00.788Z,1578342600.788 [Default:CheckIn] Running Loop=10 2020-01-06T20:30:00.788Z,1578342600.788 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-01-06T20:30:00.788Z,1578342600.788 [Default:CheckIn:Read_GPS] Running Loop=1 2020-01-06T20:30:02.780Z,1578342602.780 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,202623.00,A,3648.16912,N,12147.27950,W,1.458,243.10,060120,,,A*7E 2020-01-06T20:30:02.782Z,1578342602.782 [NAL9602](INFO): GPS fix at 20200106T202623: (36.802819, -121.787992) 2020-01-06T20:30:02.838Z,1578342602.838 [Default:CheckIn:Read_GPS] Stopped 2020-01-06T20:30:02.839Z,1578342602.839 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-01-06T20:30:10.613Z,1578342610.613 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20200106T195438/Courier0015.lzma 2020-01-06T20:30:12.619Z,1578342612.619 [DataOverHttps](INFO): Moved sent file to Logs/20200106T195438/Courier0015.lzma.bak 2020-01-06T20:30:12.619Z,1578342612.619 [DataOverHttps](INFO): SBD MOMSN=12185493 2020-01-06T20:30:32.845Z,1578342632.845 [DataOverHttps](INFO): Sending 133 bytes from file Logs/20200106T195438/Express0016.lzma 2020-01-06T20:30:34.851Z,1578342634.851 [DataOverHttps](INFO): Moved sent file to Logs/20200106T195438/Express0016.lzma.bak 2020-01-06T20:30:34.851Z,1578342634.851 [DataOverHttps](INFO): SBD MOMSN=12185496 2020-01-06T20:30:36.353Z,1578342636.353 [Default:CheckIn:Read_Iridium] Stopped 2020-01-06T20:30:36.353Z,1578342636.353 [Default:CheckIn:C.Wait] Running Loop=1 2020-01-06T20:30:36.353Z,1578342636.353 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-01-06T20:32:28.660Z,1578342748.660 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2020-01-06T20:32:28.663Z,1578342748.663 [BPC1](INFO): Received data from all battery sticks. 2020-01-06T20:32:48.416Z,1578342768.416 [NAL9602](INFO): SBD MO Status=2, MOMSN=18953, MT Status=2, MTMSN=0 2020-01-06T20:32:48.416Z,1578342768.416 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2020-01-06T20:35:05.390Z,1578342905.390 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2020-01-06T20:35:36.088Z,1578342936.088 [NAL9602](INFO): Not Powering down - fast GPS 2020-01-06T20:35:36.949Z,1578342936.949 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-01-06T20:35:36.949Z,1578342936.949 [Default:CheckIn:C.Wait] Stopped 2020-01-06T20:35:36.949Z,1578342936.949 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-01-06T20:35:36.950Z,1578342936.950 [Default:CheckIn:D] Running Loop=1 2020-01-06T20:35:37.331Z,1578342937.331 [Default:CheckIn:D] Stopped 2020-01-06T20:35:37.331Z,1578342937.331 [Default:CheckIn:E] Running Loop=1 2020-01-06T20:35:37.738Z,1578342937.738 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 69.142212 min 2020-01-06T20:35:37.739Z,1578342937.739 [Default:CheckIn:E] Stopped 2020-01-06T20:35:37.739Z,1578342937.739 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-01-06T20:35:37.739Z,1578342937.739 [Default:CheckIn] Stopped 2020-01-06T20:35:37.739Z,1578342937.739 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-01-06T20:35:37.739Z,1578342937.739 [Default:CheckIn](INFO): Running loop #11 2020-01-06T20:35:37.739Z,1578342937.739 [Default:CheckIn] Running Loop=11 2020-01-06T20:35:37.739Z,1578342937.739 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-01-06T20:35:37.739Z,1578342937.739 [Default:CheckIn:Read_GPS] Running Loop=1 2020-01-06T20:35:39.727Z,1578342939.727 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,203159.00,A,3648.17779,N,12147.28031,W,0.525,302.74,060120,,,A*7A 2020-01-06T20:35:39.730Z,1578342939.730 [NAL9602](INFO): GPS fix at 20200106T203159: (36.802963, -121.788005) 2020-01-06T20:35:39.781Z,1578342939.781 [Default:CheckIn:Read_GPS] Stopped 2020-01-06T20:35:39.781Z,1578342939.781 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-01-06T20:35:47.533Z,1578342947.533 [DataOverHttps](INFO): Sending 221 bytes from file Logs/20200106T195438/Courier0018.lzma 2020-01-06T20:35:49.539Z,1578342949.539 [DataOverHttps](INFO): Moved sent file to Logs/20200106T195438/Courier0018.lzma.bak 2020-01-06T20:35:49.539Z,1578342949.539 [DataOverHttps](INFO): SBD MOMSN=12185499 2020-01-06T20:36:06.549Z,1578342966.549 [DataOverHttps](INFO): Sending 222 bytes from file Logs/20200106T195438/Express0019.lzma 2020-01-06T20:36:08.555Z,1578342968.555 [DataOverHttps](INFO): Moved sent file to Logs/20200106T195438/Express0019.lzma.bak 2020-01-06T20:36:08.555Z,1578342968.555 [DataOverHttps](INFO): SBD MOMSN=12185502 2020-01-06T20:36:10.063Z,1578342970.063 [Default:CheckIn:Read_Iridium] Stopped 2020-01-06T20:36:10.063Z,1578342970.063 [Default:CheckIn:C.Wait] Running Loop=1 2020-01-06T20:36:10.063Z,1578342970.063 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-01-06T20:36:10.438Z,1578342970.438 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2020-01-06T20:36:10.517Z,1578342970.517 [NAL9602](FAULT): received: +CSQ:0 OK953, 2, 0, 0, 0 OK 2020-01-06T20:36:10.517Z,1578342970.517 [NAL9602] Data Fault, FailCount= 1 2020-01-06T20:36:10.517Z,1578342970.517 [NAL9602](ERROR): Data Fault 2020-01-06T20:36:10.554Z,1578342970.554 [CBIT](ERROR): Data Fault in component: NAL9602 2020-01-06T20:36:10.838Z,1578342970.838 [NAL9602](INFO): Powering down 2020-01-06T20:36:11.706Z,1578342971.706 [CBIT](INFO): Clearing failed state for component NAL9602 2020-01-06T20:36:11.706Z,1578342971.706 [NAL9602] No Fault, FailCount= 1 2020-01-06T20:36:41.147Z,1578343001.147 [NAL9602](INFO): Powering up NAL9602 2020-01-06T20:36:52.046Z,1578343012.046 [NAL9602](INFO): NAL9602 initialized 2020-01-06T20:37:23.152Z,1578343043.152 [NAL9602](INFO): Not Powering down - fast GPS 2020-01-06T20:41:10.626Z,1578343270.626 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-01-06T20:41:10.626Z,1578343270.626 [Default:CheckIn:C.Wait] Stopped 2020-01-06T20:41:10.626Z,1578343270.626 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-01-06T20:41:10.627Z,1578343270.627 [Default:CheckIn:D] Running Loop=1 2020-01-06T20:41:11.044Z,1578343271.044 [Default:CheckIn:D] Stopped 2020-01-06T20:41:11.044Z,1578343271.044 [Default:CheckIn:E] Running Loop=1 2020-01-06T20:41:11.451Z,1578343271.451 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 74.704085 min 2020-01-06T20:41:11.451Z,1578343271.451 [Default:CheckIn:E] Stopped 2020-01-06T20:41:11.451Z,1578343271.451 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-01-06T20:41:11.451Z,1578343271.451 [Default:CheckIn] Stopped 2020-01-06T20:41:11.451Z,1578343271.451 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-01-06T20:41:11.451Z,1578343271.451 [Default:CheckIn](INFO): Running loop #12 2020-01-06T20:41:11.451Z,1578343271.451 [Default:CheckIn] Running Loop=12 2020-01-06T20:41:11.451Z,1578343271.451 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-01-06T20:41:11.452Z,1578343271.452 [Default:CheckIn:Read_GPS] Running Loop=1 2020-01-06T20:41:13.452Z,1578343273.452 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,203731.00,A,3648.16896,N,12147.27399,W,1.186,73.27,060120,,,A*4C 2020-01-06T20:41:13.463Z,1578343273.463 [NAL9602](INFO): GPS fix at 20200106T203731: (36.802816, -121.787900) 2020-01-06T20:41:13.487Z,1578343273.487 [Default:CheckIn:Read_GPS] Stopped 2020-01-06T20:41:13.487Z,1578343273.487 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-01-06T20:41:15.050Z,1578343275.050 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2020-01-06T20:41:21.001Z,1578343281.001 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20200106T195438/Courier0021.lzma 2020-01-06T20:41:23.007Z,1578343283.007 [DataOverHttps](INFO): Moved sent file to Logs/20200106T195438/Courier0021.lzma.bak 2020-01-06T20:41:23.007Z,1578343283.007 [DataOverHttps](INFO): SBD MOMSN=12185504 2020-01-06T20:41:44.225Z,1578343304.225 [DataOverHttps](INFO): Sending 164 bytes from file Logs/20200106T195438/Express0022.lzma 2020-01-06T20:41:45.776Z,1578343305.776 [NAL9602](INFO): Not Powering down - fast GPS 2020-01-06T20:41:46.231Z,1578343306.231 [DataOverHttps](INFO): Moved sent file to Logs/20200106T195438/Express0022.lzma.bak 2020-01-06T20:41:46.231Z,1578343306.231 [DataOverHttps](INFO): SBD MOMSN=12185507 2020-01-06T20:41:47.418Z,1578343307.418 [Default:CheckIn:Read_Iridium] Stopped 2020-01-06T20:41:47.418Z,1578343307.418 [Default:CheckIn:C.Wait] Running Loop=1 2020-01-06T20:41:47.418Z,1578343307.418 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-01-06T20:46:48.013Z,1578343608.013 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-01-06T20:46:48.013Z,1578343608.013 [Default:CheckIn:C.Wait] Stopped 2020-01-06T20:46:48.013Z,1578343608.013 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-01-06T20:46:48.014Z,1578343608.014 [Default:CheckIn:D] Running Loop=1 2020-01-06T20:46:48.431Z,1578343608.431 [Default:CheckIn:D] Stopped 2020-01-06T20:46:48.431Z,1578343608.431 [Default:CheckIn:E] Running Loop=1 2020-01-06T20:46:48.833Z,1578343608.833 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 80.327214 min 2020-01-06T20:46:48.833Z,1578343608.833 [Default:CheckIn:E] Stopped 2020-01-06T20:46:48.833Z,1578343608.833 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-01-06T20:46:48.833Z,1578343608.833 [Default:CheckIn] Stopped 2020-01-06T20:46:48.833Z,1578343608.833 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-01-06T20:46:48.833Z,1578343608.833 [Default:CheckIn](INFO): Running loop #13 2020-01-06T20:46:48.833Z,1578343608.833 [Default:CheckIn] Running Loop=13 2020-01-06T20:46:48.834Z,1578343608.834 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-01-06T20:46:48.834Z,1578343608.834 [Default:CheckIn:Read_GPS] Running Loop=1 2020-01-06T20:46:50.819Z,1578343610.819 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,204308.00,A,3648.16792,N,12147.27754,W,0.233,346.31,060120,,,A*75 2020-01-06T20:46:50.821Z,1578343610.821 [NAL9602](INFO): GPS fix at 20200106T204308: (36.802799, -121.787959) 2020-01-06T20:46:50.875Z,1578343610.875 [Default:CheckIn:Read_GPS] Stopped 2020-01-06T20:46:50.875Z,1578343610.875 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-01-06T20:46:58.441Z,1578343618.441 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20200106T195438/Courier0024.lzma 2020-01-06T20:47:00.447Z,1578343620.447 [DataOverHttps](INFO): Moved sent file to Logs/20200106T195438/Courier0024.lzma.bak 2020-01-06T20:47:00.447Z,1578343620.447 [DataOverHttps](INFO): SBD MOMSN=12185509 2020-01-06T20:47:17.457Z,1578343637.457 [DataOverHttps](INFO): Sending 196 bytes from file Logs/20200106T195438/Express0025.lzma 2020-01-06T20:47:19.463Z,1578343639.463 [DataOverHttps](INFO): Moved sent file to Logs/20200106T195438/Express0025.lzma.bak 2020-01-06T20:47:19.463Z,1578343639.463 [DataOverHttps](INFO): SBD MOMSN=12185512 2020-01-06T20:47:20.774Z,1578343640.774 [Default:CheckIn:Read_Iridium] Stopped 2020-01-06T20:47:20.774Z,1578343640.774 [Default:CheckIn:C.Wait] Running Loop=1 2020-01-06T20:47:20.774Z,1578343640.774 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-01-06T20:51:53.052Z,1578343913.052 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2020-01-06T20:52:21.385Z,1578343941.385 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-01-06T20:52:21.385Z,1578343941.385 [Default:CheckIn:C.Wait] Stopped 2020-01-06T20:52:21.385Z,1578343941.385 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-01-06T20:52:21.386Z,1578343941.386 [Default:CheckIn:D] Running Loop=1 2020-01-06T20:52:21.769Z,1578343941.769 [Default:CheckIn:D] Stopped 2020-01-06T20:52:21.769Z,1578343941.769 [Default:CheckIn:E] Running Loop=1 2020-01-06T20:52:22.177Z,1578343942.177 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 85.882853 min 2020-01-06T20:52:22.177Z,1578343942.177 [Default:CheckIn:E] Stopped 2020-01-06T20:52:22.177Z,1578343942.177 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-01-06T20:52:22.177Z,1578343942.177 [Default:CheckIn] Stopped 2020-01-06T20:52:22.177Z,1578343942.177 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-01-06T20:52:22.178Z,1578343942.178 [Default:CheckIn](INFO): Running loop #14 2020-01-06T20:52:22.178Z,1578343942.178 [Default:CheckIn] Running Loop=14 2020-01-06T20:52:22.178Z,1578343942.178 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-01-06T20:52:22.178Z,1578343942.178 [Default:CheckIn:Read_GPS] Running Loop=1 2020-01-06T20:52:24.165Z,1578343944.165 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,204842.00,A,3648.16813,N,12147.27513,W,1.691,84.87,060120,,,D*4F 2020-01-06T20:52:24.167Z,1578343944.167 [NAL9602](INFO): GPS fix at 20200106T204842: (36.802802, -121.787919) 2020-01-06T20:52:24.214Z,1578343944.214 [Default:CheckIn:Read_GPS] Stopped 2020-01-06T20:52:24.214Z,1578343944.214 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-01-06T20:52:33.777Z,1578343953.777 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20200106T195438/Courier0027.lzma 2020-01-06T20:52:35.783Z,1578343955.783 [DataOverHttps](INFO): Moved sent file to Logs/20200106T195438/Courier0027.lzma.bak 2020-01-06T20:52:35.783Z,1578343955.783 [DataOverHttps](INFO): SBD MOMSN=12185514 2020-01-06T20:52:52.862Z,1578343972.862 [DataOverHttps](INFO): Sending 196 bytes from file Logs/20200106T195438/Express0028.lzma 2020-01-06T20:52:54.867Z,1578343974.867 [DataOverHttps](INFO): Moved sent file to Logs/20200106T195438/Express0028.lzma.bak 2020-01-06T20:52:54.868Z,1578343974.868 [DataOverHttps](INFO): SBD MOMSN=12185517 2020-01-06T20:52:56.115Z,1578343976.115 [Default:CheckIn:Read_Iridium] Stopped 2020-01-06T20:52:56.115Z,1578343976.115 [Default:CheckIn:C.Wait] Running Loop=1 2020-01-06T20:52:56.115Z,1578343976.115 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-01-06T20:52:56.486Z,1578343976.486 [NAL9602](INFO): Not Powering down - fast GPS 2020-01-06T20:57:56.740Z,1578344276.740 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-01-06T20:57:56.741Z,1578344276.741 [Default:CheckIn:C.Wait] Stopped 2020-01-06T20:57:56.741Z,1578344276.741 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-01-06T20:57:56.741Z,1578344276.741 [Default:CheckIn:D] Running Loop=1 2020-01-06T20:57:57.130Z,1578344277.130 [Default:CheckIn:D] Stopped 2020-01-06T20:57:57.130Z,1578344277.130 [Default:CheckIn:E] Running Loop=1 2020-01-06T20:57:57.533Z,1578344277.533 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 91.472192 min 2020-01-06T20:57:57.533Z,1578344277.533 [Default:CheckIn:E] Stopped 2020-01-06T20:57:57.533Z,1578344277.533 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-01-06T20:57:57.533Z,1578344277.533 [Default:CheckIn] Stopped 2020-01-06T20:57:57.533Z,1578344277.533 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-01-06T20:57:57.533Z,1578344277.533 [Default:CheckIn](INFO): Running loop #15 2020-01-06T20:57:57.534Z,1578344277.534 [Default:CheckIn] Running Loop=15 2020-01-06T20:57:57.534Z,1578344277.534 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-01-06T20:57:57.534Z,1578344277.534 [Default:CheckIn:Read_GPS] Running Loop=1 2020-01-06T20:57:59.524Z,1578344279.524 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,205417.00,A,3648.16502,N,12147.28452,W,0.194,91.95,060120,,,D*40 2020-01-06T20:57:59.530Z,1578344279.530 [NAL9602](INFO): GPS fix at 20200106T205417: (36.802750, -121.788075) 2020-01-06T20:57:59.580Z,1578344279.580 [Default:CheckIn:Read_GPS] Stopped 2020-01-06T20:57:59.580Z,1578344279.580 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-01-06T20:58:06.925Z,1578344286.925 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20200106T195438/Courier0030.lzma 2020-01-06T20:58:08.931Z,1578344288.931 [DataOverHttps](INFO): Moved sent file to Logs/20200106T195438/Courier0030.lzma.bak 2020-01-06T20:58:08.931Z,1578344288.931 [DataOverHttps](INFO): SBD MOMSN=12185519 2020-01-06T20:58:25.937Z,1578344305.937 [DataOverHttps](INFO): Sending 121 bytes from file Logs/20200106T195438/Express0031.lzma 2020-01-06T20:58:27.943Z,1578344307.943 [DataOverHttps](INFO): Moved sent file to Logs/20200106T195438/Express0031.lzma.bak 2020-01-06T20:58:27.943Z,1578344307.943 [DataOverHttps](INFO): SBD MOMSN=12185522 2020-01-06T20:58:29.458Z,1578344309.458 [Default:CheckIn:Read_Iridium] Stopped 2020-01-06T20:58:29.458Z,1578344309.458 [Default:CheckIn:C.Wait] Running Loop=1 2020-01-06T20:58:29.458Z,1578344309.458 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-01-06T20:58:30.230Z,1578344310.230 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2020-01-06T20:58:30.309Z,1578344310.309 [NAL9602](FAULT): received: +CSQ:0 OK953, 2, 0, 0, 0 OK 2020-01-06T20:58:30.309Z,1578344310.309 [NAL9602] Data Fault, FailCount= 1 2020-01-06T20:58:30.309Z,1578344310.309 [NAL9602](ERROR): Data Fault 2020-01-06T20:58:30.373Z,1578344310.373 [CBIT](ERROR): Data Fault in component: NAL9602 2020-01-06T20:58:30.628Z,1578344310.628 [NAL9602](INFO): Powering down 2020-01-06T20:58:31.507Z,1578344311.507 [CBIT](INFO): Clearing failed state for component NAL9602 2020-01-06T20:58:31.507Z,1578344311.507 [NAL9602] No Fault, FailCount= 1 2020-01-06T20:59:00.931Z,1578344340.931 [NAL9602](INFO): Powering up NAL9602 2020-01-06T20:59:11.846Z,1578344351.846 [NAL9602](INFO): NAL9602 initialized 2020-01-06T20:59:42.958Z,1578344382.958 [NAL9602](INFO): Not Powering down - fast GPS 2020-01-06T21:03:30.071Z,1578344610.071 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-01-06T21:03:30.071Z,1578344610.071 [Default:CheckIn:C.Wait] Stopped 2020-01-06T21:03:30.071Z,1578344610.071 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-01-06T21:03:30.071Z,1578344610.071 [Default:CheckIn:D] Running Loop=1 2020-01-06T21:03:30.442Z,1578344610.442 [Default:CheckIn:D] Stopped 2020-01-06T21:03:30.442Z,1578344610.442 [Default:CheckIn:E] Running Loop=1 2020-01-06T21:03:30.863Z,1578344610.863 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 97.027401 min 2020-01-06T21:03:30.864Z,1578344610.864 [Default:CheckIn:E] Stopped 2020-01-06T21:03:30.864Z,1578344610.864 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-01-06T21:03:30.864Z,1578344610.864 [Default:CheckIn] Stopped 2020-01-06T21:03:30.864Z,1578344610.864 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-01-06T21:03:30.864Z,1578344610.864 [Default:CheckIn](INFO): Running loop #16 2020-01-06T21:03:30.864Z,1578344610.864 [Default:CheckIn] Running Loop=16 2020-01-06T21:03:30.864Z,1578344610.864 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-01-06T21:03:30.864Z,1578344610.864 [Default:CheckIn:Read_GPS] Running Loop=1 2020-01-06T21:03:35.254Z,1578344615.254 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2020-01-06T21:08:31.018Z,1578344911.018 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-01-06T21:03:30.9Z 2020-01-06T21:08:31.018Z,1578344911.018 [Default:CheckIn:Read_GPS] Stopped 2020-01-06T21:08:31.018Z,1578344911.018 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-01-06T21:08:38.401Z,1578344918.401 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20200106T195438/Courier0033.lzma 2020-01-06T21:08:40.407Z,1578344920.407 [DataOverHttps](INFO): Moved sent file to Logs/20200106T195438/Courier0033.lzma.bak 2020-01-06T21:08:40.407Z,1578344920.407 [DataOverHttps](INFO): SBD MOMSN=12185525 2020-01-06T21:08:57.586Z,1578344937.586 [DataOverHttps](INFO): Sending 239 bytes from file Logs/20200106T195438/Express0034.lzma 2020-01-06T21:08:59.591Z,1578344939.591 [DataOverHttps](INFO): Moved sent file to Logs/20200106T195438/Express0034.lzma.bak 2020-01-06T21:08:59.591Z,1578344939.591 [DataOverHttps](INFO): SBD MOMSN=12185527 2020-01-06T21:09:00.897Z,1578344940.897 [Default:CheckIn:Read_Iridium] Stopped 2020-01-06T21:09:00.897Z,1578344940.897 [Default:CheckIn:C.Wait] Running Loop=1 2020-01-06T21:09:00.897Z,1578344940.897 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-01-06T21:09:03.298Z,1578344943.298 [NAL9602](INFO): Not Powering down - fast GPS 2020-01-06T21:14:01.484Z,1578345241.484 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-01-06T21:14:01.484Z,1578345241.484 [Default:CheckIn:C.Wait] Stopped 2020-01-06T21:14:01.484Z,1578345241.484 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-01-06T21:14:01.484Z,1578345241.484 [Default:CheckIn:D] Running Loop=1 2020-01-06T21:14:01.902Z,1578345241.902 [Default:CheckIn:D] Stopped 2020-01-06T21:14:01.902Z,1578345241.902 [Default:CheckIn:E] Running Loop=1 2020-01-06T21:14:02.285Z,1578345242.285 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 107.551725 min 2020-01-06T21:14:02.285Z,1578345242.285 [Default:CheckIn:E] Stopped 2020-01-06T21:14:02.311Z,1578345242.311 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-01-06T21:14:02.311Z,1578345242.311 [Default:CheckIn] Stopped 2020-01-06T21:14:02.311Z,1578345242.311 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-01-06T21:14:02.311Z,1578345242.311 [Default:CheckIn](INFO): Running loop #17 2020-01-06T21:14:02.311Z,1578345242.311 [Default:CheckIn] Running Loop=17 2020-01-06T21:14:02.311Z,1578345242.311 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-01-06T21:14:02.311Z,1578345242.311 [Default:CheckIn:Read_GPS] Running Loop=1 2020-01-06T21:14:03.876Z,1578345243.876 [NAL9602](FAULT): GPS failed to acquire within timeout. 2020-01-06T21:14:03.876Z,1578345243.876 [NAL9602] Data Fault, FailCount= 1 2020-01-06T21:14:03.876Z,1578345243.876 [NAL9602](ERROR): Data Fault 2020-01-06T21:14:03.942Z,1578345243.942 [CBIT](ERROR): Data Fault in component: NAL9602 2020-01-06T21:14:04.286Z,1578345244.286 [NAL9602](INFO): Powering down 2020-01-06T21:14:05.142Z,1578345245.142 [CBIT](INFO): Clearing failed state for component NAL9602 2020-01-06T21:14:05.142Z,1578345245.142 [NAL9602] No Fault, FailCount= 1 2020-01-06T21:14:34.582Z,1578345274.582 [NAL9602](INFO): Powering up NAL9602 2020-01-06T21:14:45.490Z,1578345285.490 [NAL9602](INFO): NAL9602 initialized 2020-01-06T21:19:02.475Z,1578345542.475 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-01-06T21:14:02.3Z 2020-01-06T21:19:02.475Z,1578345542.475 [Default:CheckIn:Read_GPS] Stopped 2020-01-06T21:19:02.476Z,1578345542.476 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-01-06T21:19:09.717Z,1578345549.717 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20200106T195438/Courier0036.lzma 2020-01-06T21:19:11.723Z,1578345551.723 [DataOverHttps](INFO): Moved sent file to Logs/20200106T195438/Courier0036.lzma.bak 2020-01-06T21:19:11.723Z,1578345551.723 [DataOverHttps](INFO): SBD MOMSN=12185529 2020-01-06T21:19:28.849Z,1578345568.849 [DataOverHttps](INFO): Sending 163 bytes from file Logs/20200106T195438/Express0037.lzma 2020-01-06T21:19:30.879Z,1578345570.879 [DataOverHttps](INFO): Moved sent file to Logs/20200106T195438/Express0037.lzma.bak 2020-01-06T21:19:30.880Z,1578345570.880 [DataOverHttps](INFO): SBD MOMSN=12185531 2020-01-06T21:19:32.375Z,1578345572.375 [Default:CheckIn:Read_Iridium] Stopped 2020-01-06T21:19:32.375Z,1578345572.375 [Default:CheckIn:C.Wait] Running Loop=1 2020-01-06T21:19:32.375Z,1578345572.375 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-01-06T21:19:48.902Z,1578345588.902 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2020-01-06T21:20:19.602Z,1578345619.602 [NAL9602](INFO): Not Powering down - fast GPS 2020-01-06T21:24:32.944Z,1578345872.944 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-01-06T21:24:32.944Z,1578345872.944 [Default:CheckIn:C.Wait] Stopped 2020-01-06T21:24:32.944Z,1578345872.944 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-01-06T21:24:32.945Z,1578345872.945 [Default:CheckIn:D] Running Loop=1 2020-01-06T21:24:33.347Z,1578345873.347 [Default:CheckIn:D] Stopped 2020-01-06T21:24:33.347Z,1578345873.347 [Default:CheckIn:E] Running Loop=1 2020-01-06T21:24:33.765Z,1578345873.765 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 118.075822 min 2020-01-06T21:24:33.765Z,1578345873.765 [Default:CheckIn:E] Stopped 2020-01-06T21:24:33.765Z,1578345873.765 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-01-06T21:24:33.765Z,1578345873.765 [Default:CheckIn] Stopped 2020-01-06T21:24:33.765Z,1578345873.765 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-01-06T21:24:33.765Z,1578345873.765 [Default:CheckIn](INFO): Running loop #18 2020-01-06T21:24:33.765Z,1578345873.765 [Default:CheckIn] Running Loop=18 2020-01-06T21:24:33.766Z,1578345873.766 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-01-06T21:24:33.766Z,1578345873.766 [Default:CheckIn:Read_GPS] Running Loop=1 2020-01-06T21:29:33.968Z,1578346173.968 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-01-06T21:24:33.8Z 2020-01-06T21:29:33.968Z,1578346173.968 [Default:CheckIn:Read_GPS] Stopped 2020-01-06T21:29:33.968Z,1578346173.968 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-01-06T21:29:38.338Z,1578346178.338 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2020-01-06T21:29:41.217Z,1578346181.217 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20200106T195438/Courier0039.lzma 2020-01-06T21:29:43.223Z,1578346183.223 [DataOverHttps](INFO): Moved sent file to Logs/20200106T195438/Courier0039.lzma.bak 2020-01-06T21:29:43.223Z,1578346183.223 [DataOverHttps](INFO): SBD MOMSN=12185533 2020-01-06T21:30:00.325Z,1578346200.325 [DataOverHttps](INFO): Sending 200 bytes from file Logs/20200106T195438/Express0040.lzma 2020-01-06T21:30:02.331Z,1578346202.331 [DataOverHttps](INFO): Moved sent file to Logs/20200106T195438/Express0040.lzma.bak 2020-01-06T21:30:02.331Z,1578346202.331 [DataOverHttps](INFO): SBD MOMSN=12185535 2020-01-06T21:30:03.821Z,1578346203.821 [Default:CheckIn:Read_Iridium] Stopped 2020-01-06T21:30:03.821Z,1578346203.821 [Default:CheckIn:C.Wait] Running Loop=1 2020-01-06T21:30:03.821Z,1578346203.821 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-01-06T21:30:09.038Z,1578346209.038 [NAL9602](INFO): Not Powering down - fast GPS 2020-01-06T21:33:50.043Z,1578346430.043 [BPC1](ERROR): BPC1A: No match for serial number 1717 in BPC1A's battery stick inventory (sticks 1-32 in onboard configuration file). 2020-01-06T21:34:03.382Z,1578346443.382 [BPC1](ERROR): BPC1A: No match for serial number 1717 in BPC1A's battery stick inventory (sticks 1-32 in onboard configuration file). 2020-01-06T21:35:04.383Z,1578346504.383 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-01-06T21:35:04.383Z,1578346504.383 [Default:CheckIn:C.Wait] Stopped 2020-01-06T21:35:04.383Z,1578346504.383 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-01-06T21:35:04.383Z,1578346504.383 [Default:CheckIn:D] Running Loop=1 2020-01-06T21:35:04.790Z,1578346504.790 [Default:CheckIn:D] Stopped 2020-01-06T21:35:04.791Z,1578346504.791 [Default:CheckIn:E] Running Loop=1 2020-01-06T21:35:05.209Z,1578346505.209 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 128.599878 min 2020-01-06T21:35:05.210Z,1578346505.210 [Default:CheckIn:E] Stopped 2020-01-06T21:35:05.210Z,1578346505.210 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-01-06T21:35:05.210Z,1578346505.210 [Default:CheckIn] Stopped 2020-01-06T21:35:05.210Z,1578346505.210 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-01-06T21:35:05.210Z,1578346505.210 [Default:CheckIn](INFO): Running loop #19 2020-01-06T21:35:05.210Z,1578346505.210 [Default:CheckIn] Running Loop=19 2020-01-06T21:35:05.210Z,1578346505.210 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-01-06T21:35:05.210Z,1578346505.210 [Default:CheckIn:Read_GPS] Running Loop=1 2020-01-06T21:35:06.790Z,1578346506.790 [NAL9602](FAULT): GPS failed to acquire within timeout. 2020-01-06T21:35:06.790Z,1578346506.790 [NAL9602] Data Fault, FailCount= 2 2020-01-06T21:35:06.790Z,1578346506.790 [NAL9602](ERROR): Data Fault 2020-01-06T21:35:06.861Z,1578346506.861 [CBIT](ERROR): Data Fault in component: NAL9602 2020-01-06T21:35:07.188Z,1578346507.188 [NAL9602](INFO): Powering down 2020-01-06T21:35:08.037Z,1578346508.037 [CBIT](INFO): Clearing failed state for component NAL9602 2020-01-06T21:35:08.037Z,1578346508.037 [NAL9602] No Fault, FailCount= 2 2020-01-06T21:35:37.510Z,1578346537.510 [NAL9602](INFO): Powering up NAL9602 2020-01-06T21:35:48.418Z,1578346548.418 [NAL9602](INFO): NAL9602 initialized 2020-01-06T21:39:58.947Z,1578346798.947 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2020-01-06T21:39:58.950Z,1578346798.950 [BPC1](INFO): Received data from all battery sticks. 2020-01-06T21:40:05.418Z,1578346805.418 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-01-06T21:35:05.2Z 2020-01-06T21:40:05.418Z,1578346805.418 [Default:CheckIn:Read_GPS] Stopped 2020-01-06T21:40:05.418Z,1578346805.418 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-01-06T21:40:13.013Z,1578346813.013 [DataOverHttps](INFO): Sending 45 bytes from file Logs/20200106T195438/Courier0042.lzma 2020-01-06T21:40:15.019Z,1578346815.019 [DataOverHttps](INFO): Moved sent file to Logs/20200106T195438/Courier0042.lzma.bak 2020-01-06T21:40:15.020Z,1578346815.020 [DataOverHttps](INFO): SBD MOMSN=12185537 2020-01-06T21:40:32.201Z,1578346832.201 [DataOverHttps](INFO): Sending 218 bytes from file Logs/20200106T195438/Express0043.lzma 2020-01-06T21:40:34.207Z,1578346834.207 [DataOverHttps](INFO): Moved sent file to Logs/20200106T195438/Express0043.lzma.bak 2020-01-06T21:40:34.207Z,1578346834.207 [DataOverHttps](INFO): SBD MOMSN=12185539 2020-01-06T21:40:35.725Z,1578346835.725 [Default:CheckIn:Read_Iridium] Stopped 2020-01-06T21:40:35.725Z,1578346835.726 [Default:CheckIn:C.Wait] Running Loop=1 2020-01-06T21:40:35.726Z,1578346835.726 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-01-06T21:40:51.845Z,1578346851.845 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2020-01-06T21:41:22.547Z,1578346882.547 [NAL9602](INFO): Not Powering down - fast GPS 2020-01-06T21:45:36.326Z,1578347136.326 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-01-06T21:45:36.326Z,1578347136.326 [Default:CheckIn:C.Wait] Stopped 2020-01-06T21:45:36.326Z,1578347136.326 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-01-06T21:45:36.326Z,1578347136.326 [Default:CheckIn:D] Running Loop=1 2020-01-06T21:45:36.726Z,1578347136.726 [Default:CheckIn:D] Stopped 2020-01-06T21:45:36.726Z,1578347136.726 [Default:CheckIn:E] Running Loop=1 2020-01-06T21:45:37.131Z,1578347137.131 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 139.132129 min 2020-01-06T21:45:37.131Z,1578347137.131 [Default:CheckIn:E] Stopped 2020-01-06T21:45:37.131Z,1578347137.131 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-01-06T21:45:37.131Z,1578347137.131 [Default:CheckIn] Stopped 2020-01-06T21:45:37.131Z,1578347137.131 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-01-06T21:45:37.132Z,1578347137.132 [Default:CheckIn](INFO): Running loop #20 2020-01-06T21:45:37.132Z,1578347137.132 [Default:CheckIn] Running Loop=20 2020-01-06T21:45:37.132Z,1578347137.132 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-01-06T21:45:37.132Z,1578347137.132 [Default:CheckIn:Read_GPS] Running Loop=1 2020-01-06T21:45:39.128Z,1578347139.128 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,214152.00,A,3648.16893,N,12147.28268,W,1.069,269.74,060120,,,D*76 2020-01-06T21:45:39.130Z,1578347139.130 [NAL9602](INFO): GPS fix at 20200106T214152: (36.802816, -121.788045) 2020-01-06T21:45:39.154Z,1578347139.154 [Default:CheckIn:Read_GPS] Stopped 2020-01-06T21:45:39.154Z,1578347139.154 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-01-06T21:45:46.737Z,1578347146.737 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20200106T195438/Courier0045.lzma 2020-01-06T21:45:48.743Z,1578347148.743 [DataOverHttps](INFO): Moved sent file to Logs/20200106T195438/Courier0045.lzma.bak 2020-01-06T21:45:48.743Z,1578347148.743 [DataOverHttps](INFO): SBD MOMSN=12185541 2020-01-06T21:46:08.694Z,1578347168.694 [DataOverHttps](INFO): Sending 198 bytes from file Logs/20200106T195438/Express0046.lzma 2020-01-06T21:46:09.820Z,1578347169.820 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2020-01-06T21:46:09.893Z,1578347169.893 [NAL9602](FAULT): received: +CSQ:0 OK953, 2, 0, 0, 0 OK 2020-01-06T21:46:09.893Z,1578347169.893 [NAL9602] Data Fault, FailCount= 3 2020-01-06T21:46:09.893Z,1578347169.893 [NAL9602](ERROR): Data Fault 2020-01-06T21:46:09.929Z,1578347169.929 [CBIT](ERROR): Data Fault in component: NAL9602 2020-01-06T21:46:10.226Z,1578347170.226 [NAL9602](INFO): Powering down 2020-01-06T21:46:10.630Z,1578347170.630 [NAL9602](FAULT): LCB fault: Software Overcurrent. 2020-01-06T21:46:10.630Z,1578347170.630 [NAL9602] Hardware Fault, FailCount= 3 2020-01-06T21:46:10.630Z,1578347170.630 [NAL9602](ERROR): Hardware Fault 2020-01-06T21:46:10.699Z,1578347170.699 [DataOverHttps](INFO): Moved sent file to Logs/20200106T195438/Express0046.lzma.bak 2020-01-06T21:46:10.699Z,1578347170.699 [DataOverHttps](INFO): SBD MOMSN=12185544 2020-01-06T21:46:11.129Z,1578347171.129 [CBIT](INFO): Clearing failed state for component NAL9602 2020-01-06T21:46:11.129Z,1578347171.129 [NAL9602] No Fault, FailCount= 3 2020-01-06T21:46:11.869Z,1578347171.869 [Default:CheckIn:Read_Iridium] Stopped 2020-01-06T21:46:11.869Z,1578347171.869 [Default:CheckIn:C.Wait] Running Loop=1 2020-01-06T21:46:11.869Z,1578347171.869 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-01-06T21:46:40.524Z,1578347200.524 [NAL9602](INFO): Powering up NAL9602 2020-01-06T21:46:51.438Z,1578347211.438 [NAL9602](INFO): NAL9602 initialized 2020-01-06T21:47:22.540Z,1578347242.540 [NAL9602](INFO): Not Powering down - fast GPS 2020-01-06T21:51:12.448Z,1578347472.448 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-01-06T21:51:12.449Z,1578347472.449 [Default:CheckIn:C.Wait] Stopped 2020-01-06T21:51:12.449Z,1578347472.449 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-01-06T21:51:12.449Z,1578347472.449 [Default:CheckIn:D] Running Loop=1 2020-01-06T21:51:12.860Z,1578347472.860 [Default:CheckIn:D] Stopped 2020-01-06T21:51:12.860Z,1578347472.860 [Default:CheckIn:E] Running Loop=1 2020-01-06T21:51:13.265Z,1578347473.265 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 144.734375 min 2020-01-06T21:51:13.265Z,1578347473.265 [Default:CheckIn:E] Stopped 2020-01-06T21:51:13.265Z,1578347473.265 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-01-06T21:51:13.265Z,1578347473.265 [Default:CheckIn] Stopped 2020-01-06T21:51:13.266Z,1578347473.266 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-01-06T21:51:13.266Z,1578347473.266 [Default:CheckIn](INFO): Running loop #21 2020-01-06T21:51:13.266Z,1578347473.266 [Default:CheckIn] Running Loop=21 2020-01-06T21:51:13.266Z,1578347473.266 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-01-06T21:51:13.266Z,1578347473.266 [Default:CheckIn:Read_GPS] Running Loop=1 2020-01-06T21:51:17.674Z,1578347477.674 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2020-01-06T21:56:13.438Z,1578347773.438 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-01-06T21:51:13.3Z 2020-01-06T21:56:13.438Z,1578347773.438 [Default:CheckIn:Read_GPS] Stopped 2020-01-06T21:56:13.438Z,1578347773.438 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-01-06T21:56:22.797Z,1578347782.797 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20200106T195438/Courier0048.lzma 2020-01-06T21:56:24.803Z,1578347784.803 [DataOverHttps](INFO): Moved sent file to Logs/20200106T195438/Courier0048.lzma.bak 2020-01-06T21:56:24.803Z,1578347784.803 [DataOverHttps](INFO): SBD MOMSN=12185546 2020-01-06T21:56:41.805Z,1578347801.805 [DataOverHttps](INFO): Sending 270 bytes from file Logs/20200106T195438/Express0049.lzma 2020-01-06T21:56:43.811Z,1578347803.811 [DataOverHttps](INFO): Moved sent file to Logs/20200106T195438/Express0049.lzma.bak 2020-01-06T21:56:43.811Z,1578347803.811 [DataOverHttps](INFO): SBD MOMSN=12185548 2020-01-06T21:56:44.514Z,1578347804.514 [NAL9602](INFO): Not Powering down - fast GPS 2020-01-06T21:56:45.340Z,1578347805.340 [Default:CheckIn:Read_Iridium] Stopped 2020-01-06T21:56:45.340Z,1578347805.340 [Default:CheckIn:C.Wait] Running Loop=1 2020-01-06T21:56:45.340Z,1578347805.340 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-01-06T22:01:45.933Z,1578348105.933 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-01-06T22:01:45.933Z,1578348105.933 [Default:CheckIn:C.Wait] Stopped 2020-01-06T22:01:45.933Z,1578348105.933 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-01-06T22:01:45.933Z,1578348105.933 [Default:CheckIn:D] Running Loop=1 2020-01-06T22:01:46.321Z,1578348106.321 [Default:CheckIn:D] Stopped 2020-01-06T22:01:46.322Z,1578348106.322 [Default:CheckIn:E] Running Loop=1 2020-01-06T22:01:46.734Z,1578348106.734 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 155.292057 min 2020-01-06T22:01:46.734Z,1578348106.734 [Default:CheckIn:E] Stopped 2020-01-06T22:01:46.735Z,1578348106.735 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-01-06T22:01:46.735Z,1578348106.735 [Default:CheckIn] Stopped 2020-01-06T22:01:46.735Z,1578348106.735 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-01-06T22:01:46.735Z,1578348106.735 [Default:CheckIn](INFO): Running loop #22 2020-01-06T22:01:46.735Z,1578348106.735 [Default:CheckIn] Running Loop=22 2020-01-06T22:01:46.735Z,1578348106.735 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-01-06T22:01:46.735Z,1578348106.735 [Default:CheckIn:Read_GPS] Running Loop=1 2020-01-06T22:01:48.322Z,1578348108.322 [NAL9602](FAULT): GPS failed to acquire within timeout. 2020-01-06T22:01:48.322Z,1578348108.322 [NAL9602] Data Fault, FailCount= 1 2020-01-06T22:01:48.322Z,1578348108.322 [NAL9602](ERROR): Data Fault 2020-01-06T22:01:48.355Z,1578348108.355 [CBIT](ERROR): Data Fault in component: NAL9602 2020-01-06T22:01:48.722Z,1578348108.722 [NAL9602](INFO): Powering down 2020-01-06T22:01:49.590Z,1578348109.590 [CBIT](INFO): Clearing failed state for component NAL9602 2020-01-06T22:01:49.590Z,1578348109.590 [NAL9602] No Fault, FailCount= 1 2020-01-06T22:02:19.026Z,1578348139.026 [NAL9602](INFO): Powering up NAL9602 2020-01-06T22:02:29.940Z,1578348149.940 [NAL9602](INFO): NAL9602 initialized 2020-01-06T22:06:46.918Z,1578348406.918 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-01-06T22:01:46.7Z 2020-01-06T22:06:46.918Z,1578348406.918 [Default:CheckIn:Read_GPS] Stopped 2020-01-06T22:06:46.919Z,1578348406.919 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-01-06T22:06:54.253Z,1578348414.253 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20200106T195438/Courier0051.lzma 2020-01-06T22:06:56.259Z,1578348416.259 [DataOverHttps](INFO): Moved sent file to Logs/20200106T195438/Courier0051.lzma.bak 2020-01-06T22:06:56.259Z,1578348416.259 [DataOverHttps](INFO): SBD MOMSN=12185550 2020-01-06T22:07:13.185Z,1578348433.185 [DataOverHttps](INFO): Sending 163 bytes from file Logs/20200106T195438/Express0052.lzma 2020-01-06T22:07:15.191Z,1578348435.191 [DataOverHttps](INFO): Moved sent file to Logs/20200106T195438/Express0052.lzma.bak 2020-01-06T22:07:15.191Z,1578348435.191 [DataOverHttps](INFO): SBD MOMSN=12185552 2020-01-06T22:07:16.402Z,1578348436.402 [Default:CheckIn:Read_Iridium] Stopped 2020-01-06T22:07:16.402Z,1578348436.402 [Default:CheckIn:C.Wait] Running Loop=1 2020-01-06T22:07:16.402Z,1578348436.402 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-01-06T22:07:33.343Z,1578348453.343 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2020-01-06T22:08:04.042Z,1578348484.042 [NAL9602](INFO): Not Powering down - fast GPS 2020-01-06T22:12:16.971Z,1578348736.971 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-01-06T22:12:16.971Z,1578348736.971 [Default:CheckIn:C.Wait] Stopped 2020-01-06T22:12:16.971Z,1578348736.971 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-01-06T22:12:16.972Z,1578348736.972 [Default:CheckIn:D] Running Loop=1 2020-01-06T22:12:17.390Z,1578348737.390 [Default:CheckIn:D] Stopped 2020-01-06T22:12:17.390Z,1578348737.390 [Default:CheckIn:E] Running Loop=1 2020-01-06T22:12:17.773Z,1578348737.773 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 165.809863 min 2020-01-06T22:12:17.773Z,1578348737.773 [Default:CheckIn:E] Stopped 2020-01-06T22:12:17.773Z,1578348737.773 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-01-06T22:12:17.773Z,1578348737.773 [Default:CheckIn] Stopped 2020-01-06T22:12:17.774Z,1578348737.774 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-01-06T22:12:17.774Z,1578348737.774 [Default:CheckIn](INFO): Running loop #23 2020-01-06T22:12:17.774Z,1578348737.774 [Default:CheckIn] Running Loop=23 2020-01-06T22:12:17.774Z,1578348737.774 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-01-06T22:12:17.774Z,1578348737.774 [Default:CheckIn:Read_GPS] Running Loop=1 2020-01-06T22:12:50.484Z,1578348770.484 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2020-01-06T22:12:50.561Z,1578348770.561 [NAL9602](FAULT): received: +CSQ:0 OK953, 2, 0, 0, 0 OK 2020-01-06T22:12:50.561Z,1578348770.561 [NAL9602] Data Fault, FailCount= 2 2020-01-06T22:12:50.561Z,1578348770.561 [NAL9602](ERROR): Data Fault 2020-01-06T22:12:50.622Z,1578348770.622 [CBIT](ERROR): Data Fault in component: NAL9602 2020-01-06T22:12:50.878Z,1578348770.878 [NAL9602](INFO): Powering down 2020-01-06T22:12:51.721Z,1578348771.721 [CBIT](INFO): Clearing failed state for component NAL9602 2020-01-06T22:12:51.721Z,1578348771.721 [NAL9602] No Fault, FailCount= 2 2020-01-06T22:13:21.176Z,1578348801.176 [NAL9602](INFO): Powering up NAL9602 2020-01-06T22:13:32.094Z,1578348812.094 [NAL9602](INFO): NAL9602 initialized 2020-01-06T22:13:32.898Z,1578348812.898 [NAL9602](FAULT): GPS failed to acquire within timeout. 2020-01-06T22:13:32.898Z,1578348812.898 [NAL9602] Data Fault, FailCount= 3 2020-01-06T22:13:32.898Z,1578348812.898 [NAL9602](ERROR): Data Fault 2020-01-06T22:13:32.970Z,1578348812.970 [CBIT](ERROR): Data Fault in component: NAL9602 2020-01-06T22:13:33.302Z,1578348813.302 [NAL9602](INFO): Powering down 2020-01-06T22:13:34.157Z,1578348814.157 [CBIT](INFO): Clearing failed state for component NAL9602 2020-01-06T22:13:34.157Z,1578348814.157 [NAL9602] No Fault, FailCount= 3 2020-01-06T22:14:03.598Z,1578348843.598 [NAL9602](INFO): Powering up NAL9602 2020-01-06T22:14:14.510Z,1578348854.510 [NAL9602](INFO): NAL9602 initialized 2020-01-06T22:17:17.965Z,1578349037.965 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-01-06T22:12:17.8Z 2020-01-06T22:17:17.965Z,1578349037.965 [Default:CheckIn:Read_GPS] Stopped 2020-01-06T22:17:17.965Z,1578349037.965 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-01-06T22:17:21.558Z,1578349041.558 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2020-01-06T22:17:25.893Z,1578349045.893 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20200106T195438/Courier0054.lzma 2020-01-06T22:17:27.923Z,1578349047.923 [DataOverHttps](INFO): Moved sent file to Logs/20200106T195438/Courier0054.lzma.bak 2020-01-06T22:17:27.923Z,1578349047.923 [DataOverHttps](INFO): SBD MOMSN=12185554 2020-01-06T22:17:44.749Z,1578349064.749 [DataOverHttps](INFO): Sending 256 bytes from file Logs/20200106T195438/Express0055.lzma 2020-01-06T22:17:46.755Z,1578349066.755 [DataOverHttps](INFO): Moved sent file to Logs/20200106T195438/Express0055.lzma.bak 2020-01-06T22:17:46.755Z,1578349066.755 [DataOverHttps](INFO): SBD MOMSN=12185556 2020-01-06T22:17:48.269Z,1578349068.269 [Default:CheckIn:Read_Iridium] Stopped 2020-01-06T22:17:48.269Z,1578349068.269 [Default:CheckIn:C.Wait] Running Loop=1 2020-01-06T22:17:48.269Z,1578349068.269 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-01-06T22:17:52.274Z,1578349072.274 [NAL9602](INFO): Not Powering down - fast GPS 2020-01-06T22:22:48.841Z,1578349368.841 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-01-06T22:22:48.841Z,1578349368.841 [Default:CheckIn:C.Wait] Stopped 2020-01-06T22:22:48.841Z,1578349368.841 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-01-06T22:22:48.841Z,1578349368.841 [Default:CheckIn:D] Running Loop=1 2020-01-06T22:22:49.246Z,1578349369.246 [Default:CheckIn:D] Stopped 2020-01-06T22:22:49.246Z,1578349369.246 [Default:CheckIn:E] Running Loop=1 2020-01-06T22:22:49.647Z,1578349369.647 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 176.340804 min 2020-01-06T22:22:49.647Z,1578349369.647 [Default:CheckIn:E] Stopped 2020-01-06T22:22:49.647Z,1578349369.647 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-01-06T22:22:49.647Z,1578349369.647 [Default:CheckIn] Stopped 2020-01-06T22:22:49.647Z,1578349369.647 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-01-06T22:22:49.648Z,1578349369.648 [Default:CheckIn](INFO): Running loop #24 2020-01-06T22:22:49.648Z,1578349369.648 [Default:CheckIn] Running Loop=24 2020-01-06T22:22:49.648Z,1578349369.648 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-01-06T22:22:49.648Z,1578349369.648 [Default:CheckIn:Read_GPS] Running Loop=1 2020-01-06T22:23:22.340Z,1578349402.340 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2020-01-06T22:23:22.413Z,1578349402.413 [NAL9602](FAULT): received: +CSQ:0 OK953, 2, 0, 0, 0 OK 2020-01-06T22:23:22.413Z,1578349402.413 [NAL9602] Data Fault, FailCount= 4 2020-01-06T22:23:22.413Z,1578349402.413 [NAL9602](ERROR): Data Fault 2020-01-06T22:23:22.478Z,1578349402.478 [CBIT](ERROR): Data Fault in component: NAL9602 2020-01-06T22:23:22.754Z,1578349402.754 [NAL9602](INFO): Powering down 2020-01-06T22:23:23.604Z,1578349403.604 [CBIT](INFO): Clearing failed state for component NAL9602 2020-01-06T22:23:23.604Z,1578349403.604 [NAL9602] No Fault, FailCount= 4 2020-01-06T22:23:53.055Z,1578349433.055 [NAL9602](INFO): Powering up NAL9602 2020-01-06T22:24:03.966Z,1578349443.966 [NAL9602](INFO): NAL9602 initialized 2020-01-06T22:27:35.256Z,1578349655.256 [NAL9602](INFO): SBD MO Status=2, MOMSN=18953, MT Status=2, MTMSN=0 2020-01-06T22:27:35.256Z,1578349655.256 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2020-01-06T22:27:49.822Z,1578349669.822 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-01-06T22:22:49.6Z 2020-01-06T22:27:49.822Z,1578349669.822 [Default:CheckIn:Read_GPS] Stopped 2020-01-06T22:27:49.822Z,1578349669.822 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-01-06T22:27:53.838Z,1578349673.838 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2020-01-06T22:27:57.621Z,1578349677.621 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20200106T195438/Courier0057.lzma 2020-01-06T22:27:59.627Z,1578349679.627 [DataOverHttps](INFO): Moved sent file to Logs/20200106T195438/Courier0057.lzma.bak 2020-01-06T22:27:59.627Z,1578349679.627 [DataOverHttps](INFO): SBD MOMSN=12185558 2020-01-06T22:28:16.901Z,1578349696.901 [DataOverHttps](INFO): Sending 239 bytes from file Logs/20200106T195438/Express0058.lzma 2020-01-06T22:28:18.908Z,1578349698.908 [DataOverHttps](INFO): Moved sent file to Logs/20200106T195438/Express0058.lzma.bak 2020-01-06T22:28:18.908Z,1578349698.908 [DataOverHttps](INFO): SBD MOMSN=12185560 2020-01-06T22:28:20.130Z,1578349700.130 [Default:CheckIn:Read_Iridium] Stopped 2020-01-06T22:28:20.130Z,1578349700.130 [Default:CheckIn:C.Wait] Running Loop=1 2020-01-06T22:28:20.131Z,1578349700.131 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-01-06T22:28:24.554Z,1578349704.554 [NAL9602](INFO): Not Powering down - fast GPS 2020-01-06T22:33:20.719Z,1578350000.719 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-01-06T22:33:20.719Z,1578350000.719 [Default:CheckIn:C.Wait] Stopped 2020-01-06T22:33:20.719Z,1578350000.719 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-01-06T22:33:20.720Z,1578350000.720 [Default:CheckIn:D] Running Loop=1 2020-01-06T22:33:21.126Z,1578350001.126 [Default:CheckIn:D] Stopped 2020-01-06T22:33:21.126Z,1578350001.126 [Default:CheckIn:E] Running Loop=1 2020-01-06T22:33:21.538Z,1578350001.538 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 186.872119 min 2020-01-06T22:33:21.538Z,1578350001.538 [Default:CheckIn:E] Stopped 2020-01-06T22:33:21.538Z,1578350001.538 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-01-06T22:33:21.539Z,1578350001.539 [Default:CheckIn] Stopped 2020-01-06T22:33:21.539Z,1578350001.539 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-01-06T22:33:21.539Z,1578350001.539 [Default:CheckIn](INFO): Running loop #25 2020-01-06T22:33:21.539Z,1578350001.539 [Default:CheckIn] Running Loop=25 2020-01-06T22:33:21.539Z,1578350001.539 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-01-06T22:33:21.539Z,1578350001.539 [Default:CheckIn:Read_GPS] Running Loop=1 2020-01-06T22:33:23.118Z,1578350003.118 [NAL9602](FAULT): GPS failed to acquire within timeout. 2020-01-06T22:33:23.118Z,1578350003.118 [NAL9602] Data Fault, FailCount= 5 2020-01-06T22:33:23.118Z,1578350003.118 [NAL9602](ERROR): Data Fault 2020-01-06T22:33:23.275Z,1578350003.275 [CBIT](ERROR): Data Fault in component: NAL9602 2020-01-06T22:33:23.276Z,1578350003.276 [CBIT](CRITICAL): Data Fault in component: NAL9602 2020-01-06T22:33:23.522Z,1578350003.522 [NAL9602](INFO): Powering down 2020-01-06T22:33:23.590Z,1578350003.590 [CommandLine](FAULT): Scheduling is paused 2020-01-06T22:33:23.591Z,1578350003.591 [CBIT](INFO): Critical error at 20200106T223323 2020-01-06T22:35:23.175Z,1578350123.175 [CBIT](INFO): Clearing failed state for component NAL9602 2020-01-06T22:35:23.175Z,1578350123.175 [NAL9602] No Fault, FailCount= 5 2020-01-06T22:35:23.536Z,1578350123.536 [NAL9602](INFO): Powering up NAL9602 2020-01-06T22:35:34.444Z,1578350134.444 [NAL9602](INFO): NAL9602 initialized 2020-01-06T22:36:58.884Z,1578350218.884 [NAL9602](INFO): SBD MO Status=2, MOMSN=18953, MT Status=2, MTMSN=0 2020-01-06T22:36:58.884Z,1578350218.884 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2020-01-06T22:37:49.387Z,1578350269.387 [NAL9602](INFO): SBD MO Status=2, MOMSN=18953, MT Status=2, MTMSN=0 2020-01-06T22:37:49.388Z,1578350269.388 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2020-01-06T22:38:21.730Z,1578350301.730 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-01-06T22:33:21.5Z 2020-01-06T22:38:21.730Z,1578350301.730 [Default:CheckIn:Read_GPS] Stopped 2020-01-06T22:38:21.730Z,1578350301.730 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-01-06T22:38:28.994Z,1578350308.994 [DataOverHttps](INFO): Sending 92 bytes from file Logs/20200106T195438/Courier0060.lzma 2020-01-06T22:38:30.995Z,1578350310.995 [DataOverHttps](INFO): Moved sent file to Logs/20200106T195438/Courier0060.lzma.bak 2020-01-06T22:38:30.995Z,1578350310.995 [DataOverHttps](INFO): SBD MOMSN=12185562 2020-01-06T22:38:47.964Z,1578350327.964 [NAL9602](INFO): SBD MO Status=0, MOMSN=18953, MT Status=0, MTMSN=0 2020-01-06T22:38:47.964Z,1578350327.964 [NAL9602](INFO): No messages in MT queue 2020-01-06T22:38:47.964Z,1578350327.964 [NAL9602](INFO): Failure count cleared after critical for NAL9602 2020-01-06T22:38:48.357Z,1578350328.357 [DataOverHttps](INFO): Sending 240 bytes from file Logs/20200106T195438/Express0061.lzma 2020-01-06T22:38:50.363Z,1578350330.363 [DataOverHttps](INFO): Moved sent file to Logs/20200106T195438/Express0061.lzma.bak 2020-01-06T22:38:50.363Z,1578350330.363 [DataOverHttps](INFO): SBD MOMSN=12185564 2020-01-06T22:38:51.637Z,1578350331.637 [Default:CheckIn:Read_Iridium] Stopped 2020-01-06T22:38:51.637Z,1578350331.637 [Default:CheckIn:C.Wait] Running Loop=1 2020-01-06T22:38:51.637Z,1578350331.637 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-01-06T22:39:18.670Z,1578350358.670 [NAL9602](INFO): Not Powering down - fast GPS 2020-01-06T22:43:07.359Z,1578350587.359 [BPC1](ERROR): BPC1B: No match for serial number 1717 in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file). 2020-01-06T22:43:52.203Z,1578350632.203 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-01-06T22:43:52.203Z,1578350632.203 [Default:CheckIn:C.Wait] Stopped 2020-01-06T22:43:52.204Z,1578350632.204 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-01-06T22:43:52.204Z,1578350632.204 [Default:CheckIn:D] Running Loop=1 2020-01-06T22:43:52.602Z,1578350632.602 [Default:CheckIn:D] Stopped 2020-01-06T22:43:52.602Z,1578350632.602 [Default:CheckIn:E] Running Loop=1 2020-01-06T22:43:53.019Z,1578350633.019 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 197.396745 min 2020-01-06T22:43:53.020Z,1578350633.020 [Default:CheckIn:E] Stopped 2020-01-06T22:43:53.020Z,1578350633.020 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-01-06T22:43:53.020Z,1578350633.020 [Default:CheckIn] Stopped 2020-01-06T22:43:53.020Z,1578350633.020 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-01-06T22:43:53.020Z,1578350633.020 [Default:CheckIn](INFO): Running loop #26 2020-01-06T22:43:53.020Z,1578350633.020 [Default:CheckIn] Running Loop=26 2020-01-06T22:43:53.020Z,1578350633.020 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-01-06T22:43:53.020Z,1578350633.020 [Default:CheckIn:Read_GPS] Running Loop=1 2020-01-06T22:47:24.691Z,1578350844.691 [NAL9602](INFO): SBD MO Status=2, MOMSN=18954, MT Status=2, MTMSN=0 2020-01-06T22:47:24.691Z,1578350844.691 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2020-01-06T22:47:28.345Z,1578350848.345 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2020-01-06T22:47:28.347Z,1578350848.347 [BPC1](INFO): Received data from all battery sticks. 2020-01-06T22:48:15.583Z,1578350895.583 [NAL9602](INFO): SBD MO Status=0, MOMSN=18954, MT Status=0, MTMSN=0 2020-01-06T22:48:15.584Z,1578350895.584 [NAL9602](INFO): No messages in MT queue 2020-01-06T22:48:16.394Z,1578350896.394 [NAL9602](FAULT): GPS failed to acquire within timeout. 2020-01-06T22:48:16.394Z,1578350896.394 [NAL9602] Data Fault, FailCount= 1 2020-01-06T22:48:16.395Z,1578350896.395 [NAL9602](ERROR): Data Fault 2020-01-06T22:48:16.427Z,1578350896.427 [CBIT](ERROR): Data Fault in component: NAL9602 2020-01-06T22:48:16.794Z,1578350896.794 [NAL9602](INFO): Powering down 2020-01-06T22:48:17.662Z,1578350897.662 [CBIT](INFO): Clearing failed state for component NAL9602 2020-01-06T22:48:17.662Z,1578350897.662 [NAL9602] No Fault, FailCount= 1 2020-01-06T22:48:47.096Z,1578350927.096 [NAL9602](INFO): Powering up NAL9602 2020-01-06T22:48:53.175Z,1578350933.175 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-01-06T22:43:53.0Z 2020-01-06T22:48:53.175Z,1578350933.175 [Default:CheckIn:Read_GPS] Stopped 2020-01-06T22:48:53.175Z,1578350933.175 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-01-06T22:48:58.002Z,1578350938.002 [NAL9602](INFO): NAL9602 initialized 2020-01-06T22:49:01.165Z,1578350941.165 [DataOverHttps](INFO): Sending 45 bytes from file Logs/20200106T195438/Courier0063.lzma 2020-01-06T22:49:03.171Z,1578350943.171 [DataOverHttps](INFO): Moved sent file to Logs/20200106T195438/Courier0063.lzma.bak 2020-01-06T22:49:03.171Z,1578350943.171 [DataOverHttps](INFO): SBD MOMSN=12185567 2020-01-06T22:49:20.161Z,1578350960.161 [DataOverHttps](INFO): Sending 163 bytes from file Logs/20200106T195438/Express0064.lzma 2020-01-06T22:49:22.167Z,1578350962.167 [DataOverHttps](INFO): Moved sent file to Logs/20200106T195438/Express0064.lzma.bak 2020-01-06T22:49:22.167Z,1578350962.167 [DataOverHttps](INFO): SBD MOMSN=12185569 2020-01-06T22:49:23.488Z,1578350963.488 [Default:CheckIn:Read_Iridium] Stopped 2020-01-06T22:49:23.488Z,1578350963.488 [Default:CheckIn:C.Wait] Running Loop=1 2020-01-06T22:49:23.488Z,1578350963.488 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-01-06T22:49:29.118Z,1578350969.118 [NAL9602](INFO): Not Powering down - fast GPS 2020-01-06T22:54:24.057Z,1578351264.057 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-01-06T22:54:24.057Z,1578351264.057 [Default:CheckIn:C.Wait] Stopped 2020-01-06T22:54:24.057Z,1578351264.057 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-01-06T22:54:24.057Z,1578351264.057 [Default:CheckIn:D] Running Loop=1 2020-01-06T22:54:24.458Z,1578351264.458 [Default:CheckIn:D] Stopped 2020-01-06T22:54:24.458Z,1578351264.458 [Default:CheckIn:E] Running Loop=1 2020-01-06T22:54:24.874Z,1578351264.874 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 207.927669 min 2020-01-06T22:54:24.874Z,1578351264.874 [Default:CheckIn:E] Stopped 2020-01-06T22:54:24.874Z,1578351264.874 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-01-06T22:54:24.874Z,1578351264.874 [Default:CheckIn] Stopped 2020-01-06T22:54:24.875Z,1578351264.875 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-01-06T22:54:24.875Z,1578351264.875 [Default:CheckIn](INFO): Running loop #27 2020-01-06T22:54:24.875Z,1578351264.875 [Default:CheckIn] Running Loop=27 2020-01-06T22:54:24.875Z,1578351264.875 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-01-06T22:54:24.875Z,1578351264.875 [Default:CheckIn:Read_GPS] Running Loop=1 2020-01-06T22:57:37.548Z,1578351457.548 [NAL9602](INFO): SBD MO Status=0, MOMSN=18955, MT Status=0, MTMSN=0 2020-01-06T22:57:37.548Z,1578351457.548 [NAL9602](INFO): No messages in MT queue 2020-01-06T22:59:25.045Z,1578351565.045 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-01-06T22:54:24.9Z 2020-01-06T22:59:25.045Z,1578351565.045 [Default:CheckIn:Read_GPS] Stopped 2020-01-06T22:59:25.046Z,1578351565.046 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-01-06T22:59:32.833Z,1578351572.833 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20200106T195438/Courier0066.lzma 2020-01-06T22:59:34.839Z,1578351574.839 [DataOverHttps](INFO): Moved sent file to Logs/20200106T195438/Courier0066.lzma.bak 2020-01-06T22:59:34.839Z,1578351574.839 [DataOverHttps](INFO): SBD MOMSN=12185572 2020-01-06T22:59:53.413Z,1578351593.413 [DataOverHttps](INFO): Sending 123 bytes from file Logs/20200106T195438/Express0067.lzma 2020-01-06T22:59:55.419Z,1578351595.419 [DataOverHttps](INFO): Moved sent file to Logs/20200106T195438/Express0067.lzma.bak 2020-01-06T22:59:55.419Z,1578351595.419 [DataOverHttps](INFO): SBD MOMSN=12185574 2020-01-06T22:59:56.150Z,1578351596.150 [NAL9602](INFO): Not Powering down - fast GPS 2020-01-06T22:59:56.989Z,1578351596.989 [Default:CheckIn:Read_Iridium] Stopped 2020-01-06T22:59:56.989Z,1578351596.989 [Default:CheckIn:C.Wait] Running Loop=1 2020-01-06T22:59:56.989Z,1578351596.989 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-01-06T23:04:57.573Z,1578351897.573 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-01-06T23:04:57.573Z,1578351897.573 [Default:CheckIn:C.Wait] Stopped 2020-01-06T23:04:57.573Z,1578351897.573 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-01-06T23:04:57.574Z,1578351897.574 [Default:CheckIn:D] Running Loop=1 2020-01-06T23:04:57.978Z,1578351897.978 [Default:CheckIn:D] Stopped 2020-01-06T23:04:57.978Z,1578351897.978 [Default:CheckIn:E] Running Loop=1 2020-01-06T23:04:58.388Z,1578351898.388 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 218.486328 min 2020-01-06T23:04:58.388Z,1578351898.388 [Default:CheckIn:E] Stopped 2020-01-06T23:04:58.388Z,1578351898.388 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-01-06T23:04:58.388Z,1578351898.388 [Default:CheckIn] Stopped 2020-01-06T23:04:58.388Z,1578351898.388 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-01-06T23:04:58.388Z,1578351898.388 [Default:CheckIn](INFO): Running loop #28 2020-01-06T23:04:58.388Z,1578351898.388 [Default:CheckIn] Running Loop=28 2020-01-06T23:04:58.389Z,1578351898.389 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-01-06T23:04:58.389Z,1578351898.389 [Default:CheckIn:Read_GPS] Running Loop=1 2020-01-06T23:04:59.966Z,1578351899.966 [NAL9602](FAULT): GPS failed to acquire within timeout. 2020-01-06T23:04:59.967Z,1578351899.967 [NAL9602] Data Fault, FailCount= 1 2020-01-06T23:04:59.967Z,1578351899.967 [NAL9602](ERROR): Data Fault 2020-01-06T23:05:00.030Z,1578351900.030 [CBIT](ERROR): Data Fault in component: NAL9602 2020-01-06T23:05:00.374Z,1578351900.374 [NAL9602](INFO): Powering down 2020-01-06T23:05:01.284Z,1578351901.284 [CBIT](INFO): Clearing failed state for component NAL9602 2020-01-06T23:05:01.284Z,1578351901.284 [NAL9602] No Fault, FailCount= 1 2020-01-06T23:05:30.668Z,1578351930.668 [NAL9602](INFO): Powering up NAL9602 2020-01-06T23:05:41.618Z,1578351941.618 [NAL9602](INFO): NAL9602 initialized 2020-01-06T23:07:49.267Z,1578352069.267 [NAL9602](INFO): SBD MO Status=0, MOMSN=18956, MT Status=0, MTMSN=0 2020-01-06T23:07:49.268Z,1578352069.268 [NAL9602](INFO): No messages in MT queue 2020-01-06T23:08:46.690Z,1578352126.690 [CBIT](IMPORTANT): Beginning ground fault scan 2020-01-06T23:08:57.583Z,1578352137.583 [CBIT](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): -0.020327 CHAN A1 (24V): -0.180685 CHAN A2 (12V): -0.002447 CHAN A3 (5V): -0.001271 CHAN B0 (3.3V): -0.000513 CHAN B1 (3.15aV): -0.000455 CHAN B2 (3.15bV): -0.000223 CHAN B3 (GND): 0.000082 OPEN: -0.000280 Full Scale Calc: 4.765 mA, -1.589 mA 2020-01-06T23:09:58.583Z,1578352198.583 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-01-06T23:04:58.4Z 2020-01-06T23:09:58.583Z,1578352198.583 [Default:CheckIn:Read_GPS] Stopped 2020-01-06T23:09:58.583Z,1578352198.583 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-01-06T23:10:06.261Z,1578352206.261 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20200106T195438/Courier0069.lzma 2020-01-06T23:10:08.267Z,1578352208.267 [DataOverHttps](INFO): Moved sent file to Logs/20200106T195438/Courier0069.lzma.bak 2020-01-06T23:10:08.267Z,1578352208.267 [DataOverHttps](INFO): SBD MOMSN=12185577 2020-01-06T23:10:25.514Z,1578352225.514 [DataOverHttps](INFO): Sending 367 bytes from file Logs/20200106T195438/Express0070.lzma 2020-01-06T23:10:27.519Z,1578352227.519 [DataOverHttps](INFO): Moved sent file to Logs/20200106T195438/Express0070.lzma.bak 2020-01-06T23:10:27.519Z,1578352227.519 [DataOverHttps](INFO): SBD MOMSN=12185580 2020-01-06T23:10:28.910Z,1578352228.910 [Default:CheckIn:Read_Iridium] Stopped 2020-01-06T23:10:28.910Z,1578352228.910 [Default:CheckIn:C.Wait] Running Loop=1 2020-01-06T23:10:28.911Z,1578352228.911 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-01-06T23:10:30.068Z,1578352230.068 [NAL9602](INFO): Not Powering down - fast GPS 2020-01-06T23:15:29.465Z,1578352529.465 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-01-06T23:15:29.465Z,1578352529.465 [Default:CheckIn:C.Wait] Stopped 2020-01-06T23:15:29.465Z,1578352529.465 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-01-06T23:15:29.466Z,1578352529.466 [Default:CheckIn:D] Running Loop=1 2020-01-06T23:15:29.881Z,1578352529.881 [Default:CheckIn:D] Stopped 2020-01-06T23:15:29.881Z,1578352529.881 [Default:CheckIn:E] Running Loop=1 2020-01-06T23:15:30.279Z,1578352530.279 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 229.018050 min 2020-01-06T23:15:30.279Z,1578352530.279 [Default:CheckIn:E] Stopped 2020-01-06T23:15:30.279Z,1578352530.279 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-01-06T23:15:30.279Z,1578352530.279 [Default:CheckIn] Stopped 2020-01-06T23:15:30.279Z,1578352530.279 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-01-06T23:15:30.280Z,1578352530.280 [Default:CheckIn](INFO): Running loop #29 2020-01-06T23:15:30.280Z,1578352530.280 [Default:CheckIn] Running Loop=29 2020-01-06T23:15:30.280Z,1578352530.280 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-01-06T23:15:30.280Z,1578352530.280 [Default:CheckIn:Read_GPS] Running Loop=1 2020-01-06T23:15:32.264Z,1578352532.264 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,231136.00,A,3648.16876,N,12147.27800,W,0.058,44.67,060120,,,A*4A 2020-01-06T23:15:32.266Z,1578352532.266 [NAL9602](INFO): GPS fix at 20200106T231136: (36.802813, -121.787967) 2020-01-06T23:15:32.290Z,1578352532.290 [Default:CheckIn:Read_GPS] Stopped 2020-01-06T23:15:32.290Z,1578352532.290 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-01-06T23:15:40.370Z,1578352540.370 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20200106T195438/Courier0072.lzma 2020-01-06T23:15:42.376Z,1578352542.376 [DataOverHttps](INFO): Moved sent file to Logs/20200106T195438/Courier0072.lzma.bak 2020-01-06T23:15:42.376Z,1578352542.376 [DataOverHttps](INFO): SBD MOMSN=12185582 2020-01-06T23:15:59.330Z,1578352559.330 [DataOverHttps](INFO): Sending 121 bytes from file Logs/20200106T195438/Express0073.lzma 2020-01-06T23:16:01.343Z,1578352561.343 [DataOverHttps](INFO): Moved sent file to Logs/20200106T195438/Express0073.lzma.bak 2020-01-06T23:16:01.344Z,1578352561.344 [DataOverHttps](INFO): SBD MOMSN=12185585 2020-01-06T23:16:02.614Z,1578352562.614 [Default:CheckIn:Read_Iridium] Stopped 2020-01-06T23:16:02.614Z,1578352562.614 [Default:CheckIn:C.Wait] Running Loop=1 2020-01-06T23:16:02.614Z,1578352562.614 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-01-06T23:16:33.672Z,1578352593.672 [NAL9602](INFO): SBD MO Status=2, MOMSN=18957, MT Status=2, MTMSN=0 2020-01-06T23:16:33.672Z,1578352593.672 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2020-01-06T23:17:02.372Z,1578352622.372 [NAL9602](INFO): SBD MO Status=2, MOMSN=18957, MT Status=2, MTMSN=0 2020-01-06T23:17:02.372Z,1578352622.372 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2020-01-06T23:17:19.328Z,1578352639.328 [NAL9602](INFO): SBD MO Status=2, MOMSN=18957, MT Status=2, MTMSN=0 2020-01-06T23:17:19.328Z,1578352639.328 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2020-01-06T23:20:34.864Z,1578352834.864 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2020-01-06T23:21:03.185Z,1578352863.185 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-01-06T23:21:03.185Z,1578352863.185 [Default:CheckIn:C.Wait] Stopped 2020-01-06T23:21:03.185Z,1578352863.185 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-01-06T23:21:03.185Z,1578352863.185 [Default:CheckIn:D] Running Loop=1 2020-01-06T23:21:03.593Z,1578352863.593 [Default:CheckIn:D] Stopped 2020-01-06T23:21:03.593Z,1578352863.593 [Default:CheckIn:E] Running Loop=1 2020-01-06T23:21:03.975Z,1578352863.975 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 234.579915 min 2020-01-06T23:21:03.975Z,1578352863.975 [Default:CheckIn:E] Stopped 2020-01-06T23:21:03.975Z,1578352863.975 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-01-06T23:21:03.975Z,1578352863.975 [Default:CheckIn] Stopped 2020-01-06T23:21:03.976Z,1578352863.976 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-01-06T23:21:03.976Z,1578352863.976 [Default:CheckIn](INFO): Running loop #30 2020-01-06T23:21:03.976Z,1578352863.976 [Default:CheckIn] Running Loop=30 2020-01-06T23:21:03.976Z,1578352863.976 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-01-06T23:21:03.976Z,1578352863.976 [Default:CheckIn:Read_GPS] Running Loop=1 2020-01-06T23:21:05.980Z,1578352865.980 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,231710.00,A,3648.16371,N,12147.29103,W,0.233,44.67,060120,,,A*4F 2020-01-06T23:21:05.982Z,1578352865.982 [NAL9602](INFO): GPS fix at 20200106T231710: (36.802729, -121.788184) 2020-01-06T23:21:06.005Z,1578352866.005 [Default:CheckIn:Read_GPS] Stopped 2020-01-06T23:21:06.005Z,1578352866.005 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-01-06T23:21:13.801Z,1578352873.801 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20200106T195438/Courier0075.lzma 2020-01-06T23:21:15.807Z,1578352875.807 [DataOverHttps](INFO): Moved sent file to Logs/20200106T195438/Courier0075.lzma.bak 2020-01-06T23:21:15.807Z,1578352875.807 [DataOverHttps](INFO): SBD MOMSN=12185587 2020-01-06T23:21:32.774Z,1578352892.774 [DataOverHttps](INFO): Sending 211 bytes from file Logs/20200106T195438/Express0076.lzma 2020-01-06T23:21:34.779Z,1578352894.779 [DataOverHttps](INFO): Moved sent file to Logs/20200106T195438/Express0076.lzma.bak 2020-01-06T23:21:34.779Z,1578352894.779 [DataOverHttps](INFO): SBD MOMSN=12185590 2020-01-06T23:21:36.309Z,1578352896.309 [Default:CheckIn:Read_Iridium] Stopped 2020-01-06T23:21:36.310Z,1578352896.310 [Default:CheckIn:C.Wait] Running Loop=1 2020-01-06T23:21:36.310Z,1578352896.310 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-01-06T23:21:38.294Z,1578352898.294 [NAL9602](INFO): Not Powering down - fast GPS 2020-01-06T23:26:36.909Z,1578353196.909 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-01-06T23:26:36.909Z,1578353196.909 [Default:CheckIn:C.Wait] Stopped 2020-01-06T23:26:36.909Z,1578353196.909 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-01-06T23:26:36.909Z,1578353196.909 [Default:CheckIn:D] Running Loop=1 2020-01-06T23:26:37.315Z,1578353197.315 [Default:CheckIn:D] Stopped 2020-01-06T23:26:37.315Z,1578353197.315 [Default:CheckIn:E] Running Loop=1 2020-01-06T23:26:37.730Z,1578353197.730 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 240.141943 min 2020-01-06T23:26:37.730Z,1578353197.730 [Default:CheckIn:E] Stopped 2020-01-06T23:26:37.730Z,1578353197.730 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-01-06T23:26:37.730Z,1578353197.730 [Default:CheckIn] Stopped 2020-01-06T23:26:37.730Z,1578353197.730 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-01-06T23:26:37.731Z,1578353197.731 [Default:CheckIn](INFO): Running loop #31 2020-01-06T23:26:37.731Z,1578353197.731 [Default:CheckIn] Running Loop=31 2020-01-06T23:26:37.731Z,1578353197.731 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-01-06T23:26:37.731Z,1578353197.731 [Default:CheckIn:Read_GPS] Running Loop=1 2020-01-06T23:26:39.710Z,1578353199.710 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,232243.00,A,3648.17439,N,12147.28226,W,0.311,0.00,060120,,,A*70 2020-01-06T23:26:39.712Z,1578353199.712 [NAL9602](INFO): GPS fix at 20200106T232243: (36.802906, -121.788038) 2020-01-06T23:26:39.735Z,1578353199.735 [Default:CheckIn:Read_GPS] Stopped 2020-01-06T23:26:39.735Z,1578353199.735 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-01-06T23:26:47.793Z,1578353207.793 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20200106T195438/Courier0078.lzma 2020-01-06T23:26:49.799Z,1578353209.799 [DataOverHttps](INFO): Moved sent file to Logs/20200106T195438/Courier0078.lzma.bak 2020-01-06T23:26:49.799Z,1578353209.799 [DataOverHttps](INFO): SBD MOMSN=12185592 2020-01-06T23:27:06.837Z,1578353226.837 [DataOverHttps](INFO): Sending 121 bytes from file Logs/20200106T195438/Express0079.lzma 2020-01-06T23:27:08.851Z,1578353228.851 [DataOverHttps](INFO): Moved sent file to Logs/20200106T195438/Express0079.lzma.bak 2020-01-06T23:27:08.851Z,1578353228.851 [DataOverHttps](INFO): SBD MOMSN=12185595 2020-01-06T23:27:10.054Z,1578353230.054 [Default:CheckIn:Read_Iridium] Stopped 2020-01-06T23:27:10.055Z,1578353230.055 [Default:CheckIn:C.Wait] Running Loop=1 2020-01-06T23:27:10.055Z,1578353230.055 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-01-06T23:27:10.416Z,1578353230.416 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2020-01-06T23:27:10.493Z,1578353230.493 [NAL9602](FAULT): received: +CSQ:0 OK957, 2, 0, 0, 0 OK 2020-01-06T23:27:10.493Z,1578353230.493 [NAL9602] Data Fault, FailCount= 1 2020-01-06T23:27:10.493Z,1578353230.493 [NAL9602](ERROR): Data Fault 2020-01-06T23:27:10.551Z,1578353230.551 [CBIT](ERROR): Data Fault in component: NAL9602 2020-01-06T23:27:10.820Z,1578353230.820 [NAL9602](INFO): Powering down 2020-01-06T23:27:11.675Z,1578353231.675 [CBIT](INFO): Clearing failed state for component NAL9602 2020-01-06T23:27:11.676Z,1578353231.676 [NAL9602] No Fault, FailCount= 1 2020-01-06T23:27:41.118Z,1578353261.118 [NAL9602](INFO): Powering up NAL9602 2020-01-06T23:27:52.036Z,1578353272.036 [NAL9602](INFO): NAL9602 initialized 2020-01-06T23:28:23.144Z,1578353303.144 [NAL9602](INFO): Not Powering down - fast GPS 2020-01-06T23:32:10.631Z,1578353530.631 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-01-06T23:32:10.631Z,1578353530.631 [Default:CheckIn:C.Wait] Stopped 2020-01-06T23:32:10.631Z,1578353530.631 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-01-06T23:32:10.631Z,1578353530.631 [Default:CheckIn:D] Running Loop=1 2020-01-06T23:32:11.034Z,1578353531.034 [Default:CheckIn:D] Stopped 2020-01-06T23:32:11.034Z,1578353531.034 [Default:CheckIn:E] Running Loop=1 2020-01-06T23:32:11.430Z,1578353531.430 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 245.703939 min 2020-01-06T23:32:11.430Z,1578353531.430 [Default:CheckIn:E] Stopped 2020-01-06T23:32:11.430Z,1578353531.430 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-01-06T23:32:11.430Z,1578353531.430 [Default:CheckIn] Stopped 2020-01-06T23:32:11.430Z,1578353531.430 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-01-06T23:32:11.430Z,1578353531.430 [Default:CheckIn](INFO): Running loop #32 2020-01-06T23:32:11.430Z,1578353531.430 [Default:CheckIn] Running Loop=32 2020-01-06T23:32:11.430Z,1578353531.430 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-01-06T23:32:11.430Z,1578353531.430 [Default:CheckIn:Read_GPS] Running Loop=1 2020-01-06T23:32:15.042Z,1578353535.042 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2020-01-06T23:37:11.640Z,1578353831.640 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-01-06T23:32:11.4Z 2020-01-06T23:37:11.640Z,1578353831.640 [Default:CheckIn:Read_GPS] Stopped 2020-01-06T23:37:11.641Z,1578353831.641 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-01-06T23:37:19.185Z,1578353839.185 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20200106T195438/Courier0081.lzma 2020-01-06T23:37:21.191Z,1578353841.191 [DataOverHttps](INFO): Moved sent file to Logs/20200106T195438/Courier0081.lzma.bak 2020-01-06T23:37:21.191Z,1578353841.191 [DataOverHttps](INFO): SBD MOMSN=12185597 2020-01-06T23:37:38.174Z,1578353858.174 [DataOverHttps](INFO): Sending 238 bytes from file Logs/20200106T195438/Express0082.lzma 2020-01-06T23:37:40.179Z,1578353860.179 [DataOverHttps](INFO): Moved sent file to Logs/20200106T195438/Express0082.lzma.bak 2020-01-06T23:37:40.179Z,1578353860.179 [DataOverHttps](INFO): SBD MOMSN=12185599 2020-01-06T23:37:41.545Z,1578353861.545 [Default:CheckIn:Read_Iridium] Stopped 2020-01-06T23:37:41.545Z,1578353861.545 [Default:CheckIn:C.Wait] Running Loop=1 2020-01-06T23:37:41.545Z,1578353861.545 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-01-06T23:37:42.704Z,1578353862.704 [NAL9602](INFO): Not Powering down - fast GPS 2020-01-06T23:42:42.163Z,1578354162.163 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-01-06T23:42:42.163Z,1578354162.163 [Default:CheckIn:C.Wait] Stopped 2020-01-06T23:42:42.163Z,1578354162.163 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-01-06T23:42:42.163Z,1578354162.163 [Default:CheckIn:D] Running Loop=1 2020-01-06T23:42:42.590Z,1578354162.590 [Default:CheckIn:D] Stopped 2020-01-06T23:42:42.590Z,1578354162.590 [Default:CheckIn:E] Running Loop=1 2020-01-06T23:42:42.965Z,1578354162.965 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 256.229867 min 2020-01-06T23:42:42.965Z,1578354162.965 [Default:CheckIn:E] Stopped 2020-01-06T23:42:42.965Z,1578354162.965 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-01-06T23:42:42.965Z,1578354162.965 [Default:CheckIn] Stopped 2020-01-06T23:42:42.965Z,1578354162.965 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-01-06T23:42:42.965Z,1578354162.965 [Default:CheckIn](INFO): Running loop #33 2020-01-06T23:42:42.966Z,1578354162.966 [Default:CheckIn] Running Loop=33 2020-01-06T23:42:42.966Z,1578354162.966 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-01-06T23:42:42.966Z,1578354162.966 [Default:CheckIn:Read_GPS] Running Loop=1 2020-01-06T23:42:44.566Z,1578354164.566 [NAL9602](FAULT): GPS failed to acquire within timeout. 2020-01-06T23:42:44.566Z,1578354164.566 [NAL9602] Data Fault, FailCount= 1 2020-01-06T23:42:44.566Z,1578354164.566 [NAL9602](ERROR): Data Fault 2020-01-06T23:42:44.602Z,1578354164.602 [CBIT](ERROR): Data Fault in component: NAL9602 2020-01-06T23:42:44.958Z,1578354164.958 [NAL9602](INFO): Powering down 2020-01-06T23:42:45.362Z,1578354165.362 [NAL9602](FAULT): LCB fault: Software Overcurrent. 2020-01-06T23:42:45.362Z,1578354165.362 [NAL9602] Hardware Fault, FailCount= 1 2020-01-06T23:42:45.362Z,1578354165.362 [NAL9602](ERROR): Hardware Fault 2020-01-06T23:42:45.839Z,1578354165.839 [CBIT](INFO): Clearing failed state for component NAL9602 2020-01-06T23:42:45.840Z,1578354165.840 [NAL9602] No Fault, FailCount= 1 2020-01-06T23:43:15.262Z,1578354195.262 [NAL9602](INFO): Powering up NAL9602 2020-01-06T23:43:26.164Z,1578354206.164 [NAL9602](INFO): NAL9602 initialized 2020-01-06T23:47:43.142Z,1578354463.142 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-01-06T23:42:42.0Z 2020-01-06T23:47:43.142Z,1578354463.142 [Default:CheckIn:Read_GPS] Stopped 2020-01-06T23:47:43.142Z,1578354463.142 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-01-06T23:47:50.925Z,1578354470.925 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20200106T195438/Courier0084.lzma 2020-01-06T23:47:52.931Z,1578354472.931 [DataOverHttps](INFO): Moved sent file to Logs/20200106T195438/Courier0084.lzma.bak 2020-01-06T23:47:52.931Z,1578354472.931 [DataOverHttps](INFO): SBD MOMSN=12185601 2020-01-06T23:48:10.113Z,1578354490.113 [DataOverHttps](INFO): Sending 195 bytes from file Logs/20200106T195438/Express0085.lzma 2020-01-06T23:48:12.119Z,1578354492.119 [DataOverHttps](INFO): Moved sent file to Logs/20200106T195438/Express0085.lzma.bak 2020-01-06T23:48:12.119Z,1578354492.119 [DataOverHttps](INFO): SBD MOMSN=12185603 2020-01-06T23:48:13.446Z,1578354493.446 [Default:CheckIn:Read_Iridium] Stopped 2020-01-06T23:48:13.446Z,1578354493.446 [Default:CheckIn:C.Wait] Running Loop=1 2020-01-06T23:48:13.446Z,1578354493.446 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-01-06T23:48:29.574Z,1578354509.574 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2020-01-06T23:49:00.278Z,1578354540.278 [NAL9602](INFO): Not Powering down - fast GPS 2020-01-06T23:53:14.008Z,1578354794.008 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-01-06T23:53:14.008Z,1578354794.008 [Default:CheckIn:C.Wait] Stopped 2020-01-06T23:53:14.008Z,1578354794.008 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-01-06T23:53:14.008Z,1578354794.008 [Default:CheckIn:D] Running Loop=1 2020-01-06T23:53:14.425Z,1578354794.425 [Default:CheckIn:D] Stopped 2020-01-06T23:53:14.426Z,1578354794.426 [Default:CheckIn:E] Running Loop=1 2020-01-06T23:53:14.834Z,1578354794.834 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 266.760449 min 2020-01-06T23:53:14.834Z,1578354794.834 [Default:CheckIn:E] Stopped 2020-01-06T23:53:14.834Z,1578354794.834 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-01-06T23:53:14.834Z,1578354794.834 [Default:CheckIn] Stopped 2020-01-06T23:53:14.834Z,1578354794.834 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-01-06T23:53:14.834Z,1578354794.834 [Default:CheckIn](INFO): Running loop #34 2020-01-06T23:53:14.834Z,1578354794.834 [Default:CheckIn] Running Loop=34 2020-01-06T23:53:14.834Z,1578354794.834 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-01-06T23:53:14.835Z,1578354794.835 [Default:CheckIn:Read_GPS] Running Loop=1 2020-01-06T23:53:47.516Z,1578354827.516 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2020-01-06T23:53:47.597Z,1578354827.597 [NAL9602](FAULT): received: +CSQ:0 OK957, 2, 0, 0, 0 OK 2020-01-06T23:53:47.597Z,1578354827.597 [NAL9602] Data Fault, FailCount= 2 2020-01-06T23:53:47.597Z,1578354827.597 [NAL9602](ERROR): Data Fault 2020-01-06T23:53:47.637Z,1578354827.637 [CBIT](ERROR): Data Fault in component: NAL9602 2020-01-06T23:53:47.922Z,1578354827.922 [NAL9602](INFO): Powering down 2020-01-06T23:53:48.326Z,1578354828.326 [NAL9602](FAULT): LCB fault: Software Overcurrent. 2020-01-06T23:53:48.326Z,1578354828.326 [NAL9602] Hardware Fault, FailCount= 2 2020-01-06T23:53:48.326Z,1578354828.326 [NAL9602](ERROR): Hardware Fault 2020-01-06T23:53:48.773Z,1578354828.773 [CBIT](INFO): Clearing failed state for component NAL9602 2020-01-06T23:53:48.773Z,1578354828.773 [NAL9602] No Fault, FailCount= 2 2020-01-06T23:54:18.220Z,1578354858.220 [NAL9602](INFO): Powering up NAL9602 2020-01-06T23:54:29.137Z,1578354869.137 [NAL9602](INFO): NAL9602 initialized 2020-01-06T23:54:29.936Z,1578354869.936 [NAL9602](FAULT): GPS failed to acquire within timeout. 2020-01-06T23:54:29.936Z,1578354869.936 [NAL9602] Data Fault, FailCount= 3 2020-01-06T23:54:29.936Z,1578354869.936 [NAL9602](ERROR): Data Fault 2020-01-06T23:54:30.014Z,1578354870.014 [CBIT](ERROR): Data Fault in component: NAL9602 2020-01-06T23:54:30.346Z,1578354870.346 [NAL9602](INFO): Powering down 2020-01-06T23:54:31.195Z,1578354871.195 [CBIT](INFO): Clearing failed state for component NAL9602 2020-01-06T23:54:31.195Z,1578354871.195 [NAL9602] No Fault, FailCount= 3 2020-01-06T23:54:35.655Z,1578354875.655 [CommandLine](IMPORTANT): got command quit 2020-01-06T23:54:36.661Z,1578354876.661 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2020-01-06T23:54:36.662Z,1578354876.662 [CommandLine ThreadHandler](INFO): Thread cancelled. 2020-01-06T23:54:36.833Z,1578354876.833 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2020-01-06T23:54:36.833Z,1578354876.833 [CommandLine ThreadHandler](INFO): Thread cancelled. 2020-01-06T23:54:36.834Z,1578354876.834 [CommandLine](INFO): Join timeout helper Thread ID is 3931 2020-01-06T23:54:36.874Z,1578354876.874 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2020-01-06T23:54:36.874Z,1578354876.874 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2020-01-06T23:54:36.875Z,1578354876.875 [NavChartDb](INFO): Join timeout helper Thread ID is 3932 2020-01-06T23:54:37.117Z,1578354877.117 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2020-01-06T23:54:37.118Z,1578354877.118 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2020-01-06T23:54:37.125Z,1578354877.125 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2020-01-06T23:54:37.125Z,1578354877.125 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2020-01-06T23:54:37.126Z,1578354877.126 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 3933 2020-01-06T23:54:37.574Z,1578354877.574 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2020-01-06T23:54:37.574Z,1578354877.574 [WetLabsBB2FL](INFO): Powering down 2020-01-06T23:54:37.575Z,1578354877.575 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2020-01-06T23:54:37.593Z,1578354877.593 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler 2020-01-06T23:54:37.593Z,1578354877.593 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2020-01-06T23:54:37.594Z,1578354877.594 [CTD_Seabird](INFO): Join timeout helper Thread ID is 3934 2020-01-06T23:54:37.938Z,1578354877.938 [CTD_Seabird](INFO): Powering down 2020-01-06T23:54:37.949Z,1578354877.949 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread. 2020-01-06T23:54:37.949Z,1578354877.949 [CTD_Seabird](INFO): Powering down 2020-01-06T23:54:37.961Z,1578354877.961 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2020-01-06T23:54:37.973Z,1578354877.973 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2020-01-06T23:54:37.973Z,1578354877.973 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2020-01-06T23:54:37.974Z,1578354877.974 [Radio_Surface](INFO): Join timeout helper Thread ID is 3935 2020-01-06T23:54:38.213Z,1578354878.213 [Radio_Surface](INFO): Powering down 2020-01-06T23:54:38.214Z,1578354878.214 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2020-01-06T23:54:38.215Z,1578354878.215 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2020-01-06T23:54:38.222Z,1578354878.222 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler 2020-01-06T23:54:38.222Z,1578354878.222 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2020-01-06T23:54:38.223Z,1578354878.223 [DataOverHttps](INFO): Join timeout helper Thread ID is 3936 2020-01-06T23:54:39.021Z,1578354879.021 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread. 2020-01-06T23:54:39.022Z,1578354879.022 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2020-01-06T23:54:39.041Z,1578354879.041 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2020-01-06T23:54:39.041Z,1578354879.041 [logger ThreadHandler](INFO): Thread cancelled. 2020-01-06T23:54:39.042Z,1578354879.042 [logger](INFO): Join timeout helper Thread ID is 3937 2020-01-06T23:54:39.042Z,1578354879.042 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2020-01-06T23:54:39.042Z,1578354879.042 [logger ThreadHandler](INFO): Thread cancelled. 2020-01-06T23:54:39.044Z,1578354879.044 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2020-01-06T23:54:39.044Z,1578354879.044 [CommandLine ThreadHandler](INFO): Thread cancelled. 2020-01-06T23:54:39.044Z,1578354879.044 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2020-01-06T23:54:39.044Z,1578354879.044 [controlThread ThreadHandler](INFO): Thread cancelled. 2020-01-06T23:54:39.044Z,1578354879.044 [controlThread](INFO): Join timeout helper Thread ID is 3938 2020-01-06T23:54:39.213Z,1578354879.213 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2020-01-06T23:54:39.214Z,1578354879.214 [controlThread](DEBUG): Uninitializing ControlThread 2020-01-06T23:54:39.214Z,1578354879.214 [AHRS_M2](INFO): Powering down 2020-01-06T23:54:39.286Z,1578354879.286 [NAL9602](INFO): Powering down 2020-01-06T23:54:39.288Z,1578354879.288 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator. 2020-01-06T23:54:39.289Z,1578354879.289 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator. 2020-01-06T23:54:39.290Z,1578354879.290 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2020-01-06T23:54:39.290Z,1578354879.290 [MissionManager](INFO): Uninitializing Mission Default 2020-01-06T23:54:39.291Z,1578354879.291 [Default] Stopped 2020-01-06T23:54:39.291Z,1578354879.291 [Default](DEBUG): Aggregate::uninitialize Default 2020-01-06T23:54:39.291Z,1578354879.291 [Default:B.GoToSurface] Stopped 2020-01-06T23:54:39.291Z,1578354879.291 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2020-01-06T23:54:39.291Z,1578354879.291 [Default:CheckIn] Stopped 2020-01-06T23:54:39.291Z,1578354879.291 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-01-06T23:54:39.291Z,1578354879.291 [Default:CheckIn:Read_GPS] Stopped 2020-01-06T23:54:39.293Z,1578354879.293 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2020-01-06T23:54:39.294Z,1578354879.294 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2020-01-06T23:54:39.294Z,1578354879.294 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2020-01-06T23:54:39.294Z,1578354879.294 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2020-01-06T23:54:39.295Z,1578354879.295 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2020-01-06T23:54:39.295Z,1578354879.295 [BuoyancyServo](INFO): Powering down 2020-01-06T23:54:39.309Z,1578354879.309 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2020-01-06T23:54:39.309Z,1578354879.309 [ElevatorServo](INFO): Powering down 2020-01-06T23:54:39.310Z,1578354879.310 [MassServo](DEBUG): Uninitialize Mass Servo. 2020-01-06T23:54:39.310Z,1578354879.310 [MassServo](INFO): Powering down 2020-01-06T23:54:39.311Z,1578354879.311 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2020-01-06T23:54:39.311Z,1578354879.311 [RudderServo](INFO): Powering down 2020-01-06T23:54:39.312Z,1578354879.312 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2020-01-06T23:54:39.312Z,1578354879.312 [ThrusterServo](INFO): Powering down 2020-01-06T23:54:39.313Z,1578354879.313 [SBIT](DEBUG): Uninitialize SBIT Component. 2020-01-06T23:54:39.313Z,1578354879.313 [IBIT](DEBUG): Uninitialize IBIT Component. 2020-01-06T23:54:39.314Z,1578354879.314 [CBIT](DEBUG): Uninitialize CBIT Component. 2020-01-06T23:54:39.314Z,1578354879.314 [CBIT](DEBUG): Powering off loads. 2020-01-06T23:54:39.325Z,1578354879.325 [CBIT](DEBUG): Disabling WDT. 2020-01-06T23:54:39.337Z,1578354879.337 [CBIT](DEBUG): Opening all GF detection circuits. 2020-01-06T23:54:39.338Z,1578354879.338 [controlThread ThreadHandler](INFO): Thread cancelled. 2020-01-06T23:54:39.421Z,1578354879.421 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2020-01-06T23:54:39.427Z,1578354879.427 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2020-01-06T23:54:39.459Z,1578354879.459 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2020-01-06T23:54:39.464Z,1578354879.464 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2020-01-06T23:54:39.499Z,1578354879.499 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2020-01-06T23:54:39.573Z,1578354879.573 [logger ThreadHandler](INFO): Thread cancelled.