2020-11-09T16:00:38.156Z,1604937638.156 [Supervisor](DEBUG): Initializing supervisor.
2020-11-09T16:00:38.158Z,1604937638.158 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2020-11-09T16:00:38.159Z,1604937638.159 [SyncHandler](INFO): Protected caller Thread ID is 6002
2020-11-09T16:00:38.159Z,1604937638.159 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2020-11-09T16:00:38.160Z,1604937638.160 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2020-11-09T16:00:38.160Z,1604937638.160 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 6003
2020-11-09T16:00:38.163Z,1604937638.163 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2020-11-09T16:00:38.180Z,1604937638.180 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2020-11-09T16:00:38.181Z,1604937638.181 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2020-11-09T16:00:38.181Z,1604937638.181 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 6004
2020-11-09T16:00:38.182Z,1604937638.182 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2020-11-09T16:00:38.183Z,1604937638.183 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2020-11-09T16:00:38.183Z,1604937638.183 [logger ThreadHandler](INFO): Protected caller Thread ID is 6005
2020-11-09T16:00:38.186Z,1604937638.186 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2020-11-09T16:00:38.186Z,1604937638.186 [Supervisor](INFO): Looking for Config files in directory: Config/
2020-11-09T16:00:38.188Z,1604937638.188 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2020-11-09T16:00:38.609Z,1604937638.609 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2020-11-09T16:00:38.609Z,1604937638.609 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2020-11-09T16:00:38.704Z,1604937638.704 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2020-11-09T16:00:38.705Z,1604937638.705 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2020-11-09T16:00:39.006Z,1604937639.006 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2020-11-09T16:00:39.007Z,1604937639.007 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2020-11-09T16:00:39.141Z,1604937639.141 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2020-11-09T16:00:39.142Z,1604937639.142 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2020-11-09T16:00:39.324Z,1604937639.324 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2020-11-09T16:00:39.325Z,1604937639.325 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2020-11-09T16:00:39.820Z,1604937639.820 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2020-11-09T16:00:39.820Z,1604937639.820 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2020-11-09T16:00:40.028Z,1604937640.028 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2020-11-09T16:00:40.028Z,1604937640.028 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2020-11-09T16:00:40.168Z,1604937640.168 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2020-11-09T16:00:40.169Z,1604937640.169 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2020-11-09T16:00:40.349Z,1604937640.349 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2020-11-09T16:00:40.350Z,1604937640.350 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2020-11-09T16:00:40.445Z,1604937640.445 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2020-11-09T16:00:40.445Z,1604937640.445 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2020-11-09T16:00:40.639Z,1604937640.639 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2020-11-09T16:00:40.640Z,1604937640.640 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2020-11-09T16:00:40.931Z,1604937640.931 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2020-11-09T16:00:40.931Z,1604937640.931 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2020-11-09T16:00:41.011Z,1604937641.011 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2020-11-09T16:00:41.115Z,1604937641.115 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2020-11-09T16:00:41.116Z,1604937641.116 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2020-11-09T16:00:41.752Z,1604937641.752 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2020-11-09T16:00:41.753Z,1604937641.753 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2020-11-09T16:00:42.156Z,1604937642.156 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2020-11-09T16:00:42.158Z,1604937642.158 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/
2020-11-09T16:00:42.159Z,1604937642.159 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/vehicle.cfg
2020-11-09T16:00:42.414Z,1604937642.414 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Control.cfg
2020-11-09T16:00:42.846Z,1604937642.846 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/BIT.cfg
2020-11-09T16:00:43.168Z,1604937643.168 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Battery.cfg
2020-11-09T16:00:43.496Z,1604937643.496 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2020-11-09T16:00:43.497Z,1604937643.497 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Simulator.cfg
2020-11-09T16:00:43.580Z,1604937643.580 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Navigation.cfg
2020-11-09T16:00:43.673Z,1604937643.673 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/logger.cfg
2020-11-09T16:00:43.782Z,1604937643.782 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/secure.cfg
2020-11-09T16:00:43.865Z,1604937643.865 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Dock.cfg
2020-11-09T16:00:43.950Z,1604937643.950 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Servo.cfg
2020-11-09T16:00:44.055Z,1604937644.055 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/workSite.cfg
2020-11-09T16:00:44.147Z,1604937644.147 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Sensor.cfg
2020-11-09T16:00:44.327Z,1604937644.327 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Science.cfg
2020-11-09T16:00:44.460Z,1604937644.460 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2020-11-09T16:00:44.463Z,1604937644.463 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2020-11-09T16:00:44.796Z,1604937644.796 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_orientation
2020-11-09T16:00:44.799Z,1604937644.799 [AHRS_M2](INFO): created writer for : platform_orientation
2020-11-09T16:00:44.800Z,1604937644.800 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_magnetic_orientation
2020-11-09T16:00:44.803Z,1604937644.803 [AHRS_M2](INFO): created writer for : platform_magnetic_orientation
2020-11-09T16:00:44.804Z,1604937644.804 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_pitch_angle
2020-11-09T16:00:44.807Z,1604937644.807 [AHRS_M2](INFO): created writer for : platform_pitch_angle
2020-11-09T16:00:44.807Z,1604937644.807 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_roll_angle
2020-11-09T16:00:44.810Z,1604937644.810 [AHRS_M2](INFO): created writer for : platform_roll_angle
2020-11-09T16:00:44.846Z,1604937644.846 [AHRS_M2] Loaded
2020-11-09T16:00:44.847Z,1604937644.847 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2020-11-09T16:00:44.916Z,1604937644.916 [DataOverHttps] Loaded
2020-11-09T16:00:44.916Z,1604937644.916 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2020-11-09T16:00:44.917Z,1604937644.917 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4077A4E0
2020-11-09T16:00:44.918Z,1604937644.918 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 6093
2020-11-09T16:00:44.936Z,1604937644.936 [DDM] Loaded
2020-11-09T16:00:44.936Z,1604937644.936 [ComponentRegistry](DEBUG): SyncComponent "DDM" handled in the control thread.
2020-11-09T16:00:44.952Z,1604937644.952 [Depth_Keller] Loaded
2020-11-09T16:00:44.952Z,1604937644.952 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2020-11-09T16:00:44.955Z,1604937644.955 [DropWeight] Loaded
2020-11-09T16:00:44.955Z,1604937644.955 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2020-11-09T16:00:44.993Z,1604937644.993 [DUSBL_Hydroid] Loaded
2020-11-09T16:00:44.994Z,1604937644.994 [ComponentRegistry](DEBUG): SyncComponent "DUSBL_Hydroid" handled in the control thread.
2020-11-09T16:00:45.026Z,1604937645.026 [Micromodem] Loaded
2020-11-09T16:00:45.026Z,1604937645.026 [ComponentRegistry](DEBUG): SyncComponent "Micromodem" handled in the control thread.
2020-11-09T16:00:45.080Z,1604937645.080 [NAL9602] Loaded
2020-11-09T16:00:45.080Z,1604937645.080 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2020-11-09T16:00:45.105Z,1604937645.105 [Onboard] Loaded
2020-11-09T16:00:45.105Z,1604937645.105 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2020-11-09T16:00:45.106Z,1604937645.106 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 407AA4E0
2020-11-09T16:00:45.106Z,1604937645.106 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 6094
2020-11-09T16:00:45.110Z,1604937645.110 [PowerOnly](INFO): Adding load control power supply at /dev/loadC1
2020-11-09T16:00:45.120Z,1604937645.120 [PowerOnly] Loaded
2020-11-09T16:00:45.120Z,1604937645.120 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread.
2020-11-09T16:00:45.131Z,1604937645.131 [Radio_Surface] Loaded
2020-11-09T16:00:45.131Z,1604937645.131 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2020-11-09T16:00:45.132Z,1604937645.132 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 407DA4E0
2020-11-09T16:00:45.132Z,1604937645.132 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 6095
2020-11-09T16:00:45.159Z,1604937645.159 [RDI_Pathfinder] Loaded
2020-11-09T16:00:45.159Z,1604937645.159 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread.
2020-11-09T16:00:45.182Z,1604937645.182 [RDI_PathfinderUp] Loaded
2020-11-09T16:00:45.182Z,1604937645.182 [ComponentRegistry](DEBUG): SyncComponent "RDI_PathfinderUp" handled in the control thread.
2020-11-09T16:00:45.959Z,1604937645.959 [BPC1] Loaded
2020-11-09T16:00:45.959Z,1604937645.959 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2020-11-09T16:00:45.959Z,1604937645.959 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2020-11-09T16:00:45.960Z,1604937645.960 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2020-11-09T16:00:45.979Z,1604937645.979 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2020-11-09T16:00:45.979Z,1604937645.979 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2020-11-09T16:00:46.058Z,1604937646.058 [DeadReckonUsingMultipleVelocitySources] Loaded
2020-11-09T16:00:46.058Z,1604937646.058 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2020-11-09T16:00:46.069Z,1604937646.069 [NavChart] Loaded
2020-11-09T16:00:46.069Z,1604937646.069 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2020-11-09T16:00:46.073Z,1604937646.073 [UniversalFixResidualReporter] Loaded
2020-11-09T16:00:46.073Z,1604937646.073 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2020-11-09T16:00:46.081Z,1604937646.081 [WorkSite] Loaded
2020-11-09T16:00:46.081Z,1604937646.081 [ComponentRegistry](DEBUG): SyncComponent "WorkSite" handled in the control thread.
2020-11-09T16:00:46.082Z,1604937646.082 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2020-11-09T16:00:46.082Z,1604937646.082 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2020-11-09T16:00:46.162Z,1604937646.162 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2020-11-09T16:00:46.163Z,1604937646.163 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2020-11-09T16:00:46.275Z,1604937646.275 [BuoyancyServo] Loaded
2020-11-09T16:00:46.275Z,1604937646.275 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2020-11-09T16:00:46.294Z,1604937646.294 [ElevatorServo] Loaded
2020-11-09T16:00:46.294Z,1604937646.294 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2020-11-09T16:00:46.311Z,1604937646.311 [MassServo] Loaded
2020-11-09T16:00:46.311Z,1604937646.311 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2020-11-09T16:00:46.328Z,1604937646.328 [RudderServo] Loaded
2020-11-09T16:00:46.328Z,1604937646.328 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2020-11-09T16:00:46.345Z,1604937646.345 [ThrusterServo] Loaded
2020-11-09T16:00:46.345Z,1604937646.345 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2020-11-09T16:00:46.345Z,1604937646.345 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2020-11-09T16:00:46.346Z,1604937646.346 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2020-11-09T16:00:46.544Z,1604937646.544 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_density
2020-11-09T16:00:46.546Z,1604937646.546 [CTD_Seabird](INFO): created writer for : sea_water_density
2020-11-09T16:00:46.547Z,1604937646.547 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): depth
2020-11-09T16:00:46.549Z,1604937646.549 [CTD_Seabird](INFO): created writer for : depth
2020-11-09T16:00:46.550Z,1604937646.550 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_pressure
2020-11-09T16:00:46.552Z,1604937646.552 [CTD_Seabird](INFO): created writer for : sea_water_pressure
2020-11-09T16:00:46.553Z,1604937646.553 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_salinity
2020-11-09T16:00:46.556Z,1604937646.556 [CTD_Seabird](INFO): created writer for : sea_water_salinity
2020-11-09T16:00:46.556Z,1604937646.556 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_temperature
2020-11-09T16:00:46.560Z,1604937646.560 [CTD_Seabird](INFO): created writer for : sea_water_temperature
2020-11-09T16:00:46.560Z,1604937646.560 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_electrical_conductivity
2020-11-09T16:00:46.563Z,1604937646.563 [CTD_Seabird](INFO): created writer for : sea_water_electrical_conductivity
2020-11-09T16:00:46.564Z,1604937646.564 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): speed_of_sound_in_sea_water
2020-11-09T16:00:46.566Z,1604937646.566 [CTD_Seabird](INFO): created writer for : speed_of_sound_in_sea_water
2020-11-09T16:00:46.567Z,1604937646.567 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): mass_concentration_of_oxygen_in_sea_water
2020-11-09T16:00:46.570Z,1604937646.570 [CTD_Seabird](INFO): created writer for : mass_concentration_of_oxygen_in_sea_water
2020-11-09T16:00:46.570Z,1604937646.570 [CTD_Seabird](DEBUG): LcmSlateWriter::add(DAtaURI): CTD_Seabird.sea_water_dissolved_oxygen_freq
2020-11-09T16:00:46.571Z,1604937646.571 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): dataName: sea_water_dissolved_oxygen_freq
2020-11-09T16:00:46.587Z,1604937646.587 [CTD_Seabird] Loaded
2020-11-09T16:00:46.587Z,1604937646.587 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2020-11-09T16:00:46.588Z,1604937646.588 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 409614E0
2020-11-09T16:00:46.588Z,1604937646.588 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 6096
2020-11-09T16:00:46.606Z,1604937646.606 [PAR_Licor] Loaded
2020-11-09T16:00:46.606Z,1604937646.606 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2020-11-09T16:00:46.634Z,1604937646.634 [WetLabsSeaOWL_UV_A] Loaded
2020-11-09T16:00:46.635Z,1604937646.635 [ComponentRegistry](DEBUG): Component "WetLabsSeaOWL_UV_A" handled in its own thread.
2020-11-09T16:00:46.636Z,1604937646.636 [WetLabsSeaOWL_UV_A ThreadHandler](DEBUG): Created PCaller Thread at 409914E0
2020-11-09T16:00:46.636Z,1604937646.636 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Protected caller Thread ID is 6097
2020-11-09T16:00:46.637Z,1604937646.637 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2020-11-09T16:00:46.637Z,1604937646.637 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2020-11-09T16:00:46.932Z,1604937646.932 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2020-11-09T16:00:46.933Z,1604937646.933 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2020-11-09T16:00:46.972Z,1604937646.972 [DepthRateCalculator] Loaded
2020-11-09T16:00:46.972Z,1604937646.972 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2020-11-09T16:00:46.976Z,1604937646.976 [PitchRateCalculator] Loaded
2020-11-09T16:00:46.976Z,1604937646.976 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2020-11-09T16:00:46.983Z,1604937646.983 [SpeedCalculator] Loaded
2020-11-09T16:00:46.983Z,1604937646.983 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2020-11-09T16:00:46.994Z,1604937646.994 [TempGradientCalculator] Loaded
2020-11-09T16:00:46.994Z,1604937646.994 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2020-11-09T16:00:46.997Z,1604937646.997 [YawRateCalculator] Loaded
2020-11-09T16:00:46.998Z,1604937646.998 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2020-11-09T16:00:47.016Z,1604937647.016 [ElevatorOffsetCalculator] Loaded
2020-11-09T16:00:47.016Z,1604937647.016 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2020-11-09T16:00:47.016Z,1604937647.016 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2020-11-09T16:00:47.017Z,1604937647.017 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2020-11-09T16:00:47.154Z,1604937647.154 [SBIT](DEBUG): Construct Startup Built In Test.
2020-11-09T16:00:47.165Z,1604937647.165 [SBIT] Loaded
2020-11-09T16:00:47.165Z,1604937647.165 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2020-11-09T16:00:47.166Z,1604937647.166 [IBIT](DEBUG): Construct Initiated Built In Test.
2020-11-09T16:00:47.178Z,1604937647.178 [IBIT] Loaded
2020-11-09T16:00:47.179Z,1604937647.179 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2020-11-09T16:00:47.182Z,1604937647.182 [CBIT](DEBUG): Construct Continuous Built In Test.
2020-11-09T16:00:47.277Z,1604937647.277 [CBIT] Loaded
2020-11-09T16:00:47.277Z,1604937647.277 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2020-11-09T16:00:47.277Z,1604937647.277 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2020-11-09T16:00:47.278Z,1604937647.278 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2020-11-09T16:00:47.364Z,1604937647.364 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2020-11-09T16:00:47.365Z,1604937647.365 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2020-11-09T16:00:47.465Z,1604937647.465 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2020-11-09T16:00:47.465Z,1604937647.465 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2020-11-09T16:00:47.682Z,1604937647.682 [VerticalControl](DEBUG): Construct VerticalControl.
2020-11-09T16:00:47.958Z,1604937647.958 [VerticalControl] Loaded
2020-11-09T16:00:47.958Z,1604937647.958 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2020-11-09T16:00:47.959Z,1604937647.959 [HorizontalControl](DEBUG): Construct HorizontalControl.
2020-11-09T16:00:48.100Z,1604937648.100 [HorizontalControl] Loaded
2020-11-09T16:00:48.100Z,1604937648.100 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2020-11-09T16:00:48.109Z,1604937648.109 [SpeedControl](DEBUG): Construct SpeedControl.
2020-11-09T16:00:48.110Z,1604937648.110 [SpeedControl] Loaded
2020-11-09T16:00:48.111Z,1604937648.111 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2020-11-09T16:00:48.111Z,1604937648.111 [LoopControl](DEBUG): Construct LoopControl.
2020-11-09T16:00:48.112Z,1604937648.112 [LoopControl] Loaded
2020-11-09T16:00:48.112Z,1604937648.112 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2020-11-09T16:00:48.112Z,1604937648.112 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2020-11-09T16:00:48.113Z,1604937648.113 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2020-11-09T16:00:48.170Z,1604937648.170 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2020-11-09T16:00:48.287Z,1604937648.287 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2020-11-09T16:00:48.288Z,1604937648.288 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2020-11-09T16:00:48.297Z,1604937648.297 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2020-11-09T16:00:48.298Z,1604937648.298 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B674E0
2020-11-09T16:00:48.299Z,1604937648.299 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 6098
2020-11-09T16:00:48.303Z,1604937648.303 [Supervisor](INFO): Main Thread ID is 5521
2020-11-09T16:00:48.303Z,1604937648.303 [Supervisor](DEBUG): Running supervisor.
2020-11-09T16:00:48.304Z,1604937648.304 [CommandLine ThreadHandler](INFO): Handler Thread ID is 6099
2020-11-09T16:00:48.306Z,1604937648.306 [controlThread ThreadHandler](INFO): Handler Thread ID is 6100
2020-11-09T16:00:48.307Z,1604937648.307 [controlThread](DEBUG): Initializing ControlThread
2020-11-09T16:00:48.312Z,1604937648.312 [NavChart](DEBUG): Initialize NavChart Navigation.
2020-11-09T16:00:48.312Z,1604937648.312 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2020-11-09T16:00:48.312Z,1604937648.312 [WorkSite](DEBUG): Initializing WorkSite component.
2020-11-09T16:00:48.317Z,1604937648.317 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2020-11-09T16:00:48.318Z,1604937648.318 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2020-11-09T16:00:48.318Z,1604937648.318 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2020-11-09T16:00:48.318Z,1604937648.318 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2020-11-09T16:00:48.319Z,1604937648.319 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2020-11-09T16:00:48.319Z,1604937648.319 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2020-11-09T16:00:48.320Z,1604937648.320 [SBIT](INFO): Initialize SBIT Component.
2020-11-09T16:00:48.320Z,1604937648.320 [SBIT](IMPORTANT): git: 2020-11-06
2020-11-09T16:00:48.320Z,1604937648.320 [SBIT](INFO): git hash: 159c5b66861882d5f99dda1b1932a945ab78dfb6
2020-11-09T16:00:48.321Z,1604937648.321 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2020-11-09T16:00:48.322Z,1604937648.322 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
Kernel Reported: #1 PREEMPT Thu Aug 6 12:04:53 PDT 2020
2020-11-09T16:00:48.323Z,1604937648.323 [SBIT](INFO): Beginning SBIT in 32.000000 seconds.
2020-11-09T16:00:48.324Z,1604937648.324 [IBIT](INFO): Initialize IBIT Component.
2020-11-09T16:00:48.324Z,1604937648.324 [CBIT](DEBUG): Initialize CBIT Component.
2020-11-09T16:00:48.325Z,1604937648.325 [logger ThreadHandler](INFO): Handler Thread ID is 6101
2020-11-09T16:00:48.337Z,1604937648.337 [CBIT](DEBUG): Initialized mux pins.
2020-11-09T16:00:48.337Z,1604937648.337 [CBIT](DEBUG): Initializing the watchdog timer.
2020-11-09T16:00:48.345Z,1604937648.345 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 6102
2020-11-09T16:00:48.346Z,1604937648.346 [DataOverHttps](DEBUG): dashIP=128.128.181.155 starts with a digit so assuming it is a numeric IP
2020-11-09T16:00:48.357Z,1604937648.357 [Onboard ThreadHandler](INFO): Handler Thread ID is 6103
2020-11-09T16:00:48.361Z,1604937648.361 [CBIT](CRITICAL): LAST REBOOT DUE TO WATCHDOG TIMER RESET.
2020-11-09T16:00:48.362Z,1604937648.362 [CBIT](DEBUG): Initializing heartbeat.
2020-11-09T16:00:48.375Z,1604937648.375 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 6104
2020-11-09T16:00:48.389Z,1604937648.389 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 6105
2020-11-09T16:00:48.390Z,1604937648.390 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2020-11-09T16:00:48.394Z,1604937648.394 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Handler Thread ID is 6107
2020-11-09T16:00:48.395Z,1604937648.395 [WetLabsSeaOWL_UV_A](INFO): Powering down
2020-11-09T16:00:48.406Z,1604937648.406 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 6108
2020-11-09T16:00:48.409Z,1604937648.409 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2020-11-09T16:00:48.409Z,1604937648.409 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2020-11-09T16:00:48.409Z,1604937648.409 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2020-11-09T16:00:48.409Z,1604937648.409 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2020-11-09T16:00:48.409Z,1604937648.409 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2020-11-09T16:00:48.409Z,1604937648.409 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2020-11-09T16:00:48.410Z,1604937648.410 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2020-11-09T16:00:48.410Z,1604937648.410 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2020-11-09T16:00:48.410Z,1604937648.410 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2020-11-09T16:00:48.410Z,1604937648.410 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2020-11-09T16:00:48.410Z,1604937648.410 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2020-11-09T16:00:48.410Z,1604937648.410 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2020-11-09T16:00:48.411Z,1604937648.411 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2020-11-09T16:00:48.411Z,1604937648.411 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2020-11-09T16:00:48.411Z,1604937648.411 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2020-11-09T16:00:48.411Z,1604937648.411 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2020-11-09T16:00:48.433Z,1604937648.433 [CBIT](DEBUG): Deactivating GF circuits.
2020-11-09T16:00:48.433Z,1604937648.433 [CBIT](DEBUG): Deactivating emergency mode.
2020-11-09T16:00:48.469Z,1604937648.469 [CBIT](DEBUG): Backplane powered.
2020-11-09T16:00:48.469Z,1604937648.469 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2020-11-09T16:00:48.471Z,1604937648.471 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2020-11-09T16:00:48.472Z,1604937648.472 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2020-11-09T16:00:48.472Z,1604937648.472 [LoopControl](DEBUG): Initialize LoopControlComponent.
2020-11-09T16:00:48.473Z,1604937648.473 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2020-11-09T16:00:48.483Z,1604937648.483 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2020-11-09T16:00:48.505Z,1604937648.505 [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-11-09T16:00:48.506Z,1604937648.506 [MissionManager](INFO): Loading Mission: Missions/underIce/DefaultWithUndock.xml
2020-11-09T16:00:48.645Z,1604937648.645 [MissionManager](INFO): DefineArg DefaultWithUndock.ElapsedSinceDefaultStarted = 0.000000 min
2020-11-09T16:00:48.665Z,1604937648.665 [MissionManager](INFO): DefineArg DefaultWithUndock.DetachTimeout = 30.000000 min
2020-11-09T16:00:48.669Z,1604937648.669 [MissionManager](INFO): DefineArg DefaultWithUndock.TransponderCode = 2.000000 count
2020-11-09T16:00:48.672Z,1604937648.672 [MissionManager](INFO): DefineArg DefaultWithUndock.TrackingUpdatePeriod = 2.500000 s
2020-11-09T16:00:48.691Z,1604937648.691 [MissionManager](INFO): DefineArg DefaultWithUndock.NumberOfPings = 1.000000 count
2020-11-09T16:00:48.695Z,1604937648.695 [MissionManager](INFO): DefineArg DefaultWithUndock.DetachModeDDM = 2.000000 count
2020-11-09T16:00:48.696Z,1604937648.696 [DefaultWithUndock:A.Wait](DEBUG): Construct Wait.
2020-11-09T16:00:48.789Z,1604937648.789 [Radio_Surface](INFO): Powering up
2020-11-09T16:00:48.805Z,1604937648.805 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Construct.
2020-11-09T16:00:48.829Z,1604937648.829 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Initializing internal variables to default values.
2020-11-09T16:00:48.863Z,1604937648.863 [DefaultWithUndock:SurfaceDefault:B.GoToSurface](DEBUG): Construct GoToSurface.
2020-11-09T16:00:48.902Z,1604937648.902 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2020-11-09T16:00:48.904Z,1604937648.904 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Construct Wait.
2020-11-09T16:00:48.937Z,1604937648.937 [DefaultWithUndock:E.Execute](DEBUG): Construct Execute.
2020-11-09T16:00:48.951Z,1604937648.951 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Dock="Tethys/Dock"
         xmlns:Estimation="Tethys/Estimation"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Sensor="Tethys/Sensor"
         xmlns:Units="Tethys/Units"
         xmlns:Universal="Tethys/Universal"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Dock http://okeanids.mbari.org/tethys/Xml/Dock.xsd
                             Tethys/Estimation http://okeanids.mbari.org/tethys/Xml/Estimation.xsd
                             Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                             Tethys/Sensor http://okeanids.mbari.org/tethys/Xml/Sensor.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                             Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
         Id="DefaultWithUndock">

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

    <DefineArg Name="DetachTimeout"><Description>
        Maximum time duration for the vehicle to detach form the dock.
    </Description><Units:minute/><Value>30</Value></DefineArg>

    <DefineArg Name="TransponderCode"><Description>
        Dock transponder address.
    </Description><Dock:Dock.transponderCode/></DefineArg>

    <DefineArg Name="TrackingUpdatePeriod"><Description>
        Time duration between acoustic range queries while the
        mission is detaching from the dock.
    </Description><Units:second/><Value>2.5</Value></DefineArg>

    <DefineArg Name="NumberOfPings"><Description>
        Number of pings requested each time.
    </Description><Units:count/><Value>1</Value></DefineArg>

    <DefineArg Name="DetachModeDDM"><Description>
        DDM DETACH mode enumeration (whiskers retracted, latch open).
    </Description><Units:count/><Value>2</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>30</Value></Setting>
    </Guidance:Wait>

    <Aggregate Id="LeaveDock">
        <Sequence/>

        <Timeout Duration="DetachTimeout">
            <Syslog Severity="Important">Timed out while trying to detach from dock at current depth of <Universal:depth/><Units:meter/>.</Syslog>
        </Timeout>

        <!-- Acoustic tracking directives -->
        <Estimation:TrackAcousticContact>
            <Parallel/>
            <Setting><Estimation:TrackAcousticContact.contactLabelSetting/><Arg Name="TransponderCode"/></Setting>
            <Setting><Estimation:TrackAcousticContact.numberOfSamplesSetting/><Arg Name="NumberOfPings"/></Setting>
            <Setting><Estimation:TrackAcousticContact.updatePeriodSetting/><Arg Name="TrackingUpdatePeriod"/></Setting>
        </Estimation:TrackAcousticContact>

        <!-- Leave the dock -->
        <Dock:Undock>
            <Sequence/>
        </Dock:Undock>

    </Aggregate>


    <Aggregate Id="SurfaceDefault">

        <Sequence/>

        <Aggregate Id="HoldLatchOpen">

            <While>
                <Universal:depth/>
                <Gt><Control:VerticalControl.surfaceThreshold/></Gt>
            </While>

            <!-- Power the DDM -->
            <ReadData>
                <Sensor:DDM.DDMMode/>
            </ReadData>

            <!-- Hold the DDM in DETACH mode (whiskers retracted, latch open) -->
            <Assign><Parallel/><Sensor:DDM.DDMModeCmd/><Arg Name="DetachModeDDM"/></Assign>

        </Aggregate>

        <!-- This mission assumes open water so from here on it's the same old default that's always used -->
        <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>

    </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-11-09T16:00:48.956Z,1604937648.956 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,DDM,Depth_Keller,DropWeight,DUSBL_Hydroid,Micromodem,NAL9602,PowerOnly,RDI_Pathfinder,RDI_PathfinderUp,BPC1,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,WorkSite,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2020-11-09T16:00:48.973Z,1604937648.973 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2020-11-09T16:00:49.005Z,1604937649.005 [DDM](INFO): Powering up
2020-11-09T16:00:49.005Z,1604937649.005 [DDM](DEBUG): Initializing DDM.
2020-11-09T16:00:49.031Z,1604937649.031 [DUSBL_Hydroid](INFO): Powering up
2020-11-09T16:00:49.031Z,1604937649.031 [DUSBL_Hydroid](DEBUG): Initializing DUSBL_Hydroid.
2020-11-09T16:00:49.271Z,1604937649.271 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2020-11-09T16:00:49.277Z,1604937649.277 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2020-11-09T16:00:49.278Z,1604937649.278 [ElevatorServo](DEBUG): Initializing EZServoServo.
2020-11-09T16:00:49.285Z,1604937649.285 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2020-11-09T16:00:49.286Z,1604937649.286 [MassServo](DEBUG): Initializing EZServoServo.
2020-11-09T16:00:49.293Z,1604937649.293 [MassServo](DEBUG): Initializing MassServo.
2020-11-09T16:00:49.294Z,1604937649.294 [RudderServo](DEBUG): Initializing EZServoServo.
2020-11-09T16:00:49.301Z,1604937649.301 [RudderServo](DEBUG): Initializing RudderServo.
2020-11-09T16:00:49.302Z,1604937649.302 [ThrusterServo](DEBUG): Initializing EZServoServo.
2020-11-09T16:00:49.309Z,1604937649.309 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2020-11-09T16:00:49.311Z,1604937649.311 [CommandLine](FAULT): Scheduling is paused
2020-11-09T16:00:49.311Z,1604937649.311 [CBIT](INFO): Critical error at 20201109T160048
2020-11-09T16:00:49.312Z,1604937649.312 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2020-11-09T16:00:49.381Z,1604937649.381 [Depth_Keller](ERROR): Pressure reading out of range: 1913.424561 decibar
2020-11-09T16:00:49.384Z,1604937649.384 [Micromodem](INFO): Powering up
2020-11-09T16:00:49.384Z,1604937649.384 [Micromodem](DEBUG): Initializing Micromodem.
2020-11-09T16:00:54.253Z,1604937654.253 [Micromodem](INFO): Nmea out: $CCCFG,ALL,0*33

2020-11-09T16:00:54.660Z,1604937654.660 [Micromodem](INFO): Nmea in: $CATMG,2020-11-09T16:00:54.271386Z,RTC,RTC*56

2020-11-09T16:00:54.660Z,1604937654.660 [Micromodem](ERROR): CFG response from modem unexpected: $CATMG,2020-11-09T16:00:54.271386Z,RTC,RTC*56

2020-11-09T16:00:55.063Z,1604937655.063 [Micromodem](INFO): Nmea in: $CACFG,ALL,0*31

2020-11-09T16:00:55.063Z,1604937655.063 [Micromodem](INFO): Nmea out: $CCCFG,SRC,1*31

2020-11-09T16:00:55.467Z,1604937655.467 [Micromodem](INFO): Nmea in: $CACFG,SRC,1*33

2020-11-09T16:00:55.467Z,1604937655.467 [Micromodem](INFO): Nmea out: $CCCFG,nav.dt.txtrig_gpio4,1*64

2020-11-09T16:00:55.875Z,1604937655.875 [Micromodem](INFO): Nmea in: $CACFG,nav.dt.txtrig_gpio4,1*66

2020-11-09T16:00:55.875Z,1604937655.875 [Micromodem](INFO): Nmea out: $CCCFG,pwramp.txlevel,0*2F

2020-11-09T16:00:56.069Z,1604937656.069 [MassServo](ERROR): getPosition uart error serial timeout
2020-11-09T16:00:56.070Z,1604937656.070 [MassServo](FAULT): Invalid EZ Servo response:"\r\376"
2020-11-09T16:00:56.070Z,1604937656.070 [MassServo] Communications Fault, FailCount= 1
2020-11-09T16:00:56.070Z,1604937656.070 [MassServo](ERROR): Communications Fault
2020-11-09T16:00:56.074Z,1604937656.074 [CBIT](ERROR): Communications Fault in component: MassServo
2020-11-09T16:00:56.279Z,1604937656.279 [Micromodem](INFO): Nmea in: $CACFG,pwramp.txlevel,0*2D

2020-11-09T16:00:56.279Z,1604937656.279 [Micromodem](INFO): Nmea out: $CCCFG,DTO,30*1E

2020-11-09T16:00:56.307Z,1604937656.307 [MassServo](DEBUG): Uninitialize Mass Servo.
2020-11-09T16:00:56.308Z,1604937656.308 [MassServo](INFO): Powering down
2020-11-09T16:00:56.683Z,1604937656.683 [Micromodem](INFO): Nmea in: $CACFG,DTO,30*1C

2020-11-09T16:00:56.683Z,1604937656.683 [Micromodem](INFO): Nmea out: $CCCFG,FC0,14500*47

2020-11-09T16:00:57.084Z,1604937657.084 [Micromodem](INFO): Nmea in: $CACFG,FC0,14500*45

2020-11-09T16:00:57.084Z,1604937657.084 [Micromodem](INFO): Nmea out: $CCCFG,BW0,4000*63

2020-11-09T16:00:57.168Z,1604937657.168 [MassServo](DEBUG): Initializing EZServoServo.
2020-11-09T16:00:57.286Z,1604937657.286 [MassServo](DEBUG): Initializing MassServo.
2020-11-09T16:00:57.290Z,1604937657.290 [CBIT](INFO): Clearing failed state for component MassServo
2020-11-09T16:00:57.290Z,1604937657.290 [MassServo] No Fault, FailCount= 1
2020-11-09T16:00:57.495Z,1604937657.495 [Micromodem](INFO): Nmea in: $CACFG,BW0,4000*61

2020-11-09T16:00:57.495Z,1604937657.495 [Micromodem](INFO): Nmea out: $CCCFG,BND,0*3A

2020-11-09T16:00:57.870Z,1604937657.870 [Micromodem](INFO): Nmea in: $CACFG,BND,0*38

2020-11-09T16:00:57.870Z,1604937657.870 [Micromodem](INFO): Nmea out: $CCCLK,2020,11,09,16,00,58*47

2020-11-09T16:00:58.268Z,1604937658.268 [Micromodem](INFO): Nmea in: $CACLK,2020,11,9,16,0,58*45

2020-11-09T16:00:58.269Z,1604937658.269 [Micromodem](INFO): Nmea in: $CATMS,0,2020-11-09T16:00:59Z*74

2020-11-09T16:00:58.271Z,1604937658.271 [Micromodem](INFO): Nmea in: $CATMG,2020-11-09T16:00:59.027507Z,USER_CMD,RTC*14

2020-11-09T16:01:04.722Z,1604937664.722 [DDM](INFO): Dynamic Docking Module:!C REMUS Capture Rev 1.1
2020-11-09T16:01:07.154Z,1604937667.154 [DUSBL_Hydroid](INFO): DUSBL Version:O
2020-11-09T16:01:15.231Z,1604937675.231 [NAL9602](INFO): Powering up NAL9602
2020-11-09T16:01:20.920Z,1604937680.920 [SBIT](IMPORTANT): Beginning Startup BIT
2020-11-09T16:01:20.928Z,1604937680.928 [CBIT](IMPORTANT): Beginning ground fault scan
2020-11-09T16:01:26.158Z,1604937686.158 [NAL9602](INFO): NAL9602 initialized
2020-11-09T16:01:31.920Z,1604937691.920 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): 0.003734
CHAN A1 (24V): -0.029593
CHAN A2 (12V): -0.007665
CHAN A3 (5V): -0.001886
CHAN B0 (3.3V): 0.000879
CHAN B1 (3.15aV): 0.000128
CHAN B2 (3.15bV): 0.000011
CHAN B3 (GND): 0.002183
OPEN: 0.005709
Full Scale Calc: 4.765 mA, -1.589 mA
2020-11-09T16:02:15.044Z,1604937735.044 [SBIT](IMPORTANT): SBIT PASSED
2020-11-09T16:02:15.044Z,1604937735.044 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2020-11-09T16:02:15.061Z,1604937735.061 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=200 milliliter;

