2020-12-01T15:51:47.033Z,1606837907.033 [Supervisor](DEBUG): Initializing supervisor. 2020-12-01T15:51:47.035Z,1606837907.035 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2020-12-01T15:51:47.036Z,1606837907.036 [SyncHandler](INFO): Protected caller Thread ID is 5458 2020-12-01T15:51:47.036Z,1606837907.036 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2020-12-01T15:51:47.037Z,1606837907.037 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2020-12-01T15:51:47.038Z,1606837907.038 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 5459 2020-12-01T15:51:47.041Z,1606837907.041 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2020-12-01T15:51:47.057Z,1606837907.057 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2020-12-01T15:51:47.058Z,1606837907.058 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2020-12-01T15:51:47.058Z,1606837907.058 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 5460 2020-12-01T15:51:47.059Z,1606837907.059 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2020-12-01T15:51:47.060Z,1606837907.060 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2020-12-01T15:51:47.060Z,1606837907.060 [logger ThreadHandler](INFO): Protected caller Thread ID is 5461 2020-12-01T15:51:47.062Z,1606837907.062 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2020-12-01T15:51:47.063Z,1606837907.063 [Supervisor](INFO): Looking for Config files in directory: Config/ 2020-12-01T15:51:47.064Z,1606837907.064 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2020-12-01T15:51:47.157Z,1606837907.157 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2020-12-01T15:51:47.158Z,1606837907.158 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2020-12-01T15:51:47.726Z,1606837907.726 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2020-12-01T15:51:47.727Z,1606837907.727 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg 2020-12-01T15:51:47.920Z,1606837907.920 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock 2020-12-01T15:51:47.920Z,1606837907.920 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2020-12-01T15:51:48.016Z,1606837908.016 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2020-12-01T15:51:48.016Z,1606837908.016 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2020-12-01T15:51:48.117Z,1606837908.117 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2020-12-01T15:51:48.117Z,1606837908.117 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2020-12-01T15:51:48.196Z,1606837908.196 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2020-12-01T15:51:48.330Z,1606837908.330 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2020-12-01T15:51:48.331Z,1606837908.331 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2020-12-01T15:51:48.610Z,1606837908.610 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2020-12-01T15:51:48.610Z,1606837908.610 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2020-12-01T15:51:49.103Z,1606837909.103 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2020-12-01T15:51:49.103Z,1606837909.103 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2020-12-01T15:51:49.243Z,1606837909.243 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2020-12-01T15:51:49.243Z,1606837909.243 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2020-12-01T15:51:49.425Z,1606837909.425 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2020-12-01T15:51:49.425Z,1606837909.425 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2020-12-01T15:51:49.899Z,1606837909.899 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2020-12-01T15:51:49.899Z,1606837909.899 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2020-12-01T15:51:50.108Z,1606837910.108 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2020-12-01T15:51:50.109Z,1606837910.109 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2020-12-01T15:51:50.301Z,1606837910.301 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2020-12-01T15:51:50.302Z,1606837910.302 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2020-12-01T15:51:50.701Z,1606837910.701 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2020-12-01T15:51:50.702Z,1606837910.702 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2020-12-01T15:51:51.013Z,1606837911.013 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2020-12-01T15:51:51.015Z,1606837911.015 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-pontus/ 2020-12-01T15:51:51.016Z,1606837911.016 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/secure.cfg 2020-12-01T15:51:51.096Z,1606837911.096 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Sensor.cfg 2020-12-01T15:51:51.245Z,1606837911.245 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Servo.cfg 2020-12-01T15:51:51.349Z,1606837911.349 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Simulator.cfg 2020-12-01T15:51:51.430Z,1606837911.430 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/logger.cfg 2020-12-01T15:51:51.521Z,1606837911.521 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/vehicle.cfg 2020-12-01T15:51:51.707Z,1606837911.707 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Battery.cfg 2020-12-01T15:51:52.001Z,1606837912.001 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2020-12-01T15:51:52.001Z,1606837912.001 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Navigation.cfg 2020-12-01T15:51:52.175Z,1606837912.175 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/BIT.cfg 2020-12-01T15:51:52.331Z,1606837912.331 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Science.cfg 2020-12-01T15:51:52.604Z,1606837912.604 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Control.cfg 2020-12-01T15:51:52.730Z,1606837912.730 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2020-12-01T15:51:52.742Z,1606837912.742 [Module Loader](DEBUG): Loading Module at Modules/Dock.so 2020-12-01T15:51:52.882Z,1606837912.882 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking) 2020-12-01T15:51:52.883Z,1606837912.883 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2020-12-01T15:51:53.018Z,1606837913.018 [VerticalControl](DEBUG): Construct VerticalControl. 2020-12-01T15:51:53.074Z,1606837913.074 [VerticalControl] Loaded 2020-12-01T15:51:53.074Z,1606837913.074 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2020-12-01T15:51:53.075Z,1606837913.075 [HorizontalControl](DEBUG): Construct HorizontalControl. 2020-12-01T15:51:53.111Z,1606837913.111 [HorizontalControl] Loaded 2020-12-01T15:51:53.111Z,1606837913.111 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2020-12-01T15:51:53.112Z,1606837913.112 [SpeedControl](DEBUG): Construct SpeedControl. 2020-12-01T15:51:53.115Z,1606837913.115 [SpeedControl] Loaded 2020-12-01T15:51:53.115Z,1606837913.115 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2020-12-01T15:51:53.116Z,1606837913.116 [LoopControl](DEBUG): Construct LoopControl. 2020-12-01T15:51:53.116Z,1606837913.116 [LoopControl] Loaded 2020-12-01T15:51:53.116Z,1606837913.116 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2020-12-01T15:51:53.117Z,1606837913.117 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2020-12-01T15:51:53.117Z,1606837913.117 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2020-12-01T15:51:53.158Z,1606837913.158 [DepthRateCalculator] Loaded 2020-12-01T15:51:53.158Z,1606837913.158 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2020-12-01T15:51:53.160Z,1606837913.160 [PitchRateCalculator] Loaded 2020-12-01T15:51:53.161Z,1606837913.161 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2020-12-01T15:51:53.168Z,1606837913.168 [SpeedCalculator] Loaded 2020-12-01T15:51:53.169Z,1606837913.169 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2020-12-01T15:51:53.179Z,1606837913.179 [TempGradientCalculator] Loaded 2020-12-01T15:51:53.180Z,1606837913.180 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2020-12-01T15:51:53.182Z,1606837913.182 [YawRateCalculator] Loaded 2020-12-01T15:51:53.182Z,1606837913.182 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2020-12-01T15:51:53.197Z,1606837913.197 [ElevatorOffsetCalculator] Loaded 2020-12-01T15:51:53.197Z,1606837913.197 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2020-12-01T15:51:53.197Z,1606837913.197 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2020-12-01T15:51:53.198Z,1606837913.198 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2020-12-01T15:51:53.224Z,1606837913.224 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2020-12-01T15:51:53.225Z,1606837913.225 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2020-12-01T15:51:53.313Z,1606837913.313 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2020-12-01T15:51:53.314Z,1606837913.314 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2020-12-01T15:51:53.614Z,1606837913.614 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2020-12-01T15:51:53.614Z,1606837913.614 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2020-12-01T15:51:53.717Z,1606837913.717 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2020-12-01T15:51:53.718Z,1606837913.718 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2020-12-01T15:51:54.035Z,1606837914.035 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_orientation 2020-12-01T15:51:54.038Z,1606837914.038 [AHRS_M2](INFO): created writer for : platform_orientation 2020-12-01T15:51:54.040Z,1606837914.040 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_magnetic_orientation 2020-12-01T15:51:54.043Z,1606837914.043 [AHRS_M2](INFO): created writer for : platform_magnetic_orientation 2020-12-01T15:51:54.043Z,1606837914.043 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_pitch_angle 2020-12-01T15:51:54.046Z,1606837914.046 [AHRS_M2](INFO): created writer for : platform_pitch_angle 2020-12-01T15:51:54.046Z,1606837914.046 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_roll_angle 2020-12-01T15:51:54.049Z,1606837914.049 [AHRS_M2](INFO): created writer for : platform_roll_angle 2020-12-01T15:51:54.085Z,1606837914.085 [AHRS_M2] Loaded 2020-12-01T15:51:54.085Z,1606837914.085 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2020-12-01T15:51:54.155Z,1606837914.155 [DataOverHttps] Loaded 2020-12-01T15:51:54.155Z,1606837914.155 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2020-12-01T15:51:54.157Z,1606837914.157 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4090F4E0 2020-12-01T15:51:54.157Z,1606837914.157 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 5543 2020-12-01T15:51:54.174Z,1606837914.174 [Depth_Keller] Loaded 2020-12-01T15:51:54.174Z,1606837914.174 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2020-12-01T15:51:54.177Z,1606837914.177 [DropWeight] Loaded 2020-12-01T15:51:54.177Z,1606837914.177 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2020-12-01T15:51:54.231Z,1606837914.231 [NAL9602] Loaded 2020-12-01T15:51:54.231Z,1606837914.231 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2020-12-01T15:51:54.256Z,1606837914.256 [Onboard] Loaded 2020-12-01T15:51:54.257Z,1606837914.257 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread. 2020-12-01T15:51:54.258Z,1606837914.258 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 4093F4E0 2020-12-01T15:51:54.258Z,1606837914.258 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 5544 2020-12-01T15:51:54.268Z,1606837914.268 [Radio_Surface] Loaded 2020-12-01T15:51:54.269Z,1606837914.269 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2020-12-01T15:51:54.270Z,1606837914.270 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4096F4E0 2020-12-01T15:51:54.270Z,1606837914.270 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 5545 2020-12-01T15:51:54.296Z,1606837914.296 [RDI_Pathfinder] Loaded 2020-12-01T15:51:54.296Z,1606837914.296 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread. 2020-12-01T15:51:54.367Z,1606837914.367 [DAT] Loaded 2020-12-01T15:51:54.368Z,1606837914.368 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread. 2020-12-01T15:51:55.156Z,1606837915.156 [BPC1] Loaded 2020-12-01T15:51:55.156Z,1606837915.156 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2020-12-01T15:51:55.157Z,1606837915.157 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2020-12-01T15:51:55.157Z,1606837915.157 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2020-12-01T15:51:55.237Z,1606837915.237 [DeadReckonUsingMultipleVelocitySources] Loaded 2020-12-01T15:51:55.237Z,1606837915.237 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2020-12-01T15:51:55.247Z,1606837915.247 [NavChart] Loaded 2020-12-01T15:51:55.247Z,1606837915.247 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2020-12-01T15:51:55.251Z,1606837915.251 [UniversalFixResidualReporter] Loaded 2020-12-01T15:51:55.251Z,1606837915.251 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2020-12-01T15:51:55.252Z,1606837915.252 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2020-12-01T15:51:55.253Z,1606837915.253 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2020-12-01T15:51:55.391Z,1606837915.391 [SBIT](DEBUG): Construct Startup Built In Test. 2020-12-01T15:51:55.399Z,1606837915.399 [SBIT] Loaded 2020-12-01T15:51:55.399Z,1606837915.399 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2020-12-01T15:51:55.400Z,1606837915.400 [IBIT](DEBUG): Construct Initiated Built In Test. 2020-12-01T15:51:55.412Z,1606837915.412 [IBIT] Loaded 2020-12-01T15:51:55.413Z,1606837915.413 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2020-12-01T15:51:55.415Z,1606837915.415 [CBIT](DEBUG): Construct Continuous Built In Test. 2020-12-01T15:51:55.508Z,1606837915.508 [CBIT] Loaded 2020-12-01T15:51:55.509Z,1606837915.509 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2020-12-01T15:51:55.509Z,1606837915.509 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2020-12-01T15:51:55.510Z,1606837915.510 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2020-12-01T15:51:55.624Z,1606837915.624 [BuoyancyServo] Loaded 2020-12-01T15:51:55.625Z,1606837915.625 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2020-12-01T15:51:55.641Z,1606837915.641 [ElevatorServo] Loaded 2020-12-01T15:51:55.642Z,1606837915.642 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2020-12-01T15:51:55.657Z,1606837915.657 [MassServo] Loaded 2020-12-01T15:51:55.657Z,1606837915.657 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2020-12-01T15:51:55.672Z,1606837915.672 [RudderServo] Loaded 2020-12-01T15:51:55.673Z,1606837915.673 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2020-12-01T15:51:55.687Z,1606837915.687 [ThrusterServo] Loaded 2020-12-01T15:51:55.688Z,1606837915.688 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2020-12-01T15:51:55.688Z,1606837915.688 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2020-12-01T15:51:55.689Z,1606837915.689 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2020-12-01T15:51:55.707Z,1606837915.707 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2020-12-01T15:51:55.708Z,1606837915.708 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2020-12-01T15:51:55.925Z,1606837915.925 [BackSeatDriver] Loaded 2020-12-01T15:51:55.925Z,1606837915.925 [ComponentRegistry](DEBUG): Component "BackSeatDriver" handled in its own thread. 2020-12-01T15:51:55.927Z,1606837915.927 [BackSeatDriver ThreadHandler](DEBUG): Created PCaller Thread at 40B074E0 2020-12-01T15:51:55.927Z,1606837915.927 [BackSeatDriver ThreadHandler](INFO): Protected caller Thread ID is 5546 2020-12-01T15:51:55.946Z,1606837915.946 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_density 2020-12-01T15:51:55.949Z,1606837915.949 [CTD_Seabird](INFO): created writer for : sea_water_density 2020-12-01T15:51:55.950Z,1606837915.950 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): depth 2020-12-01T15:51:55.952Z,1606837915.952 [CTD_Seabird](INFO): created writer for : depth 2020-12-01T15:51:55.953Z,1606837915.953 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_pressure 2020-12-01T15:51:55.955Z,1606837915.955 [CTD_Seabird](INFO): created writer for : sea_water_pressure 2020-12-01T15:51:55.956Z,1606837915.956 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_salinity 2020-12-01T15:51:55.959Z,1606837915.959 [CTD_Seabird](INFO): created writer for : sea_water_salinity 2020-12-01T15:51:55.959Z,1606837915.959 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_temperature 2020-12-01T15:51:55.962Z,1606837915.962 [CTD_Seabird](INFO): created writer for : sea_water_temperature 2020-12-01T15:51:55.963Z,1606837915.963 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_electrical_conductivity 2020-12-01T15:51:55.966Z,1606837915.966 [CTD_Seabird](INFO): created writer for : sea_water_electrical_conductivity 2020-12-01T15:51:55.966Z,1606837915.966 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): speed_of_sound_in_sea_water 2020-12-01T15:51:55.969Z,1606837915.969 [CTD_Seabird](INFO): created writer for : speed_of_sound_in_sea_water 2020-12-01T15:51:55.970Z,1606837915.970 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): mass_concentration_of_oxygen_in_sea_water 2020-12-01T15:51:55.973Z,1606837915.973 [CTD_Seabird](INFO): created writer for : mass_concentration_of_oxygen_in_sea_water 2020-12-01T15:51:55.973Z,1606837915.973 [CTD_Seabird](DEBUG): LcmSlateWriter::add(DAtaURI): CTD_Seabird.sea_water_dissolved_oxygen_freq 2020-12-01T15:51:55.974Z,1606837915.974 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): dataName: sea_water_dissolved_oxygen_freq 2020-12-01T15:51:55.990Z,1606837915.990 [CTD_Seabird] Loaded 2020-12-01T15:51:55.990Z,1606837915.990 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2020-12-01T15:51:55.991Z,1606837915.991 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40B374E0 2020-12-01T15:51:55.991Z,1606837915.991 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 5547 2020-12-01T15:51:56.008Z,1606837916.008 [PAR_Licor] Loaded 2020-12-01T15:51:56.008Z,1606837916.008 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2020-12-01T15:51:56.021Z,1606837916.021 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.Output470 2020-12-01T15:51:56.021Z,1606837916.021 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: Output470 2020-12-01T15:51:56.023Z,1606837916.023 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.Output650 2020-12-01T15:51:56.023Z,1606837916.023 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: Output650 2020-12-01T15:51:56.025Z,1606837916.025 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.OutputChl 2020-12-01T15:51:56.025Z,1606837916.025 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: OutputChl 2020-12-01T15:51:56.027Z,1606837916.027 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.VolumeScatCoeff117deg470nm 2020-12-01T15:51:56.027Z,1606837916.027 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: VolumeScatCoeff117deg470nm 2020-12-01T15:51:56.029Z,1606837916.029 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.VolumeScatCoeff117deg650nm 2020-12-01T15:51:56.029Z,1606837916.029 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: VolumeScatCoeff117deg650nm 2020-12-01T15:51:56.032Z,1606837916.032 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.BackscatteringCoeff470nm 2020-12-01T15:51:56.032Z,1606837916.032 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: BackscatteringCoeff470nm 2020-12-01T15:51:56.034Z,1606837916.034 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.BackscatteringCoeff650nm 2020-12-01T15:51:56.034Z,1606837916.034 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: BackscatteringCoeff650nm 2020-12-01T15:51:56.036Z,1606837916.036 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): mass_concentration_of_chlorophyll_in_sea_water 2020-12-01T15:51:56.038Z,1606837916.038 [WetLabsBB2FL](INFO): created writer for : mass_concentration_of_chlorophyll_in_sea_water 2020-12-01T15:51:56.039Z,1606837916.039 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_median_mass_concentration_of_chlorophyll_in_sea_water 2020-12-01T15:51:56.039Z,1606837916.039 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_median_mass_concentration_of_chlorophyll_in_sea_water 2020-12-01T15:51:56.041Z,1606837916.041 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water 2020-12-01T15:51:56.041Z,1606837916.041 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_mean_mass_concentration_of_chlorophyll_in_sea_water 2020-12-01T15:51:56.043Z,1606837916.043 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_variance_mass_concentration_of_chlorophyll_in_sea_water 2020-12-01T15:51:56.043Z,1606837916.043 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_variance_mass_concentration_of_chlorophyll_in_sea_water 2020-12-01T15:51:56.045Z,1606837916.045 [WetLabsBB2FL] Loaded 2020-12-01T15:51:56.045Z,1606837916.045 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2020-12-01T15:51:56.046Z,1606837916.046 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40B674E0 2020-12-01T15:51:56.047Z,1606837916.047 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 5548 2020-12-01T15:51:56.066Z,1606837916.066 [WetLabsUBAT..SerialDriver](INFO): Created logger 2020-12-01T15:51:56.067Z,1606837916.067 [WetLabsUBAT..SerialDriver](INFO): publishing on LCM channel WetLabsUBAT 2020-12-01T15:51:56.067Z,1606837916.067 [WetLabsUBAT..StreamSerialDriver](INFO): Created logger 2020-12-01T15:51:56.072Z,1606837916.072 [WetLabsUBAT](INFO): readConfig(): serialNo_: UBAT0051, uartName_: /dev/ttyC1, optionalArgs_: 2020-12-01T15:51:56.072Z,1606837916.072 [WetLabsUBAT](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsUBAT.biolum_potential 2020-12-01T15:51:56.072Z,1606837916.072 [WetLabsUBAT](DEBUG): LcmSlateWriter::add(): dataName: biolum_potential 2020-12-01T15:51:56.074Z,1606837916.074 [WetLabsUBAT](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsUBAT.flow_rate 2020-12-01T15:51:56.074Z,1606837916.074 [WetLabsUBAT](DEBUG): LcmSlateWriter::add(): dataName: flow_rate 2020-12-01T15:51:56.077Z,1606837916.077 [WetLabsUBAT] Loaded 2020-12-01T15:51:56.078Z,1606837916.078 [ComponentRegistry](DEBUG): Component "WetLabsUBAT" handled in its own thread. 2020-12-01T15:51:56.079Z,1606837916.079 [WetLabsUBAT ThreadHandler](DEBUG): Created PCaller Thread at 40B974E0 2020-12-01T15:51:56.079Z,1606837916.079 [WetLabsUBAT ThreadHandler](INFO): Protected caller Thread ID is 5549 2020-12-01T15:51:56.080Z,1606837916.080 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2020-12-01T15:51:56.083Z,1606837916.083 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2020-12-01T15:51:56.084Z,1606837916.084 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2020-12-01T15:51:56.092Z,1606837916.092 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2020-12-01T15:51:56.093Z,1606837916.093 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40BC74E0 2020-12-01T15:51:56.094Z,1606837916.094 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 5550 2020-12-01T15:51:56.098Z,1606837916.098 [Supervisor](INFO): Main Thread ID is 5457 2020-12-01T15:51:56.098Z,1606837916.098 [Supervisor](DEBUG): Running supervisor. 2020-12-01T15:51:56.099Z,1606837916.099 [CommandLine ThreadHandler](INFO): Handler Thread ID is 5551 2020-12-01T15:51:56.102Z,1606837916.102 [controlThread ThreadHandler](INFO): Handler Thread ID is 5552 2020-12-01T15:51:56.102Z,1606837916.102 [controlThread](DEBUG): Initializing ControlThread 2020-12-01T15:51:56.103Z,1606837916.103 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2020-12-01T15:51:56.105Z,1606837916.105 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2020-12-01T15:51:56.105Z,1606837916.105 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2020-12-01T15:51:56.106Z,1606837916.106 [LoopControl](DEBUG): Initialize LoopControlComponent. 2020-12-01T15:51:56.106Z,1606837916.106 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2020-12-01T15:51:56.106Z,1606837916.106 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2020-12-01T15:51:56.107Z,1606837916.107 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2020-12-01T15:51:56.107Z,1606837916.107 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2020-12-01T15:51:56.108Z,1606837916.108 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2020-12-01T15:51:56.108Z,1606837916.108 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2020-12-01T15:51:56.114Z,1606837916.114 [NavChart](DEBUG): Initialize NavChart Navigation. 2020-12-01T15:51:56.115Z,1606837916.115 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2020-12-01T15:51:56.115Z,1606837916.115 [SBIT](INFO): Initialize SBIT Component. 2020-12-01T15:51:56.116Z,1606837916.116 [SBIT](IMPORTANT): git: 2020-11-24 2020-12-01T15:51:56.116Z,1606837916.116 [SBIT](INFO): git hash: adde971cea593344b7c42ced3277a520a74b3766 2020-12-01T15:51:56.116Z,1606837916.116 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2020-12-01T15:51:56.117Z,1606837916.117 [SBIT](INFO): Kernel Reporting Different Version From Configuration. Kernel Expected: #1 PREEMPT Thu Feb 21 11:17:40 PST 2019 Kernel Reported: #1 PREEMPT Thu Aug 6 12:04:53 PDT 2020 2020-12-01T15:51:56.118Z,1606837916.118 [SBIT](INFO): Beginning SBIT in 49.000000 seconds. 2020-12-01T15:51:56.119Z,1606837916.119 [IBIT](INFO): Initialize IBIT Component. 2020-12-01T15:51:56.119Z,1606837916.119 [CBIT](DEBUG): Initialize CBIT Component. 2020-12-01T15:51:56.121Z,1606837916.121 [logger ThreadHandler](INFO): Handler Thread ID is 5553 2020-12-01T15:51:56.132Z,1606837916.132 [CBIT](DEBUG): Initialized mux pins. 2020-12-01T15:51:56.132Z,1606837916.132 [CBIT](DEBUG): Initializing the watchdog timer. 2020-12-01T15:51:56.140Z,1606837916.140 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 5554 2020-12-01T15:51:56.141Z,1606837916.141 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2020-12-01T15:51:56.152Z,1606837916.152 [Onboard ThreadHandler](INFO): Handler Thread ID is 5555 2020-12-01T15:51:56.157Z,1606837916.157 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2020-12-01T15:51:56.157Z,1606837916.157 [CBIT](DEBUG): Initializing heartbeat. 2020-12-01T15:51:56.188Z,1606837916.188 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 5556 2020-12-01T15:51:56.189Z,1606837916.189 [BackSeatDriver ThreadHandler](INFO): Handler Thread ID is 5557 2020-12-01T15:51:56.200Z,1606837916.200 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 5558 2020-12-01T15:51:56.201Z,1606837916.201 [CTD_Seabird](DEBUG): Initializing CTD_Seabird. 2020-12-01T15:51:56.205Z,1606837916.205 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 5560 2020-12-01T15:51:56.206Z,1606837916.206 [WetLabsBB2FL](INFO): Powering down 2020-12-01T15:51:56.217Z,1606837916.217 [WetLabsUBAT ThreadHandler](INFO): Handler Thread ID is 5561 2020-12-01T15:51:56.224Z,1606837916.224 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 5562 2020-12-01T15:51:56.227Z,1606837916.227 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2020-12-01T15:51:56.227Z,1606837916.227 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2020-12-01T15:51:56.228Z,1606837916.228 [CBIT](DEBUG): Deactivating GF circuits. 2020-12-01T15:51:56.228Z,1606837916.228 [CBIT](DEBUG): Deactivating emergency mode. 2020-12-01T15:51:56.228Z,1606837916.228 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2020-12-01T15:51:56.228Z,1606837916.228 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2020-12-01T15:51:56.228Z,1606837916.228 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2020-12-01T15:51:56.229Z,1606837916.229 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2020-12-01T15:51:56.229Z,1606837916.229 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000 2020-12-01T15:51:56.229Z,1606837916.229 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2020-12-01T15:51:56.229Z,1606837916.229 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2020-12-01T15:51:56.229Z,1606837916.229 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2020-12-01T15:51:56.229Z,1606837916.229 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000 2020-12-01T15:51:56.229Z,1606837916.229 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2020-12-01T15:51:56.230Z,1606837916.230 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000 2020-12-01T15:51:56.230Z,1606837916.230 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2020-12-01T15:51:56.230Z,1606837916.230 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000 2020-12-01T15:51:56.230Z,1606837916.230 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2020-12-01T15:51:56.264Z,1606837916.264 [CBIT](DEBUG): Backplane powered. 2020-12-01T15:51:56.269Z,1606837916.269 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2020-12-01T15:51:56.279Z,1606837916.279 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2020-12-01T15:51:56.320Z,1606837916.320 [MissionManager](DEBUG): 2020-12-01T15:51:56.321Z,1606837916.321 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2020-12-01T15:51:56.389Z,1606837916.389 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2020-12-01T15:51:56.390Z,1606837916.390 [Default:A.Wait](DEBUG): Construct Wait. 2020-12-01T15:51:56.392Z,1606837916.392 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2020-12-01T15:51:56.447Z,1606837916.447 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2020-12-01T15:51:56.449Z,1606837916.449 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2020-12-01T15:51:56.470Z,1606837916.470 [Default:E.Execute](DEBUG): Construct Execute. 2020-12-01T15:51:56.474Z,1606837916.474 [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-12-01T15:51:56.487Z,1606837916.487 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,NAL9602,RDI_Pathfinder,DAT,BPC1,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2020-12-01T15:51:56.500Z,1606837916.500 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2020-12-01T15:51:56.533Z,1606837916.533 [Depth_Keller](ERROR): Pressure reading out of range: 1650.297119 decibar 2020-12-01T15:51:56.543Z,1606837916.543 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2 2020-12-01T15:51:56.543Z,1606837916.543 [DAT](INFO): Powering up 2020-12-01T15:51:56.543Z,1606837916.543 [DAT](DEBUG): Initializing DAT. 2020-12-01T15:51:56.592Z,1606837916.592 [Radio_Surface](INFO): Powering up 2020-12-01T15:51:56.600Z,1606837916.600 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2 2020-12-01T15:51:56.660Z,1606837916.660 [DepthRateCalculator](ERROR): Depth measurement is not active 2020-12-01T15:51:56.691Z,1606837916.691 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2020-12-01T15:51:56.709Z,1606837916.709 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2020-12-01T15:51:56.710Z,1606837916.710 [ElevatorServo](DEBUG): Initializing EZServoServo. 2020-12-01T15:51:56.720Z,1606837916.720 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2020-12-01T15:51:56.721Z,1606837916.721 [MassServo](DEBUG): Initializing EZServoServo. 2020-12-01T15:51:56.728Z,1606837916.728 [MassServo](DEBUG): Initializing MassServo. 2020-12-01T15:51:56.729Z,1606837916.729 [RudderServo](DEBUG): Initializing EZServoServo. 2020-12-01T15:51:56.736Z,1606837916.736 [RudderServo](DEBUG): Initializing RudderServo. 2020-12-01T15:51:56.737Z,1606837916.737 [ThrusterServo](DEBUG): Initializing EZServoServo. 2020-12-01T15:51:56.744Z,1606837916.744 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2020-12-01T15:51:56.920Z,1606837916.920 [DropWeight](CRITICAL): DROP WEIGHT MISSING. 2020-12-01T15:51:56.921Z,1606837916.921 [DropWeight] Hardware Fault, FailCount= 1 2020-12-01T15:51:56.921Z,1606837916.921 [DropWeight](ERROR): Hardware Fault 2020-12-01T15:51:56.977Z,1606837916.977 [DepthRateCalculator](ERROR): Depth measurement is not active 2020-12-01T15:51:57.004Z,1606837917.004 [CommandLine](FAULT): Scheduling is paused 2020-12-01T15:51:57.004Z,1606837917.004 [CBIT](INFO): Critical error at 20201201T155156 2020-12-01T15:51:57.004Z,1606837917.004 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals 2020-12-01T15:51:57.021Z,1606837917.021 [CBIT](ERROR): Hardware Fault in component: DropWeight 2020-12-01T15:51:57.022Z,1606837917.022 [CBIT](CRITICAL): Hardware Fault in component: DropWeight 2020-12-01T15:51:57.628Z,1606837917.628 [RudderServo](ERROR): Rudder initialization uart error serial timeout 2020-12-01T15:51:57.628Z,1606837917.628 [RudderServo](FAULT): Rudder failed to initialize 2020-12-01T15:51:57.628Z,1606837917.628 [RudderServo] Communications Fault, FailCount= 1 2020-12-01T15:51:57.628Z,1606837917.628 [RudderServo](ERROR): Communications Fault 2020-12-01T15:51:57.726Z,1606837917.726 [CBIT](INFO): Critical error at 20201201T155157 2020-12-01T15:51:57.729Z,1606837917.729 [CBIT](ERROR): Communications Fault in component: RudderServo 2020-12-01T15:51:57.925Z,1606837917.925 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2020-12-01T15:51:57.925Z,1606837917.925 [RudderServo](INFO): Powering down 2020-12-01T15:51:58.586Z,1606837918.586 [RudderServo](DEBUG): Initializing EZServoServo. 2020-12-01T15:51:58.705Z,1606837918.705 [RudderServo](DEBUG): Initializing RudderServo. 2020-12-01T15:51:58.709Z,1606837918.709 [CBIT](INFO): Clearing failed state for component RudderServo 2020-12-01T15:51:58.709Z,1606837918.709 [RudderServo] No Fault, FailCount= 1 2020-12-01T15:52:10.063Z,1606837930.063 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004775 2020-12-01T15:52:10.672Z,1606837930.672 [DAT](INFO): commRate: 800 2020-12-01T15:52:11.482Z,1606837931.482 [RDI_Pathfinder](ERROR): only read 3 of 4 data items 2020-12-01T15:52:12.701Z,1606837932.701 [DAT](INFO): entering command mode 2020-12-01T15:52:13.094Z,1606837933.094 [DAT](DEBUG): checking for command mode acknowledgment 2020-12-01T15:52:13.510Z,1606837933.510 [DAT](DEBUG): checking for command mode acknowledgment 2020-12-01T15:52:13.912Z,1606837933.912 [DAT](DEBUG): checking for command mode acknowledgment 2020-12-01T15:52:14.316Z,1606837934.316 [DAT](DEBUG): checking for command mode acknowledgment 2020-12-01T15:52:14.710Z,1606837934.710 [DAT](DEBUG): checking for command mode acknowledgment 2020-12-01T15:52:15.124Z,1606837935.124 [DAT](DEBUG): checking for command mode acknowledgment 2020-12-01T15:52:15.528Z,1606837935.528 [DAT](DEBUG): checking for command mode acknowledgment 2020-12-01T15:52:15.922Z,1606837935.922 [DAT](DEBUG): checking for command mode acknowledgment 2020-12-01T15:52:16.336Z,1606837936.336 [DAT](DEBUG): checking for command mode acknowledgment 2020-12-01T15:52:16.730Z,1606837936.730 [DAT](DEBUG): checking for command mode acknowledgment 2020-12-01T15:52:17.144Z,1606837937.144 [DAT](DEBUG): checking for command mode acknowledgment 2020-12-01T15:52:17.538Z,1606837937.538 [DAT](DEBUG): checking for command mode acknowledgment 2020-12-01T15:52:17.942Z,1606837937.942 [DAT](DEBUG): checking for command mode acknowledgment 2020-12-01T15:52:18.368Z,1606837938.368 [DAT](DEBUG): checking for command mode acknowledgment 2020-12-01T15:52:18.746Z,1606837938.746 [DAT](DEBUG): checking for command mode acknowledgment 2020-12-01T15:52:19.163Z,1606837939.163 [DAT](DEBUG): checking for command mode acknowledgment 2020-12-01T15:52:19.558Z,1606837939.558 [DAT](DEBUG): checking for command mode acknowledgment 2020-12-01T15:52:19.957Z,1606837939.957 [DAT](DEBUG): checking for command mode acknowledgment 2020-12-01T15:52:20.372Z,1606837940.372 [DAT](DEBUG): checking for command mode acknowledgment 2020-12-01T15:52:20.766Z,1606837940.766 [DAT](DEBUG): checking for command mode acknowledgment 2020-12-01T15:52:21.170Z,1606837941.170 [DAT](DEBUG): checking for command mode acknowledgment 2020-12-01T15:52:21.590Z,1606837941.590 [DAT](DEBUG): checking for command mode acknowledgment 2020-12-01T15:52:21.978Z,1606837941.978 [DAT](DEBUG): checking for command mode acknowledgment 2020-12-01T15:52:22.384Z,1606837942.384 [DAT](DEBUG): checking for command mode acknowledgment 2020-12-01T15:52:22.808Z,1606837942.808 [DAT](DEBUG): checking for command mode acknowledgment 2020-12-01T15:52:23.213Z,1606837943.213 [DAT](DEBUG): checking for command mode acknowledgment 2020-12-01T15:52:23.594Z,1606837943.594 [DAT](DEBUG): checking for command mode acknowledgment 2020-12-01T15:52:24.006Z,1606837944.006 [DAT](DEBUG): checking for command mode acknowledgment 2020-12-01T15:52:24.405Z,1606837944.405 [NAL9602](INFO): Powering up NAL9602 2020-12-01T15:52:24.425Z,1606837944.425 [DAT](DEBUG): checking for command mode acknowledgment 2020-12-01T15:52:24.806Z,1606837944.806 [DAT](DEBUG): checking for command mode acknowledgment 2020-12-01T15:52:25.230Z,1606837945.230 [DAT](DEBUG): checking for command mode acknowledgment 2020-12-01T15:52:25.614Z,1606837945.614 [DAT](DEBUG): checking for command mode acknowledgment 2020-12-01T15:52:26.072Z,1606837946.072 [DAT](DEBUG): checking for command mode acknowledgment 2020-12-01T15:52:26.427Z,1606837946.427 [DAT](DEBUG): checking for command mode acknowledgment 2020-12-01T15:52:26.826Z,1606837946.826 [DAT](DEBUG): checking for command mode acknowledgment 2020-12-01T15:52:27.244Z,1606837947.244 [DAT](DEBUG): checking for command mode acknowledgment 2020-12-01T15:52:27.634Z,1606837947.634 [DAT](DEBUG): checking for command mode acknowledgment 2020-12-01T15:52:28.038Z,1606837948.038 [DAT](DEBUG): checking for command mode acknowledgment 2020-12-01T15:52:28.038Z,1606837948.038 [DAT](FAULT): failed to enter command mode 2020-12-01T15:52:28.456Z,1606837948.456 [DAT](INFO): entering command mode 2020-12-01T15:52:28.847Z,1606837948.847 [DAT](INFO): setting verbose to 3 2020-12-01T15:52:29.268Z,1606837949.268 [DAT](INFO): set verbose to 3 2020-12-01T15:52:29.269Z,1606837949.269 [DAT](INFO): setting DatVerbose to 27440 2020-12-01T15:52:29.655Z,1606837949.655 [DAT](INFO): set DatVerbose to 27440 2020-12-01T15:52:29.655Z,1606837949.655 [DAT](INFO): setting transmit power to 8 2020-12-01T15:52:30.059Z,1606837950.059 [DAT](INFO): set transmit power to 8 2020-12-01T15:52:30.059Z,1606837950.059 [DAT](INFO): setting local address to 9 2020-12-01T15:52:30.463Z,1606837950.463 [DAT](INFO): set local address to 9 2020-12-01T15:52:35.313Z,1606837955.313 [NAL9602](INFO): NAL9602 initialized 2020-12-01T15:52:45.851Z,1606837965.851 [SBIT](IMPORTANT): Beginning Startup BIT 2020-12-01T15:52:45.867Z,1606837965.867 [CBIT](IMPORTANT): Beginning ground fault scan 2020-12-01T15:52:56.800Z,1606837976.800 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.013204 CHAN A1 (24V): -0.001717 CHAN A2 (12V): -0.007338 CHAN A3 (5V): -0.002030 CHAN B0 (3.3V): 0.000482 CHAN B1 (3.15aV): -0.000020 CHAN B2 (3.15bV): -0.000010 CHAN B3 (GND): 0.002003 OPEN: 0.004812 Full Scale Calc: 4.765 mA, -1.589 mA 2020-12-01T15:53:39.637Z,1606838019.637 [SBIT](IMPORTANT): SBIT PASSED 2020-12-01T15:53:39.637Z,1606838019.637 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2020-12-01T15:53:39.638Z,1606838019.638 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=6 count; 2020-12-01T15:53:39.638Z,1606838019.638 [SBIT](IMPORTANT): CBIT.gf24Offset=145 microampere; 2020-12-01T15:53:39.638Z,1606838019.638 [SBIT](IMPORTANT): DAT.loadAtStartup=1 bool; 2020-12-01T15:53:39.638Z,1606838019.638 [SBIT](IMPORTANT): DAT.sbdAddress=-1 enum; 2020-12-01T15:53:39.638Z,1606838019.638 [SBIT](IMPORTANT): DAT.surfaceThreshold=100 meter; 2020-12-01T15:53:39.638Z,1606838019.638 [SBIT](IMPORTANT): DAT.verbosity=0 count; 2020-12-01T15:53:39.638Z,1606838019.638 [SBIT](IMPORTANT): Express linearApproximation WetLabsUBAT.flow_rate 1.000000 liter_per_second; 2020-12-01T15:53:39.639Z,1606838019.639 [SBIT](IMPORTANT): PAR_Licor.loadAtStartup=1 bool; 2020-12-01T15:53:39.639Z,1606838019.639 [SBIT](IMPORTANT): PAR_Licor.parCal=1.01146 none; 2020-12-01T15:53:39.639Z,1606838019.639 [SBIT](IMPORTANT): RDI_Pathfinder.loadAtStartup=1 bool; 2020-12-01T15:53:39.639Z,1606838019.639 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=254.6 cubic_centimeter; 2020-12-01T15:53:39.639Z,1606838019.639 [SBIT](IMPORTANT): VerticalControl.massDefault=7.48 millimeter; 2020-12-01T15:53:39.639Z,1606838019.639 [SBIT](IMPORTANT): WetLabsUBAT.loadAtStartup=1 bool; 2020-12-01T15:53:40.019Z,1606838020.019 [MissionManager](IMPORTANT): Started mission Startup 2020-12-01T15:53:40.020Z,1606838020.020 [Startup] Running Loop=1 2020-12-01T15:53:40.020Z,1606838020.020 [Startup](DEBUG): Aggregate::initialize Startup 2020-12-01T15:53:40.020Z,1606838020.020 [Startup:A.GoToSurface] Running Loop=1 2020-12-01T15:53:40.020Z,1606838020.020 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2020-12-01T15:53:40.021Z,1606838020.021 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2020-12-01T15:53:40.021Z,1606838020.021 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2020-12-01T15:53:40.022Z,1606838020.022 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2020-12-01T15:53:40.022Z,1606838020.022 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2020-12-01T15:53:40.022Z,1606838020.022 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2020-12-01T15:53:40.024Z,1606838020.024 [Startup:StartupSatComms] Running Loop=1 2020-12-01T15:53:40.024Z,1606838020.024 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2020-12-01T15:53:40.024Z,1606838020.024 [Startup:StartupSatComms:A] Running Loop=1 2020-12-01T15:53:40.447Z,1606838020.447 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2020-12-01T15:54:40.232Z,1606838080.232 [Startup:StartupSatComms:A](INFO): Timed out from 2020-12-01T15:53:40.0Z 2020-12-01T15:54:40.233Z,1606838080.233 [Startup:StartupSatComms:A] Stopped 2020-12-01T15:54:40.233Z,1606838080.233 [Startup:StartupSatComms:B] Running Loop=1 2020-12-01T15:54:40.634Z,1606838080.634 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2020-12-01T15:54:56.383Z,1606838096.383 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2020-12-01T15:54:56.383Z,1606838096.383 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-12-01T15:54:56.393Z,1606838096.393 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-12-01T15:54:56.794Z,1606838096.794 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-12-01T15:54:56.794Z,1606838096.794 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2020-12-01T15:55:04.063Z,1606838104.063 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20201130T222335/Courier0007.lzma 2020-12-01T15:55:05.066Z,1606838105.066 [DataOverHttps](INFO): Moved sent file to Logs/20201130T222335/Courier0007.lzma.bak 2020-12-01T15:55:05.067Z,1606838105.067 [DataOverHttps](INFO): SBD MOMSN=13371837 2020-12-01T15:55:40.410Z,1606838140.410 [Startup:StartupSatComms:B](INFO): Timed out from 2020-12-01T15:54:40.2Z 2020-12-01T15:55:40.410Z,1606838140.410 [Startup:StartupSatComms:B] Stopped 2020-12-01T15:55:40.411Z,1606838140.411 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2020-12-01T15:55:40.411Z,1606838140.411 [Startup:StartupSatComms] Stopped 2020-12-01T15:55:40.411Z,1606838140.411 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2020-12-01T15:55:40.411Z,1606838140.411 [Startup](INFO): Completed Startup 2020-12-01T15:55:40.412Z,1606838140.412 [MissionManager](INFO): Startup is completed. 2020-12-01T15:55:40.412Z,1606838140.412 [MissionManager](INFO): Uninitializing Mission Startup 2020-12-01T15:55:40.412Z,1606838140.412 [Startup] Stopped 2020-12-01T15:55:40.412Z,1606838140.412 [Startup](DEBUG): Aggregate::uninitialize Startup 2020-12-01T15:55:40.412Z,1606838140.412 [Startup:A.GoToSurface] Stopped 2020-12-01T15:55:40.412Z,1606838140.412 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2020-12-01T15:55:40.842Z,1606838140.842 [MissionManager](IMPORTANT): Started mission Default 2020-12-01T15:55:40.842Z,1606838140.842 [Default] Running Loop=1 2020-12-01T15:55:40.843Z,1606838140.843 [Default](DEBUG): Aggregate::initialize Default 2020-12-01T15:55:40.843Z,1606838140.843 [Default:B.GoToSurface] Running Loop=1 2020-12-01T15:55:40.843Z,1606838140.843 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2020-12-01T15:55:40.843Z,1606838140.843 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2020-12-01T15:55:40.843Z,1606838140.843 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2020-12-01T15:55:40.844Z,1606838140.844 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2020-12-01T15:55:40.844Z,1606838140.844 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2020-12-01T15:55:40.844Z,1606838140.844 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2020-12-01T15:55:40.845Z,1606838140.845 [Default:A.Wait] Running Loop=1 2020-12-01T15:55:40.845Z,1606838140.845 [Default:A.Wait](DEBUG): Initialize Wait Component. 2020-12-01T15:55:54.176Z,1606838154.176 [Default:A.Wait](INFO): Done Waiting. 2020-12-01T15:55:54.176Z,1606838154.176 [Default:A.Wait] Stopped 2020-12-01T15:55:54.176Z,1606838154.176 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2020-12-01T15:55:54.554Z,1606838154.554 [Default:CheckIn] Running Loop=1 2020-12-01T15:55:54.554Z,1606838154.554 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-12-01T15:55:54.555Z,1606838154.555 [Default:CheckIn:Read_GPS] Running Loop=1 2020-12-01T15:55:54.954Z,1606838154.954 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2020-12-01T15:57:38.369Z,1606838258.369 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2020-12-01T15:57:57.375Z,1606838277.375 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2 2020-12-01T15:57:57.375Z,1606838277.375 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-12-01T15:57:57.410Z,1606838277.410 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-12-01T15:57:57.778Z,1606838277.778 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-12-01T15:57:57.778Z,1606838277.778 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2 2020-12-01T15:58:08.659Z,1606838288.659 [DataOverHttps](INFO): Sending 240 bytes from file Logs/20201130T223619/Courier0000.lzma 2020-12-01T15:58:09.657Z,1606838289.657 [DataOverHttps](INFO): Moved sent file to Logs/20201130T223619/Courier0000.lzma.bak 2020-12-01T15:58:09.658Z,1606838289.658 [DataOverHttps](INFO): SBD MOMSN=13371882 2020-12-01T15:59:21.008Z,1606838361.008 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2020-12-01T15:59:21.015Z,1606838361.015 [BPC1](INFO): Received data from all battery sticks. 2020-12-01T16:00:54.723Z,1606838454.723 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-12-01T15:55:54.6Z 2020-12-01T16:00:54.723Z,1606838454.723 [Default:CheckIn:Read_GPS] Stopped 2020-12-01T16:00:54.723Z,1606838454.723 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-12-01T16:00:55.159Z,1606838455.159 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2020-12-01T16:00:58.492Z,1606838458.492 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3 2020-12-01T16:00:58.492Z,1606838458.492 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-12-01T16:00:58.535Z,1606838458.535 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-12-01T16:00:58.955Z,1606838458.955 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-12-01T16:00:58.955Z,1606838458.955 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3 2020-12-01T16:01:03.387Z,1606838463.387 [DataOverHttps](INFO): Sending 38 bytes from file Logs/20201130T223619/Courier0004.lzma 2020-12-01T16:01:04.390Z,1606838464.390 [DataOverHttps](INFO): Moved sent file to Logs/20201130T223619/Courier0004.lzma.bak 2020-12-01T16:01:04.390Z,1606838464.390 [DataOverHttps](INFO): SBD MOMSN=13371938 2020-12-01T16:01:20.212Z,1606838480.212 [DataOverHttps](INFO): Sending 241 bytes from file Logs/20201201T155147/Courier0000.lzma 2020-12-01T16:01:21.214Z,1606838481.214 [DataOverHttps](INFO): Moved sent file to Logs/20201201T155147/Courier0000.lzma.bak 2020-12-01T16:01:21.214Z,1606838481.214 [DataOverHttps](INFO): SBD MOMSN=13371940 2020-12-01T16:01:36.984Z,1606838496.984 [DataOverHttps](INFO): Sending 168 bytes from file Logs/20201201T155147/Courier0004.lzma 2020-12-01T16:01:37.985Z,1606838497.985 [DataOverHttps](INFO): Moved sent file to Logs/20201201T155147/Courier0004.lzma.bak 2020-12-01T16:01:37.986Z,1606838497.986 [DataOverHttps](INFO): SBD MOMSN=13371945 2020-12-01T16:01:53.776Z,1606838513.776 [DataOverHttps](INFO): Sending 536 bytes from file Logs/20201130T222335/Express0008.lzma 2020-12-01T16:01:54.778Z,1606838514.778 [DataOverHttps](INFO): Moved sent file to Logs/20201130T222335/Express0008.lzma.bak 2020-12-01T16:01:54.778Z,1606838514.778 [DataOverHttps](INFO): SBD MOMSN=13371947 2020-12-01T16:02:10.670Z,1606838530.670 [DataOverHttps](INFO): Sending 1420 bytes from file Logs/20201130T223619/Express0001.lzma 2020-12-01T16:02:11.670Z,1606838531.670 [DataOverHttps](INFO): Moved sent file to Logs/20201130T223619/Express0001.lzma.bak 2020-12-01T16:02:11.670Z,1606838531.670 [DataOverHttps](INFO): SBD MOMSN=13371965 2020-12-01T16:02:27.384Z,1606838547.384 [DataOverHttps](INFO): Sending 264 bytes from file Logs/20201130T223619/Express0005.lzma 2020-12-01T16:02:28.386Z,1606838548.386 [DataOverHttps](INFO): Moved sent file to Logs/20201130T223619/Express0005.lzma.bak 2020-12-01T16:02:28.386Z,1606838548.386 [DataOverHttps](INFO): SBD MOMSN=13372014 2020-12-01T16:02:36.227Z,1606838556.227 [NAL9602](FAULT): GPS failed to acquire within timeout. 2020-12-01T16:02:36.227Z,1606838556.227 [NAL9602] Data Fault, FailCount= 1 2020-12-01T16:02:36.227Z,1606838556.227 [NAL9602](ERROR): Data Fault 2020-12-01T16:02:36.253Z,1606838556.253 [CBIT](ERROR): Data Fault in component: NAL9602 2020-12-01T16:02:36.617Z,1606838556.617 [NAL9602](INFO): Powering down 2020-12-01T16:02:37.450Z,1606838557.450 [CBIT](INFO): Clearing failed state for component NAL9602 2020-12-01T16:02:37.450Z,1606838557.450 [NAL9602] No Fault, FailCount= 1 2020-12-01T16:02:44.213Z,1606838564.213 [DataOverHttps](INFO): Sending 1012 bytes from file Logs/20201201T155147/Express0001.lzma 2020-12-01T16:02:45.217Z,1606838565.217 [DataOverHttps](INFO): Moved sent file to Logs/20201201T155147/Express0001.lzma.bak 2020-12-01T16:02:45.217Z,1606838565.217 [DataOverHttps](INFO): SBD MOMSN=13372023 2020-12-01T16:03:00.879Z,1606838580.879 [DataOverHttps](INFO): Sending 186 bytes from file Logs/20201201T155147/Express0005.lzma 2020-12-01T16:03:01.882Z,1606838581.882 [DataOverHttps](INFO): Moved sent file to Logs/20201201T155147/Express0005.lzma.bak 2020-12-01T16:03:01.882Z,1606838581.882 [DataOverHttps](INFO): SBD MOMSN=13372051 2020-12-01T16:03:02.900Z,1606838582.900 [Default:CheckIn:Read_Iridium] Stopped 2020-12-01T16:03:02.900Z,1606838582.900 [Default:CheckIn:C.Wait] Running Loop=1 2020-12-01T16:03:02.900Z,1606838582.900 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-12-01T16:03:06.917Z,1606838586.917 [NAL9602](INFO): Powering up NAL9602 2020-12-01T16:03:17.829Z,1606838597.829 [NAL9602](INFO): NAL9602 initialized 2020-12-01T16:03:59.453Z,1606838639.453 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4 2020-12-01T16:03:59.453Z,1606838639.453 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-12-01T16:03:59.463Z,1606838639.463 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-12-01T16:03:59.872Z,1606838639.872 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-12-01T16:03:59.872Z,1606838639.872 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4 2020-12-01T16:06:57.254Z,1606838817.254 [CBIT](INFO): Clearing failed state for component DropWeight 2020-12-01T16:06:57.254Z,1606838817.254 [DropWeight] No Fault, FailCount= 1 2020-12-01T16:07:00.450Z,1606838820.450 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5 2020-12-01T16:07:00.450Z,1606838820.450 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-12-01T16:07:00.460Z,1606838820.460 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-12-01T16:07:00.861Z,1606838820.861 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-12-01T16:07:00.861Z,1606838820.861 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5 2020-12-01T16:08:03.474Z,1606838883.474 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-12-01T16:08:03.474Z,1606838883.474 [Default:CheckIn:C.Wait] Stopped 2020-12-01T16:08:03.474Z,1606838883.474 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-12-01T16:08:03.474Z,1606838883.474 [Default:CheckIn:D] Running Loop=1 2020-12-01T16:08:03.870Z,1606838883.870 [Default:CheckIn:D] Stopped 2020-12-01T16:08:03.870Z,1606838883.870 [Default:CheckIn:E] Running Loop=1 2020-12-01T16:08:04.298Z,1606838884.298 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 12.383787 min 2020-12-01T16:08:04.298Z,1606838884.298 [Default:CheckIn:E] Stopped 2020-12-01T16:08:04.298Z,1606838884.298 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-12-01T16:08:04.299Z,1606838884.299 [Default:CheckIn] Stopped 2020-12-01T16:08:04.299Z,1606838884.299 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-12-01T16:08:04.299Z,1606838884.299 [Default:CheckIn](INFO): Running loop #2 2020-12-01T16:08:04.299Z,1606838884.299 [Default:CheckIn] Running Loop=2 2020-12-01T16:08:04.299Z,1606838884.299 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-12-01T16:08:04.299Z,1606838884.299 [Default:CheckIn:Read_GPS] Running Loop=1 2020-12-01T16:10:01.433Z,1606839001.433 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6 2020-12-01T16:10:01.433Z,1606839001.433 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-12-01T16:10:01.443Z,1606839001.443 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-12-01T16:10:01.852Z,1606839001.852 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-12-01T16:10:01.852Z,1606839001.852 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6 2020-12-01T16:10:06.318Z,1606839006.318 [CommandLine](IMPORTANT): got command strobe off 2020-12-01T16:10:06.318Z,1606839006.318 [CommandLine](IMPORTANT): Deactivating strobe 2020-12-01T16:13:02.457Z,1606839182.457 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7 2020-12-01T16:13:02.457Z,1606839182.457 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-12-01T16:13:02.466Z,1606839182.466 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-12-01T16:13:02.842Z,1606839182.842 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-12-01T16:13:02.842Z,1606839182.842 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7 2020-12-01T16:13:04.462Z,1606839184.462 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-12-01T16:08:04.3Z 2020-12-01T16:13:04.462Z,1606839184.462 [Default:CheckIn:Read_GPS] Stopped 2020-12-01T16:13:04.462Z,1606839184.462 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-12-01T16:13:11.867Z,1606839191.867 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20201201T155147/Courier0007.lzma 2020-12-01T16:13:12.870Z,1606839192.870 [DataOverHttps](INFO): Moved sent file to Logs/20201201T155147/Courier0007.lzma.bak 2020-12-01T16:13:12.870Z,1606839192.870 [DataOverHttps](INFO): SBD MOMSN=13372109 2020-12-01T16:13:19.387Z,1606839199.387 [NAL9602](FAULT): GPS failed to acquire within timeout. 2020-12-01T16:13:19.388Z,1606839199.388 [NAL9602] Data Fault, FailCount= 2 2020-12-01T16:13:19.388Z,1606839199.388 [NAL9602](ERROR): Data Fault 2020-12-01T16:13:19.434Z,1606839199.434 [CBIT](ERROR): Data Fault in component: NAL9602 2020-12-01T16:13:19.793Z,1606839199.793 [NAL9602](INFO): Powering down 2020-12-01T16:13:20.617Z,1606839200.617 [CBIT](INFO): Clearing failed state for component NAL9602 2020-12-01T16:13:20.617Z,1606839200.617 [NAL9602] No Fault, FailCount= 2 2020-12-01T16:13:28.660Z,1606839208.660 [DataOverHttps](INFO): Sending 221 bytes from file Logs/20201201T155147/Express0008.lzma 2020-12-01T16:13:29.662Z,1606839209.662 [DataOverHttps](INFO): Moved sent file to Logs/20201201T155147/Express0008.lzma.bak 2020-12-01T16:13:29.662Z,1606839209.662 [DataOverHttps](INFO): SBD MOMSN=13372111 2020-12-01T16:13:30.705Z,1606839210.705 [Default:CheckIn:Read_Iridium] Stopped 2020-12-01T16:13:30.705Z,1606839210.705 [Default:CheckIn:C.Wait] Running Loop=1 2020-12-01T16:13:30.705Z,1606839210.705 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-12-01T16:13:50.108Z,1606839230.108 [NAL9602](INFO): Powering up NAL9602 2020-12-01T16:14:00.998Z,1606839240.998 [NAL9602](INFO): NAL9602 initialized 2020-12-01T16:16:03.424Z,1606839363.424 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 8 2020-12-01T16:16:03.424Z,1606839363.424 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-12-01T16:16:03.434Z,1606839363.434 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-12-01T16:16:03.838Z,1606839363.838 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-12-01T16:16:03.838Z,1606839363.838 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 8 2020-12-01T16:18:31.312Z,1606839511.312 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-12-01T16:18:31.312Z,1606839511.312 [Default:CheckIn:C.Wait] Stopped 2020-12-01T16:18:31.313Z,1606839511.313 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-12-01T16:18:31.313Z,1606839511.313 [Default:CheckIn:D] Running Loop=1 2020-12-01T16:18:31.721Z,1606839511.721 [Default:CheckIn:D] Stopped 2020-12-01T16:18:31.721Z,1606839511.721 [Default:CheckIn:E] Running Loop=1 2020-12-01T16:18:32.125Z,1606839512.125 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 22.847970 min 2020-12-01T16:18:32.125Z,1606839512.125 [Default:CheckIn:E] Stopped 2020-12-01T16:18:32.125Z,1606839512.125 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-12-01T16:18:32.125Z,1606839512.125 [Default:CheckIn] Stopped 2020-12-01T16:18:32.125Z,1606839512.125 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-12-01T16:18:32.125Z,1606839512.125 [Default:CheckIn](INFO): Running loop #3 2020-12-01T16:18:32.125Z,1606839512.125 [Default:CheckIn] Running Loop=3 2020-12-01T16:18:32.125Z,1606839512.125 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-12-01T16:18:32.125Z,1606839512.125 [Default:CheckIn:Read_GPS] Running Loop=1 2020-12-01T16:19:04.462Z,1606839544.462 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 9 2020-12-01T16:19:04.462Z,1606839544.462 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-12-01T16:19:04.480Z,1606839544.480 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-12-01T16:19:04.854Z,1606839544.854 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-12-01T16:19:04.854Z,1606839544.854 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 9 2020-12-01T16:22:05.423Z,1606839725.423 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 10 2020-12-01T16:22:05.423Z,1606839725.423 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-12-01T16:22:05.453Z,1606839725.453 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-12-01T16:22:05.833Z,1606839725.833 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-12-01T16:22:05.833Z,1606839725.833 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 10 2020-12-01T16:23:32.306Z,1606839812.306 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-12-01T16:18:32.1Z 2020-12-01T16:23:32.306Z,1606839812.306 [Default:CheckIn:Read_GPS] Stopped 2020-12-01T16:23:32.306Z,1606839812.306 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-12-01T16:23:48.007Z,1606839828.007 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20201201T155147/Courier0010.lzma 2020-12-01T16:23:49.010Z,1606839829.010 [DataOverHttps](INFO): Moved sent file to Logs/20201201T155147/Courier0010.lzma.bak 2020-12-01T16:23:49.010Z,1606839829.010 [DataOverHttps](INFO): SBD MOMSN=13372176 2020-12-01T16:24:04.185Z,1606839844.185 [NAL9602](FAULT): GPS failed to acquire within timeout. 2020-12-01T16:24:04.185Z,1606839844.185 [NAL9602] Data Fault, FailCount= 3 2020-12-01T16:24:04.185Z,1606839844.185 [NAL9602](ERROR): Data Fault 2020-12-01T16:24:04.228Z,1606839844.228 [CBIT](ERROR): Data Fault in component: NAL9602 2020-12-01T16:24:04.589Z,1606839844.589 [NAL9602](INFO): Powering down 2020-12-01T16:24:04.887Z,1606839844.887 [DataOverHttps](INFO): Sending 149 bytes from file Logs/20201201T155147/Express0011.lzma 2020-12-01T16:24:05.419Z,1606839845.419 [CBIT](INFO): Clearing failed state for component NAL9602 2020-12-01T16:24:05.419Z,1606839845.419 [NAL9602] No Fault, FailCount= 3 2020-12-01T16:24:05.890Z,1606839845.890 [DataOverHttps](INFO): Moved sent file to Logs/20201201T155147/Express0011.lzma.bak 2020-12-01T16:24:05.890Z,1606839845.890 [DataOverHttps](INFO): SBD MOMSN=13372178 2020-12-01T16:24:07.056Z,1606839847.056 [Default:CheckIn:Read_Iridium] Stopped 2020-12-01T16:24:07.056Z,1606839847.056 [Default:CheckIn:C.Wait] Running Loop=1 2020-12-01T16:24:07.057Z,1606839847.057 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-12-01T16:24:34.901Z,1606839874.901 [NAL9602](INFO): Powering up NAL9602 2020-12-01T16:24:45.793Z,1606839885.793 [NAL9602](INFO): NAL9602 initialized 2020-12-01T16:25:06.433Z,1606839906.433 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 11 2020-12-01T16:25:06.433Z,1606839906.433 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-12-01T16:25:06.451Z,1606839906.451 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-12-01T16:25:06.825Z,1606839906.825 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-12-01T16:25:06.825Z,1606839906.825 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 11 2020-12-01T16:28:07.433Z,1606840087.433 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 12 2020-12-01T16:28:07.433Z,1606840087.433 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-12-01T16:28:07.463Z,1606840087.463 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-12-01T16:28:07.876Z,1606840087.876 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-12-01T16:28:07.876Z,1606840087.876 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 12 2020-12-01T16:29:07.650Z,1606840147.650 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-12-01T16:29:07.650Z,1606840147.650 [Default:CheckIn:C.Wait] Stopped 2020-12-01T16:29:07.650Z,1606840147.650 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-12-01T16:29:07.650Z,1606840147.650 [Default:CheckIn:D] Running Loop=1 2020-12-01T16:29:08.070Z,1606840148.070 [Default:CheckIn:D] Stopped 2020-12-01T16:29:08.070Z,1606840148.070 [Default:CheckIn:E] Running Loop=1 2020-12-01T16:29:08.465Z,1606840148.465 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 33.453790 min 2020-12-01T16:29:08.465Z,1606840148.465 [Default:CheckIn:E] Stopped 2020-12-01T16:29:08.465Z,1606840148.465 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-12-01T16:29:08.465Z,1606840148.465 [Default:CheckIn] Stopped 2020-12-01T16:29:08.465Z,1606840148.465 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-12-01T16:29:08.465Z,1606840148.465 [Default:CheckIn](INFO): Running loop #4 2020-12-01T16:29:08.465Z,1606840148.465 [Default:CheckIn] Running Loop=4 2020-12-01T16:29:08.466Z,1606840148.466 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-12-01T16:29:08.466Z,1606840148.466 [Default:CheckIn:Read_GPS] Running Loop=1 2020-12-01T16:30:38.146Z,1606840238.146 [RDI_Pathfinder](ERROR): only read 2 of 4 data items 2020-12-01T16:31:08.513Z,1606840268.513 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 13 2020-12-01T16:31:08.513Z,1606840268.513 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-12-01T16:31:08.543Z,1606840268.543 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-12-01T16:31:08.928Z,1606840268.928 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-12-01T16:31:08.928Z,1606840268.928 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 13 2020-12-01T16:32:39.453Z,1606840359.453 [DAT](INFO): unknown deviceResponse_: D:45.9 SPD:+0.0 2020-12-01T16:32:39.453Z,1606840359.453 [DAT](INFO): unknown deviceResponse_: AGC:91 2020-12-01T16:34:08.709Z,1606840448.709 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-12-01T16:29:08.5Z 2020-12-01T16:34:08.709Z,1606840448.709 [Default:CheckIn:Read_GPS] Stopped 2020-12-01T16:34:08.709Z,1606840448.709 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-12-01T16:34:09.525Z,1606840449.525 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 14 2020-12-01T16:34:09.525Z,1606840449.525 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-12-01T16:34:09.535Z,1606840449.535 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-12-01T16:34:09.941Z,1606840449.941 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-12-01T16:34:09.941Z,1606840449.941 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 14 2020-12-01T16:34:46.778Z,1606840486.778 [NAL9602](FAULT): GPS failed to acquire within timeout. 2020-12-01T16:34:46.778Z,1606840486.778 [NAL9602] Data Fault, FailCount= 4 2020-12-01T16:34:46.778Z,1606840486.778 [NAL9602](ERROR): Data Fault 2020-12-01T16:34:46.795Z,1606840486.795 [CBIT](ERROR): Data Fault in component: NAL9602 2020-12-01T16:34:47.181Z,1606840487.181 [NAL9602](INFO): Powering down 2020-12-01T16:34:48.037Z,1606840488.037 [CBIT](INFO): Clearing failed state for component NAL9602 2020-12-01T16:34:48.037Z,1606840488.037 [NAL9602] No Fault, FailCount= 4 2020-12-01T16:35:17.485Z,1606840517.485 [NAL9602](INFO): Powering up NAL9602 2020-12-01T16:35:28.389Z,1606840528.389 [NAL9602](INFO): NAL9602 initialized 2020-12-01T16:36:41.395Z,1606840601.395 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20201201T155147/Courier0013.lzma 2020-12-01T16:36:42.397Z,1606840602.397 [DataOverHttps](INFO): Moved sent file to Logs/20201201T155147/Courier0013.lzma.bak 2020-12-01T16:36:42.398Z,1606840602.398 [DataOverHttps](INFO): SBD MOMSN=13372242 2020-12-01T16:36:58.127Z,1606840618.127 [DataOverHttps](INFO): Sending 159 bytes from file Logs/20201201T155147/Express0014.lzma 2020-12-01T16:36:58.597Z,1606840618.597 [DropWeight](CRITICAL): DROP WEIGHT MISSING. 2020-12-01T16:36:58.597Z,1606840618.597 [DropWeight] Hardware Fault, FailCount= 1 2020-12-01T16:36:58.597Z,1606840618.597 [DropWeight](ERROR): Hardware Fault 2020-12-01T16:36:58.687Z,1606840618.687 [CBIT](INFO): Critical error at 20201201T163658 2020-12-01T16:36:58.690Z,1606840618.690 [CBIT](ERROR): Hardware Fault in component: DropWeight 2020-12-01T16:36:58.691Z,1606840618.691 [CBIT](CRITICAL): Hardware Fault in component: DropWeight 2020-12-01T16:36:59.037Z,1606840619.037 [CBIT](INFO): Critical error at 20201201T163658 2020-12-01T16:36:59.130Z,1606840619.130 [DataOverHttps](INFO): Moved sent file to Logs/20201201T155147/Express0014.lzma.bak 2020-12-01T16:36:59.130Z,1606840619.130 [DataOverHttps](INFO): SBD MOMSN=13372244 2020-12-01T16:37:00.235Z,1606840620.235 [Default:CheckIn:Read_Iridium] Stopped 2020-12-01T16:37:00.235Z,1606840620.235 [Default:CheckIn:C.Wait] Running Loop=1 2020-12-01T16:37:00.235Z,1606840620.235 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-12-01T16:37:10.357Z,1606840630.357 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 15 2020-12-01T16:37:10.357Z,1606840630.357 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-12-01T16:37:10.367Z,1606840630.367 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-12-01T16:37:10.770Z,1606840630.770 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-12-01T16:37:10.770Z,1606840630.770 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 15 2020-12-01T16:39:23.650Z,1606840763.650 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2020-12-01T16:40:11.348Z,1606840811.348 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 16 2020-12-01T16:40:11.348Z,1606840811.348 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-12-01T16:40:11.358Z,1606840811.358 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-12-01T16:40:11.735Z,1606840811.735 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-12-01T16:40:11.735Z,1606840811.735 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 16 2020-12-01T16:42:00.822Z,1606840920.822 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-12-01T16:42:00.822Z,1606840920.822 [Default:CheckIn:C.Wait] Stopped 2020-12-01T16:42:00.822Z,1606840920.822 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-12-01T16:42:00.822Z,1606840920.822 [Default:CheckIn:D] Running Loop=1 2020-12-01T16:42:01.242Z,1606840921.242 [Default:CheckIn:D] Stopped 2020-12-01T16:42:01.242Z,1606840921.242 [Default:CheckIn:E] Running Loop=1 2020-12-01T16:42:01.610Z,1606840921.610 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 46.339990 min 2020-12-01T16:42:01.610Z,1606840921.610 [Default:CheckIn:E] Stopped 2020-12-01T16:42:01.610Z,1606840921.610 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-12-01T16:42:01.610Z,1606840921.610 [Default:CheckIn] Stopped 2020-12-01T16:42:01.610Z,1606840921.610 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-12-01T16:42:01.610Z,1606840921.610 [Default:CheckIn](INFO): Running loop #5 2020-12-01T16:42:01.611Z,1606840921.611 [Default:CheckIn] Running Loop=5 2020-12-01T16:42:01.611Z,1606840921.611 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-12-01T16:42:01.611Z,1606840921.611 [Default:CheckIn:Read_GPS] Running Loop=1 2020-12-01T16:43:12.378Z,1606840992.378 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 17 2020-12-01T16:43:12.378Z,1606840992.378 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-12-01T16:43:12.388Z,1606840992.388 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-12-01T16:43:12.794Z,1606840992.794 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-12-01T16:43:12.794Z,1606840992.794 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 17 2020-12-01T16:44:02.055Z,1606841042.055 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164401.00,A,3648.16066,N,12147.27187,W,0.136,0.00,011220,,,A*7A 2020-12-01T16:44:02.058Z,1606841042.058 [NAL9602](INFO): GPS fix at 20201201T164401: (36.802678, -121.787864) 2020-12-01T16:44:02.079Z,1606841042.079 [Default:CheckIn:Read_GPS] Stopped 2020-12-01T16:44:02.079Z,1606841042.079 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-12-01T16:44:11.704Z,1606841051.704 [DataOverHttps](INFO): Sending 293 bytes from file Logs/20201201T155147/Courier0016.lzma 2020-12-01T16:44:12.706Z,1606841052.706 [DataOverHttps](INFO): Moved sent file to Logs/20201201T155147/Courier0016.lzma.bak 2020-12-01T16:44:12.706Z,1606841052.706 [DataOverHttps](INFO): SBD MOMSN=13372252 2020-12-01T16:44:34.145Z,1606841074.145 [NAL9602](INFO): Not Powering down - fast GPS 2020-12-01T16:46:54.372Z,1606841214.372 [DataOverHttps](INFO): Sending 296 bytes from file Logs/20201201T155147/Express0017.lzma 2020-12-01T16:46:55.374Z,1606841215.374 [DataOverHttps](INFO): Moved sent file to Logs/20201201T155147/Express0017.lzma.bak 2020-12-01T16:46:55.374Z,1606841215.374 [DataOverHttps](INFO): SBD MOMSN=13372269 2020-12-01T16:46:56.497Z,1606841216.497 [Default:CheckIn:Read_Iridium] Stopped 2020-12-01T16:46:56.497Z,1606841216.497 [Default:CheckIn:C.Wait] Running Loop=1 2020-12-01T16:46:56.497Z,1606841216.497 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-12-01T16:47:03.937Z,1606841223.937 [DataOverHttps](IMPORTANT): SBD MTMSN=20201201T164702 2020-12-01T16:47:11.548Z,1606841231.548 [DataOverHttps](INFO): Received command:restart app 2020-12-01T16:47:11.613Z,1606841231.613 [CommandLine](IMPORTANT): got command restart application 2020-12-01T16:47:12.616Z,1606841232.616 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2020-12-01T16:47:12.616Z,1606841232.616 [CommandLine ThreadHandler](INFO): Thread cancelled. 2020-12-01T16:47:12.804Z,1606841232.804 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2020-12-01T16:47:12.804Z,1606841232.804 [CommandLine ThreadHandler](INFO): Thread cancelled. 2020-12-01T16:47:12.805Z,1606841232.805 [CommandLine](INFO): Join timeout helper Thread ID is 5655 2020-12-01T16:47:12.805Z,1606841232.805 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2020-12-01T16:47:12.805Z,1606841232.805 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2020-12-01T16:47:12.805Z,1606841232.805 [NavChartDb](INFO): Join timeout helper Thread ID is 5656 2020-12-01T16:47:12.812Z,1606841232.812 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2020-12-01T16:47:12.812Z,1606841232.812 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2020-12-01T16:47:12.824Z,1606841232.824 [ComponentRegistry](INFO): Shutting down WetLabsUBAT ThreadHandler 2020-12-01T16:47:12.824Z,1606841232.824 [WetLabsUBAT ThreadHandler](INFO): Thread cancelled. 2020-12-01T16:47:12.824Z,1606841232.824 [WetLabsUBAT](INFO): Join timeout helper Thread ID is 5657 2020-12-01T16:47:13.168Z,1606841233.168 [WetLabsUBAT ThreadHandler](INFO): Uninitializing protected caller thread. 2020-12-01T16:47:13.169Z,1606841233.169 [WetLabsUBAT](INFO): Powering down 2020-12-01T16:47:13.169Z,1606841233.169 [WetLabsUBAT ThreadHandler](INFO): Thread cancelled. 2020-12-01T16:47:13.184Z,1606841233.184 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2020-12-01T16:47:13.184Z,1606841233.184 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2020-12-01T16:47:13.184Z,1606841233.184 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 5658 2020-12-01T16:47:13.628Z,1606841233.628 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2020-12-01T16:47:13.628Z,1606841233.628 [WetLabsBB2FL](INFO): Powering down 2020-12-01T16:47:13.629Z,1606841233.629 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2020-12-01T16:47:13.644Z,1606841233.644 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler 2020-12-01T16:47:13.644Z,1606841233.644 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2020-12-01T16:47:13.644Z,1606841233.644 [CTD_Seabird](INFO): Join timeout helper Thread ID is 5659 2020-12-01T16:47:14.148Z,1606841234.148 [CTD_Seabird](INFO): Powering down 2020-12-01T16:47:14.160Z,1606841234.160 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread. 2020-12-01T16:47:14.160Z,1606841234.160 [CTD_Seabird](INFO): Powering down 2020-12-01T16:47:14.172Z,1606841234.172 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2020-12-01T16:47:14.173Z,1606841234.173 [ComponentRegistry](INFO): Shutting down BackSeatDriver ThreadHandler 2020-12-01T16:47:14.173Z,1606841234.173 [BackSeatDriver ThreadHandler](INFO): Thread cancelled. 2020-12-01T16:47:14.174Z,1606841234.174 [BackSeatDriver](INFO): Join timeout helper Thread ID is 5660 2020-12-01T16:47:14.380Z,1606841234.380 [BackSeatDriver ThreadHandler](INFO): Uninitializing protected caller thread. 2020-12-01T16:47:14.380Z,1606841234.380 [BackSeatDriver ThreadHandler](INFO): Thread cancelled. 2020-12-01T16:47:14.396Z,1606841234.396 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2020-12-01T16:47:14.397Z,1606841234.397 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2020-12-01T16:47:14.397Z,1606841234.397 [Radio_Surface](INFO): Join timeout helper Thread ID is 5661 2020-12-01T16:47:14.780Z,1606841234.780 [Radio_Surface](INFO): Powering down 2020-12-01T16:47:14.781Z,1606841234.781 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2020-12-01T16:47:14.781Z,1606841234.781 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2020-12-01T16:47:14.796Z,1606841234.796 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler 2020-12-01T16:47:14.797Z,1606841234.797 [Onboard ThreadHandler](INFO): Thread cancelled. 2020-12-01T16:47:14.797Z,1606841234.797 [Onboard](INFO): Join timeout helper Thread ID is 5662 2020-12-01T16:47:15.560Z,1606841235.560 [DataOverHttps](INFO): Radio surface powered OFF, will not connect. 2020-12-01T16:47:18.000Z,1606841239.000 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread. 2020-12-01T16:47:19.000Z,1606841239.000 [Onboard ThreadHandler](INFO): Thread cancelled. 2020-12-01T16:47:19.014Z,1606841239.014 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler 2020-12-01T16:47:19.014Z,1606841239.014 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2020-12-01T16:47:19.015Z,1606841239.015 [DataOverHttps](INFO): Join timeout helper Thread ID is 5663 2020-12-01T16:47:19.576Z,1606841239.576 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread. 2020-12-01T16:47:19.576Z,1606841239.576 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2020-12-01T16:47:19.589Z,1606841239.589 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2020-12-01T16:47:19.589Z,1606841239.589 [logger ThreadHandler](INFO): Thread cancelled. 2020-12-01T16:47:19.589Z,1606841239.589 [logger](INFO): Join timeout helper Thread ID is 5664 2020-12-01T16:47:19.620Z,1606841239.620 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2020-12-01T16:47:19.620Z,1606841239.620 [logger ThreadHandler](INFO): Thread cancelled. 2020-12-01T16:47:19.628Z,1606841239.628 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2020-12-01T16:47:19.629Z,1606841239.629 [CommandLine ThreadHandler](INFO): Thread cancelled. 2020-12-01T16:47:19.629Z,1606841239.629 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2020-12-01T16:47:19.629Z,1606841239.629 [controlThread ThreadHandler](INFO): Thread cancelled. 2020-12-01T16:47:19.629Z,1606841239.629 [controlThread](INFO): Join timeout helper Thread ID is 5665 2020-12-01T16:47:19.892Z,1606841239.892 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2020-12-01T16:47:19.892Z,1606841239.892 [controlThread](DEBUG): Uninitializing ControlThread 2020-12-01T16:47:19.892Z,1606841239.892 [AHRS_M2](INFO): Powering down 2020-12-01T16:47:19.964Z,1606841239.964 [NAL9602](INFO): Powering down 2020-12-01T16:47:20.036Z,1606841240.036 [RDI_Pathfinder](INFO): Powering down 2020-12-01T16:47:20.037Z,1606841240.037 [DAT](INFO): Powering down 2020-12-01T16:47:20.157Z,1606841240.157 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator. 2020-12-01T16:47:20.158Z,1606841240.158 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator. 2020-12-01T16:47:20.158Z,1606841240.158 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2020-12-01T16:47:20.159Z,1606841240.159 [MissionManager](INFO): Uninitializing Mission Default 2020-12-01T16:47:20.159Z,1606841240.159 [Default] Stopped 2020-12-01T16:47:20.159Z,1606841240.159 [Default](DEBUG): Aggregate::uninitialize Default 2020-12-01T16:47:20.159Z,1606841240.159 [Default:B.GoToSurface] Stopped 2020-12-01T16:47:20.159Z,1606841240.159 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2020-12-01T16:47:20.159Z,1606841240.159 [Default:CheckIn] Stopped 2020-12-01T16:47:20.159Z,1606841240.159 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-12-01T16:47:20.159Z,1606841240.159 [Default:CheckIn:C.Wait] Stopped 2020-12-01T16:47:20.159Z,1606841240.159 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-12-01T16:47:20.161Z,1606841240.161 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2020-12-01T16:47:20.162Z,1606841240.162 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2020-12-01T16:47:20.162Z,1606841240.162 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2020-12-01T16:47:20.162Z,1606841240.162 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2020-12-01T16:47:20.163Z,1606841240.163 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2020-12-01T16:47:20.163Z,1606841240.163 [BuoyancyServo](INFO): Powering down 2020-12-01T16:47:20.176Z,1606841240.176 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2020-12-01T16:47:20.176Z,1606841240.176 [ElevatorServo](INFO): Powering down 2020-12-01T16:47:20.177Z,1606841240.177 [MassServo](DEBUG): Uninitialize Mass Servo. 2020-12-01T16:47:20.177Z,1606841240.177 [MassServo](INFO): Powering down 2020-12-01T16:47:20.178Z,1606841240.178 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2020-12-01T16:47:20.178Z,1606841240.178 [RudderServo](INFO): Powering down 2020-12-01T16:47:20.178Z,1606841240.178 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2020-12-01T16:47:20.178Z,1606841240.178 [ThrusterServo](INFO): Powering down 2020-12-01T16:47:20.179Z,1606841240.179 [SBIT](DEBUG): Uninitialize SBIT Component. 2020-12-01T16:47:20.179Z,1606841240.179 [IBIT](DEBUG): Uninitialize IBIT Component. 2020-12-01T16:47:20.180Z,1606841240.180 [CBIT](DEBUG): Uninitialize CBIT Component. 2020-12-01T16:47:20.180Z,1606841240.180 [CBIT](DEBUG): Powering off loads. 2020-12-01T16:47:20.192Z,1606841240.192 [CBIT](DEBUG): Disabling WDT. 2020-12-01T16:47:20.204Z,1606841240.204 [CBIT](DEBUG): Opening all GF detection circuits. 2020-12-01T16:47:20.205Z,1606841240.205 [controlThread ThreadHandler](INFO): Thread cancelled. 2020-12-01T16:47:20.289Z,1606841240.289 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2020-12-01T16:47:20.291Z,1606841240.291 [Onboard ThreadHandler](INFO): Thread cancelled. 2020-12-01T16:47:20.297Z,1606841240.297 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2020-12-01T16:47:20.355Z,1606841240.355 [WetLabsUBAT ThreadHandler](INFO): Thread cancelled. 2020-12-01T16:47:20.356Z,1606841240.356 [WetLabsUBAT](INFO): WetLabs destructor: _dataLog is not open 2020-12-01T16:47:20.356Z,1606841240.356 [WetLabsUBAT](INFO): WetLabs destructor: done 2020-12-01T16:47:20.359Z,1606841240.359 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2020-12-01T16:47:20.362Z,1606841240.362 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2020-12-01T16:47:20.365Z,1606841240.365 [BackSeatDriver ThreadHandler](INFO): Thread cancelled. 2020-12-01T16:47:20.375Z,1606841240.375 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2020-12-01T16:47:20.446Z,1606841240.446 [logger ThreadHandler](INFO): Thread cancelled.