2018-11-17T11:06:49.561Z,1542452809.561 [Supervisor](DEBUG): Initializing supervisor.
2018-11-17T11:06:49.563Z,1542452809.563 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2018-11-17T11:06:49.564Z,1542452809.564 [SyncHandler](INFO): Protected caller Thread ID is 799
2018-11-17T11:06:49.564Z,1542452809.564 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2018-11-17T11:06:49.565Z,1542452809.565 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2018-11-17T11:06:49.566Z,1542452809.566 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 800
2018-11-17T11:06:49.568Z,1542452809.568 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2018-11-17T11:06:49.580Z,1542452809.580 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2018-11-17T11:06:49.581Z,1542452809.581 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2018-11-17T11:06:49.582Z,1542452809.582 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 801
2018-11-17T11:06:49.582Z,1542452809.582 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2018-11-17T11:06:49.583Z,1542452809.583 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2018-11-17T11:06:49.584Z,1542452809.584 [logger ThreadHandler](INFO): Protected caller Thread ID is 802
2018-11-17T11:06:49.586Z,1542452809.586 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2018-11-17T11:06:49.586Z,1542452809.586 [Supervisor](INFO): Looking for Config files in directory: Config/
2018-11-17T11:06:49.590Z,1542452809.590 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2018-11-17T11:06:49.691Z,1542452809.691 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2018-11-17T11:06:49.693Z,1542452809.693 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2018-11-17T11:06:49.796Z,1542452809.796 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2018-11-17T11:06:49.798Z,1542452809.798 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2018-11-17T11:06:50.010Z,1542452810.010 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2018-11-17T11:06:50.010Z,1542452810.010 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2018-11-17T11:06:50.365Z,1542452810.365 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2018-11-17T11:06:50.367Z,1542452810.367 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2018-11-17T11:06:50.733Z,1542452810.733 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2018-11-17T11:06:50.735Z,1542452810.735 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2018-11-17T11:06:51.223Z,1542452811.223 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2018-11-17T11:06:51.225Z,1542452811.225 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2018-11-17T11:06:51.720Z,1542452811.720 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2018-11-17T11:06:51.722Z,1542452811.722 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2018-11-17T11:06:52.200Z,1542452812.200 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2018-11-17T11:06:52.202Z,1542452812.202 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2018-11-17T11:06:52.300Z,1542452812.300 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2018-11-17T11:06:52.642Z,1542452812.642 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2018-11-17T11:06:52.644Z,1542452812.644 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2018-11-17T11:06:52.800Z,1542452812.800 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2018-11-17T11:06:52.800Z,1542452812.800 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2018-11-17T11:06:53.030Z,1542452813.030 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2018-11-17T11:06:53.031Z,1542452813.031 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2018-11-17T11:06:53.754Z,1542452813.754 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2018-11-17T11:06:53.754Z,1542452813.754 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2018-11-17T11:06:53.855Z,1542452813.855 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2018-11-17T11:06:53.857Z,1542452813.857 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2018-11-17T11:06:54.009Z,1542452814.009 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2018-11-17T11:06:54.011Z,1542452814.011 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/
2018-11-17T11:06:54.013Z,1542452814.013 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg
2018-11-17T11:06:54.251Z,1542452814.251 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2018-11-17T11:06:54.252Z,1542452814.252 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg
2018-11-17T11:06:54.361Z,1542452814.361 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg
2018-11-17T11:06:54.519Z,1542452814.519 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg
2018-11-17T11:06:54.615Z,1542452814.615 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg
2018-11-17T11:06:54.702Z,1542452814.702 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg
2018-11-17T11:06:54.866Z,1542452814.866 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg
2018-11-17T11:06:55.076Z,1542452815.076 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg
2018-11-17T11:06:55.177Z,1542452815.177 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg
2018-11-17T11:06:55.276Z,1542452815.276 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg
2018-11-17T11:06:55.378Z,1542452815.378 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg
2018-11-17T11:06:55.462Z,1542452815.462 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg
2018-11-17T11:06:55.465Z,1542452815.465 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2018-11-17T11:06:55.601Z,1542452815.601 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2018-11-17T11:06:55.603Z,1542452815.603 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2018-11-17T11:06:55.627Z,1542452815.627 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2018-11-17T11:06:55.629Z,1542452815.629 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2018-11-17T11:06:55.687Z,1542452815.687 [DepthRateCalculator] Loaded
2018-11-17T11:06:55.687Z,1542452815.687 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2018-11-17T11:06:55.693Z,1542452815.693 [PitchRateCalculator] Loaded
2018-11-17T11:06:55.694Z,1542452815.694 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2018-11-17T11:06:55.711Z,1542452815.711 [SpeedCalculator] Loaded
2018-11-17T11:06:55.711Z,1542452815.711 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2018-11-17T11:06:55.733Z,1542452815.733 [TempGradientCalculator] Loaded
2018-11-17T11:06:55.733Z,1542452815.733 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2018-11-17T11:06:55.739Z,1542452815.739 [YawRateCalculator] Loaded
2018-11-17T11:06:55.740Z,1542452815.740 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2018-11-17T11:06:55.782Z,1542452815.782 [ElevatorOffsetCalculator] Loaded
2018-11-17T11:06:55.782Z,1542452815.782 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2018-11-17T11:06:55.782Z,1542452815.782 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2018-11-17T11:06:55.783Z,1542452815.783 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2018-11-17T11:06:55.822Z,1542452815.822 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2018-11-17T11:06:55.822Z,1542452815.822 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2018-11-17T11:06:56.319Z,1542452816.319 [AcousticModem_Benthos_ATM900] Loaded
2018-11-17T11:06:56.319Z,1542452816.319 [ComponentRegistry](DEBUG): SyncComponent "AcousticModem_Benthos_ATM900" handled in the control thread.
2018-11-17T11:06:56.459Z,1542452816.459 [DataOverHttps] Loaded
2018-11-17T11:06:56.459Z,1542452816.459 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2018-11-17T11:06:56.474Z,1542452816.474 [Depth_Keller] Loaded
2018-11-17T11:06:56.474Z,1542452816.474 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2018-11-17T11:06:56.479Z,1542452816.479 [DropWeight] Loaded
2018-11-17T11:06:56.479Z,1542452816.479 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2018-11-17T11:06:56.583Z,1542452816.583 [NAL9602] Loaded
2018-11-17T11:06:56.583Z,1542452816.583 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2018-11-17T11:06:56.599Z,1542452816.599 [Onboard] Loaded
2018-11-17T11:06:56.600Z,1542452816.600 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2018-11-17T11:06:56.610Z,1542452816.610 [Radio_Surface] Loaded
2018-11-17T11:06:56.611Z,1542452816.611 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2018-11-17T11:06:56.612Z,1542452816.612 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 407C24E0
2018-11-17T11:06:56.612Z,1542452816.612 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 881
2018-11-17T11:06:56.768Z,1542452816.768 [PNI_TCM] Loaded
2018-11-17T11:06:56.768Z,1542452816.768 [ComponentRegistry](DEBUG): SyncComponent "PNI_TCM" handled in the control thread.
2018-11-17T11:06:56.833Z,1542452816.833 [Rowe_600LCM] Loaded
2018-11-17T11:06:56.833Z,1542452816.833 [ComponentRegistry](DEBUG): Component "Rowe_600LCM" handled in its own thread.
2018-11-17T11:06:56.835Z,1542452816.835 [Rowe_600LCM ThreadHandler](DEBUG): Created PCaller Thread at 407F24E0
2018-11-17T11:06:56.835Z,1542452816.835 [Rowe_600LCM ThreadHandler](INFO): Protected caller Thread ID is 882
2018-11-17T11:06:59.047Z,1542452819.047 [BPC1] Loaded
2018-11-17T11:06:59.047Z,1542452819.047 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2018-11-17T11:06:59.048Z,1542452819.048 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2018-11-17T11:06:59.048Z,1542452819.048 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2018-11-17T11:06:59.214Z,1542452819.214 [SBIT](DEBUG): Construct Startup Built In Test.
2018-11-17T11:06:59.238Z,1542452819.238 [SBIT] Loaded
2018-11-17T11:06:59.238Z,1542452819.238 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2018-11-17T11:06:59.239Z,1542452819.239 [IBIT](DEBUG): Construct Initiated Built In Test.
2018-11-17T11:06:59.250Z,1542452819.250 [IBIT] Loaded
2018-11-17T11:06:59.251Z,1542452819.251 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2018-11-17T11:06:59.254Z,1542452819.254 [CBIT](DEBUG): Construct Continuous Built In Test.
2018-11-17T11:06:59.410Z,1542452819.410 [CBIT] Loaded
2018-11-17T11:06:59.410Z,1542452819.410 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2018-11-17T11:06:59.411Z,1542452819.411 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2018-11-17T11:06:59.411Z,1542452819.411 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2018-11-17T11:06:59.629Z,1542452819.629 [Aanderaa_O2] Loaded
2018-11-17T11:06:59.630Z,1542452819.630 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2018-11-17T11:06:59.690Z,1542452819.690 [CTD_Seabird] Loaded
2018-11-17T11:06:59.690Z,1542452819.690 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2018-11-17T11:06:59.691Z,1542452819.691 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 408C74E0
2018-11-17T11:06:59.692Z,1542452819.692 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 883
2018-11-17T11:06:59.710Z,1542452819.710 [ESPComponent] Loaded
2018-11-17T11:06:59.711Z,1542452819.711 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2018-11-17T11:06:59.725Z,1542452819.725 [PAR_Licor] Loaded
2018-11-17T11:06:59.726Z,1542452819.726 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2018-11-17T11:06:59.777Z,1542452819.777 [WetLabsBB2FL] Loaded
2018-11-17T11:06:59.777Z,1542452819.777 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2018-11-17T11:06:59.778Z,1542452819.778 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 408F74E0
2018-11-17T11:06:59.779Z,1542452819.779 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 884
2018-11-17T11:06:59.779Z,1542452819.779 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2018-11-17T11:06:59.781Z,1542452819.781 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2018-11-17T11:07:00.077Z,1542452820.077 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2018-11-17T11:07:00.078Z,1542452820.078 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2018-11-17T11:07:00.170Z,1542452820.170 [VerticalControl](DEBUG): Construct VerticalControl.
2018-11-17T11:07:00.270Z,1542452820.270 [VerticalControl] Loaded
2018-11-17T11:07:00.270Z,1542452820.270 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2018-11-17T11:07:00.271Z,1542452820.271 [HorizontalControl](DEBUG): Construct HorizontalControl.
2018-11-17T11:07:00.335Z,1542452820.335 [HorizontalControl] Loaded
2018-11-17T11:07:00.335Z,1542452820.335 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2018-11-17T11:07:00.336Z,1542452820.336 [SpeedControl](DEBUG): Construct SpeedControl.
2018-11-17T11:07:00.341Z,1542452820.341 [SpeedControl] Loaded
2018-11-17T11:07:00.342Z,1542452820.342 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2018-11-17T11:07:00.342Z,1542452820.342 [LoopControl](DEBUG): Construct LoopControl.
2018-11-17T11:07:00.343Z,1542452820.343 [LoopControl] Loaded
2018-11-17T11:07:00.343Z,1542452820.343 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2018-11-17T11:07:00.344Z,1542452820.344 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2018-11-17T11:07:00.346Z,1542452820.346 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2018-11-17T11:07:00.451Z,1542452820.451 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2018-11-17T11:07:00.452Z,1542452820.452 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2018-11-17T11:07:00.577Z,1542452820.577 [BuoyancyServo] Loaded
2018-11-17T11:07:00.577Z,1542452820.577 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2018-11-17T11:07:00.589Z,1542452820.589 [ElevatorServo] Loaded
2018-11-17T11:07:00.589Z,1542452820.589 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2018-11-17T11:07:00.600Z,1542452820.600 [MassServo] Loaded
2018-11-17T11:07:00.601Z,1542452820.601 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2018-11-17T11:07:00.613Z,1542452820.613 [RudderServo] Loaded
2018-11-17T11:07:00.613Z,1542452820.613 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2018-11-17T11:07:00.624Z,1542452820.624 [ThrusterServo] Loaded
2018-11-17T11:07:00.625Z,1542452820.625 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2018-11-17T11:07:00.625Z,1542452820.625 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2018-11-17T11:07:00.626Z,1542452820.626 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2018-11-17T11:07:00.737Z,1542452820.737 [DeadReckonUsingSpeedCalculator] Loaded
2018-11-17T11:07:00.738Z,1542452820.738 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2018-11-17T11:07:00.755Z,1542452820.755 [NavChart] Loaded
2018-11-17T11:07:00.755Z,1542452820.755 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2018-11-17T11:07:00.759Z,1542452820.759 [UniversalFixResidualReporter] Loaded
2018-11-17T11:07:00.759Z,1542452820.759 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2018-11-17T11:07:00.760Z,1542452820.760 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2018-11-17T11:07:00.764Z,1542452820.764 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2018-11-17T11:07:00.764Z,1542452820.764 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2018-11-17T11:07:00.771Z,1542452820.771 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2018-11-17T11:07:00.772Z,1542452820.772 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40A504E0
2018-11-17T11:07:00.773Z,1542452820.773 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 885
2018-11-17T11:07:00.777Z,1542452820.777 [Supervisor](INFO): Main Thread ID is 795
2018-11-17T11:07:00.777Z,1542452820.777 [Supervisor](DEBUG): Running supervisor.
2018-11-17T11:07:00.778Z,1542452820.778 [CommandLine ThreadHandler](INFO): Handler Thread ID is 886
2018-11-17T11:07:00.780Z,1542452820.780 [controlThread ThreadHandler](INFO): Handler Thread ID is 887
2018-11-17T11:07:00.781Z,1542452820.781 [controlThread](DEBUG): Initializing ControlThread
2018-11-17T11:07:00.782Z,1542452820.782 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2018-11-17T11:07:00.782Z,1542452820.782 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2018-11-17T11:07:00.782Z,1542452820.782 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2018-11-17T11:07:00.783Z,1542452820.783 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2018-11-17T11:07:00.783Z,1542452820.783 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2018-11-17T11:07:00.783Z,1542452820.783 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2018-11-17T11:07:00.788Z,1542452820.788 [SBIT](INFO): Initialize SBIT Component.
2018-11-17T11:07:00.789Z,1542452820.789 [SBIT](IMPORTANT): git: 2018-11-05-3-g424fd37
2018-11-17T11:07:00.789Z,1542452820.789 [SBIT](INFO): git hash: 424fd377e53a63ada65ca308b07209cf4fd40d4d
2018-11-17T11:07:00.789Z,1542452820.789 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2018-11-17T11:07:00.790Z,1542452820.790 [SBIT](IMPORTANT): Kernel Version:#2 PREEMPT Thu Jan 11 20:13:48 PST 2018
2018-11-17T11:07:00.791Z,1542452820.791 [SBIT](INFO): Beginning SBIT in 24.000000 seconds.
2018-11-17T11:07:00.791Z,1542452820.791 [IBIT](INFO): Initialize IBIT Component.
2018-11-17T11:07:00.792Z,1542452820.792 [CBIT](DEBUG): Initialize CBIT Component.
2018-11-17T11:07:00.792Z,1542452820.792 [CBIT](DEBUG): Initialized mux pins.
2018-11-17T11:07:00.792Z,1542452820.792 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL.
2018-11-17T11:07:00.792Z,1542452820.792 [CBIT](DEBUG): Initializing the watchdog timer.
2018-11-17T11:07:00.793Z,1542452820.793 [logger ThreadHandler](INFO): Handler Thread ID is 888
2018-11-17T11:07:00.814Z,1542452820.814 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 889
2018-11-17T11:07:00.820Z,1542452820.820 [CBIT](CRITICAL): LAST REBOOT DUE TO WATCHDOG TIMER RESET.
2018-11-17T11:07:00.820Z,1542452820.820 [CBIT](DEBUG): Initializing heartbeat.
2018-11-17T11:07:00.820Z,1542452820.820 [Radio_Surface](INFO): Powering up
2018-11-17T11:07:00.826Z,1542452820.826 [Rowe_600LCM ThreadHandler](INFO): Handler Thread ID is 890
2018-11-17T11:07:00.827Z,1542452820.827 [Rowe_600LCM](INFO): Initializing
2018-11-17T11:07:00.827Z,1542452820.827 [Rowe_600LCM](INFO): Checking LCM
2018-11-17T11:07:00.914Z,1542452820.914 [CBIT](DEBUG): Deactivating GF circuits.
2018-11-17T11:07:00.915Z,1542452820.915 [CBIT](DEBUG): Deactivating emergency mode.
2018-11-17T11:07:00.922Z,1542452820.922 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 891
2018-11-17T11:07:00.922Z,1542452820.922 [CTD_Seabird](INFO): Initializing
2018-11-17T11:07:00.923Z,1542452820.923 [CTD_Seabird](INFO): Checking LCM
2018-11-17T11:07:00.973Z,1542452820.973 [CBIT](DEBUG): Backplane powered.
2018-11-17T11:07:01.018Z,1542452821.018 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 892
2018-11-17T11:07:01.019Z,1542452821.019 [WetLabsBB2FL](INFO): Powering down
2018-11-17T11:07:01.037Z,1542452821.037 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2018-11-17T11:07:01.039Z,1542452821.039 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2018-11-17T11:07:01.040Z,1542452821.040 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2018-11-17T11:07:01.040Z,1542452821.040 [LoopControl](DEBUG): Initialize LoopControlComponent.
2018-11-17T11:07:01.042Z,1542452821.042 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-11-17T11:07:01.043Z,1542452821.043 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-11-17T11:07:01.043Z,1542452821.043 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-11-17T11:07:01.043Z,1542452821.043 [NavChart](DEBUG): Initialize NavChart Navigation.
2018-11-17T11:07:01.044Z,1542452821.044 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2018-11-17T11:07:01.045Z,1542452821.045 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2018-11-17T11:07:01.060Z,1542452821.060 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 893
2018-11-17T11:07:01.187Z,1542452821.187 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2018-11-17T11:07:01.187Z,1542452821.187 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2018-11-17T11:07:01.188Z,1542452821.188 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2018-11-17T11:07:01.188Z,1542452821.188 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2018-11-17T11:07:01.188Z,1542452821.188 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2018-11-17T11:07:01.188Z,1542452821.188 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2018-11-17T11:07:01.188Z,1542452821.188 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2018-11-17T11:07:01.188Z,1542452821.188 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2018-11-17T11:07:01.189Z,1542452821.189 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2018-11-17T11:07:01.189Z,1542452821.189 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2018-11-17T11:07:01.189Z,1542452821.189 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2018-11-17T11:07:01.189Z,1542452821.189 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2018-11-17T11:07:01.192Z,1542452821.192 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2018-11-17T11:07:01.198Z,1542452821.197 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2018-11-17T11:07:01.198Z,1542452821.198 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2018-11-17T11:07:01.198Z,1542452821.198 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2018-11-17T11:07:01.198Z,1542452821.198 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2018-11-17T11:07:01.219Z,1542452821.219 [CTD_Seabird](INFO): LCM OK
2018-11-17T11:07:01.219Z,1542452821.219 [CTD_Seabird](INFO): Powering up
2018-11-17T11:07:01.233Z,1542452821.233 [Rowe_600LCM](INFO): LCM OK
2018-11-17T11:07:01.233Z,1542452821.233 [Rowe_600LCM](INFO): Powering up
2018-11-17T11:07:01.240Z,1542452821.240 [MissionManager](DEBUG):
2018-11-17T11:07:01.240Z,1542452821.240 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2018-11-17T11:07:01.321Z,1542452821.321 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2018-11-17T11:07:01.322Z,1542452821.322 [Default:A.Wait](DEBUG): Construct Wait.
2018-11-17T11:07:01.324Z,1542452821.324 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2018-11-17T11:07:01.380Z,1542452821.380 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2018-11-17T11:07:01.382Z,1542452821.382 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2018-11-17T11:07:01.404Z,1542452821.404 [Default:E.Execute](DEBUG): Construct Execute.
2018-11-17T11:07:01.408Z,1542452821.408 [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-17T11:07:01.414Z,1542452821.414 [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-17T11:07:01.442Z,1542452821.442 [AcousticModem_Benthos_ATM900](INFO): Powering up
2018-11-17T11:07:01.442Z,1542452821.442 [AcousticModem_Benthos_ATM900](DEBUG): Initializing AcousticModem_Benthos_ATM900.
2018-11-17T11:07:01.468Z,1542452821.468 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2018-11-17T11:07:01.764Z,1542452821.764 [ESPComponent](INFO): powering down ESP
2018-11-17T11:07:02.366Z,1542452822.366 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2018-11-17T11:07:02.374Z,1542452822.374 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2018-11-17T11:07:02.396Z,1542452822.396 [ElevatorServo](DEBUG): Initializing EZServoServo.
2018-11-17T11:07:02.402Z,1542452822.402 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2018-11-17T11:07:02.408Z,1542452822.408 [MassServo](DEBUG): Initializing EZServoServo.
2018-11-17T11:07:02.414Z,1542452822.414 [MassServo](DEBUG): Initializing MassServo.
2018-11-17T11:07:02.420Z,1542452822.420 [RudderServo](DEBUG): Initializing EZServoServo.
2018-11-17T11:07:02.430Z,1542452822.430 [RudderServo](DEBUG): Initializing RudderServo.
2018-11-17T11:07:02.452Z,1542452822.452 [ThrusterServo](DEBUG): Initializing EZServoServo.
2018-11-17T11:07:02.458Z,1542452822.458 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2018-11-17T11:07:02.487Z,1542452822.487 [CommandLine](FAULT): Scheduling is paused
2018-11-17T11:07:02.487Z,1542452822.487 [CBIT](INFO): Critical error at 20181117T110700
2018-11-17T11:07:02.488Z,1542452822.488 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2018-11-17T11:07:02.597Z,1542452822.597 [DropWeight](CRITICAL): DROP WEIGHT MISSING.
2018-11-17T11:07:02.597Z,1542452822.597 [DropWeight] Hardware Fault, FailCount= 1
2018-11-17T11:07:02.598Z,1542452822.598 [DropWeight](ERROR): Hardware Fault
2018-11-17T11:07:02.714Z,1542452822.714 [CBIT](INFO): Critical error at 20181117T110702
2018-11-17T11:07:02.716Z,1542452822.716 [CBIT](ERROR): Hardware Fault in component: DropWeight
2018-11-17T11:07:02.717Z,1542452822.717 [CBIT](CRITICAL): Hardware Fault in component: DropWeight
2018-11-17T11:07:03.322Z,1542452823.322 [BuoyancyServo](ERROR): Buoyancy initialization uart error serial timeout
2018-11-17T11:07:03.322Z,1542452823.322 [BuoyancyServo](FAULT): Buoyancy failed to initialize
2018-11-17T11:07:03.322Z,1542452823.322 [BuoyancyServo] Communications Fault, FailCount= 1
2018-11-17T11:07:03.322Z,1542452823.322 [BuoyancyServo](ERROR): Communications Fault
2018-11-17T11:07:03.527Z,1542452823.527 [CBIT](INFO): Critical error at 20181117T110702
2018-11-17T11:07:03.530Z,1542452823.530 [CBIT](ERROR): Communications Fault in component: BuoyancyServo
2018-11-17T11:07:05.089Z,1542452825.089 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-11-17T11:07:05.196Z,1542452825.196 [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-17T11:07:05.342Z,1542452825.342 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-11-17T11:07:05.343Z,1542452825.343 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-11-17T11:07:05.343Z,1542452825.343 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-11-17T11:07:05.655Z,1542452825.655 [CBIT](INFO): Clearing failed state for component BuoyancyServo
2018-11-17T11:07:05.655Z,1542452825.655 [BuoyancyServo] No Fault, FailCount= 1
2018-11-17T11:07:06.020Z,1542452826.020 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2018-11-17T11:07:06.020Z,1542452826.020 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2018-11-17T11:07:06.392Z,1542452826.392 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface
2018-11-17T11:07:06.491Z,1542452826.491 [Radio_Surface](INFO): Powering down
2018-11-17T11:07:06.597Z,1542452826.597 [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-17T11:07:06.598Z,1542452826.598 [CTD_Seabird](INFO): LCM subscribed to channel:seabird_gpctd_t.seabird-gpctd
2018-11-17T11:07:06.998Z,1542452826.998 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface
2018-11-17T11:07:06.998Z,1542452826.998 [CTD_Seabird](INFO): Powering down
2018-11-17T11:07:09.138Z,1542452829.138 [AcousticModem_Benthos_ATM900](DEBUG):
2018-11-17T11:07:09.157Z,1542452829.157 [PNI_TCM](FAULT): Failed to set parameters during initialization.
2018-11-17T11:07:09.158Z,1542452829.158 [PNI_TCM] Data Fault, FailCount= 1
2018-11-17T11:07:09.158Z,1542452829.158 [PNI_TCM](ERROR): Data Fault
2018-11-17T11:07:09.319Z,1542452829.319 [CBIT](ERROR): Data Fault in component: PNI_TCM
2018-11-17T11:07:09.557Z,1542452829.557 [PNI_TCM](INFO): Powering down
2018-11-17T11:07:10.340Z,1542452830.340 [AcousticModem_Benthos_ATM900](DEBUG): Teledyne Benthos ATM-900 Series OEM w/burn wire
2018-11-17T11:07:10.340Z,1542452830.340 [AcousticModem_Benthos_ATM900](DEBUG): MF Frequency Band
2018-11-17T11:07:10.341Z,1542452830.341 [AcousticModem_Benthos_ATM900](DEBUG): Standard version 8.6.3
2018-11-17T11:07:10.342Z,1542452830.342 [AcousticModem_Benthos_ATM900](DEBUG): Nov 4 2018 21:52:51
2018-11-17T11:07:10.739Z,1542452830.739 [AcousticModem_Benthos_ATM900](DEBUG): WARNING: battery low
2018-11-17T11:07:10.871Z,1542452830.871 [CBIT](CRITICAL): Environmental Failure. Press:14.734596 PSI. Humidity:24%. Temp:29 C. ABORTING MISSION
2018-11-17T11:07:10.872Z,1542452830.872 [CBIT](INFO): Clearing failed state for component PNI_TCM
2018-11-17T11:07:10.872Z,1542452830.872 [PNI_TCM] No Fault, FailCount= 1
2018-11-17T11:07:11.257Z,1542452831.257 [CBIT](INFO): Critical error at 20181117T110710
2018-11-17T11:07:11.538Z,1542452831.538 [AcousticModem_Benthos_ATM900](INFO): entering command mode
2018-11-17T11:07:11.939Z,1542452831.939 [AcousticModem_Benthos_ATM900](DEBUG): checking for command mode acknowledgment
2018-11-17T11:07:11.939Z,1542452831.939 [AcousticModem_Benthos_ATM900](DEBUG): read user prompt 1: user:1>
2018-11-17T11:07:11.940Z,1542452831.940 [AcousticModem_Benthos_ATM900](INFO): command mode acknowledged
2018-11-17T11:07:11.971Z,1542452831.971 [Aanderaa_O2](FAULT): Failed to initialize within timeout.
2018-11-17T11:07:11.971Z,1542452831.971 [Aanderaa_O2] Communications Fault, FailCount= 1
2018-11-17T11:07:11.971Z,1542452831.971 [Aanderaa_O2](ERROR): Communications Fault
2018-11-17T11:07:12.021Z,1542452832.021 [CBIT](ERROR): Communications Fault in component: Aanderaa_O2
2018-11-17T11:07:12.338Z,1542452832.338 [AcousticModem_Benthos_ATM900](INFO): setting local address to 3
2018-11-17T11:07:12.370Z,1542452832.370 [Aanderaa_O2](INFO): Powering down
2018-11-17T11:07:12.738Z,1542452832.738 [AcousticModem_Benthos_ATM900](DEBUG): checking for local address setting acknowledgment
2018-11-17T11:07:12.739Z,1542452832.739 [AcousticModem_Benthos_ATM900](INFO): set local address to 3
2018-11-17T11:07:13.139Z,1542452833.139 [AcousticModem_Benthos_ATM900](DEBUG): read user prompt 2: user:2>
2018-11-17T11:07:13.242Z,1542452833.242 [CBIT](INFO): Clearing failed state for component Aanderaa_O2
2018-11-17T11:07:13.242Z,1542452833.242 [Aanderaa_O2] No Fault, FailCount= 1
2018-11-17T11:07:18.358Z,1542452838.358 [PNI_TCM](FAULT): Failed to set parameters during initialization.
2018-11-17T11:07:18.358Z,1542452838.358 [PNI_TCM] Data Fault, FailCount= 2
2018-11-17T11:07:18.358Z,1542452838.358 [PNI_TCM](ERROR): Data Fault
2018-11-17T11:07:18.444Z,1542452838.444 [CBIT](ERROR): Data Fault in component: PNI_TCM
2018-11-17T11:07:18.758Z,1542452838.758 [PNI_TCM](INFO): Powering down
2018-11-17T11:07:20.021Z,1542452840.021 [CBIT](INFO): Clearing failed state for component PNI_TCM
2018-11-17T11:07:20.021Z,1542452840.021 [PNI_TCM] No Fault, FailCount= 2
2018-11-17T11:07:23.567Z,1542452843.567 [Aanderaa_O2](FAULT): Failed to initialize within timeout.
2018-11-17T11:07:23.567Z,1542452843.567 [Aanderaa_O2] Communications Fault, FailCount= 2
2018-11-17T11:07:23.567Z,1542452843.567 [Aanderaa_O2](ERROR): Communications Fault
2018-11-17T11:07:23.627Z,1542452843.627 [CBIT](ERROR): Communications Fault in component: Aanderaa_O2
2018-11-17T11:07:23.959Z,1542452843.959 [Aanderaa_O2](INFO): Powering down
2018-11-17T11:07:24.836Z,1542452844.836 [CBIT](INFO): Clearing failed state for component Aanderaa_O2
2018-11-17T11:07:24.836Z,1542452844.836 [Aanderaa_O2] No Fault, FailCount= 2
2018-11-17T11:07:25.234Z,1542452845.234 [SBIT](IMPORTANT): Beginning Startup BIT
2018-11-17T11:07:25.251Z,1542452845.251 [CBIT](IMPORTANT): Beginning ground fault scan
2018-11-17T11:07:26.743Z,1542452846.743 [NAL9602](INFO): Powering up NAL9602
2018-11-17T11:07:27.675Z,1542452847.675 [PNI_TCM](FAULT): Failed to set parameters during initialization.
2018-11-17T11:07:27.675Z,1542452847.675 [PNI_TCM] Data Fault, FailCount= 3
2018-11-17T11:07:27.675Z,1542452847.675 [PNI_TCM](ERROR): Data Fault
2018-11-17T11:07:27.843Z,1542452847.843 [CBIT](ERROR): Data Fault in component: PNI_TCM
2018-11-17T11:07:28.068Z,1542452848.068 [PNI_TCM](INFO): Powering down
2018-11-17T11:07:29.134Z,1542452849.134 [Radio_Surface](INFO): Powering up
2018-11-17T11:07:29.427Z,1542452849.427 [CBIT](INFO): Clearing failed state for component PNI_TCM
2018-11-17T11:07:29.427Z,1542452849.427 [PNI_TCM] No Fault, FailCount= 3
2018-11-17T11:07:35.262Z,1542452855.262 [Aanderaa_O2](FAULT): Failed to initialize within timeout.
2018-11-17T11:07:35.262Z,1542452855.262 [Aanderaa_O2] Communications Fault, FailCount= 3
2018-11-17T11:07:35.262Z,1542452855.262 [Aanderaa_O2](ERROR): Communications Fault
2018-11-17T11:07:35.359Z,1542452855.359 [CBIT](ERROR): Communications Fault in component: Aanderaa_O2
2018-11-17T11:07:35.360Z,1542452855.360 [CBIT](FAULT): Communications Fault in component: Aanderaa_O2
2018-11-17T11:07:35.778Z,1542452855.778 [Aanderaa_O2](INFO): Powering down
2018-11-17T11:07:36.155Z,1542452856.155 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.006125
CHAN A1 (24V): -0.010277
CHAN A2 (12V): -0.005098
CHAN A3 (5V): -0.002652
CHAN B0 (3.3V): -0.000860
CHAN B1 (3.15aV): -0.000669
CHAN B2 (3.15bV): -0.001285
CHAN B3 (GND): -0.000457
OPEN: 0.003913
Full Scale Calc: 4.765 mA, -1.589 mA
2018-11-17T11:07:36.810Z,1542452856.810 [Radio_Surface](INFO): Powering down
2018-11-17T11:07:36.869Z,1542452856.869 [PNI_TCM](FAULT): Failed to set parameters during initialization.
2018-11-17T11:07:36.869Z,1542452856.869 [PNI_TCM] Data Fault, FailCount= 4
2018-11-17T11:07:36.869Z,1542452856.869 [PNI_TCM](ERROR): Data Fault
2018-11-17T11:07:37.011Z,1542452857.011 [CBIT](ERROR): Data Fault in component: PNI_TCM
2018-11-17T11:07:37.273Z,1542452857.273 [PNI_TCM](INFO): Powering down
2018-11-17T11:07:37.647Z,1542452857.647 [NAL9602](INFO): NAL9602 initialized
2018-11-17T11:07:38.635Z,1542452858.635 [CBIT](INFO): Clearing failed state for component PNI_TCM
2018-11-17T11:07:38.635Z,1542452858.635 [PNI_TCM] No Fault, FailCount= 4
2018-11-17T11:07:46.277Z,1542452866.277 [PNI_TCM](FAULT): Failed to set parameters during initialization.
2018-11-17T11:07:46.277Z,1542452866.277 [PNI_TCM] Data Fault, FailCount= 5
2018-11-17T11:07:46.277Z,1542452866.277 [PNI_TCM](ERROR): Data Fault
2018-11-17T11:07:46.502Z,1542452866.502 [CBIT](ERROR): Data Fault in component: PNI_TCM
2018-11-17T11:07:46.503Z,1542452866.503 [CBIT](CRITICAL): Data Fault in component: PNI_TCM
2018-11-17T11:07:46.676Z,1542452866.676 [PNI_TCM](INFO): Powering down
2018-11-17T11:07:46.849Z,1542452866.849 [CBIT](INFO): Critical error at 20181117T110746
2018-11-17T11:08:19.216Z,1542452899.216 [SBIT](IMPORTANT): SBIT PASSED
2018-11-17T11:08:19.236Z,1542452899.236 [CommandLine](IMPORTANT): got command configSet list
2018-11-17T11:08:19.237Z,1542452899.237 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2018-11-17T11:08:19.240Z,1542452899.240 [CommandLine](IMPORTANT): PAR_Licor.loadAtStartup=1 bool;
2018-11-17T11:08:19.609Z,1542452899.609 [MissionManager](IMPORTANT): Started mission Startup
2018-11-17T11:08:19.609Z,1542452899.609 [Startup] Running Loop=1
2018-11-17T11:08:19.609Z,1542452899.609 [Startup](DEBUG): Aggregate::initialize Startup
2018-11-17T11:08:19.609Z,1542452899.609 [Startup:A.GoToSurface] Running Loop=1
2018-11-17T11:08:19.610Z,1542452899.610 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-11-17T11:08:19.610Z,1542452899.610 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2018-11-17T11:08:19.611Z,1542452899.611 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2018-11-17T11:08:19.611Z,1542452899.611 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2018-11-17T11:08:19.611Z,1542452899.611 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-11-17T11:08:19.612Z,1542452899.612 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2018-11-17T11:08:19.690Z,1542452899.690 [Radio_Surface](INFO): Powering up
2018-11-17T11:09:01.255Z,1542452941.255 [DeadReckonUsingSpeedCalculator](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2018-11-17T11:09:01.255Z,1542452941.255 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 1
2018-11-17T11:09:01.255Z,1542452941.255 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-11-17T11:09:01.269Z,1542452941.269 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-11-17T11:09:01.668Z,1542452941.668 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-11-17T11:09:01.668Z,1542452941.668 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 1
2018-11-17T11:09:01.697Z,1542452941.697 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-11-17T11:09:01.698Z,1542452941.698 [Rowe_600LCM] Communications Fault, FailCount= 1
2018-11-17T11:09:01.698Z,1542452941.698 [Rowe_600LCM](ERROR): Communications Fault
2018-11-17T11:09:02.055Z,1542452942.055 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-11-17T11:09:02.055Z,1542452942.055 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-11-17T11:09:02.055Z,1542452942.055 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-11-17T11:09:02.072Z,1542452942.072 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-11-17T11:09:02.102Z,1542452942.102 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-11-17T11:09:02.192Z,1542452942.192 [Rowe_600LCM](INFO): Powering down
2018-11-17T11:09:03.677Z,1542452943.677 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-11-17T11:09:03.677Z,1542452943.677 [Rowe_600LCM] No Fault, FailCount= 1
2018-11-17T11:09:03.806Z,1542452943.806 [Rowe_600LCM](INFO): Initializing
2018-11-17T11:09:03.806Z,1542452943.806 [Rowe_600LCM](INFO): Checking LCM
2018-11-17T11:09:03.806Z,1542452943.806 [Rowe_600LCM](INFO): LCM OK
2018-11-17T11:09:03.806Z,1542452943.806 [Rowe_600LCM](INFO): Powering up
2018-11-17T11:09:05.275Z,1542452945.275 [VerticalControl](CRITICAL): Excessive depth excursion=11.500118 m, failToGoUpDepth_=32.927418 m, depthRate=0.251046 m/s, pitch=nan deg.
2018-11-17T11:09:05.281Z,1542452945.281 [CBIT](INFO): Critical error at 20181117T110905
2018-11-17T11:09:07.926Z,1542452947.926 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-11-17T11:09:07.984Z,1542452947.984 [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-17T11:09:07.985Z,1542452947.985 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-11-17T11:09:07.986Z,1542452947.986 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-11-17T11:09:07.986Z,1542452947.986 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-11-17T11:09:46.865Z,1542452986.865 [VerticalControl](CRITICAL): Dropping drop weight at excessive depth excursion=21.734863, failToGoUpDepth_=32.927418, depthRate=0.249688 m/s, pitch=nan deg.
2018-11-17T11:09:46.883Z,1542452986.883 [CBIT](INFO): Critical error at 20181117T110946
2018-11-17T11:10:05.266Z,1542453005.266 [CBIT](INFO): Clearing failed state for component Aanderaa_O2
2018-11-17T11:10:05.266Z,1542453005.266 [Aanderaa_O2] No Fault, FailCount= 3
2018-11-17T11:10:15.634Z,1542453015.634 [Aanderaa_O2](FAULT): Failed to initialize within timeout.
2018-11-17T11:10:15.634Z,1542453015.634 [Aanderaa_O2] Communications Fault, FailCount= 1
2018-11-17T11:10:15.634Z,1542453015.634 [Aanderaa_O2](ERROR): Communications Fault
2018-11-17T11:10:15.681Z,1542453015.681 [CBIT](ERROR): Communications Fault in component: Aanderaa_O2
2018-11-17T11:10:16.166Z,1542453016.166 [Aanderaa_O2](INFO): Powering down
2018-11-17T11:10:16.886Z,1542453016.886 [CBIT](INFO): Clearing failed state for component Aanderaa_O2
2018-11-17T11:10:16.886Z,1542453016.886 [Aanderaa_O2] No Fault, FailCount= 1
2018-11-17T11:10:27.250Z,1542453027.250 [Aanderaa_O2](FAULT): Failed to initialize within timeout.
2018-11-17T11:10:27.250Z,1542453027.250 [Aanderaa_O2] Communications Fault, FailCount= 2
2018-11-17T11:10:27.250Z,1542453027.250 [Aanderaa_O2](ERROR): Communications Fault
2018-11-17T11:10:27.301Z,1542453027.301 [CBIT](ERROR): Communications Fault in component: Aanderaa_O2
2018-11-17T11:10:27.763Z,1542453027.763 [Aanderaa_O2](INFO): Powering down
2018-11-17T11:10:28.504Z,1542453028.504 [CBIT](INFO): Clearing failed state for component Aanderaa_O2
2018-11-17T11:10:28.504Z,1542453028.504 [Aanderaa_O2] No Fault, FailCount= 2
2018-11-17T11:10:38.848Z,1542453038.848 [Aanderaa_O2](FAULT): Failed to initialize within timeout.
2018-11-17T11:10:38.848Z,1542453038.848 [Aanderaa_O2] Communications Fault, FailCount= 3
2018-11-17T11:10:38.848Z,1542453038.848 [Aanderaa_O2](ERROR): Communications Fault
2018-11-17T11:10:38.871Z,1542453038.871 [CBIT](ERROR): Communications Fault in component: Aanderaa_O2
2018-11-17T11:10:38.871Z,1542453038.871 [CBIT](FAULT): Communications Fault in component: Aanderaa_O2
2018-11-17T11:10:39.346Z,1542453039.346 [Aanderaa_O2](INFO):