2021-04-13T17:45:26.499Z,1618335926.499 [Supervisor](DEBUG): Initializing supervisor.
2021-04-13T17:45:26.503Z,1618335926.503 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2021-04-13T17:45:26.504Z,1618335926.504 [SyncHandler](INFO): Protected caller Thread ID is 8969
2021-04-13T17:45:26.504Z,1618335926.504 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2021-04-13T17:45:26.505Z,1618335926.505 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2021-04-13T17:45:26.505Z,1618335926.505 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 8970
2021-04-13T17:45:26.509Z,1618335926.509 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2021-04-13T17:45:26.528Z,1618335926.528 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2021-04-13T17:45:26.529Z,1618335926.529 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2021-04-13T17:45:26.529Z,1618335926.529 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 8971
2021-04-13T17:45:26.531Z,1618335926.531 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2021-04-13T17:45:26.532Z,1618335926.532 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2021-04-13T17:45:26.533Z,1618335926.533 [logger ThreadHandler](INFO): Protected caller Thread ID is 8972
2021-04-13T17:45:26.536Z,1618335926.536 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2021-04-13T17:45:26.537Z,1618335926.537 [Supervisor](INFO): Looking for Config files in directory: Config/
2021-04-13T17:45:26.541Z,1618335926.541 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2021-04-13T17:45:26.904Z,1618335926.904 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2021-04-13T17:45:26.906Z,1618335926.906 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2021-04-13T17:45:27.522Z,1618335927.522 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2021-04-13T17:45:27.522Z,1618335927.522 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2021-04-13T17:45:27.624Z,1618335927.624 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2021-04-13T17:45:27.625Z,1618335927.625 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2021-04-13T17:45:28.148Z,1618335928.148 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2021-04-13T17:45:28.150Z,1618335928.150 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2021-04-13T17:45:28.247Z,1618335928.247 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2021-04-13T17:45:28.248Z,1618335928.248 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2021-04-13T17:45:28.330Z,1618335928.330 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2021-04-13T17:45:28.688Z,1618335928.688 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2021-04-13T17:45:28.690Z,1618335928.690 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2021-04-13T17:45:28.840Z,1618335928.840 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2021-04-13T17:45:28.842Z,1618335928.842 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2021-04-13T17:45:28.969Z,1618335928.969 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2021-04-13T17:45:28.971Z,1618335928.971 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2021-04-13T17:45:29.205Z,1618335929.205 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2021-04-13T17:45:29.205Z,1618335929.205 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2021-04-13T17:45:29.652Z,1618335929.652 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2021-04-13T17:45:29.653Z,1618335929.653 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2021-04-13T17:45:30.018Z,1618335930.018 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2021-04-13T17:45:30.018Z,1618335930.018 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2021-04-13T17:45:30.099Z,1618335930.099 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2021-04-13T17:45:30.294Z,1618335930.294 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2021-04-13T17:45:30.294Z,1618335930.294 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2021-04-13T17:45:30.541Z,1618335930.541 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2021-04-13T17:45:30.728Z,1618335930.728 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2021-04-13T17:45:31.202Z,1618335931.202 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2021-04-13T17:45:31.204Z,1618335931.204 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-brizo/
2021-04-13T17:45:31.207Z,1618335931.207 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Control.cfg
2021-04-13T17:45:31.307Z,1618335931.307 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Sensor.cfg
2021-04-13T17:45:31.455Z,1618335931.455 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Simulator.cfg
2021-04-13T17:45:31.542Z,1618335931.542 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/secure.cfg
2021-04-13T17:45:31.627Z,1618335931.627 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Servo.cfg
2021-04-13T17:45:31.736Z,1618335931.736 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/vehicle.cfg
2021-04-13T17:45:31.925Z,1618335931.925 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Battery.cfg
2021-04-13T17:45:32.185Z,1618335932.185 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2021-04-13T17:45:32.187Z,1618335932.187 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Science.cfg
2021-04-13T17:45:32.324Z,1618335932.324 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/logger.cfg
2021-04-13T17:45:32.421Z,1618335932.421 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/BIT.cfg
2021-04-13T17:45:32.528Z,1618335932.528 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Navigation.cfg
2021-04-13T17:45:32.624Z,1618335932.624 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-brizo/root/
2021-04-13T17:45:32.625Z,1618335932.625 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2021-04-13T17:45:32.633Z,1618335932.633 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2021-04-13T17:45:32.719Z,1618335932.719 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2021-04-13T17:45:32.720Z,1618335932.720 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2021-04-13T17:45:32.732Z,1618335932.732 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2021-04-13T17:45:32.732Z,1618335932.732 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2021-04-13T17:45:32.773Z,1618335932.773 [DepthRateCalculator] Loaded
2021-04-13T17:45:32.773Z,1618335932.773 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2021-04-13T17:45:32.778Z,1618335932.778 [PitchRateCalculator] Loaded
2021-04-13T17:45:32.779Z,1618335932.779 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2021-04-13T17:45:32.789Z,1618335932.789 [SpeedCalculator] Loaded
2021-04-13T17:45:32.789Z,1618335932.789 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2021-04-13T17:45:32.802Z,1618335932.802 [TempGradientCalculator] Loaded
2021-04-13T17:45:32.802Z,1618335932.802 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2021-04-13T17:45:32.807Z,1618335932.807 [YawRateCalculator] Loaded
2021-04-13T17:45:32.807Z,1618335932.807 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2021-04-13T17:45:32.827Z,1618335932.827 [ElevatorOffsetCalculator] Loaded
2021-04-13T17:45:32.827Z,1618335932.827 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2021-04-13T17:45:32.828Z,1618335932.828 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2021-04-13T17:45:32.828Z,1618335932.828 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2021-04-13T17:45:32.880Z,1618335932.880 [VerticalControl](DEBUG): Construct VerticalControl.
2021-04-13T17:45:32.935Z,1618335932.935 [VerticalControl] Loaded
2021-04-13T17:45:32.935Z,1618335932.935 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2021-04-13T17:45:32.938Z,1618335932.938 [HorizontalControl](DEBUG): Construct HorizontalControl.
2021-04-13T17:45:32.975Z,1618335932.975 [HorizontalControl] Loaded
2021-04-13T17:45:32.975Z,1618335932.975 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2021-04-13T17:45:32.977Z,1618335932.977 [SpeedControl](DEBUG): Construct SpeedControl.
2021-04-13T17:45:32.980Z,1618335932.980 [SpeedControl] Loaded
2021-04-13T17:45:32.980Z,1618335932.980 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2021-04-13T17:45:32.983Z,1618335932.983 [LoopControl](DEBUG): Construct LoopControl.
2021-04-13T17:45:32.983Z,1618335932.983 [LoopControl] Loaded
2021-04-13T17:45:32.983Z,1618335932.983 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2021-04-13T17:45:32.984Z,1618335932.984 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2021-04-13T17:45:32.984Z,1618335932.984 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2021-04-13T17:45:33.068Z,1618335933.068 [DeadReckonUsingMultipleVelocitySources] Loaded
2021-04-13T17:45:33.069Z,1618335933.069 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2021-04-13T17:45:33.081Z,1618335933.081 [NavChart] Loaded
2021-04-13T17:45:33.081Z,1618335933.081 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2021-04-13T17:45:33.087Z,1618335933.087 [UniversalFixResidualReporter] Loaded
2021-04-13T17:45:33.087Z,1618335933.087 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2021-04-13T17:45:33.088Z,1618335933.088 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2021-04-13T17:45:33.088Z,1618335933.088 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2021-04-13T17:45:33.186Z,1618335933.186 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2021-04-13T17:45:33.187Z,1618335933.187 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2021-04-13T17:45:33.541Z,1618335933.541 [AHRS_M2] Loaded
2021-04-13T17:45:33.541Z,1618335933.541 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2021-04-13T17:45:33.570Z,1618335933.570 [BackseatComponent] Loaded
2021-04-13T17:45:33.571Z,1618335933.571 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2021-04-13T17:45:33.572Z,1618335933.572 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 408674E0
2021-04-13T17:45:33.572Z,1618335933.572 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 9054
2021-04-13T17:45:33.575Z,1618335933.575 [LcmUniversalReporter] Loaded
2021-04-13T17:45:33.575Z,1618335933.575 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2021-04-13T17:45:34.343Z,1618335934.343 [BPC1] Loaded
2021-04-13T17:45:34.343Z,1618335934.343 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2021-04-13T17:45:34.413Z,1618335934.413 [DataOverHttps] Loaded
2021-04-13T17:45:34.414Z,1618335934.414 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2021-04-13T17:45:34.415Z,1618335934.415 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 408974E0
2021-04-13T17:45:34.415Z,1618335934.415 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 9055
2021-04-13T17:45:34.434Z,1618335934.434 [Depth_Keller] Loaded
2021-04-13T17:45:34.434Z,1618335934.434 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2021-04-13T17:45:34.439Z,1618335934.439 [DropWeight] Loaded
2021-04-13T17:45:34.439Z,1618335934.439 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2021-04-13T17:45:34.473Z,1618335934.473 [DVL_micro] Loaded
2021-04-13T17:45:34.473Z,1618335934.473 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread.
2021-04-13T17:45:34.530Z,1618335934.530 [NAL9602] Loaded
2021-04-13T17:45:34.530Z,1618335934.530 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2021-04-13T17:45:34.558Z,1618335934.558 [Onboard] Loaded
2021-04-13T17:45:34.558Z,1618335934.558 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2021-04-13T17:45:34.559Z,1618335934.559 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 408C74E0
2021-04-13T17:45:34.559Z,1618335934.559 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 9056
2021-04-13T17:45:34.572Z,1618335934.572 [Radio_Surface] Loaded
2021-04-13T17:45:34.572Z,1618335934.572 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2021-04-13T17:45:34.573Z,1618335934.573 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408F74E0
2021-04-13T17:45:34.573Z,1618335934.573 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 9057
2021-04-13T17:45:34.653Z,1618335934.653 [DAT] Loaded
2021-04-13T17:45:34.653Z,1618335934.653 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread.
2021-04-13T17:45:34.653Z,1618335934.653 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2021-04-13T17:45:34.654Z,1618335934.654 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2021-04-13T17:45:34.770Z,1618335934.770 [BuoyancyServo] Loaded
2021-04-13T17:45:34.770Z,1618335934.770 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2021-04-13T17:45:34.789Z,1618335934.789 [ElevatorServo] Loaded
2021-04-13T17:45:34.789Z,1618335934.789 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2021-04-13T17:45:34.807Z,1618335934.807 [MassServo] Loaded
2021-04-13T17:45:34.808Z,1618335934.808 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2021-04-13T17:45:34.825Z,1618335934.825 [RudderServo] Loaded
2021-04-13T17:45:34.825Z,1618335934.825 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2021-04-13T17:45:34.842Z,1618335934.842 [ThrusterServo] Loaded
2021-04-13T17:45:34.842Z,1618335934.842 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2021-04-13T17:45:34.843Z,1618335934.843 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2021-04-13T17:45:34.843Z,1618335934.843 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2021-04-13T17:45:34.897Z,1618335934.897 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2021-04-13T17:45:34.897Z,1618335934.897 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2021-04-13T17:45:34.930Z,1618335934.930 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2021-04-13T17:45:34.931Z,1618335934.931 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2021-04-13T17:45:35.238Z,1618335935.238 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2021-04-13T17:45:35.238Z,1618335935.238 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2021-04-13T17:45:35.384Z,1618335935.384 [ESPComponent] Loaded
2021-04-13T17:45:35.384Z,1618335935.384 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2021-04-13T17:45:35.403Z,1618335935.403 [PAR_Licor] Loaded
2021-04-13T17:45:35.403Z,1618335935.403 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2021-04-13T17:45:35.435Z,1618335935.435 [WetLabsBB2FL] Loaded
2021-04-13T17:45:35.435Z,1618335935.435 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2021-04-13T17:45:35.436Z,1618335935.436 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40A7F4E0
2021-04-13T17:45:35.436Z,1618335935.436 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 9058
2021-04-13T17:45:35.437Z,1618335935.437 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2021-04-13T17:45:35.438Z,1618335935.438 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2021-04-13T17:45:35.573Z,1618335935.573 [SBIT](DEBUG): Construct Startup Built In Test.
2021-04-13T17:45:35.582Z,1618335935.582 [SBIT] Loaded
2021-04-13T17:45:35.582Z,1618335935.582 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2021-04-13T17:45:35.585Z,1618335935.585 [IBIT](DEBUG): Construct Initiated Built In Test.
2021-04-13T17:45:35.598Z,1618335935.598 [IBIT] Loaded
2021-04-13T17:45:35.598Z,1618335935.598 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2021-04-13T17:45:35.604Z,1618335935.604 [CBIT](DEBUG): Construct Continuous Built In Test.
2021-04-13T17:45:35.703Z,1618335935.703 [CBIT] Loaded
2021-04-13T17:45:35.704Z,1618335935.704 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2021-04-13T17:45:35.704Z,1618335935.704 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2021-04-13T17:45:35.775Z,1618335935.775 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2021-04-13T17:45:35.777Z,1618335935.777 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2021-04-13T17:45:35.823Z,1618335935.823 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2021-04-13T17:45:35.824Z,1618335935.824 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40AEB4E0
2021-04-13T17:45:35.825Z,1618335935.825 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 9059
2021-04-13T17:45:35.838Z,1618335935.838 [Supervisor](INFO): Main Thread ID is 815
2021-04-13T17:45:35.838Z,1618335935.838 [Supervisor](DEBUG): Running supervisor.
2021-04-13T17:45:35.838Z,1618335935.838 [CommandLine ThreadHandler](INFO): Handler Thread ID is 9060
2021-04-13T17:45:35.842Z,1618335935.842 [controlThread ThreadHandler](INFO): Handler Thread ID is 9061
2021-04-13T17:45:35.843Z,1618335935.843 [controlThread](DEBUG): Initializing ControlThread
2021-04-13T17:45:35.843Z,1618335935.843 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2021-04-13T17:45:35.844Z,1618335935.844 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2021-04-13T17:45:35.844Z,1618335935.844 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2021-04-13T17:45:35.844Z,1618335935.844 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2021-04-13T17:45:35.845Z,1618335935.845 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2021-04-13T17:45:35.845Z,1618335935.845 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2021-04-13T17:45:35.846Z,1618335935.846 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2021-04-13T17:45:35.847Z,1618335935.847 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2021-04-13T17:45:35.848Z,1618335935.848 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2021-04-13T17:45:35.848Z,1618335935.848 [LoopControl](DEBUG): Initialize LoopControlComponent.
2021-04-13T17:45:35.849Z,1618335935.849 [NavChart](DEBUG): Initialize NavChart Navigation.
2021-04-13T17:45:35.850Z,1618335935.850 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2021-04-13T17:45:35.862Z,1618335935.862 [SBIT](INFO): Initialize SBIT Component.
2021-04-13T17:45:35.863Z,1618335935.863 [SBIT](IMPORTANT): git: 2021-04-12
2021-04-13T17:45:35.863Z,1618335935.863 [SBIT](INFO): git hash: 4d37ca66b772b9605b4b6eba7ca05c94731fcf29
2021-04-13T17:45:35.863Z,1618335935.863 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2021-04-13T17:45:35.864Z,1618335935.864 [SBIT](IMPORTANT): Kernel Version:#1 PREEMPT Tue Sep 24 11:12:27 PDT 2019
2021-04-13T17:45:35.865Z,1618335935.865 [SBIT](INFO): Beginning SBIT in 24.000000 seconds.
2021-04-13T17:45:35.866Z,1618335935.866 [IBIT](INFO): Initialize IBIT Component.
2021-04-13T17:45:35.867Z,1618335935.867 [CBIT](DEBUG): Initialize CBIT Component.
2021-04-13T17:45:35.878Z,1618335935.878 [CBIT](DEBUG): Initialized mux pins.
2021-04-13T17:45:35.878Z,1618335935.878 [CBIT](DEBUG): Initializing the watchdog timer.
2021-04-13T17:45:35.902Z,1618335935.902 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2021-04-13T17:45:35.902Z,1618335935.902 [CBIT](DEBUG): Initializing heartbeat.
2021-04-13T17:45:35.906Z,1618335935.906 [logger ThreadHandler](INFO): Handler Thread ID is 9062
2021-04-13T17:45:35.930Z,1618335935.930 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 9063
2021-04-13T17:45:35.931Z,1618335935.931 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 9064
2021-04-13T17:45:35.932Z,1618335935.932 [Onboard ThreadHandler](INFO): Handler Thread ID is 9065
2021-04-13T17:45:35.958Z,1618335935.958 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2021-04-13T17:45:35.974Z,1618335935.974 [CBIT](DEBUG): Deactivating GF circuits.
2021-04-13T17:45:35.974Z,1618335935.974 [CBIT](DEBUG): Deactivating emergency mode.
2021-04-13T17:45:35.976Z,1618335935.976 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 9067
2021-04-13T17:45:35.983Z,1618335935.983 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 9069
2021-04-13T17:45:36.002Z,1618335936.002 [WetLabsBB2FL](INFO): Powering up
2021-04-13T17:45:36.003Z,1618335936.003 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 9066
2021-04-13T17:45:36.010Z,1618335936.010 [CBIT](DEBUG): Backplane powered.
2021-04-13T17:45:36.011Z,1618335936.011 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2021-04-13T17:45:36.142Z,1618335936.142 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2021-04-13T17:45:36.142Z,1618335936.142 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2021-04-13T17:45:36.142Z,1618335936.142 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2021-04-13T17:45:36.143Z,1618335936.143 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2021-04-13T17:45:36.143Z,1618335936.143 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2021-04-13T17:45:36.143Z,1618335936.143 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2021-04-13T17:45:36.143Z,1618335936.143 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2021-04-13T17:45:36.143Z,1618335936.143 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2021-04-13T17:45:36.143Z,1618335936.143 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2021-04-13T17:45:36.143Z,1618335936.143 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2021-04-13T17:45:36.144Z,1618335936.144 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2021-04-13T17:45:36.144Z,1618335936.144 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2021-04-13T17:45:36.144Z,1618335936.144 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2021-04-13T17:45:36.144Z,1618335936.144 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2021-04-13T17:45:36.144Z,1618335936.144 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2021-04-13T17:45:36.144Z,1618335936.144 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2021-04-13T17:45:36.161Z,1618335936.161 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2021-04-13T17:45:36.193Z,1618335936.193 [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-04-13T17:45:36.193Z,1618335936.193 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2021-04-13T17:45:36.364Z,1618335936.364 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2021-04-13T17:45:36.382Z,1618335936.382 [Default:A.Wait](DEBUG): Construct Wait.
2021-04-13T17:45:36.384Z,1618335936.384 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2021-04-13T17:45:36.406Z,1618335936.406 [Radio_Surface](INFO): Powering up
2021-04-13T17:45:36.415Z,1618335936.415 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2021-04-13T17:45:36.418Z,1618335936.418 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2021-04-13T17:45:36.440Z,1618335936.440 [Default:E.Execute](DEBUG): Construct Execute.
2021-04-13T17:45:36.443Z,1618335936.443 [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-04-13T17:45:36.462Z,1618335936.462 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,DVL_micro,NAL9602,DAT,ESPComponent,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,LcmUniversalReporter,Reporter,LogSplitter,
2021-04-13T17:45:36.481Z,1618335936.481 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2021-04-13T17:45:36.701Z,1618335936.701 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2
2021-04-13T17:45:36.701Z,1618335936.701 [DAT](INFO): Powering up
2021-04-13T17:45:36.701Z,1618335936.701 [DAT](DEBUG): Initializing DAT.
2021-04-13T17:45:36.738Z,1618335936.738 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2
2021-04-13T17:45:36.783Z,1618335936.783 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2021-04-13T17:45:36.786Z,1618335936.786 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2021-04-13T17:45:36.787Z,1618335936.787 [ElevatorServo](DEBUG): Initializing EZServoServo.
2021-04-13T17:45:36.798Z,1618335936.798 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2021-04-13T17:45:36.799Z,1618335936.799 [MassServo](DEBUG): Initializing EZServoServo.
2021-04-13T17:45:36.811Z,1618335936.811 [MassServo](DEBUG): Initializing MassServo.
2021-04-13T17:45:36.812Z,1618335936.812 [RudderServo](DEBUG): Initializing EZServoServo.
2021-04-13T17:45:36.822Z,1618335936.822 [RudderServo](DEBUG): Initializing RudderServo.
2021-04-13T17:45:36.823Z,1618335936.823 [ThrusterServo](DEBUG): Initializing EZServoServo.
2021-04-13T17:45:36.834Z,1618335936.834 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2021-04-13T17:45:38.594Z,1618335938.594 [WetLabsBB2FL](INFO): Powering down
2021-04-13T17:46:00.342Z,1618335960.342 [SBIT](IMPORTANT): Beginning Startup BIT
2021-04-13T17:46:00.350Z,1618335960.350 [CBIT](IMPORTANT): Beginning ground fault scan
2021-04-13T17:46:04.752Z,1618335964.752 [NAL9602](INFO): Powering up NAL9602
2021-04-13T17:46:11.282Z,1618335971.282 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): 0.000718
CHAN A1 (24V): 0.004754
CHAN A2 (12V): 0.002939
CHAN A3 (5V): 0.000728
CHAN B0 (3.3V): -0.000244
CHAN B1 (3.15aV): -0.000388
CHAN B2 (3.15bV): 0.000774
CHAN B3 (GND): -0.001525
OPEN: 0.003825
Full Scale Calc: 4.765 mA, -1.589 mA
2021-04-13T17:46:15.660Z,1618335975.660 [NAL9602](INFO): NAL9602 initialized
2021-04-13T17:46:37.105Z,1618335997.105 [DAT](FAULT): failed to initialize, no bytes available on serial interface
2021-04-13T17:46:37.105Z,1618335997.105 [DAT] Communications Fault, FailCount= 1
2021-04-13T17:46:37.105Z,1618335997.105 [DAT](ERROR): Communications Fault
2021-04-13T17:46:37.158Z,1618335997.158 [CBIT](ERROR): Communications Fault in component: DAT
2021-04-13T17:46:37.493Z,1618335997.493 [DAT](INFO): Powering down
2021-04-13T17:46:38.325Z,1618335998.325 [CBIT](INFO): Clearing failed state for component DAT
2021-04-13T17:46:38.325Z,1618335998.325 [DAT] No Fault, FailCount= 1
2021-04-13T17:46:40.719Z,1618336000.719 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2
2021-04-13T17:46:40.719Z,1618336000.719 [DAT](INFO): Powering up
2021-04-13T17:46:40.719Z,1618336000.719 [DAT](DEBUG): Initializing DAT.
2021-04-13T17:46:40.775Z,1618336000.775 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2
2021-04-13T17:46:54.465Z,1618336014.465 [SBIT](IMPORTANT): SBIT PASSED
2021-04-13T17:46:54.465Z,1618336014.465 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2021-04-13T17:46:54.482Z,1618336014.482 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=2 count;

2021-04-13T17:46:54.482Z,1618336014.482 [SBIT](IMPORTANT): BackseatComponent.loadAtStartup=1 bool;

2021-04-13T17:46:54.483Z,1618336014.483 [SBIT](IMPORTANT): BackseatComponent.simulateHardware=1 bool;

2021-04-13T17:46:54.483Z,1618336014.483 [SBIT](IMPORTANT): CTD_Seabird.loadAtStartup=0 bool;

2021-04-13T17:46:54.483Z,1618336014.483 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=214.815570 cubic_centimeter;

2021-04-13T17:46:54.483Z,1618336014.483 [SBIT](IMPORTANT): VerticalControl.massDefault=-1.247810 millimeter;

2021-04-13T17:46:54.868Z,1618336014.868 [MissionManager](IMPORTANT): Started mission Startup
2021-04-13T17:46:54.869Z,1618336014.869 [Startup] Running Loop=1
2021-04-13T17:46:54.869Z,1618336014.869 [Startup](DEBUG): Aggregate::initialize Startup
2021-04-13T17:46:54.869Z,1618336014.869 [Startup:A.GoToSurface] Running Loop=1
2021-04-13T17:46:54.869Z,1618336014.869 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2021-04-13T17:46:54.870Z,1618336014.870 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2021-04-13T17:46:54.870Z,1618336014.870 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2021-04-13T17:46:54.871Z,1618336014.871 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2021-04-13T17:46:54.871Z,1618336014.871 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2021-04-13T17:46:54.871Z,1618336014.871 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2021-04-13T17:46:54.873Z,1618336014.873 [Startup:StartupSatComms] Running Loop=1
2021-04-13T17:46:54.873Z,1618336014.873 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2021-04-13T17:46:54.873Z,1618336014.873 [Startup:StartupSatComms:A] Running Loop=1
2021-04-13T17:46:55.272Z,1618336015.272 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2021-04-13T17:46:59.707Z,1618336019.707 [NAL9602](INFO): SBD MO Status=0, MOMSN=1982, MT Status=0, MTMSN=0
2021-04-13T17:46:59.708Z,1618336019.708 [NAL9602](INFO): No messages in MT queue
2021-04-13T17:47:00.927Z,1618336020.927 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174659.00,A,3648.13966,N,12147.20849,W,0.019,0.00,130421,,,A*7D
2021-04-13T17:47:00.930Z,1618336020.930 [NAL9602](INFO): GPS fix at 20210413T174659: (36.802328, -121.786808)
2021-04-13T17:47:00.941Z,1618336020.941 [Startup:StartupSatComms:A] Stopped
2021-04-13T17:47:00.941Z,1618336020.941 [Startup:StartupSatComms:B] Running Loop=1
2021-04-13T17:47:01.361Z,1618336021.361 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2021-04-13T17:47:08.572Z,1618336028.572 [DVL_micro](ERROR): Failed to parse:
:SA,-01.68,-00.54,235.6
2021-04-13T17:47:12.209Z,1618336032.209 [NAL9602](INFO): SBD MO Status=1, MOMSN=1983, MT Status=0, MTMSN=0
2021-04-13T17:47:12.264Z,1618336032.264 [NAL9602](INFO): Sent 39 bytes from file Logs/20210413T171631/Courier0024.lzma
2021-04-13T17:47:12.265Z,1618336032.265 [NAL9602](INFO): Packets left to send: 0
2021-04-13T17:47:21.106Z,1618336041.106 [DVL_micro](ERROR): only read 3 of 4 data items
2021-04-13T17:47:21.106Z,1618336041.106 [DVL_micro](ERROR): Failed to parse:
:BI,-00419,00263,+00000,I
2021-04-13T17:47:27.903Z,1618336047.903 [NAL9602](INFO): SBD MO Status=1, MOMSN=1984, MT Status=0, MTMSN=0
2021-04-13T17:47:27.948Z,1618336047.948 [NAL9602](INFO): Sent 265 bytes from file Logs/20210413T174526/Courier0000.lzma
2021-04-13T17:47:27.949Z,1618336047.949 [NAL9602](INFO): Packets left to send: 0
2021-04-13T17:47:40.852Z,1618336060.852 [DAT](FAULT): failed to initialize, no bytes available on serial interface
2021-04-13T17:47:40.852Z,1618336060.852 [DAT] Communications Fault, FailCount= 2
2021-04-13T17:47:40.852Z,1618336060.852 [DAT](ERROR): Communications Fault
2021-04-13T17:47:40.905Z,1618336060.905 [CBIT](ERROR): Communications Fault in component: DAT
2021-04-13T17:47:41.260Z,1618336061.260 [DAT](INFO): Powering down
2021-04-13T17:47:42.064Z,1618336062.064 [CBIT](INFO): Clearing failed state for component DAT
2021-04-13T17:47:42.064Z,1618336062.064 [DAT] No Fault, FailCount= 2
2021-04-13T17:47:44.475Z,1618336064.475 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2
2021-04-13T17:47:44.475Z,1618336064.475 [DAT](INFO): Powering up
2021-04-13T17:47:44.476Z,1618336064.476 [DAT](DEBUG): Initializing DAT.
2021-04-13T17:47:44.567Z,1618336064.567 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2
2021-04-13T17:47:48.107Z,1618336068.107 [NAL9602](INFO): SBD MO Status=2, MOMSN=1985, MT Status=2, MTMSN=0
2021-04-13T17:47:48.107Z,1618336068.107 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-04-13T17:48:01.101Z,1618336081.101 [Startup:StartupSatComms:B](INFO): Timed out from 2021-04-13T17:47:00.9Z
2021-04-13T17:48:01.101Z,1618336081.101 [Startup:StartupSatComms:B] Stopped
2021-04-13T17:48:01.101Z,1618336081.101 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2021-04-13T17:48:01.101Z,1618336081.101 [Startup:StartupSatComms] Stopped
2021-04-13T17:48:01.101Z,1618336081.101 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2021-04-13T17:48:01.112Z,1618336081.112 [Startup](INFO): Completed Startup
2021-04-13T17:48:01.112Z,1618336081.112 [MissionManager](INFO): Startup is completed.
2021-04-13T17:48:01.113Z,1618336081.113 [MissionManager](INFO): Uninitializing Mission Startup
2021-04-13T17:48:01.113Z,1618336081.113 [Startup] Stopped
2021-04-13T17:48:01.122Z,1618336081.122 [Startup](DEBUG): Aggregate::uninitialize Startup
2021-04-13T17:48:01.122Z,1618336081.122 [Startup:A.GoToSurface] Stopped
2021-04-13T17:48:01.122Z,1618336081.122 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2021-04-13T17:48:01.471Z,1618336081.471 [MissionManager](IMPORTANT): Started mission Default
2021-04-13T17:48:01.471Z,1618336081.471 [Default] Running Loop=1
2021-04-13T17:48:01.471Z,1618336081.471 [Default](DEBUG): Aggregate::initialize Default
2021-04-13T17:48:01.471Z,1618336081.471 [Default:B.GoToSurface] Running Loop=1
2021-04-13T17:48:01.471Z,1618336081.471 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2021-04-13T17:48:01.472Z,1618336081.472 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2021-04-13T17:48:01.472Z,1618336081.472 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2021-04-13T17:48:01.472Z,1618336081.472 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2021-04-13T17:48:01.472Z,1618336081.472 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2021-04-13T17:48:01.473Z,1618336081.473 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2021-04-13T17:48:01.473Z,1618336081.473 [Default:A.Wait] Running Loop=1
2021-04-13T17:48:01.473Z,1618336081.473 [Default:A.Wait](DEBUG): Initialize Wait Component.
2021-04-13T17:48:14.826Z,1618336094.826 [Default:A.Wait](INFO): Done Waiting.
2021-04-13T17:48:14.826Z,1618336094.826 [Default:A.Wait] Stopped
2021-04-13T17:48:14.826Z,1618336094.826 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2021-04-13T17:48:15.205Z,1618336095.205 [Default:CheckIn] Running Loop=1
2021-04-13T17:48:15.205Z,1618336095.205 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-13T17:48:15.206Z,1618336095.206 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-13T17:48:15.610Z,1618336095.610 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2021-04-13T17:48:16.803Z,1618336096.803 [NAL9602](INFO): SBD MO Status=1, MOMSN=1985, MT Status=0, MTMSN=0
2021-04-13T17:48:16.862Z,1618336096.862 [NAL9602](INFO): Sent 332 bytes from file Logs/20210413T171631/Express0025.lzma
2021-04-13T17:48:16.862Z,1618336096.862 [NAL9602](INFO): Packets left to send: 1
2021-04-13T17:48:18.021Z,1618336098.021 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174816.00,A,3648.13957,N,12147.20805,W,0.039,0.00,130421,,,A*70
2021-04-13T17:48:18.023Z,1618336098.023 [NAL9602](INFO): GPS fix at 20210413T174816: (36.802326, -121.786801)
2021-04-13T17:48:18.034Z,1618336098.034 [Default:CheckIn:Read_GPS] Stopped
2021-04-13T17:48:18.034Z,1618336098.034 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-13T17:48:18.448Z,1618336098.448 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2021-04-13T17:48:34.805Z,1618336114.805 [NAL9602](INFO): SBD MO Status=1, MOMSN=1986, MT Status=0, MTMSN=0
2021-04-13T17:48:34.854Z,1618336114.854 [NAL9602](INFO): Sent 71 bytes from file Logs/20210413T174526/Courier0004.lzma
2021-04-13T17:48:34.854Z,1618336114.854 [NAL9602](INFO): Packets left to send: 0
2021-04-13T17:48:39.900Z,1618336119.900 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.008454
2021-04-13T17:48:44.764Z,1618336124.764 [DAT](FAULT): failed to initialize, no bytes available on serial interface
2021-04-13T17:48:44.764Z,1618336124.764 [DAT] Communications Fault, FailCount= 3
2021-04-13T17:48:44.764Z,1618336124.764 [DAT](ERROR): Communications Fault
2021-04-13T17:48:44.831Z,1618336124.831 [CBIT](ERROR): Communications Fault in component: DAT
2021-04-13T17:48:45.168Z,1618336125.168 [DAT](INFO): Powering down
2021-04-13T17:48:46.023Z,1618336126.023 [CBIT](INFO): Clearing failed state for component DAT
2021-04-13T17:48:46.023Z,1618336126.023 [DAT] No Fault, FailCount= 3
2021-04-13T17:48:46.781Z,1618336126.781 [NAL9602](INFO): SBD MO Status=1, MOMSN=1987, MT Status=0, MTMSN=0
2021-04-13T17:48:46.834Z,1618336126.834 [NAL9602](INFO): Sent 55 bytes from file Logs/20210413T171631/Express0025.lzma
2021-04-13T17:48:46.834Z,1618336126.834 [NAL9602](INFO): Packets left to send: 0
2021-04-13T17:48:46.889Z,1618336126.889 [Default:CheckIn:Read_Iridium] Stopped
2021-04-13T17:48:46.889Z,1618336126.889 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-13T17:48:46.898Z,1618336126.898 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-13T17:48:48.411Z,1618336128.411 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2
2021-04-13T17:48:48.411Z,1618336128.411 [DAT](INFO): Powering up
2021-04-13T17:48:48.412Z,1618336128.412 [DAT](DEBUG): Initializing DAT.
2021-04-13T17:48:48.464Z,1618336128.464 [DataOverHttps](IMPORTANT): Could not stat file Logs/20210413T171631/Express0025.lzma
2021-04-13T17:48:48.464Z,1618336128.464 [DataOverHttps](FAULT): Could not open file Logs/20210413T171631/Express0025.lzma
2021-04-13T17:48:48.502Z,1618336128.502 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2
2021-04-13T17:48:57.216Z,1618336137.216 [DataOverHttps](IMPORTANT): Could not stat file Logs/20210413T171631/Express0025.lzma
2021-04-13T17:48:57.216Z,1618336137.216 [DataOverHttps](FAULT): Could not open file Logs/20210413T171631/Express0025.lzma
2021-04-13T17:49:17.487Z,1618336157.487 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-13T17:49:32.880Z,1618336172.880 [DataOverHttps](IMPORTANT): Could not stat file Logs/20210413T171631/Express0025.lzma
2021-04-13T17:49:32.880Z,1618336172.880 [DataOverHttps](FAULT): Could not open file Logs/20210413T171631/Express0025.lzma
2021-04-13T17:49:48.601Z,1618336188.601 [DAT](FAULT): failed to initialize, no bytes available on serial interface
2021-04-13T17:49:48.601Z,1618336188.601 [DAT] Communications Fault, FailCount= 4
2021-04-13T17:49:48.601Z,1618336188.601 [DAT](ERROR): Communications Fault
2021-04-13T17:49:48.620Z,1618336188.620 [CBIT](ERROR): Communications Fault in component: DAT
2021-04-13T17:49:48.996Z,1618336188.996 [DAT](INFO): Powering down
2021-04-13T17:49:49.839Z,1618336189.839 [CBIT](INFO): Clearing failed state for component DAT
2021-04-13T17:49:49.839Z,1618336189.839 [DAT] No Fault, FailCount= 4
2021-04-13T17:49:52.272Z,1618336192.272 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2
2021-04-13T17:49:52.272Z,1618336192.272 [DAT](INFO): Powering up
2021-04-13T17:49:52.272Z,1618336192.272 [DAT](DEBUG): Initializing DAT.
2021-04-13T17:49:52.329Z,1618336192.329 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2
2021-04-13T17:50:11.372Z,1618336211.372 [DataOverHttps](IMPORTANT): Could not stat file Logs/20210413T171631/Express0025.lzma
2021-04-13T17:50:11.372Z,1618336211.372 [DataOverHttps](FAULT): Could not open file Logs/20210413T171631/Express0025.lzma
2021-04-13T17:50:43.800Z,1618336243.800 [DataOverHttps](IMPORTANT): Could not stat file Logs/20210413T171631/Express0025.lzma
2021-04-13T17:50:43.800Z,1618336243.800 [DataOverHttps](FAULT): Could not open file Logs/20210413T171631/Express0025.lzma
2021-04-13T17:50:52.534Z,1618336252.534 [DAT](FAULT): failed to initialize, no bytes available on serial interface
2021-04-13T17:50:52.534Z,1618336252.534 [DAT] Communications Fault, FailCount= 5
2021-04-13T17:50:52.534Z,1618336252.534 [DAT](ERROR): Communications Fault
2021-04-13T17:50:52.552Z,1618336252.552 [CBIT](ERROR): Communications Fault in component: DAT
2021-04-13T17:50:52.949Z,1618336252.949 [DAT](INFO): Powering down
2021-04-13T17:50:53.772Z,1618336253.772 [CBIT](INFO): Clearing failed state for component DAT
2021-04-13T17:50:53.772Z,1618336253.772 [DAT] No Fault, FailCount= 5
2021-04-13T17:50:56.200Z,1618336256.200 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2
2021-04-13T17:50:56.200Z,1618336256.200 [DAT](INFO): Powering up
2021-04-13T17:50:56.200Z,1618336256.200 [DAT](DEBUG): Initializing DAT.
2021-04-13T17:50:56.271Z,1618336256.271 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2
2021-04-13T17:51:19.492Z,1618336279.492 [DataOverHttps](IMPORTANT): Could not stat file Logs/20210413T171631/Express0025.lzma
2021-04-13T17:51:19.492Z,1618336279.492 [DataOverHttps](FAULT): Could not open file Logs/20210413T171631/Express0025.lzma
2021-04-13T17:51:39.814Z,1618336299.814 [DAT](INFO): unknown deviceResponse_: Acoustic Wakeup

2021-04-13T17:51:39.815Z,1618336299.815 [DAT](INFO): commRate: 800
2021-04-13T17:51:40.616Z,1618336300.616 [DAT](INFO): unknown deviceResponse_: Lowpower

2021-04-13T17:51:41.834Z,1618336301.834 [DAT](INFO): entering command mode
2021-04-13T17:51:42.239Z,1618336302.239 [DAT](INFO): commRate: 800
2021-04-13T17:51:44.252Z,1618336304.252 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-13T17:51:44.669Z,1618336304.669 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-13T17:51:45.060Z,1618336305.060 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-13T17:51:45.464Z,1618336305.464 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-13T17:51:45.925Z,1618336305.925 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-13T17:51:46.382Z,1618336306.382 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-13T17:51:46.693Z,1618336306.693 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-13T17:51:47.116Z,1618336307.116 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-13T17:51:47.505Z,1618336307.505 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-13T17:51:47.892Z,1618336307.892 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-13T17:51:48.288Z,1618336308.288 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-13T17:51:48.690Z,1618336308.690 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-13T17:51:49.100Z,1618336309.100 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-13T17:51:49.506Z,1618336309.506 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-13T17:51:49.911Z,1618336309.911 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-13T17:51:50.312Z,1618336310.312 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-13T17:51:50.712Z,1618336310.712 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-13T17:51:51.116Z,1618336311.116 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-13T17:51:51.520Z,1618336311.520 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-13T17:51:51.923Z,1618336311.923 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-13T17:51:52.345Z,1618336312.345 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-13T17:51:52.737Z,1618336312.737 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-13T17:51:53.135Z,1618336313.135 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-13T17:51:53.540Z,1618336313.540 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-13T17:51:53.944Z,1618336313.944 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-13T17:51:54.348Z,1618336314.348 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-13T17:51:54.749Z,1618336314.749 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-13T17:51:55.170Z,1618336315.170 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-13T17:51:55.224Z,1618336315.224 [DataOverHttps](IMPORTANT): Could not stat file Logs/20210413T171631/Express0025.lzma
2021-04-13T17:51:55.224Z,1618336315.224 [DataOverHttps](FAULT): Could not open file Logs/20210413T171631/Express0025.lzma
2021-04-13T17:51:55.560Z,1618336315.560 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-13T17:51:55.961Z,1618336315.961 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-13T17:51:56.376Z,1618336316.376 [DAT](FAULT): failed to initialize; deviceResponse_ loaded: 
, available: user:6>
2021-04-13T17:51:56.376Z,1618336316.376 [DAT] Communications Fault, FailCount= 6
2021-04-13T17:51:56.376Z,1618336316.376 [DAT](ERROR): Communications Fault
2021-04-13T17:51:56.399Z,1618336316.399 [CBIT](ERROR): Communications Fault in component: DAT
2021-04-13T17:51:56.772Z,1618336316.772 [DAT](INFO): Powering down
2021-04-13T17:51:57.631Z,1618336317.631 [CBIT](INFO): Clearing failed state for component DAT
2021-04-13T17:51:57.631Z,1618336317.631 [DAT] No Fault, FailCount= 6
2021-04-13T17:52:00.021Z,1618336320.021 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2
2021-04-13T17:52:00.021Z,1618336320.021 [DAT](INFO): Powering up
2021-04-13T17:52:00.022Z,1618336320.022 [DAT](DEBUG): Initializing DAT.
2021-04-13T17:52:00.102Z,1618336320.102 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2
2021-04-13T17:52:14.148Z,1618336334.148 [DAT](INFO): commRate: 800
2021-04-13T17:52:16.178Z,1618336336.178 [DAT](INFO): entering command mode
2021-04-13T17:52:16.593Z,1618336336.593 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-13T17:52:16.976Z,1618336336.976 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-13T17:52:17.388Z,1618336337.388 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-13T17:52:17.812Z,1618336337.812 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-13T17:52:18.204Z,1618336338.204 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-13T17:52:18.595Z,1618336338.595 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-13T17:52:18.999Z,1618336338.999 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-13T17:52:19.404Z,1618336339.404 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-13T17:52:19.812Z,1618336339.812 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-13T17:52:20.205Z,1618336340.205 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-13T17:52:20.629Z,1618336340.629 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-13T17:52:21.016Z,1618336341.016 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-13T17:52:21.424Z,1618336341.424 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-13T17:52:21.828Z,1618336341.828 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-13T17:52:22.230Z,1618336342.230 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-13T17:52:22.629Z,1618336342.629 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-13T17:52:23.045Z,1618336343.045 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-13T17:52:23.444Z,1618336343.444 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-13T17:52:23.845Z,1618336343.845 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-13T17:52:24.248Z,1618336344.248 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-13T17:52:24.650Z,1618336344.650 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-13T17:52:25.060Z,1618336345.060 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-13T17:52:25.459Z,1618336345.459 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-13T17:52:25.883Z,1618336345.883 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-13T17:52:26.272Z,1618336346.272 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-13T17:52:26.671Z,1618336346.671 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-13T17:52:27.080Z,1618336347.080 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-13T17:52:27.480Z,1618336347.480 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-13T17:52:27.884Z,1618336347.884 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-13T17:52:28.299Z,1618336348.299 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-13T17:52:28.696Z,1618336348.696 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-13T17:52:29.216Z,1618336349.216 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-13T17:52:29.634Z,1618336349.634 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-13T17:52:29.924Z,1618336349.924 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-13T17:52:30.336Z,1618336350.336 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-13T17:52:30.737Z,1618336350.737 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-13T17:52:31.036Z,1618336351.036 [DataOverHttps](IMPORTANT): Could not stat file Logs/20210413T171631/Express0025.lzma
2021-04-13T17:52:31.036Z,1618336351.036 [DataOverHttps](FAULT): Could not open file Logs/20210413T171631/Express0025.lzma
2021-04-13T17:52:31.123Z,1618336351.123 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-13T17:52:31.524Z,1618336351.524 [DAT](DEBUG): checking for command mode acknowledgment
2021-04-13T17:52:31.524Z,1618336351.524 [DAT](FAULT): failed to enter command mode
2021-04-13T17:52:31.932Z,1618336351.932 [DAT](INFO): entering command mode
2021-04-13T17:52:32.333Z,1618336352.333 [DAT](INFO): setting verbose to 3
2021-04-13T17:52:32.733Z,1618336352.733 [DAT](INFO): set verbose to 3
2021-04-13T17:52:32.734Z,1618336352.734 [DAT](INFO): setting DatVerbose to 27440
2021-04-13T17:52:33.135Z,1618336353.135 [DAT](INFO): set DatVerbose to 27440
2021-04-13T17:52:33.135Z,1618336353.135 [DAT](INFO): setting transmit power to 8
2021-04-13T17:52:33.558Z,1618336353.558 [DAT](INFO): set transmit power to 8
2021-04-13T17:52:33.559Z,1618336353.559 [DAT](INFO): setting local address to 8
2021-04-13T17:52:33.945Z,1618336353.945 [DAT](INFO): set local address to 8
2021-04-13T17:53:06.592Z,1618336386.592 [DataOverHttps](IMPORTANT): Could not stat file Logs/20210413T171631/Express0025.lzma
2021-04-13T17:53:06.592Z,1618336386.592 [DataOverHttps](FAULT): Could not open file Logs/20210413T171631/Express0025.lzma
2021-04-13T17:53:12.734Z,1618336392.734 [BPC1](ERROR): Battery stick #6 (s/n: 00CA) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0.
2021-04-13T17:53:12.735Z,1618336392.735 [BPC1](INFO): Calculating totals. Valid battery stick count: 55. Valid reserve battery stick count: 6.
2021-04-13T17:53:12.738Z,1618336392.738 [BPC1](INFO): Received data from all battery sticks.
2021-04-13T17:53:41.984Z,1618336421.984 [DataOverHttps](IMPORTANT): Could not stat file Logs/20210413T171631/Express0025.lzma
2021-04-13T17:53:41.984Z,1618336421.984 [DataOverHttps](FAULT): Could not open file Logs/20210413T171631/Express0025.lzma
2021-04-13T17:53:47.506Z,1618336427.506 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-13T17:53:47.506Z,1618336427.506 [Default:CheckIn:C.Wait] Stopped
2021-04-13T17:53:47.506Z,1618336427.506 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-13T17:53:47.506Z,1618336427.506 [Default:CheckIn:D] Running Loop=1
2021-04-13T17:53:47.893Z,1618336427.893 [Default:CheckIn:D] Stopped
2021-04-13T17:53:47.893Z,1618336427.893 [Default:CheckIn:E] Running Loop=1
2021-04-13T17:53:48.296Z,1618336428.296 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 5.773695 min 
2021-04-13T17:53:48.296Z,1618336428.296 [Default:CheckIn:E] Stopped
2021-04-13T17:53:48.296Z,1618336428.296 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-13T17:53:48.296Z,1618336428.296 [Default:CheckIn] Stopped
2021-04-13T17:53:48.296Z,1618336428.296 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-13T17:53:48.296Z,1618336428.296 [Default:CheckIn](INFO): Running loop #2
2021-04-13T17:53:48.296Z,1618336428.296 [Default:CheckIn] Running Loop=2
2021-04-13T17:53:48.296Z,1618336428.296 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-13T17:53:48.297Z,1618336428.297 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-13T17:53:50.309Z,1618336430.309 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175348.00,A,3648.14099,N,12147.20812,W,0.039,0.00,130421,,,D*7E
2021-04-13T17:53:50.311Z,1618336430.311 [NAL9602](INFO): GPS fix at 20210413T175348: (36.802350, -121.786802)
2021-04-13T17:53:50.322Z,1618336430.322 [Default:CheckIn:Read_GPS] Stopped
2021-04-13T17:53:50.322Z,1618336430.322 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-13T17:53:57.582Z,1618336437.582 [DataOverHttps](INFO): Sending 202 bytes from file Logs/20210413T174526/Courier0007.lzma
2021-04-13T17:53:58.584Z,1618336438.584 [DataOverHttps](INFO): Moved sent file to Logs/20210413T174526/Courier0007.lzma.bak
2021-04-13T17:53:58.584Z,1618336438.584 [DataOverHttps](INFO): SBD MOMSN=15565265
2021-04-13T17:54:12.585Z,1618336452.585 [NAL9602](INFO): SBD MO Status=2, MOMSN=1988, MT Status=2, MTMSN=0
2021-04-13T17:54:12.585Z,1618336452.585 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-04-13T17:54:21.492Z,1618336461.492 [DataOverHttps](INFO): Sending 932 bytes from file Logs/20210413T174526/Express0001.lzma
2021-04-13T17:54:22.492Z,1618336462.492 [DataOverHttps](INFO): Moved sent file to Logs/20210413T174526/Express0001.lzma.bak
2021-04-13T17:54:22.492Z,1618336462.492 [DataOverHttps](INFO): SBD MOMSN=15565268
2021-04-13T17:54:23.147Z,1618336463.147 [DVL_micro](ERROR): only read 1 of 4 data items
2021-04-13T17:54:23.147Z,1618336463.147 [DVL_micro](ERROR): Failed to parse:
:RD,+9999..99,+9999.99,+9999.99
2021-04-13T17:54:41.282Z,1618336481.282 [DataOverHttps](INFO): Sending 307 bytes from file Logs/20210413T174526/Express0005.lzma
2021-04-13T17:54:42.284Z,1618336482.284 [DataOverHttps](INFO): Moved sent file to Logs/20210413T174526/Express0005.lzma.bak
2021-04-13T17:54:42.284Z,1618336482.284 [DataOverHttps](INFO): SBD MOMSN=15565289
2021-04-13T17:54:49.413Z,1618336489.413 [NAL9602](INFO): SBD MO Status=0, MOMSN=1988, MT Status=0, MTMSN=0
2021-04-13T17:54:49.413Z,1618336489.413 [NAL9602](INFO): No messages in MT queue
2021-04-13T17:54:59.271Z,1618336499.271 [DataOverHttps](INFO): Sending 504 bytes from file Logs/20210413T174526/Express0008.lzma
2021-04-13T17:55:00.271Z,1618336500.271 [DataOverHttps](INFO): Moved sent file to Logs/20210413T174526/Express0008.lzma.bak
2021-04-13T17:55:00.272Z,1618336500.272 [DataOverHttps](INFO): SBD MOMSN=15565294
2021-04-13T17:55:01.530Z,1618336501.530 [DVL_micro](ERROR): Failed to parse:
:WI,-00146,00325,+0:BI,-00146,+0325,+000D,+0000000000000.00,+00000000.00,9999.99,000.00
2021-04-13T17:55:02.769Z,1618336502.769 [Default:CheckIn:Read_Iridium] Stopped
2021-04-13T17:55:02.769Z,1618336502.769 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-13T17:55:02.769Z,1618336502.769 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-13T17:55:20.111Z,1618336520.111 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-13T17:56:59.135Z,1618336619.135 [DVL_micro](ERROR): Failed to parse:
:.99,+9999.99,+9999.99,+9999.99
2021-04-13T17:57:22.149Z,1618336642.149 [DVL_micro](ERROR): Failed to parse:
:WI,-01697,+00062,-00665,+00000,A
2021-04-13T18:00:03.413Z,1618336803.413 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-13T18:00:03.413Z,1618336803.413 [Default:CheckIn:C.Wait] Stopped
2021-04-13T18:00:03.413Z,1618336803.413 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-13T18:00:03.438Z,1618336803.438 [Default:CheckIn:D] Running Loop=1
2021-04-13T18:00:03.814Z,1618336803.814 [Default:CheckIn:D] Stopped
2021-04-13T18:00:03.814Z,1618336803.814 [Default:CheckIn:E] Running Loop=1
2021-04-13T18:00:04.220Z,1618336804.220 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 12.039058 min 
2021-04-13T18:00:04.220Z,1618336804.220 [Default:CheckIn:E] Stopped
2021-04-13T18:00:04.220Z,1618336804.220 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-13T18:00:04.221Z,1618336804.221 [Default:CheckIn] Stopped
2021-04-13T18:00:04.221Z,1618336804.221 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-13T18:00:04.221Z,1618336804.221 [Default:CheckIn](INFO): Running loop #3
2021-04-13T18:00:04.221Z,1618336804.221 [Default:CheckIn] Running Loop=3
2021-04-13T18:00:04.221Z,1618336804.221 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-13T18:00:04.221Z,1618336804.221 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-13T18:00:06.217Z,1618336806.217 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180005.00,A,3648.14056,N,12147.20727,W,0.019,0.00,130421,,,D*76
2021-04-13T18:00:06.219Z,1618336806.219 [NAL9602](INFO): GPS fix at 20210413T180005: (36.802343, -121.786788)
2021-04-13T18:00:06.239Z,1618336806.239 [Default:CheckIn:Read_GPS] Stopped
2021-04-13T18:00:06.239Z,1618336806.239 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-13T18:00:17.782Z,1618336817.782 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210413T174526/Courier0010.lzma
2021-04-13T18:00:18.784Z,1618336818.784 [DataOverHttps](INFO): Moved sent file to Logs/20210413T174526/Courier0010.lzma.bak
2021-04-13T18:00:18.784Z,1618336818.784 [DataOverHttps](INFO): SBD MOMSN=15565330
2021-04-13T18:00:22.549Z,1618336822.549 [NAL9602](INFO): SBD MO Status=0, MOMSN=1989, MT Status=0, MTMSN=0
2021-04-13T18:00:22.549Z,1618336822.549 [NAL9602](INFO): No messages in MT queue
2021-04-13T18:00:36.750Z,1618336836.750 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20210413T174526/Express0011.lzma
2021-04-13T18:00:37.753Z,1618336837.753 [DataOverHttps](INFO): Moved sent file to Logs/20210413T174526/Express0011.lzma.bak
2021-04-13T18:00:37.753Z,1618336837.753 [DataOverHttps](INFO): SBD MOMSN=15565333
2021-04-13T18:00:39.948Z,1618336839.948 [Default:CheckIn:Read_Iridium] Stopped
2021-04-13T18:00:39.948Z,1618336839.948 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-13T18:00:39.949Z,1618336839.949 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-13T18:00:53.279Z,1618336853.279 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-13T18:04:32.390Z,1618337072.390 [DVL_micro](ERROR): DVL uart error: serial timeout
2021-04-13T18:04:32.390Z,1618337072.390 [DVL_micro] Communications Fault, FailCount= 1
2021-04-13T18:04:32.390Z,1618337072.390 [DVL_micro](ERROR): Communications Fault
2021-04-13T18:04:32.390Z,1618337072.390 [DVL_micro](ERROR): Failed to parse:
2021-04-13T18:04:32.415Z,1618337072.415 [CBIT](ERROR): Communications Fault in component: DVL_micro
2021-04-13T18:04:32.790Z,1618337072.790 [DVL_micro](INFO): Powering down
2021-04-13T18:04:33.566Z,1618337073.566 [CBIT](INFO): Clearing failed state for component DVL_micro
2021-04-13T18:04:33.566Z,1618337073.566 [DVL_micro] No Fault, FailCount= 1
2021-04-13T18:05:01.831Z,1618337101.831 [DVL_micro](ERROR): Failed to parse:
:WI,+00053,-00049,-00271,+00000,A
2021-04-13T18:05:40.615Z,1618337140.615 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-13T18:05:40.615Z,1618337140.615 [Default:CheckIn:C.Wait] Stopped
2021-04-13T18:05:40.615Z,1618337140.615 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-13T18:05:40.615Z,1618337140.615 [Default:CheckIn:D] Running Loop=1
2021-04-13T18:05:41.022Z,1618337141.022 [Default:CheckIn:D] Stopped
2021-04-13T18:05:41.022Z,1618337141.022 [Default:CheckIn:E] Running Loop=1
2021-04-13T18:05:41.428Z,1618337141.428 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 17.659186 min 
2021-04-13T18:05:41.428Z,1618337141.428 [Default:CheckIn:E] Stopped
2021-04-13T18:05:41.428Z,1618337141.428 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-13T18:05:41.428Z,1618337141.428 [Default:CheckIn] Stopped
2021-04-13T18:05:41.428Z,1618337141.428 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-13T18:05:41.428Z,1618337141.428 [Default:CheckIn](INFO): Running loop #4
2021-04-13T18:05:41.428Z,1618337141.428 [Default:CheckIn] Running Loop=4
2021-04-13T18:05:41.428Z,1618337141.428 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-13T18:05:41.428Z,1618337141.428 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-13T18:05:43.434Z,1618337143.434 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180542.00,A,3648.13950,N,12147.20700,W,0.039,0.00,130421,,,D*7F
2021-04-13T18:05:43.436Z,1618337143.436 [NAL9602](INFO): GPS fix at 20210413T180542: (36.802325, -121.786783)
2021-04-13T18:05:43.479Z,1618337143.479 [Default:CheckIn:Read_GPS] Stopped
2021-04-13T18:05:43.479Z,1618337143.479 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-13T18:05:50.721Z,1618337150.721 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210413T174526/Courier0013.lzma
2021-04-13T18:05:51.724Z,1618337151.724 [DataOverHttps](INFO): Moved sent file to Logs/20210413T174526/Courier0013.lzma.bak
2021-04-13T18:05:51.724Z,1618337151.724 [DataOverHttps](INFO): SBD MOMSN=15565338
2021-04-13T18:06:13.103Z,1618337173.103 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20210413T174526/Express0014.lzma
2021-04-13T18:06:14.104Z,1618337174.104 [DataOverHttps](INFO): Moved sent file to Logs/20210413T174526/Express0014.lzma.bak
2021-04-13T18:06:14.104Z,1618337174.104 [DataOverHttps](INFO): SBD MOMSN=15565341
2021-04-13T18:06:17.154Z,1618337177.154 [Default:CheckIn:Read_Iridium] Stopped
2021-04-13T18:06:17.155Z,1618337177.155 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-13T18:06:17.155Z,1618337177.155 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-13T18:06:28.461Z,1618337188.461 [NAL9602](INFO): SBD MO Status=0, MOMSN=1990, MT Status=0, MTMSN=0
2021-04-13T18:06:28.461Z,1618337188.461 [NAL9602](INFO): No messages in MT queue
2021-04-13T18:06:59.179Z,1618337219.179 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-13T18:11:17.825Z,1618337477.825 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-13T18:11:17.825Z,1618337477.825 [Default:CheckIn:C.Wait] Stopped
2021-04-13T18:11:17.830Z,1618337477.830 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-13T18:11:17.830Z,1618337477.830 [Default:CheckIn:D] Running Loop=1
2021-04-13T18:11:18.226Z,1618337478.226 [Default:CheckIn:D] Stopped
2021-04-13T18:11:18.227Z,1618337478.227 [Default:CheckIn:E] Running Loop=1
2021-04-13T18:11:18.648Z,1618337478.648 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 23.279258 min 
2021-04-13T18:11:18.648Z,1618337478.648 [Default:CheckIn:E] Stopped
2021-04-13T18:11:18.648Z,1618337478.648 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-13T18:11:18.648Z,1618337478.648 [Default:CheckIn] Stopped
2021-04-13T18:11:18.648Z,1618337478.648 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-13T18:11:18.648Z,1618337478.648 [Default:CheckIn](INFO): Running loop #5
2021-04-13T18:11:18.648Z,1618337478.648 [Default:CheckIn] Running Loop=5
2021-04-13T18:11:18.649Z,1618337478.649 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-13T18:11:18.649Z,1618337478.649 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-13T18:11:20.639Z,1618337480.639 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181119.00,A,3648.14040,N,12147.20692,W,0.039,0.00,130421,,,D*71
2021-04-13T18:11:20.641Z,1618337480.641 [NAL9602](INFO): GPS fix at 20210413T181119: (36.802340, -121.786782)
2021-04-13T18:11:20.680Z,1618337480.680 [Default:CheckIn:Read_GPS] Stopped
2021-04-13T18:11:20.680Z,1618337480.680 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-13T18:11:22.198Z,1618337482.198 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210413T174526/Courier0016.lzma
2021-04-13T18:11:22.539Z,1618337482.539 [DataOverHttps](INFO): Moved sent file to Logs/20210413T174526/Courier0016.lzma.bak
2021-04-13T18:11:22.540Z,1618337482.540 [DataOverHttps](INFO): SBD MOMSN=15565345
2021-04-13T18:11:29.925Z,1618337489.925 [NAL9602](INFO): SBD MO Status=0, MOMSN=1991, MT Status=0, MTMSN=0
2021-04-13T18:11:29.925Z,1618337489.925 [NAL9602](INFO): No messages in MT queue
2021-04-13T18:11:40.809Z,1618337500.809 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20210413T174526/Express0017.lzma
2021-04-13T18:11:41.836Z,1618337501.836 [DataOverHttps](INFO): Moved sent file to Logs/20210413T174526/Express0017.lzma.bak
2021-04-13T18:11:41.836Z,1618337501.836 [DataOverHttps](INFO): SBD MOMSN=15565348
2021-04-13T18:11:44.105Z,1618337504.105 [Default:CheckIn:Read_Iridium] Stopped
2021-04-13T18:11:44.105Z,1618337504.105 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-13T18:11:44.105Z,1618337504.105 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-13T18:12:00.624Z,1618337520.624 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-13T18:13:52.552Z,1618337632.552 [DVL_micro](ERROR): only read 1 of 4 data items
2021-04-13T18:13:52.552Z,1618337632.552 [DVL_micro](ERROR): Failed to parse:
:BI,-00046-00177,+00000,I
2021-04-13T18:15:32.757Z,1618337732.757 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2021-04-13T18:15:32.766Z,1618337732.766 [DVL_micro](ERROR): Failed to parse:
:TS,000000000000012.3,0000.0,1489.0,000
2021-04-13T18:16:44.759Z,1618337804.759 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-13T18:16:44.759Z,1618337804.759 [Default:CheckIn:C.Wait] Stopped
2021-04-13T18:16:44.759Z,1618337804.759 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-13T18:16:44.759Z,1618337804.759 [Default:CheckIn:D] Running Loop=1
2021-04-13T18:16:45.150Z,1618337805.150 [Default:CheckIn:D] Stopped
2021-04-13T18:16:45.150Z,1618337805.150 [Default:CheckIn:E] Running Loop=1
2021-04-13T18:16:45.554Z,1618337805.554 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 28.727991 min 
2021-04-13T18:16:45.554Z,1618337805.554 [Default:CheckIn:E] Stopped
2021-04-13T18:16:45.554Z,1618337805.554 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-13T18:16:45.554Z,1618337805.554 [Default:CheckIn] Stopped
2021-04-13T18:16:45.555Z,1618337805.555 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-13T18:16:45.555Z,1618337805.555 [Default:CheckIn](INFO): Running loop #6
2021-04-13T18:16:45.555Z,1618337805.555 [Default:CheckIn] Running Loop=6
2021-04-13T18:16:45.555Z,1618337805.555 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-13T18:16:45.555Z,1618337805.555 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-13T18:16:47.565Z,1618337807.565 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181646.00,A,3648.13894,N,12147.20980,W,0.117,0.00,130421,,,D*7B
2021-04-13T18:16:47.568Z,1618337807.568 [NAL9602](INFO): GPS fix at 20210413T181646: (36.802316, -121.786830)
2021-04-13T18:16:47.601Z,1618337807.601 [Default:CheckIn:Read_GPS] Stopped
2021-04-13T18:16:47.601Z,1618337807.601 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-13T18:16:55.333Z,1618337815.333 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210413T174526/Courier0019.lzma
2021-04-13T18:16:56.335Z,1618337816.335 [DataOverHttps](INFO): Moved sent file to Logs/20210413T174526/Courier0019.lzma.bak
2021-04-13T18:16:56.336Z,1618337816.336 [DataOverHttps](INFO): SBD MOMSN=15565352
2021-04-13T18:17:08.973Z,1618337828.973 [NAL9602](INFO): SBD MO Status=0, MOMSN=1992, MT Status=0, MTMSN=0
2021-04-13T18:17:08.973Z,1618337828.973 [NAL9602](INFO): No messages in MT queue
2021-04-13T18:17:13.146Z,1618337833.146 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20210413T174526/Express0020.lzma
2021-04-13T18:17:14.148Z,1618337834.148 [DataOverHttps](INFO): Moved sent file to Logs/20210413T174526/Express0020.lzma.bak
2021-04-13T18:17:14.148Z,1618337834.148 [DataOverHttps](INFO): SBD MOMSN=15565355
2021-04-13T18:17:16.266Z,1618337836.266 [Default:CheckIn:Read_Iridium] Stopped
2021-04-13T18:17:16.266Z,1618337836.266 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-13T18:17:16.266Z,1618337836.266 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-13T18:17:39.673Z,1618337859.673 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-13T18:18:19.727Z,1618337899.727 [DVL_micro](ERROR): only read 3 of 4 data items
2021-04-13T18:18:19.727Z,1618337899.727 [DVL_micro](ERROR): Failed to parse:
:BI,-00158,+00144,00000,I
2021-04-13T18:20:18.117Z,1618338018.117 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2021-04-13T18:20:18.117Z,1618338018.117 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0000.0,1489.0,000
2021-04-13T18:21:55.486Z,1618338115.486 [DVL_micro](ERROR): only read 3 of 4 data items
2021-04-13T18:21:55.486Z,1618338115.486 [DVL_micro](ERROR): Failed to parse:
:BI,00153,-00160,+00000,I
2021-04-13T18:22:17.029Z,1618338137.029 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-13T18:22:17.029Z,1618338137.029 [Default:CheckIn:C.Wait] Stopped
2021-04-13T18:22:17.029Z,1618338137.029 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-13T18:22:17.029Z,1618338137.029 [Default:CheckIn:D] Running Loop=1
2021-04-13T18:22:17.427Z,1618338137.427 [Default:CheckIn:D] Stopped
2021-04-13T18:22:17.427Z,1618338137.427 [Default:CheckIn:E] Running Loop=1
2021-04-13T18:22:17.791Z,1618338137.791 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 34.265930 min 
2021-04-13T18:22:17.791Z,1618338137.791 [Default:CheckIn:E] Stopped
2021-04-13T18:22:17.791Z,1618338137.791 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-13T18:22:17.791Z,1618338137.791 [Default:CheckIn] Stopped
2021-04-13T18:22:17.791Z,1618338137.791 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-13T18:22:17.792Z,1618338137.792 [Default:CheckIn](INFO): Running loop #7
2021-04-13T18:22:17.792Z,1618338137.792 [Default:CheckIn] Running Loop=7
2021-04-13T18:22:17.792Z,1618338137.792 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-13T18:22:17.792Z,1618338137.792 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-13T18:22:19.798Z,1618338139.798 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182219.00,A,3648.13952,N,12147.20781,W,0.019,0.00,130421,,,D*7D
2021-04-13T18:22:19.800Z,1618338139.800 [NAL9602](INFO): GPS fix at 20210413T182219: (36.802325, -121.786797)
2021-04-13T18:22:19.819Z,1618338139.819 [Default:CheckIn:Read_GPS] Stopped
2021-04-13T18:22:19.819Z,1618338139.819 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-13T18:22:28.945Z,1618338148.945 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210413T174526/Courier0022.lzma
2021-04-13T18:22:29.948Z,1618338149.948 [DataOverHttps](INFO): Moved sent file to Logs/20210413T174526/Courier0022.lzma.bak
2021-04-13T18:22:29.948Z,1618338149.948 [DataOverHttps](INFO): SBD MOMSN=15565359
2021-04-13T18:22:34.801Z,1618338154.801 [NAL9602](INFO): SBD MO Status=0, MOMSN=1993, MT Status=0, MTMSN=0
2021-04-13T18:22:34.801Z,1618338154.801 [NAL9602](INFO): No messages in MT queue
2021-04-13T18:22:46.950Z,1618338166.950 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20210413T174526/Express0023.lzma
2021-04-13T18:22:47.952Z,1618338167.952 [DataOverHttps](INFO): Moved sent file to Logs/20210413T174526/Express0023.lzma.bak
2021-04-13T18:22:47.952Z,1618338167.952 [DataOverHttps](INFO): SBD MOMSN=15565362
2021-04-13T18:22:50.175Z,1618338170.175 [Default:CheckIn:Read_Iridium] Stopped
2021-04-13T18:22:50.175Z,1618338170.175 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-13T18:22:50.175Z,1618338170.175 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-13T18:23:05.503Z,1618338185.503 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-13T18:23:32.992Z,1618338212.992 [DVL_micro](ERROR): only read 3 of 4 data items
2021-04-13T18:23:32.992Z,1618338212.992 [DVL_micro](ERROR): Failed to parse:
:RD,+9999.99,+9999.999,+9999.99
2021-04-13T18:27:50.793Z,1618338470.793 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-13T18:27:50.806Z,1618338470.806 [Default:CheckIn:C.Wait] Stopped
2021-04-13T18:27:50.806Z,1618338470.806 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-13T18:27:50.806Z,1618338470.806 [Default:CheckIn:D] Running Loop=1
2021-04-13T18:27:51.202Z,1618338471.202 [Default:CheckIn:D] Stopped
2021-04-13T18:27:51.202Z,1618338471.202 [Default:CheckIn:E] Running Loop=1
2021-04-13T18:27:51.606Z,1618338471.606 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 39.828849 min 
2021-04-13T18:27:51.606Z,1618338471.606 [Default:CheckIn:E] Stopped
2021-04-13T18:27:51.606Z,1618338471.606 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-13T18:27:51.606Z,1618338471.606 [Default:CheckIn] Stopped
2021-04-13T18:27:51.606Z,1618338471.606 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-13T18:27:51.606Z,1618338471.606 [Default:CheckIn](INFO): Running loop #8
2021-04-13T18:27:51.606Z,1618338471.606 [Default:CheckIn] Running Loop=8
2021-04-13T18:27:51.607Z,1618338471.607 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-13T18:27:51.607Z,1618338471.607 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-13T18:27:53.615Z,1618338473.615 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182752.00,A,3648.14152,N,12147.20783,W,0.000,0.00,130421,,,D*72
2021-04-13T18:27:53.617Z,1618338473.617 [NAL9602](INFO): GPS fix at 20210413T182752: (36.802359, -121.786797)
2021-04-13T18:27:53.628Z,1618338473.628 [Default:CheckIn:Read_GPS] Stopped
2021-04-13T18:27:53.628Z,1618338473.628 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-13T18:28:01.321Z,1618338481.321 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210413T174526/Courier0025.lzma
2021-04-13T18:28:02.324Z,1618338482.324 [DataOverHttps](INFO): Moved sent file to Logs/20210413T174526/Courier0025.lzma.bak
2021-04-13T18:28:02.324Z,1618338482.324 [DataOverHttps](INFO): SBD MOMSN=15565367
2021-04-13T18:28:11.053Z,1618338491.053 [NAL9602](INFO): SBD MO Status=0, MOMSN=1994, MT Status=0, MTMSN=0
2021-04-13T18:28:11.053Z,1618338491.053 [NAL9602](INFO): No messages in MT queue
2021-04-13T18:28:26.094Z,1618338506.094 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20210413T174526/Express0026.lzma
2021-04-13T18:28:27.096Z,1618338507.096 [DataOverHttps](INFO): Moved sent file to Logs/20210413T174526/Express0026.lzma.bak
2021-04-13T18:28:27.096Z,1618338507.096 [DataOverHttps](INFO): SBD MOMSN=15565370
2021-04-13T18:28:29.738Z,1618338509.738 [Default:CheckIn:Read_Iridium] Stopped
2021-04-13T18:28:29.738Z,1618338509.738 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-13T18:28:29.738Z,1618338509.738 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-13T18:28:41.839Z,1618338521.839 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-13T18:31:53.384Z,1618338713.384 [DVL_micro](ERROR): only read 3 of 4 data items
2021-04-13T18:31:53.384Z,1618338713.384 [DVL_micro](ERROR): Failed to parse:
:BI,-0003,-00174,+00000,I
2021-04-13T18:33:30.363Z,1618338810.363 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-13T18:33:30.363Z,1618338810.363 [Default:CheckIn:C.Wait] Stopped
2021-04-13T18:33:30.363Z,1618338810.363 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-13T18:33:30.363Z,1618338810.363 [Default:CheckIn:D] Running Loop=1
2021-04-13T18:33:30.778Z,1618338810.778 [Default:CheckIn:D] Stopped
2021-04-13T18:33:30.778Z,1618338810.778 [Default:CheckIn:E] Running Loop=1
2021-04-13T18:33:31.190Z,1618338811.190 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 45.488452 min 
2021-04-13T18:33:31.190Z,1618338811.190 [Default:CheckIn:E] Stopped
2021-04-13T18:33:31.190Z,1618338811.190 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-13T18:33:31.190Z,1618338811.190 [Default:CheckIn] Stopped
2021-04-13T18:33:31.190Z,1618338811.190 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-13T18:33:31.191Z,1618338811.191 [Default:CheckIn](INFO): Running loop #9
2021-04-13T18:33:31.191Z,1618338811.191 [Default:CheckIn] Running Loop=9
2021-04-13T18:33:31.191Z,1618338811.191 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-13T18:33:31.191Z,1618338811.191 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-13T18:33:33.189Z,1618338813.189 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183332.00,A,3648.14002,N,12147.20751,W,0.000,0.00,130421,,,D*7A
2021-04-13T18:33:33.192Z,1618338813.192 [NAL9602](INFO): GPS fix at 20210413T183332: (36.802334, -121.786792)
2021-04-13T18:33:33.203Z,1618338813.203 [Default:CheckIn:Read_GPS] Stopped
2021-04-13T18:33:33.203Z,1618338813.203 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-13T18:33:40.233Z,1618338820.233 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210413T174526/Courier0028.lzma
2021-04-13T18:33:41.236Z,1618338821.236 [DataOverHttps](INFO): Moved sent file to Logs/20210413T174526/Courier0028.lzma.bak
2021-04-13T18:33:41.236Z,1618338821.236 [DataOverHttps](INFO): SBD MOMSN=15565389
2021-04-13T18:33:47.429Z,1618338827.429 [NAL9602](INFO): SBD MO Status=0, MOMSN=1995, MT Status=0, MTMSN=0
2021-04-13T18:33:47.429Z,1618338827.429 [NAL9602](INFO): No messages in MT queue
2021-04-13T18:33:58.290Z,1618338838.290 [DataOverHttps](INFO): Sending 128 bytes from file Logs/20210413T174526/Express0029.lzma
2021-04-13T18:33:59.292Z,1618338839.292 [DataOverHttps](INFO): Moved sent file to Logs/20210413T174526/Express0029.lzma.bak
2021-04-13T18:33:59.292Z,1618338839.292 [DataOverHttps](INFO): SBD MOMSN=15565392
2021-04-13T18:34:01.604Z,1618338841.604 [Default:CheckIn:Read_Iridium] Stopped
2021-04-13T18:34:01.604Z,1618338841.604 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-13T18:34:01.604Z,1618338841.604 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-13T18:34:17.832Z,1618338857.832 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-13T18:38:34.898Z,1618339114.898 [DVL_micro](ERROR): Failed to parse:
:WI,-00196,-00110,-00107,+00000,A
2021-04-13T18:39:02.362Z,1618339142.362 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-13T18:39:02.362Z,1618339142.362 [Default:CheckIn:C.Wait] Stopped
2021-04-13T18:39:02.363Z,1618339142.363 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-13T18:39:02.363Z,1618339142.363 [Default:CheckIn:D] Running Loop=1
2021-04-13T18:39:02.795Z,1618339142.795 [Default:CheckIn:D] Stopped
2021-04-13T18:39:02.795Z,1618339142.795 [Default:CheckIn:E] Running Loop=1
2021-04-13T18:39:03.180Z,1618339143.180 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 51.022074 min 
2021-04-13T18:39:03.180Z,1618339143.180 [Default:CheckIn:E] Stopped
2021-04-13T18:39:03.180Z,1618339143.180 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-13T18:39:03.180Z,1618339143.180 [Default:CheckIn] Stopped
2021-04-13T18:39:03.180Z,1618339143.180 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-13T18:39:03.180Z,1618339143.180 [Default:CheckIn](INFO): Running loop #10
2021-04-13T18:39:03.180Z,1618339143.180 [Default:CheckIn] Running Loop=10
2021-04-13T18:39:03.180Z,1618339143.180 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-13T18:39:03.181Z,1618339143.181 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-13T18:39:05.174Z,1618339145.174 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183904.00,A,3648.13907,N,12147.20855,W,0.019,0.00,130421,,,D*7D
2021-04-13T18:39:05.176Z,1618339145.176 [NAL9602](INFO): GPS fix at 20210413T183904: (36.802318, -121.786809)
2021-04-13T18:39:05.187Z,1618339145.187 [Default:CheckIn:Read_GPS] Stopped
2021-04-13T18:39:05.187Z,1618339145.187 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-13T18:39:13.969Z,1618339153.969 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210413T174526/Courier0031.lzma
2021-04-13T18:39:14.972Z,1618339154.972 [DataOverHttps](INFO): Moved sent file to Logs/20210413T174526/Courier0031.lzma.bak
2021-04-13T18:39:14.972Z,1618339154.972 [DataOverHttps](INFO): SBD MOMSN=15565396
2021-04-13T18:39:17.690Z,1618339157.690 [NAL9602](INFO): SBD MO Status=0, MOMSN=1996, MT Status=0, MTMSN=0
2021-04-13T18:39:17.690Z,1618339157.690 [NAL9602](INFO): No messages in MT queue
2021-04-13T18:39:31.854Z,1618339171.854 [DataOverHttps](INFO): Sending 128 bytes from file Logs/20210413T174526/Express0032.lzma
2021-04-13T18:39:32.856Z,1618339172.856 [DataOverHttps](INFO): Moved sent file to Logs/20210413T174526/Express0032.lzma.bak
2021-04-13T18:39:32.856Z,1618339172.856 [DataOverHttps](INFO): SBD MOMSN=15565399
2021-04-13T18:39:35.098Z,1618339175.098 [Default:CheckIn:Read_Iridium] Stopped
2021-04-13T18:39:35.098Z,1618339175.098 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-13T18:39:35.098Z,1618339175.098 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-13T18:39:48.395Z,1618339188.395 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-13T18:43:41.342Z,1618339421.342 [DVL_micro](ERROR): DVL uart error: serial timeout
2021-04-13T18:43:41.342Z,1618339421.342 [DVL_micro] Communications Fault, FailCount= 1
2021-04-13T18:43:41.342Z,1618339421.342 [DVL_micro](ERROR): Communications Fault
2021-04-13T18:43:41.342Z,1618339421.342 [DVL_micro](ERROR): Failed to parse:
2021-04-13T18:43:41.407Z,1618339421.407 [CBIT](ERROR): Communications Fault in component: DVL_micro
2021-04-13T18:43:41.726Z,1618339421.726 [DVL_micro](INFO): Powering down
2021-04-13T18:43:42.544Z,1618339422.544 [CBIT](INFO): Clearing failed state for component DVL_micro
2021-04-13T18:43:42.544Z,1618339422.544 [DVL_micro] No Fault, FailCount= 1
2021-04-13T18:44:35.806Z,1618339475.806 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-13T18:44:35.806Z,1618339475.806 [Default:CheckIn:C.Wait] Stopped
2021-04-13T18:44:35.806Z,1618339475.806 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-13T18:44:35.806Z,1618339475.806 [Default:CheckIn:D] Running Loop=1
2021-04-13T18:44:36.205Z,1618339476.205 [Default:CheckIn:D] Stopped
2021-04-13T18:44:36.205Z,1618339476.205 [Default:CheckIn:E] Running Loop=1
2021-04-13T18:44:36.619Z,1618339476.619 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 56.578906 min 
2021-04-13T18:44:36.619Z,1618339476.619 [Default:CheckIn:E] Stopped
2021-04-13T18:44:36.619Z,1618339476.619 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-13T18:44:36.619Z,1618339476.619 [Default:CheckIn] Stopped
2021-04-13T18:44:36.619Z,1618339476.619 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-13T18:44:36.619Z,1618339476.619 [Default:CheckIn](INFO): Running loop #11
2021-04-13T18:44:36.619Z,1618339476.619 [Default:CheckIn] Running Loop=11
2021-04-13T18:44:36.620Z,1618339476.620 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-13T18:44:36.620Z,1618339476.620 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-13T18:44:38.625Z,1618339478.625 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184437.00,A,3648.14284,N,12147.20768,W,0.039,0.00,130421,,,D*73
2021-04-13T18:44:38.627Z,1618339478.627 [NAL9602](INFO): GPS fix at 20210413T184437: (36.802381, -121.786795)
2021-04-13T18:44:38.638Z,1618339478.638 [Default:CheckIn:Read_GPS] Stopped
2021-04-13T18:44:38.638Z,1618339478.638 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-13T18:44:46.265Z,1618339486.265 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210413T174526/Courier0034.lzma
2021-04-13T18:44:47.268Z,1618339487.268 [DataOverHttps](INFO): Moved sent file to Logs/20210413T174526/Courier0034.lzma.bak
2021-04-13T18:44:47.268Z,1618339487.268 [DataOverHttps](INFO): SBD MOMSN=15565403
2021-04-13T18:44:54.786Z,1618339494.786 [NAL9602](INFO): SBD MO Status=0, MOMSN=1997, MT Status=0, MTMSN=0
2021-04-13T18:44:54.786Z,1618339494.786 [NAL9602](INFO): No messages in MT queue
2021-04-13T18:45:04.190Z,1618339504.190 [DataOverHttps](INFO): Sending 133 bytes from file Logs/20210413T174526/Express0035.lzma
2021-04-13T18:45:05.192Z,1618339505.192 [DataOverHttps](INFO): Moved sent file to Logs/20210413T174526/Express0035.lzma.bak
2021-04-13T18:45:05.192Z,1618339505.192 [DataOverHttps](INFO): SBD MOMSN=15565406
2021-04-13T18:45:07.351Z,1618339507.351 [Default:CheckIn:Read_Iridium] Stopped
2021-04-13T18:45:07.351Z,1618339507.351 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-13T18:45:07.351Z,1618339507.351 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-13T18:45:25.498Z,1618339525.498 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-13T18:50:08.063Z,1618339808.063 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-13T18:50:08.063Z,1618339808.063 [Default:CheckIn:C.Wait] Stopped
2021-04-13T18:50:08.063Z,1618339808.063 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-13T18:50:08.063Z,1618339808.063 [Default:CheckIn:D] Running Loop=1
2021-04-13T18:50:08.520Z,1618339808.520 [Default:CheckIn:D] Stopped
2021-04-13T18:50:08.520Z,1618339808.520 [Default:CheckIn:E] Running Loop=1
2021-04-13T18:50:08.859Z,1618339808.859 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 62.117480 min 
2021-04-13T18:50:08.859Z,1618339808.859 [Default:CheckIn:E] Stopped
2021-04-13T18:50:08.859Z,1618339808.859 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-13T18:50:08.859Z,1618339808.859 [Default:CheckIn] Stopped
2021-04-13T18:50:08.859Z,1618339808.859 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-13T18:50:08.860Z,1618339808.860 [Default:CheckIn](INFO): Running loop #12
2021-04-13T18:50:08.860Z,1618339808.860 [Default:CheckIn] Running Loop=12
2021-04-13T18:50:08.860Z,1618339808.860 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-13T18:50:08.860Z,1618339808.860 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-13T18:50:10.855Z,1618339810.855 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,185010.00,A,3648.14061,N,12147.20820,W,0.019,0.00,130421,,,D*7B
2021-04-13T18:50:10.857Z,1618339810.857 [NAL9602](INFO): GPS fix at 20210413T185010: (36.802343, -121.786803)
2021-04-13T18:50:10.904Z,1618339810.904 [Default:CheckIn:Read_GPS] Stopped
2021-04-13T18:50:10.904Z,1618339810.904 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-13T18:50:22.690Z,1618339822.690 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210413T174526/Courier0037.lzma
2021-04-13T18:50:23.688Z,1618339823.688 [DataOverHttps](INFO): Moved sent file to Logs/20210413T174526/Courier0037.lzma.bak
2021-04-13T18:50:23.688Z,1618339823.688 [DataOverHttps](INFO): SBD MOMSN=15565411
2021-04-13T18:50:31.941Z,1618339831.941 [NAL9602](INFO): SBD MO Status=0, MOMSN=1998, MT Status=0, MTMSN=0
2021-04-13T18:50:31.941Z,1618339831.941 [NAL9602](INFO): No messages in MT queue
2021-04-13T18:50:41.574Z,1618339841.574 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20210413T174526/Express0038.lzma
2021-04-13T18:50:42.576Z,1618339842.576 [DataOverHttps](INFO): Moved sent file to Logs/20210413T174526/Express0038.lzma.bak
2021-04-13T18:50:42.576Z,1618339842.576 [DataOverHttps](INFO): SBD MOMSN=15565414
2021-04-13T18:50:44.897Z,1618339844.897 [Default:CheckIn:Read_Iridium] Stopped
2021-04-13T18:50:44.902Z,1618339844.902 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-13T18:50:44.902Z,1618339844.902 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-13T18:51:02.644Z,1618339862.644 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-13T18:54:43.710Z,1618340083.710 [DVL_micro](ERROR): only read 3 of 4 data items
2021-04-13T18:54:43.711Z,1618340083.711 [DVL_micro](ERROR): Failed to parse:
:BI,-00004,+00122,-00063,+

2021-04-13T18:55:45.542Z,1618340145.542 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-13T18:55:45.542Z,1618340145.542 [Default:CheckIn:C.Wait] Stopped
2021-04-13T18:55:45.542Z,1618340145.542 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-13T18:55:45.543Z,1618340145.543 [Default:CheckIn:D] Running Loop=1
2021-04-13T18:55:45.949Z,1618340145.949 [Default:CheckIn:D] Stopped
2021-04-13T18:55:45.950Z,1618340145.950 [Default:CheckIn:E] Running Loop=1
2021-04-13T18:55:46.347Z,1618340146.347 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 67.741309 min 
2021-04-13T18:55:46.347Z,1618340146.347 [Default:CheckIn:E] Stopped
2021-04-13T18:55:46.347Z,1618340146.347 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-13T18:55:46.347Z,1618340146.347 [Default:CheckIn] Stopped
2021-04-13T18:55:46.348Z,1618340146.348 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-13T18:55:46.348Z,1618340146.348 [Default:CheckIn](INFO): Running loop #13
2021-04-13T18:55:46.348Z,1618340146.348 [Default:CheckIn] Running Loop=13
2021-04-13T18:55:46.348Z,1618340146.348 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-13T18:55:46.348Z,1618340146.348 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-13T18:55:48.342Z,1618340148.342 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,185547.00,A,3648.14276,N,12147.20702,W,0.097,0.00,130421,,,D*71
2021-04-13T18:55:48.344Z,1618340148.344 [NAL9602](INFO): GPS fix at 20210413T185547: (36.802379, -121.786784)
2021-04-13T18:55:48.354Z,1618340148.354 [Default:CheckIn:Read_GPS] Stopped
2021-04-13T18:55:48.355Z,1618340148.355 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-13T18:55:56.493Z,1618340156.493 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210413T174526/Courier0040.lzma
2021-04-13T18:55:57.496Z,1618340157.496 [DataOverHttps](INFO): Moved sent file to Logs/20210413T174526/Courier0040.lzma.bak
2021-04-13T18:55:57.496Z,1618340157.496 [DataOverHttps](INFO): SBD MOMSN=15565419
2021-04-13T18:56:08.177Z,1618340168.177 [NAL9602](INFO): SBD MO Status=0, MOMSN=1999, MT Status=0, MTMSN=0
2021-04-13T18:56:08.177Z,1618340168.177 [NAL9602](INFO): No messages in MT queue
2021-04-13T18:56:20.478Z,1618340180.478 [DataOverHttps](INFO): Sending 128 bytes from file Logs/20210413T174526/Express0041.lzma
2021-04-13T18:56:21.480Z,1618340181.480 [DataOverHttps](INFO): Moved sent file to Logs/20210413T174526/Express0041.lzma.bak
2021-04-13T18:56:21.480Z,1618340181.480 [DataOverHttps](INFO): SBD MOMSN=15565424
2021-04-13T18:56:25.043Z,1618340185.043 [Default:CheckIn:Read_Iridium] Stopped
2021-04-13T18:56:25.043Z,1618340185.043 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-13T18:56:25.043Z,1618340185.043 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-13T18:56:38.707Z,1618340198.707 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-13T19:00:51.697Z,1618340451.697 [BPC1](ERROR): Battery stick #6 (s/n: 00CA) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0.
2021-04-13T19:00:51.698Z,1618340451.698 [BPC1](INFO): Calculating totals. Valid battery stick count: 55. Valid reserve battery stick count: 6.
2021-04-13T19:00:51.701Z,1618340451.701 [BPC1](INFO): Received data from all battery sticks.
2021-04-13T19:01:25.650Z,1618340485.650 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-13T19:01:25.650Z,1618340485.650 [Default:CheckIn:C.Wait] Stopped
2021-04-13T19:01:25.651Z,1618340485.651 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-13T19:01:25.651Z,1618340485.651 [Default:CheckIn:D] Running Loop=1
2021-04-13T19:01:26.072Z,1618340486.072 [Default:CheckIn:D] Stopped
2021-04-13T19:01:26.072Z,1618340486.072 [Default:CheckIn:E] Running Loop=1
2021-04-13T19:01:26.447Z,1618340486.447 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 73.410010 min 
2021-04-13T19:01:26.447Z,1618340486.447 [Default:CheckIn:E] Stopped
2021-04-13T19:01:26.447Z,1618340486.447 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-13T19:01:26.448Z,1618340486.448 [Default:CheckIn] Stopped
2021-04-13T19:01:26.448Z,1618340486.448 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-13T19:01:26.448Z,1618340486.448 [Default:CheckIn](INFO): Running loop #14
2021-04-13T19:01:26.448Z,1618340486.448 [Default:CheckIn] Running Loop=14
2021-04-13T19:01:26.448Z,1618340486.448 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-13T19:01:26.448Z,1618340486.448 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-13T19:01:28.465Z,1618340488.465 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190127.00,A,3648.14091,N,12147.20913,W,0.078,0.00,130421,,,D*73
2021-04-13T19:01:28.468Z,1618340488.468 [NAL9602](INFO): GPS fix at 20210413T190127: (36.802349, -121.786819)
2021-04-13T19:01:28.478Z,1618340488.478 [Default:CheckIn:Read_GPS] Stopped
2021-04-13T19:01:28.478Z,1618340488.478 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-13T19:01:35.669Z,1618340495.669 [DataOverHttps](INFO): Sending 83 bytes from file Logs/20210413T174526/Courier0043.lzma
2021-04-13T19:01:36.672Z,1618340496.672 [DataOverHttps](INFO): Moved sent file to Logs/20210413T174526/Courier0043.lzma.bak
2021-04-13T19:01:36.672Z,1618340496.672 [DataOverHttps](INFO): SBD MOMSN=15565428
2021-04-13T19:01:45.846Z,1618340505.846 [NAL9602](INFO): SBD MO Status=0, MOMSN=2000, MT Status=0, MTMSN=0
2021-04-13T19:01:45.846Z,1618340505.846 [NAL9602](INFO): No messages in MT queue
2021-04-13T19:01:53.622Z,1618340513.622 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20210413T174526/Express0044.lzma
2021-04-13T19:01:55.697Z,1618340515.697 [DataOverHttps](INFO): Moved sent file to Logs/20210413T174526/Express0044.lzma.bak
2021-04-13T19:01:55.698Z,1618340515.698 [DataOverHttps](INFO): SBD MOMSN=15565431
2021-04-13T19:01:57.171Z,1618340517.171 [Default:CheckIn:Read_Iridium] Stopped
2021-04-13T19:01:57.171Z,1618340517.171 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-13T19:01:57.171Z,1618340517.171 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-13T19:02:16.591Z,1618340536.591 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-13T19:06:57.827Z,1618340817.827 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-13T19:06:57.827Z,1618340817.827 [Default:CheckIn:C.Wait] Stopped
2021-04-13T19:06:57.827Z,1618340817.827 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-13T19:06:57.827Z,1618340817.827 [Default:CheckIn:D] Running Loop=1
2021-04-13T19:06:58.217Z,1618340818.217 [Default:CheckIn:D] Stopped
2021-04-13T19:06:58.217Z,1618340818.217 [Default:CheckIn:E] Running Loop=1
2021-04-13T19:06:58.616Z,1618340818.616 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 78.945768 min 
2021-04-13T19:06:58.616Z,1618340818.616 [Default:CheckIn:E] Stopped
2021-04-13T19:06:58.616Z,1618340818.616 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-13T19:06:58.616Z,1618340818.616 [Default:CheckIn] Stopped
2021-04-13T19:06:58.616Z,1618340818.616 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-13T19:06:58.616Z,1618340818.616 [Default:CheckIn](INFO): Running loop #15
2021-04-13T19:06:58.616Z,1618340818.616 [Default:CheckIn] Running Loop=15
2021-04-13T19:06:58.617Z,1618340818.617 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-13T19:06:58.617Z,1618340818.617 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-13T19:07:00.633Z,1618340820.633 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190659.00,A,3648.13942,N,12147.20665,W,0.039,0.00,130421,,,D*76
2021-04-13T19:07:00.636Z,1618340820.636 [NAL9602](INFO): GPS fix at 20210413T190659: (36.802324, -121.786777)
2021-04-13T19:07:00.669Z,1618340820.669 [Default:CheckIn:Read_GPS] Stopped
2021-04-13T19:07:00.669Z,1618340820.669 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-13T19:07:07.925Z,1618340827.925 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210413T174526/Courier0046.lzma
2021-04-13T19:07:08.928Z,1618340828.928 [DataOverHttps](INFO): Moved sent file to Logs/20210413T174526/Courier0046.lzma.bak
2021-04-13T19:07:08.928Z,1618340828.928 [DataOverHttps](INFO): SBD MOMSN=15565436
2021-04-13T19:07:16.385Z,1618340836.385 [NAL9602](INFO): SBD MO Status=0, MOMSN=2001, MT Status=0, MTMSN=0
2021-04-13T19:07:16.385Z,1618340836.385 [NAL9602](INFO): No messages in MT queue
2021-04-13T19:07:25.802Z,1618340845.802 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20210413T174526/Express0047.lzma
2021-04-13T19:07:26.804Z,1618340846.804 [DataOverHttps](INFO): Moved sent file to Logs/20210413T174526/Express0047.lzma.bak
2021-04-13T19:07:26.804Z,1618340846.804 [DataOverHttps](INFO): SBD MOMSN=15565439
2021-04-13T19:07:28.940Z,1618340848.940 [Default:CheckIn:Read_Iridium] Stopped
2021-04-13T19:07:28.940Z,1618340848.940 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-13T19:07:28.940Z,1618340848.940 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-13T19:07:32.954Z,1618340852.954 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2021-04-13T19:07:32.954Z,1618340852.954 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,+13.1,0000.0000
2021-04-13T19:07:47.091Z,1618340867.091 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-13T19:09:03.113Z,1618340943.113 [DVL_micro](ERROR): only read 3 of 4 data items
2021-04-13T19:09:03.114Z,1618340943.114 [DVL_micro](ERROR): Failed to parse:
:RD,+9999.99,+99999.99,+9999.99
2021-04-13T19:12:29.623Z,1618341149.623 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-13T19:12:29.623Z,1618341149.623 [Default:CheckIn:C.Wait] Stopped
2021-04-13T19:12:29.623Z,1618341149.623 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-13T19:12:29.623Z,1618341149.623 [Default:CheckIn:D] Running Loop=1
2021-04-13T19:12:30.043Z,1618341150.043 [Default:CheckIn:D] Stopped
2021-04-13T19:12:30.043Z,1618341150.043 [Default:CheckIn:E] Running Loop=1
2021-04-13T19:12:30.470Z,1618341150.470 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 84.476196 min 
2021-04-13T19:12:30.470Z,1618341150.470 [Default:CheckIn:E] Stopped
2021-04-13T19:12:30.470Z,1618341150.470 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-13T19:12:30.470Z,1618341150.470 [Default:CheckIn] Stopped
2021-04-13T19:12:30.470Z,1618341150.470 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-13T19:12:30.471Z,1618341150.471 [Default:CheckIn](INFO): Running loop #16
2021-04-13T19:12:30.471Z,1618341150.471 [Default:CheckIn] Running Loop=16
2021-04-13T19:12:30.471Z,1618341150.471 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-13T19:12:30.471Z,1618341150.471 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-13T19:12:32.455Z,1618341152.455 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,191231.00,A,3648.14164,N,12147.20703,W,0.039,0.00,130421,,,D*77
2021-04-13T19:12:32.480Z,1618341152.480 [NAL9602](INFO): GPS fix at 20210413T191231: (36.802361, -121.786784)
2021-04-13T19:12:32.491Z,1618341152.491 [Default:CheckIn:Read_GPS] Stopped
2021-04-13T19:12:32.491Z,1618341152.491 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-13T19:12:39.961Z,1618341159.961 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210413T174526/Courier0049.lzma
2021-04-13T19:12:40.964Z,1618341160.964 [DataOverHttps](INFO): Moved sent file to Logs/20210413T174526/Courier0049.lzma.bak
2021-04-13T19:12:40.964Z,1618341160.964 [DataOverHttps](INFO): SBD MOMSN=15565443
2021-04-13T19:12:49.826Z,1618341169.826 [NAL9602](INFO): SBD MO Status=0, MOMSN=2002, MT Status=0, MTMSN=0
2021-04-13T19:12:49.826Z,1618341169.826 [NAL9602](INFO): No messages in MT queue
2021-04-13T19:12:58.058Z,1618341178.058 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20210413T174526/Express0050.lzma
2021-04-13T19:12:59.060Z,1618341179.060 [DataOverHttps](INFO): Moved sent file to Logs/20210413T174526/Express0050.lzma.bak
2021-04-13T19:12:59.060Z,1618341179.060 [DataOverHttps](INFO): SBD MOMSN=15565446
2021-04-13T19:13:01.142Z,1618341181.142 [Default:CheckIn:Read_Iridium] Stopped
2021-04-13T19:13:01.142Z,1618341181.142 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-13T19:13:01.142Z,1618341181.142 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-13T19:13:20.535Z,1618341200.535 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-13T19:18:01.822Z,1618341481.822 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-13T19:18:01.823Z,1618341481.823 [Default:CheckIn:C.Wait] Stopped
2021-04-13T19:18:01.823Z,1618341481.823 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-13T19:18:01.823Z,1618341481.823 [Default:CheckIn:D] Running Loop=1
2021-04-13T19:18:02.206Z,1618341482.206 [Default:CheckIn:D] Stopped
2021-04-13T19:18:02.206Z,1618341482.206 [Default:CheckIn:E] Running Loop=1
2021-04-13T19:18:02.627Z,1618341482.627 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 90.012248 min 
2021-04-13T19:18:02.627Z,1618341482.627 [Default:CheckIn:E] Stopped
2021-04-13T19:18:02.627Z,1618341482.627 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-13T19:18:02.627Z,1618341482.627 [Default:CheckIn] Stopped
2021-04-13T19:18:02.627Z,1618341482.627 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-13T19:18:02.628Z,1618341482.628 [Default:CheckIn](INFO): Running loop #17
2021-04-13T19:18:02.628Z,1618341482.628 [Default:CheckIn] Running Loop=17
2021-04-13T19:18:02.628Z,1618341482.628 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-13T19:18:02.628Z,1618341482.628 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-13T19:18:04.621Z,1618341484.621 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,191803.00,A,3648.16916,N,12147.26316,W,2.624,298.08,130421,,,D*76
2021-04-13T19:18:04.624Z,1618341484.624 [NAL9602](INFO): GPS fix at 20210413T191803: (36.802819, -121.787719)
2021-04-13T19:18:04.682Z,1618341484.682 [Default:CheckIn:Read_GPS] Stopped
2021-04-13T19:18:04.682Z,1618341484.682 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-13T19:18:16.522Z,1618341496.522 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210413T174526/Courier0052.lzma
2021-04-13T19:18:17.524Z,1618341497.524 [DataOverHttps](INFO): Moved sent file to Logs/20210413T174526/Courier0052.lzma.bak
2021-04-13T19:18:17.524Z,1618341497.524 [DataOverHttps](INFO): SBD MOMSN=15565450
2021-04-13T19:18:20.457Z,1618341500.457 [NAL9602](INFO): SBD MO Status=0, MOMSN=2003, MT Status=0, MTMSN=0
2021-04-13T19:18:20.457Z,1618341500.457 [NAL9602](INFO): No messages in MT queue
2021-04-13T19:18:36.494Z,1618341516.494 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20210413T174526/Express0053.lzma
2021-04-13T19:18:37.496Z,1618341517.496 [DataOverHttps](INFO): Moved sent file to Logs/20210413T174526/Express0053.lzma.bak
2021-04-13T19:18:37.496Z,1618341517.496 [DataOverHttps](INFO): SBD MOMSN=15565453
2021-04-13T19:18:39.870Z,1618341519.870 [Default:CheckIn:Read_Iridium] Stopped
2021-04-13T19:18:39.871Z,1618341519.871 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-13T19:18:39.871Z,1618341519.871 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-13T19:18:51.163Z,1618341531.163 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-13T19:19:31.159Z,1618341571.159 [DVL_micro](ERROR): only read 3 of 4 data items
2021-04-13T19:19:31.159Z,1618341571.159 [DVL_micro](ERROR): Failed to parse:
:BI,-00237,+00153,+0000,I
2021-04-13T19:23:40.513Z,1618341820.513 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-13T19:23:40.513Z,1618341820.513 [Default:CheckIn:C.Wait] Stopped
2021-04-13T19:23:40.513Z,1618341820.513 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-13T19:23:40.513Z,1618341820.513 [Default:CheckIn:D] Running Loop=1
2021-04-13T19:23:40.906Z,1618341820.906 [Default:CheckIn:D] Stopped
2021-04-13T19:23:40.906Z,1618341820.906 [Default:CheckIn:E] Running Loop=1
2021-04-13T19:23:41.303Z,1618341821.303 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 95.657251 min 
2021-04-13T19:23:41.303Z,1618341821.303 [Default:CheckIn:E] Stopped
2021-04-13T19:23:41.303Z,1618341821.303 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-13T19:23:41.303Z,1618341821.303 [Default:CheckIn] Stopped
2021-04-13T19:23:41.303Z,1618341821.303 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-13T19:23:41.303Z,1618341821.303 [Default:CheckIn](INFO): Running loop #18
2021-04-13T19:23:41.303Z,1618341821.303 [Default:CheckIn] Running Loop=18
2021-04-13T19:23:41.303Z,1618341821.303 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-13T19:23:41.303Z,1618341821.303 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-13T19:23:43.329Z,1618341823.329 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,192342.00,A,3648.17576,N,12147.28485,W,0.700,200.56,130421,,,D*7C
2021-04-13T19:23:43.331Z,1618341823.331 [NAL9602](INFO): GPS fix at 20210413T192342: (36.802929, -121.788081)
2021-04-13T19:23:43.342Z,1618341823.342 [Default:CheckIn:Read_GPS] Stopped
2021-04-13T19:23:43.342Z,1618341823.342 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-13T19:23:50.317Z,1618341830.317 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210413T174526/Courier0055.lzma
2021-04-13T19:23:51.320Z,1618341831.320 [DataOverHttps](INFO): Moved sent file to Logs/20210413T174526/Courier0055.lzma.bak
2021-04-13T19:23:51.320Z,1618341831.320 [DataOverHttps](INFO): SBD MOMSN=15565460
2021-04-13T19:24:12.494Z,1618341852.494 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20210413T174526/Express0056.lzma
2021-04-13T19:24:13.496Z,1618341853.496 [DataOverHttps](INFO): Moved sent file to Logs/20210413T174526/Express0056.lzma.bak
2021-04-13T19:24:13.496Z,1618341853.496 [DataOverHttps](INFO): SBD MOMSN=15565463
2021-04-13T19:24:16.663Z,1618341856.663 [Default:CheckIn:Read_Iridium] Stopped
2021-04-13T19:24:16.663Z,1618341856.663 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-13T19:24:16.664Z,1618341856.664 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-13T19:25:57.614Z,1618341957.614 [NAL9602](INFO): SBD MO Status=2, MOMSN=2004, MT Status=2, MTMSN=0
2021-04-13T19:25:57.614Z,1618341957.614 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-04-13T19:26:21.445Z,1618341981.445 [NAL9602](INFO): SBD MO Status=2, MOMSN=2004, MT Status=2, MTMSN=0
2021-04-13T19:26:21.445Z,1618341981.445 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-04-13T19:26:55.798Z,1618342015.798 [NAL9602](INFO): SBD MO Status=2, MOMSN=2004, MT Status=2, MTMSN=0
2021-04-13T19:26:55.798Z,1618342015.798 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-04-13T19:27:28.105Z,1618342048.105 [NAL9602](INFO): SBD MO Status=2, MOMSN=2004, MT Status=2, MTMSN=0
2021-04-13T19:27:28.105Z,1618342048.105 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-04-13T19:27:45.218Z,1618342065.218 [CommandLine](IMPORTANT): got command failComponent
2021-04-13T19:27:45.218Z,1618342065.218 [CommandLine](IMPORTANT): Failed components:
2021-04-13T19:27:45.218Z,1618342065.218 [CommandLine](IMPORTANT): No failed Components.
2021-04-13T19:28:45.351Z,1618342125.351 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2021-04-13T19:29:06.361Z,1618342146.361 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2021-04-13T19:29:06.361Z,1618342146.361 [DVL_micro](ERROR): Failed to parse:
:TS,000000000000004.0,0000.0,1489.0,000
2021-04-13T19:29:16.051Z,1618342156.051 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-13T19:29:17.302Z,1618342157.302 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-13T19:29:17.302Z,1618342157.302 [Default:CheckIn:C.Wait] Stopped
2021-04-13T19:29:17.302Z,1618342157.302 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-13T19:29:17.302Z,1618342157.302 [Default:CheckIn:D] Running Loop=1
2021-04-13T19:29:17.677Z,1618342157.677 [Default:CheckIn:D] Stopped
2021-04-13T19:29:17.677Z,1618342157.677 [Default:CheckIn:E] Running Loop=1
2021-04-13T19:29:18.096Z,1618342158.096 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 101.270101 min 
2021-04-13T19:29:18.096Z,1618342158.096 [Default:CheckIn:E] Stopped
2021-04-13T19:29:18.096Z,1618342158.096 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-13T19:29:18.096Z,1618342158.096 [Default:CheckIn] Stopped
2021-04-13T19:29:18.096Z,1618342158.096 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-13T19:29:18.096Z,1618342158.096 [Default:CheckIn](INFO): Running loop #19
2021-04-13T19:29:18.096Z,1618342158.096 [Default:CheckIn] Running Loop=19
2021-04-13T19:29:18.096Z,1618342158.096 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-13T19:29:18.097Z,1618342158.097 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-13T19:29:20.103Z,1618342160.103 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,192919.00,A,3648.17191,N,12147.28254,W,0.253,68.98,130421,,,A*47
2021-04-13T19:29:20.105Z,1618342160.105 [NAL9602](INFO): GPS fix at 20210413T192919: (36.802865, -121.788042)
2021-04-13T19:29:20.115Z,1618342160.115 [Default:CheckIn:Read_GPS] Stopped
2021-04-13T19:29:20.116Z,1618342160.116 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-13T19:29:28.973Z,1618342168.973 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210413T174526/Courier0058.lzma
2021-04-13T19:29:29.976Z,1618342169.976 [DataOverHttps](INFO): Moved sent file to Logs/20210413T174526/Courier0058.lzma.bak
2021-04-13T19:29:29.976Z,1618342169.976 [DataOverHttps](INFO): SBD MOMSN=15565469
2021-04-13T19:29:47.479Z,1618342187.479 [DataOverHttps](INFO): Sending 280 bytes from file Logs/20210413T174526/Express0059.lzma
2021-04-13T19:29:48.480Z,1618342188.480 [DataOverHttps](INFO): Moved sent file to Logs/20210413T174526/Express0059.lzma.bak
2021-04-13T19:29:48.480Z,1618342188.480 [DataOverHttps](INFO): SBD MOMSN=15565472
2021-04-13T19:29:50.795Z,1618342190.795 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2021-04-13T19:29:50.874Z,1618342190.874 [NAL9602](ERROR): received: 
+CSQ:0

OK04, 2, 0, 0, 0

OK
2021-04-13T19:29:51.659Z,1618342191.659 [Default:CheckIn:Read_Iridium] Stopped
2021-04-13T19:29:51.659Z,1618342191.659 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-13T19:29:51.659Z,1618342191.659 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-13T19:30:54.295Z,1618342254.295 [DVL_micro](ERROR): Failed to parse:
:SA,+10.15,-01.66,211.6
2021-04-13T19:31:52.069Z,1618342312.069 [NAL9602](INFO): SBD MO Status=0, MOMSN=2004, MT Status=0, MTMSN=0
2021-04-13T19:31:52.069Z,1618342312.069 [NAL9602](INFO): No messages in MT queue
2021-04-13T19:32:22.775Z,1618342342.775 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-13T19:33:31.868Z,1618342411.868 [DVL_micro](ERROR): only read 3 of 4 data items
2021-04-13T19:33:31.869Z,1618342411.869 [DVL_micro](ERROR): Failed to parse:
:BI,+00188,+0006,+00000,A
2021-04-13T19:34:52.344Z,1618342492.344 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-13T19:34:52.344Z,1618342492.344 [Default:CheckIn:C.Wait] Stopped
2021-04-13T19:34:52.344Z,1618342492.344 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-13T19:34:52.344Z,1618342492.344 [Default:CheckIn:D] Running Loop=1
2021-04-13T19:34:52.769Z,1618342492.769 [Default:CheckIn:D] Stopped
2021-04-13T19:34:52.770Z,1618342492.770 [Default:CheckIn:E] Running Loop=1
2021-04-13T19:34:53.145Z,1618342493.145 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 106.854972 min 
2021-04-13T19:34:53.145Z,1618342493.145 [Default:CheckIn:E] Stopped
2021-04-13T19:34:53.145Z,1618342493.145 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-13T19:34:53.145Z,1618342493.145 [Default:CheckIn] Stopped
2021-04-13T19:34:53.145Z,1618342493.145 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-13T19:34:53.146Z,1618342493.146 [Default:CheckIn](INFO): Running loop #20
2021-04-13T19:34:53.146Z,1618342493.146 [Default:CheckIn] Running Loop=20
2021-04-13T19:34:53.146Z,1618342493.146 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-13T19:34:53.146Z,1618342493.146 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-13T19:34:55.154Z,1618342495.154 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,193454.00,A,3648.16883,N,12147.28109,W,0.292,124.77,130421,,,A*77
2021-04-13T19:34:55.156Z,1618342495.156 [NAL9602](INFO): GPS fix at 20210413T193454: (36.802814, -121.788018)
2021-04-13T19:34:55.167Z,1618342495.167 [Default:CheckIn:Read_GPS] Stopped
2021-04-13T19:34:55.167Z,1618342495.167 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-13T19:35:02.929Z,1618342502.929 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20210413T174526/Courier0061.lzma
2021-04-13T19:35:03.932Z,1618342503.932 [DataOverHttps](INFO): Moved sent file to Logs/20210413T174526/Courier0061.lzma.bak
2021-04-13T19:35:03.932Z,1618342503.932 [DataOverHttps](INFO): SBD MOMSN=15565491
2021-04-13T19:35:20.934Z,1618342520.934 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20210413T174526/Express0062.lzma
2021-04-13T19:35:21.936Z,1618342521.936 [DataOverHttps](INFO): Moved sent file to Logs/20210413T174526/Express0062.lzma.bak
2021-04-13T19:35:21.936Z,1618342521.936 [DataOverHttps](INFO): SBD MOMSN=15565494
2021-04-13T19:35:24.270Z,1618342524.270 [Default:CheckIn:Read_Iridium] Stopped
2021-04-13T19:35:24.270Z,1618342524.270 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-13T19:35:24.271Z,1618342524.271 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-13T19:35:34.339Z,1618342534.339 [NAL9602](INFO): SBD MO Status=2, MOMSN=2005, MT Status=2, MTMSN=0
2021-04-13T19:35:34.339Z,1618342534.339 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-04-13T19:35:49.293Z,1618342549.293 [NAL9602](INFO): SBD MO Status=0, MOMSN=2005, MT Status=0, MTMSN=0
2021-04-13T19:35:49.293Z,1618342549.293 [NAL9602](INFO): No messages in MT queue
2021-04-13T19:36:20.051Z,1618342580.051 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-13T19:39:28.753Z,1618342768.753 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2021-04-13T19:39:28.753Z,1618342768.753 [DVL_micro](ERROR): Failed to parse:
:TS,000000000.0,+16.0,0000.0,1489.0,000
2021-04-13T19:40:24.903Z,1618342824.903 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-13T19:40:24.903Z,1618342824.903 [Default:CheckIn:C.Wait] Stopped
2021-04-13T19:40:24.903Z,1618342824.903 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-13T19:40:24.903Z,1618342824.903 [Default:CheckIn:D] Running Loop=1
2021-04-13T19:40:25.322Z,1618342825.322 [Default:CheckIn:D] Stopped
2021-04-13T19:40:25.322Z,1618342825.322 [Default:CheckIn:E] Running Loop=1
2021-04-13T19:40:25.707Z,1618342825.707 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 112.397510 min 
2021-04-13T19:40:25.707Z,1618342825.707 [Default:CheckIn:E] Stopped
2021-04-13T19:40:25.707Z,1618342825.707 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-13T19:40:25.707Z,1618342825.707 [Default:CheckIn] Stopped
2021-04-13T19:40:25.707Z,1618342825.707 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-13T19:40:25.707Z,1618342825.707 [Default:CheckIn](INFO): Running loop #21
2021-04-13T19:40:25.707Z,1618342825.707 [Default:CheckIn] Running Loop=21
2021-04-13T19:40:25.708Z,1618342825.708 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-13T19:40:25.708Z,1618342825.708 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-13T19:40:27.731Z,1618342827.731 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194027.00,A,3648.16713,N,12147.27675,W,2.333,353.58,130421,,,A*72
2021-04-13T19:40:27.733Z,1618342827.733 [NAL9602](INFO): GPS fix at 20210413T194027: (36.802785, -121.787946)
2021-04-13T19:40:27.744Z,1618342827.744 [Default:CheckIn:Read_GPS] Stopped
2021-04-13T19:40:27.744Z,1618342827.744 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-13T19:40:35.717Z,1618342835.717 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210413T174526/Courier0064.lzma
2021-04-13T19:40:36.720Z,1618342836.720 [DataOverHttps](INFO): Moved sent file to Logs/20210413T174526/Courier0064.lzma.bak
2021-04-13T19:40:36.720Z,1618342836.720 [DataOverHttps](INFO): SBD MOMSN=15565510
2021-04-13T19:40:53.638Z,1618342853.638 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20210413T174526/Express0065.lzma
2021-04-13T19:40:54.640Z,1618342854.640 [DataOverHttps](INFO): Moved sent file to Logs/20210413T174526/Express0065.lzma.bak
2021-04-13T19:40:54.640Z,1618342854.640 [DataOverHttps](INFO): SBD MOMSN=15565513
2021-04-13T19:40:56.886Z,1618342856.886 [Default:CheckIn:Read_Iridium] Stopped
2021-04-13T19:40:56.886Z,1618342856.886 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-13T19:40:56.886Z,1618342856.886 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-13T19:43:47.327Z,1618343027.327 [DVL_micro](ERROR): only read 3 of 4 data items
2021-04-13T19:43:47.327Z,1618343027.327 [DVL_micro](ERROR): Failed to parse:
:RD,+99999.99,+9999.99,+9999.99
2021-04-13T19:44:21.325Z,1618343061.325 [NAL9602](INFO): SBD MO Status=2, MOMSN=2006, MT Status=2, MTMSN=0
2021-04-13T19:44:21.325Z,1618343061.325 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-04-13T19:44:37.489Z,1618343077.489 [NAL9602](INFO): SBD MO Status=2, MOMSN=2006, MT Status=2, MTMSN=0
2021-04-13T19:44:37.489Z,1618343077.489 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-04-13T19:45:01.725Z,1618343101.725 [NAL9602](INFO): SBD MO Status=2, MOMSN=2006, MT Status=2, MTMSN=0
2021-04-13T19:45:01.725Z,1618343101.725 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-04-13T19:45:30.409Z,1618343130.409 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2021-04-13T19:45:57.490Z,1618343157.490 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-13T19:45:57.490Z,1618343157.490 [Default:CheckIn:C.Wait] Stopped
2021-04-13T19:45:57.490Z,1618343157.490 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-13T19:45:57.490Z,1618343157.490 [Default:CheckIn:D] Running Loop=1
2021-04-13T19:45:57.897Z,1618343157.897 [Default:CheckIn:D] Stopped
2021-04-13T19:45:57.897Z,1618343157.897 [Default:CheckIn:E] Running Loop=1
2021-04-13T19:45:58.314Z,1618343158.314 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 117.940438 min 
2021-04-13T19:45:58.314Z,1618343158.314 [Default:CheckIn:E] Stopped
2021-04-13T19:45:58.314Z,1618343158.314 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-13T19:45:58.315Z,1618343158.315 [Default:CheckIn] Stopped
2021-04-13T19:45:58.315Z,1618343158.315 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-13T19:45:58.315Z,1618343158.315 [Default:CheckIn](INFO): Running loop #22
2021-04-13T19:45:58.315Z,1618343158.315 [Default:CheckIn] Running Loop=22
2021-04-13T19:45:58.315Z,1618343158.315 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-13T19:45:58.315Z,1618343158.315 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-13T19:46:00.315Z,1618343160.315 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194559.00,A,3648.17963,N,12147.28428,W,1.886,359.26,130421,,,A*76
2021-04-13T19:46:00.317Z,1618343160.317 [NAL9602](INFO): GPS fix at 20210413T194559: (36.802994, -121.788071)
2021-04-13T19:46:00.328Z,1618343160.328 [Default:CheckIn:Read_GPS] Stopped
2021-04-13T19:46:00.328Z,1618343160.328 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-13T19:46:10.617Z,1618343170.617 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210413T174526/Courier0067.lzma
2021-04-13T19:46:11.620Z,1618343171.620 [DataOverHttps](INFO): Moved sent file to Logs/20210413T174526/Courier0067.lzma.bak
2021-04-13T19:46:11.620Z,1618343171.620 [DataOverHttps](INFO): SBD MOMSN=15565516
2021-04-13T19:46:32.397Z,1618343192.397 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-13T19:46:32.742Z,1618343192.742 [DataOverHttps](INFO): Sending 206 bytes from file Logs/20210413T174526/Express0068.lzma
2021-04-13T19:46:33.744Z,1618343193.744 [DataOverHttps](INFO): Moved sent file to Logs/20210413T174526/Express0068.lzma.bak
2021-04-13T19:46:33.744Z,1618343193.744 [DataOverHttps](INFO): SBD MOMSN=15565519
2021-04-13T19:46:36.120Z,1618343196.120 [Default:CheckIn:Read_Iridium] Stopped
2021-04-13T19:46:36.120Z,1618343196.120 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-13T19:46:36.120Z,1618343196.120 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-13T19:51:36.613Z,1618343496.613 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-13T19:51:36.613Z,1618343496.613 [Default:CheckIn:C.Wait] Stopped
2021-04-13T19:51:36.613Z,1618343496.613 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-13T19:51:36.613Z,1618343496.613 [Default:CheckIn:D] Running Loop=1
2021-04-13T19:51:37.018Z,1618343497.018 [Default:CheckIn:D] Stopped
2021-04-13T19:51:37.018Z,1618343497.018 [Default:CheckIn:E] Running Loop=1
2021-04-13T19:51:37.464Z,1618343497.464 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 123.592440 min 
2021-04-13T19:51:37.464Z,1618343497.464 [Default:CheckIn:E] Stopped
2021-04-13T19:51:37.464Z,1618343497.464 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-13T19:51:37.464Z,1618343497.464 [Default:CheckIn] Stopped
2021-04-13T19:51:37.464Z,1618343497.464 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-13T19:51:37.464Z,1618343497.464 [Default:CheckIn](INFO): Running loop #23
2021-04-13T19:51:37.464Z,1618343497.464 [Default:CheckIn] Running Loop=23
2021-04-13T19:51:37.465Z,1618343497.465 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-13T19:51:37.465Z,1618343497.465 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-13T19:51:39.433Z,1618343499.433 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,195138.00,A,3648.16558,N,12147.29436,W,1.283,28.04,130421,,,A*45
2021-04-13T19:51:39.435Z,1618343499.435 [NAL9602](INFO): GPS fix at 20210413T195138: (36.802760, -121.788239)
2021-04-13T19:51:39.447Z,1618343499.447 [Default:CheckIn:Read_GPS] Stopped
2021-04-13T19:51:39.447Z,1618343499.447 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-13T19:51:42.730Z,1618343502.730 [DVL_micro](ERROR): DVL uart error: serial timeout
2021-04-13T19:51:42.730Z,1618343502.730 [DVL_micro] Communications Fault, FailCount= 1
2021-04-13T19:51:42.730Z,1618343502.730 [DVL_micro](ERROR): Communications Fault
2021-04-13T19:51:42.730Z,1618343502.730 [DVL_micro](ERROR): Failed to parse:
2021-04-13T19:51:42.830Z,1618343502.830 [CBIT](ERROR): Communications Fault in component: DVL_micro
2021-04-13T19:51:43.134Z,1618343503.134 [DVL_micro](INFO): Powering down
2021-04-13T19:51:43.926Z,1618343503.926 [CBIT](INFO): Clearing failed state for component DVL_micro
2021-04-13T19:51:43.926Z,1618343503.926 [DVL_micro] No Fault, FailCount= 1
2021-04-13T19:51:47.332Z,1618343507.332 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210413T174526/Courier0070.lzma
2021-04-13T19:51:48.333Z,1618343508.333 [DataOverHttps](INFO): Moved sent file to Logs/20210413T174526/Courier0070.lzma.bak
2021-04-13T19:51:48.333Z,1618343508.333 [DataOverHttps](INFO): SBD MOMSN=15565523
2021-04-13T19:52:07.858Z,1618343527.858 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20210413T174526/Express0071.lzma
2021-04-13T19:52:08.860Z,1618343528.860 [DataOverHttps](INFO): Moved sent file to Logs/20210413T174526/Express0071.lzma.bak
2021-04-13T19:52:08.860Z,1618343528.860 [DataOverHttps](INFO): SBD MOMSN=15565526
2021-04-13T19:52:10.184Z,1618343530.184 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2021-04-13T19:52:10.266Z,1618343530.266 [NAL9602](ERROR): received: 
+CSQ:0

OK06, 2, 0, 0, 0

OK
2021-04-13T19:52:11.843Z,1618343531.843 [Default:CheckIn:Read_Iridium] Stopped
2021-04-13T19:52:11.843Z,1618343531.843 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-13T19:52:11.843Z,1618343531.843 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-13T19:52:28.445Z,1618343548.445 [NAL9602](INFO): SBD MO Status=2, MOMSN=2006, MT Status=2, MTMSN=0
2021-04-13T19:52:28.445Z,1618343548.445 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-04-13T19:53:14.097Z,1618343594.097 [NAL9602](INFO): SBD MO Status=2, MOMSN=2006, MT Status=2, MTMSN=0
2021-04-13T19:53:14.097Z,1618343594.097 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-04-13T19:53:41.598Z,1618343621.598 [NAL9602](INFO): SBD MO Status=2, MOMSN=2006, MT Status=2, MTMSN=0
2021-04-13T19:53:41.598Z,1618343621.598 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-04-13T19:54:03.406Z,1618343643.406 [NAL9602](INFO): SBD MO Status=2, MOMSN=2006, MT Status=2, MTMSN=0
2021-04-13T19:54:03.406Z,1618343643.406 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-04-13T19:55:21.425Z,1618343721.425 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2021-04-13T19:55:21.425Z,1618343721.425 [DVL_micro](ERROR): Failed to parse:
:TS,000009,+00410,+00000,A
2021-04-13T19:56:41.066Z,1618343801.066 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2021-04-13T19:57:11.763Z,1618343831.763 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-13T19:57:12.585Z,1618343832.585 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-13T19:57:12.586Z,1618343832.586 [Default:CheckIn:C.Wait] Stopped
2021-04-13T19:57:12.586Z,1618343832.586 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-13T19:57:12.586Z,1618343832.586 [Default:CheckIn:D] Running Loop=1
2021-04-13T19:57:13.001Z,1618343833.001 [Default:CheckIn:D] Stopped
2021-04-13T19:57:13.001Z,1618343833.001 [Default:CheckIn:E] Running Loop=1
2021-04-13T19:57:13.414Z,1618343833.414 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 129.192171 min 
2021-04-13T19:57:13.414Z,1618343833.414 [Default:CheckIn:E] Stopped
2021-04-13T19:57:13.415Z,1618343833.415 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-13T19:57:13.415Z,1618343833.415 [Default:CheckIn] Stopped
2021-04-13T19:57:13.415Z,1618343833.415 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-13T19:57:13.415Z,1618343833.415 [Default:CheckIn](INFO): Running loop #24
2021-04-13T19:57:13.415Z,1618343833.415 [Default:CheckIn] Running Loop=24
2021-04-13T19:57:13.415Z,1618343833.415 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-13T19:57:13.415Z,1618343833.415 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-13T19:57:46.108Z,1618343866.108 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2021-04-13T19:57:46.182Z,1618343866.182 [NAL9602](ERROR): received: 
+CSQ:0

OK06, 2, 0, 0, 0

OK
2021-04-13T20:02:13.682Z,1618344133.682 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-04-13T19:57:13.4Z
2021-04-13T20:02:13.682Z,1618344133.682 [Default:CheckIn:Read_GPS] Stopped
2021-04-13T20:02:13.683Z,1618344133.683 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-13T20:02:23.681Z,1618344143.681 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20210413T174526/Courier0073.lzma
2021-04-13T20:02:24.686Z,1618344144.686 [DataOverHttps](INFO): Moved sent file to Logs/20210413T174526/Courier0073.lzma.bak
2021-04-13T20:02:24.686Z,1618344144.686 [DataOverHttps](INFO): SBD MOMSN=15565530
2021-04-13T20:02:31.293Z,1618344151.293 [NAL9602](INFO): SBD MO Status=2, MOMSN=2006, MT Status=2, MTMSN=0
2021-04-13T20:02:31.293Z,1618344151.293 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-04-13T20:02:31.700Z,1618344151.700 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2021-04-13T20:02:41.934Z,1618344161.934 [DataOverHttps](INFO): Sending 205 bytes from file Logs/20210413T174526/Express0074.lzma
2021-04-13T20:02:42.936Z,1618344162.936 [DataOverHttps](INFO): Moved sent file to Logs/20210413T174526/Express0074.lzma.bak
2021-04-13T20:02:42.936Z,1618344162.936 [DataOverHttps](INFO): SBD MOMSN=15565532
2021-04-13T20:02:45.475Z,1618344165.475 [Default:CheckIn:Read_Iridium] Stopped
2021-04-13T20:02:45.475Z,1618344165.475 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-13T20:02:45.475Z,1618344165.475 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-13T20:03:02.395Z,1618344182.395 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-13T20:03:08.093Z,1618344188.093 [DVL_micro](ERROR): DVL BIT error. See manual. Result code: 437
2021-04-13T20:03:08.099Z,1618344188.099 [DVL_micro](ERROR): Failed to parse:
:BD,+000,+00000000.00,+00000000.00,9999.99,000.00
2021-04-13T20:05:23.457Z,1618344323.457 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2021-04-13T20:05:23.457Z,1618344323.457 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,.5,0000.0000
2021-04-13T20:07:43.676Z,1618344463.676 [DVL_micro](ERROR): only read 3 of 4 data items
2021-04-13T20:07:43.677Z,1618344463.677 [DVL_micro](ERROR): Failed to parse:
:RD,+9999.99,+9999.99,+9999.99,
2021-04-13T20:07:46.121Z,1618344466.121 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-13T20:07:46.121Z,1618344466.121 [Default:CheckIn:C.Wait] Stopped
2021-04-13T20:07:46.121Z,1618344466.121 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-13T20:07:46.121Z,1618344466.121 [Default:CheckIn:D] Running Loop=1
2021-04-13T20:07:46.497Z,1618344466.497 [Default:CheckIn:D] Stopped
2021-04-13T20:07:46.497Z,1618344466.497 [Default:CheckIn:E] Running Loop=1
2021-04-13T20:07:46.902Z,1618344466.902 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 139.750439 min 
2021-04-13T20:07:46.902Z,1618344466.902 [Default:CheckIn:E] Stopped
2021-04-13T20:07:46.902Z,1618344466.902 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-13T20:07:46.902Z,1618344466.902 [Default:CheckIn] Stopped
2021-04-13T20:07:46.902Z,1618344466.902 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-13T20:07:46.902Z,1618344466.902 [Default:CheckIn](INFO): Running loop #25
2021-04-13T20:07:46.903Z,1618344466.903 [Default:CheckIn] Running Loop=25
2021-04-13T20:07:46.903Z,1618344466.903 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-13T20:07:46.903Z,1618344466.903 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-13T20:07:48.516Z,1618344468.516 [NAL9602](FAULT): GPS failed to acquire within timeout.
2021-04-13T20:07:48.516Z,1618344468.516 [NAL9602] Data Fault, FailCount= 1
2021-04-13T20:07:48.517Z,1618344468.517 [NAL9602](ERROR): Data Fault
2021-04-13T20:07:48.536Z,1618344468.536 [CBIT](ERROR): Data Fault in component: NAL9602
2021-04-13T20:07:48.908Z,1618344468.908 [NAL9602](INFO): Powering down
2021-04-13T20:07:49.732Z,1618344469.732 [CBIT](INFO): Clearing failed state for component NAL9602
2021-04-13T20:07:49.732Z,1618344469.732 [NAL9602] No Fault, FailCount= 1
2021-04-13T20:08:19.230Z,1618344499.230 [NAL9602](INFO): Powering up NAL9602
2021-04-13T20:08:27.710Z,1618344507.710 [BPC1](FAULT): Battery stick #6 (s/n: 00CA) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0.
2021-04-13T20:08:27.711Z,1618344507.711 [BPC1](INFO): Calculating totals. Valid battery stick count: 55. Valid reserve battery stick count: 6.
2021-04-13T20:08:27.713Z,1618344507.713 [BPC1](INFO): Received data from all battery sticks.
2021-04-13T20:08:30.120Z,1618344510.120 [NAL9602](INFO): NAL9602 initialized
2021-04-13T20:12:47.191Z,1618344767.191 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-04-13T20:07:46.9Z
2021-04-13T20:12:47.192Z,1618344767.192 [Default:CheckIn:Read_GPS] Stopped
2021-04-13T20:12:47.192Z,1618344767.192 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-13T20:12:54.973Z,1618344774.973 [DataOverHttps](INFO): Sending 50 bytes from file Logs/20210413T174526/Courier0076.lzma
2021-04-13T20:12:55.976Z,1618344775.976 [DataOverHttps](INFO): Moved sent file to Logs/20210413T174526/Courier0076.lzma.bak
2021-04-13T20:12:55.976Z,1618344775.976 [DataOverHttps](INFO): SBD MOMSN=15565536
2021-04-13T20:13:12.727Z,1618344792.727 [DataOverHttps](INFO): Sending 327 bytes from file Logs/20210413T174526/Express0077.lzma
2021-04-13T20:13:13.728Z,1618344793.728 [DataOverHttps](INFO): Moved sent file to Logs/20210413T174526/Express0077.lzma.bak
2021-04-13T20:13:13.728Z,1618344793.728 [DataOverHttps](INFO): SBD MOMSN=15565538
2021-04-13T20:13:15.883Z,1618344795.883 [Default:CheckIn:Read_Iridium] Stopped
2021-04-13T20:13:15.883Z,1618344795.883 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-13T20:13:15.883Z,1618344795.883 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-13T20:13:33.229Z,1618344813.229 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2021-04-13T20:14:03.955Z,1618344843.955 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-13T20:18:16.623Z,1618345096.623 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-13T20:18:16.623Z,1618345096.623 [Default:CheckIn:C.Wait] Stopped
2021-04-13T20:18:16.623Z,1618345096.623 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-13T20:18:16.623Z,1618345096.623 [Default:CheckIn:D] Running Loop=1
2021-04-13T20:18:17.017Z,1618345097.017 [Default:CheckIn:D] Stopped
2021-04-13T20:18:17.017Z,1618345097.017 [Default:CheckIn:E] Running Loop=1
2021-04-13T20:18:17.403Z,1618345097.403 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 150.259115 min 
2021-04-13T20:18:17.403Z,1618345097.403 [Default:CheckIn:E] Stopped
2021-04-13T20:18:17.403Z,1618345097.403 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-13T20:18:17.403Z,1618345097.403 [Default:CheckIn] Stopped
2021-04-13T20:18:17.404Z,1618345097.404 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-13T20:18:17.404Z,1618345097.404 [Default:CheckIn](INFO): Running loop #26
2021-04-13T20:18:17.404Z,1618345097.404 [Default:CheckIn] Running Loop=26
2021-04-13T20:18:17.404Z,1618345097.404 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-13T20:18:17.404Z,1618345097.404 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-13T20:18:50.088Z,1618345130.088 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2021-04-13T20:18:50.162Z,1618345130.162 [NAL9602](ERROR): received: 
+CSQ:0

OK06, 2, 0, 0, 0

OK
2021-04-13T20:21:54.317Z,1618345314.317 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2021-04-13T20:21:54.317Z,1618345314.317 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,+16.9,0000.0,148

2021-04-13T20:23:17.583Z,1618345397.583 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-04-13T20:18:17.4Z
2021-04-13T20:23:17.583Z,1618345397.583 [Default:CheckIn:Read_GPS] Stopped
2021-04-13T20:23:17.583Z,1618345397.583 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-13T20:23:21.184Z,1618345401.184 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2021-04-13T20:23:25.229Z,1618345405.229 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20210413T174526/Courier0079.lzma
2021-04-13T20:23:26.232Z,1618345406.232 [DataOverHttps](INFO): Moved sent file to Logs/20210413T174526/Courier0079.lzma.bak
2021-04-13T20:23:26.232Z,1618345406.232 [DataOverHttps](INFO): SBD MOMSN=15565544
2021-04-13T20:23:44.670Z,1618345424.670 [DataOverHttps](INFO): Sending 209 bytes from file Logs/20210413T174526/Express0080.lzma
2021-04-13T20:23:45.672Z,1618345425.672 [DataOverHttps](INFO): Moved sent file to Logs/20210413T174526/Express0080.lzma.bak
2021-04-13T20:23:45.672Z,1618345425.672 [DataOverHttps](INFO): SBD MOMSN=15565548
2021-04-13T20:23:47.899Z,1618345427.899 [Default:CheckIn:Read_Iridium] Stopped
2021-04-13T20:23:47.900Z,1618345427.900 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-13T20:23:47.900Z,1618345427.900 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-13T20:23:51.887Z,1618345431.887 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-13T20:26:44.413Z,1618345604.413 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2021-04-13T20:26:44.414Z,1618345604.414 [DVL_micro](ERROR): Failed to parse:
:TS,000000,35.0,+170,1489.0,0-01656,+01174,+00131,+00000,A
2021-04-13T20:28:48.497Z,1618345728.497 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-13T20:28:48.497Z,1618345728.497 [Default:CheckIn:C.Wait] Stopped
2021-04-13T20:28:48.497Z,1618345728.497 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-13T20:28:48.499Z,1618345728.499 [Default:CheckIn:D] Running Loop=1
2021-04-13T20:28:48.900Z,1618345728.900 [Default:CheckIn:D] Stopped
2021-04-13T20:28:48.900Z,1618345728.900 [Default:CheckIn:E] Running Loop=1
2021-04-13T20:28:49.318Z,1618345729.318 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 160.790479 min 
2021-04-13T20:28:49.318Z,1618345729.318 [Default:CheckIn:E] Stopped
2021-04-13T20:28:49.318Z,1618345729.318 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-13T20:28:49.318Z,1618345729.318 [Default:CheckIn] Stopped
2021-04-13T20:28:49.318Z,1618345729.318 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-13T20:28:49.318Z,1618345729.318 [Default:CheckIn](INFO): Running loop #27
2021-04-13T20:28:49.318Z,1618345729.318 [Default:CheckIn] Running Loop=27
2021-04-13T20:28:49.319Z,1618345729.319 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-13T20:28:49.319Z,1618345729.319 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-13T20:28:50.904Z,1618345730.904 [NAL9602](FAULT): GPS failed to acquire within timeout.
2021-04-13T20:28:50.904Z,1618345730.904 [NAL9602] Data Fault, FailCount= 2
2021-04-13T20:28:50.904Z,1618345730.904 [NAL9602](ERROR): Data Fault
2021-04-13T20:28:50.952Z,1618345730.952 [CBIT](ERROR): Data Fault in component: NAL9602
2021-04-13T20:28:51.311Z,1618345731.311 [NAL9602](INFO): Powering down
2021-04-13T20:28:52.140Z,1618345732.140 [CBIT](INFO): Clearing failed state for component NAL9602
2021-04-13T20:28:52.140Z,1618345732.140 [NAL9602] No Fault, FailCount= 2
2021-04-13T20:29:21.607Z,1618345761.607 [NAL9602](INFO): Powering up NAL9602
2021-04-13T20:29:32.541Z,1618345772.541 [NAL9602](INFO): NAL9602 initialized
2021-04-13T20:31:34.933Z,1618345894.933 [DVL_micro](ERROR): only read 3 of 4 data items
2021-04-13T20:31:34.933Z,1618345894.933 [DVL_micro](ERROR): Failed to parse:
:RD,+9999.99,+9999.99,+99999.99
2021-04-13T20:33:49.523Z,1618346029.523 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-04-13T20:28:49.3Z
2021-04-13T20:33:49.524Z,1618346029.524 [Default:CheckIn:Read_GPS] Stopped
2021-04-13T20:33:49.524Z,1618346029.524 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-13T20:33:55.139Z,1618346035.139 [DVL_micro](ERROR): only read 1 of 4 data items
2021-04-13T20:33:55.140Z,1618346035.140 [DVL_micro](ERROR): Failed to parse:
:BI,+00707-00118,+00000,I
2021-04-13T20:33:57.169Z,1618346037.169 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20210413T174526/Courier0082.lzma
2021-04-13T20:33:58.172Z,1618346038.172 [DataOverHttps](INFO): Moved sent file to Logs/20210413T174526/Courier0082.lzma.bak
2021-04-13T20:33:58.172Z,1618346038.172 [DataOverHttps](INFO): SBD MOMSN=15565552
2021-04-13T20:34:15.270Z,1618346055.270 [DataOverHttps](INFO): Sending 225 bytes from file Logs/20210413T174526/Express0083.lzma
2021-04-13T20:34:16.272Z,1618346056.272 [DataOverHttps](INFO): Moved sent file to Logs/20210413T174526/Express0083.lzma.bak
2021-04-13T20:34:16.272Z,1618346056.272 [DataOverHttps](INFO): SBD MOMSN=15565554
2021-04-13T20:34:18.577Z,1618346058.577 [Default:CheckIn:Read_Iridium] Stopped
2021-04-13T20:34:18.577Z,1618346058.577 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-13T20:34:18.577Z,1618346058.577 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-13T20:34:35.540Z,1618346075.540 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2021-04-13T20:35:06.267Z,1618346106.267 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-13T20:38:10.063Z,1618346290.063 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2021-04-13T20:38:10.063Z,1618346290.063 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,00.0,1489.0,000
2021-04-13T20:39:19.186Z,1618346359.186 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-13T20:39:19.187Z,1618346359.187 [Default:CheckIn:C.Wait] Stopped
2021-04-13T20:39:19.187Z,1618346359.187 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-13T20:39:19.187Z,1618346359.187 [Default:CheckIn:D] Running Loop=1
2021-04-13T20:39:19.561Z,1618346359.561 [Default:CheckIn:D] Stopped
2021-04-13T20:39:19.561Z,1618346359.561 [Default:CheckIn:E] Running Loop=1
2021-04-13T20:39:19.989Z,1618346359.989 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 171.301497 min 
2021-04-13T20:39:19.989Z,1618346359.989 [Default:CheckIn:E] Stopped
2021-04-13T20:39:19.989Z,1618346359.989 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-13T20:39:19.989Z,1618346359.989 [Default:CheckIn] Stopped
2021-04-13T20:39:19.989Z,1618346359.989 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-13T20:39:19.989Z,1618346359.989 [Default:CheckIn](INFO): Running loop #28
2021-04-13T20:39:19.989Z,1618346359.989 [Default:CheckIn] Running Loop=28
2021-04-13T20:39:19.989Z,1618346359.989 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-13T20:39:19.990Z,1618346359.990 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-13T20:39:52.680Z,1618346392.680 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2021-04-13T20:39:52.762Z,1618346392.762 [NAL9602](ERROR): received: 
+CSQ:0

OK06, 2, 0, 0, 0

OK
2021-04-13T20:40:22.983Z,1618346422.983 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2021-04-13T20:40:22.983Z,1618346422.983 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,+17.,1489.0,000
2021-04-13T20:44:20.238Z,1618346660.238 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-04-13T20:39:19.0Z
2021-04-13T20:44:20.238Z,1618346660.238 [Default:CheckIn:Read_GPS] Stopped
2021-04-13T20:44:20.238Z,1618346660.238 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-13T20:44:24.321Z,1618346664.321 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2021-04-13T20:44:32.722Z,1618346672.722 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20210413T174526/Courier0085.lzma
2021-04-13T20:44:33.728Z,1618346673.728 [DataOverHttps](INFO): Moved sent file to Logs/20210413T174526/Courier0085.lzma.bak
2021-04-13T20:44:33.728Z,1618346673.728 [DataOverHttps](INFO): SBD MOMSN=15565574
2021-04-13T20:44:55.027Z,1618346695.027 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-13T20:45:00.218Z,1618346700.218 [DataOverHttps](INFO): Sending 209 bytes from file Logs/20210413T174526/Express0086.lzma
2021-04-13T20:45:01.220Z,1618346701.220 [DataOverHttps](INFO): Moved sent file to Logs/20210413T174526/Express0086.lzma.bak
2021-04-13T20:45:01.220Z,1618346701.220 [DataOverHttps](INFO): SBD MOMSN=15565576
2021-04-13T20:45:05.161Z,1618346705.161 [Default:CheckIn:Read_Iridium] Stopped
2021-04-13T20:45:05.161Z,1618346705.161 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-13T20:45:05.161Z,1618346705.161 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-13T20:45:57.252Z,1618346757.252 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2021-04-13T20:45:57.253Z,1618346757.253 [DVL_micro](ERROR): Failed to parse:
:TS,000000035.0,+17.4,0000.0,1489.0,000
2021-04-13T20:46:58.266Z,1618346818.266 [DVL_micro](ERROR): Failed to parse:
:WI,+01863,-01581,+00280,+00000,A
2021-04-13T20:50:05.837Z,1618347005.837 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-13T20:50:05.837Z,1618347005.837 [Default:CheckIn:C.Wait] Stopped
2021-04-13T20:50:05.837Z,1618347005.837 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-13T20:50:05.837Z,1618347005.837 [Default:CheckIn:D] Running Loop=1
2021-04-13T20:50:06.217Z,1618347006.217 [Default:CheckIn:D] Stopped
2021-04-13T20:50:06.217Z,1618347006.217 [Default:CheckIn:E] Running Loop=1
2021-04-13T20:50:06.627Z,1618347006.627 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 182.079102 min 
2021-04-13T20:50:06.627Z,1618347006.627 [Default:CheckIn:E] Stopped
2021-04-13T20:50:06.627Z,1618347006.627 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-13T20:50:06.627Z,1618347006.627 [Default:CheckIn] Stopped
2021-04-13T20:50:06.627Z,1618347006.627 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-13T20:50:06.627Z,1618347006.627 [Default:CheckIn](INFO): Running loop #29
2021-04-13T20:50:06.627Z,1618347006.627 [Default:CheckIn] Running Loop=29
2021-04-13T20:50:06.628Z,1618347006.628 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-13T20:50:06.628Z,1618347006.628 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-13T20:50:08.231Z,1618347008.231 [NAL9602](FAULT): GPS failed to acquire within timeout.
2021-04-13T20:50:08.232Z,1618347008.232 [NAL9602] Data Fault, FailCount= 3
2021-04-13T20:50:08.232Z,1618347008.232 [NAL9602](ERROR): Data Fault
2021-04-13T20:50:08.295Z,1618347008.295 [CBIT](ERROR): Data Fault in component: NAL9602
2021-04-13T20:50:08.636Z,1618347008.636 [NAL9602](INFO): Powering down
2021-04-13T20:50:09.494Z,1618347009.494 [CBIT](INFO): Clearing failed state for component NAL9602
2021-04-13T20:50:09.494Z,1618347009.494 [NAL9602] No Fault, FailCount= 3
2021-04-13T20:50:38.932Z,1618347038.932 [NAL9602](INFO): Powering up NAL9602
2021-04-13T20:50:49.892Z,1618347049.892 [NAL9602](INFO): NAL9602 initialized
2021-04-13T20:50:53.151Z,1618347053.151 [DVL_micro](ERROR): Failed to parse:
:0,-01811,+00330,+00000,I
2021-04-13T20:51:00.812Z,1618347060.812 [DVL_micro](ERROR): Failed to parse:
:T

2021-04-13T20:55:06.844Z,1618347306.844 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-04-13T20:50:06.6Z
2021-04-13T20:55:06.844Z,1618347306.844 [Default:CheckIn:Read_GPS] Stopped
2021-04-13T20:55:06.844Z,1618347306.844 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-13T20:55:14.509Z,1618347314.509 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20210413T174526/Courier0088.lzma
2021-04-13T20:55:15.512Z,1618347315.512 [DataOverHttps](INFO): Moved sent file to Logs/20210413T174526/Courier0088.lzma.bak
2021-04-13T20:55:15.512Z,1618347315.512 [DataOverHttps](INFO): SBD MOMSN=15565585
2021-04-13T20:55:32.954Z,1618347332.954 [DataOverHttps](INFO): Sending 226 bytes from file Logs/20210413T174526/Express0089.lzma
2021-04-13T20:55:33.956Z,1618347333.956 [DataOverHttps](INFO): Moved sent file to Logs/20210413T174526/Express0089.lzma.bak
2021-04-13T20:55:33.956Z,1618347333.956 [DataOverHttps](INFO): SBD MOMSN=15565587
2021-04-13T20:55:36.387Z,1618347336.387 [Default:CheckIn:Read_Iridium] Stopped
2021-04-13T20:55:36.387Z,1618347336.387 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-13T20:55:36.387Z,1618347336.387 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-13T20:55:46.853Z,1618347346.853 [DAT](INFO): unknown deviceResponse_: Acoustic Wakeup

2021-04-13T20:55:46.854Z,1618347346.854 [DAT](INFO): commRate: 800
2021-04-13T20:55:47.661Z,1618347347.661 [DAT](INFO): unknown deviceResponse_: Lowpower

2021-04-13T20:55:52.916Z,1618347352.916 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2021-04-13T20:56:23.615Z,1618347383.615 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-13T21:00:33.720Z,1618347633.720 [DAT](INFO): unknown deviceResponse_: Acoustic Wakeup

2021-04-13T21:00:33.722Z,1618347633.722 [DAT](INFO): commRate: 800
2021-04-13T21:00:34.528Z,1618347634.528 [DAT](INFO): unknown deviceResponse_: Lowpower

2021-04-13T21:00:36.962Z,1618347636.962 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-04-13T21:00:36.962Z,1618347636.962 [Default:CheckIn:C.Wait] Stopped
2021-04-13T21:00:36.962Z,1618347636.962 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-13T21:00:36.962Z,1618347636.962 [Default:CheckIn:D] Running Loop=1
2021-04-13T21:00:37.381Z,1618347637.381 [Default:CheckIn:D] Stopped
2021-04-13T21:00:37.381Z,1618347637.381 [Default:CheckIn:E] Running Loop=1
2021-04-13T21:00:37.786Z,1618347637.786 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 192.598503 min 
2021-04-13T21:00:37.787Z,1618347637.787 [Default:CheckIn:E] Stopped
2021-04-13T21:00:37.787Z,1618347637.787 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-04-13T21:00:37.787Z,1618347637.787 [Default:CheckIn] Stopped
2021-04-13T21:00:37.787Z,1618347637.787 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-13T21:00:37.787Z,1618347637.787 [Default:CheckIn](INFO): Running loop #30
2021-04-13T21:00:37.787Z,1618347637.787 [Default:CheckIn] Running Loop=30
2021-04-13T21:00:37.787Z,1618347637.787 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-04-13T21:00:37.787Z,1618347637.787 [Default:CheckIn:Read_GPS] Running Loop=1
2021-04-13T21:01:10.484Z,1618347670.484 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2021-04-13T21:01:10.558Z,1618347670.558 [NAL9602](ERROR): received: 
+CSQ:0

OK06, 2, 0, 0, 0

OK
2021-04-13T21:01:39.173Z,1618347699.173 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2021-04-13T21:01:39.173Z,1618347699.173 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35,0000.0,1489.0,000
2021-04-13T21:05:31.486Z,1618347931.486 [DVL_micro](ERROR): only read 3 of 4 data items
2021-04-13T21:05:31.486Z,1618347931.486 [DVL_micro](ERROR): Failed to parse:
:RD,+9999.99,+9999.999,+9999.99
2021-04-13T21:05:37.944Z,1618347937.944 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-04-13T21:00:37.8Z
2021-04-13T21:05:37.944Z,1618347937.944 [Default:CheckIn:Read_GPS] Stopped
2021-04-13T21:05:37.944Z,1618347937.944 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-04-13T21:05:41.976Z,1618347941.976 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2021-04-13T21:05:45.773Z,1618347945.773 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20210413T174526/Courier0091.lzma
2021-04-13T21:05:46.776Z,1618347946.776 [DataOverHttps](INFO): Moved sent file to Logs/20210413T174526/Courier0091.lzma.bak
2021-04-13T21:05:46.776Z,1618347946.776 [DataOverHttps](INFO): SBD MOMSN=15565594
2021-04-13T21:06:04.214Z,1618347964.214 [DataOverHttps](INFO): Sending 209 bytes from file Logs/20210413T174526/Express0092.lzma
2021-04-13T21:06:05.216Z,1618347965.216 [DataOverHttps](INFO): Moved sent file to Logs/20210413T174526/Express0092.lzma.bak
2021-04-13T21:06:05.216Z,1618347965.216 [DataOverHttps](INFO): SBD MOMSN=15565596
2021-04-13T21:06:08.669Z,1618347968.669 [Default:CheckIn:Read_Iridium] Stopped
2021-04-13T21:06:08.669Z,1618347968.669 [Default:CheckIn:C.Wait] Running Loop=1
2021-04-13T21:06:08.669Z,1618347968.669 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-04-13T21:06:12.679Z,1618347972.679 [NAL9602](INFO): Not Powering down - fast GPS
2021-04-13T21:07:55.101Z,1618348075.101 [CommandLine](IMPORTANT): got command restart application
2021-04-13T21:07:56.110Z,1618348076.110 [Supervisor](INFO): Stop Mission called by Supervisor::terminate
2021-04-13T21:07:56.110Z,1618348076.110 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2021-04-13T21:07:56.111Z,1618348076.111 [CommandLine ThreadHandler](INFO): Thread cancelled.
2021-04-13T21:07:56.270Z,1618348076.270 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2021-04-13T21:07:56.270Z,1618348076.270 [CommandLine ThreadHandler](INFO): Thread cancelled.
2021-04-13T21:07:56.271Z,1618348076.271 [CommandLine](INFO): Join timeout helper Thread ID is 9675
2021-04-13T21:07:56.271Z,1618348076.271 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2021-04-13T21:07:56.271Z,1618348076.271 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2021-04-13T21:07:56.272Z,1618348076.272 [NavChartDb](INFO): Join timeout helper Thread ID is 9676
2021-04-13T21:07:56.666Z,1618348076.666 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2021-04-13T21:07:56.666Z,1618348076.666 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2021-04-13T21:07:56.678Z,1618348076.678 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2021-04-13T21:07:56.678Z,1618348076.678 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2021-04-13T21:07:56.678Z,1618348076.678 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 9677
2021-04-13T21:07:56.950Z,1618348076.950 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2021-04-13T21:07:56.950Z,1618348076.950 [WetLabsBB2FL](INFO): Powering down
2021-04-13T21:07:56.951Z,1618348076.951 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2021-04-13T21:07:56.951Z,1618348076.951 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2021-04-13T21:07:56.952Z,1618348076.952 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2021-04-13T21:07:56.952Z,1618348076.952 [Radio_Surface](INFO): Join timeout helper Thread ID is 9678
2021-04-13T21:07:57.062Z,1618348077.062 [Radio_Surface](INFO): Powering down
2021-04-13T21:07:57.063Z,1618348077.063 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2021-04-13T21:07:57.063Z,1618348077.063 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2021-04-13T21:07:57.078Z,1618348077.078 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler
2021-04-13T21:07:57.078Z,1618348077.078 [Onboard ThreadHandler](INFO): Thread cancelled.
2021-04-13T21:07:57.078Z,1618348077.078 [Onboard](INFO): Join timeout helper Thread ID is 9679
2021-04-13T21:08:01.510Z,1618348081.510 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread.
2021-04-13T21:08:01.510Z,1618348081.510 [Onboard ThreadHandler](INFO): Thread cancelled.
2021-04-13T21:08:01.515Z,1618348081.515 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2021-04-13T21:08:01.515Z,1618348081.515 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2021-04-13T21:08:01.515Z,1618348081.515 [DataOverHttps](INFO): Join timeout helper Thread ID is 9680
2021-04-13T21:08:02.130Z,1618348082.130 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2021-04-13T21:08:02.131Z,1618348082.131 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2021-04-13T21:08:02.142Z,1618348082.142 [ComponentRegistry](INFO): Shutting down BackseatComponent ThreadHandler
2021-04-13T21:08:02.143Z,1618348082.143 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2021-04-13T21:08:02.143Z,1618348082.143 [BackseatComponent](INFO): Join timeout helper Thread ID is 9681
2021-04-13T21:08:02.298Z,1618348082.298 [BackseatComponent ThreadHandler](INFO): Uninitializing protected caller thread.
2021-04-13T21:08:02.298Z,1618348082.298 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2021-04-13T21:08:02.302Z,1618348082.302 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2021-04-13T21:08:02.303Z,1618348082.303 [logger ThreadHandler](INFO): Thread cancelled.
2021-04-13T21:08:02.303Z,1618348082.303 [logger](INFO): Join timeout helper Thread ID is 9682
2021-04-13T21:08:02.326Z,1618348082.326 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2021-04-13T21:08:02.326Z,1618348082.326 [logger ThreadHandler](INFO): Thread cancelled.
2021-04-13T21:08:02.342Z,1618348082.342 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2021-04-13T21:08:02.343Z,1618348082.343 [CommandLine ThreadHandler](INFO): Thread cancelled.
2021-04-13T21:08:02.343Z,1618348082.343 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2021-04-13T21:08:02.343Z,1618348082.343 [controlThread ThreadHandler](INFO): Thread cancelled.
2021-04-13T21:08:02.343Z,1618348082.343 [controlThread](INFO): Join timeout helper Thread ID is 9683
2021-04-13T21:08:02.550Z,1618348082.550 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2021-04-13T21:08:02.550Z,1618348082.550 [controlThread](DEBUG): Uninitializing ControlThread
2021-04-13T21:08:02.551Z,1618348082.551 [AHRS_M2](INFO): Powering down
2021-04-13T21:08:02.694Z,1618348082.694 [DVL_micro](INFO): Powering down
2021-04-13T21:08:02.695Z,1618348082.695 [NAL9602](INFO): Powering down
2021-04-13T21:08:02.696Z,1618348082.696 [DAT](INFO): Powering down
2021-04-13T21:08:02.816Z,1618348082.816 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2021-04-13T21:08:02.817Z,1618348082.817 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2021-04-13T21:08:02.817Z,1618348082.817 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2021-04-13T21:08:02.818Z,1618348082.818 [MissionManager](INFO): Uninitializing Mission Default
2021-04-13T21:08:02.818Z,1618348082.818 [Default] Stopped
2021-04-13T21:08:02.818Z,1618348082.818 [Default](DEBUG): Aggregate::uninitialize Default
2021-04-13T21:08:02.818Z,1618348082.818 [Default:B.GoToSurface] Stopped
2021-04-13T21:08:02.818Z,1618348082.818 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2021-04-13T21:08:02.818Z,1618348082.818 [Default:CheckIn] Stopped
2021-04-13T21:08:02.818Z,1618348082.818 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-04-13T21:08:02.818Z,1618348082.818 [Default:CheckIn:C.Wait] Stopped
2021-04-13T21:08:02.819Z,1618348082.819 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-04-13T21:08:02.821Z,1618348082.821 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2021-04-13T21:08:02.822Z,1618348082.822 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2021-04-13T21:08:02.822Z,1618348082.822 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2021-04-13T21:08:02.822Z,1618348082.822 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2021-04-13T21:08:02.823Z,1618348082.823 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2021-04-13T21:08:02.823Z,1618348082.823 [BuoyancyServo](INFO): Powering down
2021-04-13T21:08:02.838Z,1618348082.838 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2021-04-13T21:08:02.838Z,1618348082.838 [ElevatorServo](INFO): Powering down
2021-04-13T21:08:02.839Z,1618348082.839 [MassServo](DEBUG): Uninitialize Mass Servo.
2021-04-13T21:08:02.839Z,1618348082.839 [MassServo](INFO): Powering down
2021-04-13T21:08:02.840Z,1618348082.840 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2021-04-13T21:08:02.840Z,1618348082.840 [RudderServo](INFO): Powering down
2021-04-13T21:08:02.840Z,1618348082.840 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2021-04-13T21:08:02.840Z,1618348082.840 [ThrusterServo](INFO): Powering down
2021-04-13T21:08:02.841Z,1618348082.841 [SBIT](DEBUG): Uninitialize SBIT Component.
2021-04-13T21:08:02.841Z,1618348082.841 [IBIT](DEBUG): Uninitialize IBIT Component.
2021-04-13T21:08:02.842Z,1618348082.842 [CBIT](DEBUG): Uninitialize CBIT Component.
2021-04-13T21:08:02.842Z,1618348082.842 [CBIT](DEBUG): Powering off loads.
2021-04-13T21:08:02.854Z,1618348082.854 [CBIT](DEBUG): Disabling WDT.
2021-04-13T21:08:02.866Z,1618348082.866 [CBIT](DEBUG): Opening all GF detection circuits.
2021-04-13T21:08:02.867Z,1618348082.867 [controlThread ThreadHandler](INFO): Thread cancelled.
2021-04-13T21:08:02.919Z,1618348082.919 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2021-04-13T21:08:02.921Z,1618348082.921 [Onboard ThreadHandler](INFO): Thread cancelled.
2021-04-13T21:08:02.929Z,1618348082.929 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2021-04-13T21:08:02.973Z,1618348082.973 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2021-04-13T21:08:03.021Z,1618348083.021 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2021-04-13T21:08:03.045Z,1618348083.045 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2021-04-13T21:08:03.119Z,1618348083.119 [logger ThreadHandler](INFO): Thread cancelled.