2022-08-18T21:23:49.545Z,1660857829.545 [CommandExec](IMPORTANT): got command restart logs 2022-08-18T21:23:52.052Z,1660857832.052 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-08-18T21:24:03.561Z,1660857843.561 [NAL9602](INFO): SBD MO Status=1, MOMSN=36005, MT Status=0, MTMSN=0 2022-08-18T21:24:03.612Z,1660857843.612 [NAL9602](INFO): Sent 39 bytes from file Logs/20220818T205612/Courier0018.lzma 2022-08-18T21:24:03.612Z,1660857843.612 [NAL9602](INFO): Packets left to send: 0 2022-08-18T21:24:14.539Z,1660857854.539 [NAL9602](INFO): SBD MO Status=1, MOMSN=36006, MT Status=0, MTMSN=0 2022-08-18T21:24:14.594Z,1660857854.594 [NAL9602](INFO): Sent 257 bytes from file Logs/20220818T205612/Express0019.lzma 2022-08-18T21:24:14.594Z,1660857854.594 [NAL9602](INFO): Packets left to send: 0 2022-08-18T21:24:21.814Z,1660857861.814 [NAL9602](INFO): SBD MO Status=0, MOMSN=36007, MT Status=0, MTMSN=0 2022-08-18T21:24:23.176Z,1660857863.176 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-08-18T21:24:41.649Z,1660857881.649 [NAL9602](INFO): SBD MO Status=1, MOMSN=36008, MT Status=0, MTMSN=0 2022-08-18T21:24:41.700Z,1660857881.700 [NAL9602](INFO): Sent 151 bytes from file Logs/20220818T212349/Courier0000.lzma 2022-08-18T21:24:41.700Z,1660857881.700 [NAL9602](INFO): Packets left to send: 0 2022-08-18T21:24:54.300Z,1660857894.300 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-08-18T21:25:01.107Z,1660857901.107 [NAL9602](INFO): SBD MO Status=1, MOMSN=36009, MT Status=0, MTMSN=0 2022-08-18T21:25:01.156Z,1660857901.156 [NAL9602](INFO): Sent 332 bytes from file Logs/20220818T212349/Express0001.lzma 2022-08-18T21:25:01.156Z,1660857901.156 [NAL9602](INFO): Packets left to send: 1 2022-08-18T21:25:19.743Z,1660857919.743 [NAL9602](INFO): SBD MO Status=2, MOMSN=36010, MT Status=2, MTMSN=0 2022-08-18T21:25:19.743Z,1660857919.743 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-08-18T21:25:25.460Z,1660857925.460 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-08-18T21:25:49.682Z,1660857949.682 [NAL9602](INFO): SBD MO Status=1, MOMSN=36010, MT Status=0, MTMSN=0 2022-08-18T21:25:49.736Z,1660857949.736 [NAL9602](INFO): Sent 32 bytes from file Logs/20220818T212349/Express0001.lzma 2022-08-18T21:25:49.736Z,1660857949.736 [NAL9602](INFO): Packets left to send: 0 2022-08-18T21:25:56.600Z,1660857956.600 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-08-18T21:26:08.671Z,1660857968.671 [NAL9602](INFO): SBD MO Status=2, MOMSN=36011, MT Status=2, MTMSN=0 2022-08-18T21:26:08.671Z,1660857968.671 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-08-18T21:26:13.605Z,1660857973.605 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2022-08-18T21:26:27.732Z,1660857987.732 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-08-18T21:26:30.081Z,1660857990.081 [NAL9602](INFO): SBD MO Status=2, MOMSN=36011, MT Status=2, MTMSN=0 2022-08-18T21:26:30.081Z,1660857990.081 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-08-18T21:26:45.838Z,1660858005.838 [NAL9602](INFO): SBD MO Status=2, MOMSN=36011, MT Status=2, MTMSN=0 2022-08-18T21:26:45.839Z,1660858005.839 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-08-18T21:26:58.856Z,1660858018.856 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-08-18T21:27:03.618Z,1660858023.618 [NAL9602](INFO): SBD MO Status=0, MOMSN=36011, MT Status=0, MTMSN=0 2022-08-18T21:27:03.697Z,1660858023.697 [Default:CheckIn:Read_Iridium] Stopped 2022-08-18T21:27:03.697Z,1660858023.697 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-18T21:27:03.697Z,1660858023.697 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-18T21:27:29.984Z,1660858049.984 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-08-18T21:27:34.331Z,1660858054.331 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-18T21:28:01.108Z,1660858081.108 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-08-18T21:28:32.252Z,1660858112.252 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-08-18T21:29:03.388Z,1660858143.388 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-08-18T21:29:34.540Z,1660858174.540 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-08-18T21:29:43.289Z,1660858183.289 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003519 2022-08-18T21:31:29.853Z,1660858289.853 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-08-18T21:31:36.318Z,1660858296.318 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-08-18T21:31:51.669Z,1660858311.669 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-08-18T21:32:04.212Z,1660858324.212 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-18T21:32:04.212Z,1660858324.212 [Default:CheckIn:C.Wait] Stopped 2022-08-18T21:32:04.212Z,1660858324.212 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-18T21:32:04.213Z,1660858324.213 [Default:CheckIn:D] Running Loop=1 2022-08-18T21:32:04.625Z,1660858324.625 [Default:CheckIn:D] Stopped 2022-08-18T21:32:04.625Z,1660858324.625 [Default:CheckIn:E] Running Loop=1 2022-08-18T21:32:05.023Z,1660858325.023 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 40.423564 min 2022-08-18T21:32:05.023Z,1660858325.023 [Default:CheckIn:E] Stopped 2022-08-18T21:32:05.023Z,1660858325.023 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-18T21:32:05.023Z,1660858325.023 [Default:CheckIn] Stopped 2022-08-18T21:32:05.023Z,1660858325.023 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-18T21:32:05.023Z,1660858325.023 [Default:CheckIn](INFO): Running loop #6 2022-08-18T21:32:05.040Z,1660858325.040 [Default:CheckIn] Running Loop=6 2022-08-18T21:32:05.040Z,1660858325.040 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-18T21:32:05.040Z,1660858325.040 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-18T21:32:07.095Z,1660858327.095 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,213205.00,A,3647.68664,N,12149.10753,W,0.816,84.56,180822,,,D*4C 2022-08-18T21:32:07.097Z,1660858327.097 [NAL9602](INFO): GPS fix at 20220818T213205: (36.794777, -121.818459) 2022-08-18T21:32:07.128Z,1660858327.128 [Default:CheckIn:Read_GPS] Stopped 2022-08-18T21:32:07.128Z,1660858327.128 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-18T21:32:07.429Z,1660858327.429 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-08-18T21:32:14.095Z,1660858334.095 [DataOverHttps](INFO): Sending 224 bytes from file Logs/20220818T212349/Courier0003.lzma 2022-08-18T21:32:15.098Z,1660858335.098 [DataOverHttps](INFO): Moved sent file to Logs/20220818T212349/Courier0003.lzma.bak 2022-08-18T21:32:15.098Z,1660858335.098 [DataOverHttps](INFO): SBD MOMSN=17112777 2022-08-18T21:32:23.630Z,1660858343.630 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-08-18T21:32:37.780Z,1660858357.780 [NAL9602](INFO): SBD MO Status=2, MOMSN=36012, MT Status=2, MTMSN=0 2022-08-18T21:32:37.780Z,1660858357.780 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-08-18T21:32:38.578Z,1660858358.578 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-08-18T21:32:53.527Z,1660858373.527 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-08-18T21:32:56.766Z,1660858376.766 [NAL9602](INFO): SBD MO Status=0, MOMSN=36012, MT Status=0, MTMSN=0 2022-08-18T21:32:56.767Z,1660858376.767 [NAL9602](INFO): No messages in MT queue 2022-08-18T21:33:08.480Z,1660858388.480 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-08-18T21:33:17.372Z,1660858397.372 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-08-18T21:33:23.422Z,1660858403.422 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-08-18T21:33:27.493Z,1660858407.493 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-18T21:33:38.774Z,1660858418.774 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-08-18T21:33:48.500Z,1660858428.500 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-08-18T21:34:00.193Z,1660858440.193 [BPC1](INFO): Calculating totals. Valid battery stick count: 54. Valid reserve battery stick count: 6. 2022-08-18T21:34:00.196Z,1660858440.196 [BPC1](INFO): Received data from all battery sticks. 2022-08-18T21:34:04.708Z,1660858444.708 [DataOverHttps](INFO): Sending 207 bytes from file Logs/20220818T212349/Express0004.lzma 2022-08-18T21:34:05.710Z,1660858445.710 [DataOverHttps](INFO): Moved sent file to Logs/20220818T212349/Express0004.lzma.bak 2022-08-18T21:34:05.710Z,1660858445.710 [DataOverHttps](INFO): SBD MOMSN=17112780 2022-08-18T21:34:07.075Z,1660858447.075 [Default:CheckIn:Read_Iridium] Stopped 2022-08-18T21:34:07.075Z,1660858447.075 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-18T21:34:07.075Z,1660858447.075 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-18T21:35:37.705Z,1660858537.705 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-08-18T21:39:07.665Z,1660858747.665 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-18T21:39:07.665Z,1660858747.665 [Default:CheckIn:C.Wait] Stopped 2022-08-18T21:39:07.665Z,1660858747.665 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-18T21:39:07.666Z,1660858747.666 [Default:CheckIn:D] Running Loop=1 2022-08-18T21:39:08.098Z,1660858748.098 [Default:CheckIn:D] Stopped 2022-08-18T21:39:08.098Z,1660858748.098 [Default:CheckIn:E] Running Loop=1 2022-08-18T21:39:08.473Z,1660858748.473 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 47.481453 min 2022-08-18T21:39:08.473Z,1660858748.473 [Default:CheckIn:E] Stopped 2022-08-18T21:39:08.473Z,1660858748.473 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-18T21:39:08.474Z,1660858748.474 [Default:CheckIn] Stopped 2022-08-18T21:39:08.474Z,1660858748.474 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-18T21:39:08.474Z,1660858748.474 [Default:CheckIn](INFO): Running loop #7 2022-08-18T21:39:08.474Z,1660858748.474 [Default:CheckIn] Running Loop=7 2022-08-18T21:39:08.474Z,1660858748.474 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-18T21:39:08.474Z,1660858748.474 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-18T21:39:10.475Z,1660858750.475 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,213908.00,A,3647.73242,N,12149.00108,W,3.499,304.92,180822,,,A*77 2022-08-18T21:39:10.477Z,1660858750.477 [NAL9602](INFO): GPS fix at 20220818T213908: (36.795540, -121.816685) 2022-08-18T21:39:10.510Z,1660858750.510 [Default:CheckIn:Read_GPS] Stopped 2022-08-18T21:39:10.510Z,1660858750.510 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-18T21:39:17.668Z,1660858757.668 [DataOverHttps](INFO): Sending 201 bytes from file Logs/20220818T212349/Courier0006.lzma 2022-08-18T21:39:18.670Z,1660858758.670 [DataOverHttps](INFO): Moved sent file to Logs/20220818T212349/Courier0006.lzma.bak 2022-08-18T21:39:18.670Z,1660858758.670 [DataOverHttps](INFO): SBD MOMSN=17112784 2022-08-18T21:39:36.940Z,1660858776.940 [DataOverHttps](INFO): Sending 168 bytes from file Logs/20220818T212349/Express0007.lzma 2022-08-18T21:39:37.941Z,1660858777.941 [DataOverHttps](INFO): Moved sent file to Logs/20220818T212349/Express0007.lzma.bak 2022-08-18T21:39:37.942Z,1660858777.942 [DataOverHttps](INFO): SBD MOMSN=17112787 2022-08-18T21:39:39.223Z,1660858779.223 [Default:CheckIn:Read_Iridium] Stopped 2022-08-18T21:39:39.223Z,1660858779.223 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-18T21:39:39.223Z,1660858779.223 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-18T21:39:41.638Z,1660858781.638 [NAL9602](INFO): SBD MO Status=2, MOMSN=36013, MT Status=2, MTMSN=0 2022-08-18T21:39:41.639Z,1660858781.639 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-08-18T21:40:08.707Z,1660858808.707 [NAL9602](INFO): SBD MO Status=0, MOMSN=36013, MT Status=0, MTMSN=0 2022-08-18T21:40:08.707Z,1660858808.707 [NAL9602](INFO): No messages in MT queue 2022-08-18T21:40:39.407Z,1660858839.407 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-18T21:41:40.268Z,1660858900.268 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-08-18T21:42:41.798Z,1660858961.798 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-08-18T21:43:12.952Z,1660858992.952 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-08-18T21:44:39.845Z,1660859079.845 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-18T21:44:39.845Z,1660859079.845 [Default:CheckIn:C.Wait] Stopped 2022-08-18T21:44:39.846Z,1660859079.846 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-18T21:44:39.846Z,1660859079.846 [Default:CheckIn:D] Running Loop=1 2022-08-18T21:44:40.265Z,1660859080.265 [Default:CheckIn:D] Stopped 2022-08-18T21:44:40.265Z,1660859080.265 [Default:CheckIn:E] Running Loop=1 2022-08-18T21:44:40.654Z,1660859080.654 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 53.017558 min 2022-08-18T21:44:40.654Z,1660859080.654 [Default:CheckIn:E] Stopped 2022-08-18T21:44:40.654Z,1660859080.654 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-18T21:44:40.654Z,1660859080.654 [Default:CheckIn] Stopped 2022-08-18T21:44:40.654Z,1660859080.654 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-18T21:44:40.655Z,1660859080.655 [Default:CheckIn](INFO): Running loop #8 2022-08-18T21:44:40.655Z,1660859080.655 [Default:CheckIn] Running Loop=8 2022-08-18T21:44:40.655Z,1660859080.655 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-18T21:44:40.655Z,1660859080.655 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-18T21:44:42.671Z,1660859082.671 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,214440.00,A,3647.75526,N,12148.99080,W,0.428,91.04,180822,,,D*4E 2022-08-18T21:44:42.673Z,1660859082.673 [NAL9602](INFO): GPS fix at 20220818T214440: (36.795921, -121.816513) 2022-08-18T21:44:42.683Z,1660859082.683 [Default:CheckIn:Read_GPS] Stopped 2022-08-18T21:44:42.683Z,1660859082.683 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-18T21:44:50.236Z,1660859090.236 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220818T212349/Courier0009.lzma 2022-08-18T21:44:51.238Z,1660859091.238 [DataOverHttps](INFO): Moved sent file to Logs/20220818T212349/Courier0009.lzma.bak 2022-08-18T21:44:51.238Z,1660859091.238 [DataOverHttps](INFO): SBD MOMSN=17112798 2022-08-18T21:45:03.722Z,1660859103.722 [NAL9602](INFO): SBD MO Status=2, MOMSN=36014, MT Status=2, MTMSN=0 2022-08-18T21:45:03.723Z,1660859103.723 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-08-18T21:45:09.752Z,1660859109.752 [DataOverHttps](INFO): Sending 162 bytes from file Logs/20220818T212349/Express0010.lzma 2022-08-18T21:45:10.754Z,1660859110.754 [DataOverHttps](INFO): Moved sent file to Logs/20220818T212349/Express0010.lzma.bak 2022-08-18T21:45:10.754Z,1660859110.754 [DataOverHttps](INFO): SBD MOMSN=17112801 2022-08-18T21:45:12.225Z,1660859112.225 [Default:CheckIn:Read_Iridium] Stopped 2022-08-18T21:45:12.225Z,1660859112.225 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-18T21:45:12.225Z,1660859112.225 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-18T21:45:22.321Z,1660859122.321 [NAL9602](INFO): SBD MO Status=2, MOMSN=36014, MT Status=2, MTMSN=0 2022-08-18T21:45:22.321Z,1660859122.321 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-08-18T21:45:43.318Z,1660859143.318 [NAL9602](INFO): SBD MO Status=2, MOMSN=36014, MT Status=2, MTMSN=0 2022-08-18T21:45:43.318Z,1660859143.318 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-08-18T21:46:12.022Z,1660859172.022 [NAL9602](INFO): SBD MO Status=2, MOMSN=36014, MT Status=2, MTMSN=0 2022-08-18T21:46:12.023Z,1660859172.023 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-08-18T21:48:30.221Z,1660859310.221 [NAL9602](INFO): SBD MO Status=0, MOMSN=36014, MT Status=0, MTMSN=0 2022-08-18T21:48:30.221Z,1660859310.221 [NAL9602](INFO): No messages in MT queue 2022-08-18T21:49:00.965Z,1660859340.965 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-18T21:50:12.901Z,1660859412.901 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-18T21:50:12.902Z,1660859412.902 [Default:CheckIn:C.Wait] Stopped 2022-08-18T21:50:12.902Z,1660859412.902 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-18T21:50:12.902Z,1660859412.902 [Default:CheckIn:D] Running Loop=1 2022-08-18T21:50:13.291Z,1660859413.291 [Default:CheckIn:D] Stopped 2022-08-18T21:50:13.291Z,1660859413.291 [Default:CheckIn:E] Running Loop=1 2022-08-18T21:50:13.695Z,1660859413.695 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 58.568001 min 2022-08-18T21:50:13.695Z,1660859413.695 [Default:CheckIn:E] Stopped 2022-08-18T21:50:13.695Z,1660859413.695 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-18T21:50:13.695Z,1660859413.695 [Default:CheckIn] Stopped 2022-08-18T21:50:13.695Z,1660859413.695 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-18T21:50:13.695Z,1660859413.695 [Default:CheckIn](INFO): Running loop #9 2022-08-18T21:50:13.695Z,1660859413.695 [Default:CheckIn] Running Loop=9 2022-08-18T21:50:13.696Z,1660859413.696 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-18T21:50:13.696Z,1660859413.696 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-18T21:50:15.703Z,1660859415.703 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,215013.00,A,3647.77577,N,12149.02884,W,4.801,268.04,180822,,,D*73 2022-08-18T21:50:15.705Z,1660859415.705 [NAL9602](INFO): GPS fix at 20220818T215013: (36.796263, -121.817147) 2022-08-18T21:50:15.716Z,1660859415.716 [Default:CheckIn:Read_GPS] Stopped 2022-08-18T21:50:15.716Z,1660859415.716 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-18T21:50:25.759Z,1660859425.759 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220818T212349/Courier0012.lzma 2022-08-18T21:50:26.762Z,1660859426.762 [DataOverHttps](INFO): Moved sent file to Logs/20220818T212349/Courier0012.lzma.bak 2022-08-18T21:50:26.762Z,1660859426.762 [DataOverHttps](INFO): SBD MOMSN=17112804 2022-08-18T21:50:32.730Z,1660859432.730 [NAL9602](INFO): SBD MO Status=0, MOMSN=36015, MT Status=0, MTMSN=0 2022-08-18T21:50:32.731Z,1660859432.731 [NAL9602](INFO): No messages in MT queue 2022-08-18T21:50:43.080Z,1660859443.080 [DataOverHttps](INFO): Sending 178 bytes from file Logs/20220818T212349/Express0013.lzma 2022-08-18T21:50:44.082Z,1660859444.082 [DataOverHttps](INFO): Moved sent file to Logs/20220818T212349/Express0013.lzma.bak 2022-08-18T21:50:44.082Z,1660859444.082 [DataOverHttps](INFO): SBD MOMSN=17112807 2022-08-18T21:50:45.268Z,1660859445.268 [Default:CheckIn:Read_Iridium] Stopped 2022-08-18T21:50:45.268Z,1660859445.268 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-18T21:50:45.268Z,1660859445.268 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-18T21:51:03.437Z,1660859463.437 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-18T21:55:46.031Z,1660859746.031 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-18T21:55:46.031Z,1660859746.031 [Default:CheckIn:C.Wait] Stopped 2022-08-18T21:55:46.031Z,1660859746.031 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-18T21:55:46.031Z,1660859746.031 [Default:CheckIn:D] Running Loop=1 2022-08-18T21:55:46.431Z,1660859746.431 [Default:CheckIn:D] Stopped 2022-08-18T21:55:46.431Z,1660859746.431 [Default:CheckIn:E] Running Loop=1 2022-08-18T21:55:46.848Z,1660859746.848 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 64.120333 min 2022-08-18T21:55:46.848Z,1660859746.848 [Default:CheckIn:E] Stopped 2022-08-18T21:55:46.848Z,1660859746.848 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-18T21:55:46.848Z,1660859746.848 [Default:CheckIn] Stopped 2022-08-18T21:55:46.849Z,1660859746.849 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-18T21:55:46.849Z,1660859746.849 [Default:CheckIn](INFO): Running loop #10 2022-08-18T21:55:46.849Z,1660859746.849 [Default:CheckIn] Running Loop=10 2022-08-18T21:55:46.849Z,1660859746.849 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-18T21:55:46.849Z,1660859746.849 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-18T21:55:48.847Z,1660859748.847 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,215547.00,A,3647.76509,N,12149.10177,W,2.527,234.50,180822,,,D*7E 2022-08-18T21:55:48.849Z,1660859748.849 [NAL9602](INFO): GPS fix at 20220818T215547: (36.796085, -121.818363) 2022-08-18T21:55:48.859Z,1660859748.859 [Default:CheckIn:Read_GPS] Stopped 2022-08-18T21:55:48.859Z,1660859748.859 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-18T21:55:55.779Z,1660859755.779 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220818T212349/Courier0015.lzma 2022-08-18T21:55:56.782Z,1660859756.782 [DataOverHttps](INFO): Moved sent file to Logs/20220818T212349/Courier0015.lzma.bak 2022-08-18T21:55:56.782Z,1660859756.782 [DataOverHttps](INFO): SBD MOMSN=17112818 2022-08-18T21:56:12.551Z,1660859772.551 [DataOverHttps](INFO): Sending 159 bytes from file Logs/20220818T212349/Express0016.lzma 2022-08-18T21:56:13.554Z,1660859773.554 [DataOverHttps](INFO): Moved sent file to Logs/20220818T212349/Express0016.lzma.bak 2022-08-18T21:56:13.554Z,1660859773.554 [DataOverHttps](INFO): SBD MOMSN=17112821 2022-08-18T21:56:14.721Z,1660859774.721 [Default:CheckIn:Read_Iridium] Stopped 2022-08-18T21:56:14.721Z,1660859774.721 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-18T21:56:14.721Z,1660859774.721 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-18T21:56:34.519Z,1660859794.519 [NAL9602](INFO): SBD MO Status=0, MOMSN=36016, MT Status=0, MTMSN=0 2022-08-18T21:56:34.519Z,1660859794.519 [NAL9602](INFO): No messages in MT queue 2022-08-18T21:56:45.516Z,1660859805.516 [DataOverHttps](INFO): Exceeded connection timeout, disconnecting. 2022-08-18T21:57:05.221Z,1660859825.221 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-18T22:00:51.580Z,1660860051.580 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-08-18T22:01:15.469Z,1660860075.469 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-18T22:01:15.469Z,1660860075.469 [Default:CheckIn:C.Wait] Stopped 2022-08-18T22:01:15.469Z,1660860075.469 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-18T22:01:15.469Z,1660860075.469 [Default:CheckIn:D] Running Loop=1 2022-08-18T22:01:15.872Z,1660860075.872 [Default:CheckIn:D] Stopped 2022-08-18T22:01:15.872Z,1660860075.872 [Default:CheckIn:E] Running Loop=1 2022-08-18T22:01:16.278Z,1660860076.278 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 69.611011 min 2022-08-18T22:01:16.278Z,1660860076.278 [Default:CheckIn:E] Stopped 2022-08-18T22:01:16.279Z,1660860076.279 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-18T22:01:16.279Z,1660860076.279 [Default:CheckIn] Stopped 2022-08-18T22:01:16.279Z,1660860076.279 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-18T22:01:16.279Z,1660860076.279 [Default:CheckIn](INFO): Running loop #11 2022-08-18T22:01:16.279Z,1660860076.279 [Default:CheckIn] Running Loop=11 2022-08-18T22:01:16.279Z,1660860076.279 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-18T22:01:16.279Z,1660860076.279 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-18T22:01:18.291Z,1660860078.291 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,220116.00,A,3647.81530,N,12148.86473,W,7.173,73.96,180822,,,D*4E 2022-08-18T22:01:18.303Z,1660860078.303 [NAL9602](INFO): GPS fix at 20220818T220116: (36.796922, -121.814412) 2022-08-18T22:01:18.313Z,1660860078.313 [Default:CheckIn:Read_GPS] Stopped 2022-08-18T22:01:18.313Z,1660860078.313 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-18T22:01:22.724Z,1660860082.724 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-08-18T22:01:51.219Z,1660860111.219 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220818T212349/Courier0018.lzma 2022-08-18T22:01:52.222Z,1660860112.222 [DataOverHttps](INFO): Moved sent file to Logs/20220818T212349/Courier0018.lzma.bak 2022-08-18T22:01:52.222Z,1660860112.222 [DataOverHttps](INFO): SBD MOMSN=17112825 2022-08-18T22:02:08.012Z,1660860128.012 [DataOverHttps](INFO): Sending 160 bytes from file Logs/20220818T212349/Express0019.lzma 2022-08-18T22:02:09.014Z,1660860129.014 [DataOverHttps](INFO): Moved sent file to Logs/20220818T212349/Express0019.lzma.bak 2022-08-18T22:02:09.014Z,1660860129.014 [DataOverHttps](INFO): SBD MOMSN=17112828 2022-08-18T22:02:10.414Z,1660860130.414 [Default:CheckIn:Read_Iridium] Stopped 2022-08-18T22:02:10.414Z,1660860130.414 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-18T22:02:10.414Z,1660860130.414 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-18T22:02:58.477Z,1660860178.477 [NAL9602](INFO): SBD MO Status=0, MOMSN=36017, MT Status=0, MTMSN=0 2022-08-18T22:02:58.477Z,1660860178.477 [NAL9602](INFO): No messages in MT queue 2022-08-18T22:03:29.185Z,1660860209.185 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-18T22:07:11.051Z,1660860431.051 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-18T22:07:11.051Z,1660860431.051 [Default:CheckIn:C.Wait] Stopped 2022-08-18T22:07:11.051Z,1660860431.051 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-18T22:07:11.051Z,1660860431.051 [Default:CheckIn:D] Running Loop=1 2022-08-18T22:07:11.445Z,1660860431.445 [Default:CheckIn:D] Stopped 2022-08-18T22:07:11.445Z,1660860431.445 [Default:CheckIn:E] Running Loop=1 2022-08-18T22:07:11.855Z,1660860431.855 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 75.537223 min 2022-08-18T22:07:11.855Z,1660860431.855 [Default:CheckIn:E] Stopped 2022-08-18T22:07:11.855Z,1660860431.855 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-18T22:07:11.855Z,1660860431.855 [Default:CheckIn] Stopped 2022-08-18T22:07:11.855Z,1660860431.855 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-18T22:07:11.856Z,1660860431.856 [Default:CheckIn](INFO): Running loop #12 2022-08-18T22:07:11.856Z,1660860431.856 [Default:CheckIn] Running Loop=12 2022-08-18T22:07:11.856Z,1660860431.856 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-18T22:07:11.856Z,1660860431.856 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-18T22:07:13.871Z,1660860433.871 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,220712.00,A,3648.41957,N,12147.36905,W,10.341,43.74,180822,,,D*70 2022-08-18T22:07:13.873Z,1660860433.873 [NAL9602](INFO): GPS fix at 20220818T220712: (36.806993, -121.789484) 2022-08-18T22:07:13.883Z,1660860433.883 [Default:CheckIn:Read_GPS] Stopped 2022-08-18T22:07:13.883Z,1660860433.883 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-18T22:07:21.711Z,1660860441.711 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220818T212349/Courier0021.lzma 2022-08-18T22:07:22.714Z,1660860442.714 [DataOverHttps](INFO): Moved sent file to Logs/20220818T212349/Courier0021.lzma.bak 2022-08-18T22:07:22.714Z,1660860442.714 [DataOverHttps](INFO): SBD MOMSN=17112844 2022-08-18T22:07:37.703Z,1660860457.703 [NAL9602](INFO): SBD MO Status=2, MOMSN=36018, MT Status=2, MTMSN=0 2022-08-18T22:07:37.703Z,1660860457.703 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-08-18T22:07:38.511Z,1660860458.511 [DataOverHttps](INFO): Sending 165 bytes from file Logs/20220818T212349/Express0022.lzma 2022-08-18T22:07:39.514Z,1660860459.514 [DataOverHttps](INFO): Moved sent file to Logs/20220818T212349/Express0022.lzma.bak 2022-08-18T22:07:39.514Z,1660860459.514 [DataOverHttps](INFO): SBD MOMSN=17112847 2022-08-18T22:07:40.940Z,1660860460.940 [Default:CheckIn:Read_Iridium] Stopped 2022-08-18T22:07:40.940Z,1660860460.940 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-18T22:07:40.940Z,1660860460.940 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-18T22:08:12.846Z,1660860492.846 [NAL9602](INFO): SBD MO Status=0, MOMSN=36018, MT Status=0, MTMSN=0 2022-08-18T22:08:12.847Z,1660860492.847 [NAL9602](INFO): No messages in MT queue 2022-08-18T22:08:43.555Z,1660860523.555 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-18T22:12:41.630Z,1660860761.630 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-18T22:12:41.630Z,1660860761.630 [Default:CheckIn:C.Wait] Stopped 2022-08-18T22:12:41.630Z,1660860761.630 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-18T22:12:41.631Z,1660860761.631 [Default:CheckIn:D] Running Loop=1 2022-08-18T22:12:42.037Z,1660860762.037 [Default:CheckIn:D] Stopped 2022-08-18T22:12:42.037Z,1660860762.037 [Default:CheckIn:E] Running Loop=1 2022-08-18T22:12:42.451Z,1660860762.451 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 81.047087 min 2022-08-18T22:12:42.451Z,1660860762.451 [Default:CheckIn:E] Stopped 2022-08-18T22:12:42.451Z,1660860762.451 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-18T22:12:42.451Z,1660860762.451 [Default:CheckIn] Stopped 2022-08-18T22:12:42.451Z,1660860762.451 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-18T22:12:42.451Z,1660860762.451 [Default:CheckIn](INFO): Running loop #13 2022-08-18T22:12:42.451Z,1660860762.451 [Default:CheckIn] Running Loop=13 2022-08-18T22:12:42.451Z,1660860762.451 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-18T22:12:42.451Z,1660860762.451 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-18T22:12:44.444Z,1660860764.444 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,221242.00,A,3648.16536,N,12147.19458,W,2.896,246.79,180822,,,D*78 2022-08-18T22:12:44.447Z,1660860764.447 [NAL9602](INFO): GPS fix at 20220818T221242: (36.802756, -121.786576) 2022-08-18T22:12:44.457Z,1660860764.457 [Default:CheckIn:Read_GPS] Stopped 2022-08-18T22:12:44.457Z,1660860764.457 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-18T22:12:54.247Z,1660860774.247 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20220818T212349/Courier0024.lzma 2022-08-18T22:12:55.250Z,1660860775.250 [DataOverHttps](INFO): Moved sent file to Logs/20220818T212349/Courier0024.lzma.bak 2022-08-18T22:12:55.250Z,1660860775.250 [DataOverHttps](INFO): SBD MOMSN=17112851 2022-08-18T22:13:11.728Z,1660860791.728 [DataOverHttps](INFO): Sending 178 bytes from file Logs/20220818T212349/Express0025.lzma 2022-08-18T22:13:12.730Z,1660860792.730 [DataOverHttps](INFO): Moved sent file to Logs/20220818T212349/Express0025.lzma.bak 2022-08-18T22:13:12.730Z,1660860792.730 [DataOverHttps](INFO): SBD MOMSN=17112854 2022-08-18T22:13:14.036Z,1660860794.036 [Default:CheckIn:Read_Iridium] Stopped 2022-08-18T22:13:14.036Z,1660860794.036 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-18T22:13:14.036Z,1660860794.036 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-18T22:15:00.302Z,1660860900.302 [NAL9602](INFO): SBD MO Status=2, MOMSN=36019, MT Status=0, MTMSN=0 2022-08-18T22:15:00.303Z,1660860900.303 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-08-18T22:15:20.903Z,1660860920.903 [NAL9602](INFO): SBD MO Status=0, MOMSN=36019, MT Status=0, MTMSN=0 2022-08-18T22:15:20.903Z,1660860920.903 [NAL9602](INFO): No messages in MT queue 2022-08-18T22:15:51.605Z,1660860951.605 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-18T22:18:14.738Z,1660861094.738 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-18T22:18:14.738Z,1660861094.738 [Default:CheckIn:C.Wait] Stopped 2022-08-18T22:18:14.738Z,1660861094.738 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-18T22:18:14.739Z,1660861094.739 [Default:CheckIn:D] Running Loop=1 2022-08-18T22:18:15.145Z,1660861095.145 [Default:CheckIn:D] Stopped 2022-08-18T22:18:15.145Z,1660861095.145 [Default:CheckIn:E] Running Loop=1 2022-08-18T22:18:15.561Z,1660861095.561 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 86.598885 min 2022-08-18T22:18:15.561Z,1660861095.561 [Default:CheckIn:E] Stopped 2022-08-18T22:18:15.561Z,1660861095.561 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-18T22:18:15.561Z,1660861095.561 [Default:CheckIn] Stopped 2022-08-18T22:18:15.561Z,1660861095.561 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-18T22:18:15.562Z,1660861095.562 [Default:CheckIn](INFO): Running loop #14 2022-08-18T22:18:15.562Z,1660861095.562 [Default:CheckIn] Running Loop=14 2022-08-18T22:18:15.562Z,1660861095.562 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-18T22:18:15.562Z,1660861095.562 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-18T22:18:17.555Z,1660861097.555 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,221815.00,A,3648.14708,N,12147.22212,W,0.194,207.72,180822,,,D*7A 2022-08-18T22:18:17.557Z,1660861097.557 [NAL9602](INFO): GPS fix at 20220818T221815: (36.802451, -121.787035) 2022-08-18T22:18:17.573Z,1660861097.573 [Default:CheckIn:Read_GPS] Stopped 2022-08-18T22:18:17.573Z,1660861097.573 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-18T22:18:27.771Z,1660861107.771 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220818T212349/Courier0027.lzma 2022-08-18T22:18:28.774Z,1660861108.774 [DataOverHttps](INFO): Moved sent file to Logs/20220818T212349/Courier0027.lzma.bak 2022-08-18T22:18:28.774Z,1660861108.774 [DataOverHttps](INFO): SBD MOMSN=17112866 2022-08-18T22:18:44.591Z,1660861124.591 [DataOverHttps](INFO): Sending 167 bytes from file Logs/20220818T212349/Express0028.lzma 2022-08-18T22:18:45.594Z,1660861125.594 [DataOverHttps](INFO): Moved sent file to Logs/20220818T212349/Express0028.lzma.bak 2022-08-18T22:18:45.594Z,1660861125.594 [DataOverHttps](INFO): SBD MOMSN=17112869 2022-08-18T22:18:46.709Z,1660861126.709 [Default:CheckIn:Read_Iridium] Stopped 2022-08-18T22:18:46.709Z,1660861126.709 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-18T22:18:46.709Z,1660861126.709 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-18T22:18:54.443Z,1660861134.443 [NAL9602](INFO): SBD MO Status=2, MOMSN=36020, MT Status=2, MTMSN=0 2022-08-18T22:18:54.443Z,1660861134.443 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-08-18T22:23:19.265Z,1660861399.265 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-08-18T22:23:47.148Z,1660861427.148 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-18T22:23:47.148Z,1660861427.148 [Default:CheckIn:C.Wait] Stopped 2022-08-18T22:23:47.149Z,1660861427.149 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-18T22:23:47.149Z,1660861427.149 [Default:CheckIn:D] Running Loop=1 2022-08-18T22:23:47.555Z,1660861427.555 [Default:CheckIn:D] Stopped 2022-08-18T22:23:47.555Z,1660861427.555 [Default:CheckIn:E] Running Loop=1 2022-08-18T22:23:47.963Z,1660861427.963 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 92.139054 min 2022-08-18T22:23:47.963Z,1660861427.963 [Default:CheckIn:E] Stopped 2022-08-18T22:23:47.963Z,1660861427.963 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-18T22:23:47.964Z,1660861427.964 [Default:CheckIn] Stopped 2022-08-18T22:23:47.964Z,1660861427.964 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-18T22:23:47.964Z,1660861427.964 [Default:CheckIn](INFO): Running loop #15 2022-08-18T22:23:47.964Z,1660861427.964 [Default:CheckIn] Running Loop=15 2022-08-18T22:23:47.964Z,1660861427.964 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-18T22:23:47.964Z,1660861427.964 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-18T22:23:49.971Z,1660861429.971 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,222348.00,A,3648.13855,N,12147.25106,W,0.622,227.10,180822,,,D*77 2022-08-18T22:23:49.973Z,1660861429.973 [NAL9602](INFO): GPS fix at 20220818T222348: (36.802309, -121.787518) 2022-08-18T22:23:49.984Z,1660861429.984 [Default:CheckIn:Read_GPS] Stopped 2022-08-18T22:23:49.984Z,1660861429.984 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-18T22:23:57.771Z,1660861437.771 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220818T212349/Courier0030.lzma 2022-08-18T22:23:58.774Z,1660861438.774 [DataOverHttps](INFO): Moved sent file to Logs/20220818T212349/Courier0030.lzma.bak 2022-08-18T22:23:58.774Z,1660861438.774 [DataOverHttps](INFO): SBD MOMSN=17112872 2022-08-18T22:24:14.596Z,1660861454.596 [DataOverHttps](INFO): Sending 261 bytes from file Logs/20220818T212349/Express0031.lzma 2022-08-18T22:24:15.598Z,1660861455.598 [DataOverHttps](INFO): Moved sent file to Logs/20220818T212349/Express0031.lzma.bak 2022-08-18T22:24:15.598Z,1660861455.598 [DataOverHttps](INFO): SBD MOMSN=17112875 2022-08-18T22:24:17.057Z,1660861457.057 [Default:CheckIn:Read_Iridium] Stopped 2022-08-18T22:24:17.057Z,1660861457.057 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-18T22:24:17.057Z,1660861457.057 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-18T22:24:22.741Z,1660861462.741 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-18T22:29:17.558Z,1660861757.558 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-18T22:29:17.558Z,1660861757.558 [Default:CheckIn:C.Wait] Stopped 2022-08-18T22:29:17.558Z,1660861757.558 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-18T22:29:17.558Z,1660861757.558 [Default:CheckIn:D] Running Loop=1 2022-08-18T22:29:17.954Z,1660861757.954 [Default:CheckIn:D] Stopped 2022-08-18T22:29:17.954Z,1660861757.954 [Default:CheckIn:E] Running Loop=1 2022-08-18T22:29:18.353Z,1660861758.353 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 97.645719 min 2022-08-18T22:29:18.354Z,1660861758.354 [Default:CheckIn:E] Stopped 2022-08-18T22:29:18.354Z,1660861758.354 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-18T22:29:18.354Z,1660861758.354 [Default:CheckIn] Stopped 2022-08-18T22:29:18.354Z,1660861758.354 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-18T22:29:18.354Z,1660861758.354 [Default:CheckIn](INFO): Running loop #16 2022-08-18T22:29:18.354Z,1660861758.354 [Default:CheckIn] Running Loop=16 2022-08-18T22:29:18.354Z,1660861758.354 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-18T22:29:18.354Z,1660861758.354 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-18T22:29:20.367Z,1660861760.367 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,222918.00,A,3648.14183,N,12147.25533,W,0.330,176.68,180822,,,D*71 2022-08-18T22:29:20.369Z,1660861760.369 [NAL9602](INFO): GPS fix at 20220818T222918: (36.802364, -121.787589) 2022-08-18T22:29:20.380Z,1660861760.380 [Default:CheckIn:Read_GPS] Stopped 2022-08-18T22:29:20.380Z,1660861760.380 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-18T22:29:28.187Z,1660861768.187 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220818T212349/Courier0033.lzma 2022-08-18T22:29:29.190Z,1660861769.190 [DataOverHttps](INFO): Moved sent file to Logs/20220818T212349/Courier0033.lzma.bak 2022-08-18T22:29:29.190Z,1660861769.190 [DataOverHttps](INFO): SBD MOMSN=17112886 2022-08-18T22:29:45.011Z,1660861785.011 [DataOverHttps](INFO): Sending 140 bytes from file Logs/20220818T212349/Express0034.lzma 2022-08-18T22:29:46.014Z,1660861786.014 [DataOverHttps](INFO): Moved sent file to Logs/20220818T212349/Express0034.lzma.bak 2022-08-18T22:29:46.014Z,1660861786.014 [DataOverHttps](INFO): SBD MOMSN=17112889 2022-08-18T22:29:47.450Z,1660861787.450 [Default:CheckIn:Read_Iridium] Stopped 2022-08-18T22:29:47.450Z,1660861787.450 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-18T22:29:47.450Z,1660861787.450 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-18T22:29:51.093Z,1660861791.093 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2022-08-18T22:29:51.172Z,1660861791.172 [NAL9602](ERROR): received: +CSQ:0 OK020, 2, 0, 0, 0 OK 2022-08-18T22:32:26.015Z,1660861946.015 [NAL9602](INFO): SBD MO Status=0, MOMSN=36020, MT Status=0, MTMSN=0 2022-08-18T22:32:26.015Z,1660861946.015 [NAL9602](INFO): No messages in MT queue 2022-08-18T22:32:56.773Z,1660861976.773 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-18T22:34:47.978Z,1660862087.978 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-18T22:34:47.978Z,1660862087.978 [Default:CheckIn:C.Wait] Stopped 2022-08-18T22:34:47.978Z,1660862087.978 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-18T22:34:47.978Z,1660862087.978 [Default:CheckIn:D] Running Loop=1 2022-08-18T22:34:48.341Z,1660862088.341 [Default:CheckIn:D] Stopped 2022-08-18T22:34:48.342Z,1660862088.342 [Default:CheckIn:E] Running Loop=1 2022-08-18T22:34:48.747Z,1660862088.747 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 103.152173 min 2022-08-18T22:34:48.747Z,1660862088.747 [Default:CheckIn:E] Stopped 2022-08-18T22:34:48.748Z,1660862088.748 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-18T22:34:48.748Z,1660862088.748 [Default:CheckIn] Stopped 2022-08-18T22:34:48.748Z,1660862088.748 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-18T22:34:48.748Z,1660862088.748 [Default:CheckIn](INFO): Running loop #17 2022-08-18T22:34:48.748Z,1660862088.748 [Default:CheckIn] Running Loop=17 2022-08-18T22:34:48.748Z,1660862088.748 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-18T22:34:48.749Z,1660862088.749 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-18T22:34:50.751Z,1660862090.751 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,223448.00,A,3648.14092,N,12147.25262,W,0.078,176.68,180822,,,D*75 2022-08-18T22:34:50.753Z,1660862090.753 [NAL9602](INFO): GPS fix at 20220818T223448: (36.802349, -121.787544) 2022-08-18T22:34:50.800Z,1660862090.800 [Default:CheckIn:Read_GPS] Stopped 2022-08-18T22:34:50.800Z,1660862090.800 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-18T22:35:00.194Z,1660862100.194 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220818T212349/Courier0036.lzma 2022-08-18T22:35:01.190Z,1660862101.190 [DataOverHttps](INFO): Moved sent file to Logs/20220818T212349/Courier0036.lzma.bak 2022-08-18T22:35:01.190Z,1660862101.190 [DataOverHttps](INFO): SBD MOMSN=17112893 2022-08-18T22:35:03.746Z,1660862103.746 [NAL9602](INFO): SBD MO Status=0, MOMSN=36021, MT Status=0, MTMSN=0 2022-08-18T22:35:03.747Z,1660862103.747 [NAL9602](INFO): No messages in MT queue 2022-08-18T22:35:17.104Z,1660862117.104 [DataOverHttps](INFO): Sending 145 bytes from file Logs/20220818T212349/Express0037.lzma 2022-08-18T22:35:18.106Z,1660862118.106 [DataOverHttps](INFO): Moved sent file to Logs/20220818T212349/Express0037.lzma.bak 2022-08-18T22:35:18.106Z,1660862118.106 [DataOverHttps](INFO): SBD MOMSN=17112896 2022-08-18T22:35:19.519Z,1660862119.519 [Default:CheckIn:Read_Iridium] Stopped 2022-08-18T22:35:19.519Z,1660862119.519 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-18T22:35:19.519Z,1660862119.519 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-18T22:35:34.508Z,1660862134.508 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-18T22:38:56.958Z,1660862336.958 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-08-18T22:39:11.906Z,1660862351.906 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-08-18T22:39:26.853Z,1660862366.853 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-08-18T22:39:41.802Z,1660862381.802 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-08-18T22:39:56.750Z,1660862396.750 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-08-18T22:40:11.699Z,1660862411.699 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-08-18T22:40:20.225Z,1660862420.225 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-18T22:40:20.225Z,1660862420.225 [Default:CheckIn:C.Wait] Stopped 2022-08-18T22:40:20.225Z,1660862420.225 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-18T22:40:20.225Z,1660862420.225 [Default:CheckIn:D] Running Loop=1 2022-08-18T22:40:20.597Z,1660862420.597 [Default:CheckIn:D] Stopped 2022-08-18T22:40:20.597Z,1660862420.597 [Default:CheckIn:E] Running Loop=1 2022-08-18T22:40:21.012Z,1660862421.012 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 108.689762 min 2022-08-18T22:40:21.012Z,1660862421.012 [Default:CheckIn:E] Stopped 2022-08-18T22:40:21.012Z,1660862421.012 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-18T22:40:21.012Z,1660862421.012 [Default:CheckIn] Stopped 2022-08-18T22:40:21.012Z,1660862421.012 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-18T22:40:21.012Z,1660862421.012 [Default:CheckIn](INFO): Running loop #18 2022-08-18T22:40:21.013Z,1660862421.013 [Default:CheckIn] Running Loop=18 2022-08-18T22:40:21.013Z,1660862421.013 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-18T22:40:21.013Z,1660862421.013 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-18T22:40:23.014Z,1660862423.014 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,224021.00,A,3648.14386,N,12147.25792,W,0.078,176.68,180822,,,D*75 2022-08-18T22:40:23.016Z,1660862423.016 [NAL9602](INFO): GPS fix at 20220818T224021: (36.802398, -121.787632) 2022-08-18T22:40:23.073Z,1660862423.073 [Default:CheckIn:Read_GPS] Stopped 2022-08-18T22:40:23.073Z,1660862423.073 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-18T22:40:27.064Z,1660862427.064 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-08-18T22:40:33.015Z,1660862433.015 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220818T212349/Courier0039.lzma 2022-08-18T22:40:34.018Z,1660862434.018 [DataOverHttps](INFO): Moved sent file to Logs/20220818T212349/Courier0039.lzma.bak 2022-08-18T22:40:34.018Z,1660862434.018 [DataOverHttps](INFO): SBD MOMSN=17112906 2022-08-18T22:40:42.827Z,1660862442.827 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-08-18T22:40:50.523Z,1660862450.523 [DataOverHttps](INFO): Sending 146 bytes from file Logs/20220818T212349/Express0040.lzma 2022-08-18T22:40:51.526Z,1660862451.526 [DataOverHttps](INFO): Moved sent file to Logs/20220818T212349/Express0040.lzma.bak 2022-08-18T22:40:51.526Z,1660862451.526 [DataOverHttps](INFO): SBD MOMSN=17112909 2022-08-18T22:40:52.953Z,1660862452.953 [Default:CheckIn:Read_Iridium] Stopped 2022-08-18T22:40:52.954Z,1660862452.954 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-18T22:40:52.954Z,1660862452.954 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-18T22:40:58.610Z,1660862458.610 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-08-18T22:41:03.870Z,1660862463.870 [NAL9602](INFO): SBD MO Status=2, MOMSN=36022, MT Status=2, MTMSN=0 2022-08-18T22:41:03.871Z,1660862463.871 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-08-18T22:41:13.558Z,1660862473.558 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2022-08-18T22:41:27.304Z,1660862487.304 [BPC1](INFO): Calculating totals. Valid battery stick count: 54. Valid reserve battery stick count: 6. 2022-08-18T22:41:27.307Z,1660862487.307 [BPC1](INFO): Received data from all battery sticks. 2022-08-18T22:41:28.511Z,1660862488.511 [NAL9602](INFO): SBD MO Status=2, MOMSN=36022, MT Status=2, MTMSN=0 2022-08-18T22:41:28.511Z,1660862488.511 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-08-18T22:41:52.758Z,1660862512.758 [NAL9602](INFO): SBD MO Status=2, MOMSN=36022, MT Status=2, MTMSN=0 2022-08-18T22:41:52.758Z,1660862512.758 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-08-18T22:42:40.422Z,1660862560.422 [NAL9602](INFO): SBD MO Status=0, MOMSN=36022, MT Status=0, MTMSN=0 2022-08-18T22:42:40.423Z,1660862560.423 [NAL9602](INFO): No messages in MT queue 2022-08-18T22:43:11.129Z,1660862591.129 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-18T22:45:53.558Z,1660862753.558 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-18T22:45:53.559Z,1660862753.559 [Default:CheckIn:C.Wait] Stopped 2022-08-18T22:45:53.559Z,1660862753.559 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-18T22:45:53.559Z,1660862753.559 [Default:CheckIn:D] Running Loop=1 2022-08-18T22:45:53.969Z,1660862753.969 [Default:CheckIn:D] Stopped 2022-08-18T22:45:53.969Z,1660862753.969 [Default:CheckIn:E] Running Loop=1 2022-08-18T22:45:54.367Z,1660862754.367 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 114.245964 min 2022-08-18T22:45:54.367Z,1660862754.367 [Default:CheckIn:E] Stopped 2022-08-18T22:45:54.367Z,1660862754.367 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-18T22:45:54.367Z,1660862754.367 [Default:CheckIn] Stopped 2022-08-18T22:45:54.367Z,1660862754.367 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-18T22:45:54.368Z,1660862754.368 [Default:CheckIn](INFO): Running loop #19 2022-08-18T22:45:54.368Z,1660862754.368 [Default:CheckIn] Running Loop=19 2022-08-18T22:45:54.368Z,1660862754.368 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-18T22:45:54.368Z,1660862754.368 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-18T22:45:56.379Z,1660862756.379 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,224554.00,A,3648.14131,N,12147.25667,W,0.058,274.70,180822,,,D*7D 2022-08-18T22:45:56.381Z,1660862756.381 [NAL9602](INFO): GPS fix at 20220818T224554: (36.802355, -121.787611) 2022-08-18T22:45:56.391Z,1660862756.391 [Default:CheckIn:Read_GPS] Stopped 2022-08-18T22:45:56.391Z,1660862756.391 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-18T22:46:03.915Z,1660862763.915 [DataOverHttps](INFO): Sending 85 bytes from file Logs/20220818T212349/Courier0042.lzma 2022-08-18T22:46:04.918Z,1660862764.918 [DataOverHttps](INFO): Moved sent file to Logs/20220818T212349/Courier0042.lzma.bak 2022-08-18T22:46:04.918Z,1660862764.918 [DataOverHttps](INFO): SBD MOMSN=17112913 2022-08-18T22:46:12.950Z,1660862772.950 [NAL9602](INFO): SBD MO Status=0, MOMSN=36023, MT Status=0, MTMSN=0 2022-08-18T22:46:12.951Z,1660862772.951 [NAL9602](INFO): No messages in MT queue 2022-08-18T22:46:21.991Z,1660862781.991 [DataOverHttps](INFO): Sending 161 bytes from file Logs/20220818T212349/Express0043.lzma 2022-08-18T22:46:22.995Z,1660862782.995 [DataOverHttps](INFO): Moved sent file to Logs/20220818T212349/Express0043.lzma.bak 2022-08-18T22:46:22.995Z,1660862782.995 [DataOverHttps](INFO): SBD MOMSN=17112916 2022-08-18T22:46:24.286Z,1660862784.286 [Default:CheckIn:Read_Iridium] Stopped 2022-08-18T22:46:24.286Z,1660862784.286 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-18T22:46:24.286Z,1660862784.286 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-18T22:46:43.694Z,1660862803.694 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-18T22:51:24.909Z,1660863084.909 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-18T22:51:24.909Z,1660863084.909 [Default:CheckIn:C.Wait] Stopped 2022-08-18T22:51:24.909Z,1660863084.909 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-18T22:51:24.909Z,1660863084.909 [Default:CheckIn:D] Running Loop=1 2022-08-18T22:51:25.299Z,1660863085.299 [Default:CheckIn:D] Stopped 2022-08-18T22:51:25.299Z,1660863085.299 [Default:CheckIn:E] Running Loop=1 2022-08-18T22:51:25.711Z,1660863085.711 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 119.768132 min 2022-08-18T22:51:25.711Z,1660863085.711 [Default:CheckIn:E] Stopped 2022-08-18T22:51:25.711Z,1660863085.711 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-18T22:51:25.711Z,1660863085.711 [Default:CheckIn] Stopped 2022-08-18T22:51:25.711Z,1660863085.711 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-18T22:51:25.711Z,1660863085.711 [Default:CheckIn](INFO): Running loop #20 2022-08-18T22:51:25.711Z,1660863085.711 [Default:CheckIn] Running Loop=20 2022-08-18T22:51:25.711Z,1660863085.711 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-18T22:51:25.711Z,1660863085.711 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-18T22:51:27.720Z,1660863087.720 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,225125.00,A,3648.14043,N,12147.24951,W,0.039,274.70,180822,,,D*76 2022-08-18T22:51:27.722Z,1660863087.722 [NAL9602](INFO): GPS fix at 20220818T225125: (36.802340, -121.787492) 2022-08-18T22:51:27.733Z,1660863087.733 [Default:CheckIn:Read_GPS] Stopped 2022-08-18T22:51:27.733Z,1660863087.733 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-18T22:51:35.515Z,1660863095.515 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220818T212349/Courier0045.lzma 2022-08-18T22:51:36.518Z,1660863096.518 [DataOverHttps](INFO): Moved sent file to Logs/20220818T212349/Courier0045.lzma.bak 2022-08-18T22:51:36.518Z,1660863096.518 [DataOverHttps](INFO): SBD MOMSN=17112927 2022-08-18T22:51:51.550Z,1660863111.550 [NAL9602](INFO): SBD MO Status=0, MOMSN=36024, MT Status=0, MTMSN=0 2022-08-18T22:51:51.551Z,1660863111.551 [NAL9602](INFO): No messages in MT queue 2022-08-18T22:51:52.363Z,1660863112.363 [DataOverHttps](INFO): Sending 146 bytes from file Logs/20220818T212349/Express0046.lzma 2022-08-18T22:51:53.366Z,1660863113.366 [DataOverHttps](INFO): Moved sent file to Logs/20220818T212349/Express0046.lzma.bak 2022-08-18T22:51:53.366Z,1660863113.366 [DataOverHttps](INFO): SBD MOMSN=17112930 2022-08-18T22:51:54.796Z,1660863114.796 [Default:CheckIn:Read_Iridium] Stopped 2022-08-18T22:51:54.796Z,1660863114.796 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-18T22:51:54.796Z,1660863114.796 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-18T22:52:22.254Z,1660863142.254 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-18T22:56:55.398Z,1660863415.398 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-18T22:56:55.398Z,1660863415.398 [Default:CheckIn:C.Wait] Stopped 2022-08-18T22:56:55.399Z,1660863415.399 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-18T22:56:55.399Z,1660863415.399 [Default:CheckIn:D] Running Loop=1 2022-08-18T22:56:55.824Z,1660863415.824 [Default:CheckIn:D] Stopped 2022-08-18T22:56:55.824Z,1660863415.824 [Default:CheckIn:E] Running Loop=1 2022-08-18T22:56:56.236Z,1660863416.236 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 125.276872 min 2022-08-18T22:56:56.236Z,1660863416.236 [Default:CheckIn:E] Stopped 2022-08-18T22:56:56.237Z,1660863416.237 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-18T22:56:56.237Z,1660863416.237 [Default:CheckIn] Stopped 2022-08-18T22:56:56.237Z,1660863416.237 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-18T22:56:56.237Z,1660863416.237 [Default:CheckIn](INFO): Running loop #21 2022-08-18T22:56:56.237Z,1660863416.237 [Default:CheckIn] Running Loop=21 2022-08-18T22:56:56.237Z,1660863416.237 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-18T22:56:56.237Z,1660863416.237 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-18T22:56:58.215Z,1660863418.215 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,225656.00,A,3648.14161,N,12147.25724,W,0.039,274.70,180822,,,D*79 2022-08-18T22:56:58.217Z,1660863418.217 [NAL9602](INFO): GPS fix at 20220818T225656: (36.802360, -121.787621) 2022-08-18T22:56:58.246Z,1660863418.246 [Default:CheckIn:Read_GPS] Stopped 2022-08-18T22:56:58.247Z,1660863418.247 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-18T22:57:05.279Z,1660863425.279 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220818T212349/Courier0048.lzma 2022-08-18T22:57:06.282Z,1660863426.282 [DataOverHttps](INFO): Moved sent file to Logs/20220818T212349/Courier0048.lzma.bak 2022-08-18T22:57:06.282Z,1660863426.282 [DataOverHttps](INFO): SBD MOMSN=17112934 2022-08-18T22:57:19.629Z,1660863439.629 [NAL9602](INFO): SBD MO Status=2, MOMSN=36025, MT Status=2, MTMSN=0 2022-08-18T22:57:19.629Z,1660863439.629 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-08-18T22:57:22.091Z,1660863442.091 [DataOverHttps](INFO): Sending 146 bytes from file Logs/20220818T212349/Express0049.lzma 2022-08-18T22:57:23.094Z,1660863443.094 [DataOverHttps](INFO): Moved sent file to Logs/20220818T212349/Express0049.lzma.bak 2022-08-18T22:57:23.094Z,1660863443.094 [DataOverHttps](INFO): SBD MOMSN=17112939 2022-08-18T22:57:23.295Z,1660863443.295 [CBIT](IMPORTANT): Beginning ground fault scan 2022-08-18T22:57:24.497Z,1660863444.497 [Default:CheckIn:Read_Iridium] Stopped 2022-08-18T22:57:24.497Z,1660863444.497 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-18T22:57:24.497Z,1660863444.497 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-18T22:57:26.174Z,1660863446.174 [CBIT](ERROR): Error reading 24V bus power status. Assuming off for scan purposes. 2022-08-18T22:57:34.198Z,1660863454.198 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.002269 CHAN A1 (24V) N/A reporting off CHAN A2 (12V): -0.001814 CHAN A3 (5V): -0.001413 CHAN B0 (3.3V): -0.000018 CHAN B1 (3.15aV): -0.000385 CHAN B2 (3.15bV): -0.000407 CHAN B3 (GND): -0.000404 OPEN: -0.000435 Full Scale: +/- 1 mA 2022-08-18T22:57:47.502Z,1660863467.502 [NAL9602](INFO): SBD MO Status=2, MOMSN=36025, MT Status=2, MTMSN=0 2022-08-18T22:57:47.503Z,1660863467.503 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-08-18T22:58:07.702Z,1660863487.702 [NAL9602](INFO): SBD MO Status=2, MOMSN=36025, MT Status=2, MTMSN=0 2022-08-18T22:58:07.703Z,1660863487.703 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-08-18T22:58:24.666Z,1660863504.666 [NAL9602](INFO): SBD MO Status=2, MOMSN=36025, MT Status=2, MTMSN=0 2022-08-18T22:58:24.667Z,1660863504.667 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-08-18T22:59:00.635Z,1660863540.635 [NAL9602](INFO): SBD MO Status=0, MOMSN=36025, MT Status=0, MTMSN=0 2022-08-18T22:59:00.635Z,1660863540.635 [NAL9602](INFO): No messages in MT queue 2022-08-18T22:59:31.325Z,1660863571.325 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-18T23:02:25.103Z,1660863745.103 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-18T23:02:25.103Z,1660863745.103 [Default:CheckIn:C.Wait] Stopped 2022-08-18T23:02:25.103Z,1660863745.103 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-18T23:02:25.103Z,1660863745.103 [Default:CheckIn:D] Running Loop=1 2022-08-18T23:02:25.478Z,1660863745.478 [Default:CheckIn:D] Stopped 2022-08-18T23:02:25.478Z,1660863745.478 [Default:CheckIn:E] Running Loop=1 2022-08-18T23:02:25.897Z,1660863745.897 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 130.771110 min 2022-08-18T23:02:25.897Z,1660863745.897 [Default:CheckIn:E] Stopped 2022-08-18T23:02:25.897Z,1660863745.897 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-18T23:02:25.897Z,1660863745.897 [Default:CheckIn] Stopped 2022-08-18T23:02:25.898Z,1660863745.898 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-18T23:02:25.898Z,1660863745.898 [Default:CheckIn](INFO): Running loop #22 2022-08-18T23:02:25.898Z,1660863745.898 [Default:CheckIn] Running Loop=22 2022-08-18T23:02:25.898Z,1660863745.898 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-18T23:02:25.898Z,1660863745.898 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-18T23:02:27.875Z,1660863747.875 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,230226.00,A,3648.14378,N,12147.25620,W,0.039,274.70,180822,,,D*71 2022-08-18T23:02:27.877Z,1660863747.877 [NAL9602](INFO): GPS fix at 20220818T230226: (36.802396, -121.787603) 2022-08-18T23:02:27.916Z,1660863747.916 [Default:CheckIn:Read_GPS] Stopped 2022-08-18T23:02:27.916Z,1660863747.916 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-18T23:02:35.831Z,1660863755.831 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220818T212349/Courier0051.lzma 2022-08-18T23:02:36.834Z,1660863756.834 [DataOverHttps](INFO): Moved sent file to Logs/20220818T212349/Courier0051.lzma.bak 2022-08-18T23:02:36.834Z,1660863756.834 [DataOverHttps](INFO): SBD MOMSN=17112947 2022-08-18T23:02:41.611Z,1660863761.611 [NAL9602](INFO): SBD MO Status=0, MOMSN=36026, MT Status=0, MTMSN=0 2022-08-18T23:02:41.611Z,1660863761.611 [NAL9602](INFO): No messages in MT queue 2022-08-18T23:02:55.384Z,1660863775.384 [DataOverHttps](INFO): Sending 368 bytes from file Logs/20220818T212349/Express0052.lzma 2022-08-18T23:02:56.386Z,1660863776.386 [DataOverHttps](INFO): Moved sent file to Logs/20220818T212349/Express0052.lzma.bak 2022-08-18T23:02:56.386Z,1660863776.386 [DataOverHttps](INFO): SBD MOMSN=17112950 2022-08-18T23:02:57.831Z,1660863777.831 [Default:CheckIn:Read_Iridium] Stopped 2022-08-18T23:02:57.832Z,1660863777.832 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-18T23:02:57.832Z,1660863777.832 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-18T23:03:12.361Z,1660863792.361 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-18T23:07:58.418Z,1660864078.418 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-18T23:07:58.418Z,1660864078.418 [Default:CheckIn:C.Wait] Stopped 2022-08-18T23:07:58.419Z,1660864078.419 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-18T23:07:58.419Z,1660864078.419 [Default:CheckIn:D] Running Loop=1 2022-08-18T23:07:58.826Z,1660864078.826 [Default:CheckIn:D] Stopped 2022-08-18T23:07:58.826Z,1660864078.826 [Default:CheckIn:E] Running Loop=1 2022-08-18T23:07:59.231Z,1660864079.231 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 136.326904 min 2022-08-18T23:07:59.231Z,1660864079.231 [Default:CheckIn:E] Stopped 2022-08-18T23:07:59.231Z,1660864079.231 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-18T23:07:59.231Z,1660864079.231 [Default:CheckIn] Stopped 2022-08-18T23:07:59.231Z,1660864079.231 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-18T23:07:59.231Z,1660864079.231 [Default:CheckIn](INFO): Running loop #23 2022-08-18T23:07:59.231Z,1660864079.231 [Default:CheckIn] Running Loop=23 2022-08-18T23:07:59.231Z,1660864079.231 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-18T23:07:59.232Z,1660864079.232 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-18T23:08:01.239Z,1660864081.239 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,230759.00,A,3648.14351,N,12147.25873,W,0.156,0.00,180822,,,D*71 2022-08-18T23:08:01.241Z,1660864081.241 [NAL9602](INFO): GPS fix at 20220818T230759: (36.802392, -121.787645) 2022-08-18T23:08:01.270Z,1660864081.270 [Default:CheckIn:Read_GPS] Stopped 2022-08-18T23:08:01.270Z,1660864081.270 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-18T23:08:08.363Z,1660864088.363 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220818T212349/Courier0054.lzma 2022-08-18T23:08:09.366Z,1660864089.366 [DataOverHttps](INFO): Moved sent file to Logs/20220818T212349/Courier0054.lzma.bak 2022-08-18T23:08:09.366Z,1660864089.366 [DataOverHttps](INFO): SBD MOMSN=17112963 2022-08-18T23:08:16.990Z,1660864096.990 [NAL9602](INFO): SBD MO Status=0, MOMSN=36027, MT Status=0, MTMSN=0 2022-08-18T23:08:16.991Z,1660864096.991 [NAL9602](INFO): No messages in MT queue 2022-08-18T23:08:27.900Z,1660864107.900 [DataOverHttps](INFO): Sending 148 bytes from file Logs/20220818T212349/Express0055.lzma 2022-08-18T23:08:28.902Z,1660864108.902 [DataOverHttps](INFO): Moved sent file to Logs/20220818T212349/Express0055.lzma.bak 2022-08-18T23:08:28.902Z,1660864108.902 [DataOverHttps](INFO): SBD MOMSN=17112966 2022-08-18T23:08:30.392Z,1660864110.392 [Default:CheckIn:Read_Iridium] Stopped 2022-08-18T23:08:30.392Z,1660864110.392 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-18T23:08:30.392Z,1660864110.392 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-18T23:08:47.745Z,1660864127.745 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-18T23:13:31.109Z,1660864411.109 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-18T23:13:31.109Z,1660864411.109 [Default:CheckIn:C.Wait] Stopped 2022-08-18T23:13:31.109Z,1660864411.109 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-18T23:13:31.109Z,1660864411.109 [Default:CheckIn:D] Running Loop=1 2022-08-18T23:13:31.487Z,1660864411.487 [Default:CheckIn:D] Stopped 2022-08-18T23:13:31.487Z,1660864411.487 [Default:CheckIn:E] Running Loop=1 2022-08-18T23:13:31.891Z,1660864411.891 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 141.871257 min 2022-08-18T23:13:31.891Z,1660864411.891 [Default:CheckIn:E] Stopped 2022-08-18T23:13:31.891Z,1660864411.891 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-18T23:13:31.891Z,1660864411.891 [Default:CheckIn] Stopped 2022-08-18T23:13:31.891Z,1660864411.891 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-18T23:13:31.891Z,1660864411.891 [Default:CheckIn](INFO): Running loop #24 2022-08-18T23:13:31.891Z,1660864411.891 [Default:CheckIn] Running Loop=24 2022-08-18T23:13:31.892Z,1660864411.892 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-18T23:13:31.892Z,1660864411.892 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-18T23:13:33.899Z,1660864413.899 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,231332.00,A,3648.14362,N,12147.25569,W,0.117,0.00,180822,,,D*7A 2022-08-18T23:13:33.901Z,1660864413.901 [NAL9602](INFO): GPS fix at 20220818T231332: (36.802394, -121.787595) 2022-08-18T23:13:34.004Z,1660864414.004 [Default:CheckIn:Read_GPS] Stopped 2022-08-18T23:13:34.004Z,1660864414.004 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-18T23:13:40.763Z,1660864420.763 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220818T212349/Courier0057.lzma 2022-08-18T23:13:41.766Z,1660864421.766 [DataOverHttps](INFO): Moved sent file to Logs/20220818T212349/Courier0057.lzma.bak 2022-08-18T23:13:41.766Z,1660864421.766 [DataOverHttps](INFO): SBD MOMSN=17112970 2022-08-18T23:13:57.744Z,1660864437.744 [DataOverHttps](INFO): Sending 150 bytes from file Logs/20220818T212349/Express0058.lzma 2022-08-18T23:13:58.746Z,1660864438.746 [DataOverHttps](INFO): Moved sent file to Logs/20220818T212349/Express0058.lzma.bak 2022-08-18T23:13:58.746Z,1660864438.746 [DataOverHttps](INFO): SBD MOMSN=17112973 2022-08-18T23:13:59.858Z,1660864439.858 [Default:CheckIn:Read_Iridium] Stopped 2022-08-18T23:13:59.858Z,1660864439.858 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-18T23:13:59.858Z,1660864439.858 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-18T23:14:05.034Z,1660864445.034 [NAL9602](INFO): SBD MO Status=0, MOMSN=36028, MT Status=0, MTMSN=0 2022-08-18T23:14:05.035Z,1660864445.035 [NAL9602](INFO): No messages in MT queue 2022-08-18T23:14:35.745Z,1660864475.745 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-18T23:19:00.419Z,1660864740.419 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-18T23:19:00.419Z,1660864740.419 [Default:CheckIn:C.Wait] Stopped 2022-08-18T23:19:00.419Z,1660864740.419 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-18T23:19:00.436Z,1660864740.436 [Default:CheckIn:D] Running Loop=1 2022-08-18T23:19:00.814Z,1660864740.814 [Default:CheckIn:D] Stopped 2022-08-18T23:19:00.814Z,1660864740.814 [Default:CheckIn:E] Running Loop=1 2022-08-18T23:19:01.235Z,1660864741.235 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 147.360042 min 2022-08-18T23:19:01.235Z,1660864741.235 [Default:CheckIn:E] Stopped 2022-08-18T23:19:01.235Z,1660864741.235 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-18T23:19:01.235Z,1660864741.235 [Default:CheckIn] Stopped 2022-08-18T23:19:01.236Z,1660864741.236 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-18T23:19:01.236Z,1660864741.236 [Default:CheckIn](INFO): Running loop #25 2022-08-18T23:19:01.236Z,1660864741.236 [Default:CheckIn] Running Loop=25 2022-08-18T23:19:01.236Z,1660864741.236 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-18T23:19:01.236Z,1660864741.236 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-18T23:19:03.235Z,1660864743.235 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,231901.00,A,3648.14274,N,12147.25317,W,0.175,0.00,180822,,,D*7D 2022-08-18T23:19:03.237Z,1660864743.237 [NAL9602](INFO): GPS fix at 20220818T231901: (36.802379, -121.787553) 2022-08-18T23:19:03.275Z,1660864743.275 [Default:CheckIn:Read_GPS] Stopped 2022-08-18T23:19:03.275Z,1660864743.275 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-18T23:19:10.163Z,1660864750.163 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220818T212349/Courier0060.lzma 2022-08-18T23:19:11.166Z,1660864751.166 [DataOverHttps](INFO): Moved sent file to Logs/20220818T212349/Courier0060.lzma.bak 2022-08-18T23:19:11.166Z,1660864751.166 [DataOverHttps](INFO): SBD MOMSN=17112983 2022-08-18T23:19:26.995Z,1660864766.995 [DataOverHttps](INFO): Sending 148 bytes from file Logs/20220818T212349/Express0061.lzma 2022-08-18T23:19:27.998Z,1660864767.998 [DataOverHttps](INFO): Moved sent file to Logs/20220818T212349/Express0061.lzma.bak 2022-08-18T23:19:27.998Z,1660864767.998 [DataOverHttps](INFO): SBD MOMSN=17112986 2022-08-18T23:19:29.097Z,1660864769.097 [Default:CheckIn:Read_Iridium] Stopped 2022-08-18T23:19:29.097Z,1660864769.097 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-18T23:19:29.097Z,1660864769.097 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-18T23:22:24.439Z,1660864944.439 [NAL9602](INFO): SBD MO Status=2, MOMSN=36029, MT Status=2, MTMSN=0 2022-08-18T23:22:24.439Z,1660864944.439 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-08-18T23:22:51.104Z,1660864971.104 [NAL9602](INFO): SBD MO Status=0, MOMSN=36029, MT Status=0, MTMSN=0 2022-08-18T23:22:51.104Z,1660864971.104 [NAL9602](INFO): No messages in MT queue 2022-08-18T23:23:21.813Z,1660865001.813 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-18T23:24:29.706Z,1660865069.706 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-18T23:24:29.706Z,1660865069.706 [Default:CheckIn:C.Wait] Stopped 2022-08-18T23:24:29.706Z,1660865069.706 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-18T23:24:29.706Z,1660865069.706 [Default:CheckIn:D] Running Loop=1 2022-08-18T23:24:30.182Z,1660865070.182 [Default:CheckIn:D] Stopped 2022-08-18T23:24:30.182Z,1660865070.182 [Default:CheckIn:E] Running Loop=1 2022-08-18T23:24:30.502Z,1660865070.502 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 152.849512 min 2022-08-18T23:24:30.502Z,1660865070.502 [Default:CheckIn:E] Stopped 2022-08-18T23:24:30.502Z,1660865070.502 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-18T23:24:30.502Z,1660865070.502 [Default:CheckIn] Stopped 2022-08-18T23:24:30.502Z,1660865070.502 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-18T23:24:30.502Z,1660865070.502 [Default:CheckIn](INFO): Running loop #26 2022-08-18T23:24:30.502Z,1660865070.502 [Default:CheckIn] Running Loop=26 2022-08-18T23:24:30.502Z,1660865070.502 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-18T23:24:30.503Z,1660865070.503 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-18T23:24:32.522Z,1660865072.522 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,232430.00,A,3648.14289,N,12147.25605,W,0.097,0.00,180822,,,D*78 2022-08-18T23:24:32.524Z,1660865072.524 [NAL9602](INFO): GPS fix at 20220818T232430: (36.802382, -121.787601) 2022-08-18T23:24:32.534Z,1660865072.534 [Default:CheckIn:Read_GPS] Stopped 2022-08-18T23:24:32.534Z,1660865072.534 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-18T23:24:39.519Z,1660865079.519 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220818T212349/Courier0063.lzma 2022-08-18T23:24:40.522Z,1660865080.522 [DataOverHttps](INFO): Moved sent file to Logs/20220818T212349/Courier0063.lzma.bak 2022-08-18T23:24:40.522Z,1660865080.522 [DataOverHttps](INFO): SBD MOMSN=17112989 2022-08-18T23:24:59.078Z,1660865099.078 [DataOverHttps](INFO): Sending 154 bytes from file Logs/20220818T212349/Express0064.lzma 2022-08-18T23:25:00.078Z,1660865100.078 [DataOverHttps](INFO): Moved sent file to Logs/20220818T212349/Express0064.lzma.bak 2022-08-18T23:25:00.078Z,1660865100.078 [DataOverHttps](INFO): SBD MOMSN=17112992 2022-08-18T23:25:00.451Z,1660865100.451 [NAL9602](INFO): SBD MO Status=0, MOMSN=36030, MT Status=0, MTMSN=0 2022-08-18T23:25:00.451Z,1660865100.451 [NAL9602](INFO): No messages in MT queue 2022-08-18T23:25:01.289Z,1660865101.289 [Default:CheckIn:Read_Iridium] Stopped 2022-08-18T23:25:01.289Z,1660865101.289 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-18T23:25:01.289Z,1660865101.289 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-18T23:25:31.151Z,1660865131.151 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-18T23:30:01.850Z,1660865401.850 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-18T23:30:01.850Z,1660865401.850 [Default:CheckIn:C.Wait] Stopped 2022-08-18T23:30:01.850Z,1660865401.850 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-18T23:30:01.850Z,1660865401.850 [Default:CheckIn:D] Running Loop=1 2022-08-18T23:30:02.267Z,1660865402.267 [Default:CheckIn:D] Stopped 2022-08-18T23:30:02.268Z,1660865402.268 [Default:CheckIn:E] Running Loop=1 2022-08-18T23:30:02.660Z,1660865402.660 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 158.384261 min 2022-08-18T23:30:02.660Z,1660865402.660 [Default:CheckIn:E] Stopped 2022-08-18T23:30:02.660Z,1660865402.660 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-18T23:30:02.660Z,1660865402.660 [Default:CheckIn] Stopped 2022-08-18T23:30:02.660Z,1660865402.660 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-18T23:30:02.660Z,1660865402.660 [Default:CheckIn](INFO): Running loop #27 2022-08-18T23:30:02.660Z,1660865402.660 [Default:CheckIn] Running Loop=27 2022-08-18T23:30:02.660Z,1660865402.660 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-18T23:30:02.661Z,1660865402.661 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-18T23:30:04.675Z,1660865404.675 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,233002.00,A,3648.14303,N,12147.25528,W,0.214,0.00,180822,,,D*7A 2022-08-18T23:30:04.686Z,1660865404.686 [NAL9602](INFO): GPS fix at 20220818T233002: (36.802384, -121.787588) 2022-08-18T23:30:04.696Z,1660865404.696 [Default:CheckIn:Read_GPS] Stopped 2022-08-18T23:30:04.697Z,1660865404.697 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-18T23:30:12.023Z,1660865412.023 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220818T212349/Courier0066.lzma 2022-08-18T23:30:13.026Z,1660865413.026 [DataOverHttps](INFO): Moved sent file to Logs/20220818T212349/Courier0066.lzma.bak 2022-08-18T23:30:13.026Z,1660865413.026 [DataOverHttps](INFO): SBD MOMSN=17113004 2022-08-18T23:30:32.339Z,1660865432.339 [DataOverHttps](INFO): Sending 147 bytes from file Logs/20220818T212349/Express0067.lzma 2022-08-18T23:30:33.342Z,1660865433.342 [DataOverHttps](INFO): Moved sent file to Logs/20220818T212349/Express0067.lzma.bak 2022-08-18T23:30:33.342Z,1660865433.342 [DataOverHttps](INFO): SBD MOMSN=17113007 2022-08-18T23:30:34.620Z,1660865434.620 [Default:CheckIn:Read_Iridium] Stopped 2022-08-18T23:30:34.620Z,1660865434.620 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-18T23:30:34.620Z,1660865434.620 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-18T23:31:41.675Z,1660865501.675 [NAL9602](INFO): SBD MO Status=2, MOMSN=36031, MT Status=2, MTMSN=0 2022-08-18T23:31:41.675Z,1660865501.675 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-08-18T23:32:52.777Z,1660865572.777 [NAL9602](INFO): SBD MO Status=0, MOMSN=36031, MT Status=0, MTMSN=0 2022-08-18T23:32:52.777Z,1660865572.777 [NAL9602](INFO): No messages in MT queue 2022-08-18T23:33:23.479Z,1660865603.479 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-18T23:35:35.199Z,1660865735.199 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-18T23:35:35.199Z,1660865735.199 [Default:CheckIn:C.Wait] Stopped 2022-08-18T23:35:35.199Z,1660865735.199 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-18T23:35:35.199Z,1660865735.199 [Default:CheckIn:D] Running Loop=1 2022-08-18T23:35:35.607Z,1660865735.607 [Default:CheckIn:D] Stopped 2022-08-18T23:35:35.607Z,1660865735.607 [Default:CheckIn:E] Running Loop=1 2022-08-18T23:35:36.001Z,1660865736.001 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 163.939925 min 2022-08-18T23:35:36.002Z,1660865736.002 [Default:CheckIn:E] Stopped 2022-08-18T23:35:36.002Z,1660865736.002 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-18T23:35:36.002Z,1660865736.002 [Default:CheckIn] Stopped 2022-08-18T23:35:36.002Z,1660865736.002 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-18T23:35:36.002Z,1660865736.002 [Default:CheckIn](INFO): Running loop #28 2022-08-18T23:35:36.002Z,1660865736.002 [Default:CheckIn] Running Loop=28 2022-08-18T23:35:36.002Z,1660865736.002 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-18T23:35:36.002Z,1660865736.002 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-18T23:35:38.019Z,1660865738.019 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,233536.00,A,3648.14528,N,12147.25927,W,0.117,0.00,180822,,,D*74 2022-08-18T23:35:38.021Z,1660865738.021 [NAL9602](INFO): GPS fix at 20220818T233536: (36.802421, -121.787655) 2022-08-18T23:35:38.032Z,1660865738.032 [Default:CheckIn:Read_GPS] Stopped 2022-08-18T23:35:38.032Z,1660865738.032 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-18T23:35:45.980Z,1660865745.980 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220818T212349/Courier0069.lzma 2022-08-18T23:35:46.982Z,1660865746.982 [DataOverHttps](INFO): Moved sent file to Logs/20220818T212349/Courier0069.lzma.bak 2022-08-18T23:35:46.982Z,1660865746.982 [DataOverHttps](INFO): SBD MOMSN=17113011 2022-08-18T23:36:02.726Z,1660865762.726 [DataOverHttps](INFO): Sending 149 bytes from file Logs/20220818T212349/Express0070.lzma 2022-08-18T23:36:03.726Z,1660865763.726 [DataOverHttps](INFO): Moved sent file to Logs/20220818T212349/Express0070.lzma.bak 2022-08-18T23:36:03.726Z,1660865763.726 [DataOverHttps](INFO): SBD MOMSN=17113014 2022-08-18T23:36:05.098Z,1660865765.098 [Default:CheckIn:Read_Iridium] Stopped 2022-08-18T23:36:05.098Z,1660865765.098 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-18T23:36:05.098Z,1660865765.098 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-18T23:36:05.895Z,1660865765.895 [NAL9602](INFO): SBD MO Status=0, MOMSN=36032, MT Status=0, MTMSN=0 2022-08-18T23:36:05.895Z,1660865765.895 [NAL9602](INFO): No messages in MT queue 2022-08-18T23:36:36.601Z,1660865796.601 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-18T23:41:05.678Z,1660866065.678 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-18T23:41:05.678Z,1660866065.678 [Default:CheckIn:C.Wait] Stopped 2022-08-18T23:41:05.678Z,1660866065.678 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-18T23:41:05.679Z,1660866065.679 [Default:CheckIn:D] Running Loop=1 2022-08-18T23:41:06.077Z,1660866066.077 [Default:CheckIn:D] Stopped 2022-08-18T23:41:06.077Z,1660866066.077 [Default:CheckIn:E] Running Loop=1 2022-08-18T23:41:06.493Z,1660866066.493 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 169.447770 min 2022-08-18T23:41:06.493Z,1660866066.493 [Default:CheckIn:E] Stopped 2022-08-18T23:41:06.493Z,1660866066.493 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-18T23:41:06.493Z,1660866066.493 [Default:CheckIn] Stopped 2022-08-18T23:41:06.493Z,1660866066.493 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-18T23:41:06.493Z,1660866066.493 [Default:CheckIn](INFO): Running loop #29 2022-08-18T23:41:06.493Z,1660866066.493 [Default:CheckIn] Running Loop=29 2022-08-18T23:41:06.493Z,1660866066.493 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-18T23:41:06.493Z,1660866066.493 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-18T23:41:08.499Z,1660866068.499 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,234106.00,A,3648.14485,N,12147.26007,W,0.058,0.00,180822,,,D*70 2022-08-18T23:41:08.501Z,1660866068.501 [NAL9602](INFO): GPS fix at 20220818T234106: (36.802414, -121.787668) 2022-08-18T23:41:08.511Z,1660866068.511 [Default:CheckIn:Read_GPS] Stopped 2022-08-18T23:41:08.512Z,1660866068.512 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-18T23:41:15.775Z,1660866075.775 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220818T212349/Courier0072.lzma 2022-08-18T23:41:16.778Z,1660866076.778 [DataOverHttps](INFO): Moved sent file to Logs/20220818T212349/Courier0072.lzma.bak 2022-08-18T23:41:16.778Z,1660866076.778 [DataOverHttps](INFO): SBD MOMSN=17113026 2022-08-18T23:41:25.461Z,1660866085.461 [NAL9602](INFO): SBD MO Status=0, MOMSN=36033, MT Status=0, MTMSN=0 2022-08-18T23:41:25.461Z,1660866085.461 [NAL9602](INFO): No messages in MT queue 2022-08-18T23:41:32.632Z,1660866092.632 [DataOverHttps](INFO): Sending 146 bytes from file Logs/20220818T212349/Express0073.lzma 2022-08-18T23:41:33.634Z,1660866093.634 [DataOverHttps](INFO): Moved sent file to Logs/20220818T212349/Express0073.lzma.bak 2022-08-18T23:41:33.634Z,1660866093.634 [DataOverHttps](INFO): SBD MOMSN=17113029 2022-08-18T23:41:34.777Z,1660866094.777 [Default:CheckIn:Read_Iridium] Stopped 2022-08-18T23:41:34.778Z,1660866094.778 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-18T23:41:34.778Z,1660866094.778 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-18T23:41:56.174Z,1660866116.174 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-18T23:46:22.031Z,1660866382.031 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-08-18T23:46:35.394Z,1660866395.394 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-18T23:46:35.394Z,1660866395.394 [Default:CheckIn:C.Wait] Stopped 2022-08-18T23:46:35.394Z,1660866395.394 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-18T23:46:35.395Z,1660866395.395 [Default:CheckIn:D] Running Loop=1 2022-08-18T23:46:35.797Z,1660866395.797 [Default:CheckIn:D] Stopped 2022-08-18T23:46:35.797Z,1660866395.797 [Default:CheckIn:E] Running Loop=1 2022-08-18T23:46:36.189Z,1660866396.189 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 174.943099 min 2022-08-18T23:46:36.189Z,1660866396.189 [Default:CheckIn:E] Stopped 2022-08-18T23:46:36.189Z,1660866396.189 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-18T23:46:36.189Z,1660866396.189 [Default:CheckIn] Stopped 2022-08-18T23:46:36.189Z,1660866396.189 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-18T23:46:36.189Z,1660866396.189 [Default:CheckIn](INFO): Running loop #30 2022-08-18T23:46:36.189Z,1660866396.189 [Default:CheckIn] Running Loop=30 2022-08-18T23:46:36.190Z,1660866396.190 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-18T23:46:36.190Z,1660866396.190 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-18T23:46:36.980Z,1660866396.980 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-08-18T23:46:38.199Z,1660866398.199 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,234636.00,A,3648.17691,N,12147.27904,W,0.467,212.68,180822,,,D*7C 2022-08-18T23:46:38.201Z,1660866398.201 [NAL9602](INFO): GPS fix at 20220818T234636: (36.802948, -121.787984) 2022-08-18T23:46:38.212Z,1660866398.212 [Default:CheckIn:Read_GPS] Stopped 2022-08-18T23:46:38.212Z,1660866398.212 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-18T23:46:45.347Z,1660866405.347 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220818T212349/Courier0075.lzma 2022-08-18T23:46:46.351Z,1660866406.351 [DataOverHttps](INFO): Moved sent file to Logs/20220818T212349/Courier0075.lzma.bak 2022-08-18T23:46:46.351Z,1660866406.351 [DataOverHttps](INFO): SBD MOMSN=17113033 2022-08-18T23:46:52.766Z,1660866412.766 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-08-18T23:47:05.044Z,1660866425.044 [DataOverHttps](INFO): Sending 165 bytes from file Logs/20220818T212349/Express0076.lzma 2022-08-18T23:47:06.046Z,1660866426.046 [DataOverHttps](INFO): Moved sent file to Logs/20220818T212349/Express0076.lzma.bak 2022-08-18T23:47:06.046Z,1660866426.046 [DataOverHttps](INFO): SBD MOMSN=17113036 2022-08-18T23:47:07.361Z,1660866427.361 [Default:CheckIn:Read_Iridium] Stopped 2022-08-18T23:47:07.361Z,1660866427.361 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-18T23:47:07.361Z,1660866427.361 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-18T23:47:08.554Z,1660866428.554 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-08-18T23:47:23.909Z,1660866443.909 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-08-18T23:47:40.067Z,1660866460.067 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-08-18T23:47:55.015Z,1660866475.015 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-08-18T23:48:10.367Z,1660866490.367 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-08-18T23:48:25.726Z,1660866505.726 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-08-18T23:48:41.474Z,1660866521.474 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2022-08-18T23:48:54.813Z,1660866534.813 [BPC1](INFO): Calculating totals. Valid battery stick count: 54. Valid reserve battery stick count: 6. 2022-08-18T23:48:54.816Z,1660866534.816 [BPC1](INFO): Received data from all battery sticks. 2022-08-18T23:51:40.454Z,1660866700.454 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-08-18T23:52:07.930Z,1660866727.930 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-18T23:52:07.930Z,1660866727.930 [Default:CheckIn:C.Wait] Stopped 2022-08-18T23:52:07.930Z,1660866727.930 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-18T23:52:07.931Z,1660866727.931 [Default:CheckIn:D] Running Loop=1 2022-08-18T23:52:08.340Z,1660866728.340 [Default:CheckIn:D] Stopped 2022-08-18T23:52:08.340Z,1660866728.340 [Default:CheckIn:E] Running Loop=1 2022-08-18T23:52:08.763Z,1660866728.763 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 180.485482 min 2022-08-18T23:52:08.763Z,1660866728.763 [Default:CheckIn:E] Stopped 2022-08-18T23:52:08.763Z,1660866728.763 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-18T23:52:08.763Z,1660866728.763 [Default:CheckIn] Stopped 2022-08-18T23:52:08.763Z,1660866728.763 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-18T23:52:08.763Z,1660866728.763 [Default:CheckIn](INFO): Running loop #31 2022-08-18T23:52:08.763Z,1660866728.763 [Default:CheckIn] Running Loop=31 2022-08-18T23:52:08.763Z,1660866728.763 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-18T23:52:08.763Z,1660866728.763 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-18T23:52:10.751Z,1660866730.751 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,235209.00,A,3648.16677,N,12147.27934,W,0.272,170.78,180822,,,A*7E 2022-08-18T23:52:10.753Z,1660866730.753 [NAL9602](INFO): GPS fix at 20220818T235209: (36.802779, -121.787989) 2022-08-18T23:52:10.764Z,1660866730.764 [Default:CheckIn:Read_GPS] Stopped 2022-08-18T23:52:10.764Z,1660866730.764 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-18T23:52:17.787Z,1660866737.787 [DataOverHttps](INFO): Sending 85 bytes from file Logs/20220818T212349/Courier0078.lzma 2022-08-18T23:52:18.790Z,1660866738.790 [DataOverHttps](INFO): Moved sent file to Logs/20220818T212349/Courier0078.lzma.bak 2022-08-18T23:52:18.790Z,1660866738.790 [DataOverHttps](INFO): SBD MOMSN=17113045 2022-08-18T23:52:37.008Z,1660866757.008 [DataOverHttps](INFO): Sending 216 bytes from file Logs/20220818T212349/Express0079.lzma 2022-08-18T23:52:38.010Z,1660866758.010 [DataOverHttps](INFO): Moved sent file to Logs/20220818T212349/Express0079.lzma.bak 2022-08-18T23:52:38.010Z,1660866758.010 [DataOverHttps](INFO): SBD MOMSN=17113048 2022-08-18T23:52:39.118Z,1660866759.118 [Default:CheckIn:Read_Iridium] Stopped 2022-08-18T23:52:39.118Z,1660866759.118 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-18T23:52:39.118Z,1660866759.118 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-18T23:52:43.537Z,1660866763.537 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-18T23:56:22.539Z,1660866982.539 [DropWeight](CRITICAL): DROP WEIGHT MISSING. 2022-08-18T23:56:22.539Z,1660866982.539 [DropWeight] Hardware Fault, FailCount= 1 2022-08-18T23:56:22.539Z,1660866982.539 [DropWeight](ERROR): Hardware Fault 2022-08-18T23:56:22.590Z,1660866982.590 [CommandExec](FAULT): Scheduling is paused 2022-08-18T23:56:22.591Z,1660866982.591 [CBIT](INFO): Critical error at 20220818T235622 2022-08-18T23:56:22.597Z,1660866982.597 [CBIT](ERROR): Hardware Fault in component: DropWeight 2022-08-18T23:56:22.598Z,1660866982.598 [CBIT](CRITICAL): Hardware Fault in component: DropWeight 2022-08-18T23:56:22.963Z,1660866982.963 [CBIT](INFO): Critical error at 20220818T235622 2022-08-18T23:57:39.726Z,1660867059.726 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-18T23:57:39.726Z,1660867059.726 [Default:CheckIn:C.Wait] Stopped 2022-08-18T23:57:39.726Z,1660867059.726 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-18T23:57:39.727Z,1660867059.727 [Default:CheckIn:D] Running Loop=1 2022-08-18T23:57:40.141Z,1660867060.141 [Default:CheckIn:D] Stopped 2022-08-18T23:57:40.141Z,1660867060.141 [Default:CheckIn:E] Running Loop=1 2022-08-18T23:57:40.527Z,1660867060.527 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 186.015495 min 2022-08-18T23:57:40.527Z,1660867060.527 [Default:CheckIn:E] Stopped 2022-08-18T23:57:40.527Z,1660867060.527 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-18T23:57:40.527Z,1660867060.527 [Default:CheckIn] Stopped 2022-08-18T23:57:40.527Z,1660867060.527 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-18T23:57:40.527Z,1660867060.527 [Default:CheckIn](INFO): Running loop #32 2022-08-18T23:57:40.527Z,1660867060.527 [Default:CheckIn] Running Loop=32 2022-08-18T23:57:40.527Z,1660867060.527 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-18T23:57:40.527Z,1660867060.527 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-18T23:57:42.538Z,1660867062.538 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,235740.00,A,3648.16822,N,12147.28319,W,0.000,170.78,180822,,,A*75 2022-08-18T23:57:42.541Z,1660867062.541 [NAL9602](INFO): GPS fix at 20220818T235740: (36.802804, -121.788053) 2022-08-18T23:57:42.551Z,1660867062.551 [Default:CheckIn:Read_GPS] Stopped 2022-08-18T23:57:42.551Z,1660867062.551 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-18T23:57:50.239Z,1660867070.239 [DataOverHttps](INFO): Sending 177 bytes from file Logs/20220818T212349/Courier0081.lzma 2022-08-18T23:57:51.242Z,1660867071.242 [DataOverHttps](INFO): Moved sent file to Logs/20220818T212349/Courier0081.lzma.bak 2022-08-18T23:57:51.242Z,1660867071.242 [DataOverHttps](INFO): SBD MOMSN=17113052 2022-08-18T23:58:07.239Z,1660867087.239 [DataOverHttps](INFO): Sending 166 bytes from file Logs/20220818T212349/Express0082.lzma 2022-08-18T23:58:08.242Z,1660867088.242 [DataOverHttps](INFO): Moved sent file to Logs/20220818T212349/Express0082.lzma.bak 2022-08-18T23:58:08.242Z,1660867088.242 [DataOverHttps](INFO): SBD MOMSN=17113057 2022-08-18T23:58:09.621Z,1660867089.621 [Default:CheckIn:Read_Iridium] Stopped 2022-08-18T23:58:09.621Z,1660867089.621 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-18T23:58:09.621Z,1660867089.621 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-18T23:58:13.237Z,1660867093.237 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2022-08-18T23:58:13.320Z,1660867093.320 [NAL9602](ERROR): received: +CSQ:0 OK033, 0, 0, 0, 0 OK 2022-08-19T00:02:44.325Z,1660867364.325 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-08-19T00:03:10.198Z,1660867390.198 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-19T00:03:10.198Z,1660867390.198 [Default:CheckIn:C.Wait] Stopped 2022-08-19T00:03:10.198Z,1660867390.198 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-19T00:03:10.199Z,1660867390.199 [Default:CheckIn:D] Running Loop=1 2022-08-19T00:03:10.591Z,1660867390.591 [Default:CheckIn:D] Stopped 2022-08-19T00:03:10.591Z,1660867390.591 [Default:CheckIn:E] Running Loop=1 2022-08-19T00:03:10.994Z,1660867390.994 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 191.522998 min 2022-08-19T00:03:10.994Z,1660867390.994 [Default:CheckIn:E] Stopped 2022-08-19T00:03:10.994Z,1660867390.994 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-19T00:03:10.994Z,1660867390.994 [Default:CheckIn] Stopped 2022-08-19T00:03:10.994Z,1660867390.994 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-19T00:03:10.994Z,1660867390.994 [Default:CheckIn](INFO): Running loop #33 2022-08-19T00:03:10.995Z,1660867390.995 [Default:CheckIn] Running Loop=33 2022-08-19T00:03:10.995Z,1660867390.995 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-19T00:03:10.995Z,1660867390.995 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-19T00:03:13.011Z,1660867393.011 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,000311.00,A,3648.16952,N,12147.28311,W,0.078,170.78,190822,,,A*71 2022-08-19T00:03:13.013Z,1660867393.013 [NAL9602](INFO): GPS fix at 20220819T000311: (36.802825, -121.788052) 2022-08-19T00:03:13.023Z,1660867393.023 [Default:CheckIn:Read_GPS] Stopped 2022-08-19T00:03:13.023Z,1660867393.023 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-19T00:03:20.275Z,1660867400.275 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220818T212349/Courier0084.lzma 2022-08-19T00:03:21.278Z,1660867401.278 [DataOverHttps](INFO): Moved sent file to Logs/20220818T212349/Courier0084.lzma.bak 2022-08-19T00:03:21.278Z,1660867401.278 [DataOverHttps](INFO): SBD MOMSN=17113068 2022-08-19T00:03:37.015Z,1660867417.015 [DataOverHttps](INFO): Sending 216 bytes from file Logs/20220818T212349/Express0085.lzma 2022-08-19T00:03:38.018Z,1660867418.018 [DataOverHttps](INFO): Moved sent file to Logs/20220818T212349/Express0085.lzma.bak 2022-08-19T00:03:38.018Z,1660867418.018 [DataOverHttps](INFO): SBD MOMSN=17113071 2022-08-19T00:03:39.304Z,1660867419.304 [Default:CheckIn:Read_Iridium] Stopped 2022-08-19T00:03:39.304Z,1660867419.304 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-19T00:03:39.304Z,1660867419.304 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-19T00:03:45.354Z,1660867425.354 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-19T00:08:39.876Z,1660867719.876 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-19T00:08:39.876Z,1660867719.876 [Default:CheckIn:C.Wait] Stopped 2022-08-19T00:08:39.877Z,1660867719.877 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-19T00:08:39.877Z,1660867719.877 [Default:CheckIn:D] Running Loop=1 2022-08-19T00:08:40.341Z,1660867720.341 [Default:CheckIn:D] Stopped 2022-08-19T00:08:40.341Z,1660867720.341 [Default:CheckIn:E] Running Loop=1 2022-08-19T00:08:40.696Z,1660867720.696 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 197.018815 min 2022-08-19T00:08:40.696Z,1660867720.696 [Default:CheckIn:E] Stopped 2022-08-19T00:08:40.696Z,1660867720.696 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-19T00:08:40.696Z,1660867720.696 [Default:CheckIn] Stopped 2022-08-19T00:08:40.696Z,1660867720.696 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-19T00:08:40.696Z,1660867720.696 [Default:CheckIn](INFO): Running loop #34 2022-08-19T00:08:40.697Z,1660867720.697 [Default:CheckIn] Running Loop=34 2022-08-19T00:08:40.697Z,1660867720.697 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-19T00:08:40.697Z,1660867720.697 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-19T00:08:42.693Z,1660867722.693 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,000841.00,A,3648.14204,N,12147.29687,W,1.963,156.89,190822,,,A*76 2022-08-19T00:08:42.695Z,1660867722.695 [NAL9602](INFO): GPS fix at 20220819T000841: (36.802367, -121.788281) 2022-08-19T00:08:42.705Z,1660867722.705 [Default:CheckIn:Read_GPS] Stopped 2022-08-19T00:08:42.705Z,1660867722.705 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-19T00:08:52.351Z,1660867732.351 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220818T212349/Courier0087.lzma 2022-08-19T00:08:53.354Z,1660867733.354 [DataOverHttps](INFO): Moved sent file to Logs/20220818T212349/Courier0087.lzma.bak 2022-08-19T00:08:53.354Z,1660867733.354 [DataOverHttps](INFO): SBD MOMSN=17113075 2022-08-19T00:09:10.447Z,1660867750.447 [DataOverHttps](INFO): Sending 155 bytes from file Logs/20220818T212349/Express0088.lzma 2022-08-19T00:09:11.450Z,1660867751.450 [DataOverHttps](INFO): Moved sent file to Logs/20220818T212349/Express0088.lzma.bak 2022-08-19T00:09:11.450Z,1660867751.450 [DataOverHttps](INFO): SBD MOMSN=17113078 2022-08-19T00:09:12.625Z,1660867752.625 [Default:CheckIn:Read_Iridium] Stopped 2022-08-19T00:09:12.625Z,1660867752.625 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-19T00:09:12.625Z,1660867752.625 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-19T00:09:13.421Z,1660867753.421 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2022-08-19T00:09:13.500Z,1660867753.500 [NAL9602](ERROR): received: +CSQ:0 OK033, 0, 0, 0, 0 OK 2022-08-19T00:11:15.409Z,1660867875.409 [CommandExec](IMPORTANT): got command quit 2022-08-19T00:11:16.412Z,1660867876.412 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread. 2022-08-19T00:11:16.412Z,1660867876.412 [CommandExec](INFO): Uninitializing the command executive. 2022-08-19T00:11:16.412Z,1660867876.412 [CommandExec](INFO): Uninitializing the command scheduler. 2022-08-19T00:11:16.412Z,1660867876.412 [CommandExec ThreadHandler](INFO): Thread cancelled. 2022-08-19T00:11:16.584Z,1660867876.584 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2022-08-19T00:11:16.584Z,1660867876.584 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2022-08-19T00:11:16.585Z,1660867876.585 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2022-08-19T00:11:16.585Z,1660867876.585 [NavChartDb](INFO): Join timeout helper Thread ID is 3023 2022-08-19T00:11:16.876Z,1660867876.876 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2022-08-19T00:11:16.877Z,1660867876.877 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2022-08-19T00:11:16.881Z,1660867876.881 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2022-08-19T00:11:16.881Z,1660867876.881 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2022-08-19T00:11:16.882Z,1660867876.882 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 3024 2022-08-19T00:11:16.984Z,1660867876.984 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2022-08-19T00:11:16.984Z,1660867876.984 [WetLabsBB2FL](INFO): Powering down 2022-08-19T00:11:16.985Z,1660867876.985 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2022-08-19T00:11:16.988Z,1660867876.988 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler 2022-08-19T00:11:16.988Z,1660867876.988 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2022-08-19T00:11:16.988Z,1660867876.988 [CTD_Seabird](INFO): Join timeout helper Thread ID is 3025 2022-08-19T00:11:17.780Z,1660867877.780 [CTD_Seabird](INFO): Powering down 2022-08-19T00:11:17.792Z,1660867877.792 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread. 2022-08-19T00:11:17.792Z,1660867877.792 [CTD_Seabird](INFO): Powering down 2022-08-19T00:11:17.805Z,1660867877.805 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2022-08-19T00:11:17.812Z,1660867877.812 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2022-08-19T00:11:17.812Z,1660867877.812 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2022-08-19T00:11:17.812Z,1660867877.812 [Radio_Surface](INFO): Join timeout helper Thread ID is 3026 2022-08-19T00:11:18.020Z,1660867878.020 [Radio_Surface](INFO): Powering down 2022-08-19T00:11:18.021Z,1660867878.021 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2022-08-19T00:11:18.021Z,1660867878.021 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2022-08-19T00:11:18.028Z,1660867878.028 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler 2022-08-19T00:11:18.028Z,1660867878.028 [Onboard ThreadHandler](INFO): Thread cancelled. 2022-08-19T00:11:18.029Z,1660867878.029 [Onboard](INFO): Join timeout helper Thread ID is 3027 2022-08-19T00:11:19.136Z,1660867879.136 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread. 2022-08-19T00:11:19.136Z,1660867879.136 [Onboard ThreadHandler](INFO): Thread cancelled. 2022-08-19T00:11:19.141Z,1660867879.141 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler 2022-08-19T00:11:19.141Z,1660867879.141 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2022-08-19T00:11:19.142Z,1660867879.142 [DataOverHttps](INFO): Join timeout helper Thread ID is 3028 2022-08-19T00:11:22.413Z,1660867882.413 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread. 2022-08-19T00:11:22.417Z,1660867882.417 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2022-08-19T00:11:22.438Z,1660867882.438 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2022-08-19T00:11:22.439Z,1660867882.439 [logger ThreadHandler](INFO): Thread cancelled. 2022-08-19T00:11:22.439Z,1660867882.439 [logger](INFO): Join timeout helper Thread ID is 3029 2022-08-19T00:11:22.469Z,1660867882.469 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2022-08-19T00:11:22.469Z,1660867882.469 [logger ThreadHandler](INFO): Thread cancelled. 2022-08-19T00:11:22.477Z,1660867882.477 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2022-08-19T00:11:22.477Z,1660867882.477 [CommandLine ThreadHandler](INFO): Thread cancelled. 2022-08-19T00:11:22.477Z,1660867882.477 [CommandLine](INFO): Join timeout helper Thread ID is 3030 2022-08-19T00:11:22.568Z,1660867882.568 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2022-08-19T00:11:22.568Z,1660867882.568 [CommandLine ThreadHandler](INFO): Thread cancelled. 2022-08-19T00:11:22.576Z,1660867882.576 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler 2022-08-19T00:11:22.577Z,1660867882.577 [CommandExec ThreadHandler](INFO): Thread cancelled. 2022-08-19T00:11:22.577Z,1660867882.577 [CommandExec](INFO): Join timeout helper Thread ID is 3031 2022-08-19T00:11:22.578Z,1660867882.578 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2022-08-19T00:11:22.578Z,1660867882.578 [controlThread ThreadHandler](INFO): Thread cancelled. 2022-08-19T00:11:22.579Z,1660867882.579 [controlThread](INFO): Join timeout helper Thread ID is 3032 2022-08-19T00:11:22.684Z,1660867882.684 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2022-08-19T00:11:22.684Z,1660867882.684 [controlThread](DEBUG): Uninitializing ControlThread 2022-08-19T00:11:22.685Z,1660867882.685 [AHRS_M2](INFO): Powering down 2022-08-19T00:11:22.757Z,1660867882.757 [NAL9602](INFO): Powering down 2022-08-19T00:11:22.759Z,1660867882.759 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator. 2022-08-19T00:11:22.760Z,1660867882.760 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator. 2022-08-19T00:11:22.760Z,1660867882.760 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2022-08-19T00:11:22.761Z,1660867882.761 [MissionManager](INFO): Uninitializing Mission Default 2022-08-19T00:11:22.761Z,1660867882.761 [Default] Stopped 2022-08-19T00:11:22.761Z,1660867882.761 [Default](DEBUG): Aggregate::uninitialize Default 2022-08-19T00:11:22.761Z,1660867882.761 [Default:B.GoToSurface] Stopped 2022-08-19T00:11:22.761Z,1660867882.761 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2022-08-19T00:11:22.761Z,1660867882.761 [Default:CheckIn] Stopped 2022-08-19T00:11:22.761Z,1660867882.761 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-19T00:11:22.762Z,1660867882.762 [Default:CheckIn:C.Wait] Stopped 2022-08-19T00:11:22.762Z,1660867882.762 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-19T00:11:22.765Z,1660867882.765 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2022-08-19T00:11:22.765Z,1660867882.765 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2022-08-19T00:11:22.765Z,1660867882.765 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2022-08-19T00:11:22.766Z,1660867882.766 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2022-08-19T00:11:22.766Z,1660867882.766 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2022-08-19T00:11:22.766Z,1660867882.766 [BuoyancyServo](INFO): Powering down 2022-08-19T00:11:22.780Z,1660867882.780 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2022-08-19T00:11:22.780Z,1660867882.780 [ElevatorServo](INFO): Powering down 2022-08-19T00:11:22.781Z,1660867882.781 [MassServo](DEBUG): Uninitialize Mass Servo. 2022-08-19T00:11:22.781Z,1660867882.781 [MassServo](INFO): Powering down 2022-08-19T00:11:22.782Z,1660867882.782 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2022-08-19T00:11:22.782Z,1660867882.782 [RudderServo](INFO): Powering down 2022-08-19T00:11:22.783Z,1660867882.783 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2022-08-19T00:11:22.783Z,1660867882.783 [ThrusterServo](INFO): Powering down 2022-08-19T00:11:22.784Z,1660867882.784 [SBIT](DEBUG): Uninitialize SBIT Component. 2022-08-19T00:11:22.784Z,1660867882.784 [IBIT](DEBUG): Uninitialize IBIT Component. 2022-08-19T00:11:22.784Z,1660867882.784 [CBIT](DEBUG): Uninitialize CBIT Component. 2022-08-19T00:11:22.785Z,1660867882.785 [CBIT](DEBUG): Powering off loads. 2022-08-19T00:11:22.796Z,1660867882.796 [CBIT](DEBUG): Disabling WDT. 2022-08-19T00:11:22.808Z,1660867882.808 [CBIT](DEBUG): Opening all GF detection circuits. 2022-08-19T00:11:22.809Z,1660867882.809 [controlThread ThreadHandler](INFO): Thread cancelled. 2022-08-19T00:11:22.862Z,1660867882.862 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2022-08-19T00:11:22.865Z,1660867882.865 [Onboard ThreadHandler](INFO): Thread cancelled. 2022-08-19T00:11:22.872Z,1660867882.872 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2022-08-19T00:11:22.945Z,1660867882.945 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2022-08-19T00:11:22.949Z,1660867882.949 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2022-08-19T00:11:22.990Z,1660867882.990 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2022-08-19T00:11:23.069Z,1660867883.069 [logger ThreadHandler](INFO): Thread cancelled.