2022-09-01T15:39:23.540Z,1662046763.540 [Supervisor](DEBUG): Initializing supervisor.
2022-09-01T15:39:23.544Z,1662046763.544 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2022-09-01T15:39:23.544Z,1662046763.544 [SyncHandler](INFO): Protected caller Thread ID is 6282
2022-09-01T15:39:23.545Z,1662046763.545 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2022-09-01T15:39:23.546Z,1662046763.546 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2022-09-01T15:39:23.546Z,1662046763.546 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 6283
2022-09-01T15:39:23.550Z,1662046763.550 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2022-09-01T15:39:23.567Z,1662046763.567 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2022-09-01T15:39:23.568Z,1662046763.568 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2022-09-01T15:39:23.568Z,1662046763.568 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 6284
2022-09-01T15:39:23.572Z,1662046763.572 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2022-09-01T15:39:23.573Z,1662046763.573 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2022-09-01T15:39:23.574Z,1662046763.574 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 6285
2022-09-01T15:39:23.576Z,1662046763.576 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2022-09-01T15:39:23.577Z,1662046763.577 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2022-09-01T15:39:23.577Z,1662046763.577 [logger ThreadHandler](INFO): Protected caller Thread ID is 6286
2022-09-01T15:39:23.581Z,1662046763.581 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2022-09-01T15:39:23.581Z,1662046763.581 [Supervisor](INFO): Looking for Config files in directory: Config/
2022-09-01T15:39:23.583Z,1662046763.583 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2022-09-01T15:39:23.979Z,1662046763.979 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2022-09-01T15:39:23.980Z,1662046763.980 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2022-09-01T15:39:24.056Z,1662046764.056 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2022-09-01T15:39:24.374Z,1662046764.374 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2022-09-01T15:39:24.374Z,1662046764.374 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2022-09-01T15:39:24.477Z,1662046764.477 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2022-09-01T15:39:24.478Z,1662046764.478 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2022-09-01T15:39:24.666Z,1662046764.666 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2022-09-01T15:39:24.667Z,1662046764.667 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2022-09-01T15:39:25.131Z,1662046765.131 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2022-09-01T15:39:25.132Z,1662046765.132 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2022-09-01T15:39:25.391Z,1662046765.391 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2022-09-01T15:39:25.391Z,1662046765.391 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2022-09-01T15:39:25.599Z,1662046765.599 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2022-09-01T15:39:25.600Z,1662046765.600 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2022-09-01T15:39:25.784Z,1662046765.784 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2022-09-01T15:39:25.785Z,1662046765.785 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2022-09-01T15:39:25.880Z,1662046765.880 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2022-09-01T15:39:25.880Z,1662046765.880 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2022-09-01T15:39:26.095Z,1662046766.095 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2022-09-01T15:39:26.096Z,1662046766.096 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2022-09-01T15:39:26.597Z,1662046766.597 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2022-09-01T15:39:26.598Z,1662046766.598 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2022-09-01T15:39:26.676Z,1662046766.676 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2022-09-01T15:39:26.811Z,1662046766.811 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2022-09-01T15:39:26.812Z,1662046766.812 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2022-09-01T15:39:27.497Z,1662046767.497 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2022-09-01T15:39:27.497Z,1662046767.497 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2022-09-01T15:39:27.848Z,1662046767.848 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2022-09-01T15:39:27.850Z,1662046767.850 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-polaris/
2022-09-01T15:39:27.851Z,1662046767.851 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/vehicle.cfg
2022-09-01T15:39:28.046Z,1662046768.046 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Control.cfg
2022-09-01T15:39:28.144Z,1662046768.144 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Estimation.cfg
2022-09-01T15:39:28.240Z,1662046768.240 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/BIT.cfg
2022-09-01T15:39:28.433Z,1662046768.433 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Battery.cfg
2022-09-01T15:39:29.085Z,1662046769.085 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2022-09-01T15:39:29.085Z,1662046769.085 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Simulator.cfg
2022-09-01T15:39:29.192Z,1662046769.192 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Navigation.cfg
2022-09-01T15:39:29.293Z,1662046769.293 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Derivation.cfg
2022-09-01T15:39:29.411Z,1662046769.411 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/logger.cfg
2022-09-01T15:39:29.520Z,1662046769.520 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/secure.cfg
2022-09-01T15:39:29.602Z,1662046769.602 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Dock.cfg
2022-09-01T15:39:29.686Z,1662046769.686 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Servo.cfg
2022-09-01T15:39:29.793Z,1662046769.793 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/workSite.cfg
2022-09-01T15:39:29.896Z,1662046769.896 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Sensor.cfg
2022-09-01T15:39:30.164Z,1662046770.164 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Science.cfg
2022-09-01T15:39:30.317Z,1662046770.317 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg
2022-09-01T15:39:30.318Z,1662046770.318 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2022-09-01T15:39:30.725Z,1662046770.725 [AHRS_M2] Loaded
2022-09-01T15:39:30.725Z,1662046770.725 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2022-09-01T15:39:31.492Z,1662046771.492 [BPC1] Loaded
2022-09-01T15:39:31.493Z,1662046771.493 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2022-09-01T15:39:31.572Z,1662046771.572 [DataOverHttps] Loaded
2022-09-01T15:39:31.572Z,1662046771.572 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2022-09-01T15:39:31.573Z,1662046771.573 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 407E44E0
2022-09-01T15:39:31.574Z,1662046771.574 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 6383
2022-09-01T15:39:31.593Z,1662046771.593 [Depth_Keller] Loaded
2022-09-01T15:39:31.593Z,1662046771.593 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2022-09-01T15:39:31.598Z,1662046771.598 [DropWeight] Loaded
2022-09-01T15:39:31.598Z,1662046771.598 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2022-09-01T15:39:31.648Z,1662046771.648 [Micromodem] Loaded
2022-09-01T15:39:31.648Z,1662046771.648 [ComponentRegistry](DEBUG): SyncComponent "Micromodem" handled in the control thread.
2022-09-01T15:39:31.709Z,1662046771.709 [NAL9602] Loaded
2022-09-01T15:39:31.709Z,1662046771.709 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2022-09-01T15:39:31.737Z,1662046771.737 [Onboard] Loaded
2022-09-01T15:39:31.738Z,1662046771.738 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2022-09-01T15:39:31.739Z,1662046771.739 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 408144E0
2022-09-01T15:39:31.739Z,1662046771.739 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 6384
2022-09-01T15:39:31.745Z,1662046771.745 [PowerOnly](INFO): Adding load control power supply at /dev/loadC1
2022-09-01T15:39:31.756Z,1662046771.756 [PowerOnly] Loaded
2022-09-01T15:39:31.756Z,1662046771.756 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread.
2022-09-01T15:39:31.767Z,1662046771.767 [Power24vConverter] Loaded
2022-09-01T15:39:31.767Z,1662046771.767 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2022-09-01T15:39:31.781Z,1662046771.781 [Radio_Surface] Loaded
2022-09-01T15:39:31.781Z,1662046771.781 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2022-09-01T15:39:31.782Z,1662046771.782 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408444E0
2022-09-01T15:39:31.782Z,1662046771.782 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 6385
2022-09-01T15:39:31.825Z,1662046771.825 [RDI_Pathfinder] Loaded
2022-09-01T15:39:31.826Z,1662046771.826 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread.
2022-09-01T15:39:31.852Z,1662046771.852 [RDI_PathfinderUp] Loaded
2022-09-01T15:39:31.853Z,1662046771.853 [ComponentRegistry](DEBUG): SyncComponent "RDI_PathfinderUp" handled in the control thread.
2022-09-01T15:39:31.853Z,1662046771.853 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2022-09-01T15:39:31.854Z,1662046771.854 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2022-09-01T15:39:31.864Z,1662046771.864 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2022-09-01T15:39:31.864Z,1662046771.864 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2022-09-01T15:39:31.974Z,1662046771.974 [DeadReckonUsingMultipleVelocitySources] Loaded
2022-09-01T15:39:31.974Z,1662046771.974 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2022-09-01T15:39:31.998Z,1662046771.998 [LBLNavigation] Loaded
2022-09-01T15:39:31.998Z,1662046771.998 [ComponentRegistry](DEBUG): SyncComponent "LBLNavigation" handled in the control thread.
2022-09-01T15:39:32.011Z,1662046772.011 [NavChart] Loaded
2022-09-01T15:39:32.011Z,1662046772.011 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2022-09-01T15:39:32.016Z,1662046772.016 [UniversalFixResidualReporter] Loaded
2022-09-01T15:39:32.017Z,1662046772.017 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2022-09-01T15:39:32.027Z,1662046772.027 [WorkSite] Loaded
2022-09-01T15:39:32.027Z,1662046772.027 [ComponentRegistry](DEBUG): SyncComponent "WorkSite" handled in the control thread.
2022-09-01T15:39:32.027Z,1662046772.027 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2022-09-01T15:39:32.028Z,1662046772.028 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2022-09-01T15:39:32.121Z,1662046772.121 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2022-09-01T15:39:32.122Z,1662046772.122 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2022-09-01T15:39:32.244Z,1662046772.244 [BuoyancyServo] Loaded
2022-09-01T15:39:32.244Z,1662046772.244 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2022-09-01T15:39:32.265Z,1662046772.265 [ElevatorServo] Loaded
2022-09-01T15:39:32.266Z,1662046772.266 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2022-09-01T15:39:32.286Z,1662046772.286 [MassServo] Loaded
2022-09-01T15:39:32.286Z,1662046772.286 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2022-09-01T15:39:32.306Z,1662046772.306 [RudderServo] Loaded
2022-09-01T15:39:32.306Z,1662046772.306 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2022-09-01T15:39:32.322Z,1662046772.322 [ThrusterHE] Loaded
2022-09-01T15:39:32.322Z,1662046772.322 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread.
2022-09-01T15:39:32.323Z,1662046772.323 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2022-09-01T15:39:32.323Z,1662046772.323 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2022-09-01T15:39:32.488Z,1662046772.488 [CTD_Seabird] Loaded
2022-09-01T15:39:32.489Z,1662046772.489 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2022-09-01T15:39:32.490Z,1662046772.490 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 409824E0
2022-09-01T15:39:32.490Z,1662046772.490 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 6386
2022-09-01T15:39:32.521Z,1662046772.521 [WetLabsSeaOWL_UV_A] Loaded
2022-09-01T15:39:32.522Z,1662046772.522 [ComponentRegistry](DEBUG): Component "WetLabsSeaOWL_UV_A" handled in its own thread.
2022-09-01T15:39:32.523Z,1662046772.523 [WetLabsSeaOWL_UV_A ThreadHandler](DEBUG): Created PCaller Thread at 409B24E0
2022-09-01T15:39:32.523Z,1662046772.523 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Protected caller Thread ID is 6387
2022-09-01T15:39:32.524Z,1662046772.524 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2022-09-01T15:39:32.524Z,1662046772.524 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2022-09-01T15:39:32.823Z,1662046772.823 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2022-09-01T15:39:32.824Z,1662046772.824 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2022-09-01T15:39:32.874Z,1662046772.874 [DepthRateCalculator] Loaded
2022-09-01T15:39:32.874Z,1662046772.874 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2022-09-01T15:39:32.879Z,1662046772.879 [PitchRateCalculator] Loaded
2022-09-01T15:39:32.879Z,1662046772.879 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2022-09-01T15:39:32.888Z,1662046772.888 [SpeedCalculator] Loaded
2022-09-01T15:39:32.889Z,1662046772.889 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2022-09-01T15:39:32.901Z,1662046772.901 [TempGradientCalculator] Loaded
2022-09-01T15:39:32.902Z,1662046772.902 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2022-09-01T15:39:32.916Z,1662046772.916 [VerticalHomogeneityIndexCalculator] Loaded
2022-09-01T15:39:32.917Z,1662046772.917 [ComponentRegistry](DEBUG): SyncComponent "VerticalHomogeneityIndexCalculator" handled in the control thread.
2022-09-01T15:39:32.921Z,1662046772.921 [YawRateCalculator] Loaded
2022-09-01T15:39:32.921Z,1662046772.921 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2022-09-01T15:39:32.943Z,1662046772.943 [ElevatorOffsetCalculator] Loaded
2022-09-01T15:39:32.943Z,1662046772.943 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2022-09-01T15:39:32.944Z,1662046772.944 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2022-09-01T15:39:32.944Z,1662046772.944 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2022-09-01T15:39:33.081Z,1662046773.081 [SBIT](DEBUG): Construct Startup Built In Test.
2022-09-01T15:39:33.094Z,1662046773.094 [SBIT] Loaded
2022-09-01T15:39:33.094Z,1662046773.094 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2022-09-01T15:39:33.097Z,1662046773.097 [IBIT](DEBUG): Construct Initiated Built In Test.
2022-09-01T15:39:33.109Z,1662046773.109 [IBIT] Loaded
2022-09-01T15:39:33.109Z,1662046773.109 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2022-09-01T15:39:33.115Z,1662046773.115 [CBIT](DEBUG): Construct Continuous Built In Test.
2022-09-01T15:39:33.218Z,1662046773.218 [CBIT] Loaded
2022-09-01T15:39:33.218Z,1662046773.218 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2022-09-01T15:39:33.218Z,1662046773.218 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2022-09-01T15:39:33.219Z,1662046773.219 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2022-09-01T15:39:33.274Z,1662046773.274 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2022-09-01T15:39:33.275Z,1662046773.275 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2022-09-01T15:39:33.420Z,1662046773.420 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2022-09-01T15:39:33.421Z,1662046773.421 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2022-09-01T15:39:33.472Z,1662046773.472 [VerticalControl](DEBUG): Construct VerticalControl.
2022-09-01T15:39:33.521Z,1662046773.521 [VerticalControl] Loaded
2022-09-01T15:39:33.522Z,1662046773.522 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2022-09-01T15:39:33.525Z,1662046773.525 [HorizontalControl](DEBUG): Construct HorizontalControl.
2022-09-01T15:39:33.561Z,1662046773.561 [HorizontalControl] Loaded
2022-09-01T15:39:33.562Z,1662046773.562 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2022-09-01T15:39:33.564Z,1662046773.564 [SpeedControl](DEBUG): Construct SpeedControl.
2022-09-01T15:39:33.566Z,1662046773.566 [SpeedControl] Loaded
2022-09-01T15:39:33.566Z,1662046773.566 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2022-09-01T15:39:33.569Z,1662046773.569 [LoopControl](DEBUG): Construct LoopControl.
2022-09-01T15:39:33.569Z,1662046773.569 [LoopControl] Loaded
2022-09-01T15:39:33.570Z,1662046773.570 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2022-09-01T15:39:33.570Z,1662046773.570 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2022-09-01T15:39:33.570Z,1662046773.570 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2022-09-01T15:39:33.685Z,1662046773.685 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2022-09-01T15:39:33.692Z,1662046773.692 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2022-09-01T15:39:33.695Z,1662046773.695 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2022-09-01T15:39:33.706Z,1662046773.706 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2022-09-01T15:39:33.707Z,1662046773.707 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B6E4E0
2022-09-01T15:39:33.707Z,1662046773.707 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 6388
2022-09-01T15:39:33.765Z,1662046773.765 [Supervisor](INFO): Main Thread ID is 6281
2022-09-01T15:39:33.765Z,1662046773.765 [Supervisor](DEBUG): Running supervisor.
2022-09-01T15:39:33.765Z,1662046773.765 [CommandExec ThreadHandler](INFO): Handler Thread ID is 6389
2022-09-01T15:39:33.766Z,1662046773.766 [CommandExec](INFO): Initializing the command executive.
2022-09-01T15:39:33.768Z,1662046773.768 [CommandLine ThreadHandler](INFO): Handler Thread ID is 6390
2022-09-01T15:39:33.784Z,1662046773.784 [controlThread ThreadHandler](INFO): Handler Thread ID is 6391
2022-09-01T15:39:33.784Z,1662046773.784 [controlThread](DEBUG): Initializing ControlThread
2022-09-01T15:39:33.791Z,1662046773.791 [NavChart](DEBUG): Initialize NavChart Navigation.
2022-09-01T15:39:33.791Z,1662046773.791 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2022-09-01T15:39:33.792Z,1662046773.792 [WorkSite](DEBUG): Initializing WorkSite component.
2022-09-01T15:39:33.793Z,1662046773.793 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2022-09-01T15:39:33.794Z,1662046773.794 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2022-09-01T15:39:33.794Z,1662046773.794 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2022-09-01T15:39:33.794Z,1662046773.794 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2022-09-01T15:39:33.795Z,1662046773.795 [VerticalHomogeneityIndexCalculator](DEBUG): (re)initializing
2022-09-01T15:39:33.796Z,1662046773.796 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2022-09-01T15:39:33.796Z,1662046773.796 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2022-09-01T15:39:33.797Z,1662046773.797 [SBIT](INFO): Initialize SBIT Component.
2022-09-01T15:39:33.797Z,1662046773.797 [SBIT](IMPORTANT): git: 2022-08-25
2022-09-01T15:39:33.798Z,1662046773.798 [SBIT](INFO): git hash: e1ddd60859d931066d70c4e9618f9367e52a6cfe
2022-09-01T15:39:33.798Z,1662046773.798 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2022-09-01T15:39:33.799Z,1662046773.799 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
Kernel Reported: #1 PREEMPT Thu Aug 6 12:04:53 PDT 2020
2022-09-01T15:39:33.800Z,1662046773.800 [SBIT](INFO): Beginning SBIT in 39.000000 seconds.
2022-09-01T15:39:33.801Z,1662046773.801 [IBIT](INFO): Initialize IBIT Component.
2022-09-01T15:39:33.802Z,1662046773.802 [CBIT](DEBUG): Initialize CBIT Component.
2022-09-01T15:39:33.803Z,1662046773.803 [logger ThreadHandler](INFO): Handler Thread ID is 6392
2022-09-01T15:39:33.819Z,1662046773.819 [CBIT](DEBUG): Initialized mux pins.
2022-09-01T15:39:33.819Z,1662046773.819 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL.
2022-09-01T15:39:33.820Z,1662046773.820 [CBIT](DEBUG): Initializing the watchdog timer.
2022-09-01T15:39:33.831Z,1662046773.831 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 6393
2022-09-01T15:39:33.838Z,1662046773.838 [DataOverHttps](DEBUG): dashIP=128.128.181.226 starts with a digit so assuming it is a numeric IP
2022-09-01T15:39:33.844Z,1662046773.844 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2022-09-01T15:39:33.844Z,1662046773.844 [CBIT](DEBUG): Initializing heartbeat.
2022-09-01T15:39:33.855Z,1662046773.855 [Onboard ThreadHandler](INFO): Handler Thread ID is 6394
2022-09-01T15:39:33.873Z,1662046773.873 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 6395
2022-09-01T15:39:33.896Z,1662046773.896 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 6396
2022-09-01T15:39:33.896Z,1662046773.896 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2022-09-01T15:39:33.901Z,1662046773.901 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Handler Thread ID is 6398
2022-09-01T15:39:33.912Z,1662046773.912 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 6399
2022-09-01T15:39:33.915Z,1662046773.915 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2022-09-01T15:39:33.915Z,1662046773.915 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2022-09-01T15:39:33.915Z,1662046773.915 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2022-09-01T15:39:33.915Z,1662046773.915 [CBIT](DEBUG): Deactivating GF circuits.
2022-09-01T15:39:33.915Z,1662046773.915 [CBIT](DEBUG): Deactivating emergency mode.
2022-09-01T15:39:33.916Z,1662046773.916 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2022-09-01T15:39:33.916Z,1662046773.916 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2022-09-01T15:39:33.916Z,1662046773.916 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2022-09-01T15:39:33.916Z,1662046773.916 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2022-09-01T15:39:33.916Z,1662046773.916 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2022-09-01T15:39:33.951Z,1662046773.951 [CBIT](DEBUG): Backplane powered.
2022-09-01T15:39:33.952Z,1662046773.952 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2022-09-01T15:39:33.953Z,1662046773.953 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2022-09-01T15:39:33.954Z,1662046773.954 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2022-09-01T15:39:33.954Z,1662046773.954 [LoopControl](DEBUG): Initialize LoopControlComponent.
2022-09-01T15:39:33.955Z,1662046773.955 [MissionManager](INFO): Loading Mission from file: Missions/Startup.xml
2022-09-01T15:39:33.969Z,1662046773.969 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2022-09-01T15:39:34.031Z,1662046774.031 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Units="Tethys/Units"
       xmlns:Universal="Tethys/Universal"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
       Id="Startup">

    <Guidance:GoToSurface>
        <Progression/>
    </Guidance:GoToSurface>

    <Aggregate Id="StartupSatComms">

        <Sequence/>

        <ReadDatum>
            <Timeout Duration="P1M" />
            <Universal:latitude_fix/>
        </ReadDatum>

        <ReadDatum>
            <Timeout Duration="P1M" />
            <Universal:platform_communications/>
        </ReadDatum>

    </Aggregate>