2020-11-09T16:02:15.456Z,1604937735.456 [WorkSite](IMPORTANT): Reading workSite position from Data/workSite.cfg
2020-11-09T16:02:15.459Z,1604937735.459 [WorkSite](IMPORTANT): WorkSite fix at 20201109T160009: (41.552760, -70.709690)
2020-11-09T16:02:15.460Z,1604937735.460 [MissionManager](IMPORTANT): Started mission Startup
2020-11-09T16:02:15.477Z,1604937735.477 [Startup] Running Loop=1
2020-11-09T16:02:15.477Z,1604937735.477 [Startup](DEBUG): Aggregate::initialize Startup
2020-11-09T16:02:15.477Z,1604937735.477 [Startup:A.GoToSurface] Running Loop=1
2020-11-09T16:02:15.477Z,1604937735.477 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2020-11-09T16:02:15.478Z,1604937735.478 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2020-11-09T16:02:15.478Z,1604937735.478 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2020-11-09T16:02:15.478Z,1604937735.478 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2020-11-09T16:02:15.479Z,1604937735.479 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2020-11-09T16:02:15.479Z,1604937735.479 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2020-11-09T16:02:15.480Z,1604937735.480 [Startup:StartupSatComms] Running Loop=1
2020-11-09T16:02:15.480Z,1604937735.480 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2020-11-09T16:02:15.485Z,1604937735.485 [Startup:StartupSatComms:A] Running Loop=1
2020-11-09T16:02:15.861Z,1604937735.861 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2020-11-09T16:03:15.673Z,1604937795.673 [Startup:StartupSatComms:A](INFO): Timed out from 2020-11-09T16:02:15.5Z
2020-11-09T16:03:15.673Z,1604937795.673 [Startup:StartupSatComms:A] Stopped
2020-11-09T16:03:15.673Z,1604937795.673 [Startup:StartupSatComms:B] Running Loop=1
2020-11-09T16:03:16.043Z,1604937796.043 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2020-11-09T16:04:15.841Z,1604937855.841 [Startup:StartupSatComms:B](INFO): Timed out from 2020-11-09T16:03:15.7Z
2020-11-09T16:04:15.841Z,1604937855.841 [Startup:StartupSatComms:B] Stopped
2020-11-09T16:04:15.842Z,1604937855.842 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2020-11-09T16:04:15.842Z,1604937855.842 [Startup:StartupSatComms] Stopped
2020-11-09T16:04:15.842Z,1604937855.842 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2020-11-09T16:04:15.842Z,1604937855.842 [Startup](INFO): Completed Startup
2020-11-09T16:04:15.843Z,1604937855.843 [MissionManager](INFO): Startup is completed.
2020-11-09T16:04:15.843Z,1604937855.843 [MissionManager](INFO): Uninitializing Mission Startup
2020-11-09T16:04:15.843Z,1604937855.843 [Startup] Stopped
2020-11-09T16:04:15.843Z,1604937855.843 [Startup](DEBUG): Aggregate::uninitialize Startup
2020-11-09T16:04:15.843Z,1604937855.843 [Startup:A.GoToSurface] Stopped
2020-11-09T16:04:15.843Z,1604937855.843 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2020-11-09T16:04:16.348Z,1604937856.348 [MissionManager](IMPORTANT): Started mission DefaultWithUndock
2020-11-09T16:04:16.348Z,1604937856.348 [DefaultWithUndock] Running Loop=1
2020-11-09T16:04:16.348Z,1604937856.348 [DefaultWithUndock](DEBUG): Aggregate::initialize DefaultWithUndock
2020-11-09T16:04:16.348Z,1604937856.348 [DefaultWithUndock:A.Wait] Running Loop=1
2020-11-09T16:04:16.348Z,1604937856.348 [DefaultWithUndock:A.Wait](DEBUG): Initialize Wait Component.
2020-11-09T16:04:43.325Z,1604937883.325 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for BIT error
2020-11-09T16:04:46.559Z,1604937886.559 [DefaultWithUndock:A.Wait](INFO): Done Waiting.
2020-11-09T16:04:46.559Z,1604937886.559 [DefaultWithUndock:A.Wait] Stopped
2020-11-09T16:04:46.559Z,1604937886.559 [DefaultWithUndock:A.Wait](DEBUG): Uninitialize Wait Component.
2020-11-09T16:04:46.559Z,1604937886.559 [DefaultWithUndock:LeaveDock] Running Loop=1
2020-11-09T16:04:46.559Z,1604937886.559 [DefaultWithUndock:LeaveDock](DEBUG): Aggregate::initialize DefaultWithUndock:LeaveDock
2020-11-09T16:04:46.559Z,1604937886.559 [DefaultWithUndock:LeaveDock:A.] Running Loop=1
2020-11-09T16:04:46.559Z,1604937886.559 [DefaultWithUndock:LeaveDock:A.](INFO): Initializing TrackAcousticContact.
2020-11-09T16:04:46.560Z,1604937886.560 [DefaultWithUndock:LeaveDock:B.Undock] Running Loop=1
2020-11-09T16:04:46.560Z,1604937886.560 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Initialize.
2020-11-09T16:04:46.560Z,1604937886.560 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Initializing internal variables to default values.
2020-11-09T16:04:46.965Z,1604937886.965 [DefaultWithUndock:LeaveDock:A.] Running Loop=1
2020-11-09T16:04:47.336Z,1604937887.336 [PowerOnly](INFO): Powering up loadControl
2020-11-09T16:04:49.442Z,1604937889.442 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact ***
2020-11-09T16:04:50.220Z,1604937890.220 [Micromodem](INFO): Nmea out: $CCPGT,1,14500,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*76

