2022-04-18T19:32:03.481Z,1650310323.481 [NAL9602](INFO): Received command: restart logs
2022-04-18T19:32:03.484Z,1650310323.484 [CommandExec](IMPORTANT): got command restart logs
2022-04-18T19:32:15.592Z,1650310335.592 [NAL9602](IMPORTANT): SBD MO Status=1, MOMSN=36061, MT Status=1, MTMSN=1405
2022-04-18T19:32:15.647Z,1650310335.647 [NAL9602](INFO): Sent 52 bytes from file Logs/20220418T191511/Courier0013.lzma
2022-04-18T19:32:15.647Z,1650310335.647 [NAL9602](INFO): Packets left to send: 0
2022-04-18T19:32:16.237Z,1650310336.237 [NAL9602](INFO): Received command: load Maintenance/ballast_and_trim.xml;set ballast_and_trim.Depth1 6 m;set ballast_and_trim.MinAltitude 4 m;set ballast_and_trim.MaxDepth 9 m;run
2022-04-18T19:32:16.280Z,1650310336.280 [CommandExec](IMPORTANT): got command load ./Missions/Maintenance/ballast_and_trim.xml
2022-04-18T19:32:16.280Z,1650310336.280 [MissionManager](INFO): Loading Mission from file: ./Missions/Maintenance/ballast_and_trim.xml
2022-04-18T19:32:16.484Z,1650310336.484 [MissionManager](INFO): DefineArg ballast_and_trim.MissionTimeout = 90.000000 min
2022-04-18T19:32:16.487Z,1650310336.487 [MissionManager](INFO): DefineArg ballast_and_trim.SkipComms = 0 bool
2022-04-18T19:32:16.491Z,1650310336.491 [MissionManager](INFO): DefineArg ballast_and_trim.Depth1 = 35.000000 m
2022-04-18T19:32:16.501Z,1650310336.501 [MissionManager](INFO): DefineArg ballast_and_trim.Depth2 = nan m
2022-04-18T19:32:16.504Z,1650310336.504 [MissionManager](INFO): DefineArg ballast_and_trim.DepthDeadband = 0.100000 m
2022-04-18T19:32:16.511Z,1650310336.511 [MissionManager](INFO): DefineArg ballast_and_trim.ApproachSpeed = 1.000000 m/s
2022-04-18T19:32:16.516Z,1650310336.516 [MissionManager](INFO): DefineArg ballast_and_trim.ApproachDepthTimeout = 20.000000 min
2022-04-18T19:32:16.528Z,1650310336.528 [MissionManager](INFO): DefineArg ballast_and_trim.ApproachDepthRate = 0.400000 m/s
2022-04-18T19:32:16.531Z,1650310336.531 [MissionManager](INFO): DefineArg ballast_and_trim.ApproachPitchLimit = 20.000000 arcdeg
2022-04-18T19:32:16.536Z,1650310336.536 [MissionManager](INFO): DefineArg ballast_and_trim.ApproachSettleTimePreDive = 0.000000 min
2022-04-18T19:32:16.547Z,1650310336.547 [MissionManager](INFO): DefineArg ballast_and_trim.SettleTime = 10.000000 min
2022-04-18T19:32:16.565Z,1650310336.565 [MissionManager](INFO): DefineArg ballast_and_trim.EstimationTimeout = 45.000000 min
2022-04-18T19:32:16.568Z,1650310336.568 [MissionManager](INFO): DefineArg ballast_and_trim.MinEstimationTime = 10.000000 min
2022-04-18T19:32:16.575Z,1650310336.575 [MissionManager](INFO): DefineArg ballast_and_trim.MassEstimationErrorBound = 0.250000 mm
2022-04-18T19:32:16.578Z,1650310336.578 [MissionManager](INFO): DefineArg ballast_and_trim.BuoyEstimationErrorBound = 15.000000 cc
2022-04-18T19:32:16.593Z,1650310336.593 [MissionManager](INFO): DefineArg ballast_and_trim.EstimationConfidence = 99.900002 %
2022-04-18T19:32:16.596Z,1650310336.596 [MissionManager](INFO): DefineArg ballast_and_trim.massDeadband = 0.250000 mm
2022-04-18T19:32:16.603Z,1650310336.603 [MissionManager](INFO): DefineArg ballast_and_trim.MinAltitude = 5.000000 m
2022-04-18T19:32:16.607Z,1650310336.607 [MissionManager](INFO): DefineArg ballast_and_trim.MaxDepth = 52.000000 m
2022-04-18T19:32:16.621Z,1650310336.621 [MissionManager](INFO): DefineArg ballast_and_trim.MinOffshore = 2.000000 km
2022-04-18T19:32:16.629Z,1650310336.629 [MissionManager](INFO): DefineArg ballast_and_trim.CheckDepths = 1.000000 bool
2022-04-18T19:32:16.629Z,1650310336.629 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/Science.xml
2022-04-18T19:32:17.146Z,1650310337.146 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDetectChlActive = 0 bool
2022-04-18T19:32:17.149Z,1650310337.149 [MissionManager](INFO): DefineArg ballast_and_trim:Science.TimeWindowPeakReport = nan min
2022-04-18T19:32:17.152Z,1650310337.152 [MissionManager](INFO): DefineArg ballast_and_trim:Science.HighestChlPeakReportActive = 0 bool
2022-04-18T19:32:17.154Z,1650310337.154 [MissionManager](INFO): DefineArg ballast_and_trim:Science.HighestSaltPeakReportActive = 0 bool
2022-04-18T19:32:17.158Z,1650310337.158 [MissionManager](INFO): DefineArg ballast_and_trim:Science.HighestOilPeakReportActive = 0 bool
2022-04-18T19:32:17.160Z,1650310337.160 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PatchTracking = 0 bool
2022-04-18T19:32:17.163Z,1650310337.163 [MissionManager](INFO): DefineArg ballast_and_trim:Science.DetectTrough = 0 bool
2022-04-18T19:32:17.166Z,1650310337.166 [MissionManager](INFO): DefineArg ballast_and_trim:Science.FilterWidthHorizontal = 3.000000 count
2022-04-18T19:32:17.170Z,1650310337.170 [MissionManager](INFO): DefineArg ballast_and_trim:Science.NumProfilesSlidingwindow = 100.000000 count
2022-04-18T19:32:17.173Z,1650310337.173 [MissionManager](INFO): DefineArg ballast_and_trim:Science.OffPeakFractionHorizontal = 80.000000 %
2022-04-18T19:32:17.175Z,1650310337.175 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDetectNO3Active = 0 bool
2022-04-18T19:32:17.178Z,1650310337.178 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDetectOilActive = 0 bool
2022-04-18T19:32:17.181Z,1650310337.181 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDetectFDOMActive = 0 bool
2022-04-18T19:32:17.183Z,1650310337.183 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDetectSalinityActive = 0 bool
2022-04-18T19:32:17.186Z,1650310337.186 [MissionManager](INFO): DefineArg ballast_and_trim:Science.UpwardDerivativeOfTemperatureActive = 0 bool
2022-04-18T19:32:17.242Z,1650310337.242 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledAanderaaO2 = 0 bool
2022-04-18T19:32:17.250Z,1650310337.250 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledNeilBrown = 0 bool
2022-04-18T19:32:17.254Z,1650310337.254 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledSeabird = 1 bool
2022-04-18T19:32:17.281Z,1650310337.281 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledWetLabsBB2FL = 0 bool
2022-04-18T19:32:17.297Z,1650310337.297 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledWetLabsSeaOWL_UV_A = 1 bool
2022-04-18T19:32:17.300Z,1650310337.300 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledWetLabsUBAT = 0 bool
2022-04-18T19:32:17.317Z,1650310337.317 [MissionManager](INFO): DefineArg ballast_and_trim:Science.LowPassWindowLength = 20.000000 count
2022-04-18T19:32:17.333Z,1650310337.333 [MissionManager](INFO): DefineArg ballast_and_trim:Science.MedianFilterLen = 5.000000 count
2022-04-18T19:32:17.336Z,1650310337.336 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakShallowBound = nan m
2022-04-18T19:32:17.348Z,1650310337.348 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDeepBound = nan m
2022-04-18T19:32:17.351Z,1650310337.351 [MissionManager](INFO): DefineArg ballast_and_trim:Science.DepChangeThreshForAttitudeFlip = 2.000000 m
2022-04-18T19:32:17.355Z,1650310337.355 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChl = 0.000000 ug/l
2022-04-18T19:32:17.366Z,1650310337.366 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChlDepth = 0.000000 m
2022-04-18T19:32:17.371Z,1650310337.371 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChlTemperature = 0.000000 degC
2022-04-18T19:32:17.382Z,1650310337.382 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChlLatitude = nan arcdeg
2022-04-18T19:32:17.386Z,1650310337.386 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChlLongitude = nan arcdeg
2022-04-18T19:32:17.401Z,1650310337.401 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakNO3 = 0.000000 umol/l
2022-04-18T19:32:17.409Z,1650310337.409 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakNO3Depth = 0.000000 m
2022-04-18T19:32:17.412Z,1650310337.412 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakNO3Latitude = nan arcdeg
2022-04-18T19:32:17.425Z,1650310337.425 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakNO3Longitude = nan arcdeg
2022-04-18T19:32:17.428Z,1650310337.428 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakOil = 0.000000 kg/m3
2022-04-18T19:32:17.435Z,1650310337.435 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakOilDepth = 0.000000 m
2022-04-18T19:32:17.450Z,1650310337.450 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakOilLatitude = nan arcdeg
2022-04-18T19:32:17.457Z,1650310337.457 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakOilLongitude = nan arcdeg
2022-04-18T19:32:17.460Z,1650310337.460 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakFDOM = 0.000000 ppb
2022-04-18T19:32:17.467Z,1650310337.467 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakFDOMDepth = 0.000000 m
2022-04-18T19:32:17.471Z,1650310337.471 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakFDOMTemperature = nan degC
2022-04-18T19:32:17.482Z,1650310337.482 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakFDOMLatitude = nan arcdeg
2022-04-18T19:32:17.490Z,1650310337.490 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakFDOMLongitude = nan arcdeg
2022-04-18T19:32:17.497Z,1650310337.497 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchFDOMDistance = nan m
2022-04-18T19:32:17.500Z,1650310337.500 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakSalt = 0.000000 psu
2022-04-18T19:32:17.507Z,1650310337.507 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakSaltDepth = 0.000000 m
2022-04-18T19:32:17.511Z,1650310337.511 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakSaltTemperature = 0.000000 degC
2022-04-18T19:32:17.526Z,1650310337.526 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakSaltLatitude = nan arcdeg
2022-04-18T19:32:17.541Z,1650310337.541 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakSaltLongitude = nan arcdeg
2022-04-18T19:32:17.548Z,1650310337.548 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChl = 0.000000 ug/l
2022-04-18T19:32:17.551Z,1650310337.551 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChlDepth = 0.000000 m
2022-04-18T19:32:17.558Z,1650310337.558 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChlLatitude = nan arcdeg
2022-04-18T19:32:17.563Z,1650310337.563 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChlLongitude = nan arcdeg
2022-04-18T19:32:17.567Z,1650310337.567 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChlDistance = nan m
2022-04-18T19:32:17.570Z,1650310337.570 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchSalt = 0.000000 psu
2022-04-18T19:32:17.585Z,1650310337.585 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchSaltDepth = 0.000000 m
2022-04-18T19:32:17.588Z,1650310337.588 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchSaltLatitude = nan arcdeg
2022-04-18T19:32:17.628Z,1650310337.628 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchSaltLongitude = nan arcdeg
2022-04-18T19:32:17.639Z,1650310337.639 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchSaltDistance = nan m
2022-04-18T19:32:17.654Z,1650310337.654 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchOil = 0.000000 psu
2022-04-18T19:32:17.662Z,1650310337.662 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchOilDepth = 0.000000 m
2022-04-18T19:32:17.673Z,1650310337.673 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchOilLatitude = nan arcdeg
2022-04-18T19:32:17.676Z,1650310337.676 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchOilLongitude = nan arcdeg
2022-04-18T19:32:17.686Z,1650310337.686 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchOilDistance = nan m
2022-04-18T19:32:17.748Z,1650310337.748 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2022-04-18T19:32:17.781Z,1650310337.781 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal](DEBUG): Construct PeakDetectHorizontal.
2022-04-18T19:32:17.803Z,1650310337.803 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2022-04-18T19:32:17.834Z,1650310337.834 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2022-04-18T19:32:17.861Z,1650310337.861 [ballast_and_trim:Science:HighestOilPeakReport:A.PeakDetectHorizontal](DEBUG): Construct PeakDetectHorizontal.
2022-04-18T19:32:17.898Z,1650310337.898 [ballast_and_trim:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2022-04-18T19:32:17.929Z,1650310337.929 [ballast_and_trim:Science:PeakDetectSalinity:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2022-04-18T19:32:17.954Z,1650310337.954 [ballast_and_trim:Science:HighestSaltPeakReport:A.PeakDetectHorizontal](DEBUG): Construct PeakDetectHorizontal.
2022-04-18T19:32:18.040Z,1650310338.040 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/NeedComms.xml
2022-04-18T19:32:18.135Z,1650310338.135 [MissionManager](INFO): DefineArg ballast_and_trim:NeedComms.DiveInterval = 3.000000 h
2022-04-18T19:32:18.146Z,1650310338.146 [MissionManager](INFO): DefineArg ballast_and_trim:NeedComms.WaitForPitchUp = 10.000000 min
2022-04-18T19:32:18.157Z,1650310338.157 [MissionManager](INFO): DefineArg ballast_and_trim:NeedComms.SurfacePitch = 20.000000 arcdeg
2022-04-18T19:32:18.160Z,1650310338.160 [MissionManager](INFO): DefineArg ballast_and_trim:NeedComms.SurfaceDepthRate = nan m/s
2022-04-18T19:32:18.167Z,1650310338.167 [MissionManager](INFO): DefineArg ballast_and_trim:NeedComms.SurfaceSpeed = 1.000000 m/s
2022-04-18T19:32:18.171Z,1650310338.171 [MissionManager](INFO): DefineArg ballast_and_trim:NeedComms.GPSTimeout = 7.000000 min
2022-04-18T19:32:18.186Z,1650310338.186 [MissionManager](INFO): DefineArg ballast_and_trim:NeedComms.CommsTimeout = 30.000000 min
2022-04-18T19:32:18.201Z,1650310338.201 [ballast_and_trim:NeedComms:B.GoToSurface](DEBUG): Construct GoToSurface.
2022-04-18T19:32:18.232Z,1650310338.232 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/StandardEnvelopes.xml
2022-04-18T19:32:18.266Z,1650310338.266 [MissionManager](INFO): DefineArg ballast_and_trim:StandardEnvelopes.MinAltitude = 5.000000 m
2022-04-18T19:32:18.281Z,1650310338.281 [MissionManager](INFO): DefineArg ballast_and_trim:StandardEnvelopes.MaxDepth = 200.000000 m
2022-04-18T19:32:18.284Z,1650310338.284 [MissionManager](INFO): DefineArg ballast_and_trim:StandardEnvelopes.MinOffshore = 2000.000000 m
2022-04-18T19:32:18.290Z,1650310338.290 [ballast_and_trim:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope.
2022-04-18T19:32:18.306Z,1650310338.306 [ballast_and_trim:StandardEnvelopes:B.DepthEnvelope](DEBUG): Construct DepthEnvelope.
2022-04-18T19:32:18.334Z,1650310338.334 [ballast_and_trim:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Construct OffshoreEnvelope.
2022-04-18T19:32:18.371Z,1650310338.371 [ballast_and_trim:CheckTargetDepths:CheckDepth1:B.Execute](DEBUG): Construct Execute.
2022-04-18T19:32:18.385Z,1650310338.385 [ballast_and_trim:CheckTargetDepths:CheckDepth2:B.Execute](DEBUG): Construct Execute.
2022-04-18T19:32:18.438Z,1650310338.438 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/BallastAndTrim.xml
2022-04-18T19:32:18.654Z,1650310338.654 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertDepth = 25.000000 m
2022-04-18T19:32:18.661Z,1650310338.661 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachSpeed = 0.000000 m/s
2022-04-18T19:32:18.664Z,1650310338.664 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachDepthRate = 0.400000 m/s
2022-04-18T19:32:18.671Z,1650310338.671 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachPitchLimit = 20.000000 arcdeg
2022-04-18T19:32:18.675Z,1650310338.675 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachSettleTimePreDive = 0.000000 min
2022-04-18T19:32:18.686Z,1650310338.686 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachDepthTimeout = 20.000000 min
2022-04-18T19:32:18.690Z,1650310338.690 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertSettleTime = 10.000000 min
2022-04-18T19:32:18.701Z,1650310338.701 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.EstTimeout = 45.000000 min
2022-04-18T19:32:18.704Z,1650310338.704 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.MinEstTime = 10.000000 min
2022-04-18T19:32:18.711Z,1650310338.711 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.MassEstErrorBound = 0.250000 mm
2022-04-18T19:32:18.716Z,1650310338.716 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.BuoyEstErrorBound = 15.000000 cc
2022-04-18T19:32:18.731Z,1650310338.731 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.EstConfidence = 99.900002 %
2022-04-18T19:32:18.748Z,1650310338.748 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertDepthDeadband = 1.000000 m
2022-04-18T19:32:18.772Z,1650310338.772 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertMassDeadband = 0.250000 mm
2022-04-18T19:32:18.863Z,1650310338.863 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:A.Point](DEBUG): Construct.
2022-04-18T19:32:18.882Z,1650310338.882 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy](DEBUG): Construct Buoyancy.
2022-04-18T19:32:18.902Z,1650310338.902 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:C.Pitch](DEBUG): Construct.
2022-04-18T19:32:18.924Z,1650310338.924 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:B.Wait](DEBUG): Construct Wait.
2022-04-18T19:32:18.931Z,1650310338.931 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed](DEBUG): Construct.
2022-04-18T19:32:18.936Z,1650310338.936 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:C.Pitch](DEBUG): Construct.
2022-04-18T19:32:18.965Z,1650310338.965 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:C.Pitch:A_Timeout:B.Execute](DEBUG): Construct Execute.
2022-04-18T19:32:18.968Z,1650310338.968 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed](DEBUG): Construct.
2022-04-18T19:32:18.972Z,1650310338.972 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:B.Pitch](DEBUG): Construct.
2022-04-18T19:32:18.992Z,1650310338.992 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait](DEBUG): Construct Wait.
2022-04-18T19:32:19.003Z,1650310339.003 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](DEBUG): Construct BallastAndTrim.
2022-04-18T19:32:19.040Z,1650310339.040 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertDepthDeadband = reader:ballast_and_trim.DepthDeadband
2022-04-18T19:32:19.046Z,1650310339.046 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachSpeed = reader:ballast_and_trim.ApproachSpeed
2022-04-18T19:32:19.047Z,1650310339.047 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachDepthRate = reader:ballast_and_trim.ApproachDepthRate
2022-04-18T19:32:19.050Z,1650310339.050 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachPitchLimit = reader:ballast_and_trim.ApproachPitchLimit
2022-04-18T19:32:19.052Z,1650310339.052 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachSettleTimePreDive = reader:ballast_and_trim.ApproachSettleTimePreDive
2022-04-18T19:32:19.062Z,1650310339.062 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachDepthTimeout = reader:ballast_and_trim.ApproachDepthTimeout
2022-04-18T19:32:19.064Z,1650310339.064 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertSettleTime = reader:ballast_and_trim.SettleTime
2022-04-18T19:32:19.070Z,1650310339.070 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.EstTimeout = reader:ballast_and_trim.EstimationTimeout
2022-04-18T19:32:19.071Z,1650310339.071 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.MinEstTime = reader:ballast_and_trim.MinEstimationTime
2022-04-18T19:32:19.081Z,1650310339.081 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.MassEstErrorBound = reader:ballast_and_trim.MassEstimationErrorBound
2022-04-18T19:32:19.083Z,1650310339.083 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.BuoyEstErrorBound = reader:ballast_and_trim.BuoyEstimationErrorBound
2022-04-18T19:32:19.086Z,1650310339.086 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.EstConfidence = reader:ballast_and_trim.EstimationConfidence
2022-04-18T19:32:19.088Z,1650310339.088 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertMassDeadband = reader:ballast_and_trim.massDeadband
2022-04-18T19:32:19.185Z,1650310339.185 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Units="Tethys/Units"
       xmlns:Guidance="Tethys/Guidance"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd"
       Id="ballast_and_trim">

    <DefineArg Name="MissionTimeout"><Description>
        Maximum duration of mission
    </Description><Units:minute/><Value>90</Value></DefineArg>

    <DefineArg Name="SkipComms"><Description>
        Skip communications at start of mission.
    </Description><False/></DefineArg>

    <DefineArg Name="Depth1"><Units:meter/><Value>35</Value></DefineArg>

    <DefineArg Name="Depth2"><Units:meter/><Value>NaN</Value></DefineArg>

    <DefineArg Name="DepthDeadband"><Description>
        How much vertical drift from the specified depth is allowed durnig the
        mission.
    </Description><Units:meter/><Value>0.1</Value></DefineArg>

    <DefineArg Name="ApproachSpeed"><Description>
        Enables vehicle thruster at the commanded speed to reach target depth
        (set to 0 m/s to drift).
    </Description><Units:meter_per_second/><Value>1</Value></DefineArg>

    <DefineArg Name="ApproachDepthTimeout"><Description>
        Maximum wait time for the vehicle to reach the targeted depth.
    </Description><Units:minute/><Value>20</Value></DefineArg>

    <DefineArg Name="ApproachDepthRate"><Description>
        Descent depth rate (Positive depth rate means going down).
    </Description><Units:meter_per_second/><Value>0.4</Value></DefineArg>

    <DefineArg Name="ApproachPitchLimit"><Description>
        Max vehicle pitch (+/-) when decending from the surface.
    </Description><Units:degree/><Value>20</Value></DefineArg>

    <DefineArg Name="ApproachSettleTimePreDive"><Description>
        Time duration for the vehicle to pump down the VBS *BEFORE* leaving the
        surface.
    </Description><Units:minute/><Value>0</Value></DefineArg>

    <DefineArg Name="SettleTime"><Description>
        How long to wait after reaching target depth before starting ballast and
        trim.
    </Description><Units:minute/><Value>10</Value></DefineArg>

    <DefineArg Name="EstimationTimeout"><Description>
        Timeout for ballast and trim estimation.
    </Description><Units:minute/><Value>45</Value></DefineArg>

    <DefineArg Name="MinEstimationTime"><Description>
        Minimum time to run ballast and trim estimation before determining
        convergence (must be shorter than timeout).
    </Description><Units:minute/><Value>10</Value></DefineArg>

    <DefineArg Name="MassEstimationErrorBound"><Description>
        Desired range of the estimated sample mean from the true mean statistic
        (smaller values take longer to converge).
    </Description><Units:millimeter/><Value>0.25</Value></DefineArg>

    <DefineArg Name="BuoyEstimationErrorBound"><Description>
        Desired range of the estimated sample mean from the true mean statistic
        (smaller values take longer to converge).
    </Description><Units:cubic_centimeter/><Value>15</Value></DefineArg>

    <DefineArg Name="EstimationConfidence"><Description>
        Confidence level that the estimator has reached the desired error range
        (larger values take longer to converge).
    </Description><Units:percent/><Value>99.9</Value></DefineArg>

    <DefineArg Name="massDeadband"><Description>
        Degree of rounding in mass-shifter command output values.
    </Description><Units:millimeter/><Value>0.25</Value></DefineArg>

    <DefineArg Name="MinAltitude"><Units:meter/><Value>5</Value></DefineArg>

    <DefineArg Name="MaxDepth"><Units:meter/><Value>52</Value></DefineArg>

    <DefineArg Name="MinOffshore"><Units:kilometer/><Value>2</Value></DefineArg>

    <DefineArg Name="CheckDepths"><Units:bool/><Value>1</Value></DefineArg>

    <Timeout Duration="MissionTimeout"/>

    <Insert Filename="Insert/Science.xml"/>

    <Insert Filename="Insert/NeedComms.xml" Id="NeedComms"/>

    <Assign><Sequence/><Arg Name="NeedComms:DiveInterval"/><Arg Name="MissionTimeout"/></Assign>

    <Insert Filename="Insert/StandardEnvelopes.xml"/>

    <Assign><Sequence/><Arg Name="StandardEnvelopes:MinAltitude"/><Arg Name="MinAltitude"/></Assign>

    <Assign><Sequence/><Arg Name="StandardEnvelopes:MaxDepth"/><Arg Name="MaxDepth"/></Assign>

    <Assign><Sequence/><Arg Name="StandardEnvelopes:MinOffshore"/><Arg Name="MinOffshore"/></Assign>

    <Aggregate Id="CheckTargetDepths">

        <Sequence/>

        <Break>
            <Not><Arg Name="CheckDepths"/></Not>
        </Break>

        <Aggregate Id="CheckDepth1">

            <Sequence/>

            <Break>
                <Not><Arg Name="Depth1"/><Gt><Arg Name="MaxDepth"/></Gt></Not>
            </Break>

            <Syslog Severity="Important">Aborting ballast and trim mission. Target depth Depth1 exceeds the mission's MaxDepth setting (review mission parameters).</Syslog>

            <Guidance:Execute>
                <Sequence/>
                <Setting><Guidance:Execute.command/><String>stop</String></Setting>
            </Guidance:Execute>

        </Aggregate>

        <Aggregate Id="CheckDepth2">

            <Sequence/>

            <Break>
                <Not><Arg Name="Depth2"/><Gt><Arg Name="MaxDepth"/></Gt></Not>
            </Break>

            <Syslog Severity="Important">Aborting ballast and trim mission. Target depth Depth2 exceeds the mission's MaxDepth setting (review mission parameters).</Syslog>

            <Guidance:Execute>
                <Sequence/>
                <Setting><Guidance:Execute.command/><String>stop</String></Setting>
            </Guidance:Execute>

        </Aggregate>

        <Assign><Sequence/><Arg Name="CheckDepths"/><Units:bool/><Value>0</Value></Assign>

    </Aggregate>

    <Aggregate Id="StartingMission">

        <Sequence/>

        <Break><Arg Name="SkipComms"/>
        </Break>

