2019-07-01T14:30:43.803Z,1561991443.803 [Supervisor](DEBUG): Initializing supervisor.
2019-07-01T14:30:43.806Z,1561991443.806 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2019-07-01T14:30:43.806Z,1561991443.806 [SyncHandler](INFO): Protected caller Thread ID is 806
2019-07-01T14:30:43.807Z,1561991443.807 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2019-07-01T14:30:43.808Z,1561991443.808 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2019-07-01T14:30:43.808Z,1561991443.808 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 807
2019-07-01T14:30:43.810Z,1561991443.810 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2019-07-01T14:30:43.822Z,1561991443.822 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2019-07-01T14:30:43.823Z,1561991443.823 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2019-07-01T14:30:43.823Z,1561991443.823 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 808
2019-07-01T14:30:43.824Z,1561991443.824 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2019-07-01T14:30:43.825Z,1561991443.825 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2019-07-01T14:30:43.826Z,1561991443.826 [logger ThreadHandler](INFO): Protected caller Thread ID is 809
2019-07-01T14:30:43.828Z,1561991443.828 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2019-07-01T14:30:43.828Z,1561991443.828 [Supervisor](INFO): Looking for Config files in directory: Config/
2019-07-01T14:30:43.832Z,1561991443.832 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2019-07-01T14:30:44.253Z,1561991444.253 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2019-07-01T14:30:44.254Z,1561991444.254 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2019-07-01T14:30:44.397Z,1561991444.397 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2019-07-01T14:30:44.399Z,1561991444.399 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2019-07-01T14:30:44.480Z,1561991444.480 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2019-07-01T14:30:44.578Z,1561991444.578 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2019-07-01T14:30:44.580Z,1561991444.580 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2019-07-01T14:30:44.675Z,1561991444.675 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2019-07-01T14:30:44.676Z,1561991444.676 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2019-07-01T14:30:45.054Z,1561991445.054 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2019-07-01T14:30:45.055Z,1561991445.055 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2019-07-01T14:30:45.158Z,1561991445.158 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2019-07-01T14:30:45.158Z,1561991445.158 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2019-07-01T14:30:45.615Z,1561991445.615 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2019-07-01T14:30:45.616Z,1561991445.616 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2019-07-01T14:30:45.818Z,1561991445.818 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2019-07-01T14:30:45.825Z,1561991445.825 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2019-07-01T14:30:46.129Z,1561991446.129 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2019-07-01T14:30:46.131Z,1561991446.131 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2019-07-01T14:30:46.344Z,1561991446.344 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2019-07-01T14:30:46.344Z,1561991446.344 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2019-07-01T14:30:46.487Z,1561991446.487 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2019-07-01T14:30:46.489Z,1561991446.489 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2019-07-01T14:30:47.066Z,1561991447.066 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2019-07-01T14:30:47.068Z,1561991447.068 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2019-07-01T14:30:47.407Z,1561991447.407 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2019-07-01T14:30:48.069Z,1561991448.069 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2019-07-01T14:30:48.679Z,1561991448.679 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2019-07-01T14:30:48.681Z,1561991448.681 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-triton/
2019-07-01T14:30:48.684Z,1561991448.684 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/vehicle.cfg
2019-07-01T14:30:48.758Z,1561991448.758 [Config/vehicle](CRITICAL): Attempting to set a string configuration value to the non-string configuration: DVL_micro.baud
2019-07-01T14:30:48.869Z,1561991448.869 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/secure.cfg
2019-07-01T14:30:48.953Z,1561991448.953 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Science.cfg
2019-07-01T14:30:49.071Z,1561991449.071 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Simulator.cfg
2019-07-01T14:30:49.156Z,1561991449.156 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Battery.cfg
2019-07-01T14:30:49.385Z,1561991449.385 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2019-07-01T14:30:49.387Z,1561991449.387 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/logger.cfg
2019-07-01T14:30:49.483Z,1561991449.483 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Servo.cfg
2019-07-01T14:30:49.595Z,1561991449.595 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Navigation.cfg
2019-07-01T14:30:49.691Z,1561991449.691 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Sensor.cfg
2019-07-01T14:30:49.843Z,1561991449.843 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Control.cfg
2019-07-01T14:30:49.945Z,1561991449.945 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/BIT.cfg
2019-07-01T14:30:50.044Z,1561991450.044 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2019-07-01T14:30:50.054Z,1561991450.054 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2019-07-01T14:30:50.078Z,1561991450.078 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2019-07-01T14:30:50.079Z,1561991450.079 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2019-07-01T14:30:50.164Z,1561991450.164 [VerticalControl](DEBUG): Construct VerticalControl.
2019-07-01T14:30:50.276Z,1561991450.276 [VerticalControl] Loaded
2019-07-01T14:30:50.277Z,1561991450.277 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2019-07-01T14:30:50.277Z,1561991450.277 [HorizontalControl](DEBUG): Construct HorizontalControl.
2019-07-01T14:30:50.345Z,1561991450.345 [HorizontalControl] Loaded
2019-07-01T14:30:50.346Z,1561991450.346 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2019-07-01T14:30:50.346Z,1561991450.346 [SpeedControl](DEBUG): Construct SpeedControl.
2019-07-01T14:30:50.352Z,1561991450.352 [SpeedControl] Loaded
2019-07-01T14:30:50.352Z,1561991450.352 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2019-07-01T14:30:50.353Z,1561991450.353 [LoopControl](DEBUG): Construct LoopControl.
2019-07-01T14:30:50.353Z,1561991450.353 [LoopControl] Loaded
2019-07-01T14:30:50.353Z,1561991450.353 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2019-07-01T14:30:50.354Z,1561991450.354 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2019-07-01T14:30:50.355Z,1561991450.355 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2019-07-01T14:30:50.504Z,1561991450.504 [BuoyancyServo] Loaded
2019-07-01T14:30:50.505Z,1561991450.505 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2019-07-01T14:30:50.516Z,1561991450.516 [ElevatorServo] Loaded
2019-07-01T14:30:50.516Z,1561991450.516 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2019-07-01T14:30:50.527Z,1561991450.527 [MassServo] Loaded
2019-07-01T14:30:50.527Z,1561991450.527 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2019-07-01T14:30:50.539Z,1561991450.539 [RudderServo] Loaded
2019-07-01T14:30:50.539Z,1561991450.539 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2019-07-01T14:30:50.549Z,1561991450.549 [ThrusterServo] Loaded
2019-07-01T14:30:50.550Z,1561991450.550 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2019-07-01T14:30:50.550Z,1561991450.550 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2019-07-01T14:30:50.552Z,1561991450.552 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2019-07-01T14:30:50.606Z,1561991450.606 [DepthRateCalculator] Loaded
2019-07-01T14:30:50.606Z,1561991450.606 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2019-07-01T14:30:50.611Z,1561991450.611 [PitchRateCalculator] Loaded
2019-07-01T14:30:50.612Z,1561991450.612 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2019-07-01T14:30:50.626Z,1561991450.626 [SpeedCalculator] Loaded
2019-07-01T14:30:50.627Z,1561991450.627 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2019-07-01T14:30:50.648Z,1561991450.648 [TempGradientCalculator] Loaded
2019-07-01T14:30:50.648Z,1561991450.648 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2019-07-01T14:30:50.653Z,1561991450.653 [YawRateCalculator] Loaded
2019-07-01T14:30:50.653Z,1561991450.653 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2019-07-01T14:30:50.682Z,1561991450.682 [ElevatorOffsetCalculator] Loaded
2019-07-01T14:30:50.682Z,1561991450.682 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2019-07-01T14:30:50.682Z,1561991450.682 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2019-07-01T14:30:50.683Z,1561991450.683 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2019-07-01T14:30:50.803Z,1561991450.803 [DeadReckonUsingMultipleVelocitySources] Loaded
2019-07-01T14:30:50.804Z,1561991450.804 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2019-07-01T14:30:50.824Z,1561991450.824 [NavChart] Loaded
2019-07-01T14:30:50.824Z,1561991450.824 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2019-07-01T14:30:50.828Z,1561991450.828 [UniversalFixResidualReporter] Loaded
2019-07-01T14:30:50.828Z,1561991450.828 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2019-07-01T14:30:50.829Z,1561991450.829 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2019-07-01T14:30:50.829Z,1561991450.829 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2019-07-01T14:30:51.508Z,1561991451.508 [AHRS_M2] Loaded
2019-07-01T14:30:51.508Z,1561991451.508 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2019-07-01T14:30:51.651Z,1561991451.651 [DataOverHttps] Loaded
2019-07-01T14:30:51.651Z,1561991451.651 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2019-07-01T14:30:51.652Z,1561991451.652 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 408094E0
2019-07-01T14:30:51.652Z,1561991451.652 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 888
2019-07-01T14:30:51.666Z,1561991451.666 [Depth_Keller] Loaded
2019-07-01T14:30:51.666Z,1561991451.666 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2019-07-01T14:30:51.671Z,1561991451.671 [DropWeight] Loaded
2019-07-01T14:30:51.671Z,1561991451.671 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2019-07-01T14:30:51.799Z,1561991451.799 [DVL_micro] Loaded
2019-07-01T14:30:51.799Z,1561991451.799 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread.
2019-07-01T14:30:51.894Z,1561991451.894 [NAL9602] Loaded
2019-07-01T14:30:51.895Z,1561991451.895 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2019-07-01T14:30:51.911Z,1561991451.911 [Onboard] Loaded
2019-07-01T14:30:51.911Z,1561991451.911 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2019-07-01T14:30:51.914Z,1561991451.914 [Radio_Surface] Loaded
2019-07-01T14:30:51.915Z,1561991451.915 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2019-07-01T14:30:51.916Z,1561991451.916 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408394E0
2019-07-01T14:30:51.916Z,1561991451.916 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 889
2019-07-01T14:30:53.697Z,1561991453.697 [BPC1] Loaded
2019-07-01T14:30:53.698Z,1561991453.698 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2019-07-01T14:30:53.698Z,1561991453.698 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2019-07-01T14:30:53.700Z,1561991453.700 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2019-07-01T14:30:53.810Z,1561991453.810 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2019-07-01T14:30:53.811Z,1561991453.811 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2019-07-01T14:30:53.934Z,1561991453.934 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2019-07-01T14:30:53.935Z,1561991453.935 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2019-07-01T14:30:53.984Z,1561991453.984 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2019-07-01T14:30:53.985Z,1561991453.985 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2019-07-01T14:30:54.231Z,1561991454.231 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_density
2019-07-01T14:30:54.236Z,1561991454.236 [CTD_Seabird](INFO): created writer for : sea_water_density
2019-07-01T14:30:54.238Z,1561991454.238 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): depth
2019-07-01T14:30:54.243Z,1561991454.243 [CTD_Seabird](INFO): created writer for : depth
2019-07-01T14:30:54.243Z,1561991454.243 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_pressure
2019-07-01T14:30:54.248Z,1561991454.248 [CTD_Seabird](INFO): created writer for : sea_water_pressure
2019-07-01T14:30:54.249Z,1561991454.249 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_salinity
2019-07-01T14:30:54.254Z,1561991454.254 [CTD_Seabird](INFO): created writer for : sea_water_salinity
2019-07-01T14:30:54.254Z,1561991454.254 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_temperature
2019-07-01T14:30:54.259Z,1561991454.259 [CTD_Seabird](INFO): created writer for : sea_water_temperature
2019-07-01T14:30:54.260Z,1561991454.260 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_electrical_conductivity
2019-07-01T14:30:54.265Z,1561991454.265 [CTD_Seabird](INFO): created writer for : sea_water_electrical_conductivity
2019-07-01T14:30:54.266Z,1561991454.266 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): speed_of_sound_in_sea_water
2019-07-01T14:30:54.271Z,1561991454.271 [CTD_Seabird](INFO): created writer for : speed_of_sound_in_sea_water
2019-07-01T14:30:54.298Z,1561991454.298 [CTD_Seabird] Loaded
2019-07-01T14:30:54.298Z,1561991454.298 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2019-07-01T14:30:54.299Z,1561991454.299 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 409CF4E0
2019-07-01T14:30:54.300Z,1561991454.300 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 891
2019-07-01T14:30:54.314Z,1561991454.314 [PAR_Licor] Loaded
2019-07-01T14:30:54.314Z,1561991454.314 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2019-07-01T14:30:54.362Z,1561991454.362 [WetLabsBB2FL] Loaded
2019-07-01T14:30:54.363Z,1561991454.363 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2019-07-01T14:30:54.364Z,1561991454.364 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 409FF4E0
2019-07-01T14:30:54.364Z,1561991454.364 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 892
2019-07-01T14:30:54.365Z,1561991454.365 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2019-07-01T14:30:54.365Z,1561991454.365 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2019-07-01T14:30:54.700Z,1561991454.700 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2019-07-01T14:30:54.700Z,1561991454.700 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2019-07-01T14:30:54.859Z,1561991454.859 [SBIT](DEBUG): Construct Startup Built In Test.
2019-07-01T14:30:54.870Z,1561991454.870 [SBIT] Loaded
2019-07-01T14:30:54.870Z,1561991454.870 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2019-07-01T14:30:54.871Z,1561991454.871 [IBIT](DEBUG): Construct Initiated Built In Test.
2019-07-01T14:30:54.882Z,1561991454.882 [IBIT] Loaded
2019-07-01T14:30:54.883Z,1561991454.883 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2019-07-01T14:30:54.886Z,1561991454.886 [CBIT](DEBUG): Construct Continuous Built In Test.
2019-07-01T14:30:55.023Z,1561991455.023 [CBIT] Loaded
2019-07-01T14:30:55.023Z,1561991455.023 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2019-07-01T14:30:55.023Z,1561991455.023 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2019-07-01T14:30:55.027Z,1561991455.027 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2019-07-01T14:30:55.028Z,1561991455.028 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2019-07-01T14:30:55.035Z,1561991455.035 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2019-07-01T14:30:55.036Z,1561991455.036 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40ADE4E0
2019-07-01T14:30:55.036Z,1561991455.036 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 893
2019-07-01T14:30:55.041Z,1561991455.041 [Supervisor](INFO): Main Thread ID is 802
2019-07-01T14:30:55.041Z,1561991455.041 [Supervisor](DEBUG): Running supervisor.
2019-07-01T14:30:55.042Z,1561991455.042 [CommandLine ThreadHandler](INFO): Handler Thread ID is 894
2019-07-01T14:30:55.044Z,1561991455.044 [controlThread ThreadHandler](INFO): Handler Thread ID is 895
2019-07-01T14:30:55.044Z,1561991455.044 [controlThread](DEBUG): Initializing ControlThread
2019-07-01T14:30:55.045Z,1561991455.045 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2019-07-01T14:30:55.047Z,1561991455.047 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2019-07-01T14:30:55.047Z,1561991455.047 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2019-07-01T14:30:55.048Z,1561991455.048 [LoopControl](DEBUG): Initialize LoopControlComponent.
2019-07-01T14:30:55.049Z,1561991455.049 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2019-07-01T14:30:55.050Z,1561991455.050 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2019-07-01T14:30:55.050Z,1561991455.050 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2019-07-01T14:30:55.050Z,1561991455.050 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2019-07-01T14:30:55.051Z,1561991455.051 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2019-07-01T14:30:55.051Z,1561991455.051 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2019-07-01T14:30:55.052Z,1561991455.052 [NavChart](DEBUG): Initialize NavChart Navigation.
2019-07-01T14:30:55.052Z,1561991455.052 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2019-07-01T14:30:55.059Z,1561991455.059 [SBIT](INFO): Initialize SBIT Component.
2019-07-01T14:30:55.060Z,1561991455.060 [SBIT](IMPORTANT): git: 2019-06-25-3-g82bf6f0
2019-07-01T14:30:55.060Z,1561991455.060 [SBIT](INFO): git hash: 82bf6f02d602d0907ca3a5c6563c0d774a7bdcbb
2019-07-01T14:30:55.060Z,1561991455.060 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2019-07-01T14:30:55.061Z,1561991455.061 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #1 PREEMPT Tue Dec 18 21:19:28 PST 2018
Kernel Reported: #1 PREEMPT Thu Feb 21 11:17:40 PST 2019
2019-07-01T14:30:55.062Z,1561991455.062 [SBIT](INFO): Beginning SBIT in 28.000000 seconds.
2019-07-01T14:30:55.063Z,1561991455.063 [IBIT](INFO): Initialize IBIT Component.
2019-07-01T14:30:55.064Z,1561991455.064 [CBIT](DEBUG): Initialize CBIT Component.
2019-07-01T14:30:55.065Z,1561991455.065 [logger ThreadHandler](INFO): Handler Thread ID is 896
2019-07-01T14:30:55.075Z,1561991455.075 [CBIT](DEBUG): Initialized mux pins.
2019-07-01T14:30:55.075Z,1561991455.075 [CBIT](DEBUG): Initializing the watchdog timer.
2019-07-01T14:30:55.083Z,1561991455.083 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 897
2019-07-01T14:30:55.084Z,1561991455.084 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2019-07-01T14:30:55.095Z,1561991455.095 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 898
2019-07-01T14:30:55.099Z,1561991455.099 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2019-07-01T14:30:55.099Z,1561991455.099 [CBIT](DEBUG): Initializing heartbeat.
2019-07-01T14:30:55.107Z,1561991455.107 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 899
2019-07-01T14:30:55.108Z,1561991455.108 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2019-07-01T14:30:55.111Z,1561991455.111 [CTD_Seabird](INFO): Opening uart, block timeout 10ths=20
2019-07-01T14:30:55.112Z,1561991455.112 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 901
2019-07-01T14:30:55.114Z,1561991455.114 [WetLabsBB2FL](INFO): Powering down
2019-07-01T14:30:55.141Z,1561991455.141 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 902
2019-07-01T14:30:55.151Z,1561991455.151 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2019-07-01T14:30:55.151Z,1561991455.151 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2019-07-01T14:30:55.151Z,1561991455.151 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2019-07-01T14:30:55.151Z,1561991455.151 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2019-07-01T14:30:55.151Z,1561991455.151 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2019-07-01T14:30:55.152Z,1561991455.152 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2019-07-01T14:30:55.152Z,1561991455.152 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2019-07-01T14:30:55.152Z,1561991455.152 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2019-07-01T14:30:55.152Z,1561991455.152 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2019-07-01T14:30:55.152Z,1561991455.152 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2019-07-01T14:30:55.153Z,1561991455.153 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2019-07-01T14:30:55.153Z,1561991455.153 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2019-07-01T14:30:55.153Z,1561991455.153 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2019-07-01T14:30:55.153Z,1561991455.153 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2019-07-01T14:30:55.154Z,1561991455.154 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2019-07-01T14:30:55.154Z,1561991455.154 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2019-07-01T14:30:55.171Z,1561991455.171 [CBIT](DEBUG): Deactivating GF circuits.
2019-07-01T14:30:55.171Z,1561991455.171 [CBIT](DEBUG): Deactivating emergency mode.
2019-07-01T14:30:55.207Z,1561991455.207 [CBIT](DEBUG): Backplane powered.
2019-07-01T14:30:55.208Z,1561991455.208 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2019-07-01T14:30:55.241Z,1561991455.241 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2019-07-01T14:30:55.252Z,1561991455.252 [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-01T14:30:55.253Z,1561991455.253 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2019-07-01T14:30:55.309Z,1561991455.309 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2019-07-01T14:30:55.311Z,1561991455.311 [Default:A.Wait](DEBUG): Construct Wait.
2019-07-01T14:30:55.312Z,1561991455.312 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2019-07-01T14:30:55.354Z,1561991455.354 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2019-07-01T14:30:55.381Z,1561991455.381 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2019-07-01T14:30:55.386Z,1561991455.386 [Default:E.Execute](DEBUG): Construct Execute.
2019-07-01T14:30:55.407Z,1561991455.407 [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-01T14:30:55.419Z,1561991455.419 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,DVL_micro,NAL9602,Onboard,BPC1,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2019-07-01T14:30:55.439Z,1561991455.439 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2019-07-01T14:30:55.499Z,1561991455.499 [Radio_Surface](INFO): Powering up
2019-07-01T14:30:55.544Z,1561991455.544 [Depth_Keller](ERROR): Pressure reading out of range: 1925.893799 decibar
2019-07-01T14:30:55.571Z,1561991455.571 [DVL_micro](INFO): Initializing
2019-07-01T14:30:55.643Z,1561991455.643 [DepthRateCalculator](ERROR): Depth measurement is not active
2019-07-01T14:30:55.708Z,1561991455.708 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2019-07-01T14:30:55.715Z,1561991455.715 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2019-07-01T14:30:55.716Z,1561991455.716 [ElevatorServo](DEBUG): Initializing EZServoServo.
2019-07-01T14:30:55.723Z,1561991455.723 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2019-07-01T14:30:55.724Z,1561991455.724 [MassServo](DEBUG): Initializing EZServoServo.
2019-07-01T14:30:55.731Z,1561991455.731 [MassServo](DEBUG): Initializing MassServo.
2019-07-01T14:30:55.732Z,1561991455.732 [RudderServo](DEBUG): Initializing EZServoServo.
2019-07-01T14:30:55.739Z,1561991455.739 [RudderServo](DEBUG): Initializing RudderServo.
2019-07-01T14:30:55.740Z,1561991455.740 [ThrusterServo](DEBUG): Initializing EZServoServo.
2019-07-01T14:30:55.747Z,1561991455.747 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2019-07-01T14:30:55.749Z,1561991455.749 [CommandLine](FAULT): Scheduling is paused
2019-07-01T14:30:55.750Z,1561991455.750 [CBIT](INFO): Critical error at 20190701T143048
2019-07-01T14:30:55.750Z,1561991455.750 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2019-07-01T14:30:56.619Z,1561991456.619 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2019-07-01T14:30:56.619Z,1561991456.619 [RudderServo](FAULT): Rudder failed to initialize
2019-07-01T14:30:56.619Z,1561991456.619 [RudderServo] Communications Fault, FailCount= 1
2019-07-01T14:30:56.619Z,1561991456.619 [RudderServo](ERROR): Communications Fault
2019-07-01T14:30:56.790Z,1561991456.790 [CBIT](ERROR): Communications Fault in component: RudderServo
2019-07-01T14:30:57.008Z,1561991457.008 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-07-01T14:30:57.008Z,1561991457.008 [RudderServo](INFO): Powering down
2019-07-01T14:30:57.677Z,1561991457.677 [RudderServo](DEBUG): Initializing EZServoServo.
2019-07-01T14:30:57.796Z,1561991457.796 [RudderServo](DEBUG): Initializing RudderServo.
2019-07-01T14:30:57.800Z,1561991457.800 [CBIT](INFO): Clearing failed state for component RudderServo
2019-07-01T14:30:57.800Z,1561991457.800 [RudderServo] No Fault, FailCount= 1
2019-07-01T14:31:21.957Z,1561991481.957 [NAL9602](INFO): Powering up NAL9602
2019-07-01T14:31:23.633Z,1561991483.633 [SBIT](IMPORTANT): Beginning Startup BIT
2019-07-01T14:31:23.642Z,1561991483.642 [CBIT](IMPORTANT): Beginning ground fault scan
2019-07-01T14:31:33.073Z,1561991493.073 [NAL9602](INFO): NAL9602 initialized
2019-07-01T14:31:33.915Z,1561991493.915 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:31:34.455Z,1561991494.455 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.005071
CHAN A1 (24V): -0.001110
CHAN A2 (12V): -0.004401
CHAN A3 (5V): -0.002581
CHAN B0 (3.3V): -0.002017
CHAN B1 (3.15aV): -0.001356
CHAN B2 (3.15bV): -0.001084
CHAN B3 (GND): -0.001381
OPEN: 0.003498
Full Scale Calc: 4.765 mA, -1.589 mA
2019-07-01T14:31:52.146Z,1561991512.146 [NAL9602](INFO): SBD MO Status=0, MOMSN=521, MT Status=0, MTMSN=0
2019-07-01T14:31:52.146Z,1561991512.146 [NAL9602](INFO): No messages in MT queue
2019-07-01T14:31:52.983Z,1561991512.983 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:31:55.795Z,1561991515.795 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:31:59.031Z,1561991519.031 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:32:01.855Z,1561991521.855 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:32:05.087Z,1561991525.087 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:32:08.059Z,1561991528.059 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:32:10.883Z,1561991530.883 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:32:14.119Z,1561991534.119 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:32:16.951Z,1561991536.951 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:32:17.406Z,1561991537.406 [SBIT](IMPORTANT): SBIT PASSED
2019-07-01T14:32:17.436Z,1561991537.436 [CommandLine](IMPORTANT): got command configSet list
2019-07-01T14:32:17.436Z,1561991537.436 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2019-07-01T14:32:17.437Z,1561991537.437 [CommandLine](IMPORTANT): CTD_NeilBrown.loadAtStartup=0 bool;

2019-07-01T14:32:17.437Z,1561991537.437 [CommandLine](IMPORTANT): PAR_Licor.darkCount=-15 count;

2019-07-01T14:32:17.437Z,1561991537.437 [CommandLine](IMPORTANT): PAR_Licor.loadAtStartup=1 bool;

2019-07-01T14:32:17.781Z,1561991537.781 [MissionManager](IMPORTANT): Started mission Startup
2019-07-01T14:32:17.781Z,1561991537.781 [Startup] Running Loop=1
2019-07-01T14:32:17.781Z,1561991537.781 [Startup](DEBUG): Aggregate::initialize Startup
2019-07-01T14:32:17.781Z,1561991537.781 [Startup:A.GoToSurface] Running Loop=1
2019-07-01T14:32:17.781Z,1561991537.781 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-07-01T14:32:17.782Z,1561991537.782 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-07-01T14:32:17.782Z,1561991537.782 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-07-01T14:32:17.783Z,1561991537.783 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-07-01T14:32:17.783Z,1561991537.783 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-07-01T14:32:17.784Z,1561991537.784 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-07-01T14:32:17.785Z,1561991537.785 [Startup:StartupSatComms] Running Loop=1
2019-07-01T14:32:17.785Z,1561991537.785 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2019-07-01T14:32:17.785Z,1561991537.785 [Startup:StartupSatComms:A] Running Loop=1
2019-07-01T14:32:18.173Z,1561991538.173 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2019-07-01T14:32:20.179Z,1561991540.179 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:32:23.003Z,1561991543.003 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:32:25.831Z,1561991545.831 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:32:29.063Z,1561991549.063 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:32:31.903Z,1561991551.903 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:32:34.315Z,1561991554.315 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:32:37.551Z,1561991557.551 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:32:40.379Z,1561991560.379 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:32:43.603Z,1561991563.603 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:32:46.435Z,1561991566.435 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:32:49.267Z,1561991569.267 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:32:52.091Z,1561991572.091 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:32:55.327Z,1561991575.327 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:32:58.151Z,1561991578.151 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:33:01.383Z,1561991581.383 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:33:04.227Z,1561991584.227 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:33:07.455Z,1561991587.455 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:33:10.275Z,1561991590.275 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:33:13.507Z,1561991593.507 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:33:16.331Z,1561991596.331 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:33:17.976Z,1561991597.976 [Startup:StartupSatComms:A](INFO): Timed out from 2019-07-01T14:32:17.8Z
2019-07-01T14:33:17.976Z,1561991597.976 [Startup:StartupSatComms:A] Stopped
2019-07-01T14:33:17.976Z,1561991597.976 [Startup:StartupSatComms:B] Running Loop=1
2019-07-01T14:33:18.373Z,1561991598.373 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-07-01T14:33:31.449Z,1561991611.449 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.005013
2019-07-01T14:33:39.542Z,1561991619.542 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190618T232705/Courier0004.lzma
2019-07-01T14:33:40.348Z,1561991620.348 [DataOverHttps](INFO): Moved sent file to Logs/20190618T232705/Courier0004.lzma.bak
2019-07-01T14:33:40.349Z,1561991620.349 [DataOverHttps](INFO): SBD MOMSN=11416138
2019-07-01T14:33:44.907Z,1561991624.907 [NAL9602](INFO): SBD MO Status=2, MOMSN=522, MT Status=2, MTMSN=0
2019-07-01T14:33:44.908Z,1561991624.908 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-01T14:33:45.771Z,1561991625.771 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:33:48.135Z,1561991628.135 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:33:51.371Z,1561991631.371 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:33:54.195Z,1561991634.195 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:33:55.476Z,1561991635.476 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2019-07-01T14:33:55.476Z,1561991635.476 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-07-01T14:33:55.500Z,1561991635.500 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-07-01T14:33:55.864Z,1561991635.864 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-07-01T14:33:55.864Z,1561991635.864 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2019-07-01T14:33:56.575Z,1561991636.575 [DataOverHttps](INFO): Sending 134 bytes from file Logs/20190624T152013/Courier0000.lzma
2019-07-01T14:33:57.380Z,1561991637.380 [DataOverHttps](INFO): Moved sent file to Logs/20190624T152013/Courier0000.lzma.bak
2019-07-01T14:33:57.380Z,1561991637.380 [DataOverHttps](INFO): SBD MOMSN=11416140
2019-07-01T14:33:57.443Z,1561991637.443 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:33:57.947Z,1561991637.947 [CommandLine](IMPORTANT): got command burn on
2019-07-01T14:33:57.948Z,1561991637.948 [CommandLine](IMPORTANT): Activating dropweight wire
2019-07-01T14:33:59.836Z,1561991639.836 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-07-01T14:33:59.836Z,1561991639.836 [DVL_micro] Data Fault, FailCount= 1
2019-07-01T14:33:59.836Z,1561991639.836 [DVL_micro](ERROR): Data Fault
2019-07-01T14:33:59.873Z,1561991639.873 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-07-01T14:34:00.311Z,1561991640.311 [DVL_micro](INFO): uninitialize:Powering down
2019-07-01T14:34:00.327Z,1561991640.327 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:34:01.101Z,1561991641.101 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-07-01T14:34:01.101Z,1561991641.101 [DVL_micro] No Fault, FailCount= 1
2019-07-01T14:34:01.458Z,1561991641.458 [DVL_micro](INFO): Initializing
2019-07-01T14:34:03.079Z,1561991643.079 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:34:06.315Z,1561991646.315 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:34:09.143Z,1561991649.143 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:34:12.078Z,1561991652.078 [DataOverHttps](INFO): Sending 134 bytes from file Logs/20190701T143043/Courier0000.lzma
2019-07-01T14:34:12.375Z,1561991652.375 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:34:12.884Z,1561991652.884 [DataOverHttps](INFO): Moved sent file to Logs/20190701T143043/Courier0000.lzma.bak
2019-07-01T14:34:12.884Z,1561991652.884 [DataOverHttps](INFO): SBD MOMSN=11416144
2019-07-01T14:34:15.203Z,1561991655.203 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:34:18.069Z,1561991658.069 [Startup:StartupSatComms:B](INFO): Timed out from 2019-07-01T14:33:17.0Z
2019-07-01T14:34:18.069Z,1561991658.069 [Startup:StartupSatComms:B] Stopped
2019-07-01T14:34:18.069Z,1561991658.069 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2019-07-01T14:34:18.069Z,1561991658.069 [Startup:StartupSatComms] Stopped
2019-07-01T14:34:18.070Z,1561991658.070 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2019-07-01T14:34:18.070Z,1561991658.070 [Startup](INFO): Completed Startup
2019-07-01T14:34:18.071Z,1561991658.071 [MissionManager](INFO): Startup is completed.
2019-07-01T14:34:18.071Z,1561991658.071 [MissionManager](INFO): Uninitializing Mission Startup
2019-07-01T14:34:18.071Z,1561991658.071 [Startup] Stopped
2019-07-01T14:34:18.071Z,1561991658.071 [Startup](DEBUG): Aggregate::uninitialize Startup
2019-07-01T14:34:18.071Z,1561991658.071 [Startup:A.GoToSurface] Stopped
2019-07-01T14:34:18.071Z,1561991658.071 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-07-01T14:34:18.435Z,1561991658.435 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:34:18.497Z,1561991658.497 [MissionManager](IMPORTANT): Started mission Default
2019-07-01T14:34:18.497Z,1561991658.497 [Default] Running Loop=1
2019-07-01T14:34:18.497Z,1561991658.497 [Default](DEBUG): Aggregate::initialize Default
2019-07-01T14:34:18.497Z,1561991658.497 [Default:B.GoToSurface] Running Loop=1
2019-07-01T14:34:18.497Z,1561991658.497 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-07-01T14:34:18.498Z,1561991658.498 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-07-01T14:34:18.498Z,1561991658.498 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-07-01T14:34:18.498Z,1561991658.498 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-07-01T14:34:18.499Z,1561991658.499 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-07-01T14:34:18.499Z,1561991658.499 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-07-01T14:34:18.499Z,1561991658.499 [Default:A.Wait] Running Loop=1
2019-07-01T14:34:18.499Z,1561991658.499 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-07-01T14:34:21.263Z,1561991661.263 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:34:24.143Z,1561991664.143 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:34:27.335Z,1561991667.335 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:34:29.300Z,1561991669.300 [DataOverHttps](INFO): Sending 374 bytes from file Logs/20190618T232705/Express0005.lzma
2019-07-01T14:34:30.104Z,1561991670.104 [DataOverHttps](INFO): Moved sent file to Logs/20190618T232705/Express0005.lzma.bak
2019-07-01T14:34:30.104Z,1561991670.104 [DataOverHttps](INFO): SBD MOMSN=11416148
2019-07-01T14:34:30.151Z,1561991670.151 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:34:31.802Z,1561991671.802 [Default:A.Wait](INFO): Done Waiting.
2019-07-01T14:34:31.802Z,1561991671.802 [Default:A.Wait] Stopped
2019-07-01T14:34:31.802Z,1561991671.802 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-07-01T14:34:32.183Z,1561991672.183 [Default:CheckIn] Running Loop=1
2019-07-01T14:34:32.183Z,1561991672.183 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-07-01T14:34:32.183Z,1561991672.183 [Default:CheckIn:Read_GPS] Running Loop=1
2019-07-01T14:34:32.590Z,1561991672.590 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2019-07-01T14:34:33.383Z,1561991673.383 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:34:36.211Z,1561991676.211 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:34:39.447Z,1561991679.447 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:34:42.271Z,1561991682.271 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:34:45.099Z,1561991685.099 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:34:48.339Z,1561991688.339 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:34:51.163Z,1561991691.163 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:34:54.391Z,1561991694.391 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:34:57.223Z,1561991697.223 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:35:00.451Z,1561991700.451 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:35:03.279Z,1561991703.279 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:35:06.143Z,1561991706.143 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:35:09.363Z,1561991709.363 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:35:12.167Z,1561991712.167 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:35:15.399Z,1561991715.399 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:35:18.235Z,1561991718.235 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:35:21.459Z,1561991721.459 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:35:24.291Z,1561991724.291 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:35:27.119Z,1561991727.119 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:35:30.351Z,1561991730.351 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:35:33.175Z,1561991733.175 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:35:36.410Z,1561991736.410 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:35:39.251Z,1561991739.251 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:35:42.487Z,1561991742.487 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:35:44.112Z,1561991744.112 [CommandLine](IMPORTANT): got command burn off
2019-07-01T14:35:44.113Z,1561991744.113 [CommandLine](IMPORTANT): Deactivating dropweight wire
2019-07-01T14:35:45.295Z,1561991745.295 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:35:48.547Z,1561991748.547 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:35:51.415Z,1561991751.415 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:35:54.183Z,1561991754.183 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:35:57.411Z,1561991757.411 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:36:00.243Z,1561991760.243 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:36:03.479Z,1561991763.479 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:36:06.303Z,1561991766.303 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:36:09.539Z,1561991769.539 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:36:12.363Z,1561991772.363 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:36:12.754Z,1561991772.754 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,143253.00,A,3648.16234,N,12147.28877,W,0.467,0.00,010719,,,A*7D
2019-07-01T14:36:12.757Z,1561991772.757 [NAL9602](INFO): GPS fix at 20190701T143253: (36.802706, -121.788146)
2019-07-01T14:36:12.838Z,1561991772.838 [Default:CheckIn:Read_GPS] Stopped
2019-07-01T14:36:12.838Z,1561991772.838 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-07-01T14:36:13.223Z,1561991773.223 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-07-01T14:36:18.901Z,1561991778.901 [DataOverHttps](INFO): Sending 215 bytes from file Logs/20190701T143043/Courier0004.lzma
2019-07-01T14:36:19.724Z,1561991779.724 [DataOverHttps](INFO): Moved sent file to Logs/20190701T143043/Courier0004.lzma.bak
2019-07-01T14:36:19.724Z,1561991779.724 [DataOverHttps](INFO): SBD MOMSN=11416167
2019-07-01T14:36:39.565Z,1561991799.565 [DataOverHttps](INFO): Sending 719 bytes from file Logs/20190624T152013/Express0001.lzma
2019-07-01T14:36:40.370Z,1561991800.370 [DataOverHttps](INFO): Moved sent file to Logs/20190624T152013/Express0001.lzma.bak
2019-07-01T14:36:40.371Z,1561991800.371 [DataOverHttps](INFO): SBD MOMSN=11416170
2019-07-01T14:36:45.204Z,1561991805.204 [NAL9602](INFO): Powering down
2019-07-01T14:36:57.247Z,1561991817.247 [DataOverHttps](INFO): Sending 708 bytes from file Logs/20190701T143043/Express0001.lzma
2019-07-01T14:36:57.754Z,1561991817.754 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-07-01T14:36:58.052Z,1561991818.052 [DataOverHttps](INFO): Moved sent file to Logs/20190701T143043/Express0001.lzma.bak
2019-07-01T14:36:58.052Z,1561991818.052 [DataOverHttps](INFO): SBD MOMSN=11416188
2019-07-01T14:37:06.212Z,1561991826.212 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-07-01T14:37:06.212Z,1561991826.212 [DVL_micro] Data Fault, FailCount= 1
2019-07-01T14:37:06.212Z,1561991826.212 [DVL_micro](ERROR): Data Fault
2019-07-01T14:37:06.268Z,1561991826.268 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-07-01T14:37:06.687Z,1561991826.687 [DVL_micro](INFO): uninitialize:Powering down
2019-07-01T14:37:07.485Z,1561991827.485 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-07-01T14:37:07.485Z,1561991827.485 [DVL_micro] No Fault, FailCount= 1
2019-07-01T14:37:07.834Z,1561991827.834 [DVL_micro](INFO): Initializing
2019-07-01T14:37:09.058Z,1561991829.058 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-07-01T14:33:56.673Z,1561991636.673 [DataOverHttps](INFO): Sending 342 bytes from file Logs/20190701T143043/Express0005.lzma
2019-07-01T14:33:57.479Z,1561991637.479 [DataOverHttps](INFO): Moved sent file to Logs/20190701T143043/Express0005.lzma.bak
2019-07-01T14:33:57.479Z,1561991637.479 [DataOverHttps](INFO): SBD MOMSN=11416205
2019-07-01T14:34:01.695Z,1561991641.695 [Default:CheckIn:Read_Iridium] Stopped
2019-07-01T14:34:01.695Z,1561991641.695 [Default:CheckIn:C.Wait] Running Loop=1
2019-07-01T14:34:01.695Z,1561991641.695 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-07-01T14:34:01.989Z,1561991641.989 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-07-01T14:34:13.305Z,1561991653.305 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-07-01T14:34:24.628Z,1561991664.628 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-07-01T14:34:35.520Z,1561991675.520 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-07-01T14:34:47.245Z,1561991687.245 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-07-01T14:34:58.553Z,1561991698.553 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-07-01T14:35:09.859Z,1561991709.859 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-07-01T14:35:21.169Z,1561991721.169 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-07-01T14:35:32.489Z,1561991732.489 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-07-01T14:35:43.402Z,1561991743.402 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-07-01T14:35:55.112Z,1561991755.112 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-07-01T14:36:54.075Z,1561991814.075 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-07-01T14:36:54.075Z,1561991814.075 [DVL_micro] Data Fault, FailCount= 1
2019-07-01T14:36:54.075Z,1561991814.075 [DVL_micro](ERROR): Data Fault
2019-07-01T14:36:54.113Z,1561991814.113 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-07-01T14:36:54.557Z,1561991814.557 [DVL_micro](INFO): uninitialize:Powering down
2019-07-01T14:36:55.326Z,1561991815.326 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-07-01T14:36:55.326Z,1561991815.326 [DVL_micro] No Fault, FailCount= 1
2019-07-01T14:36:55.700Z,1561991815.700 [DVL_micro](INFO): Initializing
2019-07-01T14:38:19.394Z,1561991899.394 [CommandLine](IMPORTANT): got command failComponent
2019-07-01T14:38:19.394Z,1561991899.394 [CommandLine](IMPORTANT): Failed components:
2019-07-01T14:38:19.394Z,1561991899.394 [CommandLine](IMPORTANT): No failed Components.
2019-07-01T14:39:02.189Z,1561991942.189 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-07-01T14:39:02.189Z,1561991942.189 [Default:CheckIn:C.Wait] Stopped
2019-07-01T14:39:02.189Z,1561991942.189 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-07-01T14:39:02.189Z,1561991942.189 [Default:CheckIn:D] Running Loop=1
2019-07-01T14:39:02.598Z,1561991942.598 [Default:CheckIn:D] Stopped
2019-07-01T14:39:02.598Z,1561991942.598 [Default:CheckIn:E] Running Loop=1
2019-07-01T14:39:03.002Z,1561991943.002 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 4.735012 min 
2019-07-01T14:39:03.002Z,1561991943.002 [Default:CheckIn:E] Stopped
2019-07-01T14:39:03.002Z,1561991943.002 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-07-01T14:39:03.003Z,1561991943.003 [Default:CheckIn] Stopped
2019-07-01T14:39:03.003Z,1561991943.003 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-07-01T14:39:03.003Z,1561991943.003 [Default:CheckIn](INFO): Running loop #2
2019-07-01T14:39:03.003Z,1561991943.003 [Default:CheckIn] Running Loop=2
2019-07-01T14:39:03.003Z,1561991943.003 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-07-01T14:39:03.003Z,1561991943.003 [Default:CheckIn:Read_GPS] Running Loop=1
2019-07-01T14:39:03.452Z,1561991943.452 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-07-01T14:39:03.772Z,1561991943.772 [NAL9602](INFO): Powering up
2019-07-01T14:39:14.704Z,1561991954.704 [NAL9602](INFO): NAL9602 initialized
2019-07-01T14:39:15.505Z,1561991955.505 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:39:27.618Z,1561991967.618 [DVL_micro](ERROR): only read 45 of 46 data items
2019-07-01T14:39:27.618Z,1561991967.618 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 0 0 0 0 -41 -582 -514 -1301 2 2 2 2 631.3 959.6 -657.4 2 -38.9 -1147.9 -657.4 2 631 959 -657 2 -38 -1147 -657 2 1.37 -2.0-3.0 19.9 0.005 35.0 1489 105
2019-07-01T14:39:36.904Z,1561991976.904 [NAL9602](INFO): SBD MO Status=2, MOMSN=522, MT Status=2, MTMSN=0
2019-07-01T14:39:36.904Z,1561991976.904 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-01T14:39:49.428Z,1561991989.428 [NAL9602](INFO): SBD MO Status=0, MOMSN=522, MT Status=0, MTMSN=0
2019-07-01T14:39:49.428Z,1561991989.428 [NAL9602](INFO): No messages in MT queue
2019-07-01T14:39:50.269Z,1561991990.269 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:39:53.497Z,1561991993.497 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:39:56.305Z,1561991996.305 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:39:59.137Z,1561991999.137 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:39:59.930Z,1561991999.930 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-07-01T14:39:59.930Z,1561991999.930 [DVL_micro] Data Fault, FailCount= 1
2019-07-01T14:39:59.930Z,1561991999.930 [DVL_micro](ERROR): Data Fault
2019-07-01T14:39:59.982Z,1561991999.982 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-07-01T14:40:00.409Z,1561992000.409 [DVL_micro](INFO): uninitialize:Powering down
2019-07-01T14:40:01.224Z,1561992001.224 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-07-01T14:40:01.224Z,1561992001.224 [DVL_micro] No Fault, FailCount= 1
2019-07-01T14:40:01.548Z,1561992001.548 [DVL_micro](INFO): Initializing
2019-07-01T14:40:01.561Z,1561992001.561 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:40:04.389Z,1561992004.389 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:40:07.209Z,1561992007.209 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:40:10.453Z,1561992010.453 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:40:13.273Z,1561992013.273 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:40:15.238Z,1561992015.238 [CommandLine](IMPORTANT): got command failComponent
2019-07-01T14:40:15.238Z,1561992015.238 [CommandLine](IMPORTANT): Failed components:
2019-07-01T14:40:15.238Z,1561992015.238 [CommandLine](IMPORTANT): No failed Components.
2019-07-01T14:40:16.501Z,1561992016.501 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:40:19.333Z,1561992019.333 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:40:22.565Z,1561992022.565 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:40:24.659Z,1561992024.659 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-07-01T14:40:25.393Z,1561992025.393 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:40:27.471Z,1561992027.471 [CommandLine](IMPORTANT): got command show variable dvl_micro
2019-07-01T14:40:27.483Z,1561992027.483 [CommandLine](IMPORTANT): DVL_micro.loadControl (none)
2019-07-01T14:40:27.484Z,1561992027.484 [CommandLine](IMPORTANT): DVL_micro.uart (none)
2019-07-01T14:40:27.484Z,1561992027.484 [CommandLine](IMPORTANT): DVL_micro.baud (bit_per_second)
2019-07-01T14:40:27.562Z,1561992027.562 [CommandLine](IMPORTANT): DVL_micro.loadAtStartup (bool)
2019-07-01T14:40:27.563Z,1561992027.563 [CommandLine](IMPORTANT): DVL_micro.simulateHardware (bool)
2019-07-01T14:40:27.563Z,1561992027.563 [CommandLine](IMPORTANT): DVL_micro.magDeviation (degree)
2019-07-01T14:40:27.564Z,1561992027.564 [CommandLine](IMPORTANT): DVL_micro.pitchOffset (degree)
2019-07-01T14:40:27.564Z,1561992027.564 [CommandLine](IMPORTANT): DVL_micro.power (watt)
2019-07-01T14:40:27.564Z,1561992027.564 [CommandLine](IMPORTANT): DVL_micro.rollOffset (degree)
2019-07-01T14:40:27.611Z,1561992027.611 [CommandLine](IMPORTANT): DVL_micro.height_above_sea_floor (meter)
2019-07-01T14:40:27.611Z,1561992027.611 [CommandLine](IMPORTANT): DVL_micro.platform_orientation (radian)
2019-07-01T14:40:27.611Z,1561992027.611 [CommandLine](IMPORTANT): DVL_micro.platform_magnetic_orientation (radian)
2019-07-01T14:40:27.612Z,1561992027.612 [CommandLine](IMPORTANT): DVL_micro.platform_pitch_angle (radian)
2019-07-01T14:40:27.612Z,1561992027.612 [CommandLine](IMPORTANT): DVL_micro.platform_roll_angle (radian)
2019-07-01T14:40:27.612Z,1561992027.612 [CommandLine](IMPORTANT): DVL_micro.platform_orientation_matrix (none)
2019-07-01T14:40:27.617Z,1561992027.617 [CommandLine](IMPORTANT): DVL_micro.platform_velocity_wrt_ground (meter_per_second)
2019-07-01T14:40:27.618Z,1561992027.618 [CommandLine](IMPORTANT): DVL_micro.platform_x_velocity_wrt_ground (meter_per_second)
2019-07-01T14:40:27.618Z,1561992027.618 [CommandLine](IMPORTANT): DVL_micro.platform_y_velocity_wrt_ground (meter_per_second)
2019-07-01T14:40:27.618Z,1561992027.618 [CommandLine](IMPORTANT): DVL_micro.platform_z_velocity_wrt_ground (meter_per_second)
2019-07-01T14:40:27.619Z,1561992027.619 [CommandLine](IMPORTANT): DVL_micro.platform_velocity_wrt_sea_water (meter_per_second)
2019-07-01T14:40:27.619Z,1561992027.619 [CommandLine](IMPORTANT): DVL_micro.platform_x_velocity_wrt_sea_water (meter_per_second)
2019-07-01T14:40:27.620Z,1561992027.620 [CommandLine](IMPORTANT): DVL_micro.platform_y_velocity_wrt_sea_water (meter_per_second)
2019-07-01T14:40:27.620Z,1561992027.620 [CommandLine](IMPORTANT): DVL_micro.platform_z_velocity_wrt_sea_water (meter_per_second)
2019-07-01T14:40:27.620Z,1561992027.620 [CommandLine](IMPORTANT): DVL_micro.platform_x_velocity_current (meter_per_second)
2019-07-01T14:40:27.621Z,1561992027.621 [CommandLine](IMPORTANT): DVL_micro.platform_y_velocity_current (meter_per_second)
2019-07-01T14:40:27.625Z,1561992027.625 [CommandLine](IMPORTANT): DVL_micro.platform_z_velocity_current (meter_per_second)
2019-07-01T14:40:27.626Z,1561992027.626 [CommandLine](IMPORTANT): DVL_micro.Status (count)
2019-07-01T14:40:27.626Z,1561992027.626 [CommandLine](IMPORTANT): DVL_micro.Beam1Good (count)
2019-07-01T14:40:27.626Z,1561992027.626 [CommandLine](IMPORTANT): DVL_micro.Beam2Good (count)
2019-07-01T14:40:27.627Z,1561992027.627 [CommandLine](IMPORTANT): DVL_micro.Beam3Good (count)
2019-07-01T14:40:27.627Z,1561992027.627 [CommandLine](IMPORTANT): DVL_micro.Beam4Good (count)
2019-07-01T14:40:27.628Z,1561992027.628 [CommandLine](IMPORTANT): DVL_micro.Altitude1 (meter)
2019-07-01T14:40:27.628Z,1561992027.628 [CommandLine](IMPORTANT): DVL_micro.Altitude2 (meter)
2019-07-01T14:40:27.628Z,1561992027.628 [CommandLine](IMPORTANT): DVL_micro.Altitude3 (meter)
2019-07-01T14:40:27.629Z,1561992027.629 [CommandLine](IMPORTANT): DVL_micro.Altitude4 (meter)
2019-07-01T14:40:27.633Z,1561992027.633 [CommandLine](IMPORTANT): DVL_micro.BottomVelocityFlag (count)
2019-07-01T14:40:27.634Z,1561992027.634 [CommandLine](IMPORTANT): DVL_micro.WaterVelocityFlag (meter)
2019-07-01T14:40:27.680Z,1561992027.680 [CommandLine](IMPORTANT): DVL_micro.component_voltage (volt)
2019-07-01T14:40:27.681Z,1561992027.681 [CommandLine](IMPORTANT): DVL_micro.component_avgVoltage (volt)
2019-07-01T14:40:27.688Z,1561992027.688 [CommandLine](IMPORTANT): DVL_micro.component_current (milliampere)
2019-07-01T14:40:27.688Z,1561992027.688 [CommandLine](IMPORTANT): DVL_micro.component_avgCurrent (milliampere)
2019-07-01T14:40:28.225Z,1561992028.225 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:40:31.453Z,1561992031.453 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:40:34.285Z,1561992034.285 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:40:37.513Z,1561992037.513 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:40:37.879Z,1561992037.879 [CommandLine](IMPORTANT): got command report mod DVL_micro.Altitude1
2019-07-01T14:40:38.032Z,1561992038.032 [Reporter](INFO): DVL_micro.Altitude1 0.000000 m
2019-07-01T14:40:40.361Z,1561992040.361 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:40:43.597Z,1561992043.597 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:40:44.663Z,1561992044.663 [CommandLine](IMPORTANT): got command report clear
2019-07-01T14:40:46.405Z,1561992046.405 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:40:49.225Z,1561992049.225 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:40:52.461Z,1561992052.461 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:40:55.285Z,1561992055.285 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:40:58.521Z,1561992058.521 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:41:01.037Z,1561992061.037 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-07-01T14:41:01.345Z,1561992061.345 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:41:04.176Z,1561992064.176 [CommandLine](IMPORTANT): got command report mod DVL_micro.platform_roll_angle
2019-07-01T14:41:04.284Z,1561992064.284 [Reporter](INFO): DVL_micro.platform_roll_angle 0.025482 rad
2019-07-01T14:41:04.594Z,1561992064.594 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:41:06.406Z,1561992066.406 [Reporter](INFO): DVL_micro.platform_roll_angle 0.024609 rad
2019-07-01T14:41:07.413Z,1561992067.413 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:41:09.431Z,1561992069.431 [DVL_micro](ERROR): only read 44 of 46 data items
2019-07-01T14:41:09.431Z,1561992069.431 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 0 0 0 0 -379 613 -385 -1478 2 2 2 2 8.0 2790.7 -4346.9 -2386.1 -439.3 2 8 2790 -439 2 1446 -2386 -439 2 1.33 -2.13 211.4 -3.0 19.9 0.01489 123
2019-07-01T14:41:10.277Z,1561992070.277 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:41:11.551Z,1561992071.551 [CommandLine](IMPORTANT): got command report clear
2019-07-01T14:41:13.473Z,1561992073.473 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:41:16.305Z,1561992076.305 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:41:18.750Z,1561992078.750 [CommandLine](IMPORTANT): got command ibit
2019-07-01T14:41:18.967Z,1561992078.967 [IBIT](IMPORTANT): Beginning Initiated BIT
2019-07-01T14:41:18.967Z,1561992078.967 [IBIT](IMPORTANT): Beginning control surface checks.
2019-07-01T14:41:18.978Z,1561992078.978 [CBIT](IMPORTANT): Beginning ground fault scan
2019-07-01T14:41:19.537Z,1561992079.537 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:41:21.813Z,1561992081.813 [CBIT](INFO): A/D timeout, 4 tries over 163 ms

2019-07-01T14:41:22.389Z,1561992082.389 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:41:25.621Z,1561992085.621 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:41:27.696Z,1561992087.696 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-07-01T14:41:28.425Z,1561992088.425 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:41:29.728Z,1561992089.728 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): -0.000931
CHAN A1 (24V): nan
CHAN A2 (12V): -0.094255
CHAN A3 (5V): -0.002308
CHAN B0 (3.3V): -0.000478
CHAN B1 (3.15aV): -0.000955
CHAN B2 (3.15bV): -0.001608
CHAN B3 (GND): -0.000092
OPEN: 0.003714
Full Scale Calc: 4.765 mA, -1.589 mA
2019-07-01T14:41:31.257Z,1561992091.257 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:41:34.489Z,1561992094.489 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:41:37.313Z,1561992097.313 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:41:40.549Z,1561992100.549 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:41:43.385Z,1561992103.385 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:41:46.605Z,1561992106.605 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:41:49.433Z,1561992109.433 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:41:52.257Z,1561992112.257 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:41:55.497Z,1561992115.497 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:41:58.321Z,1561992118.321 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:42:01.573Z,1561992121.573 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:42:04.409Z,1561992124.409 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:42:07.653Z,1561992127.653 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:42:10.444Z,1561992130.444 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:42:13.273Z,1561992133.273 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:42:16.513Z,1561992136.513 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:42:19.329Z,1561992139.329 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:42:22.561Z,1561992142.561 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:42:22.985Z,1561992142.985 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,144222.00,A,3648.15100,N,12147.29177,W,0.408,0.00,010719,,,A*7A
2019-07-01T14:42:22.988Z,1561992142.988 [NAL9602](INFO): GPS fix at 20190701T144222: (36.802517, -121.788196)
2019-07-01T14:42:23.063Z,1561992143.063 [IBIT](IMPORTANT): Communications Status:
Fix Status: 1
Iridium Signal Strength: 2
Latitude: 36.802517 Longitude: -121.788193
2019-07-01T14:42:23.426Z,1561992143.426 [IBIT](FAULT): Warning: Battery Data not active. Expected only when running primaries. Threshold checking not active.
2019-07-01T14:42:23.819Z,1561992143.819 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2019-07-01T14:42:23.819Z,1561992143.819 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2019-07-01T14:42:23.820Z,1561992143.820 [IBIT](IMPORTANT): Pressure:7.148775 PSI
2019-07-01T14:42:23.820Z,1561992143.820 [IBIT](IMPORTANT): Humidity:11.463801 %
2019-07-01T14:42:24.257Z,1561992144.257 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2019-07-01T14:42:24.257Z,1561992144.257 [IBIT](IMPORTANT): buoyancyNeutral: 300.000000 cc
2019-07-01T14:42:24.257Z,1561992144.257 [IBIT](IMPORTANT): massDefault: 0.200000 cm
2019-07-01T14:42:24.258Z,1561992144.258 [IBIT](IMPORTANT): stopDepth: 215.000000 m
2019-07-01T14:42:24.258Z,1561992144.258 [IBIT](IMPORTANT): abortDepth: 255.000000 m
2019-07-01T14:42:24.258Z,1561992144.258 [IBIT](IMPORTANT): IBIT PASSED
2019-07-01T14:42:24.621Z,1561992144.621 [Default:CheckIn:Read_GPS] Stopped
2019-07-01T14:42:24.621Z,1561992144.621 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-07-01T14:42:31.216Z,1561992151.216 [DataOverHttps](INFO): Sending 64 bytes from file Logs/20190701T143043/Courier0007.lzma
2019-07-01T14:42:32.023Z,1561992152.023 [DataOverHttps](INFO): Moved sent file to Logs/20190701T143043/Courier0007.lzma.bak
2019-07-01T14:42:32.023Z,1561992152.023 [DataOverHttps](INFO): SBD MOMSN=11416222
2019-07-01T14:42:47.067Z,1561992167.067 [DataOverHttps](INFO): Sending 1348 bytes from file Logs/20190701T143043/Express0008.lzma
2019-07-01T14:42:47.871Z,1561992167.871 [DataOverHttps](INFO): Moved sent file to Logs/20190701T143043/Express0008.lzma.bak
2019-07-01T14:42:47.871Z,1561992167.871 [DataOverHttps](INFO): SBD MOMSN=11416225
2019-07-01T14:42:51.790Z,1561992171.790 [Default:CheckIn:Read_Iridium] Stopped
2019-07-01T14:42:51.790Z,1561992171.790 [Default:CheckIn:C.Wait] Running Loop=1
2019-07-01T14:42:51.790Z,1561992171.790 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-07-01T14:42:55.374Z,1561992175.374 [NAL9602](INFO): Powering down
2019-07-01T14:43:06.278Z,1561992186.278 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-07-01T14:43:06.278Z,1561992186.278 [DVL_micro] Data Fault, FailCount= 1
2019-07-01T14:43:06.278Z,1561992186.278 [DVL_micro](ERROR): Data Fault
2019-07-01T14:43:06.325Z,1561992186.325 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-07-01T14:43:06.757Z,1561992186.757 [DVL_micro](INFO): uninitialize:Powering down
2019-07-01T14:43:07.533Z,1561992187.533 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-07-01T14:43:07.533Z,1561992187.533 [DVL_micro] No Fault, FailCount= 1
2019-07-01T14:43:07.898Z,1561992187.898 [DVL_micro](INFO): Initializing
2019-07-01T14:43:29.841Z,1561992209.841 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-07-01T14:43:43.990Z,1561992223.990 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-07-01T14:43:58.121Z,1561992238.121 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-07-01T14:44:12.291Z,1561992252.291 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-07-01T14:44:26.405Z,1561992266.405 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-07-01T14:44:41.381Z,1561992281.381 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-07-01T14:44:55.485Z,1561992295.485 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-07-01T14:45:09.623Z,1561992309.623 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-07-01T14:45:23.770Z,1561992323.770 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-07-01T14:45:37.909Z,1561992337.909 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-07-01T14:45:52.045Z,1561992352.045 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-07-01T14:46:11.826Z,1561992371.826 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-07-01T14:46:11.827Z,1561992371.827 [DVL_micro] Data Fault, FailCount= 1
2019-07-01T14:46:11.827Z,1561992371.827 [DVL_micro](ERROR): Data Fault
2019-07-01T14:46:11.865Z,1561992371.865 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-07-01T14:46:12.301Z,1561992372.301 [DVL_micro](INFO): uninitialize:Powering down
2019-07-01T14:46:13.090Z,1561992373.090 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-07-01T14:46:13.091Z,1561992373.091 [DVL_micro] No Fault, FailCount= 1
2019-07-01T14:46:13.448Z,1561992373.448 [DVL_micro](INFO): Initializing
2019-07-01T14:46:28.472Z,1561992388.472 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-07-01T14:46:41.406Z,1561992401.406 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-07-01T14:47:07.877Z,1561992427.877 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-07-01T14:47:20.222Z,1561992440.222 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-07-01T14:47:46.915Z,1561992466.915 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-07-01T14:47:52.462Z,1561992472.462 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-07-01T14:47:52.462Z,1561992472.462 [Default:CheckIn:C.Wait] Stopped
2019-07-01T14:47:52.462Z,1561992472.462 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-07-01T14:47:52.462Z,1561992472.462 [Default:CheckIn:D] Running Loop=1
2019-07-01T14:47:52.873Z,1561992472.873 [Default:CheckIn:D] Stopped
2019-07-01T14:47:52.873Z,1561992472.873 [Default:CheckIn:E] Running Loop=1
2019-07-01T14:47:53.271Z,1561992473.271 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 13.572939 min 
2019-07-01T14:47:53.271Z,1561992473.271 [Default:CheckIn:E] Stopped
2019-07-01T14:47:53.271Z,1561992473.271 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-07-01T14:47:53.271Z,1561992473.271 [Default:CheckIn] Stopped
2019-07-01T14:47:53.271Z,1561992473.271 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-07-01T14:47:53.272Z,1561992473.272 [Default:CheckIn](INFO): Running loop #3
2019-07-01T14:47:53.272Z,1561992473.272 [Default:CheckIn] Running Loop=3
2019-07-01T14:47:53.272Z,1561992473.272 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-07-01T14:47:53.272Z,1561992473.272 [Default:CheckIn:Read_GPS] Running Loop=1
2019-07-01T14:47:54.052Z,1561992474.052 [NAL9602](INFO): Powering up
2019-07-01T14:48:04.963Z,1561992484.963 [NAL9602](INFO): NAL9602 initialized
2019-07-01T14:48:05.785Z,1561992485.785 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:48:21.524Z,1561992501.524 [NAL9602](INFO): SBD MO Status=0, MOMSN=523, MT Status=0, MTMSN=0
2019-07-01T14:48:21.524Z,1561992501.524 [NAL9602](INFO): No messages in MT queue
2019-07-01T14:48:22.341Z,1561992502.341 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:48:25.573Z,1561992505.573 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:48:28.405Z,1561992508.405 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:48:31.238Z,1561992511.238 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:48:34.469Z,1561992514.469 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:48:37.293Z,1561992517.293 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:48:40.122Z,1561992520.122 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:48:43.357Z,1561992523.357 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:48:46.185Z,1561992526.185 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:48:49.417Z,1561992529.417 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:48:52.245Z,1561992532.245 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:48:55.473Z,1561992535.473 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:48:58.337Z,1561992538.337 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:49:01.557Z,1561992541.557 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:49:04.369Z,1561992544.369 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:49:07.597Z,1561992547.597 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:49:10.425Z,1561992550.425 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:49:13.657Z,1561992553.657 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:49:16.485Z,1561992556.485 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:49:17.682Z,1561992557.682 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-07-01T14:49:17.682Z,1561992557.682 [DVL_micro] Data Fault, FailCount= 1
2019-07-01T14:49:17.682Z,1561992557.682 [DVL_micro](ERROR): Data Fault
2019-07-01T14:49:17.746Z,1561992557.746 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-07-01T14:49:18.161Z,1561992558.161 [DVL_micro](INFO): uninitialize:Powering down
2019-07-01T14:49:18.927Z,1561992558.927 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-07-01T14:49:18.927Z,1561992558.927 [DVL_micro] No Fault, FailCount= 1
2019-07-01T14:49:19.304Z,1561992559.304 [DVL_micro](INFO): Initializing
2019-07-01T14:49:19.317Z,1561992559.317 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:49:22.133Z,1561992562.133 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:49:25.373Z,1561992565.373 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:49:28.197Z,1561992568.197 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:49:31.429Z,1561992571.429 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:49:34.264Z,1561992574.264 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:49:37.489Z,1561992577.489 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:49:40.317Z,1561992580.317 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:49:43.554Z,1561992583.554 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:49:46.378Z,1561992586.378 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:49:49.613Z,1561992589.613 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:49:52.437Z,1561992592.437 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:49:55.673Z,1561992595.673 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:49:58.497Z,1561992598.497 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:50:01.345Z,1561992601.345 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:50:04.153Z,1561992604.153 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:50:07.381Z,1561992607.381 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:50:10.214Z,1561992610.214 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:50:13.450Z,1561992613.450 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:50:16.277Z,1561992616.277 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:50:19.505Z,1561992619.505 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:50:22.337Z,1561992622.337 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:50:25.561Z,1561992625.561 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:50:28.397Z,1561992628.397 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:50:31.622Z,1561992631.622 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:50:34.453Z,1561992634.453 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:50:37.285Z,1561992637.285 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:50:40.513Z,1561992640.513 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:50:43.385Z,1561992643.385 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:50:46.165Z,1561992646.165 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:50:49.401Z,1561992649.401 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:50:52.225Z,1561992652.225 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:50:55.461Z,1561992655.461 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:50:58.285Z,1561992658.285 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:50:58.814Z,1561992658.814 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-07-01T14:51:01.521Z,1561992661.521 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:51:04.384Z,1561992664.384 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:51:07.601Z,1561992667.601 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:51:10.433Z,1561992670.433 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:51:13.277Z,1561992673.277 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:51:16.508Z,1561992676.508 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:51:18.907Z,1561992678.907 [DVL_micro](ERROR): only read 44 of 46 data items
2019-07-01T14:51:18.907Z,1561992678.907 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 0 0 0 0 202 -234 -556 -1295 2 2 2 2 1011.7 1416.0 -507.7 2 -128.9 -1735.4 -507.7 2 1011 1416 -507 2 -128 -1735 -507 2 1.46 -2.03 211.3 -3.0 20.1 0.005 35121
2019-07-01T14:51:19.317Z,1561992679.317 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:51:22.177Z,1561992682.177 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:51:25.397Z,1561992685.397 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:51:25.870Z,1561992685.870 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-07-01T14:51:28.205Z,1561992688.205 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:51:31.433Z,1561992691.433 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:51:34.265Z,1561992694.265 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:51:37.505Z,1561992697.505 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:51:40.333Z,1561992700.333 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:51:43.557Z,1561992703.557 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:51:46.385Z,1561992706.385 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:51:49.617Z,1561992709.617 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:51:52.445Z,1561992712.445 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:51:52.980Z,1561992712.980 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-07-01T14:51:55.273Z,1561992715.273 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:51:58.505Z,1561992718.505 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:52:01.737Z,1561992721.737 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:52:04.569Z,1561992724.569 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:52:06.255Z,1561992726.255 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-07-01T14:52:07.429Z,1561992727.429 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:52:07.799Z,1561992727.799 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,145206.00,A,3648.15161,N,12147.29363,W,0.117,0.00,010719,,,A*76
2019-07-01T14:52:07.802Z,1561992727.802 [NAL9602](INFO): GPS fix at 20190701T145206: (36.802527, -121.788227)
2019-07-01T14:52:07.826Z,1561992727.826 [Default:CheckIn:Read_GPS] Stopped
2019-07-01T14:52:07.826Z,1561992727.826 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-07-01T14:52:16.033Z,1561992736.033 [DataOverHttps](INFO): Sending 64 bytes from file Logs/20190701T143043/Courier0010.lzma
2019-07-01T14:52:16.839Z,1561992736.839 [DataOverHttps](INFO): Moved sent file to Logs/20190701T143043/Courier0010.lzma.bak
2019-07-01T14:52:16.839Z,1561992736.839 [DataOverHttps](INFO): SBD MOMSN=11416304
2019-07-01T14:52:18.846Z,1561992738.846 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-07-01T14:52:19.268Z,1561992739.268 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-07-01T14:52:23.566Z,1561992743.566 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-07-01T14:52:23.566Z,1561992743.566 [DVL_micro] Data Fault, FailCount= 1
2019-07-01T14:52:23.567Z,1561992743.567 [DVL_micro](ERROR): Data Fault
2019-07-01T14:52:23.662Z,1561992743.662 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-07-01T14:52:24.045Z,1561992744.045 [DVL_micro](INFO): uninitialize:Powering down
2019-07-01T14:52:24.830Z,1561992744.830 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-07-01T14:52:24.830Z,1561992744.830 [DVL_micro] No Fault, FailCount= 1
2019-07-01T14:52:25.188Z,1561992745.188 [DVL_micro](INFO): Initializing
2019-07-01T14:52:31.384Z,1561992751.384 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-07-01T14:52:32.194Z,1561992752.194 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-07-01T14:52:33.901Z,1561992753.901 [DataOverHttps](INFO): Sending 182 bytes from file Logs/20190701T143043/Express0011.lzma
2019-07-01T14:52:34.706Z,1561992754.706 [DataOverHttps](INFO): Moved sent file to Logs/20190701T143043/Express0011.lzma.bak
2019-07-01T14:52:34.707Z,1561992754.707 [DataOverHttps](INFO): SBD MOMSN=11416307
2019-07-01T14:52:38.562Z,1561992758.562 [Default:CheckIn:Read_Iridium] Stopped
2019-07-01T14:52:38.562Z,1561992758.562 [Default:CheckIn:C.Wait] Running Loop=1
2019-07-01T14:52:38.562Z,1561992758.562 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-07-01T14:52:40.130Z,1561992760.130 [NAL9602](INFO): Powering down
2019-07-01T14:53:16.986Z,1561992796.986 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-07-01T14:53:18.123Z,1561992798.123 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-07-01T14:53:32.265Z,1561992812.265 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-07-01T14:53:46.402Z,1561992826.402 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-07-01T14:54:00.542Z,1561992840.542 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-07-01T14:54:14.685Z,1561992854.685 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-07-01T14:54:28.821Z,1561992868.821 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-07-01T14:54:42.558Z,1561992882.558 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-07-01T14:54:56.699Z,1561992896.699 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-07-01T14:55:11.253Z,1561992911.253 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-07-01T14:55:20.191Z,1561992920.191 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-07-01T14:55:25.379Z,1561992925.379 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-07-01T14:55:29.414Z,1561992929.414 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-07-01T14:55:29.414Z,1561992929.414 [DVL_micro] Data Fault, FailCount= 1
2019-07-01T14:55:29.414Z,1561992929.414 [DVL_micro](ERROR): Data Fault
2019-07-01T14:55:29.447Z,1561992929.447 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-07-01T14:55:29.881Z,1561992929.881 [DVL_micro](INFO): uninitialize:Powering down
2019-07-01T14:55:30.674Z,1561992930.674 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-07-01T14:55:30.674Z,1561992930.674 [DVL_micro] No Fault, FailCount= 1
2019-07-01T14:55:31.032Z,1561992931.032 [DVL_micro](INFO): Initializing
2019-07-01T14:55:39.932Z,1561992939.932 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-07-01T14:56:13.188Z,1561992973.188 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-07-01T14:56:55.543Z,1561993015.543 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-07-01T14:57:35.620Z,1561993055.620 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-07-01T14:57:39.172Z,1561993059.172 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-07-01T14:57:39.172Z,1561993059.172 [Default:CheckIn:C.Wait] Stopped
2019-07-01T14:57:39.172Z,1561993059.172 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-07-01T14:57:39.172Z,1561993059.172 [Default:CheckIn:D] Running Loop=1
2019-07-01T14:57:39.640Z,1561993059.640 [Default:CheckIn:D] Stopped
2019-07-01T14:57:39.640Z,1561993059.640 [Default:CheckIn:E] Running Loop=1
2019-07-01T14:57:40.002Z,1561993060.002 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 23.352382 min 
2019-07-01T14:57:40.002Z,1561993060.002 [Default:CheckIn:E] Stopped
2019-07-01T14:57:40.002Z,1561993060.002 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-07-01T14:57:40.003Z,1561993060.003 [Default:CheckIn] Stopped
2019-07-01T14:57:40.003Z,1561993060.003 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-07-01T14:57:40.003Z,1561993060.003 [Default:CheckIn](INFO): Running loop #4
2019-07-01T14:57:40.003Z,1561993060.003 [Default:CheckIn] Running Loop=4
2019-07-01T14:57:40.003Z,1561993060.003 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-07-01T14:57:40.003Z,1561993060.003 [Default:CheckIn:Read_GPS] Running Loop=1
2019-07-01T14:57:40.723Z,1561993060.723 [NAL9602](INFO): Powering up
2019-07-01T14:57:51.631Z,1561993071.631 [NAL9602](INFO): NAL9602 initialized
2019-07-01T14:57:52.462Z,1561993072.462 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:58:02.708Z,1561993082.708 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-07-01T14:58:23.956Z,1561993103.956 [NAL9602](INFO): SBD MO Status=0, MOMSN=524, MT Status=0, MTMSN=0
2019-07-01T14:58:23.956Z,1561993103.956 [NAL9602](INFO): No messages in MT queue
2019-07-01T14:58:24.773Z,1561993104.773 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:58:27.201Z,1561993107.201 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:58:30.433Z,1561993110.433 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:58:33.257Z,1561993113.257 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:58:35.262Z,1561993115.262 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-07-01T14:58:35.263Z,1561993115.263 [DVL_micro] Data Fault, FailCount= 1
2019-07-01T14:58:35.263Z,1561993115.263 [DVL_micro](ERROR): Data Fault
2019-07-01T14:58:35.296Z,1561993115.296 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-07-01T14:58:35.733Z,1561993115.733 [DVL_micro](INFO): uninitialize:Powering down
2019-07-01T14:58:36.485Z,1561993116.485 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:58:36.533Z,1561993116.533 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-07-01T14:58:36.533Z,1561993116.533 [DVL_micro] No Fault, FailCount= 1
2019-07-01T14:58:36.888Z,1561993116.888 [DVL_micro](INFO): Initializing
2019-07-01T14:58:39.317Z,1561993119.317 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:58:42.146Z,1561993122.146 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:58:45.373Z,1561993125.373 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:58:48.209Z,1561993128.209 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:58:51.437Z,1561993131.437 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:58:54.265Z,1561993134.265 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:58:55.962Z,1561993135.962 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-07-01T14:58:57.093Z,1561993137.093 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:59:00.337Z,1561993140.337 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:59:03.157Z,1561993143.157 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:59:06.385Z,1561993146.385 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:59:09.253Z,1561993149.253 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:59:12.469Z,1561993152.469 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:59:15.277Z,1561993155.277 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:59:18.101Z,1561993158.101 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:59:21.337Z,1561993161.337 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:59:24.161Z,1561993164.161 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:59:27.389Z,1561993167.389 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:59:30.217Z,1561993170.217 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:59:33.449Z,1561993173.449 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:59:36.281Z,1561993176.281 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:59:39.109Z,1561993179.109 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:59:42.344Z,1561993182.344 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:59:45.169Z,1561993185.169 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:59:48.409Z,1561993188.409 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:59:51.249Z,1561993191.249 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:59:54.501Z,1561993194.501 [NAL9602](DEBUG): Fix Requested
2019-07-01T14:59:57.289Z,1561993197.289 [NAL9602](DEBUG): Fix Requested
2019-07-01T15:00:00.121Z,1561993200.121 [NAL9602](DEBUG): Fix Requested
2019-07-01T15:00:03.349Z,1561993203.349 [NAL9602](DEBUG): Fix Requested
2019-07-01T15:00:06.185Z,1561993206.185 [NAL9602](DEBUG): Fix Requested
2019-07-01T15:00:09.413Z,1561993209.413 [NAL9602](DEBUG): Fix Requested
2019-07-01T15:00:12.241Z,1561993212.241 [NAL9602](DEBUG): Fix Requested
2019-07-01T15:00:15.469Z,1561993215.469 [NAL9602](DEBUG): Fix Requested
2019-07-01T15:00:18.297Z,1561993218.297 [NAL9602](DEBUG): Fix Requested
2019-07-01T15:00:21.125Z,1561993221.125 [NAL9602](DEBUG): Fix Requested
2019-07-01T15:00:24.353Z,1561993224.353 [NAL9602](DEBUG): Fix Requested
2019-07-01T15:00:27.185Z,1561993227.185 [NAL9602](DEBUG): Fix Requested
2019-07-01T15:00:30.421Z,1561993230.421 [NAL9602](DEBUG): Fix Requested
2019-07-01T15:00:33.269Z,1561993233.269 [NAL9602](DEBUG): Fix Requested
2019-07-01T15:00:36.505Z,1561993236.505 [NAL9602](DEBUG): Fix Requested
2019-07-01T15:00:39.305Z,1561993239.305 [NAL9602](DEBUG): Fix Requested
2019-07-01T15:00:42.133Z,1561993242.133 [NAL9602](DEBUG): Fix Requested
2019-07-01T15:00:45.365Z,1561993245.365 [NAL9602](DEBUG): Fix Requested
2019-07-01T15:00:48.193Z,1561993248.193 [NAL9602](DEBUG): Fix Requested
2019-07-01T15:00:51.429Z,1561993251.429 [NAL9602](DEBUG): Fix Requested
2019-07-01T15:00:54.257Z,1561993254.257 [NAL9602](DEBUG): Fix Requested
2019-07-01T15:00:57.481Z,1561993257.481 [NAL9602](DEBUG): Fix Requested
2019-07-01T15:01:00.313Z,1561993260.313 [NAL9602](DEBUG): Fix Requested
2019-07-01T15:01:03.145Z,1561993263.145 [NAL9602](DEBUG): Fix Requested
2019-07-01T15:01:06.378Z,1561993266.378 [NAL9602](DEBUG): Fix Requested
2019-07-01T15:01:09.205Z,1561993269.205 [NAL9602](DEBUG): Fix Requested
2019-07-01T15:01:12.433Z,1561993272.433 [NAL9602](DEBUG): Fix Requested
2019-07-01T15:01:15.285Z,1561993275.285 [NAL9602](DEBUG): Fix Requested
2019-07-01T15:01:18.509Z,1561993278.509 [NAL9602](DEBUG): Fix Requested
2019-07-01T15:01:21.337Z,1561993281.337 [NAL9602](DEBUG): Fix Requested
2019-07-01T15:01:24.145Z,1561993284.145 [NAL9602](DEBUG): Fix Requested
2019-07-01T15:01:27.377Z,1561993287.377 [NAL9602](DEBUG): Fix Requested
2019-07-01T15:01:30.209Z,1561993290.209 [NAL9602](DEBUG): Fix Requested
2019-07-01T15:01:33.446Z,1561993293.446 [NAL9602](DEBUG): Fix Requested
2019-07-01T15:01:36.269Z,1561993296.269 [NAL9602](DEBUG): Fix Requested
2019-07-01T15:01:39.501Z,1561993299.501 [NAL9602](DEBUG): Fix Requested
2019-07-01T15:01:39.622Z,1561993299.622 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-07-01T15:01:41.106Z,1561993301.106 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-07-01T15:01:41.106Z,1561993301.106 [DVL_micro] Data Fault, FailCount= 1
2019-07-01T15:01:41.106Z,1561993301.106 [DVL_micro](ERROR): Data Fault
2019-07-01T15:01:41.147Z,1561993301.147 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-07-01T15:01:41.581Z,1561993301.581 [DVL_micro](INFO): uninitialize:Powering down
2019-07-01T15:01:42.333Z,1561993302.333 [NAL9602](DEBUG): Fix Requested
2019-07-01T15:01:42.394Z,1561993302.394 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-07-01T15:01:42.394Z,1561993302.394 [DVL_micro] No Fault, FailCount= 1
2019-07-01T15:01:42.724Z,1561993302.724 [DVL_micro](INFO): Initializing
2019-07-01T15:01:45.153Z,1561993305.153 [NAL9602](DEBUG): Fix Requested
2019-07-01T15:01:48.389Z,1561993308.389 [NAL9602](DEBUG): Fix Requested
2019-07-01T15:01:51.217Z,1561993311.217 [NAL9602](DEBUG): Fix Requested
2019-07-01T15:01:54.449Z,1561993314.449 [NAL9602](DEBUG): Fix Requested
2019-07-01T15:01:56.094Z,1561993316.094 [BPC1](INFO): Calculating totals. Valid battery stick count: 54. Valid reserve battery stick count: 6.
2019-07-01T15:01:56.097Z,1561993316.097 [BPC1](ERROR): Failed to receive data from all sticks prior to timeout. Will not retry this scan cycle.
2019-07-01T15:01:57.277Z,1561993317.277 [NAL9602](DEBUG): Fix Requested
2019-07-01T15:02:00.509Z,1561993320.509 [NAL9602](DEBUG): Fix Requested
2019-07-01T15:02:03.341Z,1561993323.341 [NAL9602](DEBUG): Fix Requested
2019-07-01T15:02:06.161Z,1561993326.161 [NAL9602](DEBUG): Fix Requested
2019-07-01T15:02:09.397Z,1561993329.397 [NAL9602](DEBUG): Fix Requested
2019-07-01T15:02:12.234Z,1561993332.234 [NAL9602](DEBUG): Fix Requested
2019-07-01T15:02:15.457Z,1561993335.457 [NAL9602](DEBUG): Fix Requested
2019-07-01T15:02:18.286Z,1561993338.286 [DVL_micro](ERROR): only read 45 of 46 data items
2019-07-01T15:02:18.286Z,1561993338.286 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 0 0 0 0 -497 -374 -409 -1281 2 2 2 2 -117.4 1210.5 -690.6 2 735.9 -968.2 -690.6 2 -117 1210 -690 68 -690 2 1.58 -2.05 211.7 -3.0 20.4 0.005 35.0 1489 93
2019-07-01T15:02:18.301Z,1561993338.301 [NAL9602](DEBUG): Fix Requested
2019-07-01T15:02:21.549Z,1561993341.549 [NAL9602](DEBUG): Fix Requested
2019-07-01T15:02:24.353Z,1561993344.353 [NAL9602](DEBUG): Fix Requested
2019-07-01T15:02:27.173Z,1561993347.173 [NAL9602](DEBUG): Fix Requested
2019-07-01T15:02:30.401Z,1561993350.401 [NAL9602](DEBUG): Fix Requested
2019-07-01T15:02:33.233Z,1561993353.233 [NAL9602](DEBUG): Fix Requested
2019-07-01T15:02:36.465Z,1561993356.465 [NAL9602](DEBUG): Fix Requested
2019-07-01T15:02:39.293Z,1561993359.293 [NAL9602](DEBUG): Fix Requested
2019-07-01T15:02:40.134Z,1561993360.134 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-07-01T14:57:40.0Z
2019-07-01T15:02:40.134Z,1561993360.134 [Default:CheckIn:Read_GPS] Stopped
2019-07-01T15:02:40.134Z,1561993360.134 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-07-01T15:02:48.609Z,1561993368.609 [DataOverHttps](INFO): Sending 187 bytes from file Logs/20190701T143043/Courier0013.lzma
2019-07-01T15:02:49.415Z,1561993369.415 [DataOverHttps](INFO): Moved sent file to Logs/20190701T143043/Courier0013.lzma.bak
2019-07-01T15:02:49.415Z,1561993369.415 [DataOverHttps](INFO): SBD MOMSN=11416323
2019-07-01T15:02:50.598Z,1561993370.598 [DVL_micro](ERROR): only read 43 of 46 data items
2019-07-01T15:02:50.598Z,1561993370.598 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 -298 -11 -333 -1268 2 2 2 2 46.7 1677.6 -515.0 2 841.7 -1451.8 -515.0 2 46 1677 -515 2 841 -1451 -515 2 1.52 -2.20 211.7 -3.0 20.4 0.005 35.0 1489 100
2019-07-01T15:03:06.105Z,1561993386.105 [DataOverHttps](INFO): Sending 188 bytes from file Logs/20190701T143043/Express0014.lzma
2019-07-01T15:03:06.911Z,1561993386.911 [DataOverHttps](INFO): Moved sent file to Logs/20190701T143043/Express0014.lzma.bak
2019-07-01T15:03:06.911Z,1561993386.911 [DataOverHttps](INFO): SBD MOMSN=11416325
2019-07-01T15:03:10.833Z,1561993390.833 [Default:CheckIn:Read_Iridium] Stopped
2019-07-01T15:03:10.834Z,1561993390.834 [Default:CheckIn:C.Wait] Running Loop=1
2019-07-01T15:03:10.834Z,1561993390.834 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-07-01T15:03:12.407Z,1561993392.407 [NAL9602](INFO): Powering down
2019-07-01T15:04:46.942Z,1561993486.942 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-07-01T15:04:46.942Z,1561993486.942 [DVL_micro] Data Fault, FailCount= 1
2019-07-01T15:04:46.942Z,1561993486.942 [DVL_micro](ERROR): Data Fault
2019-07-01T15:04:46.974Z,1561993486.974 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-07-01T15:04:47.423Z,1561993487.423 [DVL_micro](INFO): uninitialize:Powering down
2019-07-01T15:04:48.201Z,1561993488.201 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-07-01T15:04:48.201Z,1561993488.201 [DVL_micro] No Fault, FailCount= 1
2019-07-01T15:04:48.562Z,1561993488.562 [DVL_micro](INFO): Initializing
2019-07-01T15:06:57.846Z,1561993617.846 [DVL_micro](ERROR): only read 43 of 46 data items
2019-07-01T15:06:57.846Z,1561993617.846 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 -286 -331 -402 -1297 2 2 2 2 154. -624.5 2 545.7 -1178.2 -624.5 2 154 1289 -624 2 545 -1178 -624 2 1.49 -2.08 211.7 -3.0 20.5 0.005 35.0 1489 94
2019-07-01T15:07:52.786Z,1561993672.786 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-07-01T15:07:52.786Z,1561993672.786 [DVL_micro] Data Fault, FailCount= 1
2019-07-01T15:07:52.786Z,1561993672.786 [DVL_micro](ERROR): Data Fault
2019-07-01T15:07:52.847Z,1561993672.847 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-07-01T15:07:53.257Z,1561993673.257 [DVL_micro](INFO): uninitialize:Powering down
2019-07-01T15:07:54.030Z,1561993674.030 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-07-01T15:07:54.030Z,1561993674.030 [DVL_micro] No Fault, FailCount= 1
2019-07-01T15:07:54.408Z,1561993674.408 [DVL_micro](INFO): Initializing
2019-07-01T15:08:11.393Z,1561993691.393 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-07-01T15:08:11.394Z,1561993691.394 [Default:CheckIn:C.Wait] Stopped
2019-07-01T15:08:11.394Z,1561993691.394 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-07-01T15:08:11.394Z,1561993691.394 [Default:CheckIn:D] Running Loop=1
2019-07-01T15:08:11.805Z,1561993691.805 [Default:CheckIn:D] Stopped
2019-07-01T15:08:11.805Z,1561993691.805 [Default:CheckIn:E] Running Loop=1
2019-07-01T15:08:12.206Z,1561993692.206 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 33.888458 min 
2019-07-01T15:08:12.206Z,1561993692.206 [Default:CheckIn:E] Stopped
2019-07-01T15:08:12.206Z,1561993692.206 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-07-01T15:08:12.206Z,1561993692.206 [Default:CheckIn] Stopped
2019-07-01T15:08:12.206Z,1561993692.206 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-07-01T15:08:12.206Z,1561993692.206 [Default:CheckIn](INFO): Running loop #5
2019-07-01T15:08:12.207Z,1561993692.207 [Default:CheckIn] Running Loop=5
2019-07-01T15:08:12.207Z,1561993692.207 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-07-01T15:08:12.207Z,1561993692.207 [Default:CheckIn:Read_GPS] Running Loop=1
2019-07-01T15:08:12.982Z,1561993692.982 [NAL9602](INFO): Powering up
2019-07-01T15:08:23.892Z,1561993703.892 [NAL9602](INFO): NAL9602 initialized
2019-07-01T15:08:24.703Z,1561993704.703 [NAL9602](FAULT): GPS failed to acquire within timeout.
2019-07-01T15:08:24.703Z,1561993704.703 [NAL9602] Data Fault, FailCount= 1
2019-07-01T15:08:24.703Z,1561993704.703 [NAL9602](ERROR): Data Fault
2019-07-01T15:08:24.742Z,1561993704.742 [CBIT](ERROR): Data Fault in component: NAL9602
2019-07-01T15:08:25.109Z,1561993705.109 [NAL9602](INFO): Powering down
2019-07-01T15:08:25.958Z,1561993705.958 [CBIT](INFO): Clearing failed state for component NAL9602
2019-07-01T15:08:25.958Z,1561993705.958 [NAL9602] No Fault, FailCount= 1
2019-07-01T15:08:55.403Z,1561993735.403 [NAL9602](INFO): Powering up NAL9602
2019-07-01T15:09:06.315Z,1561993746.315 [NAL9602](INFO): NAL9602 initialized
2019-07-01T15:09:07.141Z,1561993747.141 [NAL9602](DEBUG): Fix Requested
2019-07-01T15:10:58.622Z,1561993858.622 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-07-01T15:10:58.622Z,1561993858.622 [DVL_micro] Data Fault, FailCount= 1
2019-07-01T15:10:58.622Z,1561993858.622 [DVL_micro](ERROR): Data Fault
2019-07-01T15:10:58.698Z,1561993858.698 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-07-01T15:10:59.097Z,1561993859.097 [DVL_micro](INFO): uninitialize:Powering down
2019-07-01T15:10:59.934Z,1561993859.934 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-07-01T15:10:59.934Z,1561993859.934 [DVL_micro] No Fault, FailCount= 1
2019-07-01T15:11:00.244Z,1561993860.244 [DVL_micro](INFO): Initializing
2019-07-01T15:13:12.375Z,1561993992.375 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-07-01T15:08:12.2Z
2019-07-01T15:13:12.375Z,1561993992.375 [Default:CheckIn:Read_GPS] Stopped
2019-07-01T15:13:12.375Z,1561993992.375 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-07-01T15:13:20.808Z,1561994000.808 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190701T143043/Courier0016.lzma
2019-07-01T15:13:21.614Z,1561994001.614 [DataOverHttps](INFO): Moved sent file to Logs/20190701T143043/Courier0016.lzma.bak
2019-07-01T15:13:21.615Z,1561994001.615 [DataOverHttps](INFO): SBD MOMSN=11416343
2019-07-01T15:13:38.053Z,1561994018.053 [DataOverHttps](INFO): Sending 221 bytes from file Logs/20190701T143043/Express0017.lzma
2019-07-01T15:13:38.859Z,1561994018.859 [DataOverHttps](INFO): Moved sent file to Logs/20190701T143043/Express0017.lzma.bak
2019-07-01T15:13:38.859Z,1561994018.859 [DataOverHttps](INFO): SBD MOMSN=11416345
2019-07-01T15:13:43.116Z,1561994023.116 [Default:CheckIn:Read_Iridium] Stopped
2019-07-01T15:13:43.116Z,1561994023.116 [Default:CheckIn:C.Wait] Running Loop=1
2019-07-01T15:13:43.116Z,1561994023.116 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-07-01T15:14:04.459Z,1561994044.459 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-07-01T15:14:04.459Z,1561994044.459 [DVL_micro] Data Fault, FailCount= 1
2019-07-01T15:14:04.459Z,1561994044.459 [DVL_micro](ERROR): Data Fault
2019-07-01T15:14:04.525Z,1561994044.525 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-07-01T15:14:04.945Z,1561994044.945 [DVL_micro](INFO): uninitialize:Powering down
2019-07-01T15:14:05.702Z,1561994045.702 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-07-01T15:14:05.702Z,1561994045.702 [DVL_micro] No Fault, FailCount= 1
2019-07-01T15:14:06.078Z,1561994046.078 [DVL_micro](INFO): Initializing
2019-07-01T15:14:09.310Z,1561994049.310 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-07-01T15:14:40.008Z,1561994080.008 [NAL9602](INFO): Powering down
2019-07-01T15:17:10.304Z,1561994230.304 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-07-01T15:17:10.304Z,1561994230.304 [DVL_micro] Data Fault, FailCount= 1
2019-07-01T15:17:10.304Z,1561994230.304 [DVL_micro](ERROR): Data Fault
2019-07-01T15:17:10.389Z,1561994230.389 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-07-01T15:17:10.769Z,1561994230.769 [DVL_micro](INFO): uninitialize:Powering down
2019-07-01T15:17:11.543Z,1561994231.543 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-07-01T15:17:11.543Z,1561994231.543 [DVL_micro] No Fault, FailCount= 1
2019-07-01T15:17:11.921Z,1561994231.921 [DVL_micro](INFO): Initializing
2019-07-01T15:18:43.644Z,1561994323.644 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-07-01T15:18:43.644Z,1561994323.644 [Default:CheckIn:C.Wait] Stopped
2019-07-01T15:18:43.644Z,1561994323.644 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-07-01T15:18:43.644Z,1561994323.644 [Default:CheckIn:D] Running Loop=1
2019-07-01T15:18:44.057Z,1561994324.057 [Default:CheckIn:D] Stopped
2019-07-01T15:18:44.057Z,1561994324.057 [Default:CheckIn:E] Running Loop=1
2019-07-01T15:18:44.454Z,1561994324.454 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 44.426005 min 
2019-07-01T15:18:44.455Z,1561994324.455 [Default:CheckIn:E] Stopped
2019-07-01T15:18:44.455Z,1561994324.455 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-07-01T15:18:44.455Z,1561994324.455 [Default:CheckIn] Stopped
2019-07-01T15:18:44.455Z,1561994324.455 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-07-01T15:18:44.455Z,1561994324.455 [Default:CheckIn](INFO): Running loop #6
2019-07-01T15:18:44.455Z,1561994324.455 [Default:CheckIn] Running Loop=6
2019-07-01T15:18:44.455Z,1561994324.455 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-07-01T15:18:44.455Z,1561994324.455 [Default:CheckIn:Read_GPS] Running Loop=1
2019-07-01T15:18:45.239Z,1561994325.239 [NAL9602](INFO): Powering up
2019-07-01T15:18:56.151Z,1561994336.151 [NAL9602](INFO): NAL9602 initialized
2019-07-01T15:18:56.969Z,1561994336.969 [NAL9602](DEBUG): Fix Requested
2019-07-01T15:19:28.065Z,1561994368.065 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2019-07-01T15:19:28.141Z,1561994368.141 [NAL9602](FAULT): received: 
+CSQ:0

OK4, 0, 0, 0, 0

OK
2019-07-01T15:19:28.142Z,1561994368.142 [NAL9602] Data Fault, FailCount= 2
2019-07-01T15:19:28.142Z,1561994368.142 [NAL9602](ERROR): Data Fault
2019-07-01T15:19:28.182Z,1561994368.182 [CBIT](ERROR): Data Fault in component: NAL9602
2019-07-01T15:19:28.467Z,1561994368.467 [NAL9602](INFO): Powering down
2019-07-01T15:19:29.305Z,1561994369.305 [CBIT](INFO): Clearing failed state for component NAL9602
2019-07-01T15:19:29.306Z,1561994369.306 [NAL9602] No Fault, FailCount= 2
2019-07-01T15:19:58.764Z,1561994398.764 [NAL9602](INFO): Powering up NAL9602
2019-07-01T15:20:09.696Z,1561994409.696 [NAL9602](INFO): NAL9602 initialized
2019-07-01T15:20:10.484Z,1561994410.484 [NAL9602](FAULT): GPS failed to acquire within timeout.
2019-07-01T15:20:10.484Z,1561994410.484 [NAL9602] Data Fault, FailCount= 3
2019-07-01T15:20:10.484Z,1561994410.484 [NAL9602](ERROR): Data Fault
2019-07-01T15:20:10.552Z,1561994410.552 [CBIT](ERROR): Data Fault in component: NAL9602
2019-07-01T15:20:10.884Z,1561994410.884 [NAL9602](INFO): Powering down
2019-07-01T15:20:11.726Z,1561994411.726 [CBIT](INFO): Clearing failed state for component NAL9602
2019-07-01T15:20:11.726Z,1561994411.726 [NAL9602] No Fault, FailCount= 3
2019-07-01T15:20:16.146Z,1561994416.146 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-07-01T15:20:16.146Z,1561994416.146 [DVL_micro] Data Fault, FailCount= 1
2019-07-01T15:20:16.146Z,1561994416.146 [DVL_micro](ERROR): Data Fault
2019-07-01T15:20:16.179Z,1561994416.179 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-07-01T15:20:16.613Z,1561994416.613 [DVL_micro](INFO): uninitialize:Powering down
2019-07-01T15:20:17.399Z,1561994417.399 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-07-01T15:20:17.399Z,1561994417.399 [DVL_micro] No Fault, FailCount= 1
2019-07-01T15:20:17.761Z,1561994417.761 [DVL_micro](INFO): Initializing
2019-07-01T15:20:41.184Z,1561994441.184 [NAL9602](INFO): Powering up NAL9602
2019-07-01T15:20:52.095Z,1561994452.095 [NAL9602](INFO): NAL9602 initialized
2019-07-01T15:20:52.917Z,1561994452.917 [NAL9602](DEBUG): Fix Requested
2019-07-01T15:23:21.979Z,1561994601.979 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-07-01T15:23:21.979Z,1561994601.979 [DVL_micro] Data Fault, FailCount= 1
2019-07-01T15:23:21.979Z,1561994601.979 [DVL_micro](ERROR): Data Fault
2019-07-01T15:23:22.030Z,1561994602.030 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-07-01T15:23:22.457Z,1561994602.457 [DVL_micro](INFO): uninitialize:Powering down
2019-07-01T15:23:23.246Z,1561994603.246 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-07-01T15:23:23.246Z,1561994603.246 [DVL_micro] No Fault, FailCount= 1
2019-07-01T15:23:23.601Z,1561994603.601 [DVL_micro](INFO): Initializing
2019-07-01T15:23:44.634Z,1561994624.634 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-07-01T15:18:44.5Z
2019-07-01T15:23:44.634Z,1561994624.634 [Default:CheckIn:Read_GPS] Stopped
2019-07-01T15:23:44.634Z,1561994624.634 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-07-01T15:23:53.272Z,1561994633.272 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190701T143043/Courier0019.lzma
2019-07-01T15:23:54.079Z,1561994634.079 [DataOverHttps](INFO): Moved sent file to Logs/20190701T143043/Courier0019.lzma.bak
2019-07-01T15:23:54.079Z,1561994634.079 [DataOverHttps](INFO): SBD MOMSN=11416362
2019-07-01T15:23:55.524Z,1561994635.524 [NAL9602](INFO): SBD MO Status=2, MOMSN=525, MT Status=2, MTMSN=0
2019-07-01T15:23:55.524Z,1561994635.524 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-01T15:23:59.183Z,1561994639.183 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-07-01T15:24:13.513Z,1561994653.513 [DataOverHttps](INFO): Sending 292 bytes from file Logs/20190701T143043/Express0020.lzma
2019-07-01T15:24:14.303Z,1561994654.303 [DataOverHttps](INFO): Moved sent file to Logs/20190701T143043/Express0020.lzma.bak
2019-07-01T15:24:14.303Z,1561994654.303 [DataOverHttps](INFO): SBD MOMSN=11416364
2019-07-01T15:24:18.190Z,1561994658.190 [Default:CheckIn:Read_Iridium] Stopped
2019-07-01T15:24:18.190Z,1561994658.190 [Default:CheckIn:C.Wait] Running Loop=1
2019-07-01T15:24:18.190Z,1561994658.190 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-07-01T15:24:29.863Z,1561994669.863 [NAL9602](INFO): Powering down
2019-07-01T15:26:27.828Z,1561994787.828 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-07-01T15:26:27.828Z,1561994787.828 [DVL_micro] Data Fault, FailCount= 1
2019-07-01T15:26:27.828Z,1561994787.828 [DVL_micro](ERROR): Data Fault
2019-07-01T15:26:27.902Z,1561994787.902 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-07-01T15:26:28.297Z,1561994788.297 [DVL_micro](INFO): uninitialize:Powering down
2019-07-01T15:26:29.082Z,1561994789.082 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-07-01T15:26:29.082Z,1561994789.082 [DVL_micro] No Fault, FailCount= 1
2019-07-01T15:26:29.456Z,1561994789.456 [DVL_micro](INFO): Initializing
2019-07-01T15:29:18.760Z,1561994958.760 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-07-01T15:29:18.760Z,1561994958.760 [Default:CheckIn:C.Wait] Stopped
2019-07-01T15:29:18.760Z,1561994958.760 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-07-01T15:29:18.760Z,1561994958.760 [Default:CheckIn:D] Running Loop=1
2019-07-01T15:29:19.167Z,1561994959.167 [Default:CheckIn:D] Stopped
2019-07-01T15:29:19.167Z,1561994959.167 [Default:CheckIn:E] Running Loop=1
2019-07-01T15:29:19.562Z,1561994959.562 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 55.011157 min 
2019-07-01T15:29:19.562Z,1561994959.562 [Default:CheckIn:E] Stopped
2019-07-01T15:29:19.562Z,1561994959.562 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-07-01T15:29:19.562Z,1561994959.562 [Default:CheckIn] Stopped
2019-07-01T15:29:19.562Z,1561994959.562 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-07-01T15:29:19.562Z,1561994959.562 [Default:CheckIn](INFO): Running loop #7
2019-07-01T15:29:19.562Z,1561994959.562 [Default:CheckIn] Running Loop=7
2019-07-01T15:29:19.562Z,1561994959.562 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-07-01T15:29:19.563Z,1561994959.563 [Default:CheckIn:Read_GPS] Running Loop=1
2019-07-01T15:29:20.339Z,1561994960.339 [NAL9602](INFO): Powering up
2019-07-01T15:29:31.255Z,1561994971.255 [NAL9602](INFO): NAL9602 initialized
2019-07-01T15:29:32.069Z,1561994972.069 [NAL9602](DEBUG): Fix Requested
2019-07-01T15:29:33.671Z,1561994973.671 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-07-01T15:29:33.671Z,1561994973.671 [DVL_micro] Data Fault, FailCount= 1
2019-07-01T15:29:33.671Z,1561994973.671 [DVL_micro](ERROR): Data Fault
2019-07-01T15:29:33.710Z,1561994973.710 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-07-01T15:29:34.145Z,1561994974.145 [DVL_micro](INFO): uninitialize:Powering down
2019-07-01T15:29:34.927Z,1561994974.927 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-07-01T15:29:34.927Z,1561994974.927 [DVL_micro] No Fault, FailCount= 1
2019-07-01T15:29:35.292Z,1561994975.292 [DVL_micro](INFO): Initializing
2019-07-01T15:30:03.167Z,1561995003.167 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2019-07-01T15:30:03.241Z,1561995003.241 [NAL9602](FAULT): received: 
+SBDI: 2, 525, 2, 0, 0, 0

OK
2019-07-01T15:30:03.241Z,1561995003.241 [NAL9602] Data Fault, FailCount= 4
2019-07-01T15:30:03.241Z,1561995003.241 [NAL9602](ERROR): Data Fault
2019-07-01T15:30:03.278Z,1561995003.278 [CBIT](ERROR): Data Fault in component: NAL9602
2019-07-01T15:30:03.567Z,1561995003.567 [NAL9602](INFO): Powering down
2019-07-01T15:30:04.434Z,1561995004.434 [CBIT](INFO): Clearing failed state for component NAL9602
2019-07-01T15:30:04.434Z,1561995004.434 [NAL9602] No Fault, FailCount= 4
2019-07-01T15:30:33.868Z,1561995033.868 [NAL9602](INFO): Powering up NAL9602
2019-07-01T15:30:44.791Z,1561995044.791 [NAL9602](INFO): NAL9602 initialized
2019-07-01T15:30:45.601Z,1561995045.601 [NAL9602](DEBUG): Fix Requested
2019-07-01T15:32:39.542Z,1561995159.542 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-07-01T15:32:39.542Z,1561995159.542 [DVL_micro] Data Fault, FailCount= 1
2019-07-01T15:32:39.542Z,1561995159.542 [DVL_micro](ERROR): Data Fault
2019-07-01T15:32:39.606Z,1561995159.606 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-07-01T15:32:40.017Z,1561995160.017 [DVL_micro](INFO): uninitialize:Powering down
2019-07-01T15:32:40.804Z,1561995160.804 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-07-01T15:32:40.804Z,1561995160.804 [DVL_micro] No Fault, FailCount= 1
2019-07-01T15:32:41.162Z,1561995161.162 [DVL_micro](INFO): Initializing
2019-07-01T15:34:19.770Z,1561995259.770 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-07-01T15:29:19.6Z
2019-07-01T15:34:19.770Z,1561995259.770 [Default:CheckIn:Read_GPS] Stopped
2019-07-01T15:34:19.771Z,1561995259.771 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-07-01T15:34:26.828Z,1561995266.828 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190701T143043/Courier0022.lzma
2019-07-01T15:34:27.634Z,1561995267.634 [DataOverHttps](INFO): Moved sent file to Logs/20190701T143043/Courier0022.lzma.bak
2019-07-01T15:34:27.635Z,1561995267.635 [DataOverHttps](INFO): SBD MOMSN=11416382
2019-07-01T15:34:33.872Z,1561995273.872 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-07-01T15:34:46.481Z,1561995286.481 [DataOverHttps](INFO): Sending 276 bytes from file Logs/20190701T143043/Express0023.lzma
2019-07-01T15:34:47.287Z,1561995287.287 [DataOverHttps](INFO): Moved sent file to Logs/20190701T143043/Express0023.lzma.bak
2019-07-01T15:34:47.287Z,1561995287.287 [DataOverHttps](INFO): SBD MOMSN=11416384
2019-07-01T15:34:51.308Z,1561995291.308 [Default:CheckIn:Read_Iridium] Stopped
2019-07-01T15:34:51.308Z,1561995291.308 [Default:CheckIn:C.Wait] Running Loop=1
2019-07-01T15:34:51.309Z,1561995291.309 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-07-01T15:35:04.579Z,1561995304.579 [NAL9602](INFO): Powering down
2019-07-01T15:35:45.382Z,1561995345.382 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-07-01T15:35:45.382Z,1561995345.382 [DVL_micro] Data Fault, FailCount= 1
2019-07-01T15:35:45.382Z,1561995345.382 [DVL_micro](ERROR): Data Fault
2019-07-01T15:35:45.415Z,1561995345.415 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-07-01T15:35:45.861Z,1561995345.861 [DVL_micro](INFO): uninitialize:Powering down
2019-07-01T15:35:46.640Z,1561995346.640 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-07-01T15:35:46.640Z,1561995346.640 [DVL_micro] No Fault, FailCount= 1
2019-07-01T15:35:47.005Z,1561995347.005 [DVL_micro](INFO): Initializing
2019-07-01T15:38:51.223Z,1561995531.223 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-07-01T15:38:51.223Z,1561995531.223 [DVL_micro] Data Fault, FailCount= 1
2019-07-01T15:38:51.223Z,1561995531.223 [DVL_micro](ERROR): Data Fault
2019-07-01T15:38:51.262Z,1561995531.262 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-07-01T15:38:51.697Z,1561995531.697 [DVL_micro](INFO): uninitialize:Powering down
2019-07-01T15:38:52.474Z,1561995532.474 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-07-01T15:38:52.474Z,1561995532.474 [DVL_micro] No Fault, FailCount= 1
2019-07-01T15:38:52.845Z,1561995532.845 [DVL_micro](INFO): Initializing
2019-07-01T15:39:51.853Z,1561995591.853 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-07-01T15:39:51.853Z,1561995591.853 [Default:CheckIn:C.Wait] Stopped
2019-07-01T15:39:51.853Z,1561995591.853 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-07-01T15:39:51.853Z,1561995591.853 [Default:CheckIn:D] Running Loop=1
2019-07-01T15:39:52.257Z,1561995592.257 [Default:CheckIn:D] Stopped
2019-07-01T15:39:52.257Z,1561995592.257 [Default:CheckIn:E] Running Loop=1
2019-07-01T15:39:52.652Z,1561995592.652 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 65.562667 min 
2019-07-01T15:39:52.652Z,1561995592.652 [Default:CheckIn:E] Stopped
2019-07-01T15:39:52.652Z,1561995592.652 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-07-01T15:39:52.652Z,1561995592.652 [Default:CheckIn] Stopped
2019-07-01T15:39:52.652Z,1561995592.652 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-07-01T15:39:52.653Z,1561995592.653 [Default:CheckIn](INFO): Running loop #8
2019-07-01T15:39:52.653Z,1561995592.653 [Default:CheckIn] Running Loop=8
2019-07-01T15:39:52.653Z,1561995592.653 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-07-01T15:39:52.653Z,1561995592.653 [Default:CheckIn:Read_GPS] Running Loop=1
2019-07-01T15:39:53.440Z,1561995593.440 [NAL9602](INFO): Powering up
2019-07-01T15:40:04.352Z,1561995604.352 [NAL9602](INFO): NAL9602 initialized
2019-07-01T15:40:05.155Z,1561995605.155 [NAL9602](FAULT): GPS failed to acquire within timeout.
2019-07-01T15:40:05.155Z,1561995605.155 [NAL9602] Data Fault, FailCount= 5
2019-07-01T15:40:05.155Z,1561995605.155 [NAL9602](ERROR): Data Fault
2019-07-01T15:40:05.218Z,1561995605.218 [CBIT](ERROR): Data Fault in component: NAL9602
2019-07-01T15:40:05.219Z,1561995605.219 [CBIT](CRITICAL): Data Fault in component: NAL9602
2019-07-01T15:40:05.560Z,1561995605.560 [NAL9602](INFO): Powering down
2019-07-01T15:40:05.589Z,1561995605.589 [CBIT](INFO): Critical error at 20190701T154005
2019-07-01T15:41:57.063Z,1561995717.063 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-07-01T15:41:57.063Z,1561995717.063 [DVL_micro] Data Fault, FailCount= 1
2019-07-01T15:41:57.063Z,1561995717.063 [DVL_micro](ERROR): Data Fault
2019-07-01T15:41:57.138Z,1561995717.138 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-07-01T15:41:57.533Z,1561995717.533 [DVL_micro](INFO): uninitialize:Powering down
2019-07-01T15:41:58.380Z,1561995718.380 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-07-01T15:41:58.380Z,1561995718.380 [DVL_micro] No Fault, FailCount= 1
2019-07-01T15:41:58.698Z,1561995718.698 [DVL_micro](INFO): Initializing
2019-07-01T15:42:05.324Z,1561995725.324 [CBIT](INFO): Clearing failed state for component NAL9602
2019-07-01T15:42:05.324Z,1561995725.324 [NAL9602] No Fault, FailCount= 5
2019-07-01T15:42:05.553Z,1561995725.553 [NAL9602](INFO): Powering up NAL9602
2019-07-01T15:42:16.467Z,1561995736.467 [NAL9602](INFO): NAL9602 initialized
2019-07-01T15:42:17.285Z,1561995737.285 [NAL9602](DEBUG): Fix Requested
2019-07-01T15:42:31.017Z,1561995751.017 [DVL_micro](ERROR): only read 13 of 46 data items
2019-07-01T15:42:31.017Z,1561995751.017 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 0 0 0 0 --225 -134 2 2 2 2 192.