2023-04-08T00:34:21.276Z,1680914061.276 [Supervisor](DEBUG): Initializing supervisor.
2023-04-08T00:34:21.280Z,1680914061.280 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2023-04-08T00:34:21.280Z,1680914061.280 [SyncHandler](INFO): Protected caller Thread ID is 354
2023-04-08T00:34:21.281Z,1680914061.281 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2023-04-08T00:34:21.282Z,1680914061.282 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2023-04-08T00:34:21.282Z,1680914061.282 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 355
2023-04-08T00:34:21.286Z,1680914061.286 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2023-04-08T00:34:21.303Z,1680914061.303 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2023-04-08T00:34:21.304Z,1680914061.304 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2023-04-08T00:34:21.304Z,1680914061.304 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 356
2023-04-08T00:34:21.309Z,1680914061.309 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2023-04-08T00:34:21.310Z,1680914061.310 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2023-04-08T00:34:21.310Z,1680914061.310 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 357
2023-04-08T00:34:21.312Z,1680914061.312 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2023-04-08T00:34:21.313Z,1680914061.313 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2023-04-08T00:34:21.313Z,1680914061.313 [logger ThreadHandler](INFO): Protected caller Thread ID is 358
2023-04-08T00:34:21.317Z,1680914061.317 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2023-04-08T00:34:21.317Z,1680914061.317 [Supervisor](INFO): Looking for Config files in directory: Config/
2023-04-08T00:34:21.319Z,1680914061.319 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2023-04-08T00:34:21.413Z,1680914061.413 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2023-04-08T00:34:21.414Z,1680914061.414 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2023-04-08T00:34:21.622Z,1680914061.622 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2023-04-08T00:34:21.623Z,1680914061.623 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2023-04-08T00:34:21.868Z,1680914061.868 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2023-04-08T00:34:21.868Z,1680914061.868 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2023-04-08T00:34:21.974Z,1680914061.974 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2023-04-08T00:34:21.974Z,1680914061.974 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2023-04-08T00:34:22.629Z,1680914062.629 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2023-04-08T00:34:22.629Z,1680914062.629 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2023-04-08T00:34:23.089Z,1680914063.089 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2023-04-08T00:34:23.089Z,1680914063.089 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2023-04-08T00:34:23.555Z,1680914063.555 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2023-04-08T00:34:23.556Z,1680914063.556 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2023-04-08T00:34:23.939Z,1680914063.939 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2023-04-08T00:34:23.940Z,1680914063.940 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2023-04-08T00:34:24.253Z,1680914064.253 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2023-04-08T00:34:24.253Z,1680914064.253 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2023-04-08T00:34:24.609Z,1680914064.609 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2023-04-08T00:34:24.610Z,1680914064.610 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2023-04-08T00:34:24.827Z,1680914064.827 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2023-04-08T00:34:24.827Z,1680914064.827 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2023-04-08T00:34:24.963Z,1680914064.963 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2023-04-08T00:34:24.963Z,1680914064.963 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2023-04-08T00:34:25.043Z,1680914065.043 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2023-04-08T00:34:25.121Z,1680914065.121 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2023-04-08T00:34:25.304Z,1680914065.304 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2023-04-08T00:34:25.305Z,1680914065.305 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2023-04-08T00:34:25.527Z,1680914065.527 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2023-04-08T00:34:25.529Z,1680914065.529 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/
2023-04-08T00:34:25.531Z,1680914065.531 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg
2023-04-08T00:34:25.850Z,1680914065.850 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg
2023-04-08T00:34:26.522Z,1680914066.522 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2023-04-08T00:34:26.523Z,1680914066.523 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg
2023-04-08T00:34:26.629Z,1680914066.629 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg
2023-04-08T00:34:26.782Z,1680914066.782 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg
2023-04-08T00:34:26.954Z,1680914066.954 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg
2023-04-08T00:34:27.037Z,1680914067.037 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg
2023-04-08T00:34:27.144Z,1680914067.144 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg
2023-04-08T00:34:27.245Z,1680914067.245 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg
2023-04-08T00:34:27.395Z,1680914067.395 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg
2023-04-08T00:34:27.488Z,1680914067.488 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg
2023-04-08T00:34:27.584Z,1680914067.584 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2023-04-08T00:34:27.599Z,1680914067.599 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2023-04-08T00:34:27.744Z,1680914067.744 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2023-04-08T00:34:27.744Z,1680914067.744 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2023-04-08T00:34:27.899Z,1680914067.899 [BuoyancyServo] Loaded
2023-04-08T00:34:27.899Z,1680914067.899 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2023-04-08T00:34:27.920Z,1680914067.920 [ElevatorServo] Loaded
2023-04-08T00:34:27.920Z,1680914067.920 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2023-04-08T00:34:27.940Z,1680914067.940 [MassServo] Loaded
2023-04-08T00:34:27.940Z,1680914067.940 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2023-04-08T00:34:27.960Z,1680914067.960 [RudderServo] Loaded
2023-04-08T00:34:27.960Z,1680914067.960 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2023-04-08T00:34:27.975Z,1680914067.975 [ThrusterHE] Loaded
2023-04-08T00:34:27.976Z,1680914067.976 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread.
2023-04-08T00:34:27.976Z,1680914067.976 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2023-04-08T00:34:27.976Z,1680914067.976 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2023-04-08T00:34:28.118Z,1680914068.118 [SBIT](DEBUG): Construct Startup Built In Test.
2023-04-08T00:34:28.132Z,1680914068.132 [SBIT] Loaded
2023-04-08T00:34:28.133Z,1680914068.133 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2023-04-08T00:34:28.135Z,1680914068.135 [IBIT](DEBUG): Construct Initiated Built In Test.
2023-04-08T00:34:28.156Z,1680914068.156 [IBIT] Loaded
2023-04-08T00:34:28.156Z,1680914068.156 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2023-04-08T00:34:28.162Z,1680914068.162 [CBIT](DEBUG): Construct Continuous Built In Test.
2023-04-08T00:34:28.375Z,1680914068.375 [CBIT] Loaded
2023-04-08T00:34:28.375Z,1680914068.375 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2023-04-08T00:34:28.376Z,1680914068.376 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2023-04-08T00:34:28.376Z,1680914068.376 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2023-04-08T00:34:28.539Z,1680914068.539 [CTD_Seabird] Loaded
2023-04-08T00:34:28.539Z,1680914068.539 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2023-04-08T00:34:28.540Z,1680914068.540 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 406644E0
2023-04-08T00:34:28.541Z,1680914068.541 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 443
2023-04-08T00:34:28.572Z,1680914068.572 [ESPComponent] Loaded
2023-04-08T00:34:28.572Z,1680914068.572 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2023-04-08T00:34:28.591Z,1680914068.591 [PAR_Licor] Loaded
2023-04-08T00:34:28.591Z,1680914068.591 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2023-04-08T00:34:28.622Z,1680914068.622 [WetLabsBB2FL] Loaded
2023-04-08T00:34:28.622Z,1680914068.622 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2023-04-08T00:34:28.623Z,1680914068.623 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 406944E0
2023-04-08T00:34:28.623Z,1680914068.623 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 444
2023-04-08T00:34:28.624Z,1680914068.624 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2023-04-08T00:34:28.625Z,1680914068.625 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2023-04-08T00:34:28.674Z,1680914068.674 [DepthRateCalculator] Loaded
2023-04-08T00:34:28.674Z,1680914068.674 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2023-04-08T00:34:28.679Z,1680914068.679 [PitchRateCalculator] Loaded
2023-04-08T00:34:28.680Z,1680914068.680 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2023-04-08T00:34:28.689Z,1680914068.689 [SpeedCalculator] Loaded
2023-04-08T00:34:28.690Z,1680914068.690 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2023-04-08T00:34:28.704Z,1680914068.704 [VerticalHomogeneityIndexCalculator] Loaded
2023-04-08T00:34:28.704Z,1680914068.704 [ComponentRegistry](DEBUG): SyncComponent "VerticalHomogeneityIndexCalculator" handled in the control thread.
2023-04-08T00:34:28.708Z,1680914068.708 [YawRateCalculator] Loaded
2023-04-08T00:34:28.709Z,1680914068.709 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2023-04-08T00:34:28.728Z,1680914068.728 [ElevatorOffsetCalculator] Loaded
2023-04-08T00:34:28.728Z,1680914068.728 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2023-04-08T00:34:28.728Z,1680914068.728 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2023-04-08T00:34:28.729Z,1680914068.729 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2023-04-08T00:34:28.827Z,1680914068.827 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2023-04-08T00:34:28.827Z,1680914068.827 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2023-04-08T00:34:28.854Z,1680914068.854 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2023-04-08T00:34:28.854Z,1680914068.854 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2023-04-08T00:34:28.965Z,1680914068.965 [DeadReckonUsingMultipleVelocitySources] Loaded
2023-04-08T00:34:28.965Z,1680914068.965 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2023-04-08T00:34:28.979Z,1680914068.979 [NavChart] Loaded
2023-04-08T00:34:28.979Z,1680914068.979 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2023-04-08T00:34:28.984Z,1680914068.984 [UniversalFixResidualReporter] Loaded
2023-04-08T00:34:28.985Z,1680914068.985 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2023-04-08T00:34:28.985Z,1680914068.985 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2023-04-08T00:34:28.986Z,1680914068.986 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2023-04-08T00:34:29.397Z,1680914069.397 [AHRS_M2] Loaded
2023-04-08T00:34:29.398Z,1680914069.398 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2023-04-08T00:34:29.431Z,1680914069.431 [BackseatComponent] Loaded
2023-04-08T00:34:29.432Z,1680914069.432 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2023-04-08T00:34:29.433Z,1680914069.433 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 40A244E0
2023-04-08T00:34:29.433Z,1680914069.433 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 445
2023-04-08T00:34:29.436Z,1680914069.436 [LcmUniversalReporter] Loaded
2023-04-08T00:34:29.436Z,1680914069.436 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2023-04-08T00:34:30.165Z,1680914070.165 [BPC1] Loaded
2023-04-08T00:34:30.166Z,1680914070.166 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2023-04-08T00:34:30.238Z,1680914070.238 [DataOverHttps] Loaded
2023-04-08T00:34:30.238Z,1680914070.238 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2023-04-08T00:34:30.239Z,1680914070.239 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 40A544E0
2023-04-08T00:34:30.240Z,1680914070.240 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 446
2023-04-08T00:34:30.260Z,1680914070.260 [Depth_Keller] Loaded
2023-04-08T00:34:30.261Z,1680914070.261 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2023-04-08T00:34:30.266Z,1680914070.266 [DropWeight] Loaded
2023-04-08T00:34:30.266Z,1680914070.266 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2023-04-08T00:34:30.304Z,1680914070.304 [DVL_micro] Loaded
2023-04-08T00:34:30.304Z,1680914070.304 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread.
2023-04-08T00:34:30.364Z,1680914070.364 [NAL9602] Loaded
2023-04-08T00:34:30.364Z,1680914070.364 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2023-04-08T00:34:30.391Z,1680914070.391 [Onboard] Loaded
2023-04-08T00:34:30.391Z,1680914070.391 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2023-04-08T00:34:30.392Z,1680914070.392 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 40A844E0
2023-04-08T00:34:30.392Z,1680914070.392 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 447
2023-04-08T00:34:30.404Z,1680914070.404 [Power24vConverter] Loaded
2023-04-08T00:34:30.405Z,1680914070.405 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2023-04-08T00:34:30.418Z,1680914070.418 [Radio_Surface] Loaded
2023-04-08T00:34:30.418Z,1680914070.418 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2023-04-08T00:34:30.419Z,1680914070.419 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 40AB44E0
2023-04-08T00:34:30.419Z,1680914070.419 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 448
2023-04-08T00:34:30.512Z,1680914070.512 [DAT] Loaded
2023-04-08T00:34:30.512Z,1680914070.512 [ComponentRegistry](DEBUG): Component "DAT" handled in its own thread.
2023-04-08T00:34:30.513Z,1680914070.513 [DAT ThreadHandler](DEBUG): Created PCaller Thread at 40AE44E0
2023-04-08T00:34:30.514Z,1680914070.514 [DAT ThreadHandler](INFO): Protected caller Thread ID is 449
2023-04-08T00:34:30.514Z,1680914070.514 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2023-04-08T00:34:30.515Z,1680914070.515 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2023-04-08T00:34:30.585Z,1680914070.585 [StratificationFrontDetector](IMPORTANT): thresholdVTHI set to: 0.050012 degC
2023-04-08T00:34:30.586Z,1680914070.586 [StratificationFrontDetector](INFO): (re)initializing
2023-04-08T00:34:30.586Z,1680914070.586 [StratificationFrontDetector] Loaded
2023-04-08T00:34:30.586Z,1680914070.586 [ComponentRegistry](DEBUG): SyncComponent "StratificationFrontDetector" handled in the control thread.
2023-04-08T00:34:30.587Z,1680914070.587 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2023-04-08T00:34:30.587Z,1680914070.587 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2023-04-08T00:34:30.868Z,1680914070.868 [VerticalControl](DEBUG): Construct VerticalControl.
2023-04-08T00:34:30.963Z,1680914070.963 [VerticalControl] Loaded
2023-04-08T00:34:30.963Z,1680914070.963 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2023-04-08T00:34:30.998Z,1680914070.998 [HorizontalControl](DEBUG): Construct HorizontalControl.
2023-04-08T00:34:31.104Z,1680914071.104 [HorizontalControl] Loaded
2023-04-08T00:34:31.104Z,1680914071.104 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2023-04-08T00:34:31.107Z,1680914071.107 [SpeedControl](DEBUG): Construct SpeedControl.
2023-04-08T00:34:31.108Z,1680914071.108 [SpeedControl] Loaded
2023-04-08T00:34:31.109Z,1680914071.109 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2023-04-08T00:34:31.111Z,1680914071.111 [LoopControl](DEBUG): Construct LoopControl.
2023-04-08T00:34:31.112Z,1680914071.112 [LoopControl] Loaded
2023-04-08T00:34:31.112Z,1680914071.112 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2023-04-08T00:34:31.113Z,1680914071.113 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2023-04-08T00:34:31.113Z,1680914071.113 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2023-04-08T00:34:31.290Z,1680914071.290 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2023-04-08T00:34:31.291Z,1680914071.291 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2023-04-08T00:34:31.593Z,1680914071.593 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2023-04-08T00:34:31.600Z,1680914071.600 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2023-04-08T00:34:31.603Z,1680914071.603 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2023-04-08T00:34:31.613Z,1680914071.613 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2023-04-08T00:34:31.614Z,1680914071.614 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40BDE4E0
2023-04-08T00:34:31.615Z,1680914071.615 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 450
2023-04-08T00:34:31.619Z,1680914071.619 [Supervisor](INFO): Main Thread ID is 5613
2023-04-08T00:34:31.619Z,1680914071.619 [Supervisor](DEBUG): Running supervisor.
2023-04-08T00:34:31.620Z,1680914071.620 [CommandExec ThreadHandler](INFO): Handler Thread ID is 451
2023-04-08T00:34:31.620Z,1680914071.620 [CommandExec](INFO): Initializing the command executive.
2023-04-08T00:34:31.622Z,1680914071.622 [CommandLine ThreadHandler](INFO): Handler Thread ID is 452
2023-04-08T00:34:31.624Z,1680914071.624 [controlThread ThreadHandler](INFO): Handler Thread ID is 453
2023-04-08T00:34:31.624Z,1680914071.624 [controlThread](DEBUG): Initializing ControlThread
2023-04-08T00:34:31.626Z,1680914071.626 [SBIT](INFO): Initialize SBIT Component.
2023-04-08T00:34:31.627Z,1680914071.627 [SBIT](IMPORTANT): git: 2023-04-04
2023-04-08T00:34:31.627Z,1680914071.627 [SBIT](INFO): git hash: b8e3dc7784c205eaa6d34dbcc6cfad52b0792170
2023-04-08T00:34:31.627Z,1680914071.627 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2023-04-08T00:34:31.629Z,1680914071.629 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
Kernel Reported: #1 PREEMPT Wed Mar 17 08:23:48 PDT 2021
2023-04-08T00:34:31.630Z,1680914071.630 [SBIT](INFO): Beginning SBIT in 59.000000 seconds.
2023-04-08T00:34:31.630Z,1680914071.630 [IBIT](INFO): Initialize IBIT Component.
2023-04-08T00:34:31.631Z,1680914071.631 [CBIT](DEBUG): Initialize CBIT Component.
2023-04-08T00:34:31.632Z,1680914071.632 [logger ThreadHandler](INFO): Handler Thread ID is 454
2023-04-08T00:34:31.642Z,1680914071.642 [CBIT](DEBUG): Initialized mux pins.
2023-04-08T00:34:31.642Z,1680914071.642 [CBIT](DEBUG): Initializing the watchdog timer.
2023-04-08T00:34:31.650Z,1680914071.650 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 455
2023-04-08T00:34:31.651Z,1680914071.651 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2023-04-08T00:34:31.655Z,1680914071.655 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 457
2023-04-08T00:34:31.658Z,1680914071.658 [WetLabsBB2FL](INFO): Powering up
2023-04-08T00:34:31.659Z,1680914071.659 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 459
2023-04-08T00:34:31.666Z,1680914071.666 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2023-04-08T00:34:31.666Z,1680914071.666 [CBIT](DEBUG): Initializing heartbeat.
2023-04-08T00:34:31.667Z,1680914071.667 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 460
2023-04-08T00:34:31.668Z,1680914071.668 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2023-04-08T00:34:31.682Z,1680914071.682 [Onboard ThreadHandler](INFO): Handler Thread ID is 461
2023-04-08T00:34:31.699Z,1680914071.699 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 462
2023-04-08T00:34:31.718Z,1680914071.718 [DAT ThreadHandler](INFO): Handler Thread ID is 463
2023-04-08T00:34:31.719Z,1680914071.719 [DAT](INFO): Powering up
2023-04-08T00:34:31.719Z,1680914071.719 [DAT](DEBUG): Initializing DAT.
2023-04-08T00:34:31.723Z,1680914071.723 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 465
2023-04-08T00:34:31.726Z,1680914071.726 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2023-04-08T00:34:31.726Z,1680914071.726 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2023-04-08T00:34:31.726Z,1680914071.726 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2023-04-08T00:34:31.727Z,1680914071.727 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2023-04-08T00:34:31.727Z,1680914071.727 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2023-04-08T00:34:31.727Z,1680914071.727 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2023-04-08T00:34:31.727Z,1680914071.727 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2023-04-08T00:34:31.727Z,1680914071.727 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2023-04-08T00:34:31.727Z,1680914071.727 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA69M.000
2023-04-08T00:34:31.727Z,1680914071.727 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA69M.000
2023-04-08T00:34:31.738Z,1680914071.738 [CBIT](DEBUG): Deactivating GF circuits.
2023-04-08T00:34:31.738Z,1680914071.738 [CBIT](DEBUG): Deactivating emergency mode.
2023-04-08T00:34:31.778Z,1680914071.778 [CBIT](DEBUG): Backplane powered.
2023-04-08T00:34:31.782Z,1680914071.782 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2023-04-08T00:34:31.782Z,1680914071.782 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2023-04-08T00:34:31.783Z,1680914071.783 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2023-04-08T00:34:31.783Z,1680914071.783 [VerticalHomogeneityIndexCalculator](DEBUG): (re)initializing
2023-04-08T00:34:31.784Z,1680914071.784 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2023-04-08T00:34:31.784Z,1680914071.784 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2023-04-08T00:34:31.785Z,1680914071.785 [NavChart](DEBUG): Initialize NavChart Navigation.
2023-04-08T00:34:31.786Z,1680914071.786 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2023-04-08T00:34:31.796Z,1680914071.796 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2023-04-08T00:34:31.806Z,1680914071.806 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2023-04-08T00:34:31.807Z,1680914071.807 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2023-04-08T00:34:31.807Z,1680914071.807 [LoopControl](DEBUG): Initialize LoopControlComponent.
2023-04-08T00:34:31.808Z,1680914071.808 [MissionManager](INFO): Loading Mission from file: Missions/Startup.xml
2023-04-08T00:34:31.845Z,1680914071.845 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2023-04-08T00:34:31.885Z,1680914071.885 [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>


2023-04-08T00:34:31.886Z,1680914071.886 [MissionManager](INFO): Loading Mission from file: Missions/Default.xml
2023-04-08T00:34:31.967Z,1680914071.967 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2023-04-08T00:34:31.969Z,1680914071.969 [Default:A.Wait](DEBUG): Construct Wait.
2023-04-08T00:34:31.987Z,1680914071.987 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2023-04-08T00:34:32.014Z,1680914072.014 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2023-04-08T00:34:32.017Z,1680914072.017 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2023-04-08T00:34:32.040Z,1680914072.040 [Default:E.Execute](DEBUG): Construct Execute.
2023-04-08T00:34:32.063Z,1680914072.063 [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="P4H">
                <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>


2023-04-08T00:34:32.068Z,1680914072.068 [controlThread](DEBUG): Component order: CycleStarter,ESPComponent,PAR_Licor,AHRS_M2,BPC1,Depth_Keller,DropWeight,DVL_micro,NAL9602,Power24vConverter,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,VerticalHomogeneityIndexCalculator,YawRateCalculator,ElevatorOffsetCalculator,StratificationFrontDetector,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter,
2023-04-08T00:34:32.092Z,1680914072.092 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2023-04-08T00:34:32.106Z,1680914072.106 [Radio_Surface](INFO): Powering up
2023-04-08T00:34:32.163Z,1680914072.163 [Depth_Keller](ERROR): Pressure or depth reading out of range: 1895.444336 decibar, 0.000000 m
2023-04-08T00:34:32.166Z,1680914072.166 [Power24vConverter](INFO): Powering up.
2023-04-08T00:34:32.171Z,1680914072.171 [DepthRateCalculator](ERROR): Depth measurement is not active
2023-04-08T00:34:32.204Z,1680914072.204 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2023-04-08T00:34:32.210Z,1680914072.210 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2023-04-08T00:34:32.211Z,1680914072.211 [ElevatorServo](DEBUG): Initializing EZServoServo.
2023-04-08T00:34:32.218Z,1680914072.218 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2023-04-08T00:34:32.219Z,1680914072.219 [MassServo](DEBUG): Initializing EZServoServo.
2023-04-08T00:34:32.226Z,1680914072.226 [MassServo](DEBUG): Initializing MassServo.
2023-04-08T00:34:32.227Z,1680914072.227 [RudderServo](DEBUG): Initializing EZServoServo.
2023-04-08T00:34:32.234Z,1680914072.234 [RudderServo](DEBUG): Initializing RudderServo.
2023-04-08T00:34:32.235Z,1680914072.235 [ThrusterHE](DEBUG): Initializing EZServoServo.
2023-04-08T00:34:32.242Z,1680914072.242 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2023-04-08T00:34:33.766Z,1680914073.766 [WetLabsBB2FL](INFO): Powering down
2023-04-08T00:34:37.939Z,1680914077.939 [ThrusterHE](ERROR): Zero Speed Commanded.
2023-04-08T00:34:38.722Z,1680914078.722 [CTD_Seabird](ERROR): Device message queue exceeded the allowed limit.
2023-04-08T00:34:43.574Z,1680914083.574 [DAT](INFO): DAT read: 

2023-04-08T00:34:43.576Z,1680914083.576 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series

2023-04-08T00:34:45.087Z,1680914085.087 [DAT](INFO): DAT read: MF Frequency Band

2023-04-08T00:34:45.088Z,1680914085.088 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.15.0

2023-04-08T00:34:45.089Z,1680914085.089 [DAT](INFO): DAT read: Apr  8 2023 00:34:40 

2023-04-08T00:34:46.095Z,1680914086.095 [DAT](INFO): DAT read: Features enabled [Bearing]

2023-04-08T00:34:46.096Z,1680914086.096 [DAT](INFO): DAT read: CONNECT 01200 bits/sec 1 of 4, Rate 1/2 CC

2023-04-08T00:34:46.096Z,1680914086.096 [DAT](INFO): commRate: 1200
2023-04-08T00:34:48.162Z,1680914088.162 [DAT](INFO): entering command mode
2023-04-08T00:34:48.362Z,1680914088.362 [DAT](INFO): DAT read: 

2023-04-08T00:34:48.363Z,1680914088.363 [DAT](INFO): DAT read: user:1>

2023-04-08T00:34:48.363Z,1680914088.363 [DAT](INFO): setting verbose to 3
2023-04-08T00:34:48.614Z,1680914088.614 [DAT](INFO): DAT read: user:1>

2023-04-08T00:34:48.615Z,1680914088.615 [DAT](INFO): DAT read: Verbose         | 3           

2023-04-08T00:34:48.616Z,1680914088.616 [DAT](INFO): set verbose to 3
2023-04-08T00:34:48.616Z,1680914088.616 [DAT](INFO): setting DatVerbose to 27440
2023-04-08T00:34:48.866Z,1680914088.866 [DAT](INFO): DAT read: user:2>

2023-04-08T00:34:48.867Z,1680914088.867 [DAT](INFO): DAT read: DatVerbose      | 27440       

2023-04-08T00:34:48.868Z,1680914088.868 [DAT](INFO): set DatVerbose to 27440
2023-04-08T00:34:48.868Z,1680914088.868 [DAT](INFO): setting transmit power to 8
2023-04-08T00:34:49.119Z,1680914089.119 [DAT](INFO): DAT read: user:3>

2023-04-08T00:34:49.119Z,1680914089.119 [DAT](INFO): DAT read: TxPower         | 8 (Max)     

2023-04-08T00:34:49.120Z,1680914089.120 [DAT](INFO): set transmit power to 8
2023-04-08T00:34:49.120Z,1680914089.120 [DAT](INFO): setting local address to 4
2023-04-08T00:34:49.370Z,1680914089.370 [DAT](INFO): DAT read: user:4>

2023-04-08T00:34:49.371Z,1680914089.371 [DAT](INFO): DAT read: LocalAddr       | 4           

2023-04-08T00:34:49.371Z,1680914089.371 [DAT](INFO): set local address to 4
2023-04-08T00:34:49.373Z,1680914089.373 [DAT](INFO): Setting time to: 0:34:49 And date to:4/8/2023
2023-04-08T00:34:49.622Z,1680914089.622 [DAT](INFO): DAT read: user:5>

2023-04-08T00:34:49.623Z,1680914089.623 [DAT](INFO): DAT read: Sat Apr 8, 2023  00:34:49  

2023-04-08T00:34:49.624Z,1680914089.624 [DAT](INFO): Local DAT time set to Sat Apr 8, 2023  00:34:49  

2023-04-08T00:35:00.772Z,1680914100.772 [NAL9602](INFO): Powering up NAL9602
2023-04-08T00:35:11.677Z,1680914111.677 [NAL9602](INFO): NAL9602 initialized
2023-04-08T00:35:31.081Z,1680914131.081 [SBIT](IMPORTANT): Beginning Startup BIT
2023-04-08T00:35:31.085Z,1680914131.085 [CBIT](IMPORTANT): Beginning ground fault scan
2023-04-08T00:35:37.535Z,1680914137.535 [NAL9602](INFO): SBD MO Status=0, MOMSN=1865, MT Status=0, MTMSN=0
2023-04-08T00:35:37.536Z,1680914137.536 [NAL9602](INFO): No messages in MT queue
2023-04-08T00:35:38.747Z,1680914138.747 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,003535.00,A,3648.13798,N,12147.24633,W,2.644,23.19,080423,,,A*40
2023-04-08T00:35:38.755Z,1680914138.755 [NAL9602](INFO): GPS fix at 20230408T003535: (36.802300, -121.787439)
2023-04-08T00:35:42.046Z,1680914142.046 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.031919
CHAN A1 (24V): 0.042977
CHAN A2 (12V): -0.020165
CHAN A3 (5V): -0.030784
CHAN B0 (3.3V): -0.016150
CHAN B1 (3.15aV): -0.013305
CHAN B2 (3.15bV): -0.006363
CHAN B3 (GND): -0.017645
OPEN: 0.006263
Full Scale: +/- 1 mA
2023-04-08T00:36:11.534Z,1680914171.534 [NAL9602](INFO): Not Powering down - fast GPS
2023-04-08T00:36:25.251Z,1680914185.251 [SBIT](IMPORTANT): SBIT PASSED
2023-04-08T00:36:25.251Z,1680914185.251 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2023-04-08T00:36:25.252Z,1680914185.252 [SBIT](IMPORTANT): CBIT.gfScanTimeout=1 hour;

2023-04-08T00:36:25.252Z,1680914185.252 [SBIT](IMPORTANT): Depth_Keller.offset=-0.8 decibar;

2023-04-08T00:36:25.252Z,1680914185.252 [SBIT](IMPORTANT): ESPComponent.sampleTimeout=4 minute;

2023-04-08T00:36:25.252Z,1680914185.252 [SBIT](IMPORTANT): ElevatorServo.offsetAngle=1 degree;

2023-04-08T00:36:25.252Z,1680914185.252 [SBIT](IMPORTANT): Express linearApproximation VerticalHomogeneityIndexCalculator.vertical_temperature_homogeneity_index 0.050000 celsius;

2023-04-08T00:36:25.252Z,1680914185.252 [SBIT](IMPORTANT): Express none WetLabsBB2FL.BackscatteringCoeff470nm;

2023-04-08T00:36:25.252Z,1680914185.252 [SBIT](IMPORTANT): Express none WetLabsBB2FL.BackscatteringCoeff650nm;

2023-04-08T00:36:25.252Z,1680914185.252 [SBIT](IMPORTANT): StratificationFrontDetector.loadAtStartup=1 bool;

2023-04-08T00:36:25.253Z,1680914185.253 [SBIT](IMPORTANT): StratificationFrontDetector.threshold_VTHI=0.05 celsius;

2023-04-08T00:36:25.253Z,1680914185.253 [SBIT](IMPORTANT): StratificationFrontDetector.verbosity=1 count;

2023-04-08T00:36:25.253Z,1680914185.253 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=155.681673 cubic_centimeter;

2023-04-08T00:36:25.253Z,1680914185.253 [SBIT](IMPORTANT): VerticalControl.massDefault=-1 centimeter;

2023-04-08T00:36:25.253Z,1680914185.253 [SBIT](IMPORTANT): VerticalHomogeneityIndexCalculator.depth3=15 meter;

2023-04-08T00:36:25.253Z,1680914185.253 [SBIT](IMPORTANT): VerticalHomogeneityIndexCalculator.depth4=20 meter;

2023-04-08T00:36:25.253Z,1680914185.253 [SBIT](IMPORTANT): VerticalHomogeneityIndexCalculator.loadAtStartup=1 bool;

2023-04-08T00:36:25.639Z,1680914185.639 [MissionManager](IMPORTANT): Started mission Startup
2023-04-08T00:36:25.639Z,1680914185.639 [Startup] Running Loop=1
2023-04-08T00:36:25.639Z,1680914185.639 [Startup](DEBUG): Aggregate::initialize Startup
2023-04-08T00:36:25.639Z,1680914185.639 [Startup:A.GoToSurface] Running Loop=1
2023-04-08T00:36:25.639Z,1680914185.639 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-04-08T00:36:25.640Z,1680914185.640 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-04-08T00:36:25.640Z,1680914185.640 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-04-08T00:36:25.641Z,1680914185.641 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-04-08T00:36:25.641Z,1680914185.641 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-04-08T00:36:25.641Z,1680914185.641 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-04-08T00:36:25.659Z,1680914185.659 [Startup:StartupSatComms] Running Loop=1
2023-04-08T00:36:25.659Z,1680914185.659 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2023-04-08T00:36:25.659Z,1680914185.659 [Startup:StartupSatComms:A] Running Loop=1
2023-04-08T00:36:26.136Z,1680914186.136 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2023-04-08T00:36:27.634Z,1680914187.634 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,003624.00,A,3648.14173,N,12147.24120,W,0.097,29.46,080423,,,A*48
2023-04-08T00:36:27.636Z,1680914187.636 [NAL9602](INFO): GPS fix at 20230408T003624: (36.802362, -121.787353)
2023-04-08T00:36:27.647Z,1680914187.647 [Startup:StartupSatComms:A] Stopped
2023-04-08T00:36:27.647Z,1680914187.647 [Startup:StartupSatComms:B] Running Loop=1
2023-04-08T00:36:28.056Z,1680914188.056 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2023-04-08T00:36:52.352Z,1680914212.352 [NAL9602](INFO): SBD MO Status=2, MOMSN=1866, MT Status=2, MTMSN=0
2023-04-08T00:36:52.352Z,1680914212.352 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-04-08T00:37:02.113Z,1680914222.113 [NAL9602](INFO): SBD MO Status=1, MOMSN=1866, MT Status=0, MTMSN=0
2023-04-08T00:37:02.170Z,1680914222.170 [NAL9602](INFO): Sent 39 bytes from file Logs/20230407T230302/Courier0037.lzma
2023-04-08T00:37:02.170Z,1680914222.170 [NAL9602](INFO): Packets left to send: 0
2023-04-08T00:37:13.895Z,1680914233.895 [NAL9602](INFO): SBD MO Status=1, MOMSN=1867, MT Status=0, MTMSN=0
2023-04-08T00:37:13.946Z,1680914233.946 [NAL9602](INFO): Sent 267 bytes from file Logs/20230408T003421/Courier0000.lzma
2023-04-08T00:37:13.946Z,1680914233.946 [NAL9602](INFO): Packets left to send: 0
2023-04-08T00:37:24.885Z,1680914244.885 [NAL9602](INFO): SBD MO Status=1, MOMSN=1868, MT Status=0, MTMSN=0
2023-04-08T00:37:24.938Z,1680914244.938 [NAL9602](INFO): Sent 187 bytes from file Logs/20230407T230302/Express0038.lzma
2023-04-08T00:37:24.938Z,1680914244.938 [NAL9602](INFO): Packets left to send: 0
2023-04-08T00:37:28.197Z,1680914248.197 [Startup:StartupSatComms:B](INFO): Timed out from 2023-04-08T00:36:27.6Z
2023-04-08T00:37:28.197Z,1680914248.197 [Startup:StartupSatComms:B] Stopped
2023-04-08T00:37:28.197Z,1680914248.197 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2023-04-08T00:37:28.198Z,1680914248.198 [Startup:StartupSatComms] Stopped
2023-04-08T00:37:28.198Z,1680914248.198 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2023-04-08T00:37:28.198Z,1680914248.198 [Startup](INFO): Completed Startup
2023-04-08T00:37:28.199Z,1680914248.199 [MissionManager](INFO): Startup is completed.
2023-04-08T00:37:28.199Z,1680914248.199 [MissionManager](INFO): Uninitializing Mission Startup
2023-04-08T00:37:28.199Z,1680914248.199 [Startup] Stopped
2023-04-08T00:37:28.199Z,1680914248.199 [Startup](DEBUG): Aggregate::uninitialize Startup
2023-04-08T00:37:28.199Z,1680914248.199 [Startup:A.GoToSurface] Stopped
2023-04-08T00:37:28.199Z,1680914248.199 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2023-04-08T00:37:28.520Z,1680914248.520 [MissionManager](IMPORTANT): Started mission Default
2023-04-08T00:37:28.520Z,1680914248.520 [Default] Running Loop=1
2023-04-08T00:37:28.520Z,1680914248.520 [Default](DEBUG): Aggregate::initialize Default
2023-04-08T00:37:28.520Z,1680914248.520 [Default:B.GoToSurface] Running Loop=1
2023-04-08T00:37:28.520Z,1680914248.520 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-04-08T00:37:28.521Z,1680914248.521 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-04-08T00:37:28.521Z,1680914248.521 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-04-08T00:37:28.521Z,1680914248.521 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-04-08T00:37:28.565Z,1680914248.565 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-04-08T00:37:28.565Z,1680914248.565 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-04-08T00:37:28.614Z,1680914248.614 [Default:A.Wait] Running Loop=1
2023-04-08T00:37:28.614Z,1680914248.614 [Default:A.Wait](DEBUG): Initialize Wait Component.
2023-04-08T00:37:41.649Z,1680914261.649 [Default:A.Wait](INFO): Done Waiting.
2023-04-08T00:37:41.649Z,1680914261.649 [Default:A.Wait] Stopped
2023-04-08T00:37:41.649Z,1680914261.649 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2023-04-08T00:37:42.055Z,1680914262.055 [NAL9602](INFO): SBD MO Status=2, MOMSN=1869, MT Status=2, MTMSN=0
2023-04-08T00:37:42.055Z,1680914262.055 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-04-08T00:37:42.065Z,1680914262.065 [Default:CheckIn] Running Loop=1
2023-04-08T00:37:42.065Z,1680914262.065 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-08T00:37:42.065Z,1680914262.065 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-08T00:37:42.460Z,1680914262.460 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2023-04-08T00:37:44.479Z,1680914264.479 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,003740.00,A,3648.14470,N,12147.22660,W,0.019,64.39,080423,,,A*4F
2023-04-08T00:37:44.482Z,1680914264.482 [NAL9602](INFO): GPS fix at 20230408T003740: (36.802412, -121.787110)
2023-04-08T00:37:44.508Z,1680914264.508 [Default:CheckIn:Read_GPS] Stopped
2023-04-08T00:37:44.508Z,1680914264.508 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-08T00:37:44.899Z,1680914264.899 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2023-04-08T00:37:59.435Z,1680914279.435 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2023-04-08T00:37:59.435Z,1680914279.435 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,+18.7,0000.0,148

2023-04-08T00:38:06.720Z,1680914286.720 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004410
2023-04-08T00:38:18.017Z,1680914298.017 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230408T003421/Courier0004.lzma
2023-04-08T00:38:19.020Z,1680914299.020 [DataOverHttps](INFO): Moved sent file to Logs/20230408T003421/Courier0004.lzma.bak
2023-04-08T00:38:19.020Z,1680914299.020 [DataOverHttps](INFO): SBD MOMSN=18171927
2023-04-08T00:38:36.828Z,1680914316.828 [DataOverHttps](INFO): Sending 1081 bytes from file Logs/20230408T003421/Express0001.lzma
2023-04-08T00:38:37.828Z,1680914317.828 [DataOverHttps](INFO): Moved sent file to Logs/20230408T003421/Express0001.lzma.bak
2023-04-08T00:38:37.828Z,1680914317.828 [DataOverHttps](INFO): SBD MOMSN=18171930
2023-04-08T00:38:39.975Z,1680914319.975 [NAL9602](INFO): Not Powering down - fast GPS
2023-04-08T00:38:56.889Z,1680914336.889 [DataOverHttps](INFO): Sending 115 bytes from file Logs/20230408T003421/Express0005.lzma
2023-04-08T00:38:57.891Z,1680914337.891 [DataOverHttps](INFO): Moved sent file to Logs/20230408T003421/Express0005.lzma.bak
2023-04-08T00:38:57.892Z,1680914337.892 [DataOverHttps](INFO): SBD MOMSN=18171957
2023-04-08T00:38:59.353Z,1680914339.353 [Default:CheckIn:Read_Iridium] Stopped
2023-04-08T00:38:59.353Z,1680914339.353 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-08T00:38:59.353Z,1680914339.353 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-08T00:42:48.417Z,1680914568.417 [DVL_micro](ERROR): Failed to parse:00000000000,35.0,+18.6,0000.0,1489.0,000
2023-04-08T00:43:16.009Z,1680914596.009 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2023-04-08T00:43:16.012Z,1680914596.012 [BPC1](INFO): Received data from all battery sticks.
2023-04-08T00:43:59.979Z,1680914639.979 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-08T00:43:59.980Z,1680914639.980 [Default:CheckIn:C.Wait] Stopped
2023-04-08T00:43:59.980Z,1680914639.980 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-08T00:43:59.980Z,1680914639.980 [Default:CheckIn:D] Running Loop=1
2023-04-08T00:44:00.384Z,1680914640.384 [Default:CheckIn:D] Stopped
2023-04-08T00:44:00.384Z,1680914640.384 [Default:CheckIn:E] Running Loop=1
2023-04-08T00:44:00.785Z,1680914640.785 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 6.531065 min 
2023-04-08T00:44:00.785Z,1680914640.785 [Default:CheckIn:E] Stopped
2023-04-08T00:44:00.786Z,1680914640.786 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-08T00:44:00.786Z,1680914640.786 [Default:CheckIn] Stopped
2023-04-08T00:44:00.786Z,1680914640.786 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-08T00:44:00.786Z,1680914640.786 [Default:CheckIn](INFO): Running loop #2
2023-04-08T00:44:00.786Z,1680914640.786 [Default:CheckIn] Running Loop=2
2023-04-08T00:44:00.786Z,1680914640.786 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-08T00:44:00.786Z,1680914640.786 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-08T00:44:02.807Z,1680914642.807 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,004402.00,A,3648.15157,N,12147.22179,W,0.039,316.56,080423,,,A*7E
2023-04-08T00:44:02.809Z,1680914642.809 [NAL9602](INFO): GPS fix at 20230408T004402: (36.802526, -121.787030)
2023-04-08T00:44:02.819Z,1680914642.819 [Default:CheckIn:Read_GPS] Stopped
2023-04-08T00:44:02.819Z,1680914642.819 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-08T00:44:09.533Z,1680914649.533 [DataOverHttps](INFO): Sending 201 bytes from file Logs/20230408T003421/Courier0007.lzma
2023-04-08T00:44:10.536Z,1680914650.536 [DataOverHttps](INFO): Moved sent file to Logs/20230408T003421/Courier0007.lzma.bak
2023-04-08T00:44:10.536Z,1680914650.536 [DataOverHttps](INFO): SBD MOMSN=18171971
2023-04-08T00:44:26.337Z,1680914666.337 [DataOverHttps](INFO): Sending 160 bytes from file Logs/20230408T003421/Express0008.lzma
2023-04-08T00:44:27.339Z,1680914667.339 [DataOverHttps](INFO): Moved sent file to Logs/20230408T003421/Express0008.lzma.bak
2023-04-08T00:44:27.340Z,1680914667.340 [DataOverHttps](INFO): SBD MOMSN=18171976
2023-04-08T00:44:29.090Z,1680914669.090 [Default:CheckIn:Read_Iridium] Stopped
2023-04-08T00:44:29.090Z,1680914669.090 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-08T00:44:29.090Z,1680914669.090 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-08T00:44:44.860Z,1680914684.860 [NAL9602](INFO): SBD MO Status=1, MOMSN=1869, MT Status=0, MTMSN=0
2023-04-08T00:44:44.860Z,1680914684.860 [NAL9602](INFO): No messages in MT queue
2023-04-08T00:45:15.547Z,1680914715.547 [NAL9602](INFO): Not Powering down - fast GPS
2023-04-08T00:47:08.822Z,1680914828.822 [DVL_micro](ERROR): only read 3 of 4 data items
2023-04-08T00:47:08.822Z,1680914828.822 [DVL_micro](ERROR): Failed to parse:
:BI,-00162,01542,+00000,I
2023-04-08T00:47:36.764Z,1680914856.764 [DVL_micro](ERROR): only read 3 of 4 data items
2023-04-08T00:47:36.765Z,1680914856.765 [DVL_micro](ERROR): Failed to parse:
:RD,+9999.999,+9999.99,+9999.99
2023-04-08T00:48:40.288Z,1680914920.288 [DVL_micro](ERROR): Failed to parse:
:R99,+9999.99,+9999.99,+9999.99
2023-04-08T00:49:29.525Z,1680914969.525 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-08T00:49:29.525Z,1680914969.525 [Default:CheckIn:C.Wait] Stopped
2023-04-08T00:49:29.525Z,1680914969.525 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-08T00:49:29.525Z,1680914969.525 [Default:CheckIn:D] Running Loop=1
2023-04-08T00:49:29.919Z,1680914969.919 [Default:CheckIn:D] Stopped
2023-04-08T00:49:29.919Z,1680914969.919 [Default:CheckIn:E] Running Loop=1
2023-04-08T00:49:30.325Z,1680914970.325 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 12.023311 min 
2023-04-08T00:49:30.325Z,1680914970.325 [Default:CheckIn:E] Stopped
2023-04-08T00:49:30.325Z,1680914970.325 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-08T00:49:30.325Z,1680914970.325 [Default:CheckIn] Stopped
2023-04-08T00:49:30.325Z,1680914970.325 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-08T00:49:30.325Z,1680914970.325 [Default:CheckIn](INFO): Running loop #3
2023-04-08T00:49:30.325Z,1680914970.325 [Default:CheckIn] Running Loop=3
2023-04-08T00:49:30.326Z,1680914970.326 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-08T00:49:30.326Z,1680914970.326 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-08T00:49:32.337Z,1680914972.337 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,004931.00,A,3648.16354,N,12147.19479,W,1.652,179.99,080423,,,D*7B
2023-04-08T00:49:32.339Z,1680914972.339 [NAL9602](INFO): GPS fix at 20230408T004931: (36.802726, -121.786580)
2023-04-08T00:49:32.359Z,1680914972.359 [Default:CheckIn:Read_GPS] Stopped
2023-04-08T00:49:32.359Z,1680914972.359 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-08T00:49:42.753Z,1680914982.753 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20230408T003421/Courier0010.lzma
2023-04-08T00:49:43.764Z,1680914983.764 [DataOverHttps](INFO): Moved sent file to Logs/20230408T003421/Courier0010.lzma.bak
2023-04-08T00:49:43.764Z,1680914983.764 [DataOverHttps](INFO): SBD MOMSN=18171991
2023-04-08T00:49:44.945Z,1680914984.945 [NAL9602](INFO): SBD MO Status=1, MOMSN=1870, MT Status=0, MTMSN=0
2023-04-08T00:49:44.945Z,1680914984.945 [NAL9602](INFO): No messages in MT queue
2023-04-08T00:50:00.337Z,1680915000.337 [DataOverHttps](INFO): Sending 141 bytes from file Logs/20230408T003421/Express0011.lzma
2023-04-08T00:50:01.340Z,1680915001.340 [DataOverHttps](INFO): Moved sent file to Logs/20230408T003421/Express0011.lzma.bak
2023-04-08T00:50:01.340Z,1680915001.340 [DataOverHttps](INFO): SBD MOMSN=18171994
2023-04-08T00:50:02.751Z,1680915002.751 [Default:CheckIn:Read_Iridium] Stopped
2023-04-08T00:50:02.751Z,1680915002.751 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-08T00:50:02.751Z,1680915002.751 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-08T00:50:15.646Z,1680915015.646 [NAL9602](INFO): Not Powering down - fast GPS
2023-04-08T00:55:03.459Z,1680915303.459 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-08T00:55:03.459Z,1680915303.459 [Default:CheckIn:C.Wait] Stopped
2023-04-08T00:55:03.459Z,1680915303.459 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-08T00:55:03.459Z,1680915303.459 [Default:CheckIn:D] Running Loop=1
2023-04-08T00:55:03.861Z,1680915303.861 [Default:CheckIn:D] Stopped
2023-04-08T00:55:03.861Z,1680915303.861 [Default:CheckIn:E] Running Loop=1
2023-04-08T00:55:04.270Z,1680915304.270 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 17.589014 min 
2023-04-08T00:55:04.270Z,1680915304.270 [Default:CheckIn:E] Stopped
2023-04-08T00:55:04.270Z,1680915304.270 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-08T00:55:04.270Z,1680915304.270 [Default:CheckIn] Stopped
2023-04-08T00:55:04.270Z,1680915304.270 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-08T00:55:04.271Z,1680915304.271 [Default:CheckIn](INFO): Running loop #4
2023-04-08T00:55:04.271Z,1680915304.271 [Default:CheckIn] Running Loop=4
2023-04-08T00:55:04.271Z,1680915304.271 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-08T00:55:04.271Z,1680915304.271 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-08T00:55:06.280Z,1680915306.280 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,005505.00,A,3648.45767,N,12147.30897,W,6.415,242.68,080423,,,D*77
2023-04-08T00:55:06.283Z,1680915306.283 [NAL9602](INFO): GPS fix at 20230408T005505: (36.807628, -121.788483)
2023-04-08T00:55:06.312Z,1680915306.312 [Default:CheckIn:Read_GPS] Stopped
2023-04-08T00:55:06.312Z,1680915306.312 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-08T00:55:14.313Z,1680915314.313 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230408T003421/Courier0013.lzma
2023-04-08T00:55:15.316Z,1680915315.316 [DataOverHttps](INFO): Moved sent file to Logs/20230408T003421/Courier0013.lzma.bak
2023-04-08T00:55:15.316Z,1680915315.316 [DataOverHttps](INFO): SBD MOMSN=18172005
2023-04-08T00:55:24.462Z,1680915324.462 [NAL9602](INFO): SBD MO Status=1, MOMSN=1871, MT Status=0, MTMSN=0
2023-04-08T00:55:24.462Z,1680915324.462 [NAL9602](INFO): No messages in MT queue
2023-04-08T00:55:31.693Z,1680915331.693 [DataOverHttps](INFO): Sending 144 bytes from file Logs/20230408T003421/Express0014.lzma
2023-04-08T00:55:32.696Z,1680915332.696 [DataOverHttps](INFO): Moved sent file to Logs/20230408T003421/Express0014.lzma.bak
2023-04-08T00:55:32.696Z,1680915332.696 [DataOverHttps](INFO): SBD MOMSN=18172008
2023-04-08T00:55:32.941Z,1680915332.941 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2023-04-08T00:55:32.941Z,1680915332.941 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,+1.0,1489.0,000
2023-04-08T00:55:34.585Z,1680915334.585 [Default:CheckIn:Read_Iridium] Stopped
2023-04-08T00:55:34.585Z,1680915334.585 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-08T00:55:34.585Z,1680915334.585 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-08T00:55:37.889Z,1680915337.889 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2023-04-08T00:55:37.889Z,1680915337.889 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0000.0,1489.0,000
2023-04-08T00:55:54.862Z,1680915354.862 [NAL9602](INFO): Not Powering down - fast GPS
2023-04-08T00:58:58.336Z,1680915538.336 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2023-04-08T00:58:58.336Z,1680915538.336 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35,0000.0,1489.0,000
2023-04-08T01:00:35.316Z,1680915635.316 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-08T01:00:35.316Z,1680915635.316 [Default:CheckIn:C.Wait] Stopped
2023-04-08T01:00:35.316Z,1680915635.316 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-08T01:00:35.317Z,1680915635.317 [Default:CheckIn:D] Running Loop=1
2023-04-08T01:00:35.720Z,1680915635.720 [Default:CheckIn:D] Stopped
2023-04-08T01:00:35.720Z,1680915635.720 [Default:CheckIn:E] Running Loop=1
2023-04-08T01:00:36.127Z,1680915636.127 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 23.119993 min 
2023-04-08T01:00:36.127Z,1680915636.127 [Default:CheckIn:E] Stopped
2023-04-08T01:00:36.127Z,1680915636.127 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-08T01:00:36.127Z,1680915636.127 [Default:CheckIn] Stopped
2023-04-08T01:00:36.127Z,1680915636.127 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-08T01:00:36.127Z,1680915636.127 [Default:CheckIn](INFO): Running loop #5
2023-04-08T01:00:36.127Z,1680915636.127 [Default:CheckIn] Running Loop=5
2023-04-08T01:00:36.127Z,1680915636.127 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-08T01:00:36.127Z,1680915636.127 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-08T01:00:38.140Z,1680915638.140 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,010037.00,A,3648.12855,N,12148.19764,W,10.050,230.28,080423,,,A*4A
2023-04-08T01:00:38.152Z,1680915638.152 [NAL9602](INFO): GPS fix at 20230408T010037: (36.802143, -121.803294)
2023-04-08T01:00:38.171Z,1680915638.171 [Default:CheckIn:Read_GPS] Stopped
2023-04-08T01:00:38.171Z,1680915638.171 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-08T01:00:46.433Z,1680915646.433 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20230408T003421/Courier0016.lzma
2023-04-08T01:00:47.436Z,1680915647.436 [DataOverHttps](INFO): Moved sent file to Logs/20230408T003421/Courier0016.lzma.bak
2023-04-08T01:00:47.436Z,1680915647.436 [DataOverHttps](INFO): SBD MOMSN=18172012
2023-04-08T01:00:54.291Z,1680915654.291 [NAL9602](INFO): SBD MO Status=1, MOMSN=1872, MT Status=0, MTMSN=0
2023-04-08T01:00:54.292Z,1680915654.292 [NAL9602](INFO): No messages in MT queue
2023-04-08T01:01:03.281Z,1680915663.281 [DataOverHttps](INFO): Sending 141 bytes from file Logs/20230408T003421/Express0017.lzma
2023-04-08T01:01:04.284Z,1680915664.284 [DataOverHttps](INFO): Moved sent file to Logs/20230408T003421/Express0017.lzma.bak
2023-04-08T01:01:04.284Z,1680915664.284 [DataOverHttps](INFO): SBD MOMSN=18172015
2023-04-08T01:01:05.639Z,1680915665.639 [Default:CheckIn:Read_Iridium] Stopped
2023-04-08T01:01:05.639Z,1680915665.639 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-08T01:01:05.639Z,1680915665.639 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-08T01:01:25.004Z,1680915685.004 [NAL9602](INFO): Not Powering down - fast GPS
2023-04-08T01:02:23.218Z,1680915743.218 [DVL_micro](ERROR): only read 3 of 4 data items
2023-04-08T01:02:23.218Z,1680915743.218 [DVL_micro](ERROR): Failed to parse:
:BI,+01150,-0013,+00000,I
2023-04-08T01:05:09.714Z,1680915909.714 [DataOverHttps](INFO): Exceeded connection timeout, disconnecting.
2023-04-08T01:05:56.232Z,1680915956.232 [DVL_micro](ERROR): Failed to parse:
:WI,+00680,+00981,-01432,+00000,A
2023-04-08T01:06:06.361Z,1680915966.361 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-04-08T01:06:06.361Z,1680915966.361 [Default:CheckIn:C.Wait] Stopped
2023-04-08T01:06:06.361Z,1680915966.361 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-04-08T01:06:06.361Z,1680915966.361 [Default:CheckIn:D] Running Loop=1
2023-04-08T01:06:06.744Z,1680915966.744 [Default:CheckIn:D] Stopped
2023-04-08T01:06:06.744Z,1680915966.744 [Default:CheckIn:E] Running Loop=1
2023-04-08T01:06:07.145Z,1680915967.145 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 28.637065 min 
2023-04-08T01:06:07.145Z,1680915967.145 [Default:CheckIn:E] Stopped
2023-04-08T01:06:07.145Z,1680915967.145 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-04-08T01:06:07.145Z,1680915967.145 [Default:CheckIn] Stopped
2023-04-08T01:06:07.145Z,1680915967.145 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-04-08T01:06:07.146Z,1680915967.146 [Default:CheckIn](INFO): Running loop #6
2023-04-08T01:06:07.146Z,1680915967.146 [Default:CheckIn] Running Loop=6
2023-04-08T01:06:07.146Z,1680915967.146 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-04-08T01:06:07.146Z,1680915967.146 [Default:CheckIn:Read_GPS] Running Loop=1
2023-04-08T01:06:09.156Z,1680915969.156 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,010608.00,A,3647.82785,N,12148.71975,W,0.875,181.07,080423,,,D*7B
2023-04-08T01:06:09.168Z,1680915969.168 [NAL9602](INFO): GPS fix at 20230408T010608: (36.797131, -121.811996)
2023-04-08T01:06:09.178Z,1680915969.178 [Default:CheckIn:Read_GPS] Stopped
2023-04-08T01:06:09.178Z,1680915969.178 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-04-08T01:06:16.225Z,1680915976.225 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230408T003421/Courier0019.lzma
2023-04-08T01:06:17.227Z,1680915977.227 [DataOverHttps](INFO): Moved sent file to Logs/20230408T003421/Courier0019.lzma.bak
2023-04-08T01:06:17.228Z,1680915977.228 [DataOverHttps](INFO): SBD MOMSN=18172033
2023-04-08T01:06:33.514Z,1680915993.514 [DataOverHttps](INFO): Sending 145 bytes from file Logs/20230408T003421/Express0020.lzma
2023-04-08T01:06:34.516Z,1680915994.516 [DataOverHttps](INFO): Moved sent file to Logs/20230408T003421/Express0020.lzma.bak
2023-04-08T01:06:34.516Z,1680915994.516 [DataOverHttps](INFO): SBD MOMSN=18172036
2023-04-08T01:06:35.912Z,1680915995.912 [NAL9602](INFO): SBD MO Status=1, MOMSN=1873, MT Status=0, MTMSN=0
2023-04-08T01:06:35.912Z,1680915995.912 [NAL9602](INFO): No messages in MT queue
2023-04-08T01:06:36.282Z,1680915996.282 [Default:CheckIn:Read_Iridium] Stopped
2023-04-08T01:06:36.282Z,1680915996.282 [Default:CheckIn:C.Wait] Running Loop=1
2023-04-08T01:06:36.282Z,1680915996.282 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-04-08T01:07:06.598Z,1680916026.598 [NAL9602](INFO): Not Powering down - fast GPS
2023-04-08T01:08:45.355Z,1680916125.355 [DataOverHttps](IMPORTANT): SBD MTMSN=20230408T010844