2019-12-13T20:22:10.483Z,1576268530.483 [Supervisor](DEBUG): Initializing supervisor. 2019-12-13T20:22:10.486Z,1576268530.486 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2019-12-13T20:22:10.487Z,1576268530.487 [SyncHandler](INFO): Protected caller Thread ID is 807 2019-12-13T20:22:10.487Z,1576268530.487 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2019-12-13T20:22:10.488Z,1576268530.488 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2019-12-13T20:22:10.488Z,1576268530.488 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 808 2019-12-13T20:22:10.491Z,1576268530.491 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2019-12-13T20:22:10.502Z,1576268530.502 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2019-12-13T20:22:10.502Z,1576268530.502 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2019-12-13T20:22:10.503Z,1576268530.503 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 809 2019-12-13T20:22:10.504Z,1576268530.504 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2019-12-13T20:22:10.505Z,1576268530.505 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2019-12-13T20:22:10.505Z,1576268530.505 [logger ThreadHandler](INFO): Protected caller Thread ID is 810 2019-12-13T20:22:10.507Z,1576268530.507 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2019-12-13T20:22:10.507Z,1576268530.507 [Supervisor](INFO): Looking for Config files in directory: Config/ 2019-12-13T20:22:10.511Z,1576268530.511 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2019-12-13T20:22:10.708Z,1576268530.708 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2019-12-13T20:22:10.710Z,1576268530.710 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2019-12-13T20:22:10.791Z,1576268530.791 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2019-12-13T20:22:11.213Z,1576268531.213 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2019-12-13T20:22:11.215Z,1576268531.215 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2019-12-13T20:22:11.531Z,1576268531.531 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2019-12-13T20:22:11.533Z,1576268531.533 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2019-12-13T20:22:11.628Z,1576268531.628 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2019-12-13T20:22:11.629Z,1576268531.629 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2019-12-13T20:22:11.918Z,1576268531.918 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2019-12-13T20:22:11.920Z,1576268531.920 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2019-12-13T20:22:12.110Z,1576268532.110 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2019-12-13T20:22:12.112Z,1576268532.112 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2019-12-13T20:22:12.567Z,1576268532.567 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2019-12-13T20:22:12.568Z,1576268532.568 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2019-12-13T20:22:12.671Z,1576268532.671 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2019-12-13T20:22:12.673Z,1576268532.673 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2019-12-13T20:22:12.772Z,1576268532.772 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2019-12-13T20:22:12.773Z,1576268532.773 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2019-12-13T20:22:13.399Z,1576268533.399 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2019-12-13T20:22:13.400Z,1576268533.400 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2019-12-13T20:22:13.806Z,1576268533.806 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2019-12-13T20:22:13.806Z,1576268533.806 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2019-12-13T20:22:14.427Z,1576268534.427 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2019-12-13T20:22:14.428Z,1576268534.428 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2019-12-13T20:22:14.571Z,1576268534.571 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2019-12-13T20:22:14.572Z,1576268534.572 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2019-12-13T20:22:14.723Z,1576268534.723 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2019-12-13T20:22:14.725Z,1576268534.725 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/ 2019-12-13T20:22:14.727Z,1576268534.727 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg 2019-12-13T20:22:14.817Z,1576268534.817 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg 2019-12-13T20:22:14.902Z,1576268534.902 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg 2019-12-13T20:22:15.002Z,1576268535.002 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg 2019-12-13T20:22:15.084Z,1576268535.084 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg 2019-12-13T20:22:15.179Z,1576268535.179 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg 2019-12-13T20:22:15.279Z,1576268535.279 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg 2019-12-13T20:22:15.480Z,1576268535.480 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg 2019-12-13T20:22:15.556Z,1576268535.556 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg 2019-12-13T20:22:15.717Z,1576268535.717 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg 2019-12-13T20:22:15.860Z,1576268535.860 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg 2019-12-13T20:22:15.975Z,1576268535.975 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg 2019-12-13T20:22:16.198Z,1576268536.198 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2019-12-13T20:22:16.200Z,1576268536.200 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/root/ 2019-12-13T20:22:16.200Z,1576268536.200 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2019-12-13T20:22:16.213Z,1576268536.213 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2019-12-13T20:22:16.275Z,1576268536.275 [VerticalControl](DEBUG): Construct VerticalControl. 2019-12-13T20:22:16.386Z,1576268536.386 [VerticalControl] Loaded 2019-12-13T20:22:16.386Z,1576268536.386 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2019-12-13T20:22:16.387Z,1576268536.387 [HorizontalControl](DEBUG): Construct HorizontalControl. 2019-12-13T20:22:16.455Z,1576268536.455 [HorizontalControl] Loaded 2019-12-13T20:22:16.455Z,1576268536.455 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2019-12-13T20:22:16.455Z,1576268536.455 [SpeedControl](DEBUG): Construct SpeedControl. 2019-12-13T20:22:16.461Z,1576268536.461 [SpeedControl] Loaded 2019-12-13T20:22:16.461Z,1576268536.461 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2019-12-13T20:22:16.462Z,1576268536.462 [LoopControl](DEBUG): Construct LoopControl. 2019-12-13T20:22:16.462Z,1576268536.462 [LoopControl] Loaded 2019-12-13T20:22:16.463Z,1576268536.463 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2019-12-13T20:22:16.463Z,1576268536.463 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2019-12-13T20:22:16.465Z,1576268536.465 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2019-12-13T20:22:16.488Z,1576268536.488 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2019-12-13T20:22:16.489Z,1576268536.489 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2019-12-13T20:22:16.614Z,1576268536.614 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2019-12-13T20:22:16.614Z,1576268536.614 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2019-12-13T20:22:16.766Z,1576268536.766 [BuoyancyServo] Loaded 2019-12-13T20:22:16.767Z,1576268536.767 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2019-12-13T20:22:16.778Z,1576268536.778 [ElevatorServo] Loaded 2019-12-13T20:22:16.778Z,1576268536.778 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2019-12-13T20:22:16.789Z,1576268536.789 [MassServo] Loaded 2019-12-13T20:22:16.789Z,1576268536.789 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2019-12-13T20:22:16.800Z,1576268536.800 [RudderServo] Loaded 2019-12-13T20:22:16.800Z,1576268536.800 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2019-12-13T20:22:16.811Z,1576268536.811 [ThrusterServo] Loaded 2019-12-13T20:22:16.811Z,1576268536.811 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2019-12-13T20:22:16.812Z,1576268536.812 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2019-12-13T20:22:16.812Z,1576268536.812 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2019-12-13T20:22:16.936Z,1576268536.936 [DeadReckonUsingMultipleVelocitySources] Loaded 2019-12-13T20:22:16.936Z,1576268536.936 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2019-12-13T20:22:16.956Z,1576268536.956 [NavChart] Loaded 2019-12-13T20:22:16.956Z,1576268536.956 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2019-12-13T20:22:16.960Z,1576268536.960 [UniversalFixResidualReporter] Loaded 2019-12-13T20:22:16.960Z,1576268536.960 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2019-12-13T20:22:16.961Z,1576268536.961 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2019-12-13T20:22:16.961Z,1576268536.961 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2019-12-13T20:22:17.075Z,1576268537.075 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2019-12-13T20:22:17.076Z,1576268537.076 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2019-12-13T20:22:17.531Z,1576268537.531 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_orientation 2019-12-13T20:22:17.536Z,1576268537.536 [AHRS_M2](INFO): created writer for : platform_orientation 2019-12-13T20:22:17.538Z,1576268537.538 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_magnetic_orientation 2019-12-13T20:22:17.543Z,1576268537.543 [AHRS_M2](INFO): created writer for : platform_magnetic_orientation 2019-12-13T20:22:17.543Z,1576268537.543 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_pitch_angle 2019-12-13T20:22:17.548Z,1576268537.548 [AHRS_M2](INFO): created writer for : platform_pitch_angle 2019-12-13T20:22:17.549Z,1576268537.549 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_roll_angle 2019-12-13T20:22:17.554Z,1576268537.554 [AHRS_M2](INFO): created writer for : platform_roll_angle 2019-12-13T20:22:17.730Z,1576268537.730 [AHRS_M2] Loaded 2019-12-13T20:22:17.730Z,1576268537.730 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2019-12-13T20:22:17.877Z,1576268537.877 [DataOverHttps] Loaded 2019-12-13T20:22:17.877Z,1576268537.877 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2019-12-13T20:22:17.878Z,1576268537.878 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 408644E0 2019-12-13T20:22:17.879Z,1576268537.879 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 893 2019-12-13T20:22:17.892Z,1576268537.892 [Depth_Keller] Loaded 2019-12-13T20:22:17.893Z,1576268537.893 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2019-12-13T20:22:17.897Z,1576268537.897 [DropWeight] Loaded 2019-12-13T20:22:17.898Z,1576268537.898 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2019-12-13T20:22:17.991Z,1576268537.991 [NAL9602] Loaded 2019-12-13T20:22:17.992Z,1576268537.992 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2019-12-13T20:22:18.007Z,1576268538.007 [Onboard] Loaded 2019-12-13T20:22:18.007Z,1576268538.007 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2019-12-13T20:22:18.010Z,1576268538.010 [Radio_Surface] Loaded 2019-12-13T20:22:18.011Z,1576268538.011 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2019-12-13T20:22:18.012Z,1576268538.012 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408944E0 2019-12-13T20:22:18.012Z,1576268538.012 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 894 2019-12-13T20:22:19.480Z,1576268539.480 [BPC1] Loaded 2019-12-13T20:22:19.480Z,1576268539.480 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2019-12-13T20:22:19.481Z,1576268539.481 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2019-12-13T20:22:19.481Z,1576268539.481 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2019-12-13T20:22:19.842Z,1576268539.842 [DepthRateCalculator] Loaded 2019-12-13T20:22:19.842Z,1576268539.842 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2019-12-13T20:22:19.847Z,1576268539.847 [PitchRateCalculator] Loaded 2019-12-13T20:22:19.847Z,1576268539.847 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2019-12-13T20:22:19.891Z,1576268539.891 [SpeedCalculator] Loaded 2019-12-13T20:22:19.891Z,1576268539.891 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2019-12-13T20:22:19.951Z,1576268539.951 [TempGradientCalculator] Loaded 2019-12-13T20:22:19.952Z,1576268539.952 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2019-12-13T20:22:20.062Z,1576268540.062 [YawRateCalculator] Loaded 2019-12-13T20:22:20.077Z,1576268540.077 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2019-12-13T20:22:20.194Z,1576268540.194 [ElevatorOffsetCalculator] Loaded 2019-12-13T20:22:20.194Z,1576268540.194 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2019-12-13T20:22:20.195Z,1576268540.195 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2019-12-13T20:22:20.195Z,1576268540.195 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2019-12-13T20:22:20.564Z,1576268540.564 [CANONSampler] Loaded 2019-12-13T20:22:20.565Z,1576268540.565 [ComponentRegistry](DEBUG): SyncComponent "CANONSampler" handled in the control thread. 2019-12-13T20:22:20.574Z,1576268540.574 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_density 2019-12-13T20:22:20.579Z,1576268540.579 [CTD_Seabird](INFO): created writer for : sea_water_density 2019-12-13T20:22:20.579Z,1576268540.579 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): depth 2019-12-13T20:22:20.584Z,1576268540.584 [CTD_Seabird](INFO): created writer for : depth 2019-12-13T20:22:20.584Z,1576268540.584 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_pressure 2019-12-13T20:22:20.589Z,1576268540.589 [CTD_Seabird](INFO): created writer for : sea_water_pressure 2019-12-13T20:22:20.590Z,1576268540.590 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_salinity 2019-12-13T20:22:20.595Z,1576268540.595 [CTD_Seabird](INFO): created writer for : sea_water_salinity 2019-12-13T20:22:20.595Z,1576268540.595 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_temperature 2019-12-13T20:22:20.600Z,1576268540.600 [CTD_Seabird](INFO): created writer for : sea_water_temperature 2019-12-13T20:22:20.601Z,1576268540.601 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_electrical_conductivity 2019-12-13T20:22:20.606Z,1576268540.606 [CTD_Seabird](INFO): created writer for : sea_water_electrical_conductivity 2019-12-13T20:22:20.607Z,1576268540.607 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): speed_of_sound_in_sea_water 2019-12-13T20:22:20.612Z,1576268540.612 [CTD_Seabird](INFO): created writer for : speed_of_sound_in_sea_water 2019-12-13T20:22:20.612Z,1576268540.612 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): mass_concentration_of_oxygen_in_sea_water 2019-12-13T20:22:20.618Z,1576268540.618 [CTD_Seabird](INFO): created writer for : mass_concentration_of_oxygen_in_sea_water 2019-12-13T20:22:20.618Z,1576268540.618 [CTD_Seabird](DEBUG): LcmSlateWriter::add(DAtaURI): CTD_Seabird.sea_water_dissolved_oxygen_freq 2019-12-13T20:22:20.619Z,1576268540.619 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): dataName: sea_water_dissolved_oxygen_freq 2019-12-13T20:22:20.650Z,1576268540.650 [CTD_Seabird] Loaded 2019-12-13T20:22:20.650Z,1576268540.650 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2019-12-13T20:22:20.651Z,1576268540.651 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 409964E0 2019-12-13T20:22:20.652Z,1576268540.652 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 895 2019-12-13T20:22:20.667Z,1576268540.667 [PAR_Licor] Loaded 2019-12-13T20:22:20.667Z,1576268540.667 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2019-12-13T20:22:20.673Z,1576268540.673 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.Output470 2019-12-13T20:22:20.673Z,1576268540.673 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: Output470 2019-12-13T20:22:20.677Z,1576268540.677 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.Output650 2019-12-13T20:22:20.677Z,1576268540.677 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: Output650 2019-12-13T20:22:20.682Z,1576268540.682 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.OutputChl 2019-12-13T20:22:20.682Z,1576268540.682 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: OutputChl 2019-12-13T20:22:20.686Z,1576268540.686 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.VolumeScatCoeff117deg470nm 2019-12-13T20:22:20.686Z,1576268540.686 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: VolumeScatCoeff117deg470nm 2019-12-13T20:22:20.691Z,1576268540.691 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.VolumeScatCoeff117deg650nm 2019-12-13T20:22:20.691Z,1576268540.691 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: VolumeScatCoeff117deg650nm 2019-12-13T20:22:20.695Z,1576268540.695 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.BackscatteringCoeff470nm 2019-12-13T20:22:20.695Z,1576268540.695 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: BackscatteringCoeff470nm 2019-12-13T20:22:20.700Z,1576268540.700 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.BackscatteringCoeff650nm 2019-12-13T20:22:20.700Z,1576268540.700 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: BackscatteringCoeff650nm 2019-12-13T20:22:20.704Z,1576268540.704 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): mass_concentration_of_chlorophyll_in_sea_water 2019-12-13T20:22:20.708Z,1576268540.708 [WetLabsBB2FL](INFO): created writer for : mass_concentration_of_chlorophyll_in_sea_water 2019-12-13T20:22:20.709Z,1576268540.709 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_median_mass_concentration_of_chlorophyll_in_sea_water 2019-12-13T20:22:20.709Z,1576268540.709 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_median_mass_concentration_of_chlorophyll_in_sea_water 2019-12-13T20:22:20.713Z,1576268540.713 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water 2019-12-13T20:22:20.713Z,1576268540.713 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_mean_mass_concentration_of_chlorophyll_in_sea_water 2019-12-13T20:22:20.718Z,1576268540.718 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_variance_mass_concentration_of_chlorophyll_in_sea_water 2019-12-13T20:22:20.718Z,1576268540.718 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_variance_mass_concentration_of_chlorophyll_in_sea_water 2019-12-13T20:22:20.722Z,1576268540.722 [WetLabsBB2FL] Loaded 2019-12-13T20:22:20.722Z,1576268540.722 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2019-12-13T20:22:20.723Z,1576268540.723 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 409C64E0 2019-12-13T20:22:20.724Z,1576268540.724 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 896 2019-12-13T20:22:20.724Z,1576268540.724 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2019-12-13T20:22:20.725Z,1576268540.725 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2019-12-13T20:22:20.773Z,1576268540.773 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2019-12-13T20:22:20.773Z,1576268540.773 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2019-12-13T20:22:21.108Z,1576268541.108 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2019-12-13T20:22:21.110Z,1576268541.110 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2019-12-13T20:22:21.271Z,1576268541.271 [SBIT](DEBUG): Construct Startup Built In Test. 2019-12-13T20:22:21.282Z,1576268541.282 [SBIT] Loaded 2019-12-13T20:22:21.282Z,1576268541.282 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2019-12-13T20:22:21.283Z,1576268541.283 [IBIT](DEBUG): Construct Initiated Built In Test. 2019-12-13T20:22:21.295Z,1576268541.295 [IBIT] Loaded 2019-12-13T20:22:21.296Z,1576268541.296 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2019-12-13T20:22:21.299Z,1576268541.299 [CBIT](DEBUG): Construct Continuous Built In Test. 2019-12-13T20:22:21.436Z,1576268541.436 [CBIT] Loaded 2019-12-13T20:22:21.436Z,1576268541.436 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2019-12-13T20:22:21.437Z,1576268541.437 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2019-12-13T20:22:21.440Z,1576268541.440 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2019-12-13T20:22:21.441Z,1576268541.441 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2019-12-13T20:22:21.447Z,1576268541.447 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2019-12-13T20:22:21.449Z,1576268541.449 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40AC54E0 2019-12-13T20:22:21.449Z,1576268541.449 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 897 2019-12-13T20:22:21.454Z,1576268541.454 [Supervisor](INFO): Main Thread ID is 803 2019-12-13T20:22:21.454Z,1576268541.454 [Supervisor](DEBUG): Running supervisor. 2019-12-13T20:22:21.454Z,1576268541.454 [CommandLine ThreadHandler](INFO): Handler Thread ID is 898 2019-12-13T20:22:21.457Z,1576268541.457 [controlThread ThreadHandler](INFO): Handler Thread ID is 899 2019-12-13T20:22:21.457Z,1576268541.457 [controlThread](DEBUG): Initializing ControlThread 2019-12-13T20:22:21.458Z,1576268541.458 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2019-12-13T20:22:21.459Z,1576268541.459 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2019-12-13T20:22:21.460Z,1576268541.460 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2019-12-13T20:22:21.461Z,1576268541.461 [LoopControl](DEBUG): Initialize LoopControlComponent. 2019-12-13T20:22:21.462Z,1576268541.462 [NavChart](DEBUG): Initialize NavChart Navigation. 2019-12-13T20:22:21.462Z,1576268541.462 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2019-12-13T20:22:21.467Z,1576268541.467 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2019-12-13T20:22:21.467Z,1576268541.467 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2019-12-13T20:22:21.467Z,1576268541.467 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2019-12-13T20:22:21.468Z,1576268541.468 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2019-12-13T20:22:21.468Z,1576268541.468 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2019-12-13T20:22:21.469Z,1576268541.469 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2019-12-13T20:22:21.473Z,1576268541.473 [SBIT](INFO): Initialize SBIT Component. 2019-12-13T20:22:21.474Z,1576268541.474 [SBIT](IMPORTANT): git: 2019-11-11 2019-12-13T20:22:21.474Z,1576268541.474 [SBIT](INFO): git hash: d323e2e841967a23cb7fd5209d5be46b38c2f2ac 2019-12-13T20:22:21.474Z,1576268541.474 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2019-12-13T20:22:21.475Z,1576268541.475 [SBIT](INFO): Kernel Reporting Different Version From Configuration. Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018 Kernel Reported: #1 PREEMPT Tue Dec 18 21:19:28 PST 2018 2019-12-13T20:22:21.476Z,1576268541.476 [SBIT](INFO): Beginning SBIT in 55.000000 seconds. 2019-12-13T20:22:21.477Z,1576268541.477 [IBIT](INFO): Initialize IBIT Component. 2019-12-13T20:22:21.478Z,1576268541.478 [CBIT](DEBUG): Initialize CBIT Component. 2019-12-13T20:22:21.479Z,1576268541.479 [logger ThreadHandler](INFO): Handler Thread ID is 900 2019-12-13T20:22:21.489Z,1576268541.489 [CBIT](DEBUG): Initialized mux pins. 2019-12-13T20:22:21.489Z,1576268541.489 [CBIT](DEBUG): Initializing the watchdog timer. 2019-12-13T20:22:21.497Z,1576268541.497 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 901 2019-12-13T20:22:21.498Z,1576268541.498 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2019-12-13T20:22:21.509Z,1576268541.509 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 902 2019-12-13T20:22:21.513Z,1576268541.513 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2019-12-13T20:22:21.513Z,1576268541.513 [CBIT](DEBUG): Initializing heartbeat. 2019-12-13T20:22:21.521Z,1576268541.521 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 903 2019-12-13T20:22:21.522Z,1576268541.522 [CTD_Seabird](DEBUG): Initializing CTD_Seabird. 2019-12-13T20:22:21.525Z,1576268541.525 [CTD_Seabird](INFO): Opening uart, block timeout 10ths=20 2019-12-13T20:22:21.527Z,1576268541.527 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 905 2019-12-13T20:22:21.528Z,1576268541.528 [WetLabsBB2FL](INFO): Powering down 2019-12-13T20:22:21.573Z,1576268541.573 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 906 2019-12-13T20:22:21.585Z,1576268541.585 [CBIT](DEBUG): Deactivating GF circuits. 2019-12-13T20:22:21.585Z,1576268541.585 [CBIT](DEBUG): Deactivating emergency mode. 2019-12-13T20:22:21.621Z,1576268541.621 [CBIT](DEBUG): Backplane powered. 2019-12-13T20:22:21.660Z,1576268541.660 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2019-12-13T20:22:21.770Z,1576268541.770 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2019-12-13T20:22:21.770Z,1576268541.770 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2019-12-13T20:22:21.770Z,1576268541.770 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2019-12-13T20:22:21.771Z,1576268541.771 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2019-12-13T20:22:21.771Z,1576268541.771 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2019-12-13T20:22:21.771Z,1576268541.771 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2019-12-13T20:22:21.771Z,1576268541.771 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000 2019-12-13T20:22:21.771Z,1576268541.771 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2019-12-13T20:22:21.772Z,1576268541.772 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2019-12-13T20:22:21.772Z,1576268541.772 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2019-12-13T20:22:21.772Z,1576268541.772 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000 2019-12-13T20:22:21.772Z,1576268541.772 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2019-12-13T20:22:21.772Z,1576268541.772 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000 2019-12-13T20:22:21.773Z,1576268541.773 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2019-12-13T20:22:21.773Z,1576268541.773 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000 2019-12-13T20:22:21.773Z,1576268541.773 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2019-12-13T20:22:21.847Z,1576268541.847 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2019-12-13T20:22:21.913Z,1576268541.913 [Radio_Surface](INFO): Powering up 2019-12-13T20:22:21.932Z,1576268541.932 [MissionManager](DEBUG): 2019-12-13T20:22:21.933Z,1576268541.933 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2019-12-13T20:22:21.999Z,1576268541.999 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2019-12-13T20:22:22.000Z,1576268542.000 [Default:A.Wait](DEBUG): Construct Wait. 2019-12-13T20:22:22.019Z,1576268542.019 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2019-12-13T20:22:22.045Z,1576268542.045 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2019-12-13T20:22:22.048Z,1576268542.048 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2019-12-13T20:22:22.081Z,1576268542.081 [Default:E.Execute](DEBUG): Construct Execute. 2019-12-13T20:22:22.084Z,1576268542.084 [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-13T20:22:22.105Z,1576268542.105 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,NAL9602,Onboard,BPC1,CANONSampler,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-13T20:22:22.117Z,1576268542.117 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2019-12-13T20:22:22.230Z,1576268542.230 [Depth_Keller](ERROR): Pressure reading out of range: 1831.023193 decibar 2019-12-13T20:22:22.277Z,1576268542.277 [CANONSampler](INFO): Powering down 2019-12-13T20:22:22.415Z,1576268542.415 [DepthRateCalculator](ERROR): Depth measurement is not active 2019-12-13T20:22:22.481Z,1576268542.481 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2019-12-13T20:22:22.489Z,1576268542.489 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2019-12-13T20:22:22.490Z,1576268542.490 [ElevatorServo](DEBUG): Initializing EZServoServo. 2019-12-13T20:22:22.497Z,1576268542.497 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2019-12-13T20:22:22.498Z,1576268542.498 [MassServo](DEBUG): Initializing EZServoServo. 2019-12-13T20:22:22.505Z,1576268542.505 [MassServo](DEBUG): Initializing MassServo. 2019-12-13T20:22:22.506Z,1576268542.506 [RudderServo](DEBUG): Initializing EZServoServo. 2019-12-13T20:22:22.513Z,1576268542.513 [RudderServo](DEBUG): Initializing RudderServo. 2019-12-13T20:22:22.514Z,1576268542.514 [ThrusterServo](DEBUG): Initializing EZServoServo. 2019-12-13T20:22:22.521Z,1576268542.521 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2019-12-13T20:22:48.398Z,1576268568.398 [NAL9602](INFO): Powering up NAL9602 2019-12-13T20:22:59.302Z,1576268579.302 [NAL9602](INFO): NAL9602 initialized 2019-12-13T20:23:17.122Z,1576268597.122 [SBIT](IMPORTANT): Beginning Startup BIT 2019-12-13T20:23:17.126Z,1576268597.126 [CBIT](IMPORTANT): Beginning ground fault scan 2019-12-13T20:23:28.151Z,1576268608.151 [CBIT](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): 4.657929 CHAN A1 (24V): -0.180726 CHAN A2 (12V): -0.002079 CHAN A3 (5V): -0.001277 CHAN B0 (3.3V): 0.000055 CHAN B1 (3.15aV): -0.000440 CHAN B2 (3.15bV): -0.000494 CHAN B3 (GND): 0.000153 OPEN: -0.000500 Full Scale Calc: 4.765 mA, -1.589 mA 2019-12-13T20:23:38.207Z,1576268618.207 [CommandLine](IMPORTANT): got command gfscan 2019-12-13T20:23:38.450Z,1576268618.450 [CBIT](IMPORTANT): Beginning ground fault scan 2019-12-13T20:23:49.390Z,1576268629.390 [CBIT](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): 4.657929 CHAN A1 (24V): -0.180497 CHAN A2 (12V): -0.002950 CHAN A3 (5V): -0.001656 CHAN B0 (3.3V): 0.000659 CHAN B1 (3.15aV): -0.000682 CHAN B2 (3.15bV): -0.000502 CHAN B3 (GND): 0.000232 OPEN: -0.000362 Full Scale Calc: 4.765 mA, -1.589 mA 2019-12-13T20:24:10.443Z,1576268650.443 [SBIT](IMPORTANT): SBIT PASSED 2019-12-13T20:24:10.470Z,1576268650.470 [CommandLine](IMPORTANT): got command configSet list 2019-12-13T20:24:10.470Z,1576268650.470 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2019-12-13T20:24:10.471Z,1576268650.471 [CommandLine](IMPORTANT): CBIT.gf24Offset=154 microampere; 2019-12-13T20:24:10.471Z,1576268650.471 [CommandLine](IMPORTANT): CTD_NeilBrown.loadAtStartup=0 bool; 2019-12-13T20:24:10.471Z,1576268650.471 [CommandLine](IMPORTANT): CTD_Seabird.verbosity=0 count; 2019-12-13T20:24:10.474Z,1576268650.474 [CommandLine](IMPORTANT): DAT.loadAtStartup=0 bool; 2019-12-13T20:24:10.474Z,1576268650.474 [CommandLine](IMPORTANT): DVL_micro.loadAtStartup=0 bool; 2019-12-13T20:24:10.474Z,1576268650.474 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral=338 cubic_centimeter; 2019-12-13T20:24:10.474Z,1576268650.474 [CommandLine](IMPORTANT): VerticalControl.massDefault=-9 millimeter; 2019-12-13T20:24:10.839Z,1576268650.839 [MissionManager](IMPORTANT): Started mission Startup 2019-12-13T20:24:10.839Z,1576268650.839 [Startup] Running Loop=1 2019-12-13T20:24:10.840Z,1576268650.840 [Startup](DEBUG): Aggregate::initialize Startup 2019-12-13T20:24:10.840Z,1576268650.840 [Startup:A.GoToSurface] Running Loop=1 2019-12-13T20:24:10.840Z,1576268650.840 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2019-12-13T20:24:10.840Z,1576268650.840 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2019-12-13T20:24:10.841Z,1576268650.841 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2019-12-13T20:24:10.841Z,1576268650.841 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2019-12-13T20:24:10.842Z,1576268650.842 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2019-12-13T20:24:10.842Z,1576268650.842 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2019-12-13T20:24:10.843Z,1576268650.843 [Startup:StartupSatComms] Running Loop=1 2019-12-13T20:24:10.843Z,1576268650.843 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2019-12-13T20:24:10.844Z,1576268650.844 [Startup:StartupSatComms:A] Running Loop=1 2019-12-13T20:24:11.243Z,1576268651.243 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2019-12-13T20:24:49.661Z,1576268689.661 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.011479 2019-12-13T20:25:11.142Z,1576268711.142 [Startup:StartupSatComms:A](INFO): Timed out from 2019-12-13T20:24:10.8Z 2019-12-13T20:25:11.142Z,1576268711.142 [Startup:StartupSatComms:A] Stopped 2019-12-13T20:25:11.142Z,1576268711.142 [Startup:StartupSatComms:B] Running Loop=1 2019-12-13T20:25:11.443Z,1576268711.443 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2019-12-13T20:25:18.218Z,1576268718.218 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20191213T173303/Courier0052.lzma 2019-12-13T20:25:20.223Z,1576268720.223 [DataOverHttps](INFO): Moved sent file to Logs/20191213T173303/Courier0052.lzma.bak 2019-12-13T20:25:20.223Z,1576268720.223 [DataOverHttps](INFO): SBD MOMSN=12155856 2019-12-13T20:25:21.520Z,1576268721.520 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2019-12-13T20:25:21.520Z,1576268721.520 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-12-13T20:25:21.530Z,1576268721.530 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-12-13T20:25:21.939Z,1576268721.939 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-12-13T20:25:21.939Z,1576268721.939 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2019-12-13T20:25:37.402Z,1576268737.402 [DataOverHttps](INFO): Sending 120 bytes from file Logs/20191213T173303/Express0053.lzma 2019-12-13T20:25:39.406Z,1576268739.406 [DataOverHttps](INFO): Moved sent file to Logs/20191213T173303/Express0053.lzma.bak 2019-12-13T20:25:39.407Z,1576268739.407 [DataOverHttps](INFO): SBD MOMSN=12155858 2019-12-13T20:25:56.150Z,1576268756.150 [DataOverHttps](INFO): Sending 785 bytes from file Logs/20191213T202210/Express0001.lzma 2019-12-13T20:25:58.154Z,1576268758.154 [DataOverHttps](INFO): Moved sent file to Logs/20191213T202210/Express0001.lzma.bak 2019-12-13T20:25:58.154Z,1576268758.154 [DataOverHttps](INFO): SBD MOMSN=12155864 2019-12-13T20:25:59.513Z,1576268759.513 [Startup:StartupSatComms:B] Stopped 2019-12-13T20:25:59.513Z,1576268759.513 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2019-12-13T20:25:59.513Z,1576268759.513 [Startup:StartupSatComms] Stopped 2019-12-13T20:25:59.513Z,1576268759.513 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2019-12-13T20:25:59.514Z,1576268759.514 [Startup](INFO): Completed Startup 2019-12-13T20:25:59.514Z,1576268759.514 [MissionManager](INFO): Startup is completed. 2019-12-13T20:25:59.514Z,1576268759.514 [MissionManager](INFO): Uninitializing Mission Startup 2019-12-13T20:25:59.514Z,1576268759.514 [Startup] Stopped 2019-12-13T20:25:59.515Z,1576268759.515 [Startup](DEBUG): Aggregate::uninitialize Startup 2019-12-13T20:25:59.515Z,1576268759.515 [Startup:A.GoToSurface] Stopped 2019-12-13T20:25:59.515Z,1576268759.515 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2019-12-13T20:25:59.919Z,1576268759.919 [MissionManager](IMPORTANT): Started mission Default 2019-12-13T20:25:59.919Z,1576268759.919 [Default] Running Loop=1 2019-12-13T20:25:59.919Z,1576268759.919 [Default](DEBUG): Aggregate::initialize Default 2019-12-13T20:25:59.919Z,1576268759.919 [Default:B.GoToSurface] Running Loop=1 2019-12-13T20:25:59.919Z,1576268759.919 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2019-12-13T20:25:59.920Z,1576268759.920 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2019-12-13T20:25:59.920Z,1576268759.920 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2019-12-13T20:25:59.920Z,1576268759.920 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2019-12-13T20:25:59.920Z,1576268759.920 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2019-12-13T20:25:59.921Z,1576268759.921 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2019-12-13T20:25:59.921Z,1576268759.921 [Default:A.Wait] Running Loop=1 2019-12-13T20:25:59.921Z,1576268759.921 [Default:A.Wait](DEBUG): Initialize Wait Component. 2019-12-13T20:26:13.246Z,1576268773.246 [Default:A.Wait](INFO): Done Waiting. 2019-12-13T20:26:13.246Z,1576268773.246 [Default:A.Wait] Stopped 2019-12-13T20:26:13.246Z,1576268773.246 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2019-12-13T20:26:13.639Z,1576268773.639 [Default:CheckIn] Running Loop=1 2019-12-13T20:26:13.639Z,1576268773.639 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-12-13T20:26:13.639Z,1576268773.639 [Default:CheckIn:Read_GPS] Running Loop=1 2019-12-13T20:26:14.041Z,1576268774.041 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2019-12-13T20:26:38.098Z,1576268798.098 [CommandLine](IMPORTANT): got command gfscan 2019-12-13T20:26:38.318Z,1576268798.318 [CBIT](IMPORTANT): Beginning ground fault scan 2019-12-13T20:26:49.215Z,1576268809.215 [CBIT](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): -0.001625 CHAN A1 (24V): -0.181200 CHAN A2 (12V): -0.002319 CHAN A3 (5V): -0.001145 CHAN B0 (3.3V): 0.000419 CHAN B1 (3.15aV): -0.000349 CHAN B2 (3.15bV): -0.000292 CHAN B3 (GND): -0.000221 OPEN: -0.000029 Full Scale Calc: 4.765 mA, -1.589 mA 2019-12-13T20:27:00.158Z,1576268820.158 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2019-12-13T20:27:02.382Z,1576268822.382 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2 2019-12-13T20:27:04.362Z,1576268824.362 [CommandLine](IMPORTANT): got command gfscan 2019-12-13T20:27:04.607Z,1576268824.607 [CBIT](IMPORTANT): Beginning ground fault scan 2019-12-13T20:27:15.493Z,1576268835.493 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.000705 CHAN A1 (24V): 0.000666 CHAN A2 (12V): -0.001756 CHAN A3 (5V): -0.001810 CHAN B0 (3.3V): 0.000129 CHAN B1 (3.15aV): -0.000351 CHAN B2 (3.15bV): -0.000257 CHAN B3 (GND): -0.000251 OPEN: -0.000126 Full Scale Calc: 4.765 mA, -1.589 mA 2019-12-13T20:27:27.222Z,1576268847.222 [CommandLine](IMPORTANT): got command ! echo 0 > /dev/loadB2 2019-12-13T20:28:02.700Z,1576268882.700 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-12-13T20:28:19.796Z,1576268899.796 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2019-12-13T20:28:22.557Z,1576268902.557 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2 2019-12-13T20:28:22.557Z,1576268902.557 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-12-13T20:28:22.566Z,1576268902.566 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-12-13T20:28:22.938Z,1576268902.938 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-12-13T20:28:22.938Z,1576268902.938 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2 2019-12-13T20:28:48.962Z,1576268928.962 [CommandLine](IMPORTANT): got command burn on 2019-12-13T20:28:48.963Z,1576268928.963 [CommandLine](IMPORTANT): Activating dropweight wire 2019-12-13T20:29:15.901Z,1576268955.901 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2019-12-13T20:29:43.790Z,1576268983.790 [CommandLine](IMPORTANT): got command burn off 2019-12-13T20:29:43.791Z,1576268983.791 [CommandLine](IMPORTANT): Deactivating dropweight wire 2019-12-13T20:30:00.743Z,1576269000.743 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2019-12-13T20:30:03.970Z,1576269003.970 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2019-12-13T20:30:54.035Z,1576269054.035 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2019-12-13T20:30:54.038Z,1576269054.038 [BPC1](INFO): Received data from all battery sticks. 2019-12-13T20:31:13.827Z,1576269073.827 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-12-13T20:26:13.6Z 2019-12-13T20:31:13.827Z,1576269073.827 [Default:CheckIn:Read_GPS] Stopped 2019-12-13T20:31:13.827Z,1576269073.827 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-12-13T20:31:14.219Z,1576269074.219 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2019-12-13T20:31:17.890Z,1576269077.890 [CommandLine](IMPORTANT): got command show variable cbit 2019-12-13T20:31:17.898Z,1576269077.898 [CommandLine](IMPORTANT): CBIT.GFActive (bool) 2019-12-13T20:31:17.932Z,1576269077.932 [CommandLine](IMPORTANT): CBIT.loadAtStartup (bool) 2019-12-13T20:31:17.949Z,1576269077.949 [CommandLine](IMPORTANT): CBIT.simulateHardware (bool) 2019-12-13T20:31:17.949Z,1576269077.949 [CommandLine](IMPORTANT): CBIT.stopDepth (meter) 2019-12-13T20:31:17.950Z,1576269077.950 [CommandLine](IMPORTANT): CBIT.abortDepth (meter) 2019-12-13T20:31:17.950Z,1576269077.950 [CommandLine](IMPORTANT): CBIT.humidityThreshold (percent) 2019-12-13T20:31:17.950Z,1576269077.950 [CommandLine](IMPORTANT): CBIT.pressureThreshold (pound_per_square_inch) 2019-12-13T20:31:17.951Z,1576269077.951 [CommandLine](IMPORTANT): CBIT.tempThreshold (fahrenheit) 2019-12-13T20:31:17.951Z,1576269077.951 [CommandLine](IMPORTANT): CBIT.abortDepthTimeout (second) 2019-12-13T20:31:17.951Z,1576269077.951 [CommandLine](IMPORTANT): CBIT.battFailReport (count) 2019-12-13T20:31:17.952Z,1576269077.952 [CommandLine](IMPORTANT): CBIT.battTempThreshold (celsius) 2019-12-13T20:31:17.952Z,1576269077.952 [CommandLine](IMPORTANT): CBIT.envTimeout (second) 2019-12-13T20:31:17.952Z,1576269077.952 [CommandLine](IMPORTANT): CBIT.runElevOffsetCalc (bool) 2019-12-13T20:31:17.953Z,1576269077.953 [CommandLine](IMPORTANT): CBIT.runFaultClassifier (bool) 2019-12-13T20:31:17.953Z,1576269077.953 [CommandLine](IMPORTANT): CBIT.vehicleOpen (bool) 2019-12-13T20:31:17.954Z,1576269077.954 [CommandLine](IMPORTANT): CBIT.gfChanA0_Threshold (milliampere) 2019-12-13T20:31:17.954Z,1576269077.954 [CommandLine](IMPORTANT): CBIT.gfChanA1_Threshold (milliampere) 2019-12-13T20:31:17.954Z,1576269077.954 [CommandLine](IMPORTANT): CBIT.gfChanA2_Threshold (milliampere) 2019-12-13T20:31:17.955Z,1576269077.955 [CommandLine](IMPORTANT): CBIT.gfChanA3_Threshold (milliampere) 2019-12-13T20:31:17.955Z,1576269077.955 [CommandLine](IMPORTANT): CBIT.gfChanB0_Threshold (milliampere) 2019-12-13T20:31:17.955Z,1576269077.955 [CommandLine](IMPORTANT): CBIT.gfChanB1_Threshold (milliampere) 2019-12-13T20:31:17.956Z,1576269077.956 [CommandLine](IMPORTANT): CBIT.gfChanB2_Threshold (milliampere) 2019-12-13T20:31:17.956Z,1576269077.956 [CommandLine](IMPORTANT): CBIT.gfChanB3_Threshold (milliampere) 2019-12-13T20:31:17.956Z,1576269077.956 [CommandLine](IMPORTANT): CBIT.gfScanTimeout (hour) 2019-12-13T20:31:17.997Z,1576269077.997 [CommandLine](IMPORTANT): CBIT.gfBattOffset (microampere) 2019-12-13T20:31:17.997Z,1576269077.997 [CommandLine](IMPORTANT): CBIT.gf24Offset (microampere) 2019-12-13T20:31:17.998Z,1576269077.998 [CommandLine](IMPORTANT): CBIT.gf12Offset (microampere) 2019-12-13T20:31:17.998Z,1576269077.998 [CommandLine](IMPORTANT): CBIT.gf5Offset (microampere) 2019-12-13T20:31:17.998Z,1576269077.998 [CommandLine](IMPORTANT): CBIT.gf3_3Offset (microampere) 2019-12-13T20:31:17.999Z,1576269077.999 [CommandLine](IMPORTANT): CBIT.gf3_15Offset (microampere) 2019-12-13T20:31:17.999Z,1576269077.999 [CommandLine](IMPORTANT): CBIT.gfCommOffset (microampere) 2019-12-13T20:31:18.003Z,1576269078.003 [CommandLine](IMPORTANT): CBITMainGroundfault.ad (none) 2019-12-13T20:31:18.004Z,1576269078.004 [CommandLine](IMPORTANT): CBITMainGroundfault.adRes (bit) 2019-12-13T20:31:18.004Z,1576269078.004 [CommandLine](IMPORTANT): CBITMainGroundfault.adTimeout (millisecond) 2019-12-13T20:31:18.004Z,1576269078.004 [CommandLine](IMPORTANT): CBITMainGroundfault.adVref (volt) 2019-12-13T20:31:18.005Z,1576269078.005 [CommandLine](IMPORTANT): CBITWaterAlarmBow.ad (none) 2019-12-13T20:31:18.005Z,1576269078.005 [CommandLine](IMPORTANT): CBITWaterAlarmBow.adRes (bit) 2019-12-13T20:31:18.005Z,1576269078.005 [CommandLine](IMPORTANT): CBITWaterAlarmBow.adVref (volt) 2019-12-13T20:31:18.006Z,1576269078.006 [CommandLine](IMPORTANT): CBITWaterAlarmStern.ad (none) 2019-12-13T20:31:18.006Z,1576269078.006 [CommandLine](IMPORTANT): CBITWaterAlarmStern.adRes (bit) 2019-12-13T20:31:18.006Z,1576269078.006 [CommandLine](IMPORTANT): CBITWaterAlarmStern.adVref (volt) 2019-12-13T20:31:18.007Z,1576269078.007 [CommandLine](IMPORTANT): CBITWaterAlarmAux.ad (none) 2019-12-13T20:31:18.007Z,1576269078.007 [CommandLine](IMPORTANT): CBITWaterAlarmAux.adRes (bit) 2019-12-13T20:31:18.008Z,1576269078.008 [CommandLine](IMPORTANT): CBITWaterAlarmAux.adVref (volt) 2019-12-13T20:31:18.314Z,1576269078.314 [CommandLine](IMPORTANT): CBIT.empiricalFaultElevOffset (radian) 2019-12-13T20:31:18.314Z,1576269078.314 [CommandLine](IMPORTANT): CBIT.shorePowerOn (bool) 2019-12-13T20:31:18.315Z,1576269078.315 [CommandLine](IMPORTANT): CBIT.platform_fault (enum) 2019-12-13T20:31:18.316Z,1576269078.316 [CommandLine](IMPORTANT): CBIT.platform_fault_leak (enum) 2019-12-13T20:31:18.316Z,1576269078.316 [CommandLine](IMPORTANT): CBIT.GFCHANA0Current (milliampere) 2019-12-13T20:31:18.316Z,1576269078.316 [CommandLine](IMPORTANT): CBIT.GFCHANA1Current (milliampere) 2019-12-13T20:31:18.317Z,1576269078.317 [CommandLine](IMPORTANT): CBIT.GFCHANA2Current (milliampere) 2019-12-13T20:31:18.317Z,1576269078.317 [CommandLine](IMPORTANT): CBIT.GFCHANA3Current (milliampere) 2019-12-13T20:31:18.317Z,1576269078.318 [CommandLine](IMPORTANT): CBIT.GFCHANB0Current (milliampere) 2019-12-13T20:31:18.318Z,1576269078.318 [CommandLine](IMPORTANT): CBIT.GFCHANB1Current (milliampere) 2019-12-13T20:31:18.318Z,1576269078.318 [CommandLine](IMPORTANT): CBIT.GFCHANB2Current (milliampere) 2019-12-13T20:31:18.319Z,1576269078.319 [CommandLine](IMPORTANT): CBIT.GFCHANB3Current (milliampere) 2019-12-13T20:31:18.319Z,1576269078.319 [CommandLine](IMPORTANT): CBIT.GFCHANOpenCurrent (milliampere) 2019-12-13T20:31:18.319Z,1576269078.319 [CommandLine](IMPORTANT): CBIT.empericalClassifierFaultDetected (enum) 2019-12-13T20:31:18.320Z,1576269078.320 [CommandLine](IMPORTANT): CBIT.binnedDepthRate (meter_per_second) 2019-12-13T20:31:21.400Z,1576269081.400 [DataOverHttps](INFO): Sending 187 bytes from file Logs/20191213T202210/Courier0004.lzma 2019-12-13T20:31:23.406Z,1576269083.406 [DataOverHttps](INFO): Moved sent file to Logs/20191213T202210/Courier0004.lzma.bak 2019-12-13T20:31:23.406Z,1576269083.406 [DataOverHttps](INFO): SBD MOMSN=12155894 2019-12-13T20:31:23.514Z,1576269083.514 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3 2019-12-13T20:31:23.514Z,1576269083.514 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-12-13T20:31:23.552Z,1576269083.552 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-12-13T20:31:23.922Z,1576269083.922 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-12-13T20:31:23.922Z,1576269083.922 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3 2019-12-13T20:31:30.474Z,1576269090.474 [CommandLine](IMPORTANT): got command show variable depth 2019-12-13T20:31:30.476Z,1576269090.476 [CommandLine](IMPORTANT): depth (meter) 2019-12-13T20:31:30.476Z,1576269090.476 [CommandLine](IMPORTANT): depth_rate (meter_per_second) 2019-12-13T20:31:30.480Z,1576269090.480 [CommandLine](IMPORTANT): sea_floor_depth_below_geoid (unknown) 2019-12-13T20:31:30.490Z,1576269090.490 [CommandLine](IMPORTANT): Config/Simulator.mixedLayerDepth (meter) 2019-12-13T20:31:30.495Z,1576269090.495 [CommandLine](IMPORTANT): VerticalControl.buoyancyPumpDepth (meter) 2019-12-13T20:31:30.496Z,1576269090.496 [CommandLine](IMPORTANT): VerticalControl.depthDeadband (meter) 2019-12-13T20:31:30.496Z,1576269090.496 [CommandLine](IMPORTANT): VerticalControl.depthRateDeadband (meter_per_second) 2019-12-13T20:31:30.496Z,1576269090.496 [CommandLine](IMPORTANT): VerticalControl.depthRateSamples (count) 2019-12-13T20:31:30.497Z,1576269090.497 [CommandLine](IMPORTANT): VerticalControl.dropWtDepthExcursion (meter) 2019-12-13T20:31:30.497Z,1576269090.497 [CommandLine](IMPORTANT): VerticalControl.excursionDepthTimeout (second) 2019-12-13T20:31:30.498Z,1576269090.498 [CommandLine](IMPORTANT): VerticalControl.kdDepth (radian_per_second_per_meter) 2019-12-13T20:31:30.498Z,1576269090.498 [CommandLine](IMPORTANT): VerticalControl.kdDepthBuoy (second) 2019-12-13T20:31:30.498Z,1576269090.498 [CommandLine](IMPORTANT): VerticalControl.kdDepthRateBuoy (second) 2019-12-13T20:31:30.499Z,1576269090.499 [CommandLine](IMPORTANT): VerticalControl.kiDepth (radian_per_second_per_meter) 2019-12-13T20:31:30.499Z,1576269090.499 [CommandLine](IMPORTANT): VerticalControl.kiDepthBuoy (reciprocal_second) 2019-12-13T20:31:30.500Z,1576269090.500 [CommandLine](IMPORTANT): VerticalControl.kiDepthOff (meter_per_second) 2019-12-13T20:31:30.500Z,1576269090.500 [CommandLine](IMPORTANT): VerticalControl.kiDepthRateBuoy (reciprocal_second) 2019-12-13T20:31:30.500Z,1576269090.500 [CommandLine](IMPORTANT): VerticalControl.kpDepth (radian_per_meter) 2019-12-13T20:31:30.537Z,1576269090.537 [CommandLine](IMPORTANT): VerticalControl.kpDepthBuoy (ratio) 2019-12-13T20:31:30.538Z,1576269090.538 [CommandLine](IMPORTANT): VerticalControl.kpDepthRateBuoy (ratio) 2019-12-13T20:31:30.538Z,1576269090.538 [CommandLine](IMPORTANT): VerticalControl.limitDepthTrajectory (bool) 2019-12-13T20:31:30.539Z,1576269090.539 [CommandLine](IMPORTANT): VerticalControl.maxDepthInt (angular_degree) 2019-12-13T20:31:30.540Z,1576269090.540 [CommandLine](IMPORTANT): VerticalControl.minDepthExcursion (meter) 2019-12-13T20:31:30.540Z,1576269090.540 [CommandLine](IMPORTANT): VerticalControl.stopDepthExcursion (meter) 2019-12-13T20:31:30.540Z,1576269090.540 [CommandLine](IMPORTANT): VerticalControl.useElevIntInDepthMode (bool) 2019-12-13T20:31:30.542Z,1576269090.542 [CommandLine](IMPORTANT): BuoyancyServo.fastPumpDepth (meter) 2019-12-13T20:31:30.545Z,1576269090.545 [CommandLine](IMPORTANT): CBIT.stopDepth (meter) 2019-12-13T20:31:30.545Z,1576269090.545 [CommandLine](IMPORTANT): CBIT.abortDepth (meter) 2019-12-13T20:31:30.546Z,1576269090.546 [CommandLine](IMPORTANT): CBIT.abortDepthTimeout (second) 2019-12-13T20:31:30.562Z,1576269090.562 [CommandLine](IMPORTANT): Depth_Keller.loadControl (none) 2019-12-13T20:31:30.563Z,1576269090.563 [CommandLine](IMPORTANT): Depth_Keller.ad (none) 2019-12-13T20:31:30.563Z,1576269090.563 [CommandLine](IMPORTANT): Depth_Keller.adRes (bit) 2019-12-13T20:31:30.564Z,1576269090.564 [CommandLine](IMPORTANT): Depth_Keller.adTimeout (millisecond) 2019-12-13T20:31:30.564Z,1576269090.564 [CommandLine](IMPORTANT): Depth_Keller.adVref (volt) 2019-12-13T20:31:30.589Z,1576269090.589 [CommandLine](IMPORTANT): Config/workSite.beaconDepth (meter) 2019-12-13T20:31:30.600Z,1576269090.600 [CommandLine](IMPORTANT): Depth_Keller.loadAtStartup (bool) 2019-12-13T20:31:30.600Z,1576269090.600 [CommandLine](IMPORTANT): Depth_Keller.simulateHardware (bool) 2019-12-13T20:31:30.600Z,1576269090.600 [CommandLine](IMPORTANT): Depth_Keller.maxPressBound (decibar) 2019-12-13T20:31:30.605Z,1576269090.605 [CommandLine](IMPORTANT): Depth_Keller.minPressBound (decibar) 2019-12-13T20:31:30.605Z,1576269090.605 [CommandLine](IMPORTANT): Depth_Keller.offset (decibar) 2019-12-13T20:31:30.606Z,1576269090.606 [CommandLine](IMPORTANT): Depth_Keller.power (watt) 2019-12-13T20:31:30.606Z,1576269090.606 [CommandLine](IMPORTANT): Depth_Keller.scale (micropascal) 2019-12-13T20:31:30.662Z,1576269090.662 [CommandLine](IMPORTANT): DepthRateCalculator.loadAtStartup (bool) 2019-12-13T20:31:30.662Z,1576269090.662 [CommandLine](IMPORTANT): TempGradientCalculator.numConsecutiveDepths (count) 2019-12-13T20:31:30.663Z,1576269090.663 [CommandLine](IMPORTANT): VerticalTemperatureHomogeneityIndexCalculator.depth1 (meter) 2019-12-13T20:31:30.664Z,1576269090.664 [CommandLine](IMPORTANT): VerticalTemperatureHomogeneityIndexCalculator.depth2 (meter) 2019-12-13T20:31:30.664Z,1576269090.664 [CommandLine](IMPORTANT): VerticalTemperatureHomogeneityIndexCalculator.depth3 (meter) 2019-12-13T20:31:30.669Z,1576269090.669 [CommandLine](IMPORTANT): VerticalTemperatureHomogeneityIndexCalculator.depth4 (meter) 2019-12-13T20:31:30.669Z,1576269090.669 [CommandLine](IMPORTANT): VerticalTemperatureHomogeneityIndexCalculator.depthWindow (meter) 2019-12-13T20:31:30.672Z,1576269090.672 [CommandLine](IMPORTANT): VerticalControl.depthRateCmd (meter_per_second) 2019-12-13T20:31:30.677Z,1576269090.677 [CommandLine](IMPORTANT): VerticalControl.depth2buoyIntInternal (cubic_centimeter) 2019-12-13T20:31:30.677Z,1576269090.677 [CommandLine](IMPORTANT): VerticalControl.depthErrorInternal (meter) 2019-12-13T20:31:30.678Z,1576269090.678 [CommandLine](IMPORTANT): VerticalControl.depthIntegralInternal (radian) 2019-12-13T20:31:30.678Z,1576269090.678 [CommandLine](IMPORTANT): VerticalControl.smoothDepthInternal (meter) 2019-12-13T20:31:30.680Z,1576269090.680 [CommandLine](IMPORTANT): DeadReckonUsingMultipleVelocitySources.depth (meter) 2019-12-13T20:31:30.686Z,1576269090.686 [CommandLine](IMPORTANT): NavChart.sea_floor_depth_below_geoid (meter) 2019-12-13T20:31:30.688Z,1576269090.688 [CommandLine](IMPORTANT): Depth_Keller.depth (meter) 2019-12-13T20:31:30.688Z,1576269090.688 [CommandLine](IMPORTANT): Depth_Keller.sea_water_pressure (decibar) 2019-12-13T20:31:30.728Z,1576269090.728 [CommandLine](IMPORTANT): DepthRateCalculator.depth_rate (meter_per_second) 2019-12-13T20:31:30.737Z,1576269090.737 [CommandLine](IMPORTANT): TempGradientCalculator.thermoclineDepth (meter) 2019-12-13T20:31:30.738Z,1576269090.738 [CommandLine](IMPORTANT): TempGradientCalculator.targetDepth (meter) 2019-12-13T20:31:30.739Z,1576269090.739 [CommandLine](IMPORTANT): CTD_Seabird.depth (meter) 2019-12-13T20:31:30.762Z,1576269090.762 [CommandLine](IMPORTANT): CBIT.binnedDepthRate (meter_per_second) 2019-12-13T20:31:30.763Z,1576269090.763 [CommandLine](IMPORTANT): NavChartDb.closestDepth (meter) 2019-12-13T20:31:30.763Z,1576269090.763 [CommandLine](IMPORTANT): NavChartDb.nextDepth (meter) 2019-12-13T20:31:39.579Z,1576269099.579 [CommandLine](IMPORTANT): got command show variable abortde 2019-12-13T20:31:39.626Z,1576269099.626 [CommandLine](IMPORTANT): CBIT.abortDepth (meter) 2019-12-13T20:31:39.627Z,1576269099.627 [CommandLine](IMPORTANT): CBIT.abortDepthTimeout (second) 2019-12-13T20:31:40.030Z,1576269100.030 [DataOverHttps](INFO): Sending 526 bytes from file Logs/20191213T202210/Express0005.lzma 2019-12-13T20:31:42.034Z,1576269102.034 [DataOverHttps](INFO): Moved sent file to Logs/20191213T202210/Express0005.lzma.bak 2019-12-13T20:31:42.034Z,1576269102.034 [DataOverHttps](INFO): SBD MOMSN=12155896 2019-12-13T20:31:43.329Z,1576269103.329 [Default:CheckIn:Read_Iridium] Stopped 2019-12-13T20:31:43.329Z,1576269103.329 [Default:CheckIn:C.Wait] Running Loop=1 2019-12-13T20:31:43.329Z,1576269103.329 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-12-13T20:31:45.666Z,1576269105.666 [CommandLine](IMPORTANT): got command get CBIT.abortDepth 2019-12-13T20:31:45.666Z,1576269105.666 [CommandLine](IMPORTANT): CBIT.abortDepth 250.000000 m 2019-12-13T20:31:59.281Z,1576269119.281 [CommandLine](IMPORTANT): got command get CBIT.stopDepth 2019-12-13T20:31:59.281Z,1576269119.281 [CommandLine](IMPORTANT): CBIT.stopDepth 205.000000 m 2019-12-13T20:32:14.903Z,1576269134.903 [CommandLine](IMPORTANT): got command show variable buoya 2019-12-13T20:32:14.905Z,1576269134.905 [CommandLine](IMPORTANT): platform_buoyancy_position (cubic_centimeter) 2019-12-13T20:32:14.912Z,1576269134.912 [CommandLine](IMPORTANT): Config/Simulator.initBuoyancyPosition (cubic_centimeter) 2019-12-13T20:32:14.913Z,1576269134.913 [CommandLine](IMPORTANT): Config/Simulator.centerHystBuoyancy (cubic_centimeter) 2019-12-13T20:32:14.914Z,1576269134.914 [CommandLine](IMPORTANT): Config/Simulator.speedBuoyancy (cubic_centimeter_per_second) 2019-12-13T20:32:14.914Z,1576269134.914 [CommandLine](IMPORTANT): Config/Simulator.wideHystBuoyancy (cubic_centimeter) 2019-12-13T20:32:14.915Z,1576269134.915 [CommandLine](IMPORTANT): Config/Simulator.buoyancyNeutralOffset (cubic_centimeter) 2019-12-13T20:32:14.916Z,1576269134.916 [CommandLine](IMPORTANT): VerticalControl.buoyancyDefault (cubic_centimeter) 2019-12-13T20:32:14.916Z,1576269134.916 [CommandLine](IMPORTANT): VerticalControl.buoyancyLimitHiCC (cubic_centimeter) 2019-12-13T20:32:14.916Z,1576269134.916 [CommandLine](IMPORTANT): VerticalControl.buoyancyLimitLoCC (cubic_centimeter) 2019-12-13T20:32:14.917Z,1576269134.917 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral (cubic_centimeter) 2019-12-13T20:32:14.917Z,1576269134.917 [CommandLine](IMPORTANT): VerticalControl.buoyancyPumpDepth (meter) 2019-12-13T20:32:14.919Z,1576269134.919 [CommandLine](IMPORTANT): BuoyancyServo.loadAtStartup (bool) 2019-12-13T20:32:14.920Z,1576269134.920 [CommandLine](IMPORTANT): BuoyancyServo.simulateHardware (bool) 2019-12-13T20:32:14.920Z,1576269134.920 [CommandLine](IMPORTANT): BuoyancyServo.accel (none) 2019-12-13T20:32:14.920Z,1576269134.920 [CommandLine](IMPORTANT): BuoyancyServo.currLimit (percent) 2019-12-13T20:32:14.957Z,1576269134.957 [CommandLine](IMPORTANT): BuoyancyServo.limitHi (count) 2019-12-13T20:32:14.957Z,1576269134.957 [CommandLine](IMPORTANT): BuoyancyServo.limitLo (count) 2019-12-13T20:32:14.958Z,1576269134.958 [CommandLine](IMPORTANT): BuoyancyServo.overloadTimeout (millisecond) 2019-12-13T20:32:14.958Z,1576269134.958 [CommandLine](IMPORTANT): BuoyancyServo.pidW (count) 2019-12-13T20:32:14.958Z,1576269134.958 [CommandLine](IMPORTANT): BuoyancyServo.pidX (count) 2019-12-13T20:32:14.959Z,1576269134.959 [CommandLine](IMPORTANT): BuoyancyServo.pidY (count) 2019-12-13T20:32:14.959Z,1576269134.959 [CommandLine](IMPORTANT): BuoyancyServo.powerOffTimeout (second) 2019-12-13T20:32:14.959Z,1576269134.959 [CommandLine](IMPORTANT): BuoyancyServo.powerOnTimeout (second) 2019-12-13T20:32:14.960Z,1576269134.960 [CommandLine](IMPORTANT): BuoyancyServo.velocity (none) 2019-12-13T20:32:14.960Z,1576269134.960 [CommandLine](IMPORTANT): BuoyancyServo.checkingTimeout (minute) 2019-12-13T20:32:14.961Z,1576269134.961 [CommandLine](IMPORTANT): BuoyancyServo.countsPerCC (count_per_cubic_centimeter) 2019-12-13T20:32:14.961Z,1576269134.961 [CommandLine](IMPORTANT): BuoyancyServo.deviationVolume (cubic_centimeter) 2019-12-13T20:32:14.961Z,1576269134.961 [CommandLine](IMPORTANT): BuoyancyServo.fastPumpCoefficient (none) 2019-12-13T20:32:14.962Z,1576269134.962 [CommandLine](IMPORTANT): BuoyancyServo.fastPumpDepth (meter) 2019-12-13T20:32:14.962Z,1576269134.962 [CommandLine](IMPORTANT): BuoyancyServo.offsetVolume (cubic_centimeter) 2019-12-13T20:32:14.975Z,1576269134.975 [CommandLine](IMPORTANT): BuoyancyServo.loadControl (none) 2019-12-13T20:32:14.976Z,1576269134.976 [CommandLine](IMPORTANT): BuoyancyServo.uart (none) 2019-12-13T20:32:14.976Z,1576269134.976 [CommandLine](IMPORTANT): BuoyancyServo.baud (bit_per_second) 2019-12-13T20:32:15.067Z,1576269135.067 [CommandLine](IMPORTANT): VerticalControl.buoyancyAction (cubic_centimeter) 2019-12-13T20:32:15.068Z,1576269135.068 [CommandLine](IMPORTANT): BuoyancyServo.platform_buoyancy_position (cubic_centimeter) 2019-12-13T20:32:15.133Z,1576269135.133 [CommandLine](IMPORTANT): BuoyancyServo.component_voltage (volt) 2019-12-13T20:32:15.134Z,1576269135.134 [CommandLine](IMPORTANT): BuoyancyServo.component_avgVoltage (volt) 2019-12-13T20:32:15.134Z,1576269135.134 [CommandLine](IMPORTANT): BuoyancyServo.component_current (milliampere) 2019-12-13T20:32:15.135Z,1576269135.135 [CommandLine](IMPORTANT): BuoyancyServo.component_avgCurrent (milliampere) 2019-12-13T20:32:23.175Z,1576269143.175 [CommandLine](IMPORTANT): got command show variable buoyancyne 2019-12-13T20:32:23.186Z,1576269143.186 [CommandLine](IMPORTANT): Config/Simulator.buoyancyNeutralOffset (cubic_centimeter) 2019-12-13T20:32:23.187Z,1576269143.187 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral (cubic_centimeter) 2019-12-13T20:32:28.751Z,1576269148.751 [CommandLine](IMPORTANT): got command get VerticalControl.buoyancyNeutral 2019-12-13T20:32:28.751Z,1576269148.751 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral 338.000000 cc 2019-12-13T20:33:00.442Z,1576269180.442 [NAL9602](FAULT): GPS failed to acquire within timeout. 2019-12-13T20:33:00.442Z,1576269180.442 [NAL9602] Data Fault, FailCount= 1 2019-12-13T20:33:00.442Z,1576269180.442 [NAL9602](ERROR): Data Fault 2019-12-13T20:33:00.510Z,1576269180.510 [CBIT](ERROR): Data Fault in component: NAL9602 2019-12-13T20:33:00.849Z,1576269180.849 [NAL9602](INFO): Powering down 2019-12-13T20:33:01.698Z,1576269181.698 [CBIT](INFO): Clearing failed state for component NAL9602 2019-12-13T20:33:01.698Z,1576269181.698 [NAL9602] No Fault, FailCount= 1 2019-12-13T20:33:31.142Z,1576269211.142 [NAL9602](INFO): Powering up NAL9602 2019-12-13T20:33:35.099Z,1576269215.099 [CommandLine](IMPORTANT): got command show variable massd 2019-12-13T20:33:35.125Z,1576269215.125 [CommandLine](IMPORTANT): VerticalControl.massDeadband (millimeter) 2019-12-13T20:33:35.126Z,1576269215.126 [CommandLine](IMPORTANT): VerticalControl.massDefault (centimeter) 2019-12-13T20:33:40.683Z,1576269220.683 [CommandLine](IMPORTANT): got command get VerticalControl.massDefault 2019-12-13T20:33:40.684Z,1576269220.684 [CommandLine](IMPORTANT): VerticalControl.massDefault -0.900000 cm 2019-12-13T20:33:42.054Z,1576269222.054 [NAL9602](INFO): NAL9602 initialized 2019-12-13T20:34:01.291Z,1576269241.291 [CommandLine](IMPORTANT): got command get VerticalControl.massPositionLimitAft 2019-12-13T20:34:01.291Z,1576269241.291 [CommandLine](IMPORTANT): VerticalControl.massPositionLimitAft -35.000000 mm 2019-12-13T20:34:08.834Z,1576269248.834 [CommandLine](IMPORTANT): got command get VerticalControl.massPositionLimitFwd 2019-12-13T20:34:08.835Z,1576269248.835 [CommandLine](IMPORTANT): VerticalControl.massPositionLimitFwd 25.000000 mm 2019-12-13T20:34:24.524Z,1576269264.524 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4 2019-12-13T20:34:24.524Z,1576269264.524 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-12-13T20:34:24.534Z,1576269264.534 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-12-13T20:34:24.918Z,1576269264.918 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-12-13T20:34:24.918Z,1576269264.918 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4 2019-12-13T20:36:43.910Z,1576269403.910 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-12-13T20:36:43.910Z,1576269403.910 [Default:CheckIn:C.Wait] Stopped 2019-12-13T20:36:43.910Z,1576269403.910 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-12-13T20:36:43.910Z,1576269403.910 [Default:CheckIn:D] Running Loop=1 2019-12-13T20:36:44.323Z,1576269404.323 [Default:CheckIn:D] Stopped 2019-12-13T20:36:44.323Z,1576269404.323 [Default:CheckIn:E] Running Loop=1 2019-12-13T20:36:44.715Z,1576269404.715 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.740064 min 2019-12-13T20:36:44.715Z,1576269404.715 [Default:CheckIn:E] Stopped 2019-12-13T20:36:44.715Z,1576269404.715 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-12-13T20:36:44.715Z,1576269404.715 [Default:CheckIn] Stopped 2019-12-13T20:36:44.716Z,1576269404.716 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-12-13T20:36:44.716Z,1576269404.716 [Default:CheckIn](INFO): Running loop #2 2019-12-13T20:36:44.716Z,1576269404.716 [Default:CheckIn] Running Loop=2 2019-12-13T20:36:44.716Z,1576269404.716 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-12-13T20:36:44.716Z,1576269404.716 [Default:CheckIn:Read_GPS] Running Loop=1 2019-12-13T20:37:25.514Z,1576269445.514 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5 2019-12-13T20:37:25.514Z,1576269445.514 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-12-13T20:37:25.523Z,1576269445.523 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-12-13T20:37:25.930Z,1576269445.930 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-12-13T20:37:25.930Z,1576269445.930 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5 2019-12-13T20:40:26.512Z,1576269626.512 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6 2019-12-13T20:40:26.512Z,1576269626.512 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-12-13T20:40:26.521Z,1576269626.521 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-12-13T20:40:26.923Z,1576269626.923 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-12-13T20:40:26.923Z,1576269626.923 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6 2019-12-13T20:41:44.894Z,1576269704.894 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-12-13T20:36:44.7Z 2019-12-13T20:41:44.894Z,1576269704.894 [Default:CheckIn:Read_GPS] Stopped 2019-12-13T20:41:44.894Z,1576269704.894 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-12-13T20:41:51.812Z,1576269711.812 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20191213T202210/Courier0007.lzma 2019-12-13T20:41:53.818Z,1576269713.818 [DataOverHttps](INFO): Moved sent file to Logs/20191213T202210/Courier0007.lzma.bak 2019-12-13T20:41:53.818Z,1576269713.818 [DataOverHttps](INFO): SBD MOMSN=12155926 2019-12-13T20:42:10.364Z,1576269730.364 [DataOverHttps](INFO): Sending 2245 bytes from file Logs/20191213T202210/Express0008.lzma 2019-12-13T20:42:12.366Z,1576269732.366 [DataOverHttps](INFO): Moved sent file to Logs/20191213T202210/Express0008.lzma.bak 2019-12-13T20:42:12.367Z,1576269732.367 [DataOverHttps](INFO): SBD MOMSN=12155928 2019-12-13T20:42:13.563Z,1576269733.563 [Default:CheckIn:Read_Iridium] Stopped 2019-12-13T20:42:13.563Z,1576269733.563 [Default:CheckIn:C.Wait] Running Loop=1 2019-12-13T20:42:13.563Z,1576269733.563 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-12-13T20:43:27.510Z,1576269807.510 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7 2019-12-13T20:43:27.510Z,1576269807.510 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-12-13T20:43:27.520Z,1576269807.520 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-12-13T20:43:27.917Z,1576269807.917 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-12-13T20:43:27.917Z,1576269807.917 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7 2019-12-13T20:43:36.955Z,1576269816.955 [CommandLine](IMPORTANT): got command maintain control VerticalControl.buoyancyAction 200.000000 cubic_centimeter 2019-12-13T20:43:36.957Z,1576269816.957 [ComponentRegistry](DEBUG): SyncComponent "Maintain_VerticalControl.buoyancyAction" handled in the control thread. 2019-12-13T20:43:37.223Z,1576269817.223 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,NAL9602,Onboard,BPC1,CANONSampler,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-13T20:43:43.218Z,1576269823.218 [NAL9602](FAULT): GPS failed to acquire within timeout. 2019-12-13T20:43:43.218Z,1576269823.218 [NAL9602] Data Fault, FailCount= 2 2019-12-13T20:43:43.218Z,1576269823.218 [NAL9602](ERROR): Data Fault 2019-12-13T20:43:43.326Z,1576269823.326 [CBIT](ERROR): Data Fault in component: NAL9602 2019-12-13T20:43:43.642Z,1576269823.642 [NAL9602](INFO): Powering down 2019-12-13T20:43:44.494Z,1576269824.494 [CBIT](INFO): Clearing failed state for component NAL9602 2019-12-13T20:43:44.494Z,1576269824.494 [NAL9602] No Fault, FailCount= 2 2019-12-13T20:43:46.722Z,1576269826.722 [CommandLine](IMPORTANT): got command report mod platform_buoyancy_position 2019-12-13T20:43:46.958Z,1576269826.958 [Reporter](INFO): platform_buoyancy_position 894.159363 cc 2019-12-13T20:43:47.358Z,1576269827.358 [Reporter](INFO): platform_buoyancy_position 887.847229 cc 2019-12-13T20:43:47.743Z,1576269827.743 [Reporter](INFO): platform_buoyancy_position 883.415344 cc 2019-12-13T20:43:48.183Z,1576269828.183 [Reporter](INFO): platform_buoyancy_position 877.103271 cc 2019-12-13T20:43:48.569Z,1576269828.569 [Reporter](INFO): platform_buoyancy_position 872.671326 cc 2019-12-13T20:43:48.971Z,1576269828.971 [Reporter](INFO): platform_buoyancy_position 868.239441 cc 2019-12-13T20:43:49.394Z,1576269829.394 [Reporter](INFO): platform_buoyancy_position 862.867432 cc 2019-12-13T20:43:49.791Z,1576269829.791 [Reporter](INFO): platform_buoyancy_position 857.764038 cc 2019-12-13T20:43:50.171Z,1576269830.171 [Reporter](INFO): platform_buoyancy_position 852.257751 cc 2019-12-13T20:43:50.554Z,1576269830.554 [Reporter](INFO): platform_buoyancy_position 847.020020 cc 2019-12-13T20:43:50.971Z,1576269830.971 [Reporter](INFO): platform_buoyancy_position 840.573669 cc 2019-12-13T20:43:51.379Z,1576269831.379 [Reporter](INFO): platform_buoyancy_position 836.141724 cc 2019-12-13T20:43:51.775Z,1576269831.775 [Reporter](INFO): platform_buoyancy_position 829.963928 cc 2019-12-13T20:43:52.167Z,1576269832.167 [Reporter](INFO): platform_buoyancy_position 825.532043 cc 2019-12-13T20:43:52.587Z,1576269832.587 [Reporter](INFO): platform_buoyancy_position 820.965820 cc 2019-12-13T20:43:52.998Z,1576269832.998 [Reporter](INFO): platform_buoyancy_position 814.788025 cc 2019-12-13T20:43:53.410Z,1576269833.410 [Reporter](INFO): platform_buoyancy_position 810.087524 cc 2019-12-13T20:43:53.791Z,1576269833.791 [Reporter](INFO): platform_buoyancy_position 803.909729 cc 2019-12-13T20:43:54.195Z,1576269834.195 [Reporter](INFO): platform_buoyancy_position 799.612122 cc 2019-12-13T20:43:54.615Z,1576269834.615 [Reporter](INFO): platform_buoyancy_position 793.165710 cc 2019-12-13T20:43:55.025Z,1576269835.025 [Reporter](INFO): platform_buoyancy_position 788.868164 cc 2019-12-13T20:43:55.399Z,1576269835.399 [Reporter](INFO): platform_buoyancy_position 782.421753 cc 2019-12-13T20:43:55.815Z,1576269835.815 [Reporter](INFO): platform_buoyancy_position 778.124146 cc 2019-12-13T20:43:56.230Z,1576269836.230 [Reporter](INFO): platform_buoyancy_position 771.812012 cc 2019-12-13T20:43:56.640Z,1576269836.640 [Reporter](INFO): platform_buoyancy_position 767.380127 cc 2019-12-13T20:43:57.025Z,1576269837.025 [Reporter](INFO): platform_buoyancy_position 762.813965 cc 2019-12-13T20:43:57.435Z,1576269837.435 [Reporter](INFO): platform_buoyancy_position 756.770447 cc 2019-12-13T20:43:57.831Z,1576269837.831 [Reporter](INFO): platform_buoyancy_position 752.338562 cc 2019-12-13T20:43:58.257Z,1576269838.257 [Reporter](INFO): platform_buoyancy_position 746.026428 cc 2019-12-13T20:43:58.635Z,1576269838.635 [Reporter](INFO): platform_buoyancy_position 741.460205 cc 2019-12-13T20:43:59.050Z,1576269839.050 [Reporter](INFO): platform_buoyancy_position 735.282410 cc 2019-12-13T20:43:59.446Z,1576269839.446 [Reporter](INFO): platform_buoyancy_position 730.850525 cc 2019-12-13T20:43:59.859Z,1576269839.859 [Reporter](INFO): platform_buoyancy_position 724.404114 cc 2019-12-13T20:44:00.251Z,1576269840.251 [Reporter](INFO): platform_buoyancy_position 720.106506 cc 2019-12-13T20:44:00.671Z,1576269840.671 [Reporter](INFO): platform_buoyancy_position 713.928711 cc 2019-12-13T20:44:01.063Z,1576269841.063 [Reporter](INFO): platform_buoyancy_position 709.362549 cc 2019-12-13T20:44:01.489Z,1576269841.489 [Reporter](INFO): platform_buoyancy_position 702.916138 cc 2019-12-13T20:44:01.871Z,1576269841.871 [Reporter](INFO): platform_buoyancy_position 698.618530 cc 2019-12-13T20:44:02.275Z,1576269842.275 [Reporter](INFO): platform_buoyancy_position 692.440735 cc 2019-12-13T20:44:02.679Z,1576269842.679 [Reporter](INFO): platform_buoyancy_position 688.008850 cc 2019-12-13T20:44:03.108Z,1576269843.108 [Reporter](INFO): platform_buoyancy_position 681.562439 cc 2019-12-13T20:44:03.483Z,1576269843.483 [Reporter](INFO): platform_buoyancy_position 677.130554 cc 2019-12-13T20:44:03.895Z,1576269843.895 [Reporter](INFO): platform_buoyancy_position 672.564331 cc 2019-12-13T20:44:04.295Z,1576269844.295 [Reporter](INFO): platform_buoyancy_position 666.520813 cc 2019-12-13T20:44:04.707Z,1576269844.707 [Reporter](INFO): platform_buoyancy_position 662.088928 cc 2019-12-13T20:44:05.099Z,1576269845.099 [Reporter](INFO): platform_buoyancy_position 655.776855 cc 2019-12-13T20:44:05.515Z,1576269845.515 [Reporter](INFO): platform_buoyancy_position 651.210632 cc 2019-12-13T20:44:05.934Z,1576269845.934 [Reporter](INFO): platform_buoyancy_position 645.032837 cc 2019-12-13T20:44:06.303Z,1576269846.303 [Reporter](INFO): platform_buoyancy_position 640.600952 cc 2019-12-13T20:44:06.721Z,1576269846.721 [Reporter](INFO): platform_buoyancy_position 634.288818 cc 2019-12-13T20:44:07.127Z,1576269847.127 [Reporter](INFO): platform_buoyancy_position 629.856934 cc 2019-12-13T20:44:07.527Z,1576269847.527 [Reporter](INFO): platform_buoyancy_position 623.410522 cc 2019-12-13T20:44:07.952Z,1576269847.952 [Reporter](INFO): platform_buoyancy_position 619.112915 cc 2019-12-13T20:44:08.331Z,1576269848.331 [Reporter](INFO): platform_buoyancy_position 612.935120 cc 2019-12-13T20:44:08.743Z,1576269848.743 [Reporter](INFO): platform_buoyancy_position 608.368896 cc 2019-12-13T20:44:09.142Z,1576269849.142 [Reporter](INFO): platform_buoyancy_position 602.056824 cc 2019-12-13T20:44:09.570Z,1576269849.570 [Reporter](INFO): platform_buoyancy_position 597.624939 cc 2019-12-13T20:44:09.947Z,1576269849.947 [Reporter](INFO): platform_buoyancy_position 593.193054 cc 2019-12-13T20:44:10.359Z,1576269850.359 [Reporter](INFO): platform_buoyancy_position 588.761108 cc 2019-12-13T20:44:10.770Z,1576269850.770 [Reporter](INFO): platform_buoyancy_position 582.583313 cc 2019-12-13T20:44:11.184Z,1576269851.184 [Reporter](INFO): platform_buoyancy_position 576.136902 cc 2019-12-13T20:44:11.562Z,1576269851.562 [Reporter](INFO): platform_buoyancy_position 571.839294 cc 2019-12-13T20:44:11.972Z,1576269851.972 [Reporter](INFO): platform_buoyancy_position 565.392944 cc 2019-12-13T20:44:12.390Z,1576269852.390 [Reporter](INFO): platform_buoyancy_position 561.095337 cc 2019-12-13T20:44:12.802Z,1576269852.802 [Reporter](INFO): platform_buoyancy_position 554.648926 cc 2019-12-13T20:44:13.175Z,1576269853.175 [Reporter](INFO): platform_buoyancy_position 550.351318 cc 2019-12-13T20:44:13.591Z,1576269853.591 [Reporter](INFO): platform_buoyancy_position 543.904907 cc 2019-12-13T20:44:13.922Z,1576269853.922 [NAL9602](INFO): Powering up NAL9602 2019-12-13T20:44:14.009Z,1576269854.009 [Reporter](INFO): platform_buoyancy_position 539.607300 cc 2019-12-13T20:44:14.410Z,1576269854.410 [Reporter](INFO): platform_buoyancy_position 533.295227 cc 2019-12-13T20:44:14.791Z,1576269854.791 [Reporter](INFO): platform_buoyancy_position 528.997620 cc 2019-12-13T20:44:15.210Z,1576269855.210 [Reporter](INFO): platform_buoyancy_position 522.551208 cc 2019-12-13T20:44:15.619Z,1576269855.619 [Reporter](INFO): platform_buoyancy_position 518.253601 cc 2019-12-13T20:44:16.015Z,1576269856.015 [Reporter](INFO): platform_buoyancy_position 512.747314 cc 2019-12-13T20:44:16.407Z,1576269856.407 [Reporter](INFO): platform_buoyancy_position 507.509674 cc 2019-12-13T20:44:16.827Z,1576269856.827 [Reporter](INFO): platform_buoyancy_position 503.077759 cc 2019-12-13T20:44:17.263Z,1576269857.263 [Reporter](INFO): platform_buoyancy_position 496.631378 cc 2019-12-13T20:44:17.649Z,1576269857.649 [Reporter](INFO): platform_buoyancy_position 492.333771 cc 2019-12-13T20:44:18.070Z,1576269858.070 [Reporter](INFO): platform_buoyancy_position 485.887360 cc 2019-12-13T20:44:18.451Z,1576269858.451 [Reporter](INFO): platform_buoyancy_position 481.724030 cc 2019-12-13T20:44:18.899Z,1576269858.899 [Reporter](INFO): platform_buoyancy_position 475.277618 cc 2019-12-13T20:44:19.270Z,1576269859.270 [Reporter](INFO): platform_buoyancy_position 470.845734 cc 2019-12-13T20:44:19.683Z,1576269859.683 [Reporter](INFO): platform_buoyancy_position 464.533661 cc 2019-12-13T20:44:20.063Z,1576269860.063 [Reporter](INFO): platform_buoyancy_position 460.236053 cc 2019-12-13T20:44:20.475Z,1576269860.475 [Reporter](INFO): platform_buoyancy_position 455.804169 cc 2019-12-13T20:44:20.863Z,1576269860.863 [Reporter](INFO): platform_buoyancy_position 451.506561 cc 2019-12-13T20:44:21.255Z,1576269861.255 [Reporter](INFO): platform_buoyancy_position 445.194427 cc 2019-12-13T20:44:21.671Z,1576269861.671 [Reporter](INFO): platform_buoyancy_position 438.882355 cc 2019-12-13T20:44:22.086Z,1576269862.086 [Reporter](INFO): platform_buoyancy_position 434.316132 cc 2019-12-13T20:44:22.492Z,1576269862.492 [Reporter](INFO): platform_buoyancy_position 428.004059 cc 2019-12-13T20:44:22.875Z,1576269862.875 [Reporter](INFO): platform_buoyancy_position 423.572113 cc 2019-12-13T20:44:23.279Z,1576269863.279 [Reporter](INFO): platform_buoyancy_position 417.260040 cc 2019-12-13T20:44:23.703Z,1576269863.703 [Reporter](INFO): platform_buoyancy_position 412.962433 cc 2019-12-13T20:44:24.107Z,1576269864.107 [Reporter](INFO): platform_buoyancy_position 407.590454 cc 2019-12-13T20:44:24.523Z,1576269864.523 [Reporter](INFO): platform_buoyancy_position 402.084137 cc 2019-12-13T20:44:24.842Z,1576269864.842 [NAL9602](INFO): NAL9602 initialized 2019-12-13T20:44:24.910Z,1576269864.910 [Reporter](INFO): platform_buoyancy_position 397.517944 cc 2019-12-13T20:44:25.310Z,1576269865.310 [Reporter](INFO): platform_buoyancy_position 391.474426 cc 2019-12-13T20:44:25.731Z,1576269865.731 [Reporter](INFO): platform_buoyancy_position 386.773926 cc 2019-12-13T20:44:26.131Z,1576269866.131 [Reporter](INFO): platform_buoyancy_position 380.596130 cc 2019-12-13T20:44:26.519Z,1576269866.519 [Reporter](INFO): platform_buoyancy_position 376.298553 cc 2019-12-13T20:44:26.926Z,1576269866.926 [Reporter](INFO): platform_buoyancy_position 369.986450 cc 2019-12-13T20:44:27.336Z,1576269867.336 [Reporter](INFO): platform_buoyancy_position 365.285950 cc 2019-12-13T20:44:27.757Z,1576269867.757 [Reporter](INFO): platform_buoyancy_position 359.108124 cc 2019-12-13T20:44:28.139Z,1576269868.139 [Reporter](INFO): platform_buoyancy_position 354.810547 cc 2019-12-13T20:44:28.551Z,1576269868.551 [Reporter](INFO): platform_buoyancy_position 348.364136 cc 2019-12-13T20:44:28.956Z,1576269868.956 [Reporter](INFO): platform_buoyancy_position 344.066528 cc 2019-12-13T20:44:29.372Z,1576269869.372 [Reporter](INFO): platform_buoyancy_position 337.888733 cc 2019-12-13T20:44:29.747Z,1576269869.747 [Reporter](INFO): platform_buoyancy_position 333.322540 cc 2019-12-13T20:44:30.166Z,1576269870.166 [Reporter](INFO): platform_buoyancy_position 329.024933 cc 2019-12-13T20:44:30.575Z,1576269870.575 [Reporter](INFO): platform_buoyancy_position 322.578522 cc 2019-12-13T20:44:30.987Z,1576269870.987 [Reporter](INFO): platform_buoyancy_position 318.146637 cc 2019-12-13T20:44:31.376Z,1576269871.376 [Reporter](INFO): platform_buoyancy_position 313.311829 cc 2019-12-13T20:44:31.782Z,1576269871.782 [Reporter](INFO): platform_buoyancy_position 307.536926 cc 2019-12-13T20:44:32.178Z,1576269872.178 [Reporter](INFO): platform_buoyancy_position 301.090546 cc 2019-12-13T20:44:32.567Z,1576269872.567 [Reporter](INFO): platform_buoyancy_position 296.792938 cc 2019-12-13T20:44:32.983Z,1576269872.983 [Reporter](INFO): platform_buoyancy_position 290.480835 cc 2019-12-13T20:44:33.398Z,1576269873.398 [Reporter](INFO): platform_buoyancy_position 286.048920 cc 2019-12-13T20:44:33.815Z,1576269873.815 [Reporter](INFO): platform_buoyancy_position 279.736847 cc 2019-12-13T20:44:34.227Z,1576269874.227 [Reporter](INFO): platform_buoyancy_position 275.304932 cc 2019-12-13T20:44:34.631Z,1576269874.631 [Reporter](INFO): platform_buoyancy_position 268.858521 cc 2019-12-13T20:44:35.010Z,1576269875.010 [Reporter](INFO): platform_buoyancy_position 264.560944 cc 2019-12-13T20:44:35.426Z,1576269875.426 [Reporter](INFO): platform_buoyancy_position 258.248840 cc 2019-12-13T20:44:35.799Z,1576269875.799 [Reporter](INFO): platform_buoyancy_position 253.816925 cc 2019-12-13T20:44:36.219Z,1576269876.219 [Reporter](INFO): platform_buoyancy_position 248.444901 cc 2019-12-13T20:44:36.627Z,1576269876.627 [Reporter](INFO): platform_buoyancy_position 243.072937 cc 2019-12-13T20:44:37.050Z,1576269877.050 [Reporter](INFO): platform_buoyancy_position 238.238129 cc 2019-12-13T20:44:37.451Z,1576269877.451 [Reporter](INFO): platform_buoyancy_position 232.463226 cc 2019-12-13T20:44:37.879Z,1576269877.879 [Reporter](INFO): platform_buoyancy_position 226.016815 cc 2019-12-13T20:44:38.247Z,1576269878.247 [Reporter](INFO): platform_buoyancy_position 221.719238 cc 2019-12-13T20:44:38.667Z,1576269878.667 [Reporter](INFO): platform_buoyancy_position 215.272827 cc 2019-12-13T20:44:39.047Z,1576269879.047 [Reporter](INFO): platform_buoyancy_position 210.975220 cc 2019-12-13T20:44:39.523Z,1576269879.523 [Reporter](INFO): platform_buoyancy_position 206.543335 cc 2019-12-13T20:46:28.522Z,1576269988.522 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 8 2019-12-13T20:46:28.522Z,1576269988.522 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-12-13T20:46:28.532Z,1576269988.532 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-12-13T20:46:28.947Z,1576269988.947 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-12-13T20:46:28.947Z,1576269988.947 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 8 2019-12-13T20:47:14.204Z,1576270034.204 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-12-13T20:47:14.204Z,1576270034.204 [Default:CheckIn:C.Wait] Stopped 2019-12-13T20:47:14.204Z,1576270034.204 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-12-13T20:47:14.204Z,1576270034.204 [Default:CheckIn:D] Running Loop=1 2019-12-13T20:47:14.603Z,1576270034.603 [Default:CheckIn:D] Stopped 2019-12-13T20:47:14.603Z,1576270034.603 [Default:CheckIn:E] Running Loop=1 2019-12-13T20:47:14.994Z,1576270034.994 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 21.244731 min 2019-12-13T20:47:14.994Z,1576270034.994 [Default:CheckIn:E] Stopped 2019-12-13T20:47:14.994Z,1576270034.994 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-12-13T20:47:14.994Z,1576270034.994 [Default:CheckIn] Stopped 2019-12-13T20:47:14.994Z,1576270034.994 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-12-13T20:47:14.994Z,1576270034.994 [Default:CheckIn](INFO): Running loop #3 2019-12-13T20:47:14.994Z,1576270034.994 [Default:CheckIn] Running Loop=3 2019-12-13T20:47:14.995Z,1576270034.995 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-12-13T20:47:14.995Z,1576270034.995 [Default:CheckIn:Read_GPS] Running Loop=1 2019-12-13T20:49:29.531Z,1576270169.531 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 9 2019-12-13T20:49:29.531Z,1576270169.531 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-12-13T20:49:29.542Z,1576270169.542 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-12-13T20:49:29.959Z,1576270169.959 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-12-13T20:49:29.959Z,1576270169.959 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 9 2019-12-13T20:52:15.183Z,1576270335.183 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-12-13T20:47:14.0Z 2019-12-13T20:52:15.183Z,1576270335.183 [Default:CheckIn:Read_GPS] Stopped 2019-12-13T20:52:15.183Z,1576270335.183 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-12-13T20:52:22.776Z,1576270342.776 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20191213T202210/Courier0010.lzma 2019-12-13T20:52:24.782Z,1576270344.782 [DataOverHttps](INFO): Moved sent file to Logs/20191213T202210/Courier0010.lzma.bak 2019-12-13T20:52:24.782Z,1576270344.782 [DataOverHttps](INFO): SBD MOMSN=12156179 2019-12-13T20:52:30.549Z,1576270350.549 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 10 2019-12-13T20:52:30.549Z,1576270350.549 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-12-13T20:52:30.570Z,1576270350.570 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-12-13T20:52:30.974Z,1576270350.974 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-12-13T20:52:30.974Z,1576270350.974 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 10 2019-12-13T20:52:41.901Z,1576270361.901 [DataOverHttps](INFO): Sending 242 bytes from file Logs/20191213T202210/Express0011.lzma 2019-12-13T20:52:43.906Z,1576270363.906 [DataOverHttps](INFO): Moved sent file to Logs/20191213T202210/Express0011.lzma.bak 2019-12-13T20:52:43.906Z,1576270363.906 [DataOverHttps](INFO): SBD MOMSN=12156181 2019-12-13T20:52:45.101Z,1576270365.101 [Default:CheckIn:Read_Iridium] Stopped 2019-12-13T20:52:45.102Z,1576270365.102 [Default:CheckIn:C.Wait] Running Loop=1 2019-12-13T20:52:45.102Z,1576270365.102 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-12-13T20:54:27.270Z,1576270467.270 [NAL9602](FAULT): GPS failed to acquire within timeout. 2019-12-13T20:54:27.270Z,1576270467.270 [NAL9602] Data Fault, FailCount= 3 2019-12-13T20:54:27.270Z,1576270467.270 [NAL9602](ERROR): Data Fault 2019-12-13T20:54:27.366Z,1576270467.366 [CBIT](ERROR): Data Fault in component: NAL9602 2019-12-13T20:54:27.674Z,1576270467.674 [NAL9602](INFO): Powering down 2019-12-13T20:54:28.519Z,1576270468.519 [CBIT](INFO): Clearing failed state for component NAL9602 2019-12-13T20:54:28.520Z,1576270468.520 [NAL9602] No Fault, FailCount= 3 2019-12-13T20:54:57.974Z,1576270497.974 [NAL9602](INFO): Powering up NAL9602 2019-12-13T20:55:08.878Z,1576270508.878 [NAL9602](INFO): NAL9602 initialized 2019-12-13T20:55:31.535Z,1576270531.535 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 11 2019-12-13T20:55:31.535Z,1576270531.535 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-12-13T20:55:31.545Z,1576270531.545 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-12-13T20:55:31.951Z,1576270531.951 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-12-13T20:55:31.952Z,1576270531.952 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 11 2019-12-13T20:57:45.696Z,1576270665.696 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-12-13T20:57:45.696Z,1576270665.696 [Default:CheckIn:C.Wait] Stopped 2019-12-13T20:57:45.696Z,1576270665.696 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-12-13T20:57:45.696Z,1576270665.696 [Default:CheckIn:D] Running Loop=1 2019-12-13T20:57:46.112Z,1576270666.112 [Default:CheckIn:D] Stopped 2019-12-13T20:57:46.112Z,1576270666.112 [Default:CheckIn:E] Running Loop=1 2019-12-13T20:57:46.492Z,1576270666.492 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 31.769875 min 2019-12-13T20:57:46.492Z,1576270666.492 [Default:CheckIn:E] Stopped 2019-12-13T20:57:46.493Z,1576270666.493 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-12-13T20:57:46.493Z,1576270666.493 [Default:CheckIn] Stopped 2019-12-13T20:57:46.493Z,1576270666.493 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-12-13T20:57:46.493Z,1576270666.493 [Default:CheckIn](INFO): Running loop #4 2019-12-13T20:57:46.493Z,1576270666.493 [Default:CheckIn] Running Loop=4 2019-12-13T20:57:46.493Z,1576270666.493 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-12-13T20:57:46.493Z,1576270666.493 [Default:CheckIn:Read_GPS] Running Loop=1 2019-12-13T20:58:32.578Z,1576270712.578 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 12 2019-12-13T20:58:32.578Z,1576270712.578 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-12-13T20:58:32.588Z,1576270712.588 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-12-13T20:58:32.999Z,1576270712.999 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-12-13T20:58:32.999Z,1576270712.999 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 12 2019-12-13T20:59:35.552Z,1576270775.552 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,205932.00,A,3648.14276,N,12147.22863,W,0.039,131.42,131219,,,A*76 2019-12-13T20:59:35.556Z,1576270775.556 [NAL9602](INFO): GPS fix at 20191213T205932: (36.802379, -121.787144) 2019-12-13T20:59:35.621Z,1576270775.621 [Default:CheckIn:Read_GPS] Stopped 2019-12-13T20:59:35.621Z,1576270775.621 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-12-13T20:59:45.105Z,1576270785.105 [DataOverHttps](INFO): Sending 212 bytes from file Logs/20191213T202210/Courier0013.lzma 2019-12-13T20:59:47.110Z,1576270787.110 [DataOverHttps](INFO): Moved sent file to Logs/20191213T202210/Courier0013.lzma.bak 2019-12-13T20:59:47.110Z,1576270787.110 [DataOverHttps](INFO): SBD MOMSN=12156199 2019-12-13T21:00:05.321Z,1576270805.321 [DataOverHttps](INFO): Sending 272 bytes from file Logs/20191213T202210/Express0014.lzma 2019-12-13T21:00:07.350Z,1576270807.350 [DataOverHttps](INFO): Moved sent file to Logs/20191213T202210/Express0014.lzma.bak 2019-12-13T21:00:07.350Z,1576270807.350 [DataOverHttps](INFO): SBD MOMSN=12156203 2019-12-13T21:00:07.875Z,1576270807.875 [NAL9602](INFO): Not Powering down - fast GPS 2019-12-13T21:00:08.709Z,1576270808.709 [Default:CheckIn:Read_Iridium] Stopped 2019-12-13T21:00:08.709Z,1576270808.709 [Default:CheckIn:C.Wait] Running Loop=1 2019-12-13T21:00:08.709Z,1576270808.709 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-12-13T21:05:09.288Z,1576271109.288 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-12-13T21:05:09.289Z,1576271109.289 [Default:CheckIn:C.Wait] Stopped 2019-12-13T21:05:09.289Z,1576271109.289 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-12-13T21:05:09.289Z,1576271109.289 [Default:CheckIn:D] Running Loop=1 2019-12-13T21:05:09.689Z,1576271109.689 [Default:CheckIn:D] Stopped 2019-12-13T21:05:09.689Z,1576271109.689 [Default:CheckIn:E] Running Loop=1 2019-12-13T21:05:10.103Z,1576271110.103 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 39.162830 min 2019-12-13T21:05:10.103Z,1576271110.103 [Default:CheckIn:E] Stopped 2019-12-13T21:05:10.104Z,1576271110.104 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-12-13T21:05:10.104Z,1576271110.104 [Default:CheckIn] Stopped 2019-12-13T21:05:10.104Z,1576271110.104 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-12-13T21:05:10.104Z,1576271110.104 [Default:CheckIn](INFO): Running loop #5 2019-12-13T21:05:10.104Z,1576271110.104 [Default:CheckIn] Running Loop=5 2019-12-13T21:05:10.104Z,1576271110.104 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-12-13T21:05:10.104Z,1576271110.104 [Default:CheckIn:Read_GPS] Running Loop=1 2019-12-13T21:05:12.089Z,1576271112.089 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,210508.00,A,3648.14205,N,12147.22734,W,0.019,131.42,131219,,,D*79 2019-12-13T21:05:12.091Z,1576271112.091 [NAL9602](INFO): GPS fix at 20191213T210508: (36.802368, -121.787122) 2019-12-13T21:05:12.142Z,1576271112.142 [Default:CheckIn:Read_GPS] Stopped 2019-12-13T21:05:12.142Z,1576271112.142 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-12-13T21:05:19.360Z,1576271119.360 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20191213T202210/Courier0016.lzma 2019-12-13T21:05:21.366Z,1576271121.366 [DataOverHttps](INFO): Moved sent file to Logs/20191213T202210/Courier0016.lzma.bak 2019-12-13T21:05:21.366Z,1576271121.366 [DataOverHttps](INFO): SBD MOMSN=12156215 2019-12-13T21:05:36.740Z,1576271136.740 [NAL9602](INFO): SBD MO Status=0, MOMSN=18037, MT Status=0, MTMSN=0 2019-12-13T21:05:36.740Z,1576271136.740 [NAL9602](INFO): No messages in MT queue 2019-12-13T21:05:38.416Z,1576271138.416 [DataOverHttps](INFO): Sending 121 bytes from file Logs/20191213T202210/Express0017.lzma 2019-12-13T21:05:40.422Z,1576271140.422 [DataOverHttps](INFO): Moved sent file to Logs/20191213T202210/Express0017.lzma.bak 2019-12-13T21:05:40.423Z,1576271140.423 [DataOverHttps](INFO): SBD MOMSN=12156218 2019-12-13T21:05:41.625Z,1576271141.625 [Default:CheckIn:Read_Iridium] Stopped 2019-12-13T21:05:41.625Z,1576271141.625 [Default:CheckIn:C.Wait] Running Loop=1 2019-12-13T21:05:41.625Z,1576271141.625 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-12-13T21:06:07.442Z,1576271167.442 [NAL9602](INFO): Not Powering down - fast GPS 2019-12-13T21:10:42.206Z,1576271442.206 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-12-13T21:10:42.206Z,1576271442.206 [Default:CheckIn:C.Wait] Stopped 2019-12-13T21:10:42.206Z,1576271442.206 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-12-13T21:10:42.206Z,1576271442.206 [Default:CheckIn:D] Running Loop=1 2019-12-13T21:10:42.615Z,1576271442.615 [Default:CheckIn:D] Stopped 2019-12-13T21:10:42.615Z,1576271442.615 [Default:CheckIn:E] Running Loop=1 2019-12-13T21:10:43.032Z,1576271443.032 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 44.711605 min 2019-12-13T21:10:43.032Z,1576271443.032 [Default:CheckIn:E] Stopped 2019-12-13T21:10:43.032Z,1576271443.032 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-12-13T21:10:43.032Z,1576271443.032 [Default:CheckIn] Stopped 2019-12-13T21:10:43.032Z,1576271443.032 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-12-13T21:10:43.032Z,1576271443.032 [Default:CheckIn](INFO): Running loop #6 2019-12-13T21:10:43.032Z,1576271443.032 [Default:CheckIn] Running Loop=6 2019-12-13T21:10:43.032Z,1576271443.032 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-12-13T21:10:43.033Z,1576271443.033 [Default:CheckIn:Read_GPS] Running Loop=1 2019-12-13T21:10:45.006Z,1576271445.006 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,211040.00,A,3648.14142,N,12147.22941,W,0.019,186.55,131219,,,D*77 2019-12-13T21:10:45.008Z,1576271445.008 [NAL9602](INFO): GPS fix at 20191213T211040: (36.802357, -121.787157) 2019-12-13T21:10:45.032Z,1576271445.032 [Default:CheckIn:Read_GPS] Stopped 2019-12-13T21:10:45.032Z,1576271445.032 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-12-13T21:10:52.584Z,1576271452.584 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20191213T202210/Courier0019.lzma 2019-12-13T21:10:54.590Z,1576271454.590 [DataOverHttps](INFO): Moved sent file to Logs/20191213T202210/Courier0019.lzma.bak 2019-12-13T21:10:54.590Z,1576271454.590 [DataOverHttps](INFO): SBD MOMSN=12156228 2019-12-13T21:11:11.679Z,1576271471.679 [DataOverHttps](INFO): Sending 121 bytes from file Logs/20191213T202210/Express0020.lzma 2019-12-13T21:11:13.682Z,1576271473.682 [DataOverHttps](INFO): Moved sent file to Logs/20191213T202210/Express0020.lzma.bak 2019-12-13T21:11:13.683Z,1576271473.683 [DataOverHttps](INFO): SBD MOMSN=12156232 2019-12-13T21:11:14.918Z,1576271474.918 [Default:CheckIn:Read_Iridium] Stopped 2019-12-13T21:11:14.918Z,1576271474.918 [Default:CheckIn:C.Wait] Running Loop=1 2019-12-13T21:11:14.918Z,1576271474.918 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-12-13T21:11:29.443Z,1576271489.443 [NAL9602](INFO): SBD MO Status=2, MOMSN=18038, MT Status=2, MTMSN=0 2019-12-13T21:11:29.443Z,1576271489.443 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-12-13T21:11:46.811Z,1576271506.811 [NAL9602](INFO): SBD MO Status=2, MOMSN=18038, MT Status=2, MTMSN=0 2019-12-13T21:11:46.812Z,1576271506.812 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-12-13T21:13:48.823Z,1576271628.823 [NAL9602](INFO): SBD MO Status=2, MOMSN=18038, MT Status=2, MTMSN=0 2019-12-13T21:13:48.823Z,1576271628.823 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-12-13T21:15:47.596Z,1576271747.596 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-12-13T21:16:15.502Z,1576271775.502 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-12-13T21:16:15.502Z,1576271775.502 [Default:CheckIn:C.Wait] Stopped 2019-12-13T21:16:15.502Z,1576271775.502 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-12-13T21:16:15.502Z,1576271775.502 [Default:CheckIn:D] Running Loop=1 2019-12-13T21:16:15.917Z,1576271775.917 [Default:CheckIn:D] Stopped 2019-12-13T21:16:15.917Z,1576271775.917 [Default:CheckIn:E] Running Loop=1 2019-12-13T21:16:16.305Z,1576271776.305 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 50.266626 min 2019-12-13T21:16:16.305Z,1576271776.305 [Default:CheckIn:E] Stopped 2019-12-13T21:16:16.305Z,1576271776.305 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-12-13T21:16:16.305Z,1576271776.305 [Default:CheckIn] Stopped 2019-12-13T21:16:16.305Z,1576271776.305 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-12-13T21:16:16.305Z,1576271776.305 [Default:CheckIn](INFO): Running loop #7 2019-12-13T21:16:16.305Z,1576271776.305 [Default:CheckIn] Running Loop=7 2019-12-13T21:16:16.305Z,1576271776.305 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-12-13T21:16:16.306Z,1576271776.306 [Default:CheckIn:Read_GPS] Running Loop=1 2019-12-13T21:16:18.308Z,1576271778.308 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,211613.00,A,3648.15022,N,12147.22263,W,0.136,53.53,131219,,,D*49 2019-12-13T21:16:18.310Z,1576271778.310 [NAL9602](INFO): GPS fix at 20191213T211613: (36.802504, -121.787044) 2019-12-13T21:16:18.371Z,1576271778.371 [Default:CheckIn:Read_GPS] Stopped 2019-12-13T21:16:18.371Z,1576271778.371 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-12-13T21:16:26.248Z,1576271786.248 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20191213T202210/Courier0022.lzma 2019-12-13T21:16:28.254Z,1576271788.254 [DataOverHttps](INFO): Moved sent file to Logs/20191213T202210/Courier0022.lzma.bak 2019-12-13T21:16:28.254Z,1576271788.254 [DataOverHttps](INFO): SBD MOMSN=12156242 2019-12-13T21:16:45.257Z,1576271805.257 [DataOverHttps](INFO): Sending 195 bytes from file Logs/20191213T202210/Express0023.lzma 2019-12-13T21:16:47.262Z,1576271807.262 [DataOverHttps](INFO): Moved sent file to Logs/20191213T202210/Express0023.lzma.bak 2019-12-13T21:16:47.263Z,1576271807.263 [DataOverHttps](INFO): SBD MOMSN=12156247 2019-12-13T21:16:48.630Z,1576271808.630 [Default:CheckIn:Read_Iridium] Stopped 2019-12-13T21:16:48.631Z,1576271808.631 [Default:CheckIn:C.Wait] Running Loop=1 2019-12-13T21:16:48.631Z,1576271808.631 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-12-13T21:16:50.622Z,1576271810.622 [NAL9602](INFO): Not Powering down - fast GPS 2019-12-13T21:21:49.207Z,1576272109.207 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-12-13T21:21:49.207Z,1576272109.207 [Default:CheckIn:C.Wait] Stopped 2019-12-13T21:21:49.207Z,1576272109.207 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-12-13T21:21:49.207Z,1576272109.207 [Default:CheckIn:D] Running Loop=1 2019-12-13T21:21:49.615Z,1576272109.615 [Default:CheckIn:D] Stopped 2019-12-13T21:21:49.616Z,1576272109.616 [Default:CheckIn:E] Running Loop=1 2019-12-13T21:21:50.007Z,1576272110.007 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 55.828271 min 2019-12-13T21:21:50.007Z,1576272110.007 [Default:CheckIn:E] Stopped 2019-12-13T21:21:50.007Z,1576272110.007 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-12-13T21:21:50.007Z,1576272110.007 [Default:CheckIn] Stopped 2019-12-13T21:21:50.007Z,1576272110.007 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-12-13T21:21:50.008Z,1576272110.008 [Default:CheckIn](INFO): Running loop #8 2019-12-13T21:21:50.008Z,1576272110.008 [Default:CheckIn] Running Loop=8 2019-12-13T21:21:50.008Z,1576272110.008 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-12-13T21:21:50.008Z,1576272110.008 [Default:CheckIn:Read_GPS] Running Loop=1 2019-12-13T21:21:52.005Z,1576272112.005 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,212146.00,A,3648.14966,N,12147.22168,W,0.019,53.53,131219,,,D*41 2019-12-13T21:21:52.008Z,1576272112.008 [NAL9602](INFO): GPS fix at 20191213T212146: (36.802494, -121.787028) 2019-12-13T21:21:52.031Z,1576272112.031 [Default:CheckIn:Read_GPS] Stopped 2019-12-13T21:21:52.031Z,1576272112.031 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-12-13T21:21:59.320Z,1576272119.320 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20191213T202210/Courier0025.lzma 2019-12-13T21:22:01.326Z,1576272121.326 [DataOverHttps](INFO): Moved sent file to Logs/20191213T202210/Courier0025.lzma.bak 2019-12-13T21:22:01.327Z,1576272121.327 [DataOverHttps](INFO): SBD MOMSN=12156266 2019-12-13T21:22:18.384Z,1576272138.384 [DataOverHttps](INFO): Sending 119 bytes from file Logs/20191213T202210/Express0026.lzma 2019-12-13T21:22:20.390Z,1576272140.390 [DataOverHttps](INFO): Moved sent file to Logs/20191213T202210/Express0026.lzma.bak 2019-12-13T21:22:20.391Z,1576272140.391 [DataOverHttps](INFO): SBD MOMSN=12156269 2019-12-13T21:22:21.526Z,1576272141.526 [Default:CheckIn:Read_Iridium] Stopped 2019-12-13T21:22:21.526Z,1576272141.526 [Default:CheckIn:C.Wait] Running Loop=1 2019-12-13T21:22:21.526Z,1576272141.526 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-12-13T21:22:22.714Z,1576272142.714 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2019-12-13T21:22:22.789Z,1576272142.789 [NAL9602](FAULT): received: +CSQ:0 OK038, 2, 0, 0, 0 OK 2019-12-13T21:22:22.789Z,1576272142.789 [NAL9602] Data Fault, FailCount= 1 2019-12-13T21:22:22.789Z,1576272142.789 [NAL9602](ERROR): Data Fault 2019-12-13T21:22:22.830Z,1576272142.830 [CBIT](ERROR): Data Fault in component: NAL9602 2019-12-13T21:22:23.114Z,1576272143.114 [NAL9602](INFO): Powering down 2019-12-13T21:22:23.518Z,1576272143.518 [NAL9602](FAULT): LCB fault: Software Overcurrent. 2019-12-13T21:22:23.518Z,1576272143.518 [NAL9602] Hardware Fault, FailCount= 1 2019-12-13T21:22:23.518Z,1576272143.518 [NAL9602](ERROR): Hardware Fault 2019-12-13T21:22:23.986Z,1576272143.986 [CBIT](INFO): Clearing failed state for component NAL9602 2019-12-13T21:22:23.986Z,1576272143.986 [NAL9602] No Fault, FailCount= 1 2019-12-13T21:22:53.422Z,1576272173.422 [NAL9602](INFO): Powering up NAL9602 2019-12-13T21:23:04.326Z,1576272184.326 [NAL9602](INFO): NAL9602 initialized 2019-12-13T21:23:35.436Z,1576272215.436 [NAL9602](INFO): Not Powering down - fast GPS 2019-12-13T21:27:22.095Z,1576272442.095 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-12-13T21:27:22.095Z,1576272442.095 [Default:CheckIn:C.Wait] Stopped 2019-12-13T21:27:22.095Z,1576272442.095 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-12-13T21:27:22.095Z,1576272442.095 [Default:CheckIn:D] Running Loop=1 2019-12-13T21:27:22.515Z,1576272442.515 [Default:CheckIn:D] Stopped 2019-12-13T21:27:22.515Z,1576272442.515 [Default:CheckIn:E] Running Loop=1 2019-12-13T21:27:22.937Z,1576272442.937 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 61.376595 min 2019-12-13T21:27:22.937Z,1576272442.937 [Default:CheckIn:E] Stopped 2019-12-13T21:27:22.937Z,1576272442.937 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-12-13T21:27:22.937Z,1576272442.937 [Default:CheckIn] Stopped 2019-12-13T21:27:22.937Z,1576272442.937 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-12-13T21:27:22.937Z,1576272442.937 [Default:CheckIn](INFO): Running loop #9 2019-12-13T21:27:22.937Z,1576272442.937 [Default:CheckIn] Running Loop=9 2019-12-13T21:27:22.938Z,1576272442.938 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-12-13T21:27:22.938Z,1576272442.938 [Default:CheckIn:Read_GPS] Running Loop=1 2019-12-13T21:27:24.919Z,1576272444.919 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,212719.00,A,3648.47955,N,12147.10854,W,6.842,351.99,131219,,,D*7B 2019-12-13T21:27:24.922Z,1576272444.922 [NAL9602](INFO): GPS fix at 20191213T212719: (36.807992, -121.785142) 2019-12-13T21:27:24.948Z,1576272444.948 [Default:CheckIn:Read_GPS] Stopped 2019-12-13T21:27:24.948Z,1576272444.948 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-12-13T21:27:27.330Z,1576272447.330 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-12-13T21:27:32.332Z,1576272452.332 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20191213T202210/Courier0028.lzma 2019-12-13T21:27:34.338Z,1576272454.338 [DataOverHttps](INFO): Moved sent file to Logs/20191213T202210/Courier0028.lzma.bak 2019-12-13T21:27:34.339Z,1576272454.339 [DataOverHttps](INFO): SBD MOMSN=12156281 2019-12-13T21:27:51.297Z,1576272471.297 [DataOverHttps](INFO): Sending 212 bytes from file Logs/20191213T202210/Express0029.lzma 2019-12-13T21:27:53.302Z,1576272473.302 [DataOverHttps](INFO): Moved sent file to Logs/20191213T202210/Express0029.lzma.bak 2019-12-13T21:27:53.302Z,1576272473.302 [DataOverHttps](INFO): SBD MOMSN=12156284 2019-12-13T21:27:54.420Z,1576272474.420 [Default:CheckIn:Read_Iridium] Stopped 2019-12-13T21:27:54.420Z,1576272474.420 [Default:CheckIn:C.Wait] Running Loop=1 2019-12-13T21:27:54.420Z,1576272474.420 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-12-13T21:27:58.034Z,1576272478.034 [NAL9602](INFO): Not Powering down - fast GPS 2019-12-13T21:31:06.422Z,1576272666.422 [DataOverHttps](IMPORTANT): SBD MTMSN=20191213T213059 2019-12-13T21:31:13.913Z,1576272673.913 [DataOverHttps](INFO): Received command:ibit 2019-12-13T21:31:13.954Z,1576272673.954 [CommandLine](IMPORTANT): got command ibit 2019-12-13T21:31:14.023Z,1576272674.023 [IBIT](IMPORTANT): Beginning Initiated BIT 2019-12-13T21:31:14.023Z,1576272674.023 [IBIT](IMPORTANT): Beginning control surface checks. 2019-12-13T21:31:14.026Z,1576272674.026 [CBIT](IMPORTANT): Beginning ground fault scan 2019-12-13T21:31:15.588Z,1576272675.588 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,213109.00,A,3647.95168,N,12148.23129,W,24.084,239.04,131219,,,D*4E 2019-12-13T21:31:15.590Z,1576272675.590 [NAL9602](INFO): GPS fix at 20191213T213109: (36.799195, -121.803855) 2019-12-13T21:31:24.942Z,1576272684.942 [CBIT](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): -0.006864 CHAN A1 (24V): 4.610929 CHAN A2 (12V): -0.002235 CHAN A3 (5V): 4.753929 CHAN B0 (3.3V): 0.001874 CHAN B1 (3.15aV): -0.000617 CHAN B2 (3.15bV): -0.000552 CHAN B3 (GND): -0.000103 OPEN: -0.000339 Full Scale Calc: 4.765 mA, -1.589 mA 2019-12-13T21:31:36.999Z,1576272696.999 [NAL9602](INFO): SBD MO Status=2, MOMSN=18038, MT Status=2, MTMSN=0 2019-12-13T21:31:36.000Z,1576272697.000 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-12-13T21:31:46.426Z,1576272706.426 [DataOverHttps](IMPORTANT): SBD MTMSN=20191213T213139 2019-12-13T21:31:54.124Z,1576272714.124 [DataOverHttps](INFO): Received command:ibit 2019-12-13T21:31:54.213Z,1576272714.213 [CommandLine](IMPORTANT): got command ibit 2019-12-13T21:32:00.471Z,1576272720.471 [IBIT](IMPORTANT): Communications Status: Fix Status: 1 Iridium Signal Strength: 3 Latitude: 36.799194 Longitude: -121.803856 2019-12-13T21:32:00.883Z,1576272720.883 [IBIT](IMPORTANT): Battery Status: Battery Charge (AH): 352.024994 Voltage: 16.593857 2019-12-13T21:32:00.883Z,1576272720.883 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah 2019-12-13T21:32:00.883Z,1576272720.883 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V 2019-12-13T21:32:01.239Z,1576272721.239 [NAL9602](INFO): SBD MO Status=2, MOMSN=18038, MT Status=2, MTMSN=0 2019-12-13T21:32:01.240Z,1576272721.240 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-12-13T21:32:01.349Z,1576272721.349 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 % 2019-12-13T21:32:01.350Z,1576272721.350 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi 2019-12-13T21:32:01.350Z,1576272721.350 [IBIT](IMPORTANT): Pressure:8.248733 PSI 2019-12-13T21:32:01.351Z,1576272721.351 [IBIT](IMPORTANT): Humidity:8.936638 % 2019-12-13T21:32:01.742Z,1576272721.742 [IBIT](IMPORTANT): Vehicle Pitch:11.400544 degrees 2019-12-13T21:32:01.743Z,1576272721.743 [IBIT](IMPORTANT): Vehicle Roll:5.425054 degrees 2019-12-13T21:32:01.743Z,1576272721.743 [IBIT](IMPORTANT): Vehicle Heading:242.842545 degrees 2019-12-13T21:32:02.106Z,1576272722.106 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m 2019-12-13T21:32:02.107Z,1576272722.107 [IBIT](IMPORTANT): buoyancyNeutral: 338.000000 cc 2019-12-13T21:32:02.107Z,1576272722.107 [IBIT](IMPORTANT): massDefault: -0.900000 cm 2019-12-13T21:32:02.107Z,1576272722.107 [IBIT](IMPORTANT): stopDepth: 205.000000 m 2019-12-13T21:32:02.107Z,1576272722.107 [IBIT](IMPORTANT): abortDepth: 250.000000 m 2019-12-13T21:32:02.108Z,1576272722.108 [IBIT](IMPORTANT): IBIT PASSED 2019-12-13T21:32:25.079Z,1576272745.079 [NAL9602](INFO): SBD MO Status=2, MOMSN=18038, MT Status=2, MTMSN=0 2019-12-13T21:32:25.080Z,1576272745.080 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-12-13T21:32:45.683Z,1576272765.683 [NAL9602](INFO): SBD MO Status=2, MOMSN=18038, MT Status=2, MTMSN=0 2019-12-13T21:32:45.683Z,1576272765.683 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-12-13T21:32:55.079Z,1576272775.079 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-12-13T21:32:55.079Z,1576272775.079 [Default:CheckIn:C.Wait] Stopped 2019-12-13T21:32:55.080Z,1576272775.080 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-12-13T21:32:55.080Z,1576272775.080 [Default:CheckIn:D] Running Loop=1 2019-12-13T21:32:55.489Z,1576272775.489 [Default:CheckIn:D] Stopped 2019-12-13T21:32:55.489Z,1576272775.489 [Default:CheckIn:E] Running Loop=1 2019-12-13T21:32:55.864Z,1576272775.864 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 66.926172 min 2019-12-13T21:32:55.864Z,1576272775.864 [Default:CheckIn:E] Stopped 2019-12-13T21:32:55.865Z,1576272775.865 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-12-13T21:32:55.865Z,1576272775.865 [Default:CheckIn] Stopped 2019-12-13T21:32:55.865Z,1576272775.865 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-12-13T21:32:55.865Z,1576272775.865 [Default:CheckIn](INFO): Running loop #10 2019-12-13T21:32:55.865Z,1576272775.865 [Default:CheckIn] Running Loop=10 2019-12-13T21:32:55.865Z,1576272775.865 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-12-13T21:32:55.866Z,1576272775.866 [Default:CheckIn:Read_GPS] Running Loop=1 2019-12-13T21:33:20.029Z,1576272800.029 [NAL9602](INFO): SBD MO Status=2, MOMSN=18038, MT Status=2, MTMSN=0 2019-12-13T21:33:20.029Z,1576272800.029 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-12-13T21:33:43.051Z,1576272823.051 [NAL9602](INFO): SBD MO Status=2, MOMSN=18038, MT Status=2, MTMSN=0 2019-12-13T21:33:43.052Z,1576272823.052 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-12-13T21:34:12.137Z,1576272852.137 [NAL9602](INFO): SBD MO Status=2, MOMSN=18038, MT Status=2, MTMSN=0 2019-12-13T21:34:12.137Z,1576272852.137 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-12-13T21:34:35.973Z,1576272875.973 [NAL9602](INFO): SBD MO Status=2, MOMSN=18038, MT Status=2, MTMSN=0 2019-12-13T21:34:35.973Z,1576272875.973 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-12-13T21:34:52.539Z,1576272892.539 [NAL9602](INFO): SBD MO Status=2, MOMSN=18038, MT Status=2, MTMSN=0 2019-12-13T21:34:52.540Z,1576272892.540 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-12-13T21:35:17.591Z,1576272917.591 [NAL9602](INFO): SBD MO Status=2, MOMSN=18038, MT Status=2, MTMSN=0 2019-12-13T21:35:17.592Z,1576272917.592 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-12-13T21:35:55.160Z,1576272955.160 [NAL9602](INFO): SBD MO Status=2, MOMSN=18038, MT Status=2, MTMSN=0 2019-12-13T21:35:55.160Z,1576272955.160 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-12-13T21:36:21.019Z,1576272981.019 [NAL9602](INFO): SBD MO Status=2, MOMSN=18038, MT Status=2, MTMSN=0 2019-12-13T21:36:21.019Z,1576272981.019 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-12-13T21:36:21.422Z,1576272981.422 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-12-13T21:36:22.636Z,1576272982.636 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,213616.00,A,3647.02738,N,12150.39291,W,21.907,245.48,131219,,,D*4C 2019-12-13T21:36:22.638Z,1576272982.638 [NAL9602](INFO): GPS fix at 20191213T213616: (36.783790, -121.839882) 2019-12-13T21:36:22.688Z,1576272982.688 [Default:CheckIn:Read_GPS] Stopped 2019-12-13T21:36:22.688Z,1576272982.688 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-12-13T21:36:31.165Z,1576272991.165 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20191213T202210/Courier0031.lzma 2019-12-13T21:36:33.170Z,1576272993.170 [DataOverHttps](INFO): Moved sent file to Logs/20191213T202210/Courier0031.lzma.bak 2019-12-13T21:36:33.171Z,1576272993.171 [DataOverHttps](INFO): SBD MOMSN=12156340 2019-12-13T21:36:55.372Z,1576273015.372 [NAL9602](INFO): Not Powering down - fast GPS 2019-12-13T21:37:14.778Z,1576273034.778 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-12-13T21:37:45.909Z,1576273065.909 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-12-13T21:38:17.033Z,1576273097.033 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-12-13T21:38:21.855Z,1576273101.855 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2019-12-13T21:38:21.857Z,1576273101.857 [BPC1](INFO): Received data from all battery sticks. 2019-12-13T21:38:48.157Z,1576273128.157 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-12-13T21:39:19.281Z,1576273159.281 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-12-13T21:39:44.419Z,1576273184.419 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.792358 2019-12-13T21:39:56.431Z,1576273196.431 [NAL9602](INFO): SBD MO Status=1, MOMSN=18038, MT Status=0, MTMSN=0 2019-12-13T21:39:56.490Z,1576273196.490 [NAL9602](INFO): Sent 25 bytes from file Logs/20191213T202210/Courier0035.lzma 2019-12-13T21:39:56.490Z,1576273196.490 [NAL9602](INFO): Packets left to send: 0 2019-12-13T21:40:15.561Z,1576273215.561 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-12-13T21:40:16.712Z,1576273216.712 [NAL9602](INFO): SBD MO Status=1, MOMSN=18039, MT Status=0, MTMSN=0 2019-12-13T21:40:16.769Z,1576273216.769 [NAL9602](INFO): Sent 332 bytes from file Logs/20191213T202210/Express0032.lzma 2019-12-13T21:40:16.769Z,1576273216.769 [NAL9602](INFO): Packets left to send: 2 2019-12-13T21:40:35.365Z,1576273235.365 [NAL9602](INFO): SBD MO Status=1, MOMSN=18040, MT Status=0, MTMSN=0 2019-12-13T21:40:35.431Z,1576273235.431 [NAL9602](INFO): Sent 332 bytes from file Logs/20191213T202210/Express0032.lzma 2019-12-13T21:40:35.432Z,1576273235.432 [NAL9602](INFO): Packets left to send: 1 2019-12-13T21:40:46.709Z,1576273246.709 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-12-13T21:40:50.771Z,1576273250.771 [NAL9602](INFO): SBD MO Status=2, MOMSN=18041, MT Status=2, MTMSN=0 2019-12-13T21:40:50.771Z,1576273250.771 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-12-13T21:41:17.833Z,1576273277.833 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-12-13T21:41:48.958Z,1576273308.958 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-12-13T21:42:20.081Z,1576273340.081 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-12-13T21:42:29.469Z,1576273349.469 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003300 2019-12-13T21:42:35.071Z,1576273355.071 [NAL9602](INFO): SBD MO Status=1, MOMSN=18041, MT Status=0, MTMSN=0 2019-12-13T21:42:35.125Z,1576273355.125 [NAL9602](INFO): Sent 274 bytes from file Logs/20191213T202210/Express0032.lzma 2019-12-13T21:42:35.125Z,1576273355.125 [NAL9602](INFO): Packets left to send: 0 2019-12-13T21:42:37.025Z,1576273357.025 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20191213T202210/Express0037.lzma 2019-12-13T21:42:39.030Z,1576273359.030 [DataOverHttps](INFO): Moved sent file to Logs/20191213T202210/Express0037.lzma.bak 2019-12-13T21:42:39.030Z,1576273359.030 [DataOverHttps](INFO): SBD MOMSN=12156356 2019-12-13T21:42:40.365Z,1576273360.365 [Default:CheckIn:Read_Iridium] Stopped 2019-12-13T21:42:40.365Z,1576273360.365 [Default:CheckIn:C.Wait] Running Loop=1 2019-12-13T21:42:40.365Z,1576273360.365 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-12-13T21:43:05.771Z,1576273385.771 [NAL9602](INFO): Not Powering down - fast GPS 2019-12-13T21:46:53.243Z,1576273613.243 [DataOverHttps](IMPORTANT): SBD MTMSN=20191213T214644 2019-12-13T21:47:00.643Z,1576273620.643 [DataOverHttps](INFO): Received command:restart logs