2019-05-30T23:38:03.386Z,1559259483.386 [Supervisor](DEBUG): Initializing supervisor.
2019-05-30T23:38:03.389Z,1559259483.389 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2019-05-30T23:38:03.389Z,1559259483.389 [SyncHandler](INFO): Protected caller Thread ID is 806
2019-05-30T23:38:03.389Z,1559259483.389 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2019-05-30T23:38:03.390Z,1559259483.390 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2019-05-30T23:38:03.391Z,1559259483.391 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 807
2019-05-30T23:38:03.393Z,1559259483.393 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2019-05-30T23:38:03.405Z,1559259483.405 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2019-05-30T23:38:03.406Z,1559259483.406 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2019-05-30T23:38:03.406Z,1559259483.406 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 808
2019-05-30T23:38:03.407Z,1559259483.407 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2019-05-30T23:38:03.408Z,1559259483.408 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2019-05-30T23:38:03.409Z,1559259483.409 [logger ThreadHandler](INFO): Protected caller Thread ID is 809
2019-05-30T23:38:03.411Z,1559259483.411 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2019-05-30T23:38:03.411Z,1559259483.411 [Supervisor](INFO): Looking for Config files in directory: Config/
2019-05-30T23:38:03.415Z,1559259483.415 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2019-05-30T23:38:03.839Z,1559259483.839 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2019-05-30T23:38:03.841Z,1559259483.841 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2019-05-30T23:38:03.939Z,1559259483.939 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2019-05-30T23:38:03.941Z,1559259483.941 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2019-05-30T23:38:04.266Z,1559259484.266 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2019-05-30T23:38:04.267Z,1559259484.267 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2019-05-30T23:38:04.408Z,1559259484.408 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2019-05-30T23:38:04.410Z,1559259484.410 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2019-05-30T23:38:04.602Z,1559259484.602 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2019-05-30T23:38:04.604Z,1559259484.604 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2019-05-30T23:38:05.069Z,1559259485.069 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2019-05-30T23:38:05.071Z,1559259485.071 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2019-05-30T23:38:05.281Z,1559259485.281 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2019-05-30T23:38:05.282Z,1559259485.282 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2019-05-30T23:38:05.427Z,1559259485.427 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2019-05-30T23:38:05.429Z,1559259485.429 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2019-05-30T23:38:05.624Z,1559259485.624 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2019-05-30T23:38:05.626Z,1559259485.626 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2019-05-30T23:38:05.723Z,1559259485.723 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2019-05-30T23:38:05.725Z,1559259485.725 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2019-05-30T23:38:06.061Z,1559259486.061 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2019-05-30T23:38:06.061Z,1559259486.061 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2019-05-30T23:38:06.142Z,1559259486.142 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2019-05-30T23:38:06.245Z,1559259486.245 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2019-05-30T23:38:06.246Z,1559259486.246 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2019-05-30T23:38:06.828Z,1559259486.828 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2019-05-30T23:38:06.829Z,1559259486.829 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2019-05-30T23:38:07.913Z,1559259487.913 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2019-05-30T23:38:07.915Z,1559259487.915 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/
2019-05-30T23:38:07.917Z,1559259487.917 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/vehicle.cfg
2019-05-30T23:38:08.126Z,1559259488.126 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Control.cfg
2019-05-30T23:38:08.226Z,1559259488.226 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/BIT.cfg
2019-05-30T23:38:08.325Z,1559259488.325 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Battery.cfg
2019-05-30T23:38:08.551Z,1559259488.551 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2019-05-30T23:38:08.552Z,1559259488.552 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Simulator.cfg
2019-05-30T23:38:08.637Z,1559259488.637 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Navigation.cfg
2019-05-30T23:38:08.732Z,1559259488.732 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/logger.cfg
2019-05-30T23:38:08.829Z,1559259488.829 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/secure.cfg
2019-05-30T23:38:08.913Z,1559259488.913 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Servo.cfg
2019-05-30T23:38:09.022Z,1559259489.022 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Sensor.cfg
2019-05-30T23:38:09.195Z,1559259489.195 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Science.cfg
2019-05-30T23:38:09.325Z,1559259489.325 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg
2019-05-30T23:38:09.328Z,1559259489.328 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2019-05-30T23:38:10.063Z,1559259490.063 [AHRS_M2] Loaded
2019-05-30T23:38:10.063Z,1559259490.063 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2019-05-30T23:38:10.204Z,1559259490.204 [DataOverHttps] Loaded
2019-05-30T23:38:10.204Z,1559259490.204 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2019-05-30T23:38:10.205Z,1559259490.205 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4075A4E0
2019-05-30T23:38:10.206Z,1559259490.206 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 888
2019-05-30T23:38:10.219Z,1559259490.219 [Depth_Keller] Loaded
2019-05-30T23:38:10.219Z,1559259490.219 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2019-05-30T23:38:10.224Z,1559259490.224 [DropWeight] Loaded
2019-05-30T23:38:10.224Z,1559259490.224 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2019-05-30T23:38:10.280Z,1559259490.280 [DUSBL_Hydroid] Loaded
2019-05-30T23:38:10.280Z,1559259490.280 [ComponentRegistry](DEBUG): SyncComponent "DUSBL_Hydroid" handled in the control thread.
2019-05-30T23:38:10.320Z,1559259490.320 [Micromodem] Loaded
2019-05-30T23:38:10.320Z,1559259490.320 [ComponentRegistry](DEBUG): SyncComponent "Micromodem" handled in the control thread.
2019-05-30T23:38:10.418Z,1559259490.418 [NAL9602] Loaded
2019-05-30T23:38:10.418Z,1559259490.418 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2019-05-30T23:38:10.433Z,1559259490.433 [Onboard] Loaded
2019-05-30T23:38:10.434Z,1559259490.434 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2019-05-30T23:38:10.439Z,1559259490.439 [PowerOnly] Loaded
2019-05-30T23:38:10.440Z,1559259490.440 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread.
2019-05-30T23:38:10.446Z,1559259490.446 [Radio_Surface] Loaded
2019-05-30T23:38:10.446Z,1559259490.446 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2019-05-30T23:38:10.447Z,1559259490.447 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4078A4E0
2019-05-30T23:38:10.448Z,1559259490.448 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 889
2019-05-30T23:38:10.491Z,1559259490.491 [RDI_Pathfinder] Loaded
2019-05-30T23:38:10.492Z,1559259490.492 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread.
2019-05-30T23:38:11.972Z,1559259491.972 [BPC1] Loaded
2019-05-30T23:38:11.972Z,1559259491.972 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2019-05-30T23:38:11.973Z,1559259491.973 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2019-05-30T23:38:11.974Z,1559259491.974 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2019-05-30T23:38:12.015Z,1559259492.015 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2019-05-30T23:38:12.016Z,1559259492.016 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2019-05-30T23:38:12.548Z,1559259492.548 [DeadReckonUsingMultipleVelocitySources] Loaded
2019-05-30T23:38:12.549Z,1559259492.549 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2019-05-30T23:38:12.569Z,1559259492.569 [NavChart] Loaded
2019-05-30T23:38:12.569Z,1559259492.569 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2019-05-30T23:38:12.573Z,1559259492.573 [UniversalFixResidualReporter] Loaded
2019-05-30T23:38:12.573Z,1559259492.573 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2019-05-30T23:38:12.574Z,1559259492.574 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2019-05-30T23:38:12.575Z,1559259492.575 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2019-05-30T23:38:12.704Z,1559259492.704 [BuoyancyServo] Loaded
2019-05-30T23:38:12.704Z,1559259492.704 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2019-05-30T23:38:12.719Z,1559259492.719 [ElevatorServo] Loaded
2019-05-30T23:38:12.720Z,1559259492.720 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2019-05-30T23:38:12.734Z,1559259492.734 [MassServo] Loaded
2019-05-30T23:38:12.735Z,1559259492.735 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2019-05-30T23:38:12.750Z,1559259492.750 [RudderServo] Loaded
2019-05-30T23:38:12.750Z,1559259492.750 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2019-05-30T23:38:12.764Z,1559259492.764 [ThrusterServo] Loaded
2019-05-30T23:38:12.765Z,1559259492.765 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2019-05-30T23:38:12.765Z,1559259492.765 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2019-05-30T23:38:12.766Z,1559259492.766 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2019-05-30T23:38:13.085Z,1559259493.085 [CTD_NeilBrown] Loaded
2019-05-30T23:38:13.085Z,1559259493.085 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2019-05-30T23:38:13.086Z,1559259493.086 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 408CC4E0
2019-05-30T23:38:13.087Z,1559259493.087 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 890
2019-05-30T23:38:13.131Z,1559259493.131 [WetLabsSeaOWL_UV_A] Loaded
2019-05-30T23:38:13.131Z,1559259493.131 [ComponentRegistry](DEBUG): Component "WetLabsSeaOWL_UV_A" handled in its own thread.
2019-05-30T23:38:13.132Z,1559259493.132 [WetLabsSeaOWL_UV_A ThreadHandler](DEBUG): Created PCaller Thread at 408FC4E0
2019-05-30T23:38:13.132Z,1559259493.132 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Protected caller Thread ID is 891
2019-05-30T23:38:13.133Z,1559259493.133 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2019-05-30T23:38:13.133Z,1559259493.133 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2019-05-30T23:38:13.472Z,1559259493.472 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2019-05-30T23:38:13.472Z,1559259493.472 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2019-05-30T23:38:13.527Z,1559259493.527 [DepthRateCalculator] Loaded
2019-05-30T23:38:13.528Z,1559259493.528 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2019-05-30T23:38:13.533Z,1559259493.533 [PitchRateCalculator] Loaded
2019-05-30T23:38:13.533Z,1559259493.533 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2019-05-30T23:38:13.546Z,1559259493.546 [SpeedCalculator] Loaded
2019-05-30T23:38:13.546Z,1559259493.546 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2019-05-30T23:38:13.566Z,1559259493.566 [TempGradientCalculator] Loaded
2019-05-30T23:38:13.567Z,1559259493.567 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2019-05-30T23:38:13.572Z,1559259493.572 [YawRateCalculator] Loaded
2019-05-30T23:38:13.573Z,1559259493.573 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2019-05-30T23:38:13.613Z,1559259493.613 [ElevatorOffsetCalculator] Loaded
2019-05-30T23:38:13.613Z,1559259493.613 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2019-05-30T23:38:13.613Z,1559259493.613 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2019-05-30T23:38:13.615Z,1559259493.615 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2019-05-30T23:38:13.773Z,1559259493.773 [SBIT](DEBUG): Construct Startup Built In Test.
2019-05-30T23:38:13.795Z,1559259493.795 [SBIT] Loaded
2019-05-30T23:38:13.795Z,1559259493.795 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2019-05-30T23:38:13.796Z,1559259493.796 [IBIT](DEBUG): Construct Initiated Built In Test.
2019-05-30T23:38:13.807Z,1559259493.807 [IBIT] Loaded
2019-05-30T23:38:13.808Z,1559259493.808 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2019-05-30T23:38:13.811Z,1559259493.811 [CBIT](DEBUG): Construct Continuous Built In Test.
2019-05-30T23:38:13.948Z,1559259493.948 [CBIT] Loaded
2019-05-30T23:38:13.948Z,1559259493.948 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2019-05-30T23:38:13.948Z,1559259493.948 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2019-05-30T23:38:13.949Z,1559259493.949 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2019-05-30T23:38:14.070Z,1559259494.070 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2019-05-30T23:38:14.072Z,1559259494.072 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2019-05-30T23:38:14.196Z,1559259494.196 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2019-05-30T23:38:14.197Z,1559259494.197 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2019-05-30T23:38:14.282Z,1559259494.282 [VerticalControl](DEBUG): Construct VerticalControl.
2019-05-30T23:38:14.366Z,1559259494.366 [VerticalControl] Loaded
2019-05-30T23:38:14.366Z,1559259494.366 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2019-05-30T23:38:14.367Z,1559259494.367 [HorizontalControl](DEBUG): Construct HorizontalControl.
2019-05-30T23:38:14.424Z,1559259494.424 [HorizontalControl] Loaded
2019-05-30T23:38:14.424Z,1559259494.424 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2019-05-30T23:38:14.425Z,1559259494.425 [SpeedControl](DEBUG): Construct SpeedControl.
2019-05-30T23:38:14.426Z,1559259494.426 [SpeedControl] Loaded
2019-05-30T23:38:14.427Z,1559259494.427 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2019-05-30T23:38:14.427Z,1559259494.427 [LoopControl](DEBUG): Construct LoopControl.
2019-05-30T23:38:14.428Z,1559259494.428 [LoopControl] Loaded
2019-05-30T23:38:14.428Z,1559259494.428 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2019-05-30T23:38:14.429Z,1559259494.429 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2019-05-30T23:38:14.429Z,1559259494.429 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2019-05-30T23:38:14.471Z,1559259494.471 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2019-05-30T23:38:14.474Z,1559259494.474 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2019-05-30T23:38:14.475Z,1559259494.475 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2019-05-30T23:38:14.482Z,1559259494.482 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2019-05-30T23:38:14.483Z,1559259494.483 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40AD54E0
2019-05-30T23:38:14.483Z,1559259494.483 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 892
2019-05-30T23:38:14.488Z,1559259494.488 [Supervisor](INFO): Main Thread ID is 802
2019-05-30T23:38:14.488Z,1559259494.488 [Supervisor](DEBUG): Running supervisor.
2019-05-30T23:38:14.489Z,1559259494.489 [CommandLine ThreadHandler](INFO): Handler Thread ID is 893
2019-05-30T23:38:14.491Z,1559259494.491 [controlThread ThreadHandler](INFO): Handler Thread ID is 894
2019-05-30T23:38:14.491Z,1559259494.491 [controlThread](DEBUG): Initializing ControlThread
2019-05-30T23:38:14.500Z,1559259494.500 [NavChart](DEBUG): Initialize NavChart Navigation.
2019-05-30T23:38:14.500Z,1559259494.500 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2019-05-30T23:38:14.502Z,1559259494.502 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2019-05-30T23:38:14.502Z,1559259494.502 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2019-05-30T23:38:14.502Z,1559259494.502 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2019-05-30T23:38:14.502Z,1559259494.502 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2019-05-30T23:38:14.503Z,1559259494.503 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2019-05-30T23:38:14.503Z,1559259494.503 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2019-05-30T23:38:14.504Z,1559259494.504 [SBIT](INFO): Initialize SBIT Component.
2019-05-30T23:38:14.504Z,1559259494.504 [SBIT](IMPORTANT): git: 2019-05-29
2019-05-30T23:38:14.504Z,1559259494.504 [SBIT](INFO): git hash: 3a408d161d85e02f941062c72493668314c507d3
2019-05-30T23:38:14.505Z,1559259494.505 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2019-05-30T23:38:14.506Z,1559259494.506 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
Kernel Reported: #1 PREEMPT Thu Feb 21 11:17:40 PST 2019
2019-05-30T23:38:14.507Z,1559259494.507 [SBIT](INFO): Beginning SBIT in 28.000000 seconds.
2019-05-30T23:38:14.508Z,1559259494.508 [IBIT](INFO): Initialize IBIT Component.
2019-05-30T23:38:14.508Z,1559259494.508 [CBIT](DEBUG): Initialize CBIT Component.
2019-05-30T23:38:14.509Z,1559259494.509 [logger ThreadHandler](INFO): Handler Thread ID is 895
2019-05-30T23:38:14.521Z,1559259494.521 [CBIT](DEBUG): Initialized mux pins.
2019-05-30T23:38:14.521Z,1559259494.521 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL.
2019-05-30T23:38:14.521Z,1559259494.521 [CBIT](DEBUG): Initializing the watchdog timer.
2019-05-30T23:38:14.529Z,1559259494.529 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 896
2019-05-30T23:38:14.530Z,1559259494.530 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2019-05-30T23:38:14.541Z,1559259494.541 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 897
2019-05-30T23:38:14.545Z,1559259494.545 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2019-05-30T23:38:14.545Z,1559259494.545 [CBIT](DEBUG): Initializing heartbeat.
2019-05-30T23:38:14.561Z,1559259494.561 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 898
2019-05-30T23:38:14.562Z,1559259494.562 [CTD_NeilBrown](INFO): Powering down
2019-05-30T23:38:14.589Z,1559259494.589 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Handler Thread ID is 899
2019-05-30T23:38:14.590Z,1559259494.590 [WetLabsSeaOWL_UV_A](INFO): Powering down
2019-05-30T23:38:14.617Z,1559259494.617 [CBIT](DEBUG): Deactivating GF circuits.
2019-05-30T23:38:14.617Z,1559259494.617 [CBIT](DEBUG): Deactivating emergency mode.
2019-05-30T23:38:14.621Z,1559259494.621 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 900
2019-05-30T23:38:14.630Z,1559259494.630 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2019-05-30T23:38:14.630Z,1559259494.630 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2019-05-30T23:38:14.630Z,1559259494.630 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2019-05-30T23:38:14.631Z,1559259494.631 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2019-05-30T23:38:14.631Z,1559259494.631 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2019-05-30T23:38:14.631Z,1559259494.631 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2019-05-30T23:38:14.631Z,1559259494.631 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2019-05-30T23:38:14.631Z,1559259494.631 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2019-05-30T23:38:14.632Z,1559259494.632 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2019-05-30T23:38:14.632Z,1559259494.632 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2019-05-30T23:38:14.632Z,1559259494.632 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2019-05-30T23:38:14.632Z,1559259494.632 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2019-05-30T23:38:14.632Z,1559259494.632 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2019-05-30T23:38:14.633Z,1559259494.633 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2019-05-30T23:38:14.633Z,1559259494.633 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2019-05-30T23:38:14.633Z,1559259494.633 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2019-05-30T23:38:14.653Z,1559259494.653 [CBIT](DEBUG): Backplane powered.
2019-05-30T23:38:14.653Z,1559259494.653 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2019-05-30T23:38:14.655Z,1559259494.655 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2019-05-30T23:38:14.655Z,1559259494.655 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2019-05-30T23:38:14.656Z,1559259494.656 [LoopControl](DEBUG): Initialize LoopControlComponent.
2019-05-30T23:38:14.657Z,1559259494.657 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2019-05-30T23:38:14.678Z,1559259494.678 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2019-05-30T23:38:14.705Z,1559259494.705 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Units="Tethys/Units"
       xmlns:Universal="Tethys/Universal"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
       Id="Startup">

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

    <Aggregate Id="StartupSatComms">

        <Sequence/>

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

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

    </Aggregate>

