2018-11-04T23:43:24.311Z,1541375004.311 [Supervisor](DEBUG): Initializing supervisor.
2018-11-04T23:43:24.314Z,1541375004.314 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2018-11-04T23:43:24.314Z,1541375004.314 [SyncHandler](INFO): Protected caller Thread ID is 797
2018-11-04T23:43:24.315Z,1541375004.315 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2018-11-04T23:43:24.315Z,1541375004.315 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2018-11-04T23:43:24.316Z,1541375004.316 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 798
2018-11-04T23:43:24.318Z,1541375004.318 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2018-11-04T23:43:24.330Z,1541375004.330 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2018-11-04T23:43:24.331Z,1541375004.331 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2018-11-04T23:43:24.331Z,1541375004.331 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 799
2018-11-04T23:43:24.332Z,1541375004.332 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2018-11-04T23:43:24.333Z,1541375004.333 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2018-11-04T23:43:24.334Z,1541375004.334 [logger ThreadHandler](INFO): Protected caller Thread ID is 800
2018-11-04T23:43:24.335Z,1541375004.335 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2018-11-04T23:43:24.336Z,1541375004.336 [Supervisor](INFO): Looking for Config files in directory: Config/
2018-11-04T23:43:24.340Z,1541375004.340 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2018-11-04T23:43:24.669Z,1541375004.669 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2018-11-04T23:43:24.671Z,1541375004.671 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2018-11-04T23:43:24.870Z,1541375004.870 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2018-11-04T23:43:24.872Z,1541375004.872 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2018-11-04T23:43:25.172Z,1541375005.172 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2018-11-04T23:43:25.174Z,1541375005.174 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2018-11-04T23:43:25.320Z,1541375005.320 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2018-11-04T23:43:25.321Z,1541375005.321 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2018-11-04T23:43:25.419Z,1541375005.419 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2018-11-04T23:43:25.420Z,1541375005.420 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2018-11-04T23:43:25.882Z,1541375005.882 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2018-11-04T23:43:25.884Z,1541375005.884 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2018-11-04T23:43:26.348Z,1541375006.348 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2018-11-04T23:43:26.349Z,1541375006.349 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2018-11-04T23:43:26.818Z,1541375006.818 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2018-11-04T23:43:26.820Z,1541375006.820 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2018-11-04T23:43:26.925Z,1541375006.925 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2018-11-04T23:43:26.925Z,1541375006.925 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2018-11-04T23:43:27.023Z,1541375007.023 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2018-11-04T23:43:27.024Z,1541375007.024 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2018-11-04T23:43:27.243Z,1541375007.243 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2018-11-04T23:43:27.245Z,1541375007.245 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2018-11-04T23:43:27.450Z,1541375007.450 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2018-11-04T23:43:27.451Z,1541375007.451 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2018-11-04T23:43:27.804Z,1541375007.804 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2018-11-04T23:43:27.804Z,1541375007.804 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2018-11-04T23:43:27.953Z,1541375007.953 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2018-11-04T23:43:27.955Z,1541375007.955 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2018-11-04T23:43:28.164Z,1541375008.164 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2018-11-04T23:43:28.754Z,1541375008.754 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2018-11-04T23:43:28.859Z,1541375008.859 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2018-11-04T23:43:28.978Z,1541375008.978 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2018-11-04T23:43:29.074Z,1541375009.074 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2018-11-04T23:43:29.159Z,1541375009.159 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2018-11-04T23:43:29.323Z,1541375009.323 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2018-11-04T23:43:29.504Z,1541375009.504 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg
2018-11-04T23:43:29.581Z,1541375009.581 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg
2018-11-04T23:43:29.811Z,1541375009.811 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2018-11-04T23:43:29.812Z,1541375009.812 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg
2018-11-04T23:43:29.896Z,1541375009.896 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg
2018-11-04T23:43:29.988Z,1541375009.988 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2018-11-04T23:43:30.090Z,1541375010.090 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2018-11-04T23:43:30.217Z,1541375010.217 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2018-11-04T23:43:30.233Z,1541375010.233 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2018-11-04T23:43:30.523Z,1541375010.523 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2018-11-04T23:43:30.524Z,1541375010.524 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2018-11-04T23:43:30.580Z,1541375010.580 [DepthRateCalculator] Loaded
2018-11-04T23:43:30.581Z,1541375010.581 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2018-11-04T23:43:30.587Z,1541375010.587 [PitchRateCalculator] Loaded
2018-11-04T23:43:30.587Z,1541375010.587 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2018-11-04T23:43:30.603Z,1541375010.603 [SpeedCalculator] Loaded
2018-11-04T23:43:30.603Z,1541375010.603 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2018-11-04T23:43:30.624Z,1541375010.624 [TempGradientCalculator] Loaded
2018-11-04T23:43:30.625Z,1541375010.625 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2018-11-04T23:43:30.630Z,1541375010.630 [YawRateCalculator] Loaded
2018-11-04T23:43:30.631Z,1541375010.631 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2018-11-04T23:43:30.670Z,1541375010.670 [ElevatorOffsetCalculator] Loaded
2018-11-04T23:43:30.670Z,1541375010.670 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2018-11-04T23:43:30.671Z,1541375010.671 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2018-11-04T23:43:30.671Z,1541375010.671 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2018-11-04T23:43:30.775Z,1541375010.775 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2018-11-04T23:43:30.775Z,1541375010.775 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2018-11-04T23:43:30.911Z,1541375010.911 [BuoyancyServo] Loaded
2018-11-04T23:43:30.912Z,1541375010.912 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2018-11-04T23:43:30.926Z,1541375010.926 [ElevatorServo] Loaded
2018-11-04T23:43:30.927Z,1541375010.927 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2018-11-04T23:43:30.941Z,1541375010.941 [MassServo] Loaded
2018-11-04T23:43:30.941Z,1541375010.941 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2018-11-04T23:43:30.957Z,1541375010.957 [RudderServo] Loaded
2018-11-04T23:43:30.957Z,1541375010.957 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2018-11-04T23:43:30.972Z,1541375010.972 [ThrusterServo] Loaded
2018-11-04T23:43:30.972Z,1541375010.972 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2018-11-04T23:43:30.973Z,1541375010.973 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2018-11-04T23:43:30.973Z,1541375010.973 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2018-11-04T23:43:30.997Z,1541375010.997 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2018-11-04T23:43:30.998Z,1541375010.998 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2018-11-04T23:43:31.127Z,1541375011.127 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2018-11-04T23:43:31.127Z,1541375011.127 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2018-11-04T23:43:31.704Z,1541375011.704 [DataOverHttps] Loaded
2018-11-04T23:43:31.705Z,1541375011.705 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2018-11-04T23:43:31.719Z,1541375011.719 [Depth_Keller] Loaded
2018-11-04T23:43:31.719Z,1541375011.719 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2018-11-04T23:43:31.724Z,1541375011.724 [DropWeight] Loaded
2018-11-04T23:43:31.724Z,1541375011.724 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2018-11-04T23:43:31.822Z,1541375011.822 [NAL9602] Loaded
2018-11-04T23:43:31.823Z,1541375011.823 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2018-11-04T23:43:31.839Z,1541375011.839 [Onboard] Loaded
2018-11-04T23:43:31.839Z,1541375011.839 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2018-11-04T23:43:31.849Z,1541375011.849 [Radio_Surface] Loaded
2018-11-04T23:43:31.850Z,1541375011.850 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2018-11-04T23:43:31.851Z,1541375011.851 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4088F4E0
2018-11-04T23:43:31.851Z,1541375011.851 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 882
2018-11-04T23:43:32.004Z,1541375012.004 [PNI_TCM] Loaded
2018-11-04T23:43:32.004Z,1541375012.004 [ComponentRegistry](DEBUG): SyncComponent "PNI_TCM" handled in the control thread.
2018-11-04T23:43:32.064Z,1541375012.064 [Rowe_600LCM] Loaded
2018-11-04T23:43:32.064Z,1541375012.064 [ComponentRegistry](DEBUG): Component "Rowe_600LCM" handled in its own thread.
2018-11-04T23:43:32.065Z,1541375012.065 [Rowe_600LCM ThreadHandler](DEBUG): Created PCaller Thread at 408BF4E0
2018-11-04T23:43:32.066Z,1541375012.066 [Rowe_600LCM ThreadHandler](INFO): Protected caller Thread ID is 883
2018-11-04T23:43:32.066Z,1541375012.066 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2018-11-04T23:43:32.067Z,1541375012.067 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2018-11-04T23:43:32.222Z,1541375012.222 [SBIT](DEBUG): Construct Startup Built In Test.
2018-11-04T23:43:32.244Z,1541375012.244 [SBIT] Loaded
2018-11-04T23:43:32.244Z,1541375012.244 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2018-11-04T23:43:32.245Z,1541375012.245 [IBIT](DEBUG): Construct Initiated Built In Test.
2018-11-04T23:43:32.257Z,1541375012.257 [IBIT] Loaded
2018-11-04T23:43:32.258Z,1541375012.258 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2018-11-04T23:43:32.261Z,1541375012.261 [CBIT](DEBUG): Construct Continuous Built In Test.
2018-11-04T23:43:32.409Z,1541375012.409 [CBIT] Loaded
2018-11-04T23:43:32.410Z,1541375012.410 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2018-11-04T23:43:32.410Z,1541375012.410 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2018-11-04T23:43:32.411Z,1541375012.411 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2018-11-04T23:43:32.619Z,1541375012.619 [Aanderaa_O2] Loaded
2018-11-04T23:43:32.619Z,1541375012.619 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2018-11-04T23:43:32.701Z,1541375012.701 [CTD_NeilBrown] Loaded
2018-11-04T23:43:32.702Z,1541375012.702 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2018-11-04T23:43:32.703Z,1541375012.703 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 4098A4E0
2018-11-04T23:43:32.703Z,1541375012.703 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 884
2018-11-04T23:43:32.759Z,1541375012.759 [CTD_Seabird] Loaded
2018-11-04T23:43:32.759Z,1541375012.759 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2018-11-04T23:43:32.760Z,1541375012.760 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 409BA4E0
2018-11-04T23:43:32.761Z,1541375012.761 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 885
2018-11-04T23:43:32.775Z,1541375012.775 [PAR_Licor] Loaded
2018-11-04T23:43:32.775Z,1541375012.775 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2018-11-04T23:43:32.825Z,1541375012.825 [WetLabsBB2FL] Loaded
2018-11-04T23:43:32.825Z,1541375012.825 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2018-11-04T23:43:32.826Z,1541375012.826 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 409EA4E0
2018-11-04T23:43:32.826Z,1541375012.826 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 886
2018-11-04T23:43:32.827Z,1541375012.827 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2018-11-04T23:43:32.829Z,1541375012.829 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2018-11-04T23:43:32.920Z,1541375012.920 [VerticalControl](DEBUG): Construct VerticalControl.
2018-11-04T23:43:33.083Z,1541375013.083 [VerticalControl] Loaded
2018-11-04T23:43:33.083Z,1541375013.083 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2018-11-04T23:43:33.084Z,1541375013.084 [HorizontalControl](DEBUG): Construct HorizontalControl.
2018-11-04T23:43:33.220Z,1541375013.220 [HorizontalControl] Loaded
2018-11-04T23:43:33.221Z,1541375013.221 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2018-11-04T23:43:33.221Z,1541375013.221 [SpeedControl](DEBUG): Construct SpeedControl.
2018-11-04T23:43:33.223Z,1541375013.223 [SpeedControl] Loaded
2018-11-04T23:43:33.223Z,1541375013.223 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2018-11-04T23:43:33.224Z,1541375013.224 [LoopControl](DEBUG): Construct LoopControl.
2018-11-04T23:43:33.225Z,1541375013.225 [LoopControl] Loaded
2018-11-04T23:43:33.225Z,1541375013.225 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2018-11-04T23:43:33.225Z,1541375013.225 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2018-11-04T23:43:33.227Z,1541375013.227 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2018-11-04T23:43:33.265Z,1541375013.265 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2018-11-04T23:43:33.266Z,1541375013.266 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2018-11-04T23:43:33.372Z,1541375013.372 [DeadReckonUsingSpeedCalculator] Loaded
2018-11-04T23:43:33.372Z,1541375013.372 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2018-11-04T23:43:33.388Z,1541375013.388 [NavChart] Loaded
2018-11-04T23:43:33.388Z,1541375013.388 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2018-11-04T23:43:33.392Z,1541375013.392 [UniversalFixResidualReporter] Loaded
2018-11-04T23:43:33.393Z,1541375013.393 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2018-11-04T23:43:33.393Z,1541375013.393 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2018-11-04T23:43:33.397Z,1541375013.397 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2018-11-04T23:43:33.398Z,1541375013.398 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2018-11-04T23:43:33.404Z,1541375013.404 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2018-11-04T23:43:33.405Z,1541375013.405 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40A764E0
2018-11-04T23:43:33.405Z,1541375013.405 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 887
2018-11-04T23:43:33.410Z,1541375013.410 [Supervisor](INFO): Main Thread ID is 796
2018-11-04T23:43:33.410Z,1541375013.410 [Supervisor](DEBUG): Running supervisor.
2018-11-04T23:43:33.411Z,1541375013.411 [CommandLine ThreadHandler](INFO): Handler Thread ID is 888
2018-11-04T23:43:33.413Z,1541375013.413 [controlThread ThreadHandler](INFO): Handler Thread ID is 889
2018-11-04T23:43:33.413Z,1541375013.413 [controlThread](DEBUG): Initializing ControlThread
2018-11-04T23:43:33.414Z,1541375013.414 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2018-11-04T23:43:33.415Z,1541375013.415 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2018-11-04T23:43:33.415Z,1541375013.415 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2018-11-04T23:43:33.415Z,1541375013.415 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2018-11-04T23:43:33.416Z,1541375013.416 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2018-11-04T23:43:33.416Z,1541375013.416 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2018-11-04T23:43:33.424Z,1541375013.424 [SBIT](INFO): Initialize SBIT Component.
2018-11-04T23:43:33.425Z,1541375013.425 [SBIT](IMPORTANT): git: 2018-11-02
2018-11-04T23:43:33.425Z,1541375013.425 [SBIT](INFO): git hash: 766718804c5d96cf896f07eddb44b232c8585615
2018-11-04T23:43:33.425Z,1541375013.425 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2018-11-04T23:43:33.426Z,1541375013.426 [SBIT](IMPORTANT): Kernel Version:#2 PREEMPT Thu Jan 11 20:13:48 PST 2018
2018-11-04T23:43:33.427Z,1541375013.427 [SBIT](INFO): Beginning SBIT in 36.000000 seconds.
2018-11-04T23:43:33.427Z,1541375013.427 [IBIT](INFO): Initialize IBIT Component.
2018-11-04T23:43:33.428Z,1541375013.428 [CBIT](DEBUG): Initialize CBIT Component.
2018-11-04T23:43:33.428Z,1541375013.428 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2018-11-04T23:43:33.429Z,1541375013.429 [logger ThreadHandler](INFO): Handler Thread ID is 890
2018-11-04T23:43:33.446Z,1541375013.446 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 891
2018-11-04T23:43:33.452Z,1541375013.452 [Radio_Surface](INFO): Powering up
2018-11-04T23:43:33.458Z,1541375013.458 [Rowe_600LCM ThreadHandler](INFO): Handler Thread ID is 892
2018-11-04T23:43:33.459Z,1541375013.459 [Rowe_600LCM](INFO): Initializing
2018-11-04T23:43:33.459Z,1541375013.459 [Rowe_600LCM](INFO): Checking LCM
2018-11-04T23:43:33.566Z,1541375013.566 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 893
2018-11-04T23:43:33.567Z,1541375013.567 [CTD_NeilBrown](INFO): Powering down
2018-11-04T23:43:33.590Z,1541375013.590 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2018-11-04T23:43:33.592Z,1541375013.592 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2018-11-04T23:43:33.593Z,1541375013.593 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2018-11-04T23:43:33.593Z,1541375013.593 [LoopControl](DEBUG): Initialize LoopControlComponent.
2018-11-04T23:43:33.594Z,1541375013.594 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-11-04T23:43:33.595Z,1541375013.595 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-11-04T23:43:33.595Z,1541375013.595 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-11-04T23:43:33.595Z,1541375013.595 [NavChart](DEBUG): Initialize NavChart Navigation.
2018-11-04T23:43:33.596Z,1541375013.596 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2018-11-04T23:43:33.597Z,1541375013.597 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2018-11-04T23:43:33.686Z,1541375013.686 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 894
2018-11-04T23:43:33.688Z,1541375013.688 [CTD_Seabird](INFO): Initializing
2018-11-04T23:43:33.689Z,1541375013.689 [CTD_Seabird](INFO): Checking LCM
2018-11-04T23:43:33.699Z,1541375013.699 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2018-11-04T23:43:33.787Z,1541375013.787 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 895
2018-11-04T23:43:33.788Z,1541375013.788 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Units="Tethys/Units"
       xmlns:Universal="Tethys/Universal"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
       Id="Startup">

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

    <Aggregate Id="StartupSatComms">

        <Sequence/>

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

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

    </Aggregate>

