2021-08-30T18:27:20.526Z,1630348040.526 [Supervisor](DEBUG): Initializing supervisor.
2021-08-30T18:27:20.531Z,1630348040.531 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2021-08-30T18:27:20.531Z,1630348040.531 [SyncHandler](INFO): Protected caller Thread ID is 4461
2021-08-30T18:27:20.532Z,1630348040.532 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2021-08-30T18:27:20.533Z,1630348040.533 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2021-08-30T18:27:20.533Z,1630348040.533 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 4462
2021-08-30T18:27:20.537Z,1630348040.537 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2021-08-30T18:27:20.558Z,1630348040.558 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2021-08-30T18:27:20.559Z,1630348040.559 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2021-08-30T18:27:20.559Z,1630348040.559 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 4463
2021-08-30T18:27:20.561Z,1630348040.561 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2021-08-30T18:27:20.562Z,1630348040.562 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2021-08-30T18:27:20.563Z,1630348040.563 [logger ThreadHandler](INFO): Protected caller Thread ID is 4464
2021-08-30T18:27:20.567Z,1630348040.567 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2021-08-30T18:27:20.567Z,1630348040.567 [Supervisor](INFO): Looking for Config files in directory: Config/
2021-08-30T18:27:20.569Z,1630348040.569 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2021-08-30T18:27:20.797Z,1630348040.797 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2021-08-30T18:27:20.797Z,1630348040.797 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2021-08-30T18:27:20.877Z,1630348040.877 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2021-08-30T18:27:21.377Z,1630348041.377 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2021-08-30T18:27:21.377Z,1630348041.377 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2021-08-30T18:27:21.710Z,1630348041.710 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2021-08-30T18:27:21.711Z,1630348041.711 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2021-08-30T18:27:21.807Z,1630348041.807 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2021-08-30T18:27:21.807Z,1630348041.807 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2021-08-30T18:27:22.182Z,1630348042.182 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2021-08-30T18:27:22.183Z,1630348042.183 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2021-08-30T18:27:22.385Z,1630348042.385 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2021-08-30T18:27:22.386Z,1630348042.386 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2021-08-30T18:27:22.945Z,1630348042.945 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2021-08-30T18:27:22.946Z,1630348042.946 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2021-08-30T18:27:23.182Z,1630348043.182 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2021-08-30T18:27:23.183Z,1630348043.183 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2021-08-30T18:27:23.262Z,1630348043.262 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2021-08-30T18:27:23.927Z,1630348043.927 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2021-08-30T18:27:23.928Z,1630348043.928 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2021-08-30T18:27:24.292Z,1630348044.292 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2021-08-30T18:27:24.293Z,1630348044.293 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2021-08-30T18:27:24.485Z,1630348044.485 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2021-08-30T18:27:24.485Z,1630348044.485 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2021-08-30T18:27:24.596Z,1630348044.596 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2021-08-30T18:27:24.596Z,1630348044.596 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2021-08-30T18:27:24.749Z,1630348044.749 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2021-08-30T18:27:24.749Z,1630348044.749 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2021-08-30T18:27:24.979Z,1630348044.979 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2021-08-30T18:27:24.981Z,1630348044.981 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2021-08-30T18:27:24.982Z,1630348044.982 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg
2021-08-30T18:27:25.073Z,1630348045.073 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2021-08-30T18:27:25.158Z,1630348045.158 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2021-08-30T18:27:25.259Z,1630348045.259 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg
2021-08-30T18:27:25.342Z,1630348045.342 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2021-08-30T18:27:25.438Z,1630348045.438 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2021-08-30T18:27:25.541Z,1630348045.541 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2021-08-30T18:27:25.730Z,1630348045.730 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg
2021-08-30T18:27:25.806Z,1630348045.806 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2021-08-30T18:27:25.955Z,1630348045.955 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2021-08-30T18:27:26.093Z,1630348046.093 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2021-08-30T18:27:26.208Z,1630348046.208 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg
2021-08-30T18:27:26.470Z,1630348046.470 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2021-08-30T18:27:26.471Z,1630348046.471 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/root/
2021-08-30T18:27:26.471Z,1630348046.471 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2021-08-30T18:27:26.484Z,1630348046.484 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2021-08-30T18:27:26.556Z,1630348046.556 [VerticalControl](DEBUG): Construct VerticalControl.
2021-08-30T18:27:26.618Z,1630348046.618 [VerticalControl] Loaded
2021-08-30T18:27:26.618Z,1630348046.618 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2021-08-30T18:27:26.621Z,1630348046.621 [HorizontalControl](DEBUG): Construct HorizontalControl.
2021-08-30T18:27:26.660Z,1630348046.660 [HorizontalControl] Loaded
2021-08-30T18:27:26.660Z,1630348046.660 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2021-08-30T18:27:26.663Z,1630348046.663 [SpeedControl](DEBUG): Construct SpeedControl.
2021-08-30T18:27:26.666Z,1630348046.666 [SpeedControl] Loaded
2021-08-30T18:27:26.666Z,1630348046.666 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2021-08-30T18:27:26.669Z,1630348046.669 [LoopControl](DEBUG): Construct LoopControl.
2021-08-30T18:27:26.669Z,1630348046.669 [LoopControl] Loaded
2021-08-30T18:27:26.670Z,1630348046.670 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2021-08-30T18:27:26.670Z,1630348046.670 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2021-08-30T18:27:26.671Z,1630348046.671 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2021-08-30T18:27:26.687Z,1630348046.687 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2021-08-30T18:27:26.687Z,1630348046.687 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2021-08-30T18:27:26.822Z,1630348046.822 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2021-08-30T18:27:26.822Z,1630348046.822 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2021-08-30T18:27:26.980Z,1630348046.980 [BuoyancyServo] Loaded
2021-08-30T18:27:26.980Z,1630348046.980 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2021-08-30T18:27:26.999Z,1630348046.999 [ElevatorServo] Loaded
2021-08-30T18:27:26.000Z,1630348047.000 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2021-08-30T18:27:27.018Z,1630348047.018 [MassServo] Loaded
2021-08-30T18:27:27.018Z,1630348047.018 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2021-08-30T18:27:27.036Z,1630348047.036 [RudderServo] Loaded
2021-08-30T18:27:27.037Z,1630348047.037 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2021-08-30T18:27:27.054Z,1630348047.054 [ThrusterServo] Loaded
2021-08-30T18:27:27.055Z,1630348047.055 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2021-08-30T18:27:27.055Z,1630348047.055 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2021-08-30T18:27:27.056Z,1630348047.056 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2021-08-30T18:27:27.156Z,1630348047.156 [DeadReckonUsingMultipleVelocitySources] Loaded
2021-08-30T18:27:27.156Z,1630348047.156 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2021-08-30T18:27:27.169Z,1630348047.169 [NavChart] Loaded
2021-08-30T18:27:27.169Z,1630348047.169 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2021-08-30T18:27:27.175Z,1630348047.175 [UniversalFixResidualReporter] Loaded
2021-08-30T18:27:27.175Z,1630348047.175 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2021-08-30T18:27:27.176Z,1630348047.176 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2021-08-30T18:27:27.176Z,1630348047.176 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2021-08-30T18:27:27.258Z,1630348047.258 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2021-08-30T18:27:27.259Z,1630348047.259 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2021-08-30T18:27:27.759Z,1630348047.759 [AHRS_M2] Loaded
2021-08-30T18:27:27.759Z,1630348047.759 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2021-08-30T18:27:28.851Z,1630348048.851 [BPC1] Loaded
2021-08-30T18:27:28.851Z,1630348048.851 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2021-08-30T18:27:28.924Z,1630348048.924 [DataOverHttps] Loaded
2021-08-30T18:27:28.924Z,1630348048.924 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2021-08-30T18:27:28.925Z,1630348048.925 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 408894E0
2021-08-30T18:27:28.926Z,1630348048.926 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 4550
2021-08-30T18:27:28.946Z,1630348048.946 [Depth_Keller] Loaded
2021-08-30T18:27:28.946Z,1630348048.946 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2021-08-30T18:27:28.950Z,1630348048.950 [DropWeight] Loaded
2021-08-30T18:27:28.951Z,1630348048.951 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2021-08-30T18:27:29.072Z,1630348049.072 [NAL9602] Loaded
2021-08-30T18:27:29.072Z,1630348049.072 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2021-08-30T18:27:29.102Z,1630348049.102 [Onboard] Loaded
2021-08-30T18:27:29.102Z,1630348049.102 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2021-08-30T18:27:29.103Z,1630348049.103 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 408B94E0
2021-08-30T18:27:29.103Z,1630348049.103 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 4551
2021-08-30T18:27:29.116Z,1630348049.116 [Power24vConverter] Loaded
2021-08-30T18:27:29.116Z,1630348049.116 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2021-08-30T18:27:29.129Z,1630348049.129 [Radio_Surface] Loaded
2021-08-30T18:27:29.129Z,1630348049.129 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2021-08-30T18:27:29.131Z,1630348049.131 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408E94E0
2021-08-30T18:27:29.131Z,1630348049.131 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 4552
2021-08-30T18:27:29.132Z,1630348049.132 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2021-08-30T18:27:29.132Z,1630348049.132 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2021-08-30T18:27:29.193Z,1630348049.193 [DepthRateCalculator] Loaded
2021-08-30T18:27:29.193Z,1630348049.193 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2021-08-30T18:27:29.198Z,1630348049.198 [PitchRateCalculator] Loaded
2021-08-30T18:27:29.199Z,1630348049.199 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2021-08-30T18:27:29.208Z,1630348049.208 [SpeedCalculator] Loaded
2021-08-30T18:27:29.208Z,1630348049.208 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2021-08-30T18:27:29.222Z,1630348049.222 [TempGradientCalculator] Loaded
2021-08-30T18:27:29.222Z,1630348049.222 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2021-08-30T18:27:29.226Z,1630348049.226 [YawRateCalculator] Loaded
2021-08-30T18:27:29.227Z,1630348049.227 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2021-08-30T18:27:29.244Z,1630348049.244 [ElevatorOffsetCalculator] Loaded
2021-08-30T18:27:29.245Z,1630348049.245 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2021-08-30T18:27:29.245Z,1630348049.245 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2021-08-30T18:27:29.246Z,1630348049.246 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2021-08-30T18:27:29.435Z,1630348049.435 [CANONSampler] Loaded
2021-08-30T18:27:29.435Z,1630348049.435 [ComponentRegistry](DEBUG): SyncComponent "CANONSampler" handled in the control thread.
2021-08-30T18:27:29.494Z,1630348049.494 [CTD_Seabird] Loaded
2021-08-30T18:27:29.494Z,1630348049.494 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2021-08-30T18:27:29.495Z,1630348049.495 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 4099E4E0
2021-08-30T18:27:29.496Z,1630348049.496 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 4553
2021-08-30T18:27:29.516Z,1630348049.516 [PAR_Licor] Loaded
2021-08-30T18:27:29.516Z,1630348049.516 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2021-08-30T18:27:29.548Z,1630348049.548 [WetLabsBB2FL] Loaded
2021-08-30T18:27:29.548Z,1630348049.548 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2021-08-30T18:27:29.549Z,1630348049.549 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 409CE4E0
2021-08-30T18:27:29.549Z,1630348049.549 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 4554
2021-08-30T18:27:29.550Z,1630348049.550 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2021-08-30T18:27:29.551Z,1630348049.551 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2021-08-30T18:27:29.594Z,1630348049.594 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2021-08-30T18:27:29.595Z,1630348049.595 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2021-08-30T18:27:29.986Z,1630348049.986 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2021-08-30T18:27:29.987Z,1630348049.987 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2021-08-30T18:27:30.171Z,1630348050.171 [SBIT](DEBUG): Construct Startup Built In Test.
2021-08-30T18:27:30.181Z,1630348050.181 [SBIT] Loaded
2021-08-30T18:27:30.181Z,1630348050.181 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2021-08-30T18:27:30.184Z,1630348050.184 [IBIT](DEBUG): Construct Initiated Built In Test.
2021-08-30T18:27:30.197Z,1630348050.197 [IBIT] Loaded
2021-08-30T18:27:30.197Z,1630348050.197 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2021-08-30T18:27:30.203Z,1630348050.203 [CBIT](DEBUG): Construct Continuous Built In Test.
2021-08-30T18:27:30.304Z,1630348050.304 [CBIT] Loaded
2021-08-30T18:27:30.304Z,1630348050.304 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2021-08-30T18:27:30.304Z,1630348050.304 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2021-08-30T18:27:30.305Z,1630348050.305 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2021-08-30T18:27:30.429Z,1630348050.429 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2021-08-30T18:27:30.435Z,1630348050.435 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2021-08-30T18:27:30.438Z,1630348050.438 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2021-08-30T18:27:30.450Z,1630348050.450 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2021-08-30T18:27:30.451Z,1630348050.451 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B024E0
2021-08-30T18:27:30.451Z,1630348050.451 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 4555
2021-08-30T18:27:30.456Z,1630348050.456 [Supervisor](INFO): Main Thread ID is 4460
2021-08-30T18:27:30.456Z,1630348050.456 [Supervisor](DEBUG): Running supervisor.
2021-08-30T18:27:30.457Z,1630348050.457 [CommandLine ThreadHandler](INFO): Handler Thread ID is 4556
2021-08-30T18:27:30.460Z,1630348050.460 [controlThread ThreadHandler](INFO): Handler Thread ID is 4557
2021-08-30T18:27:30.460Z,1630348050.460 [controlThread](DEBUG): Initializing ControlThread
2021-08-30T18:27:30.461Z,1630348050.461 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2021-08-30T18:27:30.463Z,1630348050.463 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2021-08-30T18:27:30.464Z,1630348050.464 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2021-08-30T18:27:30.464Z,1630348050.464 [LoopControl](DEBUG): Initialize LoopControlComponent.
2021-08-30T18:27:30.466Z,1630348050.466 [NavChart](DEBUG): Initialize NavChart Navigation.
2021-08-30T18:27:30.467Z,1630348050.467 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2021-08-30T18:27:30.472Z,1630348050.472 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2021-08-30T18:27:30.472Z,1630348050.472 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2021-08-30T18:27:30.472Z,1630348050.472 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2021-08-30T18:27:30.473Z,1630348050.473 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2021-08-30T18:27:30.473Z,1630348050.473 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2021-08-30T18:27:30.474Z,1630348050.474 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2021-08-30T18:27:30.478Z,1630348050.478 [SBIT](INFO): Initialize SBIT Component.
2021-08-30T18:27:30.479Z,1630348050.479 [SBIT](IMPORTANT): git: 2021-08-30
2021-08-30T18:27:30.479Z,1630348050.479 [SBIT](INFO): git hash: b14b86a971cb12811ac9295595a9f4c3c356b790
2021-08-30T18:27:30.479Z,1630348050.479 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2021-08-30T18:27:30.481Z,1630348050.481 [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
2021-08-30T18:27:30.482Z,1630348050.482 [SBIT](INFO): Beginning SBIT in 90.000000 seconds.
2021-08-30T18:27:30.482Z,1630348050.482 [IBIT](INFO): Initialize IBIT Component.
2021-08-30T18:27:30.483Z,1630348050.483 [CBIT](DEBUG): Initialize CBIT Component.
2021-08-30T18:27:30.484Z,1630348050.484 [logger ThreadHandler](INFO): Handler Thread ID is 4558
2021-08-30T18:27:30.498Z,1630348050.498 [CBIT](DEBUG): Initialized mux pins.
2021-08-30T18:27:30.498Z,1630348050.498 [CBIT](DEBUG): Initializing the watchdog timer.
2021-08-30T18:27:30.502Z,1630348050.502 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 4559
2021-08-30T18:27:30.503Z,1630348050.503 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2021-08-30T18:27:30.510Z,1630348050.510 [Onboard ThreadHandler](INFO): Handler Thread ID is 4560
2021-08-30T18:27:30.522Z,1630348050.522 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2021-08-30T18:27:30.522Z,1630348050.522 [CBIT](DEBUG): Initializing heartbeat.
2021-08-30T18:27:30.528Z,1630348050.528 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 4561
2021-08-30T18:27:30.546Z,1630348050.546 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 4562
2021-08-30T18:27:30.547Z,1630348050.547 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2021-08-30T18:27:30.551Z,1630348050.551 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 4564
2021-08-30T18:27:30.554Z,1630348050.554 [WetLabsBB2FL](INFO): Powering up
2021-08-30T18:27:30.556Z,1630348050.556 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 4566
2021-08-30T18:27:30.560Z,1630348050.560 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2021-08-30T18:27:30.560Z,1630348050.560 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2021-08-30T18:27:30.560Z,1630348050.560 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2021-08-30T18:27:30.560Z,1630348050.560 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2021-08-30T18:27:30.561Z,1630348050.561 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2021-08-30T18:27:30.561Z,1630348050.561 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2021-08-30T18:27:30.561Z,1630348050.561 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2021-08-30T18:27:30.561Z,1630348050.561 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2021-08-30T18:27:30.561Z,1630348050.561 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2021-08-30T18:27:30.562Z,1630348050.562 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2021-08-30T18:27:30.562Z,1630348050.562 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2021-08-30T18:27:30.563Z,1630348050.563 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2021-08-30T18:27:30.563Z,1630348050.563 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2021-08-30T18:27:30.563Z,1630348050.563 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2021-08-30T18:27:30.563Z,1630348050.563 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2021-08-30T18:27:30.563Z,1630348050.563 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2021-08-30T18:27:30.594Z,1630348050.594 [CBIT](DEBUG): Deactivating GF circuits.
2021-08-30T18:27:30.594Z,1630348050.594 [CBIT](DEBUG): Deactivating emergency mode.
2021-08-30T18:27:30.630Z,1630348050.630 [CBIT](DEBUG): Backplane powered.
2021-08-30T18:27:30.631Z,1630348050.631 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2021-08-30T18:27:30.647Z,1630348050.647 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2021-08-30T18:27:30.675Z,1630348050.675 [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>


2021-08-30T18:27:30.676Z,1630348050.676 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2021-08-30T18:27:30.752Z,1630348050.752 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2021-08-30T18:27:30.753Z,1630348050.753 [Default:A.Wait](DEBUG): Construct Wait.
2021-08-30T18:27:30.776Z,1630348050.776 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2021-08-30T18:27:30.796Z,1630348050.796 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2021-08-30T18:27:30.827Z,1630348050.827 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2021-08-30T18:27:30.833Z,1630348050.833 [Default:E.Execute](DEBUG): Construct Execute.
2021-08-30T18:27:30.852Z,1630348050.852 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Universal="Tethys/Universal"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                             Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                             Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
         Id="Default">

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

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

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

    <Aggregate Id="CheckIn">

        <Sequence Repeat="288"/>

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

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

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

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

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

    </Aggregate>

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

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

</Mission>


2021-08-30T18:27:30.857Z,1630348050.857 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,Power24vConverter,CANONSampler,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2021-08-30T18:27:30.870Z,1630348050.870 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2021-08-30T18:27:30.934Z,1630348050.934 [Radio_Surface](INFO): Powering up
2021-08-30T18:27:30.948Z,1630348050.948 [Power24vConverter](INFO): Powering up.
2021-08-30T18:27:30.949Z,1630348050.949 [CANONSampler](INFO): Powering down
2021-08-30T18:27:30.988Z,1630348050.988 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2021-08-30T18:27:30.994Z,1630348050.994 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2021-08-30T18:27:30.995Z,1630348050.995 [ElevatorServo](DEBUG): Initializing EZServoServo.
2021-08-30T18:27:31.002Z,1630348051.002 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2021-08-30T18:27:31.003Z,1630348051.003 [MassServo](DEBUG): Initializing EZServoServo.
2021-08-30T18:27:31.010Z,1630348051.010 [MassServo](DEBUG): Initializing MassServo.
2021-08-30T18:27:31.011Z,1630348051.011 [RudderServo](DEBUG): Initializing EZServoServo.
2021-08-30T18:27:31.018Z,1630348051.018 [RudderServo](DEBUG): Initializing RudderServo.
2021-08-30T18:27:31.019Z,1630348051.019 [ThrusterServo](DEBUG): Initializing EZServoServo.
2021-08-30T18:27:31.026Z,1630348051.026 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2021-08-30T18:27:32.006Z,1630348052.006 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2021-08-30T18:27:32.006Z,1630348052.006 [RudderServo](FAULT): Rudder failed to initialize
2021-08-30T18:27:32.006Z,1630348052.006 [RudderServo] Communications Fault, FailCount= 1
2021-08-30T18:27:32.006Z,1630348052.006 [RudderServo](ERROR): Communications Fault
2021-08-30T18:27:32.109Z,1630348052.109 [CBIT](ERROR): Communications Fault in component: RudderServo
2021-08-30T18:27:32.255Z,1630348052.255 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2021-08-30T18:27:32.255Z,1630348052.255 [RudderServo](INFO): Powering down
2021-08-30T18:27:32.662Z,1630348052.662 [WetLabsBB2FL](INFO): Powering down
2021-08-30T18:27:32.995Z,1630348052.995 [RudderServo](DEBUG): Initializing EZServoServo.
2021-08-30T18:27:33.115Z,1630348053.115 [RudderServo](DEBUG): Initializing RudderServo.
2021-08-30T18:27:33.119Z,1630348053.119 [CBIT](INFO): Clearing failed state for component RudderServo
2021-08-30T18:27:33.119Z,1630348053.119 [RudderServo] No Fault, FailCount= 1
2021-08-30T18:27:37.606Z,1630348057.606 [CTD_Seabird](ERROR): Device message queue exceeded the allowed limit.
2021-08-30T18:27:43.328Z,1630348063.328 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004654
2021-08-30T18:27:59.196Z,1630348079.196 [NAL9602](INFO): Powering up NAL9602
2021-08-30T18:28:10.100Z,1630348090.100 [NAL9602](INFO): NAL9602 initialized
2021-08-30T18:28:44.632Z,1630348124.632 [CommandLine](IMPORTANT): got command show variable stopDepth
2021-08-30T18:28:44.718Z,1630348124.718 [CommandLine](IMPORTANT): VerticalControl.stopDepthExcursion (meter)
2021-08-30T18:28:44.727Z,1630348124.727 [CommandLine](IMPORTANT): CBIT.stopDepth (meter)
2021-08-30T18:28:48.046Z,1630348128.046 [CommandLine](IMPORTANT): got command get CBIT.stopDepth
2021-08-30T18:28:48.047Z,1630348128.047 [CommandLine](IMPORTANT): CBIT.stopDepth 205.000000 m
2021-08-30T18:28:53.479Z,1630348133.479 [CommandLine](IMPORTANT): got command get CBIT.abortDepth
2021-08-30T18:28:53.480Z,1630348133.480 [CommandLine](IMPORTANT): CBIT.abortDepth 250.000000 m
2021-08-30T18:29:01.039Z,1630348141.039 [SBIT](IMPORTANT): Beginning Startup BIT
2021-08-30T18:29:01.047Z,1630348141.047 [CBIT](IMPORTANT): Beginning ground fault scan
2021-08-30T18:29:11.940Z,1630348151.940 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.013977
CHAN A1 (24V): -0.180908
CHAN A2 (12V): -0.002151
CHAN A3 (5V): -0.001219
CHAN B0 (3.3V): 4.766929
CHAN B1 (3.15aV): -0.000105
CHAN B2 (3.15bV): 0.000031
CHAN B3 (GND): 0.000426
OPEN: -0.000383
Full Scale Calc: 4.765 mA, -1.589 mA
2021-08-30T18:29:54.471Z,1630348194.471 [CommandLine](IMPORTANT): got command gfscan
2021-08-30T18:29:54.839Z,1630348194.839 [SBIT](IMPORTANT): SBIT PASSED
2021-08-30T18:29:54.839Z,1630348194.839 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2021-08-30T18:29:54.840Z,1630348194.840 [SBIT](IMPORTANT): AMEcho.loadAtStartup=0 bool;

2021-08-30T18:29:54.840Z,1630348194.840 [SBIT](IMPORTANT): BuoyancyServo.fastPumpDepth=6 meter;

2021-08-30T18:29:54.840Z,1630348194.840 [SBIT](IMPORTANT): CANONSampler.loadAtStartup=1 bool;

2021-08-30T18:29:54.841Z,1630348194.841 [SBIT](IMPORTANT): DAT.loadAtStartup=0 bool;

2021-08-30T18:29:54.841Z,1630348194.841 [SBIT](IMPORTANT): DAT.verbosity=3 count;

2021-08-30T18:29:54.841Z,1630348194.841 [SBIT](IMPORTANT): ESPComponent.loadAtStartup=0 bool;

2021-08-30T18:29:54.841Z,1630348194.841 [SBIT](IMPORTANT): ESPComponent.simulateHardware=1 bool;

2021-08-30T18:29:54.841Z,1630348194.841 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=310.836325 cubic_centimeter;

2021-08-30T18:29:54.841Z,1630348194.841 [SBIT](IMPORTANT): VerticalControl.kdDepthBuoy=1000 second;

2021-08-30T18:29:54.841Z,1630348194.841 [SBIT](IMPORTANT): VerticalControl.kiDepthBuoy=0.15 reciprocal_second;

2021-08-30T18:29:54.841Z,1630348194.841 [SBIT](IMPORTANT): VerticalControl.kiDepthOff=0.01 meter_per_second;

2021-08-30T18:29:54.842Z,1630348194.842 [SBIT](IMPORTANT): VerticalControl.kpDepthBuoy=120 ratio;

2021-08-30T18:29:54.842Z,1630348194.842 [SBIT](IMPORTANT): VerticalControl.massDefault=-17.611304 millimeter;

2021-08-30T18:29:54.846Z,1630348194.846 [CBIT](IMPORTANT): Beginning ground fault scan
2021-08-30T18:29:55.158Z,1630348195.158 [MissionManager](IMPORTANT): Started mission Startup
2021-08-30T18:29:55.159Z,1630348195.159 [Startup] Running Loop=1
2021-08-30T18:29:55.159Z,1630348195.159 [Startup](DEBUG): Aggregate::initialize Startup
2021-08-30T18:29:55.159Z,1630348195.159 [Startup:A.GoToSurface] Running Loop=1
2021-08-30T18:29:55.159Z,1630348195.159 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2021-08-30T18:29:55.160Z,1630348195.160 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2021-08-30T18:29:55.160Z,1630348195.160 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2021-08-30T18:29:55.160Z,1630348195.160 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2021-08-30T18:29:55.161Z,1630348195.161 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2021-08-30T18:29:55.161Z,1630348195.161 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2021-08-30T18:29:55.164Z,1630348195.164 [Startup:StartupSatComms] Running Loop=1
2021-08-30T18:29:55.164Z,1630348195.164 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2021-08-30T18:29:55.164Z,1630348195.164 [Startup:StartupSatComms:A] Running Loop=1
2021-08-30T18:29:55.565Z,1630348195.565 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2021-08-30T18:30:05.805Z,1630348205.805 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.013998
CHAN A1 (24V): 4.610929
CHAN A2 (12V): -0.002230
CHAN A3 (5V): -0.001194
CHAN B0 (3.3V): 0.000048
CHAN B1 (3.15aV): -0.000335
CHAN B2 (3.15bV): -0.000019
CHAN B3 (GND): -0.000132
OPEN: -0.000703
Full Scale Calc: 4.765 mA, -1.589 mA
2021-08-30T18:30:12.328Z,1630348212.328 [CommandLine](IMPORTANT): got command gfscan
2021-08-30T18:30:12.660Z,1630348212.660 [CBIT](IMPORTANT): Beginning ground fault scan
2021-08-30T18:30:23.536Z,1630348223.536 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.013842
CHAN A1 (24V): -0.180452
CHAN A2 (12V): -0.001989
CHAN A3 (5V): -0.001101
CHAN B0 (3.3V): -0.000333
CHAN B1 (3.15aV): -0.000310
CHAN B2 (3.15bV): 0.000161
CHAN B3 (GND): 4.792929
OPEN: -0.000324
Full Scale Calc: 4.765 mA, -1.589 mA
2021-08-30T18:30:30.724Z,1630348230.724 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2021-08-30T18:30:30.724Z,1630348230.724 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-08-30T18:30:30.806Z,1630348230.806 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-08-30T18:30:31.178Z,1630348231.178 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-08-30T18:30:31.178Z,1630348231.178 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2021-08-30T18:30:55.539Z,1630348255.539 [Startup:StartupSatComms:A](INFO): Timed out from 2021-08-30T18:29:55.2Z
2021-08-30T18:30:55.539Z,1630348255.539 [Startup:StartupSatComms:A] Stopped
2021-08-30T18:30:55.539Z,1630348255.539 [Startup:StartupSatComms:B] Running Loop=1
2021-08-30T18:30:55.940Z,1630348255.940 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2021-08-30T18:31:01.673Z,1630348261.673 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20210830T182720/Courier0000.lzma
2021-08-30T18:31:02.668Z,1630348262.668 [DataOverHttps](INFO): Moved sent file to Logs/20210830T182720/Courier0000.lzma.bak
2021-08-30T18:31:02.668Z,1630348262.668 [DataOverHttps](INFO): SBD MOMSN=15902740
2021-08-30T18:31:18.141Z,1630348278.141 [DataOverHttps](INFO): Sending 1140 bytes from file Logs/20210830T182720/Express0001.lzma
2021-08-30T18:31:19.136Z,1630348279.136 [DataOverHttps](INFO): Moved sent file to Logs/20210830T182720/Express0001.lzma.bak
2021-08-30T18:31:19.136Z,1630348279.136 [DataOverHttps](INFO): SBD MOMSN=15902743
2021-08-30T18:31:20.206Z,1630348280.206 [Startup:StartupSatComms:B] Stopped
2021-08-30T18:31:20.206Z,1630348280.206 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2021-08-30T18:31:20.206Z,1630348280.206 [Startup:StartupSatComms] Stopped
2021-08-30T18:31:20.206Z,1630348280.206 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2021-08-30T18:31:20.207Z,1630348280.207 [Startup](INFO): Completed Startup
2021-08-30T18:31:20.207Z,1630348280.207 [MissionManager](INFO): Startup is completed.
2021-08-30T18:31:20.208Z,1630348280.208 [MissionManager](INFO): Uninitializing Mission Startup
2021-08-30T18:31:20.208Z,1630348280.208 [Startup] Stopped
2021-08-30T18:31:20.208Z,1630348280.208 [Startup](DEBUG): Aggregate::uninitialize Startup
2021-08-30T18:31:20.208Z,1630348280.208 [Startup:A.GoToSurface] Stopped
2021-08-30T18:31:20.208Z,1630348280.208 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2021-08-30T18:31:20.589Z,1630348280.589 [MissionManager](IMPORTANT): Started mission Default
2021-08-30T18:31:20.589Z,1630348280.589 [Default] Running Loop=1
2021-08-30T18:31:20.589Z,1630348280.589 [Default](DEBUG): Aggregate::initialize Default
2021-08-30T18:31:20.589Z,1630348280.589 [Default:B.GoToSurface] Running Loop=1
2021-08-30T18:31:20.589Z,1630348280.589 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2021-08-30T18:31:20.589Z,1630348280.589 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2021-08-30T18:31:20.590Z,1630348280.590 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2021-08-30T18:31:20.590Z,1630348280.590 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2021-08-30T18:31:20.591Z,1630348280.591 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2021-08-30T18:31:20.591Z,1630348280.591 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2021-08-30T18:31:20.591Z,1630348280.591 [Default:A.Wait] Running Loop=1
2021-08-30T18:31:20.591Z,1630348280.591 [Default:A.Wait](DEBUG): Initialize Wait Component.
2021-08-30T18:31:22.088Z,1630348282.088 [CommandLine](IMPORTANT): got command gfscan
2021-08-30T18:31:22.243Z,1630348282.243 [CBIT](IMPORTANT): Beginning ground fault scan
2021-08-30T18:31:33.133Z,1630348293.133 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.015201
CHAN A1 (24V): -0.180847
CHAN A2 (12V): -0.001965
CHAN A3 (5V): -0.001079
CHAN B0 (3.3V): -0.000024
CHAN B1 (3.15aV): -0.000248
CHAN B2 (3.15bV): -0.000214
CHAN B3 (GND): -0.000074
OPEN: -0.000120
Full Scale Calc: 4.765 mA, -1.589 mA
2021-08-30T18:31:33.916Z,1630348293.916 [Default:A.Wait](INFO): Done Waiting.
2021-08-30T18:31:33.916Z,1630348293.916 [Default:A.Wait] Stopped
2021-08-30T18:31:33.916Z,1630348293.916 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2021-08-30T18:31:34.320Z,1630348294.320 [Default:CheckIn] Running Loop=1
2021-08-30T18:31:34.320Z,1630348294.320 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-08-30T18:31:34.320Z,1630348294.320 [Default:CheckIn:Read_GPS] Running Loop=1
2021-08-30T18:31:34.745Z,1630348294.745 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2021-08-30T18:31:42.351Z,1630348302.351 [CommandLine](IMPORTANT): got command show variable sampler
2021-08-30T18:31:42.460Z,1630348302.460 [CommandLine](IMPORTANT): CANONSampler.loadControl (none)
2021-08-30T18:31:42.461Z,1630348302.461 [CommandLine](IMPORTANT): CANONSampler.uart (none)
2021-08-30T18:31:42.461Z,1630348302.461 [CommandLine](IMPORTANT): CANONSampler.baud (bit_per_second)
2021-08-30T18:31:42.508Z,1630348302.508 [CommandLine](IMPORTANT): CANONSampler.loadAtStartup (bool)
2021-08-30T18:31:42.509Z,1630348302.509 [CommandLine](IMPORTANT): CANONSampler.simulateHardware (bool)
2021-08-30T18:31:42.509Z,1630348302.509 [CommandLine](IMPORTANT): CANONSampler.rotateOnly (bool)
2021-08-30T18:31:42.510Z,1630348302.510 [CommandLine](IMPORTANT): CANONSampler.sampleTimeout (minute)
2021-08-30T18:31:42.566Z,1630348302.566 [CommandLine](IMPORTANT): CANONSampler.enableBroadcast (bool)
2021-08-30T18:31:42.567Z,1630348302.567 [CommandLine](IMPORTANT): CANONSampler.component_voltage (volt)
2021-08-30T18:31:42.567Z,1630348302.567 [CommandLine](IMPORTANT): CANONSampler.component_avgVoltage (volt)
2021-08-30T18:31:42.568Z,1630348302.568 [CommandLine](IMPORTANT): CANONSampler.component_current (milliampere)
2021-08-30T18:31:42.568Z,1630348302.568 [CommandLine](IMPORTANT): CANONSampler.component_avgCurrent (milliampere)
2021-08-30T18:31:42.568Z,1630348302.568 [CommandLine](IMPORTANT): CANONSampler.sampling (bool)
2021-08-30T18:31:42.569Z,1630348302.569 [CommandLine](IMPORTANT): CANONSampler.sample_number (count)
2021-08-30T18:31:49.448Z,1630348309.448 [CommandLine](IMPORTANT): got command get CANONSampler.loadControl
2021-08-30T18:31:49.449Z,1630348309.449 [CommandLine](IMPORTANT): CANONSampler.loadControl /dev/loadB1
2021-08-30T18:31:54.615Z,1630348314.615 [CommandLine](IMPORTANT): got command get CANONSampler.loadAtStartup
2021-08-30T18:31:54.615Z,1630348314.615 [CommandLine](IMPORTANT): CANONSampler.loadAtStartup 1 bool
2021-08-30T18:32:06.279Z,1630348326.279 [CommandLine](IMPORTANT): got command ! echo i > /dev/loadB1
2021-08-30T18:32:08.190Z,1630348328.190 [CommandLine](IMPORTANT): got command gfscan
2021-08-30T18:32:08.267Z,1630348328.267 [CBIT](IMPORTANT): Beginning ground fault scan
2021-08-30T18:32:19.178Z,1630348339.178 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.014469
CHAN A1 (24V): -0.180591
CHAN A2 (12V): -0.002103
CHAN A3 (5V): -0.001703
CHAN B0 (3.3V): 0.000126
CHAN B1 (3.15aV): -0.000058
CHAN B2 (3.15bV): 0.000077
CHAN B3 (GND): 0.000003
OPEN: 0.000048
Full Scale Calc: 4.765 mA, -1.589 mA
2021-08-30T18:32:25.327Z,1630348345.327 [CommandLine](IMPORTANT): got command show variable dvl
2021-08-30T18:32:25.343Z,1630348345.343 [CommandLine](IMPORTANT): DeadReckonUsingDVLWaterTrack.loadAtStartup (bool)
2021-08-30T18:32:25.343Z,1630348345.343 [CommandLine](IMPORTANT): DeadReckonUsingDVLWaterTrack.accuracyPremultiplier (none)
2021-08-30T18:32:25.344Z,1630348345.344 [CommandLine](IMPORTANT): DeadReckonUsingDVLWaterTrack.allowableFailures (count)
2021-08-30T18:32:25.344Z,1630348345.344 [CommandLine](IMPORTANT): DeadReckonUsingDVLWaterTrack.orientationStaleAfter (minute)
2021-08-30T18:32:25.345Z,1630348345.345 [CommandLine](IMPORTANT): DeadReckonUsingDVLWaterTrack.velocityStaleAfter (second)
2021-08-30T18:32:25.345Z,1630348345.345 [CommandLine](IMPORTANT): DeadReckonUsingDVLWaterTrack.verbosity (count)
2021-08-30T18:32:25.415Z,1630348345.415 [CommandLine](IMPORTANT): DVL_micro.loadControl (none)
2021-08-30T18:32:25.415Z,1630348345.415 [CommandLine](IMPORTANT): DVL_micro.uart (none)
2021-08-30T18:32:25.416Z,1630348345.416 [CommandLine](IMPORTANT): DVL_micro.baud (bit_per_second)
2021-08-30T18:32:25.449Z,1630348345.449 [CommandLine](IMPORTANT): DVL_micro.loadAtStartup (bool)
2021-08-30T18:32:25.450Z,1630348345.450 [CommandLine](IMPORTANT): DVL_micro.simulateHardware (bool)
2021-08-30T18:32:25.450Z,1630348345.450 [CommandLine](IMPORTANT): DVL_micro.magDeviation (degree)
2021-08-30T18:32:25.450Z,1630348345.450 [CommandLine](IMPORTANT): DVL_micro.pitchOffset (degree)
2021-08-30T18:32:25.451Z,1630348345.451 [CommandLine](IMPORTANT): DVL_micro.power (watt)
2021-08-30T18:32:25.451Z,1630348345.451 [CommandLine](IMPORTANT): DVL_micro.rollOffset (degree)
2021-08-30T18:33:13.696Z,1630348393.696 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2021-08-30T18:33:31.883Z,1630348411.883 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2021-08-30T18:33:31.883Z,1630348411.883 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-08-30T18:33:31.894Z,1630348411.894 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-08-30T18:33:32.361Z,1630348412.361 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-08-30T18:33:32.361Z,1630348412.361 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2021-08-30T18:34:38.411Z,1630348478.411 [CommandLine](IMPORTANT): got command show variable altimeter
2021-08-30T18:34:42.213Z,1630348482.213 [CommandLine](IMPORTANT): got command show variable echo
2021-08-30T18:34:42.288Z,1630348482.288 [CommandLine](IMPORTANT): AMEcho.loadControl (none)
2021-08-30T18:34:42.288Z,1630348482.288 [CommandLine](IMPORTANT): AMEcho.uart (none)
2021-08-30T18:34:42.289Z,1630348482.289 [CommandLine](IMPORTANT): AMEcho.baud (bit_per_second)
2021-08-30T18:34:42.297Z,1630348482.297 [CommandLine](IMPORTANT): AMEcho.loadAtStartup (bool)
2021-08-30T18:34:42.298Z,1630348482.298 [CommandLine](IMPORTANT): AMEcho.simulateHardware (bool)
2021-08-30T18:34:42.298Z,1630348482.298 [CommandLine](IMPORTANT): AMEcho.enabled (bool)
2021-08-30T18:34:42.299Z,1630348482.299 [CommandLine](IMPORTANT): AMEcho.depthThreshold (meter)
2021-08-30T18:34:49.891Z,1630348489.891 [CommandLine](IMPORTANT): got command get AMEcho.loadControl
2021-08-30T18:34:49.891Z,1630348489.891 [CommandLine](IMPORTANT): AMEcho.loadControl /dev/loadB4
2021-08-30T18:34:51.867Z,1630348491.867 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2021-08-30T18:34:51.871Z,1630348491.871 [BPC1](INFO): Received data from all battery sticks.
2021-08-30T18:34:56.976Z,1630348496.976 [CommandLine](IMPORTANT): got command get AMEcho.loadAtStartup
2021-08-30T18:34:56.977Z,1630348496.977 [CommandLine](IMPORTANT): AMEcho.loadAtStartup 0 bool
2021-08-30T18:35:08.332Z,1630348508.332 [CommandLine](IMPORTANT): got command ! echo i > /dev/loadB2
2021-08-30T18:35:12.762Z,1630348512.762 [CommandLine](IMPORTANT): got command gfscan
2021-08-30T18:35:12.915Z,1630348512.915 [CBIT](IMPORTANT): Beginning ground fault scan
2021-08-30T18:35:23.806Z,1630348523.806 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.014974
CHAN A1 (24V): -0.180650
CHAN A2 (12V): -0.002027
CHAN A3 (5V): -0.001662
CHAN B0 (3.3V): 0.000261
CHAN B1 (3.15aV): -0.000278
CHAN B2 (3.15bV): -0.000266
CHAN B3 (GND): -0.000227
OPEN: -0.000559
Full Scale Calc: 4.765 mA, -1.589 mA
2021-08-30T18:35:35.692Z,1630348535.692 [CommandLine](IMPORTANT): got command get AMEcho.loadControl
2021-08-30T18:35:35.692Z,1630348535.692 [CommandLine](IMPORTANT): AMEcho.loadControl /dev/loadB4
2021-08-30T18:35:42.844Z,1630348542.844 [CommandLine](IMPORTANT): got command ! echo i > /dev/loadB4
2021-08-30T18:35:44.188Z,1630348544.188 [CommandLine](IMPORTANT): got command gfscan
2021-08-30T18:35:44.465Z,1630348544.465 [CBIT](IMPORTANT): Beginning ground fault scan
2021-08-30T18:35:55.382Z,1630348555.382 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.015127
CHAN A1 (24V): -0.180321
CHAN A2 (12V): -0.002024
CHAN A3 (5V): -0.001215
CHAN B0 (3.3V): 0.000131
CHAN B1 (3.15aV): -0.000184
CHAN B2 (3.15bV): -0.000176
CHAN B3 (GND): -0.000245
OPEN: -0.000571
Full Scale Calc: 4.765 mA, -1.589 mA
2021-08-30T18:36:32.924Z,1630348592.924 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2021-08-30T18:36:32.924Z,1630348592.924 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-08-30T18:36:32.962Z,1630348592.962 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-08-30T18:36:33.330Z,1630348593.330 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-08-30T18:36:33.330Z,1630348593.330 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2021-08-30T18:36:34.530Z,1630348594.530 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-08-30T18:31:34.3Z
2021-08-30T18:36:34.530Z,1630348594.530 [Default:CheckIn:Read_GPS] Stopped
2021-08-30T18:36:34.530Z,1630348594.530 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-08-30T18:36:34.948Z,1630348594.948 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2021-08-30T18:36:41.697Z,1630348601.697 [DataOverHttps](INFO): Sending 169 bytes from file Logs/20210830T182720/Courier0004.lzma
2021-08-30T18:36:42.700Z,1630348602.700 [DataOverHttps](INFO): Moved sent file to Logs/20210830T182720/Courier0004.lzma.bak
2021-08-30T18:36:42.700Z,1630348602.700 [DataOverHttps](INFO): SBD MOMSN=15902781
2021-08-30T18:36:58.095Z,1630348618.095 [DataOverHttps](INFO): Sending 1218 bytes from file Logs/20210830T182720/Express0005.lzma
2021-08-30T18:36:59.096Z,1630348619.096 [DataOverHttps](INFO): Moved sent file to Logs/20210830T182720/Express0005.lzma.bak
2021-08-30T18:36:59.096Z,1630348619.096 [DataOverHttps](INFO): SBD MOMSN=15902783
2021-08-30T18:37:00.376Z,1630348620.376 [Default:CheckIn:Read_Iridium] Stopped
2021-08-30T18:37:00.376Z,1630348620.376 [Default:CheckIn:C.Wait] Running Loop=1
2021-08-30T18:37:00.376Z,1630348620.376 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-08-30T18:37:31.880Z,1630348651.880 [Power24vConverter](INFO): Powering down.
2021-08-30T18:38:04.507Z,1630348684.507 [CommandLine](IMPORTANT): got command gfscan
2021-08-30T18:38:04.674Z,1630348684.674 [CBIT](IMPORTANT): Beginning ground fault scan
2021-08-30T18:38:11.077Z,1630348691.077 [NAL9602](FAULT): GPS failed to acquire within timeout.
2021-08-30T18:38:11.077Z,1630348691.077 [NAL9602] Data Fault, FailCount= 1
2021-08-30T18:38:11.077Z,1630348691.077 [NAL9602](ERROR): Data Fault
2021-08-30T18:38:11.132Z,1630348691.132 [CBIT](ERROR): Data Fault in component: NAL9602
2021-08-30T18:38:11.467Z,1630348691.467 [NAL9602](INFO): Powering down
2021-08-30T18:38:12.306Z,1630348692.306 [CBIT](INFO): Clearing failed state for component NAL9602
2021-08-30T18:38:12.306Z,1630348692.306 [NAL9602] No Fault, FailCount= 1
2021-08-30T18:38:15.536Z,1630348695.536 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.015234
CHAN A1 (24V): -0.180797
CHAN A2 (12V): -0.002429
CHAN A3 (5V): -0.001601
CHAN B0 (3.3V): 0.000205
CHAN B1 (3.15aV): -0.000202
CHAN B2 (3.15bV): -0.000219
CHAN B3 (GND): -0.000198
OPEN: -0.000444
Full Scale Calc: 4.765 mA, -1.589 mA
2021-08-30T18:38:41.767Z,1630348721.767 [NAL9602](INFO): Powering up NAL9602
2021-08-30T18:38:52.683Z,1630348732.683 [NAL9602](INFO): NAL9602 initialized
2021-08-30T18:39:33.927Z,1630348773.927 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2021-08-30T18:39:33.927Z,1630348773.927 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-08-30T18:39:33.970Z,1630348773.970 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-08-30T18:39:34.333Z,1630348774.333 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-08-30T18:39:34.333Z,1630348774.333 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2021-08-30T18:39:58.093Z,1630348798.093 [CommandLine](IMPORTANT): got command ! echo i > /dev/loadA7
2021-08-30T18:39:59.832Z,1630348799.832 [CommandLine](IMPORTANT): got command ! echo i > /dev/loadA6
2021-08-30T18:40:05.315Z,1630348805.315 [CommandLine](IMPORTANT): got command gfscan
2021-08-30T18:40:05.478Z,1630348805.478 [CBIT](IMPORTANT): Beginning ground fault scan
2021-08-30T18:40:16.353Z,1630348816.353 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.014466
CHAN A1 (24V): -0.180697
CHAN A2 (12V): -0.002427
CHAN A3 (5V): -0.001627
CHAN B0 (3.3V): -0.000131
CHAN B1 (3.15aV): -0.000302
CHAN B2 (3.15bV): -0.000242
CHAN B3 (GND): -0.000341
OPEN: -0.000371
Full Scale Calc: 4.765 mA, -1.589 mA
2021-08-30T18:40:24.055Z,1630348824.055 [CommandLine](IMPORTANT): got command ! echo i > /dev/loadC6
2021-08-30T18:40:28.004Z,1630348828.004 [CommandLine](IMPORTANT): got command ! echo i > /dev/loadC5
2021-08-30T18:40:29.684Z,1630348829.684 [CommandLine](IMPORTANT): got command ! echo i > /dev/loadC4
2021-08-30T18:40:31.035Z,1630348831.035 [CommandLine](IMPORTANT): got command ! echo i > /dev/loadC3
2021-08-30T18:40:37.620Z,1630348837.620 [CommandLine](IMPORTANT): got command ! echo i > /dev/loadC2
2021-08-30T18:40:40.238Z,1630348840.238 [CommandLine](IMPORTANT): got command ! echo i > /dev/loadC1
2021-08-30T18:40:44.523Z,1630348844.523 [CommandLine](IMPORTANT): got command gfscan
2021-08-30T18:40:44.693Z,1630348844.693 [CBIT](IMPORTANT): Beginning ground fault scan
2021-08-30T18:40:55.577Z,1630348855.577 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.014545
CHAN A1 (24V): -0.180408
CHAN A2 (12V): -0.002088
CHAN A3 (5V): -0.001019
CHAN B0 (3.3V): -0.000452
CHAN B1 (3.15aV): 0.000202
CHAN B2 (3.15bV): -0.000081
CHAN B3 (GND): 0.000180
OPEN: -0.000651
Full Scale Calc: 4.765 mA, -1.589 mA
2021-08-30T18:41:03.971Z,1630348863.971 [CommandLine](IMPORTANT): got command ! echo i > /dev/loadB3
2021-08-30T18:41:05.786Z,1630348865.786 [CommandLine](IMPORTANT): got command gfscan
2021-08-30T18:41:06.110Z,1630348866.110 [CBIT](IMPORTANT): Beginning ground fault scan
2021-08-30T18:41:17.015Z,1630348877.015 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.014539
CHAN A1 (24V): -0.180632
CHAN A2 (12V): -0.002151
CHAN A3 (5V): -0.001386
CHAN B0 (3.3V): 0.000067
CHAN B1 (3.15aV): -0.000273
CHAN B2 (3.15bV): -0.000195
CHAN B3 (GND): -0.000385
OPEN: -0.000301
Full Scale Calc: 4.765 mA, -1.589 mA
2021-08-30T18:41:33.117Z,1630348893.117 [CommandLine](IMPORTANT): got command gfscan
2021-08-30T18:41:33.145Z,1630348893.145 [CBIT](IMPORTANT): Beginning ground fault scan
2021-08-30T18:41:44.089Z,1630348904.089 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.015014
CHAN A1 (24V): -0.180902
CHAN A2 (12V): -0.002477
CHAN A3 (5V): -0.001347
CHAN B0 (3.3V): 0.000225
CHAN B1 (3.15aV): 0.000083
CHAN B2 (3.15bV): -0.000376
CHAN B3 (GND): 0.000509
OPEN: -0.000389
Full Scale Calc: 4.765 mA, -1.589 mA
2021-08-30T18:42:01.008Z,1630348921.008 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-08-30T18:42:01.008Z,1630348921.008 [Default:CheckIn:C.Wait] Stopped
2021-08-30T18:42:01.008Z,1630348921.008 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-08-30T18:42:01.008Z,1630348921.008 [Default:CheckIn:D] Running Loop=1
2021-08-30T18:42:01.433Z,1630348921.433 [Default:CheckIn:D] Stopped
2021-08-30T18:42:01.433Z,1630348921.433 [Default:CheckIn:E] Running Loop=1
2021-08-30T18:42:01.837Z,1630348921.837 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.680732 min 
2021-08-30T18:42:01.837Z,1630348921.837 [Default:CheckIn:E] Stopped
2021-08-30T18:42:01.837Z,1630348921.837 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-08-30T18:42:01.837Z,1630348921.837 [Default:CheckIn] Stopped
2021-08-30T18:42:01.837Z,1630348921.837 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-08-30T18:42:01.837Z,1630348921.837 [Default:CheckIn](INFO): Running loop #2
2021-08-30T18:42:01.838Z,1630348921.838 [Default:CheckIn] Running Loop=2
2021-08-30T18:42:01.838Z,1630348921.838 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-08-30T18:42:01.838Z,1630348921.838 [Default:CheckIn:Read_GPS] Running Loop=1
2021-08-30T18:42:34.942Z,1630348954.942 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5
2021-08-30T18:42:34.943Z,1630348954.943 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-08-30T18:42:34.970Z,1630348954.970 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-08-30T18:42:35.390Z,1630348955.390 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-08-30T18:42:35.390Z,1630348955.390 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5
2021-08-30T18:44:29.415Z,1630349069.415 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2
2021-08-30T18:44:35.991Z,1630349075.991 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB3
2021-08-30T18:44:37.431Z,1630349077.431 [CommandLine](IMPORTANT): got command gfscan
2021-08-30T18:44:37.834Z,1630349077.834 [CBIT](IMPORTANT): Beginning ground fault scan
2021-08-30T18:44:43.564Z,1630349083.564 [CommandLine](IMPORTANT): got command burn on
2021-08-30T18:44:43.564Z,1630349083.564 [CommandLine](IMPORTANT): Activating dropweight wire
2021-08-30T18:44:48.685Z,1630349088.685 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.002480
CHAN A1 (24V): 0.000301
CHAN A2 (12V): -0.002195
CHAN A3 (5V): -0.001018
CHAN B0 (3.3V): 0.000267
CHAN B1 (3.15aV): -0.000722
CHAN B2 (3.15bV): -0.000013
CHAN B3 (GND): -0.000027
OPEN: -0.000332
Full Scale Calc: 4.765 mA, -1.589 mA
2021-08-30T18:44:56.622Z,1630349096.622 [CommandLine](IMPORTANT): got command burn off
2021-08-30T18:44:56.623Z,1630349096.623 [CommandLine](IMPORTANT): Deactivating dropweight wire
2021-08-30T18:45:35.945Z,1630349135.945 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6
2021-08-30T18:45:35.945Z,1630349135.945 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-08-30T18:45:35.956Z,1630349135.956 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-08-30T18:45:36.377Z,1630349136.377 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-08-30T18:45:36.377Z,1630349136.377 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6
2021-08-30T18:45:50.302Z,1630349150.302 [CommandLine](IMPORTANT): got command burn on
2021-08-30T18:45:50.302Z,1630349150.302 [CommandLine](IMPORTANT): Activating dropweight wire
2021-08-30T18:46:40.709Z,1630349200.709 [CommandLine](IMPORTANT): got command burn off
2021-08-30T18:46:40.709Z,1630349200.709 [CommandLine](IMPORTANT): Deactivating dropweight wire
2021-08-30T18:47:02.006Z,1630349222.006 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-08-30T18:42:01.8Z
2021-08-30T18:47:02.007Z,1630349222.007 [Default:CheckIn:Read_GPS] Stopped
2021-08-30T18:47:02.007Z,1630349222.007 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-08-30T18:47:09.565Z,1630349229.565 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20210830T182720/Courier0007.lzma
2021-08-30T18:47:10.568Z,1630349230.568 [DataOverHttps](INFO): Moved sent file to Logs/20210830T182720/Courier0007.lzma.bak
2021-08-30T18:47:10.568Z,1630349230.568 [DataOverHttps](INFO): SBD MOMSN=15902852
2021-08-30T18:47:25.947Z,1630349245.947 [DataOverHttps](INFO): Sending 812 bytes from file Logs/20210830T182720/Express0008.lzma
2021-08-30T18:47:26.948Z,1630349246.948 [DataOverHttps](INFO): Moved sent file to Logs/20210830T182720/Express0008.lzma.bak
2021-08-30T18:47:26.948Z,1630349246.948 [DataOverHttps](INFO): SBD MOMSN=15902854
2021-08-30T18:47:28.268Z,1630349248.268 [Default:CheckIn:Read_Iridium] Stopped
2021-08-30T18:47:28.268Z,1630349248.268 [Default:CheckIn:C.Wait] Running Loop=1
2021-08-30T18:47:28.268Z,1630349248.268 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-08-30T18:48:36.963Z,1630349316.963 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7
2021-08-30T18:48:36.963Z,1630349316.963 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-08-30T18:48:36.993Z,1630349316.993 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-08-30T18:48:37.355Z,1630349317.355 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-08-30T18:48:37.355Z,1630349317.355 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7
2021-08-30T18:48:55.100Z,1630349335.100 [NAL9602](FAULT): GPS failed to acquire within timeout.
2021-08-30T18:48:55.100Z,1630349335.100 [NAL9602] Data Fault, FailCount= 2
2021-08-30T18:48:55.100Z,1630349335.100 [NAL9602](ERROR): Data Fault
2021-08-30T18:48:55.118Z,1630349335.118 [CBIT](ERROR): Data Fault in component: NAL9602
2021-08-30T18:48:55.503Z,1630349335.503 [NAL9602](INFO): Powering down
2021-08-30T18:48:56.348Z,1630349336.348 [CBIT](INFO): Clearing failed state for component NAL9602
2021-08-30T18:48:56.348Z,1630349336.348 [NAL9602] No Fault, FailCount= 2
2021-08-30T18:49:25.807Z,1630349365.807 [NAL9602](INFO): Powering up NAL9602
2021-08-30T18:49:36.716Z,1630349376.716 [NAL9602](INFO): NAL9602 initialized
2021-08-30T18:50:47.040Z,1630349447.040 [CommandLine](IMPORTANT): got command failComponent
2021-08-30T18:50:47.040Z,1630349447.040 [CommandLine](IMPORTANT): Failed components:
2021-08-30T18:50:47.040Z,1630349447.040 [CommandLine](IMPORTANT): No failed Components.
2021-08-30T18:51:37.934Z,1630349497.934 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 8
2021-08-30T18:51:37.934Z,1630349497.934 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-08-30T18:51:37.945Z,1630349497.945 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-08-30T18:51:38.362Z,1630349498.362 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-08-30T18:51:38.362Z,1630349498.362 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 8
2021-08-30T18:51:45.384Z,1630349505.384 [CommandLine](IMPORTANT): got command maintain control SpeedControl.propOmegaAction 300.000000 revolution_per_minute
2021-08-30T18:51:45.388Z,1630349505.388 [ComponentRegistry](DEBUG): SyncComponent "Maintain_SpeedControl.propOmegaAction" handled in the control thread.
2021-08-30T18:51:45.628Z,1630349505.628 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,Power24vConverter,CANONSampler,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,Maintain_SpeedControl.propOmegaAction,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2021-08-30T18:51:57.136Z,1630349517.136 [CommandLine](IMPORTANT): got command maintain clear
2021-08-30T18:51:57.403Z,1630349517.403 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,Power24vConverter,CANONSampler,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2021-08-30T18:52:09.646Z,1630349529.646 [CommandLine](IMPORTANT): got command strobe off
2021-08-30T18:52:09.647Z,1630349529.647 [CommandLine](IMPORTANT): Deactivating strobe
2021-08-30T18:52:28.832Z,1630349548.832 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-08-30T18:52:28.832Z,1630349548.832 [Default:CheckIn:C.Wait] Stopped
2021-08-30T18:52:28.832Z,1630349548.832 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-08-30T18:52:28.832Z,1630349548.832 [Default:CheckIn:D] Running Loop=1
2021-08-30T18:52:29.253Z,1630349549.253 [Default:CheckIn:D] Stopped
2021-08-30T18:52:29.253Z,1630349549.253 [Default:CheckIn:E] Running Loop=1
2021-08-30T18:52:29.665Z,1630349549.665 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 21.144401 min 
2021-08-30T18:52:29.665Z,1630349549.665 [Default:CheckIn:E] Stopped
2021-08-30T18:52:29.665Z,1630349549.665 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-08-30T18:52:29.665Z,1630349549.665 [Default:CheckIn] Stopped
2021-08-30T18:52:29.665Z,1630349549.665 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-08-30T18:52:29.665Z,1630349549.665 [Default:CheckIn](INFO): Running loop #3
2021-08-30T18:52:29.666Z,1630349549.666 [Default:CheckIn] Running Loop=3
2021-08-30T18:52:29.666Z,1630349549.666 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-08-30T18:52:29.666Z,1630349549.666 [Default:CheckIn:Read_GPS] Running Loop=1
2021-08-30T18:54:38.928Z,1630349678.928 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 9
2021-08-30T18:54:38.928Z,1630349678.928 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-08-30T18:54:38.947Z,1630349678.947 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-08-30T18:54:39.349Z,1630349679.349 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-08-30T18:54:39.349Z,1630349679.349 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 9
2021-08-30T18:57:29.833Z,1630349849.833 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-08-30T18:52:29.7Z
2021-08-30T18:57:29.833Z,1630349849.833 [Default:CheckIn:Read_GPS] Stopped
2021-08-30T18:57:29.833Z,1630349849.833 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-08-30T18:57:30.637Z,1630349850.637 [Default:CheckIn:Read_Iridium] Stopped
2021-08-30T18:57:30.637Z,1630349850.637 [Default:CheckIn:C.Wait] Running Loop=1
2021-08-30T18:57:30.637Z,1630349850.637 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-08-30T18:57:39.943Z,1630349859.943 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 10
2021-08-30T18:57:39.943Z,1630349859.943 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-08-30T18:57:39.954Z,1630349859.954 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-08-30T18:57:40.365Z,1630349860.365 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-08-30T18:57:40.365Z,1630349860.365 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 10
2021-08-30T18:57:58.095Z,1630349878.095 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,185756.00,A,3648.17081,N,12147.27607,W,0.078,320.82,300821,,,A*7B
2021-08-30T18:57:58.129Z,1630349878.129 [NAL9602](INFO): GPS fix at 20210830T185756: (36.802847, -121.787935)
2021-08-30T18:58:30.431Z,1630349910.431 [NAL9602](INFO): Not Powering down - fast GPS
2021-08-30T19:02:31.249Z,1630350151.249 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-08-30T19:02:31.250Z,1630350151.250 [Default:CheckIn:C.Wait] Stopped
2021-08-30T19:02:31.250Z,1630350151.250 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-08-30T19:02:31.250Z,1630350151.250 [Default:CheckIn:D] Running Loop=1
2021-08-30T19:02:31.637Z,1630350151.637 [Default:CheckIn:D] Stopped
2021-08-30T19:02:31.637Z,1630350151.637 [Default:CheckIn:E] Running Loop=1
2021-08-30T19:02:32.045Z,1630350152.045 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 31.184141 min 
2021-08-30T19:02:32.045Z,1630350152.045 [Default:CheckIn:E] Stopped
2021-08-30T19:02:32.045Z,1630350152.045 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-08-30T19:02:32.046Z,1630350152.046 [Default:CheckIn] Stopped
2021-08-30T19:02:32.046Z,1630350152.046 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-08-30T19:02:32.046Z,1630350152.046 [Default:CheckIn](INFO): Running loop #4
2021-08-30T19:02:32.046Z,1630350152.046 [Default:CheckIn] Running Loop=4
2021-08-30T19:02:32.046Z,1630350152.046 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-08-30T19:02:32.047Z,1630350152.047 [Default:CheckIn:Read_GPS] Running Loop=1
2021-08-30T19:02:34.050Z,1630350154.050 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190232.00,A,3648.14774,N,12147.25568,W,0.369,207.71,300821,,,A*75
2021-08-30T19:02:34.053Z,1630350154.053 [NAL9602](INFO): GPS fix at 20210830T190232: (36.802462, -121.787595)
2021-08-30T19:02:34.064Z,1630350154.064 [Default:CheckIn:Read_GPS] Stopped
2021-08-30T19:02:34.064Z,1630350154.064 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-08-30T19:02:41.845Z,1630350161.845 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20210830T182720/Courier0010.lzma
2021-08-30T19:02:42.848Z,1630350162.848 [DataOverHttps](INFO): Moved sent file to Logs/20210830T182720/Courier0010.lzma.bak
2021-08-30T19:02:42.848Z,1630350162.848 [DataOverHttps](INFO): SBD MOMSN=15902895
2021-08-30T19:03:01.894Z,1630350181.894 [DataOverHttps](INFO): Sending 222 bytes from file Logs/20210830T182720/Courier0013.lzma
2021-08-30T19:03:02.896Z,1630350182.896 [DataOverHttps](INFO): Moved sent file to Logs/20210830T182720/Courier0013.lzma.bak
2021-08-30T19:03:02.896Z,1630350182.896 [DataOverHttps](INFO): SBD MOMSN=15902897
2021-08-30T19:03:03.592Z,1630350183.592 [NAL9602](INFO): SBD MO Status=0, MOMSN=29034, MT Status=0, MTMSN=0
2021-08-30T19:03:03.592Z,1630350183.592 [NAL9602](INFO): No messages in MT queue
2021-08-30T19:03:18.858Z,1630350198.858 [DataOverHttps](INFO): Sending 304 bytes from file Logs/20210830T182720/Express0011.lzma
2021-08-30T19:03:19.860Z,1630350199.860 [DataOverHttps](INFO): Moved sent file to Logs/20210830T182720/Express0011.lzma.bak
2021-08-30T19:03:19.860Z,1630350199.860 [DataOverHttps](INFO): SBD MOMSN=15902900
2021-08-30T19:03:34.291Z,1630350214.291 [NAL9602](INFO): Not Powering down - fast GPS
2021-08-30T19:03:35.814Z,1630350215.814 [DataOverHttps](INFO): Sending 269 bytes from file Logs/20210830T182720/Express0014.lzma
2021-08-30T19:03:36.817Z,1630350216.817 [DataOverHttps](INFO): Moved sent file to Logs/20210830T182720/Express0014.lzma.bak
2021-08-30T19:03:36.817Z,1630350216.817 [DataOverHttps](INFO): SBD MOMSN=15902911
2021-08-30T19:03:37.936Z,1630350217.936 [Default:CheckIn:Read_Iridium] Stopped
2021-08-30T19:03:37.936Z,1630350217.936 [Default:CheckIn:C.Wait] Running Loop=1
2021-08-30T19:03:37.936Z,1630350217.936 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-08-30T19:07:49.355Z,1630350469.355 [DataOverHttps](IMPORTANT): SBD MTMSN=20210830T190748
2021-08-30T19:07:56.658Z,1630350476.658 [DataOverHttps](INFO): Received command:ibit
2021-08-30T19:07:56.671Z,1630350476.671 [CommandLine](IMPORTANT): got command ibit
2021-08-30T19:07:56.919Z,1630350476.919 [IBIT](IMPORTANT): Beginning Initiated BIT
2021-08-30T19:07:56.920Z,1630350476.920 [IBIT](IMPORTANT): Beginning control surface checks.
2021-08-30T19:07:56.923Z,1630350476.923 [CBIT](IMPORTANT): Beginning ground fault scan
2021-08-30T19:07:58.523Z,1630350478.523 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190757.00,A,3648.14076,N,12147.22973,W,0.000,69.48,300821,,,D*4E
2021-08-30T19:07:58.526Z,1630350478.526 [NAL9602](INFO): GPS fix at 20210830T190757: (36.802346, -121.787162)
2021-08-30T19:08:07.837Z,1630350487.837 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): -0.002139
CHAN A1 (24V): 4.610929
CHAN A2 (12V): -0.002712
CHAN A3 (5V): -0.000969
CHAN B0 (3.3V): 0.000011
CHAN B1 (3.15aV): -0.000226
CHAN B2 (3.15bV): -0.000426
CHAN B3 (GND): 0.000520
OPEN: -0.000333
Full Scale Calc: 4.765 mA, -1.589 mA
2021-08-30T19:08:25.993Z,1630350505.993 [NAL9602](INFO): SBD MO Status=0, MOMSN=29035, MT Status=0, MTMSN=0
2021-08-30T19:08:25.993Z,1630350505.993 [NAL9602](INFO): No messages in MT queue
2021-08-30T19:08:27.208Z,1630350507.208 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190826.00,A,3648.14180,N,12147.22881,W,0.117,69.48,300821,,,D*44
2021-08-30T19:08:27.211Z,1630350507.211 [NAL9602](INFO): GPS fix at 20210830T190826: (36.802363, -121.787147)
2021-08-30T19:08:30.034Z,1630350510.034 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190829.00,A,3648.14192,N,12147.22867,W,0.000,69.48,300821,,,D*47
2021-08-30T19:08:30.036Z,1630350510.036 [NAL9602](INFO): GPS fix at 20210830T190829: (36.802365, -121.787144)
2021-08-30T19:08:32.861Z,1630350512.861 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190832.00,A,3648.14204,N,12147.22848,W,0.039,69.48,300821,,,D*46
2021-08-30T19:08:32.863Z,1630350512.863 [NAL9602](INFO): GPS fix at 20210830T190832: (36.802367, -121.787141)
2021-08-30T19:08:36.097Z,1630350516.097 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190835.00,A,3648.14203,N,12147.22830,W,0.058,69.48,300821,,,D*4E
2021-08-30T19:08:36.101Z,1630350516.101 [NAL9602](INFO): GPS fix at 20210830T190835: (36.802367, -121.787138)
2021-08-30T19:08:38.921Z,1630350518.921 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190838.00,A,3648.14203,N,12147.22823,W,0.058,69.48,300821,,,D*41
2021-08-30T19:08:38.924Z,1630350518.924 [NAL9602](INFO): GPS fix at 20210830T190838: (36.802367, -121.787137)
2021-08-30T19:08:42.153Z,1630350522.153 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190841.00,A,3648.14203,N,12147.22821,W,0.039,69.48,300821,,,D*4A
2021-08-30T19:08:42.155Z,1630350522.155 [NAL9602](INFO): GPS fix at 20210830T190841: (36.802367, -121.787137)
2021-08-30T19:08:43.064Z,1630350523.064 [IBIT](IMPORTANT): Communications Status:
Fix Status: 1
Iridium Signal Strength: 3
Latitude: 36.802368 Longitude: -121.787140
2021-08-30T19:08:43.472Z,1630350523.472 [IBIT](IMPORTANT): Battery Status:
Battery Charge (AH): 0.000000
Voltage: 16.532000
2021-08-30T19:08:43.472Z,1630350523.472 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah
2021-08-30T19:08:43.472Z,1630350523.472 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V
2021-08-30T19:08:43.883Z,1630350523.883 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2021-08-30T19:08:43.884Z,1630350523.884 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2021-08-30T19:08:43.884Z,1630350523.884 [IBIT](IMPORTANT): Pressure:9.916967 PSI
2021-08-30T19:08:43.884Z,1630350523.884 [IBIT](IMPORTANT): Humidity:7.215236 %
2021-08-30T19:08:44.263Z,1630350524.263 [IBIT](IMPORTANT): Vehicle Pitch:0.238227 degrees
2021-08-30T19:08:44.264Z,1630350524.264 [IBIT](IMPORTANT): Vehicle  Roll:3.057178 degrees
2021-08-30T19:08:44.264Z,1630350524.264 [IBIT](IMPORTANT): Vehicle  Heading:35.258427 degrees
2021-08-30T19:08:44.679Z,1630350524.679 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2021-08-30T19:08:44.680Z,1630350524.680 [IBIT](IMPORTANT): buoyancyNeutral: 310.836334 cc
2021-08-30T19:08:44.680Z,1630350524.680 [IBIT](IMPORTANT): massDefault: -1.761130 cm
2021-08-30T19:08:44.680Z,1630350524.680 [IBIT](IMPORTANT): stopDepth: 205.000000 m
2021-08-30T19:08:44.681Z,1630350524.681 [IBIT](IMPORTANT): abortDepth: 250.000000 m
2021-08-30T19:08:44.681Z,1630350524.681 [IBIT](IMPORTANT): IBIT PASSED
2021-08-30T19:08:44.993Z,1630350524.993 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-08-30T19:08:44.993Z,1630350524.993 [Default:CheckIn:C.Wait] Stopped
2021-08-30T19:08:44.993Z,1630350524.993 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-08-30T19:08:44.994Z,1630350524.994 [Default:CheckIn:D] Running Loop=1
2021-08-30T19:08:45.397Z,1630350525.397 [Default:CheckIn:D] Stopped
2021-08-30T19:08:45.397Z,1630350525.397 [Default:CheckIn:E] Running Loop=1
2021-08-30T19:08:45.812Z,1630350525.812 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 37.413468 min 
2021-08-30T19:08:45.812Z,1630350525.812 [Default:CheckIn:E] Stopped
2021-08-30T19:08:45.812Z,1630350525.812 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-08-30T19:08:45.812Z,1630350525.812 [Default:CheckIn] Stopped
2021-08-30T19:08:45.812Z,1630350525.812 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-08-30T19:08:45.812Z,1630350525.812 [Default:CheckIn](INFO): Running loop #5
2021-08-30T19:08:45.812Z,1630350525.812 [Default:CheckIn] Running Loop=5
2021-08-30T19:08:45.812Z,1630350525.812 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-08-30T19:08:45.813Z,1630350525.813 [Default:CheckIn:Read_GPS] Running Loop=1
2021-08-30T19:08:47.809Z,1630350527.809 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190847.00,A,3648.14188,N,12147.22838,W,0.019,69.48,300821,,,D*46
2021-08-30T19:08:47.811Z,1630350527.811 [NAL9602](INFO): GPS fix at 20210830T190847: (36.802365, -121.787140)
2021-08-30T19:08:47.875Z,1630350527.875 [Default:CheckIn:Read_GPS] Stopped
2021-08-30T19:08:47.875Z,1630350527.875 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-08-30T19:08:50.414Z,1630350530.414 [RudderServo](ERROR): getPosition uart error serial timeout
2021-08-30T19:08:50.414Z,1630350530.414 [RudderServo](FAULT): Rudder uart error - getPosition..serial timeout
2021-08-30T19:08:50.414Z,1630350530.414 [RudderServo] Communications Fault, FailCount= 1
2021-08-30T19:08:50.414Z,1630350530.414 [RudderServo](ERROR): Communications Fault
2021-08-30T19:08:50.418Z,1630350530.418 [CBIT](ERROR): Communications Fault in component: RudderServo
2021-08-30T19:08:50.822Z,1630350530.822 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2021-08-30T19:08:50.822Z,1630350530.822 [RudderServo](INFO): Powering down
2021-08-30T19:08:51.640Z,1630350531.640 [RudderServo](DEBUG): Initializing EZServoServo.
2021-08-30T19:08:51.763Z,1630350531.763 [RudderServo](DEBUG): Initializing RudderServo.
2021-08-30T19:08:51.767Z,1630350531.767 [CBIT](INFO): Clearing failed state for component RudderServo
2021-08-30T19:08:51.767Z,1630350531.767 [RudderServo] No Fault, FailCount= 1
2021-08-30T19:08:58.037Z,1630350538.037 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210830T182720/Courier0016.lzma
2021-08-30T19:08:59.040Z,1630350539.040 [DataOverHttps](INFO): Moved sent file to Logs/20210830T182720/Courier0016.lzma.bak
2021-08-30T19:08:59.040Z,1630350539.040 [DataOverHttps](INFO): SBD MOMSN=15902917
2021-08-30T19:09:14.847Z,1630350554.847 [DataOverHttps](INFO): Sending 836 bytes from file Logs/20210830T182720/Express0017.lzma
2021-08-30T19:09:15.848Z,1630350555.848 [DataOverHttps](INFO): Moved sent file to Logs/20210830T182720/Express0017.lzma.bak
2021-08-30T19:09:15.848Z,1630350555.848 [DataOverHttps](INFO): SBD MOMSN=15902920
2021-08-30T19:09:17.075Z,1630350557.075 [Default:CheckIn:Read_Iridium] Stopped
2021-08-30T19:09:17.075Z,1630350557.075 [Default:CheckIn:C.Wait] Running Loop=1
2021-08-30T19:09:17.075Z,1630350557.075 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-08-30T19:09:20.687Z,1630350560.687 [NAL9602](INFO): Not Powering down - fast GPS
2021-08-30T19:14:17.817Z,1630350857.817 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-08-30T19:14:17.817Z,1630350857.817 [Default:CheckIn:C.Wait] Stopped
2021-08-30T19:14:17.817Z,1630350857.817 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-08-30T19:14:17.817Z,1630350857.817 [Default:CheckIn:D] Running Loop=1
2021-08-30T19:14:18.251Z,1630350858.251 [Default:CheckIn:D] Stopped
2021-08-30T19:14:18.251Z,1630350858.251 [Default:CheckIn:E] Running Loop=1
2021-08-30T19:14:18.630Z,1630350858.630 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 42.961031 min 
2021-08-30T19:14:18.630Z,1630350858.630 [Default:CheckIn:E] Stopped
2021-08-30T19:14:18.630Z,1630350858.630 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-08-30T19:14:18.631Z,1630350858.631 [Default:CheckIn] Stopped
2021-08-30T19:14:18.631Z,1630350858.631 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-08-30T19:14:18.631Z,1630350858.631 [Default:CheckIn](INFO): Running loop #6
2021-08-30T19:14:18.631Z,1630350858.631 [Default:CheckIn] Running Loop=6
2021-08-30T19:14:18.631Z,1630350858.631 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-08-30T19:14:18.631Z,1630350858.631 [Default:CheckIn:Read_GPS] Running Loop=1
2021-08-30T19:14:20.633Z,1630350860.633 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,191419.00,A,3648.14973,N,12147.22271,W,0.097,24.04,300821,,,D*4C
2021-08-30T19:14:20.652Z,1630350860.652 [NAL9602](INFO): GPS fix at 20210830T191419: (36.802495, -121.787045)
2021-08-30T19:14:20.684Z,1630350860.684 [Default:CheckIn:Read_GPS] Stopped
2021-08-30T19:14:20.684Z,1630350860.684 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-08-30T19:14:30.493Z,1630350870.493 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210830T182720/Courier0019.lzma
2021-08-30T19:14:31.496Z,1630350871.496 [DataOverHttps](INFO): Moved sent file to Logs/20210830T182720/Courier0019.lzma.bak
2021-08-30T19:14:31.496Z,1630350871.496 [DataOverHttps](INFO): SBD MOMSN=15902947
2021-08-30T19:14:47.414Z,1630350887.414 [DataOverHttps](INFO): Sending 182 bytes from file Logs/20210830T182720/Express0021.lzma
2021-08-30T19:14:48.416Z,1630350888.416 [DataOverHttps](INFO): Moved sent file to Logs/20210830T182720/Express0021.lzma.bak
2021-08-30T19:14:48.416Z,1630350888.416 [DataOverHttps](INFO): SBD MOMSN=15902950
2021-08-30T19:14:49.479Z,1630350889.479 [Default:CheckIn:Read_Iridium] Stopped
2021-08-30T19:14:49.479Z,1630350889.479 [Default:CheckIn:C.Wait] Running Loop=1
2021-08-30T19:14:49.479Z,1630350889.479 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-08-30T19:14:52.313Z,1630350892.313 [NAL9602](INFO): SBD MO Status=2, MOMSN=29036, MT Status=2, MTMSN=0
2021-08-30T19:14:52.313Z,1630350892.313 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-08-30T19:15:37.192Z,1630350937.192 [NAL9602](INFO): SBD MO Status=2, MOMSN=29036, MT Status=2, MTMSN=0
2021-08-30T19:15:37.193Z,1630350937.193 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-08-30T19:17:15.421Z,1630351035.421 [NAL9602](INFO): SBD MO Status=2, MOMSN=29036, MT Status=2, MTMSN=0
2021-08-30T19:17:15.421Z,1630351035.421 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-08-30T19:17:45.312Z,1630351065.312 [NAL9602](INFO): SBD MO Status=0, MOMSN=29036, MT Status=0, MTMSN=0
2021-08-30T19:17:45.313Z,1630351065.313 [NAL9602](INFO): No messages in MT queue
2021-08-30T19:18:16.017Z,1630351096.017 [NAL9602](INFO): Not Powering down - fast GPS
2021-08-30T19:19:50.173Z,1630351190.173 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-08-30T19:19:50.173Z,1630351190.173 [Default:CheckIn:C.Wait] Stopped
2021-08-30T19:19:50.173Z,1630351190.173 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-08-30T19:19:50.173Z,1630351190.173 [Default:CheckIn:D] Running Loop=1
2021-08-30T19:19:50.566Z,1630351190.566 [Default:CheckIn:D] Stopped
2021-08-30T19:19:50.566Z,1630351190.566 [Default:CheckIn:E] Running Loop=1
2021-08-30T19:19:50.969Z,1630351190.969 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 48.499622 min 
2021-08-30T19:19:50.969Z,1630351190.969 [Default:CheckIn:E] Stopped
2021-08-30T19:19:50.970Z,1630351190.970 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-08-30T19:19:50.970Z,1630351190.970 [Default:CheckIn] Stopped
2021-08-30T19:19:50.970Z,1630351190.970 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-08-30T19:19:50.970Z,1630351190.970 [Default:CheckIn](INFO): Running loop #7
2021-08-30T19:19:50.970Z,1630351190.970 [Default:CheckIn] Running Loop=7
2021-08-30T19:19:50.970Z,1630351190.970 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-08-30T19:19:50.970Z,1630351190.970 [Default:CheckIn:Read_GPS] Running Loop=1
2021-08-30T19:19:52.979Z,1630351192.979 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,191952.00,A,3648.14930,N,12147.22209,W,0.039,24.04,300821,,,D*42
2021-08-30T19:19:52.981Z,1630351192.981 [NAL9602](INFO): GPS fix at 20210830T191952: (36.802488, -121.787035)
2021-08-30T19:19:52.992Z,1630351192.992 [Default:CheckIn:Read_GPS] Stopped
2021-08-30T19:19:52.992Z,1630351192.992 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-08-30T19:19:59.977Z,1630351199.977 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210830T182720/Courier0025.lzma
2021-08-30T19:20:00.980Z,1630351200.980 [DataOverHttps](INFO): Moved sent file to Logs/20210830T182720/Courier0025.lzma.bak
2021-08-30T19:20:00.980Z,1630351200.980 [DataOverHttps](INFO): SBD MOMSN=15902955
2021-08-30T19:20:12.376Z,1630351212.376 [NAL9602](INFO): SBD MO Status=0, MOMSN=29037, MT Status=0, MTMSN=0
2021-08-30T19:20:12.377Z,1630351212.377 [NAL9602](INFO): No messages in MT queue
2021-08-30T19:20:16.773Z,1630351216.773 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20210830T182720/Express0026.lzma
2021-08-30T19:20:17.776Z,1630351217.776 [DataOverHttps](INFO): Moved sent file to Logs/20210830T182720/Express0026.lzma.bak
2021-08-30T19:20:17.776Z,1630351217.776 [DataOverHttps](INFO): SBD MOMSN=15902958
2021-08-30T19:20:18.845Z,1630351218.845 [Default:CheckIn:Read_Iridium] Stopped
2021-08-30T19:20:18.845Z,1630351218.845 [Default:CheckIn:C.Wait] Running Loop=1
2021-08-30T19:20:18.845Z,1630351218.845 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-08-30T19:20:43.143Z,1630351243.143 [NAL9602](INFO): Not Powering down - fast GPS
2021-08-30T19:25:19.619Z,1630351519.619 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-08-30T19:25:19.619Z,1630351519.619 [Default:CheckIn:C.Wait] Stopped
2021-08-30T19:25:19.619Z,1630351519.619 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-08-30T19:25:19.619Z,1630351519.619 [Default:CheckIn:D] Running Loop=1
2021-08-30T19:25:20.013Z,1630351520.013 [Default:CheckIn:D] Stopped
2021-08-30T19:25:20.013Z,1630351520.013 [Default:CheckIn:E] Running Loop=1
2021-08-30T19:25:20.422Z,1630351520.422 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 53.990397 min 
2021-08-30T19:25:20.422Z,1630351520.422 [Default:CheckIn:E] Stopped
2021-08-30T19:25:20.422Z,1630351520.422 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-08-30T19:25:20.422Z,1630351520.422 [Default:CheckIn] Stopped
2021-08-30T19:25:20.422Z,1630351520.422 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-08-30T19:25:20.422Z,1630351520.422 [Default:CheckIn](INFO): Running loop #8
2021-08-30T19:25:20.423Z,1630351520.423 [Default:CheckIn] Running Loop=8
2021-08-30T19:25:20.423Z,1630351520.423 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-08-30T19:25:20.423Z,1630351520.423 [Default:CheckIn:Read_GPS] Running Loop=1
2021-08-30T19:25:22.437Z,1630351522.437 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,192521.00,A,3648.52876,N,12147.18642,W,6.181,255.11,300821,,,A*7B
2021-08-30T19:25:22.439Z,1630351522.439 [NAL9602](INFO): GPS fix at 20210830T192521: (36.808813, -121.786440)
2021-08-30T19:25:22.450Z,1630351522.450 [Default:CheckIn:Read_GPS] Stopped
2021-08-30T19:25:22.450Z,1630351522.450 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-08-30T19:25:28.861Z,1630351528.861 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210830T182720/Courier0028.lzma
2021-08-30T19:25:29.864Z,1630351529.864 [DataOverHttps](INFO): Moved sent file to Logs/20210830T182720/Courier0028.lzma.bak
2021-08-30T19:25:29.864Z,1630351529.864 [DataOverHttps](INFO): SBD MOMSN=15902964
2021-08-30T19:25:45.055Z,1630351545.055 [NAL9602](INFO): SBD MO Status=2, MOMSN=29038, MT Status=2, MTMSN=0
2021-08-30T19:25:45.055Z,1630351545.055 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-08-30T19:25:45.737Z,1630351545.737 [DataOverHttps](INFO): Sending 145 bytes from file Logs/20210830T182720/Express0029.lzma
2021-08-30T19:25:46.740Z,1630351546.740 [DataOverHttps](INFO): Moved sent file to Logs/20210830T182720/Express0029.lzma.bak
2021-08-30T19:25:46.740Z,1630351546.740 [DataOverHttps](INFO): SBD MOMSN=15902967
2021-08-30T19:25:47.910Z,1630351547.910 [Default:CheckIn:Read_Iridium] Stopped
2021-08-30T19:25:47.910Z,1630351547.910 [Default:CheckIn:C.Wait] Running Loop=1
2021-08-30T19:25:47.910Z,1630351547.910 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-08-30T19:25:54.344Z,1630351554.344 [NAL9602](INFO): SBD MO Status=0, MOMSN=29038, MT Status=0, MTMSN=0
2021-08-30T19:25:54.344Z,1630351554.344 [NAL9602](INFO): No messages in MT queue
2021-08-30T19:26:25.115Z,1630351585.115 [NAL9602](INFO): Not Powering down - fast GPS
2021-08-30T19:26:28.171Z,1630351588.171 [DataOverHttps](IMPORTANT): SBD MTMSN=20210830T192627
2021-08-30T19:26:35.654Z,1630351595.654 [DataOverHttps](INFO): Received command:schedule clear;schedule resume
2021-08-30T19:26:35.663Z,1630351595.663 [CommandLine](IMPORTANT): got command schedule clear
2021-08-30T19:26:35.663Z,1630351595.663 [CommandLine](IMPORTANT): #Cleared scheduled commands:0
2021-08-30T19:26:35.664Z,1630351595.664 [CommandLine](IMPORTANT): got command schedule resume
2021-08-30T19:30:48.525Z,1630351848.525 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-08-30T19:30:48.525Z,1630351848.525 [Default:CheckIn:C.Wait] Stopped
2021-08-30T19:30:48.525Z,1630351848.525 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-08-30T19:30:48.525Z,1630351848.525 [Default:CheckIn:D] Running Loop=1
2021-08-30T19:30:48.962Z,1630351848.962 [Default:CheckIn:D] Stopped
2021-08-30T19:30:48.962Z,1630351848.962 [Default:CheckIn:E] Running Loop=1
2021-08-30T19:30:49.344Z,1630351849.344 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 59.472811 min 
2021-08-30T19:30:49.344Z,1630351849.344 [Default:CheckIn:E] Stopped
2021-08-30T19:30:49.344Z,1630351849.344 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-08-30T19:30:49.344Z,1630351849.344 [Default:CheckIn] Stopped
2021-08-30T19:30:49.344Z,1630351849.344 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-08-30T19:30:49.344Z,1630351849.344 [Default:CheckIn](INFO): Running loop #9
2021-08-30T19:30:49.344Z,1630351849.344 [Default:CheckIn] Running Loop=9
2021-08-30T19:30:49.345Z,1630351849.345 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-08-30T19:30:49.345Z,1630351849.345 [Default:CheckIn:Read_GPS] Running Loop=1
2021-08-30T19:30:51.345Z,1630351851.345 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,193050.00,A,3648.33671,N,12148.63770,W,15.454,276.54,300821,,,A*4B
2021-08-30T19:30:51.347Z,1630351851.347 [NAL9602](INFO): GPS fix at 20210830T193050: (36.805612, -121.810628)
2021-08-30T19:30:51.387Z,1630351851.387 [Default:CheckIn:Read_GPS] Stopped
2021-08-30T19:30:51.387Z,1630351851.387 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-08-30T19:31:00.633Z,1630351860.633 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210830T182720/Courier0031.lzma
2021-08-30T19:31:01.636Z,1630351861.636 [DataOverHttps](INFO): Moved sent file to Logs/20210830T182720/Courier0031.lzma.bak
2021-08-30T19:31:01.636Z,1630351861.636 [DataOverHttps](INFO): SBD MOMSN=15902973
2021-08-30T19:31:09.608Z,1630351869.608 [NAL9602](INFO): SBD MO Status=0, MOMSN=29039, MT Status=0, MTMSN=0
2021-08-30T19:31:09.608Z,1630351869.608 [NAL9602](INFO): No messages in MT queue
2021-08-30T19:31:40.319Z,1630351900.319 [NAL9602](INFO): Not Powering down - fast GPS
2021-08-30T19:31:55.022Z,1630351915.022 [DataOverHttps](INFO): Sending 244 bytes from file Logs/20210830T182720/Express0032.lzma
2021-08-30T19:31:56.024Z,1630351916.024 [DataOverHttps](INFO): Moved sent file to Logs/20210830T182720/Express0032.lzma.bak
2021-08-30T19:31:56.024Z,1630351916.024 [DataOverHttps](INFO): SBD MOMSN=15902976
2021-08-30T19:31:57.303Z,1630351917.303 [Default:CheckIn:Read_Iridium] Stopped
2021-08-30T19:31:57.303Z,1630351917.303 [Default:CheckIn:C.Wait] Running Loop=1
2021-08-30T19:31:57.303Z,1630351917.303 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-08-30T19:36:57.929Z,1630352217.929 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-08-30T19:36:57.929Z,1630352217.929 [Default:CheckIn:C.Wait] Stopped
2021-08-30T19:36:57.929Z,1630352217.929 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-08-30T19:36:57.929Z,1630352217.929 [Default:CheckIn:D] Running Loop=1
2021-08-30T19:36:58.332Z,1630352218.332 [Default:CheckIn:D] Stopped
2021-08-30T19:36:58.332Z,1630352218.332 [Default:CheckIn:E] Running Loop=1
2021-08-30T19:36:58.748Z,1630352218.748 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 65.629053 min 
2021-08-30T19:36:58.748Z,1630352218.748 [Default:CheckIn:E] Stopped
2021-08-30T19:36:58.748Z,1630352218.748 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-08-30T19:36:58.749Z,1630352218.749 [Default:CheckIn] Stopped
2021-08-30T19:36:58.749Z,1630352218.749 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-08-30T19:36:58.749Z,1630352218.749 [Default:CheckIn](INFO): Running loop #10
2021-08-30T19:36:58.749Z,1630352218.749 [Default:CheckIn] Running Loop=10
2021-08-30T19:36:58.749Z,1630352218.749 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-08-30T19:36:58.749Z,1630352218.749 [Default:CheckIn:Read_GPS] Running Loop=1
2021-08-30T19:37:00.750Z,1630352220.750 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,193700.00,A,3647.90489,N,12150.57238,W,17.067,252.90,300821,,,A*45
2021-08-30T19:37:00.752Z,1630352220.752 [NAL9602](INFO): GPS fix at 20210830T193700: (36.798415, -121.842873)
2021-08-30T19:37:00.791Z,1630352220.791 [Default:CheckIn:Read_GPS] Stopped
2021-08-30T19:37:00.791Z,1630352220.791 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-08-30T19:37:12.132Z,1630352232.132 [NAL9602](INFO): SBD MO Status=0, MOMSN=29040, MT Status=0, MTMSN=0
2021-08-30T19:37:12.132Z,1630352232.132 [NAL9602](INFO): No messages in MT queue
2021-08-30T19:37:12.597Z,1630352232.597 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210830T182720/Courier0034.lzma
2021-08-30T19:37:13.600Z,1630352233.600 [DataOverHttps](INFO): Moved sent file to Logs/20210830T182720/Courier0034.lzma.bak
2021-08-30T19:37:13.600Z,1630352233.600 [DataOverHttps](INFO): SBD MOMSN=15902985
2021-08-30T19:37:42.831Z,1630352262.831 [NAL9602](INFO): Not Powering down - fast GPS
2021-08-30T19:38:24.694Z,1630352304.694 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-08-30T19:38:55.818Z,1630352335.818 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-08-30T19:39:26.942Z,1630352366.942 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-08-30T19:39:58.066Z,1630352398.066 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-08-30T19:40:14.425Z,1630352414.425 [DataOverHttps](INFO): Sending 148 bytes from file Logs/20210830T182720/Express0036.lzma
2021-08-30T19:40:15.428Z,1630352415.428 [DataOverHttps](INFO): Moved sent file to Logs/20210830T182720/Express0036.lzma.bak
2021-08-30T19:40:15.428Z,1630352415.428 [DataOverHttps](INFO): SBD MOMSN=15902990
2021-08-30T19:40:16.453Z,1630352416.453 [Default:CheckIn:Read_Iridium] Stopped
2021-08-30T19:40:16.453Z,1630352416.453 [Default:CheckIn:C.Wait] Running Loop=1
2021-08-30T19:40:16.453Z,1630352416.453 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-08-30T19:42:16.049Z,1630352536.049 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2021-08-30T19:42:16.051Z,1630352536.051 [BPC1](INFO): Received data from all battery sticks.
2021-08-30T19:42:59.103Z,1630352579.103 [DataOverHttps](IMPORTANT): SBD MTMSN=20210830T194258
2021-08-30T19:43:06.745Z,1630352586.745 [DataOverHttps](INFO): Received command:restart logs