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.