<!-- DO NOT REMOVE the syslog entry below. The MissionManager seems to ignore the value of SkipComms, does not evaluate the Break statement properly, and always calls NeedComms. Adding the syslog call somehow fixes it. -->

        <Syslog Severity="Info">Checking for additional instructions before submerging.</Syslog>

        <Call Id="StartingMission" RefId="NeedComms"/>

    </Aggregate>

    <Aggregate Id="RunBallastAndTrim">

        <Sequence/>

        <Insert Filename="Insert/BallastAndTrim.xml">
            <RedefineArg Name="InsertDepthDeadband"><Arg Name="DepthDeadband"/></RedefineArg>
            <RedefineArg Name="InsertApproachSpeed"><Arg Name="ApproachSpeed"/></RedefineArg>
            <RedefineArg Name="InsertApproachDepthRate"><Arg Name="ApproachDepthRate"/></RedefineArg>
            <RedefineArg Name="InsertApproachPitchLimit"><Arg Name="ApproachPitchLimit"/></RedefineArg>
            <RedefineArg Name="InsertApproachSettleTimePreDive"><Arg Name="ApproachSettleTimePreDive"/></RedefineArg>
            <RedefineArg Name="InsertApproachDepthTimeout"><Arg Name="ApproachDepthTimeout"/></RedefineArg>
            <RedefineArg Name="InsertSettleTime"><Arg Name="SettleTime"/></RedefineArg>
            <RedefineArg Name="EstTimeout"><Arg Name="EstimationTimeout"/></RedefineArg>
            <RedefineArg Name="MinEstTime"><Arg Name="MinEstimationTime"/></RedefineArg>
            <RedefineArg Name="MassEstErrorBound"><Arg Name="MassEstimationErrorBound"/></RedefineArg>
            <RedefineArg Name="BuoyEstErrorBound"><Arg Name="BuoyEstimationErrorBound"/></RedefineArg>
            <RedefineArg Name="EstConfidence"><Arg Name="EstimationConfidence"/></RedefineArg>
            <RedefineArg Name="InsertMassDeadband"><Arg Name="massDeadband"/></RedefineArg>
        </Insert>

        <Aggregate Id="RunDepth1">

            <Sequence/>

            <Break>
                <IsNaN><Arg Name="Depth1"/>
                </IsNaN>
            </Break>

            <Assign><Sequence/><Arg Name="BallastAndTrim:InsertDepth"/><Arg Name="Depth1"/></Assign>

            <Call RefId="BallastAndTrim"/>

        </Aggregate>

        <Aggregate Id="RunDepth2">

            <Sequence/>

            <Break>
                <IsNaN><Arg Name="Depth2"/>
                </IsNaN>
            </Break>

            <Assign><Sequence/><Arg Name="BallastAndTrim:InsertDepth"/><Arg Name="Depth2"/></Assign>

            <Call RefId="BallastAndTrim"/>

        </Aggregate>

    </Aggregate>

    <Call Id="EndingMission" RefId="NeedComms"/>

</Mission>


2022-04-18T19:32:19.189Z,1650310339.189 [CommandExec](IMPORTANT): Loaded ./Missions/Maintenance/ballast_and_trim.xml
2022-04-18T19:32:26.431Z,1650310346.431 [CommandExec](IMPORTANT): got command set ballast_and_trim.Depth1 6 meter
2022-04-18T19:32:26.432Z,1650310346.432 [CommandExec](IMPORTANT): got command set ballast_and_trim.MinAltitude 4 meter
2022-04-18T19:32:26.432Z,1650310346.432 [CommandExec](IMPORTANT): got command set ballast_and_trim.MaxDepth 9 meter
2022-04-18T19:32:26.441Z,1650310346.441 [CommandExec](IMPORTANT): got command run
2022-04-18T19:32:26.448Z,1650310346.448 [CommandExec](IMPORTANT): Running 
2022-04-18T19:32:26.846Z,1650310346.846 [Default] Stopped
2022-04-18T19:32:26.846Z,1650310346.846 [Default](DEBUG): Aggregate::uninitialize Default
2022-04-18T19:32:26.846Z,1650310346.846 [Default:B.GoToSurface] Stopped
2022-04-18T19:32:26.846Z,1650310346.846 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2022-04-18T19:32:26.846Z,1650310346.846 [Default:CheckIn] Stopped
2022-04-18T19:32:26.846Z,1650310346.846 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-04-18T19:32:26.846Z,1650310346.846 [Default:CheckIn:Read_Iridium] Stopped
2022-04-18T19:32:26.846Z,1650310346.846 [MissionManager](IMPORTANT): Started mission ballast_and_trim
2022-04-18T19:32:26.847Z,1650310346.847 [ballast_and_trim] Running Loop=1
2022-04-18T19:32:26.847Z,1650310346.847 [ballast_and_trim](DEBUG): Aggregate::initialize ballast_and_trim
2022-04-18T19:32:26.847Z,1650310346.847 [ballast_and_trim:Science] Running Loop=1
2022-04-18T19:32:26.847Z,1650310346.847 [ballast_and_trim:Science](DEBUG): Aggregate::initialize ballast_and_trim:Science
2022-04-18T19:32:26.847Z,1650310346.847 [ballast_and_trim:Science:A] Running Loop=1
2022-04-18T19:32:26.847Z,1650310346.847 [ballast_and_trim:Science:B] Running Loop=1
2022-04-18T19:32:26.847Z,1650310346.847 [ballast_and_trim:Science:C] Running Loop=1
2022-04-18T19:32:26.847Z,1650310346.847 [ballast_and_trim:Science:D] Running Loop=1
2022-04-18T19:32:26.847Z,1650310346.847 [ballast_and_trim:Science:E] Running Loop=1
2022-04-18T19:32:26.847Z,1650310346.847 [ballast_and_trim:Science:F] Running Loop=1
2022-04-18T19:32:26.847Z,1650310346.847 [ballast_and_trim:Science:Read_Oil] Running Loop=1
2022-04-18T19:32:26.847Z,1650310346.847 [ballast_and_trim:Science:PeakDetectChl] Running Loop=1
2022-04-18T19:32:26.848Z,1650310346.848 [ballast_and_trim:Science:PeakDetectChl](DEBUG): Aggregate::initialize ballast_and_trim:Science:PeakDetectChl
2022-04-18T19:32:26.848Z,1650310346.848 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth] Running Loop=1
2022-04-18T19:32:26.848Z,1650310346.848 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Initialize.
2022-04-18T19:32:26.850Z,1650310346.850 [ballast_and_trim:Science:HighestChlPeakReport] Running Loop=1
2022-04-18T19:32:26.850Z,1650310346.850 [ballast_and_trim:Science:HighestChlPeakReport](DEBUG): Aggregate::initialize ballast_and_trim:Science:HighestChlPeakReport
2022-04-18T19:32:26.850Z,1650310346.850 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal] Running Loop=1
2022-04-18T19:32:26.850Z,1650310346.850 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal](INFO): Initialize.
2022-04-18T19:32:26.851Z,1650310346.851 [ballast_and_trim:Science:PeakDetectNO3] Running Loop=1
2022-04-18T19:32:26.851Z,1650310346.851 [ballast_and_trim:Science:PeakDetectNO3](DEBUG): Aggregate::initialize ballast_and_trim:Science:PeakDetectNO3
2022-04-18T19:32:26.851Z,1650310346.851 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth] Running Loop=1
2022-04-18T19:32:26.851Z,1650310346.851 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Initialize.
2022-04-18T19:32:26.853Z,1650310346.853 [ballast_and_trim:Science:PeakDetectOil] Running Loop=1
2022-04-18T19:32:26.853Z,1650310346.853 [ballast_and_trim:Science:PeakDetectOil](DEBUG): Aggregate::initialize ballast_and_trim:Science:PeakDetectOil
2022-04-18T19:32:26.854Z,1650310346.854 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth] Running Loop=1
2022-04-18T19:32:26.854Z,1650310346.854 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Initialize.
2022-04-18T19:32:26.855Z,1650310346.855 [ballast_and_trim:Science:HighestOilPeakReport] Running Loop=1
2022-04-18T19:32:26.856Z,1650310346.856 [ballast_and_trim:Science:HighestOilPeakReport](DEBUG): Aggregate::initialize ballast_and_trim:Science:HighestOilPeakReport
2022-04-18T19:32:26.856Z,1650310346.856 [ballast_and_trim:Science:HighestOilPeakReport:A.PeakDetectHorizontal] Running Loop=1
2022-04-18T19:32:26.856Z,1650310346.856 [ballast_and_trim:Science:HighestOilPeakReport:A.PeakDetectHorizontal](INFO): Initialize.
2022-04-18T19:32:26.856Z,1650310346.856 [ballast_and_trim:Science:PeakDetectFDOM] Running Loop=1
2022-04-18T19:32:26.856Z,1650310346.856 [ballast_and_trim:Science:PeakDetectFDOM](DEBUG): Aggregate::initialize ballast_and_trim:Science:PeakDetectFDOM
2022-04-18T19:32:26.857Z,1650310346.857 [ballast_and_trim:Science:PeakDetectFDOM:A.PeakDetectVsDepth] Running Loop=1
2022-04-18T19:32:26.857Z,1650310346.857 [ballast_and_trim:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Initialize.
2022-04-18T19:32:26.858Z,1650310346.858 [ballast_and_trim:Science:PeakDetectSalinity] Running Loop=1
2022-04-18T19:32:26.859Z,1650310346.859 [ballast_and_trim:Science:PeakDetectSalinity](DEBUG): Aggregate::initialize ballast_and_trim:Science:PeakDetectSalinity
2022-04-18T19:32:26.859Z,1650310346.859 [ballast_and_trim:Science:PeakDetectSalinity:A.PeakDetectVsDepth] Running Loop=1
2022-04-18T19:32:26.859Z,1650310346.859 [ballast_and_trim:Science:PeakDetectSalinity:A.PeakDetectVsDepth](DEBUG): Initialize.
2022-04-18T19:32:26.861Z,1650310346.861 [ballast_and_trim:Science:HighestSaltPeakReport] Running Loop=1
2022-04-18T19:32:26.861Z,1650310346.861 [ballast_and_trim:Science:HighestSaltPeakReport](DEBUG): Aggregate::initialize ballast_and_trim:Science:HighestSaltPeakReport
2022-04-18T19:32:26.861Z,1650310346.861 [ballast_and_trim:Science:HighestSaltPeakReport:A.PeakDetectHorizontal] Running Loop=1
2022-04-18T19:32:26.861Z,1650310346.861 [ballast_and_trim:Science:HighestSaltPeakReport:A.PeakDetectHorizontal](INFO): Initialize.
2022-04-18T19:32:26.861Z,1650310346.861 [ballast_and_trim:Science:OceanCurrent] Running Loop=1
2022-04-18T19:32:26.861Z,1650310346.861 [ballast_and_trim:Science:OceanCurrent](DEBUG): Aggregate::initialize ballast_and_trim:Science:OceanCurrent
2022-04-18T19:32:26.862Z,1650310346.862 [ballast_and_trim:Science:OceanCurrent:A.] Running Loop=1
2022-04-18T19:32:26.862Z,1650310346.862 [ballast_and_trim:Science:OceanCurrent:A.](INFO): Initializing CurrentEstimator.
2022-04-18T19:32:26.862Z,1650310346.862 [ballast_and_trim:StandardEnvelopes] Running Loop=1
2022-04-18T19:32:26.862Z,1650310346.862 [ballast_and_trim:StandardEnvelopes](DEBUG): Aggregate::initialize ballast_and_trim:StandardEnvelopes
2022-04-18T19:32:26.862Z,1650310346.862 [ballast_and_trim:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1
2022-04-18T19:32:26.862Z,1650310346.862 [ballast_and_trim:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent.
2022-04-18T19:32:26.862Z,1650310346.862 [ballast_and_trim:StandardEnvelopes:B.DepthEnvelope] Running Loop=1
2022-04-18T19:32:26.862Z,1650310346.862 [ballast_and_trim:StandardEnvelopes:B.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent.
2022-04-18T19:32:26.863Z,1650310346.863 [ballast_and_trim:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1
2022-04-18T19:32:26.863Z,1650310346.863 [ballast_and_trim:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Initialize OffshoreEnvelopeComponent.
2022-04-18T19:32:26.863Z,1650310346.863 [ballast_and_trim:C] Running Loop=1
2022-04-18T19:32:26.863Z,1650310346.863 [ballast_and_trim:StandardEnvelopes] Running Loop=1
2022-04-18T19:32:26.863Z,1650310346.863 [ballast_and_trim:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1
2022-04-18T19:32:26.864Z,1650310346.864 [ballast_and_trim:StandardEnvelopes:B.DepthEnvelope] Running Loop=1
2022-04-18T19:32:26.865Z,1650310346.865 [ballast_and_trim:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1
2022-04-18T19:32:26.866Z,1650310346.866 [ballast_and_trim:C] Stopped
2022-04-18T19:32:26.866Z,1650310346.866 [ballast_and_trim:E] Running Loop=1
2022-04-18T19:32:26.866Z,1650310346.866 [ballast_and_trim:Science] Running Loop=1
2022-04-18T19:32:26.867Z,1650310346.867 [ballast_and_trim:Science:HighestSaltPeakReport] Stopped
2022-04-18T19:32:26.867Z,1650310346.867 [ballast_and_trim:Science:HighestSaltPeakReport](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:HighestSaltPeakReport
2022-04-18T19:32:26.867Z,1650310346.867 [ballast_and_trim:Science:HighestSaltPeakReport:A.PeakDetectHorizontal] Stopped
2022-04-18T19:32:26.868Z,1650310346.868 [ballast_and_trim:Science:HighestSaltPeakReport:A.PeakDetectHorizontal](DEBUG): Uninitialize.
2022-04-18T19:32:26.868Z,1650310346.868 [ballast_and_trim:Science:PeakDetectSalinity] Stopped
2022-04-18T19:32:26.868Z,1650310346.868 [ballast_and_trim:Science:PeakDetectSalinity](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:PeakDetectSalinity
2022-04-18T19:32:26.868Z,1650310346.868 [ballast_and_trim:Science:PeakDetectSalinity:A.PeakDetectVsDepth] Stopped
2022-04-18T19:32:26.868Z,1650310346.868 [ballast_and_trim:Science:PeakDetectSalinity:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2022-04-18T19:32:26.868Z,1650310346.868 [ballast_and_trim:Science:PeakDetectFDOM] Stopped
2022-04-18T19:32:26.868Z,1650310346.868 [ballast_and_trim:Science:PeakDetectFDOM](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:PeakDetectFDOM
2022-04-18T19:32:26.868Z,1650310346.868 [ballast_and_trim:Science:PeakDetectFDOM:A.PeakDetectVsDepth] Stopped
2022-04-18T19:32:26.868Z,1650310346.868 [ballast_and_trim:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2022-04-18T19:32:26.868Z,1650310346.868 [ballast_and_trim:Science:HighestOilPeakReport] Stopped
2022-04-18T19:32:26.869Z,1650310346.869 [ballast_and_trim:Science:HighestOilPeakReport](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:HighestOilPeakReport
2022-04-18T19:32:26.869Z,1650310346.869 [ballast_and_trim:Science:HighestOilPeakReport:A.PeakDetectHorizontal] Stopped
2022-04-18T19:32:26.869Z,1650310346.869 [ballast_and_trim:Science:HighestOilPeakReport:A.PeakDetectHorizontal](DEBUG): Uninitialize.
2022-04-18T19:32:26.869Z,1650310346.869 [ballast_and_trim:Science:PeakDetectOil] Stopped
2022-04-18T19:32:26.869Z,1650310346.869 [ballast_and_trim:Science:PeakDetectOil](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:PeakDetectOil
2022-04-18T19:32:26.869Z,1650310346.869 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth] Stopped
2022-04-18T19:32:26.869Z,1650310346.869 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2022-04-18T19:32:26.869Z,1650310346.869 [ballast_and_trim:Science:PeakDetectNO3] Stopped
2022-04-18T19:32:26.869Z,1650310346.869 [ballast_and_trim:Science:PeakDetectNO3](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:PeakDetectNO3
2022-04-18T19:32:26.869Z,1650310346.869 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth] Stopped
2022-04-18T19:32:26.869Z,1650310346.869 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2022-04-18T19:32:26.869Z,1650310346.869 [ballast_and_trim:Science:HighestChlPeakReport] Stopped
2022-04-18T19:32:26.870Z,1650310346.870 [ballast_and_trim:Science:HighestChlPeakReport](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:HighestChlPeakReport
2022-04-18T19:32:26.870Z,1650310346.870 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal] Stopped
2022-04-18T19:32:26.870Z,1650310346.870 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal](DEBUG): Uninitialize.
2022-04-18T19:32:26.870Z,1650310346.870 [ballast_and_trim:Science:PeakDetectChl] Stopped
2022-04-18T19:32:26.870Z,1650310346.870 [ballast_and_trim:Science:PeakDetectChl](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:PeakDetectChl
2022-04-18T19:32:26.870Z,1650310346.870 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth] Stopped
2022-04-18T19:32:26.870Z,1650310346.870 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2022-04-18T19:32:26.870Z,1650310346.870 [ballast_and_trim:Science:OceanCurrent:A.] Running Loop=1
2022-04-18T19:32:26.872Z,1650310346.872 [ballast_and_trim:Science:Read_Oil] Running Loop=1
2022-04-18T19:32:26.889Z,1650310346.889 [ballast_and_trim:Science:Read_Oil](DEBUG): Initialize ReadDataComponent to sense mass_concentration_of_petroleum_hydrocarbons_in_sea_water
2022-04-18T19:32:26.889Z,1650310346.889 [ballast_and_trim:Science:F] Stopped
2022-04-18T19:32:26.889Z,1650310346.889 [ballast_and_trim:Science:E] Stopped
2022-04-18T19:32:26.889Z,1650310346.889 [ballast_and_trim:Science:D] Stopped
2022-04-18T19:32:26.889Z,1650310346.889 [ballast_and_trim:Science:C] Running Loop=1
2022-04-18T19:32:26.890Z,1650310346.890 [ballast_and_trim:Science:C](DEBUG): Initialize ReadDataComponent to sense CTD_Seabird.sea_water_temperature
2022-04-18T19:32:26.891Z,1650310346.891 [ballast_and_trim:Science:C](DEBUG): Initialize ReadDataComponent to sense CTD_Seabird.sea_water_salinity
2022-04-18T19:32:26.891Z,1650310346.891 [ballast_and_trim:Science:B] Running Loop=1
2022-04-18T19:32:26.892Z,1650310346.892 [ballast_and_trim:Science:B](DEBUG): Initialize ReadDataComponent to sense sea_water_temperature
2022-04-18T19:32:26.892Z,1650310346.892 [ballast_and_trim:Science:B](DEBUG): Initialize ReadDataComponent to sense sea_water_salinity
2022-04-18T19:32:26.897Z,1650310346.897 [ballast_and_trim:Science:A] Stopped
2022-04-18T19:32:27.208Z,1650310347.208 [ballast_and_trim:E] Stopped
2022-04-18T19:32:27.208Z,1650310347.208 [ballast_and_trim:F] Running Loop=1
2022-04-18T19:32:27.622Z,1650310347.622 [ballast_and_trim:F] Stopped
2022-04-18T19:32:27.622Z,1650310347.622 [ballast_and_trim:G] Running Loop=1
2022-04-18T19:32:28.016Z,1650310348.016 [ballast_and_trim:G] Stopped
2022-04-18T19:32:28.033Z,1650310348.033 [ballast_and_trim:CheckTargetDepths] Running Loop=1
2022-04-18T19:32:28.033Z,1650310348.033 [ballast_and_trim:CheckTargetDepths](DEBUG): Aggregate::initialize ballast_and_trim:CheckTargetDepths
2022-04-18T19:32:28.033Z,1650310348.033 [ballast_and_trim:CheckTargetDepths:CheckDepth1] Running Loop=1
2022-04-18T19:32:28.033Z,1650310348.033 [ballast_and_trim:CheckTargetDepths:CheckDepth1](DEBUG): Aggregate::initialize ballast_and_trim:CheckTargetDepths:CheckDepth1
2022-04-18T19:32:28.033Z,1650310348.033 [ballast_and_trim:CheckTargetDepths:CheckDepth1:A] Running Loop=1
2022-04-18T19:32:28.409Z,1650310348.409 [ballast_and_trim:CheckTargetDepths:CheckDepth1] Stopped
2022-04-18T19:32:28.409Z,1650310348.409 [ballast_and_trim:CheckTargetDepths:CheckDepth1](DEBUG): Aggregate::uninitialize ballast_and_trim:CheckTargetDepths:CheckDepth1
2022-04-18T19:32:28.409Z,1650310348.409 [ballast_and_trim:CheckTargetDepths:CheckDepth1:A] Stopped
2022-04-18T19:32:28.409Z,1650310348.409 [ballast_and_trim:CheckTargetDepths:CheckDepth2] Running Loop=1
2022-04-18T19:32:28.409Z,1650310348.409 [ballast_and_trim:CheckTargetDepths:CheckDepth2](DEBUG): Aggregate::initialize ballast_and_trim:CheckTargetDepths:CheckDepth2
2022-04-18T19:32:28.409Z,1650310348.409 [ballast_and_trim:CheckTargetDepths:CheckDepth2:A] Running Loop=1
2022-04-18T19:32:28.849Z,1650310348.849 [ballast_and_trim:CheckTargetDepths:CheckDepth2] Stopped
2022-04-18T19:32:28.849Z,1650310348.849 [ballast_and_trim:CheckTargetDepths:CheckDepth2](DEBUG): Aggregate::uninitialize ballast_and_trim:CheckTargetDepths:CheckDepth2
2022-04-18T19:32:28.849Z,1650310348.849 [ballast_and_trim:CheckTargetDepths:CheckDepth2:A] Stopped
2022-04-18T19:32:28.849Z,1650310348.849 [ballast_and_trim:CheckTargetDepths:C] Running Loop=1
2022-04-18T19:32:29.243Z,1650310349.243 [ballast_and_trim:CheckTargetDepths:C] Stopped
2022-04-18T19:32:29.243Z,1650310349.243 [ballast_and_trim:CheckTargetDepths](INFO): Completed ballast_and_trim:CheckTargetDepths
2022-04-18T19:32:29.243Z,1650310349.243 [ballast_and_trim:CheckTargetDepths] Stopped
2022-04-18T19:32:29.243Z,1650310349.243 [ballast_and_trim:CheckTargetDepths](DEBUG): Aggregate::uninitialize ballast_and_trim:CheckTargetDepths
2022-04-18T19:32:29.243Z,1650310349.243 [ballast_and_trim:StartingMission] Running Loop=1
2022-04-18T19:32:29.243Z,1650310349.243 [ballast_and_trim:StartingMission](DEBUG): Aggregate::initialize ballast_and_trim:StartingMission
2022-04-18T19:32:29.244Z,1650310349.244 [ballast_and_trim:StartingMission:A] Running Loop=1
2022-04-18T19:32:29.612Z,1650310349.612 [ballast_and_trim:StartingMission:A](INFO): Checking for additional instructions before submerging.
2022-04-18T19:32:29.612Z,1650310349.612 [ballast_and_trim:StartingMission:A] Stopped
2022-04-18T19:32:29.613Z,1650310349.613 [ballast_and_trim:StartingMission:StartingMission] Running Loop=1
2022-04-18T19:32:29.613Z,1650310349.613 [ballast_and_trim:StartingMission:StartingMission](DEBUG): Aggregate::initialize ballast_and_trim:StartingMission:StartingMission
2022-04-18T19:32:30.031Z,1650310350.031 [ballast_and_trim:NeedComms] Running Loop=1
2022-04-18T19:32:30.031Z,1650310350.031 [ballast_and_trim:NeedComms](DEBUG): Aggregate::initialize ballast_and_trim:NeedComms
2022-04-18T19:32:30.031Z,1650310350.031 [ballast_and_trim:NeedComms:B.GoToSurface] Running Loop=1
2022-04-18T19:32:30.031Z,1650310350.031 [ballast_and_trim:NeedComms:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2022-04-18T19:32:30.031Z,1650310350.031 [ballast_and_trim:NeedComms:B.GoToSurface](INFO): Received depth rate setting nan m/s.
2022-04-18T19:32:30.032Z,1650310350.032 [ballast_and_trim:NeedComms:B.GoToSurface](INFO): Received pitch setting 19.999999 degrees.
2022-04-18T19:32:30.032Z,1650310350.032 [ballast_and_trim:NeedComms:B.GoToSurface](INFO): Received speed setting 1.000000 m/s.
2022-04-18T19:32:30.033Z,1650310350.033 [ballast_and_trim:NeedComms:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2022-04-18T19:32:30.033Z,1650310350.033 [ballast_and_trim:NeedComms:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2022-04-18T19:32:30.033Z,1650310350.033 [ballast_and_trim:NeedComms:A] Running Loop=1
2022-04-18T19:32:30.034Z,1650310350.034 [ballast_and_trim:NeedComms:A](INFO): last time_fix was: 1650310307.000000 second since 1970/01/01T00:00:00Z 
2022-04-18T19:32:30.035Z,1650310350.035 [ballast_and_trim:NeedComms:A] Stopped
2022-04-18T19:32:30.441Z,1650310350.441 [ballast_and_trim:NeedComms:C] Running Loop=1
2022-04-18T19:32:30.482Z,1650310350.482 [CTD_Seabird](ERROR): Failed to parse device response: <!--startlogging-->
2022-04-18T19:32:30.871Z,1650310350.871 [ballast_and_trim:NeedComms:C](DEBUG): Initialize ReadDataComponent to sense time_fix
2022-04-18T19:32:31.613Z,1650310351.613 [NAL9602](INFO): SBD MO Status=1, MOMSN=36062, MT Status=0, MTMSN=0
2022-04-18T19:32:31.661Z,1650310351.661 [NAL9602](INFO): Sent 119 bytes from file Logs/20220418T191511/Express0011.lzma
2022-04-18T19:32:31.661Z,1650310351.661 [NAL9602](INFO): Packets left to send: 0
2022-04-18T19:32:32.829Z,1650310352.829 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,193234.00,A,4131.75357,N,07047.07564,W,0.525,237.27,180422,,,A*7E
2022-04-18T19:32:32.831Z,1650310352.831 [NAL9602](INFO): GPS fix at 20220418T193234: (41.529226, -70.784594)
2022-04-18T19:32:32.929Z,1650310352.929 [ballast_and_trim:NeedComms:C] Stopped
2022-04-18T19:32:32.929Z,1650310352.929 [ballast_and_trim:NeedComms:D] Running Loop=1
2022-04-18T19:32:33.278Z,1650310353.278 [ballast_and_trim:NeedComms:D](DEBUG): Initialize ReadDataComponent to sense platform_communications
2022-04-18T19:32:49.140Z,1650310369.140 [NAL9602](INFO): SBD MO Status=1, MOMSN=36063, MT Status=0, MTMSN=0
2022-04-18T19:32:49.201Z,1650310369.201 [NAL9602](INFO): Sent 169 bytes from file Logs/20220418T193203/Courier0000.lzma
2022-04-18T19:32:49.201Z,1650310369.201 [NAL9602](INFO): Packets left to send: 0
2022-04-18T19:32:57.745Z,1650310377.745 [NAL9602](INFO): SBD MO Status=1, MOMSN=36064, MT Status=0, MTMSN=0
2022-04-18T19:32:57.793Z,1650310377.793 [NAL9602](INFO): Sent 184 bytes from file Logs/20220418T193203/Courier0003.lzma
2022-04-18T19:32:57.793Z,1650310377.793 [NAL9602](INFO): Packets left to send: 1
2022-04-18T19:33:09.585Z,1650310389.585 [NAL9602](INFO): SBD MO Status=1, MOMSN=36065, MT Status=0, MTMSN=0
2022-04-18T19:33:09.641Z,1650310389.641 [NAL9602](INFO): Sent 41 bytes from file Logs/20220418T193203/Courier0003.lzma
2022-04-18T19:33:09.641Z,1650310389.641 [NAL9602](INFO): Packets left to send: 0
2022-04-18T19:33:16.960Z,1650310396.960 [NAL9602](INFO): SBD MO Status=1, MOMSN=36066, MT Status=0, MTMSN=0
2022-04-18T19:33:17.009Z,1650310397.009 [NAL9602](INFO): Sent 135 bytes from file Logs/20220418T191511/Express0014.lzma
2022-04-18T19:33:17.009Z,1650310397.009 [NAL9602](INFO): Packets left to send: 0
2022-04-18T19:33:28.006Z,1650310408.006 [NAL9602](INFO): SBD MO Status=1, MOMSN=36067, MT Status=0, MTMSN=0
2022-04-18T19:33:28.056Z,1650310408.056 [NAL9602](INFO): Sent 184 bytes from file Logs/20220418T193203/Express0001.lzma
2022-04-18T19:33:28.058Z,1650310408.058 [NAL9602](INFO): Packets left to send: 3
2022-04-18T19:33:41.860Z,1650310421.860 [NAL9602](INFO): SBD MO Status=1, MOMSN=36068, MT Status=0, MTMSN=0
2022-04-18T19:33:41.914Z,1650310421.914 [NAL9602](INFO): Sent 184 bytes from file Logs/20220418T193203/Express0001.lzma
2022-04-18T19:33:41.914Z,1650310421.914 [NAL9602](INFO): Packets left to send: 2
2022-04-18T19:33:53.349Z,1650310433.349 [NAL9602](INFO): SBD MO Status=1, MOMSN=36069, MT Status=0, MTMSN=0
2022-04-18T19:33:53.397Z,1650310433.397 [NAL9602](INFO): Sent 184 bytes from file Logs/20220418T193203/Express0001.lzma
2022-04-18T19:33:53.398Z,1650310433.398 [NAL9602](INFO): Packets left to send: 1
2022-04-18T19:34:10.028Z,1650310450.028 [NAL9602](INFO): SBD MO Status=1, MOMSN=36070, MT Status=0, MTMSN=0
2022-04-18T19:34:10.078Z,1650310450.078 [NAL9602](INFO): Sent 84 bytes from file Logs/20220418T193203/Express0001.lzma
2022-04-18T19:34:10.079Z,1650310450.079 [NAL9602](INFO): Packets left to send: 0
2022-04-18T19:34:17.064Z,1650310457.064 [NAL9602](INFO): SBD MO Status=1, MOMSN=36071, MT Status=0, MTMSN=0
2022-04-18T19:34:17.117Z,1650310457.117 [NAL9602](INFO): Sent 78 bytes from file Logs/20220418T193203/Express0004.lzma
2022-04-18T19:34:17.117Z,1650310457.117 [NAL9602](INFO): Packets left to send: 0
2022-04-18T19:34:23.191Z,1650310463.191 [RDI_PathfinderUp](ERROR): only read 3 of 4 data items
2022-04-18T19:34:24.336Z,1650310464.336 [NAL9602](INFO): SBD MO Status=0, MOMSN=36072, MT Status=0, MTMSN=0
2022-04-18T19:34:24.446Z,1650310464.446 [ballast_and_trim:NeedComms:D] Stopped
2022-04-18T19:34:24.446Z,1650310464.446 [ballast_and_trim:NeedComms:E] Running Loop=1
2022-04-18T19:34:24.816Z,1650310464.816 [ballast_and_trim:NeedComms:E](DEBUG): Initialize ReadDataComponent to sense time_fix
2022-04-18T19:34:26.801Z,1650310466.801 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,193428.00,A,4131.75780,N,07047.08709,W,0.486,301.34,180422,,,A*73
2022-04-18T19:34:26.804Z,1650310466.804 [NAL9602](INFO): GPS fix at 20220418T193428: (41.529297, -70.784785)
2022-04-18T19:34:26.873Z,1650310466.873 [ballast_and_trim:NeedComms:E] Stopped
2022-04-18T19:34:26.874Z,1650310466.874 [ballast_and_trim:NeedComms](INFO): Completed ballast_and_trim:NeedComms
2022-04-18T19:34:26.874Z,1650310466.874 [ballast_and_trim:NeedComms] Stopped
2022-04-18T19:34:26.874Z,1650310466.874 [ballast_and_trim:NeedComms](DEBUG): Aggregate::uninitialize ballast_and_trim:NeedComms
2022-04-18T19:34:26.874Z,1650310466.874 [ballast_and_trim:NeedComms:B.GoToSurface] Stopped
2022-04-18T19:34:26.874Z,1650310466.874 [ballast_and_trim:NeedComms:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2022-04-18T19:34:27.226Z,1650310467.226 [ballast_and_trim:StartingMission:StartingMission](INFO): Completed ballast_and_trim:StartingMission:StartingMission
2022-04-18T19:34:27.226Z,1650310467.226 [ballast_and_trim:StartingMission:StartingMission] Stopped
2022-04-18T19:34:27.226Z,1650310467.226 [ballast_and_trim:StartingMission:StartingMission](DEBUG): Aggregate::uninitialize ballast_and_trim:StartingMission:StartingMission
2022-04-18T19:34:27.226Z,1650310467.226 [ballast_and_trim:StartingMission](INFO): Completed ballast_and_trim:StartingMission
2022-04-18T19:34:27.226Z,1650310467.226 [ballast_and_trim:StartingMission] Stopped
2022-04-18T19:34:27.227Z,1650310467.227 [ballast_and_trim:StartingMission](DEBUG): Aggregate::uninitialize ballast_and_trim:StartingMission
2022-04-18T19:34:27.227Z,1650310467.227 [ballast_and_trim:RunBallastAndTrim] Running Loop=1
2022-04-18T19:34:27.227Z,1650310467.227 [ballast_and_trim:RunBallastAndTrim](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim
2022-04-18T19:34:27.227Z,1650310467.227 [ballast_and_trim:RunBallastAndTrim:RunDepth1] Running Loop=1
2022-04-18T19:34:27.227Z,1650310467.227 [ballast_and_trim:RunBallastAndTrim:RunDepth1](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:RunDepth1
2022-04-18T19:34:27.227Z,1650310467.227 [ballast_and_trim:RunBallastAndTrim:RunDepth1:A] Running Loop=1
2022-04-18T19:34:27.583Z,1650310467.583 [ballast_and_trim:RunBallastAndTrim:RunDepth1:A] Stopped
2022-04-18T19:34:27.583Z,1650310467.583 [ballast_and_trim:RunBallastAndTrim:RunDepth1:B] Running Loop=1
2022-04-18T19:34:27.583Z,1650310467.583 [ballast_and_trim:RunBallastAndTrim:RunDepth1:B](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:RunDepth1:B
2022-04-18T19:34:28.012Z,1650310468.012 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim] Running Loop=1
2022-04-18T19:34:28.013Z,1650310468.013 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim
2022-04-18T19:34:28.013Z,1650310468.013 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:A] Running Loop=1
2022-04-18T19:34:28.013Z,1650310468.013 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:B] Running Loop=1
2022-04-18T19:34:28.013Z,1650310468.013 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:C] Running Loop=1
2022-04-18T19:34:28.013Z,1650310468.013 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:D] Running Loop=1
2022-04-18T19:34:28.013Z,1650310468.013 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:E] Running Loop=1
2022-04-18T19:34:28.013Z,1650310468.013 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:F] Running Loop=1
2022-04-18T19:34:28.016Z,1650310468.016 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:F](INFO): Going to target depth. Speed set to 1.000000 m/s 
2022-04-18T19:34:28.016Z,1650310468.016 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:F] Stopped
2022-04-18T19:34:28.016Z,1650310468.016 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth] Running Loop=1
2022-04-18T19:34:28.016Z,1650310468.016 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth
2022-04-18T19:34:28.016Z,1650310468.016 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:A] Running Loop=1
2022-04-18T19:34:28.016Z,1650310468.016 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold] Running Loop=1
2022-04-18T19:34:28.017Z,1650310468.017 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold
2022-04-18T19:34:28.017Z,1650310468.017 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:A.Point] Running Loop=1
2022-04-18T19:34:28.017Z,1650310468.017 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:A.Point](DEBUG): Initialize.
2022-04-18T19:34:28.017Z,1650310468.017 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy] Running Loop=1
2022-04-18T19:34:28.017Z,1650310468.017 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy](DEBUG): Initialize Buoyancy Component.
2022-04-18T19:34:28.017Z,1650310468.017 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:C.Pitch] Running Loop=1
2022-04-18T19:34:28.017Z,1650310468.017 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:C.Pitch](DEBUG): Initialize.
2022-04-18T19:34:28.018Z,1650310468.018 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive] Running Loop=1
2022-04-18T19:34:28.018Z,1650310468.018 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive
2022-04-18T19:34:28.018Z,1650310468.018 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:A] Running Loop=1
2022-04-18T19:34:28.018Z,1650310468.018 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:E] Running Loop=1
2022-04-18T19:34:28.019Z,1650310468.019 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:D] Running Loop=1
2022-04-18T19:34:28.019Z,1650310468.019 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:C] Running Loop=1
2022-04-18T19:34:28.019Z,1650310468.019 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:B] Running Loop=1
2022-04-18T19:34:28.019Z,1650310468.019 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:A] Running Loop=1
2022-04-18T19:34:28.411Z,1650310468.411 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:A](INFO): Waiting for 0.000000 min while pumping down to neutral.
2022-04-18T19:34:28.411Z,1650310468.411 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:A] Stopped
2022-04-18T19:34:28.411Z,1650310468.411 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:B.Wait] Running Loop=1
2022-04-18T19:34:28.411Z,1650310468.411 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:B.Wait](DEBUG): Initialize Wait Component.
2022-04-18T19:34:28.411Z,1650310468.411 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold] Running Loop=1
2022-04-18T19:34:28.411Z,1650310468.411 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:C.Pitch] Running Loop=1
2022-04-18T19:34:28.412Z,1650310468.412 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy] Running Loop=1
2022-04-18T19:34:28.412Z,1650310468.412 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:A.Point] Running Loop=1
2022-04-18T19:34:28.412Z,1650310468.412 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:A] Running Loop=1
2022-04-18T19:34:28.843Z,1650310468.843 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:B.Wait](INFO): Done Waiting.
2022-04-18T19:34:28.843Z,1650310468.843 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:B.Wait] Stopped
2022-04-18T19:34:28.843Z,1650310468.843 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:B.Wait](DEBUG): Uninitialize Wait Component.
2022-04-18T19:34:28.843Z,1650310468.843 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive](INFO): Completed ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive
2022-04-18T19:34:28.843Z,1650310468.843 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive] Stopped
2022-04-18T19:34:28.843Z,1650310468.843 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive
2022-04-18T19:34:28.843Z,1650310468.843 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth] Running Loop=1
2022-04-18T19:34:28.844Z,1650310468.844 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth
2022-04-18T19:34:28.844Z,1650310468.844 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed] Running Loop=1
2022-04-18T19:34:28.844Z,1650310468.844 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed](DEBUG): Initialize.
2022-04-18T19:34:28.844Z,1650310468.844 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:A] Running Loop=1
2022-04-18T19:34:29.218Z,1650310469.218 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed] Running Loop=1
2022-04-18T19:34:29.219Z,1650310469.219 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:A](INFO): Moving to 6.000000 m 
2022-04-18T19:34:29.219Z,1650310469.219 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:A] Stopped
2022-04-18T19:34:29.219Z,1650310469.219 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:C.Pitch] Running Loop=1
2022-04-18T19:34:29.219Z,1650310469.219 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:C.Pitch](DEBUG): Initialize.
2022-04-18T19:34:49.791Z,1650310489.791 [Micromodem](INFO): Nmea in: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error

