2019-05-01T16:07:58.164Z,1556726878.164 [Supervisor](DEBUG): Initializing supervisor.
2019-05-01T16:07:58.167Z,1556726878.167 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2019-05-01T16:07:58.167Z,1556726878.167 [SyncHandler](INFO): Protected caller Thread ID is 4478
2019-05-01T16:07:58.168Z,1556726878.168 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2019-05-01T16:07:58.169Z,1556726878.169 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2019-05-01T16:07:58.169Z,1556726878.169 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 4479
2019-05-01T16:07:58.172Z,1556726878.172 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2019-05-01T16:07:58.184Z,1556726878.184 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2019-05-01T16:07:58.185Z,1556726878.185 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2019-05-01T16:07:58.186Z,1556726878.186 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 4480
2019-05-01T16:07:58.187Z,1556726878.187 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2019-05-01T16:07:58.188Z,1556726878.188 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2019-05-01T16:07:58.188Z,1556726878.188 [logger ThreadHandler](INFO): Protected caller Thread ID is 4481
2019-05-01T16:07:58.190Z,1556726878.190 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2019-05-01T16:07:58.190Z,1556726878.190 [Supervisor](INFO): Looking for Config files in directory: Config/
2019-05-01T16:07:58.192Z,1556726878.192 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2019-05-01T16:07:58.390Z,1556726878.390 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2019-05-01T16:07:58.391Z,1556726878.391 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2019-05-01T16:07:58.470Z,1556726878.470 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2019-05-01T16:07:58.933Z,1556726878.933 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2019-05-01T16:07:58.933Z,1556726878.933 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2019-05-01T16:07:59.274Z,1556726879.274 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2019-05-01T16:07:59.274Z,1556726879.274 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2019-05-01T16:07:59.369Z,1556726879.369 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2019-05-01T16:07:59.369Z,1556726879.369 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2019-05-01T16:07:59.679Z,1556726879.679 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2019-05-01T16:07:59.679Z,1556726879.679 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2019-05-01T16:07:59.871Z,1556726879.871 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2019-05-01T16:07:59.872Z,1556726879.872 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2019-05-01T16:08:00.319Z,1556726880.319 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2019-05-01T16:08:00.319Z,1556726880.319 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2019-05-01T16:08:00.425Z,1556726880.425 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2019-05-01T16:08:00.425Z,1556726880.425 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2019-05-01T16:08:00.523Z,1556726880.523 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2019-05-01T16:08:00.524Z,1556726880.524 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2019-05-01T16:08:01.091Z,1556726881.091 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2019-05-01T16:08:01.092Z,1556726881.092 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2019-05-01T16:08:01.495Z,1556726881.495 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2019-05-01T16:08:01.496Z,1556726881.496 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2019-05-01T16:08:01.688Z,1556726881.688 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2019-05-01T16:08:01.688Z,1556726881.688 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2019-05-01T16:08:01.831Z,1556726881.831 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2019-05-01T16:08:01.831Z,1556726881.831 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2019-05-01T16:08:01.978Z,1556726881.978 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2019-05-01T16:08:01.980Z,1556726881.980 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2019-05-01T16:08:01.980Z,1556726881.980 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg
2019-05-01T16:08:02.069Z,1556726882.069 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2019-05-01T16:08:02.152Z,1556726882.152 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2019-05-01T16:08:02.252Z,1556726882.252 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg
2019-05-01T16:08:02.333Z,1556726882.333 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2019-05-01T16:08:02.426Z,1556726882.426 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2019-05-01T16:08:02.524Z,1556726882.524 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2019-05-01T16:08:02.725Z,1556726882.725 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg
2019-05-01T16:08:02.800Z,1556726882.800 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2019-05-01T16:08:02.967Z,1556726882.967 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2019-05-01T16:08:03.101Z,1556726883.101 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2019-05-01T16:08:03.220Z,1556726883.220 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg
2019-05-01T16:08:03.446Z,1556726883.446 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2019-05-01T16:08:03.448Z,1556726883.448 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/root/
2019-05-01T16:08:03.448Z,1556726883.448 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2019-05-01T16:08:03.452Z,1556726883.452 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2019-05-01T16:08:03.519Z,1556726883.519 [VerticalControl](DEBUG): Construct VerticalControl.
2019-05-01T16:08:03.631Z,1556726883.631 [VerticalControl] Loaded
2019-05-01T16:08:03.632Z,1556726883.632 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2019-05-01T16:08:03.632Z,1556726883.632 [HorizontalControl](DEBUG): Construct HorizontalControl.
2019-05-01T16:08:03.700Z,1556726883.700 [HorizontalControl] Loaded
2019-05-01T16:08:03.700Z,1556726883.700 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2019-05-01T16:08:03.701Z,1556726883.701 [SpeedControl](DEBUG): Construct SpeedControl.
2019-05-01T16:08:03.706Z,1556726883.706 [SpeedControl] Loaded
2019-05-01T16:08:03.707Z,1556726883.707 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2019-05-01T16:08:03.707Z,1556726883.707 [LoopControl](DEBUG): Construct LoopControl.
2019-05-01T16:08:03.708Z,1556726883.708 [LoopControl] Loaded
2019-05-01T16:08:03.708Z,1556726883.708 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2019-05-01T16:08:03.709Z,1556726883.709 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2019-05-01T16:08:03.709Z,1556726883.709 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2019-05-01T16:08:03.722Z,1556726883.722 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2019-05-01T16:08:03.723Z,1556726883.723 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2019-05-01T16:08:03.821Z,1556726883.821 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2019-05-01T16:08:03.822Z,1556726883.822 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2019-05-01T16:08:03.946Z,1556726883.946 [BuoyancyServo] Loaded
2019-05-01T16:08:03.947Z,1556726883.947 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2019-05-01T16:08:03.958Z,1556726883.958 [ElevatorServo] Loaded
2019-05-01T16:08:03.958Z,1556726883.958 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2019-05-01T16:08:03.969Z,1556726883.969 [MassServo] Loaded
2019-05-01T16:08:03.969Z,1556726883.969 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2019-05-01T16:08:03.980Z,1556726883.980 [RudderServo] Loaded
2019-05-01T16:08:03.980Z,1556726883.980 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2019-05-01T16:08:03.991Z,1556726883.991 [ThrusterServo] Loaded
2019-05-01T16:08:03.991Z,1556726883.991 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2019-05-01T16:08:03.992Z,1556726883.992 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2019-05-01T16:08:03.992Z,1556726883.992 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2019-05-01T16:08:04.185Z,1556726884.185 [DeadReckonUsingMultipleVelocitySources] Loaded
2019-05-01T16:08:04.186Z,1556726884.186 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2019-05-01T16:08:04.206Z,1556726884.206 [NavChart] Loaded
2019-05-01T16:08:04.206Z,1556726884.206 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2019-05-01T16:08:04.210Z,1556726884.210 [UniversalFixResidualReporter] Loaded
2019-05-01T16:08:04.210Z,1556726884.210 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2019-05-01T16:08:04.211Z,1556726884.211 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2019-05-01T16:08:04.211Z,1556726884.211 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2019-05-01T16:08:04.356Z,1556726884.356 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2019-05-01T16:08:04.403Z,1556726884.403 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2019-05-01T16:08:05.076Z,1556726885.076 [AHRS_M2] Loaded
2019-05-01T16:08:05.076Z,1556726885.076 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2019-05-01T16:08:05.150Z,1556726885.150 [DataOverHttps] Loaded
2019-05-01T16:08:05.151Z,1556726885.151 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2019-05-01T16:08:05.152Z,1556726885.152 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4087B4E0
2019-05-01T16:08:05.152Z,1556726885.152 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 4563
2019-05-01T16:08:05.166Z,1556726885.166 [Depth_Keller] Loaded
2019-05-01T16:08:05.166Z,1556726885.166 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2019-05-01T16:08:05.171Z,1556726885.171 [DropWeight] Loaded
2019-05-01T16:08:05.171Z,1556726885.171 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2019-05-01T16:08:05.299Z,1556726885.299 [DVL_micro] Loaded
2019-05-01T16:08:05.300Z,1556726885.300 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread.
2019-05-01T16:08:05.396Z,1556726885.396 [NAL9602] Loaded
2019-05-01T16:08:05.396Z,1556726885.396 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2019-05-01T16:08:05.424Z,1556726885.424 [Onboard] Loaded
2019-05-01T16:08:05.424Z,1556726885.424 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2019-05-01T16:08:05.428Z,1556726885.428 [Radio_Surface] Loaded
2019-05-01T16:08:05.428Z,1556726885.428 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2019-05-01T16:08:05.431Z,1556726885.431 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408AB4E0
2019-05-01T16:08:05.431Z,1556726885.431 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 4564
2019-05-01T16:08:05.684Z,1556726885.684 [DAT] Loaded
2019-05-01T16:08:05.684Z,1556726885.684 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread.
2019-05-01T16:08:07.284Z,1556726887.284 [BPC1] Loaded
2019-05-01T16:08:07.284Z,1556726887.284 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2019-05-01T16:08:07.285Z,1556726887.285 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2019-05-01T16:08:07.285Z,1556726887.285 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2019-05-01T16:08:07.326Z,1556726887.326 [DepthRateCalculator] Loaded
2019-05-01T16:08:07.326Z,1556726887.326 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2019-05-01T16:08:07.331Z,1556726887.331 [PitchRateCalculator] Loaded
2019-05-01T16:08:07.331Z,1556726887.331 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2019-05-01T16:08:07.343Z,1556726887.343 [SpeedCalculator] Loaded
2019-05-01T16:08:07.343Z,1556726887.343 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2019-05-01T16:08:07.364Z,1556726887.364 [TempGradientCalculator] Loaded
2019-05-01T16:08:07.365Z,1556726887.365 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2019-05-01T16:08:07.370Z,1556726887.370 [YawRateCalculator] Loaded
2019-05-01T16:08:07.370Z,1556726887.370 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2019-05-01T16:08:07.399Z,1556726887.399 [ElevatorOffsetCalculator] Loaded
2019-05-01T16:08:07.400Z,1556726887.400 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2019-05-01T16:08:07.400Z,1556726887.400 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2019-05-01T16:08:07.401Z,1556726887.401 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2019-05-01T16:08:07.647Z,1556726887.647 [CTD_NeilBrown] Loaded
2019-05-01T16:08:07.647Z,1556726887.647 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2019-05-01T16:08:07.648Z,1556726887.648 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 409A54E0
2019-05-01T16:08:07.648Z,1556726887.648 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 4565
2019-05-01T16:08:07.657Z,1556726887.657 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_density
2019-05-01T16:08:07.663Z,1556726887.663 [CTD_Seabird](INFO): created writer for : sea_water_density
2019-05-01T16:08:07.664Z,1556726887.664 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): depth
2019-05-01T16:08:07.669Z,1556726887.669 [CTD_Seabird](INFO): created writer for : depth
2019-05-01T16:08:07.669Z,1556726887.669 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_pressure
2019-05-01T16:08:07.674Z,1556726887.674 [CTD_Seabird](INFO): created writer for : sea_water_pressure
2019-05-01T16:08:07.675Z,1556726887.675 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_salinity
2019-05-01T16:08:07.680Z,1556726887.680 [CTD_Seabird](INFO): created writer for : sea_water_salinity
2019-05-01T16:08:07.680Z,1556726887.680 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_temperature
2019-05-01T16:08:07.685Z,1556726887.685 [CTD_Seabird](INFO): created writer for : sea_water_temperature
2019-05-01T16:08:07.686Z,1556726887.686 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_electrical_conductivity
2019-05-01T16:08:07.691Z,1556726887.691 [CTD_Seabird](INFO): created writer for : sea_water_electrical_conductivity
2019-05-01T16:08:07.691Z,1556726887.691 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): speed_of_sound_in_sea_water
2019-05-01T16:08:07.696Z,1556726887.696 [CTD_Seabird](INFO): created writer for : speed_of_sound_in_sea_water
2019-05-01T16:08:07.723Z,1556726887.723 [CTD_Seabird] Loaded
2019-05-01T16:08:07.724Z,1556726887.724 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2019-05-01T16:08:07.725Z,1556726887.725 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 409D54E0
2019-05-01T16:08:07.725Z,1556726887.725 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 4566
2019-05-01T16:08:07.739Z,1556726887.739 [PAR_Licor] Loaded
2019-05-01T16:08:07.740Z,1556726887.740 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2019-05-01T16:08:07.787Z,1556726887.787 [WetLabsBB2FL] Loaded
2019-05-01T16:08:07.787Z,1556726887.787 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2019-05-01T16:08:07.788Z,1556726887.788 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40A054E0
2019-05-01T16:08:07.789Z,1556726887.789 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 4567
2019-05-01T16:08:07.790Z,1556726887.790 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2019-05-01T16:08:07.790Z,1556726887.790 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2019-05-01T16:08:07.816Z,1556726887.816 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2019-05-01T16:08:07.817Z,1556726887.817 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2019-05-01T16:08:08.106Z,1556726888.106 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2019-05-01T16:08:08.107Z,1556726888.107 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2019-05-01T16:08:08.241Z,1556726888.241 [SBIT](DEBUG): Construct Startup Built In Test.
2019-05-01T16:08:08.252Z,1556726888.252 [SBIT] Loaded
2019-05-01T16:08:08.252Z,1556726888.252 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2019-05-01T16:08:08.253Z,1556726888.253 [IBIT](DEBUG): Construct Initiated Built In Test.
2019-05-01T16:08:08.264Z,1556726888.264 [IBIT] Loaded
2019-05-01T16:08:08.264Z,1556726888.264 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2019-05-01T16:08:08.268Z,1556726888.268 [CBIT](DEBUG): Construct Continuous Built In Test.
2019-05-01T16:08:08.406Z,1556726888.406 [CBIT] Loaded
2019-05-01T16:08:08.407Z,1556726888.407 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2019-05-01T16:08:08.407Z,1556726888.407 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2019-05-01T16:08:08.411Z,1556726888.411 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2019-05-01T16:08:08.412Z,1556726888.412 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2019-05-01T16:08:08.418Z,1556726888.418 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2019-05-01T16:08:08.419Z,1556726888.419 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B034E0
2019-05-01T16:08:08.420Z,1556726888.420 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 4568
2019-05-01T16:08:08.425Z,1556726888.425 [Supervisor](INFO): Main Thread ID is 4339
2019-05-01T16:08:08.425Z,1556726888.425 [Supervisor](DEBUG): Running supervisor.
2019-05-01T16:08:08.425Z,1556726888.425 [CommandLine ThreadHandler](INFO): Handler Thread ID is 4569
2019-05-01T16:08:08.428Z,1556726888.428 [controlThread ThreadHandler](INFO): Handler Thread ID is 4570
2019-05-01T16:08:08.428Z,1556726888.428 [controlThread](DEBUG): Initializing ControlThread
2019-05-01T16:08:08.429Z,1556726888.429 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2019-05-01T16:08:08.431Z,1556726888.431 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2019-05-01T16:08:08.431Z,1556726888.431 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2019-05-01T16:08:08.432Z,1556726888.432 [LoopControl](DEBUG): Initialize LoopControlComponent.
2019-05-01T16:08:08.434Z,1556726888.434 [NavChart](DEBUG): Initialize NavChart Navigation.
2019-05-01T16:08:08.434Z,1556726888.434 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2019-05-01T16:08:08.439Z,1556726888.439 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2019-05-01T16:08:08.439Z,1556726888.439 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2019-05-01T16:08:08.440Z,1556726888.440 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2019-05-01T16:08:08.440Z,1556726888.440 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2019-05-01T16:08:08.441Z,1556726888.441 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2019-05-01T16:08:08.441Z,1556726888.441 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2019-05-01T16:08:08.445Z,1556726888.445 [SBIT](INFO): Initialize SBIT Component.
2019-05-01T16:08:08.446Z,1556726888.446 [SBIT](IMPORTANT): git: 2019-04-10-23-g672f59b
2019-05-01T16:08:08.446Z,1556726888.446 [SBIT](INFO): git hash: 672f59b3bb9ba34f4915fd4dcb9119316785292f
2019-05-01T16:08:08.446Z,1556726888.446 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2019-05-01T16:08:08.447Z,1556726888.447 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
Kernel Reported: #1 PREEMPT Tue Dec 18 21:19:28 PST 2018
2019-05-01T16:08:08.448Z,1556726888.448 [SBIT](INFO): Beginning SBIT in 23.000000 seconds.
2019-05-01T16:08:08.449Z,1556726888.449 [IBIT](INFO): Initialize IBIT Component.
2019-05-01T16:08:08.450Z,1556726888.450 [CBIT](DEBUG): Initialize CBIT Component.
2019-05-01T16:08:08.451Z,1556726888.451 [logger ThreadHandler](INFO): Handler Thread ID is 4571
2019-05-01T16:08:08.461Z,1556726888.461 [CBIT](DEBUG): Initialized mux pins.
2019-05-01T16:08:08.461Z,1556726888.461 [CBIT](DEBUG): Initializing the watchdog timer.
2019-05-01T16:08:08.469Z,1556726888.469 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 4572
2019-05-01T16:08:08.470Z,1556726888.470 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2019-05-01T16:08:08.481Z,1556726888.481 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 4573
2019-05-01T16:08:08.485Z,1556726888.485 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2019-05-01T16:08:08.485Z,1556726888.485 [CBIT](DEBUG): Initializing heartbeat.
2019-05-01T16:08:08.493Z,1556726888.493 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 4574
2019-05-01T16:08:08.494Z,1556726888.494 [CTD_NeilBrown](INFO): Powering down
2019-05-01T16:08:08.521Z,1556726888.521 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 4575
2019-05-01T16:08:08.522Z,1556726888.522 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2019-05-01T16:08:08.529Z,1556726888.529 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 4577
2019-05-01T16:08:08.530Z,1556726888.530 [WetLabsBB2FL](INFO): Powering down
2019-05-01T16:08:08.549Z,1556726888.549 [CTD_Seabird](INFO): Opening uart, block timeout 10ths=20
2019-05-01T16:08:08.557Z,1556726888.557 [CBIT](DEBUG): Deactivating GF circuits.
2019-05-01T16:08:08.557Z,1556726888.557 [CBIT](DEBUG): Deactivating emergency mode.
2019-05-01T16:08:08.558Z,1556726888.558 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 4578
2019-05-01T16:08:08.561Z,1556726888.561 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2019-05-01T16:08:08.561Z,1556726888.561 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2019-05-01T16:08:08.562Z,1556726888.562 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2019-05-01T16:08:08.562Z,1556726888.562 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2019-05-01T16:08:08.562Z,1556726888.562 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2019-05-01T16:08:08.562Z,1556726888.562 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2019-05-01T16:08:08.562Z,1556726888.562 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2019-05-01T16:08:08.563Z,1556726888.563 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2019-05-01T16:08:08.563Z,1556726888.563 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2019-05-01T16:08:08.563Z,1556726888.563 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2019-05-01T16:08:08.563Z,1556726888.563 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2019-05-01T16:08:08.563Z,1556726888.563 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2019-05-01T16:08:08.564Z,1556726888.564 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2019-05-01T16:08:08.564Z,1556726888.564 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2019-05-01T16:08:08.564Z,1556726888.564 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2019-05-01T16:08:08.564Z,1556726888.564 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2019-05-01T16:08:08.593Z,1556726888.593 [CBIT](DEBUG): Backplane powered.
2019-05-01T16:08:08.594Z,1556726888.594 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2019-05-01T16:08:08.603Z,1556726888.603 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2019-05-01T16:08:08.614Z,1556726888.614 [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>


2019-05-01T16:08:08.615Z,1556726888.615 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2019-05-01T16:08:08.685Z,1556726888.685 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2019-05-01T16:08:08.686Z,1556726888.686 [Default:A.Wait](DEBUG): Construct Wait.
2019-05-01T16:08:08.688Z,1556726888.688 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2019-05-01T16:08:08.727Z,1556726888.727 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2019-05-01T16:08:08.730Z,1556726888.730 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2019-05-01T16:08:08.751Z,1556726888.751 [Default:E.Execute](DEBUG): Construct Execute.
2019-05-01T16:08:08.754Z,1556726888.754 [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>


2019-05-01T16:08:08.771Z,1556726888.771 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,DVL_micro,NAL9602,Onboard,DAT,BPC1,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2019-05-01T16:08:08.781Z,1556726888.781 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2019-05-01T16:08:08.816Z,1556726888.816 [Depth_Keller](ERROR): Pressure reading out of range: 1831.023193 decibar
2019-05-01T16:08:08.832Z,1556726888.832 [DVL_micro](INFO): Initializing
2019-05-01T16:08:08.879Z,1556726888.879 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2
2019-05-01T16:08:08.879Z,1556726888.879 [DAT](INFO): Powering up
2019-05-01T16:08:08.880Z,1556726888.880 [DAT](DEBUG): Initializing DAT.
2019-05-01T16:08:08.885Z,1556726888.885 [Radio_Surface](INFO): Powering up
2019-05-01T16:08:08.926Z,1556726888.926 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2
2019-05-01T16:08:08.969Z,1556726888.969 [DepthRateCalculator](ERROR): Depth measurement is not active
2019-05-01T16:08:09.027Z,1556726889.027 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2019-05-01T16:08:09.041Z,1556726889.041 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2019-05-01T16:08:09.042Z,1556726889.042 [ElevatorServo](DEBUG): Initializing EZServoServo.
2019-05-01T16:08:09.053Z,1556726889.053 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2019-05-01T16:08:09.054Z,1556726889.054 [MassServo](DEBUG): Initializing EZServoServo.
2019-05-01T16:08:09.067Z,1556726889.067 [MassServo](DEBUG): Initializing MassServo.
2019-05-01T16:08:09.068Z,1556726889.068 [RudderServo](DEBUG): Initializing EZServoServo.
2019-05-01T16:08:09.077Z,1556726889.077 [RudderServo](DEBUG): Initializing RudderServo.
2019-05-01T16:08:09.078Z,1556726889.078 [ThrusterServo](DEBUG): Initializing EZServoServo.
2019-05-01T16:08:09.085Z,1556726889.085 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2019-05-01T16:08:09.969Z,1556726889.969 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2019-05-01T16:08:09.969Z,1556726889.969 [RudderServo](FAULT): Rudder failed to initialize
2019-05-01T16:08:09.969Z,1556726889.969 [RudderServo] Communications Fault, FailCount= 1
2019-05-01T16:08:09.969Z,1556726889.969 [RudderServo](ERROR): Communications Fault
2019-05-01T16:08:10.080Z,1556726890.080 [CBIT](ERROR): Communications Fault in component: RudderServo
2019-05-01T16:08:10.246Z,1556726890.246 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-05-01T16:08:10.246Z,1556726890.246 [RudderServo](INFO): Powering down
2019-05-01T16:08:10.942Z,1556726890.942 [RudderServo](DEBUG): Initializing EZServoServo.
2019-05-01T16:08:11.062Z,1556726891.062 [RudderServo](DEBUG): Initializing RudderServo.
2019-05-01T16:08:11.066Z,1556726891.066 [CBIT](INFO): Clearing failed state for component RudderServo
2019-05-01T16:08:11.066Z,1556726891.066 [RudderServo] No Fault, FailCount= 1
2019-05-01T16:08:16.558Z,1556726896.558 [CTD_Seabird](ERROR): Device message queue exceeded the allowed limit.
2019-05-01T16:08:22.256Z,1556726902.256 [DAT](INFO): setting local address to 2
2019-05-01T16:08:22.676Z,1556726902.676 [DAT](INFO): set local address to 2
2019-05-01T16:08:31.983Z,1556726911.983 [SBIT](IMPORTANT): Beginning Startup BIT
2019-05-01T16:08:31.988Z,1556726911.988 [CBIT](IMPORTANT): Beginning ground fault scan
2019-05-01T16:08:35.717Z,1556726915.717 [NAL9602](INFO): Powering up NAL9602
2019-05-01T16:08:43.450Z,1556726923.450 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): -0.003797
CHAN A1 (24V): -0.017502
CHAN A2 (12V): -0.002050
CHAN A3 (5V): -0.001381
CHAN B0 (3.3V): 4.766929
CHAN B1 (3.15aV): 0.000072
CHAN B2 (3.15bV): 0.000024
CHAN B3 (GND): 0.000585
OPEN: -0.000729
Full Scale Calc: 4.765 mA, -1.589 mA
2019-05-01T16:08:46.611Z,1556726926.611 [NAL9602](INFO): NAL9602 initialized
2019-05-01T16:08:47.705Z,1556726927.705 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:09:12.323Z,1556726952.323 [NAL9602](INFO): SBD MO Status=2, MOMSN=11644, MT Status=2, MTMSN=0
2019-05-01T16:09:12.323Z,1556726952.323 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-05-01T16:09:25.400Z,1556726965.400 [SBIT](IMPORTANT): SBIT PASSED
2019-05-01T16:09:25.481Z,1556726965.481 [CommandLine](IMPORTANT): got command configSet list
2019-05-01T16:09:25.481Z,1556726965.481 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2019-05-01T16:09:25.482Z,1556726965.482 [CommandLine](IMPORTANT): Aanderaa_O2.loadAtStartup=0 bool;

2019-05-01T16:09:25.482Z,1556726965.482 [CommandLine](IMPORTANT): CBIT.gf24Offset=172 microampere;

2019-05-01T16:09:25.788Z,1556726965.788 [MissionManager](IMPORTANT): Started mission Startup
2019-05-01T16:09:25.789Z,1556726965.789 [Startup] Running Loop=1
2019-05-01T16:09:25.789Z,1556726965.789 [Startup](DEBUG): Aggregate::initialize Startup
2019-05-01T16:09:25.789Z,1556726965.789 [Startup:A.GoToSurface] Running Loop=1
2019-05-01T16:09:25.789Z,1556726965.789 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-05-01T16:09:25.790Z,1556726965.790 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-05-01T16:09:25.790Z,1556726965.790 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-05-01T16:09:25.791Z,1556726965.791 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-05-01T16:09:25.791Z,1556726965.791 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-05-01T16:09:25.792Z,1556726965.792 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-05-01T16:09:25.794Z,1556726965.794 [Startup:StartupSatComms] Running Loop=1
2019-05-01T16:09:25.794Z,1556726965.794 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2019-05-01T16:09:25.794Z,1556726965.794 [Startup:StartupSatComms:A] Running Loop=1
2019-05-01T16:09:26.211Z,1556726966.211 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2019-05-01T16:09:30.122Z,1556726970.122 [CommandLine](IMPORTANT): got command show best height_above_sea_floor
2019-05-01T16:09:30.122Z,1556726970.122 [CommandLine](IMPORTANT): height_above_sea_floor best is DVL_micro.height_above_sea_floor
2019-05-01T16:09:40.998Z,1556726980.998 [CommandLine](IMPORTANT): got command report touch DVL_micro.height_above_sea_floor
2019-05-01T16:09:41.599Z,1556726981.599 [Reporter](INFO): DVL_micro.height_above_sea_floor 0.200000 m
2019-05-01T16:09:42.373Z,1556726982.373 [Reporter](INFO): DVL_micro.height_above_sea_floor 0.200000 m
2019-05-01T16:09:43.187Z,1556726983.187 [Reporter](INFO): DVL_micro.height_above_sea_floor 0.200000 m
2019-05-01T16:09:44.009Z,1556726984.009 [Reporter](INFO): DVL_micro.height_above_sea_floor 0.200000 m
2019-05-01T16:09:44.826Z,1556726984.826 [Reporter](INFO): DVL_micro.height_above_sea_floor 0.200000 m
2019-05-01T16:09:45.621Z,1556726985.621 [Reporter](INFO): DVL_micro.height_above_sea_floor 0.200000 m
2019-05-01T16:09:46.413Z,1556726986.413 [Reporter](INFO): DVL_micro.height_above_sea_floor 0.200000 m
2019-05-01T16:09:47.229Z,1556726987.229 [Reporter](INFO): DVL_micro.height_above_sea_floor 0.200000 m
2019-05-01T16:09:48.069Z,1556726988.069 [Reporter](INFO): DVL_micro.height_above_sea_floor 0.200000 m
2019-05-01T16:09:48.875Z,1556726988.875 [Reporter](INFO): DVL_micro.height_above_sea_floor 0.200000 m
2019-05-01T16:09:49.641Z,1556726989.641 [Reporter](INFO): DVL_micro.height_above_sea_floor 0.200000 m
2019-05-01T16:09:50.450Z,1556726990.450 [Reporter](INFO): DVL_micro.height_above_sea_floor 0.200000 m
2019-05-01T16:09:51.294Z,1556726991.294 [Reporter](INFO): DVL_micro.height_above_sea_floor 0.200000 m
2019-05-01T16:09:52.122Z,1556726992.122 [Reporter](INFO): DVL_micro.height_above_sea_floor 0.200000 m
2019-05-01T16:09:52.885Z,1556726992.885 [Reporter](INFO): DVL_micro.height_above_sea_floor 0.200000 m
2019-05-01T16:09:53.708Z,1556726993.708 [Reporter](INFO): DVL_micro.height_above_sea_floor 0.200000 m
2019-05-01T16:09:54.061Z,1556726994.061 [NAL9602](IMPORTANT): SBD MO Status=0, MOMSN=11644, MT Status=1, MTMSN=1647
2019-05-01T16:09:54.061Z,1556726994.061 [NAL9602](INFO): Data available in MT queue
2019-05-01T16:09:54.706Z,1556726994.706 [NAL9602](INFO): Received command:load Maintenance/sample.xml;set sample.Depth 0 meter;set sample.WaitBeforeSample 3 second;set sample:SampleAtDepth.TargetDepth 0 meter;run 
2019-05-01T16:09:54.719Z,1556726994.719 [CommandLine](IMPORTANT): got command load ./Missions/Maintenance/sample.xml
2019-05-01T16:09:54.719Z,1556726994.719 [MissionManager](INFO): Loading Mission: ./Missions/Maintenance/sample.xml
2019-05-01T16:09:54.744Z,1556726994.744 [MissionManager](INFO): DefineArg sample.MissionTimeout = 90.000000 min
2019-05-01T16:09:54.747Z,1556726994.747 [MissionManager](INFO): DefineArg sample.Depth = 7.000000 m
2019-05-01T16:09:54.750Z,1556726994.750 [MissionManager](INFO): DefineArg sample.NumberOfSamples = 1.000000 count
2019-05-01T16:09:54.753Z,1556726994.753 [MissionManager](INFO): DefineArg sample.WaitBeforeSample = 3.000000 min
2019-05-01T16:09:54.754Z,1556726994.754 [sample:A.Pitch](DEBUG): Construct.
2019-05-01T16:09:54.760Z,1556726994.760 [sample:B.SetSpeed](DEBUG): Construct.
2019-05-01T16:09:54.762Z,1556726994.762 [MissionManager](INFO): Inserting Stack: Missions/Insert/SampleAtDepth.xml
2019-05-01T16:09:54.904Z,1556726994.904 [MissionManager](INFO): DefineArg sample:SampleAtDepth.TargetDepth = 5.000000 m
2019-05-01T16:09:54.920Z,1556726994.920 [MissionManager](INFO): DefineArg sample:SampleAtDepth.SettleTime = 10.000000 s
2019-05-01T16:09:54.922Z,1556726994.922 [MissionManager](INFO): DefineArg sample:SampleAtDepth.MaxWaitNotReachingDepth = 3.000000 h
2019-05-01T16:09:54.925Z,1556726994.925 [MissionManager](INFO): DefineArg sample:SampleAtDepth.RotateOnly = 0.000000 bool
2019-05-01T16:09:54.937Z,1556726994.937 [MissionManager](INFO): DefineArg sample:SampleAtDepth.UseCANONSampler = 0.000000 bool
2019-05-01T16:09:54.954Z,1556726994.954 [MissionManager](INFO): DefineArg sample:SampleAtDepth.UseESP = 0.000000 bool
2019-05-01T16:09:54.957Z,1556726994.957 [MissionManager](INFO): DefineArg sample:SampleAtDepth.CANONSamplerTriggerTimeout = 1.000000 min
2019-05-01T16:09:54.960Z,1556726994.960 [MissionManager](INFO): DefineArg sample:SampleAtDepth.CANONSamplerTimeout = 6.000000 min
2019-05-01T16:09:54.970Z,1556726994.970 [MissionManager](INFO): DefineArg sample:SampleAtDepth.BuoyancyNeutral = 315.000012 cc
2019-05-01T16:09:54.973Z,1556726994.973 [sample:SampleAtDepth:ApproachDepth:B.Pitch](DEBUG): Construct.
2019-05-01T16:09:55.007Z,1556726995.007 [sample:SampleAtDepth:ApproachDepth:B.Pitch:A_Timeout:B.Execute](DEBUG): Construct Execute.
2019-05-01T16:09:55.010Z,1556726995.010 [sample:SampleAtDepth:SampleWrapper:A.Pitch](DEBUG): Construct.
2019-05-01T16:09:55.037Z,1556726995.037 [sample:SampleAtDepth:SampleWrapper:C.Wait](DEBUG): Construct Wait.
2019-05-01T16:09:55.065Z,1556726995.065 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:TriggerCANONSampler:A_Timeout:B.Execute](DEBUG): Construct Execute.
2019-05-01T16:09:55.085Z,1556726995.085 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:E:A_Timeout:B.Execute](DEBUG): Construct Execute.
2019-05-01T16:09:55.136Z,1556726995.136 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<!-- ====================
     Generated by TethysL
     ==================== -->
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Control="Tethys/Control"
         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/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd"
       Id="sample">

    <Description>
        This mission is designed to be run in the test tank only and samples
        whichever sampler is installed once the vehicle reaches the target
        depth.
    </Description>

    <DefineArg Name="MissionTimeout"><Description>
        How long to let the mission run.
    </Description><Units:minute/><Value>90</Value></DefineArg>

    <DefineArg Name="Depth"><Description>
        Depth to sample at.
    </Description><Units:meter/><Value>7</Value></DefineArg>

    <DefineArg Name="NumberOfSamples"><Description>
        Number of samples to take.
    </Description><Units:count/><Value>1</Value></DefineArg>

    <DefineArg Name="WaitBeforeSample"><Description>
        How long to wait between samples. This starts *before* the first sample
        to exercise the SettleTime setting in the insert aggregate.
    </Description><Units:minute/><Value>3</Value></DefineArg>

    <Timeout Duration="MissionTimeout"/>

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

    <Guidance:SetSpeed>
        <Parallel/>
        <Setting><Guidance:SetSpeed.speed/><Units:meter_per_second/><Value>0</Value></Setting>
    </Guidance:SetSpeed>

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

    <Assign><Sequence/><Arg Name="SampleAtDepth:TargetDepth"/><Arg Name="Depth"/></Assign>

    <Assign><Sequence/><Arg Name="SampleAtDepth:SettleTime"/><Arg Name="WaitBeforeSample"/></Assign>

    <Aggregate Id="SampleRepeater">

        <Sequence Repeat="NumberOfSamples"/>

        <Call Id="Sample" RefId="SampleAtDepth"/>

    </Aggregate>

