2020-12-01T17:29:47.816Z,1606843787.816 [Supervisor](DEBUG): Initializing supervisor.
2020-12-01T17:29:47.818Z,1606843787.818 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2020-12-01T17:29:47.819Z,1606843787.819 [SyncHandler](INFO): Protected caller Thread ID is 6260
2020-12-01T17:29:47.819Z,1606843787.819 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2020-12-01T17:29:47.820Z,1606843787.820 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2020-12-01T17:29:47.820Z,1606843787.820 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 6261
2020-12-01T17:29:47.823Z,1606843787.823 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2020-12-01T17:29:47.840Z,1606843787.840 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2020-12-01T17:29:47.841Z,1606843787.841 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2020-12-01T17:29:47.841Z,1606843787.841 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 6262
2020-12-01T17:29:47.842Z,1606843787.842 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2020-12-01T17:29:47.843Z,1606843787.843 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2020-12-01T17:29:47.843Z,1606843787.843 [logger ThreadHandler](INFO): Protected caller Thread ID is 6263
2020-12-01T17:29:47.845Z,1606843787.845 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2020-12-01T17:29:47.846Z,1606843787.846 [Supervisor](INFO): Looking for Config files in directory: Config/
2020-12-01T17:29:47.847Z,1606843787.847 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2020-12-01T17:29:47.942Z,1606843787.942 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2020-12-01T17:29:47.942Z,1606843787.942 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2020-12-01T17:29:48.532Z,1606843788.532 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2020-12-01T17:29:48.533Z,1606843788.533 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2020-12-01T17:29:48.734Z,1606843788.734 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2020-12-01T17:29:48.734Z,1606843788.734 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2020-12-01T17:29:48.832Z,1606843788.832 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2020-12-01T17:29:48.833Z,1606843788.833 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2020-12-01T17:29:48.937Z,1606843788.937 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2020-12-01T17:29:48.938Z,1606843788.938 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2020-12-01T17:29:49.018Z,1606843789.018 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2020-12-01T17:29:49.158Z,1606843789.158 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2020-12-01T17:29:49.158Z,1606843789.158 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2020-12-01T17:29:49.449Z,1606843789.449 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2020-12-01T17:29:49.449Z,1606843789.449 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2020-12-01T17:29:50.003Z,1606843790.003 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2020-12-01T17:29:50.004Z,1606843790.004 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2020-12-01T17:29:50.277Z,1606843790.277 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2020-12-01T17:29:50.278Z,1606843790.278 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2020-12-01T17:29:50.468Z,1606843790.468 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2020-12-01T17:29:50.468Z,1606843790.468 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2020-12-01T17:29:50.957Z,1606843790.957 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2020-12-01T17:29:50.958Z,1606843790.958 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2020-12-01T17:29:51.174Z,1606843791.174 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2020-12-01T17:29:51.174Z,1606843791.174 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2020-12-01T17:29:51.374Z,1606843791.374 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2020-12-01T17:29:51.375Z,1606843791.375 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2020-12-01T17:29:51.786Z,1606843791.786 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2020-12-01T17:29:51.787Z,1606843791.787 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2020-12-01T17:29:52.111Z,1606843792.111 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2020-12-01T17:29:52.113Z,1606843792.113 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-pontus/
2020-12-01T17:29:52.113Z,1606843792.113 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/secure.cfg
2020-12-01T17:29:52.196Z,1606843792.196 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Sensor.cfg
2020-12-01T17:29:52.350Z,1606843792.350 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Servo.cfg
2020-12-01T17:29:52.457Z,1606843792.457 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Simulator.cfg
2020-12-01T17:29:52.542Z,1606843792.542 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/logger.cfg
2020-12-01T17:29:52.635Z,1606843792.635 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/vehicle.cfg
2020-12-01T17:29:52.829Z,1606843792.829 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Battery.cfg
2020-12-01T17:29:53.086Z,1606843793.086 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2020-12-01T17:29:53.087Z,1606843793.087 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Navigation.cfg
2020-12-01T17:29:53.180Z,1606843793.180 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/BIT.cfg
2020-12-01T17:29:53.277Z,1606843793.277 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Science.cfg
2020-12-01T17:29:53.419Z,1606843793.419 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Control.cfg
2020-12-01T17:29:53.518Z,1606843793.518 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-pontus/root/
2020-12-01T17:29:53.518Z,1606843793.518 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2020-12-01T17:29:53.530Z,1606843793.530 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2020-12-01T17:29:53.615Z,1606843793.615 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2020-12-01T17:29:53.616Z,1606843793.616 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2020-12-01T17:29:53.667Z,1606843793.667 [VerticalControl](DEBUG): Construct VerticalControl.
2020-12-01T17:29:53.723Z,1606843793.723 [VerticalControl] Loaded
2020-12-01T17:29:53.724Z,1606843793.724 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2020-12-01T17:29:53.724Z,1606843793.724 [HorizontalControl](DEBUG): Construct HorizontalControl.
2020-12-01T17:29:53.760Z,1606843793.760 [HorizontalControl] Loaded
2020-12-01T17:29:53.760Z,1606843793.760 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2020-12-01T17:29:53.761Z,1606843793.761 [SpeedControl](DEBUG): Construct SpeedControl.
2020-12-01T17:29:53.764Z,1606843793.764 [SpeedControl] Loaded
2020-12-01T17:29:53.764Z,1606843793.764 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2020-12-01T17:29:53.765Z,1606843793.765 [LoopControl](DEBUG): Construct LoopControl.
2020-12-01T17:29:53.765Z,1606843793.765 [LoopControl] Loaded
2020-12-01T17:29:53.765Z,1606843793.765 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2020-12-01T17:29:53.766Z,1606843793.766 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2020-12-01T17:29:53.766Z,1606843793.766 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2020-12-01T17:29:53.808Z,1606843793.808 [DepthRateCalculator] Loaded
2020-12-01T17:29:53.808Z,1606843793.808 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2020-12-01T17:29:53.810Z,1606843793.810 [PitchRateCalculator] Loaded
2020-12-01T17:29:53.811Z,1606843793.811 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2020-12-01T17:29:53.818Z,1606843793.818 [SpeedCalculator] Loaded
2020-12-01T17:29:53.819Z,1606843793.819 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2020-12-01T17:29:53.829Z,1606843793.829 [TempGradientCalculator] Loaded
2020-12-01T17:29:53.830Z,1606843793.830 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2020-12-01T17:29:53.832Z,1606843793.832 [YawRateCalculator] Loaded
2020-12-01T17:29:53.832Z,1606843793.832 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2020-12-01T17:29:53.847Z,1606843793.847 [ElevatorOffsetCalculator] Loaded
2020-12-01T17:29:53.847Z,1606843793.847 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2020-12-01T17:29:53.847Z,1606843793.847 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2020-12-01T17:29:53.848Z,1606843793.848 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2020-12-01T17:29:53.875Z,1606843793.875 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2020-12-01T17:29:53.876Z,1606843793.876 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2020-12-01T17:29:53.965Z,1606843793.965 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2020-12-01T17:29:53.966Z,1606843793.966 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2020-12-01T17:29:54.277Z,1606843794.277 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2020-12-01T17:29:54.277Z,1606843794.277 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2020-12-01T17:29:54.384Z,1606843794.384 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2020-12-01T17:29:54.385Z,1606843794.385 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2020-12-01T17:29:54.734Z,1606843794.734 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_orientation
2020-12-01T17:29:54.736Z,1606843794.736 [AHRS_M2](INFO): created writer for : platform_orientation
2020-12-01T17:29:54.738Z,1606843794.738 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_magnetic_orientation
2020-12-01T17:29:54.741Z,1606843794.741 [AHRS_M2](INFO): created writer for : platform_magnetic_orientation
2020-12-01T17:29:54.742Z,1606843794.742 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_pitch_angle
2020-12-01T17:29:54.744Z,1606843794.744 [AHRS_M2](INFO): created writer for : platform_pitch_angle
2020-12-01T17:29:54.745Z,1606843794.745 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_roll_angle
2020-12-01T17:29:54.748Z,1606843794.748 [AHRS_M2](INFO): created writer for : platform_roll_angle
2020-12-01T17:29:54.783Z,1606843794.783 [AHRS_M2] Loaded
2020-12-01T17:29:54.784Z,1606843794.784 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2020-12-01T17:29:54.854Z,1606843794.854 [DataOverHttps] Loaded
2020-12-01T17:29:54.854Z,1606843794.854 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2020-12-01T17:29:54.855Z,1606843794.855 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4090F4E0
2020-12-01T17:29:54.855Z,1606843794.855 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 6345
2020-12-01T17:29:54.872Z,1606843794.872 [Depth_Keller] Loaded
2020-12-01T17:29:54.872Z,1606843794.872 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2020-12-01T17:29:54.874Z,1606843794.874 [DropWeight] Loaded
2020-12-01T17:29:54.875Z,1606843794.875 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2020-12-01T17:29:54.930Z,1606843794.930 [NAL9602] Loaded
2020-12-01T17:29:54.930Z,1606843794.930 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2020-12-01T17:29:54.955Z,1606843794.955 [Onboard] Loaded
2020-12-01T17:29:54.956Z,1606843794.956 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2020-12-01T17:29:54.957Z,1606843794.957 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 4093F4E0
2020-12-01T17:29:54.957Z,1606843794.957 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 6346
2020-12-01T17:29:54.967Z,1606843794.967 [Radio_Surface] Loaded
2020-12-01T17:29:54.968Z,1606843794.968 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2020-12-01T17:29:54.969Z,1606843794.969 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4096F4E0
2020-12-01T17:29:54.969Z,1606843794.969 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 6347
2020-12-01T17:29:54.995Z,1606843794.995 [RDI_Pathfinder] Loaded
2020-12-01T17:29:54.996Z,1606843794.996 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread.
2020-12-01T17:29:55.170Z,1606843795.170 [DAT] Loaded
2020-12-01T17:29:55.171Z,1606843795.171 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread.
2020-12-01T17:29:56.355Z,1606843796.355 [BPC1] Loaded
2020-12-01T17:29:56.355Z,1606843796.355 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2020-12-01T17:29:56.356Z,1606843796.356 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2020-12-01T17:29:56.356Z,1606843796.356 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2020-12-01T17:29:56.436Z,1606843796.436 [DeadReckonUsingMultipleVelocitySources] Loaded
2020-12-01T17:29:56.436Z,1606843796.436 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2020-12-01T17:29:56.446Z,1606843796.446 [NavChart] Loaded
2020-12-01T17:29:56.447Z,1606843796.447 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2020-12-01T17:29:56.450Z,1606843796.450 [UniversalFixResidualReporter] Loaded
2020-12-01T17:29:56.451Z,1606843796.451 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2020-12-01T17:29:56.451Z,1606843796.451 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2020-12-01T17:29:56.452Z,1606843796.452 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2020-12-01T17:29:56.595Z,1606843796.595 [SBIT](DEBUG): Construct Startup Built In Test.
2020-12-01T17:29:56.603Z,1606843796.603 [SBIT] Loaded
2020-12-01T17:29:56.603Z,1606843796.603 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2020-12-01T17:29:56.604Z,1606843796.604 [IBIT](DEBUG): Construct Initiated Built In Test.
2020-12-01T17:29:56.616Z,1606843796.616 [IBIT] Loaded
2020-12-01T17:29:56.617Z,1606843796.617 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2020-12-01T17:29:56.620Z,1606843796.620 [CBIT](DEBUG): Construct Continuous Built In Test.
2020-12-01T17:29:56.713Z,1606843796.713 [CBIT] Loaded
2020-12-01T17:29:56.713Z,1606843796.713 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2020-12-01T17:29:56.713Z,1606843796.713 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2020-12-01T17:29:56.714Z,1606843796.714 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2020-12-01T17:29:56.832Z,1606843796.832 [BuoyancyServo] Loaded
2020-12-01T17:29:56.832Z,1606843796.832 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2020-12-01T17:29:56.849Z,1606843796.849 [ElevatorServo] Loaded
2020-12-01T17:29:56.849Z,1606843796.849 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2020-12-01T17:29:56.865Z,1606843796.865 [MassServo] Loaded
2020-12-01T17:29:56.865Z,1606843796.865 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2020-12-01T17:29:56.881Z,1606843796.881 [RudderServo] Loaded
2020-12-01T17:29:56.881Z,1606843796.881 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2020-12-01T17:29:56.896Z,1606843796.896 [ThrusterServo] Loaded
2020-12-01T17:29:56.896Z,1606843796.896 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2020-12-01T17:29:56.896Z,1606843796.896 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2020-12-01T17:29:56.897Z,1606843796.897 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2020-12-01T17:29:56.916Z,1606843796.916 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2020-12-01T17:29:56.916Z,1606843796.916 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2020-12-01T17:29:57.138Z,1606843797.138 [BackSeatDriver] Loaded
2020-12-01T17:29:57.139Z,1606843797.139 [ComponentRegistry](DEBUG): Component "BackSeatDriver" handled in its own thread.
2020-12-01T17:29:57.140Z,1606843797.140 [BackSeatDriver ThreadHandler](DEBUG): Created PCaller Thread at 40B074E0
2020-12-01T17:29:57.140Z,1606843797.140 [BackSeatDriver ThreadHandler](INFO): Protected caller Thread ID is 6348
2020-12-01T17:29:57.160Z,1606843797.160 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_density
2020-12-01T17:29:57.163Z,1606843797.163 [CTD_Seabird](INFO): created writer for : sea_water_density
2020-12-01T17:29:57.163Z,1606843797.163 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): depth
2020-12-01T17:29:57.166Z,1606843797.166 [CTD_Seabird](INFO): created writer for : depth
2020-12-01T17:29:57.166Z,1606843797.166 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_pressure
2020-12-01T17:29:57.169Z,1606843797.169 [CTD_Seabird](INFO): created writer for : sea_water_pressure
2020-12-01T17:29:57.169Z,1606843797.169 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_salinity
2020-12-01T17:29:57.172Z,1606843797.172 [CTD_Seabird](INFO): created writer for : sea_water_salinity
2020-12-01T17:29:57.173Z,1606843797.173 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_temperature
2020-12-01T17:29:57.176Z,1606843797.176 [CTD_Seabird](INFO): created writer for : sea_water_temperature
2020-12-01T17:29:57.177Z,1606843797.177 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_electrical_conductivity
2020-12-01T17:29:57.180Z,1606843797.180 [CTD_Seabird](INFO): created writer for : sea_water_electrical_conductivity
2020-12-01T17:29:57.180Z,1606843797.180 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): speed_of_sound_in_sea_water
2020-12-01T17:29:57.183Z,1606843797.183 [CTD_Seabird](INFO): created writer for : speed_of_sound_in_sea_water
2020-12-01T17:29:57.183Z,1606843797.183 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): mass_concentration_of_oxygen_in_sea_water
2020-12-01T17:29:57.186Z,1606843797.186 [CTD_Seabird](INFO): created writer for : mass_concentration_of_oxygen_in_sea_water
2020-12-01T17:29:57.187Z,1606843797.187 [CTD_Seabird](DEBUG): LcmSlateWriter::add(DAtaURI): CTD_Seabird.sea_water_dissolved_oxygen_freq
2020-12-01T17:29:57.187Z,1606843797.187 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): dataName: sea_water_dissolved_oxygen_freq
2020-12-01T17:29:57.203Z,1606843797.203 [CTD_Seabird] Loaded
2020-12-01T17:29:57.203Z,1606843797.203 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2020-12-01T17:29:57.204Z,1606843797.204 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40B374E0
2020-12-01T17:29:57.205Z,1606843797.205 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 6349
2020-12-01T17:29:57.222Z,1606843797.222 [PAR_Licor] Loaded
2020-12-01T17:29:57.222Z,1606843797.222 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2020-12-01T17:29:57.235Z,1606843797.235 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.Output470
2020-12-01T17:29:57.235Z,1606843797.235 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: Output470
2020-12-01T17:29:57.237Z,1606843797.237 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.Output650
2020-12-01T17:29:57.237Z,1606843797.237 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: Output650
2020-12-01T17:29:57.239Z,1606843797.239 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.OutputChl
2020-12-01T17:29:57.239Z,1606843797.239 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: OutputChl
2020-12-01T17:29:57.241Z,1606843797.241 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.VolumeScatCoeff117deg470nm
2020-12-01T17:29:57.241Z,1606843797.241 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: VolumeScatCoeff117deg470nm
2020-12-01T17:29:57.243Z,1606843797.243 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.VolumeScatCoeff117deg650nm
2020-12-01T17:29:57.243Z,1606843797.243 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: VolumeScatCoeff117deg650nm
2020-12-01T17:29:57.246Z,1606843797.246 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.BackscatteringCoeff470nm
2020-12-01T17:29:57.246Z,1606843797.246 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: BackscatteringCoeff470nm
2020-12-01T17:29:57.248Z,1606843797.248 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.BackscatteringCoeff650nm
2020-12-01T17:29:57.248Z,1606843797.248 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: BackscatteringCoeff650nm
2020-12-01T17:29:57.250Z,1606843797.250 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): mass_concentration_of_chlorophyll_in_sea_water
2020-12-01T17:29:57.252Z,1606843797.252 [WetLabsBB2FL](INFO): created writer for : mass_concentration_of_chlorophyll_in_sea_water
2020-12-01T17:29:57.253Z,1606843797.253 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_median_mass_concentration_of_chlorophyll_in_sea_water
2020-12-01T17:29:57.253Z,1606843797.253 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_median_mass_concentration_of_chlorophyll_in_sea_water
2020-12-01T17:29:57.255Z,1606843797.255 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water
2020-12-01T17:29:57.255Z,1606843797.255 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_mean_mass_concentration_of_chlorophyll_in_sea_water
2020-12-01T17:29:57.257Z,1606843797.257 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_variance_mass_concentration_of_chlorophyll_in_sea_water
2020-12-01T17:29:57.257Z,1606843797.257 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_variance_mass_concentration_of_chlorophyll_in_sea_water
2020-12-01T17:29:57.259Z,1606843797.259 [WetLabsBB2FL] Loaded
2020-12-01T17:29:57.260Z,1606843797.260 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2020-12-01T17:29:57.261Z,1606843797.261 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40B674E0
2020-12-01T17:29:57.261Z,1606843797.261 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 6350
2020-12-01T17:29:57.283Z,1606843797.283 [WetLabsUBAT..SerialDriver](INFO): Created logger
2020-12-01T17:29:57.284Z,1606843797.284 [WetLabsUBAT..SerialDriver](INFO): publishing on LCM channel WetLabsUBAT
2020-12-01T17:29:57.284Z,1606843797.284 [WetLabsUBAT..StreamSerialDriver](INFO): Created logger
2020-12-01T17:29:57.289Z,1606843797.289 [WetLabsUBAT](INFO): readConfig(): serialNo_: UBAT0051, uartName_: /dev/ttyC1, optionalArgs_: 
2020-12-01T17:29:57.289Z,1606843797.289 [WetLabsUBAT](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsUBAT.biolum_potential
2020-12-01T17:29:57.289Z,1606843797.289 [WetLabsUBAT](DEBUG): LcmSlateWriter::add(): dataName: biolum_potential
2020-12-01T17:29:57.291Z,1606843797.291 [WetLabsUBAT](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsUBAT.flow_rate
2020-12-01T17:29:57.291Z,1606843797.291 [WetLabsUBAT](DEBUG): LcmSlateWriter::add(): dataName: flow_rate
2020-12-01T17:29:57.294Z,1606843797.294 [WetLabsUBAT] Loaded
2020-12-01T17:29:57.295Z,1606843797.295 [ComponentRegistry](DEBUG): Component "WetLabsUBAT" handled in its own thread.
2020-12-01T17:29:57.296Z,1606843797.296 [WetLabsUBAT ThreadHandler](DEBUG): Created PCaller Thread at 40B974E0
2020-12-01T17:29:57.296Z,1606843797.296 [WetLabsUBAT ThreadHandler](INFO): Protected caller Thread ID is 6351
2020-12-01T17:29:57.297Z,1606843797.297 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2020-12-01T17:29:57.301Z,1606843797.301 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2020-12-01T17:29:57.301Z,1606843797.301 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2020-12-01T17:29:57.310Z,1606843797.310 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2020-12-01T17:29:57.311Z,1606843797.311 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40BC74E0
2020-12-01T17:29:57.312Z,1606843797.312 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 6352
2020-12-01T17:29:57.316Z,1606843797.316 [Supervisor](INFO): Main Thread ID is 5457
2020-12-01T17:29:57.316Z,1606843797.316 [Supervisor](DEBUG): Running supervisor.
2020-12-01T17:29:57.317Z,1606843797.317 [CommandLine ThreadHandler](INFO): Handler Thread ID is 6353
2020-12-01T17:29:57.322Z,1606843797.322 [controlThread ThreadHandler](INFO): Handler Thread ID is 6354
2020-12-01T17:29:57.322Z,1606843797.322 [controlThread](DEBUG): Initializing ControlThread
2020-12-01T17:29:57.323Z,1606843797.323 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2020-12-01T17:29:57.325Z,1606843797.325 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2020-12-01T17:29:57.325Z,1606843797.325 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2020-12-01T17:29:57.326Z,1606843797.326 [LoopControl](DEBUG): Initialize LoopControlComponent.
2020-12-01T17:29:57.326Z,1606843797.326 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2020-12-01T17:29:57.327Z,1606843797.327 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2020-12-01T17:29:57.327Z,1606843797.327 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2020-12-01T17:29:57.327Z,1606843797.327 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2020-12-01T17:29:57.328Z,1606843797.328 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2020-12-01T17:29:57.328Z,1606843797.328 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2020-12-01T17:29:57.334Z,1606843797.334 [NavChart](DEBUG): Initialize NavChart Navigation.
2020-12-01T17:29:57.335Z,1606843797.335 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2020-12-01T17:29:57.335Z,1606843797.335 [SBIT](INFO): Initialize SBIT Component.
2020-12-01T17:29:57.335Z,1606843797.335 [SBIT](IMPORTANT): git: 2020-11-24
2020-12-01T17:29:57.336Z,1606843797.336 [SBIT](INFO): git hash: adde971cea593344b7c42ced3277a520a74b3766
2020-12-01T17:29:57.336Z,1606843797.336 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2020-12-01T17:29:57.337Z,1606843797.337 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #1 PREEMPT Thu Feb 21 11:17:40 PST 2019
Kernel Reported: #1 PREEMPT Thu Aug 6 12:04:53 PDT 2020
2020-12-01T17:29:57.338Z,1606843797.338 [SBIT](INFO): Beginning SBIT in 49.000000 seconds.
2020-12-01T17:29:57.339Z,1606843797.339 [IBIT](INFO): Initialize IBIT Component.
2020-12-01T17:29:57.339Z,1606843797.339 [CBIT](DEBUG): Initialize CBIT Component.
2020-12-01T17:29:57.341Z,1606843797.341 [logger ThreadHandler](INFO): Handler Thread ID is 6355
2020-12-01T17:29:57.352Z,1606843797.352 [CBIT](DEBUG): Initialized mux pins.
2020-12-01T17:29:57.352Z,1606843797.352 [CBIT](DEBUG): Initializing the watchdog timer.
2020-12-01T17:29:57.360Z,1606843797.360 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 6356
2020-12-01T17:29:57.361Z,1606843797.361 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2020-12-01T17:29:57.372Z,1606843797.372 [Onboard ThreadHandler](INFO): Handler Thread ID is 6357
2020-12-01T17:29:57.376Z,1606843797.376 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2020-12-01T17:29:57.377Z,1606843797.377 [CBIT](DEBUG): Initializing heartbeat.
2020-12-01T17:29:57.390Z,1606843797.390 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 6358
2020-12-01T17:29:57.412Z,1606843797.412 [BackSeatDriver ThreadHandler](INFO): Handler Thread ID is 6359
2020-12-01T17:29:57.432Z,1606843797.432 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 6360
2020-12-01T17:29:57.433Z,1606843797.433 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2020-12-01T17:29:57.437Z,1606843797.437 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 6362
2020-12-01T17:29:57.438Z,1606843797.438 [WetLabsBB2FL](INFO): Powering down
2020-12-01T17:29:57.448Z,1606843797.448 [CBIT](DEBUG): Deactivating GF circuits.
2020-12-01T17:29:57.448Z,1606843797.448 [CBIT](DEBUG): Deactivating emergency mode.
2020-12-01T17:29:57.449Z,1606843797.449 [WetLabsUBAT ThreadHandler](INFO): Handler Thread ID is 6363
2020-12-01T17:29:57.456Z,1606843797.456 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 6364
2020-12-01T17:29:57.459Z,1606843797.459 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2020-12-01T17:29:57.459Z,1606843797.459 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2020-12-01T17:29:57.460Z,1606843797.460 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2020-12-01T17:29:57.460Z,1606843797.460 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2020-12-01T17:29:57.460Z,1606843797.460 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2020-12-01T17:29:57.460Z,1606843797.460 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2020-12-01T17:29:57.460Z,1606843797.460 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2020-12-01T17:29:57.461Z,1606843797.461 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2020-12-01T17:29:57.461Z,1606843797.461 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2020-12-01T17:29:57.461Z,1606843797.461 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2020-12-01T17:29:57.461Z,1606843797.461 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2020-12-01T17:29:57.461Z,1606843797.461 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2020-12-01T17:29:57.461Z,1606843797.461 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2020-12-01T17:29:57.462Z,1606843797.462 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2020-12-01T17:29:57.462Z,1606843797.462 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2020-12-01T17:29:57.462Z,1606843797.462 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2020-12-01T17:29:57.484Z,1606843797.484 [CBIT](DEBUG): Backplane powered.
2020-12-01T17:29:57.489Z,1606843797.489 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2020-12-01T17:29:57.498Z,1606843797.498 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2020-12-01T17:29:57.538Z,1606843797.538 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Units="Tethys/Units"
       xmlns:Universal="Tethys/Universal"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
       Id="Startup">

    <Guidance:GoToSurface>
        <Progression/>
    </Guidance:GoToSurface>

    <Aggregate Id="StartupSatComms">

        <Sequence/>

        <ReadDatum>
            <Timeout Duration="P1M" />
            <Universal:latitude_fix/>
        </ReadDatum>

        <ReadDatum>
            <Timeout Duration="P1M" />
            <Universal:platform_communications/>
        </ReadDatum>

    </Aggregate>

</Mission>


2020-12-01T17:29:57.538Z,1606843797.538 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2020-12-01T17:29:57.619Z,1606843797.619 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2020-12-01T17:29:57.628Z,1606843797.628 [Default:A.Wait](DEBUG): Construct Wait.
2020-12-01T17:29:57.629Z,1606843797.629 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2020-12-01T17:29:57.664Z,1606843797.664 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2020-12-01T17:29:57.666Z,1606843797.666 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2020-12-01T17:29:57.688Z,1606843797.688 [Default:E.Execute](DEBUG): Construct Execute.
2020-12-01T17:29:57.691Z,1606843797.691 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Universal="Tethys/Universal"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                             Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                             Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
         Id="Default">

    <DefineArg Name="ElapsedSinceDefaultStarted"><Units:minute/><Value>0</Value></DefineArg>

    <Guidance:Wait>
        <Description>
            Wait a moment to see if the scheduler starts a new mission before
            starting to actually run Default.
        </Description>
        <Sequence/>
        <Setting><Guidance:Wait.duration/><Units:second/><Value>13</Value></Setting>
    </Guidance:Wait>

    <Guidance:GoToSurface>
        <Progression/>
    </Guidance:GoToSurface>

    <Aggregate Id="CheckIn">

        <Sequence Repeat="288"/>

        <ReadDatum Id="Read_GPS">
            <Timeout Duration="P5M"/>
            <Universal:time_fix/>
        </ReadDatum>

        <ReadDatum Id="Read_Iridium">
            <Timeout Duration="P2H">
                <Guidance:Execute>
                    <Sequence/>
                    <Setting><Guidance:Execute.command/><String>Burn on</String></Setting>
                </Guidance:Execute>
                <Syslog Severity="Critical">Dropped weight due to communications timeout.</Syslog>
            </Timeout>
            <Universal:platform_communications/>
        </ReadDatum>

        <Guidance:Wait>
            <Sequence/>
            <Setting><Guidance:Wait.duration/><Units:minute/><Value>5</Value></Setting>
        </Guidance:Wait>

        <Assign><Sequence/><Arg Name="ElapsedSinceDefaultStarted"/><Elapsed><Universal:mission_started/></Elapsed></Assign>

        <Syslog Severity="Important">Default mission has been running for <Arg Name="ElapsedSinceDefaultStarted"/><Units:minute/></Syslog>

    </Aggregate>

    <Syslog Severity="Important">Restarting logs and Default mission.</Syslog>

    <Guidance:Execute>
        <Sequence/>
        <Setting><Guidance:Execute.command/><String>restart logs</String></Setting>
    </Guidance:Execute>

</Mission>


2020-12-01T17:29:57.699Z,1606843797.699 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,NAL9602,RDI_Pathfinder,DAT,BPC1,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2020-12-01T17:29:57.712Z,1606843797.712 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2020-12-01T17:29:57.796Z,1606843797.796 [Radio_Surface](INFO): Powering up
2020-12-01T17:29:57.875Z,1606843797.875 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2
2020-12-01T17:29:57.875Z,1606843797.875 [DAT](INFO): Powering up
2020-12-01T17:29:57.875Z,1606843797.875 [DAT](DEBUG): Initializing DAT.
2020-12-01T17:29:57.920Z,1606843797.920 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2
2020-12-01T17:29:57.978Z,1606843797.978 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2020-12-01T17:29:57.988Z,1606843797.988 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2020-12-01T17:29:57.990Z,1606843797.990 [ElevatorServo](DEBUG): Initializing EZServoServo.
2020-12-01T17:29:58.000Z,1606843798.000 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2020-12-01T17:29:58.001Z,1606843798.001 [MassServo](DEBUG): Initializing EZServoServo.
2020-12-01T17:29:58.016Z,1606843798.016 [MassServo](DEBUG): Initializing MassServo.
2020-12-01T17:29:58.017Z,1606843798.017 [RudderServo](DEBUG): Initializing EZServoServo.
2020-12-01T17:29:58.028Z,1606843798.028 [RudderServo](DEBUG): Initializing RudderServo.
2020-12-01T17:29:58.029Z,1606843798.029 [ThrusterServo](DEBUG): Initializing EZServoServo.
2020-12-01T17:29:58.040Z,1606843798.040 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2020-12-01T17:29:58.133Z,1606843798.133 [DropWeight](CRITICAL): DROP WEIGHT MISSING.

2020-12-01T17:29:58.133Z,1606843798.133 [DropWeight] Hardware Fault, FailCount= 1
2020-12-01T17:29:58.133Z,1606843798.133 [DropWeight](ERROR): Hardware Fault
2020-12-01T17:29:58.174Z,1606843798.174 [CommandLine](FAULT): Scheduling is paused
2020-12-01T17:29:58.174Z,1606843798.174 [CBIT](INFO): Critical error at 20201201T172958
2020-12-01T17:29:58.175Z,1606843798.175 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2020-12-01T17:29:58.177Z,1606843798.177 [CBIT](ERROR): Hardware Fault in component: DropWeight
2020-12-01T17:29:58.177Z,1606843798.177 [CBIT](CRITICAL): Hardware Fault in component: DropWeight
2020-12-01T17:29:58.832Z,1606843798.832 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2020-12-01T17:29:58.832Z,1606843798.832 [RudderServo](FAULT): Rudder failed to initialize
2020-12-01T17:29:58.832Z,1606843798.832 [RudderServo] Communications Fault, FailCount= 1
2020-12-01T17:29:58.832Z,1606843798.832 [RudderServo](ERROR): Communications Fault
2020-12-01T17:29:58.930Z,1606843798.930 [CBIT](INFO): Critical error at 20201201T172958
2020-12-01T17:29:58.932Z,1606843798.932 [CBIT](ERROR): Communications Fault in component: RudderServo
2020-12-01T17:29:59.129Z,1606843799.129 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2020-12-01T17:29:59.129Z,1606843799.129 [RudderServo](INFO): Powering down
2020-12-01T17:29:59.768Z,1606843799.768 [RudderServo](DEBUG): Initializing EZServoServo.
2020-12-01T17:29:59.889Z,1606843799.889 [RudderServo](DEBUG): Initializing RudderServo.
2020-12-01T17:29:59.893Z,1606843799.893 [CBIT](INFO): Clearing failed state for component RudderServo
2020-12-01T17:29:59.893Z,1606843799.893 [RudderServo] No Fault, FailCount= 1
2020-12-01T17:30:11.879Z,1606843811.879 [DAT](INFO): commRate: 800
2020-12-01T17:30:13.908Z,1606843813.908 [DAT](INFO): entering command mode
2020-12-01T17:30:14.302Z,1606843814.302 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-01T17:30:14.714Z,1606843814.714 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-01T17:30:15.116Z,1606843815.116 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-01T17:30:15.524Z,1606843815.524 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-01T17:30:15.917Z,1606843815.917 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-01T17:30:16.326Z,1606843816.326 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-01T17:30:16.750Z,1606843816.750 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-01T17:30:17.129Z,1606843817.129 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-01T17:30:17.540Z,1606843817.540 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-01T17:30:17.938Z,1606843817.938 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-01T17:30:18.369Z,1606843818.369 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-01T17:30:18.752Z,1606843818.752 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-01T17:30:19.146Z,1606843819.146 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-01T17:30:19.564Z,1606843819.564 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-01T17:30:19.954Z,1606843819.954 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-01T17:30:20.358Z,1606843820.358 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-01T17:30:20.784Z,1606843820.784 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-01T17:30:21.166Z,1606843821.166 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-01T17:30:21.590Z,1606843821.590 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-01T17:30:21.978Z,1606843821.978 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-01T17:30:22.378Z,1606843822.378 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-01T17:30:22.794Z,1606843822.794 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-01T17:30:23.212Z,1606843823.212 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-01T17:30:23.590Z,1606843823.590 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-01T17:30:24.036Z,1606843824.036 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-01T17:30:24.424Z,1606843824.424 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-01T17:30:24.807Z,1606843824.807 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-01T17:30:25.205Z,1606843825.205 [NAL9602](INFO): Powering up NAL9602
2020-12-01T17:30:25.207Z,1606843825.207 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-01T17:30:25.620Z,1606843825.620 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-01T17:30:26.014Z,1606843826.014 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-01T17:30:26.434Z,1606843826.434 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-01T17:30:26.825Z,1606843826.825 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-01T17:30:27.226Z,1606843827.226 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-01T17:30:27.656Z,1606843827.656 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-01T17:30:28.038Z,1606843828.038 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-01T17:30:28.463Z,1606843828.463 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-01T17:30:28.842Z,1606843828.842 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-01T17:30:29.246Z,1606843829.246 [DAT](DEBUG): checking for command mode acknowledgment
2020-12-01T17:30:29.246Z,1606843829.246 [DAT](FAULT): failed to enter command mode
2020-12-01T17:30:29.671Z,1606843829.671 [DAT](INFO): entering command mode
2020-12-01T17:30:30.055Z,1606843830.055 [DAT](INFO): setting verbose to 3
2020-12-01T17:30:30.459Z,1606843830.459 [DAT](INFO): set verbose to 3
2020-12-01T17:30:30.459Z,1606843830.459 [DAT](INFO): setting DatVerbose to 27440
2020-12-01T17:30:30.878Z,1606843830.878 [DAT](INFO): set DatVerbose to 27440
2020-12-01T17:30:30.878Z,1606843830.878 [DAT](INFO): setting transmit power to 8
2020-12-01T17:30:31.271Z,1606843831.271 [DAT](INFO): set transmit power to 8
2020-12-01T17:30:31.271Z,1606843831.271 [DAT](INFO): setting local address to 9
2020-12-01T17:30:31.674Z,1606843831.674 [DAT](INFO): set local address to 9
2020-12-01T17:30:36.129Z,1606843836.129 [NAL9602](INFO): NAL9602 initialized
2020-12-01T17:30:47.063Z,1606843847.063 [SBIT](IMPORTANT): Beginning Startup BIT
2020-12-01T17:30:47.067Z,1606843847.067 [CBIT](IMPORTANT): Beginning ground fault scan
2020-12-01T17:30:58.013Z,1606843858.013 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.011462
CHAN A1 (24V): -0.002185
CHAN A2 (12V): -0.007506
CHAN A3 (5V): -0.002124
CHAN B0 (3.3V): 0.000007
CHAN B1 (3.15aV): -0.000248
CHAN B2 (3.15bV): -0.000260
CHAN B3 (GND): 0.002295
OPEN: 0.005289
Full Scale Calc: 4.765 mA, -1.589 mA
2020-12-01T17:31:40.803Z,1606843900.803 [SBIT](IMPORTANT): SBIT PASSED
2020-12-01T17:31:40.803Z,1606843900.803 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2020-12-01T17:31:40.804Z,1606843900.804 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=6 count;

2020-12-01T17:31:40.804Z,1606843900.804 [SBIT](IMPORTANT): CBIT.gf24Offset=145 microampere;

2020-12-01T17:31:40.804Z,1606843900.804 [SBIT](IMPORTANT): DAT.loadAtStartup=1 bool;

2020-12-01T17:31:40.804Z,1606843900.804 [SBIT](IMPORTANT): DAT.sbdAddress=-1 enum;

2020-12-01T17:31:40.805Z,1606843900.805 [SBIT](IMPORTANT): DAT.surfaceThreshold=100 meter;

2020-12-01T17:31:40.805Z,1606843900.805 [SBIT](IMPORTANT): DAT.verbosity=0 count;

2020-12-01T17:31:40.805Z,1606843900.805 [SBIT](IMPORTANT): Express linearApproximation WetLabsUBAT.flow_rate 1.000000 liter_per_second;

2020-12-01T17:31:40.805Z,1606843900.805 [SBIT](IMPORTANT): PAR_Licor.loadAtStartup=1 bool;

2020-12-01T17:31:40.805Z,1606843900.805 [SBIT](IMPORTANT): PAR_Licor.parCal=1.01146 none;

2020-12-01T17:31:40.805Z,1606843900.805 [SBIT](IMPORTANT): RDI_Pathfinder.loadAtStartup=1 bool;

2020-12-01T17:31:40.805Z,1606843900.805 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=254.6 cubic_centimeter;

2020-12-01T17:31:40.805Z,1606843900.805 [SBIT](IMPORTANT): VerticalControl.massDefault=7.48 millimeter;

2020-12-01T17:31:40.805Z,1606843900.805 [SBIT](IMPORTANT): WetLabsUBAT.loadAtStartup=1 bool;

2020-12-01T17:31:41.194Z,1606843901.194 [MissionManager](IMPORTANT): Started mission Startup
2020-12-01T17:31:41.194Z,1606843901.194 [Startup] Running Loop=1
2020-12-01T17:31:41.194Z,1606843901.194 [Startup](DEBUG): Aggregate::initialize Startup
2020-12-01T17:31:41.194Z,1606843901.194 [Startup:A.GoToSurface] Running Loop=1
2020-12-01T17:31:41.194Z,1606843901.194 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2020-12-01T17:31:41.195Z,1606843901.195 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2020-12-01T17:31:41.195Z,1606843901.195 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2020-12-01T17:31:41.196Z,1606843901.196 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2020-12-01T17:31:41.196Z,1606843901.196 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2020-12-01T17:31:41.197Z,1606843901.197 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2020-12-01T17:31:41.198Z,1606843901.198 [Startup:StartupSatComms] Running Loop=1
2020-12-01T17:31:41.198Z,1606843901.198 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2020-12-01T17:31:41.198Z,1606843901.198 [Startup:StartupSatComms:A] Running Loop=1
2020-12-01T17:31:41.606Z,1606843901.606 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2020-12-01T17:32:41.477Z,1606843961.477 [Startup:StartupSatComms:A](INFO): Timed out from 2020-12-01T17:31:41.2Z
2020-12-01T17:32:41.478Z,1606843961.478 [Startup:StartupSatComms:A] Stopped
2020-12-01T17:32:41.478Z,1606843961.478 [Startup:StartupSatComms:B] Running Loop=1
2020-12-01T17:32:41.798Z,1606843961.798 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2020-12-01T17:32:57.586Z,1606843977.586 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2020-12-01T17:32:57.586Z,1606843977.586 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-12-01T17:32:57.596Z,1606843977.596 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-12-01T17:32:57.965Z,1606843977.965 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-12-01T17:32:57.965Z,1606843977.965 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2020-12-01T17:33:23.278Z,1606844003.278 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.005190
2020-12-01T17:33:27.642Z,1606844007.642 [CommandLine](IMPORTANT): got command failComponent
2020-12-01T17:33:27.643Z,1606844007.643 [CommandLine](IMPORTANT): Failed components:
2020-12-01T17:33:27.643Z,1606844007.643 [CommandLine](IMPORTANT): DropWeight: Hardware Fault
2020-12-01T17:33:30.821Z,1606844010.821 [DataOverHttps](INFO): Sending 168 bytes from file Logs/20201201T171815/Courier0007.lzma
2020-12-01T17:33:31.822Z,1606844011.822 [DataOverHttps](INFO): Moved sent file to Logs/20201201T171815/Courier0007.lzma.bak
2020-12-01T17:33:31.822Z,1606844011.822 [DataOverHttps](INFO): SBD MOMSN=13372763
2020-12-01T17:33:41.635Z,1606844021.635 [Startup:StartupSatComms:B](INFO): Timed out from 2020-12-01T17:32:41.5Z
2020-12-01T17:33:41.635Z,1606844021.635 [Startup:StartupSatComms:B] Stopped
2020-12-01T17:33:41.635Z,1606844021.635 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2020-12-01T17:33:41.635Z,1606844021.635 [Startup:StartupSatComms] Stopped
2020-12-01T17:33:41.635Z,1606844021.635 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2020-12-01T17:33:41.636Z,1606844021.636 [Startup](INFO): Completed Startup
2020-12-01T17:33:41.636Z,1606844021.636 [MissionManager](INFO): Startup is completed.
2020-12-01T17:33:41.636Z,1606844021.636 [MissionManager](INFO): Uninitializing Mission Startup
2020-12-01T17:33:41.636Z,1606844021.636 [Startup] Stopped
2020-12-01T17:33:41.636Z,1606844021.636 [Startup](DEBUG): Aggregate::uninitialize Startup
2020-12-01T17:33:41.636Z,1606844021.636 [Startup:A.GoToSurface] Stopped
2020-12-01T17:33:41.636Z,1606844021.636 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2020-12-01T17:33:42.039Z,1606844022.039 [MissionManager](IMPORTANT): Started mission Default
2020-12-01T17:33:42.039Z,1606844022.039 [Default] Running Loop=1
2020-12-01T17:33:42.039Z,1606844022.039 [Default](DEBUG): Aggregate::initialize Default
2020-12-01T17:33:42.039Z,1606844022.039 [Default:B.GoToSurface] Running Loop=1
2020-12-01T17:33:42.039Z,1606844022.039 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2020-12-01T17:33:42.039Z,1606844022.039 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2020-12-01T17:33:42.040Z,1606844022.040 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2020-12-01T17:33:42.040Z,1606844022.040 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2020-12-01T17:33:42.041Z,1606844022.041 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2020-12-01T17:33:42.041Z,1606844022.041 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2020-12-01T17:33:42.041Z,1606844022.041 [Default:A.Wait] Running Loop=1
2020-12-01T17:33:42.041Z,1606844022.041 [Default:A.Wait](DEBUG): Initialize Wait Component.
2020-12-01T17:33:47.680Z,1606844027.680 [DataOverHttps](INFO): Sending 240 bytes from file Logs/20201201T172947/Courier0000.lzma
2020-12-01T17:33:48.681Z,1606844028.681 [DataOverHttps](INFO): Moved sent file to Logs/20201201T172947/Courier0000.lzma.bak
2020-12-01T17:33:48.682Z,1606844028.682 [DataOverHttps](INFO): SBD MOMSN=13372765
2020-12-01T17:33:55.377Z,1606844035.377 [Default:A.Wait](INFO): Done Waiting.
2020-12-01T17:33:55.377Z,1606844035.377 [Default:A.Wait] Stopped
2020-12-01T17:33:55.377Z,1606844035.377 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2020-12-01T17:33:55.773Z,1606844035.773 [Default:CheckIn] Running Loop=1
2020-12-01T17:33:55.773Z,1606844035.773 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-12-01T17:33:55.773Z,1606844035.773 [Default:CheckIn:Read_GPS] Running Loop=1
2020-12-01T17:33:56.158Z,1606844036.158 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2020-12-01T17:35:58.704Z,1606844158.704 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2020-12-01T17:35:58.704Z,1606844158.704 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-12-01T17:35:58.725Z,1606844158.725 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-12-01T17:35:59.094Z,1606844159.094 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-12-01T17:35:59.094Z,1606844159.094 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2020-12-01T17:36:03.552Z,1606844163.552 [NAL9602](INFO): SBD MO Status=0, MOMSN=11383, MT Status=0, MTMSN=0
2020-12-01T17:36:03.553Z,1606844163.553 [NAL9602](INFO): No messages in MT queue
2020-12-01T17:37:23.553Z,1606844243.553 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2020-12-01T17:37:23.556Z,1606844243.556 [BPC1](INFO): Received data from all battery sticks.
2020-12-01T17:38:56.130Z,1606844336.130 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-12-01T17:33:55.8Z
2020-12-01T17:38:56.130Z,1606844336.130 [Default:CheckIn:Read_GPS] Stopped
2020-12-01T17:38:56.130Z,1606844336.130 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-12-01T17:38:56.513Z,1606844336.513 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2020-12-01T17:38:59.812Z,1606844339.812 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2020-12-01T17:38:59.812Z,1606844339.812 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-12-01T17:38:59.830Z,1606844339.830 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-12-01T17:39:00.176Z,1606844340.176 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-12-01T17:39:00.176Z,1606844340.176 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2020-12-01T17:39:04.063Z,1606844344.063 [DataOverHttps](INFO): Sending 168 bytes from file Logs/20201201T172947/Courier0004.lzma
2020-12-01T17:39:05.066Z,1606844345.066 [DataOverHttps](INFO): Moved sent file to Logs/20201201T172947/Courier0004.lzma.bak
2020-12-01T17:39:05.066Z,1606844345.066 [DataOverHttps](INFO): SBD MOMSN=13372789
2020-12-01T17:39:38.107Z,1606844378.107 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173937.00,A,3648.16514,N,12147.28322,W,0.175,12.83,011220,,,D*4C
2020-12-01T17:39:38.110Z,1606844378.110 [NAL9602](INFO): GPS fix at 20201201T173937: (36.802752, -121.788054)
2020-12-01T17:40:10.432Z,1606844410.432 [NAL9602](INFO): Not Powering down - fast GPS
2020-12-01T17:40:32.396Z,1606844432.396 [CommandLine](IMPORTANT): got command strobe off
2020-12-01T17:40:32.396Z,1606844432.396 [CommandLine](IMPORTANT): Deactivating strobe
2020-12-01T17:41:30.580Z,1606844490.580 [DataOverHttps](INFO): Sending 281 bytes from file Logs/20201201T171815/Express0008.lzma
2020-12-01T17:41:31.582Z,1606844491.582 [DataOverHttps](INFO): Moved sent file to Logs/20201201T171815/Express0008.lzma.bak
2020-12-01T17:41:31.582Z,1606844491.582 [DataOverHttps](INFO): SBD MOMSN=13372827
2020-12-01T17:41:47.621Z,1606844507.621 [DataOverHttps](INFO): Sending 1010 bytes from file Logs/20201201T172947/Express0001.lzma
2020-12-01T17:41:48.622Z,1606844508.622 [DataOverHttps](INFO): Moved sent file to Logs/20201201T172947/Express0001.lzma.bak
2020-12-01T17:41:48.622Z,1606844508.622 [DataOverHttps](INFO): SBD MOMSN=13372843
2020-12-01T17:42:04.908Z,1606844524.908 [DataOverHttps](INFO): Sending 152 bytes from file Logs/20201201T172947/Express0005.lzma
2020-12-01T17:42:05.913Z,1606844525.913 [DataOverHttps](INFO): Moved sent file to Logs/20201201T172947/Express0005.lzma.bak
2020-12-01T17:42:05.914Z,1606844525.914 [DataOverHttps](INFO): SBD MOMSN=13372871
2020-12-01T17:42:06.949Z,1606844526.949 [Default:CheckIn:Read_Iridium] Stopped
2020-12-01T17:42:06.949Z,1606844526.949 [Default:CheckIn:C.Wait] Running Loop=1
2020-12-01T17:42:06.949Z,1606844526.949 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-12-01T17:44:58.393Z,1606844698.393 [CBIT](INFO): Clearing failed state for component DropWeight
2020-12-01T17:44:58.393Z,1606844698.393 [DropWeight] No Fault, FailCount= 1
2020-12-01T17:47:07.698Z,1606844827.698 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-12-01T17:47:07.699Z,1606844827.699 [Default:CheckIn:C.Wait] Stopped
2020-12-01T17:47:07.699Z,1606844827.699 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-12-01T17:47:07.699Z,1606844827.699 [Default:CheckIn:D] Running Loop=1
2020-12-01T17:47:08.104Z,1606844828.104 [Default:CheckIn:D] Stopped
2020-12-01T17:47:08.104Z,1606844828.104 [Default:CheckIn:E] Running Loop=1
2020-12-01T17:47:08.500Z,1606844828.500 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 13.434416 min 
2020-12-01T17:47:08.500Z,1606844828.500 [Default:CheckIn:E] Stopped
2020-12-01T17:47:08.500Z,1606844828.500 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-12-01T17:47:08.500Z,1606844828.500 [Default:CheckIn] Stopped
2020-12-01T17:47:08.500Z,1606844828.500 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-12-01T17:47:08.500Z,1606844828.500 [Default:CheckIn](INFO): Running loop #2
2020-12-01T17:47:08.501Z,1606844828.501 [Default:CheckIn] Running Loop=2
2020-12-01T17:47:08.501Z,1606844828.501 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-12-01T17:47:08.501Z,1606844828.501 [Default:CheckIn:Read_GPS] Running Loop=1
2020-12-01T17:47:10.501Z,1606844830.501 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174709.00,A,3648.17037,N,12147.27538,W,0.253,12.83,011220,,,D*48
2020-12-01T17:47:10.503Z,1606844830.503 [NAL9602](INFO): GPS fix at 20201201T174709: (36.802839, -121.787923)
2020-12-01T17:47:10.514Z,1606844830.514 [Default:CheckIn:Read_GPS] Stopped
2020-12-01T17:47:10.514Z,1606844830.514 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-12-01T17:47:18.043Z,1606844838.043 [DataOverHttps](INFO): Sending 223 bytes from file Logs/20201201T172947/Courier0007.lzma
2020-12-01T17:47:19.046Z,1606844839.046 [DataOverHttps](INFO): Moved sent file to Logs/20201201T172947/Courier0007.lzma.bak
2020-12-01T17:47:19.046Z,1606844839.046 [DataOverHttps](INFO): SBD MOMSN=13372911
2020-12-01T17:47:35.284Z,1606844855.284 [DataOverHttps](INFO): Sending 326 bytes from file Logs/20201201T172947/Express0008.lzma
2020-12-01T17:47:36.286Z,1606844856.286 [DataOverHttps](INFO): Moved sent file to Logs/20201201T172947/Express0008.lzma.bak
2020-12-01T17:47:36.286Z,1606844856.286 [DataOverHttps](INFO): SBD MOMSN=13372914
2020-12-01T17:47:37.584Z,1606844857.584 [Default:CheckIn:Read_Iridium] Stopped
2020-12-01T17:47:37.584Z,1606844857.584 [Default:CheckIn:C.Wait] Running Loop=1
2020-12-01T17:47:37.584Z,1606844857.584 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-12-01T17:50:08.700Z,1606845008.700 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2020-12-01T17:52:23.247Z,1606845143.247 [NAL9602](INFO): SBD MO Status=0, MOMSN=11384, MT Status=0, MTMSN=0
2020-12-01T17:52:23.247Z,1606845143.247 [NAL9602](INFO): No messages in MT queue
2020-12-01T17:52:33.905Z,1606845153.905 [DataOverHttps](IMPORTANT): SBD MTMSN=20201201T175232
2020-12-01T17:52:38.317Z,1606845158.317 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-12-01T17:52:38.317Z,1606845158.317 [Default:CheckIn:C.Wait] Stopped
2020-12-01T17:52:38.317Z,1606845158.317 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-12-01T17:52:38.317Z,1606845158.317 [Default:CheckIn:D] Running Loop=1
2020-12-01T17:52:38.696Z,1606845158.696 [Default:CheckIn:D] Stopped
2020-12-01T17:52:38.696Z,1606845158.696 [Default:CheckIn:E] Running Loop=1
2020-12-01T17:52:39.103Z,1606845159.103 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 18.944287 min 
2020-12-01T17:52:39.103Z,1606845159.103 [Default:CheckIn:E] Stopped
2020-12-01T17:52:39.103Z,1606845159.103 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-12-01T17:52:39.103Z,1606845159.103 [Default:CheckIn] Stopped
2020-12-01T17:52:39.103Z,1606845159.103 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-12-01T17:52:39.103Z,1606845159.103 [Default:CheckIn](INFO): Running loop #3
2020-12-01T17:52:39.103Z,1606845159.103 [Default:CheckIn] Running Loop=3
2020-12-01T17:52:39.103Z,1606845159.103 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-12-01T17:52:39.104Z,1606845159.104 [Default:CheckIn:Read_GPS] Running Loop=1
2020-12-01T17:52:41.086Z,1606845161.086 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175240.00,A,3648.16340,N,12147.27873,W,0.078,4.54,011220,,,A*72
2020-12-01T17:52:41.089Z,1606845161.089 [NAL9602](INFO): GPS fix at 20201201T175240: (36.802723, -121.787979)
2020-12-01T17:52:41.132Z,1606845161.132 [Default:CheckIn:Read_GPS] Stopped
2020-12-01T17:52:41.132Z,1606845161.132 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-12-01T17:52:42.992Z,1606845162.992 [DataOverHttps](INFO): Received command:restart app
2020-12-01T17:52:43.048Z,1606845163.048 [CommandLine](IMPORTANT): got command restart application
2020-12-01T17:52:44.052Z,1606845164.052 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2020-12-01T17:52:44.052Z,1606845164.052 [CommandLine ThreadHandler](INFO): Thread cancelled.
2020-12-01T17:52:44.120Z,1606845164.120 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2020-12-01T17:52:44.120Z,1606845164.120 [CommandLine ThreadHandler](INFO): Thread cancelled.
2020-12-01T17:52:44.150Z,1606845164.150 [CommandLine](INFO): Join timeout helper Thread ID is 6645
2020-12-01T17:52:44.166Z,1606845164.166 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2020-12-01T17:52:44.166Z,1606845164.166 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2020-12-01T17:52:44.166Z,1606845164.166 [NavChartDb](INFO): Join timeout helper Thread ID is 6646
2020-12-01T17:52:44.568Z,1606845164.568 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2020-12-01T17:52:44.568Z,1606845164.568 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2020-12-01T17:52:44.584Z,1606845164.584 [ComponentRegistry](INFO): Shutting down WetLabsUBAT ThreadHandler
2020-12-01T17:52:44.584Z,1606845164.584 [WetLabsUBAT ThreadHandler](INFO): Thread cancelled.
2020-12-01T17:52:44.584Z,1606845164.584 [WetLabsUBAT](INFO): Join timeout helper Thread ID is 6647
2020-12-01T17:52:44.840Z,1606845164.840 [WetLabsUBAT ThreadHandler](INFO): Uninitializing protected caller thread.
2020-12-01T17:52:44.840Z,1606845164.840 [WetLabsUBAT](INFO): Powering down
2020-12-01T17:52:44.841Z,1606845164.841 [WetLabsUBAT ThreadHandler](INFO): Thread cancelled.
2020-12-01T17:52:44.848Z,1606845164.848 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2020-12-01T17:52:44.848Z,1606845164.848 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2020-12-01T17:52:44.848Z,1606845164.848 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 6648
2020-12-01T17:52:45.332Z,1606845165.332 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2020-12-01T17:52:45.333Z,1606845165.333 [WetLabsBB2FL](INFO): Powering down
2020-12-01T17:52:45.333Z,1606845165.333 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2020-12-01T17:52:45.352Z,1606845165.352 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2020-12-01T17:52:45.352Z,1606845165.352 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2020-12-01T17:52:45.352Z,1606845165.352 [CTD_Seabird](INFO): Join timeout helper Thread ID is 6649
2020-12-01T17:52:45.468Z,1606845165.468 [CTD_Seabird](INFO): Powering down
2020-12-01T17:52:45.480Z,1606845165.480 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2020-12-01T17:52:45.480Z,1606845165.480 [CTD_Seabird](INFO): Powering down
2020-12-01T17:52:45.499Z,1606845165.499 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2020-12-01T17:52:45.501Z,1606845165.501 [ComponentRegistry](INFO): Shutting down BackSeatDriver ThreadHandler
2020-12-01T17:52:45.501Z,1606845165.501 [BackSeatDriver ThreadHandler](INFO): Thread cancelled.
2020-12-01T17:52:45.502Z,1606845165.502 [BackSeatDriver](INFO): Join timeout helper Thread ID is 6650
2020-12-01T17:52:45.660Z,1606845165.660 [BackSeatDriver ThreadHandler](INFO): Uninitializing protected caller thread.
2020-12-01T17:52:45.660Z,1606845165.660 [BackSeatDriver ThreadHandler](INFO): Thread cancelled.
2020-12-01T17:52:45.665Z,1606845165.665 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2020-12-01T17:52:45.665Z,1606845165.665 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2020-12-01T17:52:45.665Z,1606845165.665 [Radio_Surface](INFO): Join timeout helper Thread ID is 6651
2020-12-01T17:52:46.060Z,1606845166.060 [Radio_Surface](INFO): Powering down
2020-12-01T17:52:46.061Z,1606845166.061 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2020-12-01T17:52:46.061Z,1606845166.061 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2020-12-01T17:52:46.089Z,1606845166.089 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler
2020-12-01T17:52:46.089Z,1606845166.089 [Onboard ThreadHandler](INFO): Thread cancelled.
2020-12-01T17:52:46.089Z,1606845166.089 [Onboard](INFO): Join timeout helper Thread ID is 6652
2020-12-01T17:52:48.560Z,1606845168.560 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread.
2020-12-01T17:52:48.560Z,1606845168.560 [Onboard ThreadHandler](INFO): Thread cancelled.
2020-12-01T17:52:48.565Z,1606845168.565 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2020-12-01T17:52:48.565Z,1606845168.565 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2020-12-01T17:52:48.565Z,1606845168.565 [DataOverHttps](INFO): Join timeout helper Thread ID is 6653
2020-12-01T17:52:49.012Z,1606845169.012 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2020-12-01T17:52:49.015Z,1606845169.015 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2020-12-01T17:52:49.029Z,1606845169.029 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2020-12-01T17:52:49.029Z,1606845169.029 [logger ThreadHandler](INFO): Thread cancelled.
2020-12-01T17:52:49.029Z,1606845169.029 [logger](INFO): Join timeout helper Thread ID is 6654
2020-12-01T17:52:49.052Z,1606845169.052 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2020-12-01T17:52:49.052Z,1606845169.052 [logger ThreadHandler](INFO): Thread cancelled.
2020-12-01T17:52:49.068Z,1606845169.068 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2020-12-01T17:52:49.069Z,1606845169.069 [CommandLine ThreadHandler](INFO): Thread cancelled.
2020-12-01T17:52:49.069Z,1606845169.069 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2020-12-01T17:52:49.069Z,1606845169.069 [controlThread ThreadHandler](INFO): Thread cancelled.
2020-12-01T17:52:49.069Z,1606845169.069 [controlThread](INFO): Join timeout helper Thread ID is 6655
2020-12-01T17:52:49.232Z,1606845169.232 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2020-12-01T17:52:49.232Z,1606845169.232 [controlThread](DEBUG): Uninitializing ControlThread
2020-12-01T17:52:49.233Z,1606845169.233 [AHRS_M2](INFO): Powering down
2020-12-01T17:52:49.304Z,1606845169.304 [NAL9602](INFO): Powering down
2020-12-01T17:52:49.376Z,1606845169.376 [RDI_Pathfinder](INFO): Powering down
2020-12-01T17:52:49.377Z,1606845169.377 [DAT](INFO): Powering down
2020-12-01T17:52:49.497Z,1606845169.497 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2020-12-01T17:52:49.498Z,1606845169.498 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2020-12-01T17:52:49.498Z,1606845169.498 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2020-12-01T17:52:49.499Z,1606845169.499 [MissionManager](INFO): Uninitializing Mission Default
2020-12-01T17:52:49.499Z,1606845169.499 [Default] Stopped
2020-12-01T17:52:49.499Z,1606845169.499 [Default](DEBUG): Aggregate::uninitialize Default
2020-12-01T17:52:49.499Z,1606845169.499 [Default:B.GoToSurface] Stopped
2020-12-01T17:52:49.499Z,1606845169.499 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2020-12-01T17:52:49.499Z,1606845169.499 [Default:CheckIn] Stopped
2020-12-01T17:52:49.499Z,1606845169.499 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-12-01T17:52:49.499Z,1606845169.499 [Default:CheckIn:Read_Iridium] Stopped
2020-12-01T17:52:49.501Z,1606845169.501 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2020-12-01T17:52:49.502Z,1606845169.502 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2020-12-01T17:52:49.502Z,1606845169.502 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2020-12-01T17:52:49.502Z,1606845169.502 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2020-12-01T17:52:49.502Z,1606845169.502 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2020-12-01T17:52:49.502Z,1606845169.502 [BuoyancyServo](INFO): Powering down
2020-12-01T17:52:49.516Z,1606845169.516 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2020-12-01T17:52:49.516Z,1606845169.516 [ElevatorServo](INFO): Powering down
2020-12-01T17:52:49.517Z,1606845169.517 [MassServo](DEBUG): Uninitialize Mass Servo.
2020-12-01T17:52:49.517Z,1606845169.517 [MassServo](INFO): Powering down
2020-12-01T17:52:49.518Z,1606845169.518 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2020-12-01T17:52:49.518Z,1606845169.518 [RudderServo](INFO): Powering down
2020-12-01T17:52:49.518Z,1606845169.518 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2020-12-01T17:52:49.518Z,1606845169.518 [ThrusterServo](INFO): Powering down
2020-12-01T17:52:49.519Z,1606845169.519 [SBIT](DEBUG): Uninitialize SBIT Component.
2020-12-01T17:52:49.519Z,1606845169.519 [IBIT](DEBUG): Uninitialize IBIT Component.
2020-12-01T17:52:49.520Z,1606845169.520 [CBIT](DEBUG): Uninitialize CBIT Component.
2020-12-01T17:52:49.520Z,1606845169.520 [CBIT](DEBUG): Powering off loads.
2020-12-01T17:52:49.532Z,1606845169.532 [CBIT](DEBUG): Disabling WDT.
2020-12-01T17:52:49.544Z,1606845169.544 [CBIT](DEBUG): Opening all GF detection circuits.
2020-12-01T17:52:49.545Z,1606845169.545 [controlThread ThreadHandler](INFO): Thread cancelled.
2020-12-01T17:52:49.630Z,1606845169.630 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2020-12-01T17:52:49.632Z,1606845169.632 [Onboard ThreadHandler](INFO): Thread cancelled.
2020-12-01T17:52:49.638Z,1606845169.638 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2020-12-01T17:52:49.695Z,1606845169.695 [WetLabsUBAT ThreadHandler](INFO): Thread cancelled.
2020-12-01T17:52:49.696Z,1606845169.696 [WetLabsUBAT](INFO): WetLabs destructor: _dataLog is not open
2020-12-01T17:52:49.696Z,1606845169.696 [WetLabsUBAT](INFO): WetLabs destructor: done
2020-12-01T17:52:49.699Z,1606845169.699 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2020-12-01T17:52:49.703Z,1606845169.703 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2020-12-01T17:52:49.706Z,1606845169.706 [BackSeatDriver ThreadHandler](INFO): Thread cancelled.
2020-12-01T17:52:49.715Z,1606845169.715 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2020-12-01T17:52:49.787Z,1606845169.787 [logger ThreadHandler](INFO): Thread cancelled.