</Mission>


2022-09-01T15:39:34.032Z,1662046774.032 [MissionManager](INFO): Loading Mission from file: Missions/Default.xml
2022-09-01T15:39:34.110Z,1662046774.110 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2022-09-01T15:39:34.112Z,1662046774.112 [Default:A.Wait](DEBUG): Construct Wait.
2022-09-01T15:39:34.114Z,1662046774.114 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2022-09-01T15:39:34.158Z,1662046774.158 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2022-09-01T15:39:34.161Z,1662046774.161 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2022-09-01T15:39:34.179Z,1662046774.179 [Default:E.Execute](DEBUG): Construct Execute.
2022-09-01T15:39:34.190Z,1662046774.190 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Universal="Tethys/Universal"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                             Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                             Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
         Id="Default">

    <DefineArg Name="ElapsedSinceDefaultStarted"><Units:minute/><Value>0</Value></DefineArg>

    <Guidance:Wait>
        <Description>
            Wait a moment to see if the scheduler starts a new mission before
            starting to actually run Default.
        </Description>
        <Sequence/>
        <Setting><Guidance:Wait.duration/><Units:second/><Value>13</Value></Setting>
    </Guidance:Wait>

    <Guidance:GoToSurface>
        <Progression/>
    </Guidance:GoToSurface>

    <Aggregate Id="CheckIn">

        <Sequence Repeat="288"/>

        <ReadDatum Id="Read_GPS">
            <Timeout Duration="P5M"/>
            <Universal:time_fix/>
        </ReadDatum>

        <ReadDatum Id="Read_Iridium">
            <Timeout Duration="P2H">
                <Guidance:Execute>
                    <Sequence/>
                    <Setting><Guidance:Execute.command/><String>Burn on</String></Setting>
                </Guidance:Execute>
                <Syslog Severity="Critical">Dropped weight due to communications timeout.</Syslog>
            </Timeout>
            <Universal:platform_communications/>
        </ReadDatum>

        <Guidance:Wait>
            <Sequence/>
            <Setting><Guidance:Wait.duration/><Units:minute/><Value>5</Value></Setting>
        </Guidance:Wait>

        <Assign><Sequence/><Arg Name="ElapsedSinceDefaultStarted"/><Elapsed><Universal:mission_started/></Elapsed></Assign>

        <Syslog Severity="Important">Default mission has been running for <Arg Name="ElapsedSinceDefaultStarted"/><Units:minute/></Syslog>

    </Aggregate>

    <Syslog Severity="Important">Restarting logs and Default mission.</Syslog>

    <Guidance:Execute>
        <Sequence/>
        <Setting><Guidance:Execute.command/><String>restart logs</String></Setting>
    </Guidance:Execute>

</Mission>


2022-09-01T15:39:34.195Z,1662046774.195 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,Micromodem,NAL9602,PowerOnly,Power24vConverter,RDI_Pathfinder,RDI_PathfinderUp,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,VerticalHomogeneityIndexCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,WorkSite,LBLNavigation,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2022-09-01T15:39:34.208Z,1662046774.208 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2022-09-01T15:39:34.287Z,1662046774.287 [Radio_Surface](INFO): Powering up
2022-09-01T15:39:34.292Z,1662046774.292 [Power24vConverter](INFO): Powering up.
2022-09-01T15:39:34.292Z,1662046774.292 [RDI_Pathfinder](IMPORTANT): Expecting PD13 message format
2022-09-01T15:39:34.367Z,1662046774.367 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2022-09-01T15:39:34.376Z,1662046774.376 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2022-09-01T15:39:34.377Z,1662046774.377 [ElevatorServo](DEBUG): Initializing EZServoServo.
2022-09-01T15:39:34.388Z,1662046774.388 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2022-09-01T15:39:34.389Z,1662046774.389 [MassServo](DEBUG): Initializing EZServoServo.
2022-09-01T15:39:34.396Z,1662046774.396 [MassServo](DEBUG): Initializing MassServo.
2022-09-01T15:39:34.396Z,1662046774.396 [RudderServo](DEBUG): Initializing EZServoServo.
2022-09-01T15:39:34.408Z,1662046774.408 [RudderServo](DEBUG): Initializing RudderServo.
2022-09-01T15:39:34.408Z,1662046774.408 [ThrusterHE](DEBUG): Initializing EZServoServo.
2022-09-01T15:39:34.416Z,1662046774.416 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2022-09-01T15:39:34.652Z,1662046774.652 [Micromodem](INFO): Powering up
2022-09-01T15:39:34.652Z,1662046774.652 [Micromodem](DEBUG): Initializing Micromodem.
2022-09-01T15:39:35.335Z,1662046775.335 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2022-09-01T15:39:35.336Z,1662046775.336 [RudderServo](FAULT): Rudder failed to initialize
2022-09-01T15:39:35.336Z,1662046775.336 [RudderServo] Communications Fault, FailCount= 1
2022-09-01T15:39:35.336Z,1662046775.336 [RudderServo](ERROR): Communications Fault
2022-09-01T15:39:35.340Z,1662046775.340 [CBIT](ERROR): Communications Fault in component: RudderServo
2022-09-01T15:39:35.552Z,1662046775.552 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2022-09-01T15:39:35.553Z,1662046775.553 [RudderServo](INFO): Powering down
2022-09-01T15:39:36.235Z,1662046776.235 [RudderServo](DEBUG): Initializing EZServoServo.
2022-09-01T15:39:36.356Z,1662046776.356 [RudderServo](DEBUG): Initializing RudderServo.
2022-09-01T15:39:36.360Z,1662046776.360 [CBIT](INFO): Clearing failed state for component RudderServo
2022-09-01T15:39:36.360Z,1662046776.360 [RudderServo] No Fault, FailCount= 1
2022-09-01T15:39:38.270Z,1662046778.270 [Micromodem](INFO): Nmea in: $CATMG,2022-09-01T15:39:37.841549Z,RTC,RTC*55

2022-09-01T15:39:39.494Z,1662046779.494 [Micromodem](INFO): Nmea out: $CCCFG,ALL,0*33

2022-09-01T15:39:39.902Z,1662046779.902 [Micromodem](INFO): Nmea in: $CACFG,ALL,0*31

2022-09-01T15:39:39.902Z,1662046779.902 [Micromodem](INFO): Nmea out: $CCCFG,POW,20*08

2022-09-01T15:39:40.228Z,1662046780.228 [ThrusterHE](ERROR): Zero Speed Commanded.
2022-09-01T15:39:40.337Z,1662046780.337 [Micromodem](INFO): Nmea in: $CACFG,POW,20*0A

