2023-03-22T18:38:57.982Z,1679510337.982 [Supervisor](DEBUG): Initializing supervisor.
2023-03-22T18:38:57.987Z,1679510337.987 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2023-03-22T18:38:57.987Z,1679510337.987 [SyncHandler](INFO): Protected caller Thread ID is 7385
2023-03-22T18:38:57.988Z,1679510337.988 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2023-03-22T18:38:57.989Z,1679510337.989 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2023-03-22T18:38:57.989Z,1679510337.989 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 7386
2023-03-22T18:38:57.993Z,1679510337.993 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2023-03-22T18:38:58.010Z,1679510338.010 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2023-03-22T18:38:58.011Z,1679510338.011 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2023-03-22T18:38:58.012Z,1679510338.012 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 7387
2023-03-22T18:38:58.016Z,1679510338.016 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2023-03-22T18:38:58.017Z,1679510338.017 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2023-03-22T18:38:58.017Z,1679510338.017 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 7388
2023-03-22T18:38:58.019Z,1679510338.019 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2023-03-22T18:38:58.020Z,1679510338.020 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2023-03-22T18:38:58.021Z,1679510338.021 [logger ThreadHandler](INFO): Protected caller Thread ID is 7389
2023-03-22T18:38:58.024Z,1679510338.024 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2023-03-22T18:38:58.025Z,1679510338.025 [Supervisor](INFO): Looking for Config files in directory: Config/
2023-03-22T18:38:58.026Z,1679510338.026 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2023-03-22T18:38:58.121Z,1679510338.121 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2023-03-22T18:38:58.122Z,1679510338.122 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2023-03-22T18:38:58.342Z,1679510338.342 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2023-03-22T18:38:58.342Z,1679510338.342 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2023-03-22T18:38:58.589Z,1679510338.589 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2023-03-22T18:38:58.590Z,1679510338.590 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2023-03-22T18:38:58.696Z,1679510338.696 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2023-03-22T18:38:58.697Z,1679510338.697 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2023-03-22T18:38:59.353Z,1679510339.353 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2023-03-22T18:38:59.354Z,1679510339.354 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2023-03-22T18:38:59.815Z,1679510339.815 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2023-03-22T18:38:59.815Z,1679510339.815 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2023-03-22T18:39:00.283Z,1679510340.283 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2023-03-22T18:39:00.284Z,1679510340.284 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2023-03-22T18:39:00.669Z,1679510340.669 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2023-03-22T18:39:00.670Z,1679510340.670 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2023-03-22T18:39:00.983Z,1679510340.983 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2023-03-22T18:39:00.984Z,1679510340.984 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2023-03-22T18:39:01.341Z,1679510341.341 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2023-03-22T18:39:01.342Z,1679510341.342 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2023-03-22T18:39:01.560Z,1679510341.560 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2023-03-22T18:39:01.560Z,1679510341.560 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2023-03-22T18:39:01.697Z,1679510341.697 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2023-03-22T18:39:01.698Z,1679510341.698 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2023-03-22T18:39:01.779Z,1679510341.779 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2023-03-22T18:39:01.858Z,1679510341.858 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2023-03-22T18:39:02.042Z,1679510342.042 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2023-03-22T18:39:02.043Z,1679510342.043 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2023-03-22T18:39:02.261Z,1679510342.261 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2023-03-22T18:39:02.263Z,1679510342.263 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/
2023-03-22T18:39:02.264Z,1679510342.264 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg
2023-03-22T18:39:02.346Z,1679510342.346 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg
2023-03-22T18:39:02.823Z,1679510342.823 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2023-03-22T18:39:02.824Z,1679510342.824 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg
2023-03-22T18:39:03.149Z,1679510343.149 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg
2023-03-22T18:39:03.392Z,1679510343.392 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg
2023-03-22T18:39:03.855Z,1679510343.855 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg
2023-03-22T18:39:04.063Z,1679510344.063 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg
2023-03-22T18:39:04.176Z,1679510344.176 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg
2023-03-22T18:39:04.278Z,1679510344.278 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg
2023-03-22T18:39:04.430Z,1679510344.430 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg
2023-03-22T18:39:04.531Z,1679510344.531 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg
2023-03-22T18:39:04.628Z,1679510344.628 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/root/
2023-03-22T18:39:04.629Z,1679510344.629 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2023-03-22T18:39:04.637Z,1679510344.637 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2023-03-22T18:39:04.783Z,1679510344.783 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2023-03-22T18:39:04.784Z,1679510344.784 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2023-03-22T18:39:04.938Z,1679510344.938 [BuoyancyServo] Loaded
2023-03-22T18:39:04.939Z,1679510344.939 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2023-03-22T18:39:04.959Z,1679510344.959 [ElevatorServo] Loaded
2023-03-22T18:39:04.960Z,1679510344.960 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2023-03-22T18:39:04.980Z,1679510344.980 [MassServo] Loaded
2023-03-22T18:39:04.980Z,1679510344.980 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2023-03-22T18:39:04.000Z,1679510345.000 [RudderServo] Loaded
2023-03-22T18:39:04.000Z,1679510345.000 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2023-03-22T18:39:05.015Z,1679510345.015 [ThrusterHE] Loaded
2023-03-22T18:39:05.016Z,1679510345.016 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread.
2023-03-22T18:39:05.016Z,1679510345.016 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2023-03-22T18:39:05.016Z,1679510345.016 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2023-03-22T18:39:05.158Z,1679510345.158 [SBIT](DEBUG): Construct Startup Built In Test.
2023-03-22T18:39:05.172Z,1679510345.172 [SBIT] Loaded
2023-03-22T18:39:05.173Z,1679510345.173 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2023-03-22T18:39:05.176Z,1679510345.176 [IBIT](DEBUG): Construct Initiated Built In Test.
2023-03-22T18:39:05.196Z,1679510345.196 [IBIT] Loaded
2023-03-22T18:39:05.196Z,1679510345.196 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2023-03-22T18:39:05.202Z,1679510345.202 [CBIT](DEBUG): Construct Continuous Built In Test.
2023-03-22T18:39:05.417Z,1679510345.417 [CBIT] Loaded
2023-03-22T18:39:05.418Z,1679510345.418 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2023-03-22T18:39:05.418Z,1679510345.418 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2023-03-22T18:39:05.418Z,1679510345.418 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2023-03-22T18:39:05.584Z,1679510345.584 [CTD_Seabird] Loaded
2023-03-22T18:39:05.584Z,1679510345.584 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2023-03-22T18:39:05.586Z,1679510345.586 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 406644E0
2023-03-22T18:39:05.586Z,1679510345.586 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 7471
2023-03-22T18:39:05.617Z,1679510345.617 [ESPComponent] Loaded
2023-03-22T18:39:05.617Z,1679510345.617 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2023-03-22T18:39:05.637Z,1679510345.637 [PAR_Licor] Loaded
2023-03-22T18:39:05.637Z,1679510345.637 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2023-03-22T18:39:05.668Z,1679510345.668 [WetLabsBB2FL] Loaded
2023-03-22T18:39:05.668Z,1679510345.668 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2023-03-22T18:39:05.669Z,1679510345.669 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 406944E0
2023-03-22T18:39:05.669Z,1679510345.669 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 7472
2023-03-22T18:39:05.670Z,1679510345.670 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2023-03-22T18:39:05.671Z,1679510345.671 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2023-03-22T18:39:05.721Z,1679510345.721 [DepthRateCalculator] Loaded
2023-03-22T18:39:05.721Z,1679510345.721 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2023-03-22T18:39:05.726Z,1679510345.726 [PitchRateCalculator] Loaded
2023-03-22T18:39:05.727Z,1679510345.727 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2023-03-22T18:39:05.737Z,1679510345.737 [SpeedCalculator] Loaded
2023-03-22T18:39:05.737Z,1679510345.737 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2023-03-22T18:39:05.742Z,1679510345.742 [YawRateCalculator] Loaded
2023-03-22T18:39:05.742Z,1679510345.742 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2023-03-22T18:39:05.761Z,1679510345.761 [ElevatorOffsetCalculator] Loaded
2023-03-22T18:39:05.761Z,1679510345.761 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2023-03-22T18:39:05.762Z,1679510345.762 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2023-03-22T18:39:05.762Z,1679510345.762 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2023-03-22T18:39:05.860Z,1679510345.860 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2023-03-22T18:39:05.860Z,1679510345.860 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2023-03-22T18:39:05.887Z,1679510345.887 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2023-03-22T18:39:05.888Z,1679510345.888 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2023-03-22T18:39:05.000Z,1679510346.000 [DeadReckonUsingMultipleVelocitySources] Loaded
2023-03-22T18:39:05.000Z,1679510346.000 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2023-03-22T18:39:06.014Z,1679510346.014 [NavChart] Loaded
2023-03-22T18:39:06.014Z,1679510346.014 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2023-03-22T18:39:06.019Z,1679510346.019 [UniversalFixResidualReporter] Loaded
2023-03-22T18:39:06.020Z,1679510346.020 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2023-03-22T18:39:06.020Z,1679510346.020 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2023-03-22T18:39:06.021Z,1679510346.021 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2023-03-22T18:39:06.438Z,1679510346.438 [AHRS_M2] Loaded
2023-03-22T18:39:06.438Z,1679510346.438 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2023-03-22T18:39:06.472Z,1679510346.472 [BackseatComponent] Loaded
2023-03-22T18:39:06.473Z,1679510346.473 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2023-03-22T18:39:06.474Z,1679510346.474 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 40A244E0
2023-03-22T18:39:06.474Z,1679510346.474 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 7473
2023-03-22T18:39:06.477Z,1679510346.477 [LcmUniversalReporter] Loaded
2023-03-22T18:39:06.478Z,1679510346.478 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2023-03-22T18:39:07.207Z,1679510347.207 [BPC1] Loaded
2023-03-22T18:39:07.207Z,1679510347.207 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2023-03-22T18:39:07.288Z,1679510347.288 [DataOverHttps] Loaded
2023-03-22T18:39:07.288Z,1679510347.288 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2023-03-22T18:39:07.289Z,1679510347.289 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 40A544E0
2023-03-22T18:39:07.290Z,1679510347.290 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 7474
2023-03-22T18:39:07.311Z,1679510347.311 [Depth_Keller] Loaded
2023-03-22T18:39:07.311Z,1679510347.311 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2023-03-22T18:39:07.316Z,1679510347.316 [DropWeight] Loaded
2023-03-22T18:39:07.316Z,1679510347.316 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2023-03-22T18:39:07.354Z,1679510347.354 [DVL_micro] Loaded
2023-03-22T18:39:07.354Z,1679510347.354 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread.
2023-03-22T18:39:07.373Z,1679510347.373 [MultiRay] Loaded
2023-03-22T18:39:07.374Z,1679510347.374 [ComponentRegistry](DEBUG): SyncComponent "MultiRay" handled in the control thread.
2023-03-22T18:39:07.433Z,1679510347.433 [NAL9602] Loaded
2023-03-22T18:39:07.434Z,1679510347.434 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2023-03-22T18:39:07.460Z,1679510347.460 [Onboard] Loaded
2023-03-22T18:39:07.460Z,1679510347.460 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2023-03-22T18:39:07.461Z,1679510347.461 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 40A844E0
2023-03-22T18:39:07.461Z,1679510347.461 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 7475
2023-03-22T18:39:07.475Z,1679510347.475 [Power24vConverter] Loaded
2023-03-22T18:39:07.475Z,1679510347.475 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2023-03-22T18:39:07.488Z,1679510347.488 [Radio_Surface] Loaded
2023-03-22T18:39:07.488Z,1679510347.488 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2023-03-22T18:39:07.490Z,1679510347.490 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 40AB44E0
2023-03-22T18:39:07.490Z,1679510347.490 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 7476
2023-03-22T18:39:07.583Z,1679510347.583 [DAT] Loaded
2023-03-22T18:39:07.583Z,1679510347.583 [ComponentRegistry](DEBUG): Component "DAT" handled in its own thread.
2023-03-22T18:39:07.584Z,1679510347.584 [DAT ThreadHandler](DEBUG): Created PCaller Thread at 40AE44E0
2023-03-22T18:39:07.585Z,1679510347.585 [DAT ThreadHandler](INFO): Protected caller Thread ID is 7477
2023-03-22T18:39:07.585Z,1679510347.585 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2023-03-22T18:39:07.586Z,1679510347.586 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2023-03-22T18:39:07.828Z,1679510347.828 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2023-03-22T18:39:07.829Z,1679510347.829 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2023-03-22T18:39:07.920Z,1679510347.920 [VerticalControl](DEBUG): Construct VerticalControl.
2023-03-22T18:39:08.141Z,1679510348.141 [VerticalControl] Loaded
2023-03-22T18:39:08.141Z,1679510348.141 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2023-03-22T18:39:08.144Z,1679510348.144 [HorizontalControl](DEBUG): Construct HorizontalControl.
2023-03-22T18:39:08.187Z,1679510348.187 [HorizontalControl] Loaded
2023-03-22T18:39:08.188Z,1679510348.188 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2023-03-22T18:39:08.190Z,1679510348.190 [SpeedControl](DEBUG): Construct SpeedControl.
2023-03-22T18:39:08.192Z,1679510348.192 [SpeedControl] Loaded
2023-03-22T18:39:08.192Z,1679510348.192 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2023-03-22T18:39:08.195Z,1679510348.195 [LoopControl](DEBUG): Construct LoopControl.
2023-03-22T18:39:08.195Z,1679510348.195 [LoopControl] Loaded
2023-03-22T18:39:08.196Z,1679510348.196 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2023-03-22T18:39:08.196Z,1679510348.196 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2023-03-22T18:39:08.197Z,1679510348.197 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2023-03-22T18:39:08.207Z,1679510348.207 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2023-03-22T18:39:08.208Z,1679510348.208 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2023-03-22T18:39:08.513Z,1679510348.513 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2023-03-22T18:39:08.519Z,1679510348.519 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2023-03-22T18:39:08.522Z,1679510348.522 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2023-03-22T18:39:08.533Z,1679510348.533 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2023-03-22T18:39:08.534Z,1679510348.534 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40BDE4E0
2023-03-22T18:39:08.535Z,1679510348.535 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 7478
2023-03-22T18:39:08.539Z,1679510348.539 [Supervisor](INFO): Main Thread ID is 6223
2023-03-22T18:39:08.539Z,1679510348.539 [Supervisor](DEBUG): Running supervisor.
2023-03-22T18:39:08.540Z,1679510348.540 [CommandExec ThreadHandler](INFO): Handler Thread ID is 7479
2023-03-22T18:39:08.540Z,1679510348.540 [CommandExec](INFO): Initializing the command executive.
2023-03-22T18:39:08.542Z,1679510348.542 [CommandLine ThreadHandler](INFO): Handler Thread ID is 7480
2023-03-22T18:39:08.545Z,1679510348.545 [controlThread ThreadHandler](INFO): Handler Thread ID is 7481
2023-03-22T18:39:08.545Z,1679510348.545 [controlThread](DEBUG): Initializing ControlThread
2023-03-22T18:39:08.547Z,1679510348.547 [SBIT](INFO): Initialize SBIT Component.
2023-03-22T18:39:08.548Z,1679510348.548 [SBIT](IMPORTANT): git: 2023-03-21
2023-03-22T18:39:08.548Z,1679510348.548 [SBIT](INFO): git hash: 28f27c305fcecd3fd8a0a0fe0a8b41600ede02df
2023-03-22T18:39:08.548Z,1679510348.548 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2023-03-22T18:39:08.550Z,1679510348.550 [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-03-22T18:39:08.551Z,1679510348.551 [SBIT](INFO): Beginning SBIT in 160.000000 seconds.
2023-03-22T18:39:08.551Z,1679510348.551 [IBIT](INFO): Initialize IBIT Component.
2023-03-22T18:39:08.552Z,1679510348.552 [CBIT](DEBUG): Initialize CBIT Component.
2023-03-22T18:39:08.553Z,1679510348.553 [logger ThreadHandler](INFO): Handler Thread ID is 7482
2023-03-22T18:39:08.565Z,1679510348.565 [CBIT](DEBUG): Initialized mux pins.
2023-03-22T18:39:08.565Z,1679510348.565 [CBIT](DEBUG): Initializing the watchdog timer.
2023-03-22T18:39:08.573Z,1679510348.573 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 7483
2023-03-22T18:39:08.574Z,1679510348.574 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2023-03-22T18:39:08.579Z,1679510348.579 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 7485
2023-03-22T18:39:08.581Z,1679510348.581 [WetLabsBB2FL](INFO): Powering up
2023-03-22T18:39:08.583Z,1679510348.583 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 7487
2023-03-22T18:39:08.589Z,1679510348.589 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2023-03-22T18:39:08.589Z,1679510348.589 [CBIT](DEBUG): Initializing heartbeat.
2023-03-22T18:39:08.591Z,1679510348.591 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 7488
2023-03-22T18:39:08.591Z,1679510348.591 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2023-03-22T18:39:08.613Z,1679510348.613 [Onboard ThreadHandler](INFO): Handler Thread ID is 7489
2023-03-22T18:39:08.631Z,1679510348.631 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 7490
2023-03-22T18:39:08.650Z,1679510348.650 [DAT ThreadHandler](INFO): Handler Thread ID is 7491
2023-03-22T18:39:08.651Z,1679510348.651 [DAT](INFO): Powering up
2023-03-22T18:39:08.651Z,1679510348.651 [DAT](DEBUG): Initializing DAT.
2023-03-22T18:39:08.654Z,1679510348.654 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 7493
2023-03-22T18:39:08.657Z,1679510348.657 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2023-03-22T18:39:08.657Z,1679510348.657 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2023-03-22T18:39:08.657Z,1679510348.657 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2023-03-22T18:39:08.657Z,1679510348.657 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2023-03-22T18:39:08.657Z,1679510348.657 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2023-03-22T18:39:08.658Z,1679510348.658 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2023-03-22T18:39:08.658Z,1679510348.658 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2023-03-22T18:39:08.658Z,1679510348.658 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2023-03-22T18:39:08.658Z,1679510348.658 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA69M.000
2023-03-22T18:39:08.658Z,1679510348.658 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA69M.000
2023-03-22T18:39:08.661Z,1679510348.661 [CBIT](DEBUG): Deactivating GF circuits.
2023-03-22T18:39:08.661Z,1679510348.661 [CBIT](DEBUG): Deactivating emergency mode.
2023-03-22T18:39:08.701Z,1679510348.701 [CBIT](DEBUG): Backplane powered.
2023-03-22T18:39:08.705Z,1679510348.705 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2023-03-22T18:39:08.706Z,1679510348.706 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2023-03-22T18:39:08.706Z,1679510348.706 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2023-03-22T18:39:08.706Z,1679510348.706 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2023-03-22T18:39:08.707Z,1679510348.707 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2023-03-22T18:39:08.708Z,1679510348.708 [NavChart](DEBUG): Initialize NavChart Navigation.
2023-03-22T18:39:08.708Z,1679510348.708 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2023-03-22T18:39:08.715Z,1679510348.715 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2023-03-22T18:39:08.721Z,1679510348.721 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2023-03-22T18:39:08.722Z,1679510348.722 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2023-03-22T18:39:08.722Z,1679510348.722 [LoopControl](DEBUG): Initialize LoopControlComponent.
2023-03-22T18:39:08.723Z,1679510348.723 [MissionManager](INFO): Loading Mission from file: Missions/Startup.xml
2023-03-22T18:39:08.757Z,1679510348.757 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2023-03-22T18:39:08.789Z,1679510348.789 [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-03-22T18:39:08.805Z,1679510348.805 [MissionManager](INFO): Loading Mission from file: Missions/Default.xml
2023-03-22T18:39:08.891Z,1679510348.891 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2023-03-22T18:39:08.892Z,1679510348.892 [Default:A.Wait](DEBUG): Construct Wait.
2023-03-22T18:39:08.904Z,1679510348.904 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2023-03-22T18:39:08.925Z,1679510348.925 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2023-03-22T18:39:08.956Z,1679510348.956 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2023-03-22T18:39:08.990Z,1679510348.990 [Default:E.Execute](DEBUG): Construct Execute.
2023-03-22T18:39:08.994Z,1679510348.994 [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-03-22T18:39:09.005Z,1679510349.005 [controlThread](DEBUG): Component order: CycleStarter,ESPComponent,PAR_Licor,AHRS_M2,BPC1,Depth_Keller,DropWeight,DVL_micro,MultiRay,NAL9602,Power24vConverter,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter,
2023-03-22T18:39:09.041Z,1679510349.041 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2023-03-22T18:39:09.053Z,1679510349.053 [Radio_Surface](INFO): Powering up
2023-03-22T18:39:09.126Z,1679510349.126 [Depth_Keller](ERROR): Pressure or depth reading out of range: 1895.444336 decibar, 0.000000 m
2023-03-22T18:39:09.138Z,1679510349.138 [MultiRay](INFO): Powering up MultiRay Lights
2023-03-22T18:39:09.177Z,1679510349.177 [Power24vConverter](INFO): Powering up.
2023-03-22T18:39:09.185Z,1679510349.185 [DepthRateCalculator](ERROR): Depth measurement is not active
2023-03-22T18:39:09.207Z,1679510349.207 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2023-03-22T18:39:09.213Z,1679510349.213 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2023-03-22T18:39:09.214Z,1679510349.214 [ElevatorServo](DEBUG): Initializing EZServoServo.
2023-03-22T18:39:09.221Z,1679510349.221 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2023-03-22T18:39:09.222Z,1679510349.222 [MassServo](DEBUG): Initializing EZServoServo.
2023-03-22T18:39:09.229Z,1679510349.229 [MassServo](DEBUG): Initializing MassServo.
2023-03-22T18:39:09.230Z,1679510349.230 [RudderServo](DEBUG): Initializing EZServoServo.
2023-03-22T18:39:09.237Z,1679510349.237 [RudderServo](DEBUG): Initializing RudderServo.
2023-03-22T18:39:09.238Z,1679510349.238 [ThrusterHE](DEBUG): Initializing EZServoServo.
2023-03-22T18:39:09.245Z,1679510349.245 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2023-03-22T18:39:10.153Z,1679510350.153 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2023-03-22T18:39:10.153Z,1679510350.153 [RudderServo](FAULT): Rudder failed to initialize
2023-03-22T18:39:10.153Z,1679510350.153 [RudderServo] Communications Fault, FailCount= 1
2023-03-22T18:39:10.153Z,1679510350.153 [RudderServo](ERROR): Communications Fault
2023-03-22T18:39:10.157Z,1679510350.157 [CBIT](ERROR): Communications Fault in component: RudderServo
2023-03-22T18:39:10.625Z,1679510350.625 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2023-03-22T18:39:10.626Z,1679510350.626 [RudderServo](INFO): Powering down
2023-03-22T18:39:10.685Z,1679510350.685 [WetLabsBB2FL](INFO): Powering down
2023-03-22T18:39:11.105Z,1679510351.105 [RudderServo](DEBUG): Initializing EZServoServo.
2023-03-22T18:39:11.226Z,1679510351.226 [RudderServo](DEBUG): Initializing RudderServo.
2023-03-22T18:39:11.230Z,1679510351.230 [CBIT](INFO): Clearing failed state for component RudderServo
2023-03-22T18:39:11.230Z,1679510351.230 [RudderServo] No Fault, FailCount= 1
2023-03-22T18:39:21.002Z,1679510361.002 [DAT](INFO): DAT read: 

2023-03-22T18:39:21.003Z,1679510361.003 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series

2023-03-22T18:39:22.514Z,1679510362.514 [DAT](INFO): DAT read: MF Frequency Band

2023-03-22T18:39:22.515Z,1679510362.515 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.15.0

2023-03-22T18:39:22.516Z,1679510362.516 [DAT](INFO): DAT read: Mar 22 2023 18:39:17 

2023-03-22T18:39:23.522Z,1679510363.522 [DAT](INFO): DAT read: Features enabled [Bearing]

2023-03-22T18:39:23.523Z,1679510363.523 [DAT](INFO): DAT read: CONNECT 01200 bits/sec 1 of 4, Rate 1/2 CC

2023-03-22T18:39:23.523Z,1679510363.523 [DAT](INFO): commRate: 1200
2023-03-22T18:39:25.589Z,1679510365.589 [DAT](INFO): entering command mode
2023-03-22T18:39:25.790Z,1679510365.790 [DAT](INFO): DAT read: 

2023-03-22T18:39:25.791Z,1679510365.791 [DAT](INFO): DAT read: user:1>

2023-03-22T18:39:25.791Z,1679510365.791 [DAT](INFO): setting verbose to 3
2023-03-22T18:39:26.042Z,1679510366.042 [DAT](INFO): DAT read: user:1>

2023-03-22T18:39:26.043Z,1679510366.043 [DAT](INFO): DAT read: Verbose         | 3           

2023-03-22T18:39:26.043Z,1679510366.043 [DAT](INFO): set verbose to 3
2023-03-22T18:39:26.043Z,1679510366.043 [DAT](INFO): setting DatVerbose to 27440
2023-03-22T18:39:26.294Z,1679510366.294 [DAT](INFO): DAT read: user:2>

2023-03-22T18:39:26.295Z,1679510366.295 [DAT](INFO): DAT read: DatVerbose      | 27440       

2023-03-22T18:39:26.295Z,1679510366.295 [DAT](INFO): set DatVerbose to 27440
2023-03-22T18:39:26.295Z,1679510366.295 [DAT](INFO): setting transmit power to 8
2023-03-22T18:39:26.548Z,1679510366.548 [DAT](INFO): DAT read: user:3>

2023-03-22T18:39:26.549Z,1679510366.549 [DAT](INFO): DAT read: TxPower         | 8 (Max)     

2023-03-22T18:39:26.549Z,1679510366.549 [DAT](INFO): set transmit power to 8
2023-03-22T18:39:26.549Z,1679510366.549 [DAT](INFO): setting local address to 4
2023-03-22T18:39:26.798Z,1679510366.798 [DAT](INFO): DAT read: user:4>

2023-03-22T18:39:26.799Z,1679510366.799 [DAT](INFO): DAT read: LocalAddr       | 4           

2023-03-22T18:39:26.799Z,1679510366.799 [DAT](INFO): set local address to 4
2023-03-22T18:39:26.800Z,1679510366.800 [DAT](INFO): Setting time to: 18:39:26 And date to:3/22/2023
2023-03-22T18:39:27.050Z,1679510367.050 [DAT](INFO): DAT read: user:5>

2023-03-22T18:39:27.051Z,1679510367.051 [DAT](INFO): DAT read: Wed Mar 22, 2023  18:39:26  

2023-03-22T18:39:27.051Z,1679510367.051 [DAT](INFO): Local DAT time set to Wed Mar 22, 2023  18:39:26  

2023-03-22T18:39:37.443Z,1679510377.443 [NAL9602](INFO): Powering up NAL9602
2023-03-22T18:39:48.340Z,1679510388.340 [NAL9602](INFO): NAL9602 initialized
2023-03-22T18:41:48.331Z,1679510508.331 [NAL9602](INFO): SBD MO Status=2, MOMSN=47467, MT Status=2, MTMSN=0
2023-03-22T18:41:48.331Z,1679510508.331 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-03-22T18:41:49.146Z,1679510509.146 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2023-03-22T18:41:49.146Z,1679510509.146 [DVL_micro](ERROR): Failed to parse:
:TS0000000,35.0,+12.9,0000.0,1489.0,000
2023-03-22T18:41:49.159Z,1679510509.159 [SBIT](IMPORTANT): Beginning Startup BIT
2023-03-22T18:41:49.164Z,1679510509.164 [CBIT](IMPORTANT): Beginning ground fault scan
2023-03-22T18:42:00.065Z,1679510520.065 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.091257
CHAN A1 (24V): 0.138682
CHAN A2 (12V): 0.027536
CHAN A3 (5V): -0.012269
CHAN B0 (3.3V): -0.007962
CHAN B1 (3.15aV): -0.004157
CHAN B2 (3.15bV): -0.000811
CHAN B3 (GND): -0.018127
OPEN: 0.008916
Full Scale: +/- 1 mA
2023-03-22T18:42:06.548Z,1679510526.548 [DVL_micro](ERROR): only read 3 of 4 data items
2023-03-22T18:42:06.548Z,1679510526.548 [DVL_micro](ERROR): Failed to parse:
:RD,+99999.99,+9999.99,+9999.99
2023-03-22T18:42:08.944Z,1679510528.944 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2023-03-22T18:42:08.944Z,1679510528.944 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-03-22T18:42:09.071Z,1679510529.071 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-03-22T18:42:09.458Z,1679510529.458 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-03-22T18:42:09.458Z,1679510529.458 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2023-03-22T18:42:10.555Z,1679510530.555 [NAL9602](INFO): SBD MO Status=2, MOMSN=47467, MT Status=2, MTMSN=0
2023-03-22T18:42:10.555Z,1679510530.555 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-03-22T18:42:40.453Z,1679510560.453 [NAL9602](INFO): SBD MO Status=2, MOMSN=47467, MT Status=2, MTMSN=0
2023-03-22T18:42:40.453Z,1679510560.453 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-03-22T18:42:42.787Z,1679510562.787 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004298
2023-03-22T18:42:43.281Z,1679510563.281 [SBIT](IMPORTANT): SBIT PASSED
2023-03-22T18:42:43.281Z,1679510563.281 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2023-03-22T18:42:43.282Z,1679510563.282 [SBIT](IMPORTANT): Depth_Keller.offset=-0.8 decibar;

2023-03-22T18:42:43.282Z,1679510563.282 [SBIT](IMPORTANT): ESPComponent.sampleTimeout=4 minute;

2023-03-22T18:42:43.282Z,1679510563.282 [SBIT](IMPORTANT): ESPComponent.simulateHardware=1 bool;

2023-03-22T18:42:43.282Z,1679510563.282 [SBIT](IMPORTANT): ElevatorServo.offsetAngle=1 degree;

2023-03-22T18:42:43.282Z,1679510563.282 [SBIT](IMPORTANT): Express none WetLabsBB2FL.BackscatteringCoeff470nm;

2023-03-22T18:42:43.283Z,1679510563.283 [SBIT](IMPORTANT): Express none WetLabsBB2FL.BackscatteringCoeff650nm;

2023-03-22T18:42:43.283Z,1679510563.283 [SBIT](IMPORTANT): VerticalControl.massDefault=3.5 centimeter;

2023-03-22T18:42:43.694Z,1679510563.694 [MissionManager](IMPORTANT): Started mission Startup
2023-03-22T18:42:43.695Z,1679510563.695 [Startup] Running Loop=1
2023-03-22T18:42:43.695Z,1679510563.695 [Startup](DEBUG): Aggregate::initialize Startup
2023-03-22T18:42:43.695Z,1679510563.695 [Startup:A.GoToSurface] Running Loop=1
2023-03-22T18:42:43.695Z,1679510563.695 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-03-22T18:42:43.696Z,1679510563.696 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-03-22T18:42:43.696Z,1679510563.696 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-03-22T18:42:43.696Z,1679510563.696 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-03-22T18:42:43.697Z,1679510563.697 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-03-22T18:42:43.698Z,1679510563.698 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-03-22T18:42:43.700Z,1679510563.700 [Startup:StartupSatComms] Running Loop=1
2023-03-22T18:42:43.700Z,1679510563.700 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2023-03-22T18:42:43.700Z,1679510563.700 [Startup:StartupSatComms:A] Running Loop=1
2023-03-22T18:42:44.103Z,1679510564.103 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2023-03-22T18:43:27.714Z,1679510607.714 [NAL9602](INFO): SBD MO Status=0, MOMSN=47467, MT Status=0, MTMSN=0
2023-03-22T18:43:27.714Z,1679510607.714 [NAL9602](INFO): No messages in MT queue
2023-03-22T18:43:28.926Z,1679510608.926 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184329.00,A,3648.17581,N,12147.27743,W,0.058,0.00,220323,,,A*71
2023-03-22T18:43:28.929Z,1679510608.929 [NAL9602](INFO): GPS fix at 20230322T184329: (36.802930, -121.787957)
2023-03-22T18:43:28.939Z,1679510608.939 [Startup:StartupSatComms:A] Stopped
2023-03-22T18:43:28.939Z,1679510608.939 [Startup:StartupSatComms:B] Running Loop=1
2023-03-22T18:43:29.370Z,1679510609.370 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2023-03-22T18:43:41.613Z,1679510621.613 [DataOverHttps](INFO): Sending 107 bytes from file Logs/20230322T152039/Courier0106.lzma
2023-03-22T18:43:42.615Z,1679510622.615 [DataOverHttps](INFO): Moved sent file to Logs/20230322T152039/Courier0106.lzma.bak
2023-03-22T18:43:42.616Z,1679510622.616 [DataOverHttps](INFO): SBD MOMSN=17541784
2023-03-22T18:43:59.809Z,1679510639.809 [DataOverHttps](INFO): Sending 267 bytes from file Logs/20230322T183857/Courier0000.lzma
2023-03-22T18:44:00.587Z,1679510640.587 [NAL9602](INFO): Not Powering down - fast GPS
2023-03-22T18:44:00.811Z,1679510640.811 [DataOverHttps](INFO): Moved sent file to Logs/20230322T183857/Courier0000.lzma.bak
2023-03-22T18:44:00.811Z,1679510640.811 [DataOverHttps](INFO): SBD MOMSN=17541788
2023-03-22T18:44:16.994Z,1679510656.994 [DataOverHttps](INFO): Sending 784 bytes from file Logs/20230322T152039/Express0107.lzma
2023-03-22T18:44:17.996Z,1679510657.996 [DataOverHttps](INFO): Moved sent file to Logs/20230322T152039/Express0107.lzma.bak
2023-03-22T18:44:17.996Z,1679510657.996 [DataOverHttps](INFO): SBD MOMSN=17541792
2023-03-22T18:44:18.784Z,1679510658.784 [DVL_micro](ERROR): only read 3 of 4 data items
2023-03-22T18:44:18.784Z,1679510658.784 [DVL_micro](ERROR): Failed to parse:
:BI,+00028,+0709,+00000,I
2023-03-22T18:44:29.284Z,1679510669.284 [Startup:StartupSatComms:B](INFO): Timed out from 2023-03-22T18:43:28.9Z
2023-03-22T18:44:29.284Z,1679510669.284 [Startup:StartupSatComms:B] Stopped
2023-03-22T18:44:29.284Z,1679510669.284 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2023-03-22T18:44:29.284Z,1679510669.284 [Startup:StartupSatComms] Stopped
2023-03-22T18:44:29.284Z,1679510669.284 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2023-03-22T18:44:29.285Z,1679510669.285 [Startup](INFO): Completed Startup
2023-03-22T18:44:29.285Z,1679510669.285 [MissionManager](INFO): Startup is completed.
2023-03-22T18:44:29.286Z,1679510669.286 [MissionManager](INFO): Uninitializing Mission Startup
2023-03-22T18:44:29.286Z,1679510669.286 [Startup] Stopped
2023-03-22T18:44:29.286Z,1679510669.286 [Startup](DEBUG): Aggregate::uninitialize Startup
2023-03-22T18:44:29.286Z,1679510669.286 [Startup:A.GoToSurface] Stopped
2023-03-22T18:44:29.286Z,1679510669.286 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2023-03-22T18:44:29.696Z,1679510669.696 [MissionManager](IMPORTANT): Started mission Default
2023-03-22T18:44:29.696Z,1679510669.696 [Default] Running Loop=1
2023-03-22T18:44:29.696Z,1679510669.696 [Default](DEBUG): Aggregate::initialize Default
2023-03-22T18:44:29.696Z,1679510669.696 [Default:B.GoToSurface] Running Loop=1
2023-03-22T18:44:29.697Z,1679510669.697 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-03-22T18:44:29.701Z,1679510669.701 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-03-22T18:44:29.701Z,1679510669.701 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-03-22T18:44:29.702Z,1679510669.702 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-03-22T18:44:29.702Z,1679510669.702 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-03-22T18:44:29.702Z,1679510669.702 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-03-22T18:44:29.703Z,1679510669.703 [Default:A.Wait] Running Loop=1
2023-03-22T18:44:29.703Z,1679510669.703 [Default:A.Wait](DEBUG): Initialize Wait Component.
2023-03-22T18:44:37.070Z,1679510677.070 [DataOverHttps](INFO): Sending 896 bytes from file Logs/20230322T183857/Express0001.lzma
2023-03-22T18:44:38.071Z,1679510678.071 [DataOverHttps](INFO): Moved sent file to Logs/20230322T183857/Express0001.lzma.bak
2023-03-22T18:44:38.071Z,1679510678.071 [DataOverHttps](INFO): SBD MOMSN=17541822
2023-03-22T18:44:42.734Z,1679510682.734 [Default:A.Wait](INFO): Done Waiting.
2023-03-22T18:44:42.734Z,1679510682.734 [Default:A.Wait] Stopped
2023-03-22T18:44:42.734Z,1679510682.734 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2023-03-22T18:44:43.095Z,1679510683.095 [Default:CheckIn] Running Loop=1
2023-03-22T18:44:43.095Z,1679510683.095 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-03-22T18:44:43.096Z,1679510683.096 [Default:CheckIn:Read_GPS] Running Loop=1
2023-03-22T18:44:43.486Z,1679510683.486 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2023-03-22T18:44:43.947Z,1679510683.947 [DVL_micro](ERROR): only read 3 of 4 data items
2023-03-22T18:44:43.947Z,1679510683.947 [DVL_micro](ERROR): Failed to parse:
:RD,+9999.99,+9999.99,+99999.99
2023-03-22T18:44:45.086Z,1679510685.086 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184446.00,A,3648.17384,N,12147.27470,W,0.078,0.00,220323,,,A*7D
2023-03-22T18:44:45.088Z,1679510685.088 [NAL9602](INFO): GPS fix at 20230322T184446: (36.802897, -121.787912)
2023-03-22T18:44:45.098Z,1679510685.098 [Default:CheckIn:Read_GPS] Stopped
2023-03-22T18:44:45.098Z,1679510685.098 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-03-22T18:44:45.546Z,1679510685.546 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2023-03-22T18:44:54.046Z,1679510694.046 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230322T183857/Courier0004.lzma
2023-03-22T18:44:55.047Z,1679510695.047 [DataOverHttps](INFO): Moved sent file to Logs/20230322T183857/Courier0004.lzma.bak
2023-03-22T18:44:55.047Z,1679510695.047 [DataOverHttps](INFO): SBD MOMSN=17541841
2023-03-22T18:45:11.229Z,1679510711.229 [DataOverHttps](INFO): Sending 106 bytes from file Logs/20230322T183857/Express0005.lzma
2023-03-22T18:45:12.231Z,1679510712.231 [DataOverHttps](INFO): Moved sent file to Logs/20230322T183857/Express0005.lzma.bak
2023-03-22T18:45:12.231Z,1679510712.231 [DataOverHttps](IMPORTANT): SBD MOMSN=17541845, MTMSN=20230322T184512
2023-03-22T18:45:13.379Z,1679510713.379 [Default:CheckIn:Read_Iridium] Stopped
2023-03-22T18:45:13.379Z,1679510713.379 [Default:CheckIn:C.Wait] Running Loop=1
2023-03-22T18:45:13.379Z,1679510713.379 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-03-22T18:45:19.821Z,1679510719.821 [DataOverHttps](INFO): Received command: failc
2023-03-22T18:45:19.846Z,1679510719.846 [CommandExec](IMPORTANT): got command failComponent
2023-03-22T18:45:19.846Z,1679510719.846 [CommandExec](IMPORTANT): Failed components:
2023-03-22T18:45:19.846Z,1679510719.846 [CommandExec](IMPORTANT): No failed Components.
2023-03-22T18:45:25.092Z,1679510725.092 [NAL9602](INFO): SBD MO Status=2, MOMSN=47468, MT Status=2, MTMSN=0
2023-03-22T18:45:25.092Z,1679510725.092 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-03-22T18:46:22.895Z,1679510782.895 [DVL_micro](ERROR): only read 3 of 4 data items
2023-03-22T18:46:22.895Z,1679510782.895 [DVL_micro](ERROR): Failed to parse:
:BI,-00787,+0575,+00000,I
2023-03-22T18:46:47.902Z,1679510807.902 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2023-03-22T18:46:47.906Z,1679510807.906 [BPC1](INFO): Received data from all battery sticks.
2023-03-22T18:49:47.678Z,1679510987.678 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-03-22T18:49:56.723Z,1679510996.723 [DataOverHttps](IMPORTANT): SBD MTMSN=20230322T184957
2023-03-22T18:49:58.597Z,1679510998.597 [DVL_micro](ERROR): only read 3 of 4 data items
2023-03-22T18:49:58.597Z,1679510998.597 [DVL_micro](ERROR): Failed to parse:
:RD,+9999.99,+9999.99,+99999.99
2023-03-22T18:50:04.233Z,1679511004.233 [DataOverHttps](INFO): Received command: configSet CBIT.gfScanTimeout 1 hour persist
2023-03-22T18:50:04.487Z,1679511004.487 [CommandExec](IMPORTANT): got command configSet CBIT.gfScanTimeout 1 hour persist
2023-03-22T18:50:13.961Z,1679511013.961 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-03-22T18:50:13.961Z,1679511013.961 [Default:CheckIn:C.Wait] Stopped
2023-03-22T18:50:13.981Z,1679511013.981 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-03-22T18:50:13.981Z,1679511013.981 [Default:CheckIn:D] Running Loop=1
2023-03-22T18:50:14.352Z,1679511014.352 [Default:CheckIn:D] Stopped
2023-03-22T18:50:14.352Z,1679511014.352 [Default:CheckIn:E] Running Loop=1
2023-03-22T18:50:14.760Z,1679511014.760 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 5.744256 min 
2023-03-22T18:50:14.760Z,1679511014.760 [Default:CheckIn:E] Stopped
2023-03-22T18:50:14.761Z,1679511014.761 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-03-22T18:50:14.761Z,1679511014.761 [Default:CheckIn] Stopped
2023-03-22T18:50:14.761Z,1679511014.761 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-03-22T18:50:14.761Z,1679511014.761 [Default:CheckIn](INFO): Running loop #2
2023-03-22T18:50:14.761Z,1679511014.761 [Default:CheckIn] Running Loop=2
2023-03-22T18:50:14.761Z,1679511014.761 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-03-22T18:50:14.761Z,1679511014.761 [Default:CheckIn:Read_GPS] Running Loop=1
2023-03-22T18:50:16.768Z,1679511016.768 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,185017.00,A,3648.17631,N,12147.27563,W,0.058,0.00,220323,,,A*76
2023-03-22T18:50:16.770Z,1679511016.770 [NAL9602](INFO): GPS fix at 20230322T185017: (36.802939, -121.787927)
2023-03-22T18:50:16.803Z,1679511016.803 [Default:CheckIn:Read_GPS] Stopped
2023-03-22T18:50:16.803Z,1679511016.803 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-03-22T18:50:23.729Z,1679511023.729 [DataOverHttps](INFO): Sending 203 bytes from file Logs/20230322T183857/Courier0007.lzma
2023-03-22T18:50:24.731Z,1679511024.731 [DataOverHttps](INFO): Moved sent file to Logs/20230322T183857/Courier0007.lzma.bak
2023-03-22T18:50:24.731Z,1679511024.731 [DataOverHttps](INFO): SBD MOMSN=17541892
2023-03-22T18:50:44.273Z,1679511044.273 [DataOverHttps](INFO): Sending 429 bytes from file Logs/20230322T183857/Express0008.lzma
2023-03-22T18:50:45.275Z,1679511045.275 [DataOverHttps](INFO): Moved sent file to Logs/20230322T183857/Express0008.lzma.bak
2023-03-22T18:50:45.275Z,1679511045.275 [DataOverHttps](INFO): SBD MOMSN=17541896
2023-03-22T18:50:46.340Z,1679511046.340 [Default:CheckIn:Read_Iridium] Stopped
2023-03-22T18:50:46.340Z,1679511046.340 [Default:CheckIn:C.Wait] Running Loop=1
2023-03-22T18:50:46.340Z,1679511046.340 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-03-22T18:50:48.707Z,1679511048.707 [NAL9602](INFO): Not Powering down - fast GPS
2023-03-22T18:50:51.960Z,1679511051.960 [DVL_micro](ERROR): Failed to parse:
:2,+000,I
2023-03-22T18:50:57.202Z,1679511057.202 [DVL_micro](ERROR): Failed to parse:
:BD,+00000000.00,+00000000.00,+00000000.00,9999.99,000.00
2023-03-22T18:53:26.934Z,1679511206.934 [DataOverHttps](IMPORTANT): SBD MTMSN=20230322T185327
2023-03-22T18:53:37.359Z,1679511217.359 [DataOverHttps](INFO): Received command: ibit
2023-03-22T18:53:37.442Z,1679511217.442 [CommandExec](IMPORTANT): got command ibit
2023-03-22T18:53:37.705Z,1679511217.705 [IBIT](IMPORTANT): Beginning Initiated BIT
2023-03-22T18:53:37.705Z,1679511217.705 [IBIT](IMPORTANT): Beginning control surface checks.
2023-03-22T18:53:37.708Z,1679511217.708 [CBIT](IMPORTANT): Beginning ground fault scan
2023-03-22T18:53:39.293Z,1679511219.293 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,185340.00,A,3648.17289,N,12147.28080,W,0.078,0.00,220323,,,A*75
2023-03-22T18:53:39.296Z,1679511219.296 [NAL9602](INFO): GPS fix at 20230322T185340: (36.802881, -121.788013)
2023-03-22T18:53:48.594Z,1679511228.594 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.084955
CHAN A1 (24V): 0.141139
CHAN A2 (12V): 0.031601
CHAN A3 (5V): -0.009891
CHAN B0 (3.3V): -0.008355
CHAN B1 (3.15aV): -0.003994
CHAN B2 (3.15bV): -0.000628
CHAN B3 (GND): -0.018502
OPEN: 0.008752
Full Scale: +/- 1 mA
2023-03-22T18:53:54.622Z,1679511234.622 [DVL_micro](ERROR): Failed to parse:
:BD,+00000000.00,+00000000.00,+00000000.00,9999.99,000.00
2023-03-22T18:54:09.978Z,1679511249.978 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-03-22T18:54:10.053Z,1679511250.053 [NAL9602](ERROR): received: 
+CSQ:0

OK468, 2, 0, 0, 0

OK
2023-03-22T18:55:28.805Z,1679511328.805 [IBIT](FAULT): Error acquiring IBIT communications status. Timeout expired.
2023-03-22T18:55:29.206Z,1679511329.206 [IBIT](IMPORTANT): Battery Status:
Battery Charge (AH): 0.000000
Voltage: 15.898000
2023-03-22T18:55:29.206Z,1679511329.206 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah
2023-03-22T18:55:29.206Z,1679511329.206 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V
2023-03-22T18:55:29.616Z,1679511329.616 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2023-03-22T18:55:29.616Z,1679511329.616 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2023-03-22T18:55:29.616Z,1679511329.616 [IBIT](IMPORTANT): Pressure:9.783592 PSI
2023-03-22T18:55:29.617Z,1679511329.617 [IBIT](IMPORTANT): Humidity:8.167500 %
2023-03-22T18:55:30.024Z,1679511330.024 [IBIT](IMPORTANT): Vehicle Pitch:-2.752722 degrees
2023-03-22T18:55:30.024Z,1679511330.024 [IBIT](IMPORTANT): Vehicle  Roll:-6.984856 degrees
2023-03-22T18:55:30.024Z,1679511330.024 [IBIT](IMPORTANT): Vehicle  Heading:117.098457 degrees
2023-03-22T18:55:30.421Z,1679511330.421 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2023-03-22T18:55:30.422Z,1679511330.422 [IBIT](IMPORTANT): buoyancyNeutral: 223.000000 cc
2023-03-22T18:55:30.422Z,1679511330.422 [IBIT](IMPORTANT): massDefault: 3.500000 cm
2023-03-22T18:55:30.422Z,1679511330.422 [IBIT](IMPORTANT): stopDepth: 215.000000 m
2023-03-22T18:55:30.422Z,1679511330.422 [IBIT](IMPORTANT): abortDepth: 250.000000 m
2023-03-22T18:55:30.422Z,1679511330.422 [IBIT](IMPORTANT): IBIT FAILED
2023-03-22T18:55:47.030Z,1679511347.030 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-03-22T18:55:47.030Z,1679511347.030 [Default:CheckIn:C.Wait] Stopped
2023-03-22T18:55:47.030Z,1679511347.030 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-03-22T18:55:47.031Z,1679511347.031 [Default:CheckIn:D] Running Loop=1
2023-03-22T18:55:47.465Z,1679511347.465 [Default:CheckIn:D] Stopped
2023-03-22T18:55:47.465Z,1679511347.465 [Default:CheckIn:E] Running Loop=1
2023-03-22T18:55:47.870Z,1679511347.870 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 11.296139 min 
2023-03-22T18:55:47.870Z,1679511347.870 [Default:CheckIn:E] Stopped
2023-03-22T18:55:47.870Z,1679511347.870 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-03-22T18:55:47.870Z,1679511347.870 [Default:CheckIn] Stopped
2023-03-22T18:55:47.870Z,1679511347.870 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-03-22T18:55:47.870Z,1679511347.870 [Default:CheckIn](INFO): Running loop #3
2023-03-22T18:55:47.870Z,1679511347.870 [Default:CheckIn] Running Loop=3
2023-03-22T18:55:47.870Z,1679511347.870 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-03-22T18:55:47.871Z,1679511347.871 [Default:CheckIn:Read_GPS] Running Loop=1
2023-03-22T18:55:58.750Z,1679511358.750 [DVL_micro](ERROR): only read 3 of 4 data items
2023-03-22T18:55:58.750Z,1679511358.750 [DVL_micro](ERROR): Failed to parse:
:RD,+9999.99,+9999.99,+99999.99
2023-03-22T18:56:59.801Z,1679511419.801 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2023-03-22T18:56:59.802Z,1679511419.802 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,+13.3,0000.,000
2023-03-22T18:58:41.758Z,1679511521.758 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-03-22T18:58:42.943Z,1679511522.943 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,185843.00,A,3648.17256,N,12147.27699,W,0.039,0.00,220323,,,A*7B
2023-03-22T18:58:42.946Z,1679511522.946 [NAL9602](INFO): GPS fix at 20230322T185843: (36.802876, -121.787950)
2023-03-22T18:58:42.975Z,1679511522.975 [Default:CheckIn:Read_GPS] Stopped
2023-03-22T18:58:42.975Z,1679511522.975 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-03-22T18:58:43.764Z,1679511523.764 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230322T183857/Courier0010.lzma
2023-03-22T18:58:44.420Z,1679511524.420 [DataOverHttps](INFO): Moved sent file to Logs/20230322T183857/Courier0010.lzma.bak
2023-03-22T18:58:44.421Z,1679511524.421 [DataOverHttps](INFO): SBD MOMSN=17541914
2023-03-22T18:59:00.422Z,1679511540.422 [DataOverHttps](INFO): Sending 830 bytes from file Logs/20230322T183857/Express0012.lzma
2023-03-22T18:59:01.423Z,1679511541.423 [DataOverHttps](INFO): Moved sent file to Logs/20230322T183857/Express0012.lzma.bak
2023-03-22T18:59:01.423Z,1679511541.423 [DataOverHttps](INFO): SBD MOMSN=17541917
2023-03-22T18:59:02.750Z,1679511542.750 [Default:CheckIn:Read_Iridium] Stopped
2023-03-22T18:59:02.750Z,1679511542.750 [Default:CheckIn:C.Wait] Running Loop=1
2023-03-22T18:59:02.750Z,1679511542.750 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-03-22T18:59:14.862Z,1679511554.862 [NAL9602](INFO): Not Powering down - fast GPS
2023-03-22T19:00:09.863Z,1679511609.863 [DVL_micro](ERROR): Failed to parse:
:WI,-00464,+02220,-02328,+00000,A
2023-03-22T19:01:44.302Z,1679511704.302 [DataOverHttps](IMPORTANT): SBD MTMSN=20230322T190144
2023-03-22T19:01:51.693Z,1679511711.693 [DataOverHttps](INFO): Received command: ibit
2023-03-22T19:01:51.702Z,1679511711.702 [CommandExec](IMPORTANT): got command ibit
2023-03-22T19:01:51.741Z,1679511711.741 [IBIT](IMPORTANT): Beginning Initiated BIT
2023-03-22T19:01:51.741Z,1679511711.741 [IBIT](IMPORTANT): Beginning control surface checks.
2023-03-22T19:01:51.744Z,1679511711.744 [CBIT](IMPORTANT): Beginning ground fault scan
2023-03-22T19:01:53.337Z,1679511713.337 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190154.00,A,3648.16786,N,12147.26002,W,3.071,114.59,220323,,,A*7B
2023-03-22T19:01:53.339Z,1679511713.339 [NAL9602](INFO): GPS fix at 20230322T190154: (36.802798, -121.787667)
2023-03-22T19:02:02.648Z,1679511722.648 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.083725
CHAN A1 (24V): 0.124651
CHAN A2 (12V): 0.065356
CHAN A3 (5V): -0.001886
CHAN B0 (3.3V): -0.004460
CHAN B1 (3.15aV): -0.000332
CHAN B2 (3.15bV): 0.002340
CHAN B3 (GND): -0.017466
OPEN: 0.008555
Full Scale: +/- 1 mA
2023-03-22T19:02:24.034Z,1679511744.034 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-03-22T19:02:24.117Z,1679511744.117 [NAL9602](ERROR): received: 
+CSQ:0

OK468, 2, 0, 0, 0

OK
2023-03-22T19:02:29.311Z,1679511749.311 [DVL_micro](ERROR): only read 1 of 4 data items
2023-03-22T19:02:29.311Z,1679511749.311 [DVL_micro](ERROR): Failed to parse:
:BI,-00700-02442,+00000,I
2023-03-22T19:02:30.147Z,1679511750.147 [NAL9602](INFO): SBD MO Status=0, MOMSN=47468, MT Status=0, MTMSN=0
2023-03-22T19:02:30.147Z,1679511750.147 [NAL9602](INFO): No messages in MT queue
2023-03-22T19:02:31.307Z,1679511751.307 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190232.00,A,3648.14930,N,12147.25290,W,0.078,188.85,220323,,,A*7D
2023-03-22T19:02:31.318Z,1679511751.318 [NAL9602](INFO): GPS fix at 20230322T190232: (36.802488, -121.787548)
2023-03-22T19:02:34.564Z,1679511754.564 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190235.00,A,3648.14936,N,12147.25291,W,0.058,188.85,220323,,,A*7F
2023-03-22T19:02:34.574Z,1679511754.574 [NAL9602](INFO): GPS fix at 20230322T190235: (36.802489, -121.787548)
2023-03-22T19:02:37.383Z,1679511757.383 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190238.00,A,3648.14922,N,12147.25283,W,1.283,165.10,220323,,,A*7E
2023-03-22T19:02:37.390Z,1679511757.390 [NAL9602](INFO): GPS fix at 20230322T190238: (36.802487, -121.787547)
2023-03-22T19:02:38.195Z,1679511758.195 [IBIT](IMPORTANT): Communications Status:
Fix Status: 1
Iridium Signal Strength: 2
Latitude: 36.802486 Longitude: -121.787544
2023-03-22T19:02:38.619Z,1679511758.619 [IBIT](IMPORTANT): Battery Status:
Battery Charge (AH): 0.000000
Voltage: 15.898000
2023-03-22T19:02:38.620Z,1679511758.620 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah
2023-03-22T19:02:38.620Z,1679511758.620 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V
2023-03-22T19:02:39.022Z,1679511759.022 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2023-03-22T19:02:39.023Z,1679511759.023 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2023-03-22T19:02:39.023Z,1679511759.023 [IBIT](IMPORTANT): Pressure:9.701334 PSI
2023-03-22T19:02:39.023Z,1679511759.023 [IBIT](IMPORTANT): Humidity:8.191918 %
2023-03-22T19:02:39.438Z,1679511759.438 [IBIT](IMPORTANT): Vehicle Pitch:0.518444 degrees
2023-03-22T19:02:39.438Z,1679511759.438 [IBIT](IMPORTANT): Vehicle  Roll:-2.600349 degrees
2023-03-22T19:02:39.439Z,1679511759.439 [IBIT](IMPORTANT): Vehicle  Heading:307.622528 degrees
2023-03-22T19:02:39.850Z,1679511759.850 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2023-03-22T19:02:39.850Z,1679511759.850 [IBIT](IMPORTANT): buoyancyNeutral: 223.000000 cc
2023-03-22T19:02:39.850Z,1679511759.850 [IBIT](IMPORTANT): massDefault: 3.500000 cm
2023-03-22T19:02:39.851Z,1679511759.851 [IBIT](IMPORTANT): stopDepth: 215.000000 m
2023-03-22T19:02:39.851Z,1679511759.851 [IBIT](IMPORTANT): abortDepth: 250.000000 m
2023-03-22T19:02:39.851Z,1679511759.851 [IBIT](IMPORTANT): IBIT PASSED
2023-03-22T19:03:09.693Z,1679511789.693 [NAL9602](INFO): Not Powering down - fast GPS
2023-03-22T19:03:20.202Z,1679511800.202 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2023-03-22T19:03:20.202Z,1679511800.202 [DVL_micro](ERROR): Failed to parse:
:TS,000000000000+13.3,0000.0,1489.0,0-01410,-00734,-02319,+00000,A
2023-03-22T19:04:03.443Z,1679511843.443 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-03-22T19:04:03.443Z,1679511843.443 [Default:CheckIn:C.Wait] Stopped
2023-03-22T19:04:03.443Z,1679511843.443 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-03-22T19:04:03.443Z,1679511843.443 [Default:CheckIn:D] Running Loop=1
2023-03-22T19:04:03.835Z,1679511843.835 [Default:CheckIn:D] Stopped
2023-03-22T19:04:03.836Z,1679511843.836 [Default:CheckIn:E] Running Loop=1
2023-03-22T19:04:04.241Z,1679511844.241 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 19.568984 min 
2023-03-22T19:04:04.241Z,1679511844.241 [Default:CheckIn:E] Stopped
2023-03-22T19:04:04.241Z,1679511844.241 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-03-22T19:04:04.242Z,1679511844.242 [Default:CheckIn] Stopped
2023-03-22T19:04:04.242Z,1679511844.242 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-03-22T19:04:04.242Z,1679511844.242 [Default:CheckIn](INFO): Running loop #4
2023-03-22T19:04:04.242Z,1679511844.242 [Default:CheckIn] Running Loop=4
2023-03-22T19:04:04.242Z,1679511844.242 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-03-22T19:04:04.242Z,1679511844.242 [Default:CheckIn:Read_GPS] Running Loop=1
2023-03-22T19:04:06.248Z,1679511846.248 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190407.00,A,3648.14959,N,12147.24655,W,0.019,115.24,220323,,,D*73
2023-03-22T19:04:06.250Z,1679511846.250 [NAL9602](INFO): GPS fix at 20230322T190407: (36.802493, -121.787442)
2023-03-22T19:04:06.280Z,1679511846.280 [Default:CheckIn:Read_GPS] Stopped
2023-03-22T19:04:06.280Z,1679511846.280 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-03-22T19:04:13.652Z,1679511853.652 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230322T183857/Courier0016.lzma
2023-03-22T19:04:14.655Z,1679511854.655 [DataOverHttps](INFO): Moved sent file to Logs/20230322T183857/Courier0016.lzma.bak
2023-03-22T19:04:14.655Z,1679511854.655 [DataOverHttps](INFO): SBD MOMSN=17541981
2023-03-22T19:04:23.630Z,1679511863.630 [NAL9602](INFO): SBD MO Status=2, MOMSN=47469, MT Status=2, MTMSN=0
2023-03-22T19:04:23.630Z,1679511863.630 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-03-22T19:04:30.554Z,1679511870.554 [DataOverHttps](INFO): Sending 811 bytes from file Logs/20230322T183857/Express0018.lzma
2023-03-22T19:04:31.555Z,1679511871.555 [DataOverHttps](INFO): Moved sent file to Logs/20230322T183857/Express0018.lzma.bak
2023-03-22T19:04:31.555Z,1679511871.555 [DataOverHttps](INFO): SBD MOMSN=17541984
2023-03-22T19:04:48.731Z,1679511888.731 [NAL9602](INFO): SBD MO Status=0, MOMSN=47469, MT Status=0, MTMSN=0
2023-03-22T19:04:48.731Z,1679511888.731 [NAL9602](INFO): No messages in MT queue
2023-03-22T19:04:51.092Z,1679511891.092 [DataOverHttps](INFO): Sending 52 bytes from file Logs/20230322T183857/Express0023.lzma
2023-03-22T19:04:52.104Z,1679511892.104 [DataOverHttps](INFO): Moved sent file to Logs/20230322T183857/Express0023.lzma.bak
2023-03-22T19:04:52.104Z,1679511892.104 [DataOverHttps](INFO): SBD MOMSN=17542011
2023-03-22T19:04:53.175Z,1679511893.175 [Default:CheckIn:Read_Iridium] Stopped
2023-03-22T19:04:53.175Z,1679511893.175 [Default:CheckIn:C.Wait] Running Loop=1
2023-03-22T19:04:53.175Z,1679511893.175 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-03-22T19:05:19.433Z,1679511919.433 [NAL9602](INFO): Not Powering down - fast GPS
2023-03-22T19:06:25.283Z,1679511985.283 [DVL_micro](ERROR): only read 1 of 4 data items
2023-03-22T19:06:25.283Z,1679511985.283 [DVL_micro](ERROR): Failed to parse:
:BI,+00282-02796,+00000,I
2023-03-22T19:06:32.279Z,1679511992.279 [DataOverHttps](IMPORTANT): SBD MTMSN=20230322T190632
2023-03-22T19:06:43.057Z,1679512003.057 [DataOverHttps](INFO): Received command: ibit
2023-03-22T19:06:43.146Z,1679512003.146 [CommandExec](IMPORTANT): got command ibit
2023-03-22T19:06:43.154Z,1679512003.154 [IBIT](IMPORTANT): Beginning Initiated BIT
2023-03-22T19:06:43.154Z,1679512003.154 [IBIT](IMPORTANT): Beginning control surface checks.
2023-03-22T19:06:43.158Z,1679512003.158 [CBIT](IMPORTANT): Beginning ground fault scan
2023-03-22T19:06:44.732Z,1679512004.732 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190645.00,A,3648.14869,N,12147.24980,W,0.000,115.24,220323,,,D*7A
2023-03-22T19:06:44.743Z,1679512004.743 [NAL9602](INFO): GPS fix at 20230322T190645: (36.802478, -121.787497)
2023-03-22T19:06:54.048Z,1679512014.048 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.089250
CHAN A1 (24V): 0.124718
CHAN A2 (12V): 0.020223
CHAN A3 (5V): -0.011782
CHAN B0 (3.3V): -0.009869
CHAN B1 (3.15aV): -0.005557
CHAN B2 (3.15bV): -0.002617
CHAN B3 (GND): -0.018554
OPEN: 0.009434
Full Scale: +/- 1 mA
2023-03-22T19:08:34.274Z,1679512114.274 [IBIT](FAULT): Error acquiring IBIT communications status. Timeout expired.
2023-03-22T19:08:34.699Z,1679512114.699 [IBIT](IMPORTANT): Battery Status:
Battery Charge (AH): 0.000000
Voltage: 15.858000
2023-03-22T19:08:34.700Z,1679512114.700 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah
2023-03-22T19:08:34.700Z,1679512114.700 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V
2023-03-22T19:08:35.104Z,1679512115.104 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2023-03-22T19:08:35.104Z,1679512115.104 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2023-03-22T19:08:35.105Z,1679512115.105 [IBIT](IMPORTANT): Pressure:9.689731 PSI
2023-03-22T19:08:35.105Z,1679512115.105 [IBIT](IMPORTANT): Humidity:8.143084 %
2023-03-22T19:08:35.487Z,1679512115.487 [IBIT](IMPORTANT): Vehicle Pitch:-1.225401 degrees
2023-03-22T19:08:35.487Z,1679512115.487 [IBIT](IMPORTANT): Vehicle  Roll:-4.859149 degrees
2023-03-22T19:08:35.487Z,1679512115.487 [IBIT](IMPORTANT): Vehicle  Heading:277.632629 degrees
2023-03-22T19:08:35.893Z,1679512115.893 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2023-03-22T19:08:35.901Z,1679512115.901 [IBIT](IMPORTANT): buoyancyNeutral: 223.000000 cc
2023-03-22T19:08:35.901Z,1679512115.901 [IBIT](IMPORTANT): massDefault: 3.500000 cm
2023-03-22T19:08:35.902Z,1679512115.902 [IBIT](IMPORTANT): stopDepth: 215.000000 m
2023-03-22T19:08:35.902Z,1679512115.902 [IBIT](IMPORTANT): abortDepth: 250.000000 m
2023-03-22T19:08:35.902Z,1679512115.902 [IBIT](IMPORTANT): IBIT FAILED
2023-03-22T19:09:53.867Z,1679512193.867 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-03-22T19:09:53.867Z,1679512193.867 [Default:CheckIn:C.Wait] Stopped
2023-03-22T19:09:53.867Z,1679512193.867 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-03-22T19:09:53.867Z,1679512193.867 [Default:CheckIn:D] Running Loop=1
2023-03-22T19:09:54.252Z,1679512194.252 [Default:CheckIn:D] Stopped
2023-03-22T19:09:54.252Z,1679512194.252 [Default:CheckIn:E] Running Loop=1
2023-03-22T19:09:54.656Z,1679512194.656 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 25.409259 min 
2023-03-22T19:09:54.656Z,1679512194.656 [Default:CheckIn:E] Stopped
2023-03-22T19:09:54.656Z,1679512194.656 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-03-22T19:09:54.657Z,1679512194.657 [Default:CheckIn] Stopped
2023-03-22T19:09:54.657Z,1679512194.657 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-03-22T19:09:54.657Z,1679512194.657 [Default:CheckIn](INFO): Running loop #5
2023-03-22T19:09:54.657Z,1679512194.657 [Default:CheckIn] Running Loop=5
2023-03-22T19:09:54.657Z,1679512194.657 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-03-22T19:09:54.657Z,1679512194.657 [Default:CheckIn:Read_GPS] Running Loop=1
2023-03-22T19:11:13.451Z,1679512273.451 [NAL9602](INFO): SBD MO Status=2, MOMSN=47470, MT Status=2, MTMSN=0
2023-03-22T19:11:13.451Z,1679512273.451 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-03-22T19:11:48.171Z,1679512308.171 [NAL9602](INFO): SBD MO Status=2, MOMSN=47470, MT Status=2, MTMSN=0
2023-03-22T19:11:48.171Z,1679512308.171 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-03-22T19:11:48.583Z,1679512308.583 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-03-22T19:11:49.801Z,1679512309.801 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,191150.00,A,3648.14794,N,12147.24801,W,0.039,115.24,220323,,,D*77
2023-03-22T19:11:49.804Z,1679512309.804 [NAL9602](INFO): GPS fix at 20230322T191150: (36.802466, -121.787467)
2023-03-22T19:11:49.813Z,1679512309.813 [Default:CheckIn:Read_GPS] Stopped
2023-03-22T19:11:49.813Z,1679512309.813 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-03-22T19:11:57.352Z,1679512317.352 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20230322T183857/Courier0025.lzma
2023-03-22T19:11:58.355Z,1679512318.355 [DataOverHttps](INFO): Moved sent file to Logs/20230322T183857/Courier0025.lzma.bak
2023-03-22T19:11:58.355Z,1679512318.355 [DataOverHttps](INFO): SBD MOMSN=17542056
2023-03-22T19:12:14.256Z,1679512334.256 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20230322T183857/Courier0028.lzma
2023-03-22T19:12:15.259Z,1679512335.259 [DataOverHttps](INFO): Moved sent file to Logs/20230322T183857/Courier0028.lzma.bak
2023-03-22T19:12:15.259Z,1679512335.259 [DataOverHttps](INFO): SBD MOMSN=17542059
2023-03-22T19:12:21.703Z,1679512341.703 [NAL9602](INFO): Not Powering down - fast GPS
2023-03-22T19:12:31.822Z,1679512351.822 [DataOverHttps](INFO): Sending 815 bytes from file Logs/20230322T183857/Express0026.lzma
2023-03-22T19:12:32.823Z,1679512352.823 [DataOverHttps](INFO): Moved sent file to Logs/20230322T183857/Express0026.lzma.bak
2023-03-22T19:12:32.823Z,1679512352.823 [DataOverHttps](INFO): SBD MOMSN=17542061
2023-03-22T19:12:45.568Z,1679512365.568 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2023-03-22T19:12:45.568Z,1679512365.568 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35,0000.0,1489.0,000
2023-03-22T19:12:51.705Z,1679512371.705 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20230322T183857/Express0029.lzma
2023-03-22T19:12:52.707Z,1679512372.707 [DataOverHttps](INFO): Moved sent file to Logs/20230322T183857/Express0029.lzma.bak
2023-03-22T19:12:52.707Z,1679512372.707 [DataOverHttps](INFO): SBD MOMSN=17542088
2023-03-22T19:12:54.065Z,1679512374.065 [Default:CheckIn:Read_Iridium] Stopped
2023-03-22T19:12:54.065Z,1679512374.065 [Default:CheckIn:C.Wait] Running Loop=1
2023-03-22T19:12:54.065Z,1679512374.065 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-03-22T19:15:55.879Z,1679512555.879 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2023-03-22T19:15:55.880Z,1679512555.880 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,+13.6,489.0,000
2023-03-22T19:17:54.777Z,1679512674.777 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-03-22T19:17:54.777Z,1679512674.777 [Default:CheckIn:C.Wait] Stopped
2023-03-22T19:17:54.797Z,1679512674.797 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-03-22T19:17:54.797Z,1679512674.797 [Default:CheckIn:D] Running Loop=1
2023-03-22T19:17:55.168Z,1679512675.168 [Default:CheckIn:D] Stopped
2023-03-22T19:17:55.168Z,1679512675.168 [Default:CheckIn:E] Running Loop=1
2023-03-22T19:17:55.578Z,1679512675.578 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 33.424522 min 
2023-03-22T19:17:55.579Z,1679512675.579 [Default:CheckIn:E] Stopped
2023-03-22T19:17:55.579Z,1679512675.579 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-03-22T19:17:55.579Z,1679512675.579 [Default:CheckIn] Stopped
2023-03-22T19:17:55.579Z,1679512675.579 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-03-22T19:17:55.579Z,1679512675.579 [Default:CheckIn](INFO): Running loop #6
2023-03-22T19:17:55.579Z,1679512675.579 [Default:CheckIn] Running Loop=6
2023-03-22T19:17:55.579Z,1679512675.579 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-03-22T19:17:55.579Z,1679512675.579 [Default:CheckIn:Read_GPS] Running Loop=1
2023-03-22T19:17:57.610Z,1679512677.610 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,191758.00,A,3648.14603,N,12147.24632,W,0.019,115.24,220323,,,D*7A
2023-03-22T19:17:57.612Z,1679512677.612 [NAL9602](INFO): GPS fix at 20230322T191758: (36.802434, -121.787439)
2023-03-22T19:17:57.621Z,1679512677.621 [Default:CheckIn:Read_GPS] Stopped
2023-03-22T19:17:57.621Z,1679512677.621 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-03-22T19:18:04.912Z,1679512684.912 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230322T183857/Courier0031.lzma
2023-03-22T19:18:05.915Z,1679512685.915 [DataOverHttps](INFO): Moved sent file to Logs/20230322T183857/Courier0031.lzma.bak
2023-03-22T19:18:05.915Z,1679512685.915 [DataOverHttps](INFO): SBD MOMSN=17542096
2023-03-22T19:18:23.924Z,1679512703.924 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20230322T183857/Express0032.lzma
2023-03-22T19:18:24.927Z,1679512704.927 [DataOverHttps](INFO): Moved sent file to Logs/20230322T183857/Express0032.lzma.bak
2023-03-22T19:18:24.927Z,1679512704.927 [DataOverHttps](INFO): SBD MOMSN=17542099
2023-03-22T19:18:26.304Z,1679512706.304 [Default:CheckIn:Read_Iridium] Stopped
2023-03-22T19:18:26.304Z,1679512706.304 [Default:CheckIn:C.Wait] Running Loop=1
2023-03-22T19:18:26.304Z,1679512706.304 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-03-22T19:19:05.881Z,1679512745.881 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2023-03-22T19:19:05.881Z,1679512745.881 [DVL_micro](ERROR): Failed to parse:
:TS,000000000000003.7,0000.0,1489.0,000
2023-03-22T19:20:08.929Z,1679512808.929 [NAL9602](INFO): SBD MO Status=2, MOMSN=47470, MT Status=2, MTMSN=0
2023-03-22T19:20:08.929Z,1679512808.929 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-03-22T19:20:42.116Z,1679512842.116 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2023-03-22T19:20:42.116Z,1679512842.116 [DVL_micro](ERROR): Failed to parse:
:TS,00000000,1489.0,000
2023-03-22T19:22:15.903Z,1679512935.903 [DVL_micro](ERROR): Failed to parse:
:BD,+00000000.00,+00000000.00,+00000000.00,9999.99,000.00
2023-03-22T19:23:06.860Z,1679512986.860 [NAL9602](INFO): SBD MO Status=2, MOMSN=47470, MT Status=2, MTMSN=0
2023-03-22T19:23:06.860Z,1679512986.860 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-03-22T19:23:07.249Z,1679512987.249 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-03-22T19:23:27.066Z,1679513007.066 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-03-22T19:23:27.066Z,1679513007.066 [Default:CheckIn:C.Wait] Stopped
2023-03-22T19:23:27.066Z,1679513007.066 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-03-22T19:23:27.067Z,1679513007.067 [Default:CheckIn:D] Running Loop=1
2023-03-22T19:23:27.476Z,1679513007.476 [Default:CheckIn:D] Stopped
2023-03-22T19:23:27.476Z,1679513007.476 [Default:CheckIn:E] Running Loop=1
2023-03-22T19:23:27.860Z,1679513007.860 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 38.962984 min 
2023-03-22T19:23:27.860Z,1679513007.860 [Default:CheckIn:E] Stopped
2023-03-22T19:23:27.860Z,1679513007.860 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-03-22T19:23:27.860Z,1679513007.860 [Default:CheckIn] Stopped
2023-03-22T19:23:27.860Z,1679513007.860 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-03-22T19:23:27.860Z,1679513007.860 [Default:CheckIn](INFO): Running loop #7
2023-03-22T19:23:27.860Z,1679513007.860 [Default:CheckIn] Running Loop=7
2023-03-22T19:23:27.860Z,1679513007.860 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-03-22T19:23:27.861Z,1679513007.861 [Default:CheckIn:Read_GPS] Running Loop=1
2023-03-22T19:23:29.895Z,1679513009.895 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,192330.00,A,3648.14854,N,12147.24936,W,0.019,115.24,220323,,,D*74
2023-03-22T19:23:29.901Z,1679513009.901 [NAL9602](INFO): GPS fix at 20230322T192330: (36.802476, -121.787489)
2023-03-22T19:23:29.939Z,1679513009.939 [Default:CheckIn:Read_GPS] Stopped
2023-03-22T19:23:29.939Z,1679513009.939 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-03-22T19:23:40.498Z,1679513020.498 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230322T183857/Courier0034.lzma
2023-03-22T19:23:41.483Z,1679513021.483 [DataOverHttps](INFO): Moved sent file to Logs/20230322T183857/Courier0034.lzma.bak
2023-03-22T19:23:41.483Z,1679513021.483 [DataOverHttps](INFO): SBD MOMSN=17542135
2023-03-22T19:23:57.437Z,1679513037.437 [DataOverHttps](INFO): Sending 205 bytes from file Logs/20230322T183857/Express0035.lzma
2023-03-22T19:23:58.439Z,1679513038.439 [DataOverHttps](INFO): Moved sent file to Logs/20230322T183857/Express0035.lzma.bak
2023-03-22T19:23:58.439Z,1679513038.439 [DataOverHttps](INFO): SBD MOMSN=17542138
2023-03-22T19:23:59.494Z,1679513039.494 [Default:CheckIn:Read_Iridium] Stopped
2023-03-22T19:23:59.494Z,1679513039.494 [Default:CheckIn:C.Wait] Running Loop=1
2023-03-22T19:23:59.494Z,1679513039.494 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-03-22T19:24:01.871Z,1679513041.871 [NAL9602](INFO): Not Powering down - fast GPS
2023-03-22T19:28:23.892Z,1679513303.892 [DVL_micro](ERROR): only read 3 of 4 data items
2023-03-22T19:28:23.892Z,1679513303.892 [DVL_micro](ERROR): Failed to parse:
:BI,-00142,-00638,-02616,+000D,+00000000.00,+00000000.00,+00000000.00,9999.99,000.00
2023-03-22T19:28:36.481Z,1679513316.481 [DVL_micro](ERROR): DVL uart error: serial timeout
2023-03-22T19:28:36.481Z,1679513316.481 [DVL_micro] Communications Fault, FailCount= 1
2023-03-22T19:28:36.481Z,1679513316.481 [DVL_micro](ERROR): Communications Fault
2023-03-22T19:28:36.482Z,1679513316.482 [DVL_micro](ERROR): Failed to parse:
2023-03-22T19:28:36.502Z,1679513316.502 [CBIT](ERROR): Communications Fault in component: DVL_micro
2023-03-22T19:28:36.877Z,1679513316.877 [DVL_micro](INFO): Powering down
2023-03-22T19:28:37.748Z,1679513317.748 [CBIT](INFO): Clearing failed state for component DVL_micro
2023-03-22T19:28:37.748Z,1679513317.748 [DVL_micro] No Fault, FailCount= 1
2023-03-22T19:29:00.271Z,1679513340.271 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-03-22T19:29:00.271Z,1679513340.271 [Default:CheckIn:C.Wait] Stopped
2023-03-22T19:29:00.271Z,1679513340.271 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-03-22T19:29:00.271Z,1679513340.271 [Default:CheckIn:D] Running Loop=1
2023-03-22T19:29:00.668Z,1679513340.668 [Default:CheckIn:D] Stopped
2023-03-22T19:29:00.668Z,1679513340.668 [Default:CheckIn:E] Running Loop=1
2023-03-22T19:29:01.060Z,1679513341.060 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 44.516195 min 
2023-03-22T19:29:01.060Z,1679513341.060 [Default:CheckIn:E] Stopped
2023-03-22T19:29:01.060Z,1679513341.060 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-03-22T19:29:01.061Z,1679513341.061 [Default:CheckIn] Stopped
2023-03-22T19:29:01.061Z,1679513341.061 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-03-22T19:29:01.061Z,1679513341.061 [Default:CheckIn](INFO): Running loop #8
2023-03-22T19:29:01.061Z,1679513341.061 [Default:CheckIn] Running Loop=8
2023-03-22T19:29:01.061Z,1679513341.061 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-03-22T19:29:01.061Z,1679513341.061 [Default:CheckIn:Read_GPS] Running Loop=1
2023-03-22T19:29:03.087Z,1679513343.087 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,192903.00,A,3648.14626,N,12147.24726,W,0.039,115.24,220323,,,D*78
2023-03-22T19:29:03.090Z,1679513343.090 [NAL9602](INFO): GPS fix at 20230322T192903: (36.802438, -121.787454)
2023-03-22T19:29:03.099Z,1679513343.099 [Default:CheckIn:Read_GPS] Stopped
2023-03-22T19:29:03.100Z,1679513343.100 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-03-22T19:29:10.372Z,1679513350.372 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230322T183857/Courier0037.lzma
2023-03-22T19:29:11.375Z,1679513351.375 [DataOverHttps](INFO): Moved sent file to Logs/20230322T183857/Courier0037.lzma.bak
2023-03-22T19:29:11.375Z,1679513351.375 [DataOverHttps](INFO): SBD MOMSN=17542151
2023-03-22T19:29:27.356Z,1679513367.356 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20230322T183857/Express0038.lzma
2023-03-22T19:29:28.359Z,1679513368.359 [DataOverHttps](INFO): Moved sent file to Logs/20230322T183857/Express0038.lzma.bak
2023-03-22T19:29:28.359Z,1679513368.359 [DataOverHttps](INFO): SBD MOMSN=17542154
2023-03-22T19:29:29.763Z,1679513369.763 [Default:CheckIn:Read_Iridium] Stopped
2023-03-22T19:29:29.764Z,1679513369.764 [Default:CheckIn:C.Wait] Running Loop=1
2023-03-22T19:29:29.764Z,1679513369.764 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-03-22T19:33:09.283Z,1679513589.283 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2023-03-22T19:33:09.283Z,1679513589.283 [DVL_micro](ERROR): Failed to parse:
:TS0000000,35.0,+14.0,0000.0,1489.0,000
2023-03-22T19:34:05.863Z,1679513645.863 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-03-22T19:34:30.543Z,1679513670.543 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-03-22T19:34:30.543Z,1679513670.543 [Default:CheckIn:C.Wait] Stopped
2023-03-22T19:34:30.543Z,1679513670.543 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-03-22T19:34:30.544Z,1679513670.544 [Default:CheckIn:D] Running Loop=1
2023-03-22T19:34:30.928Z,1679513670.928 [Default:CheckIn:D] Stopped
2023-03-22T19:34:30.928Z,1679513670.928 [Default:CheckIn:E] Running Loop=1
2023-03-22T19:34:31.351Z,1679513671.351 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 50.020532 min 
2023-03-22T19:34:31.351Z,1679513671.351 [Default:CheckIn:E] Stopped
2023-03-22T19:34:31.351Z,1679513671.351 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-03-22T19:34:31.351Z,1679513671.351 [Default:CheckIn] Stopped
2023-03-22T19:34:31.352Z,1679513671.352 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-03-22T19:34:31.352Z,1679513671.352 [Default:CheckIn](INFO): Running loop #9
2023-03-22T19:34:31.352Z,1679513671.352 [Default:CheckIn] Running Loop=9
2023-03-22T19:34:31.352Z,1679513671.352 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-03-22T19:34:31.352Z,1679513671.352 [Default:CheckIn:Read_GPS] Running Loop=1
2023-03-22T19:34:33.336Z,1679513673.336 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,193434.00,A,3648.14729,N,12147.24891,W,0.039,115.24,220323,,,D*7D
2023-03-22T19:34:33.346Z,1679513673.346 [NAL9602](INFO): GPS fix at 20230322T193434: (36.802455, -121.787482)
2023-03-22T19:34:33.355Z,1679513673.355 [Default:CheckIn:Read_GPS] Stopped
2023-03-22T19:34:33.355Z,1679513673.355 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-03-22T19:34:43.572Z,1679513683.572 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230322T183857/Courier0040.lzma
2023-03-22T19:34:44.575Z,1679513684.575 [DataOverHttps](INFO): Moved sent file to Logs/20230322T183857/Courier0040.lzma.bak
2023-03-22T19:34:44.575Z,1679513684.575 [DataOverHttps](INFO): SBD MOMSN=17542203
2023-03-22T19:35:00.413Z,1679513700.413 [DataOverHttps](INFO): Sending 203 bytes from file Logs/20230322T183857/Express0041.lzma
2023-03-22T19:35:01.415Z,1679513701.415 [DataOverHttps](INFO): Moved sent file to Logs/20230322T183857/Express0041.lzma.bak
2023-03-22T19:35:01.415Z,1679513701.415 [DataOverHttps](INFO): SBD MOMSN=17542206
2023-03-22T19:35:02.866Z,1679513702.866 [Default:CheckIn:Read_Iridium] Stopped
2023-03-22T19:35:02.866Z,1679513702.866 [Default:CheckIn:C.Wait] Running Loop=1
2023-03-22T19:35:02.866Z,1679513702.866 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-03-22T19:35:06.105Z,1679513706.105 [NAL9602](INFO): Not Powering down - fast GPS
2023-03-22T19:39:27.146Z,1679513967.146 [DVL_micro](ERROR): only read 3 of 4 data items
2023-03-22T19:39:27.146Z,1679513967.146 [DVL_micro](ERROR): Failed to parse:
:BI,00061,-02664,+00000,I
2023-03-22T19:39:49.773Z,1679513989.773 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2023-03-22T19:39:49.773Z,1679513989.773 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,+14.000
2023-03-22T19:40:03.535Z,1679514003.535 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-03-22T19:40:03.535Z,1679514003.535 [Default:CheckIn:C.Wait] Stopped
2023-03-22T19:40:03.535Z,1679514003.535 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-03-22T19:40:03.535Z,1679514003.535 [Default:CheckIn:D] Running Loop=1
2023-03-22T19:40:03.922Z,1679514003.922 [Default:CheckIn:D] Stopped
2023-03-22T19:40:03.922Z,1679514003.922 [Default:CheckIn:E] Running Loop=1
2023-03-22T19:40:04.324Z,1679514004.324 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 55.570431 min 
2023-03-22T19:40:04.324Z,1679514004.324 [Default:CheckIn:E] Stopped
2023-03-22T19:40:04.325Z,1679514004.325 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-03-22T19:40:04.325Z,1679514004.325 [Default:CheckIn] Stopped
2023-03-22T19:40:04.325Z,1679514004.325 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-03-22T19:40:04.325Z,1679514004.325 [Default:CheckIn](INFO): Running loop #10
2023-03-22T19:40:04.325Z,1679514004.325 [Default:CheckIn] Running Loop=10
2023-03-22T19:40:04.325Z,1679514004.325 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-03-22T19:40:04.325Z,1679514004.325 [Default:CheckIn:Read_GPS] Running Loop=1
2023-03-22T19:40:06.332Z,1679514006.332 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194007.00,A,3648.14754,N,12147.24915,W,0.039,115.24,220323,,,D*79
2023-03-22T19:40:06.344Z,1679514006.344 [NAL9602](INFO): GPS fix at 20230322T194007: (36.802459, -121.787486)
2023-03-22T19:40:06.354Z,1679514006.354 [Default:CheckIn:Read_GPS] Stopped
2023-03-22T19:40:06.354Z,1679514006.354 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-03-22T19:40:14.356Z,1679514014.356 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230322T183857/Courier0043.lzma
2023-03-22T19:40:15.359Z,1679514015.359 [DataOverHttps](INFO): Moved sent file to Logs/20230322T183857/Courier0043.lzma.bak
2023-03-22T19:40:15.359Z,1679514015.359 [DataOverHttps](INFO): SBD MOMSN=17542216
2023-03-22T19:40:31.353Z,1679514031.353 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20230322T183857/Express0044.lzma
2023-03-22T19:40:32.355Z,1679514032.355 [DataOverHttps](INFO): Moved sent file to Logs/20230322T183857/Express0044.lzma.bak
2023-03-22T19:40:32.355Z,1679514032.355 [DataOverHttps](INFO): SBD MOMSN=17542219
2023-03-22T19:40:33.855Z,1679514033.855 [Default:CheckIn:Read_Iridium] Stopped
2023-03-22T19:40:33.855Z,1679514033.855 [Default:CheckIn:C.Wait] Running Loop=1
2023-03-22T19:40:33.855Z,1679514033.855 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-03-22T19:40:37.087Z,1679514037.087 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-03-22T19:40:37.161Z,1679514037.161 [NAL9602](ERROR): received: 
+CSQ:0

OK470, 2, 0, 0, 0

OK
2023-03-22T19:42:42.368Z,1679514162.368 [NAL9602](INFO): SBD MO Status=0, MOMSN=47470, MT Status=0, MTMSN=0
2023-03-22T19:42:42.368Z,1679514162.368 [NAL9602](INFO): No messages in MT queue
2023-03-22T19:43:13.065Z,1679514193.065 [NAL9602](INFO): Not Powering down - fast GPS
2023-03-22T19:45:34.488Z,1679514334.488 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-03-22T19:45:34.488Z,1679514334.488 [Default:CheckIn:C.Wait] Stopped
2023-03-22T19:45:34.488Z,1679514334.488 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-03-22T19:45:34.488Z,1679514334.488 [Default:CheckIn:D] Running Loop=1
2023-03-22T19:45:34.881Z,1679514334.881 [Default:CheckIn:D] Stopped
2023-03-22T19:45:34.881Z,1679514334.881 [Default:CheckIn:E] Running Loop=1
2023-03-22T19:45:35.289Z,1679514335.289 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 61.086405 min 
2023-03-22T19:45:35.289Z,1679514335.289 [Default:CheckIn:E] Stopped
2023-03-22T19:45:35.289Z,1679514335.289 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-03-22T19:45:35.289Z,1679514335.289 [Default:CheckIn] Stopped
2023-03-22T19:45:35.289Z,1679514335.289 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-03-22T19:45:35.289Z,1679514335.289 [Default:CheckIn](INFO): Running loop #11
2023-03-22T19:45:35.289Z,1679514335.289 [Default:CheckIn] Running Loop=11
2023-03-22T19:45:35.290Z,1679514335.290 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-03-22T19:45:35.290Z,1679514335.290 [Default:CheckIn:Read_GPS] Running Loop=1
2023-03-22T19:45:37.307Z,1679514337.307 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194538.00,A,3648.14858,N,12147.25011,W,0.019,115.24,220323,,,D*7D
2023-03-22T19:45:37.309Z,1679514337.309 [NAL9602](INFO): GPS fix at 20230322T194538: (36.802476, -121.787502)
2023-03-22T19:45:37.319Z,1679514337.319 [Default:CheckIn:Read_GPS] Stopped
2023-03-22T19:45:37.319Z,1679514337.319 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-03-22T19:45:44.672Z,1679514344.672 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230322T183857/Courier0046.lzma
2023-03-22T19:45:45.675Z,1679514345.675 [DataOverHttps](INFO): Moved sent file to Logs/20230322T183857/Courier0046.lzma.bak
2023-03-22T19:45:45.675Z,1679514345.675 [DataOverHttps](INFO): SBD MOMSN=17542307
2023-03-22T19:46:01.632Z,1679514361.632 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20230322T183857/Express0047.lzma
2023-03-22T19:46:02.635Z,1679514362.635 [DataOverHttps](INFO): Moved sent file to Logs/20230322T183857/Express0047.lzma.bak
2023-03-22T19:46:02.635Z,1679514362.635 [DataOverHttps](INFO): SBD MOMSN=17542310
2023-03-22T19:46:03.979Z,1679514363.979 [Default:CheckIn:Read_Iridium] Stopped
2023-03-22T19:46:03.979Z,1679514363.979 [Default:CheckIn:C.Wait] Running Loop=1
2023-03-22T19:46:03.979Z,1679514363.979 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-03-22T19:50:39.959Z,1679514639.959 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-03-22T19:51:04.623Z,1679514664.623 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-03-22T19:51:04.623Z,1679514664.623 [Default:CheckIn:C.Wait] Stopped
2023-03-22T19:51:04.624Z,1679514664.624 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-03-22T19:51:04.624Z,1679514664.624 [Default:CheckIn:D] Running Loop=1
2023-03-22T19:51:05.080Z,1679514665.080 [Default:CheckIn:D] Stopped
2023-03-22T19:51:05.080Z,1679514665.080 [Default:CheckIn:E] Running Loop=1
2023-03-22T19:51:05.451Z,1679514665.451 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 66.589730 min 
2023-03-22T19:51:05.451Z,1679514665.451 [Default:CheckIn:E] Stopped
2023-03-22T19:51:05.451Z,1679514665.451 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-03-22T19:51:05.451Z,1679514665.451 [Default:CheckIn] Stopped
2023-03-22T19:51:05.451Z,1679514665.451 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-03-22T19:51:05.452Z,1679514665.452 [Default:CheckIn](INFO): Running loop #12
2023-03-22T19:51:05.452Z,1679514665.452 [Default:CheckIn] Running Loop=12
2023-03-22T19:51:05.452Z,1679514665.452 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-03-22T19:51:05.452Z,1679514665.452 [Default:CheckIn:Read_GPS] Running Loop=1
2023-03-22T19:51:07.426Z,1679514667.426 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,195108.00,A,3648.14801,N,12147.24756,W,0.019,0.00,220323,,,D*71
2023-03-22T19:51:07.428Z,1679514667.428 [NAL9602](INFO): GPS fix at 20230322T195108: (36.802467, -121.787459)
2023-03-22T19:51:07.438Z,1679514667.438 [Default:CheckIn:Read_GPS] Stopped
2023-03-22T19:51:07.438Z,1679514667.438 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-03-22T19:51:15.136Z,1679514675.136 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20230322T183857/Courier0049.lzma
2023-03-22T19:51:16.139Z,1679514676.139 [DataOverHttps](INFO): Moved sent file to Logs/20230322T183857/Courier0049.lzma.bak
2023-03-22T19:51:16.139Z,1679514676.139 [DataOverHttps](INFO): SBD MOMSN=17542320
2023-03-22T19:51:32.629Z,1679514692.629 [DataOverHttps](INFO): Sending 204 bytes from file Logs/20230322T183857/Express0050.lzma
2023-03-22T19:51:33.631Z,1679514693.631 [DataOverHttps](INFO): Moved sent file to Logs/20230322T183857/Express0050.lzma.bak
2023-03-22T19:51:33.631Z,1679514693.631 [DataOverHttps](INFO): SBD MOMSN=17542323
2023-03-22T19:51:34.908Z,1679514694.908 [Default:CheckIn:Read_Iridium] Stopped
2023-03-22T19:51:34.909Z,1679514694.909 [Default:CheckIn:C.Wait] Running Loop=1
2023-03-22T19:51:34.909Z,1679514694.909 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-03-22T19:51:39.852Z,1679514699.852 [NAL9602](INFO): Not Powering down - fast GPS
2023-03-22T19:52:12.557Z,1679514732.557 [DVL_micro](ERROR): Failed to parse:
:WI,+00206,+01058,-02484,+00000,A
2023-03-22T19:54:25.439Z,1679514865.439 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2023-03-22T19:54:25.442Z,1679514865.442 [BPC1](INFO): Received data from all battery sticks.
2023-03-22T19:56:35.545Z,1679514995.545 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-03-22T19:56:35.545Z,1679514995.545 [Default:CheckIn:C.Wait] Stopped
2023-03-22T19:56:35.545Z,1679514995.545 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-03-22T19:56:35.545Z,1679514995.545 [Default:CheckIn:D] Running Loop=1
2023-03-22T19:56:35.953Z,1679514995.953 [Default:CheckIn:D] Stopped
2023-03-22T19:56:35.953Z,1679514995.953 [Default:CheckIn:E] Running Loop=1
2023-03-22T19:56:36.396Z,1679514996.396 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 72.104272 min 
2023-03-22T19:56:36.397Z,1679514996.397 [Default:CheckIn:E] Stopped
2023-03-22T19:56:36.397Z,1679514996.397 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-03-22T19:56:36.401Z,1679514996.401 [Default:CheckIn] Stopped
2023-03-22T19:56:36.401Z,1679514996.401 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-03-22T19:56:36.401Z,1679514996.401 [Default:CheckIn](INFO): Running loop #13
2023-03-22T19:56:36.401Z,1679514996.401 [Default:CheckIn] Running Loop=13
2023-03-22T19:56:36.401Z,1679514996.401 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-03-22T19:56:36.402Z,1679514996.402 [Default:CheckIn:Read_GPS] Running Loop=1
2023-03-22T19:56:38.357Z,1679514998.357 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,195639.00,A,3648.14780,N,12147.24922,W,0.019,0.00,220323,,,D*7F
2023-03-22T19:56:38.363Z,1679514998.363 [NAL9602](INFO): GPS fix at 20230322T195639: (36.802463, -121.787487)
2023-03-22T19:56:38.385Z,1679514998.385 [Default:CheckIn:Read_GPS] Stopped
2023-03-22T19:56:38.385Z,1679514998.385 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-03-22T19:56:45.476Z,1679515005.476 [DataOverHttps](INFO): Sending 85 bytes from file Logs/20230322T183857/Courier0052.lzma
2023-03-22T19:56:46.479Z,1679515006.479 [DataOverHttps](INFO): Moved sent file to Logs/20230322T183857/Courier0052.lzma.bak
2023-03-22T19:56:46.479Z,1679515006.479 [DataOverHttps](INFO): SBD MOMSN=17542369
2023-03-22T19:57:02.352Z,1679515022.352 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20230322T183857/Express0053.lzma
2023-03-22T19:57:03.355Z,1679515023.355 [DataOverHttps](INFO): Moved sent file to Logs/20230322T183857/Express0053.lzma.bak
2023-03-22T19:57:03.355Z,1679515023.355 [DataOverHttps](INFO): SBD MOMSN=17542372
2023-03-22T19:57:04.745Z,1679515024.745 [Default:CheckIn:Read_Iridium] Stopped
2023-03-22T19:57:04.745Z,1679515024.745 [Default:CheckIn:C.Wait] Running Loop=1
2023-03-22T19:57:04.745Z,1679515024.745 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-03-22T19:57:09.188Z,1679515029.188 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-03-22T19:57:09.261Z,1679515029.261 [NAL9602](ERROR): received: 
+CSQ:0

OK470, 0, 0, 0, 0

OK
2023-03-22T20:01:40.679Z,1679515300.679 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-03-22T20:01:55.632Z,1679515315.632 [DVL_micro](ERROR): only read 3 of 4 data items
2023-03-22T20:01:55.633Z,1679515315.633 [DVL_micro](ERROR): Failed to parse:
:BI,-00427,+00672,-0264,I
2023-03-22T20:02:05.326Z,1679515325.326 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-03-22T20:02:05.326Z,1679515325.326 [Default:CheckIn:C.Wait] Stopped
2023-03-22T20:02:05.326Z,1679515325.326 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-03-22T20:02:05.326Z,1679515325.326 [Default:CheckIn:D] Running Loop=1
2023-03-22T20:02:05.741Z,1679515325.741 [Default:CheckIn:D] Stopped
2023-03-22T20:02:05.741Z,1679515325.741 [Default:CheckIn:E] Running Loop=1
2023-03-22T20:02:06.143Z,1679515326.143 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 77.600741 min 
2023-03-22T20:02:06.143Z,1679515326.143 [Default:CheckIn:E] Stopped
2023-03-22T20:02:06.143Z,1679515326.143 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-03-22T20:02:06.143Z,1679515326.143 [Default:CheckIn] Stopped
2023-03-22T20:02:06.143Z,1679515326.143 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-03-22T20:02:06.143Z,1679515326.143 [Default:CheckIn](INFO): Running loop #14
2023-03-22T20:02:06.143Z,1679515326.143 [Default:CheckIn] Running Loop=14
2023-03-22T20:02:06.144Z,1679515326.144 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-03-22T20:02:06.144Z,1679515326.144 [Default:CheckIn:Read_GPS] Running Loop=1
2023-03-22T20:02:08.170Z,1679515328.170 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,200209.00,A,3648.14804,N,12147.24941,W,0.019,0.00,220323,,,D*71
2023-03-22T20:02:08.172Z,1679515328.172 [NAL9602](INFO): GPS fix at 20230322T200209: (36.802467, -121.787490)
2023-03-22T20:02:08.181Z,1679515328.181 [Default:CheckIn:Read_GPS] Stopped
2023-03-22T20:02:08.181Z,1679515328.181 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-03-22T20:02:15.928Z,1679515335.928 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230322T183857/Courier0055.lzma
2023-03-22T20:02:16.931Z,1679515336.931 [DataOverHttps](INFO): Moved sent file to Logs/20230322T183857/Courier0055.lzma.bak
2023-03-22T20:02:16.931Z,1679515336.931 [DataOverHttps](INFO): SBD MOMSN=17542381
2023-03-22T20:02:34.073Z,1679515354.073 [DataOverHttps](INFO): Sending 204 bytes from file Logs/20230322T183857/Express0056.lzma
2023-03-22T20:02:35.075Z,1679515355.075 [DataOverHttps](INFO): Moved sent file to Logs/20230322T183857/Express0056.lzma.bak
2023-03-22T20:02:35.075Z,1679515355.075 [DataOverHttps](INFO): SBD MOMSN=17542384
2023-03-22T20:02:36.455Z,1679515356.455 [Default:CheckIn:Read_Iridium] Stopped
2023-03-22T20:02:36.455Z,1679515356.455 [Default:CheckIn:C.Wait] Running Loop=1
2023-03-22T20:02:36.455Z,1679515356.455 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-03-22T20:02:40.936Z,1679515360.936 [NAL9602](INFO): Not Powering down - fast GPS
2023-03-22T20:05:08.367Z,1679515508.367 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2023-03-22T20:05:08.367Z,1679515508.367 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,+14.8,0000.0,10
2023-03-22T20:06:54.234Z,1679515614.234 [CBIT](IMPORTANT): Beginning ground fault scan
2023-03-22T20:07:05.141Z,1679515625.141 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.059122
CHAN A1 (24V): 0.053388
CHAN A2 (12V): -0.006106
CHAN A3 (5V): -0.018805
CHAN B0 (3.3V): -0.012491
CHAN B1 (3.15aV): -0.009345
CHAN B2 (3.15bV): -0.006491
CHAN B3 (GND): -0.012764
OPEN: 0.007551
Full Scale: +/- 1 mA
2023-03-22T20:07:37.063Z,1679515657.063 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-03-22T20:07:37.063Z,1679515657.063 [Default:CheckIn:C.Wait] Stopped
2023-03-22T20:07:37.063Z,1679515657.063 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-03-22T20:07:37.064Z,1679515657.064 [Default:CheckIn:D] Running Loop=1
2023-03-22T20:07:37.462Z,1679515657.462 [Default:CheckIn:D] Stopped
2023-03-22T20:07:37.462Z,1679515657.462 [Default:CheckIn:E] Running Loop=1
2023-03-22T20:07:37.910Z,1679515657.910 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 83.129427 min 
2023-03-22T20:07:37.910Z,1679515657.910 [Default:CheckIn:E] Stopped
2023-03-22T20:07:37.911Z,1679515657.911 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-03-22T20:07:37.911Z,1679515657.911 [Default:CheckIn] Stopped
2023-03-22T20:07:37.911Z,1679515657.911 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-03-22T20:07:37.911Z,1679515657.911 [Default:CheckIn](INFO): Running loop #15
2023-03-22T20:07:37.911Z,1679515657.911 [Default:CheckIn] Running Loop=15
2023-03-22T20:07:37.911Z,1679515657.911 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-03-22T20:07:37.911Z,1679515657.911 [Default:CheckIn:Read_GPS] Running Loop=1
2023-03-22T20:07:39.873Z,1679515659.873 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,200740.00,A,3648.14833,N,12147.24761,W,0.019,0.00,220323,,,D*71
2023-03-22T20:07:39.875Z,1679515659.875 [NAL9602](INFO): GPS fix at 20230322T200740: (36.802472, -121.787460)
2023-03-22T20:07:39.884Z,1679515659.884 [Default:CheckIn:Read_GPS] Stopped
2023-03-22T20:07:39.884Z,1679515659.884 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-03-22T20:07:47.600Z,1679515667.600 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230322T183857/Courier0058.lzma
2023-03-22T20:07:48.603Z,1679515668.603 [DataOverHttps](INFO): Moved sent file to Logs/20230322T183857/Courier0058.lzma.bak
2023-03-22T20:07:48.603Z,1679515668.603 [DataOverHttps](INFO): SBD MOMSN=17542395
2023-03-22T20:08:04.573Z,1679515684.573 [DataOverHttps](INFO): Sending 309 bytes from file Logs/20230322T183857/Express0059.lzma
2023-03-22T20:08:05.575Z,1679515685.575 [DataOverHttps](INFO): Moved sent file to Logs/20230322T183857/Express0059.lzma.bak
2023-03-22T20:08:05.575Z,1679515685.575 [DataOverHttps](INFO): SBD MOMSN=17542398
2023-03-22T20:08:06.973Z,1679515686.973 [Default:CheckIn:Read_Iridium] Stopped
2023-03-22T20:08:06.973Z,1679515686.973 [Default:CheckIn:C.Wait] Running Loop=1
2023-03-22T20:08:06.973Z,1679515686.973 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-03-22T20:12:11.765Z,1679515931.765 [DVL_micro](ERROR): Failed to parse:
:WI,+00571,+00403,-02656,+00000,A
2023-03-22T20:12:17.022Z,1679515937.022 [NAL9602](INFO): SBD MO Status=0, MOMSN=47471, MT Status=0, MTMSN=0
2023-03-22T20:12:17.022Z,1679515937.022 [NAL9602](INFO): No messages in MT queue
2023-03-22T20:12:47.715Z,1679515967.715 [NAL9602](INFO): Not Powering down - fast GPS
2023-03-22T20:13:07.554Z,1679515987.554 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-03-22T20:13:07.554Z,1679515987.554 [Default:CheckIn:C.Wait] Stopped
2023-03-22T20:13:07.554Z,1679515987.554 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-03-22T20:13:07.554Z,1679515987.554 [Default:CheckIn:D] Running Loop=1
2023-03-22T20:13:07.928Z,1679515987.928 [Default:CheckIn:D] Stopped
2023-03-22T20:13:07.928Z,1679515987.928 [Default:CheckIn:E] Running Loop=1
2023-03-22T20:13:08.328Z,1679515988.328 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 88.637199 min 
2023-03-22T20:13:08.328Z,1679515988.328 [Default:CheckIn:E] Stopped
2023-03-22T20:13:08.328Z,1679515988.328 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-03-22T20:13:08.328Z,1679515988.328 [Default:CheckIn] Stopped
2023-03-22T20:13:08.328Z,1679515988.328 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-03-22T20:13:08.328Z,1679515988.328 [Default:CheckIn](INFO): Running loop #16
2023-03-22T20:13:08.328Z,1679515988.328 [Default:CheckIn] Running Loop=16
2023-03-22T20:13:08.329Z,1679515988.329 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-03-22T20:13:08.329Z,1679515988.329 [Default:CheckIn:Read_GPS] Running Loop=1
2023-03-22T20:13:10.351Z,1679515990.351 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,201311.00,A,3648.14738,N,12147.24826,W,0.039,0.00,220323,,,D*7A
2023-03-22T20:13:10.354Z,1679515990.354 [NAL9602](INFO): GPS fix at 20230322T201311: (36.802456, -121.787471)
2023-03-22T20:13:10.363Z,1679515990.363 [Default:CheckIn:Read_GPS] Stopped
2023-03-22T20:13:10.363Z,1679515990.363 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-03-22T20:13:17.716Z,1679515997.716 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230322T183857/Courier0061.lzma
2023-03-22T20:13:18.719Z,1679515998.719 [DataOverHttps](INFO): Moved sent file to Logs/20230322T183857/Courier0061.lzma.bak
2023-03-22T20:13:18.719Z,1679515998.719 [DataOverHttps](INFO): SBD MOMSN=17542411
2023-03-22T20:13:36.279Z,1679516016.279 [NAL9602](INFO): SBD MO Status=0, MOMSN=47472, MT Status=0, MTMSN=0
2023-03-22T20:13:36.279Z,1679516016.279 [NAL9602](INFO): No messages in MT queue
2023-03-22T20:13:37.585Z,1679516017.585 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20230322T183857/Express0062.lzma
2023-03-22T20:13:38.587Z,1679516018.587 [DataOverHttps](INFO): Moved sent file to Logs/20230322T183857/Express0062.lzma.bak
2023-03-22T20:13:38.587Z,1679516018.587 [DataOverHttps](INFO): SBD MOMSN=17542414
2023-03-22T20:13:39.893Z,1679516019.893 [Default:CheckIn:Read_Iridium] Stopped
2023-03-22T20:13:39.893Z,1679516019.893 [Default:CheckIn:C.Wait] Running Loop=1
2023-03-22T20:13:39.893Z,1679516019.893 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-03-22T20:14:06.943Z,1679516046.943 [NAL9602](INFO): Not Powering down - fast GPS
2023-03-22T20:14:48.598Z,1679516088.598 [DVL_micro](ERROR): only read 3 of 4 data items
2023-03-22T20:14:48.598Z,1679516088.598 [DVL_micro](ERROR): Failed to parse:
:BI,-0038,-02260,+00000,I
2023-03-22T20:18:40.458Z,1679516320.458 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-03-22T20:18:40.458Z,1679516320.458 [Default:CheckIn:C.Wait] Stopped
2023-03-22T20:18:40.458Z,1679516320.458 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-03-22T20:18:40.458Z,1679516320.458 [Default:CheckIn:D] Running Loop=1
2023-03-22T20:18:40.868Z,1679516320.868 [Default:CheckIn:D] Stopped
2023-03-22T20:18:40.868Z,1679516320.868 [Default:CheckIn:E] Running Loop=1
2023-03-22T20:18:41.276Z,1679516321.276 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 94.186190 min 
2023-03-22T20:18:41.276Z,1679516321.276 [Default:CheckIn:E] Stopped
2023-03-22T20:18:41.276Z,1679516321.276 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-03-22T20:18:41.276Z,1679516321.276 [Default:CheckIn] Stopped
2023-03-22T20:18:41.277Z,1679516321.277 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-03-22T20:18:41.277Z,1679516321.277 [Default:CheckIn](INFO): Running loop #17
2023-03-22T20:18:41.277Z,1679516321.277 [Default:CheckIn] Running Loop=17
2023-03-22T20:18:41.277Z,1679516321.277 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-03-22T20:18:41.277Z,1679516321.277 [Default:CheckIn:Read_GPS] Running Loop=1
2023-03-22T20:18:43.283Z,1679516323.283 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,201844.00,A,3648.14864,N,12147.24924,W,0.000,0.00,220323,,,D*7E
2023-03-22T20:18:43.286Z,1679516323.286 [NAL9602](INFO): GPS fix at 20230322T201844: (36.802477, -121.787487)
2023-03-22T20:18:43.295Z,1679516323.295 [Default:CheckIn:Read_GPS] Stopped
2023-03-22T20:18:43.295Z,1679516323.295 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-03-22T20:18:50.460Z,1679516330.460 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230322T183857/Courier0064.lzma
2023-03-22T20:18:51.463Z,1679516331.463 [DataOverHttps](INFO): Moved sent file to Logs/20230322T183857/Courier0064.lzma.bak
2023-03-22T20:18:51.463Z,1679516331.463 [DataOverHttps](INFO): SBD MOMSN=17542445
2023-03-22T20:19:07.417Z,1679516347.417 [DataOverHttps](INFO): Sending 136 bytes from file Logs/20230322T183857/Express0065.lzma
2023-03-22T20:19:08.419Z,1679516348.419 [DataOverHttps](INFO): Moved sent file to Logs/20230322T183857/Express0065.lzma.bak
2023-03-22T20:19:08.419Z,1679516348.419 [DataOverHttps](INFO): SBD MOMSN=17542448
2023-03-22T20:19:09.551Z,1679516349.551 [Default:CheckIn:Read_Iridium] Stopped
2023-03-22T20:19:09.551Z,1679516349.551 [Default:CheckIn:C.Wait] Running Loop=1
2023-03-22T20:19:09.551Z,1679516349.551 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-03-22T20:20:35.188Z,1679516435.188 [NAL9602](INFO): SBD MO Status=2, MOMSN=47473, MT Status=2, MTMSN=0
2023-03-22T20:20:35.188Z,1679516435.188 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-03-22T20:21:01.453Z,1679516461.453 [DVL_micro](ERROR): Failed to parse:
:SA,-00.93,-04.95,243.1
2023-03-22T20:21:12.359Z,1679516472.359 [NAL9602](INFO): SBD MO Status=2, MOMSN=47473, MT Status=2, MTMSN=0
2023-03-22T20:21:12.359Z,1679516472.359 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-03-22T20:21:38.233Z,1679516498.233 [NAL9602](INFO): SBD MO Status=2, MOMSN=47473, MT Status=2, MTMSN=0
2023-03-22T20:21:38.237Z,1679516498.237 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-03-22T20:22:04.471Z,1679516524.471 [NAL9602](INFO): SBD MO Status=0, MOMSN=47473, MT Status=0, MTMSN=0
2023-03-22T20:22:04.471Z,1679516524.471 [NAL9602](INFO): No messages in MT queue
2023-03-22T20:22:35.199Z,1679516555.199 [NAL9602](INFO): Not Powering down - fast GPS
2023-03-22T20:24:10.145Z,1679516650.145 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-03-22T20:24:10.145Z,1679516650.145 [Default:CheckIn:C.Wait] Stopped
2023-03-22T20:24:10.145Z,1679516650.145 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-03-22T20:24:10.145Z,1679516650.145 [Default:CheckIn:D] Running Loop=1
2023-03-22T20:24:10.535Z,1679516650.535 [Default:CheckIn:D] Stopped
2023-03-22T20:24:10.535Z,1679516650.535 [Default:CheckIn:E] Running Loop=1
2023-03-22T20:24:10.936Z,1679516650.936 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 99.680648 min 
2023-03-22T20:24:10.936Z,1679516650.936 [Default:CheckIn:E] Stopped
2023-03-22T20:24:10.936Z,1679516650.936 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-03-22T20:24:10.936Z,1679516650.936 [Default:CheckIn] Stopped
2023-03-22T20:24:10.936Z,1679516650.936 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-03-22T20:24:10.937Z,1679516650.937 [Default:CheckIn](INFO): Running loop #18
2023-03-22T20:24:10.937Z,1679516650.937 [Default:CheckIn] Running Loop=18
2023-03-22T20:24:10.937Z,1679516650.937 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-03-22T20:24:10.937Z,1679516650.937 [Default:CheckIn:Read_GPS] Running Loop=1
2023-03-22T20:24:12.954Z,1679516652.954 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,202413.00,A,3648.14656,N,12147.24788,W,0.039,0.00,220323,,,D*7E
2023-03-22T20:24:12.956Z,1679516652.956 [NAL9602](INFO): GPS fix at 20230322T202413: (36.802443, -121.787465)
2023-03-22T20:24:12.967Z,1679516652.967 [Default:CheckIn:Read_GPS] Stopped
2023-03-22T20:24:12.967Z,1679516652.967 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-03-22T20:24:19.884Z,1679516659.884 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230322T183857/Courier0067.lzma
2023-03-22T20:24:20.887Z,1679516660.887 [DataOverHttps](INFO): Moved sent file to Logs/20230322T183857/Courier0067.lzma.bak
2023-03-22T20:24:20.887Z,1679516660.887 [DataOverHttps](INFO): SBD MOMSN=17542460
2023-03-22T20:24:39.753Z,1679516679.753 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20230322T183857/Express0068.lzma
2023-03-22T20:24:40.755Z,1679516680.755 [DataOverHttps](INFO): Moved sent file to Logs/20230322T183857/Express0068.lzma.bak
2023-03-22T20:24:40.755Z,1679516680.755 [DataOverHttps](INFO): SBD MOMSN=17542466
2023-03-22T20:24:42.134Z,1679516682.134 [Default:CheckIn:Read_Iridium] Stopped
2023-03-22T20:24:42.134Z,1679516682.134 [Default:CheckIn:C.Wait] Running Loop=1
2023-03-22T20:24:42.134Z,1679516682.134 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-03-22T20:27:03.893Z,1679516823.893 [DVL_micro](ERROR): only read 3 of 4 data items
2023-03-22T20:27:03.894Z,1679516823.894 [DVL_micro](ERROR): Failed to parse:
:BI,+0027,-02223,+00000,I
2023-03-22T20:29:04.310Z,1679516944.310 [NAL9602](INFO): SBD MO Status=2, MOMSN=47474, MT Status=2, MTMSN=0
2023-03-22T20:29:04.310Z,1679516944.310 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-03-22T20:29:14.778Z,1679516954.778 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-03-22T20:29:42.668Z,1679516982.668 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-03-22T20:29:42.668Z,1679516982.668 [Default:CheckIn:C.Wait] Stopped
2023-03-22T20:29:42.668Z,1679516982.668 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-03-22T20:29:42.668Z,1679516982.668 [Default:CheckIn:D] Running Loop=1
2023-03-22T20:29:43.067Z,1679516983.067 [Default:CheckIn:D] Stopped
2023-03-22T20:29:43.067Z,1679516983.067 [Default:CheckIn:E] Running Loop=1
2023-03-22T20:29:43.484Z,1679516983.484 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 105.222843 min 
2023-03-22T20:29:43.484Z,1679516983.484 [Default:CheckIn:E] Stopped
2023-03-22T20:29:43.484Z,1679516983.484 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-03-22T20:29:43.485Z,1679516983.485 [Default:CheckIn] Stopped
2023-03-22T20:29:43.485Z,1679516983.485 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-03-22T20:29:43.485Z,1679516983.485 [Default:CheckIn](INFO): Running loop #19
2023-03-22T20:29:43.485Z,1679516983.485 [Default:CheckIn] Running Loop=19
2023-03-22T20:29:43.485Z,1679516983.485 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-03-22T20:29:43.485Z,1679516983.485 [Default:CheckIn:Read_GPS] Running Loop=1
2023-03-22T20:29:45.488Z,1679516985.488 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,202946.00,A,3648.14661,N,12147.25019,W,0.019,0.00,220323,,,D*7B
2023-03-22T20:29:45.491Z,1679516985.491 [NAL9602](INFO): GPS fix at 20230322T202946: (36.802444, -121.787503)
2023-03-22T20:29:45.500Z,1679516985.500 [Default:CheckIn:Read_GPS] Stopped
2023-03-22T20:29:45.501Z,1679516985.501 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-03-22T20:29:53.236Z,1679516993.236 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230322T183857/Courier0070.lzma
2023-03-22T20:29:54.239Z,1679516994.239 [DataOverHttps](INFO): Moved sent file to Logs/20230322T183857/Courier0070.lzma.bak
2023-03-22T20:29:54.239Z,1679516994.239 [DataOverHttps](INFO): SBD MOMSN=17542470
2023-03-22T20:30:10.077Z,1679517010.077 [DataOverHttps](INFO): Sending 208 bytes from file Logs/20230322T183857/Express0071.lzma
2023-03-22T20:30:11.079Z,1679517011.079 [DataOverHttps](INFO): Moved sent file to Logs/20230322T183857/Express0071.lzma.bak
2023-03-22T20:30:11.079Z,1679517011.079 [DataOverHttps](INFO): SBD MOMSN=17542473
2023-03-22T20:30:12.160Z,1679517012.160 [Default:CheckIn:Read_Iridium] Stopped
2023-03-22T20:30:12.160Z,1679517012.160 [Default:CheckIn:C.Wait] Running Loop=1
2023-03-22T20:30:12.160Z,1679517012.160 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-03-22T20:30:17.803Z,1679517017.803 [NAL9602](INFO): Not Powering down - fast GPS
2023-03-22T20:32:10.602Z,1679517130.602 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2023-03-22T20:32:10.602Z,1679517130.602 [DVL_micro](ERROR): Failed to parse:
:TS,000000000.0,+15.2,0000.0,1489.0,000
2023-03-22T20:34:12.204Z,1679517252.204 [DVL_micro](ERROR): Failed to parse:
:SA,-09.26,-11.80,284.3
2023-03-22T20:35:12.799Z,1679517312.799 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-03-22T20:35:12.799Z,1679517312.799 [Default:CheckIn:C.Wait] Stopped
2023-03-22T20:35:12.799Z,1679517312.799 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-03-22T20:35:12.799Z,1679517312.799 [Default:CheckIn:D] Running Loop=1
2023-03-22T20:35:13.209Z,1679517313.209 [Default:CheckIn:D] Stopped
2023-03-22T20:35:13.209Z,1679517313.209 [Default:CheckIn:E] Running Loop=1
2023-03-22T20:35:13.610Z,1679517313.610 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 110.725203 min 
2023-03-22T20:35:13.610Z,1679517313.610 [Default:CheckIn:E] Stopped
2023-03-22T20:35:13.611Z,1679517313.611 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-03-22T20:35:13.611Z,1679517313.611 [Default:CheckIn] Stopped
2023-03-22T20:35:13.611Z,1679517313.611 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-03-22T20:35:13.611Z,1679517313.611 [Default:CheckIn](INFO): Running loop #20
2023-03-22T20:35:13.611Z,1679517313.611 [Default:CheckIn] Running Loop=20
2023-03-22T20:35:13.611Z,1679517313.611 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-03-22T20:35:13.611Z,1679517313.611 [Default:CheckIn:Read_GPS] Running Loop=1
2023-03-22T20:35:15.646Z,1679517315.646 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,203516.00,A,3648.14602,N,12147.22510,W,1.866,25.88,220323,,,D*4B
2023-03-22T20:35:15.648Z,1679517315.648 [NAL9602](INFO): GPS fix at 20230322T203516: (36.802434, -121.787085)
2023-03-22T20:35:15.673Z,1679517315.673 [Default:CheckIn:Read_GPS] Stopped
2023-03-22T20:35:15.673Z,1679517315.673 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-03-22T20:35:23.752Z,1679517323.752 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230322T183857/Courier0073.lzma
2023-03-22T20:35:24.755Z,1679517324.755 [DataOverHttps](INFO): Moved sent file to Logs/20230322T183857/Courier0073.lzma.bak
2023-03-22T20:35:24.755Z,1679517324.755 [DataOverHttps](INFO): SBD MOMSN=17542484
2023-03-22T20:35:44.413Z,1679517344.413 [DataOverHttps](INFO): Sending 140 bytes from file Logs/20230322T183857/Express0074.lzma
2023-03-22T20:35:45.415Z,1679517345.415 [DataOverHttps](INFO): Moved sent file to Logs/20230322T183857/Express0074.lzma.bak
2023-03-22T20:35:45.415Z,1679517345.415 [DataOverHttps](INFO): SBD MOMSN=17542487
2023-03-22T20:35:46.393Z,1679517346.393 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-03-22T20:35:46.477Z,1679517346.477 [NAL9602](ERROR): received: 
+CSQ:0

OK474, 2, 0, 0, 0

OK
2023-03-22T20:35:46.493Z,1679517346.493 [Default:CheckIn:Read_Iridium] Stopped
2023-03-22T20:35:46.493Z,1679517346.493 [Default:CheckIn:C.Wait] Running Loop=1
2023-03-22T20:35:46.493Z,1679517346.493 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-03-22T20:36:41.751Z,1679517401.751 [DVL_micro](ERROR): only read 3 of 4 data items
2023-03-22T20:36:41.752Z,1679517401.752 [DVL_micro](ERROR): Failed to parse:
:BI,+01683,01212,+00000,I
2023-03-22T20:37:24.989Z,1679517444.989 [DVL_micro](ERROR): only read 3 of 4 data items
2023-03-22T20:37:24.989Z,1679517444.989 [DVL_micro](ERROR): Failed to parse:
:BI,-00100,+01458,-0000,I
2023-03-22T20:37:45.177Z,1679517465.177 [DVL_micro](ERROR): only read 1 of 4 data items
2023-03-22T20:37:45.177Z,1679517465.177 [DVL_micro](ERROR): Failed to parse:
:RD,+9999.99,++9999.99,+9999.99
2023-03-22T20:37:53.656Z,1679517473.656 [NAL9602](INFO): SBD MO Status=2, MOMSN=47474, MT Status=2, MTMSN=0
2023-03-22T20:37:53.656Z,1679517473.656 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-03-22T20:38:11.839Z,1679517491.839 [NAL9602](INFO): SBD MO Status=2, MOMSN=47474, MT Status=2, MTMSN=0
2023-03-22T20:38:11.839Z,1679517491.839 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-03-22T20:38:46.987Z,1679517526.987 [NAL9602](INFO): SBD MO Status=0, MOMSN=47474, MT Status=0, MTMSN=0
2023-03-22T20:38:46.987Z,1679517526.987 [NAL9602](INFO): No messages in MT queue
2023-03-22T20:39:17.690Z,1679517557.690 [NAL9602](INFO): Not Powering down - fast GPS
2023-03-22T20:40:42.535Z,1679517642.535 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2023-03-22T20:40:42.535Z,1679517642.535 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,+0.0,1489.0,000
2023-03-22T20:40:46.987Z,1679517646.987 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-03-22T20:40:46.987Z,1679517646.987 [Default:CheckIn:C.Wait] Stopped
2023-03-22T20:40:46.987Z,1679517646.987 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-03-22T20:40:46.988Z,1679517646.988 [Default:CheckIn:D] Running Loop=1
2023-03-22T20:40:47.402Z,1679517647.402 [Default:CheckIn:D] Stopped
2023-03-22T20:40:47.402Z,1679517647.402 [Default:CheckIn:E] Running Loop=1
2023-03-22T20:40:47.800Z,1679517647.800 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 116.295101 min 
2023-03-22T20:40:47.800Z,1679517647.800 [Default:CheckIn:E] Stopped
2023-03-22T20:40:47.800Z,1679517647.800 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-03-22T20:40:47.800Z,1679517647.800 [Default:CheckIn] Stopped
2023-03-22T20:40:47.800Z,1679517647.800 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-03-22T20:40:47.801Z,1679517647.801 [Default:CheckIn](INFO): Running loop #21
2023-03-22T20:40:47.817Z,1679517647.817 [Default:CheckIn] Running Loop=21
2023-03-22T20:40:47.817Z,1679517647.817 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-03-22T20:40:47.817Z,1679517647.817 [Default:CheckIn:Read_GPS] Running Loop=1
2023-03-22T20:40:49.803Z,1679517649.803 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,204050.00,A,3648.14999,N,12147.22130,W,0.194,4.75,220323,,,D*74
2023-03-22T20:40:49.806Z,1679517649.806 [NAL9602](INFO): GPS fix at 20230322T204050: (36.802500, -121.787022)
2023-03-22T20:40:49.815Z,1679517649.815 [Default:CheckIn:Read_GPS] Stopped
2023-03-22T20:40:49.815Z,1679517649.815 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-03-22T20:40:51.012Z,1679517651.012 [NAL9602](FAULT): LCB fault:  Invalid Command. Hardware Overcurrent Shutdown. Current Limiter Activated.
2023-03-22T20:40:51.012Z,1679517651.012 [NAL9602] Hardware Fault, FailCount= 1
2023-03-22T20:40:51.012Z,1679517651.012 [NAL9602](ERROR): Hardware Fault
2023-03-22T20:40:51.051Z,1679517651.051 [CBIT](ERROR): Hardware Fault in component: NAL9602
2023-03-22T20:40:51.419Z,1679517651.419 [NAL9602](INFO): Powering down
2023-03-22T20:40:52.256Z,1679517652.256 [CBIT](INFO): Clearing failed state for component NAL9602
2023-03-22T20:40:52.256Z,1679517652.256 [NAL9602] No Fault, FailCount= 1
2023-03-22T20:40:57.776Z,1679517657.776 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20230322T183857/Courier0076.lzma
2023-03-22T20:40:58.779Z,1679517658.779 [DataOverHttps](INFO): Moved sent file to Logs/20230322T183857/Courier0076.lzma.bak
2023-03-22T20:40:58.779Z,1679517658.779 [DataOverHttps](INFO): SBD MOMSN=17542491
2023-03-22T20:41:14.724Z,1679517674.724 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20230322T183857/Express0077.lzma
2023-03-22T20:41:15.727Z,1679517675.727 [DataOverHttps](INFO): Moved sent file to Logs/20230322T183857/Express0077.lzma.bak
2023-03-22T20:41:15.727Z,1679517675.727 [DataOverHttps](INFO): SBD MOMSN=17542496
2023-03-22T20:41:16.894Z,1679517676.894 [Default:CheckIn:Read_Iridium] Stopped
2023-03-22T20:41:16.894Z,1679517676.894 [Default:CheckIn:C.Wait] Running Loop=1
2023-03-22T20:41:16.894Z,1679517676.894 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-03-22T20:41:21.715Z,1679517681.715 [NAL9602](INFO): Powering up NAL9602
2023-03-22T20:41:32.623Z,1679517692.623 [NAL9602](INFO): NAL9602 initialized
2023-03-22T20:42:03.742Z,1679517723.742 [NAL9602](INFO): Not Powering down - fast GPS
2023-03-22T20:45:59.614Z,1679517959.614 [DataOverHttps](IMPORTANT): SBD MTMSN=20230322T204600
2023-03-22T20:46:07.065Z,1679517967.065 [DataOverHttps](INFO): Received command: restart sys
2023-03-22T20:46:07.146Z,1679517967.146 [CommandExec](IMPORTANT): got command restart system
2023-03-22T20:46:09.258Z,1679517969.258 [Supervisor](INFO): Stop Mission called by Supervisor::terminate
2023-03-22T20:46:09.259Z,1679517969.259 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread.
2023-03-22T20:46:09.259Z,1679517969.259 [CommandExec](INFO): Uninitializing the command executive.
2023-03-22T20:46:09.259Z,1679517969.259 [CommandExec](INFO): Uninitializing the command scheduler.
2023-03-22T20:46:09.260Z,1679517969.260 [CommandExec ThreadHandler](INFO): Thread cancelled.
2023-03-22T20:46:09.329Z,1679517969.329 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2023-03-22T20:46:09.329Z,1679517969.329 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2023-03-22T20:46:09.330Z,1679517969.330 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2023-03-22T20:46:09.330Z,1679517969.330 [NavChartDb](INFO): Join timeout helper Thread ID is 8163
2023-03-22T20:46:09.577Z,1679517969.577 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2023-03-22T20:46:09.577Z,1679517969.577 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2023-03-22T20:46:09.597Z,1679517969.597 [ComponentRegistry](INFO): Shutting down DAT ThreadHandler
2023-03-22T20:46:09.597Z,1679517969.597 [DAT ThreadHandler](INFO): Thread cancelled.
2023-03-22T20:46:09.598Z,1679517969.598 [DAT](INFO): Join timeout helper Thread ID is 8164
2023-03-22T20:46:09.609Z,1679517969.609 [DAT](INFO): Powering down
2023-03-22T20:46:09.678Z,1679517969.678 [DAT ThreadHandler](INFO): Uninitializing protected caller thread.
2023-03-22T20:46:09.678Z,1679517969.678 [DAT](INFO): Powering down
2023-03-22T20:46:09.679Z,1679517969.679 [DAT ThreadHandler](INFO): Thread cancelled.
2023-03-22T20:46:09.700Z,1679517969.700 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2023-03-22T20:46:09.700Z,1679517969.700 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2023-03-22T20:46:09.700Z,1679517969.700 [Radio_Surface](INFO): Join timeout helper Thread ID is 8165
2023-03-22T20:46:10.017Z,1679517970.017 [Radio_Surface](INFO): Powering down
2023-03-22T20:46:10.019Z,1679517970.019 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2023-03-22T20:46:10.020Z,1679517970.020 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2023-03-22T20:46:10.022Z,1679517970.022 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler
2023-03-22T20:46:10.023Z,1679517970.023 [Onboard ThreadHandler](INFO): Thread cancelled.
2023-03-22T20:46:10.024Z,1679517970.024 [Onboard](INFO): Join timeout helper Thread ID is 8166
2023-03-22T20:46:10.073Z,1679517970.073 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2023-03-22T20:46:10.129Z,1679517970.129 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread.
2023-03-22T20:46:10.129Z,1679517970.129 [Onboard ThreadHandler](INFO): Thread cancelled.
2023-03-22T20:46:10.145Z,1679517970.145 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2023-03-22T20:46:10.145Z,1679517970.145 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2023-03-22T20:46:10.145Z,1679517970.145 [DataOverHttps](INFO): Join timeout helper Thread ID is 8167
2023-03-22T20:46:11.077Z,1679517971.077 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2023-03-22T20:46:11.077Z,1679517971.077 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2023-03-22T20:46:11.090Z,1679517971.090 [ComponentRegistry](INFO): Shutting down BackseatComponent ThreadHandler
2023-03-22T20:46:11.090Z,1679517971.090 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2023-03-22T20:46:11.090Z,1679517971.090 [BackseatComponent](INFO): Join timeout helper Thread ID is 8168
2023-03-22T20:46:11.277Z,1679517971.277 [BackseatComponent ThreadHandler](INFO): Uninitializing protected caller thread.
2023-03-22T20:46:11.277Z,1679517971.277 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2023-03-22T20:46:11.290Z,1679517971.290 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2023-03-22T20:46:11.290Z,1679517971.290 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2023-03-22T20:46:11.290Z,1679517971.290 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 8169
2023-03-22T20:46:11.437Z,1679517971.437 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2023-03-22T20:46:11.438Z,1679517971.438 [WetLabsBB2FL](INFO): Powering down
2023-03-22T20:46:11.438Z,1679517971.438 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2023-03-22T20:46:11.454Z,1679517971.454 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2023-03-22T20:46:11.454Z,1679517971.454 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2023-03-22T20:46:11.454Z,1679517971.454 [CTD_Seabird](INFO): Join timeout helper Thread ID is 8170
2023-03-22T20:46:11.693Z,1679517971.693 [CTD_Seabird](INFO): Powering down
2023-03-22T20:46:11.705Z,1679517971.705 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2023-03-22T20:46:11.705Z,1679517971.705 [CTD_Seabird](INFO): Powering down
2023-03-22T20:46:11.717Z,1679517971.717 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2023-03-22T20:46:11.718Z,1679517971.718 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2023-03-22T20:46:11.718Z,1679517971.718 [logger ThreadHandler](INFO): Thread cancelled.
2023-03-22T20:46:11.719Z,1679517971.719 [logger](INFO): Join timeout helper Thread ID is 8171
2023-03-22T20:46:11.725Z,1679517971.725 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2023-03-22T20:46:11.725Z,1679517971.725 [logger ThreadHandler](INFO): Thread cancelled.
2023-03-22T20:46:11.738Z,1679517971.738 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2023-03-22T20:46:11.738Z,1679517971.738 [CommandLine ThreadHandler](INFO): Thread cancelled.
2023-03-22T20:46:11.738Z,1679517971.738 [CommandLine](INFO): Join timeout helper Thread ID is 8172
2023-03-22T20:46:11.793Z,1679517971.793 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2023-03-22T20:46:11.794Z,1679517971.794 [CommandLine ThreadHandler](INFO): Thread cancelled.
2023-03-22T20:46:11.806Z,1679517971.806 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler
2023-03-22T20:46:11.806Z,1679517971.806 [CommandExec ThreadHandler](INFO): Thread cancelled.
2023-03-22T20:46:11.806Z,1679517971.806 [CommandExec](INFO): Join timeout helper Thread ID is 8173
2023-03-22T20:46:11.810Z,1679517971.810 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2023-03-22T20:46:11.810Z,1679517971.810 [controlThread ThreadHandler](INFO): Thread cancelled.
2023-03-22T20:46:11.810Z,1679517971.810 [controlThread](INFO): Join timeout helper Thread ID is 8174
2023-03-22T20:46:12.169Z,1679517972.169 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2023-03-22T20:46:12.169Z,1679517972.169 [controlThread](DEBUG): Uninitializing ControlThread
2023-03-22T20:46:12.170Z,1679517972.170 [AHRS_M2](INFO): Powering down
2023-03-22T20:46:12.313Z,1679517972.313 [DVL_micro](INFO): Powering down
2023-03-22T20:46:12.314Z,1679517972.314 [MultiRay](INFO): Powering down.
2023-03-22T20:46:12.315Z,1679517972.315 [NAL9602](INFO): Powering down
2023-03-22T20:46:12.317Z,1679517972.317 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2023-03-22T20:46:12.318Z,1679517972.318 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2023-03-22T20:46:12.318Z,1679517972.318 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2023-03-22T20:46:12.319Z,1679517972.319 [MissionManager](INFO): Uninitializing Mission Default
2023-03-22T20:46:12.319Z,1679517972.319 [Default] Stopped
2023-03-22T20:46:12.319Z,1679517972.319 [Default](DEBUG): Aggregate::uninitialize Default
2023-03-22T20:46:12.319Z,1679517972.319 [Default:B.GoToSurface] Stopped
2023-03-22T20:46:12.319Z,1679517972.319 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2023-03-22T20:46:12.319Z,1679517972.319 [Default:CheckIn] Stopped
2023-03-22T20:46:12.319Z,1679517972.319 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-03-22T20:46:12.319Z,1679517972.319 [Default:CheckIn:C.Wait] Stopped
2023-03-22T20:46:12.319Z,1679517972.319 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-03-22T20:46:12.322Z,1679517972.322 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2023-03-22T20:46:12.322Z,1679517972.322 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2023-03-22T20:46:12.323Z,1679517972.323 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2023-03-22T20:46:12.323Z,1679517972.323 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2023-03-22T20:46:12.323Z,1679517972.323 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2023-03-22T20:46:12.323Z,1679517972.323 [BuoyancyServo](INFO): Powering down
2023-03-22T20:46:12.337Z,1679517972.337 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2023-03-22T20:46:12.337Z,1679517972.337 [ElevatorServo](INFO): Powering down
2023-03-22T20:46:12.338Z,1679517972.338 [MassServo](DEBUG): Uninitialize Mass Servo.
2023-03-22T20:46:12.338Z,1679517972.338 [MassServo](INFO): Powering down
2023-03-22T20:46:12.339Z,1679517972.339 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2023-03-22T20:46:12.339Z,1679517972.339 [RudderServo](INFO): Powering down
2023-03-22T20:46:12.340Z,1679517972.340 [ThrusterHE](DEBUG): Uninitialize Thruster Servo.
2023-03-22T20:46:12.340Z,1679517972.340 [ThrusterHE](INFO): Powering down
2023-03-22T20:46:12.341Z,1679517972.341 [SBIT](DEBUG): Uninitialize SBIT Component.
2023-03-22T20:46:12.342Z,1679517972.342 [IBIT](DEBUG): Uninitialize IBIT Component.
2023-03-22T20:46:12.342Z,1679517972.342 [CBIT](DEBUG): Uninitialize CBIT Component.
2023-03-22T20:46:12.342Z,1679517972.342 [CBIT](DEBUG): Powering off loads.
2023-03-22T20:46:12.353Z,1679517972.353 [CBIT](DEBUG): Disabling WDT.
2023-03-22T20:46:12.365Z,1679517972.365 [CBIT](DEBUG): Opening all GF detection circuits.
2023-03-22T20:46:12.366Z,1679517972.366 [controlThread ThreadHandler](INFO): Thread cancelled.
2023-03-22T20:46:12.408Z,1679517972.408 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2023-03-22T20:46:12.414Z,1679517972.414 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2023-03-22T20:46:12.451Z,1679517972.451 [DAT ThreadHandler](INFO): Thread cancelled.
2023-03-22T20:46:12.455Z,1679517972.455 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2023-03-22T20:46:12.458Z,1679517972.458 [Onboard ThreadHandler](INFO): Thread cancelled.
2023-03-22T20:46:12.467Z,1679517972.467 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2023-03-22T20:46:12.514Z,1679517972.514 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2023-03-22T20:46:12.578Z,1679517972.578 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2023-03-22T20:46:12.649Z,1679517972.649 [logger ThreadHandler](INFO): Thread cancelled.