2019-09-23T20:31:56.658Z,1569270716.658 [Supervisor](DEBUG): Initializing supervisor. 2019-09-23T20:31:56.661Z,1569270716.661 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2019-09-23T20:31:56.662Z,1569270716.662 [SyncHandler](INFO): Protected caller Thread ID is 1543 2019-09-23T20:31:56.663Z,1569270716.663 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2019-09-23T20:31:56.664Z,1569270716.664 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2019-09-23T20:31:56.664Z,1569270716.664 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 1544 2019-09-23T20:31:56.667Z,1569270716.667 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2019-09-23T20:31:56.678Z,1569270716.678 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2019-09-23T20:31:56.679Z,1569270716.679 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2019-09-23T20:31:56.680Z,1569270716.680 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 1545 2019-09-23T20:31:56.680Z,1569270716.680 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2019-09-23T20:31:56.681Z,1569270716.681 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2019-09-23T20:31:56.682Z,1569270716.682 [logger ThreadHandler](INFO): Protected caller Thread ID is 1546 2019-09-23T20:31:56.684Z,1569270716.684 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2019-09-23T20:31:56.684Z,1569270716.684 [Supervisor](INFO): Looking for Config files in directory: Config/ 2019-09-23T20:31:56.686Z,1569270716.686 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2019-09-23T20:31:57.096Z,1569270717.096 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2019-09-23T20:31:57.096Z,1569270717.096 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2019-09-23T20:31:57.237Z,1569270717.237 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2019-09-23T20:31:57.238Z,1569270717.238 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2019-09-23T20:31:57.318Z,1569270717.318 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2019-09-23T20:31:57.416Z,1569270717.416 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2019-09-23T20:31:57.417Z,1569270717.417 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2019-09-23T20:31:57.511Z,1569270717.511 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2019-09-23T20:31:57.512Z,1569270717.512 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2019-09-23T20:31:57.969Z,1569270717.969 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2019-09-23T20:31:57.970Z,1569270717.970 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2019-09-23T20:31:58.169Z,1569270718.169 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2019-09-23T20:31:58.170Z,1569270718.170 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2019-09-23T20:31:58.753Z,1569270718.753 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2019-09-23T20:31:58.754Z,1569270718.754 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2019-09-23T20:31:58.949Z,1569270718.949 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2019-09-23T20:31:58.950Z,1569270718.950 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2019-09-23T20:31:59.247Z,1569270719.247 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2019-09-23T20:31:59.247Z,1569270719.247 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2019-09-23T20:31:59.456Z,1569270719.456 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2019-09-23T20:31:59.456Z,1569270719.456 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2019-09-23T20:31:59.597Z,1569270719.597 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2019-09-23T20:31:59.597Z,1569270719.597 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2019-09-23T20:32:00.203Z,1569270720.203 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2019-09-23T20:32:00.203Z,1569270720.203 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2019-09-23T20:32:00.545Z,1569270720.545 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2019-09-23T20:32:00.546Z,1569270720.546 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2019-09-23T20:32:00.751Z,1569270720.751 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2019-09-23T20:32:00.753Z,1569270720.753 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-triton/ 2019-09-23T20:32:00.754Z,1569270720.754 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/vehicle.cfg 2019-09-23T20:32:00.952Z,1569270720.952 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/secure.cfg 2019-09-23T20:32:01.035Z,1569270721.035 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Science.cfg 2019-09-23T20:32:01.165Z,1569270721.165 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Simulator.cfg 2019-09-23T20:32:01.251Z,1569270721.251 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Battery.cfg 2019-09-23T20:32:01.481Z,1569270721.481 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2019-09-23T20:32:01.481Z,1569270721.481 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/logger.cfg 2019-09-23T20:32:01.575Z,1569270721.575 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Servo.cfg 2019-09-23T20:32:01.682Z,1569270721.682 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Navigation.cfg 2019-09-23T20:32:01.774Z,1569270721.774 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Sensor.cfg 2019-09-23T20:32:01.924Z,1569270721.924 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Control.cfg 2019-09-23T20:32:02.023Z,1569270722.023 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/BIT.cfg 2019-09-23T20:32:02.121Z,1569270722.121 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-triton/root/ 2019-09-23T20:32:02.121Z,1569270722.121 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2019-09-23T20:32:02.124Z,1569270722.124 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2019-09-23T20:32:02.138Z,1569270722.138 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2019-09-23T20:32:02.138Z,1569270722.138 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2019-09-23T20:32:02.207Z,1569270722.207 [VerticalControl](DEBUG): Construct VerticalControl. 2019-09-23T20:32:02.320Z,1569270722.320 [VerticalControl] Loaded 2019-09-23T20:32:02.320Z,1569270722.320 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2019-09-23T20:32:02.321Z,1569270722.321 [HorizontalControl](DEBUG): Construct HorizontalControl. 2019-09-23T20:32:02.389Z,1569270722.389 [HorizontalControl] Loaded 2019-09-23T20:32:02.390Z,1569270722.390 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2019-09-23T20:32:02.390Z,1569270722.390 [SpeedControl](DEBUG): Construct SpeedControl. 2019-09-23T20:32:02.396Z,1569270722.396 [SpeedControl] Loaded 2019-09-23T20:32:02.396Z,1569270722.396 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2019-09-23T20:32:02.397Z,1569270722.397 [LoopControl](DEBUG): Construct LoopControl. 2019-09-23T20:32:02.397Z,1569270722.397 [LoopControl] Loaded 2019-09-23T20:32:02.398Z,1569270722.398 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2019-09-23T20:32:02.398Z,1569270722.398 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2019-09-23T20:32:02.399Z,1569270722.399 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2019-09-23T20:32:02.526Z,1569270722.526 [BuoyancyServo] Loaded 2019-09-23T20:32:02.527Z,1569270722.527 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2019-09-23T20:32:02.538Z,1569270722.538 [ElevatorServo] Loaded 2019-09-23T20:32:02.538Z,1569270722.538 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2019-09-23T20:32:02.549Z,1569270722.549 [MassServo] Loaded 2019-09-23T20:32:02.549Z,1569270722.549 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2019-09-23T20:32:02.560Z,1569270722.560 [RudderServo] Loaded 2019-09-23T20:32:02.560Z,1569270722.560 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2019-09-23T20:32:02.571Z,1569270722.571 [ThrusterServo] Loaded 2019-09-23T20:32:02.571Z,1569270722.571 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2019-09-23T20:32:02.572Z,1569270722.572 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2019-09-23T20:32:02.572Z,1569270722.572 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2019-09-23T20:32:02.614Z,1569270722.614 [DepthRateCalculator] Loaded 2019-09-23T20:32:02.614Z,1569270722.614 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2019-09-23T20:32:02.620Z,1569270722.620 [PitchRateCalculator] Loaded 2019-09-23T20:32:02.620Z,1569270722.620 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2019-09-23T20:32:02.635Z,1569270722.635 [SpeedCalculator] Loaded 2019-09-23T20:32:02.635Z,1569270722.635 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2019-09-23T20:32:02.656Z,1569270722.656 [TempGradientCalculator] Loaded 2019-09-23T20:32:02.656Z,1569270722.656 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2019-09-23T20:32:02.662Z,1569270722.662 [YawRateCalculator] Loaded 2019-09-23T20:32:02.662Z,1569270722.662 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2019-09-23T20:32:02.692Z,1569270722.692 [ElevatorOffsetCalculator] Loaded 2019-09-23T20:32:02.692Z,1569270722.692 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2019-09-23T20:32:02.692Z,1569270722.692 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2019-09-23T20:32:02.693Z,1569270722.693 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2019-09-23T20:32:02.798Z,1569270722.798 [DeadReckonUsingMultipleVelocitySources] Loaded 2019-09-23T20:32:02.798Z,1569270722.798 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2019-09-23T20:32:02.818Z,1569270722.818 [NavChart] Loaded 2019-09-23T20:32:02.819Z,1569270722.819 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2019-09-23T20:32:02.823Z,1569270722.823 [UniversalFixResidualReporter] Loaded 2019-09-23T20:32:02.824Z,1569270722.824 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2019-09-23T20:32:02.824Z,1569270722.824 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2019-09-23T20:32:02.825Z,1569270722.825 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2019-09-23T20:32:03.096Z,1569270723.096 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_orientation 2019-09-23T20:32:03.101Z,1569270723.101 [AHRS_M2](INFO): created writer for : platform_orientation 2019-09-23T20:32:03.103Z,1569270723.103 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_magnetic_orientation 2019-09-23T20:32:03.108Z,1569270723.108 [AHRS_M2](INFO): created writer for : platform_magnetic_orientation 2019-09-23T20:32:03.109Z,1569270723.109 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_pitch_angle 2019-09-23T20:32:03.114Z,1569270723.114 [AHRS_M2](INFO): created writer for : platform_pitch_angle 2019-09-23T20:32:03.115Z,1569270723.115 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_roll_angle 2019-09-23T20:32:03.120Z,1569270723.120 [AHRS_M2](INFO): created writer for : platform_roll_angle 2019-09-23T20:32:03.191Z,1569270723.191 [AHRS_M2] Loaded 2019-09-23T20:32:03.191Z,1569270723.191 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2019-09-23T20:32:03.264Z,1569270723.264 [DataOverHttps] Loaded 2019-09-23T20:32:03.265Z,1569270723.265 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2019-09-23T20:32:03.266Z,1569270723.266 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 408134E0 2019-09-23T20:32:03.266Z,1569270723.266 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 1625 2019-09-23T20:32:03.280Z,1569270723.280 [Depth_Keller] Loaded 2019-09-23T20:32:03.280Z,1569270723.280 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2019-09-23T20:32:03.285Z,1569270723.285 [DropWeight] Loaded 2019-09-23T20:32:03.285Z,1569270723.285 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2019-09-23T20:32:03.415Z,1569270723.415 [DVL_micro] Loaded 2019-09-23T20:32:03.415Z,1569270723.415 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread. 2019-09-23T20:32:03.513Z,1569270723.513 [NAL9602] Loaded 2019-09-23T20:32:03.513Z,1569270723.513 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2019-09-23T20:32:03.529Z,1569270723.529 [Onboard] Loaded 2019-09-23T20:32:03.529Z,1569270723.529 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2019-09-23T20:32:03.533Z,1569270723.533 [Radio_Surface] Loaded 2019-09-23T20:32:03.533Z,1569270723.533 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2019-09-23T20:32:03.534Z,1569270723.534 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408434E0 2019-09-23T20:32:03.534Z,1569270723.534 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 1626 2019-09-23T20:32:03.784Z,1569270723.784 [DAT] Loaded 2019-09-23T20:32:03.784Z,1569270723.784 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread. 2019-09-23T20:32:05.640Z,1569270725.640 [BPC1] Loaded 2019-09-23T20:32:05.640Z,1569270725.640 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2019-09-23T20:32:05.662Z,1569270725.662 [BR_Ping1D] Loaded 2019-09-23T20:32:05.662Z,1569270725.662 [ComponentRegistry](DEBUG): SyncComponent "BR_Ping1D" handled in the control thread. 2019-09-23T20:32:05.662Z,1569270725.662 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2019-09-23T20:32:05.663Z,1569270725.663 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2019-09-23T20:32:05.733Z,1569270725.733 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2019-09-23T20:32:05.734Z,1569270725.734 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2019-09-23T20:32:05.833Z,1569270725.833 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2019-09-23T20:32:05.834Z,1569270725.834 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2019-09-23T20:32:05.866Z,1569270725.866 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2019-09-23T20:32:05.867Z,1569270725.867 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2019-09-23T20:32:06.046Z,1569270726.046 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_density 2019-09-23T20:32:06.052Z,1569270726.052 [CTD_Seabird](INFO): created writer for : sea_water_density 2019-09-23T20:32:06.052Z,1569270726.052 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): depth 2019-09-23T20:32:06.057Z,1569270726.057 [CTD_Seabird](INFO): created writer for : depth 2019-09-23T20:32:06.058Z,1569270726.058 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_pressure 2019-09-23T20:32:06.063Z,1569270726.063 [CTD_Seabird](INFO): created writer for : sea_water_pressure 2019-09-23T20:32:06.063Z,1569270726.063 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_salinity 2019-09-23T20:32:06.069Z,1569270726.069 [CTD_Seabird](INFO): created writer for : sea_water_salinity 2019-09-23T20:32:06.069Z,1569270726.069 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_temperature 2019-09-23T20:32:06.074Z,1569270726.074 [CTD_Seabird](INFO): created writer for : sea_water_temperature 2019-09-23T20:32:06.075Z,1569270726.075 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_electrical_conductivity 2019-09-23T20:32:06.080Z,1569270726.080 [CTD_Seabird](INFO): created writer for : sea_water_electrical_conductivity 2019-09-23T20:32:06.081Z,1569270726.081 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): speed_of_sound_in_sea_water 2019-09-23T20:32:06.086Z,1569270726.086 [CTD_Seabird](INFO): created writer for : speed_of_sound_in_sea_water 2019-09-23T20:32:06.086Z,1569270726.086 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): mass_concentration_of_oxygen_in_sea_water 2019-09-23T20:32:06.091Z,1569270726.091 [CTD_Seabird](INFO): created writer for : mass_concentration_of_oxygen_in_sea_water 2019-09-23T20:32:06.092Z,1569270726.092 [CTD_Seabird](DEBUG): LcmSlateWriter::add(DAtaURI): CTD_Seabird.sea_water_dissolved_oxygen_freq 2019-09-23T20:32:06.092Z,1569270726.092 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): dataName: sea_water_dissolved_oxygen_freq 2019-09-23T20:32:06.125Z,1569270726.125 [CTD_Seabird] Loaded 2019-09-23T20:32:06.126Z,1569270726.126 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2019-09-23T20:32:06.127Z,1569270726.127 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 409DA4E0 2019-09-23T20:32:06.127Z,1569270726.127 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 1627 2019-09-23T20:32:06.142Z,1569270726.142 [PAR_Licor] Loaded 2019-09-23T20:32:06.142Z,1569270726.142 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2019-09-23T20:32:06.190Z,1569270726.190 [WetLabsBB2FL] Loaded 2019-09-23T20:32:06.190Z,1569270726.190 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2019-09-23T20:32:06.191Z,1569270726.191 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40A0A4E0 2019-09-23T20:32:06.192Z,1569270726.192 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 1628 2019-09-23T20:32:06.193Z,1569270726.193 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2019-09-23T20:32:06.193Z,1569270726.193 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2019-09-23T20:32:06.490Z,1569270726.490 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2019-09-23T20:32:06.490Z,1569270726.490 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2019-09-23T20:32:06.629Z,1569270726.629 [SBIT](DEBUG): Construct Startup Built In Test. 2019-09-23T20:32:06.641Z,1569270726.641 [SBIT] Loaded 2019-09-23T20:32:06.641Z,1569270726.641 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2019-09-23T20:32:06.642Z,1569270726.642 [IBIT](DEBUG): Construct Initiated Built In Test. 2019-09-23T20:32:06.653Z,1569270726.653 [IBIT] Loaded 2019-09-23T20:32:06.653Z,1569270726.653 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2019-09-23T20:32:06.656Z,1569270726.656 [CBIT](DEBUG): Construct Continuous Built In Test. 2019-09-23T20:32:06.797Z,1569270726.797 [CBIT] Loaded 2019-09-23T20:32:06.798Z,1569270726.798 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2019-09-23T20:32:06.798Z,1569270726.798 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2019-09-23T20:32:06.802Z,1569270726.802 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2019-09-23T20:32:06.803Z,1569270726.803 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2019-09-23T20:32:06.809Z,1569270726.809 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2019-09-23T20:32:06.810Z,1569270726.810 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40AE94E0 2019-09-23T20:32:06.811Z,1569270726.811 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 1629 2019-09-23T20:32:06.815Z,1569270726.815 [Supervisor](INFO): Main Thread ID is 801 2019-09-23T20:32:06.816Z,1569270726.816 [Supervisor](DEBUG): Running supervisor. 2019-09-23T20:32:06.816Z,1569270726.816 [CommandLine ThreadHandler](INFO): Handler Thread ID is 1630 2019-09-23T20:32:06.819Z,1569270726.819 [controlThread ThreadHandler](INFO): Handler Thread ID is 1631 2019-09-23T20:32:06.819Z,1569270726.819 [controlThread](DEBUG): Initializing ControlThread 2019-09-23T20:32:06.820Z,1569270726.820 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2019-09-23T20:32:06.821Z,1569270726.821 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2019-09-23T20:32:06.822Z,1569270726.822 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2019-09-23T20:32:06.823Z,1569270726.823 [LoopControl](DEBUG): Initialize LoopControlComponent. 2019-09-23T20:32:06.824Z,1569270726.824 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2019-09-23T20:32:06.824Z,1569270726.824 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2019-09-23T20:32:06.825Z,1569270726.825 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2019-09-23T20:32:06.825Z,1569270726.825 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2019-09-23T20:32:06.825Z,1569270726.825 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2019-09-23T20:32:06.826Z,1569270726.826 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2019-09-23T20:32:06.827Z,1569270726.827 [NavChart](DEBUG): Initialize NavChart Navigation. 2019-09-23T20:32:06.827Z,1569270726.827 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2019-09-23T20:32:06.833Z,1569270726.833 [SBIT](INFO): Initialize SBIT Component. 2019-09-23T20:32:06.833Z,1569270726.833 [SBIT](IMPORTANT): git: 2019-09-23 2019-09-23T20:32:06.834Z,1569270726.834 [SBIT](INFO): git hash: 7e4785a483d29691317a903ec02330d414b844f9 2019-09-23T20:32:06.834Z,1569270726.834 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2019-09-23T20:32:06.835Z,1569270726.835 [SBIT](INFO): Kernel Reporting Different Version From Configuration. Kernel Expected: #1 PREEMPT Tue Dec 18 21:19:28 PST 2018 Kernel Reported: #1 PREEMPT Thu Feb 21 11:17:40 PST 2019 2019-09-23T20:32:06.836Z,1569270726.836 [SBIT](INFO): Beginning SBIT in 30.000000 seconds. 2019-09-23T20:32:06.837Z,1569270726.837 [IBIT](INFO): Initialize IBIT Component. 2019-09-23T20:32:06.838Z,1569270726.838 [CBIT](DEBUG): Initialize CBIT Component. 2019-09-23T20:32:06.839Z,1569270726.839 [logger ThreadHandler](INFO): Handler Thread ID is 1632 2019-09-23T20:32:06.849Z,1569270726.849 [CBIT](DEBUG): Initialized mux pins. 2019-09-23T20:32:06.849Z,1569270726.849 [CBIT](DEBUG): Initializing the watchdog timer. 2019-09-23T20:32:06.857Z,1569270726.857 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 1633 2019-09-23T20:32:06.858Z,1569270726.858 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2019-09-23T20:32:06.869Z,1569270726.869 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 1634 2019-09-23T20:32:06.873Z,1569270726.873 [CBIT](CRITICAL): LAST REBOOT DUE TO WATCHDOG TIMER RESET. 2019-09-23T20:32:06.873Z,1569270726.873 [CBIT](DEBUG): Initializing heartbeat. 2019-09-23T20:32:06.881Z,1569270726.881 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 1635 2019-09-23T20:32:06.882Z,1569270726.882 [CTD_Seabird](DEBUG): Initializing CTD_Seabird. 2019-09-23T20:32:06.885Z,1569270726.885 [CTD_Seabird](INFO): Opening uart, block timeout 10ths=20 2019-09-23T20:32:06.886Z,1569270726.886 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 1637 2019-09-23T20:32:06.887Z,1569270726.887 [WetLabsBB2FL](INFO): Powering down 2019-09-23T20:32:06.913Z,1569270726.913 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 1638 2019-09-23T20:32:06.916Z,1569270726.916 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2019-09-23T20:32:06.916Z,1569270726.916 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2019-09-23T20:32:06.917Z,1569270726.917 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2019-09-23T20:32:06.917Z,1569270726.917 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2019-09-23T20:32:06.917Z,1569270726.917 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2019-09-23T20:32:06.917Z,1569270726.917 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2019-09-23T20:32:06.918Z,1569270726.918 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000 2019-09-23T20:32:06.918Z,1569270726.918 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2019-09-23T20:32:06.918Z,1569270726.918 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2019-09-23T20:32:06.918Z,1569270726.918 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2019-09-23T20:32:06.918Z,1569270726.918 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000 2019-09-23T20:32:06.918Z,1569270726.918 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2019-09-23T20:32:06.919Z,1569270726.919 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000 2019-09-23T20:32:06.919Z,1569270726.919 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2019-09-23T20:32:06.919Z,1569270726.919 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000 2019-09-23T20:32:06.919Z,1569270726.919 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2019-09-23T20:32:06.945Z,1569270726.945 [CBIT](DEBUG): Deactivating GF circuits. 2019-09-23T20:32:06.945Z,1569270726.945 [CBIT](DEBUG): Deactivating emergency mode. 2019-09-23T20:32:06.980Z,1569270726.980 [CBIT](DEBUG): Backplane powered. 2019-09-23T20:32:06.981Z,1569270726.981 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2019-09-23T20:32:06.991Z,1569270726.991 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2019-09-23T20:32:07.001Z,1569270727.001 [MissionManager](DEBUG): 2019-09-23T20:32:07.002Z,1569270727.002 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2019-09-23T20:32:07.064Z,1569270727.064 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2019-09-23T20:32:07.081Z,1569270727.081 [Default:A.Wait](DEBUG): Construct Wait. 2019-09-23T20:32:07.083Z,1569270727.083 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2019-09-23T20:32:07.102Z,1569270727.102 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2019-09-23T20:32:07.104Z,1569270727.104 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2019-09-23T20:32:07.130Z,1569270727.130 [Default:E.Execute](DEBUG): Construct Execute. 2019-09-23T20:32:07.152Z,1569270727.152 [MissionManager](DEBUG): 0 Wait a moment to see if the scheduler starts a new mission before starting to actually run Default. 13 Burn on Dropped weight due to communications timeout. 5 Default mission has been running for Restarting logs and Default mission. restart logs 2019-09-23T20:32:07.167Z,1569270727.167 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,DVL_micro,NAL9602,Onboard,DAT,BPC1,BR_Ping1D,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2019-09-23T20:32:07.193Z,1569270727.193 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2019-09-23T20:32:07.227Z,1569270727.227 [Depth_Keller](ERROR): Pressure reading out of range: 1925.893799 decibar 2019-09-23T20:32:07.250Z,1569270727.250 [DVL_micro](INFO): Initializing 2019-09-23T20:32:07.273Z,1569270727.273 [Radio_Surface](INFO): Powering up 2019-09-23T20:32:07.275Z,1569270727.275 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2 2019-09-23T20:32:07.275Z,1569270727.275 [DAT](INFO): Powering up 2019-09-23T20:32:07.275Z,1569270727.275 [DAT](DEBUG): Initializing DAT. 2019-09-23T20:32:07.317Z,1569270727.317 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2 2019-09-23T20:32:07.429Z,1569270727.429 [DepthRateCalculator](ERROR): Depth measurement is not active 2019-09-23T20:32:07.471Z,1569270727.471 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2019-09-23T20:32:07.477Z,1569270727.477 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2019-09-23T20:32:07.478Z,1569270727.478 [ElevatorServo](DEBUG): Initializing EZServoServo. 2019-09-23T20:32:07.485Z,1569270727.485 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2019-09-23T20:32:07.486Z,1569270727.486 [MassServo](DEBUG): Initializing EZServoServo. 2019-09-23T20:32:07.493Z,1569270727.493 [MassServo](DEBUG): Initializing MassServo. 2019-09-23T20:32:07.494Z,1569270727.494 [RudderServo](DEBUG): Initializing EZServoServo. 2019-09-23T20:32:07.501Z,1569270727.501 [RudderServo](DEBUG): Initializing RudderServo. 2019-09-23T20:32:07.502Z,1569270727.502 [ThrusterServo](DEBUG): Initializing EZServoServo. 2019-09-23T20:32:07.509Z,1569270727.509 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2019-09-23T20:32:07.511Z,1569270727.511 [CommandLine](FAULT): Scheduling is paused 2019-09-23T20:32:07.512Z,1569270727.512 [CBIT](INFO): Critical error at 20190923T203206 2019-09-23T20:32:07.512Z,1569270727.512 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals 2019-09-23T20:32:08.369Z,1569270728.369 [RudderServo](ERROR): Rudder initialization uart error serial timeout 2019-09-23T20:32:08.369Z,1569270728.369 [RudderServo](FAULT): Rudder failed to initialize 2019-09-23T20:32:08.369Z,1569270728.369 [RudderServo] Communications Fault, FailCount= 1 2019-09-23T20:32:08.369Z,1569270728.369 [RudderServo](ERROR): Communications Fault 2019-09-23T20:32:08.480Z,1569270728.480 [CBIT](ERROR): Communications Fault in component: RudderServo 2019-09-23T20:32:08.686Z,1569270728.686 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2019-09-23T20:32:08.686Z,1569270728.686 [RudderServo](INFO): Powering down 2019-09-23T20:32:09.346Z,1569270729.346 [RudderServo](DEBUG): Initializing EZServoServo. 2019-09-23T20:32:09.465Z,1569270729.465 [RudderServo](DEBUG): Initializing RudderServo. 2019-09-23T20:32:09.469Z,1569270729.469 [CBIT](INFO): Clearing failed state for component RudderServo 2019-09-23T20:32:09.470Z,1569270729.470 [RudderServo] No Fault, FailCount= 1 2019-09-23T20:32:17.870Z,1569270737.870 [DVL_micro](ERROR): No DVL communication! Re-initializing 2019-09-23T20:32:17.871Z,1569270737.871 [DVL_micro] Communications Fault, FailCount= 1 2019-09-23T20:32:17.871Z,1569270737.871 [DVL_micro](ERROR): Communications Fault 2019-09-23T20:32:17.920Z,1569270737.920 [CBIT](ERROR): Communications Fault in component: DVL_micro 2019-09-23T20:32:18.333Z,1569270738.333 [DVL_micro](INFO): uninitialize:Powering down 2019-09-23T20:32:19.138Z,1569270739.138 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-09-23T20:32:19.138Z,1569270739.138 [DVL_micro] No Fault, FailCount= 1 2019-09-23T20:32:19.472Z,1569270739.472 [DVL_micro](INFO): Initializing 2019-09-23T20:32:20.697Z,1569270740.697 [DAT](INFO): setting local address to 5 2019-09-23T20:32:21.097Z,1569270741.097 [DAT](INFO): set local address to 5 2019-09-23T20:32:29.989Z,1569270749.989 [DVL_micro](ERROR): No DVL communication! Re-initializing 2019-09-23T20:32:29.989Z,1569270749.989 [DVL_micro] Communications Fault, FailCount= 2 2019-09-23T20:32:29.989Z,1569270749.989 [DVL_micro](ERROR): Communications Fault 2019-09-23T20:32:30.075Z,1569270750.075 [CBIT](ERROR): Communications Fault in component: DVL_micro 2019-09-23T20:32:30.445Z,1569270750.445 [DVL_micro](INFO): uninitialize:Powering down 2019-09-23T20:32:31.265Z,1569270751.265 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-09-23T20:32:31.266Z,1569270751.266 [DVL_micro] No Fault, FailCount= 2 2019-09-23T20:32:31.609Z,1569270751.609 [DVL_micro](INFO): Initializing 2019-09-23T20:32:33.610Z,1569270753.610 [NAL9602](INFO): Powering up NAL9602 2019-09-23T20:32:37.296Z,1569270757.296 [SBIT](IMPORTANT): Beginning Startup BIT 2019-09-23T20:32:37.309Z,1569270757.309 [CBIT](IMPORTANT): Beginning ground fault scan 2019-09-23T20:32:41.806Z,1569270761.806 [CommandLine](IMPORTANT): got command show variable control.bu 2019-09-23T20:32:42.134Z,1569270762.134 [CommandLine](IMPORTANT): VerticalControl.buoyancyDefault (cubic_centimeter) 2019-09-23T20:32:42.135Z,1569270762.135 [CommandLine](IMPORTANT): VerticalControl.buoyancyLimitHiCC (cubic_centimeter) 2019-09-23T20:32:42.135Z,1569270762.135 [CommandLine](IMPORTANT): VerticalControl.buoyancyLimitLoCC (cubic_centimeter) 2019-09-23T20:32:42.135Z,1569270762.135 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral (cubic_centimeter) 2019-09-23T20:32:42.136Z,1569270762.136 [CommandLine](IMPORTANT): VerticalControl.buoyancyPumpDepth (meter) 2019-09-23T20:32:42.202Z,1569270762.202 [DVL_micro](ERROR): No DVL communication! Re-initializing 2019-09-23T20:32:42.202Z,1569270762.202 [DVL_micro] Communications Fault, FailCount= 3 2019-09-23T20:32:42.202Z,1569270762.202 [DVL_micro](ERROR): Communications Fault 2019-09-23T20:32:42.267Z,1569270762.267 [CommandLine](IMPORTANT): VeritcalControl.buoyancyLimitHiCC (cubic_centimeter) 2019-09-23T20:32:42.278Z,1569270762.278 [CommandLine](IMPORTANT): VerticalControl.buoyancyAction (cubic_centimeter) 2019-09-23T20:32:42.417Z,1569270762.417 [CBIT](ERROR): Communications Fault in component: DVL_micro 2019-09-23T20:32:42.673Z,1569270762.673 [DVL_micro](INFO): uninitialize:Powering down 2019-09-23T20:32:43.513Z,1569270763.513 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-09-23T20:32:43.513Z,1569270763.513 [DVL_micro] No Fault, FailCount= 3 2019-09-23T20:32:43.828Z,1569270763.828 [DVL_micro](INFO): Initializing 2019-09-23T20:32:44.626Z,1569270764.626 [NAL9602](INFO): NAL9602 initialized 2019-09-23T20:32:45.449Z,1569270765.449 [NAL9602](DEBUG): Fix Requested 2019-09-23T20:32:48.357Z,1569270768.357 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.005863 CHAN A1 (24V): 0.000640 CHAN A2 (12V): -0.005125 CHAN A3 (5V): -0.003926 CHAN B0 (3.3V): -0.001193 CHAN B1 (3.15aV): -0.001462 CHAN B2 (3.15bV): -0.001261 CHAN B3 (GND): -0.001987 OPEN: 0.005926 Full Scale Calc: 4.765 mA, -1.589 mA 2019-09-23T20:32:54.525Z,1569270774.525 [DVL_micro](ERROR): No DVL communication! Re-initializing 2019-09-23T20:32:54.525Z,1569270774.525 [DVL_micro] Communications Fault, FailCount= 4 2019-09-23T20:32:54.525Z,1569270774.525 [DVL_micro](ERROR): Communications Fault 2019-09-23T20:32:54.718Z,1569270774.718 [CBIT](ERROR): Communications Fault in component: DVL_micro 2019-09-23T20:32:55.001Z,1569270775.001 [DVL_micro](INFO): uninitialize:Powering down 2019-09-23T20:32:55.873Z,1569270775.873 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-09-23T20:32:55.873Z,1569270775.873 [DVL_micro] No Fault, FailCount= 4 2019-09-23T20:32:56.132Z,1569270776.132 [DVL_micro](INFO): Initializing 2019-09-23T20:32:56.810Z,1569270776.810 [CommandLine](IMPORTANT): got command configSet VerticalControl.buoyancyDefault 200.000000 cubic_centimeter persist 2019-09-23T20:33:06.634Z,1569270786.634 [DVL_micro](ERROR): No DVL communication! Re-initializing 2019-09-23T20:33:06.634Z,1569270786.634 [DVL_micro] Communications Fault, FailCount= 5 2019-09-23T20:33:06.634Z,1569270786.634 [DVL_micro](ERROR): Communications Fault 2019-09-23T20:33:06.761Z,1569270786.761 [CBIT](ERROR): Communications Fault in component: DVL_micro 2019-09-23T20:33:06.762Z,1569270786.762 [CBIT](CRITICAL): Communications Fault in component: DVL_micro 2019-09-23T20:33:07.101Z,1569270787.101 [DVL_micro](INFO): uninitialize:Powering down 2019-09-23T20:33:07.231Z,1569270787.231 [CBIT](INFO): Critical error at 20190923T203306 2019-09-23T20:33:09.642Z,1569270789.642 [CommandLine](IMPORTANT): got command show variable control.mass 2019-09-23T20:33:09.726Z,1569270789.726 [CommandLine](IMPORTANT): VerticalControl.massBackOnGoToSurface (bool) 2019-09-23T20:33:09.727Z,1569270789.727 [CommandLine](IMPORTANT): VerticalControl.massDeadband (millimeter) 2019-09-23T20:33:09.727Z,1569270789.727 [CommandLine](IMPORTANT): VerticalControl.massDefault (centimeter) 2019-09-23T20:33:09.728Z,1569270789.728 [CommandLine](IMPORTANT): VerticalControl.massFilterLimit (degree) 2019-09-23T20:33:09.728Z,1569270789.728 [CommandLine](IMPORTANT): VerticalControl.massFilterWidth (second) 2019-09-23T20:33:09.729Z,1569270789.729 [CommandLine](IMPORTANT): VerticalControl.massPositionLimitAft (millimeter) 2019-09-23T20:33:09.729Z,1569270789.729 [CommandLine](IMPORTANT): VerticalControl.massPositionLimitFwd (millimeter) 2019-09-23T20:33:09.729Z,1569270789.729 [CommandLine](IMPORTANT): VerticalControl.massTurnTime (second) 2019-09-23T20:33:09.742Z,1569270789.742 [CommandLine](IMPORTANT): VerticalControl.massPositionCmd (meter) 2019-09-23T20:33:09.743Z,1569270789.743 [CommandLine](IMPORTANT): VerticalControl.massIntegralInternal (meter) 2019-09-23T20:33:09.744Z,1569270789.744 [CommandLine](IMPORTANT): VerticalControl.massPitchErrorInternal (radian) 2019-09-23T20:33:09.745Z,1569270789.745 [CommandLine](IMPORTANT): VerticalControl.massPositionAction (meter) 2019-09-23T20:33:16.736Z,1569270796.736 [NAL9602](INFO): SBD MO Status=2, MOMSN=1568, MT Status=2, MTMSN=0 2019-09-23T20:33:16.736Z,1569270796.736 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-09-23T20:33:30.686Z,1569270810.686 [SBIT](IMPORTANT): SBIT PASSED 2019-09-23T20:33:30.713Z,1569270810.713 [CommandLine](IMPORTANT): got command configSet list 2019-09-23T20:33:30.714Z,1569270810.714 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2019-09-23T20:33:30.714Z,1569270810.714 [CommandLine](IMPORTANT): CBIT.gf24Offset=150 microampere; 2019-09-23T20:33:30.715Z,1569270810.715 [CommandLine](IMPORTANT): VerticalControl.buoyancyDefault=200 cubic_centimeter; 2019-09-23T20:33:31.057Z,1569270811.057 [MissionManager](IMPORTANT): Started mission Startup 2019-09-23T20:33:31.057Z,1569270811.057 [Startup] Running Loop=1 2019-09-23T20:33:31.058Z,1569270811.058 [Startup](DEBUG): Aggregate::initialize Startup 2019-09-23T20:33:31.058Z,1569270811.058 [Startup:A.GoToSurface] Running Loop=1 2019-09-23T20:33:31.058Z,1569270811.058 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2019-09-23T20:33:31.058Z,1569270811.058 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2019-09-23T20:33:31.059Z,1569270811.059 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2019-09-23T20:33:31.059Z,1569270811.059 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2019-09-23T20:33:31.060Z,1569270811.060 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2019-09-23T20:33:31.060Z,1569270811.060 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2019-09-23T20:33:31.061Z,1569270811.061 [Startup:StartupSatComms] Running Loop=1 2019-09-23T20:33:31.062Z,1569270811.062 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2019-09-23T20:33:31.062Z,1569270811.062 [Startup:StartupSatComms:A] Running Loop=1 2019-09-23T20:33:31.449Z,1569270811.449 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2019-09-23T20:33:46.555Z,1569270826.555 [CommandLine](IMPORTANT): got command configSet VerticalControl.massDefault 5.000000 millimeter persist 2019-09-23T20:33:46.771Z,1569270826.771 [NAL9602](INFO): SBD MO Status=2, MOMSN=1568, MT Status=2, MTMSN=0 2019-09-23T20:33:46.771Z,1569270826.771 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-09-23T20:34:12.691Z,1569270852.691 [NAL9602](INFO): SBD MO Status=2, MOMSN=1568, MT Status=2, MTMSN=0 2019-09-23T20:34:12.692Z,1569270852.692 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-09-23T20:34:29.690Z,1569270869.690 [CommandLine](IMPORTANT): got command get VerticalControl.massPositionLimitAft 2019-09-23T20:34:29.691Z,1569270869.691 [CommandLine](IMPORTANT): VerticalControl.massPositionLimitAft -32.000000 mm 2019-09-23T20:34:31.332Z,1569270871.332 [Startup:StartupSatComms:A](INFO): Timed out from 2019-09-23T20:33:31.1Z 2019-09-23T20:34:31.332Z,1569270871.332 [Startup:StartupSatComms:A] Stopped 2019-09-23T20:34:31.332Z,1569270871.332 [Startup:StartupSatComms:B] Running Loop=1 2019-09-23T20:34:31.727Z,1569270871.727 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2019-09-23T20:34:36.163Z,1569270876.163 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004837 2019-09-23T20:34:36.670Z,1569270876.670 [NAL9602](INFO): SBD MO Status=2, MOMSN=1568, MT Status=2, MTMSN=0 2019-09-23T20:34:36.671Z,1569270876.671 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-09-23T20:34:43.934Z,1569270883.934 [CommandLine](IMPORTANT): got command get VerticalControl.massPositionLimitFwd 2019-09-23T20:34:43.934Z,1569270883.934 [CommandLine](IMPORTANT): VerticalControl.massPositionLimitFwd 30.000000 mm 2019-09-23T20:34:45.457Z,1569270885.457 [DataOverHttps](INFO): Sending 186 bytes from file Logs/20190923T201937/Courier0007.lzma 2019-09-23T20:34:47.462Z,1569270887.462 [DataOverHttps](INFO): Moved sent file to Logs/20190923T201937/Courier0007.lzma.bak 2019-09-23T20:34:47.462Z,1569270887.462 [DataOverHttps](INFO): SBD MOMSN=11805015 2019-09-23T20:34:49.595Z,1569270889.595 [NAL9602](INFO): SBD MO Status=2, MOMSN=1568, MT Status=2, MTMSN=0 2019-09-23T20:34:49.596Z,1569270889.596 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-09-23T20:35:03.731Z,1569270903.731 [NAL9602](INFO): SBD MO Status=2, MOMSN=1568, MT Status=2, MTMSN=0 2019-09-23T20:35:03.732Z,1569270903.732 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-09-23T20:35:05.500Z,1569270905.500 [DataOverHttps](INFO): Sending 146 bytes from file Logs/20190923T203156/Courier0000.lzma 2019-09-23T20:35:07.003Z,1569270907.003 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2019-09-23T20:35:07.003Z,1569270907.003 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-09-23T20:35:07.013Z,1569270907.013 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-09-23T20:35:07.428Z,1569270907.428 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-09-23T20:35:07.428Z,1569270907.428 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2019-09-23T20:35:07.506Z,1569270907.506 [DataOverHttps](INFO): Moved sent file to Logs/20190923T203156/Courier0000.lzma.bak 2019-09-23T20:35:07.507Z,1569270907.507 [DataOverHttps](INFO): SBD MOMSN=11805017 2019-09-23T20:35:26.359Z,1569270926.359 [NAL9602](INFO): SBD MO Status=2, MOMSN=1568, MT Status=2, MTMSN=0 2019-09-23T20:35:26.359Z,1569270926.359 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-09-23T20:35:26.652Z,1569270926.652 [DataOverHttps](INFO): Sending 100 bytes from file Logs/20190923T201937/Express0008.lzma 2019-09-23T20:35:27.185Z,1569270927.185 [BPC1](ERROR): BPC1B: No match for serial number 1717 in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file). 2019-09-23T20:35:28.658Z,1569270928.658 [DataOverHttps](INFO): Moved sent file to Logs/20190923T201937/Express0008.lzma.bak 2019-09-23T20:35:28.658Z,1569270928.658 [DataOverHttps](INFO): SBD MOMSN=11805022 2019-09-23T20:35:31.663Z,1569270931.663 [Startup:StartupSatComms:B](INFO): Timed out from 2019-09-23T20:34:31.3Z 2019-09-23T20:35:31.663Z,1569270931.663 [Startup:StartupSatComms:B] Stopped 2019-09-23T20:35:31.663Z,1569270931.663 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2019-09-23T20:35:31.663Z,1569270931.663 [Startup:StartupSatComms] Stopped 2019-09-23T20:35:31.664Z,1569270931.664 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2019-09-23T20:35:31.664Z,1569270931.664 [Startup](INFO): Completed Startup 2019-09-23T20:35:31.665Z,1569270931.665 [MissionManager](INFO): Startup is completed. 2019-09-23T20:35:31.665Z,1569270931.665 [MissionManager](INFO): Uninitializing Mission Startup 2019-09-23T20:35:31.665Z,1569270931.665 [Startup] Stopped 2019-09-23T20:35:31.665Z,1569270931.665 [Startup](DEBUG): Aggregate::uninitialize Startup 2019-09-23T20:35:31.665Z,1569270931.665 [Startup:A.GoToSurface] Stopped 2019-09-23T20:35:31.665Z,1569270931.665 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2019-09-23T20:35:32.044Z,1569270932.044 [MissionManager](IMPORTANT): Started mission Default 2019-09-23T20:35:32.044Z,1569270932.044 [Default] Running Loop=1 2019-09-23T20:35:32.045Z,1569270932.045 [Default](DEBUG): Aggregate::initialize Default 2019-09-23T20:35:32.045Z,1569270932.045 [Default:B.GoToSurface] Running Loop=1 2019-09-23T20:35:32.045Z,1569270932.045 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2019-09-23T20:35:32.045Z,1569270932.045 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2019-09-23T20:35:32.045Z,1569270932.045 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2019-09-23T20:35:32.046Z,1569270932.046 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2019-09-23T20:35:32.046Z,1569270932.046 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2019-09-23T20:35:32.046Z,1569270932.046 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2019-09-23T20:35:32.047Z,1569270932.047 [Default:A.Wait] Running Loop=1 2019-09-23T20:35:32.047Z,1569270932.047 [Default:A.Wait](DEBUG): Initialize Wait Component. 2019-09-23T20:35:40.794Z,1569270940.794 [CommandLine](IMPORTANT): got command restart system 2019-09-23T20:35:42.869Z,1569270942.869 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2019-09-23T20:35:42.869Z,1569270942.869 [CommandLine ThreadHandler](INFO): Thread cancelled. 2019-09-23T20:35:42.941Z,1569270942.941 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2019-09-23T20:35:42.941Z,1569270942.941 [CommandLine ThreadHandler](INFO): Thread cancelled. 2019-09-23T20:35:42.942Z,1569270942.942 [CommandLine](INFO): Join timeout helper Thread ID is 1672 2019-09-23T20:35:42.945Z,1569270942.945 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2019-09-23T20:35:42.945Z,1569270942.945 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2019-09-23T20:35:42.945Z,1569270942.945 [NavChartDb](INFO): Join timeout helper Thread ID is 1673 2019-09-23T20:35:43.025Z,1569270943.025 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2019-09-23T20:35:43.025Z,1569270943.025 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2019-09-23T20:35:43.044Z,1569270943.044 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2019-09-23T20:35:43.044Z,1569270943.044 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2019-09-23T20:35:43.045Z,1569270943.045 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 1674 2019-09-23T20:35:43.161Z,1569270943.161 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2019-09-23T20:35:43.162Z,1569270943.162 [WetLabsBB2FL](INFO): Powering down 2019-09-23T20:35:43.162Z,1569270943.162 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2019-09-23T20:35:43.165Z,1569270943.165 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler 2019-09-23T20:35:43.165Z,1569270943.165 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2019-09-23T20:35:43.165Z,1569270943.165 [CTD_Seabird](INFO): Join timeout helper Thread ID is 1675 2019-09-23T20:35:43.789Z,1569270943.789 [CTD_Seabird](INFO): Powering down 2019-09-23T20:35:43.801Z,1569270943.801 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread. 2019-09-23T20:35:43.801Z,1569270943.801 [CTD_Seabird](INFO): Powering down 2019-09-23T20:35:43.813Z,1569270943.813 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2019-09-23T20:35:43.817Z,1569270943.817 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2019-09-23T20:35:43.817Z,1569270943.817 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2019-09-23T20:35:43.817Z,1569270943.817 [Radio_Surface](INFO): Join timeout helper Thread ID is 1676 2019-09-23T20:35:43.821Z,1569270943.821 [Radio_Surface](INFO): Powering down 2019-09-23T20:35:43.822Z,1569270943.822 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2019-09-23T20:35:43.822Z,1569270943.822 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2019-09-23T20:35:43.833Z,1569270943.833 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler 2019-09-23T20:35:43.833Z,1569270943.833 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2019-09-23T20:35:43.833Z,1569270943.833 [DataOverHttps](INFO): Join timeout helper Thread ID is 1677 2019-09-23T20:35:44.505Z,1569270944.505 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread. 2019-09-23T20:35:44.505Z,1569270944.505 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2019-09-23T20:35:44.525Z,1569270944.525 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2019-09-23T20:35:44.526Z,1569270944.526 [logger ThreadHandler](INFO): Thread cancelled. 2019-09-23T20:35:44.526Z,1569270944.526 [logger](INFO): Join timeout helper Thread ID is 1678 2019-09-23T20:35:44.549Z,1569270944.549 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2019-09-23T20:35:44.549Z,1569270944.549 [logger ThreadHandler](INFO): Thread cancelled. 2019-09-23T20:35:44.557Z,1569270944.557 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2019-09-23T20:35:44.557Z,1569270944.557 [CommandLine ThreadHandler](INFO): Thread cancelled. 2019-09-23T20:35:44.558Z,1569270944.558 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2019-09-23T20:35:44.558Z,1569270944.558 [controlThread ThreadHandler](INFO): Thread cancelled. 2019-09-23T20:35:44.558Z,1569270944.558 [controlThread](INFO): Join timeout helper Thread ID is 1679 2019-09-23T20:35:44.593Z,1569270944.593 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2019-09-23T20:35:44.593Z,1569270944.593 [controlThread](DEBUG): Uninitializing ControlThread 2019-09-23T20:35:44.594Z,1569270944.594 [AHRS_M2](INFO): Powering down 2019-09-23T20:35:44.665Z,1569270944.665 [DVL_micro](INFO): uninitialize:Powering down 2019-09-23T20:35:44.667Z,1569270944.667 [NAL9602](INFO): Powering down 2019-09-23T20:35:44.668Z,1569270944.668 [DAT](INFO): Powering down 2019-09-23T20:35:44.786Z,1569270944.786 [BR_Ping1D](INFO): Powering down 2019-09-23T20:35:44.857Z,1569270944.857 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator. 2019-09-23T20:35:44.858Z,1569270944.858 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator. 2019-09-23T20:35:44.859Z,1569270944.859 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2019-09-23T20:35:44.859Z,1569270944.859 [MissionManager](INFO): Uninitializing Mission Default 2019-09-23T20:35:44.859Z,1569270944.859 [Default] Stopped 2019-09-23T20:35:44.859Z,1569270944.859 [Default](DEBUG): Aggregate::uninitialize Default 2019-09-23T20:35:44.860Z,1569270944.860 [Default:A.Wait] Stopped 2019-09-23T20:35:44.860Z,1569270944.860 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2019-09-23T20:35:44.860Z,1569270944.860 [Default:B.GoToSurface] Stopped 2019-09-23T20:35:44.860Z,1569270944.860 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2019-09-23T20:35:44.862Z,1569270944.862 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2019-09-23T20:35:44.863Z,1569270944.863 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2019-09-23T20:35:44.863Z,1569270944.863 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2019-09-23T20:35:44.863Z,1569270944.863 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2019-09-23T20:35:44.863Z,1569270944.863 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2019-09-23T20:35:44.863Z,1569270944.863 [BuoyancyServo](INFO): Powering down 2019-09-23T20:35:44.877Z,1569270944.877 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2019-09-23T20:35:44.877Z,1569270944.877 [ElevatorServo](INFO): Powering down 2019-09-23T20:35:44.878Z,1569270944.878 [MassServo](DEBUG): Uninitialize Mass Servo. 2019-09-23T20:35:44.878Z,1569270944.878 [MassServo](INFO): Powering down 2019-09-23T20:35:44.879Z,1569270944.879 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2019-09-23T20:35:44.879Z,1569270944.879 [RudderServo](INFO): Powering down 2019-09-23T20:35:44.879Z,1569270944.879 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2019-09-23T20:35:44.880Z,1569270944.880 [ThrusterServo](INFO): Powering down 2019-09-23T20:35:44.880Z,1569270944.880 [SBIT](DEBUG): Uninitialize SBIT Component. 2019-09-23T20:35:44.881Z,1569270944.881 [IBIT](DEBUG): Uninitialize IBIT Component. 2019-09-23T20:35:44.881Z,1569270944.881 [CBIT](DEBUG): Uninitialize CBIT Component. 2019-09-23T20:35:44.881Z,1569270944.881 [CBIT](DEBUG): Powering off loads. 2019-09-23T20:35:44.892Z,1569270944.892 [CBIT](DEBUG): Disabling WDT. 2019-09-23T20:35:44.904Z,1569270944.904 [CBIT](DEBUG): Opening all GF detection circuits. 2019-09-23T20:35:44.905Z,1569270944.905 [controlThread ThreadHandler](INFO): Thread cancelled. 2019-09-23T20:35:44.997Z,1569270944.997 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2019-09-23T20:35:45.006Z,1569270945.006 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2019-09-23T20:35:45.044Z,1569270945.044 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2019-09-23T20:35:45.047Z,1569270945.047 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2019-09-23T20:35:45.082Z,1569270945.082 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2019-09-23T20:35:45.142Z,1569270945.142 [logger ThreadHandler](INFO): Thread cancelled.