</Mission>


2018-11-04T23:43:33.788Z,1541375013.788 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2018-11-04T23:43:33.790Z,1541375013.790 [WetLabsBB2FL](INFO): Powering down
2018-11-04T23:43:33.799Z,1541375013.799 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 896
2018-11-04T23:43:33.806Z,1541375013.806 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2018-11-04T23:43:33.806Z,1541375013.806 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2018-11-04T23:43:33.807Z,1541375013.807 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2018-11-04T23:43:33.807Z,1541375013.807 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2018-11-04T23:43:33.807Z,1541375013.807 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2018-11-04T23:43:33.807Z,1541375013.807 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2018-11-04T23:43:33.807Z,1541375013.807 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2018-11-04T23:43:33.807Z,1541375013.807 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2018-11-04T23:43:33.808Z,1541375013.808 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2018-11-04T23:43:33.808Z,1541375013.808 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2018-11-04T23:43:33.808Z,1541375013.808 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2018-11-04T23:43:33.808Z,1541375013.808 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2018-11-04T23:43:33.808Z,1541375013.808 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2018-11-04T23:43:33.809Z,1541375013.809 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2018-11-04T23:43:33.809Z,1541375013.809 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2018-11-04T23:43:33.809Z,1541375013.809 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2018-11-04T23:43:33.902Z,1541375013.902 [CTD_Seabird](INFO): LCM OK
2018-11-04T23:43:33.902Z,1541375013.902 [CTD_Seabird](INFO): Powering up
2018-11-04T23:43:33.902Z,1541375013.902 [Rowe_600LCM](INFO): LCM OK
2018-11-04T23:43:33.902Z,1541375013.902 [Rowe_600LCM](INFO): Powering up
2018-11-04T23:43:33.951Z,1541375013.951 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2018-11-04T23:43:33.952Z,1541375013.952 [Default:A.Wait](DEBUG): Construct Wait.
2018-11-04T23:43:33.954Z,1541375013.954 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2018-11-04T23:43:33.985Z,1541375013.985 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2018-11-04T23:43:34.022Z,1541375014.022 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2018-11-04T23:43:34.028Z,1541375014.028 [Default:E.Execute](DEBUG): Construct Execute.
2018-11-04T23:43:34.048Z,1541375014.048 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Universal="Tethys/Universal"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                             Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                             Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
         Id="Default">

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

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

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

    <Aggregate Id="CheckIn">

        <Sequence Repeat="288"/>

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

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

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

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

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

    </Aggregate>

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

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

