2019-05-16T18:58:40.075Z,1558033120.075 [Supervisor](DEBUG): Initializing supervisor.
2019-05-16T18:58:40.078Z,1558033120.078 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2019-05-16T18:58:40.078Z,1558033120.078 [SyncHandler](INFO): Protected caller Thread ID is 3128
2019-05-16T18:58:40.079Z,1558033120.079 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2019-05-16T18:58:40.080Z,1558033120.080 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2019-05-16T18:58:40.080Z,1558033120.080 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 3129
2019-05-16T18:58:40.082Z,1558033120.082 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2019-05-16T18:58:40.094Z,1558033120.094 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2019-05-16T18:58:40.095Z,1558033120.095 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2019-05-16T18:58:40.095Z,1558033120.095 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 3130
2019-05-16T18:58:40.096Z,1558033120.096 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2019-05-16T18:58:40.097Z,1558033120.097 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2019-05-16T18:58:40.098Z,1558033120.098 [logger ThreadHandler](INFO): Protected caller Thread ID is 3131
2019-05-16T18:58:40.100Z,1558033120.100 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2019-05-16T18:58:40.100Z,1558033120.100 [Supervisor](INFO): Looking for Config files in directory: Config/
2019-05-16T18:58:40.101Z,1558033120.101 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2019-05-16T18:58:40.198Z,1558033120.198 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2019-05-16T18:58:40.198Z,1558033120.198 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2019-05-16T18:58:40.401Z,1558033120.401 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2019-05-16T18:58:40.401Z,1558033120.401 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2019-05-16T18:58:40.539Z,1558033120.539 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2019-05-16T18:58:40.540Z,1558033120.540 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2019-05-16T18:58:41.085Z,1558033121.085 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2019-05-16T18:58:41.086Z,1558033121.086 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2019-05-16T18:58:41.546Z,1558033121.546 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2019-05-16T18:58:41.547Z,1558033121.547 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2019-05-16T18:58:42.016Z,1558033122.016 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2019-05-16T18:58:42.017Z,1558033122.017 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2019-05-16T18:58:42.325Z,1558033122.325 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2019-05-16T18:58:42.326Z,1558033122.326 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2019-05-16T18:58:42.738Z,1558033122.738 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2019-05-16T18:58:42.738Z,1558033122.738 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2019-05-16T18:58:43.138Z,1558033123.138 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2019-05-16T18:58:43.138Z,1558033123.138 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2019-05-16T18:58:43.290Z,1558033123.290 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2019-05-16T18:58:43.291Z,1558033123.291 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2019-05-16T18:58:43.397Z,1558033123.397 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2019-05-16T18:58:43.398Z,1558033123.398 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2019-05-16T18:58:43.480Z,1558033123.480 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2019-05-16T18:58:43.582Z,1558033123.582 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2019-05-16T18:58:43.583Z,1558033123.583 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2019-05-16T18:58:43.782Z,1558033123.782 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2019-05-16T18:58:43.782Z,1558033123.782 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2019-05-16T18:58:43.991Z,1558033123.991 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2019-05-16T18:58:43.992Z,1558033123.992 [Supervisor](INFO): Opening Config file at: Config/._workSite.cfg
2019-05-16T18:58:44.067Z,1558033124.067 [Config/._workSite](ERROR): Could not parse value: resource
2019-05-16T18:58:44.141Z,1558033124.141 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/
2019-05-16T18:58:44.142Z,1558033124.142 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg
2019-05-16T18:58:44.226Z,1558033124.226 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg
2019-05-16T18:58:44.452Z,1558033124.452 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2019-05-16T18:58:44.452Z,1558033124.452 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg
2019-05-16T18:58:44.549Z,1558033124.549 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg
2019-05-16T18:58:44.716Z,1558033124.716 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg
2019-05-16T18:58:44.959Z,1558033124.959 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg
2019-05-16T18:58:45.102Z,1558033125.102 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg
2019-05-16T18:58:45.232Z,1558033125.232 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg
2019-05-16T18:58:45.368Z,1558033125.368 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg
2019-05-16T18:58:45.721Z,1558033125.721 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg
2019-05-16T18:58:45.939Z,1558033125.939 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg
2019-05-16T18:58:46.045Z,1558033126.045 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/root/
2019-05-16T18:58:46.045Z,1558033126.045 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2019-05-16T18:58:46.054Z,1558033126.054 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2019-05-16T18:58:46.148Z,1558033126.148 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2019-05-16T18:58:46.149Z,1558033126.149 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2019-05-16T18:58:46.252Z,1558033126.252 [BuoyancyServo] Loaded
2019-05-16T18:58:46.252Z,1558033126.252 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2019-05-16T18:58:46.267Z,1558033126.267 [ElevatorServo] Loaded
2019-05-16T18:58:46.267Z,1558033126.267 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2019-05-16T18:58:46.281Z,1558033126.281 [MassServo] Loaded
2019-05-16T18:58:46.282Z,1558033126.282 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2019-05-16T18:58:46.296Z,1558033126.296 [RudderServo] Loaded
2019-05-16T18:58:46.297Z,1558033126.297 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2019-05-16T18:58:46.310Z,1558033126.310 [ThrusterServo] Loaded
2019-05-16T18:58:46.311Z,1558033126.311 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2019-05-16T18:58:46.311Z,1558033126.311 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2019-05-16T18:58:46.312Z,1558033126.312 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2019-05-16T18:58:46.439Z,1558033126.439 [SBIT](DEBUG): Construct Startup Built In Test.
2019-05-16T18:58:46.467Z,1558033126.467 [SBIT] Loaded
2019-05-16T18:58:46.468Z,1558033126.468 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2019-05-16T18:58:46.468Z,1558033126.468 [IBIT](DEBUG): Construct Initiated Built In Test.
2019-05-16T18:58:46.495Z,1558033126.495 [IBIT] Loaded
2019-05-16T18:58:46.495Z,1558033126.495 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2019-05-16T18:58:46.498Z,1558033126.498 [CBIT](DEBUG): Construct Continuous Built In Test.
2019-05-16T18:58:46.874Z,1558033126.874 [CBIT] Loaded
2019-05-16T18:58:46.874Z,1558033126.874 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2019-05-16T18:58:46.874Z,1558033126.874 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2019-05-16T18:58:46.875Z,1558033126.875 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2019-05-16T18:58:47.063Z,1558033127.063 [ESPComponent] Loaded
2019-05-16T18:58:47.063Z,1558033127.063 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2019-05-16T18:58:47.076Z,1558033127.076 [PAR_Licor] Loaded
2019-05-16T18:58:47.077Z,1558033127.077 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2019-05-16T18:58:47.123Z,1558033127.123 [WetLabsBB2FL] Loaded
2019-05-16T18:58:47.123Z,1558033127.123 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2019-05-16T18:58:47.125Z,1558033127.125 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 406624E0
2019-05-16T18:58:47.125Z,1558033127.125 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 3214
2019-05-16T18:58:47.126Z,1558033127.126 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2019-05-16T18:58:47.126Z,1558033127.126 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2019-05-16T18:58:47.166Z,1558033127.166 [DepthRateCalculator] Loaded
2019-05-16T18:58:47.166Z,1558033127.166 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2019-05-16T18:58:47.171Z,1558033127.171 [PitchRateCalculator] Loaded
2019-05-16T18:58:47.172Z,1558033127.172 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2019-05-16T18:58:47.187Z,1558033127.187 [SpeedCalculator] Loaded
2019-05-16T18:58:47.187Z,1558033127.187 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2019-05-16T18:58:47.208Z,1558033127.208 [TempGradientCalculator] Loaded
2019-05-16T18:58:47.208Z,1558033127.208 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2019-05-16T18:58:47.214Z,1558033127.214 [YawRateCalculator] Loaded
2019-05-16T18:58:47.214Z,1558033127.214 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2019-05-16T18:58:47.246Z,1558033127.246 [ElevatorOffsetCalculator] Loaded
2019-05-16T18:58:47.246Z,1558033127.246 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2019-05-16T18:58:47.247Z,1558033127.247 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2019-05-16T18:58:47.247Z,1558033127.247 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2019-05-16T18:58:47.273Z,1558033127.273 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2019-05-16T18:58:47.274Z,1558033127.274 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2019-05-16T18:58:47.374Z,1558033127.374 [DeadReckonUsingMultipleVelocitySources] Loaded
2019-05-16T18:58:47.374Z,1558033127.374 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2019-05-16T18:58:47.395Z,1558033127.395 [NavChart] Loaded
2019-05-16T18:58:47.395Z,1558033127.395 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2019-05-16T18:58:47.399Z,1558033127.399 [UniversalFixResidualReporter] Loaded
2019-05-16T18:58:47.399Z,1558033127.399 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2019-05-16T18:58:47.399Z,1558033127.399 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2019-05-16T18:58:47.400Z,1558033127.400 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2019-05-16T18:58:47.738Z,1558033127.738 [AHRS_M2] Loaded
2019-05-16T18:58:47.738Z,1558033127.738 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2019-05-16T18:58:47.815Z,1558033127.815 [DataOverHttps] Loaded
2019-05-16T18:58:47.815Z,1558033127.815 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2019-05-16T18:58:47.816Z,1558033127.816 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4093A4E0
2019-05-16T18:58:47.816Z,1558033127.816 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 3215
2019-05-16T18:58:47.829Z,1558033127.829 [Depth_Keller] Loaded
2019-05-16T18:58:47.830Z,1558033127.830 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2019-05-16T18:58:47.955Z,1558033127.955 [DVL_micro] Loaded
2019-05-16T18:58:47.956Z,1558033127.956 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread.
2019-05-16T18:58:48.043Z,1558033128.043 [NAL9602] Loaded
2019-05-16T18:58:48.043Z,1558033128.043 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2019-05-16T18:58:48.048Z,1558033128.048 [Onboard] Loaded
2019-05-16T18:58:48.049Z,1558033128.049 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2019-05-16T18:58:48.052Z,1558033128.052 [Radio_Surface] Loaded
2019-05-16T18:58:48.052Z,1558033128.052 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2019-05-16T18:58:48.053Z,1558033128.053 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4096A4E0
2019-05-16T18:58:48.054Z,1558033128.054 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 3216
2019-05-16T18:58:48.181Z,1558033128.181 [DAT] Loaded
2019-05-16T18:58:48.181Z,1558033128.181 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread.
2019-05-16T18:58:49.423Z,1558033129.423 [BPC1] Loaded
2019-05-16T18:58:49.423Z,1558033129.423 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2019-05-16T18:58:49.424Z,1558033129.424 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2019-05-16T18:58:49.424Z,1558033129.424 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2019-05-16T18:58:49.492Z,1558033129.492 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2019-05-16T18:58:49.492Z,1558033129.492 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2019-05-16T18:58:49.556Z,1558033129.556 [VerticalControl](DEBUG): Construct VerticalControl.
2019-05-16T18:58:49.638Z,1558033129.638 [VerticalControl] Loaded
2019-05-16T18:58:49.638Z,1558033129.638 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2019-05-16T18:58:49.639Z,1558033129.639 [HorizontalControl](DEBUG): Construct HorizontalControl.
2019-05-16T18:58:49.694Z,1558033129.694 [HorizontalControl] Loaded
2019-05-16T18:58:49.694Z,1558033129.694 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2019-05-16T18:58:49.695Z,1558033129.695 [SpeedControl](DEBUG): Construct SpeedControl.
2019-05-16T18:58:49.697Z,1558033129.697 [SpeedControl] Loaded
2019-05-16T18:58:49.697Z,1558033129.697 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2019-05-16T18:58:49.698Z,1558033129.698 [LoopControl](DEBUG): Construct LoopControl.
2019-05-16T18:58:49.698Z,1558033129.698 [LoopControl] Loaded
2019-05-16T18:58:49.699Z,1558033129.699 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2019-05-16T18:58:49.699Z,1558033129.699 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2019-05-16T18:58:49.700Z,1558033129.700 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2019-05-16T18:58:49.712Z,1558033129.712 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2019-05-16T18:58:49.713Z,1558033129.713 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2019-05-16T18:58:50.141Z,1558033130.141 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2019-05-16T18:58:50.152Z,1558033130.152 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2019-05-16T18:58:50.156Z,1558033130.156 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2019-05-16T18:58:50.162Z,1558033130.162 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2019-05-16T18:58:50.163Z,1558033130.163 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40AA54E0
2019-05-16T18:58:50.164Z,1558033130.164 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 3217
2019-05-16T18:58:50.307Z,1558033130.307 [Supervisor](INFO): Main Thread ID is 3127
2019-05-16T18:58:50.307Z,1558033130.307 [Supervisor](DEBUG): Running supervisor.
2019-05-16T18:58:50.308Z,1558033130.308 [CommandLine ThreadHandler](INFO): Handler Thread ID is 3218
2019-05-16T18:58:50.310Z,1558033130.310 [controlThread ThreadHandler](INFO): Handler Thread ID is 3219
2019-05-16T18:58:50.311Z,1558033130.311 [controlThread](DEBUG): Initializing ControlThread
2019-05-16T18:58:50.312Z,1558033130.312 [SBIT](INFO): Initialize SBIT Component.
2019-05-16T18:58:50.312Z,1558033130.312 [SBIT](IMPORTANT): git: 2019-05-01-16-gabf2db2
2019-05-16T18:58:50.313Z,1558033130.313 [SBIT](INFO): git hash: abf2db22d373819956bb5fd2f1aa4151f065a92d
2019-05-16T18:58:50.313Z,1558033130.313 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2019-05-16T18:58:50.314Z,1558033130.314 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
Kernel Reported: #1 PREEMPT Thu Feb 21 11:17:40 PST 2019
2019-05-16T18:58:50.316Z,1558033130.316 [SBIT](INFO): Beginning SBIT in 24.000000 seconds.
2019-05-16T18:58:50.316Z,1558033130.316 [IBIT](INFO): Initialize IBIT Component.
2019-05-16T18:58:50.317Z,1558033130.317 [CBIT](DEBUG): Initialize CBIT Component.
2019-05-16T18:58:50.318Z,1558033130.318 [logger ThreadHandler](INFO): Handler Thread ID is 3220
2019-05-16T18:58:50.329Z,1558033130.329 [CBIT](DEBUG): Initialized mux pins.
2019-05-16T18:58:50.329Z,1558033130.329 [CBIT](DEBUG): Initializing the watchdog timer.
2019-05-16T18:58:50.337Z,1558033130.337 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 3221
2019-05-16T18:58:50.338Z,1558033130.338 [WetLabsBB2FL](INFO): Powering down
2019-05-16T18:58:50.353Z,1558033130.353 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2019-05-16T18:58:50.353Z,1558033130.353 [CBIT](DEBUG): Initializing heartbeat.
2019-05-16T18:58:50.369Z,1558033130.369 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 3222
2019-05-16T18:58:50.370Z,1558033130.370 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2019-05-16T18:58:50.381Z,1558033130.381 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 3223
2019-05-16T18:58:50.401Z,1558033130.401 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 3224
2019-05-16T18:58:50.404Z,1558033130.404 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2019-05-16T18:58:50.405Z,1558033130.405 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2019-05-16T18:58:50.405Z,1558033130.405 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2019-05-16T18:58:50.405Z,1558033130.405 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2019-05-16T18:58:50.405Z,1558033130.405 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2019-05-16T18:58:50.405Z,1558033130.405 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2019-05-16T18:58:50.406Z,1558033130.406 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2019-05-16T18:58:50.406Z,1558033130.406 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2019-05-16T18:58:50.406Z,1558033130.406 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2019-05-16T18:58:50.406Z,1558033130.406 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2019-05-16T18:58:50.406Z,1558033130.406 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2019-05-16T18:58:50.407Z,1558033130.407 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2019-05-16T18:58:50.407Z,1558033130.407 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2019-05-16T18:58:50.407Z,1558033130.407 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2019-05-16T18:58:50.407Z,1558033130.407 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2019-05-16T18:58:50.407Z,1558033130.407 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2019-05-16T18:58:50.425Z,1558033130.425 [CBIT](DEBUG): Deactivating GF circuits.
2019-05-16T18:58:50.425Z,1558033130.425 [CBIT](DEBUG): Deactivating emergency mode.
2019-05-16T18:58:50.461Z,1558033130.461 [CBIT](DEBUG): Backplane powered.
2019-05-16T18:58:50.465Z,1558033130.465 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2019-05-16T18:58:50.465Z,1558033130.465 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2019-05-16T18:58:50.466Z,1558033130.466 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2019-05-16T18:58:50.466Z,1558033130.466 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2019-05-16T18:58:50.467Z,1558033130.467 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2019-05-16T18:58:50.467Z,1558033130.467 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2019-05-16T18:58:50.468Z,1558033130.468 [NavChart](DEBUG): Initialize NavChart Navigation.
2019-05-16T18:58:50.468Z,1558033130.468 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2019-05-16T18:58:50.478Z,1558033130.478 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2019-05-16T18:58:50.480Z,1558033130.480 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2019-05-16T18:58:50.481Z,1558033130.481 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2019-05-16T18:58:50.481Z,1558033130.481 [LoopControl](DEBUG): Initialize LoopControlComponent.
2019-05-16T18:58:50.482Z,1558033130.482 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2019-05-16T18:58:50.508Z,1558033130.508 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2019-05-16T18:58:50.547Z,1558033130.547 [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-05-16T18:58:50.548Z,1558033130.548 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2019-05-16T18:58:50.615Z,1558033130.615 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2019-05-16T18:58:50.637Z,1558033130.637 [Default:A.Wait](DEBUG): Construct Wait.
2019-05-16T18:58:50.638Z,1558033130.638 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2019-05-16T18:58:50.669Z,1558033130.669 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2019-05-16T18:58:50.671Z,1558033130.671 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2019-05-16T18:58:50.693Z,1558033130.693 [Default:E.Execute](DEBUG): Construct Execute.
2019-05-16T18:58:50.696Z,1558033130.696 [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-05-16T18:58:50.721Z,1558033130.721 [controlThread](DEBUG): Component order: CycleStarter,ESPComponent,PAR_Licor,AHRS_M2,Depth_Keller,DVL_micro,NAL9602,Onboard,DAT,BPC1,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,
2019-05-16T18:58:50.733Z,1558033130.733 [ESPComponent](INFO): powering down ESP
2019-05-16T18:58:50.785Z,1558033130.785 [Radio_Surface](INFO): Powering up
2019-05-16T18:58:51.058Z,1558033131.058 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2019-05-16T18:58:51.098Z,1558033131.098 [Depth_Keller](ERROR): Pressure reading out of range: 1895.684326 decibar
2019-05-16T18:58:51.104Z,1558033131.104 [DVL_micro](INFO): Initializing
2019-05-16T18:58:51.147Z,1558033131.147 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2
2019-05-16T18:58:51.147Z,1558033131.147 [DAT](INFO): Powering up
2019-05-16T18:58:51.147Z,1558033131.147 [DAT](DEBUG): Initializing DAT.
2019-05-16T18:58:51.217Z,1558033131.217 [DepthRateCalculator](ERROR): Depth measurement is not active
2019-05-16T18:58:51.225Z,1558033131.225 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2
2019-05-16T18:58:51.273Z,1558033131.273 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2019-05-16T18:58:51.281Z,1558033131.281 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2019-05-16T18:58:51.282Z,1558033131.282 [ElevatorServo](DEBUG): Initializing EZServoServo.
2019-05-16T18:58:51.293Z,1558033131.293 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2019-05-16T18:58:51.294Z,1558033131.294 [MassServo](DEBUG): Initializing EZServoServo.
2019-05-16T18:58:51.305Z,1558033131.305 [MassServo](DEBUG): Initializing MassServo.
2019-05-16T18:58:51.306Z,1558033131.306 [RudderServo](DEBUG): Initializing EZServoServo.
2019-05-16T18:58:51.317Z,1558033131.317 [RudderServo](DEBUG): Initializing RudderServo.
2019-05-16T18:58:51.318Z,1558033131.318 [ThrusterServo](DEBUG): Initializing EZServoServo.
2019-05-16T18:58:51.329Z,1558033131.329 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2019-05-16T18:58:54.313Z,1558033134.313 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout
2019-05-16T18:58:54.725Z,1558033134.725 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout
2019-05-16T18:58:55.446Z,1558033135.446 [DVL_micro](ERROR): checksum mismatch: reported67 , calculated:71
2019-05-16T18:58:55.446Z,1558033135.446 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 1 1 1 1 9.9 9.1 11.1 9.1 6.3 -30.3 -12.9 -0.4 33 81 -87 -77 1 1 1 1 25.6 -39 1 -13.0 -46.3 6.2 1 160 210 -13 2 264 21 -13 2 -18.85 -6.28 311.9 9.1 18.2 0.005 35.0 1489 67
2019-05-16T18:58:56.349Z,1558033136.349 [AHRS_M2](ERROR): Subscribe Pitch UART error: serial timeout
2019-05-16T18:58:57.521Z,1558033137.521 [AHRS_M2](ERROR): Subscribe Yaw UART error: serial timeout
2019-05-16T18:58:57.929Z,1558033137.929 [AHRS_M2](ERROR): Subscribe Yaw UART error: serial timeout
2019-05-16T18:59:03.618Z,1558033143.618 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004362
2019-05-16T18:59:14.859Z,1558033154.859 [SBIT](IMPORTANT): Beginning Startup BIT
2019-05-16T18:59:14.871Z,1558033154.871 [CBIT](IMPORTANT): Beginning ground fault scan
2019-05-16T18:59:18.296Z,1558033158.296 [NAL9602](INFO): Powering up NAL9602
2019-05-16T18:59:26.045Z,1558033166.045 [CBIT](IMPORTANT): Low side ground fault detected
mA:
CHAN A0 (Batt): 0.844579
CHAN A1 (24V): 0.777327
CHAN A2 (12V): 0.881374
CHAN A3 (5V): 0.344834
CHAN B0 (3.3V): 0.175484
CHAN B1 (3.15aV): 0.219697
CHAN B2 (3.15bV): 0.228396
CHAN B3 (GND): -0.245100
OPEN: 0.014311
Full Scale Calc: 4.765 mA, -1.589 mA
2019-05-16T18:59:29.188Z,1558033169.188 [NAL9602](INFO): NAL9602 initialized
2019-05-16T18:59:30.009Z,1558033170.009 [NAL9602](DEBUG): Fix Requested
2019-05-16T18:59:35.879Z,1558033175.879 [CommandLine](IMPORTANT): got command failComponent
2019-05-16T18:59:35.879Z,1558033175.879 [CommandLine](IMPORTANT): Failed components:
2019-05-16T18:59:35.879Z,1558033175.879 [CommandLine](IMPORTANT): No failed Components.
2019-05-16T18:59:49.315Z,1558033189.315 [CommandLine](IMPORTANT): got command maintain control SpeedControl.propOmegaAction 0.000000 revolution_per_minute
2019-05-16T18:59:49.316Z,1558033189.316 [ComponentRegistry](DEBUG): SyncComponent "Maintain_SpeedControl.propOmegaAction" handled in the control thread.
2019-05-16T18:59:49.595Z,1558033189.595 [controlThread](DEBUG): Component order: CycleStarter,ESPComponent,PAR_Licor,AHRS_M2,Depth_Keller,DVL_micro,NAL9602,Onboard,DAT,BPC1,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,Maintain_SpeedControl.propOmegaAction,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2019-05-16T18:59:51.174Z,1558033191.174 [DAT](FAULT): failed to initialize; deviceResponse_ loaded: , available: Lowpower
D
2019-05-16T18:59:51.174Z,1558033191.174 [DAT] Communications Fault, FailCount= 1
2019-05-16T18:59:51.174Z,1558033191.174 [DAT](ERROR): Communications Fault
2019-05-16T18:59:51.247Z,1558033191.247 [CBIT](ERROR): Communications Fault in component: DAT
2019-05-16T18:59:51.589Z,1558033191.589 [DAT](INFO): Powering down
2019-05-16T18:59:52.473Z,1558033192.473 [CBIT](INFO): Clearing failed state for component DAT
2019-05-16T18:59:52.473Z,1558033192.473 [DAT] No Fault, FailCount= 1
2019-05-16T18:59:54.863Z,1558033194.863 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2
2019-05-16T18:59:54.863Z,1558033194.863 [DAT](INFO): Powering up
2019-05-16T18:59:54.863Z,1558033194.863 [DAT](DEBUG): Initializing DAT.
2019-05-16T18:59:54.930Z,1558033194.930 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2
2019-05-16T19:00:08.710Z,1558033208.710 [SBIT](IMPORTANT): SBIT PASSED
2019-05-16T19:00:08.774Z,1558033208.774 [CommandLine](IMPORTANT): got command configSet list
2019-05-16T19:00:08.774Z,1558033208.774 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2019-05-16T19:00:08.776Z,1558033208.776 [CommandLine](IMPORTANT): Aanderaa_O2.loadAtStartup=0 bool;

2019-05-16T19:00:08.776Z,1558033208.776 [CommandLine](IMPORTANT): AcousticModem_Benthos_ATM900.loadAtStartup=0 bool;

2019-05-16T19:00:08.776Z,1558033208.776 [CommandLine](IMPORTANT): BR_Ping1D.verbosity=1 count;

2019-05-16T19:00:08.776Z,1558033208.776 [CommandLine](IMPORTANT): CTD_Seabird.loadAtStartup=0 bool;

2019-05-16T19:00:08.778Z,1558033208.778 [CommandLine](IMPORTANT): DropWeight.loadAtStartup=0 bool;

2019-05-16T19:00:08.778Z,1558033208.778 [CommandLine](IMPORTANT): PAR_Licor.adcCal=8.765e-06 microampere_per_count;

2019-05-16T19:00:08.778Z,1558033208.778 [CommandLine](IMPORTANT): PAR_Licor.darkCount=0 count;

2019-05-16T19:00:08.779Z,1558033208.779 [CommandLine](IMPORTANT): PAR_Licor.multiplier=190.3 micromole_per_second_per_square_meter_per_microampere;

2019-05-16T19:00:08.779Z,1558033208.779 [CommandLine](IMPORTANT): PNI_TCM.loadAtStartup=0 bool;

2019-05-16T19:00:08.779Z,1558033208.779 [CommandLine](IMPORTANT): Rowe_600LCM.loadAtStartup=0 bool;

2019-05-16T19:00:09.075Z,1558033209.075 [MissionManager](IMPORTANT): Started mission Startup
2019-05-16T19:00:09.075Z,1558033209.075 [Startup] Running Loop=1
2019-05-16T19:00:09.075Z,1558033209.075 [Startup](DEBUG): Aggregate::initialize Startup
2019-05-16T19:00:09.076Z,1558033209.076 [Startup:A.GoToSurface] Running Loop=1
2019-05-16T19:00:09.076Z,1558033209.076 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-05-16T19:00:09.076Z,1558033209.076 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-05-16T19:00:09.077Z,1558033209.077 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-05-16T19:00:09.078Z,1558033209.078 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-05-16T19:00:09.078Z,1558033209.078 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-05-16T19:00:09.079Z,1558033209.079 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-05-16T19:00:09.081Z,1558033209.081 [Startup:StartupSatComms] Running Loop=1
2019-05-16T19:00:09.081Z,1558033209.081 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2019-05-16T19:00:09.081Z,1558033209.081 [Startup:StartupSatComms:A] Running Loop=1
2019-05-16T19:00:09.489Z,1558033209.489 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2019-05-16T19:00:12.705Z,1558033212.705 [NAL9602](INFO): SBD MO Status=2, MOMSN=25310, MT Status=2, MTMSN=0
2019-05-16T19:00:12.705Z,1558033212.705 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-05-16T19:00:55.122Z,1558033255.122 [DAT](FAULT): failed to initialize; deviceResponse_ loaded: , available: 
2019-05-16T19:00:55.122Z,1558033255.122 [DAT] Communications Fault, FailCount= 2
2019-05-16T19:00:55.122Z,1558033255.122 [DAT](ERROR): Communications Fault
2019-05-16T19:00:55.196Z,1558033255.196 [CBIT](ERROR): Communications Fault in component: DAT
2019-05-16T19:00:55.540Z,1558033255.540 [DAT](INFO): Powering down
2019-05-16T19:00:56.433Z,1558033256.433 [CBIT](INFO): Clearing failed state for component DAT
2019-05-16T19:00:56.433Z,1558033256.433 [DAT] No Fault, FailCount= 2
2019-05-16T19:00:58.767Z,1558033258.767 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2
2019-05-16T19:00:58.767Z,1558033258.767 [DAT](INFO): Powering up
2019-05-16T19:00:58.768Z,1558033258.768 [DAT](DEBUG): Initializing DAT.
2019-05-16T19:00:58.786Z,1558033258.786 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2
2019-05-16T19:01:09.303Z,1558033269.303 [Startup:StartupSatComms:A](INFO): Timed out from 2019-05-16T19:00:09.1Z
2019-05-16T19:01:09.303Z,1558033269.303 [Startup:StartupSatComms:A] Stopped
2019-05-16T19:01:09.303Z,1558033269.303 [Startup:StartupSatComms:B] Running Loop=1
2019-05-16T19:01:09.679Z,1558033269.679 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-05-16T19:01:16.864Z,1558033276.864 [DataOverHttps](INFO): Sending 102 bytes from file Logs/20190516T185012/Courier0004.lzma
2019-05-16T19:01:17.670Z,1558033277.670 [DataOverHttps](INFO): Moved sent file to Logs/20190516T185012/Courier0004.lzma.bak
2019-05-16T19:01:17.671Z,1558033277.671 [DataOverHttps](INFO): SBD MOMSN=11082815
2019-05-16T19:01:35.738Z,1558033295.738 [DataOverHttps](INFO): Sending 912 bytes from file Logs/20190516T185012/Express0001.lzma
2019-05-16T19:01:36.542Z,1558033296.542 [DataOverHttps](INFO): Moved sent file to Logs/20190516T185012/Express0001.lzma.bak
2019-05-16T19:01:36.542Z,1558033296.542 [DataOverHttps](INFO): SBD MOMSN=11082819
2019-05-16T19:01:41.566Z,1558033301.566 [CommandLine](IMPORTANT): got command failComponent
2019-05-16T19:01:41.566Z,1558033301.566 [CommandLine](IMPORTANT): Failed components:
2019-05-16T19:01:41.566Z,1558033301.566 [CommandLine](IMPORTANT): No failed Components.
2019-05-16T19:01:50.548Z,1558033310.548 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2019-05-16T19:01:50.548Z,1558033310.548 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-05-16T19:01:50.574Z,1558033310.574 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-05-16T19:01:50.964Z,1558033310.964 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-05-16T19:01:50.964Z,1558033310.964 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2019-05-16T19:01:59.007Z,1558033319.007 [DAT](FAULT): failed to initialize; deviceResponse_ loaded: , available: 
2019-05-16T19:01:59.007Z,1558033319.007 [DAT] Communications Fault, FailCount= 3
2019-05-16T19:01:59.007Z,1558033319.007 [DAT](ERROR): Communications Fault
2019-05-16T19:01:59.043Z,1558033319.043 [CBIT](ERROR): Communications Fault in component: DAT
2019-05-16T19:01:59.439Z,1558033319.439 [DAT](INFO): Powering down
2019-05-16T19:02:00.254Z,1558033320.254 [CBIT](INFO): Clearing failed state for component DAT
2019-05-16T19:02:00.254Z,1558033320.254 [DAT] No Fault, FailCount= 3
2019-05-16T19:02:00.549Z,1558033320.549 [DataOverHttps](INFO): Sending 483 bytes from file Logs/20190516T185012/Express0005.lzma
2019-05-16T19:02:01.354Z,1558033321.354 [DataOverHttps](INFO): Moved sent file to Logs/20190516T185012/Express0005.lzma.bak
2019-05-16T19:02:01.354Z,1558033321.354 [DataOverHttps](INFO): SBD MOMSN=11082848
2019-05-16T19:02:02.648Z,1558033322.648 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2
2019-05-16T19:02:02.648Z,1558033322.648 [DAT](INFO): Powering up
2019-05-16T19:02:02.648Z,1558033322.648 [DAT](DEBUG): Initializing DAT.
2019-05-16T19:02:02.685Z,1558033322.685 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2
2019-05-16T19:02:09.499Z,1558033329.499 [Startup:StartupSatComms:B](INFO): Timed out from 2019-05-16T19:01:09.3Z
2019-05-16T19:02:09.499Z,1558033329.499 [Startup:StartupSatComms:B] Stopped
2019-05-16T19:02:09.499Z,1558033329.499 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2019-05-16T19:02:09.499Z,1558033329.499 [Startup:StartupSatComms] Stopped
2019-05-16T19:02:09.499Z,1558033329.499 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2019-05-16T19:02:09.500Z,1558033329.500 [Startup](INFO): Completed Startup
2019-05-16T19:02:09.500Z,1558033329.500 [MissionManager](INFO): Startup is completed.
2019-05-16T19:02:09.500Z,1558033329.500 [MissionManager](INFO): Uninitializing Mission Startup
2019-05-16T19:02:09.500Z,1558033329.500 [Startup] Stopped
2019-05-16T19:02:09.505Z,1558033329.505 [Startup](DEBUG): Aggregate::uninitialize Startup
2019-05-16T19:02:09.505Z,1558033329.505 [Startup:A.GoToSurface] Stopped
2019-05-16T19:02:09.505Z,1558033329.505 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-05-16T19:02:10.078Z,1558033330.078 [MissionManager](IMPORTANT): Started mission Default
2019-05-16T19:02:10.078Z,1558033330.078 [Default] Running Loop=1
2019-05-16T19:02:10.078Z,1558033330.078 [Default](DEBUG): Aggregate::initialize Default
2019-05-16T19:02:10.078Z,1558033330.078 [Default:B.GoToSurface] Running Loop=1
2019-05-16T19:02:10.078Z,1558033330.078 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-05-16T19:02:10.078Z,1558033330.078 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-05-16T19:02:10.079Z,1558033330.079 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-05-16T19:02:10.079Z,1558033330.079 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-05-16T19:02:10.079Z,1558033330.079 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-05-16T19:02:10.080Z,1558033330.080 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-05-16T19:02:10.080Z,1558033330.080 [Default:A.Wait] Running Loop=1
2019-05-16T19:02:10.080Z,1558033330.080 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-05-16T19:02:12.701Z,1558033332.701 [AHRS_M2](FAULT): Failed to acquire valid data within timeout.
2019-05-16T19:02:12.701Z,1558033332.701 [AHRS_M2] Data Fault, FailCount= 1
2019-05-16T19:02:12.701Z,1558033332.701 [AHRS_M2](ERROR): Data Fault
2019-05-16T19:02:12.743Z,1558033332.743 [CBIT](ERROR): Data Fault in component: AHRS_M2
2019-05-16T19:02:13.093Z,1558033333.093 [AHRS_M2](INFO): Powering down
2019-05-16T19:02:13.977Z,1558033333.977 [CBIT](INFO): Clearing failed state for component AHRS_M2
2019-05-16T19:02:13.977Z,1558033333.977 [AHRS_M2] No Fault, FailCount= 1
2019-05-16T19:02:14.301Z,1558033334.301 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2019-05-16T19:02:17.629Z,1558033337.629 [AHRS_M2](ERROR): Start data-stream UART error: serial timeout
2019-05-16T19:02:18.858Z,1558033338.858 [DataOverHttps](INFO): Sending 1018 bytes from file Logs/20190516T185840/Express0001.lzma
2019-05-16T19:02:19.682Z,1558033339.682 [DataOverHttps](INFO): Moved sent file to Logs/20190516T185840/Express0001.lzma.bak
2019-05-16T19:02:19.682Z,1558033339.682 [DataOverHttps](INFO): SBD MOMSN=11082860
2019-05-16T19:02:23.251Z,1558033343.251 [Default:A.Wait](INFO): Done Waiting.
2019-05-16T19:02:23.251Z,1558033343.251 [Default:A.Wait] Stopped
2019-05-16T19:02:23.252Z,1558033343.252 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-05-16T19:02:23.663Z,1558033343.663 [Default:CheckIn] Running Loop=1
2019-05-16T19:02:23.663Z,1558033343.663 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-05-16T19:02:23.663Z,1558033343.663 [Default:CheckIn:Read_GPS] Running Loop=1
2019-05-16T19:02:24.055Z,1558033344.055 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2019-05-16T19:03:02.806Z,1558033382.806 [DAT](FAULT): failed to initialize; deviceResponse_ loaded: , available: 
2019-05-16T19:03:02.806Z,1558033382.806 [DAT] Communications Fault, FailCount= 4
2019-05-16T19:03:02.806Z,1558033382.806 [DAT](ERROR): Communications Fault
2019-05-16T19:03:02.836Z,1558033382.836 [CBIT](ERROR): Communications Fault in component: DAT
2019-05-16T19:03:03.217Z,1558033383.217 [DAT](INFO): Powering down
2019-05-16T19:03:04.067Z,1558033384.067 [CBIT](INFO): Clearing failed state for component DAT
2019-05-16T19:03:04.067Z,1558033384.067 [DAT] No Fault, FailCount= 4
2019-05-16T19:03:06.455Z,1558033386.455 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2
2019-05-16T19:03:06.455Z,1558033386.455 [DAT](INFO): Powering up
2019-05-16T19:03:06.455Z,1558033386.455 [DAT](DEBUG): Initializing DAT.
2019-05-16T19:03:06.545Z,1558033386.545 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2
2019-05-16T19:04:06.632Z,1558033446.632 [DAT](FAULT): failed to initialize; deviceResponse_ loaded: , available: 
2019-05-16T19:04:06.632Z,1558033446.632 [DAT] Communications Fault, FailCount= 5
2019-05-16T19:04:06.632Z,1558033446.632 [DAT](ERROR): Communications Fault
2019-05-16T19:04:06.660Z,1558033446.660 [CBIT](ERROR): Communications Fault in component: DAT
2019-05-16T19:04:07.075Z,1558033447.075 [DAT](INFO): Powering down
2019-05-16T19:04:07.881Z,1558033447.881 [CBIT](INFO): Clearing failed state for component DAT
2019-05-16T19:04:07.881Z,1558033447.881 [DAT] No Fault, FailCount= 5
2019-05-16T19:04:10.289Z,1558033450.289 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2
2019-05-16T19:04:10.289Z,1558033450.289 [DAT](INFO): Powering up
2019-05-16T19:04:10.289Z,1558033450.289 [DAT](DEBUG): Initializing DAT.
2019-05-16T19:04:10.338Z,1558033450.338 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2
2019-05-16T19:04:19.156Z,1558033459.156 [NAL9602](INFO): SBD MO Status=2, MOMSN=25310, MT Status=2, MTMSN=0
2019-05-16T19:04:19.156Z,1558033459.156 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-05-16T19:04:32.480Z,1558033472.480 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-05-16T19:04:33.317Z,1558033473.317 [NAL9602](DEBUG): Fix Requested
2019-05-16T19:04:36.139Z,1558033476.139 [DVL_micro](ERROR): checksum mismatch: reported106 , calculated:107
2019-05-16T19:04:36.139Z,1558033476.139 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 1 1 1 1 10.0 9.0 11.0 9.1 5.6 1.2 -0.3 5.7 88 -1687 -202 280 1 1 1 1 7.9 -6.0 3.3 1 1.6 -8.5 5.9 1 3 -410 2 -1684 -2050 -410 2 -18.90 -6.20 312.2 9.0 18.3 0.005 35.0 1489 106
2019-05-16T19:04:37.357Z,1558033477.357 [NAL9602](DEBUG): Fix Requested
2019-05-16T19:04:37.745Z,1558033477.745 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,185811.00,A,3648.16208,N,12147.28174,W,0.680,0.00,160519,,,A*71
2019-05-16T19:04:37.748Z,1558033477.748 [NAL9602](INFO): GPS fix at 20190516T185811: (36.802701, -121.788029)
2019-05-16T19:04:37.772Z,1558033477.772 [Default:CheckIn:Read_GPS] Stopped
2019-05-16T19:04:37.772Z,1558033477.772 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-05-16T19:04:38.200Z,1558033478.200 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-05-16T19:04:57.549Z,1558033497.549 [DataOverHttps](INFO): Sending 215 bytes from file Logs/20190516T185840/Courier0004.lzma
2019-05-16T19:04:58.354Z,1558033498.354 [DataOverHttps](INFO): Moved sent file to Logs/20190516T185840/Courier0004.lzma.bak
2019-05-16T19:04:58.354Z,1558033498.354 [DataOverHttps](INFO): SBD MOMSN=11082900
2019-05-16T19:05:07.545Z,1558033507.546 [CommandLine](IMPORTANT): got command get DAT.loadControl
2019-05-16T19:05:07.546Z,1558033507.546 [CommandLine](IMPORTANT): DAT.loadControl /dev/loadB3
2019-05-16T19:05:10.158Z,1558033510.158 [NAL9602](INFO): Powering down
2019-05-16T19:05:10.615Z,1558033510.615 [DAT](FAULT): failed to initialize; deviceResponse_ loaded: , available: 
2019-05-16T19:05:10.615Z,1558033510.615 [DAT] Communications Fault, FailCount= 6
2019-05-16T19:05:10.615Z,1558033510.615 [DAT](ERROR): Communications Fault
2019-05-16T19:05:10.670Z,1558033510.670 [CBIT](ERROR): Communications Fault in component: DAT
2019-05-16T19:05:11.029Z,1558033511.029 [DAT](INFO): Powering down
2019-05-16T19:05:11.866Z,1558033511.866 [CBIT](INFO): Clearing failed state for component DAT
2019-05-16T19:05:11.869Z,1558033511.869 [DAT] No Fault, FailCount= 6
2019-05-16T19:05:14.216Z,1558033514.216 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2
2019-05-16T19:05:14.216Z,1558033514.216 [DAT](INFO): Powering up
2019-05-16T19:05:14.217Z,1558033514.217 [DAT](DEBUG): Initializing DAT.
2019-05-16T19:05:14.275Z,1558033514.275 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2
2019-05-16T19:05:19.085Z,1558033519.085 [DataOverHttps](INFO): Sending 481 bytes from file Logs/20190516T185840/Express0005.lzma
2019-05-16T19:05:19.890Z,1558033519.890 [DataOverHttps](INFO): Moved sent file to Logs/20190516T185840/Express0005.lzma.bak
2019-05-16T19:05:19.890Z,1558033519.890 [DataOverHttps](INFO): SBD MOMSN=11082903
2019-05-16T19:05:23.001Z,1558033523.001 [CommandLine](IMPORTANT): got command failComponent
2019-05-16T19:05:23.002Z,1558033523.002 [CommandLine](IMPORTANT): Failed components:
2019-05-16T19:05:23.002Z,1558033523.002 [CommandLine](IMPORTANT): No failed Components.
2019-05-16T19:05:23.956Z,1558033523.956 [Default:CheckIn:Read_Iridium] Stopped
2019-05-16T19:05:23.956Z,1558033523.956 [Default:CheckIn:C.Wait] Running Loop=1
2019-05-16T19:05:23.956Z,1558033523.956 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-05-16T19:06:14.398Z,1558033574.398 [DAT](FAULT): failed to initialize; deviceResponse_ loaded: , available: 
2019-05-16T19:06:14.398Z,1558033574.398 [DAT] Communications Fault, FailCount= 7
2019-05-16T19:06:14.398Z,1558033574.398 [DAT](ERROR): Communications Fault
2019-05-16T19:06:14.501Z,1558033574.501 [CBIT](ERROR): Communications Fault in component: DAT
2019-05-16T19:06:14.808Z,1558033574.808 [DAT](INFO): Powering down
2019-05-16T19:06:15.658Z,1558033575.658 [CBIT](INFO): Clearing failed state for component DAT
2019-05-16T19:06:15.658Z,1558033575.658 [DAT] No Fault, FailCount= 7
2019-05-16T19:06:18.047Z,1558033578.047 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2
2019-05-16T19:06:18.048Z,1558033578.048 [DAT](INFO): Powering up
2019-05-16T19:06:18.048Z,1558033578.048 [DAT](DEBUG): Initializing DAT.
2019-05-16T19:06:18.115Z,1558033578.115 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2
2019-05-16T19:06:32.978Z,1558033592.978 [DAT](INFO): setting local address to 3
2019-05-16T19:06:33.397Z,1558033593.397 [DAT](INFO): set local address to 3
2019-05-16T19:06:41.886Z,1558033601.886 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2019-05-16T19:06:41.893Z,1558033601.893 [BPC1](INFO): Received data from all battery sticks.
2019-05-16T19:07:11.619Z,1558033631.619 [CommandLine](IMPORTANT): got command get latitude_fix
2019-05-16T19:07:11.619Z,1558033631.619 [CommandLine](IMPORTANT): latitude_fix 36.802701 arcdeg
2019-05-16T19:07:20.147Z,1558033640.147 [CommandLine](IMPORTANT): got command get latitude
2019-05-16T19:07:20.147Z,1558033640.147 [CommandLine](IMPORTANT): latitude 36.802704 arcdeg
2019-05-16T19:07:57.275Z,1558033677.275 [CommandLine](IMPORTANT): got command configSet DVL_micro.loadAtStartup 0.000000 bool persist
2019-05-16T19:07:57.275Z,1558033677.275 [CommandLine](IMPORTANT): configSet DVL_micro.loadAtStartup requires a restart to take effect.
2019-05-16T19:08:01.154Z,1558033681.154 [CommandLine](IMPORTANT): got command restart application
2019-05-16T19:08:02.157Z,1558033682.157 [Supervisor](INFO): Stop Mission called by Supervisor::terminate
2019-05-16T19:08:02.157Z,1558033682.157 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-16T19:08:02.158Z,1558033682.158 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-05-16T19:08:02.213Z,1558033682.213 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2019-05-16T19:08:02.213Z,1558033682.213 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-05-16T19:08:02.214Z,1558033682.214 [CommandLine](INFO): Join timeout helper Thread ID is 3265
2019-05-16T19:08:02.214Z,1558033682.214 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2019-05-16T19:08:02.214Z,1558033682.214 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-05-16T19:08:02.215Z,1558033682.215 [NavChartDb](INFO): Join timeout helper Thread ID is 3266
2019-05-16T19:08:02.425Z,1558033682.425 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-16T19:08:02.425Z,1558033682.425 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-05-16T19:08:02.433Z,1558033682.433 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2019-05-16T19:08:02.433Z,1558033682.433 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-05-16T19:08:02.433Z,1558033682.433 [Radio_Surface](INFO): Join timeout helper Thread ID is 3267
2019-05-16T19:08:02.797Z,1558033682.797 [Radio_Surface](INFO): Powering down
2019-05-16T19:08:02.798Z,1558033682.798 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-16T19:08:02.798Z,1558033682.798 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-05-16T19:08:02.813Z,1558033682.813 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2019-05-16T19:08:02.813Z,1558033682.813 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-05-16T19:08:02.813Z,1558033682.813 [DataOverHttps](INFO): Join timeout helper Thread ID is 3268
2019-05-16T19:08:02.857Z,1558033682.857 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-16T19:08:02.857Z,1558033682.857 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-05-16T19:08:02.873Z,1558033682.873 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2019-05-16T19:08:02.873Z,1558033682.873 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-05-16T19:08:02.873Z,1558033682.873 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 3269
2019-05-16T19:08:03.357Z,1558033683.357 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-16T19:08:03.357Z,1558033683.357 [WetLabsBB2FL](INFO): Powering down
2019-05-16T19:08:03.358Z,1558033683.358 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-05-16T19:08:03.372Z,1558033683.372 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2019-05-16T19:08:03.372Z,1558033683.372 [logger ThreadHandler](INFO): Thread cancelled.
2019-05-16T19:08:03.373Z,1558033683.373 [logger](INFO): Join timeout helper Thread ID is 3270
2019-05-16T19:08:03.449Z,1558033683.449 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-16T19:08:03.449Z,1558033683.449 [logger ThreadHandler](INFO): Thread cancelled.
2019-05-16T19:08:03.458Z,1558033683.458 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2019-05-16T19:08:03.458Z,1558033683.458 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-05-16T19:08:03.458Z,1558033683.458 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2019-05-16T19:08:03.458Z,1558033683.458 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-05-16T19:08:03.458Z,1558033683.458 [controlThread](INFO): Join timeout helper Thread ID is 3271
2019-05-16T19:08:03.500Z,1558033683.500 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-16T19:08:03.501Z,1558033683.501 [controlThread](DEBUG): Uninitializing ControlThread
2019-05-16T19:08:03.502Z,1558033683.502 [AHRS_M2](INFO): Powering down
2019-05-16T19:08:03.645Z,1558033683.645 [DVL_micro](INFO): uninitialize:Powering down
2019-05-16T19:08:03.646Z,1558033683.646 [NAL9602](INFO): Powering down
2019-05-16T19:08:03.647Z,1558033683.647 [DAT](INFO): Powering down
2019-05-16T19:08:03.766Z,1558033683.766 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2019-05-16T19:08:03.767Z,1558033683.767 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2019-05-16T19:08:03.767Z,1558033683.767 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2019-05-16T19:08:03.767Z,1558033683.767 [MissionManager](INFO): Uninitializing Mission Default
2019-05-16T19:08:03.768Z,1558033683.768 [Default] Stopped
2019-05-16T19:08:03.768Z,1558033683.768 [Default](DEBUG): Aggregate::uninitialize Default
2019-05-16T19:08:03.768Z,1558033683.768 [Default:B.GoToSurface] Stopped
2019-05-16T19:08:03.768Z,1558033683.768 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-05-16T19:08:03.768Z,1558033683.768 [Default:CheckIn] Stopped
2019-05-16T19:08:03.768Z,1558033683.768 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-05-16T19:08:03.768Z,1558033683.768 [Default:CheckIn:C.Wait] Stopped
2019-05-16T19:08:03.768Z,1558033683.768 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-16T19:08:03.770Z,1558033683.770 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2019-05-16T19:08:03.771Z,1558033683.771 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2019-05-16T19:08:03.771Z,1558033683.771 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2019-05-16T19:08:03.771Z,1558033683.771 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2019-05-16T19:08:03.772Z,1558033683.772 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2019-05-16T19:08:03.772Z,1558033683.772 [BuoyancyServo](INFO): Powering down
2019-05-16T19:08:03.785Z,1558033683.785 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2019-05-16T19:08:03.785Z,1558033683.785 [ElevatorServo](INFO): Powering down
2019-05-16T19:08:03.786Z,1558033683.786 [MassServo](DEBUG): Uninitialize Mass Servo.
2019-05-16T19:08:03.786Z,1558033683.786 [MassServo](INFO): Powering down
2019-05-16T19:08:03.787Z,1558033683.787 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-05-16T19:08:03.787Z,1558033683.787 [RudderServo](INFO): Powering down
2019-05-16T19:08:03.788Z,1558033683.788 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2019-05-16T19:08:03.788Z,1558033683.788 [ThrusterServo](INFO): Powering down
2019-05-16T19:08:03.788Z,1558033683.788 [SBIT](DEBUG): Uninitialize SBIT Component.
2019-05-16T19:08:03.789Z,1558033683.789 [IBIT](DEBUG): Uninitialize IBIT Component.
2019-05-16T19:08:03.789Z,1558033683.789 [CBIT](DEBUG): Uninitialize CBIT Component.
2019-05-16T19:08:03.789Z,1558033683.789 [CBIT](DEBUG): Powering off loads.
2019-05-16T19:08:03.801Z,1558033683.801 [CBIT](DEBUG): Disabling WDT.
2019-05-16T19:08:03.813Z,1558033683.813 [CBIT](DEBUG): Opening all GF detection circuits.
2019-05-16T19:08:03.814Z,1558033683.814 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-05-16T19:08:03.851Z,1558033683.851 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-05-16T19:08:03.914Z,1558033683.914 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-05-16T19:08:03.923Z,1558033683.923 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-05-16T19:08:03.972Z,1558033683.972 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-05-16T19:08:04.040Z,1558033684.040 [logger ThreadHandler](INFO): Thread cancelled.