2021-06-07T15:35:07.392Z,1623080107.392 [Supervisor](DEBUG): Initializing supervisor.
2021-06-07T15:35:07.396Z,1623080107.396 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2021-06-07T15:35:07.396Z,1623080107.396 [SyncHandler](INFO): Protected caller Thread ID is 833
2021-06-07T15:35:07.397Z,1623080107.397 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2021-06-07T15:35:07.398Z,1623080107.398 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2021-06-07T15:35:07.398Z,1623080107.398 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 834
2021-06-07T15:35:07.402Z,1623080107.402 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2021-06-07T15:35:07.423Z,1623080107.423 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2021-06-07T15:35:07.424Z,1623080107.424 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2021-06-07T15:35:07.424Z,1623080107.424 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 835
2021-06-07T15:35:07.426Z,1623080107.426 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2021-06-07T15:35:07.427Z,1623080107.427 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2021-06-07T15:35:07.427Z,1623080107.427 [logger ThreadHandler](INFO): Protected caller Thread ID is 836
2021-06-07T15:35:07.431Z,1623080107.431 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2021-06-07T15:35:07.432Z,1623080107.432 [Supervisor](INFO): Looking for Config files in directory: Config/
2021-06-07T15:35:07.436Z,1623080107.436 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2021-06-07T15:35:07.870Z,1623080107.870 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2021-06-07T15:35:07.872Z,1623080107.872 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2021-06-07T15:35:08.018Z,1623080108.018 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2021-06-07T15:35:08.020Z,1623080108.020 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2021-06-07T15:35:08.101Z,1623080108.101 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2021-06-07T15:35:08.318Z,1623080108.318 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2021-06-07T15:35:08.320Z,1623080108.320 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2021-06-07T15:35:08.401Z,1623080108.401 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2021-06-07T15:35:08.498Z,1623080108.498 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2021-06-07T15:35:08.500Z,1623080108.500 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2021-06-07T15:35:08.846Z,1623080108.846 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2021-06-07T15:35:08.848Z,1623080108.848 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2021-06-07T15:35:08.973Z,1623080108.973 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2021-06-07T15:35:08.974Z,1623080108.974 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2021-06-07T15:35:09.512Z,1623080109.512 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2021-06-07T15:35:09.513Z,1623080109.513 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2021-06-07T15:35:09.708Z,1623080109.708 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2021-06-07T15:35:09.708Z,1623080109.708 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2021-06-07T15:35:10.093Z,1623080110.093 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2021-06-07T15:35:10.095Z,1623080110.095 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2021-06-07T15:35:10.341Z,1623080110.341 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2021-06-07T15:35:10.342Z,1623080110.342 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2021-06-07T15:35:10.445Z,1623080110.445 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2021-06-07T15:35:10.445Z,1623080110.445 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2021-06-07T15:35:11.475Z,1623080111.475 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2021-06-07T15:35:11.626Z,1623080111.626 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2021-06-07T15:35:12.469Z,1623080112.469 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2021-06-07T15:35:12.470Z,1623080112.470 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2021-06-07T15:35:12.690Z,1623080112.690 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2021-06-07T15:35:12.692Z,1623080112.692 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-triton/
2021-06-07T15:35:12.696Z,1623080112.696 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/vehicle.cfg
2021-06-07T15:35:12.896Z,1623080112.896 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/secure.cfg
2021-06-07T15:35:12.981Z,1623080112.981 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Science.cfg
2021-06-07T15:35:13.123Z,1623080113.123 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Simulator.cfg
2021-06-07T15:35:13.246Z,1623080113.246 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Battery.cfg
2021-06-07T15:35:13.522Z,1623080113.522 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2021-06-07T15:35:13.524Z,1623080113.524 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/logger.cfg
2021-06-07T15:35:13.633Z,1623080113.633 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Servo.cfg
2021-06-07T15:35:13.746Z,1623080113.746 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Navigation.cfg
2021-06-07T15:35:13.841Z,1623080113.841 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Sensor.cfg
2021-06-07T15:35:13.987Z,1623080113.987 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Control.cfg
2021-06-07T15:35:14.088Z,1623080114.088 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/BIT.cfg
2021-06-07T15:35:14.189Z,1623080114.189 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2021-06-07T15:35:14.204Z,1623080114.204 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2021-06-07T15:35:14.222Z,1623080114.222 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2021-06-07T15:35:14.223Z,1623080114.223 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2021-06-07T15:35:14.348Z,1623080114.348 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2021-06-07T15:35:14.349Z,1623080114.349 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2021-06-07T15:35:14.424Z,1623080114.424 [VerticalControl](DEBUG): Construct VerticalControl.
2021-06-07T15:35:14.487Z,1623080114.487 [VerticalControl] Loaded
2021-06-07T15:35:14.487Z,1623080114.487 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2021-06-07T15:35:14.490Z,1623080114.490 [HorizontalControl](DEBUG): Construct HorizontalControl.
2021-06-07T15:35:14.529Z,1623080114.529 [HorizontalControl] Loaded
2021-06-07T15:35:14.529Z,1623080114.529 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2021-06-07T15:35:14.532Z,1623080114.532 [SpeedControl](DEBUG): Construct SpeedControl.
2021-06-07T15:35:14.535Z,1623080114.535 [SpeedControl] Loaded
2021-06-07T15:35:14.535Z,1623080114.535 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2021-06-07T15:35:14.538Z,1623080114.538 [LoopControl](DEBUG): Construct LoopControl.
2021-06-07T15:35:14.538Z,1623080114.538 [LoopControl] Loaded
2021-06-07T15:35:14.538Z,1623080114.538 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2021-06-07T15:35:14.539Z,1623080114.539 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2021-06-07T15:35:14.540Z,1623080114.540 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2021-06-07T15:35:14.728Z,1623080114.728 [BuoyancyServo] Loaded
2021-06-07T15:35:14.728Z,1623080114.728 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2021-06-07T15:35:14.747Z,1623080114.747 [ElevatorServo] Loaded
2021-06-07T15:35:14.748Z,1623080114.748 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2021-06-07T15:35:14.766Z,1623080114.766 [MassServo] Loaded
2021-06-07T15:35:14.767Z,1623080114.767 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2021-06-07T15:35:14.785Z,1623080114.785 [RudderServo] Loaded
2021-06-07T15:35:14.785Z,1623080114.785 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2021-06-07T15:35:14.801Z,1623080114.801 [ThrusterHE] Loaded
2021-06-07T15:35:14.801Z,1623080114.801 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread.
2021-06-07T15:35:14.801Z,1623080114.801 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2021-06-07T15:35:14.802Z,1623080114.802 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2021-06-07T15:35:14.861Z,1623080114.861 [DepthRateCalculator] Loaded
2021-06-07T15:35:14.862Z,1623080114.862 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2021-06-07T15:35:14.867Z,1623080114.867 [PitchRateCalculator] Loaded
2021-06-07T15:35:14.867Z,1623080114.867 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2021-06-07T15:35:14.877Z,1623080114.877 [SpeedCalculator] Loaded
2021-06-07T15:35:14.877Z,1623080114.877 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2021-06-07T15:35:14.891Z,1623080114.891 [TempGradientCalculator] Loaded
2021-06-07T15:35:14.891Z,1623080114.891 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2021-06-07T15:35:14.895Z,1623080114.895 [YawRateCalculator] Loaded
2021-06-07T15:35:14.896Z,1623080114.896 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2021-06-07T15:35:14.913Z,1623080114.913 [ElevatorOffsetCalculator] Loaded
2021-06-07T15:35:14.914Z,1623080114.914 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2021-06-07T15:35:14.914Z,1623080114.914 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2021-06-07T15:35:14.915Z,1623080114.915 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2021-06-07T15:35:15.018Z,1623080115.018 [DeadReckonUsingMultipleVelocitySources] Loaded
2021-06-07T15:35:15.018Z,1623080115.018 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2021-06-07T15:35:15.032Z,1623080115.032 [NavChart] Loaded
2021-06-07T15:35:15.032Z,1623080115.032 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2021-06-07T15:35:15.038Z,1623080115.038 [UniversalFixResidualReporter] Loaded
2021-06-07T15:35:15.038Z,1623080115.038 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2021-06-07T15:35:15.039Z,1623080115.039 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2021-06-07T15:35:15.039Z,1623080115.039 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2021-06-07T15:35:15.727Z,1623080115.727 [AHRS_M2] Loaded
2021-06-07T15:35:15.727Z,1623080115.727 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2021-06-07T15:35:15.972Z,1623080115.972 [BackseatComponent] Loaded
2021-06-07T15:35:15.973Z,1623080115.973 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2021-06-07T15:35:15.974Z,1623080115.974 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 4086A4E0
2021-06-07T15:35:15.974Z,1623080115.974 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 919
2021-06-07T15:35:15.977Z,1623080115.977 [LcmUniversalReporter] Loaded
2021-06-07T15:35:15.977Z,1623080115.977 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2021-06-07T15:35:16.797Z,1623080116.797 [BPC1] Loaded
2021-06-07T15:35:16.798Z,1623080116.798 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2021-06-07T15:35:16.939Z,1623080116.939 [DataOverHttps] Loaded
2021-06-07T15:35:16.939Z,1623080116.939 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2021-06-07T15:35:16.940Z,1623080116.940 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4089A4E0
2021-06-07T15:35:16.940Z,1623080116.940 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 920
2021-06-07T15:35:16.961Z,1623080116.961 [Depth_Keller] Loaded
2021-06-07T15:35:16.961Z,1623080116.961 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2021-06-07T15:35:17.138Z,1623080117.138 [NAL9602] Loaded
2021-06-07T15:35:17.138Z,1623080117.138 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2021-06-07T15:35:17.298Z,1623080117.298 [Onboard] Loaded
2021-06-07T15:35:17.299Z,1623080117.299 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2021-06-07T15:35:17.321Z,1623080117.321 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 408CA4E0
2021-06-07T15:35:17.321Z,1623080117.321 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 921
2021-06-07T15:35:17.347Z,1623080117.347 [Power24vConverter] Loaded
2021-06-07T15:35:17.347Z,1623080117.347 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2021-06-07T15:35:17.361Z,1623080117.361 [Radio_Surface] Loaded
2021-06-07T15:35:17.361Z,1623080117.361 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2021-06-07T15:35:17.362Z,1623080117.362 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408FA4E0
2021-06-07T15:35:17.362Z,1623080117.362 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 922
2021-06-07T15:35:17.363Z,1623080117.363 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2021-06-07T15:35:17.364Z,1623080117.364 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2021-06-07T15:35:17.585Z,1623080117.585 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2021-06-07T15:35:17.586Z,1623080117.586 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2021-06-07T15:35:17.728Z,1623080117.728 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2021-06-07T15:35:17.729Z,1623080117.729 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2021-06-07T15:35:17.773Z,1623080117.773 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2021-06-07T15:35:17.773Z,1623080117.773 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2021-06-07T15:35:18.002Z,1623080118.002 [CTD_Seabird] Loaded
2021-06-07T15:35:18.003Z,1623080118.003 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2021-06-07T15:35:18.004Z,1623080118.004 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40A184E0
2021-06-07T15:35:18.004Z,1623080118.004 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 923
2021-06-07T15:35:18.025Z,1623080118.025 [PAR_Licor] Loaded
2021-06-07T15:35:18.025Z,1623080118.025 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2021-06-07T15:35:18.057Z,1623080118.057 [WetLabsBB2FL] Loaded
2021-06-07T15:35:18.058Z,1623080118.058 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2021-06-07T15:35:18.059Z,1623080118.059 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40A484E0
2021-06-07T15:35:18.059Z,1623080118.059 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 924
2021-06-07T15:35:18.060Z,1623080118.060 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2021-06-07T15:35:18.061Z,1623080118.061 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2021-06-07T15:35:18.462Z,1623080118.462 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2021-06-07T15:35:18.463Z,1623080118.463 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2021-06-07T15:35:18.649Z,1623080118.649 [SBIT](DEBUG): Construct Startup Built In Test.
2021-06-07T15:35:18.658Z,1623080118.658 [SBIT] Loaded
2021-06-07T15:35:18.658Z,1623080118.658 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2021-06-07T15:35:18.661Z,1623080118.661 [IBIT](DEBUG): Construct Initiated Built In Test.
2021-06-07T15:35:18.674Z,1623080118.674 [IBIT] Loaded
2021-06-07T15:35:18.675Z,1623080118.675 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2021-06-07T15:35:18.681Z,1623080118.681 [CBIT](DEBUG): Construct Continuous Built In Test.
2021-06-07T15:35:18.785Z,1623080118.785 [CBIT] Loaded
2021-06-07T15:35:18.785Z,1623080118.785 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2021-06-07T15:35:18.786Z,1623080118.786 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2021-06-07T15:35:18.792Z,1623080118.792 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2021-06-07T15:35:18.795Z,1623080118.795 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2021-06-07T15:35:18.806Z,1623080118.806 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2021-06-07T15:35:18.807Z,1623080118.807 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B2D4E0
2021-06-07T15:35:18.807Z,1623080118.807 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 925
2021-06-07T15:35:18.812Z,1623080118.812 [Supervisor](INFO): Main Thread ID is 829
2021-06-07T15:35:18.812Z,1623080118.812 [Supervisor](DEBUG): Running supervisor.
2021-06-07T15:35:18.813Z,1623080118.813 [CommandLine ThreadHandler](INFO): Handler Thread ID is 926
2021-06-07T15:35:18.815Z,1623080118.815 [controlThread ThreadHandler](INFO): Handler Thread ID is 927
2021-06-07T15:35:18.815Z,1623080118.815 [controlThread](DEBUG): Initializing ControlThread
2021-06-07T15:35:18.816Z,1623080118.816 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2021-06-07T15:35:18.818Z,1623080118.818 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2021-06-07T15:35:18.819Z,1623080118.819 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2021-06-07T15:35:18.819Z,1623080118.819 [LoopControl](DEBUG): Initialize LoopControlComponent.
2021-06-07T15:35:18.821Z,1623080118.821 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2021-06-07T15:35:18.821Z,1623080118.821 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2021-06-07T15:35:18.822Z,1623080118.822 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2021-06-07T15:35:18.822Z,1623080118.822 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2021-06-07T15:35:18.823Z,1623080118.823 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2021-06-07T15:35:18.823Z,1623080118.823 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2021-06-07T15:35:18.824Z,1623080118.824 [NavChart](DEBUG): Initialize NavChart Navigation.
2021-06-07T15:35:18.825Z,1623080118.825 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2021-06-07T15:35:18.832Z,1623080118.832 [SBIT](INFO): Initialize SBIT Component.
2021-06-07T15:35:18.833Z,1623080118.833 [SBIT](IMPORTANT): git: 2021-06-02-ThrusterHE
2021-06-07T15:35:18.833Z,1623080118.833 [SBIT](INFO): git hash: 2c2dae3d4c3cff651e9d151669d77b072e977ae9
2021-06-07T15:35:18.833Z,1623080118.833 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2021-06-07T15:35:18.834Z,1623080118.834 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #1 PREEMPT Tue Dec 18 21:19:28 PST 2018
Kernel Reported: #1 PREEMPT Tue May 26 08:17:09 PDT 2020
2021-06-07T15:35:18.836Z,1623080118.836 [SBIT](INFO): Beginning SBIT in 125.000000 seconds.
2021-06-07T15:35:18.836Z,1623080118.836 [IBIT](INFO): Initialize IBIT Component.
2021-06-07T15:35:18.837Z,1623080118.837 [CBIT](DEBUG): Initialize CBIT Component.
2021-06-07T15:35:18.838Z,1623080118.838 [logger ThreadHandler](INFO): Handler Thread ID is 928
2021-06-07T15:35:18.852Z,1623080118.852 [CBIT](DEBUG): Initialized mux pins.
2021-06-07T15:35:18.852Z,1623080118.852 [CBIT](DEBUG): Initializing the watchdog timer.
2021-06-07T15:35:18.856Z,1623080118.856 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 929
2021-06-07T15:35:18.864Z,1623080118.864 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 930
2021-06-07T15:35:18.865Z,1623080118.865 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2021-06-07T15:35:18.872Z,1623080118.872 [Onboard ThreadHandler](INFO): Handler Thread ID is 931
2021-06-07T15:35:18.877Z,1623080118.877 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2021-06-07T15:35:18.877Z,1623080118.877 [CBIT](DEBUG): Initializing heartbeat.
2021-06-07T15:35:18.893Z,1623080118.893 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 932
2021-06-07T15:35:18.913Z,1623080118.913 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 933
2021-06-07T15:35:18.913Z,1623080118.913 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2021-06-07T15:35:18.917Z,1623080118.917 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 935
2021-06-07T15:35:18.920Z,1623080118.920 [WetLabsBB2FL](INFO): Powering up
2021-06-07T15:35:18.921Z,1623080118.921 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 937
2021-06-07T15:35:18.930Z,1623080118.930 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2021-06-07T15:35:18.930Z,1623080118.930 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2021-06-07T15:35:18.930Z,1623080118.930 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2021-06-07T15:35:18.930Z,1623080118.930 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2021-06-07T15:35:18.930Z,1623080118.930 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2021-06-07T15:35:18.931Z,1623080118.931 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2021-06-07T15:35:18.931Z,1623080118.931 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2021-06-07T15:35:18.931Z,1623080118.931 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2021-06-07T15:35:18.931Z,1623080118.931 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2021-06-07T15:35:18.931Z,1623080118.931 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2021-06-07T15:35:18.931Z,1623080118.931 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2021-06-07T15:35:18.932Z,1623080118.932 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2021-06-07T15:35:18.932Z,1623080118.932 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2021-06-07T15:35:18.932Z,1623080118.932 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2021-06-07T15:35:18.933Z,1623080118.933 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2021-06-07T15:35:18.933Z,1623080118.933 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2021-06-07T15:35:18.948Z,1623080118.948 [CBIT](DEBUG): Deactivating GF circuits.
2021-06-07T15:35:18.949Z,1623080118.949 [CBIT](DEBUG): Deactivating emergency mode.
2021-06-07T15:35:18.984Z,1623080118.984 [CBIT](DEBUG): Backplane powered.
2021-06-07T15:35:18.985Z,1623080118.985 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2021-06-07T15:35:19.023Z,1623080119.023 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2021-06-07T15:35:19.077Z,1623080119.077 [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-06-07T15:35:19.078Z,1623080119.078 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2021-06-07T15:35:19.168Z,1623080119.168 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2021-06-07T15:35:19.189Z,1623080119.189 [Default:A.Wait](DEBUG): Construct Wait.
2021-06-07T15:35:19.192Z,1623080119.192 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2021-06-07T15:35:19.232Z,1623080119.232 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2021-06-07T15:35:19.235Z,1623080119.235 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2021-06-07T15:35:19.273Z,1623080119.273 [Default:E.Execute](DEBUG): Construct Execute.
2021-06-07T15:35:19.277Z,1623080119.277 [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-06-07T15:35:19.282Z,1623080119.282 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,NAL9602,Power24vConverter,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter,
2021-06-07T15:35:19.300Z,1623080119.300 [Radio_Surface](INFO): Powering up
2021-06-07T15:35:19.305Z,1623080119.305 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2021-06-07T15:35:19.493Z,1623080119.493 [Depth_Keller](ERROR): Pressure reading out of range: 1925.893799 decibar
2021-06-07T15:35:19.494Z,1623080119.494 [Power24vConverter](INFO): Powering up.
2021-06-07T15:35:19.552Z,1623080119.552 [DepthRateCalculator](ERROR): Depth measurement is not active
2021-06-07T15:35:19.578Z,1623080119.578 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2021-06-07T15:35:19.584Z,1623080119.584 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2021-06-07T15:35:19.585Z,1623080119.585 [ElevatorServo](DEBUG): Initializing EZServoServo.
2021-06-07T15:35:19.592Z,1623080119.592 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2021-06-07T15:35:19.593Z,1623080119.593 [MassServo](DEBUG): Initializing EZServoServo.
2021-06-07T15:35:19.600Z,1623080119.600 [MassServo](DEBUG): Initializing MassServo.
2021-06-07T15:35:19.601Z,1623080119.601 [RudderServo](DEBUG): Initializing EZServoServo.
2021-06-07T15:35:19.608Z,1623080119.608 [RudderServo](DEBUG): Initializing RudderServo.
2021-06-07T15:35:19.609Z,1623080119.609 [ThrusterHE](DEBUG): Initializing EZServoServo.
2021-06-07T15:35:19.616Z,1623080119.616 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2021-06-07T15:35:20.420Z,1623080120.420 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2021-06-07T15:35:20.420Z,1623080120.420 [RudderServo](FAULT): Rudder failed to initialize
2021-06-07T15:35:20.420Z,1623080120.420 [RudderServo] Communications Fault, FailCount= 1
2021-06-07T15:35:20.420Z,1623080120.420 [RudderServo](ERROR): Communications Fault
2021-06-07T15:35:20.435Z,1623080120.435 [CBIT](ERROR): Communications Fault in component: RudderServo
2021-06-07T15:35:20.661Z,1623080120.661 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2021-06-07T15:35:20.661Z,1623080120.661 [RudderServo](INFO): Powering down
2021-06-07T15:35:21.028Z,1623080121.028 [WetLabsBB2FL](INFO): Powering down
2021-06-07T15:35:21.329Z,1623080121.329 [RudderServo](DEBUG): Initializing EZServoServo.
2021-06-07T15:35:21.449Z,1623080121.449 [RudderServo](DEBUG): Initializing RudderServo.
2021-06-07T15:35:21.453Z,1623080121.453 [CBIT](INFO): Clearing failed state for component RudderServo
2021-06-07T15:35:21.453Z,1623080121.453 [RudderServo] No Fault, FailCount= 1
2021-06-07T15:35:25.944Z,1623080125.944 [CTD_Seabird](ERROR): Device message queue exceeded the allowed limit.
2021-06-07T15:35:47.169Z,1623080147.169 [NAL9602](INFO): Powering up NAL9602
2021-06-07T15:35:58.082Z,1623080158.082 [NAL9602](INFO): NAL9602 initialized
2021-06-07T15:37:24.577Z,1623080244.577 [SBIT](IMPORTANT): Beginning Startup BIT
2021-06-07T15:37:24.597Z,1623080244.597 [CBIT](IMPORTANT): Beginning ground fault scan
2021-06-07T15:37:35.477Z,1623080255.477 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.022015
CHAN A1 (24V): -0.148704
CHAN A2 (12V): 0.003061
CHAN A3 (5V): 0.000367
CHAN B0 (3.3V): 0.001067
CHAN B1 (3.15aV): 0.000629
CHAN B2 (3.15bV): 0.000664
CHAN B3 (GND): -0.000430
OPEN: -0.004185
Full Scale Calc: 4.765 mA, -1.589 mA
2021-06-07T15:38:18.601Z,1623080298.601 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004883
2021-06-07T15:38:18.782Z,1623080298.782 [SBIT](IMPORTANT): SBIT PASSED
2021-06-07T15:38:18.782Z,1623080298.782 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2021-06-07T15:38:18.783Z,1623080298.783 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=6 count;

2021-06-07T15:38:18.783Z,1623080298.783 [SBIT](IMPORTANT): BPC1.batterySamplingInterval=1 minute;

2021-06-07T15:38:18.783Z,1623080298.783 [SBIT](IMPORTANT): BPC1.batteryStickCommsTimeout=10 second;

2021-06-07T15:38:18.783Z,1623080298.783 [SBIT](IMPORTANT): CBIT.abortDepth=165 meter;

2021-06-07T15:38:18.783Z,1623080298.783 [SBIT](IMPORTANT): CBIT.stopDepth=150 meter;

2021-06-07T15:38:18.784Z,1623080298.784 [SBIT](IMPORTANT): DAT.loadAtStartup=0 bool;

2021-06-07T15:38:18.784Z,1623080298.784 [SBIT](IMPORTANT): DropWeight.loadAtStartup=0 bool;

2021-06-07T15:38:18.784Z,1623080298.784 [SBIT](IMPORTANT): Express none WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water;

2021-06-07T15:38:18.784Z,1623080298.784 [SBIT](IMPORTANT): ThrusterServo.loadAtStartup=0 bool;

2021-06-07T15:38:18.784Z,1623080298.784 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=87.804932 cubic_centimeter;

2021-06-07T15:38:18.784Z,1623080298.784 [SBIT](IMPORTANT): VerticalControl.massDefault=26.492700 millimeter;

2021-06-07T15:38:19.164Z,1623080299.164 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2021-06-07T15:38:19.164Z,1623080299.164 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-06-07T15:38:19.166Z,1623080299.166 [MissionManager](IMPORTANT): Started mission Startup
2021-06-07T15:38:19.166Z,1623080299.166 [Startup] Running Loop=1
2021-06-07T15:38:19.166Z,1623080299.166 [Startup](DEBUG): Aggregate::initialize Startup
2021-06-07T15:38:19.166Z,1623080299.166 [Startup:A.GoToSurface] Running Loop=1
2021-06-07T15:38:19.166Z,1623080299.166 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2021-06-07T15:38:19.188Z,1623080299.188 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2021-06-07T15:38:19.188Z,1623080299.188 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2021-06-07T15:38:19.189Z,1623080299.189 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2021-06-07T15:38:19.189Z,1623080299.189 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2021-06-07T15:38:19.189Z,1623080299.189 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2021-06-07T15:38:19.195Z,1623080299.195 [Startup:StartupSatComms] Running Loop=1
2021-06-07T15:38:19.195Z,1623080299.195 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2021-06-07T15:38:19.195Z,1623080299.195 [Startup:StartupSatComms:A] Running Loop=1
2021-06-07T15:38:19.213Z,1623080299.213 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-06-07T15:38:19.577Z,1623080299.577 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2021-06-07T15:38:19.607Z,1623080299.607 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-06-07T15:38:19.607Z,1623080299.607 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2021-06-07T15:39:19.356Z,1623080359.356 [Startup:StartupSatComms:A](INFO): Timed out from 2021-06-07T15:38:19.2Z
2021-06-07T15:39:19.356Z,1623080359.356 [Startup:StartupSatComms:A] Stopped
2021-06-07T15:39:19.356Z,1623080359.356 [Startup:StartupSatComms:B] Running Loop=1
2021-06-07T15:39:19.749Z,1623080359.749 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2021-06-07T15:39:26.542Z,1623080366.542 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20210605T185739/Courier0816.lzma
2021-06-07T15:39:27.545Z,1623080367.545 [DataOverHttps](INFO): Moved sent file to Logs/20210605T185739/Courier0816.lzma.bak
2021-06-07T15:39:27.545Z,1623080367.545 [DataOverHttps](INFO): SBD MOMSN=15699560
2021-06-07T15:39:43.018Z,1623080383.018 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20210607T153507/Courier0000.lzma
2021-06-07T15:39:44.021Z,1623080384.021 [DataOverHttps](INFO): Moved sent file to Logs/20210607T153507/Courier0000.lzma.bak
2021-06-07T15:39:44.021Z,1623080384.021 [DataOverHttps](INFO): SBD MOMSN=15699562
2021-06-07T15:39:59.550Z,1623080399.550 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20210605T185739/Express0817.lzma
2021-06-07T15:40:00.553Z,1623080400.553 [DataOverHttps](INFO): Moved sent file to Logs/20210605T185739/Express0817.lzma.bak
2021-06-07T15:40:00.553Z,1623080400.553 [DataOverHttps](INFO): SBD MOMSN=15699565
2021-06-07T15:40:15.108Z,1623080415.108 [DataOverHttps](INFO): Sending 929 bytes from file Logs/20210607T153507/Express0001.lzma
2021-06-07T15:40:16.100Z,1623080416.100 [DataOverHttps](INFO): Moved sent file to Logs/20210607T153507/Express0001.lzma.bak
2021-06-07T15:40:16.101Z,1623080416.101 [DataOverHttps](INFO): SBD MOMSN=15699567
2021-06-07T15:40:17.934Z,1623080417.934 [Startup:StartupSatComms:B] Stopped
2021-06-07T15:40:17.934Z,1623080417.934 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2021-06-07T15:40:17.934Z,1623080417.934 [Startup:StartupSatComms] Stopped
2021-06-07T15:40:17.934Z,1623080417.934 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2021-06-07T15:40:17.935Z,1623080417.935 [Startup](INFO): Completed Startup
2021-06-07T15:40:17.935Z,1623080417.935 [MissionManager](INFO): Startup is completed.
2021-06-07T15:40:17.936Z,1623080417.936 [MissionManager](INFO): Uninitializing Mission Startup
2021-06-07T15:40:17.936Z,1623080417.936 [Startup] Stopped
2021-06-07T15:40:17.936Z,1623080417.936 [Startup](DEBUG): Aggregate::uninitialize Startup
2021-06-07T15:40:17.936Z,1623080417.936 [Startup:A.GoToSurface] Stopped
2021-06-07T15:40:17.936Z,1623080417.936 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2021-06-07T15:40:18.329Z,1623080418.329 [MissionManager](IMPORTANT): Started mission Default
2021-06-07T15:40:18.329Z,1623080418.329 [Default] Running Loop=1
2021-06-07T15:40:18.330Z,1623080418.330 [Default](DEBUG): Aggregate::initialize Default
2021-06-07T15:40:18.330Z,1623080418.330 [Default:B.GoToSurface] Running Loop=1
2021-06-07T15:40:18.330Z,1623080418.330 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2021-06-07T15:40:18.330Z,1623080418.330 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2021-06-07T15:40:18.331Z,1623080418.331 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2021-06-07T15:40:18.331Z,1623080418.331 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2021-06-07T15:40:18.331Z,1623080418.331 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2021-06-07T15:40:18.332Z,1623080418.332 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2021-06-07T15:40:18.332Z,1623080418.332 [Default:A.Wait] Running Loop=1
2021-06-07T15:40:18.332Z,1623080418.332 [Default:A.Wait](DEBUG): Initialize Wait Component.
2021-06-07T15:40:31.671Z,1623080431.671 [Default:A.Wait](INFO): Done Waiting.
2021-06-07T15:40:31.671Z,1623080431.671 [Default:A.Wait] Stopped
2021-06-07T15:40:31.671Z,1623080431.671 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2021-06-07T15:40:32.082Z,1623080432.082 [Default:CheckIn] Running Loop=1
2021-06-07T15:40:32.082Z,1623080432.082 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-06-07T15:40:32.083Z,1623080432.083 [Default:CheckIn:Read_GPS] Running Loop=1
2021-06-07T15:40:32.470Z,1623080432.470 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2021-06-07T15:41:01.341Z,1623080461.341 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2021-06-07T15:41:20.172Z,1623080480.172 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2021-06-07T15:41:20.172Z,1623080480.172 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-06-07T15:41:20.183Z,1623080480.183 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-06-07T15:41:20.554Z,1623080480.554 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-06-07T15:41:20.554Z,1623080480.554 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2021-06-07T15:44:21.170Z,1623080661.170 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2021-06-07T15:44:21.171Z,1623080661.171 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-06-07T15:44:21.181Z,1623080661.181 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-06-07T15:44:21.596Z,1623080661.596 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-06-07T15:44:21.596Z,1623080661.596 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2021-06-07T15:45:20.163Z,1623080720.163 [Power24vConverter](INFO): Powering down.
2021-06-07T15:45:32.309Z,1623080732.309 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-06-07T15:40:32.1Z
2021-06-07T15:45:32.309Z,1623080732.309 [Default:CheckIn:Read_GPS] Stopped
2021-06-07T15:45:32.309Z,1623080732.309 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-06-07T15:45:32.699Z,1623080732.699 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2021-06-07T15:45:39.114Z,1623080739.114 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20210607T153507/Courier0004.lzma
2021-06-07T15:45:40.117Z,1623080740.117 [DataOverHttps](INFO): Moved sent file to Logs/20210607T153507/Courier0004.lzma.bak
2021-06-07T15:45:40.117Z,1623080740.117 [DataOverHttps](INFO): SBD MOMSN=15699599
2021-06-07T15:45:55.410Z,1623080755.410 [DataOverHttps](INFO): Sending 187 bytes from file Logs/20210607T153507/Express0005.lzma
2021-06-07T15:45:56.412Z,1623080756.412 [DataOverHttps](INFO): Moved sent file to Logs/20210607T153507/Express0005.lzma.bak
2021-06-07T15:45:56.413Z,1623080756.413 [DataOverHttps](INFO): SBD MOMSN=15699602
2021-06-07T15:45:58.149Z,1623080758.149 [Default:CheckIn:Read_Iridium] Stopped
2021-06-07T15:45:58.149Z,1623080758.149 [Default:CheckIn:C.Wait] Running Loop=1
2021-06-07T15:45:58.149Z,1623080758.149 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-06-07T15:45:58.932Z,1623080758.932 [NAL9602](FAULT): GPS failed to acquire within timeout.
2021-06-07T15:45:58.932Z,1623080758.932 [NAL9602] Data Fault, FailCount= 1
2021-06-07T15:45:58.932Z,1623080758.932 [NAL9602](ERROR): Data Fault
2021-06-07T15:45:58.987Z,1623080758.987 [CBIT](ERROR): Data Fault in component: NAL9602
2021-06-07T15:45:59.336Z,1623080759.336 [NAL9602](INFO): Powering down
2021-06-07T15:46:00.261Z,1623080760.261 [CBIT](INFO): Clearing failed state for component NAL9602
2021-06-07T15:46:00.261Z,1623080760.261 [NAL9602] No Fault, FailCount= 1
2021-06-07T15:46:29.656Z,1623080789.656 [NAL9602](INFO): Powering up NAL9602
2021-06-07T15:46:40.564Z,1623080800.564 [NAL9602](INFO): NAL9602 initialized
2021-06-07T15:47:22.167Z,1623080842.167 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2021-06-07T15:47:22.167Z,1623080842.167 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-06-07T15:47:22.179Z,1623080842.179 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-06-07T15:47:22.592Z,1623080842.592 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-06-07T15:47:22.592Z,1623080842.592 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2021-06-07T15:50:23.177Z,1623081023.177 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5
2021-06-07T15:50:23.177Z,1623081023.177 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-06-07T15:50:23.189Z,1623081023.189 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-06-07T15:50:23.574Z,1623081023.574 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-06-07T15:50:23.574Z,1623081023.574 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5
2021-06-07T15:50:58.751Z,1623081058.751 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-06-07T15:50:58.751Z,1623081058.751 [Default:CheckIn:C.Wait] Stopped
2021-06-07T15:50:58.751Z,1623081058.751 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-06-07T15:50:58.751Z,1623081058.751 [Default:CheckIn:D] Running Loop=1
2021-06-07T15:50:59.114Z,1623081059.114 [Default:CheckIn:D] Stopped
2021-06-07T15:50:59.114Z,1623081059.114 [Default:CheckIn:E] Running Loop=1
2021-06-07T15:50:59.534Z,1623081059.534 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.679739 min 
2021-06-07T15:50:59.534Z,1623081059.534 [Default:CheckIn:E] Stopped
2021-06-07T15:50:59.534Z,1623081059.534 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-06-07T15:50:59.534Z,1623081059.534 [Default:CheckIn] Stopped
2021-06-07T15:50:59.534Z,1623081059.534 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-06-07T15:50:59.534Z,1623081059.534 [Default:CheckIn](INFO): Running loop #2
2021-06-07T15:50:59.535Z,1623081059.535 [Default:CheckIn] Running Loop=2
2021-06-07T15:50:59.535Z,1623081059.535 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-06-07T15:50:59.535Z,1623081059.535 [Default:CheckIn:Read_GPS] Running Loop=1
2021-06-07T15:53:24.166Z,1623081204.166 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6
2021-06-07T15:53:24.166Z,1623081204.166 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-06-07T15:53:24.177Z,1623081204.177 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-06-07T15:53:24.591Z,1623081204.591 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-06-07T15:53:24.591Z,1623081204.591 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6
2021-06-07T15:55:59.700Z,1623081359.700 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-06-07T15:50:59.5Z
2021-06-07T15:55:59.700Z,1623081359.700 [Default:CheckIn:Read_GPS] Stopped
2021-06-07T15:55:59.701Z,1623081359.701 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-06-07T15:56:05.738Z,1623081365.738 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20210607T153507/Courier0007.lzma
2021-06-07T15:56:06.740Z,1623081366.740 [DataOverHttps](INFO): Moved sent file to Logs/20210607T153507/Courier0007.lzma.bak
2021-06-07T15:56:06.741Z,1623081366.741 [DataOverHttps](INFO): SBD MOMSN=15699626
2021-06-07T15:56:21.126Z,1623081381.126 [DataOverHttps](INFO): Sending 181 bytes from file Logs/20210607T153507/Express0008.lzma
2021-06-07T15:56:22.116Z,1623081382.116 [DataOverHttps](INFO): Moved sent file to Logs/20210607T153507/Express0008.lzma.bak
2021-06-07T15:56:22.117Z,1623081382.117 [DataOverHttps](INFO): SBD MOMSN=15699628
2021-06-07T15:56:23.957Z,1623081383.957 [Default:CheckIn:Read_Iridium] Stopped
2021-06-07T15:56:23.958Z,1623081383.958 [Default:CheckIn:C.Wait] Running Loop=1
2021-06-07T15:56:23.958Z,1623081383.958 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-06-07T15:56:25.186Z,1623081385.186 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7
2021-06-07T15:56:25.186Z,1623081385.186 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-06-07T15:56:25.206Z,1623081385.206 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-06-07T15:56:25.605Z,1623081385.605 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-06-07T15:56:25.606Z,1623081385.606 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7
2021-06-07T15:56:43.360Z,1623081403.360 [NAL9602](FAULT): GPS failed to acquire within timeout.
2021-06-07T15:56:43.360Z,1623081403.360 [NAL9602] Data Fault, FailCount= 2
2021-06-07T15:56:43.360Z,1623081403.360 [NAL9602](ERROR): Data Fault
2021-06-07T15:56:43.479Z,1623081403.479 [CBIT](ERROR): Data Fault in component: NAL9602
2021-06-07T15:56:43.784Z,1623081403.784 [NAL9602](INFO): Powering down
2021-06-07T15:56:44.559Z,1623081404.559 [CBIT](INFO): Clearing failed state for component NAL9602
2021-06-07T15:56:44.559Z,1623081404.559 [NAL9602] No Fault, FailCount= 2
2021-06-07T15:57:14.020Z,1623081434.020 [NAL9602](INFO): Powering up NAL9602
2021-06-07T15:57:25.080Z,1623081445.080 [NAL9602](INFO): NAL9602 initialized
2021-06-07T15:57:48.766Z,1623081468.766 [CommandLine](IMPORTANT): got command burn on
2021-06-07T15:57:48.766Z,1623081468.766 [CommandLine](IMPORTANT): Activating dropweight wire
2021-06-07T15:59:26.188Z,1623081566.188 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 8
2021-06-07T15:59:26.188Z,1623081566.188 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-06-07T15:59:26.220Z,1623081566.220 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-06-07T15:59:26.579Z,1623081566.579 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-06-07T15:59:26.579Z,1623081566.579 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 8
2021-06-07T16:00:42.586Z,1623081642.586 [CommandLine](IMPORTANT): got command burn off
2021-06-07T16:00:42.586Z,1623081642.586 [CommandLine](IMPORTANT): Deactivating dropweight wire
2021-06-07T16:00:45.733Z,1623081645.733 [CommandLine](IMPORTANT): got command failComponent
2021-06-07T16:00:45.733Z,1623081645.733 [CommandLine](IMPORTANT): Failed components:
2021-06-07T16:00:45.733Z,1623081645.733 [CommandLine](IMPORTANT): No failed Components.
2021-06-07T16:01:24.550Z,1623081684.550 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-06-07T16:01:24.550Z,1623081684.550 [Default:CheckIn:C.Wait] Stopped
2021-06-07T16:01:24.550Z,1623081684.550 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-06-07T16:01:24.550Z,1623081684.550 [Default:CheckIn:D] Running Loop=1
2021-06-07T16:01:24.954Z,1623081684.954 [Default:CheckIn:D] Stopped
2021-06-07T16:01:24.954Z,1623081684.954 [Default:CheckIn:E] Running Loop=1
2021-06-07T16:01:25.346Z,1623081685.346 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 21.110409 min 
2021-06-07T16:01:25.346Z,1623081685.346 [Default:CheckIn:E] Stopped
2021-06-07T16:01:25.346Z,1623081685.346 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-06-07T16:01:25.346Z,1623081685.346 [Default:CheckIn] Stopped
2021-06-07T16:01:25.347Z,1623081685.347 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-06-07T16:01:25.347Z,1623081685.347 [Default:CheckIn](INFO): Running loop #3
2021-06-07T16:01:25.347Z,1623081685.347 [Default:CheckIn] Running Loop=3
2021-06-07T16:01:25.347Z,1623081685.347 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-06-07T16:01:25.347Z,1623081685.347 [Default:CheckIn:Read_GPS] Running Loop=1
2021-06-07T16:02:27.155Z,1623081747.155 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 9
2021-06-07T16:02:27.155Z,1623081747.155 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-06-07T16:02:27.166Z,1623081747.166 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-06-07T16:02:27.572Z,1623081747.572 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-06-07T16:02:27.572Z,1623081747.572 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 9
2021-06-07T16:03:30.573Z,1623081810.573 [BPC1](INFO): Calculating totals. Valid battery stick count: 51. Valid reserve battery stick count: 5.
2021-06-07T16:03:30.581Z,1623081810.581 [BPC1](INFO): Received data from all battery sticks.
2021-06-07T16:05:28.217Z,1623081928.217 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 10
2021-06-07T16:05:28.217Z,1623081928.217 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-06-07T16:05:28.228Z,1623081928.228 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-06-07T16:05:28.642Z,1623081928.642 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-06-07T16:05:28.642Z,1623081928.642 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 10
2021-06-07T16:06:25.578Z,1623081985.578 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-06-07T16:01:25.3Z
2021-06-07T16:06:25.579Z,1623081985.579 [Default:CheckIn:Read_GPS] Stopped
2021-06-07T16:06:25.579Z,1623081985.579 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-06-07T16:06:31.310Z,1623081991.310 [DataOverHttps](INFO): Sending 167 bytes from file Logs/20210607T153507/Courier0010.lzma
2021-06-07T16:06:32.313Z,1623081992.313 [DataOverHttps](INFO): Moved sent file to Logs/20210607T153507/Courier0010.lzma.bak
2021-06-07T16:06:32.313Z,1623081992.313 [DataOverHttps](INFO): SBD MOMSN=15699651
2021-06-07T16:06:53.507Z,1623082013.507 [DataOverHttps](INFO): Sending 275 bytes from file Logs/20210607T153507/Express0011.lzma
2021-06-07T16:06:54.508Z,1623082014.508 [DataOverHttps](INFO): Moved sent file to Logs/20210607T153507/Express0011.lzma.bak
2021-06-07T16:06:54.509Z,1623082014.509 [DataOverHttps](INFO): SBD MOMSN=15699655
2021-06-07T16:06:56.393Z,1623082016.393 [Default:CheckIn:Read_Iridium] Stopped
2021-06-07T16:06:56.393Z,1623082016.393 [Default:CheckIn:C.Wait] Running Loop=1
2021-06-07T16:06:56.393Z,1623082016.393 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-06-07T16:07:27.480Z,1623082047.480 [NAL9602](FAULT): GPS failed to acquire within timeout.
2021-06-07T16:07:27.480Z,1623082047.480 [NAL9602] Data Fault, FailCount= 3
2021-06-07T16:07:27.480Z,1623082047.480 [NAL9602](ERROR): Data Fault
2021-06-07T16:07:27.498Z,1623082047.498 [CBIT](ERROR): Data Fault in component: NAL9602
2021-06-07T16:07:27.886Z,1623082047.886 [NAL9602](INFO): Powering down
2021-06-07T16:07:28.709Z,1623082048.709 [CBIT](INFO): Clearing failed state for component NAL9602
2021-06-07T16:07:28.709Z,1623082048.709 [NAL9602] No Fault, FailCount= 3
2021-06-07T16:07:58.179Z,1623082078.179 [NAL9602](INFO): Powering up NAL9602
2021-06-07T16:08:09.092Z,1623082089.092 [NAL9602](INFO): NAL9602 initialized
2021-06-07T16:08:29.300Z,1623082109.300 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 11
2021-06-07T16:08:29.300Z,1623082109.300 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-06-07T16:08:29.311Z,1623082109.311 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-06-07T16:08:29.713Z,1623082109.713 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-06-07T16:08:29.713Z,1623082109.713 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 11
2021-06-07T16:11:30.339Z,1623082290.339 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 12
2021-06-07T16:11:30.339Z,1623082290.339 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-06-07T16:11:30.375Z,1623082290.375 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-06-07T16:11:30.755Z,1623082290.755 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-06-07T16:11:30.755Z,1623082290.755 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 12
2021-06-07T16:11:57.022Z,1623082317.022 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-06-07T16:11:57.023Z,1623082317.023 [Default:CheckIn:C.Wait] Stopped
2021-06-07T16:11:57.023Z,1623082317.023 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-06-07T16:11:57.023Z,1623082317.023 [Default:CheckIn:D] Running Loop=1
2021-06-07T16:11:57.402Z,1623082317.402 [Default:CheckIn:D] Stopped
2021-06-07T16:11:57.402Z,1623082317.402 [Default:CheckIn:E] Running Loop=1
2021-06-07T16:11:57.812Z,1623082317.812 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 31.651211 min 
2021-06-07T16:11:57.812Z,1623082317.812 [Default:CheckIn:E] Stopped
2021-06-07T16:11:57.813Z,1623082317.813 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-06-07T16:11:57.813Z,1623082317.813 [Default:CheckIn] Stopped
2021-06-07T16:11:57.813Z,1623082317.813 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-06-07T16:11:57.813Z,1623082317.813 [Default:CheckIn](INFO): Running loop #4
2021-06-07T16:11:57.813Z,1623082317.813 [Default:CheckIn] Running Loop=4
2021-06-07T16:11:57.813Z,1623082317.813 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-06-07T16:11:57.813Z,1623082317.813 [Default:CheckIn:Read_GPS] Running Loop=1
2021-06-07T16:14:31.356Z,1623082471.356 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 13
2021-06-07T16:14:31.356Z,1623082471.356 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-06-07T16:14:31.367Z,1623082471.367 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-06-07T16:14:31.746Z,1623082471.746 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-06-07T16:14:31.746Z,1623082471.746 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 13
2021-06-07T16:15:57.838Z,1623082557.838 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,161556.00,A,3648.17255,N,12147.25926,W,2.877,139.99,070621,,,A*79
2021-06-07T16:15:57.842Z,1623082557.842 [NAL9602](INFO): GPS fix at 20210607T161556: (36.802876, -121.787654)
2021-06-07T16:15:57.853Z,1623082557.853 [Default:CheckIn:Read_GPS] Stopped
2021-06-07T16:15:57.853Z,1623082557.853 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-06-07T16:16:07.610Z,1623082567.610 [DataOverHttps](INFO): Sending 222 bytes from file Logs/20210607T153507/Courier0013.lzma
2021-06-07T16:16:08.612Z,1623082568.612 [DataOverHttps](INFO): Moved sent file to Logs/20210607T153507/Courier0013.lzma.bak
2021-06-07T16:16:08.613Z,1623082568.613 [DataOverHttps](INFO): SBD MOMSN=15699679
2021-06-07T16:16:25.440Z,1623082585.440 [DataOverHttps](INFO): Sending 285 bytes from file Logs/20210607T153507/Express0014.lzma
2021-06-07T16:16:26.440Z,1623082586.440 [DataOverHttps](INFO): Moved sent file to Logs/20210607T153507/Express0014.lzma.bak
2021-06-07T16:16:26.441Z,1623082586.441 [DataOverHttps](INFO): SBD MOMSN=15699686
2021-06-07T16:16:28.167Z,1623082588.167 [Default:CheckIn:Read_Iridium] Stopped
2021-06-07T16:16:28.167Z,1623082588.167 [Default:CheckIn:C.Wait] Running Loop=1
2021-06-07T16:16:28.167Z,1623082588.167 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-06-07T16:16:30.563Z,1623082590.563 [NAL9602](INFO): Not Powering down - fast GPS
2021-06-07T16:21:28.822Z,1623082888.822 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-06-07T16:21:28.822Z,1623082888.822 [Default:CheckIn:C.Wait] Stopped
2021-06-07T16:21:28.822Z,1623082888.822 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-06-07T16:21:28.823Z,1623082888.823 [Default:CheckIn:D] Running Loop=1
2021-06-07T16:21:29.229Z,1623082889.229 [Default:CheckIn:D] Stopped
2021-06-07T16:21:29.229Z,1623082889.229 [Default:CheckIn:E] Running Loop=1
2021-06-07T16:21:29.609Z,1623082889.609 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 41.181657 min 
2021-06-07T16:21:29.609Z,1623082889.609 [Default:CheckIn:E] Stopped
2021-06-07T16:21:29.609Z,1623082889.609 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-06-07T16:21:29.609Z,1623082889.609 [Default:CheckIn] Stopped
2021-06-07T16:21:29.610Z,1623082889.610 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-06-07T16:21:29.610Z,1623082889.610 [Default:CheckIn](INFO): Running loop #5
2021-06-07T16:21:29.611Z,1623082889.611 [Default:CheckIn] Running Loop=5
2021-06-07T16:21:29.611Z,1623082889.611 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-06-07T16:21:29.611Z,1623082889.611 [Default:CheckIn:Read_GPS] Running Loop=1
2021-06-07T16:21:31.622Z,1623082891.622 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162130.00,A,3648.11882,N,12147.23149,W,0.019,103.47,070621,,,D*72
2021-06-07T16:21:31.625Z,1623082891.625 [NAL9602](INFO): GPS fix at 20210607T162130: (36.801980, -121.787192)
2021-06-07T16:21:31.635Z,1623082891.635 [Default:CheckIn:Read_GPS] Stopped
2021-06-07T16:21:31.636Z,1623082891.636 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-06-07T16:21:38.914Z,1623082898.914 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210607T153507/Courier0016.lzma
2021-06-07T16:21:39.916Z,1623082899.916 [DataOverHttps](INFO): Moved sent file to Logs/20210607T153507/Courier0016.lzma.bak
2021-06-07T16:21:39.917Z,1623082899.917 [DataOverHttps](INFO): SBD MOMSN=15699694
2021-06-07T16:21:51.827Z,1623082911.827 [NAL9602](INFO): SBD MO Status=0, MOMSN=4602, MT Status=0, MTMSN=0
2021-06-07T16:21:51.827Z,1623082911.827 [NAL9602](INFO): No messages in MT queue
2021-06-07T16:21:55.870Z,1623082915.870 [DataOverHttps](INFO): Sending 143 bytes from file Logs/20210607T153507/Express0017.lzma
2021-06-07T16:21:56.872Z,1623082916.872 [DataOverHttps](INFO): Moved sent file to Logs/20210607T153507/Express0017.lzma.bak
2021-06-07T16:21:56.873Z,1623082916.873 [DataOverHttps](INFO): SBD MOMSN=15699697
2021-06-07T16:21:58.754Z,1623082918.754 [Default:CheckIn:Read_Iridium] Stopped
2021-06-07T16:21:58.754Z,1623082918.754 [Default:CheckIn:C.Wait] Running Loop=1
2021-06-07T16:21:58.754Z,1623082918.754 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-06-07T16:22:22.524Z,1623082942.523 [NAL9602](INFO): Not Powering down - fast GPS
2021-06-07T16:24:28.464Z,1623083068.464 [DataOverHttps](IMPORTANT): SBD MTMSN=20210607T162427
2021-06-07T16:24:39.351Z,1623083079.351 [DataOverHttps](INFO): Received command:ibit
2021-06-07T16:24:39.447Z,1623083079.447 [CommandLine](IMPORTANT): got command ibit
2021-06-07T16:24:39.620Z,1623083079.620 [IBIT](IMPORTANT): Beginning Initiated BIT
2021-06-07T16:24:39.621Z,1623083079.621 [IBIT](IMPORTANT): Beginning control surface checks.
2021-06-07T16:24:39.653Z,1623083079.653 [CBIT](IMPORTANT): Beginning ground fault scan
2021-06-07T16:24:41.207Z,1623083081.207 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162440.00,A,3648.11933,N,12147.23009,W,0.039,77.38,070621,,,D*46
2021-06-07T16:24:41.210Z,1623083081.210 [NAL9602](INFO): GPS fix at 20210607T162440: (36.801989, -121.787168)
2021-06-07T16:24:50.542Z,1623083090.542 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.005246
CHAN A1 (24V): -0.184667
CHAN A2 (12V): 0.003064
CHAN A3 (5V): 0.000170
CHAN B0 (3.3V): 0.000661
CHAN B1 (3.15aV): 0.001140
CHAN B2 (3.15bV): 0.001300
CHAN B3 (GND): -0.000289
OPEN: 0.004514
Full Scale Calc: 4.765 mA, -1.589 mA
2021-06-07T16:24:53.741Z,1623083093.741 [NAL9602](INFO): SBD MO Status=0, MOMSN=4603, MT Status=0, MTMSN=0
2021-06-07T16:24:53.741Z,1623083093.741 [NAL9602](INFO): No messages in MT queue
2021-06-07T16:24:54.954Z,1623083094.954 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162454.00,A,3648.11921,N,12147.23082,W,0.058,77.38,070621,,,D*44
2021-06-07T16:24:54.956Z,1623083094.956 [NAL9602](INFO): GPS fix at 20210607T162454: (36.801987, -121.787180)
2021-06-07T16:24:58.182Z,1623083098.182 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162457.00,A,3648.11917,N,12147.23081,W,0.019,77.38,070621,,,D*44
2021-06-07T16:24:58.184Z,1623083098.184 [NAL9602](INFO): GPS fix at 20210607T162457: (36.801986, -121.787180)
2021-06-07T16:25:01.015Z,1623083101.015 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162500.00,A,3648.11915,N,12147.23079,W,0.039,77.38,070621,,,D*40
2021-06-07T16:25:01.017Z,1623083101.017 [NAL9602](INFO): GPS fix at 20210607T162500: (36.801986, -121.787180)
2021-06-07T16:25:04.244Z,1623083104.244 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162503.00,A,3648.11918,N,12147.23094,W,0.039,77.38,070621,,,D*4D
2021-06-07T16:25:04.246Z,1623083104.246 [NAL9602](INFO): GPS fix at 20210607T162503: (36.801986, -121.787182)
2021-06-07T16:25:07.072Z,1623083107.072 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162506.00,A,3648.11939,N,12147.23111,W,0.019,77.38,070621,,,D*45
2021-06-07T16:25:07.074Z,1623083107.074 [NAL9602](INFO): GPS fix at 20210607T162506: (36.801990, -121.787185)
2021-06-07T16:25:09.904Z,1623083109.904 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162509.00,A,3648.11959,N,12147.23108,W,0.078,77.38,070621,,,D*43
2021-06-07T16:25:09.911Z,1623083109.911 [NAL9602](INFO): GPS fix at 20210607T162509: (36.801993, -121.787185)
2021-06-07T16:25:13.145Z,1623083113.145 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162512.00,A,3648.11977,N,12147.23104,W,0.078,77.38,070621,,,D*49
2021-06-07T16:25:13.148Z,1623083113.148 [NAL9602](INFO): GPS fix at 20210607T162512: (36.801996, -121.787184)
2021-06-07T16:25:15.962Z,1623083115.962 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162515.00,A,3648.11990,N,12147.23093,W,0.019,77.38,070621,,,D*4F
2021-06-07T16:25:15.964Z,1623083115.964 [NAL9602](INFO): GPS fix at 20210607T162515: (36.801998, -121.787182)
2021-06-07T16:25:19.253Z,1623083119.253 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162518.00,A,3648.12001,N,12147.23090,W,0.019,77.38,070621,,,D*43
2021-06-07T16:25:19.255Z,1623083119.255 [NAL9602](INFO): GPS fix at 20210607T162518: (36.802000, -121.787182)
2021-06-07T16:25:22.022Z,1623083122.022 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162521.00,A,3648.12010,N,12147.23078,W,0.039,77.38,070621,,,D*4D
2021-06-07T16:25:22.025Z,1623083122.025 [NAL9602](INFO): GPS fix at 20210607T162521: (36.802002, -121.787180)
2021-06-07T16:25:25.254Z,1623083125.254 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162524.00,A,3648.12019,N,12147.23069,W,0.000,77.38,070621,,,D*4B
2021-06-07T16:25:25.256Z,1623083125.256 [NAL9602](INFO): GPS fix at 20210607T162524: (36.802003, -121.787178)
2021-06-07T16:25:25.711Z,1623083125.711 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2021-06-07T16:25:26.093Z,1623083126.093 [IBIT](IMPORTANT): Communications Status:
Fix Status: 1
Iridium Signal Strength: 3
Latitude: 36.802002 Longitude: -121.787178
2021-06-07T16:25:26.489Z,1623083126.489 [IBIT](IMPORTANT): Battery Status:
Battery Charge (AH): 365.505402
Voltage: 16.611000
2021-06-07T16:25:26.489Z,1623083126.489 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah
2021-06-07T16:25:26.490Z,1623083126.490 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V
2021-06-07T16:25:26.913Z,1623083126.913 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2021-06-07T16:25:26.913Z,1623083126.913 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2021-06-07T16:25:26.913Z,1623083126.913 [IBIT](IMPORTANT): Pressure:9.935416 PSI
2021-06-07T16:25:26.914Z,1623083126.914 [IBIT](IMPORTANT): Humidity:10.236845 %
2021-06-07T16:25:27.288Z,1623083127.288 [IBIT](IMPORTANT): Vehicle Pitch:0.185599 degrees
2021-06-07T16:25:27.288Z,1623083127.288 [IBIT](IMPORTANT): Vehicle  Roll:1.085945 degrees
2021-06-07T16:25:27.289Z,1623083127.289 [IBIT](IMPORTANT): Vehicle  Heading:290.704681 degrees
2021-06-07T16:25:27.696Z,1623083127.696 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2021-06-07T16:25:27.697Z,1623083127.697 [IBIT](IMPORTANT): buoyancyNeutral: 87.804932 cc
2021-06-07T16:25:27.697Z,1623083127.697 [IBIT](IMPORTANT): massDefault: 2.649270 cm
2021-06-07T16:25:27.697Z,1623083127.697 [IBIT](IMPORTANT): stopDepth: 150.000000 m
2021-06-07T16:25:27.698Z,1623083127.698 [IBIT](IMPORTANT): abortDepth: 165.000000 m
2021-06-07T16:25:27.698Z,1623083127.698 [IBIT](IMPORTANT): IBIT PASSED
2021-06-07T16:25:57.571Z,1623083157.571 [NAL9602](INFO): Not Powering down - fast GPS
2021-06-07T16:26:59.405Z,1623083219.405 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-06-07T16:26:59.405Z,1623083219.405 [Default:CheckIn:C.Wait] Stopped
2021-06-07T16:26:59.405Z,1623083219.405 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-06-07T16:26:59.405Z,1623083219.405 [Default:CheckIn:D] Running Loop=1
2021-06-07T16:26:59.798Z,1623083219.798 [Default:CheckIn:D] Stopped
2021-06-07T16:26:59.798Z,1623083219.798 [Default:CheckIn:E] Running Loop=1
2021-06-07T16:27:00.202Z,1623083220.202 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 46.691138 min 
2021-06-07T16:27:00.202Z,1623083220.202 [Default:CheckIn:E] Stopped
2021-06-07T16:27:00.202Z,1623083220.202 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-06-07T16:27:00.202Z,1623083220.202 [Default:CheckIn] Stopped
2021-06-07T16:27:00.202Z,1623083220.202 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-06-07T16:27:00.202Z,1623083220.202 [Default:CheckIn](INFO): Running loop #6
2021-06-07T16:27:00.202Z,1623083220.202 [Default:CheckIn] Running Loop=6
2021-06-07T16:27:00.203Z,1623083220.203 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-06-07T16:27:00.203Z,1623083220.203 [Default:CheckIn:Read_GPS] Running Loop=1
2021-06-07T16:27:02.212Z,1623083222.212 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162701.00,A,3648.11874,N,12147.23064,W,0.039,77.38,070621,,,D*49
2021-06-07T16:27:02.214Z,1623083222.214 [NAL9602](INFO): GPS fix at 20210607T162701: (36.801979, -121.787177)
2021-06-07T16:27:02.225Z,1623083222.225 [Default:CheckIn:Read_GPS] Stopped
2021-06-07T16:27:02.225Z,1623083222.225 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-06-07T16:27:09.386Z,1623083229.386 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210607T153507/Courier0019.lzma
2021-06-07T16:27:10.388Z,1623083230.388 [DataOverHttps](INFO): Moved sent file to Logs/20210607T153507/Courier0019.lzma.bak
2021-06-07T16:27:10.389Z,1623083230.389 [DataOverHttps](INFO): SBD MOMSN=15699710
2021-06-07T16:27:13.930Z,1623083233.930 [NAL9602](INFO): SBD MO Status=0, MOMSN=4604, MT Status=0, MTMSN=0
2021-06-07T16:27:13.930Z,1623083233.930 [NAL9602](INFO): No messages in MT queue
2021-06-07T16:27:26.096Z,1623083246.096 [DataOverHttps](INFO): Sending 822 bytes from file Logs/20210607T153507/Express0020.lzma
2021-06-07T16:27:27.096Z,1623083247.096 [DataOverHttps](INFO): Moved sent file to Logs/20210607T153507/Express0020.lzma.bak
2021-06-07T16:27:27.097Z,1623083247.097 [DataOverHttps](INFO): SBD MOMSN=15699718
2021-06-07T16:27:42.874Z,1623083262.874 [DataOverHttps](INFO): Sending 52 bytes from file Logs/20210607T153507/Express0021.lzma
2021-06-07T16:27:43.898Z,1623083263.898 [DataOverHttps](INFO): Moved sent file to Logs/20210607T153507/Express0021.lzma.bak
2021-06-07T16:27:43.898Z,1623083263.898 [DataOverHttps](INFO): SBD MOMSN=15699748
2021-06-07T16:27:44.631Z,1623083264.631 [NAL9602](INFO): Not Powering down - fast GPS
2021-06-07T16:27:45.854Z,1623083265.854 [Default:CheckIn:Read_Iridium] Stopped
2021-06-07T16:27:45.854Z,1623083265.854 [Default:CheckIn:C.Wait] Running Loop=1
2021-06-07T16:27:45.854Z,1623083265.854 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-06-07T16:32:46.519Z,1623083566.519 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-06-07T16:32:46.520Z,1623083566.520 [Default:CheckIn:C.Wait] Stopped
2021-06-07T16:32:46.520Z,1623083566.520 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-06-07T16:32:46.520Z,1623083566.520 [Default:CheckIn:D] Running Loop=1
2021-06-07T16:32:46.903Z,1623083566.903 [Default:CheckIn:D] Stopped
2021-06-07T16:32:46.904Z,1623083566.904 [Default:CheckIn:E] Running Loop=1
2021-06-07T16:32:47.308Z,1623083567.308 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 52.476233 min 
2021-06-07T16:32:47.308Z,1623083567.308 [Default:CheckIn:E] Stopped
2021-06-07T16:32:47.308Z,1623083567.308 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-06-07T16:32:47.308Z,1623083567.308 [Default:CheckIn] Stopped
2021-06-07T16:32:47.308Z,1623083567.308 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-06-07T16:32:47.309Z,1623083567.309 [Default:CheckIn](INFO): Running loop #7
2021-06-07T16:32:47.309Z,1623083567.309 [Default:CheckIn] Running Loop=7
2021-06-07T16:32:47.309Z,1623083567.309 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-06-07T16:32:47.309Z,1623083567.309 [Default:CheckIn:Read_GPS] Running Loop=1
2021-06-07T16:32:49.318Z,1623083569.318 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163248.00,A,3648.11959,N,12147.23068,W,0.058,77.38,070621,,,D*45
2021-06-07T16:32:49.339Z,1623083569.339 [NAL9602](INFO): GPS fix at 20210607T163248: (36.801993, -121.787178)
2021-06-07T16:32:49.352Z,1623083569.352 [Default:CheckIn:Read_GPS] Stopped
2021-06-07T16:32:49.353Z,1623083569.353 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-06-07T16:32:56.938Z,1623083576.938 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210607T153507/Courier0024.lzma
2021-06-07T16:32:57.940Z,1623083577.940 [DataOverHttps](INFO): Moved sent file to Logs/20210607T153507/Courier0024.lzma.bak
2021-06-07T16:32:57.941Z,1623083577.941 [DataOverHttps](INFO): SBD MOMSN=15699756
2021-06-07T16:33:13.153Z,1623083593.153 [NAL9602](INFO): SBD MO Status=2, MOMSN=4605, MT Status=2, MTMSN=0
2021-06-07T16:33:13.154Z,1623083593.154 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-06-07T16:33:13.926Z,1623083593.926 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20210607T153507/Express0026.lzma
2021-06-07T16:33:14.929Z,1623083594.929 [DataOverHttps](INFO): Moved sent file to Logs/20210607T153507/Express0026.lzma.bak
2021-06-07T16:33:14.929Z,1623083594.929 [DataOverHttps](INFO): SBD MOMSN=15699759
2021-06-07T16:33:16.804Z,1623083596.804 [Default:CheckIn:Read_Iridium] Stopped
2021-06-07T16:33:16.804Z,1623083596.804 [Default:CheckIn:C.Wait] Running Loop=1
2021-06-07T16:33:16.804Z,1623083596.804 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-06-07T16:33:34.609Z,1623083614.609 [NAL9602](INFO): SBD MO Status=0, MOMSN=4605, MT Status=0, MTMSN=0
2021-06-07T16:33:34.609Z,1623083614.609 [NAL9602](INFO): No messages in MT queue
2021-06-07T16:34:05.271Z,1623083645.271 [NAL9602](INFO): Not Powering down - fast GPS
2021-06-07T16:38:17.390Z,1623083897.390 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-06-07T16:38:17.390Z,1623083897.390 [Default:CheckIn:C.Wait] Stopped
2021-06-07T16:38:17.390Z,1623083897.390 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-06-07T16:38:17.390Z,1623083897.390 [Default:CheckIn:D] Running Loop=1
2021-06-07T16:38:17.845Z,1623083897.845 [Default:CheckIn:D] Stopped
2021-06-07T16:38:17.845Z,1623083897.845 [Default:CheckIn:E] Running Loop=1
2021-06-07T16:38:18.216Z,1623083898.216 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 57.991931 min 
2021-06-07T16:38:18.216Z,1623083898.216 [Default:CheckIn:E] Stopped
2021-06-07T16:38:18.216Z,1623083898.216 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-06-07T16:38:18.216Z,1623083898.216 [Default:CheckIn] Stopped
2021-06-07T16:38:18.217Z,1623083898.217 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-06-07T16:38:18.217Z,1623083898.217 [Default:CheckIn](INFO): Running loop #8
2021-06-07T16:38:18.217Z,1623083898.217 [Default:CheckIn] Running Loop=8
2021-06-07T16:38:18.217Z,1623083898.217 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-06-07T16:38:18.217Z,1623083898.217 [Default:CheckIn:Read_GPS] Running Loop=1
2021-06-07T16:38:20.210Z,1623083900.210 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163819.00,A,3648.23500,N,12147.15143,W,2.391,170.89,070621,,,D*7F
2021-06-07T16:38:20.212Z,1623083900.212 [NAL9602](INFO): GPS fix at 20210607T163819: (36.803917, -121.785857)
2021-06-07T16:38:20.224Z,1623083900.224 [Default:CheckIn:Read_GPS] Stopped
2021-06-07T16:38:20.224Z,1623083900.224 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-06-07T16:38:25.080Z,1623083905.080 [NAL9602](INFO): SBD MO Status=0, MOMSN=4606, MT Status=0, MTMSN=0
2021-06-07T16:38:25.080Z,1623083905.080 [NAL9602](INFO): No messages in MT queue
2021-06-07T16:38:27.786Z,1623083907.786 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210607T153507/Courier0028.lzma
2021-06-07T16:38:28.788Z,1623083908.788 [DataOverHttps](INFO): Moved sent file to Logs/20210607T153507/Courier0028.lzma.bak
2021-06-07T16:38:28.789Z,1623083908.789 [DataOverHttps](INFO): SBD MOMSN=15699768
2021-06-07T16:38:50.610Z,1623083930.610 [DataOverHttps](INFO): Sending 144 bytes from file Logs/20210607T153507/Express0029.lzma
2021-06-07T16:38:51.613Z,1623083931.613 [DataOverHttps](INFO): Moved sent file to Logs/20210607T153507/Express0029.lzma.bak
2021-06-07T16:38:51.613Z,1623083931.613 [DataOverHttps](INFO): SBD MOMSN=15699774
2021-06-07T16:38:53.918Z,1623083933.918 [Default:CheckIn:Read_Iridium] Stopped
2021-06-07T16:38:53.918Z,1623083933.918 [Default:CheckIn:C.Wait] Running Loop=1
2021-06-07T16:38:53.918Z,1623083933.918 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-06-07T16:38:55.489Z,1623083935.489 [NAL9602](INFO): Not Powering down - fast GPS
2021-06-07T16:43:09.664Z,1623084189.664 [BPC1](ERROR): BPC1A: No match for serial number 1717 in BPC1A's battery stick inventory (sticks 1-32 in onboard configuration file).
2021-06-07T16:43:54.522Z,1623084234.522 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-06-07T16:43:54.523Z,1623084234.523 [Default:CheckIn:C.Wait] Stopped
2021-06-07T16:43:54.523Z,1623084234.523 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-06-07T16:43:54.523Z,1623084234.523 [Default:CheckIn:D] Running Loop=1
2021-06-07T16:43:54.928Z,1623084234.928 [Default:CheckIn:D] Stopped
2021-06-07T16:43:54.928Z,1623084234.928 [Default:CheckIn:E] Running Loop=1
2021-06-07T16:43:55.344Z,1623084235.344 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 63.609973 min 
2021-06-07T16:43:55.344Z,1623084235.344 [Default:CheckIn:E] Stopped
2021-06-07T16:43:55.345Z,1623084235.345 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-06-07T16:43:55.345Z,1623084235.345 [Default:CheckIn] Stopped
2021-06-07T16:43:55.345Z,1623084235.345 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-06-07T16:43:55.345Z,1623084235.345 [Default:CheckIn](INFO): Running loop #9
2021-06-07T16:43:55.345Z,1623084235.345 [Default:CheckIn] Running Loop=9
2021-06-07T16:43:55.345Z,1623084235.345 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-06-07T16:43:55.345Z,1623084235.345 [Default:CheckIn:Read_GPS] Running Loop=1
2021-06-07T16:43:57.338Z,1623084237.338 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164356.00,A,3648.44564,N,12147.34399,W,16.736,233.66,070621,,,D*44
2021-06-07T16:43:57.340Z,1623084237.340 [NAL9602](INFO): GPS fix at 20210607T164356: (36.807427, -121.789067)
2021-06-07T16:43:57.351Z,1623084237.351 [Default:CheckIn:Read_GPS] Stopped
2021-06-07T16:43:57.351Z,1623084237.351 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-06-07T16:44:04.610Z,1623084244.610 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210607T153507/Courier0031.lzma
2021-06-07T16:44:05.612Z,1623084245.612 [DataOverHttps](INFO): Moved sent file to Logs/20210607T153507/Courier0031.lzma.bak
2021-06-07T16:44:05.613Z,1623084245.613 [DataOverHttps](INFO): SBD MOMSN=15699784
2021-06-07T16:44:13.517Z,1623084253.517 [NAL9602](INFO): SBD MO Status=0, MOMSN=4607, MT Status=0, MTMSN=0
2021-06-07T16:44:13.517Z,1623084253.517 [NAL9602](INFO): No messages in MT queue
2021-06-07T16:44:21.558Z,1623084261.558 [DataOverHttps](INFO): Sending 143 bytes from file Logs/20210607T153507/Express0032.lzma
2021-06-07T16:44:22.560Z,1623084262.560 [DataOverHttps](INFO): Moved sent file to Logs/20210607T153507/Express0032.lzma.bak
2021-06-07T16:44:22.561Z,1623084262.561 [DataOverHttps](INFO): SBD MOMSN=15699791
2021-06-07T16:44:24.420Z,1623084264.420 [Default:CheckIn:Read_Iridium] Stopped
2021-06-07T16:44:24.420Z,1623084264.420 [Default:CheckIn:C.Wait] Running Loop=1
2021-06-07T16:44:24.420Z,1623084264.420 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-06-07T16:44:26.018Z,1623084266.018 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2021-06-07T16:44:32.503Z,1623084272.503 [BPC1](INFO): Calculating totals. Valid battery stick count: 50. Valid reserve battery stick count: 5.
2021-06-07T16:44:32.507Z,1623084272.507 [BPC1](FAULT): Failed to receive data from 7 sticks prior to timeout. Missing stick IDs are: 40, 41, 42, 43, 45, 46, 47.
2021-06-07T16:44:32.507Z,1623084272.507 [BPC1] Data Fault, FailCount= 1
2021-06-07T16:44:32.507Z,1623084272.507 [BPC1](ERROR): Data Fault
2021-06-07T16:44:32.561Z,1623084272.561 [CBIT](ERROR): Data Fault in component: BPC1
2021-06-07T16:44:44.225Z,1623084284.225 [NAL9602](INFO): Not Powering down - fast GPS
2021-06-07T16:49:25.070Z,1623084565.070 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-06-07T16:49:25.070Z,1623084565.070 [Default:CheckIn:C.Wait] Stopped
2021-06-07T16:49:25.070Z,1623084565.070 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-06-07T16:49:25.070Z,1623084565.070 [Default:CheckIn:D] Running Loop=1
2021-06-07T16:49:25.476Z,1623084565.476 [Default:CheckIn:D] Stopped
2021-06-07T16:49:25.476Z,1623084565.476 [Default:CheckIn:E] Running Loop=1
2021-06-07T16:49:25.892Z,1623084565.892 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 69.119100 min 
2021-06-07T16:49:25.892Z,1623084565.892 [Default:CheckIn:E] Stopped
2021-06-07T16:49:25.892Z,1623084565.892 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-06-07T16:49:25.892Z,1623084565.892 [Default:CheckIn] Stopped
2021-06-07T16:49:25.892Z,1623084565.892 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-06-07T16:49:25.892Z,1623084565.892 [Default:CheckIn](INFO): Running loop #10
2021-06-07T16:49:25.892Z,1623084565.892 [Default:CheckIn] Running Loop=10
2021-06-07T16:49:25.893Z,1623084565.893 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-06-07T16:49:25.893Z,1623084565.893 [Default:CheckIn:Read_GPS] Running Loop=1
2021-06-07T16:49:27.894Z,1623084567.894 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164927.00,A,3648.40147,N,12148.96808,W,18.175,271.33,070621,,,A*41
2021-06-07T16:49:27.897Z,1623084567.897 [NAL9602](INFO): GPS fix at 20210607T164927: (36.806691, -121.816135)
2021-06-07T16:49:27.925Z,1623084567.925 [Default:CheckIn:Read_GPS] Stopped
2021-06-07T16:49:27.925Z,1623084567.925 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-06-07T16:49:34.878Z,1623084574.878 [DataOverHttps](INFO): Sending 84 bytes from file Logs/20210607T153507/Courier0034.lzma
2021-06-07T16:49:35.880Z,1623084575.880 [DataOverHttps](INFO): Moved sent file to Logs/20210607T153507/Courier0034.lzma.bak
2021-06-07T16:49:35.881Z,1623084575.881 [DataOverHttps](INFO): SBD MOMSN=15699802
2021-06-07T16:49:52.134Z,1623084592.134 [NAL9602](INFO): SBD MO Status=0, MOMSN=4608, MT Status=0, MTMSN=0
2021-06-07T16:49:52.134Z,1623084592.134 [NAL9602](INFO): No messages in MT queue
2021-06-07T16:49:56.607Z,1623084596.607 [DataOverHttps](INFO): Sending 254 bytes from file Logs/20210607T153507/Express0035.lzma
2021-06-07T16:49:57.608Z,1623084597.608 [DataOverHttps](INFO): Moved sent file to Logs/20210607T153507/Express0035.lzma.bak
2021-06-07T16:49:57.609Z,1623084597.609 [DataOverHttps](INFO): SBD MOMSN=15699805
2021-06-07T16:49:59.423Z,1623084599.423 [Default:CheckIn:Read_Iridium] Stopped
2021-06-07T16:49:59.423Z,1623084599.423 [Default:CheckIn:C.Wait] Running Loop=1
2021-06-07T16:49:59.423Z,1623084599.423 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-06-07T16:50:22.839Z,1623084622.839 [NAL9602](INFO): Not Powering down - fast GPS
2021-06-07T16:51:22.487Z,1623084682.487 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.251408
2021-06-07T16:52:14.719Z,1623084734.719 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-06-07T16:52:49.863Z,1623084769.863 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-06-07T16:53:02.175Z,1623084782.175 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.002850
2021-06-07T16:54:33.361Z,1623084873.361 [CBIT](INFO): Clearing failed state for component BPC1
2021-06-07T16:54:33.361Z,1623084873.361 [BPC1] No Fault, FailCount= 1
2021-06-07T16:55:00.042Z,1623084900.042 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-06-07T16:55:00.042Z,1623084900.042 [Default:CheckIn:C.Wait] Stopped
2021-06-07T16:55:00.042Z,1623084900.042 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-06-07T16:55:00.042Z,1623084900.042 [Default:CheckIn:D] Running Loop=1
2021-06-07T16:55:00.449Z,1623084900.449 [Default:CheckIn:D] Stopped
2021-06-07T16:55:00.449Z,1623084900.449 [Default:CheckIn:E] Running Loop=1
2021-06-07T16:55:00.846Z,1623084900.846 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 74.701986 min 
2021-06-07T16:55:00.863Z,1623084900.863 [Default:CheckIn:E] Stopped
2021-06-07T16:55:00.863Z,1623084900.863 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-06-07T16:55:00.863Z,1623084900.863 [Default:CheckIn] Stopped
2021-06-07T16:55:00.863Z,1623084900.863 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-06-07T16:55:00.863Z,1623084900.863 [Default:CheckIn](INFO): Running loop #11
2021-06-07T16:55:00.863Z,1623084900.863 [Default:CheckIn] Running Loop=11
2021-06-07T16:55:00.863Z,1623084900.863 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-06-07T16:55:00.864Z,1623084900.864 [Default:CheckIn:Read_GPS] Running Loop=1
2021-06-07T16:55:02.861Z,1623084902.861 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165502.00,A,3648.47728,N,12149.35261,W,0.816,320.53,070621,,,A*78
2021-06-07T16:55:02.864Z,1623084902.864 [NAL9602](INFO): GPS fix at 20210607T165502: (36.807955, -121.822543)
2021-06-07T16:55:02.874Z,1623084902.874 [Default:CheckIn:Read_GPS] Stopped
2021-06-07T16:55:02.907Z,1623084902.907 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-06-07T16:55:09.830Z,1623084909.830 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210607T153507/Courier0037.lzma
2021-06-07T16:55:10.832Z,1623084910.832 [DataOverHttps](INFO): Moved sent file to Logs/20210607T153507/Courier0037.lzma.bak
2021-06-07T16:55:10.833Z,1623084910.833 [DataOverHttps](INFO): SBD MOMSN=15699820
2021-06-07T16:55:18.213Z,1623084918.213 [NAL9602](INFO): SBD MO Status=0, MOMSN=4609, MT Status=0, MTMSN=0
2021-06-07T16:55:18.213Z,1623084918.213 [NAL9602](INFO): No messages in MT queue
2021-06-07T16:55:26.454Z,1623084926.454 [DataOverHttps](INFO): Sending 144 bytes from file Logs/20210607T153507/Express0038.lzma
2021-06-07T16:55:27.458Z,1623084927.458 [DataOverHttps](INFO): Moved sent file to Logs/20210607T153507/Express0038.lzma.bak
2021-06-07T16:55:27.458Z,1623084927.458 [DataOverHttps](INFO): SBD MOMSN=15699823
2021-06-07T16:55:29.144Z,1623084929.144 [Default:CheckIn:Read_Iridium] Stopped
2021-06-07T16:55:29.144Z,1623084929.144 [Default:CheckIn:C.Wait] Running Loop=1
2021-06-07T16:55:29.144Z,1623084929.144 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-06-07T16:55:48.912Z,1623084948.912 [NAL9602](INFO): Not Powering down - fast GPS
2021-06-07T16:56:12.608Z,1623084972.608 [DataOverHttps](IMPORTANT): SBD MTMSN=20210607T165611