2021-08-04T17:28:47.424Z,1628098127.424 [CommandLine](IMPORTANT): got command restart logs 2021-08-04T17:28:56.087Z,1628098136.087 [NAL9602](INFO): SBD MO Status=2, MOMSN=41922, MT Status=2, MTMSN=0 2021-08-04T17:28:56.088Z,1628098136.088 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-04T17:29:03.761Z,1628098143.761 [NAL9602](INFO): SBD MO Status=2, MOMSN=41922, MT Status=2, MTMSN=0 2021-08-04T17:29:03.761Z,1628098143.761 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-04T17:29:21.944Z,1628098161.944 [NAL9602](INFO): SBD MO Status=2, MOMSN=41922, MT Status=2, MTMSN=0 2021-08-04T17:29:21.944Z,1628098161.944 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-04T17:29:30.839Z,1628098170.839 [NAL9602](INFO): SBD MO Status=2, MOMSN=41922, MT Status=2, MTMSN=0 2021-08-04T17:29:30.839Z,1628098170.839 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-04T17:29:49.055Z,1628098189.055 [NAL9602](INFO): SBD MO Status=2, MOMSN=41922, MT Status=2, MTMSN=0 2021-08-04T17:29:49.055Z,1628098189.055 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-04T17:29:56.711Z,1628098196.711 [NAL9602](INFO): SBD MO Status=2, MOMSN=41922, MT Status=2, MTMSN=0 2021-08-04T17:29:56.711Z,1628098196.711 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-04T17:30:05.203Z,1628098205.203 [NAL9602](INFO): SBD MO Status=2, MOMSN=41922, MT Status=2, MTMSN=0 2021-08-04T17:30:05.203Z,1628098205.203 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-04T17:30:23.371Z,1628098223.371 [NAL9602](INFO): SBD MO Status=2, MOMSN=41922, MT Status=2, MTMSN=0 2021-08-04T17:30:23.371Z,1628098223.371 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-04T17:30:25.438Z,1628098225.438 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-08-04T17:25:25.1Z 2021-08-04T17:30:25.438Z,1628098225.438 [Default:CheckIn:Read_GPS] Stopped 2021-08-04T17:30:25.438Z,1628098225.438 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-04T17:30:29.038Z,1628098229.038 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-08-04T17:30:34.155Z,1628098234.155 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20210804T130744/Courier0127.lzma 2021-08-04T17:30:35.161Z,1628098235.161 [DataOverHttps](INFO): Moved sent file to Logs/20210804T130744/Courier0127.lzma.bak 2021-08-04T17:30:35.162Z,1628098235.162 [DataOverHttps](INFO): SBD MOMSN=15823091 2021-08-04T17:30:56.400Z,1628098256.400 [DataOverHttps](INFO): Sending 150 bytes from file Logs/20210804T172847/Courier0000.lzma 2021-08-04T17:30:57.402Z,1628098257.402 [DataOverHttps](INFO): Moved sent file to Logs/20210804T172847/Courier0000.lzma.bak 2021-08-04T17:30:57.402Z,1628098257.402 [DataOverHttps](INFO): SBD MOMSN=15823099 2021-08-04T17:30:59.801Z,1628098259.801 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-04T17:31:14.340Z,1628098274.340 [DataOverHttps](INFO): Sending 238 bytes from file Logs/20210804T130744/Express0128.lzma 2021-08-04T17:31:15.343Z,1628098275.343 [DataOverHttps](INFO): Moved sent file to Logs/20210804T130744/Express0128.lzma.bak 2021-08-04T17:31:15.343Z,1628098275.343 [DataOverHttps](INFO): SBD MOMSN=15823105 2021-08-04T17:31:32.572Z,1628098292.572 [DataOverHttps](INFO): Sending 311 bytes from file Logs/20210804T172847/Express0001.lzma 2021-08-04T17:31:33.578Z,1628098293.578 [DataOverHttps](INFO): Moved sent file to Logs/20210804T172847/Express0001.lzma.bak 2021-08-04T17:31:33.578Z,1628098293.578 [DataOverHttps](INFO): SBD MOMSN=15823110 2021-08-04T17:31:35.428Z,1628098295.428 [Default:CheckIn:Read_Iridium] Stopped 2021-08-04T17:31:35.428Z,1628098295.428 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-04T17:31:35.428Z,1628098295.428 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-04T17:34:03.640Z,1628098443.640 [CommandLine](IMPORTANT): got command failComponent 2021-08-04T17:34:03.640Z,1628098443.640 [CommandLine](IMPORTANT): Failed components: 2021-08-04T17:34:03.641Z,1628098443.641 [CommandLine](IMPORTANT): No failed Components. 2021-08-04T17:36:36.132Z,1628098596.132 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-04T17:36:36.132Z,1628098596.132 [Default:CheckIn:C.Wait] Stopped 2021-08-04T17:36:36.132Z,1628098596.132 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-04T17:36:36.133Z,1628098596.133 [Default:CheckIn:D] Running Loop=1 2021-08-04T17:36:36.566Z,1628098596.566 [Default:CheckIn:D] Stopped 2021-08-04T17:36:36.566Z,1628098596.566 [Default:CheckIn:E] Running Loop=1 2021-08-04T17:36:37.090Z,1628098597.090 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 265.827360 min 2021-08-04T17:36:37.090Z,1628098597.090 [Default:CheckIn:E] Stopped 2021-08-04T17:36:37.090Z,1628098597.090 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-04T17:36:37.090Z,1628098597.090 [Default:CheckIn] Stopped 2021-08-04T17:36:37.090Z,1628098597.090 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-04T17:36:37.090Z,1628098597.090 [Default:CheckIn](INFO): Running loop #42 2021-08-04T17:36:37.090Z,1628098597.090 [Default:CheckIn] Running Loop=42 2021-08-04T17:36:37.091Z,1628098597.091 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-04T17:36:37.091Z,1628098597.091 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-04T17:36:38.557Z,1628098598.557 [NAL9602](FAULT): GPS failed to acquire within timeout. 2021-08-04T17:36:38.557Z,1628098598.557 [NAL9602] Data Fault, FailCount= 4 2021-08-04T17:36:38.557Z,1628098598.557 [NAL9602](ERROR): Data Fault 2021-08-04T17:36:38.649Z,1628098598.649 [CBIT](ERROR): Data Fault in component: NAL9602 2021-08-04T17:36:38.975Z,1628098598.975 [NAL9602](INFO): Powering down 2021-08-04T17:36:39.788Z,1628098599.788 [CBIT](INFO): Clearing failed state for component NAL9602 2021-08-04T17:36:39.788Z,1628098599.788 [NAL9602] No Fault, FailCount= 4 2021-08-04T17:37:09.261Z,1628098629.261 [NAL9602](INFO): Powering up NAL9602 2021-08-04T17:37:20.174Z,1628098640.174 [NAL9602](INFO): NAL9602 initialized 2021-08-04T17:37:35.934Z,1628098655.934 [NAL9602](INFO): SBD MO Status=2, MOMSN=41922, MT Status=2, MTMSN=0 2021-08-04T17:37:35.934Z,1628098655.934 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-04T17:37:44.862Z,1628098664.862 [NAL9602](INFO): SBD MO Status=2, MOMSN=41922, MT Status=2, MTMSN=0 2021-08-04T17:37:44.862Z,1628098664.862 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-04T17:37:53.317Z,1628098673.317 [NAL9602](INFO): SBD MO Status=2, MOMSN=41922, MT Status=2, MTMSN=0 2021-08-04T17:37:53.318Z,1628098673.318 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-04T17:38:01.799Z,1628098681.799 [NAL9602](INFO): SBD MO Status=2, MOMSN=41922, MT Status=2, MTMSN=0 2021-08-04T17:38:01.800Z,1628098681.800 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-04T17:38:28.057Z,1628098708.057 [NAL9602](INFO): SBD MO Status=2, MOMSN=41922, MT Status=2, MTMSN=0 2021-08-04T17:38:28.058Z,1628098708.058 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-04T17:38:45.876Z,1628098725.876 [NAL9602](INFO): SBD MO Status=2, MOMSN=41922, MT Status=2, MTMSN=0 2021-08-04T17:38:45.876Z,1628098725.876 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-04T17:38:53.519Z,1628098733.519 [NAL9602](INFO): SBD MO Status=2, MOMSN=41922, MT Status=2, MTMSN=0 2021-08-04T17:38:53.519Z,1628098733.519 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-04T17:39:02.411Z,1628098742.411 [NAL9602](INFO): SBD MO Status=2, MOMSN=41922, MT Status=2, MTMSN=0 2021-08-04T17:39:02.411Z,1628098742.411 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-04T17:39:09.688Z,1628098749.688 [NAL9602](INFO): SBD MO Status=2, MOMSN=41922, MT Status=2, MTMSN=0 2021-08-04T17:39:09.688Z,1628098749.688 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-04T17:39:18.585Z,1628098758.585 [NAL9602](INFO): SBD MO Status=2, MOMSN=41922, MT Status=2, MTMSN=0 2021-08-04T17:39:18.585Z,1628098758.585 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-04T17:39:22.612Z,1628098762.612 [DVL_micro](ERROR): only read 3 of 4 data items 2021-08-04T17:39:22.613Z,1628098762.613 [DVL_micro](ERROR): Failed to parse: :RD,+0000.30,+0000.629,+0002.97 2021-08-04T17:39:36.764Z,1628098776.764 [NAL9602](INFO): SBD MO Status=2, MOMSN=41922, MT Status=2, MTMSN=0 2021-08-04T17:39:36.765Z,1628098776.765 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-04T17:39:54.181Z,1628098794.181 [NAL9602](INFO): SBD MO Status=2, MOMSN=41922, MT Status=2, MTMSN=0 2021-08-04T17:39:54.181Z,1628098794.181 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-04T17:40:07.059Z,1628098807.059 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2021-08-04T17:40:10.697Z,1628098810.697 [NAL9602](INFO): SBD MO Status=2, MOMSN=41922, MT Status=2, MTMSN=0 2021-08-04T17:40:10.698Z,1628098810.698 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-04T17:40:18.775Z,1628098818.775 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2021-08-04T17:40:19.611Z,1628098819.611 [NAL9602](INFO): SBD MO Status=2, MOMSN=41922, MT Status=2, MTMSN=0 2021-08-04T17:40:19.612Z,1628098819.612 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-04T17:40:27.673Z,1628098827.673 [NAL9602](INFO): SBD MO Status=2, MOMSN=41922, MT Status=2, MTMSN=0 2021-08-04T17:40:27.673Z,1628098827.673 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-04T17:40:30.087Z,1628098830.087 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2021-08-04T17:40:36.177Z,1628098836.177 [NAL9602](INFO): SBD MO Status=2, MOMSN=41922, MT Status=2, MTMSN=0 2021-08-04T17:40:36.177Z,1628098836.177 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-04T17:40:41.818Z,1628098841.818 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2021-08-04T17:40:53.130Z,1628098853.130 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2021-08-04T17:41:04.442Z,1628098864.442 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2021-08-04T17:41:09.703Z,1628098869.703 [NAL9602](INFO): SBD MO Status=2, MOMSN=41922, MT Status=2, MTMSN=0 2021-08-04T17:41:09.703Z,1628098869.703 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-04T17:41:15.783Z,1628098875.783 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2021-08-04T17:41:18.191Z,1628098878.191 [NAL9602](INFO): SBD MO Status=2, MOMSN=41922, MT Status=2, MTMSN=0 2021-08-04T17:41:18.191Z,1628098878.191 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-04T17:41:24.249Z,1628098884.249 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2021-08-04T17:41:24.249Z,1628098884.249 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+26.,1489.0,000 2021-08-04T17:41:27.079Z,1628098887.079 [NAL9602](INFO): SBD MO Status=2, MOMSN=41922, MT Status=2, MTMSN=0 2021-08-04T17:41:27.080Z,1628098887.080 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-04T17:41:27.875Z,1628098887.875 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2021-08-04T17:41:35.559Z,1628098895.559 [NAL9602](INFO): SBD MO Status=2, MOMSN=41922, MT Status=2, MTMSN=0 2021-08-04T17:41:35.568Z,1628098895.568 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-04T17:41:37.220Z,1628098897.220 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-08-04T17:36:37.1Z 2021-08-04T17:41:37.221Z,1628098897.221 [Default:CheckIn:Read_GPS] Stopped 2021-08-04T17:41:37.221Z,1628098897.221 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-04T17:41:44.105Z,1628098904.105 [NAL9602](INFO): SBD MO Status=2, MOMSN=41922, MT Status=2, MTMSN=0 2021-08-04T17:41:44.105Z,1628098904.105 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-04T17:41:47.047Z,1628098907.047 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20210804T172847/Courier0005.lzma 2021-08-04T17:41:48.054Z,1628098908.054 [DataOverHttps](INFO): Moved sent file to Logs/20210804T172847/Courier0005.lzma.bak 2021-08-04T17:41:48.054Z,1628098908.054 [DataOverHttps](INFO): SBD MOMSN=15823197 2021-08-04T17:42:01.463Z,1628098921.463 [NAL9602](INFO): SBD MO Status=2, MOMSN=41922, MT Status=2, MTMSN=0 2021-08-04T17:42:01.463Z,1628098921.463 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-04T17:42:05.385Z,1628098925.385 [DataOverHttps](INFO): Sending 402 bytes from file Logs/20210804T172847/Express0004.lzma 2021-08-04T17:42:06.386Z,1628098926.386 [DataOverHttps](INFO): Moved sent file to Logs/20210804T172847/Express0004.lzma.bak 2021-08-04T17:42:06.386Z,1628098926.386 [DataOverHttps](INFO): SBD MOMSN=15823202 2021-08-04T17:42:07.965Z,1628098927.965 [Default:CheckIn:Read_Iridium] Stopped 2021-08-04T17:42:07.965Z,1628098927.965 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-04T17:42:07.966Z,1628098927.966 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-04T17:42:19.664Z,1628098939.664 [NAL9602](INFO): SBD MO Status=2, MOMSN=41922, MT Status=2, MTMSN=0 2021-08-04T17:42:19.664Z,1628098939.664 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-04T17:42:24.096Z,1628098944.096 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-08-04T17:42:54.830Z,1628098974.830 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-04T17:43:05.389Z,1628098985.389 [DVL_micro](ERROR): Failed to parse: :SA,-00.16,+06.26,308.9 2021-08-04T17:44:34.684Z,1628099074.684 [DVL_micro](ERROR): Failed to parse: :0,+00000,00000,I 2021-08-04T17:44:36.206Z,1628099076.206 [CommandLine](IMPORTANT): got command show variable limitFwd 2021-08-04T17:44:36.481Z,1628099076.481 [CommandLine](IMPORTANT): VerticalControl.massPositionLimitFwd (millimeter) 2021-08-04T17:44:39.576Z,1628099079.576 [DVL_micro](ERROR): only read 1 of 4 data items 2021-08-04T17:44:39.576Z,1628099079.576 [DVL_micro](ERROR): Failed to parse: :BI,+00000+00000,+00000,I 2021-08-04T17:44:58.689Z,1628099098.689 [CommandLine](IMPORTANT): got command get VerticalControl.massPositionLimitFwd centimeter 2021-08-04T17:44:58.689Z,1628099098.689 [CommandLine](IMPORTANT): VerticalControl.massPositionLimitFwd 4.000000 cm 2021-08-04T17:45:07.263Z,1628099107.263 [CommandLine](IMPORTANT): got command get platform_mass_position centimeter 2021-08-04T17:45:07.263Z,1628099107.263 [CommandLine](IMPORTANT): platform_mass_position 0.894604 cm 2021-08-04T17:45:55.246Z,1628099155.246 [CommandLine](IMPORTANT): got command maintain control VerticalControl.massPositionAction 3.000000 centimeter 2021-08-04T17:45:55.250Z,1628099155.250 [ComponentRegistry](DEBUG): SyncComponent "Maintain_VerticalControl.massPositionAction" handled in the control thread. 2021-08-04T17:45:55.655Z,1628099155.655 [controlThread](DEBUG): Component order: CycleStarter,ESPComponent,PAR_Licor,AHRS_M2,BPC1,Depth_Keller,DropWeight,DVL_micro,NAL9602,Power24vConverter,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,Maintain_VerticalControl.massPositionAction,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2021-08-04T17:46:25.494Z,1628099185.494 [BPC1](ERROR): BPC1A: No match for serial number 1717 in BPC1A's battery stick inventory (sticks 1-32 in onboard configuration file). 2021-08-04T17:46:38.433Z,1628099198.433 [BPC1](ERROR): Battery stick #38 (s/n: 0139) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x4AD0. 2021-08-04T17:46:38.434Z,1628099198.434 [BPC1](INFO): Calculating totals. Valid battery stick count: 55. Valid reserve battery stick count: 5. 2021-08-04T17:46:38.437Z,1628099198.437 [BPC1](INFO): Received data from all battery sticks. 2021-08-04T17:47:08.733Z,1628099228.733 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-04T17:47:08.733Z,1628099228.733 [Default:CheckIn:C.Wait] Stopped 2021-08-04T17:47:08.733Z,1628099228.733 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-04T17:47:08.734Z,1628099228.734 [Default:CheckIn:D] Running Loop=1 2021-08-04T17:47:09.150Z,1628099229.150 [Default:CheckIn:D] Stopped 2021-08-04T17:47:09.150Z,1628099229.150 [Default:CheckIn:E] Running Loop=1 2021-08-04T17:47:09.538Z,1628099229.538 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 276.370410 min 2021-08-04T17:47:09.539Z,1628099229.539 [Default:CheckIn:E] Stopped 2021-08-04T17:47:09.539Z,1628099229.539 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-04T17:47:09.539Z,1628099229.539 [Default:CheckIn] Stopped 2021-08-04T17:47:09.539Z,1628099229.539 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-04T17:47:09.539Z,1628099229.539 [Default:CheckIn](INFO): Running loop #43 2021-08-04T17:47:09.539Z,1628099229.539 [Default:CheckIn] Running Loop=43 2021-08-04T17:47:09.539Z,1628099229.539 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-04T17:47:09.539Z,1628099229.539 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-04T17:47:11.558Z,1628099231.558 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174712.00,A,4149.69355,N,08324.71609,W,0.292,247.77,040821,,,A*7D 2021-08-04T17:47:11.561Z,1628099231.561 [NAL9602](INFO): GPS fix at 20210804T174712: (41.828226, -83.411935) 2021-08-04T17:47:11.573Z,1628099231.573 [UniversalFixResidualReporter](INFO): Fix residual: 35.4 %DT, over the last 789.5 m. Residual distance 279.5 m at bearing 94.6 degrees. Fix at (41.8282, -83.4119) with 47.5 m made good. 2021-08-04T17:47:11.573Z,1628099231.573 [Default:CheckIn:Read_GPS] Stopped 2021-08-04T17:47:11.573Z,1628099231.573 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-04T17:47:19.252Z,1628099239.252 [DataOverHttps](INFO): Sending 342 bytes from file Logs/20210804T172847/Courier0009.lzma 2021-08-04T17:47:20.254Z,1628099240.254 [DataOverHttps](INFO): Moved sent file to Logs/20210804T172847/Courier0009.lzma.bak 2021-08-04T17:47:20.254Z,1628099240.254 [DataOverHttps](INFO): SBD MOMSN=15823250 2021-08-04T17:47:26.127Z,1628099246.127 [CommandLine](IMPORTANT): got command maintain control VerticalControl.massPositionAction 3.500000 2021-08-04T17:47:26.127Z,1628099246.127 [CommandLine](FAULT): Incomplete syntax. Try: help maintain 2021-08-04T17:47:30.948Z,1628099250.948 [NAL9602](INFO): SBD MO Status=0, MOMSN=41922, MT Status=0, MTMSN=0 2021-08-04T17:47:30.948Z,1628099250.948 [NAL9602](INFO): No messages in MT queue 2021-08-04T17:47:44.405Z,1628099264.405 [DataOverHttps](INFO): Sending 431 bytes from file Logs/20210804T172847/Express0010.lzma 2021-08-04T17:47:45.406Z,1628099265.406 [DataOverHttps](INFO): Moved sent file to Logs/20210804T172847/Express0010.lzma.bak 2021-08-04T17:47:45.406Z,1628099265.406 [DataOverHttps](INFO): SBD MOMSN=15823256 2021-08-04T17:47:47.234Z,1628099267.234 [Default:CheckIn:Read_Iridium] Stopped 2021-08-04T17:47:47.234Z,1628099267.234 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-04T17:47:47.234Z,1628099267.234 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-04T17:47:55.697Z,1628099275.697 [DVL_micro](ERROR): Failed to parse: 00000000026.1,0000.0,148 2021-08-04T17:47:55.812Z,1628099275.812 [CommandLine](IMPORTANT): got command maintain control VerticalControl.massPositionAction 3.500000 centimeter 2021-08-04T17:48:01.349Z,1628099281.349 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-04T17:48:19.574Z,1628099299.574 [CommandLine](IMPORTANT): got command maintain control VerticalControl.massPositionAction 3.800000 centimeter 2021-08-04T17:52:47.907Z,1628099567.907 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-04T17:52:47.907Z,1628099567.907 [Default:CheckIn:C.Wait] Stopped 2021-08-04T17:52:47.907Z,1628099567.907 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-04T17:52:47.908Z,1628099567.908 [Default:CheckIn:D] Running Loop=1 2021-08-04T17:52:48.306Z,1628099568.306 [Default:CheckIn:D] Stopped 2021-08-04T17:52:48.306Z,1628099568.306 [Default:CheckIn:E] Running Loop=1 2021-08-04T17:52:48.716Z,1628099568.716 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 282.023014 min 2021-08-04T17:52:48.716Z,1628099568.716 [Default:CheckIn:E] Stopped 2021-08-04T17:52:48.717Z,1628099568.717 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-04T17:52:48.717Z,1628099568.717 [Default:CheckIn] Stopped 2021-08-04T17:52:48.717Z,1628099568.717 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-04T17:52:48.717Z,1628099568.717 [Default:CheckIn](INFO): Running loop #44 2021-08-04T17:52:48.717Z,1628099568.717 [Default:CheckIn] Running Loop=44 2021-08-04T17:52:48.717Z,1628099568.717 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-04T17:52:48.717Z,1628099568.717 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-04T17:52:49.915Z,1628099569.915 [DVL_micro](ERROR): Failed to parse: :WI,+00000,+00000,+00000,+00000,I 2021-08-04T17:52:50.718Z,1628099570.718 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175251.00,A,4149.69009,N,08324.71957,W,0.039,225.04,040821,,,D*76 2021-08-04T17:52:50.720Z,1628099570.720 [NAL9602](INFO): GPS fix at 20210804T175251: (41.828168, -83.411993) 2021-08-04T17:52:50.730Z,1628099570.730 [Default:CheckIn:Read_GPS] Stopped 2021-08-04T17:52:50.730Z,1628099570.730 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-04T17:52:57.464Z,1628099577.464 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210804T172847/Courier0012.lzma 2021-08-04T17:52:58.462Z,1628099578.462 [DataOverHttps](INFO): Moved sent file to Logs/20210804T172847/Courier0012.lzma.bak 2021-08-04T17:52:58.462Z,1628099578.462 [DataOverHttps](INFO): SBD MOMSN=15823311 2021-08-04T17:53:15.684Z,1628099595.684 [DataOverHttps](INFO): Sending 289 bytes from file Logs/20210804T172847/Express0013.lzma 2021-08-04T17:53:16.686Z,1628099596.686 [DataOverHttps](INFO): Moved sent file to Logs/20210804T172847/Express0013.lzma.bak 2021-08-04T17:53:16.686Z,1628099596.686 [DataOverHttps](INFO): SBD MOMSN=15823317 2021-08-04T17:53:18.204Z,1628099598.204 [Default:CheckIn:Read_Iridium] Stopped 2021-08-04T17:53:18.204Z,1628099598.204 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-04T17:53:18.205Z,1628099598.205 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-04T17:53:19.878Z,1628099599.878 [NAL9602](INFO): SBD MO Status=2, MOMSN=41923, MT Status=2, MTMSN=0 2021-08-04T17:53:19.878Z,1628099599.878 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-04T17:53:51.728Z,1628099631.728 [NAL9602](INFO): SBD MO Status=2, MOMSN=41923, MT Status=2, MTMSN=0 2021-08-04T17:53:51.729Z,1628099631.729 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-04T17:54:10.722Z,1628099650.722 [NAL9602](INFO): SBD MO Status=2, MOMSN=41923, MT Status=2, MTMSN=0 2021-08-04T17:54:10.722Z,1628099650.722 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-04T17:54:17.995Z,1628099657.995 [NAL9602](INFO): SBD MO Status=2, MOMSN=41923, MT Status=2, MTMSN=0 2021-08-04T17:54:17.995Z,1628099657.995 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-04T17:54:53.984Z,1628099693.984 [NAL9602](INFO): SBD MO Status=2, MOMSN=41923, MT Status=2, MTMSN=0 2021-08-04T17:54:53.984Z,1628099693.984 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-04T17:55:12.555Z,1628099712.555 [NAL9602](INFO): SBD MO Status=2, MOMSN=41923, MT Status=2, MTMSN=0 2021-08-04T17:55:12.555Z,1628099712.555 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-04T17:55:18.614Z,1628099718.614 [NAL9602](INFO): SBD MO Status=2, MOMSN=41923, MT Status=2, MTMSN=0 2021-08-04T17:55:18.614Z,1628099718.614 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-04T17:55:30.714Z,1628099730.714 [DVL_micro](ERROR): only read 3 of 4 data items 2021-08-04T17:55:30.714Z,1628099730.714 [DVL_micro](ERROR): Failed to parse: :BI,-0787,+00011,+00000,A 2021-08-04T17:55:37.178Z,1628099737.178 [NAL9602](INFO): SBD MO Status=2, MOMSN=41923, MT Status=2, MTMSN=0 2021-08-04T17:55:37.178Z,1628099737.178 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-04T17:55:44.863Z,1628099744.863 [NAL9602](INFO): SBD MO Status=2, MOMSN=41923, MT Status=2, MTMSN=0 2021-08-04T17:55:44.863Z,1628099744.863 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-04T17:55:59.810Z,1628099759.810 [NAL9602](INFO): SBD MO Status=2, MOMSN=41923, MT Status=2, MTMSN=0 2021-08-04T17:55:59.810Z,1628099759.810 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-04T17:56:10.325Z,1628099770.325 [DVL_micro](ERROR): Failed to parse: :WI,+00000,+00000,+00000,+00000,I 2021-08-04T17:56:17.203Z,1628099777.203 [NAL9602](INFO): SBD MO Status=2, MOMSN=41923, MT Status=2, MTMSN=0 2021-08-04T17:56:17.203Z,1628099777.203 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-04T17:56:34.998Z,1628099794.998 [NAL9602](INFO): SBD MO Status=2, MOMSN=41923, MT Status=2, MTMSN=0 2021-08-04T17:56:34.998Z,1628099794.998 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-04T17:56:53.555Z,1628099813.555 [NAL9602](INFO): SBD MO Status=2, MOMSN=41923, MT Status=2, MTMSN=0 2021-08-04T17:56:53.555Z,1628099813.555 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-04T17:57:11.330Z,1628099831.330 [NAL9602](INFO): SBD MO Status=2, MOMSN=41923, MT Status=2, MTMSN=0 2021-08-04T17:57:11.330Z,1628099831.330 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-04T17:57:16.604Z,1628099836.604 [NAL9602](INFO): SBD MO Status=2, MOMSN=41923, MT Status=2, MTMSN=0 2021-08-04T17:57:16.605Z,1628099836.605 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-04T17:57:21.439Z,1628099841.439 [NAL9602](INFO): SBD MO Status=2, MOMSN=41923, MT Status=2, MTMSN=0 2021-08-04T17:57:21.439Z,1628099841.439 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-04T17:57:29.520Z,1628099849.520 [NAL9602](INFO): SBD MO Status=2, MOMSN=41923, MT Status=2, MTMSN=0 2021-08-04T17:57:29.520Z,1628099849.520 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-04T17:57:38.445Z,1628099858.445 [NAL9602](INFO): SBD MO Status=2, MOMSN=41923, MT Status=2, MTMSN=0 2021-08-04T17:57:38.445Z,1628099858.445 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-04T17:57:46.913Z,1628099866.913 [NAL9602](INFO): SBD MO Status=2, MOMSN=41923, MT Status=2, MTMSN=0 2021-08-04T17:57:46.913Z,1628099866.913 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-04T17:57:47.236Z,1628099867.236 [CommandLine](IMPORTANT): got command maintain clear 2021-08-04T17:57:47.429Z,1628099867.429 [controlThread](DEBUG): Component order: CycleStarter,ESPComponent,PAR_Licor,AHRS_M2,BPC1,Depth_Keller,DropWeight,DVL_micro,NAL9602,Power24vConverter,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2021-08-04T17:57:50.141Z,1628099870.141 [DVL_micro](ERROR): only read 2 of 4 data items 2021-08-04T17:57:50.141Z,1628099870.141 [DVL_micro](ERROR): Failed to parse: :BI,00242,+0002,A 2021-08-04T17:57:55.799Z,1628099875.799 [NAL9602](INFO): SBD MO Status=2, MOMSN=41923, MT Status=2, MTMSN=0 2021-08-04T17:57:55.799Z,1628099875.799 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-04T17:57:56.219Z,1628099876.219 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-08-04T17:58:18.847Z,1628099898.847 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-04T17:58:18.847Z,1628099898.847 [Default:CheckIn:C.Wait] Stopped 2021-08-04T17:58:18.847Z,1628099898.847 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-04T17:58:18.847Z,1628099898.847 [Default:CheckIn:D] Running Loop=1 2021-08-04T17:58:19.250Z,1628099899.250 [Default:CheckIn:D] Stopped 2021-08-04T17:58:19.250Z,1628099899.250 [Default:CheckIn:E] Running Loop=1 2021-08-04T17:58:19.656Z,1628099899.656 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 287.538770 min 2021-08-04T17:58:19.656Z,1628099899.656 [Default:CheckIn:E] Stopped 2021-08-04T17:58:19.656Z,1628099899.656 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-04T17:58:19.657Z,1628099899.657 [Default:CheckIn] Stopped 2021-08-04T17:58:19.657Z,1628099899.657 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-04T17:58:19.657Z,1628099899.657 [Default:CheckIn](INFO): Running loop #45 2021-08-04T17:58:19.657Z,1628099899.657 [Default:CheckIn] Running Loop=45 2021-08-04T17:58:19.657Z,1628099899.657 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-04T17:58:19.657Z,1628099899.657 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-04T17:58:21.651Z,1628099901.651 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175822.00,A,4149.69311,N,08324.71507,W,0.194,225.04,040821,,,A*78 2021-08-04T17:58:21.653Z,1628099901.653 [NAL9602](INFO): GPS fix at 20210804T175822: (41.828218, -83.411918) 2021-08-04T17:58:21.664Z,1628099901.664 [UniversalFixResidualReporter](INFO): Fix residual: 25.8 %DT, over the last 684.3 m. Residual distance 176.2 m at bearing 114.9 degrees. Fix at (41.8282, -83.4119) with 8.4 m made good. 2021-08-04T17:58:21.665Z,1628099901.665 [Default:CheckIn:Read_GPS] Stopped 2021-08-04T17:58:21.665Z,1628099901.665 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-04T17:58:28.911Z,1628099908.911 [DataOverHttps](INFO): Sending 82 bytes from file Logs/20210804T172847/Courier0015.lzma 2021-08-04T17:58:29.914Z,1628099909.914 [DataOverHttps](INFO): Moved sent file to Logs/20210804T172847/Courier0015.lzma.bak 2021-08-04T17:58:29.914Z,1628099909.914 [DataOverHttps](INFO): SBD MOMSN=15823357 2021-08-04T17:58:53.325Z,1628099933.325 [DataOverHttps](INFO): Sending 349 bytes from file Logs/20210804T172847/Express0016.lzma 2021-08-04T17:58:54.326Z,1628099934.326 [DataOverHttps](INFO): Moved sent file to Logs/20210804T172847/Express0016.lzma.bak 2021-08-04T17:58:54.326Z,1628099934.326 [DataOverHttps](INFO): SBD MOMSN=15823364 2021-08-04T17:58:54.453Z,1628099934.453 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-04T17:58:56.077Z,1628099936.077 [Default:CheckIn:Read_Iridium] Stopped 2021-08-04T17:58:56.077Z,1628099936.077 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-04T17:58:56.078Z,1628099936.078 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-04T17:59:30.426Z,1628099970.426 [DVL_micro](ERROR): only read 3 of 4 data items 2021-08-04T17:59:30.426Z,1628099970.426 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,+0002.70,+9999.99,+ 2021-08-04T18:01:06.641Z,1628100066.641 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2021-08-04T18:01:06.641Z,1628100066.641 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+25.9,089.0,000 2021-08-04T18:01:11.498Z,1628100071.498 [DVL_micro](ERROR): Failed to parse: :R99,+0002.747,+0003.47 2021-08-04T18:01:52.844Z,1628100112.844 [CommandLine](IMPORTANT): got command maintain control VerticalControl.massPositionAction 2.000000 centimeter 2021-08-04T18:01:52.846Z,1628100112.846 [ComponentRegistry](DEBUG): SyncComponent "Maintain_VerticalControl.massPositionAction" handled in the control thread. 2021-08-04T18:01:53.199Z,1628100113.199 [controlThread](DEBUG): Component order: CycleStarter,ESPComponent,PAR_Licor,AHRS_M2,BPC1,Depth_Keller,DropWeight,DVL_micro,NAL9602,Power24vConverter,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,Maintain_VerticalControl.massPositionAction,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2021-08-04T18:02:11.644Z,1628100131.644 [CommandLine](IMPORTANT): got command maintain control VerticalControl.massPositionAction 2.500000 centimeter 2021-08-04T18:02:50.619Z,1628100170.619 [DVL_micro](ERROR): Failed to parse: :WI,+00000,+00000,+00000,+00000,I 2021-08-04T18:03:56.549Z,1628100236.549 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-04T18:03:56.549Z,1628100236.549 [Default:CheckIn:C.Wait] Stopped 2021-08-04T18:03:56.549Z,1628100236.549 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-04T18:03:56.549Z,1628100236.549 [Default:CheckIn:D] Running Loop=1 2021-08-04T18:03:56.965Z,1628100236.965 [Default:CheckIn:D] Stopped 2021-08-04T18:03:56.965Z,1628100236.965 [Default:CheckIn:E] Running Loop=1 2021-08-04T18:03:57.369Z,1628100237.369 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 293.167350 min 2021-08-04T18:03:57.369Z,1628100237.369 [Default:CheckIn:E] Stopped 2021-08-04T18:03:57.369Z,1628100237.369 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-04T18:03:57.369Z,1628100237.369 [Default:CheckIn] Stopped 2021-08-04T18:03:57.370Z,1628100237.370 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-04T18:03:57.370Z,1628100237.370 [Default:CheckIn](INFO): Running loop #46 2021-08-04T18:03:57.370Z,1628100237.370 [Default:CheckIn] Running Loop=46 2021-08-04T18:03:57.370Z,1628100237.370 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-04T18:03:57.370Z,1628100237.370 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-04T18:03:59.375Z,1628100239.375 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180359.00,A,4149.69416,N,08324.71557,W,0.058,225.04,040821,,,A*71 2021-08-04T18:03:59.377Z,1628100239.377 [NAL9602](INFO): GPS fix at 20210804T180359: (41.828236, -83.411926) 2021-08-04T18:03:59.389Z,1628100239.389 [UniversalFixResidualReporter](INFO): Fix residual: 26.6 %DT, over the last 1000.1 m. Residual distance 265.8 m at bearing 116.7 degrees. Fix at (41.8282, -83.4119) with 2.1 m made good. 2021-08-04T18:03:59.389Z,1628100239.389 [Default:CheckIn:Read_GPS] Stopped 2021-08-04T18:03:59.389Z,1628100239.389 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-04T18:04:07.983Z,1628100247.983 [DataOverHttps](INFO): Sending 82 bytes from file Logs/20210804T172847/Courier0018.lzma 2021-08-04T18:04:08.986Z,1628100248.986 [DataOverHttps](INFO): Moved sent file to Logs/20210804T172847/Courier0018.lzma.bak 2021-08-04T18:04:08.986Z,1628100248.986 [DataOverHttps](INFO): SBD MOMSN=15823401 2021-08-04T18:04:25.641Z,1628100265.641 [NAL9602](INFO): SBD MO Status=2, MOMSN=41923, MT Status=2, MTMSN=0 2021-08-04T18:04:25.641Z,1628100265.641 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-04T18:04:26.233Z,1628100266.233 [DataOverHttps](INFO): Sending 358 bytes from file Logs/20210804T172847/Express0019.lzma 2021-08-04T18:04:27.234Z,1628100267.234 [DataOverHttps](INFO): Moved sent file to Logs/20210804T172847/Express0019.lzma.bak 2021-08-04T18:04:27.234Z,1628100267.234 [DataOverHttps](INFO): SBD MOMSN=15823408 2021-08-04T18:04:28.918Z,1628100268.918 [Default:CheckIn:Read_Iridium] Stopped 2021-08-04T18:04:28.918Z,1628100268.918 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-04T18:04:28.918Z,1628100268.918 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-04T18:04:41.859Z,1628100281.859 [NAL9602](INFO): SBD MO Status=2, MOMSN=41923, MT Status=2, MTMSN=0 2021-08-04T18:04:41.868Z,1628100281.868 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-04T18:04:49.134Z,1628100289.134 [NAL9602](INFO): SBD MO Status=2, MOMSN=41923, MT Status=2, MTMSN=0 2021-08-04T18:04:49.134Z,1628100289.134 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-04T18:05:04.497Z,1628100304.497 [NAL9602](INFO): SBD MO Status=2, MOMSN=41923, MT Status=2, MTMSN=0 2021-08-04T18:05:04.497Z,1628100304.497 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-04T18:05:17.424Z,1628100317.424 [DVL_micro](ERROR): Failed to parse: :BD,+00000000.00,+00000000.00,+00000000.00,0000.10,000.00 2021-08-04T18:05:21.087Z,1628100321.087 [NAL9602](INFO): SBD MO Status=2, MOMSN=41923, MT Status=2, MTMSN=0 2021-08-04T18:05:21.087Z,1628100321.087 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-04T18:05:52.656Z,1628100352.656 [NAL9602](INFO): SBD MO Status=0, MOMSN=41923, MT Status=0, MTMSN=0 2021-08-04T18:05:52.656Z,1628100352.656 [NAL9602](INFO): No messages in MT queue 2021-08-04T18:06:15.695Z,1628100375.695 [DVL_micro](ERROR): only read 3 of 4 data items 2021-08-04T18:06:15.695Z,1628100375.695 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,+0002.72,+00003.79 2021-08-04T18:06:22.554Z,1628100382.554 [DVL_micro](ERROR): only read 3 of 4 data items 2021-08-04T18:06:22.554Z,1628100382.554 [DVL_micro](ERROR): Failed to parse: :BI,+0000,+00000,+00000,I 2021-08-04T18:06:23.363Z,1628100383.363 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-04T18:07:55.701Z,1628100475.701 [DVL_micro](ERROR): Failed to parse:00000000000,35.0,+26.0,0000.0,1489.0,000 2021-08-04T18:09:29.482Z,1628100569.482 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-04T18:09:29.482Z,1628100569.482 [Default:CheckIn:C.Wait] Stopped 2021-08-04T18:09:29.482Z,1628100569.482 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-04T18:09:29.482Z,1628100569.482 [Default:CheckIn:D] Running Loop=1 2021-08-04T18:09:29.915Z,1628100569.915 [Default:CheckIn:D] Stopped 2021-08-04T18:09:29.915Z,1628100569.915 [Default:CheckIn:E] Running Loop=1 2021-08-04T18:09:30.299Z,1628100570.299 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 298.716504 min 2021-08-04T18:09:30.299Z,1628100570.299 [Default:CheckIn:E] Stopped 2021-08-04T18:09:30.299Z,1628100570.299 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-04T18:09:30.299Z,1628100570.299 [Default:CheckIn] Stopped 2021-08-04T18:09:30.299Z,1628100570.299 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-04T18:09:30.300Z,1628100570.300 [Default:CheckIn](INFO): Running loop #47 2021-08-04T18:09:30.300Z,1628100570.300 [Default:CheckIn] Running Loop=47 2021-08-04T18:09:30.300Z,1628100570.300 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-04T18:09:30.300Z,1628100570.300 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-04T18:09:32.283Z,1628100572.283 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180932.00,A,4149.69229,N,08324.71576,W,0.136,225.04,040821,,,A*76 2021-08-04T18:09:32.286Z,1628100572.286 [NAL9602](INFO): GPS fix at 20210804T180932: (41.828205, -83.411929) 2021-08-04T18:09:32.356Z,1628100572.356 [UniversalFixResidualReporter](INFO): Fix residual: 7.5 %DT, over the last 644.1 m. Residual distance 48.0 m at bearing 75.5 degrees. Fix at (41.8282, -83.4119) with 3.5 m made good. 2021-08-04T18:09:32.356Z,1628100572.356 [Default:CheckIn:Read_GPS] Stopped 2021-08-04T18:09:32.357Z,1628100572.357 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-04T18:09:35.998Z,1628100575.998 [DVL_micro](ERROR): Failed to parse: :BD,+00000000.00,+0000000000000.00,0000.30,000.00 2021-08-04T18:09:47.679Z,1628100587.679 [DataOverHttps](INFO): Sending 81 bytes from file Logs/20210804T172847/Courier0021.lzma 2021-08-04T18:09:48.682Z,1628100588.682 [DataOverHttps](INFO): Moved sent file to Logs/20210804T172847/Courier0021.lzma.bak 2021-08-04T18:09:48.682Z,1628100588.682 [DataOverHttps](INFO): SBD MOMSN=15823497 2021-08-04T18:09:51.812Z,1628100591.812 [NAL9602](INFO): SBD MO Status=0, MOMSN=41924, MT Status=0, MTMSN=0 2021-08-04T18:09:51.813Z,1628100591.813 [NAL9602](INFO): No messages in MT queue 2021-08-04T18:10:05.856Z,1628100605.856 [DataOverHttps](INFO): Sending 244 bytes from file Logs/20210804T172847/Express0022.lzma 2021-08-04T18:10:06.858Z,1628100606.858 [DataOverHttps](INFO): Moved sent file to Logs/20210804T172847/Express0022.lzma.bak 2021-08-04T18:10:06.858Z,1628100606.858 [DataOverHttps](INFO): SBD MOMSN=15823503 2021-08-04T18:10:08.398Z,1628100608.398 [Default:CheckIn:Read_Iridium] Stopped 2021-08-04T18:10:08.398Z,1628100608.398 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-04T18:10:08.398Z,1628100608.398 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-04T18:10:22.509Z,1628100622.509 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-04T18:11:21.120Z,1628100681.120 [DVL_micro](ERROR): only read 3 of 4 data items 2021-08-04T18:11:21.121Z,1628100681.121 [DVL_micro](ERROR): Failed to parse: :BI,+00052,+00245,+00027,+ 2021-08-04T18:12:06.786Z,1628100726.786 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2021-08-04T18:12:06.786Z,1628100726.786 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+26.0,489.0,000 2021-08-04T18:12:57.316Z,1628100777.316 [DVL_micro](ERROR): only read 3 of 4 data items 2021-08-04T18:12:57.316Z,1628100777.316 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,+00020.43,+0003.39 2021-08-04T18:13:02.156Z,1628100782.156 [DVL_micro](ERROR): Failed to parse: :BD,+00000000.00,+00000000.00,+00000000.00,0000.30,000.00 2021-08-04T18:14:41.190Z,1628100881.190 [DVL_micro](ERROR): only read 3 of 4 data items 2021-08-04T18:14:41.190Z,1628100881.190 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,+0002.943,+0003.38 2021-08-04T18:15:09.064Z,1628100909.064 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-04T18:15:09.064Z,1628100909.064 [Default:CheckIn:C.Wait] Stopped 2021-08-04T18:15:09.064Z,1628100909.064 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-04T18:15:09.064Z,1628100909.064 [Default:CheckIn:D] Running Loop=1 2021-08-04T18:15:09.438Z,1628100909.438 [Default:CheckIn:D] Stopped 2021-08-04T18:15:09.438Z,1628100909.438 [Default:CheckIn:E] Running Loop=1 2021-08-04T18:15:09.853Z,1628100909.853 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 304.375228 min 2021-08-04T18:15:09.853Z,1628100909.853 [Default:CheckIn:E] Stopped 2021-08-04T18:15:09.853Z,1628100909.853 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-04T18:15:09.853Z,1628100909.853 [Default:CheckIn] Stopped 2021-08-04T18:15:09.853Z,1628100909.853 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-04T18:15:09.853Z,1628100909.853 [Default:CheckIn](INFO): Running loop #48 2021-08-04T18:15:09.853Z,1628100909.853 [Default:CheckIn] Running Loop=48 2021-08-04T18:15:09.853Z,1628100909.853 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-04T18:15:09.854Z,1628100909.854 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-04T18:15:11.889Z,1628100911.889 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181512.00,A,4149.69243,N,08324.71644,W,0.078,228.85,040821,,,A*78 2021-08-04T18:15:11.896Z,1628100911.896 [NAL9602](INFO): GPS fix at 20210804T181512: (41.828207, -83.411941) 2021-08-04T18:15:11.914Z,1628100911.914 [Default:CheckIn:Read_GPS] Stopped 2021-08-04T18:15:11.914Z,1628100911.914 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-04T18:15:19.567Z,1628100919.567 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210804T172847/Courier0024.lzma 2021-08-04T18:15:20.570Z,1628100920.570 [DataOverHttps](INFO): Moved sent file to Logs/20210804T172847/Courier0024.lzma.bak 2021-08-04T18:15:20.570Z,1628100920.570 [DataOverHttps](INFO): SBD MOMSN=15823548 2021-08-04T18:15:29.283Z,1628100929.283 [NAL9602](INFO): SBD MO Status=0, MOMSN=41925, MT Status=0, MTMSN=0 2021-08-04T18:15:29.283Z,1628100929.283 [NAL9602](INFO): No messages in MT queue 2021-08-04T18:15:29.687Z,1628100929.687 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2021-08-04T18:15:29.687Z,1628100929.687 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35,0000.0,1489.0,000 2021-08-04T18:15:42.800Z,1628100942.800 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20210804T172847/Express0025.lzma 2021-08-04T18:15:43.802Z,1628100943.802 [DataOverHttps](INFO): Moved sent file to Logs/20210804T172847/Express0025.lzma.bak 2021-08-04T18:15:43.802Z,1628100943.802 [DataOverHttps](INFO): SBD MOMSN=15823554 2021-08-04T18:15:45.577Z,1628100945.577 [Default:CheckIn:Read_Iridium] Stopped 2021-08-04T18:15:45.577Z,1628100945.577 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-04T18:15:45.577Z,1628100945.577 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-04T18:16:00.072Z,1628100960.072 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-04T18:16:21.501Z,1628100981.501 [DVL_micro](ERROR): only read 3 of 4 data items 2021-08-04T18:16:21.501Z,1628100981.501 [DVL_micro](ERROR): Failed to parse: :BI,-00025,+0009,+00000,A 2021-08-04T18:19:46.384Z,1628101186.384 [DVL_micro](ERROR): only read 0 of 4 data items 2021-08-04T18:19:46.384Z,1628101186.384 [DVL_micro](ERROR): Failed to parse: :BI-00044,+00000,+00000,A 2021-08-04T18:20:46.226Z,1628101246.226 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-04T18:20:46.227Z,1628101246.227 [Default:CheckIn:C.Wait] Stopped 2021-08-04T18:20:46.227Z,1628101246.227 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-04T18:20:46.227Z,1628101246.227 [Default:CheckIn:D] Running Loop=1 2021-08-04T18:20:46.607Z,1628101246.607 [Default:CheckIn:D] Stopped 2021-08-04T18:20:46.607Z,1628101246.607 [Default:CheckIn:E] Running Loop=1 2021-08-04T18:20:47.027Z,1628101247.027 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 309.994694 min 2021-08-04T18:20:47.027Z,1628101247.027 [Default:CheckIn:E] Stopped 2021-08-04T18:20:47.028Z,1628101247.028 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-04T18:20:47.028Z,1628101247.028 [Default:CheckIn] Stopped 2021-08-04T18:20:47.028Z,1628101247.028 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-04T18:20:47.028Z,1628101247.028 [Default:CheckIn](INFO): Running loop #49 2021-08-04T18:20:47.028Z,1628101247.028 [Default:CheckIn] Running Loop=49 2021-08-04T18:20:47.028Z,1628101247.028 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-04T18:20:47.028Z,1628101247.028 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-04T18:20:49.032Z,1628101249.032 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182049.00,A,4149.69378,N,08324.71782,W,0.058,217.19,040821,,,A*79 2021-08-04T18:20:49.034Z,1628101249.034 [NAL9602](INFO): GPS fix at 20210804T182049: (41.828230, -83.411964) 2021-08-04T18:20:49.044Z,1628101249.044 [Default:CheckIn:Read_GPS] Stopped 2021-08-04T18:20:49.044Z,1628101249.044 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-04T18:20:55.711Z,1628101255.711 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210804T172847/Courier0027.lzma 2021-08-04T18:20:56.714Z,1628101256.714 [DataOverHttps](INFO): Moved sent file to Logs/20210804T172847/Courier0027.lzma.bak 2021-08-04T18:20:56.714Z,1628101256.714 [DataOverHttps](INFO): SBD MOMSN=15823599 2021-08-04T18:21:08.499Z,1628101268.499 [ElevatorOffsetCalculator](INFO): New estimator for commanded vars: speed 1.00 m/s, pitch 30.00 deg, mass-position -13.00 mm (1 active estimators). 2021-08-04T18:21:17.398Z,1628101277.398 [NAL9602](INFO): SBD MO Status=2, MOMSN=41926, MT Status=2, MTMSN=0 2021-08-04T18:21:17.398Z,1628101277.398 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-04T18:21:48.008Z,1628101308.008 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-08-04T18:22:19.132Z,1628101339.132 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-08-04T18:22:50.256Z,1628101370.256 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-08-04T18:23:10.914Z,1628101390.914 [NAL9602](INFO): SBD MO Status=2, MOMSN=41926, MT Status=2, MTMSN=0 2021-08-04T18:23:10.914Z,1628101390.914 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-04T18:23:21.380Z,1628101401.380 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-08-04T18:23:29.480Z,1628101409.480 [DataOverHttps](INFO): Sending 159 bytes from file Logs/20210804T172847/Express0028.lzma 2021-08-04T18:23:30.482Z,1628101410.482 [DataOverHttps](INFO): Moved sent file to Logs/20210804T172847/Express0028.lzma.bak 2021-08-04T18:23:30.482Z,1628101410.482 [DataOverHttps](INFO): SBD MOMSN=15823623 2021-08-04T18:23:32.347Z,1628101412.347 [Default:CheckIn:Read_Iridium] Stopped 2021-08-04T18:23:32.347Z,1628101412.347 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-04T18:23:32.347Z,1628101412.347 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-04T18:23:33.646Z,1628101413.646 [NAL9602](INFO): SBD MO Status=0, MOMSN=41926, MT Status=0, MTMSN=0 2021-08-04T18:23:33.646Z,1628101413.646 [NAL9602](INFO): No messages in MT queue 2021-08-04T18:24:04.331Z,1628101444.331 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-04T18:28:32.961Z,1628101712.961 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-04T18:28:32.961Z,1628101712.961 [Default:CheckIn:C.Wait] Stopped 2021-08-04T18:28:32.961Z,1628101712.961 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-04T18:28:32.961Z,1628101712.961 [Default:CheckIn:D] Running Loop=1 2021-08-04T18:28:33.273Z,1628101713.273 [Default:CheckIn:D] Stopped 2021-08-04T18:28:33.273Z,1628101713.273 [Default:CheckIn:E] Running Loop=1 2021-08-04T18:28:33.647Z,1628101713.647 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 317.772493 min 2021-08-04T18:28:33.647Z,1628101713.647 [Default:CheckIn:E] Stopped 2021-08-04T18:28:33.648Z,1628101713.648 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-04T18:28:33.648Z,1628101713.648 [Default:CheckIn] Stopped 2021-08-04T18:28:33.648Z,1628101713.648 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-04T18:28:33.648Z,1628101713.648 [Default:CheckIn](INFO): Running loop #50 2021-08-04T18:28:33.648Z,1628101713.648 [Default:CheckIn] Running Loop=50 2021-08-04T18:28:33.649Z,1628101713.649 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-04T18:28:33.649Z,1628101713.649 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-04T18:28:35.660Z,1628101715.660 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182836.00,A,4149.69245,N,08324.71564,W,0.019,355.06,040821,,,D*75 2021-08-04T18:28:35.663Z,1628101715.663 [NAL9602](INFO): GPS fix at 20210804T182836: (41.828207, -83.411927) 2021-08-04T18:28:35.673Z,1628101715.673 [Default:CheckIn:Read_GPS] Stopped 2021-08-04T18:28:35.673Z,1628101715.673 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-04T18:28:46.595Z,1628101726.595 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210804T172847/Courier0030.lzma 2021-08-04T18:28:47.598Z,1628101727.598 [DataOverHttps](INFO): Moved sent file to Logs/20210804T172847/Courier0030.lzma.bak 2021-08-04T18:28:47.598Z,1628101727.598 [DataOverHttps](INFO): SBD MOMSN=15823677 2021-08-04T18:28:49.440Z,1628101729.440 [NAL9602](INFO): SBD MO Status=0, MOMSN=41927, MT Status=0, MTMSN=0 2021-08-04T18:28:49.440Z,1628101729.440 [NAL9602](INFO): No messages in MT queue 2021-08-04T18:29:05.123Z,1628101745.123 [DataOverHttps](INFO): Sending 139 bytes from file Logs/20210804T172847/Express0031.lzma 2021-08-04T18:29:06.126Z,1628101746.126 [DataOverHttps](INFO): Moved sent file to Logs/20210804T172847/Express0031.lzma.bak 2021-08-04T18:29:06.126Z,1628101746.126 [DataOverHttps](INFO): SBD MOMSN=15823684 2021-08-04T18:29:07.647Z,1628101747.647 [Default:CheckIn:Read_Iridium] Stopped 2021-08-04T18:29:07.647Z,1628101747.647 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-04T18:29:07.647Z,1628101747.647 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-04T18:29:20.159Z,1628101760.159 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-04T18:32:43.010Z,1628101963.010 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2021-08-04T18:32:43.010Z,1628101963.010 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+260,1489:WI,+00000,+00000,+00000,+00000,I 2021-08-04T18:34:08.275Z,1628102048.275 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-04T18:34:08.275Z,1628102048.275 [Default:CheckIn:C.Wait] Stopped 2021-08-04T18:34:08.276Z,1628102048.276 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-04T18:34:08.276Z,1628102048.276 [Default:CheckIn:D] Running Loop=1 2021-08-04T18:34:08.675Z,1628102048.675 [Default:CheckIn:D] Stopped 2021-08-04T18:34:08.675Z,1628102048.675 [Default:CheckIn:E] Running Loop=1 2021-08-04T18:34:09.099Z,1628102049.099 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 323.362500 min 2021-08-04T18:34:09.099Z,1628102049.099 [Default:CheckIn:E] Stopped 2021-08-04T18:34:09.099Z,1628102049.099 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-04T18:34:09.099Z,1628102049.099 [Default:CheckIn] Stopped 2021-08-04T18:34:09.104Z,1628102049.104 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-04T18:34:09.104Z,1628102049.104 [Default:CheckIn](INFO): Running loop #51 2021-08-04T18:34:09.104Z,1628102049.104 [Default:CheckIn] Running Loop=51 2021-08-04T18:34:09.104Z,1628102049.104 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-04T18:34:09.104Z,1628102049.104 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-04T18:34:11.082Z,1628102051.082 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183411.00,A,4149.69302,N,08324.71842,W,0.428,355.06,040821,,,D*70 2021-08-04T18:34:11.084Z,1628102051.084 [NAL9602](INFO): GPS fix at 20210804T183411: (41.828217, -83.411974) 2021-08-04T18:34:11.094Z,1628102051.094 [Default:CheckIn:Read_GPS] Stopped 2021-08-04T18:34:11.094Z,1628102051.094 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-04T18:34:19.127Z,1628102059.127 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210804T172847/Courier0033.lzma 2021-08-04T18:34:20.130Z,1628102060.130 [DataOverHttps](INFO): Moved sent file to Logs/20210804T172847/Courier0033.lzma.bak 2021-08-04T18:34:20.130Z,1628102060.130 [DataOverHttps](INFO): SBD MOMSN=15823734 2021-08-04T18:34:21.995Z,1628102061.995 [NAL9602](INFO): SBD MO Status=0, MOMSN=41928, MT Status=0, MTMSN=0 2021-08-04T18:34:21.995Z,1628102061.995 [NAL9602](INFO): No messages in MT queue 2021-08-04T18:34:41.688Z,1628102081.688 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20210804T172847/Express0034.lzma 2021-08-04T18:34:42.690Z,1628102082.690 [DataOverHttps](INFO): Moved sent file to Logs/20210804T172847/Express0034.lzma.bak 2021-08-04T18:34:42.690Z,1628102082.690 [DataOverHttps](INFO): SBD MOMSN=15823740 2021-08-04T18:34:45.138Z,1628102085.138 [Default:CheckIn:Read_Iridium] Stopped 2021-08-04T18:34:45.138Z,1628102085.138 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-04T18:34:45.138Z,1628102085.138 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-04T18:34:52.767Z,1628102092.767 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-04T18:37:48.589Z,1628102268.589 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2021-08-04T18:37:48.589Z,1628102268.589 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+26.1,0000.0,1489.0,,+00000,+00000,+00000,+00000,I 2021-08-04T18:39:29.590Z,1628102369.590 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2021-08-04T18:39:29.590Z,1628102369.590 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+26.1,0000.0,1489:WI,+00000,+00000,+00000,+00000,I 2021-08-04T18:39:45.812Z,1628102385.812 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-04T18:39:45.812Z,1628102385.812 [Default:CheckIn:C.Wait] Stopped 2021-08-04T18:39:45.812Z,1628102385.812 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-04T18:39:45.812Z,1628102385.812 [Default:CheckIn:D] Running Loop=1 2021-08-04T18:39:46.214Z,1628102386.214 [Default:CheckIn:D] Stopped 2021-08-04T18:39:46.214Z,1628102386.214 [Default:CheckIn:E] Running Loop=1 2021-08-04T18:39:46.587Z,1628102386.587 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 328.988151 min 2021-08-04T18:39:46.587Z,1628102386.587 [Default:CheckIn:E] Stopped 2021-08-04T18:39:46.587Z,1628102386.587 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-04T18:39:46.587Z,1628102386.587 [Default:CheckIn] Stopped 2021-08-04T18:39:46.587Z,1628102386.587 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-04T18:39:46.588Z,1628102386.588 [Default:CheckIn](INFO): Running loop #52 2021-08-04T18:39:46.588Z,1628102386.588 [Default:CheckIn] Running Loop=52 2021-08-04T18:39:46.588Z,1628102386.588 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-04T18:39:46.588Z,1628102386.588 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-04T18:39:48.596Z,1628102388.596 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183949.00,A,4149.69290,N,08324.71833,W,0.408,355.06,040821,,,A*7B 2021-08-04T18:39:48.598Z,1628102388.598 [NAL9602](INFO): GPS fix at 20210804T183949: (41.828215, -83.411972) 2021-08-04T18:39:48.609Z,1628102388.609 [Default:CheckIn:Read_GPS] Stopped 2021-08-04T18:39:48.609Z,1628102388.609 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-04T18:39:56.551Z,1628102396.551 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210804T172847/Courier0036.lzma 2021-08-04T18:39:57.554Z,1628102397.554 [DataOverHttps](INFO): Moved sent file to Logs/20210804T172847/Courier0036.lzma.bak 2021-08-04T18:39:57.554Z,1628102397.554 [DataOverHttps](INFO): SBD MOMSN=15823785 2021-08-04T18:40:13.643Z,1628102413.643 [NAL9602](INFO): SBD MO Status=2, MOMSN=41929, MT Status=2, MTMSN=0 2021-08-04T18:40:13.643Z,1628102413.643 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-04T18:40:15.089Z,1628102415.089 [DataOverHttps](INFO): Sending 178 bytes from file Logs/20210804T172847/Express0037.lzma 2021-08-04T18:40:16.090Z,1628102416.090 [DataOverHttps](INFO): Moved sent file to Logs/20210804T172847/Express0037.lzma.bak 2021-08-04T18:40:16.090Z,1628102416.090 [DataOverHttps](INFO): SBD MOMSN=15823792 2021-08-04T18:40:17.707Z,1628102417.707 [Default:CheckIn:Read_Iridium] Stopped 2021-08-04T18:40:17.707Z,1628102417.707 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-04T18:40:17.707Z,1628102417.707 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-04T18:40:49.640Z,1628102449.640 [NAL9602](INFO): SBD MO Status=2, MOMSN=41929, MT Status=2, MTMSN=0 2021-08-04T18:40:49.640Z,1628102449.640 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-04T18:41:07.795Z,1628102467.795 [NAL9602](INFO): SBD MO Status=2, MOMSN=41929, MT Status=2, MTMSN=0 2021-08-04T18:41:07.795Z,1628102467.795 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-04T18:41:13.446Z,1628102473.446 [DVL_micro](ERROR): only read 3 of 4 data items 2021-08-04T18:41:13.446Z,1628102473.446 [DVL_micro](ERROR): Failed to parse: :BI,-00044,+00796,-0000,A 2021-08-04T18:41:31.314Z,1628102491.314 [NAL9602](INFO): SBD MO Status=2, MOMSN=41929, MT Status=2, MTMSN=0 2021-08-04T18:41:31.314Z,1628102491.314 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-04T18:42:03.960Z,1628102523.960 [NAL9602](INFO): SBD MO Status=2, MOMSN=41929, MT Status=2, MTMSN=0 2021-08-04T18:42:03.961Z,1628102523.961 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-04T18:42:23.355Z,1628102543.355 [NAL9602](INFO): SBD MO Status=0, MOMSN=41929, MT Status=0, MTMSN=0 2021-08-04T18:42:23.355Z,1628102543.355 [NAL9602](INFO): No messages in MT queue 2021-08-04T18:42:54.070Z,1628102574.070 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-04T18:44:26.713Z,1628102666.713 [DVL_micro](ERROR): Failed to parse: :3,+00279,-0000,A 2021-08-04T18:44:32.692Z,1628102672.692 [DVL_micro](ERROR): only read 2 of 4 data items 2021-08-04T18:44:32.692Z,1628102672.692 [DVL_micro](ERROR): Failed to parse: :RD,+0000.32,+0003.45,,+0002.72 2021-08-04T18:44:37.931Z,1628102677.931 [DVL_micro](ERROR): only read 3 of 4 data items 2021-08-04T18:44:37.931Z,1628102677.931 [DVL_micro](ERROR): Failed to parse: :RD,+0000.32,+0003.43,+0000..70 2021-08-04T18:45:18.349Z,1628102718.349 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-04T18:45:18.349Z,1628102718.349 [Default:CheckIn:C.Wait] Stopped 2021-08-04T18:45:18.349Z,1628102718.349 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-04T18:45:18.349Z,1628102718.349 [Default:CheckIn:D] Running Loop=1 2021-08-04T18:45:18.761Z,1628102718.761 [Default:CheckIn:D] Stopped 2021-08-04T18:45:18.761Z,1628102718.761 [Default:CheckIn:E] Running Loop=1 2021-08-04T18:45:19.150Z,1628102719.150 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 334.530599 min 2021-08-04T18:45:19.151Z,1628102719.151 [Default:CheckIn:E] Stopped 2021-08-04T18:45:19.151Z,1628102719.151 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-04T18:45:19.151Z,1628102719.151 [Default:CheckIn] Stopped 2021-08-04T18:45:19.151Z,1628102719.151 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-04T18:45:19.151Z,1628102719.151 [Default:CheckIn](INFO): Running loop #53 2021-08-04T18:45:19.151Z,1628102719.151 [Default:CheckIn] Running Loop=53 2021-08-04T18:45:19.151Z,1628102719.151 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-04T18:45:19.152Z,1628102719.152 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-04T18:45:21.195Z,1628102721.195 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184521.00,A,4149.69312,N,08324.71959,W,0.214,355.06,040821,,,D*76 2021-08-04T18:45:21.198Z,1628102721.198 [NAL9602](INFO): GPS fix at 20210804T184521: (41.828219, -83.411993) 2021-08-04T18:45:21.226Z,1628102721.226 [Default:CheckIn:Read_GPS] Stopped 2021-08-04T18:45:21.226Z,1628102721.226 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-04T18:45:27.583Z,1628102727.583 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210804T172847/Courier0039.lzma 2021-08-04T18:45:28.586Z,1628102728.586 [DataOverHttps](INFO): Moved sent file to Logs/20210804T172847/Courier0039.lzma.bak 2021-08-04T18:45:28.586Z,1628102728.586 [DataOverHttps](INFO): SBD MOMSN=15823835 2021-08-04T18:45:29.005Z,1628102729.005 [NAL9602](INFO): SBD MO Status=0, MOMSN=41930, MT Status=0, MTMSN=0 2021-08-04T18:45:29.006Z,1628102729.006 [NAL9602](INFO): No messages in MT queue 2021-08-04T18:45:50.264Z,1628102750.264 [DataOverHttps](INFO): Sending 142 bytes from file Logs/20210804T172847/Express0040.lzma 2021-08-04T18:45:51.266Z,1628102751.266 [DataOverHttps](INFO): Moved sent file to Logs/20210804T172847/Express0040.lzma.bak 2021-08-04T18:45:51.266Z,1628102751.266 [DataOverHttps](INFO): SBD MOMSN=15823841 2021-08-04T18:45:52.933Z,1628102752.933 [Default:CheckIn:Read_Iridium] Stopped 2021-08-04T18:45:52.933Z,1628102752.933 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-04T18:45:52.933Z,1628102752.933 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-04T18:45:59.772Z,1628102759.772 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-04T18:46:17.956Z,1628102777.956 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2021-08-04T18:46:17.956Z,1628102777.956 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,32,0000.0,1489.0,000 2021-08-04T18:47:45.279Z,1628102865.279 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2021-08-04T18:47:56.994Z,1628102876.994 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2021-08-04T18:47:57.829Z,1628102877.829 [DVL_micro](ERROR): only read 2 of 4 data items 2021-08-04T18:47:57.829Z,1628102877.829 [DVL_micro](ERROR): Failed to parse: :BI,+0759,+0011,A 2021-08-04T18:48:08.308Z,1628102888.308 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2021-08-04T18:48:20.020Z,1628102900.020 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2021-08-04T18:48:31.335Z,1628102911.335 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2021-08-04T18:48:42.670Z,1628102922.670 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2021-08-04T18:48:53.970Z,1628102933.970 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2021-08-04T18:49:05.286Z,1628102945.286 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2021-08-04T18:49:39.254Z,1628102979.254 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2021-08-04T18:49:39.254Z,1628102979.254 [DVL_micro](ERROR): Failed to parse: :TS,000000000.0,+26.2,0000.0,1489.0,000 2021-08-04T18:50:53.662Z,1628103053.662 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-04T18:50:53.662Z,1628103053.662 [Default:CheckIn:C.Wait] Stopped 2021-08-04T18:50:53.662Z,1628103053.662 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-04T18:50:53.662Z,1628103053.662 [Default:CheckIn:D] Running Loop=1 2021-08-04T18:50:54.039Z,1628103054.039 [Default:CheckIn:D] Stopped 2021-08-04T18:50:54.039Z,1628103054.039 [Default:CheckIn:E] Running Loop=1 2021-08-04T18:50:54.455Z,1628103054.455 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 340.118555 min 2021-08-04T18:50:54.455Z,1628103054.455 [Default:CheckIn:E] Stopped 2021-08-04T18:50:54.455Z,1628103054.455 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-04T18:50:54.455Z,1628103054.455 [Default:CheckIn] Stopped 2021-08-04T18:50:54.455Z,1628103054.455 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-04T18:50:54.456Z,1628103054.456 [Default:CheckIn](INFO): Running loop #54 2021-08-04T18:50:54.456Z,1628103054.456 [Default:CheckIn] Running Loop=54 2021-08-04T18:50:54.456Z,1628103054.456 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-04T18:50:54.456Z,1628103054.456 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-04T18:50:56.481Z,1628103056.481 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,185056.00,A,4149.69261,N,08324.71685,W,0.117,355.06,040821,,,D*79 2021-08-04T18:50:56.483Z,1628103056.483 [NAL9602](INFO): GPS fix at 20210804T185056: (41.828210, -83.411947) 2021-08-04T18:50:56.509Z,1628103056.509 [Default:CheckIn:Read_GPS] Stopped 2021-08-04T18:50:56.509Z,1628103056.509 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-04T18:51:04.463Z,1628103064.463 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210804T172847/Courier0042.lzma 2021-08-04T18:51:05.466Z,1628103065.466 [DataOverHttps](INFO): Moved sent file to Logs/20210804T172847/Courier0042.lzma.bak 2021-08-04T18:51:05.466Z,1628103065.466 [DataOverHttps](INFO): SBD MOMSN=15823886 2021-08-04T18:51:22.868Z,1628103082.868 [DataOverHttps](INFO): Sending 156 bytes from file Logs/20210804T172847/Express0043.lzma 2021-08-04T18:51:23.870Z,1628103083.870 [DataOverHttps](INFO): Moved sent file to Logs/20210804T172847/Express0043.lzma.bak 2021-08-04T18:51:23.870Z,1628103083.870 [DataOverHttps](INFO): SBD MOMSN=15823892 2021-08-04T18:51:25.585Z,1628103085.585 [Default:CheckIn:Read_Iridium] Stopped 2021-08-04T18:51:25.585Z,1628103085.585 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-04T18:51:25.585Z,1628103085.585 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-04T18:51:27.608Z,1628103087.608 [NAL9602](INFO): SBD MO Status=0, MOMSN=41931, MT Status=0, MTMSN=0 2021-08-04T18:51:27.608Z,1628103087.608 [NAL9602](INFO): No messages in MT queue 2021-08-04T18:51:58.329Z,1628103118.329 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-04T18:53:05.814Z,1628103185.814 [CommandLine](IMPORTANT): got command get platform_mass_position centimeter 2021-08-04T18:53:05.815Z,1628103185.815 [CommandLine](IMPORTANT): platform_mass_position 2.497392 cm 2021-08-04T18:53:24.259Z,1628103204.259 [CommandLine](IMPORTANT): got command maintain control VerticalControl.buoyancyAction 500.000000 cubic_centimeter 2021-08-04T18:53:24.262Z,1628103204.262 [ComponentRegistry](DEBUG): SyncComponent "Maintain_VerticalControl.buoyancyAction" handled in the control thread. 2021-08-04T18:53:24.498Z,1628103204.498 [controlThread](DEBUG): Component order: CycleStarter,ESPComponent,PAR_Licor,AHRS_M2,BPC1,Depth_Keller,DropWeight,DVL_micro,NAL9602,Power24vConverter,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,Maintain_VerticalControl.massPositionAction,Maintain_VerticalControl.buoyancyAction,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2021-08-04T18:53:44.124Z,1628103224.124 [CommandLine](IMPORTANT): got command maintain control VerticalControl.massPositionAction 3.500000 centimeter 2021-08-04T18:53:55.604Z,1628103235.604 [CommandLine](IMPORTANT): got command report mod platform_buoyancy_position 2021-08-04T18:53:55.834Z,1628103235.834 [Reporter](INFO): platform_buoyancy_position 634.154541 cc 2021-08-04T18:53:56.214Z,1628103236.214 [Reporter](INFO): platform_buoyancy_position 627.842407 cc 2021-08-04T18:53:56.627Z,1628103236.627 [Reporter](INFO): platform_buoyancy_position 623.410522 cc 2021-08-04T18:53:57.034Z,1628103237.034 [Reporter](INFO): platform_buoyancy_position 616.964111 cc 2021-08-04T18:53:57.438Z,1628103237.438 [Reporter](INFO): platform_buoyancy_position 612.800842 cc 2021-08-04T18:53:57.885Z,1628103237.885 [Reporter](INFO): platform_buoyancy_position 606.354431 cc 2021-08-04T18:53:58.249Z,1628103238.249 [Reporter](INFO): platform_buoyancy_position 601.922546 cc 2021-08-04T18:53:58.686Z,1628103238.686 [Reporter](INFO): platform_buoyancy_position 595.744751 cc 2021-08-04T18:53:59.050Z,1628103239.050 [Reporter](INFO): platform_buoyancy_position 591.312805 cc 2021-08-04T18:53:59.470Z,1628103239.470 [Reporter](INFO): platform_buoyancy_position 586.880920 cc 2021-08-04T18:53:59.862Z,1628103239.862 [Reporter](INFO): platform_buoyancy_position 580.568848 cc 2021-08-04T18:54:00.414Z,1628103240.414 [Reporter](INFO): platform_buoyancy_position 574.793945 cc 2021-08-04T18:54:00.874Z,1628103240.874 [Reporter](INFO): platform_buoyancy_position 567.676025 cc 2021-08-04T18:54:01.122Z,1628103241.122 [Reporter](INFO): platform_buoyancy_position 563.378418 cc 2021-08-04T18:54:01.562Z,1628103241.562 [Reporter](INFO): platform_buoyancy_position 558.409302 cc 2021-08-04T18:54:01.926Z,1628103241.926 [Reporter](INFO): platform_buoyancy_position 552.500122 cc 2021-08-04T18:54:02.286Z,1628103242.286 [Reporter](INFO): platform_buoyancy_position 548.605408 cc 2021-08-04T18:54:02.714Z,1628103242.714 [Reporter](INFO): platform_buoyancy_position 542.427612 cc 2021-08-04T18:54:03.149Z,1628103243.149 [Reporter](INFO): platform_buoyancy_position 537.458496 cc 2021-08-04T18:54:03.486Z,1628103243.486 [Reporter](INFO): platform_buoyancy_position 533.160950 cc 2021-08-04T18:54:03.916Z,1628103243.916 [Reporter](INFO): platform_buoyancy_position 526.714539 cc 2021-08-04T18:54:04.299Z,1628103244.299 [Reporter](INFO): platform_buoyancy_position 522.416931 cc 2021-08-04T18:54:04.709Z,1628103244.709 [Reporter](INFO): platform_buoyancy_position 516.239136 cc 2021-08-04T18:54:05.158Z,1628103245.158 [Reporter](INFO): platform_buoyancy_position 511.672943 cc 2021-08-04T18:54:05.545Z,1628103245.545 [Reporter](INFO): platform_buoyancy_position 507.509674 cc 2021-08-04T18:54:20.401Z,1628103260.401 [BPC1](ERROR): Battery stick #38 (s/n: 0139) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x4AD0. 2021-08-04T18:54:20.402Z,1628103260.402 [BPC1](INFO): Calculating totals. Valid battery stick count: 55. Valid reserve battery stick count: 5. 2021-08-04T18:54:20.405Z,1628103260.405 [BPC1](INFO): Received data from all battery sticks. 2021-08-04T18:55:29.144Z,1628103329.144 [DVL_micro](ERROR): only read 3 of 4 data items 2021-08-04T18:55:29.144Z,1628103329.144 [DVL_micro](ERROR): Failed to parse: :RD,+0000.34,+0002.74,+00003.24 2021-08-04T18:56:19.766Z,1628103379.766 [DVL_micro](ERROR): Failed to parse: :SA,-16.80,+11.65,024.3 2021-08-04T18:56:26.182Z,1628103386.182 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-04T18:56:26.182Z,1628103386.182 [Default:CheckIn:C.Wait] Stopped 2021-08-04T18:56:26.182Z,1628103386.182 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-04T18:56:26.183Z,1628103386.183 [Default:CheckIn:D] Running Loop=1 2021-08-04T18:56:26.603Z,1628103386.603 [Default:CheckIn:D] Stopped 2021-08-04T18:56:26.603Z,1628103386.603 [Default:CheckIn:E] Running Loop=1 2021-08-04T18:56:26.991Z,1628103386.991 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 345.661296 min 2021-08-04T18:56:26.991Z,1628103386.991 [Default:CheckIn:E] Stopped 2021-08-04T18:56:26.991Z,1628103386.991 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-04T18:56:26.991Z,1628103386.991 [Default:CheckIn] Stopped 2021-08-04T18:56:26.991Z,1628103386.991 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-04T18:56:26.992Z,1628103386.992 [Default:CheckIn](INFO): Running loop #55 2021-08-04T18:56:26.992Z,1628103386.992 [Default:CheckIn] Running Loop=55 2021-08-04T18:56:26.992Z,1628103386.992 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-04T18:56:26.992Z,1628103386.992 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-04T18:56:29.004Z,1628103389.004 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,185629.00,A,4149.69171,N,08324.71656,W,0.156,355.06,040821,,,D*7E 2021-08-04T18:56:29.006Z,1628103389.006 [NAL9602](INFO): GPS fix at 20210804T185629: (41.828195, -83.411943) 2021-08-04T18:56:29.015Z,1628103389.015 [Default:CheckIn:Read_GPS] Stopped 2021-08-04T18:56:29.016Z,1628103389.016 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-04T18:56:41.311Z,1628103401.311 [DataOverHttps](INFO): Sending 83 bytes from file Logs/20210804T172847/Courier0045.lzma 2021-08-04T18:56:42.314Z,1628103402.314 [DataOverHttps](INFO): Moved sent file to Logs/20210804T172847/Courier0045.lzma.bak 2021-08-04T18:56:42.314Z,1628103402.314 [DataOverHttps](INFO): SBD MOMSN=15823937 2021-08-04T18:56:55.380Z,1628103415.380 [NAL9602](INFO): SBD MO Status=2, MOMSN=41932, MT Status=2, MTMSN=0 2021-08-04T18:56:55.380Z,1628103415.380 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-04T18:57:00.657Z,1628103420.657 [DataOverHttps](INFO): Sending 343 bytes from file Logs/20210804T172847/Express0046.lzma 2021-08-04T18:57:01.658Z,1628103421.658 [DataOverHttps](INFO): Moved sent file to Logs/20210804T172847/Express0046.lzma.bak 2021-08-04T18:57:01.658Z,1628103421.658 [DataOverHttps](INFO): SBD MOMSN=15823942 2021-08-04T18:57:03.454Z,1628103423.454 [Default:CheckIn:Read_Iridium] Stopped 2021-08-04T18:57:03.454Z,1628103423.454 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-04T18:57:03.454Z,1628103423.454 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-04T18:57:07.891Z,1628103427.891 [NAL9602](INFO): SBD MO Status=0, MOMSN=41932, MT Status=0, MTMSN=0 2021-08-04T18:57:07.930Z,1628103427.930 [NAL9602](INFO): No messages in MT queue 2021-08-04T18:57:38.703Z,1628103458.703 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-04T18:58:04.531Z,1628103484.531 [DVL_micro](ERROR): Failed to parse:000,+00000,+00000,+00000,I 2021-08-04T18:58:08.082Z,1628103488.082 [CommandLine](IMPORTANT): got command maintain control VerticalControl.massPositionAction 2.000000 centimeter 2021-08-04T18:58:29.522Z,1628103509.522 [CommandLine](IMPORTANT): got command maintain control VerticalControl.massPositionAction 1.000000 centimeter 2021-08-04T19:01:26.401Z,1628103686.401 [CommandLine](IMPORTANT): got command maintain control VerticalControl.massPositionAction 1.500000 centimeter 2021-08-04T19:01:28.736Z,1628103688.736 [DVL_micro](ERROR): only read 0 of 4 data items 2021-08-04T19:01:28.737Z,1628103688.737 [DVL_micro](ERROR): Failed to parse: :RD,,+0002.82,+0000.35,+0003.12 2021-08-04T19:02:03.874Z,1628103723.874 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-04T19:02:03.874Z,1628103723.874 [Default:CheckIn:C.Wait] Stopped 2021-08-04T19:02:03.874Z,1628103723.874 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-04T19:02:03.874Z,1628103723.874 [Default:CheckIn:D] Running Loop=1 2021-08-04T19:02:04.285Z,1628103724.285 [Default:CheckIn:D] Stopped 2021-08-04T19:02:04.285Z,1628103724.285 [Default:CheckIn:E] Running Loop=1 2021-08-04T19:02:04.706Z,1628103724.706 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 351.289355 min 2021-08-04T19:02:04.706Z,1628103724.706 [Default:CheckIn:E] Stopped 2021-08-04T19:02:04.706Z,1628103724.706 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-04T19:02:04.706Z,1628103724.706 [Default:CheckIn] Stopped 2021-08-04T19:02:04.706Z,1628103724.706 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-04T19:02:04.706Z,1628103724.706 [Default:CheckIn](INFO): Running loop #56 2021-08-04T19:02:04.706Z,1628103724.706 [Default:CheckIn] Running Loop=56 2021-08-04T19:02:04.706Z,1628103724.706 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-04T19:02:04.707Z,1628103724.707 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-04T19:02:06.715Z,1628103726.715 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190207.00,A,4149.69600,N,08324.71646,W,0.058,0.00,040821,,,D*78 2021-08-04T19:02:06.717Z,1628103726.717 [NAL9602](INFO): GPS fix at 20210804T190207: (41.828267, -83.411941) 2021-08-04T19:02:06.743Z,1628103726.743 [Default:CheckIn:Read_GPS] Stopped 2021-08-04T19:02:06.743Z,1628103726.743 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-04T19:02:14.783Z,1628103734.783 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210804T172847/Courier0048.lzma 2021-08-04T19:02:15.786Z,1628103735.786 [DataOverHttps](INFO): Moved sent file to Logs/20210804T172847/Courier0048.lzma.bak 2021-08-04T19:02:15.786Z,1628103735.786 [DataOverHttps](INFO): SBD MOMSN=15823991 2021-08-04T19:02:19.623Z,1628103739.623 [NAL9602](INFO): SBD MO Status=0, MOMSN=41933, MT Status=0, MTMSN=0 2021-08-04T19:02:19.623Z,1628103739.623 [NAL9602](INFO): No messages in MT queue 2021-08-04T19:02:34.996Z,1628103754.996 [DataOverHttps](INFO): Sending 254 bytes from file Logs/20210804T172847/Express0049.lzma 2021-08-04T19:02:35.998Z,1628103755.998 [DataOverHttps](INFO): Moved sent file to Logs/20210804T172847/Express0049.lzma.bak 2021-08-04T19:02:35.998Z,1628103755.998 [DataOverHttps](INFO): SBD MOMSN=15823997 2021-08-04T19:02:38.407Z,1628103758.407 [Default:CheckIn:Read_Iridium] Stopped 2021-08-04T19:02:38.407Z,1628103758.407 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-04T19:02:38.407Z,1628103758.407 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-04T19:02:50.406Z,1628103770.406 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-04T19:03:09.003Z,1628103789.003 [DVL_micro](ERROR): only read 0 of 4 data items 2021-08-04T19:03:09.003Z,1628103789.003 [DVL_micro](ERROR): Failed to parse: :RD,,+0002.83,+0000.38,+0003.23 2021-08-04T19:03:16.695Z,1628103796.695 [CommandLine](IMPORTANT): got command maintain control VerticalControl.massPositionAction 0.000000 centimeter 2021-08-04T19:04:47.129Z,1628103887.129 [CommandLine](IMPORTANT): got command maintain control VerticalControl.buoyancyAction 300.000000 cubic_centimeter 2021-08-04T19:04:48.968Z,1628103888.968 [Reporter](INFO): platform_buoyancy_position 496.765656 cc 2021-08-04T19:04:49.310Z,1628103889.310 [Reporter](INFO): platform_buoyancy_position 496.631378 cc 2021-08-04T19:04:49.739Z,1628103889.739 [Reporter](INFO): platform_buoyancy_position 494.616852 cc 2021-08-04T19:04:50.110Z,1628103890.110 [Reporter](INFO): platform_buoyancy_position 488.304718 cc 2021-08-04T19:04:50.515Z,1628103890.515 [Reporter](INFO): platform_buoyancy_position 485.887360 cc 2021-08-04T19:04:50.945Z,1628103890.945 [Reporter](INFO): platform_buoyancy_position 481.589752 cc 2021-08-04T19:04:51.322Z,1628103891.322 [Reporter](INFO): platform_buoyancy_position 477.157867 cc 2021-08-04T19:04:51.722Z,1628103891.722 [Reporter](INFO): platform_buoyancy_position 470.980072 cc 2021-08-04T19:04:52.154Z,1628103892.154 [Reporter](INFO): platform_buoyancy_position 466.548126 cc 2021-08-04T19:04:52.559Z,1628103892.559 [Reporter](INFO): platform_buoyancy_position 462.116241 cc 2021-08-04T19:04:53.006Z,1628103893.006 [Reporter](INFO): platform_buoyancy_position 455.938446 cc 2021-08-04T19:04:53.396Z,1628103893.396 [Reporter](INFO): platform_buoyancy_position 451.640839 cc 2021-08-04T19:04:53.755Z,1628103893.755 [Reporter](INFO): platform_buoyancy_position 447.208954 cc 2021-08-04T19:04:54.099Z,1628103894.099 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2021-08-04T19:04:54.099Z,1628103894.099 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+26.1,0000.0,10 2021-08-04T19:04:54.202Z,1628103894.202 [Reporter](INFO): platform_buoyancy_position 440.762543 cc 2021-08-04T19:04:54.587Z,1628103894.587 [Reporter](INFO): platform_buoyancy_position 434.316132 cc 2021-08-04T19:04:55.041Z,1628103895.041 [Reporter](INFO): platform_buoyancy_position 429.078461 cc 2021-08-04T19:04:55.384Z,1628103895.384 [Reporter](INFO): platform_buoyancy_position 423.840729 cc 2021-08-04T19:04:55.841Z,1628103895.841 [Reporter](INFO): platform_buoyancy_position 419.274567 cc 2021-08-04T19:04:56.260Z,1628103896.260 [Reporter](INFO): platform_buoyancy_position 412.828156 cc 2021-08-04T19:04:56.634Z,1628103896.634 [Reporter](INFO): platform_buoyancy_position 408.261932 cc 2021-08-04T19:04:57.002Z,1628103897.002 [Reporter](INFO): platform_buoyancy_position 402.218445 cc 2021-08-04T19:04:57.396Z,1628103897.396 [Reporter](INFO): platform_buoyancy_position 396.309235 cc 2021-08-04T19:04:57.784Z,1628103897.784 [Reporter](INFO): platform_buoyancy_position 391.340149 cc 2021-08-04T19:04:58.208Z,1628103898.208 [Reporter](INFO): platform_buoyancy_position 387.311127 cc 2021-08-04T19:04:58.635Z,1628103898.635 [Reporter](INFO): platform_buoyancy_position 381.133331 cc 2021-08-04T19:04:59.026Z,1628103899.026 [Reporter](INFO): platform_buoyancy_position 376.298553 cc 2021-08-04T19:04:59.421Z,1628103899.421 [Reporter](INFO): platform_buoyancy_position 372.000946 cc 2021-08-04T19:04:59.874Z,1628103899.874 [Reporter](INFO): platform_buoyancy_position 365.688843 cc 2021-08-04T19:05:00.218Z,1628103900.218 [Reporter](INFO): platform_buoyancy_position 361.122650 cc 2021-08-04T19:05:00.617Z,1628103900.617 [Reporter](INFO): platform_buoyancy_position 354.944824 cc 2021-08-04T19:05:01.018Z,1628103901.018 [Reporter](INFO): platform_buoyancy_position 350.512939 cc 2021-08-04T19:05:01.430Z,1628103901.430 [Reporter](INFO): platform_buoyancy_position 344.738037 cc 2021-08-04T19:05:01.854Z,1628103901.854 [Reporter](INFO): platform_buoyancy_position 339.768951 cc 2021-08-04T19:05:02.214Z,1628103902.214 [Reporter](INFO): platform_buoyancy_position 333.456848 cc 2021-08-04T19:05:02.650Z,1628103902.650 [Reporter](INFO): platform_buoyancy_position 329.024933 cc 2021-08-04T19:05:03.105Z,1628103903.105 [Reporter](INFO): platform_buoyancy_position 322.847137 cc 2021-08-04T19:05:03.434Z,1628103903.434 [Reporter](INFO): platform_buoyancy_position 318.415222 cc 2021-08-04T19:05:03.902Z,1628103903.902 [Reporter](INFO): platform_buoyancy_position 313.849030 cc 2021-08-04T19:05:04.302Z,1628103904.302 [Reporter](INFO): platform_buoyancy_position 309.148529 cc 2021-08-04T19:05:32.760Z,1628103932.760 [CommandLine](IMPORTANT): got command maintain control VerticalControl.massPositionAction -0.500000 centimeter 2021-08-04T19:06:35.335Z,1628103995.335 [CommandLine](IMPORTANT): got command maintain control VerticalControl.buoyancyAction 600.000000 cubic_centimeter 2021-08-04T19:06:37.742Z,1628103997.742 [Reporter](INFO): platform_buoyancy_position 301.359131 cc 2021-08-04T19:06:38.038Z,1628103998.038 [Reporter](INFO): platform_buoyancy_position 302.970734 cc 2021-08-04T19:06:38.434Z,1628103998.434 [Reporter](INFO): platform_buoyancy_position 302.836426 cc 2021-08-04T19:06:38.841Z,1628103998.841 [Reporter](INFO): platform_buoyancy_position 303.373627 cc 2021-08-04T19:06:39.262Z,1628103999.262 [Reporter](INFO): platform_buoyancy_position 307.671234 cc 2021-08-04T19:06:39.618Z,1628103999.618 [Reporter](INFO): platform_buoyancy_position 311.968842 cc 2021-08-04T19:06:40.069Z,1628104000.069 [Reporter](INFO): platform_buoyancy_position 318.280945 cc 2021-08-04T19:06:40.461Z,1628104000.461 [Reporter](INFO): platform_buoyancy_position 322.578522 cc 2021-08-04T19:06:40.822Z,1628104000.822 [Reporter](INFO): platform_buoyancy_position 328.622040 cc 2021-08-04T19:06:41.377Z,1628104001.377 [Reporter](INFO): platform_buoyancy_position 335.605621 cc 2021-08-04T19:06:41.702Z,1628104001.702 [Reporter](INFO): platform_buoyancy_position 339.768951 cc 2021-08-04T19:06:42.078Z,1628104002.078 [Reporter](INFO): platform_buoyancy_position 344.603729 cc 2021-08-04T19:06:42.502Z,1628104002.502 [Reporter](INFO): platform_buoyancy_position 350.512939 cc 2021-08-04T19:06:42.902Z,1628104002.902 [Reporter](INFO): platform_buoyancy_position 356.959351 cc 2021-08-04T19:06:43.286Z,1628104003.286 [Reporter](INFO): platform_buoyancy_position 361.391235 cc 2021-08-04T19:06:43.709Z,1628104003.709 [Reporter](INFO): platform_buoyancy_position 365.688843 cc 2021-08-04T19:06:44.136Z,1628104004.136 [Reporter](INFO): platform_buoyancy_position 374.149750 cc 2021-08-04T19:06:44.486Z,1628104004.486 [Reporter](INFO): platform_buoyancy_position 378.178741 cc 2021-08-04T19:06:44.898Z,1628104004.898 [Reporter](INFO): platform_buoyancy_position 382.879242 cc 2021-08-04T19:06:45.302Z,1628104005.302 [Reporter](INFO): platform_buoyancy_position 387.176849 cc 2021-08-04T19:06:45.670Z,1628104005.670 [Reporter](INFO): platform_buoyancy_position 393.354645 cc 2021-08-04T19:06:46.143Z,1628104006.143 [Reporter](INFO): platform_buoyancy_position 399.935333 cc 2021-08-04T19:06:46.502Z,1628104006.502 [Reporter](INFO): platform_buoyancy_position 404.232941 cc 2021-08-04T19:06:46.910Z,1628104006.910 [Reporter](INFO): platform_buoyancy_position 408.799133 cc 2021-08-04T19:06:47.290Z,1628104007.290 [Reporter](INFO): platform_buoyancy_position 414.976959 cc 2021-08-04T19:06:47.706Z,1628104007.706 [Reporter](INFO): platform_buoyancy_position 419.274567 cc 2021-08-04T19:06:48.118Z,1628104008.118 [Reporter](INFO): platform_buoyancy_position 424.109344 cc 2021-08-04T19:06:48.510Z,1628104008.510 [Reporter](INFO): platform_buoyancy_position 430.152863 cc 2021-08-04T19:06:48.929Z,1628104008.929 [Reporter](INFO): platform_buoyancy_position 434.853363 cc 2021-08-04T19:06:49.322Z,1628104009.322 [Reporter](INFO): platform_buoyancy_position 440.762543 cc 2021-08-04T19:06:49.734Z,1628104009.734 [Reporter](INFO): platform_buoyancy_position 447.208954 cc 2021-08-04T19:06:50.137Z,1628104010.137 [Reporter](INFO): platform_buoyancy_position 451.640839 cc 2021-08-04T19:06:50.538Z,1628104010.538 [Reporter](INFO): platform_buoyancy_position 455.804169 cc 2021-08-04T19:06:50.954Z,1628104010.954 [Reporter](INFO): platform_buoyancy_position 461.444733 cc 2021-08-04T19:06:51.322Z,1628104011.322 [Reporter](INFO): platform_buoyancy_position 466.682465 cc 2021-08-04T19:06:51.738Z,1628104011.738 [Reporter](INFO): platform_buoyancy_position 472.994537 cc 2021-08-04T19:06:52.162Z,1628104012.162 [Reporter](INFO): platform_buoyancy_position 477.426422 cc 2021-08-04T19:06:52.560Z,1628104012.560 [Reporter](INFO): platform_buoyancy_position 482.932770 cc 2021-08-04T19:06:52.946Z,1628104012.946 [CommandLine](IMPORTANT): got command maintain control VerticalControl.massPositionAction -1.000000 centimeter 2021-08-04T19:06:52.990Z,1628104012.990 [Reporter](INFO): platform_buoyancy_position 488.036163 cc 2021-08-04T19:06:53.368Z,1628104013.368 [Reporter](INFO): platform_buoyancy_position 494.482574 cc 2021-08-04T19:06:53.789Z,1628104013.789 [Reporter](INFO): platform_buoyancy_position 498.780121 cc 2021-08-04T19:06:54.238Z,1628104014.238 [Reporter](INFO): platform_buoyancy_position 505.360901 cc 2021-08-04T19:06:54.645Z,1628104014.645 [Reporter](INFO): platform_buoyancy_position 509.658478 cc 2021-08-04T19:06:55.089Z,1628104015.089 [Reporter](INFO): platform_buoyancy_position 515.970520 cc 2021-08-04T19:06:55.458Z,1628104015.458 [Reporter](INFO): platform_buoyancy_position 520.671021 cc 2021-08-04T19:06:55.854Z,1628104015.854 [Reporter](INFO): platform_buoyancy_position 526.714539 cc 2021-08-04T19:06:56.285Z,1628104016.285 [Reporter](INFO): platform_buoyancy_position 531.683594 cc 2021-08-04T19:06:56.650Z,1628104016.650 [Reporter](INFO): platform_buoyancy_position 537.458496 cc 2021-08-04T19:06:57.113Z,1628104017.113 [Reporter](INFO): platform_buoyancy_position 542.158997 cc 2021-08-04T19:06:57.451Z,1628104017.451 [Reporter](INFO): platform_buoyancy_position 547.128113 cc 2021-08-04T19:06:57.910Z,1628104017.910 [Reporter](INFO): platform_buoyancy_position 552.768738 cc 2021-08-04T19:06:58.222Z,1628104018.222 [Reporter](INFO): platform_buoyancy_position 557.066345 cc 2021-08-04T19:06:58.629Z,1628104018.629 [Reporter](INFO): platform_buoyancy_position 563.378418 cc 2021-08-04T19:06:59.050Z,1628104019.050 [Reporter](INFO): platform_buoyancy_position 567.676025 cc 2021-08-04T19:06:59.427Z,1628104019.427 [Reporter](INFO): platform_buoyancy_position 572.779419 cc 2021-08-04T19:06:59.877Z,1628104019.877 [Reporter](INFO): platform_buoyancy_position 578.420044 cc 2021-08-04T19:07:00.246Z,1628104020.246 [Reporter](INFO): platform_buoyancy_position 583.926331 cc 2021-08-04T19:07:00.710Z,1628104020.710 [Reporter](INFO): platform_buoyancy_position 589.029724 cc 2021-08-04T19:07:01.157Z,1628104021.157 [Reporter](INFO): platform_buoyancy_position 593.461609 cc 2021-08-04T19:07:39.023Z,1628104059.023 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-04T19:07:39.023Z,1628104059.023 [Default:CheckIn:C.Wait] Stopped 2021-08-04T19:07:39.023Z,1628104059.023 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-04T19:07:39.023Z,1628104059.023 [Default:CheckIn:D] Running Loop=1 2021-08-04T19:07:39.406Z,1628104059.406 [Default:CheckIn:D] Stopped 2021-08-04T19:07:39.406Z,1628104059.406 [Default:CheckIn:E] Running Loop=1 2021-08-04T19:07:39.800Z,1628104059.800 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 356.874707 min 2021-08-04T19:07:39.800Z,1628104059.800 [Default:CheckIn:E] Stopped 2021-08-04T19:07:39.800Z,1628104059.800 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-04T19:07:39.800Z,1628104059.800 [Default:CheckIn] Stopped 2021-08-04T19:07:39.800Z,1628104059.800 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-04T19:07:39.801Z,1628104059.801 [Default:CheckIn](INFO): Running loop #57 2021-08-04T19:07:39.801Z,1628104059.801 [Default:CheckIn] Running Loop=57 2021-08-04T19:07:39.801Z,1628104059.801 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-04T19:07:39.801Z,1628104059.801 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-04T19:07:41.796Z,1628104061.796 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190742.00,A,4149.69281,N,08324.71688,W,0.233,0.00,040821,,,D*7C 2021-08-04T19:07:41.798Z,1628104061.798 [NAL9602](INFO): GPS fix at 20210804T190742: (41.828213, -83.411948) 2021-08-04T19:07:41.849Z,1628104061.849 [Default:CheckIn:Read_GPS] Stopped 2021-08-04T19:07:41.849Z,1628104061.849 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-04T19:07:50.347Z,1628104070.347 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210804T172847/Courier0051.lzma 2021-08-04T19:07:51.350Z,1628104071.350 [DataOverHttps](INFO): Moved sent file to Logs/20210804T172847/Courier0051.lzma.bak 2021-08-04T19:07:51.350Z,1628104071.350 [DataOverHttps](INFO): SBD MOMSN=15824045 2021-08-04T19:07:58.765Z,1628104078.765 [NAL9602](INFO): SBD MO Status=0, MOMSN=41934, MT Status=0, MTMSN=0 2021-08-04T19:07:58.766Z,1628104078.766 [NAL9602](INFO): No messages in MT queue 2021-08-04T19:08:07.940Z,1628104087.940 [CommandLine](IMPORTANT): got command show variable limitAft 2021-08-04T19:08:08.018Z,1628104088.018 [CommandLine](IMPORTANT): VerticalControl.massPositionLimitAft (millimeter) 2021-08-04T19:08:08.665Z,1628104088.665 [DataOverHttps](INFO): Sending 293 bytes from file Logs/20210804T172847/Express0052.lzma 2021-08-04T19:08:09.666Z,1628104089.666 [DataOverHttps](INFO): Moved sent file to Logs/20210804T172847/Express0052.lzma.bak 2021-08-04T19:08:09.666Z,1628104089.666 [DataOverHttps](INFO): SBD MOMSN=15824051 2021-08-04T19:08:11.765Z,1628104091.765 [Default:CheckIn:Read_Iridium] Stopped 2021-08-04T19:08:11.765Z,1628104091.765 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-04T19:08:11.765Z,1628104091.765 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-04T19:08:15.003Z,1628104095.003 [CommandLine](IMPORTANT): got command get VerticalControl.massPositionLimitAft 2021-08-04T19:08:15.004Z,1628104095.004 [CommandLine](IMPORTANT): VerticalControl.massPositionLimitAft -13.000000 mm 2021-08-04T19:08:19.370Z,1628104099.370 [DVL_micro](ERROR): Failed to parse: :WI,+00000,+00000,+00000,+00000,I 2021-08-04T19:08:29.475Z,1628104109.475 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-04T19:09:01.018Z,1628104141.018 [CBIT](IMPORTANT): Beginning ground fault scan 2021-08-04T19:09:04.867Z,1628104144.867 [CommandLine](IMPORTANT): got command maintain control VerticalControl.massPositionAction 0.000000 centimeter 2021-08-04T19:09:12.014Z,1628104152.014 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.005644 CHAN A1 (24V): 0.001410 CHAN A2 (12V): -0.007991 CHAN A3 (5V): -0.004091 CHAN B0 (3.3V): -0.002432 CHAN B1 (3.15aV): -0.001487 CHAN B2 (3.15bV): -0.001478 CHAN B3 (GND): -0.000580 OPEN: 0.012015 Full Scale Calc: 4.765 mA, -1.589 mA 2021-08-04T19:11:44.269Z,1628104304.269 [DVL_micro](ERROR): Failed to parse: :WI,+00000,+00000,+00000,+0000,-00273,+01577,-00123,+000D,+00000000.00,+00000000.00,+00000000.00,000.00 2021-08-04T19:11:51.143Z,1628104311.143 [DVL_micro](ERROR): only read 3 of 4 data items 2021-08-04T19:11:51.143Z,1628104311.143 [DVL_micro](ERROR): Failed to parse: :BI,-00003,+01242,+00000,+0:BD,+00000000.00,+00000000.00,+00000000.00,0000.20,000.00 2021-08-04T19:13:12.414Z,1628104392.414 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-04T19:13:12.414Z,1628104392.414 [Default:CheckIn:C.Wait] Stopped 2021-08-04T19:13:12.414Z,1628104392.414 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-04T19:13:12.414Z,1628104392.414 [Default:CheckIn:D] Running Loop=1 2021-08-04T19:13:12.787Z,1628104392.787 [Default:CheckIn:D] Stopped 2021-08-04T19:13:12.788Z,1628104392.788 [Default:CheckIn:E] Running Loop=1 2021-08-04T19:13:13.178Z,1628104393.178 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 362.431055 min 2021-08-04T19:13:13.178Z,1628104393.178 [Default:CheckIn:E] Stopped 2021-08-04T19:13:13.178Z,1628104393.178 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-04T19:13:13.178Z,1628104393.178 [Default:CheckIn] Stopped 2021-08-04T19:13:13.178Z,1628104393.178 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-04T19:13:13.178Z,1628104393.178 [Default:CheckIn](INFO): Running loop #58 2021-08-04T19:13:13.178Z,1628104393.178 [Default:CheckIn] Running Loop=58 2021-08-04T19:13:13.178Z,1628104393.178 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-04T19:13:13.179Z,1628104393.179 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-04T19:13:15.198Z,1628104395.198 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,191315.00,A,4149.69328,N,08324.71764,W,0.156,53.15,040821,,,D*48 2021-08-04T19:13:15.200Z,1628104395.200 [NAL9602](INFO): GPS fix at 20210804T191315: (41.828221, -83.411961) 2021-08-04T19:13:15.210Z,1628104395.210 [Default:CheckIn:Read_GPS] Stopped 2021-08-04T19:13:15.210Z,1628104395.210 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-04T19:13:23.319Z,1628104403.319 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210804T172847/Courier0054.lzma 2021-08-04T19:13:24.322Z,1628104404.322 [DataOverHttps](INFO): Moved sent file to Logs/20210804T172847/Courier0054.lzma.bak 2021-08-04T19:13:24.322Z,1628104404.322 [DataOverHttps](INFO): SBD MOMSN=15824099 2021-08-04T19:13:24.492Z,1628104404.492 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2021-08-04T19:13:24.492Z,1628104404.492 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+26.0,0000.0,00 2021-08-04T19:13:45.570Z,1628104425.570 [NAL9602](INFO): SBD MO Status=0, MOMSN=41935, MT Status=0, MTMSN=0 2021-08-04T19:13:45.570Z,1628104425.570 [NAL9602](INFO): No messages in MT queue 2021-08-04T19:13:46.287Z,1628104426.287 [DataOverHttps](INFO): Sending 522 bytes from file Logs/20210804T172847/Express0055.lzma 2021-08-04T19:13:47.283Z,1628104427.283 [DataOverHttps](INFO): Moved sent file to Logs/20210804T172847/Express0055.lzma.bak 2021-08-04T19:13:47.283Z,1628104427.283 [DataOverHttps](INFO): SBD MOMSN=15824102 2021-08-04T19:13:48.803Z,1628104428.803 [Default:CheckIn:Read_Iridium] Stopped 2021-08-04T19:13:48.803Z,1628104428.803 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-04T19:13:48.803Z,1628104428.803 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-04T19:13:57.710Z,1628104437.710 [CommandLine](IMPORTANT): got command get depth 2021-08-04T19:13:57.710Z,1628104437.710 [CommandLine](IMPORTANT): depth 0.279282 m 2021-08-04T19:14:05.127Z,1628104445.127 [CommandLine](IMPORTANT): got command get height_above_sea_floor 2021-08-04T19:14:05.127Z,1628104445.127 [CommandLine](IMPORTANT): height_above_sea_floor 2.740000 m 2021-08-04T19:14:16.261Z,1628104456.261 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-04T19:14:35.754Z,1628104475.754 [CommandLine](IMPORTANT): got command maintain control VerticalControl.massPositionAction 0.500000 centimeter 2021-08-04T19:15:09.601Z,1628104509.601 [DVL_micro](ERROR): only read 3 of 4 data items 2021-08-04T19:15:09.602Z,1628104509.602 [DVL_micro](ERROR): Failed to parse: :BI,00000,+00000,+00000,I 2021-08-04T19:15:16.450Z,1628104516.450 [CommandLine](IMPORTANT): got command maintain control VerticalControl.massPositionAction 1.000000 centimeter 2021-08-04T19:15:28.588Z,1628104528.588 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2021-08-04T19:15:28.588Z,1628104528.588 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+26.0,0000.0,1489.0,,+00000,+00000,+00000,+00000,I 2021-08-04T19:15:32.239Z,1628104532.239 [DVL_micro](ERROR): only read 1 of 4 data items 2021-08-04T19:15:32.239Z,1628104532.239 [DVL_micro](ERROR): Failed to parse: :RD,+00 2021-08-04T19:16:19.499Z,1628104579.499 [CommandLine](IMPORTANT): got command maintain control VerticalControl.massPositionAction 0.500000 centimeter 2021-08-04T19:18:49.486Z,1628104729.486 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-04T19:18:49.486Z,1628104729.486 [Default:CheckIn:C.Wait] Stopped 2021-08-04T19:18:49.486Z,1628104729.486 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-04T19:18:49.486Z,1628104729.486 [Default:CheckIn:D] Running Loop=1 2021-08-04T19:18:49.862Z,1628104729.862 [Default:CheckIn:D] Stopped 2021-08-04T19:18:49.862Z,1628104729.862 [Default:CheckIn:E] Running Loop=1 2021-08-04T19:18:50.262Z,1628104730.262 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 368.048958 min 2021-08-04T19:18:50.262Z,1628104730.262 [Default:CheckIn:E] Stopped 2021-08-04T19:18:50.262Z,1628104730.262 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-04T19:18:50.262Z,1628104730.262 [Default:CheckIn] Stopped 2021-08-04T19:18:50.262Z,1628104730.262 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-04T19:18:50.263Z,1628104730.263 [Default:CheckIn](INFO): Running loop #59 2021-08-04T19:18:50.263Z,1628104730.263 [Default:CheckIn] Running Loop=59 2021-08-04T19:18:50.263Z,1628104730.263 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-04T19:18:50.263Z,1628104730.263 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-04T19:18:52.282Z,1628104732.282 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,191852.00,A,4149.69328,N,08324.71796,W,0.505,259.03,040821,,,D*70 2021-08-04T19:18:52.284Z,1628104732.284 [NAL9602](INFO): GPS fix at 20210804T191852: (41.828221, -83.411966) 2021-08-04T19:18:52.294Z,1628104732.294 [Default:CheckIn:Read_GPS] Stopped 2021-08-04T19:18:52.294Z,1628104732.294 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-04T19:18:59.783Z,1628104739.783 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210804T172847/Courier0057.lzma 2021-08-04T19:19:00.786Z,1628104740.786 [DataOverHttps](INFO): Moved sent file to Logs/20210804T172847/Courier0057.lzma.bak 2021-08-04T19:19:00.786Z,1628104740.786 [DataOverHttps](INFO): SBD MOMSN=15824153 2021-08-04T19:19:10.862Z,1628104750.862 [NAL9602](INFO): SBD MO Status=0, MOMSN=41936, MT Status=0, MTMSN=0 2021-08-04T19:19:10.862Z,1628104750.862 [NAL9602](INFO): No messages in MT queue 2021-08-04T19:19:18.036Z,1628104758.036 [DataOverHttps](INFO): Sending 337 bytes from file Logs/20210804T172847/Express0058.lzma 2021-08-04T19:19:19.038Z,1628104759.038 [DataOverHttps](INFO): Moved sent file to Logs/20210804T172847/Express0058.lzma.bak 2021-08-04T19:19:19.038Z,1628104759.038 [DataOverHttps](INFO): SBD MOMSN=15824156 2021-08-04T19:19:20.589Z,1628104760.589 [Default:CheckIn:Read_Iridium] Stopped 2021-08-04T19:19:20.589Z,1628104760.589 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-04T19:19:20.589Z,1628104760.589 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-04T19:19:41.594Z,1628104781.594 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-04T19:20:05.641Z,1628104805.641 [CommandLine](IMPORTANT): got command maintain control VerticalControl.massPositionAction 0.750000 centimeter 2021-08-04T19:20:19.980Z,1628104819.980 [DVL_micro](ERROR): Failed to parse:047,+00521,+00074,+00000,A 2021-08-04T19:20:20.376Z,1628104820.376 [CommandLine](IMPORTANT): got command maintain control VerticalControl.buoyancyAction 300.000000 cubic_centimeter 2021-08-04T19:20:22.487Z,1628104822.487 [Reporter](INFO): platform_buoyancy_position 599.908020 cc 2021-08-04T19:20:23.274Z,1628104823.274 [Reporter](INFO): platform_buoyancy_position 597.624939 cc 2021-08-04T19:20:23.698Z,1628104823.698 [Reporter](INFO): platform_buoyancy_position 591.178528 cc 2021-08-04T19:20:24.082Z,1628104824.082 [Reporter](INFO): platform_buoyancy_position 588.895447 cc 2021-08-04T19:20:24.506Z,1628104824.506 [Reporter](INFO): platform_buoyancy_position 584.732117 cc 2021-08-04T19:20:24.968Z,1628104824.968 [Reporter](INFO): platform_buoyancy_position 578.420044 cc 2021-08-04T19:20:25.306Z,1628104825.306 [Reporter](INFO): platform_buoyancy_position 574.122437 cc 2021-08-04T19:20:25.750Z,1628104825.750 [Reporter](INFO): platform_buoyancy_position 568.750427 cc 2021-08-04T19:20:26.124Z,1628104826.124 [Reporter](INFO): platform_buoyancy_position 563.244141 cc 2021-08-04T19:20:26.495Z,1628104826.495 [Reporter](INFO): platform_buoyancy_position 559.080811 cc 2021-08-04T19:20:26.961Z,1628104826.961 [Reporter](INFO): platform_buoyancy_position 552.500122 cc 2021-08-04T19:20:27.350Z,1628104827.350 [Reporter](INFO): platform_buoyancy_position 547.665344 cc 2021-08-04T19:20:27.746Z,1628104827.746 [Reporter](INFO): platform_buoyancy_position 541.890442 cc 2021-08-04T19:20:28.124Z,1628104828.124 [Reporter](INFO): platform_buoyancy_position 537.727112 cc 2021-08-04T19:20:28.526Z,1628104828.526 [Reporter](INFO): platform_buoyancy_position 532.757996 cc 2021-08-04T19:20:28.938Z,1628104828.938 [Reporter](INFO): platform_buoyancy_position 526.714539 cc 2021-08-04T19:20:29.329Z,1628104829.329 [Reporter](INFO): platform_buoyancy_position 522.551208 cc 2021-08-04T19:20:29.754Z,1628104829.754 [Reporter](INFO): platform_buoyancy_position 516.104797 cc 2021-08-04T19:20:30.134Z,1628104830.134 [Reporter](INFO): platform_buoyancy_position 511.404297 cc 2021-08-04T19:20:30.582Z,1628104830.582 [Reporter](INFO): platform_buoyancy_position 505.360901 cc 2021-08-04T19:20:30.966Z,1628104830.966 [Reporter](INFO): platform_buoyancy_position 501.063232 cc 2021-08-04T19:20:31.374Z,1628104831.374 [Reporter](INFO): platform_buoyancy_position 494.482574 cc 2021-08-04T19:20:31.779Z,1628104831.779 [Reporter](INFO): platform_buoyancy_position 490.050659 cc 2021-08-04T19:20:32.178Z,1628104832.178 [Reporter](INFO): platform_buoyancy_position 483.872833 cc 2021-08-04T19:20:32.693Z,1628104832.693 [Reporter](INFO): platform_buoyancy_position 477.292145 cc 2021-08-04T19:20:33.082Z,1628104833.082 [Reporter](INFO): platform_buoyancy_position 473.128876 cc 2021-08-04T19:20:33.381Z,1628104833.381 [Reporter](INFO): platform_buoyancy_position 468.696930 cc 2021-08-04T19:20:33.821Z,1628104833.821 [Reporter](INFO): platform_buoyancy_position 464.265045 cc 2021-08-04T19:20:34.182Z,1628104834.182 [Reporter](INFO): platform_buoyancy_position 458.221527 cc 2021-08-04T19:20:34.626Z,1628104834.626 [Reporter](INFO): platform_buoyancy_position 453.655365 cc 2021-08-04T19:20:34.993Z,1628104834.993 [Reporter](INFO): platform_buoyancy_position 449.357758 cc 2021-08-04T19:20:35.426Z,1628104835.426 [Reporter](INFO): platform_buoyancy_position 442.911346 cc 2021-08-04T19:20:35.858Z,1628104835.858 [Reporter](INFO): platform_buoyancy_position 436.464935 cc 2021-08-04T19:20:36.282Z,1628104836.282 [Reporter](INFO): platform_buoyancy_position 432.033051 cc 2021-08-04T19:20:36.766Z,1628104836.766 [Reporter](INFO): platform_buoyancy_position 424.646515 cc 2021-08-04T19:20:37.094Z,1628104837.094 [Reporter](INFO): platform_buoyancy_position 421.423370 cc 2021-08-04T19:20:37.438Z,1628104837.438 [Reporter](INFO): platform_buoyancy_position 415.514130 cc 2021-08-04T19:20:37.882Z,1628104837.882 [Reporter](INFO): platform_buoyancy_position 408.530548 cc 2021-08-04T19:20:38.242Z,1628104838.242 [Reporter](INFO): platform_buoyancy_position 404.501526 cc 2021-08-04T19:20:38.668Z,1628104838.668 [Reporter](INFO): platform_buoyancy_position 398.055145 cc 2021-08-04T19:20:39.086Z,1628104839.086 [Reporter](INFO): platform_buoyancy_position 393.623230 cc 2021-08-04T19:20:39.505Z,1628104839.505 [Reporter](INFO): platform_buoyancy_position 389.191345 cc 2021-08-04T19:20:39.902Z,1628104839.902 [Reporter](INFO): platform_buoyancy_position 382.744934 cc 2021-08-04T19:20:40.262Z,1628104840.262 [Reporter](INFO): platform_buoyancy_position 378.715942 cc 2021-08-04T19:20:40.666Z,1628104840.666 [Reporter](INFO): platform_buoyancy_position 374.015442 cc 2021-08-04T19:20:41.117Z,1628104841.117 [Reporter](INFO): platform_buoyancy_position 367.837646 cc 2021-08-04T19:20:41.526Z,1628104841.526 [Reporter](INFO): platform_buoyancy_position 361.256927 cc 2021-08-04T19:20:41.923Z,1628104841.923 [Reporter](INFO): platform_buoyancy_position 356.959351 cc 2021-08-04T19:20:42.311Z,1628104842.311 [Reporter](INFO): platform_buoyancy_position 350.781525 cc 2021-08-04T19:20:42.713Z,1628104842.713 [Reporter](INFO): platform_buoyancy_position 346.081024 cc 2021-08-04T19:20:43.075Z,1628104843.075 [Reporter](INFO): platform_buoyancy_position 341.783447 cc 2021-08-04T19:20:43.518Z,1628104843.518 [Reporter](INFO): platform_buoyancy_position 335.605621 cc 2021-08-04T19:20:43.912Z,1628104843.912 [Reporter](INFO): platform_buoyancy_position 331.173737 cc 2021-08-04T19:20:44.334Z,1628104844.334 [Reporter](INFO): platform_buoyancy_position 324.727325 cc 2021-08-04T19:20:44.651Z,1628104844.651 [DVL_micro](ERROR): Failed to parse:00000000000,35.0,+26.0,0000.0,1489.0,000 2021-08-04T19:20:44.754Z,1628104844.754 [Reporter](INFO): platform_buoyancy_position 320.429749 cc 2021-08-04T19:20:45.123Z,1628104845.123 [Reporter](INFO): platform_buoyancy_position 315.997833 cc 2021-08-04T19:20:45.647Z,1628104845.647 [Reporter](INFO): platform_buoyancy_position 309.820038 cc 2021-08-04T19:21:48.028Z,1628104908.028 [CommandLine](IMPORTANT): got command maintain clear 2021-08-04T19:21:48.140Z,1628104908.140 [controlThread](DEBUG): Component order: CycleStarter,ESPComponent,PAR_Licor,AHRS_M2,BPC1,Depth_Keller,DropWeight,DVL_micro,NAL9602,Power24vConverter,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2021-08-04T19:21:48.484Z,1628104908.484 [CommandLine](IMPORTANT): got command maintain clear 2021-08-04T19:21:50.666Z,1628104910.666 [Reporter](INFO): platform_buoyancy_position 302.836426 cc 2021-08-04T19:21:50.987Z,1628104910.987 [Reporter](INFO): platform_buoyancy_position 303.239319 cc 2021-08-04T19:21:51.390Z,1628104911.390 [Reporter](INFO): platform_buoyancy_position 303.373627 cc 2021-08-04T19:21:51.811Z,1628104911.811 [Reporter](INFO): platform_buoyancy_position 305.522430 cc 2021-08-04T19:21:52.266Z,1628104912.266 [Reporter](INFO): platform_buoyancy_position 309.820038 cc 2021-08-04T19:21:52.640Z,1628104912.640 [Reporter](INFO): platform_buoyancy_position 313.983337 cc 2021-08-04T19:21:53.154Z,1628104913.154 [Reporter](INFO): platform_buoyancy_position 320.429749 cc 2021-08-04T19:21:53.402Z,1628104913.402 [Reporter](INFO): platform_buoyancy_position 324.861633 cc 2021-08-04T19:21:53.798Z,1628104913.798 [Reporter](INFO): platform_buoyancy_position 331.308044 cc 2021-08-04T19:21:54.215Z,1628104914.215 [Reporter](INFO): platform_buoyancy_position 337.485840 cc 2021-08-04T19:21:54.598Z,1628104914.598 [Reporter](INFO): platform_buoyancy_position 342.052032 cc 2021-08-04T19:21:55.055Z,1628104915.055 [Reporter](INFO): platform_buoyancy_position 348.498444 cc 2021-08-04T19:21:55.430Z,1628104915.430 [Reporter](INFO): platform_buoyancy_position 352.796051 cc 2021-08-04T19:21:55.817Z,1628104915.817 [Reporter](INFO): platform_buoyancy_position 357.227936 cc 2021-08-04T19:21:56.274Z,1628104916.274 [Reporter](INFO): platform_buoyancy_position 363.405731 cc 2021-08-04T19:21:56.652Z,1628104916.652 [Reporter](INFO): platform_buoyancy_position 367.703339 cc 2021-08-04T19:21:57.070Z,1628104917.070 [Reporter](INFO): platform_buoyancy_position 376.432831 cc 2021-08-04T19:21:57.450Z,1628104917.450 [Reporter](INFO): platform_buoyancy_position 380.058929 cc 2021-08-04T19:21:57.906Z,1628104917.906 [Reporter](INFO): platform_buoyancy_position 385.028046 cc 2021-08-04T19:21:58.261Z,1628104918.261 [Reporter](INFO): platform_buoyancy_position 389.325653 cc 2021-08-04T19:21:58.642Z,1628104918.642 [Reporter](INFO): platform_buoyancy_position 395.637726 cc 2021-08-04T19:21:59.070Z,1628104919.070 [Reporter](INFO): platform_buoyancy_position 400.069641 cc 2021-08-04T19:21:59.431Z,1628104919.431 [Reporter](INFO): platform_buoyancy_position 406.381744 cc 2021-08-04T19:21:59.859Z,1628104919.859 [Reporter](INFO): platform_buoyancy_position 410.813629 cc 2021-08-04T19:22:00.267Z,1628104920.267 [Reporter](INFO): platform_buoyancy_position 417.125763 cc 2021-08-04T19:22:00.689Z,1628104920.689 [Reporter](INFO): platform_buoyancy_position 421.557648 cc 2021-08-04T19:22:01.070Z,1628104921.070 [Reporter](INFO): platform_buoyancy_position 426.392426 cc 2021-08-04T19:22:01.450Z,1628104921.450 [Reporter](INFO): platform_buoyancy_position 432.301666 cc 2021-08-04T19:22:01.871Z,1628104921.871 [Reporter](INFO): platform_buoyancy_position 438.479462 cc 2021-08-04T19:22:02.280Z,1628104922.280 [Reporter](INFO): platform_buoyancy_position 442.911346 cc 2021-08-04T19:22:02.678Z,1628104922.678 [Reporter](INFO): platform_buoyancy_position 447.477570 cc 2021-08-04T19:22:03.075Z,1628104923.075 [Reporter](INFO): platform_buoyancy_position 453.521027 cc 2021-08-04T19:22:03.499Z,1628104923.499 [Reporter](INFO): platform_buoyancy_position 457.818634 cc 2021-08-04T19:22:03.957Z,1628104923.957 [Reporter](INFO): platform_buoyancy_position 464.533661 cc 2021-08-04T19:22:04.322Z,1628104924.322 [Reporter](INFO): platform_buoyancy_position 470.845734 cc 2021-08-04T19:22:04.686Z,1628104924.686 [Reporter](INFO): platform_buoyancy_position 475.143341 cc 2021-08-04T19:22:05.065Z,1628104925.065 [DVL_micro](ERROR): only read 2 of 4 data items 2021-08-04T19:22:05.065Z,1628104925.065 [DVL_micro](ERROR): Failed to parse: :RD,+00002.29,+00003.13 2021-08-04T19:22:05.142Z,1628104925.142 [Reporter](INFO): platform_buoyancy_position 479.575226 cc 2021-08-04T19:22:05.518Z,1628104925.518 [Reporter](INFO): platform_buoyancy_position 486.021637 cc 2021-08-04T19:22:05.742Z,1628104925.742 [CommandLine](IMPORTANT): got command maintain clear 2021-08-04T19:22:05.914Z,1628104925.914 [Reporter](INFO): platform_buoyancy_position 490.319214 cc 2021-08-04T19:22:06.326Z,1628104926.326 [Reporter](INFO): platform_buoyancy_position 496.765656 cc 2021-08-04T19:22:06.750Z,1628104926.750 [Reporter](INFO): platform_buoyancy_position 501.466156 cc 2021-08-04T19:22:07.182Z,1628104927.182 [Reporter](INFO): platform_buoyancy_position 507.375336 cc 2021-08-04T19:22:07.578Z,1628104927.578 [Reporter](INFO): platform_buoyancy_position 511.941559 cc 2021-08-04T19:22:07.994Z,1628104927.994 [Reporter](INFO): platform_buoyancy_position 518.119324 cc 2021-08-04T19:22:08.351Z,1628104928.351 [Reporter](INFO): platform_buoyancy_position 522.551208 cc 2021-08-04T19:22:08.790Z,1628104928.790 [Reporter](INFO): platform_buoyancy_position 528.863342 cc 2021-08-04T19:22:09.142Z,1628104929.142 [Reporter](INFO): platform_buoyancy_position 533.295227 cc 2021-08-04T19:22:09.565Z,1628104929.565 [Reporter](INFO): platform_buoyancy_position 537.727112 cc 2021-08-04T19:22:09.978Z,1628104929.978 [Reporter](INFO): platform_buoyancy_position 544.039246 cc 2021-08-04T19:22:10.370Z,1628104930.370 [Reporter](INFO): platform_buoyancy_position 548.336792 cc 2021-08-04T19:22:10.759Z,1628104930.759 [Reporter](INFO): platform_buoyancy_position 554.648926 cc 2021-08-04T19:22:11.170Z,1628104931.170 [Reporter](INFO): platform_buoyancy_position 559.080811 cc 2021-08-04T19:22:11.590Z,1628104931.590 [Reporter](INFO): platform_buoyancy_position 565.392944 cc 2021-08-04T19:22:11.990Z,1628104931.990 [Reporter](INFO): platform_buoyancy_position 569.824829 cc 2021-08-04T19:22:12.378Z,1628104932.378 [Reporter](INFO): platform_buoyancy_position 576.136902 cc 2021-08-04T19:22:12.794Z,1628104932.794 [Reporter](INFO): platform_buoyancy_position 580.434509 cc 2021-08-04T19:22:13.182Z,1628104933.182 [Reporter](INFO): platform_buoyancy_position 585.000732 cc 2021-08-04T19:22:13.571Z,1628104933.571 [Reporter](INFO): platform_buoyancy_position 591.178528 cc 2021-08-04T19:22:13.997Z,1628104933.997 [Reporter](INFO): platform_buoyancy_position 595.744751 cc 2021-08-04T19:22:14.410Z,1628104934.410 [Reporter](INFO): platform_buoyancy_position 602.056824 cc 2021-08-04T19:22:14.878Z,1628104934.878 [Reporter](INFO): platform_buoyancy_position 608.503235 cc 2021-08-04T19:22:15.190Z,1628104935.190 [Reporter](INFO): platform_buoyancy_position 612.800842 cc 2021-08-04T19:22:15.613Z,1628104935.613 [Reporter](INFO): platform_buoyancy_position 617.232727 cc 2021-08-04T19:22:16.026Z,1628104936.026 [Reporter](INFO): platform_buoyancy_position 623.410522 cc 2021-08-04T19:22:16.398Z,1628104936.398 [Reporter](INFO): platform_buoyancy_position 627.708130 cc 2021-08-04T19:22:16.811Z,1628104936.811 [Reporter](INFO): platform_buoyancy_position 634.288818 cc 2021-08-04T19:22:17.230Z,1628104937.230 [Reporter](INFO): platform_buoyancy_position 638.452148 cc 2021-08-04T19:22:17.632Z,1628104937.632 [Reporter](INFO): platform_buoyancy_position 644.898499 cc 2021-08-04T19:22:18.070Z,1628104938.070 [Reporter](INFO): platform_buoyancy_position 649.733337 cc 2021-08-04T19:22:18.430Z,1628104938.430 [Reporter](INFO): platform_buoyancy_position 655.642517 cc 2021-08-04T19:22:18.850Z,1628104938.850 [Reporter](INFO): platform_buoyancy_position 660.074402 cc 2021-08-04T19:22:19.251Z,1628104939.251 [Reporter](INFO): platform_buoyancy_position 665.849304 cc 2021-08-04T19:22:19.678Z,1628104939.678 [Reporter](INFO): platform_buoyancy_position 670.818420 cc 2021-08-04T19:22:20.050Z,1628104940.050 [Reporter](INFO): platform_buoyancy_position 675.116028 cc 2021-08-04T19:22:20.462Z,1628104940.462 [Reporter](INFO): platform_buoyancy_position 681.562439 cc 2021-08-04T19:22:20.882Z,1628104940.882 [Reporter](INFO): platform_buoyancy_position 686.128601 cc 2021-08-04T19:22:21.290Z,1628104941.290 [Reporter](INFO): platform_buoyancy_position 692.172119 cc 2021-08-04T19:22:21.715Z,1628104941.715 [Reporter](INFO): platform_buoyancy_position 698.484253 cc 2021-08-04T19:22:22.106Z,1628104942.106 [Reporter](INFO): platform_buoyancy_position 703.050415 cc 2021-08-04T19:22:22.501Z,1628104942.501 [Reporter](INFO): platform_buoyancy_position 707.348022 cc 2021-08-04T19:22:22.874Z,1628104942.874 [Reporter](INFO): platform_buoyancy_position 713.794434 cc 2021-08-04T19:22:23.286Z,1628104943.286 [Reporter](INFO): platform_buoyancy_position 717.957764 cc 2021-08-04T19:22:23.714Z,1628104943.714 [Reporter](INFO): platform_buoyancy_position 724.404114 cc 2021-08-04T19:22:24.076Z,1628104944.076 [Reporter](INFO): platform_buoyancy_position 728.701721 cc 2021-08-04T19:22:24.499Z,1628104944.499 [Reporter](INFO): platform_buoyancy_position 733.133606 cc 2021-08-04T19:22:24.914Z,1628104944.914 [Reporter](INFO): platform_buoyancy_position 739.445740 cc 2021-08-04T19:22:25.302Z,1628104945.302 [Reporter](INFO): platform_buoyancy_position 743.877625 cc 2021-08-04T19:22:25.789Z,1628104945.789 [Reporter](INFO): platform_buoyancy_position 751.801331 cc 2021-08-04T19:22:26.145Z,1628104946.145 [Reporter](INFO): platform_buoyancy_position 755.158813 cc 2021-08-04T19:22:26.575Z,1628104946.575 [Reporter](INFO): platform_buoyancy_position 761.068054 cc 2021-08-04T19:22:26.969Z,1628104946.969 [Reporter](INFO): platform_buoyancy_position 767.514465 cc 2021-08-04T19:22:27.342Z,1628104947.342 [Reporter](INFO): platform_buoyancy_position 771.677734 cc 2021-08-04T19:22:27.754Z,1628104947.754 [Reporter](INFO): platform_buoyancy_position 776.243958 cc 2021-08-04T19:22:28.156Z,1628104948.156 [Reporter](INFO): platform_buoyancy_position 782.421753 cc 2021-08-04T19:22:28.570Z,1628104948.570 [Reporter](INFO): platform_buoyancy_position 787.122253 cc 2021-08-04T19:22:28.986Z,1628104948.986 [Reporter](INFO): platform_buoyancy_position 793.300049 cc 2021-08-04T19:22:29.403Z,1628104949.403 [Reporter](INFO): platform_buoyancy_position 799.612122 cc 2021-08-04T19:22:29.766Z,1628104949.766 [Reporter](INFO): platform_buoyancy_position 803.775452 cc 2021-08-04T19:22:30.154Z,1628104950.154 [Reporter](INFO): platform_buoyancy_position 808.341614 cc 2021-08-04T19:22:30.634Z,1628104950.634 [Reporter](INFO): platform_buoyancy_position 814.788025 cc 2021-08-04T19:22:30.942Z,1628104950.942 [Reporter](INFO): platform_buoyancy_position 818.951355 cc 2021-08-04T19:22:31.363Z,1628104951.363 [Reporter](INFO): platform_buoyancy_position 825.397766 cc 2021-08-04T19:22:31.790Z,1628104951.790 [Reporter](INFO): platform_buoyancy_position 829.829651 cc 2021-08-04T19:22:32.158Z,1628104952.158 [Reporter](INFO): platform_buoyancy_position 833.992920 cc 2021-08-04T19:22:32.587Z,1628104952.587 [Reporter](INFO): platform_buoyancy_position 840.439331 cc 2021-08-04T19:22:32.970Z,1628104952.970 [Reporter](INFO): platform_buoyancy_position 844.871216 cc 2021-08-04T19:22:33.386Z,1628104953.386 [Reporter](INFO): platform_buoyancy_position 851.317627 cc 2021-08-04T19:22:33.898Z,1628104953.898 [Reporter](INFO): platform_buoyancy_position 857.629761 cc 2021-08-04T19:22:34.281Z,1628104954.281 [Reporter](INFO): platform_buoyancy_position 862.061646 cc 2021-08-04T19:22:34.645Z,1628104954.645 [Reporter](INFO): platform_buoyancy_position 866.359253 cc 2021-08-04T19:22:35.021Z,1628104955.021 [Reporter](INFO): platform_buoyancy_position 871.059753 cc 2021-08-04T19:22:35.427Z,1628104955.427 [Reporter](INFO): platform_buoyancy_position 877.103271 cc 2021-08-04T19:22:35.814Z,1628104955.814 [Reporter](INFO): platform_buoyancy_position 881.400818 cc 2021-08-04T19:22:36.225Z,1628104956.225 [Reporter](INFO): platform_buoyancy_position 887.847229 cc 2021-08-04T19:22:36.650Z,1628104956.650 [Reporter](INFO): platform_buoyancy_position 894.293640 cc 2021-08-04T19:22:37.030Z,1628104957.030 [Reporter](INFO): platform_buoyancy_position 898.591248 cc 2021-08-04T19:22:37.537Z,1628104957.537 [Reporter](INFO): platform_buoyancy_position 905.037659 cc 2021-08-04T19:22:37.969Z,1628104957.969 [Reporter](INFO): platform_buoyancy_position 911.349731 cc 2021-08-04T19:22:38.278Z,1628104958.278 [Reporter](INFO): platform_buoyancy_position 915.647339 cc 2021-08-04T19:22:38.671Z,1628104958.671 [Reporter](INFO): platform_buoyancy_position 919.944946 cc 2021-08-04T19:22:39.070Z,1628104959.070 [Reporter](INFO): platform_buoyancy_position 924.376831 cc 2021-08-04T19:22:39.494Z,1628104959.494 [Reporter](INFO): platform_buoyancy_position 930.688965 cc 2021-08-04T19:22:39.907Z,1628104959.907 [Reporter](INFO): platform_buoyancy_position 935.120850 cc 2021-08-04T19:22:40.293Z,1628104960.293 [Reporter](INFO): platform_buoyancy_position 941.432983 cc 2021-08-04T19:22:40.698Z,1628104960.698 [Reporter](INFO): platform_buoyancy_position 945.730591 cc 2021-08-04T19:24:21.226Z,1628105061.226 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-04T19:24:21.226Z,1628105061.226 [Default:CheckIn:C.Wait] Stopped 2021-08-04T19:24:21.226Z,1628105061.226 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-04T19:24:21.226Z,1628105061.226 [Default:CheckIn:D] Running Loop=1 2021-08-04T19:24:21.637Z,1628105061.637 [Default:CheckIn:D] Stopped 2021-08-04T19:24:21.637Z,1628105061.637 [Default:CheckIn:E] Running Loop=1 2021-08-04T19:24:22.044Z,1628105062.044 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 373.578548 min 2021-08-04T19:24:22.044Z,1628105062.044 [Default:CheckIn:E] Stopped 2021-08-04T19:24:22.044Z,1628105062.044 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-04T19:24:22.045Z,1628105062.045 [Default:CheckIn] Stopped 2021-08-04T19:24:22.045Z,1628105062.045 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-04T19:24:22.045Z,1628105062.045 [Default:CheckIn](INFO): Running loop #60 2021-08-04T19:24:22.045Z,1628105062.045 [Default:CheckIn] Running Loop=60 2021-08-04T19:24:22.045Z,1628105062.045 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-04T19:24:22.045Z,1628105062.045 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-04T19:24:24.044Z,1628105064.044 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,192424.00,A,4149.69228,N,08324.71648,W,0.058,304.15,040821,,,D*7E 2021-08-04T19:24:24.046Z,1628105064.046 [NAL9602](INFO): GPS fix at 20210804T192424: (41.828205, -83.411941) 2021-08-04T19:24:24.060Z,1628105064.060 [Default:CheckIn:Read_GPS] Stopped 2021-08-04T19:24:24.061Z,1628105064.061 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-04T19:24:31.375Z,1628105071.375 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210804T172847/Courier0060.lzma 2021-08-04T19:24:32.378Z,1628105072.378 [DataOverHttps](INFO): Moved sent file to Logs/20210804T172847/Courier0060.lzma.bak 2021-08-04T19:24:32.378Z,1628105072.378 [DataOverHttps](INFO): SBD MOMSN=15824215 2021-08-04T19:24:43.509Z,1628105083.509 [NAL9602](INFO): SBD MO Status=2, MOMSN=41937, MT Status=2, MTMSN=0 2021-08-04T19:24:43.509Z,1628105083.509 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-04T19:24:53.187Z,1628105093.187 [NAL9602](INFO): SBD MO Status=0, MOMSN=41937, MT Status=0, MTMSN=0 2021-08-04T19:24:53.188Z,1628105093.188 [NAL9602](INFO): No messages in MT queue 2021-08-04T19:24:55.116Z,1628105095.116 [DataOverHttps](INFO): Sending 265 bytes from file Logs/20210804T172847/Express0061.lzma 2021-08-04T19:24:55.615Z,1628105095.615 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2021-08-04T19:24:55.616Z,1628105095.616 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,30,0000.0,1489.0,000 2021-08-04T19:24:56.118Z,1628105096.118 [DataOverHttps](INFO): Moved sent file to Logs/20210804T172847/Express0061.lzma.bak 2021-08-04T19:24:56.118Z,1628105096.118 [DataOverHttps](INFO): SBD MOMSN=15824218 2021-08-04T19:24:58.051Z,1628105098.051 [Default:CheckIn:Read_Iridium] Stopped 2021-08-04T19:24:58.051Z,1628105098.051 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-04T19:24:58.051Z,1628105098.051 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-04T19:25:23.896Z,1628105123.896 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-04T19:25:29.954Z,1628105129.954 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2021-08-04T19:25:29.954Z,1628105129.954 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+26.0,0000.0,10 2021-08-04T19:27:15.105Z,1628105235.105 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2021-08-04T19:27:15.106Z,1628105235.106 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+26.0,0000.0,1489.0,,+00000,+0000,+00000,I 2021-08-04T19:27:27.223Z,1628105247.223 [DVL_micro](ERROR): only read 3 of 4 data items 2021-08-04T19:27:27.223Z,1628105247.223 [DVL_micro](ERROR): Failed to parse: :RD,+0000.34,+0001.24,+0000.35, 2021-08-04T19:29:01.108Z,1628105341.108 [DVL_micro](ERROR): Failed to parse: 0.34,+0001.09,+0000.38,+0003.12 2021-08-04T19:29:58.611Z,1628105398.611 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-04T19:29:58.611Z,1628105398.611 [Default:CheckIn:C.Wait] Stopped 2021-08-04T19:29:58.611Z,1628105398.611 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-04T19:29:58.611Z,1628105398.611 [Default:CheckIn:D] Running Loop=1 2021-08-04T19:29:58.978Z,1628105398.978 [Default:CheckIn:D] Stopped 2021-08-04T19:29:58.978Z,1628105398.978 [Default:CheckIn:E] Running Loop=1 2021-08-04T19:29:59.395Z,1628105399.395 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 379.200879 min 2021-08-04T19:29:59.395Z,1628105399.395 [Default:CheckIn:E] Stopped 2021-08-04T19:29:59.396Z,1628105399.396 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-04T19:29:59.396Z,1628105399.396 [Default:CheckIn] Stopped 2021-08-04T19:29:59.396Z,1628105399.396 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-04T19:29:59.396Z,1628105399.396 [Default:CheckIn](INFO): Running loop #61 2021-08-04T19:29:59.396Z,1628105399.396 [Default:CheckIn] Running Loop=61 2021-08-04T19:29:59.396Z,1628105399.396 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-04T19:29:59.396Z,1628105399.396 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-04T19:30:01.375Z,1628105401.375 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,193001.00,A,4149.69178,N,08324.71539,W,0.175,304.15,040821,,,D*71 2021-08-04T19:30:01.377Z,1628105401.377 [NAL9602](INFO): GPS fix at 20210804T193001: (41.828196, -83.411923) 2021-08-04T19:30:01.387Z,1628105401.387 [Default:CheckIn:Read_GPS] Stopped 2021-08-04T19:30:01.387Z,1628105401.387 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-04T19:30:09.071Z,1628105409.071 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210804T172847/Courier0063.lzma 2021-08-04T19:30:10.074Z,1628105410.074 [DataOverHttps](INFO): Moved sent file to Logs/20210804T172847/Courier0063.lzma.bak 2021-08-04T19:30:10.074Z,1628105410.074 [DataOverHttps](INFO): SBD MOMSN=15824270 2021-08-04T19:30:15.111Z,1628105415.111 [NAL9602](INFO): SBD MO Status=0, MOMSN=41938, MT Status=0, MTMSN=0 2021-08-04T19:30:15.130Z,1628105415.130 [NAL9602](INFO): No messages in MT queue 2021-08-04T19:30:27.348Z,1628105427.348 [DataOverHttps](INFO): Sending 152 bytes from file Logs/20210804T172847/Express0064.lzma 2021-08-04T19:30:28.350Z,1628105428.350 [DataOverHttps](INFO): Moved sent file to Logs/20210804T172847/Express0064.lzma.bak 2021-08-04T19:30:28.350Z,1628105428.350 [DataOverHttps](INFO): SBD MOMSN=15824273 2021-08-04T19:30:30.083Z,1628105430.083 [Default:CheckIn:Read_Iridium] Stopped 2021-08-04T19:30:30.108Z,1628105430.108 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-04T19:30:30.108Z,1628105430.108 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-04T19:30:45.890Z,1628105445.890 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-04T19:32:25.354Z,1628105545.354 [DVL_micro](ERROR): only read 3 of 4 data items 2021-08-04T19:32:25.355Z,1628105545.355 [DVL_micro](ERROR): Failed to parse: :BI,+00012,-0034,+00000,A 2021-08-04T19:33:17.167Z,1628105597.167 [DVL_micro](ERROR): only read 1 of 4 data items 2021-08-04T19:33:17.168Z,1628105597.168 [DVL_micro](ERROR): Failed to parse: :RD,+0000.34,,+0000.35,+0003.17 2021-08-04T19:33:17.919Z,1628105597.919 [CommandLine](IMPORTANT): got command get depth 2021-08-04T19:33:17.920Z,1628105597.920 [CommandLine](IMPORTANT): depth 0.260891 m 2021-08-04T19:33:48.935Z,1628105628.935 [CommandLine](IMPORTANT): got command show variable offset 2021-08-04T19:33:48.949Z,1628105628.949 [CommandLine](IMPORTANT): Docked.dockingDepthOffset (meter) 2021-08-04T19:33:48.991Z,1628105628.991 [CommandLine](IMPORTANT): Depth_Keller.offset (decibar) 2021-08-04T19:33:48.991Z,1628105628.991 [CommandLine](IMPORTANT): DVL_micro.pitchOffset (degree) 2021-08-04T19:33:49.004Z,1628105629.004 [CommandLine](IMPORTANT): DVL_micro.rollOffset (degree) 2021-08-04T19:33:49.025Z,1628105629.025 [CommandLine](IMPORTANT): PNI_TCM.pitchOffset (degree) 2021-08-04T19:33:49.025Z,1628105629.025 [CommandLine](IMPORTANT): PNI_TCM.rollOffset (degree) 2021-08-04T19:33:49.027Z,1628105629.027 [CommandLine](IMPORTANT): Rowe_600.headingOffset (degree) 2021-08-04T19:33:49.028Z,1628105629.028 [CommandLine](IMPORTANT): Rowe_600.pitchOffset (degree) 2021-08-04T19:33:49.028Z,1628105629.028 [CommandLine](IMPORTANT): Rowe_600.rollOffset (degree) 2021-08-04T19:33:49.160Z,1628105629.160 [CommandLine](IMPORTANT): Config/Simulator.buoyancyNeutralOffset (cubic_centimeter) 2021-08-04T19:33:49.161Z,1628105629.161 [CommandLine](IMPORTANT): Config/Simulator.massPositionOffset (millimeter) 2021-08-04T19:33:49.163Z,1628105629.163 [CommandLine](IMPORTANT): BuoyancyServo.offsetVolume (cubic_centimeter) 2021-08-04T19:33:49.217Z,1628105629.217 [CommandLine](IMPORTANT): DockingServo.offsetAngle (degree) 2021-08-04T19:33:49.219Z,1628105629.219 [CommandLine](IMPORTANT): ElevatorServo.offsetAngle (degree) 2021-08-04T19:33:49.234Z,1628105629.234 [CommandLine](IMPORTANT): RudderServo.offsetAngle (degree) 2021-08-04T19:33:49.317Z,1628105629.317 [CommandLine](IMPORTANT): CTD_NeilBrown.offset (decibar) 2021-08-04T19:33:49.318Z,1628105629.318 [CommandLine](IMPORTANT): CTD_Seabird.offset (decibar) 2021-08-04T19:33:49.319Z,1628105629.319 [CommandLine](IMPORTANT): CTD_Seabird.oxygenCalCoeffFOffset (none) 2021-08-04T19:33:49.356Z,1628105629.356 [CommandLine](IMPORTANT): ElevatorOffsetCalculator.loadAtStartup (bool) 2021-08-04T19:33:49.357Z,1628105629.357 [CommandLine](IMPORTANT): ElevatorOffsetCalculator.targetConfidenceLevel (percent) 2021-08-04T19:33:49.357Z,1628105629.357 [CommandLine](IMPORTANT): ElevatorOffsetCalculator.targetErrorBound (degree) 2021-08-04T19:33:49.357Z,1628105629.357 [CommandLine](IMPORTANT): ElevatorOffsetCalculator.verbosity (count) 2021-08-04T19:33:49.368Z,1628105629.368 [CommandLine](IMPORTANT): CBIT.runElevOffsetCalc (bool) 2021-08-04T19:33:49.369Z,1628105629.369 [CommandLine](IMPORTANT): CBIT.gfBattOffset (microampere) 2021-08-04T19:33:49.369Z,1628105629.369 [CommandLine](IMPORTANT): CBIT.gf24Offset (microampere) 2021-08-04T19:33:49.370Z,1628105629.370 [CommandLine](IMPORTANT): CBIT.gf12Offset (microampere) 2021-08-04T19:33:49.370Z,1628105629.370 [CommandLine](IMPORTANT): CBIT.gf5Offset (microampere) 2021-08-04T19:33:49.371Z,1628105629.371 [CommandLine](IMPORTANT): CBIT.gf3_3Offset (microampere) 2021-08-04T19:33:49.371Z,1628105629.371 [CommandLine](IMPORTANT): CBIT.gf3_15Offset (microampere) 2021-08-04T19:33:49.371Z,1628105629.371 [CommandLine](IMPORTANT): CBIT.gfCommOffset (microampere) 2021-08-04T19:33:49.438Z,1628105629.438 [CommandLine](IMPORTANT): CBIT.empiricalFaultElevOffset (radian) 2021-08-04T19:33:49.467Z,1628105629.467 [CommandLine](IMPORTANT): ElevatorOffsetCalculator.enableBroadcast (bool) 2021-08-04T19:33:49.468Z,1628105629.468 [CommandLine](IMPORTANT): ElevatorOffsetCalculator.elevator_angle_average (radian) 2021-08-04T19:33:49.468Z,1628105629.468 [CommandLine](IMPORTANT): ElevatorOffsetCalculator.elevator_angle_variance (radian) 2021-08-04T19:33:49.469Z,1628105629.469 [CommandLine](IMPORTANT): ElevatorOffsetCalculator.elevator_angle_error_bound (radian) 2021-08-04T19:33:49.469Z,1628105629.469 [CommandLine](IMPORTANT): ElevatorOffsetCalculator.elevator_angle_cmd_speed_identifier (meter_per_second) 2021-08-04T19:33:49.470Z,1628105629.470 [CommandLine](IMPORTANT): ElevatorOffsetCalculator.elevator_angle_cmd_pitch_identifier (radian) 2021-08-04T19:33:49.470Z,1628105629.470 [CommandLine](IMPORTANT): ElevatorOffsetCalculator.elevator_angle_cmd_mass_position_identifier (meter) 2021-08-04T19:34:05.720Z,1628105645.720 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2021-08-04T19:34:05.720Z,1628105645.720 [DVL_micro](ERROR): Failed to parse::TS,00000000000000,35.0,+26.1,0000.,000 2021-08-04T19:34:08.068Z,1628105648.068 [CommandLine](IMPORTANT): got command get Depth_Keller.offset 2021-08-04T19:34:08.069Z,1628105648.069 [CommandLine](IMPORTANT): Depth_Keller.offset -0.285900 db 2021-08-04T19:34:29.690Z,1628105669.690 [CommandLine](IMPORTANT): got command get depth 2021-08-04T19:34:29.690Z,1628105669.690 [CommandLine](IMPORTANT): depth 0.270311 m 2021-08-04T19:34:58.786Z,1628105698.786 [CommandLine](IMPORTANT): got command configSet Depth_Keller.offset -0.550000 decibar persist 2021-08-04T19:35:03.587Z,1628105703.587 [CommandLine](IMPORTANT): got command get depth 2021-08-04T19:35:03.588Z,1628105703.588 [CommandLine](IMPORTANT): depth 0.006933 m 2021-08-04T19:35:30.717Z,1628105730.717 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-04T19:35:30.717Z,1628105730.717 [Default:CheckIn:C.Wait] Stopped 2021-08-04T19:35:30.717Z,1628105730.717 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-04T19:35:30.717Z,1628105730.717 [Default:CheckIn:D] Running Loop=1 2021-08-04T19:35:31.080Z,1628105731.080 [Default:CheckIn:D] Stopped 2021-08-04T19:35:31.080Z,1628105731.080 [Default:CheckIn:E] Running Loop=1 2021-08-04T19:35:31.486Z,1628105731.486 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 384.735937 min 2021-08-04T19:35:31.486Z,1628105731.486 [Default:CheckIn:E] Stopped 2021-08-04T19:35:31.486Z,1628105731.486 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-04T19:35:31.486Z,1628105731.486 [Default:CheckIn] Stopped 2021-08-04T19:35:31.486Z,1628105731.486 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-04T19:35:31.486Z,1628105731.486 [Default:CheckIn](INFO): Running loop #62 2021-08-04T19:35:31.486Z,1628105731.486 [Default:CheckIn] Running Loop=62 2021-08-04T19:35:31.487Z,1628105731.487 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-04T19:35:31.487Z,1628105731.487 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-04T19:35:33.466Z,1628105733.466 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,193534.00,A,4149.69631,N,08324.71704,W,0.078,304.15,040821,,,D*78 2021-08-04T19:35:33.477Z,1628105733.477 [NAL9602](INFO): GPS fix at 20210804T193534: (41.828272, -83.411951) 2021-08-04T19:35:33.487Z,1628105733.487 [Default:CheckIn:Read_GPS] Stopped 2021-08-04T19:35:33.487Z,1628105733.487 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-04T19:35:46.062Z,1628105746.062 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210804T172847/Courier0066.lzma 2021-08-04T19:35:47.062Z,1628105747.062 [DataOverHttps](INFO): Moved sent file to Logs/20210804T172847/Courier0066.lzma.bak 2021-08-04T19:35:47.062Z,1628105747.062 [DataOverHttps](INFO): SBD MOMSN=15824321 2021-08-04T19:35:48.633Z,1628105748.633 [NAL9602](INFO): SBD MO Status=0, MOMSN=41939, MT Status=0, MTMSN=0 2021-08-04T19:35:48.633Z,1628105748.633 [NAL9602](INFO): No messages in MT queue 2021-08-04T19:36:04.198Z,1628105764.198 [DataOverHttps](INFO): Sending 922 bytes from file Logs/20210804T172847/Express0067.lzma 2021-08-04T19:36:05.198Z,1628105765.198 [DataOverHttps](INFO): Moved sent file to Logs/20210804T172847/Express0067.lzma.bak 2021-08-04T19:36:05.198Z,1628105765.198 [DataOverHttps](INFO): SBD MOMSN=15824324 2021-08-04T19:36:06.799Z,1628105766.799 [Default:CheckIn:Read_Iridium] Stopped 2021-08-04T19:36:06.799Z,1628105766.799 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-04T19:36:06.799Z,1628105766.799 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-04T19:36:19.317Z,1628105779.317 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-04T19:39:11.042Z,1628105951.042 [DVL_micro](ERROR): Failed to parse: :B,-00655,-00126,+00000,A 2021-08-04T19:39:47.861Z,1628105987.861 [DataOverHttps](IMPORTANT): SBD MTMSN=20210804T193948 2021-08-04T19:39:55.932Z,1628105995.932 [DataOverHttps](INFO): Received command:ibit 2021-08-04T19:39:55.972Z,1628105995.972 [CommandLine](IMPORTANT): got command ibit 2021-08-04T19:39:56.371Z,1628105996.371 [IBIT](IMPORTANT): Beginning Initiated BIT 2021-08-04T19:39:56.372Z,1628105996.372 [IBIT](IMPORTANT): Beginning control surface checks. 2021-08-04T19:39:56.383Z,1628105996.383 [CBIT](IMPORTANT): Beginning ground fault scan 2021-08-04T19:39:57.913Z,1628105997.913 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,193958.00,A,4149.69450,N,08324.71635,W,0.039,304.15,040821,,,D*7D 2021-08-04T19:39:57.915Z,1628105997.915 [NAL9602](INFO): GPS fix at 20210804T193958: (41.828242, -83.411939) 2021-08-04T19:40:03.568Z,1628106003.568 [NAL9602](INFO): SBD MO Status=0, MOMSN=41940, MT Status=0, MTMSN=0 2021-08-04T19:40:03.568Z,1628106003.568 [NAL9602](INFO): No messages in MT queue 2021-08-04T19:40:04.774Z,1628106004.774 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194005.00,A,4149.69433,N,08324.71635,W,0.078,304.15,040821,,,D*7B 2021-08-04T19:40:04.777Z,1628106004.777 [NAL9602](INFO): GPS fix at 20210804T194005: (41.828239, -83.411939) 2021-08-04T19:40:07.278Z,1628106007.278 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.006705 CHAN A1 (24V): 0.001436 CHAN A2 (12V): -0.005473 CHAN A3 (5V): -0.003546 CHAN B0 (3.3V): -0.002215 CHAN B1 (3.15aV): -0.001503 CHAN B2 (3.15bV): -0.001618 CHAN B3 (GND): -0.001175 OPEN: 0.011897 Full Scale Calc: 4.765 mA, -1.589 mA 2021-08-04T19:40:07.600Z,1628106007.600 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194008.00,A,4149.69439,N,08324.71638,W,0.156,304.15,040821,,,D*7C 2021-08-04T19:40:07.602Z,1628106007.602 [NAL9602](INFO): GPS fix at 20210804T194008: (41.828240, -83.411940) 2021-08-04T19:40:10.848Z,1628106010.848 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194011.00,A,4149.69451,N,08324.71638,W,0.058,304.15,040821,,,D*75 2021-08-04T19:40:10.851Z,1628106010.851 [NAL9602](INFO): GPS fix at 20210804T194011: (41.828242, -83.411940) 2021-08-04T19:40:13.663Z,1628106013.663 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194014.00,A,4149.69462,N,08324.71644,W,0.039,304.15,040821,,,D*7C 2021-08-04T19:40:13.666Z,1628106013.666 [NAL9602](INFO): GPS fix at 20210804T194014: (41.828244, -83.411941) 2021-08-04T19:40:16.896Z,1628106016.896 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194017.00,A,4149.69471,N,08324.71644,W,0.136,304.15,040821,,,D*73 2021-08-04T19:40:16.899Z,1628106016.899 [NAL9602](INFO): GPS fix at 20210804T194017: (41.828245, -83.411941) 2021-08-04T19:40:19.722Z,1628106019.722 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194020.00,A,4149.69480,N,08324.71644,W,0.156,304.15,040821,,,D*7F 2021-08-04T19:40:19.725Z,1628106019.725 [NAL9602](INFO): GPS fix at 20210804T194020: (41.828247, -83.411941) 2021-08-04T19:40:22.950Z,1628106022.950 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194023.00,A,4149.69489,N,08324.71643,W,0.097,304.15,040821,,,D*7E 2021-08-04T19:40:22.953Z,1628106022.953 [NAL9602](INFO): GPS fix at 20210804T194023: (41.828248, -83.411941) 2021-08-04T19:40:25.780Z,1628106025.780 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194026.00,A,4149.69494,N,08324.71656,W,0.097,304.15,040821,,,D*73 2021-08-04T19:40:25.782Z,1628106025.782 [NAL9602](INFO): GPS fix at 20210804T194026: (41.828249, -83.411943) 2021-08-04T19:40:28.615Z,1628106028.615 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194029.00,A,4149.69489,N,08324.71665,W,0.058,304.15,040821,,,D*73 2021-08-04T19:40:28.628Z,1628106028.628 [NAL9602](INFO): GPS fix at 20210804T194029: (41.828248, -83.411944) 2021-08-04T19:40:31.839Z,1628106031.839 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194032.00,A,4149.69472,N,08324.71660,W,0.097,304.15,040821,,,D*7B 2021-08-04T19:40:31.850Z,1628106031.850 [NAL9602](INFO): GPS fix at 20210804T194032: (41.828245, -83.411943) 2021-08-04T19:40:34.678Z,1628106034.678 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194035.00,A,4149.69472,N,08324.71652,W,0.156,304.15,040821,,,D*71 2021-08-04T19:40:34.680Z,1628106034.680 [NAL9602](INFO): GPS fix at 20210804T194035: (41.828245, -83.411942) 2021-08-04T19:40:37.918Z,1628106037.918 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194038.00,A,4149.69488,N,08324.71640,W,0.097,304.15,040821,,,D*76 2021-08-04T19:40:37.944Z,1628106037.944 [NAL9602](INFO): GPS fix at 20210804T194038: (41.828248, -83.411940) 2021-08-04T19:40:40.782Z,1628106040.782 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194041.00,A,4149.69499,N,08324.71649,W,0.019,304.15,040821,,,D*77 2021-08-04T19:40:40.788Z,1628106040.788 [NAL9602](INFO): GPS fix at 20210804T194041: (41.828250, -83.411941) 2021-08-04T19:40:42.798Z,1628106042.798 [IBIT](IMPORTANT): Communications Status: Fix Status: 1 Iridium Signal Strength: 5 Latitude: 41.828251 Longitude: -83.411942 2021-08-04T19:40:43.321Z,1628106043.321 [IBIT](IMPORTANT): Battery Status: Battery Charge (AH): 0.000000 Voltage: 16.532000 2021-08-04T19:40:43.322Z,1628106043.322 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah 2021-08-04T19:40:43.322Z,1628106043.322 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V 2021-08-04T19:40:43.591Z,1628106043.591 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 % 2021-08-04T19:40:43.591Z,1628106043.591 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi 2021-08-04T19:40:43.591Z,1628106043.591 [IBIT](IMPORTANT): Pressure:8.034412 PSI 2021-08-04T19:40:43.592Z,1628106043.592 [IBIT](IMPORTANT): Humidity:16.817238 % 2021-08-04T19:40:44.014Z,1628106044.014 [IBIT](IMPORTANT): Vehicle Pitch:-1.591349 degrees 2021-08-04T19:40:44.014Z,1628106044.014 [IBIT](IMPORTANT): Vehicle Roll:11.750868 degrees 2021-08-04T19:40:44.014Z,1628106044.014 [IBIT](IMPORTANT): Vehicle Heading:88.916428 degrees 2021-08-04T19:40:44.400Z,1628106044.400 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m 2021-08-04T19:40:44.400Z,1628106044.400 [IBIT](IMPORTANT): buoyancyNeutral: 325.319336 cc 2021-08-04T19:40:44.401Z,1628106044.401 [IBIT](IMPORTANT): massDefault: 0.894689 cm 2021-08-04T19:40:44.401Z,1628106044.401 [IBIT](IMPORTANT): stopDepth: 10.000000 m 2021-08-04T19:40:44.401Z,1628106044.401 [IBIT](IMPORTANT): abortDepth: 15.000000 m 2021-08-04T19:40:44.401Z,1628106044.401 [IBIT](IMPORTANT): IBIT PASSED 2021-08-04T19:41:07.455Z,1628106067.455 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-04T19:41:07.455Z,1628106067.455 [Default:CheckIn:C.Wait] Stopped 2021-08-04T19:41:07.455Z,1628106067.455 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-04T19:41:07.460Z,1628106067.460 [Default:CheckIn:D] Running Loop=1 2021-08-04T19:41:07.884Z,1628106067.884 [Default:CheckIn:D] Stopped 2021-08-04T19:41:07.884Z,1628106067.884 [Default:CheckIn:E] Running Loop=1 2021-08-04T19:41:08.234Z,1628106068.234 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 390.349316 min 2021-08-04T19:41:08.234Z,1628106068.234 [Default:CheckIn:E] Stopped 2021-08-04T19:41:08.234Z,1628106068.234 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-04T19:41:08.234Z,1628106068.234 [Default:CheckIn] Stopped 2021-08-04T19:41:08.234Z,1628106068.234 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-04T19:41:08.235Z,1628106068.235 [Default:CheckIn](INFO): Running loop #63 2021-08-04T19:41:08.235Z,1628106068.235 [Default:CheckIn] Running Loop=63 2021-08-04T19:41:08.235Z,1628106068.235 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-04T19:41:08.235Z,1628106068.235 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-04T19:41:10.246Z,1628106070.246 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194110.00,A,4149.69520,N,08324.71708,W,0.058,304.15,040821,,,D*70 2021-08-04T19:41:10.249Z,1628106070.249 [NAL9602](INFO): GPS fix at 20210804T194110: (41.828253, -83.411951) 2021-08-04T19:41:10.281Z,1628106070.281 [Default:CheckIn:Read_GPS] Stopped 2021-08-04T19:41:10.281Z,1628106070.281 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-04T19:41:18.819Z,1628106078.819 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210804T172847/Courier0069.lzma 2021-08-04T19:41:19.822Z,1628106079.822 [DataOverHttps](INFO): Moved sent file to Logs/20210804T172847/Courier0069.lzma.bak 2021-08-04T19:41:19.822Z,1628106079.822 [DataOverHttps](INFO): SBD MOMSN=15824426 2021-08-04T19:41:40.451Z,1628106100.451 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20210804T172847/Courier0072.lzma 2021-08-04T19:41:41.454Z,1628106101.454 [DataOverHttps](INFO): Moved sent file to Logs/20210804T172847/Courier0072.lzma.bak 2021-08-04T19:41:41.454Z,1628106101.454 [DataOverHttps](INFO): SBD MOMSN=15824430 2021-08-04T19:41:42.286Z,1628106102.286 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-04T19:41:59.346Z,1628106119.346 [DataOverHttps](INFO): Sending 849 bytes from file Logs/20210804T172847/Express0070.lzma 2021-08-04T19:42:00.346Z,1628106120.346 [DataOverHttps](INFO): Moved sent file to Logs/20210804T172847/Express0070.lzma.bak 2021-08-04T19:42:00.346Z,1628106120.346 [DataOverHttps](INFO): SBD MOMSN=15824433 2021-08-04T19:42:17.535Z,1628106137.535 [DataOverHttps](INFO): Sending 70 bytes from file Logs/20210804T172847/Express0073.lzma 2021-08-04T19:42:18.538Z,1628106138.538 [DataOverHttps](INFO): Moved sent file to Logs/20210804T172847/Express0073.lzma.bak 2021-08-04T19:42:18.538Z,1628106138.538 [DataOverHttps](INFO): SBD MOMSN=15824465 2021-08-04T19:42:20.254Z,1628106140.254 [Default:CheckIn:Read_Iridium] Stopped 2021-08-04T19:42:20.254Z,1628106140.254 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-04T19:42:20.254Z,1628106140.254 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-04T19:44:27.157Z,1628106267.157 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2021-08-04T19:44:27.157Z,1628106267.157 [DVL_micro](ERROR): Failed to parse: :TS,000000005.0,+26.1,0000.0,1489.0,000 2021-08-04T19:44:42.104Z,1628106282.104 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2021-08-04T19:44:42.104Z,1628106282.104 [DVL_micro](ERROR): Failed to parse: :TS0000000,35.0,+26.1,0000.0,1489.0,000 2021-08-04T19:46:11.394Z,1628106371.394 [DVL_micro](ERROR): Failed to parse:00000000000,35.0,+26.0,0000.0,1489.0,000 2021-08-04T19:47:20.906Z,1628106440.906 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-04T19:47:20.906Z,1628106440.906 [Default:CheckIn:C.Wait] Stopped 2021-08-04T19:47:20.906Z,1628106440.906 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-04T19:47:20.906Z,1628106440.906 [Default:CheckIn:D] Running Loop=1 2021-08-04T19:47:21.314Z,1628106441.314 [Default:CheckIn:D] Stopped 2021-08-04T19:47:21.314Z,1628106441.314 [Default:CheckIn:E] Running Loop=1 2021-08-04T19:47:21.724Z,1628106441.724 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 396.573177 min 2021-08-04T19:47:21.724Z,1628106441.724 [Default:CheckIn:E] Stopped 2021-08-04T19:47:21.725Z,1628106441.725 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-04T19:47:21.725Z,1628106441.725 [Default:CheckIn] Stopped 2021-08-04T19:47:21.725Z,1628106441.725 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-04T19:47:21.725Z,1628106441.725 [Default:CheckIn](INFO): Running loop #64 2021-08-04T19:47:21.725Z,1628106441.725 [Default:CheckIn] Running Loop=64 2021-08-04T19:47:21.725Z,1628106441.725 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-04T19:47:21.725Z,1628106441.725 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-04T19:47:23.744Z,1628106443.744 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194724.00,A,4149.69282,N,08324.71663,W,0.136,304.15,040821,,,D*7B 2021-08-04T19:47:23.746Z,1628106443.746 [NAL9602](INFO): GPS fix at 20210804T194724: (41.828214, -83.411944) 2021-08-04T19:47:23.756Z,1628106443.756 [Default:CheckIn:Read_GPS] Stopped 2021-08-04T19:47:23.756Z,1628106443.756 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-04T19:47:29.787Z,1628106449.787 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210804T172847/Courier0075.lzma 2021-08-04T19:47:30.790Z,1628106450.790 [DataOverHttps](INFO): Moved sent file to Logs/20210804T172847/Courier0075.lzma.bak 2021-08-04T19:47:30.790Z,1628106450.790 [DataOverHttps](INFO): SBD MOMSN=15824509 2021-08-04T19:47:33.051Z,1628106453.051 [NAL9602](INFO): SBD MO Status=0, MOMSN=41941, MT Status=0, MTMSN=0 2021-08-04T19:47:33.051Z,1628106453.051 [NAL9602](INFO): No messages in MT queue 2021-08-04T19:47:51.311Z,1628106471.311 [DVL_micro](ERROR): Failed to parse: :BD,+00000000.00,+00000000.00,+00000000.00,0000.20,000.00 2021-08-04T19:47:53.396Z,1628106473.396 [DataOverHttps](INFO): Sending 162 bytes from file Logs/20210804T172847/Express0076.lzma 2021-08-04T19:47:54.398Z,1628106474.398 [DataOverHttps](INFO): Moved sent file to Logs/20210804T172847/Express0076.lzma.bak 2021-08-04T19:47:54.398Z,1628106474.398 [DataOverHttps](INFO): SBD MOMSN=15824518 2021-08-04T19:47:56.182Z,1628106476.182 [Default:CheckIn:Read_Iridium] Stopped 2021-08-04T19:47:56.182Z,1628106476.182 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-04T19:47:56.182Z,1628106476.182 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-04T19:48:03.828Z,1628106483.828 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-04T19:50:17.225Z,1628106617.225 [DVL_micro](ERROR): only read 3 of 4 data items 2021-08-04T19:50:17.225Z,1628106617.225 [DVL_micro](ERROR): Failed to parse: :RD,+0000.32,+0002.63,+99003.90 2021-08-04T19:51:37.370Z,1628106697.370 [DVL_micro](ERROR): Failed to parse: :WI,+00000,+00000,+00000,+00000,I 2021-08-04T19:52:56.618Z,1628106776.618 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-04T19:52:56.619Z,1628106776.619 [Default:CheckIn:C.Wait] Stopped 2021-08-04T19:52:56.619Z,1628106776.619 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-04T19:52:56.619Z,1628106776.619 [Default:CheckIn:D] Running Loop=1 2021-08-04T19:52:57.016Z,1628106777.016 [Default:CheckIn:D] Stopped 2021-08-04T19:52:57.016Z,1628106777.016 [Default:CheckIn:E] Running Loop=1 2021-08-04T19:52:57.445Z,1628106777.445 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 402.168197 min 2021-08-04T19:52:57.445Z,1628106777.445 [Default:CheckIn:E] Stopped 2021-08-04T19:52:57.445Z,1628106777.445 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-04T19:52:57.445Z,1628106777.445 [Default:CheckIn] Stopped 2021-08-04T19:52:57.445Z,1628106777.445 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-04T19:52:57.445Z,1628106777.445 [Default:CheckIn](INFO): Running loop #65 2021-08-04T19:52:57.445Z,1628106777.445 [Default:CheckIn] Running Loop=65 2021-08-04T19:52:57.445Z,1628106777.445 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-04T19:52:57.446Z,1628106777.446 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-04T19:52:59.453Z,1628106779.453 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,195259.00,A,4149.69536,N,08324.70948,W,0.214,179.48,040821,,,D*79 2021-08-04T19:52:59.456Z,1628106779.456 [NAL9602](INFO): GPS fix at 20210804T195259: (41.828256, -83.411825) 2021-08-04T19:52:59.466Z,1628106779.466 [Default:CheckIn:Read_GPS] Stopped 2021-08-04T19:52:59.466Z,1628106779.466 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-04T19:53:01.468Z,1628106781.468 [DVL_micro](ERROR): only read 2 of 4 data items 2021-08-04T19:53:01.468Z,1628106781.468 [DVL_micro](ERROR): Failed to parse: :RD,+0000.344,+0000..64 2021-08-04T19:53:07.123Z,1628106787.123 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210804T172847/Courier0078.lzma 2021-08-04T19:53:08.126Z,1628106788.126 [DataOverHttps](INFO): Moved sent file to Logs/20210804T172847/Courier0078.lzma.bak 2021-08-04T19:53:08.126Z,1628106788.126 [DataOverHttps](INFO): SBD MOMSN=15824558 2021-08-04T19:53:18.828Z,1628106798.828 [NAL9602](INFO): SBD MO Status=2, MOMSN=41942, MT Status=2, MTMSN=0 2021-08-04T19:53:18.828Z,1628106798.828 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-04T19:53:25.445Z,1628106805.445 [DataOverHttps](INFO): Sending 167 bytes from file Logs/20210804T172847/Express0079.lzma 2021-08-04T19:53:26.430Z,1628106806.430 [DataOverHttps](INFO): Moved sent file to Logs/20210804T172847/Express0079.lzma.bak 2021-08-04T19:53:26.430Z,1628106806.430 [DataOverHttps](INFO): SBD MOMSN=15824567 2021-08-04T19:53:28.136Z,1628106808.136 [Default:CheckIn:Read_Iridium] Stopped 2021-08-04T19:53:28.136Z,1628106808.136 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-04T19:53:28.136Z,1628106808.136 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-04T19:53:33.419Z,1628106813.419 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2021-08-04T19:53:33.419Z,1628106813.419 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,.0,0000.0,1489.0,000 2021-08-04T19:53:54.827Z,1628106834.827 [NAL9602](INFO): SBD MO Status=2, MOMSN=41942, MT Status=2, MTMSN=0 2021-08-04T19:53:54.827Z,1628106834.827 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-04T19:54:22.308Z,1628106862.308 [NAL9602](INFO): SBD MO Status=0, MOMSN=41942, MT Status=0, MTMSN=0 2021-08-04T19:54:22.308Z,1628106862.308 [NAL9602](INFO): No messages in MT queue 2021-08-04T19:54:53.077Z,1628106893.077 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-04T19:55:27.403Z,1628106927.403 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2021-08-04T19:55:39.176Z,1628106939.176 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2021-08-04T19:55:50.483Z,1628106950.483 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2021-08-04T19:56:01.804Z,1628106961.804 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2021-08-04T19:56:13.106Z,1628106973.106 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2021-08-04T19:56:24.433Z,1628106984.433 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2021-08-04T19:56:35.536Z,1628106995.536 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2021-08-04T19:56:46.739Z,1628107006.739 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2021-08-04T19:58:28.659Z,1628107108.659 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-04T19:58:28.659Z,1628107108.659 [Default:CheckIn:C.Wait] Stopped 2021-08-04T19:58:28.659Z,1628107108.659 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-04T19:58:28.659Z,1628107108.659 [Default:CheckIn:D] Running Loop=1 2021-08-04T19:58:29.079Z,1628107109.079 [Default:CheckIn:D] Stopped 2021-08-04T19:58:29.079Z,1628107109.079 [Default:CheckIn:E] Running Loop=1 2021-08-04T19:58:29.467Z,1628107109.467 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 407.702572 min 2021-08-04T19:58:29.467Z,1628107109.467 [Default:CheckIn:E] Stopped 2021-08-04T19:58:29.467Z,1628107109.467 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-04T19:58:29.468Z,1628107109.468 [Default:CheckIn] Stopped 2021-08-04T19:58:29.468Z,1628107109.468 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-04T19:58:29.468Z,1628107109.468 [Default:CheckIn](INFO): Running loop #66 2021-08-04T19:58:29.468Z,1628107109.468 [Default:CheckIn] Running Loop=66 2021-08-04T19:58:29.468Z,1628107109.468 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-04T19:58:29.468Z,1628107109.468 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-04T19:58:31.478Z,1628107111.478 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,195832.00,A,4149.69462,N,08324.70664,W,0.272,179.48,040821,,,A*7A 2021-08-04T19:58:31.480Z,1628107111.480 [NAL9602](INFO): GPS fix at 20210804T195832: (41.828244, -83.411777) 2021-08-04T19:58:31.490Z,1628107111.490 [Default:CheckIn:Read_GPS] Stopped 2021-08-04T19:58:31.490Z,1628107111.490 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-04T19:58:43.043Z,1628107123.043 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210804T172847/Courier0081.lzma 2021-08-04T19:58:44.046Z,1628107124.046 [DataOverHttps](INFO): Moved sent file to Logs/20210804T172847/Courier0081.lzma.bak 2021-08-04T19:58:44.046Z,1628107124.046 [DataOverHttps](INFO): SBD MOMSN=15824610 2021-08-04T19:59:01.340Z,1628107141.340 [DataOverHttps](INFO): Sending 163 bytes from file Logs/20210804T172847/Express0082.lzma 2021-08-04T19:59:02.342Z,1628107142.342 [DataOverHttps](INFO): Moved sent file to Logs/20210804T172847/Express0082.lzma.bak 2021-08-04T19:59:02.342Z,1628107142.342 [DataOverHttps](INFO): SBD MOMSN=15824616 2021-08-04T19:59:03.995Z,1628107143.995 [Default:CheckIn:Read_Iridium] Stopped 2021-08-04T19:59:03.995Z,1628107143.995 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-04T19:59:03.995Z,1628107143.995 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-04T19:59:19.738Z,1628107159.738 [NAL9602](INFO): SBD MO Status=2, MOMSN=41943, MT Status=2, MTMSN=0 2021-08-04T19:59:19.738Z,1628107159.738 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-04T19:59:31.855Z,1628107171.855 [NAL9602](INFO): SBD MO Status=0, MOMSN=41943, MT Status=0, MTMSN=0 2021-08-04T19:59:31.855Z,1628107171.855 [NAL9602](INFO): No messages in MT queue 2021-08-04T20:00:02.603Z,1628107202.603 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-04T20:01:59.018Z,1628107319.018 [BPC1](ERROR): Battery stick #38 (s/n: 0139) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x4AD0. 2021-08-04T20:01:59.018Z,1628107319.018 [BPC1](INFO): Calculating totals. Valid battery stick count: 55. Valid reserve battery stick count: 5. 2021-08-04T20:01:59.033Z,1628107319.033 [BPC1](INFO): Received data from all battery sticks. 2021-08-04T20:04:04.407Z,1628107444.407 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-04T20:04:04.407Z,1628107444.407 [Default:CheckIn:C.Wait] Stopped 2021-08-04T20:04:04.407Z,1628107444.407 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-04T20:04:04.407Z,1628107444.407 [Default:CheckIn:D] Running Loop=1 2021-08-04T20:04:04.791Z,1628107444.791 [Default:CheckIn:D] Stopped 2021-08-04T20:04:04.791Z,1628107444.791 [Default:CheckIn:E] Running Loop=1 2021-08-04T20:04:05.162Z,1628107445.162 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 413.297786 min 2021-08-04T20:04:05.162Z,1628107445.162 [Default:CheckIn:E] Stopped 2021-08-04T20:04:05.163Z,1628107445.163 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-04T20:04:05.163Z,1628107445.163 [Default:CheckIn] Stopped 2021-08-04T20:04:05.163Z,1628107445.163 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-04T20:04:05.163Z,1628107445.163 [Default:CheckIn](INFO): Running loop #67 2021-08-04T20:04:05.163Z,1628107445.163 [Default:CheckIn] Running Loop=67 2021-08-04T20:04:05.163Z,1628107445.163 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-04T20:04:05.163Z,1628107445.163 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-04T20:04:07.169Z,1628107447.169 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,200407.00,A,4149.67138,N,08324.69748,W,1.536,49.36,040821,,,A*41 2021-08-04T20:04:07.171Z,1628107447.171 [NAL9602](INFO): GPS fix at 20210804T200407: (41.827856, -83.411625) 2021-08-04T20:04:07.202Z,1628107447.202 [Default:CheckIn:Read_GPS] Stopped 2021-08-04T20:04:07.202Z,1628107447.202 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-04T20:04:13.783Z,1628107453.783 [DataOverHttps](INFO): Sending 82 bytes from file Logs/20210804T172847/Courier0084.lzma 2021-08-04T20:04:14.786Z,1628107454.786 [DataOverHttps](INFO): Moved sent file to Logs/20210804T172847/Courier0084.lzma.bak 2021-08-04T20:04:14.786Z,1628107454.786 [DataOverHttps](INFO): SBD MOMSN=15824675 2021-08-04T20:04:31.783Z,1628107471.783 [DataOverHttps](INFO): Sending 139 bytes from file Logs/20210804T172847/Express0085.lzma 2021-08-04T20:04:32.786Z,1628107472.786 [DataOverHttps](INFO): Moved sent file to Logs/20210804T172847/Express0085.lzma.bak 2021-08-04T20:04:32.786Z,1628107472.786 [DataOverHttps](INFO): SBD MOMSN=15824681 2021-08-04T20:04:34.708Z,1628107474.708 [Default:CheckIn:Read_Iridium] Stopped 2021-08-04T20:04:34.708Z,1628107474.708 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-04T20:04:34.708Z,1628107474.708 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-04T20:04:42.168Z,1628107482.168 [DVL_micro](ERROR): only read 3 of 4 data items 2021-08-04T20:04:42.169Z,1628107482.169 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,+99999.99,+9999.99 2021-08-04T20:08:15.112Z,1628107695.112 [DropWeight](CRITICAL): DROP WEIGHT MISSING. 2021-08-04T20:08:15.112Z,1628107695.112 [DropWeight] Hardware Fault, FailCount= 1 2021-08-04T20:08:15.112Z,1628107695.112 [DropWeight](ERROR): Hardware Fault 2021-08-04T20:08:15.248Z,1628107695.248 [CBIT](INFO): Critical error at 20210804T200815 2021-08-04T20:08:15.251Z,1628107695.251 [CBIT](ERROR): Hardware Fault in component: DropWeight 2021-08-04T20:08:15.251Z,1628107695.251 [CBIT](CRITICAL): Hardware Fault in component: DropWeight 2021-08-04T20:08:15.520Z,1628107695.520 [CBIT](INFO): Critical error at 20210804T200815 2021-08-04T20:09:08.865Z,1628107748.865 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-08-04T20:09:35.129Z,1628107775.129 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-04T20:09:35.129Z,1628107775.129 [Default:CheckIn:C.Wait] Stopped 2021-08-04T20:09:35.129Z,1628107775.129 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-04T20:09:35.129Z,1628107775.129 [Default:CheckIn:D] Running Loop=1 2021-08-04T20:09:35.549Z,1628107775.549 [Default:CheckIn:D] Stopped 2021-08-04T20:09:35.549Z,1628107775.549 [Default:CheckIn:E] Running Loop=1 2021-08-04T20:09:35.945Z,1628107775.945 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 418.810417 min 2021-08-04T20:09:35.945Z,1628107775.945 [Default:CheckIn:E] Stopped 2021-08-04T20:09:35.945Z,1628107775.945 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-04T20:09:35.945Z,1628107775.945 [Default:CheckIn] Stopped 2021-08-04T20:09:35.945Z,1628107775.945 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-04T20:09:35.945Z,1628107775.945 [Default:CheckIn](INFO): Running loop #68 2021-08-04T20:09:35.946Z,1628107775.946 [Default:CheckIn] Running Loop=68 2021-08-04T20:09:35.946Z,1628107775.946 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-04T20:09:35.946Z,1628107775.946 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-04T20:09:38.013Z,1628107778.013 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,200938.00,A,4149.67572,N,08324.68888,W,0.175,49.36,040821,,,A*4A 2021-08-04T20:09:38.015Z,1628107778.015 [NAL9602](INFO): GPS fix at 20210804T200938: (41.827929, -83.411481) 2021-08-04T20:09:38.109Z,1628107778.109 [Default:CheckIn:Read_GPS] Stopped 2021-08-04T20:09:38.109Z,1628107778.109 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-04T20:09:46.308Z,1628107786.308 [DataOverHttps](INFO): Sending 180 bytes from file Logs/20210804T172847/Courier0087.lzma 2021-08-04T20:09:47.441Z,1628107787.441 [DataOverHttps](INFO): Moved sent file to Logs/20210804T172847/Courier0087.lzma.bak 2021-08-04T20:09:47.442Z,1628107787.442 [DataOverHttps](IMPORTANT): SBD MOMSN=15824720, MTMSN=20210804T200947 2021-08-04T20:09:55.336Z,1628107795.336 [DataOverHttps](INFO): Received command:strobe off 2021-08-04T20:09:55.353Z,1628107795.353 [CommandLine](IMPORTANT): got command strobe off 2021-08-04T20:09:55.353Z,1628107795.353 [CommandLine](IMPORTANT): Deactivating strobe 2021-08-04T20:10:04.356Z,1628107804.356 [DataOverHttps](INFO): Sending 205 bytes from file Logs/20210804T172847/Express0088.lzma 2021-08-04T20:10:05.358Z,1628107805.358 [DataOverHttps](INFO): Moved sent file to Logs/20210804T172847/Express0088.lzma.bak 2021-08-04T20:10:05.358Z,1628107805.358 [DataOverHttps](INFO): SBD MOMSN=15824729 2021-08-04T20:10:10.423Z,1628107810.423 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-04T20:10:22.424Z,1628107822.424 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20210804T172847/Courier0090.lzma 2021-08-04T20:10:23.266Z,1628107823.266 [DataOverHttps](INFO): Moved sent file to Logs/20210804T172847/Courier0090.lzma.bak 2021-08-04T20:10:23.266Z,1628107823.266 [DataOverHttps](INFO): SBD MOMSN=15824739 2021-08-04T20:10:47.896Z,1628107847.896 [DataOverHttps](INFO): Sending 153 bytes from file Logs/20210804T172847/Express0091.lzma 2021-08-04T20:10:48.899Z,1628107848.899 [DataOverHttps](INFO): Moved sent file to Logs/20210804T172847/Express0091.lzma.bak 2021-08-04T20:10:48.899Z,1628107848.899 [DataOverHttps](INFO): SBD MOMSN=15824744 2021-08-04T20:10:50.476Z,1628107850.476 [Default:CheckIn:Read_Iridium] Stopped 2021-08-04T20:10:50.476Z,1628107850.476 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-04T20:10:50.476Z,1628107850.476 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-04T20:15:51.172Z,1628108151.172 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-04T20:15:51.172Z,1628108151.172 [Default:CheckIn:C.Wait] Stopped 2021-08-04T20:15:51.172Z,1628108151.172 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-04T20:15:51.172Z,1628108151.172 [Default:CheckIn:D] Running Loop=1 2021-08-04T20:15:51.582Z,1628108151.582 [Default:CheckIn:D] Stopped 2021-08-04T20:15:51.582Z,1628108151.582 [Default:CheckIn:E] Running Loop=1 2021-08-04T20:15:51.981Z,1628108151.981 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 425.077637 min 2021-08-04T20:15:51.981Z,1628108151.981 [Default:CheckIn:E] Stopped 2021-08-04T20:15:51.981Z,1628108151.981 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-04T20:15:51.981Z,1628108151.981 [Default:CheckIn] Stopped 2021-08-04T20:15:51.981Z,1628108151.981 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-04T20:15:51.982Z,1628108151.982 [Default:CheckIn](INFO): Running loop #69 2021-08-04T20:15:51.982Z,1628108151.982 [Default:CheckIn] Running Loop=69 2021-08-04T20:15:51.982Z,1628108151.982 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-04T20:15:51.982Z,1628108151.982 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-04T20:15:54.017Z,1628108154.017 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,201554.00,A,4149.67614,N,08324.68548,W,0.991,170.46,040821,,,A*71 2021-08-04T20:15:54.019Z,1628108154.019 [NAL9602](INFO): GPS fix at 20210804T201554: (41.827936, -83.411425) 2021-08-04T20:15:54.037Z,1628108154.037 [Default:CheckIn:Read_GPS] Stopped 2021-08-04T20:15:54.037Z,1628108154.037 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-04T20:15:58.992Z,1628108158.992 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210804T172847/Courier0093.lzma 2021-08-04T20:15:59.734Z,1628108159.734 [DataOverHttps](INFO): Moved sent file to Logs/20210804T172847/Courier0093.lzma.bak 2021-08-04T20:15:59.734Z,1628108159.734 [DataOverHttps](INFO): SBD MOMSN=15824816 2021-08-04T20:16:16.367Z,1628108176.367 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20210804T172847/Express0094.lzma 2021-08-04T20:16:17.526Z,1628108177.526 [DataOverHttps](INFO): Moved sent file to Logs/20210804T172847/Express0094.lzma.bak 2021-08-04T20:16:17.526Z,1628108177.526 [DataOverHttps](INFO): SBD MOMSN=15824822 2021-08-04T20:16:19.184Z,1628108179.184 [Default:CheckIn:Read_Iridium] Stopped 2021-08-04T20:16:19.184Z,1628108179.184 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-04T20:16:19.185Z,1628108179.185 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-04T20:16:24.767Z,1628108184.767 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-08-04T20:16:24.848Z,1628108184.848 [NAL9602](ERROR): received: +CSQ:0 OK943, 0, 0, 0, 0 OK 2021-08-04T20:17:14.491Z,1628108234.491 [NAL9602](INFO): SBD MO Status=2, MOMSN=41944, MT Status=2, MTMSN=0 2021-08-04T20:17:14.491Z,1628108234.491 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-04T20:18:48.219Z,1628108328.219 [NAL9602](INFO): SBD MO Status=2, MOMSN=41944, MT Status=2, MTMSN=0 2021-08-04T20:18:48.219Z,1628108328.219 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-04T20:20:56.322Z,1628108456.322 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-08-04T20:21:19.765Z,1628108479.765 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-04T20:21:19.765Z,1628108479.765 [Default:CheckIn:C.Wait] Stopped 2021-08-04T20:21:19.765Z,1628108479.765 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-04T20:21:19.765Z,1628108479.765 [Default:CheckIn:D] Running Loop=1 2021-08-04T20:21:20.177Z,1628108480.177 [Default:CheckIn:D] Stopped 2021-08-04T20:21:20.177Z,1628108480.177 [Default:CheckIn:E] Running Loop=1 2021-08-04T20:21:20.583Z,1628108480.583 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 430.554199 min 2021-08-04T20:21:20.583Z,1628108480.583 [Default:CheckIn:E] Stopped 2021-08-04T20:21:20.583Z,1628108480.583 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-04T20:21:20.583Z,1628108480.583 [Default:CheckIn] Stopped 2021-08-04T20:21:20.583Z,1628108480.583 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-04T20:21:20.584Z,1628108480.584 [Default:CheckIn](INFO): Running loop #70 2021-08-04T20:21:20.584Z,1628108480.584 [Default:CheckIn] Running Loop=70 2021-08-04T20:21:20.584Z,1628108480.584 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-04T20:21:20.584Z,1628108480.584 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-04T20:21:22.621Z,1628108482.621 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,202123.00,A,4149.71856,N,08324.70141,W,4.918,312.76,040821,,,A*7D 2021-08-04T20:21:22.623Z,1628108482.623 [NAL9602](INFO): GPS fix at 20210804T202123: (41.828643, -83.411690) 2021-08-04T20:21:22.636Z,1628108482.636 [Default:CheckIn:Read_GPS] Stopped 2021-08-04T20:21:22.636Z,1628108482.636 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-04T20:21:28.799Z,1628108488.799 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210804T172847/Courier0096.lzma 2021-08-04T20:21:29.802Z,1628108489.802 [DataOverHttps](INFO): Moved sent file to Logs/20210804T172847/Courier0096.lzma.bak 2021-08-04T20:21:29.802Z,1628108489.802 [DataOverHttps](INFO): SBD MOMSN=15824855 2021-08-04T20:21:50.656Z,1628108510.656 [DataOverHttps](INFO): Sending 219 bytes from file Logs/20210804T172847/Express0097.lzma 2021-08-04T20:21:51.658Z,1628108511.658 [DataOverHttps](INFO): Moved sent file to Logs/20210804T172847/Express0097.lzma.bak 2021-08-04T20:21:51.658Z,1628108511.658 [DataOverHttps](INFO): SBD MOMSN=15824869 2021-08-04T20:21:53.387Z,1628108513.387 [Default:CheckIn:Read_Iridium] Stopped 2021-08-04T20:21:53.387Z,1628108513.387 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-04T20:21:53.387Z,1628108513.387 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-04T20:21:55.392Z,1628108515.392 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-04T20:23:15.460Z,1628108595.460 [CBIT](INFO): Clearing failed state for component DropWeight 2021-08-04T20:23:15.461Z,1628108595.461 [DropWeight] No Fault, FailCount= 1 2021-08-04T20:24:13.224Z,1628108653.224 [DVL_micro](ERROR): only read 3 of 4 data items 2021-08-04T20:24:13.224Z,1628108653.224 [DVL_micro](ERROR): Failed to parse: :BI,+00587,+01258,+0000,I 2021-08-04T20:26:54.147Z,1628108814.147 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-04T20:26:54.152Z,1628108814.152 [Default:CheckIn:C.Wait] Stopped 2021-08-04T20:26:54.152Z,1628108814.152 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-04T20:26:54.152Z,1628108814.152 [Default:CheckIn:D] Running Loop=1 2021-08-04T20:26:54.526Z,1628108814.526 [Default:CheckIn:D] Stopped 2021-08-04T20:26:54.526Z,1628108814.526 [Default:CheckIn:E] Running Loop=1 2021-08-04T20:26:54.933Z,1628108814.933 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 436.126693 min 2021-08-04T20:26:54.934Z,1628108814.934 [Default:CheckIn:E] Stopped 2021-08-04T20:26:54.934Z,1628108814.934 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-04T20:26:54.934Z,1628108814.934 [Default:CheckIn] Stopped 2021-08-04T20:26:54.934Z,1628108814.934 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-04T20:26:54.934Z,1628108814.934 [Default:CheckIn](INFO): Running loop #71 2021-08-04T20:26:54.934Z,1628108814.934 [Default:CheckIn] Running Loop=71 2021-08-04T20:26:54.934Z,1628108814.934 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-04T20:26:54.935Z,1628108814.935 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-04T20:26:56.944Z,1628108816.944 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,202657.00,A,4149.66805,N,08324.68193,W,1.672,13.30,040821,,,A*49 2021-08-04T20:26:56.946Z,1628108816.946 [NAL9602](INFO): GPS fix at 20210804T202657: (41.827801, -83.411366) 2021-08-04T20:26:56.955Z,1628108816.955 [Default:CheckIn:Read_GPS] Stopped 2021-08-04T20:26:56.955Z,1628108816.955 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-04T20:27:05.415Z,1628108825.415 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210804T172847/Courier0099.lzma 2021-08-04T20:27:06.418Z,1628108826.418 [DataOverHttps](INFO): Moved sent file to Logs/20210804T172847/Courier0099.lzma.bak 2021-08-04T20:27:06.418Z,1628108826.418 [DataOverHttps](INFO): SBD MOMSN=15824965 2021-08-04T20:27:23.292Z,1628108843.292 [DataOverHttps](INFO): Sending 143 bytes from file Logs/20210804T172847/Express0100.lzma 2021-08-04T20:27:24.294Z,1628108844.294 [DataOverHttps](INFO): Moved sent file to Logs/20210804T172847/Express0100.lzma.bak 2021-08-04T20:27:24.294Z,1628108844.294 [DataOverHttps](INFO): SBD MOMSN=15824971 2021-08-04T20:27:26.107Z,1628108846.107 [Default:CheckIn:Read_Iridium] Stopped 2021-08-04T20:27:26.107Z,1628108846.107 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-04T20:27:26.108Z,1628108846.108 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-04T20:27:27.672Z,1628108847.672 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-08-04T20:27:27.748Z,1628108847.748 [NAL9602](ERROR): received: +CSQ:0 OK944, 2, 0, 0, 0 OK 2021-08-04T20:28:48.644Z,1628108928.644 [NAL9602](INFO): SBD MO Status=2, MOMSN=41944, MT Status=2, MTMSN=0 2021-08-04T20:28:48.644Z,1628108928.644 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-04T20:31:59.118Z,1628109119.118 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-08-04T20:32:26.597Z,1628109146.597 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-04T20:32:26.598Z,1628109146.598 [Default:CheckIn:C.Wait] Stopped 2021-08-04T20:32:26.598Z,1628109146.598 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-04T20:32:26.598Z,1628109146.598 [Default:CheckIn:D] Running Loop=1 2021-08-04T20:32:27.011Z,1628109147.011 [Default:CheckIn:D] Stopped 2021-08-04T20:32:27.011Z,1628109147.011 [Default:CheckIn:E] Running Loop=1 2021-08-04T20:32:27.417Z,1628109147.417 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 441.668099 min 2021-08-04T20:32:27.417Z,1628109147.417 [Default:CheckIn:E] Stopped 2021-08-04T20:32:27.417Z,1628109147.417 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-04T20:32:27.417Z,1628109147.417 [Default:CheckIn] Stopped 2021-08-04T20:32:27.417Z,1628109147.418 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-04T20:32:27.418Z,1628109147.418 [Default:CheckIn](INFO): Running loop #72 2021-08-04T20:32:27.418Z,1628109147.418 [Default:CheckIn] Running Loop=72 2021-08-04T20:32:27.418Z,1628109147.418 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-04T20:32:27.418Z,1628109147.418 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-04T20:32:29.427Z,1628109149.427 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,203230.00,A,4149.66792,N,08324.69412,W,0.525,151.53,040821,,,A*73 2021-08-04T20:32:29.430Z,1628109149.430 [NAL9602](INFO): GPS fix at 20210804T203230: (41.827799, -83.411569) 2021-08-04T20:32:29.460Z,1628109149.460 [Default:CheckIn:Read_GPS] Stopped 2021-08-04T20:32:29.460Z,1628109149.460 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-04T20:32:40.135Z,1628109160.135 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210804T172847/Courier0102.lzma 2021-08-04T20:32:41.138Z,1628109161.138 [DataOverHttps](INFO): Moved sent file to Logs/20210804T172847/Courier0102.lzma.bak 2021-08-04T20:32:41.138Z,1628109161.138 [DataOverHttps](INFO): SBD MOMSN=15825008 2021-08-04T20:32:58.688Z,1628109178.688 [DataOverHttps](INFO): Sending 218 bytes from file Logs/20210804T172847/Express0103.lzma 2021-08-04T20:32:59.690Z,1628109179.690 [DataOverHttps](INFO): Moved sent file to Logs/20210804T172847/Express0103.lzma.bak 2021-08-04T20:32:59.690Z,1628109179.690 [DataOverHttps](INFO): SBD MOMSN=15825015 2021-08-04T20:33:01.431Z,1628109181.431 [Default:CheckIn:Read_Iridium] Stopped 2021-08-04T20:33:01.431Z,1628109181.431 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-04T20:33:01.431Z,1628109181.431 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-04T20:33:02.218Z,1628109182.218 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-04T20:33:48.759Z,1628109228.759 [DVL_micro](ERROR): Failed to parse: :000000000,35.0,+26.7,0000.0,1489.0,000 2021-08-04T20:33:54.016Z,1628109234.016 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2021-08-04T20:33:54.017Z,1628109234.017 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0000.0,1489.0I,-01302,+00009,+00643,+00000,A 2021-08-04T20:38:01.910Z,1628109481.910 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-04T20:38:01.910Z,1628109481.910 [Default:CheckIn:C.Wait] Stopped 2021-08-04T20:38:01.910Z,1628109481.910 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-04T20:38:01.910Z,1628109481.910 [Default:CheckIn:D] Running Loop=1 2021-08-04T20:38:02.330Z,1628109482.330 [Default:CheckIn:D] Stopped 2021-08-04T20:38:02.330Z,1628109482.330 [Default:CheckIn:E] Running Loop=1 2021-08-04T20:38:02.713Z,1628109482.713 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 447.256771 min 2021-08-04T20:38:02.713Z,1628109482.713 [Default:CheckIn:E] Stopped 2021-08-04T20:38:02.713Z,1628109482.713 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-04T20:38:02.713Z,1628109482.713 [Default:CheckIn] Stopped 2021-08-04T20:38:02.713Z,1628109482.713 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-04T20:38:02.714Z,1628109482.714 [Default:CheckIn](INFO): Running loop #73 2021-08-04T20:38:02.714Z,1628109482.714 [Default:CheckIn] Running Loop=73 2021-08-04T20:38:02.714Z,1628109482.714 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-04T20:38:02.714Z,1628109482.714 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-04T20:38:04.719Z,1628109484.719 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,203805.00,A,4149.67883,N,08324.68464,W,0.350,53.48,040821,,,A*4C 2021-08-04T20:38:04.722Z,1628109484.722 [NAL9602](INFO): GPS fix at 20210804T203805: (41.827981, -83.411411) 2021-08-04T20:38:04.752Z,1628109484.752 [Default:CheckIn:Read_GPS] Stopped 2021-08-04T20:38:04.752Z,1628109484.752 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-04T20:38:12.107Z,1628109492.107 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210804T172847/Courier0105.lzma 2021-08-04T20:38:13.110Z,1628109493.110 [DataOverHttps](INFO): Moved sent file to Logs/20210804T172847/Courier0105.lzma.bak 2021-08-04T20:38:13.110Z,1628109493.110 [DataOverHttps](INFO): SBD MOMSN=15825088 2021-08-04T20:38:30.111Z,1628109510.111 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20210804T172847/Express0106.lzma 2021-08-04T20:38:31.114Z,1628109511.114 [DataOverHttps](INFO): Moved sent file to Logs/20210804T172847/Express0106.lzma.bak 2021-08-04T20:38:31.114Z,1628109511.114 [DataOverHttps](INFO): SBD MOMSN=15825094 2021-08-04T20:38:32.625Z,1628109512.625 [Default:CheckIn:Read_Iridium] Stopped 2021-08-04T20:38:32.625Z,1628109512.625 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-04T20:38:32.625Z,1628109512.625 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-04T20:38:35.422Z,1628109515.422 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-08-04T20:38:35.505Z,1628109515.505 [NAL9602](ERROR): received: +CSQ:0 OK944, 2, 0, 0, 0 OK 2021-08-04T20:43:06.793Z,1628109786.793 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-08-04T20:43:33.177Z,1628109813.177 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-04T20:43:33.177Z,1628109813.177 [Default:CheckIn:C.Wait] Stopped 2021-08-04T20:43:33.177Z,1628109813.177 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-04T20:43:33.177Z,1628109813.177 [Default:CheckIn:D] Running Loop=1 2021-08-04T20:43:33.506Z,1628109813.506 [Default:CheckIn:D] Stopped 2021-08-04T20:43:33.507Z,1628109813.507 [Default:CheckIn:E] Running Loop=1 2021-08-04T20:43:33.879Z,1628109813.879 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 452.776367 min 2021-08-04T20:43:33.880Z,1628109813.880 [Default:CheckIn:E] Stopped 2021-08-04T20:43:33.880Z,1628109813.880 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-04T20:43:33.880Z,1628109813.880 [Default:CheckIn] Stopped 2021-08-04T20:43:33.880Z,1628109813.880 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-04T20:43:33.880Z,1628109813.880 [Default:CheckIn](INFO): Running loop #74 2021-08-04T20:43:33.881Z,1628109813.881 [Default:CheckIn] Running Loop=74 2021-08-04T20:43:33.881Z,1628109813.881 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-04T20:43:33.881Z,1628109813.881 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-04T20:43:35.883Z,1628109815.883 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,204336.00,A,4149.67465,N,08324.69571,W,2.158,2.29,040821,,,A*7B 2021-08-04T20:43:35.886Z,1628109815.886 [NAL9602](INFO): GPS fix at 20210804T204336: (41.827911, -83.411595) 2021-08-04T20:43:35.903Z,1628109815.903 [Default:CheckIn:Read_GPS] Stopped 2021-08-04T20:43:35.920Z,1628109815.920 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-04T20:43:46.947Z,1628109826.947 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210804T172847/Courier0108.lzma 2021-08-04T20:43:47.950Z,1628109827.950 [DataOverHttps](INFO): Moved sent file to Logs/20210804T172847/Courier0108.lzma.bak 2021-08-04T20:43:47.950Z,1628109827.950 [DataOverHttps](INFO): SBD MOMSN=15825149 2021-08-04T20:44:04.877Z,1628109844.877 [DataOverHttps](INFO): Sending 206 bytes from file Logs/20210804T172847/Express0109.lzma 2021-08-04T20:44:05.874Z,1628109845.874 [DataOverHttps](INFO): Moved sent file to Logs/20210804T172847/Express0109.lzma.bak 2021-08-04T20:44:05.874Z,1628109845.874 [DataOverHttps](INFO): SBD MOMSN=15825155 2021-08-04T20:44:07.542Z,1628109847.542 [Default:CheckIn:Read_Iridium] Stopped 2021-08-04T20:44:07.542Z,1628109847.542 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-04T20:44:07.542Z,1628109847.542 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-04T20:44:08.351Z,1628109848.351 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-04T20:47:19.510Z,1628110039.510 [DVL_micro](ERROR): only read 3 of 4 data items 2021-08-04T20:47:19.510Z,1628110039.510 [DVL_micro](ERROR): Failed to parse: :BI,+00176,+01333,+00308,+00000+00000000.00,+00000000.00,+00000000.00,9999.99,000.00 2021-08-04T20:49:08.218Z,1628110148.218 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-04T20:49:08.218Z,1628110148.218 [Default:CheckIn:C.Wait] Stopped 2021-08-04T20:49:08.218Z,1628110148.218 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-04T20:49:08.218Z,1628110148.218 [Default:CheckIn:D] Running Loop=1 2021-08-04T20:49:08.606Z,1628110148.606 [Default:CheckIn:D] Stopped 2021-08-04T20:49:08.606Z,1628110148.606 [Default:CheckIn:E] Running Loop=1 2021-08-04T20:49:09.011Z,1628110149.011 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 458.361361 min 2021-08-04T20:49:09.011Z,1628110149.011 [Default:CheckIn:E] Stopped 2021-08-04T20:49:09.011Z,1628110149.011 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-04T20:49:09.011Z,1628110149.011 [Default:CheckIn] Stopped 2021-08-04T20:49:09.011Z,1628110149.011 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-04T20:49:09.012Z,1628110149.012 [Default:CheckIn](INFO): Running loop #75 2021-08-04T20:49:09.012Z,1628110149.012 [Default:CheckIn] Running Loop=75 2021-08-04T20:49:09.012Z,1628110149.012 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-04T20:49:09.012Z,1628110149.012 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-04T20:49:11.024Z,1628110151.024 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,204911.00,A,4149.67557,N,08324.67022,W,1.419,187.10,040821,,,A*7C 2021-08-04T20:49:11.026Z,1628110151.026 [NAL9602](INFO): GPS fix at 20210804T204911: (41.827926, -83.411170) 2021-08-04T20:49:11.060Z,1628110151.060 [Default:CheckIn:Read_GPS] Stopped 2021-08-04T20:49:11.060Z,1628110151.060 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-04T20:49:18.035Z,1628110158.035 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210804T172847/Courier0111.lzma 2021-08-04T20:49:19.038Z,1628110159.038 [DataOverHttps](INFO): Moved sent file to Logs/20210804T172847/Courier0111.lzma.bak 2021-08-04T20:49:19.038Z,1628110159.038 [DataOverHttps](INFO): SBD MOMSN=15825220 2021-08-04T20:49:40.724Z,1628110180.724 [DataOverHttps](INFO): Sending 139 bytes from file Logs/20210804T172847/Express0112.lzma 2021-08-04T20:49:41.726Z,1628110181.726 [DataOverHttps](INFO): Moved sent file to Logs/20210804T172847/Express0112.lzma.bak 2021-08-04T20:49:41.727Z,1628110181.727 [DataOverHttps](INFO): SBD MOMSN=15825229 2021-08-04T20:49:41.825Z,1628110181.825 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-08-04T20:49:41.908Z,1628110181.908 [NAL9602](ERROR): received: +CSQ:0 OK944, 2, 0, 0, 0 OK 2021-08-04T20:49:44.271Z,1628110184.271 [Default:CheckIn:Read_Iridium] Stopped 2021-08-04T20:49:44.271Z,1628110184.271 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-04T20:49:44.271Z,1628110184.271 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-04T20:54:13.394Z,1628110453.394 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-08-04T20:54:44.109Z,1628110484.109 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-04T20:54:44.956Z,1628110484.956 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-04T20:54:44.956Z,1628110484.956 [Default:CheckIn:C.Wait] Stopped 2021-08-04T20:54:44.956Z,1628110484.956 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-04T20:54:44.956Z,1628110484.956 [Default:CheckIn:D] Running Loop=1 2021-08-04T20:54:45.342Z,1628110485.342 [Default:CheckIn:D] Stopped 2021-08-04T20:54:45.342Z,1628110485.342 [Default:CheckIn:E] Running Loop=1 2021-08-04T20:54:45.739Z,1628110485.739 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 463.973633 min 2021-08-04T20:54:45.739Z,1628110485.739 [Default:CheckIn:E] Stopped 2021-08-04T20:54:45.739Z,1628110485.739 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-04T20:54:45.739Z,1628110485.739 [Default:CheckIn] Stopped 2021-08-04T20:54:45.739Z,1628110485.739 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-04T20:54:45.740Z,1628110485.740 [Default:CheckIn](INFO): Running loop #76 2021-08-04T20:54:45.740Z,1628110485.740 [Default:CheckIn] Running Loop=76 2021-08-04T20:54:45.740Z,1628110485.740 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-04T20:54:45.740Z,1628110485.740 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-04T20:54:47.747Z,1628110487.747 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,205448.00,A,4149.67730,N,08324.68469,W,0.428,353.60,040821,,,A*74 2021-08-04T20:54:47.749Z,1628110487.749 [NAL9602](INFO): GPS fix at 20210804T205448: (41.827955, -83.411411) 2021-08-04T20:54:47.759Z,1628110487.759 [Default:CheckIn:Read_GPS] Stopped 2021-08-04T20:54:47.759Z,1628110487.759 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-04T20:54:49.832Z,1628110489.832 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2021-08-04T20:54:49.832Z,1628110489.832 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+28.2,00000,000 2021-08-04T20:54:55.536Z,1628110495.536 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210804T172847/Courier0114.lzma 2021-08-04T20:54:56.538Z,1628110496.538 [DataOverHttps](INFO): Moved sent file to Logs/20210804T172847/Courier0114.lzma.bak 2021-08-04T20:54:56.538Z,1628110496.538 [DataOverHttps](INFO): SBD MOMSN=15825266 2021-08-04T20:55:14.096Z,1628110514.096 [DataOverHttps](INFO): Sending 216 bytes from file Logs/20210804T172847/Express0115.lzma 2021-08-04T20:55:15.098Z,1628110515.098 [DataOverHttps](INFO): Moved sent file to Logs/20210804T172847/Express0115.lzma.bak 2021-08-04T20:55:15.098Z,1628110515.098 [DataOverHttps](INFO): SBD MOMSN=15825275 2021-08-04T20:55:17.259Z,1628110517.259 [Default:CheckIn:Read_Iridium] Stopped 2021-08-04T20:55:17.259Z,1628110517.259 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-04T20:55:17.264Z,1628110517.264 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-04T20:55:18.461Z,1628110518.461 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-08-04T20:55:18.544Z,1628110518.544 [NAL9602](ERROR): received: +CSQ:0 OK944, 2, 0, 0, 0 OK 2021-08-04T20:58:33.726Z,1628110713.726 [DVL_micro](ERROR): Failed to parse: :WI,+00076,+00004,+00167,+00000,A 2021-08-04T20:59:50.113Z,1628110790.113 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-08-04T21:00:18.002Z,1628110818.002 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-04T21:00:18.002Z,1628110818.002 [Default:CheckIn:C.Wait] Stopped 2021-08-04T21:00:18.002Z,1628110818.002 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-04T21:00:18.002Z,1628110818.002 [Default:CheckIn:D] Running Loop=1 2021-08-04T21:00:18.403Z,1628110818.403 [Default:CheckIn:D] Stopped 2021-08-04T21:00:18.403Z,1628110818.403 [Default:CheckIn:E] Running Loop=1 2021-08-04T21:00:18.813Z,1628110818.813 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 469.524642 min 2021-08-04T21:00:18.814Z,1628110818.814 [Default:CheckIn:E] Stopped 2021-08-04T21:00:18.814Z,1628110818.814 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-04T21:00:18.814Z,1628110818.814 [Default:CheckIn] Stopped 2021-08-04T21:00:18.814Z,1628110818.814 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-04T21:00:18.814Z,1628110818.814 [Default:CheckIn](INFO): Running loop #77 2021-08-04T21:00:18.814Z,1628110818.814 [Default:CheckIn] Running Loop=77 2021-08-04T21:00:18.814Z,1628110818.814 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-04T21:00:18.814Z,1628110818.814 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-04T21:00:20.823Z,1628110820.823 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,210021.00,A,4149.66760,N,08324.69673,W,2.702,358.92,040821,,,A*78 2021-08-04T21:00:20.826Z,1628110820.826 [NAL9602](INFO): GPS fix at 20210804T210021: (41.827793, -83.411612) 2021-08-04T21:00:20.856Z,1628110820.856 [Default:CheckIn:Read_GPS] Stopped 2021-08-04T21:00:20.856Z,1628110820.856 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-04T21:00:29.045Z,1628110829.045 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210804T172847/Courier0117.lzma 2021-08-04T21:00:30.046Z,1628110830.046 [DataOverHttps](INFO): Moved sent file to Logs/20210804T172847/Courier0117.lzma.bak 2021-08-04T21:00:30.046Z,1628110830.046 [DataOverHttps](INFO): SBD MOMSN=15825343 2021-08-04T21:00:52.520Z,1628110852.520 [DataOverHttps](INFO): Sending 218 bytes from file Logs/20210804T172847/Express0118.lzma 2021-08-04T21:00:53.228Z,1628110853.228 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-04T21:00:53.522Z,1628110853.522 [DataOverHttps](INFO): Moved sent file to Logs/20210804T172847/Express0118.lzma.bak 2021-08-04T21:00:53.522Z,1628110853.522 [DataOverHttps](INFO): SBD MOMSN=15825353 2021-08-04T21:00:55.250Z,1628110855.250 [Default:CheckIn:Read_Iridium] Stopped 2021-08-04T21:00:55.250Z,1628110855.250 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-04T21:00:55.250Z,1628110855.250 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-04T21:01:02.465Z,1628110862.465 [DataOverHttps](IMPORTANT): SBD MTMSN=20210804T210102 2021-08-04T21:01:10.411Z,1628110870.411 [DataOverHttps](INFO): Received command:configSet Express linearApproximation height_above_sea_floor 1 meter persist 2021-08-04T21:01:11.261Z,1628110871.261 [CommandLine](IMPORTANT): got command configSet Express linearApproximation height_above_sea_floor 1.000000 meter persist 2021-08-04T21:03:05.518Z,1628110985.518 [DVL_micro](ERROR): only read 3 of 4 data items 2021-08-04T21:03:05.519Z,1628110985.519 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,+9999.999,+9999.99 2021-08-04T21:03:05.894Z,1628110985.894 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2021-08-04T21:03:17.219Z,1628110997.219 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2021-08-04T21:03:28.519Z,1628111008.519 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2021-08-04T21:03:38.293Z,1628111018.293 [DVL_micro](ERROR): Failed to parse: :WI,-00242,+00264,+00330,+00000,A 2021-08-04T21:03:39.880Z,1628111019.880 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2021-08-04T21:03:51.194Z,1628111031.194 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2021-08-04T21:04:02.914Z,1628111042.914 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2021-08-04T21:04:14.223Z,1628111054.223 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2021-08-04T21:04:25.938Z,1628111065.938 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2021-08-04T21:05:55.734Z,1628111155.734 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-04T21:05:55.734Z,1628111155.734 [Default:CheckIn:C.Wait] Stopped 2021-08-04T21:05:55.734Z,1628111155.734 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-04T21:05:55.735Z,1628111155.735 [Default:CheckIn:D] Running Loop=1 2021-08-04T21:05:56.137Z,1628111156.137 [Default:CheckIn:D] Stopped 2021-08-04T21:05:56.137Z,1628111156.137 [Default:CheckIn:E] Running Loop=1 2021-08-04T21:05:56.559Z,1628111156.559 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 475.153548 min 2021-08-04T21:05:56.560Z,1628111156.560 [Default:CheckIn:E] Stopped 2021-08-04T21:05:56.560Z,1628111156.560 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-04T21:05:56.560Z,1628111156.560 [Default:CheckIn] Stopped 2021-08-04T21:05:56.560Z,1628111156.560 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-04T21:05:56.560Z,1628111156.560 [Default:CheckIn](INFO): Running loop #78 2021-08-04T21:05:56.560Z,1628111156.560 [Default:CheckIn] Running Loop=78 2021-08-04T21:05:56.561Z,1628111156.561 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-04T21:05:56.561Z,1628111156.561 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-04T21:05:58.675Z,1628111158.675 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,210559.00,A,4149.69521,N,08324.70440,W,0.194,35.45,040821,,,A*49 2021-08-04T21:05:58.678Z,1628111158.678 [NAL9602](INFO): GPS fix at 20210804T210559: (41.828254, -83.411740) 2021-08-04T21:05:58.687Z,1628111158.687 [Default:CheckIn:Read_GPS] Stopped 2021-08-04T21:05:58.688Z,1628111158.688 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-04T21:06:06.563Z,1628111166.563 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210804T172847/Courier0120.lzma 2021-08-04T21:06:07.566Z,1628111167.566 [DataOverHttps](INFO): Moved sent file to Logs/20210804T172847/Courier0120.lzma.bak 2021-08-04T21:06:07.566Z,1628111167.566 [DataOverHttps](INFO): SBD MOMSN=15825393 2021-08-04T21:06:24.732Z,1628111184.732 [DataOverHttps](INFO): Sending 256 bytes from file Logs/20210804T172847/Express0121.lzma 2021-08-04T21:06:25.734Z,1628111185.734 [DataOverHttps](INFO): Moved sent file to Logs/20210804T172847/Express0121.lzma.bak 2021-08-04T21:06:25.734Z,1628111185.734 [DataOverHttps](INFO): SBD MOMSN=15825399 2021-08-04T21:06:29.022Z,1628111189.022 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-08-04T21:06:29.100Z,1628111189.100 [NAL9602](ERROR): received: +CSQ:0 OK944, 2, 0, 0, 0 OK 2021-08-04T21:06:47.803Z,1628111207.803 [DataOverHttps](INFO): Sending 52 bytes from file Logs/20210804T172847/Express0124.lzma 2021-08-04T21:06:48.806Z,1628111208.806 [DataOverHttps](INFO): Moved sent file to Logs/20210804T172847/Express0124.lzma.bak 2021-08-04T21:06:48.806Z,1628111208.806 [DataOverHttps](INFO): SBD MOMSN=15825413 2021-08-04T21:06:50.348Z,1628111210.348 [Default:CheckIn:Read_Iridium] Stopped 2021-08-04T21:06:50.348Z,1628111210.348 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-04T21:06:50.348Z,1628111210.348 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-04T21:06:51.143Z,1628111211.143 [NAL9602](INFO): SBD MO Status=2, MOMSN=41944, MT Status=2, MTMSN=0 2021-08-04T21:06:51.143Z,1628111211.143 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-04T21:07:18.207Z,1628111238.207 [NAL9602](INFO): SBD MO Status=2, MOMSN=41944, MT Status=2, MTMSN=0 2021-08-04T21:07:18.207Z,1628111238.207 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-04T21:07:27.094Z,1628111247.094 [NAL9602](INFO): SBD MO Status=0, MOMSN=41944, MT Status=0, MTMSN=0 2021-08-04T21:07:27.095Z,1628111247.095 [NAL9602](INFO): No messages in MT queue 2021-08-04T21:07:57.817Z,1628111277.817 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-04T21:09:17.461Z,1628111357.461 [DVL_micro](ERROR): Failed to parse: 9.99,+9999.99,+9999.99,+9999.99 2021-08-04T21:09:42.491Z,1628111382.491 [BPC1](ERROR): Battery stick #38 (s/n: 0139) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x4AD0. 2021-08-04T21:09:42.492Z,1628111382.492 [BPC1](INFO): Calculating totals. Valid battery stick count: 55. Valid reserve battery stick count: 5. 2021-08-04T21:09:42.495Z,1628111382.495 [BPC1](INFO): Received data from all battery sticks. 2021-08-04T21:11:51.090Z,1628111511.090 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-04T21:11:51.090Z,1628111511.090 [Default:CheckIn:C.Wait] Stopped 2021-08-04T21:11:51.090Z,1628111511.090 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-04T21:11:51.091Z,1628111511.091 [Default:CheckIn:D] Running Loop=1 2021-08-04T21:11:51.485Z,1628111511.485 [Default:CheckIn:D] Stopped 2021-08-04T21:11:51.485Z,1628111511.485 [Default:CheckIn:E] Running Loop=1 2021-08-04T21:11:51.925Z,1628111511.925 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 481.076009 min 2021-08-04T21:11:51.925Z,1628111511.925 [Default:CheckIn:E] Stopped 2021-08-04T21:11:51.925Z,1628111511.925 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-04T21:11:51.925Z,1628111511.925 [Default:CheckIn] Stopped 2021-08-04T21:11:51.925Z,1628111511.925 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-04T21:11:51.925Z,1628111511.925 [Default:CheckIn](INFO): Running loop #79 2021-08-04T21:11:51.925Z,1628111511.925 [Default:CheckIn] Running Loop=79 2021-08-04T21:11:51.926Z,1628111511.926 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-04T21:11:51.926Z,1628111511.926 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-04T21:11:53.891Z,1628111513.891 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,211154.00,A,4149.69550,N,08324.70688,W,0.097,137.49,040821,,,A*7C 2021-08-04T21:11:53.893Z,1628111513.893 [NAL9602](INFO): GPS fix at 20210804T211154: (41.828258, -83.411781) 2021-08-04T21:11:53.903Z,1628111513.903 [Default:CheckIn:Read_GPS] Stopped 2021-08-04T21:11:53.903Z,1628111513.903 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-04T21:11:58.994Z,1628111518.994 [DataOverHttps](INFO): Sending 84 bytes from file Logs/20210804T172847/Courier0126.lzma 2021-08-04T21:11:59.726Z,1628111519.726 [DataOverHttps](INFO): Moved sent file to Logs/20210804T172847/Courier0126.lzma.bak 2021-08-04T21:11:59.726Z,1628111519.726 [DataOverHttps](INFO): SBD MOMSN=15825467 2021-08-04T21:12:12.243Z,1628111532.243 [NAL9602](INFO): SBD MO Status=0, MOMSN=41945, MT Status=0, MTMSN=0 2021-08-04T21:12:12.244Z,1628111532.244 [NAL9602](INFO): No messages in MT queue 2021-08-04T21:12:15.968Z,1628111535.968 [DVL_micro](ERROR): DVL uart error: serial timeout 2021-08-04T21:12:15.968Z,1628111535.968 [DVL_micro] Communications Fault, FailCount= 1 2021-08-04T21:12:15.968Z,1628111535.968 [DVL_micro](ERROR): Communications Fault 2021-08-04T21:12:15.969Z,1628111535.969 [DVL_micro](ERROR): Failed to parse: 2021-08-04T21:12:16.062Z,1628111536.062 [CBIT](ERROR): Communications Fault in component: DVL_micro 2021-08-04T21:12:16.352Z,1628111536.352 [DVL_micro](INFO): Powering down 2021-08-04T21:12:16.686Z,1628111536.686 [Power24vConverter](INFO): Powering down. 2021-08-04T21:12:17.109Z,1628111537.109 [CBIT](INFO): Clearing failed state for component DVL_micro 2021-08-04T21:12:17.109Z,1628111537.109 [DVL_micro] No Fault, FailCount= 1 2021-08-04T21:12:17.501Z,1628111537.501 [Power24vConverter](INFO): Powering up. 2021-08-04T21:12:17.520Z,1628111537.520 [DataOverHttps](INFO): Sending 291 bytes from file Logs/20210804T172847/Express0127.lzma 2021-08-04T21:12:18.522Z,1628111538.522 [DataOverHttps](INFO): Moved sent file to Logs/20210804T172847/Express0127.lzma.bak 2021-08-04T21:12:18.522Z,1628111538.522 [DataOverHttps](INFO): SBD MOMSN=15825473 2021-08-04T21:12:19.942Z,1628111539.942 [Default:CheckIn:Read_Iridium] Stopped 2021-08-04T21:12:19.942Z,1628111539.942 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-04T21:12:19.943Z,1628111539.943 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-04T21:12:36.102Z,1628111556.102 [DVL_micro](ERROR): only read 3 of 4 data items 2021-08-04T21:12:36.102Z,1628111556.102 [DVL_micro](ERROR): Failed to parse: :RD,+00002.60,+0000.34,+0003.50 2021-08-04T21:12:42.986Z,1628111562.986 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-04T21:15:43.404Z,1628111743.404 [CommandLine](IMPORTANT): got command get height_above_sea_floor 2021-08-04T21:15:43.405Z,1628111743.405 [CommandLine](IMPORTANT): height_above_sea_floor 0.680000 m 2021-08-04T21:15:48.313Z,1628111748.313 [CommandLine](IMPORTANT): got command get height_above_sea_floor 2021-08-04T21:15:48.314Z,1628111748.314 [CommandLine](IMPORTANT): height_above_sea_floor 3.500000 m 2021-08-04T21:15:57.023Z,1628111757.023 [CommandLine](IMPORTANT): got command get height_above_sea_floor 2021-08-04T21:15:57.023Z,1628111757.023 [CommandLine](IMPORTANT): height_above_sea_floor 0.680000 m 2021-08-04T21:16:02.045Z,1628111762.045 [CommandLine](IMPORTANT): got command get height_above_sea_floor 2021-08-04T21:16:02.045Z,1628111762.045 [CommandLine](IMPORTANT): height_above_sea_floor 3.300000 m