2018-11-06T04:38:57.425Z,1541479137.425 [Supervisor](DEBUG): Initializing supervisor.
2018-11-06T04:38:57.428Z,1541479137.428 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2018-11-06T04:38:57.429Z,1541479137.429 [SyncHandler](INFO): Protected caller Thread ID is 893
2018-11-06T04:38:57.430Z,1541479137.430 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2018-11-06T04:38:57.431Z,1541479137.431 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2018-11-06T04:38:57.431Z,1541479137.431 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 894
2018-11-06T04:38:57.434Z,1541479137.434 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2018-11-06T04:38:57.446Z,1541479137.446 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2018-11-06T04:38:57.447Z,1541479137.447 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2018-11-06T04:38:57.448Z,1541479137.448 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 895
2018-11-06T04:38:57.448Z,1541479137.448 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2018-11-06T04:38:57.449Z,1541479137.449 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2018-11-06T04:38:57.450Z,1541479137.450 [logger ThreadHandler](INFO): Protected caller Thread ID is 896
2018-11-06T04:38:57.451Z,1541479137.451 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2018-11-06T04:38:57.452Z,1541479137.452 [Supervisor](INFO): Looking for Config files in directory: Config/
2018-11-06T04:38:57.454Z,1541479137.454 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2018-11-06T04:38:57.787Z,1541479137.787 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2018-11-06T04:38:57.787Z,1541479137.787 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2018-11-06T04:38:57.994Z,1541479137.994 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2018-11-06T04:38:57.994Z,1541479137.994 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2018-11-06T04:38:58.288Z,1541479138.288 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2018-11-06T04:38:58.289Z,1541479138.289 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2018-11-06T04:38:58.432Z,1541479138.432 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2018-11-06T04:38:58.433Z,1541479138.433 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2018-11-06T04:38:58.531Z,1541479138.531 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2018-11-06T04:38:58.531Z,1541479138.531 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2018-11-06T04:38:58.986Z,1541479138.986 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2018-11-06T04:38:58.987Z,1541479138.987 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2018-11-06T04:38:59.445Z,1541479139.445 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2018-11-06T04:38:59.446Z,1541479139.446 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2018-11-06T04:38:59.910Z,1541479139.910 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2018-11-06T04:38:59.910Z,1541479139.910 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2018-11-06T04:39:00.013Z,1541479140.013 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2018-11-06T04:39:00.014Z,1541479140.014 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2018-11-06T04:39:00.109Z,1541479140.109 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2018-11-06T04:39:00.110Z,1541479140.110 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2018-11-06T04:39:00.326Z,1541479140.326 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2018-11-06T04:39:00.326Z,1541479140.326 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2018-11-06T04:39:00.528Z,1541479140.528 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2018-11-06T04:39:00.528Z,1541479140.528 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2018-11-06T04:39:00.877Z,1541479140.877 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2018-11-06T04:39:00.878Z,1541479140.878 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2018-11-06T04:39:01.021Z,1541479141.021 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2018-11-06T04:39:01.022Z,1541479141.022 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2018-11-06T04:39:01.103Z,1541479141.103 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2018-11-06T04:39:01.104Z,1541479141.104 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2018-11-06T04:39:01.205Z,1541479141.205 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2018-11-06T04:39:01.322Z,1541479141.322 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2018-11-06T04:39:01.416Z,1541479141.416 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2018-11-06T04:39:01.500Z,1541479141.500 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2018-11-06T04:39:01.662Z,1541479141.662 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2018-11-06T04:39:01.840Z,1541479141.840 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg
2018-11-06T04:39:01.915Z,1541479141.915 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg
2018-11-06T04:39:02.142Z,1541479142.142 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2018-11-06T04:39:02.143Z,1541479142.143 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg
2018-11-06T04:39:02.225Z,1541479142.225 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg
2018-11-06T04:39:02.315Z,1541479142.315 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2018-11-06T04:39:02.416Z,1541479142.416 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2018-11-06T04:39:02.542Z,1541479142.542 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/root/
2018-11-06T04:39:02.543Z,1541479142.543 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2018-11-06T04:39:02.552Z,1541479142.552 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2018-11-06T04:39:02.794Z,1541479142.794 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2018-11-06T04:39:02.794Z,1541479142.794 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2018-11-06T04:39:02.931Z,1541479142.931 [DepthRateCalculator] Loaded
2018-11-06T04:39:02.931Z,1541479142.931 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2018-11-06T04:39:02.955Z,1541479142.955 [PitchRateCalculator] Loaded
2018-11-06T04:39:02.955Z,1541479142.955 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2018-11-06T04:39:02.985Z,1541479142.985 [SpeedCalculator] Loaded
2018-11-06T04:39:02.985Z,1541479142.985 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2018-11-06T04:39:03.006Z,1541479143.006 [TempGradientCalculator] Loaded
2018-11-06T04:39:03.013Z,1541479143.013 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2018-11-06T04:39:03.018Z,1541479143.018 [YawRateCalculator] Loaded
2018-11-06T04:39:03.019Z,1541479143.019 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2018-11-06T04:39:03.203Z,1541479143.203 [ElevatorOffsetCalculator] Loaded
2018-11-06T04:39:03.203Z,1541479143.203 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2018-11-06T04:39:03.204Z,1541479143.204 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2018-11-06T04:39:03.204Z,1541479143.204 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2018-11-06T04:39:03.269Z,1541479143.269 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2018-11-06T04:39:03.270Z,1541479143.270 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2018-11-06T04:39:03.618Z,1541479143.618 [BuoyancyServo] Loaded
2018-11-06T04:39:03.618Z,1541479143.618 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2018-11-06T04:39:03.633Z,1541479143.633 [ElevatorServo] Loaded
2018-11-06T04:39:03.634Z,1541479143.634 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2018-11-06T04:39:03.648Z,1541479143.648 [MassServo] Loaded
2018-11-06T04:39:03.648Z,1541479143.648 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2018-11-06T04:39:03.667Z,1541479143.667 [RudderServo] Loaded
2018-11-06T04:39:03.668Z,1541479143.668 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2018-11-06T04:39:03.682Z,1541479143.682 [ThrusterServo] Loaded
2018-11-06T04:39:03.683Z,1541479143.683 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2018-11-06T04:39:03.683Z,1541479143.683 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2018-11-06T04:39:03.684Z,1541479143.684 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2018-11-06T04:39:03.697Z,1541479143.697 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2018-11-06T04:39:03.697Z,1541479143.697 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2018-11-06T04:39:03.798Z,1541479143.798 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2018-11-06T04:39:03.799Z,1541479143.799 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2018-11-06T04:39:04.087Z,1541479144.087 [DataOverHttps] Loaded
2018-11-06T04:39:04.087Z,1541479144.087 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2018-11-06T04:39:04.101Z,1541479144.101 [Depth_Keller] Loaded
2018-11-06T04:39:04.101Z,1541479144.101 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2018-11-06T04:39:04.106Z,1541479144.106 [DropWeight] Loaded
2018-11-06T04:39:04.106Z,1541479144.106 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2018-11-06T04:39:04.204Z,1541479144.204 [NAL9602] Loaded
2018-11-06T04:39:04.204Z,1541479144.204 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2018-11-06T04:39:04.220Z,1541479144.220 [Onboard] Loaded
2018-11-06T04:39:04.221Z,1541479144.221 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2018-11-06T04:39:04.231Z,1541479144.231 [Radio_Surface] Loaded
2018-11-06T04:39:04.231Z,1541479144.231 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2018-11-06T04:39:04.233Z,1541479144.233 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4088F4E0
2018-11-06T04:39:04.233Z,1541479144.233 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 978
2018-11-06T04:39:04.279Z,1541479144.279 [PNI_TCM] Loaded
2018-11-06T04:39:04.279Z,1541479144.279 [ComponentRegistry](DEBUG): SyncComponent "PNI_TCM" handled in the control thread.
2018-11-06T04:39:04.340Z,1541479144.340 [Rowe_600LCM] Loaded
2018-11-06T04:39:04.340Z,1541479144.340 [ComponentRegistry](DEBUG): Component "Rowe_600LCM" handled in its own thread.
2018-11-06T04:39:04.341Z,1541479144.341 [Rowe_600LCM ThreadHandler](DEBUG): Created PCaller Thread at 408BF4E0
2018-11-06T04:39:04.341Z,1541479144.341 [Rowe_600LCM ThreadHandler](INFO): Protected caller Thread ID is 979
2018-11-06T04:39:04.342Z,1541479144.342 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2018-11-06T04:39:04.342Z,1541479144.342 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2018-11-06T04:39:04.470Z,1541479144.470 [SBIT](DEBUG): Construct Startup Built In Test.
2018-11-06T04:39:04.492Z,1541479144.492 [SBIT] Loaded
2018-11-06T04:39:04.492Z,1541479144.492 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2018-11-06T04:39:04.493Z,1541479144.493 [IBIT](DEBUG): Construct Initiated Built In Test.
2018-11-06T04:39:04.506Z,1541479144.506 [IBIT] Loaded
2018-11-06T04:39:04.506Z,1541479144.506 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2018-11-06T04:39:04.509Z,1541479144.509 [CBIT](DEBUG): Construct Continuous Built In Test.
2018-11-06T04:39:04.657Z,1541479144.657 [CBIT] Loaded
2018-11-06T04:39:04.657Z,1541479144.657 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2018-11-06T04:39:04.658Z,1541479144.658 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2018-11-06T04:39:04.658Z,1541479144.658 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2018-11-06T04:39:04.817Z,1541479144.817 [Aanderaa_O2] Loaded
2018-11-06T04:39:04.817Z,1541479144.817 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2018-11-06T04:39:04.900Z,1541479144.900 [CTD_NeilBrown] Loaded
2018-11-06T04:39:04.900Z,1541479144.900 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2018-11-06T04:39:04.901Z,1541479144.901 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 4098B4E0
2018-11-06T04:39:04.902Z,1541479144.902 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 980
2018-11-06T04:39:04.916Z,1541479144.916 [PAR_Licor] Loaded
2018-11-06T04:39:04.916Z,1541479144.916 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2018-11-06T04:39:04.964Z,1541479144.964 [WetLabsBB2FL] Loaded
2018-11-06T04:39:04.964Z,1541479144.964 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2018-11-06T04:39:04.966Z,1541479144.966 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 409BB4E0
2018-11-06T04:39:04.966Z,1541479144.966 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 981
2018-11-06T04:39:04.967Z,1541479144.967 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2018-11-06T04:39:04.967Z,1541479144.967 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2018-11-06T04:39:05.034Z,1541479145.034 [VerticalControl](DEBUG): Construct VerticalControl.
2018-11-06T04:39:05.117Z,1541479145.117 [VerticalControl] Loaded
2018-11-06T04:39:05.117Z,1541479145.117 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2018-11-06T04:39:05.118Z,1541479145.118 [HorizontalControl](DEBUG): Construct HorizontalControl.
2018-11-06T04:39:05.174Z,1541479145.174 [HorizontalControl] Loaded
2018-11-06T04:39:05.174Z,1541479145.174 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2018-11-06T04:39:05.175Z,1541479145.175 [SpeedControl](DEBUG): Construct SpeedControl.
2018-11-06T04:39:05.177Z,1541479145.177 [SpeedControl] Loaded
2018-11-06T04:39:05.177Z,1541479145.177 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2018-11-06T04:39:05.178Z,1541479145.178 [LoopControl](DEBUG): Construct LoopControl.
2018-11-06T04:39:05.178Z,1541479145.178 [LoopControl] Loaded
2018-11-06T04:39:05.179Z,1541479145.179 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2018-11-06T04:39:05.179Z,1541479145.179 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2018-11-06T04:39:05.180Z,1541479145.180 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2018-11-06T04:39:05.204Z,1541479145.204 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2018-11-06T04:39:05.205Z,1541479145.205 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2018-11-06T04:39:05.294Z,1541479145.294 [DeadReckonUsingSpeedCalculator] Loaded
2018-11-06T04:39:05.294Z,1541479145.294 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2018-11-06T04:39:05.310Z,1541479145.310 [NavChart] Loaded
2018-11-06T04:39:05.310Z,1541479145.310 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2018-11-06T04:39:05.314Z,1541479145.314 [UniversalFixResidualReporter] Loaded
2018-11-06T04:39:05.315Z,1541479145.315 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2018-11-06T04:39:05.315Z,1541479145.315 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2018-11-06T04:39:05.319Z,1541479145.319 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2018-11-06T04:39:05.320Z,1541479145.320 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2018-11-06T04:39:05.326Z,1541479145.326 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2018-11-06T04:39:05.327Z,1541479145.327 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40A474E0
2018-11-06T04:39:05.328Z,1541479145.328 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 982
2018-11-06T04:39:05.332Z,1541479145.332 [Supervisor](INFO): Main Thread ID is 642
2018-11-06T04:39:05.332Z,1541479145.332 [Supervisor](DEBUG): Running supervisor.
2018-11-06T04:39:05.333Z,1541479145.333 [CommandLine ThreadHandler](INFO): Handler Thread ID is 983
2018-11-06T04:39:05.335Z,1541479145.335 [controlThread ThreadHandler](INFO): Handler Thread ID is 984
2018-11-06T04:39:05.336Z,1541479145.336 [controlThread](DEBUG): Initializing ControlThread
2018-11-06T04:39:05.337Z,1541479145.337 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2018-11-06T04:39:05.337Z,1541479145.337 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2018-11-06T04:39:05.338Z,1541479145.338 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2018-11-06T04:39:05.338Z,1541479145.338 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2018-11-06T04:39:05.338Z,1541479145.338 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2018-11-06T04:39:05.339Z,1541479145.339 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2018-11-06T04:39:05.347Z,1541479145.347 [SBIT](INFO): Initialize SBIT Component.
2018-11-06T04:39:05.347Z,1541479145.347 [SBIT](IMPORTANT): git: 2018-11-05
2018-11-06T04:39:05.348Z,1541479145.348 [SBIT](INFO): git hash: 17f8e4440ddc7f0910aa911cb821ed1a114d9cee
2018-11-06T04:39:05.348Z,1541479145.348 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2018-11-06T04:39:05.348Z,1541479145.348 [SBIT](IMPORTANT): Kernel Version:#2 PREEMPT Thu Jan 11 20:13:48 PST 2018
2018-11-06T04:39:05.349Z,1541479145.349 [SBIT](INFO): Beginning SBIT in 36.000000 seconds.
2018-11-06T04:39:05.350Z,1541479145.350 [IBIT](INFO): Initialize IBIT Component.
2018-11-06T04:39:05.351Z,1541479145.351 [CBIT](DEBUG): Initialize CBIT Component.
2018-11-06T04:39:05.351Z,1541479145.351 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2018-11-06T04:39:05.352Z,1541479145.352 [logger ThreadHandler](INFO): Handler Thread ID is 985
2018-11-06T04:39:05.369Z,1541479145.369 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 986
2018-11-06T04:39:05.375Z,1541479145.375 [Radio_Surface](INFO): Powering up
2018-11-06T04:39:05.381Z,1541479145.381 [Rowe_600LCM ThreadHandler](INFO): Handler Thread ID is 987
2018-11-06T04:39:05.382Z,1541479145.382 [Rowe_600LCM](INFO): Initializing
2018-11-06T04:39:05.382Z,1541479145.382 [Rowe_600LCM](INFO): Checking LCM
2018-11-06T04:39:05.392Z,1541479145.392 [Rowe_600LCM](INFO): LCM OK
2018-11-06T04:39:05.392Z,1541479145.392 [Rowe_600LCM](INFO): Powering up
2018-11-06T04:39:05.398Z,1541479145.398 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 988
2018-11-06T04:39:05.398Z,1541479145.398 [CTD_NeilBrown](INFO): Powering down
2018-11-06T04:39:05.425Z,1541479145.425 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 989
2018-11-06T04:39:05.427Z,1541479145.427 [WetLabsBB2FL](INFO): Powering down
2018-11-06T04:39:05.449Z,1541479145.449 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 990
2018-11-06T04:39:05.452Z,1541479145.452 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2018-11-06T04:39:05.453Z,1541479145.453 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2018-11-06T04:39:05.453Z,1541479145.453 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2018-11-06T04:39:05.453Z,1541479145.453 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2018-11-06T04:39:05.454Z,1541479145.454 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2018-11-06T04:39:05.454Z,1541479145.454 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2018-11-06T04:39:05.454Z,1541479145.454 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2018-11-06T04:39:05.454Z,1541479145.454 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2018-11-06T04:39:05.454Z,1541479145.454 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2018-11-06T04:39:05.454Z,1541479145.454 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2018-11-06T04:39:05.455Z,1541479145.455 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2018-11-06T04:39:05.455Z,1541479145.455 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2018-11-06T04:39:05.455Z,1541479145.455 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2018-11-06T04:39:05.455Z,1541479145.455 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2018-11-06T04:39:05.455Z,1541479145.455 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2018-11-06T04:39:05.456Z,1541479145.456 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2018-11-06T04:39:05.461Z,1541479145.461 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2018-11-06T04:39:05.463Z,1541479145.463 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2018-11-06T04:39:05.464Z,1541479145.464 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2018-11-06T04:39:05.465Z,1541479145.465 [LoopControl](DEBUG): Initialize LoopControlComponent.
2018-11-06T04:39:05.465Z,1541479145.465 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-11-06T04:39:05.466Z,1541479145.466 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-11-06T04:39:05.466Z,1541479145.466 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-11-06T04:39:05.467Z,1541479145.467 [NavChart](DEBUG): Initialize NavChart Navigation.
2018-11-06T04:39:05.467Z,1541479145.467 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2018-11-06T04:39:05.468Z,1541479145.468 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2018-11-06T04:39:05.484Z,1541479145.484 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2018-11-06T04:39:05.536Z,1541479145.536 [MissionManager](DEBUG):
2018-11-06T04:39:05.537Z,1541479145.537 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2018-11-06T04:39:05.611Z,1541479145.611 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2018-11-06T04:39:05.612Z,1541479145.612 [Default:A.Wait](DEBUG): Construct Wait.
2018-11-06T04:39:05.622Z,1541479145.622 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2018-11-06T04:39:05.658Z,1541479145.658 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2018-11-06T04:39:05.677Z,1541479145.677 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2018-11-06T04:39:05.683Z,1541479145.683 [Default:E.Execute](DEBUG): Construct Execute.
2018-11-06T04:39:05.703Z,1541479145.703 [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-06T04:39:05.707Z,1541479145.707 [controlThread](DEBUG): Component order: CycleStarter,DataOverHttps,Depth_Keller,DropWeight,NAL9602,Onboard,PNI_TCM,Aanderaa_O2,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2018-11-06T04:39:05.729Z,1541479145.729 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2018-11-06T04:39:06.194Z,1541479146.194 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2018-11-06T04:39:06.202Z,1541479146.202 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2018-11-06T04:39:06.241Z,1541479146.241 [ElevatorServo](DEBUG): Initializing EZServoServo.
2018-11-06T04:39:06.249Z,1541479146.249 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2018-11-06T04:39:06.263Z,1541479146.263 [MassServo](DEBUG): Initializing EZServoServo.
2018-11-06T04:39:06.269Z,1541479146.269 [MassServo](DEBUG): Initializing MassServo.
2018-11-06T04:39:06.275Z,1541479146.275 [RudderServo](DEBUG): Initializing EZServoServo.
2018-11-06T04:39:06.281Z,1541479146.281 [RudderServo](DEBUG): Initializing RudderServo.
2018-11-06T04:39:06.287Z,1541479146.287 [ThrusterServo](DEBUG): Initializing EZServoServo.
2018-11-06T04:39:06.293Z,1541479146.293 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2018-11-06T04:39:09.417Z,1541479149.417 [Aanderaa_O2](INFO): Powering down
2018-11-06T04:39:09.768Z,1541479149.768 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-11-06T04:39:09.893Z,1541479149.893 [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-06T04:39:09.974Z,1541479149.974 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-11-06T04:39:09.975Z,1541479149.975 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-11-06T04:39:09.975Z,1541479149.975 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-11-06T04:39:34.583Z,1541479174.583 [NAL9602](INFO): Powering up NAL9602
2018-11-06T04:39:40.786Z,1541479180.786 [CommandLine](IMPORTANT): got command failComponent
2018-11-06T04:39:40.786Z,1541479180.786 [CommandLine](IMPORTANT): Failed components:
2018-11-06T04:39:40.786Z,1541479180.786 [CommandLine](IMPORTANT): No failed Components.
2018-11-06T04:39:41.857Z,1541479181.857 [SBIT](IMPORTANT): Beginning Startup BIT
2018-11-06T04:39:41.878Z,1541479181.878 [CBIT](IMPORTANT): Beginning ground fault scan
2018-11-06T04:39:45.842Z,1541479185.842 [CommandLine](IMPORTANT): got command restart application
2018-11-06T04:39:46.845Z,1541479186.845 [Supervisor](INFO): Stop Mission called by Supervisor::terminate
2018-11-06T04:39:46.848Z,1541479186.848 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2018-11-06T04:39:46.848Z,1541479186.848 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-11-06T04:39:46.969Z,1541479186.969 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye!
2018-11-06T04:39:46.969Z,1541479186.969 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-11-06T04:39:46.970Z,1541479186.970 [CommandLine](INFO): Join timeout helper Thread ID is 1003
2018-11-06T04:39:46.971Z,1541479186.971 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2018-11-06T04:39:46.971Z,1541479186.971 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-11-06T04:39:46.973Z,1541479186.973 [NavChartDb](INFO): Join timeout helper Thread ID is 1004
2018-11-06T04:39:48.877Z,1541479188.877 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2018-11-06T04:39:48.877Z,1541479188.877 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-11-06T04:39:48.893Z,1541479188.893 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2018-11-06T04:39:48.893Z,1541479188.893 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2018-11-06T04:39:48.894Z,1541479188.894 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 1005
2018-11-06T04:39:49.393Z,1541479189.393 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2018-11-06T04:39:49.393Z,1541479189.393 [WetLabsBB2FL](INFO): Powering down
2018-11-06T04:39:49.394Z,1541479189.394 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2018-11-06T04:39:49.397Z,1541479189.397 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2018-11-06T04:39:49.397Z,1541479189.397 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2018-11-06T04:39:49.398Z,1541479189.398 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 1006
2018-11-06T04:39:49.398Z,1541479189.398 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread.
2018-11-06T04:39:49.398Z,1541479189.398 [CTD_NeilBrown](INFO): Powering down
2018-11-06T04:39:49.413Z,1541479189.413 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2018-11-06T04:39:49.421Z,1541479189.421 [ComponentRegistry](INFO): Shutting down Rowe_600LCM ThreadHandler
2018-11-06T04:39:49.421Z,1541479189.421 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2018-11-06T04:39:49.422Z,1541479189.422 [Rowe_600LCM](INFO): Join timeout helper Thread ID is 1007
2018-11-06T04:39:49.422Z,1541479189.422 [Rowe_600LCM ThreadHandler](INFO): Uninitializing protected caller thread.
2018-11-06T04:39:49.422Z,1541479189.422 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-11-06T04:39:49.676Z,1541479189.676 [Rowe_600LCM](INFO): Powering down
2018-11-06T04:39:49.678Z,1541479189.678 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2018-11-06T04:39:49.690Z,1541479189.690 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2018-11-06T04:39:49.690Z,1541479189.690 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-11-06T04:39:49.691Z,1541479189.691 [Radio_Surface](INFO): Join timeout helper Thread ID is 1009
2018-11-06T04:39:49.869Z,1541479189.869 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2018-11-06T04:39:49.869Z,1541479189.869 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-11-06T04:39:49.878Z,1541479189.878 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2018-11-06T04:39:49.878Z,1541479189.878 [logger ThreadHandler](INFO): Thread cancelled.
2018-11-06T04:39:49.878Z,1541479189.878 [logger](INFO): Join timeout helper Thread ID is 1010
2018-11-06T04:39:49.909Z,1541479189.909 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2018-11-06T04:39:49.909Z,1541479189.909 [logger ThreadHandler](INFO): Thread cancelled.
2018-11-06T04:39:49.918Z,1541479189.918 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2018-11-06T04:39:49.918Z,1541479189.918 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-11-06T04:39:49.918Z,1541479189.918 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2018-11-06T04:39:49.918Z,1541479189.918 [controlThread ThreadHandler](INFO): Thread cancelled.
2018-11-06T04:39:49.919Z,1541479189.919 [controlThread](INFO): Join timeout helper Thread ID is 1011
2018-11-06T04:39:50.082Z,1541479190.082 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2018-11-06T04:39:50.082Z,1541479190.082 [controlThread](DEBUG): Uninitializing ControlThread
2018-11-06T04:39:50.083Z,1541479190.083 [NAL9602](INFO): Powering down
2018-11-06T04:39:50.085Z,1541479190.085 [PNI_TCM](INFO): Powering down
2018-11-06T04:39:50.173Z,1541479190.173 [Aanderaa_O2](INFO): Powering down
2018-11-06T04:39:50.175Z,1541479190.175 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2018-11-06T04:39:50.176Z,1541479190.176 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2018-11-06T04:39:50.176Z,1541479190.176 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2018-11-06T04:39:50.177Z,1541479190.177 [MissionManager](INFO): Uninitializing Mission Default
2018-11-06T04:39:50.179Z,1541479190.179 [MissionManager](INFO): Uninitializing Mission Startup
2018-11-06T04:39:50.181Z,1541479190.181 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2018-11-06T04:39:50.181Z,1541479190.181 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2018-11-06T04:39:50.181Z,1541479190.181 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2018-11-06T04:39:50.182Z,1541479190.182 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2018-11-06T04:39:50.182Z,1541479190.182 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2018-11-06T04:39:50.182Z,1541479190.182 [BuoyancyServo](INFO): Powering down
2018-11-06T04:39:50.197Z,1541479190.197 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2018-11-06T04:39:50.197Z,1541479190.197 [ElevatorServo](INFO): Powering down
2018-11-06T04:39:50.198Z,1541479190.198 [MassServo](DEBUG): Uninitialize Mass Servo.
2018-11-06T04:39:50.198Z,1541479190.198 [MassServo](INFO): Powering down
2018-11-06T04:39:50.199Z,1541479190.199 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2018-11-06T04:39:50.199Z,1541479190.199 [RudderServo](INFO): Powering down
2018-11-06T04:39:50.200Z,1541479190.200 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2018-11-06T04:39:50.200Z,1541479190.200 [ThrusterServo](INFO): Powering down
2018-11-06T04:39:50.201Z,1541479190.201 [SBIT](DEBUG): Uninitialize SBIT Component.
2018-11-06T04:39:50.201Z,1541479190.201 [IBIT](DEBUG): Uninitialize IBIT Component.
2018-11-06T04:39:50.202Z,1541479190.202 [CBIT](DEBUG): Uninitialize CBIT Component.
2018-11-06T04:39:50.203Z,1541479190.203 [controlThread ThreadHandler](INFO): Thread cancelled.
2018-11-06T04:39:50.375Z,1541479190.375 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2018-11-06T04:39:50.381Z,1541479190.381 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-11-06T04:39:50.417Z,1541479190.417 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2018-11-06T04:39:50.421Z,1541479190.421 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2018-11-06T04:39:50.448Z,1541479190.448 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-11-06T04:39:50.495Z,1541479190.495 [logger ThreadHandler](INFO): Thread cancelled.