2023-03-24T16:33:53.357Z,1679675633.357 [CommandExec](IMPORTANT): got command restart logs 2023-03-24T16:34:11.344Z,1679675651.344 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2023-03-24T16:34:42.058Z,1679675682.058 [NAL9602](INFO): Not Powering down - fast GPS 2023-03-24T16:36:02.454Z,1679675762.454 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-03-24T16:36:02.454Z,1679675762.454 [Default:CheckIn:C.Wait] Stopped 2023-03-24T16:36:02.454Z,1679675762.454 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-03-24T16:36:02.454Z,1679675762.454 [Default:CheckIn:D] Running Loop=1 2023-03-24T16:36:02.859Z,1679675762.859 [Default:CheckIn:D] Stopped 2023-03-24T16:36:02.859Z,1679675762.859 [Default:CheckIn:E] Running Loop=1 2023-03-24T16:36:03.268Z,1679675763.268 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 26.350281 min 2023-03-24T16:36:03.268Z,1679675763.268 [Default:CheckIn:E] Stopped 2023-03-24T16:36:03.268Z,1679675763.268 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-03-24T16:36:03.268Z,1679675763.268 [Default:CheckIn] Stopped 2023-03-24T16:36:03.268Z,1679675763.268 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-03-24T16:36:03.269Z,1679675763.269 [Default:CheckIn](INFO): Running loop #5 2023-03-24T16:36:03.269Z,1679675763.269 [Default:CheckIn] Running Loop=5 2023-03-24T16:36:03.269Z,1679675763.269 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-03-24T16:36:03.269Z,1679675763.269 [Default:CheckIn:Read_GPS] Running Loop=1 2023-03-24T16:36:05.275Z,1679675765.275 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163604.00,A,3647.70802,N,12150.83892,W,0.680,34.13,240323,,,A*41 2023-03-24T16:36:05.286Z,1679675765.286 [NAL9602](INFO): GPS fix at 20230324T163604: (36.795134, -121.847315) 2023-03-24T16:36:05.332Z,1679675765.332 [Default:CheckIn:Read_GPS] Stopped 2023-03-24T16:36:05.332Z,1679675765.332 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-03-24T16:36:16.375Z,1679675776.375 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20230323T230021/Courier0112.lzma 2023-03-24T16:36:17.378Z,1679675777.378 [DataOverHttps](INFO): Moved sent file to Logs/20230323T230021/Courier0112.lzma.bak 2023-03-24T16:36:17.378Z,1679675777.378 [DataOverHttps](INFO): SBD MOMSN=17547953 2023-03-24T16:36:33.793Z,1679675793.793 [DataOverHttps](INFO): Sending 268 bytes from file Logs/20230324T163353/Courier0000.lzma 2023-03-24T16:36:34.794Z,1679675794.794 [DataOverHttps](INFO): Moved sent file to Logs/20230324T163353/Courier0000.lzma.bak 2023-03-24T16:36:34.794Z,1679675794.794 [DataOverHttps](INFO): SBD MOMSN=17547955 2023-03-24T16:36:36.078Z,1679675796.078 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2023-03-24T16:36:36.152Z,1679675796.152 [NAL9602](ERROR): received: +CSQ:0 OK518, 2, 0, 0, 0 OK 2023-03-24T16:37:07.123Z,1679675827.123 [DataOverHttps](INFO): Sending 161 bytes from file Logs/20230323T230021/Express0113.lzma 2023-03-24T16:37:08.126Z,1679675828.126 [DataOverHttps](INFO): Moved sent file to Logs/20230323T230021/Express0113.lzma.bak 2023-03-24T16:37:08.126Z,1679675828.126 [DataOverHttps](INFO): SBD MOMSN=17547959 2023-03-24T16:37:24.320Z,1679675844.320 [DataOverHttps](INFO): Sending 485 bytes from file Logs/20230324T163353/Express0001.lzma 2023-03-24T16:37:25.322Z,1679675845.322 [DataOverHttps](INFO): Moved sent file to Logs/20230324T163353/Express0001.lzma.bak 2023-03-24T16:37:25.322Z,1679675845.322 [DataOverHttps](INFO): SBD MOMSN=17547962 2023-03-24T16:37:25.822Z,1679675845.822 [NAL9602](IMPORTANT): SBD MO Status=0, MOMSN=47518, MT Status=1, MTMSN=3537 2023-03-24T16:37:25.822Z,1679675845.822 [NAL9602](INFO): Data available in MT queue 2023-03-24T16:37:26.336Z,1679675846.336 [NAL9602](INFO): Received command: schedule clear;schedule resume 2023-03-24T16:37:26.388Z,1679675846.388 [CommandExec](IMPORTANT): got command schedule clear 2023-03-24T16:37:26.388Z,1679675846.388 [CommandExec](IMPORTANT): Cleared 0 scheduled commands. 2023-03-24T16:37:26.388Z,1679675846.388 [CommandExec](IMPORTANT): got command schedule resume 2023-03-24T16:37:26.388Z,1679675846.388 [CommandExec](IMPORTANT): Scheduling is resumed 2023-03-24T16:37:49.435Z,1679675869.435 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20230324T163353/Express0004.lzma 2023-03-24T16:37:50.438Z,1679675870.438 [DataOverHttps](INFO): Moved sent file to Logs/20230324T163353/Express0004.lzma.bak 2023-03-24T16:37:50.438Z,1679675870.438 [DataOverHttps](INFO): SBD MOMSN=17547972 2023-03-24T16:37:51.743Z,1679675871.743 [Default:CheckIn:Read_Iridium] Stopped 2023-03-24T16:37:51.743Z,1679675871.743 [Default:CheckIn:C.Wait] Running Loop=1 2023-03-24T16:37:51.743Z,1679675871.743 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-03-24T16:37:56.986Z,1679675876.986 [NAL9602](INFO): Not Powering down - fast GPS 2023-03-24T16:37:57.790Z,1679675877.790 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2023-03-24T16:37:57.791Z,1679675877.791 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,.0,0000.0,10 2023-03-24T16:40:50.307Z,1679676050.307 [DVL_micro](ERROR): only read 2 of 4 data items 2023-03-24T16:40:50.307Z,1679676050.307 [DVL_micro](ERROR): Failed to parse::BI,+0290,+00855, 2023-03-24T16:42:52.373Z,1679676172.373 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-03-24T16:42:52.373Z,1679676172.373 [Default:CheckIn:C.Wait] Stopped 2023-03-24T16:42:52.373Z,1679676172.373 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-03-24T16:42:52.373Z,1679676172.373 [Default:CheckIn:D] Running Loop=1 2023-03-24T16:42:52.746Z,1679676172.746 [Default:CheckIn:D] Stopped 2023-03-24T16:42:52.746Z,1679676172.746 [Default:CheckIn:E] Running Loop=1 2023-03-24T16:42:53.147Z,1679676173.147 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 33.181720 min 2023-03-24T16:42:53.147Z,1679676173.147 [Default:CheckIn:E] Stopped 2023-03-24T16:42:53.147Z,1679676173.147 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-03-24T16:42:53.147Z,1679676173.147 [Default:CheckIn] Stopped 2023-03-24T16:42:53.148Z,1679676173.148 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-03-24T16:42:53.148Z,1679676173.148 [Default:CheckIn](INFO): Running loop #6 2023-03-24T16:42:53.148Z,1679676173.148 [Default:CheckIn] Running Loop=6 2023-03-24T16:42:53.148Z,1679676173.148 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-03-24T16:42:53.148Z,1679676173.148 [Default:CheckIn:Read_GPS] Running Loop=1 2023-03-24T16:42:55.164Z,1679676175.164 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164254.00,A,3647.67946,N,12150.71467,W,7.736,92.45,240323,,,D*4A 2023-03-24T16:42:55.166Z,1679676175.166 [NAL9602](INFO): GPS fix at 20230324T164254: (36.794658, -121.845245) 2023-03-24T16:42:55.176Z,1679676175.176 [Default:CheckIn:Read_GPS] Stopped 2023-03-24T16:42:55.177Z,1679676175.177 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-03-24T16:43:03.991Z,1679676183.991 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230324T163353/Courier0006.lzma 2023-03-24T16:43:04.994Z,1679676184.994 [DataOverHttps](INFO): Moved sent file to Logs/20230324T163353/Courier0006.lzma.bak 2023-03-24T16:43:04.994Z,1679676184.994 [DataOverHttps](INFO): SBD MOMSN=17547982 2023-03-24T16:43:27.577Z,1679676207.577 [DataOverHttps](IMPORTANT): SBD MTMSN=20230324T164326 2023-03-24T16:43:36.596Z,1679676216.596 [DataOverHttps](INFO): Sending 261 bytes from file Logs/20230324T163353/Express0007.lzma 2023-03-24T16:43:36.599Z,1679676216.599 [DataOverHttps](INFO): Received command: strobe off 2023-03-24T16:43:36.621Z,1679676216.621 [CommandExec](IMPORTANT): got command strobe off 2023-03-24T16:43:36.622Z,1679676216.622 [CommandExec](IMPORTANT): Deactivating strobe 2023-03-24T16:43:38.055Z,1679676218.055 [DataOverHttps](INFO): Moved sent file to Logs/20230324T163353/Express0007.lzma.bak 2023-03-24T16:43:38.072Z,1679676218.072 [DataOverHttps](INFO): SBD MOMSN=17547988 2023-03-24T16:43:56.207Z,1679676236.207 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20230324T163353/Courier0009.lzma 2023-03-24T16:43:57.210Z,1679676237.210 [DataOverHttps](INFO): Moved sent file to Logs/20230324T163353/Courier0009.lzma.bak 2023-03-24T16:43:57.210Z,1679676237.210 [DataOverHttps](INFO): SBD MOMSN=17547998 2023-03-24T16:44:13.249Z,1679676253.249 [DataOverHttps](INFO): Sending 184 bytes from file Logs/20230324T163353/Express0010.lzma 2023-03-24T16:44:14.250Z,1679676254.250 [DataOverHttps](INFO): Moved sent file to Logs/20230324T163353/Express0010.lzma.bak 2023-03-24T16:44:14.250Z,1679676254.250 [DataOverHttps](INFO): SBD MOMSN=17548000 2023-03-24T16:44:15.626Z,1679676255.626 [Default:CheckIn:Read_Iridium] Stopped 2023-03-24T16:44:15.626Z,1679676255.626 [Default:CheckIn:C.Wait] Running Loop=1 2023-03-24T16:44:15.626Z,1679676255.626 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-03-24T16:44:22.483Z,1679676262.483 [NAL9602](INFO): SBD MO Status=2, MOMSN=47519, MT Status=2, MTMSN=0 2023-03-24T16:44:22.483Z,1679676262.483 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-03-24T16:44:30.562Z,1679676270.562 [NAL9602](INFO): SBD MO Status=2, MOMSN=47519, MT Status=2, MTMSN=0 2023-03-24T16:44:30.562Z,1679676270.562 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-03-24T16:45:39.242Z,1679676339.242 [NAL9602](INFO): SBD MO Status=2, MOMSN=47519, MT Status=2, MTMSN=0 2023-03-24T16:45:39.242Z,1679676339.242 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-03-24T16:46:21.691Z,1679676381.691 [NAL9602](INFO): SBD MO Status=2, MOMSN=47519, MT Status=2, MTMSN=0 2023-03-24T16:46:21.691Z,1679676381.691 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-03-24T16:46:30.598Z,1679676390.598 [NAL9602](INFO): SBD MO Status=2, MOMSN=47519, MT Status=2, MTMSN=0 2023-03-24T16:46:30.598Z,1679676390.598 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-03-24T16:46:39.470Z,1679676399.470 [NAL9602](INFO): SBD MO Status=2, MOMSN=47519, MT Status=2, MTMSN=0 2023-03-24T16:46:39.470Z,1679676399.470 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-03-24T16:46:50.792Z,1679676410.792 [DVL_micro](ERROR): DVL BIT error. See manual. Result code: 2666 2023-03-24T16:46:50.794Z,1679676410.794 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,+9999.99,+9999.99,+9999.99 2023-03-24T16:47:06.150Z,1679676426.150 [NAL9602](INFO): SBD MO Status=2, MOMSN=47519, MT Status=2, MTMSN=0 2023-03-24T16:47:06.150Z,1679676426.150 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-03-24T16:47:21.906Z,1679676441.906 [NAL9602](INFO): SBD MO Status=2, MOMSN=47519, MT Status=2, MTMSN=0 2023-03-24T16:47:21.906Z,1679676441.906 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-03-24T16:47:40.098Z,1679676460.098 [NAL9602](INFO): SBD MO Status=2, MOMSN=47519, MT Status=2, MTMSN=0 2023-03-24T16:47:40.098Z,1679676460.098 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-03-24T16:47:57.056Z,1679676477.056 [NAL9602](INFO): SBD MO Status=2, MOMSN=47519, MT Status=2, MTMSN=0 2023-03-24T16:47:57.056Z,1679676477.056 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-03-24T16:47:57.457Z,1679676477.457 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2023-03-24T16:48:28.162Z,1679676508.162 [NAL9602](INFO): Not Powering down - fast GPS 2023-03-24T16:49:16.302Z,1679676556.302 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-03-24T16:49:16.302Z,1679676556.302 [Default:CheckIn:C.Wait] Stopped 2023-03-24T16:49:16.302Z,1679676556.302 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-03-24T16:49:16.302Z,1679676556.302 [Default:CheckIn:D] Running Loop=1 2023-03-24T16:49:16.707Z,1679676556.707 [Default:CheckIn:D] Stopped 2023-03-24T16:49:16.707Z,1679676556.707 [Default:CheckIn:E] Running Loop=1 2023-03-24T16:49:17.111Z,1679676557.111 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 39.581071 min 2023-03-24T16:49:17.111Z,1679676557.111 [Default:CheckIn:E] Stopped 2023-03-24T16:49:17.111Z,1679676557.111 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-03-24T16:49:17.111Z,1679676557.111 [Default:CheckIn] Stopped 2023-03-24T16:49:17.111Z,1679676557.111 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-03-24T16:49:17.112Z,1679676557.112 [Default:CheckIn](INFO): Running loop #7 2023-03-24T16:49:17.112Z,1679676557.112 [Default:CheckIn] Running Loop=7 2023-03-24T16:49:17.112Z,1679676557.112 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-03-24T16:49:17.112Z,1679676557.112 [Default:CheckIn:Read_GPS] Running Loop=1 2023-03-24T16:49:19.131Z,1679676559.131 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164918.00,A,3648.20143,N,12147.80651,W,25.134,67.02,240323,,,D*7A 2023-03-24T16:49:19.133Z,1679676559.133 [NAL9602](INFO): GPS fix at 20230324T164918: (36.803357, -121.796775) 2023-03-24T16:49:19.143Z,1679676559.143 [Default:CheckIn:Read_GPS] Stopped 2023-03-24T16:49:19.143Z,1679676559.143 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-03-24T16:49:26.435Z,1679676566.435 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230324T163353/Courier0012.lzma 2023-03-24T16:49:27.438Z,1679676567.438 [DataOverHttps](INFO): Moved sent file to Logs/20230324T163353/Courier0012.lzma.bak 2023-03-24T16:49:27.438Z,1679676567.438 [DataOverHttps](INFO): SBD MOMSN=17548021 2023-03-24T16:49:47.059Z,1679676587.059 [DataOverHttps](INFO): Sending 224 bytes from file Logs/20230324T163353/Express0013.lzma 2023-03-24T16:49:48.062Z,1679676588.062 [DataOverHttps](INFO): Moved sent file to Logs/20230324T163353/Express0013.lzma.bak 2023-03-24T16:49:48.062Z,1679676588.062 [DataOverHttps](INFO): SBD MOMSN=17548024 2023-03-24T16:49:49.493Z,1679676589.493 [Default:CheckIn:Read_Iridium] Stopped 2023-03-24T16:49:49.494Z,1679676589.494 [Default:CheckIn:C.Wait] Running Loop=1 2023-03-24T16:49:49.494Z,1679676589.494 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-03-24T16:52:24.186Z,1679676744.186 [NAL9602](INFO): SBD MO Status=2, MOMSN=47519, MT Status=2, MTMSN=0 2023-03-24T16:52:24.186Z,1679676744.186 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-03-24T16:52:46.002Z,1679676766.002 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2023-03-24T16:52:46.002Z,1679676766.002 [DVL_micro](ERROR): Failed to parse: :TS,000000000000011.9,0000.,000 2023-03-24T16:54:21.354Z,1679676861.354 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2023-03-24T16:54:50.047Z,1679676890.047 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-03-24T16:54:50.047Z,1679676890.047 [Default:CheckIn:C.Wait] Stopped 2023-03-24T16:54:50.047Z,1679676890.047 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-03-24T16:54:50.047Z,1679676890.047 [Default:CheckIn:D] Running Loop=1 2023-03-24T16:54:50.467Z,1679676890.467 [Default:CheckIn:D] Stopped 2023-03-24T16:54:50.467Z,1679676890.467 [Default:CheckIn:E] Running Loop=1 2023-03-24T16:54:50.851Z,1679676890.851 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 45.143742 min 2023-03-24T16:54:50.851Z,1679676890.851 [Default:CheckIn:E] Stopped 2023-03-24T16:54:50.851Z,1679676890.851 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-03-24T16:54:50.851Z,1679676890.851 [Default:CheckIn] Stopped 2023-03-24T16:54:50.851Z,1679676890.851 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-03-24T16:54:50.852Z,1679676890.852 [Default:CheckIn](INFO): Running loop #8 2023-03-24T16:54:50.852Z,1679676890.852 [Default:CheckIn] Running Loop=8 2023-03-24T16:54:50.852Z,1679676890.852 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-03-24T16:54:50.852Z,1679676890.852 [Default:CheckIn:Read_GPS] Running Loop=1 2023-03-24T16:54:52.873Z,1679676892.873 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165452.00,A,3648.26225,N,12147.14379,W,4.976,197.44,240323,,,D*7E 2023-03-24T16:54:52.875Z,1679676892.875 [NAL9602](INFO): GPS fix at 20230324T165452: (36.804371, -121.785730) 2023-03-24T16:54:52.885Z,1679676892.885 [Default:CheckIn:Read_GPS] Stopped 2023-03-24T16:54:52.885Z,1679676892.885 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-03-24T16:55:00.539Z,1679676900.539 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230324T163353/Courier0015.lzma 2023-03-24T16:55:01.629Z,1679676901.629 [DataOverHttps](INFO): Moved sent file to Logs/20230324T163353/Courier0015.lzma.bak 2023-03-24T16:55:01.629Z,1679676901.629 [DataOverHttps](INFO): SBD MOMSN=17548036 2023-03-24T16:55:17.524Z,1679676917.524 [DataOverHttps](INFO): Sending 222 bytes from file Logs/20230324T163353/Express0016.lzma 2023-03-24T16:55:18.526Z,1679676918.526 [DataOverHttps](INFO): Moved sent file to Logs/20230324T163353/Express0016.lzma.bak 2023-03-24T16:55:18.526Z,1679676918.526 [DataOverHttps](INFO): SBD MOMSN=17548039 2023-03-24T16:55:19.991Z,1679676919.991 [Default:CheckIn:Read_Iridium] Stopped 2023-03-24T16:55:19.991Z,1679676919.991 [Default:CheckIn:C.Wait] Running Loop=1 2023-03-24T16:55:19.991Z,1679676919.991 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-03-24T16:55:25.629Z,1679676925.629 [NAL9602](INFO): Not Powering down - fast GPS 2023-03-24T16:55:46.239Z,1679676946.239 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2023-03-24T16:55:46.239Z,1679676946.239 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0000.0,1489.0,000 2023-03-24T17:00:20.562Z,1679677220.562 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-03-24T17:00:20.563Z,1679677220.563 [Default:CheckIn:C.Wait] Stopped 2023-03-24T17:00:20.563Z,1679677220.563 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-03-24T17:00:20.563Z,1679677220.563 [Default:CheckIn:D] Running Loop=1 2023-03-24T17:00:20.973Z,1679677220.973 [Default:CheckIn:D] Stopped 2023-03-24T17:00:20.973Z,1679677220.973 [Default:CheckIn:E] Running Loop=1 2023-03-24T17:00:21.388Z,1679677221.388 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 50.652173 min 2023-03-24T17:00:21.388Z,1679677221.388 [Default:CheckIn:E] Stopped 2023-03-24T17:00:21.388Z,1679677221.388 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-03-24T17:00:21.388Z,1679677221.388 [Default:CheckIn] Stopped 2023-03-24T17:00:21.388Z,1679677221.388 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-03-24T17:00:21.389Z,1679677221.389 [Default:CheckIn](INFO): Running loop #9 2023-03-24T17:00:21.389Z,1679677221.389 [Default:CheckIn] Running Loop=9 2023-03-24T17:00:21.389Z,1679677221.389 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-03-24T17:00:21.389Z,1679677221.389 [Default:CheckIn:Read_GPS] Running Loop=1 2023-03-24T17:00:23.386Z,1679677223.386 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170022.00,A,3648.13832,N,12147.20663,W,0.097,295.06,240323,,,D*7F 2023-03-24T17:00:23.388Z,1679677223.388 [NAL9602](INFO): GPS fix at 20230324T170022: (36.802305, -121.786777) 2023-03-24T17:00:23.398Z,1679677223.398 [Default:CheckIn:Read_GPS] Stopped 2023-03-24T17:00:23.398Z,1679677223.398 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-03-24T17:00:30.757Z,1679677230.757 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230324T163353/Courier0018.lzma 2023-03-24T17:00:31.758Z,1679677231.758 [DataOverHttps](INFO): Moved sent file to Logs/20230324T163353/Courier0018.lzma.bak 2023-03-24T17:00:31.758Z,1679677231.758 [DataOverHttps](INFO): SBD MOMSN=17548050 2023-03-24T17:00:50.687Z,1679677250.687 [DataOverHttps](INFO): Sending 146 bytes from file Logs/20230324T163353/Express0019.lzma 2023-03-24T17:00:51.690Z,1679677251.690 [DataOverHttps](INFO): Moved sent file to Logs/20230324T163353/Express0019.lzma.bak 2023-03-24T17:00:51.690Z,1679677251.690 [DataOverHttps](INFO): SBD MOMSN=17548053 2023-03-24T17:00:52.955Z,1679677252.955 [Default:CheckIn:Read_Iridium] Stopped 2023-03-24T17:00:52.955Z,1679677252.955 [Default:CheckIn:C.Wait] Running Loop=1 2023-03-24T17:00:52.955Z,1679677252.955 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-03-24T17:00:54.152Z,1679677254.152 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2023-03-24T17:00:54.236Z,1679677254.236 [NAL9602](ERROR): received: +CSQ:1 OK519, 2, 0, 0, 0 OK 2023-03-24T17:03:33.734Z,1679677413.734 [NAL9602](IMPORTANT): SBD MO Status=0, MOMSN=47519, MT Status=1, MTMSN=3538 2023-03-24T17:03:33.734Z,1679677413.734 [NAL9602](INFO): Data available in MT queue 2023-03-24T17:03:34.397Z,1679677414.397 [NAL9602](INFO): Received command: sched "load Transport/keepstation.tl;set keepstation.MissionTimeout 10 h;set keepstation.Latitude 36.797 degree;set keepstation.Longitude -121.847 degree;set keepstation.Depth 10 m;run" 2023-03-24T17:03:34.487Z,1679677414.487 [CommandExec](IMPORTANT): got command schedule "load Transport/keepstation.tl;set keepstation.MissionTimeout 10 h;set keepstation.Latitude 36.797 degree;set keepstation.Longitude -121.847 degree;set keepstation.Depth 10 m;run" 2023-03-24T17:03:34.487Z,1679677414.487 [CommandExec](IMPORTANT): Scheduled #7: "load Transport/keepstation.tl;set keepstation.MissionTimeout 10 h;set keepstation.Latitude 36.797 degree;set keepstation.Longitude -121.847 degree;set keepstation.Depth 10 m;run", AFTER MISSION 2023-03-24T17:03:34.611Z,1679677414.611 [CommandExec](IMPORTANT): got command load ./Missions/Transport/keepstation.tl 2023-03-24T17:03:34.624Z,1679677414.624 [MissionManager](INFO): Loading Mission from file: ./Missions/Transport/keepstation.tl 2023-03-24T17:03:34.625Z,1679677414.625 [MissionManager](IMPORTANT): Loading Compiled TethysL script from file ./Missions/Transport/keepstation.tx 2023-03-24T17:03:34.772Z,1679677414.772 [MissionManager](INFO): DefineArg keepstation.MissionTimeout = 4.000000 h 2023-03-24T17:03:34.774Z,1679677414.774 [MissionManager](INFO): DefineArg keepstation.NeedCommsTime = 45.000000 min 2023-03-24T17:03:34.777Z,1679677414.777 [MissionManager](INFO): DefineArg keepstation.Latitude = nan arcdeg 2023-03-24T17:03:34.779Z,1679677414.779 [MissionManager](INFO): DefineArg keepstation.Longitude = nan arcdeg 2023-03-24T17:03:34.781Z,1679677414.781 [MissionManager](INFO): DefineArg keepstation.Depth = 30.000000 m 2023-03-24T17:03:34.783Z,1679677414.783 [MissionManager](INFO): DefineArg keepstation.ApproachDepth = 15.000000 m 2023-03-24T17:03:34.793Z,1679677414.793 [MissionManager](INFO): DefineArg keepstation.DepthDeadband = 4.000000 m 2023-03-24T17:03:34.796Z,1679677414.796 [MissionManager](INFO): DefineArg keepstation.Speed = 0.750000 m/s 2023-03-24T17:03:34.798Z,1679677414.798 [MissionManager](INFO): DefineArg keepstation.Radius = 200.000000 m 2023-03-24T17:03:34.800Z,1679677414.800 [MissionManager](INFO): DefineArg keepstation.MaxDepth = 45.000000 m 2023-03-24T17:03:34.802Z,1679677414.802 [MissionManager](INFO): DefineArg keepstation.MinOffshore = 2.000000 km 2023-03-24T17:03:34.803Z,1679677414.803 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/NeedComms.xml 2023-03-24T17:03:35.037Z,1679677415.037 [MissionManager](INFO): DefineArg keepstation:NeedComms.DiveInterval = 3.000000 h 2023-03-24T17:03:35.039Z,1679677415.039 [MissionManager](INFO): DefineArg keepstation:NeedComms.WaitForPitchUp = 10.000000 min 2023-03-24T17:03:35.045Z,1679677415.045 [MissionManager](INFO): DefineArg keepstation:NeedComms.SurfacePitch = 20.000000 arcdeg 2023-03-24T17:03:35.047Z,1679677415.047 [MissionManager](INFO): DefineArg keepstation:NeedComms.SurfaceDepthRate = nan m/s 2023-03-24T17:03:35.083Z,1679677415.083 [MissionManager](INFO): DefineArg keepstation:NeedComms.SurfaceSpeed = 1.000000 m/s 2023-03-24T17:03:35.106Z,1679677415.106 [MissionManager](INFO): DefineArg keepstation:NeedComms.SurfacingTimeout = 1000.000000 s 2023-03-24T17:03:35.112Z,1679677415.112 [MissionManager](INFO): DefineArg keepstation:NeedComms.GPSTimeout = 7.000000 min 2023-03-24T17:03:35.114Z,1679677415.114 [MissionManager](INFO): DefineArg keepstation:NeedComms.CommsTimeout = 30.000000 min 2023-03-24T17:03:35.155Z,1679677415.155 [keepstation:NeedComms:B.GoToSurface](DEBUG): Construct GoToSurface. 2023-03-24T17:03:35.189Z,1679677415.189 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/StandardEnvelopes.xml 2023-03-24T17:03:35.215Z,1679677415.215 [MissionManager](INFO): DefineArg keepstation:StandardEnvelopes.MinAltitude = 5.000000 m 2023-03-24T17:03:35.236Z,1679677415.236 [MissionManager](INFO): DefineArg keepstation:StandardEnvelopes.MaxDepth = 200.000000 m 2023-03-24T17:03:35.238Z,1679677415.238 [MissionManager](INFO): DefineArg keepstation:StandardEnvelopes.MinOffshore = 2000.000000 m 2023-03-24T17:03:35.239Z,1679677415.239 [keepstation:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope. 2023-03-24T17:03:35.253Z,1679677415.253 [keepstation:StandardEnvelopes:B.DepthEnvelope](DEBUG): Construct DepthEnvelope. 2023-03-24T17:03:35.259Z,1679677415.259 [keepstation:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Construct OffshoreEnvelope. 2023-03-24T17:03:35.300Z,1679677415.300 [keepstation:F.Pitch](DEBUG): Construct. 2023-03-24T17:03:35.306Z,1679677415.306 [keepstation:TransitToStation:A.Buoyancy](DEBUG): Construct Buoyancy. 2023-03-24T17:03:35.309Z,1679677415.309 [keepstation:TransitToStation:B.Pitch](DEBUG): Construct. 2023-03-24T17:03:35.322Z,1679677415.322 [keepstation:TransitToStation:C.SetSpeed](DEBUG): Construct. 2023-03-24T17:03:35.324Z,1679677415.324 [keepstation:TransitToStation:Wpt1.Waypoint](DEBUG): Construct Waypoint. 2023-03-24T17:03:35.394Z,1679677415.394 [keepstation:KeepStation:B.Pitch](DEBUG): Construct. 2023-03-24T17:03:35.407Z,1679677415.407 [keepstation:KeepStation:C.KeepStation](DEBUG): Construct KeepStation. 2023-03-24T17:03:35.442Z,1679677415.442 [keepstation:KeepStation:D.Wait](DEBUG): Construct Wait. 2023-03-24T17:03:35.479Z,1679677415.479 [MissionManager](DEBUG): mission keepstation { """ Vehicle transits to desired waypoint (or stays put if none is commanded) and stays within the specified radius. """ arguments { MissionTimeout = 4 hour """ Maximum duration of mission """ NeedCommsTime = 45 minute """ How often to surface for communications """ Latitude = NaN degree """ Latitude of waypoint to hold. If NaN, hold the latitude at start of mission. """ Longitude = NaN degree """ Longitude of waypoint to hold. If NaN, hold the longitude at start of mission. """ Depth = 30 meter """ Depth held during drift mode """ ApproachDepth = 15 meter """ Depth for initial approach to station. """ DepthDeadband = 4 meter """ How much vertical drift from the specified depth is allowed in drift mode """ Speed = 0.75 meter_per_second """ Vehicle transit speed. """ Radius = 200 meter """ Radius of circle around waypoint to hold. """ MaxDepth = 45 meter """ Maximum allowable depth during the mission. """ MinOffshore = 2 kilometer """ Minimum distance from the shoreline to maintain """ } timeout duration=MissionTimeout insert id="NeedComms" Insert/NeedComms.xml assign in sequence NeedComms:DiveInterval = NeedCommsTime insert Insert/StandardEnvelopes.xml assign in sequence StandardEnvelopes:MaxDepth = MaxDepth assign in sequence StandardEnvelopes:MinOffshore = MinOffshore behavior Guidance:Pitch { run in parallel set massPosition = Control:VerticalControl.massDefault } call id="StartingMission" refId="NeedComms" aggregate TransitToStation { """ Need a separate aggregate for transit if we want to specify a different depth for the approach. """ run in sequence behavior Guidance:Buoyancy { run in parallel set position = Control:VerticalControl.buoyancyNeutral } behavior Guidance:Pitch { run in parallel set depth = ApproachDepth } behavior Guidance:SetSpeed { run in parallel set speed = Speed } behavior Guidance:Waypoint id="Wpt1" { run in sequence set latitude = Latitude set longitude = Longitude } } call id="OnStation" refId="NeedComms" aggregate KeepStation { run in sequence assign in parallel Control:VerticalControl.depthDeadband = DepthDeadband behavior Guidance:Pitch { run in parallel set depth = Depth } behavior Guidance:KeepStation { run in parallel set latitude = Latitude set longitude = Longitude set radius = Radius set speed = Speed } behavior Guidance:Wait { """ Due to the way the KeepStation behavior is currently implemented, we must run it in parallel and use a Wait to keep from completing the mission before the timeout expires. However, this new version of the mission uses a top-level timeout so that the entire mission will not run for longer then MissionTimeout. """ run in sequence set duration = MissionTimeout } } } 2023-03-24T17:03:35.479Z,1679677415.479 [CommandExec](IMPORTANT): Loaded ./Missions/Transport/keepstation.tl 2023-03-24T17:03:49.806Z,1679677429.806 [CommandExec](IMPORTANT): got command set keepstation.MissionTimeout 10 hour 2023-03-24T17:03:49.807Z,1679677429.807 [CommandExec](IMPORTANT): got command set keepstation.Latitude 36.797 degree 2023-03-24T17:03:49.808Z,1679677429.808 [CommandExec](IMPORTANT): got command set keepstation.Longitude -121.847 degree 2023-03-24T17:03:49.808Z,1679677429.808 [CommandExec](IMPORTANT): got command set keepstation.Depth 10 meter 2023-03-24T17:03:49.809Z,1679677429.809 [CommandExec](IMPORTANT): got command run 2023-03-24T17:03:49.816Z,1679677429.816 [CommandExec](IMPORTANT): Running 2023-03-24T17:03:50.014Z,1679677430.014 [Default] Stopped 2023-03-24T17:03:50.015Z,1679677430.015 [Default](DEBUG): Aggregate::uninitialize Default 2023-03-24T17:03:50.015Z,1679677430.015 [Default:B.GoToSurface] Stopped 2023-03-24T17:03:50.015Z,1679677430.015 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2023-03-24T17:03:50.015Z,1679677430.015 [Default:CheckIn] Stopped 2023-03-24T17:03:50.015Z,1679677430.015 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-03-24T17:03:50.015Z,1679677430.015 [Default:CheckIn:C.Wait] Stopped 2023-03-24T17:03:50.015Z,1679677430.015 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-03-24T17:03:50.015Z,1679677430.015 [MissionManager](IMPORTANT): Started mission keepstation 2023-03-24T17:03:50.015Z,1679677430.015 [keepstation] Running Loop=1 2023-03-24T17:03:50.016Z,1679677430.016 [keepstation](DEBUG): Aggregate::initialize keepstation 2023-03-24T17:03:50.016Z,1679677430.016 [keepstation:StandardEnvelopes] Running Loop=1 2023-03-24T17:03:50.016Z,1679677430.016 [keepstation:StandardEnvelopes](DEBUG): Aggregate::initialize keepstation:StandardEnvelopes 2023-03-24T17:03:50.016Z,1679677430.016 [keepstation:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1 2023-03-24T17:03:50.016Z,1679677430.016 [keepstation:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent. 2023-03-24T17:03:50.016Z,1679677430.016 [keepstation:StandardEnvelopes:B.DepthEnvelope] Running Loop=1 2023-03-24T17:03:50.016Z,1679677430.016 [keepstation:StandardEnvelopes:B.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent. 2023-03-24T17:03:50.016Z,1679677430.016 [keepstation:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1 2023-03-24T17:03:50.017Z,1679677430.017 [keepstation:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Initialize OffshoreEnvelopeComponent. 2023-03-24T17:03:50.017Z,1679677430.017 [keepstation:F.Pitch] Running Loop=1 2023-03-24T17:03:50.017Z,1679677430.017 [keepstation:F.Pitch](DEBUG): Initialize. 2023-03-24T17:03:50.017Z,1679677430.017 [keepstation:B] Running Loop=1 2023-03-24T17:03:50.017Z,1679677430.017 [keepstation:F.Pitch] Running Loop=1 2023-03-24T17:03:50.018Z,1679677430.018 [keepstation:StandardEnvelopes] Running Loop=1 2023-03-24T17:03:50.018Z,1679677430.018 [keepstation:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1 2023-03-24T17:03:50.026Z,1679677430.026 [keepstation:StandardEnvelopes:B.DepthEnvelope] Running Loop=1 2023-03-24T17:03:50.027Z,1679677430.027 [keepstation:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1 2023-03-24T17:03:50.027Z,1679677430.027 [keepstation:B] Stopped 2023-03-24T17:03:50.027Z,1679677430.027 [keepstation:D] Running Loop=1 2023-03-24T17:03:50.418Z,1679677430.418 [ElevatorOffsetCalculator](INFO): Removing expired estimator for commanded vars: speed 1.00 m/s, pitch 30.00 deg, mass-position 31.31 mm. 2023-03-24T17:03:50.424Z,1679677430.424 [keepstation:D] Stopped 2023-03-24T17:03:50.424Z,1679677430.424 [keepstation:E] Running Loop=1 2023-03-24T17:03:50.844Z,1679677430.844 [keepstation:E] Stopped 2023-03-24T17:03:50.844Z,1679677430.844 [keepstation:StartingMission] Running Loop=1 2023-03-24T17:03:50.845Z,1679677430.845 [keepstation:StartingMission](DEBUG): Aggregate::initialize keepstation:StartingMission 2023-03-24T17:03:51.226Z,1679677431.226 [keepstation:NeedComms] Running Loop=1 2023-03-24T17:03:51.226Z,1679677431.226 [keepstation:NeedComms](DEBUG): Aggregate::initialize keepstation:NeedComms 2023-03-24T17:03:51.226Z,1679677431.226 [keepstation:NeedComms:B.GoToSurface] Running Loop=1 2023-03-24T17:03:51.226Z,1679677431.226 [keepstation:NeedComms:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2023-03-24T17:03:51.226Z,1679677431.226 [keepstation:NeedComms:B.GoToSurface](INFO): Received depth rate setting nan m/s. 2023-03-24T17:03:51.227Z,1679677431.227 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch setting 19.999999 degrees. 2023-03-24T17:03:51.227Z,1679677431.227 [keepstation:NeedComms:B.GoToSurface](INFO): Received speed setting 1.000000 m/s. 2023-03-24T17:03:51.227Z,1679677431.227 [keepstation:NeedComms:B.GoToSurface](INFO): Received surface timeout setting 1000.000000 seconds. 2023-03-24T17:03:51.228Z,1679677431.228 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2023-03-24T17:03:51.228Z,1679677431.228 [keepstation:NeedComms:A] Running Loop=1 2023-03-24T17:03:51.229Z,1679677431.229 [keepstation:NeedComms:A](INFO): last time_fix was: 1679677222.000000 second since 1970/01/01T00:00:00Z 2023-03-24T17:03:51.229Z,1679677431.229 [keepstation:NeedComms:A] Stopped 2023-03-24T17:03:51.636Z,1679677431.636 [keepstation:NeedComms:C] Running Loop=1 2023-03-24T17:03:52.047Z,1679677432.047 [keepstation:NeedComms:C](DEBUG): Initialize ReadDataComponent to sense time_fix 2023-03-24T17:03:53.643Z,1679677433.643 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170352.00,A,3648.13961,N,12147.20838,W,0.000,246.74,240323,,,D*79 2023-03-24T17:03:53.646Z,1679677433.646 [NAL9602](INFO): GPS fix at 20230324T170352: (36.802327, -121.786806) 2023-03-24T17:03:53.664Z,1679677433.664 [keepstation:NeedComms:C] Stopped 2023-03-24T17:03:53.665Z,1679677433.665 [keepstation:NeedComms:D] Running Loop=1 2023-03-24T17:03:54.082Z,1679677434.082 [keepstation:NeedComms:D](DEBUG): Initialize ReadDataComponent to sense platform_communications 2023-03-24T17:04:00.983Z,1679677440.983 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230324T163353/Courier0021.lzma 2023-03-24T17:04:01.986Z,1679677441.986 [DataOverHttps](INFO): Moved sent file to Logs/20230324T163353/Courier0021.lzma.bak 2023-03-24T17:04:01.986Z,1679677441.986 [DataOverHttps](INFO): SBD MOMSN=17548059 2023-03-24T17:04:18.176Z,1679677458.176 [DataOverHttps](INFO): Sending 458 bytes from file Logs/20230324T163353/Express0022.lzma 2023-03-24T17:04:19.178Z,1679677459.178 [DataOverHttps](INFO): Moved sent file to Logs/20230324T163353/Express0022.lzma.bak 2023-03-24T17:04:19.178Z,1679677459.178 [DataOverHttps](INFO): SBD MOMSN=17548065 2023-03-24T17:04:20.723Z,1679677460.723 [keepstation:NeedComms:D] Stopped 2023-03-24T17:04:20.723Z,1679677460.723 [keepstation:NeedComms:E] Running Loop=1 2023-03-24T17:04:21.173Z,1679677461.173 [keepstation:NeedComms:E](DEBUG): Initialize ReadDataComponent to sense time_fix 2023-03-24T17:04:22.736Z,1679677462.736 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170422.00,A,3648.14012,N,12147.20806,W,0.019,246.74,240323,,,D*76 2023-03-24T17:04:22.738Z,1679677462.738 [NAL9602](INFO): GPS fix at 20230324T170422: (36.802335, -121.786801) 2023-03-24T17:04:22.801Z,1679677462.801 [keepstation:NeedComms:E] Stopped 2023-03-24T17:04:22.801Z,1679677462.801 [keepstation:NeedComms](INFO): Completed keepstation:NeedComms 2023-03-24T17:04:22.802Z,1679677462.802 [keepstation:NeedComms] Stopped 2023-03-24T17:04:22.802Z,1679677462.802 [keepstation:NeedComms](DEBUG): Aggregate::uninitialize keepstation:NeedComms 2023-03-24T17:04:22.802Z,1679677462.802 [keepstation:NeedComms:B.GoToSurface] Stopped 2023-03-24T17:04:22.802Z,1679677462.802 [keepstation:NeedComms:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2023-03-24T17:04:23.169Z,1679677463.169 [keepstation:StartingMission](INFO): Completed keepstation:StartingMission 2023-03-24T17:04:23.169Z,1679677463.169 [keepstation:StartingMission] Stopped 2023-03-24T17:04:23.169Z,1679677463.169 [keepstation:StartingMission](DEBUG): Aggregate::uninitialize keepstation:StartingMission 2023-03-24T17:04:23.170Z,1679677463.170 [keepstation:TransitToStation] Running Loop=1 2023-03-24T17:04:23.170Z,1679677463.170 [keepstation:TransitToStation](DEBUG): Aggregate::initialize keepstation:TransitToStation 2023-03-24T17:04:23.170Z,1679677463.170 [keepstation:TransitToStation:A.Buoyancy] Running Loop=1 2023-03-24T17:04:23.170Z,1679677463.170 [keepstation:TransitToStation:A.Buoyancy](DEBUG): Initialize Buoyancy Component. 2023-03-24T17:04:23.170Z,1679677463.170 [keepstation:TransitToStation:B.Pitch] Running Loop=1 2023-03-24T17:04:23.170Z,1679677463.170 [keepstation:TransitToStation:B.Pitch](DEBUG): Initialize. 2023-03-24T17:04:23.170Z,1679677463.170 [keepstation:TransitToStation:C.SetSpeed] Running Loop=1 2023-03-24T17:04:23.170Z,1679677463.170 [keepstation:TransitToStation:C.SetSpeed](DEBUG): Initialize. 2023-03-24T17:04:23.171Z,1679677463.171 [keepstation:TransitToStation:Wpt1.Waypoint] Running Loop=1 2023-03-24T17:04:23.171Z,1679677463.171 [keepstation:TransitToStation:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent. 2023-03-24T17:04:23.171Z,1679677463.171 [keepstation:TransitToStation:Wpt1.Waypoint](IMPORTANT): Navigating to waypoint: 36.797001,-121.847000 2023-03-24T17:04:23.558Z,1679677463.558 [keepstation:TransitToStation:C.SetSpeed] Running Loop=1 2023-03-24T17:04:23.558Z,1679677463.558 [keepstation:TransitToStation:B.Pitch] Running Loop=1 2023-03-24T17:04:23.558Z,1679677463.558 [keepstation:TransitToStation:A.Buoyancy] Running Loop=1 2023-03-24T17:04:55.454Z,1679677495.454 [NAL9602](INFO): Not Powering down - fast GPS 2023-03-24T17:05:59.609Z,1679677559.609 [DataOverHttps](IMPORTANT): SBD MTMSN=20230324T170558 2023-03-24T17:06:07.591Z,1679677567.591 [DataOverHttps](INFO): Received command: stop 2023-03-24T17:06:07.631Z,1679677567.631 [CommandExec](IMPORTANT): got command stop 2023-03-24T17:06:07.631Z,1679677567.631 [CommandExec](IMPORTANT): Scheduling is paused 2023-03-24T17:06:07.632Z,1679677567.632 [Supervisor](INFO): Stop Mission called by CommandExec::commandStop 2023-03-24T17:06:07.886Z,1679677567.886 [MissionManager](INFO): MissionManager is completed. 2023-03-24T17:06:07.886Z,1679677567.886 [MissionManager](INFO): Uninitializing Mission keepstation 2023-03-24T17:06:07.886Z,1679677567.886 [keepstation] Stopped 2023-03-24T17:06:07.886Z,1679677567.886 [keepstation](DEBUG): Aggregate::uninitialize keepstation 2023-03-24T17:06:07.886Z,1679677567.886 [keepstation:StandardEnvelopes] Stopped 2023-03-24T17:06:07.886Z,1679677567.886 [keepstation:StandardEnvelopes](DEBUG): Aggregate::uninitialize keepstation:StandardEnvelopes 2023-03-24T17:06:07.886Z,1679677567.886 [keepstation:StandardEnvelopes:A.AltitudeEnvelope] Stopped 2023-03-24T17:06:07.886Z,1679677567.886 [keepstation:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent. 2023-03-24T17:06:07.887Z,1679677567.887 [keepstation:StandardEnvelopes:B.DepthEnvelope] Stopped 2023-03-24T17:06:07.887Z,1679677567.887 [keepstation:StandardEnvelopes:B.DepthEnvelope](DEBUG): Uninitialize. 2023-03-24T17:06:07.887Z,1679677567.887 [keepstation:StandardEnvelopes:C.OffshoreEnvelope] Stopped 2023-03-24T17:06:07.887Z,1679677567.887 [keepstation:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Uninitialize OffshoreEnvelopeComponent. 2023-03-24T17:06:07.887Z,1679677567.887 [keepstation:F.Pitch] Stopped 2023-03-24T17:06:07.887Z,1679677567.887 [keepstation:TransitToStation] Stopped 2023-03-24T17:06:07.887Z,1679677567.887 [keepstation:TransitToStation](DEBUG): Aggregate::uninitialize keepstation:TransitToStation 2023-03-24T17:06:07.887Z,1679677567.887 [keepstation:TransitToStation:A.Buoyancy] Stopped 2023-03-24T17:06:07.887Z,1679677567.887 [keepstation:TransitToStation:A.Buoyancy](DEBUG): Uninitialize Buoyancy Component. 2023-03-24T17:06:07.887Z,1679677567.887 [keepstation:TransitToStation:B.Pitch] Stopped 2023-03-24T17:06:07.887Z,1679677567.887 [keepstation:TransitToStation:C.SetSpeed] Stopped 2023-03-24T17:06:07.887Z,1679677567.887 [keepstation:TransitToStation:C.SetSpeed](DEBUG): Uninitialize. 2023-03-24T17:06:07.887Z,1679677567.887 [keepstation:TransitToStation:Wpt1.Waypoint] Stopped 2023-03-24T17:06:07.887Z,1679677567.887 [keepstation:TransitToStation:Wpt1.Waypoint](DEBUG): Uninitialize WaypointComponent. 2023-03-24T17:06:08.197Z,1679677568.197 [MissionManager](IMPORTANT): Started mission Default 2023-03-24T17:06:08.197Z,1679677568.197 [Default] Running Loop=1 2023-03-24T17:06:08.197Z,1679677568.197 [Default](DEBUG): Aggregate::initialize Default 2023-03-24T17:06:08.197Z,1679677568.197 [Default:B.GoToSurface] Running Loop=1 2023-03-24T17:06:08.197Z,1679677568.197 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2023-03-24T17:06:08.198Z,1679677568.198 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2023-03-24T17:06:08.198Z,1679677568.198 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2023-03-24T17:06:08.198Z,1679677568.198 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2023-03-24T17:06:08.199Z,1679677568.199 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2023-03-24T17:06:08.199Z,1679677568.199 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2023-03-24T17:06:08.199Z,1679677568.199 [Default:A.Wait] Running Loop=1 2023-03-24T17:06:08.199Z,1679677568.199 [Default:A.Wait](DEBUG): Initialize Wait Component. 2023-03-24T17:06:19.550Z,1679677579.550 [CBIT](IMPORTANT): Beginning ground fault scan 2023-03-24T17:06:21.547Z,1679677581.547 [Default:A.Wait](INFO): Done Waiting. 2023-03-24T17:06:21.547Z,1679677581.547 [Default:A.Wait] Stopped 2023-03-24T17:06:21.547Z,1679677581.547 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2023-03-24T17:06:21.949Z,1679677581.949 [Default:CheckIn] Running Loop=1 2023-03-24T17:06:21.949Z,1679677581.949 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-03-24T17:06:21.949Z,1679677581.949 [Default:CheckIn:Read_GPS] Running Loop=1 2023-03-24T17:06:23.963Z,1679677583.963 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170623.00,A,3648.14192,N,12147.20771,W,0.000,246.74,240323,,,D*7B 2023-03-24T17:06:23.965Z,1679677583.965 [NAL9602](INFO): GPS fix at 20230324T170623: (36.802365, -121.786795) 2023-03-24T17:06:23.975Z,1679677583.975 [Default:CheckIn:Read_GPS] Stopped 2023-03-24T17:06:23.975Z,1679677583.975 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-03-24T17:06:30.467Z,1679677590.467 [CBIT](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): 0.028897 CHAN A1 (24V): 0.037608 CHAN A2 (12V): -0.020519 CHAN A3 (5V): -0.031111 CHAN B0 (3.3V): -0.015441 CHAN B1 (3.15aV): -0.008854 CHAN B2 (3.15bV): -0.005429 CHAN B3 (GND): -0.017483 OPEN: 0.009038 Full Scale: +/- 1 mA 2023-03-24T17:06:31.407Z,1679677591.407 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230324T163353/Courier0024.lzma 2023-03-24T17:06:32.410Z,1679677592.410 [DataOverHttps](INFO): Moved sent file to Logs/20230324T163353/Courier0024.lzma.bak 2023-03-24T17:06:32.410Z,1679677592.410 [DataOverHttps](INFO): SBD MOMSN=17548085 2023-03-24T17:06:51.956Z,1679677611.956 [DataOverHttps](INFO): Sending 329 bytes from file Logs/20230324T163353/Express0025.lzma 2023-03-24T17:06:52.958Z,1679677612.958 [DataOverHttps](INFO): Moved sent file to Logs/20230324T163353/Express0025.lzma.bak 2023-03-24T17:06:52.958Z,1679677612.958 [DataOverHttps](INFO): SBD MOMSN=17548088 2023-03-24T17:06:54.333Z,1679677614.333 [Default:CheckIn:Read_Iridium] Stopped 2023-03-24T17:06:54.333Z,1679677614.333 [Default:CheckIn:C.Wait] Running Loop=1 2023-03-24T17:06:54.333Z,1679677614.333 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-03-24T17:07:35.094Z,1679677655.094 [NAL9602](IMPORTANT): SBD MO Status=0, MOMSN=47520, MT Status=1, MTMSN=3539 2023-03-24T17:07:35.094Z,1679677655.094 [NAL9602](INFO): Data available in MT queue 2023-03-24T17:07:35.584Z,1679677655.584 [NAL9602](INFO): Received command: stop 2023-03-24T17:07:35.685Z,1679677655.685 [CommandExec](IMPORTANT): got command stop 2023-03-24T17:08:06.201Z,1679677686.201 [NAL9602](INFO): Not Powering down - fast GPS 2023-03-24T17:10:51.884Z,1679677851.884 [DVL_micro](ERROR): Failed to parse: 12,-00024,-02421,+00000,I 2023-03-24T17:10:53.103Z,1679677853.103 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2023-03-24T17:10:53.106Z,1679677853.106 [BPC1](INFO): Received data from all battery sticks. 2023-03-24T17:11:54.967Z,1679677914.967 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-03-24T17:11:54.967Z,1679677914.967 [Default:CheckIn:C.Wait] Stopped 2023-03-24T17:11:54.967Z,1679677914.967 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-03-24T17:11:54.968Z,1679677914.968 [Default:CheckIn:D] Running Loop=1 2023-03-24T17:11:55.391Z,1679677915.391 [Default:CheckIn:D] Stopped 2023-03-24T17:11:55.391Z,1679677915.391 [Default:CheckIn:E] Running Loop=1 2023-03-24T17:11:55.773Z,1679677915.773 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 5.786568 min 2023-03-24T17:11:55.773Z,1679677915.773 [Default:CheckIn:E] Stopped 2023-03-24T17:11:55.773Z,1679677915.773 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-03-24T17:11:55.773Z,1679677915.773 [Default:CheckIn] Stopped 2023-03-24T17:11:55.773Z,1679677915.773 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-03-24T17:11:55.774Z,1679677915.774 [Default:CheckIn](INFO): Running loop #2 2023-03-24T17:11:55.774Z,1679677915.774 [Default:CheckIn] Running Loop=2 2023-03-24T17:11:55.774Z,1679677915.774 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-03-24T17:11:55.774Z,1679677915.774 [Default:CheckIn:Read_GPS] Running Loop=1 2023-03-24T17:11:57.798Z,1679677917.798 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171157.00,A,3648.14315,N,12147.20677,W,0.019,246.74,240323,,,D*7C 2023-03-24T17:11:57.801Z,1679677917.801 [NAL9602](INFO): GPS fix at 20230324T171157: (36.802386, -121.786779) 2023-03-24T17:11:57.811Z,1679677917.811 [Default:CheckIn:Read_GPS] Stopped 2023-03-24T17:11:57.811Z,1679677917.811 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-03-24T17:12:05.811Z,1679677925.811 [DataOverHttps](INFO): Sending 202 bytes from file Logs/20230324T163353/Courier0030.lzma 2023-03-24T17:12:06.814Z,1679677926.814 [DataOverHttps](INFO): Moved sent file to Logs/20230324T163353/Courier0030.lzma.bak 2023-03-24T17:12:06.814Z,1679677926.814 [DataOverHttps](INFO): SBD MOMSN=17548105 2023-03-24T17:12:22.825Z,1679677942.825 [DataOverHttps](INFO): Sending 354 bytes from file Logs/20230324T163353/Express0031.lzma 2023-03-24T17:12:23.822Z,1679677943.822 [DataOverHttps](INFO): Moved sent file to Logs/20230324T163353/Express0031.lzma.bak 2023-03-24T17:12:23.822Z,1679677943.822 [DataOverHttps](INFO): SBD MOMSN=17548108 2023-03-24T17:12:25.289Z,1679677945.289 [Default:CheckIn:Read_Iridium] Stopped 2023-03-24T17:12:25.289Z,1679677945.289 [Default:CheckIn:C.Wait] Running Loop=1 2023-03-24T17:12:25.289Z,1679677945.289 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-03-24T17:13:56.989Z,1679678036.989 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2023-03-24T17:13:56.989Z,1679678036.989 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+12.9,009.0,000 2023-03-24T17:17:00.497Z,1679678220.497 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2023-03-24T17:17:25.959Z,1679678245.959 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-03-24T17:17:25.959Z,1679678245.959 [Default:CheckIn:C.Wait] Stopped 2023-03-24T17:17:25.959Z,1679678245.959 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-03-24T17:17:25.960Z,1679678245.960 [Default:CheckIn:D] Running Loop=1 2023-03-24T17:17:26.364Z,1679678246.364 [Default:CheckIn:D] Stopped 2023-03-24T17:17:26.364Z,1679678246.364 [Default:CheckIn:E] Running Loop=1 2023-03-24T17:17:26.774Z,1679678246.774 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 11.302780 min 2023-03-24T17:17:26.775Z,1679678246.775 [Default:CheckIn:E] Stopped 2023-03-24T17:17:26.775Z,1679678246.775 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-03-24T17:17:26.775Z,1679678246.775 [Default:CheckIn] Stopped 2023-03-24T17:17:26.775Z,1679678246.775 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-03-24T17:17:26.775Z,1679678246.775 [Default:CheckIn](INFO): Running loop #3 2023-03-24T17:17:26.775Z,1679678246.775 [Default:CheckIn] Running Loop=3 2023-03-24T17:17:26.775Z,1679678246.775 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-03-24T17:17:26.775Z,1679678246.775 [Default:CheckIn:Read_GPS] Running Loop=1 2023-03-24T17:17:28.782Z,1679678248.782 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171728.00,A,3648.17266,N,12147.28107,W,0.078,223.62,240323,,,D*7F 2023-03-24T17:17:28.786Z,1679678248.786 [NAL9602](INFO): GPS fix at 20230324T171728: (36.802878, -121.788018) 2023-03-24T17:17:28.814Z,1679678248.814 [Default:CheckIn:Read_GPS] Stopped 2023-03-24T17:17:28.814Z,1679678248.814 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-03-24T17:17:39.803Z,1679678259.803 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230324T163353/Courier0033.lzma 2023-03-24T17:17:40.808Z,1679678260.808 [DataOverHttps](INFO): Moved sent file to Logs/20230324T163353/Courier0033.lzma.bak 2023-03-24T17:17:40.808Z,1679678260.808 [DataOverHttps](INFO): SBD MOMSN=17548125 2023-03-24T17:17:57.236Z,1679678277.236 [DataOverHttps](INFO): Sending 220 bytes from file Logs/20230324T163353/Express0034.lzma 2023-03-24T17:17:58.238Z,1679678278.238 [DataOverHttps](INFO): Moved sent file to Logs/20230324T163353/Express0034.lzma.bak 2023-03-24T17:17:58.238Z,1679678278.238 [DataOverHttps](INFO): SBD MOMSN=17548128 2023-03-24T17:17:59.564Z,1679678279.564 [Default:CheckIn:Read_Iridium] Stopped 2023-03-24T17:17:59.565Z,1679678279.565 [Default:CheckIn:C.Wait] Running Loop=1 2023-03-24T17:17:59.565Z,1679678279.565 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-03-24T17:18:01.574Z,1679678281.574 [NAL9602](INFO): Not Powering down - fast GPS 2023-03-24T17:18:51.324Z,1679678331.324 [DVL_micro](ERROR): only read 3 of 4 data items 2023-03-24T17:18:51.324Z,1679678331.324 [DVL_micro](ERROR): Failed to parse: :BI,-02808,-00213,-02017,+ 2023-03-24T17:20:12.212Z,1679678412.212 [DVL_micro](ERROR): only read 3 of 4 data items 2023-03-24T17:20:12.212Z,1679678412.212 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,+9999.99,+99999.99 2023-03-24T17:23:00.315Z,1679678580.315 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-03-24T17:23:00.315Z,1679678580.315 [Default:CheckIn:C.Wait] Stopped 2023-03-24T17:23:00.315Z,1679678580.315 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-03-24T17:23:00.315Z,1679678580.315 [Default:CheckIn:D] Running Loop=1 2023-03-24T17:23:00.720Z,1679678580.720 [Default:CheckIn:D] Stopped 2023-03-24T17:23:00.720Z,1679678580.720 [Default:CheckIn:E] Running Loop=1 2023-03-24T17:23:01.118Z,1679678581.118 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 16.875373 min 2023-03-24T17:23:01.118Z,1679678581.118 [Default:CheckIn:E] Stopped 2023-03-24T17:23:01.118Z,1679678581.118 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-03-24T17:23:01.118Z,1679678581.118 [Default:CheckIn] Stopped 2023-03-24T17:23:01.118Z,1679678581.118 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-03-24T17:23:01.119Z,1679678581.119 [Default:CheckIn](INFO): Running loop #4 2023-03-24T17:23:01.119Z,1679678581.119 [Default:CheckIn] Running Loop=4 2023-03-24T17:23:01.119Z,1679678581.119 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-03-24T17:23:01.119Z,1679678581.119 [Default:CheckIn:Read_GPS] Running Loop=1 2023-03-24T17:23:03.134Z,1679678583.134 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172302.00,A,3648.16790,N,12147.28246,W,1.166,344.21,240323,,,D*73 2023-03-24T17:23:03.137Z,1679678583.137 [NAL9602](INFO): GPS fix at 20230324T172302: (36.802798, -121.788041) 2023-03-24T17:23:03.147Z,1679678583.147 [Default:CheckIn:Read_GPS] Stopped 2023-03-24T17:23:03.147Z,1679678583.147 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-03-24T17:23:10.431Z,1679678590.431 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230324T163353/Courier0036.lzma 2023-03-24T17:23:11.434Z,1679678591.434 [DataOverHttps](INFO): Moved sent file to Logs/20230324T163353/Courier0036.lzma.bak 2023-03-24T17:23:11.434Z,1679678591.434 [DataOverHttps](INFO): SBD MOMSN=17548143 2023-03-24T17:23:27.319Z,1679678607.319 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20230324T163353/Express0037.lzma 2023-03-24T17:23:28.322Z,1679678608.322 [DataOverHttps](INFO): Moved sent file to Logs/20230324T163353/Express0037.lzma.bak 2023-03-24T17:23:28.322Z,1679678608.322 [DataOverHttps](INFO): SBD MOMSN=17548146 2023-03-24T17:23:29.836Z,1679678609.836 [Default:CheckIn:Read_Iridium] Stopped 2023-03-24T17:23:29.836Z,1679678609.836 [Default:CheckIn:C.Wait] Running Loop=1 2023-03-24T17:23:29.836Z,1679678609.836 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-03-24T17:23:33.902Z,1679678613.902 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2023-03-24T17:23:33.976Z,1679678613.976 [NAL9602](ERROR): received: +CSQ:0 OKCJ*´ˆö 2023-03-24T17:26:32.547Z,1679678792.547 [DVL_micro](ERROR): only read 2 of 4 data items 2023-03-24T17:26:32.547Z,1679678792.547 [DVL_micro](ERROR): Failed to parse::RD,+9999.999,+9999.999 2023-03-24T17:28:05.517Z,1679678885.517 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2023-03-24T17:28:30.570Z,1679678910.570 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-03-24T17:28:30.570Z,1679678910.570 [Default:CheckIn:C.Wait] Stopped 2023-03-24T17:28:30.570Z,1679678910.570 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-03-24T17:28:30.570Z,1679678910.570 [Default:CheckIn:D] Running Loop=1 2023-03-24T17:28:30.975Z,1679678910.975 [Default:CheckIn:D] Stopped 2023-03-24T17:28:30.975Z,1679678910.975 [Default:CheckIn:E] Running Loop=1 2023-03-24T17:28:31.390Z,1679678911.390 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 22.379637 min 2023-03-24T17:28:31.390Z,1679678911.390 [Default:CheckIn:E] Stopped 2023-03-24T17:28:31.390Z,1679678911.390 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-03-24T17:28:31.390Z,1679678911.390 [Default:CheckIn] Stopped 2023-03-24T17:28:31.390Z,1679678911.390 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-03-24T17:28:31.391Z,1679678911.391 [Default:CheckIn](INFO): Running loop #5 2023-03-24T17:28:31.391Z,1679678911.391 [Default:CheckIn] Running Loop=5 2023-03-24T17:28:31.391Z,1679678911.391 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-03-24T17:28:31.391Z,1679678911.391 [Default:CheckIn:Read_GPS] Running Loop=1 2023-03-24T17:28:33.390Z,1679678913.390 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172832.00,A,3648.16633,N,12147.28292,W,0.156,344.21,240323,,,D*78 2023-03-24T17:28:33.392Z,1679678913.392 [NAL9602](INFO): GPS fix at 20230324T172832: (36.802772, -121.788049) 2023-03-24T17:28:33.402Z,1679678913.402 [Default:CheckIn:Read_GPS] Stopped 2023-03-24T17:28:33.402Z,1679678913.402 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-03-24T17:28:41.007Z,1679678921.007 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230324T163353/Courier0039.lzma 2023-03-24T17:28:42.010Z,1679678922.010 [DataOverHttps](INFO): Moved sent file to Logs/20230324T163353/Courier0039.lzma.bak 2023-03-24T17:28:42.010Z,1679678922.010 [DataOverHttps](INFO): SBD MOMSN=17548156 2023-03-24T17:28:57.803Z,1679678937.803 [DataOverHttps](INFO): Sending 205 bytes from file Logs/20230324T163353/Express0040.lzma 2023-03-24T17:28:58.806Z,1679678938.806 [DataOverHttps](INFO): Moved sent file to Logs/20230324T163353/Express0040.lzma.bak 2023-03-24T17:28:58.806Z,1679678938.806 [DataOverHttps](INFO): SBD MOMSN=17548159 2023-03-24T17:29:00.072Z,1679678940.072 [Default:CheckIn:Read_Iridium] Stopped 2023-03-24T17:29:00.072Z,1679678940.072 [Default:CheckIn:C.Wait] Running Loop=1 2023-03-24T17:29:00.072Z,1679678940.072 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-03-24T17:29:05.713Z,1679678945.713 [NAL9602](INFO): Not Powering down - fast GPS 2023-03-24T17:31:25.216Z,1679679085.216 [DropWeight](CRITICAL): DROP WEIGHT MISSING. 2023-03-24T17:31:25.217Z,1679679085.217 [DropWeight] Hardware Fault, FailCount= 1 2023-03-24T17:31:25.217Z,1679679085.217 [DropWeight](ERROR): Hardware Fault 2023-03-24T17:31:25.234Z,1679679085.234 [CommandExec](FAULT): Scheduling is paused 2023-03-24T17:31:25.235Z,1679679085.235 [CBIT](INFO): Critical error at 20230324T173125 2023-03-24T17:31:25.237Z,1679679085.237 [CBIT](ERROR): Hardware Fault in component: DropWeight 2023-03-24T17:31:25.238Z,1679679085.238 [CBIT](CRITICAL): Hardware Fault in component: DropWeight 2023-03-24T17:31:25.647Z,1679679085.647 [CBIT](INFO): Critical error at 20230324T173125 2023-03-24T17:31:54.781Z,1679679114.781 [DVL_micro](ERROR): only read 0 of 4 data items 2023-03-24T17:31:54.782Z,1679679114.782 [DVL_micro](ERROR): Failed to parse: :BI-04286,-02255,+0000,+00000000.00,+00000000.00,+00000000.00,9999.99,000.00 2023-03-24T17:34:00.529Z,1679679240.529 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-03-24T17:34:00.529Z,1679679240.529 [Default:CheckIn:C.Wait] Stopped 2023-03-24T17:34:00.529Z,1679679240.529 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-03-24T17:34:00.530Z,1679679240.530 [Default:CheckIn:D] Running Loop=1 2023-03-24T17:34:00.929Z,1679679240.929 [Default:CheckIn:D] Stopped 2023-03-24T17:34:00.929Z,1679679240.929 [Default:CheckIn:E] Running Loop=1 2023-03-24T17:34:01.361Z,1679679241.361 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 27.878868 min 2023-03-24T17:34:01.361Z,1679679241.361 [Default:CheckIn:E] Stopped 2023-03-24T17:34:01.361Z,1679679241.361 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-03-24T17:34:01.361Z,1679679241.361 [Default:CheckIn] Stopped 2023-03-24T17:34:01.361Z,1679679241.361 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-03-24T17:34:01.361Z,1679679241.361 [Default:CheckIn](INFO): Running loop #6 2023-03-24T17:34:01.361Z,1679679241.361 [Default:CheckIn] Running Loop=6 2023-03-24T17:34:01.361Z,1679679241.361 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-03-24T17:34:01.361Z,1679679241.361 [Default:CheckIn:Read_GPS] Running Loop=1 2023-03-24T17:34:03.353Z,1679679243.353 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173402.00,A,3648.16898,N,12147.28042,W,0.544,278.04,240323,,,D*78 2023-03-24T17:34:03.355Z,1679679243.355 [NAL9602](INFO): GPS fix at 20230324T173402: (36.802816, -121.788007) 2023-03-24T17:34:03.365Z,1679679243.365 [Default:CheckIn:Read_GPS] Stopped 2023-03-24T17:34:03.365Z,1679679243.365 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-03-24T17:34:11.023Z,1679679251.023 [DataOverHttps](INFO): Sending 178 bytes from file Logs/20230324T163353/Courier0042.lzma 2023-03-24T17:34:12.026Z,1679679252.026 [DataOverHttps](INFO): Moved sent file to Logs/20230324T163353/Courier0042.lzma.bak 2023-03-24T17:34:12.026Z,1679679252.026 [DataOverHttps](INFO): SBD MOMSN=17548170 2023-03-24T17:34:28.403Z,1679679268.403 [DataOverHttps](INFO): Sending 158 bytes from file Logs/20230324T163353/Express0043.lzma 2023-03-24T17:34:29.406Z,1679679269.406 [DataOverHttps](INFO): Moved sent file to Logs/20230324T163353/Express0043.lzma.bak 2023-03-24T17:34:29.406Z,1679679269.406 [DataOverHttps](INFO): SBD MOMSN=17548175 2023-03-24T17:34:30.835Z,1679679270.835 [Default:CheckIn:Read_Iridium] Stopped 2023-03-24T17:34:30.835Z,1679679270.835 [Default:CheckIn:C.Wait] Running Loop=1 2023-03-24T17:34:30.835Z,1679679270.835 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-03-24T17:34:34.106Z,1679679274.106 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2023-03-24T17:34:34.196Z,1679679274.196 [NAL9602](ERROR): received: +CSQ:0 OKCJ*´ˆö 2023-03-24T17:39:05.431Z,1679679545.431 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2023-03-24T17:39:28.454Z,1679679568.454 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2023-03-24T17:39:28.454Z,1679679568.454 [DVL_micro](ERROR): Failed to parse: :TS,000000000000013.7,0000.0,1489.0,000 2023-03-24T17:39:31.289Z,1679679571.289 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-03-24T17:39:31.289Z,1679679571.289 [Default:CheckIn:C.Wait] Stopped 2023-03-24T17:39:31.289Z,1679679571.289 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-03-24T17:39:31.289Z,1679679571.289 [Default:CheckIn:D] Running Loop=1 2023-03-24T17:39:31.691Z,1679679571.691 [Default:CheckIn:D] Stopped 2023-03-24T17:39:31.691Z,1679679571.691 [Default:CheckIn:E] Running Loop=1 2023-03-24T17:39:32.121Z,1679679572.121 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 33.391569 min 2023-03-24T17:39:32.121Z,1679679572.121 [Default:CheckIn:E] Stopped 2023-03-24T17:39:32.122Z,1679679572.122 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-03-24T17:39:32.122Z,1679679572.122 [Default:CheckIn] Stopped 2023-03-24T17:39:32.123Z,1679679572.123 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-03-24T17:39:32.123Z,1679679572.123 [Default:CheckIn](INFO): Running loop #7 2023-03-24T17:39:32.128Z,1679679572.128 [Default:CheckIn] Running Loop=7 2023-03-24T17:39:32.128Z,1679679572.128 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-03-24T17:39:32.128Z,1679679572.128 [Default:CheckIn:Read_GPS] Running Loop=1 2023-03-24T17:39:34.106Z,1679679574.106 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173933.00,A,3648.16367,N,12147.27481,W,1.127,243.10,240323,,,A*70 2023-03-24T17:39:34.116Z,1679679574.116 [NAL9602](INFO): GPS fix at 20230324T173933: (36.802728, -121.787914) 2023-03-24T17:39:34.152Z,1679679574.152 [Default:CheckIn:Read_GPS] Stopped 2023-03-24T17:39:34.152Z,1679679574.152 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-03-24T17:39:44.227Z,1679679584.227 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230324T163353/Courier0045.lzma 2023-03-24T17:39:45.230Z,1679679585.230 [DataOverHttps](INFO): Moved sent file to Logs/20230324T163353/Courier0045.lzma.bak 2023-03-24T17:39:45.230Z,1679679585.230 [DataOverHttps](INFO): SBD MOMSN=17548185 2023-03-24T17:40:01.219Z,1679679601.219 [DataOverHttps](INFO): Sending 207 bytes from file Logs/20230324T163353/Express0046.lzma 2023-03-24T17:40:02.222Z,1679679602.222 [DataOverHttps](INFO): Moved sent file to Logs/20230324T163353/Express0046.lzma.bak 2023-03-24T17:40:02.222Z,1679679602.222 [DataOverHttps](INFO): SBD MOMSN=17548188 2023-03-24T17:40:03.763Z,1679679603.763 [Default:CheckIn:Read_Iridium] Stopped 2023-03-24T17:40:03.763Z,1679679603.763 [Default:CheckIn:C.Wait] Running Loop=1 2023-03-24T17:40:03.763Z,1679679603.763 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-03-24T17:40:06.208Z,1679679606.208 [NAL9602](INFO): Not Powering down - fast GPS 2023-03-24T17:42:53.547Z,1679679773.547 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2023-03-24T17:42:53.547Z,1679679773.547 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+13.8,00000,000 2023-03-24T17:45:04.453Z,1679679904.453 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-03-24T17:45:04.453Z,1679679904.453 [Default:CheckIn:C.Wait] Stopped 2023-03-24T17:45:04.453Z,1679679904.453 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-03-24T17:45:04.454Z,1679679904.454 [Default:CheckIn:D] Running Loop=1 2023-03-24T17:45:04.855Z,1679679904.855 [Default:CheckIn:D] Stopped 2023-03-24T17:45:04.855Z,1679679904.855 [Default:CheckIn:E] Running Loop=1 2023-03-24T17:45:05.278Z,1679679905.278 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 38.944299 min 2023-03-24T17:45:05.279Z,1679679905.279 [Default:CheckIn:E] Stopped 2023-03-24T17:45:05.279Z,1679679905.279 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-03-24T17:45:05.279Z,1679679905.279 [Default:CheckIn] Stopped 2023-03-24T17:45:05.279Z,1679679905.279 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-03-24T17:45:05.279Z,1679679905.279 [Default:CheckIn](INFO): Running loop #8 2023-03-24T17:45:05.279Z,1679679905.279 [Default:CheckIn] Running Loop=8 2023-03-24T17:45:05.279Z,1679679905.279 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-03-24T17:45:05.279Z,1679679905.279 [Default:CheckIn:Read_GPS] Running Loop=1 2023-03-24T17:45:07.274Z,1679679907.274 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174506.00,A,3648.16910,N,12147.27623,W,1.205,243.10,240323,,,A*7E 2023-03-24T17:45:07.277Z,1679679907.277 [NAL9602](INFO): GPS fix at 20230324T174506: (36.802818, -121.787937) 2023-03-24T17:45:07.287Z,1679679907.287 [Default:CheckIn:Read_GPS] Stopped 2023-03-24T17:45:07.287Z,1679679907.287 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-03-24T17:45:15.379Z,1679679915.379 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230324T163353/Courier0048.lzma 2023-03-24T17:45:16.382Z,1679679916.382 [DataOverHttps](INFO): Moved sent file to Logs/20230324T163353/Courier0048.lzma.bak 2023-03-24T17:45:16.382Z,1679679916.382 [DataOverHttps](INFO): SBD MOMSN=17548199 2023-03-24T17:45:32.338Z,1679679932.338 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20230324T163353/Express0049.lzma 2023-03-24T17:45:33.338Z,1679679933.338 [DataOverHttps](INFO): Moved sent file to Logs/20230324T163353/Express0049.lzma.bak 2023-03-24T17:45:33.338Z,1679679933.338 [DataOverHttps](INFO): SBD MOMSN=17548202 2023-03-24T17:45:34.763Z,1679679934.763 [Default:CheckIn:Read_Iridium] Stopped 2023-03-24T17:45:34.763Z,1679679934.763 [Default:CheckIn:C.Wait] Running Loop=1 2023-03-24T17:45:34.763Z,1679679934.763 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-03-24T17:45:37.986Z,1679679937.986 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2023-03-24T17:45:38.060Z,1679679938.060 [NAL9602](ERROR): received: +CSQ:0 OKCJ*´ˆö 2023-03-24T17:46:25.282Z,1679679985.282 [CBIT](INFO): Clearing failed state for component DropWeight 2023-03-24T17:46:25.282Z,1679679985.282 [DropWeight] No Fault, FailCount= 1 2023-03-24T17:47:44.456Z,1679680064.456 [CommandExec](IMPORTANT): got command quit 2023-03-24T17:47:45.464Z,1679680065.464 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread. 2023-03-24T17:47:45.464Z,1679680065.464 [CommandExec](INFO): Uninitializing the command executive. 2023-03-24T17:47:45.464Z,1679680065.464 [CommandExec](INFO): Uninitializing the command scheduler. 2023-03-24T17:47:45.464Z,1679680065.464 [CommandExec ThreadHandler](INFO): Thread cancelled. 2023-03-24T17:47:45.517Z,1679680065.517 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2023-03-24T17:47:45.518Z,1679680065.518 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2023-03-24T17:47:45.518Z,1679680065.518 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2023-03-24T17:47:45.518Z,1679680065.518 [NavChartDb](INFO): Join timeout helper Thread ID is 9530 2023-03-24T17:47:45.764Z,1679680065.764 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2023-03-24T17:47:45.765Z,1679680065.765 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2023-03-24T17:47:45.772Z,1679680065.772 [ComponentRegistry](INFO): Shutting down DAT ThreadHandler 2023-03-24T17:47:45.772Z,1679680065.772 [DAT ThreadHandler](INFO): Thread cancelled. 2023-03-24T17:47:45.772Z,1679680065.772 [DAT](INFO): Join timeout helper Thread ID is 9531 2023-03-24T17:47:45.896Z,1679680065.896 [DAT](INFO): Powering down 2023-03-24T17:47:45.968Z,1679680065.968 [DAT ThreadHandler](INFO): Uninitializing protected caller thread. 2023-03-24T17:47:45.969Z,1679680065.969 [DAT](INFO): Powering down 2023-03-24T17:47:45.970Z,1679680065.970 [DAT ThreadHandler](INFO): Thread cancelled. 2023-03-24T17:47:45.980Z,1679680065.980 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2023-03-24T17:47:45.980Z,1679680065.980 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2023-03-24T17:47:45.980Z,1679680065.980 [Radio_Surface](INFO): Join timeout helper Thread ID is 9532 2023-03-24T17:47:46.256Z,1679680066.256 [Radio_Surface](INFO): Powering down 2023-03-24T17:47:46.257Z,1679680066.257 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2023-03-24T17:47:46.257Z,1679680066.257 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2023-03-24T17:47:46.260Z,1679680066.260 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler 2023-03-24T17:47:46.260Z,1679680066.260 [Onboard ThreadHandler](INFO): Thread cancelled. 2023-03-24T17:47:46.260Z,1679680066.260 [Onboard](INFO): Join timeout helper Thread ID is 9533 2023-03-24T17:47:46.516Z,1679680066.516 [DataOverHttps](INFO): Radio surface powered OFF, will not connect. 2023-03-24T17:47:48.596Z,1679680068.596 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread. 2023-03-24T17:47:48.596Z,1679680068.596 [Onboard ThreadHandler](INFO): Thread cancelled. 2023-03-24T17:47:48.616Z,1679680068.616 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler 2023-03-24T17:47:48.616Z,1679680068.616 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2023-03-24T17:47:48.616Z,1679680068.616 [DataOverHttps](INFO): Join timeout helper Thread ID is 9534 2023-03-24T17:47:49.529Z,1679680069.529 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread. 2023-03-24T17:47:49.529Z,1679680069.529 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2023-03-24T17:47:49.537Z,1679680069.537 [ComponentRegistry](INFO): Shutting down BackseatComponent ThreadHandler 2023-03-24T17:47:49.537Z,1679680069.537 [BackseatComponent ThreadHandler](INFO): Thread cancelled. 2023-03-24T17:47:49.537Z,1679680069.537 [BackseatComponent](INFO): Join timeout helper Thread ID is 9535 2023-03-24T17:47:49.744Z,1679680069.744 [BackseatComponent ThreadHandler](INFO): Uninitializing protected caller thread. 2023-03-24T17:47:49.744Z,1679680069.744 [BackseatComponent ThreadHandler](INFO): Thread cancelled. 2023-03-24T17:47:49.767Z,1679680069.767 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2023-03-24T17:47:49.767Z,1679680069.767 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2023-03-24T17:47:49.769Z,1679680069.769 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 9536 2023-03-24T17:47:50.260Z,1679680070.260 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2023-03-24T17:47:50.260Z,1679680070.260 [WetLabsBB2FL](INFO): Powering down 2023-03-24T17:47:50.261Z,1679680070.261 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2023-03-24T17:47:50.273Z,1679680070.273 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler 2023-03-24T17:47:50.273Z,1679680070.273 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2023-03-24T17:47:50.273Z,1679680070.273 [CTD_Seabird](INFO): Join timeout helper Thread ID is 9537 2023-03-24T17:47:50.964Z,1679680070.964 [CTD_Seabird](INFO): Powering down 2023-03-24T17:47:50.980Z,1679680070.980 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread. 2023-03-24T17:47:50.981Z,1679680070.981 [CTD_Seabird](INFO): Powering down 2023-03-24T17:47:50.992Z,1679680070.992 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2023-03-24T17:47:51.009Z,1679680071.009 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2023-03-24T17:47:51.009Z,1679680071.009 [logger ThreadHandler](INFO): Thread cancelled. 2023-03-24T17:47:51.009Z,1679680071.009 [logger](INFO): Join timeout helper Thread ID is 9538 2023-03-24T17:47:51.024Z,1679680071.024 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2023-03-24T17:47:51.024Z,1679680071.024 [logger ThreadHandler](INFO): Thread cancelled. 2023-03-24T17:47:51.029Z,1679680071.029 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2023-03-24T17:47:51.029Z,1679680071.029 [CommandLine ThreadHandler](INFO): Thread cancelled. 2023-03-24T17:47:51.029Z,1679680071.029 [CommandLine](INFO): Join timeout helper Thread ID is 9539 2023-03-24T17:47:51.108Z,1679680071.108 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2023-03-24T17:47:51.108Z,1679680071.108 [CommandLine ThreadHandler](INFO): Thread cancelled. 2023-03-24T17:47:51.131Z,1679680071.131 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler 2023-03-24T17:47:51.132Z,1679680071.132 [CommandExec ThreadHandler](INFO): Thread cancelled. 2023-03-24T17:47:51.133Z,1679680071.133 [CommandExec](INFO): Join timeout helper Thread ID is 9540 2023-03-24T17:47:51.134Z,1679680071.134 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2023-03-24T17:47:51.134Z,1679680071.134 [controlThread ThreadHandler](INFO): Thread cancelled. 2023-03-24T17:47:51.135Z,1679680071.135 [controlThread](INFO): Join timeout helper Thread ID is 9541 2023-03-24T17:47:51.272Z,1679680071.272 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2023-03-24T17:47:51.272Z,1679680071.272 [controlThread](DEBUG): Uninitializing ControlThread 2023-03-24T17:47:51.273Z,1679680071.273 [AHRS_M2](INFO): Powering down 2023-03-24T17:47:51.416Z,1679680071.416 [DVL_micro](INFO): Powering down 2023-03-24T17:47:51.417Z,1679680071.417 [MultiRay](INFO): Powering down. 2023-03-24T17:47:51.418Z,1679680071.418 [NAL9602](INFO): Powering down 2023-03-24T17:47:51.419Z,1679680071.419 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator. 2023-03-24T17:47:51.420Z,1679680071.420 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator. 2023-03-24T17:47:51.421Z,1679680071.421 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2023-03-24T17:47:51.421Z,1679680071.421 [MissionManager](INFO): Uninitializing Mission Default 2023-03-24T17:47:51.422Z,1679680071.422 [Default] Stopped 2023-03-24T17:47:51.422Z,1679680071.422 [Default](DEBUG): Aggregate::uninitialize Default 2023-03-24T17:47:51.422Z,1679680071.422 [Default:B.GoToSurface] Stopped 2023-03-24T17:47:51.422Z,1679680071.422 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2023-03-24T17:47:51.422Z,1679680071.422 [Default:CheckIn] Stopped 2023-03-24T17:47:51.422Z,1679680071.422 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-03-24T17:47:51.422Z,1679680071.422 [Default:CheckIn:C.Wait] Stopped 2023-03-24T17:47:51.422Z,1679680071.422 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-03-24T17:47:51.425Z,1679680071.425 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2023-03-24T17:47:51.425Z,1679680071.425 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2023-03-24T17:47:51.426Z,1679680071.426 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2023-03-24T17:47:51.426Z,1679680071.426 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2023-03-24T17:47:51.426Z,1679680071.426 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2023-03-24T17:47:51.426Z,1679680071.426 [BuoyancyServo](INFO): Powering down 2023-03-24T17:47:51.440Z,1679680071.440 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2023-03-24T17:47:51.440Z,1679680071.440 [ElevatorServo](INFO): Powering down 2023-03-24T17:47:51.441Z,1679680071.441 [MassServo](DEBUG): Uninitialize Mass Servo. 2023-03-24T17:47:51.441Z,1679680071.441 [MassServo](INFO): Powering down 2023-03-24T17:47:51.442Z,1679680071.442 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2023-03-24T17:47:51.442Z,1679680071.442 [RudderServo](INFO): Powering down 2023-03-24T17:47:51.443Z,1679680071.443 [ThrusterHE](DEBUG): Uninitialize Thruster Servo. 2023-03-24T17:47:51.443Z,1679680071.443 [ThrusterHE](INFO): Powering down 2023-03-24T17:47:51.444Z,1679680071.444 [SBIT](DEBUG): Uninitialize SBIT Component. 2023-03-24T17:47:51.444Z,1679680071.444 [IBIT](DEBUG): Uninitialize IBIT Component. 2023-03-24T17:47:51.444Z,1679680071.444 [CBIT](DEBUG): Uninitialize CBIT Component. 2023-03-24T17:47:51.445Z,1679680071.445 [CBIT](DEBUG): Powering off loads. 2023-03-24T17:47:51.456Z,1679680071.456 [CBIT](DEBUG): Disabling WDT. 2023-03-24T17:47:51.468Z,1679680071.468 [CBIT](DEBUG): Opening all GF detection circuits. 2023-03-24T17:47:51.469Z,1679680071.469 [controlThread ThreadHandler](INFO): Thread cancelled. 2023-03-24T17:47:51.503Z,1679680071.503 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2023-03-24T17:47:51.509Z,1679680071.509 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2023-03-24T17:47:51.538Z,1679680071.538 [DAT ThreadHandler](INFO): Thread cancelled. 2023-03-24T17:47:51.542Z,1679680071.542 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2023-03-24T17:47:51.544Z,1679680071.544 [Onboard ThreadHandler](INFO): Thread cancelled. 2023-03-24T17:47:51.552Z,1679680071.552 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2023-03-24T17:47:51.596Z,1679680071.596 [BackseatComponent ThreadHandler](INFO): Thread cancelled. 2023-03-24T17:47:51.645Z,1679680071.645 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2023-03-24T17:47:51.720Z,1679680071.720 [logger ThreadHandler](INFO): Thread cancelled.