</Mission>


2019-05-30T23:38:14.706Z,1559259494.706 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2019-05-30T23:38:14.790Z,1559259494.790 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2019-05-30T23:38:14.791Z,1559259494.791 [Default:A.Wait](DEBUG): Construct Wait.
2019-05-30T23:38:14.793Z,1559259494.793 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2019-05-30T23:38:14.816Z,1559259494.816 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2019-05-30T23:38:14.851Z,1559259494.851 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2019-05-30T23:38:14.856Z,1559259494.856 [Default:E.Execute](DEBUG): Construct Execute.
2019-05-30T23:38:14.876Z,1559259494.876 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Universal="Tethys/Universal"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                             Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                             Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
         Id="Default">

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

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

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

    <Aggregate Id="CheckIn">

        <Sequence Repeat="288"/>

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

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

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

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

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

    </Aggregate>

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

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

</Mission>


2019-05-30T23:38:14.880Z,1559259494.880 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,DUSBL_Hydroid,Micromodem,NAL9602,Onboard,PowerOnly,RDI_Pathfinder,BPC1,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2019-05-30T23:38:14.889Z,1559259494.889 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2019-05-30T23:38:14.945Z,1559259494.945 [Radio_Surface](INFO): Powering up
2019-05-30T23:38:15.137Z,1559259495.137 [DUSBL_Hydroid](INFO): Powering up
2019-05-30T23:38:15.138Z,1559259495.138 [DUSBL_Hydroid](DEBUG): Initializing DUSBL_Hydroid.
2019-05-30T23:38:15.227Z,1559259495.227 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2019-05-30T23:38:15.233Z,1559259495.233 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2019-05-30T23:38:15.234Z,1559259495.234 [ElevatorServo](DEBUG): Initializing EZServoServo.
2019-05-30T23:38:15.245Z,1559259495.245 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2019-05-30T23:38:15.246Z,1559259495.246 [MassServo](DEBUG): Initializing EZServoServo.
2019-05-30T23:38:15.253Z,1559259495.253 [MassServo](DEBUG): Initializing MassServo.
2019-05-30T23:38:15.254Z,1559259495.254 [RudderServo](DEBUG): Initializing EZServoServo.
2019-05-30T23:38:15.261Z,1559259495.261 [RudderServo](DEBUG): Initializing RudderServo.
2019-05-30T23:38:15.262Z,1559259495.262 [ThrusterServo](DEBUG): Initializing EZServoServo.
2019-05-30T23:38:15.269Z,1559259495.269 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2019-05-30T23:38:15.303Z,1559259495.303 [Micromodem](INFO): Powering up
2019-05-30T23:38:15.304Z,1559259495.304 [Micromodem](DEBUG): Initializing Micromodem.
2019-05-30T23:38:28.647Z,1559259508.647 [RDI_Pathfinder](ERROR): Failed to parse:Pathfinder
2019-05-30T23:38:33.066Z,1559259513.066 [DUSBL_Hydroid](INFO): DUSBL Version:O
2019-05-30T23:38:40.743Z,1559259520.743 [NAL9602](INFO): Powering up NAL9602
2019-05-30T23:38:43.222Z,1559259523.222 [SBIT](IMPORTANT): Beginning Startup BIT
2019-05-30T23:38:43.238Z,1559259523.238 [CBIT](IMPORTANT): Beginning ground fault scan
2019-05-30T23:38:51.743Z,1559259531.743 [NAL9602](INFO): NAL9602 initialized
2019-05-30T23:38:52.561Z,1559259532.561 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:38:54.261Z,1559259534.261 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.012846
CHAN A1 (24V): -0.025722
CHAN A2 (12V): -0.005922
CHAN A3 (5V): -0.001774
CHAN B0 (3.3V): 0.000355
CHAN B1 (3.15aV): 0.000484
CHAN B2 (3.15bV): 0.000227
CHAN B3 (GND): 0.002198
OPEN: 0.005929
Full Scale Calc: 4.765 mA, -1.589 mA
2019-05-30T23:39:10.597Z,1559259550.597 [RDI_Pathfinder](ERROR): DVL uart error: serial timeout
2019-05-30T23:39:10.597Z,1559259550.597 [RDI_Pathfinder] Communications Fault, FailCount= 1
2019-05-30T23:39:10.597Z,1559259550.597 [RDI_Pathfinder](ERROR): Communications Fault
2019-05-30T23:39:10.597Z,1559259550.597 [RDI_Pathfinder](ERROR): Failed to parse:
2019-05-30T23:39:10.658Z,1559259550.658 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder
2019-05-30T23:39:10.981Z,1559259550.981 [RDI_Pathfinder](INFO): Powering down
2019-05-30T23:39:11.766Z,1559259551.766 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2019-05-30T23:39:11.766Z,1559259551.766 [RDI_Pathfinder] No Fault, FailCount= 1
2019-05-30T23:39:24.208Z,1559259564.208 [NAL9602](INFO): SBD MO Status=2, MOMSN=5614, MT Status=2, MTMSN=0
2019-05-30T23:39:24.208Z,1559259564.208 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-05-30T23:39:25.040Z,1559259565.040 [RDI_Pathfinder](ERROR): Failed to parse:Pathfinder
2019-05-30T23:39:36.923Z,1559259576.923 [SBIT](IMPORTANT): SBIT PASSED
2019-05-30T23:39:36.978Z,1559259576.978 [CommandLine](IMPORTANT): got command configSet list
2019-05-30T23:39:36.978Z,1559259576.978 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2019-05-30T23:39:36.982Z,1559259576.982 [CommandLine](IMPORTANT): BPC1.batterySamplingInterval=3 hour;

