2022-10-13T15:52:03.933Z,1665676323.933 [NAL9602](INFO): Received command: restart logs 2022-10-13T15:52:03.942Z,1665676323.942 [CommandExec](IMPORTANT): got command restart logs 2022-10-13T15:52:03.967Z,1665676323.967 [DataOverHttps](INFO): Moved sent file to Logs/20221011T121140/Express0170.lzma.bak 2022-10-13T15:52:03.967Z,1665676323.967 [DataOverHttps](INFO): SBD MOMSN=17244545 2022-10-13T15:52:34.558Z,1665676354.558 [NAL9602](INFO): Not Powering down - fast GPS 2022-10-13T15:55:08.128Z,1665676508.128 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20221011T121140/Courier0172.lzma 2022-10-13T15:55:09.131Z,1665676509.131 [DataOverHttps](INFO): Moved sent file to Logs/20221011T121140/Courier0172.lzma.bak 2022-10-13T15:55:09.131Z,1665676509.131 [DataOverHttps](INFO): SBD MOMSN=17244549 2022-10-13T15:58:15.252Z,1665676695.252 [DataOverHttps](INFO): Sending 137 bytes from file Logs/20221011T121140/Express0173.lzma 2022-10-13T15:58:16.255Z,1665676696.255 [DataOverHttps](INFO): Moved sent file to Logs/20221011T121140/Express0173.lzma.bak 2022-10-13T15:58:16.255Z,1665676696.255 [DataOverHttps](INFO): SBD MOMSN=17244551 2022-10-13T15:58:17.728Z,1665676697.728 [Default:CheckIn:Read_Iridium] Stopped 2022-10-13T15:58:17.728Z,1665676697.728 [Default:CheckIn:C.Wait] Running Loop=1 2022-10-13T15:58:17.728Z,1665676697.728 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-10-13T16:03:18.329Z,1665676998.329 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-10-13T16:03:18.329Z,1665676998.329 [Default:CheckIn:C.Wait] Stopped 2022-10-13T16:03:18.329Z,1665676998.329 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-10-13T16:03:18.330Z,1665676998.330 [Default:CheckIn:D] Running Loop=1 2022-10-13T16:03:18.746Z,1665676998.746 [Default:CheckIn:D] Stopped 2022-10-13T16:03:18.746Z,1665676998.746 [Default:CheckIn:E] Running Loop=1 2022-10-13T16:03:19.128Z,1665676999.128 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 39.811450 min 2022-10-13T16:03:19.128Z,1665676999.128 [Default:CheckIn:E] Stopped 2022-10-13T16:03:19.128Z,1665676999.128 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-10-13T16:03:19.129Z,1665676999.129 [Default:CheckIn] Stopped 2022-10-13T16:03:19.129Z,1665676999.129 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-10-13T16:03:19.129Z,1665676999.129 [Default:CheckIn](INFO): Running loop #4 2022-10-13T16:03:19.129Z,1665676999.129 [Default:CheckIn] Running Loop=4 2022-10-13T16:03:19.129Z,1665676999.129 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-10-13T16:03:19.129Z,1665676999.129 [Default:CheckIn:Read_GPS] Running Loop=1 2022-10-13T16:03:21.151Z,1665677001.151 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160323.00,A,3648.17305,N,12147.21447,W,0.117,243.13,131022,,,D*73 2022-10-13T16:03:21.154Z,1665677001.154 [NAL9602](INFO): GPS fix at 20221013T160323: (36.802884, -121.786908) 2022-10-13T16:03:21.164Z,1665677001.164 [Default:CheckIn:Read_GPS] Stopped 2022-10-13T16:03:21.164Z,1665677001.164 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-10-13T16:03:28.025Z,1665677008.025 [DataOverHttps](INFO): Sending 268 bytes from file Logs/20221013T155203/Courier0000.lzma 2022-10-13T16:03:29.027Z,1665677009.027 [DataOverHttps](INFO): Moved sent file to Logs/20221013T155203/Courier0000.lzma.bak 2022-10-13T16:03:29.027Z,1665677009.027 [DataOverHttps](INFO): SBD MOMSN=17244554 2022-10-13T16:03:44.878Z,1665677024.878 [DataOverHttps](INFO): Sending 448 bytes from file Logs/20221013T155203/Express0001.lzma 2022-10-13T16:03:45.878Z,1665677025.878 [DataOverHttps](INFO): Moved sent file to Logs/20221013T155203/Express0001.lzma.bak 2022-10-13T16:03:45.879Z,1665677025.879 [DataOverHttps](INFO): SBD MOMSN=17244558 2022-10-13T16:03:47.038Z,1665677027.038 [Default:CheckIn:Read_Iridium] Stopped 2022-10-13T16:03:47.038Z,1665677027.038 [Default:CheckIn:C.Wait] Running Loop=1 2022-10-13T16:03:47.038Z,1665677027.038 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-10-13T16:04:34.295Z,1665677074.295 [NAL9602](INFO): SBD MO Status=2, MOMSN=37308, MT Status=2, MTMSN=0 2022-10-13T16:04:34.295Z,1665677074.295 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-10-13T16:05:03.439Z,1665677103.439 [NAL9602](INFO): SBD MO Status=0, MOMSN=37308, MT Status=0, MTMSN=0 2022-10-13T16:05:03.439Z,1665677103.439 [NAL9602](INFO): No messages in MT queue 2022-10-13T16:05:34.138Z,1665677134.138 [NAL9602](INFO): Not Powering down - fast GPS 2022-10-13T16:08:47.663Z,1665677327.663 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-10-13T16:08:47.663Z,1665677327.663 [Default:CheckIn:C.Wait] Stopped 2022-10-13T16:08:47.663Z,1665677327.663 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-10-13T16:08:47.663Z,1665677327.663 [Default:CheckIn:D] Running Loop=1 2022-10-13T16:08:48.069Z,1665677328.069 [Default:CheckIn:D] Stopped 2022-10-13T16:08:48.069Z,1665677328.069 [Default:CheckIn:E] Running Loop=1 2022-10-13T16:08:48.483Z,1665677328.483 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 45.300175 min 2022-10-13T16:08:48.483Z,1665677328.483 [Default:CheckIn:E] Stopped 2022-10-13T16:08:48.483Z,1665677328.483 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-10-13T16:08:48.483Z,1665677328.483 [Default:CheckIn] Stopped 2022-10-13T16:08:48.483Z,1665677328.483 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-10-13T16:08:48.483Z,1665677328.483 [Default:CheckIn](INFO): Running loop #5 2022-10-13T16:08:48.483Z,1665677328.483 [Default:CheckIn] Running Loop=5 2022-10-13T16:08:48.484Z,1665677328.484 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-10-13T16:08:48.484Z,1665677328.484 [Default:CheckIn:Read_GPS] Running Loop=1 2022-10-13T16:08:50.483Z,1665677330.483 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160852.00,A,3648.14360,N,12147.23051,W,0.078,323.48,131022,,,D*7E 2022-10-13T16:08:50.486Z,1665677330.486 [NAL9602](INFO): GPS fix at 20221013T160852: (36.802393, -121.787175) 2022-10-13T16:08:50.522Z,1665677330.522 [Default:CheckIn:Read_GPS] Stopped 2022-10-13T16:08:50.522Z,1665677330.522 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-10-13T16:08:58.068Z,1665677338.068 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20221013T155203/Courier0003.lzma 2022-10-13T16:08:59.070Z,1665677339.070 [DataOverHttps](INFO): Moved sent file to Logs/20221013T155203/Courier0003.lzma.bak 2022-10-13T16:08:59.070Z,1665677339.070 [DataOverHttps](INFO): SBD MOMSN=17244566 2022-10-13T16:09:14.969Z,1665677354.969 [DataOverHttps](INFO): Sending 168 bytes from file Logs/20221013T155203/Express0004.lzma 2022-10-13T16:09:15.978Z,1665677355.978 [DataOverHttps](INFO): Moved sent file to Logs/20221013T155203/Express0004.lzma.bak 2022-10-13T16:09:15.979Z,1665677355.979 [DataOverHttps](INFO): SBD MOMSN=17244569 2022-10-13T16:09:17.164Z,1665677357.164 [Default:CheckIn:Read_Iridium] Stopped 2022-10-13T16:09:17.164Z,1665677357.164 [Default:CheckIn:C.Wait] Running Loop=1 2022-10-13T16:09:17.164Z,1665677357.164 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-10-13T16:10:00.784Z,1665677400.784 [NAL9602](INFO): SBD MO Status=2, MOMSN=37309, MT Status=2, MTMSN=0 2022-10-13T16:10:00.784Z,1665677400.784 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-10-13T16:13:52.713Z,1665677632.713 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-10-13T16:14:17.767Z,1665677657.767 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-10-13T16:14:17.767Z,1665677657.767 [Default:CheckIn:C.Wait] Stopped 2022-10-13T16:14:17.767Z,1665677657.767 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-10-13T16:14:17.768Z,1665677657.768 [Default:CheckIn:D] Running Loop=1 2022-10-13T16:14:18.173Z,1665677658.173 [Default:CheckIn:D] Stopped 2022-10-13T16:14:18.173Z,1665677658.173 [Default:CheckIn:E] Running Loop=1 2022-10-13T16:14:18.572Z,1665677658.572 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 50.801908 min 2022-10-13T16:14:18.572Z,1665677658.572 [Default:CheckIn:E] Stopped 2022-10-13T16:14:18.572Z,1665677658.572 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-10-13T16:14:18.572Z,1665677658.572 [Default:CheckIn] Stopped 2022-10-13T16:14:18.573Z,1665677658.573 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-10-13T16:14:18.573Z,1665677658.573 [Default:CheckIn](INFO): Running loop #6 2022-10-13T16:14:18.573Z,1665677658.573 [Default:CheckIn] Running Loop=6 2022-10-13T16:14:18.573Z,1665677658.573 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-10-13T16:14:18.574Z,1665677658.574 [Default:CheckIn:Read_GPS] Running Loop=1 2022-10-13T16:14:20.588Z,1665677660.588 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,161422.00,A,3648.16612,N,12147.28354,W,1.050,293.10,131022,,,D*77 2022-10-13T16:14:20.599Z,1665677660.599 [NAL9602](INFO): GPS fix at 20221013T161422: (36.802769, -121.788059) 2022-10-13T16:14:20.610Z,1665677660.610 [Default:CheckIn:Read_GPS] Stopped 2022-10-13T16:14:20.610Z,1665677660.610 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-10-13T16:14:28.316Z,1665677668.316 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20221013T155203/Courier0006.lzma 2022-10-13T16:14:29.318Z,1665677669.318 [DataOverHttps](INFO): Moved sent file to Logs/20221013T155203/Courier0006.lzma.bak 2022-10-13T16:14:29.318Z,1665677669.318 [DataOverHttps](INFO): SBD MOMSN=17244572 2022-10-13T16:14:45.369Z,1665677685.369 [DataOverHttps](INFO): Sending 262 bytes from file Logs/20221013T155203/Express0007.lzma 2022-10-13T16:14:46.370Z,1665677686.370 [DataOverHttps](INFO): Moved sent file to Logs/20221013T155203/Express0007.lzma.bak 2022-10-13T16:14:46.371Z,1665677686.371 [DataOverHttps](INFO): SBD MOMSN=17244575 2022-10-13T16:14:47.660Z,1665677687.660 [Default:CheckIn:Read_Iridium] Stopped 2022-10-13T16:14:47.660Z,1665677687.660 [Default:CheckIn:C.Wait] Running Loop=1 2022-10-13T16:14:47.660Z,1665677687.660 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-10-13T16:14:52.950Z,1665677692.950 [NAL9602](INFO): Not Powering down - fast GPS 2022-10-13T16:19:48.315Z,1665677988.315 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-10-13T16:19:48.316Z,1665677988.316 [Default:CheckIn:C.Wait] Stopped 2022-10-13T16:19:48.316Z,1665677988.316 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-10-13T16:19:48.316Z,1665677988.316 [Default:CheckIn:D] Running Loop=1 2022-10-13T16:19:48.706Z,1665677988.706 [Default:CheckIn:D] Stopped 2022-10-13T16:19:48.706Z,1665677988.706 [Default:CheckIn:E] Running Loop=1 2022-10-13T16:19:49.112Z,1665677989.112 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 56.310779 min 2022-10-13T16:19:49.112Z,1665677989.112 [Default:CheckIn:E] Stopped 2022-10-13T16:19:49.112Z,1665677989.112 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-10-13T16:19:49.112Z,1665677989.112 [Default:CheckIn] Stopped 2022-10-13T16:19:49.112Z,1665677989.112 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-10-13T16:19:49.112Z,1665677989.112 [Default:CheckIn](INFO): Running loop #7 2022-10-13T16:19:49.112Z,1665677989.112 [Default:CheckIn] Running Loop=7 2022-10-13T16:19:49.113Z,1665677989.113 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-10-13T16:19:49.113Z,1665677989.113 [Default:CheckIn:Read_GPS] Running Loop=1 2022-10-13T16:19:51.123Z,1665677991.123 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,161953.00,A,3648.16812,N,12147.28722,W,0.447,293.10,131022,,,D*74 2022-10-13T16:19:51.126Z,1665677991.126 [NAL9602](INFO): GPS fix at 20221013T161953: (36.802802, -121.788120) 2022-10-13T16:19:51.136Z,1665677991.136 [Default:CheckIn:Read_GPS] Stopped 2022-10-13T16:19:51.136Z,1665677991.136 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-10-13T16:19:58.760Z,1665677998.760 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20221013T155203/Courier0009.lzma 2022-10-13T16:19:59.763Z,1665677999.763 [DataOverHttps](INFO): Moved sent file to Logs/20221013T155203/Courier0009.lzma.bak 2022-10-13T16:19:59.763Z,1665677999.763 [DataOverHttps](INFO): SBD MOMSN=17244579 2022-10-13T16:20:15.729Z,1665678015.729 [DataOverHttps](INFO): Sending 141 bytes from file Logs/20221013T155203/Express0010.lzma 2022-10-13T16:20:16.730Z,1665678016.730 [DataOverHttps](INFO): Moved sent file to Logs/20221013T155203/Express0010.lzma.bak 2022-10-13T16:20:16.730Z,1665678016.730 [DataOverHttps](INFO): SBD MOMSN=17244582 2022-10-13T16:20:18.220Z,1665678018.220 [Default:CheckIn:Read_Iridium] Stopped 2022-10-13T16:20:18.220Z,1665678018.220 [Default:CheckIn:C.Wait] Running Loop=1 2022-10-13T16:20:18.220Z,1665678018.220 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-10-13T16:20:21.822Z,1665678021.822 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2022-10-13T16:20:21.901Z,1665678021.901 [NAL9602](ERROR): received: +CSQ:0 OK309, 2, 0, 0, 0 OK 2022-10-13T16:24:53.734Z,1665678293.734 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-10-13T16:25:18.795Z,1665678318.795 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-10-13T16:25:18.795Z,1665678318.795 [Default:CheckIn:C.Wait] Stopped 2022-10-13T16:25:18.795Z,1665678318.795 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-10-13T16:25:18.796Z,1665678318.796 [Default:CheckIn:D] Running Loop=1 2022-10-13T16:25:19.196Z,1665678319.196 [Default:CheckIn:D] Stopped 2022-10-13T16:25:19.196Z,1665678319.196 [Default:CheckIn:E] Running Loop=1 2022-10-13T16:25:19.607Z,1665678319.607 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 61.818949 min 2022-10-13T16:25:19.607Z,1665678319.607 [Default:CheckIn:E] Stopped 2022-10-13T16:25:19.608Z,1665678319.608 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-10-13T16:25:19.608Z,1665678319.608 [Default:CheckIn] Stopped 2022-10-13T16:25:19.608Z,1665678319.608 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-10-13T16:25:19.608Z,1665678319.608 [Default:CheckIn](INFO): Running loop #8 2022-10-13T16:25:19.608Z,1665678319.608 [Default:CheckIn] Running Loop=8 2022-10-13T16:25:19.608Z,1665678319.608 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-10-13T16:25:19.608Z,1665678319.608 [Default:CheckIn:Read_GPS] Running Loop=1 2022-10-13T16:25:21.615Z,1665678321.615 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162523.00,A,3648.16741,N,12147.28434,W,0.719,0.00,131022,,,A*75 2022-10-13T16:25:21.618Z,1665678321.618 [NAL9602](INFO): GPS fix at 20221013T162523: (36.802790, -121.788072) 2022-10-13T16:25:21.649Z,1665678321.649 [Default:CheckIn:Read_GPS] Stopped 2022-10-13T16:25:21.649Z,1665678321.649 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-10-13T16:25:29.284Z,1665678329.284 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20221013T155203/Courier0012.lzma 2022-10-13T16:25:30.286Z,1665678330.286 [DataOverHttps](INFO): Moved sent file to Logs/20221013T155203/Courier0012.lzma.bak 2022-10-13T16:25:30.286Z,1665678330.286 [DataOverHttps](INFO): SBD MOMSN=17244636 2022-10-13T16:25:46.149Z,1665678346.149 [DataOverHttps](INFO): Sending 215 bytes from file Logs/20221013T155203/Express0013.lzma 2022-10-13T16:25:47.150Z,1665678347.150 [DataOverHttps](INFO): Moved sent file to Logs/20221013T155203/Express0013.lzma.bak 2022-10-13T16:25:47.151Z,1665678347.151 [DataOverHttps](INFO): SBD MOMSN=17244639 2022-10-13T16:25:48.290Z,1665678348.290 [Default:CheckIn:Read_Iridium] Stopped 2022-10-13T16:25:48.290Z,1665678348.290 [Default:CheckIn:C.Wait] Running Loop=1 2022-10-13T16:25:48.290Z,1665678348.290 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-10-13T16:25:53.526Z,1665678353.526 [NAL9602](INFO): Not Powering down - fast GPS 2022-10-13T16:30:48.875Z,1665678648.875 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-10-13T16:30:48.875Z,1665678648.875 [Default:CheckIn:C.Wait] Stopped 2022-10-13T16:30:48.875Z,1665678648.875 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-10-13T16:30:48.876Z,1665678648.876 [Default:CheckIn:D] Running Loop=1 2022-10-13T16:30:49.275Z,1665678649.275 [Default:CheckIn:D] Stopped 2022-10-13T16:30:49.275Z,1665678649.275 [Default:CheckIn:E] Running Loop=1 2022-10-13T16:30:49.691Z,1665678649.691 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 67.320276 min 2022-10-13T16:30:49.691Z,1665678649.691 [Default:CheckIn:E] Stopped 2022-10-13T16:30:49.691Z,1665678649.691 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-10-13T16:30:49.691Z,1665678649.691 [Default:CheckIn] Stopped 2022-10-13T16:30:49.691Z,1665678649.691 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-10-13T16:30:49.692Z,1665678649.692 [Default:CheckIn](INFO): Running loop #9 2022-10-13T16:30:49.692Z,1665678649.692 [Default:CheckIn] Running Loop=9 2022-10-13T16:30:49.692Z,1665678649.692 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-10-13T16:30:49.692Z,1665678649.692 [Default:CheckIn:Read_GPS] Running Loop=1 2022-10-13T16:30:51.687Z,1665678651.687 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163053.00,A,3648.16333,N,12147.27922,W,0.680,191.99,131022,,,A*7A 2022-10-13T16:30:51.690Z,1665678651.690 [NAL9602](INFO): GPS fix at 20221013T163053: (36.802722, -121.787987) 2022-10-13T16:30:51.721Z,1665678651.721 [Default:CheckIn:Read_GPS] Stopped 2022-10-13T16:30:51.721Z,1665678651.721 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-10-13T16:30:59.536Z,1665678659.536 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20221013T155203/Courier0015.lzma 2022-10-13T16:31:00.538Z,1665678660.538 [DataOverHttps](INFO): Moved sent file to Logs/20221013T155203/Courier0015.lzma.bak 2022-10-13T16:31:00.539Z,1665678660.539 [DataOverHttps](INFO): SBD MOMSN=17244643 2022-10-13T16:31:16.449Z,1665678676.449 [DataOverHttps](INFO): Sending 139 bytes from file Logs/20221013T155203/Express0016.lzma 2022-10-13T16:31:17.450Z,1665678677.450 [DataOverHttps](INFO): Moved sent file to Logs/20221013T155203/Express0016.lzma.bak 2022-10-13T16:31:17.451Z,1665678677.451 [DataOverHttps](INFO): SBD MOMSN=17244646 2022-10-13T16:31:18.769Z,1665678678.769 [Default:CheckIn:Read_Iridium] Stopped 2022-10-13T16:31:18.770Z,1665678678.770 [Default:CheckIn:C.Wait] Running Loop=1 2022-10-13T16:31:18.770Z,1665678678.770 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-10-13T16:31:22.394Z,1665678682.394 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2022-10-13T16:31:22.469Z,1665678682.469 [NAL9602](ERROR): received: +CSQ:0 OK309, 2, 0, 0, 0 OK 2022-10-13T16:35:53.488Z,1665678953.488 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-10-13T16:36:19.352Z,1665678979.352 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-10-13T16:36:19.352Z,1665678979.352 [Default:CheckIn:C.Wait] Stopped 2022-10-13T16:36:19.353Z,1665678979.353 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-10-13T16:36:19.353Z,1665678979.353 [Default:CheckIn:D] Running Loop=1 2022-10-13T16:36:19.818Z,1665678979.818 [Default:CheckIn:D] Stopped 2022-10-13T16:36:19.818Z,1665678979.818 [Default:CheckIn:E] Running Loop=1 2022-10-13T16:36:20.168Z,1665678980.168 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 72.829321 min 2022-10-13T16:36:20.168Z,1665678980.168 [Default:CheckIn:E] Stopped 2022-10-13T16:36:20.168Z,1665678980.168 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-10-13T16:36:20.169Z,1665678980.169 [Default:CheckIn] Stopped 2022-10-13T16:36:20.169Z,1665678980.169 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-10-13T16:36:20.169Z,1665678980.169 [Default:CheckIn](INFO): Running loop #10 2022-10-13T16:36:20.169Z,1665678980.169 [Default:CheckIn] Running Loop=10 2022-10-13T16:36:20.169Z,1665678980.169 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-10-13T16:36:20.169Z,1665678980.169 [Default:CheckIn:Read_GPS] Running Loop=1 2022-10-13T16:36:22.192Z,1665678982.192 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163624.00,A,3648.17049,N,12147.27804,W,0.369,191.99,131022,,,A*74 2022-10-13T16:36:22.198Z,1665678982.198 [NAL9602](INFO): GPS fix at 20221013T163624: (36.802841, -121.787967) 2022-10-13T16:36:22.217Z,1665678982.217 [Default:CheckIn:Read_GPS] Stopped 2022-10-13T16:36:22.217Z,1665678982.217 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-10-13T16:36:29.612Z,1665678989.612 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20221013T155203/Courier0018.lzma 2022-10-13T16:36:30.614Z,1665678990.614 [DataOverHttps](INFO): Moved sent file to Logs/20221013T155203/Courier0018.lzma.bak 2022-10-13T16:36:30.614Z,1665678990.614 [DataOverHttps](INFO): SBD MOMSN=17244649 2022-10-13T16:36:33.474Z,1665678993.474 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-10-13T16:36:47.285Z,1665679007.285 [DataOverHttps](INFO): Sending 214 bytes from file Logs/20221013T155203/Express0019.lzma 2022-10-13T16:36:48.287Z,1665679008.287 [DataOverHttps](INFO): Moved sent file to Logs/20221013T155203/Express0019.lzma.bak 2022-10-13T16:36:48.287Z,1665679008.287 [DataOverHttps](INFO): SBD MOMSN=17244652 2022-10-13T16:36:48.423Z,1665679008.423 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-10-13T16:36:49.679Z,1665679009.679 [Default:CheckIn:Read_Iridium] Stopped 2022-10-13T16:36:49.679Z,1665679009.679 [Default:CheckIn:C.Wait] Running Loop=1 2022-10-13T16:36:49.679Z,1665679009.679 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-10-13T16:36:54.522Z,1665679014.522 [NAL9602](INFO): Not Powering down - fast GPS 2022-10-13T16:37:03.800Z,1665679023.800 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-10-13T16:37:18.747Z,1665679038.747 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-10-13T16:37:33.696Z,1665679053.696 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-10-13T16:37:48.642Z,1665679068.642 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-10-13T16:38:04.014Z,1665679084.014 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-10-13T16:38:19.751Z,1665679099.751 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-10-13T16:38:34.699Z,1665679114.699 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-10-13T16:38:50.051Z,1665679130.051 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-10-13T16:39:06.622Z,1665679146.622 [BPC1](INFO): Calculating totals. Valid battery stick count: 48. Valid reserve battery stick count: 5. 2022-10-13T16:39:06.625Z,1665679146.625 [BPC1](INFO): Received data from all battery sticks. 2022-10-13T16:41:50.259Z,1665679310.259 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-10-13T16:41:50.259Z,1665679310.259 [Default:CheckIn:C.Wait] Stopped 2022-10-13T16:41:50.259Z,1665679310.259 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-10-13T16:41:50.260Z,1665679310.260 [Default:CheckIn:D] Running Loop=1 2022-10-13T16:41:50.651Z,1665679310.651 [Default:CheckIn:D] Stopped 2022-10-13T16:41:50.651Z,1665679310.651 [Default:CheckIn:E] Running Loop=1 2022-10-13T16:41:51.059Z,1665679311.059 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 78.343197 min 2022-10-13T16:41:51.060Z,1665679311.060 [Default:CheckIn:E] Stopped 2022-10-13T16:41:51.060Z,1665679311.060 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-10-13T16:41:51.060Z,1665679311.060 [Default:CheckIn] Stopped 2022-10-13T16:41:51.060Z,1665679311.060 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-10-13T16:41:51.060Z,1665679311.060 [Default:CheckIn](INFO): Running loop #11 2022-10-13T16:41:51.060Z,1665679311.060 [Default:CheckIn] Running Loop=11 2022-10-13T16:41:51.060Z,1665679311.060 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-10-13T16:41:51.061Z,1665679311.061 [Default:CheckIn:Read_GPS] Running Loop=1 2022-10-13T16:41:53.068Z,1665679313.068 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164155.00,A,3648.16826,N,12147.28597,W,0.369,323.05,131022,,,A*74 2022-10-13T16:41:53.070Z,1665679313.070 [NAL9602](INFO): GPS fix at 20221013T164155: (36.802804, -121.788100) 2022-10-13T16:41:53.081Z,1665679313.081 [Default:CheckIn:Read_GPS] Stopped 2022-10-13T16:41:53.081Z,1665679313.081 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-10-13T16:42:00.668Z,1665679320.668 [DataOverHttps](INFO): Sending 202 bytes from file Logs/20221013T155203/Courier0021.lzma 2022-10-13T16:42:01.670Z,1665679321.670 [DataOverHttps](INFO): Moved sent file to Logs/20221013T155203/Courier0021.lzma.bak 2022-10-13T16:42:01.671Z,1665679321.671 [DataOverHttps](INFO): SBD MOMSN=17244656 2022-10-13T16:42:17.440Z,1665679337.440 [DataOverHttps](INFO): Sending 140 bytes from file Logs/20221013T155203/Express0022.lzma 2022-10-13T16:42:18.442Z,1665679338.442 [DataOverHttps](INFO): Moved sent file to Logs/20221013T155203/Express0022.lzma.bak 2022-10-13T16:42:18.442Z,1665679338.442 [DataOverHttps](INFO): SBD MOMSN=17244660 2022-10-13T16:42:19.752Z,1665679339.752 [Default:CheckIn:Read_Iridium] Stopped 2022-10-13T16:42:19.753Z,1665679339.753 [Default:CheckIn:C.Wait] Running Loop=1 2022-10-13T16:42:19.753Z,1665679339.753 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-10-13T16:42:23.770Z,1665679343.770 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2022-10-13T16:42:23.853Z,1665679343.853 [NAL9602](ERROR): received: +CSQ:0 OK309, 2, 0, 0, 0 OK 2022-10-13T16:44:23.757Z,1665679463.757 [DropWeight](CRITICAL): DROP WEIGHT MISSING. 2022-10-13T16:44:23.758Z,1665679463.758 [DropWeight] Hardware Fault, FailCount= 1 2022-10-13T16:44:23.758Z,1665679463.758 [DropWeight](ERROR): Hardware Fault 2022-10-13T16:44:23.837Z,1665679463.837 [CommandExec](FAULT): Scheduling is paused 2022-10-13T16:44:23.837Z,1665679463.837 [CBIT](INFO): Critical error at 20221013T164423 2022-10-13T16:44:23.840Z,1665679463.840 [CBIT](ERROR): Hardware Fault in component: DropWeight 2022-10-13T16:44:23.840Z,1665679463.840 [CBIT](CRITICAL): Hardware Fault in component: DropWeight 2022-10-13T16:44:24.222Z,1665679464.222 [CBIT](INFO): Critical error at 20221013T164423 2022-10-13T16:46:55.673Z,1665679615.673 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-10-13T16:47:20.326Z,1665679640.326 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-10-13T16:47:20.326Z,1665679640.326 [Default:CheckIn:C.Wait] Stopped 2022-10-13T16:47:20.326Z,1665679640.326 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-10-13T16:47:20.326Z,1665679640.326 [Default:CheckIn:D] Running Loop=1 2022-10-13T16:47:20.737Z,1665679640.737 [Default:CheckIn:D] Stopped 2022-10-13T16:47:20.737Z,1665679640.737 [Default:CheckIn:E] Running Loop=1 2022-10-13T16:47:21.135Z,1665679641.135 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 83.844645 min 2022-10-13T16:47:21.135Z,1665679641.135 [Default:CheckIn:E] Stopped 2022-10-13T16:47:21.135Z,1665679641.135 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-10-13T16:47:21.135Z,1665679641.135 [Default:CheckIn] Stopped 2022-10-13T16:47:21.135Z,1665679641.135 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-10-13T16:47:21.135Z,1665679641.135 [Default:CheckIn](INFO): Running loop #12 2022-10-13T16:47:21.135Z,1665679641.135 [Default:CheckIn] Running Loop=12 2022-10-13T16:47:21.135Z,1665679641.135 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-10-13T16:47:21.136Z,1665679641.136 [Default:CheckIn:Read_GPS] Running Loop=1 2022-10-13T16:47:23.151Z,1665679643.151 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164725.00,A,3648.16606,N,12147.28245,W,0.292,323.05,131022,,,A*74 2022-10-13T16:47:23.153Z,1665679643.153 [NAL9602](INFO): GPS fix at 20221013T164725: (36.802768, -121.788041) 2022-10-13T16:47:23.164Z,1665679643.164 [Default:CheckIn:Read_GPS] Stopped 2022-10-13T16:47:23.164Z,1665679643.164 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-10-13T16:47:30.740Z,1665679650.740 [DataOverHttps](INFO): Sending 178 bytes from file Logs/20221013T155203/Courier0024.lzma 2022-10-13T16:47:31.742Z,1665679651.742 [DataOverHttps](INFO): Moved sent file to Logs/20221013T155203/Courier0024.lzma.bak 2022-10-13T16:47:31.743Z,1665679651.743 [DataOverHttps](INFO): SBD MOMSN=17244663 2022-10-13T16:47:47.465Z,1665679667.465 [DataOverHttps](INFO): Sending 235 bytes from file Logs/20221013T155203/Express0025.lzma 2022-10-13T16:47:48.466Z,1665679668.466 [DataOverHttps](INFO): Moved sent file to Logs/20221013T155203/Express0025.lzma.bak 2022-10-13T16:47:48.466Z,1665679668.466 [DataOverHttps](INFO): SBD MOMSN=17244668 2022-10-13T16:47:49.836Z,1665679669.836 [Default:CheckIn:Read_Iridium] Stopped 2022-10-13T16:47:49.836Z,1665679669.836 [Default:CheckIn:C.Wait] Running Loop=1 2022-10-13T16:47:49.837Z,1665679669.837 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-10-13T16:47:55.875Z,1665679675.875 [NAL9602](INFO): Not Powering down - fast GPS 2022-10-13T16:52:50.411Z,1665679970.411 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-10-13T16:52:50.412Z,1665679970.412 [Default:CheckIn:C.Wait] Stopped 2022-10-13T16:52:50.412Z,1665679970.412 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-10-13T16:52:50.412Z,1665679970.412 [Default:CheckIn:D] Running Loop=1 2022-10-13T16:52:50.824Z,1665679970.824 [Default:CheckIn:D] Stopped 2022-10-13T16:52:50.824Z,1665679970.824 [Default:CheckIn:E] Running Loop=1 2022-10-13T16:52:51.224Z,1665679971.224 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 89.346077 min 2022-10-13T16:52:51.224Z,1665679971.224 [Default:CheckIn:E] Stopped 2022-10-13T16:52:51.224Z,1665679971.224 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-10-13T16:52:51.224Z,1665679971.224 [Default:CheckIn] Stopped 2022-10-13T16:52:51.224Z,1665679971.224 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-10-13T16:52:51.224Z,1665679971.224 [Default:CheckIn](INFO): Running loop #13 2022-10-13T16:52:51.225Z,1665679971.225 [Default:CheckIn] Running Loop=13 2022-10-13T16:52:51.225Z,1665679971.225 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-10-13T16:52:51.225Z,1665679971.225 [Default:CheckIn:Read_GPS] Running Loop=1 2022-10-13T16:52:53.246Z,1665679973.246 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165255.00,A,3648.16652,N,12147.28473,W,0.039,0.00,131022,,,D*74 2022-10-13T16:52:53.249Z,1665679973.249 [NAL9602](INFO): GPS fix at 20221013T165255: (36.802775, -121.788079) 2022-10-13T16:52:53.259Z,1665679973.259 [Default:CheckIn:Read_GPS] Stopped 2022-10-13T16:52:53.259Z,1665679973.259 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-10-13T16:53:01.148Z,1665679981.148 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20221013T155203/Courier0027.lzma 2022-10-13T16:53:02.159Z,1665679982.159 [DataOverHttps](INFO): Moved sent file to Logs/20221013T155203/Courier0027.lzma.bak 2022-10-13T16:53:02.159Z,1665679982.159 [DataOverHttps](INFO): SBD MOMSN=17244673 2022-10-13T16:53:17.953Z,1665679997.953 [DataOverHttps](INFO): Sending 140 bytes from file Logs/20221013T155203/Express0028.lzma 2022-10-13T16:53:18.954Z,1665679998.954 [DataOverHttps](INFO): Moved sent file to Logs/20221013T155203/Express0028.lzma.bak 2022-10-13T16:53:18.955Z,1665679998.955 [DataOverHttps](INFO): SBD MOMSN=17244676 2022-10-13T16:53:20.313Z,1665680000.313 [Default:CheckIn:Read_Iridium] Stopped 2022-10-13T16:53:20.314Z,1665680000.314 [Default:CheckIn:C.Wait] Running Loop=1 2022-10-13T16:53:20.314Z,1665680000.314 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-10-13T16:57:55.436Z,1665680275.436 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-10-13T16:58:20.898Z,1665680300.898 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-10-13T16:58:20.898Z,1665680300.898 [Default:CheckIn:C.Wait] Stopped 2022-10-13T16:58:20.898Z,1665680300.898 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-10-13T16:58:20.899Z,1665680300.899 [Default:CheckIn:D] Running Loop=1 2022-10-13T16:58:21.310Z,1665680301.310 [Default:CheckIn:D] Stopped 2022-10-13T16:58:21.310Z,1665680301.310 [Default:CheckIn:E] Running Loop=1 2022-10-13T16:58:21.716Z,1665680301.716 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 94.854183 min 2022-10-13T16:58:21.716Z,1665680301.716 [Default:CheckIn:E] Stopped 2022-10-13T16:58:21.716Z,1665680301.716 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-10-13T16:58:21.716Z,1665680301.716 [Default:CheckIn] Stopped 2022-10-13T16:58:21.716Z,1665680301.716 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-10-13T16:58:21.717Z,1665680301.717 [Default:CheckIn](INFO): Running loop #14 2022-10-13T16:58:21.717Z,1665680301.717 [Default:CheckIn] Running Loop=14 2022-10-13T16:58:21.717Z,1665680301.717 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-10-13T16:58:21.717Z,1665680301.717 [Default:CheckIn:Read_GPS] Running Loop=1 2022-10-13T16:58:23.719Z,1665680303.719 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165825.00,A,3648.16913,N,12147.28809,W,0.486,41.58,131022,,,D*4A 2022-10-13T16:58:23.722Z,1665680303.722 [NAL9602](INFO): GPS fix at 20221013T165825: (36.802819, -121.788135) 2022-10-13T16:58:23.749Z,1665680303.749 [Default:CheckIn:Read_GPS] Stopped 2022-10-13T16:58:23.750Z,1665680303.750 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-10-13T16:58:30.632Z,1665680310.632 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20221013T155203/Courier0030.lzma 2022-10-13T16:58:31.634Z,1665680311.634 [DataOverHttps](INFO): Moved sent file to Logs/20221013T155203/Courier0030.lzma.bak 2022-10-13T16:58:31.635Z,1665680311.635 [DataOverHttps](INFO): SBD MOMSN=17244679 2022-10-13T16:58:47.449Z,1665680327.449 [DataOverHttps](INFO): Sending 216 bytes from file Logs/20221013T155203/Express0031.lzma 2022-10-13T16:58:48.450Z,1665680328.450 [DataOverHttps](INFO): Moved sent file to Logs/20221013T155203/Express0031.lzma.bak 2022-10-13T16:58:48.451Z,1665680328.451 [DataOverHttps](INFO): SBD MOMSN=17244682 2022-10-13T16:58:49.999Z,1665680329.999 [Default:CheckIn:Read_Iridium] Stopped 2022-10-13T16:58:49.999Z,1665680329.999 [Default:CheckIn:C.Wait] Running Loop=1 2022-10-13T16:58:49.000Z,1665680330.000 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-10-13T16:58:55.645Z,1665680335.645 [NAL9602](INFO): Not Powering down - fast GPS 2022-10-13T16:59:23.978Z,1665680363.978 [CBIT](INFO): Clearing failed state for component DropWeight 2022-10-13T16:59:23.978Z,1665680363.978 [DropWeight] No Fault, FailCount= 1 2022-10-13T17:03:50.621Z,1665680630.621 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-10-13T17:03:50.622Z,1665680630.622 [Default:CheckIn:C.Wait] Stopped 2022-10-13T17:03:50.622Z,1665680630.622 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-10-13T17:03:50.622Z,1665680630.622 [Default:CheckIn:D] Running Loop=1 2022-10-13T17:03:51.028Z,1665680631.028 [Default:CheckIn:D] Stopped 2022-10-13T17:03:51.028Z,1665680631.028 [Default:CheckIn:E] Running Loop=1 2022-10-13T17:03:51.454Z,1665680631.454 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 100.349479 min 2022-10-13T17:03:51.454Z,1665680631.454 [Default:CheckIn:E] Stopped 2022-10-13T17:03:51.454Z,1665680631.454 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-10-13T17:03:51.454Z,1665680631.454 [Default:CheckIn] Stopped 2022-10-13T17:03:51.454Z,1665680631.454 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-10-13T17:03:51.455Z,1665680631.455 [Default:CheckIn](INFO): Running loop #15 2022-10-13T17:03:51.455Z,1665680631.455 [Default:CheckIn] Running Loop=15 2022-10-13T17:03:51.455Z,1665680631.455 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-10-13T17:03:51.455Z,1665680631.455 [Default:CheckIn:Read_GPS] Running Loop=1 2022-10-13T17:03:53.423Z,1665680633.423 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170355.00,A,3648.17581,N,12147.28088,W,2.333,190.70,131022,,,A*7C 2022-10-13T17:03:53.426Z,1665680633.426 [NAL9602](INFO): GPS fix at 20221013T170355: (36.802930, -121.788015) 2022-10-13T17:03:53.478Z,1665680633.478 [Default:CheckIn:Read_GPS] Stopped 2022-10-13T17:03:53.478Z,1665680633.478 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-10-13T17:04:04.285Z,1665680644.285 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20221013T155203/Courier0033.lzma 2022-10-13T17:04:05.283Z,1665680645.283 [DataOverHttps](INFO): Moved sent file to Logs/20221013T155203/Courier0033.lzma.bak 2022-10-13T17:04:05.283Z,1665680645.283 [DataOverHttps](INFO): SBD MOMSN=17244686 2022-10-13T17:04:29.489Z,1665680669.489 [DataOverHttps](INFO): Sending 139 bytes from file Logs/20221013T155203/Express0034.lzma 2022-10-13T17:04:30.482Z,1665680670.482 [DataOverHttps](INFO): Moved sent file to Logs/20221013T155203/Express0034.lzma.bak 2022-10-13T17:04:30.483Z,1665680670.483 [DataOverHttps](INFO): SBD MOMSN=17244689 2022-10-13T17:04:31.927Z,1665680671.927 [Default:CheckIn:Read_Iridium] Stopped 2022-10-13T17:04:31.927Z,1665680671.927 [Default:CheckIn:C.Wait] Running Loop=1 2022-10-13T17:04:31.927Z,1665680671.927 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-10-13T17:08:55.302Z,1665680935.302 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-10-13T17:09:26.010Z,1665680966.010 [NAL9602](INFO): Not Powering down - fast GPS 2022-10-13T17:09:32.488Z,1665680972.488 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-10-13T17:09:32.493Z,1665680972.493 [Default:CheckIn:C.Wait] Stopped 2022-10-13T17:09:32.493Z,1665680972.493 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-10-13T17:09:32.495Z,1665680972.495 [Default:CheckIn:D] Running Loop=1 2022-10-13T17:09:32.901Z,1665680972.901 [Default:CheckIn:D] Stopped 2022-10-13T17:09:32.901Z,1665680972.901 [Default:CheckIn:E] Running Loop=1 2022-10-13T17:09:33.331Z,1665680973.331 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 106.047371 min 2022-10-13T17:09:33.331Z,1665680973.331 [Default:CheckIn:E] Stopped 2022-10-13T17:09:33.331Z,1665680973.331 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-10-13T17:09:33.331Z,1665680973.331 [Default:CheckIn] Stopped 2022-10-13T17:09:33.331Z,1665680973.331 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-10-13T17:09:33.331Z,1665680973.331 [Default:CheckIn](INFO): Running loop #16 2022-10-13T17:09:33.332Z,1665680973.332 [Default:CheckIn] Running Loop=16 2022-10-13T17:09:33.332Z,1665680973.332 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-10-13T17:09:33.332Z,1665680973.332 [Default:CheckIn:Read_GPS] Running Loop=1 2022-10-13T17:09:35.300Z,1665680975.300 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170937.00,A,3648.15866,N,12147.29218,W,2.099,223.37,131022,,,A*75 2022-10-13T17:09:35.302Z,1665680975.302 [NAL9602](INFO): GPS fix at 20221013T170937: (36.802644, -121.788203) 2022-10-13T17:09:35.352Z,1665680975.352 [Default:CheckIn:Read_GPS] Stopped 2022-10-13T17:09:35.353Z,1665680975.353 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-10-13T17:09:47.040Z,1665680987.040 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20221013T155203/Courier0036.lzma 2022-10-13T17:09:48.043Z,1665680988.043 [DataOverHttps](INFO): Moved sent file to Logs/20221013T155203/Courier0036.lzma.bak 2022-10-13T17:09:48.043Z,1665680988.043 [DataOverHttps](INFO): SBD MOMSN=17244692 2022-10-13T17:10:05.720Z,1665681005.720 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2022-10-13T17:10:05.797Z,1665681005.797 [NAL9602](ERROR): received: +CSQ:0 OK309, 2, 0, 0, 0 OK 2022-10-13T17:10:12.217Z,1665681012.217 [DataOverHttps](INFO): Sending 225 bytes from file Logs/20221013T155203/Express0037.lzma 2022-10-13T17:10:13.219Z,1665681013.219 [DataOverHttps](INFO): Moved sent file to Logs/20221013T155203/Express0037.lzma.bak 2022-10-13T17:10:13.219Z,1665681013.219 [DataOverHttps](INFO): SBD MOMSN=17244695 2022-10-13T17:10:14.654Z,1665681014.654 [Default:CheckIn:Read_Iridium] Stopped 2022-10-13T17:10:14.654Z,1665681014.654 [Default:CheckIn:C.Wait] Running Loop=1 2022-10-13T17:10:14.654Z,1665681014.654 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-10-13T17:14:37.616Z,1665681277.616 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-10-13T17:15:08.316Z,1665681308.316 [NAL9602](INFO): Not Powering down - fast GPS 2022-10-13T17:15:15.204Z,1665681315.204 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-10-13T17:15:15.205Z,1665681315.205 [Default:CheckIn:C.Wait] Stopped 2022-10-13T17:15:15.205Z,1665681315.205 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-10-13T17:15:15.205Z,1665681315.205 [Default:CheckIn:D] Running Loop=1 2022-10-13T17:15:15.596Z,1665681315.596 [Default:CheckIn:D] Stopped 2022-10-13T17:15:15.596Z,1665681315.596 [Default:CheckIn:E] Running Loop=1 2022-10-13T17:15:16.001Z,1665681316.001 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 111.758960 min 2022-10-13T17:15:16.001Z,1665681316.001 [Default:CheckIn:E] Stopped 2022-10-13T17:15:16.001Z,1665681316.001 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-10-13T17:15:16.001Z,1665681316.001 [Default:CheckIn] Stopped 2022-10-13T17:15:16.001Z,1665681316.001 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-10-13T17:15:16.001Z,1665681316.001 [Default:CheckIn](INFO): Running loop #17 2022-10-13T17:15:16.002Z,1665681316.002 [Default:CheckIn] Running Loop=17 2022-10-13T17:15:16.002Z,1665681316.002 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-10-13T17:15:16.002Z,1665681316.002 [Default:CheckIn:Read_GPS] Running Loop=1 2022-10-13T17:15:18.018Z,1665681318.018 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171517.00,A,3648.16832,N,12147.28712,W,1.186,198.46,131022,,,A*7F 2022-10-13T17:15:18.020Z,1665681318.020 [NAL9602](INFO): GPS fix at 20221013T171517: (36.802805, -121.788119) 2022-10-13T17:15:18.031Z,1665681318.031 [Default:CheckIn:Read_GPS] Stopped 2022-10-13T17:15:18.031Z,1665681318.031 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-10-13T17:15:25.710Z,1665681325.710 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20221013T155203/Courier0039.lzma 2022-10-13T17:15:26.713Z,1665681326.713 [DataOverHttps](INFO): Moved sent file to Logs/20221013T155203/Courier0039.lzma.bak 2022-10-13T17:15:26.713Z,1665681326.713 [DataOverHttps](INFO): SBD MOMSN=17244699 2022-10-13T17:15:35.024Z,1665681335.024 [DataOverHttps](IMPORTANT): SBD MTMSN=20221013T171534 2022-10-13T17:15:42.715Z,1665681342.715 [DataOverHttps](INFO): Sending 216 bytes from file Logs/20221013T155203/Express0040.lzma 2022-10-13T17:15:42.718Z,1665681342.718 [DataOverHttps](INFO): Received command: strobe off 2022-10-13T17:15:42.728Z,1665681342.728 [CommandExec](IMPORTANT): got command strobe off 2022-10-13T17:15:42.729Z,1665681342.729 [CommandExec](IMPORTANT): Deactivating strobe 2022-10-13T17:15:43.966Z,1665681343.966 [DataOverHttps](INFO): Moved sent file to Logs/20221013T155203/Express0040.lzma.bak 2022-10-13T17:15:43.966Z,1665681343.966 [DataOverHttps](INFO): SBD MOMSN=17244703 2022-10-13T17:15:59.622Z,1665681359.622 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20221013T155203/Courier0042.lzma 2022-10-13T17:16:00.625Z,1665681360.625 [DataOverHttps](INFO): Moved sent file to Logs/20221013T155203/Courier0042.lzma.bak 2022-10-13T17:16:00.625Z,1665681360.625 [DataOverHttps](INFO): SBD MOMSN=17244708 2022-10-13T17:16:16.515Z,1665681376.515 [DataOverHttps](INFO): Sending 193 bytes from file Logs/20221013T155203/Express0043.lzma 2022-10-13T17:16:17.517Z,1665681377.517 [DataOverHttps](INFO): Moved sent file to Logs/20221013T155203/Express0043.lzma.bak 2022-10-13T17:16:17.517Z,1665681377.517 [DataOverHttps](INFO): SBD MOMSN=17244710 2022-10-13T17:16:18.647Z,1665681378.647 [Default:CheckIn:Read_Iridium] Stopped 2022-10-13T17:16:18.647Z,1665681378.647 [Default:CheckIn:C.Wait] Running Loop=1 2022-10-13T17:16:18.647Z,1665681378.647 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-10-13T17:20:20.224Z,1665681620.224 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-10-13T17:20:50.928Z,1665681650.928 [NAL9602](INFO): Not Powering down - fast GPS 2022-10-13T17:21:19.216Z,1665681679.216 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-10-13T17:21:19.216Z,1665681679.216 [Default:CheckIn:C.Wait] Stopped 2022-10-13T17:21:19.216Z,1665681679.216 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-10-13T17:21:19.216Z,1665681679.216 [Default:CheckIn:D] Running Loop=1 2022-10-13T17:21:19.626Z,1665681679.626 [Default:CheckIn:D] Stopped 2022-10-13T17:21:19.626Z,1665681679.626 [Default:CheckIn:E] Running Loop=1 2022-10-13T17:21:20.030Z,1665681680.030 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 117.826123 min 2022-10-13T17:21:20.030Z,1665681680.030 [Default:CheckIn:E] Stopped 2022-10-13T17:21:20.030Z,1665681680.030 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-10-13T17:21:20.030Z,1665681680.030 [Default:CheckIn] Stopped 2022-10-13T17:21:20.030Z,1665681680.030 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-10-13T17:21:20.031Z,1665681680.031 [Default:CheckIn](INFO): Running loop #18 2022-10-13T17:21:20.031Z,1665681680.031 [Default:CheckIn] Running Loop=18 2022-10-13T17:21:20.031Z,1665681680.031 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-10-13T17:21:20.031Z,1665681680.031 [Default:CheckIn:Read_GPS] Running Loop=1 2022-10-13T17:21:22.038Z,1665681682.038 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172121.00,A,3648.17036,N,12147.29036,W,0.778,250.14,131022,,,A*76 2022-10-13T17:21:22.041Z,1665681682.041 [NAL9602](INFO): GPS fix at 20221013T172121: (36.802839, -121.788173) 2022-10-13T17:21:22.074Z,1665681682.074 [Default:CheckIn:Read_GPS] Stopped 2022-10-13T17:21:22.074Z,1665681682.074 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-10-13T17:21:28.995Z,1665681688.995 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20221013T155203/Courier0045.lzma 2022-10-13T17:21:29.997Z,1665681689.997 [DataOverHttps](INFO): Moved sent file to Logs/20221013T155203/Courier0045.lzma.bak 2022-10-13T17:21:29.997Z,1665681689.997 [DataOverHttps](INFO): SBD MOMSN=17244715 2022-10-13T17:21:45.795Z,1665681705.795 [DataOverHttps](INFO): Sending 214 bytes from file Logs/20221013T155203/Express0046.lzma 2022-10-13T17:21:46.797Z,1665681706.797 [DataOverHttps](INFO): Moved sent file to Logs/20221013T155203/Express0046.lzma.bak 2022-10-13T17:21:46.797Z,1665681706.797 [DataOverHttps](INFO): SBD MOMSN=17244718 2022-10-13T17:21:47.904Z,1665681707.904 [Default:CheckIn:Read_Iridium] Stopped 2022-10-13T17:21:47.904Z,1665681707.904 [Default:CheckIn:C.Wait] Running Loop=1 2022-10-13T17:21:47.904Z,1665681707.904 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-10-13T17:21:52.741Z,1665681712.741 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2022-10-13T17:21:52.823Z,1665681712.823 [NAL9602](ERROR): received: +CSQ:0 OK309, 2, 0, 0, 0 OK 2022-10-13T17:26:24.273Z,1665681984.273 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-10-13T17:26:48.486Z,1665682008.486 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-10-13T17:26:48.486Z,1665682008.486 [Default:CheckIn:C.Wait] Stopped 2022-10-13T17:26:48.486Z,1665682008.486 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-10-13T17:26:48.487Z,1665682008.487 [Default:CheckIn:D] Running Loop=1 2022-10-13T17:26:48.886Z,1665682008.886 [Default:CheckIn:D] Stopped 2022-10-13T17:26:48.886Z,1665682008.886 [Default:CheckIn:E] Running Loop=1 2022-10-13T17:26:49.321Z,1665682009.321 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 123.313778 min 2022-10-13T17:26:49.321Z,1665682009.321 [Default:CheckIn:E] Stopped 2022-10-13T17:26:49.321Z,1665682009.321 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-10-13T17:26:49.321Z,1665682009.321 [Default:CheckIn] Stopped 2022-10-13T17:26:49.321Z,1665682009.321 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-10-13T17:26:49.322Z,1665682009.322 [Default:CheckIn](INFO): Running loop #19 2022-10-13T17:26:49.322Z,1665682009.322 [Default:CheckIn] Running Loop=19 2022-10-13T17:26:49.322Z,1665682009.322 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-10-13T17:26:49.322Z,1665682009.322 [Default:CheckIn:Read_GPS] Running Loop=1 2022-10-13T17:26:51.306Z,1665682011.306 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172650.00,A,3648.16222,N,12147.28653,W,0.778,71.19,131022,,,A*49 2022-10-13T17:26:51.308Z,1665682011.308 [NAL9602](INFO): GPS fix at 20221013T172650: (36.802704, -121.788109) 2022-10-13T17:26:51.318Z,1665682011.318 [Default:CheckIn:Read_GPS] Stopped 2022-10-13T17:26:51.318Z,1665682011.318 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-10-13T17:26:58.306Z,1665682018.306 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20221013T155203/Courier0048.lzma 2022-10-13T17:26:59.309Z,1665682019.309 [DataOverHttps](INFO): Moved sent file to Logs/20221013T155203/Courier0048.lzma.bak 2022-10-13T17:26:59.309Z,1665682019.309 [DataOverHttps](INFO): SBD MOMSN=17244722 2022-10-13T17:27:15.039Z,1665682035.039 [DataOverHttps](INFO): Sending 215 bytes from file Logs/20221013T155203/Express0049.lzma 2022-10-13T17:27:16.041Z,1665682036.041 [DataOverHttps](INFO): Moved sent file to Logs/20221013T155203/Express0049.lzma.bak 2022-10-13T17:27:16.042Z,1665682036.042 [DataOverHttps](INFO): SBD MOMSN=17244725 2022-10-13T17:27:17.162Z,1665682037.162 [Default:CheckIn:Read_Iridium] Stopped 2022-10-13T17:27:17.162Z,1665682037.162 [Default:CheckIn:C.Wait] Running Loop=1 2022-10-13T17:27:17.162Z,1665682037.162 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-10-13T17:27:23.210Z,1665682043.210 [NAL9602](INFO): Not Powering down - fast GPS 2022-10-13T17:29:25.220Z,1665682165.220 [DropWeight](CRITICAL): DROP WEIGHT MISSING. 2022-10-13T17:29:25.220Z,1665682165.220 [DropWeight] Hardware Fault, FailCount= 1 2022-10-13T17:29:25.220Z,1665682165.220 [DropWeight](ERROR): Hardware Fault 2022-10-13T17:29:25.276Z,1665682165.276 [CBIT](INFO): Critical error at 20221013T172925 2022-10-13T17:29:25.279Z,1665682165.279 [CBIT](ERROR): Hardware Fault in component: DropWeight 2022-10-13T17:29:25.279Z,1665682165.279 [CBIT](CRITICAL): Hardware Fault in component: DropWeight 2022-10-13T17:29:25.672Z,1665682165.672 [CBIT](INFO): Critical error at 20221013T172925 2022-10-13T17:32:17.742Z,1665682337.742 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-10-13T17:32:17.742Z,1665682337.742 [Default:CheckIn:C.Wait] Stopped 2022-10-13T17:32:17.742Z,1665682337.742 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-10-13T17:32:17.742Z,1665682337.742 [Default:CheckIn:D] Running Loop=1 2022-10-13T17:32:18.145Z,1665682338.145 [Default:CheckIn:D] Stopped 2022-10-13T17:32:18.146Z,1665682338.146 [Default:CheckIn:E] Running Loop=1 2022-10-13T17:32:18.547Z,1665682338.547 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 128.801440 min 2022-10-13T17:32:18.547Z,1665682338.547 [Default:CheckIn:E] Stopped 2022-10-13T17:32:18.547Z,1665682338.547 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-10-13T17:32:18.547Z,1665682338.547 [Default:CheckIn] Stopped 2022-10-13T17:32:18.547Z,1665682338.547 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-10-13T17:32:18.547Z,1665682338.547 [Default:CheckIn](INFO): Running loop #20 2022-10-13T17:32:18.548Z,1665682338.547 [Default:CheckIn] Running Loop=20 2022-10-13T17:32:18.548Z,1665682338.548 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-10-13T17:32:18.548Z,1665682338.548 [Default:CheckIn:Read_GPS] Running Loop=1 2022-10-13T17:32:20.568Z,1665682340.568 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173219.00,A,3648.16403,N,12147.27996,W,0.700,117.98,131022,,,A*7A 2022-10-13T17:32:20.570Z,1665682340.570 [NAL9602](INFO): GPS fix at 20221013T173219: (36.802734, -121.787999) 2022-10-13T17:32:20.581Z,1665682340.581 [Default:CheckIn:Read_GPS] Stopped 2022-10-13T17:32:20.581Z,1665682340.581 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-10-13T17:32:28.155Z,1665682348.155 [DataOverHttps](INFO): Sending 148 bytes from file Logs/20221013T155203/Courier0051.lzma 2022-10-13T17:32:29.157Z,1665682349.157 [DataOverHttps](INFO): Moved sent file to Logs/20221013T155203/Courier0051.lzma.bak 2022-10-13T17:32:29.157Z,1665682349.157 [DataOverHttps](INFO): SBD MOMSN=17244729 2022-10-13T17:32:44.907Z,1665682364.907 [DataOverHttps](INFO): Sending 141 bytes from file Logs/20221013T155203/Express0052.lzma 2022-10-13T17:32:45.909Z,1665682365.909 [DataOverHttps](INFO): Moved sent file to Logs/20221013T155203/Express0052.lzma.bak 2022-10-13T17:32:45.909Z,1665682365.909 [DataOverHttps](INFO): SBD MOMSN=17244734 2022-10-13T17:32:47.249Z,1665682367.249 [Default:CheckIn:Read_Iridium] Stopped 2022-10-13T17:32:47.249Z,1665682367.249 [Default:CheckIn:C.Wait] Running Loop=1 2022-10-13T17:32:47.249Z,1665682367.249 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-10-13T17:32:51.261Z,1665682371.261 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2022-10-13T17:32:51.343Z,1665682371.343 [NAL9602](ERROR): received: +CSQ:0 OK309, 2, 0, 0, 0 OK 2022-10-13T17:37:22.350Z,1665682642.350 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-10-13T17:37:47.823Z,1665682667.823 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-10-13T17:37:47.823Z,1665682667.823 [Default:CheckIn:C.Wait] Stopped 2022-10-13T17:37:47.823Z,1665682667.823 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-10-13T17:37:47.824Z,1665682667.824 [Default:CheckIn:D] Running Loop=1 2022-10-13T17:37:48.208Z,1665682668.208 [Default:CheckIn:D] Stopped 2022-10-13T17:37:48.208Z,1665682668.208 [Default:CheckIn:E] Running Loop=1 2022-10-13T17:37:48.613Z,1665682668.613 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 134.302482 min 2022-10-13T17:37:48.613Z,1665682668.613 [Default:CheckIn:E] Stopped 2022-10-13T17:37:48.613Z,1665682668.613 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-10-13T17:37:48.613Z,1665682668.613 [Default:CheckIn] Stopped 2022-10-13T17:37:48.613Z,1665682668.613 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-10-13T17:37:48.614Z,1665682668.614 [Default:CheckIn](INFO): Running loop #21 2022-10-13T17:37:48.614Z,1665682668.614 [Default:CheckIn] Running Loop=21 2022-10-13T17:37:48.614Z,1665682668.614 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-10-13T17:37:48.614Z,1665682668.614 [Default:CheckIn:Read_GPS] Running Loop=1 2022-10-13T17:37:50.627Z,1665682670.627 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173749.00,A,3648.16579,N,12147.28842,W,0.739,158.08,131022,,,A*79 2022-10-13T17:37:50.629Z,1665682670.629 [NAL9602](INFO): GPS fix at 20221013T173749: (36.802763, -121.788140) 2022-10-13T17:37:50.663Z,1665682670.663 [Default:CheckIn:Read_GPS] Stopped 2022-10-13T17:37:50.663Z,1665682670.663 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-10-13T17:37:58.603Z,1665682678.603 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20221013T155203/Courier0054.lzma 2022-10-13T17:37:59.605Z,1665682679.605 [DataOverHttps](INFO): Moved sent file to Logs/20221013T155203/Courier0054.lzma.bak 2022-10-13T17:37:59.605Z,1665682679.605 [DataOverHttps](INFO): SBD MOMSN=17244737 2022-10-13T17:38:15.663Z,1665682695.663 [DataOverHttps](INFO): Sending 217 bytes from file Logs/20221013T155203/Express0055.lzma 2022-10-13T17:38:16.665Z,1665682696.665 [DataOverHttps](INFO): Moved sent file to Logs/20221013T155203/Express0055.lzma.bak 2022-10-13T17:38:16.665Z,1665682696.665 [DataOverHttps](INFO): SBD MOMSN=17244740 2022-10-13T17:38:18.118Z,1665682698.118 [Default:CheckIn:Read_Iridium] Stopped 2022-10-13T17:38:18.118Z,1665682698.118 [Default:CheckIn:C.Wait] Running Loop=1 2022-10-13T17:38:18.118Z,1665682698.118 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-10-13T17:38:23.352Z,1665682703.352 [NAL9602](INFO): Not Powering down - fast GPS 2022-10-13T17:41:18.392Z,1665682878.392 [CommandExec](IMPORTANT): got command quit 2022-10-13T17:41:19.400Z,1665682879.400 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread. 2022-10-13T17:41:19.400Z,1665682879.400 [CommandExec](INFO): Uninitializing the command executive. 2022-10-13T17:41:19.400Z,1665682879.400 [CommandExec](INFO): Uninitializing the command scheduler. 2022-10-13T17:41:19.401Z,1665682879.401 [CommandExec ThreadHandler](INFO): Thread cancelled. 2022-10-13T17:41:19.415Z,1665682879.415 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2022-10-13T17:41:19.415Z,1665682879.415 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2022-10-13T17:41:19.415Z,1665682879.415 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2022-10-13T17:41:19.416Z,1665682879.416 [NavChartDb](INFO): Join timeout helper Thread ID is 9836 2022-10-13T17:41:19.763Z,1665682879.763 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2022-10-13T17:41:19.764Z,1665682879.764 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2022-10-13T17:41:19.771Z,1665682879.771 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2022-10-13T17:41:19.771Z,1665682879.771 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2022-10-13T17:41:19.772Z,1665682879.772 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 9837 2022-10-13T17:41:19.915Z,1665682879.915 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2022-10-13T17:41:19.916Z,1665682879.916 [WetLabsBB2FL](INFO): Powering down 2022-10-13T17:41:19.916Z,1665682879.916 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2022-10-13T17:41:19.919Z,1665682879.919 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler 2022-10-13T17:41:19.919Z,1665682879.919 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2022-10-13T17:41:19.920Z,1665682879.920 [CTD_Seabird](INFO): Join timeout helper Thread ID is 9838 2022-10-13T17:41:20.875Z,1665682880.875 [CTD_Seabird](INFO): Powering down 2022-10-13T17:41:20.892Z,1665682880.892 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread. 2022-10-13T17:41:20.903Z,1665682880.903 [CTD_Seabird](INFO): Powering down 2022-10-13T17:41:20.915Z,1665682880.915 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2022-10-13T17:41:20.931Z,1665682880.931 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2022-10-13T17:41:20.931Z,1665682880.931 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2022-10-13T17:41:20.932Z,1665682880.932 [Radio_Surface](INFO): Join timeout helper Thread ID is 9839 2022-10-13T17:41:21.271Z,1665682881.271 [Radio_Surface](INFO): Powering down 2022-10-13T17:41:21.272Z,1665682881.272 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2022-10-13T17:41:21.272Z,1665682881.272 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2022-10-13T17:41:21.291Z,1665682881.291 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler 2022-10-13T17:41:21.291Z,1665682881.291 [Onboard ThreadHandler](INFO): Thread cancelled. 2022-10-13T17:41:21.291Z,1665682881.291 [Onboard](INFO): Join timeout helper Thread ID is 9840 2022-10-13T17:41:21.570Z,1665682881.570 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2022-10-13T17:41:25.031Z,1665682885.031 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread. 2022-10-13T17:41:25.031Z,1665682885.031 [Onboard ThreadHandler](INFO): Thread cancelled. 2022-10-13T17:41:25.040Z,1665682885.040 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler 2022-10-13T17:41:25.040Z,1665682885.040 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2022-10-13T17:41:25.040Z,1665682885.040 [DataOverHttps](INFO): Join timeout helper Thread ID is 9841 2022-10-13T17:41:25.967Z,1665682885.967 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread. 2022-10-13T17:41:25.968Z,1665682885.968 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2022-10-13T17:41:25.980Z,1665682885.980 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2022-10-13T17:41:25.980Z,1665682885.980 [logger ThreadHandler](INFO): Thread cancelled. 2022-10-13T17:41:25.980Z,1665682885.980 [logger](INFO): Join timeout helper Thread ID is 9842 2022-10-13T17:41:25.991Z,1665682885.991 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2022-10-13T17:41:25.991Z,1665682885.991 [logger ThreadHandler](INFO): Thread cancelled. 2022-10-13T17:41:26.004Z,1665682886.004 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2022-10-13T17:41:26.004Z,1665682886.004 [CommandLine ThreadHandler](INFO): Thread cancelled. 2022-10-13T17:41:26.004Z,1665682886.004 [CommandLine](INFO): Join timeout helper Thread ID is 9843 2022-10-13T17:41:26.059Z,1665682886.059 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2022-10-13T17:41:26.059Z,1665682886.059 [CommandLine ThreadHandler](INFO): Thread cancelled. 2022-10-13T17:41:26.064Z,1665682886.064 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler 2022-10-13T17:41:26.064Z,1665682886.064 [CommandExec ThreadHandler](INFO): Thread cancelled. 2022-10-13T17:41:26.064Z,1665682886.064 [CommandExec](INFO): Join timeout helper Thread ID is 9844 2022-10-13T17:41:26.065Z,1665682886.065 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2022-10-13T17:41:26.066Z,1665682886.066 [controlThread ThreadHandler](INFO): Thread cancelled. 2022-10-13T17:41:26.066Z,1665682886.066 [controlThread](INFO): Join timeout helper Thread ID is 9845 2022-10-13T17:41:26.343Z,1665682886.343 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2022-10-13T17:41:26.344Z,1665682886.344 [controlThread](DEBUG): Uninitializing ControlThread 2022-10-13T17:41:26.344Z,1665682886.344 [AHRS_M2](INFO): Powering down 2022-10-13T17:41:26.416Z,1665682886.416 [NAL9602](INFO): Powering down 2022-10-13T17:41:26.419Z,1665682886.419 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator. 2022-10-13T17:41:26.420Z,1665682886.420 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator. 2022-10-13T17:41:26.420Z,1665682886.420 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2022-10-13T17:41:26.421Z,1665682886.421 [MissionManager](INFO): Uninitializing Mission Default 2022-10-13T17:41:26.421Z,1665682886.421 [Default] Stopped 2022-10-13T17:41:26.421Z,1665682886.421 [Default](DEBUG): Aggregate::uninitialize Default 2022-10-13T17:41:26.421Z,1665682886.421 [Default:B.GoToSurface] Stopped 2022-10-13T17:41:26.421Z,1665682886.421 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2022-10-13T17:41:26.421Z,1665682886.421 [Default:CheckIn] Stopped 2022-10-13T17:41:26.421Z,1665682886.421 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-10-13T17:41:26.421Z,1665682886.421 [Default:CheckIn:C.Wait] Stopped 2022-10-13T17:41:26.421Z,1665682886.421 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-10-13T17:41:26.424Z,1665682886.424 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2022-10-13T17:41:26.424Z,1665682886.424 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2022-10-13T17:41:26.425Z,1665682886.425 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2022-10-13T17:41:26.425Z,1665682886.425 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2022-10-13T17:41:26.425Z,1665682886.425 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2022-10-13T17:41:26.425Z,1665682886.425 [BuoyancyServo](INFO): Powering down 2022-10-13T17:41:26.439Z,1665682886.439 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2022-10-13T17:41:26.439Z,1665682886.439 [ElevatorServo](INFO): Powering down 2022-10-13T17:41:26.440Z,1665682886.440 [MassServo](DEBUG): Uninitialize Mass Servo. 2022-10-13T17:41:26.440Z,1665682886.440 [MassServo](INFO): Powering down 2022-10-13T17:41:26.441Z,1665682886.441 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2022-10-13T17:41:26.441Z,1665682886.441 [RudderServo](INFO): Powering down 2022-10-13T17:41:26.442Z,1665682886.442 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2022-10-13T17:41:26.442Z,1665682886.442 [ThrusterServo](INFO): Powering down 2022-10-13T17:41:26.443Z,1665682886.443 [SBIT](DEBUG): Uninitialize SBIT Component. 2022-10-13T17:41:26.443Z,1665682886.443 [IBIT](DEBUG): Uninitialize IBIT Component. 2022-10-13T17:41:26.444Z,1665682886.444 [CBIT](DEBUG): Uninitialize CBIT Component. 2022-10-13T17:41:26.444Z,1665682886.444 [CBIT](DEBUG): Powering off loads. 2022-10-13T17:41:26.455Z,1665682886.455 [CBIT](DEBUG): Disabling WDT. 2022-10-13T17:41:26.467Z,1665682886.467 [CBIT](DEBUG): Opening all GF detection circuits. 2022-10-13T17:41:26.468Z,1665682886.468 [controlThread ThreadHandler](INFO): Thread cancelled. 2022-10-13T17:41:26.525Z,1665682886.525 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2022-10-13T17:41:26.528Z,1665682886.528 [Onboard ThreadHandler](INFO): Thread cancelled. 2022-10-13T17:41:26.534Z,1665682886.534 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2022-10-13T17:41:26.605Z,1665682886.605 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2022-10-13T17:41:26.608Z,1665682886.608 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2022-10-13T17:41:26.648Z,1665682886.648 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2022-10-13T17:41:26.748Z,1665682886.748 [logger ThreadHandler](INFO): Thread cancelled.