</Mission>


2018-11-04T23:43:34.052Z,1541375014.052 [controlThread](DEBUG): Component order: CycleStarter,DataOverHttps,Depth_Keller,DropWeight,NAL9602,Onboard,PNI_TCM,Aanderaa_O2,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2018-11-04T23:43:34.090Z,1541375014.090 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2018-11-04T23:43:34.098Z,1541375014.098 [Depth_Keller](ERROR): Pressure reading out of range: 1831.023193 decibar
2018-11-04T23:43:34.247Z,1541375014.247 [DepthRateCalculator](ERROR): Depth measurement is not active
2018-11-04T23:43:34.563Z,1541375014.563 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2018-11-04T23:43:34.570Z,1541375014.570 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2018-11-04T23:43:34.592Z,1541375014.592 [ElevatorServo](DEBUG): Initializing EZServoServo.
2018-11-04T23:43:34.598Z,1541375014.598 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2018-11-04T23:43:34.612Z,1541375014.612 [MassServo](DEBUG): Initializing EZServoServo.
2018-11-04T23:43:34.618Z,1541375014.618 [MassServo](DEBUG): Initializing MassServo.
2018-11-04T23:43:34.632Z,1541375014.632 [RudderServo](DEBUG): Initializing EZServoServo.
2018-11-04T23:43:34.638Z,1541375014.638 [RudderServo](DEBUG): Initializing RudderServo.
2018-11-04T23:43:34.644Z,1541375014.644 [ThrusterServo](DEBUG): Initializing EZServoServo.
2018-11-04T23:43:34.650Z,1541375014.650 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2018-11-04T23:43:35.502Z,1541375015.502 [BuoyancyServo](ERROR): Buoyancy initialization uart error serial timeout
2018-11-04T23:43:35.502Z,1541375015.502 [BuoyancyServo](FAULT): Buoyancy failed to initialize
2018-11-04T23:43:35.502Z,1541375015.502 [BuoyancyServo] Communications Fault, FailCount= 1
2018-11-04T23:43:35.503Z,1541375015.503 [BuoyancyServo](ERROR): Communications Fault
2018-11-04T23:43:35.721Z,1541375015.721 [CBIT](ERROR): Communications Fault in component: BuoyancyServo
2018-11-04T23:43:35.818Z,1541375015.818 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2018-11-04T23:43:35.819Z,1541375015.819 [BuoyancyServo](INFO): Powering down
2018-11-04T23:43:37.482Z,1541375017.482 [Aanderaa_O2](INFO): Powering down
2018-11-04T23:43:37.808Z,1541375017.808 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-11-04T23:43:37.943Z,1541375017.943 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null &
2018-11-04T23:43:38.099Z,1541375018.099 [CBIT](INFO): Clearing failed state for component BuoyancyServo
2018-11-04T23:43:38.099Z,1541375018.099 [BuoyancyServo] No Fault, FailCount= 1
2018-11-04T23:43:38.159Z,1541375018.159 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-11-04T23:43:38.159Z,1541375018.159 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-11-04T23:43:38.160Z,1541375018.160 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-11-04T23:43:38.233Z,1541375018.233 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2018-11-04T23:43:38.246Z,1541375018.246 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2018-11-04T23:43:39.083Z,1541375019.083 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface
2018-11-04T23:43:39.638Z,1541375019.638 [CTD_Seabird](INFO): Started Seabird LCM interface with command:nohup ./lrauv-framework/onboard/bin/gpctd -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyC6 -b 9600 >& /dev/null &
2018-11-04T23:43:39.640Z,1541375019.640 [CTD_Seabird](INFO): LCM subscribed to channel:seabird_gpctd_t.seabird-gpctd
2018-11-04T23:43:40.411Z,1541375020.411 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface
2018-11-04T23:43:40.411Z,1541375020.411 [CTD_Seabird](INFO): Powering down
2018-11-04T23:44:02.012Z,1541375042.012 [NAL9602](INFO): Powering up NAL9602
2018-11-04T23:44:10.109Z,1541375050.109 [SBIT](IMPORTANT): Beginning Startup BIT
2018-11-04T23:44:10.114Z,1541375050.114 [CBIT](IMPORTANT): Beginning ground fault scan
2018-11-04T23:44:12.956Z,1541375052.956 [NAL9602](INFO): NAL9602 initialized
2018-11-04T23:44:19.219Z,1541375059.219 [CommandLine](IMPORTANT): got command failComponent
2018-11-04T23:44:19.219Z,1541375059.219 [CommandLine](IMPORTANT): Failed components:
2018-11-04T23:44:19.219Z,1541375059.219 [CommandLine](IMPORTANT): No failed Components.
2018-11-04T23:44:21.164Z,1541375061.164 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.004126
CHAN A1 (24V): -0.008696
CHAN A2 (12V): -0.001989
CHAN A3 (5V): -0.001210
CHAN B0 (3.3V): 0.000207
CHAN B1 (3.15aV): -0.000402
CHAN B2 (3.15bV): -0.000158
CHAN B3 (GND): -0.000015
OPEN: -0.000479
Full Scale Calc: 4.765 mA, -1.589 mA
2018-11-04T23:44:52.112Z,1541375092.112 [CommandLine](IMPORTANT): got command configSet list
2018-11-04T23:44:52.112Z,1541375092.112 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2018-11-04T23:44:52.113Z,1541375092.113 [CommandLine](IMPORTANT): BPC1.batteryMissingStickThreshold=28 count;