2019-05-30T23:39:36.982Z,1559259576.982 [CommandLine](IMPORTANT): BPC1.loadAtStartup=1 bool;

2019-05-30T23:39:36.982Z,1559259576.982 [CommandLine](IMPORTANT): DUSBL_Hydroid.detectionThreshold=40 count;

2019-05-30T23:39:36.982Z,1559259576.982 [CommandLine](IMPORTANT): Express linearApproximation DUSBL_Hydroid.range 2.000000 meter;

2019-05-30T23:39:36.982Z,1559259576.982 [CommandLine](IMPORTANT): Express linearApproximation DUSBL_Hydroid.xAngle 2.000000 angular_degree;

2019-05-30T23:39:36.982Z,1559259576.982 [CommandLine](IMPORTANT): Express linearApproximation RDI_Pathfinder.BottomVelocityFlag 0.000000 count;

2019-05-30T23:39:36.982Z,1559259576.982 [CommandLine](IMPORTANT): Express linearApproximation RDI_Pathfinder.height_above_sea_floor 2.000000 meter;

2019-05-30T23:39:36.982Z,1559259576.982 [CommandLine](IMPORTANT): Express none TrackAcousticContact.contact_latitude;

2019-05-30T23:39:36.982Z,1559259576.982 [CommandLine](IMPORTANT): Express none TrackAcousticContact.contact_longitude;

