2019-04-02T23:16:01.676Z,1554246961.676 [Supervisor](DEBUG): Initializing supervisor.
2019-04-02T23:16:01.679Z,1554246961.679 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2019-04-02T23:16:01.679Z,1554246961.679 [SyncHandler](INFO): Protected caller Thread ID is 8459
2019-04-02T23:16:01.680Z,1554246961.680 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2019-04-02T23:16:01.681Z,1554246961.681 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2019-04-02T23:16:01.681Z,1554246961.681 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 8460
2019-04-02T23:16:01.688Z,1554246961.688 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2019-04-02T23:16:01.700Z,1554246961.700 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2019-04-02T23:16:01.701Z,1554246961.701 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2019-04-02T23:16:01.701Z,1554246961.701 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 8461
2019-04-02T23:16:01.702Z,1554246961.702 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2019-04-02T23:16:01.703Z,1554246961.703 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2019-04-02T23:16:01.704Z,1554246961.704 [logger ThreadHandler](INFO): Protected caller Thread ID is 8462
2019-04-02T23:16:01.706Z,1554246961.706 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2019-04-02T23:16:01.706Z,1554246961.706 [Supervisor](INFO): Looking for Config files in directory: Config/
2019-04-02T23:16:01.708Z,1554246961.708 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2019-04-02T23:16:01.840Z,1554246961.840 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2019-04-02T23:16:01.840Z,1554246961.840 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2019-04-02T23:16:02.296Z,1554246962.296 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2019-04-02T23:16:02.297Z,1554246962.297 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2019-04-02T23:16:02.395Z,1554246962.395 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2019-04-02T23:16:02.396Z,1554246962.396 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2019-04-02T23:16:02.501Z,1554246962.501 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2019-04-02T23:16:02.501Z,1554246962.501 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2019-04-02T23:16:02.584Z,1554246962.584 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2019-04-02T23:16:02.726Z,1554246962.726 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2019-04-02T23:16:02.726Z,1554246962.726 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2019-04-02T23:16:03.024Z,1554246963.024 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2019-04-02T23:16:03.025Z,1554246963.025 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2019-04-02T23:16:03.485Z,1554246963.485 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2019-04-02T23:16:03.485Z,1554246963.485 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2019-04-02T23:16:03.633Z,1554246963.633 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2019-04-02T23:16:03.634Z,1554246963.634 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2019-04-02T23:16:03.831Z,1554246963.831 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2019-04-02T23:16:03.832Z,1554246963.832 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2019-04-02T23:16:04.291Z,1554246964.291 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2019-04-02T23:16:04.292Z,1554246964.292 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2019-04-02T23:16:04.507Z,1554246964.507 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2019-04-02T23:16:04.508Z,1554246964.508 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2019-04-02T23:16:04.711Z,1554246964.711 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2019-04-02T23:16:04.712Z,1554246964.712 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2019-04-02T23:16:05.110Z,1554246965.110 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2019-04-02T23:16:05.110Z,1554246965.110 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2019-04-02T23:16:05.448Z,1554246965.448 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2019-04-02T23:16:05.450Z,1554246965.450 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-pontus/
2019-04-02T23:16:05.451Z,1554246965.451 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/secure.cfg
2019-04-02T23:16:05.535Z,1554246965.535 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Sensor.cfg
2019-04-02T23:16:05.685Z,1554246965.685 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Servo.cfg
2019-04-02T23:16:05.795Z,1554246965.795 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Simulator.cfg
2019-04-02T23:16:05.880Z,1554246965.880 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/logger.cfg
2019-04-02T23:16:05.975Z,1554246965.975 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/vehicle.cfg
2019-04-02T23:16:06.157Z,1554246966.157 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Battery.cfg
2019-04-02T23:16:06.386Z,1554246966.386 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2019-04-02T23:16:06.387Z,1554246966.387 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Navigation.cfg
2019-04-02T23:16:06.481Z,1554246966.481 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/BIT.cfg
2019-04-02T23:16:06.581Z,1554246966.581 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Science.cfg
2019-04-02T23:16:06.727Z,1554246966.727 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Control.cfg
2019-04-02T23:16:07.068Z,1554246967.068 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2019-04-02T23:16:07.070Z,1554246967.070 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2019-04-02T23:16:07.234Z,1554246967.234 [VerticalControl](DEBUG): Construct VerticalControl.
2019-04-02T23:16:07.616Z,1554246967.616 [VerticalControl] Loaded
2019-04-02T23:16:07.616Z,1554246967.616 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2019-04-02T23:16:07.617Z,1554246967.617 [HorizontalControl](DEBUG): Construct HorizontalControl.
2019-04-02T23:16:07.686Z,1554246967.686 [HorizontalControl] Loaded
2019-04-02T23:16:07.686Z,1554246967.686 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2019-04-02T23:16:07.686Z,1554246967.686 [SpeedControl](DEBUG): Construct SpeedControl.
2019-04-02T23:16:07.692Z,1554246967.692 [SpeedControl] Loaded
2019-04-02T23:16:07.692Z,1554246967.692 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2019-04-02T23:16:07.693Z,1554246967.693 [LoopControl](DEBUG): Construct LoopControl.
2019-04-02T23:16:07.693Z,1554246967.693 [LoopControl] Loaded
2019-04-02T23:16:07.694Z,1554246967.694 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2019-04-02T23:16:07.694Z,1554246967.694 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2019-04-02T23:16:07.695Z,1554246967.695 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2019-04-02T23:16:07.736Z,1554246967.736 [DepthRateCalculator] Loaded
2019-04-02T23:16:07.736Z,1554246967.736 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2019-04-02T23:16:07.742Z,1554246967.742 [PitchRateCalculator] Loaded
2019-04-02T23:16:07.742Z,1554246967.742 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2019-04-02T23:16:07.757Z,1554246967.757 [SpeedCalculator] Loaded
2019-04-02T23:16:07.758Z,1554246967.758 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2019-04-02T23:16:07.779Z,1554246967.779 [TempGradientCalculator] Loaded
2019-04-02T23:16:07.780Z,1554246967.780 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2019-04-02T23:16:07.785Z,1554246967.785 [YawRateCalculator] Loaded
2019-04-02T23:16:07.785Z,1554246967.785 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2019-04-02T23:16:07.814Z,1554246967.814 [ElevatorOffsetCalculator] Loaded
2019-04-02T23:16:07.814Z,1554246967.814 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2019-04-02T23:16:07.815Z,1554246967.815 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2019-04-02T23:16:07.815Z,1554246967.815 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2019-04-02T23:16:07.843Z,1554246967.843 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2019-04-02T23:16:07.843Z,1554246967.843 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2019-04-02T23:16:07.912Z,1554246967.912 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2019-04-02T23:16:07.912Z,1554246967.912 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2019-04-02T23:16:08.187Z,1554246968.187 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2019-04-02T23:16:08.187Z,1554246968.187 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2019-04-02T23:16:08.288Z,1554246968.288 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2019-04-02T23:16:08.289Z,1554246968.289 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2019-04-02T23:16:08.772Z,1554246968.772 [AHRS_M2] Loaded
2019-04-02T23:16:08.773Z,1554246968.773 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2019-04-02T23:16:08.873Z,1554246968.873 [DataOverHttps] Loaded
2019-04-02T23:16:08.874Z,1554246968.874 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2019-04-02T23:16:08.875Z,1554246968.875 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 408B64E0
2019-04-02T23:16:08.875Z,1554246968.875 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 8541
2019-04-02T23:16:08.889Z,1554246968.889 [Depth_Keller] Loaded
2019-04-02T23:16:08.889Z,1554246968.889 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2019-04-02T23:16:08.894Z,1554246968.894 [DropWeight] Loaded
2019-04-02T23:16:08.894Z,1554246968.894 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2019-04-02T23:16:08.992Z,1554246968.992 [NAL9602] Loaded
2019-04-02T23:16:08.992Z,1554246968.992 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2019-04-02T23:16:09.008Z,1554246969.008 [Onboard] Loaded
2019-04-02T23:16:09.008Z,1554246969.008 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2019-04-02T23:16:09.011Z,1554246969.011 [Radio_Surface] Loaded
2019-04-02T23:16:09.012Z,1554246969.012 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2019-04-02T23:16:09.013Z,1554246969.013 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408E64E0
2019-04-02T23:16:09.013Z,1554246969.013 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 8542
2019-04-02T23:16:10.498Z,1554246970.498 [BPC1] Loaded
2019-04-02T23:16:10.498Z,1554246970.498 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2019-04-02T23:16:10.498Z,1554246970.498 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2019-04-02T23:16:10.499Z,1554246970.499 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2019-04-02T23:16:10.602Z,1554246970.602 [DeadReckonUsingMultipleVelocitySources] Loaded
2019-04-02T23:16:10.603Z,1554246970.603 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2019-04-02T23:16:10.663Z,1554246970.663 [DeadReckonUsingSpeedCalculator] Loaded
2019-04-02T23:16:10.663Z,1554246970.663 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2019-04-02T23:16:10.684Z,1554246970.684 [NavChart] Loaded
2019-04-02T23:16:10.684Z,1554246970.684 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2019-04-02T23:16:10.688Z,1554246970.688 [UniversalFixResidualReporter] Loaded
2019-04-02T23:16:10.689Z,1554246970.689 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2019-04-02T23:16:10.689Z,1554246970.689 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2019-04-02T23:16:10.690Z,1554246970.690 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2019-04-02T23:16:10.851Z,1554246970.851 [SBIT](DEBUG): Construct Startup Built In Test.
2019-04-02T23:16:10.862Z,1554246970.862 [SBIT] Loaded
2019-04-02T23:16:10.862Z,1554246970.862 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2019-04-02T23:16:10.863Z,1554246970.863 [IBIT](DEBUG): Construct Initiated Built In Test.
2019-04-02T23:16:10.875Z,1554246970.875 [IBIT] Loaded
2019-04-02T23:16:10.875Z,1554246970.875 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2019-04-02T23:16:10.878Z,1554246970.878 [CBIT](DEBUG): Construct Continuous Built In Test.
2019-04-02T23:16:11.017Z,1554246971.017 [CBIT] Loaded
2019-04-02T23:16:11.017Z,1554246971.017 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2019-04-02T23:16:11.018Z,1554246971.018 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2019-04-02T23:16:11.018Z,1554246971.018 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2019-04-02T23:16:11.116Z,1554246971.116 [BuoyancyServo] Loaded
2019-04-02T23:16:11.117Z,1554246971.117 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2019-04-02T23:16:11.128Z,1554246971.128 [ElevatorServo] Loaded
2019-04-02T23:16:11.129Z,1554246971.129 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2019-04-02T23:16:11.139Z,1554246971.139 [MassServo] Loaded
2019-04-02T23:16:11.140Z,1554246971.140 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2019-04-02T23:16:11.151Z,1554246971.151 [RudderServo] Loaded
2019-04-02T23:16:11.151Z,1554246971.151 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2019-04-02T23:16:11.162Z,1554246971.162 [ThrusterServo] Loaded
2019-04-02T23:16:11.162Z,1554246971.162 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2019-04-02T23:16:11.163Z,1554246971.163 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2019-04-02T23:16:11.163Z,1554246971.163 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2019-04-02T23:16:11.187Z,1554246971.187 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2019-04-02T23:16:11.187Z,1554246971.187 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2019-04-02T23:16:11.509Z,1554246971.509 [CTD_NeilBrown] Loaded
2019-04-02T23:16:11.509Z,1554246971.509 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2019-04-02T23:16:11.510Z,1554246971.510 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 40A654E0
2019-04-02T23:16:11.511Z,1554246971.511 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 8543
2019-04-02T23:16:11.520Z,1554246971.520 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_density
2019-04-02T23:16:11.525Z,1554246971.525 [CTD_Seabird](INFO): created writer for : sea_water_density
2019-04-02T23:16:11.528Z,1554246971.528 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): depth
2019-04-02T23:16:11.533Z,1554246971.533 [CTD_Seabird](INFO): created writer for : depth
2019-04-02T23:16:11.533Z,1554246971.533 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_pressure
2019-04-02T23:16:11.538Z,1554246971.538 [CTD_Seabird](INFO): created writer for : sea_water_pressure
2019-04-02T23:16:11.539Z,1554246971.539 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_salinity
2019-04-02T23:16:11.544Z,1554246971.544 [CTD_Seabird](INFO): created writer for : sea_water_salinity
2019-04-02T23:16:11.544Z,1554246971.544 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_temperature
2019-04-02T23:16:11.550Z,1554246971.550 [CTD_Seabird](INFO): created writer for : sea_water_temperature
2019-04-02T23:16:11.551Z,1554246971.551 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_electrical_conductivity
2019-04-02T23:16:11.556Z,1554246971.556 [CTD_Seabird](INFO): created writer for : sea_water_electrical_conductivity
2019-04-02T23:16:11.557Z,1554246971.557 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): speed_of_sound_in_sea_water
2019-04-02T23:16:11.561Z,1554246971.561 [CTD_Seabird](INFO): created writer for : speed_of_sound_in_sea_water
2019-04-02T23:16:11.588Z,1554246971.588 [CTD_Seabird] Loaded
2019-04-02T23:16:11.588Z,1554246971.588 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2019-04-02T23:16:11.589Z,1554246971.589 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40A954E0
2019-04-02T23:16:11.590Z,1554246971.590 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 8544
2019-04-02T23:16:11.637Z,1554246971.637 [WetLabsBB2FL] Loaded
2019-04-02T23:16:11.638Z,1554246971.638 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2019-04-02T23:16:11.639Z,1554246971.639 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40AC54E0
2019-04-02T23:16:11.639Z,1554246971.639 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 8545
2019-04-02T23:16:11.640Z,1554246971.640 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2019-04-02T23:16:11.644Z,1554246971.644 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2019-04-02T23:16:11.644Z,1554246971.644 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2019-04-02T23:16:11.651Z,1554246971.651 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2019-04-02T23:16:11.652Z,1554246971.652 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40AF54E0
2019-04-02T23:16:11.653Z,1554246971.653 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 8546
2019-04-02T23:16:11.658Z,1554246971.658 [Supervisor](INFO): Main Thread ID is 8458
2019-04-02T23:16:11.658Z,1554246971.658 [Supervisor](DEBUG): Running supervisor.
2019-04-02T23:16:11.658Z,1554246971.658 [CommandLine ThreadHandler](INFO): Handler Thread ID is 8547
2019-04-02T23:16:11.661Z,1554246971.661 [controlThread ThreadHandler](INFO): Handler Thread ID is 8548
2019-04-02T23:16:11.661Z,1554246971.661 [controlThread](DEBUG): Initializing ControlThread
2019-04-02T23:16:11.662Z,1554246971.662 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2019-04-02T23:16:11.664Z,1554246971.664 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2019-04-02T23:16:11.665Z,1554246971.665 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2019-04-02T23:16:11.665Z,1554246971.665 [LoopControl](DEBUG): Initialize LoopControlComponent.
2019-04-02T23:16:11.666Z,1554246971.666 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2019-04-02T23:16:11.666Z,1554246971.666 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2019-04-02T23:16:11.666Z,1554246971.666 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2019-04-02T23:16:11.667Z,1554246971.667 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2019-04-02T23:16:11.667Z,1554246971.667 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2019-04-02T23:16:11.668Z,1554246971.668 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2019-04-02T23:16:11.674Z,1554246971.674 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2019-04-02T23:16:11.674Z,1554246971.674 [NavChart](DEBUG): Initialize NavChart Navigation.
2019-04-02T23:16:11.675Z,1554246971.675 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2019-04-02T23:16:11.675Z,1554246971.675 [SBIT](INFO): Initialize SBIT Component.
2019-04-02T23:16:11.676Z,1554246971.676 [SBIT](IMPORTANT): git: 2019-03-18-31-ge98d5dc
2019-04-02T23:16:11.676Z,1554246971.676 [SBIT](INFO): git hash: e98d5dc50cbc39e402f19b9946ff4dc0776c8725
2019-04-02T23:16:11.676Z,1554246971.676 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2019-04-02T23:16:11.677Z,1554246971.677 [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-04-02T23:16:11.679Z,1554246971.679 [SBIT](INFO): Beginning SBIT in 28.000000 seconds.
2019-04-02T23:16:11.679Z,1554246971.679 [IBIT](INFO): Initialize IBIT Component.
2019-04-02T23:16:11.680Z,1554246971.680 [CBIT](DEBUG): Initialize CBIT Component.
2019-04-02T23:16:11.681Z,1554246971.681 [logger ThreadHandler](INFO): Handler Thread ID is 8549
2019-04-02T23:16:11.691Z,1554246971.691 [CBIT](DEBUG): Initialized mux pins.
2019-04-02T23:16:11.691Z,1554246971.691 [CBIT](DEBUG): Initializing the watchdog timer.
2019-04-02T23:16:11.699Z,1554246971.699 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 8550
2019-04-02T23:16:11.700Z,1554246971.700 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2019-04-02T23:16:11.711Z,1554246971.711 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 8551
2019-04-02T23:16:11.715Z,1554246971.715 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2019-04-02T23:16:11.715Z,1554246971.715 [CBIT](DEBUG): Initializing heartbeat.
2019-04-02T23:16:11.723Z,1554246971.723 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 8552
2019-04-02T23:16:11.735Z,1554246971.735 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 8553
2019-04-02T23:16:11.736Z,1554246971.736 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2019-04-02T23:16:11.739Z,1554246971.739 [CTD_Seabird](INFO): Opening uart, block timeout 10ths=20
2019-04-02T23:16:11.740Z,1554246971.740 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 8555
2019-04-02T23:16:11.742Z,1554246971.742 [WetLabsBB2FL](INFO): Powering down
2019-04-02T23:16:11.771Z,1554246971.771 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 8556
2019-04-02T23:16:11.773Z,1554246971.773 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2019-04-02T23:16:11.775Z,1554246971.775 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US1WC07M.000
2019-04-02T23:16:11.777Z,1554246971.777 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2019-04-02T23:16:11.787Z,1554246971.787 [CBIT](DEBUG): Deactivating GF circuits.
2019-04-02T23:16:11.787Z,1554246971.787 [CBIT](DEBUG): Deactivating emergency mode.
2019-04-02T23:16:11.823Z,1554246971.823 [CBIT](DEBUG): Backplane powered.
2019-04-02T23:16:11.825Z,1554246971.825 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2019-04-02T23:16:11.852Z,1554246971.852 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US2WC11M.000
2019-04-02T23:16:11.852Z,1554246971.852 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2019-04-02T23:16:11.854Z,1554246971.854 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US3CA52M.000
2019-04-02T23:16:11.854Z,1554246971.854 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2019-04-02T23:16:11.867Z,1554246971.867 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2019-04-02T23:16:11.887Z,1554246971.887 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US4CA60M.000
2019-04-02T23:16:11.888Z,1554246971.888 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2019-04-02T23:16:11.889Z,1554246971.889 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US5CA50M.000
2019-04-02T23:16:11.889Z,1554246971.889 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2019-04-02T23:16:11.891Z,1554246971.891 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US5CA61M.000
2019-04-02T23:16:11.891Z,1554246971.891 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2019-04-02T23:16:11.893Z,1554246971.893 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US5CA62M.000
2019-04-02T23:16:11.893Z,1554246971.893 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2019-04-02T23:16:11.907Z,1554246971.907 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US5CA83M.000
2019-04-02T23:16:11.909Z,1554246971.909 [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-04-02T23:16:11.910Z,1554246971.910 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2019-04-02T23:16:11.912Z,1554246971.912 [NavChartDb](INFO): Setup scan of Resources/ElectronicNavigationCharts/US5CA83M.000
2019-04-02T23:16:11.970Z,1554246971.970 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2019-04-02T23:16:11.971Z,1554246971.971 [Default:A.Wait](DEBUG): Construct Wait.
2019-04-02T23:16:11.973Z,1554246971.973 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2019-04-02T23:16:11.985Z,1554246971.985 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2019-04-02T23:16:12.006Z,1554246972.006 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2019-04-02T23:16:12.012Z,1554246972.012 [Default:E.Execute](DEBUG): Construct Execute.
2019-04-02T23:16:12.038Z,1554246972.038 [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-04-02T23:16:12.042Z,1554246972.042 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,NAL9602,Onboard,BPC1,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2019-04-02T23:16:12.051Z,1554246972.051 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2019-04-02T23:16:12.115Z,1554246972.115 [Radio_Surface](INFO): Powering up
2019-04-02T23:16:12.802Z,1554246972.802 [Depth_Keller](ERROR): Pressure reading out of range: 1925.893799 decibar
2019-04-02T23:16:12.856Z,1554246972.856 [DepthRateCalculator](ERROR): Depth measurement is not active
2019-04-02T23:16:13.000Z,1554246973.000 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2019-04-02T23:16:13.007Z,1554246973.007 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2019-04-02T23:16:13.008Z,1554246973.008 [ElevatorServo](DEBUG): Initializing EZServoServo.
2019-04-02T23:16:13.015Z,1554246973.015 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2019-04-02T23:16:13.016Z,1554246973.016 [MassServo](DEBUG): Initializing EZServoServo.
2019-04-02T23:16:13.023Z,1554246973.023 [MassServo](DEBUG): Initializing MassServo.
2019-04-02T23:16:13.024Z,1554246973.024 [RudderServo](DEBUG): Initializing EZServoServo.
2019-04-02T23:16:13.031Z,1554246973.031 [RudderServo](DEBUG): Initializing RudderServo.
2019-04-02T23:16:13.032Z,1554246973.032 [ThrusterServo](DEBUG): Initializing EZServoServo.
2019-04-02T23:16:13.039Z,1554246973.039 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2019-04-02T23:16:13.252Z,1554246973.252 [DropWeight](CRITICAL): DROP WEIGHT MISSING.

2019-04-02T23:16:13.252Z,1554246973.252 [DropWeight] Hardware Fault, FailCount= 1
2019-04-02T23:16:13.252Z,1554246973.252 [DropWeight](ERROR): Hardware Fault
2019-04-02T23:16:13.330Z,1554246973.330 [CommandLine](FAULT): Scheduling is paused
2019-04-02T23:16:13.331Z,1554246973.331 [CBIT](INFO): Critical error at 20190402T231613
2019-04-02T23:16:13.331Z,1554246973.331 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2019-04-02T23:16:13.334Z,1554246973.334 [CBIT](ERROR): Hardware Fault in component: DropWeight
2019-04-02T23:16:13.351Z,1554246973.351 [CBIT](CRITICAL): Hardware Fault in component: DropWeight
2019-04-02T23:16:13.500Z,1554246973.500 [CBIT](INFO): Critical error at 20190402T231613
2019-04-02T23:16:17.927Z,1554246977.927 [AHRS_M2](ERROR): Subscribe Roll UART error: serial timeout
2019-04-02T23:16:18.351Z,1554246978.351 [AHRS_M2](ERROR): Subscribe Roll UART error: serial timeout
2019-04-02T23:16:18.775Z,1554246978.775 [AHRS_M2](ERROR): Subscribe Roll UART error: serial timeout
2019-04-02T23:16:19.223Z,1554246979.223 [AHRS_M2](ERROR): Subscribe Roll UART error: serial timeout
2019-04-02T23:16:19.643Z,1554246979.643 [AHRS_M2](ERROR): Subscribe Roll UART error: serial timeout
2019-04-02T23:16:20.135Z,1554246980.135 [AHRS_M2](ERROR): Subscribe Roll UART error: serial timeout
2019-04-02T23:16:20.591Z,1554246980.591 [AHRS_M2](ERROR): Subscribe Roll UART error: serial timeout
2019-04-02T23:16:21.011Z,1554246981.011 [AHRS_M2](ERROR): Subscribe Roll UART error: serial timeout
2019-04-02T23:16:21.503Z,1554246981.503 [AHRS_M2](ERROR): Subscribe Roll UART error: serial timeout
2019-04-02T23:16:21.927Z,1554246981.927 [AHRS_M2](ERROR): Subscribe Roll UART error: serial timeout
2019-04-02T23:16:22.023Z,1554246982.023 [CBIT](CRITICAL): Environmental Failure. Press:14.408415 PSI. Humidity:45%. Temp:25 C. ABORTING MISSION
2019-04-02T23:16:22.355Z,1554246982.355 [AHRS_M2](ERROR): Subscribe Roll UART error: serial timeout
2019-04-02T23:16:22.445Z,1554246982.445 [CBIT](INFO): Critical error at 20190402T231622
2019-04-02T23:16:22.771Z,1554246982.771 [AHRS_M2](ERROR): Subscribe Roll UART error: serial timeout
2019-04-02T23:16:23.019Z,1554246983.019 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.039069
2019-04-02T23:16:23.195Z,1554246983.195 [AHRS_M2](ERROR): Subscribe Roll UART error: serial timeout
2019-04-02T23:16:23.607Z,1554246983.607 [AHRS_M2](ERROR): Subscribe Roll UART error: serial timeout
2019-04-02T23:16:24.019Z,1554246984.019 [AHRS_M2](ERROR): Subscribe Roll UART error: serial timeout
2019-04-02T23:16:24.439Z,1554246984.439 [AHRS_M2](ERROR): Subscribe Roll UART error: serial timeout
2019-04-02T23:16:24.787Z,1554246984.787 [CTD_Seabird](FAULT): Failed to initialize within timeout.
2019-04-02T23:16:24.787Z,1554246984.787 [CTD_Seabird] Communications Fault, FailCount= 1
2019-04-02T23:16:24.787Z,1554246984.787 [CTD_Seabird](ERROR): Communications Fault
2019-04-02T23:16:24.851Z,1554246984.851 [AHRS_M2](ERROR): Subscribe Roll UART error: serial timeout
2019-04-02T23:16:24.947Z,1554246984.947 [CBIT](ERROR): Communications Fault in component: CTD_Seabird
2019-04-02T23:16:25.191Z,1554246985.191 [CTD_Seabird](INFO): Powering down
2019-04-02T23:16:25.271Z,1554246985.271 [AHRS_M2](ERROR): Subscribe Roll UART error: serial timeout
2019-04-02T23:16:25.695Z,1554246985.695 [AHRS_M2](ERROR): Subscribe Roll UART error: serial timeout
2019-04-02T23:16:25.695Z,1554246985.695 [AHRS_M2](FAULT): Failed to initialize within timeout.
2019-04-02T23:16:25.695Z,1554246985.695 [AHRS_M2] Communications Fault, FailCount= 1
2019-04-02T23:16:25.695Z,1554246985.695 [AHRS_M2](ERROR): Communications Fault
2019-04-02T23:16:25.783Z,1554246985.783 [CBIT](ERROR): Communications Fault in component: AHRS_M2
2019-04-02T23:16:25.788Z,1554246985.788 [AHRS_M2](INFO): Powering down
2019-04-02T23:16:26.287Z,1554246986.287 [CBIT](INFO): Clearing failed state for component CTD_Seabird
2019-04-02T23:16:26.287Z,1554246986.287 [CTD_Seabird] No Fault, FailCount= 1
2019-04-02T23:16:26.555Z,1554246986.555 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2019-04-02T23:16:26.557Z,1554246986.557 [CTD_Seabird](INFO): Opening uart, block timeout 10ths=20
2019-04-02T23:16:26.722Z,1554246986.722 [CBIT](INFO): Clearing failed state for component AHRS_M2
2019-04-02T23:16:26.723Z,1554246986.723 [AHRS_M2] No Fault, FailCount= 1
2019-04-02T23:16:26.999Z,1554246986.999 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2019-04-02T23:16:29.317Z,1554246989.317 [NavChartDb](INFO): Done scanning features of Resources/ElectronicNavigationCharts/US5CA83M.000
2019-04-02T23:16:30.555Z,1554246990.555 [AHRS_M2](ERROR): Subscribe Roll UART error: serial timeout
2019-04-02T23:16:30.991Z,1554246990.991 [AHRS_M2](ERROR): Subscribe Roll UART error: serial timeout
2019-04-02T23:16:31.411Z,1554246991.411 [AHRS_M2](ERROR): Subscribe Roll UART error: serial timeout
2019-04-02T23:16:31.815Z,1554246991.815 [AHRS_M2](ERROR): Subscribe Roll UART error: serial timeout
2019-04-02T23:16:32.239Z,1554246992.239 [AHRS_M2](ERROR): Subscribe Roll UART error: serial timeout
2019-04-02T23:16:32.675Z,1554246992.675 [AHRS_M2](ERROR): Subscribe Roll UART error: serial timeout
2019-04-02T23:16:33.111Z,1554246993.111 [AHRS_M2](ERROR): Subscribe Roll UART error: serial timeout
2019-04-02T23:16:33.527Z,1554246993.527 [AHRS_M2](ERROR): Subscribe Roll UART error: serial timeout
2019-04-02T23:16:33.963Z,1554246993.963 [AHRS_M2](ERROR): Subscribe Roll UART error: serial timeout
2019-04-02T23:16:34.427Z,1554246994.427 [AHRS_M2](ERROR): Subscribe Roll UART error: serial timeout
2019-04-02T23:16:34.875Z,1554246994.875 [AHRS_M2](ERROR): Subscribe Roll UART error: serial timeout
2019-04-02T23:16:35.295Z,1554246995.295 [AHRS_M2](ERROR): Subscribe Roll UART error: serial timeout
2019-04-02T23:16:35.707Z,1554246995.707 [AHRS_M2](ERROR): Subscribe Roll UART error: serial timeout
2019-04-02T23:16:36.127Z,1554246996.127 [AHRS_M2](ERROR): Subscribe Roll UART error: serial timeout
2019-04-02T23:16:36.567Z,1554246996.567 [AHRS_M2](ERROR): Subscribe Roll UART error: serial timeout
2019-04-02T23:16:37.027Z,1554246997.027 [AHRS_M2](ERROR): Subscribe Roll UART error: serial timeout
2019-04-02T23:16:37.459Z,1554246997.459 [AHRS_M2](ERROR): Subscribe Roll UART error: serial timeout
2019-04-02T23:16:37.875Z,1554246997.875 [AHRS_M2](ERROR): Subscribe Roll UART error: serial timeout
2019-04-02T23:16:38.327Z,1554246998.327 [AHRS_M2](ERROR): Subscribe Roll UART error: serial timeout
2019-04-02T23:16:38.759Z,1554246998.759 [AHRS_M2](ERROR): Subscribe Roll UART error: serial timeout
2019-04-02T23:16:39.187Z,1554246999.187 [AHRS_M2](ERROR): Subscribe Roll UART error: serial timeout
2019-04-02T23:16:39.189Z,1554246999.189 [NAL9602](INFO): Powering up NAL9602
2019-04-02T23:16:39.607Z,1554246999.607 [CTD_Seabird](FAULT): Failed to initialize within timeout.
2019-04-02T23:16:39.607Z,1554246999.607 [CTD_Seabird] Communications Fault, FailCount= 2
2019-04-02T23:16:39.607Z,1554246999.607 [CTD_Seabird](ERROR): Communications Fault
2019-04-02T23:16:39.627Z,1554246999.627 [AHRS_M2](ERROR): Subscribe Roll UART error: serial timeout
2019-04-02T23:16:39.759Z,1554246999.759 [CBIT](ERROR): Communications Fault in component: CTD_Seabird
2019-04-02T23:16:40.011Z,1554247000.011 [CTD_Seabird](INFO): Powering down
2019-04-02T23:16:40.095Z,1554247000.095 [AHRS_M2](ERROR): Subscribe Roll UART error: serial timeout
2019-04-02T23:16:40.095Z,1554247000.095 [AHRS_M2](FAULT): Failed to initialize within timeout.
2019-04-02T23:16:40.095Z,1554247000.095 [AHRS_M2] Communications Fault, FailCount= 2
2019-04-02T23:16:40.095Z,1554247000.095 [AHRS_M2](ERROR): Communications Fault
2019-04-02T23:16:40.176Z,1554247000.176 [SBIT](IMPORTANT): Beginning Startup BIT
2019-04-02T23:16:40.197Z,1554247000.197 [CBIT](ERROR): Communications Fault in component: AHRS_M2
2019-04-02T23:16:40.197Z,1554247000.197 [CBIT](IMPORTANT): Beginning ground fault scan
2019-04-02T23:16:40.207Z,1554247000.207 [AHRS_M2](INFO): Powering down
2019-04-02T23:16:41.140Z,1554247001.140 [CBIT](INFO): Clearing failed state for component AHRS_M2
2019-04-02T23:16:41.140Z,1554247001.140 [AHRS_M2] No Fault, FailCount= 2
2019-04-02T23:16:41.141Z,1554247001.141 [CBIT](INFO): Clearing failed state for component CTD_Seabird
2019-04-02T23:16:41.141Z,1554247001.141 [CTD_Seabird] No Fault, FailCount= 2
2019-04-02T23:16:41.355Z,1554247001.355 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2019-04-02T23:16:41.356Z,1554247001.356 [CTD_Seabird](INFO): Opening uart, block timeout 10ths=20
2019-04-02T23:16:41.411Z,1554247001.411 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2019-04-02T23:16:44.967Z,1554247004.967 [AHRS_M2](ERROR): Subscribe Roll UART error: serial timeout
2019-04-02T23:16:45.627Z,1554247005.627 [AHRS_M2](ERROR): Subscribe Roll UART error: serial timeout
2019-04-02T23:16:46.047Z,1554247006.047 [AHRS_M2](ERROR): Subscribe Roll UART error: serial timeout
2019-04-02T23:16:46.463Z,1554247006.463 [AHRS_M2](ERROR): Subscribe Roll UART error: serial timeout
2019-04-02T23:16:46.887Z,1554247006.887 [AHRS_M2](ERROR): Subscribe Roll UART error: serial timeout
2019-04-02T23:16:47.415Z,1554247007.415 [AHRS_M2](ERROR): Subscribe Roll UART error: serial timeout
2019-04-02T23:16:47.835Z,1554247007.835 [AHRS_M2](ERROR): Subscribe Roll UART error: serial timeout
2019-04-02T23:16:48.247Z,1554247008.247 [AHRS_M2](ERROR): Subscribe Roll UART error: serial timeout
2019-04-02T23:16:48.763Z,1554247008.763 [AHRS_M2](ERROR): Subscribe Roll UART error: serial timeout
2019-04-02T23:16:49.091Z,1554247009.091 [CommandLine](IMPORTANT): got command quit
2019-04-02T23:16:49.191Z,1554247009.191 [AHRS_M2](ERROR): Subscribe Roll UART error: serial timeout
2019-04-02T23:16:49.631Z,1554247009.631 [AHRS_M2](ERROR): Subscribe Roll UART error: serial timeout
2019-04-02T23:16:50.095Z,1554247010.095 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2019-04-02T23:16:50.095Z,1554247010.095 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-04-02T23:16:50.167Z,1554247010.167 [AHRS_M2](ERROR): Subscribe Roll UART error: serial timeout
2019-04-02T23:16:50.215Z,1554247010.215 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2019-04-02T23:16:50.215Z,1554247010.215 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-04-02T23:16:50.216Z,1554247010.216 [CommandLine](INFO): Join timeout helper Thread ID is 8569
2019-04-02T23:16:50.230Z,1554247010.230 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2019-04-02T23:16:50.232Z,1554247010.232 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-04-02T23:16:50.237Z,1554247010.237 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2019-04-02T23:16:50.238Z,1554247010.238 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-04-02T23:16:50.239Z,1554247010.239 [NavChartDb](INFO): Join timeout helper Thread ID is 8570
2019-04-02T23:16:50.255Z,1554247010.255 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2019-04-02T23:16:50.255Z,1554247010.255 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-04-02T23:16:50.255Z,1554247010.255 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 8571
2019-04-02T23:16:50.575Z,1554247010.575 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2019-04-02T23:16:50.576Z,1554247010.576 [WetLabsBB2FL](INFO): Powering down
2019-04-02T23:16:50.576Z,1554247010.576 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-04-02T23:16:50.583Z,1554247010.583 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2019-04-02T23:16:50.583Z,1554247010.583 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2019-04-02T23:16:50.583Z,1554247010.583 [CTD_Seabird](INFO): Join timeout helper Thread ID is 8572
2019-04-02T23:16:50.647Z,1554247010.647 [AHRS_M2](ERROR): Subscribe Roll UART error: serial timeout
2019-04-02T23:16:51.083Z,1554247011.083 [AHRS_M2](ERROR): Subscribe Roll UART error: serial timeout
2019-04-02T23:16:51.395Z,1554247011.395 [CTD_Seabird](INFO): Powering down
2019-04-02T23:16:51.527Z,1554247011.527 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2019-04-02T23:16:51.527Z,1554247011.527 [CTD_Seabird](INFO): Powering down
2019-04-02T23:16:51.539Z,1554247011.539 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2019-04-02T23:16:51.543Z,1554247011.543 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2019-04-02T23:16:51.543Z,1554247011.543 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-04-02T23:16:51.543Z,1554247011.543 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 8573
2019-04-02T23:16:51.555Z,1554247011.555 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread.
2019-04-02T23:16:51.555Z,1554247011.555 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-04-02T23:16:51.557Z,1554247011.557 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2019-04-02T23:16:51.557Z,1554247011.557 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-04-02T23:16:51.557Z,1554247011.557 [Radio_Surface](INFO): Join timeout helper Thread ID is 8574
2019-04-02T23:16:51.611Z,1554247011.611 [AHRS_M2](ERROR): Subscribe Roll UART error: serial timeout
2019-04-02T23:16:51.719Z,1554247011.719 [Radio_Surface](INFO): Powering down
2019-04-02T23:16:51.720Z,1554247011.720 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2019-04-02T23:16:51.720Z,1554247011.720 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-04-02T23:16:51.740Z,1554247011.740 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2019-04-02T23:16:51.740Z,1554247011.740 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-04-02T23:16:51.740Z,1554247011.740 [DataOverHttps](INFO): Join timeout helper Thread ID is 8575
2019-04-02T23:16:51.751Z,1554247011.751 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): 0.000322
CHAN A1 (24V): 0.003142
CHAN A2 (12V): -0.007109
CHAN A3 (5V): -0.002195
CHAN B0 (3.3V): -0.000178
CHAN B1 (3.15aV): 0.000037
CHAN B2 (3.15bV): 0.000145
CHAN B3 (GND): 0.001921
OPEN: -0.000895
Full Scale Calc: 4.765 mA, -1.589 mA
2019-04-02T23:16:52.081Z,1554247012.081 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2019-04-02T23:16:52.083Z,1554247012.083 [AHRS_M2](ERROR): Subscribe Roll UART error: serial timeout
2019-04-02T23:16:52.103Z,1554247012.103 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-04-02T23:16:52.120Z,1554247012.120 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2019-04-02T23:16:52.120Z,1554247012.120 [logger ThreadHandler](INFO): Thread cancelled.
2019-04-02T23:16:52.120Z,1554247012.120 [logger](INFO): Join timeout helper Thread ID is 8576
2019-04-02T23:16:52.148Z,1554247012.148 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2019-04-02T23:16:52.149Z,1554247012.149 [logger ThreadHandler](INFO): Thread cancelled.
2019-04-02T23:16:52.160Z,1554247012.160 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2019-04-02T23:16:52.160Z,1554247012.160 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-04-02T23:16:52.160Z,1554247012.160 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2019-04-02T23:16:52.160Z,1554247012.160 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-04-02T23:16:52.161Z,1554247012.161 [controlThread](INFO): Join timeout helper Thread ID is 8577
2019-04-02T23:16:52.177Z,1554247012.177 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2019-04-02T23:16:52.177Z,1554247012.177 [controlThread](DEBUG): Uninitializing ControlThread
2019-04-02T23:16:52.177Z,1554247012.177 [AHRS_M2](INFO): Powering down
2019-04-02T23:16:52.247Z,1554247012.247 [NAL9602](INFO): Powering down
2019-04-02T23:16:52.250Z,1554247012.250 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2019-04-02T23:16:52.250Z,1554247012.250 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2019-04-02T23:16:52.251Z,1554247012.251 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2019-04-02T23:16:52.252Z,1554247012.252 [MissionManager](INFO): Uninitializing Mission Default
2019-04-02T23:16:52.254Z,1554247012.254 [MissionManager](INFO): Uninitializing Mission Startup
2019-04-02T23:16:52.256Z,1554247012.256 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2019-04-02T23:16:52.256Z,1554247012.256 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2019-04-02T23:16:52.256Z,1554247012.256 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2019-04-02T23:16:52.256Z,1554247012.256 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2019-04-02T23:16:52.257Z,1554247012.257 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2019-04-02T23:16:52.257Z,1554247012.257 [BuoyancyServo](INFO): Powering down
2019-04-02T23:16:52.387Z,1554247012.387 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2019-04-02T23:16:52.387Z,1554247012.387 [ElevatorServo](INFO): Powering down
2019-04-02T23:16:52.388Z,1554247012.388 [MassServo](DEBUG): Uninitialize Mass Servo.
2019-04-02T23:16:52.388Z,1554247012.388 [MassServo](INFO): Powering down
2019-04-02T23:16:52.406Z,1554247012.406 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-04-02T23:16:52.406Z,1554247012.406 [RudderServo](INFO): Powering down
2019-04-02T23:16:52.407Z,1554247012.407 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2019-04-02T23:16:52.407Z,1554247012.407 [ThrusterServo](INFO): Powering down
2019-04-02T23:16:52.408Z,1554247012.408 [SBIT](DEBUG): Uninitialize SBIT Component.
2019-04-02T23:16:52.408Z,1554247012.408 [IBIT](DEBUG): Uninitialize IBIT Component.
2019-04-02T23:16:52.409Z,1554247012.409 [CBIT](DEBUG): Uninitialize CBIT Component.
2019-04-02T23:16:52.409Z,1554247012.409 [CBIT](DEBUG): Powering off loads.
2019-04-02T23:16:52.423Z,1554247012.423 [CBIT](DEBUG): Disabling WDT.
2019-04-02T23:16:52.435Z,1554247012.435 [CBIT](DEBUG): Opening all GF detection circuits.
2019-04-02T23:16:52.435Z,1554247012.435 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-04-02T23:16:52.510Z,1554247012.510 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-04-02T23:16:52.516Z,1554247012.516 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-04-02T23:16:52.687Z,1554247012.687 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-04-02T23:16:52.689Z,1554247012.689 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2019-04-02T23:16:52.693Z,1554247012.693 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-04-02T23:16:52.701Z,1554247012.701 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-04-02T23:16:52.746Z,1554247012.746 [logger ThreadHandler](INFO): Thread cancelled.