2019-08-28T22:19:05.450Z,1567030745.450 [Supervisor](DEBUG): Initializing supervisor.
2019-08-28T22:19:05.453Z,1567030745.453 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2019-08-28T22:19:05.454Z,1567030745.454 [SyncHandler](INFO): Protected caller Thread ID is 4232
2019-08-28T22:19:05.455Z,1567030745.455 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2019-08-28T22:19:05.456Z,1567030745.456 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2019-08-28T22:19:05.456Z,1567030745.456 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 4233
2019-08-28T22:19:05.459Z,1567030745.459 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2019-08-28T22:19:05.471Z,1567030745.471 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2019-08-28T22:19:05.472Z,1567030745.472 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2019-08-28T22:19:05.472Z,1567030745.472 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 4234
2019-08-28T22:19:05.473Z,1567030745.473 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2019-08-28T22:19:05.474Z,1567030745.474 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2019-08-28T22:19:05.474Z,1567030745.474 [logger ThreadHandler](INFO): Protected caller Thread ID is 4235
2019-08-28T22:19:05.476Z,1567030745.476 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2019-08-28T22:19:05.476Z,1567030745.476 [Supervisor](INFO): Looking for Config files in directory: Config/
2019-08-28T22:19:05.478Z,1567030745.478 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2019-08-28T22:19:05.640Z,1567030745.640 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2019-08-28T22:19:05.641Z,1567030745.641 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2019-08-28T22:19:06.217Z,1567030746.217 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2019-08-28T22:19:06.218Z,1567030746.218 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2019-08-28T22:19:06.316Z,1567030746.316 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2019-08-28T22:19:06.317Z,1567030746.317 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2019-08-28T22:19:06.419Z,1567030746.419 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2019-08-28T22:19:06.420Z,1567030746.420 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2019-08-28T22:19:06.502Z,1567030746.502 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2019-08-28T22:19:06.639Z,1567030746.639 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2019-08-28T22:19:06.640Z,1567030746.640 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2019-08-28T22:19:06.925Z,1567030746.925 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2019-08-28T22:19:06.925Z,1567030746.925 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2019-08-28T22:19:07.367Z,1567030747.367 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2019-08-28T22:19:07.368Z,1567030747.368 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2019-08-28T22:19:07.511Z,1567030747.511 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2019-08-28T22:19:07.512Z,1567030747.512 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2019-08-28T22:19:07.707Z,1567030747.707 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2019-08-28T22:19:07.707Z,1567030747.707 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2019-08-28T22:19:08.145Z,1567030748.145 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2019-08-28T22:19:08.145Z,1567030748.145 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2019-08-28T22:19:08.354Z,1567030748.354 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2019-08-28T22:19:08.354Z,1567030748.354 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2019-08-28T22:19:08.552Z,1567030748.552 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2019-08-28T22:19:08.553Z,1567030748.553 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2019-08-28T22:19:08.932Z,1567030748.932 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2019-08-28T22:19:08.933Z,1567030748.933 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2019-08-28T22:19:09.256Z,1567030749.256 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2019-08-28T22:19:09.258Z,1567030749.258 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-pontus/
2019-08-28T22:19:09.259Z,1567030749.259 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/secure.cfg
2019-08-28T22:19:09.343Z,1567030749.343 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Sensor.cfg
2019-08-28T22:19:09.508Z,1567030749.508 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Servo.cfg
2019-08-28T22:19:10.215Z,1567030750.215 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Simulator.cfg
2019-08-28T22:19:10.570Z,1567030750.570 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/logger.cfg
2019-08-28T22:19:10.819Z,1567030750.819 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/vehicle.cfg
2019-08-28T22:19:11.009Z,1567030751.009 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Battery.cfg
2019-08-28T22:19:11.235Z,1567030751.235 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2019-08-28T22:19:11.236Z,1567030751.236 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Navigation.cfg
2019-08-28T22:19:11.330Z,1567030751.330 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/BIT.cfg
2019-08-28T22:19:11.429Z,1567030751.429 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Science.cfg
2019-08-28T22:19:11.548Z,1567030751.548 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Control.cfg
2019-08-28T22:19:11.649Z,1567030751.649 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-pontus/root/
2019-08-28T22:19:11.650Z,1567030751.650 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2019-08-28T22:19:11.655Z,1567030751.655 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2019-08-28T22:19:11.720Z,1567030751.720 [VerticalControl](DEBUG): Construct VerticalControl.
2019-08-28T22:19:11.827Z,1567030751.827 [VerticalControl] Loaded
2019-08-28T22:19:11.828Z,1567030751.828 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2019-08-28T22:19:11.828Z,1567030751.828 [HorizontalControl](DEBUG): Construct HorizontalControl.
2019-08-28T22:19:11.894Z,1567030751.894 [HorizontalControl] Loaded
2019-08-28T22:19:11.894Z,1567030751.894 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2019-08-28T22:19:11.895Z,1567030751.895 [SpeedControl](DEBUG): Construct SpeedControl.
2019-08-28T22:19:11.900Z,1567030751.900 [SpeedControl] Loaded
2019-08-28T22:19:11.900Z,1567030751.900 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2019-08-28T22:19:11.901Z,1567030751.901 [LoopControl](DEBUG): Construct LoopControl.
2019-08-28T22:19:11.902Z,1567030751.902 [LoopControl] Loaded
2019-08-28T22:19:11.902Z,1567030751.902 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2019-08-28T22:19:11.902Z,1567030751.902 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2019-08-28T22:19:11.903Z,1567030751.903 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2019-08-28T22:19:11.943Z,1567030751.943 [DepthRateCalculator] Loaded
2019-08-28T22:19:11.943Z,1567030751.943 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2019-08-28T22:19:11.948Z,1567030751.948 [PitchRateCalculator] Loaded
2019-08-28T22:19:11.948Z,1567030751.948 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2019-08-28T22:19:11.963Z,1567030751.963 [SpeedCalculator] Loaded
2019-08-28T22:19:11.963Z,1567030751.963 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2019-08-28T22:19:11.983Z,1567030751.983 [TempGradientCalculator] Loaded
2019-08-28T22:19:11.983Z,1567030751.983 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2019-08-28T22:19:11.988Z,1567030751.988 [YawRateCalculator] Loaded
2019-08-28T22:19:11.988Z,1567030751.988 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2019-08-28T22:19:12.016Z,1567030752.016 [ElevatorOffsetCalculator] Loaded
2019-08-28T22:19:12.016Z,1567030752.016 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2019-08-28T22:19:12.017Z,1567030752.017 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2019-08-28T22:19:12.017Z,1567030752.017 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2019-08-28T22:19:12.052Z,1567030752.052 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2019-08-28T22:19:12.053Z,1567030752.053 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2019-08-28T22:19:12.126Z,1567030752.126 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2019-08-28T22:19:12.127Z,1567030752.127 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2019-08-28T22:19:12.405Z,1567030752.405 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2019-08-28T22:19:12.405Z,1567030752.405 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2019-08-28T22:19:12.503Z,1567030752.503 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2019-08-28T22:19:12.504Z,1567030752.504 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2019-08-28T22:19:12.878Z,1567030752.878 [AHRS_M2] Loaded
2019-08-28T22:19:12.878Z,1567030752.878 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2019-08-28T22:19:12.950Z,1567030752.950 [DataOverHttps] Loaded
2019-08-28T22:19:12.950Z,1567030752.950 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2019-08-28T22:19:12.951Z,1567030752.951 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 408CA4E0
2019-08-28T22:19:12.952Z,1567030752.952 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 4314
2019-08-28T22:19:12.964Z,1567030752.964 [Depth_Keller] Loaded
2019-08-28T22:19:12.965Z,1567030752.965 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2019-08-28T22:19:12.969Z,1567030752.969 [DropWeight] Loaded
2019-08-28T22:19:12.970Z,1567030752.970 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2019-08-28T22:19:13.062Z,1567030753.062 [NAL9602] Loaded
2019-08-28T22:19:13.062Z,1567030753.062 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2019-08-28T22:19:13.078Z,1567030753.078 [Onboard] Loaded
2019-08-28T22:19:13.078Z,1567030753.078 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2019-08-28T22:19:13.081Z,1567030753.081 [Radio_Surface] Loaded
2019-08-28T22:19:13.081Z,1567030753.081 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2019-08-28T22:19:13.082Z,1567030753.082 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408FA4E0
2019-08-28T22:19:13.083Z,1567030753.083 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 4315
2019-08-28T22:19:13.251Z,1567030753.251 [Rowe_600] Loaded
2019-08-28T22:19:13.251Z,1567030753.251 [ComponentRegistry](DEBUG): Component "Rowe_600" handled in its own thread.
2019-08-28T22:19:13.252Z,1567030753.252 [Rowe_600 ThreadHandler](DEBUG): Created PCaller Thread at 4092A4E0
2019-08-28T22:19:13.252Z,1567030753.252 [Rowe_600 ThreadHandler](INFO): Protected caller Thread ID is 4316
2019-08-28T22:19:14.876Z,1567030754.876 [BPC1] Loaded
2019-08-28T22:19:14.876Z,1567030754.876 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2019-08-28T22:19:14.877Z,1567030754.877 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2019-08-28T22:19:14.877Z,1567030754.877 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2019-08-28T22:19:14.977Z,1567030754.977 [DeadReckonUsingMultipleVelocitySources] Loaded
2019-08-28T22:19:14.977Z,1567030754.977 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2019-08-28T22:19:14.996Z,1567030754.996 [NavChart] Loaded
2019-08-28T22:19:14.997Z,1567030754.997 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2019-08-28T22:19:15.000Z,1567030755.000 [UniversalFixResidualReporter] Loaded
2019-08-28T22:19:15.001Z,1567030755.001 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2019-08-28T22:19:15.001Z,1567030755.001 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2019-08-28T22:19:15.002Z,1567030755.002 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2019-08-28T22:19:15.132Z,1567030755.132 [SBIT](DEBUG): Construct Startup Built In Test.
2019-08-28T22:19:15.143Z,1567030755.143 [SBIT] Loaded
2019-08-28T22:19:15.144Z,1567030755.144 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2019-08-28T22:19:15.144Z,1567030755.144 [IBIT](DEBUG): Construct Initiated Built In Test.
2019-08-28T22:19:15.155Z,1567030755.155 [IBIT] Loaded
2019-08-28T22:19:15.156Z,1567030755.156 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2019-08-28T22:19:15.159Z,1567030755.159 [CBIT](DEBUG): Construct Continuous Built In Test.
2019-08-28T22:19:15.290Z,1567030755.290 [CBIT] Loaded
2019-08-28T22:19:15.291Z,1567030755.291 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2019-08-28T22:19:15.291Z,1567030755.291 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2019-08-28T22:19:15.291Z,1567030755.291 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2019-08-28T22:19:15.394Z,1567030755.394 [BuoyancyServo] Loaded
2019-08-28T22:19:15.395Z,1567030755.395 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2019-08-28T22:19:15.406Z,1567030755.406 [ElevatorServo] Loaded
2019-08-28T22:19:15.406Z,1567030755.406 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2019-08-28T22:19:15.416Z,1567030755.416 [MassServo] Loaded
2019-08-28T22:19:15.417Z,1567030755.417 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2019-08-28T22:19:15.428Z,1567030755.428 [RudderServo] Loaded
2019-08-28T22:19:15.428Z,1567030755.428 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2019-08-28T22:19:15.438Z,1567030755.438 [ThrusterServo] Loaded
2019-08-28T22:19:15.439Z,1567030755.439 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2019-08-28T22:19:15.439Z,1567030755.439 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2019-08-28T22:19:15.439Z,1567030755.439 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2019-08-28T22:19:15.455Z,1567030755.455 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2019-08-28T22:19:15.455Z,1567030755.455 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2019-08-28T22:19:15.626Z,1567030755.626 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_density
2019-08-28T22:19:15.632Z,1567030755.632 [CTD_Seabird](INFO): created writer for : sea_water_density
2019-08-28T22:19:15.634Z,1567030755.634 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): depth
2019-08-28T22:19:15.638Z,1567030755.638 [CTD_Seabird](INFO): created writer for : depth
2019-08-28T22:19:15.639Z,1567030755.639 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_pressure
2019-08-28T22:19:15.644Z,1567030755.644 [CTD_Seabird](INFO): created writer for : sea_water_pressure
2019-08-28T22:19:15.644Z,1567030755.644 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_salinity
2019-08-28T22:19:15.650Z,1567030755.650 [CTD_Seabird](INFO): created writer for : sea_water_salinity
2019-08-28T22:19:15.650Z,1567030755.650 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_temperature
2019-08-28T22:19:15.655Z,1567030755.655 [CTD_Seabird](INFO): created writer for : sea_water_temperature
2019-08-28T22:19:15.656Z,1567030755.656 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_electrical_conductivity
2019-08-28T22:19:15.661Z,1567030755.661 [CTD_Seabird](INFO): created writer for : sea_water_electrical_conductivity
2019-08-28T22:19:15.662Z,1567030755.662 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): speed_of_sound_in_sea_water
2019-08-28T22:19:15.666Z,1567030755.666 [CTD_Seabird](INFO): created writer for : speed_of_sound_in_sea_water
2019-08-28T22:19:15.693Z,1567030755.693 [CTD_Seabird] Loaded
2019-08-28T22:19:15.693Z,1567030755.693 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2019-08-28T22:19:15.694Z,1567030755.694 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40AAF4E0
2019-08-28T22:19:15.695Z,1567030755.695 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 4317
2019-08-28T22:19:15.742Z,1567030755.742 [WetLabsBB2FL] Loaded
2019-08-28T22:19:15.742Z,1567030755.742 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2019-08-28T22:19:15.743Z,1567030755.743 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40ADF4E0
2019-08-28T22:19:15.743Z,1567030755.743 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 4318
2019-08-28T22:19:15.744Z,1567030755.744 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2019-08-28T22:19:15.747Z,1567030755.747 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2019-08-28T22:19:15.748Z,1567030755.748 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2019-08-28T22:19:15.755Z,1567030755.755 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2019-08-28T22:19:15.756Z,1567030755.756 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B0F4E0
2019-08-28T22:19:15.756Z,1567030755.756 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 4319
2019-08-28T22:19:15.761Z,1567030755.761 [Supervisor](INFO): Main Thread ID is 2133
2019-08-28T22:19:15.761Z,1567030755.761 [Supervisor](DEBUG): Running supervisor.
2019-08-28T22:19:15.762Z,1567030755.762 [CommandLine ThreadHandler](INFO): Handler Thread ID is 4320
2019-08-28T22:19:15.764Z,1567030755.764 [controlThread ThreadHandler](INFO): Handler Thread ID is 4321
2019-08-28T22:19:15.765Z,1567030755.765 [controlThread](DEBUG): Initializing ControlThread
2019-08-28T22:19:15.766Z,1567030755.766 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2019-08-28T22:19:15.767Z,1567030755.767 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2019-08-28T22:19:15.768Z,1567030755.768 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2019-08-28T22:19:15.768Z,1567030755.768 [LoopControl](DEBUG): Initialize LoopControlComponent.
2019-08-28T22:19:15.769Z,1567030755.769 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2019-08-28T22:19:15.769Z,1567030755.769 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2019-08-28T22:19:15.769Z,1567030755.769 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2019-08-28T22:19:15.769Z,1567030755.769 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2019-08-28T22:19:15.770Z,1567030755.770 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2019-08-28T22:19:15.770Z,1567030755.770 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2019-08-28T22:19:15.775Z,1567030755.775 [NavChart](DEBUG): Initialize NavChart Navigation.
2019-08-28T22:19:15.776Z,1567030755.776 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2019-08-28T22:19:15.776Z,1567030755.776 [SBIT](INFO): Initialize SBIT Component.
2019-08-28T22:19:15.777Z,1567030755.777 [SBIT](IMPORTANT): git: 2019-08-13-14-ga69707b
2019-08-28T22:19:15.777Z,1567030755.777 [SBIT](INFO): git hash: a69707bda281f6918618f51d3c69bc2653483d55
2019-08-28T22:19:15.777Z,1567030755.777 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2019-08-28T22:19:15.777Z,1567030755.777 [SBIT](IMPORTANT): Kernel Version:#1 PREEMPT Thu Feb 21 11:17:40 PST 2019
2019-08-28T22:19:15.778Z,1567030755.778 [SBIT](INFO): Beginning SBIT in 59.000000 seconds.
2019-08-28T22:19:15.779Z,1567030755.779 [IBIT](INFO): Initialize IBIT Component.
2019-08-28T22:19:15.780Z,1567030755.780 [CBIT](DEBUG): Initialize CBIT Component.
2019-08-28T22:19:15.781Z,1567030755.781 [logger ThreadHandler](INFO): Handler Thread ID is 4322
2019-08-28T22:19:15.793Z,1567030755.793 [CBIT](DEBUG): Initialized mux pins.
2019-08-28T22:19:15.793Z,1567030755.793 [CBIT](DEBUG): Initializing the watchdog timer.
2019-08-28T22:19:15.801Z,1567030755.801 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 4323
2019-08-28T22:19:15.802Z,1567030755.802 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2019-08-28T22:19:15.813Z,1567030755.813 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 4324
2019-08-28T22:19:15.817Z,1567030755.817 [CBIT](CRITICAL): LAST REBOOT DUE TO WATCHDOG TIMER RESET.
2019-08-28T22:19:15.817Z,1567030755.817 [CBIT](DEBUG): Initializing heartbeat.
2019-08-28T22:19:15.825Z,1567030755.825 [Rowe_600 ThreadHandler](INFO): Handler Thread ID is 4325
2019-08-28T22:19:15.837Z,1567030755.837 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 4326
2019-08-28T22:19:15.838Z,1567030755.838 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2019-08-28T22:19:15.841Z,1567030755.841 [CTD_Seabird](INFO): Opening uart, block timeout 10ths=20
2019-08-28T22:19:15.842Z,1567030755.842 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 4328
2019-08-28T22:19:15.844Z,1567030755.844 [WetLabsBB2FL](INFO): Powering down
2019-08-28T22:19:15.870Z,1567030755.870 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 4329
2019-08-28T22:19:15.877Z,1567030755.877 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2019-08-28T22:19:15.877Z,1567030755.877 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2019-08-28T22:19:15.877Z,1567030755.877 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2019-08-28T22:19:15.877Z,1567030755.877 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2019-08-28T22:19:15.877Z,1567030755.877 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2019-08-28T22:19:15.878Z,1567030755.878 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2019-08-28T22:19:15.878Z,1567030755.878 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2019-08-28T22:19:15.878Z,1567030755.878 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2019-08-28T22:19:15.878Z,1567030755.878 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2019-08-28T22:19:15.878Z,1567030755.878 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2019-08-28T22:19:15.878Z,1567030755.878 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2019-08-28T22:19:15.879Z,1567030755.879 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2019-08-28T22:19:15.879Z,1567030755.879 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2019-08-28T22:19:15.879Z,1567030755.879 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2019-08-28T22:19:15.879Z,1567030755.879 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2019-08-28T22:19:15.879Z,1567030755.879 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2019-08-28T22:19:15.889Z,1567030755.889 [CBIT](DEBUG): Deactivating GF circuits.
2019-08-28T22:19:15.889Z,1567030755.889 [CBIT](DEBUG): Deactivating emergency mode.
2019-08-28T22:19:15.925Z,1567030755.925 [CBIT](DEBUG): Backplane powered.
2019-08-28T22:19:15.927Z,1567030755.927 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2019-08-28T22:19:15.939Z,1567030755.939 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2019-08-28T22:19:15.971Z,1567030755.971 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Units="Tethys/Units"
       xmlns:Universal="Tethys/Universal"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
       Id="Startup">

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

    <Aggregate Id="StartupSatComms">

        <Sequence/>

        <ReadDatum>
            <Timeout Duration="P1M" />
            <Universal:latitude_fix/>
        </ReadDatum>

        <ReadDatum>
            <Timeout Duration="P1M" />
            <Universal:platform_communications/>
        </ReadDatum>

    </Aggregate>