2018-11-04T23:44:52.113Z,1541375092.113 [CommandLine](IMPORTANT): BPC1.batteryMuxCycleTime=10 minute;

2018-11-04T23:44:52.113Z,1541375092.113 [CommandLine](IMPORTANT): BPC1.batterySamplingInterval=1 minute;

2018-11-04T23:44:52.113Z,1541375092.113 [CommandLine](IMPORTANT): BPC1.loadAtStartup=0 bool;

2018-11-04T23:44:52.113Z,1541375092.113 [CommandLine](IMPORTANT): CTD_NeilBrown.loadAtStartup=1 bool;

2018-11-04T23:44:52.113Z,1541375092.113 [CommandLine](IMPORTANT): CTD_Seabird.loadAtStartup=1 bool;

2018-11-04T23:44:52.113Z,1541375092.113 [CommandLine](IMPORTANT): Express none VerticalTemperatureHomogeneityIndexCalculator.vertical_temperature_homogeneity_index;

2018-11-04T23:44:52.114Z,1541375092.114 [CommandLine](IMPORTANT): Express linearApproximation height_above_sea_floor 5.000000 meter;

2018-11-04T23:44:52.114Z,1541375092.114 [CommandLine](IMPORTANT): Rowe_600LCM.loadAtStartup=1 bool;

