2018-11-06T05:59:49.120Z,1541483989.120 [Supervisor](DEBUG): Initializing supervisor.
2018-11-06T05:59:49.123Z,1541483989.123 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2018-11-06T05:59:49.124Z,1541483989.124 [SyncHandler](INFO): Protected caller Thread ID is 2842
2018-11-06T05:59:49.124Z,1541483989.124 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2018-11-06T05:59:49.125Z,1541483989.125 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2018-11-06T05:59:49.125Z,1541483989.125 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 2843
2018-11-06T05:59:49.128Z,1541483989.128 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2018-11-06T05:59:49.140Z,1541483989.140 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2018-11-06T05:59:49.141Z,1541483989.141 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2018-11-06T05:59:49.141Z,1541483989.141 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 2844
2018-11-06T05:59:49.142Z,1541483989.142 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2018-11-06T05:59:49.143Z,1541483989.143 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2018-11-06T05:59:49.143Z,1541483989.143 [logger ThreadHandler](INFO): Protected caller Thread ID is 2845
2018-11-06T05:59:49.145Z,1541483989.145 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2018-11-06T05:59:49.145Z,1541483989.145 [Supervisor](INFO): Looking for Config files in directory: Config/
2018-11-06T05:59:49.147Z,1541483989.147 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2018-11-06T05:59:49.367Z,1541483989.367 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2018-11-06T05:59:49.368Z,1541483989.368 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2018-11-06T05:59:49.468Z,1541483989.468 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2018-11-06T05:59:49.469Z,1541483989.469 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2018-11-06T05:59:49.667Z,1541483989.667 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2018-11-06T05:59:49.667Z,1541483989.667 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2018-11-06T05:59:50.002Z,1541483990.002 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2018-11-06T05:59:50.002Z,1541483990.002 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2018-11-06T05:59:50.345Z,1541483990.345 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2018-11-06T05:59:50.346Z,1541483990.346 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2018-11-06T05:59:50.803Z,1541483990.803 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2018-11-06T05:59:50.804Z,1541483990.804 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2018-11-06T05:59:51.267Z,1541483991.267 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2018-11-06T05:59:51.268Z,1541483991.268 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2018-11-06T05:59:51.718Z,1541483991.718 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2018-11-06T05:59:51.718Z,1541483991.718 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2018-11-06T05:59:51.799Z,1541483991.799 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2018-11-06T05:59:52.123Z,1541483992.123 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2018-11-06T05:59:52.123Z,1541483992.123 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2018-11-06T05:59:52.272Z,1541483992.272 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2018-11-06T05:59:52.272Z,1541483992.272 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2018-11-06T05:59:52.486Z,1541483992.486 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2018-11-06T05:59:52.487Z,1541483992.487 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2018-11-06T05:59:52.879Z,1541483992.879 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2018-11-06T05:59:52.880Z,1541483992.880 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2018-11-06T05:59:53.119Z,1541483993.119 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2018-11-06T05:59:53.120Z,1541483993.120 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2018-11-06T05:59:53.265Z,1541483993.265 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2018-11-06T05:59:53.267Z,1541483993.267 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/
2018-11-06T05:59:53.268Z,1541483993.268 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg
2018-11-06T05:59:53.496Z,1541483993.496 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2018-11-06T05:59:53.496Z,1541483993.496 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg
2018-11-06T05:59:53.604Z,1541483993.604 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg
2018-11-06T05:59:53.759Z,1541483993.759 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg
2018-11-06T05:59:53.854Z,1541483993.854 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg
2018-11-06T05:59:53.940Z,1541483993.940 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg
2018-11-06T05:59:54.102Z,1541483994.102 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg
2018-11-06T05:59:54.357Z,1541483994.357 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg
2018-11-06T05:59:54.628Z,1541483994.628 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg
2018-11-06T05:59:54.826Z,1541483994.826 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg
2018-11-06T05:59:55.008Z,1541483995.008 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg
2018-11-06T05:59:55.324Z,1541483995.324 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/root/
2018-11-06T05:59:55.324Z,1541483995.324 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2018-11-06T05:59:55.328Z,1541483995.328 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2018-11-06T05:59:55.429Z,1541483995.429 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2018-11-06T05:59:55.430Z,1541483995.430 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2018-11-06T05:59:55.443Z,1541483995.443 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2018-11-06T05:59:55.443Z,1541483995.443 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2018-11-06T05:59:55.485Z,1541483995.485 [DepthRateCalculator] Loaded
2018-11-06T05:59:55.486Z,1541483995.486 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2018-11-06T05:59:55.492Z,1541483995.492 [PitchRateCalculator] Loaded
2018-11-06T05:59:55.492Z,1541483995.492 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2018-11-06T05:59:55.508Z,1541483995.508 [SpeedCalculator] Loaded
2018-11-06T05:59:55.508Z,1541483995.508 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2018-11-06T05:59:55.529Z,1541483995.529 [TempGradientCalculator] Loaded
2018-11-06T05:59:55.529Z,1541483995.529 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2018-11-06T05:59:55.535Z,1541483995.535 [YawRateCalculator] Loaded
2018-11-06T05:59:55.535Z,1541483995.535 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2018-11-06T05:59:55.576Z,1541483995.576 [ElevatorOffsetCalculator] Loaded
2018-11-06T05:59:55.576Z,1541483995.576 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2018-11-06T05:59:55.576Z,1541483995.576 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2018-11-06T05:59:55.577Z,1541483995.577 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2018-11-06T05:59:55.602Z,1541483995.602 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2018-11-06T05:59:55.603Z,1541483995.603 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2018-11-06T05:59:55.880Z,1541483995.880 [AcousticModem_Benthos_ATM900] Loaded
2018-11-06T05:59:55.880Z,1541483995.880 [ComponentRegistry](DEBUG): SyncComponent "AcousticModem_Benthos_ATM900" handled in the control thread.
2018-11-06T05:59:55.960Z,1541483995.960 [DataOverHttps] Loaded
2018-11-06T05:59:55.961Z,1541483995.961 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2018-11-06T05:59:55.974Z,1541483995.974 [Depth_Keller] Loaded
2018-11-06T05:59:55.975Z,1541483995.975 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2018-11-06T05:59:55.979Z,1541483995.979 [DropWeight] Loaded
2018-11-06T05:59:55.980Z,1541483995.980 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2018-11-06T05:59:56.077Z,1541483996.077 [NAL9602] Loaded
2018-11-06T05:59:56.078Z,1541483996.078 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2018-11-06T05:59:56.093Z,1541483996.093 [Onboard] Loaded
2018-11-06T05:59:56.094Z,1541483996.094 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2018-11-06T05:59:56.104Z,1541483996.104 [Radio_Surface] Loaded
2018-11-06T05:59:56.104Z,1541483996.104 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2018-11-06T05:59:56.105Z,1541483996.105 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 407C24E0
2018-11-06T05:59:56.106Z,1541483996.106 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 2924
2018-11-06T05:59:56.153Z,1541483996.153 [PNI_TCM] Loaded
2018-11-06T05:59:56.154Z,1541483996.154 [ComponentRegistry](DEBUG): SyncComponent "PNI_TCM" handled in the control thread.
2018-11-06T05:59:56.215Z,1541483996.215 [Rowe_600LCM] Loaded
2018-11-06T05:59:56.215Z,1541483996.215 [ComponentRegistry](DEBUG): Component "Rowe_600LCM" handled in its own thread.
2018-11-06T05:59:56.216Z,1541483996.216 [Rowe_600LCM ThreadHandler](DEBUG): Created PCaller Thread at 407F24E0
2018-11-06T05:59:56.217Z,1541483996.217 [Rowe_600LCM ThreadHandler](INFO): Protected caller Thread ID is 2925
2018-11-06T05:59:57.983Z,1541483997.983 [BPC1] Loaded
2018-11-06T05:59:57.984Z,1541483997.984 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2018-11-06T05:59:57.984Z,1541483997.984 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2018-11-06T05:59:57.985Z,1541483997.985 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2018-11-06T05:59:58.119Z,1541483998.119 [SBIT](DEBUG): Construct Startup Built In Test.
2018-11-06T05:59:58.142Z,1541483998.142 [SBIT] Loaded
2018-11-06T05:59:58.142Z,1541483998.142 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2018-11-06T05:59:58.143Z,1541483998.143 [IBIT](DEBUG): Construct Initiated Built In Test.
2018-11-06T05:59:58.155Z,1541483998.155 [IBIT] Loaded
2018-11-06T05:59:58.155Z,1541483998.155 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2018-11-06T05:59:58.158Z,1541483998.158 [CBIT](DEBUG): Construct Continuous Built In Test.
2018-11-06T05:59:58.306Z,1541483998.306 [CBIT] Loaded
2018-11-06T05:59:58.307Z,1541483998.307 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2018-11-06T05:59:58.307Z,1541483998.307 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2018-11-06T05:59:58.308Z,1541483998.308 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2018-11-06T05:59:58.469Z,1541483998.469 [Aanderaa_O2] Loaded
2018-11-06T05:59:58.469Z,1541483998.469 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2018-11-06T05:59:58.526Z,1541483998.526 [CTD_Seabird] Loaded
2018-11-06T05:59:58.526Z,1541483998.526 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2018-11-06T05:59:58.527Z,1541483998.527 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 408BE4E0
2018-11-06T05:59:58.528Z,1541483998.528 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 2926
2018-11-06T05:59:58.545Z,1541483998.545 [ESPComponent] Loaded
2018-11-06T05:59:58.545Z,1541483998.545 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2018-11-06T05:59:58.559Z,1541483998.559 [PAR_Licor] Loaded
2018-11-06T05:59:58.560Z,1541483998.560 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2018-11-06T05:59:58.608Z,1541483998.608 [WetLabsBB2FL] Loaded
2018-11-06T05:59:58.609Z,1541483998.609 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2018-11-06T05:59:58.610Z,1541483998.610 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 408EE4E0
2018-11-06T05:59:58.610Z,1541483998.610 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 2927
2018-11-06T05:59:58.611Z,1541483998.611 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2018-11-06T05:59:58.611Z,1541483998.611 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2018-11-06T05:59:58.853Z,1541483998.853 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2018-11-06T05:59:58.853Z,1541483998.853 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2018-11-06T05:59:58.921Z,1541483998.921 [VerticalControl](DEBUG): Construct VerticalControl.
2018-11-06T05:59:59.017Z,1541483999.017 [VerticalControl] Loaded
2018-11-06T05:59:59.017Z,1541483999.017 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2018-11-06T05:59:59.018Z,1541483999.018 [HorizontalControl](DEBUG): Construct HorizontalControl.
2018-11-06T05:59:59.079Z,1541483999.079 [HorizontalControl] Loaded
2018-11-06T05:59:59.079Z,1541483999.079 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2018-11-06T05:59:59.080Z,1541483999.080 [SpeedControl](DEBUG): Construct SpeedControl.
2018-11-06T05:59:59.085Z,1541483999.085 [SpeedControl] Loaded
2018-11-06T05:59:59.085Z,1541483999.085 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2018-11-06T05:59:59.086Z,1541483999.086 [LoopControl](DEBUG): Construct LoopControl.
2018-11-06T05:59:59.086Z,1541483999.086 [LoopControl] Loaded
2018-11-06T05:59:59.087Z,1541483999.087 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2018-11-06T05:59:59.087Z,1541483999.087 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2018-11-06T05:59:59.088Z,1541483999.088 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2018-11-06T05:59:59.153Z,1541483999.153 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2018-11-06T05:59:59.154Z,1541483999.154 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2018-11-06T05:59:59.252Z,1541483999.252 [BuoyancyServo] Loaded
2018-11-06T05:59:59.252Z,1541483999.252 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2018-11-06T05:59:59.264Z,1541483999.264 [ElevatorServo] Loaded
2018-11-06T05:59:59.264Z,1541483999.264 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2018-11-06T05:59:59.276Z,1541483999.276 [MassServo] Loaded
2018-11-06T05:59:59.276Z,1541483999.276 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2018-11-06T05:59:59.288Z,1541483999.288 [RudderServo] Loaded
2018-11-06T05:59:59.288Z,1541483999.288 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2018-11-06T05:59:59.299Z,1541483999.299 [ThrusterServo] Loaded
2018-11-06T05:59:59.299Z,1541483999.299 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2018-11-06T05:59:59.299Z,1541483999.299 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2018-11-06T05:59:59.300Z,1541483999.300 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2018-11-06T05:59:59.391Z,1541483999.391 [DeadReckonUsingSpeedCalculator] Loaded
2018-11-06T05:59:59.391Z,1541483999.391 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2018-11-06T05:59:59.407Z,1541483999.407 [NavChart] Loaded
2018-11-06T05:59:59.407Z,1541483999.407 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2018-11-06T05:59:59.411Z,1541483999.411 [UniversalFixResidualReporter] Loaded
2018-11-06T05:59:59.412Z,1541483999.412 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2018-11-06T05:59:59.412Z,1541483999.412 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2018-11-06T05:59:59.427Z,1541483999.427 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2018-11-06T05:59:59.428Z,1541483999.428 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2018-11-06T05:59:59.476Z,1541483999.476 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2018-11-06T05:59:59.477Z,1541483999.477 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40A474E0
2018-11-06T05:59:59.477Z,1541483999.477 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 2928
2018-11-06T05:59:59.547Z,1541483999.547 [Supervisor](INFO): Main Thread ID is 2717
2018-11-06T05:59:59.547Z,1541483999.547 [Supervisor](DEBUG): Running supervisor.
2018-11-06T05:59:59.547Z,1541483999.547 [CommandLine ThreadHandler](INFO): Handler Thread ID is 2929
2018-11-06T05:59:59.550Z,1541483999.550 [controlThread ThreadHandler](INFO): Handler Thread ID is 2930
2018-11-06T05:59:59.551Z,1541483999.551 [controlThread](DEBUG): Initializing ControlThread
2018-11-06T05:59:59.551Z,1541483999.551 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2018-11-06T05:59:59.552Z,1541483999.552 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2018-11-06T05:59:59.552Z,1541483999.552 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2018-11-06T05:59:59.552Z,1541483999.552 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2018-11-06T05:59:59.553Z,1541483999.553 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2018-11-06T05:59:59.553Z,1541483999.553 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2018-11-06T05:59:59.560Z,1541483999.560 [SBIT](INFO): Initialize SBIT Component.
2018-11-06T05:59:59.560Z,1541483999.560 [SBIT](IMPORTANT): git: 2018-11-05
2018-11-06T05:59:59.560Z,1541483999.560 [SBIT](INFO): git hash: 17f8e4440ddc7f0910aa911cb821ed1a114d9cee
2018-11-06T05:59:59.561Z,1541483999.561 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2018-11-06T05:59:59.561Z,1541483999.561 [SBIT](IMPORTANT): Kernel Version:#2 PREEMPT Thu Jan 11 20:13:48 PST 2018
2018-11-06T05:59:59.562Z,1541483999.562 [SBIT](INFO): Beginning SBIT in 24.000000 seconds.
2018-11-06T05:59:59.563Z,1541483999.563 [IBIT](INFO): Initialize IBIT Component.
2018-11-06T05:59:59.564Z,1541483999.564 [CBIT](DEBUG): Initialize CBIT Component.
2018-11-06T05:59:59.564Z,1541483999.564 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2018-11-06T05:59:59.565Z,1541483999.565 [logger ThreadHandler](INFO): Handler Thread ID is 2931
2018-11-06T05:59:59.586Z,1541483999.586 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 2932
2018-11-06T05:59:59.592Z,1541483999.592 [Radio_Surface](INFO): Powering up
2018-11-06T05:59:59.598Z,1541483999.598 [Rowe_600LCM ThreadHandler](INFO): Handler Thread ID is 2933
2018-11-06T05:59:59.598Z,1541483999.598 [Rowe_600LCM](INFO): Initializing
2018-11-06T05:59:59.599Z,1541483999.599 [Rowe_600LCM](INFO): Checking LCM
2018-11-06T05:59:59.608Z,1541483999.608 [Rowe_600LCM](INFO): LCM OK
2018-11-06T05:59:59.608Z,1541483999.608 [Rowe_600LCM](INFO): Powering up
2018-11-06T05:59:59.614Z,1541483999.614 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 2934
2018-11-06T05:59:59.614Z,1541483999.614 [CTD_Seabird](INFO): Initializing
2018-11-06T05:59:59.615Z,1541483999.615 [CTD_Seabird](INFO): Checking LCM
2018-11-06T05:59:59.615Z,1541483999.615 [CTD_Seabird](INFO): LCM OK
2018-11-06T05:59:59.615Z,1541483999.615 [CTD_Seabird](INFO): Powering up
2018-11-06T05:59:59.626Z,1541483999.626 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 2935
2018-11-06T05:59:59.627Z,1541483999.627 [WetLabsBB2FL](INFO): Powering down
2018-11-06T05:59:59.654Z,1541483999.654 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 2936
2018-11-06T05:59:59.657Z,1541483999.657 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2018-11-06T05:59:59.657Z,1541483999.657 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2018-11-06T05:59:59.657Z,1541483999.657 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2018-11-06T05:59:59.657Z,1541483999.657 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2018-11-06T05:59:59.658Z,1541483999.658 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2018-11-06T05:59:59.658Z,1541483999.658 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2018-11-06T05:59:59.658Z,1541483999.658 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2018-11-06T05:59:59.658Z,1541483999.658 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2018-11-06T05:59:59.658Z,1541483999.658 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2018-11-06T05:59:59.659Z,1541483999.659 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2018-11-06T05:59:59.659Z,1541483999.659 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2018-11-06T05:59:59.659Z,1541483999.659 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2018-11-06T05:59:59.659Z,1541483999.659 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2018-11-06T05:59:59.659Z,1541483999.659 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2018-11-06T05:59:59.659Z,1541483999.659 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2018-11-06T05:59:59.660Z,1541483999.660 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2018-11-06T05:59:59.673Z,1541483999.673 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2018-11-06T05:59:59.675Z,1541483999.675 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2018-11-06T05:59:59.676Z,1541483999.676 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2018-11-06T05:59:59.676Z,1541483999.676 [LoopControl](DEBUG): Initialize LoopControlComponent.
2018-11-06T05:59:59.678Z,1541483999.678 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-11-06T05:59:59.679Z,1541483999.679 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-11-06T05:59:59.679Z,1541483999.679 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-11-06T05:59:59.680Z,1541483999.680 [NavChart](DEBUG): Initialize NavChart Navigation.
2018-11-06T05:59:59.680Z,1541483999.680 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2018-11-06T05:59:59.685Z,1541483999.685 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2018-11-06T05:59:59.713Z,1541483999.713 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2018-11-06T05:59:59.737Z,1541483999.737 [MissionManager](DEBUG):
2018-11-06T05:59:59.738Z,1541483999.738 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2018-11-06T05:59:59.824Z,1541483999.824 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2018-11-06T05:59:59.842Z,1541483999.842 [Default:A.Wait](DEBUG): Construct Wait.
2018-11-06T05:59:59.843Z,1541483999.843 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2018-11-06T05:59:59.878Z,1541483999.878 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2018-11-06T05:59:59.881Z,1541483999.881 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2018-11-06T05:59:59.916Z,1541483999.916 [Default:E.Execute](DEBUG): Construct Execute.
2018-11-06T05:59:59.920Z,1541483999.920 [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-06T05:59:59.937Z,1541483999.937 [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-06T05:59:59.961Z,1541483999.961 [AcousticModem_Benthos_ATM900](INFO): Powering up
2018-11-06T05:59:59.961Z,1541483999.961 [AcousticModem_Benthos_ATM900](DEBUG): Initializing AcousticModem_Benthos_ATM900.
2018-11-06T05:59:59.987Z,1541483999.987 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2018-11-06T05:59:59.996Z,1541483999.996 [Depth_Keller](ERROR): Pressure reading out of range: 1895.684326 decibar
2018-11-06T06:00:00.187Z,1541484000.187 [ESPComponent](INFO): powering down ESP
2018-11-06T06:00:00.500Z,1541484000.500 [DepthRateCalculator](ERROR): Depth measurement is not active
2018-11-06T06:00:00.703Z,1541484000.703 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2018-11-06T06:00:00.709Z,1541484000.709 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2018-11-06T06:00:00.716Z,1541484000.716 [ElevatorServo](DEBUG): Initializing EZServoServo.
2018-11-06T06:00:00.721Z,1541484000.721 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2018-11-06T06:00:00.727Z,1541484000.727 [MassServo](DEBUG): Initializing EZServoServo.
2018-11-06T06:00:00.733Z,1541484000.733 [MassServo](DEBUG): Initializing MassServo.
2018-11-06T06:00:00.739Z,1541484000.739 [RudderServo](DEBUG): Initializing EZServoServo.
2018-11-06T06:00:00.745Z,1541484000.745 [RudderServo](DEBUG): Initializing RudderServo.
2018-11-06T06:00:00.751Z,1541484000.751 [ThrusterServo](DEBUG): Initializing EZServoServo.
2018-11-06T06:00:00.757Z,1541484000.757 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2018-11-06T06:00:01.015Z,1541484001.015 [DropWeight](CRITICAL): DROP WEIGHT MISSING.
2018-11-06T06:00:01.015Z,1541484001.015 [DropWeight] Hardware Fault, FailCount= 1
2018-11-06T06:00:01.015Z,1541484001.015 [DropWeight](ERROR): Hardware Fault
2018-11-06T06:00:01.133Z,1541484001.133 [CommandLine](FAULT): Scheduling is paused
2018-11-06T06:00:01.133Z,1541484001.133 [CBIT](INFO): Critical error at 20181106T060001
2018-11-06T06:00:01.133Z,1541484001.133 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2018-11-06T06:00:01.136Z,1541484001.136 [CBIT](ERROR): Hardware Fault in component: DropWeight
2018-11-06T06:00:01.137Z,1541484001.137 [CBIT](CRITICAL): Hardware Fault in component: DropWeight
2018-11-06T06:00:01.609Z,1541484001.609 [BuoyancyServo](ERROR): Buoyancy initialization uart error serial timeout
2018-11-06T06:00:01.610Z,1541484001.610 [BuoyancyServo](FAULT): Buoyancy failed to initialize
2018-11-06T06:00:01.610Z,1541484001.610 [BuoyancyServo] Communications Fault, FailCount= 1
2018-11-06T06:00:01.610Z,1541484001.610 [BuoyancyServo](ERROR): Communications Fault
2018-11-06T06:00:01.819Z,1541484001.819 [CBIT](INFO): Critical error at 20181106T060001
2018-11-06T06:00:01.821Z,1541484001.821 [CBIT](ERROR): Communications Fault in component: BuoyancyServo
2018-11-06T06:00:03.887Z,1541484003.887 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-11-06T06:00:04.014Z,1541484004.014 [CBIT](INFO): Clearing failed state for component BuoyancyServo
2018-11-06T06:00:04.015Z,1541484004.015 [BuoyancyServo] No Fault, FailCount= 1
2018-11-06T06:00:04.040Z,1541484004.040 [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-06T06:00:04.079Z,1541484004.079 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-11-06T06:00:04.080Z,1541484004.080 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-11-06T06:00:04.080Z,1541484004.080 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-11-06T06:00:04.314Z,1541484004.314 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2018-11-06T06:00:04.315Z,1541484004.315 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2018-11-06T06:00:05.106Z,1541484005.106 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface
2018-11-06T06:00:05.272Z,1541484005.272 [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-06T06:00:05.274Z,1541484005.274 [CTD_Seabird](INFO): LCM subscribed to channel:seabird_gpctd_t.seabird-gpctd
2018-11-06T06:00:05.664Z,1541484005.664 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface
2018-11-06T06:00:05.664Z,1541484005.664 [CTD_Seabird](INFO): Powering down
2018-11-06T06:00:07.430Z,1541484007.430 [AcousticModem_Benthos_ATM900](DEBUG):
2018-11-06T06:00:07.449Z,1541484007.449 [PNI_TCM](FAULT): Failed to set parameters during initialization.
2018-11-06T06:00:07.449Z,1541484007.449 [PNI_TCM] Data Fault, FailCount= 1
2018-11-06T06:00:07.449Z,1541484007.449 [PNI_TCM](ERROR): Data Fault
2018-11-06T06:00:07.566Z,1541484007.566 [CBIT](ERROR): Data Fault in component: PNI_TCM
2018-11-06T06:00:07.849Z,1541484007.849 [PNI_TCM](INFO): Powering down
2018-11-06T06:00:08.634Z,1541484008.634 [AcousticModem_Benthos_ATM900](DEBUG): Teledyne Benthos ATM-900 Series OEM w/burn wire
2018-11-06T06:00:08.635Z,1541484008.635 [AcousticModem_Benthos_ATM900](DEBUG): MF Frequency Band
2018-11-06T06:00:08.636Z,1541484008.636 [AcousticModem_Benthos_ATM900](DEBUG): Standard version 8.6.3
2018-11-06T06:00:08.637Z,1541484008.637 [AcousticModem_Benthos_ATM900](DEBUG): Oct 25 2018 06:42:47
2018-11-06T06:00:09.150Z,1541484009.150 [CBIT](INFO): Clearing failed state for component PNI_TCM
2018-11-06T06:00:09.150Z,1541484009.150 [PNI_TCM] No Fault, FailCount= 1
2018-11-06T06:00:09.431Z,1541484009.431 [AcousticModem_Benthos_ATM900](DEBUG): WARNING: battery low
2018-11-06T06:00:09.998Z,1541484009.998 [CBIT](CRITICAL): Environmental Failure. Press:14.754064 PSI. Humidity:34%. Temp:26 C. ABORTING MISSION
2018-11-06T06:00:10.230Z,1541484010.230 [AcousticModem_Benthos_ATM900](INFO): entering command mode
2018-11-06T06:00:10.282Z,1541484010.282 [Aanderaa_O2](FAULT): Failed to initialize within timeout.
2018-11-06T06:00:10.282Z,1541484010.282 [Aanderaa_O2] Communications Fault, FailCount= 1
2018-11-06T06:00:10.283Z,1541484010.283 [Aanderaa_O2](ERROR): Communications Fault
2018-11-06T06:00:10.348Z,1541484010.348 [CBIT](INFO): Critical error at 20181106T060009
2018-11-06T06:00:10.351Z,1541484010.351 [CBIT](ERROR): Communications Fault in component: Aanderaa_O2
2018-11-06T06:00:10.630Z,1541484010.630 [AcousticModem_Benthos_ATM900](DEBUG): checking for command mode acknowledgment
2018-11-06T06:00:10.631Z,1541484010.631 [AcousticModem_Benthos_ATM900](DEBUG): read user prompt 1: user:1>
2018-11-06T06:00:10.631Z,1541484010.631 [AcousticModem_Benthos_ATM900](INFO): command mode acknowledged
2018-11-06T06:00:10.651Z,1541484010.651 [Aanderaa_O2](INFO): Powering down
2018-11-06T06:00:11.031Z,1541484011.031 [AcousticModem_Benthos_ATM900](INFO): setting local address to 3
2018-11-06T06:00:11.430Z,1541484011.430 [AcousticModem_Benthos_ATM900](DEBUG): checking for local address setting acknowledgment
2018-11-06T06:00:11.431Z,1541484011.431 [AcousticModem_Benthos_ATM900](INFO): set local address to 3
2018-11-06T06:00:11.570Z,1541484011.570 [CBIT](INFO): Clearing failed state for component Aanderaa_O2
2018-11-06T06:00:11.570Z,1541484011.570 [Aanderaa_O2] No Fault, FailCount= 1
2018-11-06T06:00:11.831Z,1541484011.831 [AcousticModem_Benthos_ATM900](DEBUG): read user prompt 2: user:2>
2018-11-06T06:00:16.649Z,1541484016.649 [PNI_TCM](FAULT): Failed to set parameters during initialization.
2018-11-06T06:00:16.649Z,1541484016.649 [PNI_TCM] Data Fault, FailCount= 2
2018-11-06T06:00:16.649Z,1541484016.649 [PNI_TCM](ERROR): Data Fault
2018-11-06T06:00:16.770Z,1541484016.770 [CBIT](ERROR): Data Fault in component: PNI_TCM
2018-11-06T06:00:17.050Z,1541484017.050 [PNI_TCM](INFO): Powering down
2018-11-06T06:00:18.366Z,1541484018.366 [CBIT](INFO): Clearing failed state for component PNI_TCM
2018-11-06T06:00:18.366Z,1541484018.366 [PNI_TCM] No Fault, FailCount= 2
2018-11-06T06:00:21.851Z,1541484021.851 [Aanderaa_O2](FAULT): Failed to initialize within timeout.
2018-11-06T06:00:21.851Z,1541484021.851 [Aanderaa_O2] Communications Fault, FailCount= 2
2018-11-06T06:00:21.851Z,1541484021.851 [Aanderaa_O2](ERROR): Communications Fault
2018-11-06T06:00:21.962Z,1541484021.962 [CBIT](ERROR): Communications Fault in component: Aanderaa_O2
2018-11-06T06:00:22.252Z,1541484022.252 [Aanderaa_O2](INFO): Powering down
2018-11-06T06:00:23.146Z,1541484023.146 [CBIT](INFO): Clearing failed state for component Aanderaa_O2
2018-11-06T06:00:23.146Z,1541484023.146 [Aanderaa_O2] No Fault, FailCount= 2
2018-11-06T06:00:24.367Z,1541484024.367 [SBIT](IMPORTANT): Beginning Startup BIT
2018-11-06T06:00:24.371Z,1541484024.371 [CBIT](IMPORTANT): Beginning ground fault scan
2018-11-06T06:00:25.849Z,1541484025.849 [PNI_TCM](FAULT): Failed to set parameters during initialization.
2018-11-06T06:00:25.849Z,1541484025.849 [PNI_TCM] Data Fault, FailCount= 3
2018-11-06T06:00:25.849Z,1541484025.849 [PNI_TCM](ERROR): Data Fault
2018-11-06T06:00:26.030Z,1541484026.030 [CBIT](ERROR): Data Fault in component: PNI_TCM
2018-11-06T06:00:26.235Z,1541484026.235 [NAL9602](INFO): Powering up NAL9602
2018-11-06T06:00:26.250Z,1541484026.250 [PNI_TCM](INFO): Powering down
2018-11-06T06:00:27.635Z,1541484027.635 [CBIT](INFO): Clearing failed state for component PNI_TCM
2018-11-06T06:00:27.635Z,1541484027.635 [PNI_TCM] No Fault, FailCount= 3
2018-11-06T06:00:33.463Z,1541484033.463 [Aanderaa_O2](FAULT): Failed to initialize within timeout.
2018-11-06T06:00:33.463Z,1541484033.463 [Aanderaa_O2] Communications Fault, FailCount= 3
2018-11-06T06:00:33.463Z,1541484033.463 [Aanderaa_O2](ERROR): Communications Fault
2018-11-06T06:00:33.583Z,1541484033.583 [CBIT](ERROR): Communications Fault in component: Aanderaa_O2
2018-11-06T06:00:33.583Z,1541484033.583 [CBIT](FAULT): Communications Fault in component: Aanderaa_O2
2018-11-06T06:00:33.969Z,1541484033.969 [Aanderaa_O2](INFO): Powering down
2018-11-06T06:00:35.057Z,1541484035.057 [PNI_TCM](FAULT): Failed to set parameters during initialization.
2018-11-06T06:00:35.057Z,1541484035.057 [PNI_TCM] Data Fault, FailCount= 4
2018-11-06T06:00:35.057Z,1541484035.057 [PNI_TCM](ERROR): Data Fault
2018-11-06T06:00:35.199Z,1541484035.199 [CBIT](ERROR): Data Fault in component: PNI_TCM
2018-11-06T06:00:35.203Z,1541484035.203 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.008758
CHAN A1 (24V): -0.015581
CHAN A2 (12V): -0.005478
CHAN A3 (5V): -0.002567
CHAN B0 (3.3V): -0.001114
CHAN B1 (3.15aV): -0.000660
CHAN B2 (3.15bV): -0.002129
CHAN B3 (GND): 0.000230
OPEN: 0.004234
Full Scale Calc: 4.765 mA, -1.589 mA
2018-11-06T06:00:35.456Z,1541484035.456 [PNI_TCM](INFO): Powering down
2018-11-06T06:00:36.754Z,1541484036.754 [CBIT](INFO): Clearing failed state for component PNI_TCM
2018-11-06T06:00:36.754Z,1541484036.754 [PNI_TCM] No Fault, FailCount= 4
2018-11-06T06:00:44.440Z,1541484044.440 [PNI_TCM](FAULT): Failed to set parameters during initialization.
2018-11-06T06:00:44.440Z,1541484044.440 [PNI_TCM] Data Fault, FailCount= 5
2018-11-06T06:00:44.440Z,1541484044.440 [PNI_TCM](ERROR): Data Fault
2018-11-06T06:00:44.670Z,1541484044.670 [CBIT](ERROR): Data Fault in component: PNI_TCM
2018-11-06T06:00:44.670Z,1541484044.670 [CBIT](CRITICAL): Data Fault in component: PNI_TCM
2018-11-06T06:00:44.841Z,1541484044.841 [PNI_TCM](INFO): Powering down
2018-11-06T06:00:45.236Z,1541484045.236 [CBIT](INFO): Critical error at 20181106T060044
2018-11-06T06:00:47.254Z,1541484047.254 [NAL9602](ERROR): NAL9602 initialization error.
2018-11-06T06:00:47.254Z,1541484047.254 [NAL9602] Communications Fault, FailCount= 1
2018-11-06T06:00:47.254Z,1541484047.254 [NAL9602](ERROR): Communications Fault
2018-11-06T06:00:47.411Z,1541484047.411 [CBIT](ERROR): Communications Fault in component: NAL9602
2018-11-06T06:00:47.654Z,1541484047.654 [NAL9602](INFO): Powering down
2018-11-06T06:00:48.590Z,1541484048.590 [CBIT](INFO): Clearing failed state for component NAL9602
2018-11-06T06:00:48.591Z,1541484048.591 [NAL9602] No Fault, FailCount= 1
2018-11-06T06:01:17.834Z,1541484077.834 [NAL9602](INFO): Powering up NAL9602
2018-11-06T06:01:18.259Z,1541484078.259 [SBIT](IMPORTANT): SBIT PASSED
2018-11-06T06:01:18.313Z,1541484078.313 [CommandLine](IMPORTANT): got command configSet list
2018-11-06T06:01:18.314Z,1541484078.314 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2018-11-06T06:01:18.315Z,1541484078.315 [CommandLine](IMPORTANT): PAR_Licor.loadAtStartup=1 bool;
2018-11-06T06:01:18.708Z,1541484078.708 [MissionManager](IMPORTANT): Started mission Startup
2018-11-06T06:01:18.708Z,1541484078.708 [Startup] Running Loop=1
2018-11-06T06:01:18.708Z,1541484078.708 [Startup](DEBUG): Aggregate::initialize Startup
2018-11-06T06:01:18.709Z,1541484078.709 [Startup:A.GoToSurface] Running Loop=1
2018-11-06T06:01:18.709Z,1541484078.709 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-11-06T06:01:18.709Z,1541484078.709 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2018-11-06T06:01:18.710Z,1541484078.710 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2018-11-06T06:01:18.710Z,1541484078.710 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2018-11-06T06:01:18.711Z,1541484078.711 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-11-06T06:01:18.711Z,1541484078.711 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2018-11-06T06:01:18.717Z,1541484078.717 [Startup:StartupSatComms] Running Loop=1
2018-11-06T06:01:18.717Z,1541484078.717 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2018-11-06T06:01:18.717Z,1541484078.717 [Startup:StartupSatComms:A] Running Loop=1
2018-11-06T06:01:19.060Z,1541484079.060 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2018-11-06T06:01:39.027Z,1541484099.027 [NAL9602](ERROR): NAL9602 initialization error.
2018-11-06T06:01:39.027Z,1541484099.027 [NAL9602] Communications Fault, FailCount= 2
2018-11-06T06:01:39.027Z,1541484099.027 [NAL9602](ERROR): Communications Fault
2018-11-06T06:01:39.097Z,1541484099.097 [CBIT](ERROR): Communications Fault in component: NAL9602
2018-11-06T06:01:39.427Z,1541484099.427 [NAL9602](INFO): Powering down
2018-11-06T06:01:40.283Z,1541484100.283 [CBIT](INFO): Clearing failed state for component NAL9602
2018-11-06T06:01:40.283Z,1541484100.283 [NAL9602] No Fault, FailCount= 2
2018-11-06T06:01:59.813Z,1541484119.813 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-11-06T06:01:59.813Z,1541484119.813 [Rowe_600LCM] Communications Fault, FailCount= 1
2018-11-06T06:01:59.813Z,1541484119.813 [Rowe_600LCM](ERROR): Communications Fault
2018-11-06T06:01:59.879Z,1541484119.879 [DeadReckonUsingSpeedCalculator](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2018-11-06T06:01:59.879Z,1541484119.879 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 1
2018-11-06T06:01:59.879Z,1541484119.879 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-11-06T06:01:59.905Z,1541484119.905 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-11-06T06:01:59.914Z,1541484119.914 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-11-06T06:02:00.225Z,1541484120.225 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-11-06T06:02:00.349Z,1541484120.349 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-11-06T06:02:00.349Z,1541484120.349 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 1
2018-11-06T06:02:00.399Z,1541484120.399 [Rowe_600LCM](INFO): Powering down
2018-11-06T06:02:00.659Z,1541484120.659 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-11-06T06:02:00.659Z,1541484120.659 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-11-06T06:02:00.660Z,1541484120.660 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-11-06T06:02:01.872Z,1541484121.872 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-11-06T06:02:01.872Z,1541484121.872 [Rowe_600LCM] No Fault, FailCount= 1
2018-11-06T06:02:02.013Z,1541484122.013 [Rowe_600LCM](INFO): Initializing
2018-11-06T06:02:02.014Z,1541484122.014 [Rowe_600LCM](INFO): Checking LCM
2018-11-06T06:02:02.014Z,1541484122.014 [Rowe_600LCM](INFO): LCM OK
2018-11-06T06:02:02.014Z,1541484122.014 [Rowe_600LCM](INFO): Powering up
2018-11-06T06:02:06.130Z,1541484126.130 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-11-06T06:02:06.200Z,1541484126.200 [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-06T06:02:06.202Z,1541484126.202 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-11-06T06:02:06.203Z,1541484126.203 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-11-06T06:02:06.203Z,1541484126.203 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-11-06T06:02:09.834Z,1541484129.834 [NAL9602](INFO): Powering up NAL9602
2018-11-06T06:02:19.068Z,1541484139.068 [Startup:StartupSatComms:A](INFO): Timed out from 2018-11-06T06:01:18.7Z
2018-11-06T06:02:19.068Z,1541484139.068 [Startup:StartupSatComms:A] Stopped
2018-11-06T06:02:19.068Z,1541484139.068 [Startup:StartupSatComms:B] Running Loop=1
2018-11-06T06:02:19.494Z,1541484139.494 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2018-11-06T06:02:30.843Z,1541484150.843 [NAL9602](ERROR): NAL9602 initialization error.
2018-11-06T06:02:30.843Z,1541484150.843 [NAL9602] Communications Fault, FailCount= 3
2018-11-06T06:02:30.843Z,1541484150.843 [NAL9602](ERROR): Communications Fault
2018-11-06T06:02:30.942Z,1541484150.942 [CBIT](ERROR): Communications Fault in component: NAL9602
2018-11-06T06:02:31.242Z,1541484151.242 [NAL9602](INFO): Powering down
2018-11-06T06:02:32.131Z,1541484152.131 [CBIT](INFO): Clearing failed state for component NAL9602
2018-11-06T06:02:32.131Z,1541484152.131 [NAL9602] No Fault, FailCount= 3
2018-11-06T06:03:01.019Z,1541484181.019 [CommandLine](IMPORTANT): got command failComponent
2018-11-06T06:03:01.019Z,1541484181.019 [CommandLine](IMPORTANT): Failed components:
2018-11-06T06:03:01.019Z,1541484181.019 [CommandLine](IMPORTANT): DropWeight: Hardware Fault
2018-11-06T06:03:01.019Z,1541484181.019 [CommandLine](IMPORTANT): PNI_TCM: Data Fault
2018-11-06T06:03:01.020Z,1541484181.020 [CommandLine](IMPORTANT): Aanderaa_O2: Communications Fault
2018-11-06T06:03:01.250Z,1541484181.250 [NAL9602](INFO): Powering up NAL9602
2018-11-06T06:03:06.407Z,1541484186.407 [CBIT](INFO): Clearing failed state for component Aanderaa_O2
2018-11-06T06:03:06.407Z,1541484186.407 [Aanderaa_O2] No Fault, FailCount= 3
2018-11-06T06:03:07.221Z,1541484187.221 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.005539
2018-11-06T06:03:12.394Z,1541484192.394 [CommandLine](IMPORTANT): got command restart application
2018-11-06T06:03:13.400Z,1541484193.400 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2018-11-06T06:03:13.400Z,1541484193.400 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-11-06T06:03:13.581Z,1541484193.581 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye!
2018-11-06T06:03:13.581Z,1541484193.581 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-11-06T06:03:13.582Z,1541484193.582 [CommandLine](INFO): Join timeout helper Thread ID is 2974
2018-11-06T06:03:13.601Z,1541484193.601 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2018-11-06T06:03:13.601Z,1541484193.601 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-11-06T06:03:13.602Z,1541484193.602 [NavChartDb](INFO): Join timeout helper Thread ID is 2975
2018-11-06T06:03:13.893Z,1541484193.893 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2018-11-06T06:03:13.893Z,1541484193.893 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-11-06T06:03:13.897Z,1541484193.897 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2018-11-06T06:03:13.897Z,1541484193.897 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2018-11-06T06:03:13.898Z,1541484193.898 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 2976
2018-11-06T06:03:14.070Z,1541484194.070 [DataOverHttps](INFO): Sending 78 bytes from file Logs/20181031T230427/Courier0007.lzma
2018-11-06T06:03:14.345Z,1541484194.345 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2018-11-06T06:03:14.345Z,1541484194.345 [WetLabsBB2FL](INFO): Powering down
2018-11-06T06:03:14.346Z,1541484194.346 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2018-11-06T06:03:14.361Z,1541484194.361 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2018-11-06T06:03:14.361Z,1541484194.361 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2018-11-06T06:03:14.361Z,1541484194.361 [CTD_Seabird](INFO): Join timeout helper Thread ID is 2977
2018-11-06T06:03:14.421Z,1541484194.421 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2018-11-06T06:03:14.604Z,1541484194.604 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface
2018-11-06T06:03:14.605Z,1541484194.605 [CTD_Seabird](INFO): Powering down
2018-11-06T06:03:14.606Z,1541484194.606 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2018-11-06T06:03:14.621Z,1541484194.621 [ComponentRegistry](INFO): Shutting down Rowe_600LCM ThreadHandler
2018-11-06T06:03:14.621Z,1541484194.621 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2018-11-06T06:03:14.622Z,1541484194.622 [Rowe_600LCM](INFO): Join timeout helper Thread ID is 2979
2018-11-06T06:03:14.868Z,1541484194.868 [DataOverHttps](INFO): Moved sent file to Logs/20181031T230427/Courier0007.lzma.bak
2018-11-06T06:03:14.869Z,1541484194.869 [DataOverHttps](INFO): SBD MOMSN=8793695
2018-11-06T06:03:15.189Z,1541484195.189 [Rowe_600LCM ThreadHandler](INFO): Uninitializing protected caller thread.
2018-11-06T06:03:15.190Z,1541484195.190 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-11-06T06:03:15.327Z,1541484195.327 [Rowe_600LCM](INFO): Powering down
2018-11-06T06:03:15.328Z,1541484195.328 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2018-11-06T06:03:15.342Z,1541484195.342 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2018-11-06T06:03:15.342Z,1541484195.342 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-11-06T06:03:15.343Z,1541484195.343 [Radio_Surface](INFO): Join timeout helper Thread ID is 2981
2018-11-06T06:03:15.657Z,1541484195.657 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2018-11-06T06:03:15.658Z,1541484195.658 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-11-06T06:03:15.670Z,1541484195.670 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2018-11-06T06:03:15.670Z,1541484195.670 [logger ThreadHandler](INFO): Thread cancelled.
2018-11-06T06:03:15.670Z,1541484195.670 [logger](INFO): Join timeout helper Thread ID is 2982
2018-11-06T06:03:15.685Z,1541484195.685 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2018-11-06T06:03:15.686Z,1541484195.686 [logger ThreadHandler](INFO): Thread cancelled.
2018-11-06T06:03:15.702Z,1541484195.702 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2018-11-06T06:03:15.702Z,1541484195.702 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-11-06T06:03:15.702Z,1541484195.702 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2018-11-06T06:03:15.702Z,1541484195.702 [controlThread ThreadHandler](INFO): Thread cancelled.
2018-11-06T06:03:15.703Z,1541484195.703 [controlThread](INFO): Join timeout helper Thread ID is 2983
2018-11-06T06:03:16.158Z,1541484196.158 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2018-11-06T06:03:16.158Z,1541484196.158 [controlThread](DEBUG): Uninitializing ControlThread
2018-11-06T06:03:16.158Z,1541484196.158 [AcousticModem_Benthos_ATM900](INFO): Powering down
2018-11-06T06:03:16.278Z,1541484196.278 [NAL9602](INFO): Powering down
2018-11-06T06:03:16.280Z,1541484196.280 [PNI_TCM](INFO): Powering down
2018-11-06T06:03:16.401Z,1541484196.401 [Aanderaa_O2](INFO): Powering down
2018-11-06T06:03:16.404Z,1541484196.404 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2018-11-06T06:03:16.405Z,1541484196.405 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2018-11-06T06:03:16.405Z,1541484196.405 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2018-11-06T06:03:16.406Z,1541484196.406 [MissionManager](INFO): Uninitializing Mission Default
2018-11-06T06:03:16.409Z,1541484196.409 [MissionManager](INFO): Uninitializing Mission Startup
2018-11-06T06:03:16.409Z,1541484196.409 [Startup] Stopped
2018-11-06T06:03:16.409Z,1541484196.409 [Startup](DEBUG): Aggregate::uninitialize Startup
2018-11-06T06:03:16.409Z,1541484196.409 [Startup:A.GoToSurface] Stopped
2018-11-06T06:03:16.409Z,1541484196.409 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2018-11-06T06:03:16.409Z,1541484196.409 [Startup:StartupSatComms] Stopped
2018-11-06T06:03:16.410Z,1541484196.410 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2018-11-06T06:03:16.410Z,1541484196.410 [Startup:StartupSatComms:B] Stopped
2018-11-06T06:03:16.411Z,1541484196.411 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2018-11-06T06:03:16.412Z,1541484196.412 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2018-11-06T06:03:16.412Z,1541484196.412 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2018-11-06T06:03:16.412Z,1541484196.412 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2018-11-06T06:03:16.413Z,1541484196.413 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2018-11-06T06:03:16.413Z,1541484196.413 [BuoyancyServo](INFO): Powering down
2018-11-06T06:03:16.425Z,1541484196.425 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2018-11-06T06:03:16.425Z,1541484196.425 [ElevatorServo](INFO): Powering down
2018-11-06T06:03:16.426Z,1541484196.426 [MassServo](DEBUG): Uninitialize Mass Servo.
2018-11-06T06:03:16.426Z,1541484196.426 [MassServo](INFO): Powering down
2018-11-06T06:03:16.427Z,1541484196.427 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2018-11-06T06:03:16.427Z,1541484196.427 [RudderServo](INFO): Powering down
2018-11-06T06:03:16.428Z,1541484196.428 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2018-11-06T06:03:16.428Z,1541484196.428 [ThrusterServo](INFO): Powering down
2018-11-06T06:03:16.429Z,1541484196.429 [SBIT](DEBUG): Uninitialize SBIT Component.
2018-11-06T06:03:16.430Z,1541484196.430 [IBIT](DEBUG): Uninitialize IBIT Component.
2018-11-06T06:03:16.430Z,1541484196.430 [CBIT](DEBUG): Uninitialize CBIT Component.
2018-11-06T06:03:16.431Z,1541484196.431 [controlThread ThreadHandler](INFO): Thread cancelled.
2018-11-06T06:03:16.512Z,1541484196.512 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2018-11-06T06:03:16.518Z,1541484196.518 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-11-06T06:03:16.557Z,1541484196.557 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2018-11-06T06:03:16.562Z,1541484196.562 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2018-11-06T06:03:16.609Z,1541484196.609 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-11-06T06:03:16.667Z,1541484196.667 [logger ThreadHandler](INFO): Thread cancelled.