2025-01-14T06:13:43.908Z,1736835223.908 [CommandExec](IMPORTANT): got command set PAM.ShallowBoundRegainDepth 20 meter
2025-01-14T06:13:43.909Z,1736835223.909 [CommandExec](IMPORTANT): got command set PAM.DeepBoundInitial 50 meter
2025-01-14T06:13:43.910Z,1736835223.910 [CommandExec](IMPORTANT): got command set PAM.ShallowBoundInitial 30 meter
2025-01-14T06:13:43.911Z,1736835223.911 [CommandExec](IMPORTANT): got command set PAM.DeepBoundFineTune 55 meter
2025-01-14T06:13:43.911Z,1736835223.911 [CommandExec](IMPORTANT): got command set PAM.ShallowBoundFineTune 25 meter
2025-01-14T06:13:43.912Z,1736835223.912 [CommandExec](IMPORTANT): got command set PAM.MaxDepth 70 meter
2025-01-14T06:13:43.913Z,1736835223.913 [CommandExec](IMPORTANT): got command set PAM.LatListening 36.698 degree
2025-01-14T06:13:43.917Z,1736835223.917 [CommandExec](IMPORTANT): got command schedule resume
2025-01-14T06:13:43.917Z,1736835223.917 [CommandExec](IMPORTANT): Scheduling is resumed
2025-01-14T06:13:43.917Z,1736835223.917 [CommandExec](IMPORTANT): got command restart logs
2025-01-14T06:13:46.672Z,1736835226.672 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-01-14T06:13:58.708Z,1736835238.708 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-01-14T06:13:59.599Z,1736835239.599 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2025-01-14T06:13:59.610Z,1736835239.610 [BPC1](INFO): Received data from all battery sticks.
2025-01-14T06:14:00.524Z,1736835240.524 [CommandExec](IMPORTANT): got command set PAM.LonListening -121.945 degree
2025-01-14T06:14:00.524Z,1736835240.524 [CommandExec](IMPORTANT): got command run
2025-01-14T06:14:00.526Z,1736835240.526 [CommandExec](IMPORTANT): Running 
2025-01-14T06:14:00.813Z,1736835240.813 [DefaultWithUndock] Stopped
2025-01-14T06:14:00.813Z,1736835240.813 [DefaultWithUndock](DEBUG): Aggregate::uninitialize DefaultWithUndock
2025-01-14T06:14:00.813Z,1736835240.813 [DefaultWithUndock:SurfaceDefault] Stopped
2025-01-14T06:14:00.813Z,1736835240.813 [DefaultWithUndock:SurfaceDefault](DEBUG): Aggregate::uninitialize DefaultWithUndock:SurfaceDefault
2025-01-14T06:14:00.813Z,1736835240.813 [DefaultWithUndock:SurfaceDefault:A.GoToSurface] Stopped
2025-01-14T06:14:00.813Z,1736835240.813 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2025-01-14T06:14:00.813Z,1736835240.813 [DefaultWithUndock:SurfaceDefault:CheckIn] Stopped
2025-01-14T06:14:00.813Z,1736835240.813 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::uninitialize DefaultWithUndock:SurfaceDefault:CheckIn
2025-01-14T06:14:00.814Z,1736835240.814 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait] Stopped
2025-01-14T06:14:00.814Z,1736835240.814 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-01-14T06:14:00.814Z,1736835240.814 [MissionManager](IMPORTANT): Started mission PAM
2025-01-14T06:14:00.814Z,1736835240.814 [PAM] Running Loop=1
2025-01-14T06:14:00.814Z,1736835240.814 [PAM](DEBUG): Aggregate::initialize PAM
2025-01-14T06:14:00.814Z,1736835240.814 [PAM:Science] Running Loop=1
2025-01-14T06:14:00.814Z,1736835240.814 [PAM:Science](DEBUG): Aggregate::initialize PAM:Science
2025-01-14T06:14:00.814Z,1736835240.814 [PAM:Science:A] Running Loop=1
2025-01-14T06:14:00.814Z,1736835240.814 [PAM:Science:B] Running Loop=1
2025-01-14T06:14:00.815Z,1736835240.815 [PAM:Science:C] Running Loop=1
2025-01-14T06:14:00.815Z,1736835240.815 [PAM:Science:D] Running Loop=1
2025-01-14T06:14:00.815Z,1736835240.815 [PAM:Science:E] Running Loop=1
2025-01-14T06:14:00.815Z,1736835240.815 [PAM:Science:F] Running Loop=1
2025-01-14T06:14:00.815Z,1736835240.815 [PAM:Science:Read_Oil] Running Loop=1
2025-01-14T06:14:00.815Z,1736835240.815 [PAM:Science:PeakDetectChl] Running Loop=1
2025-01-14T06:14:00.815Z,1736835240.815 [PAM:Science:PeakDetectChl](DEBUG): Aggregate::initialize PAM:Science:PeakDetectChl
2025-01-14T06:14:00.815Z,1736835240.815 [PAM:Science:PeakDetectChl:A.PeakDetectVsDepth] Running Loop=1
2025-01-14T06:14:00.815Z,1736835240.815 [PAM:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Initialize.
2025-01-14T06:14:00.841Z,1736835240.841 [PAM:Science:HighestChlPeakReport] Running Loop=1
2025-01-14T06:14:00.841Z,1736835240.841 [PAM:Science:HighestChlPeakReport](DEBUG): Aggregate::initialize PAM:Science:HighestChlPeakReport
2025-01-14T06:14:00.841Z,1736835240.841 [PAM:Science:HighestChlPeakReport:A.PeakDetectHorizontal] Running Loop=1
2025-01-14T06:14:00.841Z,1736835240.841 [PAM:Science:HighestChlPeakReport:A.PeakDetectHorizontal](INFO): Initialize.
2025-01-14T06:14:00.841Z,1736835240.841 [PAM:Science:PeakDetectNO3] Running Loop=1
2025-01-14T06:14:00.842Z,1736835240.842 [PAM:Science:PeakDetectNO3](DEBUG): Aggregate::initialize PAM:Science:PeakDetectNO3
2025-01-14T06:14:00.842Z,1736835240.842 [PAM:Science:PeakDetectNO3:A.PeakDetectVsDepth] Running Loop=1
2025-01-14T06:14:00.842Z,1736835240.842 [PAM:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Initialize.
2025-01-14T06:14:00.843Z,1736835240.843 [PAM:Science:PeakDetectOil] Running Loop=1
2025-01-14T06:14:00.843Z,1736835240.843 [PAM:Science:PeakDetectOil](DEBUG): Aggregate::initialize PAM:Science:PeakDetectOil
2025-01-14T06:14:00.852Z,1736835240.852 [PAM:Science:PeakDetectOil:A.PeakDetectVsDepth] Running Loop=1
2025-01-14T06:14:00.852Z,1736835240.852 [PAM:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Initialize.
2025-01-14T06:14:00.854Z,1736835240.854 [PAM:Science:HighestOilPeakReport] Running Loop=1
2025-01-14T06:14:00.854Z,1736835240.854 [PAM:Science:HighestOilPeakReport](DEBUG): Aggregate::initialize PAM:Science:HighestOilPeakReport
2025-01-14T06:14:00.854Z,1736835240.854 [PAM:Science:HighestOilPeakReport:A.PeakDetectHorizontal] Running Loop=1
2025-01-14T06:14:00.854Z,1736835240.854 [PAM:Science:HighestOilPeakReport:A.PeakDetectHorizontal](INFO): Initialize.
2025-01-14T06:14:00.855Z,1736835240.855 [PAM:Science:PeakDetectFDOM] Running Loop=1
2025-01-14T06:14:00.855Z,1736835240.855 [PAM:Science:PeakDetectFDOM](DEBUG): Aggregate::initialize PAM:Science:PeakDetectFDOM
2025-01-14T06:14:00.855Z,1736835240.855 [PAM:Science:PeakDetectFDOM:A.PeakDetectVsDepth] Running Loop=1
2025-01-14T06:14:00.855Z,1736835240.855 [PAM:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Initialize.
2025-01-14T06:14:00.868Z,1736835240.868 [PAM:Science:PeakDetectSalinity] Running Loop=1
2025-01-14T06:14:00.868Z,1736835240.868 [PAM:Science:PeakDetectSalinity](DEBUG): Aggregate::initialize PAM:Science:PeakDetectSalinity
2025-01-14T06:14:00.869Z,1736835240.869 [PAM:Science:PeakDetectSalinity:A.PeakDetectVsDepth] Running Loop=1
2025-01-14T06:14:00.869Z,1736835240.869 [PAM:Science:PeakDetectSalinity:A.PeakDetectVsDepth](DEBUG): Initialize.
2025-01-14T06:14:00.870Z,1736835240.870 [PAM:Science:HighestSaltPeakReport] Running Loop=1
2025-01-14T06:14:00.870Z,1736835240.870 [PAM:Science:HighestSaltPeakReport](DEBUG): Aggregate::initialize PAM:Science:HighestSaltPeakReport
2025-01-14T06:14:00.870Z,1736835240.870 [PAM:Science:HighestSaltPeakReport:A.PeakDetectHorizontal] Running Loop=1
2025-01-14T06:14:00.870Z,1736835240.870 [PAM:Science:HighestSaltPeakReport:A.PeakDetectHorizontal](INFO): Initialize.
2025-01-14T06:14:00.871Z,1736835240.871 [PAM:Science:PeakDetectPlanktivoreLMavgROI] Running Loop=1
2025-01-14T06:14:00.871Z,1736835240.871 [PAM:Science:PeakDetectPlanktivoreLMavgROI](DEBUG): Aggregate::initialize PAM:Science:PeakDetectPlanktivoreLMavgROI
2025-01-14T06:14:00.871Z,1736835240.871 [PAM:Science:PeakDetectPlanktivoreLMavgROI:A.PeakDetectVsDepth] Running Loop=1
2025-01-14T06:14:00.871Z,1736835240.871 [PAM:Science:PeakDetectPlanktivoreLMavgROI:A.PeakDetectVsDepth](DEBUG): Initialize.
2025-01-14T06:14:00.871Z,1736835240.871 [PAM:Science:PeakDetectPlanktivoreLMavgROI:A.PeakDetectVsDepth](INFO): No ElementURI called _.planktivore_LM_AvgRois , but backseat URI detected. Waiting for presence.
2025-01-14T06:14:00.880Z,1736835240.880 [PAM:Science:PeakDetectPlanktivoreHMavgROI] Running Loop=1
2025-01-14T06:14:00.880Z,1736835240.880 [PAM:Science:PeakDetectPlanktivoreHMavgROI](DEBUG): Aggregate::initialize PAM:Science:PeakDetectPlanktivoreHMavgROI
2025-01-14T06:14:00.881Z,1736835240.881 [PAM:Science:PeakDetectPlanktivoreHMavgROI:A.PeakDetectVsDepth] Running Loop=1
2025-01-14T06:14:00.881Z,1736835240.881 [PAM:Science:PeakDetectPlanktivoreHMavgROI:A.PeakDetectVsDepth](DEBUG): Initialize.
2025-01-14T06:14:00.881Z,1736835240.881 [PAM:Science:PeakDetectPlanktivoreHMavgROI:A.PeakDetectVsDepth](INFO): No ElementURI called _.planktivore_HM_AvgRois , but backseat URI detected. Waiting for presence.
2025-01-14T06:14:00.882Z,1736835240.882 [PAM:Science:PeakDetectPlanktivoreDiatoms] Running Loop=1
2025-01-14T06:14:00.882Z,1736835240.882 [PAM:Science:PeakDetectPlanktivoreDiatoms](DEBUG): Aggregate::initialize PAM:Science:PeakDetectPlanktivoreDiatoms
2025-01-14T06:14:00.882Z,1736835240.882 [PAM:Science:PeakDetectPlanktivoreDiatoms:A.PeakDetectVsDepth] Running Loop=1
2025-01-14T06:14:00.882Z,1736835240.882 [PAM:Science:PeakDetectPlanktivoreDiatoms:A.PeakDetectVsDepth](DEBUG): Initialize.
2025-01-14T06:14:00.883Z,1736835240.883 [PAM:Science:PeakDetectPlanktivoreDiatoms:A.PeakDetectVsDepth](INFO): No ElementURI called _.planktivore_diatoms , but backseat URI detected. Waiting for presence.
2025-01-14T06:14:00.892Z,1736835240.892 [PAM:Science:PeakDetectPlanktivoreDinoflagellates] Running Loop=1
2025-01-14T06:14:00.892Z,1736835240.892 [PAM:Science:PeakDetectPlanktivoreDinoflagellates](DEBUG): Aggregate::initialize PAM:Science:PeakDetectPlanktivoreDinoflagellates
2025-01-14T06:14:00.892Z,1736835240.892 [PAM:Science:PeakDetectPlanktivoreDinoflagellates:A.PeakDetectVsDepth] Running Loop=1
2025-01-14T06:14:00.892Z,1736835240.892 [PAM:Science:PeakDetectPlanktivoreDinoflagellates:A.PeakDetectVsDepth](DEBUG): Initialize.
2025-01-14T06:14:00.893Z,1736835240.893 [PAM:Science:PeakDetectPlanktivoreDinoflagellates:A.PeakDetectVsDepth](INFO): No ElementURI called _.planktivore_dinoflagellates , but backseat URI detected. Waiting for presence.
2025-01-14T06:14:00.894Z,1736835240.894 [PAM:Science:ChlThreshTrigger] Running Loop=1
2025-01-14T06:14:00.894Z,1736835240.894 [PAM:Science:ChlThreshTrigger](DEBUG): Aggregate::initialize PAM:Science:ChlThreshTrigger
2025-01-14T06:14:00.894Z,1736835240.894 [PAM:Science:ChlThreshTrigger:A.ValueDetect] Running Loop=1
2025-01-14T06:14:00.894Z,1736835240.894 [PAM:Science:ChlThreshTrigger:A.ValueDetect](INFO): Initialize.
2025-01-14T06:14:00.894Z,1736835240.894 [PAM:Science:OceanCurrent] Running Loop=1
2025-01-14T06:14:00.894Z,1736835240.894 [PAM:Science:OceanCurrent](DEBUG): Aggregate::initialize PAM:Science:OceanCurrent
2025-01-14T06:14:00.894Z,1736835240.894 [PAM:Science:OceanCurrent:A.] Running Loop=1
2025-01-14T06:14:00.894Z,1736835240.894 [PAM:Science:OceanCurrent:A.](INFO): Initializing CurrentEstimator.
2025-01-14T06:14:00.895Z,1736835240.895 [PAM:StandardEnvelopes] Running Loop=1
2025-01-14T06:14:00.895Z,1736835240.895 [PAM:StandardEnvelopes](DEBUG): Aggregate::initialize PAM:StandardEnvelopes
2025-01-14T06:14:00.895Z,1736835240.895 [PAM:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1
2025-01-14T06:14:00.895Z,1736835240.895 [PAM:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent.
2025-01-14T06:14:00.895Z,1736835240.895 [PAM:StandardEnvelopes:B.DepthEnvelope] Running Loop=1
2025-01-14T06:14:00.895Z,1736835240.895 [PAM:StandardEnvelopes:B.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent.
2025-01-14T06:14:00.895Z,1736835240.895 [PAM:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1
2025-01-14T06:14:00.895Z,1736835240.895 [PAM:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Initialize OffshoreEnvelopeComponent.
2025-01-14T06:14:00.895Z,1736835240.895 [PAM:AbortDrift] Running Loop=1
2025-01-14T06:14:00.908Z,1736835240.908 [PAM:AbortDrift](DEBUG): Aggregate::initialize PAM:AbortDrift
2025-01-14T06:14:00.908Z,1736835240.908 [PAM:AbortDrift:A] Running Loop=1
2025-01-14T06:14:00.908Z,1736835240.908 [PAM:BackseatDriver] Running Loop=1
2025-01-14T06:14:00.909Z,1736835240.909 [PAM:BackseatDriver](DEBUG): Aggregate::initialize PAM:BackseatDriver
2025-01-14T06:14:00.909Z,1736835240.909 [PAM:BackseatDriver:A.BackseatDriver] Running Loop=1
2025-01-14T06:14:00.909Z,1736835240.909 [PAM:K] Running Loop=1
2025-01-14T06:14:00.909Z,1736835240.909 [PAM:L] Running Loop=1
2025-01-14T06:14:00.909Z,1736835240.909 [PAM:M] Running Loop=1
2025-01-14T06:14:00.909Z,1736835240.909 [PAM:N] Running Loop=1
2025-01-14T06:14:00.909Z,1736835240.909 [PAM:C] Running Loop=1
2025-01-14T06:14:00.910Z,1736835240.910 [PAM:N] Running Loop=1
2025-01-14T06:14:00.910Z,1736835240.910 [PAM:M] Running Loop=1
2025-01-14T06:14:00.911Z,1736835240.911 [PAM:L] Running Loop=1
2025-01-14T06:14:00.911Z,1736835240.911 [PAM:K] Running Loop=1
2025-01-14T06:14:00.911Z,1736835240.911 [PAM:BackseatDriver] Running Loop=1
2025-01-14T06:14:00.911Z,1736835240.911 [PAM:AbortDrift] Running Loop=1
2025-01-14T06:14:00.920Z,1736835240.920 [PAM:AbortDrift:A](INFO): Insert acoustic timeout set to  240.000000 h .
2025-01-14T06:14:00.921Z,1736835240.921 [PAM:AbortDrift:A] Stopped
2025-01-14T06:14:00.921Z,1736835240.921 [PAM:AbortDrift:B.AbortDrift] Running Loop=1
2025-01-14T06:14:00.921Z,1736835240.921 [PAM:AbortDrift:B.AbortDrift](INFO): Initializing AbortDrift.
2025-01-14T06:14:00.921Z,1736835240.921 [PAM:AbortDrift:B.AbortDrift](IMPORTANT): Acoustic timeout set to: 240.00 hours.
2025-01-14T06:14:00.921Z,1736835240.921 [PAM:StandardEnvelopes] Running Loop=1
2025-01-14T06:14:00.921Z,1736835240.921 [PAM:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1
2025-01-14T06:14:00.922Z,1736835240.922 [PAM:StandardEnvelopes:B.DepthEnvelope] Running Loop=1
2025-01-14T06:14:00.922Z,1736835240.922 [PAM:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1
2025-01-14T06:14:00.922Z,1736835240.922 [PAM:C] Stopped
2025-01-14T06:14:00.923Z,1736835240.923 [PAM:D] Running Loop=1
2025-01-14T06:14:00.923Z,1736835240.923 [PAM:Science] Running Loop=1
2025-01-14T06:14:00.932Z,1736835240.932 [PAM:Science:ChlThreshTrigger] Stopped
2025-01-14T06:14:00.932Z,1736835240.932 [PAM:Science:ChlThreshTrigger](DEBUG): Aggregate::uninitialize PAM:Science:ChlThreshTrigger
2025-01-14T06:14:00.932Z,1736835240.932 [PAM:Science:ChlThreshTrigger:A.ValueDetect] Stopped
2025-01-14T06:14:00.932Z,1736835240.932 [PAM:Science:ChlThreshTrigger:A.ValueDetect](DEBUG): Uninitialize.
2025-01-14T06:14:00.932Z,1736835240.932 [PAM:Science:PeakDetectPlanktivoreDinoflagellates] Stopped
2025-01-14T06:14:00.933Z,1736835240.933 [PAM:Science:PeakDetectPlanktivoreDinoflagellates](DEBUG): Aggregate::uninitialize PAM:Science:PeakDetectPlanktivoreDinoflagellates
2025-01-14T06:14:00.933Z,1736835240.933 [PAM:Science:PeakDetectPlanktivoreDinoflagellates:A.PeakDetectVsDepth] Stopped
2025-01-14T06:14:00.933Z,1736835240.933 [PAM:Science:PeakDetectPlanktivoreDinoflagellates:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2025-01-14T06:14:00.933Z,1736835240.933 [PAM:Science:PeakDetectPlanktivoreDiatoms] Stopped
2025-01-14T06:14:00.933Z,1736835240.933 [PAM:Science:PeakDetectPlanktivoreDiatoms](DEBUG): Aggregate::uninitialize PAM:Science:PeakDetectPlanktivoreDiatoms
2025-01-14T06:14:00.933Z,1736835240.933 [PAM:Science:PeakDetectPlanktivoreDiatoms:A.PeakDetectVsDepth] Stopped
2025-01-14T06:14:00.933Z,1736835240.933 [PAM:Science:PeakDetectPlanktivoreDiatoms:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2025-01-14T06:14:00.933Z,1736835240.933 [PAM:Science:PeakDetectPlanktivoreHMavgROI] Stopped
2025-01-14T06:14:00.933Z,1736835240.933 [PAM:Science:PeakDetectPlanktivoreHMavgROI](DEBUG): Aggregate::uninitialize PAM:Science:PeakDetectPlanktivoreHMavgROI
2025-01-14T06:14:00.933Z,1736835240.933 [PAM:Science:PeakDetectPlanktivoreHMavgROI:A.PeakDetectVsDepth] Stopped
2025-01-14T06:14:00.933Z,1736835240.933 [PAM:Science:PeakDetectPlanktivoreHMavgROI:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2025-01-14T06:14:00.933Z,1736835240.933 [PAM:Science:PeakDetectPlanktivoreLMavgROI] Stopped
2025-01-14T06:14:00.934Z,1736835240.934 [PAM:Science:PeakDetectPlanktivoreLMavgROI](DEBUG): Aggregate::uninitialize PAM:Science:PeakDetectPlanktivoreLMavgROI
2025-01-14T06:14:00.934Z,1736835240.934 [PAM:Science:PeakDetectPlanktivoreLMavgROI:A.PeakDetectVsDepth] Stopped
2025-01-14T06:14:00.934Z,1736835240.934 [PAM:Science:PeakDetectPlanktivoreLMavgROI:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2025-01-14T06:14:00.934Z,1736835240.934 [PAM:Science:HighestSaltPeakReport] Stopped
2025-01-14T06:14:00.934Z,1736835240.934 [PAM:Science:HighestSaltPeakReport](DEBUG): Aggregate::uninitialize PAM:Science:HighestSaltPeakReport
2025-01-14T06:14:00.934Z,1736835240.934 [PAM:Science:HighestSaltPeakReport:A.PeakDetectHorizontal] Stopped
2025-01-14T06:14:00.934Z,1736835240.934 [PAM:Science:HighestSaltPeakReport:A.PeakDetectHorizontal](DEBUG): Uninitialize.
2025-01-14T06:14:00.934Z,1736835240.934 [PAM:Science:PeakDetectSalinity] Stopped
2025-01-14T06:14:00.934Z,1736835240.934 [PAM:Science:PeakDetectSalinity](DEBUG): Aggregate::uninitialize PAM:Science:PeakDetectSalinity
2025-01-14T06:14:00.934Z,1736835240.934 [PAM:Science:PeakDetectSalinity:A.PeakDetectVsDepth] Stopped
2025-01-14T06:14:00.934Z,1736835240.934 [PAM:Science:PeakDetectSalinity:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2025-01-14T06:14:00.934Z,1736835240.934 [PAM:Science:PeakDetectFDOM] Stopped
2025-01-14T06:14:00.934Z,1736835240.934 [PAM:Science:PeakDetectFDOM](DEBUG): Aggregate::uninitialize PAM:Science:PeakDetectFDOM
2025-01-14T06:14:00.935Z,1736835240.935 [PAM:Science:PeakDetectFDOM:A.PeakDetectVsDepth] Stopped
2025-01-14T06:14:00.935Z,1736835240.935 [PAM:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2025-01-14T06:14:00.935Z,1736835240.935 [PAM:Science:HighestOilPeakReport] Stopped
2025-01-14T06:14:00.935Z,1736835240.935 [PAM:Science:HighestOilPeakReport](DEBUG): Aggregate::uninitialize PAM:Science:HighestOilPeakReport
2025-01-14T06:14:00.935Z,1736835240.935 [PAM:Science:HighestOilPeakReport:A.PeakDetectHorizontal] Stopped
2025-01-14T06:14:00.935Z,1736835240.935 [PAM:Science:HighestOilPeakReport:A.PeakDetectHorizontal](DEBUG): Uninitialize.
2025-01-14T06:14:00.935Z,1736835240.935 [PAM:Science:PeakDetectOil] Stopped
2025-01-14T06:14:00.935Z,1736835240.935 [PAM:Science:PeakDetectOil](DEBUG): Aggregate::uninitialize PAM:Science:PeakDetectOil
2025-01-14T06:14:00.935Z,1736835240.935 [PAM:Science:PeakDetectOil:A.PeakDetectVsDepth] Stopped
2025-01-14T06:14:00.935Z,1736835240.935 [PAM:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2025-01-14T06:14:00.935Z,1736835240.935 [PAM:Science:PeakDetectNO3] Stopped
2025-01-14T06:14:00.944Z,1736835240.944 [PAM:Science:PeakDetectNO3](DEBUG): Aggregate::uninitialize PAM:Science:PeakDetectNO3
2025-01-14T06:14:00.944Z,1736835240.944 [PAM:Science:PeakDetectNO3:A.PeakDetectVsDepth] Stopped
2025-01-14T06:14:00.944Z,1736835240.944 [PAM:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2025-01-14T06:14:00.944Z,1736835240.944 [PAM:Science:HighestChlPeakReport] Stopped
2025-01-14T06:14:00.944Z,1736835240.944 [PAM:Science:HighestChlPeakReport](DEBUG): Aggregate::uninitialize PAM:Science:HighestChlPeakReport
2025-01-14T06:14:00.944Z,1736835240.944 [PAM:Science:HighestChlPeakReport:A.PeakDetectHorizontal] Stopped
2025-01-14T06:14:00.944Z,1736835240.944 [PAM:Science:HighestChlPeakReport:A.PeakDetectHorizontal](DEBUG): Uninitialize.
2025-01-14T06:14:00.944Z,1736835240.944 [PAM:Science:PeakDetectChl] Stopped
2025-01-14T06:14:00.944Z,1736835240.944 [PAM:Science:PeakDetectChl](DEBUG): Aggregate::uninitialize PAM:Science:PeakDetectChl
2025-01-14T06:14:00.944Z,1736835240.944 [PAM:Science:PeakDetectChl:A.PeakDetectVsDepth] Stopped
2025-01-14T06:14:00.945Z,1736835240.945 [PAM:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2025-01-14T06:14:00.945Z,1736835240.945 [PAM:Science:OceanCurrent:A.] Running Loop=1
2025-01-14T06:14:00.946Z,1736835240.946 [PAM:Science:Read_Oil] Stopped
2025-01-14T06:14:00.946Z,1736835240.946 [PAM:Science:F] Running Loop=1
2025-01-14T06:14:00.946Z,1736835240.946 [PAM:Science:F](DEBUG): Initialize ReadDataComponent to sense WetLabsUBAT.average_bioluminescence
2025-01-14T06:14:00.946Z,1736835240.946 [PAM:Science:E] Running Loop=1
2025-01-14T06:14:00.947Z,1736835240.947 [PAM:Science:E](DEBUG): Initialize ReadDataComponent to sense mass_concentration_of_chlorophyll_in_sea_water
2025-01-14T06:14:00.947Z,1736835240.947 [PAM:Science:D] Stopped
2025-01-14T06:14:00.947Z,1736835240.947 [PAM:Science:C] Running Loop=1
2025-01-14T06:14:00.956Z,1736835240.956 [PAM:Science:C](DEBUG): Initialize ReadDataComponent to sense CTD_Seabird.sea_water_temperature
2025-01-14T06:14:00.957Z,1736835240.957 [PAM:Science:C](DEBUG): Initialize ReadDataComponent to sense CTD_Seabird.sea_water_salinity
2025-01-14T06:14:00.957Z,1736835240.957 [PAM:Science:B] Running Loop=1
2025-01-14T06:14:00.957Z,1736835240.957 [PAM:Science:B](DEBUG): Initialize ReadDataComponent to sense sea_water_temperature
2025-01-14T06:14:00.958Z,1736835240.958 [PAM:Science:B](DEBUG): Initialize ReadDataComponent to sense sea_water_salinity
2025-01-14T06:14:00.958Z,1736835240.958 [PAM:Science:A] Stopped
2025-01-14T06:14:01.092Z,1736835241.092 [WetLabsBB2FL](INFO): Powering up
2025-01-14T06:14:01.171Z,1736835241.171 [PAM:AbortDrift:B.AbortDrift](INFO): Received valid gps time fix: 1736835072.00. Resetting abort timer.
2025-01-14T06:14:01.180Z,1736835241.180 [PAM:D] Stopped
2025-01-14T06:14:01.180Z,1736835241.180 [PAM:F] Running Loop=1
2025-01-14T06:14:01.698Z,1736835241.698 [PAM:F] Stopped
2025-01-14T06:14:01.698Z,1736835241.698 [PAM:G] Running Loop=1
2025-01-14T06:14:01.728Z,1736835241.728 [WetLabsUBAT](INFO): Powering up
2025-01-14T06:14:01.983Z,1736835241.983 [PAM:G] Stopped
2025-01-14T06:14:01.983Z,1736835241.983 [PAM:H] Running Loop=1
2025-01-14T06:14:02.390Z,1736835242.390 [PAM:H] Stopped
2025-01-14T06:14:02.390Z,1736835242.390 [PAM:O] Running Loop=1
2025-01-14T06:14:02.797Z,1736835242.797 [PAM:O] Stopped
2025-01-14T06:14:02.797Z,1736835242.797 [PAM:P] Running Loop=1
2025-01-14T06:14:03.219Z,1736835243.219 [PAM:P] Stopped
2025-01-14T06:14:03.219Z,1736835243.219 [PAM:Q] Running Loop=1
2025-01-14T06:14:03.686Z,1736835243.686 [PAM:Q] Stopped
2025-01-14T06:14:03.686Z,1736835243.686 [PAM:U] Running Loop=1
2025-01-14T06:14:04.005Z,1736835244.005 [PAM:U] Stopped
2025-01-14T06:14:04.006Z,1736835244.006 [PAM:R] Running Loop=1
2025-01-14T06:14:04.209Z,1736835244.209 [CTD_Seabird](ERROR): Failed to parse device response: <!--startlogging-->
2025-01-14T06:14:04.413Z,1736835244.413 [PAM:R] Stopped
2025-01-14T06:14:04.414Z,1736835244.414 [PAM:S] Running Loop=1
2025-01-14T06:14:04.829Z,1736835244.829 [PAM:S] Stopped
2025-01-14T06:14:04.829Z,1736835244.829 [PAM:V] Running Loop=1
2025-01-14T06:14:05.206Z,1736835245.206 [PAM:V](IMPORTANT): NeutralBuoyancy =  401.869354 cc .
2025-01-14T06:14:05.206Z,1736835245.206 [PAM:V] Stopped
2025-01-14T06:14:05.206Z,1736835245.206 [PAM:X] Running Loop=1
2025-01-14T06:14:05.632Z,1736835245.632 [PAM:X](IMPORTANT): BuoyancyAdjustmentStep =  16.000000 cc .
2025-01-14T06:14:05.632Z,1736835245.632 [PAM:X] Stopped
2025-01-14T06:14:05.632Z,1736835245.632 [PAM:Y] Running Loop=1
2025-01-14T06:14:06.019Z,1736835246.019 [PAM:Y](IMPORTANT): BuoyancyAdjustmentStepFineTune =  2.000000 cc .
2025-01-14T06:14:06.019Z,1736835246.019 [PAM:Y] Stopped
2025-01-14T06:14:06.020Z,1736835246.020 [PAM:Z] Running Loop=1
2025-01-14T06:14:06.414Z,1736835246.414 [PAM:Z](IMPORTANT): MassPosition =  21.805965 mm .
2025-01-14T06:14:06.414Z,1736835246.414 [PAM:Z] Stopped
2025-01-14T06:14:06.414Z,1736835246.414 [PAM:BA] Running Loop=1
2025-01-14T06:14:06.817Z,1736835246.817 [PAM:BA](IMPORTANT): MassPositionAdjustmentStep =  0.528000 mm .
2025-01-14T06:14:06.817Z,1736835246.817 [PAM:BA] Stopped
2025-01-14T06:14:06.817Z,1736835246.817 [PAM:BB] Running Loop=1
2025-01-14T06:14:07.233Z,1736835247.233 [PAM:BB](IMPORTANT): MassPositionAdjustmentStepFineTune =  0.066000 mm .
2025-01-14T06:14:07.233Z,1736835247.233 [PAM:BB] Stopped
2025-01-14T06:14:07.233Z,1736835247.233 [PAM:BC] Running Loop=1
2025-01-14T06:14:07.654Z,1736835247.654 [PAM:BC] Stopped
2025-01-14T06:14:07.654Z,1736835247.654 [PAM:BD] Running Loop=1
2025-01-14T06:14:08.029Z,1736835248.029 [PAM:BD] Stopped
2025-01-14T06:14:08.029Z,1736835248.029 [PAM:BE] Running Loop=1
2025-01-14T06:14:08.160Z,1736835248.160 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-01-14T06:14:08.434Z,1736835248.434 [PAM:BE](IMPORTANT): Initially: ShallowBound =  30.000000 m , DeepBound =  50.000000 m , BuoyancyAdjustmentStep =  16.000000 cc , WaitAfterBuoyancyChange =  5.000000 min .
2025-01-14T06:14:08.434Z,1736835248.434 [PAM:BE] Stopped
2025-01-14T06:14:08.435Z,1736835248.435 [PAM:BF] Running Loop=1
2025-01-14T06:14:08.861Z,1736835248.861 [PAM:BF] Stopped
2025-01-14T06:14:08.861Z,1736835248.861 [PAM:BG] Running Loop=1
2025-01-14T06:14:09.243Z,1736835249.243 [PAM:BG](IMPORTANT): TargetDepthMinusShallowBound =  10.000000 m .
2025-01-14T06:14:09.243Z,1736835249.243 [PAM:BG] Stopped
2025-01-14T06:14:09.243Z,1736835249.243 [PAM:BH] Running Loop=1
2025-01-14T06:14:09.662Z,1736835249.662 [PAM:BH] Stopped
2025-01-14T06:14:09.662Z,1736835249.662 [PAM:BI] Running Loop=1
2025-01-14T06:14:10.061Z,1736835250.061 [PAM:BI](IMPORTANT): DeepBoundMinusTargetDepth =  10.000000 m .
2025-01-14T06:14:10.061Z,1736835250.061 [PAM:BI] Stopped
2025-01-14T06:14:10.062Z,1736835250.062 [PAM:CheckTargetDepths] Running Loop=1
2025-01-14T06:14:10.062Z,1736835250.062 [PAM:CheckTargetDepths](DEBUG): Aggregate::initialize PAM:CheckTargetDepths
2025-01-14T06:14:10.062Z,1736835250.062 [PAM:CheckTargetDepths:CheckDepth] Running Loop=1
2025-01-14T06:14:10.062Z,1736835250.062 [PAM:CheckTargetDepths:CheckDepth](DEBUG): Aggregate::initialize PAM:CheckTargetDepths:CheckDepth
2025-01-14T06:14:10.062Z,1736835250.062 [PAM:CheckTargetDepths:CheckDepth:A] Running Loop=1
2025-01-14T06:14:10.474Z,1736835250.474 [PAM:CheckTargetDepths:CheckDepth] Stopped
2025-01-14T06:14:10.474Z,1736835250.474 [PAM:CheckTargetDepths:CheckDepth](DEBUG): Aggregate::uninitialize PAM:CheckTargetDepths:CheckDepth
2025-01-14T06:14:10.474Z,1736835250.474 [PAM:CheckTargetDepths:CheckDepth:A] Stopped
2025-01-14T06:14:10.474Z,1736835250.474 [PAM:CheckTargetDepths:B] Running Loop=1
2025-01-14T06:14:10.885Z,1736835250.885 [PAM:CheckTargetDepths:B] Stopped
2025-01-14T06:14:10.885Z,1736835250.885 [PAM:CheckTargetDepths](INFO): Completed PAM:CheckTargetDepths
2025-01-14T06:14:10.885Z,1736835250.885 [PAM:CheckTargetDepths] Stopped
2025-01-14T06:14:10.885Z,1736835250.885 [PAM:CheckTargetDepths](DEBUG): Aggregate::uninitialize PAM:CheckTargetDepths
2025-01-14T06:14:10.886Z,1736835250.886 [PAM:StartingMission] Running Loop=1
2025-01-14T06:14:10.886Z,1736835250.886 [PAM:StartingMission](DEBUG): Aggregate::initialize PAM:StartingMission
2025-01-14T06:14:10.886Z,1736835250.886 [PAM:StartingMission:A] Running Loop=1
2025-01-14T06:14:11.348Z,1736835251.348 [PAM:StartingMission:A](INFO): Checking for additional instructions before submerging.
2025-01-14T06:14:11.348Z,1736835251.348 [PAM:StartingMission:A] Stopped
2025-01-14T06:14:11.348Z,1736835251.348 [PAM:StartingMission:StartingMission] Running Loop=1
2025-01-14T06:14:11.348Z,1736835251.348 [PAM:StartingMission:StartingMission](DEBUG): Aggregate::initialize PAM:StartingMission:StartingMission
2025-01-14T06:14:11.837Z,1736835251.837 [PAM:NeedComms] Running Loop=1
2025-01-14T06:14:11.837Z,1736835251.837 [PAM:NeedComms](DEBUG): Aggregate::initialize PAM:NeedComms
2025-01-14T06:14:11.837Z,1736835251.837 [PAM:NeedComms:B.GoToSurface] Running Loop=1
2025-01-14T06:14:11.837Z,1736835251.837 [PAM:NeedComms:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-01-14T06:14:11.838Z,1736835251.838 [PAM:NeedComms:B.GoToSurface](INFO): Received depth rate setting nan m/s.
2025-01-14T06:14:11.839Z,1736835251.839 [PAM:NeedComms:B.GoToSurface](INFO): Received pitch setting 19.999999 degrees.
2025-01-14T06:14:11.839Z,1736835251.839 [PAM:NeedComms:B.GoToSurface](INFO): Received speed setting 1.000000 m/s.
2025-01-14T06:14:11.876Z,1736835251.876 [PAM:NeedComms:B.GoToSurface](INFO): Received surface timeout setting 1000.000000 seconds.
2025-01-14T06:14:11.876Z,1736835251.876 [PAM:NeedComms:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-01-14T06:14:11.876Z,1736835251.876 [PAM:NeedComms:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-01-14T06:14:11.877Z,1736835251.877 [PAM:NeedComms:A] Running Loop=1
2025-01-14T06:14:11.878Z,1736835251.878 [PAM:NeedComms:A](INFO): last time_fix was:  1736835021.000000 second since 1970/01/01T00:00:00Z 
2025-01-14T06:14:11.878Z,1736835251.878 [PAM:NeedComms:A] Stopped
2025-01-14T06:14:11.897Z,1736835251.897 [WetLabsUBAT](FAULT): UBAT flow rate is below the specified threshold of 0.05 l/s.
2025-01-14T06:14:12.149Z,1736835252.149 [PAM:NeedComms:C] Running Loop=1
2025-01-14T06:14:12.558Z,1736835252.558 [PAM:NeedComms:C](DEBUG): Initialize ReadDataComponent to sense time_fix
2025-01-14T06:14:14.233Z,1736835254.233 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,061413.00,A,3641.88399,N,12156.59249,W,0.175,300.48,140125,,,D*76
2025-01-14T06:14:14.235Z,1736835254.235 [NAL9602](INFO): GPS fix at 20250114T061413: (36.698067, -121.943208)
2025-01-14T06:14:14.352Z,1736835254.352 [PAM:AbortDrift:B.AbortDrift](INFO): Received valid gps time fix: 1736835200.00. Resetting abort timer.
2025-01-14T06:14:14.353Z,1736835254.353 [PAM:NeedComms:C] Stopped
2025-01-14T06:14:14.353Z,1736835254.353 [PAM:NeedComms:D] Running Loop=1
2025-01-14T06:14:14.802Z,1736835254.802 [PAM:NeedComms:D](DEBUG): Initialize ReadDataComponent to sense platform_communications
2025-01-14T06:14:14.944Z,1736835254.944 [WetLabsUBAT](ERROR): Failed to parse incomplete device message.
2025-01-14T06:14:26.130Z,1736835266.130 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250113T234609/Courier0099.lzma
2025-01-14T06:14:27.162Z,1736835267.162 [DataOverHttps](INFO): Moved sent file to Logs/20250113T234609/Courier0099.lzma.bak
2025-01-14T06:14:27.162Z,1736835267.162 [DataOverHttps](INFO): SBD MOMSN=23903525
2025-01-14T06:14:48.652Z,1736835288.652 [DataOverHttps](INFO): Sending 306 bytes from file Logs/20250114T061343/Courier0000.lzma
2025-01-14T06:14:49.654Z,1736835289.654 [DataOverHttps](INFO): Moved sent file to Logs/20250114T061343/Courier0000.lzma.bak
2025-01-14T06:14:49.654Z,1736835289.654 [DataOverHttps](INFO): SBD MOMSN=23903527
2025-01-14T06:15:04.043Z,1736835304.043 [NAL9602](INFO): SBD MO Status=2, MOMSN=47243, MT Status=2, MTMSN=0
2025-01-14T06:15:04.043Z,1736835304.043 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-01-14T06:15:10.620Z,1736835310.620 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250114T061343/Courier0003.lzma
2025-01-14T06:15:11.623Z,1736835311.623 [DataOverHttps](INFO): Moved sent file to Logs/20250114T061343/Courier0003.lzma.bak
2025-01-14T06:15:11.623Z,1736835311.623 [DataOverHttps](INFO): SBD MOMSN=23903531
2025-01-14T06:15:16.009Z,1736835316.009 [WetLabsUBAT](ERROR): Failed to parse incomplete device message.
2025-01-14T06:15:34.293Z,1736835334.293 [DataOverHttps](INFO): Sending 608 bytes from file Logs/20250113T234609/Express0100.lzma
2025-01-14T06:15:35.294Z,1736835335.294 [DataOverHttps](INFO): Moved sent file to Logs/20250113T234609/Express0100.lzma.bak
2025-01-14T06:15:35.294Z,1736835335.294 [DataOverHttps](INFO): SBD MOMSN=23903533
2025-01-14T06:15:58.813Z,1736835358.813 [DataOverHttps](INFO): Sending 1125 bytes from file Logs/20250114T061343/Express0001.lzma
2025-01-14T06:15:59.810Z,1736835359.810 [DataOverHttps](INFO): Moved sent file to Logs/20250114T061343/Express0001.lzma.bak
2025-01-14T06:15:59.810Z,1736835359.810 [DataOverHttps](INFO): SBD MOMSN=23903555
2025-01-14T06:16:13.992Z,1736835373.992 [WetLabsUBAT](ERROR): Failed to parse incomplete device message.
2025-01-14T06:16:20.100Z,1736835380.100 [WetLabsUBAT](ERROR): Failed to parse incomplete device message.
2025-01-14T06:16:21.315Z,1736835381.315 [NAL9602](INFO): SBD MO Status=2, MOMSN=47243, MT Status=2, MTMSN=0
2025-01-14T06:16:21.315Z,1736835381.315 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-01-14T06:16:21.877Z,1736835381.877 [CTD_Seabird](ERROR): Failed to parse device response: 0.27,11.5315,9519.24
2025-01-14T06:16:30.211Z,1736835390.211 [DataOverHttps](INFO): Sending 89 bytes from file Logs/20250114T061343/Express0004.lzma
2025-01-14T06:16:31.214Z,1736835391.214 [DataOverHttps](INFO): Moved sent file to Logs/20250114T061343/Express0004.lzma.bak
2025-01-14T06:16:31.214Z,1736835391.214 [DataOverHttps](INFO): SBD MOMSN=23903583
2025-01-14T06:16:31.427Z,1736835391.427 [NAL9602](INFO): SBD MO Status=0, MOMSN=47243, MT Status=0, MTMSN=0
2025-01-14T06:16:31.427Z,1736835391.427 [NAL9602](INFO): No messages in MT queue
2025-01-14T06:16:36.747Z,1736835396.747 [PAM:NeedComms:D] Stopped
2025-01-14T06:16:36.747Z,1736835396.747 [PAM:NeedComms:E] Running Loop=1
2025-01-14T06:16:37.120Z,1736835397.120 [PAM:NeedComms:E](DEBUG): Initialize ReadDataComponent to sense time_fix
2025-01-14T06:16:38.724Z,1736835398.724 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,061638.00,A,3641.90134,N,12156.60792,W,0.097,326.32,140125,,,D*7C
2025-01-14T06:16:38.726Z,1736835398.726 [NAL9602](INFO): GPS fix at 20250114T061638: (36.698356, -121.943465)
2025-01-14T06:16:38.754Z,1736835398.754 [PAM:AbortDrift:B.AbortDrift](INFO): Received valid gps time fix: 1736835456.00. Resetting abort timer.
2025-01-14T06:16:38.760Z,1736835398.760 [PAM:NeedComms:E] Stopped
2025-01-14T06:16:38.761Z,1736835398.761 [PAM:NeedComms](INFO): Completed PAM:NeedComms
2025-01-14T06:16:38.761Z,1736835398.761 [PAM:NeedComms] Stopped
2025-01-14T06:16:38.761Z,1736835398.761 [PAM:NeedComms](DEBUG): Aggregate::uninitialize PAM:NeedComms
2025-01-14T06:16:38.761Z,1736835398.761 [PAM:NeedComms:B.GoToSurface] Stopped
2025-01-14T06:16:38.761Z,1736835398.761 [PAM:NeedComms:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2025-01-14T06:16:39.168Z,1736835399.168 [PAM:StartingMission:StartingMission](INFO): Completed PAM:StartingMission:StartingMission
2025-01-14T06:16:39.168Z,1736835399.168 [PAM:StartingMission:StartingMission] Stopped
2025-01-14T06:16:39.168Z,1736835399.168 [PAM:StartingMission:StartingMission](DEBUG): Aggregate::uninitialize PAM:StartingMission:StartingMission
2025-01-14T06:16:39.168Z,1736835399.168 [PAM:StartingMission](INFO): Completed PAM:StartingMission
2025-01-14T06:16:39.168Z,1736835399.168 [PAM:StartingMission] Stopped
2025-01-14T06:16:39.168Z,1736835399.168 [PAM:StartingMission](DEBUG): Aggregate::uninitialize PAM:StartingMission
2025-01-14T06:16:39.169Z,1736835399.169 [PAM:InitialTransitToListeningLocation] Running Loop=1
2025-01-14T06:16:39.169Z,1736835399.169 [PAM:InitialTransitToListeningLocation](DEBUG): Aggregate::initialize PAM:InitialTransitToListeningLocation
2025-01-14T06:16:39.169Z,1736835399.169 [PAM:InitialTransitToListeningLocation:InitialYoYo] Running Loop=1
2025-01-14T06:16:39.169Z,1736835399.169 [PAM:InitialTransitToListeningLocation:InitialYoYo](DEBUG): Aggregate::initialize PAM:InitialTransitToListeningLocation:InitialYoYo
2025-01-14T06:16:39.169Z,1736835399.169 [PAM:InitialTransitToListeningLocation:InitialYoYo:D.SetSpeed] Running Loop=1
2025-01-14T06:16:39.169Z,1736835399.169 [PAM:InitialTransitToListeningLocation:InitialYoYo:D.SetSpeed](DEBUG): Initialize.
2025-01-14T06:16:39.169Z,1736835399.169 [PAM:InitialTransitToListeningLocation:InitialYoYo:E.DepthEnvelope] Running Loop=1
2025-01-14T06:16:39.169Z,1736835399.169 [PAM:InitialTransitToListeningLocation:InitialYoYo:E.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent.
2025-01-14T06:16:39.170Z,1736835399.170 [PAM:InitialTransitToListeningLocation:InitialYoYo:F.YoYo] Running Loop=1
2025-01-14T06:16:39.170Z,1736835399.170 [PAM:InitialTransitToListeningLocation:InitialYoYo:F.YoYo](DEBUG): Initialize YoYoComponent.
2025-01-14T06:16:39.170Z,1736835399.170 [PAM:InitialTransitToListeningLocation:InitialYoYo:G.Pitch] Running Loop=1
2025-01-14T06:16:39.170Z,1736835399.170 [PAM:InitialTransitToListeningLocation:InitialYoYo:G.Pitch](DEBUG): Initialize.
2025-01-14T06:16:39.170Z,1736835399.170 [PAM:InitialTransitToListeningLocation:InitialYoYo:H.Buoyancy] Running Loop=1
2025-01-14T06:16:39.170Z,1736835399.170 [PAM:InitialTransitToListeningLocation:InitialYoYo:H.Buoyancy](DEBUG): Initialize Buoyancy Component.
2025-01-14T06:16:39.170Z,1736835399.170 [PAM:InitialTransitToListeningLocation:InitialYoYo:A] Running Loop=1
2025-01-14T06:16:39.614Z,1736835399.614 [PAM:InitialTransitToListeningLocation:InitialYoYo] Stopped
2025-01-14T06:16:39.615Z,1736835399.615 [PAM:InitialTransitToListeningLocation:InitialYoYo](DEBUG): Aggregate::uninitialize PAM:InitialTransitToListeningLocation:InitialYoYo
2025-01-14T06:16:39.615Z,1736835399.615 [PAM:InitialTransitToListeningLocation:InitialYoYo:A] Stopped
2025-01-14T06:16:39.615Z,1736835399.615 [PAM:InitialTransitToListeningLocation:InitialYoYo:D.SetSpeed] Stopped
2025-01-14T06:16:39.615Z,1736835399.615 [PAM:InitialTransitToListeningLocation:InitialYoYo:D.SetSpeed](DEBUG): Uninitialize.
2025-01-14T06:16:39.615Z,1736835399.615 [PAM:InitialTransitToListeningLocation:InitialYoYo:E.DepthEnvelope] Stopped
2025-01-14T06:16:39.615Z,1736835399.615 [PAM:InitialTransitToListeningLocation:InitialYoYo:E.DepthEnvelope](DEBUG): Uninitialize.
2025-01-14T06:16:39.615Z,1736835399.615 [PAM:InitialTransitToListeningLocation:InitialYoYo:F.YoYo] Stopped
2025-01-14T06:16:39.615Z,1736835399.615 [PAM:InitialTransitToListeningLocation:InitialYoYo:F.YoYo](DEBUG): Uninitialize YoYoComponent.
2025-01-14T06:16:39.615Z,1736835399.615 [PAM:InitialTransitToListeningLocation:InitialYoYo:G.Pitch] Stopped
2025-01-14T06:16:39.615Z,1736835399.615 [PAM:InitialTransitToListeningLocation:InitialYoYo:H.Buoyancy] Stopped
2025-01-14T06:16:39.615Z,1736835399.615 [PAM:InitialTransitToListeningLocation:InitialYoYo:H.Buoyancy](DEBUG): Uninitialize Buoyancy Component.
2025-01-14T06:16:39.615Z,1736835399.615 [PAM:InitialTransitToListeningLocation:InitialLevelRun] Running Loop=1
2025-01-14T06:16:39.644Z,1736835399.644 [PAM:InitialTransitToListeningLocation:InitialLevelRun](DEBUG): Aggregate::initialize PAM:InitialTransitToListeningLocation:InitialLevelRun
2025-01-14T06:16:39.644Z,1736835399.644 [PAM:InitialTransitToListeningLocation:InitialLevelRun:D.SetSpeed] Running Loop=1
2025-01-14T06:16:39.644Z,1736835399.644 [PAM:InitialTransitToListeningLocation:InitialLevelRun:D.SetSpeed](DEBUG): Initialize.
2025-01-14T06:16:39.644Z,1736835399.644 [PAM:InitialTransitToListeningLocation:InitialLevelRun:E.Mass] Running Loop=1
2025-01-14T06:16:39.644Z,1736835399.644 [PAM:InitialTransitToListeningLocation:InitialLevelRun:E.Mass](DEBUG): Initialize.
2025-01-14T06:16:39.644Z,1736835399.644 [PAM:InitialTransitToListeningLocation:InitialLevelRun:F.Buoyancy] Running Loop=1
2025-01-14T06:16:39.644Z,1736835399.644 [PAM:InitialTransitToListeningLocation:InitialLevelRun:F.Buoyancy](DEBUG): Initialize Buoyancy Component.
2025-01-14T06:16:39.645Z,1736835399.645 [PAM:InitialTransitToListeningLocation:InitialLevelRun:G.Pitch] Running Loop=1
2025-01-14T06:16:39.645Z,1736835399.645 [PAM:InitialTransitToListeningLocation:InitialLevelRun:G.Pitch](DEBUG): Initialize.
2025-01-14T06:16:39.645Z,1736835399.645 [PAM:InitialTransitToListeningLocation:InitialLevelRun:A] Running Loop=1
2025-01-14T06:16:40.009Z,1736835400.009 [PAM:InitialTransitToListeningLocation:InitialLevelRun:G.Pitch] Running Loop=1
2025-01-14T06:16:40.009Z,1736835400.009 [PAM:InitialTransitToListeningLocation:InitialLevelRun:F.Buoyancy] Running Loop=1
2025-01-14T06:16:40.010Z,1736835400.010 [PAM:InitialTransitToListeningLocation:InitialLevelRun:E.Mass] Running Loop=1
2025-01-14T06:16:40.011Z,1736835400.011 [PAM:InitialTransitToListeningLocation:InitialLevelRun:D.SetSpeed] Running Loop=1
2025-01-14T06:16:40.040Z,1736835400.040 [PAM:InitialTransitToListeningLocation:InitialLevelRun:A] Stopped
2025-01-14T06:16:40.041Z,1736835400.041 [PAM:InitialTransitToListeningLocation:InitialLevelRun:B] Running Loop=1
2025-01-14T06:16:40.366Z,1736835400.366 [PAM:InitialTransitToListeningLocation:InitialLevelRun:B](IMPORTANT): Initial level run transit to listening location LatListening =  36.698002 arcdeg , LonListening =  -121.945000 arcdeg .
2025-01-14T06:16:40.366Z,1736835400.366 [PAM:InitialTransitToListeningLocation:InitialLevelRun:B] Stopped
2025-01-14T06:16:40.366Z,1736835400.366 [PAM:InitialTransitToListeningLocation:InitialLevelRun:C] Running Loop=1
2025-01-14T06:16:40.784Z,1736835400.784 [PAM:InitialTransitToListeningLocation:InitialLevelRun:C] Stopped
2025-01-14T06:16:40.784Z,1736835400.784 [PAM:InitialTransitToListeningLocation:InitialLevelRun:H.Waypoint] Running Loop=1
2025-01-14T06:16:40.784Z,1736835400.784 [PAM:InitialTransitToListeningLocation:InitialLevelRun:H.Waypoint](DEBUG): Initialize WaypointComponent.
2025-01-14T06:16:40.785Z,1736835400.785 [PAM:InitialTransitToListeningLocation:InitialLevelRun:H.Waypoint](IMPORTANT): Navigating to waypoint: 36.698002,-121.945000
2025-01-14T06:16:41.161Z,1736835401.161 [PAM:InitialTransitToListeningLocation:InitialLevelRun:H.Waypoint](INFO): Navigating to waypoint: 36.698002,-121.945000
2025-01-14T06:17:01.336Z,1736835421.336 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-01-14T06:17:11.462Z,1736835431.462 [NAL9602](INFO): Not Powering down - fast GPS
2025-01-14T06:17:11.958Z,1736835431.958 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-01-14T06:17:22.637Z,1736835442.637 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-01-14T06:17:33.180Z,1736835453.180 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-01-14T06:18:04.697Z,1736835484.697 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-01-14T06:18:22.144Z,1736835502.144 [WetLabsUBAT](ERROR): Failed to parse incomplete device message.
2025-01-14T06:18:32.810Z,1736835512.810 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.632652
2025-01-14T06:18:33.812Z,1736835513.812 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-01-14T06:18:43.716Z,1736835523.716 [Radio_Surface](INFO): Powering down
2025-01-14T06:19:03.972Z,1736835543.972 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-14T06:19:04.976Z,1736835544.976 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2025-01-14T06:19:04.976Z,1736835544.976 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-01-14T06:19:35.096Z,1736835575.096 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-14T06:19:36.100Z,1736835576.100 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-01-14T06:19:40.169Z,1736835580.169 [PAM:InitialTransitToListeningLocation:InitialLevelRun:H.Waypoint](IMPORTANT): Reached waypoint: 36.698002,-121.945000
2025-01-14T06:19:40.169Z,1736835580.169 [PAM:InitialTransitToListeningLocation:InitialLevelRun:H.Waypoint] Stopped
2025-01-14T06:19:40.169Z,1736835580.169 [PAM:InitialTransitToListeningLocation:InitialLevelRun:H.Waypoint](DEBUG): Uninitialize WaypointComponent.
2025-01-14T06:19:40.169Z,1736835580.169 [PAM:InitialTransitToListeningLocation:InitialLevelRun:InitialLevelRunReachedWaypoint] Running Loop=1
2025-01-14T06:19:40.169Z,1736835580.169 [PAM:InitialTransitToListeningLocation:InitialLevelRun:InitialLevelRunReachedWaypoint](DEBUG): Aggregate::initialize PAM:InitialTransitToListeningLocation:InitialLevelRun:InitialLevelRunReachedWaypoint
2025-01-14T06:19:40.584Z,1736835580.584 [PAM:NeedComms] Running Loop=1
2025-01-14T06:19:40.585Z,1736835580.585 [PAM:NeedComms](DEBUG): Aggregate::initialize PAM:NeedComms
2025-01-14T06:19:40.585Z,1736835580.585 [PAM:NeedComms:B.GoToSurface] Running Loop=1
2025-01-14T06:19:40.585Z,1736835580.585 [PAM:NeedComms:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-01-14T06:19:40.585Z,1736835580.585 [PAM:NeedComms:B.GoToSurface](INFO): Received depth rate setting nan m/s.
2025-01-14T06:19:40.586Z,1736835580.586 [PAM:NeedComms:B.GoToSurface](INFO): Received pitch setting 19.999999 degrees.
2025-01-14T06:19:40.586Z,1736835580.586 [PAM:NeedComms:B.GoToSurface](INFO): Received speed setting 1.000000 m/s.
2025-01-14T06:19:40.586Z,1736835580.586 [PAM:NeedComms:B.GoToSurface](INFO): Received surface timeout setting 1000.000000 seconds.
2025-01-14T06:19:40.587Z,1736835580.587 [PAM:NeedComms:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-01-14T06:19:40.587Z,1736835580.587 [PAM:NeedComms:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-01-14T06:19:40.587Z,1736835580.587 [PAM:NeedComms:A] Running Loop=1
2025-01-14T06:19:40.606Z,1736835580.606 [PAM:NeedComms:A](INFO): last time_fix was:  1736835398.000000 second since 1970/01/01T00:00:00Z 
2025-01-14T06:19:40.606Z,1736835580.606 [PAM:NeedComms:A] Stopped
2025-01-14T06:20:06.226Z,1736835606.226 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-14T06:20:07.228Z,1736835607.228 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-01-14T06:20:37.348Z,1736835637.348 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-14T06:20:38.352Z,1736835638.352 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-01-14T06:20:42.593Z,1736835642.593 [PAM:NeedComms:C] Running Loop=1
2025-01-14T06:20:42.000Z,1736835643.000 [Radio_Surface](INFO): Powering up
2025-01-14T06:20:44.536Z,1736835644.536 [WetLabsUBAT](ERROR): Failed to parse incomplete device message.
2025-01-14T06:20:48.252Z,1736835648.252 [Radio_Surface](INFO): Checking local IP, expecting subnet 10.89.10
2025-01-14T06:20:48.253Z,1736835648.253 [Radio_Surface](INFO): Found local IP address 10.89.10.2 for eth0
2025-01-14T06:21:08.477Z,1736835668.477 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-14T06:21:09.480Z,1736835669.480 [DataOverHttps](INFO): Radio surface powered ON.
2025-01-14T06:21:09.480Z,1736835669.480 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-01-14T06:21:16.483Z,1736835676.483 [NAL9602](INFO): SBD MO Status=2, MOMSN=47244, MT Status=2, MTMSN=0
2025-01-14T06:21:16.483Z,1736835676.483 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-01-14T06:21:33.475Z,1736835693.475 [NAL9602](INFO): SBD MO Status=2, MOMSN=47244, MT Status=2, MTMSN=0
2025-01-14T06:21:33.475Z,1736835693.475 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-01-14T06:21:39.601Z,1736835699.601 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-14T06:21:40.604Z,1736835700.604 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-01-14T06:21:43.147Z,1736835703.147 [NAL9602](INFO): SBD MO Status=0, MOMSN=47244, MT Status=0, MTMSN=0
2025-01-14T06:21:43.147Z,1736835703.147 [NAL9602](INFO): No messages in MT queue
2025-01-14T06:21:44.365Z,1736835704.365 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,062143.00,A,3641.85502,N,12156.72876,W,0.486,261.19,140125,,,D*78
2025-01-14T06:21:44.367Z,1736835704.367 [NAL9602](INFO): GPS fix at 20250114T062143: (36.697584, -121.945479)
2025-01-14T06:21:44.384Z,1736835704.384 [PAM:AbortDrift:B.AbortDrift](INFO): Received valid gps time fix: 1736835712.00. Resetting abort timer.
2025-01-14T06:21:44.385Z,1736835704.385 [PAM:NeedComms:C] Stopped
2025-01-14T06:21:44.386Z,1736835704.386 [PAM:NeedComms:D] Running Loop=1
2025-01-14T06:21:59.773Z,1736835719.773 [NAL9602](INFO): SBD MO Status=1, MOMSN=47245, MT Status=0, MTMSN=0
2025-01-14T06:21:59.828Z,1736835719.828 [NAL9602](INFO): Sent 73 bytes from file Logs/20250114T061343/Courier0006.lzma
2025-01-14T06:21:59.828Z,1736835719.828 [NAL9602](INFO): Packets left to send: 0
2025-01-14T06:22:10.724Z,1736835730.724 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-14T06:22:11.728Z,1736835731.728 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-01-14T06:22:19.492Z,1736835739.492 [NAL9602](INFO): SBD MO Status=1, MOMSN=47246, MT Status=0, MTMSN=0
2025-01-14T06:22:19.551Z,1736835739.551 [NAL9602](INFO): Sent 332 bytes from file Logs/20250114T061343/Express0007.lzma
2025-01-14T06:22:19.555Z,1736835739.555 [NAL9602](INFO): Packets left to send: 1
2025-01-14T06:22:37.111Z,1736835757.111 [NAL9602](INFO): SBD MO Status=1, MOMSN=47247, MT Status=0, MTMSN=0
2025-01-14T06:22:37.160Z,1736835757.160 [NAL9602](INFO): Sent 131 bytes from file Logs/20250114T061343/Express0007.lzma
2025-01-14T06:22:37.160Z,1736835757.160 [NAL9602](INFO): Packets left to send: 0
2025-01-14T06:22:41.852Z,1736835761.852 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-14T06:22:42.857Z,1736835762.857 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-01-14T06:22:45.820Z,1736835765.820 [NAL9602](INFO): SBD MO Status=0, MOMSN=47248, MT Status=0, MTMSN=0
2025-01-14T06:22:45.942Z,1736835765.942 [PAM:NeedComms:D] Stopped
2025-01-14T06:22:45.942Z,1736835765.942 [PAM:NeedComms:E] Running Loop=1
2025-01-14T06:22:48.241Z,1736835768.241 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,062247.00,A,3641.86023,N,12156.73346,W,0.680,311.04,140125,,,D*7D
2025-01-14T06:22:48.243Z,1736835768.243 [NAL9602](INFO): GPS fix at 20250114T062247: (36.697671, -121.945558)
2025-01-14T06:22:48.279Z,1736835768.279 [PAM:AbortDrift:B.AbortDrift](INFO): Received valid gps time fix: 1736835712.00. Resetting abort timer.
2025-01-14T06:22:48.281Z,1736835768.281 [PAM:NeedComms:E] Stopped
2025-01-14T06:22:48.282Z,1736835768.282 [PAM:NeedComms](INFO): Completed PAM:NeedComms
2025-01-14T06:22:48.282Z,1736835768.282 [PAM:NeedComms] Stopped
2025-01-14T06:22:48.282Z,1736835768.282 [PAM:NeedComms](DEBUG): Aggregate::uninitialize PAM:NeedComms
2025-01-14T06:22:48.282Z,1736835768.282 [PAM:NeedComms:B.GoToSurface] Stopped
2025-01-14T06:22:48.282Z,1736835768.282 [PAM:NeedComms:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2025-01-14T06:22:48.678Z,1736835768.678 [PAM:InitialTransitToListeningLocation:InitialLevelRun:InitialLevelRunReachedWaypoint](INFO): Completed PAM:InitialTransitToListeningLocation:InitialLevelRun:InitialLevelRunReachedWaypoint
2025-01-14T06:22:48.678Z,1736835768.678 [PAM:InitialTransitToListeningLocation:InitialLevelRun:InitialLevelRunReachedWaypoint] Stopped
2025-01-14T06:22:48.678Z,1736835768.678 [PAM:InitialTransitToListeningLocation:InitialLevelRun:InitialLevelRunReachedWaypoint](DEBUG): Aggregate::uninitialize PAM:InitialTransitToListeningLocation:InitialLevelRun:InitialLevelRunReachedWaypoint
2025-01-14T06:22:48.679Z,1736835768.679 [PAM:InitialTransitToListeningLocation:InitialLevelRun:J] Running Loop=1
2025-01-14T06:22:49.079Z,1736835769.079 [PAM:InitialTransitToListeningLocation:InitialLevelRun:J] Stopped
2025-01-14T06:22:49.079Z,1736835769.079 [PAM:InitialTransitToListeningLocation:InitialLevelRun:K] Running Loop=1
2025-01-14T06:22:49.495Z,1736835769.495 [PAM:InitialTransitToListeningLocation:InitialLevelRun:K] Stopped
2025-01-14T06:22:49.496Z,1736835769.496 [PAM:InitialTransitToListeningLocation:InitialLevelRun](INFO): Completed PAM:InitialTransitToListeningLocation:InitialLevelRun
2025-01-14T06:22:49.496Z,1736835769.496 [PAM:InitialTransitToListeningLocation:InitialLevelRun] Stopped
2025-01-14T06:22:49.496Z,1736835769.496 [PAM:InitialTransitToListeningLocation:InitialLevelRun](DEBUG): Aggregate::uninitialize PAM:InitialTransitToListeningLocation:InitialLevelRun
2025-01-14T06:22:49.496Z,1736835769.496 [PAM:InitialTransitToListeningLocation:InitialLevelRun:D.SetSpeed] Stopped
2025-01-14T06:22:49.496Z,1736835769.496 [PAM:InitialTransitToListeningLocation:InitialLevelRun:D.SetSpeed](DEBUG): Uninitialize.
2025-01-14T06:22:49.497Z,1736835769.497 [PAM:InitialTransitToListeningLocation:InitialLevelRun:E.Mass] Stopped
2025-01-14T06:22:49.497Z,1736835769.497 [PAM:InitialTransitToListeningLocation:InitialLevelRun:E.Mass](DEBUG): Uninitialize.
2025-01-14T06:22:49.497Z,1736835769.497 [PAM:InitialTransitToListeningLocation:InitialLevelRun:F.Buoyancy] Stopped
2025-01-14T06:22:49.497Z,1736835769.497 [PAM:InitialTransitToListeningLocation:InitialLevelRun:F.Buoyancy](DEBUG): Uninitialize Buoyancy Component.
2025-01-14T06:22:49.497Z,1736835769.497 [PAM:InitialTransitToListeningLocation:InitialLevelRun:G.Pitch] Stopped
2025-01-14T06:22:49.497Z,1736835769.497 [PAM:InitialTransitToListeningLocation](INFO): Completed PAM:InitialTransitToListeningLocation
2025-01-14T06:22:49.497Z,1736835769.497 [PAM:InitialTransitToListeningLocation] Stopped
2025-01-14T06:22:49.497Z,1736835769.497 [PAM:InitialTransitToListeningLocation](DEBUG): Aggregate::uninitialize PAM:InitialTransitToListeningLocation
2025-01-14T06:22:49.497Z,1736835769.497 [PAM:PAM] Running Loop=1
2025-01-14T06:22:49.497Z,1736835769.497 [PAM:PAM](DEBUG): Aggregate::initialize PAM:PAM
2025-01-14T06:22:49.498Z,1736835769.498 [PAM:PAM:SettingVariables] Running Loop=1
2025-01-14T06:22:49.498Z,1736835769.498 [PAM:PAM:SettingVariables](DEBUG): Aggregate::initialize PAM:PAM:SettingVariables
2025-01-14T06:22:49.498Z,1736835769.498 [PAM:PAM:SettingVariables:A.Mass] Running Loop=1
2025-01-14T06:22:49.498Z,1736835769.498 [PAM:PAM:SettingVariables:A.Mass](DEBUG): Initialize.
2025-01-14T06:22:49.498Z,1736835769.498 [PAM:PAM:SettingVariables:B.Buoyancy] Running Loop=1
2025-01-14T06:22:49.498Z,1736835769.498 [PAM:PAM:SettingVariables:B.Buoyancy](DEBUG): Initialize Buoyancy Component.
2025-01-14T06:22:49.498Z,1736835769.498 [PAM:PAM:SettingVariables:C] Running Loop=1
2025-01-14T06:22:49.926Z,1736835769.926 [PAM:PAM:SettingVariables:C] Stopped
2025-01-14T06:22:49.926Z,1736835769.926 [PAM:PAM:SettingVariables:D] Running Loop=1
2025-01-14T06:22:49.926Z,1736835769.926 [PAM:PAM:SettingVariables:B.Buoyancy] Running Loop=1
2025-01-14T06:22:49.927Z,1736835769.927 [PAM:PAM:SettingVariables:A.Mass] Running Loop=1
2025-01-14T06:22:50.311Z,1736835770.311 [PAM:PAM:SettingVariables:D] Stopped
2025-01-14T06:22:50.311Z,1736835770.311 [PAM:PAM:SettingVariables:E] Running Loop=1
2025-01-14T06:22:50.734Z,1736835770.734 [PAM:PAM:SettingVariables:E] Stopped
2025-01-14T06:22:50.734Z,1736835770.734 [PAM:PAM:SettingVariables:F] Running Loop=1
2025-01-14T06:22:51.132Z,1736835771.132 [PAM:PAM:SettingVariables:F](IMPORTANT): Cnt =  1.000000 count 
2025-01-14T06:22:51.133Z,1736835771.133 [PAM:PAM:SettingVariables:F] Stopped
2025-01-14T06:22:51.133Z,1736835771.133 [PAM:PAM:SettingVariables:G] Running Loop=1
2025-01-14T06:22:51.616Z,1736835771.616 [PAM:PAM:SettingVariables:G](IMPORTANT): NeutralBuoyancy =  401.869354 cc , BuoyancyAdjustmentStep =  16.000000 cc , MassPosition =  21.805965 mm , MassPositionAdjustmentStep =  0.528000 mm 
2025-01-14T06:22:51.617Z,1736835771.617 [PAM:PAM:SettingVariables:G] Stopped
2025-01-14T06:22:51.617Z,1736835771.617 [PAM:PAM:SettingVariables:H] Running Loop=1
2025-01-14T06:22:51.977Z,1736835771.977 [PAM:PAM:SettingVariables:H] Stopped
2025-01-14T06:22:51.977Z,1736835771.977 [PAM:PAM:SettingVariables:I] Running Loop=1
2025-01-14T06:22:52.337Z,1736835772.337 [PAM:PAM:SettingVariables:I] Stopped
2025-01-14T06:22:52.337Z,1736835772.337 [PAM:PAM:SettingVariables](INFO): Completed PAM:PAM:SettingVariables
2025-01-14T06:22:52.338Z,1736835772.338 [PAM:PAM:SettingVariables] Stopped
2025-01-14T06:22:52.338Z,1736835772.338 [PAM:PAM:SettingVariables](DEBUG): Aggregate::uninitialize PAM:PAM:SettingVariables
2025-01-14T06:22:52.338Z,1736835772.338 [PAM:PAM:SettingVariables:A.Mass] Stopped
2025-01-14T06:22:52.338Z,1736835772.338 [PAM:PAM:SettingVariables:A.Mass](DEBUG): Uninitialize.
2025-01-14T06:22:52.338Z,1736835772.338 [PAM:PAM:SettingVariables:B.Buoyancy] Stopped
2025-01-14T06:22:52.338Z,1736835772.338 [PAM:PAM:SettingVariables:B.Buoyancy](DEBUG): Uninitialize Buoyancy Component.
2025-01-14T06:22:52.338Z,1736835772.338 [PAM:PAM:Waits] Running Loop=1
2025-01-14T06:22:52.338Z,1736835772.338 [PAM:PAM:Waits](DEBUG): Aggregate::initialize PAM:PAM:Waits
2025-01-14T06:22:52.338Z,1736835772.338 [PAM:PAM:Waits:A.Mass] Running Loop=1
2025-01-14T06:22:52.338Z,1736835772.338 [PAM:PAM:Waits:A.Mass](DEBUG): Initialize.
2025-01-14T06:22:52.338Z,1736835772.338 [PAM:PAM:Waits:B.Buoyancy] Running Loop=1
2025-01-14T06:22:52.339Z,1736835772.339 [PAM:PAM:Waits:B.Buoyancy](DEBUG): Initialize Buoyancy Component.
2025-01-14T06:22:52.339Z,1736835772.339 [PAM:PAM:Waits:WaitForSurfaceCommsCompletion] Running Loop=1
2025-01-14T06:22:52.339Z,1736835772.339 [PAM:PAM:Waits:WaitForSurfaceCommsCompletion](DEBUG): Aggregate::initialize PAM:PAM:Waits:WaitForSurfaceCommsCompletion
2025-01-14T06:22:52.339Z,1736835772.339 [PAM:PAM:Waits:WaitForSurfaceCommsCompletion:A.Wait] Running Loop=1
2025-01-14T06:22:52.340Z,1736835772.340 [PAM:PAM:Waits:WaitForSurfaceCommsCompletion:A.Wait](DEBUG): Initialize Wait Component.
2025-01-14T06:22:52.770Z,1736835772.770 [PAM:PAM:Waits:WaitForSurfaceCommsCompletion] Stopped
2025-01-14T06:22:52.770Z,1736835772.770 [PAM:PAM:Waits:WaitForSurfaceCommsCompletion](DEBUG): Aggregate::uninitialize PAM:PAM:Waits:WaitForSurfaceCommsCompletion
2025-01-14T06:22:52.770Z,1736835772.770 [PAM:PAM:Waits:WaitForSurfaceCommsCompletion:A.Wait] Stopped
2025-01-14T06:22:52.770Z,1736835772.770 [PAM:PAM:Waits:WaitForSurfaceCommsCompletion:A.Wait](DEBUG): Uninitialize Wait Component.
2025-01-14T06:22:52.770Z,1736835772.770 [PAM:PAM:Waits:WaitBuoyancyChange] Running Loop=1
2025-01-14T06:22:52.770Z,1736835772.770 [PAM:PAM:Waits:WaitBuoyancyChange](DEBUG): Aggregate::initialize PAM:PAM:Waits:WaitBuoyancyChange
2025-01-14T06:22:52.770Z,1736835772.770 [PAM:PAM:Waits:WaitBuoyancyChange:A] Running Loop=1
2025-01-14T06:22:52.770Z,1736835772.770 [PAM:PAM:Waits:B.Buoyancy] Running Loop=1
2025-01-14T06:22:52.771Z,1736835772.771 [PAM:PAM:Waits:A.Mass] Running Loop=1
2025-01-14T06:22:53.136Z,1736835773.136 [PAM:PAM:Waits:WaitBuoyancyChange] Stopped
2025-01-14T06:22:53.136Z,1736835773.136 [PAM:PAM:Waits:WaitBuoyancyChange](DEBUG): Aggregate::uninitialize PAM:PAM:Waits:WaitBuoyancyChange
2025-01-14T06:22:53.136Z,1736835773.136 [PAM:PAM:Waits:WaitBuoyancyChange:A] Stopped
2025-01-14T06:22:53.137Z,1736835773.137 [PAM:PAM:Waits](INFO): Completed PAM:PAM:Waits
2025-01-14T06:22:53.137Z,1736835773.137 [PAM:PAM:Waits] Stopped
2025-01-14T06:22:53.137Z,1736835773.137 [PAM:PAM:Waits](DEBUG): Aggregate::uninitialize PAM:PAM:Waits
2025-01-14T06:22:53.137Z,1736835773.137 [PAM:PAM:Waits:A.Mass] Stopped
2025-01-14T06:22:53.137Z,1736835773.137 [PAM:PAM:Waits:A.Mass](DEBUG): Uninitialize.
2025-01-14T06:22:53.137Z,1736835773.137 [PAM:PAM:Waits:B.Buoyancy] Stopped
2025-01-14T06:22:53.137Z,1736835773.137 [PAM:PAM:Waits:B.Buoyancy](DEBUG): Uninitialize Buoyancy Component.
2025-01-14T06:22:53.137Z,1736835773.137 [PAM:PAM:C] Running Loop=1
2025-01-14T06:22:53.708Z,1736835773.708 [PAM:PAM:C] Stopped
2025-01-14T06:22:53.708Z,1736835773.708 [PAM:PAM:ApproachDepthSettleAtDepth] Running Loop=1
2025-01-14T06:22:53.708Z,1736835773.708 [PAM:PAM:ApproachDepthSettleAtDepth](DEBUG): Aggregate::initialize PAM:PAM:ApproachDepthSettleAtDepth
2025-01-14T06:22:53.709Z,1736835773.709 [PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth] Running Loop=1
2025-01-14T06:22:53.709Z,1736835773.709 [PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth](DEBUG): Aggregate::initialize PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth
2025-01-14T06:22:53.709Z,1736835773.709 [PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth:ApproachDepthPropellerOn] Running Loop=1
2025-01-14T06:22:53.709Z,1736835773.709 [PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth:ApproachDepthPropellerOn](DEBUG): Aggregate::initialize PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth:ApproachDepthPropellerOn
2025-01-14T06:22:53.709Z,1736835773.709 [PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth:ApproachDepthPropellerOn:A.Mass] Running Loop=1
2025-01-14T06:22:53.709Z,1736835773.709 [PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth:ApproachDepthPropellerOn:A.Mass](DEBUG): Initialize.
2025-01-14T06:22:53.710Z,1736835773.710 [PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth:ApproachDepthPropellerOn:B.Buoyancy] Running Loop=1
2025-01-14T06:22:53.710Z,1736835773.710 [PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth:ApproachDepthPropellerOn:B.Buoyancy](DEBUG): Initialize Buoyancy Component.
2025-01-14T06:22:53.710Z,1736835773.710 [PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth:ApproachDepthPropellerOn:E.Point] Running Loop=1
2025-01-14T06:22:53.710Z,1736835773.710 [PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth:ApproachDepthPropellerOn:E.Point](DEBUG): Initialize.
2025-01-14T06:22:53.710Z,1736835773.710 [PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth:ApproachDepthPropellerOn:F.SetSpeed] Running Loop=1
2025-01-14T06:22:53.710Z,1736835773.710 [PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth:ApproachDepthPropellerOn:F.SetSpeed](DEBUG): Initialize.
2025-01-14T06:22:53.711Z,1736835773.711 [PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth:ApproachDepthPropellerOn:C] Running Loop=1
2025-01-14T06:22:53.943Z,1736835773.943 [PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth:ApproachDepthPropellerOn:F.SetSpeed] Running Loop=1
2025-01-14T06:22:53.943Z,1736835773.943 [PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth:ApproachDepthPropellerOn:E.Point] Running Loop=1
2025-01-14T06:22:53.944Z,1736835773.944 [PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth:ApproachDepthPropellerOn:C] Stopped
2025-01-14T06:22:53.944Z,1736835773.944 [PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth:ApproachDepthPropellerOn:D] Running Loop=1
2025-01-14T06:22:53.944Z,1736835773.944 [PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth:ApproachDepthPropellerOn:B.Buoyancy] Running Loop=1
2025-01-14T06:22:53.944Z,1736835773.944 [PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth:ApproachDepthPropellerOn:A.Mass] Running Loop=1
2025-01-14T06:22:54.350Z,1736835774.350 [PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth:ApproachDepthPropellerOn:D](IMPORTANT): Depth  0.069560 m  outside of the envelope defined by ShallowBoundRegainDepth =  20.000000 m  and DeepBoundRegainDepth =  60.000000 m . Moving to  40.000000 m . Propeller on.
2025-01-14T06:22:54.350Z,1736835774.350 [PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth:ApproachDepthPropellerOn:D] Stopped
2025-01-14T06:22:54.350Z,1736835774.350 [PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth:ApproachDepthPropellerOn:G.Pitch] Running Loop=1
2025-01-14T06:22:54.350Z,1736835774.350 [PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth:ApproachDepthPropellerOn:G.Pitch](DEBUG): Initialize.
2025-01-14T06:23:12.993Z,1736835792.993 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-14T06:23:13.996Z,1736835793.996 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-01-14T06:23:19.917Z,1736835799.917 [NAL9602](INFO): Not Powering down - fast GPS
2025-01-14T06:23:44.117Z,1736835824.117 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-14T06:23:45.120Z,1736835825.120 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-01-14T06:24:15.245Z,1736835855.245 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-14T06:24:16.248Z,1736835856.248 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-01-14T06:24:46.372Z,1736835886.372 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-14T06:24:47.377Z,1736835887.377 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-01-14T06:24:59.656Z,1736835899.656 [Radio_Surface](INFO): Powering down
2025-01-14T06:25:17.496Z,1736835917.496 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-14T06:25:18.500Z,1736835918.500 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2025-01-14T06:25:18.500Z,1736835918.500 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-01-14T06:25:48.624Z,1736835948.624 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-14T06:25:49.628Z,1736835949.628 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-01-14T06:26:19.748Z,1736835979.748 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-14T06:26:20.752Z,1736835980.752 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-01-14T06:26:34.360Z,1736835994.360 [WetLabsUBAT](ERROR): Failed to parse incomplete device message.
2025-01-14T06:26:50.872Z,1736836010.872 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-14T06:26:51.876Z,1736836011.876 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-01-14T06:27:21.998Z,1736836041.998 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-14T06:27:23.004Z,1736836043.004 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-01-14T06:27:53.127Z,1736836073.127 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-14T06:27:54.128Z,1736836074.128 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-01-14T06:28:11.615Z,1736836091.615 [RDI_Pathfinder](ERROR): only read 3 of 4 data items for beam range. Device response is::RA,  0.00, 590.29, 659.74, 570.04, 

2025-01-14T06:28:24.252Z,1736836104.252 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-14T06:28:25.256Z,1736836105.256 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-01-14T06:28:31.831Z,1736836111.831 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error. Device response is::TS,253, +12.0,   0.0,1497.0,  0
2025-01-14T06:28:41.591Z,1736836121.591 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error. Device response is::TS2294484,35.0, +11.9,4
2025-01-14T06:28:46.379Z,1736836126.379 [PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth:ApproachDepthPropellerOn:G.Pitch] Stopped
2025-01-14T06:28:46.381Z,1736836126.381 [PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth:ApproachDepthPropellerOn](INFO): Completed PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth:ApproachDepthPropellerOn
2025-01-14T06:28:46.381Z,1736836126.381 [PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth:ApproachDepthPropellerOn] Stopped
2025-01-14T06:28:46.381Z,1736836126.381 [PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth:ApproachDepthPropellerOn](DEBUG): Aggregate::uninitialize PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth:ApproachDepthPropellerOn
2025-01-14T06:28:46.381Z,1736836126.381 [PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth:ApproachDepthPropellerOn:A.Mass] Stopped
2025-01-14T06:28:46.381Z,1736836126.381 [PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth:ApproachDepthPropellerOn:A.Mass](DEBUG): Uninitialize.
2025-01-14T06:28:46.381Z,1736836126.381 [PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth:ApproachDepthPropellerOn:B.Buoyancy] Stopped
2025-01-14T06:28:46.381Z,1736836126.381 [PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth:ApproachDepthPropellerOn:B.Buoyancy](DEBUG): Uninitialize Buoyancy Component.
2025-01-14T06:28:46.381Z,1736836126.381 [PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth:ApproachDepthPropellerOn:E.Point] Stopped
2025-01-14T06:28:46.381Z,1736836126.381 [PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth:ApproachDepthPropellerOn:F.SetSpeed] Stopped
2025-01-14T06:28:46.381Z,1736836126.381 [PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth:ApproachDepthPropellerOn:F.SetSpeed](DEBUG): Uninitialize.
2025-01-14T06:28:46.382Z,1736836126.382 [PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth:ApproachDepthPropellerOff] Running Loop=1
2025-01-14T06:28:46.382Z,1736836126.382 [PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth:ApproachDepthPropellerOff](DEBUG): Aggregate::initialize PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth:ApproachDepthPropellerOff
2025-01-14T06:28:46.382Z,1736836126.382 [PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth:ApproachDepthPropellerOff:A.Mass] Running Loop=1
2025-01-14T06:28:46.382Z,1736836126.382 [PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth:ApproachDepthPropellerOff:A.Mass](DEBUG): Initialize.
2025-01-14T06:28:46.382Z,1736836126.382 [PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth:ApproachDepthPropellerOff:D.Point] Running Loop=1
2025-01-14T06:28:46.382Z,1736836126.382 [PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth:ApproachDepthPropellerOff:D.Point](DEBUG): Initialize.
2025-01-14T06:28:46.382Z,1736836126.382 [PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth:ApproachDepthPropellerOff:E.SetSpeed] Running Loop=1
2025-01-14T06:28:46.382Z,1736836126.382 [PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth:ApproachDepthPropellerOff:E.SetSpeed](DEBUG): Initialize.
2025-01-14T06:28:46.382Z,1736836126.382 [PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth:ApproachDepthPropellerOff:B] Running Loop=1
2025-01-14T06:28:46.795Z,1736836126.795 [PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth:ApproachDepthPropellerOff] Stopped
2025-01-14T06:28:46.795Z,1736836126.795 [PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth:ApproachDepthPropellerOff](DEBUG): Aggregate::uninitialize PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth:ApproachDepthPropellerOff
2025-01-14T06:28:46.795Z,1736836126.795 [PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth:ApproachDepthPropellerOff:A.Mass] Stopped
2025-01-14T06:28:46.795Z,1736836126.795 [PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth:ApproachDepthPropellerOff:A.Mass](DEBUG): Uninitialize.
2025-01-14T06:28:46.795Z,1736836126.795 [PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth:ApproachDepthPropellerOff:B] Stopped
2025-01-14T06:28:46.795Z,1736836126.795 [PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth:ApproachDepthPropellerOff:D.Point] Stopped
2025-01-14T06:28:46.796Z,1736836126.796 [PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth:ApproachDepthPropellerOff:E.SetSpeed] Stopped
2025-01-14T06:28:46.796Z,1736836126.796 [PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth:ApproachDepthPropellerOff:E.SetSpeed](DEBUG): Uninitialize.
2025-01-14T06:28:46.796Z,1736836126.796 [PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth](INFO): Completed PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth
2025-01-14T06:28:46.796Z,1736836126.796 [PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth] Stopped
2025-01-14T06:28:46.796Z,1736836126.796 [PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth](DEBUG): Aggregate::uninitialize PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth
2025-01-14T06:28:46.796Z,1736836126.796 [PAM:PAM:ApproachDepthSettleAtDepth:Settle] Running Loop=1
2025-01-14T06:28:46.796Z,1736836126.796 [PAM:PAM:ApproachDepthSettleAtDepth:Settle](DEBUG): Aggregate::initialize PAM:PAM:ApproachDepthSettleAtDepth:Settle
2025-01-14T06:28:46.796Z,1736836126.796 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:A.Mass] Running Loop=1
2025-01-14T06:28:46.796Z,1736836126.796 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:A.Mass](DEBUG): Initialize.
2025-01-14T06:28:46.797Z,1736836126.797 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:B.Buoyancy] Running Loop=1
2025-01-14T06:28:46.797Z,1736836126.797 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:B.Buoyancy](DEBUG): Initialize Buoyancy Component.
2025-01-14T06:28:46.797Z,1736836126.797 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:VBSDepthLimit] Running Loop=1
2025-01-14T06:28:46.797Z,1736836126.797 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:VBSDepthLimit](DEBUG): Aggregate::initialize PAM:PAM:ApproachDepthSettleAtDepth:Settle:VBSDepthLimit
2025-01-14T06:28:46.797Z,1736836126.797 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:VBSDepthLimit:ShallowerThanVBSDepthLimit] Running Loop=1
2025-01-14T06:28:46.797Z,1736836126.797 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:VBSDepthLimit:ShallowerThanVBSDepthLimit](DEBUG): Aggregate::initialize PAM:PAM:ApproachDepthSettleAtDepth:Settle:VBSDepthLimit:ShallowerThanVBSDepthLimit
2025-01-14T06:28:46.797Z,1736836126.797 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:VBSDepthLimit:ShallowerThanVBSDepthLimit:A] Running Loop=1
2025-01-14T06:28:47.183Z,1736836127.183 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:VBSDepthLimit:ShallowerThanVBSDepthLimit:A] Stopped
2025-01-14T06:28:47.183Z,1736836127.183 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:VBSDepthLimit:ShallowerThanVBSDepthLimit](INFO): Completed PAM:PAM:ApproachDepthSettleAtDepth:Settle:VBSDepthLimit:ShallowerThanVBSDepthLimit
2025-01-14T06:28:47.183Z,1736836127.183 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:VBSDepthLimit:ShallowerThanVBSDepthLimit] Stopped
2025-01-14T06:28:47.184Z,1736836127.184 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:VBSDepthLimit:ShallowerThanVBSDepthLimit](DEBUG): Aggregate::uninitialize PAM:PAM:ApproachDepthSettleAtDepth:Settle:VBSDepthLimit:ShallowerThanVBSDepthLimit
2025-01-14T06:28:47.184Z,1736836127.184 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:VBSDepthLimit:DeeperThanVBSDepthLimit] Running Loop=1
2025-01-14T06:28:47.184Z,1736836127.184 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:VBSDepthLimit:DeeperThanVBSDepthLimit](DEBUG): Aggregate::initialize PAM:PAM:ApproachDepthSettleAtDepth:Settle:VBSDepthLimit:DeeperThanVBSDepthLimit
2025-01-14T06:28:47.184Z,1736836127.184 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:VBSDepthLimit:DeeperThanVBSDepthLimit:A] Running Loop=1
2025-01-14T06:28:47.184Z,1736836127.184 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:B.Buoyancy] Running Loop=1
2025-01-14T06:28:47.185Z,1736836127.185 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:A.Mass] Running Loop=1
2025-01-14T06:28:47.683Z,1736836127.683 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:VBSDepthLimit:DeeperThanVBSDepthLimit] Stopped
2025-01-14T06:28:47.684Z,1736836127.684 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:VBSDepthLimit:DeeperThanVBSDepthLimit](DEBUG): Aggregate::uninitialize PAM:PAM:ApproachDepthSettleAtDepth:Settle:VBSDepthLimit:DeeperThanVBSDepthLimit
2025-01-14T06:28:47.684Z,1736836127.684 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:VBSDepthLimit:DeeperThanVBSDepthLimit:A] Stopped
2025-01-14T06:28:47.685Z,1736836127.685 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:VBSDepthLimit](INFO): Completed PAM:PAM:ApproachDepthSettleAtDepth:Settle:VBSDepthLimit
2025-01-14T06:28:47.685Z,1736836127.685 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:VBSDepthLimit] Stopped
2025-01-14T06:28:47.685Z,1736836127.685 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:VBSDepthLimit](DEBUG): Aggregate::uninitialize PAM:PAM:ApproachDepthSettleAtDepth:Settle:VBSDepthLimit
2025-01-14T06:28:47.685Z,1736836127.685 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:settle_at_depth] Running Loop=1
2025-01-14T06:28:47.685Z,1736836127.685 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:settle_at_depth](DEBUG): Aggregate::initialize PAM:PAM:ApproachDepthSettleAtDepth:Settle:settle_at_depth
2025-01-14T06:28:47.685Z,1736836127.685 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:settle_at_depth:A] Running Loop=1
2025-01-14T06:28:48.097Z,1736836128.097 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:settle_at_depth:A](IMPORTANT): Reached  40.201092 m , settling for  5.000000 min at 0.000000 m/s 
2025-01-14T06:28:48.098Z,1736836128.098 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:settle_at_depth:A] Stopped
2025-01-14T06:28:48.098Z,1736836128.098 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:settle_at_depth:SettleAtDepthPropellerOn] Running Loop=1
2025-01-14T06:28:48.098Z,1736836128.098 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:settle_at_depth:SettleAtDepthPropellerOn](DEBUG): Aggregate::initialize PAM:PAM:ApproachDepthSettleAtDepth:Settle:settle_at_depth:SettleAtDepthPropellerOn
2025-01-14T06:28:48.098Z,1736836128.098 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:settle_at_depth:SettleAtDepthPropellerOn:A.Point] Running Loop=1
2025-01-14T06:28:48.098Z,1736836128.098 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:settle_at_depth:SettleAtDepthPropellerOn:A.Point](DEBUG): Initialize.
2025-01-14T06:28:48.098Z,1736836128.098 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:settle_at_depth:SettleAtDepthPropellerOn:B.SetSpeed] Running Loop=1
2025-01-14T06:28:48.099Z,1736836128.099 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:settle_at_depth:SettleAtDepthPropellerOn:B.SetSpeed](DEBUG): Initialize.
2025-01-14T06:28:48.099Z,1736836128.099 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:settle_at_depth:SettleAtDepthPropellerOn:C.Pitch] Running Loop=1
2025-01-14T06:28:48.099Z,1736836128.099 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:settle_at_depth:SettleAtDepthPropellerOn:C.Pitch](DEBUG): Initialize.
2025-01-14T06:28:48.099Z,1736836128.099 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:settle_at_depth:SettleAtDepthPropellerOn:D.Wait] Running Loop=1
2025-01-14T06:28:48.099Z,1736836128.099 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:settle_at_depth:SettleAtDepthPropellerOn:D.Wait](DEBUG): Initialize Wait Component.
2025-01-14T06:28:48.388Z,1736836128.388 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:settle_at_depth:SettleAtDepthPropellerOn] Stopped
2025-01-14T06:28:48.388Z,1736836128.388 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:settle_at_depth:SettleAtDepthPropellerOn](DEBUG): Aggregate::uninitialize PAM:PAM:ApproachDepthSettleAtDepth:Settle:settle_at_depth:SettleAtDepthPropellerOn
2025-01-14T06:28:48.388Z,1736836128.388 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:settle_at_depth:SettleAtDepthPropellerOn:A.Point] Stopped
2025-01-14T06:28:48.388Z,1736836128.388 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:settle_at_depth:SettleAtDepthPropellerOn:B.SetSpeed] Stopped
2025-01-14T06:28:48.388Z,1736836128.388 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:settle_at_depth:SettleAtDepthPropellerOn:B.SetSpeed](DEBUG): Uninitialize.
2025-01-14T06:28:48.388Z,1736836128.388 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:settle_at_depth:SettleAtDepthPropellerOn:C.Pitch] Stopped
2025-01-14T06:28:48.388Z,1736836128.388 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:settle_at_depth:SettleAtDepthPropellerOn:D.Wait] Stopped
2025-01-14T06:28:48.388Z,1736836128.388 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:settle_at_depth:SettleAtDepthPropellerOn:D.Wait](DEBUG): Uninitialize Wait Component.
2025-01-14T06:28:48.389Z,1736836128.389 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:settle_at_depth:SettleAtDepthPropellerOff] Running Loop=1
2025-01-14T06:28:48.389Z,1736836128.389 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:settle_at_depth:SettleAtDepthPropellerOff](DEBUG): Aggregate::initialize PAM:PAM:ApproachDepthSettleAtDepth:Settle:settle_at_depth:SettleAtDepthPropellerOff
2025-01-14T06:28:48.389Z,1736836128.389 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:settle_at_depth:SettleAtDepthPropellerOff:A.Point] Running Loop=1
2025-01-14T06:28:48.389Z,1736836128.389 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:settle_at_depth:SettleAtDepthPropellerOff:A.Point](DEBUG): Initialize.
2025-01-14T06:28:48.389Z,1736836128.389 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:settle_at_depth:SettleAtDepthPropellerOff:B.SetSpeed] Running Loop=1
2025-01-14T06:28:48.389Z,1736836128.389 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:settle_at_depth:SettleAtDepthPropellerOff:B.SetSpeed](DEBUG): Initialize.
2025-01-14T06:28:48.389Z,1736836128.389 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:settle_at_depth:SettleAtDepthPropellerOff:C.Pitch] Running Loop=1
2025-01-14T06:28:48.389Z,1736836128.389 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:settle_at_depth:SettleAtDepthPropellerOff:C.Pitch](DEBUG): Initialize.
2025-01-14T06:28:48.390Z,1736836128.390 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:settle_at_depth:SettleAtDepthPropellerOff:D.Wait] Running Loop=1
2025-01-14T06:28:48.390Z,1736836128.390 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:settle_at_depth:SettleAtDepthPropellerOff:D.Wait](DEBUG): Initialize Wait Component.
2025-01-14T06:28:48.592Z,1736836128.592 [WetLabsUBAT](ERROR): Failed to parse incomplete device message.
2025-01-14T06:28:48.803Z,1736836128.803 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:settle_at_depth:SettleAtDepthPropellerOff:C.Pitch] Running Loop=1
2025-01-14T06:28:48.803Z,1736836128.803 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:settle_at_depth:SettleAtDepthPropellerOff:B.SetSpeed] Running Loop=1
2025-01-14T06:28:48.804Z,1736836128.804 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:settle_at_depth:SettleAtDepthPropellerOff:A.Point] Running Loop=1
2025-01-14T06:28:51.615Z,1736836131.615 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error. Device response is::TS,25011322295484,35.0, +11.9,   0.0,1496.8, ,588.19, 544.62, 547.34, 577.30
2025-01-14T06:28:55.380Z,1736836135.380 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-14T06:28:56.384Z,1736836136.384 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-01-14T06:29:11.816Z,1736836151.816 [RDI_Pathfinder](ERROR): only read 2 of 4 data items for water velocity. Device response is::WS,    +8,  +375A
2025-01-14T06:29:21.925Z,1736836161.925 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for water mass range. Device response is::WD,     -320.52,     +166  -188.93,  20.00,  B,  +239,    -2,  