2019-05-30T23:39:36.983Z,1559259576.983 [CommandLine](IMPORTANT): Express linearApproximation acoustic_contact_range 1.000000 meter;

2019-05-30T23:39:36.983Z,1559259576.983 [CommandLine](IMPORTANT): Express linearApproximation mass_concentration_of_chlorophyll_in_sea_water 5.000000 microgram_per_liter;

2019-05-30T23:39:36.983Z,1559259576.983 [CommandLine](IMPORTANT): Express none mass_concentration_of_oxygen_in_sea_water;

2019-05-30T23:39:36.983Z,1559259576.983 [CommandLine](IMPORTANT): NAL9602.fastGPSFix=1 bool;

2019-05-30T23:39:36.983Z,1559259576.983 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral=190 cubic_centimeter;

2019-05-30T23:39:36.983Z,1559259576.983 [CommandLine](IMPORTANT): VerticalControl.massDefault=5 millimeter;

2019-05-30T23:39:37.331Z,1559259577.331 [MissionManager](IMPORTANT): Started mission Startup
2019-05-30T23:39:37.331Z,1559259577.331 [Startup] Running Loop=1
2019-05-30T23:39:37.331Z,1559259577.331 [Startup](DEBUG): Aggregate::initialize Startup
2019-05-30T23:39:37.331Z,1559259577.331 [Startup:A.GoToSurface] Running Loop=1
2019-05-30T23:39:37.331Z,1559259577.331 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-05-30T23:39:37.332Z,1559259577.332 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-05-30T23:39:37.333Z,1559259577.333 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-05-30T23:39:37.333Z,1559259577.333 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-05-30T23:39:37.333Z,1559259577.333 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-05-30T23:39:37.334Z,1559259577.334 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-05-30T23:39:37.335Z,1559259577.335 [Startup:StartupSatComms] Running Loop=1
2019-05-30T23:39:37.335Z,1559259577.335 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2019-05-30T23:39:37.335Z,1559259577.335 [Startup:StartupSatComms:A] Running Loop=1
2019-05-30T23:39:37.730Z,1559259577.730 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2019-05-30T23:39:38.912Z,1559259578.912 [NAL9602](INFO): SBD MO Status=2, MOMSN=5614, MT Status=2, MTMSN=0
2019-05-30T23:39:38.912Z,1559259578.912 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-05-30T23:39:57.105Z,1559259597.105 [NAL9602](INFO): SBD MO Status=0, MOMSN=5614, MT Status=0, MTMSN=0
2019-05-30T23:39:57.105Z,1559259597.105 [NAL9602](INFO): No messages in MT queue
2019-05-30T23:39:57.913Z,1559259597.913 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:40:01.153Z,1559259601.153 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:40:03.977Z,1559259603.977 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:40:07.209Z,1559259607.209 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:40:10.049Z,1559259610.049 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:40:13.273Z,1559259613.273 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:40:16.109Z,1559259616.109 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:40:19.333Z,1559259619.333 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:40:22.153Z,1559259622.153 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:40:24.985Z,1559259624.985 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:40:28.213Z,1559259628.213 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:40:31.041Z,1559259631.041 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:40:34.273Z,1559259634.273 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:40:37.101Z,1559259637.101 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:40:37.554Z,1559259637.554 [Startup:StartupSatComms:A](INFO): Timed out from 2019-05-30T23:39:37.3Z
2019-05-30T23:40:37.554Z,1559259637.554 [Startup:StartupSatComms:A] Stopped
2019-05-30T23:40:37.554Z,1559259637.554 [Startup:StartupSatComms:B] Running Loop=1
2019-05-30T23:40:37.942Z,1559259637.942 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-05-30T23:41:06.452Z,1559259666.452 [NAL9602](INFO): SBD MO Status=2, MOMSN=5615, MT Status=2, MTMSN=0
2019-05-30T23:41:06.452Z,1559259666.452 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-05-30T23:41:07.269Z,1559259667.269 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:41:14.784Z,1559259674.784 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2019-05-30T23:41:14.785Z,1559259674.785 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-05-30T23:41:14.794Z,1559259674.794 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-05-30T23:41:15.204Z,1559259675.204 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-05-30T23:41:15.204Z,1559259675.204 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2019-05-30T23:41:25.264Z,1559259685.264 [NAL9602](INFO): SBD MO Status=2, MOMSN=5615, MT Status=2, MTMSN=0
2019-05-30T23:41:25.264Z,1559259685.264 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-05-30T23:41:26.085Z,1559259686.085 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:41:37.891Z,1559259697.891 [Startup:StartupSatComms:B](INFO): Timed out from 2019-05-30T23:40:37.6Z
2019-05-30T23:41:37.891Z,1559259697.891 [Startup:StartupSatComms:B] Stopped
2019-05-30T23:41:37.891Z,1559259697.891 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2019-05-30T23:41:37.891Z,1559259697.891 [Startup:StartupSatComms] Stopped
2019-05-30T23:41:37.891Z,1559259697.891 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2019-05-30T23:41:37.892Z,1559259697.892 [Startup](INFO): Completed Startup
2019-05-30T23:41:37.892Z,1559259697.892 [MissionManager](INFO): Startup is completed.
2019-05-30T23:41:37.892Z,1559259697.892 [MissionManager](INFO): Uninitializing Mission Startup
2019-05-30T23:41:37.892Z,1559259697.892 [Startup] Stopped
2019-05-30T23:41:37.892Z,1559259697.892 [Startup](DEBUG): Aggregate::uninitialize Startup
2019-05-30T23:41:37.893Z,1559259697.893 [Startup:A.GoToSurface] Stopped
2019-05-30T23:41:37.893Z,1559259697.893 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-05-30T23:41:38.300Z,1559259698.300 [MissionManager](IMPORTANT): Started mission Default
2019-05-30T23:41:38.300Z,1559259698.300 [Default] Running Loop=1
2019-05-30T23:41:38.300Z,1559259698.300 [Default](DEBUG): Aggregate::initialize Default
2019-05-30T23:41:38.300Z,1559259698.300 [Default:B.GoToSurface] Running Loop=1
2019-05-30T23:41:38.300Z,1559259698.300 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-05-30T23:41:38.301Z,1559259698.301 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-05-30T23:41:38.301Z,1559259698.301 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-05-30T23:41:38.301Z,1559259698.301 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-05-30T23:41:38.302Z,1559259698.302 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-05-30T23:41:38.302Z,1559259698.302 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-05-30T23:41:38.302Z,1559259698.302 [Default:A.Wait] Running Loop=1
2019-05-30T23:41:38.302Z,1559259698.302 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-05-30T23:41:39.126Z,1559259699.126 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2019-05-30T23:41:39.126Z,1559259699.126 [RDI_Pathfinder](ERROR): Failed to parse:
:RA,  0.00, 326.57, 304.04, 304.04
2019-05-30T23:41:50.987Z,1559259710.987 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.005072
2019-05-30T23:41:51.193Z,1559259711.193 [NAL9602](INFO): SBD MO Status=2, MOMSN=5615, MT Status=2, MTMSN=0
2019-05-30T23:41:51.193Z,1559259711.193 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-05-30T23:41:51.622Z,1559259711.622 [Default:A.Wait](INFO): Done Waiting.
2019-05-30T23:41:51.622Z,1559259711.622 [Default:A.Wait] Stopped
2019-05-30T23:41:51.623Z,1559259711.623 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-05-30T23:41:52.013Z,1559259712.013 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:41:52.038Z,1559259712.038 [Default:CheckIn] Running Loop=1
2019-05-30T23:41:52.038Z,1559259712.038 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-05-30T23:41:52.039Z,1559259712.039 [Default:CheckIn:Read_GPS] Running Loop=1
2019-05-30T23:41:52.445Z,1559259712.445 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2019-05-30T23:41:55.249Z,1559259715.249 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:41:58.069Z,1559259718.069 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:42:01.301Z,1559259721.301 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:42:04.141Z,1559259724.141 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:42:06.961Z,1559259726.961 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:42:10.189Z,1559259730.189 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:42:13.025Z,1559259733.025 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:42:16.253Z,1559259736.253 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:42:19.085Z,1559259739.085 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:42:22.309Z,1559259742.309 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:42:25.137Z,1559259745.137 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:42:27.969Z,1559259747.969 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:42:31.201Z,1559259751.201 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:42:34.029Z,1559259754.029 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:42:37.257Z,1559259757.257 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:42:40.089Z,1559259760.089 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:42:43.321Z,1559259763.321 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:42:46.153Z,1559259766.153 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:42:48.973Z,1559259768.973 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:42:52.205Z,1559259772.205 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:42:55.033Z,1559259775.033 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:42:58.265Z,1559259778.265 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:43:01.109Z,1559259781.109 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:43:04.325Z,1559259784.325 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:43:07.161Z,1559259787.161 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:43:09.981Z,1559259789.981 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:43:13.213Z,1559259793.213 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:43:16.045Z,1559259796.045 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:43:19.277Z,1559259799.277 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:43:21.349Z,1559259801.349 [CommandLine](IMPORTANT): got command configSet list
2019-05-30T23:43:21.349Z,1559259801.349 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2019-05-30T23:43:21.350Z,1559259801.350 [CommandLine](IMPORTANT): BPC1.batterySamplingInterval=3 hour;