2022-09-01T15:39:40.338Z,1662046780.338 [Micromodem](INFO): Nmea out: $CCCFG,SRC,0*30

2022-09-01T15:39:40.742Z,1662046780.742 [Micromodem](INFO): Nmea in: $CACFG,SRC,0*32

2022-09-01T15:39:40.742Z,1662046780.742 [Micromodem](INFO): Nmea out: $CCCFG,nav.dt.txtrig_gpio4,1*64

2022-09-01T15:39:41.147Z,1662046781.147 [Micromodem](INFO): Nmea in: $CACFG,nav.dt.txtrig_gpio4,1*66

2022-09-01T15:39:41.147Z,1662046781.147 [Micromodem](INFO): Nmea out: $CCCFG,pwramp.txlevel,0*2F

2022-09-01T15:39:41.550Z,1662046781.550 [Micromodem](INFO): Nmea in: $CACFG,pwramp.txlevel,0*2D

2022-09-01T15:39:41.550Z,1662046781.550 [Micromodem](INFO): Nmea out: $CCCFG,DTO,30*1E

2022-09-01T15:39:41.957Z,1662046781.957 [Micromodem](INFO): Nmea in: $CACFG,DTO,30*1C

2022-09-01T15:39:41.958Z,1662046781.958 [Micromodem](INFO): Nmea out: $CCCFG,FC0,14500*47

2022-09-01T15:39:42.369Z,1662046782.369 [Micromodem](INFO): Nmea in: $CACFG,FC0,14500*45

2022-09-01T15:39:42.370Z,1662046782.370 [Micromodem](INFO): Nmea out: $CCCFG,BW0,4000*63

2022-09-01T15:39:42.765Z,1662046782.765 [Micromodem](INFO): Nmea in: $CACFG,BW0,4000*61

2022-09-01T15:39:42.766Z,1662046782.766 [Micromodem](INFO): Nmea out: $CCCFG,BND,0*3A

2022-09-01T15:39:43.141Z,1662046783.141 [Micromodem](INFO): Nmea in: $CACFG,BND,0*38

2022-09-01T15:39:43.142Z,1662046783.142 [Micromodem](INFO): Nmea out: $CCCLK,2022,09,01,15,39,44*40

2022-09-01T15:39:43.537Z,1662046783.537 [Micromodem](INFO): Nmea in: $CACLK,2022,9,1,15,39,44*42

2022-09-01T15:39:43.942Z,1662046783.942 [Micromodem](INFO): Nmea in: $CATMS,0,2022-09-01T15:39:45Z*73

2022-09-01T15:39:43.948Z,1662046783.948 [Micromodem](INFO): Nmea in: $CATMG,2022-09-01T15:39:45.027948Z,USER_CMD,RTC*14

2022-09-01T15:40:01.722Z,1662046801.722 [NAL9602](INFO): Powering up NAL9602
2022-09-01T15:40:12.630Z,1662046812.630 [NAL9602](INFO): NAL9602 initialized
2022-09-01T15:40:13.475Z,1662046813.475 [SBIT](IMPORTANT): Beginning Startup BIT
2022-09-01T15:40:13.501Z,1662046813.501 [CBIT](IMPORTANT): Beginning ground fault scan
2022-09-01T15:40:24.407Z,1662046824.407 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.084293
CHAN A1 (24V): 0.010523
CHAN A2 (12V): 0.004435
CHAN A3 (5V): -0.001830
CHAN B0 (3.3V): 0.000564
CHAN B1 (3.15aV): 0.000569
CHAN B2 (3.15bV): 0.001172
CHAN B3 (GND): -0.002525
OPEN: 0.005261
Full Scale: +/- 1 mA
2022-09-01T15:40:33.235Z,1662046833.235 [NAL9602](INFO): SBD MO Status=2, MOMSN=44610, MT Status=2, MTMSN=0
2022-09-01T15:40:33.236Z,1662046833.236 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-09-01T15:40:57.492Z,1662046857.492 [NAL9602](INFO): SBD MO Status=2, MOMSN=44610, MT Status=2, MTMSN=0
2022-09-01T15:40:57.492Z,1662046857.492 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-09-01T15:41:07.604Z,1662046867.604 [SBIT](IMPORTANT): SBIT PASSED
2022-09-01T15:41:07.604Z,1662046867.604 [SBIT](FAULT): Ignoring configuration overrides from Data/persisted.cfg
2022-09-01T15:41:08.013Z,1662046868.013 [WorkSite](IMPORTANT): Reading workSite position from Data/workSite.cfg
2022-09-01T15:41:08.016Z,1662046868.016 [WorkSite](IMPORTANT): WorkSite fix at 20220901T153712: (40.712365, -70.672314)
2022-09-01T15:41:08.018Z,1662046868.018 [MissionManager](IMPORTANT): Started mission Startup
2022-09-01T15:41:08.018Z,1662046868.018 [Startup] Running Loop=1
2022-09-01T15:41:08.018Z,1662046868.018 [Startup](DEBUG): Aggregate::initialize Startup
2022-09-01T15:41:08.018Z,1662046868.018 [Startup:A.GoToSurface] Running Loop=1
2022-09-01T15:41:08.018Z,1662046868.018 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2022-09-01T15:41:08.019Z,1662046868.019 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2022-09-01T15:41:08.020Z,1662046868.020 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2022-09-01T15:41:08.020Z,1662046868.020 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2022-09-01T15:41:08.020Z,1662046868.020 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2022-09-01T15:41:08.021Z,1662046868.021 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2022-09-01T15:41:08.022Z,1662046868.022 [Startup:StartupSatComms] Running Loop=1
2022-09-01T15:41:08.022Z,1662046868.022 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2022-09-01T15:41:08.022Z,1662046868.022 [Startup:StartupSatComms:A] Running Loop=1
2022-09-01T15:41:08.443Z,1662046868.443 [LBLNavigation](INFO): Reset ping filters
2022-09-01T15:41:08.444Z,1662046868.444 [LBLNavigation](INFO): Reset fix filter
2022-09-01T15:41:08.445Z,1662046868.445 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2022-09-01T15:41:35.475Z,1662046895.475 [NAL9602](INFO): SBD MO Status=2, MOMSN=44610, MT Status=2, MTMSN=0
2022-09-01T15:41:35.475Z,1662046895.475 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-09-01T15:41:44.359Z,1662046904.359 [NAL9602](INFO): SBD MO Status=0, MOMSN=44610, MT Status=0, MTMSN=0
2022-09-01T15:41:44.359Z,1662046904.359 [NAL9602](INFO): No messages in MT queue
2022-09-01T15:41:45.567Z,1662046905.567 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,154151.00,A,4040.66958,N,07039.96546,W,9.972,181.69,010922,,,A*72
2022-09-01T15:41:45.570Z,1662046905.570 [NAL9602](INFO): GPS fix at 20220901T154151: (40.677826, -70.666091)
2022-09-01T15:41:45.621Z,1662046905.621 [Startup:StartupSatComms:A] Stopped
2022-09-01T15:41:45.621Z,1662046905.621 [Startup:StartupSatComms:B] Running Loop=1
2022-09-01T15:41:46.016Z,1662046906.016 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2022-09-01T15:42:06.378Z,1662046926.378 [NAL9602](INFO): SBD MO Status=1, MOMSN=44611, MT Status=0, MTMSN=0
2022-09-01T15:42:06.428Z,1662046926.428 [NAL9602](INFO): Sent 169 bytes from file Logs/20220901T152931/Courier0000.lzma
2022-09-01T15:42:06.428Z,1662046926.428 [NAL9602](INFO): Packets left to send: 0
2022-09-01T15:42:25.722Z,1662046945.722 [NAL9602](INFO): SBD MO Status=2, MOMSN=44612, MT Status=2, MTMSN=0
2022-09-01T15:42:25.722Z,1662046945.722 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-09-01T15:42:45.733Z,1662046965.733 [Startup:StartupSatComms:B](INFO): Timed out from 2022-09-01T15:41:45.6Z
2022-09-01T15:42:45.733Z,1662046965.733 [Startup:StartupSatComms:B] Stopped
2022-09-01T15:42:45.733Z,1662046965.733 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2022-09-01T15:42:45.733Z,1662046965.733 [Startup:StartupSatComms] Stopped
2022-09-01T15:42:45.733Z,1662046965.733 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2022-09-01T15:42:45.734Z,1662046965.734 [Startup](INFO): Completed Startup
2022-09-01T15:42:45.734Z,1662046965.734 [MissionManager](INFO): Startup is completed.
2022-09-01T15:42:45.734Z,1662046965.734 [MissionManager](INFO): Uninitializing Mission Startup
2022-09-01T15:42:45.734Z,1662046965.734 [Startup] Stopped
2022-09-01T15:42:45.734Z,1662046965.734 [Startup](DEBUG): Aggregate::uninitialize Startup
2022-09-01T15:42:45.734Z,1662046965.734 [Startup:A.GoToSurface] Stopped
2022-09-01T15:42:45.734Z,1662046965.734 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2022-09-01T15:42:46.136Z,1662046966.136 [MissionManager](IMPORTANT): Started mission Default
2022-09-01T15:42:46.136Z,1662046966.136 [Default] Running Loop=1
2022-09-01T15:42:46.136Z,1662046966.136 [Default](DEBUG): Aggregate::initialize Default
2022-09-01T15:42:46.136Z,1662046966.136 [Default:B.GoToSurface] Running Loop=1
2022-09-01T15:42:46.136Z,1662046966.136 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2022-09-01T15:42:46.136Z,1662046966.136 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2022-09-01T15:42:46.137Z,1662046966.137 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2022-09-01T15:42:46.137Z,1662046966.137 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2022-09-01T15:42:46.137Z,1662046966.137 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2022-09-01T15:42:46.138Z,1662046966.138 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2022-09-01T15:42:46.138Z,1662046966.138 [Default:A.Wait] Running Loop=1
2022-09-01T15:42:46.138Z,1662046966.138 [Default:A.Wait](DEBUG): Initialize Wait Component.
2022-09-01T15:42:51.783Z,1662046971.783 [NAL9602](INFO): SBD MO Status=2, MOMSN=44612, MT Status=2, MTMSN=0
2022-09-01T15:42:51.784Z,1662046971.784 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-09-01T15:42:59.479Z,1662046979.479 [Default:A.Wait](INFO): Done Waiting.
2022-09-01T15:42:59.479Z,1662046979.479 [Default:A.Wait] Stopped
2022-09-01T15:42:59.479Z,1662046979.479 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2022-09-01T15:42:59.865Z,1662046979.865 [Default:CheckIn] Running Loop=1
2022-09-01T15:42:59.865Z,1662046979.865 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-09-01T15:42:59.865Z,1662046979.865 [Default:CheckIn:Read_GPS] Running Loop=1
2022-09-01T15:43:00.275Z,1662046980.275 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2022-09-01T15:43:01.873Z,1662046981.873 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,154307.00,A,4040.45983,N,07039.95446,W,10.419,181.40,010922,,,D*40
2022-09-01T15:43:01.877Z,1662046981.877 [NAL9602](INFO): GPS fix at 20220901T154307: (40.674330, -70.665908)
2022-09-01T15:43:01.887Z,1662046981.887 [Default:CheckIn:Read_GPS] Stopped
2022-09-01T15:43:01.888Z,1662046981.888 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-09-01T15:43:02.368Z,1662046982.368 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2022-09-01T15:43:17.517Z,1662046997.517 [NAL9602](INFO): SBD MO Status=2, MOMSN=44612, MT Status=2, MTMSN=0
2022-09-01T15:43:17.518Z,1662046997.518 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-09-01T15:43:41.167Z,1662047021.167 [NAL9602](INFO): SBD MO Status=1, MOMSN=44612, MT Status=0, MTMSN=0
2022-09-01T15:43:41.224Z,1662047021.224 [NAL9602](INFO): Sent 51 bytes from file Logs/20220901T152931/Courier0003.lzma
2022-09-01T15:43:41.224Z,1662047021.224 [NAL9602](INFO): Packets left to send: 0
2022-09-01T15:43:49.120Z,1662047029.120 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31

2022-09-01T15:43:49.493Z,1662047029.493 [Micromodem](INFO): Nmea in: $CACST,6,1,20220901154349.900023,06,2348,21,0225,0150,156,01,01,02,01,-1,-01,-01,1,3,7,0,150,29.4,0.04,-100,2.96,-01,-0.39,52,14500,4000*54