2025-01-14T06:29:26.504Z,1736836166.504 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-14T06:29:27.508Z,1736836167.508 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-01-14T06:29:41.754Z,1736836181.754 [RDI_Pathfinder](ERROR): only read 2 of 4 data items for bottom velocity. Device response is::BS,   +36,  +278,  

2025-01-14T06:29:51.827Z,1736836191.827 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude. Device response is::BD,     -    +1900.87, .69,  0.00
2025-01-14T06:29:57.641Z,1736836197.641 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-14T06:29:58.645Z,1736836198.645 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-01-14T06:30:01.929Z,1736836201.929 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude. Device response is::BD,     -222.71,     +1903.0155.74,  56.27,  0.00
2025-01-14T06:30:28.784Z,1736836228.784 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-14T06:30:29.789Z,1736836229.789 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-01-14T06:30:59.908Z,1736836259.908 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-14T06:31:00.912Z,1736836260.912 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-01-14T06:31:23.932Z,1736836283.932 [RDI_Pathfinder](ERROR): only read 2 of 4 data items for beam range. Device response is::RA,  0.00, 591.92, 479.66-7,A
2025-01-14T06:31:31.040Z,1736836291.040 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-14T06:31:32.044Z,1736836292.044 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-01-14T06:32:02.164Z,1736836322.164 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-14T06:32:03.168Z,1736836323.168 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-01-14T06:32:33.288Z,1736836353.288 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-14T06:32:34.292Z,1736836354.292 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-01-14T06:33:04.412Z,1736836384.412 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-14T06:33:05.416Z,1736836385.416 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-01-14T06:33:23.924Z,1736836403.924 [RDI_Pathfinder](ERROR): only read 3 of 4 data items for beam range. Device response is::RA,  0.00, 552.33, 490.40, 502.31
2025-01-14T06:33:35.556Z,1736836415.556 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-14T06:33:36.557Z,1736836416.557 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-01-14T06:33:48.980Z,1736836428.980 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:settle_at_depth:SettleAtDepthPropellerOff:D.Wait](INFO): Done Waiting.
2025-01-14T06:33:48.980Z,1736836428.980 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:settle_at_depth:SettleAtDepthPropellerOff:D.Wait] Stopped
2025-01-14T06:33:48.980Z,1736836428.980 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:settle_at_depth:SettleAtDepthPropellerOff:D.Wait](DEBUG): Uninitialize Wait Component.
2025-01-14T06:33:48.980Z,1736836428.980 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:settle_at_depth:SettleAtDepthPropellerOff:E] Running Loop=1
2025-01-14T06:33:49.395Z,1736836429.395 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:settle_at_depth:SettleAtDepthPropellerOff:E] Stopped
2025-01-14T06:33:49.395Z,1736836429.395 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:settle_at_depth:SettleAtDepthPropellerOff:F] Running Loop=1
2025-01-14T06:33:49.830Z,1736836429.830 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:settle_at_depth:SettleAtDepthPropellerOff:F] Stopped
2025-01-14T06:33:49.831Z,1736836429.831 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:settle_at_depth:SettleAtDepthPropellerOff](INFO): Completed PAM:PAM:ApproachDepthSettleAtDepth:Settle:settle_at_depth:SettleAtDepthPropellerOff
2025-01-14T06:33:49.831Z,1736836429.831 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:settle_at_depth:SettleAtDepthPropellerOff] Stopped
2025-01-14T06:33:49.831Z,1736836429.831 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:settle_at_depth:SettleAtDepthPropellerOff](DEBUG): Aggregate::uninitialize PAM:PAM:ApproachDepthSettleAtDepth:Settle:settle_at_depth:SettleAtDepthPropellerOff
2025-01-14T06:33:49.831Z,1736836429.831 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:settle_at_depth:SettleAtDepthPropellerOff:A.Point] Stopped
2025-01-14T06:33:49.831Z,1736836429.831 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:settle_at_depth:SettleAtDepthPropellerOff:B.SetSpeed] Stopped
2025-01-14T06:33:49.831Z,1736836429.831 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:settle_at_depth:SettleAtDepthPropellerOff:B.SetSpeed](DEBUG): Uninitialize.
2025-01-14T06:33:49.831Z,1736836429.831 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:settle_at_depth:SettleAtDepthPropellerOff:C.Pitch] Stopped
2025-01-14T06:33:49.832Z,1736836429.832 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:settle_at_depth](INFO): Completed PAM:PAM:ApproachDepthSettleAtDepth:Settle:settle_at_depth
2025-01-14T06:33:49.832Z,1736836429.832 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:settle_at_depth] Stopped
2025-01-14T06:33:49.832Z,1736836429.832 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:settle_at_depth](DEBUG): Aggregate::uninitialize PAM:PAM:ApproachDepthSettleAtDepth:Settle:settle_at_depth
2025-01-14T06:33:49.833Z,1736836429.833 [PAM:PAM:ApproachDepthSettleAtDepth:Settle](INFO): Completed PAM:PAM:ApproachDepthSettleAtDepth:Settle
2025-01-14T06:33:49.833Z,1736836429.833 [PAM:PAM:ApproachDepthSettleAtDepth:Settle] Stopped
2025-01-14T06:33:49.833Z,1736836429.833 [PAM:PAM:ApproachDepthSettleAtDepth:Settle](DEBUG): Aggregate::uninitialize PAM:PAM:ApproachDepthSettleAtDepth:Settle
2025-01-14T06:33:49.833Z,1736836429.833 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:A.Mass] Stopped
2025-01-14T06:33:49.833Z,1736836429.833 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:A.Mass](DEBUG): Uninitialize.
2025-01-14T06:33:49.833Z,1736836429.833 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:B.Buoyancy] Stopped
2025-01-14T06:33:49.833Z,1736836429.833 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:B.Buoyancy](DEBUG): Uninitialize Buoyancy Component.
2025-01-14T06:33:49.833Z,1736836429.833 [PAM:PAM:ApproachDepthSettleAtDepth:Hover] Running Loop=1
2025-01-14T06:33:49.833Z,1736836429.833 [PAM:PAM:ApproachDepthSettleAtDepth:Hover](DEBUG): Aggregate::initialize PAM:PAM:ApproachDepthSettleAtDepth:Hover
2025-01-14T06:33:49.833Z,1736836429.833 [PAM:PAM:ApproachDepthSettleAtDepth:Hover:A.Mass] Running Loop=1
2025-01-14T06:33:49.833Z,1736836429.833 [PAM:PAM:ApproachDepthSettleAtDepth:Hover:A.Mass](DEBUG): Initialize.
2025-01-14T06:33:49.834Z,1736836429.834 [PAM:PAM:ApproachDepthSettleAtDepth:Hover:B.Buoyancy] Running Loop=1
2025-01-14T06:33:49.834Z,1736836429.834 [PAM:PAM:ApproachDepthSettleAtDepth:Hover:B.Buoyancy](DEBUG): Initialize Buoyancy Component.
2025-01-14T06:33:49.834Z,1736836429.834 [PAM:PAM:ApproachDepthSettleAtDepth:Hover:C.Pitch] Running Loop=1
2025-01-14T06:33:49.834Z,1736836429.834 [PAM:PAM:ApproachDepthSettleAtDepth:Hover:C.Pitch](DEBUG): Initialize.
2025-01-14T06:33:49.834Z,1736836429.834 [PAM:PAM:ApproachDepthSettleAtDepth:Hover:D.Point] Running Loop=1
2025-01-14T06:33:49.834Z,1736836429.834 [PAM:PAM:ApproachDepthSettleAtDepth:Hover:D.Point](DEBUG): Initialize.
2025-01-14T06:33:49.834Z,1736836429.834 [PAM:PAM:ApproachDepthSettleAtDepth:Hover:E.SetSpeed] Running Loop=1
2025-01-14T06:33:49.834Z,1736836429.834 [PAM:PAM:ApproachDepthSettleAtDepth:Hover:E.SetSpeed](DEBUG): Initialize.
2025-01-14T06:33:49.834Z,1736836429.834 [PAM:PAM:ApproachDepthSettleAtDepth:Hover:F.Wait] Running Loop=1
2025-01-14T06:33:49.834Z,1736836429.834 [PAM:PAM:ApproachDepthSettleAtDepth:Hover:F.Wait](DEBUG): Initialize Wait Component.
2025-01-14T06:33:50.186Z,1736836430.186 [PAM:PAM:ApproachDepthSettleAtDepth:Hover:E.SetSpeed] Running Loop=1
2025-01-14T06:33:50.187Z,1736836430.187 [PAM:PAM:ApproachDepthSettleAtDepth:Hover:D.Point] Running Loop=1
2025-01-14T06:33:50.187Z,1736836430.187 [PAM:PAM:ApproachDepthSettleAtDepth:Hover:C.Pitch] Running Loop=1
2025-01-14T06:33:50.187Z,1736836430.187 [PAM:PAM:ApproachDepthSettleAtDepth:Hover:B.Buoyancy] Running Loop=1
2025-01-14T06:33:50.189Z,1736836430.189 [PAM:PAM:ApproachDepthSettleAtDepth:Hover:A.Mass] Running Loop=1
2025-01-14T06:34:06.676Z,1736836446.676 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-14T06:34:07.681Z,1736836447.681 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-01-14T06:34:24.930Z,1736836464.930 [PAM:PAM:ApproachDepthSettleAtDepth:Hover] Stopped
2025-01-14T06:34:24.930Z,1736836464.930 [PAM:PAM:ApproachDepthSettleAtDepth:Hover](DEBUG): Aggregate::uninitialize PAM:PAM:ApproachDepthSettleAtDepth:Hover
2025-01-14T06:34:24.931Z,1736836464.931 [PAM:PAM:ApproachDepthSettleAtDepth:Hover:A.Mass] Stopped
2025-01-14T06:34:24.931Z,1736836464.931 [PAM:PAM:ApproachDepthSettleAtDepth:Hover:A.Mass](DEBUG): Uninitialize.
2025-01-14T06:34:24.931Z,1736836464.931 [PAM:PAM:ApproachDepthSettleAtDepth:Hover:B.Buoyancy] Stopped
2025-01-14T06:34:24.931Z,1736836464.931 [PAM:PAM:ApproachDepthSettleAtDepth:Hover:B.Buoyancy](DEBUG): Uninitialize Buoyancy Component.
2025-01-14T06:34:24.931Z,1736836464.931 [PAM:PAM:ApproachDepthSettleAtDepth:Hover:C.Pitch] Stopped
2025-01-14T06:34:24.931Z,1736836464.931 [PAM:PAM:ApproachDepthSettleAtDepth:Hover:D.Point] Stopped
2025-01-14T06:34:24.931Z,1736836464.931 [PAM:PAM:ApproachDepthSettleAtDepth:Hover:E.SetSpeed] Stopped
2025-01-14T06:34:24.931Z,1736836464.931 [PAM:PAM:ApproachDepthSettleAtDepth:Hover:E.SetSpeed](DEBUG): Uninitialize.
2025-01-14T06:34:24.931Z,1736836464.931 [PAM:PAM:ApproachDepthSettleAtDepth:Hover:F.Wait] Stopped
2025-01-14T06:34:24.931Z,1736836464.931 [PAM:PAM:ApproachDepthSettleAtDepth:Hover:F.Wait](DEBUG): Uninitialize Wait Component.
2025-01-14T06:34:24.932Z,1736836464.932 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound] Running Loop=1
2025-01-14T06:34:24.932Z,1736836464.932 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound](DEBUG): Aggregate::initialize PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound
2025-01-14T06:34:24.932Z,1736836464.932 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:A.Mass] Running Loop=1
2025-01-14T06:34:24.932Z,1736836464.932 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:A.Mass](DEBUG): Initialize.
2025-01-14T06:34:24.932Z,1736836464.932 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:B.Buoyancy] Running Loop=1
2025-01-14T06:34:24.932Z,1736836464.932 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:B.Buoyancy](DEBUG): Initialize Buoyancy Component.
2025-01-14T06:34:24.933Z,1736836464.933 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:C] Running Loop=1
2025-01-14T06:34:25.338Z,1736836465.338 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:C] Stopped
2025-01-14T06:34:25.339Z,1736836465.339 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:D] Running Loop=1
2025-01-14T06:34:25.339Z,1736836465.339 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:B.Buoyancy] Running Loop=1
2025-01-14T06:34:25.339Z,1736836465.339 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:A.Mass] Running Loop=1
2025-01-14T06:34:25.788Z,1736836465.788 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:D] Stopped
2025-01-14T06:34:25.788Z,1736836465.788 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:E] Running Loop=1
2025-01-14T06:34:26.149Z,1736836466.149 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:E] Stopped
2025-01-14T06:34:26.149Z,1736836466.149 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:F] Running Loop=1
2025-01-14T06:34:26.568Z,1736836466.568 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:F](IMPORTANT): Now depth  50.067768 m  is deeper than DeepBound  50.000000 m .
2025-01-14T06:34:26.568Z,1736836466.568 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:F] Stopped
2025-01-14T06:34:26.568Z,1736836466.568 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:IncreaseNeutralBuoyancy] Running Loop=1
2025-01-14T06:34:26.568Z,1736836466.568 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:IncreaseNeutralBuoyancy](DEBUG): Aggregate::initialize PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:IncreaseNeutralBuoyancy
2025-01-14T06:34:26.568Z,1736836466.568 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:IncreaseNeutralBuoyancy:IncreaseNeutralBuoyancyDecreaseDelta] Running Loop=1
2025-01-14T06:34:26.568Z,1736836466.568 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:IncreaseNeutralBuoyancy:IncreaseNeutralBuoyancyDecreaseDelta](DEBUG): Aggregate::initialize PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:IncreaseNeutralBuoyancy:IncreaseNeutralBuoyancyDecreaseDelta
2025-01-14T06:34:26.569Z,1736836466.569 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:IncreaseNeutralBuoyancy:IncreaseNeutralBuoyancyDecreaseDelta:A] Running Loop=1
2025-01-14T06:34:26.951Z,1736836466.951 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:IncreaseNeutralBuoyancy:IncreaseNeutralBuoyancyDecreaseDelta] Stopped
2025-01-14T06:34:26.953Z,1736836466.953 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:IncreaseNeutralBuoyancy:IncreaseNeutralBuoyancyDecreaseDelta](DEBUG): Aggregate::uninitialize PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:IncreaseNeutralBuoyancy:IncreaseNeutralBuoyancyDecreaseDelta
2025-01-14T06:34:26.953Z,1736836466.953 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:IncreaseNeutralBuoyancy:IncreaseNeutralBuoyancyDecreaseDelta:A] Stopped
2025-01-14T06:34:26.953Z,1736836466.953 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:IncreaseNeutralBuoyancy:IncreaseNeutralBuoyancyDoNotChangeDelta] Running Loop=1
2025-01-14T06:34:26.953Z,1736836466.953 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:IncreaseNeutralBuoyancy:IncreaseNeutralBuoyancyDoNotChangeDelta](DEBUG): Aggregate::initialize PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:IncreaseNeutralBuoyancy:IncreaseNeutralBuoyancyDoNotChangeDelta
2025-01-14T06:34:26.953Z,1736836466.953 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:IncreaseNeutralBuoyancy:IncreaseNeutralBuoyancyDoNotChangeDelta:A] Running Loop=1
2025-01-14T06:34:27.365Z,1736836467.365 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:IncreaseNeutralBuoyancy:IncreaseNeutralBuoyancyDoNotChangeDelta:A] Stopped
2025-01-14T06:34:27.365Z,1736836467.365 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:IncreaseNeutralBuoyancy:IncreaseNeutralBuoyancyDoNotChangeDelta:B] Running Loop=1
2025-01-14T06:34:27.786Z,1736836467.786 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:IncreaseNeutralBuoyancy:IncreaseNeutralBuoyancyDoNotChangeDelta:B] Stopped
2025-01-14T06:34:27.786Z,1736836467.786 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:IncreaseNeutralBuoyancy:IncreaseNeutralBuoyancyDoNotChangeDelta:C] Running Loop=1
2025-01-14T06:34:28.186Z,1736836468.186 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:IncreaseNeutralBuoyancy:IncreaseNeutralBuoyancyDoNotChangeDelta:C] Stopped
2025-01-14T06:34:28.186Z,1736836468.186 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:IncreaseNeutralBuoyancy:IncreaseNeutralBuoyancyDoNotChangeDelta:D] Running Loop=1
2025-01-14T06:34:28.581Z,1736836468.581 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:IncreaseNeutralBuoyancy:IncreaseNeutralBuoyancyDoNotChangeDelta:D] Stopped
2025-01-14T06:34:28.581Z,1736836468.581 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:IncreaseNeutralBuoyancy:IncreaseNeutralBuoyancyDoNotChangeDelta:E] Running Loop=1
2025-01-14T06:34:28.984Z,1736836468.984 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:IncreaseNeutralBuoyancy:IncreaseNeutralBuoyancyDoNotChangeDelta:E](IMPORTANT): Vehicle is too heavy. Increase neutral buoyancy:  401.869358 cc  +  16.000000 cc  =  417.869354 cc . Move mass backwards:  21.805966 mm  -  0.528000 mm  =  21.277966 mm . FineTune =  0 bool . WaitAfterBuoyancyChange =  5.000000 min .
2025-01-14T06:34:28.984Z,1736836468.984 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:IncreaseNeutralBuoyancy:IncreaseNeutralBuoyancyDoNotChangeDelta:E] Stopped
2025-01-14T06:34:28.984Z,1736836468.984 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:IncreaseNeutralBuoyancy:IncreaseNeutralBuoyancyDoNotChangeDelta:F] Running Loop=1
2025-01-14T06:34:29.395Z,1736836469.395 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:IncreaseNeutralBuoyancy:IncreaseNeutralBuoyancyDoNotChangeDelta:F] Stopped
2025-01-14T06:34:29.396Z,1736836469.396 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:IncreaseNeutralBuoyancy:IncreaseNeutralBuoyancyDoNotChangeDelta:G] Running Loop=1
2025-01-14T06:34:29.817Z,1736836469.817 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:IncreaseNeutralBuoyancy:IncreaseNeutralBuoyancyDoNotChangeDelta:G] Stopped
2025-01-14T06:34:29.817Z,1736836469.817 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:IncreaseNeutralBuoyancy:IncreaseNeutralBuoyancyDoNotChangeDelta:H] Running Loop=1
2025-01-14T06:34:30.207Z,1736836470.207 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:IncreaseNeutralBuoyancy:IncreaseNeutralBuoyancyDoNotChangeDelta:H] Stopped
2025-01-14T06:34:30.207Z,1736836470.207 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:IncreaseNeutralBuoyancy:IncreaseNeutralBuoyancyDoNotChangeDelta](INFO): Completed PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:IncreaseNeutralBuoyancy:IncreaseNeutralBuoyancyDoNotChangeDelta
2025-01-14T06:34:30.207Z,1736836470.207 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:IncreaseNeutralBuoyancy:IncreaseNeutralBuoyancyDoNotChangeDelta] Stopped
2025-01-14T06:34:30.207Z,1736836470.207 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:IncreaseNeutralBuoyancy:IncreaseNeutralBuoyancyDoNotChangeDelta](DEBUG): Aggregate::uninitialize PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:IncreaseNeutralBuoyancy:IncreaseNeutralBuoyancyDoNotChangeDelta
2025-01-14T06:34:30.232Z,1736836470.232 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:IncreaseNeutralBuoyancy](INFO): Completed PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:IncreaseNeutralBuoyancy
2025-01-14T06:34:30.232Z,1736836470.232 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:IncreaseNeutralBuoyancy] Stopped
2025-01-14T06:34:30.232Z,1736836470.232 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:IncreaseNeutralBuoyancy](DEBUG): Aggregate::uninitialize PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:IncreaseNeutralBuoyancy
2025-01-14T06:34:30.232Z,1736836470.232 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:I] Running Loop=1
2025-01-14T06:34:30.613Z,1736836470.613 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:I] Stopped
2025-01-14T06:34:30.614Z,1736836470.614 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:TurnOnFineTuneModeDeeperThanDeepBound] Running Loop=1
2025-01-14T06:34:30.614Z,1736836470.614 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:TurnOnFineTuneModeDeeperThanDeepBound](DEBUG): Aggregate::initialize PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:TurnOnFineTuneModeDeeperThanDeepBound
2025-01-14T06:34:31.006Z,1736836471.006 [PAM:TurnOnFineTuneMode] Running Loop=1
2025-01-14T06:34:31.006Z,1736836471.006 [PAM:TurnOnFineTuneMode](DEBUG): Aggregate::initialize PAM:TurnOnFineTuneMode
2025-01-14T06:34:31.006Z,1736836471.006 [PAM:TurnOnFineTuneMode:FineTune] Running Loop=1
2025-01-14T06:34:31.006Z,1736836471.006 [PAM:TurnOnFineTuneMode:FineTune](DEBUG): Aggregate::initialize PAM:TurnOnFineTuneMode:FineTune
2025-01-14T06:34:31.006Z,1736836471.006 [PAM:TurnOnFineTuneMode:FineTune:A] Running Loop=1
2025-01-14T06:34:31.007Z,1736836471.007 [PAM:TurnOnFineTuneMode:FineTune] Stopped
2025-01-14T06:34:31.007Z,1736836471.007 [PAM:TurnOnFineTuneMode:FineTune](DEBUG): Aggregate::uninitialize PAM:TurnOnFineTuneMode:FineTune
2025-01-14T06:34:31.007Z,1736836471.007 [PAM:TurnOnFineTuneMode:FineTune:A] Stopped
2025-01-14T06:34:31.007Z,1736836471.007 [PAM:TurnOnFineTuneMode](INFO): Completed PAM:TurnOnFineTuneMode
2025-01-14T06:34:31.008Z,1736836471.008 [PAM:TurnOnFineTuneMode] Stopped
2025-01-14T06:34:31.008Z,1736836471.008 [PAM:TurnOnFineTuneMode](DEBUG): Aggregate::uninitialize PAM:TurnOnFineTuneMode
2025-01-14T06:34:31.418Z,1736836471.418 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:TurnOnFineTuneModeDeeperThanDeepBound](INFO): Completed PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:TurnOnFineTuneModeDeeperThanDeepBound
2025-01-14T06:34:31.418Z,1736836471.418 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:TurnOnFineTuneModeDeeperThanDeepBound] Stopped
2025-01-14T06:34:31.418Z,1736836471.418 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:TurnOnFineTuneModeDeeperThanDeepBound](DEBUG): Aggregate::uninitialize PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:TurnOnFineTuneModeDeeperThanDeepBound
2025-01-14T06:34:31.419Z,1736836471.419 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound](INFO): Completed PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound
2025-01-14T06:34:31.419Z,1736836471.419 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound] Stopped
2025-01-14T06:34:31.419Z,1736836471.419 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound](DEBUG): Aggregate::uninitialize PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound
2025-01-14T06:34:31.419Z,1736836471.419 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:A.Mass] Stopped
2025-01-14T06:34:31.419Z,1736836471.419 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:A.Mass](DEBUG): Uninitialize.
2025-01-14T06:34:31.419Z,1736836471.419 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:B.Buoyancy] Stopped
2025-01-14T06:34:31.419Z,1736836471.419 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:B.Buoyancy](DEBUG): Uninitialize Buoyancy Component.
2025-01-14T06:34:31.424Z,1736836471.424 [PAM:PAM:ApproachDepthSettleAtDepth:ShallowerThanShallowBound] Running Loop=1
2025-01-14T06:34:31.424Z,1736836471.424 [PAM:PAM:ApproachDepthSettleAtDepth:ShallowerThanShallowBound](DEBUG): Aggregate::initialize PAM:PAM:ApproachDepthSettleAtDepth:ShallowerThanShallowBound
2025-01-14T06:34:31.424Z,1736836471.424 [PAM:PAM:ApproachDepthSettleAtDepth:ShallowerThanShallowBound:A.Mass] Running Loop=1
2025-01-14T06:34:31.424Z,1736836471.424 [PAM:PAM:ApproachDepthSettleAtDepth:ShallowerThanShallowBound:A.Mass](DEBUG): Initialize.
2025-01-14T06:34:31.424Z,1736836471.424 [PAM:PAM:ApproachDepthSettleAtDepth:ShallowerThanShallowBound:B.Buoyancy] Running Loop=1
2025-01-14T06:34:31.424Z,1736836471.424 [PAM:PAM:ApproachDepthSettleAtDepth:ShallowerThanShallowBound:B.Buoyancy](DEBUG): Initialize Buoyancy Component.
2025-01-14T06:34:31.424Z,1736836471.424 [PAM:PAM:ApproachDepthSettleAtDepth:ShallowerThanShallowBound:C] Running Loop=1
2025-01-14T06:34:31.862Z,1736836471.862 [PAM:PAM:ApproachDepthSettleAtDepth:ShallowerThanShallowBound] Stopped
2025-01-14T06:34:31.862Z,1736836471.862 [PAM:PAM:ApproachDepthSettleAtDepth:ShallowerThanShallowBound](DEBUG): Aggregate::uninitialize PAM:PAM:ApproachDepthSettleAtDepth:ShallowerThanShallowBound
2025-01-14T06:34:31.862Z,1736836471.862 [PAM:PAM:ApproachDepthSettleAtDepth:ShallowerThanShallowBound:A.Mass] Stopped
2025-01-14T06:34:31.862Z,1736836471.862 [PAM:PAM:ApproachDepthSettleAtDepth:ShallowerThanShallowBound:A.Mass](DEBUG): Uninitialize.
2025-01-14T06:34:31.863Z,1736836471.863 [PAM:PAM:ApproachDepthSettleAtDepth:ShallowerThanShallowBound:B.Buoyancy] Stopped
2025-01-14T06:34:31.863Z,1736836471.863 [PAM:PAM:ApproachDepthSettleAtDepth:ShallowerThanShallowBound:B.Buoyancy](DEBUG): Uninitialize Buoyancy Component.
2025-01-14T06:34:31.863Z,1736836471.863 [PAM:PAM:ApproachDepthSettleAtDepth:ShallowerThanShallowBound:C] Stopped
2025-01-14T06:34:31.863Z,1736836471.863 [PAM:PAM:ApproachDepthSettleAtDepth](INFO): Completed PAM:PAM:ApproachDepthSettleAtDepth
2025-01-14T06:34:31.863Z,1736836471.863 [PAM:PAM:ApproachDepthSettleAtDepth] Stopped
2025-01-14T06:34:31.863Z,1736836471.863 [PAM:PAM:ApproachDepthSettleAtDepth](DEBUG): Aggregate::uninitialize PAM:PAM:ApproachDepthSettleAtDepth
2025-01-14T06:34:31.863Z,1736836471.863 [PAM:PAM](INFO): Completed PAM:PAM
2025-01-14T06:34:31.863Z,1736836471.863 [PAM:PAM] Stopped
2025-01-14T06:34:31.863Z,1736836471.863 [PAM:PAM](DEBUG): Aggregate::uninitialize PAM:PAM
2025-01-14T06:34:31.864Z,1736836471.864 [PAM:PAM](INFO): Running loop #2
2025-01-14T06:34:31.864Z,1736836471.864 [PAM:PAM] Running Loop=2
2025-01-14T06:34:31.864Z,1736836471.864 [PAM:PAM](DEBUG): Aggregate::initialize PAM:PAM
2025-01-14T06:34:31.864Z,1736836471.864 [PAM:PAM:SettingVariables] Running Loop=1
2025-01-14T06:34:31.864Z,1736836471.864 [PAM:PAM:SettingVariables](DEBUG): Aggregate::initialize PAM:PAM:SettingVariables
2025-01-14T06:34:31.864Z,1736836471.864 [PAM:PAM:SettingVariables:A.Mass] Running Loop=1
2025-01-14T06:34:31.864Z,1736836471.864 [PAM:PAM:SettingVariables:A.Mass](DEBUG): Initialize.
2025-01-14T06:34:31.864Z,1736836471.864 [PAM:PAM:SettingVariables:B.Buoyancy] Running Loop=1
2025-01-14T06:34:31.865Z,1736836471.865 [PAM:PAM:SettingVariables:B.Buoyancy](DEBUG): Initialize Buoyancy Component.
2025-01-14T06:34:31.865Z,1736836471.865 [PAM:PAM:SettingVariables:C] Running Loop=1
2025-01-14T06:34:32.212Z,1736836472.212 [PAM:PAM:SettingVariables:C] Stopped
2025-01-14T06:34:32.212Z,1736836472.212 [PAM:PAM:SettingVariables:D] Running Loop=1
2025-01-14T06:34:32.626Z,1736836472.626 [PAM:PAM:SettingVariables:D] Stopped
2025-01-14T06:34:32.626Z,1736836472.626 [PAM:PAM:SettingVariables:E] Running Loop=1
2025-01-14T06:34:33.019Z,1736836473.019 [PAM:PAM:SettingVariables:E] Stopped
2025-01-14T06:34:33.019Z,1736836473.019 [PAM:PAM:SettingVariables:F] Running Loop=1
2025-01-14T06:34:33.421Z,1736836473.421 [PAM:PAM:SettingVariables:F](IMPORTANT): Cnt =  2.000000 count 
2025-01-14T06:34:33.421Z,1736836473.421 [PAM:PAM:SettingVariables:F] Stopped
2025-01-14T06:34:33.421Z,1736836473.421 [PAM:PAM:SettingVariables:G] Running Loop=1
2025-01-14T06:34:33.883Z,1736836473.883 [PAM:PAM:SettingVariables:G](IMPORTANT): NeutralBuoyancy =  417.869354 cc , BuoyancyAdjustmentStep =  16.000000 cc , MassPosition =  21.277966 mm , MassPositionAdjustmentStep =  0.528000 mm 
2025-01-14T06:34:33.884Z,1736836473.884 [PAM:PAM:SettingVariables:G] Stopped
2025-01-14T06:34:33.884Z,1736836473.884 [PAM:PAM:SettingVariables:H] Running Loop=1
2025-01-14T06:34:34.243Z,1736836474.243 [PAM:PAM:SettingVariables:H] Stopped
2025-01-14T06:34:34.243Z,1736836474.243 [PAM:PAM:SettingVariables:I] Running Loop=1
2025-01-14T06:34:34.634Z,1736836474.634 [PAM:PAM:SettingVariables:I] Stopped
2025-01-14T06:34:34.634Z,1736836474.634 [PAM:PAM:SettingVariables](INFO): Completed PAM:PAM:SettingVariables
2025-01-14T06:34:34.634Z,1736836474.634 [PAM:PAM:SettingVariables] Stopped
2025-01-14T06:34:34.634Z,1736836474.634 [PAM:PAM:SettingVariables](DEBUG): Aggregate::uninitialize PAM:PAM:SettingVariables
2025-01-14T06:34:34.635Z,1736836474.635 [PAM:PAM:SettingVariables:A.Mass] Stopped
2025-01-14T06:34:34.635Z,1736836474.635 [PAM:PAM:SettingVariables:A.Mass](DEBUG): Uninitialize.
2025-01-14T06:34:34.635Z,1736836474.635 [PAM:PAM:SettingVariables:B.Buoyancy] Stopped
2025-01-14T06:34:34.635Z,1736836474.635 [PAM:PAM:SettingVariables:B.Buoyancy](DEBUG): Uninitialize Buoyancy Component.
2025-01-14T06:34:34.635Z,1736836474.635 [PAM:PAM:Waits] Running Loop=1
2025-01-14T06:34:34.635Z,1736836474.635 [PAM:PAM:Waits](DEBUG): Aggregate::initialize PAM:PAM:Waits
2025-01-14T06:34:34.635Z,1736836474.635 [PAM:PAM:Waits:A.Mass] Running Loop=1
2025-01-14T06:34:34.635Z,1736836474.635 [PAM:PAM:Waits:A.Mass](DEBUG): Initialize.
2025-01-14T06:34:34.635Z,1736836474.635 [PAM:PAM:Waits:B.Buoyancy] Running Loop=1
2025-01-14T06:34:34.635Z,1736836474.635 [PAM:PAM:Waits:B.Buoyancy](DEBUG): Initialize Buoyancy Component.
2025-01-14T06:34:34.636Z,1736836474.636 [PAM:PAM:Waits:WaitForSurfaceCommsCompletion] Running Loop=1
2025-01-14T06:34:34.636Z,1736836474.636 [PAM:PAM:Waits:WaitForSurfaceCommsCompletion](DEBUG): Aggregate::initialize PAM:PAM:Waits:WaitForSurfaceCommsCompletion
2025-01-14T06:34:34.636Z,1736836474.636 [PAM:PAM:Waits:WaitForSurfaceCommsCompletion:A.Wait] Running Loop=1
2025-01-14T06:34:34.636Z,1736836474.636 [PAM:PAM:Waits:WaitForSurfaceCommsCompletion:A.Wait](DEBUG): Initialize Wait Component.
2025-01-14T06:34:35.040Z,1736836475.040 [PAM:PAM:Waits:WaitForSurfaceCommsCompletion] Stopped
2025-01-14T06:34:35.040Z,1736836475.040 [PAM:PAM:Waits:WaitForSurfaceCommsCompletion](DEBUG): Aggregate::uninitialize PAM:PAM:Waits:WaitForSurfaceCommsCompletion
2025-01-14T06:34:35.040Z,1736836475.040 [PAM:PAM:Waits:WaitForSurfaceCommsCompletion:A.Wait] Stopped
2025-01-14T06:34:35.040Z,1736836475.040 [PAM:PAM:Waits:WaitForSurfaceCommsCompletion:A.Wait](DEBUG): Uninitialize Wait Component.
2025-01-14T06:34:35.040Z,1736836475.040 [PAM:PAM:Waits:WaitBuoyancyChange] Running Loop=1
2025-01-14T06:34:35.041Z,1736836475.041 [PAM:PAM:Waits:WaitBuoyancyChange](DEBUG): Aggregate::initialize PAM:PAM:Waits:WaitBuoyancyChange
2025-01-14T06:34:35.041Z,1736836475.041 [PAM:PAM:Waits:WaitBuoyancyChange:A] Running Loop=1
2025-01-14T06:34:35.460Z,1736836475.460 [PAM:PAM:Waits:WaitBuoyancyChange:A](IMPORTANT): After buoyancy change, wait for  5.000000 min 
2025-01-14T06:34:35.460Z,1736836475.460 [PAM:PAM:Waits:WaitBuoyancyChange:A] Stopped
2025-01-14T06:34:35.461Z,1736836475.461 [PAM:PAM:Waits:WaitBuoyancyChange:B.Wait] Running Loop=1
2025-01-14T06:34:35.461Z,1736836475.461 [PAM:PAM:Waits:WaitBuoyancyChange:B.Wait](DEBUG): Initialize Wait Component.
2025-01-14T06:34:37.800Z,1736836477.800 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-14T06:34:38.807Z,1736836478.807 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-01-14T06:35:08.924Z,1736836508.924 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-14T06:35:09.928Z,1736836509.928 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-01-14T06:35:23.196Z,1736836523.196 [WetLabsUBAT](ERROR): Failed to parse incomplete device message.
2025-01-14T06:35:40.048Z,1736836540.048 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-14T06:35:41.052Z,1736836541.052 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-01-14T06:36:11.176Z,1736836571.176 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-14T06:36:12.180Z,1736836572.180 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-01-14T06:36:42.318Z,1736836602.318 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-14T06:36:43.320Z,1736836603.320 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-01-14T06:37:13.440Z,1736836633.440 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-14T06:37:14.444Z,1736836634.444 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-01-14T06:37:44.568Z,1736836664.568 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-14T06:37:45.575Z,1736836665.575 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-01-14T06:38:15.709Z,1736836695.709 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-14T06:38:16.713Z,1736836696.713 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-01-14T06:38:46.834Z,1736836726.834 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-14T06:38:47.837Z,1736836727.837 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-01-14T06:39:17.964Z,1736836757.964 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-14T06:39:18.968Z,1736836758.968 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-01-14T06:39:36.028Z,1736836776.028 [PAM:PAM:Waits:WaitBuoyancyChange:B.Wait](INFO): Done Waiting.
2025-01-14T06:39:36.028Z,1736836776.028 [PAM:PAM:Waits:WaitBuoyancyChange:B.Wait] Stopped
2025-01-14T06:39:36.028Z,1736836776.028 [PAM:PAM:Waits:WaitBuoyancyChange:B.Wait](DEBUG): Uninitialize Wait Component.
2025-01-14T06:39:36.028Z,1736836776.028 [PAM:PAM:Waits:WaitBuoyancyChange](INFO): Completed PAM:PAM:Waits:WaitBuoyancyChange
2025-01-14T06:39:36.029Z,1736836776.029 [PAM:PAM:Waits:WaitBuoyancyChange] Stopped
2025-01-14T06:39:36.029Z,1736836776.029 [PAM:PAM:Waits:WaitBuoyancyChange](DEBUG): Aggregate::uninitialize PAM:PAM:Waits:WaitBuoyancyChange
2025-01-14T06:39:36.029Z,1736836776.029 [PAM:PAM:Waits](INFO): Completed PAM:PAM:Waits
2025-01-14T06:39:36.029Z,1736836776.029 [PAM:PAM:Waits] Stopped
2025-01-14T06:39:36.030Z,1736836776.030 [PAM:PAM:Waits](DEBUG): Aggregate::uninitialize PAM:PAM:Waits
2025-01-14T06:39:36.030Z,1736836776.030 [PAM:PAM:Waits:A.Mass] Stopped
2025-01-14T06:39:36.030Z,1736836776.030 [PAM:PAM:Waits:A.Mass](DEBUG): Uninitialize.
2025-01-14T06:39:36.030Z,1736836776.030 [PAM:PAM:Waits:B.Buoyancy] Stopped
2025-01-14T06:39:36.030Z,1736836776.030 [PAM:PAM:Waits:B.Buoyancy](DEBUG): Uninitialize Buoyancy Component.
2025-01-14T06:39:36.030Z,1736836776.030 [PAM:PAM:C] Running Loop=1
2025-01-14T06:39:36.438Z,1736836776.438 [PAM:PAM:C] Stopped
2025-01-14T06:39:36.438Z,1736836776.438 [PAM:PAM:ApproachDepthSettleAtDepth] Running Loop=1
2025-01-14T06:39:36.438Z,1736836776.438 [PAM:PAM:ApproachDepthSettleAtDepth](DEBUG): Aggregate::initialize PAM:PAM:ApproachDepthSettleAtDepth
2025-01-14T06:39:36.438Z,1736836776.438 [PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth] Running Loop=1
2025-01-14T06:39:36.438Z,1736836776.438 [PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth](DEBUG): Aggregate::initialize PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth
2025-01-14T06:39:36.438Z,1736836776.438 [PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth:ApproachDepthPropellerOn] Running Loop=1
2025-01-14T06:39:36.439Z,1736836776.439 [PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth:ApproachDepthPropellerOn](DEBUG): Aggregate::initialize PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth:ApproachDepthPropellerOn
2025-01-14T06:39:36.439Z,1736836776.439 [PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth:ApproachDepthPropellerOn:A.Mass] Running Loop=1
2025-01-14T06:39:36.439Z,1736836776.439 [PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth:ApproachDepthPropellerOn:A.Mass](DEBUG): Initialize.
2025-01-14T06:39:36.439Z,1736836776.439 [PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth:ApproachDepthPropellerOn:B.Buoyancy] Running Loop=1
2025-01-14T06:39:36.439Z,1736836776.439 [PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth:ApproachDepthPropellerOn:B.Buoyancy](DEBUG): Initialize Buoyancy Component.
2025-01-14T06:39:36.439Z,1736836776.439 [PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth:ApproachDepthPropellerOn:E.Point] Running Loop=1
2025-01-14T06:39:36.439Z,1736836776.439 [PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth:ApproachDepthPropellerOn:E.Point](DEBUG): Initialize.
2025-01-14T06:39:36.439Z,1736836776.439 [PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth:ApproachDepthPropellerOn:F.SetSpeed] Running Loop=1
2025-01-14T06:39:36.439Z,1736836776.439 [PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth:ApproachDepthPropellerOn:F.SetSpeed](DEBUG): Initialize.
2025-01-14T06:39:36.440Z,1736836776.440 [PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth:ApproachDepthPropellerOn:C] Running Loop=1
2025-01-14T06:39:36.836Z,1736836776.836 [PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth] Stopped
2025-01-14T06:39:36.836Z,1736836776.836 [PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth](DEBUG): Aggregate::uninitialize PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth
2025-01-14T06:39:36.836Z,1736836776.836 [PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth:ApproachDepthPropellerOn] Stopped
2025-01-14T06:39:36.836Z,1736836776.836 [PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth:ApproachDepthPropellerOn](DEBUG): Aggregate::uninitialize PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth:ApproachDepthPropellerOn
2025-01-14T06:39:36.837Z,1736836776.837 [PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth:ApproachDepthPropellerOn:A.Mass] Stopped
2025-01-14T06:39:36.837Z,1736836776.837 [PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth:ApproachDepthPropellerOn:A.Mass](DEBUG): Uninitialize.
2025-01-14T06:39:36.837Z,1736836776.837 [PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth:ApproachDepthPropellerOn:B.Buoyancy] Stopped
2025-01-14T06:39:36.837Z,1736836776.837 [PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth:ApproachDepthPropellerOn:B.Buoyancy](DEBUG): Uninitialize Buoyancy Component.
2025-01-14T06:39:36.837Z,1736836776.837 [PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth:ApproachDepthPropellerOn:C] Stopped
2025-01-14T06:39:36.837Z,1736836776.837 [PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth:ApproachDepthPropellerOn:E.Point] Stopped
2025-01-14T06:39:36.837Z,1736836776.837 [PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth:ApproachDepthPropellerOn:F.SetSpeed] Stopped
2025-01-14T06:39:36.837Z,1736836776.837 [PAM:PAM:ApproachDepthSettleAtDepth:ApproachDepth:ApproachDepthPropellerOn:F.SetSpeed](DEBUG): Uninitialize.
2025-01-14T06:39:36.837Z,1736836776.837 [PAM:PAM:ApproachDepthSettleAtDepth:Settle] Running Loop=1
2025-01-14T06:39:36.837Z,1736836776.837 [PAM:PAM:ApproachDepthSettleAtDepth:Settle](DEBUG): Aggregate::initialize PAM:PAM:ApproachDepthSettleAtDepth:Settle
2025-01-14T06:39:36.837Z,1736836776.837 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:A.Mass] Running Loop=1
2025-01-14T06:39:36.837Z,1736836776.837 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:A.Mass](DEBUG): Initialize.
2025-01-14T06:39:36.838Z,1736836776.838 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:B.Buoyancy] Running Loop=1
2025-01-14T06:39:36.838Z,1736836776.838 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:B.Buoyancy](DEBUG): Initialize Buoyancy Component.
2025-01-14T06:39:36.838Z,1736836776.838 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:VBSDepthLimit] Running Loop=1
2025-01-14T06:39:36.838Z,1736836776.838 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:VBSDepthLimit](DEBUG): Aggregate::initialize PAM:PAM:ApproachDepthSettleAtDepth:Settle:VBSDepthLimit
2025-01-14T06:39:36.838Z,1736836776.838 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:VBSDepthLimit:ShallowerThanVBSDepthLimit] Running Loop=1
2025-01-14T06:39:36.838Z,1736836776.838 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:VBSDepthLimit:ShallowerThanVBSDepthLimit](DEBUG): Aggregate::initialize PAM:PAM:ApproachDepthSettleAtDepth:Settle:VBSDepthLimit:ShallowerThanVBSDepthLimit
2025-01-14T06:39:36.838Z,1736836776.838 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:VBSDepthLimit:ShallowerThanVBSDepthLimit:A] Running Loop=1
2025-01-14T06:39:37.255Z,1736836777.255 [PAM:PAM:ApproachDepthSettleAtDepth:Settle] Stopped
2025-01-14T06:39:37.255Z,1736836777.255 [PAM:PAM:ApproachDepthSettleAtDepth:Settle](DEBUG): Aggregate::uninitialize PAM:PAM:ApproachDepthSettleAtDepth:Settle
2025-01-14T06:39:37.255Z,1736836777.255 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:A.Mass] Stopped
2025-01-14T06:39:37.255Z,1736836777.255 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:A.Mass](DEBUG): Uninitialize.
2025-01-14T06:39:37.255Z,1736836777.255 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:B.Buoyancy] Stopped
2025-01-14T06:39:37.255Z,1736836777.255 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:B.Buoyancy](DEBUG): Uninitialize Buoyancy Component.
2025-01-14T06:39:37.255Z,1736836777.255 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:VBSDepthLimit] Stopped
2025-01-14T06:39:37.256Z,1736836777.256 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:VBSDepthLimit](DEBUG): Aggregate::uninitialize PAM:PAM:ApproachDepthSettleAtDepth:Settle:VBSDepthLimit
2025-01-14T06:39:37.256Z,1736836777.256 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:VBSDepthLimit:ShallowerThanVBSDepthLimit] Stopped
2025-01-14T06:39:37.256Z,1736836777.256 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:VBSDepthLimit:ShallowerThanVBSDepthLimit](DEBUG): Aggregate::uninitialize PAM:PAM:ApproachDepthSettleAtDepth:Settle:VBSDepthLimit:ShallowerThanVBSDepthLimit
2025-01-14T06:39:37.256Z,1736836777.256 [PAM:PAM:ApproachDepthSettleAtDepth:Settle:VBSDepthLimit:ShallowerThanVBSDepthLimit:A] Stopped
2025-01-14T06:39:37.256Z,1736836777.256 [PAM:PAM:ApproachDepthSettleAtDepth:Hover] Running Loop=1
2025-01-14T06:39:37.256Z,1736836777.256 [PAM:PAM:ApproachDepthSettleAtDepth:Hover](DEBUG): Aggregate::initialize PAM:PAM:ApproachDepthSettleAtDepth:Hover
2025-01-14T06:39:37.256Z,1736836777.256 [PAM:PAM:ApproachDepthSettleAtDepth:Hover:A.Mass] Running Loop=1
2025-01-14T06:39:37.256Z,1736836777.256 [PAM:PAM:ApproachDepthSettleAtDepth:Hover:A.Mass](DEBUG): Initialize.
2025-01-14T06:39:37.256Z,1736836777.256 [PAM:PAM:ApproachDepthSettleAtDepth:Hover:B.Buoyancy] Running Loop=1
2025-01-14T06:39:37.257Z,1736836777.257 [PAM:PAM:ApproachDepthSettleAtDepth:Hover:B.Buoyancy](DEBUG): Initialize Buoyancy Component.
2025-01-14T06:39:37.257Z,1736836777.257 [PAM:PAM:ApproachDepthSettleAtDepth:Hover:C.Pitch] Running Loop=1
2025-01-14T06:39:37.257Z,1736836777.257 [PAM:PAM:ApproachDepthSettleAtDepth:Hover:C.Pitch](DEBUG): Initialize.
2025-01-14T06:39:37.257Z,1736836777.257 [PAM:PAM:ApproachDepthSettleAtDepth:Hover:D.Point] Running Loop=1
2025-01-14T06:39:37.257Z,1736836777.257 [PAM:PAM:ApproachDepthSettleAtDepth:Hover:D.Point](DEBUG): Initialize.
2025-01-14T06:39:37.257Z,1736836777.257 [PAM:PAM:ApproachDepthSettleAtDepth:Hover:E.SetSpeed] Running Loop=1
2025-01-14T06:39:37.257Z,1736836777.257 [PAM:PAM:ApproachDepthSettleAtDepth:Hover:E.SetSpeed](DEBUG): Initialize.
2025-01-14T06:39:37.257Z,1736836777.257 [PAM:PAM:ApproachDepthSettleAtDepth:Hover:F.Wait] Running Loop=1
2025-01-14T06:39:37.257Z,1736836777.257 [PAM:PAM:ApproachDepthSettleAtDepth:Hover:F.Wait](DEBUG): Initialize Wait Component.
2025-01-14T06:39:37.686Z,1736836777.686 [PAM:PAM:ApproachDepthSettleAtDepth:Hover] Stopped
2025-01-14T06:39:37.686Z,1736836777.686 [PAM:PAM:ApproachDepthSettleAtDepth:Hover](DEBUG): Aggregate::uninitialize PAM:PAM:ApproachDepthSettleAtDepth:Hover
2025-01-14T06:39:37.686Z,1736836777.686 [PAM:PAM:ApproachDepthSettleAtDepth:Hover:A.Mass] Stopped
2025-01-14T06:39:37.687Z,1736836777.687 [PAM:PAM:ApproachDepthSettleAtDepth:Hover:A.Mass](DEBUG): Uninitialize.
2025-01-14T06:39:37.687Z,1736836777.687 [PAM:PAM:ApproachDepthSettleAtDepth:Hover:B.Buoyancy] Stopped
2025-01-14T06:39:37.687Z,1736836777.687 [PAM:PAM:ApproachDepthSettleAtDepth:Hover:B.Buoyancy](DEBUG): Uninitialize Buoyancy Component.
2025-01-14T06:39:37.687Z,1736836777.687 [PAM:PAM:ApproachDepthSettleAtDepth:Hover:C.Pitch] Stopped
2025-01-14T06:39:37.687Z,1736836777.687 [PAM:PAM:ApproachDepthSettleAtDepth:Hover:D.Point] Stopped
2025-01-14T06:39:37.687Z,1736836777.687 [PAM:PAM:ApproachDepthSettleAtDepth:Hover:E.SetSpeed] Stopped
2025-01-14T06:39:37.687Z,1736836777.687 [PAM:PAM:ApproachDepthSettleAtDepth:Hover:E.SetSpeed](DEBUG): Uninitialize.
2025-01-14T06:39:37.687Z,1736836777.687 [PAM:PAM:ApproachDepthSettleAtDepth:Hover:F.Wait] Stopped
2025-01-14T06:39:37.687Z,1736836777.687 [PAM:PAM:ApproachDepthSettleAtDepth:Hover:F.Wait](DEBUG): Uninitialize Wait Component.
2025-01-14T06:39:37.689Z,1736836777.689 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound] Running Loop=1
2025-01-14T06:39:37.689Z,1736836777.689 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound](DEBUG): Aggregate::initialize PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound
2025-01-14T06:39:37.689Z,1736836777.689 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:A.Mass] Running Loop=1
2025-01-14T06:39:37.689Z,1736836777.689 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:A.Mass](DEBUG): Initialize.
2025-01-14T06:39:37.689Z,1736836777.689 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:B.Buoyancy] Running Loop=1
2025-01-14T06:39:37.689Z,1736836777.689 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:B.Buoyancy](DEBUG): Initialize Buoyancy Component.
2025-01-14T06:39:37.690Z,1736836777.690 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:C] Running Loop=1
2025-01-14T06:39:38.078Z,1736836778.078 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:C] Stopped
2025-01-14T06:39:38.078Z,1736836778.078 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:D] Running Loop=1
2025-01-14T06:39:38.464Z,1736836778.464 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:D] Stopped
2025-01-14T06:39:38.464Z,1736836778.464 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:E] Running Loop=1
2025-01-14T06:39:38.872Z,1736836778.872 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:E] Stopped
2025-01-14T06:39:38.872Z,1736836778.872 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:F] Running Loop=1
2025-01-14T06:39:39.281Z,1736836779.281 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:F](IMPORTANT): Now depth  56.913174 m  is deeper than DeepBound  50.000000 m .
2025-01-14T06:39:39.281Z,1736836779.281 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:F] Stopped
2025-01-14T06:39:39.281Z,1736836779.281 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:IncreaseNeutralBuoyancy] Running Loop=1
2025-01-14T06:39:39.281Z,1736836779.281 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:IncreaseNeutralBuoyancy](DEBUG): Aggregate::initialize PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:IncreaseNeutralBuoyancy
2025-01-14T06:39:39.281Z,1736836779.281 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:IncreaseNeutralBuoyancy:IncreaseNeutralBuoyancyDecreaseDelta] Running Loop=1
2025-01-14T06:39:39.281Z,1736836779.281 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:IncreaseNeutralBuoyancy:IncreaseNeutralBuoyancyDecreaseDelta](DEBUG): Aggregate::initialize PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:IncreaseNeutralBuoyancy:IncreaseNeutralBuoyancyDecreaseDelta
2025-01-14T06:39:39.281Z,1736836779.281 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:IncreaseNeutralBuoyancy:IncreaseNeutralBuoyancyDecreaseDelta:A] Running Loop=1
2025-01-14T06:39:39.731Z,1736836779.731 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:IncreaseNeutralBuoyancy:IncreaseNeutralBuoyancyDecreaseDelta] Stopped
2025-01-14T06:39:39.736Z,1736836779.736 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:IncreaseNeutralBuoyancy:IncreaseNeutralBuoyancyDecreaseDelta](DEBUG): Aggregate::uninitialize PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:IncreaseNeutralBuoyancy:IncreaseNeutralBuoyancyDecreaseDelta
2025-01-14T06:39:39.736Z,1736836779.736 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:IncreaseNeutralBuoyancy:IncreaseNeutralBuoyancyDecreaseDelta:A] Stopped
2025-01-14T06:39:39.736Z,1736836779.736 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:IncreaseNeutralBuoyancy:IncreaseNeutralBuoyancyDoNotChangeDelta] Running Loop=1
2025-01-14T06:39:39.736Z,1736836779.736 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:IncreaseNeutralBuoyancy:IncreaseNeutralBuoyancyDoNotChangeDelta](DEBUG): Aggregate::initialize PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:IncreaseNeutralBuoyancy:IncreaseNeutralBuoyancyDoNotChangeDelta
2025-01-14T06:39:39.736Z,1736836779.736 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:IncreaseNeutralBuoyancy:IncreaseNeutralBuoyancyDoNotChangeDelta:A] Running Loop=1
2025-01-14T06:39:40.070Z,1736836780.070 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:IncreaseNeutralBuoyancy:IncreaseNeutralBuoyancyDoNotChangeDelta:A] Stopped
2025-01-14T06:39:40.070Z,1736836780.070 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:IncreaseNeutralBuoyancy:IncreaseNeutralBuoyancyDoNotChangeDelta:B] Running Loop=1
2025-01-14T06:39:40.479Z,1736836780.479 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:IncreaseNeutralBuoyancy:IncreaseNeutralBuoyancyDoNotChangeDelta:B] Stopped
2025-01-14T06:39:40.480Z,1736836780.480 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:IncreaseNeutralBuoyancy:IncreaseNeutralBuoyancyDoNotChangeDelta:C] Running Loop=1
2025-01-14T06:39:40.889Z,1736836780.889 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:IncreaseNeutralBuoyancy:IncreaseNeutralBuoyancyDoNotChangeDelta:C] Stopped
2025-01-14T06:39:40.889Z,1736836780.889 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:IncreaseNeutralBuoyancy:IncreaseNeutralBuoyancyDoNotChangeDelta:D] Running Loop=1
2025-01-14T06:39:41.279Z,1736836781.279 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:IncreaseNeutralBuoyancy:IncreaseNeutralBuoyancyDoNotChangeDelta:D] Stopped
2025-01-14T06:39:41.279Z,1736836781.279 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:IncreaseNeutralBuoyancy:IncreaseNeutralBuoyancyDoNotChangeDelta:E] Running Loop=1
2025-01-14T06:39:41.761Z,1736836781.761 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:IncreaseNeutralBuoyancy:IncreaseNeutralBuoyancyDoNotChangeDelta:E](IMPORTANT): Vehicle is too heavy. Increase neutral buoyancy:  417.869363 cc  +  16.000000 cc  =  433.869354 cc . Move mass backwards:  21.277966 mm  -  0.528000 mm  =  20.749966 mm . FineTune =  0 bool . WaitAfterBuoyancyChange =  5.000000 min .
2025-01-14T06:39:41.761Z,1736836781.761 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:IncreaseNeutralBuoyancy:IncreaseNeutralBuoyancyDoNotChangeDelta:E] Stopped
2025-01-14T06:39:41.761Z,1736836781.761 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:IncreaseNeutralBuoyancy:IncreaseNeutralBuoyancyDoNotChangeDelta:F] Running Loop=1
2025-01-14T06:39:42.116Z,1736836782.116 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:IncreaseNeutralBuoyancy:IncreaseNeutralBuoyancyDoNotChangeDelta:F] Stopped
2025-01-14T06:39:42.116Z,1736836782.116 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:IncreaseNeutralBuoyancy:IncreaseNeutralBuoyancyDoNotChangeDelta:G] Running Loop=1
2025-01-14T06:39:42.515Z,1736836782.515 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:IncreaseNeutralBuoyancy:IncreaseNeutralBuoyancyDoNotChangeDelta:G] Stopped
2025-01-14T06:39:42.516Z,1736836782.516 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:IncreaseNeutralBuoyancy:IncreaseNeutralBuoyancyDoNotChangeDelta:H] Running Loop=1
2025-01-14T06:39:42.927Z,1736836782.927 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:IncreaseNeutralBuoyancy:IncreaseNeutralBuoyancyDoNotChangeDelta:H] Stopped
2025-01-14T06:39:42.928Z,1736836782.928 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:IncreaseNeutralBuoyancy:IncreaseNeutralBuoyancyDoNotChangeDelta](INFO): Completed PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:IncreaseNeutralBuoyancy:IncreaseNeutralBuoyancyDoNotChangeDelta
2025-01-14T06:39:42.928Z,1736836782.928 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:IncreaseNeutralBuoyancy:IncreaseNeutralBuoyancyDoNotChangeDelta] Stopped
2025-01-14T06:39:42.928Z,1736836782.928 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:IncreaseNeutralBuoyancy:IncreaseNeutralBuoyancyDoNotChangeDelta](DEBUG): Aggregate::uninitialize PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:IncreaseNeutralBuoyancy:IncreaseNeutralBuoyancyDoNotChangeDelta
2025-01-14T06:39:42.928Z,1736836782.928 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:IncreaseNeutralBuoyancy](INFO): Completed PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:IncreaseNeutralBuoyancy
2025-01-14T06:39:42.928Z,1736836782.928 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:IncreaseNeutralBuoyancy] Stopped
2025-01-14T06:39:42.928Z,1736836782.928 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:IncreaseNeutralBuoyancy](DEBUG): Aggregate::uninitialize PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:IncreaseNeutralBuoyancy
2025-01-14T06:39:42.928Z,1736836782.928 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:I] Running Loop=1
2025-01-14T06:39:43.303Z,1736836783.303 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:I] Stopped
2025-01-14T06:39:43.303Z,1736836783.303 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:TurnOnFineTuneModeDeeperThanDeepBound] Running Loop=1
2025-01-14T06:39:43.303Z,1736836783.303 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:TurnOnFineTuneModeDeeperThanDeepBound](DEBUG): Aggregate::initialize PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:TurnOnFineTuneModeDeeperThanDeepBound
2025-01-14T06:39:43.745Z,1736836783.745 [PAM:TurnOnFineTuneMode] Running Loop=1
2025-01-14T06:39:43.745Z,1736836783.745 [PAM:TurnOnFineTuneMode](DEBUG): Aggregate::initialize PAM:TurnOnFineTuneMode
2025-01-14T06:39:43.745Z,1736836783.745 [PAM:TurnOnFineTuneMode:FineTune] Running Loop=1
2025-01-14T06:39:43.746Z,1736836783.746 [PAM:TurnOnFineTuneMode:FineTune](DEBUG): Aggregate::initialize PAM:TurnOnFineTuneMode:FineTune
2025-01-14T06:39:43.746Z,1736836783.746 [PAM:TurnOnFineTuneMode:FineTune:A] Running Loop=1
2025-01-14T06:39:43.746Z,1736836783.746 [PAM:TurnOnFineTuneMode:FineTune] Stopped
2025-01-14T06:39:43.746Z,1736836783.746 [PAM:TurnOnFineTuneMode:FineTune](DEBUG): Aggregate::uninitialize PAM:TurnOnFineTuneMode:FineTune
2025-01-14T06:39:43.746Z,1736836783.746 [PAM:TurnOnFineTuneMode:FineTune:A] Stopped
2025-01-14T06:39:43.746Z,1736836783.746 [PAM:TurnOnFineTuneMode](INFO): Completed PAM:TurnOnFineTuneMode
2025-01-14T06:39:43.746Z,1736836783.746 [PAM:TurnOnFineTuneMode] Stopped
2025-01-14T06:39:43.747Z,1736836783.747 [PAM:TurnOnFineTuneMode](DEBUG): Aggregate::uninitialize PAM:TurnOnFineTuneMode
2025-01-14T06:39:44.106Z,1736836784.106 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:TurnOnFineTuneModeDeeperThanDeepBound](INFO): Completed PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:TurnOnFineTuneModeDeeperThanDeepBound
2025-01-14T06:39:44.106Z,1736836784.106 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:TurnOnFineTuneModeDeeperThanDeepBound] Stopped
2025-01-14T06:39:44.107Z,1736836784.107 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:TurnOnFineTuneModeDeeperThanDeepBound](DEBUG): Aggregate::uninitialize PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:TurnOnFineTuneModeDeeperThanDeepBound
2025-01-14T06:39:44.107Z,1736836784.107 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound](INFO): Completed PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound
2025-01-14T06:39:44.107Z,1736836784.107 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound] Stopped
2025-01-14T06:39:44.110Z,1736836784.110 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound](DEBUG): Aggregate::uninitialize PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound
2025-01-14T06:39:44.110Z,1736836784.110 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:A.Mass] Stopped
2025-01-14T06:39:44.110Z,1736836784.110 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:A.Mass](DEBUG): Uninitialize.
2025-01-14T06:39:44.110Z,1736836784.110 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:B.Buoyancy] Stopped
2025-01-14T06:39:44.110Z,1736836784.110 [PAM:PAM:ApproachDepthSettleAtDepth:DeeperThanDeepBound:B.Buoyancy](DEBUG): Uninitialize Buoyancy Component.
2025-01-14T06:39:44.110Z,1736836784.110 [PAM:PAM:ApproachDepthSettleAtDepth:ShallowerThanShallowBound] Running Loop=1
2025-01-14T06:39:44.110Z,1736836784.110 [PAM:PAM:ApproachDepthSettleAtDepth:ShallowerThanShallowBound](DEBUG): Aggregate::initialize PAM:PAM:ApproachDepthSettleAtDepth:ShallowerThanShallowBound
2025-01-14T06:39:44.110Z,1736836784.110 [PAM:PAM:ApproachDepthSettleAtDepth:ShallowerThanShallowBound:A.Mass] Running Loop=1
2025-01-14T06:39:44.110Z,1736836784.110 [PAM:PAM:ApproachDepthSettleAtDepth:ShallowerThanShallowBound:A.Mass](DEBUG): Initialize.
2025-01-14T06:39:44.110Z,1736836784.110 [PAM:PAM:ApproachDepthSettleAtDepth:ShallowerThanShallowBound:B.Buoyancy] Running Loop=1
2025-01-14T06:39:44.110Z,1736836784.110 [PAM:PAM:ApproachDepthSettleAtDepth:ShallowerThanShallowBound:B.Buoyancy](DEBUG): Initialize Buoyancy Component.
2025-01-14T06:39:44.111Z,1736836784.111 [PAM:PAM:ApproachDepthSettleAtDepth:ShallowerThanShallowBound:C] Running Loop=1
2025-01-14T06:39:44.510Z,1736836784.510 [PAM:PAM:ApproachDepthSettleAtDepth:ShallowerThanShallowBound] Stopped
2025-01-14T06:39:44.511Z,1736836784.511 [PAM:PAM:ApproachDepthSettleAtDepth:ShallowerThanShallowBound](DEBUG): Aggregate::uninitialize PAM:PAM:ApproachDepthSettleAtDepth:ShallowerThanShallowBound
2025-01-14T06:39:44.511Z,1736836784.511 [PAM:PAM:ApproachDepthSettleAtDepth:ShallowerThanShallowBound:A.Mass] Stopped
2025-01-14T06:39:44.511Z,1736836784.511 [PAM:PAM:ApproachDepthSettleAtDepth:ShallowerThanShallowBound:A.Mass](DEBUG): Uninitialize.
2025-01-14T06:39:44.511Z,1736836784.511 [PAM:PAM:ApproachDepthSettleAtDepth:ShallowerThanShallowBound:B.Buoyancy] Stopped
2025-01-14T06:39:44.511Z,1736836784.511 [PAM:PAM:ApproachDepthSettleAtDepth:ShallowerThanShallowBound:B.Buoyancy](DEBUG): Uninitialize Buoyancy Component.
2025-01-14T06:39:44.511Z,1736836784.511 [PAM:PAM:ApproachDepthSettleAtDepth:ShallowerThanShallowBound:C] Stopped
2025-01-14T06:39:44.511Z,1736836784.511 [PAM:PAM:ApproachDepthSettleAtDepth](INFO): Completed PAM:PAM:ApproachDepthSettleAtDepth
2025-01-14T06:39:44.511Z,1736836784.511 [PAM:PAM:ApproachDepthSettleAtDepth] Stopped
2025-01-14T06:39:44.511Z,1736836784.511 [PAM:PAM:ApproachDepthSettleAtDepth](DEBUG): Aggregate::uninitialize PAM:PAM:ApproachDepthSettleAtDepth
2025-01-14T06:39:44.512Z,1736836784.512 [PAM:PAM](INFO): Completed PAM:PAM
2025-01-14T06:39:44.512Z,1736836784.512 [PAM:PAM] Stopped
2025-01-14T06:39:44.512Z,1736836784.512 [PAM:PAM](DEBUG): Aggregate::uninitialize PAM:PAM
2025-01-14T06:39:44.512Z,1736836784.512 [PAM:PAM](INFO): Running loop #3
2025-01-14T06:39:44.512Z,1736836784.512 [PAM:PAM] Running Loop=3
2025-01-14T06:39:44.513Z,1736836784.513 [PAM:PAM](DEBUG): Aggregate::initialize PAM:PAM
2025-01-14T06:39:44.513Z,1736836784.513 [PAM:PAM:SettingVariables] Running Loop=1
2025-01-14T06:39:44.513Z,1736836784.513 [PAM:PAM:SettingVariables](DEBUG): Aggregate::initialize PAM:PAM:SettingVariables
2025-01-14T06:39:44.513Z,1736836784.513 [PAM:PAM:SettingVariables:A.Mass] Running Loop=1
2025-01-14T06:39:44.513Z,1736836784.513 [PAM:PAM:SettingVariables:A.Mass](DEBUG): Initialize.
2025-01-14T06:39:44.513Z,1736836784.513 [PAM:PAM:SettingVariables:B.Buoyancy] Running Loop=1
2025-01-14T06:39:44.513Z,1736836784.513 [PAM:PAM:SettingVariables:B.Buoyancy](DEBUG): Initialize Buoyancy Component.
2025-01-14T06:39:44.513Z,1736836784.513 [PAM:PAM:SettingVariables:C] Running Loop=1
2025-01-14T06:39:44.927Z,1736836784.927 [PAM:PAM:SettingVariables:C] Stopped
2025-01-14T06:39:44.927Z,1736836784.927 [PAM:PAM:SettingVariables:D] Running Loop=1
2025-01-14T06:39:45.344Z,1736836785.344 [PAM:PAM:SettingVariables:D] Stopped
2025-01-14T06:39:45.344Z,1736836785.344 [PAM:PAM:SettingVariables:E] Running Loop=1
2025-01-14T06:39:45.764Z,1736836785.764 [PAM:PAM:SettingVariables:E] Stopped
2025-01-14T06:39:45.764Z,1736836785.764 [PAM:PAM:SettingVariables:F] Running Loop=1
2025-01-14T06:39:46.130Z,1736836786.130 [PAM:PAM:SettingVariables:F](IMPORTANT): Cnt =  3.000000 count 
2025-01-14T06:39:46.130Z,1736836786.130 [PAM:PAM:SettingVariables:F] Stopped
2025-01-14T06:39:46.131Z,1736836786.131 [PAM:PAM:SettingVariables:G] Running Loop=1
2025-01-14T06:39:46.544Z,1736836786.544 [PAM:PAM:SettingVariables:G](IMPORTANT): NeutralBuoyancy =  433.869354 cc , BuoyancyAdjustmentStep =  16.000000 cc , MassPosition =  20.749966 mm , MassPositionAdjustmentStep =  0.528000 mm 
2025-01-14T06:39:46.544Z,1736836786.544 [PAM:PAM:SettingVariables:G] Stopped
2025-01-14T06:39:46.544Z,1736836786.544 [PAM:PAM:SettingVariables:H] Running Loop=1
2025-01-14T06:39:46.934Z,1736836786.934 [PAM:PAM:SettingVariables:H] Stopped
2025-01-14T06:39:46.934Z,1736836786.934 [PAM:PAM:SettingVariables:I] Running Loop=1
2025-01-14T06:39:47.338Z,1736836787.338 [PAM:PAM:SettingVariables:I] Stopped
2025-01-14T06:39:47.339Z,1736836787.339 [PAM:PAM:SettingVariables](INFO): Completed PAM:PAM:SettingVariables
2025-01-14T06:39:47.339Z,1736836787.339 [PAM:PAM:SettingVariables] Stopped
2025-01-14T06:39:47.339Z,1736836787.339 [PAM:PAM:SettingVariables](DEBUG): Aggregate::uninitialize PAM:PAM:SettingVariables
2025-01-14T06:39:47.339Z,1736836787.339 [PAM:PAM:SettingVariables:A.Mass] Stopped
2025-01-14T06:39:47.339Z,1736836787.339 [PAM:PAM:SettingVariables:A.Mass](DEBUG): Uninitialize.
2025-01-14T06:39:47.339Z,1736836787.339 [PAM:PAM:SettingVariables:B.Buoyancy] Stopped
2025-01-14T06:39:47.339Z,1736836787.339 [PAM:PAM:SettingVariables:B.Buoyancy](DEBUG): Uninitialize Buoyancy Component.
2025-01-14T06:39:47.340Z,1736836787.340 [PAM:PAM:Waits] Running Loop=1
2025-01-14T06:39:47.340Z,1736836787.340 [PAM:PAM:Waits](DEBUG): Aggregate::initialize PAM:PAM:Waits
2025-01-14T06:39:47.340Z,1736836787.340 [PAM:PAM:Waits:A.Mass] Running Loop=1
2025-01-14T06:39:47.340Z,1736836787.340 [PAM:PAM:Waits:A.Mass](DEBUG): Initialize.
2025-01-14T06:39:47.340Z,1736836787.340 [PAM:PAM:Waits:B.Buoyancy] Running Loop=1
2025-01-14T06:39:47.340Z,1736836787.340 [PAM:PAM:Waits:B.Buoyancy](DEBUG): Initialize Buoyancy Component.
2025-01-14T06:39:47.340Z,1736836787.340 [PAM:PAM:Waits:WaitForSurfaceCommsCompletion] Running Loop=1
2025-01-14T06:39:47.340Z,1736836787.340 [PAM:PAM:Waits:WaitForSurfaceCommsCompletion](DEBUG): Aggregate::initialize PAM:PAM:Waits:WaitForSurfaceCommsCompletion
2025-01-14T06:39:47.341Z,1736836787.341 [PAM:PAM:Waits:WaitForSurfaceCommsCompletion:A.Wait] Running Loop=1
2025-01-14T06:39:47.341Z,1736836787.341 [PAM:PAM:Waits:WaitForSurfaceCommsCompletion:A.Wait](DEBUG): Initialize Wait Component.
2025-01-14T06:39:47.813Z,1736836787.813 [PAM:PAM:Waits:WaitForSurfaceCommsCompletion] Stopped
2025-01-14T06:39:47.813Z,1736836787.813 [PAM:PAM:Waits:WaitForSurfaceCommsCompletion](DEBUG): Aggregate::uninitialize PAM:PAM:Waits:WaitForSurfaceCommsCompletion
2025-01-14T06:39:47.813Z,1736836787.813 [PAM:PAM:Waits:WaitForSurfaceCommsCompletion:A.Wait] Stopped
2025-01-14T06:39:47.813Z,1736836787.813 [PAM:PAM:Waits:WaitForSurfaceCommsCompletion:A.Wait](DEBUG): Uninitialize Wait Component.
2025-01-14T06:39:47.813Z,1736836787.813 [PAM:PAM:Waits:WaitBuoyancyChange] Running Loop=1
2025-01-14T06:39:47.813Z,1736836787.813 [PAM:PAM:Waits:WaitBuoyancyChange](DEBUG): Aggregate::initialize PAM:PAM:Waits:WaitBuoyancyChange
2025-01-14T06:39:47.813Z,1736836787.813 [PAM:PAM:Waits:WaitBuoyancyChange:A] Running Loop=1
2025-01-14T06:39:48.164Z,1736836788.164 [PAM:PAM:Waits:WaitBuoyancyChange:A](IMPORTANT): After buoyancy change, wait for  5.000000 min 
2025-01-14T06:39:48.165Z,1736836788.165 [PAM:PAM:Waits:WaitBuoyancyChange:A] Stopped
2025-01-14T06:39:48.165Z,1736836788.165 [PAM:PAM:Waits:WaitBuoyancyChange:B.Wait] Running Loop=1
2025-01-14T06:39:48.165Z,1736836788.165 [PAM:PAM:Waits:WaitBuoyancyChange:B.Wait](DEBUG): Initialize Wait Component.
2025-01-14T06:39:49.100Z,1736836789.100 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-14T06:39:50.104Z,1736836790.104 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-01-14T06:40:20.224Z,1736836820.224 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-14T06:40:21.230Z,1736836821.230 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-01-14T06:40:51.352Z,1736836851.352 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-14T06:40:52.356Z,1736836852.356 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-01-14T06:41:22.478Z,1736836882.478 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-14T06:41:23.480Z,1736836883.480 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-01-14T06:41:53.600Z,1736836913.600 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-14T06:41:54.604Z,1736836914.604 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-01-14T06:42:24.732Z,1736836944.732 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-14T06:42:25.736Z,1736836945.736 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-01-14T06:42:55.856Z,1736836975.856 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-14T06:42:56.860Z,1736836976.860 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-01-14T06:43:26.980Z,1736837006.980 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-14T06:43:27.996Z,1736837007.996 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-01-14T06:43:58.124Z,1736837038.124 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-14T06:43:59.129Z,1736837039.129 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-01-14T06:44:01.073Z,1736837041.073 [PAM](INFO): Timed out from 2025-01-14T06:14:00.8Z
2025-01-14T06:44:01.073Z,1736837041.073 [MissionManager](INFO): PAM is completed.
2025-01-14T06:44:01.073Z,1736837041.073 [MissionManager](INFO): Uninitializing Mission PAM
2025-01-14T06:44:01.073Z,1736837041.073 [PAM] Stopped
2025-01-14T06:44:01.073Z,1736837041.073 [PAM](DEBUG): Aggregate::uninitialize PAM
2025-01-14T06:44:01.073Z,1736837041.073 [PAM:Science] Stopped
2025-01-14T06:44:01.073Z,1736837041.073 [PAM:Science](DEBUG): Aggregate::uninitialize PAM:Science
2025-01-14T06:44:01.073Z,1736837041.073 [PAM:Science:B] Stopped
2025-01-14T06:44:01.073Z,1736837041.073 [PAM:Science:C] Stopped
2025-01-14T06:44:01.074Z,1736837041.074 [PAM:Science:E] Stopped
2025-01-14T06:44:01.074Z,1736837041.074 [PAM:Science:F] Stopped
2025-01-14T06:44:01.074Z,1736837041.074 [PAM:Science:OceanCurrent] Stopped
2025-01-14T06:44:01.074Z,1736837041.074 [PAM:Science:OceanCurrent](DEBUG): Aggregate::uninitialize PAM:Science:OceanCurrent
2025-01-14T06:44:01.074Z,1736837041.074 [PAM:Science:OceanCurrent:A.] Stopped
2025-01-14T06:44:01.074Z,1736837041.074 [PAM:StandardEnvelopes] Stopped
2025-01-14T06:44:01.074Z,1736837041.074 [PAM:StandardEnvelopes](DEBUG): Aggregate::uninitialize PAM:StandardEnvelopes
2025-01-14T06:44:01.074Z,1736837041.074 [PAM:StandardEnvelopes:A.AltitudeEnvelope] Stopped
2025-01-14T06:44:01.074Z,1736837041.074 [PAM:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent.
2025-01-14T06:44:01.074Z,1736837041.074 [PAM:StandardEnvelopes:B.DepthEnvelope] Stopped
2025-01-14T06:44:01.074Z,1736837041.074 [PAM:StandardEnvelopes:B.DepthEnvelope](DEBUG): Uninitialize.
2025-01-14T06:44:01.074Z,1736837041.074 [PAM:StandardEnvelopes:C.OffshoreEnvelope] Stopped
2025-01-14T06:44:01.074Z,1736837041.074 [PAM:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Uninitialize OffshoreEnvelopeComponent.
2025-01-14T06:44:01.074Z,1736837041.074 [PAM:AbortDrift] Stopped
2025-01-14T06:44:01.075Z,1736837041.075 [PAM:AbortDrift](DEBUG): Aggregate::uninitialize PAM:AbortDrift
2025-01-14T06:44:01.075Z,1736837041.075 [PAM:AbortDrift:B.AbortDrift] Stopped
2025-01-14T06:44:01.075Z,1736837041.075 [PAM:AbortDrift:B.AbortDrift](INFO): Uninitializing AbortDrift.
2025-01-14T06:44:01.075Z,1736837041.075 [PAM:BackseatDriver] Stopped
2025-01-14T06:44:01.075Z,1736837041.075 [PAM:BackseatDriver](DEBUG): Aggregate::uninitialize PAM:BackseatDriver
2025-01-14T06:44:01.075Z,1736837041.075 [PAM:BackseatDriver:A.BackseatDriver] Stopped
2025-01-14T06:44:01.075Z,1736837041.075 [PAM:K] Stopped
2025-01-14T06:44:01.075Z,1736837041.075 [PAM:L] Stopped
2025-01-14T06:44:01.075Z,1736837041.075 [PAM:M] Stopped
2025-01-14T06:44:01.075Z,1736837041.075 [PAM:N] Stopped
2025-01-14T06:44:01.075Z,1736837041.075 [PAM:PAM] Stopped
2025-01-14T06:44:01.076Z,1736837041.076 [PAM:PAM](DEBUG): Aggregate::uninitialize PAM:PAM
2025-01-14T06:44:01.076Z,1736837041.076 [PAM:PAM:Waits] Stopped
2025-01-14T06:44:01.076Z,1736837041.076 [PAM:PAM:Waits](DEBUG): Aggregate::uninitialize PAM:PAM:Waits
2025-01-14T06:44:01.076Z,1736837041.076 [PAM:PAM:Waits:A.Mass] Stopped
2025-01-14T06:44:01.076Z,1736837041.076 [PAM:PAM:Waits:A.Mass](DEBUG): Uninitialize.
2025-01-14T06:44:01.076Z,1736837041.076 [PAM:PAM:Waits:B.Buoyancy] Stopped
2025-01-14T06:44:01.076Z,1736837041.076 [PAM:PAM:Waits:B.Buoyancy](DEBUG): Uninitialize Buoyancy Component.
2025-01-14T06:44:01.076Z,1736837041.076 [PAM:PAM:Waits:WaitBuoyancyChange] Stopped
2025-01-14T06:44:01.076Z,1736837041.076 [PAM:PAM:Waits:WaitBuoyancyChange](DEBUG): Aggregate::uninitialize PAM:PAM:Waits:WaitBuoyancyChange
2025-01-14T06:44:01.076Z,1736837041.076 [PAM:PAM:Waits:WaitBuoyancyChange:B.Wait] Stopped
2025-01-14T06:44:01.076Z,1736837041.076 [PAM:PAM:Waits:WaitBuoyancyChange:B.Wait](DEBUG): Uninitialize Wait Component.
2025-01-14T06:44:01.440Z,1736837041.440 [WetLabsBB2FL](INFO): Powering down
2025-01-14T06:44:01.466Z,1736837041.466 [MissionManager](IMPORTANT): Started mission DefaultWithUndock
2025-01-14T06:44:01.467Z,1736837041.467 [DefaultWithUndock] Running Loop=1
2025-01-14T06:44:01.467Z,1736837041.467 [DefaultWithUndock](DEBUG): Aggregate::initialize DefaultWithUndock
2025-01-14T06:44:01.467Z,1736837041.467 [DefaultWithUndock:A.Wait] Running Loop=1
2025-01-14T06:44:01.467Z,1736837041.467 [DefaultWithUndock:A.Wait](DEBUG): Initialize Wait Component.
2025-01-14T06:44:01.564Z,1736837041.564 [WetLabsUBAT](INFO): Powering down
2025-01-14T06:44:07.937Z,1736837047.937 [RDI_Pathfinder](ERROR): only read 2 of 4 data items for bottom velocity. Device response is::BS,   00,    +6,A
2025-01-14T06:44:29.252Z,1736837069.252 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-14T06:44:30.256Z,1736837070.256 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-01-14T06:44:31.782Z,1736837071.782 [DefaultWithUndock:A.Wait](INFO): Done Waiting.
2025-01-14T06:44:31.783Z,1736837071.783 [DefaultWithUndock:A.Wait] Stopped
2025-01-14T06:44:31.783Z,1736837071.783 [DefaultWithUndock:A.Wait](DEBUG): Uninitialize Wait Component.
2025-01-14T06:44:31.783Z,1736837071.783 [DefaultWithUndock:LeaveDock] Running Loop=1
2025-01-14T06:44:31.783Z,1736837071.783 [DefaultWithUndock:LeaveDock](DEBUG): Aggregate::initialize DefaultWithUndock:LeaveDock
2025-01-14T06:44:31.783Z,1736837071.783 [DefaultWithUndock:LeaveDock:A.] Running Loop=1
2025-01-14T06:44:31.783Z,1736837071.783 [DefaultWithUndock:LeaveDock:A.](INFO): Initializing TrackAcousticContact.
2025-01-14T06:44:31.783Z,1736837071.783 [DefaultWithUndock:LeaveDock:B.Undock] Running Loop=1
2025-01-14T06:44:31.783Z,1736837071.783 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Initialize.
2025-01-14T06:44:31.784Z,1736837071.784 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Initializing internal variables to default values.
2025-01-14T06:44:32.184Z,1736837072.184 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Initialize.
2025-01-14T06:44:32.184Z,1736837072.184 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Initializing internal variables to default values.
2025-01-14T06:44:32.185Z,1736837072.185 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Detached from dock at depth 59.920689 m.
2025-01-14T06:44:32.342Z,1736837072.342 [DockingStepper](INFO): Resume
2025-01-14T06:44:32.608Z,1736837072.608 [DockingStepper](INFO): Resuming
2025-01-14T06:44:32.986Z,1736837072.986 [DockingStepper](INFO): Start
2025-01-14T06:44:32.986Z,1736837072.986 [DockingStepper](DEBUG): Initializing EZServoServo.
2025-01-14T06:44:33.101Z,1736837073.101 [DockingStepper](DEBUG): Initializing DockingStepper.
2025-01-14T06:44:33.400Z,1736837073.400 [DockingStepper](INFO): Starting
2025-01-14T06:44:33.892Z,1736837073.892 [DockingStepper](INFO): Starting
2025-01-14T06:44:34.190Z,1736837074.190 [DockingStepper](INFO): Starting
2025-01-14T06:44:34.241Z,1736837074.241 [DockingStepper](INFO): Init string: /1z16367aE13561N3m50
2025-01-14T06:44:34.598Z,1736837074.598 [DockingStepper](INFO): Starting
2025-01-14T06:44:34.949Z,1736837074.949 [CTD_Seabird](ERROR): Failed to parse device response: <!--startlogging-->
2025-01-14T06:44:35.009Z,1736837075.009 [DockingStepper](INFO): Starting
2025-01-14T06:44:35.424Z,1736837075.424 [DockingStepper](INFO): Starting
2025-01-14T06:44:35.849Z,1736837075.849 [DockingStepper](INFO): Starting
2025-01-14T06:44:35.892Z,1736837075.892 [DockingStepper](INFO): Sent speed cmd:/1V10000 Response:ÿ/0@
2025-01-14T06:44:36.369Z,1736837076.369 [DockingStepper](INFO): Starting
2025-01-14T06:44:36.669Z,1736837076.669 [DockingStepper](INFO): Changing to mode: 3
2025-01-14T06:44:36.669Z,1736837076.669 [DockingStepper](INFO): Detach mode.
2025-01-14T06:44:36.732Z,1736837076.732 [DockingStepper](INFO): Commanding negative:54494
2025-01-14T06:44:41.889Z,1736837081.889 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact ***
2025-01-14T06:44:41.965Z,1736837081.965 [DAT](DEBUG): Acoustic response timeout
2025-01-14T06:44:41.966Z,1736837081.966 [DAT](INFO): Querying Benthos address 50 with one ping in standard two-way mode.
2025-01-14T06:44:42.219Z,1736837082.219 [DAT](INFO): DAT read: user:335>

2025-01-14T06:44:42.220Z,1736837082.220 [DAT](INFO): DAT read: Tx time:06:44:42.1206

2025-01-14T06:44:42.220Z,1736837082.220 [DAT](INFO): Ping request sent.
2025-01-14T06:44:42.220Z,1736837082.220 [DAT](INFO): transmitted an acoustic signal
2025-01-14T06:44:42.220Z,1736837082.220 [DAT](INFO): publishing transmit ping time
2025-01-14T06:44:42.221Z,1736837082.221 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.000756
2025-01-14T06:44:42.469Z,1736837082.469 [DAT](INFO): DAT read: TxSync time:06:44:42.1198

2025-01-14T06:44:42.470Z,1736837082.470 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.249446
2025-01-14T06:44:42.669Z,1736837082.669 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Detected possible detachment. Starting timer.
2025-01-14T06:44:42.723Z,1736837082.723 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.502900
2025-01-14T06:44:42.973Z,1736837082.973 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.752484
2025-01-14T06:44:43.225Z,1736837083.225 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.004715
2025-01-14T06:44:43.477Z,1736837083.477 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.256682
2025-01-14T06:44:43.729Z,1736837083.729 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.508544
2025-01-14T06:44:43.981Z,1736837083.981 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.760877
2025-01-14T06:44:44.233Z,1736837084.233 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.012545
2025-01-14T06:44:44.485Z,1736837084.485 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.264481
2025-01-14T06:44:44.737Z,1736837084.737 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.517145
2025-01-14T06:44:44.989Z,1736837084.989 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.768525
2025-01-14T06:44:45.241Z,1736837085.241 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.020671
2025-01-14T06:44:45.493Z,1736837085.493 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.272730
2025-01-14T06:44:45.745Z,1736837085.745 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.524985
2025-01-14T06:44:45.997Z,1736837085.997 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.777097
2025-01-14T06:44:46.249Z,1736837086.249 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.028805
2025-01-14T06:44:46.502Z,1736837086.502 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.281837
2025-01-14T06:44:46.754Z,1736837086.754 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.533653
2025-01-14T06:44:47.005Z,1736837087.005 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.784825
2025-01-14T06:44:47.257Z,1736837087.257 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.036548
2025-01-14T06:44:47.509Z,1736837087.509 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.289092
2025-01-14T06:44:47.761Z,1736837087.761 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.540570
2025-01-14T06:44:48.013Z,1736837088.013 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.792740
2025-01-14T06:44:48.265Z,1736837088.265 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.044526
2025-01-14T06:44:48.517Z,1736837088.517 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.296947
2025-01-14T06:44:48.769Z,1736837088.769 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.549081
2025-01-14T06:44:49.021Z,1736837089.021 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.800550
2025-01-14T06:44:49.273Z,1736837089.273 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.052544
2025-01-14T06:44:49.527Z,1736837089.527 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.306779
2025-01-14T06:44:49.777Z,1736837089.777 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.556523
2025-01-14T06:44:50.029Z,1736837090.029 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.808592
2025-01-14T06:44:50.281Z,1736837090.281 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.060718
2025-01-14T06:44:50.533Z,1736837090.533 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.312524
2025-01-14T06:44:50.785Z,1736837090.785 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.564584
2025-01-14T06:44:51.037Z,1736837091.037 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.816577
2025-01-14T06:44:51.289Z,1736837091.289 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.068925
2025-01-14T06:44:51.546Z,1736837091.546 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.325357
2025-01-14T06:44:51.797Z,1736837091.797 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.576665
2025-01-14T06:44:51.982Z,1736837091.982 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact ***
2025-01-14T06:44:52.049Z,1736837092.049 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.828605
2025-01-14T06:44:52.301Z,1736837092.301 [DAT](INFO): Reached modem response timeout
2025-01-14T06:44:52.301Z,1736837092.301 [DAT](DEBUG): Acoustic response timeout
2025-01-14T06:44:52.301Z,1736837092.301 [DAT](INFO): Querying Benthos address 50 with one ping in standard two-way mode.
2025-01-14T06:44:52.552Z,1736837092.552 [DAT](INFO): Reached modem response timeout
2025-01-14T06:44:52.553Z,1736837092.553 [DAT](DEBUG): Acoustic response timeout
2025-01-14T06:44:52.553Z,1736837092.553 [DAT](INFO): Querying Benthos address 50 with one ping in standard two-way mode.
2025-01-14T06:44:52.813Z,1736837092.813 [DAT](INFO): Reached modem response timeout
2025-01-14T06:44:52.814Z,1736837092.814 [DAT](DEBUG): Acoustic response timeout
2025-01-14T06:44:52.814Z,1736837092.814 [DAT](INFO): Querying Benthos address 50 with one ping in standard two-way mode.
2025-01-14T06:44:53.065Z,1736837093.065 [DAT](INFO): DAT read: Response Not Received

2025-01-14T06:44:53.065Z,1736837093.065 [DAT](INFO): response not received
2025-01-14T06:44:53.066Z,1736837093.066 [DAT](INFO): DAT read: user:336>

2025-01-14T06:44:53.066Z,1736837093.066 [DAT](INFO): DAT read: Tx time:06:44:53.0706

2025-01-14T06:44:53.067Z,1736837093.067 [DAT](INFO): Ping request sent.
2025-01-14T06:44:53.067Z,1736837093.067 [DAT](INFO): transmitted an acoustic signal
2025-01-14T06:44:53.067Z,1736837093.067 [DAT](INFO): publishing transmit ping time
2025-01-14T06:44:53.068Z,1736837093.068 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.000741
2025-01-14T06:44:53.317Z,1736837093.317 [DAT](INFO): DAT read: TxSync time:06:44:53.0698

2025-01-14T06:44:53.318Z,1736837093.318 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.250989
2025-01-14T06:44:53.571Z,1736837093.571 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.504125
2025-01-14T06:44:53.821Z,1736837093.821 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.754181
2025-01-14T06:44:54.073Z,1736837094.073 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.005937
2025-01-14T06:44:54.325Z,1736837094.325 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.258228
2025-01-14T06:44:54.577Z,1736837094.577 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.509861
2025-01-14T06:44:54.830Z,1736837094.830 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.762443
2025-01-14T06:44:55.081Z,1736837095.081 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.013852
2025-01-14T06:44:55.333Z,1736837095.333 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.265898
2025-01-14T06:44:55.588Z,1736837095.588 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.520424
2025-01-14T06:44:55.837Z,1736837095.837 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.769850
2025-01-14T06:44:56.089Z,1736837096.089 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.022357
2025-01-14T06:44:56.341Z,1736837096.341 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.273947
2025-01-14T06:44:56.595Z,1736837096.595 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.528040
2025-01-14T06:44:56.846Z,1736837096.846 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.778899
2025-01-14T06:44:57.097Z,1736837097.097 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.029916
2025-01-14T06:44:57.349Z,1736837097.349 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.281871
2025-01-14T06:44:57.601Z,1736837097.601 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.534263
2025-01-14T06:44:57.853Z,1736837097.853 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.785911
2025-01-14T06:44:58.105Z,1736837098.105 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.037841
2025-01-14T06:44:58.357Z,1736837098.357 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.290122
2025-01-14T06:44:58.609Z,1736837098.609 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.541941
2025-01-14T06:44:58.861Z,1736837098.861 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.794114
2025-01-14T06:44:59.113Z,1736837099.113 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.046131
2025-01-14T06:44:59.365Z,1736837099.365 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.297949
2025-01-14T06:44:59.617Z,1736837099.617 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.549862
2025-01-14T06:44:59.869Z,1736837099.869 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.802161
2025-01-14T06:45:00.121Z,1736837100.121 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.053915
2025-01-14T06:45:00.376Z,1736837100.376 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-14T06:45:00.379Z,1736837100.379 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.311890
2025-01-14T06:45:00.633Z,1736837100.633 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.566291
2025-01-14T06:45:00.898Z,1736837100.898 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.831428
2025-01-14T06:45:01.149Z,1736837101.149 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.081883
2025-01-14T06:45:01.380Z,1736837101.380 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-01-14T06:45:01.401Z,1736837101.401 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.333915
2025-01-14T06:45:01.653Z,1736837101.653 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.586006
2025-01-14T06:45:01.905Z,1736837101.905 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.837881
2025-01-14T06:45:02.060Z,1736837102.060 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact ***
2025-01-14T06:45:02.157Z,1736837102.157 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.089894
2025-01-14T06:45:02.409Z,1736837102.409 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.341934
2025-01-14T06:45:02.661Z,1736837102.661 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.593879
2025-01-14T06:45:02.877Z,1736837102.877 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Detached at range: nan m. Transitioning docking module to standby.
2025-01-14T06:45:02.913Z,1736837102.913 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.846328
2025-01-14T06:45:03.164Z,1736837103.164 [DAT](INFO): Reached modem response timeout
2025-01-14T06:45:03.165Z,1736837103.165 [DAT](DEBUG): Acoustic response timeout
2025-01-14T06:45:03.165Z,1736837103.165 [DAT](INFO): Querying Benthos address 50 with one ping in standard two-way mode.
2025-01-14T06:45:03.305Z,1736837103.305 [DockingStepper](INFO): Changing to mode: 1
2025-01-14T06:45:03.305Z,1736837103.305 [DockingStepper](INFO): Standby mode.
2025-01-14T06:45:03.368Z,1736837103.368 [DockingStepper](INFO): Commanding positive:54482
2025-01-14T06:45:03.416Z,1736837103.416 [DAT](INFO): Reached modem response timeout
2025-01-14T06:45:03.417Z,1736837103.417 [DAT](DEBUG): Acoustic response timeout
2025-01-14T06:45:03.417Z,1736837103.417 [DAT](INFO): Querying Benthos address 50 with one ping in standard two-way mode.
2025-01-14T06:45:03.669Z,1736837103.669 [DAT](INFO): Reached modem response timeout
2025-01-14T06:45:03.669Z,1736837103.669 [DAT](DEBUG): Acoustic response timeout
2025-01-14T06:45:03.669Z,1736837103.669 [DAT](INFO): Querying Benthos address 50 with one ping in standard two-way mode.
2025-01-14T06:45:03.921Z,1736837103.921 [DAT](INFO): DAT read: Response Not Received

2025-01-14T06:45:03.921Z,1736837103.921 [DAT](INFO): response not received
2025-01-14T06:45:03.921Z,1736837103.921 [DAT](INFO): DAT read: user:337>

2025-01-14T06:45:03.922Z,1736837103.922 [DAT](ERROR): No response from remote modem.
2025-01-14T06:45:03.922Z,1736837103.922 [DAT](DEBUG): Acoustic response timeout
2025-01-14T06:45:03.922Z,1736837103.922 [DAT](INFO): Querying Benthos address 50 with one ping in standard two-way mode.
2025-01-14T06:45:04.173Z,1736837104.173 [DAT](INFO): DAT read: Tx time:06:45:04.0207

2025-01-14T06:45:04.174Z,1736837104.174 [DAT](INFO): Ping request sent.
2025-01-14T06:45:04.174Z,1736837104.174 [DAT](INFO): transmitted an acoustic signal
2025-01-14T06:45:04.174Z,1736837104.174 [DAT](INFO): DAT read: TxSync time:06:45:04.0199

2025-01-14T06:45:04.175Z,1736837104.175 [DAT](INFO): publishing transmit ping time
2025-01-14T06:45:04.175Z,1736837104.175 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.001560
2025-01-14T06:45:04.425Z,1736837104.425 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.251283
2025-01-14T06:45:04.677Z,1736837104.677 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.503036
2025-01-14T06:45:04.929Z,1736837104.929 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.755084
2025-01-14T06:45:05.181Z,1736837105.181 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.007241
2025-01-14T06:45:05.433Z,1736837105.433 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.259012
2025-01-14T06:45:05.685Z,1736837105.685 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.511616
2025-01-14T06:45:05.937Z,1736837105.937 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.763238
2025-01-14T06:45:06.189Z,1736837106.189 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.015043
2025-01-14T06:45:06.441Z,1736837106.441 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.266966
2025-01-14T06:45:06.694Z,1736837106.694 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.519960
2025-01-14T06:45:06.945Z,1736837106.945 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.771036
2025-01-14T06:45:07.197Z,1736837107.197 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.022956
2025-01-14T06:45:07.449Z,1736837107.449 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.274968
2025-01-14T06:45:07.702Z,1736837107.702 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.528286
2025-01-14T06:45:07.953Z,1736837107.953 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.778943
2025-01-14T06:45:08.205Z,1736837108.205 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.030950
2025-01-14T06:45:08.457Z,1736837108.457 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.283045
2025-01-14T06:45:08.709Z,1736837108.709 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.535376
2025-01-14T06:45:08.978Z,1736837108.978 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.804127
2025-01-14T06:45:09.226Z,1736837109.226 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.052026
2025-01-14T06:45:09.340Z,1736837109.340 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Docking module at standby.
2025-01-14T06:45:09.477Z,1736837109.477 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.303091
2025-01-14T06:45:09.729Z,1736837109.729 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.554959
2025-01-14T06:45:09.770Z,1736837109.770 [DefaultWithUndock:LeaveDock:B.Undock](IMPORTANT): Undocking sequence complete.
2025-01-14T06:45:09.770Z,1736837109.770 [DefaultWithUndock:LeaveDock:B.Undock] Stopped
2025-01-14T06:45:09.770Z,1736837109.770 [DefaultWithUndock:LeaveDock](INFO): Completed DefaultWithUndock:LeaveDock
2025-01-14T06:45:09.771Z,1736837109.771 [DefaultWithUndock:LeaveDock] Stopped
2025-01-14T06:45:09.771Z,1736837109.771 [DefaultWithUndock:LeaveDock](DEBUG): Aggregate::uninitialize DefaultWithUndock:LeaveDock
2025-01-14T06:45:09.771Z,1736837109.771 [DefaultWithUndock:LeaveDock:A.] Stopped
2025-01-14T06:45:09.771Z,1736837109.771 [DefaultWithUndock:LeaveDock:A.](DEBUG): Uninitializing TrackAcousticContact.
2025-01-14T06:45:09.771Z,1736837109.771 [DefaultWithUndock:SurfaceDefault] Running Loop=1
2025-01-14T06:45:09.771Z,1736837109.771 [DefaultWithUndock:SurfaceDefault](DEBUG): Aggregate::initialize DefaultWithUndock:SurfaceDefault
2025-01-14T06:45:09.771Z,1736837109.771 [DefaultWithUndock:SurfaceDefault:A.GoToSurface] Running Loop=1
2025-01-14T06:45:09.771Z,1736837109.771 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-01-14T06:45:09.772Z,1736837109.772 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2025-01-14T06:45:09.772Z,1736837109.772 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2025-01-14T06:45:09.772Z,1736837109.772 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2025-01-14T06:45:09.773Z,1736837109.773 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2025-01-14T06:45:09.773Z,1736837109.773 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-01-14T06:45:09.773Z,1736837109.773 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-01-14T06:45:09.981Z,1736837109.981 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.806985
2025-01-14T06:45:10.152Z,1736837110.152 [DockingStepper](INFO): Pause
2025-01-14T06:45:10.233Z,1736837110.233 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.059148
2025-01-14T06:45:10.485Z,1736837110.485 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.311271
2025-01-14T06:45:10.545Z,1736837110.545 [ElevatorOffsetCalculator](INFO): New estimator for commanded vars: speed 1.00 m/s, pitch 30.00 deg, mass-position -22.00 mm (2 active estimators).
2025-01-14T06:45:10.737Z,1736837110.737 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.563019
2025-01-14T06:45:10.932Z,1736837110.932 [Radio_Surface](INFO): Powering up
2025-01-14T06:45:11.009Z,1736837111.009 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.834889
2025-01-14T06:45:11.261Z,1736837111.261 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.087143
2025-01-14T06:45:11.516Z,1736837111.516 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.342104
2025-01-14T06:45:11.765Z,1736837111.765 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.590952
2025-01-14T06:45:12.018Z,1736837112.018 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.844459
2025-01-14T06:45:12.271Z,1736837112.271 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.097180
2025-01-14T06:45:12.521Z,1736837112.521 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.346918
2025-01-14T06:45:12.778Z,1736837112.778 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.603924
2025-01-14T06:45:13.029Z,1736837113.029 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.854946
2025-01-14T06:45:13.281Z,1736837113.281 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.107064
2025-01-14T06:45:13.537Z,1736837113.537 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.362904
2025-01-14T06:45:13.785Z,1736837113.785 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.611042
2025-01-14T06:45:14.038Z,1736837114.038 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.863797
2025-01-14T06:45:14.288Z,1736837114.288 [DAT](INFO): Reached modem response timeout
2025-01-14T06:45:15.045Z,1736837115.045 [DAT](INFO): DAT read: Response Not Received

2025-01-14T06:45:15.045Z,1736837115.045 [DAT](INFO): response not received
2025-01-14T06:45:15.045Z,1736837115.045 [DAT](INFO): DAT read: user:338>

2025-01-14T06:45:15.046Z,1736837115.046 [DAT](INFO): DAT read: Tx time:06:45:14.9708

2025-01-14T06:45:15.046Z,1736837115.046 [DAT](INFO): Ping request sent.
2025-01-14T06:45:15.047Z,1736837115.047 [DAT](INFO): transmitted an acoustic signal
2025-01-14T06:45:15.047Z,1736837115.047 [DAT](INFO): publishing transmit ping time
2025-01-14T06:45:15.047Z,1736837115.047 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.000749
2025-01-14T06:45:15.297Z,1736837115.297 [DAT](INFO): DAT read: TxSync time:06:45:14.9700

2025-01-14T06:45:15.298Z,1736837115.298 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.250990
2025-01-14T06:45:15.552Z,1736837115.552 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.504705
2025-01-14T06:45:15.801Z,1736837115.801 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.754311
2025-01-14T06:45:16.053Z,1736837116.053 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.006113
2025-01-14T06:45:16.184Z,1736837116.184 [Radio_Surface](INFO): Checking local IP, expecting subnet 10.89.10
2025-01-14T06:45:16.185Z,1736837116.185 [Radio_Surface](INFO): Found local IP address 10.89.10.2 for eth0
2025-01-14T06:45:16.305Z,1736837116.305 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.258604
2025-01-14T06:45:16.557Z,1736837116.557 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.510048
2025-01-14T06:45:16.809Z,1736837116.809 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.762051
2025-01-14T06:45:17.061Z,1736837117.061 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.013975
2025-01-14T06:45:17.313Z,1736837117.313 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.266414
2025-01-14T06:45:17.568Z,1736837117.568 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.520844
2025-01-14T06:45:17.817Z,1736837117.817 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.770029
2025-01-14T06:45:18.069Z,1736837118.069 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.022054
2025-01-14T06:45:18.321Z,1736837118.321 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.274831
2025-01-14T06:45:18.573Z,1736837118.573 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.526033
2025-01-14T06:45:18.825Z,1736837118.825 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.778296
2025-01-14T06:45:19.077Z,1736837119.077 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.030086
2025-01-14T06:45:19.329Z,1736837119.329 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.282027
2025-01-14T06:45:19.584Z,1736837119.584 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.537163
2025-01-14T06:45:19.833Z,1736837119.833 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.786050
2025-01-14T06:45:20.085Z,1736837120.085 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.038057
2025-01-14T06:45:20.337Z,1736837120.337 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.290129
2025-01-14T06:45:20.589Z,1736837120.589 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.542101
2025-01-14T06:45:20.841Z,1736837120.841 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.794813
2025-01-14T06:45:21.093Z,1736837121.093 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.045996
2025-01-14T06:45:21.345Z,1736837121.345 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.298160
2025-01-14T06:45:21.597Z,1736837121.597 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.550133
2025-01-14T06:45:21.849Z,1736837121.849 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.802264
2025-01-14T06:45:22.101Z,1736837122.101 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.054097
2025-01-14T06:45:22.354Z,1736837122.354 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.307613
2025-01-14T06:45:22.605Z,1736837122.605 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.558052
2025-01-14T06:45:22.857Z,1736837122.857 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.810186
2025-01-14T06:45:23.109Z,1736837123.109 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.062048
2025-01-14T06:45:23.361Z,1736837123.361 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.314061
2025-01-14T06:45:23.625Z,1736837123.625 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.578497
2025-01-14T06:45:23.877Z,1736837123.877 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.830059
2025-01-14T06:45:24.129Z,1736837124.129 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.082094
2025-01-14T06:45:24.381Z,1736837124.381 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.334107
2025-01-14T06:45:24.633Z,1736837124.633 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.586853
2025-01-14T06:45:24.885Z,1736837124.885 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.838600
2025-01-14T06:45:25.909Z,1736837125.909 [DAT](INFO): DAT read: Response Not Received

2025-01-14T06:45:25.909Z,1736837125.909 [DAT](INFO): response not received
2025-01-14T06:45:25.909Z,1736837125.909 [DAT](INFO): DAT read: user:339>

2025-01-14T06:45:25.910Z,1736837125.910 [DAT](INFO): DAT read: Tx time:06:45:25.9208

2025-01-14T06:45:25.910Z,1736837125.910 [DAT](INFO): Ping request sent.
2025-01-14T06:45:25.910Z,1736837125.910 [DAT](INFO): transmitted an acoustic signal
2025-01-14T06:45:25.911Z,1736837125.911 [DAT](INFO): publishing transmit ping time
2025-01-14T06:45:25.911Z,1736837125.911 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.000736
2025-01-14T06:45:26.161Z,1736837126.161 [DAT](INFO): DAT read: TxSync time:06:45:25.9201

2025-01-14T06:45:26.162Z,1736837126.162 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.251410
2025-01-14T06:45:26.413Z,1736837126.413 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.502604
2025-01-14T06:45:26.665Z,1736837126.665 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.754116
2025-01-14T06:45:26.917Z,1736837126.917 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.006097
2025-01-14T06:45:27.169Z,1736837127.169 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.258460
2025-01-14T06:45:27.421Z,1736837127.421 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.510138
2025-01-14T06:45:27.673Z,1736837127.673 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.762700
2025-01-14T06:45:27.925Z,1736837127.925 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.014091
2025-01-14T06:45:28.177Z,1736837128.177 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.266152
2025-01-14T06:45:28.429Z,1736837128.429 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.518082
2025-01-14T06:45:28.681Z,1736837128.681 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.770084
2025-01-14T06:45:28.933Z,1736837128.933 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.022092
2025-01-14T06:45:29.185Z,1736837129.185 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.274565
2025-01-14T06:45:29.437Z,1736837129.437 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.526355
2025-01-14T06:45:29.689Z,1736837129.689 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.778542
2025-01-14T06:45:29.941Z,1736837129.941 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.030062
2025-01-14T06:45:30.193Z,1736837130.193 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.282120
2025-01-14T06:45:30.445Z,1736837130.445 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.534328
2025-01-14T06:45:30.697Z,1736837130.697 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.786088
2025-01-14T06:45:30.949Z,1736837130.949 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.038081
2025-01-14T06:45:31.201Z,1736837131.201 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.290090
2025-01-14T06:45:31.453Z,1736837131.453 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.542080
2025-01-14T06:45:31.500Z,1736837131.500 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-14T06:45:31.706Z,1736837131.706 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.795647
2025-01-14T06:45:31.957Z,1736837131.957 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.046136
2025-01-14T06:45:32.209Z,1736837132.209 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.298086
2025-01-14T06:45:32.463Z,1736837132.463 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.552549
2025-01-14T06:45:32.504Z,1736837132.504 [DataOverHttps](INFO): Radio surface powered ON.
2025-01-14T06:45:32.505Z,1736837132.505 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-01-14T06:45:32.717Z,1736837132.717 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.806302
2025-01-14T06:45:32.969Z,1736837132.969 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.058102
2025-01-14T06:45:33.221Z,1736837133.221 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.310189
2025-01-14T06:45:33.473Z,1736837133.473 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.562872
2025-01-14T06:45:33.725Z,1736837133.725 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.813977
2025-01-14T06:45:33.977Z,1736837133.977 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.066120
2025-01-14T06:45:34.229Z,1736837134.229 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.318217
2025-01-14T06:45:34.482Z,1736837134.482 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.570590
2025-01-14T06:45:34.733Z,1736837134.733 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.822105
2025-01-14T06:45:34.985Z,1736837134.985 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.074603
2025-01-14T06:45:35.237Z,1736837135.237 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.326072
2025-01-14T06:45:35.489Z,1736837135.489 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.578067
2025-01-14T06:45:35.741Z,1736837135.741 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.830573
2025-01-14T06:45:36.749Z,1736837136.749 [DAT](INFO): DAT read: Response Not Received

2025-01-14T06:45:36.749Z,1736837136.749 [DAT](INFO): response not received
2025-01-14T06:45:36.749Z,1736837136.749 [DAT](INFO): DAT read: user:340>

2025-01-14T06:45:36.750Z,1736837136.750 [DAT](ERROR): No response from remote modem.
2025-01-14T06:45:37.002Z,1736837137.002 [DAT](INFO): DAT read: Tx time:06:45:36.8709

2025-01-14T06:45:37.002Z,1736837137.002 [DAT](INFO): Ping request sent.
2025-01-14T06:45:37.002Z,1736837137.002 [DAT](INFO): transmitted an acoustic signal
2025-01-14T06:45:37.003Z,1736837137.003 [DAT](INFO): DAT read: TxSync time:06:45:36.8702

2025-01-14T06:45:37.004Z,1736837137.004 [DAT](INFO): publishing transmit ping time
2025-01-14T06:45:37.004Z,1736837137.004 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.001679
2025-01-14T06:45:37.253Z,1736837137.253 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.250278
2025-01-14T06:45:37.508Z,1736837137.508 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.504530
2025-01-14T06:45:37.757Z,1736837137.757 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.754490
2025-01-14T06:45:38.009Z,1736837138.009 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.006083
2025-01-14T06:45:38.261Z,1736837138.261 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.258162
2025-01-14T06:45:38.517Z,1736837138.517 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.514125
2025-01-14T06:45:38.769Z,1736837138.769 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.766202
2025-01-14T06:45:39.021Z,1736837139.021 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.018719
2025-01-14T06:45:39.273Z,1736837139.273 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.270149
2025-01-14T06:45:39.529Z,1736837139.529 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.525557
2025-01-14T06:45:39.777Z,1736837139.777 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.774058
2025-01-14T06:45:40.029Z,1736837140.029 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.026129
2025-01-14T06:45:40.282Z,1736837140.282 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.279424
2025-01-14T06:45:40.533Z,1736837140.533 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.530212
2025-01-14T06:45:40.785Z,1736837140.785 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.782445
2025-01-14T06:45:41.037Z,1736837141.037 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.034209
2025-01-14T06:45:41.289Z,1736837141.289 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.286125
2025-01-14T06:45:41.544Z,1736837141.544 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.541056
2025-01-14T06:45:41.793Z,1736837141.793 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.790280
2025-01-14T06:45:42.045Z,1736837142.045 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.042152
2025-01-14T06:45:42.297Z,1736837142.297 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.294152
2025-01-14T06:45:42.550Z,1736837142.550 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.547713
2025-01-14T06:45:42.801Z,1736837142.801 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.798169
2025-01-14T06:45:43.053Z,1736837143.053 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.050158
2025-01-14T06:45:43.305Z,1736837143.305 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.302216
2025-01-14T06:45:43.562Z,1736837143.562 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.558631
2025-01-14T06:45:43.809Z,1736837143.809 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.806562
2025-01-14T06:45:44.061Z,1736837144.061 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.058190
2025-01-14T06:45:44.313Z,1736837144.313 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.310138
2025-01-14T06:45:44.565Z,1736837144.565 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.562294
2025-01-14T06:45:44.817Z,1736837144.817 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.814192
2025-01-14T06:45:45.071Z,1736837145.071 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.068063
2025-01-14T06:45:45.321Z,1736837145.321 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.318418
2025-01-14T06:45:45.576Z,1736837145.576 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.572540
2025-01-14T06:45:45.825Z,1736837145.825 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.822273
2025-01-14T06:45:46.077Z,1736837146.077 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.074163
2025-01-14T06:45:46.329Z,1736837146.329 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.326773
2025-01-14T06:45:46.581Z,1736837146.581 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.578271
2025-01-14T06:45:46.833Z,1736837146.833 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.830255
2025-01-14T06:45:47.841Z,1736837147.841 [DAT](INFO): DAT read: Response Not Received

2025-01-14T06:45:47.841Z,1736837147.841 [DAT](INFO): response not received
2025-01-14T06:45:47.842Z,1736837147.842 [DAT](INFO): DAT read: user:341>

2025-01-14T06:45:47.842Z,1736837147.842 [DAT](INFO): DAT read: Tx time:06:45:47.8209

2025-01-14T06:45:47.843Z,1736837147.843 [DAT](INFO): Ping request sent.
2025-01-14T06:45:47.843Z,1736837147.843 [DAT](INFO): transmitted an acoustic signal
2025-01-14T06:45:47.843Z,1736837147.843 [DAT](INFO): publishing transmit ping time
2025-01-14T06:45:47.844Z,1736837147.844 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.000962
2025-01-14T06:45:48.093Z,1736837148.093 [DAT](INFO): DAT read: TxSync time:06:45:47.8202

2025-01-14T06:45:48.094Z,1736837148.094 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.250639
2025-01-14T06:45:48.345Z,1736837148.345 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.501769
2025-01-14T06:45:48.597Z,1736837148.597 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.753915
2025-01-14T06:45:48.849Z,1736837148.849 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.005700
2025-01-14T06:45:49.101Z,1736837149.101 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.257817
2025-01-14T06:45:49.353Z,1736837149.353 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.509833
2025-01-14T06:45:49.605Z,1736837149.605 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.761735
2025-01-14T06:45:49.870Z,1736837149.870 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.027271
2025-01-14T06:45:50.121Z,1736837150.121 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.277785
2025-01-14T06:45:50.373Z,1736837150.373 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.529731
2025-01-14T06:45:50.625Z,1736837150.625 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.781859
2025-01-14T06:45:50.877Z,1736837150.877 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.033705
2025-01-14T06:45:51.129Z,1736837151.129 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.286044
2025-01-14T06:45:51.381Z,1736837151.381 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.537761
2025-01-14T06:45:51.633Z,1736837151.633 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.790196
2025-01-14T06:45:51.885Z,1736837151.885 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.042321
2025-01-14T06:45:52.137Z,1736837152.137 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.294049
2025-01-14T06:45:52.389Z,1736837152.389 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.545965
2025-01-14T06:45:52.644Z,1736837152.644 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.800689
2025-01-14T06:45:52.893Z,1736837152.893 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.049901
2025-01-14T06:45:53.145Z,1736837153.145 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.301950
2025-01-14T06:45:53.397Z,1736837153.397 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.553713
2025-01-14T06:45:53.650Z,1736837153.650 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.806649
2025-01-14T06:45:53.901Z,1736837153.901 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.058106
2025-01-14T06:45:54.153Z,1736837154.153 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.309743
2025-01-14T06:45:54.405Z,1736837154.405 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.561688
2025-01-14T06:45:54.657Z,1736837154.657 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.813940
2025-01-14T06:45:54.909Z,1736837154.909 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.065675
2025-01-14T06:45:55.161Z,1736837155.161 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.318231
2025-01-14T06:45:55.413Z,1736837155.413 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.569765
2025-01-14T06:45:55.665Z,1736837155.665 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.821753
2025-01-14T06:45:55.917Z,1736837155.917 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.074036
2025-01-14T06:45:56.170Z,1736837156.170 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.326608
2025-01-14T06:45:56.421Z,1736837156.421 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.578005
2025-01-14T06:45:56.673Z,1736837156.673 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.829679
2025-01-14T06:45:56.926Z,1736837156.926 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.083201
2025-01-14T06:45:57.177Z,1736837157.177 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.333751
2025-01-14T06:45:57.432Z,1736837157.432 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.589356
2025-01-14T06:45:57.685Z,1736837157.685 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.841812
2025-01-14T06:45:58.693Z,1736837158.693 [DAT](INFO): DAT read: Response Not Received

2025-01-14T06:45:58.693Z,1736837158.693 [DAT](INFO): response not received
2025-01-14T06:45:58.693Z,1736837158.693 [DAT](INFO): DAT read: user:342>

2025-01-14T06:45:58.694Z,1736837158.694 [DAT](INFO): DAT read: Tx time:06:45:58.7709

2025-01-14T06:45:58.694Z,1736837158.694 [DAT](INFO): Ping request sent.
2025-01-14T06:45:58.695Z,1736837158.695 [DAT](INFO): transmitted an acoustic signal
2025-01-14T06:45:58.695Z,1736837158.695 [DAT](INFO): publishing transmit ping time
2025-01-14T06:45:58.696Z,1736837158.696 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.000746
2025-01-14T06:45:58.945Z,1736837158.945 [DAT](INFO): DAT read: TxSync time:06:45:58.7702

2025-01-14T06:45:58.946Z,1736837158.946 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.250873
2025-01-14T06:45:59.197Z,1736837159.197 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.502063
2025-01-14T06:45:59.449Z,1736837159.449 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.753991
2025-01-14T06:45:59.701Z,1736837159.701 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.006262
2025-01-14T06:45:59.953Z,1736837159.953 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.258041
2025-01-14T06:46:00.205Z,1736837160.205 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.509965
2025-01-14T06:46:00.457Z,1736837160.457 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.761984
2025-01-14T06:46:00.709Z,1736837160.709 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.014039
2025-01-14T06:46:00.962Z,1736837160.962 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.267635
2025-01-14T06:46:01.213Z,1736837161.213 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.518226
2025-01-14T06:46:01.465Z,1736837161.465 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.770136
2025-01-14T06:46:01.720Z,1736837161.720 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.024772
2025-01-14T06:46:01.969Z,1736837161.969 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.273910
2025-01-14T06:46:02.221Z,1736837162.221 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.526247
2025-01-14T06:46:02.473Z,1736837162.473 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.778384
2025-01-14T06:46:02.636Z,1736837162.636 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-14T06:46:02.725Z,1736837162.725 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.030077
2025-01-14T06:46:02.977Z,1736837162.977 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.282051
2025-01-14T06:46:03.229Z,1736837163.229 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.534591
2025-01-14T06:46:03.481Z,1736837163.481 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.786018
2025-01-14T06:46:03.640Z,1736837163.640 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-01-14T06:46:03.733Z,1736837163.733 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.038112
2025-01-14T06:46:03.985Z,1736837163.985 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.290453
2025-01-14T06:46:04.237Z,1736837164.237 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.541957
2025-01-14T06:46:04.489Z,1736837164.489 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.794146
2025-01-14T06:46:04.741Z,1736837164.741 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.046076
2025-01-14T06:46:04.993Z,1736837164.993 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.298196
2025-01-14T06:46:05.245Z,1736837165.245 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.550033
2025-01-14T06:46:05.497Z,1736837165.497 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.801990
2025-01-14T06:46:05.749Z,1736837165.749 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.054363
2025-01-14T06:46:06.001Z,1736837166.001 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.306777
2025-01-14T06:46:06.253Z,1736837166.253 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.557969
2025-01-14T06:46:06.505Z,1736837166.505 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.810101
2025-01-14T06:46:06.757Z,1736837166.757 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.062039
2025-01-14T06:46:07.009Z,1736837167.009 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.313996
2025-01-14T06:46:07.261Z,1736837167.261 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.566466
2025-01-14T06:46:07.513Z,1736837167.513 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.818111
2025-01-14T06:46:07.765Z,1736837167.765 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.070019
2025-01-14T06:46:08.017Z,1736837168.017 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.321955
2025-01-14T06:46:08.269Z,1736837168.269 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.574063
2025-01-14T06:46:08.521Z,1736837168.521 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.825972
2025-01-14T06:46:09.781Z,1736837169.781 [DAT](INFO): DAT read: Response Not Received

2025-01-14T06:46:09.781Z,1736837169.781 [DAT](INFO): response not received
2025-01-14T06:46:09.781Z,1736837169.781 [DAT](ERROR): No response from remote modem.
2025-01-14T06:46:33.780Z,1736837193.780 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-14T06:46:34.784Z,1736837194.784 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-01-14T06:47:04.904Z,1736837224.904 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-14T06:47:05.908Z,1736837225.908 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-01-14T06:47:13.441Z,1736837233.441 [DefaultWithUndock:SurfaceDefault:CheckIn] Running Loop=1
2025-01-14T06:47:13.442Z,1736837233.442 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::initialize DefaultWithUndock:SurfaceDefault:CheckIn
2025-01-14T06:47:13.442Z,1736837233.442 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Running Loop=1
2025-01-14T06:47:28.781Z,1736837248.781 [NAL9602](INFO): SBD MO Status=0, MOMSN=47249, MT Status=0, MTMSN=0
2025-01-14T06:47:28.781Z,1736837248.781 [NAL9602](INFO): No messages in MT queue
2025-01-14T06:47:29.994Z,1736837249.994 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,064729.00,A,3641.89622,N,12156.81053,W,0.447,179.14,140125,,,A*75
2025-01-14T06:47:29.996Z,1736837249.996 [NAL9602](INFO): GPS fix at 20250114T064729: (36.698270, -121.946842)
2025-01-14T06:47:30.027Z,1736837250.027 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Stopped
2025-01-14T06:47:30.027Z,1736837250.027 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Running Loop=1
2025-01-14T06:47:36.032Z,1736837256.032 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-14T06:47:37.036Z,1736837257.036 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-01-14T06:47:47.535Z,1736837267.535 [NAL9602](INFO): SBD MO Status=1, MOMSN=47250, MT Status=0, MTMSN=0
2025-01-14T06:47:47.581Z,1736837267.581 [NAL9602](INFO): Sent 73 bytes from file Logs/20250114T061343/Courier0009.lzma
2025-01-14T06:47:47.582Z,1736837267.582 [NAL9602](INFO): Packets left to send: 0
2025-01-14T06:47:57.826Z,1736837277.826 [NAL9602](INFO): SBD MO Status=1, MOMSN=47251, MT Status=0, MTMSN=0
2025-01-14T06:47:57.876Z,1736837277.876 [NAL9602](INFO): Sent 332 bytes from file Logs/20250114T061343/Express0010.lzma
2025-01-14T06:47:57.876Z,1736837277.876 [NAL9602](INFO): Packets left to send: 3
2025-01-14T06:48:07.156Z,1736837287.156 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-14T06:48:08.160Z,1736837288.160 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-01-14T06:48:14.650Z,1736837294.650 [NAL9602](INFO): SBD MO Status=1, MOMSN=47252, MT Status=0, MTMSN=0
2025-01-14T06:48:14.700Z,1736837294.700 [NAL9602](INFO): Sent 332 bytes from file Logs/20250114T061343/Express0010.lzma
2025-01-14T06:48:14.700Z,1736837294.700 [NAL9602](INFO): Packets left to send: 2
2025-01-14T06:48:27.215Z,1736837307.215 [NAL9602](INFO): SBD MO Status=1, MOMSN=47253, MT Status=0, MTMSN=0
2025-01-14T06:48:27.280Z,1736837307.280 [NAL9602](INFO): Sent 332 bytes from file Logs/20250114T061343/Express0010.lzma
2025-01-14T06:48:27.280Z,1736837307.280 [NAL9602](INFO): Packets left to send: 1
2025-01-14T06:48:30.461Z,1736837310.461 [RDI_Pathfinder](ERROR): only read 2 of 4 data items for water velocity. Device response is::WS,  -201,   -29A
2025-01-14T06:48:37.474Z,1736837317.474 [NAL9602](INFO): SBD MO Status=1, MOMSN=47254, MT Status=0, MTMSN=0
2025-01-14T06:48:37.567Z,1736837317.567 [NAL9602](INFO): Sent 6 bytes from file Logs/20250114T061343/Express0010.lzma
2025-01-14T06:48:37.579Z,1736837317.579 [NAL9602](INFO): Packets left to send: 0
2025-01-14T06:48:37.618Z,1736837317.618 [RDI_Pathfinder](ERROR): only read 2 of 4 data items for bottom velocity. Device response is::BS,  -21,  +331,A
2025-01-14T06:48:38.280Z,1736837318.280 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-14T06:48:39.284Z,1736837319.284 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-01-14T06:48:45.990Z,1736837325.990 [NAL9602](INFO): SBD MO Status=0, MOMSN=47255, MT Status=0, MTMSN=0
2025-01-14T06:48:46.089Z,1736837326.089 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Stopped
2025-01-14T06:48:46.090Z,1736837326.090 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait] Running Loop=1
2025-01-14T06:48:46.090Z,1736837326.090 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-01-14T06:48:56.020Z,1736837336.020 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003150
2025-01-14T06:48:57.020Z,1736837337.020 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-01-14T06:49:05.664Z,1736837345.664 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-01-14T06:49:14.288Z,1736837354.288 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-01-14T06:49:16.697Z,1736837356.697 [NAL9602](INFO): Not Powering down - fast GPS
2025-01-14T06:49:22.884Z,1736837362.884 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-01-14T06:49:31.632Z,1736837371.632 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-01-14T06:49:40.213Z,1736837380.213 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-01-14T06:49:48.772Z,1736837388.772 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-01-14T06:49:57.424Z,1736837397.424 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-01-14T06:50:06.100Z,1736837406.100 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-01-14T06:50:16.104Z,1736837416.104 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-01-14T06:50:28.121Z,1736837428.121 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-01-14T06:50:36.812Z,1736837436.812 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-01-14T06:50:46.692Z,1736837446.692 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-01-14T06:50:54.313Z,1736837454.313 [DataOverHttps](IMPORTANT): SBD MTMSN=20250114T065053
2025-01-14T06:51:02.094Z,1736837462.094 [DataOverHttps](INFO): Received command: restart logs