2023-11-15T16:12:27.439Z,1700064747.439 [CommandExec](IMPORTANT): got command restart logs 2023-11-15T16:15:24.562Z,1700064924.562 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2023-11-15T16:15:55.778Z,1700064955.778 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2023-11-15T16:16:26.902Z,1700064986.902 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2023-11-15T16:16:33.044Z,1700064993.044 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-11-15T16:16:33.044Z,1700064993.044 [Default:CheckIn:C.Wait] Stopped 2023-11-15T16:16:33.044Z,1700064993.044 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-11-15T16:16:33.044Z,1700064993.044 [Default:CheckIn:D] Running Loop=1 2023-11-15T16:16:33.445Z,1700064993.445 [Default:CheckIn:D] Stopped 2023-11-15T16:16:33.445Z,1700064993.445 [Default:CheckIn:E] Running Loop=1 2023-11-15T16:16:33.849Z,1700064993.849 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 25.426896 min 2023-11-15T16:16:33.849Z,1700064993.849 [Default:CheckIn:E] Stopped 2023-11-15T16:16:33.850Z,1700064993.850 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-11-15T16:16:33.850Z,1700064993.850 [Default:CheckIn] Stopped 2023-11-15T16:16:33.850Z,1700064993.850 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-11-15T16:16:33.850Z,1700064993.850 [Default:CheckIn](INFO): Running loop #5 2023-11-15T16:16:33.850Z,1700064993.850 [Default:CheckIn] Running Loop=5 2023-11-15T16:16:33.850Z,1700064993.850 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-11-15T16:16:33.850Z,1700064993.850 [Default:CheckIn:Read_GPS] Running Loop=1 2023-11-15T16:16:35.860Z,1700064995.860 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,161635.00,A,3648.40742,N,12148.47014,W,27.972,109.09,151123,,,D*46 2023-11-15T16:16:35.871Z,1700064995.871 [NAL9602](INFO): GPS fix at 20231115T161635: (36.806790, -121.807836) 2023-11-15T16:16:35.882Z,1700064995.882 [Default:CheckIn:Read_GPS] Stopped 2023-11-15T16:16:35.882Z,1700064995.882 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-11-15T16:16:56.464Z,1700065016.464 [NAL9602](INFO): SBD MO Status=1, MOMSN=45811, MT Status=0, MTMSN=0 2023-11-15T16:16:56.464Z,1700065016.464 [NAL9602](INFO): No messages in MT queue 2023-11-15T16:16:58.026Z,1700065018.026 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2023-11-15T16:17:04.413Z,1700065024.413 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=184.194061 2023-11-15T16:17:12.010Z,1700065032.010 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003168 2023-11-15T16:17:18.384Z,1700065038.384 [NAL9602](INFO): SBD MO Status=1, MOMSN=45812, MT Status=0, MTMSN=0 2023-11-15T16:17:18.446Z,1700065038.446 [NAL9602](INFO): Sent 39 bytes from file Logs/20231114T192405/Courier0090.lzma 2023-11-15T16:17:18.446Z,1700065038.446 [NAL9602](INFO): Packets left to send: 0 2023-11-15T16:17:19.438Z,1700065039.438 [DataOverHttps](INFO): Sending 267 bytes from file Logs/20231115T161227/Courier0000.lzma 2023-11-15T16:17:20.403Z,1700065040.403 [DataOverHttps](INFO): Moved sent file to Logs/20231115T161227/Courier0000.lzma.bak 2023-11-15T16:17:20.403Z,1700065040.403 [DataOverHttps](INFO): SBD MOMSN=19067669 2023-11-15T16:17:40.005Z,1700065060.005 [DataOverHttps](INFO): Sending 140 bytes from file Logs/20231114T192405/Express0091.lzma 2023-11-15T16:17:41.007Z,1700065061.007 [DataOverHttps](INFO): Moved sent file to Logs/20231114T192405/Express0091.lzma.bak 2023-11-15T16:17:41.008Z,1700065061.008 [DataOverHttps](INFO): SBD MOMSN=19067674 2023-11-15T16:17:49.137Z,1700065069.137 [NAL9602](INFO): Not Powering down - fast GPS 2023-11-15T16:17:56.834Z,1700065076.834 [DataOverHttps](INFO): Sending 399 bytes from file Logs/20231115T161227/Express0001.lzma 2023-11-15T16:17:57.835Z,1700065077.835 [DataOverHttps](INFO): Moved sent file to Logs/20231115T161227/Express0001.lzma.bak 2023-11-15T16:17:57.835Z,1700065077.835 [DataOverHttps](INFO): SBD MOMSN=19067677 2023-11-15T16:18:13.869Z,1700065093.869 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20231115T161227/Express0004.lzma 2023-11-15T16:18:14.871Z,1700065094.871 [DataOverHttps](INFO): Moved sent file to Logs/20231115T161227/Express0004.lzma.bak 2023-11-15T16:18:14.871Z,1700065094.871 [DataOverHttps](INFO): SBD MOMSN=19067681 2023-11-15T16:18:16.222Z,1700065096.222 [Default:CheckIn:Read_Iridium] Stopped 2023-11-15T16:18:16.223Z,1700065096.223 [Default:CheckIn:C.Wait] Running Loop=1 2023-11-15T16:18:16.223Z,1700065096.223 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-11-15T16:23:16.888Z,1700065396.888 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-11-15T16:23:16.888Z,1700065396.888 [Default:CheckIn:C.Wait] Stopped 2023-11-15T16:23:16.888Z,1700065396.888 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-11-15T16:23:16.889Z,1700065396.889 [Default:CheckIn:D] Running Loop=1 2023-11-15T16:23:17.305Z,1700065397.305 [Default:CheckIn:D] Stopped 2023-11-15T16:23:17.305Z,1700065397.305 [Default:CheckIn:E] Running Loop=1 2023-11-15T16:23:17.702Z,1700065397.702 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 32.157900 min 2023-11-15T16:23:17.702Z,1700065397.702 [Default:CheckIn:E] Stopped 2023-11-15T16:23:17.702Z,1700065397.702 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-11-15T16:23:17.702Z,1700065397.702 [Default:CheckIn] Stopped 2023-11-15T16:23:17.702Z,1700065397.702 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-11-15T16:23:17.702Z,1700065397.702 [Default:CheckIn](INFO): Running loop #6 2023-11-15T16:23:17.702Z,1700065397.702 [Default:CheckIn] Running Loop=6 2023-11-15T16:23:17.702Z,1700065397.702 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-11-15T16:23:17.703Z,1700065397.703 [Default:CheckIn:Read_GPS] Running Loop=1 2023-11-15T16:23:19.712Z,1700065399.712 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162318.00,A,3648.33722,N,12147.12961,W,4.937,187.31,151123,,,D*74 2023-11-15T16:23:19.724Z,1700065399.724 [NAL9602](INFO): GPS fix at 20231115T162318: (36.805620, -121.785494) 2023-11-15T16:23:19.735Z,1700065399.735 [Default:CheckIn:Read_GPS] Stopped 2023-11-15T16:23:19.736Z,1700065399.736 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-11-15T16:23:27.461Z,1700065407.461 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20231115T161227/Courier0006.lzma 2023-11-15T16:23:28.463Z,1700065408.463 [DataOverHttps](INFO): Moved sent file to Logs/20231115T161227/Courier0006.lzma.bak 2023-11-15T16:23:28.463Z,1700065408.463 [DataOverHttps](INFO): SBD MOMSN=19067772 2023-11-15T16:23:44.407Z,1700065424.407 [DataOverHttps](INFO): Sending 144 bytes from file Logs/20231115T161227/Express0007.lzma 2023-11-15T16:23:45.335Z,1700065425.335 [DataOverHttps](INFO): Moved sent file to Logs/20231115T161227/Express0007.lzma.bak 2023-11-15T16:23:45.335Z,1700065425.335 [DataOverHttps](INFO): SBD MOMSN=19067776 2023-11-15T16:23:46.420Z,1700065426.420 [Default:CheckIn:Read_Iridium] Stopped 2023-11-15T16:23:46.421Z,1700065426.421 [Default:CheckIn:C.Wait] Running Loop=1 2023-11-15T16:23:46.421Z,1700065426.421 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-11-15T16:23:47.588Z,1700065427.588 [NAL9602](INFO): SBD MO Status=0, MOMSN=45813, MT Status=0, MTMSN=0 2023-11-15T16:23:47.588Z,1700065427.588 [NAL9602](INFO): No messages in MT queue 2023-11-15T16:24:18.290Z,1700065458.290 [NAL9602](INFO): Not Powering down - fast GPS 2023-11-15T16:28:47.028Z,1700065727.028 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-11-15T16:28:47.029Z,1700065727.029 [Default:CheckIn:C.Wait] Stopped 2023-11-15T16:28:47.029Z,1700065727.029 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-11-15T16:28:47.029Z,1700065727.029 [Default:CheckIn:D] Running Loop=1 2023-11-15T16:28:47.436Z,1700065727.436 [Default:CheckIn:D] Stopped 2023-11-15T16:28:47.436Z,1700065727.436 [Default:CheckIn:E] Running Loop=1 2023-11-15T16:28:47.837Z,1700065727.837 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 37.660079 min 2023-11-15T16:28:47.837Z,1700065727.837 [Default:CheckIn:E] Stopped 2023-11-15T16:28:47.838Z,1700065727.838 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-11-15T16:28:47.838Z,1700065727.838 [Default:CheckIn] Stopped 2023-11-15T16:28:47.838Z,1700065727.838 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-11-15T16:28:47.838Z,1700065727.838 [Default:CheckIn](INFO): Running loop #7 2023-11-15T16:28:47.838Z,1700065727.838 [Default:CheckIn] Running Loop=7 2023-11-15T16:28:47.838Z,1700065727.838 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-11-15T16:28:47.838Z,1700065727.838 [Default:CheckIn:Read_GPS] Running Loop=1 2023-11-15T16:28:49.845Z,1700065729.845 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162849.00,A,3648.15045,N,12147.22331,W,0.039,199.20,151123,,,D*79 2023-11-15T16:28:49.847Z,1700065729.847 [NAL9602](INFO): GPS fix at 20231115T162849: (36.802507, -121.787055) 2023-11-15T16:28:49.858Z,1700065729.858 [Default:CheckIn:Read_GPS] Stopped 2023-11-15T16:28:49.858Z,1700065729.858 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-11-15T16:28:56.925Z,1700065736.925 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20231115T161227/Courier0009.lzma 2023-11-15T16:28:57.927Z,1700065737.927 [DataOverHttps](INFO): Moved sent file to Logs/20231115T161227/Courier0009.lzma.bak 2023-11-15T16:28:57.927Z,1700065737.927 [DataOverHttps](INFO): SBD MOMSN=19067787 2023-11-15T16:29:13.785Z,1700065753.785 [DataOverHttps](INFO): Sending 144 bytes from file Logs/20231115T161227/Express0010.lzma 2023-11-15T16:29:14.787Z,1700065754.787 [DataOverHttps](INFO): Moved sent file to Logs/20231115T161227/Express0010.lzma.bak 2023-11-15T16:29:14.787Z,1700065754.787 [DataOverHttps](INFO): SBD MOMSN=19067790 2023-11-15T16:29:15.876Z,1700065755.876 [Default:CheckIn:Read_Iridium] Stopped 2023-11-15T16:29:15.877Z,1700065755.877 [Default:CheckIn:C.Wait] Running Loop=1 2023-11-15T16:29:15.877Z,1700065755.877 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-11-15T16:29:52.188Z,1700065792.188 [NAL9602](INFO): SBD MO Status=2, MOMSN=45814, MT Status=2, MTMSN=0 2023-11-15T16:29:52.188Z,1700065792.188 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-11-15T16:30:24.508Z,1700065824.508 [NAL9602](INFO): SBD MO Status=2, MOMSN=45814, MT Status=2, MTMSN=0 2023-11-15T16:30:24.508Z,1700065824.508 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-11-15T16:30:44.304Z,1700065844.304 [NAL9602](INFO): SBD MO Status=0, MOMSN=45814, MT Status=0, MTMSN=0 2023-11-15T16:30:44.304Z,1700065844.304 [NAL9602](INFO): No messages in MT queue 2023-11-15T16:31:15.010Z,1700065875.010 [NAL9602](INFO): Not Powering down - fast GPS 2023-11-15T16:34:16.417Z,1700066056.417 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-11-15T16:34:16.417Z,1700066056.417 [Default:CheckIn:C.Wait] Stopped 2023-11-15T16:34:16.417Z,1700066056.417 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-11-15T16:34:16.418Z,1700066056.418 [Default:CheckIn:D] Running Loop=1 2023-11-15T16:34:16.834Z,1700066056.834 [Default:CheckIn:D] Stopped 2023-11-15T16:34:16.834Z,1700066056.834 [Default:CheckIn:E] Running Loop=1 2023-11-15T16:34:17.225Z,1700066057.225 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 43.150049 min 2023-11-15T16:34:17.225Z,1700066057.225 [Default:CheckIn:E] Stopped 2023-11-15T16:34:17.225Z,1700066057.225 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-11-15T16:34:17.225Z,1700066057.225 [Default:CheckIn] Stopped 2023-11-15T16:34:17.237Z,1700066057.237 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-11-15T16:34:17.238Z,1700066057.238 [Default:CheckIn](INFO): Running loop #8 2023-11-15T16:34:17.238Z,1700066057.238 [Default:CheckIn] Running Loop=8 2023-11-15T16:34:17.238Z,1700066057.238 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-11-15T16:34:17.238Z,1700066057.238 [Default:CheckIn:Read_GPS] Running Loop=1 2023-11-15T16:34:19.237Z,1700066059.237 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163418.00,A,3648.14894,N,12147.22492,W,0.097,199.20,151123,,,A*7A 2023-11-15T16:34:19.239Z,1700066059.239 [NAL9602](INFO): GPS fix at 20231115T163418: (36.802482, -121.787082) 2023-11-15T16:34:19.250Z,1700066059.250 [Default:CheckIn:Read_GPS] Stopped 2023-11-15T16:34:19.250Z,1700066059.250 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-11-15T16:34:26.645Z,1700066066.645 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20231115T161227/Courier0012.lzma 2023-11-15T16:34:27.647Z,1700066067.647 [DataOverHttps](INFO): Moved sent file to Logs/20231115T161227/Courier0012.lzma.bak 2023-11-15T16:34:27.647Z,1700066067.647 [DataOverHttps](INFO): SBD MOMSN=19067837 2023-11-15T16:34:34.996Z,1700066074.996 [NAL9602](INFO): SBD MO Status=0, MOMSN=45815, MT Status=0, MTMSN=0 2023-11-15T16:34:34.996Z,1700066074.996 [NAL9602](INFO): No messages in MT queue 2023-11-15T16:34:43.457Z,1700066083.457 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20231115T161227/Express0013.lzma 2023-11-15T16:34:44.459Z,1700066084.459 [DataOverHttps](INFO): Moved sent file to Logs/20231115T161227/Express0013.lzma.bak 2023-11-15T16:34:44.459Z,1700066084.459 [DataOverHttps](INFO): SBD MOMSN=19067840 2023-11-15T16:34:45.552Z,1700066085.552 [Default:CheckIn:Read_Iridium] Stopped 2023-11-15T16:34:45.553Z,1700066085.553 [Default:CheckIn:C.Wait] Running Loop=1 2023-11-15T16:34:45.553Z,1700066085.553 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-11-15T16:35:05.742Z,1700066105.742 [NAL9602](INFO): Not Powering down - fast GPS 2023-11-15T16:39:46.233Z,1700066386.233 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-11-15T16:39:46.233Z,1700066386.233 [Default:CheckIn:C.Wait] Stopped 2023-11-15T16:39:46.233Z,1700066386.233 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-11-15T16:39:46.233Z,1700066386.233 [Default:CheckIn:D] Running Loop=1 2023-11-15T16:39:46.626Z,1700066386.626 [Default:CheckIn:D] Stopped 2023-11-15T16:39:46.626Z,1700066386.626 [Default:CheckIn:E] Running Loop=1 2023-11-15T16:39:47.040Z,1700066387.040 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 48.646578 min 2023-11-15T16:39:47.040Z,1700066387.040 [Default:CheckIn:E] Stopped 2023-11-15T16:39:47.040Z,1700066387.040 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-11-15T16:39:47.040Z,1700066387.040 [Default:CheckIn] Stopped 2023-11-15T16:39:47.040Z,1700066387.040 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-11-15T16:39:47.041Z,1700066387.041 [Default:CheckIn](INFO): Running loop #9 2023-11-15T16:39:47.041Z,1700066387.041 [Default:CheckIn] Running Loop=9 2023-11-15T16:39:47.041Z,1700066387.041 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-11-15T16:39:47.041Z,1700066387.041 [Default:CheckIn:Read_GPS] Running Loop=1 2023-11-15T16:39:49.044Z,1700066389.044 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163948.00,A,3648.16871,N,12147.27830,W,0.583,170.49,151123,,,A*72 2023-11-15T16:39:49.047Z,1700066389.047 [NAL9602](INFO): GPS fix at 20231115T163948: (36.802812, -121.787972) 2023-11-15T16:39:49.080Z,1700066389.080 [Default:CheckIn:Read_GPS] Stopped 2023-11-15T16:39:49.080Z,1700066389.080 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-11-15T16:39:56.937Z,1700066396.937 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20231115T161227/Courier0015.lzma 2023-11-15T16:39:57.939Z,1700066397.939 [DataOverHttps](INFO): Moved sent file to Logs/20231115T161227/Courier0015.lzma.bak 2023-11-15T16:39:57.939Z,1700066397.939 [DataOverHttps](INFO): SBD MOMSN=19067845 2023-11-15T16:40:13.745Z,1700066413.745 [DataOverHttps](INFO): Sending 144 bytes from file Logs/20231115T161227/Express0016.lzma 2023-11-15T16:40:14.747Z,1700066414.747 [DataOverHttps](INFO): Moved sent file to Logs/20231115T161227/Express0016.lzma.bak 2023-11-15T16:40:14.747Z,1700066414.747 [DataOverHttps](INFO): SBD MOMSN=19067848 2023-11-15T16:40:16.121Z,1700066416.121 [Default:CheckIn:Read_Iridium] Stopped 2023-11-15T16:40:16.122Z,1700066416.122 [Default:CheckIn:C.Wait] Running Loop=1 2023-11-15T16:40:16.122Z,1700066416.122 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-11-15T16:44:16.608Z,1700066656.608 [NAL9602](INFO): SBD MO Status=2, MOMSN=45816, MT Status=2, MTMSN=0 2023-11-15T16:44:16.609Z,1700066656.609 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-11-15T16:44:51.350Z,1700066691.350 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2023-11-15T16:45:16.852Z,1700066716.852 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-11-15T16:45:16.852Z,1700066716.852 [Default:CheckIn:C.Wait] Stopped 2023-11-15T16:45:16.852Z,1700066716.852 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-11-15T16:45:16.853Z,1700066716.853 [Default:CheckIn:D] Running Loop=1 2023-11-15T16:45:17.264Z,1700066717.264 [Default:CheckIn:D] Stopped 2023-11-15T16:45:17.264Z,1700066717.264 [Default:CheckIn:E] Running Loop=1 2023-11-15T16:45:17.662Z,1700066717.662 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 54.157222 min 2023-11-15T16:45:17.662Z,1700066717.662 [Default:CheckIn:E] Stopped 2023-11-15T16:45:17.663Z,1700066717.663 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-11-15T16:45:17.663Z,1700066717.663 [Default:CheckIn] Stopped 2023-11-15T16:45:17.663Z,1700066717.663 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-11-15T16:45:17.663Z,1700066717.663 [Default:CheckIn](INFO): Running loop #10 2023-11-15T16:45:17.663Z,1700066717.663 [Default:CheckIn] Running Loop=10 2023-11-15T16:45:17.663Z,1700066717.663 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-11-15T16:45:17.663Z,1700066717.663 [Default:CheckIn:Read_GPS] Running Loop=1 2023-11-15T16:45:19.672Z,1700066719.672 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164518.00,A,3648.16242,N,12147.28854,W,1.341,135.99,151123,,,A*7E 2023-11-15T16:45:19.683Z,1700066719.683 [NAL9602](INFO): GPS fix at 20231115T164518: (36.802707, -121.788142) 2023-11-15T16:45:19.695Z,1700066719.695 [Default:CheckIn:Read_GPS] Stopped 2023-11-15T16:45:19.695Z,1700066719.695 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-11-15T16:45:27.161Z,1700066727.161 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20231115T161227/Courier0018.lzma 2023-11-15T16:45:28.163Z,1700066728.163 [DataOverHttps](INFO): Moved sent file to Logs/20231115T161227/Courier0018.lzma.bak 2023-11-15T16:45:28.163Z,1700066728.163 [DataOverHttps](INFO): SBD MOMSN=19067857 2023-11-15T16:45:44.361Z,1700066744.361 [DataOverHttps](INFO): Sending 231 bytes from file Logs/20231115T161227/Express0019.lzma 2023-11-15T16:45:45.363Z,1700066745.363 [DataOverHttps](INFO): Moved sent file to Logs/20231115T161227/Express0019.lzma.bak 2023-11-15T16:45:45.363Z,1700066745.363 [DataOverHttps](INFO): SBD MOMSN=19067860 2023-11-15T16:45:46.758Z,1700066746.758 [Default:CheckIn:Read_Iridium] Stopped 2023-11-15T16:45:46.758Z,1700066746.758 [Default:CheckIn:C.Wait] Running Loop=1 2023-11-15T16:45:46.758Z,1700066746.758 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-11-15T16:45:52.394Z,1700066752.394 [NAL9602](INFO): Not Powering down - fast GPS 2023-11-15T16:48:59.583Z,1700066939.583 [DataOverHttps](IMPORTANT): SBD MTMSN=20231115T164858 2023-11-15T16:49:06.897Z,1700066946.897 [DataOverHttps](INFO): Received command: strobe off 2023-11-15T16:49:06.903Z,1700066946.903 [CommandExec](IMPORTANT): got command strobe off 2023-11-15T16:49:06.903Z,1700066946.903 [CommandExec](IMPORTANT): Deactivating strobe 2023-11-15T16:50:47.455Z,1700067047.455 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-11-15T16:50:47.455Z,1700067047.455 [Default:CheckIn:C.Wait] Stopped 2023-11-15T16:50:47.455Z,1700067047.455 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-11-15T16:50:47.456Z,1700067047.456 [Default:CheckIn:D] Running Loop=1 2023-11-15T16:50:47.834Z,1700067047.834 [Default:CheckIn:D] Stopped 2023-11-15T16:50:47.834Z,1700067047.834 [Default:CheckIn:E] Running Loop=1 2023-11-15T16:50:48.255Z,1700067048.255 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 59.666703 min 2023-11-15T16:50:48.255Z,1700067048.255 [Default:CheckIn:E] Stopped 2023-11-15T16:50:48.255Z,1700067048.255 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-11-15T16:50:48.255Z,1700067048.255 [Default:CheckIn] Stopped 2023-11-15T16:50:48.255Z,1700067048.255 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-11-15T16:50:48.256Z,1700067048.256 [Default:CheckIn](INFO): Running loop #11 2023-11-15T16:50:48.256Z,1700067048.256 [Default:CheckIn] Running Loop=11 2023-11-15T16:50:48.256Z,1700067048.256 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-11-15T16:50:48.256Z,1700067048.256 [Default:CheckIn:Read_GPS] Running Loop=1 2023-11-15T16:51:20.955Z,1700067080.955 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2023-11-15T16:51:21.029Z,1700067081.029 [NAL9602](ERROR): received: +CSQ:0 OK816, 2, 0, 0, 0 OK 2023-11-15T16:55:48.501Z,1700067348.501 [Default:CheckIn:Read_GPS](INFO): Timed out from 2023-11-15T16:50:48.3Z 2023-11-15T16:55:48.501Z,1700067348.501 [Default:CheckIn:Read_GPS] Stopped 2023-11-15T16:55:48.502Z,1700067348.502 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-11-15T16:55:52.487Z,1700067352.487 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2023-11-15T16:55:56.277Z,1700067356.277 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20231115T161227/Courier0021.lzma 2023-11-15T16:55:57.279Z,1700067357.279 [DataOverHttps](INFO): Moved sent file to Logs/20231115T161227/Courier0021.lzma.bak 2023-11-15T16:55:57.279Z,1700067357.279 [DataOverHttps](INFO): SBD MOMSN=19067868 2023-11-15T16:56:14.038Z,1700067374.038 [DataOverHttps](INFO): Sending 236 bytes from file Logs/20231115T161227/Express0022.lzma 2023-11-15T16:56:18.051Z,1700067378.051 [DataOverHttps](INFO): Moved sent file to Logs/20231115T161227/Express0022.lzma.bak 2023-11-15T16:56:18.052Z,1700067378.052 [DataOverHttps](INFO): SBD MOMSN=19067870 2023-11-15T16:56:23.194Z,1700067383.194 [NAL9602](INFO): Not Powering down - fast GPS 2023-11-15T16:56:34.173Z,1700067394.173 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20231115T161227/Express0025.lzma 2023-11-15T16:56:35.175Z,1700067395.175 [DataOverHttps](INFO): Moved sent file to Logs/20231115T161227/Express0025.lzma.bak 2023-11-15T16:56:35.175Z,1700067395.175 [DataOverHttps](INFO): SBD MOMSN=19067876 2023-11-15T16:56:36.544Z,1700067396.544 [Default:CheckIn:Read_Iridium] Stopped 2023-11-15T16:56:36.544Z,1700067396.544 [Default:CheckIn:C.Wait] Running Loop=1 2023-11-15T16:56:36.544Z,1700067396.544 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-11-15T17:01:37.112Z,1700067697.112 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-11-15T17:01:37.112Z,1700067697.112 [Default:CheckIn:C.Wait] Stopped 2023-11-15T17:01:37.112Z,1700067697.112 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-11-15T17:01:37.113Z,1700067697.113 [Default:CheckIn:D] Running Loop=1 2023-11-15T17:01:37.512Z,1700067697.512 [Default:CheckIn:D] Stopped 2023-11-15T17:01:37.512Z,1700067697.512 [Default:CheckIn:E] Running Loop=1 2023-11-15T17:01:37.926Z,1700067697.926 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 70.494678 min 2023-11-15T17:01:37.926Z,1700067697.926 [Default:CheckIn:E] Stopped 2023-11-15T17:01:37.926Z,1700067697.926 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-11-15T17:01:37.927Z,1700067697.927 [Default:CheckIn] Stopped 2023-11-15T17:01:37.927Z,1700067697.927 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-11-15T17:01:37.927Z,1700067697.927 [Default:CheckIn](INFO): Running loop #12 2023-11-15T17:01:37.927Z,1700067697.927 [Default:CheckIn] Running Loop=12 2023-11-15T17:01:37.927Z,1700067697.927 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-11-15T17:01:37.927Z,1700067697.927 [Default:CheckIn:Read_GPS] Running Loop=1 2023-11-15T17:01:39.527Z,1700067699.527 [NAL9602](FAULT): GPS failed to acquire within timeout. 2023-11-15T17:01:39.527Z,1700067699.527 [NAL9602] Data Fault, FailCount= 1 2023-11-15T17:01:39.527Z,1700067699.527 [NAL9602](ERROR): Data Fault 2023-11-15T17:01:39.589Z,1700067699.589 [CBIT](ERROR): Data Fault in component: NAL9602 2023-11-15T17:01:39.931Z,1700067699.931 [NAL9602](INFO): Powering down 2023-11-15T17:01:40.771Z,1700067700.771 [CBIT](INFO): Clearing failed state for component NAL9602 2023-11-15T17:01:40.771Z,1700067700.771 [NAL9602] No Fault, FailCount= 1 2023-11-15T17:02:10.225Z,1700067730.225 [NAL9602](INFO): Powering up NAL9602 2023-11-15T17:02:21.143Z,1700067741.143 [NAL9602](INFO): NAL9602 initialized 2023-11-15T17:06:38.153Z,1700067998.153 [Default:CheckIn:Read_GPS](INFO): Timed out from 2023-11-15T17:01:37.9Z 2023-11-15T17:06:38.153Z,1700067998.153 [Default:CheckIn:Read_GPS] Stopped 2023-11-15T17:06:38.153Z,1700067998.153 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-11-15T17:06:45.029Z,1700068005.029 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20231115T161227/Courier0027.lzma 2023-11-15T17:06:46.031Z,1700068006.031 [DataOverHttps](INFO): Moved sent file to Logs/20231115T161227/Courier0027.lzma.bak 2023-11-15T17:06:46.031Z,1700068006.031 [DataOverHttps](INFO): SBD MOMSN=19067883 2023-11-15T17:07:05.506Z,1700068025.506 [DataOverHttps](INFO): Sending 225 bytes from file Logs/20231115T161227/Express0028.lzma 2023-11-15T17:07:06.520Z,1700068026.520 [DataOverHttps](INFO): Moved sent file to Logs/20231115T161227/Express0028.lzma.bak 2023-11-15T17:07:06.520Z,1700068026.520 [DataOverHttps](INFO): SBD MOMSN=19067885 2023-11-15T17:07:07.727Z,1700068027.727 [Default:CheckIn:Read_Iridium] Stopped 2023-11-15T17:07:07.727Z,1700068027.727 [Default:CheckIn:C.Wait] Running Loop=1 2023-11-15T17:07:07.727Z,1700068027.727 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-11-15T17:07:24.651Z,1700068044.651 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2023-11-15T17:07:55.358Z,1700068075.358 [NAL9602](INFO): Not Powering down - fast GPS 2023-11-15T17:12:08.293Z,1700068328.293 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-11-15T17:12:08.293Z,1700068328.293 [Default:CheckIn:C.Wait] Stopped 2023-11-15T17:12:08.294Z,1700068328.294 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-11-15T17:12:08.294Z,1700068328.294 [Default:CheckIn:D] Running Loop=1 2023-11-15T17:12:08.702Z,1700068328.702 [Default:CheckIn:D] Stopped 2023-11-15T17:12:08.702Z,1700068328.702 [Default:CheckIn:E] Running Loop=1 2023-11-15T17:12:09.097Z,1700068329.097 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 81.014510 min 2023-11-15T17:12:09.097Z,1700068329.097 [Default:CheckIn:E] Stopped 2023-11-15T17:12:09.097Z,1700068329.097 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-11-15T17:12:09.098Z,1700068329.098 [Default:CheckIn] Stopped 2023-11-15T17:12:09.098Z,1700068329.098 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-11-15T17:12:09.098Z,1700068329.098 [Default:CheckIn](INFO): Running loop #13 2023-11-15T17:12:09.098Z,1700068329.098 [Default:CheckIn] Running Loop=13 2023-11-15T17:12:09.098Z,1700068329.098 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-11-15T17:12:09.098Z,1700068329.098 [Default:CheckIn:Read_GPS] Running Loop=1 2023-11-15T17:12:13.530Z,1700068333.530 [BPC1](ERROR): BPC1A: No match for serial number 1717 in BPC1A's battery stick inventory (sticks 1-31 in onboard configuration file). 2023-11-15T17:13:07.286Z,1700068387.286 [BPC1](ERROR): BPC1A: No match for serial number 1717 in BPC1A's battery stick inventory (sticks 1-31 in onboard configuration file). 2023-11-15T17:14:26.879Z,1700068466.879 [BPC1](INFO): Calculating totals. Valid battery stick count: 42. Valid reserve battery stick count: 5. 2023-11-15T17:14:26.881Z,1700068466.881 [BPC1](INFO): Received data from all battery sticks. 2023-11-15T17:17:09.437Z,1700068629.437 [Default:CheckIn:Read_GPS](INFO): Timed out from 2023-11-15T17:12:09.1Z 2023-11-15T17:17:09.437Z,1700068629.437 [Default:CheckIn:Read_GPS] Stopped 2023-11-15T17:17:09.438Z,1700068629.438 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-11-15T17:17:13.451Z,1700068633.451 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2023-11-15T17:17:16.389Z,1700068636.389 [DataOverHttps](INFO): Sending 168 bytes from file Logs/20231115T161227/Courier0030.lzma 2023-11-15T17:17:17.391Z,1700068637.391 [DataOverHttps](INFO): Moved sent file to Logs/20231115T161227/Courier0030.lzma.bak 2023-11-15T17:17:17.391Z,1700068637.391 [DataOverHttps](INFO): SBD MOMSN=19067921 2023-11-15T17:17:33.233Z,1700068653.233 [DataOverHttps](INFO): Sending 207 bytes from file Logs/20231115T161227/Express0031.lzma 2023-11-15T17:17:34.235Z,1700068654.235 [DataOverHttps](INFO): Moved sent file to Logs/20231115T161227/Express0031.lzma.bak 2023-11-15T17:17:34.235Z,1700068654.235 [DataOverHttps](INFO): SBD MOMSN=19067923 2023-11-15T17:17:35.688Z,1700068655.688 [Default:CheckIn:Read_Iridium] Stopped 2023-11-15T17:17:35.688Z,1700068655.688 [Default:CheckIn:C.Wait] Running Loop=1 2023-11-15T17:17:35.689Z,1700068655.689 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-11-15T17:17:44.162Z,1700068664.162 [NAL9602](INFO): Not Powering down - fast GPS 2023-11-15T17:22:36.305Z,1700068956.305 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-11-15T17:22:36.305Z,1700068956.305 [Default:CheckIn:C.Wait] Stopped 2023-11-15T17:22:36.305Z,1700068956.305 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-11-15T17:22:36.305Z,1700068956.305 [Default:CheckIn:D] Running Loop=1 2023-11-15T17:22:36.719Z,1700068956.719 [Default:CheckIn:D] Stopped 2023-11-15T17:22:36.719Z,1700068956.719 [Default:CheckIn:E] Running Loop=1 2023-11-15T17:22:37.109Z,1700068957.109 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 91.481470 min 2023-11-15T17:22:37.109Z,1700068957.109 [Default:CheckIn:E] Stopped 2023-11-15T17:22:37.110Z,1700068957.110 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-11-15T17:22:37.110Z,1700068957.110 [Default:CheckIn] Stopped 2023-11-15T17:22:37.110Z,1700068957.110 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-11-15T17:22:37.110Z,1700068957.110 [Default:CheckIn](INFO): Running loop #14 2023-11-15T17:22:37.110Z,1700068957.110 [Default:CheckIn] Running Loop=14 2023-11-15T17:22:37.110Z,1700068957.110 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-11-15T17:22:37.110Z,1700068957.110 [Default:CheckIn:Read_GPS] Running Loop=1 2023-11-15T17:22:38.715Z,1700068958.715 [NAL9602](FAULT): GPS failed to acquire within timeout. 2023-11-15T17:22:38.715Z,1700068958.715 [NAL9602] Data Fault, FailCount= 2 2023-11-15T17:22:38.715Z,1700068958.715 [NAL9602](ERROR): Data Fault 2023-11-15T17:22:38.759Z,1700068958.759 [CBIT](ERROR): Data Fault in component: NAL9602 2023-11-15T17:22:39.119Z,1700068959.119 [NAL9602](INFO): Powering down 2023-11-15T17:22:39.955Z,1700068959.955 [CBIT](INFO): Clearing failed state for component NAL9602 2023-11-15T17:22:39.955Z,1700068959.955 [NAL9602] No Fault, FailCount= 2 2023-11-15T17:23:09.427Z,1700068989.427 [NAL9602](INFO): Powering up NAL9602 2023-11-15T17:23:20.331Z,1700069000.331 [NAL9602](INFO): NAL9602 initialized 2023-11-15T17:27:37.336Z,1700069257.336 [Default:CheckIn:Read_GPS](INFO): Timed out from 2023-11-15T17:22:37.1Z 2023-11-15T17:27:37.337Z,1700069257.337 [Default:CheckIn:Read_GPS] Stopped 2023-11-15T17:27:37.337Z,1700069257.337 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-11-15T17:27:44.533Z,1700069264.533 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20231115T161227/Courier0033.lzma 2023-11-15T17:27:45.535Z,1700069265.535 [DataOverHttps](INFO): Moved sent file to Logs/20231115T161227/Courier0033.lzma.bak 2023-11-15T17:27:45.535Z,1700069265.535 [DataOverHttps](INFO): SBD MOMSN=19067935 2023-11-15T17:28:01.289Z,1700069281.289 [DataOverHttps](INFO): Sending 224 bytes from file Logs/20231115T161227/Express0034.lzma 2023-11-15T17:28:02.291Z,1700069282.291 [DataOverHttps](INFO): Moved sent file to Logs/20231115T161227/Express0034.lzma.bak 2023-11-15T17:28:02.291Z,1700069282.291 [DataOverHttps](INFO): SBD MOMSN=19067937 2023-11-15T17:28:03.597Z,1700069283.597 [Default:CheckIn:Read_Iridium] Stopped 2023-11-15T17:28:03.597Z,1700069283.597 [Default:CheckIn:C.Wait] Running Loop=1 2023-11-15T17:28:03.597Z,1700069283.597 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-11-15T17:28:23.779Z,1700069303.779 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2023-11-15T17:28:54.478Z,1700069334.478 [NAL9602](INFO): Not Powering down - fast GPS 2023-11-15T17:33:04.174Z,1700069584.174 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-11-15T17:33:04.174Z,1700069584.174 [Default:CheckIn:C.Wait] Stopped 2023-11-15T17:33:04.174Z,1700069584.174 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-11-15T17:33:04.174Z,1700069584.174 [Default:CheckIn:D] Running Loop=1 2023-11-15T17:33:04.574Z,1700069584.574 [Default:CheckIn:D] Stopped 2023-11-15T17:33:04.574Z,1700069584.574 [Default:CheckIn:E] Running Loop=1 2023-11-15T17:33:04.991Z,1700069584.991 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 101.945719 min 2023-11-15T17:33:04.991Z,1700069584.991 [Default:CheckIn:E] Stopped 2023-11-15T17:33:04.992Z,1700069584.992 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-11-15T17:33:04.992Z,1700069584.992 [Default:CheckIn] Stopped 2023-11-15T17:33:04.992Z,1700069584.992 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-11-15T17:33:04.992Z,1700069584.992 [Default:CheckIn](INFO): Running loop #15 2023-11-15T17:33:04.992Z,1700069584.992 [Default:CheckIn] Running Loop=15 2023-11-15T17:33:04.992Z,1700069584.992 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-11-15T17:33:04.992Z,1700069584.992 [Default:CheckIn:Read_GPS] Running Loop=1 2023-11-15T17:38:05.167Z,1700069885.167 [Default:CheckIn:Read_GPS](INFO): Timed out from 2023-11-15T17:33:04.0Z 2023-11-15T17:38:05.167Z,1700069885.167 [Default:CheckIn:Read_GPS] Stopped 2023-11-15T17:38:05.167Z,1700069885.167 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-11-15T17:38:09.183Z,1700069889.183 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2023-11-15T17:38:12.478Z,1700069892.478 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20231115T161227/Courier0036.lzma 2023-11-15T17:38:13.479Z,1700069893.479 [DataOverHttps](INFO): Moved sent file to Logs/20231115T161227/Courier0036.lzma.bak 2023-11-15T17:38:13.479Z,1700069893.479 [DataOverHttps](INFO): SBD MOMSN=19067942 2023-11-15T17:38:29.524Z,1700069909.524 [DataOverHttps](INFO): Sending 208 bytes from file Logs/20231115T161227/Express0037.lzma 2023-11-15T17:38:30.323Z,1700069910.323 [DataOverHttps](INFO): Moved sent file to Logs/20231115T161227/Express0037.lzma.bak 2023-11-15T17:38:30.323Z,1700069910.323 [DataOverHttps](INFO): SBD MOMSN=19067944 2023-11-15T17:38:31.418Z,1700069911.418 [Default:CheckIn:Read_Iridium] Stopped 2023-11-15T17:38:31.418Z,1700069911.418 [Default:CheckIn:C.Wait] Running Loop=1 2023-11-15T17:38:31.418Z,1700069911.418 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-11-15T17:38:39.890Z,1700069919.890 [NAL9602](INFO): Not Powering down - fast GPS 2023-11-15T17:43:32.008Z,1700070212.008 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-11-15T17:43:32.008Z,1700070212.008 [Default:CheckIn:C.Wait] Stopped 2023-11-15T17:43:32.008Z,1700070212.008 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-11-15T17:43:32.009Z,1700070212.009 [Default:CheckIn:D] Running Loop=1 2023-11-15T17:43:32.401Z,1700070212.401 [Default:CheckIn:D] Stopped 2023-11-15T17:43:32.401Z,1700070212.401 [Default:CheckIn:E] Running Loop=1 2023-11-15T17:43:32.804Z,1700070212.804 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 112.409489 min 2023-11-15T17:43:32.805Z,1700070212.805 [Default:CheckIn:E] Stopped 2023-11-15T17:43:32.805Z,1700070212.805 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-11-15T17:43:32.805Z,1700070212.805 [Default:CheckIn] Stopped 2023-11-15T17:43:32.805Z,1700070212.805 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-11-15T17:43:32.805Z,1700070212.805 [Default:CheckIn](INFO): Running loop #16 2023-11-15T17:43:32.805Z,1700070212.805 [Default:CheckIn] Running Loop=16 2023-11-15T17:43:32.805Z,1700070212.805 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-11-15T17:43:32.806Z,1700070212.806 [Default:CheckIn:Read_GPS] Running Loop=1 2023-11-15T17:43:34.415Z,1700070214.415 [NAL9602](FAULT): GPS failed to acquire within timeout. 2023-11-15T17:43:34.415Z,1700070214.415 [NAL9602] Data Fault, FailCount= 3 2023-11-15T17:43:34.415Z,1700070214.415 [NAL9602](ERROR): Data Fault 2023-11-15T17:43:34.435Z,1700070214.435 [CBIT](ERROR): Data Fault in component: NAL9602 2023-11-15T17:43:34.816Z,1700070214.816 [NAL9602](INFO): Powering down 2023-11-15T17:43:35.670Z,1700070215.670 [CBIT](INFO): Clearing failed state for component NAL9602 2023-11-15T17:43:35.670Z,1700070215.670 [NAL9602] No Fault, FailCount= 3 2023-11-15T17:44:05.114Z,1700070245.114 [NAL9602](INFO): Powering up NAL9602 2023-11-15T17:44:16.027Z,1700070256.027 [NAL9602](INFO): NAL9602 initialized 2023-11-15T17:48:32.000Z,1700070513.000 [Default:CheckIn:Read_GPS](INFO): Timed out from 2023-11-15T17:43:32.8Z 2023-11-15T17:48:32.000Z,1700070513.000 [Default:CheckIn:Read_GPS] Stopped 2023-11-15T17:48:33.000Z,1700070513.000 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-11-15T17:48:40.637Z,1700070520.637 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20231115T161227/Courier0039.lzma 2023-11-15T17:48:41.639Z,1700070521.639 [DataOverHttps](INFO): Moved sent file to Logs/20231115T161227/Courier0039.lzma.bak 2023-11-15T17:48:41.639Z,1700070521.639 [DataOverHttps](INFO): SBD MOMSN=19067964 2023-11-15T17:48:57.533Z,1700070537.533 [DataOverHttps](INFO): Sending 227 bytes from file Logs/20231115T161227/Express0040.lzma 2023-11-15T17:48:58.535Z,1700070538.535 [DataOverHttps](INFO): Moved sent file to Logs/20231115T161227/Express0040.lzma.bak 2023-11-15T17:48:58.535Z,1700070538.535 [DataOverHttps](INFO): SBD MOMSN=19067966 2023-11-15T17:49:00.055Z,1700070540.055 [Default:CheckIn:Read_Iridium] Stopped 2023-11-15T17:49:00.055Z,1700070540.055 [Default:CheckIn:C.Wait] Running Loop=1 2023-11-15T17:49:00.055Z,1700070540.055 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-11-15T17:49:19.435Z,1700070559.435 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2023-11-15T17:49:50.138Z,1700070590.138 [NAL9602](INFO): Not Powering down - fast GPS 2023-11-15T17:54:00.689Z,1700070840.689 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-11-15T17:54:00.689Z,1700070840.689 [Default:CheckIn:C.Wait] Stopped 2023-11-15T17:54:00.689Z,1700070840.689 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-11-15T17:54:00.689Z,1700070840.689 [Default:CheckIn:D] Running Loop=1 2023-11-15T17:54:01.101Z,1700070841.101 [Default:CheckIn:D] Stopped 2023-11-15T17:54:01.101Z,1700070841.101 [Default:CheckIn:E] Running Loop=1 2023-11-15T17:54:01.492Z,1700070841.492 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 122.887834 min 2023-11-15T17:54:01.493Z,1700070841.493 [Default:CheckIn:E] Stopped 2023-11-15T17:54:01.493Z,1700070841.493 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-11-15T17:54:01.493Z,1700070841.493 [Default:CheckIn] Stopped 2023-11-15T17:54:01.493Z,1700070841.493 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-11-15T17:54:01.493Z,1700070841.493 [Default:CheckIn](INFO): Running loop #17 2023-11-15T17:54:01.493Z,1700070841.493 [Default:CheckIn] Running Loop=17 2023-11-15T17:54:01.493Z,1700070841.493 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-11-15T17:54:01.494Z,1700070841.494 [Default:CheckIn:Read_GPS] Running Loop=1 2023-11-15T17:58:34.318Z,1700071114.318 [CBIT](IMPORTANT): Beginning ground fault scan 2023-11-15T17:58:37.144Z,1700071117.144 [CBIT](ERROR): Error reading 24V bus power status. Assuming off for scan purposes. 2023-11-15T17:58:45.331Z,1700071125.331 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.002260 CHAN A1 (24V) N/A reporting off CHAN A2 (12V): -0.002356 CHAN A3 (5V): -0.001360 CHAN B0 (3.3V): 0.000022 CHAN B1 (3.15aV): -0.000672 CHAN B2 (3.15bV): -0.000048 CHAN B3 (GND): -0.000080 OPEN: -0.000676 Full Scale: +/- 1 mA 2023-11-15T17:59:01.813Z,1700071141.813 [Default:CheckIn:Read_GPS](INFO): Timed out from 2023-11-15T17:54:01.5Z 2023-11-15T17:59:01.813Z,1700071141.813 [Default:CheckIn:Read_GPS] Stopped 2023-11-15T17:59:01.814Z,1700071141.814 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-11-15T17:59:05.031Z,1700071145.031 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2023-11-15T17:59:09.575Z,1700071149.575 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20231115T161227/Courier0042.lzma 2023-11-15T17:59:10.451Z,1700071150.451 [DataOverHttps](INFO): Moved sent file to Logs/20231115T161227/Courier0042.lzma.bak 2023-11-15T17:59:10.451Z,1700071150.451 [DataOverHttps](INFO): SBD MOMSN=19068004 2023-11-15T17:59:26.442Z,1700071166.442 [DataOverHttps](INFO): Sending 408 bytes from file Logs/20231115T161227/Express0043.lzma 2023-11-15T17:59:27.443Z,1700071167.443 [DataOverHttps](INFO): Moved sent file to Logs/20231115T161227/Express0043.lzma.bak 2023-11-15T17:59:27.443Z,1700071167.443 [DataOverHttps](INFO): SBD MOMSN=19068008 2023-11-15T17:59:28.542Z,1700071168.542 [Default:CheckIn:Read_Iridium] Stopped 2023-11-15T17:59:28.542Z,1700071168.542 [Default:CheckIn:C.Wait] Running Loop=1 2023-11-15T17:59:28.542Z,1700071168.542 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-11-15T17:59:35.768Z,1700071175.768 [NAL9602](INFO): Not Powering down - fast GPS 2023-11-15T18:04:29.194Z,1700071469.194 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-11-15T18:04:29.194Z,1700071469.194 [Default:CheckIn:C.Wait] Stopped 2023-11-15T18:04:29.194Z,1700071469.194 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-11-15T18:04:29.195Z,1700071469.195 [Default:CheckIn:D] Running Loop=1 2023-11-15T18:04:29.610Z,1700071469.610 [Default:CheckIn:D] Stopped 2023-11-15T18:04:29.610Z,1700071469.610 [Default:CheckIn:E] Running Loop=1 2023-11-15T18:04:30.000Z,1700071470.000 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 133.362988 min 2023-11-15T18:04:30.000Z,1700071470.000 [Default:CheckIn:E] Stopped 2023-11-15T18:04:30.000Z,1700071470.000 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-11-15T18:04:30.001Z,1700071470.001 [Default:CheckIn] Stopped 2023-11-15T18:04:30.001Z,1700071470.001 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-11-15T18:04:30.001Z,1700071470.001 [Default:CheckIn](INFO): Running loop #18 2023-11-15T18:04:30.001Z,1700071470.001 [Default:CheckIn] Running Loop=18 2023-11-15T18:04:30.001Z,1700071470.001 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-11-15T18:04:30.001Z,1700071470.001 [Default:CheckIn:Read_GPS] Running Loop=1 2023-11-15T18:04:31.607Z,1700071471.607 [NAL9602](FAULT): GPS failed to acquire within timeout. 2023-11-15T18:04:31.607Z,1700071471.607 [NAL9602] Data Fault, FailCount= 4 2023-11-15T18:04:31.607Z,1700071471.607 [NAL9602](ERROR): Data Fault 2023-11-15T18:04:31.653Z,1700071471.653 [CBIT](ERROR): Data Fault in component: NAL9602 2023-11-15T18:04:32.015Z,1700071472.015 [NAL9602](INFO): Powering down 2023-11-15T18:04:32.847Z,1700071472.847 [CBIT](INFO): Clearing failed state for component NAL9602 2023-11-15T18:04:32.847Z,1700071472.847 [NAL9602] No Fault, FailCount= 4 2023-11-15T18:05:02.310Z,1700071502.310 [NAL9602](INFO): Powering up NAL9602 2023-11-15T18:05:13.218Z,1700071513.218 [NAL9602](INFO): NAL9602 initialized 2023-11-15T18:09:30.178Z,1700071770.178 [Default:CheckIn:Read_GPS](INFO): Timed out from 2023-11-15T18:04:30.0Z 2023-11-15T18:09:30.178Z,1700071770.178 [Default:CheckIn:Read_GPS] Stopped 2023-11-15T18:09:30.179Z,1700071770.179 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-11-15T18:09:37.909Z,1700071777.909 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20231115T161227/Courier0045.lzma 2023-11-15T18:09:38.911Z,1700071778.911 [DataOverHttps](INFO): Moved sent file to Logs/20231115T161227/Courier0045.lzma.bak 2023-11-15T18:09:38.911Z,1700071778.911 [DataOverHttps](INFO): SBD MOMSN=19068105 2023-11-15T18:09:54.749Z,1700071794.749 [DataOverHttps](INFO): Sending 226 bytes from file Logs/20231115T161227/Express0046.lzma 2023-11-15T18:09:55.751Z,1700071795.751 [DataOverHttps](INFO): Moved sent file to Logs/20231115T161227/Express0046.lzma.bak 2023-11-15T18:09:55.752Z,1700071795.752 [DataOverHttps](INFO): SBD MOMSN=19068107 2023-11-15T18:09:56.840Z,1700071796.840 [Default:CheckIn:Read_Iridium] Stopped 2023-11-15T18:09:56.840Z,1700071796.840 [Default:CheckIn:C.Wait] Running Loop=1 2023-11-15T18:09:56.840Z,1700071796.840 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-11-15T18:10:16.223Z,1700071816.223 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2023-11-15T18:10:46.930Z,1700071846.930 [NAL9602](INFO): Not Powering down - fast GPS 2023-11-15T18:14:57.412Z,1700072097.412 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-11-15T18:14:57.412Z,1700072097.412 [Default:CheckIn:C.Wait] Stopped 2023-11-15T18:14:57.412Z,1700072097.412 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-11-15T18:14:57.413Z,1700072097.413 [Default:CheckIn:D] Running Loop=1 2023-11-15T18:14:57.823Z,1700072097.823 [Default:CheckIn:D] Stopped 2023-11-15T18:14:57.823Z,1700072097.823 [Default:CheckIn:E] Running Loop=1 2023-11-15T18:14:58.243Z,1700072098.243 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 143.833187 min 2023-11-15T18:14:58.243Z,1700072098.243 [Default:CheckIn:E] Stopped 2023-11-15T18:14:58.244Z,1700072098.244 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-11-15T18:14:58.244Z,1700072098.244 [Default:CheckIn] Stopped 2023-11-15T18:14:58.244Z,1700072098.244 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-11-15T18:14:58.244Z,1700072098.244 [Default:CheckIn](INFO): Running loop #19 2023-11-15T18:14:58.244Z,1700072098.244 [Default:CheckIn] Running Loop=19 2023-11-15T18:14:58.244Z,1700072098.244 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-11-15T18:14:58.244Z,1700072098.244 [Default:CheckIn:Read_GPS] Running Loop=1 2023-11-15T18:15:00.233Z,1700072100.233 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181459.00,A,3648.16267,N,12147.28699,W,0.758,0.00,151123,,,A*73 2023-11-15T18:15:00.240Z,1700072100.240 [NAL9602](INFO): GPS fix at 20231115T181459: (36.802711, -121.788117) 2023-11-15T18:15:00.271Z,1700072100.271 [Default:CheckIn:Read_GPS] Stopped 2023-11-15T18:15:00.271Z,1700072100.271 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-11-15T18:15:07.261Z,1700072107.261 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20231115T161227/Courier0048.lzma 2023-11-15T18:15:08.263Z,1700072108.263 [DataOverHttps](INFO): Moved sent file to Logs/20231115T161227/Courier0048.lzma.bak 2023-11-15T18:15:08.264Z,1700072108.264 [DataOverHttps](INFO): SBD MOMSN=19068112 2023-11-15T18:15:24.201Z,1700072124.201 [DataOverHttps](INFO): Sending 207 bytes from file Logs/20231115T161227/Express0049.lzma 2023-11-15T18:15:25.203Z,1700072125.203 [DataOverHttps](INFO): Moved sent file to Logs/20231115T161227/Express0049.lzma.bak 2023-11-15T18:15:25.204Z,1700072125.204 [DataOverHttps](INFO): SBD MOMSN=19068115 2023-11-15T18:15:26.515Z,1700072126.515 [Default:CheckIn:Read_Iridium] Stopped 2023-11-15T18:15:26.515Z,1700072126.515 [Default:CheckIn:C.Wait] Running Loop=1 2023-11-15T18:15:26.515Z,1700072126.515 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-11-15T18:15:30.943Z,1700072130.943 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2023-11-15T18:15:31.026Z,1700072131.026 [NAL9602](ERROR): received: +CSQ:0 OK816, 2, 0, 0, 0 OK 2023-11-15T18:16:15.783Z,1700072175.783 [BPC1](ERROR): BPC1A: No match for serial number 1717 in BPC1A's battery stick inventory (sticks 1-31 in onboard configuration file). 2023-11-15T18:17:31.740Z,1700072251.740 [NAL9602](INFO): SBD MO Status=2, MOMSN=45816, MT Status=2, MTMSN=0 2023-11-15T18:17:31.740Z,1700072251.740 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-11-15T18:18:51.336Z,1700072331.336 [NAL9602](INFO): SBD MO Status=0, MOMSN=45816, MT Status=0, MTMSN=0 2023-11-15T18:18:51.336Z,1700072331.336 [NAL9602](INFO): No messages in MT queue 2023-11-15T18:19:22.044Z,1700072362.044 [NAL9602](INFO): Not Powering down - fast GPS 2023-11-15T18:20:27.101Z,1700072427.101 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-11-15T18:20:27.102Z,1700072427.102 [Default:CheckIn:C.Wait] Stopped 2023-11-15T18:20:27.102Z,1700072427.102 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-11-15T18:20:27.102Z,1700072427.102 [Default:CheckIn:D] Running Loop=1 2023-11-15T18:20:27.509Z,1700072427.509 [Default:CheckIn:D] Stopped 2023-11-15T18:20:27.509Z,1700072427.509 [Default:CheckIn:E] Running Loop=1 2023-11-15T18:20:27.920Z,1700072427.920 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 149.327962 min 2023-11-15T18:20:27.920Z,1700072427.920 [Default:CheckIn:E] Stopped 2023-11-15T18:20:27.920Z,1700072427.920 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-11-15T18:20:27.920Z,1700072427.920 [Default:CheckIn] Stopped 2023-11-15T18:20:27.920Z,1700072427.920 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-11-15T18:20:27.920Z,1700072427.920 [Default:CheckIn](INFO): Running loop #20 2023-11-15T18:20:27.920Z,1700072427.920 [Default:CheckIn] Running Loop=20 2023-11-15T18:20:27.920Z,1700072427.920 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-11-15T18:20:27.920Z,1700072427.920 [Default:CheckIn:Read_GPS] Running Loop=1 2023-11-15T18:20:29.926Z,1700072429.926 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182029.00,A,3648.16535,N,12147.27992,W,0.117,0.00,151123,,,A*75 2023-11-15T18:20:29.928Z,1700072429.928 [NAL9602](INFO): GPS fix at 20231115T182029: (36.802756, -121.787999) 2023-11-15T18:20:30.039Z,1700072430.039 [Default:CheckIn:Read_GPS] Stopped 2023-11-15T18:20:30.039Z,1700072430.039 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-11-15T18:20:37.001Z,1700072437.001 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20231115T161227/Courier0051.lzma 2023-11-15T18:20:38.003Z,1700072438.003 [DataOverHttps](INFO): Moved sent file to Logs/20231115T161227/Courier0051.lzma.bak 2023-11-15T18:20:38.004Z,1700072438.004 [DataOverHttps](INFO): SBD MOMSN=19068119 2023-11-15T18:20:57.121Z,1700072457.121 [DataOverHttps](INFO): Sending 133 bytes from file Logs/20231115T161227/Express0052.lzma 2023-11-15T18:20:58.123Z,1700072458.123 [DataOverHttps](INFO): Moved sent file to Logs/20231115T161227/Express0052.lzma.bak 2023-11-15T18:20:58.124Z,1700072458.124 [DataOverHttps](INFO): SBD MOMSN=19068122 2023-11-15T18:20:59.641Z,1700072459.641 [NAL9602](INFO): SBD MO Status=2, MOMSN=45817, MT Status=2, MTMSN=0 2023-11-15T18:20:59.642Z,1700072459.642 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-11-15T18:20:59.656Z,1700072459.656 [Default:CheckIn:Read_Iridium] Stopped 2023-11-15T18:20:59.656Z,1700072459.656 [Default:CheckIn:C.Wait] Running Loop=1 2023-11-15T18:20:59.656Z,1700072459.656 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-11-15T18:21:32.994Z,1700072492.994 [NAL9602](INFO): SBD MO Status=2, MOMSN=45817, MT Status=2, MTMSN=0 2023-11-15T18:21:32.994Z,1700072492.994 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-11-15T18:21:45.916Z,1700072505.916 [BPC1](INFO): Calculating totals. Valid battery stick count: 42. Valid reserve battery stick count: 5. 2023-11-15T18:21:45.919Z,1700072505.919 [BPC1](INFO): Received data from all battery sticks. 2023-11-15T18:22:44.491Z,1700072564.491 [NAL9602](INFO): SBD MO Status=2, MOMSN=45817, MT Status=2, MTMSN=0 2023-11-15T18:22:44.492Z,1700072564.492 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-11-15T18:25:32.567Z,1700072732.567 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2023-11-15T18:26:00.062Z,1700072760.062 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-11-15T18:26:00.062Z,1700072760.062 [Default:CheckIn:C.Wait] Stopped 2023-11-15T18:26:00.062Z,1700072760.062 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-11-15T18:26:00.063Z,1700072760.063 [Default:CheckIn:D] Running Loop=1 2023-11-15T18:26:00.467Z,1700072760.467 [Default:CheckIn:D] Stopped 2023-11-15T18:26:00.467Z,1700072760.467 [Default:CheckIn:E] Running Loop=1 2023-11-15T18:26:00.857Z,1700072760.857 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 154.877262 min 2023-11-15T18:26:00.857Z,1700072760.857 [Default:CheckIn:E] Stopped 2023-11-15T18:26:00.858Z,1700072760.858 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-11-15T18:26:00.858Z,1700072760.858 [Default:CheckIn] Stopped 2023-11-15T18:26:00.858Z,1700072760.858 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-11-15T18:26:00.858Z,1700072760.858 [Default:CheckIn](INFO): Running loop #21 2023-11-15T18:26:00.858Z,1700072760.858 [Default:CheckIn] Running Loop=21 2023-11-15T18:26:00.858Z,1700072760.858 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-11-15T18:26:00.858Z,1700072760.858 [Default:CheckIn:Read_GPS] Running Loop=1 2023-11-15T18:26:02.864Z,1700072762.864 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182602.00,A,3648.16955,N,12147.27959,W,0.058,94.34,151123,,,A*47 2023-11-15T18:26:02.866Z,1700072762.866 [NAL9602](INFO): GPS fix at 20231115T182602: (36.802826, -121.787993) 2023-11-15T18:26:02.877Z,1700072762.877 [Default:CheckIn:Read_GPS] Stopped 2023-11-15T18:26:02.877Z,1700072762.877 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-11-15T18:26:10.301Z,1700072770.301 [DataOverHttps](INFO): Sending 85 bytes from file Logs/20231115T161227/Courier0054.lzma 2023-11-15T18:26:11.303Z,1700072771.303 [DataOverHttps](INFO): Moved sent file to Logs/20231115T161227/Courier0054.lzma.bak 2023-11-15T18:26:11.303Z,1700072771.303 [DataOverHttps](INFO): SBD MOMSN=19068130 2023-11-15T18:26:27.141Z,1700072787.141 [DataOverHttps](INFO): Sending 207 bytes from file Logs/20231115T161227/Express0055.lzma 2023-11-15T18:26:28.143Z,1700072788.143 [DataOverHttps](INFO): Moved sent file to Logs/20231115T161227/Express0055.lzma.bak 2023-11-15T18:26:28.143Z,1700072788.143 [DataOverHttps](INFO): SBD MOMSN=19068133 2023-11-15T18:26:29.541Z,1700072789.541 [Default:CheckIn:Read_Iridium] Stopped 2023-11-15T18:26:29.541Z,1700072789.541 [Default:CheckIn:C.Wait] Running Loop=1 2023-11-15T18:26:29.541Z,1700072789.541 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-11-15T18:26:35.590Z,1700072795.590 [NAL9602](INFO): Not Powering down - fast GPS 2023-11-15T18:31:30.132Z,1700073090.132 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-11-15T18:31:30.132Z,1700073090.132 [Default:CheckIn:C.Wait] Stopped 2023-11-15T18:31:30.132Z,1700073090.132 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-11-15T18:31:30.133Z,1700073090.133 [Default:CheckIn:D] Running Loop=1 2023-11-15T18:31:30.544Z,1700073090.544 [Default:CheckIn:D] Stopped 2023-11-15T18:31:30.544Z,1700073090.544 [Default:CheckIn:E] Running Loop=1 2023-11-15T18:31:30.951Z,1700073090.951 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 160.378548 min 2023-11-15T18:31:30.951Z,1700073090.951 [Default:CheckIn:E] Stopped 2023-11-15T18:31:30.951Z,1700073090.951 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-11-15T18:31:30.951Z,1700073090.951 [Default:CheckIn] Stopped 2023-11-15T18:31:30.952Z,1700073090.952 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-11-15T18:31:30.952Z,1700073090.952 [Default:CheckIn](INFO): Running loop #22 2023-11-15T18:31:30.952Z,1700073090.952 [Default:CheckIn] Running Loop=22 2023-11-15T18:31:30.952Z,1700073090.952 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-11-15T18:31:30.952Z,1700073090.952 [Default:CheckIn:Read_GPS] Running Loop=1 2023-11-15T18:31:32.954Z,1700073092.954 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183132.00,A,3648.16878,N,12147.28767,W,0.078,307.23,151123,,,A*7D 2023-11-15T18:31:32.956Z,1700073092.956 [NAL9602](INFO): GPS fix at 20231115T183132: (36.802813, -121.788128) 2023-11-15T18:31:32.979Z,1700073092.979 [Default:CheckIn:Read_GPS] Stopped 2023-11-15T18:31:32.979Z,1700073092.979 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-11-15T18:31:40.885Z,1700073100.885 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20231115T161227/Courier0057.lzma 2023-11-15T18:31:41.887Z,1700073101.887 [DataOverHttps](INFO): Moved sent file to Logs/20231115T161227/Courier0057.lzma.bak 2023-11-15T18:31:41.888Z,1700073101.888 [DataOverHttps](INFO): SBD MOMSN=19068137 2023-11-15T18:31:57.697Z,1700073117.697 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20231115T161227/Express0058.lzma 2023-11-15T18:31:58.699Z,1700073118.699 [DataOverHttps](INFO): Moved sent file to Logs/20231115T161227/Express0058.lzma.bak 2023-11-15T18:31:58.700Z,1700073118.700 [DataOverHttps](INFO): SBD MOMSN=19068140 2023-11-15T18:32:00.037Z,1700073120.037 [Default:CheckIn:Read_Iridium] Stopped 2023-11-15T18:32:00.037Z,1700073120.037 [Default:CheckIn:C.Wait] Running Loop=1 2023-11-15T18:32:00.037Z,1700073120.037 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-11-15T18:36:35.559Z,1700073395.559 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2023-11-15T18:37:00.617Z,1700073420.617 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-11-15T18:37:00.617Z,1700073420.617 [Default:CheckIn:C.Wait] Stopped 2023-11-15T18:37:00.617Z,1700073420.617 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-11-15T18:37:00.618Z,1700073420.618 [Default:CheckIn:D] Running Loop=1 2023-11-15T18:37:01.030Z,1700073421.030 [Default:CheckIn:D] Stopped 2023-11-15T18:37:01.030Z,1700073421.030 [Default:CheckIn:E] Running Loop=1 2023-11-15T18:37:01.420Z,1700073421.420 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 165.886654 min 2023-11-15T18:37:01.420Z,1700073421.420 [Default:CheckIn:E] Stopped 2023-11-15T18:37:01.420Z,1700073421.420 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-11-15T18:37:01.420Z,1700073421.420 [Default:CheckIn] Stopped 2023-11-15T18:37:01.420Z,1700073421.420 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-11-15T18:37:01.420Z,1700073421.420 [Default:CheckIn](INFO): Running loop #23 2023-11-15T18:37:01.421Z,1700073421.421 [Default:CheckIn] Running Loop=23 2023-11-15T18:37:01.421Z,1700073421.421 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-11-15T18:37:01.421Z,1700073421.421 [Default:CheckIn:Read_GPS] Running Loop=1 2023-11-15T18:37:03.437Z,1700073423.437 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183702.00,A,3648.16471,N,12147.28409,W,0.078,307.23,151123,,,A*76 2023-11-15T18:37:03.439Z,1700073423.439 [NAL9602](INFO): GPS fix at 20231115T183702: (36.802745, -121.788068) 2023-11-15T18:37:03.450Z,1700073423.450 [Default:CheckIn:Read_GPS] Stopped 2023-11-15T18:37:03.450Z,1700073423.450 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-11-15T18:37:10.333Z,1700073430.333 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20231115T161227/Courier0060.lzma 2023-11-15T18:37:11.336Z,1700073431.336 [DataOverHttps](INFO): Moved sent file to Logs/20231115T161227/Courier0060.lzma.bak 2023-11-15T18:37:11.336Z,1700073431.336 [DataOverHttps](INFO): SBD MOMSN=19068146 2023-11-15T18:37:27.157Z,1700073447.157 [DataOverHttps](INFO): Sending 209 bytes from file Logs/20231115T161227/Express0061.lzma 2023-11-15T18:37:28.159Z,1700073448.159 [DataOverHttps](INFO): Moved sent file to Logs/20231115T161227/Express0061.lzma.bak 2023-11-15T18:37:28.160Z,1700073448.160 [DataOverHttps](INFO): SBD MOMSN=19068149 2023-11-15T18:37:29.297Z,1700073449.297 [Default:CheckIn:Read_Iridium] Stopped 2023-11-15T18:37:29.297Z,1700073449.297 [Default:CheckIn:C.Wait] Running Loop=1 2023-11-15T18:37:29.298Z,1700073449.298 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-11-15T18:37:35.350Z,1700073455.350 [NAL9602](INFO): Not Powering down - fast GPS 2023-11-15T18:42:29.881Z,1700073749.881 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-11-15T18:42:29.881Z,1700073749.881 [Default:CheckIn:C.Wait] Stopped 2023-11-15T18:42:29.881Z,1700073749.881 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-11-15T18:42:29.881Z,1700073749.881 [Default:CheckIn:D] Running Loop=1 2023-11-15T18:42:30.297Z,1700073750.297 [Default:CheckIn:D] Stopped 2023-11-15T18:42:30.297Z,1700073750.297 [Default:CheckIn:E] Running Loop=1 2023-11-15T18:42:30.689Z,1700073750.689 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 171.374430 min 2023-11-15T18:42:30.689Z,1700073750.689 [Default:CheckIn:E] Stopped 2023-11-15T18:42:30.689Z,1700073750.689 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-11-15T18:42:30.689Z,1700073750.689 [Default:CheckIn] Stopped 2023-11-15T18:42:30.689Z,1700073750.689 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-11-15T18:42:30.689Z,1700073750.689 [Default:CheckIn](INFO): Running loop #24 2023-11-15T18:42:30.689Z,1700073750.689 [Default:CheckIn] Running Loop=24 2023-11-15T18:42:30.690Z,1700073750.690 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-11-15T18:42:30.690Z,1700073750.690 [Default:CheckIn:Read_GPS] Running Loop=1 2023-11-15T18:42:32.700Z,1700073752.700 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184231.00,A,3648.16048,N,12147.28464,W,0.622,72.83,151123,,,A*43 2023-11-15T18:42:32.702Z,1700073752.702 [NAL9602](INFO): GPS fix at 20231115T184231: (36.802675, -121.788077) 2023-11-15T18:42:32.713Z,1700073752.713 [Default:CheckIn:Read_GPS] Stopped 2023-11-15T18:42:32.713Z,1700073752.713 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-11-15T18:42:39.925Z,1700073759.925 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20231115T161227/Courier0063.lzma 2023-11-15T18:42:40.927Z,1700073760.927 [DataOverHttps](INFO): Moved sent file to Logs/20231115T161227/Courier0063.lzma.bak 2023-11-15T18:42:40.928Z,1700073760.928 [DataOverHttps](INFO): SBD MOMSN=19068154 2023-11-15T18:42:59.825Z,1700073779.825 [DataOverHttps](INFO): Sending 136 bytes from file Logs/20231115T161227/Express0064.lzma 2023-11-15T18:43:00.827Z,1700073780.827 [DataOverHttps](INFO): Moved sent file to Logs/20231115T161227/Express0064.lzma.bak 2023-11-15T18:43:00.827Z,1700073780.827 [DataOverHttps](INFO): SBD MOMSN=19068157 2023-11-15T18:43:02.269Z,1700073782.269 [Default:CheckIn:Read_Iridium] Stopped 2023-11-15T18:43:02.269Z,1700073782.269 [Default:CheckIn:C.Wait] Running Loop=1 2023-11-15T18:43:02.269Z,1700073782.269 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-11-15T18:43:03.466Z,1700073783.466 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2023-11-15T18:43:03.545Z,1700073783.545 [NAL9602](ERROR): received: +CSQ:0 OK817, 2, 0, 0, 0 OK 2023-11-15T18:45:02.649Z,1700073902.649 [NAL9602](INFO): SBD MO Status=2, MOMSN=45817, MT Status=2, MTMSN=0 2023-11-15T18:45:02.649Z,1700073902.649 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-11-15T18:47:35.368Z,1700074055.368 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2023-11-15T18:48:02.856Z,1700074082.856 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-11-15T18:48:02.856Z,1700074082.856 [Default:CheckIn:C.Wait] Stopped 2023-11-15T18:48:02.856Z,1700074082.856 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-11-15T18:48:02.857Z,1700074082.857 [Default:CheckIn:D] Running Loop=1 2023-11-15T18:48:03.249Z,1700074083.249 [Default:CheckIn:D] Stopped 2023-11-15T18:48:03.249Z,1700074083.249 [Default:CheckIn:E] Running Loop=1 2023-11-15T18:48:03.657Z,1700074083.657 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 176.923633 min 2023-11-15T18:48:03.657Z,1700074083.657 [Default:CheckIn:E] Stopped 2023-11-15T18:48:03.657Z,1700074083.657 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-11-15T18:48:03.657Z,1700074083.657 [Default:CheckIn] Stopped 2023-11-15T18:48:03.657Z,1700074083.657 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-11-15T18:48:03.657Z,1700074083.657 [Default:CheckIn](INFO): Running loop #25 2023-11-15T18:48:03.657Z,1700074083.657 [Default:CheckIn] Running Loop=25 2023-11-15T18:48:03.657Z,1700074083.657 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-11-15T18:48:03.658Z,1700074083.658 [Default:CheckIn:Read_GPS] Running Loop=1 2023-11-15T18:48:05.665Z,1700074085.665 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184804.00,A,3648.16554,N,12147.28385,W,0.058,351.22,151123,,,A*7D 2023-11-15T18:48:05.667Z,1700074085.667 [NAL9602](INFO): GPS fix at 20231115T184804: (36.802759, -121.788064) 2023-11-15T18:48:05.678Z,1700074085.678 [Default:CheckIn:Read_GPS] Stopped 2023-11-15T18:48:05.678Z,1700074085.678 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-11-15T18:48:07.279Z,1700074087.279 [NAL9602](FAULT): LCB fault: Invalid Command. Hardware Overcurrent Shutdown. Current Limiter Activated. 2023-11-15T18:48:07.279Z,1700074087.279 [NAL9602] Hardware Fault, FailCount= 1 2023-11-15T18:48:07.279Z,1700074087.279 [NAL9602](ERROR): Hardware Fault 2023-11-15T18:48:07.324Z,1700074087.324 [CBIT](ERROR): Hardware Fault in component: NAL9602 2023-11-15T18:48:07.686Z,1700074087.686 [NAL9602](INFO): Powering down 2023-11-15T18:48:08.514Z,1700074088.514 [CBIT](INFO): Clearing failed state for component NAL9602 2023-11-15T18:48:08.514Z,1700074088.514 [NAL9602] No Fault, FailCount= 1 2023-11-15T18:48:13.697Z,1700074093.697 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20231115T161227/Courier0066.lzma 2023-11-15T18:48:14.699Z,1700074094.699 [DataOverHttps](INFO): Moved sent file to Logs/20231115T161227/Courier0066.lzma.bak 2023-11-15T18:48:14.699Z,1700074094.699 [DataOverHttps](INFO): SBD MOMSN=19068175 2023-11-15T18:48:31.093Z,1700074111.093 [DataOverHttps](INFO): Sending 208 bytes from file Logs/20231115T161227/Express0067.lzma 2023-11-15T18:48:32.095Z,1700074112.095 [DataOverHttps](INFO): Moved sent file to Logs/20231115T161227/Express0067.lzma.bak 2023-11-15T18:48:32.096Z,1700074112.096 [DataOverHttps](INFO): SBD MOMSN=19068178 2023-11-15T18:48:33.549Z,1700074113.549 [Default:CheckIn:Read_Iridium] Stopped 2023-11-15T18:48:33.550Z,1700074113.550 [Default:CheckIn:C.Wait] Running Loop=1 2023-11-15T18:48:33.550Z,1700074113.550 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-11-15T18:48:37.987Z,1700074117.987 [NAL9602](INFO): Powering up NAL9602 2023-11-15T18:48:48.891Z,1700074128.891 [NAL9602](INFO): NAL9602 initialized 2023-11-15T18:49:20.001Z,1700074160.001 [NAL9602](INFO): Not Powering down - fast GPS 2023-11-15T18:53:34.132Z,1700074414.132 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-11-15T18:53:34.132Z,1700074414.132 [Default:CheckIn:C.Wait] Stopped 2023-11-15T18:53:34.132Z,1700074414.132 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-11-15T18:53:34.132Z,1700074414.132 [Default:CheckIn:D] Running Loop=1 2023-11-15T18:53:34.542Z,1700074414.542 [Default:CheckIn:D] Stopped 2023-11-15T18:53:34.542Z,1700074414.542 [Default:CheckIn:E] Running Loop=1 2023-11-15T18:53:34.943Z,1700074414.943 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 182.445182 min 2023-11-15T18:53:34.943Z,1700074414.943 [Default:CheckIn:E] Stopped 2023-11-15T18:53:34.943Z,1700074414.943 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-11-15T18:53:34.943Z,1700074414.943 [Default:CheckIn] Stopped 2023-11-15T18:53:34.943Z,1700074414.943 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-11-15T18:53:34.943Z,1700074414.943 [Default:CheckIn](INFO): Running loop #26 2023-11-15T18:53:34.943Z,1700074414.943 [Default:CheckIn] Running Loop=26 2023-11-15T18:53:34.943Z,1700074414.943 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-11-15T18:53:34.943Z,1700074414.943 [Default:CheckIn:Read_GPS] Running Loop=1 2023-11-15T18:54:06.851Z,1700074446.851 [NAL9602](ERROR): parseGSV uart error: serial timeout 2023-11-15T18:58:35.146Z,1700074715.146 [Default:CheckIn:Read_GPS](INFO): Timed out from 2023-11-15T18:53:34.9Z 2023-11-15T18:58:35.146Z,1700074715.146 [Default:CheckIn:Read_GPS] Stopped 2023-11-15T18:58:35.146Z,1700074715.146 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-11-15T18:58:45.061Z,1700074725.061 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20231115T161227/Courier0069.lzma 2023-11-15T18:58:46.063Z,1700074726.063 [DataOverHttps](INFO): Moved sent file to Logs/20231115T161227/Courier0069.lzma.bak 2023-11-15T18:58:46.064Z,1700074726.064 [DataOverHttps](INFO): SBD MOMSN=19068271 2023-11-15T18:59:01.798Z,1700074741.798 [DataOverHttps](INFO): Sending 210 bytes from file Logs/20231115T161227/Express0070.lzma 2023-11-15T18:59:02.800Z,1700074742.800 [DataOverHttps](INFO): Moved sent file to Logs/20231115T161227/Express0070.lzma.bak 2023-11-15T18:59:02.800Z,1700074742.800 [DataOverHttps](INFO): SBD MOMSN=19068273 2023-11-15T18:59:04.232Z,1700074744.232 [Default:CheckIn:Read_Iridium] Stopped 2023-11-15T18:59:04.232Z,1700074744.232 [Default:CheckIn:C.Wait] Running Loop=1 2023-11-15T18:59:04.232Z,1700074744.232 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-11-15T18:59:07.435Z,1700074747.435 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2023-11-15T18:59:38.139Z,1700074778.139 [NAL9602](INFO): Not Powering down - fast GPS 2023-11-15T19:04:04.828Z,1700075044.828 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-11-15T19:04:04.828Z,1700075044.828 [Default:CheckIn:C.Wait] Stopped 2023-11-15T19:04:04.828Z,1700075044.828 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-11-15T19:04:04.828Z,1700075044.828 [Default:CheckIn:D] Running Loop=1 2023-11-15T19:04:05.220Z,1700075045.220 [Default:CheckIn:D] Stopped 2023-11-15T19:04:05.220Z,1700075045.220 [Default:CheckIn:E] Running Loop=1 2023-11-15T19:04:05.624Z,1700075045.624 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 192.956478 min 2023-11-15T19:04:05.624Z,1700075045.624 [Default:CheckIn:E] Stopped 2023-11-15T19:04:05.624Z,1700075045.624 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-11-15T19:04:05.625Z,1700075045.625 [Default:CheckIn] Stopped 2023-11-15T19:04:05.625Z,1700075045.625 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-11-15T19:04:05.625Z,1700075045.625 [Default:CheckIn](INFO): Running loop #27 2023-11-15T19:04:05.625Z,1700075045.625 [Default:CheckIn] Running Loop=27 2023-11-15T19:04:05.625Z,1700075045.625 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-11-15T19:04:05.625Z,1700075045.625 [Default:CheckIn:Read_GPS] Running Loop=1 2023-11-15T19:04:07.239Z,1700075047.239 [NAL9602](FAULT): GPS failed to acquire within timeout. 2023-11-15T19:04:07.239Z,1700075047.239 [NAL9602] Data Fault, FailCount= 1 2023-11-15T19:04:07.239Z,1700075047.239 [NAL9602](ERROR): Data Fault 2023-11-15T19:04:07.259Z,1700075047.259 [CBIT](ERROR): Data Fault in component: NAL9602 2023-11-15T19:04:07.635Z,1700075047.635 [NAL9602](INFO): Powering down 2023-11-15T19:04:08.465Z,1700075048.465 [CBIT](INFO): Clearing failed state for component NAL9602 2023-11-15T19:04:08.465Z,1700075048.465 [NAL9602] No Fault, FailCount= 1 2023-11-15T19:04:37.935Z,1700075077.935 [NAL9602](INFO): Powering up NAL9602 2023-11-15T19:04:48.842Z,1700075088.842 [NAL9602](INFO): NAL9602 initialized 2023-11-15T19:09:05.895Z,1700075345.895 [Default:CheckIn:Read_GPS](INFO): Timed out from 2023-11-15T19:04:05.6Z 2023-11-15T19:09:05.895Z,1700075345.895 [Default:CheckIn:Read_GPS] Stopped 2023-11-15T19:09:05.895Z,1700075345.895 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-11-15T19:09:12.901Z,1700075352.901 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20231115T161227/Courier0072.lzma 2023-11-15T19:09:13.903Z,1700075353.903 [DataOverHttps](INFO): Moved sent file to Logs/20231115T161227/Courier0072.lzma.bak 2023-11-15T19:09:13.904Z,1700075353.904 [DataOverHttps](INFO): SBD MOMSN=19068371 2023-11-15T19:09:29.681Z,1700075369.681 [DataOverHttps](INFO): Sending 227 bytes from file Logs/20231115T161227/Express0073.lzma 2023-11-15T19:09:30.683Z,1700075370.683 [DataOverHttps](INFO): Moved sent file to Logs/20231115T161227/Express0073.lzma.bak 2023-11-15T19:09:30.684Z,1700075370.684 [DataOverHttps](INFO): SBD MOMSN=19068407 2023-11-15T19:09:32.161Z,1700075372.161 [Default:CheckIn:Read_Iridium] Stopped 2023-11-15T19:09:32.165Z,1700075372.165 [Default:CheckIn:C.Wait] Running Loop=1 2023-11-15T19:09:32.165Z,1700075372.165 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-11-15T19:09:52.322Z,1700075392.322 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2023-11-15T19:10:23.030Z,1700075423.030 [NAL9602](INFO): Not Powering down - fast GPS 2023-11-15T19:14:32.781Z,1700075672.781 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-11-15T19:14:32.781Z,1700075672.781 [Default:CheckIn:C.Wait] Stopped 2023-11-15T19:14:32.781Z,1700075672.781 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-11-15T19:14:32.782Z,1700075672.782 [Default:CheckIn:D] Running Loop=1 2023-11-15T19:14:33.169Z,1700075673.169 [Default:CheckIn:D] Stopped 2023-11-15T19:14:33.169Z,1700075673.169 [Default:CheckIn:E] Running Loop=1 2023-11-15T19:14:33.573Z,1700075673.573 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 203.422298 min 2023-11-15T19:14:33.574Z,1700075673.574 [Default:CheckIn:E] Stopped 2023-11-15T19:14:33.574Z,1700075673.574 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-11-15T19:14:33.575Z,1700075673.575 [Default:CheckIn] Stopped 2023-11-15T19:14:33.575Z,1700075673.575 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-11-15T19:14:33.576Z,1700075673.576 [Default:CheckIn](INFO): Running loop #28 2023-11-15T19:14:33.577Z,1700075673.577 [Default:CheckIn] Running Loop=28 2023-11-15T19:14:33.577Z,1700075673.577 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-11-15T19:14:33.578Z,1700075673.578 [Default:CheckIn:Read_GPS] Running Loop=1 2023-11-15T19:15:06.287Z,1700075706.287 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2023-11-15T19:15:06.365Z,1700075706.365 [NAL9602](ERROR): received: +CSQ:0 OK817, 2, 0, 0, 0 OK 2023-11-15T19:15:06.687Z,1700075706.687 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2023-11-15T19:15:37.826Z,1700075737.826 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2023-11-15T19:16:08.950Z,1700075768.950 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2023-11-15T19:16:40.074Z,1700075800.074 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2023-11-15T19:17:11.210Z,1700075831.210 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2023-11-15T19:17:14.222Z,1700075834.222 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.759552 2023-11-15T19:18:12.478Z,1700075892.478 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2023-11-15T19:18:43.614Z,1700075923.614 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2023-11-15T19:19:14.738Z,1700075954.738 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2023-11-15T19:19:23.158Z,1700075963.158 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003583 2023-11-15T19:19:33.771Z,1700075973.771 [Default:CheckIn:Read_GPS](INFO): Timed out from 2023-11-15T19:14:33.6Z 2023-11-15T19:19:33.771Z,1700075973.771 [Default:CheckIn:Read_GPS] Stopped 2023-11-15T19:19:33.771Z,1700075973.771 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-11-15T19:19:38.187Z,1700075978.187 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2023-11-15T19:19:40.713Z,1700075980.713 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20231115T161227/Courier0075.lzma 2023-11-15T19:19:41.715Z,1700075981.715 [DataOverHttps](INFO): Moved sent file to Logs/20231115T161227/Courier0075.lzma.bak 2023-11-15T19:19:41.716Z,1700075981.716 [DataOverHttps](INFO): SBD MOMSN=19068480 2023-11-15T19:19:57.613Z,1700075997.613 [DataOverHttps](INFO): Sending 209 bytes from file Logs/20231115T161227/Express0076.lzma 2023-11-15T19:19:58.615Z,1700075998.615 [DataOverHttps](INFO): Moved sent file to Logs/20231115T161227/Express0076.lzma.bak 2023-11-15T19:19:58.616Z,1700075998.616 [DataOverHttps](INFO): SBD MOMSN=19068482 2023-11-15T19:20:00.018Z,1700076000.018 [Default:CheckIn:Read_Iridium] Stopped 2023-11-15T19:20:00.018Z,1700076000.018 [Default:CheckIn:C.Wait] Running Loop=1 2023-11-15T19:20:00.018Z,1700076000.018 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-11-15T19:20:08.894Z,1700076008.894 [NAL9602](INFO): Not Powering down - fast GPS 2023-11-15T19:25:00.696Z,1700076300.696 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-11-15T19:25:00.696Z,1700076300.696 [Default:CheckIn:C.Wait] Stopped 2023-11-15T19:25:00.696Z,1700076300.696 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-11-15T19:25:00.697Z,1700076300.697 [Default:CheckIn:D] Running Loop=1 2023-11-15T19:25:01.103Z,1700076301.103 [Default:CheckIn:D] Stopped 2023-11-15T19:25:01.103Z,1700076301.103 [Default:CheckIn:E] Running Loop=1 2023-11-15T19:25:01.519Z,1700076301.519 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 213.887874 min 2023-11-15T19:25:01.519Z,1700076301.519 [Default:CheckIn:E] Stopped 2023-11-15T19:25:01.519Z,1700076301.519 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-11-15T19:25:01.519Z,1700076301.519 [Default:CheckIn] Stopped 2023-11-15T19:25:01.519Z,1700076301.519 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-11-15T19:25:01.519Z,1700076301.519 [Default:CheckIn](INFO): Running loop #29 2023-11-15T19:25:01.519Z,1700076301.519 [Default:CheckIn] Running Loop=29 2023-11-15T19:25:01.520Z,1700076301.520 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-11-15T19:25:01.520Z,1700076301.520 [Default:CheckIn:Read_GPS] Running Loop=1 2023-11-15T19:25:03.099Z,1700076303.099 [NAL9602](FAULT): GPS failed to acquire within timeout. 2023-11-15T19:25:03.099Z,1700076303.099 [NAL9602] Data Fault, FailCount= 2 2023-11-15T19:25:03.099Z,1700076303.099 [NAL9602](ERROR): Data Fault 2023-11-15T19:25:03.206Z,1700076303.206 [CBIT](ERROR): Data Fault in component: NAL9602 2023-11-15T19:25:03.499Z,1700076303.499 [NAL9602](INFO): Powering down 2023-11-15T19:25:04.362Z,1700076304.362 [CBIT](INFO): Clearing failed state for component NAL9602 2023-11-15T19:25:04.363Z,1700076304.363 [NAL9602] No Fault, FailCount= 2 2023-11-15T19:25:33.532Z,1700076333.532 [NAL9602](INFO): Powering up NAL9602 2023-11-15T19:25:44.435Z,1700076344.435 [NAL9602](INFO): NAL9602 initialized 2023-11-15T19:25:58.583Z,1700076358.583 [DropWeight](CRITICAL): DROP WEIGHT MISSING. 2023-11-15T19:25:58.583Z,1700076358.583 [DropWeight] Hardware Fault, FailCount= 1 2023-11-15T19:25:58.583Z,1700076358.583 [DropWeight](ERROR): Hardware Fault 2023-11-15T19:25:58.670Z,1700076358.670 [CommandExec](FAULT): Scheduling is paused 2023-11-15T19:25:58.671Z,1700076358.671 [CBIT](INFO): Critical error at 20231115T192558 2023-11-15T19:25:58.673Z,1700076358.673 [CBIT](ERROR): Hardware Fault in component: DropWeight 2023-11-15T19:25:58.682Z,1700076358.682 [CBIT](CRITICAL): Hardware Fault in component: DropWeight 2023-11-15T19:25:59.053Z,1700076359.053 [CBIT](INFO): Critical error at 20231115T192558 2023-11-15T19:27:54.114Z,1700076474.114 [CommandExec](IMPORTANT): got command quit 2023-11-15T19:27:55.166Z,1700076475.166 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread. 2023-11-15T19:27:55.166Z,1700076475.166 [CommandExec](INFO): Uninitializing the command executive. 2023-11-15T19:27:55.166Z,1700076475.166 [CommandExec](INFO): Uninitializing the command scheduler. 2023-11-15T19:27:55.166Z,1700076475.166 [CommandExec ThreadHandler](INFO): Thread cancelled. 2023-11-15T19:27:55.321Z,1700076475.321 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2023-11-15T19:27:55.322Z,1700076475.322 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2023-11-15T19:27:55.322Z,1700076475.322 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2023-11-15T19:27:55.322Z,1700076475.322 [NavChartDb](INFO): Join timeout helper Thread ID is 9418 2023-11-15T19:27:55.590Z,1700076475.590 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2023-11-15T19:27:55.590Z,1700076475.590 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2023-11-15T19:27:55.594Z,1700076475.594 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2023-11-15T19:27:55.594Z,1700076475.594 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2023-11-15T19:27:55.594Z,1700076475.594 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 9419 2023-11-15T19:27:55.814Z,1700076475.814 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2023-11-15T19:27:55.814Z,1700076475.814 [WetLabsBB2FL](INFO): Powering down 2023-11-15T19:27:55.815Z,1700076475.815 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2023-11-15T19:27:55.830Z,1700076475.830 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler 2023-11-15T19:27:55.830Z,1700076475.830 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2023-11-15T19:27:55.830Z,1700076475.830 [CTD_Seabird](INFO): Join timeout helper Thread ID is 9420 2023-11-15T19:27:56.118Z,1700076476.118 [CTD_Seabird](INFO): Powering down 2023-11-15T19:27:56.130Z,1700076476.130 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread. 2023-11-15T19:27:56.130Z,1700076476.130 [CTD_Seabird](INFO): Powering down 2023-11-15T19:27:56.142Z,1700076476.142 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2023-11-15T19:27:56.150Z,1700076476.150 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2023-11-15T19:27:56.150Z,1700076476.150 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2023-11-15T19:27:56.150Z,1700076476.150 [Radio_Surface](INFO): Join timeout helper Thread ID is 9421 2023-11-15T19:27:56.302Z,1700076476.302 [Radio_Surface](INFO): Powering down 2023-11-15T19:27:56.303Z,1700076476.303 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2023-11-15T19:27:56.303Z,1700076476.303 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2023-11-15T19:27:56.314Z,1700076476.314 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler 2023-11-15T19:27:56.314Z,1700076476.314 [Onboard ThreadHandler](INFO): Thread cancelled. 2023-11-15T19:27:56.314Z,1700076476.314 [Onboard](INFO): Join timeout helper Thread ID is 9422 2023-11-15T19:27:56.946Z,1700076476.946 [DataOverHttps](INFO): Radio surface powered OFF, will not connect. 2023-11-15T19:27:58.310Z,1700076478.310 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread. 2023-11-15T19:27:58.310Z,1700076478.310 [Onboard ThreadHandler](INFO): Thread cancelled. 2023-11-15T19:27:58.327Z,1700076478.327 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler 2023-11-15T19:27:58.327Z,1700076478.327 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2023-11-15T19:27:58.328Z,1700076478.328 [DataOverHttps](INFO): Join timeout helper Thread ID is 9423 2023-11-15T19:27:58.954Z,1700076478.954 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread. 2023-11-15T19:27:58.954Z,1700076478.954 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2023-11-15T19:27:58.962Z,1700076478.962 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2023-11-15T19:27:58.962Z,1700076478.962 [logger ThreadHandler](INFO): Thread cancelled. 2023-11-15T19:27:58.963Z,1700076478.963 [logger](INFO): Join timeout helper Thread ID is 9424 2023-11-15T19:27:58.998Z,1700076478.998 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2023-11-15T19:27:58.998Z,1700076478.998 [logger ThreadHandler](INFO): Thread cancelled. 2023-11-15T19:27:59.002Z,1700076479.002 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2023-11-15T19:27:59.002Z,1700076479.002 [CommandLine ThreadHandler](INFO): Thread cancelled. 2023-11-15T19:27:59.003Z,1700076479.003 [CommandLine](INFO): Join timeout helper Thread ID is 9425 2023-11-15T19:27:59.097Z,1700076479.097 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2023-11-15T19:27:59.098Z,1700076479.098 [CommandLine ThreadHandler](INFO): Thread cancelled. 2023-11-15T19:27:59.102Z,1700076479.102 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler 2023-11-15T19:27:59.102Z,1700076479.102 [CommandExec ThreadHandler](INFO): Thread cancelled. 2023-11-15T19:27:59.103Z,1700076479.103 [CommandExec](INFO): Join timeout helper Thread ID is 9426 2023-11-15T19:27:59.104Z,1700076479.104 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2023-11-15T19:27:59.104Z,1700076479.104 [controlThread ThreadHandler](INFO): Thread cancelled. 2023-11-15T19:27:59.104Z,1700076479.104 [controlThread](INFO): Join timeout helper Thread ID is 9427 2023-11-15T19:27:59.389Z,1700076479.389 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2023-11-15T19:27:59.390Z,1700076479.390 [controlThread](DEBUG): Uninitializing ControlThread 2023-11-15T19:27:59.390Z,1700076479.390 [AHRS_M2](INFO): Powering down 2023-11-15T19:27:59.463Z,1700076479.463 [NAL9602](INFO): Powering down 2023-11-15T19:27:59.464Z,1700076479.464 [Sonardyne_Nano](INFO): Powering down 2023-11-15T19:27:59.583Z,1700076479.583 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator. 2023-11-15T19:27:59.583Z,1700076479.583 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator. 2023-11-15T19:27:59.584Z,1700076479.584 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2023-11-15T19:27:59.584Z,1700076479.584 [MissionManager](INFO): Uninitializing Mission Default 2023-11-15T19:27:59.584Z,1700076479.584 [Default] Stopped 2023-11-15T19:27:59.584Z,1700076479.584 [Default](DEBUG): Aggregate::uninitialize Default 2023-11-15T19:27:59.584Z,1700076479.584 [Default:B.GoToSurface] Stopped 2023-11-15T19:27:59.584Z,1700076479.584 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2023-11-15T19:27:59.585Z,1700076479.585 [Default:CheckIn] Stopped 2023-11-15T19:27:59.585Z,1700076479.585 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-11-15T19:27:59.585Z,1700076479.585 [Default:CheckIn:Read_GPS] Stopped 2023-11-15T19:27:59.588Z,1700076479.588 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2023-11-15T19:27:59.588Z,1700076479.588 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2023-11-15T19:27:59.588Z,1700076479.588 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2023-11-15T19:27:59.589Z,1700076479.589 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2023-11-15T19:27:59.589Z,1700076479.589 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2023-11-15T19:27:59.589Z,1700076479.589 [BuoyancyServo](INFO): Powering down 2023-11-15T19:27:59.602Z,1700076479.602 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2023-11-15T19:27:59.602Z,1700076479.602 [ElevatorServo](INFO): Powering down 2023-11-15T19:27:59.603Z,1700076479.603 [MassServo](DEBUG): Uninitialize Mass Servo. 2023-11-15T19:27:59.603Z,1700076479.603 [MassServo](INFO): Powering down 2023-11-15T19:27:59.604Z,1700076479.604 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2023-11-15T19:27:59.604Z,1700076479.604 [RudderServo](INFO): Powering down 2023-11-15T19:27:59.604Z,1700076479.604 [ThrusterHE](DEBUG): Uninitialize Thruster Servo. 2023-11-15T19:27:59.605Z,1700076479.605 [ThrusterHE](INFO): Powering down 2023-11-15T19:27:59.606Z,1700076479.606 [SBIT](DEBUG): Uninitialize SBIT Component. 2023-11-15T19:27:59.606Z,1700076479.606 [IBIT](DEBUG): Uninitialize IBIT Component. 2023-11-15T19:27:59.606Z,1700076479.606 [CBIT](DEBUG): Uninitialize CBIT Component. 2023-11-15T19:27:59.606Z,1700076479.606 [CBIT](DEBUG): Powering off loads. 2023-11-15T19:27:59.617Z,1700076479.617 [CBIT](DEBUG): Disabling WDT. 2023-11-15T19:27:59.629Z,1700076479.629 [CBIT](DEBUG): Opening all GF detection circuits. 2023-11-15T19:27:59.630Z,1700076479.630 [controlThread ThreadHandler](INFO): Thread cancelled. 2023-11-15T19:27:59.685Z,1700076479.685 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2023-11-15T19:27:59.688Z,1700076479.688 [Onboard ThreadHandler](INFO): Thread cancelled. 2023-11-15T19:27:59.694Z,1700076479.694 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2023-11-15T19:27:59.766Z,1700076479.766 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2023-11-15T19:27:59.769Z,1700076479.769 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2023-11-15T19:27:59.809Z,1700076479.809 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2023-11-15T19:27:59.915Z,1700076479.915 [logger ThreadHandler](INFO): Thread cancelled.