2019-07-25T21:19:32.701Z,1564089572.701 [Supervisor](DEBUG): Initializing supervisor.
2019-07-25T21:19:32.705Z,1564089572.705 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2019-07-25T21:19:32.705Z,1564089572.705 [SyncHandler](INFO): Protected caller Thread ID is 5765
2019-07-25T21:19:32.706Z,1564089572.706 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2019-07-25T21:19:32.707Z,1564089572.707 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2019-07-25T21:19:32.707Z,1564089572.707 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 5766
2019-07-25T21:19:32.711Z,1564089572.711 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2019-07-25T21:19:32.723Z,1564089572.723 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2019-07-25T21:19:32.724Z,1564089572.724 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2019-07-25T21:19:32.725Z,1564089572.725 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 5767
2019-07-25T21:19:32.726Z,1564089572.726 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2019-07-25T21:19:32.727Z,1564089572.727 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2019-07-25T21:19:32.727Z,1564089572.727 [logger ThreadHandler](INFO): Protected caller Thread ID is 5768
2019-07-25T21:19:32.729Z,1564089572.729 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2019-07-25T21:19:32.729Z,1564089572.729 [Supervisor](INFO): Looking for Config files in directory: Config/
2019-07-25T21:19:32.731Z,1564089572.731 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2019-07-25T21:19:32.830Z,1564089572.830 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2019-07-25T21:19:32.831Z,1564089572.831 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2019-07-25T21:19:33.044Z,1564089573.044 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2019-07-25T21:19:33.044Z,1564089573.044 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2019-07-25T21:19:33.188Z,1564089573.188 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2019-07-25T21:19:33.188Z,1564089573.188 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2019-07-25T21:19:33.786Z,1564089573.786 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2019-07-25T21:19:33.787Z,1564089573.787 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2019-07-25T21:19:34.257Z,1564089574.257 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2019-07-25T21:19:34.258Z,1564089574.258 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2019-07-25T21:19:34.762Z,1564089574.762 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2019-07-25T21:19:34.762Z,1564089574.762 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2019-07-25T21:19:35.086Z,1564089575.086 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2019-07-25T21:19:35.087Z,1564089575.087 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2019-07-25T21:19:35.444Z,1564089575.444 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2019-07-25T21:19:35.445Z,1564089575.445 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2019-07-25T21:19:35.863Z,1564089575.863 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2019-07-25T21:19:35.863Z,1564089575.863 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2019-07-25T21:19:36.020Z,1564089576.020 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2019-07-25T21:19:36.020Z,1564089576.020 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2019-07-25T21:19:36.130Z,1564089576.130 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2019-07-25T21:19:36.131Z,1564089576.131 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2019-07-25T21:19:36.215Z,1564089576.215 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2019-07-25T21:19:36.356Z,1564089576.356 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2019-07-25T21:19:36.356Z,1564089576.356 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2019-07-25T21:19:36.993Z,1564089576.993 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2019-07-25T21:19:36.994Z,1564089576.994 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2019-07-25T21:19:37.224Z,1564089577.224 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2019-07-25T21:19:37.226Z,1564089577.226 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/
2019-07-25T21:19:37.227Z,1564089577.227 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg
2019-07-25T21:19:37.314Z,1564089577.314 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg
2019-07-25T21:19:37.550Z,1564089577.550 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2019-07-25T21:19:37.551Z,1564089577.551 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg
2019-07-25T21:19:37.652Z,1564089577.652 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg
2019-07-25T21:19:37.833Z,1564089577.833 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg
2019-07-25T21:19:38.062Z,1564089578.062 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg
2019-07-25T21:19:38.152Z,1564089578.152 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg
2019-07-25T21:19:38.260Z,1564089578.260 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg
2019-07-25T21:19:38.359Z,1564089578.359 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg
2019-07-25T21:19:38.528Z,1564089578.528 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg
2019-07-25T21:19:38.641Z,1564089578.641 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg
2019-07-25T21:19:38.745Z,1564089578.745 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/root/
2019-07-25T21:19:38.746Z,1564089578.746 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2019-07-25T21:19:38.752Z,1564089578.752 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2019-07-25T21:19:38.854Z,1564089578.854 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2019-07-25T21:19:38.855Z,1564089578.855 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2019-07-25T21:19:38.988Z,1564089578.988 [BuoyancyServo] Loaded
2019-07-25T21:19:38.989Z,1564089578.989 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2019-07-25T21:19:39.004Z,1564089579.004 [ElevatorServo] Loaded
2019-07-25T21:19:39.004Z,1564089579.004 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2019-07-25T21:19:39.019Z,1564089579.019 [MassServo] Loaded
2019-07-25T21:19:39.019Z,1564089579.019 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2019-07-25T21:19:39.034Z,1564089579.034 [RudderServo] Loaded
2019-07-25T21:19:39.035Z,1564089579.035 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2019-07-25T21:19:39.049Z,1564089579.049 [ThrusterServo] Loaded
2019-07-25T21:19:39.050Z,1564089579.050 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2019-07-25T21:19:39.050Z,1564089579.050 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2019-07-25T21:19:39.051Z,1564089579.051 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2019-07-25T21:19:39.189Z,1564089579.189 [SBIT](DEBUG): Construct Startup Built In Test.
2019-07-25T21:19:39.220Z,1564089579.220 [SBIT] Loaded
2019-07-25T21:19:39.220Z,1564089579.220 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2019-07-25T21:19:39.220Z,1564089579.220 [IBIT](DEBUG): Construct Initiated Built In Test.
2019-07-25T21:19:39.248Z,1564089579.248 [IBIT] Loaded
2019-07-25T21:19:39.249Z,1564089579.249 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2019-07-25T21:19:39.252Z,1564089579.252 [CBIT](DEBUG): Construct Continuous Built In Test.
2019-07-25T21:19:39.647Z,1564089579.647 [CBIT] Loaded
2019-07-25T21:19:39.647Z,1564089579.647 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2019-07-25T21:19:39.647Z,1564089579.647 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2019-07-25T21:19:39.648Z,1564089579.648 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2019-07-25T21:19:39.841Z,1564089579.841 [Aanderaa_O2] Loaded
2019-07-25T21:19:39.841Z,1564089579.841 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2019-07-25T21:19:39.851Z,1564089579.851 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_density
2019-07-25T21:19:39.856Z,1564089579.856 [CTD_Seabird](INFO): created writer for : sea_water_density
2019-07-25T21:19:39.858Z,1564089579.858 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): depth
2019-07-25T21:19:39.863Z,1564089579.863 [CTD_Seabird](INFO): created writer for : depth
2019-07-25T21:19:39.864Z,1564089579.864 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_pressure
2019-07-25T21:19:39.869Z,1564089579.869 [CTD_Seabird](INFO): created writer for : sea_water_pressure
2019-07-25T21:19:39.869Z,1564089579.869 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_salinity
2019-07-25T21:19:39.875Z,1564089579.875 [CTD_Seabird](INFO): created writer for : sea_water_salinity
2019-07-25T21:19:39.875Z,1564089579.875 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_temperature
2019-07-25T21:19:39.881Z,1564089579.881 [CTD_Seabird](INFO): created writer for : sea_water_temperature
2019-07-25T21:19:39.881Z,1564089579.881 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_electrical_conductivity
2019-07-25T21:19:39.887Z,1564089579.887 [CTD_Seabird](INFO): created writer for : sea_water_electrical_conductivity
2019-07-25T21:19:39.887Z,1564089579.887 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): speed_of_sound_in_sea_water
2019-07-25T21:19:39.892Z,1564089579.892 [CTD_Seabird](INFO): created writer for : speed_of_sound_in_sea_water
2019-07-25T21:19:39.919Z,1564089579.919 [CTD_Seabird] Loaded
2019-07-25T21:19:39.920Z,1564089579.920 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2019-07-25T21:19:39.921Z,1564089579.921 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 4066B4E0
2019-07-25T21:19:39.921Z,1564089579.921 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 5847
2019-07-25T21:19:39.952Z,1564089579.952 [ESPComponent] Loaded
2019-07-25T21:19:39.953Z,1564089579.953 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2019-07-25T21:19:39.967Z,1564089579.967 [PAR_Licor] Loaded
2019-07-25T21:19:39.967Z,1564089579.967 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2019-07-25T21:19:40.016Z,1564089580.016 [WetLabsBB2FL] Loaded
2019-07-25T21:19:40.016Z,1564089580.016 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2019-07-25T21:19:40.017Z,1564089580.017 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 4069B4E0
2019-07-25T21:19:40.018Z,1564089580.018 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 5848
2019-07-25T21:19:40.019Z,1564089580.019 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2019-07-25T21:19:40.019Z,1564089580.019 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2019-07-25T21:19:40.062Z,1564089580.062 [DepthRateCalculator] Loaded
2019-07-25T21:19:40.062Z,1564089580.062 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2019-07-25T21:19:40.068Z,1564089580.068 [PitchRateCalculator] Loaded
2019-07-25T21:19:40.068Z,1564089580.068 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2019-07-25T21:19:40.084Z,1564089580.084 [SpeedCalculator] Loaded
2019-07-25T21:19:40.085Z,1564089580.085 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2019-07-25T21:19:40.106Z,1564089580.106 [TempGradientCalculator] Loaded
2019-07-25T21:19:40.106Z,1564089580.106 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2019-07-25T21:19:40.112Z,1564089580.112 [YawRateCalculator] Loaded
2019-07-25T21:19:40.112Z,1564089580.112 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2019-07-25T21:19:40.146Z,1564089580.146 [ElevatorOffsetCalculator] Loaded
2019-07-25T21:19:40.146Z,1564089580.146 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2019-07-25T21:19:40.147Z,1564089580.147 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2019-07-25T21:19:40.147Z,1564089580.147 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2019-07-25T21:19:40.180Z,1564089580.180 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2019-07-25T21:19:40.181Z,1564089580.181 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2019-07-25T21:19:40.287Z,1564089580.287 [DeadReckonUsingMultipleVelocitySources] Loaded
2019-07-25T21:19:40.288Z,1564089580.288 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2019-07-25T21:19:40.309Z,1564089580.309 [NavChart] Loaded
2019-07-25T21:19:40.310Z,1564089580.310 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2019-07-25T21:19:40.314Z,1564089580.314 [UniversalFixResidualReporter] Loaded
2019-07-25T21:19:40.314Z,1564089580.314 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2019-07-25T21:19:40.314Z,1564089580.314 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2019-07-25T21:19:40.315Z,1564089580.315 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2019-07-25T21:19:40.680Z,1564089580.680 [AHRS_M2] Loaded
2019-07-25T21:19:40.680Z,1564089580.680 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2019-07-25T21:19:40.756Z,1564089580.756 [DataOverHttps] Loaded
2019-07-25T21:19:40.756Z,1564089580.756 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2019-07-25T21:19:40.757Z,1564089580.757 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 409744E0
2019-07-25T21:19:40.758Z,1564089580.758 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 5849
2019-07-25T21:19:40.771Z,1564089580.771 [Depth_Keller] Loaded
2019-07-25T21:19:40.771Z,1564089580.771 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2019-07-25T21:19:40.776Z,1564089580.776 [DropWeight] Loaded
2019-07-25T21:19:40.776Z,1564089580.776 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2019-07-25T21:19:40.910Z,1564089580.910 [DVL_micro] Loaded
2019-07-25T21:19:40.911Z,1564089580.911 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread.
2019-07-25T21:19:41.003Z,1564089581.003 [NAL9602] Loaded
2019-07-25T21:19:41.003Z,1564089581.003 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2019-07-25T21:19:41.009Z,1564089581.009 [Onboard] Loaded
2019-07-25T21:19:41.009Z,1564089581.009 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2019-07-25T21:19:41.012Z,1564089581.012 [Radio_Surface] Loaded
2019-07-25T21:19:41.012Z,1564089581.012 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2019-07-25T21:19:41.013Z,1564089581.013 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409A44E0
2019-07-25T21:19:41.014Z,1564089581.014 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 5850
2019-07-25T21:19:41.145Z,1564089581.145 [DAT] Loaded
2019-07-25T21:19:41.145Z,1564089581.145 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread.
2019-07-25T21:19:42.847Z,1564089582.847 [BPC1] Loaded
2019-07-25T21:19:42.848Z,1564089582.848 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2019-07-25T21:19:42.848Z,1564089582.848 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2019-07-25T21:19:42.849Z,1564089582.849 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2019-07-25T21:19:42.924Z,1564089582.924 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2019-07-25T21:19:42.924Z,1564089582.924 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2019-07-25T21:19:42.993Z,1564089582.993 [VerticalControl](DEBUG): Construct VerticalControl.
2019-07-25T21:19:43.078Z,1564089583.078 [VerticalControl] Loaded
2019-07-25T21:19:43.079Z,1564089583.079 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2019-07-25T21:19:43.079Z,1564089583.079 [HorizontalControl](DEBUG): Construct HorizontalControl.
2019-07-25T21:19:43.138Z,1564089583.138 [HorizontalControl] Loaded
2019-07-25T21:19:43.139Z,1564089583.139 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2019-07-25T21:19:43.139Z,1564089583.139 [SpeedControl](DEBUG): Construct SpeedControl.
2019-07-25T21:19:43.141Z,1564089583.141 [SpeedControl] Loaded
2019-07-25T21:19:43.141Z,1564089583.141 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2019-07-25T21:19:43.142Z,1564089583.142 [LoopControl](DEBUG): Construct LoopControl.
2019-07-25T21:19:43.143Z,1564089583.143 [LoopControl] Loaded
2019-07-25T21:19:43.143Z,1564089583.143 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2019-07-25T21:19:43.143Z,1564089583.143 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2019-07-25T21:19:43.144Z,1564089583.144 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2019-07-25T21:19:43.158Z,1564089583.158 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2019-07-25T21:19:43.158Z,1564089583.158 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2019-07-25T21:19:43.457Z,1564089583.457 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2019-07-25T21:19:43.461Z,1564089583.461 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2019-07-25T21:19:43.462Z,1564089583.462 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2019-07-25T21:19:43.469Z,1564089583.469 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2019-07-25T21:19:43.470Z,1564089583.470 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40ADF4E0
2019-07-25T21:19:43.470Z,1564089583.470 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 5851
2019-07-25T21:19:43.475Z,1564089583.475 [Supervisor](INFO): Main Thread ID is 4408
2019-07-25T21:19:43.475Z,1564089583.475 [Supervisor](DEBUG): Running supervisor.
2019-07-25T21:19:43.476Z,1564089583.476 [CommandLine ThreadHandler](INFO): Handler Thread ID is 5852
2019-07-25T21:19:43.478Z,1564089583.478 [controlThread ThreadHandler](INFO): Handler Thread ID is 5853
2019-07-25T21:19:43.479Z,1564089583.479 [controlThread](DEBUG): Initializing ControlThread
2019-07-25T21:19:43.481Z,1564089583.481 [SBIT](INFO): Initialize SBIT Component.
2019-07-25T21:19:43.481Z,1564089583.481 [SBIT](IMPORTANT): git: 2019-07-25
2019-07-25T21:19:43.481Z,1564089583.481 [SBIT](INFO): git hash: 199ea7540e13e92b1841ff66eb0cd68f22a07869
2019-07-25T21:19:43.482Z,1564089583.482 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2019-07-25T21:19:43.483Z,1564089583.483 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
Kernel Reported: #1 PREEMPT Thu Feb 21 11:17:40 PST 2019
2019-07-25T21:19:43.484Z,1564089583.484 [SBIT](INFO): Beginning SBIT in 74.000000 seconds.
2019-07-25T21:19:43.485Z,1564089583.485 [IBIT](INFO): Initialize IBIT Component.
2019-07-25T21:19:43.485Z,1564089583.485 [CBIT](DEBUG): Initialize CBIT Component.
2019-07-25T21:19:43.486Z,1564089583.486 [logger ThreadHandler](INFO): Handler Thread ID is 5854
2019-07-25T21:19:43.498Z,1564089583.498 [CBIT](DEBUG): Initialized mux pins.
2019-07-25T21:19:43.498Z,1564089583.498 [CBIT](DEBUG): Initializing the watchdog timer.
2019-07-25T21:19:43.506Z,1564089583.506 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 5855
2019-07-25T21:19:43.507Z,1564089583.507 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2019-07-25T21:19:43.511Z,1564089583.511 [CTD_Seabird](INFO): Opening uart, block timeout 10ths=20
2019-07-25T21:19:43.512Z,1564089583.512 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 5857
2019-07-25T21:19:43.513Z,1564089583.513 [WetLabsBB2FL](INFO): Powering down
2019-07-25T21:19:43.522Z,1564089583.522 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2019-07-25T21:19:43.522Z,1564089583.522 [CBIT](DEBUG): Initializing heartbeat.
2019-07-25T21:19:43.542Z,1564089583.542 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 5858
2019-07-25T21:19:43.543Z,1564089583.543 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2019-07-25T21:19:43.554Z,1564089583.554 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 5859
2019-07-25T21:19:43.570Z,1564089583.570 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 5860
2019-07-25T21:19:43.574Z,1564089583.574 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2019-07-25T21:19:43.574Z,1564089583.574 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2019-07-25T21:19:43.574Z,1564089583.574 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2019-07-25T21:19:43.574Z,1564089583.574 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2019-07-25T21:19:43.575Z,1564089583.575 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2019-07-25T21:19:43.575Z,1564089583.575 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2019-07-25T21:19:43.575Z,1564089583.575 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2019-07-25T21:19:43.575Z,1564089583.575 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2019-07-25T21:19:43.575Z,1564089583.575 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2019-07-25T21:19:43.575Z,1564089583.575 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2019-07-25T21:19:43.576Z,1564089583.576 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2019-07-25T21:19:43.576Z,1564089583.576 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2019-07-25T21:19:43.576Z,1564089583.576 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2019-07-25T21:19:43.576Z,1564089583.576 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2019-07-25T21:19:43.576Z,1564089583.576 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2019-07-25T21:19:43.576Z,1564089583.576 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2019-07-25T21:19:43.594Z,1564089583.594 [CBIT](DEBUG): Deactivating GF circuits.
2019-07-25T21:19:43.594Z,1564089583.594 [CBIT](DEBUG): Deactivating emergency mode.
2019-07-25T21:19:43.630Z,1564089583.630 [CBIT](DEBUG): Backplane powered.
2019-07-25T21:19:43.635Z,1564089583.635 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2019-07-25T21:19:43.635Z,1564089583.635 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2019-07-25T21:19:43.635Z,1564089583.635 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2019-07-25T21:19:43.636Z,1564089583.636 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2019-07-25T21:19:43.636Z,1564089583.636 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2019-07-25T21:19:43.636Z,1564089583.636 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2019-07-25T21:19:43.638Z,1564089583.638 [NavChart](DEBUG): Initialize NavChart Navigation.
2019-07-25T21:19:43.638Z,1564089583.638 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2019-07-25T21:19:43.649Z,1564089583.649 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2019-07-25T21:19:43.659Z,1564089583.659 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2019-07-25T21:19:43.659Z,1564089583.659 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2019-07-25T21:19:43.660Z,1564089583.660 [LoopControl](DEBUG): Initialize LoopControlComponent.
2019-07-25T21:19:43.660Z,1564089583.660 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2019-07-25T21:19:43.696Z,1564089583.696 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2019-07-25T21:19:43.743Z,1564089583.743 [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-07-25T21:19:43.744Z,1564089583.744 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2019-07-25T21:19:43.829Z,1564089583.829 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2019-07-25T21:19:43.830Z,1564089583.830 [Default:A.Wait](DEBUG): Construct Wait.
2019-07-25T21:19:43.832Z,1564089583.832 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2019-07-25T21:19:43.862Z,1564089583.862 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2019-07-25T21:19:43.865Z,1564089583.865 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2019-07-25T21:19:43.907Z,1564089583.907 [Default:E.Execute](DEBUG): Construct Execute.
2019-07-25T21:19:43.910Z,1564089583.910 [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-07-25T21:19:43.935Z,1564089583.935 [controlThread](DEBUG): Component order: CycleStarter,Aanderaa_O2,ESPComponent,PAR_Licor,AHRS_M2,Depth_Keller,DropWeight,DVL_micro,NAL9602,Onboard,DAT,BPC1,PAR_Licor,Depth_Keller,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-07-25T21:19:43.958Z,1564089583.958 [Radio_Surface](INFO): Powering up
2019-07-25T21:19:43.967Z,1564089583.967 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2019-07-25T21:19:44.115Z,1564089584.115 [DVL_micro](INFO): Initializing
2019-07-25T21:19:44.151Z,1564089584.151 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2
2019-07-25T21:19:44.151Z,1564089584.151 [DAT](INFO): Powering up
2019-07-25T21:19:44.151Z,1564089584.151 [DAT](DEBUG): Initializing DAT.
2019-07-25T21:19:44.179Z,1564089584.179 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2
2019-07-25T21:19:44.256Z,1564089584.256 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2019-07-25T21:19:44.262Z,1564089584.262 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2019-07-25T21:19:44.264Z,1564089584.264 [ElevatorServo](DEBUG): Initializing EZServoServo.
2019-07-25T21:19:44.274Z,1564089584.274 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2019-07-25T21:19:44.275Z,1564089584.275 [MassServo](DEBUG): Initializing EZServoServo.
2019-07-25T21:19:44.286Z,1564089584.286 [MassServo](DEBUG): Initializing MassServo.
2019-07-25T21:19:44.287Z,1564089584.287 [RudderServo](DEBUG): Initializing EZServoServo.
2019-07-25T21:19:44.298Z,1564089584.298 [RudderServo](DEBUG): Initializing RudderServo.
2019-07-25T21:19:44.299Z,1564089584.299 [ThrusterServo](DEBUG): Initializing EZServoServo.
2019-07-25T21:19:44.313Z,1564089584.313 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2019-07-25T21:19:45.102Z,1564089585.102 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2019-07-25T21:19:45.102Z,1564089585.102 [RudderServo](FAULT): Rudder failed to initialize
2019-07-25T21:19:45.102Z,1564089585.102 [RudderServo] Communications Fault, FailCount= 1
2019-07-25T21:19:45.102Z,1564089585.102 [RudderServo](ERROR): Communications Fault
2019-07-25T21:19:45.273Z,1564089585.273 [CBIT](ERROR): Communications Fault in component: RudderServo
2019-07-25T21:19:45.471Z,1564089585.471 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-07-25T21:19:45.471Z,1564089585.471 [RudderServo](INFO): Powering down
2019-07-25T21:19:46.141Z,1564089586.141 [RudderServo](DEBUG): Initializing EZServoServo.
2019-07-25T21:19:46.275Z,1564089586.275 [RudderServo](DEBUG): Initializing RudderServo.
2019-07-25T21:19:46.279Z,1564089586.279 [CBIT](INFO): Clearing failed state for component RudderServo
2019-07-25T21:19:46.279Z,1564089586.279 [RudderServo] No Fault, FailCount= 1
2019-07-25T21:19:47.418Z,1564089587.418 [Aanderaa_O2](INFO): Powering down
2019-07-25T21:19:50.563Z,1564089590.563 [CTD_Seabird](ERROR): Device message queue exceeded the allowed limit.
2019-07-25T21:19:59.446Z,1564089599.446 [DAT](INFO): setting local address to 3
2019-07-25T21:19:59.847Z,1564089599.847 [DAT](INFO): set local address to 3
2019-07-25T21:20:11.144Z,1564089611.144 [NAL9602](INFO): Powering up NAL9602
2019-07-25T21:20:22.052Z,1564089622.052 [NAL9602](INFO): NAL9602 initialized
2019-07-25T21:20:22.898Z,1564089622.898 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:20:32.567Z,1564089632.567 [DVL_micro](ERROR): only read 45 of 46 data items
2019-07-25T21:20:32.567Z,1564089632.567 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 0 0 0 0 238 1515 1887 397 2 3 2 2 -2200.8 1492.1 1088.5 2 1929.8 1829.0 1088.5 2 -2200 1492 1088 229 1088 2 -13.33 -1.46 257.6 -3.0 20.8 0.005 35.0 1489 112
2019-07-25T21:20:58.039Z,1564089658.039 [SBIT](IMPORTANT): Beginning Startup BIT
2019-07-25T21:20:58.043Z,1564089658.043 [CBIT](IMPORTANT): Beginning ground fault scan
2019-07-25T21:21:09.078Z,1564089669.078 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.096331
CHAN A1 (24V): 0.060860
CHAN A2 (12V): -0.029503
CHAN A3 (5V): -0.057302
CHAN B0 (3.3V): -0.035464
CHAN B1 (3.15aV): -0.023002
CHAN B2 (3.15bV): -0.014792
CHAN B3 (GND): -0.033815
OPEN: 0.008982
Full Scale Calc: 4.765 mA, -1.589 mA
2019-07-25T21:21:09.401Z,1564089669.401 [NAL9602](INFO): SBD MO Status=2, MOMSN=30030, MT Status=2, MTMSN=0
2019-07-25T21:21:09.402Z,1564089669.402 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-25T21:21:51.328Z,1564089711.328 [SBIT](IMPORTANT): SBIT PASSED
2019-07-25T21:21:51.383Z,1564089711.383 [CommandLine](IMPORTANT): got command configSet list
2019-07-25T21:21:51.384Z,1564089711.384 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2019-07-25T21:21:51.384Z,1564089711.384 [CommandLine](IMPORTANT): BPC1.batteryMissingStickThreshold=2 count;

2019-07-25T21:21:51.385Z,1564089711.385 [CommandLine](IMPORTANT): BuoyancyServo.fastPumpDepth=5 meter;

2019-07-25T21:21:51.385Z,1564089711.385 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral=400 cubic_centimeter;

2019-07-25T21:21:51.385Z,1564089711.385 [CommandLine](IMPORTANT): VerticalControl.kiDepthBuoy=0.3 reciprocal_second;

2019-07-25T21:21:51.385Z,1564089711.385 [CommandLine](IMPORTANT): VerticalControl.massDefault=13.5 millimeter;

2019-07-25T21:21:51.739Z,1564089711.739 [MissionManager](IMPORTANT): Started mission Startup
2019-07-25T21:21:51.740Z,1564089711.740 [Startup] Running Loop=1
2019-07-25T21:21:51.740Z,1564089711.740 [Startup](DEBUG): Aggregate::initialize Startup
2019-07-25T21:21:51.740Z,1564089711.740 [Startup:A.GoToSurface] Running Loop=1
2019-07-25T21:21:51.740Z,1564089711.740 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-07-25T21:21:51.740Z,1564089711.740 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-07-25T21:21:51.741Z,1564089711.741 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-07-25T21:21:51.741Z,1564089711.741 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-07-25T21:21:51.742Z,1564089711.742 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-07-25T21:21:51.742Z,1564089711.742 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-07-25T21:21:51.744Z,1564089711.744 [Startup:StartupSatComms] Running Loop=1
2019-07-25T21:21:51.744Z,1564089711.744 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2019-07-25T21:21:51.744Z,1564089711.744 [Startup:StartupSatComms:A] Running Loop=1
2019-07-25T21:21:52.148Z,1564089712.148 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2019-07-25T21:22:27.216Z,1564089747.216 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.005020
2019-07-25T21:22:43.860Z,1564089763.860 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2019-07-25T21:22:43.860Z,1564089763.860 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-07-25T21:22:43.870Z,1564089763.870 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-07-25T21:22:44.273Z,1564089764.273 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-07-25T21:22:44.273Z,1564089764.273 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2019-07-25T21:22:48.284Z,1564089768.284 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-07-25T21:22:48.284Z,1564089768.284 [DVL_micro] Data Fault, FailCount= 1
2019-07-25T21:22:48.284Z,1564089768.284 [DVL_micro](ERROR): Data Fault
2019-07-25T21:22:48.339Z,1564089768.339 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-07-25T21:22:48.770Z,1564089768.770 [DVL_micro](INFO): uninitialize:Powering down
2019-07-25T21:22:49.567Z,1564089769.567 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-07-25T21:22:49.567Z,1564089769.567 [DVL_micro] No Fault, FailCount= 1
2019-07-25T21:22:49.917Z,1564089769.917 [DVL_micro](INFO): Initializing
2019-07-25T21:22:52.017Z,1564089772.017 [Startup:StartupSatComms:A](INFO): Timed out from 2019-07-25T21:21:51.7Z
2019-07-25T21:22:52.017Z,1564089772.017 [Startup:StartupSatComms:A] Stopped
2019-07-25T21:22:52.017Z,1564089772.017 [Startup:StartupSatComms:B] Running Loop=1
2019-07-25T21:22:52.384Z,1564089772.384 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-07-25T21:23:06.754Z,1564089786.754 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190725T161926/Courier0123.lzma
2019-07-25T21:23:07.557Z,1564089787.557 [DataOverHttps](INFO): Moved sent file to Logs/20190725T161926/Courier0123.lzma.bak
2019-07-25T21:23:07.558Z,1564089787.558 [DataOverHttps](INFO): SBD MOMSN=11475934
2019-07-25T21:23:34.478Z,1564089814.478 [DataOverHttps](INFO): Sending 300 bytes from file Logs/20190725T161926/Express0124.lzma
2019-07-25T21:23:35.284Z,1564089815.284 [DataOverHttps](INFO): Moved sent file to Logs/20190725T161926/Express0124.lzma.bak
2019-07-25T21:23:35.284Z,1564089815.284 [DataOverHttps](INFO): SBD MOMSN=11475936
2019-07-25T21:23:52.155Z,1564089832.155 [Startup:StartupSatComms:B](INFO): Timed out from 2019-07-25T21:22:52.0Z
2019-07-25T21:23:52.155Z,1564089832.155 [Startup:StartupSatComms:B] Stopped
2019-07-25T21:23:52.155Z,1564089832.155 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2019-07-25T21:23:52.156Z,1564089832.156 [Startup:StartupSatComms] Stopped
2019-07-25T21:23:52.156Z,1564089832.156 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2019-07-25T21:23:52.156Z,1564089832.156 [Startup](INFO): Completed Startup
2019-07-25T21:23:52.157Z,1564089832.157 [MissionManager](INFO): Startup is completed.
2019-07-25T21:23:52.157Z,1564089832.157 [MissionManager](INFO): Uninitializing Mission Startup
2019-07-25T21:23:52.157Z,1564089832.157 [Startup] Stopped
2019-07-25T21:23:52.157Z,1564089832.157 [Startup](DEBUG): Aggregate::uninitialize Startup
2019-07-25T21:23:52.157Z,1564089832.157 [Startup:A.GoToSurface] Stopped
2019-07-25T21:23:52.157Z,1564089832.157 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-07-25T21:23:52.551Z,1564089832.551 [MissionManager](IMPORTANT): Started mission Default
2019-07-25T21:23:52.551Z,1564089832.551 [Default] Running Loop=1
2019-07-25T21:23:52.551Z,1564089832.551 [Default](DEBUG): Aggregate::initialize Default
2019-07-25T21:23:52.551Z,1564089832.551 [Default:B.GoToSurface] Running Loop=1
2019-07-25T21:23:52.551Z,1564089832.551 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-07-25T21:23:52.551Z,1564089832.551 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-07-25T21:23:52.552Z,1564089832.552 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-07-25T21:23:52.552Z,1564089832.552 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-07-25T21:23:52.552Z,1564089832.552 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-07-25T21:23:52.553Z,1564089832.553 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-07-25T21:23:52.553Z,1564089832.553 [Default:A.Wait] Running Loop=1
2019-07-25T21:23:52.553Z,1564089832.553 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-07-25T21:23:54.811Z,1564089834.811 [DataOverHttps](INFO): Sending 838 bytes from file Logs/20190725T211932/Express0001.lzma
2019-07-25T21:23:55.615Z,1564089835.615 [DataOverHttps](INFO): Moved sent file to Logs/20190725T211932/Express0001.lzma.bak
2019-07-25T21:23:55.615Z,1564089835.615 [DataOverHttps](INFO): SBD MOMSN=11475944
2019-07-25T21:24:05.874Z,1564089845.874 [Default:A.Wait](INFO): Done Waiting.
2019-07-25T21:24:05.874Z,1564089845.874 [Default:A.Wait] Stopped
2019-07-25T21:24:05.874Z,1564089845.874 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-07-25T21:24:06.273Z,1564089846.273 [Default:CheckIn] Running Loop=1
2019-07-25T21:24:06.273Z,1564089846.273 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-07-25T21:24:06.273Z,1564089846.273 [Default:CheckIn:Read_GPS] Running Loop=1
2019-07-25T21:24:06.682Z,1564089846.682 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2019-07-25T21:25:25.050Z,1564089925.050 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-07-25T21:25:25.858Z,1564089925.858 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:25:30.295Z,1564089930.295 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:25:33.134Z,1564089933.134 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:25:36.362Z,1564089936.362 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:25:39.186Z,1564089939.186 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:25:42.022Z,1564089942.022 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:25:44.862Z,1564089944.862 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2019-07-25T21:25:44.862Z,1564089944.862 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-07-25T21:25:44.872Z,1564089944.872 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-07-25T21:25:45.258Z,1564089945.258 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:25:45.295Z,1564089945.295 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-07-25T21:25:45.295Z,1564089945.295 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2019-07-25T21:25:48.074Z,1564089948.074 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:25:51.310Z,1564089951.310 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:25:54.123Z,1564089954.123 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-07-25T21:25:54.123Z,1564089954.123 [DVL_micro] Data Fault, FailCount= 1
2019-07-25T21:25:54.123Z,1564089954.123 [DVL_micro](ERROR): Data Fault
2019-07-25T21:25:54.138Z,1564089954.138 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:25:54.204Z,1564089954.204 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-07-25T21:25:54.598Z,1564089954.598 [DVL_micro](INFO): uninitialize:Powering down
2019-07-25T21:25:55.372Z,1564089955.372 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-07-25T21:25:55.372Z,1564089955.372 [DVL_micro] No Fault, FailCount= 1
2019-07-25T21:25:55.747Z,1564089955.747 [DVL_micro](INFO): Initializing
2019-07-25T21:25:57.370Z,1564089957.370 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:26:00.198Z,1564089960.198 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:26:03.030Z,1564089963.030 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:26:06.262Z,1564089966.262 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:26:09.082Z,1564089969.082 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:26:12.322Z,1564089972.322 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:26:15.546Z,1564089975.546 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:26:18.394Z,1564089978.394 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:26:21.206Z,1564089981.206 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:26:24.438Z,1564089984.438 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:26:27.266Z,1564089987.266 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:26:30.090Z,1564089990.090 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:26:33.322Z,1564089993.322 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:26:36.158Z,1564089996.158 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:26:39.394Z,1564089999.394 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:26:42.218Z,1564090002.218 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:26:45.442Z,1564090005.442 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:26:48.274Z,1564090008.274 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:26:51.106Z,1564090011.106 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:26:54.334Z,1564090014.334 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:26:57.182Z,1564090017.182 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:27:00.414Z,1564090020.414 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:27:03.218Z,1564090023.218 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:27:06.454Z,1564090026.454 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:27:09.282Z,1564090029.282 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:27:12.514Z,1564090032.514 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:27:15.342Z,1564090035.342 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:27:18.170Z,1564090038.170 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:27:18.193Z,1564090038.193 [BPC1](ERROR): Battery stick #38 (s/n: 0139) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0.
2019-07-25T21:27:18.193Z,1564090038.193 [BPC1](ERROR): Battery stick #39 (s/n: 00F0) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0.
2019-07-25T21:27:18.194Z,1564090038.194 [BPC1](INFO): Calculating totals. Valid battery stick count: 53. Valid reserve battery stick count: 5.
2019-07-25T21:27:18.197Z,1564090038.197 [BPC1](INFO): Received data from all battery sticks.
2019-07-25T21:27:21.402Z,1564090041.402 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:27:24.226Z,1564090044.226 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:27:27.458Z,1564090047.458 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:27:30.290Z,1564090050.290 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:27:33.522Z,1564090053.522 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:27:36.370Z,1564090056.370 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:27:39.590Z,1564090059.590 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:27:42.446Z,1564090062.446 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:27:45.246Z,1564090065.246 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:27:48.474Z,1564090068.474 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:27:51.298Z,1564090071.298 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:27:54.530Z,1564090074.530 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:27:57.358Z,1564090077.358 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:28:00.590Z,1564090080.590 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:28:03.418Z,1564090083.418 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:28:06.646Z,1564090086.646 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:28:09.479Z,1564090089.479 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:28:12.310Z,1564090092.310 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:28:15.538Z,1564090095.538 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:28:18.370Z,1564090098.370 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:28:21.204Z,1564090101.204 [DVL_micro](ERROR): only read 43 of 46 data items
2019-07-25T21:28:21.204Z,1564090101.204 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 407 1471 468 226 2 3 2 2 -81.4 1661.6 693.5 2 1639.8 -280.2 693.5 2 -81 1661 693 2 1639 -280 693 2 -13.33 -1.53 257.5 -3.0 20.9 0.005 35.0 1489 65
2019-07-25T21:28:21.598Z,1564090101.598 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:28:24.442Z,1564090104.442 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:28:27.674Z,1564090107.674 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:28:30.490Z,1564090110.490 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:28:33.318Z,1564090113.318 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:28:36.550Z,1564090116.550 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:28:39.378Z,1564090119.378 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:28:42.606Z,1564090122.606 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:28:45.434Z,1564090125.434 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:28:45.862Z,1564090125.862 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2019-07-25T21:28:45.862Z,1564090125.862 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-07-25T21:28:45.872Z,1564090125.872 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-07-25T21:28:46.275Z,1564090126.275 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-07-25T21:28:46.275Z,1564090126.275 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2019-07-25T21:28:48.666Z,1564090128.666 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:28:51.494Z,1564090131.494 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:28:54.326Z,1564090134.326 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:28:57.558Z,1564090137.558 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:28:59.963Z,1564090139.963 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-07-25T21:28:59.964Z,1564090139.964 [DVL_micro] Data Fault, FailCount= 1
2019-07-25T21:28:59.964Z,1564090139.964 [DVL_micro](ERROR): Data Fault
2019-07-25T21:28:59.000Z,1564090140.000 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-07-25T21:29:00.438Z,1564090140.438 [DVL_micro](INFO): uninitialize:Powering down
2019-07-25T21:29:00.450Z,1564090140.450 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:29:00.776Z,1564090140.776 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,212647.00,A,3648.17943,N,12147.29170,W,0.622,335.97,250719,,,A*70
2019-07-25T21:29:00.779Z,1564090140.779 [NAL9602](INFO): GPS fix at 20190725T212647: (36.802990, -121.788195)
2019-07-25T21:29:00.803Z,1564090140.803 [Default:CheckIn:Read_GPS] Stopped
2019-07-25T21:29:00.803Z,1564090140.803 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-07-25T21:29:01.229Z,1564090141.229 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-07-25T21:29:01.238Z,1564090141.238 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-07-25T21:29:01.238Z,1564090141.238 [DVL_micro] No Fault, FailCount= 1
2019-07-25T21:29:01.587Z,1564090141.587 [DVL_micro](INFO): Initializing
2019-07-25T21:29:08.266Z,1564090148.266 [DataOverHttps](INFO): Sending 302 bytes from file Logs/20190725T211932/Courier0004.lzma
2019-07-25T21:29:09.071Z,1564090149.071 [DataOverHttps](INFO): Moved sent file to Logs/20190725T211932/Courier0004.lzma.bak
2019-07-25T21:29:09.072Z,1564090149.072 [DataOverHttps](INFO): SBD MOMSN=11475977
2019-07-25T21:29:17.749Z,1564090157.749 [DVL_micro](ERROR): only read 45 of 46 data items
2019-07-25T21:29:17.750Z,1564090157.750 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 0 0 0 0 159 650 453 528 2 3 2 2 -392.4 162.8 482.6 2 244.5 347.4 -392 162 482 2 244 347 482 2 -13.41 -1.57 257.4 -3.0 21.0 0.005 35.0 1489 115
2019-07-25T21:29:23.310Z,1564090163.310 [DataOverHttps](INFO): Sending 337 bytes from file Logs/20190725T211932/Express0005.lzma
2019-07-25T21:29:24.115Z,1564090164.115 [DataOverHttps](INFO): Moved sent file to Logs/20190725T211932/Express0005.lzma.bak
2019-07-25T21:29:24.116Z,1564090164.116 [DataOverHttps](INFO): SBD MOMSN=11475980
2019-07-25T21:29:24.636Z,1564090164.636 [Default:CheckIn:Read_Iridium] Stopped
2019-07-25T21:29:24.636Z,1564090164.636 [Default:CheckIn:C.Wait] Running Loop=1
2019-07-25T21:29:24.636Z,1564090164.636 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-07-25T21:29:33.515Z,1564090173.515 [NAL9602](INFO): Not Powering down - fast GPS
2019-07-25T21:31:14.101Z,1564090274.101 [DVL_micro](ERROR): checksum mismatch: reported120 , calculated:122
2019-07-25T21:31:14.102Z,1564090274.102 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 0 0 0 0 1136 1168 521 337 2 3 2 2 820.8 1109.1 852.6 2 905.1 -12.6 2 820 1109 852 2 905 -1041 852 2 -13.33 -1.50 257.5 -3.0 21.0 0.005 35.0 1489 120
2019-07-25T21:32:05.807Z,1564090325.807 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-07-25T21:32:05.807Z,1564090325.807 [DVL_micro] Data Fault, FailCount= 1
2019-07-25T21:32:05.807Z,1564090325.807 [DVL_micro](ERROR): Data Fault
2019-07-25T21:32:05.846Z,1564090325.846 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-07-25T21:32:06.290Z,1564090326.290 [DVL_micro](INFO): uninitialize:Powering down
2019-07-25T21:32:07.060Z,1564090327.060 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-07-25T21:32:07.060Z,1564090327.060 [DVL_micro] No Fault, FailCount= 1
2019-07-25T21:32:07.433Z,1564090327.433 [DVL_micro](INFO): Initializing
2019-07-25T21:33:08.848Z,1564090388.848 [DVL_micro](ERROR): only read 45 of 46 data items
2019-07-25T21:33:08.848Z,1564090388.848 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 0 0 0 0 452 1334 1939 739 2 3 2 2 -1984.6 794.1 1203.6 2 1204.8 1765.6 1203.6 2 -1984 794 1203 2 1204 1765 1203 2 -.50 257.5 -3.0 21.0 0.005 35.0 1489 122
2019-07-25T21:34:25.226Z,1564090465.226 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-07-25T21:34:25.226Z,1564090465.226 [Default:CheckIn:C.Wait] Stopped
2019-07-25T21:34:25.226Z,1564090465.226 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-07-25T21:34:25.226Z,1564090465.226 [Default:CheckIn:D] Running Loop=1
2019-07-25T21:34:25.629Z,1564090465.629 [Default:CheckIn:D] Stopped
2019-07-25T21:34:25.629Z,1564090465.629 [Default:CheckIn:E] Running Loop=1
2019-07-25T21:34:26.034Z,1564090466.034 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.551306 min 
2019-07-25T21:34:26.034Z,1564090466.034 [Default:CheckIn:E] Stopped
2019-07-25T21:34:26.034Z,1564090466.034 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-07-25T21:34:26.034Z,1564090466.034 [Default:CheckIn] Stopped
2019-07-25T21:34:26.034Z,1564090466.034 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-07-25T21:34:26.034Z,1564090466.034 [Default:CheckIn](INFO): Running loop #2
2019-07-25T21:34:26.034Z,1564090466.034 [Default:CheckIn] Running Loop=2
2019-07-25T21:34:26.035Z,1564090466.035 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-07-25T21:34:26.035Z,1564090466.035 [Default:CheckIn:Read_GPS] Running Loop=1
2019-07-25T21:34:27.634Z,1564090467.634 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:34:28.023Z,1564090468.023 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,213213.00,A,3648.16300,N,12147.29023,W,0.505,288.47,250719,,,A*73
2019-07-25T21:34:28.025Z,1564090468.025 [NAL9602](INFO): GPS fix at 20190725T213213: (36.802717, -121.788171)
2019-07-25T21:34:28.049Z,1564090468.049 [Default:CheckIn:Read_GPS] Stopped
2019-07-25T21:34:28.049Z,1564090468.049 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-07-25T21:34:34.915Z,1564090474.915 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20190725T211932/Courier0007.lzma
2019-07-25T21:34:35.675Z,1564090475.675 [DataOverHttps](INFO): Moved sent file to Logs/20190725T211932/Courier0007.lzma.bak
2019-07-25T21:34:35.675Z,1564090475.675 [DataOverHttps](INFO): SBD MOMSN=11475986
2019-07-25T21:34:50.574Z,1564090490.574 [DataOverHttps](INFO): Sending 209 bytes from file Logs/20190725T211932/Express0008.lzma
2019-07-25T21:34:51.379Z,1564090491.379 [DataOverHttps](INFO): Moved sent file to Logs/20190725T211932/Express0008.lzma.bak
2019-07-25T21:34:51.380Z,1564090491.380 [DataOverHttps](INFO): SBD MOMSN=11475989
2019-07-25T21:34:51.882Z,1564090491.882 [Default:CheckIn:Read_Iridium] Stopped
2019-07-25T21:34:51.883Z,1564090491.883 [Default:CheckIn:C.Wait] Running Loop=1
2019-07-25T21:34:51.883Z,1564090491.883 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-07-25T21:34:58.752Z,1564090498.752 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2019-07-25T21:34:58.826Z,1564090498.826 [NAL9602](FAULT): received: 
+CSQ:0

OK030, 2, 0, 0, 0

OK
2019-07-25T21:34:58.826Z,1564090498.826 [NAL9602] Data Fault, FailCount= 1
2019-07-25T21:34:58.826Z,1564090498.826 [NAL9602](ERROR): Data Fault
2019-07-25T21:34:58.887Z,1564090498.887 [CBIT](ERROR): Data Fault in component: NAL9602
2019-07-25T21:34:59.141Z,1564090499.141 [NAL9602](INFO): Powering down
2019-07-25T21:35:00.008Z,1564090500.008 [CBIT](INFO): Clearing failed state for component NAL9602
2019-07-25T21:35:00.008Z,1564090500.008 [NAL9602] No Fault, FailCount= 1
2019-07-25T21:35:11.653Z,1564090511.653 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-07-25T21:35:11.653Z,1564090511.653 [DVL_micro] Data Fault, FailCount= 1
2019-07-25T21:35:11.653Z,1564090511.653 [DVL_micro](ERROR): Data Fault
2019-07-25T21:35:11.686Z,1564090511.686 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-07-25T21:35:12.134Z,1564090512.134 [DVL_micro](INFO): uninitialize:Powering down
2019-07-25T21:35:12.913Z,1564090512.913 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-07-25T21:35:12.918Z,1564090512.918 [DVL_micro] No Fault, FailCount= 1
2019-07-25T21:35:13.275Z,1564090513.275 [DVL_micro](INFO): Initializing
2019-07-25T21:35:29.478Z,1564090529.478 [NAL9602](INFO): Powering up NAL9602
2019-07-25T21:35:40.337Z,1564090540.337 [NAL9602](INFO): NAL9602 initialized
2019-07-25T21:36:11.468Z,1564090571.468 [NAL9602](INFO): Not Powering down - fast GPS
2019-07-25T21:38:17.511Z,1564090697.511 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-07-25T21:38:17.511Z,1564090697.511 [DVL_micro] Data Fault, FailCount= 1
2019-07-25T21:38:17.511Z,1564090697.511 [DVL_micro](ERROR): Data Fault
2019-07-25T21:38:17.565Z,1564090697.565 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-07-25T21:38:17.994Z,1564090697.994 [DVL_micro](INFO): uninitialize:Powering down
2019-07-25T21:38:18.772Z,1564090698.772 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-07-25T21:38:18.772Z,1564090698.772 [DVL_micro] No Fault, FailCount= 1
2019-07-25T21:38:19.135Z,1564090699.135 [DVL_micro](INFO): Initializing
2019-07-25T21:39:52.478Z,1564090792.478 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-07-25T21:39:52.478Z,1564090792.478 [Default:CheckIn:C.Wait] Stopped
2019-07-25T21:39:52.478Z,1564090792.478 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-07-25T21:39:52.478Z,1564090792.478 [Default:CheckIn:D] Running Loop=1
2019-07-25T21:39:52.898Z,1564090792.898 [Default:CheckIn:D] Stopped
2019-07-25T21:39:52.898Z,1564090792.898 [Default:CheckIn:E] Running Loop=1
2019-07-25T21:39:53.292Z,1564090793.292 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 16.005792 min 
2019-07-25T21:39:53.292Z,1564090793.292 [Default:CheckIn:E] Stopped
2019-07-25T21:39:53.292Z,1564090793.292 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-07-25T21:39:53.292Z,1564090793.292 [Default:CheckIn] Stopped
2019-07-25T21:39:53.292Z,1564090793.292 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-07-25T21:39:53.292Z,1564090793.292 [Default:CheckIn](INFO): Running loop #3
2019-07-25T21:39:53.292Z,1564090793.292 [Default:CheckIn] Running Loop=3
2019-07-25T21:39:53.292Z,1564090793.292 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-07-25T21:39:53.293Z,1564090793.293 [Default:CheckIn:Read_GPS] Running Loop=1
2019-07-25T21:39:54.902Z,1564090794.902 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:39:56.502Z,1564090796.502 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-07-25T21:39:57.330Z,1564090797.330 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:40:00.142Z,1564090800.142 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:40:02.974Z,1564090802.974 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:40:06.206Z,1564090806.206 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:40:09.054Z,1564090809.054 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:40:12.282Z,1564090812.282 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:40:15.094Z,1564090815.094 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:40:18.318Z,1564090818.318 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:40:21.150Z,1564090821.150 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:40:23.982Z,1564090823.982 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:40:25.994Z,1564090825.994 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:40:28.014Z,1564090828.014 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:40:31.270Z,1564090831.270 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:40:34.074Z,1564090834.074 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:40:37.314Z,1564090837.314 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:40:40.142Z,1564090840.142 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:40:43.374Z,1564090843.374 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:40:46.194Z,1564090846.194 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:40:49.030Z,1564090849.030 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:40:51.074Z,1564090851.074 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:40:54.306Z,1564090854.306 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:40:57.110Z,1564090857.110 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:41:00.350Z,1564090860.350 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:41:03.162Z,1564090863.162 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:41:06.414Z,1564090866.414 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:41:09.230Z,1564090869.230 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:41:12.050Z,1564090872.050 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:41:14.082Z,1564090874.082 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:41:17.310Z,1564090877.310 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:41:20.154Z,1564090880.154 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:41:23.355Z,1564090883.355 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-07-25T21:41:23.355Z,1564090883.355 [DVL_micro] Data Fault, FailCount= 1
2019-07-25T21:41:23.355Z,1564090883.355 [DVL_micro](ERROR): Data Fault
2019-07-25T21:41:23.370Z,1564090883.370 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:41:23.406Z,1564090883.406 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-07-25T21:41:23.834Z,1564090883.834 [DVL_micro](INFO): uninitialize:Powering down
2019-07-25T21:41:24.612Z,1564090884.612 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-07-25T21:41:24.613Z,1564090884.613 [DVL_micro] No Fault, FailCount= 1
2019-07-25T21:41:24.971Z,1564090884.971 [DVL_micro](INFO): Initializing
2019-07-25T21:41:26.190Z,1564090886.190 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:41:28.618Z,1564090888.618 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:41:31.486Z,1564090891.486 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:41:33.866Z,1564090893.866 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:41:36.698Z,1564090896.698 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:41:39.522Z,1564090899.522 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:41:42.350Z,1564090902.350 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:41:44.402Z,1564090904.402 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:41:47.654Z,1564090907.654 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:41:50.430Z,1564090910.430 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:41:53.670Z,1564090913.670 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:41:56.494Z,1564090916.494 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:41:59.726Z,1564090919.726 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:42:02.559Z,1564090922.559 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:42:05.798Z,1564090925.798 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:42:08.610Z,1564090928.610 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:42:11.438Z,1564090931.438 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:42:14.670Z,1564090934.670 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:42:17.498Z,1564090937.498 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:42:20.730Z,1564090940.730 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:42:23.574Z,1564090943.574 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:42:26.798Z,1564090946.798 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:42:29.662Z,1564090949.662 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:42:32.462Z,1564090952.462 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:42:35.678Z,1564090955.678 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:42:38.510Z,1564090958.510 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:42:41.746Z,1564090961.746 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:42:44.566Z,1564090964.566 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:42:47.798Z,1564090967.798 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:42:50.634Z,1564090970.634 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:42:53.454Z,1564090973.454 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:42:55.502Z,1564090975.502 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:42:57.906Z,1564090977.906 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:43:00.726Z,1564090980.726 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:43:03.962Z,1564090983.962 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:43:06.786Z,1564090986.786 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:43:10.018Z,1564090990.018 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:43:12.846Z,1564090992.846 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:43:15.678Z,1564090995.678 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:43:18.522Z,1564090998.522 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:43:20.522Z,1564091000.522 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:43:23.754Z,1564091003.754 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:43:26.582Z,1564091006.582 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:43:29.817Z,1564091009.817 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:43:32.646Z,1564091012.646 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:43:35.874Z,1564091015.874 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:43:38.706Z,1564091018.706 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:43:41.536Z,1564091021.536 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:43:43.554Z,1564091023.554 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:43:45.974Z,1564091025.974 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:43:48.814Z,1564091028.814 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:43:52.034Z,1564091032.034 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:43:54.866Z,1564091034.866 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:43:57.690Z,1564091037.690 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:44:00.930Z,1564091040.930 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:44:03.770Z,1564091043.770 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:44:06.610Z,1564091046.610 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:44:08.598Z,1564091048.598 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:44:11.838Z,1564091051.838 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:44:14.658Z,1564091054.658 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:44:17.894Z,1564091057.894 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:44:20.718Z,1564091060.718 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:44:23.962Z,1564091063.962 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:44:26.778Z,1564091066.778 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:44:29.191Z,1564091069.191 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-07-25T21:44:29.191Z,1564091069.191 [DVL_micro] Data Fault, FailCount= 1
2019-07-25T21:44:29.191Z,1564091069.191 [DVL_micro](ERROR): Data Fault
2019-07-25T21:44:29.276Z,1564091069.276 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-07-25T21:44:29.670Z,1564091069.670 [DVL_micro](INFO): uninitialize:Powering down
2019-07-25T21:44:29.682Z,1564091069.682 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:44:30.486Z,1564091070.486 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-07-25T21:44:30.486Z,1564091070.486 [DVL_micro] No Fault, FailCount= 1
2019-07-25T21:44:30.813Z,1564091070.813 [DVL_micro](INFO): Initializing
2019-07-25T21:44:31.626Z,1564091071.626 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:44:34.054Z,1564091074.054 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:44:36.885Z,1564091076.885 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:44:40.110Z,1564091080.110 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:44:42.942Z,1564091082.942 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:44:46.170Z,1564091086.170 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:44:48.998Z,1564091088.998 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:44:51.842Z,1564091091.842 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:44:53.481Z,1564091093.481 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-07-25T21:39:53.3Z
2019-07-25T21:44:53.481Z,1564091093.481 [Default:CheckIn:Read_GPS] Stopped
2019-07-25T21:44:53.482Z,1564091093.482 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-07-25T21:44:59.930Z,1564091099.930 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190725T211932/Courier0010.lzma
2019-07-25T21:45:00.736Z,1564091100.736 [DataOverHttps](INFO): Moved sent file to Logs/20190725T211932/Courier0010.lzma.bak
2019-07-25T21:45:00.736Z,1564091100.736 [DataOverHttps](INFO): SBD MOMSN=11476001
2019-07-25T21:45:23.210Z,1564091123.210 [DataOverHttps](INFO): Sending 278 bytes from file Logs/20190725T211932/Express0011.lzma
2019-07-25T21:45:24.015Z,1564091124.015 [DataOverHttps](INFO): Moved sent file to Logs/20190725T211932/Express0011.lzma.bak
2019-07-25T21:45:24.015Z,1564091124.015 [DataOverHttps](INFO): SBD MOMSN=11476003
2019-07-25T21:45:24.537Z,1564091124.537 [NAL9602](INFO): Not Powering down - fast GPS
2019-07-25T21:45:24.569Z,1564091124.569 [Default:CheckIn:Read_Iridium] Stopped
2019-07-25T21:45:24.569Z,1564091124.569 [Default:CheckIn:C.Wait] Running Loop=1
2019-07-25T21:45:24.569Z,1564091124.569 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-07-25T21:47:35.031Z,1564091255.031 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-07-25T21:47:35.031Z,1564091255.031 [DVL_micro] Data Fault, FailCount= 1
2019-07-25T21:47:35.031Z,1564091255.031 [DVL_micro](ERROR): Data Fault
2019-07-25T21:47:35.110Z,1564091255.110 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-07-25T21:47:35.514Z,1564091255.514 [DVL_micro](INFO): uninitialize:Powering down
2019-07-25T21:47:36.314Z,1564091256.314 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-07-25T21:47:36.314Z,1564091256.314 [DVL_micro] No Fault, FailCount= 1
2019-07-25T21:47:36.665Z,1564091256.665 [DVL_micro](INFO): Initializing
2019-07-25T21:50:25.138Z,1564091425.138 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-07-25T21:50:25.138Z,1564091425.138 [Default:CheckIn:C.Wait] Stopped
2019-07-25T21:50:25.138Z,1564091425.138 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-07-25T21:50:25.138Z,1564091425.138 [Default:CheckIn:D] Running Loop=1
2019-07-25T21:50:25.553Z,1564091425.553 [Default:CheckIn:D] Stopped
2019-07-25T21:50:25.553Z,1564091425.553 [Default:CheckIn:E] Running Loop=1
2019-07-25T21:50:25.949Z,1564091425.949 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 26.550041 min 
2019-07-25T21:50:25.949Z,1564091425.949 [Default:CheckIn:E] Stopped
2019-07-25T21:50:25.950Z,1564091425.950 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-07-25T21:50:25.950Z,1564091425.950 [Default:CheckIn] Stopped
2019-07-25T21:50:25.950Z,1564091425.950 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-07-25T21:50:25.950Z,1564091425.950 [Default:CheckIn](INFO): Running loop #4
2019-07-25T21:50:25.950Z,1564091425.950 [Default:CheckIn] Running Loop=4
2019-07-25T21:50:25.950Z,1564091425.950 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-07-25T21:50:25.950Z,1564091425.950 [Default:CheckIn:Read_GPS] Running Loop=1
2019-07-25T21:50:27.538Z,1564091427.538 [NAL9602](FAULT): GPS failed to acquire within timeout.
2019-07-25T21:50:27.538Z,1564091427.538 [NAL9602] Data Fault, FailCount= 1
2019-07-25T21:50:27.538Z,1564091427.538 [NAL9602](ERROR): Data Fault
2019-07-25T21:50:27.600Z,1564091427.600 [CBIT](ERROR): Data Fault in component: NAL9602
2019-07-25T21:50:28.017Z,1564091428.017 [NAL9602](INFO): Powering down
2019-07-25T21:50:28.834Z,1564091428.834 [CBIT](INFO): Clearing failed state for component NAL9602
2019-07-25T21:50:28.834Z,1564091428.834 [NAL9602] No Fault, FailCount= 1
2019-07-25T21:50:40.875Z,1564091440.875 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-07-25T21:50:40.875Z,1564091440.875 [DVL_micro] Data Fault, FailCount= 1
2019-07-25T21:50:40.875Z,1564091440.875 [DVL_micro](ERROR): Data Fault
2019-07-25T21:50:40.908Z,1564091440.908 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-07-25T21:50:41.346Z,1564091441.346 [DVL_micro](INFO): uninitialize:Powering down
2019-07-25T21:50:42.122Z,1564091442.122 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-07-25T21:50:42.122Z,1564091442.122 [DVL_micro] No Fault, FailCount= 1
2019-07-25T21:50:42.497Z,1564091442.497 [DVL_micro](INFO): Initializing
2019-07-25T21:50:58.248Z,1564091458.248 [NAL9602](INFO): Powering up NAL9602
2019-07-25T21:51:09.150Z,1564091469.150 [NAL9602](INFO): NAL9602 initialized
2019-07-25T21:51:09.978Z,1564091469.978 [NAL9602](DEBUG): Fix Requested
2019-07-25T21:53:46.717Z,1564091626.717 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-07-25T21:53:46.717Z,1564091626.717 [DVL_micro] Data Fault, FailCount= 1
2019-07-25T21:53:46.717Z,1564091626.717 [DVL_micro](ERROR): Data Fault
2019-07-25T21:53:46.750Z,1564091626.750 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-07-25T21:53:47.203Z,1564091627.203 [DVL_micro](INFO): uninitialize:Powering down
2019-07-25T21:53:47.968Z,1564091627.968 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-07-25T21:53:47.968Z,1564091627.968 [DVL_micro] No Fault, FailCount= 1
2019-07-25T21:53:48.351Z,1564091628.351 [DVL_micro](INFO): Initializing
2019-07-25T21:54:43.306Z,1564091683.306 [NAL9602](INFO): SBD MO Status=2, MOMSN=30030, MT Status=2, MTMSN=0
2019-07-25T21:54:43.306Z,1564091683.306 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-25T21:55:00.253Z,1564091700.253 [NAL9602](INFO): SBD MO Status=2, MOMSN=30030, MT Status=2, MTMSN=0
2019-07-25T21:55:00.254Z,1564091700.254 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-25T21:55:26.125Z,1564091726.125 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-07-25T21:50:25.0Z
2019-07-25T21:55:26.125Z,1564091726.125 [Default:CheckIn:Read_GPS] Stopped
2019-07-25T21:55:26.125Z,1564091726.125 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-07-25T21:55:30.553Z,1564091730.553 [NAL9602](INFO): SBD MO Status=2, MOMSN=30030, MT Status=2, MTMSN=0
2019-07-25T21:55:30.553Z,1564091730.553 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-25T21:55:34.961Z,1564091734.961 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190725T211932/Courier0013.lzma
2019-07-25T21:55:35.767Z,1564091735.767 [DataOverHttps](INFO): Moved sent file to Logs/20190725T211932/Courier0013.lzma.bak
2019-07-25T21:55:35.767Z,1564091735.767 [DataOverHttps](INFO): SBD MOMSN=11476067
2019-07-25T21:55:45.095Z,1564091745.095 [NAL9602](INFO): SBD MO Status=2, MOMSN=30030, MT Status=2, MTMSN=0
2019-07-25T21:55:45.095Z,1564091745.095 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-25T21:55:53.985Z,1564091753.985 [NAL9602](INFO): SBD MO Status=2, MOMSN=30030, MT Status=2, MTMSN=0
2019-07-25T21:55:53.985Z,1564091753.985 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-25T21:55:56.238Z,1564091756.238 [DataOverHttps](INFO): Sending 198 bytes from file Logs/20190725T211932/Express0014.lzma
2019-07-25T21:55:57.043Z,1564091757.043 [DataOverHttps](INFO): Moved sent file to Logs/20190725T211932/Express0014.lzma.bak
2019-07-25T21:55:57.044Z,1564091757.044 [DataOverHttps](INFO): SBD MOMSN=11476069
2019-07-25T21:55:57.693Z,1564091757.693 [Default:CheckIn:Read_Iridium] Stopped
2019-07-25T21:55:57.693Z,1564091757.693 [Default:CheckIn:C.Wait] Running Loop=1
2019-07-25T21:55:57.693Z,1564091757.693 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-07-25T21:56:16.199Z,1564091776.199 [NAL9602](INFO): SBD MO Status=2, MOMSN=30030, MT Status=2, MTMSN=0
2019-07-25T21:56:16.199Z,1564091776.199 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-25T21:56:16.612Z,1564091776.612 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-07-25T21:56:47.305Z,1564091807.305 [NAL9602](INFO): Not Powering down - fast GPS
2019-07-25T21:56:52.563Z,1564091812.563 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-07-25T21:56:52.563Z,1564091812.563 [DVL_micro] Data Fault, FailCount= 1
2019-07-25T21:56:52.563Z,1564091812.563 [DVL_micro](ERROR): Data Fault
2019-07-25T21:56:52.622Z,1564091812.622 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-07-25T21:56:53.034Z,1564091813.034 [DVL_micro](INFO): uninitialize:Powering down
2019-07-25T21:56:53.800Z,1564091813.800 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-07-25T21:56:53.800Z,1564091813.800 [DVL_micro] No Fault, FailCount= 1
2019-07-25T21:56:54.185Z,1564091814.185 [DVL_micro](INFO): Initializing
2019-07-25T21:59:58.401Z,1564091998.401 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-07-25T21:59:58.401Z,1564091998.401 [DVL_micro] Data Fault, FailCount= 1
2019-07-25T21:59:58.401Z,1564091998.401 [DVL_micro](ERROR): Data Fault
2019-07-25T21:59:58.434Z,1564091998.434 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-07-25T21:59:58.882Z,1564091998.882 [DVL_micro](INFO): uninitialize:Powering down
2019-07-25T21:59:59.650Z,1564091999.650 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-07-25T21:59:59.650Z,1564091999.650 [DVL_micro] No Fault, FailCount= 1
2019-07-25T22:00:00.027Z,1564092000.027 [DVL_micro](INFO): Initializing
2019-07-25T22:00:58.253Z,1564092058.253 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-07-25T22:00:58.253Z,1564092058.253 [Default:CheckIn:C.Wait] Stopped
2019-07-25T22:00:58.253Z,1564092058.253 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-07-25T22:00:58.253Z,1564092058.253 [Default:CheckIn:D] Running Loop=1
2019-07-25T22:00:58.637Z,1564092058.637 [Default:CheckIn:D] Stopped
2019-07-25T22:00:58.637Z,1564092058.637 [Default:CheckIn:E] Running Loop=1
2019-07-25T22:00:59.040Z,1564092059.040 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 37.101432 min 
2019-07-25T22:00:59.040Z,1564092059.040 [Default:CheckIn:E] Stopped
2019-07-25T22:00:59.040Z,1564092059.040 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-07-25T22:00:59.040Z,1564092059.040 [Default:CheckIn] Stopped
2019-07-25T22:00:59.040Z,1564092059.040 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-07-25T22:00:59.041Z,1564092059.041 [Default:CheckIn](INFO): Running loop #5
2019-07-25T22:00:59.041Z,1564092059.041 [Default:CheckIn] Running Loop=5
2019-07-25T22:00:59.041Z,1564092059.041 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-07-25T22:00:59.041Z,1564092059.041 [Default:CheckIn:Read_GPS] Running Loop=1
2019-07-25T22:01:00.630Z,1564092060.630 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:01:01.023Z,1564092061.023 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,215844.00,A,3648.15929,N,12147.30344,W,0.447,112.96,250719,,,A*7E
2019-07-25T22:01:01.025Z,1564092061.025 [NAL9602](INFO): GPS fix at 20190725T215844: (36.802655, -121.788391)
2019-07-25T22:01:01.049Z,1564092061.049 [Default:CheckIn:Read_GPS] Stopped
2019-07-25T22:01:01.049Z,1564092061.049 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-07-25T22:01:07.005Z,1564092067.005 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20190725T211932/Courier0016.lzma
2019-07-25T22:01:07.811Z,1564092067.811 [DataOverHttps](INFO): Moved sent file to Logs/20190725T211932/Courier0016.lzma.bak
2019-07-25T22:01:07.811Z,1564092067.811 [DataOverHttps](INFO): SBD MOMSN=11476076
2019-07-25T22:01:32.131Z,1564092092.131 [NAL9602](INFO): SBD MO Status=2, MOMSN=30030, MT Status=2, MTMSN=0
2019-07-25T22:01:32.131Z,1564092092.131 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-25T22:01:51.238Z,1564092111.238 [DataOverHttps](INFO): Sending 241 bytes from file Logs/20190725T211932/Express0017.lzma
2019-07-25T22:01:52.043Z,1564092112.043 [DataOverHttps](INFO): Moved sent file to Logs/20190725T211932/Express0017.lzma.bak
2019-07-25T22:01:52.044Z,1564092112.044 [DataOverHttps](INFO): SBD MOMSN=11476080
2019-07-25T22:01:52.762Z,1564092112.762 [Default:CheckIn:Read_Iridium] Stopped
2019-07-25T22:01:52.762Z,1564092112.762 [Default:CheckIn:C.Wait] Running Loop=1
2019-07-25T22:01:52.762Z,1564092112.762 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-07-25T22:03:04.243Z,1564092184.243 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-07-25T22:03:04.243Z,1564092184.243 [DVL_micro] Data Fault, FailCount= 1
2019-07-25T22:03:04.243Z,1564092184.243 [DVL_micro](ERROR): Data Fault
2019-07-25T22:03:04.310Z,1564092184.310 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-07-25T22:03:04.710Z,1564092184.710 [DVL_micro](INFO): uninitialize:Powering down
2019-07-25T22:03:05.490Z,1564092185.490 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-07-25T22:03:05.490Z,1564092185.490 [DVL_micro] No Fault, FailCount= 1
2019-07-25T22:03:05.863Z,1564092185.863 [DVL_micro](INFO): Initializing
2019-07-25T22:03:43.841Z,1564092223.841 [NAL9602](INFO): SBD MO Status=2, MOMSN=30030, MT Status=2, MTMSN=0
2019-07-25T22:03:43.841Z,1564092223.841 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-25T22:04:45.243Z,1564092285.243 [NAL9602](INFO): SBD MO Status=2, MOMSN=30030, MT Status=2, MTMSN=0
2019-07-25T22:04:45.243Z,1564092285.243 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-25T22:04:59.789Z,1564092299.789 [NAL9602](INFO): SBD MO Status=2, MOMSN=30030, MT Status=2, MTMSN=0
2019-07-25T22:04:59.789Z,1564092299.789 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-25T22:05:05.866Z,1564092305.866 [NAL9602](INFO): SBD MO Status=2, MOMSN=30030, MT Status=2, MTMSN=0
2019-07-25T22:05:05.866Z,1564092305.866 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-25T22:05:20.395Z,1564092320.395 [NAL9602](INFO): SBD MO Status=2, MOMSN=30030, MT Status=2, MTMSN=0
2019-07-25T22:05:20.395Z,1564092320.395 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-25T22:06:02.009Z,1564092362.009 [NAL9602](INFO): SBD MO Status=2, MOMSN=30030, MT Status=2, MTMSN=0
2019-07-25T22:06:02.009Z,1564092362.009 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-25T22:06:03.220Z,1564092363.220 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-07-25T22:06:10.081Z,1564092370.081 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-07-25T22:06:10.081Z,1564092370.081 [DVL_micro] Data Fault, FailCount= 1
2019-07-25T22:06:10.081Z,1564092370.081 [DVL_micro](ERROR): Data Fault
2019-07-25T22:06:10.139Z,1564092370.139 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-07-25T22:06:10.562Z,1564092370.562 [DVL_micro](INFO): uninitialize:Powering down
2019-07-25T22:06:11.338Z,1564092371.338 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-07-25T22:06:11.338Z,1564092371.338 [DVL_micro] No Fault, FailCount= 1
2019-07-25T22:06:11.721Z,1564092371.721 [DVL_micro](INFO): Initializing
2019-07-25T22:06:33.917Z,1564092393.917 [NAL9602](INFO): Not Powering down - fast GPS
2019-07-25T22:06:53.334Z,1564092413.334 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-07-25T22:06:53.334Z,1564092413.334 [Default:CheckIn:C.Wait] Stopped
2019-07-25T22:06:53.334Z,1564092413.334 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-07-25T22:06:53.334Z,1564092413.334 [Default:CheckIn:D] Running Loop=1
2019-07-25T22:06:53.769Z,1564092413.769 [Default:CheckIn:D] Stopped
2019-07-25T22:06:53.769Z,1564092413.769 [Default:CheckIn:E] Running Loop=1
2019-07-25T22:06:54.166Z,1564092414.166 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 43.020308 min 
2019-07-25T22:06:54.166Z,1564092414.166 [Default:CheckIn:E] Stopped
2019-07-25T22:06:54.166Z,1564092414.166 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-07-25T22:06:54.166Z,1564092414.166 [Default:CheckIn] Stopped
2019-07-25T22:06:54.166Z,1564092414.166 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-07-25T22:06:54.166Z,1564092414.166 [Default:CheckIn](INFO): Running loop #6
2019-07-25T22:06:54.166Z,1564092414.166 [Default:CheckIn] Running Loop=6
2019-07-25T22:06:54.167Z,1564092414.167 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-07-25T22:06:54.167Z,1564092414.167 [Default:CheckIn:Read_GPS] Running Loop=1
2019-07-25T22:06:55.746Z,1564092415.746 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:06:56.143Z,1564092416.143 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,220438.00,A,3648.16240,N,12147.28596,W,0.350,187.04,250719,,,A*7E
2019-07-25T22:06:56.145Z,1564092416.145 [NAL9602](INFO): GPS fix at 20190725T220438: (36.802707, -121.788099)
2019-07-25T22:06:56.173Z,1564092416.173 [Default:CheckIn:Read_GPS] Stopped
2019-07-25T22:06:56.173Z,1564092416.173 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-07-25T22:07:00.568Z,1564092420.568 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20190725T211932/Courier0019.lzma
2019-07-25T22:07:01.304Z,1564092421.304 [DataOverHttps](INFO): Moved sent file to Logs/20190725T211932/Courier0019.lzma.bak
2019-07-25T22:07:01.304Z,1564092421.304 [DataOverHttps](INFO): SBD MOMSN=11476150
2019-07-25T22:07:22.054Z,1564092442.054 [DataOverHttps](INFO): Sending 241 bytes from file Logs/20190725T211932/Express0020.lzma
2019-07-25T22:07:22.859Z,1564092442.859 [DataOverHttps](INFO): Moved sent file to Logs/20190725T211932/Express0020.lzma.bak
2019-07-25T22:07:22.860Z,1564092442.860 [DataOverHttps](INFO): SBD MOMSN=11476153
2019-07-25T22:07:23.754Z,1564092443.754 [Default:CheckIn:Read_Iridium] Stopped
2019-07-25T22:07:23.754Z,1564092443.754 [Default:CheckIn:C.Wait] Running Loop=1
2019-07-25T22:07:23.754Z,1564092443.754 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-07-25T22:07:26.934Z,1564092446.934 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2019-07-25T22:07:27.018Z,1564092447.018 [NAL9602](FAULT): received: 
+SBDI: 2, 30030, 2, 0, 0, 0

OK
2019-07-25T22:07:27.018Z,1564092447.018 [NAL9602] Data Fault, FailCount= 2
2019-07-25T22:07:27.018Z,1564092447.018 [NAL9602](ERROR): Data Fault
2019-07-25T22:07:27.082Z,1564092447.082 [CBIT](ERROR): Data Fault in component: NAL9602
2019-07-25T22:07:27.333Z,1564092447.333 [NAL9602](INFO): Powering down
2019-07-25T22:07:28.181Z,1564092448.181 [CBIT](INFO): Clearing failed state for component NAL9602
2019-07-25T22:07:28.181Z,1564092448.181 [NAL9602] No Fault, FailCount= 2
2019-07-25T22:07:57.643Z,1564092477.643 [NAL9602](INFO): Powering up NAL9602
2019-07-25T22:08:08.552Z,1564092488.552 [NAL9602](INFO): NAL9602 initialized
2019-07-25T22:08:39.663Z,1564092519.663 [NAL9602](INFO): Not Powering down - fast GPS
2019-07-25T22:09:16.017Z,1564092556.017 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-07-25T22:09:16.017Z,1564092556.017 [DVL_micro] Data Fault, FailCount= 1
2019-07-25T22:09:16.017Z,1564092556.017 [DVL_micro](ERROR): Data Fault
2019-07-25T22:09:16.054Z,1564092556.054 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-07-25T22:09:16.494Z,1564092556.494 [DVL_micro](INFO): uninitialize:Powering down
2019-07-25T22:09:17.274Z,1564092557.274 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-07-25T22:09:17.274Z,1564092557.274 [DVL_micro] No Fault, FailCount= 1
2019-07-25T22:09:17.636Z,1564092557.636 [DVL_micro](INFO): Initializing
2019-07-25T22:12:21.859Z,1564092741.859 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-07-25T22:12:21.859Z,1564092741.859 [DVL_micro] Data Fault, FailCount= 1
2019-07-25T22:12:21.859Z,1564092741.859 [DVL_micro](ERROR): Data Fault
2019-07-25T22:12:21.927Z,1564092741.927 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-07-25T22:12:22.354Z,1564092742.354 [DVL_micro](INFO): uninitialize:Powering down
2019-07-25T22:12:23.127Z,1564092743.127 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-07-25T22:12:23.128Z,1564092743.128 [DVL_micro] No Fault, FailCount= 1
2019-07-25T22:12:23.481Z,1564092743.481 [DVL_micro](INFO): Initializing
2019-07-25T22:12:24.329Z,1564092744.329 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-07-25T22:12:24.329Z,1564092744.329 [Default:CheckIn:C.Wait] Stopped
2019-07-25T22:12:24.329Z,1564092744.329 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-07-25T22:12:24.329Z,1564092744.329 [Default:CheckIn:D] Running Loop=1
2019-07-25T22:12:24.721Z,1564092744.721 [Default:CheckIn:D] Stopped
2019-07-25T22:12:24.721Z,1564092744.721 [Default:CheckIn:E] Running Loop=1
2019-07-25T22:12:25.114Z,1564092745.114 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 48.536174 min 
2019-07-25T22:12:25.114Z,1564092745.114 [Default:CheckIn:E] Stopped
2019-07-25T22:12:25.114Z,1564092745.114 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-07-25T22:12:25.114Z,1564092745.114 [Default:CheckIn] Stopped
2019-07-25T22:12:25.114Z,1564092745.114 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-07-25T22:12:25.114Z,1564092745.114 [Default:CheckIn](INFO): Running loop #7
2019-07-25T22:12:25.115Z,1564092745.115 [Default:CheckIn] Running Loop=7
2019-07-25T22:12:25.115Z,1564092745.115 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-07-25T22:12:25.115Z,1564092745.115 [Default:CheckIn:Read_GPS] Running Loop=1
2019-07-25T22:12:26.750Z,1564092746.750 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:12:29.138Z,1564092749.138 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-07-25T22:12:29.994Z,1564092749.994 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:12:32.378Z,1564092752.378 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:12:35.202Z,1564092755.202 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:12:37.230Z,1564092757.230 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:12:40.454Z,1564092760.454 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:12:43.287Z,1564092763.287 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:12:46.530Z,1564092766.530 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:12:49.366Z,1564092769.366 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:12:52.594Z,1564092772.594 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:12:55.410Z,1564092775.410 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:12:58.230Z,1564092778.230 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:13:00.658Z,1564092780.658 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:13:03.486Z,1564092783.486 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:13:06.714Z,1564092786.714 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:13:09.546Z,1564092789.546 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:13:12.774Z,1564092792.774 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:13:15.610Z,1564092795.610 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:13:18.466Z,1564092798.466 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:13:21.682Z,1564092801.682 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:13:24.490Z,1564092804.490 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:13:27.318Z,1564092807.318 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:13:30.550Z,1564092810.550 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:13:33.378Z,1564092813.378 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:13:36.610Z,1564092816.610 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:13:39.438Z,1564092819.438 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:13:42.670Z,1564092822.670 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:13:45.502Z,1564092825.502 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:13:48.734Z,1564092828.734 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:13:51.562Z,1564092831.562 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:13:54.795Z,1564092834.795 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:13:57.622Z,1564092837.622 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:14:00.474Z,1564092840.474 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:14:03.698Z,1564092843.698 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:14:06.506Z,1564092846.506 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:14:09.746Z,1564092849.746 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:14:12.570Z,1564092852.570 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:14:15.798Z,1564092855.798 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:14:18.633Z,1564092858.633 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:14:21.858Z,1564092861.858 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:14:24.690Z,1564092864.690 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:14:25.087Z,1564092865.087 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,221206.00,A,3648.16404,N,12147.28796,W,0.700,0.00,250719,,,A*7B
2019-07-25T22:14:25.090Z,1564092865.090 [NAL9602](INFO): GPS fix at 20190725T221206: (36.802734, -121.788133)
2019-07-25T22:14:25.127Z,1564092865.127 [Default:CheckIn:Read_GPS] Stopped
2019-07-25T22:14:25.127Z,1564092865.127 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-07-25T22:14:33.405Z,1564092873.405 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20190725T211932/Courier0022.lzma
2019-07-25T22:14:34.211Z,1564092874.211 [DataOverHttps](INFO): Moved sent file to Logs/20190725T211932/Courier0022.lzma.bak
2019-07-25T22:14:34.211Z,1564092874.211 [DataOverHttps](INFO): SBD MOMSN=11476257
2019-07-25T22:14:54.502Z,1564092894.502 [DataOverHttps](INFO): Sending 271 bytes from file Logs/20190725T211932/Express0023.lzma
2019-07-25T22:14:55.307Z,1564092895.307 [DataOverHttps](INFO): Moved sent file to Logs/20190725T211932/Express0023.lzma.bak
2019-07-25T22:14:55.308Z,1564092895.308 [DataOverHttps](INFO): SBD MOMSN=11476260
2019-07-25T22:14:55.826Z,1564092895.826 [Default:CheckIn:Read_Iridium] Stopped
2019-07-25T22:14:55.826Z,1564092895.826 [Default:CheckIn:C.Wait] Running Loop=1
2019-07-25T22:14:55.826Z,1564092895.826 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-07-25T22:14:57.403Z,1564092897.403 [NAL9602](INFO): Not Powering down - fast GPS
2019-07-25T22:15:27.701Z,1564092927.701 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-07-25T22:15:27.701Z,1564092927.701 [DVL_micro] Data Fault, FailCount= 1
2019-07-25T22:15:27.701Z,1564092927.701 [DVL_micro](ERROR): Data Fault
2019-07-25T22:15:27.741Z,1564092927.741 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-07-25T22:15:28.178Z,1564092928.178 [DVL_micro](INFO): uninitialize:Powering down
2019-07-25T22:15:28.950Z,1564092928.950 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-07-25T22:15:28.950Z,1564092928.950 [DVL_micro] No Fault, FailCount= 1
2019-07-25T22:15:29.325Z,1564092929.325 [DVL_micro](INFO): Initializing
2019-07-25T22:18:33.546Z,1564093113.546 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-07-25T22:18:33.546Z,1564093113.546 [DVL_micro] Data Fault, FailCount= 1
2019-07-25T22:18:33.546Z,1564093113.546 [DVL_micro](ERROR): Data Fault
2019-07-25T22:18:33.600Z,1564093113.600 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-07-25T22:18:34.010Z,1564093114.010 [DVL_micro](INFO): uninitialize:Powering down
2019-07-25T22:18:34.789Z,1564093114.789 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-07-25T22:18:34.789Z,1564093114.789 [DVL_micro] No Fault, FailCount= 1
2019-07-25T22:18:35.163Z,1564093115.163 [DVL_micro](INFO): Initializing
2019-07-25T22:19:56.392Z,1564093196.392 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-07-25T22:19:56.392Z,1564093196.392 [Default:CheckIn:C.Wait] Stopped
2019-07-25T22:19:56.392Z,1564093196.392 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-07-25T22:19:56.392Z,1564093196.392 [Default:CheckIn:D] Running Loop=1
2019-07-25T22:19:56.802Z,1564093196.802 [Default:CheckIn:D] Stopped
2019-07-25T22:19:56.802Z,1564093196.802 [Default:CheckIn:E] Running Loop=1
2019-07-25T22:19:57.194Z,1564093197.194 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 56.070846 min 
2019-07-25T22:19:57.194Z,1564093197.194 [Default:CheckIn:E] Stopped
2019-07-25T22:19:57.194Z,1564093197.194 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-07-25T22:19:57.194Z,1564093197.194 [Default:CheckIn] Stopped
2019-07-25T22:19:57.194Z,1564093197.194 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-07-25T22:19:57.194Z,1564093197.194 [Default:CheckIn](INFO): Running loop #8
2019-07-25T22:19:57.194Z,1564093197.194 [Default:CheckIn] Running Loop=8
2019-07-25T22:19:57.195Z,1564093197.195 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-07-25T22:19:57.195Z,1564093197.195 [Default:CheckIn:Read_GPS] Running Loop=1
2019-07-25T22:19:58.794Z,1564093198.794 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:19:59.211Z,1564093199.211 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,221740.00,A,3648.16478,N,12147.28394,W,0.330,0.00,250719,,,A*76
2019-07-25T22:19:59.213Z,1564093199.213 [NAL9602](INFO): GPS fix at 20190725T221740: (36.802746, -121.788066)
2019-07-25T22:19:59.241Z,1564093199.241 [Default:CheckIn:Read_GPS] Stopped
2019-07-25T22:19:59.241Z,1564093199.241 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-07-25T22:20:10.542Z,1564093210.542 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20190725T211932/Courier0025.lzma
2019-07-25T22:20:11.347Z,1564093211.347 [DataOverHttps](INFO): Moved sent file to Logs/20190725T211932/Courier0025.lzma.bak
2019-07-25T22:20:11.348Z,1564093211.348 [DataOverHttps](INFO): SBD MOMSN=11476268
2019-07-25T22:20:26.525Z,1564093226.525 [DataOverHttps](INFO): Sending 175 bytes from file Logs/20190725T211932/Express0026.lzma
2019-07-25T22:20:27.331Z,1564093227.331 [DataOverHttps](INFO): Moved sent file to Logs/20190725T211932/Express0026.lzma.bak
2019-07-25T22:20:27.332Z,1564093227.332 [DataOverHttps](INFO): SBD MOMSN=11476271
2019-07-25T22:20:27.901Z,1564093227.901 [Default:CheckIn:Read_Iridium] Stopped
2019-07-25T22:20:27.901Z,1564093227.901 [Default:CheckIn:C.Wait] Running Loop=1
2019-07-25T22:20:27.901Z,1564093227.901 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-07-25T22:21:39.377Z,1564093299.377 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-07-25T22:21:39.377Z,1564093299.377 [DVL_micro] Data Fault, FailCount= 1
2019-07-25T22:21:39.377Z,1564093299.377 [DVL_micro](ERROR): Data Fault
2019-07-25T22:21:39.410Z,1564093299.410 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-07-25T22:21:39.854Z,1564093299.854 [DVL_micro](INFO): uninitialize:Powering down
2019-07-25T22:21:40.639Z,1564093300.639 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-07-25T22:21:40.639Z,1564093300.639 [DVL_micro] No Fault, FailCount= 1
2019-07-25T22:21:40.999Z,1564093300.999 [DVL_micro](INFO): Initializing
2019-07-25T22:22:10.102Z,1564093330.102 [DVL_micro](ERROR): only read 43 of 46 data items
2019-07-25T22:22:10.102Z,1564093330.102 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 0 0 0 0 1920 -1751 296 694 2167.4 -3263.2 312.5 2 -3652.3 -1416.1 312.5 2 2167 -3263 312 2 -3652 -1416 312 2 -13.29 -1.43 257.6 -3.0 21.6 0.005 35.0 1489 85
2019-07-25T22:22:59.779Z,1564093379.779 [NAL9602](INFO): SBD MO Status=2, MOMSN=30030, MT Status=2, MTMSN=0
2019-07-25T22:22:59.779Z,1564093379.779 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-25T22:23:32.499Z,1564093412.499 [NAL9602](INFO): SBD MO Status=2, MOMSN=30030, MT Status=2, MTMSN=0
2019-07-25T22:23:32.500Z,1564093412.500 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-25T22:23:47.071Z,1564093427.071 [NAL9602](INFO): SBD MO Status=2, MOMSN=30030, MT Status=2, MTMSN=0
2019-07-25T22:23:47.071Z,1564093427.071 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-25T22:24:04.013Z,1564093444.013 [NAL9602](INFO): SBD MO Status=2, MOMSN=30030, MT Status=2, MTMSN=0
2019-07-25T22:24:04.013Z,1564093444.013 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-25T22:24:34.724Z,1564093474.724 [NAL9602](INFO): SBD MO Status=2, MOMSN=30030, MT Status=2, MTMSN=0
2019-07-25T22:24:34.724Z,1564093474.724 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-25T22:24:43.205Z,1564093483.205 [NAL9602](INFO): SBD MO Status=2, MOMSN=30030, MT Status=2, MTMSN=0
2019-07-25T22:24:43.205Z,1564093483.205 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-25T22:24:45.221Z,1564093485.221 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-07-25T22:24:45.221Z,1564093485.221 [DVL_micro] Data Fault, FailCount= 1
2019-07-25T22:24:45.221Z,1564093485.221 [DVL_micro](ERROR): Data Fault
2019-07-25T22:24:45.278Z,1564093485.278 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-07-25T22:24:45.694Z,1564093485.694 [DVL_micro](INFO): uninitialize:Powering down
2019-07-25T22:24:46.467Z,1564093486.467 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-07-25T22:24:46.467Z,1564093486.467 [DVL_micro] No Fault, FailCount= 1
2019-07-25T22:24:46.843Z,1564093486.843 [DVL_micro](INFO): Initializing
2019-07-25T22:24:56.552Z,1564093496.552 [NAL9602](INFO): SBD MO Status=2, MOMSN=30030, MT Status=2, MTMSN=0
2019-07-25T22:24:56.553Z,1564093496.553 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-25T22:25:00.978Z,1564093500.978 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-07-25T22:25:28.470Z,1564093528.470 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-07-25T22:25:28.470Z,1564093528.470 [Default:CheckIn:C.Wait] Stopped
2019-07-25T22:25:28.470Z,1564093528.470 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-07-25T22:25:28.470Z,1564093528.470 [Default:CheckIn:D] Running Loop=1
2019-07-25T22:25:28.909Z,1564093528.909 [Default:CheckIn:D] Stopped
2019-07-25T22:25:28.909Z,1564093528.909 [Default:CheckIn:E] Running Loop=1
2019-07-25T22:25:29.297Z,1564093529.297 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 61.605973 min 
2019-07-25T22:25:29.297Z,1564093529.297 [Default:CheckIn:E] Stopped
2019-07-25T22:25:29.297Z,1564093529.297 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-07-25T22:25:29.297Z,1564093529.297 [Default:CheckIn] Stopped
2019-07-25T22:25:29.297Z,1564093529.297 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-07-25T22:25:29.298Z,1564093529.298 [Default:CheckIn](INFO): Running loop #9
2019-07-25T22:25:29.298Z,1564093529.298 [Default:CheckIn] Running Loop=9
2019-07-25T22:25:29.298Z,1564093529.298 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-07-25T22:25:29.298Z,1564093529.298 [Default:CheckIn:Read_GPS] Running Loop=1
2019-07-25T22:25:30.882Z,1564093530.882 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:25:31.275Z,1564093531.275 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,222312.00,A,3648.16534,N,12147.28575,W,0.428,0.00,250719,,,A*78
2019-07-25T22:25:31.277Z,1564093531.277 [NAL9602](INFO): GPS fix at 20190725T222312: (36.802756, -121.788096)
2019-07-25T22:25:31.301Z,1564093531.301 [Default:CheckIn:Read_GPS] Stopped
2019-07-25T22:25:31.301Z,1564093531.301 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-07-25T22:25:35.689Z,1564093535.689 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20190725T211932/Courier0028.lzma
2019-07-25T22:25:36.467Z,1564093536.467 [DataOverHttps](INFO): Moved sent file to Logs/20190725T211932/Courier0028.lzma.bak
2019-07-25T22:25:36.468Z,1564093536.468 [DataOverHttps](INFO): SBD MOMSN=11476276
2019-07-25T22:25:55.006Z,1564093555.006 [DataOverHttps](INFO): Sending 227 bytes from file Logs/20190725T211932/Express0029.lzma
2019-07-25T22:25:55.811Z,1564093555.811 [DataOverHttps](INFO): Moved sent file to Logs/20190725T211932/Express0029.lzma.bak
2019-07-25T22:25:55.812Z,1564093555.812 [DataOverHttps](INFO): SBD MOMSN=11476279
2019-07-25T22:25:56.437Z,1564093556.437 [Default:CheckIn:Read_Iridium] Stopped
2019-07-25T22:25:56.437Z,1564093556.437 [Default:CheckIn:C.Wait] Running Loop=1
2019-07-25T22:25:56.438Z,1564093556.438 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-07-25T22:26:03.678Z,1564093563.678 [NAL9602](INFO): Not Powering down - fast GPS
2019-07-25T22:27:51.153Z,1564093671.153 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-07-25T22:27:51.153Z,1564093671.153 [DVL_micro] Data Fault, FailCount= 1
2019-07-25T22:27:51.153Z,1564093671.153 [DVL_micro](ERROR): Data Fault
2019-07-25T22:27:51.185Z,1564093671.185 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-07-25T22:27:51.623Z,1564093671.623 [DVL_micro](INFO): uninitialize:Powering down
2019-07-25T22:27:52.393Z,1564093672.393 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-07-25T22:27:52.393Z,1564093672.393 [DVL_micro] No Fault, FailCount= 1
2019-07-25T22:27:52.768Z,1564093672.768 [DVL_micro](INFO): Initializing
2019-07-25T22:30:56.989Z,1564093856.989 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-07-25T22:30:56.989Z,1564093856.989 [DVL_micro] Data Fault, FailCount= 1
2019-07-25T22:30:56.989Z,1564093856.989 [DVL_micro](ERROR): Data Fault
2019-07-25T22:30:57.014Z,1564093857.014 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-07-25T22:30:57.014Z,1564093857.014 [Default:CheckIn:C.Wait] Stopped
2019-07-25T22:30:57.014Z,1564093857.014 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-07-25T22:30:57.014Z,1564093857.014 [Default:CheckIn:D] Running Loop=1
2019-07-25T22:30:57.023Z,1564093857.023 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-07-25T22:30:57.462Z,1564093857.462 [DVL_micro](INFO): uninitialize:Powering down
2019-07-25T22:30:57.516Z,1564093857.516 [Default:CheckIn:D] Stopped
2019-07-25T22:30:57.516Z,1564093857.516 [Default:CheckIn:E] Running Loop=1
2019-07-25T22:30:57.826Z,1564093857.826 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 67.082743 min 
2019-07-25T22:30:57.826Z,1564093857.826 [Default:CheckIn:E] Stopped
2019-07-25T22:30:57.827Z,1564093857.827 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-07-25T22:30:57.827Z,1564093857.827 [Default:CheckIn] Stopped
2019-07-25T22:30:57.827Z,1564093857.827 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-07-25T22:30:57.827Z,1564093857.827 [Default:CheckIn](INFO): Running loop #10
2019-07-25T22:30:57.827Z,1564093857.827 [Default:CheckIn] Running Loop=10
2019-07-25T22:30:57.827Z,1564093857.827 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-07-25T22:30:57.827Z,1564093857.827 [Default:CheckIn:Read_GPS] Running Loop=1
2019-07-25T22:30:58.236Z,1564093858.236 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-07-25T22:30:58.236Z,1564093858.236 [DVL_micro] No Fault, FailCount= 1
2019-07-25T22:30:58.624Z,1564093858.624 [DVL_micro](INFO): Initializing
2019-07-25T22:30:59.426Z,1564093859.426 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:30:59.815Z,1564093859.815 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,222840.00,A,3648.16384,N,12147.28028,W,0.292,259.38,250719,,,A*76
2019-07-25T22:30:59.817Z,1564093859.817 [NAL9602](INFO): GPS fix at 20190725T222840: (36.802731, -121.788005)
2019-07-25T22:30:59.845Z,1564093859.845 [Default:CheckIn:Read_GPS] Stopped
2019-07-25T22:30:59.845Z,1564093859.845 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-07-25T22:31:07.045Z,1564093867.045 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20190725T211932/Courier0031.lzma
2019-07-25T22:31:07.851Z,1564093867.851 [DataOverHttps](INFO): Moved sent file to Logs/20190725T211932/Courier0031.lzma.bak
2019-07-25T22:31:07.852Z,1564093867.852 [DataOverHttps](INFO): SBD MOMSN=11476285
2019-07-25T22:31:25.114Z,1564093885.114 [DataOverHttps](INFO): Sending 173 bytes from file Logs/20190725T211932/Express0032.lzma
2019-07-25T22:31:25.920Z,1564093885.920 [DataOverHttps](INFO): Moved sent file to Logs/20190725T211932/Express0032.lzma.bak
2019-07-25T22:31:25.920Z,1564093885.920 [DataOverHttps](INFO): SBD MOMSN=11476288
2019-07-25T22:31:26.514Z,1564093886.514 [Default:CheckIn:Read_Iridium] Stopped
2019-07-25T22:31:26.514Z,1564093886.514 [Default:CheckIn:C.Wait] Running Loop=1
2019-07-25T22:31:26.514Z,1564093886.514 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-07-25T22:31:30.522Z,1564093890.522 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2019-07-25T22:31:30.594Z,1564093890.594 [NAL9602](FAULT): received: 
+SBDI: 2, 30030, 2, 0, 0, 0

OK
2019-07-25T22:31:30.594Z,1564093890.594 [NAL9602] Data Fault, FailCount= 1
2019-07-25T22:31:30.594Z,1564093890.594 [NAL9602](ERROR): Data Fault
2019-07-25T22:31:30.634Z,1564093890.634 [CBIT](ERROR): Data Fault in component: NAL9602
2019-07-25T22:31:30.950Z,1564093890.950 [NAL9602](INFO): Powering down
2019-07-25T22:31:31.767Z,1564093891.767 [CBIT](INFO): Clearing failed state for component NAL9602
2019-07-25T22:31:31.767Z,1564093891.767 [NAL9602] No Fault, FailCount= 1
2019-07-25T22:32:01.226Z,1564093921.226 [NAL9602](INFO): Powering up NAL9602
2019-07-25T22:32:12.130Z,1564093932.130 [NAL9602](INFO): NAL9602 initialized
2019-07-25T22:32:43.245Z,1564093963.245 [NAL9602](INFO): Not Powering down - fast GPS
2019-07-25T22:34:02.845Z,1564094042.845 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-07-25T22:34:02.845Z,1564094042.845 [DVL_micro] Data Fault, FailCount= 1
2019-07-25T22:34:02.845Z,1564094042.845 [DVL_micro](ERROR): Data Fault
2019-07-25T22:34:02.902Z,1564094042.902 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-07-25T22:34:03.302Z,1564094043.302 [DVL_micro](INFO): uninitialize:Powering down
2019-07-25T22:34:04.110Z,1564094044.110 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-07-25T22:34:04.110Z,1564094044.110 [DVL_micro] No Fault, FailCount= 1
2019-07-25T22:34:04.461Z,1564094044.461 [DVL_micro](INFO): Initializing
2019-07-25T22:35:00.631Z,1564094100.631 [BPC1](ERROR): Battery stick #38 (s/n: 0139) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0.
2019-07-25T22:35:00.632Z,1564094100.632 [BPC1](ERROR): Battery stick #39 (s/n: 00F0) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0.
2019-07-25T22:35:00.632Z,1564094100.632 [BPC1](INFO): Calculating totals. Valid battery stick count: 55. Valid reserve battery stick count: 5.
2019-07-25T22:35:00.635Z,1564094100.635 [BPC1](INFO): Received data from all battery sticks.
2019-07-25T22:36:27.093Z,1564094187.093 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-07-25T22:36:27.093Z,1564094187.093 [Default:CheckIn:C.Wait] Stopped
2019-07-25T22:36:27.093Z,1564094187.093 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-07-25T22:36:27.093Z,1564094187.093 [Default:CheckIn:D] Running Loop=1
2019-07-25T22:36:27.501Z,1564094187.501 [Default:CheckIn:D] Stopped
2019-07-25T22:36:27.501Z,1564094187.501 [Default:CheckIn:E] Running Loop=1
2019-07-25T22:36:27.903Z,1564094187.903 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 72.582495 min 
2019-07-25T22:36:27.903Z,1564094187.903 [Default:CheckIn:E] Stopped
2019-07-25T22:36:27.903Z,1564094187.903 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-07-25T22:36:27.903Z,1564094187.903 [Default:CheckIn] Stopped
2019-07-25T22:36:27.903Z,1564094187.903 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-07-25T22:36:27.903Z,1564094187.903 [Default:CheckIn](INFO): Running loop #11
2019-07-25T22:36:27.903Z,1564094187.903 [Default:CheckIn] Running Loop=11
2019-07-25T22:36:27.904Z,1564094187.904 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-07-25T22:36:27.904Z,1564094187.904 [Default:CheckIn:Read_GPS] Running Loop=1
2019-07-25T22:36:29.494Z,1564094189.494 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:36:32.346Z,1564094192.346 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-07-25T22:36:33.162Z,1564094193.162 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:36:35.550Z,1564094195.550 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:36:38.782Z,1564094198.782 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:36:41.610Z,1564094201.610 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:36:44.858Z,1564094204.858 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:36:47.670Z,1564094207.670 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:36:50.502Z,1564094210.502 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:36:53.734Z,1564094213.734 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:36:56.558Z,1564094216.558 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:36:59.794Z,1564094219.794 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:37:02.622Z,1564094222.622 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:37:05.858Z,1564094225.858 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:37:08.665Z,1564094228.665 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-07-25T22:37:08.665Z,1564094228.665 [DVL_micro] Data Fault, FailCount= 1
2019-07-25T22:37:08.665Z,1564094228.665 [DVL_micro](ERROR): Data Fault
2019-07-25T22:37:08.678Z,1564094228.678 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:37:08.734Z,1564094228.734 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-07-25T22:37:09.139Z,1564094229.139 [DVL_micro](INFO): uninitialize:Powering down
2019-07-25T22:37:09.912Z,1564094229.912 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-07-25T22:37:09.912Z,1564094229.912 [DVL_micro] No Fault, FailCount= 1
2019-07-25T22:37:10.287Z,1564094230.287 [DVL_micro](INFO): Initializing
2019-07-25T22:37:11.910Z,1564094231.910 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:37:14.738Z,1564094234.738 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:37:17.566Z,1564094237.566 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:37:20.798Z,1564094240.798 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:37:23.634Z,1564094243.634 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:37:26.456Z,1564094246.456 [DVL_micro](ERROR): only read 44 of 46 data items
2019-07-25T22:37:26.456Z,1564094246.456 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 0 0 0 0 1677 -2707 443 780 2 3 2 2 1646.9 -4653.9 52.0 2 -4898.7 -609.1 52.0 2 1646 -4653898 -609 52 2 -13.37 -1.48 257.6 -3.0 21.7 0.005 35.0 1489 85
2019-07-25T22:37:26.867Z,1564094246.867 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:37:29.718Z,1564094249.718 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:37:32.979Z,1564094252.979 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:37:35.762Z,1564094255.762 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:37:38.582Z,1564094258.582 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:37:41.810Z,1564094261.810 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:37:44.638Z,1564094264.638 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:37:47.870Z,1564094267.870 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:37:50.694Z,1564094270.694 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:37:53.930Z,1564094273.930 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:37:56.754Z,1564094276.754 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:37:59.986Z,1564094279.986 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:38:02.818Z,1564094282.818 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:38:05.646Z,1564094285.646 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:38:08.882Z,1564094288.882 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:38:11.738Z,1564094291.738 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:38:14.966Z,1564094294.966 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:38:17.774Z,1564094297.774 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:38:20.998Z,1564094300.998 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:38:23.826Z,1564094303.826 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:38:27.054Z,1564094307.054 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:38:29.882Z,1564094309.882 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:38:32.714Z,1564094312.714 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:38:35.942Z,1564094315.942 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:38:38.786Z,1564094318.786 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:38:42.018Z,1564094322.018 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:38:44.830Z,1564094324.830 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:38:48.070Z,1564094328.070 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:38:50.898Z,1564094330.898 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:38:53.738Z,1564094333.738 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:38:56.970Z,1564094336.970 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:38:59.790Z,1564094339.790 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:39:03.010Z,1564094343.010 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:39:05.842Z,1564094345.842 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:39:09.077Z,1564094349.077 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:39:11.902Z,1564094351.902 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:39:15.138Z,1564094355.138 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:39:17.958Z,1564094357.958 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:39:20.794Z,1564094360.794 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:39:24.018Z,1564094364.018 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:39:26.850Z,1564094366.850 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:39:30.078Z,1564094370.078 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:39:32.922Z,1564094372.922 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:39:36.143Z,1564094376.143 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:39:39.002Z,1564094379.002 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:39:41.794Z,1564094381.794 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:39:45.034Z,1564094385.034 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:39:47.866Z,1564094387.866 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:39:51.098Z,1564094391.098 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:39:53.914Z,1564094393.914 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:39:57.150Z,1564094397.150 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:39:59.978Z,1564094399.978 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:40:03.222Z,1564094403.222 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:40:06.042Z,1564094406.042 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:40:08.866Z,1564094408.866 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:40:12.098Z,1564094412.098 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:40:14.517Z,1564094414.517 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-07-25T22:40:14.517Z,1564094414.517 [DVL_micro] Data Fault, FailCount= 1
2019-07-25T22:40:14.517Z,1564094414.517 [DVL_micro](ERROR): Data Fault
2019-07-25T22:40:14.550Z,1564094414.550 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-07-25T22:40:14.982Z,1564094414.982 [DVL_micro](INFO): uninitialize:Powering down
2019-07-25T22:40:14.998Z,1564094414.998 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:40:15.790Z,1564094415.790 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-07-25T22:40:15.790Z,1564094415.790 [DVL_micro] No Fault, FailCount= 1
2019-07-25T22:40:16.127Z,1564094416.127 [DVL_micro](INFO): Initializing
2019-07-25T22:40:18.154Z,1564094418.154 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:40:20.994Z,1564094420.994 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:40:24.218Z,1564094424.218 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:40:27.046Z,1564094427.046 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:40:29.874Z,1564094429.874 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:40:33.102Z,1564094433.102 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:40:35.934Z,1564094435.934 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:40:39.178Z,1564094439.178 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:40:42.054Z,1564094442.054 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:40:45.246Z,1564094445.246 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:40:48.054Z,1564094448.054 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:40:51.282Z,1564094451.282 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:40:54.126Z,1564094454.126 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:40:56.938Z,1564094456.938 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:41:00.174Z,1564094460.174 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:41:02.998Z,1564094462.998 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:41:06.242Z,1564094466.242 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:41:09.058Z,1564094469.058 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:41:12.302Z,1564094472.302 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:41:15.122Z,1564094475.122 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:41:18.354Z,1564094478.354 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:41:21.186Z,1564094481.186 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:41:24.038Z,1564094484.038 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:41:27.278Z,1564094487.278 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:41:28.086Z,1564094488.086 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-07-25T22:36:27.9Z
2019-07-25T22:41:28.086Z,1564094488.086 [Default:CheckIn:Read_GPS] Stopped
2019-07-25T22:41:28.086Z,1564094488.086 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-07-25T22:41:36.197Z,1564094496.197 [DataOverHttps](INFO): Sending 44 bytes from file Logs/20190725T211932/Courier0034.lzma
2019-07-25T22:41:37.003Z,1564094497.003 [DataOverHttps](INFO): Moved sent file to Logs/20190725T211932/Courier0034.lzma.bak
2019-07-25T22:41:37.004Z,1564094497.004 [DataOverHttps](INFO): SBD MOMSN=11476293
2019-07-25T22:41:58.494Z,1564094518.494 [DataOverHttps](INFO): Sending 279 bytes from file Logs/20190725T211932/Express0035.lzma
2019-07-25T22:41:59.299Z,1564094519.299 [DataOverHttps](INFO): Moved sent file to Logs/20190725T211932/Express0035.lzma.bak
2019-07-25T22:41:59.300Z,1564094519.300 [DataOverHttps](INFO): SBD MOMSN=11476295
2019-07-25T22:41:59.957Z,1564094519.957 [NAL9602](INFO): Not Powering down - fast GPS
2019-07-25T22:41:59.982Z,1564094519.982 [Default:CheckIn:Read_Iridium] Stopped
2019-07-25T22:41:59.982Z,1564094519.982 [Default:CheckIn:C.Wait] Running Loop=1
2019-07-25T22:41:59.982Z,1564094519.982 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-07-25T22:43:20.347Z,1564094600.347 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-07-25T22:43:20.347Z,1564094600.347 [DVL_micro] Data Fault, FailCount= 1
2019-07-25T22:43:20.347Z,1564094600.347 [DVL_micro](ERROR): Data Fault
2019-07-25T22:43:20.385Z,1564094600.385 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-07-25T22:43:20.823Z,1564094600.823 [DVL_micro](INFO): uninitialize:Powering down
2019-07-25T22:43:21.602Z,1564094601.602 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-07-25T22:43:21.602Z,1564094601.602 [DVL_micro] No Fault, FailCount= 1
2019-07-25T22:43:21.971Z,1564094601.971 [DVL_micro](INFO): Initializing
2019-07-25T22:46:26.192Z,1564094786.192 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-07-25T22:46:26.193Z,1564094786.193 [DVL_micro] Data Fault, FailCount= 1
2019-07-25T22:46:26.193Z,1564094786.193 [DVL_micro](ERROR): Data Fault
2019-07-25T22:46:26.230Z,1564094786.230 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-07-25T22:46:26.666Z,1564094786.666 [DVL_micro](INFO): uninitialize:Powering down
2019-07-25T22:46:27.482Z,1564094787.482 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-07-25T22:46:27.482Z,1564094787.482 [DVL_micro] No Fault, FailCount= 1
2019-07-25T22:46:27.811Z,1564094787.811 [DVL_micro](INFO): Initializing
2019-07-25T22:47:00.585Z,1564094820.585 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-07-25T22:47:00.585Z,1564094820.585 [Default:CheckIn:C.Wait] Stopped
2019-07-25T22:47:00.585Z,1564094820.585 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-07-25T22:47:00.585Z,1564094820.585 [Default:CheckIn:D] Running Loop=1
2019-07-25T22:47:00.969Z,1564094820.969 [Default:CheckIn:D] Stopped
2019-07-25T22:47:00.969Z,1564094820.969 [Default:CheckIn:E] Running Loop=1
2019-07-25T22:47:01.362Z,1564094821.362 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 83.140308 min 
2019-07-25T22:47:01.362Z,1564094821.362 [Default:CheckIn:E] Stopped
2019-07-25T22:47:01.362Z,1564094821.362 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-07-25T22:47:01.362Z,1564094821.362 [Default:CheckIn] Stopped
2019-07-25T22:47:01.362Z,1564094821.362 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-07-25T22:47:01.363Z,1564094821.363 [Default:CheckIn](INFO): Running loop #12
2019-07-25T22:47:01.363Z,1564094821.363 [Default:CheckIn] Running Loop=12
2019-07-25T22:47:01.363Z,1564094821.363 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-07-25T22:47:01.363Z,1564094821.363 [Default:CheckIn:Read_GPS] Running Loop=1
2019-07-25T22:47:02.952Z,1564094822.952 [NAL9602](FAULT): GPS failed to acquire within timeout.
2019-07-25T22:47:02.952Z,1564094822.952 [NAL9602] Data Fault, FailCount= 1
2019-07-25T22:47:02.952Z,1564094822.952 [NAL9602](ERROR): Data Fault
2019-07-25T22:47:03.030Z,1564094823.030 [CBIT](ERROR): Data Fault in component: NAL9602
2019-07-25T22:47:03.418Z,1564094823.418 [NAL9602](INFO): Powering down
2019-07-25T22:47:04.234Z,1564094824.234 [CBIT](INFO): Clearing failed state for component NAL9602
2019-07-25T22:47:04.234Z,1564094824.234 [NAL9602] No Fault, FailCount= 1
2019-07-25T22:47:33.681Z,1564094853.681 [NAL9602](INFO): Powering up NAL9602
2019-07-25T22:47:44.568Z,1564094864.568 [NAL9602](INFO): NAL9602 initialized
2019-07-25T22:47:45.414Z,1564094865.414 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:49:32.031Z,1564094972.031 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-07-25T22:49:32.031Z,1564094972.031 [DVL_micro] Data Fault, FailCount= 1
2019-07-25T22:49:32.031Z,1564094972.031 [DVL_micro](ERROR): Data Fault
2019-07-25T22:49:32.065Z,1564094972.065 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-07-25T22:49:32.502Z,1564094972.502 [DVL_micro](INFO): uninitialize:Powering down
2019-07-25T22:49:33.277Z,1564094973.277 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-07-25T22:49:33.277Z,1564094973.277 [DVL_micro] No Fault, FailCount= 1
2019-07-25T22:49:33.653Z,1564094973.653 [DVL_micro](INFO): Initializing
2019-07-25T22:52:01.529Z,1564095121.529 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-07-25T22:47:01.4Z
2019-07-25T22:52:01.529Z,1564095121.529 [Default:CheckIn:Read_GPS] Stopped
2019-07-25T22:52:01.529Z,1564095121.529 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-07-25T22:52:09.877Z,1564095129.877 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190725T211932/Courier0037.lzma
2019-07-25T22:52:10.683Z,1564095130.683 [DataOverHttps](INFO): Moved sent file to Logs/20190725T211932/Courier0037.lzma.bak
2019-07-25T22:52:10.684Z,1564095130.684 [DataOverHttps](INFO): SBD MOMSN=11476439
2019-07-25T22:52:34.566Z,1564095154.566 [DataOverHttps](INFO): Sending 196 bytes from file Logs/20190725T211932/Express0038.lzma
2019-07-25T22:52:35.371Z,1564095155.371 [DataOverHttps](INFO): Moved sent file to Logs/20190725T211932/Express0038.lzma.bak
2019-07-25T22:52:35.372Z,1564095155.372 [DataOverHttps](INFO): SBD MOMSN=11476441
2019-07-25T22:52:35.889Z,1564095155.889 [Default:CheckIn:Read_Iridium] Stopped
2019-07-25T22:52:35.889Z,1564095155.889 [Default:CheckIn:C.Wait] Running Loop=1
2019-07-25T22:52:35.889Z,1564095155.889 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-07-25T22:52:37.871Z,1564095157.871 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-07-25T22:52:37.871Z,1564095157.871 [DVL_micro] Data Fault, FailCount= 1
2019-07-25T22:52:37.871Z,1564095157.871 [DVL_micro](ERROR): Data Fault
2019-07-25T22:52:37.925Z,1564095157.925 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-07-25T22:52:38.342Z,1564095158.342 [DVL_micro](INFO): uninitialize:Powering down
2019-07-25T22:52:39.115Z,1564095159.115 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-07-25T22:52:39.115Z,1564095159.115 [DVL_micro] No Fault, FailCount= 1
2019-07-25T22:52:39.493Z,1564095159.493 [DVL_micro](INFO): Initializing
2019-07-25T22:52:47.571Z,1564095167.571 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-07-25T22:53:18.302Z,1564095198.302 [NAL9602](INFO): Not Powering down - fast GPS
2019-07-25T22:54:48.772Z,1564095288.772 [DVL_micro](ERROR): only read 44 of 46 data items
2019-07-25T22:54:48.772Z,1564095288.772 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 0 0 0 0 742 -1107 603 731 2 3 2 2 185.5 -2453.1 261.2 2 -2435.6 345.6 261.2 2 185 -2453 261 2 -2435 345 261 2 -13.39 -1.51 257.6 -3.0 21.8 0.005 3597
2019-07-25T22:55:43.707Z,1564095343.707 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-07-25T22:55:43.707Z,1564095343.707 [DVL_micro] Data Fault, FailCount= 1
2019-07-25T22:55:43.707Z,1564095343.707 [DVL_micro](ERROR): Data Fault
2019-07-25T22:55:43.762Z,1564095343.762 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-07-25T22:55:44.178Z,1564095344.178 [DVL_micro](INFO): uninitialize:Powering down
2019-07-25T22:55:44.966Z,1564095344.966 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-07-25T22:55:44.966Z,1564095344.966 [DVL_micro] No Fault, FailCount= 1
2019-07-25T22:55:45.329Z,1564095345.329 [DVL_micro](INFO): Initializing
2019-07-25T22:57:36.444Z,1564095456.444 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-07-25T22:57:36.444Z,1564095456.444 [Default:CheckIn:C.Wait] Stopped
2019-07-25T22:57:36.444Z,1564095456.444 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-07-25T22:57:36.444Z,1564095456.444 [Default:CheckIn:D] Running Loop=1
2019-07-25T22:57:36.853Z,1564095456.853 [Default:CheckIn:D] Stopped
2019-07-25T22:57:36.853Z,1564095456.853 [Default:CheckIn:E] Running Loop=1
2019-07-25T22:57:37.261Z,1564095457.261 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 93.738371 min 
2019-07-25T22:57:37.262Z,1564095457.263 [Default:CheckIn:E] Stopped
2019-07-25T22:57:37.263Z,1564095457.263 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-07-25T22:57:37.263Z,1564095457.263 [Default:CheckIn] Stopped
2019-07-25T22:57:37.263Z,1564095457.263 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-07-25T22:57:37.263Z,1564095457.263 [Default:CheckIn](INFO): Running loop #13
2019-07-25T22:57:37.263Z,1564095457.263 [Default:CheckIn] Running Loop=13
2019-07-25T22:57:37.263Z,1564095457.263 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-07-25T22:57:37.263Z,1564095457.263 [Default:CheckIn:Read_GPS] Running Loop=1
2019-07-25T22:57:38.894Z,1564095458.894 [NAL9602](DEBUG): Fix Requested
2019-07-25T22:57:39.251Z,1564095459.251 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,225517.00,A,3648.16597,N,12147.27635,W,0.311,309.75,250719,,,A*78
2019-07-25T22:57:39.253Z,1564095459.253 [NAL9602](INFO): GPS fix at 20190725T225517: (36.802766, -121.787939)
2019-07-25T22:57:39.316Z,1564095459.316 [Default:CheckIn:Read_GPS] Stopped
2019-07-25T22:57:39.316Z,1564095459.316 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-07-25T22:57:47.119Z,1564095467.119 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20190725T211932/Courier0040.lzma
2019-07-25T22:57:47.847Z,1564095467.847 [DataOverHttps](INFO): Moved sent file to Logs/20190725T211932/Courier0040.lzma.bak
2019-07-25T22:57:47.848Z,1564095467.848 [DataOverHttps](INFO): SBD MOMSN=11476498
2019-07-25T22:58:07.694Z,1564095487.694 [DataOverHttps](INFO): Sending 229 bytes from file Logs/20190725T211932/Express0041.lzma
2019-07-25T22:58:08.499Z,1564095488.499 [DataOverHttps](INFO): Moved sent file to Logs/20190725T211932/Express0041.lzma.bak
2019-07-25T22:58:08.500Z,1564095488.500 [DataOverHttps](INFO): SBD MOMSN=11476501
2019-07-25T22:58:09.109Z,1564095489.109 [Default:CheckIn:Read_Iridium] Stopped
2019-07-25T22:58:09.109Z,1564095489.109 [Default:CheckIn:C.Wait] Running Loop=1
2019-07-25T22:58:09.109Z,1564095489.109 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-07-25T22:58:09.892Z,1564095489.892 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2019-07-25T22:58:09.966Z,1564095489.966 [NAL9602](FAULT): received: 
+CSQ:0

OK030, 2, 0, 0, 0

OK
2019-07-25T22:58:09.966Z,1564095489.966 [NAL9602] Data Fault, FailCount= 2
2019-07-25T22:58:09.966Z,1564095489.966 [NAL9602](ERROR): Data Fault
2019-07-25T22:58:10.026Z,1564095490.026 [CBIT](ERROR): Data Fault in component: NAL9602
2019-07-25T22:58:10.277Z,1564095490.277 [NAL9602](INFO): Powering down
2019-07-25T22:58:11.133Z,1564095491.133 [CBIT](INFO): Clearing failed state for component NAL9602
2019-07-25T22:58:11.134Z,1564095491.134 [NAL9602] No Fault, FailCount= 2
2019-07-25T22:58:40.581Z,1564095520.581 [NAL9602](INFO): Powering up NAL9602
2019-07-25T22:58:49.469Z,1564095529.469 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-07-25T22:58:49.469Z,1564095529.469 [DVL_micro] Data Fault, FailCount= 1
2019-07-25T22:58:49.469Z,1564095529.469 [DVL_micro](ERROR): Data Fault
2019-07-25T22:58:49.501Z,1564095529.501 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-07-25T22:58:49.942Z,1564095529.942 [DVL_micro](INFO): uninitialize:Powering down
2019-07-25T22:58:50.708Z,1564095530.708 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-07-25T22:58:50.708Z,1564095530.708 [DVL_micro] No Fault, FailCount= 1
2019-07-25T22:58:51.091Z,1564095531.091 [DVL_micro](INFO): Initializing
2019-07-25T22:58:51.492Z,1564095531.492 [NAL9602](INFO): NAL9602 initialized
2019-07-25T22:59:22.593Z,1564095562.593 [NAL9602](INFO): Not Powering down - fast GPS
2019-07-25T23:01:55.305Z,1564095715.305 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-07-25T23:01:55.305Z,1564095715.305 [DVL_micro] Data Fault, FailCount= 1
2019-07-25T23:01:55.305Z,1564095715.305 [DVL_micro](ERROR): Data Fault
2019-07-25T23:01:55.342Z,1564095715.342 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-07-25T23:01:55.786Z,1564095715.786 [DVL_micro](INFO): uninitialize:Powering down
2019-07-25T23:01:56.562Z,1564095716.562 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-07-25T23:01:56.562Z,1564095716.562 [DVL_micro] No Fault, FailCount= 1
2019-07-25T23:01:56.933Z,1564095716.933 [DVL_micro](INFO): Initializing
2019-07-25T23:03:09.670Z,1564095789.670 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-07-25T23:03:09.670Z,1564095789.670 [Default:CheckIn:C.Wait] Stopped
2019-07-25T23:03:09.670Z,1564095789.670 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-07-25T23:03:09.670Z,1564095789.670 [Default:CheckIn:D] Running Loop=1
2019-07-25T23:03:10.073Z,1564095790.073 [Default:CheckIn:D] Stopped
2019-07-25T23:03:10.073Z,1564095790.073 [Default:CheckIn:E] Running Loop=1
2019-07-25T23:03:10.482Z,1564095790.482 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 99.292041 min 
2019-07-25T23:03:10.482Z,1564095790.482 [Default:CheckIn:E] Stopped
2019-07-25T23:03:10.482Z,1564095790.482 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-07-25T23:03:10.482Z,1564095790.482 [Default:CheckIn] Stopped
2019-07-25T23:03:10.482Z,1564095790.482 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-07-25T23:03:10.483Z,1564095790.483 [Default:CheckIn](INFO): Running loop #14
2019-07-25T23:03:10.483Z,1564095790.483 [Default:CheckIn] Running Loop=14
2019-07-25T23:03:10.483Z,1564095790.483 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-07-25T23:03:10.483Z,1564095790.483 [Default:CheckIn:Read_GPS] Running Loop=1
2019-07-25T23:03:12.082Z,1564095792.082 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:03:14.521Z,1564095794.521 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-07-25T23:03:15.314Z,1564095795.314 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:03:18.162Z,1564095798.162 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:03:20.998Z,1564095800.998 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:03:23.394Z,1564095803.394 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:03:26.218Z,1564095806.218 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:03:29.054Z,1564095809.054 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:03:31.878Z,1564095811.878 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:03:35.114Z,1564095815.114 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:03:37.938Z,1564095817.938 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:03:41.174Z,1564095821.174 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:03:44.014Z,1564095824.014 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:03:47.234Z,1564095827.234 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:03:50.094Z,1564095830.094 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:03:53.322Z,1564095833.322 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:03:56.114Z,1564095836.114 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:03:59.354Z,1564095839.354 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:04:02.182Z,1564095842.182 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:04:05.414Z,1564095845.414 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:04:08.238Z,1564095848.238 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:04:11.474Z,1564095851.474 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:04:14.306Z,1564095854.306 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:04:17.126Z,1564095857.126 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:04:19.954Z,1564095859.954 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:04:23.190Z,1564095863.190 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:04:26.022Z,1564095866.022 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:04:29.250Z,1564095869.250 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:04:32.098Z,1564095872.098 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:04:35.322Z,1564095875.322 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:04:38.138Z,1564095878.138 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:04:41.362Z,1564095881.362 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:04:44.198Z,1564095884.198 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:04:47.422Z,1564095887.422 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:04:50.250Z,1564095890.250 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:04:53.486Z,1564095893.486 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:04:56.318Z,1564095896.318 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:04:59.562Z,1564095899.562 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:05:01.151Z,1564095901.151 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-07-25T23:05:01.151Z,1564095901.151 [DVL_micro] Data Fault, FailCount= 1
2019-07-25T23:05:01.151Z,1564095901.151 [DVL_micro](ERROR): Data Fault
2019-07-25T23:05:01.191Z,1564095901.191 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-07-25T23:05:01.630Z,1564095901.630 [DVL_micro](INFO): uninitialize:Powering down
2019-07-25T23:05:02.378Z,1564095902.378 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:05:02.426Z,1564095902.426 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-07-25T23:05:02.426Z,1564095902.426 [DVL_micro] No Fault, FailCount= 1
2019-07-25T23:05:02.775Z,1564095902.775 [DVL_micro](INFO): Initializing
2019-07-25T23:05:05.210Z,1564095905.210 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:05:08.026Z,1564095908.026 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:05:11.262Z,1564095911.262 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:05:14.086Z,1564095914.086 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:05:17.318Z,1564095917.318 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:05:20.146Z,1564095920.146 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:05:23.382Z,1564095923.382 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:05:26.206Z,1564095926.206 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:05:29.442Z,1564095929.442 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:05:32.278Z,1564095932.278 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:05:35.506Z,1564095935.506 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:05:38.358Z,1564095938.358 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:05:41.598Z,1564095941.598 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:05:44.386Z,1564095944.386 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:05:47.230Z,1564095947.230 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:05:50.454Z,1564095950.454 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:05:53.278Z,1564095953.278 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:05:56.526Z,1564095956.526 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:05:59.338Z,1564095959.338 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:06:02.566Z,1564095962.566 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:06:05.410Z,1564095965.410 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:06:08.630Z,1564095968.630 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:06:11.466Z,1564095971.466 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:06:14.294Z,1564095974.294 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:06:17.518Z,1564095977.518 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:06:20.370Z,1564095980.370 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:06:23.602Z,1564095983.602 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:06:26.406Z,1564095986.406 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:06:29.642Z,1564095989.642 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:06:32.466Z,1564095992.466 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:06:35.702Z,1564095995.702 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:06:38.526Z,1564095998.526 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:06:41.350Z,1564096001.350 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:06:44.582Z,1564096004.582 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:06:47.422Z,1564096007.422 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:06:50.646Z,1564096010.646 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:06:53.474Z,1564096013.474 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:06:56.710Z,1564096016.710 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:06:59.542Z,1564096019.542 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:07:02.386Z,1564096022.386 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:07:05.614Z,1564096025.614 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:07:08.426Z,1564096028.426 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:07:11.658Z,1564096031.658 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:07:14.486Z,1564096034.486 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:07:17.718Z,1564096037.718 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:07:20.542Z,1564096040.542 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:07:23.770Z,1564096043.770 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:07:26.622Z,1564096046.622 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:07:29.458Z,1564096049.458 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:07:32.682Z,1564096052.682 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:07:35.514Z,1564096055.514 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:07:38.746Z,1564096058.746 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:07:41.566Z,1564096061.566 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:07:44.814Z,1564096064.814 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:07:47.678Z,1564096067.678 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:07:50.454Z,1564096070.454 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:07:53.694Z,1564096073.694 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:07:54.113Z,1564096074.113 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,230530.00,A,3648.16788,N,12147.28760,W,1.244,0.00,250719,,,A*73
2019-07-25T23:07:54.115Z,1564096074.115 [NAL9602](INFO): GPS fix at 20190725T230530: (36.802798, -121.788127)
2019-07-25T23:07:54.145Z,1564096074.145 [Default:CheckIn:Read_GPS] Stopped
2019-07-25T23:07:54.145Z,1564096074.145 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-07-25T23:08:00.487Z,1564096080.487 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20190725T211932/Courier0043.lzma
2019-07-25T23:08:01.290Z,1564096081.290 [DataOverHttps](INFO): Moved sent file to Logs/20190725T211932/Courier0043.lzma.bak
2019-07-25T23:08:01.290Z,1564096081.290 [DataOverHttps](INFO): SBD MOMSN=11476507
2019-07-25T23:08:07.011Z,1564096087.011 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-07-25T23:08:07.011Z,1564096087.011 [DVL_micro] Data Fault, FailCount= 1
2019-07-25T23:08:07.011Z,1564096087.011 [DVL_micro](ERROR): Data Fault
2019-07-25T23:08:07.064Z,1564096087.064 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-07-25T23:08:07.482Z,1564096087.482 [DVL_micro](INFO): uninitialize:Powering down
2019-07-25T23:08:08.246Z,1564096088.246 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-07-25T23:08:08.246Z,1564096088.246 [DVL_micro] No Fault, FailCount= 1
2019-07-25T23:08:08.631Z,1564096088.631 [DVL_micro](INFO): Initializing
2019-07-25T23:08:26.403Z,1564096106.403 [NAL9602](INFO): Not Powering down - fast GPS
2019-07-25T23:08:53.298Z,1564096133.298 [DataOverHttps](INFO): Sending 274 bytes from file Logs/20190725T211932/Express0044.lzma
2019-07-25T23:08:54.103Z,1564096134.103 [DataOverHttps](INFO): Moved sent file to Logs/20190725T211932/Express0044.lzma.bak
2019-07-25T23:08:54.104Z,1564096134.104 [DataOverHttps](INFO): SBD MOMSN=11476510
2019-07-25T23:08:54.714Z,1564096134.714 [Default:CheckIn:Read_Iridium] Stopped
2019-07-25T23:08:54.714Z,1564096134.714 [Default:CheckIn:C.Wait] Running Loop=1
2019-07-25T23:08:54.714Z,1564096134.714 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-07-25T23:11:12.849Z,1564096272.849 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-07-25T23:11:12.849Z,1564096272.849 [DVL_micro] Data Fault, FailCount= 1
2019-07-25T23:11:12.849Z,1564096272.849 [DVL_micro](ERROR): Data Fault
2019-07-25T23:11:12.910Z,1564096272.910 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-07-25T23:11:13.318Z,1564096273.318 [DVL_micro](INFO): uninitialize:Powering down
2019-07-25T23:11:14.098Z,1564096274.098 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-07-25T23:11:14.098Z,1564096274.098 [DVL_micro] No Fault, FailCount= 1
2019-07-25T23:11:14.473Z,1564096274.473 [DVL_micro](INFO): Initializing
2019-07-25T23:13:55.285Z,1564096435.285 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-07-25T23:13:55.285Z,1564096435.285 [Default:CheckIn:C.Wait] Stopped
2019-07-25T23:13:55.285Z,1564096435.285 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-07-25T23:13:55.285Z,1564096435.285 [Default:CheckIn:D] Running Loop=1
2019-07-25T23:13:55.689Z,1564096435.689 [Default:CheckIn:D] Stopped
2019-07-25T23:13:55.689Z,1564096435.689 [Default:CheckIn:E] Running Loop=1
2019-07-25T23:13:56.111Z,1564096436.111 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 110.052303 min 
2019-07-25T23:13:56.111Z,1564096436.111 [Default:CheckIn:E] Stopped
2019-07-25T23:13:56.112Z,1564096436.112 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-07-25T23:13:56.112Z,1564096436.112 [Default:CheckIn] Stopped
2019-07-25T23:13:56.112Z,1564096436.112 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-07-25T23:13:56.112Z,1564096436.112 [Default:CheckIn](INFO): Running loop #15
2019-07-25T23:13:56.112Z,1564096436.112 [Default:CheckIn] Running Loop=15
2019-07-25T23:13:56.112Z,1564096436.112 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-07-25T23:13:56.112Z,1564096436.112 [Default:CheckIn:Read_GPS] Running Loop=1
2019-07-25T23:13:57.697Z,1564096437.697 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:13:58.090Z,1564096438.090 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,231134.00,A,3648.16812,N,12147.28185,W,0.330,0.00,250719,,,A*70
2019-07-25T23:13:58.092Z,1564096438.092 [NAL9602](INFO): GPS fix at 20190725T231134: (36.802802, -121.788031)
2019-07-25T23:13:58.135Z,1564096438.135 [Default:CheckIn:Read_GPS] Stopped
2019-07-25T23:13:58.135Z,1564096438.135 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-07-25T23:14:04.833Z,1564096444.833 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20190725T211932/Courier0046.lzma
2019-07-25T23:14:05.639Z,1564096445.639 [DataOverHttps](INFO): Moved sent file to Logs/20190725T211932/Courier0046.lzma.bak
2019-07-25T23:14:05.640Z,1564096445.640 [DataOverHttps](INFO): SBD MOMSN=11476519
2019-07-25T23:14:18.691Z,1564096458.691 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-07-25T23:14:18.691Z,1564096458.691 [DVL_micro] Data Fault, FailCount= 1
2019-07-25T23:14:18.691Z,1564096458.691 [DVL_micro](ERROR): Data Fault
2019-07-25T23:14:18.752Z,1564096458.752 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-07-25T23:14:19.162Z,1564096459.162 [DVL_micro](INFO): uninitialize:Powering down
2019-07-25T23:14:19.935Z,1564096459.935 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-07-25T23:14:19.935Z,1564096459.935 [DVL_micro] No Fault, FailCount= 1
2019-07-25T23:14:20.313Z,1564096460.313 [DVL_micro](INFO): Initializing
2019-07-25T23:14:25.930Z,1564096465.930 [DataOverHttps](INFO): Sending 175 bytes from file Logs/20190725T211932/Express0047.lzma
2019-07-25T23:14:26.736Z,1564096466.736 [DataOverHttps](INFO): Moved sent file to Logs/20190725T211932/Express0047.lzma.bak
2019-07-25T23:14:26.736Z,1564096466.736 [DataOverHttps](INFO): SBD MOMSN=11476522
2019-07-25T23:14:27.621Z,1564096467.621 [Default:CheckIn:Read_Iridium] Stopped
2019-07-25T23:14:27.621Z,1564096467.621 [Default:CheckIn:C.Wait] Running Loop=1
2019-07-25T23:14:27.622Z,1564096467.622 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-07-25T23:15:06.765Z,1564096506.765 [NAL9602](INFO): SBD MO Status=2, MOMSN=30030, MT Status=2, MTMSN=0
2019-07-25T23:15:06.765Z,1564096506.765 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-25T23:17:24.531Z,1564096644.531 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-07-25T23:17:24.531Z,1564096644.531 [DVL_micro] Data Fault, FailCount= 1
2019-07-25T23:17:24.531Z,1564096644.531 [DVL_micro](ERROR): Data Fault
2019-07-25T23:17:24.564Z,1564096644.564 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-07-25T23:17:25.006Z,1564096645.006 [DVL_micro](INFO): uninitialize:Powering down
2019-07-25T23:17:25.794Z,1564096645.794 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-07-25T23:17:25.794Z,1564096645.794 [DVL_micro] No Fault, FailCount= 1
2019-07-25T23:17:26.151Z,1564096646.151 [DVL_micro](INFO): Initializing
2019-07-25T23:18:59.891Z,1564096739.891 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-07-25T23:19:28.193Z,1564096768.193 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-07-25T23:19:28.193Z,1564096768.193 [Default:CheckIn:C.Wait] Stopped
2019-07-25T23:19:28.193Z,1564096768.193 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-07-25T23:19:28.193Z,1564096768.193 [Default:CheckIn:D] Running Loop=1
2019-07-25T23:19:28.601Z,1564096768.601 [Default:CheckIn:D] Stopped
2019-07-25T23:19:28.601Z,1564096768.601 [Default:CheckIn:E] Running Loop=1
2019-07-25T23:19:29.045Z,1564096769.045 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 115.600830 min 
2019-07-25T23:19:29.050Z,1564096769.050 [Default:CheckIn:E] Stopped
2019-07-25T23:19:29.050Z,1564096769.050 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-07-25T23:19:29.050Z,1564096769.050 [Default:CheckIn] Stopped
2019-07-25T23:19:29.050Z,1564096769.050 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-07-25T23:19:29.050Z,1564096769.050 [Default:CheckIn](INFO): Running loop #16
2019-07-25T23:19:29.051Z,1564096769.051 [Default:CheckIn] Running Loop=16
2019-07-25T23:19:29.051Z,1564096769.051 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-07-25T23:19:29.051Z,1564096769.051 [Default:CheckIn:Read_GPS] Running Loop=1
2019-07-25T23:19:30.598Z,1564096770.598 [NAL9602](DEBUG): Fix Requested
2019-07-25T23:19:30.985Z,1564096770.985 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,231707.00,A,3648.16825,N,12147.28613,W,0.292,0.00,250719,,,A*73
2019-07-25T23:19:30.988Z,1564096770.988 [NAL9602](INFO): GPS fix at 20190725T231707: (36.802804, -121.788102)
2019-07-25T23:19:31.011Z,1564096771.011 [Default:CheckIn:Read_GPS] Stopped
2019-07-25T23:19:31.012Z,1564096771.012 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-07-25T23:19:37.369Z,1564096777.369 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20190725T211932/Courier0049.lzma
2019-07-25T23:19:38.175Z,1564096778.175 [DataOverHttps](INFO): Moved sent file to Logs/20190725T211932/Courier0049.lzma.bak
2019-07-25T23:19:38.176Z,1564096778.176 [DataOverHttps](INFO): SBD MOMSN=11476527
2019-07-25T23:20:03.703Z,1564096803.703 [NAL9602](INFO): Not Powering down - fast GPS
2019-07-25T23:20:04.450Z,1564096804.450 [DataOverHttps](INFO): Sending 229 bytes from file Logs/20190725T211932/Express0050.lzma
2019-07-25T23:20:05.255Z,1564096805.255 [DataOverHttps](INFO): Moved sent file to Logs/20190725T211932/Express0050.lzma.bak
2019-07-25T23:20:05.256Z,1564096805.256 [DataOverHttps](INFO): SBD MOMSN=11476530
2019-07-25T23:20:05.774Z,1564096805.773 [Default:CheckIn:Read_Iridium] Stopped
2019-07-25T23:20:05.774Z,1564096805.774 [Default:CheckIn:C.Wait] Running Loop=1
2019-07-25T23:20:05.774Z,1564096805.774 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-07-25T23:20:30.373Z,1564096830.373 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-07-25T23:20:30.373Z,1564096830.373 [DVL_micro] Data Fault, FailCount= 1
2019-07-25T23:20:30.373Z,1564096830.373 [DVL_micro](ERROR): Data Fault
2019-07-25T23:20:30.406Z,1564096830.406 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-07-25T23:20:30.846Z,1564096830.846 [DVL_micro](INFO): uninitialize:Powering down
2019-07-25T23:20:31.626Z,1564096831.626 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-07-25T23:20:31.626Z,1564096831.626 [DVL_micro] No Fault, FailCount= 1
2019-07-25T23:20:31.993Z,1564096831.993 [DVL_micro](INFO): Initializing
2019-07-25T23:23:36.205Z,1564097016.205 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-07-25T23:23:36.205Z,1564097016.205 [DVL_micro] Data Fault, FailCount= 1
2019-07-25T23:23:36.205Z,1564097016.205 [DVL_micro](ERROR): Data Fault
2019-07-25T23:23:36.237Z,1564097016.237 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-07-25T23:23:36.682Z,1564097016.682 [DVL_micro](INFO): uninitialize:Powering down
2019-07-25T23:23:37.455Z,1564097017.455 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-07-25T23:23:37.455Z,1564097017.455 [DVL_micro] No Fault, FailCount= 1
2019-07-25T23:23:37.841Z,1564097017.841 [DVL_micro](INFO): Initializing
2019-07-25T23:21:52.753Z,1564096912.753 [CommandLine](IMPORTANT): got command restart system
2019-07-25T23:21:54.848Z,1564096914.848 [Supervisor](INFO): Stop Mission called by Supervisor::terminate
2019-07-25T23:21:54.848Z,1564096914.848 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2019-07-25T23:21:54.848Z,1564096914.848 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-07-25T23:21:54.985Z,1564096914.985 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2019-07-25T23:21:54.986Z,1564096914.986 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-07-25T23:21:54.989Z,1564096914.989 [CommandLine](INFO): Join timeout helper Thread ID is 6059
2019-07-25T23:21:54.990Z,1564096914.990 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2019-07-25T23:21:54.991Z,1564096914.991 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-07-25T23:21:54.994Z,1564096914.994 [NavChartDb](INFO): Join timeout helper Thread ID is 6060
2019-07-25T23:21:55.219Z,1564096915.219 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2019-07-25T23:21:55.220Z,1564096915.220 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-07-25T23:21:55.223Z,1564096915.223 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2019-07-25T23:21:55.223Z,1564096915.223 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-07-25T23:21:55.224Z,1564096915.224 [Radio_Surface](INFO): Join timeout helper Thread ID is 6061
2019-07-25T23:21:55.259Z,1564096915.259 [Radio_Surface](INFO): Powering down
2019-07-25T23:21:55.261Z,1564096915.261 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2019-07-25T23:21:55.261Z,1564096915.261 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-07-25T23:21:55.263Z,1564096915.263 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2019-07-25T23:21:55.264Z,1564096915.264 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-07-25T23:21:55.264Z,1564096915.264 [DataOverHttps](INFO): Join timeout helper Thread ID is 6062
2019-07-25T23:21:55.572Z,1564096915.572 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2019-07-25T23:21:55.572Z,1564096915.572 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-07-25T23:21:55.591Z,1564096915.591 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2019-07-25T23:21:55.591Z,1564096915.591 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-07-25T23:21:55.592Z,1564096915.592 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 6063
2019-07-25T23:21:56.076Z,1564096916.076 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2019-07-25T23:21:56.076Z,1564096916.076 [WetLabsBB2FL](INFO): Powering down
2019-07-25T23:21:56.077Z,1564096916.077 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-07-25T23:21:56.092Z,1564096916.092 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2019-07-25T23:21:56.092Z,1564096916.092 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2019-07-25T23:21:56.093Z,1564096916.093 [CTD_Seabird](INFO): Join timeout helper Thread ID is 6064
2019-07-25T23:21:57.064Z,1564096917.064 [CTD_Seabird](INFO): Powering down
2019-07-25T23:21:57.075Z,1564096917.075 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2019-07-25T23:21:57.076Z,1564096917.076 [CTD_Seabird](INFO): Powering down
2019-07-25T23:21:57.087Z,1564096917.087 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2019-07-25T23:21:57.089Z,1564096917.089 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2019-07-25T23:21:57.089Z,1564096917.089 [logger ThreadHandler](INFO): Thread cancelled.
2019-07-25T23:21:57.089Z,1564096917.089 [logger](INFO): Join timeout helper Thread ID is 6065
2019-07-25T23:21:57.124Z,1564096917.124 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2019-07-25T23:21:57.124Z,1564096917.124 [logger ThreadHandler](INFO): Thread cancelled.
2019-07-25T23:21:57.128Z,1564096917.128 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2019-07-25T23:21:57.128Z,1564096917.128 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-07-25T23:21:57.128Z,1564096917.128 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2019-07-25T23:21:57.129Z,1564096917.129 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-07-25T23:21:57.129Z,1564096917.129 [controlThread](INFO): Join timeout helper Thread ID is 6066
2019-07-25T23:21:57.379Z,1564096917.379 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2019-07-25T23:21:57.380Z,1564096917.380 [controlThread](DEBUG): Uninitializing ControlThread
2019-07-25T23:21:57.380Z,1564096917.380 [Aanderaa_O2](INFO): Powering down
2019-07-25T23:21:57.407Z,1564096917.407 [AHRS_M2](INFO): Powering down
2019-07-25T23:21:57.552Z,1564096917.552 [DVL_micro](INFO): uninitialize:Powering down
2019-07-25T23:21:57.553Z,1564096917.553 [NAL9602](INFO): Powering down
2019-07-25T23:21:57.554Z,1564096917.554 [DAT](INFO): Powering down
2019-07-25T23:21:57.672Z,1564096917.672 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2019-07-25T23:21:57.673Z,1564096917.673 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2019-07-25T23:21:57.674Z,1564096917.674 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2019-07-25T23:21:57.674Z,1564096917.674 [MissionManager](INFO): Uninitializing Mission Default
2019-07-25T23:21:57.674Z,1564096917.674 [Default] Stopped
2019-07-25T23:21:57.675Z,1564096917.675 [Default](DEBUG): Aggregate::uninitialize Default
2019-07-25T23:21:57.675Z,1564096917.675 [Default:B.GoToSurface] Stopped
2019-07-25T23:21:57.675Z,1564096917.675 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-07-25T23:21:57.675Z,1564096917.675 [Default:CheckIn] Stopped
2019-07-25T23:21:57.675Z,1564096917.675 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-07-25T23:21:57.675Z,1564096917.675 [Default:CheckIn:C.Wait] Stopped
2019-07-25T23:21:57.675Z,1564096917.675 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-07-25T23:21:57.677Z,1564096917.677 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2019-07-25T23:21:57.678Z,1564096917.678 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2019-07-25T23:21:57.678Z,1564096917.678 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2019-07-25T23:21:57.678Z,1564096917.678 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2019-07-25T23:21:57.679Z,1564096917.679 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2019-07-25T23:21:57.679Z,1564096917.679 [BuoyancyServo](INFO): Powering down
2019-07-25T23:21:57.692Z,1564096917.692 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2019-07-25T23:21:57.692Z,1564096917.692 [ElevatorServo](INFO): Powering down
2019-07-25T23:21:57.693Z,1564096917.693 [MassServo](DEBUG): Uninitialize Mass Servo.
2019-07-25T23:21:57.693Z,1564096917.693 [MassServo](INFO): Powering down
2019-07-25T23:21:57.693Z,1564096917.693 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-07-25T23:21:57.694Z,1564096917.694 [RudderServo](INFO): Powering down
2019-07-25T23:21:57.694Z,1564096917.694 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2019-07-25T23:21:57.694Z,1564096917.694 [ThrusterServo](INFO): Powering down
2019-07-25T23:21:57.696Z,1564096917.696 [SBIT](DEBUG): Uninitialize SBIT Component.
2019-07-25T23:21:57.696Z,1564096917.696 [IBIT](DEBUG): Uninitialize IBIT Component.
2019-07-25T23:21:57.696Z,1564096917.696 [CBIT](DEBUG): Uninitialize CBIT Component.
2019-07-25T23:21:57.696Z,1564096917.696 [CBIT](DEBUG): Powering off loads.
2019-07-25T23:21:57.707Z,1564096917.707 [CBIT](DEBUG): Disabling WDT.
2019-07-25T23:21:57.719Z,1564096917.719 [CBIT](DEBUG): Opening all GF detection circuits.
2019-07-25T23:21:57.720Z,1564096917.720 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-07-25T23:21:57.764Z,1564096917.764 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-07-25T23:21:57.769Z,1564096917.769 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2019-07-25T23:21:57.846Z,1564096917.846 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-07-25T23:21:57.854Z,1564096917.854 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-07-25T23:21:57.915Z,1564096917.915 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-07-25T23:21:57.987Z,1564096917.987 [logger ThreadHandler](INFO): Thread cancelled.