2019-04-22T22:16:27.691Z,1555971387.691 [Supervisor](DEBUG): Initializing supervisor.
2019-04-22T22:16:27.694Z,1555971387.694 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2019-04-22T22:16:27.695Z,1555971387.695 [SyncHandler](INFO): Protected caller Thread ID is 806
2019-04-22T22:16:27.695Z,1555971387.695 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2019-04-22T22:16:27.696Z,1555971387.696 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2019-04-22T22:16:27.696Z,1555971387.696 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 807
2019-04-22T22:16:27.699Z,1555971387.699 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2019-04-22T22:16:27.710Z,1555971387.710 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2019-04-22T22:16:27.711Z,1555971387.711 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2019-04-22T22:16:27.712Z,1555971387.712 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 808
2019-04-22T22:16:27.713Z,1555971387.713 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2019-04-22T22:16:27.714Z,1555971387.714 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2019-04-22T22:16:27.714Z,1555971387.714 [logger ThreadHandler](INFO): Protected caller Thread ID is 809
2019-04-22T22:16:27.716Z,1555971387.716 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2019-04-22T22:16:27.716Z,1555971387.716 [Supervisor](INFO): Looking for Config files in directory: Config/
2019-04-22T22:16:27.721Z,1555971387.721 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2019-04-22T22:16:27.922Z,1555971387.922 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2019-04-22T22:16:27.923Z,1555971387.923 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2019-04-22T22:16:28.005Z,1555971388.005 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2019-04-22T22:16:28.450Z,1555971388.450 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2019-04-22T22:16:28.452Z,1555971388.452 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2019-04-22T22:16:28.788Z,1555971388.788 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2019-04-22T22:16:28.790Z,1555971388.790 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2019-04-22T22:16:28.886Z,1555971388.886 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2019-04-22T22:16:28.887Z,1555971388.887 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2019-04-22T22:16:29.186Z,1555971389.186 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2019-04-22T22:16:29.188Z,1555971389.188 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2019-04-22T22:16:29.384Z,1555971389.384 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2019-04-22T22:16:29.384Z,1555971389.384 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2019-04-22T22:16:29.839Z,1555971389.839 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2019-04-22T22:16:29.840Z,1555971389.840 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2019-04-22T22:16:29.946Z,1555971389.946 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2019-04-22T22:16:29.946Z,1555971389.946 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2019-04-22T22:16:30.047Z,1555971390.047 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2019-04-22T22:16:30.047Z,1555971390.047 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2019-04-22T22:16:30.546Z,1555971390.546 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2019-04-22T22:16:30.547Z,1555971390.547 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2019-04-22T22:16:30.954Z,1555971390.954 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2019-04-22T22:16:30.955Z,1555971390.955 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2019-04-22T22:16:31.300Z,1555971391.300 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2019-04-22T22:16:31.300Z,1555971391.300 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2019-04-22T22:16:32.121Z,1555971392.121 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2019-04-22T22:16:32.122Z,1555971392.122 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2019-04-22T22:16:32.271Z,1555971392.271 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2019-04-22T22:16:32.273Z,1555971392.273 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2019-04-22T22:16:32.276Z,1555971392.276 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg
2019-04-22T22:16:32.367Z,1555971392.367 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2019-04-22T22:16:32.452Z,1555971392.452 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2019-04-22T22:16:32.554Z,1555971392.554 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg
2019-04-22T22:16:32.637Z,1555971392.637 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2019-04-22T22:16:32.732Z,1555971392.732 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2019-04-22T22:16:32.833Z,1555971392.833 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2019-04-22T22:16:33.037Z,1555971393.037 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg
2019-04-22T22:16:33.114Z,1555971393.114 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2019-04-22T22:16:33.278Z,1555971393.278 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2019-04-22T22:16:33.412Z,1555971393.412 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2019-04-22T22:16:33.529Z,1555971393.529 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg
2019-04-22T22:16:33.758Z,1555971393.758 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2019-04-22T22:16:33.759Z,1555971393.759 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2019-04-22T22:16:33.766Z,1555971393.766 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2019-04-22T22:16:33.853Z,1555971393.853 [VerticalControl](DEBUG): Construct VerticalControl.
2019-04-22T22:16:33.964Z,1555971393.964 [VerticalControl] Loaded
2019-04-22T22:16:33.964Z,1555971393.964 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2019-04-22T22:16:33.965Z,1555971393.965 [HorizontalControl](DEBUG): Construct HorizontalControl.
2019-04-22T22:16:34.033Z,1555971394.033 [HorizontalControl] Loaded
2019-04-22T22:16:34.033Z,1555971394.033 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2019-04-22T22:16:34.034Z,1555971394.034 [SpeedControl](DEBUG): Construct SpeedControl.
2019-04-22T22:16:34.039Z,1555971394.039 [SpeedControl] Loaded
2019-04-22T22:16:34.039Z,1555971394.039 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2019-04-22T22:16:34.040Z,1555971394.040 [LoopControl](DEBUG): Construct LoopControl.
2019-04-22T22:16:34.041Z,1555971394.041 [LoopControl] Loaded
2019-04-22T22:16:34.041Z,1555971394.041 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2019-04-22T22:16:34.041Z,1555971394.041 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2019-04-22T22:16:34.042Z,1555971394.042 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2019-04-22T22:16:34.066Z,1555971394.066 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2019-04-22T22:16:34.068Z,1555971394.068 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2019-04-22T22:16:34.190Z,1555971394.190 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2019-04-22T22:16:34.191Z,1555971394.191 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2019-04-22T22:16:34.335Z,1555971394.335 [BuoyancyServo] Loaded
2019-04-22T22:16:34.335Z,1555971394.335 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2019-04-22T22:16:34.346Z,1555971394.346 [ElevatorServo] Loaded
2019-04-22T22:16:34.346Z,1555971394.346 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2019-04-22T22:16:34.357Z,1555971394.357 [MassServo] Loaded
2019-04-22T22:16:34.357Z,1555971394.357 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2019-04-22T22:16:34.368Z,1555971394.368 [RudderServo] Loaded
2019-04-22T22:16:34.368Z,1555971394.368 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2019-04-22T22:16:34.379Z,1555971394.379 [ThrusterServo] Loaded
2019-04-22T22:16:34.379Z,1555971394.379 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2019-04-22T22:16:34.380Z,1555971394.380 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2019-04-22T22:16:34.381Z,1555971394.381 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2019-04-22T22:16:34.503Z,1555971394.503 [DeadReckonUsingMultipleVelocitySources] Loaded
2019-04-22T22:16:34.504Z,1555971394.504 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2019-04-22T22:16:34.524Z,1555971394.524 [NavChart] Loaded
2019-04-22T22:16:34.525Z,1555971394.525 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2019-04-22T22:16:34.529Z,1555971394.529 [UniversalFixResidualReporter] Loaded
2019-04-22T22:16:34.529Z,1555971394.529 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2019-04-22T22:16:34.529Z,1555971394.529 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2019-04-22T22:16:34.530Z,1555971394.530 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2019-04-22T22:16:34.631Z,1555971394.631 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2019-04-22T22:16:34.632Z,1555971394.632 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2019-04-22T22:16:35.294Z,1555971395.294 [AHRS_M2] Loaded
2019-04-22T22:16:35.294Z,1555971395.294 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2019-04-22T22:16:35.442Z,1555971395.442 [DataOverHttps] Loaded
2019-04-22T22:16:35.442Z,1555971395.442 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2019-04-22T22:16:35.444Z,1555971395.444 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4086D4E0
2019-04-22T22:16:35.444Z,1555971395.444 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 891
2019-04-22T22:16:35.457Z,1555971395.457 [Depth_Keller] Loaded
2019-04-22T22:16:35.457Z,1555971395.457 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2019-04-22T22:16:35.462Z,1555971395.462 [DropWeight] Loaded
2019-04-22T22:16:35.462Z,1555971395.462 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2019-04-22T22:16:35.559Z,1555971395.559 [NAL9602] Loaded
2019-04-22T22:16:35.559Z,1555971395.559 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2019-04-22T22:16:35.575Z,1555971395.575 [Onboard] Loaded
2019-04-22T22:16:35.575Z,1555971395.575 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2019-04-22T22:16:35.579Z,1555971395.579 [Radio_Surface] Loaded
2019-04-22T22:16:35.579Z,1555971395.579 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2019-04-22T22:16:35.580Z,1555971395.580 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4089D4E0
2019-04-22T22:16:35.580Z,1555971395.580 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 892
2019-04-22T22:16:37.514Z,1555971397.514 [BPC1] Loaded
2019-04-22T22:16:37.515Z,1555971397.515 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2019-04-22T22:16:37.515Z,1555971397.515 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2019-04-22T22:16:37.516Z,1555971397.516 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2019-04-22T22:16:37.570Z,1555971397.570 [DepthRateCalculator] Loaded
2019-04-22T22:16:37.571Z,1555971397.571 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2019-04-22T22:16:37.576Z,1555971397.576 [PitchRateCalculator] Loaded
2019-04-22T22:16:37.576Z,1555971397.576 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2019-04-22T22:16:37.588Z,1555971397.588 [SpeedCalculator] Loaded
2019-04-22T22:16:37.588Z,1555971397.588 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2019-04-22T22:16:37.609Z,1555971397.609 [TempGradientCalculator] Loaded
2019-04-22T22:16:37.610Z,1555971397.610 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2019-04-22T22:16:37.615Z,1555971397.615 [YawRateCalculator] Loaded
2019-04-22T22:16:37.615Z,1555971397.615 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2019-04-22T22:16:37.644Z,1555971397.644 [ElevatorOffsetCalculator] Loaded
2019-04-22T22:16:37.645Z,1555971397.645 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2019-04-22T22:16:37.645Z,1555971397.645 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2019-04-22T22:16:37.647Z,1555971397.647 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2019-04-22T22:16:37.899Z,1555971397.899 [Aanderaa_O2] Loaded
2019-04-22T22:16:37.900Z,1555971397.900 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2019-04-22T22:16:37.984Z,1555971397.984 [CTD_NeilBrown] Loaded
2019-04-22T22:16:37.984Z,1555971397.984 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2019-04-22T22:16:37.986Z,1555971397.986 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 409974E0
2019-04-22T22:16:37.986Z,1555971397.986 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 893
2019-04-22T22:16:37.996Z,1555971397.996 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_density
2019-04-22T22:16:38.001Z,1555971398.001 [CTD_Seabird](INFO): created writer for : sea_water_density
2019-04-22T22:16:38.002Z,1555971398.002 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): depth
2019-04-22T22:16:38.007Z,1555971398.007 [CTD_Seabird](INFO): created writer for : depth
2019-04-22T22:16:38.008Z,1555971398.008 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_pressure
2019-04-22T22:16:38.013Z,1555971398.013 [CTD_Seabird](INFO): created writer for : sea_water_pressure
2019-04-22T22:16:38.014Z,1555971398.014 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_salinity
2019-04-22T22:16:38.018Z,1555971398.018 [CTD_Seabird](INFO): created writer for : sea_water_salinity
2019-04-22T22:16:38.019Z,1555971398.019 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_temperature
2019-04-22T22:16:38.024Z,1555971398.024 [CTD_Seabird](INFO): created writer for : sea_water_temperature
2019-04-22T22:16:38.025Z,1555971398.025 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_electrical_conductivity
2019-04-22T22:16:38.030Z,1555971398.030 [CTD_Seabird](INFO): created writer for : sea_water_electrical_conductivity
2019-04-22T22:16:38.030Z,1555971398.030 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): speed_of_sound_in_sea_water
2019-04-22T22:16:38.035Z,1555971398.035 [CTD_Seabird](INFO): created writer for : speed_of_sound_in_sea_water
2019-04-22T22:16:38.062Z,1555971398.062 [CTD_Seabird] Loaded
2019-04-22T22:16:38.062Z,1555971398.062 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2019-04-22T22:16:38.063Z,1555971398.063 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 409C74E0
2019-04-22T22:16:38.063Z,1555971398.063 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 894
2019-04-22T22:16:38.090Z,1555971398.090 [ESPComponent] Loaded
2019-04-22T22:16:38.090Z,1555971398.090 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2019-04-22T22:16:38.104Z,1555971398.104 [PAR_Licor] Loaded
2019-04-22T22:16:38.104Z,1555971398.104 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2019-04-22T22:16:38.151Z,1555971398.151 [WetLabsBB2FL] Loaded
2019-04-22T22:16:38.152Z,1555971398.152 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2019-04-22T22:16:38.153Z,1555971398.153 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 409F74E0
2019-04-22T22:16:38.153Z,1555971398.153 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 895
2019-04-22T22:16:38.154Z,1555971398.154 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2019-04-22T22:16:38.154Z,1555971398.154 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2019-04-22T22:16:38.196Z,1555971398.196 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2019-04-22T22:16:38.196Z,1555971398.196 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2019-04-22T22:16:38.510Z,1555971398.510 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2019-04-22T22:16:38.511Z,1555971398.511 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2019-04-22T22:16:38.667Z,1555971398.667 [SBIT](DEBUG): Construct Startup Built In Test.
2019-04-22T22:16:38.678Z,1555971398.678 [SBIT] Loaded
2019-04-22T22:16:38.678Z,1555971398.678 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2019-04-22T22:16:38.679Z,1555971398.679 [IBIT](DEBUG): Construct Initiated Built In Test.
2019-04-22T22:16:38.691Z,1555971398.691 [IBIT] Loaded
2019-04-22T22:16:38.691Z,1555971398.691 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2019-04-22T22:16:38.694Z,1555971398.694 [CBIT](DEBUG): Construct Continuous Built In Test.
2019-04-22T22:16:38.833Z,1555971398.833 [CBIT] Loaded
2019-04-22T22:16:38.833Z,1555971398.833 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2019-04-22T22:16:38.833Z,1555971398.833 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2019-04-22T22:16:38.837Z,1555971398.837 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2019-04-22T22:16:38.838Z,1555971398.838 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2019-04-22T22:16:38.845Z,1555971398.845 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2019-04-22T22:16:38.846Z,1555971398.846 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40AEE4E0
2019-04-22T22:16:38.846Z,1555971398.846 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 896
2019-04-22T22:16:38.851Z,1555971398.851 [Supervisor](INFO): Main Thread ID is 802
2019-04-22T22:16:38.851Z,1555971398.851 [Supervisor](DEBUG): Running supervisor.
2019-04-22T22:16:38.852Z,1555971398.852 [CommandLine ThreadHandler](INFO): Handler Thread ID is 897
2019-04-22T22:16:38.854Z,1555971398.854 [controlThread ThreadHandler](INFO): Handler Thread ID is 898
2019-04-22T22:16:38.854Z,1555971398.854 [controlThread](DEBUG): Initializing ControlThread
2019-04-22T22:16:38.855Z,1555971398.855 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2019-04-22T22:16:38.857Z,1555971398.857 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2019-04-22T22:16:38.857Z,1555971398.857 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2019-04-22T22:16:38.858Z,1555971398.858 [LoopControl](DEBUG): Initialize LoopControlComponent.
2019-04-22T22:16:38.860Z,1555971398.860 [NavChart](DEBUG): Initialize NavChart Navigation.
2019-04-22T22:16:38.860Z,1555971398.860 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2019-04-22T22:16:38.863Z,1555971398.863 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2019-04-22T22:16:38.864Z,1555971398.864 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2019-04-22T22:16:38.864Z,1555971398.864 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2019-04-22T22:16:38.864Z,1555971398.864 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2019-04-22T22:16:38.865Z,1555971398.865 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2019-04-22T22:16:38.865Z,1555971398.865 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2019-04-22T22:16:38.869Z,1555971398.869 [SBIT](INFO): Initialize SBIT Component.
2019-04-22T22:16:38.870Z,1555971398.870 [SBIT](IMPORTANT): git: 2019-04-03-2-gc409d73
2019-04-22T22:16:38.870Z,1555971398.870 [SBIT](INFO): git hash: c409d736a048220002cf5e268fada2ff754601b0
2019-04-22T22:16:38.870Z,1555971398.870 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2019-04-22T22:16:38.871Z,1555971398.871 [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-04-22T22:16:38.872Z,1555971398.872 [SBIT](INFO): Beginning SBIT in 23.000000 seconds.
2019-04-22T22:16:38.873Z,1555971398.873 [IBIT](INFO): Initialize IBIT Component.
2019-04-22T22:16:38.874Z,1555971398.874 [CBIT](DEBUG): Initialize CBIT Component.
2019-04-22T22:16:38.875Z,1555971398.875 [logger ThreadHandler](INFO): Handler Thread ID is 899
2019-04-22T22:16:38.885Z,1555971398.885 [CBIT](DEBUG): Initialized mux pins.
2019-04-22T22:16:38.885Z,1555971398.885 [CBIT](DEBUG): Initializing the watchdog timer.
2019-04-22T22:16:38.893Z,1555971398.893 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 900
2019-04-22T22:16:38.894Z,1555971398.894 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2019-04-22T22:16:38.905Z,1555971398.905 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 901
2019-04-22T22:16:38.909Z,1555971398.909 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2019-04-22T22:16:38.909Z,1555971398.909 [CBIT](DEBUG): Initializing heartbeat.
2019-04-22T22:16:38.917Z,1555971398.917 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 902
2019-04-22T22:16:38.918Z,1555971398.918 [CTD_NeilBrown](INFO): Powering down
2019-04-22T22:16:38.945Z,1555971398.945 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 903
2019-04-22T22:16:38.946Z,1555971398.946 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2019-04-22T22:16:38.949Z,1555971398.949 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 905
2019-04-22T22:16:38.950Z,1555971398.950 [CTD_Seabird](INFO): Opening uart, block timeout 10ths=20
2019-04-22T22:16:38.952Z,1555971398.952 [WetLabsBB2FL](INFO): Powering down
2019-04-22T22:16:38.981Z,1555971398.981 [CBIT](DEBUG): Deactivating GF circuits.
2019-04-22T22:16:38.981Z,1555971398.981 [CBIT](DEBUG): Deactivating emergency mode.
2019-04-22T22:16:38.982Z,1555971398.982 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 906
2019-04-22T22:16:38.990Z,1555971398.990 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2019-04-22T22:16:38.990Z,1555971398.990 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2019-04-22T22:16:38.991Z,1555971398.991 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2019-04-22T22:16:38.991Z,1555971398.991 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2019-04-22T22:16:38.991Z,1555971398.991 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2019-04-22T22:16:38.991Z,1555971398.991 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2019-04-22T22:16:38.991Z,1555971398.991 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2019-04-22T22:16:38.992Z,1555971398.992 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2019-04-22T22:16:38.992Z,1555971398.992 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2019-04-22T22:16:38.992Z,1555971398.992 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2019-04-22T22:16:38.992Z,1555971398.992 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2019-04-22T22:16:38.992Z,1555971398.992 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2019-04-22T22:16:38.993Z,1555971398.993 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2019-04-22T22:16:38.993Z,1555971398.993 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2019-04-22T22:16:38.993Z,1555971398.993 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2019-04-22T22:16:38.994Z,1555971398.994 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2019-04-22T22:16:39.017Z,1555971399.017 [CBIT](DEBUG): Backplane powered.
2019-04-22T22:16:39.018Z,1555971399.018 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2019-04-22T22:16:39.041Z,1555971399.041 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2019-04-22T22:16:39.072Z,1555971399.072 [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-04-22T22:16:39.093Z,1555971399.093 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2019-04-22T22:16:39.150Z,1555971399.150 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2019-04-22T22:16:39.151Z,1555971399.151 [Default:A.Wait](DEBUG): Construct Wait.
2019-04-22T22:16:39.152Z,1555971399.152 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2019-04-22T22:16:39.204Z,1555971399.204 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2019-04-22T22:16:39.221Z,1555971399.221 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2019-04-22T22:16:39.227Z,1555971399.227 [Default:E.Execute](DEBUG): Construct Execute.
2019-04-22T22:16:39.246Z,1555971399.246 [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-04-22T22:16:39.251Z,1555971399.251 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,NAL9602,Onboard,BPC1,Aanderaa_O2,ESPComponent,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-04-22T22:16:39.257Z,1555971399.257 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2019-04-22T22:16:39.309Z,1555971399.309 [Radio_Surface](INFO): Powering up
2019-04-22T22:16:39.378Z,1555971399.378 [Depth_Keller](ERROR): Pressure reading out of range: 1831.023193 decibar
2019-04-22T22:16:39.454Z,1555971399.454 [ESPComponent](INFO): powering down ESP
2019-04-22T22:16:39.857Z,1555971399.857 [DepthRateCalculator](ERROR): Depth measurement is not active
2019-04-22T22:16:39.927Z,1555971399.927 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2019-04-22T22:16:39.933Z,1555971399.933 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2019-04-22T22:16:39.934Z,1555971399.934 [ElevatorServo](DEBUG): Initializing EZServoServo.
2019-04-22T22:16:39.941Z,1555971399.941 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2019-04-22T22:16:39.942Z,1555971399.942 [MassServo](DEBUG): Initializing EZServoServo.
2019-04-22T22:16:39.950Z,1555971399.950 [MassServo](DEBUG): Initializing MassServo.
2019-04-22T22:16:39.951Z,1555971399.951 [RudderServo](DEBUG): Initializing EZServoServo.
2019-04-22T22:16:39.958Z,1555971399.958 [RudderServo](DEBUG): Initializing RudderServo.
2019-04-22T22:16:39.959Z,1555971399.959 [ThrusterServo](DEBUG): Initializing EZServoServo.
2019-04-22T22:16:39.965Z,1555971399.965 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2019-04-22T22:16:42.965Z,1555971402.965 [Aanderaa_O2](INFO): Powering down
2019-04-22T22:17:02.295Z,1555971422.295 [SBIT](IMPORTANT): Beginning Startup BIT
2019-04-22T22:17:02.308Z,1555971422.308 [CBIT](IMPORTANT): Beginning ground fault scan
2019-04-22T22:17:05.685Z,1555971425.685 [NAL9602](INFO): Powering up NAL9602
2019-04-22T22:17:13.018Z,1555971433.018 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): -0.007116
CHAN A1 (24V): -0.133946
CHAN A2 (12V): -0.002224
CHAN A3 (5V): -0.001672
CHAN B0 (3.3V): -0.000113
CHAN B1 (3.15aV): -0.000755
CHAN B2 (3.15bV): 4.767929
CHAN B3 (GND): 0.001138
OPEN: -0.000488
Full Scale Calc: 4.765 mA, -1.589 mA
2019-04-22T22:17:16.586Z,1555971436.586 [NAL9602](INFO): NAL9602 initialized
2019-04-22T22:17:17.401Z,1555971437.401 [NAL9602](DEBUG): Fix Requested
2019-04-22T22:17:55.670Z,1555971475.670 [SBIT](IMPORTANT): SBIT PASSED
2019-04-22T22:17:55.741Z,1555971475.741 [CommandLine](IMPORTANT): got command configSet list
2019-04-22T22:17:55.742Z,1555971475.742 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2019-04-22T22:17:55.743Z,1555971475.743 [CommandLine](IMPORTANT): DVL_micro.loadAtStartup=0 bool;

2019-04-22T22:17:55.743Z,1555971475.743 [CommandLine](IMPORTANT): DeadReckonUsingSpeedCalculator.loadAtStartup=0 bool;

2019-04-22T22:17:55.743Z,1555971475.743 [CommandLine](IMPORTANT): DeadReckonWithRespectToSeafloor.loadAtStartup=0 bool;

2019-04-22T22:17:56.075Z,1555971476.075 [MissionManager](IMPORTANT): Started mission Startup
2019-04-22T22:17:56.075Z,1555971476.075 [Startup] Running Loop=1
2019-04-22T22:17:56.075Z,1555971476.075 [Startup](DEBUG): Aggregate::initialize Startup
2019-04-22T22:17:56.075Z,1555971476.075 [Startup:A.GoToSurface] Running Loop=1
2019-04-22T22:17:56.076Z,1555971476.076 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-04-22T22:17:56.076Z,1555971476.076 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-04-22T22:17:56.078Z,1555971476.078 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-04-22T22:17:56.078Z,1555971476.078 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-04-22T22:17:56.078Z,1555971476.078 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-04-22T22:17:56.079Z,1555971476.079 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-04-22T22:17:56.080Z,1555971476.080 [Startup:StartupSatComms] Running Loop=1
2019-04-22T22:17:56.080Z,1555971476.080 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2019-04-22T22:17:56.080Z,1555971476.080 [Startup:StartupSatComms:A] Running Loop=1
2019-04-22T22:17:56.479Z,1555971476.479 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2019-04-22T22:18:56.271Z,1555971536.271 [Startup:StartupSatComms:A](INFO): Timed out from 2019-04-22T22:17:56.1Z
2019-04-22T22:18:56.271Z,1555971536.271 [Startup:StartupSatComms:A] Stopped
2019-04-22T22:18:56.271Z,1555971536.271 [Startup:StartupSatComms:B] Running Loop=1
2019-04-22T22:18:56.675Z,1555971536.675 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-04-22T22:19:39.115Z,1555971579.115 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2019-04-22T22:19:39.115Z,1555971579.115 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-04-22T22:19:39.137Z,1555971579.137 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-04-22T22:19:39.540Z,1555971579.540 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-04-22T22:19:39.540Z,1555971579.540 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2019-04-22T22:19:56.467Z,1555971596.467 [Startup:StartupSatComms:B](INFO): Timed out from 2019-04-22T22:18:56.3Z
2019-04-22T22:19:56.467Z,1555971596.467 [Startup:StartupSatComms:B] Stopped
2019-04-22T22:19:56.467Z,1555971596.467 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2019-04-22T22:19:56.467Z,1555971596.467 [Startup:StartupSatComms] Stopped
2019-04-22T22:19:56.467Z,1555971596.467 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2019-04-22T22:19:56.468Z,1555971596.468 [Startup](INFO): Completed Startup
2019-04-22T22:19:56.468Z,1555971596.468 [MissionManager](INFO): Startup is completed.
2019-04-22T22:19:56.468Z,1555971596.468 [MissionManager](INFO): Uninitializing Mission Startup
2019-04-22T22:19:56.469Z,1555971596.469 [Startup] Stopped
2019-04-22T22:19:56.469Z,1555971596.469 [Startup](DEBUG): Aggregate::uninitialize Startup
2019-04-22T22:19:56.469Z,1555971596.469 [Startup:A.GoToSurface] Stopped
2019-04-22T22:19:56.469Z,1555971596.469 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-04-22T22:19:56.873Z,1555971596.873 [MissionManager](IMPORTANT): Started mission Default
2019-04-22T22:19:56.873Z,1555971596.873 [Default] Running Loop=1
2019-04-22T22:19:56.873Z,1555971596.873 [Default](DEBUG): Aggregate::initialize Default
2019-04-22T22:19:56.873Z,1555971596.873 [Default:B.GoToSurface] Running Loop=1
2019-04-22T22:19:56.873Z,1555971596.873 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-04-22T22:19:56.874Z,1555971596.874 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-04-22T22:19:56.874Z,1555971596.874 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-04-22T22:19:56.874Z,1555971596.874 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-04-22T22:19:56.874Z,1555971596.874 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-04-22T22:19:56.875Z,1555971596.875 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-04-22T22:19:56.875Z,1555971596.875 [Default:A.Wait] Running Loop=1
2019-04-22T22:19:56.875Z,1555971596.875 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-04-22T22:19:59.676Z,1555971599.676 [NAL9602](INFO): SBD MO Status=2, MOMSN=11546, MT Status=2, MTMSN=0
2019-04-22T22:19:59.676Z,1555971599.676 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-04-22T22:20:10.211Z,1555971610.211 [Default:A.Wait](INFO): Done Waiting.
2019-04-22T22:20:10.211Z,1555971610.211 [Default:A.Wait] Stopped
2019-04-22T22:20:10.211Z,1555971610.211 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-04-22T22:20:10.621Z,1555971610.621 [Default:CheckIn] Running Loop=1
2019-04-22T22:20:10.622Z,1555971610.622 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-04-22T22:20:10.622Z,1555971610.622 [Default:CheckIn:Read_GPS] Running Loop=1
2019-04-22T22:20:11.034Z,1555971611.034 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2019-04-22T22:20:13.995Z,1555971613.995 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004957
2019-04-22T22:21:02.696Z,1555971662.696 [NAL9602](INFO): SBD MO Status=2, MOMSN=11546, MT Status=2, MTMSN=0
2019-04-22T22:21:02.696Z,1555971662.696 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-04-22T22:21:33.399Z,1555971693.399 [NAL9602](INFO): SBD MO Status=2, MOMSN=11546, MT Status=2, MTMSN=0
2019-04-22T22:21:33.400Z,1555971693.400 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-04-22T22:22:20.686Z,1555971740.686 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-04-22T22:22:21.513Z,1555971741.513 [NAL9602](DEBUG): Fix Requested
2019-04-22T22:22:25.545Z,1555971745.545 [NAL9602](DEBUG): Fix Requested
2019-04-22T22:22:27.977Z,1555971747.977 [NAL9602](DEBUG): Fix Requested
2019-04-22T22:22:31.209Z,1555971751.209 [NAL9602](DEBUG): Fix Requested
2019-04-22T22:22:34.033Z,1555971754.033 [NAL9602](DEBUG): Fix Requested
2019-04-22T22:22:37.265Z,1555971757.265 [NAL9602](DEBUG): Fix Requested
2019-04-22T22:22:40.089Z,1555971760.089 [NAL9602](DEBUG): Fix Requested
2019-04-22T22:22:40.114Z,1555971760.114 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2019-04-22T22:22:40.114Z,1555971760.114 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-04-22T22:22:40.124Z,1555971760.124 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-04-22T22:22:40.531Z,1555971760.531 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-04-22T22:22:40.531Z,1555971760.531 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2019-04-22T22:22:42.513Z,1555971762.513 [NAL9602](DEBUG): Fix Requested
2019-04-22T22:22:45.345Z,1555971765.345 [NAL9602](DEBUG): Fix Requested
2019-04-22T22:22:48.169Z,1555971768.169 [NAL9602](DEBUG): Fix Requested
2019-04-22T22:22:50.997Z,1555971770.997 [NAL9602](DEBUG): Fix Requested
2019-04-22T22:22:54.237Z,1555971774.237 [NAL9602](DEBUG): Fix Requested
2019-04-22T22:22:57.057Z,1555971777.057 [NAL9602](DEBUG): Fix Requested
2019-04-22T22:23:00.289Z,1555971780.289 [NAL9602](DEBUG): Fix Requested
2019-04-22T22:23:03.117Z,1555971783.117 [NAL9602](DEBUG): Fix Requested
2019-04-22T22:23:06.353Z,1555971786.353 [NAL9602](DEBUG): Fix Requested
2019-04-22T22:23:09.185Z,1555971789.185 [NAL9602](DEBUG): Fix Requested
2019-04-22T22:23:12.009Z,1555971792.009 [NAL9602](DEBUG): Fix Requested
2019-04-22T22:23:15.237Z,1555971795.237 [NAL9602](DEBUG): Fix Requested
2019-04-22T22:23:18.069Z,1555971798.069 [NAL9602](DEBUG): Fix Requested
2019-04-22T22:23:21.301Z,1555971801.301 [NAL9602](DEBUG): Fix Requested
2019-04-22T22:23:24.129Z,1555971804.129 [NAL9602](DEBUG): Fix Requested
2019-04-22T22:23:27.357Z,1555971807.357 [NAL9602](DEBUG): Fix Requested
2019-04-22T22:23:30.189Z,1555971810.189 [NAL9602](DEBUG): Fix Requested
2019-04-22T22:23:33.417Z,1555971813.417 [NAL9602](DEBUG): Fix Requested
2019-04-22T22:23:36.253Z,1555971816.253 [NAL9602](DEBUG): Fix Requested
2019-04-22T22:23:39.073Z,1555971819.073 [NAL9602](DEBUG): Fix Requested
2019-04-22T22:23:42.309Z,1555971822.309 [NAL9602](DEBUG): Fix Requested
2019-04-22T22:23:45.137Z,1555971825.137 [NAL9602](DEBUG): Fix Requested
2019-04-22T22:23:48.373Z,1555971828.373 [NAL9602](DEBUG): Fix Requested
2019-04-22T22:23:51.197Z,1555971831.197 [NAL9602](DEBUG): Fix Requested
2019-04-22T22:23:54.433Z,1555971834.433 [NAL9602](DEBUG): Fix Requested
2019-04-22T22:23:57.253Z,1555971837.253 [NAL9602](DEBUG): Fix Requested
2019-04-22T22:24:00.085Z,1555971840.085 [NAL9602](DEBUG): Fix Requested
2019-04-22T22:24:03.313Z,1555971843.313 [NAL9602](DEBUG): Fix Requested
2019-04-22T22:24:06.145Z,1555971846.145 [NAL9602](DEBUG): Fix Requested
2019-04-22T22:24:09.373Z,1555971849.373 [NAL9602](DEBUG): Fix Requested
2019-04-22T22:24:12.201Z,1555971852.201 [NAL9602](DEBUG): Fix Requested
2019-04-22T22:24:15.433Z,1555971855.433 [NAL9602](DEBUG): Fix Requested
2019-04-22T22:24:18.261Z,1555971858.261 [NAL9602](DEBUG): Fix Requested
2019-04-22T22:24:21.497Z,1555971861.497 [NAL9602](DEBUG): Fix Requested
2019-04-22T22:24:24.321Z,1555971864.321 [NAL9602](DEBUG): Fix Requested
2019-04-22T22:24:27.157Z,1555971867.157 [NAL9602](DEBUG): Fix Requested
2019-04-22T22:24:30.389Z,1555971870.389 [NAL9602](DEBUG): Fix Requested
2019-04-22T22:24:33.221Z,1555971873.221 [NAL9602](DEBUG): Fix Requested
2019-04-22T22:24:36.445Z,1555971876.445 [NAL9602](DEBUG): Fix Requested
2019-04-22T22:24:39.273Z,1555971879.273 [NAL9602](DEBUG): Fix Requested
2019-04-22T22:24:42.501Z,1555971882.501 [NAL9602](DEBUG): Fix Requested
2019-04-22T22:24:45.333Z,1555971885.333 [NAL9602](DEBUG): Fix Requested
2019-04-22T22:24:48.561Z,1555971888.561 [NAL9602](DEBUG): Fix Requested
2019-04-22T22:24:51.393Z,1555971891.393 [NAL9602](DEBUG): Fix Requested
2019-04-22T22:24:54.225Z,1555971894.225 [NAL9602](DEBUG): Fix Requested
2019-04-22T22:24:57.457Z,1555971897.457 [NAL9602](DEBUG): Fix Requested
2019-04-22T22:25:00.277Z,1555971900.277 [NAL9602](DEBUG): Fix Requested
2019-04-22T22:25:03.509Z,1555971903.509 [NAL9602](DEBUG): Fix Requested
2019-04-22T22:25:06.337Z,1555971906.337 [NAL9602](DEBUG): Fix Requested
2019-04-22T22:25:06.732Z,1555971906.732 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,221310.00,A,3648.16605,N,12147.28275,W,0.097,50.45,220419,,,A*4F
2019-04-22T22:25:06.735Z,1555971906.735 [NAL9602](INFO): GPS fix at 20190422T221310: (36.802768, -121.788046)
2019-04-22T22:25:06.777Z,1555971906.777 [Default:CheckIn:Read_GPS] Stopped
2019-04-22T22:25:06.777Z,1555971906.777 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-04-22T22:25:07.189Z,1555971907.189 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-04-22T22:25:15.546Z,1555971915.546 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190421T020700/Courier0753.lzma
2019-04-22T22:25:16.351Z,1555971916.351 [DataOverHttps](INFO): Moved sent file to Logs/20190421T020700/Courier0753.lzma.bak
2019-04-22T22:25:16.351Z,1555971916.351 [DataOverHttps](INFO): SBD MOMSN=10736417
2019-04-22T22:25:30.484Z,1555971930.484 [DataOverHttps](INFO): Sending 215 bytes from file Logs/20190422T221627/Courier0004.lzma
2019-04-22T22:25:31.290Z,1555971931.290 [DataOverHttps](INFO): Moved sent file to Logs/20190422T221627/Courier0004.lzma.bak
2019-04-22T22:25:31.291Z,1555971931.291 [DataOverHttps](INFO): SBD MOMSN=10736499
2019-04-22T22:25:39.463Z,1555971939.463 [NAL9602](INFO): Powering down
2019-04-22T22:25:43.846Z,1555971943.846 [DataOverHttps](INFO): Sending 174 bytes from file Logs/20190421T020700/Express0754.lzma
2019-04-22T22:25:44.651Z,1555971944.651 [DataOverHttps](INFO): Moved sent file to Logs/20190421T020700/Express0754.lzma.bak
2019-04-22T22:25:44.651Z,1555971944.651 [DataOverHttps](INFO): SBD MOMSN=10736503
2019-04-22T22:25:57.765Z,1555971957.765 [DataOverHttps](INFO): Sending 657 bytes from file Logs/20190422T221627/Express0001.lzma
2019-04-22T22:25:58.570Z,1555971958.570 [DataOverHttps](INFO): Moved sent file to Logs/20190422T221627/Express0001.lzma.bak
2019-04-22T22:25:58.570Z,1555971958.570 [DataOverHttps](INFO): SBD MOMSN=10736507
2019-04-22T22:26:10.885Z,1555971970.885 [DataOverHttps](INFO): Sending 301 bytes from file Logs/20190422T221627/Express0005.lzma
2019-04-22T22:26:11.690Z,1555971971.690 [DataOverHttps](INFO): Moved sent file to Logs/20190422T221627/Express0005.lzma.bak
2019-04-22T22:26:11.690Z,1555971971.690 [DataOverHttps](INFO): SBD MOMSN=10736522
2019-04-22T22:26:13.836Z,1555971973.836 [Default:CheckIn:Read_Iridium] Stopped
2019-04-22T22:26:13.836Z,1555971973.836 [Default:CheckIn:C.Wait] Running Loop=1
2019-04-22T22:26:13.836Z,1555971973.836 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-04-22T22:29:23.808Z,1555972163.808 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-04-22T22:31:14.415Z,1555972274.415 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-04-22T22:31:14.415Z,1555972274.415 [Default:CheckIn:C.Wait] Stopped
2019-04-22T22:31:14.415Z,1555972274.415 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-04-22T22:31:14.415Z,1555972274.415 [Default:CheckIn:D] Running Loop=1
2019-04-22T22:31:14.825Z,1555972274.825 [Default:CheckIn:D] Stopped
2019-04-22T22:31:14.825Z,1555972274.825 [Default:CheckIn:E] Running Loop=1
2019-04-22T22:31:15.229Z,1555972275.229 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 11.299203 min 
2019-04-22T22:31:15.229Z,1555972275.229 [Default:CheckIn:E] Stopped
2019-04-22T22:31:15.230Z,1555972275.230 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-04-22T22:31:15.230Z,1555972275.230 [Default:CheckIn] Stopped
2019-04-22T22:31:15.230Z,1555972275.230 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-04-22T22:31:15.230Z,1555972275.230 [Default:CheckIn](INFO): Running loop #2
2019-04-22T22:31:15.230Z,1555972275.230 [Default:CheckIn] Running Loop=2
2019-04-22T22:31:15.230Z,1555972275.230 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-04-22T22:31:15.230Z,1555972275.230 [Default:CheckIn:Read_GPS] Running Loop=1
2019-04-22T22:31:16.010Z,1555972276.010 [NAL9602](INFO): Powering up
2019-04-22T22:31:26.918Z,1555972286.918 [NAL9602](INFO): NAL9602 initialized
2019-04-22T22:31:27.737Z,1555972287.737 [NAL9602](DEBUG): Fix Requested
2019-04-22T22:31:58.834Z,1555972318.834 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2019-04-22T22:31:58.913Z,1555972318.913 [NAL9602](FAULT): received: 
+CSQ:0

OK546, 2, 0, 0, 0

OK
2019-04-22T22:31:58.913Z,1555972318.913 [NAL9602] Data Fault, FailCount= 1
2019-04-22T22:31:58.913Z,1555972318.913 [NAL9602](ERROR): Data Fault
2019-04-22T22:31:58.950Z,1555972318.950 [CBIT](ERROR): Data Fault in component: NAL9602
2019-04-22T22:31:59.242Z,1555972319.242 [NAL9602](INFO): Powering down
2019-04-22T22:32:00.078Z,1555972320.078 [CBIT](INFO): Clearing failed state for component NAL9602
2019-04-22T22:32:00.078Z,1555972320.078 [NAL9602] No Fault, FailCount= 1
2019-04-22T22:32:29.554Z,1555972349.554 [NAL9602](INFO): Powering up NAL9602
2019-04-22T22:32:40.446Z,1555972360.446 [NAL9602](INFO): NAL9602 initialized
2019-04-22T22:32:41.265Z,1555972361.265 [NAL9602](DEBUG): Fix Requested
2019-04-22T22:33:26.049Z,1555972406.049 [CommandLine](IMPORTANT): got command maintain control VerticalControl.buoyancyAction 150.000000 cubic_centimeter
2019-04-22T22:33:26.051Z,1555972406.051 [ComponentRegistry](DEBUG): SyncComponent "Maintain_VerticalControl.buoyancyAction" handled in the control thread.
2019-04-22T22:33:26.186Z,1555972406.186 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,NAL9602,Onboard,BPC1,Aanderaa_O2,ESPComponent,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,Maintain_VerticalControl.buoyancyAction,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2019-04-22T22:33:52.966Z,1555972432.966 [CommandLine](IMPORTANT): got command report mod platform_buoyancy_position
2019-04-22T22:33:53.255Z,1555972433.255 [Reporter](INFO): platform_buoyancy_position 664.237732 cc
2019-04-22T22:33:53.647Z,1555972433.647 [Reporter](INFO): platform_buoyancy_position 659.671509 cc
2019-04-22T22:33:54.059Z,1555972434.059 [Reporter](INFO): platform_buoyancy_position 653.493713 cc
2019-04-22T22:33:54.443Z,1555972434.443 [Reporter](INFO): platform_buoyancy_position 649.061829 cc
2019-04-22T22:33:54.863Z,1555972434.863 [Reporter](INFO): platform_buoyancy_position 642.884033 cc
2019-04-22T22:33:55.255Z,1555972435.255 [Reporter](INFO): platform_buoyancy_position 638.452148 cc
2019-04-22T22:33:55.699Z,1555972435.699 [Reporter](INFO): platform_buoyancy_position 632.005737 cc
2019-04-22T22:33:56.103Z,1555972436.103 [Reporter](INFO): platform_buoyancy_position 627.439514 cc
2019-04-22T22:33:56.479Z,1555972436.479 [Reporter](INFO): platform_buoyancy_position 621.261719 cc
2019-04-22T22:33:56.903Z,1555972436.903 [Reporter](INFO): platform_buoyancy_position 616.964111 cc
2019-04-22T22:33:57.303Z,1555972437.303 [Reporter](INFO): platform_buoyancy_position 610.652039 cc
2019-04-22T22:33:57.723Z,1555972437.723 [Reporter](INFO): platform_buoyancy_position 606.085815 cc
2019-04-22T22:33:58.127Z,1555972438.127 [Reporter](INFO): platform_buoyancy_position 599.908020 cc
2019-04-22T22:33:58.508Z,1555972438.508 [Reporter](INFO): platform_buoyancy_position 595.476135 cc
2019-04-22T22:33:58.926Z,1555972438.926 [Reporter](INFO): platform_buoyancy_position 591.044250 cc
2019-04-22T22:33:59.303Z,1555972439.303 [Reporter](INFO): platform_buoyancy_position 586.075134 cc
2019-04-22T22:33:59.703Z,1555972439.703 [Reporter](INFO): platform_buoyancy_position 580.434509 cc
2019-04-22T22:34:00.123Z,1555972440.123 [Reporter](INFO): platform_buoyancy_position 574.122437 cc
2019-04-22T22:34:00.511Z,1555972440.511 [Reporter](INFO): platform_buoyancy_position 569.690552 cc
2019-04-22T22:34:00.915Z,1555972440.915 [Reporter](INFO): platform_buoyancy_position 563.244141 cc
2019-04-22T22:34:01.330Z,1555972441.330 [Reporter](INFO): platform_buoyancy_position 558.946533 cc
2019-04-22T22:34:01.715Z,1555972441.715 [Reporter](INFO): platform_buoyancy_position 552.500122 cc
2019-04-22T22:34:02.131Z,1555972442.131 [Reporter](INFO): platform_buoyancy_position 548.202515 cc
2019-04-22T22:34:02.544Z,1555972442.544 [Reporter](INFO): platform_buoyancy_position 541.756104 cc
2019-04-22T22:34:02.939Z,1555972442.939 [Reporter](INFO): platform_buoyancy_position 537.458496 cc
2019-04-22T22:34:03.359Z,1555972443.359 [Reporter](INFO): platform_buoyancy_position 531.146423 cc
2019-04-22T22:34:03.755Z,1555972443.755 [Reporter](INFO): platform_buoyancy_position 526.848816 cc
2019-04-22T22:34:04.135Z,1555972444.135 [Reporter](INFO): platform_buoyancy_position 521.342529 cc
2019-04-22T22:34:04.555Z,1555972444.555 [Reporter](INFO): platform_buoyancy_position 516.104797 cc
2019-04-22T22:34:04.967Z,1555972444.967 [Reporter](INFO): platform_buoyancy_position 511.672943 cc
2019-04-22T22:34:05.359Z,1555972445.359 [Reporter](INFO): platform_buoyancy_position 505.360901 cc
2019-04-22T22:34:05.755Z,1555972445.755 [Reporter](INFO): platform_buoyancy_position 500.660400 cc
2019-04-22T22:34:06.227Z,1555972446.227 [Reporter](INFO): platform_buoyancy_position 494.482574 cc
2019-04-22T22:34:06.643Z,1555972446.643 [Reporter](INFO): platform_buoyancy_position 488.036163 cc
2019-04-22T22:34:07.027Z,1555972447.027 [Reporter](INFO): platform_buoyancy_position 483.738556 cc
2019-04-22T22:34:07.415Z,1555972447.415 [Reporter](INFO): platform_buoyancy_position 479.172333 cc
2019-04-22T22:34:07.839Z,1555972447.839 [Reporter](INFO): platform_buoyancy_position 473.128876 cc
2019-04-22T22:34:08.207Z,1555972448.207 [Reporter](INFO): platform_buoyancy_position 468.831268 cc
2019-04-22T22:34:08.603Z,1555972448.603 [Reporter](INFO): platform_buoyancy_position 463.324921 cc
2019-04-22T22:34:09.002Z,1555972449.002 [Reporter](INFO): platform_buoyancy_position 458.087250 cc
2019-04-22T22:34:09.403Z,1555972449.403 [Reporter](INFO): platform_buoyancy_position 453.655365 cc
2019-04-22T22:34:09.799Z,1555972449.799 [Reporter](INFO): platform_buoyancy_position 449.223419 cc
2019-04-22T22:34:10.239Z,1555972450.239 [Reporter](INFO): platform_buoyancy_position 442.911346 cc
2019-04-22T22:34:10.619Z,1555972450.619 [Reporter](INFO): platform_buoyancy_position 436.599274 cc
2019-04-22T22:34:11.043Z,1555972451.043 [Reporter](INFO): platform_buoyancy_position 432.167328 cc
2019-04-22T22:34:11.431Z,1555972451.431 [Reporter](INFO): platform_buoyancy_position 425.989532 cc
2019-04-22T22:34:11.827Z,1555972451.827 [Reporter](INFO): platform_buoyancy_position 421.423370 cc
2019-04-22T22:34:12.235Z,1555972452.235 [Reporter](INFO): platform_buoyancy_position 415.111237 cc
2019-04-22T22:34:12.655Z,1555972452.655 [Reporter](INFO): platform_buoyancy_position 410.679352 cc
2019-04-22T22:34:13.067Z,1555972453.067 [Reporter](INFO): platform_buoyancy_position 404.232941 cc
2019-04-22T22:34:13.479Z,1555972453.479 [Reporter](INFO): platform_buoyancy_position 399.935333 cc
2019-04-22T22:34:13.866Z,1555972453.866 [Reporter](INFO): platform_buoyancy_position 393.757538 cc
2019-04-22T22:34:14.251Z,1555972454.251 [Reporter](INFO): platform_buoyancy_position 389.325653 cc
2019-04-22T22:34:14.651Z,1555972454.651 [Reporter](INFO): platform_buoyancy_position 383.147827 cc
2019-04-22T22:34:15.063Z,1555972455.063 [Reporter](INFO): platform_buoyancy_position 378.447327 cc
2019-04-22T22:34:15.467Z,1555972455.467 [Reporter](INFO): platform_buoyancy_position 373.075348 cc
2019-04-22T22:34:15.859Z,1555972455.859 [Reporter](INFO): platform_buoyancy_position 367.837646 cc
2019-04-22T22:34:16.263Z,1555972456.263 [Reporter](INFO): platform_buoyancy_position 363.271423 cc
2019-04-22T22:34:16.675Z,1555972456.675 [Reporter](INFO): platform_buoyancy_position 356.959351 cc
2019-04-22T22:34:17.095Z,1555972457.095 [Reporter](INFO): platform_buoyancy_position 352.661743 cc
2019-04-22T22:34:17.475Z,1555972457.475 [Reporter](INFO): platform_buoyancy_position 346.349640 cc
2019-04-22T22:34:17.895Z,1555972457.895 [Reporter](INFO): platform_buoyancy_position 341.917725 cc
2019-04-22T22:34:18.299Z,1555972458.299 [Reporter](INFO): platform_buoyancy_position 335.605621 cc
2019-04-22T22:34:18.774Z,1555972458.774 [Reporter](INFO): platform_buoyancy_position 331.173737 cc
2019-04-22T22:34:19.143Z,1555972459.143 [Reporter](INFO): platform_buoyancy_position 324.861633 cc
2019-04-22T22:34:19.531Z,1555972459.531 [Reporter](INFO): platform_buoyancy_position 320.429749 cc
2019-04-22T22:34:19.911Z,1555972459.911 [Reporter](INFO): platform_buoyancy_position 315.594940 cc
2019-04-22T22:34:20.395Z,1555972460.395 [Reporter](INFO): platform_buoyancy_position 309.820038 cc
2019-04-22T22:34:20.699Z,1555972460.699 [Reporter](INFO): platform_buoyancy_position 305.522430 cc
2019-04-22T22:34:21.171Z,1555972461.171 [Reporter](INFO): platform_buoyancy_position 298.941742 cc
2019-04-22T22:34:21.523Z,1555972461.523 [Reporter](INFO): platform_buoyancy_position 294.644135 cc
2019-04-22T22:34:21.855Z,1555972461.855 [CommandLine](IMPORTANT): got command get VerticalControl.massDefault
2019-04-22T22:34:21.856Z,1555972461.856 [CommandLine](IMPORTANT): VerticalControl.massDefault -0.075000 cm
2019-04-22T22:34:21.959Z,1555972461.959 [Reporter](INFO): platform_buoyancy_position 288.197723 cc
2019-04-22T22:34:22.343Z,1555972462.343 [Reporter](INFO): platform_buoyancy_position 283.765839 cc
2019-04-22T22:34:22.731Z,1555972462.731 [Reporter](INFO): platform_buoyancy_position 277.588043 cc
2019-04-22T22:34:23.139Z,1555972463.139 [Reporter](INFO): platform_buoyancy_position 273.156128 cc
2019-04-22T22:34:23.555Z,1555972463.555 [Reporter](INFO): platform_buoyancy_position 266.844025 cc
2019-04-22T22:34:23.967Z,1555972463.967 [Reporter](INFO): platform_buoyancy_position 262.412140 cc
2019-04-22T22:34:24.359Z,1555972464.359 [Reporter](INFO): platform_buoyancy_position 256.100037 cc
2019-04-22T22:34:24.755Z,1555972464.755 [Reporter](INFO): platform_buoyancy_position 251.668121 cc
2019-04-22T22:34:25.183Z,1555972465.183 [Reporter](INFO): platform_buoyancy_position 245.221741 cc
2019-04-22T22:34:25.579Z,1555972465.579 [Reporter](INFO): platform_buoyancy_position 240.924133 cc
2019-04-22T22:34:26.003Z,1555972466.003 [Reporter](INFO): platform_buoyancy_position 234.477722 cc
2019-04-22T22:34:26.379Z,1555972466.379 [Reporter](INFO): platform_buoyancy_position 230.045837 cc
2019-04-22T22:34:26.786Z,1555972466.786 [Reporter](INFO): platform_buoyancy_position 223.868042 cc
2019-04-22T22:34:27.175Z,1555972467.175 [Reporter](INFO): platform_buoyancy_position 219.436127 cc
2019-04-22T22:34:27.630Z,1555972467.630 [Reporter](INFO): platform_buoyancy_position 213.258331 cc
2019-04-22T22:34:27.754Z,1555972467.754 [CommandLine](IMPORTANT): got command get VerticalControl.massDefault millimeter
2019-04-22T22:34:27.754Z,1555972467.754 [CommandLine](IMPORTANT): VerticalControl.massDefault -0.750000 mm
2019-04-22T22:34:28.058Z,1555972468.058 [Reporter](INFO): platform_buoyancy_position 208.557831 cc
2019-04-22T22:34:28.419Z,1555972468.419 [Reporter](INFO): platform_buoyancy_position 203.857330 cc
2019-04-22T22:34:28.835Z,1555972468.835 [Reporter](INFO): platform_buoyancy_position 197.948120 cc
2019-04-22T22:34:29.227Z,1555972469.227 [Reporter](INFO): platform_buoyancy_position 193.381927 cc
2019-04-22T22:34:29.643Z,1555972469.643 [Reporter](INFO): platform_buoyancy_position 187.338440 cc
2019-04-22T22:34:29.991Z,1555972469.991 [Reporter](INFO): platform_buoyancy_position 183.040833 cc
2019-04-22T22:34:30.399Z,1555972470.399 [Reporter](INFO): platform_buoyancy_position 178.206024 cc
2019-04-22T22:34:30.807Z,1555972470.807 [Reporter](INFO): platform_buoyancy_position 171.893921 cc
2019-04-22T22:34:31.215Z,1555972471.215 [Reporter](INFO): platform_buoyancy_position 165.850433 cc
2019-04-22T22:34:35.365Z,1555972475.365 [Reporter](INFO): platform_buoyancy_position 151.346008 cc
2019-04-22T22:35:10.638Z,1555972510.638 [CommandLine](IMPORTANT): got command maintain control VerticalControl.buoyancyAction 300.000000 cubic_centimeter
2019-04-22T22:35:15.299Z,1555972515.299 [Reporter](INFO): platform_buoyancy_position 150.003021 cc
2019-04-22T22:35:15.639Z,1555972515.639 [Reporter](INFO): platform_buoyancy_position 148.928619 cc
2019-04-22T22:35:16.055Z,1555972516.055 [Reporter](INFO): platform_buoyancy_position 150.674530 cc
2019-04-22T22:35:16.463Z,1555972516.463 [Reporter](INFO): platform_buoyancy_position 155.106415 cc
2019-04-22T22:35:16.867Z,1555972516.867 [Reporter](INFO): platform_buoyancy_position 159.269714 cc
2019-04-22T22:35:17.279Z,1555972517.279 [Reporter](INFO): platform_buoyancy_position 163.567322 cc
2019-04-22T22:35:17.695Z,1555972517.695 [Reporter](INFO): platform_buoyancy_position 167.999237 cc
2019-04-22T22:35:18.075Z,1555972518.075 [Reporter](INFO): platform_buoyancy_position 174.311310 cc
2019-04-22T22:35:18.539Z,1555972518.539 [Reporter](INFO): platform_buoyancy_position 180.757721 cc
2019-04-22T22:35:18.903Z,1555972518.903 [Reporter](INFO): platform_buoyancy_position 185.189636 cc
2019-04-22T22:35:19.323Z,1555972519.323 [Reporter](INFO): platform_buoyancy_position 189.487213 cc
2019-04-22T22:35:19.751Z,1555972519.751 [Reporter](INFO): platform_buoyancy_position 195.799316 cc
2019-04-22T22:35:20.103Z,1555972520.103 [Reporter](INFO): platform_buoyancy_position 200.096924 cc
2019-04-22T22:35:20.507Z,1555972520.507 [Reporter](INFO): platform_buoyancy_position 204.663116 cc
2019-04-22T22:35:20.923Z,1555972520.923 [Reporter](INFO): platform_buoyancy_position 210.975220 cc
2019-04-22T22:35:21.315Z,1555972521.315 [Reporter](INFO): platform_buoyancy_position 215.138519 cc
2019-04-22T22:35:21.715Z,1555972521.715 [Reporter](INFO): platform_buoyancy_position 221.584930 cc
2019-04-22T22:35:22.139Z,1555972522.139 [Reporter](INFO): platform_buoyancy_position 226.285431 cc
2019-04-22T22:35:22.507Z,1555972522.507 [Reporter](INFO): platform_buoyancy_position 232.194641 cc
2019-04-22T22:35:22.927Z,1555972522.927 [Reporter](INFO): platform_buoyancy_position 236.760834 cc
2019-04-22T22:35:23.347Z,1555972523.347 [Reporter](INFO): platform_buoyancy_position 243.207214 cc
2019-04-22T22:35:23.751Z,1555972523.751 [Reporter](INFO): platform_buoyancy_position 247.504822 cc
2019-04-22T22:35:24.159Z,1555972524.159 [Reporter](INFO): platform_buoyancy_position 253.816925 cc
2019-04-22T22:35:24.583Z,1555972524.583 [Reporter](INFO): platform_buoyancy_position 258.248840 cc
2019-04-22T22:35:24.951Z,1555972524.951 [Reporter](INFO): platform_buoyancy_position 264.158020 cc
2019-04-22T22:35:25.367Z,1555972525.367 [Reporter](INFO): platform_buoyancy_position 268.858521 cc
2019-04-22T22:35:25.755Z,1555972525.755 [Reporter](INFO): platform_buoyancy_position 273.961945 cc
2019-04-22T22:35:26.203Z,1555972526.203 [Reporter](INFO): platform_buoyancy_position 279.602539 cc
2019-04-22T22:35:26.583Z,1555972526.583 [Reporter](INFO): platform_buoyancy_position 284.168732 cc
2019-04-22T22:35:27.047Z,1555972527.047 [Reporter](INFO): platform_buoyancy_position 290.346527 cc
2019-04-22T22:35:40.761Z,1555972540.761 [CommandLine](IMPORTANT): got command configSet VerticalControl.massDefault -10.000000 millimeter
2019-04-22T22:36:15.463Z,1555972575.463 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-04-22T22:31:15.2Z
2019-04-22T22:36:15.463Z,1555972575.463 [Default:CheckIn:Read_GPS] Stopped
2019-04-22T22:36:15.463Z,1555972575.463 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-04-22T22:36:23.520Z,1555972583.520 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190422T221627/Courier0007.lzma
2019-04-22T22:36:24.326Z,1555972584.326 [DataOverHttps](INFO): Moved sent file to Logs/20190422T221627/Courier0007.lzma.bak
2019-04-22T22:36:24.326Z,1555972584.326 [DataOverHttps](INFO): SBD MOMSN=10736780
2019-04-22T22:36:26.527Z,1555972586.527 [CommandLine](IMPORTANT): got command configSet VerticalControl.massDefault -5.000000 millimeter
2019-04-22T22:36:30.890Z,1555972590.890 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-04-22T22:36:37.101Z,1555972597.101 [DataOverHttps](INFO): Sending 388 bytes from file Logs/20190422T221627/Express0008.lzma
2019-04-22T22:36:37.906Z,1555972597.906 [DataOverHttps](INFO): Moved sent file to Logs/20190422T221627/Express0008.lzma.bak
2019-04-22T22:36:37.907Z,1555972597.907 [DataOverHttps](INFO): SBD MOMSN=10736782
2019-04-22T22:36:39.844Z,1555972599.844 [Default:CheckIn:Read_Iridium] Stopped
2019-04-22T22:36:39.844Z,1555972599.844 [Default:CheckIn:C.Wait] Running Loop=1
2019-04-22T22:36:39.844Z,1555972599.844 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-04-22T22:36:44.542Z,1555972604.542 [CommandLine](IMPORTANT): got command get platform_pitch_angle degree
2019-04-22T22:36:44.543Z,1555972604.543 [CommandLine](IMPORTANT): platform_pitch_angle -3.319601 arcdeg
2019-04-22T22:36:58.767Z,1555972618.767 [CommandLine](IMPORTANT): got command maintain clear
2019-04-22T22:36:58.898Z,1555972618.898 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,NAL9602,Onboard,BPC1,Aanderaa_O2,ESPComponent,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-04-22T22:37:00.099Z,1555972620.099 [Reporter](INFO): platform_buoyancy_position 294.375519 cc
2019-04-22T22:37:00.475Z,1555972620.475 [Reporter](INFO): platform_buoyancy_position 294.778442 cc
2019-04-22T22:37:01.271Z,1555972621.271 [Reporter](INFO): platform_buoyancy_position 298.941742 cc
2019-04-22T22:37:01.598Z,1555972621.598 [NAL9602](INFO): Powering down
2019-04-22T22:37:01.663Z,1555972621.663 [Reporter](INFO): platform_buoyancy_position 303.239319 cc
2019-04-22T22:37:02.143Z,1555972622.143 [Reporter](INFO): platform_buoyancy_position 309.820038 cc
2019-04-22T22:37:02.467Z,1555972622.467 [Reporter](INFO): platform_buoyancy_position 312.371735 cc
2019-04-22T22:37:02.895Z,1555972622.895 [Reporter](INFO): platform_buoyancy_position 318.415222 cc
2019-04-22T22:37:03.308Z,1555972623.308 [Reporter](INFO): platform_buoyancy_position 324.593048 cc
2019-04-22T22:37:03.699Z,1555972623.699 [Reporter](INFO): platform_buoyancy_position 329.159241 cc
2019-04-22T22:37:04.083Z,1555972624.083 [Reporter](INFO): platform_buoyancy_position 333.456848 cc
2019-04-22T22:37:04.506Z,1555972624.506 [Reporter](INFO): platform_buoyancy_position 339.768951 cc
2019-04-22T22:37:04.891Z,1555972624.891 [Reporter](INFO): platform_buoyancy_position 344.872345 cc
2019-04-22T22:37:05.287Z,1555972625.287 [Reporter](INFO): platform_buoyancy_position 350.647247 cc
2019-04-22T22:37:05.711Z,1555972625.711 [Reporter](INFO): platform_buoyancy_position 355.213440 cc
2019-04-22T22:37:06.111Z,1555972626.111 [Reporter](INFO): platform_buoyancy_position 361.256927 cc
2019-04-22T22:37:06.527Z,1555972626.527 [Reporter](INFO): platform_buoyancy_position 365.688843 cc
2019-04-22T22:37:06.915Z,1555972626.915 [Reporter](INFO): platform_buoyancy_position 372.000946 cc
2019-04-22T22:37:07.315Z,1555972627.315 [Reporter](INFO): platform_buoyancy_position 376.432831 cc
2019-04-22T22:37:07.731Z,1555972627.731 [Reporter](INFO): platform_buoyancy_position 382.744934 cc
2019-04-22T22:37:08.159Z,1555972628.159 [Reporter](INFO): platform_buoyancy_position 387.176849 cc
2019-04-22T22:37:08.531Z,1555972628.531 [Reporter](INFO): platform_buoyancy_position 393.488953 cc
2019-04-22T22:37:08.939Z,1555972628.939 [Reporter](INFO): platform_buoyancy_position 397.786530 cc
2019-04-22T22:37:09.343Z,1555972629.343 [Reporter](INFO): platform_buoyancy_position 404.367249 cc
2019-04-22T22:37:09.763Z,1555972629.763 [Reporter](INFO): platform_buoyancy_position 408.530548 cc
2019-04-22T22:37:10.159Z,1555972630.159 [Reporter](INFO): platform_buoyancy_position 412.962433 cc
2019-04-22T22:37:10.559Z,1555972630.559 [Reporter](INFO): platform_buoyancy_position 419.274567 cc
2019-04-22T22:37:10.967Z,1555972630.967 [Reporter](INFO): platform_buoyancy_position 423.706451 cc
2019-04-22T22:37:11.359Z,1555972631.359 [Reporter](INFO): platform_buoyancy_position 430.152863 cc
2019-04-22T22:37:11.755Z,1555972631.755 [Reporter](INFO): platform_buoyancy_position 434.450470 cc
2019-04-22T22:37:12.163Z,1555972632.163 [Reporter](INFO): platform_buoyancy_position 440.762543 cc
2019-04-22T22:37:12.571Z,1555972632.571 [Reporter](INFO): platform_buoyancy_position 445.194427 cc
2019-04-22T22:37:12.983Z,1555972632.983 [Reporter](INFO): platform_buoyancy_position 449.894928 cc
2019-04-22T22:37:13.443Z,1555972633.443 [Reporter](INFO): platform_buoyancy_position 455.804169 cc
2019-04-22T22:37:13.783Z,1555972633.783 [Reporter](INFO): platform_buoyancy_position 460.101715 cc
2019-04-22T22:37:14.199Z,1555972634.199 [Reporter](INFO): platform_buoyancy_position 466.682465 cc
2019-04-22T22:37:14.611Z,1555972634.611 [Reporter](INFO): platform_buoyancy_position 471.517242 cc
2019-04-22T22:37:14.995Z,1555972634.995 [Reporter](INFO): platform_buoyancy_position 477.426422 cc
2019-04-22T22:37:15.399Z,1555972635.399 [Reporter](INFO): platform_buoyancy_position 481.724030 cc
2019-04-22T22:37:15.807Z,1555972635.807 [Reporter](INFO): platform_buoyancy_position 488.036163 cc
2019-04-22T22:37:16.223Z,1555972636.223 [Reporter](INFO): platform_buoyancy_position 493.542480 cc
2019-04-22T22:37:16.675Z,1555972636.675 [Reporter](INFO): platform_buoyancy_position 498.914459 cc
2019-04-22T22:37:17.023Z,1555972637.023 [Reporter](INFO): platform_buoyancy_position 503.346313 cc
2019-04-22T22:37:17.431Z,1555972637.431 [Reporter](INFO): platform_buoyancy_position 509.658478 cc
2019-04-22T22:37:17.875Z,1555972637.875 [Reporter](INFO): platform_buoyancy_position 515.970520 cc
2019-04-22T22:37:18.231Z,1555972638.231 [Reporter](INFO): platform_buoyancy_position 520.536743 cc
2019-04-22T22:37:18.671Z,1555972638.671 [Reporter](INFO): platform_buoyancy_position 525.237244 cc
2019-04-22T22:37:19.094Z,1555972639.094 [Reporter](INFO): platform_buoyancy_position 531.012146 cc
2019-04-22T22:37:19.455Z,1555972639.455 [Reporter](INFO): platform_buoyancy_position 535.444031 cc
2019-04-22T22:37:19.872Z,1555972639.872 [Reporter](INFO): platform_buoyancy_position 541.890442 cc
2019-04-22T22:37:20.284Z,1555972640.284 [Reporter](INFO): platform_buoyancy_position 546.590942 cc
2019-04-22T22:37:20.667Z,1555972640.667 [Reporter](INFO): platform_buoyancy_position 552.500122 cc
2019-04-22T22:37:21.115Z,1555972641.115 [Reporter](INFO): platform_buoyancy_position 558.006409 cc
2019-04-22T22:37:21.495Z,1555972641.495 [Reporter](INFO): platform_buoyancy_position 563.109802 cc
2019-04-22T22:37:21.867Z,1555972641.867 [Reporter](INFO): platform_buoyancy_position 567.541748 cc
2019-04-22T22:37:22.267Z,1555972642.267 [Reporter](INFO): platform_buoyancy_position 573.182312 cc
2019-04-22T22:37:22.671Z,1555972642.671 [Reporter](INFO): platform_buoyancy_position 578.285706 cc
2019-04-22T22:37:23.091Z,1555972643.091 [Reporter](INFO): platform_buoyancy_position 584.732117 cc
2019-04-22T22:37:23.495Z,1555972643.495 [Reporter](INFO): platform_buoyancy_position 589.164001 cc
2019-04-22T22:37:23.891Z,1555972643.891 [Reporter](INFO): platform_buoyancy_position 593.461609 cc
2019-04-22T22:37:24.299Z,1555972644.299 [Reporter](INFO): platform_buoyancy_position 597.893555 cc
2019-04-22T22:37:24.711Z,1555972644.711 [Reporter](INFO): platform_buoyancy_position 604.071350 cc
2019-04-22T22:37:25.102Z,1555972645.102 [Reporter](INFO): platform_buoyancy_position 609.711914 cc
2019-04-22T22:37:25.507Z,1555972645.507 [Reporter](INFO): platform_buoyancy_position 614.949646 cc
2019-04-22T22:37:25.909Z,1555972645.909 [Reporter](INFO): platform_buoyancy_position 621.261719 cc
2019-04-22T22:37:26.335Z,1555972646.335 [Reporter](INFO): platform_buoyancy_position 625.693604 cc
2019-04-22T22:37:26.727Z,1555972646.727 [Reporter](INFO): platform_buoyancy_position 630.796997 cc
2019-04-22T22:37:27.119Z,1555972647.119 [Reporter](INFO): platform_buoyancy_position 636.303345 cc
2019-04-22T22:37:27.535Z,1555972647.535 [Reporter](INFO): platform_buoyancy_position 640.869507 cc
2019-04-22T22:37:27.995Z,1555972647.995 [Reporter](INFO): platform_buoyancy_position 647.315918 cc
2019-04-22T22:37:28.335Z,1555972648.335 [Reporter](INFO): platform_buoyancy_position 651.479248 cc
2019-04-22T22:37:28.751Z,1555972648.751 [Reporter](INFO): platform_buoyancy_position 657.925659 cc
2019-04-22T22:37:29.147Z,1555972649.147 [Reporter](INFO): platform_buoyancy_position 662.223206 cc
2019-04-22T22:37:29.559Z,1555972649.559 [Reporter](INFO): platform_buoyancy_position 668.535339 cc
2019-04-22T22:37:29.939Z,1555972649.939 [Reporter](INFO): platform_buoyancy_position 672.832947 cc
2019-04-22T22:37:30.347Z,1555972650.347 [Reporter](INFO): platform_buoyancy_position 677.533447 cc
2019-04-22T22:37:30.823Z,1555972650.823 [Reporter](INFO): platform_buoyancy_position 683.845520 cc
2019-04-22T22:37:31.155Z,1555972651.155 [Reporter](INFO): platform_buoyancy_position 688.411743 cc
2019-04-22T22:37:31.611Z,1555972651.611 [Reporter](INFO): platform_buoyancy_position 694.455261 cc
2019-04-22T22:37:31.979Z,1555972651.979 [Reporter](INFO): platform_buoyancy_position 700.095825 cc
2019-04-22T22:37:32.379Z,1555972652.379 [Reporter](INFO): platform_buoyancy_position 705.199219 cc
2019-04-22T22:37:32.787Z,1555972652.787 [Reporter](INFO): platform_buoyancy_position 709.765442 cc
2019-04-22T22:37:33.175Z,1555972653.175 [Reporter](INFO): platform_buoyancy_position 715.808960 cc
2019-04-22T22:37:33.582Z,1555972653.582 [Reporter](INFO): platform_buoyancy_position 720.106506 cc
2019-04-22T22:37:33.995Z,1555972653.995 [Reporter](INFO): platform_buoyancy_position 726.687256 cc
2019-04-22T22:37:34.383Z,1555972654.383 [Reporter](INFO): platform_buoyancy_position 730.850525 cc
2019-04-22T22:37:34.791Z,1555972654.791 [Reporter](INFO): platform_buoyancy_position 737.296936 cc
2019-04-22T22:37:35.203Z,1555972655.203 [Reporter](INFO): platform_buoyancy_position 741.728821 cc
2019-04-22T22:37:35.607Z,1555972655.607 [Reporter](INFO): platform_buoyancy_position 748.040955 cc
2019-04-22T22:37:36.006Z,1555972656.006 [Reporter](INFO): platform_buoyancy_position 752.338562 cc
2019-04-22T22:37:36.407Z,1555972656.407 [Reporter](INFO): platform_buoyancy_position 756.904724 cc
2019-04-22T22:37:36.819Z,1555972656.819 [Reporter](INFO): platform_buoyancy_position 763.216858 cc
2019-04-22T22:37:37.215Z,1555972657.215 [Reporter](INFO): platform_buoyancy_position 767.648743 cc
2019-04-22T22:37:37.619Z,1555972657.619 [Reporter](INFO): platform_buoyancy_position 773.826538 cc
2019-04-22T22:37:38.019Z,1555972658.019 [Reporter](INFO): platform_buoyancy_position 778.258423 cc
2019-04-22T22:37:38.451Z,1555972658.451 [Reporter](INFO): platform_buoyancy_position 784.704834 cc
2019-04-22T22:37:38.843Z,1555972658.843 [Reporter](INFO): platform_buoyancy_position 789.808228 cc
2019-04-22T22:37:39.231Z,1555972659.231 [Reporter](INFO): platform_buoyancy_position 795.314514 cc
2019-04-22T22:37:39.639Z,1555972659.639 [Reporter](INFO): platform_buoyancy_position 799.746460 cc
2019-04-22T22:37:40.055Z,1555972660.055 [Reporter](INFO): platform_buoyancy_position 806.058533 cc
2019-04-22T22:37:40.443Z,1555972660.443 [Reporter](INFO): platform_buoyancy_position 810.490417 cc
2019-04-22T22:37:40.851Z,1555972660.851 [Reporter](INFO): platform_buoyancy_position 816.802551 cc
2019-04-22T22:37:41.259Z,1555972661.259 [Reporter](INFO): platform_buoyancy_position 821.234436 cc
2019-04-22T22:37:41.667Z,1555972661.667 [Reporter](INFO): platform_buoyancy_position 827.412231 cc
2019-04-22T22:37:42.083Z,1555972662.083 [Reporter](INFO): platform_buoyancy_position 831.978455 cc
2019-04-22T22:37:42.559Z,1555972662.559 [Reporter](INFO): platform_buoyancy_position 838.290527 cc
2019-04-22T22:37:42.880Z,1555972662.880 [Reporter](INFO): platform_buoyancy_position 842.722473 cc
2019-04-22T22:37:43.295Z,1555972663.295 [Reporter](INFO): platform_buoyancy_position 848.094421 cc
2019-04-22T22:37:43.699Z,1555972663.699 [Reporter](INFO): platform_buoyancy_position 853.466431 cc
2019-04-22T22:37:44.075Z,1555972664.075 [Reporter](INFO): platform_buoyancy_position 857.764038 cc
2019-04-22T22:37:44.483Z,1555972664.483 [Reporter](INFO): platform_buoyancy_position 863.941833 cc
2019-04-22T22:37:44.895Z,1555972664.895 [Reporter](INFO): platform_buoyancy_position 868.508057 cc
2019-04-22T22:37:45.379Z,1555972665.379 [Reporter](INFO): platform_buoyancy_position 874.954468 cc
2019-04-22T22:37:45.735Z,1555972665.735 [Reporter](INFO): platform_buoyancy_position 879.252075 cc
2019-04-22T22:37:46.135Z,1555972666.135 [Reporter](INFO): platform_buoyancy_position 885.564148 cc
2019-04-22T22:37:46.511Z,1555972666.511 [Reporter](INFO): platform_buoyancy_position 889.996033 cc
2019-04-22T22:37:46.907Z,1555972666.907 [Reporter](INFO): platform_buoyancy_position 894.965149 cc
2019-04-22T22:37:47.311Z,1555972667.311 [Reporter](INFO): platform_buoyancy_position 900.605774 cc
2019-04-22T22:37:47.719Z,1555972667.719 [Reporter](INFO): platform_buoyancy_position 907.052124 cc
2019-04-22T22:37:48.158Z,1555972668.158 [Reporter](INFO): platform_buoyancy_position 911.618347 cc
2019-04-22T22:37:48.551Z,1555972668.551 [Reporter](INFO): platform_buoyancy_position 917.527527 cc
2019-04-22T22:37:48.955Z,1555972668.955 [Reporter](INFO): platform_buoyancy_position 922.093750 cc
2019-04-22T22:37:49.394Z,1555972669.394 [Reporter](INFO): platform_buoyancy_position 928.540161 cc
2019-04-22T22:37:49.755Z,1555972669.755 [Reporter](INFO): platform_buoyancy_position 932.837769 cc
2019-04-22T22:37:50.179Z,1555972670.179 [Reporter](INFO): platform_buoyancy_position 937.269653 cc
2019-04-22T22:37:54.231Z,1555972674.231 [Reporter](INFO): platform_buoyancy_position 954.460083 cc
2019-04-22T22:41:40.409Z,1555972900.409 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-04-22T22:41:40.409Z,1555972900.409 [Default:CheckIn:C.Wait] Stopped
2019-04-22T22:41:40.409Z,1555972900.409 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-04-22T22:41:40.409Z,1555972900.409 [Default:CheckIn:D] Running Loop=1
2019-04-22T22:41:40.806Z,1555972900.806 [Default:CheckIn:D] Stopped
2019-04-22T22:41:40.806Z,1555972900.806 [Default:CheckIn:E] Running Loop=1
2019-04-22T22:41:41.206Z,1555972901.206 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 21.732220 min 
2019-04-22T22:41:41.206Z,1555972901.206 [Default:CheckIn:E] Stopped
2019-04-22T22:41:41.206Z,1555972901.206 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-04-22T22:41:41.207Z,1555972901.207 [Default:CheckIn] Stopped
2019-04-22T22:41:41.207Z,1555972901.207 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-04-22T22:41:41.207Z,1555972901.207 [Default:CheckIn](INFO): Running loop #3
2019-04-22T22:41:41.207Z,1555972901.207 [Default:CheckIn] Running Loop=3
2019-04-22T22:41:41.207Z,1555972901.207 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-04-22T22:41:41.207Z,1555972901.207 [Default:CheckIn:Read_GPS] Running Loop=1
2019-04-22T22:41:41.990Z,1555972901.990 [NAL9602](INFO): Powering up
2019-04-22T22:41:52.894Z,1555972912.894 [NAL9602](INFO): NAL9602 initialized
2019-04-22T22:41:53.702Z,1555972913.702 [NAL9602](FAULT): GPS failed to acquire within timeout.
2019-04-22T22:41:53.702Z,1555972913.702 [NAL9602] Data Fault, FailCount= 2
2019-04-22T22:41:53.702Z,1555972913.702 [NAL9602](ERROR): Data Fault
2019-04-22T22:41:53.781Z,1555972913.781 [CBIT](ERROR): Data Fault in component: NAL9602
2019-04-22T22:41:54.110Z,1555972914.110 [NAL9602](INFO): Powering down
2019-04-22T22:41:54.953Z,1555972914.953 [CBIT](INFO): Clearing failed state for component NAL9602
2019-04-22T22:41:54.954Z,1555972914.954 [NAL9602] No Fault, FailCount= 2
2019-04-22T22:42:24.426Z,1555972944.426 [NAL9602](INFO): Powering up NAL9602
2019-04-22T22:42:35.334Z,1555972955.334 [NAL9602](INFO): NAL9602 initialized
2019-04-22T22:42:36.153Z,1555972956.153 [NAL9602](DEBUG): Fix Requested
2019-04-22T22:43:47.104Z,1555973027.104 [CommandLine](IMPORTANT): got command failComponent
2019-04-22T22:43:47.104Z,1555973027.104 [CommandLine](IMPORTANT): Failed components:
2019-04-22T22:43:47.105Z,1555973027.105 [CommandLine](IMPORTANT): No failed Components.
2019-04-22T22:44:02.872Z,1555973042.872 [CommandLine](IMPORTANT): got command restart application
2019-04-22T22:44:03.881Z,1555973043.881 [Supervisor](INFO): Stop Mission called by Supervisor::terminate
2019-04-22T22:44:03.881Z,1555973043.881 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2019-04-22T22:44:03.882Z,1555973043.882 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-04-22T22:44:03.941Z,1555973043.941 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2019-04-22T22:44:03.941Z,1555973043.941 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-04-22T22:44:03.942Z,1555973043.942 [CommandLine](INFO): Join timeout helper Thread ID is 1002
2019-04-22T22:44:03.942Z,1555973043.942 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2019-04-22T22:44:03.942Z,1555973043.942 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-04-22T22:44:03.943Z,1555973043.943 [NavChartDb](INFO): Join timeout helper Thread ID is 1003
2019-04-22T22:44:04.265Z,1555973044.265 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2019-04-22T22:44:04.265Z,1555973044.265 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-04-22T22:44:04.285Z,1555973044.285 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2019-04-22T22:44:04.285Z,1555973044.285 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-04-22T22:44:04.285Z,1555973044.285 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 1004
2019-04-22T22:44:04.677Z,1555973044.677 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2019-04-22T22:44:04.678Z,1555973044.678 [WetLabsBB2FL](INFO): Powering down
2019-04-22T22:44:04.678Z,1555973044.678 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-04-22T22:44:04.681Z,1555973044.681 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2019-04-22T22:44:04.681Z,1555973044.681 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2019-04-22T22:44:04.681Z,1555973044.681 [CTD_Seabird](INFO): Join timeout helper Thread ID is 1005
2019-04-22T22:44:04.821Z,1555973044.821 [CTD_Seabird](INFO): Powering down
2019-04-22T22:44:04.833Z,1555973044.833 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2019-04-22T22:44:04.833Z,1555973044.833 [CTD_Seabird](INFO): Powering down
2019-04-22T22:44:04.845Z,1555973044.845 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2019-04-22T22:44:04.845Z,1555973044.845 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2019-04-22T22:44:04.845Z,1555973044.845 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-04-22T22:44:04.846Z,1555973044.846 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 1006
2019-04-22T22:44:04.977Z,1555973044.977 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread.
2019-04-22T22:44:04.977Z,1555973044.977 [CTD_NeilBrown](INFO): Powering down
2019-04-22T22:44:04.989Z,1555973044.989 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-04-22T22:44:04.990Z,1555973044.990 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2019-04-22T22:44:04.990Z,1555973044.990 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-04-22T22:44:04.991Z,1555973044.991 [Radio_Surface](INFO): Join timeout helper Thread ID is 1007
2019-04-22T22:44:05.205Z,1555973045.205 [Radio_Surface](INFO): Powering down
2019-04-22T22:44:05.206Z,1555973045.206 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2019-04-22T22:44:05.207Z,1555973045.207 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-04-22T22:44:05.210Z,1555973045.210 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2019-04-22T22:44:05.210Z,1555973045.210 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-04-22T22:44:05.210Z,1555973045.210 [DataOverHttps](INFO): Join timeout helper Thread ID is 1008
2019-04-22T22:44:05.581Z,1555973045.581 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2019-04-22T22:44:05.581Z,1555973045.581 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-04-22T22:44:05.594Z,1555973045.594 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2019-04-22T22:44:05.594Z,1555973045.594 [logger ThreadHandler](INFO): Thread cancelled.
2019-04-22T22:44:05.594Z,1555973045.594 [logger](INFO): Join timeout helper Thread ID is 1009
2019-04-22T22:44:05.621Z,1555973045.621 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2019-04-22T22:44:05.621Z,1555973045.621 [logger ThreadHandler](INFO): Thread cancelled.
2019-04-22T22:44:05.634Z,1555973045.634 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2019-04-22T22:44:05.634Z,1555973045.634 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-04-22T22:44:05.634Z,1555973045.634 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2019-04-22T22:44:05.634Z,1555973045.634 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-04-22T22:44:05.634Z,1555973045.634 [controlThread](INFO): Join timeout helper Thread ID is 1010
2019-04-22T22:44:05.813Z,1555973045.813 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2019-04-22T22:44:05.813Z,1555973045.813 [controlThread](DEBUG): Uninitializing ControlThread
2019-04-22T22:44:05.814Z,1555973045.814 [AHRS_M2](INFO): Powering down
2019-04-22T22:44:05.885Z,1555973045.885 [NAL9602](INFO): Powering down
2019-04-22T22:44:05.887Z,1555973045.887 [Aanderaa_O2](INFO): Powering down
2019-04-22T22:44:05.890Z,1555973045.890 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2019-04-22T22:44:05.891Z,1555973045.891 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2019-04-22T22:44:05.891Z,1555973045.891 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2019-04-22T22:44:05.892Z,1555973045.892 [MissionManager](INFO): Uninitializing Mission Default
2019-04-22T22:44:05.892Z,1555973045.892 [Default] Stopped
2019-04-22T22:44:05.892Z,1555973045.892 [Default](DEBUG): Aggregate::uninitialize Default
2019-04-22T22:44:05.892Z,1555973045.892 [Default:B.GoToSurface] Stopped
2019-04-22T22:44:05.892Z,1555973045.892 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-04-22T22:44:05.892Z,1555973045.892 [Default:CheckIn] Stopped
2019-04-22T22:44:05.892Z,1555973045.892 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-04-22T22:44:05.892Z,1555973045.892 [Default:CheckIn:Read_GPS] Stopped
2019-04-22T22:44:05.895Z,1555973045.895 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2019-04-22T22:44:05.895Z,1555973045.895 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2019-04-22T22:44:05.895Z,1555973045.895 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2019-04-22T22:44:05.896Z,1555973045.896 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2019-04-22T22:44:05.896Z,1555973045.896 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2019-04-22T22:44:05.896Z,1555973045.896 [BuoyancyServo](INFO): Powering down
2019-04-22T22:44:05.909Z,1555973045.909 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2019-04-22T22:44:05.909Z,1555973045.909 [ElevatorServo](INFO): Powering down
2019-04-22T22:44:05.910Z,1555973045.910 [MassServo](DEBUG): Uninitialize Mass Servo.
2019-04-22T22:44:05.910Z,1555973045.910 [MassServo](INFO): Powering down
2019-04-22T22:44:05.911Z,1555973045.911 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-04-22T22:44:05.911Z,1555973045.911 [RudderServo](INFO): Powering down
2019-04-22T22:44:05.912Z,1555973045.912 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2019-04-22T22:44:05.912Z,1555973045.912 [ThrusterServo](INFO): Powering down
2019-04-22T22:44:05.912Z,1555973045.912 [SBIT](DEBUG): Uninitialize SBIT Component.
2019-04-22T22:44:05.913Z,1555973045.913 [IBIT](DEBUG): Uninitialize IBIT Component.
2019-04-22T22:44:05.913Z,1555973045.913 [CBIT](DEBUG): Uninitialize CBIT Component.
2019-04-22T22:44:05.913Z,1555973045.913 [CBIT](DEBUG): Powering off loads.
2019-04-22T22:44:05.925Z,1555973045.925 [CBIT](DEBUG): Disabling WDT.
2019-04-22T22:44:05.937Z,1555973045.937 [CBIT](DEBUG): Opening all GF detection circuits.
2019-04-22T22:44:05.938Z,1555973045.938 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-04-22T22:44:06.023Z,1555973046.023 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-04-22T22:44:06.029Z,1555973046.029 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-04-22T22:44:06.059Z,1555973046.059 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-04-22T22:44:06.063Z,1555973046.063 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2019-04-22T22:44:06.066Z,1555973046.066 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-04-22T22:44:06.102Z,1555973046.102 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-04-22T22:44:06.167Z,1555973046.167 [logger ThreadHandler](INFO): Thread cancelled.