2018-09-24T20:41:55.331Z,1537821715.331 [Supervisor](DEBUG): Initializing supervisor.
2018-09-24T20:41:55.334Z,1537821715.334 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2018-09-24T20:41:55.335Z,1537821715.335 [SyncHandler](INFO): Protected caller Thread ID is 3236
2018-09-24T20:41:55.335Z,1537821715.335 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2018-09-24T20:41:55.336Z,1537821715.336 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2018-09-24T20:41:55.336Z,1537821715.336 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 3237
2018-09-24T20:41:55.339Z,1537821715.339 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2018-09-24T20:41:55.351Z,1537821715.351 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2018-09-24T20:41:55.352Z,1537821715.352 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2018-09-24T20:41:55.352Z,1537821715.352 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 3238
2018-09-24T20:41:55.353Z,1537821715.353 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2018-09-24T20:41:55.354Z,1537821715.354 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2018-09-24T20:41:55.354Z,1537821715.354 [logger ThreadHandler](INFO): Protected caller Thread ID is 3239
2018-09-24T20:41:55.356Z,1537821715.356 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2018-09-24T20:41:55.357Z,1537821715.357 [Supervisor](INFO): Looking for Config files in directory: Config/
2018-09-24T20:41:55.358Z,1537821715.358 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2018-09-24T20:41:55.565Z,1537821715.565 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2018-09-24T20:41:55.565Z,1537821715.565 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2018-09-24T20:41:55.736Z,1537821715.736 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2018-09-24T20:41:55.737Z,1537821715.737 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2018-09-24T20:41:56.113Z,1537821716.113 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2018-09-24T20:41:56.114Z,1537821716.114 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2018-09-24T20:41:56.259Z,1537821716.259 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2018-09-24T20:41:56.260Z,1537821716.260 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2018-09-24T20:41:56.343Z,1537821716.343 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2018-09-24T20:41:56.557Z,1537821716.557 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2018-09-24T20:41:56.557Z,1537821716.557 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2018-09-24T20:41:56.659Z,1537821716.659 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2018-09-24T20:41:56.659Z,1537821716.659 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2018-09-24T20:41:57.028Z,1537821717.028 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2018-09-24T20:41:57.029Z,1537821717.029 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2018-09-24T20:41:57.517Z,1537821717.517 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2018-09-24T20:41:57.518Z,1537821717.518 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2018-09-24T20:41:57.855Z,1537821717.855 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2018-09-24T20:41:57.855Z,1537821717.855 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2018-09-24T20:41:58.390Z,1537821718.390 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2018-09-24T20:41:58.390Z,1537821718.390 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2018-09-24T20:41:58.616Z,1537821718.616 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2018-09-24T20:41:58.617Z,1537821718.617 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2018-09-24T20:41:58.719Z,1537821718.719 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2018-09-24T20:41:58.720Z,1537821718.720 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2018-09-24T20:41:59.242Z,1537821719.242 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2018-09-24T20:41:59.242Z,1537821719.242 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2018-09-24T20:41:59.354Z,1537821719.354 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2018-09-24T20:41:59.355Z,1537821719.355 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/
2018-09-24T20:41:59.356Z,1537821719.356 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Battery.cfg
2018-09-24T20:41:59.593Z,1537821719.593 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2018-09-24T20:41:59.594Z,1537821719.594 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/BIT.cfg
2018-09-24T20:41:59.696Z,1537821719.696 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Navigation.cfg
2018-09-24T20:41:59.793Z,1537821719.793 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Control.cfg
2018-09-24T20:41:59.900Z,1537821719.900 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Simulator.cfg
2018-09-24T20:41:59.988Z,1537821719.988 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Science.cfg
2018-09-24T20:42:00.131Z,1537821720.131 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Sensor.cfg
2018-09-24T20:42:00.311Z,1537821720.311 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Servo.cfg
2018-09-24T20:42:00.426Z,1537821720.426 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/logger.cfg
2018-09-24T20:42:00.513Z,1537821720.513 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/secure.cfg
2018-09-24T20:42:00.606Z,1537821720.606 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/vehicle.cfg
2018-09-24T20:42:00.864Z,1537821720.864 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2018-09-24T20:42:00.880Z,1537821720.880 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2018-09-24T20:42:01.013Z,1537821721.013 [SBIT](DEBUG): Construct Startup Built In Test.
2018-09-24T20:42:01.044Z,1537821721.044 [SBIT] Loaded
2018-09-24T20:42:01.045Z,1537821721.045 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2018-09-24T20:42:01.045Z,1537821721.045 [IBIT](DEBUG): Construct Initiated Built In Test.
2018-09-24T20:42:01.074Z,1537821721.074 [IBIT] Loaded
2018-09-24T20:42:01.074Z,1537821721.074 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2018-09-24T20:42:01.077Z,1537821721.077 [CBIT](DEBUG): Construct Continuous Built In Test.
2018-09-24T20:42:01.238Z,1537821721.238 [CBIT] Loaded
2018-09-24T20:42:01.239Z,1537821721.239 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2018-09-24T20:42:01.239Z,1537821721.239 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2018-09-24T20:42:01.240Z,1537821721.240 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2018-09-24T20:42:01.309Z,1537821721.309 [VerticalControl](DEBUG): Construct VerticalControl.
2018-09-24T20:42:01.413Z,1537821721.413 [VerticalControl] Loaded
2018-09-24T20:42:01.413Z,1537821721.413 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2018-09-24T20:42:01.414Z,1537821721.414 [HorizontalControl](DEBUG): Construct HorizontalControl.
2018-09-24T20:42:01.526Z,1537821721.526 [HorizontalControl] Loaded
2018-09-24T20:42:01.526Z,1537821721.526 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2018-09-24T20:42:01.527Z,1537821721.527 [SpeedControl](DEBUG): Construct SpeedControl.
2018-09-24T20:42:01.541Z,1537821721.541 [SpeedControl] Loaded
2018-09-24T20:42:01.542Z,1537821721.542 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2018-09-24T20:42:01.542Z,1537821721.542 [LoopControl](DEBUG): Construct LoopControl.
2018-09-24T20:42:01.543Z,1537821721.543 [LoopControl] Loaded
2018-09-24T20:42:01.543Z,1537821721.543 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2018-09-24T20:42:01.543Z,1537821721.543 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2018-09-24T20:42:01.544Z,1537821721.544 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2018-09-24T20:42:01.586Z,1537821721.586 [DepthRateCalculator] Loaded
2018-09-24T20:42:01.586Z,1537821721.586 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2018-09-24T20:42:01.592Z,1537821721.592 [PitchRateCalculator] Loaded
2018-09-24T20:42:01.592Z,1537821721.592 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2018-09-24T20:42:01.608Z,1537821721.608 [SpeedCalculator] Loaded
2018-09-24T20:42:01.609Z,1537821721.609 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2018-09-24T20:42:01.631Z,1537821721.631 [TempGradientCalculator] Loaded
2018-09-24T20:42:01.631Z,1537821721.631 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2018-09-24T20:42:01.637Z,1537821721.637 [YawRateCalculator] Loaded
2018-09-24T20:42:01.637Z,1537821721.637 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2018-09-24T20:42:01.667Z,1537821721.667 [ElevatorOffsetCalculator] Loaded
2018-09-24T20:42:01.668Z,1537821721.668 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2018-09-24T20:42:01.668Z,1537821721.668 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2018-09-24T20:42:01.669Z,1537821721.669 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2018-09-24T20:42:01.734Z,1537821721.734 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2018-09-24T20:42:01.735Z,1537821721.735 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2018-09-24T20:42:01.986Z,1537821721.986 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2018-09-24T20:42:01.986Z,1537821721.986 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2018-09-24T20:42:02.086Z,1537821722.086 [DeadReckonUsingMultipleVelocitySources] Loaded
2018-09-24T20:42:02.086Z,1537821722.086 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2018-09-24T20:42:02.143Z,1537821722.143 [DeadReckonUsingSpeedCalculator] Loaded
2018-09-24T20:42:02.143Z,1537821722.143 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2018-09-24T20:42:02.160Z,1537821722.160 [NavChart] Loaded
2018-09-24T20:42:02.160Z,1537821722.160 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2018-09-24T20:42:02.164Z,1537821722.164 [UniversalFixResidualReporter] Loaded
2018-09-24T20:42:02.165Z,1537821722.165 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2018-09-24T20:42:02.165Z,1537821722.165 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2018-09-24T20:42:02.166Z,1537821722.166 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2018-09-24T20:42:02.179Z,1537821722.179 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2018-09-24T20:42:02.180Z,1537821722.180 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2018-09-24T20:42:02.382Z,1537821722.382 [WetLabsSeaOWL_UV_A] Loaded
2018-09-24T20:42:02.382Z,1537821722.382 [ComponentRegistry](DEBUG): Component "WetLabsSeaOWL_UV_A" handled in its own thread.
2018-09-24T20:42:02.383Z,1537821722.383 [WetLabsSeaOWL_UV_A ThreadHandler](DEBUG): Created PCaller Thread at 406DB4E0
2018-09-24T20:42:02.384Z,1537821722.384 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Protected caller Thread ID is 3318
2018-09-24T20:42:02.384Z,1537821722.384 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2018-09-24T20:42:02.385Z,1537821722.385 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2018-09-24T20:42:02.696Z,1537821722.696 [AHRS_M2] Loaded
2018-09-24T20:42:02.697Z,1537821722.697 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2018-09-24T20:42:02.767Z,1537821722.767 [DataOverHttps] Loaded
2018-09-24T20:42:02.767Z,1537821722.767 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2018-09-24T20:42:02.781Z,1537821722.781 [Depth_Keller] Loaded
2018-09-24T20:42:02.781Z,1537821722.781 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2018-09-24T20:42:02.786Z,1537821722.786 [DropWeight] Loaded
2018-09-24T20:42:02.786Z,1537821722.786 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2018-09-24T20:42:02.880Z,1537821722.880 [NAL9602] Loaded
2018-09-24T20:42:02.880Z,1537821722.880 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2018-09-24T20:42:02.886Z,1537821722.886 [Onboard] Loaded
2018-09-24T20:42:02.886Z,1537821722.886 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2018-09-24T20:42:02.893Z,1537821722.893 [Radio_Surface] Loaded
2018-09-24T20:42:02.893Z,1537821722.893 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2018-09-24T20:42:02.895Z,1537821722.895 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4093C4E0
2018-09-24T20:42:02.895Z,1537821722.895 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 3319
2018-09-24T20:42:02.925Z,1537821722.925 [RDI_Pathfinder] Loaded
2018-09-24T20:42:02.925Z,1537821722.925 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread.
2018-09-24T20:42:02.932Z,1537821722.932 [SCPI] Loaded
2018-09-24T20:42:02.932Z,1537821722.932 [ComponentRegistry](DEBUG): SyncComponent "SCPI" handled in the control thread.
2018-09-24T20:42:04.803Z,1537821724.803 [BPC1] Loaded
2018-09-24T20:42:04.803Z,1537821724.803 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2018-09-24T20:42:04.804Z,1537821724.804 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2018-09-24T20:42:04.804Z,1537821724.804 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2018-09-24T20:42:04.907Z,1537821724.907 [BuoyancyServo] Loaded
2018-09-24T20:42:04.907Z,1537821724.907 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2018-09-24T20:42:04.919Z,1537821724.919 [ElevatorServo] Loaded
2018-09-24T20:42:04.919Z,1537821724.919 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2018-09-24T20:42:04.931Z,1537821724.931 [MassServo] Loaded
2018-09-24T20:42:04.931Z,1537821724.931 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2018-09-24T20:42:04.943Z,1537821724.943 [RudderServo] Loaded
2018-09-24T20:42:04.943Z,1537821724.943 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2018-09-24T20:42:04.954Z,1537821724.954 [ThrusterServo] Loaded
2018-09-24T20:42:04.955Z,1537821724.955 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2018-09-24T20:42:04.955Z,1537821724.955 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2018-09-24T20:42:04.956Z,1537821724.956 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2018-09-24T20:42:05.062Z,1537821725.062 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2018-09-24T20:42:05.063Z,1537821725.063 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2018-09-24T20:42:05.087Z,1537821725.087 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2018-09-24T20:42:05.091Z,1537821725.091 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2018-09-24T20:42:05.092Z,1537821725.092 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2018-09-24T20:42:05.099Z,1537821725.099 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2018-09-24T20:42:05.100Z,1537821725.100 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 409E54E0
2018-09-24T20:42:05.100Z,1537821725.100 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 3320
2018-09-24T20:42:05.105Z,1537821725.105 [Supervisor](INFO): Main Thread ID is 795
2018-09-24T20:42:05.105Z,1537821725.105 [Supervisor](DEBUG): Running supervisor.
2018-09-24T20:42:05.105Z,1537821725.105 [CommandLine ThreadHandler](INFO): Handler Thread ID is 3321
2018-09-24T20:42:05.108Z,1537821725.108 [controlThread ThreadHandler](INFO): Handler Thread ID is 3322
2018-09-24T20:42:05.108Z,1537821725.108 [controlThread](DEBUG): Initializing ControlThread
2018-09-24T20:42:05.109Z,1537821725.109 [SBIT](INFO): Initialize SBIT Component.
2018-09-24T20:42:05.109Z,1537821725.109 [SBIT](IMPORTANT): git: 2018-09-20
2018-09-24T20:42:05.110Z,1537821725.110 [SBIT](INFO): git hash: cc82e4f04ca47b19cdcc10b5d3e1760510b3ba6f
2018-09-24T20:42:05.110Z,1537821725.110 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2018-09-24T20:42:05.110Z,1537821725.110 [SBIT](IMPORTANT): Kernel Version:#2 PREEMPT Thu Jan 11 20:13:48 PST 2018
2018-09-24T20:42:05.111Z,1537821725.111 [SBIT](INFO): Beginning SBIT in 20.000000 seconds.
2018-09-24T20:42:05.112Z,1537821725.112 [IBIT](INFO): Initialize IBIT Component.
2018-09-24T20:42:05.113Z,1537821725.113 [CBIT](DEBUG): Initialize CBIT Component.
2018-09-24T20:42:05.113Z,1537821725.113 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2018-09-24T20:42:05.114Z,1537821725.114 [logger ThreadHandler](INFO): Handler Thread ID is 3323
2018-09-24T20:42:05.141Z,1537821725.141 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Handler Thread ID is 3324
2018-09-24T20:42:05.143Z,1537821725.143 [WetLabsSeaOWL_UV_A](INFO): Powering down
2018-09-24T20:42:05.174Z,1537821725.174 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 3325
2018-09-24T20:42:05.180Z,1537821725.180 [Radio_Surface](INFO): Powering up
2018-09-24T20:42:05.186Z,1537821725.186 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 3326
2018-09-24T20:42:05.189Z,1537821725.189 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2018-09-24T20:42:05.189Z,1537821725.189 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2018-09-24T20:42:05.189Z,1537821725.189 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2018-09-24T20:42:05.189Z,1537821725.189 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2018-09-24T20:42:05.190Z,1537821725.190 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2018-09-24T20:42:05.190Z,1537821725.190 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2018-09-24T20:42:05.190Z,1537821725.190 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2018-09-24T20:42:05.190Z,1537821725.190 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2018-09-24T20:42:05.190Z,1537821725.190 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2018-09-24T20:42:05.191Z,1537821725.191 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2018-09-24T20:42:05.191Z,1537821725.191 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2018-09-24T20:42:05.191Z,1537821725.191 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2018-09-24T20:42:05.191Z,1537821725.191 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2018-09-24T20:42:05.191Z,1537821725.191 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2018-09-24T20:42:05.192Z,1537821725.192 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2018-09-24T20:42:05.192Z,1537821725.192 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2018-09-24T20:42:05.221Z,1537821725.221 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2018-09-24T20:42:05.223Z,1537821725.223 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2018-09-24T20:42:05.223Z,1537821725.223 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2018-09-24T20:42:05.224Z,1537821725.224 [LoopControl](DEBUG): Initialize LoopControlComponent.
2018-09-24T20:42:05.224Z,1537821725.224 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2018-09-24T20:42:05.224Z,1537821725.224 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2018-09-24T20:42:05.225Z,1537821725.225 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2018-09-24T20:42:05.225Z,1537821725.225 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2018-09-24T20:42:05.226Z,1537821725.226 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2018-09-24T20:42:05.226Z,1537821725.226 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2018-09-24T20:42:05.227Z,1537821725.227 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2018-09-24T20:42:05.228Z,1537821725.228 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s.
2018-09-24T20:42:05.228Z,1537821725.228 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s.
2018-09-24T20:42:05.228Z,1537821725.228 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-09-24T20:42:05.229Z,1537821725.229 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-09-24T20:42:05.229Z,1537821725.229 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-09-24T20:42:05.230Z,1537821725.230 [NavChart](DEBUG): Initialize NavChart Navigation.
2018-09-24T20:42:05.230Z,1537821725.230 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2018-09-24T20:42:05.238Z,1537821725.238 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2018-09-24T20:42:05.270Z,1537821725.270 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2018-09-24T20:42:05.313Z,1537821725.313 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Units="Tethys/Units"
       xmlns:Universal="Tethys/Universal"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
       Id="Startup">

    <Guidance:GoToSurface>
        <Progression/>
    </Guidance:GoToSurface>

    <Aggregate Id="StartupSatComms">

        <Sequence/>

        <ReadDatum>
            <Timeout Duration="P1M" />
            <Universal:latitude_fix/>
        </ReadDatum>

        <ReadDatum>
            <Timeout Duration="P1M" />
            <Universal:platform_communications/>
        </ReadDatum>

    </Aggregate>

