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.