2023-06-28T14:46:15.378Z,1687963575.378 [Supervisor](DEBUG): Initializing supervisor.
2023-06-28T14:46:15.382Z,1687963575.382 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2023-06-28T14:46:15.383Z,1687963575.383 [SyncHandler](INFO): Protected caller Thread ID is 842
2023-06-28T14:46:15.383Z,1687963575.383 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2023-06-28T14:46:15.384Z,1687963575.384 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2023-06-28T14:46:15.385Z,1687963575.385 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 843
2023-06-28T14:46:15.389Z,1687963575.389 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2023-06-28T14:46:15.406Z,1687963575.406 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2023-06-28T14:46:15.407Z,1687963575.407 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2023-06-28T14:46:15.407Z,1687963575.407 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 844
2023-06-28T14:46:15.411Z,1687963575.411 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2023-06-28T14:46:15.413Z,1687963575.413 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2023-06-28T14:46:15.413Z,1687963575.413 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 845
2023-06-28T14:46:15.415Z,1687963575.415 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2023-06-28T14:46:15.416Z,1687963575.416 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2023-06-28T14:46:15.416Z,1687963575.416 [logger ThreadHandler](INFO): Protected caller Thread ID is 846
2023-06-28T14:46:15.420Z,1687963575.420 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2023-06-28T14:46:15.420Z,1687963575.420 [Supervisor](INFO): Looking for Config files in directory: Config/
2023-06-28T14:46:15.424Z,1687963575.424 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2023-06-28T14:46:15.937Z,1687963575.937 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2023-06-28T14:46:15.939Z,1687963575.939 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2023-06-28T14:46:16.144Z,1687963576.144 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2023-06-28T14:46:16.145Z,1687963576.145 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2023-06-28T14:46:16.225Z,1687963576.225 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2023-06-28T14:46:16.439Z,1687963576.439 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2023-06-28T14:46:16.441Z,1687963576.441 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2023-06-28T14:46:16.521Z,1687963576.521 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2023-06-28T14:46:16.617Z,1687963576.617 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2023-06-28T14:46:16.619Z,1687963576.619 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2023-06-28T14:46:16.962Z,1687963576.962 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2023-06-28T14:46:16.964Z,1687963576.964 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2023-06-28T14:46:17.096Z,1687963577.096 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2023-06-28T14:46:17.098Z,1687963577.098 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2023-06-28T14:46:17.575Z,1687963577.575 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2023-06-28T14:46:17.576Z,1687963577.576 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2023-06-28T14:46:17.755Z,1687963577.755 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2023-06-28T14:46:17.756Z,1687963577.756 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2023-06-28T14:46:18.144Z,1687963578.144 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2023-06-28T14:46:18.146Z,1687963578.146 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2023-06-28T14:46:18.454Z,1687963578.454 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2023-06-28T14:46:18.963Z,1687963578.963 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2023-06-28T14:46:19.203Z,1687963579.203 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2023-06-28T14:46:19.204Z,1687963579.204 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2023-06-28T14:46:20.070Z,1687963580.070 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2023-06-28T14:46:20.070Z,1687963580.070 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2023-06-28T14:46:20.393Z,1687963580.393 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2023-06-28T14:46:20.394Z,1687963580.394 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2023-06-28T14:46:20.615Z,1687963580.615 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2023-06-28T14:46:20.617Z,1687963580.617 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-triton/
2023-06-28T14:46:20.619Z,1687963580.619 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/vehicle.cfg
2023-06-28T14:46:20.742Z,1687963580.742 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/secure.cfg
2023-06-28T14:46:20.827Z,1687963580.827 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Science.cfg
2023-06-28T14:46:20.966Z,1687963580.966 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Simulator.cfg
2023-06-28T14:46:21.052Z,1687963581.052 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Battery.cfg
2023-06-28T14:46:21.318Z,1687963581.318 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2023-06-28T14:46:21.319Z,1687963581.319 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/logger.cfg
2023-06-28T14:46:21.422Z,1687963581.422 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Servo.cfg
2023-06-28T14:46:21.530Z,1687963581.530 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Navigation.cfg
2023-06-28T14:46:21.642Z,1687963581.642 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Sensor.cfg
2023-06-28T14:46:21.788Z,1687963581.788 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Control.cfg
2023-06-28T14:46:21.887Z,1687963581.887 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/BIT.cfg
2023-06-28T14:46:21.984Z,1687963581.984 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2023-06-28T14:46:21.999Z,1687963581.999 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2023-06-28T14:46:22.015Z,1687963582.015 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2023-06-28T14:46:22.017Z,1687963582.017 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2023-06-28T14:46:22.141Z,1687963582.141 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2023-06-28T14:46:22.143Z,1687963582.143 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2023-06-28T14:46:22.212Z,1687963582.212 [VerticalControl](DEBUG): Construct VerticalControl.
2023-06-28T14:46:22.271Z,1687963582.271 [VerticalControl] Loaded
2023-06-28T14:46:22.272Z,1687963582.272 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2023-06-28T14:46:22.275Z,1687963582.275 [HorizontalControl](DEBUG): Construct HorizontalControl.
2023-06-28T14:46:22.315Z,1687963582.315 [HorizontalControl] Loaded
2023-06-28T14:46:22.316Z,1687963582.316 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2023-06-28T14:46:22.318Z,1687963582.318 [SpeedControl](DEBUG): Construct SpeedControl.
2023-06-28T14:46:22.321Z,1687963582.321 [SpeedControl] Loaded
2023-06-28T14:46:22.321Z,1687963582.321 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2023-06-28T14:46:22.324Z,1687963582.324 [LoopControl](DEBUG): Construct LoopControl.
2023-06-28T14:46:22.325Z,1687963582.325 [LoopControl] Loaded
2023-06-28T14:46:22.325Z,1687963582.325 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2023-06-28T14:46:22.325Z,1687963582.325 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2023-06-28T14:46:22.327Z,1687963582.327 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2023-06-28T14:46:22.509Z,1687963582.509 [BuoyancyServo] Loaded
2023-06-28T14:46:22.509Z,1687963582.509 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2023-06-28T14:46:22.529Z,1687963582.529 [ElevatorServo] Loaded
2023-06-28T14:46:22.529Z,1687963582.529 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2023-06-28T14:46:22.548Z,1687963582.548 [MassServo] Loaded
2023-06-28T14:46:22.548Z,1687963582.548 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2023-06-28T14:46:22.566Z,1687963582.566 [RudderServo] Loaded
2023-06-28T14:46:22.567Z,1687963582.567 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2023-06-28T14:46:22.581Z,1687963582.581 [ThrusterHE] Loaded
2023-06-28T14:46:22.582Z,1687963582.582 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread.
2023-06-28T14:46:22.582Z,1687963582.582 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2023-06-28T14:46:22.583Z,1687963582.583 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2023-06-28T14:46:22.651Z,1687963582.651 [DepthRateCalculator] Loaded
2023-06-28T14:46:22.652Z,1687963582.652 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2023-06-28T14:46:22.656Z,1687963582.656 [PitchRateCalculator] Loaded
2023-06-28T14:46:22.657Z,1687963582.657 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2023-06-28T14:46:22.666Z,1687963582.666 [SpeedCalculator] Loaded
2023-06-28T14:46:22.667Z,1687963582.667 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2023-06-28T14:46:22.671Z,1687963582.671 [YawRateCalculator] Loaded
2023-06-28T14:46:22.671Z,1687963582.671 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2023-06-28T14:46:22.689Z,1687963582.689 [ElevatorOffsetCalculator] Loaded
2023-06-28T14:46:22.690Z,1687963582.690 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2023-06-28T14:46:22.690Z,1687963582.690 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2023-06-28T14:46:22.692Z,1687963582.692 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2023-06-28T14:46:22.831Z,1687963582.831 [DeadReckonUsingMultipleVelocitySources] Loaded
2023-06-28T14:46:22.831Z,1687963582.831 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2023-06-28T14:46:22.845Z,1687963582.845 [NavChart] Loaded
2023-06-28T14:46:22.845Z,1687963582.845 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2023-06-28T14:46:22.851Z,1687963582.851 [UniversalFixResidualReporter] Loaded
2023-06-28T14:46:22.851Z,1687963582.851 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2023-06-28T14:46:22.851Z,1687963582.851 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2023-06-28T14:46:22.853Z,1687963582.853 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2023-06-28T14:46:23.771Z,1687963583.771 [AHRS_M2] Loaded
2023-06-28T14:46:23.771Z,1687963583.771 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2023-06-28T14:46:24.020Z,1687963584.020 [BackseatComponent] Loaded
2023-06-28T14:46:24.020Z,1687963584.020 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2023-06-28T14:46:24.022Z,1687963584.022 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 408E54E0
2023-06-28T14:46:24.022Z,1687963584.022 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 928
2023-06-28T14:46:24.025Z,1687963584.025 [LcmUniversalReporter] Loaded
2023-06-28T14:46:24.025Z,1687963584.025 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2023-06-28T14:46:24.031Z,1687963584.031 [BioacousticsDataBridge] Loaded
2023-06-28T14:46:24.031Z,1687963584.031 [ComponentRegistry](DEBUG): SyncComponent "BioacousticsDataBridge" handled in the control thread.
2023-06-28T14:46:25.405Z,1687963585.405 [BPC1] Loaded
2023-06-28T14:46:25.405Z,1687963585.405 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2023-06-28T14:46:25.734Z,1687963585.734 [DataOverHttps] Loaded
2023-06-28T14:46:25.734Z,1687963585.734 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2023-06-28T14:46:25.735Z,1687963585.735 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 409154E0
2023-06-28T14:46:25.736Z,1687963585.736 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 930
2023-06-28T14:46:25.757Z,1687963585.757 [Depth_Keller] Loaded
2023-06-28T14:46:25.757Z,1687963585.757 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2023-06-28T14:46:25.762Z,1687963585.762 [DropWeight] Loaded
2023-06-28T14:46:25.762Z,1687963585.762 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2023-06-28T14:46:25.825Z,1687963585.825 [NAL9602] Loaded
2023-06-28T14:46:25.825Z,1687963585.825 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2023-06-28T14:46:25.855Z,1687963585.855 [Onboard] Loaded
2023-06-28T14:46:25.855Z,1687963585.855 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2023-06-28T14:46:25.856Z,1687963585.856 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 409454E0
2023-06-28T14:46:25.856Z,1687963585.856 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 931
2023-06-28T14:46:25.868Z,1687963585.868 [Power24vConverter] Loaded
2023-06-28T14:46:25.869Z,1687963585.869 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2023-06-28T14:46:25.882Z,1687963585.882 [Radio_Surface] Loaded
2023-06-28T14:46:25.882Z,1687963585.882 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2023-06-28T14:46:25.883Z,1687963585.883 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409754E0
2023-06-28T14:46:25.883Z,1687963585.883 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 932
2023-06-28T14:46:25.897Z,1687963585.897 [Sonardyne_Nano] Loaded
2023-06-28T14:46:25.897Z,1687963585.897 [ComponentRegistry](DEBUG): SyncComponent "Sonardyne_Nano" handled in the control thread.
2023-06-28T14:46:25.898Z,1687963585.898 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2023-06-28T14:46:25.899Z,1687963585.899 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2023-06-28T14:46:25.980Z,1687963585.980 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2023-06-28T14:46:25.981Z,1687963585.981 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2023-06-28T14:46:26.164Z,1687963586.164 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2023-06-28T14:46:26.165Z,1687963586.165 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2023-06-28T14:46:26.207Z,1687963586.207 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2023-06-28T14:46:26.208Z,1687963586.208 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2023-06-28T14:46:26.423Z,1687963586.423 [CTD_Seabird] Loaded
2023-06-28T14:46:26.423Z,1687963586.423 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2023-06-28T14:46:26.424Z,1687963586.424 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40AA94E0
2023-06-28T14:46:26.425Z,1687963586.425 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 933
2023-06-28T14:46:26.445Z,1687963586.445 [PAR_Licor] Loaded
2023-06-28T14:46:26.445Z,1687963586.445 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2023-06-28T14:46:26.476Z,1687963586.476 [WetLabsBB2FL] Loaded
2023-06-28T14:46:26.477Z,1687963586.477 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2023-06-28T14:46:26.478Z,1687963586.478 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40AD94E0
2023-06-28T14:46:26.478Z,1687963586.478 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 934
2023-06-28T14:46:26.479Z,1687963586.479 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2023-06-28T14:46:26.479Z,1687963586.479 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2023-06-28T14:46:26.833Z,1687963586.833 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2023-06-28T14:46:26.833Z,1687963586.833 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2023-06-28T14:46:27.004Z,1687963587.004 [SBIT](DEBUG): Construct Startup Built In Test.
2023-06-28T14:46:27.013Z,1687963587.013 [SBIT] Loaded
2023-06-28T14:46:27.013Z,1687963587.013 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2023-06-28T14:46:27.016Z,1687963587.016 [IBIT](DEBUG): Construct Initiated Built In Test.
2023-06-28T14:46:27.030Z,1687963587.030 [IBIT] Loaded
2023-06-28T14:46:27.030Z,1687963587.030 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2023-06-28T14:46:27.036Z,1687963587.036 [CBIT](DEBUG): Construct Continuous Built In Test.
2023-06-28T14:46:27.141Z,1687963587.141 [CBIT] Loaded
2023-06-28T14:46:27.141Z,1687963587.141 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2023-06-28T14:46:27.142Z,1687963587.142 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2023-06-28T14:46:27.148Z,1687963587.148 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2023-06-28T14:46:27.151Z,1687963587.151 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2023-06-28T14:46:27.162Z,1687963587.162 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2023-06-28T14:46:27.163Z,1687963587.163 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40BC44E0
2023-06-28T14:46:27.163Z,1687963587.163 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 935
2023-06-28T14:46:27.168Z,1687963587.168 [Supervisor](INFO): Main Thread ID is 835
2023-06-28T14:46:27.168Z,1687963587.168 [Supervisor](DEBUG): Running supervisor.
2023-06-28T14:46:27.169Z,1687963587.169 [CommandExec ThreadHandler](INFO): Handler Thread ID is 936
2023-06-28T14:46:27.169Z,1687963587.169 [CommandExec](INFO): Initializing the command executive.
2023-06-28T14:46:27.171Z,1687963587.171 [CommandLine ThreadHandler](INFO): Handler Thread ID is 937
2023-06-28T14:46:27.173Z,1687963587.173 [controlThread ThreadHandler](INFO): Handler Thread ID is 938
2023-06-28T14:46:27.173Z,1687963587.173 [controlThread](DEBUG): Initializing ControlThread
2023-06-28T14:46:27.174Z,1687963587.174 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2023-06-28T14:46:27.176Z,1687963587.176 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2023-06-28T14:46:27.176Z,1687963587.176 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2023-06-28T14:46:27.177Z,1687963587.177 [LoopControl](DEBUG): Initialize LoopControlComponent.
2023-06-28T14:46:27.178Z,1687963587.178 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2023-06-28T14:46:27.179Z,1687963587.179 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2023-06-28T14:46:27.179Z,1687963587.179 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2023-06-28T14:46:27.179Z,1687963587.180 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2023-06-28T14:46:27.180Z,1687963587.180 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2023-06-28T14:46:27.181Z,1687963587.181 [NavChart](DEBUG): Initialize NavChart Navigation.
2023-06-28T14:46:27.181Z,1687963587.181 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2023-06-28T14:46:27.189Z,1687963587.189 [SBIT](INFO): Initialize SBIT Component.
2023-06-28T14:46:27.189Z,1687963587.189 [SBIT](IMPORTANT): git: 2023-06-27_B
2023-06-28T14:46:27.190Z,1687963587.190 [SBIT](INFO): git hash: ff84f56c2b48606b9e34bb544c9bbe31deaa129e
2023-06-28T14:46:27.190Z,1687963587.190 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2023-06-28T14:46:27.191Z,1687963587.191 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #1 PREEMPT Tue Dec 18 21:19:28 PST 2018
Kernel Reported: #1 PREEMPT Wed Mar 17 08:23:48 PDT 2021
2023-06-28T14:46:27.192Z,1687963587.192 [SBIT](INFO): Beginning SBIT in 130.000000 seconds.
2023-06-28T14:46:27.193Z,1687963587.193 [IBIT](INFO): Initialize IBIT Component.
2023-06-28T14:46:27.194Z,1687963587.194 [CBIT](DEBUG): Initialize CBIT Component.
2023-06-28T14:46:27.195Z,1687963587.195 [logger ThreadHandler](INFO): Handler Thread ID is 939
2023-06-28T14:46:27.205Z,1687963587.205 [CBIT](DEBUG): Initialized mux pins.
2023-06-28T14:46:27.205Z,1687963587.205 [CBIT](DEBUG): Initializing the watchdog timer.
2023-06-28T14:46:27.213Z,1687963587.213 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 940
2023-06-28T14:46:27.225Z,1687963587.225 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 941
2023-06-28T14:46:27.226Z,1687963587.226 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2023-06-28T14:46:27.229Z,1687963587.229 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2023-06-28T14:46:27.229Z,1687963587.229 [CBIT](DEBUG): Initializing heartbeat.
2023-06-28T14:46:27.237Z,1687963587.237 [Onboard ThreadHandler](INFO): Handler Thread ID is 942
2023-06-28T14:46:27.255Z,1687963587.255 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 943
2023-06-28T14:46:27.274Z,1687963587.274 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 944
2023-06-28T14:46:27.274Z,1687963587.274 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2023-06-28T14:46:27.278Z,1687963587.278 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 946
2023-06-28T14:46:27.281Z,1687963587.281 [WetLabsBB2FL](INFO): Powering up
2023-06-28T14:46:27.282Z,1687963587.282 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 948
2023-06-28T14:46:27.291Z,1687963587.291 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2MI01M.000
2023-06-28T14:46:27.291Z,1687963587.291 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2MI01M.000
2023-06-28T14:46:27.292Z,1687963587.292 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2MI80M.000
2023-06-28T14:46:27.292Z,1687963587.292 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2MI80M.000
2023-06-28T14:46:27.292Z,1687963587.292 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4MI57M.000
2023-06-28T14:46:27.292Z,1687963587.292 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4MI57M.000
2023-06-28T14:46:27.292Z,1687963587.292 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4MI56M.000
2023-06-28T14:46:27.292Z,1687963587.292 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4MI56M.000
2023-06-28T14:46:27.293Z,1687963587.293 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4MI90M.000
2023-06-28T14:46:27.293Z,1687963587.293 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4MI90M.000
2023-06-28T14:46:27.293Z,1687963587.293 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4MI89M.000
2023-06-28T14:46:27.293Z,1687963587.293 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4MI89M.000
2023-06-28T14:46:27.294Z,1687963587.294 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2MI79M.000
2023-06-28T14:46:27.297Z,1687963587.297 [NavChartDb](FAULT): Change detected in ENC collection. Wiping NavChart Directory
2023-06-28T14:46:27.301Z,1687963587.301 [CBIT](DEBUG): Deactivating GF circuits.
2023-06-28T14:46:27.301Z,1687963587.301 [CBIT](DEBUG): Deactivating emergency mode.
2023-06-28T14:46:27.341Z,1687963587.341 [CBIT](DEBUG): Backplane powered.
2023-06-28T14:46:27.342Z,1687963587.342 [MissionManager](INFO): Loading Mission from file: Missions/Startup.xml
2023-06-28T14:46:27.347Z,1687963587.347 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2MI01M.000
2023-06-28T14:46:27.353Z,1687963587.353 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US2MI01M.000
2023-06-28T14:46:27.354Z,1687963587.354 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2MI80M.000
2023-06-28T14:46:27.355Z,1687963587.355 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US2MI80M.000
2023-06-28T14:46:27.355Z,1687963587.355 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4MI57M.000
2023-06-28T14:46:27.361Z,1687963587.361 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US4MI57M.000
2023-06-28T14:46:27.361Z,1687963587.361 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4MI56M.000
2023-06-28T14:46:27.376Z,1687963587.376 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2023-06-28T14:46:27.385Z,1687963587.385 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US4MI56M.000
2023-06-28T14:46:27.385Z,1687963587.385 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4MI90M.000
2023-06-28T14:46:27.387Z,1687963587.387 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US4MI90M.000
2023-06-28T14:46:27.387Z,1687963587.387 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4MI89M.000
2023-06-28T14:46:27.389Z,1687963587.389 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US4MI89M.000
2023-06-28T14:46:27.389Z,1687963587.389 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2MI79M.000
2023-06-28T14:46:27.390Z,1687963587.390 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US2MI79M.000
2023-06-28T14:46:27.391Z,1687963587.391 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4MN1DD.000
2023-06-28T14:46:27.392Z,1687963587.392 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US4MN1DD.000
2023-06-28T14:46:27.404Z,1687963587.404 [MissionManager](DEBUG):
2023-06-28T14:46:27.404Z,1687963587.404 [MissionManager](INFO): Loading Mission from file: Missions/Default.xml
2023-06-28T14:46:27.392Z,1687963587.392 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4MN1DE.000
2023-06-28T14:46:27.407Z,1687963587.407 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US4MN1DE.000
2023-06-28T14:46:27.407Z,1687963587.407 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4MN1DF.000
2023-06-28T14:46:27.409Z,1687963587.409 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US4MN1DF.000
2023-06-28T14:46:27.409Z,1687963587.409 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4MN1DG.000
2023-06-28T14:46:27.411Z,1687963587.411 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US4MN1DG.000
2023-06-28T14:46:27.411Z,1687963587.411 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4MN1DH.000
2023-06-28T14:46:27.433Z,1687963587.433 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US4MN1DH.000
2023-06-28T14:46:27.433Z,1687963587.433 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4MN1CC.000
2023-06-28T14:46:27.435Z,1687963587.435 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US4MN1CC.000
2023-06-28T14:46:27.435Z,1687963587.435 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4MN1CD.000
2023-06-28T14:46:27.437Z,1687963587.437 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US4MN1CD.000
2023-06-28T14:46:27.437Z,1687963587.437 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4MN1CE.000
2023-06-28T14:46:27.439Z,1687963587.439 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US4MN1CE.000
2023-06-28T14:46:27.439Z,1687963587.439 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4WI1QE.000
2023-06-28T14:46:27.457Z,1687963587.457 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US4WI1QE.000
2023-06-28T14:46:27.457Z,1687963587.457 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4WI1QF.000
2023-06-28T14:46:27.459Z,1687963587.459 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US4WI1QF.000
2023-06-28T14:46:27.459Z,1687963587.459 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4WI1QG.000
2023-06-28T14:46:27.461Z,1687963587.461 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US4WI1QG.000
2023-06-28T14:46:27.461Z,1687963587.461 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4WI1PB.000
2023-06-28T14:46:27.463Z,1687963587.463 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US4WI1PB.000
2023-06-28T14:46:27.463Z,1687963587.463 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4WI1PC.000
2023-06-28T14:46:27.482Z,1687963587.482 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US4WI1PC.000
2023-06-28T14:46:27.482Z,1687963587.482 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4WI1PD.000
2023-06-28T14:46:27.484Z,1687963587.484 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US4WI1PD.000
2023-06-28T14:46:27.484Z,1687963587.484 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4WI1PE.000
2023-06-28T14:46:27.486Z,1687963587.486 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US4WI1PE.000
2023-06-28T14:46:27.486Z,1687963587.486 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4WI1PF.000
2023-06-28T14:46:27.488Z,1687963587.488 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US4WI1PF.000
2023-06-28T14:46:27.488Z,1687963587.488 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4WI1PG.000
2023-06-28T14:46:27.490Z,1687963587.490 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2023-06-28T14:46:27.491Z,1687963587.491 [Default:A.Wait](DEBUG): Construct Wait.
2023-06-28T14:46:27.494Z,1687963587.494 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2023-06-28T14:46:27.505Z,1687963587.505 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US4WI1PG.000
2023-06-28T14:46:27.505Z,1687963587.505 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5WI22M.000
2023-06-28T14:46:27.507Z,1687963587.507 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US5WI22M.000
2023-06-28T14:46:27.534Z,1687963587.534 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2023-06-28T14:46:27.537Z,1687963587.537 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2023-06-28T14:46:27.542Z,1687963587.542 [NavChartDb](INFO): Setup scan of Resources/ElectronicNavigationCharts/US5WI22M.000
2023-06-28T14:46:27.557Z,1687963587.557 [Default:E.Execute](DEBUG): Construct Execute.
2023-06-28T14:46:27.565Z,1687963587.565 [MissionManager](DEBUG):
0
Wait a moment to see if the scheduler starts a new mission before
starting to actually run Default.
13
Burn on
Dropped weight due to communications timeout.
5
Default mission has been running for
Restarting logs and Default mission.
restart logs
2023-06-28T14:46:27.579Z,1687963587.579 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BioacousticsDataBridge,BPC1,Depth_Keller,DropWeight,NAL9602,Power24vConverter,Sonardyne_Nano,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter,
2023-06-28T14:46:27.605Z,1687963587.605 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2023-06-28T14:46:27.661Z,1687963587.661 [Radio_Surface](INFO): Powering up
2023-06-28T14:46:27.712Z,1687963587.712 [Power24vConverter](INFO): Powering up.
2023-06-28T14:46:27.717Z,1687963587.717 [Sonardyne_Nano](INFO): Initializing.
2023-06-28T14:46:27.805Z,1687963587.805 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2023-06-28T14:46:27.813Z,1687963587.813 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2023-06-28T14:46:27.814Z,1687963587.814 [ElevatorServo](DEBUG): Initializing EZServoServo.
2023-06-28T14:46:27.821Z,1687963587.821 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2023-06-28T14:46:27.822Z,1687963587.822 [MassServo](DEBUG): Initializing EZServoServo.
2023-06-28T14:46:27.829Z,1687963587.829 [MassServo](DEBUG): Initializing MassServo.
2023-06-28T14:46:27.830Z,1687963587.830 [RudderServo](DEBUG): Initializing EZServoServo.
2023-06-28T14:46:27.837Z,1687963587.837 [RudderServo](DEBUG): Initializing RudderServo.
2023-06-28T14:46:27.838Z,1687963587.838 [ThrusterHE](DEBUG): Initializing EZServoServo.
2023-06-28T14:46:27.845Z,1687963587.845 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2023-06-28T14:46:29.385Z,1687963589.385 [WetLabsBB2FL](INFO): Powering down
2023-06-28T14:46:29.677Z,1687963589.677 [NavChartDb](INFO): Done scanning features of Resources/ElectronicNavigationCharts/US5WI22M.000
2023-06-28T14:46:30.011Z,1687963590.011 [Sonardyne_Nano](ERROR): Failed to get valid response or reached max queue size, flushing UART
2023-06-28T14:46:33.470Z,1687963593.470 [ThrusterHE](ERROR): Zero Speed Commanded.
2023-06-28T14:46:41.921Z,1687963601.921 [NavChartDb](INFO): Calculating coverage of Resources/ElectronicNavigationCharts/US5WI22M.000
2023-06-28T14:46:44.826Z,1687963604.826 [NavChartDb](INFO): # of records loaded: 5000
2023-06-28T14:46:52.547Z,1687963612.547 [NavChartDb](INFO): # of records loaded: 10000
2023-06-28T14:46:55.870Z,1687963615.870 [NAL9602](INFO): Powering up NAL9602
2023-06-28T14:46:57.798Z,1687963617.798 [NavChartDb](INFO): Done scanning edges of Resources/ElectronicNavigationCharts/US5WI22M.000
2023-06-28T14:47:03.493Z,1687963623.493 [NavChartDb](INFO): Done scanning nodes of Resources/ElectronicNavigationCharts/US5WI22M.000
2023-06-28T14:47:03.592Z,1687963623.592 [NavChartDb](INFO): # of records loaded: 14894
2023-06-28T14:47:03.599Z,1687963623.599 [NavChartDb](IMPORTANT): Loaded Electronic Nav Chart data from US5WI22M.000
2023-06-28T14:47:03.600Z,1687963623.600 [NavChartDb](INFO): Setup scan of Resources/ElectronicNavigationCharts/US4WI1PG.000
2023-06-28T14:47:03.815Z,1687963623.815 [NavChartDb](INFO): Done scanning features of Resources/ElectronicNavigationCharts/US4WI1PG.000
2023-06-28T14:47:04.888Z,1687963624.888 [NavChartDb](INFO): Calculating coverage of Resources/ElectronicNavigationCharts/US4WI1PG.000
2023-06-28T14:47:05.297Z,1687963625.297 [MassServo](ERROR): getPosition uart error serial timeout
2023-06-28T14:47:05.297Z,1687963625.297 [MassServo](FAULT): Invalid EZ Servo response:""
2023-06-28T14:47:05.297Z,1687963625.297 [MassServo] Communications Fault, FailCount= 1
2023-06-28T14:47:05.297Z,1687963625.297 [MassServo](ERROR): Communications Fault
2023-06-28T14:47:05.302Z,1687963625.302 [CBIT](ERROR): Communications Fault in component: MassServo
2023-06-28T14:47:05.613Z,1687963625.613 [MassServo](DEBUG): Uninitialize Mass Servo.
2023-06-28T14:47:05.613Z,1687963625.613 [MassServo](INFO): Powering down
2023-06-28T14:47:05.872Z,1687963625.872 [NavChartDb](INFO): Done scanning edges of Resources/ElectronicNavigationCharts/US4WI1PG.000
2023-06-28T14:47:06.446Z,1687963626.446 [MassServo](DEBUG): Initializing EZServoServo.
2023-06-28T14:47:06.566Z,1687963626.566 [MassServo](DEBUG): Initializing MassServo.
2023-06-28T14:47:06.570Z,1687963626.570 [CBIT](INFO): Clearing failed state for component MassServo
2023-06-28T14:47:06.570Z,1687963626.570 [MassServo] No Fault, FailCount= 1
2023-06-28T14:47:06.636Z,1687963626.636 [NavChartDb](INFO): Done scanning nodes of Resources/ElectronicNavigationCharts/US4WI1PG.000
2023-06-28T14:47:06.668Z,1687963626.668 [NavChartDb](INFO): # of records loaded: 1291
2023-06-28T14:47:06.671Z,1687963626.671 [NavChartDb](IMPORTANT): Loaded Electronic Nav Chart data from US4WI1PG.000
2023-06-28T14:47:06.713Z,1687963626.713 [NavChartDb](INFO): Setup scan of Resources/ElectronicNavigationCharts/US4WI1PF.000
2023-06-28T14:47:06.779Z,1687963626.779 [NAL9602](INFO): NAL9602 initialized
2023-06-28T14:47:07.456Z,1687963627.456 [NavChartDb](INFO): Done scanning features of Resources/ElectronicNavigationCharts/US4WI1PF.000
2023-06-28T14:47:16.704Z,1687963636.704 [NavChartDb](INFO): # of records loaded: 5000
2023-06-28T14:47:18.634Z,1687963638.634 [NavChartDb](INFO): Calculating coverage of Resources/ElectronicNavigationCharts/US4WI1PF.000
2023-06-28T14:47:19.504Z,1687963639.504 [NavChartDb](INFO): Done scanning edges of Resources/ElectronicNavigationCharts/US4WI1PF.000
2023-06-28T14:47:22.079Z,1687963642.079 [NavChartDb](INFO): Done scanning nodes of Resources/ElectronicNavigationCharts/US4WI1PF.000
2023-06-28T14:47:22.110Z,1687963642.110 [NavChartDb](INFO): # of records loaded: 7307
2023-06-28T14:47:22.113Z,1687963642.113 [NavChartDb](IMPORTANT): Loaded Electronic Nav Chart data from US4WI1PF.000
2023-06-28T14:47:22.154Z,1687963642.154 [NavChartDb](INFO): Setup scan of Resources/ElectronicNavigationCharts/US4WI1PE.000
2023-06-28T14:47:22.491Z,1687963642.491 [NavChartDb](INFO): Done scanning features of Resources/ElectronicNavigationCharts/US4WI1PE.000
2023-06-28T14:47:23.864Z,1687963643.864 [NavChartDb](INFO): Calculating coverage of Resources/ElectronicNavigationCharts/US4WI1PE.000
2023-06-28T14:47:24.410Z,1687963644.410 [NavChartDb](INFO): Done scanning edges of Resources/ElectronicNavigationCharts/US4WI1PE.000
2023-06-28T14:47:25.138Z,1687963645.138 [NavChartDb](INFO): Done scanning nodes of Resources/ElectronicNavigationCharts/US4WI1PE.000
2023-06-28T14:47:25.171Z,1687963645.171 [NavChartDb](INFO): # of records loaded: 942
2023-06-28T14:47:25.174Z,1687963645.174 [NavChartDb](IMPORTANT): Loaded Electronic Nav Chart data from US4WI1PE.000
2023-06-28T14:47:25.241Z,1687963645.241 [NavChartDb](INFO): Setup scan of Resources/ElectronicNavigationCharts/US4WI1PD.000
2023-06-28T14:47:25.349Z,1687963645.349 [NavChartDb](INFO): Done scanning features of Resources/ElectronicNavigationCharts/US4WI1PD.000
2023-06-28T14:47:26.802Z,1687963646.802 [NavChartDb](INFO): Calculating coverage of Resources/ElectronicNavigationCharts/US4WI1PD.000
2023-06-28T14:47:27.031Z,1687963647.031 [NavChartDb](INFO): Done scanning edges of Resources/ElectronicNavigationCharts/US4WI1PD.000
2023-06-28T14:47:27.318Z,1687963647.318 [NavChartDb](INFO): Done scanning nodes of Resources/ElectronicNavigationCharts/US4WI1PD.000
2023-06-28T14:47:27.357Z,1687963647.357 [NavChartDb](INFO): # of records loaded: 916
2023-06-28T14:47:27.359Z,1687963647.359 [NavChartDb](IMPORTANT): Loaded Electronic Nav Chart data from US4WI1PD.000
2023-06-28T14:47:27.421Z,1687963647.421 [NavChartDb](INFO): Setup scan of Resources/ElectronicNavigationCharts/US4WI1PC.000
2023-06-28T14:47:27.547Z,1687963647.547 [NavChartDb](INFO): Done scanning features of Resources/ElectronicNavigationCharts/US4WI1PC.000
2023-06-28T14:47:29.950Z,1687963649.950 [NavChartDb](INFO): Calculating coverage of Resources/ElectronicNavigationCharts/US4WI1PC.000
2023-06-28T14:47:30.011Z,1687963650.011 [NavChartDb](INFO): Done scanning edges of Resources/ElectronicNavigationCharts/US4WI1PC.000
2023-06-28T14:47:30.290Z,1687963650.290 [NavChartDb](INFO): Done scanning nodes of Resources/ElectronicNavigationCharts/US4WI1PC.000
2023-06-28T14:47:30.378Z,1687963650.378 [NavChartDb](INFO): # of records loaded: 1686
2023-06-28T14:47:30.381Z,1687963650.381 [NavChartDb](IMPORTANT): Loaded Electronic Nav Chart data from US4WI1PC.000
2023-06-28T14:47:30.449Z,1687963650.449 [NavChartDb](INFO): Setup scan of Resources/ElectronicNavigationCharts/US4WI1PB.000
2023-06-28T14:47:30.702Z,1687963650.702 [NavChartDb](INFO): Done scanning features of Resources/ElectronicNavigationCharts/US4WI1PB.000
2023-06-28T14:47:34.651Z,1687963654.651 [NavChartDb](INFO): Calculating coverage of Resources/ElectronicNavigationCharts/US4WI1PB.000
2023-06-28T14:47:34.674Z,1687963654.674 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-06-28T14:47:34.872Z,1687963654.872 [NavChartDb](INFO): Done scanning edges of Resources/ElectronicNavigationCharts/US4WI1PB.000
2023-06-28T14:47:35.696Z,1687963655.696 [NavChartDb](INFO): Done scanning nodes of Resources/ElectronicNavigationCharts/US4WI1PB.000
2023-06-28T14:47:35.747Z,1687963655.747 [NavChartDb](INFO): # of records loaded: 2399
2023-06-28T14:47:35.750Z,1687963655.750 [NavChartDb](IMPORTANT): Loaded Electronic Nav Chart data from US4WI1PB.000
2023-06-28T14:47:35.785Z,1687963655.785 [NavChartDb](INFO): Setup scan of Resources/ElectronicNavigationCharts/US4WI1QG.000
2023-06-28T14:47:36.321Z,1687963656.321 [NavChartDb](INFO): Done scanning features of Resources/ElectronicNavigationCharts/US4WI1QG.000
2023-06-28T14:47:38.731Z,1687963658.731 [NAL9602](INFO): SBD MO Status=2, MOMSN=10, MT Status=2, MTMSN=0
2023-06-28T14:47:38.732Z,1687963658.732 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-06-28T14:47:43.497Z,1687963663.497 [NavChartDb](INFO): Calculating coverage of Resources/ElectronicNavigationCharts/US4WI1QG.000
2023-06-28T14:47:45.140Z,1687963665.140 [NavChartDb](INFO): Done scanning edges of Resources/ElectronicNavigationCharts/US4WI1QG.000
2023-06-28T14:47:45.917Z,1687963665.917 [NavChartDb](INFO): # of records loaded: 5000
2023-06-28T14:47:48.303Z,1687963668.303 [NavChartDb](INFO): Done scanning nodes of Resources/ElectronicNavigationCharts/US4WI1QG.000
2023-06-28T14:47:48.348Z,1687963668.348 [NavChartDb](INFO): # of records loaded: 5994
2023-06-28T14:47:48.351Z,1687963668.351 [NavChartDb](IMPORTANT): Loaded Electronic Nav Chart data from US4WI1QG.000
2023-06-28T14:47:48.377Z,1687963668.377 [NavChartDb](INFO): Setup scan of Resources/ElectronicNavigationCharts/US4WI1QF.000
2023-06-28T14:47:49.835Z,1687963669.835 [NavChartDb](INFO): Done scanning features of Resources/ElectronicNavigationCharts/US4WI1QF.000
2023-06-28T14:47:50.434Z,1687963670.434 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-06-28T14:47:54.483Z,1687963674.483 [NAL9602](INFO): SBD MO Status=0, MOMSN=10, MT Status=0, MTMSN=0
2023-06-28T14:47:54.483Z,1687963674.483 [NAL9602](INFO): No messages in MT queue
2023-06-28T14:47:55.696Z,1687963675.696 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162703.00,A,4313.39520,N,08620.11330,W,0.156,0.00,280623,,,A*76
2023-06-28T14:47:55.699Z,1687963675.699 [NAL9602](INFO): GPS fix at 20230628T162703: (43.223253, -86.335222)
2023-06-28T14:47:59.605Z,1687963679.605 [NavChartDb](INFO): Calculating coverage of Resources/ElectronicNavigationCharts/US4WI1QF.000
2023-06-28T14:48:00.877Z,1687963680.877 [NavChartDb](INFO): # of records loaded: 5000
2023-06-28T14:48:06.606Z,1687963686.606 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-06-28T14:48:10.969Z,1687963690.969 [NavChartDb](INFO): Done scanning edges of Resources/ElectronicNavigationCharts/US4WI1QF.000
2023-06-28T14:48:13.715Z,1687963693.715 [NavChartDb](INFO): # of records loaded: 10000
2023-06-28T14:48:17.668Z,1687963697.668 [NavChartDb](INFO): Done scanning nodes of Resources/ElectronicNavigationCharts/US4WI1QF.000
2023-06-28T14:48:17.730Z,1687963697.730 [NavChartDb](INFO): # of records loaded: 11279
2023-06-28T14:48:17.735Z,1687963697.735 [NavChartDb](IMPORTANT): Loaded Electronic Nav Chart data from US4WI1QF.000
2023-06-28T14:48:17.736Z,1687963697.736 [NavChartDb](INFO): Setup scan of Resources/ElectronicNavigationCharts/US4WI1QE.000
2023-06-28T14:48:18.185Z,1687963698.185 [NavChartDb](INFO): Done scanning features of Resources/ElectronicNavigationCharts/US4WI1QE.000
2023-06-28T14:48:22.363Z,1687963702.363 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-06-28T14:48:23.986Z,1687963703.986 [NavChartDb](INFO): Calculating coverage of Resources/ElectronicNavigationCharts/US4WI1QE.000
2023-06-28T14:48:25.174Z,1687963705.174 [NavChartDb](INFO): Done scanning edges of Resources/ElectronicNavigationCharts/US4WI1QE.000
2023-06-28T14:48:27.302Z,1687963707.302 [NavChartDb](INFO): Done scanning nodes of Resources/ElectronicNavigationCharts/US4WI1QE.000
2023-06-28T14:48:27.387Z,1687963707.387 [NavChartDb](INFO): # of records loaded: 3775
2023-06-28T14:48:27.390Z,1687963707.390 [NavChartDb](IMPORTANT): Loaded Electronic Nav Chart data from US4WI1QE.000
2023-06-28T14:48:27.406Z,1687963707.406 [NavChartDb](INFO): Setup scan of Resources/ElectronicNavigationCharts/US4MN1CE.000
2023-06-28T14:48:27.524Z,1687963707.524 [NavChartDb](INFO): Done scanning features of Resources/ElectronicNavigationCharts/US4MN1CE.000
2023-06-28T14:48:27.630Z,1687963707.630 [NAL9602](INFO): Not Powering down - fast GPS
2023-06-28T14:48:29.166Z,1687963709.166 [NavChartDb](INFO): Calculating coverage of Resources/ElectronicNavigationCharts/US4MN1CE.000
2023-06-28T14:48:29.195Z,1687963709.195 [NavChartDb](INFO): Done scanning edges of Resources/ElectronicNavigationCharts/US4MN1CE.000
2023-06-28T14:48:29.715Z,1687963709.715 [NavChartDb](INFO): Done scanning nodes of Resources/ElectronicNavigationCharts/US4MN1CE.000
2023-06-28T14:48:29.793Z,1687963709.793 [NavChartDb](INFO): # of records loaded: 1158
2023-06-28T14:48:29.796Z,1687963709.796 [NavChartDb](IMPORTANT): Loaded Electronic Nav Chart data from US4MN1CE.000
2023-06-28T14:48:29.813Z,1687963709.813 [NavChartDb](INFO): Setup scan of Resources/ElectronicNavigationCharts/US4MN1CD.000
2023-06-28T14:48:30.024Z,1687963710.024 [NavChartDb](INFO): Done scanning features of Resources/ElectronicNavigationCharts/US4MN1CD.000
2023-06-28T14:48:31.525Z,1687963711.525 [NavChartDb](INFO): Calculating coverage of Resources/ElectronicNavigationCharts/US4MN1CD.000
2023-06-28T14:48:32.139Z,1687963712.139 [NavChartDb](INFO): Done scanning edges of Resources/ElectronicNavigationCharts/US4MN1CD.000
2023-06-28T14:48:32.860Z,1687963712.860 [NavChartDb](INFO): Done scanning nodes of Resources/ElectronicNavigationCharts/US4MN1CD.000
2023-06-28T14:48:32.978Z,1687963712.978 [NavChartDb](INFO): # of records loaded: 1200
2023-06-28T14:48:32.980Z,1687963712.980 [NavChartDb](IMPORTANT): Loaded Electronic Nav Chart data from US4MN1CD.000
2023-06-28T14:48:32.981Z,1687963712.981 [NavChartDb](INFO): Setup scan of Resources/ElectronicNavigationCharts/US4MN1CC.000
2023-06-28T14:48:33.199Z,1687963713.199 [NavChartDb](INFO): Done scanning features of Resources/ElectronicNavigationCharts/US4MN1CC.000
2023-06-28T14:48:35.090Z,1687963715.090 [NavChartDb](INFO): Calculating coverage of Resources/ElectronicNavigationCharts/US4MN1CC.000
2023-06-28T14:48:35.512Z,1687963715.512 [NavChartDb](INFO): Done scanning edges of Resources/ElectronicNavigationCharts/US4MN1CC.000
2023-06-28T14:48:36.288Z,1687963716.288 [NavChartDb](INFO): Done scanning nodes of Resources/ElectronicNavigationCharts/US4MN1CC.000
2023-06-28T14:48:36.360Z,1687963716.360 [NavChartDb](INFO): # of records loaded: 1344
2023-06-28T14:48:36.363Z,1687963716.363 [NavChartDb](IMPORTANT): Loaded Electronic Nav Chart data from US4MN1CC.000
2023-06-28T14:48:36.389Z,1687963716.389 [NavChartDb](INFO): Setup scan of Resources/ElectronicNavigationCharts/US4MN1DH.000
2023-06-28T14:48:36.434Z,1687963716.434 [NavChartDb](INFO): Done scanning features of Resources/ElectronicNavigationCharts/US4MN1DH.000
2023-06-28T14:48:36.598Z,1687963716.598 [NavChartDb](INFO): Calculating coverage of Resources/ElectronicNavigationCharts/US4MN1DH.000
2023-06-28T14:48:36.620Z,1687963716.620 [NavChartDb](INFO): Done scanning edges of Resources/ElectronicNavigationCharts/US4MN1DH.000
2023-06-28T14:48:37.148Z,1687963717.148 [NavChartDb](INFO): Done scanning nodes of Resources/ElectronicNavigationCharts/US4MN1DH.000
2023-06-28T14:48:37.226Z,1687963717.226 [NavChartDb](INFO): # of records loaded: 194
2023-06-28T14:48:37.228Z,1687963717.228 [NavChartDb](IMPORTANT): Loaded Electronic Nav Chart data from US4MN1DH.000
2023-06-28T14:48:37.229Z,1687963717.229 [NavChartDb](INFO): Setup scan of Resources/ElectronicNavigationCharts/US4MN1DG.000
2023-06-28T14:48:37.253Z,1687963717.253 [NavChartDb](INFO): Done scanning features of Resources/ElectronicNavigationCharts/US4MN1DG.000
2023-06-28T14:48:37.325Z,1687963717.325 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-06-28T14:48:37.342Z,1687963717.342 [NavChartDb](INFO): Calculating coverage of Resources/ElectronicNavigationCharts/US4MN1DG.000
2023-06-28T14:48:37.440Z,1687963717.440 [NavChartDb](INFO): Done scanning edges of Resources/ElectronicNavigationCharts/US4MN1DG.000
2023-06-28T14:48:37.684Z,1687963717.684 [NavChartDb](INFO): Done scanning nodes of Resources/ElectronicNavigationCharts/US4MN1DG.000
2023-06-28T14:48:37.782Z,1687963717.782 [SBIT](IMPORTANT): Beginning Startup BIT
2023-06-28T14:48:37.810Z,1687963717.810 [CBIT](IMPORTANT): Beginning ground fault scan
2023-06-28T14:48:37.831Z,1687963717.831 [NavChartDb](INFO): # of records loaded: 168
2023-06-28T14:48:37.840Z,1687963717.840 [NavChartDb](IMPORTANT): Loaded Electronic Nav Chart data from US4MN1DG.000
2023-06-28T14:48:37.841Z,1687963717.841 [NavChartDb](INFO): Setup scan of Resources/ElectronicNavigationCharts/US4MN1DF.000
2023-06-28T14:48:37.952Z,1687963717.952 [NavChartDb](INFO): Done scanning features of Resources/ElectronicNavigationCharts/US4MN1DF.000
2023-06-28T14:48:38.862Z,1687963718.862 [NavChartDb](INFO): Calculating coverage of Resources/ElectronicNavigationCharts/US4MN1DF.000
2023-06-28T14:48:38.879Z,1687963718.879 [NavChartDb](INFO): Done scanning edges of Resources/ElectronicNavigationCharts/US4MN1DF.000
2023-06-28T14:48:39.434Z,1687963719.434 [NavChartDb](INFO): Done scanning nodes of Resources/ElectronicNavigationCharts/US4MN1DF.000
2023-06-28T14:48:39.559Z,1687963719.559 [NavChartDb](INFO): # of records loaded: 665
2023-06-28T14:48:39.561Z,1687963719.561 [NavChartDb](IMPORTANT): Loaded Electronic Nav Chart data from US4MN1DF.000
2023-06-28T14:48:39.562Z,1687963719.562 [NavChartDb](INFO): Setup scan of Resources/ElectronicNavigationCharts/US4MN1DE.000
2023-06-28T14:48:39.884Z,1687963719.884 [NavChartDb](INFO): Done scanning features of Resources/ElectronicNavigationCharts/US4MN1DE.000
2023-06-28T14:48:43.646Z,1687963723.646 [NavChartDb](INFO): Calculating coverage of Resources/ElectronicNavigationCharts/US4MN1DE.000
2023-06-28T14:48:43.763Z,1687963723.763 [NavChartDb](INFO): Done scanning edges of Resources/ElectronicNavigationCharts/US4MN1DE.000
2023-06-28T14:48:44.616Z,1687963724.616 [NavChartDb](INFO): Done scanning nodes of Resources/ElectronicNavigationCharts/US4MN1DE.000
2023-06-28T14:48:44.746Z,1687963724.746 [NavChartDb](INFO): # of records loaded: 1975
2023-06-28T14:48:44.749Z,1687963724.749 [NavChartDb](IMPORTANT): Loaded Electronic Nav Chart data from US4MN1DE.000
2023-06-28T14:48:44.785Z,1687963724.785 [NavChartDb](INFO): Setup scan of Resources/ElectronicNavigationCharts/US4MN1DD.000
2023-06-28T14:48:44.810Z,1687963724.810 [NavChartDb](INFO): Done scanning features of Resources/ElectronicNavigationCharts/US4MN1DD.000
2023-06-28T14:48:45.113Z,1687963725.113 [NavChartDb](INFO): Calculating coverage of Resources/ElectronicNavigationCharts/US4MN1DD.000
2023-06-28T14:48:45.122Z,1687963725.122 [NavChartDb](INFO): Done scanning edges of Resources/ElectronicNavigationCharts/US4MN1DD.000
2023-06-28T14:48:45.217Z,1687963725.217 [NavChartDb](INFO): Done scanning nodes of Resources/ElectronicNavigationCharts/US4MN1DD.000
2023-06-28T14:48:45.303Z,1687963725.303 [NavChartDb](INFO): # of records loaded: 164
2023-06-28T14:48:45.306Z,1687963725.306 [NavChartDb](IMPORTANT): Loaded Electronic Nav Chart data from US4MN1DD.000
2023-06-28T14:48:45.321Z,1687963725.321 [NavChartDb](INFO): Setup scan of Resources/ElectronicNavigationCharts/US4MI89M.000
2023-06-28T14:48:46.375Z,1687963726.375 [NavChartDb](INFO): Done scanning features of Resources/ElectronicNavigationCharts/US4MI89M.000
2023-06-28T14:48:49.098Z,1687963729.098 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.230768
CHAN A1 (24V): 0.315836
CHAN A2 (12V): 0.139281
CHAN A3 (5V): 0.051355
CHAN B0 (3.3V): 0.033199
CHAN B1 (3.15aV): 0.033673
CHAN B2 (3.15bV): 0.034723
CHAN B3 (GND): 0.001836
OPEN: 0.010223
Full Scale: +/- 1 mA
2023-06-28T14:48:51.090Z,1687963731.090 [SBIT](FAULT): Mass: EXPECTED:0.028000 ACTUAL:0.027530
2023-06-28T14:48:52.271Z,1687963732.271 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-06-28T14:48:55.434Z,1687963735.434 [NavChartDb](INFO): # of records loaded: 5000
2023-06-28T14:49:05.158Z,1687963745.158 [NavChartDb](INFO): # of records loaded: 10000
2023-06-28T14:49:07.220Z,1687963747.220 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-06-28T14:49:09.962Z,1687963749.962 [NavChartDb](INFO): Calculating coverage of Resources/ElectronicNavigationCharts/US4MI89M.000
2023-06-28T14:49:10.340Z,1687963750.340 [NavChartDb](INFO): Done scanning edges of Resources/ElectronicNavigationCharts/US4MI89M.000
2023-06-28T14:49:15.047Z,1687963755.047 [NavChartDb](INFO): Done scanning nodes of Resources/ElectronicNavigationCharts/US4MI89M.000
2023-06-28T14:49:15.264Z,1687963755.264 [NavChartDb](INFO): # of records loaded: 14969
2023-06-28T14:49:15.268Z,1687963755.268 [NavChartDb](IMPORTANT): Loaded Electronic Nav Chart data from US4MI89M.000
2023-06-28T14:49:15.269Z,1687963755.269 [NavChartDb](INFO): Setup scan of Resources/ElectronicNavigationCharts/US4MI90M.000
2023-06-28T14:49:18.808Z,1687963758.808 [NavChartDb](INFO): Done scanning features of Resources/ElectronicNavigationCharts/US4MI90M.000
2023-06-28T14:49:23.390Z,1687963763.390 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-06-28T14:49:30.738Z,1687963770.738 [NavChartDb](INFO): # of records loaded: 5000
2023-06-28T14:49:31.894Z,1687963771.894 [SBIT](CRITICAL): SBIT FAILED
2023-06-28T14:49:31.894Z,1687963771.894 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2023-06-28T14:49:31.895Z,1687963771.895 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=6 count;
2023-06-28T14:49:31.895Z,1687963771.895 [SBIT](IMPORTANT): CBIT.gfScanTimeout=90 minute;
2023-06-28T14:49:31.895Z,1687963771.895 [SBIT](IMPORTANT): ESPComponent.sampleTimeout=10 minute;
2023-06-28T14:49:31.895Z,1687963771.895 [SBIT](IMPORTANT): Express linearApproximation height_above_sea_floor 50.000000 meter;
2023-06-28T14:49:31.895Z,1687963771.895 [SBIT](IMPORTANT): Express none platform_roll_angle;
2023-06-28T14:49:31.895Z,1687963771.895 [SBIT](IMPORTANT): NAL9602.fastGPSFix=1 bool;
2023-06-28T14:49:31.896Z,1687963771.896 [SBIT](IMPORTANT): NAL9602.iridiumMTQueueTimeout=1 minute;
2023-06-28T14:49:31.896Z,1687963771.896 [SBIT](IMPORTANT): Sonardyne_Nano.loadAtStartup=1 bool;
2023-06-28T14:49:31.896Z,1687963771.896 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=315.710998 cubic_centimeter;
2023-06-28T14:49:31.896Z,1687963771.896 [SBIT](IMPORTANT): VerticalControl.elevDeadband=0.1 angular_degree;
2023-06-28T14:49:31.896Z,1687963771.896 [SBIT](IMPORTANT): VerticalControl.massDefault=27.530240 millimeter;
2023-06-28T14:49:31.898Z,1687963771.898 [CommandExec](FAULT): Scheduling is paused
2023-06-28T14:49:31.898Z,1687963771.898 [CBIT](INFO): Critical error at 20230628T144931
2023-06-28T14:49:31.898Z,1687963771.898 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2023-06-28T14:49:32.283Z,1687963772.283 [MissionManager](IMPORTANT): Started mission Startup
2023-06-28T14:49:32.284Z,1687963772.284 [Startup] Running Loop=1
2023-06-28T14:49:32.284Z,1687963772.284 [Startup](DEBUG): Aggregate::initialize Startup
2023-06-28T14:49:32.284Z,1687963772.284 [Startup:A.GoToSurface] Running Loop=1
2023-06-28T14:49:32.289Z,1687963772.289 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-06-28T14:49:32.289Z,1687963772.289 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-06-28T14:49:32.290Z,1687963772.290 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-06-28T14:49:32.290Z,1687963772.290 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-06-28T14:49:32.290Z,1687963772.290 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-06-28T14:49:32.291Z,1687963772.291 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-06-28T14:49:32.292Z,1687963772.292 [Startup:StartupSatComms] Running Loop=1
2023-06-28T14:49:32.292Z,1687963772.292 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2023-06-28T14:49:32.297Z,1687963772.297 [Startup:StartupSatComms:A] Running Loop=1
2023-06-28T14:49:32.692Z,1687963772.692 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2023-06-28T14:49:34.292Z,1687963774.292 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162843.00,A,4313.39563,N,08620.11381,W,0.019,0.00,280623,,,A*7A
2023-06-28T14:49:34.302Z,1687963774.302 [NAL9602](INFO): GPS fix at 20230628T162843: (43.223261, -86.335230)
2023-06-28T14:49:34.325Z,1687963774.325 [Startup:StartupSatComms:A] Stopped
2023-06-28T14:49:34.325Z,1687963774.325 [Startup:StartupSatComms:B] Running Loop=1
2023-06-28T14:49:34.742Z,1687963774.742 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2023-06-28T14:49:38.067Z,1687963778.067 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2023-06-28T14:49:40.476Z,1687963780.476 [NavChartDb](INFO): # of records loaded: 10000
2023-06-28T14:49:55.334Z,1687963795.334 [NavChartDb](INFO): # of records loaded: 15000
2023-06-28T14:49:58.421Z,1687963798.421 [NAL9602](INFO): SBD MO Status=1, MOMSN=11, MT Status=0, MTMSN=0
2023-06-28T14:49:58.473Z,1687963798.473 [NAL9602](INFO): Sent 332 bytes from file Logs/20230627T193117/Courier0000.lzma
2023-06-28T14:49:58.474Z,1687963798.474 [NAL9602](INFO): Packets left to send: 1
2023-06-28T14:50:05.471Z,1687963805.471 [NAL9602](INFO): SBD MO Status=1, MOMSN=12, MT Status=0, MTMSN=0
2023-06-28T14:50:05.542Z,1687963805.542 [NAL9602](INFO): Sent 33 bytes from file Logs/20230627T193117/Courier0000.lzma
2023-06-28T14:50:05.542Z,1687963805.542 [NAL9602](INFO): Packets left to send: 0
2023-06-28T14:50:11.806Z,1687963811.806 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004228
2023-06-28T14:50:14.455Z,1687963814.455 [NAL9602](INFO): SBD MO Status=1, MOMSN=13, MT Status=0, MTMSN=0
2023-06-28T14:50:14.513Z,1687963814.513 [NAL9602](INFO): Sent 109 bytes from file Logs/20230627T193117/Courier0004.lzma
2023-06-28T14:50:14.513Z,1687963814.513 [NAL9602](INFO): Packets left to send: 0
2023-06-28T14:50:14.580Z,1687963814.580 [Startup:StartupSatComms:B] Stopped
2023-06-28T14:50:14.580Z,1687963814.580 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2023-06-28T14:50:14.580Z,1687963814.580 [Startup:StartupSatComms] Stopped
2023-06-28T14:50:14.580Z,1687963814.580 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2023-06-28T14:50:14.589Z,1687963814.589 [Startup](INFO): Completed Startup
2023-06-28T14:50:14.589Z,1687963814.589 [MissionManager](INFO): Startup is completed.
2023-06-28T14:50:14.590Z,1687963814.590 [MissionManager](INFO): Uninitializing Mission Startup
2023-06-28T14:50:14.590Z,1687963814.590 [Startup] Stopped
2023-06-28T14:50:14.590Z,1687963814.590 [Startup](DEBUG): Aggregate::uninitialize Startup
2023-06-28T14:50:14.590Z,1687963814.590 [Startup:A.GoToSurface] Stopped
2023-06-28T14:50:14.590Z,1687963814.590 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2023-06-28T14:50:14.874Z,1687963814.874 [MissionManager](IMPORTANT): Started mission Default
2023-06-28T14:50:14.874Z,1687963814.874 [Default] Running Loop=1
2023-06-28T14:50:14.874Z,1687963814.874 [Default](DEBUG): Aggregate::initialize Default
2023-06-28T14:50:14.874Z,1687963814.874 [Default:B.GoToSurface] Running Loop=1
2023-06-28T14:50:14.874Z,1687963814.874 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-06-28T14:50:14.875Z,1687963814.875 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-06-28T14:50:14.875Z,1687963814.875 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-06-28T14:50:14.875Z,1687963814.875 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-06-28T14:50:14.876Z,1687963814.876 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-06-28T14:50:14.876Z,1687963814.876 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-06-28T14:50:14.876Z,1687963814.876 [Default:A.Wait] Running Loop=1
2023-06-28T14:50:14.876Z,1687963814.876 [Default:A.Wait](DEBUG): Initialize Wait Component.
2023-06-28T14:50:20.725Z,1687963820.725 [NavChartDb](INFO): # of records loaded: 20000
2023-06-28T14:50:27.982Z,1687963827.982 [Default:A.Wait](INFO): Done Waiting.
2023-06-28T14:50:27.983Z,1687963827.983 [Default:A.Wait] Stopped
2023-06-28T14:50:27.983Z,1687963827.983 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2023-06-28T14:50:28.366Z,1687963828.366 [Default:CheckIn] Running Loop=1
2023-06-28T14:50:28.366Z,1687963828.366 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-06-28T14:50:28.366Z,1687963828.366 [Default:CheckIn:Read_GPS] Running Loop=1
2023-06-28T14:50:28.724Z,1687963828.724 [DataOverHttps](IMPORTANT): Could not stat file Logs/20230627T193117/Courier0004.lzma
2023-06-28T14:50:28.724Z,1687963828.724 [DataOverHttps](FAULT): Could not open file Logs/20230627T193117/Courier0004.lzma
2023-06-28T14:50:28.818Z,1687963828.818 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2023-06-28T14:50:30.356Z,1687963830.356 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162939.00,A,4313.39441,N,08620.11375,W,0.019,0.00,280623,,,A*7C
2023-06-28T14:50:30.367Z,1687963830.367 [NAL9602](INFO): GPS fix at 20230628T162939: (43.223240, -86.335229)
2023-06-28T14:50:30.377Z,1687963830.377 [Default:CheckIn:Read_GPS] Stopped
2023-06-28T14:50:30.377Z,1687963830.377 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-06-28T14:50:30.820Z,1687963830.820 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2023-06-28T14:50:32.559Z,1687963832.559 [NavChartDb](INFO): Calculating coverage of Resources/ElectronicNavigationCharts/US4MI90M.000
2023-06-28T14:50:36.490Z,1687963836.490 [NavChartDb](INFO): Done scanning edges of Resources/ElectronicNavigationCharts/US4MI90M.000
2023-06-28T14:50:42.250Z,1687963842.250 [NavChartDb](INFO): # of records loaded: 25000
2023-06-28T14:50:43.066Z,1687963843.066 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20230627T193117/Courier0007.lzma
2023-06-28T14:50:44.066Z,1687963844.066 [DataOverHttps](INFO): Moved sent file to Logs/20230627T193117/Courier0007.lzma.bak
2023-06-28T14:50:44.067Z,1687963844.067 [DataOverHttps](INFO): SBD MOMSN=18438731
2023-06-28T14:50:55.897Z,1687963855.897 [NavChartDb](INFO): Done scanning nodes of Resources/ElectronicNavigationCharts/US4MI90M.000
2023-06-28T14:50:58.436Z,1687963858.436 [NavChartDb](INFO): # of records loaded: 27984
2023-06-28T14:50:58.449Z,1687963858.449 [NavChartDb](IMPORTANT): Loaded Electronic Nav Chart data from US4MI90M.000
2023-06-28T14:50:58.450Z,1687963858.450 [NavChartDb](INFO): Setup scan of Resources/ElectronicNavigationCharts/US4MI56M.000
2023-06-28T14:51:00.576Z,1687963860.576 [NavChartDb](INFO): Done scanning features of Resources/ElectronicNavigationCharts/US4MI56M.000
2023-06-28T14:51:02.702Z,1687963862.702 [NAL9602](INFO): Not Powering down - fast GPS
2023-06-28T14:51:05.774Z,1687963865.774 [DataOverHttps](INFO): Sending 271 bytes from file Logs/20230627T200947/Courier0000.lzma
2023-06-28T14:51:06.775Z,1687963866.775 [DataOverHttps](INFO): Moved sent file to Logs/20230627T200947/Courier0000.lzma.bak
2023-06-28T14:51:06.775Z,1687963866.775 [DataOverHttps](INFO): SBD MOMSN=18438734
2023-06-28T14:51:13.005Z,1687963873.005 [NavChartDb](INFO): # of records loaded: 5000
2023-06-28T14:51:25.914Z,1687963885.914 [NavChartDb](INFO): # of records loaded: 10000
2023-06-28T14:51:30.228Z,1687963890.228 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20230627T200947/Courier0004.lzma
2023-06-28T14:51:31.231Z,1687963891.231 [DataOverHttps](INFO): Moved sent file to Logs/20230627T200947/Courier0004.lzma.bak
2023-06-28T14:51:31.231Z,1687963891.231 [DataOverHttps](INFO): SBD MOMSN=18438740
2023-06-28T14:51:42.250Z,1687963902.250 [NavChartDb](INFO): # of records loaded: 15000
2023-06-28T14:51:51.609Z,1687963911.609 [CommandExec](IMPORTANT): got command ibit
2023-06-28T14:51:51.720Z,1687963911.720 [IBIT](IMPORTANT): Beginning Initiated BIT
2023-06-28T14:51:51.745Z,1687963911.745 [IBIT](IMPORTANT): Beginning control surface checks.
2023-06-28T14:51:51.748Z,1687963911.748 [CBIT](IMPORTANT): Beginning ground fault scan
2023-06-28T14:51:53.308Z,1687963913.308 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163102.00,A,4313.39499,N,08620.11420,W,0.019,0.00,280623,,,A*7F
2023-06-28T14:51:53.310Z,1687963913.310 [NAL9602](INFO): GPS fix at 20230628T163102: (43.223250, -86.335237)
2023-06-28T14:51:58.961Z,1687963918.961 [NavChartDb](INFO): # of records loaded: 20000
2023-06-28T14:52:02.921Z,1687963922.921 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.222095
CHAN A1 (24V): 0.332580
CHAN A2 (12V): 0.149987
CHAN A3 (5V): 0.052290
CHAN B0 (3.3V): 0.036183
CHAN B1 (3.15aV): 0.038154
CHAN B2 (3.15bV): 0.037807
CHAN B3 (GND): 0.001657
OPEN: 0.012380
Full Scale: +/- 1 mA
2023-06-28T14:52:07.105Z,1687963927.105 [DataOverHttps](INFO): Sending 440 bytes from file Logs/20230627T201556/Courier0000.lzma
2023-06-28T14:52:08.095Z,1687963928.095 [DataOverHttps](INFO): Moved sent file to Logs/20230627T201556/Courier0000.lzma.bak
2023-06-28T14:52:08.095Z,1687963928.095 [DataOverHttps](INFO): SBD MOMSN=18438742
2023-06-28T14:52:12.210Z,1687963932.210 [NavChartDb](INFO): Calculating coverage of Resources/ElectronicNavigationCharts/US4MI56M.000
2023-06-28T14:52:12.653Z,1687963932.653 [NavChartDb](INFO): Done scanning edges of Resources/ElectronicNavigationCharts/US4MI56M.000
2023-06-28T14:52:19.282Z,1687963939.282 [NavChartDb](INFO): # of records loaded: 25000
2023-06-28T14:52:23.428Z,1687963943.428 [NAL9602](INFO): SBD MO Status=2, MOMSN=14, MT Status=2, MTMSN=0
2023-06-28T14:52:23.429Z,1687963943.429 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-06-28T14:52:25.031Z,1687963945.031 [NavChartDb](INFO): Done scanning nodes of Resources/ElectronicNavigationCharts/US4MI56M.000
2023-06-28T14:52:26.498Z,1687963946.498 [NavChartDb](INFO): # of records loaded: 26626
2023-06-28T14:52:26.521Z,1687963946.521 [NavChartDb](IMPORTANT): Loaded Electronic Nav Chart data from US4MI56M.000
2023-06-28T14:52:26.522Z,1687963946.522 [NavChartDb](INFO): Setup scan of Resources/ElectronicNavigationCharts/US4MI57M.000
2023-06-28T14:52:32.174Z,1687963952.174 [DataOverHttps](INFO): Sending 487 bytes from file Logs/20230627T201719/Courier0000.lzma
2023-06-28T14:52:33.716Z,1687963953.716 [NavChartDb](INFO): Done scanning features of Resources/ElectronicNavigationCharts/US4MI57M.000
2023-06-28T14:52:37.988Z,1687963957.988 [IBIT](IMPORTANT): Communications Status:
Fix Status: 1
Iridium Signal Strength: 2
Latitude: 43.223251 Longitude: -86.335236
2023-06-28T14:52:38.195Z,1687963958.195 [DataOverHttps](INFO): Moved sent file to Logs/20230627T201719/Courier0000.lzma.bak
2023-06-28T14:52:38.195Z,1687963958.195 [DataOverHttps](INFO): SBD MOMSN=18438762
2023-06-28T14:52:38.351Z,1687963958.351 [NAL9602](INFO): SBD MO Status=2, MOMSN=14, MT Status=2, MTMSN=0
2023-06-28T14:52:38.351Z,1687963958.351 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-06-28T14:52:38.410Z,1687963958.410 [IBIT](FAULT): Warning: Battery Data not active. Expected only when running primaries. Threshold checking not active.
2023-06-28T14:52:38.794Z,1687963958.794 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2023-06-28T14:52:38.795Z,1687963958.795 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2023-06-28T14:52:38.795Z,1687963958.795 [IBIT](IMPORTANT): Pressure:10.157155 PSI
2023-06-28T14:52:38.795Z,1687963958.795 [IBIT](IMPORTANT): Humidity:8.143084 %
2023-06-28T14:52:39.245Z,1687963959.245 [IBIT](IMPORTANT): Vehicle Pitch:-2.432936 degrees
2023-06-28T14:52:39.245Z,1687963959.245 [IBIT](IMPORTANT): Vehicle Roll:8.300656 degrees
2023-06-28T14:52:39.245Z,1687963959.245 [IBIT](IMPORTANT): Vehicle Heading:212.896530 degrees
2023-06-28T14:52:39.633Z,1687963959.633 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2023-06-28T14:52:39.633Z,1687963959.633 [IBIT](IMPORTANT): buoyancyNeutral: 315.710999 cc
2023-06-28T14:52:39.633Z,1687963959.633 [IBIT](IMPORTANT): massDefault: 2.753024 cm
2023-06-28T14:52:39.634Z,1687963959.634 [IBIT](IMPORTANT): stopDepth: 100.000000 m
2023-06-28T14:52:39.634Z,1687963959.634 [IBIT](IMPORTANT): abortDepth: 120.000000 m
2023-06-28T14:52:39.634Z,1687963959.634 [IBIT](IMPORTANT): IBIT PASSED
2023-06-28T14:52:53.555Z,1687963973.555 [NavChartDb](INFO): # of records loaded: 5000
2023-06-28T14:52:55.366Z,1687963975.366 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-06-28T14:53:11.213Z,1687963991.213 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230627T201719/Courier0004.lzma
2023-06-28T14:53:12.215Z,1687963992.215 [DataOverHttps](INFO): Moved sent file to Logs/20230627T201719/Courier0004.lzma.bak
2023-06-28T14:53:12.215Z,1687963992.215 [DataOverHttps](INFO): SBD MOMSN=18438782
2023-06-28T14:53:12.807Z,1687963992.807 [NavChartDb](INFO): # of records loaded: 10000
2023-06-28T14:53:25.774Z,1687964005.774 [NAL9602](INFO): Not Powering down - fast GPS
2023-06-28T14:53:27.647Z,1687964007.647 [NavChartDb](INFO): # of records loaded: 15000
2023-06-28T14:53:36.014Z,1687964016.014 [DataOverHttps](INFO): Sending 270 bytes from file Logs/20230627T201719/Courier0007.lzma
2023-06-28T14:53:37.015Z,1687964017.015 [DataOverHttps](INFO): Moved sent file to Logs/20230627T201719/Courier0007.lzma.bak
2023-06-28T14:53:37.015Z,1687964017.015 [DataOverHttps](INFO): SBD MOMSN=18438785
2023-06-28T14:53:40.995Z,1687964020.995 [NavChartDb](INFO): # of records loaded: 20000
2023-06-28T14:54:03.469Z,1687964043.469 [NavChartDb](INFO): # of records loaded: 25000
2023-06-28T14:54:14.460Z,1687964054.460 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20230627T205857/Courier0000.lzma
2023-06-28T14:54:15.462Z,1687964055.462 [DataOverHttps](INFO): Moved sent file to Logs/20230627T205857/Courier0000.lzma.bak
2023-06-28T14:54:15.463Z,1687964055.463 [DataOverHttps](INFO): SBD MOMSN=18438795
2023-06-28T14:54:21.124Z,1687964061.124 [NavChartDb](INFO): # of records loaded: 30000
2023-06-28T14:54:34.489Z,1687964074.489 [NavChartDb](INFO): # of records loaded: 35000
2023-06-28T14:54:35.972Z,1687964075.972 [BPC1](INFO): Calculating totals. Valid battery stick count: 54. Valid reserve battery stick count: 6.
2023-06-28T14:54:35.983Z,1687964075.983 [BPC1](INFO): Received data from all battery sticks.
2023-06-28T14:54:39.546Z,1687964079.546 [DataOverHttps](INFO): Sending 335 bytes from file Logs/20230627T210034/Courier0000.lzma
2023-06-28T14:54:40.547Z,1687964080.547 [DataOverHttps](INFO): Moved sent file to Logs/20230627T210034/Courier0000.lzma.bak
2023-06-28T14:54:40.547Z,1687964080.547 [DataOverHttps](INFO): SBD MOMSN=18438798
2023-06-28T14:54:45.167Z,1687964085.167 [NavChartDb](INFO): # of records loaded: 40000
2023-06-28T14:54:57.919Z,1687964097.919 [NavChartDb](INFO): # of records loaded: 45000
2023-06-28T14:55:02.904Z,1687964102.904 [DataOverHttps](INFO): Sending 364 bytes from file Logs/20230627T210330/Courier0000.lzma
2023-06-28T14:55:03.615Z,1687964103.615 [DataOverHttps](INFO): Moved sent file to Logs/20230627T210330/Courier0000.lzma.bak
2023-06-28T14:55:03.615Z,1687964103.615 [DataOverHttps](INFO): SBD MOMSN=18438806
2023-06-28T14:55:13.780Z,1687964113.780 [NavChartDb](INFO): # of records loaded: 50000
2023-06-28T14:55:22.746Z,1687964122.746 [NavChartDb](INFO): Calculating coverage of Resources/ElectronicNavigationCharts/US4MI57M.000
2023-06-28T14:55:24.888Z,1687964124.888 [NavChartDb](INFO): Done scanning edges of Resources/ElectronicNavigationCharts/US4MI57M.000
2023-06-28T14:55:25.350Z,1687964125.350 [DataOverHttps](INFO): Sending 401 bytes from file Logs/20230627T210934/Courier0000.lzma
2023-06-28T14:55:26.350Z,1687964126.350 [DataOverHttps](INFO): Moved sent file to Logs/20230627T210934/Courier0000.lzma.bak
2023-06-28T14:55:26.351Z,1687964126.351 [DataOverHttps](INFO): SBD MOMSN=18438814
2023-06-28T14:55:27.570Z,1687964127.570 [NavChartDb](INFO): # of records loaded: 55000
2023-06-28T14:55:50.722Z,1687964150.722 [DataOverHttps](INFO): Sending 212 bytes from file Logs/20230627T210934/Courier0004.lzma
2023-06-28T14:55:51.723Z,1687964151.723 [DataOverHttps](INFO): Moved sent file to Logs/20230627T210934/Courier0004.lzma.bak
2023-06-28T14:55:51.723Z,1687964151.723 [DataOverHttps](INFO): SBD MOMSN=18438824
2023-06-28T14:56:03.753Z,1687964163.753 [NavChartDb](INFO): Done scanning nodes of Resources/ElectronicNavigationCharts/US4MI57M.000
2023-06-28T14:56:06.863Z,1687964166.863 [NavChartDb](INFO): # of records loaded: 59244
2023-06-28T14:56:06.870Z,1687964166.870 [NavChartDb](IMPORTANT): Loaded Electronic Nav Chart data from US4MI57M.000
2023-06-28T14:56:06.871Z,1687964166.871 [NavChartDb](INFO): Setup scan of Resources/ElectronicNavigationCharts/US2MI79M.000
2023-06-28T14:56:11.887Z,1687964171.887 [NavChartDb](INFO): Done scanning features of Resources/ElectronicNavigationCharts/US2MI79M.000
2023-06-28T14:56:21.439Z,1687964181.439 [DataOverHttps](INFO): Sending 765 bytes from file Logs/20230627T210934/Courier0007.lzma
2023-06-28T14:56:25.451Z,1687964185.451 [DataOverHttps](INFO): Moved sent file to Logs/20230627T210934/Courier0007.lzma.bak
2023-06-28T14:56:25.451Z,1687964185.451 [DataOverHttps](INFO): SBD MOMSN=18438827
2023-06-28T14:56:25.977Z,1687964185.977 [NavChartDb](INFO): # of records loaded: 5000
2023-06-28T14:56:28.898Z,1687964188.898 [Power24vConverter](INFO): Powering down.
2023-06-28T14:56:39.637Z,1687964199.637 [NavChartDb](INFO): # of records loaded: 10000
2023-06-28T14:56:51.081Z,1687964211.081 [NavChartDb](INFO): # of records loaded: 15000
2023-06-28T14:56:51.466Z,1687964211.466 [DataOverHttps](INFO): Sending 502 bytes from file Logs/20230627T210934/Courier0010.lzma
2023-06-28T14:57:00.111Z,1687964220.111 [NavChartDb](INFO): # of records loaded: 20000
2023-06-28T14:57:00.506Z,1687964220.506 [DataOverHttps](INFO): Moved sent file to Logs/20230627T210934/Courier0010.lzma.bak
2023-06-28T14:57:00.506Z,1687964220.506 [DataOverHttps](IMPORTANT): SBD MOMSN=18438883, MTMSN=20230628T163605
2023-06-28T14:57:11.221Z,1687964231.221 [NavChartDb](INFO): # of records loaded: 25000
2023-06-28T14:57:13.029Z,1687964233.029 [DataOverHttps](INFO): Received command: sched asap "load Transport/transit.tl;set transit.MissionTimeout 30 min;set transit.NeedCommsTime 12 min;set transit.Latitude 43.20017 degree;set transit.Longitude -86.3649 degree;set transit.Depth 1 m;set transit.MaxDepth 2 m" 1vy3s 1 2
2023-06-28T14:57:13.125Z,1687964233.125 [CommandExec](IMPORTANT): got command schedule asap "load Transport/transit.tl;set transit.MissionTimeout 30 min;set transit.NeedCommsTime 12 min;set transit.Latitude 43.20017 degree;set transit.Longitude -86.3649 degree;set transit.Depth 1 m;set transit.MaxDepth 2 m" 1vy3s 1 2.000000
2023-06-28T14:57:13.126Z,1687964233.126 [CommandExec](IMPORTANT): Scheduling command #1 of 2 with id=1vy3s
2023-06-28T14:57:13.127Z,1687964233.127 [CommandExec](IMPORTANT): Scheduled #1 (#1 of 2 with id='1vy3s'): "load Transport/transit.tl;set transit.MissionTimeout 30 min;set transit.NeedCommsTime 12 min;set transit.Latitude 43.20017 degree;set transit.Longitude -86.3649 degree;set transit.Depth 1 m;set transit.MaxDepth 2 m", ASAP
2023-06-28T14:57:14.506Z,1687964234.506 [DataOverHttps](IMPORTANT): SBD MTMSN=20230628T163622
2023-06-28T14:57:20.887Z,1687964240.887 [NavChartDb](INFO): # of records loaded: 30000
2023-06-28T14:57:24.821Z,1687964244.821 [NavChartDb](INFO): Calculating coverage of Resources/ElectronicNavigationCharts/US2MI79M.000
2023-06-28T14:57:32.984Z,1687964252.984 [NavChartDb](INFO): # of records loaded: 35000
2023-06-28T14:57:41.446Z,1687964261.446 [DataOverHttps](INFO): Sending 508 bytes from file Logs/20230627T210934/Courier0013.lzma
2023-06-28T14:57:41.450Z,1687964261.450 [DataOverHttps](INFO): Received command: sched asap "set transit.MinOffshore 0.00001 km;set transit.MinAltitude 2 m;run" 1vy3s 2 2
2023-06-28T14:57:41.460Z,1687964261.460 [CommandExec](IMPORTANT): got command schedule asap "set transit.MinOffshore 0.00001 km;set transit.MinAltitude 2 m;run" 1vy3s 2 2.000000
2023-06-28T14:57:41.460Z,1687964261.460 [CommandExec](IMPORTANT): Scheduling command #2 of 2 with id=1vy3s
2023-06-28T14:57:41.461Z,1687964261.461 [CommandExec](IMPORTANT): Scheduled #2 (#2 of 2 with id='1vy3s'): "set transit.MinOffshore 0.00001 km;set transit.MinAltitude 2 m;run", ASAP
2023-06-28T14:57:41.575Z,1687964261.575 [CommandExec](IMPORTANT): got command load ./Missions/Transport/transit.tl
2023-06-28T14:57:41.575Z,1687964261.575 [MissionManager](INFO): Loading Mission from file: ./Missions/Transport/transit.tl
2023-06-28T14:57:41.575Z,1687964261.575 [MissionManager](IMPORTANT): Loading Compiled TethysL script from file ./Missions/Transport/transit.tx
2023-06-28T14:57:41.770Z,1687964261.770 [MissionManager](INFO): DefineArg transit.MissionTimeout = 60.000000 min
2023-06-28T14:57:41.772Z,1687964261.772 [MissionManager](INFO): DefineArg transit.NeedCommsTime = 30.000000 min
2023-06-28T14:57:41.780Z,1687964261.780 [MissionManager](INFO): DefineArg transit.Latitude = nan arcdeg
2023-06-28T14:57:41.787Z,1687964261.787 [MissionManager](INFO): DefineArg transit.Longitude = nan arcdeg
2023-06-28T14:57:41.794Z,1687964261.794 [MissionManager](INFO): DefineArg transit.Northings = 0.000000 m
2023-06-28T14:57:41.801Z,1687964261.801 [MissionManager](INFO): DefineArg transit.Eastings = 0.000000 m
2023-06-28T14:57:41.804Z,1687964261.804 [MissionManager](INFO): DefineArg transit.Depth = 10.000000 m
2023-06-28T14:57:41.811Z,1687964261.811 [MissionManager](INFO): DefineArg transit.Speed = 1.000000 m/s
2023-06-28T14:57:41.854Z,1687964261.854 [MissionManager](INFO): DefineArg transit.MaxDepth = 20.000000 m
2023-06-28T14:57:41.858Z,1687964261.858 [MissionManager](INFO): DefineArg transit.MinOffshore = 1.000000 km
2023-06-28T14:57:41.877Z,1687964261.877 [MissionManager](INFO): DefineArg transit.MinAltitude = 7.000000 m
2023-06-28T14:57:41.880Z,1687964261.880 [MissionManager](INFO): DefineArg transit.MassHold = 1 bool
2023-06-28T14:57:41.891Z,1687964261.891 [MissionManager](INFO): DefineArg transit.BuoyancyHold = 1 bool
2023-06-28T14:57:41.891Z,1687964261.891 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/NeedComms.xml
2023-06-28T14:57:41.902Z,1687964261.902 [NavChartDb](INFO): # of records loaded: 40000
2023-06-28T14:57:42.098Z,1687964262.098 [MissionManager](INFO): DefineArg transit:NeedComms.DiveInterval = 1.000000 h
2023-06-28T14:57:42.121Z,1687964262.121 [MissionManager](INFO): DefineArg transit:NeedComms.WaitForPitchUp = 10.000000 min
2023-06-28T14:57:42.124Z,1687964262.124 [MissionManager](INFO): DefineArg transit:NeedComms.SurfacePitch = 20.000000 arcdeg
2023-06-28T14:57:42.126Z,1687964262.126 [MissionManager](INFO): DefineArg transit:NeedComms.SurfaceDepthRate = nan m/s
2023-06-28T14:57:42.162Z,1687964262.162 [MissionManager](INFO): DefineArg transit:NeedComms.SurfaceSpeed = 1.000000 m/s
2023-06-28T14:57:42.170Z,1687964262.170 [MissionManager](INFO): DefineArg transit:NeedComms.SurfacingTimeout = 1000.000000 s
2023-06-28T14:57:42.173Z,1687964262.173 [MissionManager](INFO): DefineArg transit:NeedComms.GPSTimeout = 7.000000 min
2023-06-28T14:57:42.176Z,1687964262.176 [MissionManager](INFO): DefineArg transit:NeedComms.CommsTimeout = 30.000000 min
2023-06-28T14:57:42.206Z,1687964262.206 [transit:NeedComms:B.GoToSurface](DEBUG): Construct GoToSurface.
2023-06-28T14:57:42.310Z,1687964262.310 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/StandardEnvelopes.xml
2023-06-28T14:57:42.421Z,1687964262.421 [MissionManager](INFO): DefineArg transit:StandardEnvelopes.MinAltitude = 5.000000 m
2023-06-28T14:57:42.424Z,1687964262.424 [MissionManager](INFO): DefineArg transit:StandardEnvelopes.MaxDepthIgnore = 0.000000 m
2023-06-28T14:57:42.483Z,1687964262.483 [MissionManager](INFO): DefineArg transit:StandardEnvelopes.MaxDepth = 200.000000 m
2023-06-28T14:57:42.506Z,1687964262.506 [MissionManager](INFO): DefineArg transit:StandardEnvelopes.MinOffshore = 2000.000000 m
2023-06-28T14:57:42.507Z,1687964262.507 [transit:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope.
2023-06-28T14:57:42.579Z,1687964262.579 [transit:StandardEnvelopes:B.DepthEnvelope](DEBUG): Construct DepthEnvelope.
2023-06-28T14:57:42.634Z,1687964262.634 [transit:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Construct OffshoreEnvelope.
2023-06-28T14:57:42.707Z,1687964262.707 [transit:BuoyancyHold.Buoyancy](DEBUG): Construct Buoyancy.
2023-06-28T14:57:42.723Z,1687964262.723 [transit:MassHold.Pitch](DEBUG): Construct.
2023-06-28T14:57:42.763Z,1687964262.763 [transit:Transit:A.Pitch](DEBUG): Construct.
2023-06-28T14:57:42.794Z,1687964262.794 [transit:Transit:B.SetSpeed](DEBUG): Construct.
2023-06-28T14:57:42.893Z,1687964262.893 [transit:Transit:Wpt1.Waypoint](DEBUG): Construct Waypoint.
2023-06-28T14:57:42.995Z,1687964262.995 [MissionManager](DEBUG):
mission transit {
"""
Vehicle transits to desired waypoint and can be commanded to use/hold
mass or buoyancy.
"""
arguments {
MissionTimeout = 60 minute
"""
Maximum duration of mission
"""
NeedCommsTime = 30 minute
"""
How often to surface for commumications
"""
Latitude = NaN degree
"""
Latitude of waypoint to seek. If set to NaN, uses latitude at mission
initialization.
"""
Longitude = NaN degree
"""
Longitude of waypoint to seek. If set to NaN, uses longitude at mission
initialization.
"""
Northings = 0 meter
"""
Northward distance of the waypoint to seek. If combined with Latitude
and/or Longitude, this is an offset from the specified Latitude and/or
Longitude.
"""
Eastings = 0 meter
"""
Eastward distance of the waypoint to seek. If combined with Latitude
and/or Longitude, this is an offset from the specified Latitude and/or
Longitude.
"""
Depth = 10 meter
"""
Depth of flat and level flight during the mission.
"""
Speed = 1 meter_per_second
"""
Speed of vehicle (relative to water) during the mission.
"""
MaxDepth = 20 meter
"""
Maximum depth for the entire mission.
"""
MinOffshore = 1 kilometer
"""
Minimum distance offshore for the entire mission.
"""
MinAltitude = 7 meter
"""
Minimum height above the sea floor for the entire mission.
"""
MassHold = true
"""
Set to True in order to hold mass at default position, False to allow
mass to run on its own.
"""
BuoyancyHold = true
"""
Set to True in order to hold buoyancy at neutral position, False to
allow buoyancy to run on its own.
"""
}
timeout duration=MissionTimeout
insert id="NeedComms" Insert/NeedComms.xml
assign in sequence NeedComms:DiveInterval = NeedCommsTime
assign in sequence NeedComms:WaitForPitchUp = 1 second
insert Insert/StandardEnvelopes.xml
assign in sequence StandardEnvelopes:MinAltitude = MinAltitude
assign in sequence StandardEnvelopes:MaxDepth = MaxDepth
assign in sequence StandardEnvelopes:MinOffshore = MinOffshore
behavior Guidance:Buoyancy id="BuoyancyHold" {
run while ( BuoyancyHold )
set position = Control:VerticalControl.buoyancyNeutral
}
behavior Guidance:Pitch id="MassHold" {
run while ( MassHold )
set massPosition = Control:VerticalControl.massDefault
}
aggregate Transit {
run in sequence
behavior Guidance:Pitch {
run in parallel
set depth = Depth
}
behavior Guidance:SetSpeed {
run in parallel
set speed = Speed
}
behavior Guidance:Waypoint id="Wpt1" {
run in sequence
set latitude = Latitude
set longitude = Longitude
set northingsDelta = Northings
set eastingsDelta = Eastings
}
call id="PhoneHome" refId="NeedComms"
}
}
2023-06-28T14:57:42.996Z,1687964262.996 [CommandExec](IMPORTANT): Loaded ./Missions/Transport/transit.tl
2023-06-28T14:57:45.489Z,1687964265.489 [DataOverHttps](INFO): Exceeded connection timeout, disconnecting.
2023-06-28T14:58:06.271Z,1687964286.271 [NavChartDb](INFO): # of records loaded: 45000
2023-06-28T14:58:08.117Z,1687964288.117 [CommandExec](IMPORTANT): got command set transit.MissionTimeout 30 minute
2023-06-28T14:58:08.118Z,1687964288.118 [CommandExec](IMPORTANT): got command set transit.NeedCommsTime 12 minute
2023-06-28T14:58:08.118Z,1687964288.118 [CommandExec](IMPORTANT): got command set transit.Latitude 43.20017 degree
2023-06-28T14:58:08.119Z,1687964288.119 [CommandExec](IMPORTANT): got command set transit.Longitude -86.3649 degree
2023-06-28T14:58:08.120Z,1687964288.120 [CommandExec](IMPORTANT): got command set transit.Depth 1 meter
2023-06-28T14:58:08.141Z,1687964288.141 [CommandExec](IMPORTANT): got command set transit.MaxDepth 2 meter
2023-06-28T14:58:12.857Z,1687964292.857 [DataOverHttps](INFO): Sending 508 bytes from file Logs/20230627T210934/Courier0013.lzma
2023-06-28T14:58:14.865Z,1687964294.865 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.358765
2023-06-28T14:58:15.985Z,1687964295.985 [CommandExec](IMPORTANT): got command set transit.MinOffshore 0.00001 kilometer
2023-06-28T14:58:15.985Z,1687964295.985 [CommandExec](IMPORTANT): got command set transit.MinAltitude 2 meter
2023-06-28T14:58:15.986Z,1687964295.986 [CommandExec](IMPORTANT): got command run
2023-06-28T14:58:15.988Z,1687964295.988 [CommandExec](IMPORTANT): Running
2023-06-28T14:58:16.752Z,1687964296.752 [Default] Stopped
2023-06-28T14:58:16.752Z,1687964296.752 [Default](DEBUG): Aggregate::uninitialize Default
2023-06-28T14:58:16.752Z,1687964296.752 [Default:B.GoToSurface] Stopped
2023-06-28T14:58:16.752Z,1687964296.752 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2023-06-28T14:58:16.752Z,1687964296.752 [Default:CheckIn] Stopped
2023-06-28T14:58:16.752Z,1687964296.752 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-06-28T14:58:16.752Z,1687964296.752 [Default:CheckIn:Read_Iridium] Stopped
2023-06-28T14:58:16.757Z,1687964296.757 [MissionManager](IMPORTANT): Started mission transit
2023-06-28T14:58:16.757Z,1687964296.757 [transit] Running Loop=1
2023-06-28T14:58:16.757Z,1687964296.757 [transit](DEBUG): Aggregate::initialize transit
2023-06-28T14:58:16.757Z,1687964296.757 [transit:StandardEnvelopes] Running Loop=1
2023-06-28T14:58:16.757Z,1687964296.757 [transit:StandardEnvelopes](DEBUG): Aggregate::initialize transit:StandardEnvelopes
2023-06-28T14:58:16.757Z,1687964296.757 [transit:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1
2023-06-28T14:58:16.757Z,1687964296.757 [transit:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent.
2023-06-28T14:58:16.758Z,1687964296.758 [transit:StandardEnvelopes:B.DepthEnvelope] Running Loop=1
2023-06-28T14:58:16.758Z,1687964296.758 [transit:StandardEnvelopes:B.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent.
2023-06-28T14:58:16.758Z,1687964296.758 [transit:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1
2023-06-28T14:58:16.758Z,1687964296.758 [transit:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Initialize OffshoreEnvelopeComponent.
2023-06-28T14:58:16.758Z,1687964296.758 [transit:BuoyancyHold.Buoyancy] Running Loop=1
2023-06-28T14:58:16.758Z,1687964296.758 [transit:BuoyancyHold.Buoyancy](DEBUG): Initialize Buoyancy Component.
2023-06-28T14:58:16.758Z,1687964296.758 [transit:MassHold.Pitch] Running Loop=1
2023-06-28T14:58:16.758Z,1687964296.758 [transit:MassHold.Pitch](DEBUG): Initialize.
2023-06-28T14:58:16.759Z,1687964296.759 [transit:B] Running Loop=1
2023-06-28T14:58:16.759Z,1687964296.759 [transit:MassHold.Pitch] Running Loop=1
2023-06-28T14:58:16.760Z,1687964296.760 [transit:BuoyancyHold.Buoyancy] Running Loop=1
2023-06-28T14:58:16.760Z,1687964296.760 [transit:StandardEnvelopes] Running Loop=1
2023-06-28T14:58:16.760Z,1687964296.760 [transit:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1
2023-06-28T14:58:16.785Z,1687964296.785 [transit:StandardEnvelopes:B.DepthEnvelope] Running Loop=1
2023-06-28T14:58:16.786Z,1687964296.786 [transit:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1
2023-06-28T14:58:16.786Z,1687964296.786 [transit:B] Stopped
2023-06-28T14:58:16.786Z,1687964296.786 [transit:C] Running Loop=1
2023-06-28T14:58:16.911Z,1687964296.911 [transit:C] Stopped
2023-06-28T14:58:16.911Z,1687964296.911 [transit:E] Running Loop=1
2023-06-28T14:58:19.305Z,1687964299.305 [transit:E] Stopped
2023-06-28T14:58:19.305Z,1687964299.305 [transit:F] Running Loop=1
2023-06-28T14:58:19.481Z,1687964299.481 [transit:F] Stopped
2023-06-28T14:58:19.481Z,1687964299.481 [transit:G] Running Loop=1
2023-06-28T14:58:19.831Z,1687964299.831 [transit:G] Stopped
2023-06-28T14:58:19.832Z,1687964299.832 [transit:Transit] Running Loop=1
2023-06-28T14:58:19.832Z,1687964299.832 [transit:Transit](DEBUG): Aggregate::initialize transit:Transit
2023-06-28T14:58:19.832Z,1687964299.832 [transit:Transit:A.Pitch] Running Loop=1
2023-06-28T14:58:19.832Z,1687964299.832 [transit:Transit:A.Pitch](DEBUG): Initialize.
2023-06-28T14:58:19.832Z,1687964299.832 [transit:Transit:B.SetSpeed] Running Loop=1
2023-06-28T14:58:19.832Z,1687964299.832 [transit:Transit:B.SetSpeed](DEBUG): Initialize.
2023-06-28T14:58:19.841Z,1687964299.841 [transit:Transit:Wpt1.Waypoint] Running Loop=1
2023-06-28T14:58:19.841Z,1687964299.841 [transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2023-06-28T14:58:19.842Z,1687964299.842 [transit:Transit:Wpt1.Waypoint](IMPORTANT): Navigating to waypoint: 43.200169,-86.364899
2023-06-28T14:58:19.843Z,1687964299.843 [transit:StandardEnvelopes:A.AltitudeEnvelope](ERROR): Altitude Measurement is not Active.
2023-06-28T14:58:20.237Z,1687964300.237 [transit:Transit:B.SetSpeed] Running Loop=1
2023-06-28T14:58:20.237Z,1687964300.237 [transit:Transit:A.Pitch] Running Loop=1
2023-06-28T14:58:23.415Z,1687964303.415 [NAL9602](INFO): SBD MO Status=1, MOMSN=14, MT Status=0, MTMSN=0
2023-06-28T14:58:23.473Z,1687964303.473 [NAL9602](INFO): Sent 332 bytes from file Logs/20230627T210934/Courier0013.lzma
2023-06-28T14:58:23.473Z,1687964303.473 [NAL9602](INFO): Packets left to send: 1
2023-06-28T14:58:25.279Z,1687964305.279 [NavChartDb](INFO): # of records loaded: 50000
2023-06-28T14:58:27.063Z,1687964307.063 [DataOverHttps](IMPORTANT): SBD MTMSN=20230628T163735
2023-06-28T14:58:27.066Z,1687964307.066 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003799
2023-06-28T14:58:39.346Z,1687964319.346 [DataOverHttps](INFO): Received command: sched asap "set transit.MinOffshore 0.00001 km;set transit.MinAltitude 2 m;run" 1vy3s 2 2
2023-06-28T14:58:39.358Z,1687964319.358 [CommandExec](IMPORTANT): got command schedule asap "set transit.MinOffshore 0.00001 km;set transit.MinAltitude 2 m;run" 1vy3s 2 2.000000
2023-06-28T14:58:39.358Z,1687964319.358 [CommandExec](IMPORTANT): Scheduling command #2 of 2 with id=1vy3s
2023-06-28T14:58:39.360Z,1687964319.360 [CommandExec](IMPORTANT): Scheduled #3 (#2 of 2 with id='1vy3s'): "set transit.MinOffshore 0.00001 km;set transit.MinAltitude 2 m;run", ASAP
2023-06-28T14:58:40.400Z,1687964320.400 [NavChartDb](INFO): # of records loaded: 55000
2023-06-28T14:58:52.475Z,1687964332.475 [NavChartDb](INFO): # of records loaded: 60000
2023-06-28T14:58:54.154Z,1687964334.154 [NAL9602](INFO): Not Powering down - fast GPS
2023-06-28T14:59:02.880Z,1687964342.880 [NavChartDb](INFO): Done scanning edges of Resources/ElectronicNavigationCharts/US2MI79M.000
2023-06-28T14:59:13.082Z,1687964353.082 [NavChartDb](INFO): # of records loaded: 65000
2023-06-28T14:59:14.918Z,1687964354.918 [DataOverHttps](IMPORTANT): SBD MTMSN=20230628T163823
2023-06-28T14:59:25.300Z,1687964365.300 [DataOverHttps](INFO): Received command: stop
2023-06-28T14:59:25.321Z,1687964365.321 [CommandExec](IMPORTANT): got command stop
2023-06-28T14:59:25.322Z,1687964365.322 [CommandExec](IMPORTANT): Scheduling is paused for 1 commands
2023-06-28T14:59:25.322Z,1687964365.322 [Supervisor](INFO): Stop Mission called by CommandExec::commandStop
2023-06-28T14:59:25.407Z,1687964365.407 [MissionManager](INFO): MissionManager is completed.
2023-06-28T14:59:25.407Z,1687964365.407 [MissionManager](INFO): Uninitializing Mission transit
2023-06-28T14:59:25.407Z,1687964365.407 [transit] Stopped
2023-06-28T14:59:25.407Z,1687964365.407 [transit](DEBUG): Aggregate::uninitialize transit
2023-06-28T14:59:25.407Z,1687964365.407 [transit:StandardEnvelopes] Stopped
2023-06-28T14:59:25.407Z,1687964365.407 [transit:StandardEnvelopes](DEBUG): Aggregate::uninitialize transit:StandardEnvelopes
2023-06-28T14:59:25.407Z,1687964365.407 [transit:StandardEnvelopes:A.AltitudeEnvelope] Stopped
2023-06-28T14:59:25.408Z,1687964365.408 [transit:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent.
2023-06-28T14:59:25.408Z,1687964365.408 [transit:StandardEnvelopes:B.DepthEnvelope] Stopped
2023-06-28T14:59:25.408Z,1687964365.408 [transit:StandardEnvelopes:B.DepthEnvelope](DEBUG): Uninitialize.
2023-06-28T14:59:25.408Z,1687964365.408 [transit:StandardEnvelopes:C.OffshoreEnvelope] Stopped
2023-06-28T14:59:25.408Z,1687964365.408 [transit:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Uninitialize OffshoreEnvelopeComponent.
2023-06-28T14:59:25.408Z,1687964365.408 [transit:BuoyancyHold.Buoyancy] Stopped
2023-06-28T14:59:25.408Z,1687964365.408 [transit:BuoyancyHold.Buoyancy](DEBUG): Uninitialize Buoyancy Component.
2023-06-28T14:59:25.408Z,1687964365.408 [transit:MassHold.Pitch] Stopped
2023-06-28T14:59:25.408Z,1687964365.408 [transit:Transit] Stopped
2023-06-28T14:59:25.408Z,1687964365.408 [transit:Transit](DEBUG): Aggregate::uninitialize transit:Transit
2023-06-28T14:59:25.408Z,1687964365.408 [transit:Transit:A.Pitch] Stopped
2023-06-28T14:59:25.408Z,1687964365.408 [transit:Transit:B.SetSpeed] Stopped
2023-06-28T14:59:25.409Z,1687964365.409 [transit:Transit:B.SetSpeed](DEBUG): Uninitialize.
2023-06-28T14:59:25.409Z,1687964365.409 [transit:Transit:Wpt1.Waypoint] Stopped
2023-06-28T14:59:25.409Z,1687964365.409 [transit:Transit:Wpt1.Waypoint](DEBUG): Uninitialize WaypointComponent.
2023-06-28T14:59:25.752Z,1687964365.752 [MissionManager](IMPORTANT): Started mission Default
2023-06-28T14:59:25.762Z,1687964365.762 [Default] Running Loop=1
2023-06-28T14:59:25.762Z,1687964365.762 [Default](DEBUG): Aggregate::initialize Default
2023-06-28T14:59:25.762Z,1687964365.762 [Default:B.GoToSurface] Running Loop=1
2023-06-28T14:59:25.762Z,1687964365.762 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-06-28T14:59:25.762Z,1687964365.762 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-06-28T14:59:25.763Z,1687964365.763 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-06-28T14:59:25.763Z,1687964365.763 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-06-28T14:59:25.763Z,1687964365.763 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-06-28T14:59:25.763Z,1687964365.763 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-06-28T14:59:25.765Z,1687964365.765 [Default:A.Wait] Running Loop=1
2023-06-28T14:59:25.765Z,1687964365.765 [Default:A.Wait](DEBUG): Initialize Wait Component.
2023-06-28T14:59:30.830Z,1687964370.830 [NavChartDb](INFO): Done scanning nodes of Resources/ElectronicNavigationCharts/US2MI79M.000
2023-06-28T14:59:31.642Z,1687964371.642 [CommandExec](IMPORTANT): got command get distance_from_shore
2023-06-28T14:59:31.642Z,1687964371.642 [CommandExec](FAULT): Element has no value
2023-06-28T14:59:32.416Z,1687964372.416 [NavChartDb](INFO): # of records loaded: 67799
2023-06-28T14:59:32.433Z,1687964372.433 [NavChartDb](IMPORTANT): Loaded Electronic Nav Chart data from US2MI79M.000
2023-06-28T14:59:32.434Z,1687964372.434 [NavChartDb](INFO): Setup scan of Resources/ElectronicNavigationCharts/US2MI80M.000
2023-06-28T14:59:38.780Z,1687964378.780 [Default:A.Wait](INFO): Done Waiting.
2023-06-28T14:59:38.780Z,1687964378.780 [Default:A.Wait] Stopped
2023-06-28T14:59:38.780Z,1687964378.780 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2023-06-28T14:59:39.168Z,1687964379.168 [Default:CheckIn] Running Loop=1
2023-06-28T14:59:39.169Z,1687964379.169 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-06-28T14:59:39.169Z,1687964379.169 [Default:CheckIn:Read_GPS] Running Loop=1
2023-06-28T14:59:41.140Z,1687964381.140 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163850.00,A,4313.39457,N,08620.11474,W,0.078,0.00,280623,,,A*75
2023-06-28T14:59:41.163Z,1687964381.163 [NAL9602](INFO): GPS fix at 20230628T163850: (43.223243, -86.335246)
2023-06-28T14:59:41.225Z,1687964381.225 [Default:CheckIn:Read_GPS] Stopped
2023-06-28T14:59:41.225Z,1687964381.225 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-06-28T14:59:53.739Z,1687964393.739 [NAL9602](INFO): SBD MO Status=0, MOMSN=15, MT Status=0, MTMSN=0
2023-06-28T14:59:53.739Z,1687964393.739 [NAL9602](INFO): No messages in MT queue
2023-06-28T14:59:55.606Z,1687964395.606 [NavChartDb](INFO): Done scanning features of Resources/ElectronicNavigationCharts/US2MI80M.000
2023-06-28T14:59:57.665Z,1687964397.665 [DataOverHttps](INFO): Sending 508 bytes from file Logs/20230627T210934/Courier0013.lzma
2023-06-28T14:59:58.667Z,1687964398.667 [DataOverHttps](INFO): Moved sent file to Logs/20230627T210934/Courier0013.lzma.bak
2023-06-28T14:59:58.667Z,1687964398.667 [DataOverHttps](INFO): SBD MOMSN=18438953
2023-06-28T15:00:15.814Z,1687964415.814 [NavChartDb](INFO): # of records loaded: 5000
2023-06-28T15:00:20.719Z,1687964420.719 [DataOverHttps](INFO): Sending 668 bytes from file Logs/20230627T210934/Courier0016.lzma
2023-06-28T15:00:21.719Z,1687964421.719 [DataOverHttps](INFO): Moved sent file to Logs/20230627T210934/Courier0016.lzma.bak
2023-06-28T15:00:21.719Z,1687964421.719 [DataOverHttps](INFO): SBD MOMSN=18439043
2023-06-28T15:00:24.441Z,1687964424.441 [NAL9602](INFO): Not Powering down - fast GPS
2023-06-28T15:00:30.990Z,1687964430.990 [NavChartDb](INFO): # of records loaded: 10000
2023-06-28T15:00:43.438Z,1687964443.438 [DataOverHttps](INFO): Sending 178 bytes from file Logs/20230627T210934/Courier0019.lzma
2023-06-28T15:00:44.439Z,1687964444.439 [DataOverHttps](INFO): Moved sent file to Logs/20230627T210934/Courier0019.lzma.bak
2023-06-28T15:00:44.439Z,1687964444.439 [DataOverHttps](INFO): SBD MOMSN=18439119
2023-06-28T15:00:45.170Z,1687964445.170 [NavChartDb](INFO): # of records loaded: 15000
2023-06-28T15:00:58.456Z,1687964458.456 [NavChartDb](INFO): # of records loaded: 20000
2023-06-28T15:01:07.089Z,1687964467.089 [DataOverHttps](INFO): Sending 298 bytes from file Logs/20230628T144615/Courier0000.lzma
2023-06-28T15:01:08.090Z,1687964468.090 [DataOverHttps](INFO): Moved sent file to Logs/20230628T144615/Courier0000.lzma.bak
2023-06-28T15:01:08.091Z,1687964468.091 [DataOverHttps](INFO): SBD MOMSN=18439125
2023-06-28T15:01:13.989Z,1687964473.989 [NavChartDb](INFO): # of records loaded: 25000
2023-06-28T15:01:29.302Z,1687964489.302 [NavChartDb](INFO): # of records loaded: 30000
2023-06-28T15:01:29.628Z,1687964489.628 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230628T144615/Courier0004.lzma
2023-06-28T15:01:30.630Z,1687964490.630 [DataOverHttps](INFO): Moved sent file to Logs/20230628T144615/Courier0004.lzma.bak
2023-06-28T15:01:30.631Z,1687964490.631 [DataOverHttps](INFO): SBD MOMSN=18439131
2023-06-28T15:01:43.782Z,1687964503.782 [NavChartDb](INFO): # of records loaded: 35000
2023-06-28T15:01:53.100Z,1687964513.100 [DataOverHttps](INFO): Sending 203 bytes from file Logs/20230628T144615/Courier0007.lzma
2023-06-28T15:01:55.107Z,1687964515.107 [DataOverHttps](INFO): Moved sent file to Logs/20230628T144615/Courier0007.lzma.bak
2023-06-28T15:01:55.107Z,1687964515.107 [DataOverHttps](INFO): SBD MOMSN=18439134
2023-06-28T15:01:59.260Z,1687964519.260 [NavChartDb](INFO): # of records loaded: 40000
2023-06-28T15:02:29.120Z,1687964549.120 [NavChartDb](INFO): # of records loaded: 45000
2023-06-28T15:02:29.564Z,1687964549.564 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20230628T144615/Courier0010.lzma
2023-06-28T15:02:30.567Z,1687964550.567 [DataOverHttps](INFO): Moved sent file to Logs/20230628T144615/Courier0010.lzma.bak
2023-06-28T15:02:30.567Z,1687964550.567 [DataOverHttps](INFO): SBD MOMSN=18439138
2023-06-28T15:02:36.469Z,1687964556.469 [CommandExec](IMPORTANT): got command get distance_from_shore
2023-06-28T15:02:36.469Z,1687964556.469 [CommandExec](FAULT): Element has no value
2023-06-28T15:02:44.629Z,1687964564.629 [NavChartDb](INFO): # of records loaded: 50000
2023-06-28T15:02:53.908Z,1687964573.908 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20230628T144615/Courier0013.lzma
2023-06-28T15:02:54.911Z,1687964574.911 [DataOverHttps](INFO): Moved sent file to Logs/20230628T144615/Courier0013.lzma.bak
2023-06-28T15:02:54.911Z,1687964574.911 [DataOverHttps](INFO): SBD MOMSN=18439140
2023-06-28T15:02:58.808Z,1687964578.808 [NavChartDb](INFO): # of records loaded: 55000
2023-06-28T15:03:11.526Z,1687964591.526 [NavChartDb](INFO): # of records loaded: 60000
2023-06-28T15:03:18.040Z,1687964598.040 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20230627T140714/Express0020.lzma
2023-06-28T15:03:19.042Z,1687964599.042 [DataOverHttps](INFO): Moved sent file to Logs/20230627T140714/Express0020.lzma.bak
2023-06-28T15:03:19.043Z,1687964599.043 [DataOverHttps](INFO): SBD MOMSN=18439144
2023-06-28T15:03:25.979Z,1687964605.979 [NavChartDb](INFO): # of records loaded: 65000
2023-06-28T15:03:39.717Z,1687964619.717 [NavChartDb](INFO): # of records loaded: 70000
2023-06-28T15:03:42.303Z,1687964622.303 [DataOverHttps](INFO): Sending 958 bytes from file Logs/20230627T193117/Express0001.lzma
2023-06-28T15:03:43.310Z,1687964623.310 [DataOverHttps](INFO): Moved sent file to Logs/20230627T193117/Express0001.lzma.bak
2023-06-28T15:03:43.311Z,1687964623.311 [DataOverHttps](INFO): SBD MOMSN=18439152
2023-06-28T15:03:57.192Z,1687964637.192 [NavChartDb](INFO): Calculating coverage of Resources/ElectronicNavigationCharts/US2MI80M.000
2023-06-28T15:04:04.584Z,1687964644.584 [NavChartDb](INFO): Done scanning edges of Resources/ElectronicNavigationCharts/US2MI80M.000
2023-06-28T15:04:16.794Z,1687964656.794 [DataOverHttps](INFO): Sending 367 bytes from file Logs/20230627T193117/Express0005.lzma
2023-06-28T15:04:18.794Z,1687964658.794 [DataOverHttps](INFO): Moved sent file to Logs/20230627T193117/Express0005.lzma.bak
2023-06-28T15:04:18.795Z,1687964658.795 [DataOverHttps](INFO): SBD MOMSN=18439177
2023-06-28T15:04:21.961Z,1687964661.961 [NavChartDb](INFO): # of records loaded: 75000
2023-06-28T15:04:40.356Z,1687964680.356 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20230627T193117/Express0008.lzma
2023-06-28T15:04:41.358Z,1687964681.358 [DataOverHttps](INFO): Moved sent file to Logs/20230627T193117/Express0008.lzma.bak
2023-06-28T15:04:41.359Z,1687964681.359 [DataOverHttps](INFO): SBD MOMSN=18439203
2023-06-28T15:05:07.695Z,1687964707.695 [DataOverHttps](INFO): Sending 875 bytes from file Logs/20230627T200947/Express0001.lzma
2023-06-28T15:05:10.703Z,1687964710.703 [DataOverHttps](INFO): Moved sent file to Logs/20230627T200947/Express0001.lzma.bak
2023-06-28T15:05:10.703Z,1687964710.703 [DataOverHttps](INFO): SBD MOMSN=18439205
2023-06-28T15:05:13.823Z,1687964713.823 [NavChartDb](INFO): # of records loaded: 80000
2023-06-28T15:05:30.114Z,1687964730.114 [NavChartDb](INFO): Done scanning nodes of Resources/ElectronicNavigationCharts/US2MI80M.000
2023-06-28T15:05:32.304Z,1687964732.304 [NavChartDb](INFO): # of records loaded: 83074
2023-06-28T15:05:32.414Z,1687964732.414 [NavChartDb](IMPORTANT): Loaded Electronic Nav Chart data from US2MI80M.000
2023-06-28T15:05:32.415Z,1687964732.415 [NavChartDb](INFO): Setup scan of Resources/ElectronicNavigationCharts/US2MI01M.000
2023-06-28T15:05:33.773Z,1687964733.773 [NavChartDb](INFO): Done scanning features of Resources/ElectronicNavigationCharts/US2MI01M.000
2023-06-28T15:05:35.172Z,1687964735.172 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20230627T200947/Express0005.lzma
2023-06-28T15:05:36.175Z,1687964736.175 [DataOverHttps](INFO): Moved sent file to Logs/20230627T200947/Express0005.lzma.bak
2023-06-28T15:05:36.175Z,1687964736.175 [DataOverHttps](INFO): SBD MOMSN=18439229
2023-06-28T15:05:46.380Z,1687964746.380 [NavChartDb](INFO): # of records loaded: 5000
2023-06-28T15:05:51.529Z,1687964751.529 [NavChartDb](INFO): Calculating coverage of Resources/ElectronicNavigationCharts/US2MI01M.000
2023-06-28T15:05:51.943Z,1687964751.943 [NavChartDb](INFO): Done scanning edges of Resources/ElectronicNavigationCharts/US2MI01M.000
2023-06-28T15:06:00.172Z,1687964760.172 [NavChartDb](INFO): Done scanning nodes of Resources/ElectronicNavigationCharts/US2MI01M.000
2023-06-28T15:06:03.273Z,1687964763.273 [NavChartDb](INFO): # of records loaded: 7824
2023-06-28T15:06:03.276Z,1687964763.276 [NavChartDb](IMPORTANT): Loaded Electronic Nav Chart data from US2MI01M.000
2023-06-28T15:06:05.211Z,1687964765.211 [DataOverHttps](INFO): Sending 832 bytes from file Logs/20230627T201556/Express0001.lzma
2023-06-28T15:06:06.220Z,1687964766.220 [DataOverHttps](INFO): Moved sent file to Logs/20230627T201556/Express0001.lzma.bak
2023-06-28T15:06:06.220Z,1687964766.220 [DataOverHttps](INFO): SBD MOMSN=18439235
2023-06-28T15:06:11.544Z,1687964771.544 [NavChartDb](INFO): Creating index for soundings
2023-06-28T15:06:28.220Z,1687964788.220 [CommandExec](IMPORTANT): got command get distance_from_shore
2023-06-28T15:06:28.221Z,1687964788.221 [CommandExec](FAULT): Element has no value
2023-06-28T15:06:37.902Z,1687964797.902 [DataOverHttps](INFO): Sending 1554 bytes from file Logs/20230627T201719/Express0001.lzma
2023-06-28T15:06:38.899Z,1687964798.899 [DataOverHttps](INFO): Moved sent file to Logs/20230627T201719/Express0001.lzma.bak
2023-06-28T15:06:38.899Z,1687964798.899 [DataOverHttps](INFO): SBD MOMSN=18439263
2023-06-28T15:06:51.282Z,1687964811.282 [NavChartDb](INFO): Creating index for 0p0
2023-06-28T15:06:56.671Z,1687964816.671 [NavChartDb](INFO): Creating index for 0p6
2023-06-28T15:06:56.774Z,1687964816.774 [NavChartDb](INFO): Creating index for 0p9
2023-06-28T15:07:03.482Z,1687964823.482 [DataOverHttps](INFO): Sending 486 bytes from file Logs/20230627T201719/Express0005.lzma
2023-06-28T15:07:05.486Z,1687964825.486 [DataOverHttps](INFO): Moved sent file to Logs/20230627T201719/Express0005.lzma.bak
2023-06-28T15:07:05.487Z,1687964825.487 [DataOverHttps](INFO): SBD MOMSN=18439314
2023-06-28T15:07:06.116Z,1687964826.116 [NavChartDb](INFO): Creating index for 1p8
2023-06-28T15:07:17.733Z,1687964837.733 [NavChartDb](INFO): Creating index for 3p6
2023-06-28T15:07:28.267Z,1687964848.267 [NavChartDb](INFO): Creating index for 5p4
2023-06-28T15:07:31.029Z,1687964851.029 [DataOverHttps](INFO): Sending 1766 bytes from file Logs/20230627T201719/Express0008.lzma
2023-06-28T15:07:33.334Z,1687964853.334 [DataOverHttps](INFO): Moved sent file to Logs/20230627T201719/Express0008.lzma.bak
2023-06-28T15:07:33.335Z,1687964853.335 [DataOverHttps](INFO): SBD MOMSN=18439327
2023-06-28T15:07:46.434Z,1687964866.434 [NavChartDb](INFO): Creating index for 7p3
2023-06-28T15:07:59.756Z,1687964879.756 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20230627T205857/Express0001.lzma
2023-06-28T15:08:00.762Z,1687964880.762 [DataOverHttps](INFO): Moved sent file to Logs/20230627T205857/Express0001.lzma.bak
2023-06-28T15:08:00.763Z,1687964880.763 [DataOverHttps](INFO): SBD MOMSN=18439500
2023-06-28T15:08:14.768Z,1687964894.768 [NavChartDb](INFO): Creating index for 9p1
2023-06-28T15:08:18.141Z,1687964898.141 [NavChartDb](INFO): Creating index for 18p2
2023-06-28T15:08:24.586Z,1687964904.586 [DataOverHttps](INFO): Sending 450 bytes from file Logs/20230627T210034/Express0001.lzma
2023-06-28T15:08:25.587Z,1687964905.587 [DataOverHttps](INFO): Moved sent file to Logs/20230627T210034/Express0001.lzma.bak
2023-06-28T15:08:25.587Z,1687964905.587 [DataOverHttps](INFO): SBD MOMSN=18439502
2023-06-28T15:08:41.155Z,1687964921.155 [DataOverHttps](INFO): Sending 885 bytes from file Logs/20230627T210330/Express0001.lzma
2023-06-28T15:08:43.206Z,1687964923.206 [DataOverHttps](INFO): Moved sent file to Logs/20230627T210330/Express0001.lzma.bak
2023-06-28T15:08:43.207Z,1687964923.207 [DataOverHttps](INFO): SBD MOMSN=18439516
2023-06-28T15:09:01.461Z,1687964941.461 [DataOverHttps](INFO): Sending 1798 bytes from file Logs/20230627T210934/Express0001.lzma
2023-06-28T15:09:02.459Z,1687964942.459 [DataOverHttps](INFO): Moved sent file to Logs/20230627T210934/Express0001.lzma.bak
2023-06-28T15:09:02.459Z,1687964942.459 [DataOverHttps](INFO): SBD MOMSN=18439553
2023-06-28T15:09:22.155Z,1687964962.155 [DataOverHttps](INFO): Sending 557 bytes from file Logs/20230627T210934/Express0005.lzma
2023-06-28T15:09:23.235Z,1687964963.235 [DataOverHttps](INFO): Moved sent file to Logs/20230627T210934/Express0005.lzma.bak
2023-06-28T15:09:23.235Z,1687964963.235 [DataOverHttps](INFO): SBD MOMSN=18439630
2023-06-28T15:09:39.790Z,1687964979.790 [DataOverHttps](INFO): Sending 3077 bytes from file Logs/20230627T210934/Express0008.lzma
2023-06-28T15:09:44.802Z,1687964984.802 [DataOverHttps](INFO): Moved sent file to Logs/20230627T210934/Express0008.lzma.bak
2023-06-28T15:09:44.803Z,1687964984.803 [DataOverHttps](INFO): SBD MOMSN=18439656
2023-06-28T15:10:04.223Z,1687965004.223 [DataOverHttps](INFO): Sending 936 bytes from file Logs/20230627T210934/Express0011.lzma
2023-06-28T15:10:05.223Z,1687965005.223 [DataOverHttps](INFO): Moved sent file to Logs/20230627T210934/Express0011.lzma.bak
2023-06-28T15:10:05.223Z,1687965005.223 [DataOverHttps](INFO): SBD MOMSN=18440033
2023-06-28T15:10:20.847Z,1687965020.847 [DataOverHttps](INFO): Sending 805 bytes from file Logs/20230627T210934/Express0014.lzma
2023-06-28T15:10:21.846Z,1687965021.846 [DataOverHttps](INFO): Moved sent file to Logs/20230627T210934/Express0014.lzma.bak
2023-06-28T15:10:21.847Z,1687965021.847 [DataOverHttps](INFO): SBD MOMSN=18440143
2023-06-28T15:10:32.903Z,1687965032.903 [CommandExec](IMPORTANT): got command get distance_from_shore
2023-06-28T15:10:32.904Z,1687965032.904 [CommandExec](IMPORTANT): distance_from_shore 88.562515 m
2023-06-28T15:10:47.250Z,1687965047.250 [DataOverHttps](INFO): Sending 2835 bytes from file Logs/20230627T210934/Express0017.lzma
2023-06-28T15:10:48.246Z,1687965048.246 [DataOverHttps](INFO): Moved sent file to Logs/20230627T210934/Express0017.lzma.bak
2023-06-28T15:10:48.247Z,1687965048.247 [DataOverHttps](INFO): SBD MOMSN=18440248
2023-06-28T15:11:07.884Z,1687965067.884 [DataOverHttps](INFO): Sending 1888 bytes from file Logs/20230627T210934/Express0020.lzma
2023-06-28T15:11:20.947Z,1687965080.947 [DataOverHttps](INFO): Moved sent file to Logs/20230627T210934/Express0020.lzma.bak
2023-06-28T15:11:20.947Z,1687965080.947 [DataOverHttps](INFO): SBD MOMSN=18440578
2023-06-28T15:12:00.094Z,1687965120.094 [DataOverHttps](INFO): Sending 1429 bytes from file Logs/20230628T144615/Express0001.lzma
2023-06-28T15:12:05.110Z,1687965125.110 [DataOverHttps](INFO): Moved sent file to Logs/20230628T144615/Express0001.lzma.bak
2023-06-28T15:12:05.111Z,1687965125.111 [DataOverHttps](INFO): SBD MOMSN=18440705
2023-06-28T15:12:37.505Z,1687965157.505 [DataOverHttps](INFO): Exceeded connection timeout, disconnecting.
2023-06-28T15:13:05.625Z,1687965185.625 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.515392
2023-06-28T15:13:25.143Z,1687965205.143 [NAL9602](INFO): SBD MO Status=1, MOMSN=16, MT Status=0, MTMSN=0
2023-06-28T15:13:25.192Z,1687965205.192 [NAL9602](INFO): Sent 203 bytes from file Logs/20230628T144615/Express0005.lzma
2023-06-28T15:13:25.192Z,1687965205.192 [NAL9602](INFO): Packets left to send: 0
2023-06-28T15:13:34.110Z,1687965214.110 [NAL9602](INFO): SBD MO Status=1, MOMSN=17, MT Status=0, MTMSN=0
2023-06-28T15:13:34.157Z,1687965214.157 [NAL9602](INFO): Sent 332 bytes from file Logs/20230628T144615/Express0008.lzma
2023-06-28T15:13:34.157Z,1687965214.157 [NAL9602](INFO): Packets left to send: 3
2023-06-28T15:13:36.765Z,1687965216.765 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-06-28T15:13:51.819Z,1687965231.819 [NAL9602](INFO): SBD MO Status=2, MOMSN=18, MT Status=2, MTMSN=0
2023-06-28T15:13:51.819Z,1687965231.819 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-06-28T15:14:11.917Z,1687965251.917 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-06-28T15:14:33.867Z,1687965273.867 [NAL9602](INFO): SBD MO Status=1, MOMSN=18, MT Status=0, MTMSN=0
2023-06-28T15:14:33.921Z,1687965273.921 [NAL9602](INFO): Sent 332 bytes from file Logs/20230628T144615/Express0008.lzma
2023-06-28T15:14:33.921Z,1687965273.921 [NAL9602](INFO): Packets left to send: 2
2023-06-28T15:14:47.065Z,1687965287.065 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-06-28T15:14:56.104Z,1687965296.104 [NAL9602](INFO): SBD MO Status=1, MOMSN=19, MT Status=0, MTMSN=0
2023-06-28T15:14:56.161Z,1687965296.161 [NAL9602](INFO): Sent 332 bytes from file Logs/20230628T144615/Express0008.lzma
2023-06-28T15:14:56.161Z,1687965296.161 [NAL9602](INFO): Packets left to send: 1
2023-06-28T15:15:06.627Z,1687965306.627 [NAL9602](INFO): SBD MO Status=1, MOMSN=20, MT Status=0, MTMSN=0
2023-06-28T15:15:06.681Z,1687965306.681 [NAL9602](INFO): Sent 82 bytes from file Logs/20230628T144615/Express0008.lzma
2023-06-28T15:15:06.682Z,1687965306.682 [NAL9602](INFO): Packets left to send: 0
2023-06-28T15:15:22.205Z,1687965322.205 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-06-28T15:15:22.495Z,1687965322.495 [NAL9602](INFO): SBD MO Status=2, MOMSN=21, MT Status=2, MTMSN=0
2023-06-28T15:15:22.495Z,1687965322.495 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-06-28T15:15:43.611Z,1687965343.611 [NAL9602](INFO): SBD MO Status=2, MOMSN=21, MT Status=2, MTMSN=0
2023-06-28T15:15:43.611Z,1687965343.611 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-06-28T15:15:57.345Z,1687965357.345 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-06-28T15:16:11.639Z,1687965371.639 [NAL9602](INFO): SBD MO Status=2, MOMSN=21, MT Status=2, MTMSN=0
2023-06-28T15:16:11.639Z,1687965371.639 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-06-28T15:16:32.485Z,1687965392.485 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-06-28T15:16:41.495Z,1687965401.495 [NAL9602](INFO): SBD MO Status=2, MOMSN=21, MT Status=2, MTMSN=0
2023-06-28T15:16:41.495Z,1687965401.495 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-06-28T15:17:07.669Z,1687965427.669 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-06-28T15:17:09.911Z,1687965429.911 [NAL9602](INFO): SBD MO Status=2, MOMSN=21, MT Status=2, MTMSN=0
2023-06-28T15:17:09.911Z,1687965429.911 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-06-28T15:17:30.123Z,1687965450.123 [NAL9602](INFO): SBD MO Status=1, MOMSN=21, MT Status=0, MTMSN=0
2023-06-28T15:17:30.189Z,1687965450.189 [NAL9602](INFO): Sent 327 bytes from file Logs/20230628T144615/Express0011.lzma
2023-06-28T15:17:30.190Z,1687965450.190 [NAL9602](INFO): Packets left to send: 0
2023-06-28T15:17:38.211Z,1687965458.211 [NAL9602](INFO): SBD MO Status=1, MOMSN=22, MT Status=0, MTMSN=0
2023-06-28T15:17:38.272Z,1687965458.272 [NAL9602](INFO): Sent 332 bytes from file Logs/20230628T144615/Express0014.lzma
2023-06-28T15:17:38.272Z,1687965458.272 [NAL9602](INFO): Packets left to send: 2
2023-06-28T15:17:42.813Z,1687965462.813 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-06-28T15:17:46.436Z,1687965466.436 [NAL9602](INFO): SBD MO Status=1, MOMSN=23, MT Status=0, MTMSN=0
2023-06-28T15:17:46.493Z,1687965466.493 [NAL9602](INFO): Sent 332 bytes from file Logs/20230628T144615/Express0014.lzma
2023-06-28T15:17:46.493Z,1687965466.493 [NAL9602](INFO): Packets left to send: 1
2023-06-28T15:17:56.433Z,1687965476.433 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003120
2023-06-28T15:17:57.960Z,1687965477.960 [NAL9602](INFO): SBD MO Status=2, MOMSN=24, MT Status=2, MTMSN=0
2023-06-28T15:17:57.960Z,1687965477.960 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-06-28T15:18:07.585Z,1687965487.585 [DataOverHttps](INFO): Sending 685 bytes from file Logs/20230628T144615/Express0014.lzma
2023-06-28T15:18:08.586Z,1687965488.586 [DataOverHttps](INFO): Moved sent file to Logs/20230628T144615/Express0014.lzma.bak
2023-06-28T15:18:08.587Z,1687965488.587 [DataOverHttps](INFO): SBD MOMSN=18440824
2023-06-28T15:18:24.192Z,1687965504.192 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20230628T144615/Express0017.lzma
2023-06-28T15:18:27.202Z,1687965507.202 [DataOverHttps](INFO): Moved sent file to Logs/20230628T144615/Express0017.lzma.bak
2023-06-28T15:18:27.203Z,1687965507.203 [DataOverHttps](INFO): SBD MOMSN=18440857
2023-06-28T15:18:28.677Z,1687965508.677 [NAL9602](INFO): Not Powering down - fast GPS
2023-06-28T15:18:29.101Z,1687965509.101 [Default:CheckIn:Read_Iridium] Stopped
2023-06-28T15:18:29.102Z,1687965509.102 [Default:CheckIn:C.Wait] Running Loop=1
2023-06-28T15:18:29.102Z,1687965509.102 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-06-28T15:22:09.222Z,1687965729.222 [DataOverHttps](IMPORTANT): SBD MTMSN=20230628T170117
2023-06-28T15:22:16.524Z,1687965736.524 [DataOverHttps](INFO): Received command: restart app
2023-06-28T15:22:16.526Z,1687965736.526 [CommandExec](IMPORTANT): got command restart application
2023-06-28T15:22:17.529Z,1687965737.529 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread.
2023-06-28T15:22:17.529Z,1687965737.529 [CommandExec](INFO): Uninitializing the command executive.
2023-06-28T15:22:17.529Z,1687965737.529 [CommandExec](INFO): Uninitializing the command scheduler.
2023-06-28T15:22:17.529Z,1687965737.529 [CommandExec ThreadHandler](INFO): Thread cancelled.
2023-06-28T15:22:17.598Z,1687965737.598 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye!
2023-06-28T15:22:17.598Z,1687965737.598 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2023-06-28T15:22:17.598Z,1687965737.598 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2023-06-28T15:22:17.599Z,1687965737.599 [NavChartDb](INFO): Join timeout helper Thread ID is 1147
2023-06-28T15:22:17.661Z,1687965737.661 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2023-06-28T15:22:17.661Z,1687965737.661 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2023-06-28T15:22:17.680Z,1687965737.680 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2023-06-28T15:22:17.680Z,1687965737.680 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2023-06-28T15:22:17.681Z,1687965737.681 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 1148
2023-06-28T15:22:17.941Z,1687965737.941 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2023-06-28T15:22:17.941Z,1687965737.941 [WetLabsBB2FL](INFO): Powering down
2023-06-28T15:22:17.942Z,1687965737.942 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2023-06-28T15:22:17.945Z,1687965737.945 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2023-06-28T15:22:17.945Z,1687965737.945 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2023-06-28T15:22:17.945Z,1687965737.945 [CTD_Seabird](INFO): Join timeout helper Thread ID is 1149
2023-06-28T15:22:18.298Z,1687965738.298 [CTD_Seabird](INFO): Powering down
2023-06-28T15:22:18.314Z,1687965738.314 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2023-06-28T15:22:18.315Z,1687965738.315 [CTD_Seabird](INFO): Powering down
2023-06-28T15:22:18.329Z,1687965738.329 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2023-06-28T15:22:18.335Z,1687965738.335 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2023-06-28T15:22:18.336Z,1687965738.336 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2023-06-28T15:22:18.336Z,1687965738.336 [Radio_Surface](INFO): Join timeout helper Thread ID is 1150
2023-06-28T15:22:18.725Z,1687965738.725 [Radio_Surface](INFO): Powering down
2023-06-28T15:22:18.726Z,1687965738.726 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2023-06-28T15:22:18.726Z,1687965738.726 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2023-06-28T15:22:18.737Z,1687965738.737 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler
2023-06-28T15:22:18.737Z,1687965738.737 [Onboard ThreadHandler](INFO): Thread cancelled.
2023-06-28T15:22:18.737Z,1687965738.737 [Onboard](INFO): Join timeout helper Thread ID is 1151
2023-06-28T15:22:19.185Z,1687965739.185 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread.
2023-06-28T15:22:19.185Z,1687965739.185 [Onboard ThreadHandler](INFO): Thread cancelled.
2023-06-28T15:22:19.201Z,1687965739.201 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2023-06-28T15:22:19.201Z,1687965739.201 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2023-06-28T15:22:19.202Z,1687965739.202 [DataOverHttps](INFO): Join timeout helper Thread ID is 1152
2023-06-28T15:22:19.533Z,1687965739.533 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2023-06-28T15:22:19.533Z,1687965739.533 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2023-06-28T15:22:19.549Z,1687965739.549 [ComponentRegistry](INFO): Shutting down BackseatComponent ThreadHandler
2023-06-28T15:22:19.549Z,1687965739.549 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2023-06-28T15:22:19.550Z,1687965739.550 [BackseatComponent](INFO): Join timeout helper Thread ID is 1153
2023-06-28T15:22:19.693Z,1687965739.693 [BackseatComponent ThreadHandler](INFO): Uninitializing protected caller thread.
2023-06-28T15:22:19.693Z,1687965739.693 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2023-06-28T15:22:19.709Z,1687965739.709 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2023-06-28T15:22:19.709Z,1687965739.709 [logger ThreadHandler](INFO): Thread cancelled.
2023-06-28T15:22:19.710Z,1687965739.710 [logger](INFO): Join timeout helper Thread ID is 1154
2023-06-28T15:22:19.725Z,1687965739.725 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2023-06-28T15:22:19.725Z,1687965739.725 [logger ThreadHandler](INFO): Thread cancelled.
2023-06-28T15:22:19.729Z,1687965739.729 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2023-06-28T15:22:19.729Z,1687965739.729 [CommandLine ThreadHandler](INFO): Thread cancelled.
2023-06-28T15:22:19.730Z,1687965739.730 [CommandLine](INFO): Join timeout helper Thread ID is 1155
2023-06-28T15:22:19.825Z,1687965739.825 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2023-06-28T15:22:19.825Z,1687965739.825 [CommandLine ThreadHandler](INFO): Thread cancelled.
2023-06-28T15:22:19.829Z,1687965739.829 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler
2023-06-28T15:22:19.829Z,1687965739.829 [CommandExec ThreadHandler](INFO): Thread cancelled.
2023-06-28T15:22:19.830Z,1687965739.830 [CommandExec](INFO): Join timeout helper Thread ID is 1156
2023-06-28T15:22:19.831Z,1687965739.831 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2023-06-28T15:22:19.831Z,1687965739.831 [controlThread ThreadHandler](INFO): Thread cancelled.
2023-06-28T15:22:19.831Z,1687965739.831 [controlThread](INFO): Join timeout helper Thread ID is 1157
2023-06-28T15:22:20.153Z,1687965740.153 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2023-06-28T15:22:20.153Z,1687965740.153 [controlThread](DEBUG): Uninitializing ControlThread
2023-06-28T15:22:20.153Z,1687965740.153 [AHRS_M2](INFO): Powering down
2023-06-28T15:22:20.226Z,1687965740.226 [NAL9602](INFO): Powering down
2023-06-28T15:22:20.227Z,1687965740.227 [Sonardyne_Nano](INFO): Powering down
2023-06-28T15:22:20.346Z,1687965740.346 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2023-06-28T15:22:20.346Z,1687965740.346 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2023-06-28T15:22:20.347Z,1687965740.347 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2023-06-28T15:22:20.347Z,1687965740.347 [MissionManager](INFO): Uninitializing Mission Default
2023-06-28T15:22:20.347Z,1687965740.347 [Default] Stopped
2023-06-28T15:22:20.348Z,1687965740.348 [Default](DEBUG): Aggregate::uninitialize Default
2023-06-28T15:22:20.348Z,1687965740.348 [Default:B.GoToSurface] Stopped
2023-06-28T15:22:20.348Z,1687965740.348 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2023-06-28T15:22:20.348Z,1687965740.348 [Default:CheckIn] Stopped
2023-06-28T15:22:20.348Z,1687965740.348 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-06-28T15:22:20.348Z,1687965740.348 [Default:CheckIn:C.Wait] Stopped
2023-06-28T15:22:20.348Z,1687965740.348 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-06-28T15:22:20.351Z,1687965740.351 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2023-06-28T15:22:20.351Z,1687965740.351 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2023-06-28T15:22:20.351Z,1687965740.351 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2023-06-28T15:22:20.352Z,1687965740.352 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2023-06-28T15:22:20.352Z,1687965740.352 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2023-06-28T15:22:20.352Z,1687965740.352 [BuoyancyServo](INFO): Powering down
2023-06-28T15:22:20.365Z,1687965740.365 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2023-06-28T15:22:20.365Z,1687965740.365 [ElevatorServo](INFO): Powering down
2023-06-28T15:22:20.366Z,1687965740.366 [MassServo](DEBUG): Uninitialize Mass Servo.
2023-06-28T15:22:20.366Z,1687965740.366 [MassServo](INFO): Powering down
2023-06-28T15:22:20.367Z,1687965740.367 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2023-06-28T15:22:20.367Z,1687965740.367 [RudderServo](INFO): Powering down
2023-06-28T15:22:20.368Z,1687965740.368 [ThrusterHE](DEBUG): Uninitialize Thruster Servo.
2023-06-28T15:22:20.368Z,1687965740.368 [ThrusterHE](INFO): Powering down
2023-06-28T15:22:20.369Z,1687965740.369 [SBIT](DEBUG): Uninitialize SBIT Component.
2023-06-28T15:22:20.369Z,1687965740.369 [IBIT](DEBUG): Uninitialize IBIT Component.
2023-06-28T15:22:20.369Z,1687965740.369 [CBIT](DEBUG): Uninitialize CBIT Component.
2023-06-28T15:22:20.370Z,1687965740.370 [CBIT](DEBUG): Powering off loads.
2023-06-28T15:22:20.380Z,1687965740.380 [CBIT](DEBUG): Disabling WDT.
2023-06-28T15:22:20.392Z,1687965740.392 [CBIT](DEBUG): Opening all GF detection circuits.
2023-06-28T15:22:20.394Z,1687965740.394 [controlThread ThreadHandler](INFO): Thread cancelled.
2023-06-28T15:22:20.451Z,1687965740.451 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2023-06-28T15:22:20.454Z,1687965740.454 [Onboard ThreadHandler](INFO): Thread cancelled.
2023-06-28T15:22:20.460Z,1687965740.460 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2023-06-28T15:22:20.505Z,1687965740.505 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2023-06-28T15:22:20.546Z,1687965740.546 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2023-06-28T15:22:20.549Z,1687965740.549 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2023-06-28T15:22:20.585Z,1687965740.585 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2023-06-28T15:22:20.648Z,1687965740.648 [logger ThreadHandler](INFO): Thread cancelled.