</Mission>


2018-09-24T20:42:05.314Z,1537821725.314 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2018-09-24T20:42:05.389Z,1537821725.389 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2018-09-24T20:42:05.391Z,1537821725.391 [Default:A.Wait](DEBUG): Construct Wait.
2018-09-24T20:42:05.392Z,1537821725.392 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2018-09-24T20:42:05.439Z,1537821725.439 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2018-09-24T20:42:05.442Z,1537821725.442 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2018-09-24T20:42:05.448Z,1537821725.448 [Default:E.Execute](DEBUG): Construct Execute.
2018-09-24T20:42:05.467Z,1537821725.467 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Universal="Tethys/Universal"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                             Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                             Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
         Id="Default">

    <DefineArg Name="ElapsedSinceDefaultStarted"><Units:minute/><Value>0</Value></DefineArg>

    <Guidance:Wait>
        <Description>
            Wait a moment to see if the scheduler starts a new mission before
            starting to actually run Default.
        </Description>
        <Sequence/>
        <Setting><Guidance:Wait.duration/><Units:second/><Value>13</Value></Setting>
    </Guidance:Wait>

    <Guidance:GoToSurface>
        <Progression/>
    </Guidance:GoToSurface>

    <Aggregate Id="CheckIn">

        <Sequence Repeat="288"/>

        <ReadDatum Id="Read_GPS">
            <Timeout Duration="P5M"/>
            <Universal:time_fix/>
        </ReadDatum>

        <ReadDatum Id="Read_Iridium">
            <Timeout Duration="P2H">
                <Guidance:Execute>
                    <Sequence/>
                    <Setting><Guidance:Execute.command/><String>Burn on</String></Setting>
                </Guidance:Execute>
                <Syslog Severity="Critical">Dropped weight due to communications timeout.</Syslog>
            </Timeout>
            <Universal:platform_communications/>
        </ReadDatum>

        <Guidance:Wait>
            <Sequence/>
            <Setting><Guidance:Wait.duration/><Units:minute/><Value>5</Value></Setting>
        </Guidance:Wait>

        <Assign><Sequence/><Arg Name="ElapsedSinceDefaultStarted"/><Elapsed><Universal:mission_started/></Elapsed></Assign>

        <Syslog Severity="Important">Default mission has been running for <Arg Name="ElapsedSinceDefaultStarted"/><Units:minute/></Syslog>

    </Aggregate>

    <Syslog Severity="Important">Restarting logs and Default mission.</Syslog>

    <Guidance:Execute>
        <Sequence/>
        <Setting><Guidance:Execute.command/><String>restart logs</String></Setting>
    </Guidance:Execute>

</Mission>


2018-09-24T20:42:05.472Z,1537821725.472 [controlThread](DEBUG): Component order: CycleStarter,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-24T20:42:05.525Z,1537821725.525 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2018-09-24T20:42:05.592Z,1537821725.592 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2018-09-24T20:42:05.630Z,1537821725.630 [Depth_Keller](ERROR): Pressure reading out of range: 1913.424561 decibar
2018-09-24T20:42:05.819Z,1537821725.819 [DepthRateCalculator](ERROR): Depth measurement is not active
2018-09-24T20:42:05.892Z,1537821725.892 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-09-24T20:42:05.916Z,1537821725.916 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-09-24T20:42:06.031Z,1537821726.031 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2018-09-24T20:42:06.037Z,1537821726.037 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2018-09-24T20:42:06.051Z,1537821726.051 [ElevatorServo](DEBUG): Initializing EZServoServo.
2018-09-24T20:42:06.057Z,1537821726.057 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2018-09-24T20:42:06.063Z,1537821726.063 [MassServo](DEBUG): Initializing EZServoServo.
2018-09-24T20:42:06.069Z,1537821726.069 [MassServo](DEBUG): Initializing MassServo.
2018-09-24T20:42:06.083Z,1537821726.083 [RudderServo](DEBUG): Initializing EZServoServo.
2018-09-24T20:42:06.089Z,1537821726.089 [RudderServo](DEBUG): Initializing RudderServo.
2018-09-24T20:42:06.107Z,1537821726.107 [ThrusterServo](DEBUG): Initializing EZServoServo.
2018-09-24T20:42:06.109Z,1537821726.109 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2018-09-24T20:42:06.321Z,1537821726.321 [DepthRateCalculator](ERROR): Depth measurement is not active
2018-09-24T20:42:06.324Z,1537821726.324 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-09-24T20:42:06.325Z,1537821726.325 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-09-24T20:42:06.632Z,1537821726.632 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-09-24T20:42:06.633Z,1537821726.633 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-09-24T20:42:06.965Z,1537821726.965 [BuoyancyServo](ERROR): Buoyancy initialization uart error serial timeout
2018-09-24T20:42:06.965Z,1537821726.965 [BuoyancyServo](FAULT): Buoyancy failed to initialize
2018-09-24T20:42:06.965Z,1537821726.965 [BuoyancyServo] Communications Fault, FailCount= 1
2018-09-24T20:42:06.965Z,1537821726.965 [BuoyancyServo](ERROR): Communications Fault
2018-09-24T20:42:07.173Z,1537821727.173 [CBIT](ERROR): Communications Fault in component: BuoyancyServo
2018-09-24T20:42:07.229Z,1537821727.229 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-09-24T20:42:07.237Z,1537821727.237 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-09-24T20:42:07.251Z,1537821727.251 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2018-09-24T20:42:07.252Z,1537821727.252 [BuoyancyServo](INFO): Powering down
2018-09-24T20:42:07.612Z,1537821727.612 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-09-24T20:42:07.613Z,1537821727.613 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-09-24T20:42:08.010Z,1537821728.010 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-09-24T20:42:08.011Z,1537821728.011 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-09-24T20:42:08.408Z,1537821728.408 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-09-24T20:42:08.411Z,1537821728.411 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-09-24T20:42:08.840Z,1537821728.840 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-09-24T20:42:08.841Z,1537821728.841 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-09-24T20:42:09.318Z,1537821729.318 [CBIT](INFO): Clearing failed state for component BuoyancyServo
2018-09-24T20:42:09.319Z,1537821729.319 [BuoyancyServo] No Fault, FailCount= 1
2018-09-24T20:42:09.637Z,1537821729.637 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2018-09-24T20:42:09.758Z,1537821729.758 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2018-09-24T20:42:19.241Z,1537821739.241 [RDI_Pathfinder](ERROR): Failed to parse:Pathfinder
2018-09-24T20:42:25.664Z,1537821745.664 [SBIT](IMPORTANT): Beginning Startup BIT
2018-09-24T20:42:25.676Z,1537821745.676 [CBIT](IMPORTANT): Beginning ground fault scan
2018-09-24T20:42:32.939Z,1537821752.939 [NAL9602](INFO): Powering up NAL9602
2018-09-24T20:42:36.651Z,1537821756.651 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.025292
CHAN A1 (24V): -0.027719
CHAN A2 (12V): -0.007032
CHAN A3 (5V): -0.002169
CHAN B0 (3.3V): -0.000071
CHAN B1 (3.15aV): 0.000416
CHAN B2 (3.15bV): 0.000143
CHAN B3 (GND): 0.002091
OPEN: 0.004982
Full Scale Calc: 4.765 mA, -1.589 mA
2018-09-24T20:42:43.951Z,1537821763.951 [NAL9602](INFO): NAL9602 initialized
2018-09-24T20:42:59.144Z,1537821779.144 [NAL9602](INFO): SBD MO Status=0, MOMSN=1620, MT Status=0, MTMSN=0
2018-09-24T20:42:59.144Z,1537821779.144 [NAL9602](INFO): No messages in MT queue
2018-09-24T20:43:19.723Z,1537821799.723 [SBIT](IMPORTANT): SBIT PASSED
2018-09-24T20:43:19.768Z,1537821799.768 [CommandLine](IMPORTANT): got command configSet list
2018-09-24T20:43:19.768Z,1537821799.768 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2018-09-24T20:43:19.769Z,1537821799.769 [CommandLine](IMPORTANT): Aanderaa_O2.loadAtStartup=0 bool;