2022-09-01T15:43:50.698Z,1662047030.698 [NAL9602](INFO): SBD MO Status=1, MOMSN=44613, MT Status=0, MTMSN=0
2022-09-01T15:43:50.760Z,1662047030.760 [NAL9602](INFO): Sent 184 bytes from file Logs/20220901T153923/Courier0000.lzma
2022-09-01T15:43:50.760Z,1662047030.760 [NAL9602](INFO): Packets left to send: 1
2022-09-01T15:44:11.981Z,1662047051.981 [NAL9602](INFO): SBD MO Status=1, MOMSN=44614, MT Status=0, MTMSN=0
2022-09-01T15:44:12.026Z,1662047052.026 [NAL9602](INFO): Sent 71 bytes from file Logs/20220901T153923/Courier0000.lzma
2022-09-01T15:44:12.026Z,1662047052.026 [NAL9602](INFO): Packets left to send: 0
2022-09-01T15:44:23.189Z,1662047063.189 [NAL9602](INFO): SBD MO Status=1, MOMSN=44615, MT Status=0, MTMSN=0
2022-09-01T15:44:23.240Z,1662047063.240 [NAL9602](INFO): Sent 73 bytes from file Logs/20220901T153923/Courier0004.lzma
2022-09-01T15:44:23.240Z,1662047063.240 [NAL9602](INFO): Packets left to send: 0
2022-09-01T15:44:42.378Z,1662047082.378 [NAL9602](INFO): SBD MO Status=2, MOMSN=44616, MT Status=2, MTMSN=0
2022-09-01T15:44:42.378Z,1662047082.378 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-09-01T15:45:21.459Z,1662047121.459 [NAL9602](INFO): SBD MO Status=2, MOMSN=44616, MT Status=2, MTMSN=0
2022-09-01T15:45:21.459Z,1662047121.459 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-09-01T15:45:40.815Z,1662047140.815 [NAL9602](INFO): SBD MO Status=1, MOMSN=44616, MT Status=0, MTMSN=0
2022-09-01T15:45:40.868Z,1662047140.868 [NAL9602](INFO): Sent 108 bytes from file Logs/20220901T141941/Express0035.lzma
2022-09-01T15:45:40.868Z,1662047140.868 [NAL9602](INFO): Packets left to send: 0
2022-09-01T15:45:51.571Z,1662047151.571 [NAL9602](INFO): SBD MO Status=1, MOMSN=44617, MT Status=0, MTMSN=0
2022-09-01T15:45:51.628Z,1662047151.628 [NAL9602](INFO): Sent 184 bytes from file Logs/20220901T152931/Express0001.lzma
2022-09-01T15:45:51.628Z,1662047151.628 [NAL9602](INFO): Packets left to send: 2
2022-09-01T15:45:59.734Z,1662047159.734 [NAL9602](INFO): SBD MO Status=1, MOMSN=44618, MT Status=0, MTMSN=0
2022-09-01T15:45:59.796Z,1662047159.796 [NAL9602](INFO): Sent 184 bytes from file Logs/20220901T152931/Express0001.lzma
2022-09-01T15:45:59.796Z,1662047159.796 [NAL9602](INFO): Packets left to send: 1
2022-09-01T15:46:01.872Z,1662047161.872 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for water mass range.
2022-09-01T15:46:08.098Z,1662047168.098 [NAL9602](INFO): SBD MO Status=1, MOMSN=44619, MT Status=0, MTMSN=0
2022-09-01T15:46:08.156Z,1662047168.156 [NAL9602](INFO): Sent 161 bytes from file Logs/20220901T152931/Express0001.lzma
2022-09-01T15:46:08.156Z,1662047168.156 [NAL9602](INFO): Packets left to send: 0
2022-09-01T15:46:29.424Z,1662047189.424 [NAL9602](INFO): SBD MO Status=2, MOMSN=44620, MT Status=2, MTMSN=0
2022-09-01T15:46:29.424Z,1662047189.424 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-09-01T15:46:52.110Z,1662047212.110 [BPC1](ERROR): Battery stick #62 (s/n: 0138) reported TERMINATE_CHARGE_ALARM. Status code: 0x40C0.
2022-09-01T15:46:52.110Z,1662047212.110 [BPC1](INFO): Calculating totals. Valid battery stick count: 55. Valid reserve battery stick count: 6.
2022-09-01T15:46:52.128Z,1662047212.128 [BPC1](INFO): Received data from all battery sticks.
2022-09-01T15:46:58.584Z,1662047218.584 [NAL9602](INFO): SBD MO Status=1, MOMSN=44620, MT Status=0, MTMSN=0
2022-09-01T15:46:58.648Z,1662047218.648 [NAL9602](INFO): Sent 184 bytes from file Logs/20220901T152931/Express0004.lzma
2022-09-01T15:46:58.648Z,1662047218.648 [NAL9602](INFO): Packets left to send: 2
2022-09-01T15:47:09.336Z,1662047229.336 [NAL9602](INFO): SBD MO Status=1, MOMSN=44621, MT Status=0, MTMSN=0
2022-09-01T15:47:09.383Z,1662047229.383 [NAL9602](INFO): Sent 184 bytes from file Logs/20220901T152931/Express0004.lzma
2022-09-01T15:47:09.383Z,1662047229.383 [NAL9602](INFO): Packets left to send: 1
2022-09-01T15:47:20.347Z,1662047240.347 [NAL9602](INFO): SBD MO Status=1, MOMSN=44622, MT Status=0, MTMSN=0
2022-09-01T15:47:20.404Z,1662047240.404 [NAL9602](INFO): Sent 31 bytes from file Logs/20220901T152931/Express0004.lzma
2022-09-01T15:47:20.404Z,1662047240.404 [NAL9602](INFO): Packets left to send: 0
2022-09-01T15:47:29.707Z,1662047249.707 [NAL9602](INFO): SBD MO Status=1, MOMSN=44623, MT Status=0, MTMSN=0
2022-09-01T15:47:29.760Z,1662047249.760 [NAL9602](INFO): Sent 184 bytes from file Logs/20220901T153923/Express0001.lzma
2022-09-01T15:47:29.760Z,1662047249.760 [NAL9602](INFO): Packets left to send: 4
2022-09-01T15:47:40.719Z,1662047260.719 [NAL9602](INFO): SBD MO Status=1, MOMSN=44624, MT Status=0, MTMSN=0
2022-09-01T15:47:40.776Z,1662047260.776 [NAL9602](INFO): Sent 184 bytes from file Logs/20220901T153923/Express0001.lzma
2022-09-01T15:47:40.776Z,1662047260.776 [NAL9602](INFO): Packets left to send: 3
2022-09-01T15:48:08.187Z,1662047288.187 [NAL9602](INFO): SBD MO Status=1, MOMSN=44625, MT Status=0, MTMSN=0
2022-09-01T15:48:08.240Z,1662047288.240 [NAL9602](INFO): Sent 184 bytes from file Logs/20220901T153923/Express0001.lzma
2022-09-01T15:48:08.240Z,1662047288.240 [NAL9602](INFO): Packets left to send: 2
2022-09-01T15:48:17.984Z,1662047297.984 [NAL9602](INFO): SBD MO Status=1, MOMSN=44626, MT Status=0, MTMSN=0
2022-09-01T15:48:18.040Z,1662047298.040 [NAL9602](INFO): Sent 184 bytes from file Logs/20220901T153923/Express0001.lzma
2022-09-01T15:48:18.040Z,1662047298.040 [NAL9602](INFO): Packets left to send: 1
2022-09-01T15:48:25.427Z,1662047305.427 [NAL9602](INFO): SBD MO Status=1, MOMSN=44627, MT Status=0, MTMSN=0
2022-09-01T15:48:25.477Z,1662047305.477 [NAL9602](INFO): Sent 85 bytes from file Logs/20220901T153923/Express0001.lzma
2022-09-01T15:48:25.477Z,1662047305.477 [NAL9602](INFO): Packets left to send: 0
2022-09-01T15:48:35.811Z,1662047315.811 [NAL9602](INFO): SBD MO Status=1, MOMSN=44628, MT Status=0, MTMSN=0
2022-09-01T15:48:35.872Z,1662047315.872 [NAL9602](INFO): Sent 93 bytes from file Logs/20220901T153923/Express0005.lzma
2022-09-01T15:48:35.873Z,1662047315.873 [NAL9602](INFO): Packets left to send: 0
2022-09-01T15:48:40.563Z,1662047320.563 [NAL9602](INFO): SBD MO Status=0, MOMSN=44629, MT Status=0, MTMSN=0
2022-09-01T15:48:40.687Z,1662047320.687 [Default:CheckIn:Read_Iridium] Stopped
2022-09-01T15:48:40.687Z,1662047320.687 [Default:CheckIn:C.Wait] Running Loop=1
2022-09-01T15:48:40.688Z,1662047320.688 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-09-01T15:49:11.265Z,1662047351.265 [NAL9602](INFO): Not Powering down - fast GPS
2022-09-01T15:51:59.757Z,1662047519.757 [RDI_PathfinderUp](ERROR): only read 3 of 4 data items
2022-09-01T15:52:24.817Z,1662047544.817 [RDI_PathfinderUp](ERROR): only read 2 of 4 data items
2022-09-01T15:52:34.583Z,1662047554.583 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for altitude
2022-09-01T15:53:41.160Z,1662047621.160 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-09-01T15:53:41.160Z,1662047621.160 [Default:CheckIn:C.Wait] Stopped
2022-09-01T15:53:41.160Z,1662047621.160 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-09-01T15:53:41.160Z,1662047621.160 [Default:CheckIn:D] Running Loop=1
2022-09-01T15:53:41.584Z,1662047621.584 [Default:CheckIn:D] Stopped
2022-09-01T15:53:41.584Z,1662047621.584 [Default:CheckIn:E] Running Loop=1
2022-09-01T15:53:41.974Z,1662047621.974 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.924134 min 
2022-09-01T15:53:41.974Z,1662047621.974 [Default:CheckIn:E] Stopped
2022-09-01T15:53:41.974Z,1662047621.974 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-09-01T15:53:41.974Z,1662047621.974 [Default:CheckIn] Stopped
2022-09-01T15:53:41.974Z,1662047621.974 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-09-01T15:53:41.975Z,1662047621.975 [Default:CheckIn](INFO): Running loop #2
2022-09-01T15:53:41.975Z,1662047621.975 [Default:CheckIn] Running Loop=2
2022-09-01T15:53:41.975Z,1662047621.975 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-09-01T15:53:41.975Z,1662047621.975 [Default:CheckIn:Read_GPS] Running Loop=1
2022-09-01T15:53:43.976Z,1662047623.976 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,155350.00,A,4038.71121,N,07039.96430,W,9.991,183.59,010922,,,D*76
2022-09-01T15:53:43.978Z,1662047623.978 [NAL9602](INFO): GPS fix at 20220901T155350: (40.645187, -70.666072)
2022-09-01T15:53:44.012Z,1662047624.012 [Default:CheckIn:Read_GPS] Stopped
2022-09-01T15:53:44.012Z,1662047624.012 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-09-01T15:54:02.372Z,1662047642.372 [NAL9602](INFO): SBD MO Status=1, MOMSN=44630, MT Status=0, MTMSN=0
2022-09-01T15:54:02.428Z,1662047642.428 [NAL9602](INFO): Sent 184 bytes from file Logs/20220901T153923/Courier0007.lzma
2022-09-01T15:54:02.428Z,1662047642.428 [NAL9602](INFO): Packets left to send: 1
2022-09-01T15:54:09.881Z,1662047649.881 [NAL9602](INFO): SBD MO Status=1, MOMSN=44631, MT Status=0, MTMSN=0
2022-09-01T15:54:09.944Z,1662047649.944 [NAL9602](INFO): Sent 18 bytes from file Logs/20220901T153923/Courier0007.lzma
2022-09-01T15:54:09.944Z,1662047649.944 [NAL9602](INFO): Packets left to send: 0
2022-09-01T15:54:19.406Z,1662047659.406 [NAL9602](INFO): SBD MO Status=1, MOMSN=44632, MT Status=0, MTMSN=0
2022-09-01T15:54:19.458Z,1662047659.458 [NAL9602](INFO): Sent 162 bytes from file Logs/20220901T153923/Express0008.lzma
2022-09-01T15:54:19.458Z,1662047659.458 [NAL9602](INFO): Packets left to send: 0
2022-09-01T15:54:29.399Z,1662047669.399 [NAL9602](INFO): SBD MO Status=0, MOMSN=44633, MT Status=0, MTMSN=0
2022-09-01T15:54:29.498Z,1662047669.498 [Default:CheckIn:Read_Iridium] Stopped
2022-09-01T15:54:29.498Z,1662047669.498 [Default:CheckIn:C.Wait] Running Loop=1
2022-09-01T15:54:29.498Z,1662047669.498 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-09-01T15:55:00.105Z,1662047700.105 [NAL9602](INFO): Not Powering down - fast GPS
2022-09-01T15:55:32.878Z,1662047732.878 [RDI_PathfinderUp](ERROR): only read 2 of 4 data items
2022-09-01T15:59:30.026Z,1662047970.026 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-09-01T15:59:30.026Z,1662047970.026 [Default:CheckIn:C.Wait] Stopped
2022-09-01T15:59:30.026Z,1662047970.026 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-09-01T15:59:30.026Z,1662047970.026 [Default:CheckIn:D] Running Loop=1
2022-09-01T15:59:30.417Z,1662047970.417 [Default:CheckIn:D] Stopped
2022-09-01T15:59:30.418Z,1662047970.418 [Default:CheckIn:E] Running Loop=1
2022-09-01T15:59:30.851Z,1662047970.851 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 16.738028 min 
2022-09-01T15:59:30.851Z,1662047970.851 [Default:CheckIn:E] Stopped
2022-09-01T15:59:30.851Z,1662047970.851 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-09-01T15:59:30.851Z,1662047970.851 [Default:CheckIn] Stopped
2022-09-01T15:59:30.852Z,1662047970.852 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-09-01T15:59:30.852Z,1662047970.852 [Default:CheckIn](INFO): Running loop #3
2022-09-01T15:59:30.852Z,1662047970.852 [Default:CheckIn] Running Loop=3
2022-09-01T15:59:30.852Z,1662047970.852 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-09-01T15:59:30.852Z,1662047970.852 [Default:CheckIn:Read_GPS] Running Loop=1
2022-09-01T15:59:32.831Z,1662047972.831 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,155939.00,A,4037.76633,N,07039.99840,W,9.583,178.93,010922,,,D*76
2022-09-01T15:59:32.833Z,1662047972.833 [NAL9602](INFO): GPS fix at 20220901T155939: (40.629439, -70.666640)
2022-09-01T15:59:32.893Z,1662047972.893 [Default:CheckIn:Read_GPS] Stopped
2022-09-01T15:59:32.893Z,1662047972.893 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-09-01T15:59:55.841Z,1662047995.841 [NAL9602](IMPORTANT): SBD MO Status=1, MOMSN=44634, MT Status=1, MTMSN=1702
2022-09-01T15:59:55.892Z,1662047995.892 [NAL9602](INFO): Sent 74 bytes from file Logs/20220901T153923/Courier0010.lzma
2022-09-01T15:59:55.892Z,1662047995.892 [NAL9602](INFO): Packets left to send: 0
2022-09-01T15:59:56.424Z,1662047996.424 [NAL9602](INFO): Received command: configSet Express none concentration_of_colored_dissolved_organic_matter_in_sea_water persist
2022-09-01T15:59:59.007Z,1662047999.007 [CommandExec](IMPORTANT): got command configSet Express none concentration_of_colored_dissolved_organic_matter_in_sea_water persist
2022-09-01T15:59:59.008Z,1662047999.008 [CommandExec](FAULT): Not allowing to overwrite existing Data/persisted.cfg after unclean shutdown.
2022-09-01T16:00:16.901Z,1662048016.901 [NAL9602](INFO): SBD MO Status=1, MOMSN=44635, MT Status=0, MTMSN=0
2022-09-01T16:00:16.948Z,1662048016.948 [NAL9602](INFO): Sent 129 bytes from file Logs/20220901T153923/Express0011.lzma
2022-09-01T16:00:16.948Z,1662048016.948 [NAL9602](INFO): Packets left to send: 0
2022-09-01T16:00:33.843Z,1662048033.843 [NAL9602](INFO): SBD MO Status=2, MOMSN=44636, MT Status=2, MTMSN=0
2022-09-01T16:00:33.843Z,1662048033.843 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-09-01T16:00:50.744Z,1662048050.744 [NAL9602](INFO): SBD MO Status=2, MOMSN=44636, MT Status=2, MTMSN=0
2022-09-01T16:00:50.744Z,1662048050.744 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-09-01T16:00:56.887Z,1662048056.887 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2022-09-01T16:01:00.830Z,1662048060.830 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2022-09-01T16:01:09.195Z,1662048069.195 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2022-09-01T16:01:14.013Z,1662048074.013 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2022-09-01T16:01:17.949Z,1662048077.949 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2022-09-01T16:01:26.751Z,1662048086.751 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2022-09-01T16:01:45.011Z,1662048105.011 [NAL9602](INFO): SBD MO Status=2, MOMSN=44636, MT Status=2, MTMSN=0
2022-09-01T16:01:45.011Z,1662048105.011 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-09-01T16:01:51.289Z,1662048111.289 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2022-09-01T16:01:54.486Z,1662048114.486 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2022-09-01T16:01:55.035Z,1662048115.035 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for BIT error
2022-09-01T16:02:02.892Z,1662048122.892 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2022-09-01T16:02:19.115Z,1662048139.115 [NAL9602](INFO): SBD MO Status=0, MOMSN=44636, MT Status=0, MTMSN=0
2022-09-01T16:02:43.225Z,1662048163.225 [NAL9602](INFO): SBD MO Status=2, MOMSN=44637, MT Status=2, MTMSN=0
2022-09-01T16:02:43.225Z,1662048163.225 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-09-01T16:03:28.023Z,1662048208.023 [NAL9602](INFO): SBD MO Status=1, MOMSN=44637, MT Status=0, MTMSN=0
2022-09-01T16:03:28.080Z,1662048208.080 [NAL9602](INFO): Sent 51 bytes from file Logs/20220901T153923/Courier0013.lzma
2022-09-01T16:03:28.080Z,1662048208.080 [NAL9602](INFO): Packets left to send: 0
2022-09-01T16:03:43.595Z,1662048223.595 [NAL9602](INFO): SBD MO Status=1, MOMSN=44638, MT Status=0, MTMSN=0
2022-09-01T16:03:43.644Z,1662048223.644 [NAL9602](INFO): Sent 184 bytes from file Logs/20220901T153923/Express0014.lzma
2022-09-01T16:03:43.644Z,1662048223.644 [NAL9602](INFO): Packets left to send: 1
2022-09-01T16:03:54.223Z,1662048234.223 [NAL9602](INFO): SBD MO Status=1, MOMSN=44639, MT Status=0, MTMSN=0
2022-09-01T16:03:54.276Z,1662048234.276 [NAL9602](INFO): Sent 123 bytes from file Logs/20220901T153923/Express0014.lzma
2022-09-01T16:03:54.276Z,1662048234.276 [NAL9602](INFO): Packets left to send: 0
2022-09-01T16:04:10.829Z,1662048250.829 [NAL9602](INFO): SBD MO Status=0, MOMSN=44640, MT Status=0, MTMSN=0
2022-09-01T16:04:10.924Z,1662048250.924 [Default:CheckIn:Read_Iridium] Stopped
2022-09-01T16:04:10.924Z,1662048250.924 [Default:CheckIn:C.Wait] Running Loop=1
2022-09-01T16:04:10.924Z,1662048250.924 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-09-01T16:04:20.160Z,1662048260.160 [RDI_PathfinderUp](ERROR): only read 2 of 4 data items
2022-09-01T16:04:41.535Z,1662048281.535 [NAL9602](INFO): Not Powering down - fast GPS
2022-09-01T16:07:42.556Z,1662048462.556 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2022-09-01T16:09:11.440Z,1662048551.440 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-09-01T16:09:11.440Z,1662048551.440 [Default:CheckIn:C.Wait] Stopped
2022-09-01T16:09:11.440Z,1662048551.440 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-09-01T16:09:11.440Z,1662048551.440 [Default:CheckIn:D] Running Loop=1
2022-09-01T16:09:11.849Z,1662048551.849 [Default:CheckIn:D] Stopped
2022-09-01T16:09:11.849Z,1662048551.849 [Default:CheckIn:E] Running Loop=1
2022-09-01T16:09:12.236Z,1662048552.236 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 26.428556 min 
2022-09-01T16:09:12.236Z,1662048552.236 [Default:CheckIn:E] Stopped
2022-09-01T16:09:12.236Z,1662048552.236 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-09-01T16:09:12.236Z,1662048552.236 [Default:CheckIn] Stopped
2022-09-01T16:09:12.236Z,1662048552.236 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-09-01T16:09:12.237Z,1662048552.237 [Default:CheckIn](INFO): Running loop #4
2022-09-01T16:09:12.237Z,1662048552.237 [Default:CheckIn] Running Loop=4
2022-09-01T16:09:12.237Z,1662048552.237 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-09-01T16:09:12.237Z,1662048552.237 [Default:CheckIn:Read_GPS] Running Loop=1
2022-09-01T16:09:14.245Z,1662048554.245 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160921.00,A,4036.22383,N,07040.01433,W,9.214,184.04,010922,,,D*74
2022-09-01T16:09:14.248Z,1662048554.248 [NAL9602](INFO): GPS fix at 20220901T160921: (40.603730, -70.666905)
2022-09-01T16:09:14.259Z,1662048554.259 [Default:CheckIn:Read_GPS] Stopped
2022-09-01T16:09:14.259Z,1662048554.259 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-09-01T16:09:42.414Z,1662048582.414 [NAL9602](INFO): SBD MO Status=2, MOMSN=44641, MT Status=2, MTMSN=0
2022-09-01T16:09:42.414Z,1662048582.414 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-09-01T16:09:50.583Z,1662048590.583 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2022-09-01T16:10:01.553Z,1662048601.553 [NAL9602](INFO): SBD MO Status=1, MOMSN=44641, MT Status=0, MTMSN=0
2022-09-01T16:10:01.603Z,1662048601.603 [NAL9602](INFO): Sent 74 bytes from file Logs/20220901T153923/Courier0016.lzma
2022-09-01T16:10:01.603Z,1662048601.603 [NAL9602](INFO): Packets left to send: 0
2022-09-01T16:10:17.149Z,1662048617.149 [NAL9602](INFO): SBD MO Status=1, MOMSN=44642, MT Status=0, MTMSN=0
2022-09-01T16:10:17.200Z,1662048617.200 [NAL9602](INFO): Sent 129 bytes from file Logs/20220901T153923/Express0017.lzma
2022-09-01T16:10:17.200Z,1662048617.200 [NAL9602](INFO): Packets left to send: 0
2022-09-01T16:10:22.842Z,1662048622.842 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for BIT error
2022-09-01T16:10:34.111Z,1662048634.111 [NAL9602](INFO): SBD MO Status=0, MOMSN=44643, MT Status=0, MTMSN=0
2022-09-01T16:10:34.197Z,1662048634.197 [Default:CheckIn:Read_Iridium] Stopped
2022-09-01T16:10:34.197Z,1662048634.197 [Default:CheckIn:C.Wait] Running Loop=1
2022-09-01T16:10:34.197Z,1662048634.197 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-09-01T16:11:04.824Z,1662048664.824 [NAL9602](INFO): Not Powering down - fast GPS
2022-09-01T16:11:45.230Z,1662048705.230 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31

