2018-05-17T16:27:10.639Z,1526574430.639 [Supervisor](DEBUG): Initializing supervisor.
2018-05-17T16:27:10.642Z,1526574430.642 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2018-05-17T16:27:10.642Z,1526574430.642 [SyncHandler](INFO): Protected caller Thread ID is 8952
2018-05-17T16:27:10.643Z,1526574430.643 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2018-05-17T16:27:10.643Z,1526574430.643 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2018-05-17T16:27:10.644Z,1526574430.644 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 8953
2018-05-17T16:27:10.646Z,1526574430.646 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2018-05-17T16:27:10.657Z,1526574430.657 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2018-05-17T16:27:10.658Z,1526574430.658 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2018-05-17T16:27:10.659Z,1526574430.659 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 8954
2018-05-17T16:27:10.659Z,1526574430.659 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2018-05-17T16:27:10.660Z,1526574430.660 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2018-05-17T16:27:10.661Z,1526574430.661 [logger ThreadHandler](INFO): Protected caller Thread ID is 8955
2018-05-17T16:27:10.663Z,1526574430.663 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2018-05-17T16:27:10.663Z,1526574430.663 [Supervisor](INFO): Looking for Config files in directory: Config/
2018-05-17T16:27:10.664Z,1526574430.664 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2018-05-17T16:27:10.986Z,1526574430.986 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2018-05-17T16:27:10.987Z,1526574430.987 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2018-05-17T16:27:11.183Z,1526574431.183 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2018-05-17T16:27:11.184Z,1526574431.184 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2018-05-17T16:27:11.463Z,1526574431.463 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2018-05-17T16:27:11.464Z,1526574431.464 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2018-05-17T16:27:11.608Z,1526574431.608 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2018-05-17T16:27:11.608Z,1526574431.608 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2018-05-17T16:27:11.775Z,1526574431.775 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2018-05-17T16:27:11.775Z,1526574431.775 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2018-05-17T16:27:12.236Z,1526574432.236 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2018-05-17T16:27:12.237Z,1526574432.237 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2018-05-17T16:27:12.594Z,1526574432.594 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2018-05-17T16:27:12.595Z,1526574432.595 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2018-05-17T16:27:13.031Z,1526574433.031 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2018-05-17T16:27:13.032Z,1526574433.032 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2018-05-17T16:27:13.136Z,1526574433.136 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2018-05-17T16:27:13.137Z,1526574433.137 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2018-05-17T16:27:13.233Z,1526574433.233 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2018-05-17T16:27:13.234Z,1526574433.234 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2018-05-17T16:27:13.433Z,1526574433.433 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2018-05-17T16:27:13.434Z,1526574433.434 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2018-05-17T16:27:13.638Z,1526574433.638 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2018-05-17T16:27:13.638Z,1526574433.638 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2018-05-17T16:27:13.977Z,1526574433.977 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2018-05-17T16:27:13.977Z,1526574433.977 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2018-05-17T16:27:14.115Z,1526574434.115 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2018-05-17T16:27:14.116Z,1526574434.116 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2018-05-17T16:27:14.197Z,1526574434.197 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2018-05-17T16:27:14.198Z,1526574434.198 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2018-05-17T16:27:14.299Z,1526574434.299 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2018-05-17T16:27:14.390Z,1526574434.390 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2018-05-17T16:27:14.484Z,1526574434.484 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2018-05-17T16:27:14.568Z,1526574434.568 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2018-05-17T16:27:14.717Z,1526574434.717 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2018-05-17T16:27:14.891Z,1526574434.891 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg
2018-05-17T16:27:14.967Z,1526574434.967 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg
2018-05-17T16:27:15.198Z,1526574435.198 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2018-05-17T16:27:15.199Z,1526574435.199 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg
2018-05-17T16:27:15.280Z,1526574435.280 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg
2018-05-17T16:27:15.368Z,1526574435.368 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2018-05-17T16:27:15.467Z,1526574435.467 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2018-05-17T16:27:15.589Z,1526574435.589 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/root/
2018-05-17T16:27:15.589Z,1526574435.589 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2018-05-17T16:27:15.592Z,1526574435.592 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2018-05-17T16:27:15.851Z,1526574435.851 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2018-05-17T16:27:15.852Z,1526574435.852 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2018-05-17T16:27:15.897Z,1526574435.897 [DepthRateCalculator] Loaded
2018-05-17T16:27:15.897Z,1526574435.897 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2018-05-17T16:27:15.903Z,1526574435.903 [PitchRateCalculator] Loaded
2018-05-17T16:27:15.904Z,1526574435.904 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2018-05-17T16:27:15.920Z,1526574435.920 [SpeedCalculator] Loaded
2018-05-17T16:27:15.920Z,1526574435.920 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2018-05-17T16:27:15.941Z,1526574435.941 [TempGradientCalculator] Loaded
2018-05-17T16:27:15.941Z,1526574435.941 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2018-05-17T16:27:15.957Z,1526574435.957 [VerticalTemperatureHomogeneityIndexCalculator] Loaded
2018-05-17T16:27:15.957Z,1526574435.957 [ComponentRegistry](DEBUG): SyncComponent "VerticalTemperatureHomogeneityIndexCalculator" handled in the control thread.
2018-05-17T16:27:15.963Z,1526574435.963 [YawRateCalculator] Loaded
2018-05-17T16:27:15.963Z,1526574435.963 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2018-05-17T16:27:16.003Z,1526574436.003 [ElevatorOffsetCalculator] Loaded
2018-05-17T16:27:16.004Z,1526574436.004 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2018-05-17T16:27:16.004Z,1526574436.004 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2018-05-17T16:27:16.004Z,1526574436.004 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2018-05-17T16:27:16.090Z,1526574436.090 [StratificationFrontDetector](INFO): threshold set to: 0.399988 degC
2018-05-17T16:27:16.091Z,1526574436.091 [StratificationFrontDetector](DEBUG): (re)initializing
2018-05-17T16:27:16.091Z,1526574436.091 [StratificationFrontDetector] Loaded
2018-05-17T16:27:16.091Z,1526574436.091 [ComponentRegistry](DEBUG): SyncComponent "StratificationFrontDetector" handled in the control thread.
2018-05-17T16:27:16.092Z,1526574436.092 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2018-05-17T16:27:16.092Z,1526574436.092 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2018-05-17T16:27:16.212Z,1526574436.212 [BuoyancyServo] Loaded
2018-05-17T16:27:16.212Z,1526574436.212 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2018-05-17T16:27:16.226Z,1526574436.226 [ElevatorServo] Loaded
2018-05-17T16:27:16.227Z,1526574436.227 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2018-05-17T16:27:16.241Z,1526574436.241 [MassServo] Loaded
2018-05-17T16:27:16.241Z,1526574436.241 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2018-05-17T16:27:16.256Z,1526574436.256 [RudderServo] Loaded
2018-05-17T16:27:16.257Z,1526574436.257 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2018-05-17T16:27:16.271Z,1526574436.271 [ThrusterServo] Loaded
2018-05-17T16:27:16.271Z,1526574436.271 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2018-05-17T16:27:16.272Z,1526574436.272 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2018-05-17T16:27:16.272Z,1526574436.272 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2018-05-17T16:27:16.285Z,1526574436.285 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2018-05-17T16:27:16.286Z,1526574436.286 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2018-05-17T16:27:16.394Z,1526574436.394 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2018-05-17T16:27:16.395Z,1526574436.395 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2018-05-17T16:27:16.690Z,1526574436.690 [DataOverHttps] Loaded
2018-05-17T16:27:16.690Z,1526574436.690 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2018-05-17T16:27:16.704Z,1526574436.704 [Depth_Keller] Loaded
2018-05-17T16:27:16.704Z,1526574436.704 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2018-05-17T16:27:16.709Z,1526574436.709 [DropWeight] Loaded
2018-05-17T16:27:16.709Z,1526574436.709 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2018-05-17T16:27:16.710Z,1526574436.710 [Module Loader](CRITICAL): Could not find element GobyModem.loadAtStartup
2018-05-17T16:27:16.811Z,1526574436.811 [NAL9602] Loaded
2018-05-17T16:27:16.811Z,1526574436.811 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2018-05-17T16:27:16.827Z,1526574436.827 [Onboard] Loaded
2018-05-17T16:27:16.827Z,1526574436.827 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2018-05-17T16:27:16.837Z,1526574436.837 [Radio_Surface] Loaded
2018-05-17T16:27:16.837Z,1526574436.837 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2018-05-17T16:27:16.839Z,1526574436.839 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408844E0
2018-05-17T16:27:16.839Z,1526574436.839 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 9037
2018-05-17T16:27:16.887Z,1526574436.887 [PNI_TCM] Loaded
2018-05-17T16:27:16.888Z,1526574436.888 [ComponentRegistry](DEBUG): SyncComponent "PNI_TCM" handled in the control thread.
2018-05-17T16:27:19.169Z,1526574439.169 [BPC1] Loaded
2018-05-17T16:27:19.169Z,1526574439.169 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2018-05-17T16:27:19.170Z,1526574439.170 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2018-05-17T16:27:19.170Z,1526574439.170 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2018-05-17T16:27:19.312Z,1526574439.312 [SBIT](DEBUG): Construct Startup Built In Test.
2018-05-17T16:27:19.334Z,1526574439.334 [SBIT] Loaded
2018-05-17T16:27:19.334Z,1526574439.334 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2018-05-17T16:27:19.335Z,1526574439.335 [IBIT](DEBUG): Construct Initiated Built In Test.
2018-05-17T16:27:19.346Z,1526574439.346 [IBIT] Loaded
2018-05-17T16:27:19.346Z,1526574439.346 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2018-05-17T16:27:19.349Z,1526574439.349 [CBIT](DEBUG): Construct Continuous Built In Test.
2018-05-17T16:27:19.502Z,1526574439.502 [CBIT] Loaded
2018-05-17T16:27:19.502Z,1526574439.502 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2018-05-17T16:27:19.503Z,1526574439.503 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2018-05-17T16:27:19.503Z,1526574439.503 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2018-05-17T16:27:19.654Z,1526574439.654 [Aanderaa_O2] Loaded
2018-05-17T16:27:19.654Z,1526574439.654 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2018-05-17T16:27:19.666Z,1526574439.666 [CANONSampler] Loaded
2018-05-17T16:27:19.666Z,1526574439.666 [ComponentRegistry](DEBUG): SyncComponent "CANONSampler" handled in the control thread.
2018-05-17T16:27:19.747Z,1526574439.747 [CTD_NeilBrown] Loaded
2018-05-17T16:27:19.747Z,1526574439.747 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2018-05-17T16:27:19.748Z,1526574439.748 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 409444E0
2018-05-17T16:27:19.748Z,1526574439.748 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 9038
2018-05-17T16:27:19.796Z,1526574439.796 [CTD_Seabird] Loaded
2018-05-17T16:27:19.796Z,1526574439.796 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2018-05-17T16:27:19.797Z,1526574439.797 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 409744E0
2018-05-17T16:27:19.798Z,1526574439.798 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 9039
2018-05-17T16:27:19.812Z,1526574439.812 [PAR_Licor] Loaded
2018-05-17T16:27:19.812Z,1526574439.812 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2018-05-17T16:27:19.862Z,1526574439.862 [WetLabsBB2FL] Loaded
2018-05-17T16:27:19.862Z,1526574439.862 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2018-05-17T16:27:19.863Z,1526574439.863 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 409A44E0
2018-05-17T16:27:19.863Z,1526574439.863 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 9040
2018-05-17T16:27:19.864Z,1526574439.864 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2018-05-17T16:27:19.865Z,1526574439.865 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2018-05-17T16:27:19.938Z,1526574439.938 [VerticalControl](DEBUG): Construct VerticalControl.
2018-05-17T16:27:20.022Z,1526574440.022 [VerticalControl] Loaded
2018-05-17T16:27:20.022Z,1526574440.022 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2018-05-17T16:27:20.023Z,1526574440.023 [HorizontalControl](DEBUG): Construct HorizontalControl.
2018-05-17T16:27:20.081Z,1526574440.081 [HorizontalControl] Loaded
2018-05-17T16:27:20.081Z,1526574440.081 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2018-05-17T16:27:20.082Z,1526574440.082 [SpeedControl](DEBUG): Construct SpeedControl.
2018-05-17T16:27:20.083Z,1526574440.083 [SpeedControl] Loaded
2018-05-17T16:27:20.084Z,1526574440.084 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2018-05-17T16:27:20.084Z,1526574440.084 [LoopControl](DEBUG): Construct LoopControl.
2018-05-17T16:27:20.085Z,1526574440.085 [LoopControl] Loaded
2018-05-17T16:27:20.085Z,1526574440.085 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2018-05-17T16:27:20.086Z,1526574440.086 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2018-05-17T16:27:20.086Z,1526574440.086 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2018-05-17T16:27:20.112Z,1526574440.112 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2018-05-17T16:27:20.112Z,1526574440.112 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2018-05-17T16:27:20.205Z,1526574440.205 [DeadReckonUsingSpeedCalculator] Loaded
2018-05-17T16:27:20.206Z,1526574440.206 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2018-05-17T16:27:20.262Z,1526574440.262 [DeadReckonWithRespectToSeafloor] Loaded
2018-05-17T16:27:20.263Z,1526574440.263 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonWithRespectToSeafloor" handled in the control thread.
2018-05-17T16:27:20.279Z,1526574440.279 [NavChart] Loaded
2018-05-17T16:27:20.279Z,1526574440.279 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2018-05-17T16:27:20.283Z,1526574440.283 [UniversalFixResidualReporter] Loaded
2018-05-17T16:27:20.284Z,1526574440.284 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2018-05-17T16:27:20.284Z,1526574440.284 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2018-05-17T16:27:20.287Z,1526574440.287 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2018-05-17T16:27:20.288Z,1526574440.288 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2018-05-17T16:27:20.295Z,1526574440.295 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2018-05-17T16:27:20.296Z,1526574440.296 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40A304E0
2018-05-17T16:27:20.296Z,1526574440.296 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 9041
2018-05-17T16:27:20.301Z,1526574440.301 [Supervisor](INFO): Main Thread ID is 8514
2018-05-17T16:27:20.301Z,1526574440.301 [Supervisor](DEBUG): Running supervisor.
2018-05-17T16:27:20.301Z,1526574440.301 [CommandLine ThreadHandler](INFO): Handler Thread ID is 9042
2018-05-17T16:27:20.304Z,1526574440.304 [controlThread ThreadHandler](INFO): Handler Thread ID is 9043
2018-05-17T16:27:20.304Z,1526574440.304 [controlThread](DEBUG): Initializing ControlThread
2018-05-17T16:27:20.305Z,1526574440.305 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2018-05-17T16:27:20.306Z,1526574440.306 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2018-05-17T16:27:20.306Z,1526574440.306 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2018-05-17T16:27:20.306Z,1526574440.306 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2018-05-17T16:27:20.307Z,1526574440.307 [VerticalTemperatureHomogeneityIndexCalculator](DEBUG): (re)initializing
2018-05-17T16:27:20.308Z,1526574440.308 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2018-05-17T16:27:20.308Z,1526574440.308 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2018-05-17T16:27:20.313Z,1526574440.313 [SBIT](INFO): Initialize SBIT Component.
2018-05-17T16:27:20.314Z,1526574440.314 [SBIT](IMPORTANT): git: 2018-03-26-70-gf564a3b
2018-05-17T16:27:20.314Z,1526574440.314 [SBIT](INFO): git hash: f564a3bc58329a2b76cea2ca9c8813404f43c181
2018-05-17T16:27:20.314Z,1526574440.314 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2018-05-17T16:27:20.315Z,1526574440.315 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #639 PREEMPT Wed Mar 12 12:53:33 PDT 2014
Kernel Reported: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
2018-05-17T16:27:20.316Z,1526574440.316 [SBIT](INFO): Beginning SBIT in 23.000000 seconds.
2018-05-17T16:27:20.317Z,1526574440.317 [IBIT](INFO): Initialize IBIT Component.
2018-05-17T16:27:20.318Z,1526574440.318 [CBIT](DEBUG): Initialize CBIT Component.
2018-05-17T16:27:20.318Z,1526574440.318 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2018-05-17T16:27:20.319Z,1526574440.319 [logger ThreadHandler](INFO): Handler Thread ID is 9044
2018-05-17T16:27:20.339Z,1526574440.339 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 9045
2018-05-17T16:27:20.345Z,1526574440.345 [Radio_Surface](INFO): Powering up
2018-05-17T16:27:20.351Z,1526574440.351 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 9046
2018-05-17T16:27:20.352Z,1526574440.352 [CTD_NeilBrown](INFO): Powering down
2018-05-17T16:27:20.379Z,1526574440.379 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 9047
2018-05-17T16:27:20.379Z,1526574440.379 [CTD_Seabird](INFO): Initializing
2018-05-17T16:27:20.380Z,1526574440.380 [CTD_Seabird](INFO): Checking LCM
2018-05-17T16:27:20.389Z,1526574440.389 [CTD_Seabird](INFO): LCM OK
2018-05-17T16:27:20.389Z,1526574440.389 [CTD_Seabird](INFO): Powering up
2018-05-17T16:27:20.399Z,1526574440.399 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 9048
2018-05-17T16:27:20.400Z,1526574440.400 [WetLabsBB2FL](INFO): Powering down
2018-05-17T16:27:20.427Z,1526574440.427 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2018-05-17T16:27:20.428Z,1526574440.428 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2018-05-17T16:27:20.429Z,1526574440.429 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2018-05-17T16:27:20.430Z,1526574440.430 [LoopControl](DEBUG): Initialize LoopControlComponent.
2018-05-17T16:27:20.430Z,1526574440.430 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-05-17T16:27:20.431Z,1526574440.431 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-05-17T16:27:20.431Z,1526574440.431 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-05-17T16:27:20.432Z,1526574440.432 [DeadReckonWithRespectToSeafloor](DEBUG): Initializing DeadReckonWithRespectToSeafloor component.
2018-05-17T16:27:20.432Z,1526574440.432 [DeadReckonWithRespectToSeafloor](INFO): Will consider orientation measurement stale after 120s.
2018-05-17T16:27:20.433Z,1526574440.433 [DeadReckonWithRespectToSeafloor](INFO): Will consider velocity measurement stale after 20s.
2018-05-17T16:27:20.433Z,1526574440.433 [NavChart](DEBUG): Initialize NavChart Navigation.
2018-05-17T16:27:20.433Z,1526574440.433 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2018-05-17T16:27:20.438Z,1526574440.438 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2018-05-17T16:27:20.447Z,1526574440.447 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 9049
2018-05-17T16:27:20.450Z,1526574440.450 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2018-05-17T16:27:20.450Z,1526574440.450 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2018-05-17T16:27:20.451Z,1526574440.451 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2018-05-17T16:27:20.451Z,1526574440.451 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2018-05-17T16:27:20.451Z,1526574440.451 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2018-05-17T16:27:20.451Z,1526574440.451 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2018-05-17T16:27:20.451Z,1526574440.451 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2018-05-17T16:27:20.451Z,1526574440.451 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2018-05-17T16:27:20.452Z,1526574440.452 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2018-05-17T16:27:20.452Z,1526574440.452 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2018-05-17T16:27:20.452Z,1526574440.452 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2018-05-17T16:27:20.452Z,1526574440.452 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2018-05-17T16:27:20.452Z,1526574440.452 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2018-05-17T16:27:20.453Z,1526574440.453 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2018-05-17T16:27:20.453Z,1526574440.453 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2018-05-17T16:27:20.453Z,1526574440.453 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2018-05-17T16:27:20.478Z,1526574440.478 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2018-05-17T16:27:20.517Z,1526574440.517 [MissionManager](DEBUG):
2018-05-17T16:27:20.518Z,1526574440.518 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2018-05-17T16:27:20.610Z,1526574440.610 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2018-05-17T16:27:20.611Z,1526574440.611 [Default:A.Wait](DEBUG): Construct Wait.
2018-05-17T16:27:20.613Z,1526574440.613 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2018-05-17T16:27:20.636Z,1526574440.636 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2018-05-17T16:27:20.658Z,1526574440.658 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2018-05-17T16:27:20.664Z,1526574440.664 [Default:E.Execute](DEBUG): Construct Execute.
2018-05-17T16:27:20.691Z,1526574440.691 [MissionManager](DEBUG):
0
Wait a moment to see if the scheduler starts a new mission before
starting to actually run Default.
13
Burn 300
Dropped weight due to communications timeout.
5
Default mission has been running for
Restarting logs and Default mission.
restart logs
2018-05-17T16:27:20.697Z,1526574440.697 [controlThread](DEBUG): Component order: CycleStarter,DataOverHttps,Depth_Keller,DropWeight,NAL9602,Onboard,PNI_TCM,BPC1,Aanderaa_O2,CANONSampler,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,VerticalTemperatureHomogeneityIndexCalculator,YawRateCalculator,ElevatorOffsetCalculator,StratificationFrontDetector,DeadReckonUsingSpeedCalculator,DeadReckonWithRespectToSeafloor,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2018-05-17T16:27:20.715Z,1526574440.715 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2018-05-17T16:27:20.758Z,1526574440.758 [Depth_Keller](ERROR): Pressure reading out of range: 1831.023193 decibar
2018-05-17T16:27:20.998Z,1526574440.998 [CANONSampler](INFO): Powering down
2018-05-17T16:27:21.180Z,1526574441.180 [DepthRateCalculator](ERROR): Depth measurement is not active
2018-05-17T16:27:21.280Z,1526574441.280 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-05-17T16:27:21.304Z,1526574441.304 [DeadReckonWithRespectToSeafloor](DEBUG): Starting up and don't have orientation data yet.
2018-05-17T16:27:21.403Z,1526574441.403 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2018-05-17T16:27:21.411Z,1526574441.411 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2018-05-17T16:27:21.425Z,1526574441.425 [ElevatorServo](DEBUG): Initializing EZServoServo.
2018-05-17T16:27:21.432Z,1526574441.432 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2018-05-17T16:27:21.446Z,1526574441.446 [MassServo](DEBUG): Initializing EZServoServo.
2018-05-17T16:27:21.451Z,1526574441.451 [MassServo](DEBUG): Initializing MassServo.
2018-05-17T16:27:21.457Z,1526574441.457 [RudderServo](DEBUG): Initializing EZServoServo.
2018-05-17T16:27:21.463Z,1526574441.463 [RudderServo](DEBUG): Initializing RudderServo.
2018-05-17T16:27:21.476Z,1526574441.476 [ThrusterServo](DEBUG): Initializing EZServoServo.
2018-05-17T16:27:21.483Z,1526574441.483 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2018-05-17T16:27:21.523Z,1526574441.523 [CommandLine](FAULT): Scheduling is paused
2018-05-17T16:27:21.524Z,1526574441.524 [CBIT](INFO): Critical error at 20180517T162716
2018-05-17T16:27:21.524Z,1526574441.524 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2018-05-17T16:27:21.712Z,1526574441.712 [DropWeight](CRITICAL): DROP WEIGHT MISSING.
2018-05-17T16:27:21.712Z,1526574441.712 [DropWeight] Hardware Fault, FailCount= 1
2018-05-17T16:27:21.712Z,1526574441.712 [DropWeight](ERROR): Hardware Fault
2018-05-17T16:27:21.767Z,1526574441.767 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-05-17T16:27:21.768Z,1526574441.768 [DeadReckonWithRespectToSeafloor](DEBUG): Starting up and don't have orientation data yet.
2018-05-17T16:27:21.791Z,1526574441.791 [CBIT](INFO): Critical error at 20180517T162721
2018-05-17T16:27:21.794Z,1526574441.794 [CBIT](ERROR): Hardware Fault in component: DropWeight
2018-05-17T16:27:21.795Z,1526574441.795 [CBIT](CRITICAL): Hardware Fault in component: DropWeight
2018-05-17T16:27:22.009Z,1526574442.009 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-05-17T16:27:22.010Z,1526574442.010 [DeadReckonWithRespectToSeafloor](DEBUG): Starting up and don't have orientation data yet.
2018-05-17T16:27:22.444Z,1526574442.444 [CBIT](INFO): Critical error at 20180517T162721
2018-05-17T16:27:22.501Z,1526574442.501 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-05-17T16:27:22.510Z,1526574442.510 [DeadReckonWithRespectToSeafloor](DEBUG): Starting up and don't have orientation data yet.
2018-05-17T16:27:22.923Z,1526574442.923 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-05-17T16:27:22.923Z,1526574442.923 [DeadReckonWithRespectToSeafloor](DEBUG): Starting up and don't have orientation data yet.
2018-05-17T16:27:23.306Z,1526574443.306 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-05-17T16:27:23.323Z,1526574443.323 [DeadReckonWithRespectToSeafloor](DEBUG): Starting up and don't have orientation data yet.
2018-05-17T16:27:23.703Z,1526574443.703 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-05-17T16:27:23.704Z,1526574443.704 [DeadReckonWithRespectToSeafloor](DEBUG): Starting up and don't have orientation data yet.
2018-05-17T16:27:24.207Z,1526574444.207 [Aanderaa_O2](INFO): Powering down
2018-05-17T16:27:24.322Z,1526574444.322 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-05-17T16:27:24.331Z,1526574444.331 [DeadReckonWithRespectToSeafloor](DEBUG): Starting up and don't have orientation data yet.
2018-05-17T16:27:25.919Z,1526574445.919 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface
2018-05-17T16:27:25.997Z,1526574445.997 [CTD_Seabird](INFO): Started Seabird LCM interface with command:nohup ./lrauv-framework/onboard/bin/gpctd -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyC6 -b 9600 >& /dev/null &
2018-05-17T16:27:26.040Z,1526574446.040 [CTD_Seabird](INFO): LCM subscribed to channel:ctd_t.seabird-gpctd
2018-05-17T16:27:26.450Z,1526574446.450 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface
2018-05-17T16:27:26.450Z,1526574446.450 [CTD_Seabird](INFO): Powering down
2018-05-17T16:27:43.771Z,1526574463.771 [SBIT](IMPORTANT): Beginning Startup BIT
2018-05-17T16:27:43.783Z,1526574463.783 [CBIT](IMPORTANT): Beginning ground fault scan
2018-05-17T16:27:47.096Z,1526574467.096 [NAL9602](INFO): Powering up NAL9602
2018-05-17T16:27:54.785Z,1526574474.785 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.002638
CHAN A1 (24V): -0.005842
CHAN A2 (12V): -0.002182
CHAN A3 (5V): -0.001671
CHAN B0 (3.3V): -0.000133
CHAN B1 (3.15aV): 0.000201
CHAN B2 (3.15bV): -0.000058
CHAN B3 (GND): 0.000268
OPEN: -0.000544
Full Scale Calc: 4.765 mA, -1.589 mA
2018-05-17T16:27:58.288Z,1526574478.288 [NAL9602](INFO): NAL9602 initialized
2018-05-17T16:28:37.502Z,1526574517.502 [SBIT](IMPORTANT): SBIT PASSED
2018-05-17T16:28:37.546Z,1526574517.546 [CommandLine](IMPORTANT): got command configSet list
2018-05-17T16:28:37.546Z,1526574517.546 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2018-05-17T16:28:37.548Z,1526574517.548 [CommandLine](IMPORTANT): Rowe_600LCM.loadAtStartup=0 bool;
2018-05-17T16:28:37.881Z,1526574517.881 [MissionManager](IMPORTANT): Started mission Startup
2018-05-17T16:28:37.881Z,1526574517.881 [Startup] Running Loop=1
2018-05-17T16:28:37.881Z,1526574517.881 [Startup](DEBUG): Aggregate::initialize Startup
2018-05-17T16:28:37.881Z,1526574517.881 [Startup:A.GoToSurface] Running Loop=1
2018-05-17T16:28:37.881Z,1526574517.881 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-05-17T16:28:37.882Z,1526574517.882 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2018-05-17T16:28:37.915Z,1526574517.915 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2018-05-17T16:28:37.916Z,1526574517.916 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2018-05-17T16:28:37.916Z,1526574517.916 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-05-17T16:28:37.916Z,1526574517.916 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2018-05-17T16:28:37.922Z,1526574517.922 [Startup:StartupSatComms] Running Loop=1
2018-05-17T16:28:37.923Z,1526574517.923 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2018-05-17T16:28:37.923Z,1526574517.923 [Startup:StartupSatComms:A] Running Loop=1
2018-05-17T16:28:38.281Z,1526574518.281 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2018-05-17T16:29:10.661Z,1526574550.661 [BPC1](ERROR): Bank A: No match for stick 4 serial number:1717 in the onboard configuration file.
2018-05-17T16:29:10.661Z,1526574550.661 [BPC1](ERROR): Failed to parse Bank A battery data
2018-05-17T16:29:38.292Z,1526574578.292 [Startup:StartupSatComms:A](INFO): Timed out from 2018-05-17T16:28:37.9Z
2018-05-17T16:29:38.292Z,1526574578.292 [Startup:StartupSatComms:A] Stopped
2018-05-17T16:29:38.292Z,1526574578.292 [Startup:StartupSatComms:B] Running Loop=1
2018-05-17T16:29:38.671Z,1526574578.671 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2018-05-17T16:30:20.682Z,1526574620.682 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-05-17T16:30:20.682Z,1526574620.682 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 1
2018-05-17T16:30:20.682Z,1526574620.682 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-05-17T16:30:20.688Z,1526574620.688 [DeadReckonWithRespectToSeafloor](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-05-17T16:30:20.688Z,1526574620.688 [DeadReckonWithRespectToSeafloor] Software Fault, FailCount= 1
2018-05-17T16:30:20.688Z,1526574620.688 [DeadReckonWithRespectToSeafloor](ERROR): Software Fault
2018-05-17T16:30:20.717Z,1526574620.717 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-05-17T16:30:20.717Z,1526574620.717 [CBIT](ERROR): Software Fault in component: DeadReckonWithRespectToSeafloor
2018-05-17T16:30:21.099Z,1526574621.099 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-05-17T16:30:21.099Z,1526574621.099 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 1
2018-05-17T16:30:21.099Z,1526574621.099 [CBIT](INFO): Clearing failed state for component DeadReckonWithRespectToSeafloor
2018-05-17T16:30:21.099Z,1526574621.099 [DeadReckonWithRespectToSeafloor] No Fault, FailCount= 1
2018-05-17T16:30:21.501Z,1526574621.501 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-05-17T16:30:21.501Z,1526574621.501 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-05-17T16:30:21.502Z,1526574621.502 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-05-17T16:30:21.502Z,1526574621.502 [DeadReckonWithRespectToSeafloor](DEBUG): Initializing DeadReckonWithRespectToSeafloor component.
2018-05-17T16:30:21.503Z,1526574621.503 [DeadReckonWithRespectToSeafloor](INFO): Will consider orientation measurement stale after 120s.
2018-05-17T16:30:21.503Z,1526574621.503 [DeadReckonWithRespectToSeafloor](INFO): Will consider velocity measurement stale after 20s.
2018-05-17T16:30:25.427Z,1526574625.427 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003944
2018-05-17T16:30:29.441Z,1526574629.441 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180517T162231/Courier0004.lzma
2018-05-17T16:30:30.240Z,1526574630.240 [DataOverHttps](INFO): Moved sent file to Logs/20180517T162231/Courier0004.lzma.bak
2018-05-17T16:30:30.240Z,1526574630.240 [DataOverHttps](INFO): SBD MOMSN=8283056
2018-05-17T16:30:40.202Z,1526574640.202 [Startup:StartupSatComms:B](INFO): Timed out from 2018-05-17T16:29:38.3Z
2018-05-17T16:30:40.202Z,1526574640.202 [Startup:StartupSatComms:B] Stopped
2018-05-17T16:30:40.203Z,1526574640.203 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2018-05-17T16:30:40.203Z,1526574640.203 [Startup:StartupSatComms] Stopped
2018-05-17T16:30:40.203Z,1526574640.203 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2018-05-17T16:30:40.204Z,1526574640.204 [Startup](INFO): Completed Startup
2018-05-17T16:30:40.204Z,1526574640.204 [MissionManager](INFO): Startup is completed.
2018-05-17T16:30:40.204Z,1526574640.204 [MissionManager](INFO): Uninitializing Mission Startup
2018-05-17T16:30:40.204Z,1526574640.204 [Startup] Stopped
2018-05-17T16:30:40.204Z,1526574640.204 [Startup](DEBUG): Aggregate::uninitialize Startup
2018-05-17T16:30:40.204Z,1526574640.204 [Startup:A.GoToSurface] Stopped
2018-05-17T16:30:40.204Z,1526574640.204 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2018-05-17T16:30:40.241Z,1526574640.241 [DataOverHttps](INFO): Sending 201 bytes from file Logs/20180517T162710/Courier0000.lzma
2018-05-17T16:30:40.371Z,1526574640.371 [MissionManager](IMPORTANT): Started mission Default
2018-05-17T16:30:40.372Z,1526574640.372 [Default] Running Loop=1
2018-05-17T16:30:40.372Z,1526574640.372 [Default](DEBUG): Aggregate::initialize Default
2018-05-17T16:30:40.372Z,1526574640.372 [Default:B.GoToSurface] Running Loop=1
2018-05-17T16:30:40.372Z,1526574640.372 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-05-17T16:30:40.372Z,1526574640.372 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2018-05-17T16:30:40.372Z,1526574640.372 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2018-05-17T16:30:40.373Z,1526574640.373 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2018-05-17T16:30:40.373Z,1526574640.373 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-05-17T16:30:40.374Z,1526574640.374 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2018-05-17T16:30:40.374Z,1526574640.374 [Default:A.Wait] Running Loop=1
2018-05-17T16:30:40.374Z,1526574640.374 [Default:A.Wait](DEBUG): Initialize Wait Component.
2018-05-17T16:30:41.023Z,1526574641.023 [DataOverHttps](INFO): Moved sent file to Logs/20180517T162710/Courier0000.lzma.bak
2018-05-17T16:30:41.024Z,1526574641.024 [DataOverHttps](INFO): SBD MOMSN=82830