</Mission>


2019-08-28T22:19:15.971Z,1567030755.971 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2019-08-28T22:19:16.022Z,1567030756.022 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2019-08-28T22:19:16.024Z,1567030756.024 [Default:A.Wait](DEBUG): Construct Wait.
2019-08-28T22:19:16.041Z,1567030756.041 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2019-08-28T22:19:16.090Z,1567030756.090 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2019-08-28T22:19:16.093Z,1567030756.093 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2019-08-28T22:19:16.101Z,1567030756.101 [Rowe_600](INFO): Powering down
2019-08-28T22:19:16.131Z,1567030756.131 [Default:E.Execute](DEBUG): Construct Execute.
2019-08-28T22:19:16.145Z,1567030756.145 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Universal="Tethys/Universal"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                             Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                             Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
         Id="Default">

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

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

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

    <Aggregate Id="CheckIn">

        <Sequence Repeat="288"/>

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

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

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

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

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

    </Aggregate>

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

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

</Mission>


2019-08-28T22:19:16.149Z,1567030756.149 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,NAL9602,Onboard,BPC1,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,
2019-08-28T22:19:16.161Z,1567030756.161 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2019-08-28T22:19:16.209Z,1567030756.209 [Depth_Keller](ERROR): Pressure reading out of range: 1650.297119 decibar
2019-08-28T22:19:16.217Z,1567030756.217 [Radio_Surface](INFO): Powering up
2019-08-28T22:19:16.269Z,1567030756.269 [DepthRateCalculator](ERROR): Depth measurement is not active
2019-08-28T22:19:16.283Z,1567030756.283 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2019-08-28T22:19:16.289Z,1567030756.289 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2019-08-28T22:19:16.290Z,1567030756.290 [ElevatorServo](DEBUG): Initializing EZServoServo.
2019-08-28T22:19:16.297Z,1567030756.297 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2019-08-28T22:19:16.298Z,1567030756.298 [MassServo](DEBUG): Initializing EZServoServo.
2019-08-28T22:19:16.305Z,1567030756.305 [MassServo](DEBUG): Initializing MassServo.
2019-08-28T22:19:16.306Z,1567030756.306 [RudderServo](DEBUG): Initializing EZServoServo.
2019-08-28T22:19:16.313Z,1567030756.313 [RudderServo](DEBUG): Initializing RudderServo.
2019-08-28T22:19:16.314Z,1567030756.314 [ThrusterServo](DEBUG): Initializing EZServoServo.
2019-08-28T22:19:16.321Z,1567030756.321 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2019-08-28T22:19:16.323Z,1567030756.323 [CommandLine](FAULT): Scheduling is paused
2019-08-28T22:19:16.323Z,1567030756.323 [CBIT](INFO): Critical error at 20190828T221915
2019-08-28T22:19:16.324Z,1567030756.324 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2019-08-28T22:19:16.345Z,1567030756.345 [Rowe_600](INFO): Data requested. STOPPED ==> START
2019-08-28T22:19:16.346Z,1567030756.346 [Rowe_600](INFO): Initializing
2019-08-28T22:19:16.365Z,1567030756.365 [Rowe_600](INFO): Powering up
2019-08-28T22:19:17.317Z,1567030757.317 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2019-08-28T22:19:17.317Z,1567030757.317 [RudderServo](FAULT): Rudder failed to initialize
2019-08-28T22:19:17.317Z,1567030757.317 [RudderServo] Communications Fault, FailCount= 1
2019-08-28T22:19:17.317Z,1567030757.317 [RudderServo](ERROR): Communications Fault
2019-08-28T22:19:17.428Z,1567030757.428 [CBIT](ERROR): Communications Fault in component: RudderServo
2019-08-28T22:19:17.602Z,1567030757.602 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-08-28T22:19:17.602Z,1567030757.602 [RudderServo](INFO): Powering down
2019-08-28T22:19:18.275Z,1567030758.275 [RudderServo](DEBUG): Initializing EZServoServo.
2019-08-28T22:19:18.394Z,1567030758.394 [RudderServo](DEBUG): Initializing RudderServo.
2019-08-28T22:19:18.398Z,1567030758.398 [CBIT](INFO): Clearing failed state for component RudderServo
2019-08-28T22:19:18.398Z,1567030758.398 [RudderServo] No Fault, FailCount= 1
2019-08-28T22:19:43.299Z,1567030783.299 [NAL9602](INFO): Powering up NAL9602
2019-08-28T22:19:54.202Z,1567030794.202 [NAL9602](INFO): NAL9602 initialized
2019-08-28T22:19:55.033Z,1567030795.033 [NAL9602](DEBUG): Fix Requested
2019-08-28T22:20:15.255Z,1567030815.255 [SBIT](IMPORTANT): Beginning Startup BIT
2019-08-28T22:20:15.259Z,1567030815.259 [CBIT](IMPORTANT): Beginning ground fault scan
2019-08-28T22:20:18.576Z,1567030818.576 [NAL9602](INFO): SBD MO Status=2, MOMSN=229, MT Status=2, MTMSN=0
2019-08-28T22:20:18.576Z,1567030818.576 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-08-28T22:20:26.335Z,1567030826.335 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.009235
CHAN A1 (24V): 0.005803
CHAN A2 (12V): -0.006324
CHAN A3 (5V): -0.002169
CHAN B0 (3.3V): 0.000291
CHAN B1 (3.15aV): 0.000766
CHAN B2 (3.15bV): -0.000647
CHAN B3 (GND): 0.002469
OPEN: 0.006847
Full Scale Calc: 4.765 mA, -1.589 mA
2019-08-28T22:20:35.624Z,1567030835.624 [NAL9602](INFO): SBD MO Status=2, MOMSN=229, MT Status=2, MTMSN=0
2019-08-28T22:20:35.624Z,1567030835.624 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-08-28T22:21:09.260Z,1567030869.260 [SBIT](IMPORTANT): SBIT PASSED
2019-08-28T22:21:09.305Z,1567030869.305 [CommandLine](IMPORTANT): got command configSet list
2019-08-28T22:21:09.305Z,1567030869.305 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2019-08-28T22:21:09.306Z,1567030869.306 [CommandLine](IMPORTANT): Micromodem.loadAtStartup=0 bool;