2020-11-09T16:04:50.378Z,1604937890.378 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Detaching from dock.
2020-11-09T16:04:50.601Z,1604937890.601 [Micromodem](INFO): Nmea in: $SNPGT,1,14500,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*6B

2020-11-09T16:04:50.691Z,1604937890.691 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Detected possible detachment. Starting timer.
2020-11-09T16:04:51.414Z,1604937891.414 [Micromodem](INFO): Nmea in: $SNTTA,,,,,160451.31*5B

2020-11-09T16:04:52.367Z,1604937892.367 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact ***
2020-11-09T16:04:53.838Z,1604937893.838 [DUSBL_Hydroid](ERROR): No response from remote modem.
2020-11-09T16:04:55.063Z,1604937895.063 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact ***
2020-11-09T16:04:55.859Z,1604937895.859 [Micromodem](INFO): Nmea out: $CCPGT,1,14500,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*76

2020-11-09T16:04:56.261Z,1604937896.261 [Micromodem](INFO): Nmea in: $SNPGT,1,14500,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*6B

2020-11-09T16:04:57.083Z,1604937897.083 [Micromodem](INFO): Nmea in: $SNTTA,,,,,160456.95*52

2020-11-09T16:04:57.893Z,1604937897.893 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact ***
2020-11-09T16:04:59.495Z,1604937899.495 [DUSBL_Hydroid](ERROR): No response from remote modem.
2020-11-09T16:05:00.734Z,1604937900.734 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact ***
2020-11-09T16:05:01.549Z,1604937901.549 [Micromodem](INFO): Nmea out: $CCPGT,1,14500,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*76

