2018-09-20T18:28:38.860Z,1537468118.860 [Supervisor](DEBUG): Initializing supervisor.
2018-09-20T18:28:38.863Z,1537468118.863 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2018-09-20T18:28:38.864Z,1537468118.864 [SyncHandler](INFO): Protected caller Thread ID is 996
2018-09-20T18:28:38.865Z,1537468118.865 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2018-09-20T18:28:38.866Z,1537468118.866 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2018-09-20T18:28:38.866Z,1537468118.866 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 997
2018-09-20T18:28:38.869Z,1537468118.869 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2018-09-20T18:28:38.882Z,1537468118.882 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2018-09-20T18:28:38.883Z,1537468118.883 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2018-09-20T18:28:38.883Z,1537468118.883 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 998
2018-09-20T18:28:38.884Z,1537468118.884 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2018-09-20T18:28:38.885Z,1537468118.885 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2018-09-20T18:28:38.885Z,1537468118.885 [logger ThreadHandler](INFO): Protected caller Thread ID is 999
2018-09-20T18:28:38.887Z,1537468118.887 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2018-09-20T18:28:38.888Z,1537468118.888 [Supervisor](INFO): Looking for Config files in directory: Config/
2018-09-20T18:28:38.889Z,1537468118.889 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2018-09-20T18:28:39.077Z,1537468119.077 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2018-09-20T18:28:39.078Z,1537468119.078 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2018-09-20T18:28:39.220Z,1537468119.220 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2018-09-20T18:28:39.221Z,1537468119.221 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2018-09-20T18:28:39.567Z,1537468119.567 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2018-09-20T18:28:39.567Z,1537468119.567 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2018-09-20T18:28:39.706Z,1537468119.706 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2018-09-20T18:28:39.706Z,1537468119.706 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2018-09-20T18:28:39.786Z,1537468119.786 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2018-09-20T18:28:40.030Z,1537468120.030 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2018-09-20T18:28:40.030Z,1537468120.030 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2018-09-20T18:28:40.128Z,1537468120.128 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2018-09-20T18:28:40.129Z,1537468120.129 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2018-09-20T18:28:40.474Z,1537468120.474 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2018-09-20T18:28:40.475Z,1537468120.475 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2018-09-20T18:28:40.931Z,1537468120.931 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2018-09-20T18:28:40.932Z,1537468120.932 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2018-09-20T18:28:41.246Z,1537468121.246 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2018-09-20T18:28:41.246Z,1537468121.246 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2018-09-20T18:28:41.747Z,1537468121.747 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2018-09-20T18:28:41.748Z,1537468121.748 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2018-09-20T18:28:41.955Z,1537468121.955 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2018-09-20T18:28:41.955Z,1537468121.955 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2018-09-20T18:28:42.054Z,1537468122.054 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2018-09-20T18:28:42.054Z,1537468122.054 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2018-09-20T18:28:42.544Z,1537468122.544 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2018-09-20T18:28:42.545Z,1537468122.545 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2018-09-20T18:28:42.652Z,1537468122.652 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2018-09-20T18:28:42.654Z,1537468122.654 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/
2018-09-20T18:28:42.655Z,1537468122.655 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Battery.cfg
2018-09-20T18:28:42.882Z,1537468122.882 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2018-09-20T18:28:42.882Z,1537468122.882 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/BIT.cfg
2018-09-20T18:28:42.980Z,1537468122.980 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Navigation.cfg
2018-09-20T18:28:43.074Z,1537468123.074 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Control.cfg
2018-09-20T18:28:43.177Z,1537468123.177 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Simulator.cfg
2018-09-20T18:28:43.262Z,1537468123.262 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Science.cfg
2018-09-20T18:28:43.396Z,1537468123.396 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Sensor.cfg
2018-09-20T18:28:43.565Z,1537468123.565 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Servo.cfg
2018-09-20T18:28:43.675Z,1537468123.675 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/logger.cfg
2018-09-20T18:28:43.759Z,1537468123.759 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/secure.cfg
2018-09-20T18:28:43.843Z,1537468123.843 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/vehicle.cfg
2018-09-20T18:28:44.034Z,1537468124.034 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/root/
2018-09-20T18:28:44.035Z,1537468124.035 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2018-09-20T18:28:44.040Z,1537468124.040 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2018-09-20T18:28:44.166Z,1537468124.166 [SBIT](DEBUG): Construct Startup Built In Test.
2018-09-20T18:28:44.197Z,1537468124.197 [SBIT] Loaded
2018-09-20T18:28:44.197Z,1537468124.197 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2018-09-20T18:28:44.198Z,1537468124.198 [IBIT](DEBUG): Construct Initiated Built In Test.
2018-09-20T18:28:44.225Z,1537468124.225 [IBIT] Loaded
2018-09-20T18:28:44.225Z,1537468124.225 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2018-09-20T18:28:44.228Z,1537468124.228 [CBIT](DEBUG): Construct Continuous Built In Test.
2018-09-20T18:28:44.386Z,1537468124.386 [CBIT] Loaded
2018-09-20T18:28:44.386Z,1537468124.386 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2018-09-20T18:28:44.386Z,1537468124.386 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2018-09-20T18:28:44.387Z,1537468124.387 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2018-09-20T18:28:44.453Z,1537468124.453 [VerticalControl](DEBUG): Construct VerticalControl.
2018-09-20T18:28:44.555Z,1537468124.555 [VerticalControl] Loaded
2018-09-20T18:28:44.555Z,1537468124.555 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2018-09-20T18:28:44.556Z,1537468124.556 [HorizontalControl](DEBUG): Construct HorizontalControl.
2018-09-20T18:28:44.617Z,1537468124.617 [HorizontalControl] Loaded
2018-09-20T18:28:44.618Z,1537468124.618 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2018-09-20T18:28:44.618Z,1537468124.618 [SpeedControl](DEBUG): Construct SpeedControl.
2018-09-20T18:28:44.624Z,1537468124.624 [SpeedControl] Loaded
2018-09-20T18:28:44.624Z,1537468124.624 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2018-09-20T18:28:44.625Z,1537468124.625 [LoopControl](DEBUG): Construct LoopControl.
2018-09-20T18:28:44.625Z,1537468124.625 [LoopControl] Loaded
2018-09-20T18:28:44.626Z,1537468124.626 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2018-09-20T18:28:44.626Z,1537468124.626 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2018-09-20T18:28:44.627Z,1537468124.627 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2018-09-20T18:28:44.668Z,1537468124.668 [DepthRateCalculator] Loaded
2018-09-20T18:28:44.668Z,1537468124.668 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2018-09-20T18:28:44.673Z,1537468124.673 [PitchRateCalculator] Loaded
2018-09-20T18:28:44.674Z,1537468124.674 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2018-09-20T18:28:44.690Z,1537468124.690 [SpeedCalculator] Loaded
2018-09-20T18:28:44.690Z,1537468124.690 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2018-09-20T18:28:44.711Z,1537468124.711 [TempGradientCalculator] Loaded
2018-09-20T18:28:44.711Z,1537468124.711 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2018-09-20T18:28:44.717Z,1537468124.717 [YawRateCalculator] Loaded
2018-09-20T18:28:44.717Z,1537468124.717 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2018-09-20T18:28:44.747Z,1537468124.747 [ElevatorOffsetCalculator] Loaded
2018-09-20T18:28:44.747Z,1537468124.747 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2018-09-20T18:28:44.747Z,1537468124.747 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2018-09-20T18:28:44.748Z,1537468124.748 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2018-09-20T18:28:44.812Z,1537468124.812 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2018-09-20T18:28:44.812Z,1537468124.812 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2018-09-20T18:28:45.051Z,1537468125.051 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2018-09-20T18:28:45.052Z,1537468125.052 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2018-09-20T18:28:45.162Z,1537468125.162 [DeadReckonUsingMultipleVelocitySources] Loaded
2018-09-20T18:28:45.162Z,1537468125.162 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2018-09-20T18:28:45.217Z,1537468125.217 [DeadReckonUsingSpeedCalculator] Loaded
2018-09-20T18:28:45.217Z,1537468125.217 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2018-09-20T18:28:45.233Z,1537468125.233 [NavChart] Loaded
2018-09-20T18:28:45.234Z,1537468125.234 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2018-09-20T18:28:45.238Z,1537468125.238 [UniversalFixResidualReporter] Loaded
2018-09-20T18:28:45.238Z,1537468125.238 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2018-09-20T18:28:45.239Z,1537468125.239 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2018-09-20T18:28:45.239Z,1537468125.239 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2018-09-20T18:28:45.253Z,1537468125.253 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2018-09-20T18:28:45.253Z,1537468125.253 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2018-09-20T18:28:45.417Z,1537468125.417 [Aanderaa_O2] Loaded
2018-09-20T18:28:45.417Z,1537468125.417 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2018-09-20T18:28:45.463Z,1537468125.463 [WetLabsSeaOWL_UV_A] Loaded
2018-09-20T18:28:45.464Z,1537468125.464 [ComponentRegistry](DEBUG): Component "WetLabsSeaOWL_UV_A" handled in its own thread.
2018-09-20T18:28:45.465Z,1537468125.465 [WetLabsSeaOWL_UV_A ThreadHandler](DEBUG): Created PCaller Thread at 406DB4E0
2018-09-20T18:28:45.465Z,1537468125.465 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Protected caller Thread ID is 1078
2018-09-20T18:28:45.466Z,1537468125.466 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2018-09-20T18:28:45.466Z,1537468125.466 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2018-09-20T18:28:45.763Z,1537468125.763 [AHRS_M2] Loaded
2018-09-20T18:28:45.764Z,1537468125.764 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2018-09-20T18:28:45.833Z,1537468125.833 [DataOverHttps] Loaded
2018-09-20T18:28:45.833Z,1537468125.833 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2018-09-20T18:28:45.846Z,1537468125.846 [Depth_Keller] Loaded
2018-09-20T18:28:45.847Z,1537468125.847 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2018-09-20T18:28:45.852Z,1537468125.852 [DropWeight] Loaded
2018-09-20T18:28:45.852Z,1537468125.852 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2018-09-20T18:28:46.097Z,1537468126.097 [NAL9602] Loaded
2018-09-20T18:28:46.097Z,1537468126.097 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2018-09-20T18:28:46.118Z,1537468126.118 [Onboard] Loaded
2018-09-20T18:28:46.118Z,1537468126.118 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2018-09-20T18:28:46.126Z,1537468126.126 [Radio_Surface] Loaded
2018-09-20T18:28:46.126Z,1537468126.126 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2018-09-20T18:28:46.134Z,1537468126.134 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4093C4E0
2018-09-20T18:28:46.134Z,1537468126.134 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 1079
2018-09-20T18:28:46.163Z,1537468126.163 [RDI_Pathfinder] Loaded
2018-09-20T18:28:46.164Z,1537468126.164 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread.
2018-09-20T18:28:46.186Z,1537468126.186 [RDI_PathfinderUp] Loaded
2018-09-20T18:28:46.186Z,1537468126.186 [ComponentRegistry](DEBUG): SyncComponent "RDI_PathfinderUp" handled in the control thread.
2018-09-20T18:28:46.193Z,1537468126.193 [SCPI] Loaded
2018-09-20T18:28:46.193Z,1537468126.193 [ComponentRegistry](DEBUG): SyncComponent "SCPI" handled in the control thread.
2018-09-20T18:28:47.993Z,1537468127.993 [BPC1] Loaded
2018-09-20T18:28:47.993Z,1537468127.993 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2018-09-20T18:28:47.994Z,1537468127.994 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2018-09-20T18:28:47.994Z,1537468127.994 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2018-09-20T18:28:48.091Z,1537468128.091 [BuoyancyServo] Loaded
2018-09-20T18:28:48.092Z,1537468128.092 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2018-09-20T18:28:48.103Z,1537468128.103 [ElevatorServo] Loaded
2018-09-20T18:28:48.104Z,1537468128.104 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2018-09-20T18:28:48.115Z,1537468128.115 [MassServo] Loaded
2018-09-20T18:28:48.115Z,1537468128.115 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2018-09-20T18:28:48.127Z,1537468128.127 [RudderServo] Loaded
2018-09-20T18:28:48.127Z,1537468128.127 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2018-09-20T18:28:48.138Z,1537468128.138 [ThrusterServo] Loaded
2018-09-20T18:28:48.139Z,1537468128.139 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2018-09-20T18:28:48.139Z,1537468128.139 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2018-09-20T18:28:48.140Z,1537468128.140 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2018-09-20T18:28:48.238Z,1537468128.238 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2018-09-20T18:28:48.239Z,1537468128.239 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2018-09-20T18:28:48.263Z,1537468128.263 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2018-09-20T18:28:48.267Z,1537468128.267 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2018-09-20T18:28:48.268Z,1537468128.268 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2018-09-20T18:28:48.274Z,1537468128.274 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2018-09-20T18:28:48.275Z,1537468128.275 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 409E54E0
2018-09-20T18:28:48.276Z,1537468128.276 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 1080
2018-09-20T18:28:48.280Z,1537468128.280 [Supervisor](INFO): Main Thread ID is 796
2018-09-20T18:28:48.281Z,1537468128.281 [Supervisor](DEBUG): Running supervisor.
2018-09-20T18:28:48.281Z,1537468128.281 [CommandLine ThreadHandler](INFO): Handler Thread ID is 1081
2018-09-20T18:28:48.284Z,1537468128.284 [controlThread ThreadHandler](INFO): Handler Thread ID is 1082
2018-09-20T18:28:48.284Z,1537468128.284 [controlThread](DEBUG): Initializing ControlThread
2018-09-20T18:28:48.285Z,1537468128.285 [SBIT](INFO): Initialize SBIT Component.
2018-09-20T18:28:48.285Z,1537468128.285 [SBIT](IMPORTANT): git: 2018-09-20
2018-09-20T18:28:48.286Z,1537468128.286 [SBIT](INFO): git hash: cc82e4f04ca47b19cdcc10b5d3e1760510b3ba6f
2018-09-20T18:28:48.286Z,1537468128.286 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2018-09-20T18:28:48.286Z,1537468128.286 [SBIT](IMPORTANT): Kernel Version:#2 PREEMPT Thu Jan 11 20:13:48 PST 2018
2018-09-20T18:28:48.287Z,1537468128.287 [SBIT](INFO): Beginning SBIT in 24.000000 seconds.
2018-09-20T18:28:48.288Z,1537468128.288 [IBIT](INFO): Initialize IBIT Component.
2018-09-20T18:28:48.289Z,1537468128.289 [CBIT](DEBUG): Initialize CBIT Component.
2018-09-20T18:28:48.289Z,1537468128.289 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2018-09-20T18:28:48.290Z,1537468128.290 [logger ThreadHandler](INFO): Handler Thread ID is 1083
2018-09-20T18:28:48.318Z,1537468128.318 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Handler Thread ID is 1084
2018-09-20T18:28:48.320Z,1537468128.320 [WetLabsSeaOWL_UV_A](INFO): Powering down
2018-09-20T18:28:48.354Z,1537468128.354 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 1085
2018-09-20T18:28:48.360Z,1537468128.360 [Radio_Surface](INFO): Powering up
2018-09-20T18:28:48.366Z,1537468128.366 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 1086
2018-09-20T18:28:48.370Z,1537468128.370 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2018-09-20T18:28:48.370Z,1537468128.370 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2018-09-20T18:28:48.370Z,1537468128.370 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2018-09-20T18:28:48.370Z,1537468128.370 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2018-09-20T18:28:48.371Z,1537468128.371 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2018-09-20T18:28:48.371Z,1537468128.371 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2018-09-20T18:28:48.371Z,1537468128.371 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2018-09-20T18:28:48.371Z,1537468128.371 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2018-09-20T18:28:48.371Z,1537468128.371 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2018-09-20T18:28:48.372Z,1537468128.372 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2018-09-20T18:28:48.372Z,1537468128.372 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2018-09-20T18:28:48.372Z,1537468128.372 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2018-09-20T18:28:48.372Z,1537468128.372 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2018-09-20T18:28:48.372Z,1537468128.372 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2018-09-20T18:28:48.373Z,1537468128.373 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2018-09-20T18:28:48.373Z,1537468128.373 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2018-09-20T18:28:48.394Z,1537468128.394 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2018-09-20T18:28:48.396Z,1537468128.396 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2018-09-20T18:28:48.396Z,1537468128.396 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2018-09-20T18:28:48.397Z,1537468128.397 [LoopControl](DEBUG): Initialize LoopControlComponent.
2018-09-20T18:28:48.397Z,1537468128.397 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2018-09-20T18:28:48.397Z,1537468128.397 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2018-09-20T18:28:48.398Z,1537468128.398 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2018-09-20T18:28:48.398Z,1537468128.398 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2018-09-20T18:28:48.399Z,1537468128.399 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2018-09-20T18:28:48.399Z,1537468128.399 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2018-09-20T18:28:48.400Z,1537468128.400 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2018-09-20T18:28:48.400Z,1537468128.400 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s.
2018-09-20T18:28:48.401Z,1537468128.401 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s.
2018-09-20T18:28:48.401Z,1537468128.401 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-09-20T18:28:48.402Z,1537468128.402 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-09-20T18:28:48.402Z,1537468128.402 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-09-20T18:28:48.403Z,1537468128.403 [NavChart](DEBUG): Initialize NavChart Navigation.
2018-09-20T18:28:48.403Z,1537468128.403 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2018-09-20T18:28:48.411Z,1537468128.411 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2018-09-20T18:28:48.434Z,1537468128.434 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2018-09-20T18:28:48.466Z,1537468128.466 [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-20T18:28:48.466Z,1537468128.466 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2018-09-20T18:28:48.554Z,1537468128.554 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2018-09-20T18:28:48.555Z,1537468128.555 [Default:A.Wait](DEBUG): Construct Wait.
2018-09-20T18:28:48.556Z,1537468128.556 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2018-09-20T18:28:48.599Z,1537468128.599 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2018-09-20T18:28:48.602Z,1537468128.602 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2018-09-20T18:28:48.623Z,1537468128.623 [Default:E.Execute](DEBUG): Construct Execute.
2018-09-20T18:28:48.627Z,1537468128.627 [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-20T18:28:48.638Z,1537468128.638 [controlThread](DEBUG): Component order: CycleStarter,Aanderaa_O2,AHRS_M2,DataOverHttps,Depth_Keller,DropWeight,NAL9602,Onboard,RDI_Pathfinder,RDI_PathfinderUp,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-20T18:28:48.706Z,1537468128.706 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2018-09-20T18:28:48.770Z,1537468128.770 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2018-09-20T18:28:49.140Z,1537468129.140 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-09-20T18:28:49.168Z,1537468129.168 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-09-20T18:28:49.283Z,1537468129.283 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2018-09-20T18:28:49.290Z,1537468129.290 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2018-09-20T18:28:49.297Z,1537468129.297 [ElevatorServo](DEBUG): Initializing EZServoServo.
2018-09-20T18:28:49.302Z,1537468129.302 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2018-09-20T18:28:49.324Z,1537468129.324 [MassServo](DEBUG): Initializing EZServoServo.
2018-09-20T18:28:49.330Z,1537468129.330 [MassServo](DEBUG): Initializing MassServo.
2018-09-20T18:28:49.337Z,1537468129.337 [RudderServo](DEBUG): Initializing EZServoServo.
2018-09-20T18:28:49.346Z,1537468129.346 [RudderServo](DEBUG): Initializing RudderServo.
2018-09-20T18:28:49.367Z,1537468129.367 [ThrusterServo](DEBUG): Initializing EZServoServo.
2018-09-20T18:28:49.374Z,1537468129.374 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2018-09-20T18:28:49.670Z,1537468129.670 [RDI_PathfinderUp](INFO): Powering down
2018-09-20T18:28:49.738Z,1537468129.738 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-09-20T18:28:49.750Z,1537468129.750 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-09-20T18:28:49.923Z,1537468129.923 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-09-20T18:28:49.924Z,1537468129.924 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-09-20T18:28:50.266Z,1537468130.266 [BuoyancyServo](ERROR): Buoyancy initialization uart error serial timeout
2018-09-20T18:28:50.266Z,1537468130.266 [BuoyancyServo](FAULT): Buoyancy failed to initialize
2018-09-20T18:28:50.266Z,1537468130.266 [BuoyancyServo] Communications Fault, FailCount= 1
2018-09-20T18:28:50.266Z,1537468130.266 [BuoyancyServo](ERROR): Communications Fault
2018-09-20T18:28:50.477Z,1537468130.477 [CBIT](ERROR): Communications Fault in component: BuoyancyServo
2018-09-20T18:28:50.529Z,1537468130.529 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-09-20T18:28:50.538Z,1537468130.538 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-09-20T18:28:50.552Z,1537468130.552 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2018-09-20T18:28:50.552Z,1537468130.552 [BuoyancyServo](INFO): Powering down
2018-09-20T18:28:50.921Z,1537468130.921 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-09-20T18:28:50.922Z,1537468130.922 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-09-20T18:28:51.321Z,1537468131.321 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-09-20T18:28:51.322Z,1537468131.322 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-09-20T18:28:51.806Z,1537468131.806 [Aanderaa_O2](INFO): Powering down
2018-09-20T18:28:51.937Z,1537468131.937 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-09-20T18:28:51.946Z,1537468131.946 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-09-20T18:28:52.150Z,1537468132.150 [AHRS_M2](ERROR): Read RFS packet UART error: serial timeout
2018-09-20T18:28:52.193Z,1537468132.193 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-09-20T18:28:52.195Z,1537468132.195 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-09-20T18:28:52.575Z,1537468132.575 [CBIT](INFO): Clearing failed state for component BuoyancyServo
2018-09-20T18:28:52.575Z,1537468132.575 [BuoyancyServo] No Fault, FailCount= 1
2018-09-20T18:28:52.944Z,1537468132.944 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2018-09-20T18:28:53.063Z,1537468133.063 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2018-09-20T18:29:02.523Z,1537468142.523 [RDI_Pathfinder](ERROR): Failed to parse:Pathfinder
2018-09-20T18:29:12.952Z,1537468152.952 [SBIT](IMPORTANT): Beginning Startup BIT
2018-09-20T18:29:12.956Z,1537468152.956 [CBIT](IMPORTANT): Beginning ground fault scan
2018-09-20T18:29:14.651Z,1537468154.651 [CommandLine](IMPORTANT): got command report touch platform_battery_voltage
2018-09-20T18:29:16.284Z,1537468156.284 [NAL9602](INFO): Powering up NAL9602
2018-09-20T18:29:24.007Z,1537468164.007 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.017037
CHAN A1 (24V): -0.020267
CHAN A2 (12V): -0.007220
CHAN A3 (5V): -0.002106
CHAN B0 (3.3V): 0.000299
CHAN B1 (3.15aV): -0.000113
CHAN B2 (3.15bV): 0.000149
CHAN B3 (GND): 0.002328
OPEN: 0.005036
Full Scale Calc: 4.765 mA, -1.589 mA
2018-09-20T18:29:26.867Z,1537468166.867 [CommandLine](IMPORTANT): got command report touch BPC1.platform_battery_voltage
2018-09-20T18:29:27.475Z,1537468167.475 [NAL9602](INFO): NAL9602 initialized
2018-09-20T18:30:07.096Z,1537468207.096 [SBIT](IMPORTANT): SBIT PASSED
2018-09-20T18:30:07.171Z,1537468207.171 [CommandLine](IMPORTANT): got command configSet list
2018-09-20T18:30:07.171Z,1537468207.171 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2018-09-20T18:30:07.172Z,1537468207.172 [CommandLine](IMPORTANT): BPC1.batterySamplingInterval=1 minute;

2018-09-20T18:30:07.172Z,1537468207.172 [CommandLine](IMPORTANT): IBIT.batteryVoltageThreshold=17 volt;

2018-09-20T18:30:07.172Z,1537468207.172 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral=275 cubic_centimeter;

2018-09-20T18:30:07.172Z,1537468207.172 [CommandLine](IMPORTANT): VerticalControl.massDefault=-1 millimeter;

2018-09-20T18:30:07.492Z,1537468207.492 [MissionManager](IMPORTANT): Started mission Startup
2018-09-20T18:30:07.492Z,1537468207.492 [Startup] Running Loop=1
2018-09-20T18:30:07.492Z,1537468207.492 [Startup](DEBUG): Aggregate::initialize Startup
2018-09-20T18:30:07.492Z,1537468207.492 [Startup:A.GoToSurface] Running Loop=1
2018-09-20T18:30:07.492Z,1537468207.492 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-09-20T18:30:07.493Z,1537468207.493 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2018-09-20T18:30:07.493Z,1537468207.493 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2018-09-20T18:30:07.494Z,1537468207.494 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2018-09-20T18:30:07.494Z,1537468207.494 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-09-20T18:30:07.495Z,1537468207.495 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2018-09-20T18:30:07.501Z,1537468207.501 [Startup:StartupSatComms] Running Loop=1
2018-09-20T18:30:07.501Z,1537468207.501 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2018-09-20T18:30:07.501Z,1537468207.501 [Startup:StartupSatComms:A] Running Loop=1
2018-09-20T18:30:07.882Z,1537468207.882 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2018-09-20T18:31:07.887Z,1537468267.887 [Startup:StartupSatComms:A](INFO): Timed out from 2018-09-20T18:30:07.5Z
2018-09-20T18:31:07.887Z,1537468267.887 [Startup:StartupSatComms:A] Stopped
2018-09-20T18:31:07.887Z,1537468267.887 [Startup:StartupSatComms:B] Running Loop=1
2018-09-20T18:31:08.286Z,1537468268.286 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2018-09-20T18:31:48.671Z,1537468308.671 [DeadReckonUsingMultipleVelocitySources](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-09-20T18:31:48.672Z,1537468308.672 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2018-09-20T18:31:48.672Z,1537468308.672 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2018-09-20T18:31:48.678Z,1537468308.678 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-09-20T18:31:48.678Z,1537468308.678 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 1
2018-09-20T18:31:48.678Z,1537468308.678 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-09-20T18:31:48.705Z,1537468308.705 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2018-09-20T18:31:48.705Z,1537468308.705 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-09-20T18:31:49.095Z,1537468309.095 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2018-09-20T18:31:49.095Z,1537468309.095 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2018-09-20T18:31:49.096Z,1537468309.096 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-09-20T18:31:49.096Z,1537468309.096 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 1
2018-09-20T18:31:49.503Z,1537468309.503 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2018-09-20T18:31:49.504Z,1537468309.504 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s.
2018-09-20T18:31:49.504Z,1537468309.504 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s.
2018-09-20T18:31:49.504Z,1537468309.504 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-09-20T18:31:49.505Z,1537468309.505 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-09-20T18:31:49.505Z,1537468309.505 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-09-20T18:32:07.904Z,1537468327.904 [Startup:StartupSatComms:B](INFO): Timed out from 2018-09-20T18:31:07.9Z
2018-09-20T18:32:07.904Z,1537468327.904 [Startup:StartupSatComms:B] Stopped
2018-09-20T18:32:07.904Z,1537468327.904 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2018-09-20T18:32:07.904Z,1537468327.904 [Startup:StartupSatComms] Stopped
2018-09-20T18:32:07.905Z,1537468327.905 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2018-09-20T18:32:07.914Z,1537468327.914 [Startup](INFO): Completed Startup
2018-09-20T18:32:07.914Z,1537468327.914 [MissionManager](INFO): Startup is completed.
2018-09-20T18:32:07.914Z,1537468327.914 [MissionManager](INFO): Uninitializing Mission Startup
2018-09-20T18:32:07.914Z,1537468327.914 [Startup] Stopped
2018-09-20T18:32:07.915Z,1537468327.915 [Startup](DEBUG): Aggregate::uninitialize Startup
2018-09-20T18:32:07.915Z,1537468327.915 [Startup:A.GoToSurface] Stopped
2018-09-20T18:32:07.915Z,1537468327.915 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2018-09-20T18:32:08.285Z,1537468328.285 [MissionManager](IMPORTANT): Started mission Default
2018-09-20T18:32:08.285Z,1537468328.285 [Default] Running Loop=1
2018-09-20T18:32:08.285Z,1537468328.285 [Default](DEBUG): Aggregate::initialize Default
2018-09-20T18:32:08.285Z,1537468328.285 [Default:B.GoToSurface] Running Loop=1
2018-09-20T18:32:08.285Z,1537468328.285 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-09-20T18:32:08.290Z,1537468328.290 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2018-09-20T18:32:08.290Z,1537468328.290 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2018-09-20T18:32:08.290Z,1537468328.290 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2018-09-20T18:32:08.291Z,1537468328.291 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-09-20T18:32:08.291Z,1537468328.291 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2018-09-20T18:32:08.291Z,1537468328.291 [Default:A.Wait] Running Loop=1
2018-09-20T18:32:08.292Z,1537468328.292 [Default:A.Wait](DEBUG): Initialize Wait Component.
2018-09-20T18:32:21.499Z,1537468341.499 [Default:A.Wait](INFO): Done Waiting.
2018-09-20T18:32:21.499Z,1537468341.499 [Default:A.Wait] Stopped
2018-09-20T18:32:21.499Z,1537468341.499 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2018-09-20T18:32:21.886Z,1537468341.886 [Default:CheckIn] Running Loop=1
2018-09-20T18:32:21.886Z,1537468341.886 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-09-20T18:32:21.886Z,1537468341.886 [Default:CheckIn:Read_GPS] Running Loop=1
2018-09-20T18:32:22.274Z,1537468342.274 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2018-09-20T18:32:54.421Z,1537468374.421 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004362
2018-09-20T18:34:30.971Z,1537468470.971 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2018-09-20T18:34:49.828Z,1537468489.828 [DeadReckonUsingMultipleVelocitySources](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-09-20T18:34:49.828Z,1537468489.828 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2018-09-20T18:34:49.828Z,1537468489.828 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2018-09-20T18:34:49.830Z,1537468489.830 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-09-20T18:34:49.830Z,1537468489.830 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 2
2018-09-20T18:34:49.830Z,1537468489.830 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-09-20T18:34:49.861Z,1537468489.861 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2018-09-20T18:34:49.861Z,1537468489.861 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-09-20T18:34:50.260Z,1537468490.260 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2018-09-20T18:34:50.260Z,1537468490.260 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2018-09-20T18:34:50.260Z,1537468490.260 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-09-20T18:34:50.260Z,1537468490.260 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 2
2018-09-20T18:34:53.417Z,1537468493.417 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2018-09-20T18:34:53.417Z,1537468493.417 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s.
2018-09-20T18:34:53.417Z,1537468493.417 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s.
2018-09-20T18:34:53.418Z,1537468493.418 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-09-20T18:34:53.418Z,1537468493.418 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-09-20T18:34:53.419Z,1537468493.419 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-09-20T18:35:15.118Z,1537468515.118 [BPC1](FAULT): Battery stick #21 (s/n: 014E) reported OVER_TEMP_ALARM. Status code: 0x1717.
2018-09-20T18:35:15.120Z,1537468515.120 [BPC1](INFO): Calculating totals. Valid battery stick count: 55. Valid reserve battery stick count: 6.
2018-09-20T18:35:15.137Z,1537468515.137 [BPC1](CRITICAL): Battery Voltage Below Threshold. 15876.363281 V.
2018-09-20T18:35:15.187Z,1537468515.187 [CommandLine](FAULT): Scheduling is paused
2018-09-20T18:35:15.187Z,1537468515.187 [CBIT](INFO): Critical error at 20180920T183515
2018-09-20T18:35:15.188Z,1537468515.188 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2018-09-20T18:35:15.195Z,1537468515.195 [Reporter](INFO): BPC1.platform_battery_voltage no_value
2018-09-20T18:37:22.072Z,1537468642.072 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-09-20T18:32:21.9Z
2018-09-20T18:37:22.072Z,1537468642.072 [Default:CheckIn:Read_GPS] Stopped
2018-09-20T18:37:22.072Z,1537468642.072 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-09-20T18:37:22.490Z,1537468642.490 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2018-09-20T18:37:26.931Z,1537468646.931 [DataOverHttps](INFO): Sending 93 bytes from file Logs/20180920T172822/Courier0019.lzma
2018-09-20T18:37:27.721Z,1537468647.721 [DataOverHttps](INFO): Moved sent file to Logs/20180920T172822/Courier0019.lzma.bak
2018-09-20T18:37:27.721Z,1537468647.721 [DataOverHttps](INFO): SBD MOMSN=8548384
2018-09-20T18:37:37.071Z,1537468657.071 [DataOverHttps](INFO): Sending 245 bytes from file Logs/20180920T182838/Courier0004.lzma
2018-09-20T18:37:37.845Z,1537468657.845 [DataOverHttps](INFO): Moved sent file to Logs/20180920T182838/Courier0004.lzma.bak
2018-09-20T18:37:37.845Z,1537468657.845 [DataOverHttps](INFO): SBD MOMSN=8548387
2018-09-20T18:37:47.243Z,1537468667.243 [DataOverHttps](INFO): Sending 658 bytes from file Logs/20180920T172822/Express0020.lzma
2018-09-20T18:37:48.016Z,1537468668.016 [DataOverHttps](INFO): Moved sent file to Logs/20180920T172822/Express0020.lzma.bak
2018-09-20T18:37:48.017Z,1537468668.017 [DataOverHttps](INFO): SBD MOMSN=8548391
2018-09-20T18:37:53.540Z,1537468673.540 [DeadReckonUsingMultipleVelocitySources](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-09-20T18:37:53.540Z,1537468673.540 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2018-09-20T18:37:53.540Z,1537468673.540 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2018-09-20T18:37:53.542Z,1537468673.542 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-09-20T18:37:53.543Z,1537468673.543 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 3
2018-09-20T18:37:53.543Z,1537468673.543 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-09-20T18:37:53.578Z,1537468673.578 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2018-09-20T18:37:53.578Z,1537468673.578 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-09-20T18:37:53.966Z,1537468673.966 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2018-09-20T18:37:53.966Z,1537468673.966 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2018-09-20T18:37:53.967Z,1537468673.967 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-09-20T18:37:53.967Z,1537468673.967 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 3
2018-09-20T18:37:54.346Z,1537468674.346 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2018-09-20T18:37:54.347Z,1537468674.347 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s.
2018-09-20T18:37:54.347Z,1537468674.347 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s.
2018-09-20T18:37:54.348Z,1537468674.348 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-09-20T18:37:54.348Z,1537468674.348 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-09-20T18:37:54.348Z,1537468674.348 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-09-20T18:37:57.961Z,1537468677.961 [DataOverHttps](INFO): Sending 808 bytes from file Logs/20180920T182838/Express0001.lzma
2018-09-20T18:37:58.752Z,1537468678.752 [DataOverHttps](INFO): Moved sent file to Logs/20180920T182838/Express0001.lzma.bak
2018-09-20T18:37:58.753Z,1537468678.753 [DataOverHttps](INFO): SBD MOMSN=8548426
2018-09-20T18:38:08.126Z,1537468688.126 [DataOverHttps](INFO): Sending 279 bytes from file Logs/20180920T182838/Express0005.lzma
2018-09-20T18:38:08.901Z,1537468688.901 [DataOverHttps](INFO): Moved sent file to Logs/20180920T182838/Express0005.lzma.bak
2018-09-20T18:38:08.901Z,1537468688.901 [DataOverHttps](INFO): SBD MOMSN=8548446
2018-09-20T18:38:09.378Z,1537468689.378 [Default:CheckIn:Read_Iridium] Stopped
2018-09-20T18:38:09.378Z,1537468689.378 [Default:CheckIn:C.Wait] Running Loop=1
2018-09-20T18:38:09.378Z,1537468689.378 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-09-20T18:38:48.205Z,1537468728.205 [NAL9602](INFO): GPS fix at 20180920T183847: (36.802896, -121.787753)
2018-09-20T18:39:20.287Z,1537468760.287 [NAL9602](INFO): Powering down
2018-09-20T18:43:10.138Z,1537468990.138 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-09-20T18:43:10.138Z,1537468990.138 [Default:CheckIn:C.Wait] Stopped
2018-09-20T18:43:10.138Z,1537468990.138 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-09-20T18:43:10.139Z,1537468990.139 [Default:CheckIn:D] Running Loop=1
2018-09-20T18:43:10.499Z,1537468990.499 [Default:CheckIn:D] Stopped
2018-09-20T18:43:10.499Z,1537468990.499 [Default:CheckIn:E] Running Loop=1
2018-09-20T18:43:13.714Z,1537468993.714 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 11.036863 min 
2018-09-20T18:43:13.716Z,1537468993.716 [Default:CheckIn:E] Stopped
2018-09-20T18:43:13.716Z,1537468993.716 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-09-20T18:43:13.716Z,1537468993.716 [Default:CheckIn] Stopped
2018-09-20T18:43:13.716Z,1537468993.716 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-09-20T18:43:13.717Z,1537468993.717 [Default:CheckIn](INFO): Running loop #2
2018-09-20T18:43:13.717Z,1537468993.717 [Default:CheckIn] Running Loop=2
2018-09-20T18:43:13.717Z,1537468993.717 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-09-20T18:43:13.717Z,1537468993.717 [Default:CheckIn:Read_GPS] Running Loop=1
2018-09-20T18:43:14.196Z,1537468994.196 [NAL9602](INFO): Powering up
2018-09-20T18:43:25.387Z,1537469005.387 [NAL9602](INFO): NAL9602 initialized
2018-09-20T18:43:57.380Z,1537469037.380 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2018-09-20T18:43:57.462Z,1537469037.462 [NAL9602](FAULT): received: 
+CSQ:0

OK
2018-09-20T18:43:57.462Z,1537469037.462 [NAL9602] Data Fault, FailCount= 1
2018-09-20T18:43:57.462Z,1537469037.462 [NAL9602](ERROR): Data Fault
2018-09-20T18:43:57.564Z,1537469037.564 [CBIT](ERROR): Data Fault in component: NAL9602
2018-09-20T18:43:57.783Z,1537469037.783 [NAL9602](INFO): Powering down
2018-09-20T18:43:58.632Z,1537469038.632 [CBIT](INFO): Clearing failed state for component NAL9602
2018-09-20T18:43:58.632Z,1537469038.632 [NAL9602] No Fault, FailCount= 1
2018-09-20T18:44:27.907Z,1537469067.907 [NAL9602](INFO): Powering up NAL9602
2018-09-20T18:44:38.712Z,1537469078.712 [NAL9602](INFO): NAL9602 initialized
2018-09-20T18:45:38.221Z,1537469138.221 [NAL9602](INFO): SBD MO Status=2, MOMSN=866, MT Status=2, MTMSN=0
2018-09-20T18:45:38.221Z,1537469138.221 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-09-20T18:46:01.821Z,1537469161.821 [NAL9602](INFO): SBD MO Status=2, MOMSN=866, MT Status=2, MTMSN=0
2018-09-20T18:46:01.821Z,1537469161.821 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-09-20T18:46:16.793Z,1537469176.793 [Reporter](INFO): platform_battery_voltage 15.876364 V
2018-09-20T18:46:26.701Z,1537469186.701 [NAL9602](INFO): SBD MO Status=2, MOMSN=866, MT Status=2, MTMSN=0
2018-09-20T18:46:26.701Z,1537469186.701 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-09-20T18:46:47.913Z,1537469207.913 [NAL9602](INFO): SBD MO Status=0, MOMSN=866, MT Status=0, MTMSN=0
2018-09-20T18:46:47.913Z,1537469207.913 [NAL9602](INFO): No messages in MT queue
2018-09-20T18:47:27.375Z,1537469247.375 [CommandLine](IMPORTANT): got command get platform_battery_voltage
2018-09-20T18:47:27.376Z,1537469247.376 [CommandLine](IMPORTANT): platform_battery_voltage 15.876364 V
2018-09-20T18:48:14.434Z,1537469294.434 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-09-20T18:43:13.7Z
2018-09-20T18:48:14.434Z,1537469294.434 [Default:CheckIn:Read_GPS] Stopped
2018-09-20T18:48:14.434Z,1537469294.434 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-09-20T18:48:19.445Z,1537469299.445 [DataOverHttps](INFO): Sending 212 bytes from file Logs/20180920T182838/Courier0007.lzma
2018-09-20T18:48:20.224Z,1537469300.224 [DataOverHttps](INFO): Moved sent file to Logs/20180920T182838/Courier0007.lzma.bak
2018-09-20T18:48:20.224Z,1537469300.224 [DataOverHttps](INFO): SBD MOMSN=8548490
2018-09-20T18:48:25.577Z,1537469305.577 [RDI_Pathfinder](ERROR): Failed to parse:
:BI,-32768,-32768,-32768,-32768,V
2018-09-20T18:48:29.789Z,1537469309.789 [DataOverHttps](INFO): Sending 357 bytes from file Logs/20180920T182838/Express0008.lzma
2018-09-20T18:48:30.543Z,1537469310.543 [DataOverHttps](INFO): Moved sent file to Logs/20180920T182838/Express0008.lzma.bak
2018-09-20T18:48:30.543Z,1537469310.543 [DataOverHttps](INFO): SBD MOMSN=8548493
2018-09-20T18:48:31.015Z,1537469311.015 [Default:CheckIn:Read_Iridium] Stopped
2018-09-20T18:48:31.015Z,1537469311.015 [Default:CheckIn:C.Wait] Running Loop=1
2018-09-20T18:48:31.015Z,1537469311.015 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-09-20T18:48:44.723Z,1537469324.723 [NAL9602](INFO): Powering down
2018-09-20T18:50:43.066Z,1537469443.066 [BPC1](ERROR): BPC1B: No match for stick with serial number:1717 in the onboard configuration file.
2018-09-20T18:52:30.029Z,1537469550.029 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2018-09-20T18:52:42.147Z,1537469562.147 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2018-09-20T18:52:42.198Z,1537469562.198 [Reporter](INFO): BPC1.platform_battery_voltage no_value
2018-09-20T18:53:31.725Z,1537469611.725 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-09-20T18:53:31.725Z,1537469611.725 [Default:CheckIn:C.Wait] Stopped
2018-09-20T18:53:31.725Z,1537469611.725 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-09-20T18:53:31.725Z,1537469611.725 [Default:CheckIn:D] Running Loop=1
2018-09-20T18:53:32.166Z,1537469612.166 [Default:CheckIn:D] Stopped
2018-09-20T18:53:32.166Z,1537469612.166 [Default:CheckIn:E] Running Loop=1
2018-09-20T18:53:35.575Z,1537469615.575 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 21.398012 min 
2018-09-20T18:53:35.576Z,1537469615.576 [Default:CheckIn:E] Stopped
2018-09-20T18:53:35.576Z,1537469615.576 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-09-20T18:53:35.576Z,1537469615.576 [Default:CheckIn] Stopped
2018-09-20T18:53:35.576Z,1537469615.576 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-09-20T18:53:35.576Z,1537469615.576 [Default:CheckIn](INFO): Running loop #3
2018-09-20T18:53:35.576Z,1537469615.576 [Default:CheckIn] Running Loop=3
2018-09-20T18:53:35.576Z,1537469615.576 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-09-20T18:53:35.576Z,1537469615.576 [Default:CheckIn:Read_GPS] Running Loop=1
2018-09-20T18:53:36.039Z,1537469616.039 [NAL9602](INFO): Powering up
2018-09-20T18:53:39.482Z,1537469619.482 [CommandLine](IMPORTANT): got command ibit
2018-09-20T18:53:39.684Z,1537469619.684 [IBIT](IMPORTANT): Beginning Initiated BIT
2018-09-20T18:53:39.685Z,1537469619.685 [IBIT](IMPORTANT): Beginning control surface checks.
2018-09-20T18:53:39.688Z,1537469619.688 [CBIT](IMPORTANT): Beginning ground fault scan
2018-09-20T18:53:46.831Z,1537469626.831 [NAL9602](INFO): NAL9602 initialized
2018-09-20T18:53:47.639Z,1537469627.639 [NAL9602](FAULT): GPS failed to acquire within timeout.
2018-09-20T18:53:47.640Z,1537469627.640 [NAL9602] Data Fault, FailCount= 1
2018-09-20T18:53:47.640Z,1537469627.640 [NAL9602](ERROR): Data Fault
2018-09-20T18:53:47.715Z,1537469627.715 [CBIT](ERROR): Data Fault in component: NAL9602
2018-09-20T18:53:48.028Z,1537469628.028 [NAL9602](INFO): Powering down
2018-09-20T18:53:48.923Z,1537469628.923 [CBIT](INFO): Clearing failed state for component NAL9602
2018-09-20T18:53:48.923Z,1537469628.923 [NAL9602] No Fault, FailCount= 1
2018-09-20T18:53:50.605Z,1537469630.605 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.137141
CHAN A1 (24V): -0.004017
CHAN A2 (12V): 0.001349
CHAN A3 (5V): -0.002636
CHAN B0 (3.3V): -0.001195
CHAN B1 (3.15aV): -0.001090
CHAN B2 (3.15bV): -0.000666
CHAN B3 (GND): -0.002791
OPEN: 0.004955
Full Scale Calc: 4.765 mA, -1.589 mA
2018-09-20T18:54:18.431Z,1537469658.431 [NAL9602](INFO): Powering up NAL9602
2018-09-20T18:54:29.231Z,1537469669.231 [NAL9602](INFO): NAL9602 initialized
2018-09-20T18:54:44.173Z,1537469684.173 [NAL9602](INFO): SBD MO Status=0, MOMSN=867, MT Status=0, MTMSN=0
2018-09-20T18:54:44.173Z,1537469684.173 [NAL9602](INFO): No messages in MT queue
2018-09-20T18:55:00.163Z,1537469700.163 [NAL9602](INFO): GPS fix at 20180920T185459: (36.802379, -121.787137)
2018-09-20T18:55:00.261Z,1537469700.261 [IBIT](IMPORTANT): Communications Status:
Fix Status: 1
Iridium Signal Strength: 2
Latitude: 36.802380 Longitude: -121.787140
2018-09-20T18:55:00.616Z,1537469700.616 [IBIT](IMPORTANT): Battery Status:
Battery Charge (AH): 0.000000
Voltage: 0.000000
2018-09-20T18:55:00.616Z,1537469700.616 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah
2018-09-20T18:55:00.616Z,1537469700.616 [IBIT](IMPORTANT): batteryVoltageThreshold: 17.000000 V
2018-09-20T18:55:01.013Z,1537469701.013 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2018-09-20T18:55:01.018Z,1537469701.018 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2018-09-20T18:55:01.018Z,1537469701.018 [IBIT](IMPORTANT): Pressure:10.395909 PSI
2018-09-20T18:55:01.018Z,1537469701.018 [IBIT](IMPORTANT): Humidity:22.707850 %
2018-09-20T18:55:01.495Z,1537469701.495 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2018-09-20T18:55:01.495Z,1537469701.495 [IBIT](IMPORTANT): buoyancyNeutral: 275.000000 cc
2018-09-20T18:55:01.495Z,1537469701.495 [IBIT](IMPORTANT): massDefault: -0.100000 cm
2018-09-20T18:55:01.496Z,1537469701.496 [IBIT](IMPORTANT): stopDepth: 215.000000 m
2018-09-20T18:55:01.496Z,1537469701.496 [IBIT](IMPORTANT): abortDepth: 255.000000 m
2018-09-20T18:55:01.496Z,1537469701.496 [IBIT](IMPORTANT): IBIT PASSED
2018-09-20T18:55:01.813Z,1537469701.813 [Default:CheckIn:Read_GPS] Stopped
2018-09-20T18:55:01.813Z,1537469701.813 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-09-20T18:55:06.357Z,1537469706.357 [DataOverHttps](INFO): Sending 80 bytes from file Logs/20180920T182838/Courier0010.lzma
2018-09-20T18:55:07.130Z,1537469707.130 [DataOverHttps](INFO): Moved sent file to Logs/20180920T182838/Courier0010.lzma.bak
2018-09-20T18:55:07.130Z,1537469707.130 [DataOverHttps](INFO): SBD MOMSN=8548540
2018-09-20T18:55:16.564Z,1537469716.564 [DataOverHttps](INFO): Sending 751 bytes from file Logs/20180920T182838/Express0011.lzma
2018-09-20T18:55:17.341Z,1537469717.341 [DataOverHttps](INFO): Moved sent file to Logs/20180920T182838/Express0011.lzma.bak
2018-09-20T18:55:17.341Z,1537469717.341 [DataOverHttps](INFO): SBD MOMSN=8548543
2018-09-20T18:55:17.372Z,1537469717.372 [RDI_Pathfinder](ERROR): Failed to parse:
:HM,G,D,0e8c,0ffd,*14.846,*-0.073,*0.000
2018-09-20T18:55:17.833Z,1537469717.833 [Default:CheckIn:Read_Iridium] Stopped
2018-09-20T18:55:17.833Z,1537469717.833 [Default:CheckIn:C.Wait] Running Loop=1
2018-09-20T18:55:17.833Z,1537469717.833 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-09-20T18:55:32.267Z,1537469732.267 [NAL9602](INFO): Powering down
2018-09-20T18:56:19.955Z,1537469779.955 [CommandLine](IMPORTANT): got command get platform_battery_voltage
2018-09-20T18:56:19.955Z,1537469779.955 [CommandLine](FAULT): Element has no value
2018-09-20T18:56:43.115Z,1537469803.115 [CommandLine](IMPORTANT): got command get BPC1.platform_battery_voltage
2018-09-20T18:56:43.116Z,1537469803.116 [CommandLine](IMPORTANT): BPC1.platform_battery_voltage 16.052679 V
2018-09-20T18:57:01.222Z,1537469821.222 [CommandLine](IMPORTANT): got command failComponent
2018-09-20T18:57:01.222Z,1537469821.222 [CommandLine](IMPORTANT): Failed components:
2018-09-20T18:57:01.222Z,1537469821.222 [CommandLine](IMPORTANT): No failed Components.
2018-09-20T19:00:18.309Z,1537470018.309 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-09-20T19:00:18.309Z,1537470018.309 [Default:CheckIn:C.Wait] Stopped
2018-09-20T19:00:18.309Z,1537470018.309 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-09-20T19:00:18.309Z,1537470018.309 [Default:CheckIn:D] Running Loop=1
2018-09-20T19:00:18.709Z,1537470018.709 [Default:CheckIn:D] Stopped
2018-09-20T19:00:18.709Z,1537470018.709 [Default:CheckIn:E] Running Loop=1
2018-09-20T19:00:19.154Z,1537470019.154 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 28.173735 min 
2018-09-20T19:00:19.154Z,1537470019.154 [Default:CheckIn:E] Stopped
2018-09-20T19:00:19.154Z,1537470019.154 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-09-20T19:00:19.155Z,1537470019.155 [Default:CheckIn] Stopped
2018-09-20T19:00:19.155Z,1537470019.155 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-09-20T19:00:19.155Z,1537470019.155 [Default:CheckIn](INFO): Running loop #4
2018-09-20T19:00:19.155Z,1537470019.155 [Default:CheckIn] Running Loop=4
2018-09-20T19:00:19.155Z,1537470019.155 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-09-20T19:00:19.155Z,1537470019.155 [Default:CheckIn:Read_GPS] Running Loop=1
2018-09-20T19:00:22.383Z,1537470022.383 [NAL9602](INFO): Powering up
2018-09-20T19:00:33.539Z,1537470033.539 [NAL9602](INFO): NAL9602 initialized
2018-09-20T19:00:56.353Z,1537470056.353 [NAL9602](INFO): SBD MO Status=2, MOMSN=868, MT Status=2, MTMSN=0
2018-09-20T19:00:56.353Z,1537470056.353 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-09-20T19:01:29.659Z,1537470089.659 [NAL9602](INFO): SBD MO Status=2, MOMSN=868, MT Status=2, MTMSN=0
2018-09-20T19:01:29.659Z,1537470089.659 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-09-20T19:01:53.648Z,1537470113.648 [NAL9602](INFO): SBD MO Status=2, MOMSN=868, MT Status=2, MTMSN=0
2018-09-20T19:01:53.649Z,1537470113.649 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-09-20T19:02:09.245Z,1537470129.245 [NAL9602](INFO): SBD MO Status=0, MOMSN=868, MT Status=0, MTMSN=0
2018-09-20T19:02:09.245Z,1537470129.245 [NAL9602](INFO): No messages in MT queue
2018-09-20T19:02:10.455Z,1537470130.455 [NAL9602](INFO): GPS fix at 20180920T190209: (36.802355, -121.787138)
2018-09-20T19:02:10.523Z,1537470130.523 [Default:CheckIn:Read_GPS] Stopped
2018-09-20T19:02:10.524Z,1537470130.524 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-09-20T19:02:15.040Z,1537470135.040 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20180920T182838/Courier0013.lzma
2018-09-20T19:02:15.758Z,1537470135.758 [DataOverHttps](INFO): Moved sent file to Logs/20180920T182838/Courier0013.lzma.bak
2018-09-20T19:02:15.758Z,1537470135.758 [DataOverHttps](INFO): SBD MOMSN=8548616
2018-09-20T19:02:25.162Z,1537470145.162 [DataOverHttps](INFO): Sending 265 bytes from file Logs/20180920T182838/Express0014.lzma
2018-09-20T19:02:25.955Z,1537470145.955 [DataOverHttps](INFO): Moved sent file to Logs/20180920T182838/Express0014.lzma.bak
2018-09-20T19:02:25.955Z,1537470145.955 [DataOverHttps](INFO): SBD MOMSN=8548619
2018-09-20T19:02:26.426Z,1537470146.426 [Default:CheckIn:Read_Iridium] Stopped
2018-09-20T19:02:26.426Z,1537470146.426 [Default:CheckIn:C.Wait] Running Loop=1
2018-09-20T19:02:26.426Z,1537470146.426 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-09-20T19:02:45.453Z,1537470165.453 [NAL9602](INFO): Powering down
2018-09-20T19:03:43.624Z,1537470223.624 [Reporter](INFO): platform_battery_voltage 16.052679 V
2018-09-20T19:07:27.173Z,1537470447.173 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-09-20T19:07:27.173Z,1537470447.173 [Default:CheckIn:C.Wait] Stopped
2018-09-20T19:07:27.173Z,1537470447.173 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-09-20T19:07:27.173Z,1537470447.173 [Default:CheckIn:D] Running Loop=1
2018-09-20T19:07:27.537Z,1537470447.537 [Default:CheckIn:D] Stopped
2018-09-20T19:07:27.537Z,1537470447.537 [Default:CheckIn:E] Running Loop=1
2018-09-20T19:07:27.930Z,1537470447.930 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 35.320866 min 
2018-09-20T19:07:27.930Z,1537470447.930 [Default:CheckIn:E] Stopped
2018-09-20T19:07:27.930Z,1537470447.930 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-09-20T19:07:27.930Z,1537470447.930 [Default:CheckIn] Stopped
2018-09-20T19:07:27.931Z,1537470447.931 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-09-20T19:07:27.931Z,1537470447.931 [Default:CheckIn](INFO): Running loop #5
2018-09-20T19:07:27.931Z,1537470447.931 [Default:CheckIn] Running Loop=5
2018-09-20T19:07:27.931Z,1537470447.931 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-09-20T19:07:27.931Z,1537470447.931 [Default:CheckIn:Read_GPS] Running Loop=1
2018-09-20T19:07:31.250Z,1537470451.250 [NAL9602](INFO): Powering up
2018-09-20T19:07:42.419Z,1537470462.419 [NAL9602](INFO): NAL9602 initialized
2018-09-20T19:08:06.437Z,1537470486.437 [NAL9602](INFO): SBD MO Status=0, MOMSN=869, MT Status=0, MTMSN=0
2018-09-20T19:08:06.437Z,1537470486.437 [NAL9602](INFO): No messages in MT queue
2018-09-20T19:08:07.619Z,1537470487.619 [NAL9602](INFO): GPS fix at 20180920T190806: (36.802330, -121.787109)
2018-09-20T19:08:07.741Z,1537470487.741 [Default:CheckIn:Read_GPS] Stopped
2018-09-20T19:08:07.741Z,1537470487.741 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-09-20T19:08:12.156Z,1537470492.156 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20180920T182838/Courier0016.lzma
2018-09-20T19:08:12.926Z,1537470492.926 [DataOverHttps](INFO): Moved sent file to Logs/20180920T182838/Courier0016.lzma.bak
2018-09-20T19:08:12.926Z,1537470492.926 [DataOverHttps](INFO): SBD MOMSN=8548631
2018-09-20T19:08:22.127Z,1537470502.127 [DataOverHttps](INFO): Sending 119 bytes from file Logs/20180920T182838/Express0017.lzma
2018-09-20T19:08:22.882Z,1537470502.882 [DataOverHttps](INFO): Moved sent file to Logs/20180920T182838/Express0017.lzma.bak
2018-09-20T19:08:22.883Z,1537470502.883 [DataOverHttps](INFO): SBD MOMSN=8548635
2018-09-20T19:08:23.372Z,1537470503.372 [Default:CheckIn:Read_Iridium] Stopped
2018-09-20T19:08:23.372Z,1537470503.372 [Default:CheckIn:C.Wait] Running Loop=1
2018-09-20T19:08:23.372Z,1537470503.372 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-09-20T19:08:42.011Z,1537470522.011 [NAL9602](INFO): Powering down
2018-09-20T19:10:09.386Z,1537470609.386 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2018-09-20T19:10:09.449Z,1537470609.449 [Reporter](INFO): BPC1.platform_battery_voltage no_value
2018-09-20T19:13:24.117Z,1537470804.117 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-09-20T19:13:24.117Z,1537470804.117 [Default:CheckIn:C.Wait] Stopped
2018-09-20T19:13:24.117Z,1537470804.117 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-09-20T19:13:24.118Z,1537470804.118 [Default:CheckIn:D] Running Loop=1
2018-09-20T19:13:24.519Z,1537470804.519 [Default:CheckIn:D] Stopped
2018-09-20T19:13:24.519Z,1537470804.519 [Default:CheckIn:E] Running Loop=1
2018-09-20T19:13:27.702Z,1537470807.702 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 41.270557 min 
2018-09-20T19:13:27.702Z,1537470807.702 [Default:CheckIn:E] Stopped
2018-09-20T19:13:27.702Z,1537470807.702 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-09-20T19:13:27.703Z,1537470807.703 [Default:CheckIn] Stopped
2018-09-20T19:13:27.703Z,1537470807.703 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-09-20T19:13:27.703Z,1537470807.703 [Default:CheckIn](INFO): Running loop #6
2018-09-20T19:13:27.703Z,1537470807.703 [Default:CheckIn] Running Loop=6
2018-09-20T19:13:27.703Z,1537470807.703 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-09-20T19:13:27.703Z,1537470807.703 [Default:CheckIn:Read_GPS] Running Loop=1
2018-09-20T19:13:28.155Z,1537470808.155 [NAL9602](INFO): Powering up
2018-09-20T19:13:39.339Z,1537470819.339 [NAL9602](INFO): NAL9602 initialized
2018-09-20T19:13:55.386Z,1537470835.386 [NAL9602](INFO): SBD MO Status=0, MOMSN=870, MT Status=0, MTMSN=0
2018-09-20T19:13:55.386Z,1537470835.386 [NAL9602](INFO): No messages in MT queue
2018-09-20T19:14:55.159Z,1537470895.159 [NAL9602](INFO): GPS fix at 20180920T191454: (36.802539, -121.787093)
2018-09-20T19:14:55.206Z,1537470895.206 [Default:CheckIn:Read_GPS] Stopped
2018-09-20T19:14:55.206Z,1537470895.206 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-09-20T19:14:59.776Z,1537470899.776 [DataOverHttps](INFO): Sending 80 bytes from file Logs/20180920T182838/Courier0019.lzma
2018-09-20T19:15:00.573Z,1537470900.573 [DataOverHttps](INFO): Moved sent file to Logs/20180920T182838/Courier0019.lzma.bak
2018-09-20T19:15:00.573Z,1537470900.573 [DataOverHttps](INFO): SBD MOMSN=8548682
2018-09-20T19:15:09.581Z,1537470909.581 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20180920T182838/Express0020.lzma
2018-09-20T19:15:10.335Z,1537470910.335 [DataOverHttps](INFO): Moved sent file to Logs/20180920T182838/Express0020.lzma.bak
2018-09-20T19:15:10.335Z,1537470910.335 [DataOverHttps](INFO): SBD MOMSN=8548685
2018-09-20T19:15:10.781Z,1537470910.781 [Default:CheckIn:Read_Iridium] Stopped
2018-09-20T19:15:10.781Z,1537470910.781 [Default:CheckIn:C.Wait] Running Loop=1
2018-09-20T19:15:10.781Z,1537470910.781 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-09-20T19:15:29.807Z,1537470929.807 [NAL9602](INFO): Powering down
2018-09-20T19:18:44.266Z,1537471124.266 [RDI_Pathfinder](ERROR): Unknown system health message
2018-09-20T19:18:44.266Z,1537471124.266 [RDI_Pathfinder] Hardware Fault, FailCount= 1
2018-09-20T19:18:44.266Z,1537471124.266 [RDI_Pathfinder](ERROR): Hardware Fault
2018-09-20T19:18:44.298Z,1537471124.298 [CBIT](ERROR): Hardware Fault in component: RDI_Pathfinder
2018-09-20T19:18:44.711Z,1537471124.711 [RDI_Pathfinder](INFO): Powering down
2018-09-20T19:18:45.463Z,1537471125.463 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2018-09-20T19:18:45.463Z,1537471125.463 [RDI_Pathfinder] No Fault, FailCount= 0
2018-09-20T19:18:59.045Z,1537471139.045 [RDI_Pathfinder](ERROR): Failed to parse:Pathfinder
2018-09-20T19:20:11.537Z,1537471211.537 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-09-20T19:20:11.542Z,1537471211.542 [Default:CheckIn:C.Wait] Stopped
2018-09-20T19:20:11.542Z,1537471211.542 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-09-20T19:20:11.542Z,1537471211.542 [Default:CheckIn:D] Running Loop=1
2018-09-20T19:20:11.972Z,1537471211.972 [Default:CheckIn:D] Stopped
2018-09-20T19:20:11.972Z,1537471211.972 [Default:CheckIn:E] Running Loop=1
2018-09-20T19:20:15.225Z,1537471215.225 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 48.061450 min 
2018-09-20T19:20:15.226Z,1537471215.226 [Default:CheckIn:E] Stopped
2018-09-20T19:20:15.226Z,1537471215.226 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-09-20T19:20:15.226Z,1537471215.226 [Default:CheckIn] Stopped
2018-09-20T19:20:15.226Z,1537471215.226 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-09-20T19:20:15.226Z,1537471215.226 [Default:CheckIn](INFO): Running loop #7
2018-09-20T19:20:15.226Z,1537471215.226 [Default:CheckIn] Running Loop=7
2018-09-20T19:20:15.226Z,1537471215.226 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-09-20T19:20:15.227Z,1537471215.227 [Default:CheckIn:Read_GPS] Running Loop=1
2018-09-20T19:20:15.712Z,1537471215.712 [NAL9602](INFO): Powering up
2018-09-20T19:20:26.895Z,1537471226.895 [NAL9602](INFO): NAL9602 initialized
2018-09-20T19:20:42.908Z,1537471242.908 [NAL9602](INFO): SBD MO Status=0, MOMSN=871, MT Status=0, MTMSN=0
2018-09-20T19:20:42.909Z,1537471242.909 [NAL9602](INFO): No messages in MT queue
2018-09-20T19:21:10.981Z,1537471270.981 [Reporter](INFO): platform_battery_voltage 16.048626 V
2018-09-20T19:21:21.150Z,1537471281.150 [NAL9602](INFO): GPS fix at 20180920T192121: (36.804197, -121.785568)
2018-09-20T19:21:21.211Z,1537471281.211 [Default:CheckIn:Read_GPS] Stopped
2018-09-20T19:21:21.211Z,1537471281.211 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-09-20T19:21:25.687Z,1537471285.687 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20180920T182838/Courier0022.lzma
2018-09-20T19:21:26.459Z,1537471286.459 [DataOverHttps](INFO): Moved sent file to Logs/20180920T182838/Courier0022.lzma.bak
2018-09-20T19:21:26.459Z,1537471286.459 [DataOverHttps](INFO): SBD MOMSN=8548731
2018-09-20T19:21:35.499Z,1537471295.499 [DataOverHttps](INFO): Sending 135 bytes from file Logs/20180920T182838/Express0023.lzma
2018-09-20T19:21:36.267Z,1537471296.267 [DataOverHttps](INFO): Moved sent file to Logs/20180920T182838/Express0023.lzma.bak
2018-09-20T19:21:36.267Z,1537471296.267 [DataOverHttps](INFO): SBD MOMSN=8548734
2018-09-20T19:21:36.726Z,1537471296.726 [Default:CheckIn:Read_Iridium] Stopped
2018-09-20T19:21:36.726Z,1537471296.726 [Default:CheckIn:C.Wait] Running Loop=1
2018-09-20T19:21:36.726Z,1537471296.726 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-09-20T19:21:55.763Z,1537471315.763 [NAL9602](INFO): Powering down
2018-09-20T19:25:42.435Z,1537471542.435 [DataOverHttps](IMPORTANT): SBD MTMSN=20180920T192542
2018-09-20T19:25:46.645Z,1537471546.645 [DataOverHttps](INFO): Received command:load Science/profile_station.xml;set profile_station.NeedCommsTime 20 minute;set profile_station.Lat 36.797 degree;set profile_station.Lon -121.847 degree;set profile_station.YoYoMaxDepth 20 meter;run 
2018-09-20T19:25:46.691Z,1537471546.691 [CommandLine](IMPORTANT): got command load ./Missions/Science/profile_station.xml
2018-09-20T19:25:46.691Z,1537471546.691 [MissionManager](INFO): Loading Mission: ./Missions/Science/profile_station.xml
2018-09-20T19:25:46.827Z,1537471546.827 [MissionManager](INFO): DefineArg profile_station.MissionTimeout = 4.000000 h
2018-09-20T19:25:46.830Z,1537471546.830 [MissionManager](INFO): DefineArg profile_station.NeedCommsTime = 60.000000 min
2018-09-20T19:25:46.833Z,1537471546.833 [MissionManager](INFO): DefineArg profile_station.Lat = 36.806966 arcdeg
2018-09-20T19:25:46.837Z,1537471546.837 [MissionManager](INFO): DefineArg profile_station.Lon = -121.824326 arcdeg
2018-09-20T19:25:46.840Z,1537471546.840 [MissionManager](INFO): DefineArg profile_station.Radius = 300.000000 m
2018-09-20T19:25:46.843Z,1537471546.843 [MissionManager](INFO): DefineArg profile_station.YoYoMinDepth = 2.000000 m
2018-09-20T19:25:46.846Z,1537471546.846 [MissionManager](INFO): DefineArg profile_station.YoYoMaxDepth = 200.000000 m
2018-09-20T19:25:46.849Z,1537471546.849 [MissionManager](INFO): DefineArg profile_station.YoYoMinAltitude = 7.000000 m
2018-09-20T19:25:46.852Z,1537471546.852 [MissionManager](INFO): DefineArg profile_station.YoYoPitch = 20.000000 arcdeg
2018-09-20T19:25:46.855Z,1537471546.855 [MissionManager](INFO): DefineArg profile_station.Speed = 1.000000 m/s
2018-09-20T19:25:46.858Z,1537471546.858 [MissionManager](INFO): DefineArg profile_station.CircleMaxError = 100.000000 m
2018-09-20T19:25:46.861Z,1537471546.861 [MissionManager](INFO): DefineArg profile_station.CircleTurnToPort = 0 bool
2018-09-20T19:25:46.864Z,1537471546.864 [MissionManager](INFO): DefineArg profile_station.KwpHeading = 0.010000 rad/m
2018-09-20T19:25:46.867Z,1537471546.867 [MissionManager](INFO): DefineArg profile_station.MinAltitude = 5.000000 m
2018-09-20T19:25:46.870Z,1537471546.870 [MissionManager](INFO): DefineArg profile_station.MaxDepth = 205.000000 m
2018-09-20T19:25:46.873Z,1537471546.873 [MissionManager](INFO): DefineArg profile_station.MinOffshore = 2.000000 km
2018-09-20T19:25:46.898Z,1537471546.898 [MissionManager](INFO): Inserting Stack: Missions/Insert/Science.xml
2018-09-20T19:25:47.311Z,1537471547.311 [MissionManager](INFO): DefineArg profile_station:Science.SampleISUS = 0 bool
2018-09-20T19:25:47.314Z,1537471547.314 [MissionManager](INFO): DefineArg profile_station:Science.SampleISUSmaxPitch = 60.000000 arcdeg
2018-09-20T19:25:47.317Z,1537471547.317 [MissionManager](INFO): DefineArg profile_station:Science.SampleISUSminPitch = -60.000000 arcdeg
2018-09-20T19:25:47.320Z,1537471547.320 [MissionManager](INFO): DefineArg profile_station:Science.PeakDetectChlActive = 0 bool
2018-09-20T19:25:47.323Z,1537471547.323 [MissionManager](INFO): DefineArg profile_station:Science.HighestChlPeakReportActive = 0 bool
2018-09-20T19:25:47.326Z,1537471547.326 [MissionManager](INFO): DefineArg profile_station:Science.PatchTracking = 0 bool
2018-09-20T19:25:47.329Z,1537471547.329 [MissionManager](INFO): DefineArg profile_station:Science.FilterWidthHorizontal = 3.000000 count
2018-09-20T19:25:47.357Z,1537471547.357 [MissionManager](INFO): DefineArg profile_station:Science.NumProfilesSlidingwindow = 100.000000 count
2018-09-20T19:25:47.359Z,1537471547.359 [MissionManager](INFO): DefineArg profile_station:Science.PeakDetectNO3Active = 0 bool
2018-09-20T19:25:47.374Z,1537471547.374 [MissionManager](INFO): DefineArg profile_station:Science.PeakDetectOilActive = 0 bool
2018-09-20T19:25:47.377Z,1537471547.377 [MissionManager](INFO): DefineArg profile_station:Science.UpwardDerivativeOfTemperatureActive = 0 bool
2018-09-20T19:25:47.385Z,1537471547.385 [MissionManager](INFO): DefineArg profile_station:Science.EnabledAanderaaO2 = 1.000000 bool
2018-09-20T19:25:47.390Z,1537471547.390 [MissionManager](INFO): DefineArg profile_station:Science.EnabledNeilBrown = 0.000000 bool
2018-09-20T19:25:47.406Z,1537471547.406 [MissionManager](INFO): DefineArg profile_station:Science.EnabledSeabird = 0.000000 bool
2018-09-20T19:25:47.410Z,1537471547.410 [MissionManager](INFO): DefineArg profile_station:Science.EnabledTurbulence_NPS = 0.000000 bool
2018-09-20T19:25:47.413Z,1537471547.413 [MissionManager](INFO): DefineArg profile_station:Science.EnabledWetLabsBB2FL = 0.000000 bool
2018-09-20T19:25:47.417Z,1537471547.417 [MissionManager](INFO): DefineArg profile_station:Science.EnabledWetLabsSeaOWL_UV_A = 1.000000 bool
2018-09-20T19:25:47.445Z,1537471547.445 [MissionManager](INFO): DefineArg profile_station:Science.EnabledISUS = 0.000000 bool
2018-09-20T19:25:47.448Z,1537471547.448 [MissionManager](INFO): DefineArg profile_station:Science.LowPassWindowLength = 20.000000 count
2018-09-20T19:25:47.452Z,1537471547.452 [MissionManager](INFO): DefineArg profile_station:Science.PeakChlShallowBound = nan m
2018-09-20T19:25:47.467Z,1537471547.467 [MissionManager](INFO): DefineArg profile_station:Science.PeakChlDeepBound = nan m
2018-09-20T19:25:47.474Z,1537471547.474 [MissionManager](INFO): DefineOutput profile_station:Science.PeakChl = 0.000000 ug/l
2018-09-20T19:25:47.477Z,1537471547.477 [MissionManager](INFO): DefineOutput profile_station:Science.PeakChlDepth = 0.000000 m
2018-09-20T19:25:47.496Z,1537471547.496 [MissionManager](INFO): DefineOutput profile_station:Science.PeakChlTemperature = 0.000000 degC
2018-09-20T19:25:47.507Z,1537471547.507 [MissionManager](INFO): DefineOutput profile_station:Science.PeakChlLatitude = nan arcdeg
2018-09-20T19:25:47.510Z,1537471547.510 [MissionManager](INFO): DefineOutput profile_station:Science.PeakChlLongitude = nan arcdeg
2018-09-20T19:25:47.513Z,1537471547.513 [MissionManager](INFO): DefineOutput profile_station:Science.PeakNO3 = 0.000000 umol/l
2018-09-20T19:25:47.516Z,1537471547.516 [MissionManager](INFO): DefineOutput profile_station:Science.PeakNO3Depth = 0.000000 m
2018-09-20T19:25:47.542Z,1537471547.542 [MissionManager](INFO): DefineOutput profile_station:Science.PeakNO3Latitude = nan arcdeg
2018-09-20T19:25:47.546Z,1537471547.546 [MissionManager](INFO): DefineOutput profile_station:Science.PeakNO3Longitude = nan arcdeg
2018-09-20T19:25:47.549Z,1537471547.549 [MissionManager](INFO): DefineOutput profile_station:Science.PatchChl = 0.000000 m
2018-09-20T19:25:47.569Z,1537471547.569 [MissionManager](INFO): DefineOutput profile_station:Science.PatchChlDepth = 0.000000 m
2018-09-20T19:25:47.572Z,1537471547.572 [MissionManager](INFO): DefineOutput profile_station:Science.PatchChlLatitude = nan arcdeg
2018-09-20T19:25:47.599Z,1537471547.599 [MissionManager](INFO): DefineOutput profile_station:Science.PatchChlLongitude = nan arcdeg
2018-09-20T19:25:47.602Z,1537471547.602 [MissionManager](INFO): DefineOutput profile_station:Science.PatchChlDistance = nan m
2018-09-20T19:25:47.605Z,1537471547.605 [MissionManager](INFO): DefineOutput profile_station:Science.PeakOil = 0.000000 kg/m3
2018-09-20T19:25:47.608Z,1537471547.608 [MissionManager](INFO): DefineOutput profile_station:Science.PeakOilDepth = 0.000000 m
2018-09-20T19:25:47.630Z,1537471547.630 [MissionManager](INFO): DefineOutput profile_station:Science.PeakOilLatitude = nan arcdeg
2018-09-20T19:25:47.633Z,1537471547.633 [MissionManager](INFO): DefineOutput profile_station:Science.PeakOilLongitude = nan arcdeg
2018-09-20T19:25:47.665Z,1537471547.665 [profile_station:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2018-09-20T19:25:47.704Z,1537471547.704 [profile_station:Science:HighestChlPeakReport:A.PeakDetectHorizontal](DEBUG): Construct PeakDetectHorizontal.
2018-09-20T19:25:47.740Z,1537471547.740 [profile_station:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2018-09-20T19:25:47.768Z,1537471547.768 [profile_station:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2018-09-20T19:25:47.802Z,1537471547.802 [MissionManager](INFO): RedefineArg profile_station:Science.SampleISUS = value:1 bool
2018-09-20T19:25:47.804Z,1537471547.804 [MissionManager](INFO): RedefineArg profile_station:Science.PeakDetectChlActive = value:1 bool
2018-09-20T19:25:47.804Z,1537471547.804 [MissionManager](INFO): Inserting Stack: Missions/Insert/NeedComms.xml
2018-09-20T19:25:47.919Z,1537471547.919 [MissionManager](INFO): DefineArg profile_station:NeedComms.DiveInterval = 3.000000 h
2018-09-20T19:25:47.923Z,1537471547.923 [MissionManager](INFO): DefineArg profile_station:NeedComms.WaitForPitchUp = 10.000000 min
2018-09-20T19:25:47.926Z,1537471547.926 [MissionManager](INFO): DefineArg profile_station:NeedComms.SurfacePitch = 20.000000 arcdeg
2018-09-20T19:25:47.928Z,1537471547.928 [MissionManager](INFO): DefineArg profile_station:NeedComms.SurfaceDepthRate = nan m/s
2018-09-20T19:25:47.931Z,1537471547.931 [MissionManager](INFO): DefineArg profile_station:NeedComms.SurfaceSpeed = 1.000000 m/s
2018-09-20T19:25:47.949Z,1537471547.949 [MissionManager](INFO): DefineArg profile_station:NeedComms.GPSTimeout = 7.000000 min
2018-09-20T19:25:47.952Z,1537471547.952 [MissionManager](INFO): DefineArg profile_station:NeedComms.CommsTimeout = 30.000000 min
2018-09-20T19:25:47.982Z,1537471547.982 [profile_station:NeedComms:B.GoToSurface](DEBUG): Construct GoToSurface.
2018-09-20T19:25:48.024Z,1537471548.024 [MissionManager](INFO): Inserting Stack: Missions/Insert/StandardEnvelopes.xml
2018-09-20T19:25:48.106Z,1537471548.106 [MissionManager](INFO): DefineArg profile_station:StandardEnvelopes.MinAltitude = 5.000000 m
2018-09-20T19:25:48.109Z,1537471548.109 [MissionManager](INFO): DefineArg profile_station:StandardEnvelopes.MaxDepth = 200.000000 m
2018-09-20T19:25:48.112Z,1537471548.112 [MissionManager](INFO): DefineArg profile_station:StandardEnvelopes.MinOffshore = 2000.000000 m
2018-09-20T19:25:48.113Z,1537471548.113 [profile_station:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope.
2018-09-20T19:25:48.141Z,1537471548.141 [profile_station:StandardEnvelopes:B.DepthEnvelope](DEBUG): Construct DepthEnvelope.
2018-09-20T19:25:48.176Z,1537471548.176 [profile_station:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Construct OffshoreEnvelope.
2018-09-20T19:25:48.215Z,1537471548.215 [profile_station:I.Pitch](DEBUG): Construct.
2018-09-20T19:25:48.221Z,1537471548.221 [profile_station:J.Buoyancy](DEBUG): Construct Buoyancy.
2018-09-20T19:25:48.225Z,1537471548.225 [profile_station:K.SetSpeed](DEBUG): Construct.
2018-09-20T19:25:48.255Z,1537471548.255 [profile_station:L.DepthEnvelope](DEBUG): Construct DepthEnvelope.
2018-09-20T19:25:48.276Z,1537471548.276 [profile_station:M.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope.
2018-09-20T19:25:48.293Z,1537471548.293 [profile_station:N.YoYo](DEBUG): Construct YoYo.
2018-09-20T19:25:48.311Z,1537471548.311 [profile_station:CircleWrapper:B.Circle](DEBUG): Construct.
2018-09-20T19:25:48.407Z,1537471548.407 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Derivation="Tethys/Derivation"
       xmlns:Estimation="Tethys/Estimation"
       xmlns:Guidance="Tethys/Guidance"
       xmlns:Sensor="Tethys/Sensor"
       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/Derivation http://okeanids.mbari.org/tethys/Xml/Derivation.xsd
                           Tethys/Estimation http://okeanids.mbari.org/tethys/Xml/Estimation.xsd
                           Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Sensor http://okeanids.mbari.org/tethys/Xml/Sensor.xsd
                           Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
       Id="profile_station">

    <Description>
        This mission yoyos in a circle around a specified location.
    </Description>

<!-- Mission-wide settings -->

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

    <DefineArg Name="NeedCommsTime"><Description>
        Elapsed time after previous surface communications when vehicle will
        begin to ascend for additional surface communications
    </Description><Units:minute/><Value>60</Value></DefineArg>

<!-- You probably need to change these. -->

    <DefineArg Name="Lat"><Description>
        The latitude of the center of the circle.
    </Description><Units:degree/><Value>36.806966</Value></DefineArg>

    <DefineArg Name="Lon"><Description>
        The longitude of the center of the circle.
    </Description><Units:degree/><Value>-121.824326</Value></DefineArg>

    <DefineArg Name="Radius"><Description>
        Radius to circle at
    </Description><Units:meter/><Value>300</Value></DefineArg>

<!-- You probably do not need to change these. -->

    <DefineArg Name="YoYoMinDepth"><Description>
        Minimum depth while performing the YoYo behavior.
    </Description><Units:meter/><Value>2</Value></DefineArg>

    <DefineArg Name="YoYoMaxDepth"><Description>
        Maximum depth while performing the YoYo behavior.
    </Description><Units:meter/><Value>200</Value></DefineArg>

    <DefineArg Name="YoYoMinAltitude"><Description>
        Minimum altitude while performing the YoYo behavior (for
        bottom-terminated YoYos).
    </Description><Units:meter/><Value>7</Value></DefineArg>

    <DefineArg Name="YoYoPitch"><Description>
        Pitch (plus and minus) for yo-yo behavior.
    </Description><Units:degree/><Value>20</Value></DefineArg>

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

<!-- You are even less likely to need to change these. -->

    <DefineArg Name="CircleMaxError"><Description>
        If this distance away from the circle, drive straight towards (or away
        from the center). Otherwise, try to reduce distance from the ideal
        circle.
    </Description><Units:meter/><Value>100</Value></DefineArg>

    <DefineArg Name="CircleTurnToPort"><Description>
        If true, vehicle turns to the left around the center point. If false,
        vehicle turns to the right.
    </Description><False/></DefineArg>

    <DefineArg Name="KwpHeading"><Description>
        Used to relax waypoint cross-track error constant that is adjusted for
        docking. (You can override this setting by passing an argument.)
    </Description><Units:radian_per_meter/><Value>0.010</Value></DefineArg>

    <DefineArg Name="MinAltitude"><Description>
        Minimum height above the sea floor for the entire mission.
    </Description><Units:meter/><Value>5</Value></DefineArg>

    <DefineArg Name="MaxDepth"><Description>
        Maximum depth for the entire mission.
    </Description><Units:meter/><Value>205</Value></DefineArg>

    <DefineArg Name="MinOffshore"><Description>
        Minimum offshore distance for the entire mission.
    </Description><Units:kilometer/><Value>2</Value></DefineArg>

<!-- Missions should almost always start with a timeout -->

    <Timeout Duration="MissionTimeout"/>

    <Insert Filename="Insert/Science.xml">
        <Description>
            Most missions will run the science sensors. If you don't place this
            aggregate above NeedComms, science instruments get turned off on the
            last upcast and while floating on the surface.
        </Description>
        <RedefineArg Name="SampleISUS"><True/></RedefineArg>
        <RedefineArg Name="PeakDetectChlActive"><True/></RedefineArg>
    </Insert>

<!-- Most missions should use the NeedComms aggregate. -->

    <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:MinAltitude"/><Arg Name="MinAltitude"/></Assign>

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

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

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

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

<!-- Many missions will keep mass position and buoyancy volume fixed at defaults. -->

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

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

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

    <Guidance:DepthEnvelope>
        <Description>
            Another depth envelope for the YoYo behavior. This envelope should
            fall within the limits of the standard safety envelopes in
            Insert/StandardEnvelopes.xml in order to avoid commanding high pitch
            angles for depth-terminated YoYos.
        </Description>
        <Parallel/>
        <Setting><Guidance:DepthEnvelope.minDepth/><Arg Name="YoYoMinDepth"/></Setting>
        <Setting><Guidance:DepthEnvelope.maxDepth/><Arg Name="YoYoMaxDepth"/></Setting>
        <Setting><Guidance:DepthEnvelope.pitch/><Arg Name="YoYoPitch"/></Setting>
    </Guidance:DepthEnvelope>

    <Guidance:AltitudeEnvelope>
        <Description>
            Another altitude envelope for the YoYo behavior. This envelope
            should fall within the limits of the standard safety envelopes in
            Insert/StandardEnvelopes.xml in order to avoid commanding high pitch
            angles for bottom-terminated YoYos.
        </Description>
        <Parallel/>
        <Setting><Guidance:AltitudeEnvelope.minAltitude/><Arg Name="YoYoMinAltitude"/></Setting>
        <Setting><Guidance:AltitudeEnvelope.pitch/><Arg Name="YoYoPitch"/></Setting>
    </Guidance:AltitudeEnvelope>

    <Guidance:YoYo>
        <Parallel/>
        <Setting><Guidance:YoYo.pitch/><Arg Name="YoYoPitch"/></Setting>
    </Guidance:YoYo>

    <Aggregate Id="CircleWrapper">

        <Sequence Repeat="4096"/>

        <Assign><Parallel/><Control:HorizontalControl.kwpHeading/><Arg Name="KwpHeading"/></Assign>

        <Guidance:Circle>
            <Sequence/>
            <Setting><Guidance:Circle.latitude/><Arg Name="Lat"/></Setting>
            <Setting><Guidance:Circle.longitude/><Arg Name="Lon"/></Setting>
            <Setting><Guidance:Circle.radius/><Arg Name="Radius"/></Setting>
            <Setting><Guidance:Circle.maxError/><Arg Name="CircleMaxError"/></Setting>
            <Setting><Guidance:Circle.turnToPort/><Arg Name="CircleTurnToPort"/></Setting>
        </Guidance:Circle>

    </Aggregate>

</Mission>


2018-09-20T19:25:48.407Z,1537471548.407 [CommandLine](IMPORTANT): Loaded ./Missions/Science/profile_station.xml
2018-09-20T19:25:57.536Z,1537471557.536 [CommandLine](IMPORTANT): got command set profile_station.NeedCommsTime 20.000000 minute
2018-09-20T19:25:57.537Z,1537471557.537 [CommandLine](IMPORTANT): got command set profile_station.Lat 36.797001 degree
2018-09-20T19:25:57.538Z,1537471557.538 [CommandLine](IMPORTANT): got command set profile_station.Lon -121.847000 degree
2018-09-20T19:25:57.539Z,1537471557.539 [CommandLine](IMPORTANT): got command set profile_station.YoYoMaxDepth 20.000000 meter
2018-09-20T19:25:57.539Z,1537471557.539 [CommandLine](IMPORTANT): got command run 
2018-09-20T19:25:57.542Z,1537471557.542 [CommandLine](IMPORTANT): Running 
2018-09-20T19:25:57.566Z,1537471557.566 [RDI_Pathfinder](ERROR): No DVL communication! Re-initializing
2018-09-20T19:25:57.566Z,1537471557.566 [RDI_Pathfinder] Communications Fault, FailCount= 1
2018-09-20T19:25:57.566Z,1537471557.566 [RDI_Pathfinder](ERROR): Communications Fault
2018-09-20T19:25:57.811Z,1537471557.811 [Default] Stopped
2018-09-20T19:25:57.811Z,1537471557.811 [Default](DEBUG): Aggregate::uninitialize Default
2018-09-20T19:25:57.811Z,1537471557.811 [Default:B.GoToSurface] Stopped
2018-09-20T19:25:57.811Z,1537471557.811 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2018-09-20T19:25:57.811Z,1537471557.811 [Default:CheckIn] Stopped
2018-09-20T19:25:57.812Z,1537471557.812 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-09-20T19:25:57.812Z,1537471557.812 [Default:CheckIn:C.Wait] Stopped
2018-09-20T19:25:57.812Z,1537471557.812 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-09-20T19:25:57.812Z,1537471557.812 [MissionManager](IMPORTANT): Started mission profile_station
2018-09-20T19:25:57.812Z,1537471557.812 [profile_station] Running Loop=1
2018-09-20T19:25:57.812Z,1537471557.812 [profile_station](DEBUG): Aggregate::initialize profile_station
2018-09-20T19:25:57.812Z,1537471557.812 [profile_station:Science] Running Loop=1
2018-09-20T19:25:57.813Z,1537471557.813 [profile_station:Science](DEBUG): Aggregate::initialize profile_station:Science
2018-09-20T19:25:57.813Z,1537471557.813 [profile_station:Science:A] Running Loop=1
2018-09-20T19:25:57.813Z,1537471557.813 [profile_station:Science:B] Running Loop=1
2018-09-20T19:25:57.813Z,1537471557.813 [profile_station:Science:C] Running Loop=1
2018-09-20T19:25:57.813Z,1537471557.813 [profile_station:Science:D] Running Loop=1
2018-09-20T19:25:57.813Z,1537471557.813 [profile_station:Science:E] Running Loop=1
2018-09-20T19:25:57.813Z,1537471557.813 [profile_station:Science:F] Running Loop=1
2018-09-20T19:25:57.813Z,1537471557.813 [profile_station:Science:G] Running Loop=1
2018-09-20T19:25:57.813Z,1537471557.813 [profile_station:Science:Read_Oil] Running Loop=1
2018-09-20T19:25:57.813Z,1537471557.813 [profile_station:Science:PeakDetectChl] Running Loop=1
2018-09-20T19:25:57.814Z,1537471557.814 [profile_station:Science:PeakDetectChl](DEBUG): Aggregate::initialize profile_station:Science:PeakDetectChl
2018-09-20T19:25:57.814Z,1537471557.814 [profile_station:Science:PeakDetectChl:A.PeakDetectVsDepth] Running Loop=1
2018-09-20T19:25:57.814Z,1537471557.814 [profile_station:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Initialize.
2018-09-20T19:25:57.816Z,1537471557.816 [profile_station:Science:HighestChlPeakReport] Running Loop=1
2018-09-20T19:25:57.816Z,1537471557.816 [profile_station:Science:HighestChlPeakReport](DEBUG): Aggregate::initialize profile_station:Science:HighestChlPeakReport
2018-09-20T19:25:57.816Z,1537471557.816 [profile_station:Science:HighestChlPeakReport:A.PeakDetectHorizontal] Running Loop=1
2018-09-20T19:25:57.816Z,1537471557.816 [profile_station:Science:HighestChlPeakReport:A.PeakDetectHorizontal](INFO): Initialize.
2018-09-20T19:25:57.817Z,1537471557.817 [profile_station:Science:PeakDetectNO3] Running Loop=1
2018-09-20T19:25:57.817Z,1537471557.817 [profile_station:Science:PeakDetectNO3](DEBUG): Aggregate::initialize profile_station:Science:PeakDetectNO3
2018-09-20T19:25:57.817Z,1537471557.817 [profile_station:Science:PeakDetectNO3:A.PeakDetectVsDepth] Running Loop=1
2018-09-20T19:25:57.817Z,1537471557.817 [profile_station:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Initialize.
2018-09-20T19:25:57.819Z,1537471557.819 [profile_station:Science:PeakDetectOil] Running Loop=1
2018-09-20T19:25:57.819Z,1537471557.819 [profile_station:Science:PeakDetectOil](DEBUG): Aggregate::initialize profile_station:Science:PeakDetectOil
2018-09-20T19:25:57.819Z,1537471557.819 [profile_station:Science:PeakDetectOil:A.PeakDetectVsDepth] Running Loop=1
2018-09-20T19:25:57.819Z,1537471557.819 [profile_station:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Initialize.
2018-09-20T19:25:57.821Z,1537471557.821 [profile_station:StandardEnvelopes] Running Loop=1
2018-09-20T19:25:57.821Z,1537471557.821 [profile_station:StandardEnvelopes](DEBUG): Aggregate::initialize profile_station:StandardEnvelopes
2018-09-20T19:25:57.821Z,1537471557.821 [profile_station:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1
2018-09-20T19:25:57.821Z,1537471557.821 [profile_station:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent.
2018-09-20T19:25:57.821Z,1537471557.821 [profile_station:StandardEnvelopes:B.DepthEnvelope] Running Loop=1
2018-09-20T19:25:57.821Z,1537471557.821 [profile_station:StandardEnvelopes:B.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent.
2018-09-20T19:25:57.822Z,1537471557.822 [profile_station:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1
2018-09-20T19:25:57.822Z,1537471557.822 [profile_station:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Initialize OffshoreEnvelopeComponent.
2018-09-20T19:25:57.822Z,1537471557.822 [profile_station:I.Pitch] Running Loop=1
2018-09-20T19:25:57.822Z,1537471557.822 [profile_station:I.Pitch](DEBUG): Initialize.
2018-09-20T19:25:57.822Z,1537471557.822 [profile_station:J.Buoyancy] Running Loop=1
2018-09-20T19:25:57.822Z,1537471557.822 [profile_station:J.Buoyancy](DEBUG): Initialize Buoyancy Component.
2018-09-20T19:25:57.822Z,1537471557.822 [profile_station:K.SetSpeed] Running Loop=1
2018-09-20T19:25:57.822Z,1537471557.822 [profile_station:K.SetSpeed](DEBUG): Initialize.
2018-09-20T19:25:57.822Z,1537471557.822 [profile_station:L.DepthEnvelope] Running Loop=1
2018-09-20T19:25:57.823Z,1537471557.823 [profile_station:L.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent.
2018-09-20T19:25:57.823Z,1537471557.823 [profile_station:M.AltitudeEnvelope] Running Loop=1
2018-09-20T19:25:57.823Z,1537471557.823 [profile_station:M.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent.
2018-09-20T19:25:57.823Z,1537471557.823 [profile_station:N.YoYo] Running Loop=1
2018-09-20T19:25:57.823Z,1537471557.823 [profile_station:N.YoYo](DEBUG): Initialize YoYoComponent.
2018-09-20T19:25:57.824Z,1537471557.824 [profile_station:C] Running Loop=1
2018-09-20T19:25:57.824Z,1537471557.824 [profile_station:N.YoYo] Running Loop=1
2018-09-20T19:25:57.829Z,1537471557.829 [profile_station:M.AltitudeEnvelope] Running Loop=1
2018-09-20T19:25:57.878Z,1537471557.878 [profile_station:L.DepthEnvelope] Running Loop=1
2018-09-20T19:25:57.884Z,1537471557.884 [profile_station:K.SetSpeed] Running Loop=1
2018-09-20T19:25:57.895Z,1537471557.895 [profile_station:J.Buoyancy] Running Loop=1
2018-09-20T19:25:57.900Z,1537471557.900 [profile_station:I.Pitch] Running Loop=1
2018-09-20T19:25:57.927Z,1537471557.927 [profile_station:StandardEnvelopes] Running Loop=1
2018-09-20T19:25:57.927Z,1537471557.927 [profile_station:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1
2018-09-20T19:25:57.945Z,1537471557.945 [profile_station:StandardEnvelopes:B.DepthEnvelope] Running Loop=1
2018-09-20T19:25:57.980Z,1537471557.980 [profile_station:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1
2018-09-20T19:25:57.987Z,1537471557.987 [profile_station:C] Stopped
2018-09-20T19:25:57.987Z,1537471557.987 [profile_station:E] Running Loop=1
2018-09-20T19:25:57.987Z,1537471557.987 [profile_station:Science] Running Loop=1
2018-09-20T19:25:58.003Z,1537471558.003 [profile_station:Science:PeakDetectOil] Stopped
2018-09-20T19:25:58.003Z,1537471558.003 [profile_station:Science:PeakDetectOil](DEBUG): Aggregate::uninitialize profile_station:Science:PeakDetectOil
2018-09-20T19:25:58.003Z,1537471558.003 [profile_station:Science:PeakDetectOil:A.PeakDetectVsDepth] Stopped
2018-09-20T19:25:58.003Z,1537471558.003 [profile_station:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2018-09-20T19:25:58.003Z,1537471558.003 [profile_station:Science:PeakDetectNO3] Stopped
2018-09-20T19:25:58.003Z,1537471558.003 [profile_station:Science:PeakDetectNO3](DEBUG): Aggregate::uninitialize profile_station:Science:PeakDetectNO3
2018-09-20T19:25:58.004Z,1537471558.004 [profile_station:Science:PeakDetectNO3:A.PeakDetectVsDepth] Stopped
2018-09-20T19:25:58.004Z,1537471558.004 [profile_station:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2018-09-20T19:25:58.004Z,1537471558.004 [profile_station:Science:HighestChlPeakReport] Stopped
2018-09-20T19:25:58.004Z,1537471558.004 [profile_station:Science:HighestChlPeakReport](DEBUG): Aggregate::uninitialize profile_station:Science:HighestChlPeakReport
2018-09-20T19:25:58.004Z,1537471558.004 [profile_station:Science:HighestChlPeakReport:A.PeakDetectHorizontal] Stopped
2018-09-20T19:25:58.004Z,1537471558.004 [profile_station:Science:HighestChlPeakReport:A.PeakDetectHorizontal](DEBUG): Uninitialize.
2018-09-20T19:25:58.005Z,1537471558.005 [profile_station:Science:PeakDetectChl] Running Loop=1
2018-09-20T19:25:58.013Z,1537471558.013 [profile_station:Science:Read_Oil] Running Loop=1
2018-09-20T19:25:58.026Z,1537471558.026 [profile_station:Science:Read_Oil](DEBUG): Initialize ReadDataComponent to sense mass_concentration_of_chlorophyll_in_sea_water
2018-09-20T19:25:58.027Z,1537471558.027 [profile_station:Science:G] Running Loop=1
2018-09-20T19:25:58.028Z,1537471558.028 [profile_station:Science:G](DEBUG): Initialize ReadDataComponent to sense mass_concentration_of_chlorophyll_in_sea_water
2018-09-20T19:25:58.030Z,1537471558.030 [profile_station:Science:F] Stopped
2018-09-20T19:25:58.030Z,1537471558.030 [profile_station:Science:E] Stopped
2018-09-20T19:25:58.030Z,1537471558.030 [profile_station:Science:D] Stopped
2018-09-20T19:25:58.030Z,1537471558.030 [profile_station:Science:C] Stopped
2018-09-20T19:25:58.030Z,1537471558.030 [profile_station:Science:B] Stopped
2018-09-20T19:25:58.030Z,1537471558.030 [profile_station:Science:A] Running Loop=1
2018-09-20T19:25:58.031Z,1537471558.031 [profile_station:Science:A](DEBUG): Initialize ReadDataComponent to sense mass_concentration_of_oxygen_in_sea_water
2018-09-20T19:25:58.066Z,1537471558.066 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder
2018-09-20T19:25:58.155Z,1537471558.155 [WetLabsSeaOWL_UV_A](INFO): Opening uart, block timeout 10ths=4
2018-09-20T19:25:58.155Z,1537471558.155 [WetLabsSeaOWL_UV_A](INFO): Powering up
2018-09-20T19:25:58.238Z,1537471558.238 [RDI_Pathfinder](INFO): Powering down
2018-09-20T19:25:58.297Z,1537471558.297 [profile_station:E] Stopped
2018-09-20T19:25:58.297Z,1537471558.297 [profile_station:F] Running Loop=1
2018-09-20T19:25:58.584Z,1537471558.584 [profile_station:F] Stopped
2018-09-20T19:25:58.584Z,1537471558.584 [profile_station:G] Running Loop=1
2018-09-20T19:25:58.942Z,1537471558.942 [ThrusterServo](FAULT): getVelocity uart error serial timeout
2018-09-20T19:25:58.942Z,1537471558.942 [ThrusterServo](FAULT): Thruster uart error: serial timeout
2018-09-20T19:25:58.942Z,1537471558.942 [ThrusterServo] Communications Fault, FailCount= 1
2018-09-20T19:25:58.942Z,1537471558.942 [ThrusterServo](ERROR): Communications Fault
2018-09-20T19:25:58.946Z,1537471558.946 [CBIT](ERROR): Communications Fault in component: ThrusterServo
2018-09-20T19:25:59.088Z,1537471559.088 [profile_station:G] Stopped
2018-09-20T19:25:59.088Z,1537471559.088 [profile_station:StartingMission] Running Loop=1
2018-09-20T19:25:59.088Z,1537471559.088 [profile_station:StartingMission](DEBUG): Aggregate::initialize profile_station:StartingMission
2018-09-20T19:25:59.326Z,1537471559.326 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2018-09-20T19:25:59.326Z,1537471559.326 [ThrusterServo](INFO): Powering down
2018-09-20T19:25:59.331Z,1537471559.331 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2018-09-20T19:25:59.331Z,1537471559.331 [RDI_Pathfinder] No Fault, FailCount= 1
2018-09-20T19:25:59.495Z,1537471559.495 [profile_station:NeedComms] Running Loop=1
2018-09-20T19:25:59.495Z,1537471559.495 [profile_station:NeedComms](DEBUG): Aggregate::initialize profile_station:NeedComms
2018-09-20T19:25:59.495Z,1537471559.495 [profile_station:NeedComms:B.GoToSurface] Running Loop=1
2018-09-20T19:25:59.495Z,1537471559.495 [profile_station:NeedComms:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-09-20T19:25:59.496Z,1537471559.496 [profile_station:NeedComms:B.GoToSurface](INFO): Received depth rate setting nan m/s.
2018-09-20T19:25:59.496Z,1537471559.496 [profile_station:NeedComms:B.GoToSurface](INFO): Received pitch setting 19.999999 degrees.
2018-09-20T19:25:59.496Z,1537471559.496 [profile_station:NeedComms:B.GoToSurface](INFO): Received speed setting 1.000000 m/s.
2018-09-20T19:25:59.497Z,1537471559.497 [profile_station:NeedComms:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-09-20T19:25:59.497Z,1537471559.497 [profile_station:NeedComms:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2018-09-20T19:25:59.498Z,1537471559.498 [profile_station:NeedComms:A] Running Loop=1
2018-09-20T19:25:59.503Z,1537471559.503 [profile_station:NeedComms:A](INFO): last time_fix was: 1537471281.000000 second since 1970/01/01T00:00:00Z 
2018-09-20T19:25:59.505Z,1537471559.505 [profile_station:NeedComms:A] Stopped
2018-09-20T19:26:00.067Z,1537471560.067 [profile_station:NeedComms:C] Running Loop=1
2018-09-20T19:26:00.450Z,1537471560.450 [CBIT](INFO): Clearing failed state for component ThrusterServo
2018-09-20T19:26:00.450Z,1537471560.450 [ThrusterServo] No Fault, FailCount= 1
2018-09-20T19:26:00.564Z,1537471560.564 [profile_station:NeedComms:C](DEBUG): Initialize ReadDataComponent to sense time_fix
2018-09-20T19:26:00.643Z,1537471560.643 [ThrusterServo](DEBUG): Initializing EZServoServo.
2018-09-20T19:26:00.648Z,1537471560.648 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2018-09-20T19:26:00.883Z,1537471560.883 [NAL9602](INFO): Powering up
2018-09-20T19:26:05.661Z,1537471565.661 [Aanderaa_O2](DEBUG): Error parsing data: 4831F	651		241.459		91.387		23.710		30.215		29.902		38.396		8.495		688.1		663.2		14.1	



2018-09-20T19:26:05.661Z,1537471565.661 [Aanderaa_O2](DEBUG): Error parsing device response
2018-09-20T19:26:06.860Z,1537471566.860 [Aanderaa_O2](DEBUG): Error parsing data: 4831F	651		241.381		91.360		23.711		30.218		29.905		38.396		8.492		688.2		662.6		14.1	



2018-09-20T19:26:06.860Z,1537471566.860 [Aanderaa_O2](DEBUG): Error parsing device response
2018-09-20T19:26:08.060Z,1537471568.060 [Aanderaa_O2](DEBUG): Error parsing data: 4831F	651		241.367		91.357		23.712		30.218		29.905		38.395		8.490		688.1		662.1		14.0	

2018-09-20T19:26:08.060Z,1537471568.060 [Aanderaa_O2](DEBUG): Error parsing device response
2018-09-20T19:26:10.060Z,1537471570.060 [Aanderaa_O2](DEBUG): Error parsing data: 4831F	651		241.315		91.343		23.716		30.219		29.906		38.394		8.488		687.9		661.2		13.9	

2018-09-20T19:26:10.060Z,1537471570.060 [Aanderaa_O2](DEBUG): Error parsing device response
2018-09-20T19:26:12.079Z,1537471572.079 [NAL9602](INFO): NAL9602 initialized
2018-09-20T19:26:12.503Z,1537471572.503 [RDI_Pathfinder](ERROR): Failed to parse:Pathfinder
2018-09-20T19:26:24.074Z,1537471584.074 [NAL9602](INFO): SBD MO Status=0, MOMSN=872, MT Status=0, MTMSN=0
2018-09-20T19:26:24.074Z,1537471584.074 [NAL9602](INFO): No messages in MT queue
2018-09-20T19:26:25.711Z,1537471585.711 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2018-09-20T19:26:25.711Z,1537471585.711 [RDI_Pathfinder](ERROR): Failed to parse:
:TS,18092012320837,35.0, -0.1,   0.0,1448.9,,-32768,-32768,-32768,-32768,V
2018-09-20T19:26:50.624Z,1537471610.624 [DataOverHttps](IMPORTANT): SBD MTMSN=20180920T192650
2018-09-20T19:26:55.048Z,1537471615.048 [DataOverHttps](INFO): Received command:stop
2018-09-20T19:26:55.093Z,1537471615.093 [CommandLine](IMPORTANT): got command stop
2018-09-20T19:26:55.093Z,1537471615.093 [CommandLine](IMPORTANT): Scheduling is paused
2018-09-20T19:26:55.094Z,1537471615.094 [Supervisor](INFO): Stop Mission called by CommandLine::commandStop
2018-09-20T19:26:55.203Z,1537471615.203 [MissionManager](INFO): MissionManager is completed.
2018-09-20T19:26:55.203Z,1537471615.203 [MissionManager](INFO): Uninitializing Mission profile_station
2018-09-20T19:26:55.203Z,1537471615.203 [profile_station] Stopped
2018-09-20T19:26:55.203Z,1537471615.203 [profile_station](DEBUG): Aggregate::uninitialize profile_station
2018-09-20T19:26:55.203Z,1537471615.203 [profile_station:Science] Stopped
2018-09-20T19:26:55.203Z,1537471615.203 [profile_station:Science](DEBUG): Aggregate::uninitialize profile_station:Science
2018-09-20T19:26:55.203Z,1537471615.203 [profile_station:Science:A] Stopped
2018-09-20T19:26:55.204Z,1537471615.204 [profile_station:Science:G] Stopped
2018-09-20T19:26:55.204Z,1537471615.204 [profile_station:Science:Read_Oil] Stopped
2018-09-20T19:26:55.204Z,1537471615.204 [profile_station:Science:PeakDetectChl] Stopped
2018-09-20T19:26:55.204Z,1537471615.204 [profile_station:Science:PeakDetectChl](DEBUG): Aggregate::uninitialize profile_station:Science:PeakDetectChl
2018-09-20T19:26:55.204Z,1537471615.204 [profile_station:Science:PeakDetectChl:A.PeakDetectVsDepth] Stopped
2018-09-20T19:26:55.204Z,1537471615.204 [profile_station:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2018-09-20T19:26:55.204Z,1537471615.204 [profile_station:NeedComms] Stopped
2018-09-20T19:26:55.204Z,1537471615.204 [profile_station:NeedComms](DEBUG): Aggregate::uninitialize profile_station:NeedComms
2018-09-20T19:26:55.204Z,1537471615.204 [profile_station:NeedComms:B.GoToSurface] Stopped
2018-09-20T19:26:55.204Z,1537471615.204 [profile_station:NeedComms:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2018-09-20T19:26:55.204Z,1537471615.204 [profile_station:NeedComms:C] Stopped
2018-09-20T19:26:55.205Z,1537471615.205 [profile_station:StandardEnvelopes] Stopped
2018-09-20T19:26:55.205Z,1537471615.205 [profile_station:StandardEnvelopes](DEBUG): Aggregate::uninitialize profile_station:StandardEnvelopes
2018-09-20T19:26:55.205Z,1537471615.205 [profile_station:StandardEnvelopes:A.AltitudeEnvelope] Stopped
2018-09-20T19:26:55.205Z,1537471615.205 [profile_station:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent.
2018-09-20T19:26:55.205Z,1537471615.205 [profile_station:StandardEnvelopes:B.DepthEnvelope] Stopped
2018-09-20T19:26:55.205Z,1537471615.205 [profile_station:StandardEnvelopes:B.DepthEnvelope](DEBUG): Uninitialize.
2018-09-20T19:26:55.205Z,1537471615.205 [profile_station:StandardEnvelopes:C.OffshoreEnvelope] Stopped
2018-09-20T19:26:55.205Z,1537471615.205 [profile_station:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Uninitialize OffshoreEnvelopeComponent.
2018-09-20T19:26:55.205Z,1537471615.205 [profile_station:StartingMission] Stopped
2018-09-20T19:26:55.210Z,1537471615.210 [profile_station:StartingMission](DEBUG): Aggregate::uninitialize profile_station:StartingMission
2018-09-20T19:26:55.214Z,1537471615.214 [profile_station:I.Pitch] Stopped
2018-09-20T19:26:55.214Z,1537471615.214 [profile_station:J.Buoyancy] Stopped
2018-09-20T19:26:55.214Z,1537471615.214 [profile_station:J.Buoyancy](DEBUG): Uninitialize Buoyancy Component.
2018-09-20T19:26:55.214Z,1537471615.214 [profile_station:K.SetSpeed] Stopped
2018-09-20T19:26:55.214Z,1537471615.214 [profile_station:K.SetSpeed](DEBUG): Uninitialize.
2018-09-20T19:26:55.214Z,1537471615.214 [profile_station:L.DepthEnvelope] Stopped
2018-09-20T19:26:55.214Z,1537471615.214 [profile_station:L.DepthEnvelope](DEBUG): Uninitialize.
2018-09-20T19:26:55.214Z,1537471615.214 [profile_station:M.AltitudeEnvelope] Stopped
2018-09-20T19:26:55.214Z,1537471615.214 [profile_station:M.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent.
2018-09-20T19:26:55.214Z,1537471615.214 [profile_station:N.YoYo] Stopped
2018-09-20T19:26:55.214Z,1537471615.214 [profile_station:N.YoYo](DEBUG): Uninitialize YoYoComponent.
2018-09-20T19:26:55.390Z,1537471615.390 [WetLabsSeaOWL_UV_A](INFO): Powering down
2018-09-20T19:26:55.501Z,1537471615.501 [MissionManager](IMPORTANT): Started mission Default
2018-09-20T19:26:55.501Z,1537471615.501 [Default] Running Loop=1
2018-09-20T19:26:55.502Z,1537471615.502 [Default](DEBUG): Aggregate::initialize Default
2018-09-20T19:26:55.502Z,1537471615.502 [Default:B.GoToSurface] Running Loop=1
2018-09-20T19:26:55.502Z,1537471615.502 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-09-20T19:26:55.502Z,1537471615.502 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2018-09-20T19:26:55.503Z,1537471615.503 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2018-09-20T19:26:55.503Z,1537471615.503 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2018-09-20T19:26:55.503Z,1537471615.503 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-09-20T19:26:55.504Z,1537471615.504 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2018-09-20T19:26:55.504Z,1537471615.504 [Default:A.Wait] Running Loop=1
2018-09-20T19:26:55.504Z,1537471615.504 [Default:A.Wait](DEBUG): Initialize Wait Component.
2018-09-20T19:26:55.918Z,1537471615.918 [Aanderaa_O2](INFO): Powering down
2018-09-20T19:27:08.722Z,1537471628.722 [Default:A.Wait](INFO): Done Waiting.
2018-09-20T19:27:08.722Z,1537471628.722 [Default:A.Wait] Stopped
2018-09-20T19:27:08.722Z,1537471628.722 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2018-09-20T19:27:09.065Z,1537471629.065 [Default:CheckIn] Running Loop=1
2018-09-20T19:27:09.066Z,1537471629.066 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-09-20T19:27:09.066Z,1537471629.066 [Default:CheckIn:Read_GPS] Running Loop=1
2018-09-20T19:27:40.248Z,1537471660.248 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2018-09-20T19:27:40.317Z,1537471660.317 [Reporter](INFO): BPC1.platform_battery_voltage no_value
2018-09-20T19:28:52.075Z,1537471732.075 [RDI_Pathfinder](ERROR): only read 2 of 5 data items
2018-09-20T19:28:52.075Z,1537471732.075 [RDI_Pathfinder](ERROR): Failed to parse:
:BI,-32768,-32768-32768,V
2018-09-20T19:29:08.793Z,1537471748.793 [RDI_Pathfinder](ERROR): Failed to parse:
:HM,G,D,0e8c,0ffd, 14.826, -0.074, 0.000
2018-09-20T19:30:23.696Z,1537471823.696 [RDI_Pathfinder](ERROR): only read 3 of 5 data items
2018-09-20T19:30:23.696Z,1537471823.696 [RDI_Pathfinder](ERROR): Failed to parse:
:BI,-32768,-32768,-3768,V
2018-09-20T19:31:31.103Z,1537471891.103 [NAL9602](INFO): GPS fix at 20180920T193130: (36.801718, -121.800229)
2018-09-20T19:31:31.178Z,1537471891.178 [Default:CheckIn:Read_GPS] Stopped
2018-09-20T19:31:31.178Z,1537471891.178 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-09-20T19:31:35.699Z,1537471895.699 [DataOverHttps](INFO): Sending 80 bytes from file Logs/20180920T182838/Courier0025.lzma
2018-09-20T19:31:36.458Z,1537471896.458 [DataOverHttps](INFO): Moved sent file to Logs/20180920T182838/Courier0025.lzma.bak
2018-09-20T19:31:36.459Z,1537471896.459 [DataOverHttps](INFO): SBD MOMSN=8548784
2018-09-20T19:31:45.979Z,1537471905.979 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180920T182838/Courier0028.lzma
2018-09-20T19:31:46.774Z,1537471906.774 [DataOverHttps](INFO): Moved sent file to Logs/20180920T182838/Courier0028.lzma.bak
2018-09-20T19:31:46.775Z,1537471906.775 [DataOverHttps](INFO): SBD MOMSN=8548787
2018-09-20T19:31:57.913Z,1537471917.913 [DataOverHttps](INFO): Sending 464 bytes from file Logs/20180920T182838/Express0026.lzma
2018-09-20T19:31:58.694Z,1537471918.694 [DataOverHttps](INFO): Moved sent file to Logs/20180920T182838/Express0026.lzma.bak
2018-09-20T19:31:58.694Z,1537471918.694 [DataOverHttps](INFO): SBD MOMSN=8548789
2018-09-20T19:32:08.164Z,1537471928.164 [NAL9602](INFO): Powering down
2018-09-20T19:32:08.336Z,1537471928.336 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180920T182838/Express0029.lzma
2018-09-20T19:32:09.106Z,1537471929.106 [DataOverHttps](INFO): Moved sent file to Logs/20180920T182838/Express0029.lzma.bak
2018-09-20T19:32:09.106Z,1537471929.106 [DataOverHttps](INFO): SBD MOMSN=8548807
2018-09-20T19:32:09.611Z,1537471929.611 [Default:CheckIn:Read_Iridium] Stopped
2018-09-20T19:32:09.611Z,1537471929.611 [Default:CheckIn:C.Wait] Running Loop=1
2018-09-20T19:32:09.611Z,1537471929.611 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-09-20T19:37:10.236Z,1537472230.236 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-09-20T19:37:10.236Z,1537472230.236 [Default:CheckIn:C.Wait] Stopped
2018-09-20T19:37:10.236Z,1537472230.236 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-09-20T19:37:10.236Z,1537472230.236 [Default:CheckIn:D] Running Loop=1
2018-09-20T19:37:10.651Z,1537472230.651 [Default:CheckIn:D] Stopped
2018-09-20T19:37:10.651Z,1537472230.651 [Default:CheckIn:E] Running Loop=1
2018-09-20T19:37:11.045Z,1537472231.045 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.252476 min 
2018-09-20T19:37:11.045Z,1537472231.045 [Default:CheckIn:E] Stopped
2018-09-20T19:37:11.045Z,1537472231.045 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-09-20T19:37:11.045Z,1537472231.045 [Default:CheckIn] Stopped
2018-09-20T19:37:11.045Z,1537472231.045 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-09-20T19:37:11.046Z,1537472231.046 [Default:CheckIn](INFO): Running loop #2
2018-09-20T19:37:11.046Z,1537472231.046 [Default:CheckIn] Running Loop=2
2018-09-20T19:37:11.046Z,1537472231.046 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-09-20T19:37:11.046Z,1537472231.046 [Default:CheckIn:Read_GPS] Running Loop=1
2018-09-20T19:37:14.335Z,1537472234.335 [NAL9602](INFO): Powering up
2018-09-20T19:37:25.479Z,1537472245.479 [NAL9602](INFO): NAL9602 initialized
2018-09-20T19:37:42.286Z,1537472262.286 [NAL9602](INFO): SBD MO Status=0, MOMSN=873, MT Status=0, MTMSN=0
2018-09-20T19:37:42.287Z,1537472262.287 [NAL9602](INFO): No messages in MT queue
2018-09-20T19:38:41.738Z,1537472321.738 [Reporter](INFO): platform_battery_voltage 16.045303 V
2018-09-20T19:40:15.798Z,1537472415.798 [DataOverHttps](IMPORTANT): SBD MTMSN=20180920T194015