2022-04-18T19:34:49.792Z,1650310489.792 [Micromodem](ERROR): Response from modem failed NMEA checksum: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error
 expected 41
2022-04-18T19:34:49.793Z,1650310489.793 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31

2022-04-18T19:34:50.202Z,1650310490.202 [Micromodem](INFO): Nmea in: $CACST,6,1,20220418193449.591319,06,945,23,0123,0150,149,02,02,01,02,-1,-01,-01,1,3,4,0,150,65.0,1.82,-100,1.18,-01,-2.41,-12,14500,4000*4E

2022-04-18T19:34:59.080Z,1650310499.080 [NAL9602](INFO): Not Powering down - fast GPS
2022-04-18T19:36:00.617Z,1650310560.617 [Radio_Surface](INFO): Powering down
2022-04-18T19:36:23.333Z,1650310583.333 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2022-04-18T19:36:25.208Z,1650310585.208 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:C.Pitch] Stopped
2022-04-18T19:36:25.208Z,1650310585.208 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth](INFO): Completed ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth
2022-04-18T19:36:25.208Z,1650310585.208 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth] Stopped
2022-04-18T19:36:25.209Z,1650310585.209 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth
2022-04-18T19:36:25.209Z,1650310585.209 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed] Stopped
2022-04-18T19:36:25.209Z,1650310585.209 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed](DEBUG): Uninitialize.
2022-04-18T19:36:25.210Z,1650310585.210 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth](INFO): Completed ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth
2022-04-18T19:36:25.210Z,1650310585.210 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth] Stopped
2022-04-18T19:36:25.210Z,1650310585.210 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth
2022-04-18T19:36:25.210Z,1650310585.210 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:A] Stopped
2022-04-18T19:36:25.210Z,1650310585.210 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold] Stopped
2022-04-18T19:36:25.210Z,1650310585.210 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold
2022-04-18T19:36:25.210Z,1650310585.210 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:A.Point] Stopped
2022-04-18T19:36:25.210Z,1650310585.210 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy] Stopped
2022-04-18T19:36:25.211Z,1650310585.211 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy](DEBUG): Uninitialize Buoyancy Component.
2022-04-18T19:36:25.211Z,1650310585.211 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:C.Pitch] Stopped
2022-04-18T19:36:25.211Z,1650310585.211 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth] Running Loop=1
2022-04-18T19:36:25.211Z,1650310585.211 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth
2022-04-18T19:36:25.211Z,1650310585.211 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed] Running Loop=1
2022-04-18T19:36:25.211Z,1650310585.211 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed](DEBUG): Initialize.
2022-04-18T19:36:25.211Z,1650310585.211 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:B.Pitch] Running Loop=1
2022-04-18T19:36:25.211Z,1650310585.211 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:B.Pitch](DEBUG): Initialize.
2022-04-18T19:36:25.211Z,1650310585.211 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:C] Running Loop=1
2022-04-18T19:36:25.574Z,1650310585.574 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:C](INFO): Waiting for the vehicle to settle. Depth = 6.036205 m 
2022-04-18T19:36:25.574Z,1650310585.574 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:C] Stopped
2022-04-18T19:36:25.574Z,1650310585.574 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait] Running Loop=1
2022-04-18T19:36:25.574Z,1650310585.574 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait](DEBUG): Initialize Wait Component.
2022-04-18T19:36:25.574Z,1650310585.574 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:B.Pitch] Running Loop=1
2022-04-18T19:36:25.575Z,1650310585.575 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed] Running Loop=1
2022-04-18T19:37:42.319Z,1650310662.319 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for altitude
2022-04-18T19:38:47.377Z,1650310727.377 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31

2022-04-18T19:38:47.778Z,1650310727.778 [Micromodem](INFO): Nmea in: $CACST,6,1,20220418193847.571251,06,1471,25,0100,0150,149,04,04,01,04,-1,-01,-01,1,3,1,0,150,9.7,0.39,-100,2.61,-01,-1.78,51,14500,4000*62

2022-04-18T19:40:48.168Z,1650310848.168 [Micromodem](INFO): Nmea in: $CAMSG,BAD_CRC, Data Header,2*00

2022-04-18T19:40:48.173Z,1650310848.173 [Micromodem](INFO): Nmea in: $CACST,6,1,20220418194045.575250,06,1483,25,0091,0150,134,00,00,01,00,1,-01,-01,2,3,2,0,150,-4.1,-0.67,-100,3.67,-01,1.24,55,14500,4000*6A

2022-04-18T19:43:39.485Z,1650311019.485 [Micromodem](INFO): Nmea in: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error

2022-04-18T19:43:39.486Z,1650311019.486 [Micromodem](ERROR): Response from modem failed NMEA checksum: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error
 expected 41
2022-04-18T19:43:39.487Z,1650311019.487 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31

2022-04-18T19:43:39.874Z,1650311019.874 [Micromodem](INFO): Nmea in: $CACST,6,1,20220418194339.580829,06,1645,26,0107,0150,208,02,02,01,02,-1,-01,-01,1,3,7,0,150,73.5,3.01,-100,-0.01,-01,-1.02,-12,14500,4000*52

2022-04-18T19:44:03.706Z,1650311043.706 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31

2022-04-18T19:44:03.710Z,1650311043.710 [Micromodem](INFO): Nmea in: $CACST,6,1,20220418194403.579247,06,1021,24,0103,0150,208,03,03,01,03,-1,-01,-01,1,3,3,0,150,3.9,0.22,-100,2.78,-01,0.77,60,14500,4000*41

2022-04-18T19:46:22.297Z,1650311182.297 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for BIT error
2022-04-18T19:46:26.340Z,1650311186.340 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait](INFO): Done Waiting.
2022-04-18T19:46:26.340Z,1650311186.340 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait] Stopped
2022-04-18T19:46:26.340Z,1650311186.340 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait](DEBUG): Uninitialize Wait Component.
2022-04-18T19:46:26.341Z,1650311186.341 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:E] Running Loop=1
2022-04-18T19:46:26.804Z,1650311186.804 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:E](INFO): Running ballast and trim. Depth = 6.222895 m 
2022-04-18T19:46:26.804Z,1650311186.804 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:E] Stopped
2022-04-18T19:46:26.804Z,1650311186.804 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.] Running Loop=1
2022-04-18T19:46:26.804Z,1650311186.804 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](INFO): Initializing BallastAndTrim.
2022-04-18T19:47:39.055Z,1650311259.055 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for water mass range.
2022-04-18T19:47:48.812Z,1650311268.812 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for water mass range.
2022-04-18T19:49:49.167Z,1650311389.167 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for BIT error
2022-04-18T19:50:29.165Z,1650311429.165 [RDI_PathfinderUp](ERROR): only read 2 of 4 data items
2022-04-18T19:50:38.938Z,1650311438.938 [RDI_PathfinderUp](ERROR): only read 2 of 4 data items
2022-04-18T19:51:13.593Z,1650311473.593 [Micromodem](INFO): Nmea in: $CAMSG,Error accessing coproc,4*51

2022-04-18T19:51:13.597Z,1650311473.597 [Micromodem](INFO): Nmea in: $CACST,6,1,20220418195113.580721,06,517,21,0132,0150,208,02,02,01,02,-1,-01,-01,4,3,0,0,-999,-99.9,-9.99,-999,-9.99,-01,0.00,-999,14500,4000*5F

2022-04-18T19:54:59.448Z,1650311699.448 [Micromodem](INFO): Nmea in: $CAMSG,BAD_CRC, Data Header,2*00

2022-04-18T19:54:59.454Z,1650311699.454 [Micromodem](INFO): Nmea in: $CACST,6,1,20220418195457.577684,06,1051,24,0107,0150,208,02,02,01,02,4,-01,-01,2,3,1,0,150,4.0,0.14,-100,2.86,-01,-3.30,60,14500,4000*48

2022-04-18T19:58:00.452Z,1650311880.452 [Micromodem](INFO): Nmea in: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error

2022-04-18T19:58:00.461Z,1650311880.461 [Micromodem](ERROR): Response from modem failed NMEA checksum: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error
 expected 41
2022-04-18T19:58:00.463Z,1650311880.463 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31

2022-04-18T19:58:00.862Z,1650311880.862 [Micromodem](INFO): Nmea in: $CACST,6,1,20220418195759.576714,06,555,21,0094,0150,208,02,02,01,02,-1,-01,-01,1,3,2,0,150,75.7,3.97,-100,-0.97,-01,-3.70,-12,14500,4000*60

2022-04-18T19:58:01.665Z,1650311881.665 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31

2022-04-18T19:58:01.669Z,1650311881.669 [Micromodem](INFO): Nmea in: $CACST,6,1,20220418195801.581313,06,168,22,0090,0150,208,02,02,00,02,-1,-01,-01,1,3,1,0,150,2.0,0.86,-100,2.14,-01,-1.75,62,14500,4000*5B

2022-04-18T20:01:40.242Z,1650312100.242 [RDI_PathfinderUp](ERROR): only read 3 of 4 data items
2022-04-18T20:05:30.148Z,1650312330.148 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): BallastAndTrim completed. Estimation time: 19.05 minutes.
2022-04-18T20:05:30.149Z,1650312330.149 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): Estimated buoyancyNeutral: 190.658274 +/- 14.999336 cc (conf. level 99.90%, sigma: 24.338548 cc).
2022-04-18T20:05:30.150Z,1650312330.150 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): Estimated massDefault: 2.122748 +/- 0.232759 mm (conf. level 99.90%, sigma: 0.377685 mm).
2022-04-18T20:05:30.151Z,1650312330.151 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): Changing persisted config values to: 190.658274 cc buoyancy neutral and 2.122748 mm mass default
2022-04-18T20:05:30.155Z,1650312330.155 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2022-04-18T20:05:30.155Z,1650312330.155 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): CBIT.gfScanTimeout=2 hour;

2022-04-18T20:05:30.155Z,1650312330.155 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): CTD_Seabird.loadAtStartup=1 bool;

2022-04-18T20:05:30.156Z,1650312330.156 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): Express linearApproximation CTD_Seabird.bin_median_sea_water_salinity 0.050000 practical_salinity_unit;

2022-04-18T20:05:30.156Z,1650312330.156 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): Express linearApproximation WetLabsSeaOWL_UV_A.mass_concentration_of_petroleum_hydrocarbons_in_sea_water 0.000020 kilogram_per_cubic_meter;

2022-04-18T20:05:30.156Z,1650312330.156 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): Express none mass_concentration_of_chlorophyll_in_sea_water;

2022-04-18T20:05:30.156Z,1650312330.156 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): InternalEnvSim.timeAdjust=1.5 day;

2022-04-18T20:05:30.156Z,1650312330.156 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): VerticalControl.buoyancyNeutral=190.658274 cubic_centimeter;

2022-04-18T20:05:30.156Z,1650312330.156 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): VerticalControl.massDefault=2.122748 millimeter;