</Mission>


2019-05-01T16:09:55.141Z,1556726995.141 [CommandLine](IMPORTANT): Loaded ./Missions/Maintenance/sample.xml
2019-05-01T16:09:59.207Z,1556726999.207 [CommandLine](IMPORTANT): got command set sample.Depth 0.000000 meter
2019-05-01T16:09:59.209Z,1556726999.209 [CommandLine](IMPORTANT): got command set sample.WaitBeforeSample 3.000000 second
2019-05-01T16:09:59.210Z,1556726999.210 [CommandLine](IMPORTANT): got command set sample:SampleAtDepth.TargetDepth 0.000000 meter
2019-05-01T16:09:59.210Z,1556726999.210 [CommandLine](IMPORTANT): got command run 
2019-05-01T16:09:59.213Z,1556726999.213 [CommandLine](IMPORTANT): Running 
2019-05-01T16:09:59.256Z,1556726999.256 [Reporter](INFO): DVL_micro.height_above_sea_floor 0.200000 m
2019-05-01T16:09:59.713Z,1556726999.713 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:09:59.765Z,1556726999.765 [Reporter](INFO): DVL_micro.height_above_sea_floor 0.200000 m
2019-05-01T16:10:00.577Z,1556727000.577 [Reporter](INFO): DVL_micro.height_above_sea_floor 0.200000 m
2019-05-01T16:10:01.339Z,1556727001.339 [Reporter](INFO): DVL_micro.height_above_sea_floor 0.200000 m
2019-05-01T16:10:02.141Z,1556727002.141 [Reporter](INFO): DVL_micro.height_above_sea_floor 0.200000 m
2019-05-01T16:10:02.945Z,1556727002.945 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:10:02.993Z,1556727002.993 [Reporter](INFO): DVL_micro.height_above_sea_floor 0.200000 m
2019-05-01T16:10:03.805Z,1556727003.805 [Reporter](INFO): DVL_micro.height_above_sea_floor 0.200000 m
2019-05-01T16:10:04.624Z,1556727004.624 [Reporter](INFO): DVL_micro.height_above_sea_floor 0.200000 m
2019-05-01T16:10:05.372Z,1556727005.372 [Reporter](INFO): DVL_micro.height_above_sea_floor 0.200000 m
2019-05-01T16:10:05.745Z,1556727005.745 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:10:06.284Z,1556727006.284 [Reporter](INFO): DVL_micro.height_above_sea_floor 0.200000 m
2019-05-01T16:10:07.037Z,1556727007.037 [Reporter](INFO): DVL_micro.height_above_sea_floor 0.200000 m
2019-05-01T16:10:07.818Z,1556727007.818 [Reporter](INFO): DVL_micro.height_above_sea_floor 0.200000 m
2019-05-01T16:10:08.585Z,1556727008.585 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:10:08.610Z,1556727008.610 [CommandLine](IMPORTANT): got command stop
2019-05-01T16:10:08.610Z,1556727008.610 [CommandLine](IMPORTANT): Scheduling is paused
2019-05-01T16:10:08.610Z,1556727008.610 [Supervisor](INFO): Stop Mission called by CommandLine::commandStop
2019-05-01T16:10:08.658Z,1556727008.658 [Reporter](INFO): DVL_micro.height_above_sea_floor 0.200000 m
2019-05-01T16:10:09.432Z,1556727009.432 [Reporter](INFO): DVL_micro.height_above_sea_floor 0.200000 m
2019-05-01T16:10:10.253Z,1556727010.253 [Reporter](INFO): DVL_micro.height_above_sea_floor 0.200000 m
2019-05-01T16:10:11.070Z,1556727011.070 [Reporter](INFO): DVL_micro.height_above_sea_floor 0.200000 m
2019-05-01T16:10:11.821Z,1556727011.821 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:10:11.892Z,1556727011.892 [Reporter](INFO): DVL_micro.height_above_sea_floor 0.200000 m
2019-05-01T16:10:12.660Z,1556727012.660 [Reporter](INFO): DVL_micro.height_above_sea_floor 0.200000 m
2019-05-01T16:10:13.469Z,1556727013.469 [Reporter](INFO): DVL_micro.height_above_sea_floor 0.200000 m
2019-05-01T16:10:14.301Z,1556727014.301 [Reporter](INFO): DVL_micro.height_above_sea_floor 0.200000 m
2019-05-01T16:10:14.633Z,1556727014.633 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:10:15.124Z,1556727015.124 [Reporter](INFO): DVL_micro.height_above_sea_floor 0.200000 m
2019-05-01T16:10:15.877Z,1556727015.877 [Reporter](INFO): DVL_micro.height_above_sea_floor 0.200000 m
2019-05-01T16:10:16.696Z,1556727016.696 [Reporter](INFO): DVL_micro.height_above_sea_floor 0.200000 m
2019-05-01T16:10:17.504Z,1556727017.504 [Reporter](INFO): DVL_micro.height_above_sea_floor 0.200000 m
2019-05-01T16:10:17.873Z,1556727017.873 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:10:18.356Z,1556727018.356 [Reporter](INFO): DVL_micro.height_above_sea_floor 0.200000 m
2019-05-01T16:10:19.108Z,1556727019.108 [Reporter](INFO): DVL_micro.height_above_sea_floor 0.200000 m
2019-05-01T16:10:19.918Z,1556727019.918 [Reporter](INFO): DVL_micro.height_above_sea_floor 0.200000 m
2019-05-01T16:10:20.713Z,1556727020.713 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:10:20.858Z,1556727020.858 [Reporter](INFO): DVL_micro.height_above_sea_floor 0.200000 m
2019-05-01T16:10:21.578Z,1556727021.578 [Reporter](INFO): DVL_micro.height_above_sea_floor 0.200000 m
2019-05-01T16:10:22.404Z,1556727022.404 [Reporter](INFO): DVL_micro.height_above_sea_floor 0.200000 m
2019-05-01T16:10:23.160Z,1556727023.160 [Reporter](INFO): DVL_micro.height_above_sea_floor 0.200000 m
2019-05-01T16:10:23.702Z,1556727023.702 [CommandLine](IMPORTANT): got command report clear
2019-05-01T16:10:23.937Z,1556727023.937 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:10:25.963Z,1556727025.963 [Startup:StartupSatComms:A](INFO): Timed out from 2019-05-01T16:09:25.8Z
2019-05-01T16:10:25.963Z,1556727025.963 [Startup:StartupSatComms:A] Stopped
2019-05-01T16:10:25.963Z,1556727025.963 [Startup:StartupSatComms:B] Running Loop=1
2019-05-01T16:10:26.374Z,1556727026.374 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-05-01T16:10:26.757Z,1556727026.757 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:10:28.367Z,1556727028.367 [CommandLine](IMPORTANT): got command show variable DVL_micro
2019-05-01T16:10:28.454Z,1556727028.454 [CommandLine](IMPORTANT): DVL_micro.loadControl (none)
2019-05-01T16:10:28.454Z,1556727028.454 [CommandLine](IMPORTANT): DVL_micro.uart (none)
2019-05-01T16:10:28.455Z,1556727028.455 [CommandLine](IMPORTANT): DVL_micro.baud (bit_per_second)
2019-05-01T16:10:28.466Z,1556727028.466 [CommandLine](IMPORTANT): DVL_micro.loadAtStartup (bool)
2019-05-01T16:10:28.466Z,1556727028.466 [CommandLine](IMPORTANT): DVL_micro.simulateHardware (bool)
2019-05-01T16:10:28.466Z,1556727028.466 [CommandLine](IMPORTANT): DVL_micro.magDeviation (degree)
2019-05-01T16:10:28.467Z,1556727028.467 [CommandLine](IMPORTANT): DVL_micro.pitchOffset (degree)
2019-05-01T16:10:28.467Z,1556727028.467 [CommandLine](IMPORTANT): DVL_micro.power (watt)
2019-05-01T16:10:28.468Z,1556727028.468 [CommandLine](IMPORTANT): DVL_micro.rollOffset (degree)
2019-05-01T16:10:28.551Z,1556727028.551 [CommandLine](IMPORTANT): DVL_micro.height_above_sea_floor (meter)
2019-05-01T16:10:28.551Z,1556727028.551 [CommandLine](IMPORTANT): DVL_micro.platform_orientation (radian)
2019-05-01T16:10:28.552Z,1556727028.552 [CommandLine](IMPORTANT): DVL_micro.platform_magnetic_orientation (radian)
2019-05-01T16:10:28.552Z,1556727028.552 [CommandLine](IMPORTANT): DVL_micro.platform_pitch_angle (radian)
2019-05-01T16:10:28.557Z,1556727028.557 [CommandLine](IMPORTANT): DVL_micro.platform_roll_angle (radian)
2019-05-01T16:10:28.557Z,1556727028.557 [CommandLine](IMPORTANT): DVL_micro.platform_orientation_matrix (none)
2019-05-01T16:10:28.558Z,1556727028.558 [CommandLine](IMPORTANT): DVL_micro.platform_velocity_wrt_ground (meter_per_second)
2019-05-01T16:10:28.558Z,1556727028.558 [CommandLine](IMPORTANT): DVL_micro.platform_x_velocity_wrt_ground (meter_per_second)
2019-05-01T16:10:28.559Z,1556727028.559 [CommandLine](IMPORTANT): DVL_micro.platform_y_velocity_wrt_ground (meter_per_second)
2019-05-01T16:10:28.559Z,1556727028.559 [CommandLine](IMPORTANT): DVL_micro.platform_z_velocity_wrt_ground (meter_per_second)
2019-05-01T16:10:28.559Z,1556727028.559 [CommandLine](IMPORTANT): DVL_micro.platform_velocity_wrt_sea_water (meter_per_second)
2019-05-01T16:10:28.560Z,1556727028.560 [CommandLine](IMPORTANT): DVL_micro.platform_x_velocity_wrt_sea_water (meter_per_second)
2019-05-01T16:10:28.566Z,1556727028.566 [CommandLine](IMPORTANT): DVL_micro.platform_y_velocity_wrt_sea_water (meter_per_second)
2019-05-01T16:10:28.570Z,1556727028.570 [CommandLine](IMPORTANT): DVL_micro.platform_z_velocity_wrt_sea_water (meter_per_second)
2019-05-01T16:10:28.572Z,1556727028.572 [CommandLine](IMPORTANT): DVL_micro.platform_x_velocity_current (meter_per_second)
2019-05-01T16:10:28.574Z,1556727028.574 [CommandLine](IMPORTANT): DVL_micro.platform_y_velocity_current (meter_per_second)
2019-05-01T16:10:28.576Z,1556727028.576 [CommandLine](IMPORTANT): DVL_micro.platform_z_velocity_current (meter_per_second)
2019-05-01T16:10:28.582Z,1556727028.582 [CommandLine](IMPORTANT): DVL_micro.Status (count)
2019-05-01T16:10:28.592Z,1556727028.592 [CommandLine](IMPORTANT): DVL_micro.Beam1Good (count)
2019-05-01T16:10:28.592Z,1556727028.592 [CommandLine](IMPORTANT): DVL_micro.Beam2Good (count)
2019-05-01T16:10:28.597Z,1556727028.597 [CommandLine](IMPORTANT): DVL_micro.Beam3Good (count)
2019-05-01T16:10:28.597Z,1556727028.597 [CommandLine](IMPORTANT): DVL_micro.Beam4Good (count)
2019-05-01T16:10:28.598Z,1556727028.598 [CommandLine](IMPORTANT): DVL_micro.Altitude1 (meter)
2019-05-01T16:10:28.598Z,1556727028.598 [CommandLine](IMPORTANT): DVL_micro.Altitude2 (meter)
2019-05-01T16:10:28.598Z,1556727028.598 [CommandLine](IMPORTANT): DVL_micro.Altitude3 (meter)
2019-05-01T16:10:28.599Z,1556727028.599 [CommandLine](IMPORTANT): DVL_micro.Altitude4 (meter)
2019-05-01T16:10:28.599Z,1556727028.599 [CommandLine](IMPORTANT): DVL_micro.BottomVelocityFlag (count)
2019-05-01T16:10:28.600Z,1556727028.600 [CommandLine](IMPORTANT): DVL_micro.WaterVelocityFlag (meter)
2019-05-01T16:10:28.660Z,1556727028.660 [CommandLine](IMPORTANT): DVL_micro.component_voltage (volt)
2019-05-01T16:10:28.660Z,1556727028.660 [CommandLine](IMPORTANT): DVL_micro.component_avgVoltage (volt)
2019-05-01T16:10:28.671Z,1556727028.671 [CommandLine](IMPORTANT): DVL_micro.component_current (milliampere)
2019-05-01T16:10:28.672Z,1556727028.672 [CommandLine](IMPORTANT): DVL_micro.component_avgCurrent (milliampere)
2019-05-01T16:10:38.041Z,1556727038.041 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:10:41.914Z,1556727041.914 [CommandLine](IMPORTANT): got command get DVL_micro.BottomVelocityFlag
2019-05-01T16:10:41.915Z,1556727041.915 [CommandLine](IMPORTANT): DVL_micro.BottomVelocityFlag 1 count
2019-05-01T16:10:52.108Z,1556727052.108 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.005883
2019-05-01T16:10:53.753Z,1556727053.753 [CommandLine](IMPORTANT): got command get DVL_micro.platform_x_velocity_wrt_ground
2019-05-01T16:10:53.753Z,1556727053.753 [CommandLine](IMPORTANT): DVL_micro.platform_x_velocity_wrt_ground 1.119600 m/s
2019-05-01T16:10:58.825Z,1556727058.825 [DataOverHttps](INFO): Sending 321 bytes from file Logs/20190430T171253/Courier0007.lzma
2019-05-01T16:10:59.630Z,1556727059.630 [DataOverHttps](INFO): Moved sent file to Logs/20190430T171253/Courier0007.lzma.bak
2019-05-01T16:10:59.630Z,1556727059.630 [DataOverHttps](INFO): SBD MOMSN=10888048
2019-05-01T16:11:08.469Z,1556727068.469 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2019-05-01T16:11:08.469Z,1556727068.469 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-05-01T16:11:08.484Z,1556727068.484 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-05-01T16:11:08.902Z,1556727068.902 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-05-01T16:11:08.902Z,1556727068.902 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2019-05-01T16:11:11.276Z,1556727071.276 [NAL9602](INFO): SBD MO Status=2, MOMSN=11645, MT Status=2, MTMSN=0
2019-05-01T16:11:11.276Z,1556727071.276 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-05-01T16:11:11.912Z,1556727071.912 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190501T160445/Courier0004.lzma
2019-05-01T16:11:12.077Z,1556727072.077 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:11:12.718Z,1556727072.718 [DataOverHttps](INFO): Moved sent file to Logs/20190501T160445/Courier0004.lzma.bak
2019-05-01T16:11:12.718Z,1556727072.718 [DataOverHttps](INFO): SBD MOMSN=10888061
2019-05-01T16:11:14.889Z,1556727074.889 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:11:17.753Z,1556727077.753 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:11:20.157Z,1556727080.157 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:11:22.969Z,1556727082.969 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:11:25.708Z,1556727085.708 [DataOverHttps](INFO): Sending 176 bytes from file Logs/20190430T171253/Express0005.lzma
2019-05-01T16:11:25.841Z,1556727085.841 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:11:26.255Z,1556727086.255 [Startup:StartupSatComms:B](INFO): Timed out from 2019-05-01T16:10:25.0Z
2019-05-01T16:11:26.255Z,1556727086.255 [Startup:StartupSatComms:B] Stopped
2019-05-01T16:11:26.256Z,1556727086.256 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2019-05-01T16:11:26.256Z,1556727086.256 [Startup:StartupSatComms] Stopped
2019-05-01T16:11:26.256Z,1556727086.256 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2019-05-01T16:11:26.257Z,1556727086.257 [Startup](INFO): Completed Startup
2019-05-01T16:11:26.257Z,1556727086.257 [MissionManager](INFO): Startup is completed.
2019-05-01T16:11:26.257Z,1556727086.257 [MissionManager](INFO): Uninitializing Mission Startup
2019-05-01T16:11:26.257Z,1556727086.257 [Startup] Stopped
2019-05-01T16:11:26.257Z,1556727086.257 [Startup](DEBUG): Aggregate::uninitialize Startup
2019-05-01T16:11:26.257Z,1556727086.257 [Startup:A.GoToSurface] Stopped
2019-05-01T16:11:26.258Z,1556727086.258 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-05-01T16:11:26.514Z,1556727086.514 [DataOverHttps](INFO): Moved sent file to Logs/20190430T171253/Express0005.lzma.bak
2019-05-01T16:11:26.515Z,1556727086.514 [DataOverHttps](INFO): SBD MOMSN=10888064
2019-05-01T16:11:26.674Z,1556727086.674 [MissionManager](IMPORTANT): Started mission sample
2019-05-01T16:11:26.675Z,1556727086.675 [sample] Running Loop=1
2019-05-01T16:11:26.675Z,1556727086.675 [sample](DEBUG): Aggregate::initialize sample
2019-05-01T16:11:26.675Z,1556727086.675 [sample:A.Pitch] Running Loop=1
2019-05-01T16:11:26.675Z,1556727086.675 [sample:A.Pitch](DEBUG): Initialize.
2019-05-01T16:11:26.675Z,1556727086.675 [sample:B.SetSpeed] Running Loop=1
2019-05-01T16:11:26.675Z,1556727086.675 [sample:B.SetSpeed](DEBUG): Initialize.
2019-05-01T16:11:26.676Z,1556727086.676 [sample:D] Running Loop=1
2019-05-01T16:11:26.676Z,1556727086.676 [sample:D] Stopped
2019-05-01T16:11:26.676Z,1556727086.676 [sample:E] Running Loop=1
2019-05-01T16:11:26.676Z,1556727086.676 [sample:B.SetSpeed] Running Loop=1
2019-05-01T16:11:26.676Z,1556727086.676 [sample:A.Pitch] Running Loop=1
2019-05-01T16:11:26.682Z,1556727086.682 [MissionManager](INFO): MissionManager is completed.
2019-05-01T16:11:26.682Z,1556727086.682 [MissionManager](INFO): Uninitializing Mission sample
2019-05-01T16:11:26.682Z,1556727086.682 [sample] Stopped
2019-05-01T16:11:26.682Z,1556727086.682 [sample](DEBUG): Aggregate::uninitialize sample
2019-05-01T16:11:26.683Z,1556727086.683 [sample:A.Pitch] Stopped
2019-05-01T16:11:26.683Z,1556727086.683 [sample:B.SetSpeed] Stopped
2019-05-01T16:11:26.683Z,1556727086.683 [sample:B.SetSpeed](DEBUG): Uninitialize.
2019-05-01T16:11:26.683Z,1556727086.683 [sample:E] Stopped
2019-05-01T16:11:27.037Z,1556727087.037 [MissionManager](IMPORTANT): Started mission Default
2019-05-01T16:11:27.037Z,1556727087.037 [Default] Running Loop=1
2019-05-01T16:11:27.038Z,1556727087.038 [Default](DEBUG): Aggregate::initialize Default
2019-05-01T16:11:27.038Z,1556727087.038 [Default:B.GoToSurface] Running Loop=1
2019-05-01T16:11:27.038Z,1556727087.038 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-05-01T16:11:27.038Z,1556727087.038 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-05-01T16:11:27.038Z,1556727087.038 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-05-01T16:11:27.039Z,1556727087.039 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-05-01T16:11:27.039Z,1556727087.039 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-05-01T16:11:27.039Z,1556727087.039 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-05-01T16:11:27.040Z,1556727087.040 [Default:A.Wait] Running Loop=1
2019-05-01T16:11:27.040Z,1556727087.040 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-05-01T16:11:29.041Z,1556727089.041 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:11:31.865Z,1556727091.865 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:11:34.697Z,1556727094.697 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:11:37.937Z,1556727097.937 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:11:40.407Z,1556727100.407 [Default:A.Wait](INFO): Done Waiting.
2019-05-01T16:11:40.407Z,1556727100.407 [Default:A.Wait] Stopped
2019-05-01T16:11:40.408Z,1556727100.408 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-05-01T16:11:40.745Z,1556727100.745 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:11:40.785Z,1556727100.785 [Default:CheckIn] Running Loop=1
2019-05-01T16:11:40.785Z,1556727100.785 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-05-01T16:11:40.785Z,1556727100.785 [Default:CheckIn:Read_GPS] Running Loop=1
2019-05-01T16:11:41.211Z,1556727101.211 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2019-05-01T16:11:43.977Z,1556727103.977 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:11:46.837Z,1556727106.837 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:11:50.041Z,1556727110.041 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:11:52.869Z,1556727112.869 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:11:56.101Z,1556727116.101 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:11:58.914Z,1556727118.914 [DVL_micro](ERROR): No DVL communication! Re-initializing
2019-05-01T16:11:58.914Z,1556727118.914 [DVL_micro] Communications Fault, FailCount= 1
2019-05-01T16:11:58.914Z,1556727118.914 [DVL_micro](ERROR): Communications Fault
2019-05-01T16:11:58.929Z,1556727118.929 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:11:58.979Z,1556727118.979 [CBIT](ERROR): Communications Fault in component: DVL_micro
2019-05-01T16:11:59.315Z,1556727119.315 [DVL_micro](INFO): uninitialize:Powering down
2019-05-01T16:12:00.191Z,1556727120.191 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-05-01T16:12:00.191Z,1556727120.191 [DVL_micro] No Fault, FailCount= 1
2019-05-01T16:12:00.532Z,1556727120.532 [DVL_micro](INFO): Initializing
2019-05-01T16:12:02.169Z,1556727122.169 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:12:04.989Z,1556727124.989 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:12:08.217Z,1556727128.217 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:12:11.085Z,1556727131.085 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:12:14.293Z,1556727134.293 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:12:17.121Z,1556727137.121 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:12:19.949Z,1556727139.949 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:12:23.181Z,1556727143.181 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:12:25.993Z,1556727145.993 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:12:29.237Z,1556727149.237 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:12:32.065Z,1556727152.065 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:12:35.305Z,1556727155.305 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:12:38.113Z,1556727158.113 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:12:40.813Z,1556727160.813 [CommandLine](IMPORTANT): got command failComponent
2019-05-01T16:12:40.814Z,1556727160.814 [CommandLine](IMPORTANT): Failed components:
2019-05-01T16:12:40.814Z,1556727160.814 [CommandLine](IMPORTANT): No failed Components.
2019-05-01T16:12:40.953Z,1556727160.953 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:12:44.193Z,1556727164.193 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:12:47.003Z,1556727167.003 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:12:49.182Z,1556727169.182 [CommandLine](IMPORTANT): got command show best height_above_sea_floor
2019-05-01T16:12:49.182Z,1556727169.182 [CommandLine](IMPORTANT): height_above_sea_floor best is DVL_micro.height_above_sea_floor
2019-05-01T16:12:50.233Z,1556727170.233 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:12:53.073Z,1556727173.073 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:12:56.313Z,1556727176.313 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:12:57.480Z,1556727177.480 [CommandLine](IMPORTANT): got command report touch DVL_micro.height_above_sea_floor
2019-05-01T16:12:58.029Z,1556727178.029 [Reporter](INFO): DVL_micro.height_above_sea_floor 0.200000 m
2019-05-01T16:12:58.805Z,1556727178.805 [Reporter](INFO): DVL_micro.height_above_sea_floor 0.200000 m
2019-05-01T16:12:59.121Z,1556727179.121 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:12:59.620Z,1556727179.620 [Reporter](INFO): DVL_micro.height_above_sea_floor 0.200000 m
2019-05-01T16:13:00.435Z,1556727180.435 [Reporter](INFO): DVL_micro.height_above_sea_floor 0.200000 m
2019-05-01T16:13:00.681Z,1556727180.681 [CommandLine](IMPORTANT): got command report clear
2019-05-01T16:13:01.981Z,1556727181.981 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:13:05.174Z,1556727185.174 [DVL_micro](ERROR): checksum mismatch: reported95 , calculated:91
2019-05-01T16:13:05.175Z,1556727185.175 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 1 1 1 1 0.2 9.9 -195.8 -1104.3 565.8 -93.3 0 0 0 -126 0 0 0 1 -1016.5 -1349.3 -223.2 1 -1483.3 789.1 -284.4 1 0 0 0 0 0 0 0 0 0.56 -2.73 278.7 0.2 18.3 0.005 35.0 1489 95
2019-05-01T16:13:05.189Z,1556727185.189 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:13:08.013Z,1556727188.013 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:13:11.245Z,1556727191.245 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:13:14.069Z,1556727194.069 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:13:15.670Z,1556727195.670 [DVL_micro](ERROR): No DVL communication! Re-initializing
2019-05-01T16:13:15.670Z,1556727195.670 [DVL_micro] Communications Fault, FailCount= 1
2019-05-01T16:13:15.670Z,1556727195.670 [DVL_micro](ERROR): Communications Fault
2019-05-01T16:13:15.743Z,1556727195.743 [CBIT](ERROR): Communications Fault in component: DVL_micro
2019-05-01T16:13:16.141Z,1556727196.141 [DVL_micro](INFO): uninitialize:Powering down
2019-05-01T16:13:16.920Z,1556727196.920 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-05-01T16:13:16.920Z,1556727196.920 [DVL_micro] No Fault, FailCount= 1
2019-05-01T16:13:17.292Z,1556727197.292 [DVL_micro](INFO): Initializing
2019-05-01T16:13:17.305Z,1556727197.305 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:13:20.133Z,1556727200.133 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:13:23.369Z,1556727203.369 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:13:26.205Z,1556727206.205 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:13:29.024Z,1556727209.024 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:13:32.249Z,1556727212.249 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:13:35.089Z,1556727215.089 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:13:38.321Z,1556727218.321 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:13:41.138Z,1556727221.138 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:13:44.373Z,1556727224.373 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:13:47.213Z,1556727227.213 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:13:50.449Z,1556727230.449 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:13:53.261Z,1556727233.261 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:13:56.117Z,1556727236.117 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:13:59.361Z,1556727239.361 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:14:02.149Z,1556727242.149 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:14:05.393Z,1556727245.393 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:14:08.217Z,1556727248.217 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:14:09.446Z,1556727249.446 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2019-05-01T16:14:09.446Z,1556727249.446 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-05-01T16:14:09.456Z,1556727249.456 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-05-01T16:14:09.891Z,1556727249.891 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-05-01T16:14:09.891Z,1556727249.891 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2019-05-01T16:14:11.449Z,1556727251.449 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:14:14.273Z,1556727254.273 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:14:17.109Z,1556727257.109 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:14:20.337Z,1556727260.337 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:14:23.153Z,1556727263.153 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:14:26.385Z,1556727266.385 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:14:29.249Z,1556727269.249 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:14:32.473Z,1556727272.473 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:14:35.273Z,1556727275.273 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:14:38.513Z,1556727278.513 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:14:41.345Z,1556727281.345 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:14:44.165Z,1556727284.165 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:14:47.393Z,1556727287.393 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:14:50.237Z,1556727290.237 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:14:53.465Z,1556727293.465 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:14:56.289Z,1556727296.289 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:14:59.525Z,1556727299.525 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:15:02.353Z,1556727302.353 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:15:05.573Z,1556727305.573 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:15:06.758Z,1556727306.758 [CommandLine](IMPORTANT): got command failComponent
2019-05-01T16:15:06.759Z,1556727306.759 [CommandLine](IMPORTANT): Failed components:
2019-05-01T16:15:06.759Z,1556727306.759 [CommandLine](IMPORTANT): No failed Components.
2019-05-01T16:15:07.192Z,1556727307.192 [DVL_micro](ERROR): No DVL communication! Re-initializing
2019-05-01T16:15:07.193Z,1556727307.193 [DVL_micro] Communications Fault, FailCount= 1
2019-05-01T16:15:07.193Z,1556727307.193 [DVL_micro](ERROR): Communications Fault
2019-05-01T16:15:07.254Z,1556727307.254 [CBIT](ERROR): Communications Fault in component: DVL_micro
2019-05-01T16:15:07.649Z,1556727307.649 [DVL_micro](INFO): uninitialize:Powering down
2019-05-01T16:15:08.405Z,1556727308.405 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:15:08.440Z,1556727308.440 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-05-01T16:15:08.440Z,1556727308.440 [DVL_micro] No Fault, FailCount= 1
2019-05-01T16:15:08.804Z,1556727308.804 [DVL_micro](INFO): Initializing
2019-05-01T16:15:11.245Z,1556727311.245 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:15:14.473Z,1556727314.473 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:15:17.289Z,1556727317.289 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:15:17.698Z,1556727317.698 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160003.00,A,3648.16669,N,12147.28452,W,0.641,0.00,010519,,,A*78
2019-05-01T16:15:17.709Z,1556727317.709 [NAL9602](INFO): GPS fix at 20190501T160003: (36.802778, -121.788075)
2019-05-01T16:15:17.784Z,1556727317.784 [Default:CheckIn:Read_GPS] Stopped
2019-05-01T16:15:17.793Z,1556727317.793 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-05-01T16:15:18.180Z,1556727318.180 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-05-01T16:15:21.961Z,1556727321.961 [CommandLine](IMPORTANT): got command get DVL_micro.platform_x_velocity_wrt_ground
2019-05-01T16:15:21.962Z,1556727321.962 [CommandLine](IMPORTANT): DVL_micro.platform_x_velocity_wrt_ground 0.632200 m/s
2019-05-01T16:15:28.501Z,1556727328.501 [DataOverHttps](INFO): Sending 212 bytes from file Logs/20190501T160758/Courier0004.lzma
2019-05-01T16:15:29.311Z,1556727329.311 [DataOverHttps](INFO): Moved sent file to Logs/20190501T160758/Courier0004.lzma.bak
2019-05-01T16:15:29.312Z,1556727329.312 [DataOverHttps](INFO): SBD MOMSN=10888149
2019-05-01T16:15:30.551Z,1556727330.551 [CommandLine](IMPORTANT): got command show variable DVL_micro
2019-05-01T16:15:30.640Z,1556727330.640 [CommandLine](IMPORTANT): DVL_micro.loadControl (none)
2019-05-01T16:15:30.640Z,1556727330.640 [CommandLine](IMPORTANT): DVL_micro.uart (none)
2019-05-01T16:15:30.641Z,1556727330.641 [CommandLine](IMPORTANT): DVL_micro.baud (bit_per_second)
2019-05-01T16:15:30.669Z,1556727330.669 [CommandLine](IMPORTANT): DVL_micro.loadAtStartup (bool)
2019-05-01T16:15:30.670Z,1556727330.670 [CommandLine](IMPORTANT): DVL_micro.simulateHardware (bool)
2019-05-01T16:15:30.670Z,1556727330.670 [CommandLine](IMPORTANT): DVL_micro.magDeviation (degree)
2019-05-01T16:15:30.671Z,1556727330.671 [CommandLine](IMPORTANT): DVL_micro.pitchOffset (degree)
2019-05-01T16:15:30.671Z,1556727330.671 [CommandLine](IMPORTANT): DVL_micro.power (watt)
2019-05-01T16:15:30.671Z,1556727330.671 [CommandLine](IMPORTANT): DVL_micro.rollOffset (degree)
2019-05-01T16:15:30.824Z,1556727330.824 [CommandLine](IMPORTANT): DVL_micro.height_above_sea_floor (meter)
2019-05-01T16:15:30.824Z,1556727330.824 [CommandLine](IMPORTANT): DVL_micro.platform_orientation (radian)
2019-05-01T16:15:30.833Z,1556727330.833 [CommandLine](IMPORTANT): DVL_micro.platform_magnetic_orientation (radian)
2019-05-01T16:15:30.834Z,1556727330.834 [CommandLine](IMPORTANT): DVL_micro.platform_pitch_angle (radian)
2019-05-01T16:15:30.834Z,1556727330.834 [CommandLine](IMPORTANT): DVL_micro.platform_roll_angle (radian)
2019-05-01T16:15:30.834Z,1556727330.834 [CommandLine](IMPORTANT): DVL_micro.platform_orientation_matrix (none)
2019-05-01T16:15:30.835Z,1556727330.835 [CommandLine](IMPORTANT): DVL_micro.platform_velocity_wrt_ground (meter_per_second)
2019-05-01T16:15:30.835Z,1556727330.835 [CommandLine](IMPORTANT): DVL_micro.platform_x_velocity_wrt_ground (meter_per_second)
2019-05-01T16:15:30.836Z,1556727330.836 [CommandLine](IMPORTANT): DVL_micro.platform_y_velocity_wrt_ground (meter_per_second)
2019-05-01T16:15:30.836Z,1556727330.836 [CommandLine](IMPORTANT): DVL_micro.platform_z_velocity_wrt_ground (meter_per_second)
2019-05-01T16:15:30.836Z,1556727330.836 [CommandLine](IMPORTANT): DVL_micro.platform_velocity_wrt_sea_water (meter_per_second)
2019-05-01T16:15:30.849Z,1556727330.849 [CommandLine](IMPORTANT): DVL_micro.platform_x_velocity_wrt_sea_water (meter_per_second)
2019-05-01T16:15:30.849Z,1556727330.849 [CommandLine](IMPORTANT): DVL_micro.platform_y_velocity_wrt_sea_water (meter_per_second)
2019-05-01T16:15:30.850Z,1556727330.850 [CommandLine](IMPORTANT): DVL_micro.platform_z_velocity_wrt_sea_water (meter_per_second)
2019-05-01T16:15:30.850Z,1556727330.850 [CommandLine](IMPORTANT): DVL_micro.platform_x_velocity_current (meter_per_second)
2019-05-01T16:15:30.851Z,1556727330.851 [CommandLine](IMPORTANT): DVL_micro.platform_y_velocity_current (meter_per_second)
2019-05-01T16:15:30.851Z,1556727330.851 [CommandLine](IMPORTANT): DVL_micro.platform_z_velocity_current (meter_per_second)
2019-05-01T16:15:30.851Z,1556727330.851 [CommandLine](IMPORTANT): DVL_micro.Status (count)
2019-05-01T16:15:30.852Z,1556727330.852 [CommandLine](IMPORTANT): DVL_micro.Beam1Good (count)
2019-05-01T16:15:30.852Z,1556727330.852 [CommandLine](IMPORTANT): DVL_micro.Beam2Good (count)
2019-05-01T16:15:30.861Z,1556727330.861 [CommandLine](IMPORTANT): DVL_micro.Beam3Good (count)
2019-05-01T16:15:30.861Z,1556727330.861 [CommandLine](IMPORTANT): DVL_micro.Beam4Good (count)
2019-05-01T16:15:30.862Z,1556727330.862 [CommandLine](IMPORTANT): DVL_micro.Altitude1 (meter)
2019-05-01T16:15:30.862Z,1556727330.862 [CommandLine](IMPORTANT): DVL_micro.Altitude2 (meter)
2019-05-01T16:15:30.862Z,1556727330.862 [CommandLine](IMPORTANT): DVL_micro.Altitude3 (meter)
2019-05-01T16:15:30.863Z,1556727330.863 [CommandLine](IMPORTANT): DVL_micro.Altitude4 (meter)
2019-05-01T16:15:30.863Z,1556727330.863 [CommandLine](IMPORTANT): DVL_micro.BottomVelocityFlag (count)
2019-05-01T16:15:30.877Z,1556727330.877 [CommandLine](IMPORTANT): DVL_micro.WaterVelocityFlag (meter)
2019-05-01T16:15:30.954Z,1556727330.954 [CommandLine](IMPORTANT): DVL_micro.component_voltage (volt)
2019-05-01T16:15:30.954Z,1556727330.954 [CommandLine](IMPORTANT): DVL_micro.component_avgVoltage (volt)
2019-05-01T16:15:30.955Z,1556727330.955 [CommandLine](IMPORTANT): DVL_micro.component_current (milliampere)
2019-05-01T16:15:30.955Z,1556727330.955 [CommandLine](IMPORTANT): DVL_micro.component_avgCurrent (milliampere)
2019-05-01T16:15:45.144Z,1556727345.144 [CommandLine](IMPORTANT): got command get DVL_micro.height_above_sea_floor
2019-05-01T16:15:45.149Z,1556727345.149 [CommandLine](IMPORTANT): DVL_micro.height_above_sea_floor 0.200000 m
2019-05-01T16:15:46.491Z,1556727346.491 [DataOverHttps](INFO): Sending 911 bytes from file Logs/20190430T171253/Express0008.lzma
2019-05-01T16:15:47.290Z,1556727347.290 [DataOverHttps](INFO): Moved sent file to Logs/20190430T171253/Express0008.lzma.bak
2019-05-01T16:15:47.290Z,1556727347.290 [DataOverHttps](INFO): SBD MOMSN=10888153
2019-05-01T16:15:50.529Z,1556727350.529 [NAL9602](INFO): Powering down
2019-05-01T16:15:51.302Z,1556727351.302 [DVL_micro](ERROR): only read 45 of 46 data items
2019-05-01T16:15:51.302Z,1556727351.302 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 1 1 1 1 0.2 9.9 0.2 9.9 -107.5 381.1 428.8 29.7 0 -492 0 -437 0 1 0 1 -715.8 469.0 197.4 1 349.8 788.1 1 -73 0 0 0 0 0 0 0.48 -2.74 278.9 0.2 18.3 0.005 35.0 1489 106
2019-05-01T16:16:03.078Z,1556727363.078 [CommandLine](IMPORTANT): got command get DVL_micro.platform_pitch_angle degree
2019-05-01T16:16:03.078Z,1556727363.078 [CommandLine](IMPORTANT): DVL_micro.platform_pitch_angle -2.790000 arcdeg
2019-05-01T16:16:03.233Z,1556727363.233 [DataOverHttps](INFO): Sending 1089 bytes from file Logs/20190501T160445/Express0001.lzma
2019-05-01T16:16:04.026Z,1556727364.026 [DataOverHttps](INFO): Moved sent file to Logs/20190501T160445/Express0001.lzma.bak
2019-05-01T16:16:04.026Z,1556727364.026 [DataOverHttps](INFO): SBD MOMSN=10888242
2019-05-01T16:16:17.872Z,1556727377.872 [DataOverHttps](INFO): Sending 157 bytes from file Logs/20190501T160445/Express0005.lzma
2019-05-01T16:16:18.678Z,1556727378.678 [DataOverHttps](INFO): Moved sent file to Logs/20190501T160445/Express0005.lzma.bak
2019-05-01T16:16:18.678Z,1556727378.678 [DataOverHttps](INFO): SBD MOMSN=10888271
2019-05-01T16:16:26.799Z,1556727386.799 [CommandLine](IMPORTANT): got command get DVL_micro.Altitude1
2019-05-01T16:16:26.799Z,1556727386.799 [CommandLine](IMPORTANT): DVL_micro.Altitude1 0.200000 m
2019-05-01T16:16:31.421Z,1556727391.421 [CommandLine](IMPORTANT): got command get DVL_micro.Altitude2
2019-05-01T16:16:31.422Z,1556727391.422 [CommandLine](IMPORTANT): DVL_micro.Altitude2 9.900000 m
2019-05-01T16:16:32.814Z,1556727392.814 [DataOverHttps](INFO): Sending 982 bytes from file Logs/20190501T160758/Express0001.lzma
2019-05-01T16:16:33.618Z,1556727393.618 [DataOverHttps](INFO): Moved sent file to Logs/20190501T160758/Express0001.lzma.bak
2019-05-01T16:16:33.618Z,1556727393.618 [DataOverHttps](INFO): SBD MOMSN=10888276
2019-05-01T16:16:38.198Z,1556727398.198 [CommandLine](IMPORTANT): got command get DVL_micro.Altitude3
2019-05-01T16:16:38.198Z,1556727398.198 [CommandLine](IMPORTANT): DVL_micro.Altitude3 0.200000 m
2019-05-01T16:16:43.594Z,1556727403.594 [CommandLine](IMPORTANT): got command get DVL_micro.Altitude4
2019-05-01T16:16:43.594Z,1556727403.594 [CommandLine](IMPORTANT): DVL_micro.Altitude4 9.900000 m
2019-05-01T16:16:49.594Z,1556727409.594 [DataOverHttps](INFO): Sending 894 bytes from file Logs/20190501T160758/Express0005.lzma
2019-05-01T16:16:50.398Z,1556727410.398 [DataOverHttps](INFO): Moved sent file to Logs/20190501T160758/Express0005.lzma.bak
2019-05-01T16:16:50.398Z,1556727410.398 [DataOverHttps](INFO): SBD MOMSN=10888306
2019-05-01T16:16:52.789Z,1556727412.789 [Default:CheckIn:Read_Iridium] Stopped
2019-05-01T16:16:52.789Z,1556727412.789 [Default:CheckIn:C.Wait] Running Loop=1
2019-05-01T16:16:52.790Z,1556727412.790 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-05-01T16:16:59.506Z,1556727419.506 [CommandLine](IMPORTANT): got command report touch height_above_sea_floor
2019-05-01T16:17:00.267Z,1556727420.267 [Reporter](INFO): height_above_sea_floor 0.200000 m
2019-05-01T16:17:00.883Z,1556727420.883 [Reporter](INFO): height_above_sea_floor 0.200000 m
2019-05-01T16:17:01.652Z,1556727421.652 [Reporter](INFO): height_above_sea_floor 0.200000 m
2019-05-01T16:17:02.507Z,1556727422.507 [Reporter](INFO): height_above_sea_floor 0.200000 m
2019-05-01T16:17:03.339Z,1556727423.339 [Reporter](INFO): height_above_sea_floor 0.200000 m
2019-05-01T16:17:03.809Z,1556727423.809 [CommandLine](IMPORTANT): got command report clear
2019-05-01T16:18:09.158Z,1556727489.158 [CommandLine](IMPORTANT): got command show variable dvl_micro
2019-05-01T16:18:09.192Z,1556727489.192 [CommandLine](IMPORTANT): DVL_micro.loadControl (none)
2019-05-01T16:18:09.192Z,1556727489.192 [CommandLine](IMPORTANT): DVL_micro.uart (none)
2019-05-01T16:18:09.193Z,1556727489.193 [CommandLine](IMPORTANT): DVL_micro.baud (bit_per_second)
2019-05-01T16:18:09.204Z,1556727489.204 [CommandLine](IMPORTANT): DVL_micro.loadAtStartup (bool)
2019-05-01T16:18:09.205Z,1556727489.205 [CommandLine](IMPORTANT): DVL_micro.simulateHardware (bool)
2019-05-01T16:18:09.206Z,1556727489.206 [CommandLine](IMPORTANT): DVL_micro.magDeviation (degree)
2019-05-01T16:18:09.206Z,1556727489.206 [CommandLine](IMPORTANT): DVL_micro.pitchOffset (degree)
2019-05-01T16:18:09.206Z,1556727489.206 [CommandLine](IMPORTANT): DVL_micro.power (watt)
2019-05-01T16:18:09.207Z,1556727489.207 [CommandLine](IMPORTANT): DVL_micro.rollOffset (degree)
2019-05-01T16:18:09.344Z,1556727489.344 [CommandLine](IMPORTANT): DVL_micro.height_above_sea_floor (meter)
2019-05-01T16:18:09.345Z,1556727489.345 [CommandLine](IMPORTANT): DVL_micro.platform_orientation (radian)
2019-05-01T16:18:09.346Z,1556727489.346 [CommandLine](IMPORTANT): DVL_micro.platform_magnetic_orientation (radian)
2019-05-01T16:18:09.346Z,1556727489.346 [CommandLine](IMPORTANT): DVL_micro.platform_pitch_angle (radian)
2019-05-01T16:18:09.346Z,1556727489.346 [CommandLine](IMPORTANT): DVL_micro.platform_roll_angle (radian)
2019-05-01T16:18:09.347Z,1556727489.347 [CommandLine](IMPORTANT): DVL_micro.platform_orientation_matrix (none)
2019-05-01T16:18:09.347Z,1556727489.347 [CommandLine](IMPORTANT): DVL_micro.platform_velocity_wrt_ground (meter_per_second)
2019-05-01T16:18:09.348Z,1556727489.348 [CommandLine](IMPORTANT): DVL_micro.platform_x_velocity_wrt_ground (meter_per_second)
2019-05-01T16:18:09.348Z,1556727489.348 [CommandLine](IMPORTANT): DVL_micro.platform_y_velocity_wrt_ground (meter_per_second)
2019-05-01T16:18:09.349Z,1556727489.349 [CommandLine](IMPORTANT): DVL_micro.platform_z_velocity_wrt_ground (meter_per_second)
2019-05-01T16:18:09.350Z,1556727489.350 [CommandLine](IMPORTANT): DVL_micro.platform_velocity_wrt_sea_water (meter_per_second)
2019-05-01T16:18:09.350Z,1556727489.350 [CommandLine](IMPORTANT): DVL_micro.platform_x_velocity_wrt_sea_water (meter_per_second)
2019-05-01T16:18:09.351Z,1556727489.351 [CommandLine](IMPORTANT): DVL_micro.platform_y_velocity_wrt_sea_water (meter_per_second)
2019-05-01T16:18:09.351Z,1556727489.351 [CommandLine](IMPORTANT): DVL_micro.platform_z_velocity_wrt_sea_water (meter_per_second)
2019-05-01T16:18:09.352Z,1556727489.352 [CommandLine](IMPORTANT): DVL_micro.platform_x_velocity_current (meter_per_second)
2019-05-01T16:18:09.352Z,1556727489.352 [CommandLine](IMPORTANT): DVL_micro.platform_y_velocity_current (meter_per_second)
2019-05-01T16:18:09.353Z,1556727489.353 [CommandLine](IMPORTANT): DVL_micro.platform_z_velocity_current (meter_per_second)
2019-05-01T16:18:09.353Z,1556727489.353 [CommandLine](IMPORTANT): DVL_micro.Status (count)
2019-05-01T16:18:09.354Z,1556727489.354 [CommandLine](IMPORTANT): DVL_micro.Beam1Good (count)
2019-05-01T16:18:09.354Z,1556727489.354 [CommandLine](IMPORTANT): DVL_micro.Beam2Good (count)
2019-05-01T16:18:09.355Z,1556727489.355 [CommandLine](IMPORTANT): DVL_micro.Beam3Good (count)
2019-05-01T16:18:09.355Z,1556727489.355 [CommandLine](IMPORTANT): DVL_micro.Beam4Good (count)
2019-05-01T16:18:09.355Z,1556727489.355 [CommandLine](IMPORTANT): DVL_micro.Altitude1 (meter)
2019-05-01T16:18:09.356Z,1556727489.356 [CommandLine](IMPORTANT): DVL_micro.Altitude2 (meter)
2019-05-01T16:18:09.357Z,1556727489.357 [CommandLine](IMPORTANT): DVL_micro.Altitude3 (meter)
2019-05-01T16:18:09.358Z,1556727489.358 [CommandLine](IMPORTANT): DVL_micro.Altitude4 (meter)
2019-05-01T16:18:09.358Z,1556727489.358 [CommandLine](IMPORTANT): DVL_micro.BottomVelocityFlag (count)
2019-05-01T16:18:09.359Z,1556727489.359 [CommandLine](IMPORTANT): DVL_micro.WaterVelocityFlag (meter)
2019-05-01T16:18:09.381Z,1556727489.381 [CommandLine](IMPORTANT): DVL_micro.component_voltage (volt)
2019-05-01T16:18:09.382Z,1556727489.382 [CommandLine](IMPORTANT): DVL_micro.component_avgVoltage (volt)
2019-05-01T16:18:09.382Z,1556727489.382 [CommandLine](IMPORTANT): DVL_micro.component_current (milliampere)
2019-05-01T16:18:09.383Z,1556727489.383 [CommandLine](IMPORTANT): DVL_micro.component_avgCurrent (milliampere)
2019-05-01T16:18:16.383Z,1556727496.383 [CommandLine](IMPORTANT): got command get DVL_micro.Beam1Good
2019-05-01T16:18:16.383Z,1556727496.383 [CommandLine](IMPORTANT): DVL_micro.Beam1Good 1 count
2019-05-01T16:18:21.466Z,1556727501.466 [CommandLine](IMPORTANT): got command get DVL_micro.Beam2Good
2019-05-01T16:18:21.467Z,1556727501.467 [CommandLine](IMPORTANT): DVL_micro.Beam2Good 1 count
2019-05-01T16:18:26.276Z,1556727506.276 [CommandLine](IMPORTANT): got command get DVL_micro.Beam3Good
2019-05-01T16:18:26.277Z,1556727506.277 [CommandLine](IMPORTANT): DVL_micro.Beam3Good 1 count
2019-05-01T16:18:35.723Z,1556727515.723 [CommandLine](IMPORTANT): got command report mod height_above_sea_floor
2019-05-01T16:18:35.943Z,1556727515.943 [Reporter](INFO): height_above_sea_floor 0.200000 m
2019-05-01T16:19:21.398Z,1556727561.398 [DVL_micro](ERROR): only read 45 of 46 data items
2019-05-01T16:19:21.398Z,1556727561.398 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 1 1 1 1 0.2 9.9 0.2 9.9 -185.4 321.1 429.1 -73.2 0 -252 0 353 0 1 0 1 -820.1 526.2 132.5 1 389.8 897.7 97.0 1 0 -807 0 0 0 0 0 2.76 279.0 0.2 18.3 0.005 35.0 1489 97
2019-05-01T16:20:31.687Z,1556727631.687 [DVL_micro](ERROR): only read 44 of 46 data items
2019-05-01T16:20:31.687Z,1556727631.687 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 1 1 1 1 0.2 9.9 0.2 9.9 -166.9 -17.8 416.0 108.9 0 -521 0 135 0 1 0 1 -778.0 -169.1 91.7 1 -289.9 745.3 53.2 1 0 -875 0 0 0 0 0 0 0.51 -2.72 279.0 0.2005 35.0 1489 91
2019-05-01T16:21:53.340Z,1556727713.340 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-05-01T16:21:53.340Z,1556727713.340 [Default:CheckIn:C.Wait] Stopped
2019-05-01T16:21:53.345Z,1556727713.345 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-05-01T16:21:53.345Z,1556727713.345 [Default:CheckIn:D] Running Loop=1
2019-05-01T16:21:53.713Z,1556727713.713 [Default:CheckIn:D] Stopped
2019-05-01T16:21:53.713Z,1556727713.713 [Default:CheckIn:E] Running Loop=1
2019-05-01T16:21:54.130Z,1556727714.130 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.444584 min 
2019-05-01T16:21:54.131Z,1556727714.131 [Default:CheckIn:E] Stopped
2019-05-01T16:21:54.131Z,1556727714.131 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-05-01T16:21:54.131Z,1556727714.131 [Default:CheckIn] Stopped
2019-05-01T16:21:54.131Z,1556727714.131 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-05-01T16:21:54.131Z,1556727714.131 [Default:CheckIn](INFO): Running loop #2
2019-05-01T16:21:54.131Z,1556727714.131 [Default:CheckIn] Running Loop=2
2019-05-01T16:21:54.131Z,1556727714.131 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-05-01T16:21:54.131Z,1556727714.131 [Default:CheckIn:Read_GPS] Running Loop=1
2019-05-01T16:21:54.917Z,1556727714.917 [NAL9602](INFO): Powering up
2019-05-01T16:22:05.804Z,1556727725.804 [NAL9602](INFO): NAL9602 initialized
2019-05-01T16:22:06.625Z,1556727726.625 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:22:45.398Z,1556727765.398 [NAL9602](IMPORTANT): SBD MO Status=0, MOMSN=11645, MT Status=1, MTMSN=1648
2019-05-01T16:22:45.398Z,1556727765.398 [NAL9602](INFO): Data available in MT queue
2019-05-01T16:22:45.925Z,1556727765.925 [NAL9602](INFO): Received command:restart sys
2019-05-01T16:22:45.997Z,1556727765.997 [CommandLine](IMPORTANT): got command restart system
2019-05-01T16:22:46.641Z,1556727766.641 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:22:48.329Z,1556727768.329 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-01T16:22:48.329Z,1556727768.329 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-05-01T16:22:48.361Z,1556727768.361 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2019-05-01T16:22:48.361Z,1556727768.361 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-05-01T16:22:48.362Z,1556727768.362 [CommandLine](INFO): Join timeout helper Thread ID is 4618
2019-05-01T16:22:48.362Z,1556727768.362 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2019-05-01T16:22:48.362Z,1556727768.362 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-05-01T16:22:48.363Z,1556727768.363 [NavChartDb](INFO): Join timeout helper Thread ID is 4619
2019-05-01T16:22:48.389Z,1556727768.389 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-01T16:22:48.389Z,1556727768.389 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-05-01T16:22:48.405Z,1556727768.405 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2019-05-01T16:22:48.405Z,1556727768.405 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-05-01T16:22:48.406Z,1556727768.406 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 4620
2019-05-01T16:22:48.863Z,1556727768.863 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-01T16:22:48.864Z,1556727768.864 [WetLabsBB2FL](INFO): Powering down
2019-05-01T16:22:48.867Z,1556727768.867 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-05-01T16:22:48.881Z,1556727768.881 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2019-05-01T16:22:48.881Z,1556727768.881 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2019-05-01T16:22:48.881Z,1556727768.881 [CTD_Seabird](INFO): Join timeout helper Thread ID is 4621
2019-05-01T16:22:49.065Z,1556727769.065 [NAL9602](DEBUG): Fix Requested
2019-05-01T16:22:49.217Z,1556727769.217 [CTD_Seabird](INFO): Powering down
2019-05-01T16:22:49.229Z,1556727769.229 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-01T16:22:49.229Z,1556727769.229 [CTD_Seabird](INFO): Powering down
2019-05-01T16:22:49.241Z,1556727769.241 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2019-05-01T16:22:49.245Z,1556727769.245 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2019-05-01T16:22:49.245Z,1556727769.245 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-05-01T16:22:49.245Z,1556727769.245 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 4622
2019-05-01T16:22:49.433Z,1556727769.433 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-01T16:22:49.433Z,1556727769.433 [CTD_NeilBrown](INFO): Powering down
2019-05-01T16:22:49.445Z,1556727769.445 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-05-01T16:22:49.458Z,1556727769.458 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2019-05-01T16:22:49.458Z,1556727769.458 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-05-01T16:22:49.458Z,1556727769.458 [Radio_Surface](INFO): Join timeout helper Thread ID is 4623
2019-05-01T16:22:49.613Z,1556727769.613 [Radio_Surface](INFO): Powering down
2019-05-01T16:22:49.614Z,1556727769.614 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-01T16:22:49.614Z,1556727769.614 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-05-01T16:22:49.625Z,1556727769.625 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2019-05-01T16:22:49.626Z,1556727769.626 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-05-01T16:22:49.626Z,1556727769.626 [DataOverHttps](INFO): Join timeout helper Thread ID is 4624
2019-05-01T16:22:49.813Z,1556727769.813 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-01T16:22:49.813Z,1556727769.813 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-05-01T16:22:49.838Z,1556727769.838 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2019-05-01T16:22:49.838Z,1556727769.838 [logger ThreadHandler](INFO): Thread cancelled.
2019-05-01T16:22:49.838Z,1556727769.838 [logger](INFO): Join timeout helper Thread ID is 4625
2019-05-01T16:22:49.857Z,1556727769.857 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-01T16:22:49.857Z,1556727769.857 [logger ThreadHandler](INFO): Thread cancelled.
2019-05-01T16:22:49.865Z,1556727769.865 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2019-05-01T16:22:49.866Z,1556727769.866 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-05-01T16:22:49.866Z,1556727769.866 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2019-05-01T16:22:49.866Z,1556727769.866 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-05-01T16:22:49.866Z,1556727769.866 [controlThread](INFO): Join timeout helper Thread ID is 4626
2019-05-01T16:22:49.907Z,1556727769.907 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-01T16:22:49.907Z,1556727769.907 [controlThread](DEBUG): Uninitializing ControlThread
2019-05-01T16:22:49.907Z,1556727769.907 [AHRS_M2](INFO): Powering down
2019-05-01T16:22:50.049Z,1556727770.049 [DVL_micro](INFO): uninitialize:Powering down
2019-05-01T16:22:50.050Z,1556727770.050 [NAL9602](INFO): Powering down
2019-05-01T16:22:50.051Z,1556727770.051 [DAT](INFO): Powering down
2019-05-01T16:22:50.170Z,1556727770.170 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2019-05-01T16:22:50.171Z,1556727770.171 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2019-05-01T16:22:50.172Z,1556727770.172 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2019-05-01T16:22:50.172Z,1556727770.172 [MissionManager](INFO): Uninitializing Mission Default
2019-05-01T16:22:50.172Z,1556727770.172 [Default] Stopped
2019-05-01T16:22:50.172Z,1556727770.172 [Default](DEBUG): Aggregate::uninitialize Default
2019-05-01T16:22:50.172Z,1556727770.172 [Default:B.GoToSurface] Stopped
2019-05-01T16:22:50.173Z,1556727770.173 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-05-01T16:22:50.173Z,1556727770.173 [Default:CheckIn] Stopped
2019-05-01T16:22:50.173Z,1556727770.173 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-05-01T16:22:50.173Z,1556727770.173 [Default:CheckIn:Read_GPS] Stopped
2019-05-01T16:22:50.175Z,1556727770.175 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2019-05-01T16:22:50.175Z,1556727770.175 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2019-05-01T16:22:50.176Z,1556727770.176 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2019-05-01T16:22:50.176Z,1556727770.176 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2019-05-01T16:22:50.176Z,1556727770.176 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2019-05-01T16:22:50.176Z,1556727770.176 [BuoyancyServo](INFO): Powering down
2019-05-01T16:22:50.189Z,1556727770.189 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2019-05-01T16:22:50.189Z,1556727770.189 [ElevatorServo](INFO): Powering down
2019-05-01T16:22:50.190Z,1556727770.190 [MassServo](DEBUG): Uninitialize Mass Servo.
2019-05-01T16:22:50.190Z,1556727770.190 [MassServo](INFO): Powering down
2019-05-01T16:22:50.191Z,1556727770.191 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-05-01T16:22:50.191Z,1556727770.191 [RudderServo](INFO): Powering down
2019-05-01T16:22:50.192Z,1556727770.192 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2019-05-01T16:22:50.192Z,1556727770.192 [ThrusterServo](INFO): Powering down
2019-05-01T16:22:50.192Z,1556727770.192 [SBIT](DEBUG): Uninitialize SBIT Component.
2019-05-01T16:22:50.193Z,1556727770.193 [IBIT](DEBUG): Uninitialize IBIT Component.
2019-05-01T16:22:50.193Z,1556727770.193 [CBIT](DEBUG): Uninitialize CBIT Component.
2019-05-01T16:22:50.193Z,1556727770.193 [CBIT](DEBUG): Powering off loads.
2019-05-01T16:22:50.205Z,1556727770.205 [CBIT](DEBUG): Disabling WDT.
2019-05-01T16:22:50.217Z,1556727770.217 [CBIT](DEBUG): Opening all GF detection circuits.
2019-05-01T16:22:50.217Z,1556727770.217 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-05-01T16:22:50.299Z,1556727770.299 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-05-01T16:22:50.308Z,1556727770.308 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-05-01T16:22:50.339Z,1556727770.339 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-05-01T16:22:50.342Z,1556727770.342 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2019-05-01T16:22:50.345Z,1556727770.345 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-05-01T16:22:50.381Z,1556727770.381 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-05-01T16:22:50.450Z,1556727770.450 [logger ThreadHandler](INFO): Thread cancelled.