2018-09-24T20:43:19.769Z,1537821799.769 [CommandLine](IMPORTANT): BPC1.batterySamplingInterval=1 hour;

2018-09-24T20:43:19.769Z,1537821799.769 [CommandLine](IMPORTANT): BuoyancyServo.accel=400 none;

2018-09-24T20:43:19.769Z,1537821799.769 [CommandLine](IMPORTANT): BuoyancyServo.fastPumpCoefficient=1 none;

2018-09-24T20:43:19.769Z,1537821799.769 [CommandLine](IMPORTANT): BuoyancyServo.velocity=300 none;

2018-09-24T20:43:19.770Z,1537821799.770 [CommandLine](IMPORTANT): CTD_NeilBrown.loadAtStartup=0 bool;

2018-09-24T20:43:19.770Z,1537821799.770 [CommandLine](IMPORTANT): CTD_NeilBrown.simulateHardware=1 bool;

2018-09-24T20:43:19.770Z,1537821799.770 [CommandLine](IMPORTANT): CTD_Seabird.loadAtStartup=0 bool;

2018-09-24T20:43:19.770Z,1537821799.770 [CommandLine](IMPORTANT): CTD_Seabird.simulateHardware=1 bool;

2018-09-24T20:43:19.770Z,1537821799.770 [CommandLine](IMPORTANT): Express linearApproximation RDI_Pathfinder.height_above_sea_floor 5.000000 meter;

2018-09-24T20:43:19.770Z,1537821799.770 [CommandLine](IMPORTANT): Express linearApproximation WetLabsSeaOWL_UV_A.mass_concentration_of_chlorophyll_in_sea_water 0.500000 microgram_per_liter;

2018-09-24T20:43:19.770Z,1537821799.770 [CommandLine](IMPORTANT): Express linearApproximation height_above_sea_floor 5.000000 meter;

2018-09-24T20:43:19.771Z,1537821799.771 [CommandLine](IMPORTANT): IBIT.batteryVoltageThreshold=13.7 volt;

2018-09-24T20:43:19.771Z,1537821799.771 [CommandLine](IMPORTANT): RDI_PathfinderUp.loadAtStartup=0 bool;

2018-09-24T20:43:19.771Z,1537821799.771 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral=205 cubic_centimeter;

2018-09-24T20:43:19.771Z,1537821799.771 [CommandLine](IMPORTANT): VerticalControl.massDefault=0 millimeter;

2018-09-24T20:43:19.771Z,1537821799.771 [CommandLine](IMPORTANT): WetLabsBB2FL.loadAtStartup=0 bool;

2018-09-24T20:43:19.771Z,1537821799.771 [CommandLine](IMPORTANT): WetLabsBB2FL.simulateHardware=0 bool;