2022-09-01T16:11:45.234Z,1662048705.234 [Micromodem](INFO): Nmea in: $CACST,6,1,20220901161145.885013,06,2106,27,0111,0150,261,02,02,01,02,-1,-01,-01,1,3,7,0,150,12.6,0.02,-100,2.98,-01,-2.06,63,14500,4000*50

2022-09-01T16:15:31.078Z,1662048931.078 [Micromodem](INFO): Nmea in: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error

2022-09-01T16:15:31.078Z,1662048931.078 [Micromodem](ERROR): Response from modem failed NMEA checksum: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error
 expected 41
2022-09-01T16:15:31.080Z,1662048931.080 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31

2022-09-01T16:15:31.473Z,1662048931.473 [Micromodem](INFO): Nmea in: $CACST,6,1,20220901161531.886679,06,2030,21,2114,0150,208,01,01,02,01,-1,-01,-01,1,3,1,0,150,-100.0,0.35,-100,2.65,-01,0.48,-2147483648,14500,4000*45

2022-09-01T16:15:34.763Z,1662048934.763 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-09-01T16:15:34.763Z,1662048934.763 [Default:CheckIn:C.Wait] Stopped
2022-09-01T16:15:34.763Z,1662048934.763 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-09-01T16:15:34.763Z,1662048934.763 [Default:CheckIn:D] Running Loop=1
2022-09-01T16:15:35.123Z,1662048935.123 [Default:CheckIn:D] Stopped
2022-09-01T16:15:35.123Z,1662048935.123 [Default:CheckIn:E] Running Loop=1
2022-09-01T16:15:35.557Z,1662048935.557 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 32.816451 min 
2022-09-01T16:15:35.557Z,1662048935.557 [Default:CheckIn:E] Stopped
2022-09-01T16:15:35.558Z,1662048935.558 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-09-01T16:15:35.558Z,1662048935.558 [Default:CheckIn] Stopped
2022-09-01T16:15:35.558Z,1662048935.558 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-09-01T16:15:35.558Z,1662048935.558 [Default:CheckIn](INFO): Running loop #5
2022-09-01T16:15:35.558Z,1662048935.558 [Default:CheckIn] Running Loop=5
2022-09-01T16:15:35.558Z,1662048935.558 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-09-01T16:15:35.558Z,1662048935.558 [Default:CheckIn:Read_GPS] Running Loop=1
2022-09-01T16:15:37.532Z,1662048937.532 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,161544.00,A,4035.21192,N,07040.01693,W,9.525,181.64,010922,,,D*76
2022-09-01T16:15:37.535Z,1662048937.535 [NAL9602](INFO): GPS fix at 20220901T161544: (40.586865, -70.666949)
2022-09-01T16:15:37.546Z,1662048937.546 [Default:CheckIn:Read_GPS] Stopped
2022-09-01T16:15:37.546Z,1662048937.546 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-09-01T16:16:02.036Z,1662048962.036 [NAL9602](INFO): SBD MO Status=1, MOMSN=44644, MT Status=0, MTMSN=0
2022-09-01T16:16:02.085Z,1662048962.085 [NAL9602](INFO): Sent 73 bytes from file Logs/20220901T153923/Courier0019.lzma
2022-09-01T16:16:02.085Z,1662048962.085 [NAL9602](INFO): Packets left to send: 0
2022-09-01T16:16:13.103Z,1662048973.103 [NAL9602](INFO): SBD MO Status=1, MOMSN=44645, MT Status=0, MTMSN=0
2022-09-01T16:16:13.152Z,1662048973.152 [NAL9602](INFO): Sent 129 bytes from file Logs/20220901T153923/Express0020.lzma
2022-09-01T16:16:13.152Z,1662048973.152 [NAL9602](INFO): Packets left to send: 0
2022-09-01T16:16:21.555Z,1662048981.555 [NAL9602](INFO): SBD MO Status=0, MOMSN=44646, MT Status=0, MTMSN=0
2022-09-01T16:16:21.640Z,1662048981.640 [Default:CheckIn:Read_Iridium] Stopped
2022-09-01T16:16:21.640Z,1662048981.640 [Default:CheckIn:C.Wait] Running Loop=1
2022-09-01T16:16:21.640Z,1662048981.640 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-09-01T16:16:52.297Z,1662049012.297 [NAL9602](INFO): Not Powering down - fast GPS
2022-09-01T16:17:59.362Z,1662049079.362 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31

2022-09-01T16:17:59.366Z,1662049079.366 [Micromodem](INFO): Nmea in: $CACST,6,1,20220901161759.888619,06,2064,21,2150,0150,208,01,01,02,02,-1,-01,-01,1,3,1,0,150,19.6,0.50,-100,2.50,-01,-0.94,56,14500,4000*53

