2020-09-29T19:31:46.312Z,1601407906.312 [Supervisor](DEBUG): Initializing supervisor.
2020-09-29T19:31:46.315Z,1601407906.315 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2020-09-29T19:31:46.315Z,1601407906.315 [SyncHandler](INFO): Protected caller Thread ID is 1981
2020-09-29T19:31:46.316Z,1601407906.316 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2020-09-29T19:31:46.317Z,1601407906.317 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2020-09-29T19:31:46.317Z,1601407906.317 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 1982
2020-09-29T19:31:46.320Z,1601407906.320 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2020-09-29T19:31:46.334Z,1601407906.334 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2020-09-29T19:31:46.335Z,1601407906.335 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2020-09-29T19:31:46.335Z,1601407906.335 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 1983
2020-09-29T19:31:46.336Z,1601407906.336 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2020-09-29T19:31:46.337Z,1601407906.337 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2020-09-29T19:31:46.337Z,1601407906.337 [logger ThreadHandler](INFO): Protected caller Thread ID is 1984
2020-09-29T19:31:46.339Z,1601407906.339 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2020-09-29T19:31:46.340Z,1601407906.340 [Supervisor](INFO): Looking for Config files in directory: Config/
2020-09-29T19:31:46.341Z,1601407906.341 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2020-09-29T19:31:46.801Z,1601407906.801 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2020-09-29T19:31:46.802Z,1601407906.802 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2020-09-29T19:31:46.902Z,1601407906.902 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2020-09-29T19:31:46.902Z,1601407906.902 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2020-09-29T19:31:47.235Z,1601407907.235 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2020-09-29T19:31:47.235Z,1601407907.235 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2020-09-29T19:31:47.416Z,1601407907.416 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2020-09-29T19:31:47.416Z,1601407907.416 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2020-09-29T19:31:47.752Z,1601407907.752 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2020-09-29T19:31:47.753Z,1601407907.753 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2020-09-29T19:31:48.229Z,1601407908.229 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2020-09-29T19:31:48.230Z,1601407908.230 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2020-09-29T19:31:48.450Z,1601407908.450 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2020-09-29T19:31:48.450Z,1601407908.450 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2020-09-29T19:31:48.600Z,1601407908.600 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2020-09-29T19:31:48.601Z,1601407908.601 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2020-09-29T19:31:48.803Z,1601407908.803 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2020-09-29T19:31:48.803Z,1601407908.803 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2020-09-29T19:31:48.903Z,1601407908.903 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2020-09-29T19:31:48.903Z,1601407908.903 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2020-09-29T19:31:49.110Z,1601407909.110 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2020-09-29T19:31:49.110Z,1601407909.110 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2020-09-29T19:31:49.425Z,1601407909.425 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2020-09-29T19:31:49.426Z,1601407909.426 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2020-09-29T19:31:49.509Z,1601407909.509 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2020-09-29T19:31:49.616Z,1601407909.616 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2020-09-29T19:31:49.616Z,1601407909.616 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2020-09-29T19:31:50.306Z,1601407910.306 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2020-09-29T19:31:50.306Z,1601407910.306 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2020-09-29T19:31:50.738Z,1601407910.738 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2020-09-29T19:31:50.740Z,1601407910.740 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/
2020-09-29T19:31:50.741Z,1601407910.741 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/vehicle.cfg
2020-09-29T19:31:50.955Z,1601407910.955 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Control.cfg
2020-09-29T19:31:51.057Z,1601407911.057 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/BIT.cfg
2020-09-29T19:31:51.158Z,1601407911.158 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Battery.cfg
2020-09-29T19:31:51.394Z,1601407911.394 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2020-09-29T19:31:51.394Z,1601407911.394 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Simulator.cfg
2020-09-29T19:31:51.482Z,1601407911.482 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Navigation.cfg
2020-09-29T19:31:51.580Z,1601407911.580 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/logger.cfg
2020-09-29T19:31:51.691Z,1601407911.691 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/secure.cfg
2020-09-29T19:31:51.778Z,1601407911.778 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Dock.cfg
2020-09-29T19:31:51.866Z,1601407911.866 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Servo.cfg
2020-09-29T19:31:51.980Z,1601407911.980 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/workSite.cfg
2020-09-29T19:31:52.076Z,1601407912.076 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Sensor.cfg
2020-09-29T19:31:52.273Z,1601407912.273 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Science.cfg
2020-09-29T19:31:52.427Z,1601407912.427 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2020-09-29T19:31:52.435Z,1601407912.435 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2020-09-29T19:31:53.592Z,1601407913.592 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_orientation
2020-09-29T19:31:53.597Z,1601407913.597 [AHRS_M2](INFO): created writer for : platform_orientation
2020-09-29T19:31:53.599Z,1601407913.599 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_magnetic_orientation
2020-09-29T19:31:53.604Z,1601407913.604 [AHRS_M2](INFO): created writer for : platform_magnetic_orientation
2020-09-29T19:31:53.605Z,1601407913.605 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_pitch_angle
2020-09-29T19:31:53.610Z,1601407913.610 [AHRS_M2](INFO): created writer for : platform_pitch_angle
2020-09-29T19:31:53.611Z,1601407913.611 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_roll_angle
2020-09-29T19:31:53.616Z,1601407913.616 [AHRS_M2](INFO): created writer for : platform_roll_angle
2020-09-29T19:31:53.694Z,1601407913.694 [AHRS_M2] Loaded
2020-09-29T19:31:53.695Z,1601407913.695 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2020-09-29T19:31:53.772Z,1601407913.772 [DataOverHttps] Loaded
2020-09-29T19:31:53.772Z,1601407913.772 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2020-09-29T19:31:53.773Z,1601407913.773 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4077A4E0
2020-09-29T19:31:53.773Z,1601407913.773 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 2072
2020-09-29T19:31:53.807Z,1601407913.807 [DDM] Loaded
2020-09-29T19:31:53.808Z,1601407913.808 [ComponentRegistry](DEBUG): SyncComponent "DDM" handled in the control thread.
2020-09-29T19:31:53.839Z,1601407913.839 [Depth_Keller] Loaded
2020-09-29T19:31:53.839Z,1601407913.839 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2020-09-29T19:31:53.920Z,1601407913.920 [DUSBL_Hydroid] Loaded
2020-09-29T19:31:53.920Z,1601407913.920 [ComponentRegistry](DEBUG): SyncComponent "DUSBL_Hydroid" handled in the control thread.
2020-09-29T19:31:53.987Z,1601407913.987 [Micromodem] Loaded
2020-09-29T19:31:53.987Z,1601407913.987 [ComponentRegistry](DEBUG): SyncComponent "Micromodem" handled in the control thread.
2020-09-29T19:31:54.105Z,1601407914.105 [NAL9602] Loaded
2020-09-29T19:31:54.105Z,1601407914.105 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2020-09-29T19:31:54.154Z,1601407914.154 [Onboard] Loaded
2020-09-29T19:31:54.155Z,1601407914.155 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2020-09-29T19:31:54.156Z,1601407914.156 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 407AA4E0
2020-09-29T19:31:54.156Z,1601407914.156 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 2073
2020-09-29T19:31:54.162Z,1601407914.162 [PowerOnly](INFO): Adding load control power supply at /dev/loadC1
2020-09-29T19:31:54.184Z,1601407914.184 [PowerOnly] Loaded
2020-09-29T19:31:54.185Z,1601407914.185 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread.
2020-09-29T19:31:54.208Z,1601407914.208 [Radio_Surface] Loaded
2020-09-29T19:31:54.208Z,1601407914.208 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2020-09-29T19:31:54.209Z,1601407914.209 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 407DA4E0
2020-09-29T19:31:54.209Z,1601407914.209 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 2074
2020-09-29T19:31:54.271Z,1601407914.271 [RDI_Pathfinder] Loaded
2020-09-29T19:31:54.272Z,1601407914.272 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread.
2020-09-29T19:31:54.326Z,1601407914.326 [RDI_PathfinderUp] Loaded
2020-09-29T19:31:54.326Z,1601407914.326 [ComponentRegistry](DEBUG): SyncComponent "RDI_PathfinderUp" handled in the control thread.
2020-09-29T19:31:55.882Z,1601407915.882 [BPC1] Loaded
2020-09-29T19:31:55.883Z,1601407915.883 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2020-09-29T19:31:55.883Z,1601407915.883 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2020-09-29T19:31:55.884Z,1601407915.884 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2020-09-29T19:31:55.903Z,1601407915.903 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2020-09-29T19:31:55.903Z,1601407915.903 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2020-09-29T19:31:56.028Z,1601407916.028 [DeadReckonUsingMultipleVelocitySources] Loaded
2020-09-29T19:31:56.028Z,1601407916.028 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2020-09-29T19:31:56.049Z,1601407916.049 [NavChart] Loaded
2020-09-29T19:31:56.049Z,1601407916.049 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2020-09-29T19:31:56.053Z,1601407916.053 [UniversalFixResidualReporter] Loaded
2020-09-29T19:31:56.053Z,1601407916.053 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2020-09-29T19:31:56.071Z,1601407916.071 [WorkSite] Loaded
2020-09-29T19:31:56.072Z,1601407916.072 [ComponentRegistry](DEBUG): SyncComponent "WorkSite" handled in the control thread.
2020-09-29T19:31:56.072Z,1601407916.072 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2020-09-29T19:31:56.072Z,1601407916.072 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2020-09-29T19:31:56.156Z,1601407916.156 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2020-09-29T19:31:56.157Z,1601407916.157 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2020-09-29T19:31:56.292Z,1601407916.292 [BuoyancyServo] Loaded
2020-09-29T19:31:56.292Z,1601407916.292 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2020-09-29T19:31:56.325Z,1601407916.325 [ElevatorServo] Loaded
2020-09-29T19:31:56.326Z,1601407916.326 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2020-09-29T19:31:56.358Z,1601407916.358 [MassServo] Loaded
2020-09-29T19:31:56.358Z,1601407916.358 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2020-09-29T19:31:56.390Z,1601407916.390 [RudderServo] Loaded
2020-09-29T19:31:56.390Z,1601407916.390 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2020-09-29T19:31:56.422Z,1601407916.422 [ThrusterServo] Loaded
2020-09-29T19:31:56.422Z,1601407916.422 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2020-09-29T19:31:56.422Z,1601407916.422 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2020-09-29T19:31:56.423Z,1601407916.423 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2020-09-29T19:31:56.644Z,1601407916.644 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_density
2020-09-29T19:31:56.649Z,1601407916.649 [CTD_Seabird](INFO): created writer for : sea_water_density
2020-09-29T19:31:56.650Z,1601407916.650 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): depth
2020-09-29T19:31:56.655Z,1601407916.655 [CTD_Seabird](INFO): created writer for : depth
2020-09-29T19:31:56.655Z,1601407916.655 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_pressure
2020-09-29T19:31:56.660Z,1601407916.660 [CTD_Seabird](INFO): created writer for : sea_water_pressure
2020-09-29T19:31:56.661Z,1601407916.661 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_salinity
2020-09-29T19:31:56.666Z,1601407916.666 [CTD_Seabird](INFO): created writer for : sea_water_salinity
2020-09-29T19:31:56.667Z,1601407916.667 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_temperature
2020-09-29T19:31:56.672Z,1601407916.672 [CTD_Seabird](INFO): created writer for : sea_water_temperature
2020-09-29T19:31:56.673Z,1601407916.673 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_electrical_conductivity
2020-09-29T19:31:56.679Z,1601407916.679 [CTD_Seabird](INFO): created writer for : sea_water_electrical_conductivity
2020-09-29T19:31:56.679Z,1601407916.679 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): speed_of_sound_in_sea_water
2020-09-29T19:31:56.685Z,1601407916.685 [CTD_Seabird](INFO): created writer for : speed_of_sound_in_sea_water
2020-09-29T19:31:56.685Z,1601407916.685 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): mass_concentration_of_oxygen_in_sea_water
2020-09-29T19:31:56.691Z,1601407916.691 [CTD_Seabird](INFO): created writer for : mass_concentration_of_oxygen_in_sea_water
2020-09-29T19:31:56.691Z,1601407916.691 [CTD_Seabird](DEBUG): LcmSlateWriter::add(DAtaURI): CTD_Seabird.sea_water_dissolved_oxygen_freq
2020-09-29T19:31:56.691Z,1601407916.691 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): dataName: sea_water_dissolved_oxygen_freq
2020-09-29T19:31:56.725Z,1601407916.725 [CTD_Seabird] Loaded
2020-09-29T19:31:56.725Z,1601407916.725 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2020-09-29T19:31:56.726Z,1601407916.726 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 4095E4E0
2020-09-29T19:31:56.727Z,1601407916.727 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 2075
2020-09-29T19:31:56.759Z,1601407916.759 [PAR_Licor] Loaded
2020-09-29T19:31:56.759Z,1601407916.759 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2020-09-29T19:31:56.820Z,1601407916.820 [WetLabsSeaOWL_UV_A] Loaded
2020-09-29T19:31:56.820Z,1601407916.820 [ComponentRegistry](DEBUG): Component "WetLabsSeaOWL_UV_A" handled in its own thread.
2020-09-29T19:31:56.821Z,1601407916.821 [WetLabsSeaOWL_UV_A ThreadHandler](DEBUG): Created PCaller Thread at 4098E4E0
2020-09-29T19:31:56.822Z,1601407916.822 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Protected caller Thread ID is 2076
2020-09-29T19:31:56.822Z,1601407916.822 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2020-09-29T19:31:56.823Z,1601407916.823 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2020-09-29T19:31:57.141Z,1601407917.141 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2020-09-29T19:31:57.142Z,1601407917.142 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2020-09-29T19:31:57.185Z,1601407917.185 [DepthRateCalculator] Loaded
2020-09-29T19:31:57.185Z,1601407917.185 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2020-09-29T19:31:57.191Z,1601407917.191 [PitchRateCalculator] Loaded
2020-09-29T19:31:57.191Z,1601407917.191 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2020-09-29T19:31:57.204Z,1601407917.204 [SpeedCalculator] Loaded
2020-09-29T19:31:57.204Z,1601407917.204 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2020-09-29T19:31:57.226Z,1601407917.226 [TempGradientCalculator] Loaded
2020-09-29T19:31:57.226Z,1601407917.226 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2020-09-29T19:31:57.232Z,1601407917.232 [YawRateCalculator] Loaded
2020-09-29T19:31:57.232Z,1601407917.232 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2020-09-29T19:31:57.273Z,1601407917.273 [ElevatorOffsetCalculator] Loaded
2020-09-29T19:31:57.274Z,1601407917.274 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2020-09-29T19:31:57.274Z,1601407917.274 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2020-09-29T19:31:57.275Z,1601407917.275 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2020-09-29T19:31:57.422Z,1601407917.422 [SBIT](DEBUG): Construct Startup Built In Test.
2020-09-29T19:31:57.441Z,1601407917.441 [SBIT] Loaded
2020-09-29T19:31:57.441Z,1601407917.441 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2020-09-29T19:31:57.442Z,1601407917.442 [IBIT](DEBUG): Construct Initiated Built In Test.
2020-09-29T19:31:57.454Z,1601407917.454 [IBIT] Loaded
2020-09-29T19:31:57.455Z,1601407917.455 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2020-09-29T19:31:57.458Z,1601407917.458 [CBIT](DEBUG): Construct Continuous Built In Test.
2020-09-29T19:31:57.601Z,1601407917.601 [CBIT] Loaded
2020-09-29T19:31:57.601Z,1601407917.601 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2020-09-29T19:31:57.601Z,1601407917.601 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2020-09-29T19:31:57.602Z,1601407917.602 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2020-09-29T19:31:57.753Z,1601407917.753 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2020-09-29T19:31:57.753Z,1601407917.753 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2020-09-29T19:31:57.860Z,1601407917.860 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2020-09-29T19:31:57.861Z,1601407917.861 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2020-09-29T19:31:57.913Z,1601407917.913 [VerticalControl](DEBUG): Construct VerticalControl.
2020-09-29T19:31:57.999Z,1601407917.999 [VerticalControl] Loaded
2020-09-29T19:31:57.999Z,1601407917.999 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2020-09-29T19:31:57.000Z,1601407918.000 [HorizontalControl](DEBUG): Construct HorizontalControl.
2020-09-29T19:31:58.071Z,1601407918.071 [HorizontalControl] Loaded
2020-09-29T19:31:58.071Z,1601407918.071 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2020-09-29T19:31:58.072Z,1601407918.072 [SpeedControl](DEBUG): Construct SpeedControl.
2020-09-29T19:31:58.074Z,1601407918.074 [SpeedControl] Loaded
2020-09-29T19:31:58.074Z,1601407918.074 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2020-09-29T19:31:58.074Z,1601407918.074 [LoopControl](DEBUG): Construct LoopControl.
2020-09-29T19:31:58.075Z,1601407918.075 [LoopControl] Loaded
2020-09-29T19:31:58.075Z,1601407918.075 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2020-09-29T19:31:58.076Z,1601407918.076 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2020-09-29T19:31:58.076Z,1601407918.076 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2020-09-29T19:31:58.105Z,1601407918.105 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2020-09-29T19:31:58.109Z,1601407918.109 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2020-09-29T19:31:58.109Z,1601407918.109 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2020-09-29T19:31:58.116Z,1601407918.116 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2020-09-29T19:31:58.117Z,1601407918.117 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B644E0
2020-09-29T19:31:58.117Z,1601407918.117 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 2077
2020-09-29T19:31:58.122Z,1601407918.122 [Supervisor](INFO): Main Thread ID is 824
2020-09-29T19:31:58.122Z,1601407918.122 [Supervisor](DEBUG): Running supervisor.
2020-09-29T19:31:58.123Z,1601407918.123 [CommandLine ThreadHandler](INFO): Handler Thread ID is 2078
2020-09-29T19:31:58.125Z,1601407918.125 [controlThread ThreadHandler](INFO): Handler Thread ID is 2079
2020-09-29T19:31:58.125Z,1601407918.125 [controlThread](DEBUG): Initializing ControlThread
2020-09-29T19:31:58.130Z,1601407918.130 [NavChart](DEBUG): Initialize NavChart Navigation.
2020-09-29T19:31:58.131Z,1601407918.131 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2020-09-29T19:31:58.131Z,1601407918.131 [WorkSite](DEBUG): Initializing WorkSite component.
2020-09-29T19:31:58.137Z,1601407918.137 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2020-09-29T19:31:58.137Z,1601407918.137 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2020-09-29T19:31:58.138Z,1601407918.138 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2020-09-29T19:31:58.138Z,1601407918.138 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2020-09-29T19:31:58.139Z,1601407918.139 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2020-09-29T19:31:58.139Z,1601407918.139 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2020-09-29T19:31:58.140Z,1601407918.140 [SBIT](INFO): Initialize SBIT Component.
2020-09-29T19:31:58.140Z,1601407918.140 [SBIT](IMPORTANT): git: 2020-09-24
2020-09-29T19:31:58.140Z,1601407918.140 [SBIT](INFO): git hash: 5d0e7d8c58095398299d5a0f1e62866c13d9facc
2020-09-29T19:31:58.141Z,1601407918.141 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2020-09-29T19:31:58.142Z,1601407918.142 [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-09-29T19:31:58.143Z,1601407918.143 [SBIT](INFO): Beginning SBIT in 30.000000 seconds.
2020-09-29T19:31:58.143Z,1601407918.143 [IBIT](INFO): Initialize IBIT Component.
2020-09-29T19:31:58.145Z,1601407918.145 [CBIT](DEBUG): Initialize CBIT Component.
2020-09-29T19:31:58.145Z,1601407918.145 [logger ThreadHandler](INFO): Handler Thread ID is 2080
2020-09-29T19:31:58.157Z,1601407918.157 [CBIT](DEBUG): Initialized mux pins.
2020-09-29T19:31:58.157Z,1601407918.157 [CBIT](DEBUG): Initializing the watchdog timer.
2020-09-29T19:31:58.165Z,1601407918.165 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 2081
2020-09-29T19:31:58.166Z,1601407918.166 [DataOverHttps](DEBUG): dashIP=128.128.181.155 starts with a digit so assuming it is a numeric IP
2020-09-29T19:31:58.177Z,1601407918.177 [Onboard ThreadHandler](INFO): Handler Thread ID is 2082
2020-09-29T19:31:58.181Z,1601407918.181 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2020-09-29T19:31:58.181Z,1601407918.181 [CBIT](DEBUG): Initializing heartbeat.
2020-09-29T19:31:58.195Z,1601407918.195 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 2083
2020-09-29T19:31:58.217Z,1601407918.217 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 2084
2020-09-29T19:31:58.218Z,1601407918.218 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2020-09-29T19:31:58.222Z,1601407918.222 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Handler Thread ID is 2086
2020-09-29T19:31:58.223Z,1601407918.223 [WetLabsSeaOWL_UV_A](INFO): Powering down
2020-09-29T19:31:58.233Z,1601407918.233 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 2087
2020-09-29T19:31:58.237Z,1601407918.237 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2020-09-29T19:31:58.237Z,1601407918.237 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2020-09-29T19:31:58.237Z,1601407918.237 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2020-09-29T19:31:58.237Z,1601407918.237 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2020-09-29T19:31:58.237Z,1601407918.237 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2020-09-29T19:31:58.237Z,1601407918.237 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2020-09-29T19:31:58.238Z,1601407918.238 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2020-09-29T19:31:58.238Z,1601407918.238 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2020-09-29T19:31:58.238Z,1601407918.238 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2020-09-29T19:31:58.238Z,1601407918.238 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2020-09-29T19:31:58.238Z,1601407918.238 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2020-09-29T19:31:58.238Z,1601407918.238 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2020-09-29T19:31:58.239Z,1601407918.239 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2020-09-29T19:31:58.239Z,1601407918.239 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2020-09-29T19:31:58.239Z,1601407918.239 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2020-09-29T19:31:58.239Z,1601407918.239 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2020-09-29T19:31:58.253Z,1601407918.253 [CBIT](DEBUG): Deactivating GF circuits.
2020-09-29T19:31:58.253Z,1601407918.253 [CBIT](DEBUG): Deactivating emergency mode.
2020-09-29T19:31:58.289Z,1601407918.289 [CBIT](DEBUG): Backplane powered.
2020-09-29T19:31:58.289Z,1601407918.289 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2020-09-29T19:31:58.291Z,1601407918.291 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2020-09-29T19:31:58.291Z,1601407918.291 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2020-09-29T19:31:58.292Z,1601407918.292 [LoopControl](DEBUG): Initialize LoopControlComponent.
2020-09-29T19:31:58.293Z,1601407918.293 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2020-09-29T19:31:58.303Z,1601407918.303 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2020-09-29T19:31:58.329Z,1601407918.329 [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-09-29T19:31:58.330Z,1601407918.330 [MissionManager](INFO): Loading Mission: Missions/underIce/DefaultWithUndock.xml
2020-09-29T19:31:58.412Z,1601407918.412 [MissionManager](INFO): DefineArg DefaultWithUndock.ElapsedSinceDefaultStarted = 0.000000 min
2020-09-29T19:31:58.432Z,1601407918.432 [MissionManager](INFO): DefineArg DefaultWithUndock.DetachTimeout = 30.000000 min
2020-09-29T19:31:58.435Z,1601407918.435 [MissionManager](INFO): DefineArg DefaultWithUndock.MicromodemCommsInterval = 2.000000 min
2020-09-29T19:31:58.436Z,1601407918.436 [DefaultWithUndock:A.Wait](DEBUG): Construct Wait.
2020-09-29T19:31:58.454Z,1601407918.454 [DefaultWithUndock:B.Undock](DEBUG): Construct.
2020-09-29T19:31:58.454Z,1601407918.454 [DefaultWithUndock:B.Undock](DEBUG): Initializing internal variables to default values.
2020-09-29T19:31:58.483Z,1601407918.483 [DefaultWithUndock:C.GoToSurface](DEBUG): Construct GoToSurface.
2020-09-29T19:31:58.526Z,1601407918.526 [DefaultWithUndock:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2020-09-29T19:31:58.528Z,1601407918.528 [DefaultWithUndock:CheckIn:C.Wait](DEBUG): Construct Wait.
2020-09-29T19:31:58.550Z,1601407918.550 [DefaultWithUndock:F.Execute](DEBUG): Construct Execute.
2020-09-29T19:31:58.569Z,1601407918.569 [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="DefaultWithUndock">

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

    <DefineArg Name="DetachTimeout"><Description>
        Maximum time duration for the vehicle to reach the approach depth after detaching form the dock.
        The vehicle will switch over to midcourse guidance after the timeout is expired.
    </Description><Units:minute/><Value>30</Value></DefineArg>

    <DefineArg Name="MicromodemCommsInterval"><Description>
        How often to trigger Umodem communications
    </Description><Units:minute/><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>

    <!-- Leave the dock if necessary --> 
    <Guidance:Undock>
        <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>
    </Guidance:Undock>

    <!-- 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>

    <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-09-29T19:31:58.574Z,1601407918.574 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,DDM,Depth_Keller,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-09-29T19:31:58.585Z,1601407918.585 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2020-09-29T19:31:58.601Z,1601407918.601 [Radio_Surface](INFO): Powering up
2020-09-29T19:31:58.618Z,1601407918.618 [DDM](INFO): Powering up
2020-09-29T19:31:58.619Z,1601407918.619 [DDM](DEBUG): Initializing DDM.
2020-09-29T19:31:58.742Z,1601407918.742 [DUSBL_Hydroid](INFO): Powering up
2020-09-29T19:31:58.743Z,1601407918.743 [DUSBL_Hydroid](DEBUG): Initializing DUSBL_Hydroid.
2020-09-29T19:31:58.914Z,1601407918.914 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2020-09-29T19:31:58.921Z,1601407918.921 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2020-09-29T19:31:58.922Z,1601407918.922 [ElevatorServo](DEBUG): Initializing EZServoServo.
2020-09-29T19:31:58.929Z,1601407918.929 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2020-09-29T19:31:58.930Z,1601407918.930 [MassServo](DEBUG): Initializing EZServoServo.
2020-09-29T19:31:58.937Z,1601407918.937 [MassServo](DEBUG): Initializing MassServo.
2020-09-29T19:31:58.938Z,1601407918.938 [RudderServo](DEBUG): Initializing EZServoServo.
2020-09-29T19:31:58.945Z,1601407918.945 [RudderServo](DEBUG): Initializing RudderServo.
2020-09-29T19:31:58.946Z,1601407918.946 [ThrusterServo](DEBUG): Initializing EZServoServo.
2020-09-29T19:31:58.953Z,1601407918.953 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2020-09-29T19:31:59.015Z,1601407919.015 [Micromodem](INFO): Powering up
2020-09-29T19:31:59.015Z,1601407919.015 [Micromodem](DEBUG): Initializing Micromodem.
2020-09-29T19:32:03.952Z,1601407923.952 [Micromodem](INFO): Nmea out: $CCCFG,ALL,0*33

2020-09-29T19:32:04.355Z,1601407924.355 [Micromodem](INFO): Nmea in: $CATMG,2020-09-29T19:32:04.260207Z,RTC,RTC*5E

2020-09-29T19:32:04.356Z,1601407924.356 [Micromodem](ERROR): CFG response from modem unexpected: $CATMG,2020-09-29T19:32:04.260207Z,RTC,RTC*5E

2020-09-29T19:32:04.763Z,1601407924.763 [Micromodem](INFO): Nmea in: $CACFG,ALL,0*31

2020-09-29T19:32:04.763Z,1601407924.763 [Micromodem](INFO): Nmea out: $CCCFG,SRC,1*31

2020-09-29T19:32:05.163Z,1601407925.163 [Micromodem](INFO): Nmea in: $CACFG,SRC,1*33

2020-09-29T19:32:05.163Z,1601407925.163 [Micromodem](INFO): Nmea out: $CCCFG,nav.dt.txtrig_gpio4,1*64

2020-09-29T19:32:05.567Z,1601407925.567 [Micromodem](INFO): Nmea in: $CACFG,nav.dt.txtrig_gpio4,1*66

2020-09-29T19:32:05.567Z,1601407925.567 [Micromodem](INFO): Nmea out: $CCCFG,pwramp.txlevel,0*2F

2020-09-29T19:32:05.971Z,1601407925.971 [Micromodem](INFO): Nmea in: $CACFG,pwramp.txlevel,0*2D

2020-09-29T19:32:05.971Z,1601407925.971 [Micromodem](INFO): Nmea out: $CCCFG,DTO,30*1E

2020-09-29T19:32:06.379Z,1601407926.379 [Micromodem](INFO): Nmea in: $CACFG,DTO,30*1C

2020-09-29T19:32:06.379Z,1601407926.379 [Micromodem](INFO): Nmea out: $CCCFG,FC0,14500*47

2020-09-29T19:32:06.779Z,1601407926.779 [Micromodem](INFO): Nmea in: $CACFG,FC0,14500*45

2020-09-29T19:32:06.779Z,1601407926.779 [Micromodem](INFO): Nmea out: $CCCFG,BW0,4000*63

2020-09-29T19:32:07.207Z,1601407927.207 [Micromodem](INFO): Nmea in: $CACFG,BW0,4000*61

2020-09-29T19:32:07.207Z,1601407927.207 [Micromodem](INFO): Nmea out: $CCCFG,BND,0*3A

2020-09-29T19:32:07.559Z,1601407927.559 [Micromodem](INFO): Nmea in: $CACFG,BND,0*38

2020-09-29T19:32:07.559Z,1601407927.559 [Micromodem](INFO): Nmea out: $CCCLK,2020,09,29,19,32,08*47

2020-09-29T19:32:07.955Z,1601407927.955 [Micromodem](INFO): Nmea in: $CACLK,2020,9,29,19,32,8*45

2020-09-29T19:32:07.956Z,1601407927.956 [Micromodem](INFO): Nmea in: $CATMS,0,2020-09-29T19:32:09Z*74

2020-09-29T19:32:07.958Z,1601407927.958 [Micromodem](INFO): Nmea in: $CATMG,2020-09-29T19:32:09.028475Z,USER_CMD,RTC*1F

2020-09-29T19:32:16.939Z,1601407936.939 [DUSBL_Hydroid](INFO): DUSBL Version:O
2020-09-29T19:32:23.718Z,1601407943.718 [DDM](FAULT): failed to initialize; deviceResponse_ loaded: , available: 0
2020-09-29T19:32:23.718Z,1601407943.718 [DDM] Communications Fault, FailCount= 1
2020-09-29T19:32:23.718Z,1601407943.718 [DDM](ERROR): Communications Fault
2020-09-29T19:32:23.786Z,1601407943.786 [CBIT](ERROR): Communications Fault in component: DDM
2020-09-29T19:32:24.121Z,1601407944.121 [DDM](INFO): Powering down
2020-09-29T19:32:24.139Z,1601407944.139 [NAL9602](INFO): Powering up NAL9602
2020-09-29T19:32:25.065Z,1601407945.065 [CBIT](INFO): Clearing failed state for component DDM
2020-09-29T19:32:25.065Z,1601407945.065 [DDM] No Fault, FailCount= 1
2020-09-29T19:32:28.655Z,1601407948.655 [SBIT](IMPORTANT): Beginning Startup BIT
2020-09-29T19:32:28.663Z,1601407948.663 [CBIT](IMPORTANT): Beginning ground fault scan
2020-09-29T19:32:29.373Z,1601407949.373 [DDM](INFO): Powering up
2020-09-29T19:32:29.373Z,1601407949.373 [DDM](DEBUG): Initializing DDM.
2020-09-29T19:32:35.043Z,1601407955.043 [NAL9602](INFO): NAL9602 initialized
2020-09-29T19:32:39.603Z,1601407959.603 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.009750
CHAN A1 (24V): -0.028288
CHAN A2 (12V): -0.007092
CHAN A3 (5V): -0.001697
CHAN B0 (3.3V): 0.000238
CHAN B1 (3.15aV): -0.000039
CHAN B2 (3.15bV): 0.000579
CHAN B3 (GND): 0.002156
OPEN: 0.006113
Full Scale Calc: 4.765 mA, -1.589 mA
2020-09-29T19:32:49.624Z,1601407969.624 [NAL9602](INFO): SBD MO Status=0, MOMSN=11393, MT Status=0, MTMSN=0
2020-09-29T19:32:49.624Z,1601407969.624 [NAL9602](INFO): No messages in MT queue
2020-09-29T19:32:54.445Z,1601407974.445 [DDM](FAULT): failed to initialize; deviceResponse_ loaded: , available: 0
2020-09-29T19:32:54.445Z,1601407974.445 [DDM] Communications Fault, FailCount= 2
2020-09-29T19:32:54.445Z,1601407974.445 [DDM](ERROR): Communications Fault
2020-09-29T19:32:54.559Z,1601407974.559 [CBIT](ERROR): Communications Fault in component: DDM
2020-09-29T19:32:54.847Z,1601407974.847 [DDM](INFO): Powering down
2020-09-29T19:32:55.766Z,1601407975.766 [CBIT](INFO): Clearing failed state for component DDM
2020-09-29T19:32:55.766Z,1601407975.766 [DDM] No Fault, FailCount= 2
2020-09-29T19:33:00.093Z,1601407980.093 [DDM](INFO): Powering up
2020-09-29T19:33:00.093Z,1601407980.093 [DDM](DEBUG): Initializing DDM.
2020-09-29T19:33:02.129Z,1601407982.129 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,193300.00,A,4131.21240,N,07040.68310,W,13.296,254.95,290920,,,A*49
2020-09-29T19:33:02.132Z,1601407982.132 [NAL9602](INFO): GPS fix at 20200929T193300: (41.520207, -70.678052)
2020-09-29T19:33:22.372Z,1601408002.372 [SBIT](IMPORTANT): SBIT PASSED
2020-09-29T19:33:22.372Z,1601408002.372 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2020-09-29T19:33:22.377Z,1601408002.377 [SBIT](IMPORTANT): DDM.loadAtStartup=1 bool;

2020-09-29T19:33:22.377Z,1601408002.377 [SBIT](IMPORTANT): DDM.verbosity=1 count;

2020-09-29T19:33:22.377Z,1601408002.377 [SBIT](IMPORTANT): DropWeight.loadAtStartup=0 bool;

2020-09-29T19:33:22.377Z,1601408002.377 [SBIT](IMPORTANT): Express linearApproximation acoustic_contact_range 10.000000 meter;

2020-09-29T19:33:22.377Z,1601408002.377 [SBIT](IMPORTANT): Micromodem.sendExpress=0 bool;

2020-09-29T19:33:22.377Z,1601408002.377 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=288.614464 cubic_centimeter;

2020-09-29T19:33:22.378Z,1601408002.378 [SBIT](IMPORTANT): VerticalControl.massDefault=2.506765 millimeter;

2020-09-29T19:33:22.764Z,1601408002.764 [WorkSite](INFO): Already have valid position. Ignoring workSite position from Data/workSite.cfg
2020-09-29T19:33:22.784Z,1601408002.784 [MissionManager](IMPORTANT): Started mission Startup
2020-09-29T19:33:22.789Z,1601408002.789 [Startup] Running Loop=1
2020-09-29T19:33:22.789Z,1601408002.789 [Startup](DEBUG): Aggregate::initialize Startup
2020-09-29T19:33:22.789Z,1601408002.789 [Startup:A.GoToSurface] Running Loop=1
2020-09-29T19:33:22.789Z,1601408002.789 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2020-09-29T19:33:22.790Z,1601408002.790 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2020-09-29T19:33:22.790Z,1601408002.790 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2020-09-29T19:33:22.790Z,1601408002.790 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2020-09-29T19:33:22.791Z,1601408002.791 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2020-09-29T19:33:22.791Z,1601408002.791 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2020-09-29T19:33:22.795Z,1601408002.795 [Startup:StartupSatComms] Running Loop=1
2020-09-29T19:33:22.795Z,1601408002.795 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2020-09-29T19:33:22.795Z,1601408002.795 [Startup:StartupSatComms:A] Running Loop=1
2020-09-29T19:33:23.219Z,1601408003.219 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2020-09-29T19:33:24.773Z,1601408004.773 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,193323.00,A,4131.19804,N,07040.79816,W,13.607,253.00,290920,,,A*43
2020-09-29T19:33:24.775Z,1601408004.775 [NAL9602](INFO): GPS fix at 20200929T193323: (41.519967, -70.679969)
2020-09-29T19:33:24.787Z,1601408004.787 [Startup:StartupSatComms:A] Stopped
2020-09-29T19:33:24.787Z,1601408004.787 [Startup:StartupSatComms:B] Running Loop=1
2020-09-29T19:33:25.151Z,1601408005.151 [DDM](FAULT): failed to initialize; deviceResponse_ loaded: , available: 0
2020-09-29T19:33:25.151Z,1601408005.151 [DDM] Communications Fault, FailCount= 3
2020-09-29T19:33:25.151Z,1601408005.151 [DDM](ERROR): Communications Fault
2020-09-29T19:33:25.224Z,1601408005.224 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2020-09-29T19:33:25.251Z,1601408005.251 [CBIT](ERROR): Communications Fault in component: DDM
2020-09-29T19:33:25.251Z,1601408005.251 [CBIT](CRITICAL): Communications Fault in component: DDM
2020-09-29T19:33:25.604Z,1601408005.604 [DDM](INFO): Powering down
2020-09-29T19:33:25.625Z,1601408005.625 [CommandLine](FAULT): Scheduling is paused
2020-09-29T19:33:25.625Z,1601408005.625 [CBIT](INFO): Critical error at 20200929T193325
2020-09-29T19:33:25.625Z,1601408005.625 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2020-09-29T19:33:47.081Z,1601408027.081 [BPC1](ERROR): BPC1A: No match for serial number 1717 in BPC1A's battery stick inventory (sticks 1-32 in onboard configuration file).
2020-09-29T19:33:50.307Z,1601408030.307 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2020-09-29T19:33:57.590Z,1601408037.590 [NAL9602](INFO): Not Powering down - fast GPS
2020-09-29T19:34:25.114Z,1601408065.114 [Startup:StartupSatComms:B](INFO): Timed out from 2020-09-29T19:33:24.8Z
2020-09-29T19:34:25.114Z,1601408065.114 [Startup:StartupSatComms:B] Stopped
2020-09-29T19:34:25.115Z,1601408065.115 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2020-09-29T19:34:25.115Z,1601408065.115 [Startup:StartupSatComms] Stopped
2020-09-29T19:34:25.115Z,1601408065.115 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2020-09-29T19:34:25.115Z,1601408065.115 [Startup](INFO): Completed Startup
2020-09-29T19:34:25.116Z,1601408065.116 [MissionManager](INFO): Startup is completed.
2020-09-29T19:34:25.116Z,1601408065.116 [MissionManager](INFO): Uninitializing Mission Startup
2020-09-29T19:34:25.116Z,1601408065.116 [Startup] Stopped
2020-09-29T19:34:25.116Z,1601408065.116 [Startup](DEBUG): Aggregate::uninitialize Startup
2020-09-29T19:34:25.116Z,1601408065.116 [Startup:A.GoToSurface] Stopped
2020-09-29T19:34:25.116Z,1601408065.116 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2020-09-29T19:34:25.481Z,1601408065.481 [MissionManager](IMPORTANT): Started mission DefaultWithUndock
2020-09-29T19:34:25.481Z,1601408065.481 [DefaultWithUndock] Running Loop=1
2020-09-29T19:34:25.481Z,1601408065.481 [DefaultWithUndock](DEBUG): Aggregate::initialize DefaultWithUndock
2020-09-29T19:34:25.481Z,1601408065.481 [DefaultWithUndock:C.GoToSurface] Running Loop=1
2020-09-29T19:34:25.481Z,1601408065.481 [DefaultWithUndock:C.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2020-09-29T19:34:25.481Z,1601408065.481 [DefaultWithUndock:C.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2020-09-29T19:34:25.482Z,1601408065.482 [DefaultWithUndock:C.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2020-09-29T19:34:25.482Z,1601408065.482 [DefaultWithUndock:C.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2020-09-29T19:34:25.482Z,1601408065.482 [DefaultWithUndock:C.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2020-09-29T19:34:25.483Z,1601408065.483 [DefaultWithUndock:C.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2020-09-29T19:34:25.483Z,1601408065.483 [DefaultWithUndock:A.Wait] Running Loop=1
2020-09-29T19:34:25.483Z,1601408065.483 [DefaultWithUndock:A.Wait](DEBUG): Initialize Wait Component.
2020-09-29T19:34:55.778Z,1601408095.778 [DefaultWithUndock:A.Wait](INFO): Done Waiting.
2020-09-29T19:34:55.778Z,1601408095.778 [DefaultWithUndock:A.Wait] Stopped
2020-09-29T19:34:55.778Z,1601408095.778 [DefaultWithUndock:A.Wait](DEBUG): Uninitialize Wait Component.
2020-09-29T19:34:55.778Z,1601408095.778 [DefaultWithUndock:B.Undock] Running Loop=1
2020-09-29T19:34:55.778Z,1601408095.778 [DefaultWithUndock:B.Undock](DEBUG): Initialize.
2020-09-29T19:34:55.778Z,1601408095.778 [DefaultWithUndock:B.Undock](DEBUG): Initializing internal variables to default values.
2020-09-29T19:34:56.583Z,1601408096.583 [PowerOnly](INFO): Powering up loadControl
2020-09-29T19:35:01.945Z,1601408101.945 [BuoyancyServo](ERROR): getPosition uart error serial timeout
2020-09-29T19:35:01.945Z,1601408101.945 [BuoyancyServo](FAULT): Buoyancy getPosition uart error.serial timeout
2020-09-29T19:35:01.945Z,1601408101.945 [BuoyancyServo] Communications Fault, FailCount= 1
2020-09-29T19:35:01.945Z,1601408101.945 [BuoyancyServo](ERROR): Communications Fault
2020-09-29T19:35:01.954Z,1601408101.954 [CBIT](ERROR): Communications Fault in component: BuoyancyServo
2020-09-29T19:35:03.930Z,1601408103.930 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2020-09-29T19:35:03.930Z,1601408103.930 [BuoyancyServo](INFO): Powering down
2020-09-29T19:35:04.721Z,1601408104.721 [CBIT](INFO): Clearing failed state for component BuoyancyServo
2020-09-29T19:35:04.721Z,1601408104.721 [BuoyancyServo] No Fault, FailCount= 1
2020-09-29T19:35:05.119Z,1601408105.119 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2020-09-29T19:35:05.125Z,1601408105.125 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2020-09-29T19:35:33.084Z,1601408133.084 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004422
2020-09-29T19:36:14.166Z,1601408174.166 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for BIT error
2020-09-29T19:36:27.887Z,1601408187.887 [PowerOnly](INFO): Powering down loadControl
2020-09-29T19:36:28.705Z,1601408188.705 [PowerOnly](INFO): Powering up loadControl
2020-09-29T19:38:00.011Z,1601408280.011 [PowerOnly](INFO): Powering down loadControl
2020-09-29T19:38:00.819Z,1601408280.819 [PowerOnly](INFO): Powering up loadControl
2020-09-29T19:38:25.487Z,1601408305.487 [CBIT](INFO): Clearing failed state for component DDM
2020-09-29T19:38:25.487Z,1601408305.487 [DDM] No Fault, FailCount= 3
2020-09-29T19:38:25.926Z,1601408305.926 [DDM](INFO): Powering up
2020-09-29T19:38:25.926Z,1601408305.926 [DDM](DEBUG): Initializing DDM.
2020-09-29T19:38:51.319Z,1601408331.319 [DDM](FAULT): failed to initialize; deviceResponse_ loaded: , available: 0
2020-09-29T19:38:51.319Z,1601408331.319 [DDM] Communications Fault, FailCount= 1
2020-09-29T19:38:51.319Z,1601408331.319 [DDM](ERROR): Communications Fault
2020-09-29T19:38:51.407Z,1601408331.407 [CBIT](ERROR): Communications Fault in component: DDM
2020-09-29T19:38:51.723Z,1601408331.723 [DDM](INFO): Powering down
2020-09-29T19:38:52.575Z,1601408332.575 [CBIT](INFO): Clearing failed state for component DDM
2020-09-29T19:38:52.576Z,1601408332.576 [DDM] No Fault, FailCount= 1
2020-09-29T19:38:56.975Z,1601408336.975 [DDM](INFO): Powering up
2020-09-29T19:38:56.975Z,1601408336.975 [DDM](DEBUG): Initializing DDM.
2020-09-29T19:39:22.027Z,1601408362.027 [DDM](FAULT): failed to initialize; deviceResponse_ loaded: , available: 0
2020-09-29T19:39:22.027Z,1601408362.027 [DDM] Communications Fault, FailCount= 2
2020-09-29T19:39:22.027Z,1601408362.027 [DDM](ERROR): Communications Fault
2020-09-29T19:39:22.166Z,1601408362.166 [CBIT](ERROR): Communications Fault in component: DDM
2020-09-29T19:39:22.431Z,1601408362.431 [DDM](INFO): Powering down
2020-09-29T19:39:22.448Z,1601408362.448 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2020-09-29T19:39:22.471Z,1601408362.471 [BPC1](INFO): Received data from all battery sticks.
2020-09-29T19:39:23.290Z,1601408363.290 [CBIT](INFO): Clearing failed state for component DDM
2020-09-29T19:39:23.290Z,1601408363.290 [DDM] No Fault, FailCount= 2
2020-09-29T19:39:27.682Z,1601408367.682 [DDM](INFO): Powering up
2020-09-29T19:39:27.683Z,1601408367.683 [DDM](DEBUG): Initializing DDM.
2020-09-29T19:39:30.536Z,1601408370.536 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2020-09-29T19:39:32.130Z,1601408372.130 [PowerOnly](INFO): Powering down loadControl
2020-09-29T19:39:32.943Z,1601408372.943 [PowerOnly](INFO): Powering up loadControl
2020-09-29T19:39:52.736Z,1601408392.736 [DDM](FAULT): failed to initialize; deviceResponse_ loaded: , available: 0
2020-09-29T19:39:52.736Z,1601408392.736 [DDM] Communications Fault, FailCount= 3
2020-09-29T19:39:52.736Z,1601408392.736 [DDM](ERROR): Communications Fault
2020-09-29T19:39:52.762Z,1601408392.762 [CBIT](ERROR): Communications Fault in component: DDM
2020-09-29T19:39:52.762Z,1601408392.762 [CBIT](CRITICAL): Communications Fault in component: DDM
2020-09-29T19:39:53.139Z,1601408393.139 [DDM](INFO): Powering down
2020-09-29T19:39:53.219Z,1601408393.219 [CBIT](INFO): Critical error at 20200929T193952
2020-09-29T19:41:04.256Z,1601408464.256 [PowerOnly](INFO): Powering down loadControl
2020-09-29T19:41:05.063Z,1601408465.063 [PowerOnly](INFO): Powering up loadControl
2020-09-29T19:41:43.058Z,1601408503.058 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2020-09-29T19:42:36.383Z,1601408556.383 [PowerOnly](INFO): Powering down loadControl
2020-09-29T19:42:37.187Z,1601408557.187 [PowerOnly](INFO): Powering up loadControl
2020-09-29T19:44:08.499Z,1601408648.499 [PowerOnly](INFO): Powering down loadControl
2020-09-29T19:44:09.311Z,1601408649.311 [PowerOnly](INFO): Powering up loadControl
2020-09-29T19:44:53.019Z,1601408693.019 [CBIT](INFO): Clearing failed state for component DDM
2020-09-29T19:44:53.019Z,1601408693.019 [DDM] No Fault, FailCount= 3
2020-09-29T19:44:53.334Z,1601408693.334 [DDM](INFO): Powering up
2020-09-29T19:44:53.334Z,1601408693.334 [DDM](DEBUG): Initializing DDM.
2020-09-29T19:44:54.150Z,1601408694.150 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2020-09-29T19:45:01.423Z,1601408701.423 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2020-09-29T19:45:03.932Z,1601408703.932 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for altitude
2020-09-29T19:45:05.079Z,1601408705.079 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2020-09-29T19:45:10.340Z,1601408710.340 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2020-09-29T19:45:18.389Z,1601408718.389 [DDM](FAULT): failed to initialize; deviceResponse_ loaded: , available: 0
2020-09-29T19:45:18.389Z,1601408718.389 [DDM] Communications Fault, FailCount= 1
2020-09-29T19:45:18.389Z,1601408718.389 [DDM](ERROR): Communications Fault
2020-09-29T19:45:18.419Z,1601408718.419 [CBIT](ERROR): Communications Fault in component: DDM
2020-09-29T19:45:18.786Z,1601408718.786 [DDM](INFO): Powering down
2020-09-29T19:45:19.623Z,1601408719.623 [CBIT](INFO): Clearing failed state for component DDM
2020-09-29T19:45:19.623Z,1601408719.623 [DDM] No Fault, FailCount= 1
2020-09-29T19:45:24.038Z,1601408724.038 [DDM](INFO): Powering up
2020-09-29T19:45:24.038Z,1601408724.038 [DDM](DEBUG): Initializing DDM.
2020-09-29T19:45:40.639Z,1601408740.639 [PowerOnly](INFO): Powering down loadControl
2020-09-29T19:45:41.438Z,1601408741.438 [PowerOnly](INFO): Powering up loadControl
2020-09-29T19:45:49.097Z,1601408749.097 [DDM](FAULT): failed to initialize; deviceResponse_ loaded: , available: 0
2020-09-29T19:45:49.097Z,1601408749.097 [DDM] Communications Fault, FailCount= 2
2020-09-29T19:45:49.097Z,1601408749.097 [DDM](ERROR): Communications Fault
2020-09-29T19:45:49.172Z,1601408749.172 [CBIT](ERROR): Communications Fault in component: DDM
2020-09-29T19:45:49.494Z,1601408749.494 [DDM](INFO): Powering down
2020-09-29T19:45:50.362Z,1601408750.362 [CBIT](INFO): Clearing failed state for component DDM
2020-09-29T19:45:50.362Z,1601408750.362 [DDM] No Fault, FailCount= 2
2020-09-29T19:45:54.746Z,1601408754.746 [DDM](INFO): Powering up
2020-09-29T19:45:54.746Z,1601408754.746 [DDM](DEBUG): Initializing DDM.
2020-09-29T19:46:19.795Z,1601408779.795 [DDM](FAULT): failed to initialize; deviceResponse_ loaded: , available: 0
2020-09-29T19:46:19.795Z,1601408779.795 [DDM] Communications Fault, FailCount= 3
2020-09-29T19:46:19.795Z,1601408779.795 [DDM](ERROR): Communications Fault
2020-09-29T19:46:19.836Z,1601408779.836 [CBIT](ERROR): Communications Fault in component: DDM
2020-09-29T19:46:19.836Z,1601408779.836 [CBIT](CRITICAL): Communications Fault in component: DDM
2020-09-29T19:46:20.203Z,1601408780.203 [DDM](INFO): Powering down
2020-09-29T19:46:20.340Z,1601408780.340 [CBIT](INFO): Critical error at 20200929T194619
2020-09-29T19:47:12.733Z,1601408832.733 [PowerOnly](INFO): Powering down loadControl
2020-09-29T19:47:13.535Z,1601408833.535 [PowerOnly](INFO): Powering up loadControl
2020-09-29T19:47:15.964Z,1601408835.964 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2020-09-29T19:48:20.303Z,1601408900.303 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude
2020-09-29T19:48:29.102Z,1601408909.102 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2020-09-29T19:48:44.855Z,1601408924.855 [PowerOnly](INFO): Powering down loadControl
2020-09-29T19:48:45.659Z,1601408925.659 [PowerOnly](INFO): Powering up loadControl
2020-09-29T19:48:49.292Z,1601408929.292 [RDI_Pathfinder](ERROR): only read 1 of 4 data items
2020-09-29T19:48:49.316Z,1601408929.316 [RDI_PathfinderUp](ERROR): only read 0 of 1 data item for altitude
2020-09-29T19:49:09.131Z,1601408949.131 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2020-09-29T19:50:16.963Z,1601409016.963 [PowerOnly](INFO): Powering down loadControl
2020-09-29T19:50:17.771Z,1601409017.771 [PowerOnly](INFO): Powering up loadControl
2020-09-29T19:51:20.007Z,1601409080.007 [CBIT](INFO): Clearing failed state for component DDM
2020-09-29T19:51:20.007Z,1601409080.007 [DDM] No Fault, FailCount= 3
2020-09-29T19:51:20.382Z,1601409080.382 [DDM](INFO): Powering up
2020-09-29T19:51:20.382Z,1601409080.382 [DDM](DEBUG): Initializing DDM.
2020-09-29T19:51:45.433Z,1601409105.433 [DDM](FAULT): failed to initialize; deviceResponse_ loaded: ø!C REMUS Captu.1
!V1,H_RECOVERY_LATCH
!V2,H_RECOVERY_WHISKERS
!V1,H_RECOVERY_LATCH
!V2,H_RECOVERY_WHISKERS
!V1,H_RECOVERY_LATCH
!V2,H_RECOVERY_WHISKERS
!V1,H_RECOVERY_LATCH
!V2,H_RECOVERY_WHISKERS
!V1,H_RECOVERY_LATCH
!V2,H_RECOVERY_WHISKERS
!V1,H_RECOVERY_LATCH
!V2,H_RECOVERY_WHISKERS
!V1,H_RECOVERY_LATCH
!V2,H_RECOVERY_WHISKERS
!V1,H_RECOVERY_LATCH
!V2,H__WHISKERS
!V1,H_RECOVERY_LATCH
!V2,H_RECOVERY_WHISKERS
!V1,H_RECOVERY_LATCH
!V2,H_RECOVERY_WHISKERS
!V1,H_RECOVERY_LATCH
!V2,H_RECOVERY_WHISKERS
!V1,H_RECOVERY_LATCH
!V2,H_RECOVERY_WHISKERS
!V1,H_RECOVERY_LATCH
!V2,H_RECOVERY_WHISKERS
!V1,H_RECOVERY_LATCH
!V2,H_RECOVERY_WHISKERS
!V1,H_RECOVERY_LATCH
!V2,H_RECOVERY_WHISKERS
!V1,H_RECOVERY_LATCH
!V2,H_RECOVERY_WHISKERS
!V1,H_RECOVERY_LATCH
!V2,H_RECOVERY_WHISKERS
!V1,H_RECOVERY_LATCH
!V2,H_RECOVERY_WHISKERS
!V1,H_RECOVERY_LATCH
!V2,H_RECOVERY_WHISKERS
!V1,H_RECOVERY_LATCH
!V2,H_RECOVERY_WHISKERS
!V1,H_RECOVERY_LATCH
!V2,H_RECOVERY_WHISKERS
COVERY_LATCH
!V2,H_RECOVERY_WHISKERS
!V1,H_RECOVERY_LATCH
!V2,H_RECOVERY_WHISKERS
!V1,H_RECOVERY_LATCH
!V2,H_RECOVERY_WHISKERS
Ä?, available: 43A
2020-09-29T19:51:45.433Z,1601409105.433 [DDM] Communications Fault, FailCount= 1
2020-09-29T19:51:45.433Z,1601409105.433 [DDM](ERROR): Communications Fault
2020-09-29T19:51:45.456Z,1601409105.456 [CBIT](ERROR): Communications Fault in component: DDM
2020-09-29T19:51:45.834Z,1601409105.834 [DDM](INFO): Powering down
2020-09-29T19:51:46.665Z,1601409106.665 [CBIT](INFO): Clearing failed state for component DDM
2020-09-29T19:51:46.665Z,1601409106.665 [DDM] No Fault, FailCount= 1
2020-09-29T19:51:49.091Z,1601409109.091 [PowerOnly](INFO): Powering down loadControl
2020-09-29T19:51:49.883Z,1601409109.883 [PowerOnly](INFO): Powering up loadControl
2020-09-29T19:51:51.086Z,1601409111.086 [DDM](INFO): Powering up
2020-09-29T19:51:51.087Z,1601409111.087 [DDM](DEBUG): Initializing DDM.
2020-09-29T19:52:06.843Z,1601409126.843 [DDM](INFO): Dynamic Docking Module:!C REMUS Capture Rev 1.1
2020-09-29T19:52:07.248Z,1601409127.248 [DDM](INFO): Detaching. Opening Latch
2020-09-29T19:52:07.650Z,1601409127.650 [DDM](INFO): Detaching. Opening Latch
2020-09-29T19:52:07.681Z,1601409127.681 [DDM](INFO): Failure count cleared after critical for DDM
2020-09-29T19:52:08.055Z,1601409128.055 [DDM](INFO): Detaching. Opening Latch
2020-09-29T19:52:08.458Z,1601409128.458 [DDM](INFO): Detaching. Opening Latch
2020-09-29T19:52:09.760Z,1601409129.760 [DefaultWithUndock:B.Undock](INFO): Detaching from dock.
2020-09-29T19:52:10.130Z,1601409130.130 [DefaultWithUndock:B.Undock](INFO): Detected possible detachment. Starting timer.
2020-09-29T19:52:30.369Z,1601409150.369 [DefaultWithUndock:B.Undock](INFO): Detached at range: nan m. Transitioning DDM to standby.
2020-09-29T19:52:31.085Z,1601409151.085 [DDM](INFO): Closing Latch
2020-09-29T19:52:31.486Z,1601409151.486 [DDM](INFO): Closing Latch
2020-09-29T19:52:31.926Z,1601409151.926 [DDM](INFO): Closing Latch
2020-09-29T19:52:33.206Z,1601409153.206 [DefaultWithUndock:B.Undock](INFO): DDM at standby.
2020-09-29T19:52:33.559Z,1601409153.559 [DefaultWithUndock:B.Undock](IMPORTANT): Undocking sequence complete.
2020-09-29T19:52:33.559Z,1601409153.559 [DefaultWithUndock:B.Undock] Stopped
2020-09-29T19:52:33.966Z,1601409153.966 [DefaultWithUndock:CheckIn] Running Loop=1
2020-09-29T19:52:33.966Z,1601409153.966 [DefaultWithUndock:CheckIn](DEBUG): Aggregate::initialize DefaultWithUndock:CheckIn
2020-09-29T19:52:33.966Z,1601409153.966 [DefaultWithUndock:CheckIn:Read_GPS] Running Loop=1
2020-09-29T19:52:34.358Z,1601409154.358 [DefaultWithUndock:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2020-09-29T19:52:35.941Z,1601409155.941 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,195235.00,A,4133.14141,N,07042.52302,W,1.613,77.72,290920,,,A*46
2020-09-29T19:52:35.943Z,1601409155.943 [NAL9602](INFO): GPS fix at 20200929T195235: (41.552357, -70.708717)
2020-09-29T19:52:35.974Z,1601409155.974 [DefaultWithUndock:CheckIn:Read_GPS] Stopped
2020-09-29T19:52:35.974Z,1601409155.974 [DefaultWithUndock:CheckIn:Read_Iridium] Running Loop=1
2020-09-29T19:52:36.374Z,1601409156.374 [DefaultWithUndock:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2020-09-29T19:52:40.388Z,1601409160.388 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20200929T180233/Courier0049.lzma
2020-09-29T19:52:46.411Z,1601409166.411 [DataOverHttps](INFO): Moved sent file to Logs/20200929T180233/Courier0049.lzma.bak
2020-09-29T19:52:46.411Z,1601409166.411 [DataOverHttps](INFO): SBD MOMSN=41151
2020-09-29T19:52:52.945Z,1601409172.945 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2020-09-29T19:52:55.448Z,1601409175.448 [DataOverHttps](INFO): Sending 268 bytes from file Logs/20200929T193146/Courier0000.lzma
2020-09-29T19:52:56.450Z,1601409176.450 [DataOverHttps](INFO): Moved sent file to Logs/20200929T193146/Courier0000.lzma.bak
2020-09-29T19:52:56.450Z,1601409176.450 [DataOverHttps](INFO): SBD MOMSN=41153
2020-09-29T19:53:00.176Z,1601409180.176 [NAL9602](INFO): SBD MO Status=2, MOMSN=11394, MT Status=2, MTMSN=0
2020-09-29T19:53:00.176Z,1601409180.176 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-09-29T19:53:04.222Z,1601409184.222 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2020-09-29T19:53:05.498Z,1601409185.498 [DataOverHttps](INFO): Sending 96 bytes from file Logs/20200929T193146/Courier0001.lzma
2020-09-29T19:53:06.498Z,1601409186.498 [DataOverHttps](INFO): Moved sent file to Logs/20200929T193146/Courier0001.lzma.bak
2020-09-29T19:53:06.499Z,1601409186.499 [DataOverHttps](INFO): SBD MOMSN=41157
2020-09-29T19:53:11.083Z,1601409191.083 [NAL9602](INFO): SBD MO Status=0, MOMSN=11394, MT Status=0, MTMSN=0
2020-09-29T19:53:11.083Z,1601409191.083 [NAL9602](INFO): No messages in MT queue
2020-09-29T19:53:16.540Z,1601409196.540 [DataOverHttps](INFO): Sending 249 bytes from file Logs/20200929T193146/Courier0004.lzma
2020-09-29T19:53:17.542Z,1601409197.542 [DataOverHttps](INFO): Moved sent file to Logs/20200929T193146/Courier0004.lzma.bak
2020-09-29T19:53:17.542Z,1601409197.542 [DataOverHttps](INFO): SBD MOMSN=41160
2020-09-29T19:53:21.186Z,1601409201.186 [PowerOnly](INFO): Powering down loadControl
2020-09-29T19:53:26.580Z,1601409206.580 [DataOverHttps](INFO): Sending 120 bytes from file Logs/20200929T180233/Express0047.lzma
2020-09-29T19:53:27.583Z,1601409207.583 [DataOverHttps](INFO): Moved sent file to Logs/20200929T180233/Express0047.lzma.bak
2020-09-29T19:53:27.583Z,1601409207.583 [DataOverHttps](INFO): SBD MOMSN=41165
2020-09-29T19:53:36.620Z,1601409216.620 [DataOverHttps](INFO): Sending 176 bytes from file Logs/20200929T180233/Express0050.lzma
2020-09-29T19:53:37.622Z,1601409217.622 [DataOverHttps](INFO): Moved sent file to Logs/20200929T180233/Express0050.lzma.bak
2020-09-29T19:53:37.623Z,1601409217.623 [DataOverHttps](INFO): SBD MOMSN=41168
2020-09-29T19:53:41.786Z,1601409221.786 [NAL9602](INFO): Not Powering down - fast GPS
2020-09-29T19:53:46.660Z,1601409226.660 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20200929T180233/Express0053.lzma
2020-09-29T19:53:47.663Z,1601409227.663 [DataOverHttps](INFO): Moved sent file to Logs/20200929T180233/Express0053.lzma.bak
2020-09-29T19:53:47.663Z,1601409227.663 [DataOverHttps](INFO): SBD MOMSN=41172
2020-09-29T19:53:57.706Z,1601409237.706 [DataOverHttps](INFO): Sending 888 bytes from file Logs/20200929T193146/Express0001.lzma
2020-09-29T19:53:58.706Z,1601409238.706 [DataOverHttps](INFO): Moved sent file to Logs/20200929T193146/Express0001.lzma.bak
2020-09-29T19:53:58.706Z,1601409238.706 [DataOverHttps](INFO): SBD MOMSN=41174
2020-09-29T19:54:07.745Z,1601409247.745 [DataOverHttps](INFO): Sending 440 bytes from file Logs/20200929T193146/Express0005.lzma
2020-09-29T19:54:08.746Z,1601409248.746 [DataOverHttps](INFO): Moved sent file to Logs/20200929T193146/Express0005.lzma.bak
2020-09-29T19:54:08.747Z,1601409248.747 [DataOverHttps](INFO): SBD MOMSN=41176
2020-09-29T19:54:10.092Z,1601409250.092 [DefaultWithUndock:CheckIn:Read_Iridium] Stopped
2020-09-29T19:54:10.109Z,1601409250.109 [DefaultWithUndock:CheckIn:C.Wait] Running Loop=1
2020-09-29T19:54:10.109Z,1601409250.109 [DefaultWithUndock:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-09-29T19:54:38.002Z,1601409278.002 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2020-09-29T19:55:34.125Z,1601409334.125 [RDI_Pathfinder](ERROR): DVL uart error: serial timeout
2020-09-29T19:55:34.125Z,1601409334.125 [RDI_Pathfinder] Communications Fault, FailCount= 1
2020-09-29T19:55:34.125Z,1601409334.125 [RDI_Pathfinder](ERROR): Communications Fault
2020-09-29T19:55:34.190Z,1601409334.190 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder
2020-09-29T19:55:34.581Z,1601409334.581 [RDI_Pathfinder](INFO): Powering down
2020-09-29T19:55:35.336Z,1601409335.336 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2020-09-29T19:55:35.336Z,1601409335.336 [RDI_Pathfinder] No Fault, FailCount= 1
2020-09-29T19:58:59.759Z,1601409539.759 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2020-09-29T19:59:10.687Z,1601409550.687 [DefaultWithUndock:CheckIn:C.Wait](INFO): Done Waiting.
2020-09-29T19:59:10.687Z,1601409550.687 [DefaultWithUndock:CheckIn:C.Wait] Stopped
2020-09-29T19:59:10.687Z,1601409550.687 [DefaultWithUndock:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-09-29T19:59:10.687Z,1601409550.687 [DefaultWithUndock:CheckIn:D] Running Loop=1
2020-09-29T19:59:11.081Z,1601409551.081 [DefaultWithUndock:CheckIn:D] Stopped
2020-09-29T19:59:11.081Z,1601409551.081 [DefaultWithUndock:CheckIn:E] Running Loop=1
2020-09-29T19:59:11.482Z,1601409551.482 [DefaultWithUndock:CheckIn:E](IMPORTANT): Default mission has been running for 24.760004 min 
2020-09-29T19:59:11.482Z,1601409551.482 [DefaultWithUndock:CheckIn:E] Stopped
2020-09-29T19:59:11.483Z,1601409551.483 [DefaultWithUndock:CheckIn](INFO): Completed DefaultWithUndock:CheckIn
2020-09-29T19:59:11.483Z,1601409551.483 [DefaultWithUndock:CheckIn] Stopped
2020-09-29T19:59:11.483Z,1601409551.483 [DefaultWithUndock:CheckIn](DEBUG): Aggregate::uninitialize DefaultWithUndock:CheckIn
2020-09-29T19:59:11.483Z,1601409551.483 [DefaultWithUndock:CheckIn](INFO): Running loop #2
2020-09-29T19:59:11.483Z,1601409551.483 [DefaultWithUndock:CheckIn] Running Loop=2
2020-09-29T19:59:11.483Z,1601409551.483 [DefaultWithUndock:CheckIn](DEBUG): Aggregate::initialize DefaultWithUndock:CheckIn
2020-09-29T19:59:11.483Z,1601409551.483 [DefaultWithUndock:CheckIn:Read_GPS] Running Loop=1
2020-09-29T19:59:13.480Z,1601409553.480 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,195912.00,A,4133.14393,N,07042.51698,W,2.760,337.41,290920,,,A*71
2020-09-29T19:59:13.483Z,1601409553.483 [NAL9602](INFO): GPS fix at 20200929T195912: (41.552399, -70.708616)
2020-09-29T19:59:13.493Z,1601409553.493 [DefaultWithUndock:CheckIn:Read_GPS] Stopped
2020-09-29T19:59:13.493Z,1601409553.493 [DefaultWithUndock:CheckIn:Read_Iridium] Running Loop=1
2020-09-29T19:59:18.016Z,1601409558.016 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20200929T193146/Courier0007.lzma
2020-09-29T19:59:20.022Z,1601409560.022 [DataOverHttps](INFO): Moved sent file to Logs/20200929T193146/Courier0007.lzma.bak
2020-09-29T19:59:20.023Z,1601409560.023 [DataOverHttps](INFO): SBD MOMSN=41181
2020-09-29T19:59:35.755Z,1601409575.755 [NAL9602](INFO): SBD MO Status=2, MOMSN=11395, MT Status=2, MTMSN=0
2020-09-29T19:59:35.755Z,1601409575.755 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-09-29T19:59:53.104Z,1601409593.104 [NAL9602](INFO): SBD MO Status=2, MOMSN=11395, MT Status=2, MTMSN=0
2020-09-29T19:59:53.104Z,1601409593.104 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-09-29T20:00:00.184Z,1601409600.184 [DataOverHttps](INFO): Sending 159 bytes from file Logs/20200929T193146/Express0008.lzma
2020-09-29T20:00:01.186Z,1601409601.186 [DataOverHttps](INFO): Moved sent file to Logs/20200929T193146/Express0008.lzma.bak
2020-09-29T20:00:01.186Z,1601409601.186 [DataOverHttps](INFO): SBD MOMSN=41184
2020-09-29T20:00:02.405Z,1601409602.405 [DefaultWithUndock:CheckIn:Read_Iridium] Stopped
2020-09-29T20:00:02.405Z,1601409602.405 [DefaultWithUndock:CheckIn:C.Wait] Running Loop=1
2020-09-29T20:00:02.405Z,1601409602.405 [DefaultWithUndock:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-09-29T20:00:04.816Z,1601409604.816 [NAL9602](INFO): SBD MO Status=0, MOMSN=11395, MT Status=0, MTMSN=0
2020-09-29T20:00:04.816Z,1601409604.816 [NAL9602](INFO): No messages in MT queue
2020-09-29T20:00:04.820Z,1601409604.820 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2020-09-29T20:00:35.523Z,1601409635.523 [NAL9602](INFO): Not Powering down - fast GPS
2020-09-29T20:02:26.774Z,1601409746.774 [DataOverHttps](IMPORTANT): SBD MTMSN=20200929T200225
2020-09-29T20:02:30.793Z,1601409750.793 [DataOverHttps](INFO): Received command:restart app
2020-09-29T20:02:30.853Z,1601409750.853 [CommandLine](IMPORTANT): got command restart application
2020-09-29T20:02:31.857Z,1601409751.857 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2020-09-29T20:02:31.858Z,1601409751.858 [CommandLine ThreadHandler](INFO): Thread cancelled.
2020-09-29T20:02:32.048Z,1601409752.048 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2020-09-29T20:02:32.049Z,1601409752.049 [CommandLine ThreadHandler](INFO): Thread cancelled.
2020-09-29T20:02:32.049Z,1601409752.049 [CommandLine](INFO): Join timeout helper Thread ID is 2161
2020-09-29T20:02:32.050Z,1601409752.050 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2020-09-29T20:02:32.050Z,1601409752.050 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2020-09-29T20:02:32.050Z,1601409752.050 [NavChartDb](INFO): Join timeout helper Thread ID is 2162
2020-09-29T20:02:32.061Z,1601409752.061 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2020-09-29T20:02:32.061Z,1601409752.061 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2020-09-29T20:02:32.069Z,1601409752.069 [ComponentRegistry](INFO): Shutting down WetLabsSeaOWL_UV_A ThreadHandler
2020-09-29T20:02:32.069Z,1601409752.069 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2020-09-29T20:02:32.069Z,1601409752.069 [WetLabsSeaOWL_UV_A](INFO): Join timeout helper Thread ID is 2163
2020-09-29T20:02:32.073Z,1601409752.073 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Uninitializing protected caller thread.
2020-09-29T20:02:32.073Z,1601409752.073 [WetLabsSeaOWL_UV_A](INFO): Powering down
2020-09-29T20:02:32.074Z,1601409752.074 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2020-09-29T20:02:32.089Z,1601409752.089 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2020-09-29T20:02:32.089Z,1601409752.089 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2020-09-29T20:02:32.089Z,1601409752.089 [CTD_Seabird](INFO): Join timeout helper Thread ID is 2164
2020-09-29T20:02:32.901Z,1601409752.901 [CTD_Seabird](INFO): Powering down
2020-09-29T20:02:32.913Z,1601409752.913 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2020-09-29T20:02:32.913Z,1601409752.913 [CTD_Seabird](INFO): Powering down
2020-09-29T20:02:32.925Z,1601409752.925 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2020-09-29T20:02:32.945Z,1601409752.945 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2020-09-29T20:02:32.945Z,1601409752.945 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2020-09-29T20:02:32.945Z,1601409752.945 [Radio_Surface](INFO): Join timeout helper Thread ID is 2165
2020-09-29T20:02:32.949Z,1601409752.949 [Radio_Surface](INFO): Powering down
2020-09-29T20:02:32.950Z,1601409752.950 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2020-09-29T20:02:32.950Z,1601409752.950 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2020-09-29T20:02:32.965Z,1601409752.965 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler
2020-09-29T20:02:32.966Z,1601409752.966 [Onboard ThreadHandler](INFO): Thread cancelled.
2020-09-29T20:02:32.966Z,1601409752.966 [Onboard](INFO): Join timeout helper Thread ID is 2166
2020-09-29T20:02:33.801Z,1601409753.801 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2020-09-29T20:02:34.733Z,1601409754.733 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread.
2020-09-29T20:02:34.733Z,1601409754.733 [Onboard ThreadHandler](INFO): Thread cancelled.
2020-09-29T20:02:34.737Z,1601409754.737 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2020-09-29T20:02:34.738Z,1601409754.738 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2020-09-29T20:02:34.738Z,1601409754.738 [DataOverHttps](INFO): Join timeout helper Thread ID is 2167
2020-09-29T20:02:34.805Z,1601409754.805 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2020-09-29T20:02:34.805Z,1601409754.805 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2020-09-29T20:02:34.821Z,1601409754.821 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2020-09-29T20:02:34.821Z,1601409754.821 [logger ThreadHandler](INFO): Thread cancelled.
2020-09-29T20:02:34.822Z,1601409754.822 [logger](INFO): Join timeout helper Thread ID is 2168
2020-09-29T20:02:34.853Z,1601409754.853 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2020-09-29T20:02:34.854Z,1601409754.854 [logger ThreadHandler](INFO): Thread cancelled.
2020-09-29T20:02:34.863Z,1601409754.863 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2020-09-29T20:02:34.863Z,1601409754.863 [CommandLine ThreadHandler](INFO): Thread cancelled.
2020-09-29T20:02:34.863Z,1601409754.863 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2020-09-29T20:02:34.864Z,1601409754.864 [controlThread ThreadHandler](INFO): Thread cancelled.
2020-09-29T20:02:34.865Z,1601409754.865 [controlThread](INFO): Join timeout helper Thread ID is 2169
2020-09-29T20:02:35.085Z,1601409755.085 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2020-09-29T20:02:35.085Z,1601409755.085 [controlThread](DEBUG): Uninitializing ControlThread
2020-09-29T20:02:35.085Z,1601409755.085 [AHRS_M2](INFO): Powering down
2020-09-29T20:02:35.157Z,1601409755.157 [DDM](INFO): Powering down
2020-09-29T20:02:35.229Z,1601409755.229 [DUSBL_Hydroid](INFO): Powering down
2020-09-29T20:02:35.301Z,1601409755.301 [Micromodem](INFO): Powering down
2020-09-29T20:02:35.397Z,1601409755.397 [NAL9602](INFO): Powering down
2020-09-29T20:02:35.469Z,1601409755.469 [RDI_Pathfinder](INFO): Powering down
2020-09-29T20:02:35.541Z,1601409755.541 [RDI_PathfinderUp](INFO): Powering down
2020-09-29T20:02:35.542Z,1601409755.542 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2020-09-29T20:02:35.543Z,1601409755.543 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2020-09-29T20:02:35.544Z,1601409755.544 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2020-09-29T20:02:35.544Z,1601409755.544 [MissionManager](INFO): Uninitializing Mission DefaultWithUndock
2020-09-29T20:02:35.544Z,1601409755.544 [DefaultWithUndock] Stopped
2020-09-29T20:02:35.545Z,1601409755.545 [DefaultWithUndock](DEBUG): Aggregate::uninitialize DefaultWithUndock
2020-09-29T20:02:35.545Z,1601409755.545 [DefaultWithUndock:C.GoToSurface] Stopped
2020-09-29T20:02:35.545Z,1601409755.545 [DefaultWithUndock:C.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2020-09-29T20:02:35.545Z,1601409755.545 [DefaultWithUndock:CheckIn] Stopped
2020-09-29T20:02:35.545Z,1601409755.545 [DefaultWithUndock:CheckIn](DEBUG): Aggregate::uninitialize DefaultWithUndock:CheckIn
2020-09-29T20:02:35.545Z,1601409755.545 [DefaultWithUndock:CheckIn:C.Wait] Stopped
2020-09-29T20:02:35.545Z,1601409755.545 [DefaultWithUndock:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-09-29T20:02:35.548Z,1601409755.548 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2020-09-29T20:02:35.549Z,1601409755.549 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2020-09-29T20:02:35.549Z,1601409755.549 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2020-09-29T20:02:35.549Z,1601409755.549 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2020-09-29T20:02:35.550Z,1601409755.550 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2020-09-29T20:02:35.550Z,1601409755.550 [BuoyancyServo](INFO): Powering down
2020-09-29T20:02:35.561Z,1601409755.561 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2020-09-29T20:02:35.561Z,1601409755.561 [ElevatorServo](INFO): Powering down
2020-09-29T20:02:35.562Z,1601409755.562 [MassServo](DEBUG): Uninitialize Mass Servo.
2020-09-29T20:02:35.562Z,1601409755.562 [MassServo](INFO): Powering down
2020-09-29T20:02:35.562Z,1601409755.562 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2020-09-29T20:02:35.563Z,1601409755.563 [RudderServo](INFO): Powering down
2020-09-29T20:02:35.563Z,1601409755.563 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2020-09-29T20:02:35.563Z,1601409755.563 [ThrusterServo](INFO): Powering down
2020-09-29T20:02:35.564Z,1601409755.564 [SBIT](DEBUG): Uninitialize SBIT Component.
2020-09-29T20:02:35.565Z,1601409755.565 [IBIT](DEBUG): Uninitialize IBIT Component.
2020-09-29T20:02:35.565Z,1601409755.565 [CBIT](DEBUG): Uninitialize CBIT Component.
2020-09-29T20:02:35.565Z,1601409755.565 [CBIT](DEBUG): Powering off loads.
2020-09-29T20:02:35.576Z,1601409755.576 [CBIT](DEBUG): Disabling WDT.
2020-09-29T20:02:35.588Z,1601409755.588 [CBIT](DEBUG): Opening all GF detection circuits.
2020-09-29T20:02:35.589Z,1601409755.589 [controlThread ThreadHandler](INFO): Thread cancelled.
2020-09-29T20:02:35.645Z,1601409755.645 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2020-09-29T20:02:35.648Z,1601409755.648 [Onboard ThreadHandler](INFO): Thread cancelled.
2020-09-29T20:02:35.657Z,1601409755.657 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2020-09-29T20:02:35.703Z,1601409755.703 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2020-09-29T20:02:35.706Z,1601409755.706 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2020-09-29T20:02:35.764Z,1601409755.764 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2020-09-29T20:02:35.833Z,1601409755.833 [logger ThreadHandler](INFO): Thread cancelled.