2018-11-15T23:35:10.712Z,1542324910.712 [Supervisor](DEBUG): Initializing supervisor.
2018-11-15T23:35:10.715Z,1542324910.715 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2018-11-15T23:35:10.716Z,1542324910.716 [SyncHandler](INFO): Protected caller Thread ID is 2949
2018-11-15T23:35:10.716Z,1542324910.716 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2018-11-15T23:35:10.718Z,1542324910.718 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2018-11-15T23:35:10.718Z,1542324910.718 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 2950
2018-11-15T23:35:10.721Z,1542324910.721 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2018-11-15T23:35:10.734Z,1542324910.734 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2018-11-15T23:35:10.735Z,1542324910.735 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2018-11-15T23:35:10.735Z,1542324910.735 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 2951
2018-11-15T23:35:10.736Z,1542324910.736 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2018-11-15T23:35:10.737Z,1542324910.737 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2018-11-15T23:35:10.738Z,1542324910.738 [logger ThreadHandler](INFO): Protected caller Thread ID is 2952
2018-11-15T23:35:10.740Z,1542324910.740 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2018-11-15T23:35:10.740Z,1542324910.740 [Supervisor](INFO): Looking for Config files in directory: Config/
2018-11-15T23:35:10.742Z,1542324910.742 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2018-11-15T23:35:10.841Z,1542324910.841 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2018-11-15T23:35:10.842Z,1542324910.842 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2018-11-15T23:35:10.945Z,1542324910.945 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2018-11-15T23:35:10.945Z,1542324910.945 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2018-11-15T23:35:11.161Z,1542324911.161 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2018-11-15T23:35:11.162Z,1542324911.162 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2018-11-15T23:35:11.513Z,1542324911.513 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2018-11-15T23:35:11.514Z,1542324911.514 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2018-11-15T23:35:11.885Z,1542324911.885 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2018-11-15T23:35:11.886Z,1542324911.886 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2018-11-15T23:35:12.377Z,1542324912.377 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2018-11-15T23:35:12.378Z,1542324912.378 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2018-11-15T23:35:12.892Z,1542324912.892 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2018-11-15T23:35:12.893Z,1542324912.893 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2018-11-15T23:35:13.639Z,1542324913.639 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2018-11-15T23:35:13.640Z,1542324913.640 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2018-11-15T23:35:13.721Z,1542324913.721 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2018-11-15T23:35:14.068Z,1542324914.068 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2018-11-15T23:35:14.069Z,1542324914.069 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2018-11-15T23:35:14.224Z,1542324914.224 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2018-11-15T23:35:14.225Z,1542324914.225 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2018-11-15T23:35:14.454Z,1542324914.454 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2018-11-15T23:35:14.455Z,1542324914.455 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2018-11-15T23:35:14.673Z,1542324914.673 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2018-11-15T23:35:14.674Z,1542324914.674 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2018-11-15T23:35:14.774Z,1542324914.774 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2018-11-15T23:35:14.774Z,1542324914.774 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2018-11-15T23:35:14.926Z,1542324914.926 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2018-11-15T23:35:14.928Z,1542324914.928 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/
2018-11-15T23:35:14.929Z,1542324914.929 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg
2018-11-15T23:35:15.165Z,1542324915.165 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2018-11-15T23:35:15.166Z,1542324915.166 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg
2018-11-15T23:35:15.275Z,1542324915.275 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg
2018-11-15T23:35:15.434Z,1542324915.434 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg
2018-11-15T23:35:15.529Z,1542324915.529 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg
2018-11-15T23:35:15.615Z,1542324915.615 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg
2018-11-15T23:35:15.780Z,1542324915.780 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg
2018-11-15T23:35:15.993Z,1542324915.993 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg
2018-11-15T23:35:16.094Z,1542324916.094 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg
2018-11-15T23:35:16.193Z,1542324916.193 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg
2018-11-15T23:35:16.293Z,1542324916.293 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg
2018-11-15T23:35:16.379Z,1542324916.379 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/root/
2018-11-15T23:35:16.379Z,1542324916.379 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2018-11-15T23:35:16.383Z,1542324916.383 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2018-11-15T23:35:16.488Z,1542324916.488 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2018-11-15T23:35:16.489Z,1542324916.489 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2018-11-15T23:35:16.505Z,1542324916.505 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2018-11-15T23:35:16.505Z,1542324916.505 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2018-11-15T23:35:16.549Z,1542324916.549 [DepthRateCalculator] Loaded
2018-11-15T23:35:16.549Z,1542324916.549 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2018-11-15T23:35:16.556Z,1542324916.556 [PitchRateCalculator] Loaded
2018-11-15T23:35:16.556Z,1542324916.556 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2018-11-15T23:35:16.573Z,1542324916.573 [SpeedCalculator] Loaded
2018-11-15T23:35:16.573Z,1542324916.573 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2018-11-15T23:35:16.595Z,1542324916.595 [TempGradientCalculator] Loaded
2018-11-15T23:35:16.596Z,1542324916.596 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2018-11-15T23:35:16.602Z,1542324916.602 [YawRateCalculator] Loaded
2018-11-15T23:35:16.602Z,1542324916.602 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2018-11-15T23:35:16.645Z,1542324916.645 [ElevatorOffsetCalculator] Loaded
2018-11-15T23:35:16.645Z,1542324916.645 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2018-11-15T23:35:16.645Z,1542324916.645 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2018-11-15T23:35:16.646Z,1542324916.646 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2018-11-15T23:35:16.672Z,1542324916.672 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2018-11-15T23:35:16.673Z,1542324916.673 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2018-11-15T23:35:19.832Z,1542324919.832 [AcousticModem_Benthos_ATM900] Loaded
2018-11-15T23:35:19.832Z,1542324919.832 [ComponentRegistry](DEBUG): SyncComponent "AcousticModem_Benthos_ATM900" handled in the control thread.
2018-11-15T23:35:19.901Z,1542324919.901 [DataOverHttps] Loaded
2018-11-15T23:35:19.901Z,1542324919.901 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2018-11-15T23:35:19.915Z,1542324919.915 [Depth_Keller] Loaded
2018-11-15T23:35:19.916Z,1542324919.916 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2018-11-15T23:35:19.921Z,1542324919.921 [DropWeight] Loaded
2018-11-15T23:35:19.921Z,1542324919.921 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2018-11-15T23:35:20.025Z,1542324920.025 [NAL9602] Loaded
2018-11-15T23:35:20.026Z,1542324920.026 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2018-11-15T23:35:20.043Z,1542324920.043 [Onboard] Loaded
2018-11-15T23:35:20.043Z,1542324920.043 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2018-11-15T23:35:20.054Z,1542324920.054 [Radio_Surface] Loaded
2018-11-15T23:35:20.054Z,1542324920.054 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2018-11-15T23:35:20.055Z,1542324920.055 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 419D44E0
2018-11-15T23:35:20.055Z,1542324920.055 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 3031
2018-11-15T23:35:20.105Z,1542324920.105 [PNI_TCM] Loaded
2018-11-15T23:35:20.105Z,1542324920.105 [ComponentRegistry](DEBUG): SyncComponent "PNI_TCM" handled in the control thread.
2018-11-15T23:35:20.170Z,1542324920.170 [Rowe_600LCM] Loaded
2018-11-15T23:35:20.170Z,1542324920.170 [ComponentRegistry](DEBUG): Component "Rowe_600LCM" handled in its own thread.
2018-11-15T23:35:20.171Z,1542324920.171 [Rowe_600LCM ThreadHandler](DEBUG): Created PCaller Thread at 41A044E0
2018-11-15T23:35:20.172Z,1542324920.172 [Rowe_600LCM ThreadHandler](INFO): Protected caller Thread ID is 3032
2018-11-15T23:35:22.024Z,1542324922.024 [BPC1] Loaded
2018-11-15T23:35:22.025Z,1542324922.025 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2018-11-15T23:35:22.025Z,1542324922.025 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2018-11-15T23:35:22.026Z,1542324922.026 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2018-11-15T23:35:22.164Z,1542324922.164 [SBIT](DEBUG): Construct Startup Built In Test.
2018-11-15T23:35:22.189Z,1542324922.189 [SBIT] Loaded
2018-11-15T23:35:22.189Z,1542324922.189 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2018-11-15T23:35:22.190Z,1542324922.190 [IBIT](DEBUG): Construct Initiated Built In Test.
2018-11-15T23:35:22.202Z,1542324922.202 [IBIT] Loaded
2018-11-15T23:35:22.202Z,1542324922.202 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2018-11-15T23:35:22.205Z,1542324922.205 [CBIT](DEBUG): Construct Continuous Built In Test.
2018-11-15T23:35:22.362Z,1542324922.362 [CBIT] Loaded
2018-11-15T23:35:22.363Z,1542324922.363 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2018-11-15T23:35:22.363Z,1542324922.363 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2018-11-15T23:35:22.364Z,1542324922.364 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2018-11-15T23:35:22.532Z,1542324922.532 [Aanderaa_O2] Loaded
2018-11-15T23:35:22.532Z,1542324922.532 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2018-11-15T23:35:22.593Z,1542324922.593 [CTD_Seabird] Loaded
2018-11-15T23:35:22.594Z,1542324922.594 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2018-11-15T23:35:22.595Z,1542324922.595 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 41AD04E0
2018-11-15T23:35:22.595Z,1542324922.595 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 3033
2018-11-15T23:35:22.613Z,1542324922.613 [ESPComponent] Loaded
2018-11-15T23:35:22.613Z,1542324922.613 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2018-11-15T23:35:22.628Z,1542324922.628 [PAR_Licor] Loaded
2018-11-15T23:35:22.628Z,1542324922.628 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2018-11-15T23:35:22.681Z,1542324922.681 [WetLabsBB2FL] Loaded
2018-11-15T23:35:22.681Z,1542324922.681 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2018-11-15T23:35:22.682Z,1542324922.682 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 41B004E0
2018-11-15T23:35:22.683Z,1542324922.683 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 3034
2018-11-15T23:35:22.683Z,1542324922.683 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2018-11-15T23:35:22.684Z,1542324922.684 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2018-11-15T23:35:22.942Z,1542324922.942 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2018-11-15T23:35:22.943Z,1542324922.943 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2018-11-15T23:35:23.014Z,1542324923.014 [VerticalControl](DEBUG): Construct VerticalControl.
2018-11-15T23:35:23.113Z,1542324923.113 [VerticalControl] Loaded
2018-11-15T23:35:23.114Z,1542324923.114 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2018-11-15T23:35:23.114Z,1542324923.114 [HorizontalControl](DEBUG): Construct HorizontalControl.
2018-11-15T23:35:23.179Z,1542324923.179 [HorizontalControl] Loaded
2018-11-15T23:35:23.179Z,1542324923.179 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2018-11-15T23:35:23.180Z,1542324923.180 [SpeedControl](DEBUG): Construct SpeedControl.
2018-11-15T23:35:23.186Z,1542324923.186 [SpeedControl] Loaded
2018-11-15T23:35:23.186Z,1542324923.186 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2018-11-15T23:35:23.187Z,1542324923.187 [LoopControl](DEBUG): Construct LoopControl.
2018-11-15T23:35:23.187Z,1542324923.187 [LoopControl] Loaded
2018-11-15T23:35:23.188Z,1542324923.188 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2018-11-15T23:35:23.188Z,1542324923.188 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2018-11-15T23:35:23.189Z,1542324923.189 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2018-11-15T23:35:23.256Z,1542324923.256 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2018-11-15T23:35:23.257Z,1542324923.257 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2018-11-15T23:35:23.360Z,1542324923.360 [BuoyancyServo] Loaded
2018-11-15T23:35:23.361Z,1542324923.361 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2018-11-15T23:35:23.372Z,1542324923.372 [ElevatorServo] Loaded
2018-11-15T23:35:23.373Z,1542324923.373 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2018-11-15T23:35:23.384Z,1542324923.384 [MassServo] Loaded
2018-11-15T23:35:23.385Z,1542324923.385 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2018-11-15T23:35:23.396Z,1542324923.396 [RudderServo] Loaded
2018-11-15T23:35:23.397Z,1542324923.397 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2018-11-15T23:35:23.408Z,1542324923.408 [ThrusterServo] Loaded
2018-11-15T23:35:23.408Z,1542324923.408 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2018-11-15T23:35:23.409Z,1542324923.409 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2018-11-15T23:35:23.409Z,1542324923.409 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2018-11-15T23:35:23.505Z,1542324923.505 [DeadReckonUsingSpeedCalculator] Loaded
2018-11-15T23:35:23.506Z,1542324923.506 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2018-11-15T23:35:23.523Z,1542324923.523 [NavChart] Loaded
2018-11-15T23:35:23.523Z,1542324923.523 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2018-11-15T23:35:23.527Z,1542324923.527 [UniversalFixResidualReporter] Loaded
2018-11-15T23:35:23.528Z,1542324923.528 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2018-11-15T23:35:23.528Z,1542324923.528 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2018-11-15T23:35:23.532Z,1542324923.532 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2018-11-15T23:35:23.533Z,1542324923.533 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2018-11-15T23:35:23.540Z,1542324923.540 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2018-11-15T23:35:23.541Z,1542324923.541 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 41C594E0
2018-11-15T23:35:23.541Z,1542324923.541 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 3035
2018-11-15T23:35:23.546Z,1542324923.546 [Supervisor](INFO): Main Thread ID is 2819
2018-11-15T23:35:23.547Z,1542324923.547 [Supervisor](DEBUG): Running supervisor.
2018-11-15T23:35:23.547Z,1542324923.547 [CommandLine ThreadHandler](INFO): Handler Thread ID is 3036
2018-11-15T23:35:23.550Z,1542324923.550 [controlThread ThreadHandler](INFO): Handler Thread ID is 3037
2018-11-15T23:35:23.550Z,1542324923.550 [controlThread](DEBUG): Initializing ControlThread
2018-11-15T23:35:23.551Z,1542324923.551 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2018-11-15T23:35:23.551Z,1542324923.551 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2018-11-15T23:35:23.552Z,1542324923.552 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2018-11-15T23:35:23.552Z,1542324923.552 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2018-11-15T23:35:23.552Z,1542324923.552 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2018-11-15T23:35:23.553Z,1542324923.553 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2018-11-15T23:35:23.560Z,1542324923.560 [SBIT](INFO): Initialize SBIT Component.
2018-11-15T23:35:23.560Z,1542324923.560 [SBIT](IMPORTANT): git: 2018-11-05
2018-11-15T23:35:23.561Z,1542324923.561 [SBIT](INFO): git hash: 17f8e4440ddc7f0910aa911cb821ed1a114d9cee
2018-11-15T23:35:23.561Z,1542324923.561 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2018-11-15T23:35:23.561Z,1542324923.561 [SBIT](IMPORTANT): Kernel Version:#2 PREEMPT Thu Jan 11 20:13:48 PST 2018
2018-11-15T23:35:23.562Z,1542324923.562 [SBIT](INFO): Beginning SBIT in 24.000000 seconds.
2018-11-15T23:35:23.563Z,1542324923.563 [IBIT](INFO): Initialize IBIT Component.
2018-11-15T23:35:23.564Z,1542324923.564 [CBIT](DEBUG): Initialize CBIT Component.
2018-11-15T23:35:23.564Z,1542324923.564 [CBIT](CRITICAL): LAST REBOOT DUE TO WATCHDOG TIMER RESET.
2018-11-15T23:35:23.565Z,1542324923.565 [logger ThreadHandler](INFO): Handler Thread ID is 3038
2018-11-15T23:35:23.582Z,1542324923.582 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 3039
2018-11-15T23:35:23.588Z,1542324923.588 [Radio_Surface](INFO): Powering up
2018-11-15T23:35:23.594Z,1542324923.594 [Rowe_600LCM ThreadHandler](INFO): Handler Thread ID is 3040
2018-11-15T23:35:23.595Z,1542324923.595 [Rowe_600LCM](INFO): Initializing
2018-11-15T23:35:23.595Z,1542324923.595 [Rowe_600LCM](INFO): Checking LCM
2018-11-15T23:35:23.604Z,1542324923.604 [Rowe_600LCM](INFO): LCM OK
2018-11-15T23:35:23.604Z,1542324923.604 [Rowe_600LCM](INFO): Powering up
2018-11-15T23:35:23.610Z,1542324923.610 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 3041
2018-11-15T23:35:23.611Z,1542324923.611 [CTD_Seabird](INFO): Initializing
2018-11-15T23:35:23.611Z,1542324923.611 [CTD_Seabird](INFO): Checking LCM
2018-11-15T23:35:23.612Z,1542324923.612 [CTD_Seabird](INFO): LCM OK
2018-11-15T23:35:23.612Z,1542324923.612 [CTD_Seabird](INFO): Powering up
2018-11-15T23:35:23.618Z,1542324923.618 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 3042
2018-11-15T23:35:23.619Z,1542324923.619 [WetLabsBB2FL](INFO): Powering down
2018-11-15T23:35:23.646Z,1542324923.646 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 3043
2018-11-15T23:35:23.650Z,1542324923.650 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2018-11-15T23:35:23.650Z,1542324923.650 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2018-11-15T23:35:23.650Z,1542324923.650 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2018-11-15T23:35:23.651Z,1542324923.651 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2018-11-15T23:35:23.651Z,1542324923.651 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2018-11-15T23:35:23.651Z,1542324923.651 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2018-11-15T23:35:23.651Z,1542324923.651 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2018-11-15T23:35:23.651Z,1542324923.651 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2018-11-15T23:35:23.652Z,1542324923.652 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2018-11-15T23:35:23.652Z,1542324923.652 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2018-11-15T23:35:23.652Z,1542324923.652 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2018-11-15T23:35:23.652Z,1542324923.652 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2018-11-15T23:35:23.652Z,1542324923.652 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2018-11-15T23:35:23.653Z,1542324923.653 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2018-11-15T23:35:23.653Z,1542324923.653 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2018-11-15T23:35:23.653Z,1542324923.653 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2018-11-15T23:35:23.674Z,1542324923.674 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2018-11-15T23:35:23.676Z,1542324923.676 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2018-11-15T23:35:23.677Z,1542324923.677 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2018-11-15T23:35:23.677Z,1542324923.677 [LoopControl](DEBUG): Initialize LoopControlComponent.
2018-11-15T23:35:23.679Z,1542324923.679 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-11-15T23:35:23.680Z,1542324923.680 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-11-15T23:35:23.680Z,1542324923.680 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-11-15T23:35:23.681Z,1542324923.681 [NavChart](DEBUG): Initialize NavChart Navigation.
2018-11-15T23:35:23.681Z,1542324923.681 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2018-11-15T23:35:23.682Z,1542324923.682 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2018-11-15T23:35:23.706Z,1542324923.706 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2018-11-15T23:35:23.738Z,1542324923.738 [MissionManager](DEBUG):
2018-11-15T23:35:23.739Z,1542324923.739 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2018-11-15T23:35:23.831Z,1542324923.831 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2018-11-15T23:35:23.832Z,1542324923.832 [Default:A.Wait](DEBUG): Construct Wait.
2018-11-15T23:35:23.834Z,1542324923.834 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2018-11-15T23:35:23.860Z,1542324923.860 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2018-11-15T23:35:23.879Z,1542324923.879 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2018-11-15T23:35:23.885Z,1542324923.885 [Default:E.Execute](DEBUG): Construct Execute.
2018-11-15T23:35:23.905Z,1542324923.905 [MissionManager](DEBUG):
0
Wait a moment to see if the scheduler starts a new mission before
starting to actually run Default.
13
Burn on
Dropped weight due to communications timeout.
5
Default mission has been running for
Restarting logs and Default mission.
restart logs
2018-11-15T23:35:23.910Z,1542324923.910 [controlThread](DEBUG): Component order: CycleStarter,AcousticModem_Benthos_ATM900,DataOverHttps,Depth_Keller,DropWeight,NAL9602,Onboard,PNI_TCM,BPC1,Aanderaa_O2,ESPComponent,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-15T23:35:23.938Z,1542324923.938 [AcousticModem_Benthos_ATM900](INFO): Powering up
2018-11-15T23:35:23.938Z,1542324923.938 [AcousticModem_Benthos_ATM900](DEBUG): Initializing AcousticModem_Benthos_ATM900.
2018-11-15T23:35:23.968Z,1542324923.968 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2018-11-15T23:35:23.983Z,1542324923.983 [Depth_Keller](ERROR): Pressure reading out of range: 1895.684326 decibar
2018-11-15T23:35:24.153Z,1542324924.153 [ESPComponent](INFO): powering down ESP
2018-11-15T23:35:24.489Z,1542324924.489 [DepthRateCalculator](ERROR): Depth measurement is not active
2018-11-15T23:35:24.699Z,1542324924.699 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2018-11-15T23:35:24.706Z,1542324924.706 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2018-11-15T23:35:24.728Z,1542324924.728 [ElevatorServo](DEBUG): Initializing EZServoServo.
2018-11-15T23:35:24.734Z,1542324924.734 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2018-11-15T23:35:24.756Z,1542324924.756 [MassServo](DEBUG): Initializing EZServoServo.
2018-11-15T23:35:24.762Z,1542324924.762 [MassServo](DEBUG): Initializing MassServo.
2018-11-15T23:35:24.768Z,1542324924.768 [RudderServo](DEBUG): Initializing EZServoServo.
2018-11-15T23:35:24.774Z,1542324924.774 [RudderServo](DEBUG): Initializing RudderServo.
2018-11-15T23:35:24.796Z,1542324924.796 [ThrusterServo](DEBUG): Initializing EZServoServo.
2018-11-15T23:35:24.802Z,1542324924.802 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2018-11-15T23:35:24.848Z,1542324924.848 [CommandLine](FAULT): Scheduling is paused
2018-11-15T23:35:24.848Z,1542324924.848 [CBIT](INFO): Critical error at 20181115T233523
2018-11-15T23:35:24.848Z,1542324924.848 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2018-11-15T23:35:25.040Z,1542324925.040 [DropWeight](CRITICAL): DROP WEIGHT MISSING.
2018-11-15T23:35:25.040Z,1542324925.040 [DropWeight] Hardware Fault, FailCount= 1
2018-11-15T23:35:25.040Z,1542324925.040 [DropWeight](ERROR): Hardware Fault
2018-11-15T23:35:25.142Z,1542324925.142 [CBIT](INFO): Critical error at 20181115T233525
2018-11-15T23:35:25.144Z,1542324925.144 [CBIT](ERROR): Hardware Fault in component: DropWeight
2018-11-15T23:35:25.145Z,1542324925.145 [CBIT](CRITICAL): Hardware Fault in component: DropWeight
2018-11-15T23:35:25.763Z,1542324925.763 [CBIT](INFO): Critical error at 20181115T233525
2018-11-15T23:35:27.917Z,1542324927.917 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-11-15T23:35:28.072Z,1542324928.072 [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-15T23:35:28.119Z,1542324928.119 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-11-15T23:35:28.120Z,1542324928.120 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-11-15T23:35:28.120Z,1542324928.120 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-11-15T23:35:29.171Z,1542324929.171 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface
2018-11-15T23:35:29.289Z,1542324929.289 [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-15T23:35:29.290Z,1542324929.290 [CTD_Seabird](INFO): LCM subscribed to channel:seabird_gpctd_t.seabird-gpctd
2018-11-15T23:35:29.679Z,1542324929.679 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface
2018-11-15T23:35:29.679Z,1542324929.679 [CTD_Seabird](INFO): Powering down
2018-11-15T23:35:31.375Z,1542324931.375 [AcousticModem_Benthos_ATM900](DEBUG):
2018-11-15T23:35:31.394Z,1542324931.394 [PNI_TCM](FAULT): Failed to set parameters during initialization.
2018-11-15T23:35:31.394Z,1542324931.394 [PNI_TCM] Data Fault, FailCount= 1
2018-11-15T23:35:31.394Z,1542324931.394 [PNI_TCM](ERROR): Data Fault
2018-11-15T23:35:31.464Z,1542324931.464 [CBIT](ERROR): Data Fault in component: PNI_TCM
2018-11-15T23:35:31.794Z,1542324931.794 [PNI_TCM](INFO): Powering down
2018-11-15T23:35:32.579Z,1542324932.579 [AcousticModem_Benthos_ATM900](DEBUG): Teledyne Benthos ATM-900 Series OEM w/burn wire
2018-11-15T23:35:32.579Z,1542324932.579 [AcousticModem_Benthos_ATM900](DEBUG): MF Frequency Band
2018-11-15T23:35:32.580Z,1542324932.580 [AcousticModem_Benthos_ATM900](DEBUG): Standard version 8.6.3
2018-11-15T23:35:32.975Z,1542324932.975 [AcousticModem_Benthos_ATM900](DEBUG): Nov 3 2018 10:21:30
2018-11-15T23:35:33.103Z,1542324933.103 [CBIT](INFO): Clearing failed state for component PNI_TCM
2018-11-15T23:35:33.103Z,1542324933.103 [PNI_TCM] No Fault, FailCount= 1
2018-11-15T23:35:33.376Z,1542324933.376 [AcousticModem_Benthos_ATM900](DEBUG): WARNING: battery low
2018-11-15T23:35:33.907Z,1542324933.907 [CBIT](CRITICAL): Environmental Failure. Press:14.803835 PSI. Humidity:32%. Temp:26 C. ABORTING MISSION
2018-11-15T23:35:34.175Z,1542324934.175 [AcousticModem_Benthos_ATM900](INFO): entering command mode
2018-11-15T23:35:34.213Z,1542324934.213 [Aanderaa_O2](FAULT): Failed to initialize within timeout.
2018-11-15T23:35:34.213Z,1542324934.213 [Aanderaa_O2] Communications Fault, FailCount= 1
2018-11-15T23:35:34.214Z,1542324934.214 [Aanderaa_O2](ERROR): Communications Fault
2018-11-15T23:35:34.374Z,1542324934.374 [CBIT](INFO): Critical error at 20181115T233533
2018-11-15T23:35:34.376Z,1542324934.376 [CBIT](ERROR): Communications Fault in component: Aanderaa_O2
2018-11-15T23:35:34.575Z,1542324934.575 [AcousticModem_Benthos_ATM900](DEBUG): checking for command mode acknowledgment
2018-11-15T23:35:34.575Z,1542324934.575 [AcousticModem_Benthos_ATM900](DEBUG): read user prompt 1: user:1>
2018-11-15T23:35:34.576Z,1542324934.576 [AcousticModem_Benthos_ATM900](INFO): command mode acknowledged
2018-11-15T23:35:34.596Z,1542324934.596 [Aanderaa_O2](INFO): Powering down
2018-11-15T23:35:34.975Z,1542324934.975 [AcousticModem_Benthos_ATM900](INFO): setting local address to 3
2018-11-15T23:35:35.375Z,1542324935.375 [AcousticModem_Benthos_ATM900](DEBUG): checking for local address setting acknowledgment
2018-11-15T23:35:35.376Z,1542324935.376 [AcousticModem_Benthos_ATM900](INFO): set local address to 3
2018-11-15T23:35:35.491Z,1542324935.491 [CBIT](INFO): Clearing failed state for component Aanderaa_O2
2018-11-15T23:35:35.491Z,1542324935.491 [Aanderaa_O2] No Fault, FailCount= 1
2018-11-15T23:35:35.775Z,1542324935.775 [AcousticModem_Benthos_ATM900](DEBUG): read user prompt 2: user:2>
2018-11-15T23:35:40.595Z,1542324940.595 [PNI_TCM](FAULT): Failed to set parameters during initialization.
2018-11-15T23:35:40.595Z,1542324940.595 [PNI_TCM] Data Fault, FailCount= 2
2018-11-15T23:35:40.595Z,1542324940.595 [PNI_TCM](ERROR): Data Fault
2018-11-15T23:35:40.666Z,1542324940.666 [CBIT](ERROR): Data Fault in component: PNI_TCM
2018-11-15T23:35:40.000Z,1542324941.000 [PNI_TCM](INFO): Powering down
2018-11-15T23:35:42.257Z,1542324942.257 [CBIT](INFO): Clearing failed state for component PNI_TCM
2018-11-15T23:35:42.257Z,1542324942.257 [PNI_TCM] No Fault, FailCount= 2
2018-11-15T23:35:45.795Z,1542324945.795 [Aanderaa_O2](FAULT): Failed to initialize within timeout.
2018-11-15T23:35:45.795Z,1542324945.795 [Aanderaa_O2] Communications Fault, FailCount= 2
2018-11-15T23:35:45.795Z,1542324945.795 [Aanderaa_O2](ERROR): Communications Fault
2018-11-15T23:35:45.887Z,1542324945.887 [CBIT](ERROR): Communications Fault in component: Aanderaa_O2
2018-11-15T23:35:46.196Z,1542324946.196 [Aanderaa_O2](INFO): Powering down
2018-11-15T23:35:47.088Z,1542324947.088 [CBIT](INFO): Clearing failed state for component Aanderaa_O2
2018-11-15T23:35:47.088Z,1542324947.088 [Aanderaa_O2] No Fault, FailCount= 2
2018-11-15T23:35:48.246Z,1542324948.246 [SBIT](IMPORTANT): Beginning Startup BIT
2018-11-15T23:35:48.250Z,1542324948.250 [CBIT](IMPORTANT): Beginning ground fault scan
2018-11-15T23:35:49.794Z,1542324949.794 [PNI_TCM](FAULT): Failed to set parameters during initialization.
2018-11-15T23:35:49.794Z,1542324949.794 [PNI_TCM] Data Fault, FailCount= 3
2018-11-15T23:35:49.794Z,1542324949.794 [PNI_TCM](ERROR): Data Fault
2018-11-15T23:35:50.002Z,1542324950.002 [CBIT](ERROR): Data Fault in component: PNI_TCM
2018-11-15T23:35:50.183Z,1542324950.183 [NAL9602](INFO): Powering up NAL9602
2018-11-15T23:35:50.210Z,1542324950.210 [PNI_TCM](INFO): Powering down
2018-11-15T23:35:51.283Z,1542324951.283 [CBIT](INFO): Clearing failed state for component PNI_TCM
2018-11-15T23:35:51.283Z,1542324951.283 [PNI_TCM] No Fault, FailCount= 3
2018-11-15T23:35:57.538Z,1542324957.538 [Aanderaa_O2](FAULT): Failed to initialize within timeout.
2018-11-15T23:35:57.538Z,1542324957.538 [Aanderaa_O2] Communications Fault, FailCount= 3
2018-11-15T23:35:57.538Z,1542324957.538 [Aanderaa_O2](ERROR): Communications Fault
2018-11-15T23:35:57.655Z,1542324957.655 [CBIT](ERROR): Communications Fault in component: Aanderaa_O2
2018-11-15T23:35:57.656Z,1542324957.656 [CBIT](FAULT): Communications Fault in component: Aanderaa_O2
2018-11-15T23:35:58.054Z,1542324958.054 [Aanderaa_O2](INFO): Powering down
2018-11-15T23:35:58.738Z,1542324958.738 [PNI_TCM](FAULT): Failed to set parameters during initialization.
2018-11-15T23:35:58.738Z,1542324958.738 [PNI_TCM] Data Fault, FailCount= 4
2018-11-15T23:35:58.738Z,1542324958.738 [PNI_TCM](ERROR): Data Fault
2018-11-15T23:35:58.831Z,1542324958.831 [CBIT](ERROR): Data Fault in component: PNI_TCM
2018-11-15T23:35:59.137Z,1542324959.137 [PNI_TCM](INFO): Powering down
2018-11-15T23:35:59.335Z,1542324959.335 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.007868
CHAN A1 (24V): -0.011786
CHAN A2 (12V): -0.005372
CHAN A3 (5V): -0.002920
CHAN B0 (3.3V): -0.000958
CHAN B1 (3.15aV): -0.001812
CHAN B2 (3.15bV): -0.001084
CHAN B3 (GND): 0.000055
OPEN: 0.004523
Full Scale Calc: 4.765 mA, -1.589 mA
2018-11-15T23:36:00.431Z,1542324960.431 [CBIT](INFO): Clearing failed state for component PNI_TCM
2018-11-15T23:36:00.431Z,1542324960.431 [PNI_TCM] No Fault, FailCount= 4
2018-11-15T23:36:01.123Z,1542324961.123 [NAL9602](INFO): NAL9602 initialized
2018-11-15T23:36:08.099Z,1542324968.099 [PNI_TCM](FAULT): Failed to set parameters during initialization.
2018-11-15T23:36:08.099Z,1542324968.099 [PNI_TCM] Data Fault, FailCount= 5
2018-11-15T23:36:08.099Z,1542324968.099 [PNI_TCM](ERROR): Data Fault
2018-11-15T23:36:08.251Z,1542324968.251 [CBIT](ERROR): Data Fault in component: PNI_TCM
2018-11-15T23:36:08.251Z,1542324968.251 [CBIT](CRITICAL): Data Fault in component: PNI_TCM
2018-11-15T23:36:08.498Z,1542324968.498 [PNI_TCM](INFO): Powering down
2018-11-15T23:36:08.765Z,1542324968.765 [CBIT](INFO): Critical error at 20181115T233608
2018-11-15T23:36:42.251Z,1542325002.251 [SBIT](IMPORTANT): SBIT PASSED
2018-11-15T23:36:42.315Z,1542325002.315 [CommandLine](IMPORTANT): got command configSet list
2018-11-15T23:36:42.315Z,1542325002.315 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2018-11-15T23:36:42.317Z,1542325002.317 [CommandLine](IMPORTANT): PAR_Licor.loadAtStartup=1 bool;
2018-11-15T23:36:42.652Z,1542325002.652 [MissionManager](IMPORTANT): Started mission Startup
2018-11-15T23:36:42.652Z,1542325002.652 [Startup] Running Loop=1
2018-11-15T23:36:42.653Z,1542325002.653 [Startup](DEBUG): Aggregate::initialize Startup
2018-11-15T23:36:42.653Z,1542325002.653 [Startup:A.GoToSurface] Running Loop=1
2018-11-15T23:36:42.653Z,1542325002.653 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-11-15T23:36:42.654Z,1542325002.654 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2018-11-15T23:36:42.654Z,1542325002.654 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2018-11-15T23:36:42.654Z,1542325002.654 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2018-11-15T23:36:42.655Z,1542325002.655 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-11-15T23:36:42.655Z,1542325002.655 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2018-11-15T23:36:42.697Z,1542325002.697 [Startup:StartupSatComms] Running Loop=1
2018-11-15T23:36:42.697Z,1542325002.697 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2018-11-15T23:36:42.697Z,1542325002.697 [Startup:StartupSatComms:A] Running Loop=1
2018-11-15T23:36:43.057Z,1542325003.057 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2018-11-15T23:37:23.794Z,1542325043.794 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-11-15T23:37:23.794Z,1542325043.794 [Rowe_600LCM] Communications Fault, FailCount= 1
2018-11-15T23:37:23.794Z,1542325043.794 [Rowe_600LCM](ERROR): Communications Fault
2018-11-15T23:37:23.863Z,1542325043.863 [DeadReckonUsingSpeedCalculator](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2018-11-15T23:37:23.863Z,1542325043.863 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 1
2018-11-15T23:37:23.863Z,1542325043.863 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-11-15T23:37:23.898Z,1542325043.898 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-11-15T23:37:23.898Z,1542325043.898 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-11-15T23:37:24.206Z,1542325044.206 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-11-15T23:37:24.360Z,1542325044.360 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-11-15T23:37:24.360Z,1542325044.360 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 1
2018-11-15T23:37:24.440Z,1542325044.440 [Rowe_600LCM](INFO): Powering down
2018-11-15T23:37:24.649Z,1542325044.649 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-11-15T23:37:24.650Z,1542325044.650 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-11-15T23:37:24.650Z,1542325044.650 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-11-15T23:37:25.861Z,1542325045.861 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-11-15T23:37:25.861Z,1542325045.861 [Rowe_600LCM] No Fault, FailCount= 1
2018-11-15T23:37:26.054Z,1542325046.054 [Rowe_600LCM](INFO): Initializing
2018-11-15T23:37:26.054Z,1542325046.054 [Rowe_600LCM](INFO): Checking LCM
2018-11-15T23:37:26.054Z,1542325046.054 [Rowe_600LCM](INFO): LCM OK
2018-11-15T23:37:26.055Z,1542325046.055 [Rowe_600LCM](INFO): Powering up
2018-11-15T23:37:30.178Z,1542325050.178 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-11-15T23:37:30.317Z,1542325050.317 [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-15T23:37:30.318Z,1542325050.318 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-11-15T23:37:30.319Z,1542325050.319 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-11-15T23:37:30.319Z,1542325050.319 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-11-15T23:37:43.073Z,1542325063.073 [Startup:StartupSatComms:A](INFO): Timed out from 2018-11-15T23:36:42.7Z
2018-11-15T23:37:43.073Z,1542325063.073 [Startup:StartupSatComms:A] Stopped
2018-11-15T23:37:43.073Z,1542325063.073 [Startup:StartupSatComms:B] Running Loop=1
2018-11-15T23:37:43.461Z,1542325063.461 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2018-11-15T23:38:27.838Z,1542325107.838 [CBIT](INFO): Clearing failed state for component Aanderaa_O2
2018-11-15T23:38:27.838Z,1542325107.838 [Aanderaa_O2] No Fault, FailCount= 3
2018-11-15T23:38:28.652Z,1542325108.652 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004314
2018-11-15T23:38:33.365Z,1542325113.365 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20181114T205553/Courier0451.lzma
2018-11-15T23:38:34.165Z,1542325114.165 [DataOverHttps](INFO): Moved sent file to Logs/20181114T205553/Courier0451.lzma.bak
2018-11-15T23:38:34.165Z,1542325114.165 [DataOverHttps](INFO): SBD MOMSN=8886964
2018-11-15T23:38:38.163Z,1542325118.163 [Aanderaa_O2](FAULT): Failed to initialize within timeout.
2018-11-15T23:38:38.163Z,1542325118.163 [Aanderaa_O2] Communications Fault, FailCount= 1
2018-11-15T23:38:38.163Z,1542325118.163 [Aanderaa_O2](ERROR): Communications Fault
2018-11-15T23:38:38.215Z,1542325118.215 [CBIT](ERROR): Communications Fault in component: Aanderaa_O2
2018-11-15T23:38:38.678Z,1542325118.678 [Aanderaa_O2](INFO): Powering down
2018-11-15T23:38:39.395Z,1542325119.395 [CBIT](INFO): Clearing failed state for component Aanderaa_O2
2018-11-15T23:38:39.395Z,1542325119.395 [Aanderaa_O2] No Fault, FailCount= 1
2018-11-15T23:38:43.398Z,1542325123.398 [Startup:StartupSatComms:B](INFO): Timed out from 2018-11-15T23:37:43.1Z
2018-11-15T23:38:43.398Z,1542325123.398 [Startup:StartupSatComms:B] Stopped
2018-11-15T23:38:43.398Z,1542325123.398 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2018-11-15T23:38:43.398Z,1542325123.398 [Startup:StartupSatComms] Stopped
2018-11-15T23:38:43.398Z,1542325123.398 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2018-11-15T23:38:43.399Z,1542325123.399 [Startup](INFO): Completed Startup
2018-11-15T23:38:43.399Z,1542325123.399 [MissionManager](INFO): Startup is completed.
2018-11-15T23:38:43.400Z,1542325123.400 [MissionManager](INFO): Uninitializing Mission Startup
2018-11-15T23:38:43.400Z,1542325123.400 [Startup] Stopped
2018-11-15T23:38:43.400Z,1542325123.400 [Startup](DEBUG): Aggregate::uninitialize Startup
2018-11-15T23:38:43.400Z,1542325123.400 [Startup:A.GoToSurface] Stopped
2018-11-15T23:38:43.400Z,1542325123.400 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2018-11-15T23:38:46.492Z,1542325126.492 [MissionManager](IMPORTANT): Started mission Default
2018-11-15T23:38:46.493Z,1542325126.493 [Default] Running Loop=1
2018-11-15T23:38:46.493Z,1542325126.493 [Default](DEBUG): Aggregate::initialize Default
2018-11-15T23:38:46.493Z,1542325126.493 [Default:B.GoToSurface] Running Loop=1
2018-11-15T23:38:46.493Z,1542325126.493 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-11-15T23:38:46.493Z,1542325126.493 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2018-11-15T23:38:46.494Z,1542325126.494 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2018-11-15T23:38:46.494Z,1542325126.494 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2018-11-15T23:38:46.494Z,1542325126.494 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-11-15T23:38:46.495Z,1542325126.495 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2018-11-15T23:38:46.495Z,1542325126.495 [Default:A.Wait] Running Loop=1
2018-11-15T23:38:46.495Z,1542325126.495 [Default:A.Wait](DEBUG): Initialize Wait Component.
2018-11-15T23:38:53.966Z,1542325133.966 [Aanderaa_O2](FAULT): Failed to initialize within timeout.
2018-11-15T23:38:53.966Z,1542325133.966 [Aanderaa_O2] Communications Fault, FailCount= 2
2018-11-15T23:38:53.966Z,1542325133.966 [Aanderaa_O2](ERROR): Communications Fault
2018-11-15T23:38:54.066Z,1542325134.066 [CBIT](ERROR): Communications Fault in component: Aanderaa_O2
2018-11-15T23:38:54.091Z,1542325134.091 [DataOverHttps](INFO): Sending 253 bytes from file Logs/20181115T233412/Courier0000.lzma
2018-11-15T23:38:54.278Z,1542325134.278 [Aanderaa_O2](INFO): Powering down
2018-11-15T23:38:54.877Z,1542325134.877 [DataOverHttps](INFO): Moved sent file to Logs/20181115T233412/Courier0000.lzma.bak
2018-11-15T23:38:54.877Z,1542325134.877 [DataOverHttps](INFO): SBD MOMSN=8886968
2018-11-15T23:38:54.970Z,1542325134.970 [CommandLine](IMPORTANT): got command restart system
2018-11-15T23:38:55.049Z,1542325135.049 [CBIT](INFO): Clearing failed state for component Aanderaa_O2
2018-11-15T23:38:55.049Z,1542325135.049 [Aanderaa_O2] No Fault, FailCount= 2
2018-11-15T23:38:59.768Z,1542325139.768 [Default:A.Wait](INFO): Done Waiting.
2018-11-15T23:38:59.770Z,1542325139.770 [Default:A.Wait] Stopped
2018-11-15T23:38:59.770Z,1542325139.770 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2018-11-15T23:39:00.153Z,1542325140.153 [Default:CheckIn] Running Loop=1
2018-11-15T23:39:00.153Z,1542325140.153 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-11-15T23:39:00.160Z,1542325140.160 [Default:CheckIn:Read_GPS] Running Loop=1
2018-11-15T23:39:00.558Z,1542325140.558 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2018-11-15T23:39:01.681Z,1542325141.681 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2018-11-15T23:39:01.681Z,1542325141.681 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-11-15T23:39:01.699Z,1542325141.699 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye!
2018-11-15T23:39:01.699Z,1542325141.699 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-11-15T23:39:01.700Z,1542325141.700 [CommandLine](INFO): Join timeout helper Thread ID is 3084
2018-11-15T23:39:01.710Z,1542325141.710 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2018-11-15T23:39:01.710Z,1542325141.710 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-11-15T23:39:01.710Z,1542325141.710 [NavChartDb](INFO): Join timeout helper Thread ID is 3085
2018-11-15T23:39:01.822Z,1542325141.822 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2018-11-15T23:39:01.822Z,1542325141.822 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-11-15T23:39:01.838Z,1542325141.838 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2018-11-15T23:39:01.838Z,1542325141.838 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2018-11-15T23:39:01.838Z,1542325141.838 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 3086
2018-11-15T23:39:02.059Z,1542325142.059 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2018-11-15T23:39:02.059Z,1542325142.059 [WetLabsBB2FL](INFO): Powering down
2018-11-15T23:39:02.061Z,1542325142.061 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2018-11-15T23:39:02.096Z,1542325142.096 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2018-11-15T23:39:02.096Z,1542325142.096 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2018-11-15T23:39:02.127Z,1542325142.127 [CTD_Seabird](INFO): Join timeout helper Thread ID is 3087
2018-11-15T23:39:02.318Z,1542325142.318 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2018-11-15T23:39:02.563Z,1542325142.563 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface
2018-11-15T23:39:02.563Z,1542325142.563 [CTD_Seabird](INFO): Powering down
2018-11-15T23:39:02.564Z,1542325142.564 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2018-11-15T23:39:02.570Z,1542325142.570 [ComponentRegistry](INFO): Shutting down Rowe_600LCM ThreadHandler
2018-11-15T23:39:02.570Z,1542325142.570 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2018-11-15T23:39:02.571Z,1542325142.571 [Rowe_600LCM](INFO): Join timeout helper Thread ID is 3089
2018-11-15T23:39:03.290Z,1542325143.290 [Rowe_600LCM ThreadHandler](INFO): Uninitializing protected caller thread.
2018-11-15T23:39:03.291Z,1542325143.291 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-11-15T23:39:03.528Z,1542325143.528 [Rowe_600LCM](INFO): Powering down
2018-11-15T23:39:03.530Z,1542325143.530 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2018-11-15T23:39:03.547Z,1542325143.547 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2018-11-15T23:39:03.547Z,1542325143.547 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-11-15T23:39:03.548Z,1542325143.548 [Radio_Surface](INFO): Join timeout helper Thread ID is 3091
2018-11-15T23:39:03.598Z,1542325143.598 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2018-11-15T23:39:03.599Z,1542325143.599 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-11-15T23:39:03.611Z,1542325143.611 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2018-11-15T23:39:03.611Z,1542325143.611 [logger ThreadHandler](INFO): Thread cancelled.
2018-11-15T23:39:03.611Z,1542325143.611 [logger](INFO): Join timeout helper Thread ID is 3092
2018-11-15T23:39:03.634Z,1542325143.634 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2018-11-15T23:39:03.634Z,1542325143.634 [logger ThreadHandler](INFO): Thread cancelled.
2018-11-15T23:39:03.636Z,1542325143.636 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2018-11-15T23:39:03.636Z,1542325143.636 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-11-15T23:39:03.636Z,1542325143.636 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2018-11-15T23:39:03.636Z,1542325143.636 [controlThread ThreadHandler](INFO): Thread cancelled.
2018-11-15T23:39:03.637Z,1542325143.637 [controlThread](INFO): Join timeout helper Thread ID is 3093
2018-11-15T23:39:03.670Z,1542325143.670 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2018-11-15T23:39:03.670Z,1542325143.670 [controlThread](DEBUG): Uninitializing ControlThread
2018-11-15T23:39:03.671Z,1542325143.671 [AcousticModem_Benthos_ATM900](INFO): Powering down
2018-11-15T23:39:03.791Z,1542325143.791 [NAL9602](INFO): Powering down
2018-11-15T23:39:03.793Z,1542325143.793 [PNI_TCM](INFO): Powering down
2018-11-15T23:39:03.918Z,1542325143.918 [Aanderaa_O2](INFO): Powering down
2018-11-15T23:39:03.921Z,1542325143.921 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2018-11-15T23:39:03.922Z,1542325143.922 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2018-11-15T23:39:03.923Z,1542325143.923 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2018-11-15T23:39:03.923Z,1542325143.923 [MissionManager](INFO): Uninitializing Mission Default
2018-11-15T23:39:03.924Z,1542325143.924 [Default] Stopped
2018-11-15T23:39:03.924Z,1542325143.924 [Default](DEBUG): Aggregate::uninitialize Default
2018-11-15T23:39:03.924Z,1542325143.924 [Default:B.GoToSurface] Stopped
2018-11-15T23:39:03.924Z,1542325143.924 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2018-11-15T23:39:03.924Z,1542325143.924 [Default:CheckIn] Stopped
2018-11-15T23:39:03.924Z,1542325143.924 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-11-15T23:39:03.924Z,1542325143.924 [Default:CheckIn:Read_GPS] Stopped
2018-11-15T23:39:03.928Z,1542325143.928 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2018-11-15T23:39:03.928Z,1542325143.928 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2018-11-15T23:39:03.929Z,1542325143.929 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2018-11-15T23:39:03.929Z,1542325143.929 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2018-11-15T23:39:03.929Z,1542325143.929 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2018-11-15T23:39:03.930Z,1542325143.930 [BuoyancyServo](INFO): Powering down
2018-11-15T23:39:03.942Z,1542325143.942 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2018-11-15T23:39:03.942Z,1542325143.942 [ElevatorServo](INFO): Powering down
2018-11-15T23:39:03.943Z,1542325143.943 [MassServo](DEBUG): Uninitialize Mass Servo.
2018-11-15T23:39:03.943Z,1542325143.943 [MassServo](INFO): Powering down
2018-11-15T23:39:03.944Z,1542325143.944 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2018-11-15T23:39:03.944Z,1542325143.944 [RudderServo](INFO): Powering down
2018-11-15T23:39:03.945Z,1542325143.945 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2018-11-15T23:39:03.946Z,1542325143.946 [ThrusterServo](INFO): Powering down
2018-11-15T23:39:03.947Z,1542325143.947 [SBIT](DEBUG): Uninitialize SBIT Component.
2018-11-15T23:39:03.947Z,1542325143.947 [IBIT](DEBUG): Uninitialize IBIT Component.
2018-11-15T23:39:03.947Z,1542325143.947 [CBIT](DEBUG): Uninitialize CBIT Component.
2018-11-15T23:39:03.948Z,1542325143.948 [controlThread ThreadHandler](INFO): Thread cancelled.
2018-11-15T23:39:04.156Z,1542325144.156 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2018-11-15T23:39:04.162Z,1542325144.162 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-11-15T23:39:04.669Z,1542325144.669 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2018-11-15T23:39:04.686Z,1542325144.686 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2018-11-15T23:39:04.778Z,1542325144.778 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-11-15T23:39:04.898Z,1542325144.898 [logger ThreadHandler](INFO): Thread cancelled.