2022-09-01T16:21:11.628Z,1662049271.628 [CommandExec](IMPORTANT): got command ibit
2022-09-01T16:21:11.710Z,1662049271.710 [IBIT](IMPORTANT): Beginning Initiated BIT
2022-09-01T16:21:11.710Z,1662049271.710 [IBIT](IMPORTANT): Beginning control surface checks.
2022-09-01T16:21:11.713Z,1662049271.713 [CBIT](IMPORTANT): Beginning ground fault scan
2022-09-01T16:21:13.308Z,1662049273.308 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162120.00,A,4034.32003,N,07040.01178,W,9.661,177.97,010922,,,D*7D
2022-09-01T16:21:13.310Z,1662049273.310 [NAL9602](INFO): GPS fix at 20220901T162120: (40.572001, -70.666863)
2022-09-01T16:21:22.687Z,1662049282.687 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.075402
CHAN A1 (24V): 0.002077
CHAN A2 (12V): 0.000933
CHAN A3 (5V): 0.001925
CHAN B0 (3.3V): 0.000794
CHAN B1 (3.15aV): 0.000578
CHAN B2 (3.15bV): 0.000898
CHAN B3 (GND): -0.001857
OPEN: 0.006379
Full Scale: +/- 1 mA
2022-09-01T16:21:29.469Z,1662049289.469 [NAL9602](INFO): SBD MO Status=0, MOMSN=44647, MT Status=0, MTMSN=0
2022-09-01T16:21:29.469Z,1662049289.469 [NAL9602](INFO): No messages in MT queue
2022-09-01T16:21:30.674Z,1662049290.674 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162137.00,A,4034.27458,N,07040.01102,W,9.603,179.21,010922,,,D*7F
2022-09-01T16:21:30.676Z,1662049290.676 [NAL9602](INFO): GPS fix at 20220901T162137: (40.571243, -70.666850)
2022-09-01T16:21:33.530Z,1662049293.530 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162140.00,A,4034.26631,N,07040.01047,W,9.428,175.78,010922,,,D*78
2022-09-01T16:21:33.532Z,1662049293.532 [NAL9602](INFO): GPS fix at 20220901T162140: (40.571105, -70.666841)
2022-09-01T16:21:36.336Z,1662049296.336 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162143.00,A,4034.25833,N,07040.01009,W,9.622,177.98,010922,,,D*7A
2022-09-01T16:21:36.339Z,1662049296.339 [NAL9602](INFO): GPS fix at 20220901T162143: (40.570972, -70.666835)
2022-09-01T16:21:39.572Z,1662049299.572 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162146.00,A,4034.25045,N,07040.00975,W,9.603,180.01,010922,,,D*7E
2022-09-01T16:21:39.574Z,1662049299.574 [NAL9602](INFO): GPS fix at 20220901T162146: (40.570841, -70.666829)
2022-09-01T16:21:42.396Z,1662049302.396 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162149.00,A,4034.24245,N,07040.00953,W,10.089,180.32,010922,,,D*4A
2022-09-01T16:21:42.398Z,1662049302.398 [NAL9602](INFO): GPS fix at 20220901T162149: (40.570707, -70.666826)
2022-09-01T16:21:45.624Z,1662049305.624 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162152.00,A,4034.23440,N,07040.00949,W,9.544,176.70,010922,,,D*7C
2022-09-01T16:21:45.626Z,1662049305.626 [NAL9602](INFO): GPS fix at 20220901T162152: (40.570573, -70.666825)
2022-09-01T16:21:48.465Z,1662049308.465 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162155.00,A,4034.22640,N,07040.00954,W,9.544,179.82,010922,,,D*76
2022-09-01T16:21:48.471Z,1662049308.471 [NAL9602](INFO): GPS fix at 20220901T162155: (40.570440, -70.666826)
2022-09-01T16:21:51.688Z,1662049311.688 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162158.00,A,4034.21865,N,07040.00975,W,9.641,180.95,010922,,,D*74
2022-09-01T16:21:51.690Z,1662049311.690 [NAL9602](INFO): GPS fix at 20220901T162158: (40.570311, -70.666829)
2022-09-01T16:21:54.532Z,1662049314.532 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162201.00,A,4034.21061,N,07040.01014,W,10.030,180.87,010922,,,D*43
2022-09-01T16:21:54.535Z,1662049314.535 [NAL9602](INFO): GPS fix at 20220901T162201: (40.570177, -70.666836)
2022-09-01T16:21:57.349Z,1662049317.349 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162204.00,A,4034.20241,N,07040.01006,W,9.972,177.70,010922,,,D*73
2022-09-01T16:21:57.351Z,1662049317.351 [NAL9602](INFO): GPS fix at 20220901T162204: (40.570040, -70.666834)
2022-09-01T16:21:58.201Z,1662049318.201 [IBIT](IMPORTANT): Communications Status:
Fix Status: 1
Iridium Signal Strength: 3
Latitude: 40.570042 Longitude: -70.666832
2022-09-01T16:21:58.631Z,1662049318.631 [IBIT](IMPORTANT): Battery Status:
Battery Charge (AH): 0.000000
Voltage: 16.690001
2022-09-01T16:21:58.635Z,1662049318.635 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah
2022-09-01T16:21:58.636Z,1662049318.636 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V
2022-09-01T16:21:58.999Z,1662049318.999 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2022-09-01T16:21:58.000Z,1662049319.000 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2022-09-01T16:21:59.000Z,1662049319.000 [IBIT](IMPORTANT): Pressure:7.668112 PSI
2022-09-01T16:21:59.001Z,1662049319.001 [IBIT](IMPORTANT): Humidity:24.044683 %
2022-09-01T16:21:59.383Z,1662049319.383 [IBIT](IMPORTANT): Vehicle Pitch:-0.862348 degrees
2022-09-01T16:21:59.384Z,1662049319.384 [IBIT](IMPORTANT): Vehicle  Roll:0.651301 degrees
2022-09-01T16:21:59.384Z,1662049319.384 [IBIT](IMPORTANT): Vehicle  Heading:356.377167 degrees
2022-09-01T16:21:59.795Z,1662049319.795 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2022-09-01T16:21:59.796Z,1662049319.796 [IBIT](IMPORTANT): buoyancyNeutral: 175.000000 cc
2022-09-01T16:21:59.796Z,1662049319.796 [IBIT](IMPORTANT): massDefault: 0.500000 cm
2022-09-01T16:21:59.796Z,1662049319.796 [IBIT](IMPORTANT): stopDepth: 35.000000 m
2022-09-01T16:21:59.797Z,1662049319.797 [IBIT](IMPORTANT): abortDepth: 50.000000 m
2022-09-01T16:21:59.797Z,1662049319.797 [IBIT](IMPORTANT): IBIT PASSED
2022-09-01T16:22:00.194Z,1662049320.194 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-09-01T16:22:00.194Z,1662049320.194 [Default:CheckIn:C.Wait] Stopped
2022-09-01T16:22:00.194Z,1662049320.194 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-09-01T16:22:00.194Z,1662049320.194 [Default:CheckIn:D] Running Loop=1
2022-09-01T16:22:00.622Z,1662049320.622 [Default:CheckIn:D] Stopped
2022-09-01T16:22:00.622Z,1662049320.622 [Default:CheckIn:E] Running Loop=1
2022-09-01T16:22:00.988Z,1662049320.988 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 39.241439 min 
2022-09-01T16:22:00.988Z,1662049320.988 [Default:CheckIn:E] Stopped
2022-09-01T16:22:00.988Z,1662049320.988 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-09-01T16:22:00.988Z,1662049320.988 [Default:CheckIn] Stopped
2022-09-01T16:22:00.988Z,1662049320.988 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-09-01T16:22:00.988Z,1662049320.988 [Default:CheckIn](INFO): Running loop #6
2022-09-01T16:22:00.988Z,1662049320.988 [Default:CheckIn] Running Loop=6
2022-09-01T16:22:00.988Z,1662049320.988 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-09-01T16:22:00.989Z,1662049320.989 [Default:CheckIn:Read_GPS] Running Loop=1
2022-09-01T16:22:02.996Z,1662049322.996 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162209.00,A,4034.18959,N,07040.01024,W,9.952,179.77,010922,,,D*7C
2022-09-01T16:22:02.998Z,1662049322.998 [NAL9602](INFO): GPS fix at 20220901T162209: (40.569826, -70.666837)
2022-09-01T16:22:03.009Z,1662049323.009 [Default:CheckIn:Read_GPS] Stopped
2022-09-01T16:22:03.009Z,1662049323.009 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-09-01T16:22:26.396Z,1662049346.396 [NAL9602](INFO): SBD MO Status=2, MOMSN=44648, MT Status=2, MTMSN=0
2022-09-01T16:22:26.396Z,1662049346.396 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-09-01T16:22:42.761Z,1662049362.761 [NAL9602](INFO): SBD MO Status=1, MOMSN=44648, MT Status=0, MTMSN=0
2022-09-01T16:22:42.816Z,1662049362.816 [NAL9602](INFO): Sent 74 bytes from file Logs/20220901T153923/Courier0022.lzma
2022-09-01T16:22:42.817Z,1662049362.817 [NAL9602](INFO): Packets left to send: 0
2022-09-01T16:22:57.315Z,1662049377.315 [Micromodem](INFO): Nmea in: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error

2022-09-01T16:22:57.316Z,1662049377.316 [Micromodem](ERROR): Response from modem failed NMEA checksum: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error
 expected 41
2022-09-01T16:22:57.718Z,1662049377.718 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31

2022-09-01T16:22:58.128Z,1662049378.128 [Micromodem](INFO): Nmea in: $CACST,6,1,20220901162257.889749,06,2086,21,0108,0150,276,02,02,02,02,-1,-01,-01,1,3,1,0,150,-100.0,0.46,-100,2.54,-01,-0.59,-2147483648,14500,4000*6F

2022-09-01T16:23:02.164Z,1662049382.164 [NAL9602](INFO): SBD MO Status=1, MOMSN=44649, MT Status=0, MTMSN=0
2022-09-01T16:23:02.212Z,1662049382.212 [NAL9602](INFO): Sent 184 bytes from file Logs/20220901T153923/Express0023.lzma
2022-09-01T16:23:02.212Z,1662049382.212 [NAL9602](INFO): Packets left to send: 4
2022-09-01T16:23:10.775Z,1662049390.775 [NAL9602](INFO): SBD MO Status=1, MOMSN=44650, MT Status=0, MTMSN=0
2022-09-01T16:23:10.836Z,1662049390.836 [NAL9602](INFO): Sent 184 bytes from file Logs/20220901T153923/Express0023.lzma
2022-09-01T16:23:10.836Z,1662049390.836 [NAL9602](INFO): Packets left to send: 3
2022-09-01T16:23:30.272Z,1662049410.272 [NAL9602](INFO): SBD MO Status=1, MOMSN=44651, MT Status=0, MTMSN=0
2022-09-01T16:23:30.320Z,1662049410.320 [NAL9602](INFO): Sent 184 bytes from file Logs/20220901T153923/Express0023.lzma
2022-09-01T16:23:30.320Z,1662049410.320 [NAL9602](INFO): Packets left to send: 2
2022-09-01T16:23:42.427Z,1662049422.427 [NAL9602](INFO): SBD MO Status=1, MOMSN=44652, MT Status=0, MTMSN=0
2022-09-01T16:23:42.502Z,1662049422.502 [NAL9602](INFO): Sent 184 bytes from file Logs/20220901T153923/Express0023.lzma
2022-09-01T16:23:42.503Z,1662049422.503 [NAL9602](INFO): Packets left to send: 1
2022-09-01T16:23:49.526Z,1662049429.526 [NAL9602](INFO): SBD MO Status=1, MOMSN=44653, MT Status=0, MTMSN=0
2022-09-01T16:23:49.592Z,1662049429.592 [NAL9602](INFO): Sent 33 bytes from file Logs/20220901T153923/Express0023.lzma
2022-09-01T16:23:49.592Z,1662049429.592 [NAL9602](INFO): Packets left to send: 0
2022-09-01T16:23:56.712Z,1662049436.712 [NAL9602](INFO): SBD MO Status=0, MOMSN=44654, MT Status=0, MTMSN=0
2022-09-01T16:23:56.844Z,1662049436.844 [Default:CheckIn:Read_Iridium] Stopped
2022-09-01T16:23:56.844Z,1662049436.844 [Default:CheckIn:C.Wait] Running Loop=1
2022-09-01T16:23:56.844Z,1662049436.844 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-09-01T16:24:27.191Z,1662049467.191 [NAL9602](INFO): Not Powering down - fast GPS
2022-09-01T16:28:57.482Z,1662049737.482 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-09-01T16:28:57.482Z,1662049737.482 [Default:CheckIn:C.Wait] Stopped
2022-09-01T16:28:57.482Z,1662049737.482 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-09-01T16:28:57.482Z,1662049737.482 [Default:CheckIn:D] Running Loop=1
2022-09-01T16:28:57.904Z,1662049737.904 [Default:CheckIn:D] Stopped
2022-09-01T16:28:57.904Z,1662049737.904 [Default:CheckIn:E] Running Loop=1
2022-09-01T16:28:58.308Z,1662049738.308 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 46.196139 min 
2022-09-01T16:28:58.308Z,1662049738.308 [Default:CheckIn:E] Stopped
2022-09-01T16:28:58.309Z,1662049738.309 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-09-01T16:28:58.309Z,1662049738.309 [Default:CheckIn] Stopped
2022-09-01T16:28:58.309Z,1662049738.309 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-09-01T16:28:58.309Z,1662049738.309 [Default:CheckIn](INFO): Running loop #7
2022-09-01T16:28:58.309Z,1662049738.309 [Default:CheckIn] Running Loop=7
2022-09-01T16:28:58.309Z,1662049738.309 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-09-01T16:28:58.309Z,1662049738.309 [Default:CheckIn:Read_GPS] Running Loop=1
2022-09-01T16:29:00.299Z,1662049740.299 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162907.00,A,4033.07538,N,07039.99130,W,9.622,179.29,010922,,,D*73
2022-09-01T16:29:00.301Z,1662049740.301 [NAL9602](INFO): GPS fix at 20220901T162907: (40.551256, -70.666522)
2022-09-01T16:29:00.322Z,1662049740.322 [Default:CheckIn:Read_GPS] Stopped
2022-09-01T16:29:00.322Z,1662049740.322 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-09-01T16:29:20.770Z,1662049760.770 [NAL9602](INFO): SBD MO Status=1, MOMSN=44655, MT Status=0, MTMSN=0
2022-09-01T16:29:20.820Z,1662049760.820 [NAL9602](INFO): Sent 73 bytes from file Logs/20220901T153923/Courier0025.lzma
2022-09-01T16:29:20.820Z,1662049760.820 [NAL9602](INFO): Packets left to send: 0
2022-09-01T16:29:32.247Z,1662049772.247 [NAL9602](INFO): SBD MO Status=1, MOMSN=44656, MT Status=0, MTMSN=0
2022-09-01T16:29:32.304Z,1662049772.304 [NAL9602](INFO): Sent 130 bytes from file Logs/20220901T153923/Express0026.lzma
2022-09-01T16:29:32.304Z,1662049772.304 [NAL9602](INFO): Packets left to send: 0
2022-09-01T16:29:51.134Z,1662049791.134 [NAL9602](INFO): SBD MO Status=0, MOMSN=44657, MT Status=0, MTMSN=0
2022-09-01T16:29:51.216Z,1662049791.216 [Default:CheckIn:Read_Iridium] Stopped
2022-09-01T16:29:51.217Z,1662049791.217 [Default:CheckIn:C.Wait] Running Loop=1
2022-09-01T16:29:51.217Z,1662049791.217 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-09-01T16:30:14.892Z,1662049814.892 [CommandExec](IMPORTANT): got command DDM arm
2022-09-01T16:30:14.893Z,1662049814.893 [CommandExec](IMPORTANT): Switching docking moudle to ARM.
2022-09-01T16:30:21.829Z,1662049821.829 [NAL9602](INFO): Not Powering down - fast GPS
2022-09-01T16:31:16.783Z,1662049876.783 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2022-09-01T16:31:26.566Z,1662049886.566 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2022-09-01T16:31:36.591Z,1662049896.591 [RDI_Pathfinder](ERROR): only read 1 of 4 data items
2022-09-01T16:31:46.716Z,1662049906.716 [RDI_PathfinderUp](ERROR): only read 3 of 4 data items
2022-09-01T16:31:53.946Z,1662049913.946 [Micromodem](INFO): Nmea in: $CAMSG,BAD_CRC, Data Header,2*00