2019-05-30T23:43:21.350Z,1559259801.350 [CommandLine](IMPORTANT): BPC1.loadAtStartup=1 bool;

2019-05-30T23:43:21.350Z,1559259801.350 [CommandLine](IMPORTANT): DUSBL_Hydroid.detectionThreshold=40 count;

2019-05-30T23:43:21.350Z,1559259801.350 [CommandLine](IMPORTANT): Express linearApproximation DUSBL_Hydroid.range 2.000000 meter;

2019-05-30T23:43:21.350Z,1559259801.350 [CommandLine](IMPORTANT): Express linearApproximation DUSBL_Hydroid.xAngle 2.000000 angular_degree;

2019-05-30T23:43:21.350Z,1559259801.350 [CommandLine](IMPORTANT): Express linearApproximation RDI_Pathfinder.BottomVelocityFlag 0.000000 count;

2019-05-30T23:43:21.350Z,1559259801.350 [CommandLine](IMPORTANT): Express linearApproximation RDI_Pathfinder.height_above_sea_floor 2.000000 meter;

2019-05-30T23:43:21.351Z,1559259801.351 [CommandLine](IMPORTANT): Express none TrackAcousticContact.contact_latitude;

2019-05-30T23:43:21.351Z,1559259801.351 [CommandLine](IMPORTANT): Express none TrackAcousticContact.contact_longitude;

