2019-09-10T16:11:10.939Z,1568131870.939 [Supervisor](DEBUG): Initializing supervisor. 2019-09-10T16:11:10.942Z,1568131870.942 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2019-09-10T16:11:10.943Z,1568131870.943 [SyncHandler](INFO): Protected caller Thread ID is 3642 2019-09-10T16:11:10.943Z,1568131870.943 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2019-09-10T16:11:10.944Z,1568131870.944 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2019-09-10T16:11:10.944Z,1568131870.944 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 3643 2019-09-10T16:11:10.947Z,1568131870.947 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2019-09-10T16:11:10.958Z,1568131870.958 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2019-09-10T16:11:10.959Z,1568131870.959 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2019-09-10T16:11:10.959Z,1568131870.959 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 3644 2019-09-10T16:11:10.960Z,1568131870.960 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2019-09-10T16:11:10.961Z,1568131870.961 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2019-09-10T16:11:10.961Z,1568131870.961 [logger ThreadHandler](INFO): Protected caller Thread ID is 3645 2019-09-10T16:11:10.963Z,1568131870.963 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2019-09-10T16:11:10.964Z,1568131870.964 [Supervisor](INFO): Looking for Config files in directory: Config/ 2019-09-10T16:11:10.966Z,1568131870.966 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2019-09-10T16:11:11.126Z,1568131871.126 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2019-09-10T16:11:11.127Z,1568131871.127 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2019-09-10T16:11:11.708Z,1568131871.708 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2019-09-10T16:11:11.708Z,1568131871.708 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2019-09-10T16:11:11.808Z,1568131871.808 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2019-09-10T16:11:11.809Z,1568131871.809 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2019-09-10T16:11:11.913Z,1568131871.913 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2019-09-10T16:11:11.914Z,1568131871.914 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2019-09-10T16:11:11.996Z,1568131871.996 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2019-09-10T16:11:12.138Z,1568131872.138 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2019-09-10T16:11:12.139Z,1568131872.139 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2019-09-10T16:11:12.443Z,1568131872.443 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2019-09-10T16:11:12.443Z,1568131872.443 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2019-09-10T16:11:12.914Z,1568131872.914 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2019-09-10T16:11:12.914Z,1568131872.914 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2019-09-10T16:11:13.063Z,1568131873.063 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2019-09-10T16:11:13.063Z,1568131873.063 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2019-09-10T16:11:13.269Z,1568131873.269 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2019-09-10T16:11:13.270Z,1568131873.270 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2019-09-10T16:11:13.735Z,1568131873.735 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2019-09-10T16:11:13.736Z,1568131873.736 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2019-09-10T16:11:13.956Z,1568131873.956 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2019-09-10T16:11:13.957Z,1568131873.957 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2019-09-10T16:11:14.164Z,1568131874.164 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2019-09-10T16:11:14.165Z,1568131874.165 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2019-09-10T16:11:14.567Z,1568131874.567 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2019-09-10T16:11:14.567Z,1568131874.567 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2019-09-10T16:11:14.913Z,1568131874.913 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2019-09-10T16:11:14.915Z,1568131874.915 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-pontus/ 2019-09-10T16:11:14.916Z,1568131874.916 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/secure.cfg 2019-09-10T16:11:15.001Z,1568131875.001 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Sensor.cfg 2019-09-10T16:11:15.164Z,1568131875.164 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Servo.cfg 2019-09-10T16:11:15.275Z,1568131875.275 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Simulator.cfg 2019-09-10T16:11:15.371Z,1568131875.371 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/logger.cfg 2019-09-10T16:11:16.429Z,1568131876.429 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/vehicle.cfg 2019-09-10T16:11:16.633Z,1568131876.633 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Battery.cfg 2019-09-10T16:11:16.864Z,1568131876.864 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2019-09-10T16:11:16.865Z,1568131876.865 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Navigation.cfg 2019-09-10T16:11:16.960Z,1568131876.960 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/BIT.cfg 2019-09-10T16:11:17.060Z,1568131877.060 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Science.cfg 2019-09-10T16:11:17.201Z,1568131877.201 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Control.cfg 2019-09-10T16:11:17.303Z,1568131877.303 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2019-09-10T16:11:17.308Z,1568131877.308 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2019-09-10T16:11:17.376Z,1568131877.376 [VerticalControl](DEBUG): Construct VerticalControl. 2019-09-10T16:11:17.491Z,1568131877.491 [VerticalControl] Loaded 2019-09-10T16:11:17.492Z,1568131877.492 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2019-09-10T16:11:17.492Z,1568131877.492 [HorizontalControl](DEBUG): Construct HorizontalControl. 2019-09-10T16:11:17.562Z,1568131877.562 [HorizontalControl] Loaded 2019-09-10T16:11:17.562Z,1568131877.562 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2019-09-10T16:11:17.563Z,1568131877.563 [SpeedControl](DEBUG): Construct SpeedControl. 2019-09-10T16:11:17.569Z,1568131877.569 [SpeedControl] Loaded 2019-09-10T16:11:17.569Z,1568131877.569 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2019-09-10T16:11:17.570Z,1568131877.570 [LoopControl](DEBUG): Construct LoopControl. 2019-09-10T16:11:17.570Z,1568131877.570 [LoopControl] Loaded 2019-09-10T16:11:17.571Z,1568131877.571 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2019-09-10T16:11:17.571Z,1568131877.571 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2019-09-10T16:11:17.572Z,1568131877.572 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2019-09-10T16:11:17.612Z,1568131877.612 [DepthRateCalculator] Loaded 2019-09-10T16:11:17.613Z,1568131877.613 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2019-09-10T16:11:17.618Z,1568131877.618 [PitchRateCalculator] Loaded 2019-09-10T16:11:17.618Z,1568131877.618 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2019-09-10T16:11:17.634Z,1568131877.634 [SpeedCalculator] Loaded 2019-09-10T16:11:17.634Z,1568131877.634 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2019-09-10T16:11:17.655Z,1568131877.655 [TempGradientCalculator] Loaded 2019-09-10T16:11:17.655Z,1568131877.655 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2019-09-10T16:11:17.660Z,1568131877.660 [YawRateCalculator] Loaded 2019-09-10T16:11:17.661Z,1568131877.661 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2019-09-10T16:11:17.690Z,1568131877.690 [ElevatorOffsetCalculator] Loaded 2019-09-10T16:11:17.691Z,1568131877.691 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2019-09-10T16:11:17.691Z,1568131877.691 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2019-09-10T16:11:17.692Z,1568131877.692 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2019-09-10T16:11:17.724Z,1568131877.724 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2019-09-10T16:11:17.724Z,1568131877.724 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2019-09-10T16:11:17.794Z,1568131877.794 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2019-09-10T16:11:17.794Z,1568131877.794 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2019-09-10T16:11:18.083Z,1568131878.083 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2019-09-10T16:11:18.084Z,1568131878.084 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2019-09-10T16:11:18.181Z,1568131878.181 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2019-09-10T16:11:18.182Z,1568131878.182 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2019-09-10T16:11:18.463Z,1568131878.463 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_orientation 2019-09-10T16:11:18.468Z,1568131878.468 [AHRS_M2](INFO): created writer for : platform_orientation 2019-09-10T16:11:18.470Z,1568131878.470 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_magnetic_orientation 2019-09-10T16:11:18.475Z,1568131878.475 [AHRS_M2](INFO): created writer for : platform_magnetic_orientation 2019-09-10T16:11:18.475Z,1568131878.475 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_pitch_angle 2019-09-10T16:11:18.480Z,1568131878.480 [AHRS_M2](INFO): created writer for : platform_pitch_angle 2019-09-10T16:11:18.481Z,1568131878.481 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_roll_angle 2019-09-10T16:11:18.486Z,1568131878.486 [AHRS_M2](INFO): created writer for : platform_roll_angle 2019-09-10T16:11:18.559Z,1568131878.559 [AHRS_M2] Loaded 2019-09-10T16:11:18.559Z,1568131878.559 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2019-09-10T16:11:18.633Z,1568131878.633 [DataOverHttps] Loaded 2019-09-10T16:11:18.633Z,1568131878.633 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2019-09-10T16:11:18.634Z,1568131878.634 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 408CA4E0 2019-09-10T16:11:18.634Z,1568131878.634 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 3724 2019-09-10T16:11:18.648Z,1568131878.648 [Depth_Keller] Loaded 2019-09-10T16:11:18.648Z,1568131878.648 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2019-09-10T16:11:18.653Z,1568131878.653 [DropWeight] Loaded 2019-09-10T16:11:18.653Z,1568131878.653 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2019-09-10T16:11:18.752Z,1568131878.752 [NAL9602] Loaded 2019-09-10T16:11:18.752Z,1568131878.752 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2019-09-10T16:11:18.768Z,1568131878.768 [Onboard] Loaded 2019-09-10T16:11:18.768Z,1568131878.768 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2019-09-10T16:11:18.771Z,1568131878.771 [Radio_Surface] Loaded 2019-09-10T16:11:18.772Z,1568131878.772 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2019-09-10T16:11:18.773Z,1568131878.773 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408FA4E0 2019-09-10T16:11:18.773Z,1568131878.773 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 3725 2019-09-10T16:11:18.819Z,1568131878.819 [RDI_Pathfinder] Loaded 2019-09-10T16:11:18.819Z,1568131878.819 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread. 2019-09-10T16:11:18.946Z,1568131878.946 [DAT] Loaded 2019-09-10T16:11:18.946Z,1568131878.946 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread. 2019-09-10T16:11:20.460Z,1568131880.460 [BPC1] Loaded 2019-09-10T16:11:20.460Z,1568131880.460 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2019-09-10T16:11:20.461Z,1568131880.461 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2019-09-10T16:11:20.461Z,1568131880.461 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2019-09-10T16:11:20.790Z,1568131880.790 [DeadReckonUsingMultipleVelocitySources] Loaded 2019-09-10T16:11:20.791Z,1568131880.791 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2019-09-10T16:11:20.900Z,1568131880.900 [NavChart] Loaded 2019-09-10T16:11:20.900Z,1568131880.900 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2019-09-10T16:11:20.906Z,1568131880.906 [UniversalFixResidualReporter] Loaded 2019-09-10T16:11:20.906Z,1568131880.906 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2019-09-10T16:11:20.907Z,1568131880.907 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2019-09-10T16:11:20.907Z,1568131880.907 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2019-09-10T16:11:21.043Z,1568131881.043 [SBIT](DEBUG): Construct Startup Built In Test. 2019-09-10T16:11:21.054Z,1568131881.054 [SBIT] Loaded 2019-09-10T16:11:21.054Z,1568131881.054 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2019-09-10T16:11:21.055Z,1568131881.055 [IBIT](DEBUG): Construct Initiated Built In Test. 2019-09-10T16:11:21.067Z,1568131881.067 [IBIT] Loaded 2019-09-10T16:11:21.067Z,1568131881.067 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2019-09-10T16:11:21.070Z,1568131881.070 [CBIT](DEBUG): Construct Continuous Built In Test. 2019-09-10T16:11:21.211Z,1568131881.211 [CBIT] Loaded 2019-09-10T16:11:21.212Z,1568131881.212 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2019-09-10T16:11:21.212Z,1568131881.212 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2019-09-10T16:11:21.213Z,1568131881.213 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2019-09-10T16:11:21.316Z,1568131881.316 [BuoyancyServo] Loaded 2019-09-10T16:11:21.316Z,1568131881.316 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2019-09-10T16:11:21.328Z,1568131881.328 [ElevatorServo] Loaded 2019-09-10T16:11:21.328Z,1568131881.328 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2019-09-10T16:11:21.339Z,1568131881.339 [MassServo] Loaded 2019-09-10T16:11:21.340Z,1568131881.340 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2019-09-10T16:11:21.351Z,1568131881.351 [RudderServo] Loaded 2019-09-10T16:11:21.351Z,1568131881.351 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2019-09-10T16:11:21.362Z,1568131881.362 [ThrusterServo] Loaded 2019-09-10T16:11:21.362Z,1568131881.362 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2019-09-10T16:11:21.363Z,1568131881.363 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2019-09-10T16:11:21.363Z,1568131881.363 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2019-09-10T16:11:21.377Z,1568131881.377 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2019-09-10T16:11:21.377Z,1568131881.377 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2019-09-10T16:11:21.549Z,1568131881.549 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_density 2019-09-10T16:11:21.554Z,1568131881.554 [CTD_Seabird](INFO): created writer for : sea_water_density 2019-09-10T16:11:21.554Z,1568131881.554 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): depth 2019-09-10T16:11:21.559Z,1568131881.559 [CTD_Seabird](INFO): created writer for : depth 2019-09-10T16:11:21.560Z,1568131881.560 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_pressure 2019-09-10T16:11:21.565Z,1568131881.565 [CTD_Seabird](INFO): created writer for : sea_water_pressure 2019-09-10T16:11:21.565Z,1568131881.565 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_salinity 2019-09-10T16:11:21.571Z,1568131881.571 [CTD_Seabird](INFO): created writer for : sea_water_salinity 2019-09-10T16:11:21.571Z,1568131881.571 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_temperature 2019-09-10T16:11:21.576Z,1568131881.576 [CTD_Seabird](INFO): created writer for : sea_water_temperature 2019-09-10T16:11:21.577Z,1568131881.577 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_electrical_conductivity 2019-09-10T16:11:21.582Z,1568131881.582 [CTD_Seabird](INFO): created writer for : sea_water_electrical_conductivity 2019-09-10T16:11:21.583Z,1568131881.583 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): speed_of_sound_in_sea_water 2019-09-10T16:11:21.588Z,1568131881.588 [CTD_Seabird](INFO): created writer for : speed_of_sound_in_sea_water 2019-09-10T16:11:21.616Z,1568131881.616 [CTD_Seabird] Loaded 2019-09-10T16:11:21.616Z,1568131881.616 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2019-09-10T16:11:21.617Z,1568131881.617 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40A7F4E0 2019-09-10T16:11:21.618Z,1568131881.618 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 3726 2019-09-10T16:11:21.667Z,1568131881.667 [WetLabsBB2FL] Loaded 2019-09-10T16:11:21.668Z,1568131881.668 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2019-09-10T16:11:21.669Z,1568131881.669 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40AAF4E0 2019-09-10T16:11:21.669Z,1568131881.669 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 3727 2019-09-10T16:11:21.683Z,1568131881.683 [WetLabsUBAT..SerialDriver](INFO): Created logger 2019-09-10T16:11:21.683Z,1568131881.683 [WetLabsUBAT..SerialDriver](INFO): publishing on LCM channel WetLabsUBAT 2019-09-10T16:11:21.684Z,1568131881.684 [WetLabsUBAT..StreamSerialDriver](INFO): Created logger 2019-09-10T16:11:21.689Z,1568131881.689 [WetLabsUBAT](INFO): readConfig(): serialNo_: UBAT0051, uartName_: /dev/ttyC1, optionalArgs_: -ldir /mnt/mmc/LRAUV/Logs/latest 2019-09-10T16:11:21.689Z,1568131881.689 [WetLabsUBAT](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsUBAT.biolum_potential 2019-09-10T16:11:21.689Z,1568131881.689 [WetLabsUBAT](DEBUG): LcmSlateWriter::add(): dataName: biolum_potential 2019-09-10T16:11:21.694Z,1568131881.694 [WetLabsUBAT](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsUBAT.flow_rate 2019-09-10T16:11:21.694Z,1568131881.694 [WetLabsUBAT](DEBUG): LcmSlateWriter::add(): dataName: flow_rate 2019-09-10T16:11:21.698Z,1568131881.698 [WetLabsUBAT] Loaded 2019-09-10T16:11:21.698Z,1568131881.698 [ComponentRegistry](DEBUG): Component "WetLabsUBAT" handled in its own thread. 2019-09-10T16:11:21.699Z,1568131881.699 [WetLabsUBAT ThreadHandler](DEBUG): Created PCaller Thread at 40ADF4E0 2019-09-10T16:11:21.700Z,1568131881.700 [WetLabsUBAT ThreadHandler](INFO): Protected caller Thread ID is 3728 2019-09-10T16:11:21.700Z,1568131881.700 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2019-09-10T16:11:21.704Z,1568131881.704 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2019-09-10T16:11:21.705Z,1568131881.705 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2019-09-10T16:11:21.711Z,1568131881.711 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2019-09-10T16:11:21.712Z,1568131881.712 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B0F4E0 2019-09-10T16:11:21.713Z,1568131881.713 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 3729 2019-09-10T16:11:21.718Z,1568131881.718 [Supervisor](INFO): Main Thread ID is 803 2019-09-10T16:11:21.718Z,1568131881.718 [Supervisor](DEBUG): Running supervisor. 2019-09-10T16:11:21.718Z,1568131881.718 [CommandLine ThreadHandler](INFO): Handler Thread ID is 3730 2019-09-10T16:11:21.721Z,1568131881.721 [controlThread ThreadHandler](INFO): Handler Thread ID is 3731 2019-09-10T16:11:21.721Z,1568131881.721 [controlThread](DEBUG): Initializing ControlThread 2019-09-10T16:11:21.722Z,1568131881.722 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2019-09-10T16:11:21.724Z,1568131881.724 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2019-09-10T16:11:21.724Z,1568131881.724 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2019-09-10T16:11:21.725Z,1568131881.725 [LoopControl](DEBUG): Initialize LoopControlComponent. 2019-09-10T16:11:21.725Z,1568131881.725 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2019-09-10T16:11:21.726Z,1568131881.726 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2019-09-10T16:11:21.726Z,1568131881.726 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2019-09-10T16:11:21.726Z,1568131881.726 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2019-09-10T16:11:21.727Z,1568131881.727 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2019-09-10T16:11:21.727Z,1568131881.727 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2019-09-10T16:11:21.732Z,1568131881.732 [NavChart](DEBUG): Initialize NavChart Navigation. 2019-09-10T16:11:21.732Z,1568131881.732 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2019-09-10T16:11:21.732Z,1568131881.732 [SBIT](INFO): Initialize SBIT Component. 2019-09-10T16:11:21.733Z,1568131881.733 [SBIT](IMPORTANT): git: 2019-09-10 2019-09-10T16:11:21.733Z,1568131881.733 [SBIT](INFO): git hash: e950883795b57abbf97d89589ea0268241928c93 2019-09-10T16:11:21.734Z,1568131881.734 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2019-09-10T16:11:21.734Z,1568131881.734 [SBIT](IMPORTANT): Kernel Version:#1 PREEMPT Thu Feb 21 11:17:40 PST 2019 2019-09-10T16:11:21.735Z,1568131881.735 [SBIT](INFO): Beginning SBIT in 59.000000 seconds. 2019-09-10T16:11:21.735Z,1568131881.735 [IBIT](INFO): Initialize IBIT Component. 2019-09-10T16:11:21.736Z,1568131881.736 [CBIT](DEBUG): Initialize CBIT Component. 2019-09-10T16:11:21.737Z,1568131881.737 [logger ThreadHandler](INFO): Handler Thread ID is 3732 2019-09-10T16:11:21.749Z,1568131881.749 [CBIT](DEBUG): Initialized mux pins. 2019-09-10T16:11:21.749Z,1568131881.749 [CBIT](DEBUG): Initializing the watchdog timer. 2019-09-10T16:11:21.757Z,1568131881.757 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 3733 2019-09-10T16:11:21.758Z,1568131881.758 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2019-09-10T16:11:21.769Z,1568131881.769 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 3734 2019-09-10T16:11:21.773Z,1568131881.773 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2019-09-10T16:11:21.773Z,1568131881.773 [CBIT](DEBUG): Initializing heartbeat. 2019-09-10T16:11:21.781Z,1568131881.781 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 3735 2019-09-10T16:11:21.782Z,1568131881.782 [CTD_Seabird](DEBUG): Initializing CTD_Seabird. 2019-09-10T16:11:21.785Z,1568131881.785 [CTD_Seabird](INFO): Opening uart, block timeout 10ths=20 2019-09-10T16:11:21.786Z,1568131881.786 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 3737 2019-09-10T16:11:21.788Z,1568131881.788 [WetLabsBB2FL](INFO): Powering down 2019-09-10T16:11:21.817Z,1568131881.817 [WetLabsUBAT ThreadHandler](INFO): Handler Thread ID is 3738 2019-09-10T16:11:21.829Z,1568131881.829 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 3739 2019-09-10T16:11:21.835Z,1568131881.835 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2019-09-10T16:11:21.835Z,1568131881.835 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2019-09-10T16:11:21.835Z,1568131881.835 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2019-09-10T16:11:21.835Z,1568131881.835 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2019-09-10T16:11:21.835Z,1568131881.835 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2019-09-10T16:11:21.835Z,1568131881.835 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2019-09-10T16:11:21.836Z,1568131881.836 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000 2019-09-10T16:11:21.836Z,1568131881.836 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2019-09-10T16:11:21.836Z,1568131881.836 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2019-09-10T16:11:21.836Z,1568131881.836 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2019-09-10T16:11:21.836Z,1568131881.836 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000 2019-09-10T16:11:21.837Z,1568131881.837 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2019-09-10T16:11:21.837Z,1568131881.837 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000 2019-09-10T16:11:21.837Z,1568131881.837 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2019-09-10T16:11:21.837Z,1568131881.837 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000 2019-09-10T16:11:21.837Z,1568131881.837 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2019-09-10T16:11:21.845Z,1568131881.845 [CBIT](DEBUG): Deactivating GF circuits. 2019-09-10T16:11:21.845Z,1568131881.845 [CBIT](DEBUG): Deactivating emergency mode. 2019-09-10T16:11:21.881Z,1568131881.881 [CBIT](DEBUG): Backplane powered. 2019-09-10T16:11:21.883Z,1568131881.883 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2019-09-10T16:11:21.894Z,1568131881.894 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2019-09-10T16:11:21.913Z,1568131881.913 [MissionManager](DEBUG): 2019-09-10T16:11:21.914Z,1568131881.914 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2019-09-10T16:11:21.997Z,1568131881.997 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2019-09-10T16:11:21.998Z,1568131881.998 [Default:A.Wait](DEBUG): Construct Wait. 2019-09-10T16:11:21.000Z,1568131882.000 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2019-09-10T16:11:22.031Z,1568131882.031 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2019-09-10T16:11:22.042Z,1568131882.042 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2019-09-10T16:11:22.047Z,1568131882.047 [Default:E.Execute](DEBUG): Construct Execute. 2019-09-10T16:11:22.071Z,1568131882.071 [MissionManager](DEBUG): 0 Wait a moment to see if the scheduler starts a new mission before starting to actually run Default. 13 Burn on Dropped weight due to communications timeout. 5 Default mission has been running for Restarting logs and Default mission. restart logs 2019-09-10T16:11:22.075Z,1568131882.075 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,NAL9602,Onboard,RDI_Pathfinder,DAT,BPC1,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2019-09-10T16:11:22.085Z,1568131882.085 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2019-09-10T16:11:22.152Z,1568131882.152 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2 2019-09-10T16:11:22.152Z,1568131882.152 [DAT](INFO): Powering up 2019-09-10T16:11:22.152Z,1568131882.152 [DAT](DEBUG): Initializing DAT. 2019-09-10T16:11:22.173Z,1568131882.173 [Radio_Surface](INFO): Powering up 2019-09-10T16:11:22.217Z,1568131882.217 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2 2019-09-10T16:11:22.248Z,1568131882.248 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2019-09-10T16:11:22.253Z,1568131882.253 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2019-09-10T16:11:22.255Z,1568131882.255 [ElevatorServo](DEBUG): Initializing EZServoServo. 2019-09-10T16:11:22.265Z,1568131882.265 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2019-09-10T16:11:22.266Z,1568131882.266 [MassServo](DEBUG): Initializing EZServoServo. 2019-09-10T16:11:22.277Z,1568131882.277 [MassServo](DEBUG): Initializing MassServo. 2019-09-10T16:11:22.278Z,1568131882.278 [RudderServo](DEBUG): Initializing EZServoServo. 2019-09-10T16:11:22.290Z,1568131882.290 [RudderServo](DEBUG): Initializing RudderServo. 2019-09-10T16:11:22.291Z,1568131882.291 [ThrusterServo](DEBUG): Initializing EZServoServo. 2019-09-10T16:11:22.301Z,1568131882.301 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2019-09-10T16:11:23.245Z,1568131883.245 [RudderServo](ERROR): Rudder initialization uart error serial timeout 2019-09-10T16:11:23.245Z,1568131883.245 [RudderServo](FAULT): Rudder failed to initialize 2019-09-10T16:11:23.245Z,1568131883.245 [RudderServo] Communications Fault, FailCount= 1 2019-09-10T16:11:23.245Z,1568131883.245 [RudderServo](ERROR): Communications Fault 2019-09-10T16:11:23.356Z,1568131883.356 [CBIT](ERROR): Communications Fault in component: RudderServo 2019-09-10T16:11:23.534Z,1568131883.534 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2019-09-10T16:11:23.534Z,1568131883.534 [RudderServo](INFO): Powering down 2019-09-10T16:11:24.201Z,1568131884.201 [RudderServo](DEBUG): Initializing EZServoServo. 2019-09-10T16:11:24.322Z,1568131884.322 [RudderServo](DEBUG): Initializing RudderServo. 2019-09-10T16:11:24.326Z,1568131884.326 [CBIT](INFO): Clearing failed state for component RudderServo 2019-09-10T16:11:24.326Z,1568131884.326 [RudderServo] No Fault, FailCount= 1 2019-09-10T16:11:35.559Z,1568131895.559 [RDI_Pathfinder](ERROR): Failed to parse:Pathfinder 2019-09-10T16:11:48.862Z,1568131908.862 [NAL9602](INFO): Powering up NAL9602 2019-09-10T16:11:59.770Z,1568131919.770 [NAL9602](INFO): NAL9602 initialized 2019-09-10T16:12:00.601Z,1568131920.601 [NAL9602](DEBUG): Fix Requested 2019-09-10T16:12:21.244Z,1568131941.244 [SBIT](IMPORTANT): Beginning Startup BIT 2019-09-10T16:12:21.248Z,1568131941.248 [CBIT](IMPORTANT): Beginning ground fault scan 2019-09-10T16:12:22.428Z,1568131942.428 [DAT](FAULT): failed to initialize; deviceResponse_ loaded: , available: 2019-09-10T16:12:22.428Z,1568131942.428 [DAT] Communications Fault, FailCount= 1 2019-09-10T16:12:22.428Z,1568131942.428 [DAT](ERROR): Communications Fault 2019-09-10T16:12:22.494Z,1568131942.494 [CBIT](ERROR): Communications Fault in component: DAT 2019-09-10T16:12:22.843Z,1568131942.843 [DAT](INFO): Powering down 2019-09-10T16:12:23.969Z,1568131943.969 [CBIT](INFO): Clearing failed state for component DAT 2019-09-10T16:12:23.969Z,1568131943.969 [DAT] No Fault, FailCount= 1 2019-09-10T16:12:26.233Z,1568131946.233 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2 2019-09-10T16:12:26.234Z,1568131946.234 [DAT](INFO): Powering up 2019-09-10T16:12:26.234Z,1568131946.234 [DAT](DEBUG): Initializing DAT. 2019-09-10T16:12:26.281Z,1568131946.281 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2 2019-09-10T16:12:32.349Z,1568131952.349 [CBIT](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): -0.014817 CHAN A1 (24V): 0.040412 CHAN A2 (12V): -0.005278 CHAN A3 (5V): -0.001206 CHAN B0 (3.3V): 0.000925 CHAN B1 (3.15aV): -0.000117 CHAN B2 (3.15bV): 0.000486 CHAN B3 (GND): 0.001898 OPEN: 0.005903 Full Scale Calc: 4.765 mA, -1.589 mA 2019-09-10T16:13:14.984Z,1568131994.984 [SBIT](IMPORTANT): SBIT PASSED 2019-09-10T16:13:15.065Z,1568131995.065 [CommandLine](IMPORTANT): got command configSet list 2019-09-10T16:13:15.066Z,1568131995.066 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2019-09-10T16:13:15.066Z,1568131995.066 [CommandLine](IMPORTANT): VerticalControl.massDefault=10 millimeter; 2019-09-10T16:13:15.378Z,1568131995.378 [MissionManager](IMPORTANT): Started mission Startup 2019-09-10T16:13:15.378Z,1568131995.378 [Startup] Running Loop=1 2019-09-10T16:13:15.378Z,1568131995.378 [Startup](DEBUG): Aggregate::initialize Startup 2019-09-10T16:13:15.378Z,1568131995.378 [Startup:A.GoToSurface] Running Loop=1 2019-09-10T16:13:15.379Z,1568131995.379 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2019-09-10T16:13:15.379Z,1568131995.379 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2019-09-10T16:13:15.380Z,1568131995.380 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2019-09-10T16:13:15.380Z,1568131995.380 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2019-09-10T16:13:15.380Z,1568131995.380 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2019-09-10T16:13:15.381Z,1568131995.381 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2019-09-10T16:13:15.382Z,1568131995.382 [Startup:StartupSatComms] Running Loop=1 2019-09-10T16:13:15.382Z,1568131995.382 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2019-09-10T16:13:15.383Z,1568131995.383 [Startup:StartupSatComms:A] Running Loop=1 2019-09-10T16:13:15.804Z,1568131995.804 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2019-09-10T16:13:26.271Z,1568132006.271 [DAT](FAULT): failed to initialize; deviceResponse_ loaded: , available: 2019-09-10T16:13:26.271Z,1568132006.271 [DAT] Communications Fault, FailCount= 2 2019-09-10T16:13:26.271Z,1568132006.271 [DAT](ERROR): Communications Fault 2019-09-10T16:13:26.294Z,1568132006.294 [CBIT](ERROR): Communications Fault in component: DAT 2019-09-10T16:13:26.698Z,1568132006.698 [DAT](INFO): Powering down 2019-09-10T16:13:27.530Z,1568132007.530 [CBIT](INFO): Clearing failed state for component DAT 2019-09-10T16:13:27.530Z,1568132007.530 [DAT] No Fault, FailCount= 2 2019-09-10T16:13:29.916Z,1568132009.916 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2 2019-09-10T16:13:29.917Z,1568132009.917 [DAT](INFO): Powering up 2019-09-10T16:13:29.917Z,1568132009.917 [DAT](DEBUG): Initializing DAT. 2019-09-10T16:13:29.989Z,1568132009.989 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2 2019-09-10T16:14:15.578Z,1568132055.578 [Startup:StartupSatComms:A](INFO): Timed out from 2019-09-10T16:13:15.4Z 2019-09-10T16:14:15.578Z,1568132055.578 [Startup:StartupSatComms:A] Stopped 2019-09-10T16:14:15.578Z,1568132055.578 [Startup:StartupSatComms:B] Running Loop=1 2019-09-10T16:14:15.969Z,1568132055.969 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2019-09-10T16:14:22.026Z,1568132062.026 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2019-09-10T16:14:22.026Z,1568132062.026 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-09-10T16:14:22.054Z,1568132062.054 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-09-10T16:14:22.461Z,1568132062.461 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-09-10T16:14:22.461Z,1568132062.461 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2019-09-10T16:14:30.097Z,1568132070.097 [DAT](FAULT): failed to initialize; deviceResponse_ loaded: , available: 2019-09-10T16:14:30.097Z,1568132070.097 [DAT] Communications Fault, FailCount= 3 2019-09-10T16:14:30.097Z,1568132070.097 [DAT](ERROR): Communications Fault 2019-09-10T16:14:30.137Z,1568132070.137 [CBIT](ERROR): Communications Fault in component: DAT 2019-09-10T16:14:30.540Z,1568132070.540 [DAT](INFO): Powering down 2019-09-10T16:14:31.398Z,1568132071.398 [CBIT](INFO): Clearing failed state for component DAT 2019-09-10T16:14:31.398Z,1568132071.398 [DAT] No Fault, FailCount= 3 2019-09-10T16:14:33.739Z,1568132073.739 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2 2019-09-10T16:14:33.739Z,1568132073.739 [DAT](INFO): Powering up 2019-09-10T16:14:33.739Z,1568132073.739 [DAT](DEBUG): Initializing DAT. 2019-09-10T16:14:33.821Z,1568132073.821 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2 2019-09-10T16:14:46.124Z,1568132086.124 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004888 2019-09-10T16:14:55.496Z,1568132095.496 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190910T062837/Courier0310.lzma 2019-09-10T16:14:57.503Z,1568132097.503 [DataOverHttps](INFO): Moved sent file to Logs/20190910T062837/Courier0310.lzma.bak 2019-09-10T16:14:57.503Z,1568132097.503 [DataOverHttps](INFO): SBD MOMSN=11763118 2019-09-10T16:15:15.778Z,1568132115.778 [Startup:StartupSatComms:B](INFO): Timed out from 2019-09-10T16:14:15.6Z 2019-09-10T16:15:15.778Z,1568132115.778 [Startup:StartupSatComms:B] Stopped 2019-09-10T16:15:15.778Z,1568132115.778 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2019-09-10T16:15:15.778Z,1568132115.778 [Startup:StartupSatComms] Stopped 2019-09-10T16:15:15.779Z,1568132115.779 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2019-09-10T16:15:15.779Z,1568132115.779 [Startup](INFO): Completed Startup 2019-09-10T16:15:15.779Z,1568132115.779 [MissionManager](INFO): Startup is completed. 2019-09-10T16:15:15.780Z,1568132115.780 [MissionManager](INFO): Uninitializing Mission Startup 2019-09-10T16:15:15.780Z,1568132115.780 [Startup] Stopped 2019-09-10T16:15:15.780Z,1568132115.780 [Startup](DEBUG): Aggregate::uninitialize Startup 2019-09-10T16:15:15.780Z,1568132115.780 [Startup:A.GoToSurface] Stopped 2019-09-10T16:15:15.780Z,1568132115.780 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2019-09-10T16:15:16.175Z,1568132116.175 [MissionManager](IMPORTANT): Started mission Default 2019-09-10T16:15:16.175Z,1568132116.175 [Default] Running Loop=1 2019-09-10T16:15:16.175Z,1568132116.175 [Default](DEBUG): Aggregate::initialize Default 2019-09-10T16:15:16.175Z,1568132116.175 [Default:B.GoToSurface] Running Loop=1 2019-09-10T16:15:16.175Z,1568132116.175 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2019-09-10T16:15:16.176Z,1568132116.176 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2019-09-10T16:15:16.176Z,1568132116.176 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2019-09-10T16:15:16.176Z,1568132116.176 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2019-09-10T16:15:16.181Z,1568132116.181 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2019-09-10T16:15:16.181Z,1568132116.181 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2019-09-10T16:15:16.181Z,1568132116.181 [Default:A.Wait] Running Loop=1 2019-09-10T16:15:16.181Z,1568132116.181 [Default:A.Wait](DEBUG): Initialize Wait Component. 2019-09-10T16:15:18.066Z,1568132118.066 [DataOverHttps](INFO): Sending 685 bytes from file Logs/20190910T062837/Express0311.lzma 2019-09-10T16:15:20.073Z,1568132120.073 [DataOverHttps](INFO): Moved sent file to Logs/20190910T062837/Express0311.lzma.bak 2019-09-10T16:15:20.073Z,1568132120.073 [DataOverHttps](INFO): SBD MOMSN=11763120 2019-09-10T16:15:29.522Z,1568132129.522 [Default:A.Wait](INFO): Done Waiting. 2019-09-10T16:15:29.522Z,1568132129.522 [Default:A.Wait] Stopped 2019-09-10T16:15:29.522Z,1568132129.522 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2019-09-10T16:15:29.906Z,1568132129.906 [Default:CheckIn] Running Loop=1 2019-09-10T16:15:29.906Z,1568132129.906 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-09-10T16:15:29.906Z,1568132129.906 [Default:CheckIn:Read_GPS] Running Loop=1 2019-09-10T16:15:30.314Z,1568132130.314 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2019-09-10T16:15:32.768Z,1568132132.768 [RDI_Pathfinder](ERROR): Failed to parse: :SA, +0.00, +0.00, 0.00 2019-09-10T16:15:33.967Z,1568132133.967 [DAT](FAULT): failed to initialize; deviceResponse_ loaded: , available: 2019-09-10T16:15:33.967Z,1568132133.967 [DAT] Communications Fault, FailCount= 4 2019-09-10T16:15:33.967Z,1568132133.967 [DAT](ERROR): Communications Fault 2019-09-10T16:15:33.982Z,1568132133.982 [CBIT](ERROR): Communications Fault in component: DAT 2019-09-10T16:15:34.340Z,1568132134.340 [DAT](INFO): Powering down 2019-09-10T16:15:35.383Z,1568132135.383 [CBIT](INFO): Clearing failed state for component DAT 2019-09-10T16:15:35.384Z,1568132135.384 [DAT] No Fault, FailCount= 4 2019-09-10T16:15:37.607Z,1568132137.607 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2 2019-09-10T16:15:37.608Z,1568132137.608 [DAT](INFO): Powering up 2019-09-10T16:15:37.608Z,1568132137.608 [DAT](DEBUG): Initializing DAT. 2019-09-10T16:15:37.662Z,1568132137.662 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2 2019-09-10T16:16:37.775Z,1568132197.775 [DAT](FAULT): failed to initialize; deviceResponse_ loaded: , available: 2019-09-10T16:16:37.775Z,1568132197.775 [DAT] Communications Fault, FailCount= 5 2019-09-10T16:16:37.775Z,1568132197.775 [DAT](ERROR): Communications Fault 2019-09-10T16:16:37.848Z,1568132197.848 [CBIT](ERROR): Communications Fault in component: DAT 2019-09-10T16:16:38.174Z,1568132198.174 [DAT](INFO): Powering down 2019-09-10T16:16:39.022Z,1568132199.022 [CBIT](INFO): Clearing failed state for component DAT 2019-09-10T16:16:39.022Z,1568132199.022 [DAT] No Fault, FailCount= 5 2019-09-10T16:16:41.412Z,1568132201.412 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2 2019-09-10T16:16:41.413Z,1568132201.413 [DAT](INFO): Powering up 2019-09-10T16:16:41.413Z,1568132201.413 [DAT](DEBUG): Initializing DAT. 2019-09-10T16:16:41.504Z,1568132201.504 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2 2019-09-10T16:17:03.202Z,1568132223.202 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-09-10T16:17:04.027Z,1568132224.027 [NAL9602](DEBUG): Fix Requested 2019-09-10T16:17:06.849Z,1568132226.849 [NAL9602](DEBUG): Fix Requested 2019-09-10T16:17:09.677Z,1568132229.677 [NAL9602](DEBUG): Fix Requested 2019-09-10T16:17:12.505Z,1568132232.505 [NAL9602](DEBUG): Fix Requested 2019-09-10T16:17:15.741Z,1568132235.741 [NAL9602](DEBUG): Fix Requested 2019-09-10T16:17:18.571Z,1568132238.571 [NAL9602](DEBUG): Fix Requested 2019-09-10T16:17:21.801Z,1568132241.801 [NAL9602](DEBUG): Fix Requested 2019-09-10T16:17:23.031Z,1568132243.031 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2 2019-09-10T16:17:23.031Z,1568132243.031 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-09-10T16:17:23.041Z,1568132243.041 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-09-10T16:17:23.448Z,1568132243.448 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-09-10T16:17:23.448Z,1568132243.448 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2 2019-09-10T16:17:24.629Z,1568132244.629 [NAL9602](DEBUG): Fix Requested 2019-09-10T16:17:27.865Z,1568132247.865 [NAL9602](DEBUG): Fix Requested 2019-09-10T16:17:30.689Z,1568132250.689 [NAL9602](DEBUG): Fix Requested 2019-09-10T16:17:33.513Z,1568132253.513 [NAL9602](DEBUG): Fix Requested 2019-09-10T16:17:36.749Z,1568132256.749 [NAL9602](DEBUG): Fix Requested 2019-09-10T16:17:39.577Z,1568132259.577 [NAL9602](DEBUG): Fix Requested 2019-09-10T16:17:41.609Z,1568132261.609 [DAT](FAULT): failed to initialize; deviceResponse_ loaded: , available: 2019-09-10T16:17:41.609Z,1568132261.609 [DAT] Communications Fault, FailCount= 6 2019-09-10T16:17:41.609Z,1568132261.609 [DAT](ERROR): Communications Fault 2019-09-10T16:17:41.640Z,1568132261.640 [CBIT](ERROR): Communications Fault in component: DAT 2019-09-10T16:17:42.012Z,1568132262.012 [DAT](INFO): Powering down 2019-09-10T16:17:42.801Z,1568132262.801 [NAL9602](DEBUG): Fix Requested 2019-09-10T16:17:42.863Z,1568132262.863 [CBIT](INFO): Clearing failed state for component DAT 2019-09-10T16:17:42.863Z,1568132262.863 [DAT] No Fault, FailCount= 6 2019-09-10T16:17:45.236Z,1568132265.236 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2 2019-09-10T16:17:45.236Z,1568132265.236 [DAT](INFO): Powering up 2019-09-10T16:17:45.236Z,1568132265.236 [DAT](DEBUG): Initializing DAT. 2019-09-10T16:17:45.257Z,1568132265.257 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2 2019-09-10T16:17:45.641Z,1568132265.641 [NAL9602](DEBUG): Fix Requested 2019-09-10T16:17:48.881Z,1568132268.881 [NAL9602](DEBUG): Fix Requested 2019-09-10T16:17:51.697Z,1568132271.697 [NAL9602](DEBUG): Fix Requested 2019-09-10T16:17:54.525Z,1568132274.525 [NAL9602](DEBUG): Fix Requested 2019-09-10T16:17:57.757Z,1568132277.757 [NAL9602](DEBUG): Fix Requested 2019-09-10T16:18:00.585Z,1568132280.585 [NAL9602](DEBUG): Fix Requested 2019-09-10T16:18:03.832Z,1568132283.832 [NAL9602](DEBUG): Fix Requested 2019-09-10T16:18:06.645Z,1568132286.645 [NAL9602](DEBUG): Fix Requested 2019-09-10T16:18:09.873Z,1568132289.873 [NAL9602](DEBUG): Fix Requested 2019-09-10T16:18:12.709Z,1568132292.709 [NAL9602](DEBUG): Fix Requested 2019-09-10T16:18:15.533Z,1568132295.533 [NAL9602](DEBUG): Fix Requested 2019-09-10T16:18:18.765Z,1568132298.765 [NAL9602](DEBUG): Fix Requested 2019-09-10T16:18:21.593Z,1568132301.593 [NAL9602](DEBUG): Fix Requested 2019-09-10T16:18:24.838Z,1568132304.838 [NAL9602](DEBUG): Fix Requested 2019-09-10T16:18:27.645Z,1568132307.645 [NAL9602](DEBUG): Fix Requested 2019-09-10T16:18:30.885Z,1568132310.885 [NAL9602](DEBUG): Fix Requested 2019-09-10T16:18:33.705Z,1568132313.705 [NAL9602](DEBUG): Fix Requested 2019-09-10T16:18:36.541Z,1568132316.541 [NAL9602](DEBUG): Fix Requested 2019-09-10T16:18:39.773Z,1568132319.773 [NAL9602](DEBUG): Fix Requested 2019-09-10T16:18:42.601Z,1568132322.601 [NAL9602](DEBUG): Fix Requested 2019-09-10T16:18:45.429Z,1568132325.429 [DAT](FAULT): failed to initialize; deviceResponse_ loaded: , available: 2019-09-10T16:18:45.429Z,1568132325.429 [DAT] Communications Fault, FailCount= 7 2019-09-10T16:18:45.429Z,1568132325.429 [DAT](ERROR): Communications Fault 2019-09-10T16:18:45.495Z,1568132325.495 [CBIT](ERROR): Communications Fault in component: DAT 2019-09-10T16:18:45.829Z,1568132325.829 [NAL9602](DEBUG): Fix Requested 2019-09-10T16:18:45.869Z,1568132325.869 [DAT](INFO): Powering down 2019-09-10T16:18:46.774Z,1568132326.774 [CBIT](INFO): Clearing failed state for component DAT 2019-09-10T16:18:46.774Z,1568132326.774 [DAT] No Fault, FailCount= 7 2019-09-10T16:18:48.653Z,1568132328.653 [NAL9602](DEBUG): Fix Requested 2019-09-10T16:18:49.082Z,1568132329.082 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2 2019-09-10T16:18:49.082Z,1568132329.082 [DAT](INFO): Powering up 2019-09-10T16:18:49.082Z,1568132329.082 [DAT](DEBUG): Initializing DAT. 2019-09-10T16:18:49.113Z,1568132329.113 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2 2019-09-10T16:18:51.893Z,1568132331.893 [NAL9602](DEBUG): Fix Requested 2019-09-10T16:18:53.538Z,1568132333.538 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2019-09-10T16:18:53.541Z,1568132333.541 [BPC1](INFO): Received data from all battery sticks. 2019-09-10T16:18:54.721Z,1568132334.721 [NAL9602](DEBUG): Fix Requested 2019-09-10T16:18:57.545Z,1568132337.545 [NAL9602](DEBUG): Fix Requested 2019-09-10T16:19:00.805Z,1568132340.805 [NAL9602](DEBUG): Fix Requested 2019-09-10T16:19:03.617Z,1568132343.617 [NAL9602](DEBUG): Fix Requested 2019-09-10T16:19:06.853Z,1568132346.853 [NAL9602](DEBUG): Fix Requested 2019-09-10T16:19:09.685Z,1568132349.685 [NAL9602](DEBUG): Fix Requested 2019-09-10T16:19:12.509Z,1568132352.509 [NAL9602](DEBUG): Fix Requested 2019-09-10T16:19:15.749Z,1568132355.749 [NAL9602](DEBUG): Fix Requested 2019-09-10T16:19:18.569Z,1568132358.569 [NAL9602](DEBUG): Fix Requested 2019-09-10T16:19:21.801Z,1568132361.801 [NAL9602](DEBUG): Fix Requested 2019-09-10T16:19:24.629Z,1568132364.629 [NAL9602](DEBUG): Fix Requested 2019-09-10T16:19:27.861Z,1568132367.861 [NAL9602](DEBUG): Fix Requested 2019-09-10T16:19:30.685Z,1568132370.685 [NAL9602](DEBUG): Fix Requested 2019-09-10T16:19:33.525Z,1568132373.525 [NAL9602](DEBUG): Fix Requested 2019-09-10T16:19:36.745Z,1568132376.745 [NAL9602](DEBUG): Fix Requested 2019-09-10T16:19:39.581Z,1568132379.581 [NAL9602](DEBUG): Fix Requested 2019-09-10T16:19:39.586Z,1568132379.586 [DataOverHttps](IMPORTANT): SBD MTMSN=20190910T161653 2019-09-10T16:19:42.809Z,1568132382.809 [NAL9602](DEBUG): Fix Requested 2019-09-10T16:19:45.645Z,1568132385.645 [NAL9602](DEBUG): Fix Requested 2019-09-10T16:19:47.093Z,1568132387.093 [DataOverHttps](INFO): Received command:! ls 2019-09-10T16:19:47.191Z,1568132387.191 [CommandLine](IMPORTANT): got command ! ls 2019-09-10T16:19:47.356Z,1568132387.356 [CommandLine](IMPORTANT): Config Data Logs Missions Modules Resources Tools auv-shared bin 2019-09-10T16:19:48.873Z,1568132388.873 [NAL9602](DEBUG): Fix Requested 2019-09-10T16:19:49.302Z,1568132389.302 [DAT](FAULT): failed to initialize; deviceResponse_ loaded: , available: 2019-09-10T16:19:49.302Z,1568132389.302 [DAT] Communications Fault, FailCount= 8 2019-09-10T16:19:49.302Z,1568132389.302 [DAT](ERROR): Communications Fault 2019-09-10T16:19:49.320Z,1568132389.320 [CBIT](ERROR): Communications Fault in component: DAT 2019-09-10T16:19:49.323Z,1568132389.323 [CBIT](CRITICAL): Communications Fault in component: DAT 2019-09-10T16:19:49.715Z,1568132389.715 [DAT](INFO): Powering down 2019-09-10T16:19:49.853Z,1568132389.853 [CommandLine](FAULT): Scheduling is paused 2019-09-10T16:19:49.854Z,1568132389.854 [CBIT](INFO): Critical error at 20190910T161949 2019-09-10T16:19:49.854Z,1568132389.854 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals 2019-09-10T16:19:51.713Z,1568132391.713 [NAL9602](DEBUG): Fix Requested 2019-09-10T16:19:54.935Z,1568132394.935 [NAL9602](DEBUG): Fix Requested 2019-09-10T16:19:57.761Z,1568132397.761 [NAL9602](DEBUG): Fix Requested 2019-09-10T16:20:00.997Z,1568132400.997 [NAL9602](DEBUG): Fix Requested 2019-09-10T16:20:03.825Z,1568132403.825 [NAL9602](DEBUG): Fix Requested 2019-09-10T16:20:07.049Z,1568132407.049 [NAL9602](DEBUG): Fix Requested 2019-09-10T16:20:09.881Z,1568132409.881 [NAL9602](DEBUG): Fix Requested 2019-09-10T16:20:12.710Z,1568132412.710 [NAL9602](DEBUG): Fix Requested 2019-09-10T16:20:15.937Z,1568132415.937 [NAL9602](DEBUG): Fix Requested 2019-09-10T16:20:18.773Z,1568132418.773 [NAL9602](DEBUG): Fix Requested 2019-09-10T16:20:21.589Z,1568132421.589 [NAL9602](DEBUG): Fix Requested 2019-09-10T16:20:24.044Z,1568132424.044 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3 2019-09-10T16:20:24.045Z,1568132424.045 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-09-10T16:20:24.055Z,1568132424.055 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-09-10T16:20:24.465Z,1568132424.465 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-09-10T16:20:24.465Z,1568132424.465 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3 2019-09-10T16:20:24.833Z,1568132424.833 [NAL9602](DEBUG): Fix Requested 2019-09-10T16:20:27.649Z,1568132427.649 [NAL9602](DEBUG): Fix Requested 2019-09-10T16:20:30.103Z,1568132430.103 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-09-10T16:15:29.9Z 2019-09-10T16:20:30.104Z,1568132430.104 [Default:CheckIn:Read_GPS] Stopped 2019-09-10T16:20:30.104Z,1568132430.104 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-09-10T16:20:30.515Z,1568132430.515 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2019-09-10T16:20:30.881Z,1568132430.881 [NAL9602](DEBUG): Fix Requested 2019-09-10T16:20:33.721Z,1568132433.721 [NAL9602](DEBUG): Fix Requested 2019-09-10T16:20:36.541Z,1568132436.541 [NAL9602](DEBUG): Fix Requested 2019-09-10T16:20:39.329Z,1568132439.329 [DataOverHttps](INFO): Sending 238 bytes from file Logs/20190910T161110/Courier0004.lzma 2019-09-10T16:20:39.773Z,1568132439.773 [NAL9602](DEBUG): Fix Requested 2019-09-10T16:20:40.164Z,1568132440.164 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,161754.00,A,3648.15569,N,12147.29357,W,0.408,282.40,100919,,,D*75 2019-09-10T16:20:40.176Z,1568132440.176 [NAL9602](INFO): GPS fix at 20190910T161754: (36.802595, -121.788226) 2019-09-10T16:20:41.334Z,1568132441.334 [DataOverHttps](INFO): Moved sent file to Logs/20190910T161110/Courier0004.lzma.bak 2019-09-10T16:20:41.334Z,1568132441.334 [DataOverHttps](INFO): SBD MOMSN=11763175 2019-09-10T16:21:10.576Z,1568132470.576 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190910T161110/Courier0007.lzma 2019-09-10T16:21:12.206Z,1568132472.206 [NAL9602](INFO): Not Powering down - fast GPS 2019-09-10T16:21:12.582Z,1568132472.582 [DataOverHttps](INFO): Moved sent file to Logs/20190910T161110/Courier0007.lzma.bak 2019-09-10T16:21:12.582Z,1568132472.582 [DataOverHttps](INFO): SBD MOMSN=11763201 2019-09-10T16:21:35.328Z,1568132495.328 [DataOverHttps](INFO): Sending 781 bytes from file Logs/20190910T161110/Express0001.lzma 2019-09-10T16:21:37.302Z,1568132497.302 [DataOverHttps](INFO): Moved sent file to Logs/20190910T161110/Express0001.lzma.bak 2019-09-10T16:21:37.303Z,1568132497.303 [DataOverHttps](INFO): SBD MOMSN=11763203 2019-09-10T16:21:50.952Z,1568132510.952 [CommandLine](IMPORTANT): got command ! ls -lah 2019-09-10T16:21:51.158Z,1568132511.158 [CommandLine](IMPORTANT): total 44K drwxr-xr-x 11 root root 4.0K Apr 2 23:16 . drwxr-xr-x 4 root root 4.0K Apr 2 23:02 .. drwxr-xr-x 21 root root 4.0K Sep 10 04:24 Config drwxr-xr-x 3 root root 4.0K Sep 10 16:11 Data drwxr-xr-x 102 root root 4.0K Sep 10 16:11 Logs drwxr-xr-x 11 root root 4.0K Mar 14 22:49 Missions drwxr-xr-x 2 root root 4.0K Sep 10 06:20 Modules drwxr-xr-x 4 root root 4.0K Jun 20 2018 Resources drwxr-xr-x 6 root root 4.0K Aug 21 19:10 Tools drwxr-xr-x 4 root root 4.0K Apr 10 16:53 auv-shared drwxr-xr-x 2 root root 4.0K Sep 10 06:18 bin 2019-09-10T16:21:58.294Z,1568132518.294 [DataOverHttps](INFO): Sending 451 bytes from file Logs/20190910T161110/Express0005.lzma 2019-09-10T16:22:00.300Z,1568132520.300 [DataOverHttps](INFO): Moved sent file to Logs/20190910T161110/Express0005.lzma.bak 2019-09-10T16:22:00.301Z,1568132520.301 [DataOverHttps](INFO): SBD MOMSN=11763223 2019-09-10T16:22:22.260Z,1568132542.260 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20190910T161110/Express0008.lzma 2019-09-10T16:22:24.266Z,1568132544.266 [DataOverHttps](INFO): Moved sent file to Logs/20190910T161110/Express0008.lzma.bak 2019-09-10T16:22:24.266Z,1568132544.266 [DataOverHttps](INFO): SBD MOMSN=11763244 2019-09-10T16:22:29.398Z,1568132549.398 [Default:CheckIn:Read_Iridium] Stopped 2019-09-10T16:22:29.398Z,1568132549.398 [Default:CheckIn:C.Wait] Running Loop=1 2019-09-10T16:22:29.398Z,1568132549.398 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-09-10T16:24:49.629Z,1568132689.629 [CBIT](INFO): Clearing failed state for component DAT 2019-09-10T16:24:49.629Z,1568132689.629 [DAT] No Fault, FailCount= 8 2019-09-10T16:24:49.994Z,1568132689.994 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2 2019-09-10T16:24:49.994Z,1568132689.994 [DAT](INFO): Powering up 2019-09-10T16:24:49.994Z,1568132689.994 [DAT](DEBUG): Initializing DAT. 2019-09-10T16:24:50.089Z,1568132690.089 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2 2019-09-10T16:25:04.156Z,1568132704.156 [DAT](INFO): setting local address to 4 2019-09-10T16:25:04.537Z,1568132704.537 [DAT](INFO): set local address to 4 2019-09-10T16:26:58.224Z,1568132818.224 [CommandLine](IMPORTANT): got command failComponent 2019-09-10T16:26:58.224Z,1568132818.224 [CommandLine](IMPORTANT): Failed components: 2019-09-10T16:26:58.224Z,1568132818.224 [CommandLine](IMPORTANT): No failed Components. 2019-09-10T16:27:29.998Z,1568132849.998 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-09-10T16:27:29.998Z,1568132849.998 [Default:CheckIn:C.Wait] Stopped 2019-09-10T16:27:29.998Z,1568132849.998 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-09-10T16:27:29.999Z,1568132849.999 [Default:CheckIn:D] Running Loop=1 2019-09-10T16:27:30.392Z,1568132850.392 [Default:CheckIn:D] Stopped 2019-09-10T16:27:30.392Z,1568132850.392 [Default:CheckIn:E] Running Loop=1 2019-09-10T16:27:30.823Z,1568132850.823 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 12.236945 min 2019-09-10T16:27:30.823Z,1568132850.823 [Default:CheckIn:E] Stopped 2019-09-10T16:27:30.824Z,1568132850.824 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-09-10T16:27:30.824Z,1568132850.824 [Default:CheckIn] Stopped 2019-09-10T16:27:30.824Z,1568132850.824 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-09-10T16:27:30.824Z,1568132850.824 [Default:CheckIn](INFO): Running loop #2 2019-09-10T16:27:30.824Z,1568132850.824 [Default:CheckIn] Running Loop=2 2019-09-10T16:27:30.824Z,1568132850.824 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-09-10T16:27:30.824Z,1568132850.824 [Default:CheckIn:Read_GPS] Running Loop=1 2019-09-10T16:27:32.401Z,1568132852.401 [NAL9602](DEBUG): Fix Requested 2019-09-10T16:28:03.135Z,1568132883.135 [DAT](FAULT): unknown deviceResponse_: 1FlowC E .6 | 0.), 15 -4..-P1), -14ms AAlt) 2019-09-10T16:28:03.135Z,1568132883.135 [DAT] Communications Fault, FailCount= 1 2019-09-10T16:28:03.135Z,1568132883.135 [DAT](ERROR): Communications Fault 2019-09-10T16:28:03.164Z,1568132883.164 [CBIT](ERROR): Communications Fault in component: DAT 2019-09-10T16:28:03.529Z,1568132883.529 [DAT](INFO): Powering down 2019-09-10T16:28:04.376Z,1568132884.376 [CBIT](INFO): Clearing failed state for component DAT 2019-09-10T16:28:04.376Z,1568132884.376 [DAT] No Fault, FailCount= 1 2019-09-10T16:28:06.799Z,1568132886.799 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2 2019-09-10T16:28:06.799Z,1568132886.799 [DAT](INFO): Powering up 2019-09-10T16:28:06.800Z,1568132886.800 [DAT](DEBUG): Initializing DAT. 2019-09-10T16:28:06.873Z,1568132886.873 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2 2019-09-10T16:29:06.963Z,1568132946.963 [DAT](FAULT): failed to initialize; deviceResponse_ loaded: , available: 2019-09-10T16:29:06.963Z,1568132946.963 [DAT] Communications Fault, FailCount= 2 2019-09-10T16:29:06.963Z,1568132946.963 [DAT](ERROR): Communications Fault 2019-09-10T16:29:06.980Z,1568132946.980 [CBIT](ERROR): Communications Fault in component: DAT 2019-09-10T16:29:07.361Z,1568132947.361 [DAT](INFO): Powering down 2019-09-10T16:29:08.192Z,1568132948.192 [CBIT](INFO): Clearing failed state for component DAT 2019-09-10T16:29:08.192Z,1568132948.192 [DAT] No Fault, FailCount= 2 2019-09-10T16:29:10.609Z,1568132950.609 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2 2019-09-10T16:29:10.609Z,1568132950.609 [DAT](INFO): Powering up 2019-09-10T16:29:10.610Z,1568132950.610 [DAT](DEBUG): Initializing DAT. 2019-09-10T16:29:10.658Z,1568132950.658 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2 2019-09-10T16:30:10.795Z,1568133010.795 [DAT](FAULT): failed to initialize; deviceResponse_ loaded: , available: 2019-09-10T16:30:10.795Z,1568133010.795 [DAT] Communications Fault, FailCount= 3 2019-09-10T16:30:10.795Z,1568133010.795 [DAT](ERROR): Communications Fault 2019-09-10T16:30:10.836Z,1568133010.836 [CBIT](ERROR): Communications Fault in component: DAT 2019-09-10T16:30:11.255Z,1568133011.255 [DAT](INFO): Powering down 2019-09-10T16:30:12.028Z,1568133012.028 [CBIT](INFO): Clearing failed state for component DAT 2019-09-10T16:30:12.028Z,1568133012.028 [DAT] No Fault, FailCount= 3 2019-09-10T16:30:14.427Z,1568133014.427 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2 2019-09-10T16:30:14.427Z,1568133014.427 [DAT](INFO): Powering up 2019-09-10T16:30:14.427Z,1568133014.427 [DAT](DEBUG): Initializing DAT. 2019-09-10T16:30:14.497Z,1568133014.497 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2 2019-09-10T16:30:28.584Z,1568133028.584 [DAT](INFO): setting local address to 4 2019-09-10T16:30:28.975Z,1568133028.975 [DAT](INFO): set local address to 4 2019-09-10T16:31:53.011Z,1568133113.011 [RDI_Pathfinder](ERROR): only read 3 of 4 data items 2019-09-10T16:31:53.011Z,1568133113.011 [RDI_Pathfinder](ERROR): Failed to parse: :BS,-32768,-32768,-32BE,-32768,-32768,-32768,V 2019-09-10T16:32:30.996Z,1568133150.996 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-09-10T16:27:30.8Z 2019-09-10T16:32:30.996Z,1568133150.996 [Default:CheckIn:Read_GPS] Stopped 2019-09-10T16:32:30.996Z,1568133150.996 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-09-10T16:32:34.702Z,1568133154.702 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-09-10T16:32:40.184Z,1568133160.184 [DataOverHttps](INFO): Sending 213 bytes from file Logs/20190910T161110/Courier0010.lzma 2019-09-10T16:32:42.191Z,1568133162.191 [DataOverHttps](INFO): Moved sent file to Logs/20190910T161110/Courier0010.lzma.bak 2019-09-10T16:32:42.191Z,1568133162.191 [DataOverHttps](INFO): SBD MOMSN=11763352 2019-09-10T16:33:04.237Z,1568133184.237 [DataOverHttps](INFO): Sending 692 bytes from file Logs/20190910T161110/Express0011.lzma 2019-09-10T16:33:05.402Z,1568133185.402 [NAL9602](INFO): Not Powering down - fast GPS 2019-09-10T16:33:06.261Z,1568133186.261 [DataOverHttps](INFO): Moved sent file to Logs/20190910T161110/Express0011.lzma.bak 2019-09-10T16:33:06.262Z,1568133186.262 [DataOverHttps](INFO): SBD MOMSN=11763355 2019-09-10T16:33:12.312Z,1568133192.312 [Default:CheckIn:Read_Iridium] Stopped 2019-09-10T16:33:12.312Z,1568133192.312 [Default:CheckIn:C.Wait] Running Loop=1 2019-09-10T16:33:12.312Z,1568133192.312 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-09-10T16:34:04.848Z,1568133244.848 [CommandLine](IMPORTANT): got command failComponent hardware DAT 2019-09-10T16:34:04.849Z,1568133244.849 [DAT] Hardware Fault, FailCount= 4 2019-09-10T16:34:04.849Z,1568133244.849 [DAT](ERROR): Hardware Fault 2019-09-10T16:34:04.849Z,1568133244.849 [CommandLine](IMPORTANT): DAT failureMode is Hardware Fault 2019-09-10T16:34:04.856Z,1568133244.856 [DAT](INFO): Powering down 2019-09-10T16:34:05.005Z,1568133245.005 [CBIT](ERROR): Hardware Fault in component: DAT 2019-09-10T16:34:05.718Z,1568133245.718 [CBIT](INFO): Clearing failed state for component DAT 2019-09-10T16:34:05.718Z,1568133245.718 [DAT] No Fault, FailCount= 4 2019-09-10T16:34:08.042Z,1568133248.042 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2 2019-09-10T16:34:08.042Z,1568133248.042 [DAT](INFO): Powering up 2019-09-10T16:34:08.042Z,1568133248.042 [DAT](DEBUG): Initializing DAT. 2019-09-10T16:34:08.052Z,1568133248.052 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2 2019-09-10T16:35:08.258Z,1568133308.258 [DAT](FAULT): failed to initialize; deviceResponse_ loaded: , available: Teledyne Benthos DAT-900 Series MF Frequency Band Directional Acoustic Transponder version 8.12.21 Sep 10 2019 16:31:18 Features enabled | | Rotation | 135.0 | 0 | MaxElev | 90.? 2019-09-10T16:35:08.258Z,1568133308.258 [DAT] Communications Fault, FailCount= 5 2019-09-10T16:35:08.258Z,1568133308.258 [DAT](ERROR): Communications Fault 2019-09-10T16:35:08.282Z,1568133308.282 [CBIT](ERROR): Communications Fault in component: DAT 2019-09-10T16:35:08.673Z,1568133308.673 [DAT](INFO): Powering down 2019-09-10T16:35:09.501Z,1568133309.501 [CBIT](INFO): Clearing failed state for component DAT 2019-09-10T16:35:09.501Z,1568133309.501 [DAT] No Fault, FailCount= 5 2019-09-10T16:35:11.893Z,1568133311.893 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2 2019-09-10T16:35:11.893Z,1568133311.893 [DAT](INFO): Powering up 2019-09-10T16:35:11.893Z,1568133311.893 [DAT](DEBUG): Initializing DAT. 2019-09-10T16:35:11.985Z,1568133311.985 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2 2019-09-10T16:36:12.068Z,1568133372.068 [DAT](FAULT): failed to initialize; deviceResponse_ loaded: , available: 2019-09-10T16:36:12.068Z,1568133372.068 [DAT] Communications Fault, FailCount= 6 2019-09-10T16:36:12.069Z,1568133372.069 [DAT](ERROR): Communications Fault 2019-09-10T16:36:12.106Z,1568133372.106 [CBIT](ERROR): Communications Fault in component: DAT 2019-09-10T16:36:12.472Z,1568133372.472 [DAT](INFO): Powering down 2019-09-10T16:36:13.310Z,1568133373.310 [CBIT](INFO): Clearing failed state for component DAT 2019-09-10T16:36:13.310Z,1568133373.310 [DAT] No Fault, FailCount= 6 2019-09-10T16:36:15.725Z,1568133375.725 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2 2019-09-10T16:36:15.725Z,1568133375.725 [DAT](INFO): Powering up 2019-09-10T16:36:15.725Z,1568133375.725 [DAT](DEBUG): Initializing DAT. 2019-09-10T16:36:15.789Z,1568133375.789 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2 2019-09-10T16:36:29.845Z,1568133389.845 [DAT](INFO): setting local address to 4 2019-09-10T16:36:30.254Z,1568133390.254 [DAT](INFO): set local address to 4 2019-09-10T16:38:12.921Z,1568133492.921 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-09-10T16:38:12.921Z,1568133492.921 [Default:CheckIn:C.Wait] Stopped 2019-09-10T16:38:12.921Z,1568133492.921 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-09-10T16:38:12.921Z,1568133492.921 [Default:CheckIn:D] Running Loop=1 2019-09-10T16:38:13.288Z,1568133493.288 [Default:CheckIn:D] Stopped 2019-09-10T16:38:13.288Z,1568133493.288 [Default:CheckIn:E] Running Loop=1 2019-09-10T16:38:13.699Z,1568133493.699 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 22.951878 min 2019-09-10T16:38:13.699Z,1568133493.699 [Default:CheckIn:E] Stopped 2019-09-10T16:38:13.699Z,1568133493.699 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-09-10T16:38:13.699Z,1568133493.699 [Default:CheckIn] Stopped 2019-09-10T16:38:13.699Z,1568133493.699 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-09-10T16:38:13.699Z,1568133493.699 [Default:CheckIn](INFO): Running loop #3 2019-09-10T16:38:13.699Z,1568133493.699 [Default:CheckIn] Running Loop=3 2019-09-10T16:38:13.700Z,1568133493.700 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-09-10T16:38:13.700Z,1568133493.700 [Default:CheckIn:Read_GPS] Running Loop=1 2019-09-10T16:38:15.270Z,1568133495.270 [NAL9602](FAULT): GPS failed to acquire within timeout. 2019-09-10T16:38:15.270Z,1568133495.270 [NAL9602] Data Fault, FailCount= 1 2019-09-10T16:38:15.270Z,1568133495.270 [NAL9602](ERROR): Data Fault 2019-09-10T16:38:15.316Z,1568133495.316 [CBIT](ERROR): Data Fault in component: NAL9602 2019-09-10T16:38:15.674Z,1568133495.674 [NAL9602](INFO): Powering down 2019-09-10T16:38:16.582Z,1568133496.582 [CBIT](INFO): Clearing failed state for component NAL9602 2019-09-10T16:38:16.582Z,1568133496.582 [NAL9602] No Fault, FailCount= 1 2019-09-10T16:38:45.986Z,1568133525.986 [NAL9602](INFO): Powering up NAL9602 2019-09-10T16:38:56.886Z,1568133536.886 [NAL9602](INFO): NAL9602 initialized 2019-09-10T16:38:57.705Z,1568133537.705 [NAL9602](DEBUG): Fix Requested 2019-09-10T16:39:25.256Z,1568133565.256 [DAT](FAULT): DAT uart error: serial buffer full 2019-09-10T16:39:25.256Z,1568133565.256 [DAT] Communications Fault, FailCount= 7 2019-09-10T16:39:25.256Z,1568133565.256 [DAT](ERROR): Communications Fault 2019-09-10T16:39:25.261Z,1568133565.261 [DAT](FAULT): unknown deviceResponse_: 1 223.9 2K 210.4 0 -0.3 -0 -0.1 -2.01G 193.4 00. 18 183.4 -0.1 -2.2 183.7 -0.1 -2.1 184.5 -0.0 -2.2 185.0 -0.1 -2.2 185.3 185.8 -0.1 -2.2 185.8 -0.1 -2.2 185.8 -0.1 -2.2 185.8 -0.1 -2.2 185.9 -0.1 -2.2 185.9 -0.1 -2.2 185.9 -0.1 -2.2 2019-09-10T16:39:25.271Z,1568133565.271 [DAT](FAULT): unknown deviceResponse_:  185.9 -0.1 -2.2 185.9 -0.1 -2.2 185.8 -0.1 -2.2 185.8 -0.1 -2.2tic Transponder| 2019-09-10T16:39:25.278Z,1568133565.278 [DAT](FAULT): unknown deviceResponse_: 0| *SWVersion | 8.12.21 *DBVersion | 1.1 | 2019-09-10T16:39:25.388Z,1568133565.388 [CBIT](ERROR): Communications Fault in component: DAT 2019-09-10T16:39:25.635Z,1568133565.635 [DAT](INFO): Powering down 2019-09-10T16:39:26.471Z,1568133566.471 [CBIT](INFO): Clearing failed state for component DAT 2019-09-10T16:39:26.471Z,1568133566.471 [DAT] No Fault, FailCount= 7 2019-09-10T16:39:28.828Z,1568133568.828 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2 2019-09-10T16:39:28.828Z,1568133568.828 [DAT](INFO): Powering up 2019-09-10T16:39:28.829Z,1568133568.829 [DAT](DEBUG): Initializing DAT. 2019-09-10T16:39:28.838Z,1568133568.838 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2 2019-09-10T16:40:29.022Z,1568133629.022 [DAT](FAULT): failed to initialize; deviceResponse_ loaded: , available: , 4800, 9600, 19200, 38400, | sec), 5 (96sec) 20| ^AuxInp | 3 (OEh(Off) | 0 (O(Datalog), | | (Manual-LP), | Dis 4| TxRate | 5 (800) | 1 (80), 2 (140), 3 (300), 4 (600), | | | 5 (800), 6 (1066), 7 (1200), | | | 8 (2400), 9 (2560), 10 (5120), | | | 11 (7680), 12 (10240), 13 (15360) | HeaderRate | 2 (140) | 1 (80), 2 (140) 6| TxPower | 8 (Max) | 1 (-21dB), 2 (-18dB), 3 (-15dB), | | | 4 (-12dB), 5 (-9dB), 6 (-6dB), | | | 7 (-3dB), 8 (Max) 17| WakeTones | Ena | Ena, Dis | AutoDetectHdr | Dis | Ena, Dis | ^ChirpThresh | 27 | 15..27 | AddrGroup | 0 | 0..4 S| Release Params | Value | Range --+---- | 0..65535 50| TimedRelease | 0 | Release in 0-999 hours |5Q | 10 | 0..10 | RlsMaxEnaTime | 40 | 10..120 S| Transport Params| Value | Range --+------------------+-------------+------------------------------------- | ^L4Enable | Ena | Ena, Dis | TPortMode | 0 (InpMode) | 0 (InpMode), 1 (AlwaysOn) | SrcP1 | 1 | 1..4 | SrcP2 | 2 | 1..4 | Dst1 | 1 (P1) | 1 (P1), 2 (P2) | Dst2 | 2 (P2) | 1 (P1), 2 (P2) | Dst3 | 1 (P1) | 1 (P1), 2 (P2) | Dst4 | 2 (P2) | 1 (P1), 2 (P2) S| Test Params | Value | Range --+------------------+-------------+------------------------------------- | ^DbgLvl | 0 | 0..2147483647 | RcvAll | Dis | Ena, Dis 42| ^RspDelay | Dis | Ena, Dis 12| PktEcho | Dis | Ena, Dis 12| PktSize | 0 (8B) | 0 (8B), 1 (32B), 2 (128B), 3 (256B), | | | 4 (512B), 5 (1024B), 6 (2048B), | | | 7 (4096B) | SimAcDly | 0 | 0..30000 ms | ^Arrival | 0 | 1 (First), 0 (Peak) S| Xpnd Params | Value | Range --+------------------+-------------+------------------------------------- 53| RxFreq | 10000 | 250 Hz steps within frequency band | RxToneDur | 10 (10ms) | 0 (12.5ms), 1 (6.25ms), 5 (5ms), | | | 6 (6ms), 7 (7ms), 8 (8ms), 9 (9ms), | | | 10 (10ms), 11 (11ms), 12 (12ms), | | | 13 (13ms), 14 (14ms), 15 (15ms) 21| RxThresh | 100 | 10..999 55| RxLockout | 30 | 10..1500 (ms) | TxToneDur | 10 (10ms) | 0 (12.5ms), 1 (6.25ms), 5 (5ms), | | | 6 (6ms), 7 (7ms), 8 (8ms), 9 (9ms), | | | 10 (10ms), 11 (11ms), 12 (12ms), | | | 13 (13ms), 14 (14ms), 15 (15ms) 40| TAT | 300 | 0..2000, 0.1 ms steps 58| ^AGCRef | 60 | 10..80 | RespFreq | 11000 | 250 Hz steps within frequency band | LBLmode | 0 (Off) | 0 (Off), 1 (Tone), 2 (Listen), | | | 3 (Chirp) | Responder | 0 (Off) | 0 (Off), 1 (Rise), 2 (Fall) | ChirpResp | 1 (Down) | 0 (Up), 1 (Down) | ^XpndBW | 9 (9kHz) | 5 (5kHz), 9 (9kHz) | ^XpndLog | Dis | Ena, Dis S| Dat Params | Value | Range --+------------------+-------------+------------------------------------- | DatVerbose | 27440 | 0..65535 | RXonDAT | Dis | Ena, Dis | PreGain | 0 | -89..89 | Rotation | 135.0 | 0 to 359.9 degrees | Orientation | 0 (up) | 0 (up), 1 (down), 2 (fwd) | ^PhaseA | -0.034 | radians @? 2019-09-10T16:40:29.022Z,1568133629.022 [DAT] Communications Fault, FailCount= 8 2019-09-10T16:40:29.022Z,1568133629.022 [DAT](ERROR): Communications Fault 2019-09-10T16:40:29.039Z,1568133629.039 [CBIT](ERROR): Communications Fault in component: DAT 2019-09-10T16:40:29.039Z,1568133629.039 [CBIT](CRITICAL): Communications Fault in component: DAT 2019-09-10T16:40:29.493Z,1568133629.493 [DAT](INFO): Powering down 2019-09-10T16:40:29.630Z,1568133629.630 [CBIT](INFO): Critical error at 20190910T164029 2019-09-10T16:43:13.887Z,1568133793.887 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-09-10T16:38:13.7Z 2019-09-10T16:43:13.887Z,1568133793.887 [Default:CheckIn:Read_GPS] Stopped 2019-09-10T16:43:13.887Z,1568133793.887 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-09-10T16:43:25.124Z,1568133805.124 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20190910T161110/Courier0013.lzma 2019-09-10T16:43:27.130Z,1568133807.130 [DataOverHttps](INFO): Moved sent file to Logs/20190910T161110/Courier0013.lzma.bak 2019-09-10T16:43:27.130Z,1568133807.130 [DataOverHttps](INFO): SBD MOMSN=11763398 2019-09-10T16:43:51.991Z,1568133831.991 [DataOverHttps](INFO): Sending 1780 bytes from file Logs/20190910T161110/Express0014.lzma 2019-09-10T16:43:53.994Z,1568133833.994 [DataOverHttps](INFO): Moved sent file to Logs/20190910T161110/Express0014.lzma.bak 2019-09-10T16:43:53.994Z,1568133833.994 [DataOverHttps](INFO): SBD MOMSN=11763401 2019-09-10T16:44:00.327Z,1568133840.327 [Default:CheckIn:Read_Iridium] Stopped 2019-09-10T16:44:00.327Z,1568133840.327 [Default:CheckIn:C.Wait] Running Loop=1 2019-09-10T16:44:00.328Z,1568133840.328 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-09-10T16:44:04.743Z,1568133844.743 [NAL9602](INFO): SBD MO Status=2, MOMSN=685, MT Status=2, MTMSN=0 2019-09-10T16:44:04.744Z,1568133844.744 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-09-10T16:44:05.142Z,1568133845.142 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-09-10T16:44:35.845Z,1568133875.845 [NAL9602](INFO): Not Powering down - fast GPS 2019-09-10T16:44:44.798Z,1568133884.798 [RDI_Pathfinder](ERROR): only read 3 of 4 data items 2019-09-10T16:44:44.798Z,1568133884.798 [RDI_Pathfinder](ERROR): Failed to parse: :RA, 0.00, 0.00, 0.00, 0.00 2019-09-10T16:45:29.249Z,1568133929.249 [CBIT](INFO): Clearing failed state for component DAT 2019-09-10T16:45:29.249Z,1568133929.249 [DAT] No Fault, FailCount= 8 2019-09-10T16:45:29.611Z,1568133929.611 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2 2019-09-10T16:45:29.612Z,1568133929.612 [DAT](INFO): Powering up 2019-09-10T16:45:29.612Z,1568133929.612 [DAT](DEBUG): Initializing DAT. 2019-09-10T16:45:29.657Z,1568133929.657 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2 2019-09-10T16:46:08.447Z,1568133968.447 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2019-09-10T16:46:08.447Z,1568133968.447 [RDI_Pathfinder](ERROR): Failed to parse: :TS,19091016442844,35.0, -0.1, 0.0,14 2019-09-10T16:46:29.806Z,1568133989.806 [DAT](FAULT): failed to initialize; deviceResponse_ loaded: , available: --+---------(Raw) b 0 4 (+----1 ( | ease | 0 | | 0..214y 5ms), | ---------boI! 2019-09-10T16:46:29.806Z,1568133989.806 [DAT] Communications Fault, FailCount= 1 2019-09-10T16:46:29.807Z,1568133989.807 [DAT](ERROR): Communications Fault 2019-09-10T16:46:29.823Z,1568133989.823 [CBIT](ERROR): Communications Fault in component: DAT 2019-09-10T16:46:30.192Z,1568133990.192 [DAT](INFO): Powering down 2019-09-10T16:46:31.018Z,1568133991.018 [CBIT](INFO): Clearing failed state for component DAT 2019-09-10T16:46:31.018Z,1568133991.018 [DAT] No Fault, FailCount= 1 2019-09-10T16:46:33.432Z,1568133993.432 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2 2019-09-10T16:46:33.432Z,1568133993.432 [DAT](INFO): Powering up 2019-09-10T16:46:33.432Z,1568133993.432 [DAT](DEBUG): Initializing DAT. 2019-09-10T16:46:33.461Z,1568133993.461 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2 2019-09-10T16:46:47.601Z,1568134007.601 [DAT](INFO): setting local address to 4 2019-09-10T16:46:47.973Z,1568134007.973 [DAT](INFO): set local address to 4 2019-09-10T16:46:50.083Z,1568134010.083 [CommandLine](IMPORTANT): got command failComponent hardware DAT 2019-09-10T16:46:50.083Z,1568134010.083 [DAT] Hardware Fault, FailCount= 2 2019-09-10T16:46:50.083Z,1568134010.083 [DAT](ERROR): Hardware Fault 2019-09-10T16:46:50.083Z,1568134010.083 [CommandLine](IMPORTANT): DAT failureMode is Hardware Fault 2019-09-10T16:46:50.404Z,1568134010.404 [DAT](INFO): Powering down 2019-09-10T16:46:50.563Z,1568134010.563 [CBIT](ERROR): Hardware Fault in component: DAT 2019-09-10T16:46:50.701Z,1568134010.701 [CommandLine](IMPORTANT): got command failComponent hardware DAT 2019-09-10T16:46:50.701Z,1568134010.701 [CommandLine](IMPORTANT): DAT failureMode is Hardware Fault 2019-09-10T16:46:50.956Z,1568134010.956 [CommandLine](IMPORTANT): got command failComponent hardware DAT 2019-09-10T16:46:50.956Z,1568134010.956 [CommandLine](IMPORTANT): DAT failureMode is Hardware Fault 2019-09-10T16:46:51.206Z,1568134011.206 [CommandLine](IMPORTANT): got command failComponent hardware DAT 2019-09-10T16:46:51.207Z,1568134011.207 [CommandLine](IMPORTANT): DAT failureMode is Hardware Fault 2019-09-10T16:46:51.255Z,1568134011.255 [CBIT](INFO): Clearing failed state for component DAT 2019-09-10T16:46:51.255Z,1568134011.255 [DAT] No Fault, FailCount= 2 2019-09-10T16:46:51.436Z,1568134011.436 [CommandLine](IMPORTANT): got command failComponent hardware DAT 2019-09-10T16:46:51.436Z,1568134011.436 [DAT] Hardware Fault, FailCount= 3 2019-09-10T16:46:51.436Z,1568134011.436 [DAT](ERROR): Hardware Fault 2019-09-10T16:46:51.453Z,1568134011.453 [CommandLine](IMPORTANT): DAT failureMode is Hardware Fault 2019-09-10T16:46:51.644Z,1568134011.644 [CommandLine](IMPORTANT): got command failComponent hardware DAT 2019-09-10T16:46:51.644Z,1568134011.644 [CommandLine](IMPORTANT): DAT failureMode is Hardware Fault 2019-09-10T16:46:51.655Z,1568134011.655 [CBIT](ERROR): Hardware Fault in component: DAT 2019-09-10T16:46:51.655Z,1568134011.655 [CBIT](INFO): Clearing failed state for component DAT 2019-09-10T16:46:51.655Z,1568134011.655 [DAT] No Fault, FailCount= 3 2019-09-10T16:46:51.832Z,1568134011.832 [CommandLine](IMPORTANT): got command failComponent hardware DAT 2019-09-10T16:46:51.832Z,1568134011.832 [DAT] Hardware Fault, FailCount= 4 2019-09-10T16:46:51.832Z,1568134011.832 [DAT](ERROR): Hardware Fault 2019-09-10T16:46:51.833Z,1568134011.833 [CommandLine](IMPORTANT): DAT failureMode is Hardware Fault 2019-09-10T16:46:52.036Z,1568134012.036 [CBIT](ERROR): Hardware Fault in component: DAT 2019-09-10T16:46:52.036Z,1568134012.036 [CBIT](INFO): Clearing failed state for component DAT 2019-09-10T16:46:52.036Z,1568134012.036 [DAT] No Fault, FailCount= 4 2019-09-10T16:46:52.058Z,1568134012.058 [CommandLine](IMPORTANT): got command failComponent hardware DAT 2019-09-10T16:46:52.058Z,1568134012.058 [DAT] Hardware Fault, FailCount= 5 2019-09-10T16:46:52.059Z,1568134012.059 [DAT](ERROR): Hardware Fault 2019-09-10T16:46:52.059Z,1568134012.059 [CommandLine](IMPORTANT): DAT failureMode is Hardware Fault 2019-09-10T16:46:52.236Z,1568134012.236 [CommandLine](IMPORTANT): got command failComponent hardware DAT 2019-09-10T16:46:52.236Z,1568134012.236 [CommandLine](IMPORTANT): DAT failureMode is Hardware Fault 2019-09-10T16:46:52.411Z,1568134012.411 [CommandLine](IMPORTANT): got command failComponent hardware DAT 2019-09-10T16:46:52.412Z,1568134012.412 [CommandLine](IMPORTANT): DAT failureMode is Hardware Fault 2019-09-10T16:46:52.466Z,1568134012.466 [CBIT](ERROR): Hardware Fault in component: DAT 2019-09-10T16:46:52.466Z,1568134012.466 [CBIT](INFO): Clearing failed state for component DAT 2019-09-10T16:46:52.466Z,1568134012.466 [DAT] No Fault, FailCount= 5 2019-09-10T16:46:52.572Z,1568134012.572 [CommandLine](IMPORTANT): got command failComponent hardware DAT 2019-09-10T16:46:52.573Z,1568134012.573 [DAT] Hardware Fault, FailCount= 6 2019-09-10T16:46:52.573Z,1568134012.573 [DAT](ERROR): Hardware Fault 2019-09-10T16:46:52.574Z,1568134012.574 [CommandLine](IMPORTANT): DAT failureMode is Hardware Fault 2019-09-10T16:46:52.722Z,1568134012.722 [CommandLine](IMPORTANT): got command failComponent hardware DAT 2019-09-10T16:46:52.722Z,1568134012.722 [CommandLine](IMPORTANT): DAT failureMode is Hardware Fault 2019-09-10T16:46:52.859Z,1568134012.859 [CBIT](ERROR): Hardware Fault in component: DAT 2019-09-10T16:46:52.860Z,1568134012.860 [CBIT](INFO): Clearing failed state for component DAT 2019-09-10T16:46:52.860Z,1568134012.860 [DAT] No Fault, FailCount= 6 2019-09-10T16:46:52.916Z,1568134012.916 [CommandLine](IMPORTANT): got command failComponent hardware DAT 2019-09-10T16:46:52.916Z,1568134012.916 [DAT] Hardware Fault, FailCount= 7 2019-09-10T16:46:52.916Z,1568134012.916 [DAT](ERROR): Hardware Fault 2019-09-10T16:46:52.917Z,1568134012.917 [CommandLine](IMPORTANT): DAT failureMode is Hardware Fault 2019-09-10T16:46:53.077Z,1568134013.077 [CommandLine](IMPORTANT): got command failComponent hardware DAT 2019-09-10T16:46:53.077Z,1568134013.077 [CommandLine](IMPORTANT): DAT failureMode is Hardware Fault 2019-09-10T16:46:53.254Z,1568134013.254 [CBIT](ERROR): Hardware Fault in component: DAT 2019-09-10T16:46:53.255Z,1568134013.255 [CBIT](INFO): Clearing failed state for component DAT 2019-09-10T16:46:53.255Z,1568134013.255 [DAT] No Fault, FailCount= 7 2019-09-10T16:46:53.290Z,1568134013.290 [CommandLine](IMPORTANT): got command failComponent hardware DAT 2019-09-10T16:46:53.290Z,1568134013.290 [DAT] Hardware Fault, FailCount= 8 2019-09-10T16:46:53.290Z,1568134013.290 [DAT](ERROR): Hardware Fault 2019-09-10T16:46:53.290Z,1568134013.290 [CommandLine](IMPORTANT): DAT failureMode is Hardware Fault 2019-09-10T16:46:53.450Z,1568134013.450 [CommandLine](IMPORTANT): got command failComponent hardware DAT 2019-09-10T16:46:53.451Z,1568134013.451 [CommandLine](IMPORTANT): DAT failureMode is Hardware Fault 2019-09-10T16:46:53.570Z,1568134013.570 [CommandLine](IMPORTANT): got command failComponent hardware DAT 2019-09-10T16:46:53.571Z,1568134013.571 [CommandLine](IMPORTANT): DAT failureMode is Hardware Fault 2019-09-10T16:46:53.666Z,1568134013.666 [CBIT](ERROR): Hardware Fault in component: DAT 2019-09-10T16:46:53.667Z,1568134013.667 [CBIT](CRITICAL): Hardware Fault in component: DAT 2019-09-10T16:46:54.065Z,1568134014.065 [CBIT](INFO): Critical error at 20190910T164653 2019-09-10T16:48:33.228Z,1568134113.228 [CommandLine](IMPORTANT): got command failComponent 2019-09-10T16:48:33.228Z,1568134113.228 [CommandLine](IMPORTANT): Failed components: 2019-09-10T16:48:33.228Z,1568134113.228 [CommandLine](IMPORTANT): DAT: Hardware Fault 2019-09-10T16:48:35.361Z,1568134115.361 [CommandLine](IMPORTANT): got command failComponent none DAT 2019-09-10T16:48:35.361Z,1568134115.361 [DAT] No Fault, FailCount= 8 2019-09-10T16:48:35.362Z,1568134115.362 [CommandLine](IMPORTANT): DAT failureMode is No Fault 2019-09-10T16:48:35.492Z,1568134115.492 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2 2019-09-10T16:48:35.492Z,1568134115.492 [DAT](INFO): Powering up 2019-09-10T16:48:35.492Z,1568134115.492 [DAT](DEBUG): Initializing DAT. 2019-09-10T16:48:35.573Z,1568134115.573 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2 2019-09-10T16:48:49.992Z,1568134129.992 [DAT](INFO): setting local address to 4 2019-09-10T16:48:50.408Z,1568134130.408 [DAT](INFO): set local address to 4 2019-09-10T16:49:00.928Z,1568134140.928 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-09-10T16:49:00.928Z,1568134140.928 [Default:CheckIn:C.Wait] Stopped 2019-09-10T16:49:00.928Z,1568134140.928 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-09-10T16:49:00.928Z,1568134140.928 [Default:CheckIn:D] Running Loop=1 2019-09-10T16:49:01.337Z,1568134141.337 [Default:CheckIn:D] Stopped 2019-09-10T16:49:01.337Z,1568134141.337 [Default:CheckIn:E] Running Loop=1 2019-09-10T16:49:01.764Z,1568134141.764 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 33.752625 min 2019-09-10T16:49:01.764Z,1568134141.764 [Default:CheckIn:E] Stopped 2019-09-10T16:49:01.764Z,1568134141.764 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-09-10T16:49:01.764Z,1568134141.764 [Default:CheckIn] Stopped 2019-09-10T16:49:01.773Z,1568134141.773 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-09-10T16:49:01.773Z,1568134141.773 [Default:CheckIn](INFO): Running loop #4 2019-09-10T16:49:01.773Z,1568134141.773 [Default:CheckIn] Running Loop=4 2019-09-10T16:49:01.773Z,1568134141.773 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-09-10T16:49:01.773Z,1568134141.773 [Default:CheckIn:Read_GPS] Running Loop=1 2019-09-10T16:49:03.310Z,1568134143.310 [NAL9602](FAULT): GPS failed to acquire within timeout. 2019-09-10T16:49:03.310Z,1568134143.310 [NAL9602] Data Fault, FailCount= 2 2019-09-10T16:49:03.310Z,1568134143.310 [NAL9602](ERROR): Data Fault 2019-09-10T16:49:03.389Z,1568134143.389 [CBIT](ERROR): Data Fault in component: NAL9602 2019-09-10T16:49:03.719Z,1568134143.719 [NAL9602](INFO): Powering down 2019-09-10T16:49:04.580Z,1568134144.580 [CBIT](INFO): Clearing failed state for component NAL9602 2019-09-10T16:49:04.580Z,1568134144.580 [NAL9602] No Fault, FailCount= 2 2019-09-10T16:49:34.014Z,1568134174.014 [NAL9602](INFO): Powering up NAL9602 2019-09-10T16:49:44.926Z,1568134184.926 [NAL9602](INFO): NAL9602 initialized 2019-09-10T16:49:45.745Z,1568134185.745 [NAL9602](DEBUG): Fix Requested 2019-09-10T16:50:06.064Z,1568134206.064 [CommandLine](IMPORTANT): got command failComponent 2019-09-10T16:50:06.064Z,1568134206.064 [CommandLine](IMPORTANT): Failed components: 2019-09-10T16:50:06.064Z,1568134206.064 [CommandLine](IMPORTANT): No failed Components. 2019-09-10T16:50:53.638Z,1568134253.638 [DataOverHttps](IMPORTANT): SBD MTMSN=20190910T164807 2019-09-10T16:51:01.581Z,1568134261.581 [DataOverHttps](INFO): Received command:restart logs