2022-09-01T16:31:53.950Z,1662049913.950 [Micromodem](INFO): Nmea in: $CACST,6,1,20220901163151.881376,06,2259,27,0095,0150,223,01,01,01,01,3,-01,-01,2,3,1,0,150,9.3,-7.91,00,10.91,-01,-2.64,57,14500,4000*42

2022-09-01T16:31:56.797Z,1662049916.797 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2022-09-01T16:31:56.801Z,1662049916.801 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for BIT error
2022-09-01T16:32:44.851Z,1662049964.851 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2022-09-01T16:34:51.721Z,1662050091.721 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-09-01T16:34:51.721Z,1662050091.721 [Default:CheckIn:C.Wait] Stopped
2022-09-01T16:34:51.721Z,1662050091.721 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-09-01T16:34:51.721Z,1662050091.721 [Default:CheckIn:D] Running Loop=1
2022-09-01T16:34:52.157Z,1662050092.157 [Default:CheckIn:D] Stopped
2022-09-01T16:34:52.158Z,1662050092.158 [Default:CheckIn:E] Running Loop=1
2022-09-01T16:34:52.630Z,1662050092.630 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 52.100362 min 
2022-09-01T16:34:52.630Z,1662050092.630 [Default:CheckIn:E] Stopped
2022-09-01T16:34:52.630Z,1662050092.630 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-09-01T16:34:52.630Z,1662050092.630 [Default:CheckIn] Stopped
2022-09-01T16:34:52.630Z,1662050092.630 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-09-01T16:34:52.630Z,1662050092.630 [Default:CheckIn](INFO): Running loop #8
2022-09-01T16:34:52.630Z,1662050092.630 [Default:CheckIn] Running Loop=8
2022-09-01T16:34:52.630Z,1662050092.630 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-09-01T16:34:52.630Z,1662050092.630 [Default:CheckIn:Read_GPS] Running Loop=1
2022-09-01T16:34:54.541Z,1662050094.541 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163501.00,A,4032.13084,N,07039.96800,W,10.050,174.70,010922,,,D*41
2022-09-01T16:34:54.543Z,1662050094.543 [NAL9602](INFO): GPS fix at 20220901T163501: (40.535514, -70.666133)
2022-09-01T16:34:54.620Z,1662050094.620 [Default:CheckIn:Read_GPS] Stopped
2022-09-01T16:34:54.620Z,1662050094.620 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-09-01T16:35:09.634Z,1662050109.634 [NAL9602](INFO): SBD MO Status=1, MOMSN=44658, MT Status=0, MTMSN=0
2022-09-01T16:35:09.688Z,1662050109.688 [NAL9602](INFO): Sent 74 bytes from file Logs/20220901T153923/Courier0028.lzma
2022-09-01T16:35:09.688Z,1662050109.688 [NAL9602](INFO): Packets left to send: 0
2022-09-01T16:35:28.875Z,1662050128.875 [NAL9602](INFO): SBD MO Status=1, MOMSN=44659, MT Status=0, MTMSN=0
2022-09-01T16:35:28.940Z,1662050128.940 [NAL9602](INFO): Sent 184 bytes from file Logs/20220901T153923/Express0029.lzma
2022-09-01T16:35:28.940Z,1662050128.940 [NAL9602](INFO): Packets left to send: 1
2022-09-01T16:35:44.060Z,1662050144.060 [NAL9602](INFO): SBD MO Status=1, MOMSN=44660, MT Status=0, MTMSN=0
2022-09-01T16:35:44.108Z,1662050144.108 [NAL9602](INFO): Sent 1 bytes from file Logs/20220901T153923/Express0029.lzma
2022-09-01T16:35:44.108Z,1662050144.108 [NAL9602](INFO): Packets left to send: 0
2022-09-01T16:35:57.297Z,1662050157.297 [NAL9602](INFO): SBD MO Status=0, MOMSN=44661, MT Status=0, MTMSN=0
2022-09-01T16:35:57.398Z,1662050157.398 [Default:CheckIn:Read_Iridium] Stopped
2022-09-01T16:35:57.398Z,1662050157.398 [Default:CheckIn:C.Wait] Running Loop=1
2022-09-01T16:35:57.398Z,1662050157.398 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-09-01T16:36:27.992Z,1662050187.992 [NAL9602](INFO): Not Powering down - fast GPS
2022-09-01T16:36:46.993Z,1662050206.993 [RDI_PathfinderUp](ERROR): only read 2 of 4 data items
2022-09-01T16:38:23.562Z,1662050303.562 [CommandExec](IMPORTANT): got command get platform_battery_charge
2022-09-01T16:38:23.563Z,1662050303.563 [CommandExec](FAULT): Element has no value
2022-09-01T16:38:30.820Z,1662050310.820 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2022-09-01T16:38:39.410Z,1662050319.410 [CommandExec](IMPORTANT): got command get platform_battery_charge 
2022-09-01T16:38:39.410Z,1662050319.410 [CommandExec](FAULT): Incomplete syntax. Try: help get
2022-09-01T16:38:58.721Z,1662050338.721 [RDI_PathfinderUp](ERROR): only read 2 of 4 data items
2022-09-01T16:40:33.494Z,1662050433.494 [CommandExec](IMPORTANT): got command get 
2022-09-01T16:40:33.494Z,1662050433.494 [CommandExec](FAULT): Incomplete syntax. Try: help get
2022-09-01T16:40:44.560Z,1662050444.560 [RDI_Pathfinder](ERROR): only read 0 of 4 data items
2022-09-01T16:40:55.580Z,1662050455.580 [CommandExec](IMPORTANT): got command DDM arm
2022-09-01T16:40:55.581Z,1662050455.581 [CommandExec](IMPORTANT): Switching docking moudle to ARM.
2022-09-01T16:40:57.897Z,1662050457.897 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-09-01T16:40:57.897Z,1662050457.897 [Default:CheckIn:C.Wait] Stopped
2022-09-01T16:40:57.897Z,1662050457.897 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-09-01T16:40:57.897Z,1662050457.897 [Default:CheckIn:D] Running Loop=1
2022-09-01T16:40:58.284Z,1662050458.284 [Default:CheckIn:D] Stopped
2022-09-01T16:40:58.284Z,1662050458.284 [Default:CheckIn:E] Running Loop=1
2022-09-01T16:40:58.776Z,1662050458.776 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 58.202474 min 
2022-09-01T16:40:58.776Z,1662050458.776 [Default:CheckIn:E] Stopped
2022-09-01T16:40:58.776Z,1662050458.776 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-09-01T16:40:58.777Z,1662050458.777 [Default:CheckIn] Stopped
2022-09-01T16:40:58.777Z,1662050458.777 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-09-01T16:40:58.777Z,1662050458.777 [Default:CheckIn](INFO): Running loop #9
2022-09-01T16:40:58.777Z,1662050458.777 [Default:CheckIn] Running Loop=9
2022-09-01T16:40:58.777Z,1662050458.777 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-09-01T16:40:58.777Z,1662050458.777 [Default:CheckIn:Read_GPS] Running Loop=1
2022-09-01T16:41:00.696Z,1662050460.696 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164107.00,A,4031.14932,N,07039.93463,W,9.661,180.84,010922,,,D*74
2022-09-01T16:41:00.698Z,1662050460.698 [NAL9602](INFO): GPS fix at 20220901T164107: (40.519155, -70.665577)
2022-09-01T16:41:00.730Z,1662050460.730 [Default:CheckIn:Read_GPS] Stopped
2022-09-01T16:41:00.730Z,1662050460.730 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-09-01T16:41:14.422Z,1662050474.422 [CommandExec](IMPORTANT): got command get platform_battery_charge
2022-09-01T16:41:14.423Z,1662050474.422 [CommandExec](FAULT): Element has no value
2022-09-01T16:41:14.783Z,1662050474.783 [NAL9602](INFO): SBD MO Status=1, MOMSN=44662, MT Status=0, MTMSN=0
2022-09-01T16:41:14.832Z,1662050474.832 [NAL9602](INFO): Sent 73 bytes from file Logs/20220901T153923/Courier0031.lzma
2022-09-01T16:41:14.832Z,1662050474.832 [NAL9602](INFO): Packets left to send: 0
2022-09-01T16:41:27.860Z,1662050487.860 [NAL9602](INFO): SBD MO Status=1, MOMSN=44663, MT Status=0, MTMSN=0
2022-09-01T16:41:27.920Z,1662050487.920 [NAL9602](INFO): Sent 184 bytes from file Logs/20220901T153923/Express0032.lzma
2022-09-01T16:41:27.920Z,1662050487.920 [NAL9602](INFO): Packets left to send: 1
2022-09-01T16:41:50.674Z,1662050510.674 [NAL9602](INFO): SBD MO Status=1, MOMSN=44664, MT Status=0, MTMSN=0
2022-09-01T16:41:50.724Z,1662050510.724 [NAL9602](INFO): Sent 100 bytes from file Logs/20220901T153923/Express0032.lzma
2022-09-01T16:41:50.724Z,1662050510.724 [NAL9602](INFO): Packets left to send: 0
2022-09-01T16:41:57.135Z,1662050517.135 [NAL9602](INFO): SBD MO Status=0, MOMSN=44665, MT Status=0, MTMSN=0
2022-09-01T16:41:57.220Z,1662050517.220 [Default:CheckIn:Read_Iridium] Stopped
2022-09-01T16:41:57.220Z,1662050517.220 [Default:CheckIn:C.Wait] Running Loop=1
2022-09-01T16:41:57.220Z,1662050517.220 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-09-01T16:42:12.148Z,1662050532.148 [RDI_PathfinderUp](ERROR): only read 3 of 4 data items
2022-09-01T16:42:27.853Z,1662050547.853 [NAL9602](INFO): Not Powering down - fast GPS
2022-09-01T16:44:37.164Z,1662050677.164 [RDI_PathfinderUp](ERROR): only read 3 of 4 data items
2022-09-01T16:44:46.835Z,1662050686.835 [Micromodem](INFO): Nmea in: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error

2022-09-01T16:44:46.835Z,1662050686.835 [Micromodem](ERROR): Response from modem failed NMEA checksum: $CATRC,RECV,COP , 213,COPROC_par_read_parobj: size error
 expected 41
2022-09-01T16:44:47.236Z,1662050687.236 [Micromodem](INFO): Nmea in: $CAMSG,Bad Modulation Header,0*31

2022-09-01T16:44:47.240Z,1662050687.240 [Micromodem](INFO): Nmea in: $CACST,6,1,20220901164445.887038,06,2324,21,0476,0150,246,02,02,02,02,-1,-01,-01,1,3,4,0,150,79.6,-3.81,-100,6.81,-01,-1.83,-12,14500,4000*5F

