2016-05-11T18:42:26.464Z,1462992146.464 [Supervisor](DEBUG): Initializing supervisor. 2016-05-11T18:42:26.466Z,1462992146.466 [SyncHandler](DEBUG): Created PCaller Thread at 4034C4E0 2016-05-11T18:42:26.467Z,1462992146.467 [SyncHandler](INFO): Protected caller Thread ID is 4027 2016-05-11T18:42:26.467Z,1462992146.467 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2016-05-11T18:42:26.468Z,1462992146.468 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4037C4E0 2016-05-11T18:42:26.469Z,1462992146.469 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 4028 2016-05-11T18:42:26.472Z,1462992146.472 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2016-05-11T18:42:26.483Z,1462992146.483 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2016-05-11T18:42:26.484Z,1462992146.484 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 403AC4E0 2016-05-11T18:42:26.485Z,1462992146.485 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 4029 2016-05-11T18:42:26.485Z,1462992146.485 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2016-05-11T18:42:26.486Z,1462992146.486 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403DC4E0 2016-05-11T18:42:26.487Z,1462992146.487 [logger ThreadHandler](INFO): Protected caller Thread ID is 4030 2016-05-11T18:42:26.489Z,1462992146.489 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2016-05-11T18:42:26.489Z,1462992146.489 [Supervisor](INFO): Looking for Config files in directory: Config/ 2016-05-11T18:42:26.491Z,1462992146.491 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2016-05-11T18:42:26.832Z,1462992146.832 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2016-05-11T18:42:26.832Z,1462992146.832 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2016-05-11T18:42:26.997Z,1462992146.997 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2016-05-11T18:42:26.998Z,1462992146.998 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2016-05-11T18:42:27.123Z,1462992147.123 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2016-05-11T18:42:27.123Z,1462992147.123 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2016-05-11T18:42:27.253Z,1462992147.253 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2016-05-11T18:42:27.254Z,1462992147.254 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2016-05-11T18:42:27.339Z,1462992147.339 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2016-05-11T18:42:27.528Z,1462992147.528 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2016-05-11T18:42:27.528Z,1462992147.528 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2016-05-11T18:42:27.613Z,1462992147.613 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2016-05-11T18:42:27.614Z,1462992147.614 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2016-05-11T18:42:27.885Z,1462992147.885 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2016-05-11T18:42:27.886Z,1462992147.886 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2016-05-11T18:42:28.223Z,1462992148.223 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2016-05-11T18:42:28.223Z,1462992148.223 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2016-05-11T18:42:28.522Z,1462992148.522 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2016-05-11T18:42:28.523Z,1462992148.523 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2016-05-11T18:42:29.039Z,1462992149.039 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2016-05-11T18:42:29.040Z,1462992149.040 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2016-05-11T18:42:29.238Z,1462992149.238 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2016-05-11T18:42:29.238Z,1462992149.238 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2016-05-11T18:42:29.340Z,1462992149.340 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2016-05-11T18:42:29.341Z,1462992149.341 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2016-05-11T18:42:29.769Z,1462992149.769 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2016-05-11T18:42:29.770Z,1462992149.770 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2016-05-11T18:42:29.880Z,1462992149.880 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2016-05-11T18:42:29.882Z,1462992149.882 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/ 2016-05-11T18:42:29.883Z,1462992149.883 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg 2016-05-11T18:42:30.120Z,1462992150.120 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2016-05-11T18:42:30.121Z,1462992150.121 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg 2016-05-11T18:42:30.236Z,1462992150.236 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg 2016-05-11T18:42:30.333Z,1462992150.333 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg 2016-05-11T18:42:30.429Z,1462992150.429 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg 2016-05-11T18:42:30.519Z,1462992150.519 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg 2016-05-11T18:42:30.663Z,1462992150.663 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg 2016-05-11T18:42:30.821Z,1462992150.821 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg 2016-05-11T18:42:30.923Z,1462992150.923 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg 2016-05-11T18:42:31.004Z,1462992151.004 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg 2016-05-11T18:42:31.093Z,1462992151.093 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg 2016-05-11T18:42:31.269Z,1462992151.269 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/root/ 2016-05-11T18:42:31.269Z,1462992151.269 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2016-05-11T18:42:31.276Z,1462992151.276 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2016-05-11T18:42:31.390Z,1462992151.390 [SBIT](DEBUG): Construct Startup Built In Test. 2016-05-11T18:42:31.420Z,1462992151.420 [SBIT] Loaded 2016-05-11T18:42:31.420Z,1462992151.420 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2016-05-11T18:42:31.421Z,1462992151.421 [IBIT](DEBUG): Construct Initiated Built In Test. 2016-05-11T18:42:31.449Z,1462992151.449 [IBIT] Loaded 2016-05-11T18:42:31.449Z,1462992151.449 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2016-05-11T18:42:31.451Z,1462992151.451 [CBIT](DEBUG): Construct Continuous Built In Test. 2016-05-11T18:42:31.588Z,1462992151.588 [CBIT] Loaded 2016-05-11T18:42:31.589Z,1462992151.589 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2016-05-11T18:42:31.589Z,1462992151.589 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2016-05-11T18:42:31.590Z,1462992151.590 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2016-05-11T18:42:31.636Z,1462992151.636 [VerticalControl](DEBUG): Construct VerticalControl. 2016-05-11T18:42:31.736Z,1462992151.736 [VerticalControl] Loaded 2016-05-11T18:42:31.736Z,1462992151.736 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2016-05-11T18:42:31.737Z,1462992151.737 [HorizontalControl](DEBUG): Construct HorizontalControl. 2016-05-11T18:42:31.799Z,1462992151.799 [HorizontalControl] Loaded 2016-05-11T18:42:31.799Z,1462992151.799 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2016-05-11T18:42:31.800Z,1462992151.800 [SpeedControl](DEBUG): Construct SpeedControl. 2016-05-11T18:42:31.805Z,1462992151.805 [SpeedControl] Loaded 2016-05-11T18:42:31.806Z,1462992151.806 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2016-05-11T18:42:31.806Z,1462992151.806 [LoopControl](DEBUG): Construct LoopControl. 2016-05-11T18:42:31.807Z,1462992151.807 [LoopControl] Loaded 2016-05-11T18:42:31.807Z,1462992151.807 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2016-05-11T18:42:31.807Z,1462992151.807 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2016-05-11T18:42:31.808Z,1462992151.808 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2016-05-11T18:42:31.830Z,1462992151.830 [DepthRateCalculator] Loaded 2016-05-11T18:42:31.830Z,1462992151.830 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2016-05-11T18:42:31.836Z,1462992151.836 [PitchRateCalculator] Loaded 2016-05-11T18:42:31.836Z,1462992151.836 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2016-05-11T18:42:31.847Z,1462992151.847 [SpeedCalculator] Loaded 2016-05-11T18:42:31.847Z,1462992151.847 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2016-05-11T18:42:31.863Z,1462992151.863 [TempGradientCalculator] Loaded 2016-05-11T18:42:31.864Z,1462992151.864 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2016-05-11T18:42:31.880Z,1462992151.880 [VerticalTemperatureHomogeneityIndexCalculator] Loaded 2016-05-11T18:42:31.880Z,1462992151.880 [ComponentRegistry](DEBUG): SyncComponent "VerticalTemperatureHomogeneityIndexCalculator" handled in the control thread. 2016-05-11T18:42:31.885Z,1462992151.885 [YawRateCalculator] Loaded 2016-05-11T18:42:31.885Z,1462992151.885 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2016-05-11T18:42:31.886Z,1462992151.886 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2016-05-11T18:42:31.886Z,1462992151.886 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2016-05-11T18:42:31.957Z,1462992151.957 [StratificationFrontDetector](INFO): threshold set to: 0.399988 degC 2016-05-11T18:42:31.958Z,1462992151.958 [StratificationFrontDetector](DEBUG): (re)initializing 2016-05-11T18:42:31.958Z,1462992151.958 [StratificationFrontDetector] Loaded 2016-05-11T18:42:31.958Z,1462992151.958 [ComponentRegistry](DEBUG): SyncComponent "StratificationFrontDetector" handled in the control thread. 2016-05-11T18:42:31.959Z,1462992151.959 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2016-05-11T18:42:31.959Z,1462992151.959 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2016-05-11T18:42:32.171Z,1462992152.171 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2016-05-11T18:42:32.171Z,1462992152.171 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2016-05-11T18:42:32.260Z,1462992152.260 [DeadReckonUsingSpeedCalculator] Loaded 2016-05-11T18:42:32.260Z,1462992152.260 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread. 2016-05-11T18:42:32.277Z,1462992152.277 [NavChart] Loaded 2016-05-11T18:42:32.278Z,1462992152.278 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2016-05-11T18:42:32.282Z,1462992152.282 [UniversalFixResidualReporter] Loaded 2016-05-11T18:42:32.282Z,1462992152.282 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2016-05-11T18:42:32.282Z,1462992152.282 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2016-05-11T18:42:32.283Z,1462992152.283 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2016-05-11T18:42:32.289Z,1462992152.289 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2016-05-11T18:42:32.289Z,1462992152.289 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2016-05-11T18:42:32.466Z,1462992152.466 [Aanderaa_O2] Loaded 2016-05-11T18:42:32.466Z,1462992152.466 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread. 2016-05-11T18:42:32.541Z,1462992152.541 [CTD_NeilBrown] Loaded 2016-05-11T18:42:32.541Z,1462992152.541 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread. 2016-05-11T18:42:32.542Z,1462992152.542 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 4059E4E0 2016-05-11T18:42:32.542Z,1462992152.542 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 4109 2016-05-11T18:42:32.545Z,1462992152.545 [ESPComponent](CRITICAL): No configuration setting for: ESPComponent.espSimulator 2016-05-11T18:42:32.551Z,1462992152.551 [ESPComponent](CRITICAL): No configuration setting for: ESPComponent.stopCompleteTimeout 2016-05-11T18:42:32.563Z,1462992152.563 [ESPComponent] Loaded 2016-05-11T18:42:32.563Z,1462992152.563 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread. 2016-05-11T18:42:32.577Z,1462992152.577 [PAR_Licor] Loaded 2016-05-11T18:42:32.578Z,1462992152.578 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2016-05-11T18:42:32.628Z,1462992152.628 [WetLabsBB2FL] Loaded 2016-05-11T18:42:32.628Z,1462992152.628 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2016-05-11T18:42:32.629Z,1462992152.629 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 405CE4E0 2016-05-11T18:42:32.629Z,1462992152.629 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 4110 2016-05-11T18:42:32.630Z,1462992152.630 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2016-05-11T18:42:32.631Z,1462992152.631 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2016-05-11T18:42:32.885Z,1462992152.885 [AcousticModem_Benthos_ATM900] Loaded 2016-05-11T18:42:32.885Z,1462992152.885 [ComponentRegistry](DEBUG): SyncComponent "AcousticModem_Benthos_ATM900" handled in the control thread. 2016-05-11T18:42:32.960Z,1462992152.960 [DataOverHttps] Loaded 2016-05-11T18:42:32.960Z,1462992152.960 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread. 2016-05-11T18:42:32.973Z,1462992152.973 [Depth_Keller] Loaded 2016-05-11T18:42:32.973Z,1462992152.973 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2016-05-11T18:42:32.978Z,1462992152.978 [DropWeight] Loaded 2016-05-11T18:42:32.979Z,1462992152.979 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2016-05-11T18:42:33.069Z,1462992153.069 [NAL9602] Loaded 2016-05-11T18:42:33.069Z,1462992153.069 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2016-05-11T18:42:33.110Z,1462992153.110 [Onboard] Loaded 2016-05-11T18:42:33.110Z,1462992153.110 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2016-05-11T18:42:33.117Z,1462992153.117 [Radio_Surface] Loaded 2016-05-11T18:42:33.118Z,1462992153.118 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2016-05-11T18:42:33.119Z,1462992153.119 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409DE4E0 2016-05-11T18:42:33.119Z,1462992153.119 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 4111 2016-05-11T18:42:33.167Z,1462992153.167 [PNI_TCM] Loaded 2016-05-11T18:42:33.167Z,1462992153.167 [ComponentRegistry](DEBUG): SyncComponent "PNI_TCM" handled in the control thread. 2016-05-11T18:42:33.346Z,1462992153.346 [Rowe_600] Loaded 2016-05-11T18:42:33.346Z,1462992153.346 [ComponentRegistry](DEBUG): Component "Rowe_600" handled in its own thread. 2016-05-11T18:42:33.347Z,1462992153.347 [Rowe_600 ThreadHandler](DEBUG): Created PCaller Thread at 40A0E4E0 2016-05-11T18:42:33.348Z,1462992153.348 [Rowe_600 ThreadHandler](INFO): Protected caller Thread ID is 4112 2016-05-11T18:42:33.363Z,1462992153.363 [Rowe_600LCM] Loaded 2016-05-11T18:42:33.364Z,1462992153.364 [ComponentRegistry](DEBUG): Component "Rowe_600LCM" handled in its own thread. 2016-05-11T18:42:33.365Z,1462992153.365 [Rowe_600LCM ThreadHandler](DEBUG): Created PCaller Thread at 40A3E4E0 2016-05-11T18:42:33.365Z,1462992153.365 [Rowe_600LCM ThreadHandler](INFO): Protected caller Thread ID is 4113 2016-05-11T18:42:35.198Z,1462992155.198 [BPC1] Loaded 2016-05-11T18:42:35.198Z,1462992155.198 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2016-05-11T18:42:35.199Z,1462992155.199 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2016-05-11T18:42:35.199Z,1462992155.199 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2016-05-11T18:42:35.293Z,1462992155.293 [BuoyancyServo] Loaded 2016-05-11T18:42:35.293Z,1462992155.293 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2016-05-11T18:42:35.305Z,1462992155.305 [ElevatorServo] Loaded 2016-05-11T18:42:35.305Z,1462992155.305 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2016-05-11T18:42:35.317Z,1462992155.317 [MassServo] Loaded 2016-05-11T18:42:35.317Z,1462992155.317 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2016-05-11T18:42:35.329Z,1462992155.329 [RudderServo] Loaded 2016-05-11T18:42:35.329Z,1462992155.329 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2016-05-11T18:42:35.340Z,1462992155.340 [ThrusterServo] Loaded 2016-05-11T18:42:35.340Z,1462992155.340 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2016-05-11T18:42:35.341Z,1462992155.341 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2016-05-11T18:42:35.341Z,1462992155.341 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2016-05-11T18:42:35.437Z,1462992155.437 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2016-05-11T18:42:35.437Z,1462992155.437 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2016-05-11T18:42:35.460Z,1462992155.460 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2016-05-11T18:42:35.464Z,1462992155.464 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2016-05-11T18:42:35.465Z,1462992155.465 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2016-05-11T18:42:35.472Z,1462992155.472 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2016-05-11T18:42:35.473Z,1462992155.473 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40AEC4E0 2016-05-11T18:42:35.473Z,1462992155.473 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 4114 2016-05-11T18:42:35.478Z,1462992155.478 [Supervisor](INFO): Main Thread ID is 4026 2016-05-11T18:42:35.478Z,1462992155.478 [Supervisor](DEBUG): Running supervisor. 2016-05-11T18:42:35.479Z,1462992155.479 [CommandLine ThreadHandler](INFO): Handler Thread ID is 4115 2016-05-11T18:42:35.482Z,1462992155.482 [controlThread ThreadHandler](INFO): Handler Thread ID is 4116 2016-05-11T18:42:35.482Z,1462992155.482 [controlThread](DEBUG): Initializing ControlThread 2016-05-11T18:42:35.483Z,1462992155.483 [SBIT](INFO): Initialize SBIT Component. 2016-05-11T18:42:35.484Z,1462992155.484 [SBIT](IMPORTANT): git: 2015-11-13-11-g036008f 2016-05-11T18:42:35.484Z,1462992155.484 [SBIT](INFO): git hash: 036008fb27dd1443c9c6898c567944386f491f02 2016-05-11T18:42:35.484Z,1462992155.484 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2016-05-11T18:42:35.484Z,1462992155.484 [SBIT](IMPORTANT): Kernel Version:#639 PREEMPT Wed Mar 12 12:53:33 PDT 2014 2016-05-11T18:42:35.485Z,1462992155.485 [SBIT](INFO): Beginning SBIT in 35.000000 seconds. 2016-05-11T18:42:35.486Z,1462992155.486 [IBIT](INFO): Initialize IBIT Component. 2016-05-11T18:42:35.487Z,1462992155.487 [CBIT](DEBUG): Initialize CBIT Component. 2016-05-11T18:42:35.487Z,1462992155.487 [CBIT](CRITICAL): LAST REBOOT DUE TO WATCHDOG TIMER RESET. 2016-05-11T18:42:35.488Z,1462992155.488 [logger ThreadHandler](INFO): Handler Thread ID is 4117 2016-05-11T18:42:35.508Z,1462992155.508 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 4118 2016-05-11T18:42:35.509Z,1462992155.509 [CTD_NeilBrown](INFO): Powering down 2016-05-11T18:42:35.513Z,1462992155.513 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2016-05-11T18:42:35.514Z,1462992155.514 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2016-05-11T18:42:35.515Z,1462992155.515 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2016-05-11T18:42:35.516Z,1462992155.516 [LoopControl](DEBUG): Initialize LoopControlComponent. 2016-05-11T18:42:35.520Z,1462992155.520 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2016-05-11T18:42:35.520Z,1462992155.520 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2016-05-11T18:42:35.521Z,1462992155.521 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2016-05-11T18:42:35.521Z,1462992155.521 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2016-05-11T18:42:35.522Z,1462992155.522 [VerticalTemperatureHomogeneityIndexCalculator](DEBUG): (re)initializing 2016-05-11T18:42:35.522Z,1462992155.522 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2016-05-11T18:42:35.523Z,1462992155.523 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2016-05-11T18:42:35.524Z,1462992155.524 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s. 2016-05-11T18:42:35.524Z,1462992155.524 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s. 2016-05-11T18:42:35.525Z,1462992155.525 [NavChart](DEBUG): Initialize NavChart Navigation. 2016-05-11T18:42:35.525Z,1462992155.525 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2016-05-11T18:42:35.540Z,1462992155.540 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2016-05-11T18:42:35.565Z,1462992155.565 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 4119 2016-05-11T18:42:35.566Z,1462992155.566 [WetLabsBB2FL](INFO): Powering down 2016-05-11T18:42:35.590Z,1462992155.590 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2016-05-11T18:42:35.609Z,1462992155.609 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 4120 2016-05-11T18:42:35.615Z,1462992155.615 [Radio_Surface](INFO): Powering up 2016-05-11T18:42:35.621Z,1462992155.621 [MissionManager](DEBUG): 2016-05-11T18:42:35.622Z,1462992155.622 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2016-05-11T18:42:35.625Z,1462992155.625 [Rowe_600 ThreadHandler](INFO): Handler Thread ID is 4121 2016-05-11T18:42:35.641Z,1462992155.641 [Rowe_600LCM ThreadHandler](INFO): Handler Thread ID is 4122 2016-05-11T18:42:35.641Z,1462992155.641 [Rowe_600LCM](INFO): stop 2016-05-11T18:42:35.641Z,1462992155.641 [Rowe_600LCM](INFO): uninitialize 2016-05-11T18:42:35.641Z,1462992155.641 [Rowe_600LCM](INFO): Powering down 2016-05-11T18:42:35.685Z,1462992155.685 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 4124 2016-05-11T18:42:35.689Z,1462992155.689 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources/ElectronicNavigationCharts 2016-05-11T18:42:35.690Z,1462992155.690 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2016-05-11T18:42:35.690Z,1462992155.690 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2016-05-11T18:42:35.690Z,1462992155.690 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2016-05-11T18:42:35.690Z,1462992155.690 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2016-05-11T18:42:35.690Z,1462992155.690 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2016-05-11T18:42:35.691Z,1462992155.691 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2016-05-11T18:42:35.691Z,1462992155.691 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2016-05-11T18:42:35.691Z,1462992155.691 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2016-05-11T18:42:35.734Z,1462992155.734 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2016-05-11T18:42:35.735Z,1462992155.735 [Default:A.Wait](DEBUG): Construct Wait. 2016-05-11T18:42:35.737Z,1462992155.737 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2016-05-11T18:42:35.788Z,1462992155.788 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2016-05-11T18:42:35.815Z,1462992155.815 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2016-05-11T18:42:35.833Z,1462992155.833 [Default:E.Execute](DEBUG): Construct Execute. 2016-05-11T18:42:35.861Z,1462992155.861 [MissionManager](DEBUG): 0 Wait a moment to see if the scheduler starts a new mission before starting to actually run Default. 13 Burn 300 Dropped weight due to communications timeout. 5 Default mission has been running for Restarting logs and Default mission. restart logs 2016-05-11T18:42:35.867Z,1462992155.867 [controlThread](DEBUG): Component order: CycleStarter,Aanderaa_O2,ESPComponent,PAR_Licor,AcousticModem_Benthos_ATM900,DataOverHttps,Depth_Keller,DropWeight,NAL9602,Onboard,PNI_TCM,BPC1,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,VerticalTemperatureHomogeneityIndexCalculator,YawRateCalculator,StratificationFrontDetector,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2016-05-11T18:42:35.901Z,1462992155.901 [Rowe_600](INFO): Powering down 2016-05-11T18:42:35.980Z,1462992155.980 [ESPComponent](INFO): powering down ESP 2016-05-11T18:42:36.032Z,1462992156.032 [Rowe_600LCM](INFO): Stopping 2016-05-11T18:42:36.033Z,1462992156.033 [Rowe_600LCM](INFO): Stopped 2016-05-11T18:42:36.033Z,1462992156.033 [Rowe_600LCM](INFO): Data requested. STOPPED ==> START 2016-05-11T18:42:36.033Z,1462992156.033 [Rowe_600LCM](INFO): start 2016-05-11T18:42:36.033Z,1462992156.033 [Rowe_600LCM](INFO): Initializing 2016-05-11T18:42:36.034Z,1462992156.034 [Rowe_600LCM](INFO): Checking LCM 2016-05-11T18:42:36.034Z,1462992156.034 [Rowe_600LCM](INFO): LCM OK 2016-05-11T18:42:36.034Z,1462992156.034 [Rowe_600LCM](INFO): Powering up 2016-05-11T18:42:36.364Z,1462992156.364 [AcousticModem_Benthos_ATM900](INFO): Powering up 2016-05-11T18:42:36.364Z,1462992156.364 [AcousticModem_Benthos_ATM900](DEBUG): Initializing AcousticModem_Benthos_ATM900. 2016-05-11T18:42:36.438Z,1462992156.438 [Rowe_600LCM](INFO): starting 2016-05-11T18:42:36.842Z,1462992156.842 [Rowe_600LCM](INFO): starting 2016-05-11T18:42:36.987Z,1462992156.987 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2016-05-11T18:42:37.123Z,1462992157.123 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2016-05-11T18:42:37.131Z,1462992157.131 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2016-05-11T18:42:37.167Z,1462992157.167 [ElevatorServo](DEBUG): Initializing EZServoServo. 2016-05-11T18:42:37.176Z,1462992157.176 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2016-05-11T18:42:37.215Z,1462992157.215 [MassServo](DEBUG): Initializing EZServoServo. 2016-05-11T18:42:37.223Z,1462992157.223 [MassServo](DEBUG): Initializing MassServo. 2016-05-11T18:42:37.230Z,1462992157.230 [RudderServo](DEBUG): Initializing EZServoServo. 2016-05-11T18:42:37.235Z,1462992157.235 [RudderServo](DEBUG): Initializing RudderServo. 2016-05-11T18:42:37.247Z,1462992157.247 [Rowe_600LCM](INFO): starting 2016-05-11T18:42:37.257Z,1462992157.257 [ThrusterServo](DEBUG): Initializing EZServoServo. 2016-05-11T18:42:37.271Z,1462992157.271 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2016-05-11T18:42:37.328Z,1462992157.328 [CommandLine](FAULT): Scheduling is paused 2016-05-11T18:42:37.516Z,1462992157.516 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2016-05-11T18:42:37.648Z,1462992157.648 [Rowe_600LCM](INFO): starting 2016-05-11T18:42:37.819Z,1462992157.819 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2016-05-11T18:42:38.052Z,1462992158.052 [Rowe_600LCM](INFO): starting 2016-05-11T18:42:38.238Z,1462992158.238 [NAL9602](INFO): Powering up NAL9602 2016-05-11T18:42:38.301Z,1462992158.301 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2016-05-11T18:42:38.453Z,1462992158.453 [Rowe_600LCM](INFO): starting 2016-05-11T18:42:38.753Z,1462992158.753 [Aanderaa_O2](INFO): Powering down 2016-05-11T18:42:38.858Z,1462992158.858 [Rowe_600LCM](INFO): starting 2016-05-11T18:42:38.925Z,1462992158.925 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2016-05-11T18:42:39.079Z,1462992159.079 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2016-05-11T18:42:39.262Z,1462992159.262 [Rowe_600LCM](INFO): starting 2016-05-11T18:42:39.458Z,1462992159.458 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2016-05-11T18:42:39.667Z,1462992159.667 [Rowe_600LCM](INFO): starting 2016-05-11T18:42:39.922Z,1462992159.922 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2016-05-11T18:42:40.072Z,1462992160.072 [Rowe_600LCM](INFO): starting 2016-05-11T18:42:40.382Z,1462992160.382 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface 2016-05-11T18:42:40.592Z,1462992160.592 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:./bin/roweadcp -dev /dev/ttyA1 -b 115200 >& adcpLog.log & 2016-05-11T18:42:40.678Z,1462992160.678 [Rowe_600LCM](INFO): LCM subscribed to channel:rti.adcp_dvl.bottom_track 2016-05-11T18:42:41.081Z,1462992161.081 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:42:41.874Z,1462992161.874 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:42:42.668Z,1462992162.668 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:42:43.461Z,1462992163.461 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:42:43.878Z,1462992163.878 [AcousticModem_Benthos_ATM900](DEBUG): 2016-05-11T18:42:44.254Z,1462992164.254 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:42:45.048Z,1462992165.048 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:42:45.074Z,1462992165.074 [AcousticModem_Benthos_ATM900](DEBUG): Teledyne Benthos ATM-900 Series OEM w/burn wire 2016-05-11T18:42:45.075Z,1462992165.075 [AcousticModem_Benthos_ATM900](DEBUG): MF Frequency Band 2016-05-11T18:42:45.076Z,1462992165.076 [AcousticModem_Benthos_ATM900](DEBUG): Standard version 8.6.3 2016-05-11T18:42:45.840Z,1462992165.840 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:42:45.882Z,1462992165.882 [AcousticModem_Benthos_ATM900](DEBUG): May 11 2016 18:35:17 2016-05-11T18:42:46.634Z,1462992166.634 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:42:47.423Z,1462992167.423 [AcousticModem_Benthos_ATM900](INFO): entering command mode 2016-05-11T18:42:47.427Z,1462992167.427 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:42:48.220Z,1462992168.220 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:42:48.229Z,1462992168.229 [AcousticModem_Benthos_ATM900](DEBUG): checking for command mode acknowledgment 2016-05-11T18:42:48.230Z,1462992168.230 [AcousticModem_Benthos_ATM900](DEBUG): read user prompt 1: user:1> 2016-05-11T18:42:48.230Z,1462992168.230 [AcousticModem_Benthos_ATM900](INFO): command mode acknowledged 2016-05-11T18:42:48.708Z,1462992168.708 [AcousticModem_Benthos_ATM900](INFO): setting local address to 3 2016-05-11T18:42:49.013Z,1462992169.013 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:42:49.014Z,1462992169.014 [Rowe_600LCM](IMPORTANT): valid:0 2016-05-11T18:42:49.015Z,1462992169.015 [Rowe_600LCM](IMPORTANT): range0:nan 2016-05-11T18:42:49.015Z,1462992169.015 [Rowe_600LCM](IMPORTANT): range1:nan 2016-05-11T18:42:49.016Z,1462992169.016 [Rowe_600LCM](IMPORTANT): range2:nan 2016-05-11T18:42:49.016Z,1462992169.016 [Rowe_600LCM](IMPORTANT): range3:nan 2016-05-11T18:42:49.151Z,1462992169.151 [AcousticModem_Benthos_ATM900](DEBUG): checking for local address setting acknowledgment 2016-05-11T18:42:49.172Z,1462992169.172 [AcousticModem_Benthos_ATM900](INFO): set local address to 3 2016-05-11T18:42:49.420Z,1462992169.420 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:42:49.480Z,1462992169.480 [NAL9602](INFO): NAL9602 initialized 2016-05-11T18:42:49.564Z,1462992169.564 [Rowe_600LCM](IMPORTANT): valid:0 2016-05-11T18:42:49.564Z,1462992169.564 [Rowe_600LCM](IMPORTANT): range0:nan 2016-05-11T18:42:49.565Z,1462992169.565 [Rowe_600LCM](IMPORTANT): range1:nan 2016-05-11T18:42:49.565Z,1462992169.565 [Rowe_600LCM](IMPORTANT): range2:nan 2016-05-11T18:42:49.565Z,1462992169.565 [Rowe_600LCM](IMPORTANT): range3:nan 2016-05-11T18:42:49.658Z,1462992169.658 [AcousticModem_Benthos_ATM900](DEBUG): read user prompt 2: user:2> 2016-05-11T18:42:49.969Z,1462992169.969 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:42:50.767Z,1462992170.767 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:42:51.564Z,1462992171.564 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:42:52.359Z,1462992172.359 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:42:52.469Z,1462992172.469 [Rowe_600LCM](IMPORTANT): valid:0 2016-05-11T18:42:52.469Z,1462992172.469 [Rowe_600LCM](IMPORTANT): range0:nan 2016-05-11T18:42:52.469Z,1462992172.469 [Rowe_600LCM](IMPORTANT): range1:nan 2016-05-11T18:42:52.470Z,1462992172.470 [Rowe_600LCM](IMPORTANT): range2:nan 2016-05-11T18:42:52.470Z,1462992172.470 [Rowe_600LCM](IMPORTANT): range3:nan 2016-05-11T18:42:52.874Z,1462992172.874 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:42:53.671Z,1462992173.671 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:42:54.466Z,1462992174.466 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:42:55.277Z,1462992175.277 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:42:56.072Z,1462992176.072 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:42:56.249Z,1462992176.249 [Rowe_600LCM](IMPORTANT): valid:0 2016-05-11T18:42:56.250Z,1462992176.250 [Rowe_600LCM](IMPORTANT): range0:nan 2016-05-11T18:42:56.250Z,1462992176.250 [Rowe_600LCM](IMPORTANT): range1:nan 2016-05-11T18:42:56.250Z,1462992176.250 [Rowe_600LCM](IMPORTANT): range2:nan 2016-05-11T18:42:56.251Z,1462992176.251 [Rowe_600LCM](IMPORTANT): range3:nan 2016-05-11T18:42:56.655Z,1462992176.655 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:42:57.449Z,1462992177.449 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:42:58.268Z,1462992178.268 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:42:59.088Z,1462992179.088 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:42:59.882Z,1462992179.882 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:42:59.883Z,1462992179.883 [Rowe_600LCM](IMPORTANT): valid:0 2016-05-11T18:42:59.883Z,1462992179.883 [Rowe_600LCM](IMPORTANT): range0:nan 2016-05-11T18:42:59.884Z,1462992179.884 [Rowe_600LCM](IMPORTANT): range1:nan 2016-05-11T18:42:59.884Z,1462992179.884 [Rowe_600LCM](IMPORTANT): range2:nan 2016-05-11T18:42:59.884Z,1462992179.884 [Rowe_600LCM](IMPORTANT): range3:nan 2016-05-11T18:43:00.289Z,1462992180.289 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:43:00.603Z,1462992180.603 [Rowe_600LCM](IMPORTANT): valid:0 2016-05-11T18:43:00.604Z,1462992180.604 [Rowe_600LCM](IMPORTANT): range0:nan 2016-05-11T18:43:00.604Z,1462992180.604 [Rowe_600LCM](IMPORTANT): range1:nan 2016-05-11T18:43:00.604Z,1462992180.604 [Rowe_600LCM](IMPORTANT): range2:nan 2016-05-11T18:43:00.605Z,1462992180.605 [Rowe_600LCM](IMPORTANT): range3:nan 2016-05-11T18:43:01.014Z,1462992181.014 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:43:01.811Z,1462992181.811 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:43:02.616Z,1462992182.616 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:43:03.412Z,1462992183.412 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:43:04.209Z,1462992184.209 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:43:04.210Z,1462992184.210 [Rowe_600LCM](IMPORTANT): valid:0 2016-05-11T18:43:04.210Z,1462992184.210 [Rowe_600LCM](IMPORTANT): range0:nan 2016-05-11T18:43:04.210Z,1462992184.210 [Rowe_600LCM](IMPORTANT): range1:nan 2016-05-11T18:43:04.211Z,1462992184.211 [Rowe_600LCM](IMPORTANT): range2:nan 2016-05-11T18:43:04.211Z,1462992184.211 [Rowe_600LCM](IMPORTANT): range3:nan 2016-05-11T18:43:04.616Z,1462992184.616 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:43:05.409Z,1462992185.409 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:43:06.206Z,1462992186.206 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:43:06.997Z,1462992186.997 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:43:07.795Z,1462992187.795 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:43:08.591Z,1462992188.591 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:43:09.391Z,1462992189.391 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:43:10.182Z,1462992190.182 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:43:10.925Z,1462992190.925 [SBIT](IMPORTANT): Beginning Startup BIT 2016-05-11T18:43:10.928Z,1462992190.928 [CBIT](IMPORTANT): Beginning GF scan 2016-05-11T18:43:10.975Z,1462992190.975 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:43:10.976Z,1462992190.976 [Rowe_600LCM](IMPORTANT): valid:0 2016-05-11T18:43:10.976Z,1462992190.976 [Rowe_600LCM](IMPORTANT): range0:nan 2016-05-11T18:43:10.977Z,1462992190.977 [Rowe_600LCM](IMPORTANT): range1:nan 2016-05-11T18:43:10.977Z,1462992190.977 [Rowe_600LCM](IMPORTANT): range2:nan 2016-05-11T18:43:10.977Z,1462992190.977 [Rowe_600LCM](IMPORTANT): range3:nan 2016-05-11T18:43:11.380Z,1462992191.380 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:43:12.173Z,1462992192.173 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:43:12.966Z,1462992192.966 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:43:13.768Z,1462992193.768 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:43:14.565Z,1462992194.565 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:43:14.566Z,1462992194.566 [Rowe_600LCM](IMPORTANT): valid:0 2016-05-11T18:43:14.566Z,1462992194.566 [Rowe_600LCM](IMPORTANT): range0:nan 2016-05-11T18:43:14.567Z,1462992194.567 [Rowe_600LCM](IMPORTANT): range1:nan 2016-05-11T18:43:14.567Z,1462992194.567 [Rowe_600LCM](IMPORTANT): range2:nan 2016-05-11T18:43:14.567Z,1462992194.567 [Rowe_600LCM](IMPORTANT): range3:nan 2016-05-11T18:43:14.972Z,1462992194.972 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:43:15.769Z,1462992195.769 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:43:16.578Z,1462992196.578 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:43:17.376Z,1462992197.376 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:43:18.171Z,1462992198.171 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:43:18.968Z,1462992198.968 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:43:18.979Z,1462992198.979 [Rowe_600LCM](IMPORTANT): valid:0 2016-05-11T18:43:18.979Z,1462992198.979 [Rowe_600LCM](IMPORTANT): range0:nan 2016-05-11T18:43:18.980Z,1462992198.980 [Rowe_600LCM](IMPORTANT): range1:nan 2016-05-11T18:43:18.981Z,1462992198.981 [Rowe_600LCM](IMPORTANT): range2:nan 2016-05-11T18:43:18.983Z,1462992198.983 [Rowe_600LCM](IMPORTANT): range3:nan 2016-05-11T18:43:19.390Z,1462992199.390 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:43:20.188Z,1462992200.188 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:43:20.991Z,1462992200.991 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:43:21.792Z,1462992201.792 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:43:22.590Z,1462992202.590 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:43:22.590Z,1462992202.590 [Rowe_600LCM](IMPORTANT): valid:0 2016-05-11T18:43:22.591Z,1462992202.591 [Rowe_600LCM](IMPORTANT): range0:nan 2016-05-11T18:43:22.591Z,1462992202.591 [Rowe_600LCM](IMPORTANT): range1:nan 2016-05-11T18:43:22.591Z,1462992202.591 [Rowe_600LCM](IMPORTANT): range2:nan 2016-05-11T18:43:22.592Z,1462992202.592 [Rowe_600LCM](IMPORTANT): range3:nan 2016-05-11T18:43:22.996Z,1462992202.996 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:43:23.790Z,1462992203.790 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:43:24.587Z,1462992204.587 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:43:25.378Z,1462992205.378 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:43:26.171Z,1462992206.171 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:43:26.966Z,1462992206.966 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:43:27.773Z,1462992207.773 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:43:28.572Z,1462992208.572 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:43:29.402Z,1462992209.402 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:43:30.195Z,1462992210.195 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:43:30.992Z,1462992210.992 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:43:31.786Z,1462992211.786 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:43:32.581Z,1462992212.581 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:43:33.374Z,1462992213.374 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:43:34.169Z,1462992214.169 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:43:34.971Z,1462992214.971 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:43:35.772Z,1462992215.772 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:43:36.565Z,1462992216.565 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:43:36.569Z,1462992216.569 [Rowe_600LCM](IMPORTANT): valid:0 2016-05-11T18:43:36.571Z,1462992216.571 [Rowe_600LCM](IMPORTANT): range0:nan 2016-05-11T18:43:36.573Z,1462992216.573 [Rowe_600LCM](IMPORTANT): range1:nan 2016-05-11T18:43:36.575Z,1462992216.575 [Rowe_600LCM](IMPORTANT): range2:nan 2016-05-11T18:43:36.577Z,1462992216.577 [Rowe_600LCM](IMPORTANT): range3:nan 2016-05-11T18:43:36.980Z,1462992216.980 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:43:37.136Z,1462992217.136 [CBIT](IMPORTANT): No ground fault detected 2016-05-11T18:43:37.669Z,1462992217.669 [CommandLine](IMPORTANT): got command quit 2016-05-11T18:43:37.779Z,1462992217.779 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:43:38.579Z,1462992218.579 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:43:38.689Z,1462992218.689 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2016-05-11T18:43:38.690Z,1462992218.690 [CommandLine ThreadHandler](INFO): Thread cancelled. 2016-05-11T18:43:38.719Z,1462992218.719 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2016-05-11T18:43:38.719Z,1462992218.719 [CommandLine ThreadHandler](INFO): Thread cancelled. 2016-05-11T18:43:38.723Z,1462992218.723 [CommandLine](INFO): Join timeout helper Thread ID is 4139 2016-05-11T18:43:38.747Z,1462992218.747 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2016-05-11T18:43:38.748Z,1462992218.748 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2016-05-11T18:43:38.769Z,1462992218.769 [NavChartDb](INFO): Join timeout helper Thread ID is 4140 2016-05-11T18:43:39.374Z,1462992219.374 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:43:40.172Z,1462992220.172 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:43:40.175Z,1462992220.175 [Rowe_600LCM](IMPORTANT): valid:0 2016-05-11T18:43:40.178Z,1462992220.178 [Rowe_600LCM](IMPORTANT): range0:nan 2016-05-11T18:43:40.180Z,1462992220.180 [Rowe_600LCM](IMPORTANT): range1:nan 2016-05-11T18:43:40.182Z,1462992220.182 [Rowe_600LCM](IMPORTANT): range2:nan 2016-05-11T18:43:40.184Z,1462992220.184 [Rowe_600LCM](IMPORTANT): range3:nan 2016-05-11T18:43:40.589Z,1462992220.589 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:43:41.385Z,1462992221.385 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:43:42.182Z,1462992222.182 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:43:42.975Z,1462992222.975 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:43:43.775Z,1462992223.775 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:43:43.778Z,1462992223.778 [Rowe_600LCM](IMPORTANT): valid:0 2016-05-11T18:43:43.782Z,1462992223.782 [Rowe_600LCM](IMPORTANT): range0:nan 2016-05-11T18:43:43.784Z,1462992223.784 [Rowe_600LCM](IMPORTANT): range1:nan 2016-05-11T18:43:43.785Z,1462992223.785 [Rowe_600LCM](IMPORTANT): range2:nan 2016-05-11T18:43:43.805Z,1462992223.805 [Rowe_600LCM](IMPORTANT): range3:nan 2016-05-11T18:43:44.247Z,1462992224.247 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:43:44.982Z,1462992224.982 [BPC1](ERROR): Failed to receive battery data 2016-05-11T18:43:44.982Z,1462992224.982 [BPC1] Communications Fault, FailCount= 1 2016-05-11T18:43:44.983Z,1462992224.983 [BPC1](ERROR): Communications Fault 2016-05-11T18:43:45.042Z,1462992225.042 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:43:45.311Z,1462992225.311 [CBIT](ERROR): Communications Fault in component: BPC1 2016-05-11T18:43:45.844Z,1462992225.844 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:43:46.637Z,1462992226.637 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:43:47.021Z,1462992227.021 [Rowe_600LCM](IMPORTANT): valid:0 2016-05-11T18:43:47.021Z,1462992227.021 [Rowe_600LCM](IMPORTANT): range0:nan 2016-05-11T18:43:47.022Z,1462992227.022 [Rowe_600LCM](IMPORTANT): range1:nan 2016-05-11T18:43:47.022Z,1462992227.022 [Rowe_600LCM](IMPORTANT): range2:nan 2016-05-11T18:43:47.022Z,1462992227.022 [Rowe_600LCM](IMPORTANT): range3:nan 2016-05-11T18:43:47.075Z,1462992227.075 [CBIT](INFO): Clearing failed state for component BPC1 2016-05-11T18:43:47.075Z,1462992227.075 [BPC1] No Fault, FailCount= 1 2016-05-11T18:43:47.426Z,1462992227.426 [Rowe_600LCM](INFO): Runnable 2016-05-11T18:43:48.171Z,1462992228.171 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2016-05-11T18:43:48.171Z,1462992228.171 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2016-05-11T18:43:48.177Z,1462992228.177 [ComponentRegistry](INFO): Shutting down Rowe_600LCM ThreadHandler 2016-05-11T18:43:48.177Z,1462992228.177 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled. 2016-05-11T18:43:48.177Z,1462992228.177 [Rowe_600LCM](INFO): Join timeout helper Thread ID is 4141 2016-05-11T18:43:48.284Z,1462992228.284 [Rowe_600LCM ThreadHandler](INFO): Uninitializing protected caller thread. 2016-05-11T18:43:48.285Z,1462992228.285 [Rowe_600LCM](INFO): uninitialize 2016-05-11T18:43:48.285Z,1462992228.285 [Rowe_600LCM](INFO): Powering down 2016-05-11T18:43:48.599Z,1462992228.599 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled. 2016-05-11T18:43:48.618Z,1462992228.618 [ComponentRegistry](INFO): Shutting down Rowe_600 ThreadHandler 2016-05-11T18:43:48.618Z,1462992228.618 [Rowe_600 ThreadHandler](INFO): Thread cancelled. 2016-05-11T18:43:48.618Z,1462992228.618 [Rowe_600](INFO): Join timeout helper Thread ID is 4143 2016-05-11T18:43:48.698Z,1462992228.698 [Rowe_600 ThreadHandler](INFO): Uninitializing protected caller thread. 2016-05-11T18:43:48.698Z,1462992228.698 [Rowe_600](INFO): Powering down 2016-05-11T18:43:48.699Z,1462992228.699 [Rowe_600 ThreadHandler](INFO): Thread cancelled. 2016-05-11T18:43:48.706Z,1462992228.706 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2016-05-11T18:43:48.706Z,1462992228.706 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2016-05-11T18:43:48.707Z,1462992228.707 [Radio_Surface](INFO): Join timeout helper Thread ID is 4144 2016-05-11T18:43:48.786Z,1462992228.786 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2016-05-11T18:43:48.786Z,1462992228.786 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2016-05-11T18:43:48.807Z,1462992228.807 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2016-05-11T18:43:48.807Z,1462992228.807 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2016-05-11T18:43:48.807Z,1462992228.807 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 4145 2016-05-11T18:43:48.830Z,1462992228.830 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2016-05-11T18:43:48.830Z,1462992228.830 [WetLabsBB2FL](INFO): Powering down 2016-05-11T18:43:48.831Z,1462992228.831 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2016-05-11T18:43:48.835Z,1462992228.835 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler 2016-05-11T18:43:48.835Z,1462992228.835 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled. 2016-05-11T18:43:48.835Z,1462992228.835 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 4146 2016-05-11T18:43:48.918Z,1462992228.918 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread. 2016-05-11T18:43:48.918Z,1462992228.918 [CTD_NeilBrown](INFO): Powering down 2016-05-11T18:43:48.919Z,1462992228.919 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled. 2016-05-11T18:43:48.923Z,1462992228.923 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2016-05-11T18:43:48.923Z,1462992228.923 [logger ThreadHandler](INFO): Thread cancelled. 2016-05-11T18:43:48.923Z,1462992228.923 [logger](INFO): Join timeout helper Thread ID is 4147 2016-05-11T18:43:48.951Z,1462992228.951 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2016-05-11T18:43:48.951Z,1462992228.951 [logger ThreadHandler](INFO): Thread cancelled. 2016-05-11T18:43:48.971Z,1462992228.971 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2016-05-11T18:43:48.971Z,1462992228.971 [CommandLine ThreadHandler](INFO): Thread cancelled. 2016-05-11T18:43:48.971Z,1462992228.971 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2016-05-11T18:43:48.971Z,1462992228.971 [controlThread ThreadHandler](INFO): Thread cancelled. 2016-05-11T18:43:48.972Z,1462992228.972 [controlThread](INFO): Join timeout helper Thread ID is 4148 2016-05-11T18:43:49.030Z,1462992229.030 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2016-05-11T18:43:49.030Z,1462992229.030 [controlThread](DEBUG): Uninitializing ControlThread 2016-05-11T18:43:49.031Z,1462992229.031 [Aanderaa_O2](INFO): Powering down 2016-05-11T18:43:49.033Z,1462992229.033 [AcousticModem_Benthos_ATM900](INFO): Powering down 2016-05-11T18:43:49.155Z,1462992229.155 [NAL9602](INFO): Powering down 2016-05-11T18:43:49.157Z,1462992229.157 [PNI_TCM](INFO): Powering down 2016-05-11T18:43:49.243Z,1462992229.243 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2016-05-11T18:43:49.245Z,1462992229.245 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2016-05-11T18:43:49.249Z,1462992229.249 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2016-05-11T18:43:49.249Z,1462992229.249 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2016-05-11T18:43:49.249Z,1462992229.249 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2016-05-11T18:43:49.250Z,1462992229.250 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2016-05-11T18:43:49.250Z,1462992229.250 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2016-05-11T18:43:49.250Z,1462992229.250 [BuoyancyServo](INFO): Powering down 2016-05-11T18:43:49.263Z,1462992229.263 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2016-05-11T18:43:49.263Z,1462992229.263 [ElevatorServo](INFO): Powering down 2016-05-11T18:43:49.264Z,1462992229.264 [MassServo](DEBUG): Uninitialize Mass Servo. 2016-05-11T18:43:49.264Z,1462992229.264 [MassServo](INFO): Powering down 2016-05-11T18:43:49.264Z,1462992229.264 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2016-05-11T18:43:49.265Z,1462992229.265 [RudderServo](INFO): Powering down 2016-05-11T18:43:49.265Z,1462992229.265 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2016-05-11T18:43:49.266Z,1462992229.266 [ThrusterServo](INFO): Powering down 2016-05-11T18:43:49.267Z,1462992229.267 [SBIT](DEBUG): Uninitialize SBIT Component. 2016-05-11T18:43:49.267Z,1462992229.267 [IBIT](DEBUG): Uninitialize IBIT Component. 2016-05-11T18:43:49.267Z,1462992229.267 [CBIT](DEBUG): Uninitialize CBIT Component. 2016-05-11T18:43:49.299Z,1462992229.299 [controlThread ThreadHandler](INFO): Thread cancelled. 2016-05-11T18:43:49.356Z,1462992229.356 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2016-05-11T18:43:49.362Z,1462992229.362 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled. 2016-05-11T18:43:49.428Z,1462992229.428 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled. 2016-05-11T18:43:49.481Z,1462992229.481 [Rowe_600 ThreadHandler](INFO): Thread cancelled. 2016-05-11T18:43:49.489Z,1462992229.489 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2016-05-11T18:43:49.539Z,1462992229.539 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2016-05-11T18:43:49.591Z,1462992229.591 [logger ThreadHandler](INFO): Thread cancelled.