2018-09-24T20:43:20.120Z,1537821800.120 [MissionManager](IMPORTANT): Started mission Startup
2018-09-24T20:43:20.125Z,1537821800.125 [Startup] Running Loop=1
2018-09-24T20:43:20.125Z,1537821800.125 [Startup](DEBUG): Aggregate::initialize Startup
2018-09-24T20:43:20.125Z,1537821800.125 [Startup:A.GoToSurface] Running Loop=1
2018-09-24T20:43:20.125Z,1537821800.125 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-09-24T20:43:20.126Z,1537821800.126 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2018-09-24T20:43:20.126Z,1537821800.126 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2018-09-24T20:43:20.127Z,1537821800.127 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2018-09-24T20:43:20.127Z,1537821800.127 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-09-24T20:43:20.127Z,1537821800.127 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2018-09-24T20:43:20.142Z,1537821800.142 [Startup:StartupSatComms] Running Loop=1
2018-09-24T20:43:20.142Z,1537821800.142 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2018-09-24T20:43:20.142Z,1537821800.142 [Startup:StartupSatComms:A] Running Loop=1
2018-09-24T20:43:20.513Z,1537821800.513 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2018-09-24T20:44:20.582Z,1537821860.582 [Startup:StartupSatComms:A](INFO): Timed out from 2018-09-24T20:43:20.1Z
2018-09-24T20:44:20.582Z,1537821860.582 [Startup:StartupSatComms:A] Stopped
2018-09-24T20:44:20.583Z,1537821860.583 [Startup:StartupSatComms:B] Running Loop=1
2018-09-24T20:44:20.986Z,1537821860.986 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2018-09-24T20:44:45.120Z,1537821885.120 [NAL9602](INFO): SBD MO Status=1, MOMSN=1621, MT Status=0, MTMSN=0
2018-09-24T20:44:45.173Z,1537821885.173 [NAL9602](INFO): Sent 189 bytes from file Logs/20180924T203303/Courier0007.lzma
2018-09-24T20:44:45.173Z,1537821885.173 [NAL9602](INFO): Packets left to send: 0
2018-09-24T20:44:45.175Z,1537821885.175 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180924T203303/Courier0007.lzma.parts/0000.sbd
2018-09-24T20:44:45.175Z,1537821885.175 [NAL9602](DEBUG): Completed sending Logs/20180924T203303/Courier0007.lzma
2018-09-24T20:44:56.564Z,1537821896.564 [NAL9602](INFO): SBD MO Status=1, MOMSN=1622, MT Status=0, MTMSN=0
2018-09-24T20:44:56.617Z,1537821896.617 [NAL9602](INFO): Sent 332 bytes from file Logs/20180924T203303/Express0005.lzma
2018-09-24T20:44:56.617Z,1537821896.617 [NAL9602](INFO): Packets left to send: 1
2018-09-24T20:44:56.619Z,1537821896.619 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180924T203303/Express0005.lzma.parts/0001.sbd
2018-09-24T20:45:05.531Z,1537821905.531 [DeadReckonUsingMultipleVelocitySources](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-09-24T20:45:05.532Z,1537821905.532 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2018-09-24T20:45:05.532Z,1537821905.532 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2018-09-24T20:45:05.538Z,1537821905.538 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-09-24T20:45:05.538Z,1537821905.538 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 1
2018-09-24T20:45:05.538Z,1537821905.538 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-09-24T20:45:05.567Z,1537821905.567 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2018-09-24T20:45:05.568Z,1537821905.568 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-09-24T20:45:05.928Z,1537821905.928 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2018-09-24T20:45:05.928Z,1537821905.928 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2018-09-24T20:45:05.928Z,1537821905.928 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-09-24T20:45:05.928Z,1537821905.928 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 1
2018-09-24T20:45:06.342Z,1537821906.342 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2018-09-24T20:45:06.342Z,1537821906.342 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s.
2018-09-24T20:45:06.343Z,1537821906.343 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s.
2018-09-24T20:45:06.343Z,1537821906.343 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-09-24T20:45:06.343Z,1537821906.343 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-09-24T20:45:06.344Z,1537821906.344 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-09-24T20:45:13.096Z,1537821913.096 [NAL9602](INFO): SBD MO Status=1, MOMSN=1623, MT Status=0, MTMSN=0
2018-09-24T20:45:13.153Z,1537821913.153 [NAL9602](INFO): Sent 223 bytes from file Logs/20180924T203303/Express0005.lzma
2018-09-24T20:45:13.153Z,1537821913.153 [NAL9602](INFO): Packets left to send: 0
2018-09-24T20:45:13.154Z,1537821913.154 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180924T203303/Express0005.lzma.parts/0000.sbd
2018-09-24T20:45:13.155Z,1537821913.155 [NAL9602](DEBUG): Completed sending Logs/20180924T203303/Express0005.lzma
2018-09-24T20:45:20.979Z,1537821920.979 [Startup:StartupSatComms:B](INFO): Timed out from 2018-09-24T20:44:20.6Z
2018-09-24T20:45:20.979Z,1537821920.979 [Startup:StartupSatComms:B] Stopped
2018-09-24T20:45:20.980Z,1537821920.980 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2018-09-24T20:45:20.980Z,1537821920.980 [Startup:StartupSatComms] Stopped
2018-09-24T20:45:20.980Z,1537821920.980 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2018-09-24T20:45:20.981Z,1537821920.981 [Startup](INFO): Completed Startup
2018-09-24T20:45:20.981Z,1537821920.981 [MissionManager](INFO): Startup is completed.
2018-09-24T20:45:20.981Z,1537821920.981 [MissionManager](INFO): Uninitializing Mission Startup
2018-09-24T20:45:20.981Z,1537821920.981 [Startup] Stopped
2018-09-24T20:45:20.982Z,1537821920.982 [Startup](DEBUG): Aggregate::uninitialize Startup
2018-09-24T20:45:20.982Z,1537821920.982 [Startup:A.GoToSurface] Stopped
2018-09-24T20:45:20.982Z,1537821920.982 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2018-09-24T20:45:21.368Z,1537821921.368 [MissionManager](IMPORTANT): Started mission Default
2018-09-24T20:45:21.373Z,1537821921.373 [Default] Running Loop=1
2018-09-24T20:45:21.373Z,1537821921.373 [Default](DEBUG): Aggregate::initialize Default
2018-09-24T20:45:21.373Z,1537821921.373 [Default:B.GoToSurface] Running Loop=1
2018-09-24T20:45:21.373Z,1537821921.373 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-09-24T20:45:21.373Z,1537821921.373 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2018-09-24T20:45:21.374Z,1537821921.374 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2018-09-24T20:45:21.374Z,1537821921.374 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2018-09-24T20:45:21.374Z,1537821921.374 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-09-24T20:45:21.375Z,1537821921.375 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2018-09-24T20:45:21.375Z,1537821921.375 [Default:A.Wait] Running Loop=1
2018-09-24T20:45:21.375Z,1537821921.375 [Default:A.Wait](DEBUG): Initialize Wait Component.
2018-09-24T20:45:33.687Z,1537821933.687 [NAL9602](INFO): SBD MO Status=1, MOMSN=1624, MT Status=0, MTMSN=0
2018-09-24T20:45:33.741Z,1537821933.741 [NAL9602](INFO): Sent 332 bytes from file Logs/20180924T203303/Express0008.lzma
2018-09-24T20:45:33.741Z,1537821933.741 [NAL9602](INFO): Packets left to send: 3
2018-09-24T20:45:33.743Z,1537821933.743 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180924T203303/Express0008.lzma.parts/0003.sbd
2018-09-24T20:45:34.746Z,1537821934.746 [Default:A.Wait](INFO): Done Waiting.
2018-09-24T20:45:34.746Z,1537821934.746 [Default:A.Wait] Stopped
2018-09-24T20:45:34.746Z,1537821934.746 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2018-09-24T20:45:35.161Z,1537821935.161 [Default:CheckIn] Running Loop=1
2018-09-24T20:45:35.161Z,1537821935.161 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-09-24T20:45:35.161Z,1537821935.161 [Default:CheckIn:Read_GPS] Running Loop=1
2018-09-24T20:45:35.526Z,1537821935.526 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2018-09-24T20:45:36.283Z,1537821936.283 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004270
2018-09-24T20:47:59.572Z,1537822079.572 [NAL9602](INFO): GPS fix at 20180924T204751: (36.851226, -121.915664)
2018-09-24T20:47:59.658Z,1537822079.658 [Default:CheckIn:Read_GPS] Stopped
2018-09-24T20:47:59.658Z,1537822079.658 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-09-24T20:48:00.119Z,1537822080.119 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2018-09-24T20:48:07.348Z,1537822087.348 [DataOverHttps](INFO): Sending 212 bytes from file Logs/20180924T204155/Courier0004.lzma
2018-09-24T20:48:09.757Z,1537822089.757 [DataOverHttps](INFO): Moved sent file to Logs/20180924T204155/Courier0004.lzma.bak
2018-09-24T20:48:09.758Z,1537822089.758 [DataOverHttps](IMPORTANT): SBD MOMSN=8575620, MTMSN=20180924T204801
2018-09-24T20:48:21.560Z,1537822101.560 [DataOverHttps](INFO): Received command:load Transport/keepstation.xml;set keepstation.NeedCommsTime 20 minute;run 
2018-09-24T20:48:21.571Z,1537822101.571 [CommandLine](IMPORTANT): got command load ./Missions/Transport/keepstation.xml
2018-09-24T20:48:21.571Z,1537822101.571 [MissionManager](INFO): Loading Mission: ./Missions/Transport/keepstation.xml
2018-09-24T20:48:21.648Z,1537822101.648 [MissionManager](INFO): DefineArg keepstation.MissionTimeout = 4.000000 h
2018-09-24T20:48:21.651Z,1537822101.651 [MissionManager](INFO): DefineArg keepstation.NeedCommsTime = 45.000000 min
2018-09-24T20:48:21.654Z,1537822101.654 [MissionManager](INFO): DefineArg keepstation.Latitude = nan arcdeg
2018-09-24T20:48:21.657Z,1537822101.657 [MissionManager](INFO): DefineArg keepstation.Longitude = nan arcdeg
2018-09-24T20:48:21.660Z,1537822101.660 [MissionManager](INFO): DefineArg keepstation.Depth = 30.000000 m
2018-09-24T20:48:21.662Z,1537822101.662 [MissionManager](INFO): DefineArg keepstation.ApproachDepth = 15.000000 m
2018-09-24T20:48:21.665Z,1537822101.665 [MissionManager](INFO): DefineArg keepstation.DepthDeadband = 4.000000 m
2018-09-24T20:48:21.668Z,1537822101.668 [MissionManager](INFO): DefineArg keepstation.Speed = 0.750000 m/s
2018-09-24T20:48:21.671Z,1537822101.671 [MissionManager](INFO): DefineArg keepstation.Radius = 200.000000 m
2018-09-24T20:48:21.704Z,1537822101.704 [MissionManager](INFO): DefineArg keepstation.MaxDepth = 45.000000 m
2018-09-24T20:48:21.707Z,1537822101.707 [MissionManager](INFO): DefineArg keepstation.MinOffshore = 2.000000 km
2018-09-24T20:48:21.707Z,1537822101.707 [MissionManager](INFO): Inserting Stack: Missions/Insert/NeedComms.xml
2018-09-24T20:48:21.842Z,1537822101.842 [MissionManager](INFO): DefineArg keepstation:NeedComms.DiveInterval = 3.000000 h
2018-09-24T20:48:21.845Z,1537822101.845 [MissionManager](INFO): DefineArg keepstation:NeedComms.WaitForPitchUp = 10.000000 min
2018-09-24T20:48:21.867Z,1537822101.867 [MissionManager](INFO): DefineArg keepstation:NeedComms.SurfacePitch = 20.000000 arcdeg
2018-09-24T20:48:21.882Z,1537822101.882 [MissionManager](INFO): DefineArg keepstation:NeedComms.SurfaceDepthRate = nan m/s
2018-09-24T20:48:21.891Z,1537822101.891 [MissionManager](INFO): DefineArg keepstation:NeedComms.SurfaceSpeed = 1.000000 m/s
2018-09-24T20:48:21.905Z,1537822101.905 [MissionManager](INFO): DefineArg keepstation:NeedComms.GPSTimeout = 7.000000 min
2018-09-24T20:48:21.909Z,1537822101.909 [MissionManager](INFO): DefineArg keepstation:NeedComms.CommsTimeout = 30.000000 min
2018-09-24T20:48:21.921Z,1537822101.921 [keepstation:NeedComms:B.GoToSurface](DEBUG): Construct GoToSurface.
2018-09-24T20:48:21.961Z,1537822101.961 [MissionManager](INFO): Inserting Stack: Missions/Insert/StandardEnvelopes.xml
2018-09-24T20:48:21.999Z,1537822101.999 [MissionManager](INFO): DefineArg keepstation:StandardEnvelopes.MinAltitude = 5.000000 m
2018-09-24T20:48:22.004Z,1537822102.004 [MissionManager](INFO): DefineArg keepstation:StandardEnvelopes.MaxDepth = 200.000000 m
2018-09-24T20:48:22.015Z,1537822102.015 [MissionManager](INFO): DefineArg keepstation:StandardEnvelopes.MinOffshore = 2000.000000 m
2018-09-24T20:48:22.021Z,1537822102.021 [keepstation:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope.
2018-09-24T20:48:22.035Z,1537822102.035 [keepstation:StandardEnvelopes:B.DepthEnvelope](DEBUG): Construct DepthEnvelope.
2018-09-24T20:48:22.044Z,1537822102.044 [keepstation:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Construct OffshoreEnvelope.
2018-09-24T20:48:22.084Z,1537822102.084 [keepstation:F.Pitch](DEBUG): Construct.
2018-09-24T20:48:22.091Z,1537822102.091 [keepstation:TransitToStation:A.Buoyancy](DEBUG): Construct Buoyancy.
2018-09-24T20:48:22.107Z,1537822102.107 [keepstation:TransitToStation:B.Pitch](DEBUG): Construct.
2018-09-24T20:48:22.112Z,1537822102.112 [keepstation:TransitToStation:C.SetSpeed](DEBUG): Construct.
2018-09-24T20:48:22.127Z,1537822102.127 [keepstation:TransitToStation:Wpt1.Waypoint](DEBUG): Construct Waypoint.
2018-09-24T20:48:22.160Z,1537822102.160 [keepstation:KeepStation:B.Pitch](DEBUG): Construct.
2018-09-24T20:48:22.165Z,1537822102.165 [keepstation:KeepStation:C.KeepStation](DEBUG): Construct KeepStation.
2018-09-24T20:48:22.182Z,1537822102.182 [keepstation:KeepStation:D.Wait](DEBUG): Construct Wait.
2018-09-24T20:48:22.196Z,1537822102.196 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="utf-8"?>
<Mission xmlns="Tethys"
         xmlns:Control="Tethys/Control"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Units="Tethys/Units"
         xmlns:Universal="Tethys/Universal"
         xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd
                             Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                             Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
         Id="keepstation">

    <Description>
        Vehicle transits to desired waypoint (or stays put if none is commanded)
        and stays within the specified radius.
    </Description>

    <DefineArg Name="MissionTimeout"><Description>
        Maximum duration of mission
    </Description><Units:hour/><Value>4</Value></DefineArg>

    <DefineArg Name="NeedCommsTime"><Description>
        How often to surface for commumications
    </Description><Units:minute/><Value>45</Value></DefineArg>

    <DefineArg Name="Latitude"><Description>
        Latitude of waypoint to hold. If NaN, hold the latitude at start of
        mission.
    </Description><Units:degree/><Value>NaN</Value></DefineArg>

    <DefineArg Name="Longitude"><Description>
        Longitude of waypoint to hold. If NaN, hold the longitude at start of
        mission.
    </Description><Units:degree/><Value>NaN</Value></DefineArg>

    <DefineArg Name="Depth"><Description>
        Depth held during drift mode
    </Description><Units:meter/><Value>30</Value></DefineArg>

    <DefineArg Name="ApproachDepth"><Description>
        Depth for initial approach to station.
    </Description><Units:meter/><Value>15</Value></DefineArg>

    <DefineArg Name="DepthDeadband"><Description>
        How much vertical drift from the specified depth is allowed in drift
        mode
    </Description><Units:meter/><Value>4</Value></DefineArg>

    <DefineArg Name="Speed"><Description>
        Vehicle transit speed.
    </Description><Units:meter_per_second/><Value>0.75</Value></DefineArg>

    <DefineArg Name="Radius"><Description>
        Radius of circle around waypoint to hold.
    </Description><Units:meter/><Value>200</Value></DefineArg>

    <DefineArg Name="MaxDepth"><Description>
        Maximum allowable depth during the mission.
    </Description><Units:meter/><Value>45</Value></DefineArg>

    <DefineArg Name="MinOffshore"><Description>
        Minimum distance from the shoreline to maintain
    </Description><Units:kilometer/><Value>2</Value></DefineArg>

<!-- Missions should almost always start with a timeout and a NeedComms aggregate. -->

    <Timeout Duration="MissionTimeout"/>

    <Insert Filename="Insert/NeedComms.xml" Id="NeedComms"/>

    <Assign><Sequence/><Arg Name="NeedComms:DiveInterval"/><Arg Name="NeedCommsTime"/></Assign>

<!-- Missions should almost always start with standard safety envelopes; most missions should not expose the parameters of these envelopes. -->

    <Insert Filename="Insert/StandardEnvelopes.xml"/>

    <Assign><Sequence/><Arg Name="StandardEnvelopes:MaxDepth"/><Arg Name="MaxDepth"/></Assign>

    <Assign><Sequence/><Arg Name="StandardEnvelopes:MinOffshore"/><Arg Name="MinOffshore"/></Assign>

<!-- Most missions should not actively control mass or buoyancy. However, keepstation will want to control buoyancy, so only set mass here. -->

    <Guidance:Pitch>
        <Parallel/>
        <Setting><Guidance:Pitch.massPosition/><Control:VerticalControl.massDefault/></Setting>
    </Guidance:Pitch>

<!-- Check for additional instructions first. -->

    <Call Id="StartingMission" RefId="NeedComms"/>

<!-- Then transit to specified location. TODO: Consider encapsulating in a standard Insert/ApproachTransit.xml -->

    <Aggregate Id="TransitToStation">

        <Description>
            Need a separate aggregate for transit if we want to specify a
            different depth for the approach.
        </Description>

        <Sequence/>

        <Guidance:Buoyancy>
            <Parallel/>
            <Setting><Guidance:Buoyancy.position/><Control:VerticalControl.buoyancyNeutral/></Setting>
        </Guidance:Buoyancy>

        <Guidance:Pitch>
            <Parallel/>
            <Setting><Guidance:Pitch.depth/><Arg Name="ApproachDepth"/></Setting>
        </Guidance:Pitch>

        <Guidance:SetSpeed>
            <Parallel/>
            <Setting><Guidance:SetSpeed.speed/><Arg Name="Speed"/></Setting>
        </Guidance:SetSpeed>

        <Guidance:Waypoint Id="Wpt1">
            <Sequence/>
            <Setting><Guidance:Waypoint.latitude/><Arg Name="Latitude"/></Setting>
            <Setting><Guidance:Waypoint.longitude/><Arg Name="Longitude"/></Setting>
        </Guidance:Waypoint>

    </Aggregate>

    <Call Id="OnStation" RefId="NeedComms"/>

    <Aggregate Id="KeepStation">

        <Sequence/>

<!-- TODO: Consider making depth and depthDeadband into settings for the keepstation behavior. -->

        <Assign><Parallel/><Control:VerticalControl.depthDeadband/><Arg Name="DepthDeadband"/></Assign>

        <Guidance:Pitch>
            <Parallel/>
            <Setting><Guidance:Pitch.depth/><Arg Name="Depth"/></Setting>
        </Guidance:Pitch>

        <Guidance:KeepStation>
            <Parallel/>
            <Setting><Guidance:KeepStation.latitude/><Arg Name="Latitude"/></Setting>
            <Setting><Guidance:KeepStation.longitude/><Arg Name="Longitude"/></Setting>
            <Setting><Guidance:KeepStation.radius/><Arg Name="Radius"/></Setting>
            <Setting><Guidance:KeepStation.speed/><Arg Name="Speed"/></Setting>
        </Guidance:KeepStation>

        <Guidance:Wait>
            <Description>
                Due to the way the KeepStation behavior is currently
                implemented, we must run it in parallel and use a Wait to keep
                from completing the mission before the timeout expires. However,
                this new version of the mission uses a top-level timeout so that
                the entire mission will not run for longer then MissionTimeout.
            </Description>
            <Sequence/>
            <Setting><Guidance:Wait.duration/><Arg Name="MissionTimeout"/></Setting>
        </Guidance:Wait>

    </Aggregate>

</Mission>


2018-09-24T20:48:22.197Z,1537822102.197 [CommandLine](IMPORTANT): Loaded ./Missions/Transport/keepstation.xml
2018-09-24T20:48:25.127Z,1537822105.127 [CommandLine](IMPORTANT): got command set keepstation.NeedCommsTime 20.000000 minute
2018-09-24T20:48:25.128Z,1537822105.128 [CommandLine](IMPORTANT): got command run 
2018-09-24T20:48:25.130Z,1537822105.130 [CommandLine](IMPORTANT): Running 
2018-09-24T20:48:25.269Z,1537822105.269 [Default] Stopped
2018-09-24T20:48:25.269Z,1537822105.269 [Default](DEBUG): Aggregate::uninitialize Default
2018-09-24T20:48:25.269Z,1537822105.269 [Default:B.GoToSurface] Stopped
2018-09-24T20:48:25.269Z,1537822105.269 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2018-09-24T20:48:25.269Z,1537822105.269 [Default:CheckIn] Stopped
2018-09-24T20:48:25.269Z,1537822105.269 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-09-24T20:48:25.269Z,1537822105.269 [Default:CheckIn:Read_Iridium] Stopped
2018-09-24T20:48:25.270Z,1537822105.270 [MissionManager](IMPORTANT): Started mission keepstation
2018-09-24T20:48:25.270Z,1537822105.270 [keepstation] Running Loop=1
2018-09-24T20:48:25.270Z,1537822105.270 [keepstation](DEBUG): Aggregate::initialize keepstation
2018-09-24T20:48:25.270Z,1537822105.270 [keepstation:StandardEnvelopes] Running Loop=1
2018-09-24T20:48:25.270Z,1537822105.270 [keepstation:StandardEnvelopes](DEBUG): Aggregate::initialize keepstation:StandardEnvelopes
2018-09-24T20:48:25.270Z,1537822105.270 [keepstation:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1
2018-09-24T20:48:25.270Z,1537822105.270 [keepstation:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent.
2018-09-24T20:48:25.271Z,1537822105.271 [keepstation:StandardEnvelopes:B.DepthEnvelope] Running Loop=1
2018-09-24T20:48:25.271Z,1537822105.271 [keepstation:StandardEnvelopes:B.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent.
2018-09-24T20:48:25.271Z,1537822105.271 [keepstation:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1
2018-09-24T20:48:25.271Z,1537822105.271 [keepstation:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Initialize OffshoreEnvelopeComponent.
2018-09-24T20:48:25.271Z,1537822105.271 [keepstation:F.Pitch] Running Loop=1
2018-09-24T20:48:25.271Z,1537822105.271 [keepstation:F.Pitch](DEBUG): Initialize.
2018-09-24T20:48:25.272Z,1537822105.272 [keepstation:B] Running Loop=1
2018-09-24T20:48:25.272Z,1537822105.272 [keepstation:F.Pitch] Running Loop=1
2018-09-24T20:48:25.309Z,1537822105.309 [keepstation:StandardEnvelopes] Running Loop=1
2018-09-24T20:48:25.309Z,1537822105.309 [keepstation:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1
2018-09-24T20:48:25.314Z,1537822105.314 [keepstation:StandardEnvelopes:B.DepthEnvelope] Running Loop=1
2018-09-24T20:48:25.340Z,1537822105.340 [keepstation:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1
2018-09-24T20:48:25.367Z,1537822105.367 [keepstation:B] Stopped
2018-09-24T20:48:25.367Z,1537822105.367 [keepstation:D] Running Loop=1
2018-09-24T20:48:25.539Z,1537822105.539 [keepstation:D] Stopped
2018-09-24T20:48:25.539Z,1537822105.539 [keepstation:E] Running Loop=1
2018-09-24T20:48:25.876Z,1537822105.876 [keepstation:E] Stopped
2018-09-24T20:48:25.876Z,1537822105.876 [keepstation:StartingMission] Running Loop=1
2018-09-24T20:48:25.876Z,1537822105.876 [keepstation:StartingMission](DEBUG): Aggregate::initialize keepstation:StartingMission
2018-09-24T20:48:26.278Z,1537822106.278 [keepstation:NeedComms] Running Loop=1
2018-09-24T20:48:26.278Z,1537822106.278 [keepstation:NeedComms](DEBUG): Aggregate::initialize keepstation:NeedComms
2018-09-24T20:48:26.278Z,1537822106.278 [keepstation:NeedComms:B.GoToSurface] Running Loop=1
2018-09-24T20:48:26.279Z,1537822106.279 [keepstation:NeedComms:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-09-24T20:48:26.279Z,1537822106.279 [keepstation:NeedComms:B.GoToSurface](INFO): Received depth rate setting nan m/s.
2018-09-24T20:48:26.279Z,1537822106.279 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch setting 19.999999 degrees.
2018-09-24T20:48:26.280Z,1537822106.280 [keepstation:NeedComms:B.GoToSurface](INFO): Received speed setting 1.000000 m/s.
2018-09-24T20:48:26.280Z,1537822106.280 [keepstation:NeedComms:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-09-24T20:48:26.280Z,1537822106.280 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2018-09-24T20:48:26.281Z,1537822106.281 [keepstation:NeedComms:A] Running Loop=1
2018-09-24T20:48:26.315Z,1537822106.315 [keepstation:NeedComms:A](INFO): last time_fix was: 1537822071.000000 second since 1970/01/01T00:00:00Z 
2018-09-24T20:48:26.316Z,1537822106.316 [keepstation:NeedComms:A] Stopped
2018-09-24T20:48:26.700Z,1537822106.700 [keepstation:NeedComms:C] Running Loop=1
2018-09-24T20:48:27.073Z,1537822107.073 [keepstation:NeedComms:C](DEBUG): Initialize ReadDataComponent to sense time_fix
2018-09-24T20:48:28.626Z,1537822108.626 [NAL9602](INFO): GPS fix at 20180924T204820: (36.851226, -121.915689)
2018-09-24T20:48:28.700Z,1537822108.700 [keepstation:NeedComms:C] Stopped
2018-09-24T20:48:28.700Z,1537822108.700 [keepstation:NeedComms:D] Running Loop=1
2018-09-24T20:48:32.078Z,1537822112.078 [keepstation:NeedComms:D](DEBUG): Initialize ReadDataComponent to sense platform_communications
2018-09-24T20:48:32.620Z,1537822112.620 [DataOverHttps](INFO): Sending 1290 bytes from file Logs/20180924T203303/Express0008.lzma
2018-09-24T20:48:36.762Z,1537822116.762 [DataOverHttps](INFO): Moved sent file to Logs/20180924T203303/Express0008.lzma.bak
2018-09-24T20:48:36.762Z,1537822116.762 [DataOverHttps](INFO): SBD MOMSN=8575625
2018-09-24T20:48:51.531Z,1537822131.531 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20180924T204155/Courier0007.lzma
2018-09-24T20:48:53.129Z,1537822133.129 [DataOverHttps](INFO): Moved sent file to Logs/20180924T204155/Courier0007.lzma.bak
2018-09-24T20:48:53.129Z,1537822133.129 [DataOverHttps](INFO): SBD MOMSN=8575681
2018-09-24T20:49:05.242Z,1537822145.242 [NAL9602](INFO): Powering down
2018-09-24T20:49:06.155Z,1537822146.155 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180924T204155/Courier0010.lzma
2018-09-24T20:49:07.753Z,1537822147.753 [DataOverHttps](INFO): Moved sent file to Logs/20180924T204155/Courier0010.lzma.bak
2018-09-24T20:49:07.753Z,1537822147.753 [DataOverHttps](INFO): SBD MOMSN=8575684
2018-09-24T20:49:22.554Z,1537822162.554 [DataOverHttps](INFO): Sending 1126 bytes from file Logs/20180924T204155/Express0001.lzma
2018-09-24T20:49:26.141Z,1537822166.141 [DataOverHttps](INFO): Moved sent file to Logs/20180924T204155/Express0001.lzma.bak
2018-09-24T20:49:26.141Z,1537822166.141 [DataOverHttps](INFO): SBD MOMSN=8575686
2018-09-24T20:49:40.984Z,1537822180.984 [DataOverHttps](INFO): Sending 220 bytes from file Logs/20180924T204155/Express0005.lzma
2018-09-24T20:49:42.973Z,1537822182.973 [DataOverHttps](INFO): Moved sent file to Logs/20180924T204155/Express0005.lzma.bak
2018-09-24T20:49:42.973Z,1537822182.973 [DataOverHttps](INFO): SBD MOMSN=8575718
2018-09-24T20:49:58.024Z,1537822198.024 [DataOverHttps](INFO): Sending 289 bytes from file Logs/20180924T204155/Express0008.lzma
2018-09-24T20:50:00.413Z,1537822200.413 [DataOverHttps](INFO): Moved sent file to Logs/20180924T204155/Express0008.lzma.bak
2018-09-24T20:50:00.413Z,1537822200.413 [DataOverHttps](INFO): SBD MOMSN=8575721
2018-09-24T20:50:23.835Z,1537822223.835 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2018-09-24T20:50:24.571Z,1537822224.571 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180924T204155/Express0011.lzma
2018-09-24T20:50:26.169Z,1537822226.169 [DataOverHttps](INFO): Moved sent file to Logs/20180924T204155/Express0011.lzma.bak
2018-09-24T20:50:26.169Z,1537822226.169 [DataOverHttps](INFO): SBD MOMSN=8575730
2018-09-24T20:50:26.747Z,1537822226.747 [keepstation:NeedComms:D] Stopped
2018-09-24T20:50:26.748Z,1537822226.748 [keepstation:NeedComms:E] Running Loop=1
2018-09-24T20:50:27.031Z,1537822227.031 [keepstation:NeedComms:E](DEBUG): Initialize ReadDataComponent to sense time_fix
2018-09-24T20:50:27.374Z,1537822227.374 [NAL9602](INFO): Powering up
2018-09-24T20:50:38.366Z,1537822238.366 [NAL9602](INFO): NAL9602 initialized
2018-09-24T20:50:53.976Z,1537822253.976 [NAL9602](INFO): SBD MO Status=0, MOMSN=1625, MT Status=0, MTMSN=0
2018-09-24T20:50:53.976Z,1537822253.976 [NAL9602](INFO): No messages in MT queue
2018-09-24T20:57:27.059Z,1537822647.059 [keepstation:NeedComms:E](INFO): Timed out from 2018-09-24T20:50:26.7Z
2018-09-24T20:57:27.059Z,1537822647.059 [keepstation:NeedComms:E:A_Timeout] Running Loop=1
2018-09-24T20:57:27.059Z,1537822647.059 [keepstation:NeedComms:E:A_Timeout](DEBUG): Aggregate::initialize keepstation:NeedComms:E:A_Timeout
2018-09-24T20:57:27.060Z,1537822647.060 [keepstation:NeedComms:E:A_Timeout:A] Running Loop=1
2018-09-24T20:57:27.060Z,1537822647.060 [keepstation:NeedComms:E:A_Timeout:A](IMPORTANT): second GPS update timeout
2018-09-24T20:57:27.069Z,1537822647.069 [keepstation:NeedComms:E:A_Timeout:A] Stopped
2018-09-24T20:57:27.070Z,1537822647.070 [keepstation:NeedComms:E:A_Timeout](INFO): Completed keepstation:NeedComms:E:A_Timeout
2018-09-24T20:57:27.070Z,1537822647.070 [keepstation:NeedComms:E] Stopped
2018-09-24T20:57:27.071Z,1537822647.071 [keepstation:NeedComms](INFO): Completed keepstation:NeedComms
2018-09-24T20:57:27.071Z,1537822647.071 [keepstation:NeedComms] Stopped
2018-09-24T20:57:27.071Z,1537822647.071 [keepstation:NeedComms](DEBUG): Aggregate::uninitialize keepstation:NeedComms
2018-09-24T20:57:27.071Z,1537822647.071 [keepstation:NeedComms:B.GoToSurface] Stopped
2018-09-24T20:57:27.071Z,1537822647.071 [keepstation:NeedComms:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2018-09-24T20:57:27.471Z,1537822647.471 [keepstation:StartingMission](INFO): Completed keepstation:StartingMission
2018-09-24T20:57:27.471Z,1537822647.471 [keepstation:StartingMission] Stopped
2018-09-24T20:57:27.471Z,1537822647.471 [keepstation:StartingMission](DEBUG): Aggregate::uninitialize keepstation:StartingMission
2018-09-24T20:57:27.471Z,1537822647.471 [keepstation:TransitToStation] Running Loop=1
2018-09-24T20:57:27.471Z,1537822647.471 [keepstation:TransitToStation](DEBUG): Aggregate::initialize keepstation:TransitToStation
2018-09-24T20:57:27.471Z,1537822647.471 [keepstation:TransitToStation:A.Buoyancy] Running Loop=1
2018-09-24T20:57:27.471Z,1537822647.471 [keepstation:TransitToStation:A.Buoyancy](DEBUG): Initialize Buoyancy Component.
2018-09-24T20:57:27.472Z,1537822647.472 [keepstation:TransitToStation:B.Pitch] Running Loop=1
2018-09-24T20:57:27.472Z,1537822647.472 [keepstation:TransitToStation:B.Pitch](DEBUG): Initialize.
2018-09-24T20:57:27.472Z,1537822647.472 [keepstation:TransitToStation:C.SetSpeed] Running Loop=1
2018-09-24T20:57:27.472Z,1537822647.472 [keepstation:TransitToStation:C.SetSpeed](DEBUG): Initialize.
2018-09-24T20:57:27.472Z,1537822647.472 [keepstation:TransitToStation:Wpt1.Waypoint] Running Loop=1
2018-09-24T20:57:27.472Z,1537822647.472 [keepstation:TransitToStation:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2018-09-24T20:57:27.873Z,1537822647.873 [keepstation:TransitToStation:C.SetSpeed] Running Loop=1
2018-09-24T20:57:27.878Z,1537822647.878 [keepstation:TransitToStation:B.Pitch] Running Loop=1
2018-09-24T20:57:27.883Z,1537822647.883 [keepstation:TransitToStation:A.Buoyancy] Running Loop=1
2018-09-24T20:58:03.066Z,1537822683.066 [NAL9602](INFO): Powering down
2018-09-24T20:58:12.450Z,1537822692.450 [Radio_Surface](INFO): Powering down
2018-09-24T20:58:57.854Z,1537822737.854 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-09-24T20:59:19.505Z,1537822759.505 [keepstation:TransitToStation:Wpt1.Waypoint] Stopped
2018-09-24T20:59:19.505Z,1537822759.505 [keepstation:TransitToStation:Wpt1.Waypoint](DEBUG): Uninitialize WaypointComponent.
2018-09-24T20:59:19.507Z,1537822759.507 [keepstation:TransitToStation](INFO): Completed keepstation:TransitToStation
2018-09-24T20:59:19.507Z,1537822759.507 [keepstation:TransitToStation] Stopped
2018-09-24T20:59:19.507Z,1537822759.507 [keepstation:TransitToStation](DEBUG): Aggregate::uninitialize keepstation:TransitToStation
2018-09-24T20:59:19.507Z,1537822759.507 [keepstation:TransitToStation:A.Buoyancy] Stopped
2018-09-24T20:59:19.507Z,1537822759.507 [keepstation:TransitToStation:A.Buoyancy](DEBUG): Uninitialize Buoyancy Component.
2018-09-24T20:59:19.507Z,1537822759.507 [keepstation:TransitToStation:B.Pitch] Stopped
2018-09-24T20:59:19.507Z,1537822759.507 [keepstation:TransitToStation:C.SetSpeed] Stopped
2018-09-24T20:59:19.507Z,1537822759.507 [keepstation:TransitToStation:C.SetSpeed](DEBUG): Uninitialize.
2018-09-24T20:59:19.507Z,1537822759.507 [keepstation:OnStation] Running Loop=1
2018-09-24T20:59:19.508Z,1537822759.508 [keepstation:OnStation](DEBUG): Aggregate::initialize keepstation:OnStation
2018-09-24T20:59:19.935Z,1537822759.935 [keepstation:NeedComms] Running Loop=1
2018-09-24T20:59:19.935Z,1537822759.935 [keepstation:NeedComms](DEBUG): Aggregate::initialize keepstation:NeedComms
2018-09-24T20:59:19.935Z,1537822759.935 [keepstation:NeedComms:B.GoToSurface] Running Loop=1
2018-09-24T20:59:19.935Z,1537822759.935 [keepstation:NeedComms:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-09-24T20:59:19.935Z,1537822759.935 [keepstation:NeedComms:B.GoToSurface](INFO): Received depth rate setting nan m/s.
2018-09-24T20:59:19.936Z,1537822759.936 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch setting 19.999999 degrees.
2018-09-24T20:59:19.936Z,1537822759.936 [keepstation:NeedComms:B.GoToSurface](INFO): Received speed setting 1.000000 m/s.
2018-09-24T20:59:19.936Z,1537822759.936 [keepstation:NeedComms:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-09-24T20:59:19.938Z,1537822759.938 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2018-09-24T20:59:19.938Z,1537822759.938 [keepstation:NeedComms:A] Running Loop=1
2018-09-24T20:59:19.940Z,1537822759.940 [keepstation:NeedComms:A](INFO): last time_fix was: 1537822100.000000 second since 1970/01/01T00:00:00Z 
2018-09-24T20:59:19.940Z,1537822759.940 [keepstation:NeedComms:A] Stopped
2018-09-24T20:59:48.998Z,1537822788.998 [keepstation:NeedComms:C] Running Loop=1
2018-09-24T20:59:49.070Z,1537822789.070 [Radio_Surface](INFO): Powering up
2018-09-24T20:59:49.738Z,1537822789.738 [NAL9602](INFO): Powering up
2018-09-24T20:59:58.136Z,1537822798.136 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-09-24T21:00:00.942Z,1537822800.942 [NAL9602](INFO): NAL9602 initialized
2018-09-24T21:00:02.970Z,1537822802.970 [RDI_Pathfinder](ERROR): Failed to parse:

2018-09-24T21:00:35.336Z,1537822835.336 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.269211
2018-09-24T21:01:58.936Z,1537822918.936 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-09-24T21:02:14.951Z,1537822934.951 [NAL9602](INFO): SBD MO Status=2, MOMSN=1626, MT Status=2, MTMSN=0
2018-09-24T21:02:14.951Z,1537822934.951 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-09-24T21:02:34.951Z,1537822954.951 [NAL9602](INFO): SBD MO Status=0, MOMSN=1626, MT Status=0, MTMSN=0
2018-09-24T21:02:34.951Z,1537822954.951 [NAL9602](INFO): No messages in MT queue
2018-09-24T21:02:35.738Z,1537822955.738 [NAL9602](FAULT): GPS failed to acquire within timeout.
2018-09-24T21:02:35.739Z,1537822955.739 [NAL9602] Data Fault, FailCount= 1
2018-09-24T21:02:35.739Z,1537822955.739 [NAL9602](ERROR): Data Fault
2018-09-24T21:02:35.810Z,1537822955.810 [CBIT](ERROR): Data Fault in component: NAL9602
2018-09-24T21:02:36.138Z,1537822956.138 [NAL9602](INFO): Powering down
2018-09-24T21:02:37.010Z,1537822957.010 [CBIT](INFO): Clearing failed state for component NAL9602
2018-09-24T21:02:37.010Z,1537822957.010 [NAL9602] No Fault, FailCount= 1
2018-09-24T21:02:59.335Z,1537822979.335 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-09-24T21:03:06.538Z,1537822986.538 [NAL9602](INFO): Powering up NAL9602
2018-09-24T21:03:17.339Z,1537822997.339 [NAL9602](INFO): NAL9602 initialized
2018-09-24T21:03:38.238Z,1537823018.238 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004704
2018-09-24T21:04:11.450Z,1537823051.450 [NAL9602](INFO): GPS fix at 20180924T210402: (36.851666, -121.915603)
2018-09-24T21:04:11.502Z,1537823051.502 [keepstation:NeedComms:C] Stopped
2018-09-24T21:04:11.502Z,1537823051.502 [keepstation:NeedComms:D] Running Loop=1
2018-09-24T21:04:26.727Z,1537823066.727 [DataOverHttps](INFO): Sending 225 bytes from file Logs/20180924T204155/Courier0013.lzma
2018-09-24T21:04:28.717Z,1537823068.717 [DataOverHttps](INFO): Moved sent file to Logs/20180924T204155/Courier0013.lzma.bak
2018-09-24T21:04:28.717Z,1537823068.717 [DataOverHttps](INFO): SBD MOMSN=8575807
2018-09-24T21:04:43.009Z,1537823083.009 [DataOverHttps](INFO): Sending 274 bytes from file Logs/20180924T204155/Express0014.lzma
2018-09-24T21:04:44.198Z,1537823084.198 [NAL9602](INFO): Powering down
2018-09-24T21:04:45.397Z,1537823085.397 [DataOverHttps](INFO): Moved sent file to Logs/20180924T204155/Express0014.lzma.bak
2018-09-24T21:04:45.397Z,1537823085.397 [DataOverHttps](INFO): SBD MOMSN=8575810
2018-09-24T21:04:45.968Z,1537823085.968 [keepstation:NeedComms:D] Stopped
2018-09-24T21:04:45.969Z,1537823085.969 [keepstation:NeedComms:E] Running Loop=1
2018-09-24T21:04:46.610Z,1537823086.610 [NAL9602](INFO): Powering up
2018-09-24T21:04:57.570Z,1537823097.570 [NAL9602](INFO): NAL9602 initialized
2018-09-24T21:05:24.776Z,1537823124.776 [NAL9602](INFO): SBD MO Status=0, MOMSN=1627, MT Status=0, MTMSN=0
2018-09-24T21:05:24.776Z,1537823124.776 [NAL9602](INFO): No messages in MT queue
2018-09-24T21:06:11.330Z,1537823171.330 [NAL9602](INFO): GPS fix at 20180924T210602: (36.851700, -121.915511)
2018-09-24T21:06:11.387Z,1537823171.387 [keepstation:NeedComms:E] Stopped
2018-09-24T21:06:11.388Z,1537823171.388 [keepstation:NeedComms](INFO): Completed keepstation:NeedComms
2018-09-24T21:06:11.388Z,1537823171.388 [keepstation:NeedComms] Stopped
2018-09-24T21:06:11.388Z,1537823171.388 [keepstation:NeedComms](DEBUG): Aggregate::uninitialize keepstation:NeedComms
2018-09-24T21:06:11.393Z,1537823171.393 [keepstation:NeedComms:B.GoToSurface] Stopped
2018-09-24T21:06:11.393Z,1537823171.393 [keepstation:NeedComms:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2018-09-24T21:06:11.777Z,1537823171.777 [keepstation:OnStation](INFO): Completed keepstation:OnStation
2018-09-24T21:06:11.777Z,1537823171.777 [keepstation:OnStation] Stopped
2018-09-24T21:06:11.777Z,1537823171.777 [keepstation:OnStation](DEBUG): Aggregate::uninitialize keepstation:OnStation
2018-09-24T21:06:11.777Z,1537823171.777 [keepstation:KeepStation] Running Loop=1
2018-09-24T21:06:11.778Z,1537823171.778 [keepstation:KeepStation](DEBUG): Aggregate::initialize keepstation:KeepStation
2018-09-24T21:06:11.778Z,1537823171.778 [keepstation:KeepStation:A] Running Loop=1
2018-09-24T21:06:11.778Z,1537823171.778 [keepstation:KeepStation:B.Pitch] Running Loop=1
2018-09-24T21:06:11.778Z,1537823171.778 [keepstation:KeepStation:B.Pitch](DEBUG): Initialize.
2018-09-24T21:06:11.778Z,1537823171.778 [keepstation:KeepStation:C.KeepStation] Running Loop=1
2018-09-24T21:06:11.778Z,1537823171.778 [keepstation:KeepStation:C.KeepStation](DEBUG): Initialize KeepStationComponent.
2018-09-24T21:06:11.779Z,1537823171.779 [keepstation:KeepStation:D.Wait] Running Loop=1
2018-09-24T21:06:11.779Z,1537823171.779 [keepstation:KeepStation:D.Wait](DEBUG): Initialize Wait Component.
2018-09-24T21:06:12.197Z,1537823172.197 [keepstation:KeepStation:C.KeepStation] Running Loop=1
2018-09-24T21:06:12.215Z,1537823172.215 [keepstation:KeepStation:B.Pitch] Running Loop=1
2018-09-24T21:06:12.219Z,1537823172.219 [keepstation:KeepStation:A] Running Loop=1
2018-09-24T21:06:44.120Z,1537823204.120 [NAL9602](INFO): Powering down
2018-09-24T21:08:34.278Z,1537823314.278 [RDI_Pathfinder](ERROR): only read 4 of 5 data items
2018-09-24T21:08:34.278Z,1537823314.278 [RDI_Pathfinder](ERROR): Failed to parse:
:BI,-32768,-32768,-32768,-32768-32768,-32768,-32768,V
2018-09-24T21:14:23.994Z,1537823663.994 [Radio_Surface](INFO): Powering down
2018-09-24T21:14:30.054Z,1537823670.054 [Radio_Surface](INFO): Powering up
2018-09-24T21:15:18.267Z,1537823718.267 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-09-24T21:16:18.268Z,1537823778.268 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-09-24T21:16:56.279Z,1537823816.279 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.407166
2018-09-24T21:17:14.931Z,1537823834.931 [Radio_Surface](INFO): Powering down
2018-09-24T21:17:21.798Z,1537823841.798 [Radio_Surface](INFO): Powering up
2018-09-24T21:18:18.681Z,1537823898.681 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-09-24T21:18:57.575Z,1537823937.575 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.002687
2018-09-24T21:19:55.830Z,1537823995.830 [Radio_Surface](INFO): Powering down
2018-09-24T21:20:01.898Z,1537824001.898 [Radio_Surface](INFO): Powering up
2018-09-24T21:20:44.338Z,1537824044.338 [Radio_Surface](INFO): Powering down
2018-09-24T21:20:50.803Z,1537824050.803 [Radio_Surface](INFO): Powering up
2018-09-24T21:20:55.179Z,1537824055.179 [RDI_Pathfinder](ERROR): Failed to parse:
:BI,-32768,-32768,-32768,-32768,V
2018-09-24T21:21:11.406Z,1537824071.406 [Radio_Surface](INFO): Powering down
2018-09-24T21:21:22.718Z,1537824082.718 [Radio_Surface](INFO): Powering up
2018-09-24T21:22:03.554Z,1537824123.554 [Radio_Surface](INFO): Powering down
2018-09-24T21:22:09.614Z,1537824129.614 [Radio_Surface](INFO): Powering up
2018-09-24T21:22:57.726Z,1537824177.726 [Radio_Surface](INFO): Powering down
2018-09-24T21:23:19.644Z,1537824199.644 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-09-24T21:24:20.044Z,1537824260.044 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-09-24T21:24:58.855Z,1537824298.855 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.410385
2018-09-24T21:26:11.704Z,1537824371.704 [keepstation:NeedComms] Running Loop=1
2018-09-24T21:26:11.704Z,1537824371.704 [keepstation:NeedComms](DEBUG): Aggregate::initialize keepstation:NeedComms
2018-09-24T21:26:11.704Z,1537824371.704 [keepstation:NeedComms:B.GoToSurface] Running Loop=1
2018-09-24T21:26:11.704Z,1537824371.704 [keepstation:NeedComms:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-09-24T21:26:11.709Z,1537824371.709 [keepstation:NeedComms:B.GoToSurface](INFO): Received depth rate setting nan m/s.
2018-09-24T21:26:11.709Z,1537824371.709 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch setting 19.999999 degrees.
2018-09-24T21:26:11.710Z,1537824371.710 [keepstation:NeedComms:B.GoToSurface](INFO): Received speed setting 1.000000 m/s.
2018-09-24T21:26:11.710Z,1537824371.710 [keepstation:NeedComms:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-09-24T21:26:11.710Z,1537824371.710 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2018-09-24T21:26:11.711Z,1537824371.711 [keepstation:NeedComms:A] Running Loop=1
2018-09-24T21:26:11.712Z,1537824371.712 [keepstation:NeedComms:A](INFO): last time_fix was: 1537823162.000000 second since 1970/01/01T00:00:00Z 
2018-09-24T21:26:11.717Z,1537824371.717 [keepstation:NeedComms:A] Stopped
2018-09-24T21:26:20.557Z,1537824380.557 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-09-24T21:26:58.574Z,1537824418.574 [keepstation:NeedComms:C] Running Loop=1
2018-09-24T21:26:58.714Z,1537824418.714 [Radio_Surface](INFO): Powering up
2018-09-24T21:26:59.290Z,1537824419.290 [NAL9602](INFO): Powering up
2018-09-24T21:27:10.218Z,1537824430.218 [NAL9602](INFO): NAL9602 initialized
2018-09-24T21:27:20.616Z,1537824440.616 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-09-24T21:28:20.616Z,1537824500.616 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-09-24T21:28:42.228Z,1537824522.228 [NAL9602](INFO): SBD MO Status=2, MOMSN=1628, MT Status=2, MTMSN=0
2018-09-24T21:28:42.228Z,1537824522.228 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-09-24T21:28:55.267Z,1537824535.267 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.002692
2018-09-24T21:30:14.308Z,1537824614.308 [NAL9602](INFO): SBD MO Status=0, MOMSN=1628, MT Status=0, MTMSN=0
2018-09-24T21:30:14.308Z,1537824614.308 [NAL9602](INFO): No messages in MT queue
2018-09-24T21:31:57.205Z,1537824717.205 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2018-09-24T21:31:57.206Z,1537824717.206 [RDI_Pathfinder](ERROR): Failed to parse:
:TS

2018-09-24T21:33:18.182Z,1537824798.182 [CommandLine](IMPORTANT): got command stop
2018-09-24T21:33:18.182Z,1537824798.182 [CommandLine](IMPORTANT): Scheduling is paused
2018-09-24T21:33:18.182Z,1537824798.182 [Supervisor](INFO): Stop Mission called by CommandLine::commandStop
2018-09-24T21:33:18.274Z,1537824798.274 [MissionManager](INFO): MissionManager is completed.
2018-09-24T21:33:18.275Z,1537824798.275 [MissionManager](INFO): Uninitializing Mission keepstation
2018-09-24T21:33:18.275Z,1537824798.275 [keepstation] Stopped
2018-09-24T21:33:18.275Z,1537824798.275 [keepstation](DEBUG): Aggregate::uninitialize keepstation
2018-09-24T21:33:18.275Z,1537824798.275 [keepstation:NeedComms] Stopped
2018-09-24T21:33:18.275Z,1537824798.275 [keepstation:NeedComms](DEBUG): Aggregate::uninitialize keepstation:NeedComms
2018-09-24T21:33:18.275Z,1537824798.275 [keepstation:NeedComms:B.GoToSurface] Stopped
2018-09-24T21:33:18.275Z,1537824798.275 [keepstation:NeedComms:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2018-09-24T21:33:18.275Z,1537824798.275 [keepstation:NeedComms:C] Stopped
2018-09-24T21:33:18.275Z,1537824798.275 [keepstation:StandardEnvelopes] Stopped
2018-09-24T21:33:18.276Z,1537824798.276 [keepstation:StandardEnvelopes](DEBUG): Aggregate::uninitialize keepstation:StandardEnvelopes
2018-09-24T21:33:18.276Z,1537824798.276 [keepstation:StandardEnvelopes:A.AltitudeEnvelope] Stopped
2018-09-24T21:33:18.276Z,1537824798.276 [keepstation:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent.
2018-09-24T21:33:18.276Z,1537824798.276 [keepstation:StandardEnvelopes:B.DepthEnvelope] Stopped
2018-09-24T21:33:18.276Z,1537824798.276 [keepstation:StandardEnvelopes:B.DepthEnvelope](DEBUG): Uninitialize.
2018-09-24T21:33:18.276Z,1537824798.276 [keepstation:StandardEnvelopes:C.OffshoreEnvelope] Stopped
2018-09-24T21:33:18.276Z,1537824798.276 [keepstation:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Uninitialize OffshoreEnvelopeComponent.
2018-09-24T21:33:18.276Z,1537824798.276 [keepstation:F.Pitch] Stopped
2018-09-24T21:33:18.276Z,1537824798.276 [keepstation:KeepStation] Stopped
2018-09-24T21:33:18.276Z,1537824798.276 [keepstation:KeepStation](DEBUG): Aggregate::uninitialize keepstation:KeepStation
2018-09-24T21:33:18.276Z,1537824798.276 [keepstation:KeepStation:A] Stopped
2018-09-24T21:33:18.276Z,1537824798.276 [keepstation:KeepStation:B.Pitch] Stopped
2018-09-24T21:33:18.277Z,1537824798.277 [keepstation:KeepStation:C.KeepStation] Stopped
2018-09-24T21:33:18.285Z,1537824798.285 [keepstation:KeepStation:C.KeepStation](DEBUG): Uninitialize KeepStationComponent.
2018-09-24T21:33:18.285Z,1537824798.285 [keepstation:KeepStation:D.Wait] Stopped
2018-09-24T21:33:18.285Z,1537824798.285 [keepstation:KeepStation:D.Wait](DEBUG): Uninitialize Wait Component.
2018-09-24T21:33:18.580Z,1537824798.580 [MissionManager](IMPORTANT): Started mission Default
2018-09-24T21:33:18.580Z,1537824798.580 [Default] Running Loop=1
2018-09-24T21:33:18.581Z,1537824798.581 [Default](DEBUG): Aggregate::initialize Default
2018-09-24T21:33:18.585Z,1537824798.585 [Default:B.GoToSurface] Running Loop=1
2018-09-24T21:33:18.585Z,1537824798.585 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-09-24T21:33:18.585Z,1537824798.585 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2018-09-24T21:33:18.586Z,1537824798.586 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2018-09-24T21:33:18.586Z,1537824798.586 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2018-09-24T21:33:18.586Z,1537824798.586 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-09-24T21:33:18.587Z,1537824798.587 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2018-09-24T21:33:18.587Z,1537824798.587 [Default:A.Wait] Running Loop=1
2018-09-24T21:33:18.587Z,1537824798.587 [Default:A.Wait](DEBUG): Initialize Wait Component.
2018-09-24T21:33:31.793Z,1537824811.793 [Default:A.Wait](INFO): Done Waiting.
2018-09-24T21:33:31.794Z,1537824811.794 [Default:A.Wait] Stopped
2018-09-24T21:33:31.794Z,1537824811.794 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2018-09-24T21:33:32.207Z,1537824812.207 [Default:CheckIn] Running Loop=1
2018-09-24T21:33:32.207Z,1537824812.207 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-09-24T21:33:32.208Z,1537824812.208 [Default:CheckIn:Read_GPS] Running Loop=1
2018-09-24T21:34:13.391Z,1537824853.391 [NAL9602](INFO): GPS fix at 20180924T213405: (36.852392, -121.914366)
2018-09-24T21:34:13.436Z,1537824853.436 [Default:CheckIn:Read_GPS] Stopped
2018-09-24T21:34:13.441Z,1537824853.441 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-09-24T21:34:18.126Z,1537824858.126 [DataOverHttps](INFO): Sending 64 bytes from file Logs/20180924T204155/Courier0016.lzma
2018-09-24T21:34:19.305Z,1537824859.305 [DataOverHttps](INFO): Moved sent file to Logs/20180924T204155/Courier0016.lzma.bak
2018-09-24T21:34:19.305Z,1537824859.305 [DataOverHttps](INFO): SBD MOMSN=8575924
2018-09-24T21:34:28.507Z,1537824868.507 [DataOverHttps](INFO): Sending 211 bytes from file Logs/20180924T204155/Express0017.lzma
2018-09-24T21:34:29.277Z,1537824869.277 [DataOverHttps](INFO): Moved sent file to Logs/20180924T204155/Express0017.lzma.bak
2018-09-24T21:34:29.277Z,1537824869.277 [DataOverHttps](INFO): SBD MOMSN=8575927
2018-09-24T21:34:29.891Z,1537824869.891 [Default:CheckIn:Read_Iridium] Stopped
2018-09-24T21:34:29.891Z,1537824869.891 [Default:CheckIn:C.Wait] Running Loop=1
2018-09-24T21:34:29.891Z,1537824869.891 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-09-24T21:34:48.278Z,1537824888.278 [NAL9602](INFO): Powering down
2018-09-24T21:35:24.364Z,1537824924.364 [CommandLine](IMPORTANT): got command configSet list
2018-09-24T21:35:24.364Z,1537824924.364 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2018-09-24T21:35:24.365Z,1537824924.365 [CommandLine](IMPORTANT): Aanderaa_O2.loadAtStartup=0 bool;

2018-09-24T21:35:24.365Z,1537824924.365 [CommandLine](IMPORTANT): BPC1.batterySamplingInterval=1 hour;

2018-09-24T21:35:24.366Z,1537824924.366 [CommandLine](IMPORTANT): BuoyancyServo.accel=400 none;

2018-09-24T21:35:24.366Z,1537824924.366 [CommandLine](IMPORTANT): BuoyancyServo.fastPumpCoefficient=1 none;

2018-09-24T21:35:24.366Z,1537824924.366 [CommandLine](IMPORTANT): BuoyancyServo.velocity=300 none;

2018-09-24T21:35:24.366Z,1537824924.366 [CommandLine](IMPORTANT): CTD_NeilBrown.loadAtStartup=0 bool;

2018-09-24T21:35:24.366Z,1537824924.366 [CommandLine](IMPORTANT): CTD_NeilBrown.simulateHardware=1 bool;

2018-09-24T21:35:24.366Z,1537824924.366 [CommandLine](IMPORTANT): CTD_Seabird.loadAtStartup=0 bool;

2018-09-24T21:35:24.366Z,1537824924.366 [CommandLine](IMPORTANT): CTD_Seabird.simulateHardware=1 bool;

2018-09-24T21:35:24.366Z,1537824924.366 [CommandLine](IMPORTANT): Express linearApproximation RDI_Pathfinder.height_above_sea_floor 5.000000 meter;

2018-09-24T21:35:24.367Z,1537824924.367 [CommandLine](IMPORTANT): Express linearApproximation WetLabsSeaOWL_UV_A.mass_concentration_of_chlorophyll_in_sea_water 0.500000 microgram_per_liter;

2018-09-24T21:35:24.367Z,1537824924.367 [CommandLine](IMPORTANT): Express linearApproximation height_above_sea_floor 5.000000 meter;

2018-09-24T21:35:24.367Z,1537824924.367 [CommandLine](IMPORTANT): IBIT.batteryVoltageThreshold=13.7 volt;

2018-09-24T21:35:24.367Z,1537824924.367 [CommandLine](IMPORTANT): RDI_PathfinderUp.loadAtStartup=0 bool;

2018-09-24T21:35:24.367Z,1537824924.367 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral=205 cubic_centimeter;

2018-09-24T21:35:24.367Z,1537824924.367 [CommandLine](IMPORTANT): VerticalControl.massDefault=0 millimeter;

2018-09-24T21:35:24.367Z,1537824924.367 [CommandLine](IMPORTANT): WetLabsBB2FL.loadAtStartup=0 bool;

2018-09-24T21:35:24.367Z,1537824924.367 [CommandLine](IMPORTANT): WetLabsBB2FL.simulateHardware=0 bool;

2018-09-24T21:35:54.620Z,1537824954.620 [CommandLine](IMPORTANT): got command configSet CTD_NeilBrown.simulateHardware 0.000000 bool persist
2018-09-24T21:35:54.623Z,1537824954.623 [CommandLine](IMPORTANT): got command configSet CTD_NeilBrown.loadAtStartup 1.000000 bool persist
2018-09-24T21:35:54.624Z,1537824954.624 [CommandLine](IMPORTANT): configSet CTD_NeilBrown.loadAtStartup requires a restart to take effect.
2018-09-24T21:35:58.680Z,1537824958.680 [CommandLine](IMPORTANT): got command restart application
2018-09-24T21:35:59.684Z,1537824959.684 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2018-09-24T21:35:59.684Z,1537824959.684 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-09-24T21:35:59.729Z,1537824959.729 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2018-09-24T21:35:59.729Z,1537824959.729 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-09-24T21:35:59.730Z,1537824959.730 [CommandLine](INFO): Join timeout helper Thread ID is 3510
2018-09-24T21:35:59.737Z,1537824959.737 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2018-09-24T21:35:59.737Z,1537824959.737 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-09-24T21:35:59.737Z,1537824959.737 [NavChartDb](INFO): Join timeout helper Thread ID is 3511
2018-09-24T21:35:59.834Z,1537824959.834 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2018-09-24T21:35:59.835Z,1537824959.835 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-09-24T21:35:59.836Z,1537824959.836 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2018-09-24T21:35:59.836Z,1537824959.836 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-09-24T21:35:59.837Z,1537824959.837 [Radio_Surface](INFO): Join timeout helper Thread ID is 3512
2018-09-24T21:36:00.113Z,1537824960.113 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2018-09-24T21:36:00.113Z,1537824960.113 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-09-24T21:36:00.117Z,1537824960.117 [ComponentRegistry](INFO): Shutting down WetLabsSeaOWL_UV_A ThreadHandler
2018-09-24T21:36:00.117Z,1537824960.117 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2018-09-24T21:36:00.118Z,1537824960.118 [WetLabsSeaOWL_UV_A](INFO): Join timeout helper Thread ID is 3513
2018-09-24T21:36:00.177Z,1537824960.177 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Uninitializing protected caller thread.
2018-09-24T21:36:00.178Z,1537824960.178 [WetLabsSeaOWL_UV_A](INFO): Powering down
2018-09-24T21:36:00.178Z,1537824960.178 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2018-09-24T21:36:00.189Z,1537824960.189 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2018-09-24T21:36:00.189Z,1537824960.189 [logger ThreadHandler](INFO): Thread cancelled.
2018-09-24T21:36:00.190Z,1537824960.190 [logger](INFO): Join timeout helper Thread ID is 3514
2018-09-24T21:36:00.196Z,1537824960.196 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2018-09-24T21:36:00.196Z,1537824960.196 [logger ThreadHandler](INFO): Thread cancelled.
2018-09-24T21:36:00.202Z,1537824960.202 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2018-09-24T21:36:00.202Z,1537824960.202 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-09-24T21:36:00.202Z,1537824960.202 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2018-09-24T21:36:00.202Z,1537824960.202 [controlThread ThreadHandler](INFO): Thread cancelled.
2018-09-24T21:36:00.203Z,1537824960.203 [controlThread](INFO): Join timeout helper Thread ID is 3515
2018-09-24T21:36:00.353Z,1537824960.353 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2018-09-24T21:36:00.354Z,1537824960.354 [controlThread](DEBUG): Uninitializing ControlThread
2018-09-24T21:36:00.354Z,1537824960.354 [AHRS_M2](INFO): Powering down
2018-09-24T21:36:00.426Z,1537824960.426 [NAL9602](INFO): Powering down
2018-09-24T21:36:00.497Z,1537824960.497 [RDI_Pathfinder](INFO): Powering down
2018-09-24T21:36:00.499Z,1537824960.499 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2018-09-24T21:36:00.500Z,1537824960.500 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2018-09-24T21:36:00.500Z,1537824960.500 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2018-09-24T21:36:00.501Z,1537824960.501 [MissionManager](INFO): Uninitializing Mission Default
2018-09-24T21:36:00.501Z,1537824960.501 [Default] Stopped
2018-09-24T21:36:00.501Z,1537824960.501 [Default](DEBUG): Aggregate::uninitialize Default
2018-09-24T21:36:00.501Z,1537824960.501 [Default:B.GoToSurface] Stopped
2018-09-24T21:36:00.501Z,1537824960.501 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2018-09-24T21:36:00.501Z,1537824960.501 [Default:CheckIn] Stopped
2018-09-24T21:36:00.501Z,1537824960.501 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-09-24T21:36:00.502Z,1537824960.502 [Default:CheckIn:C.Wait] Stopped
2018-09-24T21:36:00.502Z,1537824960.502 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-09-24T21:36:00.505Z,1537824960.505 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2018-09-24T21:36:00.505Z,1537824960.505 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2018-09-24T21:36:00.505Z,1537824960.505 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2018-09-24T21:36:00.506Z,1537824960.506 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2018-09-24T21:36:00.506Z,1537824960.506 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2018-09-24T21:36:00.507Z,1537824960.507 [BuoyancyServo](INFO): Powering down
2018-09-24T21:36:00.522Z,1537824960.522 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2018-09-24T21:36:00.522Z,1537824960.522 [ElevatorServo](INFO): Powering down
2018-09-24T21:36:00.523Z,1537824960.523 [MassServo](DEBUG): Uninitialize Mass Servo.
2018-09-24T21:36:00.523Z,1537824960.523 [MassServo](INFO): Powering down
2018-09-24T21:36:00.525Z,1537824960.525 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2018-09-24T21:36:00.525Z,1537824960.525 [RudderServo](INFO): Powering down
2018-09-24T21:36:00.526Z,1537824960.526 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2018-09-24T21:36:00.526Z,1537824960.526 [ThrusterServo](INFO): Powering down
2018-09-24T21:36:00.527Z,1537824960.527 [SBIT](DEBUG): Uninitialize SBIT Component.
2018-09-24T21:36:00.527Z,1537824960.527 [IBIT](DEBUG): Uninitialize IBIT Component.
2018-09-24T21:36:00.527Z,1537824960.527 [CBIT](DEBUG): Uninitialize CBIT Component.
2018-09-24T21:36:00.528Z,1537824960.528 [controlThread ThreadHandler](INFO): Thread cancelled.
2018-09-24T21:36:00.581Z,1537824960.581 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2018-09-24T21:36:00.644Z,1537824960.644 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-09-24T21:36:00.804Z,1537824960.804 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-09-24T21:36:00.872Z,1537824960.872 [logger ThreadHandler](INFO): Thread cancelled.