2022-09-01T16:45:24.120Z,1662050724.120 [CommandExec](IMPORTANT): got command get platform_battery_voltage
2022-09-01T16:45:24.120Z,1662050724.120 [CommandExec](IMPORTANT): platform_battery_voltage 16.690001 V
2022-09-01T16:45:24.850Z,1662050724.850 [RDI_PathfinderUp](ERROR): only read 3 of 4 data items
2022-09-01T16:45:35.054Z,1662050735.054 [CommandExec](IMPORTANT): got command get platform_battery_charge
2022-09-01T16:45:35.054Z,1662050735.054 [CommandExec](FAULT): Element has no value
2022-09-01T16:45:39.324Z,1662050739.324 [CommandExec](IMPORTANT): got command failComponent 
2022-09-01T16:45:39.324Z,1662050739.324 [CommandExec](IMPORTANT): Failed components:
2022-09-01T16:45:39.324Z,1662050739.324 [CommandExec](IMPORTANT): No failed Components.
2022-09-01T16:46:57.751Z,1662050817.751 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-09-01T16:46:57.751Z,1662050817.751 [Default:CheckIn:C.Wait] Stopped
2022-09-01T16:46:57.751Z,1662050817.751 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-09-01T16:46:57.751Z,1662050817.751 [Default:CheckIn:D] Running Loop=1
2022-09-01T16:46:58.151Z,1662050818.151 [Default:CheckIn:D] Stopped
2022-09-01T16:46:58.151Z,1662050818.151 [Default:CheckIn:E] Running Loop=1
2022-09-01T16:46:58.575Z,1662050818.575 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 64.200244 min 
2022-09-01T16:46:58.575Z,1662050818.575 [Default:CheckIn:E] Stopped
2022-09-01T16:46:58.575Z,1662050818.575 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-09-01T16:46:58.575Z,1662050818.575 [Default:CheckIn] Stopped
2022-09-01T16:46:58.576Z,1662050818.576 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-09-01T16:46:58.576Z,1662050818.576 [Default:CheckIn](INFO): Running loop #10
2022-09-01T16:46:58.576Z,1662050818.576 [Default:CheckIn] Running Loop=10
2022-09-01T16:46:58.576Z,1662050818.576 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-09-01T16:46:58.576Z,1662050818.576 [Default:CheckIn:Read_GPS] Running Loop=1
2022-09-01T16:47:00.559Z,1662050820.559 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164707.00,A,4030.21529,N,07039.90585,W,6.512,175.58,010922,,,D*7A
2022-09-01T16:47:00.562Z,1662050820.562 [NAL9602](INFO): GPS fix at 20220901T164707: (40.503588, -70.665098)
2022-09-01T16:47:00.621Z,1662050820.621 [Default:CheckIn:Read_GPS] Stopped
2022-09-01T16:47:00.621Z,1662050820.621 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-09-01T16:47:23.799Z,1662050843.799 [NAL9602](INFO): SBD MO Status=1, MOMSN=44666, MT Status=0, MTMSN=0
2022-09-01T16:47:23.856Z,1662050843.856 [NAL9602](INFO): Sent 74 bytes from file Logs/20220901T153923/Courier0034.lzma
2022-09-01T16:47:23.856Z,1662050843.856 [NAL9602](INFO): Packets left to send: 0
2022-09-01T16:47:35.296Z,1662050855.296 [NAL9602](INFO): SBD MO Status=1, MOMSN=44667, MT Status=0, MTMSN=0
2022-09-01T16:47:35.350Z,1662050855.350 [NAL9602](INFO): Sent 184 bytes from file Logs/20220901T153923/Express0035.lzma
2022-09-01T16:47:35.350Z,1662050855.350 [NAL9602](INFO): Packets left to send: 1
2022-09-01T16:47:44.711Z,1662050864.711 [NAL9602](INFO): SBD MO Status=1, MOMSN=44668, MT Status=0, MTMSN=0
2022-09-01T16:47:44.776Z,1662050864.776 [NAL9602](INFO): Sent 93 bytes from file Logs/20220901T153923/Express0035.lzma
2022-09-01T16:47:44.776Z,1662050864.776 [NAL9602](INFO): Packets left to send: 0
2022-09-01T16:47:51.924Z,1662050871.924 [NAL9602](INFO): SBD MO Status=0, MOMSN=44669, MT Status=0, MTMSN=0
2022-09-01T16:47:52.032Z,1662050872.032 [Default:CheckIn:Read_Iridium] Stopped
2022-09-01T16:47:52.032Z,1662050872.032 [Default:CheckIn:C.Wait] Running Loop=1
2022-09-01T16:47:52.033Z,1662050872.033 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-09-01T16:48:03.149Z,1662050883.149 [CommandExec](IMPORTANT): got command configSet DDM.loadAtStartup 1 bool persist
2022-09-01T16:48:03.149Z,1662050883.149 [CommandExec](IMPORTANT): configSet DDM.loadAtStartup requires a restart to take effect.
2022-09-01T16:48:03.150Z,1662050883.150 [CommandExec](FAULT): Not allowing to overwrite existing Data/persisted.cfg after unclean shutdown.
2022-09-01T16:48:22.618Z,1662050902.618 [NAL9602](INFO): Not Powering down - fast GPS
2022-09-01T16:48:27.425Z,1662050907.425 [CommandExec](IMPORTANT): got command restart application
2022-09-01T16:48:28.431Z,1662050908.431 [Supervisor](INFO): Stop Mission called by Supervisor::terminate
2022-09-01T16:48:28.432Z,1662050908.432 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread.
2022-09-01T16:48:28.432Z,1662050908.432 [CommandExec](INFO): Uninitializing the command executive.
2022-09-01T16:48:28.432Z,1662050908.432 [CommandExec](INFO): Uninitializing the command scheduler.
2022-09-01T16:48:28.432Z,1662050908.432 [CommandExec ThreadHandler](INFO): Thread cancelled.
2022-09-01T16:48:28.515Z,1662050908.515 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2022-09-01T16:48:28.516Z,1662050908.516 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2022-09-01T16:48:28.516Z,1662050908.516 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2022-09-01T16:48:28.516Z,1662050908.516 [NavChartDb](INFO): Join timeout helper Thread ID is 6428
2022-09-01T16:48:28.528Z,1662050908.528 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2022-09-01T16:48:28.528Z,1662050908.528 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2022-09-01T16:48:28.535Z,1662050908.535 [ComponentRegistry](INFO): Shutting down WetLabsSeaOWL_UV_A ThreadHandler
2022-09-01T16:48:28.536Z,1662050908.536 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2022-09-01T16:48:28.536Z,1662050908.536 [WetLabsSeaOWL_UV_A](INFO): Join timeout helper Thread ID is 6429
2022-09-01T16:48:28.624Z,1662050908.624 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Uninitializing protected caller thread.
2022-09-01T16:48:28.624Z,1662050908.624 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2022-09-01T16:48:28.636Z,1662050908.636 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2022-09-01T16:48:28.636Z,1662050908.636 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2022-09-01T16:48:28.636Z,1662050908.636 [CTD_Seabird](INFO): Join timeout helper Thread ID is 6430
2022-09-01T16:48:29.052Z,1662050909.052 [CTD_Seabird](INFO): Powering down
2022-09-01T16:48:29.063Z,1662050909.063 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2022-09-01T16:48:29.064Z,1662050909.064 [CTD_Seabird](INFO): Powering down
2022-09-01T16:48:29.084Z,1662050909.084 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2022-09-01T16:48:29.103Z,1662050909.103 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2022-09-01T16:48:29.104Z,1662050909.104 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2022-09-01T16:48:29.104Z,1662050909.104 [Radio_Surface](INFO): Join timeout helper Thread ID is 6431
2022-09-01T16:48:29.284Z,1662050909.284 [Radio_Surface](INFO): Powering down
2022-09-01T16:48:29.284Z,1662050909.284 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2022-09-01T16:48:29.285Z,1662050909.285 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2022-09-01T16:48:29.285Z,1662050909.285 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler
2022-09-01T16:48:29.285Z,1662050909.285 [Onboard ThreadHandler](INFO): Thread cancelled.
2022-09-01T16:48:29.286Z,1662050909.286 [Onboard](INFO): Join timeout helper Thread ID is 6432
2022-09-01T16:48:32.283Z,1662050912.283 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread.
2022-09-01T16:48:32.284Z,1662050912.284 [Onboard ThreadHandler](INFO): Thread cancelled.
2022-09-01T16:48:32.296Z,1662050912.296 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2022-09-01T16:48:32.296Z,1662050912.296 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2022-09-01T16:48:32.297Z,1662050912.297 [DataOverHttps](INFO): Join timeout helper Thread ID is 6434
2022-09-01T16:48:32.800Z,1662050912.800 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2022-09-01T16:48:32.800Z,1662050912.800 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2022-09-01T16:48:32.812Z,1662050912.812 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2022-09-01T16:48:32.812Z,1662050912.812 [logger ThreadHandler](INFO): Thread cancelled.
2022-09-01T16:48:32.813Z,1662050912.813 [logger](INFO): Join timeout helper Thread ID is 6435
2022-09-01T16:48:32.826Z,1662050912.826 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2022-09-01T16:48:32.826Z,1662050912.826 [logger ThreadHandler](INFO): Thread cancelled.
2022-09-01T16:48:32.844Z,1662050912.844 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2022-09-01T16:48:32.844Z,1662050912.844 [CommandLine ThreadHandler](INFO): Thread cancelled.
2022-09-01T16:48:32.845Z,1662050912.845 [CommandLine](INFO): Join timeout helper Thread ID is 6436
2022-09-01T16:48:32.892Z,1662050912.892 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2022-09-01T16:48:32.892Z,1662050912.892 [CommandLine ThreadHandler](INFO): Thread cancelled.
2022-09-01T16:48:32.908Z,1662050912.908 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler
2022-09-01T16:48:32.908Z,1662050912.908 [CommandExec ThreadHandler](INFO): Thread cancelled.
2022-09-01T16:48:32.909Z,1662050912.909 [CommandExec](INFO): Join timeout helper Thread ID is 6437
2022-09-01T16:48:32.914Z,1662050912.914 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2022-09-01T16:48:32.914Z,1662050912.914 [controlThread ThreadHandler](INFO): Thread cancelled.
2022-09-01T16:48:32.914Z,1662050912.914 [controlThread](INFO): Join timeout helper Thread ID is 6438
2022-09-01T16:48:33.275Z,1662050913.275 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2022-09-01T16:48:33.276Z,1662050913.276 [controlThread](DEBUG): Uninitializing ControlThread
2022-09-01T16:48:33.276Z,1662050913.276 [AHRS_M2](INFO): Powering down
2022-09-01T16:48:33.348Z,1662050913.348 [Micromodem](INFO): Powering down
2022-09-01T16:48:33.444Z,1662050913.444 [NAL9602](INFO): Powering down
2022-09-01T16:48:33.516Z,1662050913.516 [RDI_Pathfinder](INFO): Powering down
2022-09-01T16:48:33.587Z,1662050913.587 [RDI_PathfinderUp](INFO): Powering down
2022-09-01T16:48:33.589Z,1662050913.589 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2022-09-01T16:48:33.590Z,1662050913.590 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2022-09-01T16:48:33.590Z,1662050913.590 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2022-09-01T16:48:33.591Z,1662050913.591 [MissionManager](INFO): Uninitializing Mission Default
2022-09-01T16:48:33.591Z,1662050913.591 [Default] Stopped
2022-09-01T16:48:33.591Z,1662050913.591 [Default](DEBUG): Aggregate::uninitialize Default
2022-09-01T16:48:33.591Z,1662050913.591 [Default:B.GoToSurface] Stopped
2022-09-01T16:48:33.592Z,1662050913.592 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2022-09-01T16:48:33.592Z,1662050913.592 [Default:CheckIn] Stopped
2022-09-01T16:48:33.592Z,1662050913.592 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-09-01T16:48:33.592Z,1662050913.592 [Default:CheckIn:C.Wait] Stopped
2022-09-01T16:48:33.592Z,1662050913.592 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-09-01T16:48:33.595Z,1662050913.595 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2022-09-01T16:48:33.595Z,1662050913.595 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2022-09-01T16:48:33.596Z,1662050913.596 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2022-09-01T16:48:33.596Z,1662050913.596 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2022-09-01T16:48:33.596Z,1662050913.596 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2022-09-01T16:48:33.596Z,1662050913.596 [BuoyancyServo](INFO): Powering down
2022-09-01T16:48:33.607Z,1662050913.607 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2022-09-01T16:48:33.608Z,1662050913.608 [ElevatorServo](INFO): Powering down
2022-09-01T16:48:33.608Z,1662050913.608 [MassServo](DEBUG): Uninitialize Mass Servo.
2022-09-01T16:48:33.609Z,1662050913.609 [MassServo](INFO): Powering down
2022-09-01T16:48:33.609Z,1662050913.609 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2022-09-01T16:48:33.609Z,1662050913.609 [RudderServo](INFO): Powering down
2022-09-01T16:48:33.610Z,1662050913.610 [ThrusterHE](DEBUG): Uninitialize Thruster Servo.
2022-09-01T16:48:33.610Z,1662050913.610 [ThrusterHE](INFO): Powering down
2022-09-01T16:48:33.611Z,1662050913.611 [SBIT](DEBUG): Uninitialize SBIT Component.
2022-09-01T16:48:33.612Z,1662050913.612 [IBIT](DEBUG): Uninitialize IBIT Component.
2022-09-01T16:48:33.612Z,1662050913.612 [CBIT](DEBUG): Uninitialize CBIT Component.
2022-09-01T16:48:33.612Z,1662050913.612 [CBIT](DEBUG): Powering off loads.
2022-09-01T16:48:33.623Z,1662050913.623 [CBIT](DEBUG): Disabling WDT.
2022-09-01T16:48:33.635Z,1662050913.635 [CBIT](DEBUG): Opening all GF detection circuits.
2022-09-01T16:48:33.636Z,1662050913.636 [controlThread ThreadHandler](INFO): Thread cancelled.
2022-09-01T16:48:33.655Z,1662050913.655 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2022-09-01T16:48:33.659Z,1662050913.659 [Onboard ThreadHandler](INFO): Thread cancelled.
2022-09-01T16:48:33.668Z,1662050913.668 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2022-09-01T16:48:33.755Z,1662050913.755 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2022-09-01T16:48:33.758Z,1662050913.758 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2022-09-01T16:48:33.817Z,1662050913.817 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2022-09-01T16:48:33.885Z,1662050913.885 [logger ThreadHandler](INFO): Thread cancelled.