2018-11-04T23:44:52.114Z,1541375092.114 [CommandLine](IMPORTANT): StratificationFrontDetector.loadAtStartup=0 bool;

2018-11-04T23:44:52.114Z,1541375092.114 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral=213 cubic_centimeter;

2018-11-04T23:44:52.114Z,1541375092.114 [CommandLine](IMPORTANT): VerticalControl.massDefault=4 millimeter;

2018-11-04T23:45:04.281Z,1541375104.281 [SBIT](IMPORTANT): SBIT PASSED
2018-11-04T23:45:04.366Z,1541375104.366 [CommandLine](IMPORTANT): got command configSet list
2018-11-04T23:45:04.366Z,1541375104.366 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2018-11-04T23:45:04.367Z,1541375104.367 [CommandLine](IMPORTANT): BPC1.batteryMissingStickThreshold=28 count;

2018-11-04T23:45:04.367Z,1541375104.367 [CommandLine](IMPORTANT): BPC1.batteryMuxCycleTime=10 minute;

2018-11-04T23:45:04.367Z,1541375104.367 [CommandLine](IMPORTANT): BPC1.batterySamplingInterval=1 minute;

2018-11-04T23:45:04.367Z,1541375104.367 [CommandLine](IMPORTANT): BPC1.loadAtStartup=0 bool;

2018-11-04T23:45:04.368Z,