2021-08-04T12:24:04.010Z,1628079844.010 [Supervisor](DEBUG): Initializing supervisor.
2021-08-04T12:24:04.015Z,1628079844.015 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2021-08-04T12:24:04.015Z,1628079844.015 [SyncHandler](INFO): Protected caller Thread ID is 2308
2021-08-04T12:24:04.016Z,1628079844.016 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2021-08-04T12:24:04.017Z,1628079844.017 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2021-08-04T12:24:04.017Z,1628079844.017 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 2309
2021-08-04T12:24:04.022Z,1628079844.022 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2021-08-04T12:24:04.043Z,1628079844.043 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2021-08-04T12:24:04.044Z,1628079844.044 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2021-08-04T12:24:04.044Z,1628079844.044 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 2310
2021-08-04T12:24:04.046Z,1628079844.046 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2021-08-04T12:24:04.047Z,1628079844.047 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2021-08-04T12:24:04.048Z,1628079844.048 [logger ThreadHandler](INFO): Protected caller Thread ID is 2311
2021-08-04T12:24:04.052Z,1628079844.052 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2021-08-04T12:24:04.052Z,1628079844.052 [Supervisor](INFO): Looking for Config files in directory: Config/
2021-08-04T12:24:04.058Z,1628079844.058 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2021-08-04T12:24:04.207Z,1628079844.207 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2021-08-04T12:24:04.208Z,1628079844.208 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2021-08-04T12:24:04.437Z,1628079844.437 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2021-08-04T12:24:04.437Z,1628079844.437 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2021-08-04T12:24:04.675Z,1628079844.675 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2021-08-04T12:24:04.675Z,1628079844.675 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2021-08-04T12:24:04.785Z,1628079844.785 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2021-08-04T12:24:04.786Z,1628079844.786 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2021-08-04T12:24:05.454Z,1628079845.454 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2021-08-04T12:24:05.455Z,1628079845.455 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2021-08-04T12:24:05.913Z,1628079845.913 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2021-08-04T12:24:05.914Z,1628079845.914 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2021-08-04T12:24:06.493Z,1628079846.493 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2021-08-04T12:24:06.494Z,1628079846.494 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2021-08-04T12:24:07.127Z,1628079847.127 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2021-08-04T12:24:07.128Z,1628079847.128 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2021-08-04T12:24:07.488Z,1628079847.488 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2021-08-04T12:24:07.489Z,1628079847.489 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2021-08-04T12:24:07.868Z,1628079847.868 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2021-08-04T12:24:07.869Z,1628079847.869 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2021-08-04T12:24:08.025Z,1628079848.025 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2021-08-04T12:24:08.025Z,1628079848.025 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2021-08-04T12:24:08.160Z,1628079848.160 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2021-08-04T12:24:08.161Z,1628079848.161 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2021-08-04T12:24:08.245Z,1628079848.245 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2021-08-04T12:24:08.326Z,1628079848.326 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2021-08-04T12:24:08.541Z,1628079848.541 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2021-08-04T12:24:08.541Z,1628079848.541 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2021-08-04T12:24:08.769Z,1628079848.769 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2021-08-04T12:24:08.771Z,1628079848.771 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/
2021-08-04T12:24:08.774Z,1628079848.774 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg
2021-08-04T12:24:08.858Z,1628079848.858 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg
2021-08-04T12:24:09.129Z,1628079849.129 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2021-08-04T12:24:09.130Z,1628079849.130 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg
2021-08-04T12:24:09.230Z,1628079849.230 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg
2021-08-04T12:24:09.399Z,1628079849.399 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg
2021-08-04T12:24:09.600Z,1628079849.600 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg
2021-08-04T12:24:09.689Z,1628079849.689 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg
2021-08-04T12:24:09.797Z,1628079849.797 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg
2021-08-04T12:24:09.902Z,1628079849.902 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg
2021-08-04T12:24:10.073Z,1628079850.073 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg
2021-08-04T12:24:10.181Z,1628079850.181 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg
2021-08-04T12:24:10.284Z,1628079850.284 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2021-08-04T12:24:10.295Z,1628079850.295 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2021-08-04T12:24:10.404Z,1628079850.404 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2021-08-04T12:24:10.405Z,1628079850.405 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2021-08-04T12:24:10.566Z,1628079850.566 [BuoyancyServo] Loaded
2021-08-04T12:24:10.566Z,1628079850.566 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2021-08-04T12:24:10.588Z,1628079850.588 [ElevatorServo] Loaded
2021-08-04T12:24:10.588Z,1628079850.588 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2021-08-04T12:24:10.609Z,1628079850.609 [MassServo] Loaded
2021-08-04T12:24:10.609Z,1628079850.609 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2021-08-04T12:24:10.629Z,1628079850.629 [RudderServo] Loaded
2021-08-04T12:24:10.629Z,1628079850.629 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2021-08-04T12:24:10.649Z,1628079850.649 [ThrusterServo] Loaded
2021-08-04T12:24:10.649Z,1628079850.649 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2021-08-04T12:24:10.650Z,1628079850.650 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2021-08-04T12:24:10.650Z,1628079850.650 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2021-08-04T12:24:10.802Z,1628079850.802 [SBIT](DEBUG): Construct Startup Built In Test.
2021-08-04T12:24:10.817Z,1628079850.817 [SBIT] Loaded
2021-08-04T12:24:10.818Z,1628079850.818 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2021-08-04T12:24:10.821Z,1628079850.821 [IBIT](DEBUG): Construct Initiated Built In Test.
2021-08-04T12:24:10.843Z,1628079850.843 [IBIT] Loaded
2021-08-04T12:24:10.843Z,1628079850.843 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2021-08-04T12:24:10.849Z,1628079850.849 [CBIT](DEBUG): Construct Continuous Built In Test.
2021-08-04T12:24:11.062Z,1628079851.062 [CBIT] Loaded
2021-08-04T12:24:11.062Z,1628079851.062 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2021-08-04T12:24:11.063Z,1628079851.063 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2021-08-04T12:24:11.063Z,1628079851.063 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2021-08-04T12:24:11.242Z,1628079851.242 [CTD_Seabird] Loaded
2021-08-04T12:24:11.242Z,1628079851.242 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2021-08-04T12:24:11.244Z,1628079851.244 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 406244E0
2021-08-04T12:24:11.244Z,1628079851.244 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 2393
2021-08-04T12:24:11.276Z,1628079851.276 [ESPComponent] Loaded
2021-08-04T12:24:11.276Z,1628079851.276 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2021-08-04T12:24:11.296Z,1628079851.296 [PAR_Licor] Loaded
2021-08-04T12:24:11.296Z,1628079851.296 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2021-08-04T12:24:11.329Z,1628079851.329 [WetLabsBB2FL] Loaded
2021-08-04T12:24:11.329Z,1628079851.329 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2021-08-04T12:24:11.330Z,1628079851.330 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 406544E0
2021-08-04T12:24:11.330Z,1628079851.330 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 2394
2021-08-04T12:24:11.331Z,1628079851.331 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2021-08-04T12:24:11.332Z,1628079851.332 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2021-08-04T12:24:11.377Z,1628079851.377 [DepthRateCalculator] Loaded
2021-08-04T12:24:11.377Z,1628079851.377 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2021-08-04T12:24:11.383Z,1628079851.383 [PitchRateCalculator] Loaded
2021-08-04T12:24:11.383Z,1628079851.383 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2021-08-04T12:24:11.394Z,1628079851.394 [SpeedCalculator] Loaded
2021-08-04T12:24:11.395Z,1628079851.395 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2021-08-04T12:24:11.408Z,1628079851.408 [TempGradientCalculator] Loaded
2021-08-04T12:24:11.409Z,1628079851.409 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2021-08-04T12:24:11.414Z,1628079851.414 [YawRateCalculator] Loaded
2021-08-04T12:24:11.414Z,1628079851.414 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2021-08-04T12:24:11.433Z,1628079851.433 [ElevatorOffsetCalculator] Loaded
2021-08-04T12:24:11.433Z,1628079851.433 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2021-08-04T12:24:11.434Z,1628079851.434 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2021-08-04T12:24:11.434Z,1628079851.434 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2021-08-04T12:24:11.537Z,1628079851.537 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2021-08-04T12:24:11.537Z,1628079851.537 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2021-08-04T12:24:11.567Z,1628079851.567 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2021-08-04T12:24:11.567Z,1628079851.567 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2021-08-04T12:24:11.649Z,1628079851.649 [DeadReckonUsingMultipleVelocitySources] Loaded
2021-08-04T12:24:11.649Z,1628079851.649 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2021-08-04T12:24:11.664Z,1628079851.664 [NavChart] Loaded
2021-08-04T12:24:11.664Z,1628079851.664 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2021-08-04T12:24:11.670Z,1628079851.670 [UniversalFixResidualReporter] Loaded
2021-08-04T12:24:11.671Z,1628079851.671 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2021-08-04T12:24:11.671Z,1628079851.671 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2021-08-04T12:24:11.672Z,1628079851.672 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2021-08-04T12:24:12.046Z,1628079852.046 [AHRS_M2] Loaded
2021-08-04T12:24:12.046Z,1628079852.046 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2021-08-04T12:24:12.962Z,1628079852.962 [BPC1] Loaded
2021-08-04T12:24:12.963Z,1628079852.963 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2021-08-04T12:24:13.169Z,1628079853.169 [DataOverHttps] Loaded
2021-08-04T12:24:13.170Z,1628079853.170 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2021-08-04T12:24:13.171Z,1628079853.171 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4099E4E0
2021-08-04T12:24:13.171Z,1628079853.171 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 2395
2021-08-04T12:24:13.191Z,1628079853.191 [Depth_Keller] Loaded
2021-08-04T12:24:13.192Z,1628079853.192 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2021-08-04T12:24:13.197Z,1628079853.197 [DropWeight] Loaded
2021-08-04T12:24:13.197Z,1628079853.197 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2021-08-04T12:24:13.235Z,1628079853.235 [DVL_micro] Loaded
2021-08-04T12:24:13.235Z,1628079853.235 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread.
2021-08-04T12:24:13.486Z,1628079853.486 [NAL9602] Loaded
2021-08-04T12:24:13.486Z,1628079853.486 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2021-08-04T12:24:13.512Z,1628079853.512 [Onboard] Loaded
2021-08-04T12:24:13.512Z,1628079853.512 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2021-08-04T12:24:13.513Z,1628079853.513 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 409CE4E0
2021-08-04T12:24:13.513Z,1628079853.513 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 2396
2021-08-04T12:24:13.525Z,1628079853.525 [Power24vConverter] Loaded
2021-08-04T12:24:13.526Z,1628079853.526 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2021-08-04T12:24:13.542Z,1628079853.542 [Radio_Surface] Loaded
2021-08-04T12:24:13.542Z,1628079853.542 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2021-08-04T12:24:13.544Z,1628079853.544 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409FE4E0
2021-08-04T12:24:13.544Z,1628079853.544 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 2397
2021-08-04T12:24:13.545Z,1628079853.545 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2021-08-04T12:24:13.546Z,1628079853.546 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2021-08-04T12:24:13.606Z,1628079853.606 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2021-08-04T12:24:13.606Z,1628079853.606 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2021-08-04T12:24:13.661Z,1628079853.661 [VerticalControl](DEBUG): Construct VerticalControl.
2021-08-04T12:24:13.715Z,1628079853.715 [VerticalControl] Loaded
2021-08-04T12:24:13.716Z,1628079853.716 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2021-08-04T12:24:13.718Z,1628079853.718 [HorizontalControl](DEBUG): Construct HorizontalControl.
2021-08-04T12:24:13.756Z,1628079853.756 [HorizontalControl] Loaded
2021-08-04T12:24:13.756Z,1628079853.756 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2021-08-04T12:24:13.759Z,1628079853.759 [SpeedControl](DEBUG): Construct SpeedControl.
2021-08-04T12:24:13.761Z,1628079853.761 [SpeedControl] Loaded
2021-08-04T12:24:13.761Z,1628079853.761 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2021-08-04T12:24:13.764Z,1628079853.764 [LoopControl](DEBUG): Construct LoopControl.
2021-08-04T12:24:13.765Z,1628079853.765 [LoopControl] Loaded
2021-08-04T12:24:13.765Z,1628079853.765 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2021-08-04T12:24:13.765Z,1628079853.765 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2021-08-04T12:24:13.766Z,1628079853.766 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2021-08-04T12:24:13.777Z,1628079853.777 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2021-08-04T12:24:13.778Z,1628079853.778 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2021-08-04T12:24:14.118Z,1628079854.118 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2021-08-04T12:24:14.124Z,1628079854.124 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2021-08-04T12:24:14.127Z,1628079854.127 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2021-08-04T12:24:14.138Z,1628079854.138 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2021-08-04T12:24:14.140Z,1628079854.140 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B024E0
2021-08-04T12:24:14.140Z,1628079854.140 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 2398
2021-08-04T12:24:14.145Z,1628079854.145 [Supervisor](INFO): Main Thread ID is 824
2021-08-04T12:24:14.145Z,1628079854.145 [Supervisor](DEBUG): Running supervisor.
2021-08-04T12:24:14.146Z,1628079854.146 [CommandLine ThreadHandler](INFO): Handler Thread ID is 2399
2021-08-04T12:24:14.148Z,1628079854.148 [controlThread ThreadHandler](INFO): Handler Thread ID is 2400
2021-08-04T12:24:14.149Z,1628079854.149 [controlThread](DEBUG): Initializing ControlThread
2021-08-04T12:24:14.150Z,1628079854.150 [SBIT](INFO): Initialize SBIT Component.
2021-08-04T12:24:14.151Z,1628079854.151 [SBIT](IMPORTANT): git: 2021-08-03_A
2021-08-04T12:24:14.151Z,1628079854.151 [SBIT](INFO): git hash: 1a2dc5c22d1670ebb142884bf70af51cbb0bbb26
2021-08-04T12:24:14.151Z,1628079854.151 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2021-08-04T12:24:14.153Z,1628079854.153 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
Kernel Reported: #1 PREEMPT Wed Mar 17 08:23:48 PDT 2021
2021-08-04T12:24:14.154Z,1628079854.154 [SBIT](INFO): Beginning SBIT in 55.000000 seconds.
2021-08-04T12:24:14.155Z,1628079854.155 [IBIT](INFO): Initialize IBIT Component.
2021-08-04T12:24:14.156Z,1628079854.156 [CBIT](DEBUG): Initialize CBIT Component.
2021-08-04T12:24:14.157Z,1628079854.157 [logger ThreadHandler](INFO): Handler Thread ID is 2401
2021-08-04T12:24:14.168Z,1628079854.168 [CBIT](DEBUG): Initialized mux pins.
2021-08-04T12:24:14.168Z,1628079854.168 [CBIT](DEBUG): Initializing the watchdog timer.
2021-08-04T12:24:14.176Z,1628079854.176 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 2402
2021-08-04T12:24:14.177Z,1628079854.177 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2021-08-04T12:24:14.181Z,1628079854.181 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 2404
2021-08-04T12:24:14.184Z,1628079854.184 [WetLabsBB2FL](INFO): Powering up
2021-08-04T12:24:14.186Z,1628079854.186 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 2406
2021-08-04T12:24:14.187Z,1628079854.187 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2021-08-04T12:24:14.192Z,1628079854.192 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2021-08-04T12:24:14.193Z,1628079854.193 [CBIT](DEBUG): Initializing heartbeat.
2021-08-04T12:24:14.204Z,1628079854.204 [Onboard ThreadHandler](INFO): Handler Thread ID is 2407
2021-08-04T12:24:14.221Z,1628079854.221 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 2408
2021-08-04T12:24:14.244Z,1628079854.244 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 2409
2021-08-04T12:24:14.250Z,1628079854.250 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2MI01M.000
2021-08-04T12:24:14.250Z,1628079854.250 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2MI01M.000
2021-08-04T12:24:14.250Z,1628079854.250 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4MI89M.000
2021-08-04T12:24:14.250Z,1628079854.250 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4MI89M.000
2021-08-04T12:24:14.251Z,1628079854.251 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4MI11M.000
2021-08-04T12:24:14.251Z,1628079854.251 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4MI11M.000
2021-08-04T12:24:14.251Z,1628079854.251 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5MI07M.000
2021-08-04T12:24:14.251Z,1628079854.251 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5MI07M.000
2021-08-04T12:24:14.251Z,1628079854.251 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5OH07M.000
2021-08-04T12:24:14.251Z,1628079854.251 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5OH07M.000
2021-08-04T12:24:14.252Z,1628079854.252 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5OH31M.000
2021-08-04T12:24:14.252Z,1628079854.252 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5OH31M.000
2021-08-04T12:24:14.264Z,1628079854.264 [CBIT](DEBUG): Deactivating GF circuits.
2021-08-04T12:24:14.264Z,1628079854.264 [CBIT](DEBUG): Deactivating emergency mode.
2021-08-04T12:24:14.300Z,1628079854.300 [CBIT](DEBUG): Backplane powered.
2021-08-04T12:24:14.304Z,1628079854.304 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2021-08-04T12:24:14.305Z,1628079854.305 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2021-08-04T12:24:14.305Z,1628079854.305 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2021-08-04T12:24:14.305Z,1628079854.305 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2021-08-04T12:24:14.306Z,1628079854.306 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2021-08-04T12:24:14.306Z,1628079854.306 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2021-08-04T12:24:14.308Z,1628079854.308 [NavChart](DEBUG): Initialize NavChart Navigation.
2021-08-04T12:24:14.308Z,1628079854.308 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2021-08-04T12:24:14.318Z,1628079854.318 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2021-08-04T12:24:14.320Z,1628079854.320 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2021-08-04T12:24:14.321Z,1628079854.321 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2021-08-04T12:24:14.321Z,1628079854.321 [LoopControl](DEBUG): Initialize LoopControlComponent.
2021-08-04T12:24:14.322Z,1628079854.322 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2021-08-04T12:24:14.369Z,1628079854.369 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2021-08-04T12:24:14.401Z,1628079854.401 [MissionManager](DEBUG):
2021-08-04T12:24:14.402Z,1628079854.402 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2021-08-04T12:24:14.488Z,1628079854.488 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2021-08-04T12:24:14.489Z,1628079854.489 [Default:A.Wait](DEBUG): Construct Wait.
2021-08-04T12:24:14.492Z,1628079854.492 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2021-08-04T12:24:14.545Z,1628079854.545 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2021-08-04T12:24:14.547Z,1628079854.547 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2021-08-04T12:24:14.568Z,1628079854.568 [Default:E.Execute](DEBUG): Construct Execute.
2021-08-04T12:24:14.588Z,1628079854.588 [MissionManager](DEBUG):
0
Wait a moment to see if the scheduler starts a new mission before
starting to actually run Default.
13
Burn on
Dropped weight due to communications timeout.
5
Default mission has been running for
Restarting logs and Default mission.
restart logs
2021-08-04T12:24:14.593Z,1628079854.593 [controlThread](DEBUG): Component order: CycleStarter,ESPComponent,PAR_Licor,AHRS_M2,BPC1,Depth_Keller,DropWeight,DVL_micro,NAL9602,Power24vConverter,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2021-08-04T12:24:14.628Z,1628079854.628 [Radio_Surface](INFO): Powering up
2021-08-04T12:24:14.630Z,1628079854.630 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2021-08-04T12:24:14.693Z,1628079854.693 [Depth_Keller](ERROR): Pressure reading out of range: 1895.958496 decibar
2021-08-04T12:24:14.701Z,1628079854.701 [Power24vConverter](INFO): Powering up.
2021-08-04T12:24:14.744Z,1628079854.744 [DepthRateCalculator](ERROR): Depth measurement is not active
2021-08-04T12:24:14.770Z,1628079854.770 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2021-08-04T12:24:14.776Z,1628079854.776 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2021-08-04T12:24:14.777Z,1628079854.777 [ElevatorServo](DEBUG): Initializing EZServoServo.
2021-08-04T12:24:14.784Z,1628079854.784 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2021-08-04T12:24:14.785Z,1628079854.785 [MassServo](DEBUG): Initializing EZServoServo.
2021-08-04T12:24:14.792Z,1628079854.792 [MassServo](DEBUG): Initializing MassServo.
2021-08-04T12:24:14.793Z,1628079854.793 [RudderServo](DEBUG): Initializing EZServoServo.
2021-08-04T12:24:14.800Z,1628079854.800 [RudderServo](DEBUG): Initializing RudderServo.
2021-08-04T12:24:14.801Z,1628079854.801 [ThrusterServo](DEBUG): Initializing EZServoServo.
2021-08-04T12:24:14.808Z,1628079854.808 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2021-08-04T12:24:15.744Z,1628079855.744 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2021-08-04T12:24:15.744Z,1628079855.744 [RudderServo](FAULT): Rudder failed to initialize
2021-08-04T12:24:15.744Z,1628079855.744 [RudderServo] Communications Fault, FailCount= 1
2021-08-04T12:24:15.744Z,1628079855.744 [RudderServo](ERROR): Communications Fault
2021-08-04T12:24:15.845Z,1628079855.845 [CBIT](ERROR): Communications Fault in component: RudderServo
2021-08-04T12:24:16.049Z,1628079856.049 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2021-08-04T12:24:16.049Z,1628079856.049 [RudderServo](INFO): Powering down
2021-08-04T12:24:16.300Z,1628079856.300 [WetLabsBB2FL](INFO): Powering down
2021-08-04T12:24:16.685Z,1628079856.685 [RudderServo](DEBUG): Initializing EZServoServo.
2021-08-04T12:24:16.805Z,1628079856.805 [RudderServo](DEBUG): Initializing RudderServo.
2021-08-04T12:24:16.809Z,1628079856.809 [CBIT](INFO): Clearing failed state for component RudderServo
2021-08-04T12:24:16.809Z,1628079856.809 [RudderServo] No Fault, FailCount= 1
2021-08-04T12:24:21.208Z,1628079861.208 [CTD_Seabird](ERROR): Device message queue exceeded the allowed limit.
2021-08-04T12:24:43.738Z,1628079883.738 [NAL9602](INFO): Powering up NAL9602
2021-08-04T12:24:54.663Z,1628079894.663 [NAL9602](INFO): NAL9602 initialized
2021-08-04T12:25:08.386Z,1628079908.386 [NAL9602](INFO): SBD MO Status=0, MOMSN=41881, MT Status=0, MTMSN=0
2021-08-04T12:25:08.386Z,1628079908.386 [NAL9602](INFO): No messages in MT queue
2021-08-04T12:25:09.663Z,1628079909.663 [SBIT](IMPORTANT): Beginning Startup BIT
2021-08-04T12:25:09.667Z,1628079909.667 [CBIT](IMPORTANT): Beginning ground fault scan
2021-08-04T12:25:19.329Z,1628079919.329 [DVL_micro](ERROR): Failed to parse:
:WI,+00118,+00030,+00588,+00000,A
2021-08-04T12:25:20.501Z,1628079920.501 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2021-08-04T12:25:20.626Z,1628079920.626 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.008210
CHAN A1 (24V): -0.000290
CHAN A2 (12V): -0.005887
CHAN A3 (5V): -0.002483
CHAN B0 (3.3V): -0.000976
CHAN B1 (3.15aV): -0.000552
CHAN B2 (3.15bV): -0.001223
CHAN B3 (GND): -0.000357
OPEN: 0.007198
Full Scale Calc: 4.765 mA, -1.589 mA
2021-08-04T12:25:24.553Z,1628079924.553 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2021-08-04T12:25:24.553Z,1628079924.553 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,+25.6,0000.0,1489.0I,-00088,+00045,+00578,+00000,A
2021-08-04T12:25:32.217Z,1628079932.217 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2021-08-04T12:25:43.528Z,1628079943.528 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2021-08-04T12:25:55.245Z,1628079955.245 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2021-08-04T12:25:56.876Z,1628079956.876 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,122451.00,A,4212.98969,N,08344.18336,W,0.156,0.00,040821,,,A*76
2021-08-04T12:25:56.879Z,1628079956.879 [NAL9602](INFO): GPS fix at 20210804T122451: (42.216495, -83.736389)
2021-08-04T12:26:03.356Z,1628079963.356 [SBIT](IMPORTANT): SBIT PASSED
2021-08-04T12:26:03.357Z,1628079963.357 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2021-08-04T12:26:03.357Z,1628079963.357 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=2 count;
2021-08-04T12:26:03.358Z,1628079963.358 [SBIT](IMPORTANT): CBIT.gf24Offset=148.5 microampere;
2021-08-04T12:26:03.358Z,1628079963.358 [SBIT](IMPORTANT): CTD_Seabird.minSalinityBound=0.01 practical_salinity_unit;
2021-08-04T12:26:03.358Z,1628079963.358 [SBIT](IMPORTANT): DAT.loadAtStartup=0 bool;
2021-08-04T12:26:03.358Z,1628079963.358 [SBIT](IMPORTANT): Depth_Keller.offset=-0.2859 decibar;
2021-08-04T12:26:03.358Z,1628079963.358 [SBIT](IMPORTANT): Express none WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water;
2021-08-04T12:26:03.358Z,1628079963.358 [SBIT](IMPORTANT): Express linearApproximation WetLabsBB2FL.bin_median_mass_concentration_of_chlorophyll_in_sea_water 0.400000 microgram_per_liter;
2021-08-04T12:26:03.358Z,1628079963.358 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=325.319339 cubic_centimeter;
2021-08-04T12:26:03.359Z,1628079963.359 [SBIT](IMPORTANT): VerticalControl.massDefault=8.946893 millimeter;
2021-08-04T12:26:03.754Z,1628079963.754 [MissionManager](IMPORTANT): Started mission Startup
2021-08-04T12:26:03.754Z,1628079963.754 [Startup] Running Loop=1
2021-08-04T12:26:03.755Z,1628079963.755 [Startup](DEBUG): Aggregate::initialize Startup
2021-08-04T12:26:03.755Z,1628079963.755 [Startup:A.GoToSurface] Running Loop=1
2021-08-04T12:26:03.755Z,1628079963.755 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2021-08-04T12:26:03.755Z,1628079963.755 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2021-08-04T12:26:03.756Z,1628079963.756 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2021-08-04T12:26:03.756Z,1628079963.756 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2021-08-04T12:26:03.757Z,1628079963.757 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2021-08-04T12:26:03.757Z,1628079963.757 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2021-08-04T12:26:03.759Z,1628079963.759 [Startup:StartupSatComms] Running Loop=1
2021-08-04T12:26:03.759Z,1628079963.759 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2021-08-04T12:26:03.759Z,1628079963.759 [Startup:StartupSatComms:A] Running Loop=1
2021-08-04T12:26:04.150Z,1628079964.150 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2021-08-04T12:26:05.803Z,1628079965.803 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,122459.00,A,4212.99010,N,08344.18246,W,1.108,0.00,040821,,,A*74
2021-08-04T12:26:05.806Z,1628079965.806 [NAL9602](INFO): GPS fix at 20210804T122459: (42.216502, -83.736374)
2021-08-04T12:26:05.814Z,1628079965.814 [Startup:StartupSatComms:A] Stopped
2021-08-04T12:26:05.814Z,1628079965.814 [Startup:StartupSatComms:B] Running Loop=1
2021-08-04T12:26:06.155Z,1628079966.155 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2021-08-04T12:26:06.212Z,1628079966.212 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2021-08-04T12:26:18.000Z,1628079978.000 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2021-08-04T12:26:21.658Z,1628079981.658 [NAL9602](INFO): SBD MO Status=1, MOMSN=41882, MT Status=0, MTMSN=0
2021-08-04T12:26:21.712Z,1628079981.712 [NAL9602](INFO): Sent 39 bytes from file Logs/20210803T185359/Courier0298.lzma
2021-08-04T12:26:21.712Z,1628079981.712 [NAL9602](INFO): Packets left to send: 0
2021-08-04T12:26:29.361Z,1628079989.361 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2021-08-04T12:26:30.975Z,1628079990.975 [NAL9602](INFO): SBD MO Status=1, MOMSN=41883, MT Status=0, MTMSN=0
2021-08-04T12:26:31.024Z,1628079991.024 [NAL9602](INFO): Sent 266 bytes from file Logs/20210804T122403/Courier0000.lzma
2021-08-04T12:26:31.024Z,1628079991.024 [NAL9602](INFO): Packets left to send: 0
2021-08-04T12:26:40.889Z,1628080000.889 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2021-08-04T12:26:41.734Z,1628080001.734 [NAL9602](INFO): SBD MO Status=1, MOMSN=41884, MT Status=0, MTMSN=0
2021-08-04T12:26:41.781Z,1628080001.781 [NAL9602](INFO): Sent 144 bytes from file Logs/20210803T185359/Express0299.lzma
2021-08-04T12:26:41.781Z,1628080001.781 [NAL9602](INFO): Packets left to send: 0
2021-08-04T12:26:50.255Z,1628080010.255 [NAL9602](INFO): SBD MO Status=1, MOMSN=41885, MT Status=0, MTMSN=0
2021-08-04T12:26:50.312Z,1628080010.312 [NAL9602](INFO): Sent 332 bytes from file Logs/20210804T122403/Express0001.lzma
2021-08-04T12:26:50.312Z,1628080010.312 [NAL9602](INFO): Packets left to send: 2
2021-08-04T12:27:01.232Z,1628080021.232 [NAL9602](INFO): SBD MO Status=1, MOMSN=41886, MT Status=0, MTMSN=0
2021-08-04T12:27:01.288Z,1628080021.288 [NAL9602](INFO): Sent 332 bytes from file Logs/20210804T122403/Express0001.lzma
2021-08-04T12:27:01.288Z,1628080021.288 [NAL9602](INFO): Packets left to send: 1
2021-08-04T12:27:06.213Z,1628080026.213 [Startup:StartupSatComms:B](INFO): Timed out from 2021-08-04T12:26:05.8Z
2021-08-04T12:27:06.213Z,1628080026.213 [Startup:StartupSatComms:B] Stopped
2021-08-04T12:27:06.213Z,1628080026.213 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2021-08-04T12:27:06.213Z,1628080026.213 [Startup:StartupSatComms] Stopped
2021-08-04T12:27:06.213Z,1628080026.213 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2021-08-04T12:27:06.214Z,1628080026.214 [Startup](INFO): Completed Startup
2021-08-04T12:27:06.215Z,1628080026.215 [MissionManager](INFO): Startup is completed.
2021-08-04T12:27:06.215Z,1628080026.215 [MissionManager](INFO): Uninitializing Mission Startup
2021-08-04T12:27:06.215Z,1628080026.215 [Startup] Stopped
2021-08-04T12:27:06.215Z,1628080026.215 [Startup](DEBUG): Aggregate::uninitialize Startup
2021-08-04T12:27:06.215Z,1628080026.215 [Startup:A.GoToSurface] Stopped
2021-08-04T12:27:06.215Z,1628080026.215 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2021-08-04T12:27:06.628Z,1628080026.628 [MissionManager](IMPORTANT): Started mission Default
2021-08-04T12:27:06.628Z,1628080026.628 [Default] Running Loop=1
2021-08-04T12:27:06.628Z,1628080026.628 [Default](DEBUG): Aggregate::initialize Default
2021-08-04T12:27:06.629Z,1628080026.629 [Default:B.GoToSurface] Running Loop=1
2021-08-04T12:27:06.629Z,1628080026.629 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2021-08-04T12:27:06.629Z,1628080026.629 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2021-08-04T12:27:06.629Z,1628080026.629 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2021-08-04T12:27:06.630Z,1628080026.630 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2021-08-04T12:27:06.630Z,1628080026.630 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2021-08-04T12:27:06.630Z,1628080026.630 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2021-08-04T12:27:06.631Z,1628080026.631 [Default:A.Wait] Running Loop=1
2021-08-04T12:27:06.631Z,1628080026.631 [Default:A.Wait](DEBUG): Initialize Wait Component.
2021-08-04T12:27:11.972Z,1628080031.972 [NAL9602](INFO): SBD MO Status=1, MOMSN=41887, MT Status=0, MTMSN=0
2021-08-04T12:27:12.040Z,1628080032.040 [NAL9602](INFO): Sent 327 bytes from file Logs/20210804T122403/Express0001.lzma
2021-08-04T12:27:12.040Z,1628080032.040 [NAL9602](INFO): Packets left to send: 0
2021-08-04T12:27:19.996Z,1628080039.996 [Default:A.Wait](INFO): Done Waiting.
2021-08-04T12:27:19.996Z,1628080039.996 [Default:A.Wait] Stopped
2021-08-04T12:27:19.996Z,1628080039.996 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2021-08-04T12:27:20.347Z,1628080040.347 [Default:CheckIn] Running Loop=1
2021-08-04T12:27:20.347Z,1628080040.347 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-08-04T12:27:20.347Z,1628080040.347 [Default:CheckIn:Read_GPS] Running Loop=1
2021-08-04T12:27:20.758Z,1628080040.758 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2021-08-04T12:27:22.354Z,1628080042.354 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,122616.00,A,4212.99052,N,08344.18599,W,0.952,343.02,040821,,,A*7E
2021-08-04T12:27:22.356Z,1628080042.356 [NAL9602](INFO): GPS fix at 20210804T122616: (42.216509, -83.736433)
2021-08-04T12:27:22.365Z,1628080042.365 [Default:CheckIn:Read_GPS] Stopped
2021-08-04T12:27:22.366Z,1628080042.366 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-08-04T12:27:22.782Z,1628080042.782 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2021-08-04T12:27:47.057Z,1628080067.057 [NAL9602](INFO): SBD MO Status=1, MOMSN=41888, MT Status=0, MTMSN=0
2021-08-04T12:27:47.104Z,1628080067.104 [NAL9602](INFO): Sent 71 bytes from file Logs/20210804T122403/Courier0004.lzma
2021-08-04T12:27:47.104Z,1628080067.104 [NAL9602](INFO): Packets left to send: 0
2021-08-04T12:27:50.037Z,1628080070.037 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004163
2021-08-04T12:27:57.476Z,1628080077.476 [DataOverHttps](INFO): Sending 226 bytes from file Logs/20210804T122403/Express0005.lzma
2021-08-04T12:27:58.478Z,1628080078.478 [DataOverHttps](INFO): Moved sent file to Logs/20210804T122403/Express0005.lzma.bak
2021-08-04T12:27:58.478Z,1628080078.478 [DataOverHttps](INFO): SBD MOMSN=15819402
2021-08-04T12:27:59.983Z,1628080079.983 [Default:CheckIn:Read_Iridium] Stopped
2021-08-04T12:27:59.984Z,1628080079.984 [Default:CheckIn:C.Wait] Running Loop=1
2021-08-04T12:27:59.984Z,1628080079.984 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-08-04T12:28:03.603Z,1628080083.603 [NAL9602](INFO): SBD MO Status=2, MOMSN=41889, MT Status=2, MTMSN=0
2021-08-04T12:28:03.603Z,1628080083.603 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-08-04T12:28:34.317Z,1628080114.317 [NAL9602](INFO): Not Powering down - fast GPS
2021-08-04T12:31:53.129Z,1628080313.129 [BPC1](INFO): Calculating totals. Valid battery stick count: 55. Valid reserve battery stick count: 5.
2021-08-04T12:31:53.132Z,1628080313.132 [BPC1](INFO): Received data from all battery sticks.
2021-08-04T12:33:00.671Z,1628080380.671 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-08-04T12:33:00.671Z,1628080380.671 [Default:CheckIn:C.Wait] Stopped
2021-08-04T12:33:00.671Z,1628080380.671 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-08-04T12:33:00.671Z,1628080380.671 [Default:CheckIn:D] Running Loop=1
2021-08-04T12:33:01.054Z,1628080381.054 [Default:CheckIn:D] Stopped
2021-08-04T12:33:01.054Z,1628080381.054 [Default:CheckIn:E] Running Loop=1
2021-08-04T12:33:01.458Z,1628080381.458 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 5.907092 min
2021-08-04T12:33:01.458Z,1628080381.458 [Default:CheckIn:E] Stopped
2021-08-04T12:33:01.458Z,1628080381.458 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-08-04T12:33:01.459Z,1628080381.459 [Default:CheckIn] Stopped
2021-08-04T12:33:01.459Z,1628080381.459 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-08-04T12:33:01.459Z,1628080381.459 [Default:CheckIn](INFO): Running loop #2
2021-08-04T12:33:01.459Z,1628080381.459 [Default:CheckIn] Running Loop=2
2021-08-04T12:33:01.459Z,1628080381.459 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-08-04T12:33:01.459Z,1628080381.459 [Default:CheckIn:Read_GPS] Running Loop=1
2021-08-04T12:33:03.474Z,1628080383.474 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,123158.00,A,4212.98990,N,08344.18699,W,0.253,296.43,040821,,,D*74
2021-08-04T12:33:03.477Z,1628080383.477 [NAL9602](INFO): GPS fix at 20210804T123158: (42.216498, -83.736450)
2021-08-04T12:33:03.486Z,1628080383.486 [Default:CheckIn:Read_GPS] Stopped
2021-08-04T12:33:03.486Z,1628080383.486 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-08-04T12:33:11.013Z,1628080391.013 [DataOverHttps](INFO): Sending 201 bytes from file Logs/20210804T122403/Courier0007.lzma
2021-08-04T12:33:12.013Z,1628080392.013 [DataOverHttps](INFO): Moved sent file to Logs/20210804T122403/Courier0007.lzma.bak
2021-08-04T12:33:12.014Z,1628080392.014 [DataOverHttps](INFO): SBD MOMSN=15819468
2021-08-04T12:33:27.689Z,1628080407.689 [DataOverHttps](INFO): Sending 162 bytes from file Logs/20210804T122403/Express0008.lzma
2021-08-04T12:33:27.714Z,1628080407.714 [NAL9602](INFO): SBD MO Status=1, MOMSN=41889, MT Status=0, MTMSN=0
2021-08-04T12:33:27.714Z,1628080407.714 [NAL9602](INFO): No messages in MT queue
2021-08-04T12:33:28.686Z,1628080408.686 [DataOverHttps](INFO): Moved sent file to Logs/20210804T122403/Express0008.lzma.bak
2021-08-04T12:33:28.686Z,1628080408.686 [DataOverHttps](INFO): SBD MOMSN=15819471
2021-08-04T12:33:30.145Z,1628080410.145 [Default:CheckIn:Read_Iridium] Stopped
2021-08-04T12:33:30.145Z,1628080410.145 [Default:CheckIn:C.Wait] Running Loop=1
2021-08-04T12:33:30.145Z,1628080410.145 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-08-04T12:33:58.413Z,1628080438.413 [NAL9602](INFO): Not Powering down - fast GPS
2021-08-04T12:36:58.108Z,1628080618.108 [CommandLine](IMPORTANT): got command show variable distance_from
2021-08-04T12:36:58.111Z,1628080618.111 [CommandLine](IMPORTANT): distance_from_shore (unknown)
2021-08-04T12:36:58.440Z,1628080618.440 [CommandLine](IMPORTANT): NavChart.distance_from_shore (meter)
2021-08-04T12:37:02.109Z,1628080622.109 [CommandLine](IMPORTANT): got command get distance_from_shore
2021-08-04T12:37:02.109Z,1628080622.109 [CommandLine](FAULT): Element has no value
2021-08-04T12:37:13.682Z,1628080633.682 [CommandLine](IMPORTANT): got command get NavChart.distance_from_shore
2021-08-04T12:37:13.683Z,1628080633.683 [CommandLine](IMPORTANT): NavChart.distance_from_shore nan m
2021-08-04T12:37:16.010Z,1628080636.010 [CommandLine](IMPORTANT): got command failComponent
2021-08-04T12:37:16.010Z,1628080636.010 [CommandLine](IMPORTANT): Failed components:
2021-08-04T12:37:16.010Z,1628080636.010 [CommandLine](IMPORTANT): No failed Components.
2021-08-04T12:37:43.417Z,1628080663.417 [DataOverHttps](IMPORTANT): SBD MTMSN=20210804T123638
2021-08-04T12:37:51.780Z,1628080671.780 [DataOverHttps](INFO): Received command:restart sys
2021-08-04T12:37:51.792Z,1628080671.792 [CommandLine](IMPORTANT): got command restart system
2021-08-04T12:37:53.856Z,1628080673.856 [Supervisor](INFO): Stop Mission called by Supervisor::terminate
2021-08-04T12:37:53.856Z,1628080673.856 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2021-08-04T12:37:53.857Z,1628080673.857 [CommandLine ThreadHandler](INFO): Thread cancelled.
2021-08-04T12:37:54.004Z,1628080674.004 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye!
2021-08-04T12:37:54.004Z,1628080674.004 [CommandLine ThreadHandler](INFO): Thread cancelled.
2021-08-04T12:37:54.005Z,1628080674.005 [CommandLine](INFO): Join timeout helper Thread ID is 2500
2021-08-04T12:37:54.005Z,1628080674.005 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2021-08-04T12:37:54.005Z,1628080674.005 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2021-08-04T12:37:54.006Z,1628080674.006 [NavChartDb](INFO): Join timeout helper Thread ID is 2501
2021-08-04T12:37:54.380Z,1628080674.380 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2021-08-04T12:37:54.380Z,1628080674.380 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2021-08-04T12:37:54.388Z,1628080674.388 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2021-08-04T12:37:54.388Z,1628080674.388 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2021-08-04T12:37:54.388Z,1628080674.388 [Radio_Surface](INFO): Join timeout helper Thread ID is 2502
2021-08-04T12:37:54.760Z,1628080674.760 [Radio_Surface](INFO): Powering down
2021-08-04T12:37:54.761Z,1628080674.761 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2021-08-04T12:37:54.761Z,1628080674.761 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2021-08-04T12:37:54.768Z,1628080674.768 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler
2021-08-04T12:37:54.768Z,1628080674.768 [Onboard ThreadHandler](INFO): Thread cancelled.
2021-08-04T12:37:54.768Z,1628080674.768 [Onboard](INFO): Join timeout helper Thread ID is 2503
2021-08-04T12:37:54.788Z,1628080674.788 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2021-08-04T12:37:54.920Z,1628080674.920 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread.
2021-08-04T12:37:54.920Z,1628080674.920 [Onboard ThreadHandler](INFO): Thread cancelled.
2021-08-04T12:37:54.932Z,1628080674.932 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2021-08-04T12:37:54.932Z,1628080674.932 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2021-08-04T12:37:54.932Z,1628080674.932 [DataOverHttps](INFO): Join timeout helper Thread ID is 2504
2021-08-04T12:37:55.792Z,1628080675.792 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2021-08-04T12:37:55.792Z,1628080675.792 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2021-08-04T12:37:55.805Z,1628080675.805 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2021-08-04T12:37:55.805Z,1628080675.805 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2021-08-04T12:37:55.805Z,1628080675.805 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 2505
2021-08-04T12:37:56.304Z,1628080676.304 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2021-08-04T12:37:56.304Z,1628080676.304 [WetLabsBB2FL](INFO): Powering down
2021-08-04T12:37:56.305Z,1628080676.305 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2021-08-04T12:37:56.327Z,1628080676.327 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2021-08-04T12:37:56.327Z,1628080676.327 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2021-08-04T12:37:56.327Z,1628080676.327 [CTD_Seabird](INFO): Join timeout helper Thread ID is 2506
2021-08-04T12:37:56.824Z,1628080676.824 [CTD_Seabird](INFO): Powering down
2021-08-04T12:37:56.836Z,1628080676.836 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2021-08-04T12:37:56.836Z,1628080676.836 [CTD_Seabird](INFO): Powering down
2021-08-04T12:37:56.848Z,1628080676.848 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2021-08-04T12:37:56.868Z,1628080676.868 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2021-08-04T12:37:56.869Z,1628080676.869 [logger ThreadHandler](INFO): Thread cancelled.
2021-08-04T12:37:56.869Z,1628080676.869 [logger](INFO): Join timeout helper Thread ID is 2507
2021-08-04T12:37:56.892Z,1628080676.892 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2021-08-04T12:37:56.892Z,1628080676.892 [logger ThreadHandler](INFO): Thread cancelled.
2021-08-04T12:37:56.909Z,1628080676.909 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2021-08-04T12:37:56.909Z,1628080676.909 [CommandLine ThreadHandler](INFO): Thread cancelled.
2021-08-04T12:37:56.909Z,1628080676.909 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2021-08-04T12:37:56.909Z,1628080676.909 [controlThread ThreadHandler](INFO): Thread cancelled.
2021-08-04T12:37:56.909Z,1628080676.909 [controlThread](INFO): Join timeout helper Thread ID is 2508
2021-08-04T12:37:56.941Z,1628080676.941 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2021-08-04T12:37:56.941Z,1628080676.941 [controlThread](DEBUG): Uninitializing ControlThread
2021-08-04T12:37:56.943Z,1628080676.943 [AHRS_M2](INFO): Powering down
2021-08-04T12:37:57.088Z,1628080677.088 [DVL_micro](INFO): Powering down
2021-08-04T12:37:57.089Z,1628080677.089 [NAL9602](INFO): Powering down
2021-08-04T12:37:57.091Z,1628080677.091 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2021-08-04T12:37:57.092Z,1628080677.092 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2021-08-04T12:37:57.092Z,1628080677.092 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2021-08-04T12:37:57.093Z,1628080677.093 [MissionManager](INFO): Uninitializing Mission Default
2021-08-04T12:37:57.093Z,1628080677.093 [Default] Stopped
2021-08-04T12:37:57.093Z,1628080677.093 [Default](DEBUG): Aggregate::uninitialize Default
2021-08-04T12:37:57.093Z,1628080677.093 [Default:B.GoToSurface] Stopped
2021-08-04T12:37:57.093Z,1628080677.093 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2021-08-04T12:37:57.094Z,1628080677.094 [Default:CheckIn] Stopped
2021-08-04T12:37:57.094Z,1628080677.094 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-08-04T12:37:57.094Z,1628080677.094 [Default:CheckIn:C.Wait] Stopped
2021-08-04T12:37:57.094Z,1628080677.094 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-08-04T12:37:57.097Z,1628080677.097 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2021-08-04T12:37:57.098Z,1628080677.098 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2021-08-04T12:37:57.098Z,1628080677.098 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2021-08-04T12:37:57.098Z,1628080677.098 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2021-08-04T12:37:57.099Z,1628080677.099 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2021-08-04T12:37:57.099Z,1628080677.099 [BuoyancyServo](INFO): Powering down
2021-08-04T12:37:57.112Z,1628080677.112 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2021-08-04T12:37:57.112Z,1628080677.112 [ElevatorServo](INFO): Powering down
2021-08-04T12:37:57.113Z,1628080677.113 [MassServo](DEBUG): Uninitialize Mass Servo.
2021-08-04T12:37:57.113Z,1628080677.113 [MassServo](INFO): Powering down
2021-08-04T12:37:57.114Z,1628080677.114 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2021-08-04T12:37:57.114Z,1628080677.114 [RudderServo](INFO): Powering down
2021-08-04T12:37:57.115Z,1628080677.115 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2021-08-04T12:37:57.115Z,1628080677.115 [ThrusterServo](INFO): Powering down
2021-08-04T12:37:57.117Z,1628080677.117 [SBIT](DEBUG): Uninitialize SBIT Component.
2021-08-04T12:37:57.117Z,1628080677.117 [IBIT](DEBUG): Uninitialize IBIT Component.
2021-08-04T12:37:57.117Z,1628080677.117 [CBIT](DEBUG): Uninitialize CBIT Component.
2021-08-04T12:37:57.117Z,1628080677.117 [CBIT](DEBUG): Powering off loads.
2021-08-04T12:37:57.128Z,1628080677.128 [CBIT](DEBUG): Disabling WDT.
2021-08-04T12:37:57.140Z,1628080677.140 [CBIT](DEBUG): Opening all GF detection circuits.
2021-08-04T12:37:57.141Z,1628080677.141 [controlThread ThreadHandler](INFO): Thread cancelled.
2021-08-04T12:37:57.193Z,1628080677.193 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2021-08-04T12:37:57.200Z,1628080677.200 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2021-08-04T12:37:57.236Z,1628080677.236 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2021-08-04T12:37:57.239Z,1628080677.239 [Onboard ThreadHandler](INFO): Thread cancelled.
2021-08-04T12:37:57.248Z,1628080677.248 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2021-08-04T12:37:57.358Z,1628080677.358 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2021-08-04T12:37:57.426Z,1628080677.426 [logger ThreadHandler](INFO): Thread cancelled.