2018-10-09T16:22:11.096Z,1539102131.096 [Supervisor](DEBUG): Initializing supervisor.
2018-10-09T16:22:11.098Z,1539102131.098 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2018-10-09T16:22:11.099Z,1539102131.099 [SyncHandler](INFO): Protected caller Thread ID is 798
2018-10-09T16:22:11.099Z,1539102131.099 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2018-10-09T16:22:11.100Z,1539102131.100 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2018-10-09T16:22:11.101Z,1539102131.101 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 799
2018-10-09T16:22:11.103Z,1539102131.103 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2018-10-09T16:22:11.115Z,1539102131.115 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2018-10-09T16:22:11.116Z,1539102131.116 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2018-10-09T16:22:11.116Z,1539102131.116 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 800
2018-10-09T16:22:11.117Z,1539102131.117 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2018-10-09T16:22:11.118Z,1539102131.118 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2018-10-09T16:22:11.118Z,1539102131.118 [logger ThreadHandler](INFO): Protected caller Thread ID is 801
2018-10-09T16:22:11.120Z,1539102131.120 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2018-10-09T16:22:11.120Z,1539102131.120 [Supervisor](INFO): Looking for Config files in directory: Config/
2018-10-09T16:22:11.124Z,1539102131.124 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2018-10-09T16:22:11.481Z,1539102131.481 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2018-10-09T16:22:11.483Z,1539102131.483 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2018-10-09T16:22:11.690Z,1539102131.690 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2018-10-09T16:22:11.692Z,1539102131.692 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2018-10-09T16:22:12.006Z,1539102132.006 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2018-10-09T16:22:12.007Z,1539102132.007 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2018-10-09T16:22:12.159Z,1539102132.159 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2018-10-09T16:22:12.160Z,1539102132.160 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2018-10-09T16:22:12.260Z,1539102132.260 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2018-10-09T16:22:12.262Z,1539102132.262 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2018-10-09T16:22:12.740Z,1539102132.740 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2018-10-09T16:22:12.742Z,1539102132.742 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2018-10-09T16:22:13.217Z,1539102133.217 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2018-10-09T16:22:13.218Z,1539102133.218 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2018-10-09T16:22:13.697Z,1539102133.697 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2018-10-09T16:22:13.698Z,1539102133.698 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2018-10-09T16:22:13.804Z,1539102133.804 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2018-10-09T16:22:13.805Z,1539102133.805 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2018-10-09T16:22:13.903Z,1539102133.903 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2018-10-09T16:22:13.905Z,1539102133.905 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2018-10-09T16:22:14.127Z,1539102134.127 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2018-10-09T16:22:14.128Z,1539102134.128 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2018-10-09T16:22:14.338Z,1539102134.338 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2018-10-09T16:22:14.339Z,1539102134.339 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2018-10-09T16:22:14.699Z,1539102134.699 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2018-10-09T16:22:14.699Z,1539102134.699 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2018-10-09T16:22:14.857Z,1539102134.857 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2018-10-09T16:22:14.857Z,1539102134.857 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2018-10-09T16:22:15.034Z,1539102135.034 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2018-10-09T16:22:15.862Z,1539102135.862 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2018-10-09T16:22:15.970Z,1539102135.970 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2018-10-09T16:22:16.091Z,1539102136.091 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2018-10-09T16:22:16.188Z,1539102136.188 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2018-10-09T16:22:16.274Z,1539102136.274 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2018-10-09T16:22:16.445Z,1539102136.445 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2018-10-09T16:22:16.632Z,1539102136.632 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg
2018-10-09T16:22:16.709Z,1539102136.709 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg
2018-10-09T16:22:16.943Z,1539102136.943 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2018-10-09T16:22:16.944Z,1539102136.944 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg
2018-10-09T16:22:17.029Z,1539102137.029 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg
2018-10-09T16:22:17.122Z,1539102137.122 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2018-10-09T16:22:17.226Z,1539102137.226 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2018-10-09T16:22:17.356Z,1539102137.356 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg
2018-10-09T16:22:17.359Z,1539102137.359 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2018-10-09T16:22:17.664Z,1539102137.664 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2018-10-09T16:22:17.666Z,1539102137.666 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2018-10-09T16:22:17.772Z,1539102137.772 [DepthRateCalculator] Loaded
2018-10-09T16:22:17.772Z,1539102137.772 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2018-10-09T16:22:17.778Z,1539102137.778 [PitchRateCalculator] Loaded
2018-10-09T16:22:17.778Z,1539102137.778 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2018-10-09T16:22:17.794Z,1539102137.794 [SpeedCalculator] Loaded
2018-10-09T16:22:17.795Z,1539102137.795 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2018-10-09T16:22:17.816Z,1539102137.816 [TempGradientCalculator] Loaded
2018-10-09T16:22:17.816Z,1539102137.816 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2018-10-09T16:22:17.821Z,1539102137.821 [YawRateCalculator] Loaded
2018-10-09T16:22:17.822Z,1539102137.822 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2018-10-09T16:22:17.861Z,1539102137.861 [ElevatorOffsetCalculator] Loaded
2018-10-09T16:22:17.861Z,1539102137.861 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2018-10-09T16:22:17.861Z,1539102137.861 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2018-10-09T16:22:17.862Z,1539102137.862 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2018-10-09T16:22:17.965Z,1539102137.965 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2018-10-09T16:22:17.966Z,1539102137.966 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2018-10-09T16:22:18.097Z,1539102138.097 [BuoyancyServo] Loaded
2018-10-09T16:22:18.097Z,1539102138.097 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2018-10-09T16:22:18.111Z,1539102138.111 [ElevatorServo] Loaded
2018-10-09T16:22:18.112Z,1539102138.112 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2018-10-09T16:22:18.126Z,1539102138.126 [MassServo] Loaded
2018-10-09T16:22:18.126Z,1539102138.126 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2018-10-09T16:22:18.141Z,1539102138.141 [RudderServo] Loaded
2018-10-09T16:22:18.142Z,1539102138.142 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2018-10-09T16:22:18.156Z,1539102138.156 [ThrusterServo] Loaded
2018-10-09T16:22:18.156Z,1539102138.156 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2018-10-09T16:22:18.156Z,1539102138.156 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2018-10-09T16:22:18.157Z,1539102138.157 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2018-10-09T16:22:18.181Z,1539102138.181 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2018-10-09T16:22:18.181Z,1539102138.181 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2018-10-09T16:22:18.305Z,1539102138.305 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2018-10-09T16:22:18.306Z,1539102138.306 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2018-10-09T16:22:18.873Z,1539102138.873 [DataOverHttps] Loaded
2018-10-09T16:22:18.873Z,1539102138.873 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2018-10-09T16:22:18.886Z,1539102138.886 [Depth_Keller] Loaded
2018-10-09T16:22:18.886Z,1539102138.886 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2018-10-09T16:22:18.891Z,1539102138.891 [DropWeight] Loaded
2018-10-09T16:22:18.891Z,1539102138.891 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2018-10-09T16:22:18.988Z,1539102138.988 [NAL9602] Loaded
2018-10-09T16:22:18.988Z,1539102138.988 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2018-10-09T16:22:19.004Z,1539102139.004 [Onboard] Loaded
2018-10-09T16:22:19.004Z,1539102139.004 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2018-10-09T16:22:19.014Z,1539102139.014 [Radio_Surface] Loaded
2018-10-09T16:22:19.014Z,1539102139.014 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2018-10-09T16:22:19.016Z,1539102139.016 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4088F4E0
2018-10-09T16:22:19.016Z,1539102139.016 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 884
2018-10-09T16:22:19.168Z,1539102139.168 [PNI_TCM] Loaded
2018-10-09T16:22:19.168Z,1539102139.168 [ComponentRegistry](DEBUG): SyncComponent "PNI_TCM" handled in the control thread.
2018-10-09T16:22:19.227Z,1539102139.227 [Rowe_600LCM] Loaded
2018-10-09T16:22:19.228Z,1539102139.228 [ComponentRegistry](DEBUG): Component "Rowe_600LCM" handled in its own thread.
2018-10-09T16:22:19.229Z,1539102139.229 [Rowe_600LCM ThreadHandler](DEBUG): Created PCaller Thread at 408BF4E0
2018-10-09T16:22:19.229Z,1539102139.229 [Rowe_600LCM ThreadHandler](INFO): Protected caller Thread ID is 885
2018-10-09T16:22:21.242Z,1539102141.242 [BPC1] Loaded
2018-10-09T16:22:21.242Z,1539102141.242 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2018-10-09T16:22:21.242Z,1539102141.242 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2018-10-09T16:22:21.244Z,1539102141.244 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2018-10-09T16:22:21.395Z,1539102141.395 [SBIT](DEBUG): Construct Startup Built In Test.
2018-10-09T16:22:21.417Z,1539102141.417 [SBIT] Loaded
2018-10-09T16:22:21.417Z,1539102141.417 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2018-10-09T16:22:21.418Z,1539102141.418 [IBIT](DEBUG): Construct Initiated Built In Test.
2018-10-09T16:22:21.429Z,1539102141.429 [IBIT] Loaded
2018-10-09T16:22:21.429Z,1539102141.429 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2018-10-09T16:22:21.432Z,1539102141.432 [CBIT](DEBUG): Construct Continuous Built In Test.
2018-10-09T16:22:21.579Z,1539102141.579 [CBIT] Loaded
2018-10-09T16:22:21.579Z,1539102141.579 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2018-10-09T16:22:21.580Z,1539102141.580 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2018-10-09T16:22:21.580Z,1539102141.580 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2018-10-09T16:22:21.783Z,1539102141.783 [Aanderaa_O2] Loaded
2018-10-09T16:22:21.783Z,1539102141.783 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2018-10-09T16:22:21.859Z,1539102141.859 [CTD_NeilBrown] Loaded
2018-10-09T16:22:21.859Z,1539102141.859 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2018-10-09T16:22:21.860Z,1539102141.860 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 409894E0
2018-10-09T16:22:21.861Z,1539102141.861 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 886
2018-10-09T16:22:21.911Z,1539102141.911 [CTD_Seabird] Loaded
2018-10-09T16:22:21.911Z,1539102141.911 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2018-10-09T16:22:21.912Z,1539102141.912 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 409B94E0
2018-10-09T16:22:21.912Z,1539102141.912 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 887
2018-10-09T16:22:21.926Z,1539102141.926 [PAR_Licor] Loaded
2018-10-09T16:22:21.927Z,1539102141.927 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2018-10-09T16:22:21.975Z,1539102141.975 [WetLabsBB2FL] Loaded
2018-10-09T16:22:21.975Z,1539102141.975 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2018-10-09T16:22:21.976Z,1539102141.976 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 409E94E0
2018-10-09T16:22:21.976Z,1539102141.976 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 888
2018-10-09T16:22:21.977Z,1539102141.977 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2018-10-09T16:22:21.979Z,1539102141.979 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2018-10-09T16:22:22.065Z,1539102142.065 [VerticalControl](DEBUG): Construct VerticalControl.
2018-10-09T16:22:22.148Z,1539102142.148 [VerticalControl] Loaded
2018-10-09T16:22:22.148Z,1539102142.148 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2018-10-09T16:22:22.149Z,1539102142.149 [HorizontalControl](DEBUG): Construct HorizontalControl.
2018-10-09T16:22:22.205Z,1539102142.205 [HorizontalControl] Loaded
2018-10-09T16:22:22.205Z,1539102142.205 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2018-10-09T16:22:22.206Z,1539102142.206 [SpeedControl](DEBUG): Construct SpeedControl.
2018-10-09T16:22:22.208Z,1539102142.208 [SpeedControl] Loaded
2018-10-09T16:22:22.208Z,1539102142.208 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2018-10-09T16:22:22.209Z,1539102142.209 [LoopControl](DEBUG): Construct LoopControl.
2018-10-09T16:22:22.209Z,1539102142.209 [LoopControl] Loaded
2018-10-09T16:22:22.210Z,1539102142.210 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2018-10-09T16:22:22.210Z,1539102142.210 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2018-10-09T16:22:22.211Z,1539102142.211 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2018-10-09T16:22:22.247Z,1539102142.247 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2018-10-09T16:22:22.248Z,1539102142.248 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2018-10-09T16:22:22.353Z,1539102142.353 [DeadReckonUsingSpeedCalculator] Loaded
2018-10-09T16:22:22.353Z,1539102142.353 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2018-10-09T16:22:22.370Z,1539102142.370 [NavChart] Loaded
2018-10-09T16:22:22.370Z,1539102142.370 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2018-10-09T16:22:22.374Z,1539102142.374 [UniversalFixResidualReporter] Loaded
2018-10-09T16:22:22.374Z,1539102142.374 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2018-10-09T16:22:22.375Z,1539102142.375 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2018-10-09T16:22:22.378Z,1539102142.378 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2018-10-09T16:22:22.379Z,1539102142.379 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2018-10-09T16:22:22.386Z,1539102142.386 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2018-10-09T16:22:22.387Z,1539102142.387 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40A754E0
2018-10-09T16:22:22.387Z,1539102142.387 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 889
2018-10-09T16:22:22.392Z,1539102142.392 [Supervisor](INFO): Main Thread ID is 797
2018-10-09T16:22:22.392Z,1539102142.392 [Supervisor](DEBUG): Running supervisor.
2018-10-09T16:22:22.392Z,1539102142.392 [CommandLine ThreadHandler](INFO): Handler Thread ID is 890
2018-10-09T16:22:22.395Z,1539102142.395 [controlThread ThreadHandler](INFO): Handler Thread ID is 891
2018-10-09T16:22:22.395Z,1539102142.395 [controlThread](DEBUG): Initializing ControlThread
2018-10-09T16:22:22.396Z,1539102142.396 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2018-10-09T16:22:22.397Z,1539102142.397 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2018-10-09T16:22:22.397Z,1539102142.397 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2018-10-09T16:22:22.397Z,1539102142.397 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2018-10-09T16:22:22.398Z,1539102142.398 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2018-10-09T16:22:22.398Z,1539102142.398 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2018-10-09T16:22:22.406Z,1539102142.406 [SBIT](INFO): Initialize SBIT Component.
2018-10-09T16:22:22.406Z,1539102142.406 [SBIT](IMPORTANT): git: 2018-10-09
2018-10-09T16:22:22.406Z,1539102142.406 [SBIT](INFO): git hash: e647870a3e94d94bcb418e3013bcadd95d09d9aa
2018-10-09T16:22:22.407Z,1539102142.407 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2018-10-09T16:22:22.407Z,1539102142.407 [SBIT](IMPORTANT): Kernel Version:#2 PREEMPT Thu Jan 11 20:13:48 PST 2018
2018-10-09T16:22:22.408Z,1539102142.408 [SBIT](INFO): Beginning SBIT in 23.000000 seconds.
2018-10-09T16:22:22.409Z,1539102142.409 [IBIT](INFO): Initialize IBIT Component.
2018-10-09T16:22:22.410Z,1539102142.410 [CBIT](DEBUG): Initialize CBIT Component.
2018-10-09T16:22:22.410Z,1539102142.410 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL.
2018-10-09T16:22:22.410Z,1539102142.410 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2018-10-09T16:22:22.411Z,1539102142.411 [logger ThreadHandler](INFO): Handler Thread ID is 892
2018-10-09T16:22:22.428Z,1539102142.428 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 893
2018-10-09T16:22:22.433Z,1539102142.433 [Radio_Surface](INFO): Powering up
2018-10-09T16:22:22.440Z,1539102142.440 [Rowe_600LCM ThreadHandler](INFO): Handler Thread ID is 894
2018-10-09T16:22:22.440Z,1539102142.440 [Rowe_600LCM](INFO): Initializing
2018-10-09T16:22:22.441Z,1539102142.441 [Rowe_600LCM](INFO): Checking LCM
2018-10-09T16:22:22.522Z,1539102142.522 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2018-10-09T16:22:22.528Z,1539102142.528 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2018-10-09T16:22:22.537Z,1539102142.537 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2018-10-09T16:22:22.539Z,1539102142.539 [LoopControl](DEBUG): Initialize LoopControlComponent.
2018-10-09T16:22:22.540Z,1539102142.540 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-10-09T16:22:22.541Z,1539102142.541 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-10-09T16:22:22.541Z,1539102142.541 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-10-09T16:22:22.553Z,1539102142.553 [NavChart](DEBUG): Initialize NavChart Navigation.
2018-10-09T16:22:22.554Z,1539102142.554 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 895
2018-10-09T16:22:22.555Z,1539102142.555 [CTD_NeilBrown](INFO): Powering down
2018-10-09T16:22:22.556Z,1539102142.556 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2018-10-09T16:22:22.571Z,1539102142.571 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2018-10-09T16:22:22.672Z,1539102142.672 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 896
2018-10-09T16:22:22.674Z,1539102142.674 [CTD_Seabird](INFO): Initializing
2018-10-09T16:22:22.674Z,1539102142.674 [CTD_Seabird](INFO): Checking LCM
2018-10-09T16:22:22.688Z,1539102142.688 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 897
2018-10-09T16:22:22.689Z,1539102142.689 [WetLabsBB2FL](INFO): Powering down
2018-10-09T16:22:22.717Z,1539102142.717 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2018-10-09T16:22:22.786Z,1539102142.786 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 898
2018-10-09T16:22:22.794Z,1539102142.794 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2018-10-09T16:22:22.794Z,1539102142.794 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2018-10-09T16:22:22.794Z,1539102142.794 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2018-10-09T16:22:22.794Z,1539102142.794 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2018-10-09T16:22:22.795Z,1539102142.795 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2018-10-09T16:22:22.795Z,1539102142.795 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2018-10-09T16:22:22.795Z,1539102142.795 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2018-10-09T16:22:22.796Z,1539102142.796 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2018-10-09T16:22:22.796Z,1539102142.796 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2018-10-09T16:22:22.796Z,1539102142.796 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2018-10-09T16:22:22.796Z,1539102142.796 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2018-10-09T16:22:22.796Z,1539102142.796 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2018-10-09T16:22:22.796Z,1539102142.796 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2018-10-09T16:22:22.797Z,1539102142.797 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2018-10-09T16:22:22.797Z,1539102142.797 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2018-10-09T16:22:22.797Z,1539102142.797 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2018-10-09T16:22:22.814Z,1539102142.814 [MissionManager](DEBUG):
2018-10-09T16:22:22.820Z,1539102142.820 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2018-10-09T16:22:22.901Z,1539102142.901 [CTD_Seabird](INFO): LCM OK
2018-10-09T16:22:22.901Z,1539102142.901 [CTD_Seabird](INFO): Powering up
2018-10-09T16:22:22.901Z,1539102142.901 [Rowe_600LCM](INFO): LCM OK
2018-10-09T16:22:22.902Z,1539102142.902 [Rowe_600LCM](INFO): Powering up
2018-10-09T16:22:22.926Z,1539102142.926 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2018-10-09T16:22:22.928Z,1539102142.928 [Default:A.Wait](DEBUG): Construct Wait.
2018-10-09T16:22:22.929Z,1539102142.929 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2018-10-09T16:22:22.972Z,1539102142.972 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2018-10-09T16:22:22.975Z,1539102142.975 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2018-10-09T16:22:22.997Z,1539102142.997 [Default:E.Execute](DEBUG): Construct Execute.
2018-10-09T16:22:23.010Z,1539102143.010 [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-10-09T16:22:23.015Z,1539102143.015 [controlThread](DEBUG): Component order: CycleStarter,DataOverHttps,Depth_Keller,DropWeight,NAL9602,Onboard,PNI_TCM,BPC1,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-10-09T16:22:23.049Z,1539102143.049 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2018-10-09T16:22:23.073Z,1539102143.073 [Depth_Keller](ERROR): Pressure reading out of range: 1831.023193 decibar
2018-10-09T16:22:23.364Z,1539102143.364 [DepthRateCalculator](ERROR): Depth measurement is not active
2018-10-09T16:22:23.453Z,1539102143.453 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-10-09T16:22:23.679Z,1539102143.679 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2018-10-09T16:22:23.687Z,1539102143.687 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2018-10-09T16:22:23.706Z,1539102143.706 [ElevatorServo](DEBUG): Initializing EZServoServo.
2018-10-09T16:22:23.712Z,1539102143.712 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2018-10-09T16:22:23.726Z,1539102143.726 [MassServo](DEBUG): Initializing EZServoServo.
2018-10-09T16:22:23.731Z,1539102143.731 [MassServo](DEBUG): Initializing MassServo.
2018-10-09T16:22:23.753Z,1539102143.753 [RudderServo](DEBUG): Initializing EZServoServo.
2018-10-09T16:22:23.759Z,1539102143.759 [RudderServo](DEBUG): Initializing RudderServo.
2018-10-09T16:22:23.773Z,1539102143.773 [ThrusterServo](DEBUG): Initializing EZServoServo.
2018-10-09T16:22:23.779Z,1539102143.779 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2018-10-09T16:22:24.138Z,1539102144.138 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-10-09T16:22:24.329Z,1539102144.329 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-10-09T16:22:24.675Z,1539102144.675 [BuoyancyServo](ERROR): Buoyancy initialization uart error serial timeout
2018-10-09T16:22:24.675Z,1539102144.675 [BuoyancyServo](FAULT): Buoyancy failed to initialize
2018-10-09T16:22:24.675Z,1539102144.675 [BuoyancyServo] Communications Fault, FailCount= 1
2018-10-09T16:22:24.676Z,1539102144.676 [BuoyancyServo](ERROR): Communications Fault
2018-10-09T16:22:24.887Z,1539102144.887 [CBIT](ERROR): Communications Fault in component: BuoyancyServo
2018-10-09T16:22:24.949Z,1539102144.949 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-10-09T16:22:24.971Z,1539102144.971 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2018-10-09T16:22:24.971Z,1539102144.971 [BuoyancyServo](INFO): Powering down
2018-10-09T16:22:25.343Z,1539102145.343 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-10-09T16:22:25.755Z,1539102145.755 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-10-09T16:22:26.162Z,1539102146.162 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-10-09T16:22:26.655Z,1539102146.655 [Aanderaa_O2](INFO): Powering down
2018-10-09T16:22:26.756Z,1539102146.756 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-10-09T16:22:26.822Z,1539102146.822 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-10-09T16:22:26.934Z,1539102146.934 [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-10-09T16:22:27.113Z,1539102147.113 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-10-09T16:22:27.114Z,1539102147.114 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-10-09T16:22:27.114Z,1539102147.114 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-10-09T16:22:27.148Z,1539102147.148 [CBIT](INFO): Clearing failed state for component BuoyancyServo
2018-10-09T16:22:27.148Z,1539102147.148 [BuoyancyServo] No Fault, FailCount= 1
2018-10-09T16:22:27.405Z,1539102147.405 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2018-10-09T16:22:27.406Z,1539102147.406 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2018-10-09T16:22:28.273Z,1539102148.273 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface
2018-10-09T16:22:28.295Z,1539102148.295 [BuoyancyServo](ERROR): Buoyancy initialization uart error serial timeout
2018-10-09T16:22:28.296Z,1539102148.296 [BuoyancyServo](FAULT): Buoyancy failed to initialize
2018-10-09T16:22:28.296Z,1539102148.296 [BuoyancyServo] Communications Fault, FailCount= 2
2018-10-09T16:22:28.296Z,1539102148.296 [BuoyancyServo](ERROR): Communications Fault
2018-10-09T16:22:28.448Z,1539102148.448 [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-10-09T16:22:28.449Z,1539102148.449 [CTD_Seabird](INFO): LCM subscribed to channel:seabird_gpctd_t.seabird-gpctd
2018-10-09T16:22:28.539Z,1539102148.539 [CBIT](ERROR): Communications Fault in component: BuoyancyServo
2018-10-09T16:22:29.057Z,1539102149.057 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2018-10-09T16:22:29.079Z,1539102149.079 [BuoyancyServo](INFO): Powering down
2018-10-09T16:22:29.352Z,1539102149.352 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface
2018-10-09T16:22:29.352Z,1539102149.352 [CTD_Seabird](INFO): Powering down
2018-10-09T16:22:31.373Z,1539102151.373 [CBIT](INFO): Clearing failed state for component BuoyancyServo
2018-10-09T16:22:31.373Z,1539102151.373 [BuoyancyServo] No Fault, FailCount= 2
2018-10-09T16:22:31.837Z,1539102151.837 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2018-10-09T16:22:31.837Z,1539102151.837 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2018-10-09T16:22:46.181Z,1539102166.181 [SBIT](IMPORTANT): Beginning Startup BIT
2018-10-09T16:22:46.186Z,1539102166.186 [CBIT](IMPORTANT): Beginning ground fault scan
2018-10-09T16:22:49.281Z,1539102169.281 [NAL9602](INFO): Powering up NAL9602
2018-10-09T16:22:57.040Z,1539102177.040 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): -0.005157
CHAN A1 (24V): 4.657929
CHAN A2 (12V): -0.002407
CHAN A3 (5V): -0.001291
CHAN B0 (3.3V): 0.000043
CHAN B1 (3.15aV): -0.000020
CHAN B2 (3.15bV): -0.000585
CHAN B3 (GND): 0.000327
OPEN: -0.000457
Full Scale Calc: 4.765 mA, -1.589 mA
2018-10-09T16:22:59.402Z,1539102179.402 [SBIT](ERROR): Could not read massPosReader_.
2018-10-09T16:23:00.481Z,1539102180.481 [NAL9602](INFO): NAL9602 initialized
2018-10-09T16:23:01.567Z,1539102181.567 [CommandLine](IMPORTANT): got command restart system
2018-10-09T16:23:03.923Z,1539102183.923 [Supervisor](INFO): Stop Mission called by Supervisor::terminate
2018-10-09T16:23:03.927Z,1539102183.927 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2018-10-09T16:23:03.927Z,1539102183.927 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-10-09T16:23:04.047Z,1539102184.047 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye!
2018-10-09T16:23:04.047Z,1539102184.047 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-10-09T16:23:04.048Z,1539102184.048 [CommandLine](INFO): Join timeout helper Thread ID is 919
2018-10-09T16:23:04.063Z,1539102184.063 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2018-10-09T16:23:04.063Z,1539102184.063 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-10-09T16:23:04.064Z,1539102184.064 [NavChartDb](INFO): Join timeout helper Thread ID is 920
2018-10-09T16:23:04.623Z,1539102184.623 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2018-10-09T16:23:04.623Z,1539102184.623 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-10-09T16:23:04.632Z,1539102184.632 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2018-10-09T16:23:04.632Z,1539102184.632 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2018-10-09T16:23:04.633Z,1539102184.633 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 921
2018-10-09T16:23:05.047Z,1539102185.047 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2018-10-09T16:23:05.048Z,1539102185.048 [WetLabsBB2FL](INFO): Powering down
2018-10-09T16:23:05.048Z,1539102185.048 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2018-10-09T16:23:05.063Z,1539102185.063 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2018-10-09T16:23:05.063Z,1539102185.063 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2018-10-09T16:23:05.064Z,1539102185.064 [CTD_Seabird](INFO): Join timeout helper Thread ID is 922
2018-10-09T16:23:05.359Z,1539102185.359 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2018-10-09T16:23:05.552Z,1539102185.552 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface
2018-10-09T16:23:05.552Z,1539102185.552 [CTD_Seabird](INFO): Powering down
2018-10-09T16:23:05.553Z,1539102185.553 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2018-10-09T16:23:05.571Z,1539102185.571 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2018-10-09T16:23:05.571Z,1539102185.571 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2018-10-09T16:23:05.572Z,1539102185.572 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 924
2018-10-09T16:23:05.947Z,1539102185.947 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread.
2018-10-09T16:23:05.948Z,1539102185.948 [CTD_NeilBrown](INFO): Powering down
2018-10-09T16:23:05.948Z,1539102185.948 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2018-10-09T16:23:05.964Z,1539102185.964 [ComponentRegistry](INFO): Shutting down Rowe_600LCM ThreadHandler
2018-10-09T16:23:05.964Z,1539102185.964 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2018-10-09T16:23:05.965Z,1539102185.965 [Rowe_600LCM](INFO): Join timeout helper Thread ID is 925
2018-10-09T16:23:06.361Z,1539102186.361 [Rowe_600LCM ThreadHandler](INFO): Uninitializing protected caller thread.
2018-10-09T16:23:06.361Z,1539102186.361 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-10-09T16:23:06.724Z,1539102186.724 [Rowe_600LCM](INFO): Powering down
2018-10-09T16:23:06.726Z,1539102186.726 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2018-10-09T16:23:06.744Z,1539102186.744 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2018-10-09T16:23:06.744Z,1539102186.744 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-10-09T16:23:06.745Z,1539102186.745 [Radio_Surface](INFO): Join timeout helper Thread ID is 927
2018-10-09T16:23:06.968Z,1539102186.968 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2018-10-09T16:23:06.969Z,1