2018-10-16T05:04:14.756Z,1539666254.756 [Supervisor](DEBUG): Initializing supervisor.
2018-10-16T05:04:14.759Z,1539666254.759 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2018-10-16T05:04:14.760Z,1539666254.760 [SyncHandler](INFO): Protected caller Thread ID is 5671
2018-10-16T05:04:14.760Z,1539666254.760 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2018-10-16T05:04:14.761Z,1539666254.761 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2018-10-16T05:04:14.762Z,1539666254.762 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 5672
2018-10-16T05:04:14.765Z,1539666254.765 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2018-10-16T05:04:14.778Z,1539666254.778 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2018-10-16T05:04:14.779Z,1539666254.779 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2018-10-16T05:04:14.779Z,1539666254.779 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 5673
2018-10-16T05:04:14.780Z,1539666254.780 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2018-10-16T05:04:14.781Z,1539666254.781 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2018-10-16T05:04:14.781Z,1539666254.781 [logger ThreadHandler](INFO): Protected caller Thread ID is 5674
2018-10-16T05:04:14.783Z,1539666254.783 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2018-10-16T05:04:14.784Z,1539666254.784 [Supervisor](INFO): Looking for Config files in directory: Config/
2018-10-16T05:04:14.785Z,1539666254.785 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2018-10-16T05:04:15.113Z,1539666255.113 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2018-10-16T05:04:15.113Z,1539666255.113 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2018-10-16T05:04:15.311Z,1539666255.311 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2018-10-16T05:04:15.312Z,1539666255.312 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2018-10-16T05:04:15.609Z,1539666255.609 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2018-10-16T05:04:15.610Z,1539666255.610 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2018-10-16T05:04:15.755Z,1539666255.755 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2018-10-16T05:04:15.755Z,1539666255.755 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2018-10-16T05:04:15.853Z,1539666255.853 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2018-10-16T05:04:15.853Z,1539666255.853 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2018-10-16T05:04:16.321Z,1539666256.321 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2018-10-16T05:04:16.322Z,1539666256.322 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2018-10-16T05:04:16.785Z,1539666256.785 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2018-10-16T05:04:16.785Z,1539666256.785 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2018-10-16T05:04:17.255Z,1539666257.255 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2018-10-16T05:04:17.256Z,1539666257.256 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2018-10-16T05:04:17.359Z,1539666257.359 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2018-10-16T05:04:17.359Z,1539666257.359 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2018-10-16T05:04:17.457Z,1539666257.457 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2018-10-16T05:04:17.457Z,1539666257.457 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2018-10-16T05:04:18.272Z,1539666258.272 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2018-10-16T05:04:18.272Z,1539666258.272 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2018-10-16T05:04:18.478Z,1539666258.478 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2018-10-16T05:04:18.479Z,1539666258.479 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2018-10-16T05:04:18.833Z,1539666258.833 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2018-10-16T05:04:18.833Z,1539666258.833 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2018-10-16T05:04:18.978Z,1539666258.978 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2018-10-16T05:04:18.979Z,1539666258.979 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2018-10-16T05:04:19.060Z,1539666259.060 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2018-10-16T05:04:19.060Z,1539666259.060 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2018-10-16T05:04:19.162Z,1539666259.162 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2018-10-16T05:04:19.279Z,1539666259.279 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2018-10-16T05:04:19.373Z,1539666259.373 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2018-10-16T05:04:19.457Z,1539666259.457 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2018-10-16T05:04:19.621Z,1539666259.621 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2018-10-16T05:04:19.801Z,1539666259.801 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg
2018-10-16T05:04:19.876Z,1539666259.876 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg
2018-10-16T05:04:20.110Z,1539666260.110 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2018-10-16T05:04:20.110Z,1539666260.110 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg
2018-10-16T05:04:20.192Z,1539666260.192 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg
2018-10-16T05:04:20.283Z,1539666260.283 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2018-10-16T05:04:20.384Z,1539666260.384 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2018-10-16T05:04:20.511Z,1539666260.511 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/root/
2018-10-16T05:04:20.512Z,1539666260.512 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2018-10-16T05:04:20.524Z,1539666260.524 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2018-10-16T05:04:20.780Z,1539666260.780 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2018-10-16T05:04:20.781Z,1539666260.781 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2018-10-16T05:04:20.825Z,1539666260.825 [DepthRateCalculator] Loaded
2018-10-16T05:04:20.826Z,1539666260.826 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2018-10-16T05:04:20.832Z,1539666260.832 [PitchRateCalculator] Loaded
2018-10-16T05:04:20.832Z,1539666260.832 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2018-10-16T05:04:20.850Z,1539666260.850 [SpeedCalculator] Loaded
2018-10-16T05:04:20.850Z,1539666260.850 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2018-10-16T05:04:20.872Z,1539666260.872 [TempGradientCalculator] Loaded
2018-10-16T05:04:20.873Z,1539666260.873 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2018-10-16T05:04:20.879Z,1539666260.879 [YawRateCalculator] Loaded
2018-10-16T05:04:20.879Z,1539666260.879 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2018-10-16T05:04:20.921Z,1539666260.921 [ElevatorOffsetCalculator] Loaded
2018-10-16T05:04:20.921Z,1539666260.921 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2018-10-16T05:04:20.921Z,1539666260.921 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2018-10-16T05:04:20.922Z,1539666260.922 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2018-10-16T05:04:20.990Z,1539666260.990 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2018-10-16T05:04:20.991Z,1539666260.991 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2018-10-16T05:04:21.109Z,1539666261.109 [BuoyancyServo] Loaded
2018-10-16T05:04:21.109Z,1539666261.109 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2018-10-16T05:04:21.124Z,1539666261.124 [ElevatorServo] Loaded
2018-10-16T05:04:21.124Z,1539666261.124 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2018-10-16T05:04:21.140Z,1539666261.140 [MassServo] Loaded
2018-10-16T05:04:21.140Z,1539666261.140 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2018-10-16T05:04:21.156Z,1539666261.156 [RudderServo] Loaded
2018-10-16T05:04:21.156Z,1539666261.156 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2018-10-16T05:04:21.171Z,1539666261.171 [ThrusterServo] Loaded
2018-10-16T05:04:21.171Z,1539666261.171 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2018-10-16T05:04:21.172Z,1539666261.172 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2018-10-16T05:04:21.172Z,1539666261.172 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2018-10-16T05:04:21.187Z,1539666261.187 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2018-10-16T05:04:21.187Z,1539666261.187 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2018-10-16T05:04:21.296Z,1539666261.296 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2018-10-16T05:04:21.296Z,1539666261.296 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2018-10-16T05:04:21.609Z,1539666261.609 [DataOverHttps] Loaded
2018-10-16T05:04:21.610Z,1539666261.610 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2018-10-16T05:04:21.624Z,1539666261.624 [Depth_Keller] Loaded
2018-10-16T05:04:21.624Z,1539666261.624 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2018-10-16T05:04:21.629Z,1539666261.629 [DropWeight] Loaded
2018-10-16T05:04:21.630Z,1539666261.630 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2018-10-16T05:04:21.733Z,1539666261.733 [NAL9602] Loaded
2018-10-16T05:04:21.734Z,1539666261.734 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2018-10-16T05:04:21.751Z,1539666261.751 [Onboard] Loaded
2018-10-16T05:04:21.751Z,1539666261.751 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2018-10-16T05:04:21.762Z,1539666261.762 [Radio_Surface] Loaded
2018-10-16T05:04:21.762Z,1539666261.762 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2018-10-16T05:04:21.764Z,1539666261.764 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4088F4E0
2018-10-16T05:04:21.764Z,1539666261.764 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 5756
2018-10-16T05:04:21.813Z,1539666261.813 [PNI_TCM] Loaded
2018-10-16T05:04:21.813Z,1539666261.813 [ComponentRegistry](DEBUG): SyncComponent "PNI_TCM" handled in the control thread.
2018-10-16T05:04:21.877Z,1539666261.877 [Rowe_600LCM] Loaded
2018-10-16T05:04:21.878Z,1539666261.878 [ComponentRegistry](DEBUG): Component "Rowe_600LCM" handled in its own thread.
2018-10-16T05:04:21.879Z,1539666261.879 [Rowe_600LCM ThreadHandler](DEBUG): Created PCaller Thread at 408BF4E0
2018-10-16T05:04:21.879Z,1539666261.879 [Rowe_600LCM ThreadHandler](INFO): Protected caller Thread ID is 5757
2018-10-16T05:04:21.880Z,1539666261.880 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2018-10-16T05:04:21.880Z,1539666261.880 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2018-10-16T05:04:22.018Z,1539666262.018 [SBIT](DEBUG): Construct Startup Built In Test.
2018-10-16T05:04:22.041Z,1539666262.041 [SBIT] Loaded
2018-10-16T05:04:22.042Z,1539666262.042 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2018-10-16T05:04:22.042Z,1539666262.042 [IBIT](DEBUG): Construct Initiated Built In Test.
2018-10-16T05:04:22.055Z,1539666262.055 [IBIT] Loaded
2018-10-16T05:04:22.055Z,1539666262.055 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2018-10-16T05:04:22.058Z,1539666262.058 [CBIT](DEBUG): Construct Continuous Built In Test.
2018-10-16T05:04:22.214Z,1539666262.214 [CBIT] Loaded
2018-10-16T05:04:22.215Z,1539666262.215 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2018-10-16T05:04:22.215Z,1539666262.215 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2018-10-16T05:04:22.216Z,1539666262.216 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2018-10-16T05:04:22.388Z,1539666262.388 [Aanderaa_O2] Loaded
2018-10-16T05:04:22.389Z,1539666262.389 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2018-10-16T05:04:22.404Z,1539666262.404 [PAR_Licor] Loaded
2018-10-16T05:04:22.404Z,1539666262.404 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2018-10-16T05:04:22.456Z,1539666262.456 [WetLabsBB2FL] Loaded
2018-10-16T05:04:22.457Z,1539666262.457 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2018-10-16T05:04:22.458Z,1539666262.458 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 4098A4E0
2018-10-16T05:04:22.458Z,1539666262.458 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 5758
2018-10-16T05:04:22.459Z,1539666262.459 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2018-10-16T05:04:22.459Z,1539666262.459 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2018-10-16T05:04:22.614Z,1539666262.614 [VerticalControl](DEBUG): Construct VerticalControl.
2018-10-16T05:04:22.801Z,1539666262.801 [VerticalControl] Loaded
2018-10-16T05:04:22.801Z,1539666262.801 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2018-10-16T05:04:22.802Z,1539666262.802 [HorizontalControl](DEBUG): Construct HorizontalControl.
2018-10-16T05:04:22.953Z,1539666262.953 [HorizontalControl] Loaded
2018-10-16T05:04:22.954Z,1539666262.954 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2018-10-16T05:04:22.971Z,1539666262.971 [SpeedControl](DEBUG): Construct SpeedControl.
2018-10-16T05:04:22.972Z,1539666262.972 [SpeedControl] Loaded
2018-10-16T05:04:22.973Z,1539666262.973 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2018-10-16T05:04:22.973Z,1539666262.973 [LoopControl](DEBUG): Construct LoopControl.
2018-10-16T05:04:22.974Z,1539666262.974 [LoopControl] Loaded
2018-10-16T05:04:22.974Z,1539666262.974 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2018-10-16T05:04:22.975Z,1539666262.975 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2018-10-16T05:04:22.975Z,1539666262.975 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2018-10-16T05:04:23.060Z,1539666263.060 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2018-10-16T05:04:23.060Z,1539666263.060 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2018-10-16T05:04:23.473Z,1539666263.473 [DeadReckonUsingSpeedCalculator] Loaded
2018-10-16T05:04:23.473Z,1539666263.473 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2018-10-16T05:04:23.490Z,1539666263.490 [NavChart] Loaded
2018-10-16T05:04:23.490Z,1539666263.490 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2018-10-16T05:04:23.494Z,1539666263.494 [UniversalFixResidualReporter] Loaded
2018-10-16T05:04:23.495Z,1539666263.495 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2018-10-16T05:04:23.495Z,1539666263.495 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2018-10-16T05:04:23.540Z,1539666263.540 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2018-10-16T05:04:23.541Z,1539666263.541 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2018-10-16T05:04:23.549Z,1539666263.549 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2018-10-16T05:04:23.550Z,1539666263.550 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40A164E0
2018-10-16T05:04:23.551Z,1539666263.551 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 5759
2018-10-16T05:04:23.556Z,1539666263.556 [Supervisor](INFO): Main Thread ID is 5405
2018-10-16T05:04:23.556Z,1539666263.556 [Supervisor](DEBUG): Running supervisor.
2018-10-16T05:04:23.556Z,1539666263.556 [CommandLine ThreadHandler](INFO): Handler Thread ID is 5760
2018-10-16T05:04:23.559Z,1539666263.559 [controlThread ThreadHandler](INFO): Handler Thread ID is 5761
2018-10-16T05:04:23.559Z,1539666263.559 [controlThread](DEBUG): Initializing ControlThread
2018-10-16T05:04:23.560Z,1539666263.560 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2018-10-16T05:04:23.561Z,1539666263.561 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2018-10-16T05:04:23.561Z,1539666263.561 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2018-10-16T05:04:23.561Z,1539666263.561 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2018-10-16T05:04:23.562Z,1539666263.562 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2018-10-16T05:04:23.562Z,1539666263.562 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2018-10-16T05:04:23.568Z,1539666263.568 [SBIT](INFO): Initialize SBIT Component.
2018-10-16T05:04:23.569Z,1539666263.569 [SBIT](IMPORTANT): git: 2018-10-09-22-g812aa5f
2018-10-16T05:04:23.569Z,1539666263.569 [SBIT](INFO): git hash: 812aa5f738ae24d7d3f6c5c137b2640d1960a87f
2018-10-16T05:04:23.569Z,1539666263.569 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2018-10-16T05:04:23.570Z,1539666263.570 [SBIT](IMPORTANT): Kernel Version:#2 PREEMPT Thu Jan 11 20:13:48 PST 2018
2018-10-16T05:04:23.571Z,1539666263.571 [SBIT](INFO): Beginning SBIT in 36.000000 seconds.
2018-10-16T05:04:23.571Z,1539666263.571 [IBIT](INFO): Initialize IBIT Component.
2018-10-16T05:04:23.572Z,1539666263.572 [CBIT](DEBUG): Initialize CBIT Component.
2018-10-16T05:04:23.572Z,1539666263.572 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2018-10-16T05:04:23.573Z,1539666263.573 [logger ThreadHandler](INFO): Handler Thread ID is 5762
2018-10-16T05:04:23.591Z,1539666263.591 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 5763
2018-10-16T05:04:23.596Z,1539666263.596 [Radio_Surface](INFO): Powering up
2018-10-16T05:04:23.603Z,1539666263.603 [Rowe_600LCM ThreadHandler](INFO): Handler Thread ID is 5764
2018-10-16T05:04:23.603Z,1539666263.603 [Rowe_600LCM](INFO): Initializing
2018-10-16T05:04:23.604Z,1539666263.604 [Rowe_600LCM](INFO): Checking LCM
2018-10-16T05:04:23.613Z,1539666263.613 [Rowe_600LCM](INFO): LCM OK
2018-10-16T05:04:23.613Z,1539666263.613 [Rowe_600LCM](INFO): Powering up
2018-10-16T05:04:23.619Z,1539666263.619 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 5765
2018-10-16T05:04:23.620Z,1539666263.620 [WetLabsBB2FL](INFO): Powering down
2018-10-16T05:04:23.647Z,1539666263.647 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 5766
2018-10-16T05:04:23.650Z,1539666263.650 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2018-10-16T05:04:23.651Z,1539666263.651 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2018-10-16T05:04:23.651Z,1539666263.651 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2018-10-16T05:04:23.651Z,1539666263.651 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2018-10-16T05:04:23.651Z,1539666263.651 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2018-10-16T05:04:23.651Z,1539666263.651 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2018-10-16T05:04:23.652Z,1539666263.652 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2018-10-16T05:04:23.652Z,1539666263.652 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2018-10-16T05:04:23.652Z,1539666263.652 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2018-10-16T05:04:23.652Z,1539666263.652 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2018-10-16T05:04:23.652Z,1539666263.652 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2018-10-16T05:04:23.653Z,1539666263.653 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2018-10-16T05:04:23.653Z,1539666263.653 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2018-10-16T05:04:23.653Z,1539666263.653 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2018-10-16T05:04:23.653Z,1539666263.653 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2018-10-16T05:04:23.653Z,1539666263.653 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2018-10-16T05:04:23.683Z,1539666263.683 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2018-10-16T05:04:23.685Z,1539666263.685 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2018-10-16T05:04:23.685Z,1539666263.685 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2018-10-16T05:04:23.686Z,1539666263.686 [LoopControl](DEBUG): Initialize LoopControlComponent.
2018-10-16T05:04:23.686Z,1539666263.686 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-10-16T05:04:23.687Z,1539666263.687 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-10-16T05:04:23.687Z,1539666263.687 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-10-16T05:04:23.688Z,1539666263.688 [NavChart](DEBUG): Initialize NavChart Navigation.
2018-10-16T05:04:23.688Z,1539666263.688 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2018-10-16T05:04:23.689Z,1539666263.689 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2018-10-16T05:04:23.713Z,1539666263.713 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2018-10-16T05:04:23.749Z,1539666263.749 [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>


2018-10-16T05:04:23.750Z,1539666263.750 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2018-10-16T05:04:23.843Z,1539666263.843 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2018-10-16T05:04:23.845Z,1539666263.845 [Default:A.Wait](DEBUG): Construct Wait.
2018-10-16T05:04:23.846Z,1539666263.846 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2018-10-16T05:04:23.881Z,1539666263.881 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2018-10-16T05:04:23.900Z,1539666263.900 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2018-10-16T05:04:23.906Z,1539666263.906 [Default:E.Execute](DEBUG): Construct Execute.
2018-10-16T05:04:23.909Z,1539666263.909 [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>


2018-10-16T05:04:23.923Z,1539666263.923 [controlThread](DEBUG): Component order: CycleStarter,DataOverHttps,Depth_Keller,DropWeight,NAL9602,Onboard,PNI_TCM,Aanderaa_O2,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2018-10-16T05:04:23.939Z,1539666263.939 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2018-10-16T05:04:23.952Z,1539666263.952 [Depth_Keller](ERROR): Pressure reading out of range: 1831.023193 decibar
2018-10-16T05:04:24.032Z,1539666264.032 [Aanderaa_O2](INFO): Start
2018-10-16T05:04:24.215Z,1539666264.215 [DepthRateCalculator](ERROR): Depth measurement is not active
2018-10-16T05:04:24.300Z,1539666264.300 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-10-16T05:04:24.415Z,1539666264.415 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2018-10-16T05:04:24.423Z,1539666264.423 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2018-10-16T05:04:24.437Z,1539666264.437 [ElevatorServo](DEBUG): Initializing EZServoServo.
2018-10-16T05:04:24.443Z,1539666264.443 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2018-10-16T05:04:24.461Z,1539666264.461 [MassServo](DEBUG): Initializing EZServoServo.
2018-10-16T05:04:24.467Z,1539666264.467 [MassServo](DEBUG): Initializing MassServo.
2018-10-16T05:04:24.474Z,1539666264.474 [RudderServo](DEBUG): Initializing EZServoServo.
2018-10-16T05:04:24.491Z,1539666264.491 [RudderServo](DEBUG): Initializing RudderServo.
2018-10-16T05:04:24.496Z,1539666264.496 [ThrusterServo](DEBUG): Initializing EZServoServo.
2018-10-16T05:04:24.503Z,1539666264.503 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2018-10-16T05:04:24.767Z,1539666264.767 [Aanderaa_O2](INFO): Starting
2018-10-16T05:04:24.778Z,1539666264.778 [Aanderaa_O2](INFO): Starting: do start.
2018-10-16T05:04:24.790Z,1539666264.790 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-10-16T05:04:25.008Z,1539666265.008 [Aanderaa_O2](INFO): Starting
2018-10-16T05:04:25.034Z,1539666265.034 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-10-16T05:04:25.504Z,1539666265.504 [Aanderaa_O2](INFO): Starting
2018-10-16T05:04:25.545Z,1539666265.545 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-10-16T05:04:25.907Z,1539666265.907 [Aanderaa_O2](INFO): Starting
2018-10-16T05:04:25.916Z,1539666265.916 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-10-16T05:04:26.292Z,1539666266.292 [Aanderaa_O2](INFO): Starting
2018-10-16T05:04:26.293Z,1539666266.293 [Aanderaa_O2](INFO): Starting: can read until (59 bytes).
2018-10-16T05:04:26.297Z,1539666266.297 [Aanderaa_O2](ERROR): Error parsing data: 

2018-10-16T05:04:26.318Z,1539666266.318 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-10-16T05:04:26.693Z,1539666266.693 [Aanderaa_O2](INFO): Starting
2018-10-16T05:04:26.714Z,1539666266.714 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-10-16T05:04:27.107Z,1539666267.107 [Aanderaa_O2](INFO): Starting
2018-10-16T05:04:27.114Z,1539666267.114 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-10-16T05:04:27.504Z,1539666267.504 [Aanderaa_O2](INFO): Starting
2018-10-16T05:04:27.922Z,1539666267.922 [Aanderaa_O2](INFO): Starting
2018-10-16T05:04:27.968Z,1539666267.968 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-10-16T05:04:28.172Z,1539666268.172 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null &
2018-10-16T05:04:28.198Z,1539666268.198 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-10-16T05:04:28.240Z,1539666268.240 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-10-16T05:04:28.241Z,1539666268.241 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-10-16T05:04:28.371Z,1539666268.371 [Aanderaa_O2](INFO): Starting
2018-10-16T05:04:28.371Z,1539666268.371 [Aanderaa_O2](INFO): Starting: can read until (5A bytes).
2018-10-16T05:04:28.375Z,1539666268.375 [Aanderaa_O2](ERROR): Error parsing data: 

2018-10-16T05:04:28.711Z,1539666268.711 [Aanderaa_O2](INFO): Starting
2018-10-16T05:04:29.110Z,1539666269.110 [Aanderaa_O2](INFO): Starting
2018-10-16T05:04:29.551Z,1539666269.551 [Aanderaa_O2](INFO): Starting
2018-10-16T05:04:29.552Z,1539666269.552 [Aanderaa_O2](INFO): Starting: can read until (59 bytes).
2018-10-16T05:04:29.575Z,1539666269.575 [Aanderaa_O2](ERROR): Uart error: serial timeout
2018-10-16T05:04:29.576Z,1539666269.576 [Aanderaa_O2] Communications Fault, FailCount= 1
2018-10-16T05:04:29.576Z,1539666269.576 [Aanderaa_O2](ERROR): Communications Fault
2018-10-16T05:04:29.749Z,1539666269.749 [CBIT](ERROR): Communications Fault in component: Aanderaa_O2
2018-10-16T05:04:29.930Z,1539666269.930 [Aanderaa_O2](INFO): Stop
2018-10-16T05:04:29.940Z,1539666269.940 [Aanderaa_O2](INFO): Powering down
2018-10-16T05:04:30.369Z,1539666270.369 [Aanderaa_O2](INFO): Stopping
2018-10-16T05:04:30.778Z,1539666270.778 [Aanderaa_O2](INFO): Stopped
2018-10-16T05:04:30.852Z,1539666270.852 [CBIT](INFO): Clearing failed state for component Aanderaa_O2
2018-10-16T05:04:30.852Z,1539666270.852 [Aanderaa_O2] No Fault, FailCount= 1
2018-10-16T05:04:31.169Z,1539666271.169 [Aanderaa_O2](INFO): Start
2018-10-16T05:04:31.560Z,1539666271.560 [Aanderaa_O2](INFO): Starting
2018-10-16T05:04:31.570Z,1539666271.570 [Aanderaa_O2](INFO): Starting: do start.
2018-10-16T05:04:31.962Z,1539666271.962 [Aanderaa_O2](INFO): Starting
2018-10-16T05:04:32.368Z,1539666272.368 [Aanderaa_O2](INFO): Starting
2018-10-16T05:04:32.771Z,1539666272.771 [Aanderaa_O2](INFO): Starting
2018-10-16T05:04:33.161Z,1539666273.161 [Aanderaa_O2](INFO): Starting
2018-10-16T05:04:33.561Z,1539666273.561 [Aanderaa_O2](INFO): Starting
2018-10-16T05:04:33.561Z,1539666273.561 [Aanderaa_O2](INFO): Starting: can read until (5E bytes).
2018-10-16T05:04:33.565Z,1539666273.565 [Aanderaa_O2](ERROR): Error parsing data: 

2018-10-16T05:04:33.968Z,1539666273.968 [Aanderaa_O2](INFO): Starting
2018-10-16T05:04:34.377Z,1539666274.377 [Aanderaa_O2](INFO): Starting
2018-10-16T05:04:34.762Z,1539666274.762 [Aanderaa_O2](INFO): Starting
2018-10-16T05:04:35.169Z,1539666275.169 [Aanderaa_O2](INFO): Starting
2018-10-16T05:04:35.568Z,1539666275.568 [Aanderaa_O2](INFO): Starting
2018-10-16T05:04:35.569Z,1539666275.569 [Aanderaa_O2](INFO): Starting: can read until (5A bytes).
2018-10-16T05:04:35.574Z,1539666275.574 [Aanderaa_O2](ERROR): Error parsing data: 

2018-10-16T05:04:35.965Z,1539666275.965 [Aanderaa_O2](INFO): Starting
2018-10-16T05:04:36.374Z,1539666276.374 [Aanderaa_O2](INFO): Starting
2018-10-16T05:04:36.374Z,1539666276.374 [Aanderaa_O2](INFO): Starting: can read until (59 bytes).
2018-10-16T05:04:36.384Z,1539666276.384 [Aanderaa_O2](ERROR): Uart error: serial timeout
2018-10-16T05:04:36.384Z,1539666276.384 [Aanderaa_O2] Communications Fault, FailCount= 2
2018-10-16T05:04:36.384Z,1539666276.384 [Aanderaa_O2](ERROR): Communications Fault
2018-10-16T05:04:36.495Z,1539666276.495 [CBIT](ERROR): Communications Fault in component: Aanderaa_O2
2018-10-16T05:04:36.762Z,1539666276.762 [Aanderaa_O2](INFO): Stop
2018-10-16T05:04:36.763Z,1539666276.763 [Aanderaa_O2](INFO): Powering down
2018-10-16T05:04:37.168Z,1539666277.168 [Aanderaa_O2](INFO): Stopping
2018-10-16T05:04:37.575Z,1539666277.575 [Aanderaa_O2](INFO): Stopped
2018-10-16T05:04:37.655Z,1539666277.655 [CBIT](INFO): Clearing failed state for component Aanderaa_O2
2018-10-16T05:04:37.656Z,1539666277.656 [Aanderaa_O2] No Fault, FailCount= 2
2018-10-16T05:04:37.961Z,1539666277.961 [Aanderaa_O2](INFO): Start
2018-10-16T05:04:38.361Z,1539666278.361 [Aanderaa_O2](INFO): Starting
2018-10-16T05:04:38.374Z,1539666278.374 [Aanderaa_O2](INFO): Starting: do start.
2018-10-16T05:04:38.768Z,1539666278.768 [Aanderaa_O2](INFO): Starting
2018-10-16T05:04:39.171Z,1539666279.171 [Aanderaa_O2](INFO): Starting
2018-10-16T05:04:39.560Z,1539666279.560 [Aanderaa_O2](INFO): Starting
2018-10-16T05:04:39.961Z,1539666279.961 [Aanderaa_O2](INFO): Starting
2018-10-16T05:04:40.368Z,1539666280.368 [Aanderaa_O2](INFO): Starting
2018-10-16T05:04:40.369Z,1539666280.369 [Aanderaa_O2](INFO): Starting: can read until (5A bytes).
2018-10-16T05:04:40.373Z,1539666280.373 [Aanderaa_O2](ERROR): Error parsing data: 

2018-10-16T05:04:40.771Z,1539666280.771 [Aanderaa_O2](INFO): Starting
2018-10-16T05:04:41.216Z,1539666281.216 [Aanderaa_O2](INFO): Starting
2018-10-16T05:04:41.571Z,1539666281.571 [Aanderaa_O2](INFO): Starting
2018-10-16T05:04:41.968Z,1539666281.968 [Aanderaa_O2](INFO): Starting
2018-10-16T05:04:42.362Z,1539666282.362 [Aanderaa_O2](INFO): Starting
2018-10-16T05:04:42.363Z,1539666282.363 [Aanderaa_O2](INFO): Starting: can read until (5A bytes).
2018-10-16T05:04:42.367Z,1539666282.367 [Aanderaa_O2](ERROR): Error parsing data: 

2018-10-16T05:04:42.791Z,1539666282.791 [Aanderaa_O2](INFO): Starting
2018-10-16T05:04:43.173Z,1539666283.173 [Aanderaa_O2](INFO): Starting
2018-10-16T05:04:43.174Z,1539666283.174 [Aanderaa_O2](INFO): Starting: can read until (59 bytes).
2018-10-16T05:04:43.195Z,1539666283.195 [Aanderaa_O2](ERROR): Uart error: serial timeout
2018-10-16T05:04:43.195Z,1539666283.195 [Aanderaa_O2] Communications Fault, FailCount= 3
2018-10-16T05:04:43.195Z,1539666283.195 [Aanderaa_O2](ERROR): Communications Fault
2018-10-16T05:04:43.304Z,1539666283.304 [CBIT](ERROR): Communications Fault in component: Aanderaa_O2
2018-10-16T05:04:43.306Z,1539666283.306 [CBIT](FAULT): Communications Fault in component: Aanderaa_O2
2018-10-16T05:04:43.568Z,1539666283.568 [Aanderaa_O2](INFO): Stop
2018-10-16T05:04:43.569Z,1539666283.569 [Aanderaa_O2](INFO): Powering down
2018-10-16T05:04:43.991Z,1539666283.991 [Aanderaa_O2](INFO): Stopping
2018-10-16T05:04:44.363Z,1539666284.363 [Aanderaa_O2](INFO): Stopped
2018-10-16T05:04:51.932Z,1539666291.932 [NAL9602](INFO): Powering up NAL9602
2018-10-16T05:05:00.024Z,1539666300.024 [SBIT](IMPORTANT): Beginning Startup BIT
2018-10-16T05:05:00.037Z,1539666300.037 [CBIT](IMPORTANT): Beginning ground fault scan
2018-10-16T05:05:03.322Z,1539666303.322 [NAL9602](INFO): NAL9602 initialized
2018-10-16T05:05:11.429Z,1539666311.429 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.004474
CHAN A1 (24V): -0.008177
CHAN A2 (12V): -0.002422
CHAN A3 (5V): -0.001412
CHAN B0 (3.3V): 0.000157
CHAN B1 (3.15aV): -0.000449
CHAN B2 (3.15bV): -0.000243
CHAN B3 (GND): 0.000259
OPEN: -0.000539
Full Scale Calc: 4.765 mA, -1.589 mA
2018-10-16T05:05:54.179Z,1539666354.179 [SBIT](IMPORTANT): SBIT PASSED
2018-10-16T05:05:54.240Z,1539666354.240 [CommandLine](IMPORTANT): got command configSet list
2018-10-16T05:05:54.240Z,1539666354.240 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2018-10-16T05:05:54.241Z,1539666354.241 [CommandLine](IMPORTANT): BPC1.batteryMissingStickThreshold=25 count;

2018-10-16T05:05:54.241Z,1539666354.241 [CommandLine](IMPORTANT): BPC1.batteryMuxCycleTime=10 minute;

2018-10-16T05:05:54.241Z,1539666354.241 [CommandLine](IMPORTANT): BPC1.batterySamplingInterval=1 minute;

2018-10-16T05:05:54.241Z,1539666354.241 [CommandLine](IMPORTANT): BPC1.loadAtStartup=0 bool;

2018-10-16T05:05:54.242Z,1539666354.242 [CommandLine](IMPORTANT): CTD_NeilBrown.loadAtStartup=0 bool;

2018-10-16T05:05:54.242Z,1539666354.242 [CommandLine](IMPORTANT): CTD_Seabird.loadAtStartup=0 bool;

2018-10-16T05:05:54.242Z,1539666354.242 [CommandLine](IMPORTANT): Express none VerticalTemperatureHomogeneityIndexCalculator.vertical_temperature_homogeneity_index;

2018-10-16T05:05:54.242Z,1539666354.242 [CommandLine](IMPORTANT): Express linearApproximation height_above_sea_floor 5.000000 meter;

2018-10-16T05:05:54.242Z,1539666354.242 [CommandLine](IMPORTANT): Rowe_600LCM.loadAtStartup=1 bool;

2018-10-16T05:05:54.242Z,1539666354.242 [CommandLine](IMPORTANT): StratificationFrontDetector.loadAtStartup=0 bool;

2018-10-16T05:05:54.242Z,1539666354.242 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral=213 cubic_centimeter;

2018-10-16T05:05:54.243Z,1539666354.243 [CommandLine](IMPORTANT): VerticalControl.massDefault=4 millimeter;

2018-10-16T05:05:54.575Z,1539666354.575 [MissionManager](IMPORTANT): Started mission Startup
2018-10-16T05:05:54.576Z,1539666354.576 [Startup] Running Loop=1
2018-10-16T05:05:54.576Z,1539666354.576 [Startup](DEBUG): Aggregate::initialize Startup
2018-10-16T05:05:54.576Z,1539666354.576 [Startup:A.GoToSurface] Running Loop=1
2018-10-16T05:05:54.576Z,1539666354.576 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-10-16T05:05:54.577Z,1539666354.577 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2018-10-16T05:05:54.577Z,1539666354.577 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2018-10-16T05:05:54.578Z,1539666354.578 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2018-10-16T05:05:54.578Z,1539666354.578 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-10-16T05:05:54.579Z,1539666354.579 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2018-10-16T05:05:54.585Z,1539666354.585 [Startup:StartupSatComms] Running Loop=1
2018-10-16T05:05:54.585Z,1539666354.585 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2018-10-16T05:05:54.585Z,1539666354.585 [Startup:StartupSatComms:A] Running Loop=1
2018-10-16T05:05:54.981Z,1539666354.981 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2018-10-16T05:06:54.588Z,1539666414.588 [Startup:StartupSatComms:A](INFO): Timed out from 2018-10-16T05:05:54.6Z
2018-10-16T05:06:54.588Z,1539666414.588 [Startup:StartupSatComms:A] Stopped
2018-10-16T05:06:54.588Z,1539666414.588 [Startup:StartupSatComms:B] Running Loop=1
2018-10-16T05:06:55.050Z,1539666415.050 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2018-10-16T05:07:13.417Z,1539666433.417 [CBIT](INFO): Clearing failed state for component Aanderaa_O2
2018-10-16T05:07:13.417Z,1539666433.417 [Aanderaa_O2] No Fault, FailCount= 3
2018-10-16T05:07:13.768Z,1539666433.768 [Aanderaa_O2](INFO): Start
2018-10-16T05:07:14.179Z,1539666434.179 [Aanderaa_O2](INFO): Starting
2018-10-16T05:07:14.206Z,1539666434.206 [Aanderaa_O2](INFO): Starting: do start.
2018-10-16T05:07:14.576Z,1539666434.576 [Aanderaa_O2](INFO): Starting
2018-10-16T05:07:15.023Z,1539666435.023 [Aanderaa_O2](INFO): Starting
2018-10-16T05:07:15.380Z,1539666435.380 [Aanderaa_O2](INFO): Starting
2018-10-16T05:07:15.760Z,1539666435.760 [Aanderaa_O2](INFO): Starting
2018-10-16T05:07:16.160Z,1539666436.160 [Aanderaa_O2](INFO): Starting
2018-10-16T05:07:16.564Z,1539666436.564 [Aanderaa_O2](INFO): Starting
2018-10-16T05:07:16.963Z,1539666436.963 [Aanderaa_O2](INFO): Starting
2018-10-16T05:07:17.385Z,1539666437.385 [Aanderaa_O2](INFO): Starting
2018-10-16T05:07:17.764Z,1539666437.764 [Aanderaa_O2](INFO): Starting
2018-10-16T05:07:18.167Z,1539666438.167 [Aanderaa_O2](INFO): Starting
2018-10-16T05:07:18.568Z,1539666438.568 [Aanderaa_O2](INFO): Starting
2018-10-16T05:07:18.965Z,1539666438.965 [Aanderaa_O2](INFO): Starting
2018-10-16T05:07:19.399Z,1539666439.399 [Aanderaa_O2](INFO): Starting
2018-10-16T05:07:19.780Z,1539666439.780 [Aanderaa_O2](INFO): Starting
2018-10-16T05:07:20.183Z,1539666440.183 [Aanderaa_O2](INFO): Starting
2018-10-16T05:07:20.583Z,1539666440.583 [Aanderaa_O2](INFO): Starting
2018-10-16T05:07:20.957Z,1539666440.957 [Aanderaa_O2](INFO): Starting
2018-10-16T05:07:21.360Z,1539666441.360 [Aanderaa_O2](INFO): Starting
2018-10-16T05:07:21.756Z,1539666441.756 [Aanderaa_O2](INFO): Starting
2018-10-16T05:07:22.160Z,1539666442.160 [Aanderaa_O2](INFO): Starting
2018-10-16T05:07:22.557Z,1539666442.557 [Aanderaa_O2](INFO): Starting
2018-10-16T05:07:22.997Z,1539666442.997 [Aanderaa_O2](INFO): Starting
2018-10-16T05:07:23.371Z,1539666443.371 [Aanderaa_O2](INFO): Starting
2018-10-16T05:07:23.767Z,1539666443.767 [Aanderaa_O2](INFO): Starting
2018-10-16T05:07:23.789Z,1539666443.789 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-10-16T05:07:23.790Z,1539666443.790 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 1
2018-10-16T05:07:23.790Z,1539666443.790 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-10-16T05:07:23.823Z,1539666443.823 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-10-16T05:07:24.168Z,1539666444.168 [Aanderaa_O2](INFO): Starting
2018-10-16T05:07:24.168Z,1539666444.168 [Aanderaa_O2](FAULT): Failed to initialize within timeout.
2018-10-16T05:07:24.168Z,1539666444.168 [Aanderaa_O2] Communications Fault, FailCount= 1
2018-10-16T05:07:24.168Z,1539666444.168 [Aanderaa_O2](ERROR): Communications Fault
2018-10-16T05:07:24.207Z,1539666444.207 [CBIT](ERROR): Communications Fault in component: Aanderaa_O2
2018-10-16T05:07:24.208Z,1539666444.208 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-10-16T05:07:24.208Z,1539666444.208 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 1
2018-10-16T05:07:24.590Z,1539666444.590 [Aanderaa_O2](INFO): Stop
2018-10-16T05:07:24.591Z,1539666444.591 [Aanderaa_O2](INFO): Powering down
2018-10-16T05:07:24.604Z,1539666444.604 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-10-16T05:07:24.605Z,1539666444.605 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-10-16T05:07:24.605Z,1539666444.605 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-10-16T05:07:28.108Z,1539666448.108 [Aanderaa_O2](INFO): Stopping
2018-10-16T05:07:28.247Z,1539666448.247 [Aanderaa_O2](INFO): Stopped
2018-10-16T05:07:28.273Z,1539666448.273 [CBIT](INFO): Clearing failed state for component Aanderaa_O2
2018-10-16T05:07:28.273Z,1539666448.273 [Aanderaa_O2] No Fault, FailCount= 1
2018-10-16T05:07:28.614Z,1539666448.614 [Aanderaa_O2](INFO): Start
2018-10-16T05:07:28.981Z,1539666448.981 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.005254
2018-10-16T05:07:29.068Z,1539666449.068 [Aanderaa_O2](INFO): Starting
2018-10-16T05:07:29.090Z,1539666449.090 [Aanderaa_O2](INFO): Starting: do start.
2018-10-16T05:07:29.459Z,1539666449.459 [Aanderaa_O2](INFO): Starting
2018-10-16T05:07:29.806Z,1539666449.806 [Aanderaa_O2](INFO): Starting
2018-10-16T05:07:33.212Z,1539666453.212 [Aanderaa_O2](INFO): Starting
2018-10-16T05:07:33.212Z,1539666453.212 [Aanderaa_O2](INFO): Starting: can read until (5A bytes).
2018-10-16T05:07:33.217Z,1539666453.217 [Aanderaa_O2](ERROR): Error parsing data: 

2018-10-16T05:07:33.288Z,1539666453.288 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20181016T045854/Courier0004.lzma
2018-10-16T05:07:33.347Z,1539666453.347 [Aanderaa_O2](INFO): Starting
2018-10-16T05:07:33.347Z,1539666453.347 [Aanderaa_O2](INFO): Starting: can read until (5A bytes).
2018-10-16T05:07:33.351Z,1539666453.351 [Aanderaa_O2](ERROR): Error parsing data: 

2018-10-16T05:07:33.739Z,1539666453.739 [Aanderaa_O2](INFO): Starting
2018-10-16T05:07:34.080Z,1539666454.080 [DataOverHttps](INFO): Moved sent file to Logs/20181016T045854/Courier0004.lzma.bak
2018-10-16T05:07:34.080Z,1539666454.080 [DataOverHttps](INFO): SBD MOMSN=8715642
2018-10-16T05:07:34.140Z,1539666454.140 [Aanderaa_O2](INFO): Starting
2018-10-16T05:07:34.140Z,1539666454.140 [Aanderaa_O2](INFO): Starting: can read until (59 bytes).
2018-10-16T05:07:34.145Z,1539666454.145 [Aanderaa_O2](ERROR): Error parsing data: 

2018-10-16T05:07:34.614Z,1539666454.614 [Aanderaa_O2](INFO): Starting
2018-10-16T05:07:34.917Z,1539666454.917 [Aanderaa_O2](INFO): Starting
2018-10-16T05:07:34.917Z,1539666454.917 [Aanderaa_O2](INFO): Starting: can read until (59 bytes).
2018-10-16T05:07:34.921Z,1539666454.921 [Aanderaa_O2](ERROR): Error parsing data: 

2018-10-16T05:07:38.432Z,1539666458.432 [Aanderaa_O2](INFO): Starting
2018-10-16T05:07:38.595Z,1539666458.595 [Aanderaa_O2](INFO): Starting
2018-10-16T05:07:38.988Z,1539666458.988 [Aanderaa_O2](INFO): Starting
2018-10-16T05:07:38.988Z,1539666458.988 [Aanderaa_O2](FAULT): Failed to initialize within timeout.
2018-10-16T05:07:38.989Z,1539666458.989 [Aanderaa_O2] Communications Fault, FailCount= 2
2018-10-16T05:07:38.989Z,1539666458.989 [Aanderaa_O2](ERROR): Communications Fault
2018-10-16T05:07:39.104Z,1539666459.104 [CBIT](ERROR): Communications Fault in component: Aanderaa_O2
2018-10-16T05:07:39.346Z,1539666459.346 [Aanderaa_O2](INFO): Stop
2018-10-16T05:07:39.347Z,1539666459.347 [Aanderaa_O2](INFO): Powering down
2018-10-16T05:07:39.717Z,1539666459.717 [Aanderaa_O2](INFO): Stopping
2018-10-16T05:07:40.119Z,1539666460.119 [Aanderaa_O2](INFO): Stopped
2018-10-16T05:07:40.170Z,1539666460.170 [CBIT](INFO): Clearing failed state for component Aanderaa_O2
2018-10-16T05:07:40.170Z,1539666460.170 [Aanderaa_O2] No Fault, FailCount= 2
2018-10-16T05:07:43.628Z,1539666463.628 [Aanderaa_O2](INFO): Start
2018-10-16T05:07:43.695Z,1539666463.695 [DataOverHttps](INFO): Sending 249 bytes from file Logs/20181016T045854/Express0005.lzma
2018-10-16T05:07:43.795Z,1539666463.795 [Aanderaa_O2](INFO): Starting
2018-10-16T05:07:43.806Z,1539666463.806 [Aanderaa_O2](INFO): Starting: do start.
2018-10-16T05:07:44.122Z,1539666464.122 [Aanderaa_O2](INFO): Starting
2018-10-16T05:07:44.480Z,1539666464.480 [DataOverHttps](INFO): Moved sent file to Logs/20181016T045854/Express0005.lzma.bak
2018-10-16T05:07:44.480Z,1539666464.480 [DataOverHttps](INFO): SBD MOMSN=8715644
2018-10-16T05:07:44.545Z,1539666464.545 [Aanderaa_O2](INFO): Starting
2018-10-16T05:07:45.029Z,1539666465.029 [Aanderaa_O2](INFO): Starting
2018-10-16T05:07:45.358Z,1539666465.358 [Aanderaa_O2](INFO): Starting
2018-10-16T05:07:48.686Z,1539666468.686 [Aanderaa_O2](INFO): Starting
2018-10-16T05:07:48.687Z,1539666468.687 [Aanderaa_O2](INFO): Starting: can read until (5A bytes).
2018-10-16T05:07:48.691Z,1539666468.691 [Aanderaa_O2](ERROR): Error parsing data: 

2018-10-16T05:07:48.835Z,1539666468.835 [Aanderaa_O2](INFO): Starting
2018-10-16T05:07:48.835Z,1539666468.835 [Aanderaa_O2](INFO): Starting: can read until (5A bytes).
2018-10-16T05:07:48.845Z,1539666468.845 [Aanderaa_O2](ERROR): Error parsing data: 

2018-10-16T05:07:49.217Z,1539666469.217 [Aanderaa_O2](INFO): Starting
2018-10-16T05:07:49.217Z,1539666469.217 [Aanderaa_O2](INFO): Starting: can read until (5A bytes).
2018-10-16T05:07:49.221Z,1539666469.221 [Aanderaa_O2](ERROR): Error parsing data: 

2018-10-16T05:07:49.644Z,1539666469.644 [Aanderaa_O2](INFO): Starting
2018-10-16T05:07:49.996Z,1539666469.996 [Aanderaa_O2](INFO): Starting
2018-10-16T05:07:49.996Z,1539666469.996 [Aanderaa_O2](INFO): Starting: can read until (59 bytes).
2018-10-16T05:07:50.000Z,1539666470.000 [Aanderaa_O2](ERROR): Error parsing data: 

2018-10-16T05:07:50.401Z,1539666470.401 [Aanderaa_O2](INFO): Starting
2018-10-16T05:07:54.099Z,1539666474.099 [Aanderaa_O2](INFO): Starting
2018-10-16T05:07:54.099Z,1539666474.099 [Aanderaa_O2](INFO): Starting: can read until (59 bytes).
2018-10-16T05:07:54.105Z,1539666474.105 [Aanderaa_O2](ERROR): Error parsing data: 

2018-10-16T05:07:54.105Z,1539666474.105 [Aanderaa_O2](FAULT): Failed to initialize within timeout.
2018-10-16T05:07:54.105Z,1539666474.105 [Aanderaa_O2] Communications Fault, FailCount= 3
2018-10-16T05:07:54.105Z,1539666474.105 [Aanderaa_O2](ERROR): Communications Fault
2018-10-16T05:07:54.154Z,1539666474.154 [CBIT](ERROR): Communications Fault in component: Aanderaa_O2
2018-10-16T05:07:54.154Z,1539666474.154 [CBIT](FAULT): Communications Fault in component: Aanderaa_O2
2018-10-16T05:07:54.185Z,1539666474.185 [DataOverHttps](INFO): Sending 957 bytes from file Logs/20181016T050414/Express0001.lzma
2018-10-16T05:07:54.251Z,1539666474.251 [Aanderaa_O2](INFO): Stop
2018-10-16T05:07:54.251Z,1539666474.251 [Aanderaa_O2](INFO): Powering down
2018-10-16T05:07:54.623Z,1539666474.623 [Aanderaa_O2](INFO): Stopping
2018-10-16T05:07:54.632Z,1539666474.632 [Startup:StartupSatComms:B](INFO): Timed out from 2018-10-16T05:06:54.6Z
2018-10-16T05:07:54.632Z,1539666474.632 [Startup:StartupSatComms:B] Stopped
2018-10-16T05:07:54.633Z,1539666474.633 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2018-10-16T05:07:54.633Z,1539666474.633 [Startup:StartupSatComms] Stopped
2018-10-16T05:07:54.633Z,1539666474.633 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2018-10-16T05:07:54.634Z,1539666474.634 [Startup](INFO): Completed Startup
2018-10-16T05:07:54.634Z,1539666474.634 [MissionManager](INFO): Startup is completed.
2018-10-16T05:07:54.634Z,1539666474.634 [MissionManager](INFO): Uninitializing Mission Startup
2018-10-16T05:07:54.634Z,1539666474.634 [Startup] Stopped
2018-10-16T05:07:54.634Z,1539666474.634 [Startup](DEBUG): Aggregate::uninitialize Startup
2018-10-16T05:07:54.635Z,1539666474.635 [Startup:A.GoToSurface] Stopped
2018-10-16T05:07:54.635Z,1539666474.635 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2018-10-16T05:07:54.971Z,1539666474.971 [DataOverHttps](INFO): Moved sent file to Logs/20181016T050414/Express0001.lzma.bak
2018-10-16T05:07:54.971Z,1539666474.971 [DataOverHttps](INFO): SBD MOMSN=8715655
2018-10-16T05:07:55.067Z,1539666475.067 [Aanderaa_O2](INFO): Stopped
2018-10-16T05:07:55.107Z,1539666475.107 [MissionManager](IMPORTANT): Started mission Default
2018-10-16T05:07:55.107Z,1539666475.107 [Default] Running Loop=1
2018-10-16T05:07:55.108Z,1539666475.108 [Default](DEBUG): Aggregate::initialize Default
2018-10-16T05:07:55.108Z,1539666475.108 [Default:B.GoToSurface] Running Loop=1
2018-10-16T05:07:55.108Z,1539666475.108 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-10-16T05:07:55.108Z,1539666475.108 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2018-10-16T05:07:55.109Z,1539666475.109 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2018-10-16T05:07:55.109Z,1539666475.109 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2018-10-16T05:07:55.110Z,1539666475.110 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-10-16T05:07:55.117Z,1539666475.117 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2018-10-16T05:07:55.117Z,1539666475.117 [Default:A.Wait] Running Loop=1
2018-10-16T05:07:55.117Z,1539666475.117 [Default:A.Wait](DEBUG): Initialize Wait Component.
2018-10-16T05:08:08.195Z,1539666488.195 [Default:A.Wait](INFO): Done Waiting.
2018-10-16T05:08:08.195Z,1539666488.195 [Default:A.Wait] Stopped
2018-10-16T05:08:08.195Z,1539666488.195 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2018-10-16T05:08:08.572Z,1539666488.572 [Default:CheckIn] Running Loop=1
2018-10-16T05:08:08.572Z,1539666488.572 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-10-16T05:08:08.572Z,1539666488.572 [Default:CheckIn:Read_GPS] Running Loop=1
2018-10-16T05:08:09.030Z,1539666489.030 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2018-10-16T05:10:06.620Z,1539666606.620 [CommandLine](IMPORTANT): got command restart application
2018-10-16T05:10:06.956Z,1539666606.956 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2018-10-16T05:10:07.626Z,1539666607.626 [Supervisor](INFO): Stop Mission called by Supervisor::terminate
2018-10-16T05:10:07.631Z,1539666607.631 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2018-10-16T05:10:07.631Z,1539666607.631 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-10-16T05:10:07.634Z,1539666607.634 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2018-10-16T05:10:07.635Z,1539666607.635 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-10-16T05:10:07.636Z,1539666607.636 [CommandLine](INFO): Join timeout helper Thread ID is 5788
2018-10-16T05:10:07.639Z,1539666607.639 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2018-10-16T05:10:07.639Z,1539666607.639 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-10-16T05:10:07.639Z,1539666607.639 [NavChartDb](INFO): Join timeout helper Thread ID is 5789
2018-10-16T05:10:07.898Z,1539666607.898 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2018-10-16T05:10:07.899Z,1539666607.899 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-10-16T05:10:07.902Z,1539666607.902 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2018-10-16T05:10:07.902Z,1539666607.902 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2018-10-16T05:10:07.903Z,1539666607.903 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 5790
2018-10-16T05:10:08.027Z,1539666608.027 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2018-10-16T05:10:08.027Z,1539666608.027 [WetLabsBB2FL](INFO): Powering down
2018-10-16T05:10:08.028Z,1539666608.028 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2018-10-16T05:10:08.042Z,1539666608.042 [ComponentRegistry](INFO): Shutting down Rowe_600LCM ThreadHandler
2018-10-16T05:10:08.042Z,1539666608.042 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2018-10-16T05:10:08.043Z,1539666608.043 [Rowe_600LCM](INFO): Join timeout helper Thread ID is 5791
2018-10-16T05:10:08.659Z,1539666608.659 [Rowe_600LCM ThreadHandler](INFO): Uninitializing protected caller thread.
2018-10-16T05:10:08.659Z,1539666608.659 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-10-16T05:10:08.758Z,1539666608.758 [Rowe_600LCM](INFO): Powering down
2018-10-16T05:10:08.759Z,1539666608.759 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2018-10-16T05:10:08.774Z,1539666608.774 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2018-10-16T05:10:08.775Z,1539666608.775 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-10-16T05:10:08.775Z,1539666608.775 [Radio_Surface](INFO): Join timeout helper Thread ID is 5793
2018-10-16T05:10:08.959Z,1539666608.959 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2018-10-16T05:10:08.960Z,1539666608.960 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-10-16T05:10:08.978Z,1539666608.978 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2018-10-16T05:10:08.978Z,1539666608.978 [logger ThreadHandler](INFO): Thread cancelled.
2018-10-16T05:10:08.978Z,1539666608.978 [logger](INFO): Join timeout helper Thread ID is 5794
2018-10-16T05:10:08.978Z,1539666608.978 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2018-10-16T05:10:08.979Z,1539666608.979 [logger ThreadHandler](INFO): Thread cancelled.
2018-10-16T05:10:08.982Z,1539666608.982 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2018-10-16T05:10:08.983Z,1539666608.983 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-10-16T05:10:08.984Z,1539666608.984 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2018-10-16T05:10:08.985Z,1539666608.985 [controlThread ThreadHandler](INFO): Thread cancelled.
2018-10-16T05:10:08.988Z,1539666608.988 [controlThread](INFO): Join timeout helper Thread ID is 5795
2018-10-16T05:10:09.023Z,1539666609.023 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2018-10-16T05:10:09.024Z,1539666609.024 [controlThread](DEBUG): Uninitializing ControlThread
2018-10-16T05:10:09.024Z,1539666609.024 [NAL9602](INFO): Powering down
2018-10-16T05:10:09.026Z,1539666609.026 [PNI_TCM](INFO): Powering down
2018-10-16T05:10:09.115Z,1539666609.115 [Aanderaa_O2](INFO): Powering down
2018-10-16T05:10:09.116Z,1539666609.116 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2018-10-16T05:10:09.117Z,1539666609.117 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2018-10-16T05:10:09.117Z,1539666609.117 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2018-10-16T05:10:09.118Z,1539666609.118 [MissionManager](INFO): Uninitializing Mission Default
2018-10-16T05:10:09.118Z,1539666609.118 [Default] Stopped
2018-10-16T05:10:09.118Z,1539666609.118 [Default](DEBUG): Aggregate::uninitialize Default
2018-10-16T05:10:09.118Z,1539666609.118 [Default:B.GoToSurface] Stopped
2018-10-16T05:10:09.119Z,1539666609.119 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2018-10-16T05:10:09.119Z,1539666609.119 [Default:CheckIn] Stopped
2018-10-16T05:10:09.119Z,1539666609.119 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-10-16T05:10:09.119Z,1539666609.119 [Default:CheckIn:Read_GPS] Stopped
2018-10-16T05:10:09.122Z,1539666609.122 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2018-10-16T05:10:09.123Z,1539666609.123 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2018-10-16T05:10:09.123Z,1539666609.123 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2018-10-16T05:10:09.123Z,1539666609.123 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2018-10-16T05:10:09.123Z,1539666609.123 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2018-10-16T05:10:09.124Z,1539666609.124 [BuoyancyServo](INFO): Powering down
2018-10-16T05:10:09.139Z,1539666609.139 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2018-10-16T05:10:09.139Z,1539666609.139 [ElevatorServo](INFO): Powering down
2018-10-16T05:10:09.140Z,1539666609.140 [MassServo](DEBUG): Uninitialize Mass Servo.
2018-10-16T05:10:09.140Z,1539666609.140 [MassServo](INFO): Powering down
2018-10-16T05:10:09.141Z,1539666609.141 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2018-10-16T05:10:09.141Z,1539666609.141 [RudderServo](INFO): Powering down
2018-10-16T05:10:09.142Z,1539666609.142 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2018-10-16T05:10:09.142Z,1539666609.142 [ThrusterServo](INFO): Powering down
2018-10-16T05:10:09.143Z,1539666609.143 [SBIT](DEBUG): Uninitialize SBIT Component.
2018-10-16T05:10:09.143Z,1539666609.143 [IBIT](DEBUG): Uninitialize IBIT Component.
2018-10-16T05:10:09.143Z,1539666609.143 [CBIT](DEBUG): Uninitialize CBIT Component.
2018-10-16T05:10:09.144Z,1539666609.144 [controlThread ThreadHandler](INFO): Thread cancelled.
2018-10-16T05:10:09.197Z,1539666609.197 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2018-10-16T05:10:09.203Z,1539666609.203 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-10-16T05:10:09.245Z,1539666609.245 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2018-10-16T05:10:09.275Z,1539666609.275 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-10-16T05:10:09.334Z,1539666609.334 [logger ThreadHandler](INFO): Thread cancelled.