2019-12-13T16:40:21.412Z,1576255221.412 [Supervisor](DEBUG): Initializing supervisor. 2019-12-13T16:40:21.425Z,1576255221.425 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2019-12-13T16:40:21.426Z,1576255221.426 [SyncHandler](INFO): Protected caller Thread ID is 805 2019-12-13T16:40:21.426Z,1576255221.426 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2019-12-13T16:40:21.427Z,1576255221.427 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2019-12-13T16:40:21.428Z,1576255221.428 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 806 2019-12-13T16:40:21.431Z,1576255221.431 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2019-12-13T16:40:21.442Z,1576255221.442 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2019-12-13T16:40:21.443Z,1576255221.443 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2019-12-13T16:40:21.443Z,1576255221.443 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 807 2019-12-13T16:40:21.444Z,1576255221.444 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2019-12-13T16:40:21.445Z,1576255221.445 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2019-12-13T16:40:21.445Z,1576255221.445 [logger ThreadHandler](INFO): Protected caller Thread ID is 808 2019-12-13T16:40:21.447Z,1576255221.447 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2019-12-13T16:40:21.447Z,1576255221.447 [Supervisor](INFO): Looking for Config files in directory: Config/ 2019-12-13T16:40:21.452Z,1576255221.452 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2019-12-13T16:40:21.901Z,1576255221.901 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2019-12-13T16:40:21.903Z,1576255221.903 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2019-12-13T16:40:22.051Z,1576255222.051 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2019-12-13T16:40:22.052Z,1576255222.052 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2019-12-13T16:40:22.134Z,1576255222.134 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2019-12-13T16:40:22.236Z,1576255222.236 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2019-12-13T16:40:22.237Z,1576255222.237 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2019-12-13T16:40:22.333Z,1576255222.333 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2019-12-13T16:40:22.334Z,1576255222.334 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2019-12-13T16:40:22.734Z,1576255222.734 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2019-12-13T16:40:22.736Z,1576255222.736 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2019-12-13T16:40:22.841Z,1576255222.841 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2019-12-13T16:40:22.843Z,1576255222.843 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2019-12-13T16:40:23.332Z,1576255223.332 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2019-12-13T16:40:23.335Z,1576255223.335 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2019-12-13T16:40:23.534Z,1576255223.534 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2019-12-13T16:40:23.536Z,1576255223.536 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2019-12-13T16:40:23.847Z,1576255223.847 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2019-12-13T16:40:23.849Z,1576255223.849 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2019-12-13T16:40:24.072Z,1576255224.072 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2019-12-13T16:40:24.261Z,1576255224.261 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2019-12-13T16:40:24.773Z,1576255224.773 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2019-12-13T16:40:24.774Z,1576255224.774 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2019-12-13T16:40:25.449Z,1576255225.449 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2019-12-13T16:40:25.451Z,1576255225.451 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2019-12-13T16:40:25.791Z,1576255225.791 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2019-12-13T16:40:25.793Z,1576255225.793 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2019-12-13T16:40:26.012Z,1576255226.012 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2019-12-13T16:40:26.014Z,1576255226.014 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-triton/ 2019-12-13T16:40:26.017Z,1576255226.017 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/vehicle.cfg 2019-12-13T16:40:26.216Z,1576255226.216 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/secure.cfg 2019-12-13T16:40:26.300Z,1576255226.300 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Science.cfg 2019-12-13T16:40:26.456Z,1576255226.456 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Simulator.cfg 2019-12-13T16:40:26.542Z,1576255226.542 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Battery.cfg 2019-12-13T16:40:26.776Z,1576255226.776 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2019-12-13T16:40:26.777Z,1576255226.777 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/logger.cfg 2019-12-13T16:40:26.875Z,1576255226.875 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Servo.cfg 2019-12-13T16:40:26.986Z,1576255226.986 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Navigation.cfg 2019-12-13T16:40:27.082Z,1576255227.082 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Sensor.cfg 2019-12-13T16:40:27.235Z,1576255227.235 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Control.cfg 2019-12-13T16:40:27.336Z,1576255227.336 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/BIT.cfg 2019-12-13T16:40:27.437Z,1576255227.437 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2019-12-13T16:40:27.453Z,1576255227.453 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2019-12-13T16:40:27.477Z,1576255227.477 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2019-12-13T16:40:27.478Z,1576255227.478 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2019-12-13T16:40:27.546Z,1576255227.546 [VerticalControl](DEBUG): Construct VerticalControl. 2019-12-13T16:40:27.663Z,1576255227.663 [VerticalControl] Loaded 2019-12-13T16:40:27.663Z,1576255227.663 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2019-12-13T16:40:27.664Z,1576255227.664 [HorizontalControl](DEBUG): Construct HorizontalControl. 2019-12-13T16:40:27.749Z,1576255227.749 [HorizontalControl] Loaded 2019-12-13T16:40:27.750Z,1576255227.750 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2019-12-13T16:40:27.750Z,1576255227.750 [SpeedControl](DEBUG): Construct SpeedControl. 2019-12-13T16:40:27.756Z,1576255227.756 [SpeedControl] Loaded 2019-12-13T16:40:27.756Z,1576255227.756 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2019-12-13T16:40:27.757Z,1576255227.757 [LoopControl](DEBUG): Construct LoopControl. 2019-12-13T16:40:27.758Z,1576255227.758 [LoopControl] Loaded 2019-12-13T16:40:27.758Z,1576255227.758 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2019-12-13T16:40:27.758Z,1576255227.758 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2019-12-13T16:40:27.759Z,1576255227.759 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2019-12-13T16:40:27.915Z,1576255227.915 [BuoyancyServo] Loaded 2019-12-13T16:40:27.915Z,1576255227.915 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2019-12-13T16:40:27.927Z,1576255227.927 [ElevatorServo] Loaded 2019-12-13T16:40:27.927Z,1576255227.927 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2019-12-13T16:40:27.938Z,1576255227.938 [MassServo] Loaded 2019-12-13T16:40:27.939Z,1576255227.939 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2019-12-13T16:40:27.950Z,1576255227.950 [RudderServo] Loaded 2019-12-13T16:40:27.950Z,1576255227.950 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2019-12-13T16:40:27.961Z,1576255227.961 [ThrusterServo] Loaded 2019-12-13T16:40:27.962Z,1576255227.962 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2019-12-13T16:40:27.962Z,1576255227.962 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2019-12-13T16:40:27.963Z,1576255227.963 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2019-12-13T16:40:28.021Z,1576255228.021 [DepthRateCalculator] Loaded 2019-12-13T16:40:28.021Z,1576255228.021 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2019-12-13T16:40:28.027Z,1576255228.027 [PitchRateCalculator] Loaded 2019-12-13T16:40:28.027Z,1576255228.027 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2019-12-13T16:40:28.043Z,1576255228.043 [SpeedCalculator] Loaded 2019-12-13T16:40:28.043Z,1576255228.043 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2019-12-13T16:40:28.065Z,1576255228.065 [TempGradientCalculator] Loaded 2019-12-13T16:40:28.066Z,1576255228.066 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2019-12-13T16:40:28.071Z,1576255228.071 [YawRateCalculator] Loaded 2019-12-13T16:40:28.071Z,1576255228.071 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2019-12-13T16:40:28.101Z,1576255228.101 [ElevatorOffsetCalculator] Loaded 2019-12-13T16:40:28.102Z,1576255228.102 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2019-12-13T16:40:28.102Z,1576255228.102 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2019-12-13T16:40:28.103Z,1576255228.103 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2019-12-13T16:40:28.227Z,1576255228.227 [DeadReckonUsingMultipleVelocitySources] Loaded 2019-12-13T16:40:28.228Z,1576255228.228 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2019-12-13T16:40:28.249Z,1576255228.249 [NavChart] Loaded 2019-12-13T16:40:28.250Z,1576255228.250 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2019-12-13T16:40:28.254Z,1576255228.254 [UniversalFixResidualReporter] Loaded 2019-12-13T16:40:28.254Z,1576255228.254 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2019-12-13T16:40:28.254Z,1576255228.254 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2019-12-13T16:40:28.255Z,1576255228.255 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2019-12-13T16:40:28.794Z,1576255228.794 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_orientation 2019-12-13T16:40:28.799Z,1576255228.799 [AHRS_M2](INFO): created writer for : platform_orientation 2019-12-13T16:40:28.801Z,1576255228.801 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_magnetic_orientation 2019-12-13T16:40:28.807Z,1576255228.807 [AHRS_M2](INFO): created writer for : platform_magnetic_orientation 2019-12-13T16:40:28.807Z,1576255228.807 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_pitch_angle 2019-12-13T16:40:28.812Z,1576255228.812 [AHRS_M2](INFO): created writer for : platform_pitch_angle 2019-12-13T16:40:28.813Z,1576255228.813 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_roll_angle 2019-12-13T16:40:28.819Z,1576255228.819 [AHRS_M2](INFO): created writer for : platform_roll_angle 2019-12-13T16:40:29.000Z,1576255229.000 [AHRS_M2] Loaded 2019-12-13T16:40:29.000Z,1576255229.000 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2019-12-13T16:40:29.150Z,1576255229.150 [DataOverHttps] Loaded 2019-12-13T16:40:29.150Z,1576255229.150 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2019-12-13T16:40:29.151Z,1576255229.151 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 408164E0 2019-12-13T16:40:29.152Z,1576255229.152 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 887 2019-12-13T16:40:29.166Z,1576255229.166 [Depth_Keller] Loaded 2019-12-13T16:40:29.166Z,1576255229.166 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2019-12-13T16:40:29.171Z,1576255229.171 [DropWeight] Loaded 2019-12-13T16:40:29.171Z,1576255229.171 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2019-12-13T16:40:29.220Z,1576255229.220 [DVL_micro] Loaded 2019-12-13T16:40:29.220Z,1576255229.220 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread. 2019-12-13T16:40:29.324Z,1576255229.324 [NAL9602] Loaded 2019-12-13T16:40:29.324Z,1576255229.324 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2019-12-13T16:40:29.364Z,1576255229.364 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-0/voltage_now 2019-12-13T16:40:29.364Z,1576255229.364 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-0/current_now 2019-12-13T16:40:29.365Z,1576255229.365 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-0/charge_now 2019-12-13T16:40:29.366Z,1576255229.366 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-0/charge_full 2019-12-13T16:40:29.366Z,1576255229.366 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-1/voltage_now 2019-12-13T16:40:29.367Z,1576255229.367 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-1/current_now 2019-12-13T16:40:29.367Z,1576255229.367 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-1/charge_now 2019-12-13T16:40:29.368Z,1576255229.368 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-1/charge_full 2019-12-13T16:40:29.368Z,1576255229.368 [Onboard] Loaded 2019-12-13T16:40:29.368Z,1576255229.368 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2019-12-13T16:40:29.372Z,1576255229.372 [Radio_Surface] Loaded 2019-12-13T16:40:29.372Z,1576255229.372 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2019-12-13T16:40:29.373Z,1576255229.373 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408464E0 2019-12-13T16:40:29.373Z,1576255229.373 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 888 2019-12-13T16:40:30.972Z,1576255230.972 [BPC1] Loaded 2019-12-13T16:40:30.973Z,1576255230.973 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2019-12-13T16:40:30.973Z,1576255230.973 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2019-12-13T16:40:30.975Z,1576255230.975 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2019-12-13T16:40:31.665Z,1576255231.665 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2019-12-13T16:40:31.666Z,1576255231.666 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2019-12-13T16:40:31.864Z,1576255231.864 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2019-12-13T16:40:31.865Z,1576255231.865 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2019-12-13T16:40:31.915Z,1576255231.915 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2019-12-13T16:40:31.916Z,1576255231.916 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2019-12-13T16:40:32.205Z,1576255232.205 [Aanderaa_O2] Loaded 2019-12-13T16:40:32.205Z,1576255232.205 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread. 2019-12-13T16:40:32.215Z,1576255232.215 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_density 2019-12-13T16:40:32.221Z,1576255232.221 [CTD_Seabird](INFO): created writer for : sea_water_density 2019-12-13T16:40:32.221Z,1576255232.221 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): depth 2019-12-13T16:40:32.226Z,1576255232.226 [CTD_Seabird](INFO): created writer for : depth 2019-12-13T16:40:32.227Z,1576255232.227 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_pressure 2019-12-13T16:40:32.232Z,1576255232.232 [CTD_Seabird](INFO): created writer for : sea_water_pressure 2019-12-13T16:40:32.233Z,1576255232.233 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_salinity 2019-12-13T16:40:32.239Z,1576255232.239 [CTD_Seabird](INFO): created writer for : sea_water_salinity 2019-12-13T16:40:32.239Z,1576255232.239 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_temperature 2019-12-13T16:40:32.245Z,1576255232.245 [CTD_Seabird](INFO): created writer for : sea_water_temperature 2019-12-13T16:40:32.245Z,1576255232.245 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_electrical_conductivity 2019-12-13T16:40:32.251Z,1576255232.251 [CTD_Seabird](INFO): created writer for : sea_water_electrical_conductivity 2019-12-13T16:40:32.252Z,1576255232.252 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): speed_of_sound_in_sea_water 2019-12-13T16:40:32.257Z,1576255232.257 [CTD_Seabird](INFO): created writer for : speed_of_sound_in_sea_water 2019-12-13T16:40:32.286Z,1576255232.286 [CTD_Seabird] Loaded 2019-12-13T16:40:32.286Z,1576255232.286 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2019-12-13T16:40:32.287Z,1576255232.287 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 409E04E0 2019-12-13T16:40:32.287Z,1576255232.287 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 889 2019-12-13T16:40:32.319Z,1576255232.319 [ESPComponent] Loaded 2019-12-13T16:40:32.319Z,1576255232.319 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread. 2019-12-13T16:40:32.334Z,1576255232.334 [PAR_Licor] Loaded 2019-12-13T16:40:32.335Z,1576255232.335 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2019-12-13T16:40:32.341Z,1576255232.341 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.Output470 2019-12-13T16:40:32.341Z,1576255232.341 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: Output470 2019-12-13T16:40:32.346Z,1576255232.346 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.Output650 2019-12-13T16:40:32.346Z,1576255232.346 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: Output650 2019-12-13T16:40:32.350Z,1576255232.350 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.OutputChl 2019-12-13T16:40:32.351Z,1576255232.351 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: OutputChl 2019-12-13T16:40:32.355Z,1576255232.355 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.VolumeScatCoeff117deg470nm 2019-12-13T16:40:32.355Z,1576255232.355 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: VolumeScatCoeff117deg470nm 2019-12-13T16:40:32.360Z,1576255232.360 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.VolumeScatCoeff117deg650nm 2019-12-13T16:40:32.360Z,1576255232.360 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: VolumeScatCoeff117deg650nm 2019-12-13T16:40:32.365Z,1576255232.365 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.BackscatteringCoeff470nm 2019-12-13T16:40:32.365Z,1576255232.365 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: BackscatteringCoeff470nm 2019-12-13T16:40:32.369Z,1576255232.369 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.BackscatteringCoeff650nm 2019-12-13T16:40:32.370Z,1576255232.370 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: BackscatteringCoeff650nm 2019-12-13T16:40:32.374Z,1576255232.374 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): mass_concentration_of_chlorophyll_in_sea_water 2019-12-13T16:40:32.379Z,1576255232.379 [WetLabsBB2FL](INFO): created writer for : mass_concentration_of_chlorophyll_in_sea_water 2019-12-13T16:40:32.379Z,1576255232.379 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_median_mass_concentration_of_chlorophyll_in_sea_water 2019-12-13T16:40:32.380Z,1576255232.380 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_median_mass_concentration_of_chlorophyll_in_sea_water 2019-12-13T16:40:32.384Z,1576255232.384 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water 2019-12-13T16:40:32.384Z,1576255232.384 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_mean_mass_concentration_of_chlorophyll_in_sea_water 2019-12-13T16:40:32.389Z,1576255232.389 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_variance_mass_concentration_of_chlorophyll_in_sea_water 2019-12-13T16:40:32.389Z,1576255232.389 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_variance_mass_concentration_of_chlorophyll_in_sea_water 2019-12-13T16:40:32.394Z,1576255232.394 [WetLabsBB2FL] Loaded 2019-12-13T16:40:32.394Z,1576255232.394 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2019-12-13T16:40:32.395Z,1576255232.395 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40A104E0 2019-12-13T16:40:32.396Z,1576255232.396 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 890 2019-12-13T16:40:32.396Z,1576255232.396 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2019-12-13T16:40:32.397Z,1576255232.397 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2019-12-13T16:40:32.781Z,1576255232.781 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2019-12-13T16:40:32.782Z,1576255232.782 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2019-12-13T16:40:32.956Z,1576255232.956 [SBIT](DEBUG): Construct Startup Built In Test. 2019-12-13T16:40:32.967Z,1576255232.967 [SBIT] Loaded 2019-12-13T16:40:32.968Z,1576255232.968 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2019-12-13T16:40:32.968Z,1576255232.968 [IBIT](DEBUG): Construct Initiated Built In Test. 2019-12-13T16:40:32.982Z,1576255232.982 [IBIT] Loaded 2019-12-13T16:40:32.982Z,1576255232.982 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2019-12-13T16:40:32.985Z,1576255232.985 [CBIT](DEBUG): Construct Continuous Built In Test. 2019-12-13T16:40:33.129Z,1576255233.129 [CBIT] Loaded 2019-12-13T16:40:33.130Z,1576255233.130 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2019-12-13T16:40:33.130Z,1576255233.130 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2019-12-13T16:40:33.134Z,1576255233.134 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2019-12-13T16:40:33.134Z,1576255233.134 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2019-12-13T16:40:33.141Z,1576255233.141 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2019-12-13T16:40:33.142Z,1576255233.142 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40AF94E0 2019-12-13T16:40:33.142Z,1576255233.142 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 891 2019-12-13T16:40:33.147Z,1576255233.147 [Supervisor](INFO): Main Thread ID is 801 2019-12-13T16:40:33.147Z,1576255233.147 [Supervisor](DEBUG): Running supervisor. 2019-12-13T16:40:33.148Z,1576255233.148 [CommandLine ThreadHandler](INFO): Handler Thread ID is 892 2019-12-13T16:40:33.150Z,1576255233.150 [controlThread ThreadHandler](INFO): Handler Thread ID is 893 2019-12-13T16:40:33.150Z,1576255233.150 [controlThread](DEBUG): Initializing ControlThread 2019-12-13T16:40:33.151Z,1576255233.151 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2019-12-13T16:40:33.153Z,1576255233.153 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2019-12-13T16:40:33.153Z,1576255233.153 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2019-12-13T16:40:33.154Z,1576255233.154 [LoopControl](DEBUG): Initialize LoopControlComponent. 2019-12-13T16:40:33.155Z,1576255233.155 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2019-12-13T16:40:33.155Z,1576255233.155 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2019-12-13T16:40:33.156Z,1576255233.156 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2019-12-13T16:40:33.156Z,1576255233.156 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2019-12-13T16:40:33.157Z,1576255233.157 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2019-12-13T16:40:33.157Z,1576255233.157 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2019-12-13T16:40:33.158Z,1576255233.158 [NavChart](DEBUG): Initialize NavChart Navigation. 2019-12-13T16:40:33.158Z,1576255233.158 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2019-12-13T16:40:33.165Z,1576255233.165 [SBIT](INFO): Initialize SBIT Component. 2019-12-13T16:40:33.166Z,1576255233.166 [SBIT](IMPORTANT): git: 2019-12-12 2019-12-13T16:40:33.166Z,1576255233.166 [SBIT](INFO): git hash: f9e633895ff379c63f31106fd166388954ec3ac0 2019-12-13T16:40:33.166Z,1576255233.166 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2019-12-13T16:40:33.167Z,1576255233.167 [SBIT](INFO): Kernel Reporting Different Version From Configuration. Kernel Expected: #1 PREEMPT Tue Dec 18 21:19:28 PST 2018 Kernel Reported: #1 PREEMPT Thu Feb 21 11:17:40 PST 2019 2019-12-13T16:40:33.168Z,1576255233.168 [SBIT](INFO): Beginning SBIT in 34.000000 seconds. 2019-12-13T16:40:33.169Z,1576255233.169 [IBIT](INFO): Initialize IBIT Component. 2019-12-13T16:40:33.170Z,1576255233.170 [CBIT](DEBUG): Initialize CBIT Component. 2019-12-13T16:40:33.171Z,1576255233.171 [logger ThreadHandler](INFO): Handler Thread ID is 894 2019-12-13T16:40:33.181Z,1576255233.181 [CBIT](DEBUG): Initialized mux pins. 2019-12-13T16:40:33.181Z,1576255233.181 [CBIT](DEBUG): Initializing the watchdog timer. 2019-12-13T16:40:33.189Z,1576255233.189 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 895 2019-12-13T16:40:33.190Z,1576255233.190 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2019-12-13T16:40:33.201Z,1576255233.201 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 896 2019-12-13T16:40:33.205Z,1576255233.205 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2019-12-13T16:40:33.205Z,1576255233.205 [CBIT](DEBUG): Initializing heartbeat. 2019-12-13T16:40:33.213Z,1576255233.213 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 897 2019-12-13T16:40:33.214Z,1576255233.214 [CTD_Seabird](DEBUG): Initializing CTD_Seabird. 2019-12-13T16:40:33.217Z,1576255233.217 [CTD_Seabird](INFO): Opening uart, block timeout 10ths=20 2019-12-13T16:40:33.219Z,1576255233.219 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 899 2019-12-13T16:40:33.219Z,1576255233.219 [WetLabsBB2FL](INFO): Powering down 2019-12-13T16:40:33.263Z,1576255233.263 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 900 2019-12-13T16:40:33.271Z,1576255233.271 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2019-12-13T16:40:33.271Z,1576255233.271 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2019-12-13T16:40:33.271Z,1576255233.271 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2019-12-13T16:40:33.271Z,1576255233.271 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2019-12-13T16:40:33.271Z,1576255233.271 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2019-12-13T16:40:33.272Z,1576255233.272 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2019-12-13T16:40:33.272Z,1576255233.272 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000 2019-12-13T16:40:33.272Z,1576255233.272 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2019-12-13T16:40:33.272Z,1576255233.272 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2019-12-13T16:40:33.272Z,1576255233.272 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2019-12-13T16:40:33.273Z,1576255233.273 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000 2019-12-13T16:40:33.273Z,1576255233.273 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2019-12-13T16:40:33.273Z,1576255233.273 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000 2019-12-13T16:40:33.273Z,1576255233.273 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2019-12-13T16:40:33.274Z,1576255233.274 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000 2019-12-13T16:40:33.274Z,1576255233.274 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2019-12-13T16:40:33.277Z,1576255233.277 [CBIT](DEBUG): Deactivating GF circuits. 2019-12-13T16:40:33.277Z,1576255233.277 [CBIT](DEBUG): Deactivating emergency mode. 2019-12-13T16:40:33.313Z,1576255233.313 [CBIT](DEBUG): Backplane powered. 2019-12-13T16:40:33.314Z,1576255233.314 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2019-12-13T16:40:33.522Z,1576255233.522 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2019-12-13T16:40:33.605Z,1576255233.605 [Radio_Surface](INFO): Powering up 2019-12-13T16:40:33.635Z,1576255233.635 [MissionManager](DEBUG): 2019-12-13T16:40:33.641Z,1576255233.641 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2019-12-13T16:40:33.720Z,1576255233.720 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2019-12-13T16:40:33.749Z,1576255233.749 [Default:A.Wait](DEBUG): Construct Wait. 2019-12-13T16:40:33.751Z,1576255233.751 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2019-12-13T16:40:33.776Z,1576255233.776 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2019-12-13T16:40:33.779Z,1576255233.779 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2019-12-13T16:40:33.793Z,1576255233.793 [Default:E.Execute](DEBUG): Construct Execute. 2019-12-13T16:40:33.821Z,1576255233.821 [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-12-13T16:40:33.826Z,1576255233.826 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,DVL_micro,NAL9602,Onboard,BPC1,Aanderaa_O2,ESPComponent,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2019-12-13T16:40:33.837Z,1576255233.837 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2019-12-13T16:40:33.946Z,1576255233.946 [Depth_Keller](ERROR): Pressure reading out of range: 1925.893799 decibar 2019-12-13T16:40:34.049Z,1576255234.049 [DepthRateCalculator](ERROR): Depth measurement is not active 2019-12-13T16:40:34.093Z,1576255234.093 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2019-12-13T16:40:34.101Z,1576255234.101 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2019-12-13T16:40:34.102Z,1576255234.102 [ElevatorServo](DEBUG): Initializing EZServoServo. 2019-12-13T16:40:34.109Z,1576255234.109 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2019-12-13T16:40:34.110Z,1576255234.110 [MassServo](DEBUG): Initializing EZServoServo. 2019-12-13T16:40:34.117Z,1576255234.117 [MassServo](DEBUG): Initializing MassServo. 2019-12-13T16:40:34.118Z,1576255234.118 [RudderServo](DEBUG): Initializing EZServoServo. 2019-12-13T16:40:34.125Z,1576255234.125 [RudderServo](DEBUG): Initializing RudderServo. 2019-12-13T16:40:34.126Z,1576255234.126 [ThrusterServo](DEBUG): Initializing EZServoServo. 2019-12-13T16:40:34.133Z,1576255234.133 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2019-12-13T16:40:35.037Z,1576255235.037 [RudderServo](ERROR): Rudder initialization uart error serial timeout 2019-12-13T16:40:35.037Z,1576255235.037 [RudderServo](FAULT): Rudder failed to initialize 2019-12-13T16:40:35.037Z,1576255235.037 [RudderServo] Communications Fault, FailCount= 1 2019-12-13T16:40:35.037Z,1576255235.037 [RudderServo](ERROR): Communications Fault 2019-12-13T16:40:35.148Z,1576255235.148 [CBIT](ERROR): Communications Fault in component: RudderServo 2019-12-13T16:40:35.326Z,1576255235.326 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2019-12-13T16:40:35.327Z,1576255235.327 [RudderServo](INFO): Powering down 2019-12-13T16:40:36.033Z,1576255236.033 [RudderServo](DEBUG): Initializing EZServoServo. 2019-12-13T16:40:36.154Z,1576255236.154 [RudderServo](DEBUG): Initializing RudderServo. 2019-12-13T16:40:36.158Z,1576255236.158 [CBIT](INFO): Clearing failed state for component RudderServo 2019-12-13T16:40:36.158Z,1576255236.158 [RudderServo] No Fault, FailCount= 1 2019-12-13T16:40:37.381Z,1576255237.381 [Aanderaa_O2](INFO): Powering down 2019-12-13T16:40:40.245Z,1576255240.245 [CTD_Seabird](ERROR): Device message queue exceeded the allowed limit. 2019-12-13T16:40:51.342Z,1576255251.342 [DVL_micro](ERROR): No DVL communication! Re-initializing 2019-12-13T16:40:51.342Z,1576255251.342 [DVL_micro] Communications Fault, FailCount= 1 2019-12-13T16:40:51.342Z,1576255251.342 [DVL_micro](ERROR): Communications Fault 2019-12-13T16:40:51.402Z,1576255251.402 [CBIT](ERROR): Communications Fault in component: DVL_micro 2019-12-13T16:40:51.821Z,1576255251.821 [DVL_micro](INFO): Powering down 2019-12-13T16:40:52.641Z,1576255252.641 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-12-13T16:40:52.641Z,1576255252.641 [DVL_micro] No Fault, FailCount= 1 2019-12-13T16:40:59.423Z,1576255259.423 [NAL9602](INFO): Powering up NAL9602 2019-12-13T16:41:07.963Z,1576255267.963 [SBIT](IMPORTANT): Beginning Startup BIT 2019-12-13T16:41:07.971Z,1576255267.971 [CBIT](IMPORTANT): Beginning ground fault scan 2019-12-13T16:41:10.458Z,1576255270.458 [DVL_micro](ERROR): No DVL communication! Re-initializing 2019-12-13T16:41:10.458Z,1576255270.458 [DVL_micro] Communications Fault, FailCount= 2 2019-12-13T16:41:10.458Z,1576255270.458 [DVL_micro](ERROR): Communications Fault 2019-12-13T16:41:10.459Z,1576255270.459 [NAL9602](INFO): NAL9602 initialized 2019-12-13T16:41:10.654Z,1576255270.654 [CBIT](ERROR): Communications Fault in component: DVL_micro 2019-12-13T16:41:10.933Z,1576255270.933 [DVL_micro](INFO): Powering down 2019-12-13T16:41:11.906Z,1576255271.906 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-12-13T16:41:11.906Z,1576255271.906 [DVL_micro] No Fault, FailCount= 2 2019-12-13T16:41:19.029Z,1576255279.029 [CBIT](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): 0.054837 CHAN A1 (24V): 0.064408 CHAN A2 (12V): 0.011371 CHAN A3 (5V): -0.021876 CHAN B0 (3.3V): -0.015380 CHAN B1 (3.15aV): -0.011449 CHAN B2 (3.15bV): -0.007614 CHAN B3 (GND): -0.021500 OPEN: 0.008142 Full Scale Calc: 4.765 mA, -1.589 mA 2019-12-13T16:41:29.550Z,1576255289.550 [DVL_micro](ERROR): No DVL communication! Re-initializing 2019-12-13T16:41:29.550Z,1576255289.550 [DVL_micro] Communications Fault, FailCount= 3 2019-12-13T16:41:29.550Z,1576255289.550 [DVL_micro](ERROR): Communications Fault 2019-12-13T16:41:29.626Z,1576255289.626 [CBIT](ERROR): Communications Fault in component: DVL_micro 2019-12-13T16:41:29.626Z,1576255289.626 [CBIT](CRITICAL): Communications Fault in component: DVL_micro 2019-12-13T16:41:30.025Z,1576255290.025 [DVL_micro](INFO): Powering down 2019-12-13T16:41:30.112Z,1576255290.112 [CommandLine](FAULT): Scheduling is paused 2019-12-13T16:41:30.112Z,1576255290.112 [CBIT](INFO): Critical error at 20191213T164129 2019-12-13T16:41:30.113Z,1576255290.113 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals 2019-12-13T16:42:01.569Z,1576255321.569 [SBIT](IMPORTANT): SBIT PASSED 2019-12-13T16:42:01.607Z,1576255321.607 [CommandLine](IMPORTANT): got command configSet list 2019-12-13T16:42:01.607Z,1576255321.607 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2019-12-13T16:42:01.608Z,1576255321.608 [CommandLine](IMPORTANT): BPC1.batteryMissingStickThreshold=2 count; 2019-12-13T16:42:01.608Z,1576255321.608 [CommandLine](IMPORTANT): DAT.loadAtStartup=0 bool; 2019-12-13T16:42:01.608Z,1576255321.608 [CommandLine](IMPORTANT): DVL_micro.loadAtStartup=1 bool; 2019-12-13T16:42:01.608Z,1576255321.608 [CommandLine](IMPORTANT): Express none CTD_Seabird.bin_median_sea_water_salinity; 2019-12-13T16:42:01.608Z,1576255321.608 [CommandLine](IMPORTANT): Express linearApproximation WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water 0.100000 microgram_per_liter; 2019-12-13T16:42:01.608Z,1576255321.608 [CommandLine](IMPORTANT): Express linearApproximation depth 5.000000 meter; 2019-12-13T16:42:01.608Z,1576255321.608 [CommandLine](IMPORTANT): Express linearApproximation latitude 0.005000 degree; 2019-12-13T16:42:01.608Z,1576255321.608 [CommandLine](IMPORTANT): Express linearApproximation longitude 0.005000 degree; 2019-12-13T16:42:01.609Z,1576255321.609 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral=168 cubic_centimeter; 2019-12-13T16:42:01.609Z,1576255321.609 [CommandLine](IMPORTANT): VerticalControl.massDefault=3.7 millimeter; 2019-12-13T16:42:01.982Z,1576255321.982 [MissionManager](IMPORTANT): Started mission Startup 2019-12-13T16:42:01.982Z,1576255321.982 [Startup] Running Loop=1 2019-12-13T16:42:01.982Z,1576255321.982 [Startup](DEBUG): Aggregate::initialize Startup 2019-12-13T16:42:01.982Z,1576255321.982 [Startup:A.GoToSurface] Running Loop=1 2019-12-13T16:42:01.982Z,1576255321.982 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2019-12-13T16:42:01.983Z,1576255321.983 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2019-12-13T16:42:01.983Z,1576255321.983 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2019-12-13T16:42:01.983Z,1576255321.983 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2019-12-13T16:42:01.984Z,1576255321.984 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2019-12-13T16:42:01.984Z,1576255321.984 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2019-12-13T16:42:01.986Z,1576255321.986 [Startup:StartupSatComms] Running Loop=1 2019-12-13T16:42:01.986Z,1576255321.986 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2019-12-13T16:42:01.986Z,1576255321.986 [Startup:StartupSatComms:A] Running Loop=1 2019-12-13T16:42:02.386Z,1576255322.386 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2019-12-13T16:43:02.227Z,1576255382.227 [Startup:StartupSatComms:A](INFO): Timed out from 2019-12-13T16:42:01.0Z 2019-12-13T16:43:02.227Z,1576255382.227 [Startup:StartupSatComms:A] Stopped 2019-12-13T16:43:02.227Z,1576255382.227 [Startup:StartupSatComms:B] Running Loop=1 2019-12-13T16:43:02.619Z,1576255382.619 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2019-12-13T16:43:25.000Z,1576255406.000 [NAL9602](INFO): SBD MO Status=0, MOMSN=3646, MT Status=0, MTMSN=0 2019-12-13T16:43:25.000Z,1576255406.000 [NAL9602](INFO): No messages in MT queue 2019-12-13T16:43:33.302Z,1576255413.302 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2019-12-13T16:43:33.302Z,1576255413.302 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-12-13T16:43:33.330Z,1576255413.330 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-12-13T16:43:33.710Z,1576255413.710 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-12-13T16:43:33.710Z,1576255413.710 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2019-12-13T16:43:57.998Z,1576255437.998 [DataOverHttps](INFO): Exceeded connection timeout, disconnecting. 2019-12-13T16:44:02.280Z,1576255442.280 [Startup:StartupSatComms:B](INFO): Timed out from 2019-12-13T16:43:02.2Z 2019-12-13T16:44:02.280Z,1576255442.280 [Startup:StartupSatComms:B] Stopped 2019-12-13T16:44:02.280Z,1576255442.280 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2019-12-13T16:44:02.280Z,1576255442.280 [Startup:StartupSatComms] Stopped 2019-12-13T16:44:02.280Z,1576255442.280 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2019-12-13T16:44:02.309Z,1576255442.309 [Startup](INFO): Completed Startup 2019-12-13T16:44:02.310Z,1576255442.310 [MissionManager](INFO): Startup is completed. 2019-12-13T16:44:02.310Z,1576255442.310 [MissionManager](INFO): Uninitializing Mission Startup 2019-12-13T16:44:02.310Z,1576255442.310 [Startup] Stopped 2019-12-13T16:44:02.310Z,1576255442.310 [Startup](DEBUG): Aggregate::uninitialize Startup 2019-12-13T16:44:02.310Z,1576255442.310 [Startup:A.GoToSurface] Stopped 2019-12-13T16:44:02.310Z,1576255442.310 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2019-12-13T16:44:02.679Z,1576255442.679 [MissionManager](IMPORTANT): Started mission Default 2019-12-13T16:44:02.679Z,1576255442.679 [Default] Running Loop=1 2019-12-13T16:44:02.679Z,1576255442.679 [Default](DEBUG): Aggregate::initialize Default 2019-12-13T16:44:02.679Z,1576255442.679 [Default:B.GoToSurface] Running Loop=1 2019-12-13T16:44:02.679Z,1576255442.679 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2019-12-13T16:44:02.679Z,1576255442.679 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2019-12-13T16:44:02.680Z,1576255442.680 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2019-12-13T16:44:02.680Z,1576255442.680 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2019-12-13T16:44:02.680Z,1576255442.680 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2019-12-13T16:44:02.681Z,1576255442.681 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2019-12-13T16:44:02.681Z,1576255442.681 [Default:A.Wait] Running Loop=1 2019-12-13T16:44:02.681Z,1576255442.681 [Default:A.Wait](DEBUG): Initialize Wait Component. 2019-12-13T16:44:05.884Z,1576255445.884 [NAL9602](INFO): SBD MO Status=1, MOMSN=3647, MT Status=0, MTMSN=0 2019-12-13T16:44:05.937Z,1576255445.937 [NAL9602](INFO): Sent 64 bytes from file Logs/20191212T204452/Courier0355.lzma 2019-12-13T16:44:05.937Z,1576255445.937 [NAL9602](INFO): Packets left to send: 0 2019-12-13T16:44:06.718Z,1576255446.718 [CommandLine](IMPORTANT): got command failComponent 2019-12-13T16:44:06.718Z,1576255446.718 [CommandLine](IMPORTANT): Failed components: 2019-12-13T16:44:06.718Z,1576255446.718 [CommandLine](IMPORTANT): DVL_micro: Communications Fault 2019-12-13T16:44:07.096Z,1576255447.096 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163523.00,A,3648.16316,N,12147.28148,W,0.117,305.28,131219,,,A*72 2019-12-13T16:44:07.099Z,1576255447.099 [NAL9602](INFO): GPS fix at 20191213T163523: (36.802719, -121.788025) 2019-12-13T16:44:11.681Z,1576255451.681 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003448 2019-12-13T16:44:16.018Z,1576255456.018 [Default:A.Wait](INFO): Done Waiting. 2019-12-13T16:44:16.019Z,1576255456.019 [Default:A.Wait] Stopped 2019-12-13T16:44:16.019Z,1576255456.019 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2019-12-13T16:44:16.429Z,1576255456.429 [Default:CheckIn] Running Loop=1 2019-12-13T16:44:16.429Z,1576255456.429 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-12-13T16:44:16.429Z,1576255456.429 [Default:CheckIn:Read_GPS] Running Loop=1 2019-12-13T16:44:16.829Z,1576255456.829 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2019-12-13T16:44:18.412Z,1576255458.412 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163534.00,A,3648.16421,N,12147.28317,W,1.205,303.64,131219,,,A*70 2019-12-13T16:44:18.414Z,1576255458.414 [NAL9602](INFO): GPS fix at 20191213T163534: (36.802737, -121.788053) 2019-12-13T16:44:18.464Z,1576255458.464 [Default:CheckIn:Read_GPS] Stopped 2019-12-13T16:44:18.464Z,1576255458.464 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-12-13T16:44:18.876Z,1576255458.876 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2019-12-13T16:44:23.761Z,1576255463.761 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2019-12-13T16:44:29.846Z,1576255469.846 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-12-13T16:44:29.846Z,1576255469.846 [DVL_micro] No Fault, FailCount= 3 2019-12-13T16:44:37.704Z,1576255477.704 [DataOverHttps](INFO): Sending 102 bytes from file Logs/20191213T164021/Courier0000.lzma 2019-12-13T16:44:37.882Z,1576255477.882 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout. 2019-12-13T16:44:37.882Z,1576255477.882 [DVL_micro] Data Fault, FailCount= 1 2019-12-13T16:44:37.882Z,1576255477.882 [DVL_micro](ERROR): Data Fault 2019-12-13T16:44:37.949Z,1576255477.949 [CBIT](ERROR): Data Fault in component: DVL_micro 2019-12-13T16:44:38.361Z,1576255478.361 [DVL_micro](INFO): Powering down 2019-12-13T16:44:39.108Z,1576255479.108 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2019-12-13T16:44:39.163Z,1576255479.163 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-12-13T16:44:39.163Z,1576255479.163 [DVL_micro] No Fault, FailCount= 1 2019-12-13T16:44:39.710Z,1576255479.710 [DataOverHttps](INFO): Moved sent file to Logs/20191213T164021/Courier0000.lzma.bak 2019-12-13T16:44:39.710Z,1576255479.710 [DataOverHttps](INFO): SBD MOMSN=12154601 2019-12-13T16:44:50.805Z,1576255490.805 [NAL9602](INFO): Not Powering down - fast GPS 2019-12-13T16:44:54.464Z,1576255494.464 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2019-12-13T16:44:56.881Z,1576255496.881 [DVL_micro](ERROR): No DVL communication! Re-initializing 2019-12-13T16:44:56.882Z,1576255496.882 [DVL_micro] Communications Fault, FailCount= 2 2019-12-13T16:44:56.882Z,1576255496.882 [DVL_micro](ERROR): Communications Fault 2019-12-13T16:44:56.968Z,1576255496.968 [CBIT](ERROR): Communications Fault in component: DVL_micro 2019-12-13T16:44:57.341Z,1576255497.341 [DVL_micro](INFO): Powering down 2019-12-13T16:44:58.187Z,1576255498.187 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-12-13T16:44:58.187Z,1576255498.187 [DVL_micro] No Fault, FailCount= 2 2019-12-13T16:44:58.785Z,1576255498.785 [DataOverHttps](INFO): Sending 213 bytes from file Logs/20191213T164021/Courier0004.lzma 2019-12-13T16:45:00.790Z,1576255500.790 [DataOverHttps](INFO): Moved sent file to Logs/20191213T164021/Courier0004.lzma.bak 2019-12-13T16:45:00.790Z,1576255500.790 [DataOverHttps](INFO): SBD MOMSN=12154608 2019-12-13T16:45:10.219Z,1576255510.219 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2019-12-13T16:45:15.854Z,1576255515.854 [DVL_micro](ERROR): No DVL communication! Re-initializing 2019-12-13T16:45:15.854Z,1576255515.854 [DVL_micro] Communications Fault, FailCount= 3 2019-12-13T16:45:15.854Z,1576255515.854 [DVL_micro](ERROR): Communications Fault 2019-12-13T16:45:15.945Z,1576255515.945 [CBIT](ERROR): Communications Fault in component: DVL_micro 2019-12-13T16:45:15.945Z,1576255515.945 [CBIT](CRITICAL): Communications Fault in component: DVL_micro 2019-12-13T16:45:16.333Z,1576255516.333 [DVL_micro](INFO): Powering down 2019-12-13T16:45:16.459Z,1576255516.459 [CBIT](INFO): Critical error at 20191213T164515 2019-12-13T16:45:25.595Z,1576255525.595 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2019-12-13T16:45:26.855Z,1576255526.855 [DataOverHttps](INFO): Sending 484 bytes from file Logs/20191212T204452/Express0356.lzma 2019-12-13T16:45:28.859Z,1576255528.859 [DataOverHttps](INFO): Moved sent file to Logs/20191212T204452/Express0356.lzma.bak 2019-12-13T16:45:28.859Z,1576255528.859 [DataOverHttps](INFO): SBD MOMSN=12154617 2019-12-13T16:45:41.356Z,1576255541.356 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2019-12-13T16:45:56.706Z,1576255556.706 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2019-12-13T16:46:02.698Z,1576255562.698 [DataOverHttps](INFO): Sending 97 bytes from file Logs/20191212T204452/Express0359.lzma 2019-12-13T16:46:04.703Z,1576255564.703 [DataOverHttps](INFO): Moved sent file to Logs/20191212T204452/Express0359.lzma.bak 2019-12-13T16:46:04.703Z,1576255564.703 [DataOverHttps](INFO): SBD MOMSN=12154647 2019-12-13T16:46:12.452Z,1576255572.452 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2019-12-13T16:46:26.611Z,1576255586.611 [DataOverHttps](INFO): Sending 919 bytes from file Logs/20191213T164021/Express0001.lzma 2019-12-13T16:46:27.815Z,1576255587.815 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2019-12-13T16:46:28.615Z,1576255588.615 [DataOverHttps](INFO): Moved sent file to Logs/20191213T164021/Express0001.lzma.bak 2019-12-13T16:46:28.615Z,1576255588.615 [DataOverHttps](INFO): SBD MOMSN=12154658 2019-12-13T16:46:49.205Z,1576255609.205 [DataOverHttps](INFO): Sending 294 bytes from file Logs/20191213T164021/Express0005.lzma 2019-12-13T16:46:50.044Z,1576255610.044 [BPC1](ERROR): Battery stick #15 (s/n: 0269) reported OVER_TEMP_ALARM. Status code: 0x1717. 2019-12-13T16:46:50.044Z,1576255610.044 [BPC1](INFO): Calculating totals. Valid battery stick count: 54. Valid reserve battery stick count: 5. 2019-12-13T16:46:50.048Z,1576255610.048 [BPC1](INFO): Received data from all battery sticks. 2019-12-13T16:46:51.210Z,1576255611.210 [DataOverHttps](INFO): Moved sent file to Logs/20191213T164021/Express0005.lzma.bak 2019-12-13T16:46:51.210Z,1576255611.210 [DataOverHttps](INFO): SBD MOMSN=12154682 2019-12-13T16:46:55.342Z,1576255615.342 [Default:CheckIn:Read_Iridium] Stopped 2019-12-13T16:46:55.342Z,1576255615.342 [Default:CheckIn:C.Wait] Running Loop=1 2019-12-13T16:46:55.342Z,1576255615.342 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-12-13T16:48:16.138Z,1576255696.138 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-12-13T16:48:16.138Z,1576255696.138 [DVL_micro] No Fault, FailCount= 3 2019-12-13T16:48:24.182Z,1576255704.182 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout. 2019-12-13T16:48:24.182Z,1576255704.182 [DVL_micro] Data Fault, FailCount= 1 2019-12-13T16:48:24.182Z,1576255704.182 [DVL_micro](ERROR): Data Fault 2019-12-13T16:48:24.214Z,1576255704.214 [CBIT](ERROR): Data Fault in component: DVL_micro 2019-12-13T16:48:24.586Z,1576255704.586 [DVL_micro](INFO): Powering down 2019-12-13T16:48:25.453Z,1576255705.453 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-12-13T16:48:25.453Z,1576255705.453 [DVL_micro] No Fault, FailCount= 1 2019-12-13T16:48:43.170Z,1576255723.170 [DVL_micro](ERROR): No DVL communication! Re-initializing 2019-12-13T16:48:43.170Z,1576255723.170 [DVL_micro] Communications Fault, FailCount= 2 2019-12-13T16:48:43.170Z,1576255723.170 [DVL_micro](ERROR): Communications Fault 2019-12-13T16:48:43.202Z,1576255723.202 [CBIT](ERROR): Communications Fault in component: DVL_micro 2019-12-13T16:48:43.571Z,1576255723.571 [DVL_micro](INFO): Powering down 2019-12-13T16:48:44.432Z,1576255724.432 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-12-13T16:48:44.432Z,1576255724.432 [DVL_micro] No Fault, FailCount= 2 2019-12-13T16:49:02.162Z,1576255742.162 [DVL_micro](ERROR): No DVL communication! Re-initializing 2019-12-13T16:49:02.162Z,1576255742.162 [DVL_micro] Communications Fault, FailCount= 3 2019-12-13T16:49:02.162Z,1576255742.162 [DVL_micro](ERROR): Communications Fault 2019-12-13T16:49:02.201Z,1576255742.201 [CBIT](ERROR): Communications Fault in component: DVL_micro 2019-12-13T16:49:02.202Z,1576255742.202 [CBIT](CRITICAL): Communications Fault in component: DVL_micro 2019-12-13T16:49:02.562Z,1576255742.562 [DVL_micro](INFO): Powering down 2019-12-13T16:49:02.609Z,1576255742.609 [CBIT](INFO): Critical error at 20191213T164902 2019-12-13T16:51:55.921Z,1576255915.921 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-12-13T16:51:55.921Z,1576255915.921 [Default:CheckIn:C.Wait] Stopped 2019-12-13T16:51:55.921Z,1576255915.921 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-12-13T16:51:55.921Z,1576255915.921 [Default:CheckIn:D] Running Loop=1 2019-12-13T16:51:56.337Z,1576255916.337 [Default:CheckIn:D] Stopped 2019-12-13T16:51:56.337Z,1576255916.337 [Default:CheckIn:E] Running Loop=1 2019-12-13T16:51:56.721Z,1576255916.721 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 7.894302 min 2019-12-13T16:51:56.721Z,1576255916.721 [Default:CheckIn:E] Stopped 2019-12-13T16:51:56.721Z,1576255916.721 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-12-13T16:51:56.721Z,1576255916.721 [Default:CheckIn] Stopped 2019-12-13T16:51:56.722Z,1576255916.722 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-12-13T16:51:56.722Z,1576255916.722 [Default:CheckIn](INFO): Running loop #2 2019-12-13T16:51:56.722Z,1576255916.722 [Default:CheckIn] Running Loop=2 2019-12-13T16:51:56.722Z,1576255916.722 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-12-13T16:51:56.722Z,1576255916.722 [Default:CheckIn:Read_GPS] Running Loop=1 2019-12-13T16:51:58.713Z,1576255918.713 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164315.00,A,3648.16047,N,12147.27610,W,0.525,322.18,131219,,,A*77 2019-12-13T16:51:58.716Z,1576255918.716 [NAL9602](INFO): GPS fix at 20191213T164315: (36.802675, -121.787935) 2019-12-13T16:51:58.756Z,1576255918.756 [Default:CheckIn:Read_GPS] Stopped 2019-12-13T16:51:58.756Z,1576255918.756 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-12-13T16:52:02.406Z,1576255922.406 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-12-13T16:52:02.406Z,1576255922.406 [DVL_micro] No Fault, FailCount= 3 2019-12-13T16:52:07.705Z,1576255927.705 [DataOverHttps](INFO): Sending 276 bytes from file Logs/20191213T164021/Courier0007.lzma 2019-12-13T16:52:09.710Z,1576255929.710 [DataOverHttps](INFO): Moved sent file to Logs/20191213T164021/Courier0007.lzma.bak 2019-12-13T16:52:09.710Z,1576255929.710 [DataOverHttps](INFO): SBD MOMSN=12154723 2019-12-13T16:52:10.428Z,1576255930.428 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout. 2019-12-13T16:52:10.428Z,1576255930.428 [DVL_micro] Data Fault, FailCount= 1 2019-12-13T16:52:10.428Z,1576255930.428 [DVL_micro](ERROR): Data Fault 2019-12-13T16:52:10.496Z,1576255930.496 [CBIT](ERROR): Data Fault in component: DVL_micro 2019-12-13T16:52:10.838Z,1576255930.838 [DVL_micro](INFO): Powering down 2019-12-13T16:52:11.709Z,1576255931.709 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-12-13T16:52:11.709Z,1576255931.709 [DVL_micro] No Fault, FailCount= 1 2019-12-13T16:52:29.418Z,1576255949.418 [DVL_micro](ERROR): No DVL communication! Re-initializing 2019-12-13T16:52:29.418Z,1576255949.418 [DVL_micro] Communications Fault, FailCount= 2 2019-12-13T16:52:29.418Z,1576255949.418 [DVL_micro](ERROR): Communications Fault 2019-12-13T16:52:29.476Z,1576255949.476 [CBIT](ERROR): Communications Fault in component: DVL_micro 2019-12-13T16:52:29.529Z,1576255949.529 [DataOverHttps](INFO): Sending 220 bytes from file Logs/20191213T164021/Express0008.lzma 2019-12-13T16:52:29.826Z,1576255949.826 [DVL_micro](INFO): Powering down 2019-12-13T16:52:30.671Z,1576255950.671 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-12-13T16:52:30.672Z,1576255950.672 [DVL_micro] No Fault, FailCount= 2 2019-12-13T16:52:31.534Z,1576255951.534 [DataOverHttps](INFO): Moved sent file to Logs/20191213T164021/Express0008.lzma.bak 2019-12-13T16:52:31.534Z,1576255951.534 [DataOverHttps](INFO): SBD MOMSN=12154731 2019-12-13T16:52:37.956Z,1576255957.956 [Default:CheckIn:Read_Iridium] Stopped 2019-12-13T16:52:37.956Z,1576255957.956 [Default:CheckIn:C.Wait] Running Loop=1 2019-12-13T16:52:37.956Z,1576255957.956 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-12-13T16:52:48.410Z,1576255968.410 [DVL_micro](ERROR): No DVL communication! Re-initializing 2019-12-13T16:52:48.410Z,1576255968.410 [DVL_micro] Communications Fault, FailCount= 3 2019-12-13T16:52:48.410Z,1576255968.410 [DVL_micro](ERROR): Communications Fault 2019-12-13T16:52:48.479Z,1576255968.479 [CBIT](ERROR): Communications Fault in component: DVL_micro 2019-12-13T16:52:48.479Z,1576255968.479 [CBIT](CRITICAL): Communications Fault in component: DVL_micro 2019-12-13T16:52:48.808Z,1576255968.808 [DVL_micro](INFO): Powering down 2019-12-13T16:52:48.839Z,1576255968.839 [CBIT](INFO): Critical error at 20191213T165248 2019-12-13T16:52:51.235Z,1576255971.235 [NAL9602](INFO): SBD MO Status=2, MOMSN=3648, MT Status=2, MTMSN=0 2019-12-13T16:52:51.236Z,1576255971.236 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-12-13T16:53:15.885Z,1576255995.885 [NAL9602](INFO): SBD MO Status=2, MOMSN=3648, MT Status=2, MTMSN=0 2019-12-13T16:53:15.885Z,1576255995.885 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-12-13T16:53:32.455Z,1576256012.455 [NAL9602](INFO): SBD MO Status=0, MOMSN=3648, MT Status=0, MTMSN=0 2019-12-13T16:53:32.456Z,1576256012.456 [NAL9602](INFO): No messages in MT queue 2019-12-13T16:53:58.557Z,1576256038.557 [CommandLine](IMPORTANT): got command failComponent hardware DVL_micro 2019-12-13T16:53:58.557Z,1576256038.557 [DVL_micro] Hardware Fault, FailCount= 3 2019-12-13T16:53:58.557Z,1576256038.557 [DVL_micro](ERROR): Hardware Fault 2019-12-13T16:53:58.557Z,1576256038.557 [CommandLine](IMPORTANT): DVL_micro failureMode is Hardware Fault 2019-12-13T16:54:03.154Z,1576256043.154 [NAL9602](INFO): Not Powering down - fast GPS 2019-12-13T16:54:05.600Z,1576256045.600 [CommandLine](IMPORTANT): got command failComponent hardware DVL_micro 2019-12-13T16:54:05.600Z,1576256045.600 [CommandLine](IMPORTANT): DVL_micro failureMode is Hardware Fault 2019-12-13T16:54:09.293Z,1576256049.293 [CommandLine](IMPORTANT): got command failComponent hardware DVL_micro 2019-12-13T16:54:09.293Z,1576256049.293 [CommandLine](IMPORTANT): DVL_micro failureMode is Hardware Fault 2019-12-13T16:54:11.355Z,1576256051.355 [CommandLine](IMPORTANT): got command failComponent hardware DVL_micro 2019-12-13T16:54:11.355Z,1576256051.355 [CommandLine](IMPORTANT): DVL_micro failureMode is Hardware Fault 2019-12-13T16:54:12.636Z,1576256052.636 [CommandLine](IMPORTANT): got command failComponent hardware DVL_micro 2019-12-13T16:54:12.636Z,1576256052.636 [CommandLine](IMPORTANT): DVL_micro failureMode is Hardware Fault 2019-12-13T16:54:19.675Z,1576256059.675 [CommandLine](IMPORTANT): got command failComponent hardware DVL_micro 2019-12-13T16:54:19.675Z,1576256059.675 [CommandLine](IMPORTANT): DVL_micro failureMode is Hardware Fault 2019-12-13T16:54:23.195Z,1576256063.195 [CommandLine](IMPORTANT): got command failComponent hardware DVL_micro 2019-12-13T16:54:23.195Z,1576256063.195 [CommandLine](IMPORTANT): DVL_micro failureMode is Hardware Fault 2019-12-13T16:54:27.715Z,1576256067.715 [CommandLine](IMPORTANT): got command failComponent hardware DVL_micro 2019-12-13T16:54:27.715Z,1576256067.715 [CommandLine](IMPORTANT): DVL_micro failureMode is Hardware Fault 2019-12-13T16:54:28.796Z,1576256068.796 [CommandLine](IMPORTANT): got command failComponent hardware DVL_micro 2019-12-13T16:54:28.796Z,1576256068.796 [CommandLine](IMPORTANT): DVL_micro failureMode is Hardware Fault 2019-12-13T16:54:29.845Z,1576256069.845 [CommandLine](IMPORTANT): got command failComponent hardware DVL_micro 2019-12-13T16:54:29.846Z,1576256069.846 [CommandLine](IMPORTANT): DVL_micro failureMode is Hardware Fault 2019-12-13T16:54:30.915Z,1576256070.915 [CommandLine](IMPORTANT): got command failComponent hardware DVL_micro 2019-12-13T16:54:30.915Z,1576256070.915 [CommandLine](IMPORTANT): DVL_micro failureMode is Hardware Fault 2019-12-13T16:55:48.629Z,1576256148.629 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-12-13T16:55:48.629Z,1576256148.629 [DVL_micro] No Fault, FailCount= 3 2019-12-13T16:55:56.686Z,1576256156.686 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout. 2019-12-13T16:55:56.686Z,1576256156.686 [DVL_micro] Data Fault, FailCount= 1 2019-12-13T16:55:56.686Z,1576256156.686 [DVL_micro](ERROR): Data Fault 2019-12-13T16:55:56.745Z,1576256156.745 [CBIT](ERROR): Data Fault in component: DVL_micro 2019-12-13T16:55:57.157Z,1576256157.157 [DVL_micro](INFO): Powering down 2019-12-13T16:55:57.946Z,1576256157.946 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-12-13T16:55:57.946Z,1576256157.946 [DVL_micro] No Fault, FailCount= 1 2019-12-13T16:56:15.664Z,1576256175.664 [DVL_micro](ERROR): No DVL communication! Re-initializing 2019-12-13T16:56:15.664Z,1576256175.664 [DVL_micro] Communications Fault, FailCount= 2 2019-12-13T16:56:15.664Z,1576256175.664 [DVL_micro](ERROR): Communications Fault 2019-12-13T16:56:15.733Z,1576256175.733 [CBIT](ERROR): Communications Fault in component: DVL_micro 2019-12-13T16:56:16.074Z,1576256176.074 [DVL_micro](INFO): Powering down 2019-12-13T16:56:16.915Z,1576256176.915 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-12-13T16:56:16.915Z,1576256176.915 [DVL_micro] No Fault, FailCount= 2 2019-12-13T16:56:34.652Z,1576256194.652 [DVL_micro](ERROR): No DVL communication! Re-initializing 2019-12-13T16:56:34.652Z,1576256194.652 [DVL_micro] Communications Fault, FailCount= 3 2019-12-13T16:56:34.652Z,1576256194.652 [DVL_micro](ERROR): Communications Fault 2019-12-13T16:56:34.708Z,1576256194.708 [CBIT](ERROR): Communications Fault in component: DVL_micro 2019-12-13T16:56:34.713Z,1576256194.713 [CBIT](CRITICAL): Communications Fault in component: DVL_micro 2019-12-13T16:56:35.064Z,1576256195.064 [DVL_micro](INFO): Powering down 2019-12-13T16:56:35.096Z,1576256195.096 [CBIT](INFO): Critical error at 20191213T165634 2019-12-13T16:57:38.585Z,1576256258.585 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-12-13T16:57:38.585Z,1576256258.585 [Default:CheckIn:C.Wait] Stopped 2019-12-13T16:57:38.585Z,1576256258.585 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-12-13T16:57:38.585Z,1576256258.585 [Default:CheckIn:D] Running Loop=1 2019-12-13T16:57:38.936Z,1576256258.936 [Default:CheckIn:D] Stopped 2019-12-13T16:57:38.936Z,1576256258.936 [Default:CheckIn:E] Running Loop=1 2019-12-13T16:57:39.356Z,1576256259.356 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 13.604288 min 2019-12-13T16:57:39.356Z,1576256259.356 [Default:CheckIn:E] Stopped 2019-12-13T16:57:39.363Z,1576256259.363 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-12-13T16:57:39.363Z,1576256259.363 [Default:CheckIn] Stopped 2019-12-13T16:57:39.363Z,1576256259.363 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-12-13T16:57:39.364Z,1576256259.364 [Default:CheckIn](INFO): Running loop #3 2019-12-13T16:57:39.364Z,1576256259.364 [Default:CheckIn] Running Loop=3 2019-12-13T16:57:39.364Z,1576256259.364 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-12-13T16:57:39.364Z,1576256259.364 [Default:CheckIn:Read_GPS] Running Loop=1 2019-12-13T16:57:41.328Z,1576256261.328 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164858.00,A,3648.16188,N,12147.28217,W,0.272,30.88,131219,,,A*47 2019-12-13T16:57:41.347Z,1576256261.347 [NAL9602](INFO): GPS fix at 20191213T164858: (36.802698, -121.788036) 2019-12-13T16:57:41.406Z,1576256261.406 [Default:CheckIn:Read_GPS] Stopped 2019-12-13T16:57:41.406Z,1576256261.406 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-12-13T16:57:44.441Z,1576256264.441 [DataOverHttps](INFO): Sending 121 bytes from file Logs/20191213T164021/Courier0010.lzma 2019-12-13T16:57:46.450Z,1576256266.450 [DataOverHttps](INFO): Moved sent file to Logs/20191213T164021/Courier0010.lzma.bak 2019-12-13T16:57:46.450Z,1576256266.450 [DataOverHttps](INFO): SBD MOMSN=12154774 2019-12-13T16:58:06.413Z,1576256286.413 [DataOverHttps](INFO): Sending 308 bytes from file Logs/20191213T164021/Express0011.lzma 2019-12-13T16:58:08.418Z,1576256288.418 [DataOverHttps](INFO): Moved sent file to Logs/20191213T164021/Express0011.lzma.bak 2019-12-13T16:58:08.418Z,1576256288.418 [DataOverHttps](INFO): SBD MOMSN=12154782 2019-12-13T16:58:12.553Z,1576256292.553 [Default:CheckIn:Read_Iridium] Stopped 2019-12-13T16:58:12.553Z,1576256292.553 [Default:CheckIn:C.Wait] Running Loop=1 2019-12-13T16:58:12.553Z,1576256292.553 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-12-13T16:59:34.975Z,1576256374.975 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-12-13T16:59:34.975Z,1576256374.975 [DVL_micro] No Fault, FailCount= 3 2019-12-13T16:59:43.017Z,1576256383.017 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout. 2019-12-13T16:59:43.017Z,1576256383.017 [DVL_micro] Data Fault, FailCount= 1 2019-12-13T16:59:43.017Z,1576256383.017 [DVL_micro](ERROR): Data Fault 2019-12-13T16:59:43.089Z,1576256383.089 [CBIT](ERROR): Data Fault in component: DVL_micro 2019-12-13T16:59:43.430Z,1576256383.430 [DVL_micro](INFO): Powering down 2019-12-13T16:59:44.281Z,1576256384.281 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-12-13T16:59:44.281Z,1576256384.281 [DVL_micro] No Fault, FailCount= 1 2019-12-13T17:00:02.006Z,1576256402.006 [DVL_micro](ERROR): No DVL communication! Re-initializing 2019-12-13T17:00:02.007Z,1576256402.007 [DVL_micro] Communications Fault, FailCount= 2 2019-12-13T17:00:02.007Z,1576256402.007 [DVL_micro](ERROR): Communications Fault 2019-12-13T17:00:02.073Z,1576256402.073 [CBIT](ERROR): Communications Fault in component: DVL_micro 2019-12-13T17:00:02.412Z,1576256402.412 [DVL_micro](INFO): Powering down 2019-12-13T17:00:03.259Z,1576256403.259 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-12-13T17:00:03.259Z,1576256403.259 [DVL_micro] No Fault, FailCount= 2 2019-12-13T17:00:20.994Z,1576256420.994 [DVL_micro](ERROR): No DVL communication! Re-initializing 2019-12-13T17:00:20.994Z,1576256420.994 [DVL_micro] Communications Fault, FailCount= 3 2019-12-13T17:00:20.994Z,1576256420.994 [DVL_micro](ERROR): Communications Fault 2019-12-13T17:00:21.062Z,1576256421.062 [CBIT](ERROR): Communications Fault in component: DVL_micro 2019-12-13T17:00:21.062Z,1576256421.062 [CBIT](CRITICAL): Communications Fault in component: DVL_micro 2019-12-13T17:00:21.398Z,1576256421.398 [DVL_micro](INFO): Powering down 2019-12-13T17:00:21.444Z,1576256421.444 [CBIT](INFO): Critical error at 20191213T170021 2019-12-13T17:01:43.819Z,1576256503.819 [NAL9602](INFO): SBD MO Status=2, MOMSN=3649, MT Status=2, MTMSN=0 2019-12-13T17:01:43.819Z,1576256503.819 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-12-13T17:02:07.655Z,1576256527.655 [NAL9602](INFO): SBD MO Status=0, MOMSN=3649, MT Status=0, MTMSN=0 2019-12-13T17:02:07.655Z,1576256527.655 [NAL9602](INFO): No messages in MT queue 2019-12-13T17:02:38.354Z,1576256558.354 [NAL9602](INFO): Not Powering down - fast GPS 2019-12-13T17:03:13.155Z,1576256593.155 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-12-13T17:03:13.155Z,1576256593.155 [Default:CheckIn:C.Wait] Stopped 2019-12-13T17:03:13.155Z,1576256593.155 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-12-13T17:03:13.155Z,1576256593.155 [Default:CheckIn:D] Running Loop=1 2019-12-13T17:03:13.569Z,1576256593.569 [Default:CheckIn:D] Stopped 2019-12-13T17:03:13.569Z,1576256593.569 [Default:CheckIn:E] Running Loop=1 2019-12-13T17:03:13.975Z,1576256593.975 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 19.181494 min 2019-12-13T17:03:13.975Z,1576256593.975 [Default:CheckIn:E] Stopped 2019-12-13T17:03:13.975Z,1576256593.975 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-12-13T17:03:13.975Z,1576256593.975 [Default:CheckIn] Stopped 2019-12-13T17:03:13.975Z,1576256593.975 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-12-13T17:03:13.976Z,1576256593.976 [Default:CheckIn](INFO): Running loop #4 2019-12-13T17:03:13.976Z,1576256593.976 [Default:CheckIn] Running Loop=4 2019-12-13T17:03:13.976Z,1576256593.976 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-12-13T17:03:13.976Z,1576256593.976 [Default:CheckIn:Read_GPS] Running Loop=1 2019-12-13T17:03:15.936Z,1576256595.936 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165432.00,A,3648.16063,N,12147.29543,W,0.253,83.57,131219,,,A*4C 2019-12-13T17:03:15.938Z,1576256595.938 [NAL9602](INFO): GPS fix at 20191213T165432: (36.802677, -121.788257) 2019-12-13T17:03:15.980Z,1576256595.980 [Default:CheckIn:Read_GPS] Stopped 2019-12-13T17:03:15.980Z,1576256595.980 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-12-13T17:03:21.217Z,1576256601.217 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-12-13T17:03:21.217Z,1576256601.217 [DVL_micro] No Fault, FailCount= 3 2019-12-13T17:03:28.088Z,1576256608.088 [DataOverHttps](INFO): Sending 114 bytes from file Logs/20191213T164021/Courier0013.lzma 2019-12-13T17:03:29.266Z,1576256609.266 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout. 2019-12-13T17:03:29.266Z,1576256609.266 [DVL_micro] Data Fault, FailCount= 1 2019-12-13T17:03:29.266Z,1576256609.266 [DVL_micro](ERROR): Data Fault 2019-12-13T17:03:29.299Z,1576256609.299 [CBIT](ERROR): Data Fault in component: DVL_micro 2019-12-13T17:03:29.741Z,1576256609.741 [DVL_micro](INFO): Powering down 2019-12-13T17:03:30.094Z,1576256610.094 [DataOverHttps](INFO): Moved sent file to Logs/20191213T164021/Courier0013.lzma.bak 2019-12-13T17:03:30.094Z,1576256610.094 [DataOverHttps](INFO): SBD MOMSN=12154853 2019-12-13T17:03:30.538Z,1576256610.538 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-12-13T17:03:30.538Z,1576256610.538 [DVL_micro] No Fault, FailCount= 1 2019-12-13T17:03:39.368Z,1576256619.368 [NAL9602](INFO): SBD MO Status=2, MOMSN=3650, MT Status=2, MTMSN=0 2019-12-13T17:03:39.368Z,1576256619.368 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-12-13T17:03:48.254Z,1576256628.254 [DVL_micro](ERROR): No DVL communication! Re-initializing 2019-12-13T17:03:48.254Z,1576256628.254 [DVL_micro] Communications Fault, FailCount= 2 2019-12-13T17:03:48.254Z,1576256628.254 [DVL_micro](ERROR): Communications Fault 2019-12-13T17:03:48.355Z,1576256628.355 [CBIT](ERROR): Communications Fault in component: DVL_micro 2019-12-13T17:03:48.729Z,1576256628.729 [DVL_micro](INFO): Powering down 2019-12-13T17:03:49.508Z,1576256629.508 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-12-13T17:03:49.509Z,1576256629.509 [DVL_micro] No Fault, FailCount= 2 2019-12-13T17:03:50.285Z,1576256630.285 [DataOverHttps](INFO): Sending 168 bytes from file Logs/20191213T164021/Express0014.lzma 2019-12-13T17:03:52.290Z,1576256632.290 [DataOverHttps](INFO): Moved sent file to Logs/20191213T164021/Express0014.lzma.bak 2019-12-13T17:03:52.291Z,1576256632.291 [DataOverHttps](INFO): SBD MOMSN=12154857 2019-12-13T17:03:56.372Z,1576256636.372 [Default:CheckIn:Read_Iridium] Stopped 2019-12-13T17:03:56.372Z,1576256636.372 [Default:CheckIn:C.Wait] Running Loop=1 2019-12-13T17:03:56.372Z,1576256636.372 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-12-13T17:04:07.239Z,1576256647.239 [DVL_micro](ERROR): No DVL communication! Re-initializing 2019-12-13T17:04:07.240Z,1576256647.240 [DVL_micro] Communications Fault, FailCount= 3 2019-12-13T17:04:07.240Z,1576256647.240 [DVL_micro](ERROR): Communications Fault 2019-12-13T17:04:07.317Z,1576256647.317 [CBIT](ERROR): Communications Fault in component: DVL_micro 2019-12-13T17:04:07.321Z,1576256647.321 [CBIT](CRITICAL): Communications Fault in component: DVL_micro 2019-12-13T17:04:07.721Z,1576256647.721 [DVL_micro](INFO): Powering down 2019-12-13T17:04:07.771Z,1576256647.771 [CBIT](INFO): Critical error at 20191213T170407 2019-12-13T17:05:29.661Z,1576256729.661 [NAL9602](INFO): SBD MO Status=2, MOMSN=3650, MT Status=2, MTMSN=0 2019-12-13T17:05:29.661Z,1576256729.661 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-12-13T17:07:07.517Z,1576256827.517 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-12-13T17:07:07.517Z,1576256827.517 [DVL_micro] No Fault, FailCount= 3 2019-12-13T17:07:15.522Z,1576256835.522 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout. 2019-12-13T17:07:15.522Z,1576256835.522 [DVL_micro] Data Fault, FailCount= 1 2019-12-13T17:07:15.522Z,1576256835.522 [DVL_micro](ERROR): Data Fault 2019-12-13T17:07:15.593Z,1576256835.593 [CBIT](ERROR): Data Fault in component: DVL_micro 2019-12-13T17:07:16.001Z,1576256836.001 [DVL_micro](INFO): Powering down 2019-12-13T17:07:16.775Z,1576256836.775 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-12-13T17:07:16.775Z,1576256836.775 [DVL_micro] No Fault, FailCount= 1 2019-12-13T17:07:34.506Z,1576256854.506 [DVL_micro](ERROR): No DVL communication! Re-initializing 2019-12-13T17:07:34.506Z,1576256854.506 [DVL_micro] Communications Fault, FailCount= 2 2019-12-13T17:07:34.506Z,1576256854.506 [DVL_micro](ERROR): Communications Fault 2019-12-13T17:07:34.597Z,1576256854.597 [CBIT](ERROR): Communications Fault in component: DVL_micro 2019-12-13T17:07:34.977Z,1576256854.977 [DVL_micro](INFO): Powering down 2019-12-13T17:07:35.764Z,1576256855.764 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-12-13T17:07:35.764Z,1576256855.764 [DVL_micro] No Fault, FailCount= 2 2019-12-13T17:07:53.499Z,1576256873.499 [DVL_micro](ERROR): No DVL communication! Re-initializing 2019-12-13T17:07:53.500Z,1576256873.500 [DVL_micro] Communications Fault, FailCount= 3 2019-12-13T17:07:53.509Z,1576256873.509 [DVL_micro](ERROR): Communications Fault 2019-12-13T17:07:53.598Z,1576256873.598 [CBIT](ERROR): Communications Fault in component: DVL_micro 2019-12-13T17:07:53.599Z,1576256873.599 [CBIT](CRITICAL): Communications Fault in component: DVL_micro 2019-12-13T17:07:53.973Z,1576256873.973 [DVL_micro](INFO): Powering down 2019-12-13T17:07:54.047Z,1576256874.047 [CBIT](INFO): Critical error at 20191213T170753 2019-12-13T17:08:04.795Z,1576256884.795 [CommandLine](IMPORTANT): got command maintain control VerticalControl.massPositionAction 200.000000 cubic_centimeter 2019-12-13T17:08:04.796Z,1576256884.796 [ComponentRegistry](DEBUG): SyncComponent "Maintain_VerticalControl.massPositionAction" handled in the control thread. 2019-12-13T17:08:04.882Z,1576256884.882 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,DVL_micro,NAL9602,Onboard,BPC1,Aanderaa_O2,ESPComponent,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,Maintain_VerticalControl.massPositionAction,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2019-12-13T17:08:13.529Z,1576256893.529 [CommandLine](IMPORTANT): got command report mod platform_mass_position 2019-12-13T17:08:13.810Z,1576256893.810 [Reporter](INFO): platform_mass_position 0.000200 m 2019-12-13T17:08:17.806Z,1576256897.806 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-12-13T17:08:34.869Z,1576256914.869 [CommandLine](IMPORTANT): got command report mod 2019-12-13T17:08:34.869Z,1576256914.869 [CommandLine](FAULT): Incomplete syntax. Try: help report 2019-12-13T17:08:42.868Z,1576256922.868 [CommandLine](IMPORTANT): got command report mod platform_buoyancy_position 2019-12-13T17:08:42.929Z,1576256922.929 [Reporter](INFO): platform_buoyancy_position 958.068970 cc 2019-12-13T17:08:48.506Z,1576256928.506 [NAL9602](INFO): Not Powering down - fast GPS 2019-12-13T17:08:57.039Z,1576256937.039 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-12-13T17:08:57.039Z,1576256937.039 [Default:CheckIn:C.Wait] Stopped 2019-12-13T17:08:57.039Z,1576256937.039 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-12-13T17:08:57.039Z,1576256937.039 [Default:CheckIn:D] Running Loop=1 2019-12-13T17:08:57.421Z,1576256937.421 [Default:CheckIn:D] Stopped 2019-12-13T17:08:57.421Z,1576256937.421 [Default:CheckIn:E] Running Loop=1 2019-12-13T17:08:57.833Z,1576256937.833 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 24.912362 min 2019-12-13T17:08:57.833Z,1576256937.833 [Default:CheckIn:E] Stopped 2019-12-13T17:08:57.833Z,1576256937.833 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-12-13T17:08:57.833Z,1576256937.833 [Default:CheckIn] Stopped 2019-12-13T17:08:57.833Z,1576256937.833 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-12-13T17:08:57.834Z,1576256937.834 [Default:CheckIn](INFO): Running loop #5 2019-12-13T17:08:57.834Z,1576256937.834 [Default:CheckIn] Running Loop=5 2019-12-13T17:08:57.834Z,1576256937.834 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-12-13T17:08:57.834Z,1576256937.834 [Default:CheckIn:Read_GPS] Running Loop=1 2019-12-13T17:08:59.824Z,1576256939.824 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170016.00,A,3648.15944,N,12147.27798,W,0.136,83.57,131219,,,A*4F 2019-12-13T17:08:59.826Z,1576256939.826 [NAL9602](INFO): GPS fix at 20191213T170016: (36.802657, -121.787966) 2019-12-13T17:08:59.906Z,1576256939.906 [Default:CheckIn:Read_GPS] Stopped 2019-12-13T17:08:59.906Z,1576256939.906 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-12-13T17:09:16.744Z,1576256956.744 [DataOverHttps](INFO): Sending 120 bytes from file Logs/20191213T164021/Courier0016.lzma 2019-12-13T17:09:18.750Z,1576256958.750 [DataOverHttps](INFO): Moved sent file to Logs/20191213T164021/Courier0016.lzma.bak 2019-12-13T17:09:18.750Z,1576256958.750 [DataOverHttps](INFO): SBD MOMSN=12154905 2019-12-13T17:09:30.562Z,1576256970.562 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2019-12-13T17:09:30.641Z,1576256970.641 [NAL9602](FAULT): received: +CSQ:0 OK50, 2, 0, 0, 0 OK 2019-12-13T17:09:30.641Z,1576256970.641 [NAL9602] Data Fault, FailCount= 1 2019-12-13T17:09:30.641Z,1576256970.641 [NAL9602](ERROR): Data Fault 2019-12-13T17:09:30.676Z,1576256970.676 [CBIT](ERROR): Data Fault in component: NAL9602 2019-12-13T17:09:30.966Z,1576256970.966 [NAL9602](INFO): Powering down 2019-12-13T17:09:31.820Z,1576256971.820 [CBIT](INFO): Clearing failed state for component NAL9602 2019-12-13T17:09:31.820Z,1576256971.820 [NAL9602] No Fault, FailCount= 1 2019-12-13T17:09:31.827Z,1576256971.827 [CommandLine](IMPORTANT): got command maintain clear 2019-12-13T17:09:32.211Z,1576256972.211 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,DVL_micro,NAL9602,Onboard,BPC1,Aanderaa_O2,ESPComponent,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2019-12-13T17:09:34.710Z,1576256974.710 [Reporter](INFO): platform_mass_position 0.000254 m 2019-12-13T17:09:35.110Z,1576256975.110 [Reporter](INFO): platform_mass_position 0.000565 m 2019-12-13T17:09:35.522Z,1576256975.522 [Reporter](INFO): platform_mass_position 0.000888 m 2019-12-13T17:09:35.938Z,1576256975.938 [Reporter](INFO): platform_mass_position 0.001214 m 2019-12-13T17:09:36.352Z,1576256976.352 [Reporter](INFO): platform_mass_position 0.001540 m 2019-12-13T17:09:36.768Z,1576256976.768 [Reporter](INFO): platform_mass_position 0.001860 m 2019-12-13T17:09:37.190Z,1576256977.190 [Reporter](INFO): platform_mass_position 0.002189 m 2019-12-13T17:09:37.689Z,1576256977.689 [Reporter](INFO): platform_mass_position 0.002537 m 2019-12-13T17:09:38.002Z,1576256978.002 [Reporter](INFO): platform_mass_position 0.002835 m 2019-12-13T17:09:38.384Z,1576256978.384 [Reporter](INFO): platform_mass_position 0.003131 m 2019-12-13T17:09:38.814Z,1576256978.814 [Reporter](INFO): platform_mass_position 0.003471 m 2019-12-13T17:09:39.231Z,1576256979.231 [Reporter](INFO): platform_mass_position 0.003700 m 2019-12-13T17:09:42.601Z,1576256982.601 [DataOverHttps](INFO): Sending 409 bytes from file Logs/20191213T164021/Express0017.lzma 2019-12-13T17:09:44.606Z,1576256984.606 [DataOverHttps](INFO): Moved sent file to Logs/20191213T164021/Express0017.lzma.bak 2019-12-13T17:09:44.606Z,1576256984.606 [DataOverHttps](INFO): SBD MOMSN=12154913 2019-12-13T17:09:46.542Z,1576256986.542 [CommandLine](IMPORTANT): got command maintain control VerticalControl.buoyancyAction 200.000000 cubic_centimeter 2019-12-13T17:09:46.543Z,1576256986.543 [ComponentRegistry](DEBUG): SyncComponent "Maintain_VerticalControl.buoyancyAction" handled in the control thread. 2019-12-13T17:09:46.814Z,1576256986.814 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,DVL_micro,NAL9602,Onboard,BPC1,Aanderaa_O2,ESPComponent,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,Maintain_VerticalControl.buoyancyAction,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2019-12-13T17:09:48.812Z,1576256988.812 [Default:CheckIn:Read_Iridium] Stopped 2019-12-13T17:09:48.812Z,1576256988.812 [Default:CheckIn:C.Wait] Running Loop=1 2019-12-13T17:09:48.812Z,1576256988.812 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-12-13T17:09:52.467Z,1576256992.467 [Reporter](INFO): platform_buoyancy_position 955.920166 cc 2019-12-13T17:09:52.883Z,1576256992.883 [Reporter](INFO): platform_buoyancy_position 945.176147 cc 2019-12-13T17:09:53.303Z,1576256993.303 [Reporter](INFO): platform_buoyancy_position 943.027344 cc 2019-12-13T17:09:53.723Z,1576256993.723 [Reporter](INFO): platform_buoyancy_position 940.878540 cc 2019-12-13T17:09:54.099Z,1576256994.099 [Reporter](INFO): platform_buoyancy_position 936.580933 cc 2019-12-13T17:09:54.535Z,1576256994.535 [Reporter](INFO): platform_buoyancy_position 932.417725 cc 2019-12-13T17:09:54.927Z,1576256994.927 [Reporter](INFO): platform_buoyancy_position 927.582886 cc 2019-12-13T17:09:55.333Z,1576256995.333 [Reporter](INFO): platform_buoyancy_position 921.539429 cc 2019-12-13T17:09:55.735Z,1576256995.735 [Reporter](INFO): platform_buoyancy_position 916.973145 cc 2019-12-13T17:09:56.172Z,1576256996.172 [Reporter](INFO): platform_buoyancy_position 910.795410 cc 2019-12-13T17:09:56.515Z,1576256996.515 [Reporter](INFO): platform_buoyancy_position 906.497803 cc 2019-12-13T17:09:56.936Z,1576256996.936 [Reporter](INFO): platform_buoyancy_position 900.185669 cc 2019-12-13T17:09:57.327Z,1576256997.327 [Reporter](INFO): platform_buoyancy_position 895.888062 cc 2019-12-13T17:09:57.731Z,1576256997.731 [Reporter](INFO): platform_buoyancy_position 889.307373 cc 2019-12-13T17:09:58.131Z,1576256998.131 [Reporter](INFO): platform_buoyancy_position 885.144043 cc 2019-12-13T17:09:58.523Z,1576256998.523 [Reporter](INFO): platform_buoyancy_position 880.712158 cc 2019-12-13T17:09:58.939Z,1576256998.939 [Reporter](INFO): platform_buoyancy_position 874.265747 cc 2019-12-13T17:09:59.355Z,1576256999.355 [Reporter](INFO): platform_buoyancy_position 870.102539 cc 2019-12-13T17:09:59.759Z,1576256999.759 [Reporter](INFO): platform_buoyancy_position 863.521729 cc 2019-12-13T17:10:00.139Z,1576257000.139 [Reporter](INFO): platform_buoyancy_position 859.358521 cc 2019-12-13T17:10:00.557Z,1576257000.557 [Reporter](INFO): platform_buoyancy_position 852.777832 cc 2019-12-13T17:10:00.971Z,1576257000.971 [Reporter](INFO): platform_buoyancy_position 848.614502 cc 2019-12-13T17:10:01.292Z,1576257001.292 [NAL9602](INFO): Powering up NAL9602 2019-12-13T17:10:01.375Z,1576257001.375 [Reporter](INFO): platform_buoyancy_position 842.033813 cc 2019-12-13T17:10:01.758Z,1576257001.758 [Reporter](INFO): platform_buoyancy_position 837.870483 cc 2019-12-13T17:10:02.179Z,1576257002.179 [Reporter](INFO): platform_buoyancy_position 831.424072 cc 2019-12-13T17:10:02.587Z,1576257002.587 [Reporter](INFO): platform_buoyancy_position 826.992188 cc 2019-12-13T17:10:03.005Z,1576257003.005 [Reporter](INFO): platform_buoyancy_position 820.814392 cc 2019-12-13T17:10:03.419Z,1576257003.419 [Reporter](INFO): platform_buoyancy_position 816.113892 cc 2019-12-13T17:10:03.811Z,1576257003.811 [Reporter](INFO): platform_buoyancy_position 809.801758 cc 2019-12-13T17:10:04.238Z,1576257004.238 [Reporter](INFO): platform_buoyancy_position 805.504150 cc 2019-12-13T17:10:04.639Z,1576257004.639 [Reporter](INFO): platform_buoyancy_position 799.192078 cc 2019-12-13T17:10:05.030Z,1576257005.030 [Reporter](INFO): platform_buoyancy_position 794.760193 cc 2019-12-13T17:10:05.432Z,1576257005.432 [Reporter](INFO): platform_buoyancy_position 788.582397 cc 2019-12-13T17:10:05.835Z,1576257005.835 [Reporter](INFO): platform_buoyancy_position 784.016174 cc 2019-12-13T17:10:06.231Z,1576257006.231 [Reporter](INFO): platform_buoyancy_position 779.852844 cc 2019-12-13T17:10:06.633Z,1576257006.633 [Reporter](INFO): platform_buoyancy_position 773.406494 cc 2019-12-13T17:10:07.027Z,1576257007.027 [Reporter](INFO): platform_buoyancy_position 768.974548 cc 2019-12-13T17:10:07.431Z,1576257007.431 [Reporter](INFO): platform_buoyancy_position 764.274048 cc 2019-12-13T17:10:07.827Z,1576257007.827 [Reporter](INFO): platform_buoyancy_position 758.364868 cc 2019-12-13T17:10:08.253Z,1576257008.253 [Reporter](INFO): platform_buoyancy_position 751.918457 cc 2019-12-13T17:10:08.627Z,1576257008.627 [Reporter](INFO): platform_buoyancy_position 747.486572 cc 2019-12-13T17:10:09.053Z,1576257009.053 [Reporter](INFO): platform_buoyancy_position 741.174500 cc 2019-12-13T17:10:09.439Z,1576257009.439 [Reporter](INFO): platform_buoyancy_position 736.742554 cc 2019-12-13T17:10:09.831Z,1576257009.831 [Reporter](INFO): platform_buoyancy_position 732.176392 cc 2019-12-13T17:10:10.263Z,1576257010.263 [Reporter](INFO): platform_buoyancy_position 725.998596 cc 2019-12-13T17:10:10.673Z,1576257010.673 [Reporter](INFO): platform_buoyancy_position 719.686462 cc 2019-12-13T17:10:11.072Z,1576257011.072 [Reporter](INFO): platform_buoyancy_position 715.254578 cc 2019-12-13T17:10:11.455Z,1576257011.455 [Reporter](INFO): platform_buoyancy_position 711.091248 cc 2019-12-13T17:10:11.906Z,1576257011.906 [Reporter](INFO): platform_buoyancy_position 704.644836 cc 2019-12-13T17:10:12.206Z,1576257012.206 [NAL9602](INFO): NAL9602 initialized 2019-12-13T17:10:12.311Z,1576257012.311 [Reporter](INFO): platform_buoyancy_position 698.198486 cc 2019-12-13T17:10:12.701Z,1576257012.701 [Reporter](INFO): platform_buoyancy_position 693.900879 cc 2019-12-13T17:10:13.091Z,1576257013.091 [Reporter](INFO): platform_buoyancy_position 689.468994 cc 2019-12-13T17:10:13.507Z,1576257013.507 [Reporter](INFO): platform_buoyancy_position 683.156860 cc 2019-12-13T17:10:13.899Z,1576257013.899 [Reporter](INFO): platform_buoyancy_position 678.724976 cc 2019-12-13T17:10:14.309Z,1576257014.309 [Reporter](INFO): platform_buoyancy_position 672.412842 cc 2019-12-13T17:10:14.723Z,1576257014.723 [Reporter](INFO): platform_buoyancy_position 667.980957 cc 2019-12-13T17:10:15.095Z,1576257015.095 [Reporter](INFO): platform_buoyancy_position 661.803162 cc 2019-12-13T17:10:15.514Z,1576257015.514 [Reporter](INFO): platform_buoyancy_position 657.236938 cc 2019-12-13T17:10:15.929Z,1576257015.929 [Reporter](INFO): platform_buoyancy_position 651.059143 cc 2019-12-13T17:10:16.330Z,1576257016.330 [Reporter](INFO): platform_buoyancy_position 646.492981 cc 2019-12-13T17:10:16.719Z,1576257016.719 [Reporter](INFO): platform_buoyancy_position 642.195374 cc 2019-12-13T17:10:17.126Z,1576257017.126 [Reporter](INFO): platform_buoyancy_position 635.883240 cc 2019-12-13T17:10:17.584Z,1576257017.584 [Reporter](INFO): platform_buoyancy_position 629.436890 cc 2019-12-13T17:10:17.964Z,1576257017.964 [Reporter](INFO): platform_buoyancy_position 625.139282 cc 2019-12-13T17:10:18.432Z,1576257018.432 [Reporter](INFO): platform_buoyancy_position 618.558533 cc 2019-12-13T17:10:18.783Z,1576257018.783 [Reporter](INFO): platform_buoyancy_position 614.395264 cc 2019-12-13T17:10:19.163Z,1576257019.163 [Reporter](INFO): platform_buoyancy_position 609.963379 cc 2019-12-13T17:10:19.566Z,1576257019.566 [Reporter](INFO): platform_buoyancy_position 603.651245 cc 2019-12-13T17:10:19.948Z,1576257019.948 [Reporter](INFO): platform_buoyancy_position 599.219360 cc 2019-12-13T17:10:20.362Z,1576257020.362 [Reporter](INFO): platform_buoyancy_position 593.578735 cc 2019-12-13T17:10:20.751Z,1576257020.751 [Reporter](INFO): platform_buoyancy_position 588.609680 cc 2019-12-13T17:10:21.143Z,1576257021.143 [Reporter](INFO): platform_buoyancy_position 582.969055 cc 2019-12-13T17:10:21.568Z,1576257021.568 [Reporter](INFO): platform_buoyancy_position 577.865662 cc 2019-12-13T17:10:21.967Z,1576257021.967 [Reporter](INFO): platform_buoyancy_position 572.762268 cc 2019-12-13T17:10:22.371Z,1576257022.371 [Reporter](INFO): platform_buoyancy_position 566.987366 cc 2019-12-13T17:10:22.793Z,1576257022.793 [Reporter](INFO): platform_buoyancy_position 562.286865 cc 2019-12-13T17:10:23.175Z,1576257023.175 [Reporter](INFO): platform_buoyancy_position 556.780579 cc 2019-12-13T17:10:23.597Z,1576257023.597 [Reporter](INFO): platform_buoyancy_position 551.945740 cc 2019-12-13T17:10:23.999Z,1576257023.999 [Reporter](INFO): platform_buoyancy_position 545.633667 cc 2019-12-13T17:10:24.379Z,1576257024.379 [Reporter](INFO): platform_buoyancy_position 541.201782 cc 2019-12-13T17:10:24.799Z,1576257024.799 [Reporter](INFO): platform_buoyancy_position 534.889648 cc 2019-12-13T17:10:25.215Z,1576257025.215 [Reporter](INFO): platform_buoyancy_position 530.457764 cc 2019-12-13T17:10:25.603Z,1576257025.603 [Reporter](INFO): platform_buoyancy_position 524.145630 cc 2019-12-13T17:10:26.025Z,1576257026.025 [Reporter](INFO): platform_buoyancy_position 519.713745 cc 2019-12-13T17:10:26.415Z,1576257026.415 [Reporter](INFO): platform_buoyancy_position 513.670227 cc 2019-12-13T17:10:26.819Z,1576257026.819 [Reporter](INFO): platform_buoyancy_position 508.969696 cc 2019-12-13T17:10:27.219Z,1576257027.219 [Reporter](INFO): platform_buoyancy_position 503.597778 cc 2019-12-13T17:10:27.615Z,1576257027.615 [Reporter](INFO): platform_buoyancy_position 498.360016 cc 2019-12-13T17:10:28.023Z,1576257028.023 [Reporter](INFO): platform_buoyancy_position 493.928162 cc 2019-12-13T17:10:28.445Z,1576257028.445 [Reporter](INFO): platform_buoyancy_position 487.481750 cc 2019-12-13T17:10:28.835Z,1576257028.835 [Reporter](INFO): platform_buoyancy_position 483.049866 cc 2019-12-13T17:10:29.227Z,1576257029.227 [Reporter](INFO): platform_buoyancy_position 476.872070 cc 2019-12-13T17:10:29.647Z,1576257029.647 [Reporter](INFO): platform_buoyancy_position 472.440125 cc 2019-12-13T17:10:30.062Z,1576257030.062 [Reporter](INFO): platform_buoyancy_position 466.262329 cc 2019-12-13T17:10:30.456Z,1576257030.456 [Reporter](INFO): platform_buoyancy_position 461.696167 cc 2019-12-13T17:10:30.873Z,1576257030.873 [Reporter](INFO): platform_buoyancy_position 456.727051 cc 2019-12-13T17:10:31.266Z,1576257031.266 [Reporter](INFO): platform_buoyancy_position 450.952148 cc 2019-12-13T17:10:31.671Z,1576257031.671 [Reporter](INFO): platform_buoyancy_position 444.505737 cc 2019-12-13T17:10:32.067Z,1576257032.067 [Reporter](INFO): platform_buoyancy_position 440.208130 cc 2019-12-13T17:10:32.467Z,1576257032.467 [Reporter](INFO): platform_buoyancy_position 434.030334 cc 2019-12-13T17:10:32.871Z,1576257032.871 [Reporter](INFO): platform_buoyancy_position 429.598450 cc 2019-12-13T17:10:33.293Z,1576257033.293 [Reporter](INFO): platform_buoyancy_position 423.689270 cc 2019-12-13T17:10:33.683Z,1576257033.683 [Reporter](INFO): platform_buoyancy_position 418.720154 cc 2019-12-13T17:10:34.075Z,1576257034.075 [Reporter](INFO): platform_buoyancy_position 414.422546 cc 2019-12-13T17:10:34.496Z,1576257034.496 [Reporter](INFO): platform_buoyancy_position 408.110474 cc 2019-12-13T17:10:34.910Z,1576257034.910 [Reporter](INFO): platform_buoyancy_position 403.275635 cc 2019-12-13T17:10:35.307Z,1576257035.307 [Reporter](INFO): platform_buoyancy_position 397.366455 cc 2019-12-13T17:10:35.696Z,1576257035.696 [Reporter](INFO): platform_buoyancy_position 392.800232 cc 2019-12-13T17:10:36.115Z,1576257036.115 [Reporter](INFO): platform_buoyancy_position 386.488159 cc 2019-12-13T17:10:36.515Z,1576257036.515 [Reporter](INFO): platform_buoyancy_position 382.190552 cc 2019-12-13T17:10:36.915Z,1576257036.915 [Reporter](INFO): platform_buoyancy_position 375.878418 cc 2019-12-13T17:10:37.337Z,1576257037.337 [Reporter](INFO): platform_buoyancy_position 371.446533 cc 2019-12-13T17:10:37.715Z,1576257037.715 [Reporter](INFO): platform_buoyancy_position 365.000122 cc 2019-12-13T17:10:38.146Z,1576257038.146 [Reporter](INFO): platform_buoyancy_position 360.702515 cc 2019-12-13T17:10:38.558Z,1576257038.558 [Reporter](INFO): platform_buoyancy_position 354.390442 cc 2019-12-13T17:10:38.966Z,1576257038.966 [Reporter](INFO): platform_buoyancy_position 350.092834 cc 2019-12-13T17:10:39.389Z,1576257039.389 [Reporter](INFO): platform_buoyancy_position 343.646423 cc 2019-12-13T17:10:39.775Z,1576257039.775 [Reporter](INFO): platform_buoyancy_position 339.348816 cc 2019-12-13T17:10:40.175Z,1576257040.175 [Reporter](INFO): platform_buoyancy_position 333.171021 cc 2019-12-13T17:10:40.584Z,1576257040.584 [Reporter](INFO): platform_buoyancy_position 328.470520 cc 2019-12-13T17:10:41.005Z,1576257041.005 [Reporter](INFO): platform_buoyancy_position 322.024109 cc 2019-12-13T17:10:41.379Z,1576257041.379 [Reporter](INFO): platform_buoyancy_position 317.860840 cc 2019-12-13T17:10:41.784Z,1576257041.784 [Reporter](INFO): platform_buoyancy_position 313.428955 cc 2019-12-13T17:10:42.190Z,1576257042.190 [Reporter](INFO): platform_buoyancy_position 306.982544 cc 2019-12-13T17:10:42.564Z,1576257042.564 [Reporter](INFO): platform_buoyancy_position 302.550629 cc 2019-12-13T17:10:42.987Z,1576257042.987 [Reporter](INFO): platform_buoyancy_position 296.372833 cc 2019-12-13T17:10:43.310Z,1576257043.310 [NAL9602](INFO): Not Powering down - fast GPS 2019-12-13T17:10:43.407Z,1576257043.407 [Reporter](INFO): platform_buoyancy_position 291.672333 cc 2019-12-13T17:10:43.783Z,1576257043.783 [Reporter](INFO): platform_buoyancy_position 285.494537 cc 2019-12-13T17:10:44.191Z,1576257044.191 [Reporter](INFO): platform_buoyancy_position 281.196930 cc 2019-12-13T17:10:44.607Z,1576257044.607 [Reporter](INFO): platform_buoyancy_position 274.884827 cc 2019-12-13T17:10:45.007Z,1576257045.007 [Reporter](INFO): platform_buoyancy_position 270.452942 cc 2019-12-13T17:10:45.407Z,1576257045.407 [Reporter](INFO): platform_buoyancy_position 264.006531 cc 2019-12-13T17:10:45.811Z,1576257045.811 [Reporter](INFO): platform_buoyancy_position 259.843231 cc 2019-12-13T17:10:46.220Z,1576257046.220 [Reporter](INFO): platform_buoyancy_position 253.665436 cc 2019-12-13T17:10:46.632Z,1576257046.632 [Reporter](INFO): platform_buoyancy_position 248.964935 cc 2019-12-13T17:10:47.033Z,1576257047.033 [Reporter](INFO): platform_buoyancy_position 243.055725 cc 2019-12-13T17:10:47.415Z,1576257047.415 [Reporter](INFO): platform_buoyancy_position 238.355225 cc 2019-12-13T17:10:47.837Z,1576257047.837 [Reporter](INFO): platform_buoyancy_position 234.057617 cc 2019-12-13T17:10:48.227Z,1576257048.227 [Reporter](INFO): platform_buoyancy_position 227.476929 cc 2019-12-13T17:10:48.619Z,1576257048.619 [Reporter](INFO): platform_buoyancy_position 223.179321 cc 2019-12-13T17:10:49.042Z,1576257049.042 [Reporter](INFO): platform_buoyancy_position 216.867218 cc 2019-12-13T17:10:49.453Z,1576257049.453 [Reporter](INFO): platform_buoyancy_position 212.569641 cc 2019-12-13T17:10:49.891Z,1576257049.891 [Reporter](INFO): platform_buoyancy_position 207.331940 cc 2019-12-13T17:10:53.849Z,1576257053.849 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-12-13T17:10:53.849Z,1576257053.849 [DVL_micro] No Fault, FailCount= 3 2019-12-13T17:11:01.894Z,1576257061.894 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout. 2019-12-13T17:11:01.894Z,1576257061.894 [DVL_micro] Data Fault, FailCount= 1 2019-12-13T17:11:01.894Z,1576257061.894 [DVL_micro](ERROR): Data Fault 2019-12-13T17:11:02.002Z,1576257062.002 [CBIT](ERROR): Data Fault in component: DVL_micro 2019-12-13T17:11:02.369Z,1576257062.369 [DVL_micro](INFO): Powering down 2019-12-13T17:11:03.173Z,1576257063.173 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-12-13T17:11:03.173Z,1576257063.173 [DVL_micro] No Fault, FailCount= 1 2019-12-13T17:11:20.936Z,1576257080.936 [DVL_micro](ERROR): No DVL communication! Re-initializing 2019-12-13T17:11:20.936Z,1576257080.936 [DVL_micro] Communications Fault, FailCount= 2 2019-12-13T17:11:20.936Z,1576257080.936 [DVL_micro](ERROR): Communications Fault 2019-12-13T17:11:21.008Z,1576257081.008 [CBIT](ERROR): Communications Fault in component: DVL_micro 2019-12-13T17:11:21.409Z,1576257081.409 [DVL_micro](INFO): Powering down 2019-12-13T17:11:22.208Z,1576257082.208 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-12-13T17:11:22.208Z,1576257082.208 [DVL_micro] No Fault, FailCount= 2 2019-12-13T17:11:39.630Z,1576257099.630 [CommandLine](IMPORTANT): got command maintain control VerticalControl.buoyancyAction 150.000000 cubic_centimeter 2019-12-13T17:11:39.926Z,1576257099.926 [DVL_micro](ERROR): No DVL communication! Re-initializing 2019-12-13T17:11:39.927Z,1576257099.927 [DVL_micro] Communications Fault, FailCount= 3 2019-12-13T17:11:39.927Z,1576257099.927 [DVL_micro](ERROR): Communications Fault 2019-12-13T17:11:40.019Z,1576257100.019 [CBIT](ERROR): Communications Fault in component: DVL_micro 2019-12-13T17:11:40.020Z,1576257100.020 [CBIT](CRITICAL): Communications Fault in component: DVL_micro 2019-12-13T17:11:40.397Z,1576257100.397 [DVL_micro](INFO): Powering down 2019-12-13T17:11:40.428Z,1576257100.428 [CBIT](INFO): Critical error at 20191213T171140 2019-12-13T17:11:44.508Z,1576257104.508 [Reporter](INFO): platform_buoyancy_position 201.825623 cc 2019-12-13T17:11:45.647Z,1576257105.647 [Reporter](INFO): platform_buoyancy_position 199.676819 cc 2019-12-13T17:11:46.132Z,1576257106.132 [Reporter](INFO): platform_buoyancy_position 197.662323 cc 2019-12-13T17:11:46.462Z,1576257106.462 [Reporter](INFO): platform_buoyancy_position 197.528015 cc 2019-12-13T17:11:46.871Z,1576257106.871 [Reporter](INFO): platform_buoyancy_position 197.393738 cc 2019-12-13T17:11:47.267Z,1576257107.267 [Reporter](INFO): platform_buoyancy_position 195.244934 cc 2019-12-13T17:11:47.663Z,1576257107.663 [Reporter](INFO): platform_buoyancy_position 194.976318 cc 2019-12-13T17:11:48.067Z,1576257108.067 [Reporter](INFO): platform_buoyancy_position 193.230438 cc 2019-12-13T17:11:48.492Z,1576257108.492 [Reporter](INFO): platform_buoyancy_position 191.081635 cc 2019-12-13T17:11:48.893Z,1576257108.893 [Reporter](INFO): platform_buoyancy_position 190.813019 cc 2019-12-13T17:11:49.286Z,1576257109.286 [Reporter](INFO): platform_buoyancy_position 188.932831 cc 2019-12-13T17:11:49.700Z,1576257109.700 [Reporter](INFO): platform_buoyancy_position 187.186920 cc 2019-12-13T17:11:50.125Z,1576257110.125 [Reporter](INFO): platform_buoyancy_position 186.649719 cc 2019-12-13T17:11:50.526Z,1576257110.526 [Reporter](INFO): platform_buoyancy_position 184.769531 cc 2019-12-13T17:11:50.911Z,1576257110.911 [Reporter](INFO): platform_buoyancy_position 184.500916 cc 2019-12-13T17:11:51.321Z,1576257111.321 [Reporter](INFO): platform_buoyancy_position 182.352142 cc 2019-12-13T17:11:51.737Z,1576257111.737 [Reporter](INFO): platform_buoyancy_position 180.337616 cc 2019-12-13T17:11:52.151Z,1576257112.151 [Reporter](INFO): platform_buoyancy_position 180.203339 cc 2019-12-13T17:11:52.572Z,1576257112.572 [Reporter](INFO): platform_buoyancy_position 178.054535 cc 2019-12-13T17:11:53.327Z,1576257113.327 [Reporter](INFO): platform_buoyancy_position 176.040039 cc 2019-12-13T17:11:53.749Z,1576257113.749 [Reporter](INFO): platform_buoyancy_position 173.891235 cc 2019-12-13T17:11:54.549Z,1576257114.549 [Reporter](INFO): platform_buoyancy_position 171.742432 cc 2019-12-13T17:11:54.960Z,1576257114.960 [Reporter](INFO): platform_buoyancy_position 169.593628 cc 2019-12-13T17:11:55.755Z,1576257115.755 [Reporter](INFO): platform_buoyancy_position 167.444824 cc 2019-12-13T17:11:56.170Z,1576257116.170 [Reporter](INFO): platform_buoyancy_position 167.310516 cc 2019-12-13T17:11:56.564Z,1576257116.564 [Reporter](INFO): platform_buoyancy_position 165.430328 cc 2019-12-13T17:11:56.980Z,1576257116.980 [Reporter](INFO): platform_buoyancy_position 163.147217 cc 2019-12-13T17:11:57.371Z,1576257117.371 [Reporter](INFO): platform_buoyancy_position 163.012939 cc 2019-12-13T17:11:57.771Z,1576257117.771 [Reporter](INFO): platform_buoyancy_position 160.998413 cc 2019-12-13T17:11:58.175Z,1576257118.175 [Reporter](INFO): platform_buoyancy_position 160.595520 cc 2019-12-13T17:11:58.597Z,1576257118.597 [Reporter](INFO): platform_buoyancy_position 158.715332 cc 2019-12-13T17:13:06.882Z,1576257186.882 [CommandLine](IMPORTANT): got command run ./Missions/Insert/Science.xml 2019-12-13T17:13:06.889Z,1576257186.889 [MissionManager](INFO): Loading Mission: ./Missions/Insert/Science.xml 2019-12-13T17:13:07.690Z,1576257187.690 [MissionManager](INFO): DefineArg Science.SampleISUS = 0 bool 2019-12-13T17:13:07.713Z,1576257187.713 [MissionManager](INFO): DefineArg Science.SampleISUSmaxPitch = 60.000000 arcdeg 2019-12-13T17:13:07.716Z,1576257187.716 [MissionManager](INFO): DefineArg Science.SampleISUSminPitch = -60.000000 arcdeg 2019-12-13T17:13:07.735Z,1576257187.735 [MissionManager](INFO): DefineArg Science.PeakDetectChlActive = 0 bool 2019-12-13T17:13:07.791Z,1576257187.791 [MissionManager](INFO): DefineArg Science.TimeWindowPeakReport = nan min 2019-12-13T17:13:07.810Z,1576257187.810 [MissionManager](INFO): DefineArg Science.HighestChlPeakReportActive = 0 bool 2019-12-13T17:13:07.841Z,1576257187.841 [MissionManager](INFO): DefineArg Science.PatchTracking = 0 bool 2019-12-13T17:13:07.844Z,1576257187.844 [MissionManager](INFO): DefineArg Science.FilterWidthHorizontal = 3.000000 count 2019-12-13T17:13:07.863Z,1576257187.863 [MissionManager](INFO): DefineArg Science.NumProfilesSlidingwindow = 100.000000 count 2019-12-13T17:13:07.882Z,1576257187.882 [MissionManager](INFO): DefineArg Science.OffPeakFractionHorizontal = 80.000000 % 2019-12-13T17:13:07.922Z,1576257187.922 [MissionManager](INFO): DefineArg Science.PeakDetectNO3Active = 0 bool 2019-12-13T17:13:07.925Z,1576257187.925 [MissionManager](INFO): DefineArg Science.PeakDetectOilActive = 0 bool 2019-12-13T17:13:07.927Z,1576257187.927 [MissionManager](INFO): DefineArg Science.PeakDetectFDOMActive = 0 bool 2019-12-13T17:13:07.968Z,1576257187.968 [MissionManager](INFO): DefineArg Science.UpwardDerivativeOfTemperatureActive = 0 bool 2019-12-13T17:13:07.971Z,1576257187.971 [MissionManager](INFO): DefineArg Science.EnabledAanderaaO2 = 1.000000 bool 2019-12-13T17:13:07.999Z,1576257187.999 [MissionManager](INFO): DefineArg Science.EnabledNeilBrown = 0.000000 bool 2019-12-13T17:13:08.003Z,1576257188.003 [MissionManager](INFO): DefineArg Science.EnabledSeabird = 1.000000 bool 2019-12-13T17:13:08.062Z,1576257188.062 [MissionManager](INFO): DefineArg Science.EnabledTurbulence_NPS = 0.000000 bool 2019-12-13T17:13:08.078Z,1576257188.078 [MissionManager](INFO): DefineArg Science.EnabledWetLabsBB2FL = 1.000000 bool 2019-12-13T17:13:08.134Z,1576257188.134 [MissionManager](INFO): DefineArg Science.EnabledWetLabsSeaOWL_UV_A = 0.000000 bool 2019-12-13T17:13:08.154Z,1576257188.154 [MissionManager](INFO): DefineArg Science.EnabledWetLabsUBAT = 0.000000 bool 2019-12-13T17:13:08.183Z,1576257188.183 [MissionManager](INFO): DefineArg Science.EnabledISUS = 0.000000 bool 2019-12-13T17:13:08.215Z,1576257188.215 [MissionManager](INFO): DefineArg Science.LowPassWindowLength = 20.000000 count 2019-12-13T17:13:08.238Z,1576257188.238 [MissionManager](INFO): DefineArg Science.MedianFilterLen = 5.000000 count 2019-12-13T17:13:08.265Z,1576257188.265 [MissionManager](INFO): DefineArg Science.PeakChlShallowBound = nan m 2019-12-13T17:13:08.268Z,1576257188.268 [MissionManager](INFO): DefineArg Science.PeakChlDeepBound = nan m 2019-12-13T17:13:08.287Z,1576257188.287 [MissionManager](INFO): DefineArg Science.PeakShallowBound = nan m 2019-12-13T17:13:08.319Z,1576257188.319 [MissionManager](INFO): DefineArg Science.PeakDeepBound = nan m 2019-12-13T17:13:08.346Z,1576257188.346 [MissionManager](INFO): DefineOutput Science.PeakChl = 0.000000 ug/l 2019-12-13T17:13:08.369Z,1576257188.369 [MissionManager](INFO): DefineOutput Science.PeakChlDepth = 0.000000 m 2019-12-13T17:13:08.372Z,1576257188.372 [MissionManager](INFO): DefineOutput Science.PeakChlTemperature = 0.000000 degC 2019-12-13T17:13:08.392Z,1576257188.392 [MissionManager](INFO): DefineOutput Science.PeakChlLatitude = nan arcdeg 2019-12-13T17:13:08.496Z,1576257188.496 [MissionManager](INFO): DefineOutput Science.PeakChlLongitude = nan arcdeg 2019-12-13T17:13:08.523Z,1576257188.523 [MissionManager](INFO): DefineOutput Science.PeakNO3 = 0.000000 umol/l 2019-12-13T17:13:08.526Z,1576257188.526 [MissionManager](INFO): DefineOutput Science.PeakNO3Depth = 0.000000 m 2019-12-13T17:13:08.573Z,1576257188.573 [MissionManager](INFO): DefineOutput Science.PeakNO3Latitude = nan arcdeg 2019-12-13T17:13:08.588Z,1576257188.588 [MissionManager](INFO): DefineOutput Science.PeakNO3Longitude = nan arcdeg 2019-12-13T17:13:08.612Z,1576257188.612 [MissionManager](INFO): DefineOutput Science.PatchChl = 0.000000 m 2019-12-13T17:13:08.627Z,1576257188.627 [MissionManager](INFO): DefineOutput Science.PatchChlDepth = 0.000000 m 2019-12-13T17:13:08.639Z,1576257188.639 [MissionManager](INFO): DefineOutput Science.PatchChlLatitude = nan arcdeg 2019-12-13T17:13:08.666Z,1576257188.666 [MissionManager](INFO): DefineOutput Science.PatchChlLongitude = nan arcdeg 2019-12-13T17:13:08.682Z,1576257188.682 [MissionManager](INFO): DefineOutput Science.PatchChlDistance = nan m 2019-12-13T17:13:08.697Z,1576257188.697 [MissionManager](INFO): DefineOutput Science.PeakOil = 0.000000 kg/m3 2019-12-13T17:13:08.700Z,1576257188.700 [MissionManager](INFO): DefineOutput Science.PeakOilDepth = 0.000000 m 2019-12-13T17:13:08.724Z,1576257188.724 [MissionManager](INFO): DefineOutput Science.PeakOilLatitude = nan arcdeg 2019-12-13T17:13:08.736Z,1576257188.736 [MissionManager](INFO): DefineOutput Science.PeakOilLongitude = nan arcdeg 2019-12-13T17:13:08.763Z,1576257188.763 [MissionManager](INFO): DefineOutput Science.PeakFDOM = 0.000000 ppb 2019-12-13T17:13:08.766Z,1576257188.766 [MissionManager](INFO): DefineOutput Science.PeakFDOMDepth = 0.000000 m 2019-12-13T17:13:08.794Z,1576257188.794 [MissionManager](INFO): DefineOutput Science.PeakFDOMLatitude = nan arcdeg 2019-12-13T17:13:08.797Z,1576257188.797 [MissionManager](INFO): DefineOutput Science.PeakFDOMLongitude = nan arcdeg 2019-12-13T17:13:08.800Z,1576257188.800 [MissionManager](INFO): DefineOutput Science.PatchFDOMDistance = nan m 2019-12-13T17:13:08.941Z,1576257188.941 [Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth. 2019-12-13T17:13:08.968Z,1576257188.968 [Science:HighestChlPeakReport:A.PeakDetectHorizontal](DEBUG): Construct PeakDetectHorizontal. 2019-12-13T17:13:09.054Z,1576257189.054 [Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth. 2019-12-13T17:13:09.104Z,1576257189.104 [Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth. 2019-12-13T17:13:09.157Z,1576257189.157 [Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth. 2019-12-13T17:13:09.291Z,1576257189.291 [MissionManager](DEBUG): Set either this or PeakDetectNO3Active to True in order to sample Nitrate. EnabledISUS must also be true. Maximum pitch to sample ISUS. (EnabledISUS must also be true.) 60.0 Minimum pitch to sample ISUS. (EnabledISUS must also be true.) -60.0 Turns on peak detection of Cholorphyll. If greater than zero, report a peak every window. If NaN or zero, this variable is ignored. NaN Turns on reporting of the highest peak value on yo-yo profiles in a horizontal sliding window (of length numProfilesSlidingwindow) If tracking a patch Width of boxcar filter applied to yoyo-wise chl peaks to pick out the highest peak. 3 Length of horizontal sliding window. The highest yoyo-wise chl peak (after low-pass filtering by a filter of length FilterWidthHorizontal) within this window. 100 When filtered horizontal value is this fraction of the peak, consider it outside the patch. 80 Turns on peak detection of Nitrate (and turns on ISUS). Turns on peak detection of Dissolved Oil. Turns on peak detection of concentration_of_chromophoric_dissolved_organic_matter_in_sea_water from FDOM sensor. Turns on seawater temperature derivative. Automatically set to True if the Aanderaa O2 sensor is installed. Set to false to disable reading Aandera O2. Automatically set to true if the Neil Brown CTD is enabled. Set to false to disable reading from the Neil Brown. Automatically set to true if the CTD is enabled. Set to false to disable reading from the CTD. Automatically set to true if the NPS Turbulence sensor is enabled. Set to false to disable reading from the NPS Turbulence sensor. Automatically set to true if the the WetLabs BB2FL is enabled. Set to false to disable the WetLabs BB2FL. Automatically set to true if the the WetLabs SeaOWL UV-A is enabled. Set to false to disable the WetLabs SeaOWL UV-A. Automatically set to true if the the WetLabs UBAT is enabled. Set to false to disable the WetLabs UBAT. Automatically set to True if ISUS is enabled. Set to false to disable ISUS. Low-pass window length (based on depth sensor sampling interval 0.4 second) for low-pass filtering. 20 Median filter length (only for chlorophyll fluorescence which tends to have spikes) 5 Shallow depth bound for detecting chl peak on each descent or ascent profile. NaN Deep depth bound for detecting chl peak on each descent or ascent profile. NaN Shallow depth bound for detecting any peak on each descent or ascent profile. NaN Deep depth bound for detecting any peak on each descent or ascent profile. NaN 0 0 0 NaN NaN 0 0 NaN NaN 0 0 NaN NaN NaN 0 0 NaN NaN 0 0 NaN NaN NaN 2019-12-13T17:13:09.317Z,1576257189.317 [CommandLine](IMPORTANT): Running ./Missions/Insert/Science.xml 2019-12-13T17:13:09.325Z,1576257189.325 [Default] Stopped 2019-12-13T17:13:09.325Z,1576257189.325 [Default](DEBUG): Aggregate::uninitialize Default 2019-12-13T17:13:09.325Z,1576257189.325 [Default:B.GoToSurface] Stopped 2019-12-13T17:13:09.325Z,1576257189.325 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2019-12-13T17:13:09.325Z,1576257189.325 [Default:CheckIn] Stopped 2019-12-13T17:13:09.325Z,1576257189.325 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-12-13T17:13:09.326Z,1576257189.326 [Default:CheckIn:C.Wait] Stopped 2019-12-13T17:13:09.326Z,1576257189.326 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-12-13T17:13:09.326Z,1576257189.326 [MissionManager](IMPORTANT): Started mission Science 2019-12-13T17:13:09.326Z,1576257189.326 [Science] Running Loop=1 2019-12-13T17:13:09.326Z,1576257189.326 [Science](DEBUG): Aggregate::initialize Science 2019-12-13T17:13:09.326Z,1576257189.326 [Science:A] Running Loop=1 2019-12-13T17:13:09.326Z,1576257189.326 [Science:B] Running Loop=1 2019-12-13T17:13:09.326Z,1576257189.326 [Science:C] Running Loop=1 2019-12-13T17:13:09.326Z,1576257189.326 [Science:D] Running Loop=1 2019-12-13T17:13:09.326Z,1576257189.326 [Science:E] Running Loop=1 2019-12-13T17:13:09.327Z,1576257189.327 [Science:F] Running Loop=1 2019-12-13T17:13:09.327Z,1576257189.327 [Science:G] Running Loop=1 2019-12-13T17:13:09.327Z,1576257189.327 [Science:H] Running Loop=1 2019-12-13T17:13:09.327Z,1576257189.327 [Science:Read_Oil] Running Loop=1 2019-12-13T17:13:09.327Z,1576257189.327 [Science:PeakDetectChl] Running Loop=1 2019-12-13T17:13:09.327Z,1576257189.327 [Science:PeakDetectChl](DEBUG): Aggregate::initialize Science:PeakDetectChl 2019-12-13T17:13:09.327Z,1576257189.327 [Science:PeakDetectChl:A.PeakDetectVsDepth] Running Loop=1 2019-12-13T17:13:09.327Z,1576257189.327 [Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Initialize. 2019-12-13T17:13:09.331Z,1576257189.331 [Science:HighestChlPeakReport] Running Loop=1 2019-12-13T17:13:09.331Z,1576257189.331 [Science:HighestChlPeakReport](DEBUG): Aggregate::initialize Science:HighestChlPeakReport 2019-12-13T17:13:09.331Z,1576257189.331 [Science:HighestChlPeakReport:A.PeakDetectHorizontal] Running Loop=1 2019-12-13T17:13:09.331Z,1576257189.331 [Science:HighestChlPeakReport:A.PeakDetectHorizontal](INFO): Initialize. 2019-12-13T17:13:09.332Z,1576257189.332 [Science:PeakDetectNO3] Running Loop=1 2019-12-13T17:13:09.332Z,1576257189.332 [Science:PeakDetectNO3](DEBUG): Aggregate::initialize Science:PeakDetectNO3 2019-12-13T17:13:09.332Z,1576257189.332 [Science:PeakDetectNO3:A.PeakDetectVsDepth] Running Loop=1 2019-12-13T17:13:09.332Z,1576257189.332 [Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Initialize. 2019-12-13T17:13:09.342Z,1576257189.342 [Science:PeakDetectOil] Running Loop=1 2019-12-13T17:13:09.342Z,1576257189.342 [Science:PeakDetectOil](DEBUG): Aggregate::initialize Science:PeakDetectOil 2019-12-13T17:13:09.343Z,1576257189.343 [Science:PeakDetectOil:A.PeakDetectVsDepth] Running Loop=1 2019-12-13T17:13:09.343Z,1576257189.343 [Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Initialize. 2019-12-13T17:13:09.369Z,1576257189.369 [Science:PeakDetectFDOM] Running Loop=1 2019-12-13T17:13:09.369Z,1576257189.369 [Science:PeakDetectFDOM](DEBUG): Aggregate::initialize Science:PeakDetectFDOM 2019-12-13T17:13:09.369Z,1576257189.369 [Science:PeakDetectFDOM:A.PeakDetectVsDepth] Running Loop=1 2019-12-13T17:13:09.369Z,1576257189.369 [Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Initialize. 2019-12-13T17:13:09.372Z,1576257189.372 [Science:PeakDetectFDOM] Stopped 2019-12-13T17:13:09.372Z,1576257189.372 [Science:PeakDetectFDOM](DEBUG): Aggregate::uninitialize Science:PeakDetectFDOM 2019-12-13T17:13:09.372Z,1576257189.372 [Science:PeakDetectFDOM:A.PeakDetectVsDepth] Stopped 2019-12-13T17:13:09.372Z,1576257189.372 [Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Uninitialize. 2019-12-13T17:13:09.372Z,1576257189.372 [Science:PeakDetectOil] Stopped 2019-12-13T17:13:09.372Z,1576257189.372 [Science:PeakDetectOil](DEBUG): Aggregate::uninitialize Science:PeakDetectOil 2019-12-13T17:13:09.372Z,1576257189.372 [Science:PeakDetectOil:A.PeakDetectVsDepth] Stopped 2019-12-13T17:13:09.372Z,1576257189.372 [Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Uninitialize. 2019-12-13T17:13:09.372Z,1576257189.372 [Science:PeakDetectNO3] Stopped 2019-12-13T17:13:09.389Z,1576257189.389 [Science:PeakDetectNO3](DEBUG): Aggregate::uninitialize Science:PeakDetectNO3 2019-12-13T17:13:09.389Z,1576257189.389 [Science:PeakDetectNO3:A.PeakDetectVsDepth] Stopped 2019-12-13T17:13:09.389Z,1576257189.389 [Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Uninitialize. 2019-12-13T17:13:09.389Z,1576257189.389 [Science:HighestChlPeakReport] Stopped 2019-12-13T17:13:09.389Z,1576257189.389 [Science:HighestChlPeakReport](DEBUG): Aggregate::uninitialize Science:HighestChlPeakReport 2019-12-13T17:13:09.389Z,1576257189.389 [Science:HighestChlPeakReport:A.PeakDetectHorizontal] Stopped 2019-12-13T17:13:09.389Z,1576257189.389 [Science:HighestChlPeakReport:A.PeakDetectHorizontal](DEBUG): Uninitialize. 2019-12-13T17:13:09.389Z,1576257189.389 [Science:PeakDetectChl] Stopped 2019-12-13T17:13:09.390Z,1576257189.390 [Science:PeakDetectChl](DEBUG): Aggregate::uninitialize Science:PeakDetectChl 2019-12-13T17:13:09.390Z,1576257189.390 [Science:PeakDetectChl:A.PeakDetectVsDepth] Stopped 2019-12-13T17:13:09.390Z,1576257189.390 [Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Uninitialize. 2019-12-13T17:13:09.390Z,1576257189.390 [Science:Read_Oil] Stopped 2019-12-13T17:13:09.390Z,1576257189.390 [Science:H] Stopped 2019-12-13T17:13:09.390Z,1576257189.390 [Science:G] Running Loop=1 2019-12-13T17:13:09.391Z,1576257189.391 [Science:G](DEBUG): Initialize ReadDataComponent to sense mass_concentration_of_chlorophyll_in_sea_water 2019-12-13T17:13:09.391Z,1576257189.391 [Science:F] Stopped 2019-12-13T17:13:09.391Z,1576257189.391 [Science:E] Stopped 2019-12-13T17:13:09.391Z,1576257189.391 [Science:D] Running Loop=1 2019-12-13T17:13:09.391Z,1576257189.391 [Science:D](DEBUG): Initialize ReadDataComponent to sense CTD_Seabird.sea_water_temperature 2019-12-13T17:13:09.392Z,1576257189.392 [Science:D](DEBUG): Initialize ReadDataComponent to sense CTD_Seabird.sea_water_salinity 2019-12-13T17:13:09.392Z,1576257189.392 [Science:C] Running Loop=1 2019-12-13T17:13:09.406Z,1576257189.406 [Science:C](DEBUG): Initialize ReadDataComponent to sense sea_water_temperature 2019-12-13T17:13:09.406Z,1576257189.406 [Science:C](DEBUG): Initialize ReadDataComponent to sense sea_water_salinity 2019-12-13T17:13:09.406Z,1576257189.406 [Science:B] Stopped 2019-12-13T17:13:09.407Z,1576257189.407 [Science:A] Running Loop=1 2019-12-13T17:13:09.407Z,1576257189.407 [Science:A](DEBUG): Initialize ReadDataComponent to sense mass_concentration_of_oxygen_in_sea_water 2019-12-13T17:13:09.437Z,1576257189.437 [WetLabsBB2FL](INFO): Opening uart, block timeout 10ths=2 2019-12-13T17:13:09.437Z,1576257189.437 [WetLabsBB2FL](INFO): Powering up 2019-12-13T17:13:09.606Z,1576257189.606 [CTD_Seabird](INFO): Opening uart, block timeout 10ths=20 2019-12-13T17:13:12.614Z,1576257192.614 [CTD_Seabird](ERROR): Failed to parse device response: 2019-12-13T17:14:40.174Z,1576257280.174 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-12-13T17:14:40.174Z,1576257280.174 [DVL_micro] No Fault, FailCount= 3 2019-12-13T17:14:48.222Z,1576257288.222 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout. 2019-12-13T17:14:48.222Z,1576257288.222 [DVL_micro] Data Fault, FailCount= 1 2019-12-13T17:14:48.222Z,1576257288.222 [DVL_micro](ERROR): Data Fault 2019-12-13T17:14:48.314Z,1576257288.314 [CBIT](ERROR): Data Fault in component: DVL_micro 2019-12-13T17:14:48.689Z,1576257288.689 [DVL_micro](INFO): Powering down 2019-12-13T17:14:49.499Z,1576257289.499 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-12-13T17:14:49.499Z,1576257289.499 [DVL_micro] No Fault, FailCount= 1 2019-12-13T17:15:02.015Z,1576257302.015 [CommandLine](IMPORTANT): got command get 2019-12-13T17:15:02.016Z,1576257302.016 [CommandLine](FAULT): Incomplete syntax. Try: help get 2019-12-13T17:15:07.254Z,1576257307.254 [DVL_micro](ERROR): No DVL communication! Re-initializing 2019-12-13T17:15:07.254Z,1576257307.254 [DVL_micro] Communications Fault, FailCount= 2 2019-12-13T17:15:07.255Z,1576257307.255 [DVL_micro](ERROR): Communications Fault 2019-12-13T17:15:07.387Z,1576257307.387 [CBIT](ERROR): Communications Fault in component: DVL_micro 2019-12-13T17:15:07.705Z,1576257307.705 [DVL_micro](INFO): Powering down 2019-12-13T17:15:08.008Z,1576257308.008 [CommandLine](IMPORTANT): got command get platform_pitch_angle 2019-12-13T17:15:08.008Z,1576257308.008 [CommandLine](IMPORTANT): platform_pitch_angle -0.178032 rad 2019-12-13T17:15:08.538Z,1576257308.538 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-12-13T17:15:08.538Z,1576257308.538 [DVL_micro] No Fault, FailCount= 2 2019-12-13T17:15:20.983Z,1576257320.983 [CommandLine](IMPORTANT): got command get platform_mass_position 2019-12-13T17:15:20.984Z,1576257320.984 [CommandLine](IMPORTANT): platform_mass_position 0.003700 m 2019-12-13T17:15:26.230Z,1576257326.230 [DVL_micro](ERROR): No DVL communication! Re-initializing 2019-12-13T17:15:26.230Z,1576257326.230 [DVL_micro] Communications Fault, FailCount= 3 2019-12-13T17:15:26.230Z,1576257326.230 [DVL_micro](ERROR): Communications Fault 2019-12-13T17:15:26.308Z,1576257326.308 [CBIT](ERROR): Communications Fault in component: DVL_micro 2019-12-13T17:15:26.308Z,1576257326.308 [CBIT](CRITICAL): Communications Fault in component: DVL_micro 2019-12-13T17:15:26.697Z,1576257326.697 [DVL_micro](INFO): Powering down 2019-12-13T17:15:26.736Z,1576257326.736 [CBIT](INFO): Critical error at 20191213T171526 2019-12-13T17:15:26.736Z,1576257326.736 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals 2019-12-13T17:15:27.071Z,1576257327.071 [MissionManager](INFO): MissionManager is completed. 2019-12-13T17:15:27.071Z,1576257327.071 [MissionManager](INFO): Uninitializing Mission Science 2019-12-13T17:15:27.071Z,1576257327.071 [Science] Stopped 2019-12-13T17:15:27.071Z,1576257327.071 [Science](DEBUG): Aggregate::uninitialize Science 2019-12-13T17:15:27.072Z,1576257327.072 [Science:A] Stopped 2019-12-13T17:15:27.072Z,1576257327.072 [Science:C] Stopped 2019-12-13T17:15:27.072Z,1576257327.072 [Science:D] Stopped 2019-12-13T17:15:27.072Z,1576257327.072 [Science:G] Stopped 2019-12-13T17:15:27.185Z,1576257327.185 [WetLabsBB2FL](INFO): Powering down 2019-12-13T17:15:27.462Z,1576257327.462 [MissionManager](IMPORTANT): Started mission Default 2019-12-13T17:15:27.462Z,1576257327.462 [Default] Running Loop=1 2019-12-13T17:15:27.462Z,1576257327.462 [Default](DEBUG): Aggregate::initialize Default 2019-12-13T17:15:27.462Z,1576257327.462 [Default:B.GoToSurface] Running Loop=1 2019-12-13T17:15:27.462Z,1576257327.462 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2019-12-13T17:15:27.462Z,1576257327.462 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2019-12-13T17:15:27.463Z,1576257327.463 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2019-12-13T17:15:27.463Z,1576257327.463 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2019-12-13T17:15:27.463Z,1576257327.463 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2019-12-13T17:15:27.464Z,1576257327.464 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2019-12-13T17:15:27.464Z,1576257327.464 [Default:A.Wait] Running Loop=1 2019-12-13T17:15:27.464Z,1576257327.464 [Default:A.Wait](DEBUG): Initialize Wait Component. 2019-12-13T17:15:27.977Z,1576257327.977 [Aanderaa_O2](INFO): Powering down 2019-12-13T17:15:39.457Z,1576257339.457 [CommandLine](IMPORTANT): got command maintain control VerticalControl.massPositionAction 0.000000 millimeter 2019-12-13T17:15:39.458Z,1576257339.458 [ComponentRegistry](DEBUG): SyncComponent "Maintain_VerticalControl.massPositionAction" handled in the control thread. 2019-12-13T17:15:39.620Z,1576257339.620 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,DVL_micro,NAL9602,Onboard,BPC1,Aanderaa_O2,ESPComponent,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,Maintain_VerticalControl.buoyancyAction,Maintain_VerticalControl.massPositionAction,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2019-12-13T17:15:40.795Z,1576257340.795 [Default:A.Wait](INFO): Done Waiting. 2019-12-13T17:15:40.795Z,1576257340.795 [Default:A.Wait] Stopped 2019-12-13T17:15:40.795Z,1576257340.795 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2019-12-13T17:15:41.215Z,1576257341.215 [Default:CheckIn] Running Loop=1 2019-12-13T17:15:41.215Z,1576257341.215 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-12-13T17:15:41.216Z,1576257341.216 [Default:CheckIn:Read_GPS] Running Loop=1 2019-12-13T17:15:42.098Z,1576257342.098 [Reporter](INFO): platform_mass_position 0.003631 m 2019-12-13T17:15:42.506Z,1576257342.506 [Reporter](INFO): platform_mass_position 0.003314 m 2019-12-13T17:15:42.918Z,1576257342.918 [Reporter](INFO): platform_mass_position 0.002990 m 2019-12-13T17:15:43.318Z,1576257343.318 [Reporter](INFO): platform_mass_position 0.002680 m 2019-12-13T17:15:43.726Z,1576257343.726 [Reporter](INFO): platform_mass_position 0.002366 m 2019-12-13T17:15:44.114Z,1576257344.114 [Reporter](INFO): platform_mass_position 0.002052 m 2019-12-13T17:15:44.514Z,1576257344.514 [Reporter](INFO): platform_mass_position 0.001742 m 2019-12-13T17:15:44.926Z,1576257344.926 [Reporter](INFO): platform_mass_position 0.001425 m 2019-12-13T17:15:45.334Z,1576257345.334 [Reporter](INFO): platform_mass_position 0.001096 m 2019-12-13T17:15:45.646Z,1576257345.646 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-12-13T17:15:45.730Z,1576257345.730 [Reporter](INFO): platform_mass_position 0.000787 m 2019-12-13T17:15:46.126Z,1576257346.126 [Reporter](INFO): platform_mass_position 0.000479 m 2019-12-13T17:15:46.562Z,1576257346.562 [Reporter](INFO): platform_mass_position 0.000133 m 2019-12-13T17:15:46.950Z,1576257346.950 [Reporter](INFO): platform_mass_position 0.000000 m 2019-12-13T17:18:26.477Z,1576257506.477 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-12-13T17:18:26.477Z,1576257506.477 [DVL_micro] No Fault, FailCount= 3 2019-12-13T17:18:34.518Z,1576257514.518 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout. 2019-12-13T17:18:34.518Z,1576257514.518 [DVL_micro] Data Fault, FailCount= 1 2019-12-13T17:18:34.518Z,1576257514.518 [DVL_micro](ERROR): Data Fault 2019-12-13T17:18:34.603Z,1576257514.603 [CBIT](ERROR): Data Fault in component: DVL_micro 2019-12-13T17:18:34.993Z,1576257514.993 [DVL_micro](INFO): Powering down 2019-12-13T17:18:35.767Z,1576257515.767 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-12-13T17:18:35.767Z,1576257515.767 [DVL_micro] No Fault, FailCount= 1 2019-12-13T17:18:40.585Z,1576257520.585 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170956.00,A,3648.15629,N,12147.28355,W,1.613,314.37,131219,,,A*76 2019-12-13T17:18:40.587Z,1576257520.587 [NAL9602](INFO): GPS fix at 20191213T170956: (36.802605, -121.788059) 2019-12-13T17:18:40.610Z,1576257520.610 [Default:CheckIn:Read_GPS] Stopped 2019-12-13T17:18:40.611Z,1576257520.611 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-12-13T17:18:53.501Z,1576257533.501 [DVL_micro](ERROR): No DVL communication! Re-initializing 2019-12-13T17:18:53.502Z,1576257533.502 [DVL_micro] Communications Fault, FailCount= 2 2019-12-13T17:18:53.502Z,1576257533.502 [DVL_micro](ERROR): Communications Fault 2019-12-13T17:18:53.542Z,1576257533.542 [CBIT](ERROR): Communications Fault in component: DVL_micro 2019-12-13T17:18:53.977Z,1576257533.977 [DVL_micro](INFO): Powering down 2019-12-13T17:18:54.744Z,1576257534.744 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-12-13T17:18:54.744Z,1576257534.744 [DVL_micro] No Fault, FailCount= 2 2019-12-13T17:18:59.660Z,1576257539.660 [DataOverHttps](INFO): Sending 120 bytes from file Logs/20191213T164021/Courier0019.lzma 2019-12-13T17:19:01.666Z,1576257541.666 [DataOverHttps](INFO): Moved sent file to Logs/20191213T164021/Courier0019.lzma.bak 2019-12-13T17:19:01.666Z,1576257541.666 [DataOverHttps](INFO): SBD MOMSN=12154992 2019-12-13T17:19:12.514Z,1576257552.514 [DVL_micro](ERROR): No DVL communication! Re-initializing 2019-12-13T17:19:12.514Z,1576257552.514 [DVL_micro] Communications Fault, FailCount= 3 2019-12-13T17:19:12.514Z,1576257552.514 [DVL_micro](ERROR): Communications Fault 2019-12-13T17:19:12.651Z,1576257552.651 [CBIT](ERROR): Communications Fault in component: DVL_micro 2019-12-13T17:19:12.651Z,1576257552.651 [CBIT](CRITICAL): Communications Fault in component: DVL_micro 2019-12-13T17:19:12.989Z,1576257552.989 [DVL_micro](INFO): Powering down 2019-12-13T17:19:12.990Z,1576257552.990 [NAL9602](INFO): Not Powering down - fast GPS 2019-12-13T17:19:13.154Z,1576257553.154 [CBIT](INFO): Critical error at 20191213T171912 2019-12-13T17:19:28.509Z,1576257568.509 [DataOverHttps](INFO): Sending 758 bytes from file Logs/20191213T164021/Express0020.lzma 2019-12-13T17:19:30.514Z,1576257570.514 [DataOverHttps](INFO): Moved sent file to Logs/20191213T164021/Express0020.lzma.bak 2019-12-13T17:19:30.515Z,1576257570.515 [DataOverHttps](INFO): SBD MOMSN=12155002 2019-12-13T17:19:35.203Z,1576257575.203 [Default:CheckIn:Read_Iridium] Stopped 2019-12-13T17:19:35.204Z,1576257575.204 [Default:CheckIn:C.Wait] Running Loop=1 2019-12-13T17:19:35.204Z,1576257575.204 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-12-13T17:19:40.996Z,1576257580.996 [CommandLine](IMPORTANT): got command maintain clear 2019-12-13T17:19:41.292Z,1576257581.292 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,DVL_micro,NAL9602,Onboard,BPC1,Aanderaa_O2,ESPComponent,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2019-12-13T17:19:44.223Z,1576257584.223 [Reporter](INFO): platform_mass_position 0.000062 m 2019-12-13T17:19:44.618Z,1576257584.618 [Reporter](INFO): platform_mass_position 0.000369 m 2019-12-13T17:19:45.030Z,1576257585.030 [Reporter](INFO): platform_mass_position 0.000685 m 2019-12-13T17:19:45.462Z,1576257585.462 [Reporter](INFO): platform_mass_position 0.001033 m 2019-12-13T17:19:45.818Z,1576257585.818 [Reporter](INFO): platform_mass_position 0.001312 m 2019-12-13T17:19:46.302Z,1576257586.302 [Reporter](INFO): platform_mass_position 0.001692 m 2019-12-13T17:19:46.303Z,1576257586.303 [Reporter](INFO): platform_buoyancy_position 154.417725 cc 2019-12-13T17:19:46.674Z,1576257586.674 [Reporter](INFO): platform_mass_position 0.001983 m 2019-12-13T17:19:47.094Z,1576257587.094 [Reporter](INFO): platform_mass_position 0.002312 m 2019-12-13T17:19:47.095Z,1576257587.095 [Reporter](INFO): platform_buoyancy_position 154.820618 cc 2019-12-13T17:19:47.472Z,1576257587.472 [Reporter](INFO): platform_mass_position 0.002607 m 2019-12-13T17:19:47.473Z,1576257587.473 [Reporter](INFO): platform_buoyancy_position 158.715332 cc 2019-12-13T17:19:47.888Z,1576257587.888 [Reporter](INFO): platform_mass_position 0.002933 m 2019-12-13T17:19:47.889Z,1576257587.889 [Reporter](INFO): platform_buoyancy_position 163.012939 cc 2019-12-13T17:19:48.286Z,1576257588.286 [Reporter](INFO): platform_mass_position 0.003247 m 2019-12-13T17:19:48.287Z,1576257588.287 [Reporter](INFO): platform_buoyancy_position 167.444824 cc 2019-12-13T17:19:48.686Z,1576257588.686 [Reporter](INFO): platform_mass_position 0.003557 m 2019-12-13T17:19:48.687Z,1576257588.687 [Reporter](INFO): platform_buoyancy_position 173.756927 cc 2019-12-13T17:19:49.084Z,1576257589.084 [Reporter](INFO): platform_mass_position 0.003700 m 2019-12-13T17:19:49.085Z,1576257589.085 [Reporter](INFO): platform_buoyancy_position 178.591736 cc 2019-12-13T17:19:49.583Z,1576257589.583 [Reporter](INFO): platform_buoyancy_position 184.500916 cc 2019-12-13T17:19:49.879Z,1576257589.879 [Reporter](INFO): platform_buoyancy_position 189.470032 cc 2019-12-13T17:19:50.292Z,1576257590.292 [Reporter](INFO): platform_buoyancy_position 195.244934 cc 2019-12-13T17:19:50.691Z,1576257590.691 [Reporter](INFO): platform_buoyancy_position 199.676819 cc 2019-12-13T17:19:51.103Z,1576257591.103 [Reporter](INFO): platform_buoyancy_position 206.123230 cc 2019-12-13T17:19:51.487Z,1576257591.487 [Reporter](INFO): platform_buoyancy_position 210.286530 cc 2019-12-13T17:19:51.908Z,1576257591.908 [Reporter](INFO): platform_buoyancy_position 216.867218 cc 2019-12-13T17:19:52.315Z,1576257592.315 [Reporter](INFO): platform_buoyancy_position 221.164825 cc 2019-12-13T17:19:52.719Z,1576257592.719 [Reporter](INFO): platform_buoyancy_position 227.611237 cc 2019-12-13T17:19:53.114Z,1576257593.114 [Reporter](INFO): platform_buoyancy_position 231.774536 cc 2019-12-13T17:19:53.503Z,1576257593.503 [Reporter](INFO): platform_buoyancy_position 238.086639 cc 2019-12-13T17:19:53.891Z,1576257593.891 [Reporter](INFO): platform_buoyancy_position 242.518524 cc 2019-12-13T17:19:54.311Z,1576257594.311 [Reporter](INFO): platform_buoyancy_position 248.964935 cc 2019-12-13T17:19:54.703Z,1576257594.703 [Reporter](INFO): platform_buoyancy_position 253.262558 cc 2019-12-13T17:19:55.129Z,1576257595.129 [Reporter](INFO): platform_buoyancy_position 259.843231 cc 2019-12-13T17:19:55.511Z,1576257595.511 [Reporter](INFO): platform_buoyancy_position 264.140839 cc 2019-12-13T17:19:55.930Z,1576257595.930 [Reporter](INFO): platform_buoyancy_position 268.841339 cc 2019-12-13T17:19:56.324Z,1576257596.324 [Reporter](INFO): platform_buoyancy_position 275.019135 cc 2019-12-13T17:19:56.723Z,1576257596.723 [Reporter](INFO): platform_buoyancy_position 279.182434 cc 2019-12-13T17:19:57.131Z,1576257597.131 [Reporter](INFO): platform_buoyancy_position 285.628845 cc 2019-12-13T17:19:57.547Z,1576257597.547 [Reporter](INFO): platform_buoyancy_position 289.926422 cc 2019-12-13T17:19:57.939Z,1576257597.939 [Reporter](INFO): platform_buoyancy_position 296.372833 cc 2019-12-13T17:19:58.355Z,1576257598.355 [Reporter](INFO): platform_buoyancy_position 300.670441 cc 2019-12-13T17:19:58.743Z,1576257598.743 [Reporter](INFO): platform_buoyancy_position 306.982544 cc 2019-12-13T17:19:59.163Z,1576257599.163 [Reporter](INFO): platform_buoyancy_position 311.414429 cc 2019-12-13T17:19:59.555Z,1576257599.555 [Reporter](INFO): platform_buoyancy_position 317.860840 cc 2019-12-13T17:19:59.976Z,1576257599.976 [Reporter](INFO): platform_buoyancy_position 322.158447 cc 2019-12-13T17:20:00.359Z,1576257600.359 [Reporter](INFO): platform_buoyancy_position 328.201965 cc 2019-12-13T17:20:00.778Z,1576257600.778 [Reporter](INFO): platform_buoyancy_position 332.902466 cc 2019-12-13T17:20:01.171Z,1576257601.171 [Reporter](INFO): platform_buoyancy_position 337.468628 cc 2019-12-13T17:20:01.587Z,1576257601.587 [Reporter](INFO): platform_buoyancy_position 343.646423 cc 2019-12-13T17:20:01.983Z,1576257601.983 [Reporter](INFO): platform_buoyancy_position 347.944031 cc 2019-12-13T17:20:02.491Z,1576257602.491 [Reporter](INFO): platform_buoyancy_position 354.793335 cc 2019-12-13T17:20:02.835Z,1576257602.835 [Reporter](INFO): platform_buoyancy_position 358.956665 cc 2019-12-13T17:20:03.301Z,1576257603.301 [Reporter](INFO): platform_buoyancy_position 365.000122 cc 2019-12-13T17:20:03.606Z,1576257603.606 [Reporter](INFO): platform_buoyancy_position 369.432068 cc 2019-12-13T17:20:04.035Z,1576257604.035 [Reporter](INFO): platform_buoyancy_position 375.878418 cc 2019-12-13T17:20:04.428Z,1576257604.428 [Reporter](INFO): platform_buoyancy_position 380.176025 cc 2019-12-13T17:20:04.799Z,1576257604.799 [Reporter](INFO): platform_buoyancy_position 386.488159 cc 2019-12-13T17:20:05.206Z,1576257605.206 [Reporter](INFO): platform_buoyancy_position 390.920044 cc 2019-12-13T17:20:05.630Z,1576257605.630 [Reporter](INFO): platform_buoyancy_position 397.232117 cc 2019-12-13T17:20:06.030Z,1576257606.030 [Reporter](INFO): platform_buoyancy_position 401.664062 cc 2019-12-13T17:20:06.442Z,1576257606.442 [Reporter](INFO): platform_buoyancy_position 408.110474 cc 2019-12-13T17:20:06.827Z,1576257606.827 [Reporter](INFO): platform_buoyancy_position 412.408020 cc 2019-12-13T17:20:07.403Z,1576257607.403 [Reporter](INFO): platform_buoyancy_position 420.868958 cc 2019-12-13T17:20:07.663Z,1576257607.663 [Reporter](INFO): platform_buoyancy_position 423.152039 cc 2019-12-13T17:20:08.031Z,1576257608.031 [Reporter](INFO): platform_buoyancy_position 427.449646 cc 2019-12-13T17:20:08.443Z,1576257608.443 [Reporter](INFO): platform_buoyancy_position 433.761719 cc 2019-12-13T17:20:08.869Z,1576257608.869 [Reporter](INFO): platform_buoyancy_position 438.462219 cc 2019-12-13T17:20:09.259Z,1576257609.259 [Reporter](INFO): platform_buoyancy_position 444.505737 cc 2019-12-13T17:20:09.651Z,1576257609.651 [Reporter](INFO): platform_buoyancy_position 448.937622 cc 2019-12-13T17:20:10.063Z,1576257610.063 [Reporter](INFO): platform_buoyancy_position 455.384033 cc 2019-12-13T17:20:10.486Z,1576257610.486 [Reporter](INFO): platform_buoyancy_position 459.547363 cc 2019-12-13T17:20:10.887Z,1576257610.887 [Reporter](INFO): platform_buoyancy_position 465.993774 cc 2019-12-13T17:20:11.271Z,1576257611.271 [Reporter](INFO): platform_buoyancy_position 470.425659 cc 2019-12-13T17:20:11.683Z,1576257611.683 [Reporter](INFO): platform_buoyancy_position 475.394775 cc 2019-12-13T17:20:12.099Z,1576257612.099 [Reporter](INFO): platform_buoyancy_position 481.035339 cc 2019-12-13T17:20:12.495Z,1576257612.495 [Reporter](INFO): platform_buoyancy_position 487.481750 cc 2019-12-13T17:20:12.887Z,1576257612.887 [Reporter](INFO): platform_buoyancy_position 491.779358 cc 2019-12-13T17:20:13.303Z,1576257613.303 [Reporter](INFO): platform_buoyancy_position 496.211243 cc 2019-12-13T17:20:13.715Z,1576257613.715 [Reporter](INFO): platform_buoyancy_position 502.523376 cc 2019-12-13T17:20:14.122Z,1576257614.122 [Reporter](INFO): platform_buoyancy_position 508.969696 cc 2019-12-13T17:20:14.503Z,1576257614.503 [Reporter](INFO): platform_buoyancy_position 513.267334 cc 2019-12-13T17:20:14.911Z,1576257614.911 [Reporter](INFO): platform_buoyancy_position 517.699280 cc 2019-12-13T17:20:15.311Z,1576257615.311 [Reporter](INFO): platform_buoyancy_position 524.011353 cc 2019-12-13T17:20:15.727Z,1576257615.727 [Reporter](INFO): platform_buoyancy_position 528.443237 cc 2019-12-13T17:20:16.115Z,1576257616.115 [Reporter](INFO): platform_buoyancy_position 534.755371 cc 2019-12-13T17:20:16.535Z,1576257616.535 [Reporter](INFO): platform_buoyancy_position 539.187256 cc 2019-12-13T17:20:16.939Z,1576257616.939 [Reporter](INFO): platform_buoyancy_position 545.499329 cc 2019-12-13T17:20:17.343Z,1576257617.343 [Reporter](INFO): platform_buoyancy_position 549.931274 cc 2019-12-13T17:20:17.739Z,1576257617.739 [Reporter](INFO): platform_buoyancy_position 556.377686 cc 2019-12-13T17:20:18.151Z,1576257618.151 [Reporter](INFO): platform_buoyancy_position 560.675232 cc 2019-12-13T17:20:18.551Z,1576257618.551 [Reporter](INFO): platform_buoyancy_position 566.987366 cc 2019-12-13T17:20:18.959Z,1576257618.959 [Reporter](INFO): platform_buoyancy_position 571.419250 cc 2019-12-13T17:20:19.351Z,1576257619.351 [Reporter](INFO): platform_buoyancy_position 576.119751 cc 2019-12-13T17:20:19.763Z,1576257619.763 [Reporter](INFO): platform_buoyancy_position 582.028931 cc 2019-12-13T17:20:20.182Z,1576257620.182 [Reporter](INFO): platform_buoyancy_position 586.460876 cc 2019-12-13T17:20:20.563Z,1576257620.563 [Reporter](INFO): platform_buoyancy_position 592.772949 cc 2019-12-13T17:20:20.982Z,1576257620.982 [Reporter](INFO): platform_buoyancy_position 597.204834 cc 2019-12-13T17:20:21.375Z,1576257621.375 [Reporter](INFO): platform_buoyancy_position 603.516968 cc 2019-12-13T17:20:21.767Z,1576257621.767 [Reporter](INFO): platform_buoyancy_position 608.083130 cc 2019-12-13T17:20:22.190Z,1576257622.190 [Reporter](INFO): platform_buoyancy_position 614.260986 cc 2019-12-13T17:20:22.599Z,1576257622.599 [Reporter](INFO): platform_buoyancy_position 618.558533 cc 2019-12-13T17:20:23.004Z,1576257623.004 [Reporter](INFO): platform_buoyancy_position 625.004944 cc 2019-12-13T17:20:23.387Z,1576257623.387 [Reporter](INFO): platform_buoyancy_position 629.302551 cc 2019-12-13T17:20:23.803Z,1576257623.803 [Reporter](INFO): platform_buoyancy_position 633.600159 cc 2019-12-13T17:20:24.219Z,1576257624.219 [Reporter](INFO): platform_buoyancy_position 640.180847 cc 2019-12-13T17:20:24.622Z,1576257624.622 [Reporter](INFO): platform_buoyancy_position 645.015686 cc 2019-12-13T17:20:25.007Z,1576257625.007 [Reporter](INFO): platform_buoyancy_position 650.924866 cc 2019-12-13T17:20:25.471Z,1576257625.471 [Reporter](INFO): platform_buoyancy_position 657.371277 cc 2019-12-13T17:20:25.840Z,1576257625.840 [Reporter](INFO): platform_buoyancy_position 661.668884 cc 2019-12-13T17:20:26.255Z,1576257626.255 [Reporter](INFO): platform_buoyancy_position 668.115234 cc 2019-12-13T17:20:26.627Z,1576257626.627 [Reporter](INFO): platform_buoyancy_position 672.278564 cc 2019-12-13T17:20:27.046Z,1576257627.046 [Reporter](INFO): platform_buoyancy_position 678.322083 cc 2019-12-13T17:20:27.459Z,1576257627.459 [Reporter](INFO): platform_buoyancy_position 683.022583 cc 2019-12-13T17:20:27.859Z,1576257627.859 [Reporter](INFO): platform_buoyancy_position 689.334656 cc 2019-12-13T17:20:28.247Z,1576257628.247 [Reporter](INFO): platform_buoyancy_position 693.900879 cc 2019-12-13T17:20:28.675Z,1576257628.675 [Reporter](INFO): platform_buoyancy_position 700.212952 cc 2019-12-13T17:20:29.060Z,1576257629.060 [Reporter](INFO): platform_buoyancy_position 704.644836 cc 2019-12-13T17:20:29.455Z,1576257629.455 [Reporter](INFO): platform_buoyancy_position 708.808167 cc 2019-12-13T17:20:29.863Z,1576257629.863 [Reporter](INFO): platform_buoyancy_position 715.388855 cc 2019-12-13T17:20:30.259Z,1576257630.259 [Reporter](INFO): platform_buoyancy_position 719.686462 cc 2019-12-13T17:20:30.691Z,1576257630.691 [Reporter](INFO): platform_buoyancy_position 725.998596 cc 2019-12-13T17:20:31.067Z,1576257631.067 [Reporter](INFO): platform_buoyancy_position 730.430481 cc 2019-12-13T17:20:31.479Z,1576257631.479 [Reporter](INFO): platform_buoyancy_position 735.802490 cc 2019-12-13T17:20:31.875Z,1576257631.875 [Reporter](INFO): platform_buoyancy_position 741.174500 cc 2019-12-13T17:20:32.287Z,1576257632.287 [Reporter](INFO): platform_buoyancy_position 746.009277 cc 2019-12-13T17:20:32.683Z,1576257632.683 [Reporter](INFO): platform_buoyancy_position 751.918457 cc 2019-12-13T17:20:33.095Z,1576257633.095 [Reporter](INFO): platform_buoyancy_position 756.216064 cc 2019-12-13T17:20:33.511Z,1576257633.511 [Reporter](INFO): platform_buoyancy_position 762.528198 cc 2019-12-13T17:20:33.912Z,1576257633.912 [Reporter](INFO): platform_buoyancy_position 767.094360 cc 2019-12-13T17:20:34.306Z,1576257634.306 [Reporter](INFO): platform_buoyancy_position 772.734985 cc 2019-12-13T17:20:34.710Z,1576257634.710 [Reporter](INFO): platform_buoyancy_position 777.704102 cc 2019-12-13T17:20:35.130Z,1576257635.130 [Reporter](INFO): platform_buoyancy_position 783.344666 cc 2019-12-13T17:20:35.496Z,1576257635.496 [Reporter](INFO): platform_buoyancy_position 788.313782 cc 2019-12-13T17:20:35.919Z,1576257635.919 [Reporter](INFO): platform_buoyancy_position 793.148560 cc 2019-12-13T17:20:36.375Z,1576257636.375 [Reporter](INFO): platform_buoyancy_position 799.326355 cc 2019-12-13T17:20:36.742Z,1576257636.742 [Reporter](INFO): platform_buoyancy_position 804.832703 cc 2019-12-13T17:20:37.130Z,1576257637.130 [Reporter](INFO): platform_buoyancy_position 809.936096 cc 2019-12-13T17:20:37.527Z,1576257637.527 [Reporter](INFO): platform_buoyancy_position 815.039490 cc 2019-12-13T17:20:37.943Z,1576257637.943 [Reporter](INFO): platform_buoyancy_position 820.680054 cc 2019-12-13T17:20:38.339Z,1576257638.339 [Reporter](INFO): platform_buoyancy_position 826.992188 cc 2019-12-13T17:20:38.763Z,1576257638.763 [Reporter](INFO): platform_buoyancy_position 831.424072 cc 2019-12-13T17:20:39.147Z,1576257639.147 [Reporter](INFO): platform_buoyancy_position 835.721680 cc 2019-12-13T17:20:39.562Z,1576257639.562 [Reporter](INFO): platform_buoyancy_position 842.033813 cc 2019-12-13T17:20:39.967Z,1576257639.967 [Reporter](INFO): platform_buoyancy_position 846.465698 cc 2019-12-13T17:20:40.371Z,1576257640.371 [Reporter](INFO): platform_buoyancy_position 852.777832 cc 2019-12-13T17:20:40.759Z,1576257640.759 [Reporter](INFO): platform_buoyancy_position 857.075317 cc 2019-12-13T17:20:41.175Z,1576257641.175 [Reporter](INFO): platform_buoyancy_position 863.521729 cc 2019-12-13T17:20:41.599Z,1576257641.599 [Reporter](INFO): platform_buoyancy_position 867.819336 cc 2019-12-13T17:20:41.971Z,1576257641.971 [Reporter](INFO): platform_buoyancy_position 872.519897 cc 2019-12-13T17:20:42.379Z,1576257642.379 [Reporter](INFO): platform_buoyancy_position 878.563354 cc 2019-12-13T17:20:42.795Z,1576257642.795 [Reporter](INFO): platform_buoyancy_position 883.666748 cc 2019-12-13T17:20:43.204Z,1576257643.204 [Reporter](INFO): platform_buoyancy_position 889.441650 cc 2019-12-13T17:20:43.608Z,1576257643.608 [Reporter](INFO): platform_buoyancy_position 895.350830 cc 2019-12-13T17:20:43.991Z,1576257643.991 [Reporter](INFO): platform_buoyancy_position 900.051392 cc 2019-12-13T17:20:44.407Z,1576257644.407 [Reporter](INFO): platform_buoyancy_position 906.497803 cc 2019-12-13T17:20:44.823Z,1576257644.823 [Reporter](INFO): platform_buoyancy_position 910.929688 cc 2019-12-13T17:20:45.199Z,1576257645.199 [Reporter](INFO): platform_buoyancy_position 915.898804 cc 2019-12-13T17:20:45.611Z,1576257645.611 [Reporter](INFO): platform_buoyancy_position 921.539429 cc 2019-12-13T17:20:46.015Z,1576257646.015 [Reporter](INFO): platform_buoyancy_position 925.837036 cc 2019-12-13T17:20:46.419Z,1576257646.419 [Reporter](INFO): platform_buoyancy_position 930.268921 cc 2019-12-13T17:20:46.835Z,1576257646.835 [Reporter](INFO): platform_buoyancy_position 936.580933 cc 2019-12-13T17:20:47.223Z,1576257647.223 [Reporter](INFO): platform_buoyancy_position 941.012939 cc 2019-12-13T17:20:47.677Z,1576257647.677 [Reporter](INFO): platform_buoyancy_position 945.176147 cc 2019-12-13T17:22:12.918Z,1576257732.918 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-12-13T17:22:12.918Z,1576257732.918 [DVL_micro] No Fault, FailCount= 3 2019-12-13T17:22:20.907Z,1576257740.907 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout. 2019-12-13T17:22:20.907Z,1576257740.907 [DVL_micro] Data Fault, FailCount= 1 2019-12-13T17:22:20.907Z,1576257740.907 [DVL_micro](ERROR): Data Fault 2019-12-13T17:22:20.975Z,1576257740.975 [CBIT](ERROR): Data Fault in component: DVL_micro 2019-12-13T17:22:21.389Z,1576257741.389 [DVL_micro](INFO): Powering down 2019-12-13T17:22:22.158Z,1576257742.158 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-12-13T17:22:22.158Z,1576257742.158 [DVL_micro] No Fault, FailCount= 1 2019-12-13T17:22:39.902Z,1576257759.902 [DVL_micro](ERROR): No DVL communication! Re-initializing 2019-12-13T17:22:39.902Z,1576257759.902 [DVL_micro] Communications Fault, FailCount= 2 2019-12-13T17:22:39.902Z,1576257759.902 [DVL_micro](ERROR): Communications Fault 2019-12-13T17:22:39.984Z,1576257759.984 [CBIT](ERROR): Communications Fault in component: DVL_micro 2019-12-13T17:22:40.369Z,1576257760.369 [DVL_micro](INFO): Powering down 2019-12-13T17:22:41.155Z,1576257761.155 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-12-13T17:22:41.155Z,1576257761.155 [DVL_micro] No Fault, FailCount= 2 2019-12-13T17:22:58.890Z,1576257778.890 [DVL_micro](ERROR): No DVL communication! Re-initializing 2019-12-13T17:22:58.890Z,1576257778.890 [DVL_micro] Communications Fault, FailCount= 3 2019-12-13T17:22:58.890Z,1576257778.890 [DVL_micro](ERROR): Communications Fault 2019-12-13T17:22:58.965Z,1576257778.965 [CBIT](ERROR): Communications Fault in component: DVL_micro 2019-12-13T17:22:58.965Z,1576257778.965 [CBIT](CRITICAL): Communications Fault in component: DVL_micro 2019-12-13T17:22:59.365Z,1576257779.365 [DVL_micro](INFO): Powering down 2019-12-13T17:22:59.397Z,1576257779.397 [CBIT](INFO): Critical error at 20191213T172258 2019-12-13T17:24:35.894Z,1576257875.894 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-12-13T17:24:35.894Z,1576257875.894 [Default:CheckIn:C.Wait] Stopped 2019-12-13T17:24:35.894Z,1576257875.894 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-12-13T17:24:35.895Z,1576257875.895 [Default:CheckIn:D] Running Loop=1 2019-12-13T17:24:36.310Z,1576257876.310 [Default:CheckIn:D] Stopped 2019-12-13T17:24:36.311Z,1576257876.311 [Default:CheckIn:E] Running Loop=1 2019-12-13T17:24:36.685Z,1576257876.685 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 9.147476 min 2019-12-13T17:24:36.685Z,1576257876.685 [Default:CheckIn:E] Stopped 2019-12-13T17:24:36.685Z,1576257876.685 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-12-13T17:24:36.686Z,1576257876.686 [Default:CheckIn] Stopped 2019-12-13T17:24:36.686Z,1576257876.686 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-12-13T17:24:36.686Z,1576257876.686 [Default:CheckIn](INFO): Running loop #2 2019-12-13T17:24:36.686Z,1576257876.686 [Default:CheckIn] Running Loop=2 2019-12-13T17:24:36.686Z,1576257876.686 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-12-13T17:24:36.686Z,1576257876.686 [Default:CheckIn:Read_GPS] Running Loop=1 2019-12-13T17:24:38.677Z,1576257878.677 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171555.00,A,3648.15813,N,12147.28085,W,0.641,76.22,131219,,,A*44 2019-12-13T17:24:38.679Z,1576257878.679 [NAL9602](INFO): GPS fix at 20191213T171555: (36.802636, -121.788014) 2019-12-13T17:24:38.725Z,1576257878.725 [Default:CheckIn:Read_GPS] Stopped 2019-12-13T17:24:38.725Z,1576257878.725 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-12-13T17:24:48.804Z,1576257888.804 [DataOverHttps](INFO): Sending 121 bytes from file Logs/20191213T164021/Courier0022.lzma 2019-12-13T17:24:50.810Z,1576257890.810 [DataOverHttps](INFO): Moved sent file to Logs/20191213T164021/Courier0022.lzma.bak 2019-12-13T17:24:50.811Z,1576257890.811 [DataOverHttps](INFO): SBD MOMSN=12155065 2019-12-13T17:25:10.685Z,1576257910.685 [DataOverHttps](INFO): Sending 200 bytes from file Logs/20191213T164021/Express0023.lzma 2019-12-13T17:25:15.069Z,1576257915.069 [DataOverHttps](INFO): Moved sent file to Logs/20191213T164021/Express0023.lzma.bak 2019-12-13T17:25:15.069Z,1576257915.069 [DataOverHttps](INFO): SBD MOMSN=12155072 2019-12-13T17:25:18.708Z,1576257918.708 [Default:CheckIn:Read_Iridium] Stopped 2019-12-13T17:25:18.737Z,1576257918.737 [Default:CheckIn:C.Wait] Running Loop=1 2019-12-13T17:25:18.737Z,1576257918.737 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-12-13T17:25:59.138Z,1576257959.138 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-12-13T17:25:59.138Z,1576257959.138 [DVL_micro] No Fault, FailCount= 3 2019-12-13T17:26:07.163Z,1576257967.163 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout. 2019-12-13T17:26:07.163Z,1576257967.163 [DVL_micro] Data Fault, FailCount= 1 2019-12-13T17:26:07.163Z,1576257967.163 [DVL_micro](ERROR): Data Fault 2019-12-13T17:26:07.226Z,1576257967.226 [CBIT](ERROR): Data Fault in component: DVL_micro 2019-12-13T17:26:07.625Z,1576257967.625 [DVL_micro](INFO): Powering down 2019-12-13T17:26:08.446Z,1576257968.446 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-12-13T17:26:08.446Z,1576257968.446 [DVL_micro] No Fault, FailCount= 1 2019-12-13T17:26:26.138Z,1576257986.138 [DVL_micro](ERROR): No DVL communication! Re-initializing 2019-12-13T17:26:26.138Z,1576257986.138 [DVL_micro] Communications Fault, FailCount= 2 2019-12-13T17:26:26.138Z,1576257986.138 [DVL_micro](ERROR): Communications Fault 2019-12-13T17:26:26.184Z,1576257986.184 [CBIT](ERROR): Communications Fault in component: DVL_micro 2019-12-13T17:26:26.613Z,1576257986.613 [DVL_micro](INFO): Powering down 2019-12-13T17:26:27.406Z,1576257987.406 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-12-13T17:26:27.406Z,1576257987.406 [DVL_micro] No Fault, FailCount= 2 2019-12-13T17:26:45.126Z,1576258005.126 [DVL_micro](ERROR): No DVL communication! Re-initializing 2019-12-13T17:26:45.126Z,1576258005.126 [DVL_micro] Communications Fault, FailCount= 3 2019-12-13T17:26:45.126Z,1576258005.126 [DVL_micro](ERROR): Communications Fault 2019-12-13T17:26:45.224Z,1576258005.224 [CBIT](ERROR): Communications Fault in component: DVL_micro 2019-12-13T17:26:45.224Z,1576258005.224 [CBIT](CRITICAL): Communications Fault in component: DVL_micro 2019-12-13T17:26:45.605Z,1576258005.605 [DVL_micro](INFO): Powering down 2019-12-13T17:26:45.675Z,1576258005.675 [CBIT](INFO): Critical error at 20191213T172645 2019-12-13T17:29:40.880Z,1576258180.880 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-12-13T17:29:45.360Z,1576258185.360 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-12-13T17:29:45.360Z,1576258185.360 [DVL_micro] No Fault, FailCount= 3 2019-12-13T17:29:53.422Z,1576258193.422 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout. 2019-12-13T17:29:53.422Z,1576258193.422 [DVL_micro] Data Fault, FailCount= 1 2019-12-13T17:29:53.422Z,1576258193.422 [DVL_micro](ERROR): Data Fault 2019-12-13T17:29:53.485Z,1576258193.485 [CBIT](ERROR): Data Fault in component: DVL_micro 2019-12-13T17:29:53.885Z,1576258193.885 [DVL_micro](INFO): Powering down 2019-12-13T17:29:54.678Z,1576258194.678 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-12-13T17:29:54.679Z,1576258194.679 [DVL_micro] No Fault, FailCount= 1 2019-12-13T17:30:11.586Z,1576258211.586 [NAL9602](INFO): Not Powering down - fast GPS 2019-12-13T17:30:12.394Z,1576258212.394 [DVL_micro](ERROR): No DVL communication! Re-initializing 2019-12-13T17:30:12.394Z,1576258212.394 [DVL_micro] Communications Fault, FailCount= 2 2019-12-13T17:30:12.394Z,1576258212.394 [DVL_micro](ERROR): Communications Fault 2019-12-13T17:30:12.433Z,1576258212.433 [CBIT](ERROR): Communications Fault in component: DVL_micro 2019-12-13T17:30:12.869Z,1576258212.869 [DVL_micro](INFO): Powering down 2019-12-13T17:30:13.636Z,1576258213.636 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-12-13T17:30:13.636Z,1576258213.636 [DVL_micro] No Fault, FailCount= 2 2019-12-13T17:30:19.292Z,1576258219.292 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-12-13T17:30:19.293Z,1576258219.293 [Default:CheckIn:C.Wait] Stopped 2019-12-13T17:30:19.293Z,1576258219.293 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-12-13T17:30:19.293Z,1576258219.293 [Default:CheckIn:D] Running Loop=1 2019-12-13T17:30:19.713Z,1576258219.713 [Default:CheckIn:D] Stopped 2019-12-13T17:30:19.713Z,1576258219.713 [Default:CheckIn:E] Running Loop=1 2019-12-13T17:30:20.118Z,1576258220.118 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 14.870781 min 2019-12-13T17:30:20.118Z,1576258220.118 [Default:CheckIn:E] Stopped 2019-12-13T17:30:20.118Z,1576258220.118 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-12-13T17:30:20.118Z,1576258220.118 [Default:CheckIn] Stopped 2019-12-13T17:30:20.118Z,1576258220.118 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-12-13T17:30:20.118Z,1576258220.118 [Default:CheckIn](INFO): Running loop #3 2019-12-13T17:30:20.119Z,1576258220.119 [Default:CheckIn] Running Loop=3 2019-12-13T17:30:20.119Z,1576258220.119 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-12-13T17:30:20.119Z,1576258220.119 [Default:CheckIn:Read_GPS] Running Loop=1 2019-12-13T17:30:22.092Z,1576258222.092 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172138.00,A,3648.16287,N,12147.29240,W,0.505,76.22,131219,,,A*45 2019-12-13T17:30:22.094Z,1576258222.094 [NAL9602](INFO): GPS fix at 20191213T172138: (36.802715, -121.788207) 2019-12-13T17:30:22.119Z,1576258222.119 [Default:CheckIn:Read_GPS] Stopped 2019-12-13T17:30:22.119Z,1576258222.119 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-12-13T17:30:31.076Z,1576258231.076 [DataOverHttps](INFO): Sending 115 bytes from file Logs/20191213T164021/Courier0025.lzma 2019-12-13T17:30:31.386Z,1576258231.386 [DVL_micro](ERROR): No DVL communication! Re-initializing 2019-12-13T17:30:31.386Z,1576258231.386 [DVL_micro] Communications Fault, FailCount= 3 2019-12-13T17:30:31.386Z,1576258231.386 [DVL_micro](ERROR): Communications Fault 2019-12-13T17:30:31.462Z,1576258231.462 [CBIT](ERROR): Communications Fault in component: DVL_micro 2019-12-13T17:30:31.463Z,1576258231.463 [CBIT](CRITICAL): Communications Fault in component: DVL_micro 2019-12-13T17:30:31.857Z,1576258231.857 [DVL_micro](INFO): Powering down 2019-12-13T17:30:31.895Z,1576258231.895 [CBIT](INFO): Critical error at 20191213T173031 2019-12-13T17:30:34.858Z,1576258234.858 [DataOverHttps](INFO): Moved sent file to Logs/20191213T164021/Courier0025.lzma.bak 2019-12-13T17:30:34.858Z,1576258234.858 [DataOverHttps](INFO): SBD MOMSN=12155160 2019-12-13T17:30:53.761Z,1576258253.761 [DataOverHttps](INFO): Sending 230 bytes from file Logs/20191213T164021/Express0026.lzma 2019-12-13T17:30:55.766Z,1576258255.766 [DataOverHttps](INFO): Moved sent file to Logs/20191213T164021/Express0026.lzma.bak 2019-12-13T17:30:55.767Z,1576258255.767 [DataOverHttps](INFO): SBD MOMSN=12155164 2019-12-13T17:31:00.113Z,1576258260.113 [Default:CheckIn:Read_Iridium] Stopped 2019-12-13T17:31:00.113Z,1576258260.113 [Default:CheckIn:C.Wait] Running Loop=1 2019-12-13T17:31:00.113Z,1576258260.113 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-12-13T17:32:28.967Z,1576258348.967 [CommandLine](IMPORTANT): got command maintain clear 2019-12-13T17:33:31.686Z,1576258411.686 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-12-13T17:33:31.686Z,1576258411.686 [DVL_micro] No Fault, FailCount= 3 2019-12-13T17:33:39.658Z,1576258419.658 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout. 2019-12-13T17:33:39.658Z,1576258419.658 [DVL_micro] Data Fault, FailCount= 1 2019-12-13T17:33:39.658Z,1576258419.658 [DVL_micro](ERROR): Data Fault 2019-12-13T17:33:39.792Z,1576258419.792 [CBIT](ERROR): Data Fault in component: DVL_micro 2019-12-13T17:33:40.137Z,1576258420.137 [DVL_micro](INFO): Powering down 2019-12-13T17:33:40.990Z,1576258420.990 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-12-13T17:33:40.991Z,1576258420.991 [DVL_micro] No Fault, FailCount= 1 2019-12-13T17:33:58.644Z,1576258438.644 [DVL_micro](ERROR): No DVL communication! Re-initializing 2019-12-13T17:33:58.644Z,1576258438.644 [DVL_micro] Communications Fault, FailCount= 2 2019-12-13T17:33:58.644Z,1576258438.644 [DVL_micro](ERROR): Communications Fault 2019-12-13T17:33:58.755Z,1576258438.755 [CBIT](ERROR): Communications Fault in component: DVL_micro 2019-12-13T17:33:59.137Z,1576258439.137 [DVL_micro](INFO): Powering down 2019-12-13T17:33:59.905Z,1576258439.905 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-12-13T17:33:59.905Z,1576258439.905 [DVL_micro] No Fault, FailCount= 2 2019-12-13T17:34:17.634Z,1576258457.634 [DVL_micro](ERROR): No DVL communication! Re-initializing 2019-12-13T17:34:17.634Z,1576258457.634 [DVL_micro] Communications Fault, FailCount= 3 2019-12-13T17:34:17.634Z,1576258457.634 [DVL_micro](ERROR): Communications Fault 2019-12-13T17:34:17.706Z,1576258457.706 [CBIT](ERROR): Communications Fault in component: DVL_micro 2019-12-13T17:34:17.706Z,1576258457.706 [CBIT](CRITICAL): Communications Fault in component: DVL_micro 2019-12-13T17:34:18.113Z,1576258458.113 [DVL_micro](INFO): Powering down 2019-12-13T17:34:18.159Z,1576258458.159 [CBIT](INFO): Critical error at 20191213T173417 2019-12-13T17:35:24.698Z,1576258524.698 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-12-13T17:35:55.399Z,1576258555.399 [NAL9602](INFO): Not Powering down - fast GPS 2019-12-13T17:36:00.730Z,1576258560.730 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-12-13T17:36:00.730Z,1576258560.730 [Default:CheckIn:C.Wait] Stopped 2019-12-13T17:36:00.730Z,1576258560.730 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-12-13T17:36:00.731Z,1576258560.731 [Default:CheckIn:D] Running Loop=1 2019-12-13T17:36:01.119Z,1576258561.119 [Default:CheckIn:D] Stopped 2019-12-13T17:36:01.119Z,1576258561.119 [Default:CheckIn:E] Running Loop=1 2019-12-13T17:36:01.500Z,1576258561.500 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 20.560958 min 2019-12-13T17:36:01.500Z,1576258561.500 [Default:CheckIn:E] Stopped 2019-12-13T17:36:01.501Z,1576258561.501 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-12-13T17:36:01.501Z,1576258561.501 [Default:CheckIn] Stopped 2019-12-13T17:36:01.501Z,1576258561.501 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-12-13T17:36:01.501Z,1576258561.501 [Default:CheckIn](INFO): Running loop #4 2019-12-13T17:36:01.501Z,1576258561.501 [Default:CheckIn] Running Loop=4 2019-12-13T17:36:01.501Z,1576258561.501 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-12-13T17:36:01.502Z,1576258561.502 [Default:CheckIn:Read_GPS] Running Loop=1 2019-12-13T17:36:03.492Z,1576258563.492 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172720.00,A,3648.15823,N,12147.28556,W,0.369,76.22,131219,,,A*40 2019-12-13T17:36:03.494Z,1576258563.494 [NAL9602](INFO): GPS fix at 20191213T172720: (36.802637, -121.788093) 2019-12-13T17:36:03.540Z,1576258563.540 [Default:CheckIn:Read_GPS] Stopped 2019-12-13T17:36:03.540Z,1576258563.540 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-12-13T17:36:12.468Z,1576258572.468 [DataOverHttps](INFO): Sending 120 bytes from file Logs/20191213T164021/Courier0028.lzma 2019-12-13T17:36:14.474Z,1576258574.474 [DataOverHttps](INFO): Moved sent file to Logs/20191213T164021/Courier0028.lzma.bak 2019-12-13T17:36:14.474Z,1576258574.474 [DataOverHttps](INFO): SBD MOMSN=12155186 2019-12-13T17:36:34.190Z,1576258594.190 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2019-12-13T17:36:34.269Z,1576258594.269 [NAL9602](FAULT): received: +CSQ:0 OK50, 2, 0, 0, 0 OK 2019-12-13T17:36:34.269Z,1576258594.269 [NAL9602] Data Fault, FailCount= 1 2019-12-13T17:36:34.269Z,1576258594.269 [NAL9602](ERROR): Data Fault 2019-12-13T17:36:34.378Z,1576258594.378 [CBIT](ERROR): Data Fault in component: NAL9602 2019-12-13T17:36:34.594Z,1576258594.594 [NAL9602](INFO): Powering down 2019-12-13T17:36:35.433Z,1576258595.433 [CBIT](INFO): Clearing failed state for component NAL9602 2019-12-13T17:36:35.433Z,1576258595.433 [NAL9602] No Fault, FailCount= 1 2019-12-13T17:36:35.861Z,1576258595.861 [DataOverHttps](INFO): Sending 252 bytes from file Logs/20191213T164021/Express0029.lzma 2019-12-13T17:36:37.866Z,1576258597.866 [DataOverHttps](INFO): Moved sent file to Logs/20191213T164021/Express0029.lzma.bak 2019-12-13T17:36:37.867Z,1576258597.867 [DataOverHttps](INFO): SBD MOMSN=12155192 2019-12-13T17:36:41.927Z,1576258601.927 [Default:CheckIn:Read_Iridium] Stopped 2019-12-13T17:36:41.927Z,1576258601.927 [Default:CheckIn:C.Wait] Running Loop=1 2019-12-13T17:36:41.927Z,1576258601.927 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-12-13T17:37:04.892Z,1576258624.892 [NAL9602](INFO): Powering up NAL9602 2019-12-13T17:37:15.806Z,1576258635.806 [NAL9602](INFO): NAL9602 initialized 2019-12-13T17:37:17.921Z,1576258637.921 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-12-13T17:37:17.921Z,1576258637.921 [DVL_micro] No Fault, FailCount= 3 2019-12-13T17:37:25.902Z,1576258645.902 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout. 2019-12-13T17:37:25.902Z,1576258645.902 [DVL_micro] Data Fault, FailCount= 1 2019-12-13T17:37:25.902Z,1576258645.902 [DVL_micro](ERROR): Data Fault 2019-12-13T17:37:25.951Z,1576258645.951 [CBIT](ERROR): Data Fault in component: DVL_micro 2019-12-13T17:37:26.369Z,1576258646.369 [DVL_micro](INFO): Powering down 2019-12-13T17:37:27.167Z,1576258647.167 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-12-13T17:37:27.167Z,1576258647.167 [DVL_micro] No Fault, FailCount= 1 2019-12-13T17:37:44.896Z,1576258664.896 [DVL_micro](ERROR): No DVL communication! Re-initializing 2019-12-13T17:37:44.896Z,1576258664.896 [DVL_micro] Communications Fault, FailCount= 2 2019-12-13T17:37:44.896Z,1576258664.896 [DVL_micro](ERROR): Communications Fault 2019-12-13T17:37:44.929Z,1576258664.929 [CBIT](ERROR): Communications Fault in component: DVL_micro 2019-12-13T17:37:45.361Z,1576258665.361 [DVL_micro](INFO): Powering down 2019-12-13T17:37:46.161Z,1576258666.161 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-12-13T17:37:46.161Z,1576258666.161 [DVL_micro] No Fault, FailCount= 2 2019-12-13T17:37:46.904Z,1576258666.904 [NAL9602](INFO): Not Powering down - fast GPS 2019-12-13T17:38:03.872Z,1576258683.872 [DVL_micro](ERROR): No DVL communication! Re-initializing 2019-12-13T17:38:03.872Z,1576258683.872 [DVL_micro] Communications Fault, FailCount= 3 2019-12-13T17:38:03.872Z,1576258683.872 [DVL_micro](ERROR): Communications Fault 2019-12-13T17:38:03.928Z,1576258683.928 [CBIT](ERROR): Communications Fault in component: DVL_micro 2019-12-13T17:38:03.933Z,1576258683.933 [CBIT](CRITICAL): Communications Fault in component: DVL_micro 2019-12-13T17:38:04.353Z,1576258684.353 [DVL_micro](INFO): Powering down 2019-12-13T17:38:04.395Z,1576258684.395 [CBIT](INFO): Critical error at 20191213T173803 2019-12-13T17:41:04.135Z,1576258864.135 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-12-13T17:41:04.135Z,1576258864.135 [DVL_micro] No Fault, FailCount= 3 2019-12-13T17:41:12.141Z,1576258872.141 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout. 2019-12-13T17:41:12.141Z,1576258872.141 [DVL_micro] Data Fault, FailCount= 1 2019-12-13T17:41:12.141Z,1576258872.141 [DVL_micro](ERROR): Data Fault 2019-12-13T17:41:12.174Z,1576258872.174 [CBIT](ERROR): Data Fault in component: DVL_micro 2019-12-13T17:41:12.613Z,1576258872.613 [DVL_micro](INFO): Powering down 2019-12-13T17:41:13.408Z,1576258873.408 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-12-13T17:41:13.408Z,1576258873.408 [DVL_micro] No Fault, FailCount= 1 2019-12-13T17:41:31.125Z,1576258891.125 [DVL_micro](ERROR): No DVL communication! Re-initializing 2019-12-13T17:41:31.126Z,1576258891.126 [DVL_micro] Communications Fault, FailCount= 2 2019-12-13T17:41:31.126Z,1576258891.126 [DVL_micro](ERROR): Communications Fault 2019-12-13T17:41:31.165Z,1576258891.165 [CBIT](ERROR): Communications Fault in component: DVL_micro 2019-12-13T17:41:31.605Z,1576258891.605 [DVL_micro](INFO): Powering down 2019-12-13T17:41:32.367Z,1576258892.367 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-12-13T17:41:32.367Z,1576258892.367 [DVL_micro] No Fault, FailCount= 2 2019-12-13T17:41:42.486Z,1576258902.486 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-12-13T17:41:42.486Z,1576258902.486 [Default:CheckIn:C.Wait] Stopped 2019-12-13T17:41:42.486Z,1576258902.486 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-12-13T17:41:42.487Z,1576258902.487 [Default:CheckIn:D] Running Loop=1 2019-12-13T17:41:42.893Z,1576258902.893 [Default:CheckIn:D] Stopped 2019-12-13T17:41:42.893Z,1576258902.893 [Default:CheckIn:E] Running Loop=1 2019-12-13T17:41:43.289Z,1576258903.289 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 26.257186 min 2019-12-13T17:41:43.289Z,1576258903.289 [Default:CheckIn:E] Stopped 2019-12-13T17:41:43.289Z,1576258903.289 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-12-13T17:41:43.289Z,1576258903.289 [Default:CheckIn] Stopped 2019-12-13T17:41:43.289Z,1576258903.289 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-12-13T17:41:43.290Z,1576258903.290 [Default:CheckIn](INFO): Running loop #5 2019-12-13T17:41:43.290Z,1576258903.290 [Default:CheckIn] Running Loop=5 2019-12-13T17:41:43.290Z,1576258903.290 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-12-13T17:41:43.290Z,1576258903.290 [Default:CheckIn:Read_GPS] Running Loop=1 2019-12-13T17:41:45.276Z,1576258905.276 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173301.00,A,3648.14745,N,12147.30093,W,1.127,229.20,131219,,,A*7E 2019-12-13T17:41:45.278Z,1576258905.278 [NAL9602](INFO): GPS fix at 20191213T173301: (36.802458, -121.788349) 2019-12-13T17:41:45.309Z,1576258905.309 [Default:CheckIn:Read_GPS] Stopped 2019-12-13T17:41:45.309Z,1576258905.309 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-12-13T17:41:47.690Z,1576258907.690 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-12-13T17:41:50.114Z,1576258910.114 [DVL_micro](ERROR): No DVL communication! Re-initializing 2019-12-13T17:41:50.114Z,1576258910.114 [DVL_micro] Communications Fault, FailCount= 3 2019-12-13T17:41:50.114Z,1576258910.114 [DVL_micro](ERROR): Communications Fault 2019-12-13T17:41:50.181Z,1576258910.181 [CBIT](ERROR): Communications Fault in component: DVL_micro 2019-12-13T17:41:50.182Z,1576258910.182 [CBIT](CRITICAL): Communications Fault in component: DVL_micro 2019-12-13T17:41:50.585Z,1576258910.585 [DVL_micro](INFO): Powering down 2019-12-13T17:41:50.627Z,1576258910.627 [CBIT](INFO): Critical error at 20191213T174150 2019-12-13T17:41:54.276Z,1576258914.276 [DataOverHttps](INFO): Sending 115 bytes from file Logs/20191213T164021/Courier0031.lzma 2019-12-13T17:41:56.282Z,1576258916.282 [DataOverHttps](INFO): Moved sent file to Logs/20191213T164021/Courier0031.lzma.bak 2019-12-13T17:41:56.282Z,1576258916.282 [DataOverHttps](INFO): SBD MOMSN=12155199 2019-12-13T17:42:16.045Z,1576258936.045 [DataOverHttps](INFO): Sending 214 bytes from file Logs/20191213T164021/Express0032.lzma 2019-12-13T17:42:18.050Z,1576258938.050 [DataOverHttps](INFO): Moved sent file to Logs/20191213T164021/Express0032.lzma.bak 2019-12-13T17:42:18.050Z,1576258938.050 [DataOverHttps](INFO): SBD MOMSN=12155203 2019-12-13T17:42:18.391Z,1576258938.391 [NAL9602](INFO): Not Powering down - fast GPS 2019-12-13T17:42:22.490Z,1576258942.490 [Default:CheckIn:Read_Iridium] Stopped 2019-12-13T17:42:22.491Z,1576258942.491 [Default:CheckIn:C.Wait] Running Loop=1 2019-12-13T17:42:22.491Z,1576258942.491 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-12-13T17:35:20.291Z,1576258520.291 [CommandLine](IMPORTANT): got command restart system 2019-12-13T17:35:22.365Z,1576258522.365 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2019-12-13T17:35:22.366Z,1576258522.366 [CommandLine ThreadHandler](INFO): Thread cancelled. 2019-12-13T17:35:22.457Z,1576258522.457 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2019-12-13T17:35:22.457Z,1576258522.457 [CommandLine ThreadHandler](INFO): Thread cancelled. 2019-12-13T17:35:22.458Z,1576258522.458 [CommandLine](INFO): Join timeout helper Thread ID is 1241 2019-12-13T17:35:22.458Z,1576258522.458 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2019-12-13T17:35:22.458Z,1576258522.458 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2019-12-13T17:35:22.459Z,1576258522.459 [NavChartDb](INFO): Join timeout helper Thread ID is 1242 2019-12-13T17:35:22.777Z,1576258522.777 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2019-12-13T17:35:22.777Z,1576258522.777 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2019-12-13T17:35:22.785Z,1576258522.785 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2019-12-13T17:35:22.785Z,1576258522.785 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2019-12-13T17:35:22.785Z,1576258522.785 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 1243 2019-12-13T17:35:23.045Z,1576258523.045 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2019-12-13T17:35:23.046Z,1576258523.046 [WetLabsBB2FL](INFO): Powering down 2019-12-13T17:35:23.046Z,1576258523.046 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2019-12-13T17:35:23.057Z,1576258523.057 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler 2019-12-13T17:35:23.057Z,1576258523.057 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2019-12-13T17:35:23.058Z,1576258523.058 [CTD_Seabird](INFO): Join timeout helper Thread ID is 1244 2019-12-13T17:35:23.801Z,1576258523.801 [CTD_Seabird](INFO): Powering down 2019-12-13T17:35:23.813Z,1576258523.813 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread. 2019-12-13T17:35:23.813Z,1576258523.813 [CTD_Seabird](INFO): Powering down 2019-12-13T17:35:23.825Z,1576258523.825 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2019-12-13T17:35:23.845Z,1576258523.845 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2019-12-13T17:35:23.845Z,1576258523.845 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2019-12-13T17:35:23.845Z,1576258523.845 [Radio_Surface](INFO): Join timeout helper Thread ID is 1245 2019-12-13T17:35:23.969Z,1576258523.969 [Radio_Surface](INFO): Powering down 2019-12-13T17:35:23.970Z,1576258523.970 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2019-12-13T17:35:23.970Z,1576258523.970 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2019-12-13T17:35:23.990Z,1576258523.990 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler 2019-12-13T17:35:23.990Z,1576258523.990 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2019-12-13T17:35:23.990Z,1576258523.990 [DataOverHttps](INFO): Join timeout helper Thread ID is 1246 2019-12-13T17:35:24.089Z,1576258524.089 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread. 2019-12-13T17:35:24.089Z,1576258524.089 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2019-12-13T17:35:24.110Z,1576258524.110 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2019-12-13T17:35:24.110Z,1576258524.110 [logger ThreadHandler](INFO): Thread cancelled. 2019-12-13T17:35:24.110Z,1576258524.110 [logger](INFO): Join timeout helper Thread ID is 1247 2019-12-13T17:35:24.113Z,1576258524.113 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2019-12-13T17:35:24.113Z,1576258524.113 [logger ThreadHandler](INFO): Thread cancelled. 2019-12-13T17:35:24.130Z,1576258524.130 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2019-12-13T17:35:24.130Z,1576258524.130 [CommandLine ThreadHandler](INFO): Thread cancelled. 2019-12-13T17:35:24.130Z,1576258524.130 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2019-12-13T17:35:24.130Z,1576258524.130 [controlThread ThreadHandler](INFO): Thread cancelled. 2019-12-13T17:35:24.131Z,1576258524.131 [controlThread](INFO): Join timeout helper Thread ID is 1248 2019-12-13T17:35:24.169Z,1576258524.169 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2019-12-13T17:35:24.169Z,1576258524.169 [controlThread](DEBUG): Uninitializing ControlThread 2019-12-13T17:35:24.170Z,1576258524.170 [AHRS_M2](INFO): Powering down 2019-12-13T17:35:24.242Z,1576258524.242 [DVL_micro](INFO): Powering down 2019-12-13T17:35:24.243Z,1576258524.243 [NAL9602](INFO): Powering down 2019-12-13T17:35:24.244Z,1576258524.244 [Aanderaa_O2](INFO): Powering down 2019-12-13T17:35:24.266Z,1576258524.266 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator. 2019-12-13T17:35:24.267Z,1576258524.267 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator. 2019-12-13T17:35:24.267Z,1576258524.267 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2019-12-13T17:35:24.268Z,1576258524.268 [MissionManager](INFO): Uninitializing Mission Default 2019-12-13T17:35:24.268Z,1576258524.268 [Default] Stopped 2019-12-13T17:35:24.268Z,1576258524.268 [Default](DEBUG): Aggregate::uninitialize Default 2019-12-13T17:35:24.268Z,1576258524.268 [Default:B.GoToSurface] Stopped 2019-12-13T17:35:24.268Z,1576258524.268 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2019-12-13T17:35:24.268Z,1576258524.268 [Default:CheckIn] Stopped 2019-12-13T17:35:24.268Z,1576258524.268 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-12-13T17:35:24.269Z,1576258524.269 [Default:CheckIn:C.Wait] Stopped 2019-12-13T17:35:24.269Z,1576258524.269 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-12-13T17:35:24.271Z,1576258524.271 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2019-12-13T17:35:24.272Z,1576258524.272 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2019-12-13T17:35:24.272Z,1576258524.272 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2019-12-13T17:35:24.272Z,1576258524.272 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2019-12-13T17:35:24.272Z,1576258524.272 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2019-12-13T17:35:24.272Z,1576258524.272 [BuoyancyServo](INFO): Powering down 2019-12-13T17:35:24.285Z,1576258524.285 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2019-12-13T17:35:24.285Z,1576258524.285 [ElevatorServo](INFO): Powering down 2019-12-13T17:35:24.286Z,1576258524.286 [MassServo](DEBUG): Uninitialize Mass Servo. 2019-12-13T17:35:24.286Z,1576258524.286 [MassServo](INFO): Powering down 2019-12-13T17:35:24.287Z,1576258524.287 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2019-12-13T17:35:24.287Z,1576258524.287 [RudderServo](INFO): Powering down 2019-12-13T17:35:24.288Z,1576258524.288 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2019-12-13T17:35:24.288Z,1576258524.288 [ThrusterServo](INFO): Powering down 2019-12-13T17:35:24.289Z,1576258524.289 [SBIT](DEBUG): Uninitialize SBIT Component. 2019-12-13T17:35:24.289Z,1576258524.289 [IBIT](DEBUG): Uninitialize IBIT Component. 2019-12-13T17:35:24.290Z,1576258524.290 [CBIT](DEBUG): Uninitialize CBIT Component. 2019-12-13T17:35:24.290Z,1576258524.290 [CBIT](DEBUG): Powering off loads. 2019-12-13T17:35:24.301Z,1576258524.301 [CBIT](DEBUG): Disabling WDT. 2019-12-13T17:35:24.313Z,1576258524.313 [CBIT](DEBUG): Opening all GF detection circuits. 2019-12-13T17:35:24.314Z,1576258524.314 [controlThread ThreadHandler](INFO): Thread cancelled. 2019-12-13T17:35:24.413Z,1576258524.413 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2019-12-13T17:35:24.421Z,1576258524.421 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2019-12-13T17:35:24.468Z,1576258524.468 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2019-12-13T17:35:24.473Z,1576258524.473 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2019-12-13T17:35:24.517Z,1576258524.517 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2019-12-13T17:35:24.593Z,1576258524.593 [logger ThreadHandler](INFO): Thread cancelled.