2020-12-03T21:23:47.854Z,1607030627.854 [Supervisor](DEBUG): Initializing supervisor.
2020-12-03T21:23:47.857Z,1607030627.857 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2020-12-03T21:23:47.858Z,1607030627.858 [SyncHandler](INFO): Protected caller Thread ID is 5376
2020-12-03T21:23:47.858Z,1607030627.858 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2020-12-03T21:23:47.859Z,1607030627.859 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2020-12-03T21:23:47.859Z,1607030627.859 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 5377
2020-12-03T21:23:47.863Z,1607030627.863 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2020-12-03T21:23:47.881Z,1607030627.881 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2020-12-03T21:23:47.882Z,1607030627.882 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2020-12-03T21:23:47.882Z,1607030627.882 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 5378
2020-12-03T21:23:47.883Z,1607030627.883 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2020-12-03T21:23:47.884Z,1607030627.884 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2020-12-03T21:23:47.885Z,1607030627.885 [logger ThreadHandler](INFO): Protected caller Thread ID is 5379
2020-12-03T21:23:47.887Z,1607030627.887 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2020-12-03T21:23:47.887Z,1607030627.887 [Supervisor](INFO): Looking for Config files in directory: Config/
2020-12-03T21:23:47.889Z,1607030627.889 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2020-12-03T21:23:48.403Z,1607030628.403 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2020-12-03T21:23:48.404Z,1607030628.404 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2020-12-03T21:23:48.553Z,1607030628.553 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2020-12-03T21:23:48.553Z,1607030628.553 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2020-12-03T21:23:48.641Z,1607030628.641 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2020-12-03T21:23:48.863Z,1607030628.863 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2020-12-03T21:23:48.864Z,1607030628.864 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2020-12-03T21:23:48.962Z,1607030628.962 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2020-12-03T21:23:48.963Z,1607030628.963 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2020-12-03T21:23:49.057Z,1607030629.057 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2020-12-03T21:23:49.058Z,1607030629.058 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2020-12-03T21:23:49.458Z,1607030629.458 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2020-12-03T21:23:49.459Z,1607030629.459 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2020-12-03T21:23:49.564Z,1607030629.564 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2020-12-03T21:23:49.565Z,1607030629.565 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2020-12-03T21:23:50.083Z,1607030630.083 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2020-12-03T21:23:50.084Z,1607030630.084 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2020-12-03T21:23:50.280Z,1607030630.280 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2020-12-03T21:23:50.281Z,1607030630.281 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2020-12-03T21:23:50.591Z,1607030630.591 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2020-12-03T21:23:50.591Z,1607030630.591 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2020-12-03T21:23:50.811Z,1607030630.811 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2020-12-03T21:23:50.812Z,1607030630.812 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2020-12-03T21:23:50.955Z,1607030630.955 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2020-12-03T21:23:50.956Z,1607030630.956 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2020-12-03T21:23:51.641Z,1607030631.641 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2020-12-03T21:23:51.641Z,1607030631.641 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2020-12-03T21:23:51.980Z,1607030631.980 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2020-12-03T21:23:51.981Z,1607030631.981 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2020-12-03T21:23:52.190Z,1607030632.190 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2020-12-03T21:23:52.192Z,1607030632.192 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-triton/
2020-12-03T21:23:52.193Z,1607030632.193 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/vehicle.cfg
2020-12-03T21:23:52.389Z,1607030632.389 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/secure.cfg
2020-12-03T21:23:52.471Z,1607030632.471 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Science.cfg
2020-12-03T21:23:52.624Z,1607030632.624 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Simulator.cfg
2020-12-03T21:23:52.709Z,1607030632.709 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Battery.cfg
2020-12-03T21:23:52.964Z,1607030632.964 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2020-12-03T21:23:52.965Z,1607030632.965 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/logger.cfg
2020-12-03T21:23:53.070Z,1607030633.070 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Servo.cfg
2020-12-03T21:23:53.179Z,1607030633.179 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Navigation.cfg
2020-12-03T21:23:53.272Z,1607030633.272 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Sensor.cfg
2020-12-03T21:23:53.420Z,1607030633.420 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Control.cfg
2020-12-03T21:23:53.518Z,1607030633.518 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/BIT.cfg
2020-12-03T21:23:53.650Z,1607030633.650 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-triton/root/
2020-12-03T21:23:53.651Z,1607030633.651 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2020-12-03T21:23:53.775Z,1607030633.775 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2020-12-03T21:23:53.817Z,1607030633.817 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2020-12-03T21:23:53.817Z,1607030633.817 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2020-12-03T21:23:53.912Z,1607030633.912 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2020-12-03T21:23:53.913Z,1607030633.913 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2020-12-03T21:23:53.986Z,1607030633.986 [VerticalControl](DEBUG): Construct VerticalControl.
2020-12-03T21:23:54.131Z,1607030634.131 [VerticalControl] Loaded
2020-12-03T21:23:54.131Z,1607030634.131 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2020-12-03T21:23:54.132Z,1607030634.132 [HorizontalControl](DEBUG): Construct HorizontalControl.
2020-12-03T21:23:54.170Z,1607030634.170 [HorizontalControl] Loaded
2020-12-03T21:23:54.170Z,1607030634.170 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2020-12-03T21:23:54.171Z,1607030634.171 [SpeedControl](DEBUG): Construct SpeedControl.
2020-12-03T21:23:54.174Z,1607030634.174 [SpeedControl] Loaded
2020-12-03T21:23:54.175Z,1607030634.175 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2020-12-03T21:23:54.175Z,1607030634.175 [LoopControl](DEBUG): Construct LoopControl.
2020-12-03T21:23:54.176Z,1607030634.176 [LoopControl] Loaded
2020-12-03T21:23:54.176Z,1607030634.176 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2020-12-03T21:23:54.176Z,1607030634.176 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2020-12-03T21:23:54.177Z,1607030634.177 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2020-12-03T21:23:54.372Z,1607030634.372 [BuoyancyServo] Loaded
2020-12-03T21:23:54.372Z,1607030634.372 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2020-12-03T21:23:54.433Z,1607030634.433 [ElevatorServo] Loaded
2020-12-03T21:23:54.433Z,1607030634.433 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2020-12-03T21:23:54.533Z,1607030634.533 [MassServo] Loaded
2020-12-03T21:23:54.534Z,1607030634.534 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2020-12-03T21:23:54.572Z,1607030634.572 [RudderServo] Loaded
2020-12-03T21:23:54.573Z,1607030634.573 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2020-12-03T21:23:54.588Z,1607030634.588 [ThrusterServo] Loaded
2020-12-03T21:23:54.588Z,1607030634.588 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2020-12-03T21:23:54.589Z,1607030634.589 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2020-12-03T21:23:54.589Z,1607030634.589 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2020-12-03T21:23:54.627Z,1607030634.627 [DepthRateCalculator] Loaded
2020-12-03T21:23:54.627Z,1607030634.627 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2020-12-03T21:23:54.630Z,1607030634.630 [PitchRateCalculator] Loaded
2020-12-03T21:23:54.630Z,1607030634.630 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2020-12-03T21:23:54.638Z,1607030634.638 [SpeedCalculator] Loaded
2020-12-03T21:23:54.638Z,1607030634.638 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2020-12-03T21:23:54.650Z,1607030634.650 [TempGradientCalculator] Loaded
2020-12-03T21:23:54.650Z,1607030634.650 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2020-12-03T21:23:54.652Z,1607030634.652 [YawRateCalculator] Loaded
2020-12-03T21:23:54.653Z,1607030634.653 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2020-12-03T21:23:54.668Z,1607030634.668 [ElevatorOffsetCalculator] Loaded
2020-12-03T21:23:54.668Z,1607030634.668 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2020-12-03T21:23:54.669Z,1607030634.669 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2020-12-03T21:23:54.669Z,1607030634.669 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2020-12-03T21:23:54.748Z,1607030634.748 [DeadReckonUsingMultipleVelocitySources] Loaded
2020-12-03T21:23:54.749Z,1607030634.749 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2020-12-03T21:23:54.760Z,1607030634.760 [NavChart] Loaded
2020-12-03T21:23:54.760Z,1607030634.760 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2020-12-03T21:23:54.764Z,1607030634.764 [UniversalFixResidualReporter] Loaded
2020-12-03T21:23:54.764Z,1607030634.764 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2020-12-03T21:23:54.765Z,1607030634.765 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2020-12-03T21:23:54.765Z,1607030634.765 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2020-12-03T21:23:55.066Z,1607030635.066 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_orientation
2020-12-03T21:23:55.069Z,1607030635.069 [AHRS_M2](INFO): created writer for : platform_orientation
2020-12-03T21:23:55.070Z,1607030635.070 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_magnetic_orientation
2020-12-03T21:23:55.073Z,1607030635.073 [AHRS_M2](INFO): created writer for : platform_magnetic_orientation
2020-12-03T21:23:55.074Z,1607030635.074 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_pitch_angle
2020-12-03T21:23:55.077Z,1607030635.077 [AHRS_M2](INFO): created writer for : platform_pitch_angle
2020-12-03T21:23:55.077Z,1607030635.077 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_roll_angle
2020-12-03T21:23:55.080Z,1607030635.080 [AHRS_M2](INFO): created writer for : platform_roll_angle
2020-12-03T21:23:55.118Z,1607030635.118 [AHRS_M2] Loaded
2020-12-03T21:23:55.118Z,1607030635.118 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2020-12-03T21:23:55.190Z,1607030635.190 [DataOverHttps] Loaded
2020-12-03T21:23:55.190Z,1607030635.190 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2020-12-03T21:23:55.191Z,1607030635.191 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 408514E0
2020-12-03T21:23:55.192Z,1607030635.192 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 5461
2020-12-03T21:23:55.209Z,1607030635.209 [Depth_Keller] Loaded
2020-12-03T21:23:55.209Z,1607030635.209 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2020-12-03T21:23:55.266Z,1607030635.266 [NAL9602] Loaded
2020-12-03T21:23:55.266Z,1607030635.266 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2020-12-03T21:23:55.293Z,1607030635.293 [Onboard] Loaded
2020-12-03T21:23:55.293Z,1607030635.293 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2020-12-03T21:23:55.294Z,1607030635.294 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 408814E0
2020-12-03T21:23:55.294Z,1607030635.294 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 5462
2020-12-03T21:23:55.305Z,1607030635.305 [Radio_Surface] Loaded
2020-12-03T21:23:55.305Z,1607030635.305 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2020-12-03T21:23:55.306Z,1607030635.306 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408B14E0
2020-12-03T21:23:55.307Z,1607030635.307 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 5463
2020-12-03T21:23:55.383Z,1607030635.383 [DAT] Loaded
2020-12-03T21:23:55.384Z,1607030635.384 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread.
2020-12-03T21:23:56.181Z,1607030636.181 [BPC1] Loaded
2020-12-03T21:23:56.181Z,1607030636.181 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2020-12-03T21:23:56.182Z,1607030636.182 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2020-12-03T21:23:56.182Z,1607030636.182 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2020-12-03T21:23:56.271Z,1607030636.271 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2020-12-03T21:23:56.272Z,1607030636.272 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2020-12-03T21:23:56.369Z,1607030636.369 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2020-12-03T21:23:56.370Z,1607030636.370 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2020-12-03T21:23:56.397Z,1607030636.397 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2020-12-03T21:23:56.397Z,1607030636.397 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2020-12-03T21:23:56.598Z,1607030636.598 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_density
2020-12-03T21:23:56.600Z,1607030636.600 [CTD_Seabird](INFO): created writer for : sea_water_density
2020-12-03T21:23:56.601Z,1607030636.601 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): depth
2020-12-03T21:23:56.603Z,1607030636.603 [CTD_Seabird](INFO): created writer for : depth
2020-12-03T21:23:56.604Z,1607030636.604 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_pressure
2020-12-03T21:23:56.607Z,1607030636.607 [CTD_Seabird](INFO): created writer for : sea_water_pressure
2020-12-03T21:23:56.607Z,1607030636.607 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_salinity
2020-12-03T21:23:56.610Z,1607030636.610 [CTD_Seabird](INFO): created writer for : sea_water_salinity
2020-12-03T21:23:56.611Z,1607030636.611 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_temperature
2020-12-03T21:23:56.614Z,1607030636.614 [CTD_Seabird](INFO): created writer for : sea_water_temperature
2020-12-03T21:23:56.614Z,1607030636.614 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_electrical_conductivity
2020-12-03T21:23:56.618Z,1607030636.618 [CTD_Seabird](INFO): created writer for : sea_water_electrical_conductivity
2020-12-03T21:23:56.618Z,1607030636.618 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): speed_of_sound_in_sea_water
2020-12-03T21:23:56.621Z,1607030636.621 [CTD_Seabird](INFO): created writer for : speed_of_sound_in_sea_water
2020-12-03T21:23:56.634Z,1607030636.634 [CTD_Seabird] Loaded
2020-12-03T21:23:56.635Z,1607030636.635 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2020-12-03T21:23:56.636Z,1607030636.636 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40A594E0
2020-12-03T21:23:56.636Z,1607030636.636 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 5464
2020-12-03T21:23:56.666Z,1607030636.666 [ESPComponent] Loaded
2020-12-03T21:23:56.666Z,1607030636.666 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2020-12-03T21:23:56.683Z,1607030636.683 [PAR_Licor] Loaded
2020-12-03T21:23:56.683Z,1607030636.683 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2020-12-03T21:23:56.696Z,1607030636.696 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.Output470
2020-12-03T21:23:56.696Z,1607030636.696 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: Output470
2020-12-03T21:23:56.698Z,1607030636.698 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.Output650
2020-12-03T21:23:56.698Z,1607030636.698 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: Output650
2020-12-03T21:23:56.700Z,1607030636.700 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.OutputChl
2020-12-03T21:23:56.701Z,1607030636.701 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: OutputChl
2020-12-03T21:23:56.703Z,1607030636.703 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.VolumeScatCoeff117deg470nm
2020-12-03T21:23:56.703Z,1607030636.703 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: VolumeScatCoeff117deg470nm
2020-12-03T21:23:56.705Z,1607030636.705 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.VolumeScatCoeff117deg650nm
2020-12-03T21:23:56.705Z,1607030636.705 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: VolumeScatCoeff117deg650nm
2020-12-03T21:23:56.707Z,1607030636.707 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.BackscatteringCoeff470nm
2020-12-03T21:23:56.707Z,1607030636.707 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: BackscatteringCoeff470nm
2020-12-03T21:23:56.709Z,1607030636.709 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.BackscatteringCoeff650nm
2020-12-03T21:23:56.710Z,1607030636.710 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: BackscatteringCoeff650nm
2020-12-03T21:23:56.711Z,1607030636.711 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): mass_concentration_of_chlorophyll_in_sea_water
2020-12-03T21:23:56.714Z,1607030636.714 [WetLabsBB2FL](INFO): created writer for : mass_concentration_of_chlorophyll_in_sea_water
2020-12-03T21:23:56.714Z,1607030636.714 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_median_mass_concentration_of_chlorophyll_in_sea_water
2020-12-03T21:23:56.715Z,1607030636.715 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_median_mass_concentration_of_chlorophyll_in_sea_water
2020-12-03T21:23:56.717Z,1607030636.717 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water
2020-12-03T21:23:56.717Z,1607030636.717 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_mean_mass_concentration_of_chlorophyll_in_sea_water
2020-12-03T21:23:56.719Z,1607030636.719 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_variance_mass_concentration_of_chlorophyll_in_sea_water
2020-12-03T21:23:56.719Z,1607030636.719 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_variance_mass_concentration_of_chlorophyll_in_sea_water
2020-12-03T21:23:56.721Z,1607030636.721 [WetLabsBB2FL] Loaded
2020-12-03T21:23:56.721Z,1607030636.721 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2020-12-03T21:23:56.723Z,1607030636.723 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40A894E0
2020-12-03T21:23:56.723Z,1607030636.723 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 5465
2020-12-03T21:23:56.724Z,1607030636.724 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2020-12-03T21:23:56.724Z,1607030636.724 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2020-12-03T21:23:57.017Z,1607030637.017 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2020-12-03T21:23:57.018Z,1607030637.018 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2020-12-03T21:23:57.154Z,1607030637.154 [SBIT](DEBUG): Construct Startup Built In Test.
2020-12-03T21:23:57.162Z,1607030637.162 [SBIT] Loaded
2020-12-03T21:23:57.163Z,1607030637.163 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2020-12-03T21:23:57.163Z,1607030637.163 [IBIT](DEBUG): Construct Initiated Built In Test.
2020-12-03T21:23:57.176Z,1607030637.176 [IBIT] Loaded
2020-12-03T21:23:57.176Z,1607030637.176 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2020-12-03T21:23:57.179Z,1607030637.179 [CBIT](DEBUG): Construct Continuous Built In Test.
2020-12-03T21:23:57.279Z,1607030637.279 [CBIT] Loaded
2020-12-03T21:23:57.279Z,1607030637.279 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2020-12-03T21:23:57.279Z,1607030637.279 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2020-12-03T21:23:57.284Z,1607030637.284 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2020-12-03T21:23:57.285Z,1607030637.285 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2020-12-03T21:23:57.293Z,1607030637.293 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2020-12-03T21:23:57.294Z,1607030637.294 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B674E0
2020-12-03T21:23:57.295Z,1607030637.295 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 5466
2020-12-03T21:23:57.299Z,1607030637.299 [Supervisor](INFO): Main Thread ID is 4582
2020-12-03T21:23:57.299Z,1607030637.299 [Supervisor](DEBUG): Running supervisor.
2020-12-03T21:23:57.300Z,1607030637.300 [CommandLine ThreadHandler](INFO): Handler Thread ID is 5467
2020-12-03T21:23:57.302Z,1607030637.302 [controlThread ThreadHandler](INFO): Handler Thread ID is 5468
2020-12-03T21:23:57.303Z,1607030637.303 [controlThread](DEBUG): Initializing ControlThread
2020-12-03T21:23:57.303Z,1607030637.303 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2020-12-03T21:23:57.305Z,1607030637.305 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2020-12-03T21:23:57.306Z,1607030637.306 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2020-12-03T21:23:57.306Z,1607030637.306 [LoopControl](DEBUG): Initialize LoopControlComponent.
2020-12-03T21:23:57.308Z,1607030637.308 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2020-12-03T21:23:57.308Z,1607030637.308 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2020-12-03T21:23:57.309Z,1607030637.309 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2020-12-03T21:23:57.309Z,1607030637.309 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2020-12-03T21:23:57.310Z,1607030637.310 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2020-12-03T21:23:57.310Z,1607030637.310 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2020-12-03T21:23:57.311Z,1607030637.311 [NavChart](DEBUG): Initialize NavChart Navigation.
2020-12-03T21:23:57.311Z,1607030637.311 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2020-12-03T21:23:57.317Z,1607030637.317 [SBIT](INFO): Initialize SBIT Component.
2020-12-03T21:23:57.317Z,1607030637.317 [SBIT](IMPORTANT): git: 2020-11-24-6-gcb638d650
2020-12-03T21:23:57.318Z,1607030637.318 [SBIT](INFO): git hash: cb638d650ac65501896d406bf5988c2fe747cbc6
2020-12-03T21:23:57.318Z,1607030637.318 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2020-12-03T21:23:57.319Z,1607030637.319 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #1 PREEMPT Tue Dec 18 21:19:28 PST 2018
Kernel Reported: #1 PREEMPT Tue May 26 08:17:09 PDT 2020
2020-12-03T21:23:57.320Z,1607030637.320 [SBIT](INFO): Beginning SBIT in 34.000000 seconds.
2020-12-03T21:23:57.321Z,1607030637.321 [IBIT](INFO): Initialize IBIT Component.
2020-12-03T21:23:57.322Z,1607030637.322 [CBIT](DEBUG): Initialize CBIT Component.
2020-12-03T21:23:57.322Z,1607030637.322 [logger ThreadHandler](INFO): Handler Thread ID is 5469
2020-12-03T21:23:57.333Z,1607030637.333 [CBIT](DEBUG): Initialized mux pins.
2020-12-03T21:23:57.333Z,1607030637.333 [CBIT](DEBUG): Initializing the watchdog timer.
2020-12-03T21:23:57.341Z,1607030637.341 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 5470
2020-12-03T21:23:57.342Z,1607030637.342 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2020-12-03T21:23:57.353Z,1607030637.353 [Onboard ThreadHandler](INFO): Handler Thread ID is 5471
2020-12-03T21:23:57.357Z,1607030637.357 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2020-12-03T21:23:57.357Z,1607030637.357 [CBIT](DEBUG): Initializing heartbeat.
2020-12-03T21:23:57.382Z,1607030637.382 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 5472
2020-12-03T21:23:57.389Z,1607030637.389 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 5473
2020-12-03T21:23:57.390Z,1607030637.390 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2020-12-03T21:23:57.394Z,1607030637.394 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 5475
2020-12-03T21:23:57.395Z,1607030637.395 [WetLabsBB2FL](INFO): Powering down
2020-12-03T21:23:57.417Z,1607030637.417 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 5476
2020-12-03T21:23:57.423Z,1607030637.423 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2020-12-03T21:23:57.423Z,1607030637.423 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2020-12-03T21:23:57.423Z,1607030637.423 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2020-12-03T21:23:57.423Z,1607030637.423 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2020-12-03T21:23:57.423Z,1607030637.423 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2020-12-03T21:23:57.424Z,1607030637.424 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2020-12-03T21:23:57.424Z,1607030637.424 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2020-12-03T21:23:57.424Z,1607030637.424 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2020-12-03T21:23:57.424Z,1607030637.424 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2020-12-03T21:23:57.424Z,1607030637.424 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2020-12-03T21:23:57.424Z,1607030637.424 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2020-12-03T21:23:57.425Z,1607030637.425 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2020-12-03T21:23:57.425Z,1607030637.425 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2020-12-03T21:23:57.425Z,1607030637.425 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2020-12-03T21:23:57.425Z,1607030637.425 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2020-12-03T21:23:57.425Z,1607030637.425 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2020-12-03T21:23:57.429Z,1607030637.429 [CBIT](DEBUG): Deactivating GF circuits.
2020-12-03T21:23:57.429Z,1607030637.429 [CBIT](DEBUG): Deactivating emergency mode.
2020-12-03T21:23:57.465Z,1607030637.465 [CBIT](DEBUG): Backplane powered.
2020-12-03T21:23:57.466Z,1607030637.466 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2020-12-03T21:23:57.475Z,1607030637.475 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2020-12-03T21:23:57.486Z,1607030637.486 [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>


2020-12-03T21:23:57.486Z,1607030637.486 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2020-12-03T21:23:57.553Z,1607030637.553 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2020-12-03T21:23:57.554Z,1607030637.554 [Default:A.Wait](DEBUG): Construct Wait.
2020-12-03T21:23:57.556Z,1607030637.556 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2020-12-03T21:23:57.598Z,1607030637.598 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2020-12-03T21:23:57.617Z,1607030637.617 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2020-12-03T21:23:57.624Z,1607030637.624 [Default:E.Execute](DEBUG): Construct Execute.
2020-12-03T21:23:57.627Z,1607030637.627 [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>


2020-12-03T21:23:57.640Z,1607030637.640 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,NAL9602,DAT,BPC1,ESPComponent,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2020-12-03T21:23:57.652Z,1607030637.652 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2020-12-03T21:23:57.690Z,1607030637.690 [Depth_Keller](ERROR): Pressure reading out of range: 1925.893799 decibar
2020-12-03T21:23:57.693Z,1607030637.693 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2
2020-12-03T21:23:57.693Z,1607030637.693 [DAT](INFO): Powering up
2020-12-03T21:23:57.693Z,1607030637.693 [DAT](DEBUG): Initializing DAT.
2020-12-03T21:23:57.701Z,1607030637.701 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2
2020-12-03T21:23:57.777Z,1607030637.777 [DepthRateCalculator](ERROR): Depth measurement is not active
2020-12-03T21:23:57.785Z,1607030637.785 [Radio_Surface](INFO): Powering up
2020-12-03T21:23:57.821Z,1607030637.821 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2020-12-03T21:23:57.836Z,1607030637.836 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2020-12-03T21:23:57.837Z,1607030637.837 [ElevatorServo](DEBUG): Initializing EZServoServo.
2020-12-03T21:23:57.845Z,1607030637.845 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2020-12-03T21:23:57.846Z,1607030637.846 [MassServo](DEBUG): Initializing EZServoServo.
2020-12-03T21:23:57.853Z,1607030637.853 [MassServo](DEBUG): Initializing MassServo.
2020-12-03T21:23:57.854Z,1607030637.854 [RudderServo](DEBUG): Initializing EZServoServo.
2020-12-03T21:23:57.869Z,1607030637.869 [RudderServo](DEBUG): Initializing RudderServo.
2020-12-03T21:23:57.870Z,1607030637.870 [ThrusterServo](DEBUG): Initializing EZServoServo.
2020-12-03T21:23:57.877Z,1607030637.877 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2020-12-03T21:23:58.789Z,1607030638.789 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2020-12-03T21:23:58.789Z,1607030638.789 [RudderServo](FAULT): Rudder failed to initialize
2020-12-03T21:23:58.789Z,1607030638.789 [RudderServo] Communications Fault, FailCount= 1
2020-12-03T21:23:58.789Z,1607030638.789 [RudderServo](ERROR): Communications Fault
2020-12-03T21:23:58.889Z,1607030638.889 [CBIT](ERROR): Communications Fault in component: RudderServo
2020-12-03T21:23:59.059Z,1607030639.059 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2020-12-03T21:23:59.060Z,1607030639.060 [RudderServo](INFO): Powering down
2020-12-03T21:23:59.726Z,1607030639.726 [RudderServo](DEBUG): Initializing EZServoServo.
2020-12-03T21:23:59.846Z,1607030639.846 [RudderServo](DEBUG): Initializing RudderServo.
2020-12-03T21:23:59.849Z,1607030639.849 [CBIT](INFO): Clearing failed state for component RudderServo
2020-12-03T21:23:59.850Z,1607030639.850 [RudderServo] No Fault, FailCount= 1
2020-12-03T21:24:08.194Z,1607030648.194 [DAT](INFO): DAT read: 

2020-12-03T21:24:08.196Z,1607030648.196 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series

2020-12-03T21:24:09.406Z,1607030649.406 [DAT](INFO): DAT read: MF Frequency Band

2020-12-03T21:24:09.408Z,1607030649.408 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.12.21

2020-12-03T21:24:09.408Z,1607030649.408 [DAT](INFO): DAT read: Dec  3 2020 21:22:21 

2020-12-03T21:24:10.211Z,1607030650.211 [DAT](INFO): DAT read: Features enabled [Bearing]

2020-12-03T21:24:10.212Z,1607030650.212 [DAT](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP

2020-12-03T21:24:10.212Z,1607030650.212 [DAT](INFO): commRate: 800
2020-12-03T21:24:12.234Z,1607030652.234 [DAT](INFO): entering command mode
2020-12-03T21:24:12.642Z,1607030652.642 [DAT](INFO): DAT read: 

2020-12-03T21:24:12.642Z,1607030652.642 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-03T21:24:13.042Z,1607030653.042 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-03T21:24:13.446Z,1607030653.446 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-03T21:24:13.850Z,1607030653.850 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-03T21:24:14.254Z,1607030654.254 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-03T21:24:14.654Z,1607030654.654 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-03T21:24:15.058Z,1607030655.058 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-03T21:24:15.462Z,1607030655.462 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-03T21:24:15.866Z,1607030655.866 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-03T21:24:16.274Z,1607030656.274 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-03T21:24:16.678Z,1607030656.678 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-03T21:24:17.082Z,1607030657.082 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-03T21:24:17.482Z,1607030657.482 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-03T21:24:17.890Z,1607030657.890 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-03T21:24:18.290Z,1607030658.290 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-03T21:24:18.694Z,1607030658.694 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-03T21:24:19.102Z,1607030659.102 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-03T21:24:19.502Z,1607030659.502 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-03T21:24:19.911Z,1607030659.911 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-03T21:24:20.310Z,1607030660.310 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-03T21:24:20.714Z,1607030660.714 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-03T21:24:21.118Z,1607030661.118 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-03T21:24:21.526Z,1607030661.526 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-03T21:24:21.926Z,1607030661.926 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-03T21:24:22.330Z,1607030662.330 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-03T21:24:22.734Z,1607030662.734 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-03T21:24:23.142Z,1607030663.142 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-03T21:24:23.542Z,1607030663.542 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-03T21:24:23.946Z,1607030663.946 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-03T21:24:24.350Z,1607030664.350 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-03T21:24:24.754Z,1607030664.754 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-03T21:24:25.164Z,1607030665.164 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-03T21:24:25.566Z,1607030665.566 [NAL9602](INFO): Powering up NAL9602
2020-12-03T21:24:25.567Z,1607030665.567 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-03T21:24:25.966Z,1607030665.966 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-03T21:24:26.370Z,1607030666.370 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-03T21:24:26.778Z,1607030666.778 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-03T21:24:27.178Z,1607030667.178 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-03T21:24:27.586Z,1607030667.586 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-03T21:24:27.586Z,1607030667.586 [DAT](FAULT): failed to enter command mode
2020-12-03T21:24:27.986Z,1607030667.986 [DAT](INFO): entering command mode
2020-12-03T21:24:28.394Z,1607030668.394 [DAT](INFO): DAT read: user:1>

2020-12-03T21:24:28.395Z,1607030668.395 [DAT](INFO): DAT read: Command '+++' not found

2020-12-03T21:24:28.395Z,1607030668.395 [DAT](INFO): DAT read: Error

2020-12-03T21:24:28.396Z,1607030668.396 [DAT](INFO): setting verbose to 3
2020-12-03T21:24:28.794Z,1607030668.794 [DAT](INFO): DAT read: user:2>

2020-12-03T21:24:28.795Z,1607030668.795 [DAT](INFO): DAT read: Verbose         | 3           

2020-12-03T21:24:28.796Z,1607030668.796 [DAT](INFO): set verbose to 3
2020-12-03T21:24:28.796Z,1607030668.796 [DAT](INFO): setting DatVerbose to 27440
2020-12-03T21:24:29.198Z,1607030669.198 [DAT](INFO): DAT read: user:3>

2020-12-03T21:24:29.199Z,1607030669.199 [DAT](INFO): DAT read: DatVerbose      | 27440       

2020-12-03T21:24:29.199Z,1607030669.199 [DAT](INFO): set DatVerbose to 27440
2020-12-03T21:24:29.200Z,1607030669.200 [DAT](INFO): setting transmit power to 8
2020-12-03T21:24:29.602Z,1607030669.602 [DAT](INFO): DAT read: user:4>

2020-12-03T21:24:29.603Z,1607030669.603 [DAT](INFO): DAT read: TxPower         | 8 (Max)     

2020-12-03T21:24:29.603Z,1607030669.603 [DAT](INFO): set transmit power to 8
2020-12-03T21:24:29.604Z,1607030669.604 [DAT](INFO): setting local address to 5
2020-12-03T21:24:30.010Z,1607030670.010 [DAT](INFO): DAT read: user:5>

2020-12-03T21:24:30.011Z,1607030670.011 [DAT](INFO): DAT read: LocalAddr       | 5           

2020-12-03T21:24:30.011Z,1607030670.011 [DAT](INFO): set local address to 5
2020-12-03T21:24:32.089Z,1607030672.089 [SBIT](IMPORTANT): Beginning Startup BIT
2020-12-03T21:24:32.093Z,1607030672.093 [CBIT](IMPORTANT): Beginning ground fault scan
2020-12-03T21:24:36.482Z,1607030676.482 [NAL9602](INFO): NAL9602 initialized
2020-12-03T21:24:43.080Z,1607030683.080 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): 0.025870
CHAN A1 (24V): -0.007183
CHAN A2 (12V): -0.005101
CHAN A3 (5V): -0.002571
CHAN B0 (3.3V): -0.000805
CHAN B1 (3.15aV): -0.001184
CHAN B2 (3.15bV): -0.001411
CHAN B3 (GND): -0.000928
OPEN: 0.004509
Full Scale Calc: 4.765 mA, -1.589 mA
2020-12-03T21:25:26.196Z,1607030726.196 [SBIT](IMPORTANT): SBIT PASSED
2020-12-03T21:25:26.196Z,1607030726.196 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2020-12-03T21:25:26.197Z,1607030726.197 [SBIT](IMPORTANT): AHRS_M2.loadAtStartup=1 bool;

2020-12-03T21:25:26.197Z,1607030726.197 [SBIT](IMPORTANT): Aanderaa_O2.loadAtStartup=0 bool;

2020-12-03T21:25:26.197Z,1607030726.197 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=2 count;

2020-12-03T21:25:26.197Z,1607030726.197 [SBIT](IMPORTANT): DAT.loadAtStartup=1 bool;

2020-12-03T21:25:26.197Z,1607030726.197 [SBIT](IMPORTANT): DAT.verbosity=3 count;

2020-12-03T21:25:26.197Z,1607030726.197 [SBIT](IMPORTANT): DVL_micro.loadAtStartup=0 bool;

2020-12-03T21:25:26.197Z,1607030726.197 [SBIT](IMPORTANT): DropWeight.loadAtStartup=0 bool;

2020-12-03T21:25:26.198Z,1607030726.198 [SBIT](IMPORTANT): Express none CTD_Seabird.bin_median_sea_water_salinity;

2020-12-03T21:25:26.198Z,1607030726.198 [SBIT](IMPORTANT): Express linearApproximation WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water 0.100000 microgram_per_liter;

2020-12-03T21:25:26.198Z,1607030726.198 [SBIT](IMPORTANT): Express linearApproximation depth 5.000000 meter;

2020-12-03T21:25:26.198Z,1607030726.198 [SBIT](IMPORTANT): Express linearApproximation latitude 0.005000 degree;

2020-12-03T21:25:26.198Z,1607030726.198 [SBIT](IMPORTANT): Express linearApproximation longitude 0.005000 degree;

2020-12-03T21:25:26.198Z,1607030726.198 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=168 cubic_centimeter;

2020-12-03T21:25:26.198Z,1607030726.198 [SBIT](IMPORTANT): VerticalControl.massDefault=3.7 millimeter;

2020-12-03T21:25:26.606Z,1607030726.606 [MissionManager](IMPORTANT): Started mission Startup
2020-12-03T21:25:26.607Z,1607030726.607 [Startup] Running Loop=1
2020-12-03T21:25:26.607Z,1607030726.607 [Startup](DEBUG): Aggregate::initialize Startup
2020-12-03T21:25:26.607Z,1607030726.607 [Startup:A.GoToSurface] Running Loop=1
2020-12-03T21:25:26.607Z,1607030726.607 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2020-12-03T21:25:26.608Z,1607030726.608 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2020-12-03T21:25:26.608Z,1607030726.608 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2020-12-03T21:25:26.608Z,1607030726.608 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2020-12-03T21:25:26.609Z,1607030726.609 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2020-12-03T21:25:26.609Z,1607030726.609 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2020-12-03T21:25:26.611Z,1607030726.611 [Startup:StartupSatComms] Running Loop=1
2020-12-03T21:25:26.611Z,1607030726.611 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2020-12-03T21:25:26.611Z,1607030726.611 [Startup:StartupSatComms:A] Running Loop=1
2020-12-03T21:25:27.007Z,1607030727.007 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2020-12-03T21:26:25.195Z,1607030785.195 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.005053
2020-12-03T21:26:26.774Z,1607030786.774 [Startup:StartupSatComms:A](INFO): Timed out from 2020-12-03T21:25:26.6Z
2020-12-03T21:26:26.774Z,1607030786.774 [Startup:StartupSatComms:A] Stopped
2020-12-03T21:26:26.775Z,1607030786.775 [Startup:StartupSatComms:B] Running Loop=1
2020-12-03T21:26:27.182Z,1607030787.182 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2020-12-03T21:26:47.743Z,1607030807.743 [CommandLine](IMPORTANT): got command maintain sensor NAL9602.latitude_fix 36.799999 degree
2020-12-03T21:26:47.745Z,1607030807.745 [ComponentRegistry](DEBUG): SyncComponent "Maintain_NAL9602.latitude_fix" handled in the control thread.
2020-12-03T21:26:47.746Z,1607030807.746 [CommandLine](IMPORTANT): got command maintain sensor NAL9602.longitude_fix -122.800003 degree
2020-12-03T21:26:47.747Z,1607030807.747 [ComponentRegistry](DEBUG): SyncComponent "Maintain_NAL9602.longitude_fix" handled in the control thread.
2020-12-03T21:26:47.915Z,1607030807.915 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,NAL9602,DAT,BPC1,ESPComponent,PAR_Licor,Depth_Keller,PAR_Licor,Maintain_NAL9602.latitude_fix,Maintain_NAL9602.longitude_fix,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2020-12-03T21:26:48.316Z,1607030808.316 [DeadReckonUsingMultipleVelocitySources](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2020-12-03T21:26:48.316Z,1607030808.316 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2020-12-03T21:26:48.316Z,1607030808.316 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-12-03T21:26:48.327Z,1607030808.327 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-12-03T21:26:48.730Z,1607030808.730 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-12-03T21:26:48.730Z,1607030808.730 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2020-12-03T21:26:49.703Z,1607030809.703 [DeadReckonUsingMultipleVelocitySources](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2020-12-03T21:26:49.703Z,1607030809.703 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2020-12-03T21:26:49.703Z,1607030809.703 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-12-03T21:26:49.762Z,1607030809.762 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-12-03T21:26:49.965Z,1607030809.965 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-12-03T21:26:49.966Z,1607030809.966 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2020-12-03T21:26:50.760Z,1607030810.760 [DeadReckonUsingMultipleVelocitySources](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2020-12-03T21:26:50.760Z,1607030810.760 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2020-12-03T21:26:50.760Z,1607030810.760 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-12-03T21:26:50.786Z,1607030810.786 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-12-03T21:26:51.195Z,1607030811.195 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-12-03T21:26:51.195Z,1607030811.195 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2020-12-03T21:26:51.934Z,1607030811.934 [DeadReckonUsingMultipleVelocitySources](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2020-12-03T21:26:51.934Z,1607030811.934 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2020-12-03T21:26:51.934Z,1607030811.934 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-12-03T21:26:52.014Z,1607030812.014 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-12-03T21:26:52.360Z,1607030812.360 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-12-03T21:26:52.360Z,1607030812.360 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2020-12-03T21:26:53.159Z,1607030813.159 [DeadReckonUsingMultipleVelocitySources](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2020-12-03T21:26:53.160Z,1607030813.160 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5
2020-12-03T21:26:53.160Z,1607030813.160 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-12-03T21:26:53.182Z,1607030813.182 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-12-03T21:26:53.554Z,1607030813.554 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-12-03T21:26:53.554Z,1607030813.554 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5
2020-12-03T21:26:54.343Z,1607030814.343 [DeadReckonUsingMultipleVelocitySources](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2020-12-03T21:26:54.343Z,1607030814.343 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6
2020-12-03T21:26:54.343Z,1607030814.343 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-12-03T21:26:54.381Z,1607030814.381 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-12-03T21:26:54.782Z,1607030814.782 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-12-03T21:26:54.782Z,1607030814.782 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6
2020-12-03T21:26:55.578Z,1607030815.578 [DeadReckonUsingMultipleVelocitySources](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2020-12-03T21:26:55.579Z,1607030815.579 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7
2020-12-03T21:26:55.579Z,1607030815.579 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-12-03T21:26:55.589Z,1607030815.589 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-12-03T21:26:55.986Z,1607030815.986 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-12-03T21:26:55.986Z,1607030815.986 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7
2020-12-03T21:26:56.771Z,1607030816.771 [DeadReckonUsingMultipleVelocitySources](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2020-12-03T21:26:56.771Z,1607030816.771 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 8
2020-12-03T21:26:56.771Z,1607030816.771 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-12-03T21:26:56.781Z,1607030816.781 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-12-03T21:26:57.184Z,1607030817.184 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-12-03T21:26:57.185Z,1607030817.185 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 8
2020-12-03T21:26:57.979Z,1607030817.979 [DeadReckonUsingMultipleVelocitySources](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2020-12-03T21:26:57.979Z,1607030817.979 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 9
2020-12-03T21:26:57.979Z,1607030817.979 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-12-03T21:26:57.989Z,1607030817.989 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-12-03T21:26:58.392Z,1607030818.392 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-12-03T21:26:58.392Z,1607030818.392 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 9
2020-12-03T21:26:59.206Z,1607030819.206 [DeadReckonUsingMultipleVelocitySources](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2020-12-03T21:26:59.206Z,1607030819.206 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 10
2020-12-03T21:26:59.206Z,1607030819.206 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-12-03T21:26:59.221Z,1607030819.221 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-12-03T21:26:59.706Z,1607030819.706 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-12-03T21:26:59.706Z,1607030819.706 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 10
2020-12-03T21:27:00.446Z,1607030820.446 [DeadReckonUsingMultipleVelocitySources](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2020-12-03T21:27:00.446Z,1607030820.446 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 11
2020-12-03T21:27:00.446Z,1607030820.446 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-12-03T21:27:00.465Z,1607030820.465 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-12-03T21:27:00.907Z,1607030820.907 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-12-03T21:27:00.908Z,1607030820.908 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 11
2020-12-03T21:27:01.637Z,1607030821.637 [DeadReckonUsingMultipleVelocitySources](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2020-12-03T21:27:01.637Z,1607030821.637 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 12
2020-12-03T21:27:01.638Z,1607030821.638 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-12-03T21:27:01.656Z,1607030821.656 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-12-03T21:27:02.146Z,1607030822.146 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-12-03T21:27:02.146Z,1607030822.146 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 12
2020-12-03T21:27:02.850Z,1607030822.850 [DeadReckonUsingMultipleVelocitySources](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2020-12-03T21:27:02.851Z,1607030822.851 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 13
2020-12-03T21:27:02.851Z,1607030822.851 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-12-03T21:27:02.861Z,1607030822.861 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-12-03T21:27:03.262Z,1607030823.262 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-12-03T21:27:03.262Z,1607030823.262 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 13
2020-12-03T21:27:03.770Z,1607030823.770 [CommandLine](IMPORTANT): got command set NAL9602.time_fix 1607030784.000000 second
2020-12-03T21:27:27.101Z,1607030847.101 [Startup:StartupSatComms:B](INFO): Timed out from 2020-12-03T21:26:26.8Z
2020-12-03T21:27:27.102Z,1607030847.102 [Startup:StartupSatComms:B] Stopped
2020-12-03T21:27:27.102Z,1607030847.102 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2020-12-03T21:27:27.102Z,1607030847.102 [Startup:StartupSatComms] Stopped
2020-12-03T21:27:27.102Z,1607030847.102 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2020-12-03T21:27:27.103Z,1607030847.103 [Startup](INFO): Completed Startup
2020-12-03T21:27:27.103Z,1607030847.103 [MissionManager](INFO): Startup is completed.
2020-12-03T21:27:27.103Z,1607030847.103 [MissionManager](INFO): Uninitializing Mission Startup
2020-12-03T21:27:27.103Z,1607030847.103 [Startup] Stopped
2020-12-03T21:27:27.103Z,1607030847.103 [Startup](DEBUG): Aggregate::uninitialize Startup
2020-12-03T21:27:27.103Z,1607030847.103 [Startup:A.GoToSurface] Stopped
2020-12-03T21:27:27.103Z,1607030847.103 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2020-12-03T21:27:27.516Z,1607030847.516 [MissionManager](IMPORTANT): Started mission Default
2020-12-03T21:27:27.516Z,1607030847.516 [Default] Running Loop=1
2020-12-03T21:27:27.516Z,1607030847.516 [Default](DEBUG): Aggregate::initialize Default
2020-12-03T21:27:27.516Z,1607030847.516 [Default:B.GoToSurface] Running Loop=1
2020-12-03T21:27:27.517Z,1607030847.517 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2020-12-03T21:27:27.517Z,1607030847.517 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2020-12-03T21:27:27.517Z,1607030847.517 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2020-12-03T21:27:27.517Z,1607030847.517 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2020-12-03T21:27:27.518Z,1607030847.518 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2020-12-03T21:27:27.518Z,1607030847.518 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2020-12-03T21:27:27.518Z,1607030847.518 [Default:A.Wait] Running Loop=1
2020-12-03T21:27:27.518Z,1607030847.518 [Default:A.Wait](DEBUG): Initialize Wait Component.
2020-12-03T21:27:40.821Z,1607030860.821 [Default:A.Wait](INFO): Done Waiting.
2020-12-03T21:27:40.822Z,1607030860.822 [Default:A.Wait] Stopped
2020-12-03T21:27:40.822Z,1607030860.822 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2020-12-03T21:27:41.230Z,1607030861.230 [Default:CheckIn] Running Loop=1
2020-12-03T21:27:41.230Z,1607030861.230 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-12-03T21:27:41.230Z,1607030861.230 [Default:CheckIn:Read_GPS] Running Loop=1
2020-12-03T21:27:41.617Z,1607030861.617 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2020-12-03T21:28:52.577Z,1607030932.577 [DataOverHttps](INFO): Sending 150 bytes from file Logs/20201203T211546/Courier0000.lzma
2020-12-03T21:28:53.578Z,1607030933.578 [DataOverHttps](INFO): Moved sent file to Logs/20201203T211546/Courier0000.lzma.bak
2020-12-03T21:28:53.579Z,1607030933.579 [DataOverHttps](INFO): SBD MOMSN=13389136
2020-12-03T21:29:39.170Z,1607030979.170 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-12-03T21:32:12.732Z,1607031132.732 [BPC1](ERROR): BPC1A: No match for serial number 1717 in BPC1A's battery stick inventory (sticks 1-32 in onboard configuration file).
2020-12-03T21:32:41.429Z,1607031161.429 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-12-03T21:27:41.2Z
2020-12-03T21:32:41.429Z,1607031161.429 [Default:CheckIn:Read_GPS] Stopped
2020-12-03T21:32:41.429Z,1607031161.429 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-12-03T21:32:41.825Z,1607031161.825 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2020-12-03T21:32:51.369Z,1607031171.369 [DataOverHttps](INFO): Sending 168 bytes from file Logs/20201203T211546/Courier0006.lzma
2020-12-03T21:32:52.370Z,1607031172.370 [DataOverHttps](INFO): Moved sent file to Logs/20201203T211546/Courier0006.lzma.bak
2020-12-03T21:32:52.371Z,1607031172.371 [DataOverHttps](INFO): SBD MOMSN=13389185
2020-12-03T21:33:11.845Z,1607031191.845 [DataOverHttps](INFO): Sending 150 bytes from file Logs/20201203T212347/Courier0000.lzma
2020-12-03T21:33:13.313Z,1607031193.313 [NAL9602](INFO): Not Powering down - fast GPS
2020-12-03T21:33:13.953Z,1607031193.953 [DataOverHttps](INFO): Moved sent file to Logs/20201203T212347/Courier0000.lzma.bak
2020-12-03T21:33:13.953Z,1607031193.953 [DataOverHttps](INFO): SBD MOMSN=13389190
2020-12-03T21:33:32.232Z,1607031212.232 [DataOverHttps](INFO): Sending 155 bytes from file Logs/20201203T212347/Courier0004.lzma
2020-12-03T21:33:33.234Z,1607031213.234 [DataOverHttps](INFO): Moved sent file to Logs/20201203T212347/Courier0004.lzma.bak
2020-12-03T21:33:33.235Z,1607031213.235 [DataOverHttps](INFO): SBD MOMSN=13389193
2020-12-03T21:33:56.524Z,1607031236.524 [DataOverHttps](INFO): Sending 1025 bytes from file Logs/20201203T204750/Express0011.lzma
2020-12-03T21:33:57.522Z,1607031237.522 [DataOverHttps](INFO): Moved sent file to Logs/20201203T204750/Express0011.lzma.bak
2020-12-03T21:33:57.523Z,1607031237.523 [DataOverHttps](INFO): SBD MOMSN=13389196
2020-12-03T21:34:19.678Z,1607031259.678 [DataOverHttps](INFO): Sending 691 bytes from file Logs/20201203T210846/Express0001.lzma
2020-12-03T21:34:20.678Z,1607031260.678 [DataOverHttps](INFO): Moved sent file to Logs/20201203T210846/Express0001.lzma.bak
2020-12-03T21:34:20.679Z,1607031260.679 [DataOverHttps](INFO): SBD MOMSN=13389249
2020-12-03T21:34:43.547Z,1607031283.547 [DataOverHttps](INFO): Sending 312 bytes from file Logs/20201203T211150/Express0001.lzma
2020-12-03T21:34:44.546Z,1607031284.546 [DataOverHttps](INFO): Moved sent file to Logs/20201203T211150/Express0001.lzma.bak
2020-12-03T21:34:44.547Z,1607031284.547 [DataOverHttps](INFO): SBD MOMSN=13389273
2020-12-03T21:35:06.396Z,1607031306.396 [DataOverHttps](INFO): Sending 52 bytes from file Logs/20201203T211150/Express0002.lzma
2020-12-03T21:35:07.398Z,1607031307.398 [DataOverHttps](INFO): Moved sent file to Logs/20201203T211150/Express0002.lzma.bak
2020-12-03T21:35:07.398Z,1607031307.398 [DataOverHttps](INFO): SBD MOMSN=13389276
2020-12-03T21:35:29.274Z,1607031329.274 [DataOverHttps](INFO): Sending 293 bytes from file Logs/20201203T211150/Express0007.lzma
2020-12-03T21:35:30.274Z,1607031330.274 [DataOverHttps](INFO): Moved sent file to Logs/20201203T211150/Express0007.lzma.bak
2020-12-03T21:35:30.275Z,1607031330.275 [DataOverHttps](INFO): SBD MOMSN=13389278
2020-12-03T21:35:52.178Z,1607031352.178 [DataOverHttps](INFO): Sending 523 bytes from file Logs/20201203T211150/Express0010.lzma
2020-12-03T21:35:53.178Z,1607031353.178 [DataOverHttps](INFO): Moved sent file to Logs/20201203T211150/Express0010.lzma.bak
2020-12-03T21:35:53.178Z,1607031353.178 [DataOverHttps](INFO): SBD MOMSN=13389283
2020-12-03T21:36:15.409Z,1607031375.409 [DataOverHttps](INFO): Sending 462 bytes from file Logs/20201203T211546/Express0001.lzma
2020-12-03T21:36:16.410Z,1607031376.410 [DataOverHttps](INFO): Moved sent file to Logs/20201203T211546/Express0001.lzma.bak
2020-12-03T21:36:16.411Z,1607031376.411 [DataOverHttps](INFO): SBD MOMSN=13389297
2020-12-03T21:36:38.061Z,1607031398.061 [DataOverHttps](INFO): Sending 178 bytes from file Logs/20201203T211546/Express0004.lzma
2020-12-03T21:36:39.062Z,1607031399.062 [DataOverHttps](INFO): Moved sent file to Logs/20201203T211546/Express0004.lzma.bak
2020-12-03T21:36:39.063Z,1607031399.063 [DataOverHttps](INFO): SBD MOMSN=13389303
2020-12-03T21:37:02.110Z,1607031422.110 [DataOverHttps](INFO): Sending 571 bytes from file Logs/20201203T211546/Express0007.lzma
2020-12-03T21:37:03.110Z,1607031423.110 [DataOverHttps](INFO): Moved sent file to Logs/20201203T211546/Express0007.lzma.bak
2020-12-03T21:37:03.111Z,1607031423.111 [DataOverHttps](INFO): SBD MOMSN=13389307
2020-12-03T21:37:24.239Z,1607031444.239 [DataOverHttps](INFO): Sending 1038 bytes from file Logs/20201203T212347/Express0001.lzma
2020-12-03T21:37:25.250Z,1607031445.250 [DataOverHttps](INFO): Moved sent file to Logs/20201203T212347/Express0001.lzma.bak
2020-12-03T21:37:25.251Z,1607031445.251 [DataOverHttps](INFO): SBD MOMSN=13389315
2020-12-03T21:37:46.998Z,1607031466.998 [DataOverHttps](INFO): Sending 424 bytes from file Logs/20201203T212347/Express0005.lzma
2020-12-03T21:37:47.998Z,1607031467.998 [DataOverHttps](INFO): Moved sent file to Logs/20201203T212347/Express0005.lzma.bak
2020-12-03T21:37:47.999Z,1607031467.999 [DataOverHttps](INFO): SBD MOMSN=13389343
2020-12-03T21:37:54.563Z,1607031474.563 [Default:CheckIn:Read_Iridium] Stopped
2020-12-03T21:37:54.563Z,1607031474.563 [Default:CheckIn:C.Wait] Running Loop=1
2020-12-03T21:37:54.563Z,1607031474.563 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-12-03T21:42:55.189Z,1607031775.189 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-12-03T21:42:55.189Z,1607031775.189 [Default:CheckIn:C.Wait] Stopped
2020-12-03T21:42:55.189Z,1607031775.189 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-12-03T21:42:55.189Z,1607031775.189 [Default:CheckIn:D] Running Loop=1
2020-12-03T21:42:55.612Z,1607031775.612 [Default:CheckIn:D] Stopped
2020-12-03T21:42:55.616Z,1607031775.616 [Default:CheckIn:E] Running Loop=1
2020-12-03T21:42:55.985Z,1607031775.985 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 15.468268 min 
2020-12-03T21:42:55.986Z,1607031775.986 [Default:CheckIn:E] Stopped
2020-12-03T21:42:55.986Z,1607031775.986 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-12-03T21:42:55.986Z,1607031775.986 [Default:CheckIn] Stopped
2020-12-03T21:42:55.986Z,1607031775.986 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-12-03T21:42:55.986Z,1607031775.986 [Default:CheckIn](INFO): Running loop #2
2020-12-03T21:42:55.986Z,1607031775.986 [Default:CheckIn] Running Loop=2
2020-12-03T21:42:55.986Z,1607031775.986 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-12-03T21:42:55.986Z,1607031775.986 [Default:CheckIn:Read_GPS] Running Loop=1
2020-12-03T21:42:57.586Z,1607031777.586 [NAL9602](FAULT): GPS failed to acquire within timeout.
2020-12-03T21:42:57.586Z,1607031777.586 [NAL9602] Data Fault, FailCount= 1
2020-12-03T21:42:57.586Z,1607031777.586 [NAL9602](ERROR): Data Fault
2020-12-03T21:42:57.626Z,1607031777.626 [CBIT](ERROR): Data Fault in component: NAL9602
2020-12-03T21:42:57.989Z,1607031777.989 [NAL9602](INFO): Powering down
2020-12-03T21:42:58.816Z,1607031778.816 [CBIT](INFO): Clearing failed state for component NAL9602
2020-12-03T21:42:58.816Z,1607031778.816 [NAL9602] No Fault, FailCount= 1
2020-12-03T21:43:28.289Z,1607031808.289 [NAL9602](INFO): Powering up NAL9602
2020-12-03T21:43:39.198Z,1607031819.198 [NAL9602](INFO): NAL9602 initialized
2020-12-03T21:47:55.342Z,1607032075.342 [BPC1](ERROR): BPC1A: No match for serial number 1717 in BPC1A's battery stick inventory (sticks 1-32 in onboard configuration file).
2020-12-03T21:47:56.181Z,1607032076.181 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-12-03T21:42:55.0Z
2020-12-03T21:47:56.181Z,1607032076.181 [Default:CheckIn:Read_GPS] Stopped
2020-12-03T21:47:56.181Z,1607032076.181 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-12-03T21:48:06.264Z,1607032086.264 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20201203T212347/Courier0007.lzma
2020-12-03T21:48:07.266Z,1607032087.266 [DataOverHttps](INFO): Moved sent file to Logs/20201203T212347/Courier0007.lzma.bak
2020-12-03T21:48:07.267Z,1607032087.267 [DataOverHttps](INFO): SBD MOMSN=13389405
2020-12-03T21:48:29.202Z,1607032109.202 [DataOverHttps](INFO): Sending 200 bytes from file Logs/20201203T212347/Express0008.lzma
2020-12-03T21:48:30.202Z,1607032110.202 [DataOverHttps](INFO): Moved sent file to Logs/20201203T212347/Express0008.lzma.bak
2020-12-03T21:48:30.203Z,1607032110.203 [DataOverHttps](INFO): SBD MOMSN=13389407
2020-12-03T21:48:36.597Z,1607032116.597 [Default:CheckIn:Read_Iridium] Stopped
2020-12-03T21:48:36.597Z,1607032116.597 [Default:CheckIn:C.Wait] Running Loop=1
2020-12-03T21:48:36.597Z,1607032116.597 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-12-03T21:48:41.794Z,1607032121.794 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-12-03T21:49:12.497Z,1607032152.497 [NAL9602](INFO): Not Powering down - fast GPS
2020-12-03T21:53:37.169Z,1607032417.169 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-12-03T21:53:37.169Z,1607032417.169 [Default:CheckIn:C.Wait] Stopped
2020-12-03T21:53:37.170Z,1607032417.170 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-12-03T21:53:37.170Z,1607032417.170 [Default:CheckIn:D] Running Loop=1
2020-12-03T21:53:37.588Z,1607032417.588 [Default:CheckIn:D] Stopped
2020-12-03T21:53:37.588Z,1607032417.588 [Default:CheckIn:E] Running Loop=1
2020-12-03T21:53:37.999Z,1607032417.999 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 26.167857 min 
2020-12-03T21:53:37.999Z,1607032417.999 [Default:CheckIn:E] Stopped
2020-12-03T21:53:37.999Z,1607032417.999 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-12-03T21:53:37.999Z,1607032417.999 [Default:CheckIn] Stopped
2020-12-03T21:53:37.000Z,1607032418.000 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-12-03T21:53:37.000Z,1607032418.000 [Default:CheckIn](INFO): Running loop #3
2020-12-03T21:53:37.000Z,1607032418.000 [Default:CheckIn] Running Loop=3
2020-12-03T21:53:37.000Z,1607032418.000 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-12-03T21:53:37.000Z,1607032418.000 [Default:CheckIn:Read_GPS] Running Loop=1
2020-12-03T21:54:57.952Z,1607032497.952 [BPC1](INFO): Calculating totals. Valid battery stick count: 50. Valid reserve battery stick count: 5.
2020-12-03T21:54:57.955Z,1607032497.955 [BPC1](ERROR): Failed to receive data from all sticks prior to timeout. Will not retry this scan cycle.
2020-12-03T21:58:38.152Z,1607032718.152 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-12-03T21:53:37.0Z
2020-12-03T21:58:38.153Z,1607032718.153 [Default:CheckIn:Read_GPS] Stopped
2020-12-03T21:58:38.153Z,1607032718.153 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-12-03T21:58:41.826Z,1607032721.826 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-12-03T21:58:47.980Z,1607032727.980 [DataOverHttps](INFO): Sending 168 bytes from file Logs/20201203T212347/Courier0010.lzma
2020-12-03T21:58:48.983Z,1607032728.983 [DataOverHttps](INFO): Moved sent file to Logs/20201203T212347/Courier0010.lzma.bak
2020-12-03T21:58:48.983Z,1607032728.983 [DataOverHttps](INFO): SBD MOMSN=13389467
2020-12-03T21:59:09.729Z,1607032749.729 [DataOverHttps](INFO): Sending 206 bytes from file Logs/20201203T212347/Express0011.lzma
2020-12-03T21:59:10.722Z,1607032750.722 [DataOverHttps](INFO): Moved sent file to Logs/20201203T212347/Express0011.lzma.bak
2020-12-03T21:59:10.722Z,1607032750.722 [DataOverHttps](INFO): SBD MOMSN=13389469
2020-12-03T21:59:12.525Z,1607032752.525 [NAL9602](INFO): Not Powering down - fast GPS
2020-12-03T21:59:17.031Z,1607032757.031 [Default:CheckIn:Read_Iridium] Stopped
2020-12-03T21:59:17.031Z,1607032757.031 [Default:CheckIn:C.Wait] Running Loop=1
2020-12-03T21:59:17.031Z,1607032757.031 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-12-03T22:04:17.575Z,1607033057.575 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-12-03T22:04:17.576Z,1607033057.576 [Default:CheckIn:C.Wait] Stopped
2020-12-03T22:04:17.576Z,1607033057.576 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-12-03T22:04:17.576Z,1607033057.576 [Default:CheckIn:D] Running Loop=1
2020-12-03T22:04:17.973Z,1607033057.973 [Default:CheckIn:D] Stopped
2020-12-03T22:04:17.973Z,1607033057.973 [Default:CheckIn:E] Running Loop=1
2020-12-03T22:04:18.382Z,1607033058.382 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 36.840951 min 
2020-12-03T22:04:18.382Z,1607033058.382 [Default:CheckIn:E] Stopped
2020-12-03T22:04:18.382Z,1607033058.382 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-12-03T22:04:18.382Z,1607033058.382 [Default:CheckIn] Stopped
2020-12-03T22:04:18.382Z,1607033058.382 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-12-03T22:04:18.382Z,1607033058.382 [Default:CheckIn](INFO): Running loop #4
2020-12-03T22:04:18.383Z,1607033058.383 [Default:CheckIn] Running Loop=4
2020-12-03T22:04:18.383Z,1607033058.383 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-12-03T22:04:18.383Z,1607033058.383 [Default:CheckIn:Read_GPS] Running Loop=1
2020-12-03T22:04:19.970Z,1607033059.970 [NAL9602](FAULT): GPS failed to acquire within timeout.
2020-12-03T22:04:19.970Z,1607033059.970 [NAL9602] Data Fault, FailCount= 2
2020-12-03T22:04:19.970Z,1607033059.970 [NAL9602](ERROR): Data Fault
2020-12-03T22:04:20.049Z,1607033060.049 [CBIT](ERROR): Data Fault in component: NAL9602
2020-12-03T22:04:20.373Z,1607033060.373 [NAL9602](INFO): Powering down
2020-12-03T22:04:21.209Z,1607033061.209 [CBIT](INFO): Clearing failed state for component NAL9602
2020-12-03T22:04:21.209Z,1607033061.209 [NAL9602] No Fault, FailCount= 2
2020-12-03T22:04:50.674Z,1607033090.674 [NAL9602](INFO): Powering up NAL9602
2020-12-03T22:05:01.582Z,1607033101.582 [NAL9602](INFO): NAL9602 initialized
2020-12-03T22:09:18.542Z,1607033358.542 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-12-03T22:04:18.4Z
2020-12-03T22:09:18.542Z,1607033358.542 [Default:CheckIn:Read_GPS] Stopped
2020-12-03T22:09:18.542Z,1607033358.542 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-12-03T22:10:04.177Z,1607033404.177 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-12-03T22:10:34.888Z,1607033434.888 [NAL9602](INFO): Not Powering down - fast GPS
2020-12-03T22:10:58.312Z,1607033458.312 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20201203T212347/Courier0013.lzma
2020-12-03T22:10:59.314Z,1607033459.314 [DataOverHttps](INFO): Moved sent file to Logs/20201203T212347/Courier0013.lzma.bak
2020-12-03T22:10:59.315Z,1607033459.315 [DataOverHttps](INFO): SBD MOMSN=13389530
2020-12-03T22:11:20.993Z,1607033480.993 [DataOverHttps](INFO): Sending 224 bytes from file Logs/20201203T212347/Express0014.lzma
2020-12-03T22:11:21.994Z,1607033481.994 [DataOverHttps](INFO): Moved sent file to Logs/20201203T212347/Express0014.lzma.bak
2020-12-03T22:11:21.995Z,1607033481.995 [DataOverHttps](INFO): SBD MOMSN=13389533
2020-12-03T22:11:28.664Z,1607033488.664 [Default:CheckIn:Read_Iridium] Stopped
2020-12-03T22:11:28.664Z,1607033488.664 [Default:CheckIn:C.Wait] Running Loop=1
2020-12-03T22:11:28.664Z,1607033488.664 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-12-03T22:16:29.253Z,1607033789.253 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-12-03T22:16:29.253Z,1607033789.253 [Default:CheckIn:C.Wait] Stopped
2020-12-03T22:16:29.253Z,1607033789.253 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-12-03T22:16:29.253Z,1607033789.253 [Default:CheckIn:D] Running Loop=1
2020-12-03T22:16:29.630Z,1607033789.630 [Default:CheckIn:D] Stopped
2020-12-03T22:16:29.631Z,1607033789.631 [Default:CheckIn:E] Running Loop=1
2020-12-03T22:16:30.043Z,1607033790.043 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 49.035217 min 
2020-12-03T22:16:30.043Z,1607033790.043 [Default:CheckIn:E] Stopped
2020-12-03T22:16:30.043Z,1607033790.043 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-12-03T22:16:30.043Z,1607033790.043 [Default:CheckIn] Stopped
2020-12-03T22:16:30.043Z,1607033790.043 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-12-03T22:16:30.043Z,1607033790.043 [Default:CheckIn](INFO): Running loop #5
2020-12-03T22:16:30.043Z,1607033790.043 [Default:CheckIn] Running Loop=5
2020-12-03T22:16:30.043Z,1607033790.043 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-12-03T22:16:30.043Z,1607033790.043 [Default:CheckIn:Read_GPS] Running Loop=1
2020-12-03T22:16:31.646Z,1607033791.646 [NAL9602](FAULT): GPS failed to acquire within timeout.
2020-12-03T22:16:31.646Z,1607033791.646 [NAL9602] Data Fault, FailCount= 3
2020-12-03T22:16:31.646Z,1607033791.646 [NAL9602](ERROR): Data Fault
2020-12-03T22:16:31.678Z,1607033791.678 [CBIT](ERROR): Data Fault in component: NAL9602
2020-12-03T22:16:32.051Z,1607033792.051 [NAL9602](INFO): Powering down
2020-12-03T22:16:32.912Z,1607033792.912 [CBIT](INFO): Clearing failed state for component NAL9602
2020-12-03T22:16:32.912Z,1607033792.912 [NAL9602] No Fault, FailCount= 3
2020-12-03T22:17:02.341Z,1607033822.341 [NAL9602](INFO): Powering up NAL9602
2020-12-03T22:17:13.249Z,1607033833.249 [NAL9602](INFO): NAL9602 initialized
2020-12-03T22:21:30.212Z,1607034090.212 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-12-03T22:16:30.0Z
2020-12-03T22:21:30.212Z,1607034090.212 [Default:CheckIn:Read_GPS] Stopped
2020-12-03T22:21:30.212Z,1607034090.212 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-12-03T22:22:15.902Z,1607034135.902 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-12-03T22:22:46.601Z,1607034166.601 [NAL9602](INFO): Not Powering down - fast GPS
2020-12-03T22:24:13.212Z,1607034253.212 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20201203T212347/Courier0016.lzma
2020-12-03T22:24:14.214Z,1607034254.214 [DataOverHttps](INFO): Moved sent file to Logs/20201203T212347/Courier0016.lzma.bak
2020-12-03T22:24:14.215Z,1607034254.215 [DataOverHttps](INFO): SBD MOMSN=13389596
2020-12-03T22:24:35.593Z,1607034275.593 [DataOverHttps](INFO): Sending 226 bytes from file Logs/20201203T212347/Express0017.lzma
2020-12-03T22:24:36.595Z,1607034276.595 [DataOverHttps](INFO): Moved sent file to Logs/20201203T212347/Express0017.lzma.bak
2020-12-03T22:24:36.595Z,1607034276.595 [DataOverHttps](INFO): SBD MOMSN=13389598
2020-12-03T22:24:42.612Z,1607034282.612 [Default:CheckIn:Read_Iridium] Stopped
2020-12-03T22:24:42.612Z,1607034282.612 [Default:CheckIn:C.Wait] Running Loop=1
2020-12-03T22:24:42.612Z,1607034282.612 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-12-03T22:29:43.183Z,1607034583.183 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-12-03T22:29:43.183Z,1607034583.183 [Default:CheckIn:C.Wait] Stopped
2020-12-03T22:29:43.183Z,1607034583.183 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-12-03T22:29:43.183Z,1607034583.183 [Default:CheckIn:D] Running Loop=1
2020-12-03T22:29:43.575Z,1607034583.575 [Default:CheckIn:D] Stopped
2020-12-03T22:29:43.575Z,1607034583.575 [Default:CheckIn:E] Running Loop=1
2020-12-03T22:29:43.977Z,1607034583.977 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 62.267639 min 
2020-12-03T22:29:43.977Z,1607034583.977 [Default:CheckIn:E] Stopped
2020-12-03T22:29:43.977Z,1607034583.977 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-12-03T22:29:43.977Z,1607034583.977 [Default:CheckIn] Stopped
2020-12-03T22:29:43.978Z,1607034583.978 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-12-03T22:29:43.978Z,1607034583.978 [Default:CheckIn](INFO): Running loop #6
2020-12-03T22:29:43.978Z,1607034583.978 [Default:CheckIn] Running Loop=6
2020-12-03T22:29:43.978Z,1607034583.978 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-12-03T22:29:43.978Z,1607034583.978 [Default:CheckIn:Read_GPS] Running Loop=1
2020-12-03T22:29:45.586Z,1607034585.586 [NAL9602](FAULT): GPS failed to acquire within timeout.
2020-12-03T22:29:45.587Z,1607034585.587 [NAL9602] Data Fault, FailCount= 4
2020-12-03T22:29:45.587Z,1607034585.587 [NAL9602](ERROR): Data Fault
2020-12-03T22:29:45.630Z,1607034585.630 [CBIT](ERROR): Data Fault in component: NAL9602
2020-12-03T22:29:45.985Z,1607034585.985 [NAL9602](INFO): Powering down
2020-12-03T22:29:46.821Z,1607034586.821 [CBIT](INFO): Clearing failed state for component NAL9602
2020-12-03T22:29:46.822Z,1607034586.822 [NAL9602] No Fault, FailCount= 4
2020-12-03T22:30:16.285Z,1607034616.285 [NAL9602](INFO): Powering up NAL9602
2020-12-03T22:30:27.190Z,1607034627.190 [NAL9602](INFO): NAL9602 initialized
2020-12-03T22:34:44.172Z,1607034884.172 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-12-03T22:29:43.0Z
2020-12-03T22:34:44.173Z,1607034884.173 [Default:CheckIn:Read_GPS] Stopped
2020-12-03T22:34:44.173Z,1607034884.173 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-12-03T22:35:29.810Z,1607034929.810 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-12-03T22:36:00.513Z,1607034960.513 [NAL9602](INFO): Not Powering down - fast GPS
2020-12-03T22:37:22.580Z,1607035042.580 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20201203T212347/Courier0019.lzma
2020-12-03T22:37:23.582Z,1607035043.582 [DataOverHttps](INFO): Moved sent file to Logs/20201203T212347/Courier0019.lzma.bak
2020-12-03T22:37:23.583Z,1607035043.583 [DataOverHttps](INFO): SBD MOMSN=13389665
2020-12-03T22:37:45.181Z,1607035065.181 [DataOverHttps](INFO): Sending 225 bytes from file Logs/20201203T212347/Express0020.lzma
2020-12-03T22:37:46.182Z,1607035066.182 [DataOverHttps](INFO): Moved sent file to Logs/20201203T212347/Express0020.lzma.bak
2020-12-03T22:37:46.183Z,1607035066.183 [DataOverHttps](INFO): SBD MOMSN=13389670
2020-12-03T22:37:52.458Z,1607035072.458 [Default:CheckIn:Read_Iridium] Stopped
2020-12-03T22:37:52.458Z,1607035072.458 [Default:CheckIn:C.Wait] Running Loop=1
2020-12-03T22:37:52.458Z,1607035072.458 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-12-03T22:41:19.038Z,1607035279.038 [CommandLine](IMPORTANT): got command failComponent
2020-12-03T22:41:19.038Z,1607035279.038 [CommandLine](IMPORTANT): Failed components:
2020-12-03T22:41:19.039Z,1607035279.039 [CommandLine](IMPORTANT): No failed Components.
2020-12-03T22:41:31.794Z,1607035291.794 [CommandLine](IMPORTANT): got command get latitude
2020-12-03T22:41:31.794Z,1607035291.794 [CommandLine](IMPORTANT): latitude 36.799999 arcdeg