2019-05-30T23:43:21.351Z,1559259801.351 [CommandLine](IMPORTANT): Express linearApproximation acoustic_contact_range 1.000000 meter;

2019-05-30T23:43:21.351Z,1559259801.351 [CommandLine](IMPORTANT): Express linearApproximation mass_concentration_of_chlorophyll_in_sea_water 5.000000 microgram_per_liter;

2019-05-30T23:43:21.351Z,1559259801.351 [CommandLine](IMPORTANT): Express none mass_concentration_of_oxygen_in_sea_water;

2019-05-30T23:43:21.351Z,1559259801.351 [CommandLine](IMPORTANT): NAL9602.fastGPSFix=1 bool;

2019-05-30T23:43:21.351Z,1559259801.351 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral=190 cubic_centimeter;

2019-05-30T23:43:21.351Z,1559259801.351 [CommandLine](IMPORTANT): VerticalControl.massDefault=5 millimeter;

2019-05-30T23:43:22.121Z,1559259802.121 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:43:24.929Z,1559259804.929 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:43:27.353Z,1559259807.353 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:43:30.181Z,1559259810.181 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:43:33.413Z,1559259813.413 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:43:36.245Z,1559259816.245 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:43:39.473Z,1559259819.473 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:43:42.309Z,1559259822.309 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:43:45.129Z,1559259825.129 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:43:47.961Z,1559259827.961 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:43:51.193Z,1559259831.193 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:43:54.021Z,1559259834.021 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:43:57.253Z,1559259837.253 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:44:00.077Z,1559259840.077 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:44:03.309Z,1559259843.309 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:44:06.141Z,1559259846.141 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:44:09.373Z,1559259849.373 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:44:11.598Z,1559259851.598 [DataOverHttps](IMPORTANT): SBD MTMSN=20190530T234403
2019-05-30T23:44:12.201Z,1559259852.201 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:44:15.433Z,1559259855.433 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:44:15.871Z,1559259855.871 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2019-05-30T23:44:15.871Z,1559259855.871 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-05-30T23:44:15.889Z,1559259855.889 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-05-30T23:44:16.333Z,1559259856.333 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-05-30T23:44:16.333Z,1559259856.333 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2019-05-30T23:44:16.849Z,1559259856.849 [DataOverHttps](INFO): Received command:restart app
2019-05-30T23:44:16.856Z,1559259856.856 [CommandLine](IMPORTANT): got command restart application
2019-05-30T23:44:17.861Z,1559259857.861 [Supervisor](INFO): Stop Mission called by Supervisor::terminate
2019-05-30T23:44:17.861Z,1559259857.861 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-30T23:44:17.862Z,1559259857.862 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-05-30T23:44:17.957Z,1559259857.957 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2019-05-30T23:44:17.957Z,1559259857.957 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-05-30T23:44:17.958Z,1559259857.958 [CommandLine](INFO): Join timeout helper Thread ID is 964
2019-05-30T23:44:17.965Z,1559259857.965 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2019-05-30T23:44:17.965Z,1559259857.965 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-05-30T23:44:17.965Z,1559259857.965 [NavChartDb](INFO): Join timeout helper Thread ID is 965
2019-05-30T23:44:18.090Z,1559259858.090 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-30T23:44:18.090Z,1559259858.090 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-05-30T23:44:18.097Z,1559259858.097 [ComponentRegistry](INFO): Shutting down WetLabsSeaOWL_UV_A ThreadHandler
2019-05-30T23:44:18.097Z,1559259858.097 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2019-05-30T23:44:18.098Z,1559259858.098 [WetLabsSeaOWL_UV_A](INFO): Join timeout helper Thread ID is 966
2019-05-30T23:44:18.264Z,1559259858.264 [NAL9602](DEBUG): Fix Requested
2019-05-30T23:44:18.317Z,1559259858.317 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-30T23:44:18.317Z,1559259858.317 [WetLabsSeaOWL_UV_A](INFO): Powering down
2019-05-30T23:44:18.318Z,1559259858.318 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2019-05-30T23:44:18.325Z,1559259858.325 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2019-05-30T23:44:18.325Z,1559259858.325 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-05-30T23:44:18.325Z,1559259858.325 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 967
2019-05-30T23:44:18.493Z,1559259858.493 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-30T23:44:18.493Z,1559259858.493 [CTD_NeilBrown](INFO): Powering down
2019-05-30T23:44:18.505Z,1559259858.505 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-05-30T23:44:18.517Z,1559259858.517 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2019-05-30T23:44:18.517Z,1559259858.517 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-05-30T23:44:18.517Z,1559259858.517 [Radio_Surface](INFO): Join timeout helper Thread ID is 968
2019-05-30T23:44:18.621Z,1559259858.621 [Radio_Surface](INFO): Powering down
2019-05-30T23:44:18.622Z,1559259858.622 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-30T23:44:18.622Z,1559259858.622 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-05-30T23:44:18.638Z,1559259858.638 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2019-05-30T23:44:18.638Z,1559259858.638 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-05-30T23:44:18.638Z,1559259858.638 [DataOverHttps](INFO): Join timeout helper Thread ID is 969
2019-05-30T23:44:18.865Z,1559259858.865 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-30T23:44:18.865Z,1559259858.865 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-05-30T23:44:18.869Z,1559259858.869 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2019-05-30T23:44:18.870Z,1559259858.870 [logger ThreadHandler](INFO): Thread cancelled.
2019-05-30T23:44:18.870Z,1559259858.870 [logger](INFO): Join timeout helper Thread ID is 970
2019-05-30T23:44:18.881Z,1559259858.881 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-30T23:44:18.881Z,1559259858.881 [logger ThreadHandler](INFO): Thread cancelled.
2019-05-30T23:44:18.889Z,1559259858.889 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2019-05-30T23:44:18.890Z,1559259858.890 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-05-30T23:44:18.890Z,1559259858.890 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2019-05-30T23:44:18.890Z,1559259858.890 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-05-30T23:44:18.890Z,1559259858.890 [controlThread](INFO): Join timeout helper Thread ID is 971
2019-05-30T23:44:19.041Z,1559259859.041 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-30T23:44:19.041Z,1559259859.041 [controlThread](DEBUG): Uninitializing ControlThread
2019-05-30T23:44:19.042Z,1559259859.042 [AHRS_M2](INFO): Powering down
2019-05-30T23:44:19.115Z,1559259859.115 [DUSBL_Hydroid](INFO): Powering down
2019-05-30T23:44:19.221Z,1559259859.221 [Micromodem](INFO): Powering down
2019-05-30T23:44:19.317Z,1559259859.317 [NAL9602](INFO): Powering down
2019-05-30T23:44:19.389Z,1559259859.389 [RDI_Pathfinder](INFO): Powering down
2019-05-30T23:44:19.391Z,1559259859.391 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2019-05-30T23:44:19.391Z,1559259859.391 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2019-05-30T23:44:19.392Z,1559259859.392 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2019-05-30T23:44:19.392Z,1559259859.392 [MissionManager](INFO): Uninitializing Mission Default
2019-05-30T23:44:19.393Z,1559259859.393 [Default] Stopped
2019-05-30T23:44:19.393Z,1559259859.393 [Default](DEBUG): Aggregate::uninitialize Default
2019-05-30T23:44:19.393Z,1559259859.393 [Default:B.GoToSurface] Stopped
2019-05-30T23:44:19.393Z,1559259859.393 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-05-30T23:44:19.393Z,1559259859.393 [Default:CheckIn] Stopped
2019-05-30T23:44:19.393Z,1559259859.393 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-05-30T23:44:19.393Z,1559259859.393 [Default:CheckIn:Read_GPS] Stopped
2019-05-30T23:44:19.395Z,1559259859.395 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2019-05-30T23:44:19.396Z,1559259859.396 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2019-05-30T23:44:19.396Z,1559259859.396 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2019-05-30T23:44:19.396Z,1559259859.396 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2019-05-30T23:44:19.397Z,1559259859.397 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2019-05-30T23:44:19.397Z,1559259859.397 [BuoyancyServo](INFO): Powering down
2019-05-30T23:44:19.409Z,1559259859.409 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2019-05-30T23:44:19.409Z,1559259859.409 [ElevatorServo](INFO): Powering down
2019-05-30T23:44:19.410Z,1559259859.410 [MassServo](DEBUG): Uninitialize Mass Servo.
2019-05-30T23:44:19.410Z,1559259859.410 [MassServo](INFO): Powering down
2019-05-30T23:44:19.411Z,1559259859.411 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-05-30T23:44:19.411Z,1559259859.411 [RudderServo](INFO): Powering down
2019-05-30T23:44:19.412Z,1559259859.412 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2019-05-30T23:44:19.412Z,1559259859.412 [ThrusterServo](INFO): Powering down
2019-05-30T23:44:19.413Z,1559259859.413 [SBIT](DEBUG): Uninitialize SBIT Component.
2019-05-30T23:44:19.413Z,1559259859.413 [IBIT](DEBUG): Uninitialize IBIT Component.
2019-05-30T23:44:19.413Z,1559259859.413 [CBIT](DEBUG): Uninitialize CBIT Component.
2019-05-30T23:44:19.413Z,1559259859.413 [CBIT](DEBUG): Powering off loads.
2019-05-30T23:44:19.425Z,1559259859.425 [CBIT](DEBUG): Disabling WDT.
2019-05-30T23:44:19.437Z,1559259859.437 [CBIT](DEBUG): Opening all GF detection circuits.
2019-05-30T23:44:19.438Z,1559259859.438 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-05-30T23:44:19.486Z,1559259859.486 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-05-30T23:44:19.494Z,1559259859.494 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-05-30T23:44:19.533Z,1559259859.533 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2019-05-30T23:44:19.535Z,1559259859.535 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-05-30T23:44:19.591Z,1559259859.591 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-05-30T23:44:19.646Z,1559259859.646 [logger ThreadHandler](INFO): Thread cancelled.