2022-04-18T20:05:30.157Z,1650312330.157 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.] Stopped
2022-04-18T20:05:30.157Z,1650312330.157 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](INFO): Uninitializing BallastAndTrim.
2022-04-18T20:05:30.158Z,1650312330.158 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth](INFO): Completed ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth
2022-04-18T20:05:30.158Z,1650312330.158 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth] Stopped
2022-04-18T20:05:30.158Z,1650312330.158 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth
2022-04-18T20:05:30.158Z,1650312330.158 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed] Stopped
2022-04-18T20:05:30.158Z,1650312330.158 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed](DEBUG): Uninitialize.
2022-04-18T20:05:30.158Z,1650312330.158 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:B.Pitch] Stopped
2022-04-18T20:05:30.159Z,1650312330.159 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim](INFO): Completed ballast_and_trim:RunBallastAndTrim:BallastAndTrim
2022-04-18T20:05:30.159Z,1650312330.159 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim] Stopped
2022-04-18T20:05:30.160Z,1650312330.160 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim
2022-04-18T20:05:30.160Z,1650312330.160 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:A] Stopped
2022-04-18T20:05:30.160Z,1650312330.160 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:B] Stopped
2022-04-18T20:05:30.160Z,1650312330.160 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:C] Stopped
2022-04-18T20:05:30.160Z,1650312330.160 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:D] Stopped
2022-04-18T20:05:30.160Z,1650312330.160 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:E] Stopped
2022-04-18T20:05:30.555Z,1650312330.555 [ballast_and_trim:RunBallastAndTrim:RunDepth1:B](INFO): Completed ballast_and_trim:RunBallastAndTrim:RunDepth1:B
2022-04-18T20:05:30.555Z,1650312330.555 [ballast_and_trim:RunBallastAndTrim:RunDepth1:B] Stopped
2022-04-18T20:05:30.555Z,1650312330.555 [ballast_and_trim:RunBallastAndTrim:RunDepth1:B](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:RunDepth1:B
2022-04-18T20:05:30.556Z,1650312330.556 [ballast_and_trim:RunBallastAndTrim:RunDepth1](INFO): Completed ballast_and_trim:RunBallastAndTrim:RunDepth1
2022-04-18T20:05:30.556Z,1650312330.556 [ballast_and_trim:RunBallastAndTrim:RunDepth1] Stopped
2022-04-18T20:05:30.556Z,1650312330.556 [ballast_and_trim:RunBallastAndTrim:RunDepth1](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:RunDepth1
2022-04-18T20:05:30.556Z,1650312330.556 [ballast_and_trim:RunBallastAndTrim:RunDepth2] Running Loop=1
2022-04-18T20:05:30.556Z,1650312330.556 [ballast_and_trim:RunBallastAndTrim:RunDepth2](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:RunDepth2
2022-04-18T20:05:30.556Z,1650312330.556 [ballast_and_trim:RunBallastAndTrim:RunDepth2:A] Running Loop=1
2022-04-18T20:05:30.983Z,1650312330.983 [ballast_and_trim:RunBallastAndTrim:RunDepth2] Stopped
2022-04-18T20:05:30.983Z,1650312330.983 [ballast_and_trim:RunBallastAndTrim:RunDepth2](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:RunDepth2
2022-04-18T20:05:30.983Z,1650312330.983 [ballast_and_trim:RunBallastAndTrim:RunDepth2:A] Stopped
2022-04-18T20:05:30.983Z,1650312330.983 [ballast_and_trim:RunBallastAndTrim](INFO): Completed ballast_and_trim:RunBallastAndTrim
2022-04-18T20:05:30.983Z,1650312330.983 [ballast_and_trim:RunBallastAndTrim] Stopped
2022-04-18T20:05:30.983Z,1650312330.983 [ballast_and_trim:RunBallastAndTrim](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim
2022-04-18T20:05:30.984Z,1650312330.984 [ballast_and_trim:EndingMission] Running Loop=1
2022-04-18T20:05:30.984Z,1650312330.984 [ballast_and_trim:EndingMission](DEBUG): Aggregate::initialize ballast_and_trim:EndingMission
2022-04-18T20:05:31.363Z,1650312331.363 [ballast_and_trim:NeedComms] Running Loop=1
2022-04-18T20:05:31.363Z,1650312331.363 [ballast_and_trim:NeedComms](DEBUG): Aggregate::initialize ballast_and_trim:NeedComms
2022-04-18T20:05:31.363Z,1650312331.363 [ballast_and_trim:NeedComms:B.GoToSurface] Running Loop=1
2022-04-18T20:05:31.363Z,1650312331.363 [ballast_and_trim:NeedComms:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2022-04-18T20:05:31.364Z,1650312331.364 [ballast_and_trim:NeedComms:B.GoToSurface](INFO): Received depth rate setting nan m/s.
2022-04-18T20:05:31.364Z,1650312331.364 [ballast_and_trim:NeedComms:B.GoToSurface](INFO): Received pitch setting 19.999999 degrees.
2022-04-18T20:05:31.365Z,1650312331.365 [ballast_and_trim:NeedComms:B.GoToSurface](INFO): Received speed setting 1.000000 m/s.
2022-04-18T20:05:31.365Z,1650312331.365 [ballast_and_trim:NeedComms:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2022-04-18T20:05:31.366Z,1650312331.366 [ballast_and_trim:NeedComms:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2022-04-18T20:05:31.366Z,1650312331.366 [ballast_and_trim:NeedComms:A] Running Loop=1
2022-04-18T20:05:31.367Z,1650312331.367 [ballast_and_trim:NeedComms:A](INFO): last time_fix was: 1650310468.000000 second since 1970/01/01T00:00:00Z 
2022-04-18T20:05:31.367Z,1650312331.367 [ballast_and_trim:NeedComms:A] Stopped
2022-04-18T20:05:49.141Z,1650312349.141 [RDI_PathfinderUp](ERROR): only read 3 of 4 data items
2022-04-18T20:06:00.448Z,1650312360.448 [ballast_and_trim:NeedComms:C] Running Loop=1
2022-04-18T20:06:01.029Z,1650312361.029 [Radio_Surface](INFO): Powering up
2022-04-18T20:06:02.863Z,1650312362.863 [CTD_Seabird](ERROR): Salinity reading out of range: 13.492951 psu
2022-04-18T20:06:06.754Z,1650312366.754 [DataOverHttps](INFO): Radio surface powered ON.
2022-04-18T20:06:23.868Z,1650312383.868 [NAL9602](INFO): SBD MO Status=2, MOMSN=36073, MT Status=2, MTMSN=0
2022-04-18T20:06:23.868Z,1650312383.868 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-04-18T20:06:36.388Z,1650312396.388 [NAL9602](INFO): SBD MO Status=2, MOMSN=36073, MT Status=2, MTMSN=0
2022-04-18T20:06:36.388Z,1650312396.388 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-04-18T20:06:48.112Z,1650312408.112 [NAL9602](INFO): SBD MO Status=0, MOMSN=36073, MT Status=0, MTMSN=0
2022-04-18T20:06:48.112Z,1650312408.112 [NAL9602](INFO): No messages in MT queue
2022-04-18T20:06:49.319Z,1650312409.319 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,200650.00,A,4131.79004,N,07047.14480,W,1.283,65.40,180422,,,A*4F
2022-04-18T20:06:49.321Z,1650312409.321 [NAL9602](INFO): GPS fix at 20220418T200650: (41.529834, -70.785747)
2022-04-18T20:06:49.334Z,1650312409.334 [ballast_and_trim:NeedComms:C] Stopped
2022-04-18T20:06:49.334Z,1650312409.334 [ballast_and_trim:NeedComms:D] Running Loop=1
2022-04-18T20:07:08.048Z,1650312428.048 [NAL9602](INFO): SBD MO Status=1, MOMSN=36074, MT Status=0, MTMSN=0
2022-04-18T20:07:08.097Z,1650312428.097 [NAL9602](INFO): Sent 73 bytes from file Logs/20220418T193203/Courier0006.lzma
2022-04-18T20:07:08.097Z,1650312428.097 [NAL9602](INFO): Packets left to send: 0
2022-04-18T20:07:25.552Z,1650312445.552 [NAL9602](INFO): SBD MO Status=2, MOMSN=36075, MT Status=2, MTMSN=0
2022-04-18T20:07:25.552Z,1650312445.552 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-04-18T20:07:33.823Z,1650312453.823 [Micromodem](INFO): Nmea in: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error

2022-04-18T20:07:33.825Z,1650312453.825 [Micromodem](ERROR): Response from modem failed NMEA checksum: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error
 expected 41
2022-04-18T20:07:34.212Z,1650312454.212 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31

2022-04-18T20:07:34.622Z,1650312454.622 [Micromodem](INFO): Nmea in: $CACST,6,1,20220418200733.567777,06,421,26,0117,0150,149,01,01,00,01,-1,-01,-01,1,3,5,0,150,66.1,-3.22,-100,6.22,-01,-1.55,-6,14500,4000*58

2022-04-18T20:07:42.708Z,1650312462.708 [NAL9602](INFO): SBD MO Status=1, MOMSN=36075, MT Status=0, MTMSN=0
2022-04-18T20:07:42.757Z,1650312462.757 [NAL9602](INFO): Sent 184 bytes from file Logs/20220418T193203/Express0007.lzma
2022-04-18T20:07:42.757Z,1650312462.757 [NAL9602](INFO): Packets left to send: 5
2022-04-18T20:08:00.988Z,1650312480.988 [NAL9602](INFO): SBD MO Status=1, MOMSN=36076, MT Status=0, MTMSN=0
2022-04-18T20:08:01.041Z,1650312481.041 [NAL9602](INFO): Sent 184 bytes from file Logs/20220418T193203/Express0007.lzma
2022-04-18T20:08:01.041Z,1650312481.041 [NAL9602](INFO): Packets left to send: 4
2022-04-18T20:08:10.408Z,1650312490.408 [NAL9602](INFO): SBD MO Status=1, MOMSN=36077, MT Status=0, MTMSN=0
2022-04-18T20:08:10.457Z,1650312490.457 [NAL9602](INFO): Sent 184 bytes from file Logs/20220418T193203/Express0007.lzma
2022-04-18T20:08:10.457Z,1650312490.457 [NAL9602](INFO): Packets left to send: 3
2022-04-18T20:08:25.103Z,1650312505.103 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude
2022-04-18T20:08:39.625Z,1650312519.625 [NAL9602](INFO): SBD MO Status=1, MOMSN=36078, MT Status=0, MTMSN=0
2022-04-18T20:08:39.677Z,1650312519.677 [NAL9602](INFO): Sent 184 bytes from file Logs/20220418T193203/Express0007.lzma
2022-04-18T20:08:39.677Z,1650312519.677 [NAL9602](INFO): Packets left to send: 2
2022-04-18T20:08:51.908Z,1650312531.908 [NAL9602](INFO): SBD MO Status=1, MOMSN=36079, MT Status=0, MTMSN=0
2022-04-18T20:08:51.957Z,1650312531.957 [NAL9602](INFO): Sent 184 bytes from file Logs/20220418T193203/Express0007.lzma
2022-04-18T20:08:51.957Z,1650312531.957 [NAL9602](INFO): Packets left to send: 1
2022-04-18T20:09:01.842Z,1650312541.842 [NAL9602](INFO): SBD MO Status=1, MOMSN=36080, MT Status=0, MTMSN=0
2022-04-18T20:09:01.897Z,1650312541.897 [NAL9602](INFO): Sent 14 bytes from file Logs/20220418T193203/Express0007.lzma
2022-04-18T20:09:01.897Z,1650312541.897 [NAL9602](INFO): Packets left to send: 0
2022-04-18T20:09:09.116Z,1650312549.116 [NAL9602](INFO): SBD MO Status=0, MOMSN=36081, MT Status=0, MTMSN=0
2022-04-18T20:09:09.222Z,1650312549.222 [ballast_and_trim:NeedComms:D] Stopped
2022-04-18T20:09:09.223Z,1650312549.223 [ballast_and_trim:NeedComms:E] Running Loop=1
2022-04-18T20:09:11.537Z,1650312551.537 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,200913.00,A,4131.79813,N,07047.15647,W,1.672,353.02,180422,,,A*7B
2022-04-18T20:09:11.539Z,1650312551.539 [NAL9602](INFO): GPS fix at 20220418T200913: (41.529969, -70.785941)
2022-04-18T20:09:11.553Z,1650312551.553 [ballast_and_trim:NeedComms:E] Stopped
2022-04-18T20:09:11.554Z,1650312551.554 [ballast_and_trim:NeedComms](INFO): Completed ballast_and_trim:NeedComms
2022-04-18T20:09:11.554Z,1650312551.554 [ballast_and_trim:NeedComms] Stopped
2022-04-18T20:09:11.554Z,1650312551.554 [ballast_and_trim:NeedComms](DEBUG): Aggregate::uninitialize ballast_and_trim:NeedComms
2022-04-18T20:09:11.554Z,1650312551.554 [ballast_and_trim:NeedComms:B.GoToSurface] Stopped
2022-04-18T20:09:11.554Z,1650312551.554 [ballast_and_trim:NeedComms:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2022-04-18T20:09:12.005Z,1650312552.005 [ballast_and_trim:EndingMission](INFO): Completed ballast_and_trim:EndingMission
2022-04-18T20:09:12.005Z,1650312552.005 [ballast_and_trim:EndingMission] Stopped
2022-04-18T20:09:12.005Z,1650312552.005 [ballast_and_trim:EndingMission](DEBUG): Aggregate::uninitialize ballast_and_trim:EndingMission
2022-04-18T20:09:12.008Z,1650312552.008 [ballast_and_trim](INFO): Completed ballast_and_trim
2022-04-18T20:09:12.008Z,1650312552.008 [MissionManager](INFO): ballast_and_trim is completed.
2022-04-18T20:09:12.013Z,1650312552.013 [MissionManager](INFO): Uninitializing Mission ballast_and_trim
2022-04-18T20:09:12.013Z,1650312552.013 [ballast_and_trim] Stopped
2022-04-18T20:09:12.013Z,1650312552.013 [ballast_and_trim](DEBUG): Aggregate::uninitialize ballast_and_trim
2022-04-18T20:09:12.013Z,1650312552.013 [ballast_and_trim:Science] Stopped
2022-04-18T20:09:12.013Z,1650312552.013 [ballast_and_trim:Science](DEBUG): Aggregate::uninitialize ballast_and_trim:Science
2022-04-18T20:09:12.013Z,1650312552.013 [ballast_and_trim:Science:B] Stopped
2022-04-18T20:09:12.013Z,1650312552.013 [ballast_and_trim:Science:C] Stopped
2022-04-18T20:09:12.013Z,1650312552.013 [ballast_and_trim:Science:Read_Oil] Stopped
2022-04-18T20:09:12.013Z,1650312552.013 [ballast_and_trim:Science:OceanCurrent] Stopped
2022-04-18T20:09:12.013Z,1650312552.013 [ballast_and_trim:Science:OceanCurrent](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:OceanCurrent
2022-04-18T20:09:12.013Z,1650312552.013 [ballast_and_trim:Science:OceanCurrent:A.] Stopped
2022-04-18T20:09:12.013Z,1650312552.013 [ballast_and_trim:StandardEnvelopes] Stopped
2022-04-18T20:09:12.014Z,1650312552.014 [ballast_and_trim:StandardEnvelopes](DEBUG): Aggregate::uninitialize ballast_and_trim:StandardEnvelopes
2022-04-18T20:09:12.014Z,1650312552.014 [ballast_and_trim:StandardEnvelopes:A.AltitudeEnvelope] Stopped
2022-04-18T20:09:12.014Z,1650312552.014 [ballast_and_trim:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent.
2022-04-18T20:09:12.014Z,1650312552.014 [ballast_and_trim:StandardEnvelopes:B.DepthEnvelope] Stopped
2022-04-18T20:09:12.014Z,1650312552.014 [ballast_and_trim:StandardEnvelopes:B.DepthEnvelope](DEBUG): Uninitialize.
2022-04-18T20:09:12.014Z,1650312552.014 [ballast_and_trim:StandardEnvelopes:C.OffshoreEnvelope] Stopped
2022-04-18T20:09:12.014Z,1650312552.014 [ballast_and_trim:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Uninitialize OffshoreEnvelopeComponent.
2022-04-18T20:09:12.368Z,1650312552.368 [MissionManager](IMPORTANT): Started mission Default
2022-04-18T20:09:12.369Z,1650312552.369 [Default] Running Loop=1
2022-04-18T20:09:12.369Z,1650312552.369 [Default](DEBUG): Aggregate::initialize Default
2022-04-18T20:09:12.369Z,1650312552.369 [Default:B.GoToSurface] Running Loop=1
2022-04-18T20:09:12.369Z,1650312552.369 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2022-04-18T20:09:12.369Z,1650312552.369 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2022-04-18T20:09:12.370Z,1650312552.370 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2022-04-18T20:09:12.370Z,1650312552.370 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2022-04-18T20:09:12.370Z,1650312552.370 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2022-04-18T20:09:12.370Z,1650312552.370 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2022-04-18T20:09:12.371Z,1650312552.371 [Default:A.Wait] Running Loop=1
2022-04-18T20:09:12.371Z,1650312552.371 [Default:A.Wait](DEBUG): Initialize Wait Component.
2022-04-18T20:09:25.715Z,1650312565.715 [Default:A.Wait](INFO): Done Waiting.
2022-04-18T20:09:25.715Z,1650312565.715 [Default:A.Wait] Stopped
2022-04-18T20:09:25.715Z,1650312565.715 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2022-04-18T20:09:26.096Z,1650312566.096 [Default:CheckIn] Running Loop=1
2022-04-18T20:09:26.096Z,1650312566.096 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-04-18T20:09:26.096Z,1650312566.096 [Default:CheckIn:Read_GPS] Running Loop=1
2022-04-18T20:09:28.101Z,1650312568.101 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,200929.00,A,4131.80005,N,07047.15696,W,5.909,227.43,180422,,,A*77
2022-04-18T20:09:28.103Z,1650312568.103 [NAL9602](INFO): GPS fix at 20220418T200929: (41.530001, -70.785949)
2022-04-18T20:09:28.126Z,1650312568.126 [Default:CheckIn:Read_GPS] Stopped
2022-04-18T20:09:28.126Z,1650312568.126 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-04-18T20:09:33.368Z,1650312573.368 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31

2022-04-18T20:09:33.756Z,1650312573.756 [Micromodem](INFO): Nmea in: $CACST,6,1,20220418200933.569480,06,937,23,0092,0150,82,00,00,01,00,-1,-01,-01,1,3,1,0,150,39.9,0.19,-100,2.81,-01,-0.75,45,14500,4000*52

2022-04-18T20:09:48.392Z,1650312588.392 [NAL9602](INFO): SBD MO Status=1, MOMSN=36082, MT Status=0, MTMSN=0
2022-04-18T20:09:48.449Z,1650312588.449 [NAL9602](INFO): Sent 73 bytes from file Logs/20220418T193203/Courier0009.lzma
2022-04-18T20:09:48.449Z,1650312588.449 [NAL9602](INFO): Packets left to send: 0
2022-04-18T20:09:58.591Z,1650312598.591 [NAL9602](INFO): SBD MO Status=1, MOMSN=36083, MT Status=0, MTMSN=0
2022-04-18T20:09:58.641Z,1650312598.641 [NAL9602](INFO): Sent 123 bytes from file Logs/20220418T193203/Express0010.lzma
2022-04-18T20:09:58.641Z,1650312598.641 [NAL9602](INFO): Packets left to send: 0
2022-04-18T20:10:13.135Z,1650312613.135 [NAL9602](INFO): SBD MO Status=0, MOMSN=36084, MT Status=0, MTMSN=0
2022-04-18T20:10:13.231Z,1650312613.231 [Default:CheckIn:Read_Iridium] Stopped
2022-04-18T20:10:13.231Z,1650312613.231 [Default:CheckIn:C.Wait] Running Loop=1
2022-04-18T20:10:13.231Z,1650312613.231 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-04-18T20:10:43.837Z,1650312643.837 [NAL9602](INFO): Not Powering down - fast GPS
2022-04-18T20:14:30.138Z,1650312870.138 [RDI_PathfinderUp](ERROR): only read 3 of 4 data items
2022-04-18T20:15:13.736Z,1650312913.736 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-04-18T20:15:13.736Z,1650312913.736 [Default:CheckIn:C.Wait] Stopped
2022-04-18T20:15:13.736Z,1650312913.736 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-04-18T20:15:13.741Z,1650312913.741 [Default:CheckIn:D] Running Loop=1
2022-04-18T20:15:14.165Z,1650312914.165 [Default:CheckIn:D] Stopped
2022-04-18T20:15:14.165Z,1650312914.165 [Default:CheckIn:E] Running Loop=1
2022-04-18T20:15:14.529Z,1650312914.529 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 6.029858 min 
2022-04-18T20:15:14.529Z,1650312914.529 [Default:CheckIn:E] Stopped
2022-04-18T20:15:14.529Z,1650312914.529 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-04-18T20:15:14.530Z,1650312914.530 [Default:CheckIn] Stopped
2022-04-18T20:15:14.530Z,1650312914.530 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-04-18T20:15:14.530Z,1650312914.530 [Default:CheckIn](INFO): Running loop #2
2022-04-18T20:15:14.530Z,1650312914.530 [Default:CheckIn] Running Loop=2
2022-04-18T20:15:14.530Z,1650312914.530 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-04-18T20:15:14.530Z,1650312914.530 [Default:CheckIn:Read_GPS] Running Loop=1
2022-04-18T20:15:16.545Z,1650312916.545 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,201518.00,A,4131.83102,N,07047.17600,W,4.121,141.19,180422,,,A*7F
2022-04-18T20:15:16.547Z,1650312916.547 [NAL9602](INFO): GPS fix at 20220418T201518: (41.530517, -70.786267)
2022-04-18T20:15:16.570Z,1650312916.570 [Default:CheckIn:Read_GPS] Stopped
2022-04-18T20:15:16.570Z,1650312916.570 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-04-18T20:15:21.808Z,1650312921.808 [Micromodem](INFO): Nmea in: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error

2022-04-18T20:15:21.809Z,1650312921.809 [Micromodem](ERROR): Response from modem failed NMEA checksum: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error
 expected 41
2022-04-18T20:15:22.199Z,1650312922.199 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31

2022-04-18T20:15:22.606Z,1650312922.606 [Micromodem](INFO): Nmea in: $CACST,6,1,20220418201521.560630,06,1281,25,0093,0150,208,03,03,01,03,-1,-01,-01,1,3,1,0,150,79.1,3.87,-100,-0.87,-01,-0.10,-18,14500,4000*58

2022-04-18T20:15:33.648Z,1650312933.648 [NAL9602](IMPORTANT): SBD MO Status=1, MOMSN=36085, MT Status=1, MTMSN=1406
2022-04-18T20:15:33.701Z,1650312933.701 [NAL9602](INFO): Sent 73 bytes from file Logs/20220418T193203/Courier0012.lzma
2022-04-18T20:15:33.701Z,1650312933.701 [NAL9602](INFO): Packets left to send: 0
2022-04-18T20:15:34.367Z,1650312934.367 [NAL9602](INFO): Received command: sched asap "load Maintenance/calibrate_sparton_compass.xml;set SpartonCompassCal.YoYoMinDepth 3 m;set SpartonCompassCal.YoYoMaxDepth 7 m;set SpartonCompassCal.YoYoMinAltitude 3 m;set SpartonCompassCal.MinAltitude 4 m" 1k3c 1 2
2022-04-18T20:15:34.410Z,1650312934.410 [CommandExec](IMPORTANT): got command schedule asap "load Maintenance/calibrate_sparton_compass.xml;set SpartonCompassCal.YoYoMinDepth 3 m;set SpartonCompassCal.YoYoMaxDepth 7 m;set SpartonCompassCal.YoYoMinAltitude 3 m;set SpartonCompassCal.MinAltitude 4 m" 1k3c 1 2.000000
2022-04-18T20:15:34.410Z,1650312934.410 [CommandExec](IMPORTANT): Scheduling command #1 of 2 with id=1k3c
2022-04-18T20:15:34.411Z,1650312934.411 [CommandExec](IMPORTANT): Scheduled #1 (#1 of 2 with id='1k3c'): "load Maintenance/calibrate_sparton_compass.xml;set SpartonCompassCal.YoYoMinDepth 3 m;set SpartonCompassCal.YoYoMaxDepth 7 m;set SpartonCompassCal.YoYoMinAltitude 3 m;set SpartonCompassCal.MinAltitude 4 m", ASAP
2022-04-18T20:15:44.303Z,1650312944.303 [NAL9602](IMPORTANT): SBD MO Status=1, MOMSN=36086, MT Status=1, MTMSN=1407
2022-04-18T20:15:44.357Z,1650312944.357 [NAL9602](INFO): Sent 153 bytes from file Logs/20220418T193203/Express0013.lzma
2022-04-18T20:15:44.357Z,1650312944.357 [NAL9602](INFO): Packets left to send: 0
2022-04-18T20:15:44.882Z,1650312944.882 [NAL9602](INFO): Received command: sched asap "set SpartonCompassCal.MaxDepth 9 m;run" 1k3c 2 2
2022-04-18T20:15:44.920Z,1650312944.920 [CommandExec](IMPORTANT): got command schedule asap "set SpartonCompassCal.MaxDepth 9 m;run" 1k3c 2 2.000000
2022-04-18T20:15:44.920Z,1650312944.920 [CommandExec](IMPORTANT): Scheduling command #2 of 2 with id=1k3c
2022-04-18T20:15:44.922Z,1650312944.922 [CommandExec](IMPORTANT): Scheduled #2 (#2 of 2 with id='1k3c'): "set SpartonCompassCal.MaxDepth 9 m;run", ASAP
2022-04-18T20:15:45.069Z,1650312945.069 [CommandExec](IMPORTANT): got command load ./Missions/Maintenance/calibrate_sparton_compass.xml
2022-04-18T20:15:45.070Z,1650312945.070 [MissionManager](INFO): Loading Mission from file: ./Missions/Maintenance/calibrate_sparton_compass.xml
2022-04-18T20:15:45.243Z,1650312945.243 [MissionManager](INFO): DefineArg SpartonCompassCal.MissionTimeout = 60.000000 min
2022-04-18T20:15:45.246Z,1650312945.246 [MissionManager](INFO): DefineArg SpartonCompassCal.NeedCommsTime = 60.000000 min
2022-04-18T20:15:45.250Z,1650312945.250 [MissionManager](INFO): DefineArg SpartonCompassCal.YoYoMinDepth = 5.000000 m
2022-04-18T20:15:45.253Z,1650312945.253 [MissionManager](INFO): DefineArg SpartonCompassCal.YoYoMaxDepth = 40.000000 m
2022-04-18T20:15:45.256Z,1650312945.256 [MissionManager](INFO): DefineArg SpartonCompassCal.YoYoMinAltitude = 7.000000 m
2022-04-18T20:15:45.259Z,1650312945.260 [MissionManager](INFO): DefineArg SpartonCompassCal.YoYoPitch = 20.000000 arcdeg
2022-04-18T20:15:45.263Z,1650312945.263 [MissionManager](INFO): DefineArg SpartonCompassCal.RudderAngle = 13.000000 arcdeg
2022-04-18T20:15:45.267Z,1650312945.267 [MissionManager](INFO): DefineArg SpartonCompassCal.Speed = 1.000000 m/s
2022-04-18T20:15:45.270Z,1650312945.270 [MissionManager](INFO): DefineArg SpartonCompassCal.CalibrationInitTimeout = 2.000000 min
2022-04-18T20:15:45.290Z,1650312945.290 [MissionManager](INFO): DefineArg SpartonCompassCal.MinAltitude = 5.000000 m
2022-04-18T20:15:45.305Z,1650312945.305 [MissionManager](INFO): DefineArg SpartonCompassCal.MaxDepth = 50.000000 m
2022-04-18T20:15:45.313Z,1650312945.313 [MissionManager](INFO): DefineArg SpartonCompassCal.MinOffshore = 2.000000 km
2022-04-18T20:15:45.313Z,1650312945.313 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/Science.xml
2022-04-18T20:15:45.672Z,1650312945.672 [MissionManager](INFO): DefineArg SpartonCompassCal:Science.PeakDetectChlActive = 0 bool
2022-04-18T20:15:45.675Z,1650312945.675 [MissionManager](INFO): DefineArg SpartonCompassCal:Science.TimeWindowPeakReport = nan min
2022-04-18T20:15:45.678Z,1650312945.678 [MissionManager](INFO): DefineArg SpartonCompassCal:Science.HighestChlPeakReportActive = 0 bool
2022-04-18T20:15:45.682Z,1650312945.682 [MissionManager](INFO): DefineArg SpartonCompassCal:Science.HighestSaltPeakReportActive = 0 bool
2022-04-18T20:15:45.685Z,1650312945.685 [MissionManager](INFO): DefineArg SpartonCompassCal:Science.HighestOilPeakReportActive = 0 bool
2022-04-18T20:15:45.688Z,1650312945.688 [MissionManager](INFO): DefineArg SpartonCompassCal:Science.PatchTracking = 0 bool
2022-04-18T20:15:45.691Z,1650312945.691 [MissionManager](INFO): DefineArg SpartonCompassCal:Science.DetectTrough = 0 bool
2022-04-18T20:15:45.694Z,1650312945.694 [MissionManager](INFO): DefineArg SpartonCompassCal:Science.FilterWidthHorizontal = 3.000000 count
2022-04-18T20:15:45.698Z,1650312945.698 [MissionManager](INFO): DefineArg SpartonCompassCal:Science.NumProfilesSlidingwindow = 100.000000 count
2022-04-18T20:15:45.725Z,1650312945.725 [MissionManager](INFO): DefineArg SpartonCompassCal:Science.OffPeakFractionHorizontal = 80.000000 %
2022-04-18T20:15:45.728Z,1650312945.728 [MissionManager](INFO): DefineArg SpartonCompassCal:Science.PeakDetectNO3Active = 0 bool
2022-04-18T20:15:45.736Z,1650312945.736 [MissionManager](INFO): DefineArg SpartonCompassCal:Science.PeakDetectOilActive = 0 bool
2022-04-18T20:15:45.743Z,1650312945.743 [MissionManager](INFO): DefineArg SpartonCompassCal:Science.PeakDetectFDOMActive = 0 bool
2022-04-18T20:15:45.747Z,1650312945.747 [MissionManager](INFO): DefineArg SpartonCompassCal:Science.PeakDetectSalinityActive = 0 bool
2022-04-18T20:15:45.763Z,1650312945.763 [MissionManager](INFO): DefineArg SpartonCompassCal:Science.UpwardDerivativeOfTemperatureActive = 0 bool
2022-04-18T20:15:45.768Z,1650312945.768 [MissionManager](INFO): DefineArg SpartonCompassCal:Science.EnabledAanderaaO2 = 0 bool
2022-04-18T20:15:45.780Z,1650312945.780 [MissionManager](INFO): DefineArg SpartonCompassCal:Science.EnabledNeilBrown = 0 bool
2022-04-18T20:15:45.788Z,1650312945.788 [MissionManager](INFO): DefineArg SpartonCompassCal:Science.EnabledSeabird = 1 bool
2022-04-18T20:15:45.800Z,1650312945.800 [MissionManager](INFO): DefineArg SpartonCompassCal:Science.EnabledWetLabsBB2FL = 0 bool
2022-04-18T20:15:45.804Z,1650312945.804 [MissionManager](INFO): DefineArg SpartonCompassCal:Science.EnabledWetLabsSeaOWL_UV_A = 1 bool
2022-04-18T20:15:45.817Z,1650312945.817 [MissionManager](INFO): DefineArg SpartonCompassCal:Science.EnabledWetLabsUBAT = 0 bool
2022-04-18T20:15:45.826Z,1650312945.826 [MissionManager](INFO): DefineArg SpartonCompassCal:Science.LowPassWindowLength = 20.000000 count
2022-04-18T20:15:45.830Z,1650312945.830 [MissionManager](INFO): DefineArg SpartonCompassCal:Science.MedianFilterLen = 5.000000 count
2022-04-18T20:15:45.841Z,1650312945.841 [MissionManager](INFO): DefineArg SpartonCompassCal:Science.PeakShallowBound = nan m
2022-04-18T20:15:45.844Z,1650312945.844 [MissionManager](INFO): DefineArg SpartonCompassCal:Science.PeakDeepBound = nan m
2022-04-18T20:15:45.863Z,1650312945.863 [MissionManager](INFO): DefineArg SpartonCompassCal:Science.DepChangeThreshForAttitudeFlip = 2.000000 m
2022-04-18T20:15:45.880Z,1650312945.880 [MissionManager](INFO): DefineOutput SpartonCompassCal:Science.PeakChl = 0.000000 ug/l
2022-04-18T20:15:45.920Z,1650312945.920 [MissionManager](INFO): DefineOutput SpartonCompassCal:Science.PeakChlDepth = 0.000000 m
2022-04-18T20:15:45.931Z,1650312945.931 [MissionManager](INFO): DefineOutput SpartonCompassCal:Science.PeakChlTemperature = 0.000000 degC
2022-04-18T20:15:45.943Z,1650312945.943 [MissionManager](INFO): DefineOutput SpartonCompassCal:Science.PeakChlLatitude = nan arcdeg
2022-04-18T20:15:45.971Z,1650312945.971 [MissionManager](INFO): DefineOutput SpartonCompassCal:Science.PeakChlLongitude = nan arcdeg
2022-04-18T20:15:45.986Z,1650312945.986 [MissionManager](INFO): DefineOutput SpartonCompassCal:Science.PeakNO3 = 0.000000 umol/l
2022-04-18T20:15:45.991Z,1650312945.991 [MissionManager](INFO): DefineOutput SpartonCompassCal:Science.PeakNO3Depth = 0.000000 m
2022-04-18T20:15:46.011Z,1650312946.011 [MissionManager](INFO): DefineOutput SpartonCompassCal:Science.PeakNO3Latitude = nan arcdeg
2022-04-18T20:15:46.018Z,1650312946.018 [MissionManager](INFO): DefineOutput SpartonCompassCal:Science.PeakNO3Longitude = nan arcdeg
2022-04-18T20:15:46.038Z,1650312946.038 [MissionManager](INFO): DefineOutput SpartonCompassCal:Science.PeakOil = 0.000000 kg/m3
2022-04-18T20:15:46.042Z,1650312946.042 [MissionManager](INFO): DefineOutput SpartonCompassCal:Science.PeakOilDepth = 0.000000 m
2022-04-18T20:15:46.053Z,1650312946.053 [MissionManager](INFO): DefineOutput SpartonCompassCal:Science.PeakOilLatitude = nan arcdeg
2022-04-18T20:15:46.061Z,1650312946.061 [MissionManager](INFO): DefineOutput SpartonCompassCal:Science.PeakOilLongitude = nan arcdeg
2022-04-18T20:15:46.064Z,1650312946.064 [MissionManager](INFO): DefineOutput SpartonCompassCal:Science.PeakFDOM = 0.000000 ppb
2022-04-18T20:15:46.072Z,1650312946.072 [MissionManager](INFO): DefineOutput SpartonCompassCal:Science.PeakFDOMDepth = 0.000000 m
2022-04-18T20:15:46.083Z,1650312946.083 [MissionManager](INFO): DefineOutput SpartonCompassCal:Science.PeakFDOMTemperature = nan degC
2022-04-18T20:15:46.088Z,1650312946.088 [MissionManager](INFO): DefineOutput SpartonCompassCal:Science.PeakFDOMLatitude = nan arcdeg
2022-04-18T20:15:46.099Z,1650312946.099 [MissionManager](INFO): DefineOutput SpartonCompassCal:Science.PeakFDOMLongitude = nan arcdeg
2022-04-18T20:15:46.104Z,1650312946.104 [MissionManager](INFO): DefineOutput SpartonCompassCal:Science.PatchFDOMDistance = nan m
2022-04-18T20:15:46.115Z,1650312946.115 [MissionManager](INFO): DefineOutput SpartonCompassCal:Science.PeakSalt = 0.000000 psu
2022-04-18T20:15:46.132Z,1650312946.132 [MissionManager](INFO): DefineOutput SpartonCompassCal:Science.PeakSaltDepth = 0.000000 m
2022-04-18T20:15:46.136Z,1650312946.136 [MissionManager](INFO): DefineOutput SpartonCompassCal:Science.PeakSaltTemperature = 0.000000 degC
2022-04-18T20:15:46.139Z,1650312946.139 [MissionManager](INFO): DefineOutput SpartonCompassCal:Science.PeakSaltLatitude = nan arcdeg
2022-04-18T20:15:46.155Z,1650312946.155 [MissionManager](INFO): DefineOutput SpartonCompassCal:Science.PeakSaltLongitude = nan arcdeg
2022-04-18T20:15:46.159Z,1650312946.159 [MissionManager](INFO): DefineOutput SpartonCompassCal:Science.PatchChl = 0.000000 ug/l
2022-04-18T20:15:46.173Z,1650312946.173 [MissionManager](INFO): DefineOutput SpartonCompassCal:Science.PatchChlDepth = 0.000000 m
2022-04-18T20:15:46.176Z,1650312946.176 [MissionManager](INFO): DefineOutput SpartonCompassCal:Science.PatchChlLatitude = nan arcdeg
2022-04-18T20:15:46.189Z,1650312946.189 [MissionManager](INFO): DefineOutput SpartonCompassCal:Science.PatchChlLongitude = nan arcdeg
2022-04-18T20:15:46.193Z,1650312946.193 [MissionManager](INFO): DefineOutput SpartonCompassCal:Science.PatchChlDistance = nan m
2022-04-18T20:15:46.196Z,1650312946.196 [MissionManager](INFO): DefineOutput SpartonCompassCal:Science.PatchSalt = 0.000000 psu
2022-04-18T20:15:46.218Z,1650312946.218 [MissionManager](INFO): DefineOutput SpartonCompassCal:Science.PatchSaltDepth = 0.000000 m
2022-04-18T20:15:46.226Z,1650312946.226 [MissionManager](INFO): DefineOutput SpartonCompassCal:Science.PatchSaltLatitude = nan arcdeg
2022-04-18T20:15:46.248Z,1650312946.248 [MissionManager](INFO): DefineOutput SpartonCompassCal:Science.PatchSaltLongitude = nan arcdeg
2022-04-18T20:15:46.251Z,1650312946.251 [MissionManager](INFO): DefineOutput SpartonCompassCal:Science.PatchSaltDistance = nan m
2022-04-18T20:15:46.255Z,1650312946.255 [MissionManager](INFO): DefineOutput SpartonCompassCal:Science.PatchOil = 0.000000 psu
2022-04-18T20:15:46.282Z,1650312946.282 [MissionManager](INFO): DefineOutput SpartonCompassCal:Science.PatchOilDepth = 0.000000 m
2022-04-18T20:15:46.286Z,1650312946.286 [MissionManager](INFO): DefineOutput SpartonCompassCal:Science.PatchOilLatitude = nan arcdeg
2022-04-18T20:15:46.289Z,1650312946.289 [MissionManager](INFO): DefineOutput SpartonCompassCal:Science.PatchOilLongitude = nan arcdeg
2022-04-18T20:15:46.297Z,1650312946.297 [MissionManager](INFO): DefineOutput SpartonCompassCal:Science.PatchOilDistance = nan m
2022-04-18T20:15:46.380Z,1650312946.380 [SpartonCompassCal:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2022-04-18T20:15:46.412Z,1650312946.412 [SpartonCompassCal:Science:HighestChlPeakReport:A.PeakDetectHorizontal](DEBUG): Construct PeakDetectHorizontal.
2022-04-18T20:15:46.444Z,1650312946.444 [SpartonCompassCal:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2022-04-18T20:15:46.474Z,1650312946.474 [SpartonCompassCal:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2022-04-18T20:15:46.505Z,1650312946.505 [SpartonCompassCal:Science:HighestOilPeakReport:A.PeakDetectHorizontal](DEBUG): Construct PeakDetectHorizontal.
2022-04-18T20:15:46.526Z,1650312946.526 [SpartonCompassCal:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2022-04-18T20:15:46.566Z,1650312946.566 [SpartonCompassCal:Science:PeakDetectSalinity:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2022-04-18T20:15:46.590Z,1650312946.590 [SpartonCompassCal:Science:HighestSaltPeakReport:A.PeakDetectHorizontal](DEBUG): Construct PeakDetectHorizontal.
2022-04-18T20:15:46.614Z,1650312946.614 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/NeedComms.xml
2022-04-18T20:15:46.769Z,1650312946.769 [MissionManager](INFO): DefineArg SpartonCompassCal:NeedComms.DiveInterval = 3.000000 h
2022-04-18T20:15:46.785Z,1650312946.785 [MissionManager](INFO): DefineArg SpartonCompassCal:NeedComms.WaitForPitchUp = 10.000000 min
2022-04-18T20:15:46.788Z,1650312946.788 [MissionManager](INFO): DefineArg SpartonCompassCal:NeedComms.SurfacePitch = 20.000000 arcdeg
2022-04-18T20:15:46.800Z,1650312946.800 [MissionManager](INFO): DefineArg SpartonCompassCal:NeedComms.SurfaceDepthRate = nan m/s
2022-04-18T20:15:46.812Z,1650312946.812 [MissionManager](INFO): DefineArg SpartonCompassCal:NeedComms.SurfaceSpeed = 1.000000 m/s
2022-04-18T20:15:46.839Z,1650312946.839 [MissionManager](INFO): DefineArg SpartonCompassCal:NeedComms.GPSTimeout = 7.000000 min
2022-04-18T20:15:46.847Z,1650312946.847 [MissionManager](INFO): DefineArg SpartonCompassCal:NeedComms.CommsTimeout = 30.000000 min
2022-04-18T20:15:46.904Z,1650312946.904 [SpartonCompassCal:NeedComms:B.GoToSurface](DEBUG): Construct GoToSurface.
2022-04-18T20:15:46.938Z,1650312946.938 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/StandardEnvelopes.xml
2022-04-18T20:15:46.983Z,1650312946.983 [MissionManager](INFO): DefineArg SpartonCompassCal:StandardEnvelopes.MinAltitude = 5.000000 m
2022-04-18T20:15:46.987Z,1650312946.987 [MissionManager](INFO): DefineArg SpartonCompassCal:StandardEnvelopes.MaxDepth = 200.000000 m
2022-04-18T20:15:47.002Z,1650312947.002 [MissionManager](INFO): DefineArg SpartonCompassCal:StandardEnvelopes.MinOffshore = 2000.000000 m
2022-04-18T20:15:47.003Z,1650312947.003 [SpartonCompassCal:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope.
2022-04-18T20:15:47.026Z,1650312947.026 [SpartonCompassCal:StandardEnvelopes:B.DepthEnvelope](DEBUG): Construct DepthEnvelope.
2022-04-18T20:15:47.043Z,1650312947.043 [SpartonCompassCal:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Construct OffshoreEnvelope.
2022-04-18T20:15:47.081Z,1650312947.081 [SpartonCompassCal:I.Pitch](DEBUG): Construct.
2022-04-18T20:15:47.088Z,1650312947.088 [SpartonCompassCal:J.Buoyancy](DEBUG): Construct Buoyancy.
2022-04-18T20:15:47.100Z,1650312947.100 [SpartonCompassCal:K.DepthEnvelope](DEBUG): Construct DepthEnvelope.
2022-04-18T20:15:47.169Z,1650312947.169 [SpartonCompassCal:L.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope.
2022-04-18T20:15:47.198Z,1650312947.198 [SpartonCompassCal:M.YoYo](DEBUG): Construct YoYo.
2022-04-18T20:15:47.229Z,1650312947.229 [SpartonCompassCal:AdaptCal:WaitForCalibrationInit:A_Timeout:B.Execute](DEBUG): Construct Execute.
2022-04-18T20:15:47.232Z,1650312947.232 [SpartonCompassCal:AdaptCal:AcquireCalibrationPoints:A.Point](DEBUG): Construct.
2022-04-18T20:15:47.247Z,1650312947.247 [SpartonCompassCal:AdaptCal:AcquireCalibrationPoints:B.SetSpeed](DEBUG): Construct.
2022-04-18T20:15:47.265Z,1650312947.265 [SpartonCompassCal:AdaptCal:C.CalibrateAHRS_M2](DEBUG): Construct CalibrateSparton.
2022-04-18T20:15:47.323Z,1650312947.323 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
    xmlns:Control="Tethys/Control"
    xmlns:Derivation="Tethys/Derivation"
    xmlns:Estimation="Tethys/Estimation"
    xmlns:Guidance="Tethys/Guidance"
    xmlns:Sensor="Tethys/Sensor"
    xmlns:Units="Tethys/Units"
    xmlns:Universal="Tethys/Universal"
    xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
    xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
    Tethys/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd
    Tethys/Derivation http://okeanids.mbari.org/tethys/Xml/Derivation.xsd
    Tethys/Estimation http://okeanids.mbari.org/tethys/Xml/Estimation.xsd
    Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
    Tethys/Sensor http://okeanids.mbari.org/tethys/Xml/Sensor.xsd
    Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
    Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
    Id="SpartonCompassCal">

    <Description>
        This mission yoyos in a spiral while calibrating the Sparton AHRS-M2
        Micro AHRS/IMU with AdaptCal.
    </Description>

<!-- Mission-wide settings -->

    <DefineArg Name="MissionTimeout"><Description>
        Maximum duration of mission
    </Description><Units:minute/><Value>60</Value></DefineArg>

    <DefineArg Name="NeedCommsTime"><Description>
        Elapsed time after previous surface communications when vehicle will
        begin to ascend for additional surface communications
    </Description><Units:minute/><Value>60</Value></DefineArg>

<!-- You probably need to change these. -->

<!-- You probably do not need to change these. -->

    <DefineArg Name="YoYoMinDepth"><Description>
        Minimum depth while performing the YoYo behavior.
    </Description><Units:meter/><Value>5</Value></DefineArg>

    <DefineArg Name="YoYoMaxDepth"><Description>
        Maximum depth while performing the YoYo behavior.
    </Description><Units:meter/><Value>40</Value></DefineArg>

    <DefineArg Name="YoYoMinAltitude"><Description>
        Minimum altitude while performing the YoYo behavior (for
        bottom-terminated YoYos).
    </Description><Units:meter/><Value>7</Value></DefineArg>

    <DefineArg Name="YoYoPitch"><Description>
        Pitch (plus and minus) for yo-yo behavior.
    </Description><Units:degree/><Value>20</Value></DefineArg>

    <DefineArg Name="RudderAngle"><Description>
        Rudder angle to use while performing the spiral cast.
    </Description><Units:degree/><Value>13</Value></DefineArg>

    <DefineArg Name="Speed"><Description>
        Vehicle speed.
    </Description><Units:meter_per_second/><Value>1</Value></DefineArg>

    <DefineArg Name="CalibrationInitTimeout"><Description>
        Elapsed time allowed for calibration to initialize
    </Description><Units:minute/><Value>2</Value></DefineArg>

<!-- You are even less likely to need to change these. -->

    <DefineArg Name="MinAltitude"><Description>
        Minimum height above the sea floor for the entire mission.
    </Description><Units:meter/><Value>5</Value></DefineArg>

    <DefineArg Name="MaxDepth"><Description>
        Maximum depth for the entire mission.
    </Description><Units:meter/><Value>50</Value></DefineArg>

    <DefineArg Name="MinOffshore"><Description>
        Minimum offshore distance for the entire mission.
    </Description><Units:kilometer/><Value>2</Value></DefineArg>

<!-- Missions should almost always start with a timeout -->

    <Timeout Duration="MissionTimeout"/>

    <Insert Filename="Insert/Science.xml">
        <Description>
            Most missions will run the science sensors. If you don't place this
            aggregate above NeedComms, science instruments get turned off on the
            last upcast and while floating on the surface.
        </Description>
    </Insert>

<!-- Most missions should use the NeedComms aggregate. -->

    <Insert Filename="Insert/NeedComms.xml" Id="NeedComms"/>

    <Assign><Sequence/><Arg Name="NeedComms:DiveInterval"/><Arg Name="NeedCommsTime"/></Assign>

<!-- Missions should almost always start with standard safety envelopes; most missions should not expose the parameters of these envelopes. -->

    <Insert Filename="Insert/StandardEnvelopes.xml"/>

    <Assign><Sequence/><Arg Name="StandardEnvelopes:MinAltitude"/><Arg Name="MinAltitude"/></Assign>

    <Assign><Sequence/><Arg Name="StandardEnvelopes:MaxDepth"/><Arg Name="MaxDepth"/></Assign>

    <Assign><Sequence/><Arg Name="StandardEnvelopes:MinOffshore"/><Arg Name="MinOffshore"/></Assign>

<!-- Check for additional instructions first. -->

    <Call Id="StartingMission" RefId="NeedComms"/>

<!-- Many missions will keep mass position and buoyancy volume fixed at defaults. -->

    <Guidance:Pitch>
        <Parallel/>
        <Setting><Guidance:Pitch.massPosition/><Control:VerticalControl.massDefault/></Setting>
    </Guidance:Pitch>

    <Guidance:Buoyancy>
        <Parallel/>
        <Setting><Guidance:Buoyancy.position/><Control:VerticalControl.buoyancyNeutral/></Setting>
    </Guidance:Buoyancy>

    <Guidance:DepthEnvelope>
        <Description>
            Another depth envelope for the YoYo behavior. This envelope should
            fall within the limits of the standard safety envelopes in
            Insert/StandardEnvelopes.xml in order to avoid commanding high pitch
            angles for depth-terminated YoYos.
        </Description>
        <Parallel/>
        <Setting><Guidance:DepthEnvelope.minDepth/><Arg Name="YoYoMinDepth"/></Setting>
        <Setting><Guidance:DepthEnvelope.maxDepth/><Arg Name="YoYoMaxDepth"/></Setting>
        <Setting><Guidance:DepthEnvelope.pitch/><Arg Name="YoYoPitch"/></Setting>
    </Guidance:DepthEnvelope>

    <Guidance:AltitudeEnvelope>
        <Description>
            Another altitude envelope for the YoYo behavior. This envelope
            should fall within the limits of the standard safety envelopes in
            Insert/StandardEnvelopes.xml in order to avoid commanding high pitch
            angles for bottom-terminated YoYos.
        </Description>
        <Parallel/>
        <Setting><Guidance:AltitudeEnvelope.minAltitude/><Arg Name="YoYoMinAltitude"/></Setting>
        <Setting><Guidance:AltitudeEnvelope.pitch/><Arg Name="YoYoPitch"/></Setting>
    </Guidance:AltitudeEnvelope>

    <Guidance:YoYo>
        <Parallel/>
        <Setting><Guidance:YoYo.pitch/><Arg Name="YoYoPitch"/></Setting>
    </Guidance:YoYo>

    <Aggregate Id="AdaptCal">

        <Sequence/>

        <ReadDatum Id="WaitForCalibrationInit">
            <Timeout Duration="CalibrationInitTimeout">
                <Syslog Severity="Important">Failed to initialize calibration within timeout. Stopping mission.</Syslog>
                <Guidance:Execute>
                    <Sequence/>
                    <Setting><Guidance:Execute.command/><String>stop</String></Setting>
                </Guidance:Execute>
            </Timeout>
            <Sensor:AHRS_M2.number_of_calbration_points/>
        </ReadDatum>

        <Aggregate Id="AcquireCalibrationPoints">

            <Sequence/>

            <Guidance:Point>
                <Parallel/>
                <Setting><Guidance:Point.rudderAngle/><Arg Name="RudderAngle"/></Setting>
            </Guidance:Point>

            <Guidance:SetSpeed>
                <Parallel/>
                <Setting><Guidance:SetSpeed.speed/><Arg Name="Speed"/></Setting>
            </Guidance:SetSpeed>

        </Aggregate>

        <Sensor:CalibrateAHRS_M2>
            <Parallel/>
        </Sensor:CalibrateAHRS_M2>

    </Aggregate>

</Mission>


2022-04-18T20:15:47.324Z,1650312947.324 [CommandExec](IMPORTANT): Loaded ./Missions/Maintenance/calibrate_sparton_compass.xml
2022-04-18T20:15:54.404Z,1650312954.404 [NAL9602](INFO): SBD MO Status=0, MOMSN=36087, MT Status=0, MTMSN=0
2022-04-18T20:15:59.741Z,1650312959.741 [CommandExec](IMPORTANT): got command set SpartonCompassCal.YoYoMinDepth 3 meter
2022-04-18T20:15:59.742Z,1650312959.742 [CommandExec](IMPORTANT): got command set SpartonCompassCal.YoYoMaxDepth 7 meter
2022-04-18T20:15:59.742Z,1650312959.742 [CommandExec](IMPORTANT): got command set SpartonCompassCal.YoYoMinAltitude 3 meter
2022-04-18T20:15:59.743Z,1650312959.743 [CommandExec](IMPORTANT): got command set SpartonCompassCal.MinAltitude 4 meter
2022-04-18T20:16:01.718Z,1650312961.718 [CommandExec](IMPORTANT): got command set SpartonCompassCal.MaxDepth 9 meter
2022-04-18T20:16:01.719Z,1650312961.719 [CommandExec](IMPORTANT): got command run
2022-04-18T20:16:01.722Z,1650312961.722 [CommandExec](IMPORTANT): Running 
2022-04-18T20:16:01.974Z,1650312961.974 [Default] Stopped
2022-04-18T20:16:01.975Z,1650312961.975 [Default](DEBUG): Aggregate::uninitialize Default
2022-04-18T20:16:01.975Z,1650312961.975 [Default:B.GoToSurface] Stopped
2022-04-18T20:16:01.975Z,1650312961.975 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2022-04-18T20:16:01.975Z,1650312961.975 [Default:CheckIn] Stopped
2022-04-18T20:16:01.975Z,1650312961.975 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-04-18T20:16:01.975Z,1650312961.975 [Default:CheckIn:Read_Iridium] Stopped
2022-04-18T20:16:01.975Z,1650312961.975 [MissionManager](IMPORTANT): Started mission SpartonCompassCal
2022-04-18T20:16:01.975Z,1650312961.975 [SpartonCompassCal] Running Loop=1
2022-04-18T20:16:01.976Z,1650312961.976 [SpartonCompassCal](DEBUG): Aggregate::initialize SpartonCompassCal
2022-04-18T20:16:01.976Z,1650312961.976 [SpartonCompassCal:Science] Running Loop=1
2022-04-18T20:16:01.976Z,1650312961.976 [SpartonCompassCal:Science](DEBUG): Aggregate::initialize SpartonCompassCal:Science
2022-04-18T20:16:01.976Z,1650312961.976 [SpartonCompassCal:Science:A] Running Loop=1
2022-04-18T20:16:01.976Z,1650312961.976 [SpartonCompassCal:Science:B] Running Loop=1
2022-04-18T20:16:01.976Z,1650312961.976 [SpartonCompassCal:Science:C] Running Loop=1
2022-04-18T20:16:01.976Z,1650312961.976 [SpartonCompassCal:Science:D] Running Loop=1
2022-04-18T20:16:01.976Z,1650312961.976 [SpartonCompassCal:Science:E] Running Loop=1
2022-04-18T20:16:01.976Z,1650312961.976 [SpartonCompassCal:Science:F] Running Loop=1
2022-04-18T20:16:01.976Z,1650312961.976 [SpartonCompassCal:Science:Read_Oil] Running Loop=1
2022-04-18T20:16:01.976Z,1650312961.976 [SpartonCompassCal:Science:PeakDetectChl] Running Loop=1
2022-04-18T20:16:01.977Z,1650312961.977 [SpartonCompassCal:Science:PeakDetectChl](DEBUG): Aggregate::initialize SpartonCompassCal:Science:PeakDetectChl
2022-04-18T20:16:01.977Z,1650312961.977 [SpartonCompassCal:Science:PeakDetectChl:A.PeakDetectVsDepth] Running Loop=1
2022-04-18T20:16:01.977Z,1650312961.977 [SpartonCompassCal:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Initialize.
2022-04-18T20:16:01.978Z,1650312961.978 [SpartonCompassCal:Science:HighestChlPeakReport] Running Loop=1
2022-04-18T20:16:01.979Z,1650312961.979 [SpartonCompassCal:Science:HighestChlPeakReport](DEBUG): Aggregate::initialize SpartonCompassCal:Science:HighestChlPeakReport
2022-04-18T20:16:01.979Z,1650312961.979 [SpartonCompassCal:Science:HighestChlPeakReport:A.PeakDetectHorizontal] Running Loop=1
2022-04-18T20:16:01.979Z,1650312961.979 [SpartonCompassCal:Science:HighestChlPeakReport:A.PeakDetectHorizontal](INFO): Initialize.
2022-04-18T20:16:01.979Z,1650312961.979 [SpartonCompassCal:Science:PeakDetectNO3] Running Loop=1
2022-04-18T20:16:01.979Z,1650312961.979 [SpartonCompassCal:Science:PeakDetectNO3](DEBUG): Aggregate::initialize SpartonCompassCal:Science:PeakDetectNO3
2022-04-18T20:16:01.979Z,1650312961.979 [SpartonCompassCal:Science:PeakDetectNO3:A.PeakDetectVsDepth] Running Loop=1
2022-04-18T20:16:01.980Z,1650312961.980 [SpartonCompassCal:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Initialize.
2022-04-18T20:16:01.981Z,1650312961.981 [SpartonCompassCal:Science:PeakDetectOil] Running Loop=1
2022-04-18T20:16:01.981Z,1650312961.981 [SpartonCompassCal:Science:PeakDetectOil](DEBUG): Aggregate::initialize SpartonCompassCal:Science:PeakDetectOil
2022-04-18T20:16:01.982Z,1650312961.982 [SpartonCompassCal:Science:PeakDetectOil:A.PeakDetectVsDepth] Running Loop=1
2022-04-18T20:16:01.982Z,1650312961.982 [SpartonCompassCal:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Initialize.
2022-04-18T20:16:01.983Z,1650312961.983 [SpartonCompassCal:Science:HighestOilPeakReport] Running Loop=1
2022-04-18T20:16:01.983Z,1650312961.983 [SpartonCompassCal:Science:HighestOilPeakReport](DEBUG): Aggregate::initialize SpartonCompassCal:Science:HighestOilPeakReport
2022-04-18T20:16:01.983Z,1650312961.983 [SpartonCompassCal:Science:HighestOilPeakReport:A.PeakDetectHorizontal] Running Loop=1
2022-04-18T20:16:01.983Z,1650312961.983 [SpartonCompassCal:Science:HighestOilPeakReport:A.PeakDetectHorizontal](INFO): Initialize.
2022-04-18T20:16:01.984Z,1650312961.984 [SpartonCompassCal:Science:PeakDetectFDOM] Running Loop=1
2022-04-18T20:16:01.984Z,1650312961.984 [SpartonCompassCal:Science:PeakDetectFDOM](DEBUG): Aggregate::initialize SpartonCompassCal:Science:PeakDetectFDOM
2022-04-18T20:16:01.984Z,1650312961.984 [SpartonCompassCal:Science:PeakDetectFDOM:A.PeakDetectVsDepth] Running Loop=1
2022-04-18T20:16:01.984Z,1650312961.984 [SpartonCompassCal:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Initialize.
2022-04-18T20:16:01.986Z,1650312961.986 [SpartonCompassCal:Science:PeakDetectSalinity] Running Loop=1
2022-04-18T20:16:01.986Z,1650312961.986 [SpartonCompassCal:Science:PeakDetectSalinity](DEBUG): Aggregate::initialize SpartonCompassCal:Science:PeakDetectSalinity
2022-04-18T20:16:01.986Z,1650312961.986 [SpartonCompassCal:Science:PeakDetectSalinity:A.PeakDetectVsDepth] Running Loop=1
2022-04-18T20:16:01.986Z,1650312961.986 [SpartonCompassCal:Science:PeakDetectSalinity:A.PeakDetectVsDepth](DEBUG): Initialize.
2022-04-18T20:16:01.988Z,1650312961.988 [SpartonCompassCal:Science:HighestSaltPeakReport] Running Loop=1
2022-04-18T20:16:01.988Z,1650312961.988 [SpartonCompassCal:Science:HighestSaltPeakReport](DEBUG): Aggregate::initialize SpartonCompassCal:Science:HighestSaltPeakReport
2022-04-18T20:16:01.988Z,1650312961.988 [SpartonCompassCal:Science:HighestSaltPeakReport:A.PeakDetectHorizontal] Running Loop=1
2022-04-18T20:16:01.988Z,1650312961.988 [SpartonCompassCal:Science:HighestSaltPeakReport:A.PeakDetectHorizontal](INFO): Initialize.
2022-04-18T20:16:01.989Z,1650312961.989 [SpartonCompassCal:Science:OceanCurrent] Running Loop=1
2022-04-18T20:16:01.989Z,1650312961.989 [SpartonCompassCal:Science:OceanCurrent](DEBUG): Aggregate::initialize SpartonCompassCal:Science:OceanCurrent
2022-04-18T20:16:01.989Z,1650312961.989 [SpartonCompassCal:Science:OceanCurrent:A.] Running Loop=1
2022-04-18T20:16:01.989Z,1650312961.989 [SpartonCompassCal:Science:OceanCurrent:A.](INFO): Initializing CurrentEstimator.
2022-04-18T20:16:01.989Z,1650312961.989 [SpartonCompassCal:StandardEnvelopes] Running Loop=1
2022-04-18T20:16:01.989Z,1650312961.989 [SpartonCompassCal:StandardEnvelopes](DEBUG): Aggregate::initialize SpartonCompassCal:StandardEnvelopes
2022-04-18T20:16:01.989Z,1650312961.989 [SpartonCompassCal:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1
2022-04-18T20:16:01.989Z,1650312961.989 [SpartonCompassCal:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent.
2022-04-18T20:16:01.989Z,1650312961.989 [SpartonCompassCal:StandardEnvelopes:B.DepthEnvelope] Running Loop=1
2022-04-18T20:16:01.990Z,1650312961.990 [SpartonCompassCal:StandardEnvelopes:B.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent.
2022-04-18T20:16:01.990Z,1650312961.990 [SpartonCompassCal:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1
2022-04-18T20:16:01.990Z,1650312961.990 [SpartonCompassCal:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Initialize OffshoreEnvelopeComponent.
2022-04-18T20:16:01.990Z,1650312961.990 [SpartonCompassCal:I.Pitch] Running Loop=1
2022-04-18T20:16:01.990Z,1650312961.990 [SpartonCompassCal:I.Pitch](DEBUG): Initialize.
2022-04-18T20:16:01.990Z,1650312961.990 [SpartonCompassCal:J.Buoyancy] Running Loop=1
2022-04-18T20:16:01.990Z,1650312961.990 [SpartonCompassCal:J.Buoyancy](DEBUG): Initialize Buoyancy Component.
2022-04-18T20:16:01.990Z,1650312961.990 [SpartonCompassCal:K.DepthEnvelope] Running Loop=1
2022-04-18T20:16:01.990Z,1650312961.990 [SpartonCompassCal:K.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent.
2022-04-18T20:16:01.991Z,1650312961.991 [SpartonCompassCal:L.AltitudeEnvelope] Running Loop=1
2022-04-18T20:16:01.991Z,1650312961.991 [SpartonCompassCal:L.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent.
2022-04-18T20:16:01.991Z,1650312961.991 [SpartonCompassCal:M.YoYo] Running Loop=1
2022-04-18T20:16:01.991Z,1650312961.991 [SpartonCompassCal:M.YoYo](DEBUG): Initialize YoYoComponent.
2022-04-18T20:16:01.991Z,1650312961.991 [SpartonCompassCal:C] Running Loop=1
2022-04-18T20:16:01.992Z,1650312961.992 [SpartonCompassCal:M.YoYo] Running Loop=1
2022-04-18T20:16:01.992Z,1650312961.992 [SpartonCompassCal:L.AltitudeEnvelope] Running Loop=1
2022-04-18T20:16:01.993Z,1650312961.993 [SpartonCompassCal:K.DepthEnvelope] Running Loop=1
2022-04-18T20:16:01.994Z,1650312961.994 [SpartonCompassCal:J.Buoyancy] Running Loop=1
2022-04-18T20:16:01.994Z,1650312961.994 [SpartonCompassCal:I.Pitch] Running Loop=1
2022-04-18T20:16:01.994Z,1650312961.994 [SpartonCompassCal:StandardEnvelopes] Running Loop=1
2022-04-18T20:16:01.994Z,1650312961.994 [SpartonCompassCal:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1
2022-04-18T20:16:01.994Z,1650312961.994 [SpartonCompassCal:StandardEnvelopes:B.DepthEnvelope] Running Loop=1
2022-04-18T20:16:01.995Z,1650312961.995 [SpartonCompassCal:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1
2022-04-18T20:16:01.995Z,1650312961.995 [SpartonCompassCal:C] Stopped
2022-04-18T20:16:01.995Z,1650312961.995 [SpartonCompassCal:E] Running Loop=1
2022-04-18T20:16:01.995Z,1650312961.995 [SpartonCompassCal:Science] Running Loop=1
2022-04-18T20:16:01.996Z,1650312961.996 [SpartonCompassCal:Science:HighestSaltPeakReport] Stopped
2022-04-18T20:16:01.997Z,1650312961.997 [SpartonCompassCal:Science:HighestSaltPeakReport](DEBUG): Aggregate::uninitialize SpartonCompassCal:Science:HighestSaltPeakReport
2022-04-18T20:16:01.997Z,1650312961.997 [SpartonCompassCal:Science:HighestSaltPeakReport:A.PeakDetectHorizontal] Stopped
2022-04-18T20:16:01.997Z,1650312961.997 [SpartonCompassCal:Science:HighestSaltPeakReport:A.PeakDetectHorizontal](DEBUG): Uninitialize.
2022-04-18T20:16:01.997Z,1650312961.997 [SpartonCompassCal:Science:PeakDetectSalinity] Stopped
2022-04-18T20:16:01.997Z,1650312961.997 [SpartonCompassCal:Science:PeakDetectSalinity](DEBUG): Aggregate::uninitialize SpartonCompassCal:Science:PeakDetectSalinity
2022-04-18T20:16:01.997Z,1650312961.997 [SpartonCompassCal:Science:PeakDetectSalinity:A.PeakDetectVsDepth] Stopped
2022-04-18T20:16:01.997Z,1650312961.997 [SpartonCompassCal:Science:PeakDetectSalinity:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2022-04-18T20:16:01.997Z,1650312961.997 [SpartonCompassCal:Science:PeakDetectFDOM] Stopped
2022-04-18T20:16:01.997Z,1650312961.997 [SpartonCompassCal:Science:PeakDetectFDOM](DEBUG): Aggregate::uninitialize SpartonCompassCal:Science:PeakDetectFDOM
2022-04-18T20:16:01.997Z,1650312961.997 [SpartonCompassCal:Science:PeakDetectFDOM:A.PeakDetectVsDepth] Stopped
2022-04-18T20:16:01.997Z,1650312961.997 [SpartonCompassCal:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2022-04-18T20:16:01.998Z,1650312961.998 [SpartonCompassCal:Science:HighestOilPeakReport] Stopped
2022-04-18T20:16:01.998Z,1650312961.998 [SpartonCompassCal:Science:HighestOilPeakReport](DEBUG): Aggregate::uninitialize SpartonCompassCal:Science:HighestOilPeakReport
2022-04-18T20:16:01.998Z,1650312961.998 [SpartonCompassCal:Science:HighestOilPeakReport:A.PeakDetectHorizontal] Stopped
2022-04-18T20:16:01.998Z,1650312961.998 [SpartonCompassCal:Science:HighestOilPeakReport:A.PeakDetectHorizontal](DEBUG): Uninitialize.
2022-04-18T20:16:01.998Z,1650312961.998 [SpartonCompassCal:Science:PeakDetectOil] Stopped
2022-04-18T20:16:01.998Z,1650312961.998 [SpartonCompassCal:Science:PeakDetectOil](DEBUG): Aggregate::uninitialize SpartonCompassCal:Science:PeakDetectOil
2022-04-18T20:16:01.998Z,1650312961.998 [SpartonCompassCal:Science:PeakDetectOil:A.PeakDetectVsDepth] Stopped
2022-04-18T20:16:01.998Z,1650312961.998 [SpartonCompassCal:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2022-04-18T20:16:01.998Z,1650312961.998 [SpartonCompassCal:Science:PeakDetectNO3] Stopped
2022-04-18T20:16:01.998Z,1650312961.998 [SpartonCompassCal:Science:PeakDetectNO3](DEBUG): Aggregate::uninitialize SpartonCompassCal:Science:PeakDetectNO3
2022-04-18T20:16:01.998Z,1650312961.998 [SpartonCompassCal:Science:PeakDetectNO3:A.PeakDetectVsDepth] Stopped
2022-04-18T20:16:01.998Z,1650312961.998 [SpartonCompassCal:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2022-04-18T20:16:01.999Z,1650312961.999 [SpartonCompassCal:Science:HighestChlPeakReport] Stopped
2022-04-18T20:16:01.999Z,1650312961.999 [SpartonCompassCal:Science:HighestChlPeakReport](DEBUG): Aggregate::uninitialize SpartonCompassCal:Science:HighestChlPeakReport
2022-04-18T20:16:01.999Z,1650312961.999 [SpartonCompassCal:Science:HighestChlPeakReport:A.PeakDetectHorizontal] Stopped
2022-04-18T20:16:01.999Z,1650312961.999 [SpartonCompassCal:Science:HighestChlPeakReport:A.PeakDetectHorizontal](DEBUG): Uninitialize.
2022-04-18T20:16:01.999Z,1650312961.999 [SpartonCompassCal:Science:PeakDetectChl] Stopped
2022-04-18T20:16:01.999Z,1650312961.999 [SpartonCompassCal:Science:PeakDetectChl](DEBUG): Aggregate::uninitialize SpartonCompassCal:Science:PeakDetectChl
2022-04-18T20:16:01.999Z,1650312961.999 [SpartonCompassCal:Science:PeakDetectChl:A.PeakDetectVsDepth] Stopped
2022-04-18T20:16:01.999Z,1650312961.999 [SpartonCompassCal:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2022-04-18T20:16:01.999Z,1650312961.999 [SpartonCompassCal:Science:OceanCurrent:A.] Running Loop=1
2022-04-18T20:16:02.000Z,1650312962.000 [SpartonCompassCal:Science:Read_Oil] Running Loop=1
2022-04-18T20:16:02.001Z,1650312962.001 [SpartonCompassCal:Science:Read_Oil](DEBUG): Initialize ReadDataComponent to sense mass_concentration_of_petroleum_hydrocarbons_in_sea_water
2022-04-18T20:16:02.001Z,1650312962.001 [SpartonCompassCal:Science:F] Stopped
2022-04-18T20:16:02.001Z,1650312962.001 [SpartonCompassCal:Science:E] Stopped
2022-04-18T20:16:02.001Z,1650312962.001 [SpartonCompassCal:Science:D] Stopped
2022-04-18T20:16:02.002Z,1650312962.002 [SpartonCompassCal:Science:C] Running Loop=1
2022-04-18T20:16:02.002Z,1650312962.002 [SpartonCompassCal:Science:C](DEBUG): Initialize ReadDataComponent to sense CTD_Seabird.sea_water_temperature
2022-04-18T20:16:02.003Z,1650312962.003 [SpartonCompassCal:Science:C](DEBUG): Initialize ReadDataComponent to sense CTD_Seabird.sea_water_salinity
2022-04-18T20:16:02.003Z,1650312962.003 [SpartonCompassCal:Science:B] Running Loop=1
2022-04-18T20:16:02.004Z,1650312962.004 [SpartonCompassCal:Science:B](DEBUG): Initialize ReadDataComponent to sense sea_water_temperature
2022-04-18T20:16:02.004Z,1650312962.004 [SpartonCompassCal:Science:B](DEBUG): Initialize ReadDataComponent to sense sea_water_salinity
2022-04-18T20:16:02.025Z,1650312962.025 [SpartonCompassCal:Science:A] Stopped
2022-04-18T20:16:02.128Z,1650312962.128 [SpartonCompassCal:E] Stopped
2022-04-18T20:16:02.128Z,1650312962.128 [SpartonCompassCal:F] Running Loop=1
2022-04-18T20:16:02.536Z,1650312962.536 [SpartonCompassCal:F] Stopped
2022-04-18T20:16:02.536Z,1650312962.536 [SpartonCompassCal:G] Running Loop=1
2022-04-18T20:16:02.977Z,1650312962.977 [SpartonCompassCal:G] Stopped
2022-04-18T20:16:02.977Z,1650312962.977 [SpartonCompassCal:StartingMission] Running Loop=1
2022-04-18T20:16:02.977Z,1650312962.977 [SpartonCompassCal:StartingMission](DEBUG): Aggregate::initialize SpartonCompassCal:StartingMission
2022-04-18T20:16:03.289Z,1650312963.289 [SpartonCompassCal:NeedComms] Running Loop=1
2022-04-18T20:16:03.289Z,1650312963.289 [SpartonCompassCal:NeedComms](DEBUG): Aggregate::initialize SpartonCompassCal:NeedComms
2022-04-18T20:16:03.289Z,1650312963.289 [SpartonCompassCal:NeedComms:B.GoToSurface] Running Loop=1
2022-04-18T20:16:03.289Z,1650312963.289 [SpartonCompassCal:NeedComms:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2022-04-18T20:16:03.290Z,1650312963.290 [SpartonCompassCal:NeedComms:B.GoToSurface](INFO): Received depth rate setting nan m/s.
2022-04-18T20:16:03.290Z,1650312963.290 [SpartonCompassCal:NeedComms:B.GoToSurface](INFO): Received pitch setting 19.999999 degrees.
2022-04-18T20:16:03.290Z,1650312963.290 [SpartonCompassCal:NeedComms:B.GoToSurface](INFO): Received speed setting 1.000000 m/s.
2022-04-18T20:16:03.291Z,1650312963.291 [SpartonCompassCal:NeedComms:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2022-04-18T20:16:03.291Z,1650312963.291 [SpartonCompassCal:NeedComms:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2022-04-18T20:16:03.291Z,1650312963.291 [SpartonCompassCal:NeedComms:A] Running Loop=1
2022-04-18T20:16:03.292Z,1650312963.292 [SpartonCompassCal:NeedComms:A](INFO): last time_fix was: 1650312918.000000 second since 1970/01/01T00:00:00Z 
2022-04-18T20:16:03.293Z,1650312963.293 [SpartonCompassCal:NeedComms:A] Stopped
2022-04-18T20:16:03.706Z,1650312963.706 [SpartonCompassCal:NeedComms:C] Running Loop=1
2022-04-18T20:16:04.117Z,1650312964.117 [SpartonCompassCal:NeedComms:C](DEBUG): Initialize ReadDataComponent to sense time_fix
2022-04-18T20:16:05.347Z,1650312965.347 [CTD_Seabird](ERROR): Failed to parse device response: <!--startlogging-->
2022-04-18T20:16:07.317Z,1650312967.317 [NAL9602](INFO): SBD MO Status=1, MOMSN=36088, MT Status=0, MTMSN=0
2022-04-18T20:16:07.373Z,1650312967.373 [NAL9602](INFO): Sent 52 bytes from file Logs/20220418T193203/Courier0015.lzma
2022-04-18T20:16:07.374Z,1650312967.374 [NAL9602](INFO): Packets left to send: 0
2022-04-18T20:16:08.529Z,1650312968.529 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,201610.00,A,4131.83081,N,07047.17819,W,1.322,145.32,180422,,,A*71
2022-04-18T20:16:08.531Z,1650312968.531 [NAL9602](INFO): GPS fix at 20220418T201610: (41.530513, -70.786303)
2022-04-18T20:16:08.572Z,1650312968.572 [SpartonCompassCal:NeedComms:C] Stopped
2022-04-18T20:16:08.577Z,1650312968.577 [SpartonCompassCal:NeedComms:D] Running Loop=1
2022-04-18T20:16:09.125Z,1650312969.125 [SpartonCompassCal:NeedComms:D](DEBUG): Initialize ReadDataComponent to sense platform_communications
2022-04-18T20:16:19.260Z,1650312979.260 [NAL9602](INFO): SBD MO Status=1, MOMSN=36089, MT Status=0, MTMSN=0
2022-04-18T20:16:19.313Z,1650312979.313 [NAL9602](INFO): Sent 80 bytes from file Logs/20220418T193203/Courier0018.lzma
2022-04-18T20:16:19.313Z,1650312979.313 [NAL9602](INFO): Packets left to send: 0
2022-04-18T20:16:32.749Z,1650312992.749 [NAL9602](INFO): SBD MO Status=1, MOMSN=36090, MT Status=0, MTMSN=0
2022-04-18T20:16:32.801Z,1650312992.801 [NAL9602](INFO): Sent 184 bytes from file Logs/20220418T193203/Express0016.lzma
2022-04-18T20:16:32.801Z,1650312992.801 [NAL9602](INFO): Packets left to send: 2
2022-04-18T20:16:42.944Z,1650313002.944 [NAL9602](INFO): SBD MO Status=1, MOMSN=36091, MT Status=0, MTMSN=0
2022-04-18T20:16:43.001Z,1650313003.001 [NAL9602](INFO): Sent 184 bytes from file Logs/20220418T193203/Express0016.lzma
2022-04-18T20:16:43.001Z,1650313003.001 [NAL9602](INFO): Packets left to send: 1
2022-04-18T20:16:55.219Z,1650313015.219 [NAL9602](INFO): SBD MO Status=1, MOMSN=36092, MT Status=0, MTMSN=0
2022-04-18T20:16:55.289Z,1650313015.289 [NAL9602](INFO): Sent 28 bytes from file Logs/20220418T193203/Express0016.lzma
2022-04-18T20:16:55.289Z,1650313015.289 [NAL9602](INFO): Packets left to send: 0
2022-04-18T20:17:05.828Z,1650313025.828 [NAL9602](INFO): SBD MO Status=1, MOMSN=36093, MT Status=0, MTMSN=0
2022-04-18T20:17:05.878Z,1650313025.878 [NAL9602](INFO): Sent 184 bytes from file Logs/20220418T193203/Express0019.lzma
2022-04-18T20:17:05.879Z,1650313025.879 [NAL9602](INFO): Packets left to send: 1
2022-04-18T20:17:21.756Z,1650313041.756 [NAL9602](INFO): SBD MO Status=1, MOMSN=36094, MT Status=0, MTMSN=0
2022-04-18T20:17:21.809Z,1650313041.809 [NAL9602](INFO): Sent 47 bytes from file Logs/20220418T193203/Express0019.lzma
2022-04-18T20:17:21.810Z,1650313041.810 [NAL9602](INFO): Packets left to send: 0
2022-04-18T20:17:32.265Z,1650313052.265 [NAL9602](INFO): SBD MO Status=0, MOMSN=36095, MT Status=0, MTMSN=0
2022-04-18T20:17:32.374Z,1650313052.374 [SpartonCompassCal:NeedComms:D] Stopped
2022-04-18T20:17:32.374Z,1650313052.374 [SpartonCompassCal:NeedComms:E] Running Loop=1
2022-04-18T20:17:32.759Z,1650313052.759 [SpartonCompassCal:NeedComms:E](DEBUG): Initialize ReadDataComponent to sense time_fix
2022-04-18T20:17:34.699Z,1650313054.699 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,201736.00,A,4131.84335,N,07047.18107,W,4.121,332.69,180422,,,A*7E
2022-04-18T20:17:34.722Z,1650313054.722 [NAL9602](INFO): GPS fix at 20220418T201736: (41.530723, -70.786351)
2022-04-18T20:17:34.771Z,1650313054.771 [SpartonCompassCal:NeedComms:E] Stopped
2022-04-18T20:17:34.772Z,1650313054.772 [SpartonCompassCal:NeedComms](INFO): Completed SpartonCompassCal:NeedComms
2022-04-18T20:17:34.772Z,1650313054.772 [SpartonCompassCal:NeedComms] Stopped
2022-04-18T20:17:34.772Z,1650313054.772 [SpartonCompassCal:NeedComms](DEBUG): Aggregate::uninitialize SpartonCompassCal:NeedComms
2022-04-18T20:17:34.772Z,1650313054.772 [SpartonCompassCal:NeedComms:B.GoToSurface] Stopped
2022-04-18T20:17:34.772Z,1650313054.772 [SpartonCompassCal:NeedComms:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2022-04-18T20:17:35.168Z,1650313055.168 [SpartonCompassCal:StartingMission](INFO): Completed SpartonCompassCal:StartingMission
2022-04-18T20:17:35.168Z,1650313055.168 [SpartonCompassCal:StartingMission] Stopped
2022-04-18T20:17:35.168Z,1650313055.168 [SpartonCompassCal:StartingMission](DEBUG): Aggregate::uninitialize SpartonCompassCal:StartingMission
2022-04-18T20:17:35.168Z,1650313055.168 [SpartonCompassCal:AdaptCal] Running Loop=1
2022-04-18T20:17:35.168Z,1650313055.168 [SpartonCompassCal:AdaptCal](DEBUG): Aggregate::initialize SpartonCompassCal:AdaptCal
2022-04-18T20:17:35.168Z,1650313055.168 [SpartonCompassCal:AdaptCal:C.CalibrateAHRS_M2] Running Loop=1
2022-04-18T20:17:35.169Z,1650313055.169 [SpartonCompassCal:AdaptCal:C.CalibrateAHRS_M2](INFO): Initialize CalibrateSpartonComponent.
2022-04-18T20:17:35.169Z,1650313055.169 [SpartonCompassCal:AdaptCal:WaitForCalibrationInit] Running Loop=1
2022-04-18T20:17:35.546Z,1650313055.546 [SpartonCompassCal:AdaptCal:C.CalibrateAHRS_M2] Running Loop=1
2022-04-18T20:17:35.546Z,1650313055.546 [SpartonCompassCal:AdaptCal:C.CalibrateAHRS_M2](INFO): Initialize CalibrateSpartonComponent.
2022-04-18T20:17:35.547Z,1650313055.547 [SpartonCompassCal:AdaptCal:WaitForCalibrationInit](DEBUG): Initialize ReadDataComponent to sense AHRS_M2.number_of_calbration_points
2022-04-18T20:17:35.943Z,1650313055.943 [SpartonCompassCal:AdaptCal:C.CalibrateAHRS_M2](INFO): Initialize CalibrateSpartonComponent.
2022-04-18T20:17:36.351Z,1650313056.351 [SpartonCompassCal:AdaptCal:C.CalibrateAHRS_M2](INFO): Initialize CalibrateSpartonComponent.
2022-04-18T20:17:36.820Z,1650313056.820 [SpartonCompassCal:AdaptCal:C.CalibrateAHRS_M2](INFO): Initialize CalibrateSpartonComponent.
2022-04-18T20:17:37.150Z,1650313057.150 [SpartonCompassCal:AdaptCal:WaitForCalibrationInit] Stopped
2022-04-18T20:17:37.151Z,1650313057.151 [SpartonCompassCal:AdaptCal:AcquireCalibrationPoints] Running Loop=1
2022-04-18T20:17:37.151Z,1650313057.151 [SpartonCompassCal:AdaptCal:AcquireCalibrationPoints](DEBUG): Aggregate::initialize SpartonCompassCal:AdaptCal:AcquireCalibrationPoints
2022-04-18T20:17:37.151Z,1650313057.151 [SpartonCompassCal:AdaptCal:AcquireCalibrationPoints:A.Point] Running Loop=1
2022-04-18T20:17:37.151Z,1650313057.151 [SpartonCompassCal:AdaptCal:AcquireCalibrationPoints:A.Point](DEBUG): Initialize.
2022-04-18T20:17:37.151Z,1650313057.151 [SpartonCompassCal:AdaptCal:AcquireCalibrationPoints:B.SetSpeed] Running Loop=1
2022-04-18T20:17:37.151Z,1650313057.151 [SpartonCompassCal:AdaptCal:AcquireCalibrationPoints:B.SetSpeed](DEBUG): Initialize.
2022-04-18T20:17:37.531Z,1650313057.531 [SpartonCompassCal:AdaptCal:AcquireCalibrationPoints:B.SetSpeed] Running Loop=1
2022-04-18T20:17:37.531Z,1650313057.531 [SpartonCompassCal:AdaptCal:AcquireCalibrationPoints:A.Point] Running Loop=1
2022-04-18T20:18:07.415Z,1650313087.415 [NAL9602](INFO): Not Powering down - fast GPS
2022-04-18T20:18:20.359Z,1650313100.359 [ElevatorOffsetCalculator](INFO): New estimator for commanded vars: speed 1.00 m/s, pitch -20.00 deg, mass-position 2.00 mm (1 active estimators).
2022-04-18T20:18:33.675Z,1650313113.675 [ElevatorOffsetCalculator](INFO): New estimator for commanded vars: speed 1.00 m/s, pitch 20.00 deg, mass-position 2.00 mm (2 active estimators).
2022-04-18T20:19:20.730Z,1650313160.730 [Radio_Surface](INFO): Powering down
2022-04-18T20:19:31.161Z,1650313171.161 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2022-04-18T20:19:43.571Z,1650313183.571 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31

2022-04-18T20:19:43.576Z,1650313183.576 [Micromodem](INFO): Nmea in: $CACST,6,1,20220418201943.554207,06,361,25,0092,0150,134,02,02,00,02,-1,-01,-01,1,3,1,0,150,23.2,-0.01,-100,3.01,-01,-1.34,50,14500,4000*4E

2022-04-18T20:19:52.061Z,1650313192.061 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for BIT error
2022-04-18T20:26:40.911Z,1650313600.911 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2022-04-18T20:26:51.014Z,1650313611.014 [RDI_Pathfinder](ERROR): DVL BIT error. See manual. Result code: 88
2022-04-18T20:27:00.768Z,1650313620.768 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for water mass range.
2022-04-18T20:27:40.780Z,1650313660.780 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude
2022-04-18T20:27:50.933Z,1650313670.933 [RDI_Pathfinder](ERROR): DVL uart error: serial timeout
2022-04-18T20:27:50.933Z,1650313670.933 [RDI_Pathfinder] Communications Fault, FailCount= 1
2022-04-18T20:27:50.933Z,1650313670.933 [RDI_Pathfinder](ERROR): Communications Fault
2022-04-18T20:27:51.056Z,1650313671.056 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder
2022-04-18T20:27:51.289Z,1650313671.289 [RDI_Pathfinder](INFO): Powering down
2022-04-18T20:27:52.178Z,1650313672.178 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2022-04-18T20:27:52.178Z,1650313672.178 [RDI_Pathfinder] No Fault, FailCount= 1
2022-04-18T20:29:25.375Z,1650313765.375 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31

2022-04-18T20:29:25.380Z,1650313765.380 [Micromodem](INFO): Nmea in: $CACST,6,1,20220418202925.395751,06,2574,28,0090,0150,141,01,01,01,01,-1,-01,-01,1,3,1,0,150,27.9,1.13,-100,1.87,-01,0.04,52,14500,4000*7E

2022-04-18T20:30:04.600Z,1650313804.600 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2022-04-18T20:30:04.602Z,1650313804.602 [BPC1](INFO): Received data from all battery sticks.
2022-04-18T20:30:11.032Z,1650313811.032 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for altitude
2022-04-18T20:30:46.197Z,1650313846.197 [RDI_PathfinderUp](ERROR): only read 3 of 4 data items
2022-04-18T20:30:55.929Z,1650313855.929 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for altitude
2022-04-18T20:31:01.142Z,1650313861.142 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for altitude
2022-04-18T20:31:36.296Z,1650313896.296 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for BIT error
2022-04-18T20:36:55.918Z,1650314215.918 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for altitude
2022-04-18T20:38:04.886Z,1650314284.886 [CTD_Seabird](ERROR): Failed to parse device response: 9.3764,3.39525,4869.44
2022-04-18T20:42:36.898Z,1650314556.898 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2022-04-18T20:43:07.194Z,1650314587.194 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31

2022-04-18T20:43:07.214Z,1650314587.214 [Micromodem](INFO): Nmea in: $CACST,6,1,20220418204307.399361,06,975,23,0157,0150,134,01,01,01,01,-1,-01,-01,1,3,1,0,150,29.8,-0.74,-100,3.74,-01,-1.53,50,14500,4000*45

2022-04-18T20:43:36.694Z,1650314616.694 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for water mass range.
2022-04-18T20:47:05.571Z,1650314825.571 [Micromodem](INFO): Nmea in: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error

2022-04-18T20:47:05.572Z,1650314825.572 [Micromodem](ERROR): Response from modem failed NMEA checksum: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error
 expected 41
2022-04-18T20:47:05.574Z,1650314825.574 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31

2022-04-18T20:47:05.970Z,1650314825.970 [Micromodem](INFO): Nmea in: $CACST,6,1,20220418204705.408702,06,134,21,0118,0150,208,02,02,00,02,-1,-01,-01,1,3,8,0,150,75.8,3.95,-100,-0.95,-01,-0.67,-12,14500,4000*6A

2022-04-18T20:49:22.690Z,1650314962.690 [CTD_Seabird](ERROR): Failed to parse device response: 4.54,9.3183,3.392.52
2022-04-18T20:49:31.901Z,1650314971.901 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for BIT error
2022-04-18T20:49:37.094Z,1650314977.094 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for altitude
2022-04-18T20:49:52.032Z,1650314992.032 [RDI_PathfinderUp](ERROR): only read 3 of 4 data items
2022-04-18T20:49:58.096Z,1650314998.096 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for BIT error
2022-04-18T20:50:02.138Z,1650315002.138 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for altitude
2022-04-18T20:50:06.983Z,1650315006.983 [RDI_PathfinderUp](ERROR): only read 3 of 4 data items
2022-04-18T20:51:54.050Z,1650315114.050 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for BIT error
2022-04-18T20:54:22.751Z,1650315262.751 [RDI_Pathfinder](ERROR): only read 1 of 4 data items
2022-04-18T20:58:54.240Z,1650315534.240 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for altitude
2022-04-18T21:01:00.685Z,1650315660.685 [Micromodem](INFO): Nmea in: $CAMSG,BAD_CRC, Data Header,2*00

2022-04-18T21:01:00.690Z,1650315660.690 [Micromodem](INFO): Nmea in: $CACST,6,1,20220418210059.386098,06,237,23,0115,0150,208,02,02,00,02,5,-01,-01,2,3,3,0,150,-16.1,6.29,-100,-3.29,-01,-6.44,65,14500,4000*47

2022-04-18T21:01:52.811Z,1650315712.811 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2022-04-18T21:02:12.618Z,1650315732.618 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2022-04-18T21:03:11.198Z,1650315791.198 [Micromodem](INFO): Nmea in: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error

2022-04-18T21:03:11.199Z,1650315791.199 [Micromodem](ERROR): Response from modem failed NMEA checksum: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error
 expected 41
2022-04-18T21:03:11.202Z,1650315791.202 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31

2022-04-18T21:03:11.587Z,1650315791.587 [Micromodem](INFO): Nmea in: $CACST,6,1,20220418210311.395739,06,171,22,0103,0150,208,02,02,00,02,-1,-01,-01,1,3,1,0,150,-100.0,0.13,-100,2.87,-01,-1.16,-2147483648,14500,4000*52

2022-04-18T21:03:37.043Z,1650315817.043 [RDI_PathfinderUp](ERROR): only read 1 of 4 data items
2022-04-18T21:09:07.965Z,1650316147.965 [RDI_PathfinderUp](ERROR): only read 3 of 4 data items
2022-04-18T21:09:12.896Z,1650316152.896 [RDI_PathfinderUp](ERROR): only read 2 of 4 data items
2022-04-18T21:09:28.193Z,1650316168.193 [RDI_PathfinderUp](ERROR): DVL uart error: serial timeout
2022-04-18T21:09:28.193Z,1650316168.193 [RDI_PathfinderUp] Communications Fault, FailCount= 1
2022-04-18T21:09:28.193Z,1650316168.193 [RDI_PathfinderUp](ERROR): Communications Fault
2022-04-18T21:09:28.308Z,1650316168.308 [CBIT](ERROR): Communications Fault in component: RDI_PathfinderUp
2022-04-18T21:09:28.661Z,1650316168.661 [RDI_PathfinderUp](INFO): Powering down
2022-04-18T21:09:29.444Z,1650316169.444 [CBIT](INFO): Clearing failed state for component RDI_PathfinderUp
2022-04-18T21:09:29.444Z,1650316169.444 [RDI_PathfinderUp] No Fault, FailCount= 1
2022-04-18T21:09:47.968Z,1650316187.968 [RDI_PathfinderUp](ERROR): only read 3 of 4 data items
2022-04-18T21:10:18.270Z,1650316218.270 [RDI_PathfinderUp](ERROR): only read 3 of 4 data items
2022-04-18T21:11:28.181Z,1650316288.181 [RDI_PathfinderUp](ERROR): DVL uart error: serial timeout
2022-04-18T21:11:28.181Z,1650316288.181 [RDI_PathfinderUp] Communications Fault, FailCount= 1
2022-04-18T21:11:28.181Z,1650316288.181 [RDI_PathfinderUp](ERROR): Communications Fault
2022-04-18T21:11:28.248Z,1650316288.248 [CBIT](ERROR): Communications Fault in component: RDI_PathfinderUp
2022-04-18T21:11:28.657Z,1650316288.657 [RDI_PathfinderUp](INFO): Powering down
2022-04-18T21:11:29.480Z,1650316289.480 [CBIT](INFO): Clearing failed state for component RDI_PathfinderUp
2022-04-18T21:11:29.480Z,1650316289.480 [RDI_PathfinderUp] No Fault, FailCount= 1
2022-04-18T21:12:01.289Z,1650316321.289 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31

2022-04-18T21:12:01.293Z,1650316321.293 [Micromodem](INFO): Nmea in: $CACST,6,1,20220418211201.378191,06,803,23,0872,0150,149,02,02,01,02,-1,-01,-01,1,3,2,0,150,19.9,0.09,-100,2.91,-01,0.73,54,14500,4000*45

2022-04-18T21:15:37.436Z,1650316537.436 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31

2022-04-18T21:15:37.441Z,1650316537.441 [Micromodem](INFO): Nmea in: $CACST,6,1,20220418211537.374535,06,660,22,0122,0150,208,02,02,01,02,-1,-01,-01,1,3,6,0,150,10.6,0.11,-100,2.89,-01,0.88,63,14500,4000*43

2022-04-18T21:16:01.804Z,1650316561.804 [CBIT](IMPORTANT): Beginning ground fault scan
2022-04-18T21:16:02.121Z,1650316562.121 [SpartonCompassCal](INFO): Timed out from 2022-04-18T20:16:01.0Z
2022-04-18T21:16:02.121Z,1650316562.121 [MissionManager](INFO): SpartonCompassCal is completed.
2022-04-18T21:16:02.121Z,1650316562.121 [MissionManager](INFO): Uninitializing Mission SpartonCompassCal
2022-04-18T21:16:02.121Z,1650316562.121 [SpartonCompassCal] Stopped
2022-04-18T21:16:02.121Z,1650316562.121 [SpartonCompassCal](DEBUG): Aggregate::uninitialize SpartonCompassCal
2022-04-18T21:16:02.121Z,1650316562.121 [SpartonCompassCal:Science] Stopped
2022-04-18T21:16:02.121Z,1650316562.121 [SpartonCompassCal:Science](DEBUG): Aggregate::uninitialize SpartonCompassCal:Science
2022-04-18T21:16:02.121Z,1650316562.121 [SpartonCompassCal:Science:B] Stopped
2022-04-18T21:16:02.121Z,1650316562.121 [SpartonCompassCal:Science:C] Stopped
2022-04-18T21:16:02.121Z,1650316562.121 [SpartonCompassCal:Science:Read_Oil] Stopped
2022-04-18T21:16:02.122Z,1650316562.122 [SpartonCompassCal:Science:OceanCurrent] Stopped
2022-04-18T21:16:02.122Z,1650316562.122 [SpartonCompassCal:Science:OceanCurrent](DEBUG): Aggregate::uninitialize SpartonCompassCal:Science:OceanCurrent
2022-04-18T21:16:02.122Z,1650316562.122 [SpartonCompassCal:Science:OceanCurrent:A.] Stopped
2022-04-18T21:16:02.122Z,1650316562.122 [SpartonCompassCal:StandardEnvelopes] Stopped
2022-04-18T21:16:02.122Z,1650316562.122 [SpartonCompassCal:StandardEnvelopes](DEBUG): Aggregate::uninitialize SpartonCompassCal:StandardEnvelopes
2022-04-18T21:16:02.122Z,1650316562.122 [SpartonCompassCal:StandardEnvelopes:A.AltitudeEnvelope] Stopped
2022-04-18T21:16:02.122Z,1650316562.122 [SpartonCompassCal:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent.
2022-04-18T21:16:02.122Z,1650316562.122 [SpartonCompassCal:StandardEnvelopes:B.DepthEnvelope] Stopped
2022-04-18T21:16:02.122Z,1650316562.122 [SpartonCompassCal:StandardEnvelopes:B.DepthEnvelope](DEBUG): Uninitialize.
2022-04-18T21:16:02.122Z,1650316562.122 [SpartonCompassCal:StandardEnvelopes:C.OffshoreEnvelope] Stopped
2022-04-18T21:16:02.122Z,1650316562.122 [SpartonCompassCal:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Uninitialize OffshoreEnvelopeComponent.
2022-04-18T21:16:02.122Z,1650316562.122 [SpartonCompassCal:I.Pitch] Stopped
2022-04-18T21:16:02.122Z,1650316562.122 [SpartonCompassCal:J.Buoyancy] Stopped
2022-04-18T21:16:02.123Z,1650316562.123 [SpartonCompassCal:J.Buoyancy](DEBUG): Uninitialize Buoyancy Component.
2022-04-18T21:16:02.123Z,1650316562.123 [SpartonCompassCal:K.DepthEnvelope] Stopped
2022-04-18T21:16:02.123Z,1650316562.123 [SpartonCompassCal:K.DepthEnvelope](DEBUG): Uninitialize.
2022-04-18T21:16:02.123Z,1650316562.123 [SpartonCompassCal:L.AltitudeEnvelope] Stopped
2022-04-18T21:16:02.123Z,1650316562.123 [SpartonCompassCal:L.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent.
2022-04-18T21:16:02.123Z,1650316562.123 [SpartonCompassCal:M.YoYo] Stopped
2022-04-18T21:16:02.123Z,1650316562.123 [SpartonCompassCal:M.YoYo](DEBUG): Uninitialize YoYoComponent.
2022-04-18T21:16:02.123Z,1650316562.123 [SpartonCompassCal:AdaptCal] Stopped
2022-04-18T21:16:02.123Z,1650316562.123 [SpartonCompassCal:AdaptCal](DEBUG): Aggregate::uninitialize SpartonCompassCal:AdaptCal
2022-04-18T21:16:02.123Z,1650316562.123 [SpartonCompassCal:AdaptCal:AcquireCalibrationPoints] Stopped
2022-04-18T21:16:02.123Z,1650316562.123 [SpartonCompassCal:AdaptCal:AcquireCalibrationPoints](DEBUG): Aggregate::uninitialize SpartonCompassCal:AdaptCal:AcquireCalibrationPoints
2022-04-18T21:16:02.123Z,1650316562.123 [SpartonCompassCal:AdaptCal:AcquireCalibrationPoints:A.Point] Stopped
2022-04-18T21:16:02.123Z,1650316562.123 [SpartonCompassCal:AdaptCal:AcquireCalibrationPoints:B.SetSpeed] Stopped
2022-04-18T21:16:02.124Z,1650316562.124 [SpartonCompassCal:AdaptCal:AcquireCalibrationPoints:B.SetSpeed](DEBUG): Uninitialize.
2022-04-18T21:16:02.124Z,1650316562.124 [SpartonCompassCal:AdaptCal:C.CalibrateAHRS_M2] Stopped
2022-04-18T21:16:02.124Z,1650316562.124 [SpartonCompassCal:AdaptCal:C.CalibrateAHRS_M2](INFO): Uninitialize CalibrateSpartonComponent.
2022-04-18T21:16:02.557Z,1650316562.557 [AHRS_M2](IMPORTANT): Acquired 8 calibration points.
2022-04-18T21:16:02.606Z,1650316562.606 [MissionManager](IMPORTANT): Started mission Default
2022-04-18T21:16:02.607Z,1650316562.607 [Default] Running Loop=1
2022-04-18T21:16:02.607Z,1650316562.607 [Default](DEBUG): Aggregate::initialize Default
2022-04-18T21:16:02.607Z,1650316562.607 [Default:B.GoToSurface] Running Loop=1
2022-04-18T21:16:02.607Z,1650316562.607 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2022-04-18T21:16:02.607Z,1650316562.607 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2022-04-18T21:16:02.608Z,1650316562.608 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2022-04-18T21:16:02.608Z,1650316562.608 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2022-04-18T21:16:02.608Z,1650316562.608 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2022-04-18T21:16:02.613Z,1650316562.613 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2022-04-18T21:16:02.613Z,1650316562.613 [Default:A.Wait] Running Loop=1
2022-04-18T21:16:02.613Z,1650316562.613 [Default:A.Wait](DEBUG): Initialize Wait Component.
2022-04-18T21:16:03.177Z,1650316563.177 [Radio_Surface](INFO): Powering up
2022-04-18T21:16:03.299Z,1650316563.299 [AHRS_M2](IMPORTANT): Magnetic calibration quality (0[best] to 10000) is 0.001261.
2022-04-18T21:16:04.120Z,1650316564.120 [ElevatorOffsetCalculator](INFO): New estimator for commanded vars: speed 1.00 m/s, pitch 30.00 deg, mass-position -25.00 mm (3 active estimators).
2022-04-18T21:16:09.217Z,1650316569.217 [DataOverHttps](INFO): Radio surface powered ON.
2022-04-18T21:16:12.791Z,1650316572.791 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.594902
CHAN A1 (24V): 0.672153
CHAN A2 (12V): 0.315285
CHAN A3 (5V): 0.055238
CHAN B0 (3.3V): 0.010764
CHAN B1 (3.15aV): 0.007044
CHAN B2 (3.15bV): 0.014651
CHAN B3 (GND): -0.079032
OPEN: 0.006492
Full Scale: +/- 1 mA
2022-04-18T21:16:15.822Z,1650316575.822 [Default:A.Wait](INFO): Done Waiting.
2022-04-18T21:16:15.822Z,1650316575.822 [Default:A.Wait] Stopped
2022-04-18T21:16:15.822Z,1650316575.822 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2022-04-18T21:16:25.534Z,1650316585.534 [Default:CheckIn] Running Loop=1
2022-04-18T21:16:25.534Z,1650316585.534 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-04-18T21:16:25.534Z,1650316585.534 [Default:CheckIn:Read_GPS] Running Loop=1
2022-04-18T21:17:03.488Z,1650316623.488 [NAL9602](INFO): SBD MO Status=2, MOMSN=36096, MT Status=2, MTMSN=0
2022-04-18T21:17:03.488Z,1650316623.488 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-04-18T21:17:13.592Z,1650316633.592 [NAL9602](INFO): SBD MO Status=0, MOMSN=36096, MT Status=0, MTMSN=0
2022-04-18T21:17:13.592Z,1650316633.592 [NAL9602](INFO): No messages in MT queue
2022-04-18T21:17:14.798Z,1650316634.798 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,211716.00,A,4131.97023,N,07047.17298,W,1.089,353.00,180422,,,A*7F
2022-04-18T21:17:14.800Z,1650316634.800 [NAL9602](INFO): GPS fix at 20220418T211716: (41.532837, -70.786216)
2022-04-18T21:17:14.852Z,1650316634.852 [UniversalFixResidualReporter](INFO): Fix residual: 3.1 %DT, over the last 2630.6 m. Residual distance 81.1 m at bearing -148.2 degrees. Fix at (41.5328, -70.7862) with 235.4 m made good.
2022-04-18T21:17:14.854Z,1650316634.854 [Default:CheckIn:Read_GPS] Stopped
2022-04-18T21:17:14.854Z,1650316634.854 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-04-18T21:17:28.714Z,1650316648.714 [NAL9602](INFO): SBD MO Status=1, MOMSN=36097, MT Status=0, MTMSN=0
2022-04-18T21:17:28.769Z,1650316648.769 [NAL9602](INFO): Sent 184 bytes from file Logs/20220418T193203/Courier0021.lzma
2022-04-18T21:17:28.769Z,1650316648.769 [NAL9602](INFO): Packets left to send: 1
2022-04-18T21:17:54.302Z,1650316674.302 [NAL9602](INFO): SBD MO Status=2, MOMSN=36098, MT Status=2, MTMSN=0
2022-04-18T21:17:54.303Z,1650316674.303 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-04-18T21:18:06.540Z,1650316686.540 [NAL9602](INFO): SBD MO Status=1, MOMSN=36098, MT Status=0, MTMSN=0
2022-04-18T21:18:06.593Z,1650316686.593 [NAL9602](INFO): Sent 87 bytes from file Logs/20220418T193203/Courier0021.lzma
2022-04-18T21:18:06.593Z,1650316686.593 [NAL9602](INFO): Packets left to send: 0
2022-04-18T21:18:18.386Z,1650316698.386 [NAL9602](INFO): SBD MO Status=1, MOMSN=36099, MT Status=0, MTMSN=0
2022-04-18T21:18:18.437Z,1650316698.437 [NAL9602](INFO): Sent 184 bytes from file Logs/20220418T193203/Express0022.lzma
2022-04-18T21:18:18.437Z,1650316698.437 [NAL9602](INFO): Packets left to send: 10
2022-04-18T21:18:31.037Z,1650316711.037 [NAL9602](INFO): SBD MO Status=1, MOMSN=36100, MT Status=0, MTMSN=0
2022-04-18T21:18:31.085Z,1650316711.085 [NAL9602](INFO): Sent 184 bytes from file Logs/20220418T193203/Express0022.lzma
2022-04-18T21:18:31.085Z,1650316711.085 [NAL9602](INFO): Packets left to send: 9
2022-04-18T21:18:42.069Z,1650316722.069 [NAL9602](INFO): SBD MO Status=1, MOMSN=36101, MT Status=0, MTMSN=0
2022-04-18T21:18:42.117Z,1650316722.117 [NAL9602](INFO): Sent 184 bytes from file Logs/20220418T193203/Express0022.lzma
2022-04-18T21:18:42.117Z,1650316722.117 [NAL9602](INFO): Packets left to send: 8
2022-04-18T21:18:55.131Z,1650316735.131 [NAL9602](INFO): SBD MO Status=1, MOMSN=36102, MT Status=0, MTMSN=0
2022-04-18T21:18:55.181Z,1650316735.181 [NAL9602](INFO): Sent 184 bytes from file Logs/20220418T193203/Express0022.lzma
2022-04-18T21:18:55.181Z,1650316735.181 [NAL9602](INFO): Packets left to send: 7
2022-04-18T21:19:06.984Z,1650316746.984 [NAL9602](INFO): SBD MO Status=1, MOMSN=36103, MT Status=0, MTMSN=0
2022-04-18T21:19:07.045Z,1650316747.045 [NAL9602](INFO): Sent 184 bytes from file Logs/20220418T193203/Express0022.lzma
2022-04-18T21:19:07.045Z,1650316747.045 [NAL9602](INFO): Packets left to send: 6
2022-04-18T21:19:15.580Z,1650316755.580 [NAL9602](INFO): SBD MO Status=1, MOMSN=36104, MT Status=0, MTMSN=0
2022-04-18T21:19:15.630Z,1650316755.630 [NAL9602](INFO): Sent 184 bytes from file Logs/20220418T193203/Express0022.lzma
2022-04-18T21:19:15.630Z,1650316755.630 [NAL9602](INFO): Packets left to send: 5
2022-04-18T21:19:26.666Z,1650316766.666 [NAL9602](INFO): SBD MO Status=1, MOMSN=36105, MT Status=0, MTMSN=0
2022-04-18T21:19:26.721Z,1650316766.721 [NAL9602](INFO): Sent 184 bytes from file Logs/20220418T193203/Express0022.lzma
2022-04-18T21:19:26.721Z,1650316766.721 [NAL9602](INFO): Packets left to send: 4
2022-04-18T21:19:32.859Z,1650316772.859 [NAL9602](INFO): SBD MO Status=1, MOMSN=36106, MT Status=0, MTMSN=0
2022-04-18T21:19:32.917Z,1650316772.917 [NAL9602](INFO): Sent 184 bytes from file Logs/20220418T193203/Express0022.lzma
2022-04-18T21:19:32.917Z,1650316772.917 [NAL9602](INFO): Packets left to send: 3
2022-04-18T21:19:43.057Z,1650316783.057 [NAL9602](INFO): SBD MO Status=1, MOMSN=36107, MT Status=0, MTMSN=0
2022-04-18T21:19:43.113Z,1650316783.113 [NAL9602](INFO): Sent 184 bytes from file Logs/20220418T193203/Express0022.lzma
2022-04-18T21:19:43.113Z,1650316783.113 [NAL9602](INFO): Packets left to send: 2
2022-04-18T21:19:54.891Z,1650316794.891 [Micromodem](INFO): Nmea in: $CAMSG,BAD_CRC, Data Header,2*00

2022-04-18T21:19:55.295Z,1650316795.295 [Micromodem](INFO): Nmea in: $CACST,6,1,20220418211951.375536,06,288,24,0254,0150,126,03,03,00,03,1,-01,-01,2,3,3,0,150,-2.2,-0.17,-100,3.17,-01,-5.34,56,14500,4000*71

2022-04-18T21:20:04.601Z,1650316804.601 [NAL9602](INFO): SBD MO Status=2, MOMSN=36108, MT Status=2, MTMSN=0
2022-04-18T21:20:04.601Z,1650316804.601 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-04-18T21:20:16.781Z,1650316816.781 [Micromodem](INFO): Nmea in: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error

2022-04-18T21:20:16.781Z,1650316816.781 [Micromodem](ERROR): Response from modem failed NMEA checksum: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error
 expected 41
2022-04-18T21:20:17.184Z,1650316817.184 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31

2022-04-18T21:20:17.590Z,1650316817.590 [Micromodem](INFO): Nmea in: $CACST,6,1,20220418212013.375175,06,291,24,0139,0150,208,01,01,00,01,-1,-01,-01,1,3,8,0,150,75.1,-343.66,-100,-308.70,-01,0.00,-6,14500,4000*59

2022-04-18T21:20:34.556Z,1650316834.556 [NAL9602](INFO): SBD MO Status=2, MOMSN=36108, MT Status=2, MTMSN=0
2022-04-18T21:20:34.556Z,1650316834.556 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-04-18T21:20:59.694Z,1650316859.694 [NAL9602](INFO): SBD MO Status=2, MOMSN=36108, MT Status=2, MTMSN=0
2022-04-18T21:20:59.695Z,1650316859.695 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-04-18T21:21:09.136Z,1650316869.136 [Micromodem](INFO): Nmea in: $CAMSG,Error accessing coproc,4*51

2022-04-18T21:21:09.537Z,1650316869.537 [Micromodem](INFO): Nmea in: $CACST,6,1,20220418212109.378326,06,210,23,0105,0150,194,02,02,00,02,-1,-01,-01,4,3,0,0,-999,-99.9,-9.99,-999,-9.99,-01,0.00,-999,14500,4000*5B

2022-04-18T21:21:22.515Z,1650316882.515 [NAL9602](INFO): SBD MO Status=2, MOMSN=36108, MT Status=2, MTMSN=0
2022-04-18T21:21:22.515Z,1650316882.515 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-04-18T21:21:38.809Z,1650316898.809 [RDI_Pathfinder](ERROR): DVL uart error: serial timeout
2022-04-18T21:21:38.809Z,1650316898.809 [RDI_Pathfinder] Communications Fault, FailCount= 1
2022-04-18T21:21:38.809Z,1650316898.809 [RDI_Pathfinder](ERROR): Communications Fault
2022-04-18T21:21:38.887Z,1650316898.887 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder
2022-04-18T21:21:39.257Z,1650316899.257 [RDI_Pathfinder](INFO): Powering down
2022-04-18T21:21:40.033Z,1650316900.033 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2022-04-18T21:21:40.033Z,1650316900.033 [RDI_Pathfinder] No Fault, FailCount= 1
2022-04-18T21:21:40.386Z,1650316900.386 [NAL9602](INFO): SBD MO Status=1, MOMSN=36108, MT Status=0, MTMSN=0
2022-04-18T21:21:40.435Z,1650316900.435 [NAL9602](INFO): Sent 184 bytes from file Logs/20220418T193203/Express0022.lzma
2022-04-18T21:21:40.435Z,1650316900.435 [NAL9602](INFO): Packets left to send: 1
2022-04-18T21:22:07.930Z,1650316927.930 [NAL9602](INFO): SBD MO Status=1, MOMSN=36109, MT Status=0, MTMSN=0
2022-04-18T21:22:07.985Z,1650316927.985 [NAL9602](INFO): Sent 93 bytes from file Logs/20220418T193203/Express0022.lzma
2022-04-18T21:22:07.985Z,1650316927.985 [NAL9602](INFO): Packets left to send: 0
2022-04-18T21:22:08.763Z,1650316928.763 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude
2022-04-18T21:22:17.632Z,1650316937.632 [NAL9602](INFO): SBD MO Status=0, MOMSN=36110, MT Status=0, MTMSN=0
2022-04-18T21:22:17.719Z,1650316937.719 [Default:CheckIn:Read_Iridium] Stopped
2022-04-18T21:22:17.719Z,1650316937.719 [Default:CheckIn:C.Wait] Running Loop=1
2022-04-18T21:22:17.719Z,1650316937.719 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-04-18T21:22:18.862Z,1650316938.862 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude
2022-04-18T21:22:48.335Z,1650316968.335 [NAL9602](INFO): Not Powering down - fast GPS
2022-04-18T21:27:18.222Z,1650317238.222 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-04-18T21:27:18.222Z,1650317238.222 [Default:CheckIn:C.Wait] Stopped
2022-04-18T21:27:18.222Z,1650317238.222 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-04-18T21:27:18.223Z,1650317238.223 [Default:CheckIn:D] Running Loop=1
2022-04-18T21:27:18.650Z,1650317238.650 [Default:CheckIn:D] Stopped
2022-04-18T21:27:18.651Z,1650317238.651 [Default:CheckIn:E] Running Loop=1
2022-04-18T21:27:19.051Z,1650317239.051 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 11.267389 min 
2022-04-18T21:27:19.051Z,1650317239.051 [Default:CheckIn:E] Stopped
2022-04-18T21:27:19.051Z,1650317239.051 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-04-18T21:27:19.051Z,1650317239.051 [Default:CheckIn] Stopped
2022-04-18T21:27:19.051Z,1650317239.051 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-04-18T21:27:19.051Z,1650317239.051 [Default:CheckIn](INFO): Running loop #2
2022-04-18T21:27:19.051Z,1650317239.051 [Default:CheckIn] Running Loop=2
2022-04-18T21:27:19.051Z,1650317239.051 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-04-18T21:27:19.051Z,1650317239.051 [Default:CheckIn:Read_GPS] Running Loop=1
2022-04-18T21:27:21.034Z,1650317241.034 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,212722.00,A,4132.03876,N,07047.17552,W,0.564,1.61,180422,,,A*78
2022-04-18T21:27:21.037Z,1650317241.037 [NAL9602](INFO): GPS fix at 20220418T212722: (41.533979, -70.786259)
2022-04-18T21:27:21.083Z,1650317241.083 [Default:CheckIn:Read_GPS] Stopped
2022-04-18T21:27:21.083Z,1650317241.083 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-04-18T21:27:50.629Z,1650317270.629 [NAL9602](IMPORTANT): SBD MO Status=1, MOMSN=36111, MT Status=1, MTMSN=1408
2022-04-18T21:27:50.686Z,1650317270.686 [NAL9602](INFO): Sent 79 bytes from file Logs/20220418T193203/Courier0024.lzma
2022-04-18T21:27:50.686Z,1650317270.686 [NAL9602](INFO): Packets left to send: 0
2022-04-18T21:27:51.177Z,1650317271.177 [NAL9602](INFO): Received command: configSet InternalEnvSim.loadAtStartup 1 bool persist
2022-04-18T21:27:51.535Z,1650317271.535 [CommandExec](IMPORTANT): got command configSet InternalEnvSim.loadAtStartup 1 bool persist
2022-04-18T21:27:51.536Z,1650317271.536 [CommandExec](IMPORTANT): configSet InternalEnvSim.loadAtStartup requires a restart to take effect.
2022-04-18T21:28:02.020Z,1650317282.020 [NAL9602](INFO): SBD MO Status=1, MOMSN=36112, MT Status=0, MTMSN=0
2022-04-18T21:28:02.069Z,1650317282.069 [NAL9602](INFO): Sent 119 bytes from file Logs/20220418T193203/Express0025.lzma
2022-04-18T21:28:02.069Z,1650317282.069 [NAL9602](INFO): Packets left to send: 0
2022-04-18T21:28:07.273Z,1650317287.273 [Micromodem](INFO): Nmea in: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error

2022-04-18T21:28:07.273Z,1650317287.273 [Micromodem](ERROR): Response from modem failed NMEA checksum: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error
 expected 41
2022-04-18T21:28:07.670Z,1650317287.670 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31

2022-04-18T21:28:08.082Z,1650317288.082 [Micromodem](INFO): Nmea in: $CACST,6,1,20220418212807.377290,06,1240,24,0090,0150,149,02,02,01,02,-1,-01,-01,1,3,1,0,150,-100.0,0.21,-100,2.79,-01,-0.82,-2147483648,14500,4000*60

2022-04-18T21:28:12.928Z,1650317292.928 [NAL9602](INFO): SBD MO Status=0, MOMSN=36113, MT Status=0, MTMSN=0
2022-04-18T21:28:32.794Z,1650317312.794 [NAL9602](INFO): SBD MO Status=1, MOMSN=36114, MT Status=0, MTMSN=0
2022-04-18T21:28:32.838Z,1650317312.838 [NAL9602](INFO): Sent 52 bytes from file Logs/20220418T193203/Courier0027.lzma
2022-04-18T21:28:32.839Z,1650317312.839 [NAL9602](INFO): Packets left to send: 0
2022-04-18T21:28:39.740Z,1650317319.740 [NAL9602](INFO): SBD MO Status=1, MOMSN=36115, MT Status=0, MTMSN=0
2022-04-18T21:28:39.793Z,1650317319.793 [NAL9602](INFO): Sent 184 bytes from file Logs/20220418T193203/Express0028.lzma
2022-04-18T21:28:39.793Z,1650317319.793 [NAL9602](INFO): Packets left to send: 1
2022-04-18T21:28:52.358Z,1650317332.358 [NAL9602](INFO): SBD MO Status=2, MOMSN=36116, MT Status=2, MTMSN=0
2022-04-18T21:28:52.359Z,1650317332.359 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-04-18T21:29:22.776Z,1650317362.776 [NAL9602](INFO): SBD MO Status=2, MOMSN=36116, MT Status=2, MTMSN=0
2022-04-18T21:29:22.776Z,1650317362.776 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-04-18T21:29:39.454Z,1650317379.454 [Micromodem](INFO): Nmea in: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error

2022-04-18T21:29:39.455Z,1650317379.455 [Micromodem](ERROR): Response from modem failed NMEA checksum: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error
 expected 41
2022-04-18T21:29:39.859Z,1650317379.859 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31

2022-04-18T21:29:40.262Z,1650317380.262 [Micromodem](INFO): Nmea in: $CACST,6,1,20220418212939.379100,06,553,27,0125,0150,179,03,03,00,03,-1,-01,-01,1,3,4,0,150,80.7,1.23,-100,1.77,-01,0.22,-18,14500,4000*60

2022-04-18T21:29:41.077Z,1650317381.077 [NAL9602](INFO): SBD MO Status=2, MOMSN=36116, MT Status=2, MTMSN=0
2022-04-18T21:29:41.078Z,1650317381.078 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-04-18T21:29:51.696Z,1650317391.696 [NAL9602](INFO): SBD MO Status=1, MOMSN=36116, MT Status=0, MTMSN=0
2022-04-18T21:29:51.745Z,1650317391.745 [NAL9602](INFO): Sent 26 bytes from file Logs/20220418T193203/Express0028.lzma
2022-04-18T21:29:51.745Z,1650317391.745 [NAL9602](INFO): Packets left to send: 0
2022-04-18T21:29:53.311Z,1650317393.311 [Micromodem](INFO): Nmea in: $CAMSG,BAD_CRC, Data Header,2*00

2022-04-18T21:29:53.718Z,1650317393.718 [Micromodem](INFO): Nmea in: $CACST,6,1,20220418212951.383847,06,944,23,0139,0150,216,02,02,01,02,6,-01,-01,2,3,3,0,150,2.1,4.44,13,-1.44,-01,-1.46,62,14500,4000*43

2022-04-18T21:29:57.348Z,1650317397.348 [Micromodem](INFO): Nmea in: $CAMSG,Error accessing coproc,4*51

2022-04-18T21:29:57.754Z,1650317397.754 [Micromodem](INFO): Nmea in: $CACST,6,1,20220418212957.391859,06,140,21,0126,0150,149,02,02,00,02,-1,-01,-01,4,3,0,0,-999,-99.9,-9.99,-999,-9.99,-01,0.00,-999,14500,4000*59

2022-04-18T21:30:12.302Z,1650317412.302 [NAL9602](INFO): SBD MO Status=0, MOMSN=36117, MT Status=0, MTMSN=0
2022-04-18T21:30:12.406Z,1650317412.406 [Default:CheckIn:Read_Iridium] Stopped
2022-04-18T21:30:12.407Z,1650317412.407 [Default:CheckIn:C.Wait] Running Loop=1
2022-04-18T21:30:12.407Z,1650317412.407 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-04-18T21:30:42.999Z,1650317442.999 [NAL9602](INFO): Not Powering down - fast GPS
2022-04-18T21:33:05.206Z,1650317585.206 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31

2022-04-18T21:33:05.210Z,1650317585.210 [Micromodem](INFO): Nmea in: $CACST,6,1,20220418213305.384034,06,1139,24,0090,0150,141,01,01,01,02,-1,-01,-01,1,3,1,0,150,22.8,0.00,-100,3.00,-01,-1.04,50,14500,4000*57

2022-04-18T21:33:21.770Z,1650317601.770 [Micromodem](INFO): Nmea in: $CAMSG,BAD_CRC, Data Header,2*00

2022-04-18T21:33:21.774Z,1650317601.774 [Micromodem](INFO): Nmea in: $CACST,6,1,20220418213321.386263,06,153,21,0100,0150,208,00,00,00,00,1,-01,-01,2,4,3,0,150,-29.3,1.65,01,1.35,-01,-0.73,64,14500,4000*75

2022-04-18T21:35:12.896Z,1650317712.896 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-04-18T21:35:12.896Z,1650317712.896 [Default:CheckIn:C.Wait] Stopped
2022-04-18T21:35:12.896Z,1650317712.896 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-04-18T21:35:12.896Z,1650317712.896 [Default:CheckIn:D] Running Loop=1
2022-04-18T21:35:13.291Z,1650317713.291 [Default:CheckIn:D] Stopped
2022-04-18T21:35:13.291Z,1650317713.291 [Default:CheckIn:E] Running Loop=1
2022-04-18T21:35:13.705Z,1650317713.705 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 19.178072 min 
2022-04-18T21:35:13.705Z,1650317713.705 [Default:CheckIn:E] Stopped
2022-04-18T21:35:13.705Z,1650317713.705 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-04-18T21:35:13.705Z,1650317713.705 [Default:CheckIn] Stopped
2022-04-18T21:35:13.705Z,1650317713.705 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-04-18T21:35:13.705Z,1650317713.705 [Default:CheckIn](INFO): Running loop #3
2022-04-18T21:35:13.705Z,1650317713.705 [Default:CheckIn] Running Loop=3
2022-04-18T21:35:13.705Z,1650317713.705 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-04-18T21:35:13.706Z,1650317713.706 [Default:CheckIn:Read_GPS] Running Loop=1
2022-04-18T21:35:15.723Z,1650317715.723 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,213517.00,A,4132.09396,N,07047.17686,W,0.641,350.06,180422,,,A*7A
2022-04-18T21:35:15.725Z,1650317715.725 [NAL9602](INFO): GPS fix at 20220418T213517: (41.534899, -70.786281)
2022-04-18T21:35:15.738Z,1650317715.738 [Default:CheckIn:Read_GPS] Stopped
2022-04-18T21:35:15.738Z,1650317715.738 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-04-18T21:35:25.940Z,1650317725.940 [NAL9602](IMPORTANT): SBD MO Status=1, MOMSN=36118, MT Status=1, MTMSN=1409
2022-04-18T21:35:25.989Z,1650317725.989 [NAL9602](INFO): Sent 73 bytes from file Logs/20220418T193203/Courier0030.lzma
2022-04-18T21:35:25.989Z,1650317725.989 [NAL9602](INFO): Packets left to send: 0
2022-04-18T21:35:26.385Z,1650317726.385 [NAL9602](INFO): Received command: restart app
2022-04-18T21:35:26.398Z,1650317726.398 [CommandExec](IMPORTANT): got command restart application
2022-04-18T21:35:27.401Z,1650317727.401 [Supervisor](INFO): Stop Mission called by Supervisor::terminate
2022-04-18T21:35:27.401Z,1650317727.401 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread.
2022-04-18T21:35:27.401Z,1650317727.401 [CommandExec](INFO): Uninitializing the command executive.
2022-04-18T21:35:27.401Z,1650317727.401 [CommandExec](INFO): Uninitializing the command scheduler.
2022-04-18T21:35:27.402Z,1650317727.402 [CommandExec ThreadHandler](INFO): Thread cancelled.
2022-04-18T21:35:27.472Z,1650317727.472 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2022-04-18T21:35:27.473Z,1650317727.473 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2022-04-18T21:35:27.473Z,1650317727.473 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2022-04-18T21:35:27.474Z,1650317727.474 [NavChartDb](INFO): Join timeout helper Thread ID is 2682
2022-04-18T21:35:27.577Z,1650317727.577 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2022-04-18T21:35:27.577Z,1650317727.577 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2022-04-18T21:35:27.589Z,1650317727.589 [ComponentRegistry](INFO): Shutting down WetLabsSeaOWL_UV_A ThreadHandler
2022-04-18T21:35:27.589Z,1650317727.589 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2022-04-18T21:35:27.589Z,1650317727.589 [WetLabsSeaOWL_UV_A](INFO): Join timeout helper Thread ID is 2683
2022-04-18T21:35:27.657Z,1650317727.657 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Uninitializing protected caller thread.
2022-04-18T21:35:27.657Z,1650317727.657 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2022-04-18T21:35:27.669Z,1650317727.669 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2022-04-18T21:35:27.669Z,1650317727.669 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2022-04-18T21:35:27.669Z,1650317727.669 [CTD_Seabird](INFO): Join timeout helper Thread ID is 2684
2022-04-18T21:35:28.241Z,1650317728.241 [CTD_Seabird](INFO): Powering down
2022-04-18T21:35:28.253Z,1650317728.253 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2022-04-18T21:35:28.253Z,1650317728.253 [CTD_Seabird](INFO): Powering down
2022-04-18T21:35:28.265Z,1650317728.265 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2022-04-18T21:35:28.275Z,1650317728.275 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2022-04-18T21:35:28.275Z,1650317728.275 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2022-04-18T21:35:28.276Z,1650317728.276 [Radio_Surface](INFO): Join timeout helper Thread ID is 2685
2022-04-18T21:35:28.493Z,1650317728.493 [Radio_Surface](INFO): Powering down
2022-04-18T21:35:28.495Z,1650317728.495 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2022-04-18T21:35:28.496Z,1650317728.496 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2022-04-18T21:35:28.513Z,1650317728.513 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler
2022-04-18T21:35:28.513Z,1650317728.513 [Onboard ThreadHandler](INFO): Thread cancelled.
2022-04-18T21:35:28.513Z,1650317728.513 [Onboard](INFO): Join timeout helper Thread ID is 2686
2022-04-18T21:35:29.053Z,1650317729.053 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2022-04-18T21:35:29.197Z,1650317729.197 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread.
2022-04-18T21:35:29.197Z,1650317729.197 [Onboard ThreadHandler](INFO): Thread cancelled.
2022-04-18T21:35:29.206Z,1650317729.206 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2022-04-18T21:35:29.206Z,1650317729.206 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2022-04-18T21:35:29.206Z,1650317729.206 [DataOverHttps](INFO): Join timeout helper Thread ID is 2687
2022-04-18T21:35:30.057Z,1650317730.057 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2022-04-18T21:35:30.058Z,1650317730.058 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2022-04-18T21:35:30.065Z,1650317730.065 [ComponentRegistry](INFO): Shutting down BackseatComponent ThreadHandler
2022-04-18T21:35:30.065Z,1650317730.065 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2022-04-18T21:35:30.066Z,1650317730.066 [BackseatComponent](INFO): Join timeout helper Thread ID is 2688
2022-04-18T21:35:30.190Z,1650317730.190 [BackseatComponent ThreadHandler](INFO): Uninitializing protected caller thread.
2022-04-18T21:35:30.190Z,1650317730.190 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2022-04-18T21:35:30.205Z,1650317730.205 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2022-04-18T21:35:30.205Z,1650317730.205 [logger ThreadHandler](INFO): Thread cancelled.
2022-04-18T21:35:30.206Z,1650317730.206 [logger](INFO): Join timeout helper Thread ID is 2689
2022-04-18T21:35:30.213Z,1650317730.213 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2022-04-18T21:35:30.213Z,1650317730.213 [logger ThreadHandler](INFO): Thread cancelled.
2022-04-18T21:35:30.225Z,1650317730.225 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2022-04-18T21:35:30.225Z,1650317730.225 [CommandLine ThreadHandler](INFO): Thread cancelled.
2022-04-18T21:35:30.226Z,1650317730.226 [CommandLine](INFO): Join timeout helper Thread ID is 2690
2022-04-18T21:35:30.257Z,1650317730.257 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2022-04-18T21:35:30.257Z,1650317730.257 [CommandLine ThreadHandler](INFO): Thread cancelled.
2022-04-18T21:35:30.265Z,1650317730.265 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler
2022-04-18T21:35:30.265Z,1650317730.265 [CommandExec ThreadHandler](INFO): Thread cancelled.
2022-04-18T21:35:30.266Z,1650317730.266 [CommandExec](INFO): Join timeout helper Thread ID is 2691
2022-04-18T21:35:30.267Z,1650317730.267 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2022-04-18T21:35:30.267Z,1650317730.267 [controlThread ThreadHandler](INFO): Thread cancelled.
2022-04-18T21:35:30.268Z,1650317730.268 [controlThread](INFO): Join timeout helper Thread ID is 2692
2022-04-18T21:35:30.321Z,1650317730.321 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2022-04-18T21:35:30.321Z,1650317730.321 [controlThread](DEBUG): Uninitializing ControlThread
2022-04-18T21:35:30.322Z,1650317730.322 [AHRS_M2](INFO): Powering down
2022-04-18T21:35:30.394Z,1650317730.394 [Micromodem](INFO): Powering down
2022-04-18T21:35:30.490Z,1650317730.490 [NAL9602](INFO): Powering down
2022-04-18T21:35:30.565Z,1650317730.565 [RDI_Pathfinder](INFO): Powering down
2022-04-18T21:35:30.637Z,1650317730.637 [RDI_PathfinderUp](INFO): Powering down
2022-04-18T21:35:30.638Z,1650317730.638 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2022-04-18T21:35:30.639Z,1650317730.639 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2022-04-18T21:35:30.640Z,1650317730.640 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2022-04-18T21:35:30.641Z,1650317730.641 [MissionManager](INFO): Uninitializing Mission Default
2022-04-18T21:35:30.641Z,1650317730.641 [Default] Stopped
2022-04-18T21:35:30.641Z,1650317730.641 [Default](DEBUG): Aggregate::uninitialize Default
2022-04-18T21:35:30.641Z,1650317730.641 [Default:B.GoToSurface] Stopped
2022-04-18T21:35:30.641Z,1650317730.641 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2022-04-18T21:35:30.641Z,1650317730.641 [Default:CheckIn] Stopped
2022-04-18T21:35:30.641Z,1650317730.641 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-04-18T21:35:30.641Z,1650317730.641 [Default:CheckIn:Read_Iridium] Stopped
2022-04-18T21:35:30.644Z,1650317730.644 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2022-04-18T21:35:30.644Z,1650317730.644 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2022-04-18T21:35:30.645Z,1650317730.645 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2022-04-18T21:35:30.645Z,1650317730.645 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2022-04-18T21:35:30.645Z,1650317730.645 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2022-04-18T21:35:30.645Z,1650317730.645 [BuoyancyServo](INFO): Powering down
2022-04-18T21:35:30.657Z,1650317730.657 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2022-04-18T21:35:30.657Z,1650317730.657 [ElevatorServo](INFO): Powering down
2022-04-18T21:35:30.658Z,1650317730.658 [MassServo](DEBUG): Uninitialize Mass Servo.
2022-04-18T21:35:30.658Z,1650317730.658 [MassServo](INFO): Powering down
2022-04-18T21:35:30.658Z,1650317730.658 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2022-04-18T21:35:30.659Z,1650317730.659 [RudderServo](INFO): Powering down
2022-04-18T21:35:30.659Z,1650317730.659 [ThrusterHE](DEBUG): Uninitialize Thruster Servo.
2022-04-18T21:35:30.659Z,1650317730.659 [ThrusterHE](INFO): Powering down
2022-04-18T21:35:30.660Z,1650317730.660 [SBIT](DEBUG): Uninitialize SBIT Component.
2022-04-18T21:35:30.660Z,1650317730.660 [IBIT](DEBUG): Uninitialize IBIT Component.
2022-04-18T21:35:30.661Z,1650317730.661 [CBIT](DEBUG): Uninitialize CBIT Component.
2022-04-18T21:35:30.661Z,1650317730.661 [CBIT](DEBUG): Powering off loads.
2022-04-18T21:35:30.672Z,1650317730.672 [CBIT](DEBUG): Disabling WDT.
2022-04-18T21:35:30.684Z,1650317730.684 [CBIT](DEBUG): Opening all GF detection circuits.
2022-04-18T21:35:30.685Z,1650317730.685 [controlThread ThreadHandler](INFO): Thread cancelled.
2022-04-18T21:35:30.691Z,1650317730.691 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2022-04-18T21:35:30.695Z,1650317730.695 [Onboard ThreadHandler](INFO): Thread cancelled.
2022-04-18T21:35:30.704Z,1650317730.704 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2022-04-18T21:35:30.748Z,1650317730.748 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2022-04-18T21:35:30.796Z,1650317730.796 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2022-04-18T21:35:30.799Z,1650317730.799 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2022-04-18T21:35:30.859Z,1650317730.859 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2022-04-18T21:35:30.929Z,1650317730.929 [logger ThreadHandler](INFO): Thread cancelled.