2021-12-07T17:23:33.266Z,1638897813.266 [DataOverHttps](INFO): Received command: restart logs 2021-12-07T17:23:33.276Z,1638897813.276 [CommandExec](IMPORTANT): got command restart logs 2021-12-07T17:25:39.435Z,1638897939.435 [RDI_Pathfinder](ERROR): only read 2 of 4 data items 2021-12-07T17:27:42.634Z,1638898062.634 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-07T17:27:42.634Z,1638898062.634 [Default:CheckIn:C.Wait] Stopped 2021-12-07T17:27:42.634Z,1638898062.634 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-07T17:27:42.635Z,1638898062.635 [Default:CheckIn:D] Running Loop=1 2021-12-07T17:27:43.065Z,1638898063.065 [Default:CheckIn:D] Stopped 2021-12-07T17:27:43.065Z,1638898063.065 [Default:CheckIn:E] Running Loop=1 2021-12-07T17:27:43.444Z,1638898063.444 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 136.518506 min 2021-12-07T17:27:43.444Z,1638898063.444 [Default:CheckIn:E] Stopped 2021-12-07T17:27:43.444Z,1638898063.444 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-07T17:27:43.444Z,1638898063.444 [Default:CheckIn] Stopped 2021-12-07T17:27:43.444Z,1638898063.444 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-07T17:27:43.445Z,1638898063.445 [Default:CheckIn](INFO): Running loop #23 2021-12-07T17:27:43.445Z,1638898063.445 [Default:CheckIn] Running Loop=23 2021-12-07T17:27:43.445Z,1638898063.445 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-07T17:27:43.445Z,1638898063.445 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-07T17:27:45.451Z,1638898065.451 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172744.00,A,3637.84995,N,12154.57194,W,0.194,263.82,071221,,,D*79 2021-12-07T17:27:45.454Z,1638898065.454 [NAL9602](INFO): GPS fix at 20211207T172744: (36.630832, -121.909532) 2021-12-07T17:27:45.466Z,1638898065.466 [Default:CheckIn:Read_GPS] Stopped 2021-12-07T17:27:45.466Z,1638898065.466 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-07T17:27:52.938Z,1638898072.938 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20211207T150746/Courier0082.lzma 2021-12-07T17:27:53.941Z,1638898073.941 [DataOverHttps](INFO): Moved sent file to Logs/20211207T150746/Courier0082.lzma.bak 2021-12-07T17:27:53.941Z,1638898073.941 [DataOverHttps](INFO): SBD MOMSN=16335043 2021-12-07T17:28:14.620Z,1638898094.620 [DataOverHttps](INFO): Sending 266 bytes from file Logs/20211207T172333/Courier0000.lzma 2021-12-07T17:28:15.620Z,1638898095.620 [DataOverHttps](INFO): Moved sent file to Logs/20211207T172333/Courier0000.lzma.bak 2021-12-07T17:28:15.621Z,1638898095.621 [DataOverHttps](INFO): SBD MOMSN=16335045 2021-12-07T17:28:19.929Z,1638898099.929 [NAL9602](INFO): SBD MO Status=2, MOMSN=17842, MT Status=2, MTMSN=0 2021-12-07T17:28:19.929Z,1638898099.929 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-12-07T17:28:32.662Z,1638898112.662 [DataOverHttps](INFO): Sending 104 bytes from file Logs/20211207T150746/Express0083.lzma 2021-12-07T17:28:33.665Z,1638898113.665 [DataOverHttps](INFO): Moved sent file to Logs/20211207T150746/Express0083.lzma.bak 2021-12-07T17:28:33.665Z,1638898113.665 [DataOverHttps](INFO): SBD MOMSN=16335049 2021-12-07T17:28:45.840Z,1638898125.840 [NAL9602](INFO): SBD MO Status=0, MOMSN=17842, MT Status=0, MTMSN=0 2021-12-07T17:28:45.840Z,1638898125.840 [NAL9602](INFO): No messages in MT queue 2021-12-07T17:28:50.540Z,1638898130.540 [DataOverHttps](INFO): Sending 381 bytes from file Logs/20211207T172333/Express0001.lzma 2021-12-07T17:28:51.541Z,1638898131.541 [DataOverHttps](INFO): Moved sent file to Logs/20211207T172333/Express0001.lzma.bak 2021-12-07T17:28:51.541Z,1638898131.541 [DataOverHttps](INFO): SBD MOMSN=16335052 2021-12-07T17:28:52.660Z,1638898132.660 [Default:CheckIn:Read_Iridium] Stopped 2021-12-07T17:28:52.660Z,1638898132.660 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-07T17:28:52.660Z,1638898132.660 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-07T17:29:16.486Z,1638898156.486 [NAL9602](INFO): Not Powering down - fast GPS 2021-12-07T17:32:01.881Z,1638898321.881 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2021-12-07T17:32:08.309Z,1638898328.309 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2021-12-07T17:32:08.312Z,1638898328.312 [BPC1](INFO): Received data from all battery sticks. 2021-12-07T17:33:08.099Z,1638898388.099 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude 2021-12-07T17:33:53.346Z,1638898433.346 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-07T17:33:53.346Z,1638898433.346 [Default:CheckIn:C.Wait] Stopped 2021-12-07T17:33:53.346Z,1638898433.346 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-07T17:33:53.346Z,1638898433.346 [Default:CheckIn:D] Running Loop=1 2021-12-07T17:33:53.773Z,1638898433.773 [Default:CheckIn:D] Stopped 2021-12-07T17:33:53.773Z,1638898433.773 [Default:CheckIn:E] Running Loop=1 2021-12-07T17:33:54.167Z,1638898434.167 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 142.696973 min 2021-12-07T17:33:54.168Z,1638898434.168 [Default:CheckIn:E] Stopped 2021-12-07T17:33:54.168Z,1638898434.168 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-07T17:33:54.168Z,1638898434.168 [Default:CheckIn] Stopped 2021-12-07T17:33:54.168Z,1638898434.168 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-07T17:33:54.168Z,1638898434.168 [Default:CheckIn](INFO): Running loop #24 2021-12-07T17:33:54.168Z,1638898434.168 [Default:CheckIn] Running Loop=24 2021-12-07T17:33:54.168Z,1638898434.168 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-07T17:33:54.168Z,1638898434.168 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-07T17:33:56.162Z,1638898436.162 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173355.00,A,3637.86703,N,12154.58663,W,0.156,261.21,071221,,,A*7F 2021-12-07T17:33:56.164Z,1638898436.164 [NAL9602](INFO): GPS fix at 20211207T173355: (36.631117, -121.909777) 2021-12-07T17:33:56.176Z,1638898436.176 [Default:CheckIn:Read_GPS] Stopped 2021-12-07T17:33:56.177Z,1638898436.177 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-07T17:34:04.159Z,1638898444.159 [DataOverHttps](INFO): Sending 202 bytes from file Logs/20211207T172333/Courier0003.lzma 2021-12-07T17:34:05.161Z,1638898445.161 [DataOverHttps](INFO): Moved sent file to Logs/20211207T172333/Courier0003.lzma.bak 2021-12-07T17:34:05.161Z,1638898445.161 [DataOverHttps](INFO): SBD MOMSN=16335061 2021-12-07T17:34:13.592Z,1638898453.592 [NAL9602](INFO): SBD MO Status=0, MOMSN=17843, MT Status=0, MTMSN=0 2021-12-07T17:34:13.592Z,1638898453.592 [NAL9602](INFO): No messages in MT queue 2021-12-07T17:34:25.366Z,1638898465.366 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20211207T172333/Express0007.lzma 2021-12-07T17:34:26.368Z,1638898466.368 [DataOverHttps](INFO): Moved sent file to Logs/20211207T172333/Express0007.lzma.bak 2021-12-07T17:34:26.369Z,1638898466.369 [DataOverHttps](INFO): SBD MOMSN=16335065 2021-12-07T17:34:27.732Z,1638898467.732 [Default:CheckIn:Read_Iridium] Stopped 2021-12-07T17:34:27.732Z,1638898467.732 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-07T17:34:27.732Z,1638898467.732 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-07T17:34:44.291Z,1638898484.291 [NAL9602](INFO): Not Powering down - fast GPS 2021-12-07T17:39:20.384Z,1638898760.384 [DataOverHttps](IMPORTANT): SBD MTMSN=20211207T173919 2021-12-07T17:39:28.118Z,1638898768.118 [DataOverHttps](INFO): Received command: Maintain control speedcontrol.propomegaaction 75 rpm 2021-12-07T17:39:28.476Z,1638898768.476 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-07T17:39:28.476Z,1638898768.476 [Default:CheckIn:C.Wait] Stopped 2021-12-07T17:39:28.476Z,1638898768.476 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-07T17:39:28.476Z,1638898768.476 [Default:CheckIn:D] Running Loop=1 2021-12-07T17:39:28.822Z,1638898768.822 [Default:CheckIn:D] Stopped 2021-12-07T17:39:28.822Z,1638898768.822 [Default:CheckIn:E] Running Loop=1 2021-12-07T17:39:29.207Z,1638898769.207 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 148.281104 min 2021-12-07T17:39:29.207Z,1638898769.207 [Default:CheckIn:E] Stopped 2021-12-07T17:39:29.208Z,1638898769.208 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-07T17:39:29.208Z,1638898769.208 [Default:CheckIn] Stopped 2021-12-07T17:39:29.208Z,1638898769.208 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-07T17:39:29.208Z,1638898769.208 [Default:CheckIn](INFO): Running loop #25 2021-12-07T17:39:29.208Z,1638898769.208 [Default:CheckIn] Running Loop=25 2021-12-07T17:39:29.208Z,1638898769.208 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-07T17:39:29.208Z,1638898769.208 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-07T17:39:29.401Z,1638898769.401 [CommandExec](IMPORTANT): got command maintain control SpeedControl.propOmegaAction 75.000000 revolution_per_minute 2021-12-07T17:39:29.402Z,1638898769.402 [ComponentRegistry](DEBUG): SyncComponent "Maintain_SpeedControl.propOmegaAction" handled in the control thread. 2021-12-07T17:39:29.672Z,1638898769.672 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,Power24vConverter,RDI_Pathfinder,DAT,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,Maintain_SpeedControl.propOmegaAction,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter, 2021-12-07T17:39:31.211Z,1638898771.211 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173930.00,A,3637.88306,N,12154.58909,W,0.233,286.38,071221,,,A*7B 2021-12-07T17:39:31.213Z,1638898771.213 [NAL9602](INFO): GPS fix at 20211207T173930: (36.631384, -121.909818) 2021-12-07T17:39:31.226Z,1638898771.226 [Default:CheckIn:Read_GPS] Stopped 2021-12-07T17:39:31.226Z,1638898771.226 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-07T17:39:39.335Z,1638898779.335 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211207T172333/Courier0009.lzma 2021-12-07T17:39:40.337Z,1638898780.337 [DataOverHttps](INFO): Moved sent file to Logs/20211207T172333/Courier0009.lzma.bak 2021-12-07T17:39:40.337Z,1638898780.337 [DataOverHttps](INFO): SBD MOMSN=16335074 2021-12-07T17:39:48.591Z,1638898788.591 [NAL9602](INFO): SBD MO Status=0, MOMSN=17844, MT Status=0, MTMSN=0 2021-12-07T17:39:48.592Z,1638898788.592 [NAL9602](INFO): No messages in MT queue 2021-12-07T17:39:57.239Z,1638898797.239 [DataOverHttps](INFO): Sending 266 bytes from file Logs/20211207T172333/Express0010.lzma 2021-12-07T17:39:58.233Z,1638898798.233 [DataOverHttps](INFO): Moved sent file to Logs/20211207T172333/Express0010.lzma.bak 2021-12-07T17:39:58.234Z,1638898798.234 [DataOverHttps](IMPORTANT): SBD MOMSN=16335078, MTMSN=20211207T173957 2021-12-07T17:40:09.279Z,1638898809.279 [DataOverHttps](INFO): Received command: load Maintenance/ballast_and_trim.xml;set ballast_and_trim.MissionTimeout 30 min;set ballast_and_trim.Depth1 9 m;set ballast_and_trim.ApproachSpeed 0 m/s;run 2021-12-07T17:40:09.399Z,1638898809.399 [CommandExec](IMPORTANT): got command load ./Missions/Maintenance/ballast_and_trim.xml 2021-12-07T17:40:09.400Z,1638898809.400 [MissionManager](INFO): Loading Mission: ./Missions/Maintenance/ballast_and_trim.xml 2021-12-07T17:40:09.612Z,1638898809.612 [MissionManager](INFO): DefineArg ballast_and_trim.MissionTimeout = 90.000000 min 2021-12-07T17:40:09.711Z,1638898809.711 [MissionManager](INFO): DefineArg ballast_and_trim.SkipComms = 0 bool 2021-12-07T17:40:09.728Z,1638898809.728 [MissionManager](INFO): DefineArg ballast_and_trim.Depth1 = 35.000000 m 2021-12-07T17:40:09.755Z,1638898809.755 [MissionManager](INFO): DefineArg ballast_and_trim.Depth2 = nan m 2021-12-07T17:40:09.758Z,1638898809.758 [MissionManager](INFO): DefineArg ballast_and_trim.DepthDeadband = 0.100000 m 2021-12-07T17:40:09.780Z,1638898809.780 [MissionManager](INFO): DefineArg ballast_and_trim.ApproachSpeed = 1.000000 m/s 2021-12-07T17:40:09.799Z,1638898809.799 [MissionManager](INFO): DefineArg ballast_and_trim.ApproachDepthTimeout = 20.000000 min 2021-12-07T17:40:09.802Z,1638898809.802 [MissionManager](INFO): DefineArg ballast_and_trim.ApproachDepthRate = 0.400000 m/s 2021-12-07T17:40:09.810Z,1638898809.810 [MissionManager](INFO): DefineArg ballast_and_trim.ApproachPitchLimit = 20.000000 arcdeg 2021-12-07T17:40:09.829Z,1638898809.829 [MissionManager](INFO): DefineArg ballast_and_trim.ApproachSettleTimePreDive = 0.000000 min 2021-12-07T17:40:09.848Z,1638898809.848 [MissionManager](INFO): DefineArg ballast_and_trim.SettleTime = 10.000000 min 2021-12-07T17:40:09.858Z,1638898809.858 [MissionManager](INFO): DefineArg ballast_and_trim.EstimationTimeout = 45.000000 min 2021-12-07T17:40:09.874Z,1638898809.874 [MissionManager](INFO): DefineArg ballast_and_trim.MinEstimationTime = 10.000000 min 2021-12-07T17:40:09.900Z,1638898809.900 [MissionManager](INFO): DefineArg ballast_and_trim.MassEstimationErrorBound = 0.250000 mm 2021-12-07T17:40:09.929Z,1638898809.929 [MissionManager](INFO): DefineArg ballast_and_trim.BuoyEstimationErrorBound = 15.000000 cc 2021-12-07T17:40:09.969Z,1638898809.969 [MissionManager](INFO): DefineArg ballast_and_trim.EstimationConfidence = 99.900000 % 2021-12-07T17:40:09.000Z,1638898810.000 [MissionManager](INFO): DefineArg ballast_and_trim.massDeadband = 0.250000 mm 2021-12-07T17:40:10.012Z,1638898810.012 [MissionManager](INFO): DefineArg ballast_and_trim.MinAltitude = 5.000000 m 2021-12-07T17:40:10.071Z,1638898810.071 [MissionManager](INFO): DefineArg ballast_and_trim.MaxDepth = 52.000000 m 2021-12-07T17:40:10.091Z,1638898810.091 [MissionManager](INFO): DefineArg ballast_and_trim.MinOffshore = 2.000000 km 2021-12-07T17:40:10.094Z,1638898810.094 [MissionManager](INFO): DefineArg ballast_and_trim.CheckDepths = 1.000000 bool 2021-12-07T17:40:10.111Z,1638898810.111 [MissionManager](INFO): Inserting Stack: Missions/Insert/Science.xml 2021-12-07T17:40:11.532Z,1638898811.532 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDetectChlActive = 0 bool 2021-12-07T17:40:11.552Z,1638898811.552 [MissionManager](INFO): DefineArg ballast_and_trim:Science.TimeWindowPeakReport = nan min 2021-12-07T17:40:11.554Z,1638898811.554 [MissionManager](INFO): DefineArg ballast_and_trim:Science.HighestChlPeakReportActive = 0 bool 2021-12-07T17:40:11.585Z,1638898811.585 [MissionManager](INFO): DefineArg ballast_and_trim:Science.HighestSaltPeakReportActive = 0 bool 2021-12-07T17:40:11.651Z,1638898811.651 [MissionManager](INFO): DefineArg ballast_and_trim:Science.HighestOilPeakReportActive = 0 bool 2021-12-07T17:40:11.654Z,1638898811.654 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PatchTracking = 0 bool 2021-12-07T17:40:11.657Z,1638898811.657 [MissionManager](INFO): DefineArg ballast_and_trim:Science.DetectTrough = 0 bool 2021-12-07T17:40:11.672Z,1638898811.672 [MissionManager](INFO): DefineArg ballast_and_trim:Science.FilterWidthHorizontal = 3.000000 count 2021-12-07T17:40:11.691Z,1638898811.691 [MissionManager](INFO): DefineArg ballast_and_trim:Science.NumProfilesSlidingwindow = 100.000000 count 2021-12-07T17:40:11.703Z,1638898811.703 [MissionManager](INFO): DefineArg ballast_and_trim:Science.OffPeakFractionHorizontal = 80.000000 % 2021-12-07T17:40:11.705Z,1638898811.705 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDetectNO3Active = 0 bool 2021-12-07T17:40:11.720Z,1638898811.720 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDetectOilActive = 0 bool 2021-12-07T17:40:11.739Z,1638898811.739 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDetectFDOMActive = 0 bool 2021-12-07T17:40:11.742Z,1638898811.742 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDetectSalinityActive = 0 bool 2021-12-07T17:40:11.765Z,1638898811.765 [MissionManager](INFO): DefineArg ballast_and_trim:Science.UpwardDerivativeOfTemperatureActive = 0 bool 2021-12-07T17:40:11.793Z,1638898811.793 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledAanderaaO2 = 0.000000 bool 2021-12-07T17:40:11.813Z,1638898811.813 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledNeilBrown = 0.000000 bool 2021-12-07T17:40:11.839Z,1638898811.839 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledSeabird = 1.000000 bool 2021-12-07T17:40:11.842Z,1638898811.842 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledWetLabsBB2FL = 1.000000 bool 2021-12-07T17:40:11.850Z,1638898811.850 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledWetLabsSeaOWL_UV_A = 0.000000 bool 2021-12-07T17:40:11.874Z,1638898811.874 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledWetLabsUBAT = 1.000000 bool 2021-12-07T17:40:11.889Z,1638898811.889 [MissionManager](INFO): DefineArg ballast_and_trim:Science.LowPassWindowLength = 20.000000 count 2021-12-07T17:40:11.893Z,1638898811.893 [MissionManager](INFO): DefineArg ballast_and_trim:Science.MedianFilterLen = 5.000000 count 2021-12-07T17:40:11.912Z,1638898811.912 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakShallowBound = nan m 2021-12-07T17:40:11.919Z,1638898811.919 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDeepBound = nan m 2021-12-07T17:40:11.922Z,1638898811.922 [MissionManager](INFO): DefineArg ballast_and_trim:Science.DepChangeThreshForAttitudeFlip = 2.000000 m 2021-12-07T17:40:11.938Z,1638898811.938 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChl = 0.000000 ug/l 2021-12-07T17:40:11.959Z,1638898811.959 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChlDepth = 0.000000 m 2021-12-07T17:40:11.989Z,1638898811.989 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChlTemperature = 0.000000 degC 2021-12-07T17:40:12.027Z,1638898812.027 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChlLatitude = nan arcdeg 2021-12-07T17:40:12.035Z,1638898812.035 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChlLongitude = nan arcdeg 2021-12-07T17:40:12.038Z,1638898812.038 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakNO3 = 0.000000 umol/l 2021-12-07T17:40:12.057Z,1638898812.057 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakNO3Depth = 0.000000 m 2021-12-07T17:40:12.061Z,1638898812.061 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakNO3Latitude = nan arcdeg 2021-12-07T17:40:12.113Z,1638898812.113 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakNO3Longitude = nan arcdeg 2021-12-07T17:40:12.128Z,1638898812.128 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakOil = 0.000000 kg/m3 2021-12-07T17:40:12.151Z,1638898812.151 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakOilDepth = 0.000000 m 2021-12-07T17:40:12.159Z,1638898812.159 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakOilLatitude = nan arcdeg 2021-12-07T17:40:12.162Z,1638898812.162 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakOilLongitude = nan arcdeg 2021-12-07T17:40:12.185Z,1638898812.185 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakFDOM = 0.000000 ppb 2021-12-07T17:40:12.208Z,1638898812.208 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakFDOMDepth = 0.000000 m 2021-12-07T17:40:12.232Z,1638898812.232 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakFDOMTemperature = nan degC 2021-12-07T17:40:12.247Z,1638898812.247 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakFDOMLatitude = nan arcdeg 2021-12-07T17:40:12.253Z,1638898812.253 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakFDOMLongitude = nan arcdeg 2021-12-07T17:40:12.272Z,1638898812.272 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchFDOMDistance = nan m 2021-12-07T17:40:12.292Z,1638898812.292 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakSalt = 0.000000 psu 2021-12-07T17:40:12.303Z,1638898812.303 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakSaltDepth = 0.000000 m 2021-12-07T17:40:12.306Z,1638898812.306 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakSaltTemperature = 0.000000 degC 2021-12-07T17:40:12.322Z,1638898812.322 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakSaltLatitude = nan arcdeg 2021-12-07T17:40:12.326Z,1638898812.326 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakSaltLongitude = nan arcdeg 2021-12-07T17:40:12.350Z,1638898812.350 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChl = 0.000000 ug/l 2021-12-07T17:40:12.365Z,1638898812.365 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChlDepth = 0.000000 m 2021-12-07T17:40:12.373Z,1638898812.373 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChlLatitude = nan arcdeg 2021-12-07T17:40:12.376Z,1638898812.376 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChlLongitude = nan arcdeg 2021-12-07T17:40:12.396Z,1638898812.396 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChlDistance = nan m 2021-12-07T17:40:12.411Z,1638898812.411 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchSalt = 0.000000 psu 2021-12-07T17:40:12.414Z,1638898812.414 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchSaltDepth = 0.000000 m 2021-12-07T17:40:12.439Z,1638898812.439 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchSaltLatitude = nan arcdeg 2021-12-07T17:40:12.442Z,1638898812.442 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchSaltLongitude = nan arcdeg 2021-12-07T17:40:12.450Z,1638898812.450 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchSaltDistance = nan m 2021-12-07T17:40:12.469Z,1638898812.469 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchOil = 0.000000 psu 2021-12-07T17:40:12.517Z,1638898812.517 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchOilDepth = 0.000000 m 2021-12-07T17:40:12.537Z,1638898812.537 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchOilLatitude = nan arcdeg 2021-12-07T17:40:12.556Z,1638898812.556 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchOilLongitude = nan arcdeg 2021-12-07T17:40:12.568Z,1638898812.568 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchOilDistance = nan m 2021-12-07T17:40:12.756Z,1638898812.756 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth. 2021-12-07T17:40:12.798Z,1638898812.798 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal](DEBUG): Construct PeakDetectHorizontal. 2021-12-07T17:40:12.853Z,1638898812.853 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth. 2021-12-07T17:40:12.948Z,1638898812.948 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth. 2021-12-07T17:40:13.062Z,1638898813.062 [ballast_and_trim:Science:HighestOilPeakReport:A.PeakDetectHorizontal](DEBUG): Construct PeakDetectHorizontal. 2021-12-07T17:40:13.121Z,1638898813.121 [ballast_and_trim:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth. 2021-12-07T17:40:13.162Z,1638898813.162 [ballast_and_trim:Science:PeakDetectSalinity:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth. 2021-12-07T17:40:13.229Z,1638898813.229 [ballast_and_trim:Science:HighestSaltPeakReport:A.PeakDetectHorizontal](DEBUG): Construct PeakDetectHorizontal. 2021-12-07T17:40:13.265Z,1638898813.265 [MissionManager](INFO): Inserting Stack: Missions/Insert/NeedComms.xml 2021-12-07T17:40:13.592Z,1638898813.592 [MissionManager](INFO): DefineArg ballast_and_trim:NeedComms.DiveInterval = 3.000000 h 2021-12-07T17:40:13.612Z,1638898813.612 [MissionManager](INFO): DefineArg ballast_and_trim:NeedComms.WaitForPitchUp = 10.000000 min 2021-12-07T17:40:13.641Z,1638898813.641 [MissionManager](INFO): DefineArg ballast_and_trim:NeedComms.SurfacePitch = 20.000000 arcdeg 2021-12-07T17:40:13.669Z,1638898813.669 [MissionManager](INFO): DefineArg ballast_and_trim:NeedComms.SurfaceDepthRate = nan m/s 2021-12-07T17:40:13.696Z,1638898813.696 [MissionManager](INFO): DefineArg ballast_and_trim:NeedComms.SurfaceSpeed = 1.000000 m/s 2021-12-07T17:40:13.715Z,1638898813.715 [MissionManager](INFO): DefineArg ballast_and_trim:NeedComms.GPSTimeout = 7.000000 min 2021-12-07T17:40:13.743Z,1638898813.743 [MissionManager](INFO): DefineArg ballast_and_trim:NeedComms.CommsTimeout = 30.000000 min 2021-12-07T17:40:13.782Z,1638898813.782 [ballast_and_trim:NeedComms:B.GoToSurface](DEBUG): Construct GoToSurface. 2021-12-07T17:40:13.925Z,1638898813.925 [MissionManager](INFO): Inserting Stack: Missions/Insert/StandardEnvelopes.xml 2021-12-07T17:40:14.102Z,1638898814.102 [MissionManager](INFO): DefineArg ballast_and_trim:StandardEnvelopes.MinAltitude = 5.000000 m 2021-12-07T17:40:14.129Z,1638898814.129 [MissionManager](INFO): DefineArg ballast_and_trim:StandardEnvelopes.MaxDepth = 200.000000 m 2021-12-07T17:40:14.153Z,1638898814.153 [MissionManager](INFO): DefineArg ballast_and_trim:StandardEnvelopes.MinOffshore = 2000.000000 m 2021-12-07T17:40:14.175Z,1638898814.175 [ballast_and_trim:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope. 2021-12-07T17:40:14.238Z,1638898814.238 [ballast_and_trim:StandardEnvelopes:B.DepthEnvelope](DEBUG): Construct DepthEnvelope. 2021-12-07T17:40:14.340Z,1638898814.340 [ballast_and_trim:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Construct OffshoreEnvelope. 2021-12-07T17:40:14.437Z,1638898814.437 [ballast_and_trim:CheckTargetDepths:CheckDepth1:B.Execute](DEBUG): Construct Execute. 2021-12-07T17:40:14.466Z,1638898814.466 [ballast_and_trim:CheckTargetDepths:CheckDepth2:B.Execute](DEBUG): Construct Execute. 2021-12-07T17:40:14.536Z,1638898814.536 [MissionManager](INFO): Inserting Stack: Missions/Insert/BallastAndTrim.xml 2021-12-07T17:40:15.223Z,1638898815.223 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertDepth = 25.000000 m 2021-12-07T17:40:15.226Z,1638898815.226 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachSpeed = 0.000000 m/s 2021-12-07T17:40:15.268Z,1638898815.268 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachDepthRate = 0.400000 m/s 2021-12-07T17:40:15.291Z,1638898815.291 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachPitchLimit = 20.000000 arcdeg 2021-12-07T17:40:15.294Z,1638898815.294 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachSettleTimePreDive = 0.000000 min 2021-12-07T17:40:15.330Z,1638898815.330 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachDepthTimeout = 20.000000 min 2021-12-07T17:40:15.369Z,1638898815.369 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertSettleTime = 10.000000 min 2021-12-07T17:40:15.389Z,1638898815.389 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.EstTimeout = 45.000000 min 2021-12-07T17:40:15.436Z,1638898815.436 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.MinEstTime = 10.000000 min 2021-12-07T17:40:15.447Z,1638898815.447 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.MassEstErrorBound = 0.250000 mm 2021-12-07T17:40:15.460Z,1638898815.460 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.BuoyEstErrorBound = 15.000000 cc 2021-12-07T17:40:15.471Z,1638898815.471 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.EstConfidence = 99.900000 % 2021-12-07T17:40:15.474Z,1638898815.474 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertDepthDeadband = 1.000000 m 2021-12-07T17:40:15.510Z,1638898815.510 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertMassDeadband = 0.250000 mm 2021-12-07T17:40:15.657Z,1638898815.657 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:A.Point](DEBUG): Construct. 2021-12-07T17:40:15.689Z,1638898815.689 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy](DEBUG): Construct Buoyancy. 2021-12-07T17:40:15.710Z,1638898815.710 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:C.Pitch](DEBUG): Construct. 2021-12-07T17:40:15.795Z,1638898815.795 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:B.Wait](DEBUG): Construct Wait. 2021-12-07T17:40:15.831Z,1638898815.831 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed](DEBUG): Construct. 2021-12-07T17:40:15.867Z,1638898815.867 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:C.Pitch](DEBUG): Construct. 2021-12-07T17:40:15.898Z,1638898815.898 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:C.Pitch:A_Timeout:B.Execute](DEBUG): Construct Execute. 2021-12-07T17:40:15.944Z,1638898815.944 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed](DEBUG): Construct. 2021-12-07T17:40:15.964Z,1638898815.964 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:B.Pitch](DEBUG): Construct. 2021-12-07T17:40:15.995Z,1638898815.995 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait](DEBUG): Construct Wait. 2021-12-07T17:40:16.038Z,1638898816.038 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](DEBUG): Construct BallastAndTrim. 2021-12-07T17:40:16.211Z,1638898816.211 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertDepthDeadband = reader:ballast_and_trim.DepthDeadband 2021-12-07T17:40:16.213Z,1638898816.213 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachSpeed = reader:ballast_and_trim.ApproachSpeed 2021-12-07T17:40:16.235Z,1638898816.235 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachDepthRate = reader:ballast_and_trim.ApproachDepthRate 2021-12-07T17:40:16.237Z,1638898816.237 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachPitchLimit = reader:ballast_and_trim.ApproachPitchLimit 2021-12-07T17:40:16.259Z,1638898816.259 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachSettleTimePreDive = reader:ballast_and_trim.ApproachSettleTimePreDive 2021-12-07T17:40:16.261Z,1638898816.261 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachDepthTimeout = reader:ballast_and_trim.ApproachDepthTimeout 2021-12-07T17:40:16.287Z,1638898816.287 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertSettleTime = reader:ballast_and_trim.SettleTime 2021-12-07T17:40:16.289Z,1638898816.289 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.EstTimeout = reader:ballast_and_trim.EstimationTimeout 2021-12-07T17:40:16.311Z,1638898816.311 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.MinEstTime = reader:ballast_and_trim.MinEstimationTime 2021-12-07T17:40:16.313Z,1638898816.313 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.MassEstErrorBound = reader:ballast_and_trim.MassEstimationErrorBound 2021-12-07T17:40:16.335Z,1638898816.335 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.BuoyEstErrorBound = reader:ballast_and_trim.BuoyEstimationErrorBound 2021-12-07T17:40:16.337Z,1638898816.337 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.EstConfidence = reader:ballast_and_trim.EstimationConfidence 2021-12-07T17:40:16.362Z,1638898816.362 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertMassDeadband = reader:ballast_and_trim.massDeadband 2021-12-07T17:40:16.741Z,1638898816.741 [MissionManager](DEBUG): Maximum duration of mission 90 Skip communications at start of mission. 35 NaN How much vertical drift from the specified depth is allowed durnig the mission. 0.1 Enables vehicle thruster at the commanded speed to reach target depth (set to 0 m/s to drift). 1 Maximum wait time for the vehicle to reach the targeted depth. 20 Descent depth rate (Positive depth rate means going down). 0.4 Max vehicle pitch (+/-) when decending from the surface. 20 Time duration for the vehicle to pump down the VBS *BEFORE* leaving the surface. 0 How long to wait after reaching target depth before starting ballast and trim. 10 Timeout for ballast and trim estimation. 45 Minimum time to run ballast and trim estimation before determining convergence (must be shorter than timeout). 10 Desired range of the estimated sample mean from the true mean statistic (smaller values take longer to converge). 0.25 Desired range of the estimated sample mean from the true mean statistic (smaller values take longer to converge). 15 Confidence level that the estimator has reached the desired error range (larger values take longer to converge). 99.9 Degree of rounding in mass-shifter command output values. 0.25 5 52 2 1 Aborting ballast and trim mission. Target depth Depth1 exceeds the mission's MaxDepth setting (review mission parameters). stop Aborting ballast and trim mission. Target depth Depth2 exceeds the mission's MaxDepth setting (review mission parameters). stop 0 Checking for additional instructions before submerging. 2021-12-07T17:40:16.742Z,1638898816.742 [CommandExec](IMPORTANT): Loaded ./Missions/Maintenance/ballast_and_trim.xml 2021-12-07T17:40:19.022Z,1638898819.022 [NAL9602](INFO): Not Powering down - fast GPS 2021-12-07T17:40:28.466Z,1638898828.466 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20211207T172333/Express0013.lzma 2021-12-07T17:40:29.468Z,1638898829.468 [DataOverHttps](INFO): Moved sent file to Logs/20211207T172333/Express0013.lzma.bak 2021-12-07T17:40:29.469Z,1638898829.469 [DataOverHttps](INFO): SBD MOMSN=16335085 2021-12-07T17:40:33.387Z,1638898833.387 [CommandExec](IMPORTANT): got command set ballast_and_trim.MissionTimeout 30.000000 minute 2021-12-07T17:40:33.388Z,1638898833.388 [CommandExec](IMPORTANT): got command set ballast_and_trim.Depth1 9.000000 meter 2021-12-07T17:40:33.389Z,1638898833.389 [CommandExec](IMPORTANT): got command set ballast_and_trim.ApproachSpeed 0.000000 meter_per_second 2021-12-07T17:40:33.389Z,1638898833.389 [CommandExec](IMPORTANT): got command run 2021-12-07T17:40:33.397Z,1638898833.397 [CommandExec](IMPORTANT): Running 2021-12-07T17:40:33.647Z,1638898833.647 [Default] Stopped 2021-12-07T17:40:33.648Z,1638898833.648 [Default](DEBUG): Aggregate::uninitialize Default 2021-12-07T17:40:33.648Z,1638898833.648 [Default:B.GoToSurface] Stopped 2021-12-07T17:40:33.648Z,1638898833.648 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2021-12-07T17:40:33.648Z,1638898833.648 [Default:CheckIn] Stopped 2021-12-07T17:40:33.648Z,1638898833.648 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-07T17:40:33.648Z,1638898833.648 [Default:CheckIn:Read_Iridium] Stopped 2021-12-07T17:40:33.648Z,1638898833.648 [MissionManager](IMPORTANT): Started mission ballast_and_trim 2021-12-07T17:40:33.649Z,1638898833.649 [ballast_and_trim] Running Loop=1 2021-12-07T17:40:33.649Z,1638898833.649 [ballast_and_trim](DEBUG): Aggregate::initialize ballast_and_trim 2021-12-07T17:40:33.649Z,1638898833.649 [ballast_and_trim:Science] Running Loop=1 2021-12-07T17:40:33.649Z,1638898833.649 [ballast_and_trim:Science](DEBUG): Aggregate::initialize ballast_and_trim:Science 2021-12-07T17:40:33.649Z,1638898833.649 [ballast_and_trim:Science:A] Running Loop=1 2021-12-07T17:40:33.649Z,1638898833.649 [ballast_and_trim:Science:B] Running Loop=1 2021-12-07T17:40:33.649Z,1638898833.649 [ballast_and_trim:Science:C] Running Loop=1 2021-12-07T17:40:33.649Z,1638898833.649 [ballast_and_trim:Science:D] Running Loop=1 2021-12-07T17:40:33.649Z,1638898833.649 [ballast_and_trim:Science:E] Running Loop=1 2021-12-07T17:40:33.649Z,1638898833.649 [ballast_and_trim:Science:F] Running Loop=1 2021-12-07T17:40:33.649Z,1638898833.649 [ballast_and_trim:Science:Read_Oil] Running Loop=1 2021-12-07T17:40:33.650Z,1638898833.650 [ballast_and_trim:Science:PeakDetectChl] Running Loop=1 2021-12-07T17:40:33.650Z,1638898833.650 [ballast_and_trim:Science:PeakDetectChl](DEBUG): Aggregate::initialize ballast_and_trim:Science:PeakDetectChl 2021-12-07T17:40:33.650Z,1638898833.650 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth] Running Loop=1 2021-12-07T17:40:33.650Z,1638898833.650 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Initialize. 2021-12-07T17:40:33.656Z,1638898833.656 [ballast_and_trim:Science:HighestChlPeakReport] Running Loop=1 2021-12-07T17:40:33.656Z,1638898833.656 [ballast_and_trim:Science:HighestChlPeakReport](DEBUG): Aggregate::initialize ballast_and_trim:Science:HighestChlPeakReport 2021-12-07T17:40:33.657Z,1638898833.657 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal] Running Loop=1 2021-12-07T17:40:33.657Z,1638898833.657 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal](INFO): Initialize. 2021-12-07T17:40:33.657Z,1638898833.657 [ballast_and_trim:Science:PeakDetectNO3] Running Loop=1 2021-12-07T17:40:33.657Z,1638898833.657 [ballast_and_trim:Science:PeakDetectNO3](DEBUG): Aggregate::initialize ballast_and_trim:Science:PeakDetectNO3 2021-12-07T17:40:33.657Z,1638898833.657 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth] Running Loop=1 2021-12-07T17:40:33.658Z,1638898833.658 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Initialize. 2021-12-07T17:40:33.664Z,1638898833.664 [ballast_and_trim:Science:PeakDetectOil] Running Loop=1 2021-12-07T17:40:33.664Z,1638898833.664 [ballast_and_trim:Science:PeakDetectOil](DEBUG): Aggregate::initialize ballast_and_trim:Science:PeakDetectOil 2021-12-07T17:40:33.664Z,1638898833.664 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth] Running Loop=1 2021-12-07T17:40:33.665Z,1638898833.665 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Initialize. 2021-12-07T17:40:33.691Z,1638898833.691 [ballast_and_trim:Science:HighestOilPeakReport] Running Loop=1 2021-12-07T17:40:33.691Z,1638898833.691 [ballast_and_trim:Science:HighestOilPeakReport](DEBUG): Aggregate::initialize ballast_and_trim:Science:HighestOilPeakReport 2021-12-07T17:40:33.692Z,1638898833.692 [ballast_and_trim:Science:HighestOilPeakReport:A.PeakDetectHorizontal] Running Loop=1 2021-12-07T17:40:33.692Z,1638898833.692 [ballast_and_trim:Science:HighestOilPeakReport:A.PeakDetectHorizontal](INFO): Initialize. 2021-12-07T17:40:33.692Z,1638898833.692 [ballast_and_trim:Science:PeakDetectFDOM] Running Loop=1 2021-12-07T17:40:33.692Z,1638898833.692 [ballast_and_trim:Science:PeakDetectFDOM](DEBUG): Aggregate::initialize ballast_and_trim:Science:PeakDetectFDOM 2021-12-07T17:40:33.692Z,1638898833.692 [ballast_and_trim:Science:PeakDetectFDOM:A.PeakDetectVsDepth] Running Loop=1 2021-12-07T17:40:33.693Z,1638898833.693 [ballast_and_trim:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Initialize. 2021-12-07T17:40:33.703Z,1638898833.703 [ballast_and_trim:Science:PeakDetectSalinity] Running Loop=1 2021-12-07T17:40:33.703Z,1638898833.703 [ballast_and_trim:Science:PeakDetectSalinity](DEBUG): Aggregate::initialize ballast_and_trim:Science:PeakDetectSalinity 2021-12-07T17:40:33.703Z,1638898833.703 [ballast_and_trim:Science:PeakDetectSalinity:A.PeakDetectVsDepth] Running Loop=1 2021-12-07T17:40:33.703Z,1638898833.703 [ballast_and_trim:Science:PeakDetectSalinity:A.PeakDetectVsDepth](DEBUG): Initialize. 2021-12-07T17:40:33.705Z,1638898833.705 [ballast_and_trim:Science:HighestSaltPeakReport] Running Loop=1 2021-12-07T17:40:33.705Z,1638898833.705 [ballast_and_trim:Science:HighestSaltPeakReport](DEBUG): Aggregate::initialize ballast_and_trim:Science:HighestSaltPeakReport 2021-12-07T17:40:33.706Z,1638898833.706 [ballast_and_trim:Science:HighestSaltPeakReport:A.PeakDetectHorizontal] Running Loop=1 2021-12-07T17:40:33.706Z,1638898833.706 [ballast_and_trim:Science:HighestSaltPeakReport:A.PeakDetectHorizontal](INFO): Initialize. 2021-12-07T17:40:33.706Z,1638898833.706 [ballast_and_trim:Science:OceanCurrent] Running Loop=1 2021-12-07T17:40:33.706Z,1638898833.706 [ballast_and_trim:Science:OceanCurrent](DEBUG): Aggregate::initialize ballast_and_trim:Science:OceanCurrent 2021-12-07T17:40:33.715Z,1638898833.715 [ballast_and_trim:Science:OceanCurrent:A.] Running Loop=1 2021-12-07T17:40:33.715Z,1638898833.715 [ballast_and_trim:Science:OceanCurrent:A.](INFO): Initializing CurrentEstimator. 2021-12-07T17:40:33.715Z,1638898833.715 [ballast_and_trim:StandardEnvelopes] Running Loop=1 2021-12-07T17:40:33.715Z,1638898833.715 [ballast_and_trim:StandardEnvelopes](DEBUG): Aggregate::initialize ballast_and_trim:StandardEnvelopes 2021-12-07T17:40:33.715Z,1638898833.715 [ballast_and_trim:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1 2021-12-07T17:40:33.715Z,1638898833.715 [ballast_and_trim:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent. 2021-12-07T17:40:33.716Z,1638898833.716 [ballast_and_trim:StandardEnvelopes:B.DepthEnvelope] Running Loop=1 2021-12-07T17:40:33.716Z,1638898833.716 [ballast_and_trim:StandardEnvelopes:B.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent. 2021-12-07T17:40:33.716Z,1638898833.716 [ballast_and_trim:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1 2021-12-07T17:40:33.716Z,1638898833.716 [ballast_and_trim:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Initialize OffshoreEnvelopeComponent. 2021-12-07T17:40:33.716Z,1638898833.716 [ballast_and_trim:C] Running Loop=1 2021-12-07T17:40:33.717Z,1638898833.717 [ballast_and_trim:StandardEnvelopes] Running Loop=1 2021-12-07T17:40:33.717Z,1638898833.717 [ballast_and_trim:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1 2021-12-07T17:40:33.752Z,1638898833.752 [ballast_and_trim:StandardEnvelopes:B.DepthEnvelope] Running Loop=1 2021-12-07T17:40:33.752Z,1638898833.752 [ballast_and_trim:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1 2021-12-07T17:40:33.753Z,1638898833.753 [ballast_and_trim:C] Stopped 2021-12-07T17:40:33.753Z,1638898833.753 [ballast_and_trim:E] Running Loop=1 2021-12-07T17:40:33.753Z,1638898833.753 [ballast_and_trim:Science] Running Loop=1 2021-12-07T17:40:33.763Z,1638898833.763 [ballast_and_trim:Science:HighestSaltPeakReport] Stopped 2021-12-07T17:40:33.763Z,1638898833.763 [ballast_and_trim:Science:HighestSaltPeakReport](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:HighestSaltPeakReport 2021-12-07T17:40:33.763Z,1638898833.763 [ballast_and_trim:Science:HighestSaltPeakReport:A.PeakDetectHorizontal] Stopped 2021-12-07T17:40:33.764Z,1638898833.764 [ballast_and_trim:Science:HighestSaltPeakReport:A.PeakDetectHorizontal](DEBUG): Uninitialize. 2021-12-07T17:40:33.764Z,1638898833.764 [ballast_and_trim:Science:PeakDetectSalinity] Stopped 2021-12-07T17:40:33.764Z,1638898833.764 [ballast_and_trim:Science:PeakDetectSalinity](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:PeakDetectSalinity 2021-12-07T17:40:33.764Z,1638898833.764 [ballast_and_trim:Science:PeakDetectSalinity:A.PeakDetectVsDepth] Stopped 2021-12-07T17:40:33.764Z,1638898833.764 [ballast_and_trim:Science:PeakDetectSalinity:A.PeakDetectVsDepth](DEBUG): Uninitialize. 2021-12-07T17:40:33.764Z,1638898833.764 [ballast_and_trim:Science:PeakDetectFDOM] Stopped 2021-12-07T17:40:33.764Z,1638898833.764 [ballast_and_trim:Science:PeakDetectFDOM](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:PeakDetectFDOM 2021-12-07T17:40:33.764Z,1638898833.764 [ballast_and_trim:Science:PeakDetectFDOM:A.PeakDetectVsDepth] Stopped 2021-12-07T17:40:33.764Z,1638898833.764 [ballast_and_trim:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Uninitialize. 2021-12-07T17:40:33.764Z,1638898833.764 [ballast_and_trim:Science:HighestOilPeakReport] Stopped 2021-12-07T17:40:33.765Z,1638898833.765 [ballast_and_trim:Science:HighestOilPeakReport](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:HighestOilPeakReport 2021-12-07T17:40:33.765Z,1638898833.765 [ballast_and_trim:Science:HighestOilPeakReport:A.PeakDetectHorizontal] Stopped 2021-12-07T17:40:33.765Z,1638898833.765 [ballast_and_trim:Science:HighestOilPeakReport:A.PeakDetectHorizontal](DEBUG): Uninitialize. 2021-12-07T17:40:33.765Z,1638898833.765 [ballast_and_trim:Science:PeakDetectOil] Stopped 2021-12-07T17:40:33.765Z,1638898833.765 [ballast_and_trim:Science:PeakDetectOil](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:PeakDetectOil 2021-12-07T17:40:33.765Z,1638898833.765 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth] Stopped 2021-12-07T17:40:33.765Z,1638898833.765 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Uninitialize. 2021-12-07T17:40:33.765Z,1638898833.765 [ballast_and_trim:Science:PeakDetectNO3] Stopped 2021-12-07T17:40:33.765Z,1638898833.765 [ballast_and_trim:Science:PeakDetectNO3](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:PeakDetectNO3 2021-12-07T17:40:33.765Z,1638898833.765 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth] Stopped 2021-12-07T17:40:33.765Z,1638898833.765 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Uninitialize. 2021-12-07T17:40:33.766Z,1638898833.766 [ballast_and_trim:Science:HighestChlPeakReport] Stopped 2021-12-07T17:40:33.766Z,1638898833.766 [ballast_and_trim:Science:HighestChlPeakReport](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:HighestChlPeakReport 2021-12-07T17:40:33.766Z,1638898833.766 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal] Stopped 2021-12-07T17:40:33.766Z,1638898833.766 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal](DEBUG): Uninitialize. 2021-12-07T17:40:33.766Z,1638898833.766 [ballast_and_trim:Science:PeakDetectChl] Stopped 2021-12-07T17:40:33.766Z,1638898833.766 [ballast_and_trim:Science:PeakDetectChl](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:PeakDetectChl 2021-12-07T17:40:33.766Z,1638898833.766 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth] Stopped 2021-12-07T17:40:33.766Z,1638898833.766 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Uninitialize. 2021-12-07T17:40:33.771Z,1638898833.771 [ballast_and_trim:Science:OceanCurrent:A.] Running Loop=1 2021-12-07T17:40:33.771Z,1638898833.771 [ballast_and_trim:Science:Read_Oil] Stopped 2021-12-07T17:40:33.771Z,1638898833.771 [ballast_and_trim:Science:F] Running Loop=1 2021-12-07T17:40:33.772Z,1638898833.772 [ballast_and_trim:Science:F](DEBUG): Initialize ReadDataComponent to sense WetLabsUBAT.average_bioluminescence 2021-12-07T17:40:33.772Z,1638898833.772 [ballast_and_trim:Science:E] Running Loop=1 2021-12-07T17:40:33.773Z,1638898833.773 [ballast_and_trim:Science:E](DEBUG): Initialize ReadDataComponent to sense mass_concentration_of_chlorophyll_in_sea_water 2021-12-07T17:40:33.773Z,1638898833.773 [ballast_and_trim:Science:D] Stopped 2021-12-07T17:40:33.773Z,1638898833.773 [ballast_and_trim:Science:C] Running Loop=1 2021-12-07T17:40:33.774Z,1638898833.774 [ballast_and_trim:Science:C](DEBUG): Initialize ReadDataComponent to sense CTD_Seabird.sea_water_temperature 2021-12-07T17:40:33.791Z,1638898833.791 [ballast_and_trim:Science:C](DEBUG): Initialize ReadDataComponent to sense CTD_Seabird.sea_water_salinity 2021-12-07T17:40:33.791Z,1638898833.791 [ballast_and_trim:Science:B] Running Loop=1 2021-12-07T17:40:33.792Z,1638898833.792 [ballast_and_trim:Science:B](DEBUG): Initialize ReadDataComponent to sense sea_water_temperature 2021-12-07T17:40:33.792Z,1638898833.792 [ballast_and_trim:Science:B](DEBUG): Initialize ReadDataComponent to sense sea_water_salinity 2021-12-07T17:40:33.793Z,1638898833.793 [ballast_and_trim:Science:A] Stopped 2021-12-07T17:40:34.044Z,1638898834.044 [ballast_and_trim:E] Stopped 2021-12-07T17:40:34.044Z,1638898834.044 [ballast_and_trim:F] Running Loop=1 2021-12-07T17:40:34.196Z,1638898834.196 [WetLabsBB2FL](INFO): Powering up 2021-12-07T17:40:34.240Z,1638898834.240 [WetLabsUBAT](INFO): Powering up 2021-12-07T17:40:34.448Z,1638898834.448 [ballast_and_trim:F] Stopped 2021-12-07T17:40:34.448Z,1638898834.448 [ballast_and_trim:G] Running Loop=1 2021-12-07T17:40:34.809Z,1638898834.809 [ballast_and_trim:G] Stopped 2021-12-07T17:40:34.809Z,1638898834.809 [ballast_and_trim:CheckTargetDepths] Running Loop=1 2021-12-07T17:40:34.809Z,1638898834.809 [ballast_and_trim:CheckTargetDepths](DEBUG): Aggregate::initialize ballast_and_trim:CheckTargetDepths 2021-12-07T17:40:34.809Z,1638898834.809 [ballast_and_trim:CheckTargetDepths:CheckDepth1] Running Loop=1 2021-12-07T17:40:34.809Z,1638898834.809 [ballast_and_trim:CheckTargetDepths:CheckDepth1](DEBUG): Aggregate::initialize ballast_and_trim:CheckTargetDepths:CheckDepth1 2021-12-07T17:40:34.809Z,1638898834.809 [ballast_and_trim:CheckTargetDepths:CheckDepth1:A] Running Loop=1 2021-12-07T17:40:35.218Z,1638898835.218 [ballast_and_trim:CheckTargetDepths:CheckDepth1] Stopped 2021-12-07T17:40:35.218Z,1638898835.218 [ballast_and_trim:CheckTargetDepths:CheckDepth1](DEBUG): Aggregate::uninitialize ballast_and_trim:CheckTargetDepths:CheckDepth1 2021-12-07T17:40:35.218Z,1638898835.218 [ballast_and_trim:CheckTargetDepths:CheckDepth1:A] Stopped 2021-12-07T17:40:35.218Z,1638898835.218 [ballast_and_trim:CheckTargetDepths:CheckDepth2] Running Loop=1 2021-12-07T17:40:35.218Z,1638898835.218 [ballast_and_trim:CheckTargetDepths:CheckDepth2](DEBUG): Aggregate::initialize ballast_and_trim:CheckTargetDepths:CheckDepth2 2021-12-07T17:40:35.223Z,1638898835.223 [ballast_and_trim:CheckTargetDepths:CheckDepth2:A] Running Loop=1 2021-12-07T17:40:35.679Z,1638898835.679 [ballast_and_trim:CheckTargetDepths:CheckDepth2] Stopped 2021-12-07T17:40:35.680Z,1638898835.680 [ballast_and_trim:CheckTargetDepths:CheckDepth2](DEBUG): Aggregate::uninitialize ballast_and_trim:CheckTargetDepths:CheckDepth2 2021-12-07T17:40:35.680Z,1638898835.680 [ballast_and_trim:CheckTargetDepths:CheckDepth2:A] Stopped 2021-12-07T17:40:35.680Z,1638898835.680 [ballast_and_trim:CheckTargetDepths:C] Running Loop=1 2021-12-07T17:40:36.014Z,1638898836.014 [ballast_and_trim:CheckTargetDepths:C] Stopped 2021-12-07T17:40:36.019Z,1638898836.019 [ballast_and_trim:CheckTargetDepths](INFO): Completed ballast_and_trim:CheckTargetDepths 2021-12-07T17:40:36.019Z,1638898836.019 [ballast_and_trim:CheckTargetDepths] Stopped 2021-12-07T17:40:36.019Z,1638898836.019 [ballast_and_trim:CheckTargetDepths](DEBUG): Aggregate::uninitialize ballast_and_trim:CheckTargetDepths 2021-12-07T17:40:36.019Z,1638898836.019 [ballast_and_trim:StartingMission] Running Loop=1 2021-12-07T17:40:36.019Z,1638898836.019 [ballast_and_trim:StartingMission](DEBUG): Aggregate::initialize ballast_and_trim:StartingMission 2021-12-07T17:40:36.019Z,1638898836.019 [ballast_and_trim:StartingMission:A] Running Loop=1 2021-12-07T17:40:36.482Z,1638898836.482 [ballast_and_trim:StartingMission:A](INFO): Checking for additional instructions before submerging. 2021-12-07T17:40:36.482Z,1638898836.482 [ballast_and_trim:StartingMission:A] Stopped 2021-12-07T17:40:36.482Z,1638898836.482 [ballast_and_trim:StartingMission:StartingMission] Running Loop=1 2021-12-07T17:40:36.482Z,1638898836.482 [ballast_and_trim:StartingMission:StartingMission](DEBUG): Aggregate::initialize ballast_and_trim:StartingMission:StartingMission 2021-12-07T17:40:36.863Z,1638898836.863 [ballast_and_trim:NeedComms] Running Loop=1 2021-12-07T17:40:36.864Z,1638898836.864 [ballast_and_trim:NeedComms](DEBUG): Aggregate::initialize ballast_and_trim:NeedComms 2021-12-07T17:40:36.864Z,1638898836.864 [ballast_and_trim:NeedComms:B.GoToSurface] Running Loop=1 2021-12-07T17:40:36.864Z,1638898836.864 [ballast_and_trim:NeedComms:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2021-12-07T17:40:36.864Z,1638898836.864 [ballast_and_trim:NeedComms:B.GoToSurface](INFO): Received depth rate setting nan m/s. 2021-12-07T17:40:36.865Z,1638898836.865 [ballast_and_trim:NeedComms:B.GoToSurface](INFO): Received pitch setting 19.999999 degrees. 2021-12-07T17:40:36.865Z,1638898836.865 [ballast_and_trim:NeedComms:B.GoToSurface](INFO): Received speed setting 1.000000 m/s. 2021-12-07T17:40:36.865Z,1638898836.865 [ballast_and_trim:NeedComms:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2021-12-07T17:40:36.866Z,1638898836.866 [ballast_and_trim:NeedComms:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2021-12-07T17:40:36.866Z,1638898836.866 [ballast_and_trim:NeedComms:A] Running Loop=1 2021-12-07T17:40:36.879Z,1638898836.879 [ballast_and_trim:NeedComms:A](INFO): last time_fix was: 1638898770.000000 second since 1970/01/01T00:00:00Z 2021-12-07T17:40:36.880Z,1638898836.880 [ballast_and_trim:NeedComms:A] Stopped 2021-12-07T17:40:37.242Z,1638898837.242 [ballast_and_trim:NeedComms:C] Running Loop=1 2021-12-07T17:40:37.652Z,1638898837.652 [CTD_Seabird](ERROR): Failed to parse device response: 2021-12-07T17:40:37.740Z,1638898837.740 [ballast_and_trim:NeedComms:C](DEBUG): Initialize ReadDataComponent to sense time_fix 2021-12-07T17:40:39.237Z,1638898839.237 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174038.00,A,3637.88634,N,12154.58816,W,0.447,334.23,071221,,,A*71 2021-12-07T17:40:39.243Z,1638898839.243 [NAL9602](INFO): GPS fix at 20211207T174038: (36.631439, -121.909803) 2021-12-07T17:40:39.271Z,1638898839.271 [ballast_and_trim:NeedComms:C] Stopped 2021-12-07T17:40:39.271Z,1638898839.271 [ballast_and_trim:NeedComms:D] Running Loop=1 2021-12-07T17:40:39.730Z,1638898839.730 [ballast_and_trim:NeedComms:D](DEBUG): Initialize ReadDataComponent to sense platform_communications 2021-12-07T17:40:44.413Z,1638898844.413 [WetLabsUBAT](FAULT): UBAT flow rate is below the specified threshold of 0.05 l/s. 2021-12-07T17:40:49.824Z,1638898849.824 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20211207T172333/Courier0015.lzma 2021-12-07T17:40:50.825Z,1638898850.825 [DataOverHttps](INFO): Moved sent file to Logs/20211207T172333/Courier0015.lzma.bak 2021-12-07T17:40:50.825Z,1638898850.825 [DataOverHttps](INFO): SBD MOMSN=16335087 2021-12-07T17:41:00.235Z,1638898860.235 [NAL9602](INFO): SBD MO Status=0, MOMSN=17845, MT Status=0, MTMSN=0 2021-12-07T17:41:00.235Z,1638898860.235 [NAL9602](INFO): No messages in MT queue 2021-12-07T17:41:10.594Z,1638898870.594 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211207T172333/Courier0018.lzma 2021-12-07T17:41:11.597Z,1638898871.597 [DataOverHttps](INFO): Moved sent file to Logs/20211207T172333/Courier0018.lzma.bak 2021-12-07T17:41:11.597Z,1638898871.597 [DataOverHttps](INFO): SBD MOMSN=16335089 2021-12-07T17:41:30.950Z,1638898890.950 [NAL9602](INFO): Not Powering down - fast GPS 2021-12-07T17:41:31.388Z,1638898891.388 [DataOverHttps](INFO): Sending 179 bytes from file Logs/20211207T172333/Express0016.lzma 2021-12-07T17:41:32.389Z,1638898892.389 [DataOverHttps](INFO): Moved sent file to Logs/20211207T172333/Express0016.lzma.bak 2021-12-07T17:41:32.389Z,1638898892.389 [DataOverHttps](INFO): SBD MOMSN=16335093 2021-12-07T17:41:52.399Z,1638898912.399 [DataOverHttps](INFO): Sending 277 bytes from file Logs/20211207T172333/Express0019.lzma 2021-12-07T17:41:53.401Z,1638898913.401 [DataOverHttps](INFO): Moved sent file to Logs/20211207T172333/Express0019.lzma.bak 2021-12-07T17:41:53.401Z,1638898913.401 [DataOverHttps](INFO): SBD MOMSN=16335097 2021-12-07T17:41:54.445Z,1638898914.445 [ballast_and_trim:NeedComms:D] Stopped 2021-12-07T17:41:54.446Z,1638898914.446 [ballast_and_trim:NeedComms:E] Running Loop=1 2021-12-07T17:41:54.859Z,1638898914.859 [ballast_and_trim:NeedComms:E](DEBUG): Initialize ReadDataComponent to sense time_fix 2021-12-07T17:41:56.404Z,1638898916.404 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174155.00,A,3637.89154,N,12154.58267,W,0.253,357.97,071221,,,A*7E 2021-12-07T17:41:56.407Z,1638898916.407 [NAL9602](INFO): GPS fix at 20211207T174155: (36.631526, -121.909711) 2021-12-07T17:41:56.512Z,1638898916.512 [ballast_and_trim:NeedComms:E] Stopped 2021-12-07T17:41:56.514Z,1638898916.514 [ballast_and_trim:NeedComms](INFO): Completed ballast_and_trim:NeedComms 2021-12-07T17:41:56.514Z,1638898916.514 [ballast_and_trim:NeedComms] Stopped 2021-12-07T17:41:56.514Z,1638898916.514 [ballast_and_trim:NeedComms](DEBUG): Aggregate::uninitialize ballast_and_trim:NeedComms 2021-12-07T17:41:56.514Z,1638898916.514 [ballast_and_trim:NeedComms:B.GoToSurface] Stopped 2021-12-07T17:41:56.523Z,1638898916.523 [ballast_and_trim:NeedComms:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2021-12-07T17:41:56.889Z,1638898916.889 [ballast_and_trim:StartingMission:StartingMission](INFO): Completed ballast_and_trim:StartingMission:StartingMission 2021-12-07T17:41:56.889Z,1638898916.889 [ballast_and_trim:StartingMission:StartingMission] Stopped 2021-12-07T17:41:56.889Z,1638898916.889 [ballast_and_trim:StartingMission:StartingMission](DEBUG): Aggregate::uninitialize ballast_and_trim:StartingMission:StartingMission 2021-12-07T17:41:56.889Z,1638898916.889 [ballast_and_trim:StartingMission](INFO): Completed ballast_and_trim:StartingMission 2021-12-07T17:41:56.889Z,1638898916.889 [ballast_and_trim:StartingMission] Stopped 2021-12-07T17:41:56.890Z,1638898916.890 [ballast_and_trim:StartingMission](DEBUG): Aggregate::uninitialize ballast_and_trim:StartingMission 2021-12-07T17:41:56.890Z,1638898916.890 [ballast_and_trim:RunBallastAndTrim] Running Loop=1 2021-12-07T17:41:56.890Z,1638898916.890 [ballast_and_trim:RunBallastAndTrim](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim 2021-12-07T17:41:56.890Z,1638898916.890 [ballast_and_trim:RunBallastAndTrim:RunDepth1] Running Loop=1 2021-12-07T17:41:56.890Z,1638898916.890 [ballast_and_trim:RunBallastAndTrim:RunDepth1](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:RunDepth1 2021-12-07T17:41:56.890Z,1638898916.890 [ballast_and_trim:RunBallastAndTrim:RunDepth1:A] Running Loop=1 2021-12-07T17:41:57.224Z,1638898917.224 [ballast_and_trim:RunBallastAndTrim:RunDepth1:A] Stopped 2021-12-07T17:41:57.224Z,1638898917.224 [ballast_and_trim:RunBallastAndTrim:RunDepth1:B] Running Loop=1 2021-12-07T17:41:57.224Z,1638898917.224 [ballast_and_trim:RunBallastAndTrim:RunDepth1:B](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:RunDepth1:B 2021-12-07T17:41:57.710Z,1638898917.710 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim] Running Loop=1 2021-12-07T17:41:57.710Z,1638898917.710 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim 2021-12-07T17:41:57.710Z,1638898917.710 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:A] Running Loop=1 2021-12-07T17:41:57.734Z,1638898917.734 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:B] Running Loop=1 2021-12-07T17:41:57.735Z,1638898917.735 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:C] Running Loop=1 2021-12-07T17:41:57.735Z,1638898917.735 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:D] Running Loop=1 2021-12-07T17:41:57.735Z,1638898917.735 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:E] Running Loop=1 2021-12-07T17:41:57.735Z,1638898917.735 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:F] Running Loop=1 2021-12-07T17:41:57.738Z,1638898917.738 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:F](INFO): Going to target depth. Speed set to 0.000000 m/s 2021-12-07T17:41:57.738Z,1638898917.738 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:F] Stopped 2021-12-07T17:41:57.747Z,1638898917.747 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth] Running Loop=1 2021-12-07T17:41:57.747Z,1638898917.747 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth 2021-12-07T17:41:57.747Z,1638898917.747 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:A] Running Loop=1 2021-12-07T17:41:57.748Z,1638898917.748 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold] Running Loop=1 2021-12-07T17:41:57.748Z,1638898917.748 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold 2021-12-07T17:41:57.748Z,1638898917.748 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:A.Point] Running Loop=1 2021-12-07T17:41:57.748Z,1638898917.748 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:A.Point](DEBUG): Initialize. 2021-12-07T17:41:57.749Z,1638898917.749 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy] Running Loop=1 2021-12-07T17:41:57.749Z,1638898917.749 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy](DEBUG): Initialize Buoyancy Component. 2021-12-07T17:41:57.749Z,1638898917.749 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:C.Pitch] Running Loop=1 2021-12-07T17:41:57.749Z,1638898917.749 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:C.Pitch](DEBUG): Initialize. 2021-12-07T17:41:57.750Z,1638898917.750 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive] Running Loop=1 2021-12-07T17:41:57.750Z,1638898917.750 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive 2021-12-07T17:41:57.759Z,1638898917.759 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:A] Running Loop=1 2021-12-07T17:41:57.759Z,1638898917.759 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:E] Running Loop=1 2021-12-07T17:41:57.760Z,1638898917.760 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:D] Running Loop=1 2021-12-07T17:41:57.760Z,1638898917.760 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:C] Running Loop=1 2021-12-07T17:41:57.760Z,1638898917.760 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:B] Running Loop=1 2021-12-07T17:41:57.760Z,1638898917.760 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:A] Running Loop=1 2021-12-07T17:41:58.084Z,1638898918.084 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive] Stopped 2021-12-07T17:41:58.084Z,1638898918.084 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive 2021-12-07T17:41:58.084Z,1638898918.084 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:A] Stopped 2021-12-07T17:41:58.084Z,1638898918.084 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth] Running Loop=1 2021-12-07T17:41:58.085Z,1638898918.085 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth 2021-12-07T17:41:58.085Z,1638898918.085 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed] Running Loop=1 2021-12-07T17:41:58.085Z,1638898918.085 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed](DEBUG): Initialize. 2021-12-07T17:41:58.086Z,1638898918.086 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:A] Running Loop=1 2021-12-07T17:41:58.086Z,1638898918.086 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold] Stopped 2021-12-07T17:41:58.086Z,1638898918.086 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold 2021-12-07T17:41:58.095Z,1638898918.095 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:A.Point] Stopped 2021-12-07T17:41:58.096Z,1638898918.096 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy] Stopped 2021-12-07T17:41:58.096Z,1638898918.096 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy](DEBUG): Uninitialize Buoyancy Component. 2021-12-07T17:41:58.096Z,1638898918.096 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:C.Pitch] Stopped 2021-12-07T17:41:58.096Z,1638898918.096 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:A] Running Loop=1 2021-12-07T17:41:58.458Z,1638898918.458 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed] Running Loop=1 2021-12-07T17:41:58.463Z,1638898918.463 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:A](INFO): Moving to 9.000000 m 2021-12-07T17:41:58.463Z,1638898918.463 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:A] Stopped 2021-12-07T17:41:58.464Z,1638898918.464 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:C.Pitch] Running Loop=1 2021-12-07T17:41:58.464Z,1638898918.464 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:C.Pitch](DEBUG): Initialize. 2021-12-07T17:42:09.712Z,1638898929.712 [NAL9602](INFO): SBD MO Status=0, MOMSN=17846, MT Status=0, MTMSN=0 2021-12-07T17:42:09.713Z,1638898929.713 [NAL9602](INFO): No messages in MT queue 2021-12-07T17:42:12.902Z,1638898932.902 [WetLabsUBAT](ERROR): Failed to parse incomplete device message. 2021-12-07T17:42:40.273Z,1638898960.273 [NAL9602](INFO): Not Powering down - fast GPS 2021-12-07T17:43:16.826Z,1638898996.826 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude 2021-12-07T17:43:41.280Z,1638899021.280 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.387405 2021-12-07T17:44:18.103Z,1638899058.103 [Radio_Surface](INFO): Powering down 2021-12-07T17:44:25.460Z,1638899065.460 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:C.Pitch] Stopped 2021-12-07T17:44:25.461Z,1638899065.461 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth](INFO): Completed ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth 2021-12-07T17:44:25.461Z,1638899065.461 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth] Stopped 2021-12-07T17:44:25.461Z,1638899065.461 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth 2021-12-07T17:44:25.461Z,1638899065.461 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed] Stopped 2021-12-07T17:44:25.461Z,1638899065.461 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed](DEBUG): Uninitialize. 2021-12-07T17:44:25.462Z,1638899065.462 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth](INFO): Completed ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth 2021-12-07T17:44:25.462Z,1638899065.462 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth] Stopped 2021-12-07T17:44:25.462Z,1638899065.462 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth 2021-12-07T17:44:25.462Z,1638899065.462 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:A] Stopped 2021-12-07T17:44:25.462Z,1638899065.462 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth] Running Loop=1 2021-12-07T17:44:25.462Z,1638899065.462 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth 2021-12-07T17:44:25.462Z,1638899065.462 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed] Running Loop=1 2021-12-07T17:44:25.462Z,1638899065.462 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed](DEBUG): Initialize. 2021-12-07T17:44:25.467Z,1638899065.467 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:B.Pitch] Running Loop=1 2021-12-07T17:44:25.467Z,1638899065.467 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:B.Pitch](DEBUG): Initialize. 2021-12-07T17:44:25.468Z,1638899065.468 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:C] Running Loop=1 2021-12-07T17:44:25.893Z,1638899065.893 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:C](INFO): Waiting for the vehicle to settle. Depth = 9.062878 m 2021-12-07T17:44:25.893Z,1638899065.893 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:C] Stopped 2021-12-07T17:44:25.893Z,1638899065.893 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait] Running Loop=1 2021-12-07T17:44:25.893Z,1638899065.893 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait](DEBUG): Initialize Wait Component. 2021-12-07T17:44:25.893Z,1638899065.893 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:B.Pitch] Running Loop=1 2021-12-07T17:44:25.893Z,1638899065.893 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed] Running Loop=1 2021-12-07T17:44:43.366Z,1638899083.366 [RDI_Pathfinder](ERROR): only read 3 of 4 data items 2021-12-07T17:44:46.563Z,1638899086.563 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-12-07T17:44:47.567Z,1638899087.567 [DataOverHttps](INFO): Radio surface powered OFF, will not connect. 2021-12-07T17:44:49.495Z,1638899089.495 [WetLabsUBAT](ERROR): Failed to parse incomplete device message. 2021-12-07T17:45:41.997Z,1638899141.997 [RDI_Pathfinder](ERROR): only read 1 of 4 data items 2021-12-07T17:46:34.231Z,1638899194.231 [WetLabsUBAT](ERROR): Failed to parse incomplete device message. 2021-12-07T17:46:53.253Z,1638899213.253 [CTD_Seabird](ERROR): Failed to parse device response: 06,3922.12 2021-12-07T17:48:21.063Z,1638899301.063 [WetLabsUBAT](ERROR): Failed to parse incomplete device message. 2021-12-07T17:51:42.533Z,1638899502.533 [RDI_Pathfinder](ERROR): only read 2 of 4 data items 2021-12-07T17:54:26.534Z,1638899666.534 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait](INFO): Done Waiting. 2021-12-07T17:54:26.534Z,1638899666.534 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait] Stopped 2021-12-07T17:54:26.534Z,1638899666.534 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait](DEBUG): Uninitialize Wait Component. 2021-12-07T17:54:26.535Z,1638899666.535 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:E] Running Loop=1 2021-12-07T17:54:26.966Z,1638899666.966 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:E](INFO): Running ballast and trim. Depth = 11.696355 m 2021-12-07T17:54:26.966Z,1638899666.966 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:E] Stopped 2021-12-07T17:54:26.966Z,1638899666.966 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.] Running Loop=1 2021-12-07T17:54:26.966Z,1638899666.966 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](INFO): Initializing BallastAndTrim. 2021-12-07T17:55:14.632Z,1638899714.632 [RDI_Pathfinder](ERROR): only read -1 of 1 data item for altitude 2021-12-07T17:55:17.479Z,1638899717.479 [RDI_Pathfinder](ERROR): only read 3 of 4 data items 2021-12-07T17:55:56.382Z,1638899756.382 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2021-12-07T17:56:43.567Z,1638899803.567 [WetLabsUBAT](ERROR): Failed to parse incomplete device message. 2021-12-07T17:59:24.393Z,1638899964.393 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2021-12-07T18:01:11.043Z,1638900071.043 [WetLabsUBAT](ERROR): Failed to parse incomplete device message. 2021-12-07T18:02:22.046Z,1638900142.046 [RDI_Pathfinder](ERROR): only read 3 of 4 data items 2021-12-07T18:05:53.022Z,1638900353.022 [RDI_Pathfinder](ERROR): DVL uart error: serial timeout 2021-12-07T18:05:53.022Z,1638900353.022 [RDI_Pathfinder] Communications Fault, FailCount= 1 2021-12-07T18:05:53.022Z,1638900353.022 [RDI_Pathfinder](ERROR): Communications Fault 2021-12-07T18:05:53.263Z,1638900353.263 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder 2021-12-07T18:05:53.391Z,1638900353.391 [RDI_Pathfinder](INFO): Powering down 2021-12-07T18:05:54.319Z,1638900354.319 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder 2021-12-07T18:05:54.319Z,1638900354.319 [RDI_Pathfinder] No Fault, FailCount= 1 2021-12-07T18:07:15.155Z,1638900435.155 [WetLabsUBAT](ERROR): Failed to parse incomplete device message. 2021-12-07T18:08:24.673Z,1638900504.673 [CTD_Seabird](ERROR): Failed to parse device response: 9718.97 2021-12-07T18:08:48.138Z,1638900528.138 [RDI_Pathfinder](ERROR): only read 2 of 4 data items 2021-12-07T18:09:34.821Z,1638900574.821 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude 2021-12-07T18:10:03.513Z,1638900603.513 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2021-12-07T18:10:33.844Z,1638900633.844 [ballast_and_trim](INFO): Timed out from 2021-12-07T17:40:33.6Z 2021-12-07T18:10:33.844Z,1638900633.844 [MissionManager](INFO): ballast_and_trim is completed. 2021-12-07T18:10:33.844Z,1638900633.844 [MissionManager](INFO): Uninitializing Mission ballast_and_trim 2021-12-07T18:10:33.844Z,1638900633.844 [ballast_and_trim] Stopped 2021-12-07T18:10:33.844Z,1638900633.844 [ballast_and_trim](DEBUG): Aggregate::uninitialize ballast_and_trim 2021-12-07T18:10:33.845Z,1638900633.845 [ballast_and_trim:Science] Stopped 2021-12-07T18:10:33.845Z,1638900633.845 [ballast_and_trim:Science](DEBUG): Aggregate::uninitialize ballast_and_trim:Science 2021-12-07T18:10:33.845Z,1638900633.845 [ballast_and_trim:Science:B] Stopped 2021-12-07T18:10:33.845Z,1638900633.845 [ballast_and_trim:Science:C] Stopped 2021-12-07T18:10:33.845Z,1638900633.845 [ballast_and_trim:Science:E] Stopped 2021-12-07T18:10:33.845Z,1638900633.845 [ballast_and_trim:Science:F] Stopped 2021-12-07T18:10:33.845Z,1638900633.845 [ballast_and_trim:Science:OceanCurrent] Stopped 2021-12-07T18:10:33.845Z,1638900633.845 [ballast_and_trim:Science:OceanCurrent](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:OceanCurrent 2021-12-07T18:10:33.845Z,1638900633.845 [ballast_and_trim:Science:OceanCurrent:A.] Stopped 2021-12-07T18:10:33.845Z,1638900633.845 [ballast_and_trim:StandardEnvelopes] Stopped 2021-12-07T18:10:33.845Z,1638900633.845 [ballast_and_trim:StandardEnvelopes](DEBUG): Aggregate::uninitialize ballast_and_trim:StandardEnvelopes 2021-12-07T18:10:33.845Z,1638900633.845 [ballast_and_trim:StandardEnvelopes:A.AltitudeEnvelope] Stopped 2021-12-07T18:10:33.846Z,1638900633.846 [ballast_and_trim:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent. 2021-12-07T18:10:33.846Z,1638900633.846 [ballast_and_trim:StandardEnvelopes:B.DepthEnvelope] Stopped 2021-12-07T18:10:33.846Z,1638900633.846 [ballast_and_trim:StandardEnvelopes:B.DepthEnvelope](DEBUG): Uninitialize. 2021-12-07T18:10:33.846Z,1638900633.846 [ballast_and_trim:StandardEnvelopes:C.OffshoreEnvelope] Stopped 2021-12-07T18:10:33.846Z,1638900633.846 [ballast_and_trim:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Uninitialize OffshoreEnvelopeComponent. 2021-12-07T18:10:33.846Z,1638900633.846 [ballast_and_trim:RunBallastAndTrim] Stopped 2021-12-07T18:10:33.846Z,1638900633.846 [ballast_and_trim:RunBallastAndTrim](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim 2021-12-07T18:10:33.846Z,1638900633.846 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim] Stopped 2021-12-07T18:10:33.867Z,1638900633.867 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim 2021-12-07T18:10:33.867Z,1638900633.867 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:A] Stopped 2021-12-07T18:10:33.867Z,1638900633.867 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:B] Stopped 2021-12-07T18:10:33.867Z,1638900633.867 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:C] Stopped 2021-12-07T18:10:33.867Z,1638900633.867 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:D] Stopped 2021-12-07T18:10:33.867Z,1638900633.867 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:E] Stopped 2021-12-07T18:10:33.867Z,1638900633.867 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth] Stopped 2021-12-07T18:10:33.868Z,1638900633.868 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth 2021-12-07T18:10:33.868Z,1638900633.868 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed] Stopped 2021-12-07T18:10:33.868Z,1638900633.868 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed](DEBUG): Uninitialize. 2021-12-07T18:10:33.868Z,1638900633.868 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:B.Pitch] Stopped 2021-12-07T18:10:33.868Z,1638900633.868 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.] Stopped 2021-12-07T18:10:33.869Z,1638900633.869 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](FAULT): BallastAndTrim aborted prematurely - reporting best estimate. Estimation time: 16.11 minutes. 2021-12-07T18:10:33.875Z,1638900633.875 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): Estimated buoyancyNeutral: 246.642609 +/- 58.895451 cc (conf. level 99.90%, sigma: 88.734376 cc). 2021-12-07T18:10:33.876Z,1638900633.876 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): Estimated massDefault: 5.761125 +/- 2.412933 mm (conf. level 99.90%, sigma: 3.635427 mm). 2021-12-07T18:10:33.876Z,1638900633.876 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](INFO): Uninitializing BallastAndTrim. 2021-12-07T18:10:33.876Z,1638900633.876 [ballast_and_trim:RunBallastAndTrim:RunDepth1] Stopped 2021-12-07T18:10:33.876Z,1638900633.876 [ballast_and_trim:RunBallastAndTrim:RunDepth1](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:RunDepth1 2021-12-07T18:10:33.876Z,1638900633.876 [ballast_and_trim:RunBallastAndTrim:RunDepth1:B] Stopped 2021-12-07T18:10:33.876Z,1638900633.876 [ballast_and_trim:RunBallastAndTrim:RunDepth1:B](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:RunDepth1:B 2021-12-07T18:10:33.960Z,1638900633.960 [WetLabsUBAT](INFO): Powering down 2021-12-07T18:10:33.964Z,1638900633.964 [WetLabsBB2FL](INFO): Powering down 2021-12-07T18:10:34.255Z,1638900634.255 [MissionManager](IMPORTANT): Started mission Default 2021-12-07T18:10:34.256Z,1638900634.256 [Default] Running Loop=1 2021-12-07T18:10:34.256Z,1638900634.256 [Default](DEBUG): Aggregate::initialize Default 2021-12-07T18:10:34.256Z,1638900634.256 [Default:B.GoToSurface] Running Loop=1 2021-12-07T18:10:34.256Z,1638900634.256 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2021-12-07T18:10:34.256Z,1638900634.256 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2021-12-07T18:10:34.257Z,1638900634.257 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2021-12-07T18:10:34.257Z,1638900634.257 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2021-12-07T18:10:34.257Z,1638900634.257 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2021-12-07T18:10:34.258Z,1638900634.258 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2021-12-07T18:10:34.258Z,1638900634.258 [Default:A.Wait] Running Loop=1 2021-12-07T18:10:34.258Z,1638900634.258 [Default:A.Wait](DEBUG): Initialize Wait Component. 2021-12-07T18:10:34.649Z,1638900634.649 [ElevatorOffsetCalculator](INFO): New estimator for commanded vars: speed 1.00 m/s, pitch 30.00 deg, mass-position -20.00 mm (1 active estimators). 2021-12-07T18:10:34.723Z,1638900634.723 [Radio_Surface](INFO): Powering up 2021-12-07T18:10:40.023Z,1638900640.023 [DataOverHttps](INFO): Radio surface powered ON. 2021-12-07T18:10:47.545Z,1638900647.545 [Default:A.Wait](INFO): Done Waiting. 2021-12-07T18:10:47.545Z,1638900647.545 [Default:A.Wait] Stopped 2021-12-07T18:10:47.545Z,1638900647.545 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2021-12-07T18:11:10.143Z,1638900670.143 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-12-07T18:11:27.573Z,1638900687.573 [Default:CheckIn] Running Loop=1 2021-12-07T18:11:27.573Z,1638900687.573 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-07T18:11:27.573Z,1638900687.573 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-07T18:11:38.444Z,1638900698.444 [NAL9602](INFO): SBD MO Status=0, MOMSN=17847, MT Status=0, MTMSN=0 2021-12-07T18:11:38.444Z,1638900698.444 [NAL9602](INFO): No messages in MT queue 2021-12-07T18:11:39.651Z,1638900699.651 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181138.00,A,3637.95880,N,12154.47165,W,0.428,281.94,071221,,,A*7E 2021-12-07T18:11:39.653Z,1638900699.653 [NAL9602](INFO): GPS fix at 20211207T181138: (36.632647, -121.907861) 2021-12-07T18:11:39.686Z,1638900699.686 [Default:CheckIn:Read_GPS] Stopped 2021-12-07T18:11:39.686Z,1638900699.686 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-07T18:11:45.296Z,1638900705.296 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-12-07T18:11:56.366Z,1638900716.366 [NAL9602](INFO): SBD MO Status=1, MOMSN=17848, MT Status=0, MTMSN=0 2021-12-07T18:11:56.419Z,1638900716.419 [NAL9602](INFO): Sent 72 bytes from file Logs/20211207T172333/Courier0021.lzma 2021-12-07T18:11:56.420Z,1638900716.420 [NAL9602](INFO): Packets left to send: 0 2021-12-07T18:12:06.225Z,1638900726.225 [NAL9602](INFO): SBD MO Status=1, MOMSN=17849, MT Status=0, MTMSN=0 2021-12-07T18:12:06.275Z,1638900726.275 [NAL9602](INFO): Sent 332 bytes from file Logs/20211207T172333/Express0022.lzma 2021-12-07T18:12:06.275Z,1638900726.275 [NAL9602](INFO): Packets left to send: 3 2021-12-07T18:12:15.277Z,1638900735.277 [NAL9602](INFO): SBD MO Status=1, MOMSN=17850, MT Status=0, MTMSN=0 2021-12-07T18:12:15.332Z,1638900735.332 [NAL9602](INFO): Sent 332 bytes from file Logs/20211207T172333/Express0022.lzma 2021-12-07T18:12:15.332Z,1638900735.332 [NAL9602](INFO): Packets left to send: 2 2021-12-07T18:12:20.435Z,1638900740.435 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-12-07T18:12:28.326Z,1638900748.326 [NAL9602](INFO): SBD MO Status=1, MOMSN=17851, MT Status=0, MTMSN=0 2021-12-07T18:12:28.391Z,1638900748.391 [NAL9602](INFO): Sent 332 bytes from file Logs/20211207T172333/Express0022.lzma 2021-12-07T18:12:28.391Z,1638900748.391 [NAL9602](INFO): Packets left to send: 1 2021-12-07T18:12:37.742Z,1638900757.742 [NAL9602](INFO): SBD MO Status=1, MOMSN=17852, MT Status=0, MTMSN=0 2021-12-07T18:12:37.795Z,1638900757.795 [NAL9602](INFO): Sent 114 bytes from file Logs/20211207T172333/Express0022.lzma 2021-12-07T18:12:37.795Z,1638900757.795 [NAL9602](INFO): Packets left to send: 0 2021-12-07T18:12:47.842Z,1638900767.842 [NAL9602](INFO): SBD MO Status=0, MOMSN=17853, MT Status=0, MTMSN=0 2021-12-07T18:12:47.947Z,1638900767.947 [Default:CheckIn:Read_Iridium] Stopped 2021-12-07T18:12:47.947Z,1638900767.947 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-07T18:12:47.947Z,1638900767.947 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-07T18:12:55.583Z,1638900775.583 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-12-07T18:13:18.544Z,1638900798.544 [NAL9602](INFO): Not Powering down - fast GPS 2021-12-07T18:13:30.743Z,1638900810.743 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-12-07T18:14:03.663Z,1638900843.663 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003227 2021-12-07T18:15:30.576Z,1638900930.576 [DataOverHttps](IMPORTANT): SBD MTMSN=20211207T181529 2021-12-07T18:15:38.330Z,1638900938.330 [DataOverHttps](INFO): Received command: Maintain clear 2021-12-07T18:15:38.333Z,1638900938.333 [CommandExec](IMPORTANT): got command maintain clear 2021-12-07T18:15:38.568Z,1638900938.568 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,Power24vConverter,RDI_Pathfinder,DAT,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter, 2021-12-07T18:17:48.557Z,1638901068.557 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-07T18:17:48.557Z,1638901068.557 [Default:CheckIn:C.Wait] Stopped 2021-12-07T18:17:48.557Z,1638901068.557 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-07T18:17:48.557Z,1638901068.557 [Default:CheckIn:D] Running Loop=1 2021-12-07T18:17:48.908Z,1638901068.908 [Default:CheckIn:D] Stopped 2021-12-07T18:17:48.909Z,1638901068.909 [Default:CheckIn:E] Running Loop=1 2021-12-07T18:17:49.321Z,1638901069.321 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 7.244210 min 2021-12-07T18:17:49.321Z,1638901069.321 [Default:CheckIn:E] Stopped 2021-12-07T18:17:49.321Z,1638901069.321 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-07T18:17:49.321Z,1638901069.321 [Default:CheckIn] Stopped 2021-12-07T18:17:49.321Z,1638901069.321 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-07T18:17:49.322Z,1638901069.322 [Default:CheckIn](INFO): Running loop #2 2021-12-07T18:17:49.322Z,1638901069.322 [Default:CheckIn] Running Loop=2 2021-12-07T18:17:49.322Z,1638901069.322 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-07T18:17:49.322Z,1638901069.322 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-07T18:17:51.318Z,1638901071.318 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181750.00,A,3637.98283,N,12154.47870,W,0.486,314.69,071221,,,A*74 2021-12-07T18:17:51.320Z,1638901071.320 [NAL9602](INFO): GPS fix at 20211207T181750: (36.633047, -121.907978) 2021-12-07T18:17:51.376Z,1638901071.376 [Default:CheckIn:Read_GPS] Stopped 2021-12-07T18:17:51.376Z,1638901071.376 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-07T18:17:58.962Z,1638901078.962 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211207T172333/Courier0024.lzma 2021-12-07T18:17:59.964Z,1638901079.964 [DataOverHttps](INFO): Moved sent file to Logs/20211207T172333/Courier0024.lzma.bak 2021-12-07T18:17:59.965Z,1638901079.965 [DataOverHttps](INFO): SBD MOMSN=16335154 2021-12-07T18:18:09.109Z,1638901089.109 [NAL9602](IMPORTANT): SBD MO Status=0, MOMSN=17854, MT Status=1, MTMSN=965 2021-12-07T18:18:09.109Z,1638901089.109 [NAL9602](INFO): Data available in MT queue 2021-12-07T18:18:09.587Z,1638901089.587 [NAL9602](INFO): Received command: Maintain clear 2021-12-07T18:18:09.633Z,1638901089.633 [CommandExec](IMPORTANT): got command maintain clear 2021-12-07T18:18:18.357Z,1638901098.357 [DataOverHttps](INFO): Sending 192 bytes from file Logs/20211207T172333/Express0025.lzma 2021-12-07T18:18:19.357Z,1638901099.357 [DataOverHttps](INFO): Moved sent file to Logs/20211207T172333/Express0025.lzma.bak 2021-12-07T18:18:19.357Z,1638901099.357 [DataOverHttps](INFO): SBD MOMSN=16335157 2021-12-07T18:18:37.502Z,1638901117.502 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20211207T172333/Express0028.lzma 2021-12-07T18:18:38.504Z,1638901118.504 [DataOverHttps](INFO): Moved sent file to Logs/20211207T172333/Express0028.lzma.bak 2021-12-07T18:18:38.505Z,1638901118.505 [DataOverHttps](INFO): SBD MOMSN=16335163 2021-12-07T18:18:39.868Z,1638901119.868 [Default:CheckIn:Read_Iridium] Stopped 2021-12-07T18:18:39.869Z,1638901119.869 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-07T18:18:39.869Z,1638901119.869 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-07T18:18:40.260Z,1638901120.260 [NAL9602](INFO): Not Powering down - fast GPS 2021-12-07T18:23:40.508Z,1638901420.508 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-07T18:23:40.508Z,1638901420.508 [Default:CheckIn:C.Wait] Stopped 2021-12-07T18:23:40.508Z,1638901420.508 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-07T18:23:40.508Z,1638901420.508 [Default:CheckIn:D] Running Loop=1 2021-12-07T18:23:40.900Z,1638901420.900 [Default:CheckIn:D] Stopped 2021-12-07T18:23:40.901Z,1638901420.901 [Default:CheckIn:E] Running Loop=1 2021-12-07T18:23:41.291Z,1638901421.291 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 13.110744 min 2021-12-07T18:23:41.292Z,1638901421.292 [Default:CheckIn:E] Stopped 2021-12-07T18:23:41.292Z,1638901421.292 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-07T18:23:41.292Z,1638901421.292 [Default:CheckIn] Stopped 2021-12-07T18:23:41.292Z,1638901421.292 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-07T18:23:41.292Z,1638901421.292 [Default:CheckIn](INFO): Running loop #3 2021-12-07T18:23:41.292Z,1638901421.292 [Default:CheckIn] Running Loop=3 2021-12-07T18:23:41.292Z,1638901421.292 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-07T18:23:41.292Z,1638901421.292 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-07T18:23:43.310Z,1638901423.310 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182342.00,A,3637.99385,N,12154.51319,W,0.117,300.08,071221,,,A*7A 2021-12-07T18:23:43.312Z,1638901423.312 [NAL9602](INFO): GPS fix at 20211207T182342: (36.633231, -121.908553) 2021-12-07T18:23:43.325Z,1638901423.325 [Default:CheckIn:Read_GPS] Stopped 2021-12-07T18:23:43.325Z,1638901423.325 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-07T18:23:51.198Z,1638901431.198 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211207T172333/Courier0030.lzma 2021-12-07T18:23:52.201Z,1638901432.201 [DataOverHttps](INFO): Moved sent file to Logs/20211207T172333/Courier0030.lzma.bak 2021-12-07T18:23:52.201Z,1638901432.201 [DataOverHttps](INFO): SBD MOMSN=16335167 2021-12-07T18:23:59.875Z,1638901439.875 [NAL9602](INFO): SBD MO Status=0, MOMSN=17855, MT Status=0, MTMSN=0 2021-12-07T18:23:59.875Z,1638901439.875 [NAL9602](INFO): No messages in MT queue 2021-12-07T18:24:08.747Z,1638901448.747 [DataOverHttps](INFO): Sending 229 bytes from file Logs/20211207T172333/Express0031.lzma 2021-12-07T18:24:09.749Z,1638901449.749 [DataOverHttps](INFO): Moved sent file to Logs/20211207T172333/Express0031.lzma.bak 2021-12-07T18:24:09.749Z,1638901449.749 [DataOverHttps](INFO): SBD MOMSN=16335171 2021-12-07T18:24:10.829Z,1638901450.829 [Default:CheckIn:Read_Iridium] Stopped 2021-12-07T18:24:10.829Z,1638901450.829 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-07T18:24:10.829Z,1638901450.829 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-07T18:24:30.632Z,1638901470.632 [NAL9602](INFO): Not Powering down - fast GPS 2021-12-07T18:29:11.416Z,1638901751.416 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-07T18:29:11.416Z,1638901751.416 [Default:CheckIn:C.Wait] Stopped 2021-12-07T18:29:11.416Z,1638901751.416 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-07T18:29:11.417Z,1638901751.417 [Default:CheckIn:D] Running Loop=1 2021-12-07T18:29:11.829Z,1638901751.829 [Default:CheckIn:D] Stopped 2021-12-07T18:29:11.829Z,1638901751.829 [Default:CheckIn:E] Running Loop=1 2021-12-07T18:29:12.237Z,1638901752.237 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 18.626213 min 2021-12-07T18:29:12.237Z,1638901752.237 [Default:CheckIn:E] Stopped 2021-12-07T18:29:12.238Z,1638901752.238 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-07T18:29:12.238Z,1638901752.238 [Default:CheckIn] Stopped 2021-12-07T18:29:12.238Z,1638901752.238 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-07T18:29:12.238Z,1638901752.238 [Default:CheckIn](INFO): Running loop #4 2021-12-07T18:29:12.238Z,1638901752.238 [Default:CheckIn] Running Loop=4 2021-12-07T18:29:12.238Z,1638901752.238 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-07T18:29:12.239Z,1638901752.239 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-07T18:29:14.234Z,1638901754.234 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182913.00,A,3638.00080,N,12154.54853,W,0.233,316.46,071221,,,D*70 2021-12-07T18:29:14.237Z,1638901754.237 [NAL9602](INFO): GPS fix at 20211207T182913: (36.633347, -121.909142) 2021-12-07T18:29:14.273Z,1638901754.273 [Default:CheckIn:Read_GPS] Stopped 2021-12-07T18:29:14.273Z,1638901754.273 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-07T18:29:21.763Z,1638901761.763 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20211207T172333/Courier0033.lzma 2021-12-07T18:29:22.784Z,1638901762.784 [DataOverHttps](INFO): Moved sent file to Logs/20211207T172333/Courier0033.lzma.bak 2021-12-07T18:29:22.785Z,1638901762.785 [DataOverHttps](INFO): SBD MOMSN=16335179 2021-12-07T18:29:25.142Z,1638901765.142 [NAL9602](INFO): SBD MO Status=0, MOMSN=17856, MT Status=0, MTMSN=0 2021-12-07T18:29:25.142Z,1638901765.142 [NAL9602](INFO): No messages in MT queue 2021-12-07T18:29:39.079Z,1638901779.079 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20211207T172333/Express0034.lzma 2021-12-07T18:29:40.080Z,1638901780.080 [DataOverHttps](INFO): Moved sent file to Logs/20211207T172333/Express0034.lzma.bak 2021-12-07T18:29:40.081Z,1638901780.081 [DataOverHttps](INFO): SBD MOMSN=16335182 2021-12-07T18:29:41.315Z,1638901781.315 [Default:CheckIn:Read_Iridium] Stopped 2021-12-07T18:29:41.316Z,1638901781.316 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-07T18:29:41.316Z,1638901781.316 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-07T18:29:55.844Z,1638901795.844 [NAL9602](INFO): Not Powering down - fast GPS 2021-12-07T18:33:09.803Z,1638901989.803 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-12-07T18:33:11.811Z,1638901991.811 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.247364 2021-12-07T18:34:20.859Z,1638902060.859 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-12-07T18:34:41.924Z,1638902081.924 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-12-07T18:34:41.924Z,1638902081.924 [Default:CheckIn:C.Wait] Stopped 2021-12-07T18:34:41.924Z,1638902081.924 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-12-07T18:34:41.924Z,1638902081.924 [Default:CheckIn:D] Running Loop=1 2021-12-07T18:34:42.339Z,1638902082.339 [Default:CheckIn:D] Stopped 2021-12-07T18:34:42.339Z,1638902082.339 [Default:CheckIn:E] Running Loop=1 2021-12-07T18:34:42.720Z,1638902082.720 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 24.134711 min 2021-12-07T18:34:42.720Z,1638902082.720 [Default:CheckIn:E] Stopped 2021-12-07T18:34:42.720Z,1638902082.720 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-12-07T18:34:42.720Z,1638902082.720 [Default:CheckIn] Stopped 2021-12-07T18:34:42.720Z,1638902082.720 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-12-07T18:34:42.720Z,1638902082.720 [Default:CheckIn](INFO): Running loop #5 2021-12-07T18:34:42.721Z,1638902082.721 [Default:CheckIn] Running Loop=5 2021-12-07T18:34:42.721Z,1638902082.721 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-12-07T18:34:42.721Z,1638902082.721 [Default:CheckIn:Read_GPS] Running Loop=1 2021-12-07T18:34:44.727Z,1638902084.727 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183443.00,A,3637.96459,N,12154.63898,W,5.618,137.44,071221,,,D*71 2021-12-07T18:34:44.730Z,1638902084.730 [NAL9602](INFO): GPS fix at 20211207T183443: (36.632743, -121.910650) 2021-12-07T18:34:44.743Z,1638902084.743 [Default:CheckIn:Read_GPS] Stopped 2021-12-07T18:34:44.743Z,1638902084.743 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-12-07T18:34:55.999Z,1638902095.999 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-12-07T18:35:08.638Z,1638902108.638 [NAL9602](INFO): SBD MO Status=1, MOMSN=17857, MT Status=0, MTMSN=0 2021-12-07T18:35:08.691Z,1638902108.691 [NAL9602](INFO): Sent 72 bytes from file Logs/20211207T172333/Courier0036.lzma 2021-12-07T18:35:08.691Z,1638902108.691 [NAL9602](INFO): Packets left to send: 0 2021-12-07T18:35:26.539Z,1638902126.539 [NAL9602](INFO): SBD MO Status=1, MOMSN=17858, MT Status=0, MTMSN=0 2021-12-07T18:35:26.592Z,1638902126.592 [NAL9602](INFO): Sent 129 bytes from file Logs/20211207T172333/Express0037.lzma 2021-12-07T18:35:26.592Z,1638902126.592 [NAL9602](INFO): Packets left to send: 0 2021-12-07T18:35:31.139Z,1638902131.139 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-12-07T18:35:43.163Z,1638902143.163 [NAL9602](INFO): SBD MO Status=0, MOMSN=17859, MT Status=0, MTMSN=0 2021-12-07T18:35:43.252Z,1638902143.252 [Default:CheckIn:Read_Iridium] Stopped 2021-12-07T18:35:43.253Z,1638902143.253 [Default:CheckIn:C.Wait] Running Loop=1 2021-12-07T18:35:43.253Z,1638902143.253 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-12-07T18:35:52.880Z,1638902152.880 [DataOverHttps](IMPORTANT): SBD MTMSN=20211207T183551 2021-12-07T18:35:52.884Z,1638902152.884 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003608