2019-08-28T22:21:09.306Z,1567030869.306 [CommandLine](IMPORTANT): VerticalControl.massDefault=10 millimeter;

2019-08-28T22:21:09.670Z,1567030869.670 [MissionManager](IMPORTANT): Started mission Startup
2019-08-28T22:21:09.670Z,1567030869.670 [Startup] Running Loop=1
2019-08-28T22:21:09.670Z,1567030869.670 [Startup](DEBUG): Aggregate::initialize Startup
2019-08-28T22:21:09.670Z,1567030869.670 [Startup:A.GoToSurface] Running Loop=1
2019-08-28T22:21:09.670Z,1567030869.670 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-08-28T22:21:09.671Z,1567030869.671 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-08-28T22:21:09.671Z,1567030869.671 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-08-28T22:21:09.672Z,1567030869.672 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-08-28T22:21:09.672Z,1567030869.672 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-08-28T22:21:09.672Z,1567030869.672 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-08-28T22:21:09.674Z,1567030869.674 [Startup:StartupSatComms] Running Loop=1
2019-08-28T22:21:09.674Z,1567030869.674 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2019-08-28T22:21:09.674Z,1567030869.674 [Startup:StartupSatComms:A] Running Loop=1
2019-08-28T22:21:10.082Z,1567030870.082 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2019-08-28T22:21:44.675Z,1567030904.675 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004873
2019-08-28T22:22:09.884Z,1567030929.884 [Startup:StartupSatComms:A](INFO): Timed out from 2019-08-28T22:21:09.7Z
2019-08-28T22:22:09.884Z,1567030929.884 [Startup:StartupSatComms:A] Stopped
2019-08-28T22:22:09.885Z,1567030929.885 [Startup:StartupSatComms:B] Running Loop=1
2019-08-28T22:22:10.286Z,1567030930.286 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-08-28T22:22:15.896Z,1567030935.896 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2019-08-28T22:22:15.896Z,1567030935.896 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-08-28T22:22:15.957Z,1567030935.957 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-08-28T22:22:16.318Z,1567030936.318 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-08-28T22:22:16.318Z,1567030936.318 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2019-08-28T22:22:22.100Z,1567030942.100 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190828T050649/Courier0543.lzma
2019-08-28T22:22:24.107Z,1567030944.107 [DataOverHttps](INFO): Moved sent file to Logs/20190828T050649/Courier0543.lzma.bak
2019-08-28T22:22:24.107Z,1567030944.107 [DataOverHttps](INFO): SBD MOMSN=11709815
2019-08-28T22:22:42.152Z,1567030962.152 [DataOverHttps](INFO): Sending 99 bytes from file Logs/20190828T221905/Courier0000.lzma
2019-08-28T22:22:44.158Z,1567030964.158 [DataOverHttps](INFO): Moved sent file to Logs/20190828T221905/Courier0000.lzma.bak
2019-08-28T22:22:44.158Z,1567030964.158 [DataOverHttps](INFO): SBD MOMSN=11709817
2019-08-28T22:23:04.352Z,1567030984.352 [DataOverHttps](INFO): Sending 141 bytes from file Logs/20190828T050649/Express0544.lzma
2019-08-28T22:23:06.359Z,1567030986.359 [DataOverHttps](INFO): Moved sent file to Logs/20190828T050649/Express0544.lzma.bak
2019-08-28T22:23:06.359Z,1567030986.359 [DataOverHttps](INFO): SBD MOMSN=11709822
2019-08-28T22:23:10.042Z,1567030990.042 [Startup:StartupSatComms:B](INFO): Timed out from 2019-08-28T22:22:09.9Z
2019-08-28T22:23:10.043Z,1567030990.043 [Startup:StartupSatComms:B] Stopped
2019-08-28T22:23:10.043Z,1567030990.043 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2019-08-28T22:23:10.043Z,1567030990.043 [Startup:StartupSatComms] Stopped
2019-08-28T22:23:10.043Z,1567030990.043 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2019-08-28T22:23:10.044Z,1567030990.044 [Startup](INFO): Completed Startup
2019-08-28T22:23:10.044Z,1567030990.044 [MissionManager](INFO): Startup is completed.
2019-08-28T22:23:10.044Z,1567030990.044 [MissionManager](INFO): Uninitializing Mission Startup
2019-08-28T22:23:10.044Z,1567030990.044 [Startup] Stopped
2019-08-28T22:23:10.044Z,1567030990.044 [Startup](DEBUG): Aggregate::uninitialize Startup
2019-08-28T22:23:10.044Z,1567030990.044 [Startup:A.GoToSurface] Stopped
2019-08-28T22:23:10.044Z,1567030990.044 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-08-28T22:23:10.446Z,1567030990.446 [MissionManager](IMPORTANT): Started mission Default
2019-08-28T22:23:10.447Z,1567030990.447 [Default] Running Loop=1
2019-08-28T22:23:10.447Z,1567030990.447 [Default](DEBUG): Aggregate::initialize Default
2019-08-28T22:23:10.447Z,1567030990.447 [Default:B.GoToSurface] Running Loop=1
2019-08-28T22:23:10.447Z,1567030990.447 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-08-28T22:23:10.447Z,1567030990.447 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-08-28T22:23:10.447Z,1567030990.447 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-08-28T22:23:10.448Z,1567030990.448 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-08-28T22:23:10.448Z,1567030990.448 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-08-28T22:23:10.448Z,1567030990.448 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-08-28T22:23:10.449Z,1567030990.449 [Default:A.Wait] Running Loop=1
2019-08-28T22:23:10.449Z,1567030990.449 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-08-28T22:23:23.786Z,1567031003.786 [Default:A.Wait](INFO): Done Waiting.
2019-08-28T22:23:23.786Z,1567031003.786 [Default:A.Wait] Stopped
2019-08-28T22:23:23.786Z,1567031003.786 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-08-28T22:23:24.170Z,1567031004.170 [Default:CheckIn] Running Loop=1
2019-08-28T22:23:24.170Z,1567031004.170 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-08-28T22:23:24.171Z,1567031004.171 [Default:CheckIn:Read_GPS] Running Loop=1
2019-08-28T22:23:24.579Z,1567031004.579 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2019-08-28T22:23:25.343Z,1567031005.343 [DataOverHttps](INFO): Sending 741 bytes from file Logs/20190828T221905/Express0001.lzma
2019-08-28T22:23:27.346Z,1567031007.346 [DataOverHttps](INFO): Moved sent file to Logs/20190828T221905/Express0001.lzma.bak
2019-08-28T22:23:27.346Z,1567031007.346 [DataOverHttps](INFO): SBD MOMSN=11709826
2019-08-28T22:24:24.374Z,1567031064.374 [BPC1](ERROR): BPC1B: No match for serial number 1717 in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2019-08-28T22:25:07.176Z,1567031107.176 [NAL9602](INFO): SBD MO Status=2, MOMSN=229, MT Status=2, MTMSN=0
2019-08-28T22:25:07.176Z,1567031107.176 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-08-28T22:25:07.570Z,1567031107.570 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-08-28T22:25:08.389Z,1567031108.389 [NAL9602](DEBUG): Fix Requested
2019-08-28T22:25:08.796Z,1567031108.796 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,222415.00,A,3648.16396,N,12147.28620,W,0.253,165.92,280819,,,A*74
2019-08-28T22:25:08.799Z,1567031108.799 [NAL9602](INFO): GPS fix at 20190828T222415: (36.802733, -121.788103)
2019-08-28T22:25:08.824Z,1567031108.824 [Default:CheckIn:Read_GPS] Stopped
2019-08-28T22:25:08.824Z,1567031108.824 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-08-28T22:25:09.243Z,1567031109.243 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-08-28T22:25:23.792Z,1567031123.792 [DataOverHttps](INFO): Sending 212 bytes from file Logs/20190828T221905/Courier0004.lzma
2019-08-28T22:25:25.798Z,1567031125.798 [DataOverHttps](INFO): Moved sent file to Logs/20190828T221905/Courier0004.lzma.bak
2019-08-28T22:25:25.799Z,1567031125.799 [DataOverHttps](INFO): SBD MOMSN=11709864
2019-08-28T22:25:40.418Z,1567031140.418 [NAL9602](INFO): Not Powering down - fast GPS
2019-08-28T22:26:09.861Z,1567031169.861 [DataOverHttps](INFO): Sending 310 bytes from file Logs/20190828T221905/Express0005.lzma
2019-08-28T22:26:11.866Z,1567031171.866 [DataOverHttps](INFO): Moved sent file to Logs/20190828T221905/Express0005.lzma.bak
2019-08-28T22:26:11.867Z,1567031171.867 [DataOverHttps](INFO): SBD MOMSN=11709876
2019-08-28T22:26:15.620Z,1567031175.620 [Default:CheckIn:Read_Iridium] Stopped
2019-08-28T22:26:15.620Z,1567031175.620 [Default:CheckIn:C.Wait] Running Loop=1
2019-08-28T22:26:15.620Z,1567031175.620 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-08-28T22:26:41.122Z,1567031201.122 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-08-28T22:26:47.532Z,1567031207.532 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2019-08-28T22:26:47.534Z,1567031207.534 [BPC1](INFO): Received data from all battery sticks.
2019-08-28T22:31:16.183Z,1567031476.183 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-08-28T22:31:16.183Z,1567031476.183 [Default:CheckIn:C.Wait] Stopped
2019-08-28T22:31:16.183Z,1567031476.183 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-08-28T22:31:16.183Z,1567031476.183 [Default:CheckIn:D] Running Loop=1
2019-08-28T22:31:16.585Z,1567031476.585 [Default:CheckIn:D] Stopped
2019-08-28T22:31:16.585Z,1567031476.585 [Default:CheckIn:E] Running Loop=1
2019-08-28T22:31:16.991Z,1567031476.991 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 8.102301 min 
2019-08-28T22:31:16.991Z,1567031476.991 [Default:CheckIn:E] Stopped
2019-08-28T22:31:16.992Z,1567031476.992 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-08-28T22:31:16.992Z,1567031476.992 [Default:CheckIn] Stopped
2019-08-28T22:31:16.992Z,1567031476.992 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-08-28T22:31:16.992Z,1567031476.992 [Default:CheckIn](INFO): Running loop #2
2019-08-28T22:31:16.992Z,1567031476.992 [Default:CheckIn] Running Loop=2
2019-08-28T22:31:16.992Z,1567031476.992 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-08-28T22:31:16.992Z,1567031476.992 [Default:CheckIn:Read_GPS] Running Loop=1
2019-08-28T22:31:18.605Z,1567031478.605 [NAL9602](DEBUG): Fix Requested
2019-08-28T22:31:18.988Z,1567031478.988 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,223026.00,A,3648.16082,N,12147.28207,W,0.117,132.10,280819,,,A*7D
2019-08-28T22:31:18.990Z,1567031478.990 [NAL9602](INFO): GPS fix at 20190828T223026: (36.802680, -121.788034)
2019-08-28T22:31:19.034Z,1567031479.034 [Default:CheckIn:Read_GPS] Stopped
2019-08-28T22:31:19.034Z,1567031479.034 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-08-28T22:31:27.885Z,1567031487.885 [DataOverHttps](INFO): Sending 221 bytes from file Logs/20190828T221905/Courier0007.lzma
2019-08-28T22:31:29.890Z,1567031489.890 [DataOverHttps](INFO): Moved sent file to Logs/20190828T221905/Courier0007.lzma.bak
2019-08-28T22:31:29.891Z,1567031489.891 [DataOverHttps](INFO): SBD MOMSN=11709884
2019-08-28T22:31:49.714Z,1567031509.714 [DataOverHttps](INFO): Sending 150 bytes from file Logs/20190828T221905/Express0008.lzma
2019-08-28T22:31:51.718Z,1567031511.718 [DataOverHttps](INFO): Moved sent file to Logs/20190828T221905/Express0008.lzma.bak
2019-08-28T22:31:51.719Z,1567031511.719 [DataOverHttps](INFO): SBD MOMSN=11709889
2019-08-28T22:31:55.392Z,1567031515.392 [Default:CheckIn:Read_Iridium] Stopped
2019-08-28T22:31:55.392Z,1567031515.392 [Default:CheckIn:C.Wait] Running Loop=1
2019-08-28T22:31:55.392Z,1567031515.392 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-08-28T22:33:51.709Z,1567031631.709 [NAL9602](INFO): SBD MO Status=2, MOMSN=229, MT Status=2, MTMSN=0
2019-08-28T22:33:51.709Z,1567031631.709 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-08-28T22:34:36.139Z,1567031676.139 [NAL9602](INFO): SBD MO Status=0, MOMSN=229, MT Status=0, MTMSN=0
2019-08-28T22:34:36.139Z,1567031676.139 [NAL9602](INFO): No messages in MT queue
2019-08-28T22:35:06.839Z,1567031706.839 [NAL9602](INFO): Not Powering down - fast GPS
2019-08-28T22:36:55.956Z,1567031815.956 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-08-28T22:36:55.956Z,1567031815.956 [Default:CheckIn:C.Wait] Stopped
2019-08-28T22:36:55.956Z,1567031815.956 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-08-28T22:36:55.956Z,1567031815.956 [Default:CheckIn:D] Running Loop=1
2019-08-28T22:36:56.360Z,1567031816.360 [Default:CheckIn:D] Stopped
2019-08-28T22:36:56.360Z,1567031816.360 [Default:CheckIn:E] Running Loop=1
2019-08-28T22:36:56.772Z,1567031816.772 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 13.765225 min 
2019-08-28T22:36:56.772Z,1567031816.772 [Default:CheckIn:E] Stopped
2019-08-28T22:36:56.772Z,1567031816.772 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-08-28T22:36:56.772Z,1567031816.772 [Default:CheckIn] Stopped
2019-08-28T22:36:56.772Z,1567031816.772 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-08-28T22:36:56.773Z,1567031816.773 [Default:CheckIn](INFO): Running loop #3
2019-08-28T22:36:56.773Z,1567031816.773 [Default:CheckIn] Running Loop=3
2019-08-28T22:36:56.773Z,1567031816.773 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-08-28T22:36:56.773Z,1567031816.773 [Default:CheckIn:Read_GPS] Running Loop=1
2019-08-28T22:36:58.361Z,1567031818.361 [NAL9602](DEBUG): Fix Requested
2019-08-28T22:36:58.752Z,1567031818.752 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,223606.00,A,3648.16054,N,12147.28890,W,0.389,132.10,280819,,,A*73
2019-08-28T22:36:58.754Z,1567031818.754 [NAL9602](INFO): GPS fix at 20190828T223606: (36.802676, -121.788148)
2019-08-28T22:36:58.784Z,1567031818.784 [Default:CheckIn:Read_GPS] Stopped
2019-08-28T22:36:58.784Z,1567031818.784 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-08-28T22:37:08.528Z,1567031828.528 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20190828T221905/Courier0010.lzma
2019-08-28T22:37:10.534Z,1567031830.534 [DataOverHttps](INFO): Moved sent file to Logs/20190828T221905/Courier0010.lzma.bak
2019-08-28T22:37:10.535Z,1567031830.535 [DataOverHttps](INFO): SBD MOMSN=11709910
2019-08-28T22:37:20.579Z,1567031840.579 [NAL9602](INFO): SBD MO Status=0, MOMSN=230, MT Status=0, MTMSN=0
2019-08-28T22:37:20.579Z,1567031840.579 [NAL9602](INFO): No messages in MT queue
2019-08-28T22:37:30.668Z,1567031850.668 [DataOverHttps](INFO): Sending 119 bytes from file Logs/20190828T221905/Express0011.lzma
2019-08-28T22:37:32.674Z,1567031852.674 [DataOverHttps](INFO): Moved sent file to Logs/20190828T221905/Express0011.lzma.bak
2019-08-28T22:37:32.675Z,1567031852.675 [DataOverHttps](INFO): SBD MOMSN=11709926
2019-08-28T22:37:36.344Z,1567031856.344 [Default:CheckIn:Read_Iridium] Stopped
2019-08-28T22:37:36.344Z,1567031856.344 [Default:CheckIn:C.Wait] Running Loop=1
2019-08-28T22:37:36.344Z,1567031856.344 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-08-28T22:37:51.270Z,1567031871.270 [NAL9602](INFO): Not Powering down - fast GPS
2019-08-28T22:42:36.928Z,1567032156.928 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-08-28T22:42:36.928Z,1567032156.928 [Default:CheckIn:C.Wait] Stopped
2019-08-28T22:42:36.928Z,1567032156.928 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-08-28T22:42:36.928Z,1567032156.928 [Default:CheckIn:D] Running Loop=1
2019-08-28T22:42:37.335Z,1567032157.335 [Default:CheckIn:D] Stopped
2019-08-28T22:42:37.335Z,1567032157.335 [Default:CheckIn:E] Running Loop=1
2019-08-28T22:42:37.743Z,1567032157.743 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 19.448145 min 
2019-08-28T22:42:37.743Z,1567032157.743 [Default:CheckIn:E] Stopped
2019-08-28T22:42:37.743Z,1567032157.743 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-08-28T22:42:37.743Z,1567032157.743 [Default:CheckIn] Stopped
2019-08-28T22:42:37.743Z,1567032157.743 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-08-28T22:42:37.744Z,1567032157.744 [Default:CheckIn](INFO): Running loop #4
2019-08-28T22:42:37.744Z,1567032157.744 [Default:CheckIn] Running Loop=4
2019-08-28T22:42:37.744Z,1567032157.744 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-08-28T22:42:37.744Z,1567032157.744 [Default:CheckIn:Read_GPS] Running Loop=1
2019-08-28T22:42:39.337Z,1567032159.337 [NAL9602](DEBUG): Fix Requested
2019-08-28T22:42:39.732Z,1567032159.732 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,224147.00,A,3648.16506,N,12147.28748,W,0.136,132.10,280819,,,A*78
2019-08-28T22:42:39.734Z,1567032159.734 [NAL9602](INFO): GPS fix at 20190828T224147: (36.802751, -121.788125)
2019-08-28T22:42:39.757Z,1567032159.757 [Default:CheckIn:Read_GPS] Stopped
2019-08-28T22:42:39.781Z,1567032159.781 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-08-28T22:42:49.596Z,1567032169.596 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20190828T221905/Courier0013.lzma
2019-08-28T22:42:51.602Z,1567032171.602 [DataOverHttps](INFO): Moved sent file to Logs/20190828T221905/Courier0013.lzma.bak
2019-08-28T22:42:51.603Z,1567032171.603 [DataOverHttps](INFO): SBD MOMSN=11709992
2019-08-28T22:43:11.240Z,1567032191.240 [DataOverHttps](INFO): Sending 119 bytes from file Logs/20190828T221905/Express0014.lzma
2019-08-28T22:43:13.246Z,1567032193.246 [DataOverHttps](INFO): Moved sent file to Logs/20190828T221905/Express0014.lzma.bak
2019-08-28T22:43:13.247Z,1567032193.247 [DataOverHttps](INFO): SBD MOMSN=11709996
2019-08-28T22:43:16.924Z,1567032196.924 [Default:CheckIn:Read_Iridium] Stopped
2019-08-28T22:43:16.924Z,1567032196.924 [Default:CheckIn:C.Wait] Running Loop=1
2019-08-28T22:43:16.925Z,1567032196.925 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-08-28T22:43:41.145Z,1567032221.145 [NAL9602](INFO): SBD MO Status=2, MOMSN=231, MT Status=2, MTMSN=0
2019-08-28T22:43:41.145Z,1567032221.145 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-08-28T22:44:01.343Z,1567032241.343 [NAL9602](INFO): SBD MO Status=2, MOMSN=231, MT Status=2, MTMSN=0
2019-08-28T22:44:01.344Z,1567032241.344 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-08-28T22:44:22.751Z,1567032262.751 [NAL9602](INFO): SBD MO Status=0, MOMSN=231, MT Status=0, MTMSN=0
2019-08-28T22:44:22.751Z,1567032262.751 [NAL9602](INFO): No messages in MT queue
2019-08-28T22:44:52.923Z,1567032292.923 [CommandLine](IMPORTANT): got command restart system
2019-08-28T22:44:53.451Z,1567032293.451 [NAL9602](INFO): Not Powering down - fast GPS
2019-08-28T22:44:54.993Z,1567032294.993 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2019-08-28T22:44:54.993Z,1567032294.993 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-08-28T22:44:55.033Z,1567032295.033 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2019-08-28T22:44:55.033Z,1567032295.033 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-08-28T22:44:55.034Z,1567032295.034 [CommandLine](INFO): Join timeout helper Thread ID is 4380
2019-08-28T22:44:55.034Z,1567032295.034 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2019-08-28T22:44:55.034Z,1567032295.034 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-08-28T22:44:55.035Z,1567032295.035 [NavChartDb](INFO): Join timeout helper Thread ID is 4381
2019-08-28T22:44:55.241Z,1567032295.241 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2019-08-28T22:44:55.241Z,1567032295.241 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-08-28T22:44:55.253Z,1567032295.253 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2019-08-28T22:44:55.253Z,1567032295.253 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-08-28T22:44:55.253Z,1567032295.253 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 4382
2019-08-28T22:44:55.261Z,1567032295.261 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2019-08-28T22:44:55.262Z,1567032295.262 [WetLabsBB2FL](INFO): Powering down
2019-08-28T22:44:55.262Z,1567032295.262 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-08-28T22:44:55.273Z,1567032295.273 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2019-08-28T22:44:55.273Z,1567032295.273 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2019-08-28T22:44:55.274Z,1567032295.274 [CTD_Seabird](INFO): Join timeout helper Thread ID is 4383
2019-08-28T22:44:56.185Z,1567032296.185 [CTD_Seabird](INFO): Powering down
2019-08-28T22:44:56.197Z,1567032296.197 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2019-08-28T22:44:56.197Z,1567032296.197 [CTD_Seabird](INFO): Powering down
2019-08-28T22:44:56.209Z,1567032296.209 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2019-08-28T22:44:56.225Z,1567032296.225 [ComponentRegistry](INFO): Shutting down Rowe_600 ThreadHandler
2019-08-28T22:44:56.225Z,1567032296.225 [Rowe_600 ThreadHandler](INFO): Thread cancelled.
2019-08-28T22:44:56.225Z,1567032296.225 [Rowe_600](INFO): Join timeout helper Thread ID is 4384
2019-08-28T22:44:56.362Z,1567032296.362 [Rowe_600 ThreadHandler](INFO): Uninitializing protected caller thread.
2019-08-28T22:44:56.363Z,1567032296.363 [Rowe_600](INFO): Powering down
2019-08-28T22:44:56.477Z,1567032296.477 [Rowe_600 ThreadHandler](INFO): Thread cancelled.
2019-08-28T22:44:56.494Z,1567032296.494 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2019-08-28T22:44:56.494Z,1567032296.494 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-08-28T22:44:56.494Z,1567032296.494 [Radio_Surface](INFO): Join timeout helper Thread ID is 4385
2019-08-28T22:44:56.809Z,1567032296.809 [Radio_Surface](INFO): Powering down
2019-08-28T22:44:56.810Z,1567032296.810 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2019-08-28T22:44:56.810Z,1567032296.810 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-08-28T22:44:56.826Z,1567032296.826 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2019-08-28T22:44:56.826Z,1567032296.826 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-08-28T22:44:56.826Z,1567032296.826 [DataOverHttps](INFO): Join timeout helper Thread ID is 4386
2019-08-28T22:44:57.525Z,1567032297.525 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2019-08-28T22:44:57.525Z,1567032297.525 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-08-28T22:44:57.542Z,1567032297.542 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2019-08-28T22:44:57.542Z,1567032297.542 [logger ThreadHandler](INFO): Thread cancelled.
2019-08-28T22:44:57.542Z,1567032297.542 [logger](INFO): Join timeout helper Thread ID is 4387
2019-08-28T22:44:57.553Z,1567032297.553 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2019-08-28T22:44:57.554Z,1567032297.554 [logger ThreadHandler](INFO): Thread cancelled.
2019-08-28T22:44:57.570Z,1567032297.570 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2019-08-28T22:44:57.570Z,1567032297.570 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-08-28T22:44:57.570Z,1567032297.570 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2019-08-28T22:44:57.570Z,1567032297.570 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-08-28T22:44:57.570Z,1567032297.570 [controlThread](INFO): Join timeout helper Thread ID is 4388
2019-08-28T22:44:57.877Z,1567032297.877 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2019-08-28T22:44:57.877Z,1567032297.877 [controlThread](DEBUG): Uninitializing ControlThread
2019-08-28T22:44:57.878Z,1567032297.878 [AHRS_M2](INFO): Powering down
2019-08-28T22:44:57.949Z,1567032297.949 [NAL9602](INFO): Powering down
2019-08-28T22:44:57.951Z,1567032297.951 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2019-08-28T22:44:57.952Z,1567032297.952 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2019-08-28T22:44:57.953Z,1567032297.953 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2019-08-28T22:44:57.953Z,1567032297.953 [MissionManager](INFO): Uninitializing Mission Default
2019-08-28T22:44:57.953Z,1567032297.953 [Default] Stopped
2019-08-28T22:44:57.954Z,1567032297.954 [Default](DEBUG): Aggregate::uninitialize Default
2019-08-28T22:44:57.954Z,1567032297.954 [Default:B.GoToSurface] Stopped
2019-08-28T22:44:57.954Z,1567032297.954 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-08-28T22:44:57.954Z,1567032297.954 [Default:CheckIn] Stopped
2019-08-28T22:44:57.954Z,1567032297.954 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-08-28T22:44:57.954Z,1567032297.954 [Default:CheckIn:C.Wait] Stopped
2019-08-28T22:44:57.954Z,1567032297.954 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-08-28T22:44:57.957Z,1567032297.957 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2019-08-28T22:44:57.957Z,1567032297.957 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2019-08-28T22:44:57.957Z,1567032297.957 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2019-08-28T22:44:57.958Z,1567032297.958 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2019-08-28T22:44:57.958Z,1567032297.958 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2019-08-28T22:44:57.958Z,1567032297.958 [BuoyancyServo](INFO): Powering down
2019-08-28T22:44:57.973Z,1567032297.973 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2019-08-28T22:44:57.973Z,1567032297.973 [ElevatorServo](INFO): Powering down
2019-08-28T22:44:57.974Z,1567032297.974 [MassServo](DEBUG): Uninitialize Mass Servo.
2019-08-28T22:44:57.974Z,1567032297.974 [MassServo](INFO): Powering down
2019-08-28T22:44:57.975Z,1567032297.975 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-08-28T22:44:57.975Z,1567032297.975 [RudderServo](INFO): Powering down
2019-08-28T22:44:57.976Z,1567032297.976 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2019-08-28T22:44:57.976Z,1567032297.976 [ThrusterServo](INFO): Powering down
2019-08-28T22:44:57.976Z,1567032297.976 [SBIT](DEBUG): Uninitialize SBIT Component.
2019-08-28T22:44:57.977Z,1567032297.977 [IBIT](DEBUG): Uninitialize IBIT Component.
2019-08-28T22:44:57.977Z,1567032297.977 [CBIT](DEBUG): Uninitialize CBIT Component.
2019-08-28T22:44:57.977Z,1567032297.977 [CBIT](DEBUG): Powering off loads.
2019-08-28T22:44:57.989Z,1567032297.989 [CBIT](DEBUG): Disabling WDT.
2019-08-28T22:44:58.001Z,1567032298.001 [CBIT](DEBUG): Opening all GF detection circuits.
2019-08-28T22:44:58.001Z,1567032298.001 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-08-28T22:44:58.084Z,1567032298.084 [Rowe_600 ThreadHandler](INFO): Thread cancelled.
2019-08-28T22:44:58.091Z,1567032298.091 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-08-28T22:44:58.096Z,1567032298.096 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-08-28T22:44:58.151Z,1567032298.151 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-08-28T22:44:58.153Z,1567032298.153 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2019-08-28T22:44:58.163Z,1567032298.163 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-08-28T22:44:58.233Z,1567032298.233 [logger ThreadHandler](INFO): Thread cancelled.