2018-09-25T21:03:55.288Z,1537909435.288 [Supervisor](DEBUG): Initializing supervisor.
2018-09-25T21:03:55.292Z,1537909435.292 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2018-09-25T21:03:55.293Z,1537909435.293 [SyncHandler](INFO): Protected caller Thread ID is 1391
2018-09-25T21:03:55.293Z,1537909435.293 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2018-09-25T21:03:55.294Z,1537909435.294 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2018-09-25T21:03:55.294Z,1537909435.294 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 1392
2018-09-25T21:03:55.298Z,1537909435.298 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2018-09-25T21:03:55.311Z,1537909435.311 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2018-09-25T21:03:55.312Z,1537909435.312 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2018-09-25T21:03:55.312Z,1537909435.312 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 1393
2018-09-25T21:03:55.313Z,1537909435.313 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2018-09-25T21:03:55.314Z,1537909435.314 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2018-09-25T21:03:55.314Z,1537909435.314 [logger ThreadHandler](INFO): Protected caller Thread ID is 1394
2018-09-25T21:03:55.316Z,1537909435.316 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2018-09-25T21:03:55.316Z,1537909435.316 [Supervisor](INFO): Looking for Config files in directory: Config/
2018-09-25T21:03:55.318Z,1537909435.318 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2018-09-25T21:03:55.504Z,1537909435.504 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2018-09-25T21:03:55.505Z,1537909435.505 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2018-09-25T21:03:55.647Z,1537909435.647 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2018-09-25T21:03:55.648Z,1537909435.648 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2018-09-25T21:03:55.991Z,1537909435.991 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2018-09-25T21:03:55.992Z,1537909435.992 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2018-09-25T21:03:56.129Z,1537909436.129 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2018-09-25T21:03:56.129Z,1537909436.129 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2018-09-25T21:03:56.209Z,1537909436.209 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2018-09-25T21:03:56.409Z,1537909436.409 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2018-09-25T21:03:56.409Z,1537909436.409 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2018-09-25T21:03:56.507Z,1537909436.507 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2018-09-25T21:03:56.507Z,1537909436.507 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2018-09-25T21:03:56.864Z,1537909436.864 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2018-09-25T21:03:56.865Z,1537909436.865 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2018-09-25T21:03:57.319Z,1537909437.319 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2018-09-25T21:03:57.319Z,1537909437.319 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2018-09-25T21:03:57.630Z,1537909437.630 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2018-09-25T21:03:57.631Z,1537909437.631 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2018-09-25T21:03:58.287Z,1537909438.287 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2018-09-25T21:03:58.287Z,1537909438.287 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2018-09-25T21:03:58.493Z,1537909438.493 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2018-09-25T21:03:58.493Z,1537909438.493 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2018-09-25T21:03:58.591Z,1537909438.591 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2018-09-25T21:03:58.591Z,1537909438.591 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2018-09-25T21:03:59.078Z,1537909439.078 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2018-09-25T21:03:59.079Z,1537909439.079 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2018-09-25T21:03:59.185Z,1537909439.185 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2018-09-25T21:03:59.187Z,1537909439.187 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/
2018-09-25T21:03:59.188Z,1537909439.188 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Battery.cfg
2018-09-25T21:03:59.415Z,1537909439.415 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2018-09-25T21:03:59.415Z,1537909439.415 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/BIT.cfg
2018-09-25T21:03:59.512Z,1537909439.512 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Navigation.cfg
2018-09-25T21:03:59.605Z,1537909439.605 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Control.cfg
2018-09-25T21:03:59.707Z,1537909439.707 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Simulator.cfg
2018-09-25T21:03:59.792Z,1537909439.792 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Science.cfg
2018-09-25T21:03:59.925Z,1537909439.925 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Sensor.cfg
2018-09-25T21:04:00.092Z,1537909440.092 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Servo.cfg
2018-09-25T21:04:00.202Z,1537909440.202 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/logger.cfg
2018-09-25T21:04:00.286Z,1537909440.286 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/secure.cfg
2018-09-25T21:04:00.368Z,1537909440.368 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/vehicle.cfg
2018-09-25T21:04:00.559Z,1537909440.559 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/root/
2018-09-25T21:04:00.559Z,1537909440.559 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2018-09-25T21:04:00.572Z,1537909440.572 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2018-09-25T21:04:00.702Z,1537909440.702 [SBIT](DEBUG): Construct Startup Built In Test.
2018-09-25T21:04:00.732Z,1537909440.732 [SBIT] Loaded
2018-09-25T21:04:00.733Z,1537909440.733 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2018-09-25T21:04:00.733Z,1537909440.733 [IBIT](DEBUG): Construct Initiated Built In Test.
2018-09-25T21:04:00.760Z,1537909440.760 [IBIT] Loaded
2018-09-25T21:04:00.761Z,1537909440.761 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2018-09-25T21:04:00.764Z,1537909440.764 [CBIT](DEBUG): Construct Continuous Built In Test.
2018-09-25T21:04:00.920Z,1537909440.920 [CBIT] Loaded
2018-09-25T21:04:00.920Z,1537909440.920 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2018-09-25T21:04:00.920Z,1537909440.920 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2018-09-25T21:04:00.921Z,1537909440.921 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2018-09-25T21:04:00.990Z,1537909440.990 [VerticalControl](DEBUG): Construct VerticalControl.
2018-09-25T21:04:01.090Z,1537909441.090 [VerticalControl] Loaded
2018-09-25T21:04:01.090Z,1537909441.090 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2018-09-25T21:04:01.091Z,1537909441.091 [HorizontalControl](DEBUG): Construct HorizontalControl.
2018-09-25T21:04:01.152Z,1537909441.152 [HorizontalControl] Loaded
2018-09-25T21:04:01.152Z,1537909441.152 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2018-09-25T21:04:01.153Z,1537909441.153 [SpeedControl](DEBUG): Construct SpeedControl.
2018-09-25T21:04:01.158Z,1537909441.158 [SpeedControl] Loaded
2018-09-25T21:04:01.159Z,1537909441.159 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2018-09-25T21:04:01.159Z,1537909441.159 [LoopControl](DEBUG): Construct LoopControl.
2018-09-25T21:04:01.160Z,1537909441.160 [LoopControl] Loaded
2018-09-25T21:04:01.160Z,1537909441.160 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2018-09-25T21:04:01.160Z,1537909441.160 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2018-09-25T21:04:01.161Z,1537909441.161 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2018-09-25T21:04:01.204Z,1537909441.204 [DepthRateCalculator] Loaded
2018-09-25T21:04:01.204Z,1537909441.204 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2018-09-25T21:04:01.209Z,1537909441.209 [PitchRateCalculator] Loaded
2018-09-25T21:04:01.210Z,1537909441.210 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2018-09-25T21:04:01.225Z,1537909441.225 [SpeedCalculator] Loaded
2018-09-25T21:04:01.225Z,1537909441.225 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2018-09-25T21:04:01.247Z,1537909441.247 [TempGradientCalculator] Loaded
2018-09-25T21:04:01.247Z,1537909441.247 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2018-09-25T21:04:01.252Z,1537909441.252 [YawRateCalculator] Loaded
2018-09-25T21:04:01.253Z,1537909441.253 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2018-09-25T21:04:01.282Z,1537909441.282 [ElevatorOffsetCalculator] Loaded
2018-09-25T21:04:01.282Z,1537909441.282 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2018-09-25T21:04:01.283Z,1537909441.283 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2018-09-25T21:04:01.283Z,1537909441.283 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2018-09-25T21:04:01.352Z,1537909441.352 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2018-09-25T21:04:01.353Z,1537909441.353 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2018-09-25T21:04:01.598Z,1537909441.598 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2018-09-25T21:04:01.598Z,1537909441.598 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2018-09-25T21:04:01.696Z,1537909441.696 [DeadReckonUsingMultipleVelocitySources] Loaded
2018-09-25T21:04:01.697Z,1537909441.697 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2018-09-25T21:04:01.751Z,1537909441.751 [DeadReckonUsingSpeedCalculator] Loaded
2018-09-25T21:04:01.751Z,1537909441.751 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2018-09-25T21:04:01.768Z,1537909441.768 [NavChart] Loaded
2018-09-25T21:04:01.768Z,1537909441.768 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2018-09-25T21:04:01.772Z,1537909441.772 [UniversalFixResidualReporter] Loaded
2018-09-25T21:04:01.772Z,1537909441.772 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2018-09-25T21:04:01.773Z,1537909441.773 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2018-09-25T21:04:01.773Z,1537909441.773 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2018-09-25T21:04:01.787Z,1537909441.787 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2018-09-25T21:04:01.788Z,1537909441.788 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2018-09-25T21:04:01.960Z,1537909441.960 [Aanderaa_O2] Loaded
2018-09-25T21:04:01.960Z,1537909441.960 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2018-09-25T21:04:02.039Z,1537909442.039 [CTD_NeilBrown] Loaded
2018-09-25T21:04:02.039Z,1537909442.039 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2018-09-25T21:04:02.040Z,1537909442.040 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 406DB4E0
2018-09-25T21:04:02.041Z,1537909442.041 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 1473
2018-09-25T21:04:02.086Z,1537909442.086 [WetLabsSeaOWL_UV_A] Loaded
2018-09-25T21:04:02.086Z,1537909442.086 [ComponentRegistry](DEBUG): Component "WetLabsSeaOWL_UV_A" handled in its own thread.
2018-09-25T21:04:02.087Z,1537909442.087 [WetLabsSeaOWL_UV_A ThreadHandler](DEBUG): Created PCaller Thread at 4070B4E0
2018-09-25T21:04:02.087Z,1537909442.087 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Protected caller Thread ID is 1474
2018-09-25T21:04:02.088Z,1537909442.088 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2018-09-25T21:04:02.088Z,1537909442.088 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2018-09-25T21:04:02.448Z,1537909442.448 [AHRS_M2] Loaded
2018-09-25T21:04:02.449Z,1537909442.449 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2018-09-25T21:04:02.518Z,1537909442.518 [DataOverHttps] Loaded
2018-09-25T21:04:02.518Z,1537909442.518 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2018-09-25T21:04:02.531Z,1537909442.531 [Depth_Keller] Loaded
2018-09-25T21:04:02.532Z,1537909442.532 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2018-09-25T21:04:02.536Z,1537909442.536 [DropWeight] Loaded
2018-09-25T21:04:02.537Z,1537909442.537 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2018-09-25T21:04:02.628Z,1537909442.628 [NAL9602] Loaded
2018-09-25T21:04:02.628Z,1537909442.628 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2018-09-25T21:04:02.634Z,1537909442.634 [Onboard] Loaded
2018-09-25T21:04:02.634Z,1537909442.634 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2018-09-25T21:04:02.641Z,1537909442.641 [Radio_Surface] Loaded
2018-09-25T21:04:02.642Z,1537909442.642 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2018-09-25T21:04:02.643Z,1537909442.643 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4096C4E0
2018-09-25T21:04:02.643Z,1537909442.643 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 1475
2018-09-25T21:04:02.671Z,1537909442.671 [RDI_Pathfinder] Loaded
2018-09-25T21:04:02.671Z,1537909442.671 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread.
2018-09-25T21:04:02.678Z,1537909442.678 [SCPI] Loaded
2018-09-25T21:04:02.678Z,1537909442.678 [ComponentRegistry](DEBUG): SyncComponent "SCPI" handled in the control thread.
2018-09-25T21:04:04.572Z,1537909444.572 [BPC1] Loaded
2018-09-25T21:04:04.572Z,1537909444.572 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2018-09-25T21:04:04.573Z,1537909444.573 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2018-09-25T21:04:04.573Z,1537909444.573 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2018-09-25T21:04:04.675Z,1537909444.675 [BuoyancyServo] Loaded
2018-09-25T21:04:04.675Z,1537909444.675 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2018-09-25T21:04:04.686Z,1537909444.686 [ElevatorServo] Loaded
2018-09-25T21:04:04.687Z,1537909444.687 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2018-09-25T21:04:04.698Z,1537909444.698 [MassServo] Loaded
2018-09-25T21:04:04.698Z,1537909444.698 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2018-09-25T21:04:04.709Z,1537909444.709 [RudderServo] Loaded
2018-09-25T21:04:04.709Z,1537909444.709 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2018-09-25T21:04:04.720Z,1537909444.720 [ThrusterServo] Loaded
2018-09-25T21:04:04.721Z,1537909444.721 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2018-09-25T21:04:04.721Z,1537909444.721 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2018-09-25T21:04:04.722Z,1537909444.722 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2018-09-25T21:04:04.824Z,1537909444.824 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2018-09-25T21:04:04.824Z,1537909444.824 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2018-09-25T21:04:05.015Z,1537909445.015 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2018-09-25T21:04:05.024Z,1537909445.024 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2018-09-25T21:04:05.025Z,1537909445.025 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2018-09-25T21:04:05.044Z,1537909445.044 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2018-09-25T21:04:05.046Z,1537909445.046 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40A154E0
2018-09-25T21:04:05.046Z,1537909445.046 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 1476
2018-09-25T21:04:05.091Z,1537909445.091 [Supervisor](INFO): Main Thread ID is 1255
2018-09-25T21:04:05.091Z,1537909445.091 [Supervisor](DEBUG): Running supervisor.
2018-09-25T21:04:05.092Z,1537909445.092 [CommandLine ThreadHandler](INFO): Handler Thread ID is 1477
2018-09-25T21:04:05.095Z,1537909445.095 [controlThread ThreadHandler](INFO): Handler Thread ID is 1478
2018-09-25T21:04:05.096Z,1537909445.096 [logger ThreadHandler](INFO): Handler Thread ID is 1479
2018-09-25T21:04:05.097Z,1537909445.097 [controlThread](DEBUG): Initializing ControlThread
2018-09-25T21:04:05.098Z,1537909445.098 [SBIT](INFO): Initialize SBIT Component.
2018-09-25T21:04:05.098Z,1537909445.098 [SBIT](IMPORTANT): git: 2018-09-20-9-g075b573
2018-09-25T21:04:05.098Z,1537909445.098 [SBIT](INFO): git hash: 075b5734c445af4803e9159a5ef7aa218c77ab9c
2018-09-25T21:04:05.099Z,1537909445.099 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2018-09-25T21:04:05.099Z,1537909445.099 [SBIT](IMPORTANT): Kernel Version:#2 PREEMPT Thu Jan 11 20:13:48 PST 2018
2018-09-25T21:04:05.100Z,1537909445.100 [SBIT](INFO): Beginning SBIT in 20.000000 seconds.
2018-09-25T21:04:05.101Z,1537909445.101 [IBIT](INFO): Initialize IBIT Component.
2018-09-25T21:04:05.102Z,1537909445.102 [CBIT](DEBUG): Initialize CBIT Component.
2018-09-25T21:04:05.102Z,1537909445.102 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2018-09-25T21:04:05.103Z,1537909445.103 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Handler Thread ID is 1481
2018-09-25T21:04:05.126Z,1537909445.126 [WetLabsSeaOWL_UV_A](INFO): Powering down
2018-09-25T21:04:05.146Z,1537909445.146 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 1482
2018-09-25T21:04:05.152Z,1537909445.152 [Radio_Surface](INFO): Powering up
2018-09-25T21:04:05.163Z,1537909445.163 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 1480
2018-09-25T21:04:05.164Z,1537909445.164 [CTD_NeilBrown](INFO): Powering down
2018-09-25T21:04:05.177Z,1537909445.177 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 1483
2018-09-25T21:04:05.188Z,1537909445.188 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2018-09-25T21:04:05.189Z,1537909445.189 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2018-09-25T21:04:05.189Z,1537909445.189 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2018-09-25T21:04:05.189Z,1537909445.189 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2018-09-25T21:04:05.189Z,1537909445.189 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2018-09-25T21:04:05.189Z,1537909445.189 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2018-09-25T21:04:05.190Z,1537909445.190 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2018-09-25T21:04:05.190Z,1537909445.190 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2018-09-25T21:04:05.190Z,1537909445.190 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2018-09-25T21:04:05.190Z,1537909445.190 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2018-09-25T21:04:05.190Z,1537909445.190 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2018-09-25T21:04:05.191Z,1537909445.191 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2018-09-25T21:04:05.191Z,1537909445.191 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2018-09-25T21:04:05.191Z,1537909445.191 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2018-09-25T21:04:05.191Z,1537909445.191 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2018-09-25T21:04:05.191Z,1537909445.191 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2018-09-25T21:04:05.209Z,1537909445.209 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2018-09-25T21:04:05.211Z,1537909445.211 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2018-09-25T21:04:05.211Z,1537909445.211 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2018-09-25T21:04:05.212Z,1537909445.212 [LoopControl](DEBUG): Initialize LoopControlComponent.
2018-09-25T21:04:05.212Z,1537909445.212 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2018-09-25T21:04:05.212Z,1537909445.212 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2018-09-25T21:04:05.213Z,1537909445.213 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2018-09-25T21:04:05.213Z,1537909445.213 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2018-09-25T21:04:05.214Z,1537909445.214 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2018-09-25T21:04:05.214Z,1537909445.214 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2018-09-25T21:04:05.215Z,1537909445.215 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2018-09-25T21:04:05.216Z,1537909445.216 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s.
2018-09-25T21:04:05.216Z,1537909445.216 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s.
2018-09-25T21:04:05.217Z,1537909445.217 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-09-25T21:04:05.217Z,1537909445.217 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-09-25T21:04:05.217Z,1537909445.217 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-09-25T21:04:05.218Z,1537909445.218 [NavChart](DEBUG): Initialize NavChart Navigation.
2018-09-25T21:04:05.218Z,1537909445.218 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2018-09-25T21:04:05.230Z,1537909445.230 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2018-09-25T21:04:05.259Z,1537909445.259 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2018-09-25T21:04:05.294Z,1537909445.294 [MissionManager](DEBUG):
2018-09-25T21:04:05.295Z,1537909445.295 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2018-09-25T21:04:05.375Z,1537909445.375 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2018-09-25T21:04:05.376Z,1537909445.376 [Default:A.Wait](DEBUG): Construct Wait.
2018-09-25T21:04:05.394Z,1537909445.394 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2018-09-25T21:04:05.421Z,1537909445.421 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2018-09-25T21:04:05.423Z,1537909445.423 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2018-09-25T21:04:05.445Z,1537909445.445 [Default:E.Execute](DEBUG): Construct Execute.
2018-09-25T21:04:05.463Z,1537909445.463 [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-09-25T21:04:05.468Z,1537909445.468 [controlThread](DEBUG): Component order: CycleStarter,Aanderaa_O2,AHRS_M2,DataOverHttps,Depth_Keller,DropWeight,NAL9602,Onboard,RDI_Pathfinder,SCPI,BPC1,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2018-09-25T21:04:05.523Z,1537909445.523 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2018-09-25T21:04:05.612Z,1537909445.612 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2018-09-25T21:04:05.681Z,1537909445.681 [Depth_Keller](ERROR): Pressure reading out of range: 1913.424561 decibar
2018-09-25T21:04:05.852Z,1537909445.852 [DepthRateCalculator](ERROR): Depth measurement is not active
2018-09-25T21:04:05.937Z,1537909445.937 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-09-25T21:04:05.961Z,1537909445.961 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-09-25T21:04:06.073Z,1537909446.073 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2018-09-25T21:04:06.081Z,1537909446.081 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2018-09-25T21:04:06.105Z,1537909446.105 [ElevatorServo](DEBUG): Initializing EZServoServo.
2018-09-25T21:04:06.113Z,1537909446.113 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2018-09-25T21:04:06.127Z,1537909446.127 [MassServo](DEBUG): Initializing EZServoServo.
2018-09-25T21:04:06.133Z,1537909446.133 [MassServo](DEBUG): Initializing MassServo.
2018-09-25T21:04:06.147Z,1537909446.147 [RudderServo](DEBUG): Initializing EZServoServo.
2018-09-25T21:04:06.153Z,1537909446.153 [RudderServo](DEBUG): Initializing RudderServo.
2018-09-25T21:04:06.175Z,1537909446.175 [ThrusterServo](DEBUG): Initializing EZServoServo.
2018-09-25T21:04:06.181Z,1537909446.181 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2018-09-25T21:04:06.381Z,1537909446.381 [DepthRateCalculator](ERROR): Depth measurement is not active
2018-09-25T21:04:06.384Z,1537909446.384 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-09-25T21:04:06.393Z,1537909446.393 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-09-25T21:04:06.717Z,1537909446.717 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-09-25T21:04:06.719Z,1537909446.719 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-09-25T21:04:07.174Z,1537909447.174 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-09-25T21:04:07.175Z,1537909447.175 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-09-25T21:04:07.560Z,1537909447.560 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-09-25T21:04:07.562Z,1537909447.562 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-09-25T21:04:07.964Z,1537909447.964 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-09-25T21:04:07.965Z,1537909447.965 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-09-25T21:04:08.360Z,1537909448.360 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-09-25T21:04:08.361Z,1537909448.361 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-09-25T21:04:08.865Z,1537909448.865 [Aanderaa_O2](INFO): Powering down
2018-09-25T21:04:08.984Z,1537909448.984 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-09-25T21:04:08.985Z,1537909448.985 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-09-25T21:04:09.197Z,1537909449.197 [AHRS_M2](ERROR): Read RFS packet UART error: serial timeout
2018-09-25T21:04:09.236Z,1537909449.236 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-09-25T21:04:09.238Z,1537909449.238 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-09-25T21:04:18.931Z,1537909458.931 [RDI_Pathfinder](ERROR): Failed to parse:Pathfinder
2018-09-25T21:04:25.745Z,1537909465.745 [SBIT](IMPORTANT): Beginning Startup BIT
2018-09-25T21:04:25.758Z,1537909465.758 [CBIT](IMPORTANT): Beginning ground fault scan
2018-09-25T21:04:33.019Z,1537909473.019 [NAL9602](INFO): Powering up NAL9602
2018-09-25T21:04:36.695Z,1537909476.695 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): -0.008662
CHAN A1 (24V): -0.131246
CHAN A2 (12V): -0.007256
CHAN A3 (5V): -0.002160
CHAN B0 (3.3V): 0.000181
CHAN B1 (3.15aV): -0.000145
CHAN B2 (3.15bV): 0.000170
CHAN B3 (GND): 0.002130
OPEN: 0.005224
Full Scale Calc: 4.765 mA, -1.589 mA
2018-09-25T21:04:44.051Z,1537909484.051 [NAL9602](INFO): NAL9602 initialized
2018-09-25T21:05:02.698Z,1537909502.698 [CommandLine](IMPORTANT): got command restart application
2018-09-25T21:05:03.701Z,1537909503.701 [Supervisor](INFO): Stop Mission called by Supervisor::terminate
2018-09-25T21:05:03.704Z,1537909503.704 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2018-09-25T21:05:03.704Z,1537909503.704 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-09-25T21:05:03.873Z,1537909503.873 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye!
2018-09-25T21:05:03.873Z,1537909503.873 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-09-25T21:05:03.875Z,1537909503.875 [CommandLine](INFO): Join timeout helper Thread ID is 1497
2018-09-25T21:05:03.885Z,1537909503.885 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2018-09-25T21:05:03.885Z,1537909503.885 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-09-25T21:05:03.886Z,1537909503.886 [NavChartDb](INFO): Join timeout helper Thread ID is 1498
2018-09-25T21:05:03.970Z,1537909503.970 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2018-09-25T21:05:03.970Z,1537909503.970 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-09-25T21:05:03.981Z,1537909503.981 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2018-09-25T21:05:03.981Z,1537909503.981 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-09-25T21:05:03.981Z,1537909503.981 [Radio_Surface](INFO): Join timeout helper Thread ID is 1499
2018-09-25T21:05:04.201Z,1537909504.201 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2018-09-25T21:05:04.201Z,1537909504.201 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-09-25T21:05:04.205Z,1537909504.205 [ComponentRegistry](INFO): Shutting down WetLabsSeaOWL_UV_A ThreadHandler
2018-09-25T21:05:04.205Z,1537909504.205 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2018-09-25T21:05:04.205Z,1537909504.205 [WetLabsSeaOWL_UV_A](INFO): Join timeout helper Thread ID is 1500
2018-09-25T21:05:04.593Z,1537909504.593 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Uninitializing protected caller thread.
2018-09-25T21:05:04.593Z,1537909504.593 [WetLabsSeaOWL_UV_A](INFO): Powering down
2018-09-25T21:05:04.594Z,1537909504.594 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2018-09-25T21:05:04.597Z,1537909504.597 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2018-09-25T21:05:04.597Z,1537909504.597 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2018-09-25T21:05:04.597Z,1537909504.597 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 1501
2018-09-25T21:05:04.701Z,1537909504.701 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread.
2018-09-25T21:05:04.701Z,1537909504.701 [CTD_NeilBrown](INFO): Powering down
2018-09-25T21:05:04.702Z,1537909504.702 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2018-09-25T21:05:04.722Z,1537909504.722 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2018-09-25T21:05:04.722Z,1537909504.722 [logger ThreadHandler](INFO): Thread cancelled.
2018-09-25T21:05:04.722Z,1537909504.722 [logger](INFO): Join timeout helper Thread ID is 1502
2018-09-25T21:05:04.737Z,1537909504.737 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2018-09-25T21:05:04.737Z,1537909504.737 [logger ThreadHandler](INFO): Thread cancelled.
2018-09-25T21:05:04.742Z,1537909504.742 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2018-09-25T21:05:04.742Z,1537909504.742 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-09-25T21:05:04.742Z,1537909504.742 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2018-09-25T21:05:04.742Z,1537909504.742 [controlThread ThreadHandler](INFO): Thread cancelled.
2018-09-25T21:05:04.742Z,1537909504.742 [controlThread](INFO): Join timeout helper Thread ID is 1503
2018-09-25T21:05:04.837Z,1537909504.837 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2018-09-25T21:05:04.837Z,1537909504.837 [controlThread](DEBUG): Uninitializing ControlThread
2018-09-25T21:05:04.838Z,1537909504.838 [Aanderaa_O2](INFO): Powering down
2018-09-25T21:05:04.839Z,1537909504.839 [AHRS_M2](INFO): Powering down
2018-09-25T21:05:04.910Z,1537909504.910 [NAL9602](INFO): Powering down
2018-09-25T21:05:04.981Z,1537909504.981 [RDI_Pathfinder](INFO): Powering down
2018-09-25T21:05:04.983Z,1537909504.983 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2018-09-25T21:05:04.984Z,1537909504.984 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2018-09-25T21:05:04.984Z,1537909504.984 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2018-09-25T21:05:04.985Z,1537909504.985 [MissionManager](INFO): Uninitializing Mission Default
2018-09-25T21:05:04.988Z,1537909504.988 [MissionManager](INFO): Uninitializing Mission Startup
2018-09-25T21:05:04.989Z,1537909504.989 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2018-09-25T21:05:04.990Z,1537909504.990 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2018-09-25T21:05:04.990Z,1537909504.990 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2018-09-25T21:05:04.990Z,1537909504.990 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2018-09-25T21:05:04.990Z,1537909504.990 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2018-09-25T21:05:04.991Z,1537909504.991 [BuoyancyServo](INFO): Powering down
2018-09-25T21:05:05.005Z,1537909505.005 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2018-09-25T21:05:05.005Z,1537909505.005 [ElevatorServo](INFO): Powering down
2018-09-25T21:05:05.006Z,1537909505.006 [MassServo](DEBUG): Uninitialize Mass Servo.
2018-09-25T21:05:05.006Z,1537909505.006 [MassServo](INFO): Powering down
2018-09-25T21:05:05.007Z,1537909505.007 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2018-09-25T21:05:05.007Z,1537909505.007 [RudderServo](INFO): Powering down
2018-09-25T21:05:05.008Z,1537909505.008 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2018-09-25T21:05:05.008Z,1537909505.008 [ThrusterServo](INFO): Powering down
2018-09-25T21:05:05.009Z,1537909505.009 [SBIT](DEBUG): Uninitialize SBIT Component.
2018-09-25T21:05:05.009Z,1537909505.009 [IBIT](DEBUG): Uninitialize IBIT Component.
2018-09-25T21:05:05.010Z,1537909505.010 [CBIT](DEBUG): Uninitialize CBIT Component.
2018-09-25T21:05:05.011Z,1537909505.011 [controlThread ThreadHandler](INFO): Thread cancelled.
2018-09-25T21:05:05.067Z,1537909505.067 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2018-09-25T21:05:05.071Z,1537909505.071 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2018-09-25T21:05:05.130Z,1537909505.130 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-09-25T21:05:05.171Z,1537909505.171 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-09-25T21:05:05.227Z,1537909505.227 [logger ThreadHandler](INFO): Thread cancelled.