2020-11-09T16:05:01.913Z,1604937901.913 [Micromodem](INFO): Nmea in: $SNPGT,1,14500,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*6B

2020-11-09T16:05:02.733Z,1604937902.733 [Micromodem](INFO): Nmea in: $SNTTA,,,,,160502.64*5C

2020-11-09T16:05:03.680Z,1604937903.680 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact ***
2020-11-09T16:05:05.165Z,1604937905.165 [DUSBL_Hydroid](ERROR): No response from remote modem.
2020-11-09T16:05:06.408Z,1604937906.408 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact ***
2020-11-09T16:05:07.190Z,1604937907.190 [Micromodem](INFO): Nmea out: $CCPGT,1,14500,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*76

2020-11-09T16:05:07.581Z,1604937907.581 [Micromodem](INFO): Nmea in: $SNPGT,1,14500,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*6B

2020-11-09T16:05:08.371Z,1604937908.371 [Micromodem](INFO): Nmea in: $SNTTA,,,,,160508.28*5E

2020-11-09T16:05:09.221Z,1604937909.221 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact ***
2020-11-09T16:05:10.806Z,1604937910.806 [DUSBL_Hydroid](ERROR): No response from remote modem.
2020-11-09T16:05:10.839Z,1604937910.839 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Detached at range: nan m. Transitioning DDM to standby.
2020-11-09T16:05:12.023Z,1604937912.023 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact ***
2020-11-09T16:05:12.823Z,1604937912.823 [Micromodem](INFO): Nmea out: $CCPGT,1,14500,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*76

