2020-10-07T20:01:12.105Z,1602100872.105 [Supervisor](DEBUG): Initializing supervisor. 2020-10-07T20:01:12.107Z,1602100872.107 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2020-10-07T20:01:12.108Z,1602100872.108 [SyncHandler](INFO): Protected caller Thread ID is 1028 2020-10-07T20:01:12.108Z,1602100872.108 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2020-10-07T20:01:12.109Z,1602100872.109 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2020-10-07T20:01:12.109Z,1602100872.109 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 1029 2020-10-07T20:01:12.112Z,1602100872.112 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2020-10-07T20:01:12.129Z,1602100872.129 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2020-10-07T20:01:12.130Z,1602100872.130 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2020-10-07T20:01:12.130Z,1602100872.130 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 1030 2020-10-07T20:01:12.131Z,1602100872.131 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2020-10-07T20:01:12.132Z,1602100872.132 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2020-10-07T20:01:12.132Z,1602100872.132 [logger ThreadHandler](INFO): Protected caller Thread ID is 1031 2020-10-07T20:01:12.134Z,1602100872.134 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2020-10-07T20:01:12.135Z,1602100872.135 [Supervisor](INFO): Looking for Config files in directory: Config/ 2020-10-07T20:01:12.136Z,1602100872.136 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2020-10-07T20:01:12.230Z,1602100872.230 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2020-10-07T20:01:12.231Z,1602100872.231 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg 2020-10-07T20:01:12.423Z,1602100872.423 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock 2020-10-07T20:01:12.424Z,1602100872.424 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2020-10-07T20:01:12.621Z,1602100872.621 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2020-10-07T20:01:12.622Z,1602100872.622 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2020-10-07T20:01:12.758Z,1602100872.758 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2020-10-07T20:01:12.759Z,1602100872.759 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2020-10-07T20:01:13.345Z,1602100873.345 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2020-10-07T20:01:13.345Z,1602100873.345 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2020-10-07T20:01:13.969Z,1602100873.969 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2020-10-07T20:01:13.969Z,1602100873.969 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2020-10-07T20:01:14.466Z,1602100874.466 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2020-10-07T20:01:14.467Z,1602100874.467 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2020-10-07T20:01:14.757Z,1602100874.757 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2020-10-07T20:01:14.758Z,1602100874.758 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2020-10-07T20:01:15.067Z,1602100875.067 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2020-10-07T20:01:15.068Z,1602100875.068 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2020-10-07T20:01:15.475Z,1602100875.475 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2020-10-07T20:01:15.475Z,1602100875.475 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2020-10-07T20:01:15.619Z,1602100875.619 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2020-10-07T20:01:15.620Z,1602100875.620 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2020-10-07T20:01:15.726Z,1602100875.726 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2020-10-07T20:01:15.726Z,1602100875.726 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2020-10-07T20:01:15.806Z,1602100875.806 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2020-10-07T20:01:15.907Z,1602100875.907 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2020-10-07T20:01:15.907Z,1602100875.907 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2020-10-07T20:01:16.096Z,1602100876.096 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2020-10-07T20:01:16.096Z,1602100876.096 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2020-10-07T20:01:16.301Z,1602100876.301 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2020-10-07T20:01:16.303Z,1602100876.303 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/ 2020-10-07T20:01:16.304Z,1602100876.304 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg 2020-10-07T20:01:16.386Z,1602100876.386 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg 2020-10-07T20:01:16.633Z,1602100876.633 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2020-10-07T20:01:16.634Z,1602100876.634 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg 2020-10-07T20:01:16.727Z,1602100876.727 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg 2020-10-07T20:01:16.887Z,1602100876.887 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg 2020-10-07T20:01:17.087Z,1602100877.087 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg 2020-10-07T20:01:17.171Z,1602100877.171 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg 2020-10-07T20:01:17.270Z,1602100877.270 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg 2020-10-07T20:01:17.360Z,1602100877.360 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg 2020-10-07T20:01:17.518Z,1602100877.518 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg 2020-10-07T20:01:17.620Z,1602100877.620 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg 2020-10-07T20:01:17.717Z,1602100877.717 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/root/ 2020-10-07T20:01:17.718Z,1602100877.718 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2020-10-07T20:01:17.726Z,1602100877.726 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2020-10-07T20:01:17.821Z,1602100877.821 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2020-10-07T20:01:17.821Z,1602100877.821 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2020-10-07T20:01:17.954Z,1602100877.954 [BuoyancyServo] Loaded 2020-10-07T20:01:17.954Z,1602100877.954 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2020-10-07T20:01:17.971Z,1602100877.971 [ElevatorServo] Loaded 2020-10-07T20:01:17.972Z,1602100877.972 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2020-10-07T20:01:17.988Z,1602100877.988 [MassServo] Loaded 2020-10-07T20:01:17.988Z,1602100877.988 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2020-10-07T20:01:18.005Z,1602100878.005 [RudderServo] Loaded 2020-10-07T20:01:18.005Z,1602100878.005 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2020-10-07T20:01:18.021Z,1602100878.021 [ThrusterServo] Loaded 2020-10-07T20:01:18.021Z,1602100878.021 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2020-10-07T20:01:18.021Z,1602100878.021 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2020-10-07T20:01:18.022Z,1602100878.022 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2020-10-07T20:01:18.154Z,1602100878.154 [SBIT](DEBUG): Construct Startup Built In Test. 2020-10-07T20:01:18.168Z,1602100878.168 [SBIT] Loaded 2020-10-07T20:01:18.169Z,1602100878.169 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2020-10-07T20:01:18.169Z,1602100878.169 [IBIT](DEBUG): Construct Initiated Built In Test. 2020-10-07T20:01:18.188Z,1602100878.188 [IBIT] Loaded 2020-10-07T20:01:18.189Z,1602100878.189 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2020-10-07T20:01:18.192Z,1602100878.192 [CBIT](DEBUG): Construct Continuous Built In Test. 2020-10-07T20:01:18.388Z,1602100878.388 [CBIT] Loaded 2020-10-07T20:01:18.388Z,1602100878.388 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2020-10-07T20:01:18.389Z,1602100878.389 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2020-10-07T20:01:18.389Z,1602100878.389 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2020-10-07T20:01:18.576Z,1602100878.576 [CANONSampler] Loaded 2020-10-07T20:01:18.576Z,1602100878.576 [ComponentRegistry](DEBUG): SyncComponent "CANONSampler" handled in the control thread. 2020-10-07T20:01:18.594Z,1602100878.594 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_density 2020-10-07T20:01:18.597Z,1602100878.597 [CTD_Seabird](INFO): created writer for : sea_water_density 2020-10-07T20:01:18.598Z,1602100878.598 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): depth 2020-10-07T20:01:18.601Z,1602100878.601 [CTD_Seabird](INFO): created writer for : depth 2020-10-07T20:01:18.601Z,1602100878.601 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_pressure 2020-10-07T20:01:18.604Z,1602100878.604 [CTD_Seabird](INFO): created writer for : sea_water_pressure 2020-10-07T20:01:18.604Z,1602100878.604 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_salinity 2020-10-07T20:01:18.607Z,1602100878.607 [CTD_Seabird](INFO): created writer for : sea_water_salinity 2020-10-07T20:01:18.608Z,1602100878.608 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_temperature 2020-10-07T20:01:18.611Z,1602100878.611 [CTD_Seabird](INFO): created writer for : sea_water_temperature 2020-10-07T20:01:18.611Z,1602100878.611 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_electrical_conductivity 2020-10-07T20:01:18.614Z,1602100878.614 [CTD_Seabird](INFO): created writer for : sea_water_electrical_conductivity 2020-10-07T20:01:18.615Z,1602100878.615 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): speed_of_sound_in_sea_water 2020-10-07T20:01:18.618Z,1602100878.618 [CTD_Seabird](INFO): created writer for : speed_of_sound_in_sea_water 2020-10-07T20:01:18.618Z,1602100878.618 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): mass_concentration_of_oxygen_in_sea_water 2020-10-07T20:01:18.621Z,1602100878.621 [CTD_Seabird](INFO): created writer for : mass_concentration_of_oxygen_in_sea_water 2020-10-07T20:01:18.621Z,1602100878.621 [CTD_Seabird](DEBUG): LcmSlateWriter::add(DAtaURI): CTD_Seabird.sea_water_dissolved_oxygen_freq 2020-10-07T20:01:18.622Z,1602100878.622 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): dataName: sea_water_dissolved_oxygen_freq 2020-10-07T20:01:18.637Z,1602100878.637 [CTD_Seabird] Loaded 2020-10-07T20:01:18.637Z,1602100878.637 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2020-10-07T20:01:18.638Z,1602100878.638 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 406784E0 2020-10-07T20:01:18.638Z,1602100878.638 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 1113 2020-10-07T20:01:18.666Z,1602100878.666 [ESPComponent] Loaded 2020-10-07T20:01:18.667Z,1602100878.667 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread. 2020-10-07T20:01:18.683Z,1602100878.683 [PAR_Licor] Loaded 2020-10-07T20:01:18.683Z,1602100878.683 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2020-10-07T20:01:18.695Z,1602100878.695 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.Output470 2020-10-07T20:01:18.695Z,1602100878.695 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: Output470 2020-10-07T20:01:18.697Z,1602100878.697 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.Output650 2020-10-07T20:01:18.698Z,1602100878.698 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: Output650 2020-10-07T20:01:18.699Z,1602100878.699 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.OutputChl 2020-10-07T20:01:18.700Z,1602100878.700 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: OutputChl 2020-10-07T20:01:18.702Z,1602100878.702 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.VolumeScatCoeff117deg470nm 2020-10-07T20:01:18.702Z,1602100878.702 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: VolumeScatCoeff117deg470nm 2020-10-07T20:01:18.703Z,1602100878.703 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.VolumeScatCoeff117deg650nm 2020-10-07T20:01:18.704Z,1602100878.704 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: VolumeScatCoeff117deg650nm 2020-10-07T20:01:18.706Z,1602100878.706 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.BackscatteringCoeff470nm 2020-10-07T20:01:18.706Z,1602100878.706 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: BackscatteringCoeff470nm 2020-10-07T20:01:18.708Z,1602100878.708 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.BackscatteringCoeff650nm 2020-10-07T20:01:18.708Z,1602100878.708 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: BackscatteringCoeff650nm 2020-10-07T20:01:18.710Z,1602100878.710 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): mass_concentration_of_chlorophyll_in_sea_water 2020-10-07T20:01:18.712Z,1602100878.712 [WetLabsBB2FL](INFO): created writer for : mass_concentration_of_chlorophyll_in_sea_water 2020-10-07T20:01:18.712Z,1602100878.712 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_median_mass_concentration_of_chlorophyll_in_sea_water 2020-10-07T20:01:18.712Z,1602100878.712 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_median_mass_concentration_of_chlorophyll_in_sea_water 2020-10-07T20:01:18.714Z,1602100878.714 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water 2020-10-07T20:01:18.714Z,1602100878.714 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_mean_mass_concentration_of_chlorophyll_in_sea_water 2020-10-07T20:01:18.716Z,1602100878.716 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_variance_mass_concentration_of_chlorophyll_in_sea_water 2020-10-07T20:01:18.717Z,1602100878.717 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_variance_mass_concentration_of_chlorophyll_in_sea_water 2020-10-07T20:01:18.718Z,1602100878.718 [WetLabsBB2FL] Loaded 2020-10-07T20:01:18.719Z,1602100878.719 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2020-10-07T20:01:18.720Z,1602100878.720 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 406A84E0 2020-10-07T20:01:18.720Z,1602100878.720 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 1114 2020-10-07T20:01:18.721Z,1602100878.721 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2020-10-07T20:01:18.721Z,1602100878.721 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2020-10-07T20:01:18.757Z,1602100878.757 [DepthRateCalculator] Loaded 2020-10-07T20:01:18.757Z,1602100878.757 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2020-10-07T20:01:18.760Z,1602100878.760 [PitchRateCalculator] Loaded 2020-10-07T20:01:18.761Z,1602100878.761 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2020-10-07T20:01:18.769Z,1602100878.769 [SpeedCalculator] Loaded 2020-10-07T20:01:18.769Z,1602100878.769 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2020-10-07T20:01:18.780Z,1602100878.780 [TempGradientCalculator] Loaded 2020-10-07T20:01:18.780Z,1602100878.780 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2020-10-07T20:01:18.783Z,1602100878.783 [YawRateCalculator] Loaded 2020-10-07T20:01:18.783Z,1602100878.783 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2020-10-07T20:01:18.798Z,1602100878.798 [ElevatorOffsetCalculator] Loaded 2020-10-07T20:01:18.799Z,1602100878.799 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2020-10-07T20:01:18.799Z,1602100878.799 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2020-10-07T20:01:18.799Z,1602100878.799 [Module Loader](DEBUG): Loading Module at Modules/Dock.so 2020-10-07T20:01:18.874Z,1602100878.874 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking) 2020-10-07T20:01:18.875Z,1602100878.875 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2020-10-07T20:01:18.900Z,1602100878.900 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2020-10-07T20:01:18.901Z,1602100878.901 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2020-10-07T20:01:18.977Z,1602100878.977 [DeadReckonUsingMultipleVelocitySources] Loaded 2020-10-07T20:01:18.977Z,1602100878.977 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2020-10-07T20:01:18.988Z,1602100878.988 [NavChart] Loaded 2020-10-07T20:01:18.988Z,1602100878.988 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2020-10-07T20:01:18.992Z,1602100878.992 [UniversalFixResidualReporter] Loaded 2020-10-07T20:01:18.992Z,1602100878.992 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2020-10-07T20:01:18.993Z,1602100878.993 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2020-10-07T20:01:18.993Z,1602100878.993 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2020-10-07T20:01:19.782Z,1602100879.782 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_orientation 2020-10-07T20:01:19.785Z,1602100879.785 [AHRS_M2](INFO): created writer for : platform_orientation 2020-10-07T20:01:19.785Z,1602100879.785 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_magnetic_orientation 2020-10-07T20:01:19.788Z,1602100879.788 [AHRS_M2](INFO): created writer for : platform_magnetic_orientation 2020-10-07T20:01:19.789Z,1602100879.789 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_pitch_angle 2020-10-07T20:01:19.791Z,1602100879.791 [AHRS_M2](INFO): created writer for : platform_pitch_angle 2020-10-07T20:01:19.792Z,1602100879.792 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_roll_angle 2020-10-07T20:01:19.795Z,1602100879.795 [AHRS_M2](INFO): created writer for : platform_roll_angle 2020-10-07T20:01:19.925Z,1602100879.925 [AHRS_M2] Loaded 2020-10-07T20:01:19.926Z,1602100879.926 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2020-10-07T20:01:20.007Z,1602100880.007 [DataOverHttps] Loaded 2020-10-07T20:01:20.008Z,1602100880.008 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2020-10-07T20:01:20.009Z,1602100880.009 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 409CC4E0 2020-10-07T20:01:20.009Z,1602100880.009 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 1115 2020-10-07T20:01:20.025Z,1602100880.025 [Depth_Keller] Loaded 2020-10-07T20:01:20.026Z,1602100880.026 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2020-10-07T20:01:20.028Z,1602100880.028 [DropWeight] Loaded 2020-10-07T20:01:20.028Z,1602100880.028 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2020-10-07T20:01:20.080Z,1602100880.080 [NAL9602] Loaded 2020-10-07T20:01:20.081Z,1602100880.081 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2020-10-07T20:01:20.102Z,1602100880.102 [Onboard] Loaded 2020-10-07T20:01:20.102Z,1602100880.102 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread. 2020-10-07T20:01:20.103Z,1602100880.103 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 409FC4E0 2020-10-07T20:01:20.103Z,1602100880.103 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 1116 2020-10-07T20:01:20.114Z,1602100880.114 [Radio_Surface] Loaded 2020-10-07T20:01:20.114Z,1602100880.114 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2020-10-07T20:01:20.115Z,1602100880.115 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 40A2C4E0 2020-10-07T20:01:20.115Z,1602100880.115 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 1117 2020-10-07T20:01:20.794Z,1602100880.794 [BPC1] Loaded 2020-10-07T20:01:20.794Z,1602100880.794 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2020-10-07T20:01:20.812Z,1602100880.812 [AMEcho] Loaded 2020-10-07T20:01:20.812Z,1602100880.812 [ComponentRegistry](DEBUG): SyncComponent "AMEcho" handled in the control thread. 2020-10-07T20:01:20.813Z,1602100880.813 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2020-10-07T20:01:20.813Z,1602100880.813 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2020-10-07T20:01:20.894Z,1602100880.894 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2020-10-07T20:01:20.895Z,1602100880.895 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2020-10-07T20:01:20.942Z,1602100880.942 [VerticalControl](DEBUG): Construct VerticalControl. 2020-10-07T20:01:20.990Z,1602100880.990 [VerticalControl] Loaded 2020-10-07T20:01:20.990Z,1602100880.990 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2020-10-07T20:01:20.991Z,1602100880.991 [HorizontalControl](DEBUG): Construct HorizontalControl. 2020-10-07T20:01:21.025Z,1602100881.025 [HorizontalControl] Loaded 2020-10-07T20:01:21.025Z,1602100881.025 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2020-10-07T20:01:21.026Z,1602100881.026 [SpeedControl](DEBUG): Construct SpeedControl. 2020-10-07T20:01:21.027Z,1602100881.027 [SpeedControl] Loaded 2020-10-07T20:01:21.028Z,1602100881.028 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2020-10-07T20:01:21.028Z,1602100881.028 [LoopControl](DEBUG): Construct LoopControl. 2020-10-07T20:01:21.029Z,1602100881.029 [LoopControl] Loaded 2020-10-07T20:01:21.029Z,1602100881.029 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2020-10-07T20:01:21.029Z,1602100881.029 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2020-10-07T20:01:21.030Z,1602100881.030 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2020-10-07T20:01:21.048Z,1602100881.048 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2020-10-07T20:01:21.048Z,1602100881.048 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2020-10-07T20:01:21.327Z,1602100881.327 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2020-10-07T20:01:21.331Z,1602100881.331 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2020-10-07T20:01:21.332Z,1602100881.332 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2020-10-07T20:01:21.340Z,1602100881.340 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2020-10-07T20:01:21.341Z,1602100881.341 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B664E0 2020-10-07T20:01:21.341Z,1602100881.341 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 1118 2020-10-07T20:01:21.346Z,1602100881.346 [Supervisor](INFO): Main Thread ID is 815 2020-10-07T20:01:21.346Z,1602100881.346 [Supervisor](DEBUG): Running supervisor. 2020-10-07T20:01:21.347Z,1602100881.347 [CommandLine ThreadHandler](INFO): Handler Thread ID is 1119 2020-10-07T20:01:21.350Z,1602100881.350 [controlThread ThreadHandler](INFO): Handler Thread ID is 1120 2020-10-07T20:01:21.350Z,1602100881.350 [controlThread](DEBUG): Initializing ControlThread 2020-10-07T20:01:21.352Z,1602100881.352 [SBIT](INFO): Initialize SBIT Component. 2020-10-07T20:01:21.353Z,1602100881.353 [SBIT](IMPORTANT): git: 2020-10-07_A 2020-10-07T20:01:21.353Z,1602100881.353 [SBIT](INFO): git hash: c52f40a9277e8d17c6912ac1d266a8bed1742f02 2020-10-07T20:01:21.353Z,1602100881.353 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2020-10-07T20:01:21.354Z,1602100881.354 [SBIT](INFO): Kernel Reporting Different Version From Configuration. Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018 Kernel Reported: #1 PREEMPT Wed Nov 13 12:38:10 PST 2019 2020-10-07T20:01:21.356Z,1602100881.356 [SBIT](INFO): Beginning SBIT in 53.000000 seconds. 2020-10-07T20:01:21.356Z,1602100881.356 [IBIT](INFO): Initialize IBIT Component. 2020-10-07T20:01:21.357Z,1602100881.357 [CBIT](DEBUG): Initialize CBIT Component. 2020-10-07T20:01:21.358Z,1602100881.358 [logger ThreadHandler](INFO): Handler Thread ID is 1121 2020-10-07T20:01:21.369Z,1602100881.369 [CBIT](DEBUG): Initialized mux pins. 2020-10-07T20:01:21.369Z,1602100881.369 [CBIT](DEBUG): Initializing the watchdog timer. 2020-10-07T20:01:21.377Z,1602100881.377 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 1122 2020-10-07T20:01:21.378Z,1602100881.378 [CTD_Seabird](DEBUG): Initializing CTD_Seabird. 2020-10-07T20:01:21.382Z,1602100881.382 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 1124 2020-10-07T20:01:21.383Z,1602100881.383 [WetLabsBB2FL](INFO): Powering down 2020-10-07T20:01:21.393Z,1602100881.393 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2020-10-07T20:01:21.393Z,1602100881.393 [CBIT](DEBUG): Initializing heartbeat. 2020-10-07T20:01:21.421Z,1602100881.421 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 1125 2020-10-07T20:01:21.422Z,1602100881.422 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2020-10-07T20:01:21.441Z,1602100881.441 [Onboard ThreadHandler](INFO): Handler Thread ID is 1126 2020-10-07T20:01:21.458Z,1602100881.458 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 1127 2020-10-07T20:01:21.465Z,1602100881.465 [CBIT](DEBUG): Deactivating GF circuits. 2020-10-07T20:01:21.465Z,1602100881.465 [CBIT](DEBUG): Deactivating emergency mode. 2020-10-07T20:01:21.477Z,1602100881.477 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 1128 2020-10-07T20:01:21.480Z,1602100881.480 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2020-10-07T20:01:21.480Z,1602100881.480 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2020-10-07T20:01:21.480Z,1602100881.480 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2020-10-07T20:01:21.481Z,1602100881.481 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2020-10-07T20:01:21.481Z,1602100881.481 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2020-10-07T20:01:21.481Z,1602100881.481 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2020-10-07T20:01:21.481Z,1602100881.481 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000 2020-10-07T20:01:21.481Z,1602100881.481 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2020-10-07T20:01:21.481Z,1602100881.481 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2020-10-07T20:01:21.481Z,1602100881.481 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2020-10-07T20:01:21.482Z,1602100881.482 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000 2020-10-07T20:01:21.482Z,1602100881.482 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2020-10-07T20:01:21.482Z,1602100881.482 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000 2020-10-07T20:01:21.482Z,1602100881.482 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2020-10-07T20:01:21.482Z,1602100881.482 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000 2020-10-07T20:01:21.482Z,1602100881.482 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2020-10-07T20:01:21.501Z,1602100881.501 [CBIT](DEBUG): Backplane powered. 2020-10-07T20:01:21.505Z,1602100881.505 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2020-10-07T20:01:21.505Z,1602100881.505 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2020-10-07T20:01:21.506Z,1602100881.506 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2020-10-07T20:01:21.506Z,1602100881.506 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2020-10-07T20:01:21.507Z,1602100881.507 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2020-10-07T20:01:21.507Z,1602100881.507 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2020-10-07T20:01:21.508Z,1602100881.508 [NavChart](DEBUG): Initialize NavChart Navigation. 2020-10-07T20:01:21.509Z,1602100881.509 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2020-10-07T20:01:21.523Z,1602100881.523 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2020-10-07T20:01:21.533Z,1602100881.533 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2020-10-07T20:01:21.533Z,1602100881.533 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2020-10-07T20:01:21.534Z,1602100881.534 [LoopControl](DEBUG): Initialize LoopControlComponent. 2020-10-07T20:01:21.535Z,1602100881.535 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2020-10-07T20:01:21.569Z,1602100881.569 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2020-10-07T20:01:21.596Z,1602100881.596 [MissionManager](DEBUG): 2020-10-07T20:01:21.613Z,1602100881.613 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2020-10-07T20:01:21.675Z,1602100881.675 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2020-10-07T20:01:21.693Z,1602100881.693 [Default:A.Wait](DEBUG): Construct Wait. 2020-10-07T20:01:21.694Z,1602100881.694 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2020-10-07T20:01:21.721Z,1602100881.721 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2020-10-07T20:01:21.723Z,1602100881.723 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2020-10-07T20:01:21.759Z,1602100881.759 [Default:E.Execute](DEBUG): Construct Execute. 2020-10-07T20:01:21.785Z,1602100881.785 [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 2020-10-07T20:01:21.817Z,1602100881.817 [controlThread](DEBUG): Component order: CycleStarter,CANONSampler,ESPComponent,PAR_Licor,AHRS_M2,Depth_Keller,DropWeight,NAL9602,BPC1,AMEcho,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2020-10-07T20:01:21.821Z,1602100881.821 [CANONSampler](INFO): Powering down 2020-10-07T20:01:21.824Z,1602100881.824 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2020-10-07T20:01:21.865Z,1602100881.865 [Radio_Surface](INFO): Powering up 2020-10-07T20:01:21.867Z,1602100881.867 [Depth_Keller](ERROR): Pressure reading out of range: 1895.684326 decibar 2020-10-07T20:01:21.897Z,1602100881.897 [AMEcho](INFO): Powering up 2020-10-07T20:01:21.910Z,1602100881.910 [AMEcho](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2 2020-10-07T20:01:21.937Z,1602100881.937 [DepthRateCalculator](ERROR): Depth measurement is not active 2020-10-07T20:01:21.961Z,1602100881.961 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2 2020-10-07T20:01:21.990Z,1602100881.990 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2020-10-07T20:01:21.997Z,1602100881.997 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2020-10-07T20:01:21.998Z,1602100881.998 [ElevatorServo](DEBUG): Initializing EZServoServo. 2020-10-07T20:01:22.009Z,1602100882.009 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2020-10-07T20:01:22.010Z,1602100882.010 [MassServo](DEBUG): Initializing EZServoServo. 2020-10-07T20:01:22.021Z,1602100882.021 [MassServo](DEBUG): Initializing MassServo. 2020-10-07T20:01:22.022Z,1602100882.022 [RudderServo](DEBUG): Initializing EZServoServo. 2020-10-07T20:01:22.033Z,1602100882.033 [RudderServo](DEBUG): Initializing RudderServo. 2020-10-07T20:01:22.034Z,1602100882.034 [ThrusterServo](DEBUG): Initializing EZServoServo. 2020-10-07T20:01:22.045Z,1602100882.045 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2020-10-07T20:01:22.529Z,1602100882.529 [AMEcho](INFO): Powering down 2020-10-07T20:01:22.917Z,1602100882.917 [RudderServo](ERROR): Rudder initialization uart error serial timeout 2020-10-07T20:01:22.917Z,1602100882.917 [RudderServo](FAULT): Rudder failed to initialize 2020-10-07T20:01:22.917Z,1602100882.917 [RudderServo] Communications Fault, FailCount= 1 2020-10-07T20:01:22.917Z,1602100882.917 [RudderServo](ERROR): Communications Fault 2020-10-07T20:01:23.028Z,1602100883.028 [CBIT](ERROR): Communications Fault in component: RudderServo 2020-10-07T20:01:23.222Z,1602100883.222 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2020-10-07T20:01:23.222Z,1602100883.222 [RudderServo](INFO): Powering down 2020-10-07T20:01:23.860Z,1602100883.860 [RudderServo](DEBUG): Initializing EZServoServo. 2020-10-07T20:01:23.978Z,1602100883.978 [RudderServo](DEBUG): Initializing RudderServo. 2020-10-07T20:01:23.982Z,1602100883.982 [CBIT](INFO): Clearing failed state for component RudderServo 2020-10-07T20:01:23.982Z,1602100883.982 [RudderServo] No Fault, FailCount= 1 2020-10-07T20:01:50.114Z,1602100910.114 [NAL9602](INFO): Powering up NAL9602 2020-10-07T20:02:01.022Z,1602100921.022 [NAL9602](INFO): NAL9602 initialized 2020-10-07T20:02:14.770Z,1602100934.770 [SBIT](IMPORTANT): Beginning Startup BIT 2020-10-07T20:02:14.774Z,1602100934.774 [CBIT](IMPORTANT): Beginning ground fault scan 2020-10-07T20:02:15.162Z,1602100935.162 [NAL9602](INFO): SBD MO Status=2, MOMSN=39109, MT Status=2, MTMSN=0 2020-10-07T20:02:15.162Z,1602100935.162 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2020-10-07T20:02:25.721Z,1602100945.721 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.004454 CHAN A1 (24V): 0.005500 CHAN A2 (12V): -0.003051 CHAN A3 (5V): -0.002265 CHAN B0 (3.3V): -0.000758 CHAN B1 (3.15aV): -0.001246 CHAN B2 (3.15bV): -0.001176 CHAN B3 (GND): 0.000380 OPEN: 0.004249 Full Scale Calc: 4.765 mA, -1.589 mA 2020-10-07T20:02:27.685Z,1602100947.685 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2020-10-07T20:02:38.000Z,1602100959.000 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2020-10-07T20:02:42.232Z,1602100962.232 [NAL9602](INFO): SBD MO Status=0, MOMSN=39109, MT Status=0, MTMSN=0 2020-10-07T20:02:42.232Z,1602100962.232 [NAL9602](INFO): No messages in MT queue 2020-10-07T20:02:43.448Z,1602100963.448 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,200241.00,A,3648.13491,N,12147.20885,W,0.058,198.09,071020,,,A*78 2020-10-07T20:02:43.451Z,1602100963.451 [NAL9602](INFO): GPS fix at 20201007T200241: (36.802248, -121.786814) 2020-10-07T20:02:49.906Z,1602100969.906 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2020-10-07T20:03:01.625Z,1602100981.625 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2020-10-07T20:03:08.914Z,1602100988.914 [SBIT](IMPORTANT): SBIT PASSED 2020-10-07T20:03:08.914Z,1602100988.914 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2020-10-07T20:03:08.915Z,1602100988.915 [SBIT](IMPORTANT): Aanderaa_O2.loadAtStartup=0 bool; 2020-10-07T20:03:08.915Z,1602100988.915 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=2 count; 2020-10-07T20:03:08.918Z,1602100988.918 [SBIT](IMPORTANT): CANONSampler.loadAtStartup=1 bool; 2020-10-07T20:03:08.918Z,1602100988.918 [SBIT](IMPORTANT): CANONSampler.rotateOnly=1 bool; 2020-10-07T20:03:08.918Z,1602100988.918 [SBIT](IMPORTANT): CBIT.gf24Offset=148.5 microampere; 2020-10-07T20:03:08.918Z,1602100988.918 [SBIT](IMPORTANT): DVL_micro.loadAtStartup=0 bool; 2020-10-07T20:03:08.918Z,1602100988.918 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=261 cubic_centimeter; 2020-10-07T20:03:08.918Z,1602100988.918 [SBIT](IMPORTANT): VerticalControl.massDefault=8.4 millimeter; 2020-10-07T20:03:09.320Z,1602100989.320 [MissionManager](IMPORTANT): Started mission Startup 2020-10-07T20:03:09.320Z,1602100989.320 [Startup] Running Loop=1 2020-10-07T20:03:09.320Z,1602100989.320 [Startup](DEBUG): Aggregate::initialize Startup 2020-10-07T20:03:09.320Z,1602100989.320 [Startup:A.GoToSurface] Running Loop=1 2020-10-07T20:03:09.320Z,1602100989.320 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2020-10-07T20:03:09.321Z,1602100989.321 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2020-10-07T20:03:09.321Z,1602100989.321 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2020-10-07T20:03:09.322Z,1602100989.322 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2020-10-07T20:03:09.322Z,1602100989.322 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2020-10-07T20:03:09.322Z,1602100989.322 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2020-10-07T20:03:09.324Z,1602100989.324 [Startup:StartupSatComms] Running Loop=1 2020-10-07T20:03:09.324Z,1602100989.324 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2020-10-07T20:03:09.324Z,1602100989.324 [Startup:StartupSatComms:A] Running Loop=1 2020-10-07T20:03:09.784Z,1602100989.784 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2020-10-07T20:03:10.118Z,1602100990.118 [AMEcho](INFO): Powering up 2020-10-07T20:03:10.119Z,1602100990.119 [AMEcho](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2 2020-10-07T20:03:10.210Z,1602100990.210 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2 2020-10-07T20:03:11.322Z,1602100991.322 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,200309.00,A,3648.13412,N,12147.20985,W,0.019,198.09,071020,,,A*7A 2020-10-07T20:03:11.325Z,1602100991.325 [NAL9602](INFO): GPS fix at 20201007T200309: (36.802235, -121.786831) 2020-10-07T20:03:11.334Z,1602100991.334 [Startup:StartupSatComms:A] Stopped 2020-10-07T20:03:11.334Z,1602100991.334 [Startup:StartupSatComms:B] Running Loop=1 2020-10-07T20:03:11.768Z,1602100991.768 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2020-10-07T20:03:12.948Z,1602100992.948 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2020-10-07T20:03:24.346Z,1602101004.346 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2020-10-07T20:03:25.563Z,1602101005.563 [NAL9602](INFO): SBD MO Status=1, MOMSN=39110, MT Status=0, MTMSN=0 2020-10-07T20:03:25.615Z,1602101005.615 [NAL9602](INFO): Sent 39 bytes from file Logs/20201007T194202/Courier0019.lzma 2020-10-07T20:03:25.615Z,1602101005.615 [NAL9602](INFO): Packets left to send: 0 2020-10-07T20:03:35.711Z,1602101015.711 [NAL9602](INFO): SBD MO Status=1, MOMSN=39111, MT Status=0, MTMSN=0 2020-10-07T20:03:35.766Z,1602101015.766 [NAL9602](INFO): Sent 267 bytes from file Logs/20201007T200112/Courier0000.lzma 2020-10-07T20:03:35.766Z,1602101015.766 [NAL9602](INFO): Packets left to send: 0 2020-10-07T20:03:35.770Z,1602101015.770 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2020-10-07T20:03:49.684Z,1602101029.684 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2020-10-07T20:03:55.738Z,1602101035.738 [NAL9602](INFO): SBD MO Status=2, MOMSN=39112, MT Status=2, MTMSN=0 2020-10-07T20:03:55.738Z,1602101035.738 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2020-10-07T20:04:11.461Z,1602101051.461 [Startup:StartupSatComms:B](INFO): Timed out from 2020-10-07T20:03:11.3Z 2020-10-07T20:04:11.461Z,1602101051.461 [Startup:StartupSatComms:B] Stopped 2020-10-07T20:04:11.461Z,1602101051.461 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2020-10-07T20:04:11.461Z,1602101051.461 [Startup:StartupSatComms] Stopped 2020-10-07T20:04:11.462Z,1602101051.462 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2020-10-07T20:04:11.462Z,1602101051.462 [Startup](INFO): Completed Startup 2020-10-07T20:04:11.462Z,1602101051.462 [MissionManager](INFO): Startup is completed. 2020-10-07T20:04:11.463Z,1602101051.463 [MissionManager](INFO): Uninitializing Mission Startup 2020-10-07T20:04:11.463Z,1602101051.463 [Startup] Stopped 2020-10-07T20:04:11.463Z,1602101051.463 [Startup](DEBUG): Aggregate::uninitialize Startup 2020-10-07T20:04:11.463Z,1602101051.463 [Startup:A.GoToSurface] Stopped 2020-10-07T20:04:11.463Z,1602101051.463 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2020-10-07T20:04:11.860Z,1602101051.860 [MissionManager](IMPORTANT): Started mission Default 2020-10-07T20:04:11.860Z,1602101051.860 [Default] Running Loop=1 2020-10-07T20:04:11.860Z,1602101051.860 [Default](DEBUG): Aggregate::initialize Default 2020-10-07T20:04:11.860Z,1602101051.860 [Default:B.GoToSurface] Running Loop=1 2020-10-07T20:04:11.860Z,1602101051.860 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2020-10-07T20:04:11.861Z,1602101051.861 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2020-10-07T20:04:11.861Z,1602101051.861 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2020-10-07T20:04:11.861Z,1602101051.861 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2020-10-07T20:04:11.862Z,1602101051.862 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2020-10-07T20:04:11.862Z,1602101051.862 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2020-10-07T20:04:11.862Z,1602101051.862 [Default:A.Wait] Running Loop=1 2020-10-07T20:04:11.862Z,1602101051.862 [Default:A.Wait](DEBUG): Initialize Wait Component. 2020-10-07T20:04:12.425Z,1602101052.425 [AMEcho](INFO): Powering down 2020-10-07T20:04:13.466Z,1602101053.466 [AMEcho](INFO): Powering up 2020-10-07T20:04:13.467Z,1602101053.467 [AMEcho](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2 2020-10-07T20:04:13.562Z,1602101053.562 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2 2020-10-07T20:04:21.552Z,1602101061.552 [NAL9602](INFO): SBD MO Status=2, MOMSN=39112, MT Status=2, MTMSN=0 2020-10-07T20:04:21.552Z,1602101061.552 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2020-10-07T20:04:25.205Z,1602101065.205 [Default:A.Wait](INFO): Done Waiting. 2020-10-07T20:04:25.205Z,1602101065.205 [Default:A.Wait] Stopped 2020-10-07T20:04:25.205Z,1602101065.205 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2020-10-07T20:04:25.593Z,1602101065.593 [Default:CheckIn] Running Loop=1 2020-10-07T20:04:25.593Z,1602101065.593 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-10-07T20:04:25.594Z,1602101065.594 [Default:CheckIn:Read_GPS] Running Loop=1 2020-10-07T20:04:25.995Z,1602101065.995 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2020-10-07T20:04:27.606Z,1602101067.606 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,200425.00,A,3648.14072,N,12147.20886,W,0.078,20.87,071020,,,A*47 2020-10-07T20:04:27.608Z,1602101067.608 [NAL9602](INFO): GPS fix at 20201007T200425: (36.802345, -121.786814) 2020-10-07T20:04:27.618Z,1602101067.618 [Default:CheckIn:Read_GPS] Stopped 2020-10-07T20:04:27.618Z,1602101067.618 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-10-07T20:04:28.041Z,1602101068.041 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2020-10-07T20:04:55.743Z,1602101095.743 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004595 2020-10-07T20:05:03.368Z,1602101103.368 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20201007T200112/Courier0004.lzma 2020-10-07T20:05:04.025Z,1602101104.025 [NAL9602](INFO): SBD MO Status=1, MOMSN=39112, MT Status=0, MTMSN=0 2020-10-07T20:05:04.077Z,1602101104.077 [NAL9602](INFO): Sent 73 bytes from file Logs/20201007T200112/Courier0004.lzma 2020-10-07T20:05:04.077Z,1602101104.077 [NAL9602](INFO): Packets left to send: 0 2020-10-07T20:05:04.124Z,1602101104.124 [Default:CheckIn:Read_Iridium] Stopped 2020-10-07T20:05:04.124Z,1602101104.124 [Default:CheckIn:C.Wait] Running Loop=1 2020-10-07T20:05:04.124Z,1602101104.124 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-10-07T20:05:04.370Z,1602101104.370 [DataOverHttps](INFO): Moved sent file to Logs/20201007T200112/Courier0004.lzma.bak 2020-10-07T20:05:04.370Z,1602101104.370 [DataOverHttps](INFO): SBD MOMSN=12811741 2020-10-07T20:05:34.732Z,1602101134.732 [NAL9602](INFO): Not Powering down - fast GPS 2020-10-07T20:09:01.224Z,1602101341.224 [BPC1](INFO): Calculating totals. Valid battery stick count: 55. Valid reserve battery stick count: 5. 2020-10-07T20:09:01.227Z,1602101341.227 [BPC1](INFO): Received data from all battery sticks. 2020-10-07T20:10:04.655Z,1602101404.655 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-10-07T20:10:04.655Z,1602101404.655 [Default:CheckIn:C.Wait] Stopped 2020-10-07T20:10:04.655Z,1602101404.655 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-10-07T20:10:04.655Z,1602101404.655 [Default:CheckIn:D] Running Loop=1 2020-10-07T20:10:05.062Z,1602101405.062 [Default:CheckIn:D] Stopped 2020-10-07T20:10:05.062Z,1602101405.062 [Default:CheckIn:E] Running Loop=1 2020-10-07T20:10:05.458Z,1602101405.458 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 5.886698 min 2020-10-07T20:10:05.458Z,1602101405.458 [Default:CheckIn:E] Stopped 2020-10-07T20:10:05.458Z,1602101405.458 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-10-07T20:10:05.458Z,1602101405.458 [Default:CheckIn] Stopped 2020-10-07T20:10:05.458Z,1602101405.458 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-10-07T20:10:05.458Z,1602101405.458 [Default:CheckIn](INFO): Running loop #2 2020-10-07T20:10:05.458Z,1602101405.458 [Default:CheckIn] Running Loop=2 2020-10-07T20:10:05.458Z,1602101405.458 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-10-07T20:10:05.458Z,1602101405.458 [Default:CheckIn:Read_GPS] Running Loop=1 2020-10-07T20:10:07.474Z,1602101407.474 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,201005.00,A,3648.13970,N,12147.20636,W,0.019,20.87,071020,,,A*4E 2020-10-07T20:10:07.476Z,1602101407.476 [NAL9602](INFO): GPS fix at 20201007T201005: (36.802328, -121.786773) 2020-10-07T20:10:07.485Z,1602101407.485 [Default:CheckIn:Read_GPS] Stopped 2020-10-07T20:10:07.485Z,1602101407.485 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-10-07T20:10:15.176Z,1602101415.176 [DataOverHttps](INFO): Sending 202 bytes from file Logs/20201007T200112/Courier0007.lzma 2020-10-07T20:10:16.179Z,1602101416.179 [DataOverHttps](INFO): Moved sent file to Logs/20201007T200112/Courier0007.lzma.bak 2020-10-07T20:10:16.179Z,1602101416.179 [DataOverHttps](INFO): SBD MOMSN=12811779 2020-10-07T20:10:31.896Z,1602101431.896 [DataOverHttps](INFO): Sending 227 bytes from file Logs/20201007T194202/Express0020.lzma 2020-10-07T20:10:32.898Z,1602101432.898 [DataOverHttps](INFO): Moved sent file to Logs/20201007T194202/Express0020.lzma.bak 2020-10-07T20:10:32.899Z,1602101432.899 [DataOverHttps](INFO): SBD MOMSN=12811800 2020-10-07T20:10:36.592Z,1602101436.592 [NAL9602](INFO): SBD MO Status=0, MOMSN=39113, MT Status=0, MTMSN=0 2020-10-07T20:10:36.592Z,1602101436.592 [NAL9602](INFO): No messages in MT queue 2020-10-07T20:10:50.158Z,1602101450.158 [DataOverHttps](INFO): Sending 917 bytes from file Logs/20201007T200112/Express0001.lzma 2020-10-07T20:10:51.158Z,1602101451.158 [DataOverHttps](INFO): Moved sent file to Logs/20201007T200112/Express0001.lzma.bak 2020-10-07T20:10:51.158Z,1602101451.158 [DataOverHttps](INFO): SBD MOMSN=12811808 2020-10-07T20:11:06.820Z,1602101466.820 [DataOverHttps](INFO): Sending 262 bytes from file Logs/20201007T200112/Express0005.lzma 2020-10-07T20:11:07.298Z,1602101467.298 [NAL9602](INFO): Not Powering down - fast GPS 2020-10-07T20:11:07.823Z,1602101467.823 [DataOverHttps](INFO): Moved sent file to Logs/20201007T200112/Express0005.lzma.bak 2020-10-07T20:11:07.824Z,1602101467.824 [DataOverHttps](INFO): SBD MOMSN=12811830 2020-10-07T20:11:23.409Z,1602101483.409 [DataOverHttps](INFO): Sending 160 bytes from file Logs/20201007T200112/Express0008.lzma 2020-10-07T20:11:24.410Z,1602101484.410 [DataOverHttps](INFO): Moved sent file to Logs/20201007T200112/Express0008.lzma.bak 2020-10-07T20:11:24.411Z,1602101484.411 [DataOverHttps](INFO): SBD MOMSN=12811841 2020-10-07T20:11:25.891Z,1602101485.891 [Default:CheckIn:Read_Iridium] Stopped 2020-10-07T20:11:25.892Z,1602101485.892 [Default:CheckIn:C.Wait] Running Loop=1 2020-10-07T20:11:25.892Z,1602101485.892 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-10-07T20:13:34.142Z,1602101614.142 [DataOverHttps](IMPORTANT): SBD MTMSN=20201007T201332 2020-10-07T20:13:41.601Z,1602101621.601 [DataOverHttps](INFO): Received command:Ibit 2020-10-07T20:13:41.634Z,1602101621.634 [CommandLine](IMPORTANT): got command ibit 2020-10-07T20:13:41.664Z,1602101621.664 [IBIT](IMPORTANT): Beginning Initiated BIT 2020-10-07T20:13:41.664Z,1602101621.664 [IBIT](IMPORTANT): Beginning control surface checks. 2020-10-07T20:13:41.700Z,1602101621.700 [CBIT](IMPORTANT): Beginning ground fault scan 2020-10-07T20:13:43.253Z,1602101623.253 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,201342.00,A,3648.13909,N,12147.20567,W,0.039,20.87,071020,,,D*40 2020-10-07T20:13:43.255Z,1602101623.255 [NAL9602](INFO): GPS fix at 20201007T201342: (36.802318, -121.786761) 2020-10-07T20:13:52.566Z,1602101632.566 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.005838 CHAN A1 (24V): 0.004108 CHAN A2 (12V): -0.002830 CHAN A3 (5V): -0.001913 CHAN B0 (3.3V): -0.000610 CHAN B1 (3.15aV): -0.000790 CHAN B2 (3.15bV): -0.000723 CHAN B3 (GND): -0.000265 OPEN: 0.004599 Full Scale Calc: 4.765 mA, -1.589 mA 2020-10-07T20:14:04.666Z,1602101644.666 [NAL9602](INFO): SBD MO Status=2, MOMSN=39114, MT Status=2, MTMSN=0 2020-10-07T20:14:04.666Z,1602101644.666 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2020-10-07T20:14:28.105Z,1602101668.105 [IBIT](IMPORTANT): Communications Status: Fix Status: 1 Iridium Signal Strength: 5 Latitude: 36.802319 Longitude: -121.786758 2020-10-07T20:14:28.512Z,1602101668.512 [IBIT](IMPORTANT): Battery Status: Battery Charge (AH): 0.000000 Voltage: 16.650999 2020-10-07T20:14:28.513Z,1602101668.513 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah 2020-10-07T20:14:28.513Z,1602101668.513 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V 2020-10-07T20:14:28.919Z,1602101668.919 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 % 2020-10-07T20:14:28.920Z,1602101668.920 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi 2020-10-07T20:14:28.920Z,1602101668.920 [IBIT](IMPORTANT): Pressure:8.393786 PSI 2020-10-07T20:14:28.920Z,1602101668.920 [IBIT](IMPORTANT): Humidity:19.777805 % 2020-10-07T20:14:29.316Z,1602101669.316 [IBIT](IMPORTANT): Vehicle Pitch:-1.311603 degrees 2020-10-07T20:14:29.317Z,1602101669.317 [IBIT](IMPORTANT): Vehicle Roll:-0.292759 degrees 2020-10-07T20:14:29.317Z,1602101669.317 [IBIT](IMPORTANT): Vehicle Heading:204.481400 degrees 2020-10-07T20:14:29.732Z,1602101669.732 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m 2020-10-07T20:14:29.732Z,1602101669.732 [IBIT](IMPORTANT): buoyancyNeutral: 261.000000 cc 2020-10-07T20:14:29.732Z,1602101669.732 [IBIT](IMPORTANT): massDefault: 0.840000 cm 2020-10-07T20:14:29.733Z,1602101669.733 [IBIT](IMPORTANT): stopDepth: 265.000000 m 2020-10-07T20:14:29.733Z,1602101669.733 [IBIT](IMPORTANT): abortDepth: 300.000000 m 2020-10-07T20:14:29.733Z,1602101669.733 [IBIT](IMPORTANT): IBIT PASSED 2020-10-07T20:14:39.811Z,1602101679.811 [NAL9602](INFO): SBD MO Status=0, MOMSN=39114, MT Status=0, MTMSN=0 2020-10-07T20:14:39.812Z,1602101679.812 [NAL9602](INFO): No messages in MT queue 2020-10-07T20:15:10.514Z,1602101710.514 [NAL9602](INFO): Not Powering down - fast GPS 2020-10-07T20:16:26.475Z,1602101786.475 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-10-07T20:16:26.475Z,1602101786.475 [Default:CheckIn:C.Wait] Stopped 2020-10-07T20:16:26.475Z,1602101786.475 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-10-07T20:16:26.475Z,1602101786.475 [Default:CheckIn:D] Running Loop=1 2020-10-07T20:16:26.881Z,1602101786.881 [Default:CheckIn:D] Stopped 2020-10-07T20:16:26.881Z,1602101786.881 [Default:CheckIn:E] Running Loop=1 2020-10-07T20:16:27.294Z,1602101787.294 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 12.250341 min 2020-10-07T20:16:27.294Z,1602101787.294 [Default:CheckIn:E] Stopped 2020-10-07T20:16:27.294Z,1602101787.294 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-10-07T20:16:27.294Z,1602101787.294 [Default:CheckIn] Stopped 2020-10-07T20:16:27.294Z,1602101787.294 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-10-07T20:16:27.294Z,1602101787.294 [Default:CheckIn](INFO): Running loop #3 2020-10-07T20:16:27.294Z,1602101787.294 [Default:CheckIn] Running Loop=3 2020-10-07T20:16:27.294Z,1602101787.294 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-10-07T20:16:27.294Z,1602101787.294 [Default:CheckIn:Read_GPS] Running Loop=1 2020-10-07T20:16:29.298Z,1602101789.298 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,201628.00,A,3648.14536,N,12147.19758,W,0.486,331.19,071020,,,A*7B 2020-10-07T20:16:29.300Z,1602101789.300 [NAL9602](INFO): GPS fix at 20201007T201628: (36.802423, -121.786626) 2020-10-07T20:16:29.330Z,1602101789.330 [Default:CheckIn:Read_GPS] Stopped 2020-10-07T20:16:29.330Z,1602101789.330 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-10-07T20:16:36.532Z,1602101796.532 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20201007T200112/Courier0010.lzma 2020-10-07T20:16:37.534Z,1602101797.534 [DataOverHttps](INFO): Moved sent file to Logs/20201007T200112/Courier0010.lzma.bak 2020-10-07T20:16:37.535Z,1602101797.535 [DataOverHttps](INFO): SBD MOMSN=12811884 2020-10-07T20:16:55.510Z,1602101815.510 [DataOverHttps](INFO): Sending 810 bytes from file Logs/20201007T200112/Express0011.lzma 2020-10-07T20:16:56.506Z,1602101816.506 [DataOverHttps](INFO): Moved sent file to Logs/20201007T200112/Express0011.lzma.bak 2020-10-07T20:16:56.507Z,1602101816.507 [DataOverHttps](INFO): SBD MOMSN=12811887 2020-10-07T20:16:56.791Z,1602101816.791 [NAL9602](INFO): SBD MO Status=0, MOMSN=39115, MT Status=0, MTMSN=0 2020-10-07T20:16:56.791Z,1602101816.791 [NAL9602](INFO): No messages in MT queue 2020-10-07T20:16:58.011Z,1602101818.011 [Default:CheckIn:Read_Iridium] Stopped 2020-10-07T20:16:58.011Z,1602101818.011 [Default:CheckIn:C.Wait] Running Loop=1 2020-10-07T20:16:58.011Z,1602101818.011 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-10-07T20:17:27.495Z,1602101847.495 [NAL9602](INFO): Not Powering down - fast GPS 2020-10-07T20:21:58.619Z,1602102118.619 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-10-07T20:21:58.619Z,1602102118.619 [Default:CheckIn:C.Wait] Stopped 2020-10-07T20:21:58.619Z,1602102118.619 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-10-07T20:21:58.619Z,1602102118.619 [Default:CheckIn:D] Running Loop=1 2020-10-07T20:21:59.012Z,1602102119.012 [Default:CheckIn:D] Stopped 2020-10-07T20:21:59.012Z,1602102119.012 [Default:CheckIn:E] Running Loop=1 2020-10-07T20:21:59.419Z,1602102119.419 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 17.785870 min 2020-10-07T20:21:59.419Z,1602102119.419 [Default:CheckIn:E] Stopped 2020-10-07T20:21:59.420Z,1602102119.420 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-10-07T20:21:59.420Z,1602102119.420 [Default:CheckIn] Stopped 2020-10-07T20:21:59.420Z,1602102119.420 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-10-07T20:21:59.420Z,1602102119.420 [Default:CheckIn](INFO): Running loop #4 2020-10-07T20:21:59.420Z,1602102119.420 [Default:CheckIn] Running Loop=4 2020-10-07T20:21:59.420Z,1602102119.420 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-10-07T20:21:59.420Z,1602102119.420 [Default:CheckIn:Read_GPS] Running Loop=1 2020-10-07T20:22:01.442Z,1602102121.442 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,202200.00,A,3648.45193,N,12147.11234,W,5.132,355.96,071020,,,D*71 2020-10-07T20:22:01.444Z,1602102121.444 [NAL9602](INFO): GPS fix at 20201007T202200: (36.807532, -121.785206) 2020-10-07T20:22:01.455Z,1602102121.455 [Default:CheckIn:Read_GPS] Stopped 2020-10-07T20:22:01.455Z,1602102121.455 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-10-07T20:22:09.184Z,1602102129.184 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20201007T200112/Courier0015.lzma 2020-10-07T20:22:10.186Z,1602102130.186 [DataOverHttps](INFO): Moved sent file to Logs/20201007T200112/Courier0015.lzma.bak 2020-10-07T20:22:10.187Z,1602102130.187 [DataOverHttps](INFO): SBD MOMSN=12811991 2020-10-07T20:22:13.958Z,1602102133.958 [NAL9602](INFO): SBD MO Status=0, MOMSN=39116, MT Status=0, MTMSN=0 2020-10-07T20:22:13.958Z,1602102133.958 [NAL9602](INFO): No messages in MT queue 2020-10-07T20:22:25.792Z,1602102145.792 [DataOverHttps](INFO): Sending 145 bytes from file Logs/20201007T200112/Express0017.lzma 2020-10-07T20:22:26.794Z,1602102146.794 [DataOverHttps](INFO): Moved sent file to Logs/20201007T200112/Express0017.lzma.bak 2020-10-07T20:22:26.795Z,1602102146.795 [DataOverHttps](INFO): SBD MOMSN=12811994 2020-10-07T20:22:28.511Z,1602102148.511 [Default:CheckIn:Read_Iridium] Stopped 2020-10-07T20:22:28.511Z,1602102148.511 [Default:CheckIn:C.Wait] Running Loop=1 2020-10-07T20:22:28.511Z,1602102148.511 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-10-07T20:22:44.658Z,1602102164.658 [NAL9602](INFO): Not Powering down - fast GPS 2020-10-07T20:27:29.095Z,1602102449.095 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-10-07T20:27:29.095Z,1602102449.095 [Default:CheckIn:C.Wait] Stopped 2020-10-07T20:27:29.095Z,1602102449.095 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-10-07T20:27:29.095Z,1602102449.095 [Default:CheckIn:D] Running Loop=1 2020-10-07T20:27:29.494Z,1602102449.494 [Default:CheckIn:D] Stopped 2020-10-07T20:27:29.494Z,1602102449.494 [Default:CheckIn:E] Running Loop=1 2020-10-07T20:27:29.895Z,1602102449.895 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 23.293903 min 2020-10-07T20:27:29.895Z,1602102449.895 [Default:CheckIn:E] Stopped 2020-10-07T20:27:29.895Z,1602102449.895 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-10-07T20:27:29.895Z,1602102449.895 [Default:CheckIn] Stopped 2020-10-07T20:27:29.895Z,1602102449.895 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-10-07T20:27:29.895Z,1602102449.895 [Default:CheckIn](INFO): Running loop #5 2020-10-07T20:27:29.896Z,1602102449.896 [Default:CheckIn] Running Loop=5 2020-10-07T20:27:29.896Z,1602102449.896 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-10-07T20:27:29.896Z,1602102449.896 [Default:CheckIn:Read_GPS] Running Loop=1 2020-10-07T20:27:31.913Z,1602102451.913 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,202730.00,A,3648.21092,N,12148.45594,W,20.994,258.17,071020,,,D*40 2020-10-07T20:27:31.915Z,1602102451.915 [NAL9602](INFO): GPS fix at 20201007T202730: (36.803515, -121.807599) 2020-10-07T20:27:31.924Z,1602102451.924 [Default:CheckIn:Read_GPS] Stopped 2020-10-07T20:27:31.924Z,1602102451.924 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-10-07T20:27:39.172Z,1602102459.172 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20201007T200112/Courier0019.lzma 2020-10-07T20:27:40.174Z,1602102460.174 [DataOverHttps](INFO): Moved sent file to Logs/20201007T200112/Courier0019.lzma.bak 2020-10-07T20:27:40.175Z,1602102460.175 [DataOverHttps](INFO): SBD MOMSN=12811998 2020-10-07T20:27:44.071Z,1602102464.071 [NAL9602](INFO): SBD MO Status=0, MOMSN=39117, MT Status=0, MTMSN=0 2020-10-07T20:27:44.071Z,1602102464.071 [NAL9602](INFO): No messages in MT queue 2020-10-07T20:27:55.800Z,1602102475.800 [DataOverHttps](INFO): Sending 143 bytes from file Logs/20201007T200112/Express0020.lzma 2020-10-07T20:27:56.802Z,1602102476.802 [DataOverHttps](INFO): Moved sent file to Logs/20201007T200112/Express0020.lzma.bak 2020-10-07T20:27:56.803Z,1602102476.803 [DataOverHttps](INFO): SBD MOMSN=12812001 2020-10-07T20:27:58.639Z,1602102478.639 [Default:CheckIn:Read_Iridium] Stopped 2020-10-07T20:27:58.639Z,1602102478.639 [Default:CheckIn:C.Wait] Running Loop=1 2020-10-07T20:27:58.640Z,1602102478.640 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-10-07T20:28:14.773Z,1602102494.773 [NAL9602](INFO): Not Powering down - fast GPS 2020-10-07T20:32:59.202Z,1602102779.202 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-10-07T20:32:59.202Z,1602102779.202 [Default:CheckIn:C.Wait] Stopped 2020-10-07T20:32:59.203Z,1602102779.203 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-10-07T20:32:59.203Z,1602102779.203 [Default:CheckIn:D] Running Loop=1 2020-10-07T20:32:59.614Z,1602102779.614 [Default:CheckIn:D] Stopped 2020-10-07T20:32:59.614Z,1602102779.614 [Default:CheckIn:E] Running Loop=1 2020-10-07T20:33:00.010Z,1602102780.010 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 28.795898 min 2020-10-07T20:33:00.010Z,1602102780.010 [Default:CheckIn:E] Stopped 2020-10-07T20:33:00.010Z,1602102780.010 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-10-07T20:33:00.010Z,1602102780.010 [Default:CheckIn] Stopped 2020-10-07T20:33:00.010Z,1602102780.010 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-10-07T20:33:00.010Z,1602102780.010 [Default:CheckIn](INFO): Running loop #6 2020-10-07T20:33:00.010Z,1602102780.010 [Default:CheckIn] Running Loop=6 2020-10-07T20:33:00.010Z,1602102780.010 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-10-07T20:33:00.010Z,1602102780.010 [Default:CheckIn:Read_GPS] Running Loop=1 2020-10-07T20:33:02.022Z,1602102782.022 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,203300.00,A,3647.84309,N,12150.36498,W,16.814,263.61,071020,,,D*42 2020-10-07T20:33:02.024Z,1602102782.024 [NAL9602](INFO): GPS fix at 20201007T203300: (36.797385, -121.839416) 2020-10-07T20:33:02.033Z,1602102782.033 [Default:CheckIn:Read_GPS] Stopped 2020-10-07T20:33:02.034Z,1602102782.034 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-10-07T20:33:09.812Z,1602102789.812 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20201007T200112/Courier0022.lzma 2020-10-07T20:33:10.814Z,1602102790.814 [DataOverHttps](INFO): Moved sent file to Logs/20201007T200112/Courier0022.lzma.bak 2020-10-07T20:33:10.815Z,1602102790.815 [DataOverHttps](INFO): SBD MOMSN=12812086 2020-10-07T20:33:18.591Z,1602102798.591 [NAL9602](INFO): SBD MO Status=0, MOMSN=39118, MT Status=0, MTMSN=0 2020-10-07T20:33:18.591Z,1602102798.591 [NAL9602](INFO): No messages in MT queue 2020-10-07T20:33:26.524Z,1602102806.524 [DataOverHttps](INFO): Sending 146 bytes from file Logs/20201007T200112/Express0023.lzma 2020-10-07T20:33:27.526Z,1602102807.526 [DataOverHttps](INFO): Moved sent file to Logs/20201007T200112/Express0023.lzma.bak 2020-10-07T20:33:27.527Z,1602102807.527 [DataOverHttps](INFO): SBD MOMSN=12812089 2020-10-07T20:33:29.108Z,1602102809.108 [Default:CheckIn:Read_Iridium] Stopped 2020-10-07T20:33:29.108Z,1602102809.108 [Default:CheckIn:C.Wait] Running Loop=1 2020-10-07T20:33:29.108Z,1602102809.108 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-10-07T20:33:49.285Z,1602102829.285 [NAL9602](INFO): Not Powering down - fast GPS 2020-10-07T20:37:33.309Z,1602103053.309 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2020-10-07T20:38:04.441Z,1602103084.441 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2020-10-07T20:38:29.690Z,1602103109.690 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-10-07T20:38:29.691Z,1602103109.691 [Default:CheckIn:C.Wait] Stopped 2020-10-07T20:38:29.691Z,1602103109.691 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-10-07T20:38:29.691Z,1602103109.691 [Default:CheckIn:D] Running Loop=1 2020-10-07T20:38:30.100Z,1602103110.100 [Default:CheckIn:D] Stopped 2020-10-07T20:38:30.100Z,1602103110.100 [Default:CheckIn:E] Running Loop=1 2020-10-07T20:38:30.494Z,1602103110.494 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 34.304000 min 2020-10-07T20:38:30.494Z,1602103110.494 [Default:CheckIn:E] Stopped 2020-10-07T20:38:30.494Z,1602103110.494 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-10-07T20:38:30.495Z,1602103110.495 [Default:CheckIn] Stopped 2020-10-07T20:38:30.495Z,1602103110.495 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-10-07T20:38:30.495Z,1602103110.495 [Default:CheckIn](INFO): Running loop #7 2020-10-07T20:38:30.495Z,1602103110.495 [Default:CheckIn] Running Loop=7 2020-10-07T20:38:30.495Z,1602103110.495 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-10-07T20:38:30.495Z,1602103110.495 [Default:CheckIn:Read_GPS] Running Loop=1 2020-10-07T20:38:32.510Z,1602103112.510 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,203831.00,A,3647.84702,N,12150.77483,W,1.458,102.94,071020,,,D*77 2020-10-07T20:38:32.512Z,1602103112.512 [NAL9602](INFO): GPS fix at 20201007T203831: (36.797450, -121.846247) 2020-10-07T20:38:32.522Z,1602103112.522 [Default:CheckIn:Read_GPS] Stopped 2020-10-07T20:38:32.522Z,1602103112.522 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-10-07T20:38:35.565Z,1602103115.565 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2020-10-07T20:38:50.287Z,1602103130.287 [NAL9602](INFO): SBD MO Status=0, MOMSN=39119, MT Status=0, MTMSN=0 2020-10-07T20:38:50.287Z,1602103130.287 [NAL9602](INFO): No messages in MT queue 2020-10-07T20:38:51.988Z,1602103131.988 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20201007T200112/Courier0025.lzma 2020-10-07T20:38:52.990Z,1602103132.990 [DataOverHttps](INFO): Moved sent file to Logs/20201007T200112/Courier0025.lzma.bak 2020-10-07T20:38:52.991Z,1602103132.991 [DataOverHttps](IMPORTANT): SBD MOMSN=12812095, MTMSN=20201007T203851 2020-10-07T20:39:00.352Z,1602103140.352 [DataOverHttps](INFO): Received command:restart logs 2020-10-07T20:39:00.364Z,1602103140.364 [CommandLine](IMPORTANT): got command restart logs