2020-11-09T16:05:13.241Z,1604937913.241 [Micromodem](INFO): Nmea in: $SNPGT,1,14500,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*6B

2020-11-09T16:05:13.691Z,1604937913.691 [DefaultWithUndock:LeaveDock:B.Undock](INFO): DDM at standby.
2020-11-09T16:05:14.050Z,1604937914.050 [Micromodem](INFO): Nmea in: $SNTTA,,,,,160513.92*55

2020-11-09T16:05:14.128Z,1604937914.128 [DefaultWithUndock:LeaveDock:B.Undock](IMPORTANT): Undocking sequence complete.
2020-11-09T16:05:14.128Z,1604937914.128 [DefaultWithUndock:LeaveDock:B.Undock] Stopped
2020-11-09T16:05:14.128Z,1604937914.128 [DefaultWithUndock:LeaveDock](INFO): Completed DefaultWithUndock:LeaveDock
2020-11-09T16:05:14.128Z,1604937914.128 [DefaultWithUndock:LeaveDock] Stopped
2020-11-09T16:05:14.133Z,1604937914.133 [DefaultWithUndock:LeaveDock](DEBUG): Aggregate::uninitialize DefaultWithUndock:LeaveDock
2020-11-09T16:05:14.133Z,1604937914.133 [DefaultWithUndock:LeaveDock:A.] Stopped
2020-11-09T16:05:14.134Z,1604937914.134 [DefaultWithUndock:SurfaceDefault] Running Loop=1
2020-11-09T16:05:14.134Z,1604937914.134 [DefaultWithUndock:SurfaceDefault](DEBUG): Aggregate::initialize DefaultWithUndock:SurfaceDefault
2020-11-09T16:05:14.134Z,1604937914.134 [DefaultWithUndock:SurfaceDefault:HoldLatchOpen] Running Loop=1
2020-11-09T16:05:14.135Z,1604937914.135 [DefaultWithUndock:SurfaceDefault:HoldLatchOpen](DEBUG): Aggregate::initialize DefaultWithUndock:SurfaceDefault:HoldLatchOpen
2020-11-09T16:05:14.135Z,1604937914.135 [DefaultWithUndock:SurfaceDefault:HoldLatchOpen:A] Running Loop=1
2020-11-09T16:05:14.135Z,1604937914.135 [DefaultWithUndock:SurfaceDefault:HoldLatchOpen:B] Running Loop=1
2020-11-09T16:05:14.135Z,1604937914.135 [DefaultWithUndock:SurfaceDefault:B.GoToSurface] Running Loop=1
2020-11-09T16:05:14.136Z,1604937914.136 [DefaultWithUndock:SurfaceDefault:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2020-11-09T16:05:14.141Z,1604937914.141 [DefaultWithUndock:SurfaceDefault:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2020-11-09T16:05:14.141Z,1604937914.141 [DefaultWithUndock:SurfaceDefault:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2020-11-09T16:05:14.141Z,1604937914.141 [DefaultWithUndock:SurfaceDefault:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2020-11-09T16:05:14.142Z,1604937914.142 [DefaultWithUndock:SurfaceDefault:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2020-11-09T16:05:14.142Z,1604937914.142 [DefaultWithUndock:SurfaceDefault:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2020-11-09T16:05:14.449Z,1604937914.449 [DefaultWithUndock:SurfaceDefault:CheckIn] Running Loop=1
2020-11-09T16:05:14.449Z,1604937914.449 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::initialize DefaultWithUndock:SurfaceDefault:CheckIn
2020-11-09T16:05:14.449Z,1604937914.449 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Running Loop=1
2020-11-09T16:05:14.449Z,1604937914.449 [DefaultWithUndock:SurfaceDefault:HoldLatchOpen] Stopped
2020-11-09T16:05:14.449Z,1604937914.449 [DefaultWithUndock:SurfaceDefault:HoldLatchOpen](DEBUG): Aggregate::uninitialize DefaultWithUndock:SurfaceDefault:HoldLatchOpen
2020-11-09T16:05:14.449Z,1604937914.449 [DefaultWithUndock:SurfaceDefault:HoldLatchOpen:A] Stopped
2020-11-09T16:05:14.449Z,1604937914.449 [DefaultWithUndock:SurfaceDefault:HoldLatchOpen:B] Stopped
2020-11-09T16:05:14.865Z,1604937914.865 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2020-11-09T16:06:18.644Z,1604937978.644 [PowerOnly](INFO): Powering down loadControl
2020-11-09T16:06:29.951Z,1604937989.951 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-11-09T16:09:20.071Z,1604938160.071 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2020-11-09T16:09:20.074Z,1604938160.074 [BPC1](INFO): Received data from all battery sticks.
2020-11-09T16:10:14.583Z,1604938214.583 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS](INFO): Timed out from 2020-11-09T16:05:14.4Z
2020-11-09T16:10:14.583Z,1604938214.583 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Stopped
2020-11-09T16:10:14.583Z,1604938214.583 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Running Loop=1
2020-11-09T16:10:15.009Z,1604938215.009 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2020-11-09T16:10:46.109Z,1604938246.109 [NAL9602](ERROR): Queried for signal strength and failed to receive proper response. 
2020-11-09T16:10:46.193Z,1604938246.193 [NAL9602](ERROR): received: 
+CSQ:0

OK
2020-11-09T16:10:46.193Z,1604938246.193 [NAL9602] Data Fault, FailCount= 1
2020-11-09T16:10:46.193Z,1604938246.193 [NAL9602](ERROR): Data Fault
2020-11-09T16:10:46.231Z,1604938246.231 [CBIT](ERROR): Data Fault in component: NAL9602
2020-11-09T16:10:46.491Z,1604938246.491 [NAL9602](INFO): Powering down
2020-11-09T16:10:47.361Z,1604938247.361 [CBIT](INFO): Clearing failed state for component NAL9602
2020-11-09T16:10:47.361Z,1604938247.361 [NAL9602] No Fault, FailCount= 1
2020-11-09T16:10:49.843Z,1604938249.843 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004643
2020-11-09T16:10:53.856Z,1604938253.856 [DataOverHttps](INFO): Sending 52 bytes from file Logs/20201109T154630/Courier0007.lzma
2020-11-09T16:10:54.859Z,1604938254.859 [DataOverHttps](INFO): Moved sent file to Logs/20201109T154630/Courier0007.lzma.bak
2020-11-09T16:10:54.859Z,1604938254.859 [DataOverHttps](INFO): SBD MOMSN=54934
2020-11-09T16:11:03.899Z,1604938263.899 [DataOverHttps](INFO): Sending 319 bytes from file Logs/20201109T160038/Courier0000.lzma
2020-11-09T16:11:04.899Z,1604938264.899 [DataOverHttps](INFO): Moved sent file to Logs/20201109T160038/Courier0000.lzma.bak
2020-11-09T16:11:04.899Z,1604938264.899 [DataOverHttps](INFO): SBD MOMSN=54936
2020-11-09T16:11:13.952Z,1604938273.952 [DataOverHttps](INFO): Sending 180 bytes from file Logs/20201109T160038/Courier0004.lzma
2020-11-09T16:11:14.955Z,1604938274.955 [DataOverHttps](INFO): Moved sent file to Logs/20201109T160038/Courier0004.lzma.bak
2020-11-09T16:11:14.955Z,1604938274.955 [DataOverHttps](INFO): SBD MOMSN=54941
2020-11-09T16:11:16.791Z,1604938276.791 [NAL9602](INFO): Powering up NAL9602
2020-11-09T16:11:23.992Z,1604938283.992 [DataOverHttps](INFO): Sending 161 bytes from file Logs/20201109T154630/Express0008.lzma
2020-11-09T16:11:24.995Z,1604938284.995 [DataOverHttps](INFO): Moved sent file to Logs/20201109T154630/Express0008.lzma.bak
2020-11-09T16:11:24.995Z,1604938284.995 [DataOverHttps](INFO): SBD MOMSN=54943
2020-11-09T16:11:27.703Z,1604938287.703 [NAL9602](INFO): NAL9602 initialized
2020-11-09T16:11:34.034Z,1604938294.034 [DataOverHttps](INFO): Sending 824 bytes from file Logs/20201109T160038/Express0001.lzma
2020-11-09T16:11:35.035Z,1604938295.035 [DataOverHttps](INFO): Moved sent file to Logs/20201109T160038/Express0001.lzma.bak
2020-11-09T16:11:35.035Z,1604938295.035 [DataOverHttps](INFO): SBD MOMSN=54950
2020-11-09T16:11:44.076Z,1604938304.076 [DataOverHttps](INFO): Sending 257 bytes from file Logs/20201109T160038/Express0005.lzma
2020-11-09T16:11:45.075Z,1604938305.075 [DataOverHttps](INFO): Moved sent file to Logs/20201109T160038/Express0005.lzma.bak
2020-11-09T16:11:45.075Z,1604938305.075 [DataOverHttps](INFO): SBD MOMSN=54966
2020-11-09T16:11:46.377Z,1604938306.377 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Stopped
2020-11-09T16:11:46.377Z,1604938306.377 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait] Running Loop=1
2020-11-09T16:11:46.377Z,1604938306.377 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-11-09T16:11:58.811Z,1604938318.811 [NAL9602](INFO): Not Powering down - fast GPS
2020-11-09T16:14:34.368Z,1604938474.368 [RDI_PathfinderUp](ERROR): only read 3 of 4 data items
2020-11-09T16:14:44.471Z,1604938484.471 [RDI_PathfinderUp](ERROR): only read 3 of 4 data items
2020-11-09T16:15:54.345Z,1604938554.345 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2020-11-09T16:16:46.873Z,1604938606.873 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](INFO): Done Waiting.
2020-11-09T16:16:46.873Z,1604938606.873 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait] Stopped
2020-11-09T16:16:46.873Z,1604938606.873 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-11-09T16:16:46.873Z,1604938606.873 [DefaultWithUndock:SurfaceDefault:CheckIn:D] Running Loop=1
2020-11-09T16:16:47.293Z,1604938607.293 [DefaultWithUndock:SurfaceDefault:CheckIn:D] Stopped
2020-11-09T16:16:47.293Z,1604938607.293 [DefaultWithUndock:SurfaceDefault:CheckIn:E] Running Loop=1
2020-11-09T16:16:47.689Z,1604938607.689 [DefaultWithUndock:SurfaceDefault:CheckIn:E](IMPORTANT): Default mission has been running for 12.515750 min 
2020-11-09T16:16:47.689Z,1604938607.689 [DefaultWithUndock:SurfaceDefault:CheckIn:E] Stopped
2020-11-09T16:16:47.690Z,1604938607.690 [DefaultWithUndock:SurfaceDefault:CheckIn](INFO): Completed DefaultWithUndock:SurfaceDefault:CheckIn
2020-11-09T16:16:47.690Z,1604938607.690 [DefaultWithUndock:SurfaceDefault:CheckIn] Stopped
2020-11-09T16:16:47.690Z,1604938607.690 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::uninitialize DefaultWithUndock:SurfaceDefault:CheckIn
2020-11-09T16:16:47.690Z,1604938607.690 [DefaultWithUndock:SurfaceDefault:CheckIn](INFO): Running loop #2
2020-11-09T16:16:47.690Z,1604938607.690 [DefaultWithUndock:SurfaceDefault:CheckIn] Running Loop=2
2020-11-09T16:16:47.690Z,1604938607.690 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::initialize DefaultWithUndock:SurfaceDefault:CheckIn
2020-11-09T16:16:47.690Z,1604938607.690 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Running Loop=1
2020-11-09T16:16:49.306Z,1604938609.306 [NAL9602](FAULT): GPS failed to acquire within timeout.
2020-11-09T16:16:49.306Z,1604938609.306 [NAL9602] Data Fault, FailCount= 1
2020-11-09T16:16:49.307Z,1604938609.307 [NAL9602](ERROR): Data Fault
2020-11-09T16:16:49.389Z,1604938609.389 [CBIT](ERROR): Data Fault in component: NAL9602
2020-11-09T16:16:49.691Z,1604938609.691 [NAL9602](INFO): Powering down
2020-11-09T16:16:50.580Z,1604938610.580 [CBIT](INFO): Clearing failed state for component NAL9602
2020-11-09T16:16:50.580Z,1604938610.580 [NAL9602] No Fault, FailCount= 1
2020-11-09T16:17:19.991Z,1604938639.991 [NAL9602](INFO): Powering up NAL9602
2020-11-09T16:17:30.899Z,1604938650.899 [NAL9602](INFO): NAL9602 initialized
2020-11-09T16:17:39.407Z,1604938659.407 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for BIT error
2020-11-09T16:17:59.594Z,1604938679.594 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for BIT error
2020-11-09T16:18:29.496Z,1604938709.496 [RDI_PathfinderUp](ERROR): only read 2 of 4 data items
2020-11-09T16:19:39.430Z,1604938779.430 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude
2020-11-09T16:21:47.877Z,1604938907.877 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS](INFO): Timed out from 2020-11-09T16:16:47.7Z
2020-11-09T16:21:47.877Z,1604938907.877 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Stopped
2020-11-09T16:21:47.878Z,1604938907.878 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Running Loop=1
2020-11-09T16:21:51.596Z,1604938911.596 [DataOverHttps](INFO): Sending 52 bytes from file Logs/20201109T160038/Courier0007.lzma
2020-11-09T16:21:52.598Z,1604938912.598 [DataOverHttps](INFO): Moved sent file to Logs/20201109T160038/Courier0007.lzma.bak
2020-11-09T16:21:52.599Z,1604938912.599 [DataOverHttps](INFO): SBD MOMSN=54971
2020-11-09T16:22:01.637Z,1604938921.637 [DataOverHttps](INFO): Sending 212 bytes from file Logs/20201109T160038/Express0008.lzma
2020-11-09T16:22:02.639Z,1604938922.639 [DataOverHttps](INFO): Moved sent file to Logs/20201109T160038/Express0008.lzma.bak
2020-11-09T16:22:02.639Z,1604938922.639 [DataOverHttps](INFO): SBD MOMSN=54973
2020-11-09T16:22:03.689Z,1604938923.689 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Stopped
2020-11-09T16:22:03.689Z,1604938923.689 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait] Running Loop=1
2020-11-09T16:22:03.689Z,1604938923.689 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-11-09T16:22:34.776Z,1604938954.776 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-11-09T16:23:03.463Z,1604938983.463 [RDI_Pathfinder](ERROR): No DVL communication! Re-initializing
2020-11-09T16:23:03.463Z,1604938983.463 [RDI_Pathfinder] Communications Fault, FailCount= 1
2020-11-09T16:23:03.464Z,1604938983.464 [RDI_Pathfinder](ERROR): Communications Fault
2020-11-09T16:23:03.528Z,1604938983.528 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder
2020-11-09T16:23:03.753Z,1604938983.753 [CommandLine](IMPORTANT): got command restart system
2020-11-09T16:23:03.937Z,1604938983.937 [RDI_Pathfinder](INFO): Powering down
2020-11-09T16:23:04.716Z,1604938984.716 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2020-11-09T16:23:04.716Z,1604938984.716 [RDI_Pathfinder] No Fault, FailCount= 1
2020-11-09T16:23:05.490Z,1604938985.490 [NAL9602](INFO): Not Powering down - fast GPS
2020-11-09T16:23:05.813Z,1604938985.813 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2020-11-09T16:23:05.813Z,1604938985.813 [CommandLine ThreadHandler](INFO): Thread cancelled.
2020-11-09T16:23:05.921Z,1604938985.921 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2020-11-09T16:23:05.921Z,1604938985.921 [CommandLine ThreadHandler](INFO): Thread cancelled.
2020-11-09T16:23:05.922Z,1604938985.922 [CommandLine](INFO): Join timeout helper Thread ID is 6180
2020-11-09T16:23:05.922Z,1604938985.922 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2020-11-09T16:23:05.922Z,1604938985.922 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2020-11-09T16:23:05.923Z,1604938985.923 [NavChartDb](INFO): Join timeout helper Thread ID is 6181
2020-11-09T16:23:06.025Z,1604938986.025 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2020-11-09T16:23:06.025Z,1604938986.025 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2020-11-09T16:23:06.041Z,1604938986.041 [ComponentRegistry](INFO): Shutting down WetLabsSeaOWL_UV_A ThreadHandler
2020-11-09T16:23:06.041Z,1604938986.041 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2020-11-09T16:23:06.041Z,1604938986.041 [WetLabsSeaOWL_UV_A](INFO): Join timeout helper Thread ID is 6182
2020-11-09T16:23:06.106Z,1604938986.106 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Uninitializing protected caller thread.
2020-11-09T16:23:06.106Z,1604938986.106 [WetLabsSeaOWL_UV_A](INFO): Powering down
2020-11-09T16:23:06.109Z,1604938986.109 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2020-11-09T16:23:06.121Z,1604938986.121 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2020-11-09T16:23:06.121Z,1604938986.121 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2020-11-09T16:23:06.121Z,1604938986.121 [CTD_Seabird](INFO): Join timeout helper Thread ID is 6183
2020-11-09T16:23:06.901Z,1604938986.901 [CTD_Seabird](INFO): Powering down
2020-11-09T16:23:06.913Z,1604938986.913 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2020-11-09T16:23:06.913Z,1604938986.913 [CTD_Seabird](INFO): Powering down
2020-11-09T16:23:06.925Z,1604938986.925 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2020-11-09T16:23:06.939Z,1604938986.939 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2020-11-09T16:23:06.939Z,1604938986.939 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2020-11-09T16:23:06.939Z,1604938986.939 [Radio_Surface](INFO): Join timeout helper Thread ID is 6184
2020-11-09T16:23:07.265Z,1604938987.265 [Radio_Surface](INFO): Powering down
2020-11-09T16:23:07.266Z,1604938987.266 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2020-11-09T16:23:07.266Z,1604938987.266 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2020-11-09T16:23:07.278Z,1604938987.278 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler
2020-11-09T16:23:07.278Z,1604938987.278 [Onboard ThreadHandler](INFO): Thread cancelled.
2020-11-09T16:23:07.278Z,1604938987.278 [Onboard](INFO): Join timeout helper Thread ID is 6185
2020-11-09T16:23:07.897Z,1604938987.897 [DataOverHttps](INFO): Ra