2020-08-25T15:09:54.112Z,1598368194.112 [Supervisor](DEBUG): Initializing supervisor.
2020-08-25T15:09:54.114Z,1598368194.114 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2020-08-25T15:09:54.115Z,1598368194.115 [SyncHandler](INFO): Protected caller Thread ID is 716
2020-08-25T15:09:54.115Z,1598368194.115 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2020-08-25T15:09:54.116Z,1598368194.116 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2020-08-25T15:09:54.116Z,1598368194.116 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 717
2020-08-25T15:09:54.119Z,1598368194.119 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2020-08-25T15:09:54.132Z,1598368194.132 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2020-08-25T15:09:54.133Z,1598368194.133 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2020-08-25T15:09:54.133Z,1598368194.133 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 718
2020-08-25T15:09:54.134Z,1598368194.134 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2020-08-25T15:09:54.135Z,1598368194.135 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2020-08-25T15:09:54.135Z,1598368194.135 [logger ThreadHandler](INFO): Protected caller Thread ID is 719
2020-08-25T15:09:54.137Z,1598368194.137 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2020-08-25T15:09:54.137Z,1598368194.137 [Supervisor](INFO): Looking for Config files in directory: Config/
2020-08-25T15:09:54.139Z,1598368194.139 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2020-08-25T15:09:54.233Z,1598368194.233 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2020-08-25T15:09:54.233Z,1598368194.233 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2020-08-25T15:09:54.805Z,1598368194.805 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2020-08-25T15:09:54.805Z,1598368194.805 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2020-08-25T15:09:54.995Z,1598368194.995 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2020-08-25T15:09:54.995Z,1598368194.995 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2020-08-25T15:09:55.097Z,1598368195.097 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2020-08-25T15:09:55.097Z,1598368195.097 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2020-08-25T15:09:55.201Z,1598368195.201 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2020-08-25T15:09:55.201Z,1598368195.201 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2020-08-25T15:09:55.282Z,1598368195.282 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2020-08-25T15:09:55.421Z,1598368195.421 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2020-08-25T15:09:55.421Z,1598368195.421 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2020-08-25T15:09:55.709Z,1598368195.709 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2020-08-25T15:09:55.709Z,1598368195.709 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2020-08-25T15:09:56.171Z,1598368196.171 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2020-08-25T15:09:56.172Z,1598368196.172 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2020-08-25T15:09:56.319Z,1598368196.319 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2020-08-25T15:09:56.319Z,1598368196.319 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2020-08-25T15:09:56.508Z,1598368196.508 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2020-08-25T15:09:56.508Z,1598368196.508 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2020-08-25T15:09:57.058Z,1598368197.058 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2020-08-25T15:09:57.059Z,1598368197.059 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2020-08-25T15:09:57.272Z,1598368197.272 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2020-08-25T15:09:57.272Z,1598368197.272 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2020-08-25T15:09:57.471Z,1598368197.471 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2020-08-25T15:09:57.472Z,1598368197.472 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2020-08-25T15:09:57.878Z,1598368197.878 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2020-08-25T15:09:57.879Z,1598368197.879 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2020-08-25T15:09:58.202Z,1598368198.202 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2020-08-25T15:09:58.204Z,1598368198.204 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-pontus/
2020-08-25T15:09:58.205Z,1598368198.205 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/secure.cfg
2020-08-25T15:09:58.289Z,1598368198.289 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Sensor.cfg
2020-08-25T15:09:58.447Z,1598368198.447 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Servo.cfg
2020-08-25T15:09:58.555Z,1598368198.555 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Simulator.cfg
2020-08-25T15:09:58.640Z,1598368198.640 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/logger.cfg
2020-08-25T15:09:58.734Z,1598368198.734 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/vehicle.cfg
2020-08-25T15:09:58.969Z,1598368198.969 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Battery.cfg
2020-08-25T15:09:59.287Z,1598368199.287 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2020-08-25T15:09:59.287Z,1598368199.287 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Navigation.cfg
2020-08-25T15:09:59.451Z,1598368199.451 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/BIT.cfg
2020-08-25T15:09:59.739Z,1598368199.739 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Science.cfg
2020-08-25T15:09:59.941Z,1598368199.941 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Control.cfg
2020-08-25T15:10:00.176Z,1598368200.176 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg
2020-08-25T15:10:00.177Z,1598368200.177 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2020-08-25T15:10:00.251Z,1598368200.251 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2020-08-25T15:10:00.252Z,1598368200.252 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2020-08-25T15:10:00.296Z,1598368200.296 [VerticalControl](DEBUG): Construct VerticalControl.
2020-08-25T15:10:00.403Z,1598368200.403 [VerticalControl] Loaded
2020-08-25T15:10:00.403Z,1598368200.403 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2020-08-25T15:10:00.404Z,1598368200.404 [HorizontalControl](DEBUG): Construct HorizontalControl.
2020-08-25T15:10:00.480Z,1598368200.480 [HorizontalControl] Loaded
2020-08-25T15:10:00.480Z,1598368200.480 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2020-08-25T15:10:00.481Z,1598368200.481 [SpeedControl](DEBUG): Construct SpeedControl.
2020-08-25T15:10:00.486Z,1598368200.486 [SpeedControl] Loaded
2020-08-25T15:10:00.486Z,1598368200.486 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2020-08-25T15:10:00.487Z,1598368200.487 [LoopControl](DEBUG): Construct LoopControl.
2020-08-25T15:10:00.487Z,1598368200.487 [LoopControl] Loaded
2020-08-25T15:10:00.487Z,1598368200.487 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2020-08-25T15:10:00.488Z,1598368200.488 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2020-08-25T15:10:00.488Z,1598368200.488 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2020-08-25T15:10:00.527Z,1598368200.527 [DepthRateCalculator] Loaded
2020-08-25T15:10:00.527Z,1598368200.527 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2020-08-25T15:10:00.532Z,1598368200.532 [PitchRateCalculator] Loaded
2020-08-25T15:10:00.532Z,1598368200.532 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2020-08-25T15:10:00.547Z,1598368200.547 [SpeedCalculator] Loaded
2020-08-25T15:10:00.547Z,1598368200.547 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2020-08-25T15:10:00.567Z,1598368200.567 [TempGradientCalculator] Loaded
2020-08-25T15:10:00.567Z,1598368200.567 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2020-08-25T15:10:00.572Z,1598368200.572 [YawRateCalculator] Loaded
2020-08-25T15:10:00.572Z,1598368200.572 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2020-08-25T15:10:00.600Z,1598368200.600 [ElevatorOffsetCalculator] Loaded
2020-08-25T15:10:00.600Z,1598368200.600 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2020-08-25T15:10:00.601Z,1598368200.601 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2020-08-25T15:10:00.601Z,1598368200.601 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2020-08-25T15:10:00.626Z,1598368200.626 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2020-08-25T15:10:00.627Z,1598368200.627 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2020-08-25T15:10:00.706Z,1598368200.706 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2020-08-25T15:10:00.707Z,1598368200.707 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2020-08-25T15:10:00.978Z,1598368200.978 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2020-08-25T15:10:00.978Z,1598368200.978 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2020-08-25T15:10:01.071Z,1598368201.071 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2020-08-25T15:10:01.072Z,1598368201.072 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2020-08-25T15:10:01.375Z,1598368201.375 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_orientation
2020-08-25T15:10:01.380Z,1598368201.380 [AHRS_M2](INFO): created writer for : platform_orientation
2020-08-25T15:10:01.381Z,1598368201.381 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_magnetic_orientation
2020-08-25T15:10:01.386Z,1598368201.386 [AHRS_M2](INFO): created writer for : platform_magnetic_orientation
2020-08-25T15:10:01.387Z,1598368201.387 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_pitch_angle
2020-08-25T15:10:01.391Z,1598368201.391 [AHRS_M2](INFO): created writer for : platform_pitch_angle
2020-08-25T15:10:01.392Z,1598368201.392 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_roll_angle
2020-08-25T15:10:01.397Z,1598368201.397 [AHRS_M2](INFO): created writer for : platform_roll_angle
2020-08-25T15:10:01.465Z,1598368201.465 [AHRS_M2] Loaded
2020-08-25T15:10:01.465Z,1598368201.465 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2020-08-25T15:10:01.541Z,1598368201.541 [DataOverHttps] Loaded
2020-08-25T15:10:01.541Z,1598368201.541 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2020-08-25T15:10:01.542Z,1598368201.542 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4090D4E0
2020-08-25T15:10:01.543Z,1598368201.543 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 809
2020-08-25T15:10:01.572Z,1598368201.572 [Depth_Keller] Loaded
2020-08-25T15:10:01.572Z,1598368201.572 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2020-08-25T15:10:01.576Z,1598368201.576 [DropWeight] Loaded
2020-08-25T15:10:01.577Z,1598368201.577 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2020-08-25T15:10:01.684Z,1598368201.684 [NAL9602] Loaded
2020-08-25T15:10:01.684Z,1598368201.684 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2020-08-25T15:10:01.731Z,1598368201.731 [Onboard] Loaded
2020-08-25T15:10:01.731Z,1598368201.731 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2020-08-25T15:10:01.732Z,1598368201.732 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 4093D4E0
2020-08-25T15:10:01.732Z,1598368201.732 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 810
2020-08-25T15:10:01.751Z,1598368201.751 [Radio_Surface] Loaded
2020-08-25T15:10:01.751Z,1598368201.751 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2020-08-25T15:10:01.752Z,1598368201.752 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4096D4E0
2020-08-25T15:10:01.752Z,1598368201.752 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 811
2020-08-25T15:10:01.809Z,1598368201.809 [RDI_Pathfinder] Loaded
2020-08-25T15:10:01.809Z,1598368201.809 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread.
2020-08-25T15:10:01.832Z,1598368201.832 [DAT](CRITICAL): No configuration setting for: DAT.maxAckTimeouts
2020-08-25T15:10:01.954Z,1598368201.954 [DAT] Loaded
2020-08-25T15:10:01.954Z,1598368201.954 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread.
2020-08-25T15:10:03.388Z,1598368203.388 [BPC1] Loaded
2020-08-25T15:10:03.389Z,1598368203.389 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2020-08-25T15:10:03.419Z,1598368203.419 [AMEcho](CRITICAL): No configuration setting for: AMEcho.enabled
2020-08-25T15:10:03.421Z,1598368203.421 [AMEcho] Loaded
2020-08-25T15:10:03.421Z,1598368203.421 [ComponentRegistry](DEBUG): SyncComponent "AMEcho" handled in the control thread.
2020-08-25T15:10:03.422Z,1598368203.422 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2020-08-25T15:10:03.422Z,1598368203.422 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2020-08-25T15:10:03.532Z,1598368203.532 [DeadReckonUsingMultipleVelocitySources] Loaded
2020-08-25T15:10:03.532Z,1598368203.532 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2020-08-25T15:10:03.551Z,1598368203.551 [NavChart] Loaded
2020-08-25T15:10:03.552Z,1598368203.552 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2020-08-25T15:10:03.555Z,1598368203.555 [UniversalFixResidualReporter] Loaded
2020-08-25T15:10:03.556Z,1598368203.556 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2020-08-25T15:10:03.556Z,1598368203.556 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2020-08-25T15:10:03.557Z,1598368203.557 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2020-08-25T15:10:03.682Z,1598368203.682 [SBIT](DEBUG): Construct Startup Built In Test.
2020-08-25T15:10:03.693Z,1598368203.693 [SBIT] Loaded
2020-08-25T15:10:03.693Z,1598368203.693 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2020-08-25T15:10:03.694Z,1598368203.694 [IBIT](DEBUG): Construct Initiated Built In Test.
2020-08-25T15:10:03.706Z,1598368203.706 [IBIT] Loaded
2020-08-25T15:10:03.706Z,1598368203.706 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2020-08-25T15:10:03.709Z,1598368203.709 [CBIT](DEBUG): Construct Continuous Built In Test.
2020-08-25T15:10:03.842Z,1598368203.842 [CBIT] Loaded
2020-08-25T15:10:03.842Z,1598368203.842 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2020-08-25T15:10:03.843Z,1598368203.843 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2020-08-25T15:10:03.843Z,1598368203.843 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2020-08-25T15:10:03.958Z,1598368203.958 [BuoyancyServo] Loaded
2020-08-25T15:10:03.959Z,1598368203.959 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2020-08-25T15:10:03.986Z,1598368203.986 [ElevatorServo] Loaded
2020-08-25T15:10:03.986Z,1598368203.986 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2020-08-25T15:10:04.013Z,1598368204.013 [MassServo] Loaded
2020-08-25T15:10:04.014Z,1598368204.014 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2020-08-25T15:10:04.040Z,1598368204.040 [RudderServo] Loaded
2020-08-25T15:10:04.040Z,1598368204.040 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2020-08-25T15:10:04.066Z,1598368204.066 [ThrusterServo] Loaded
2020-08-25T15:10:04.066Z,1598368204.066 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2020-08-25T15:10:04.066Z,1598368204.066 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2020-08-25T15:10:04.067Z,1598368204.067 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2020-08-25T15:10:04.126Z,1598368204.126 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2020-08-25T15:10:04.142Z,1598368204.142 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2020-08-25T15:10:04.439Z,1598368204.439 [BackSeatDriver] Loaded
2020-08-25T15:10:04.439Z,1598368204.439 [ComponentRegistry](DEBUG): Component "BackSeatDriver" handled in its own thread.
2020-08-25T15:10:04.440Z,1598368204.440 [BackSeatDriver ThreadHandler](DEBUG): Created PCaller Thread at 40B034E0
2020-08-25T15:10:04.440Z,1598368204.440 [BackSeatDriver ThreadHandler](INFO): Protected caller Thread ID is 812
2020-08-25T15:10:04.469Z,1598368204.469 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_density
2020-08-25T15:10:04.474Z,1598368204.474 [CTD_Seabird](INFO): created writer for : sea_water_density
2020-08-25T15:10:04.475Z,1598368204.475 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): depth
2020-08-25T15:10:04.479Z,1598368204.479 [CTD_Seabird](INFO): created writer for : depth
2020-08-25T15:10:04.480Z,1598368204.480 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_pressure
2020-08-25T15:10:04.484Z,1598368204.484 [CTD_Seabird](INFO): created writer for : sea_water_pressure
2020-08-25T15:10:04.485Z,1598368204.485 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_salinity
2020-08-25T15:10:04.490Z,1598368204.490 [CTD_Seabird](INFO): created writer for : sea_water_salinity
2020-08-25T15:10:04.490Z,1598368204.490 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_temperature
2020-08-25T15:10:04.495Z,1598368204.495 [CTD_Seabird](INFO): created writer for : sea_water_temperature
2020-08-25T15:10:04.496Z,1598368204.496 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_electrical_conductivity
2020-08-25T15:10:04.501Z,1598368204.501 [CTD_Seabird](INFO): created writer for : sea_water_electrical_conductivity
2020-08-25T15:10:04.502Z,1598368204.502 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): speed_of_sound_in_sea_water
2020-08-25T15:10:04.507Z,1598368204.507 [CTD_Seabird](INFO): created writer for : speed_of_sound_in_sea_water
2020-08-25T15:10:04.533Z,1598368204.533 [CTD_Seabird] Loaded
2020-08-25T15:10:04.533Z,1598368204.533 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2020-08-25T15:10:04.534Z,1598368204.534 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40B334E0
2020-08-25T15:10:04.534Z,1598368204.534 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 813
2020-08-25T15:10:04.556Z,1598368204.556 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.Output470
2020-08-25T15:10:04.556Z,1598368204.556 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: Output470
2020-08-25T15:10:04.560Z,1598368204.560 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.Output650
2020-08-25T15:10:04.560Z,1598368204.560 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: Output650
2020-08-25T15:10:04.564Z,1598368204.564 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.OutputChl
2020-08-25T15:10:04.564Z,1598368204.564 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: OutputChl
2020-08-25T15:10:04.568Z,1598368204.568 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.VolumeScatCoeff117deg470nm
2020-08-25T15:10:04.568Z,1598368204.568 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: VolumeScatCoeff117deg470nm
2020-08-25T15:10:04.573Z,1598368204.573 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.VolumeScatCoeff117deg650nm
2020-08-25T15:10:04.573Z,1598368204.573 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: VolumeScatCoeff117deg650nm
2020-08-25T15:10:04.577Z,1598368204.577 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.BackscatteringCoeff470nm
2020-08-25T15:10:04.577Z,1598368204.577 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: BackscatteringCoeff470nm
2020-08-25T15:10:04.581Z,1598368204.581 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.BackscatteringCoeff650nm
2020-08-25T15:10:04.581Z,1598368204.581 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: BackscatteringCoeff650nm
2020-08-25T15:10:04.586Z,1598368204.586 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): mass_concentration_of_chlorophyll_in_sea_water
2020-08-25T15:10:04.590Z,1598368204.590 [WetLabsBB2FL](INFO): created writer for : mass_concentration_of_chlorophyll_in_sea_water
2020-08-25T15:10:04.591Z,1598368204.591 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_median_mass_concentration_of_chlorophyll_in_sea_water
2020-08-25T15:10:04.591Z,1598368204.591 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_median_mass_concentration_of_chlorophyll_in_sea_water
2020-08-25T15:10:04.595Z,1598368204.595 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water
2020-08-25T15:10:04.595Z,1598368204.595 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_mean_mass_concentration_of_chlorophyll_in_sea_water
2020-08-25T15:10:04.599Z,1598368204.599 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_variance_mass_concentration_of_chlorophyll_in_sea_water
2020-08-25T15:10:04.599Z,1598368204.599 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_variance_mass_concentration_of_chlorophyll_in_sea_water
2020-08-25T15:10:04.603Z,1598368204.603 [WetLabsBB2FL] Loaded
2020-08-25T15:10:04.604Z,1598368204.604 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2020-08-25T15:10:04.605Z,1598368204.605 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40B634E0
2020-08-25T15:10:04.605Z,1598368204.605 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 814
2020-08-25T15:10:04.641Z,1598368204.641 [WetLabsUBAT..SerialDriver](INFO): Created logger
2020-08-25T15:10:04.642Z,1598368204.642 [WetLabsUBAT..SerialDriver](INFO): publishing on LCM channel WetLabsUBAT
2020-08-25T15:10:04.642Z,1598368204.642 [WetLabsUBAT..StreamSerialDriver](INFO): Created logger
2020-08-25T15:10:04.689Z,1598368204.689 [WetLabsUBAT](CRITICAL): No configuration setting for: WetLabsUBAT.optionalArgs
2020-08-25T15:10:04.691Z,1598368204.691 [WetLabsUBAT](CRITICAL): No configuration setting for: WetLabsUBAT.emulateHardware
2020-08-25T15:10:04.693Z,1598368204.693 [WetLabsUBAT](INFO): readConfig(): serialNo_: UBAT0051, uartName_: /dev/ttyC1, optionalArgs_: UBAT0051
2020-08-25T15:10:04.693Z,1598368204.693 [WetLabsUBAT](CRITICAL): Error loading configuration parameters during WetLabsUBAT::start()
2020-08-25T15:10:04.693Z,1598368204.693 [WetLabsUBAT] Data Fault, FailCount= 1
2020-08-25T15:10:04.693Z,1598368204.693 [WetLabsUBAT](ERROR): Data Fault
2020-08-25T15:10:04.693Z,1598368204.693 [WetLabsUBAT](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsUBAT.biolum_potential
2020-08-25T15:10:04.693Z,1598368204.693 [WetLabsUBAT](DEBUG): LcmSlateWriter::add(): dataName: biolum_potential
2020-08-25T15:10:04.697Z,1598368204.697 [WetLabsUBAT](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsUBAT.flow_rate
2020-08-25T15:10:04.697Z,1598368204.697 [WetLabsUBAT](DEBUG): LcmSlateWriter::add(): dataName: flow_rate
2020-08-25T15:10:04.703Z,1598368204.703 [WetLabsUBAT] Loaded
2020-08-25T15:10:04.703Z,1598368204.703 [ComponentRegistry](DEBUG): Component "WetLabsUBAT" handled in its own thread.
2020-08-25T15:10:04.704Z,1598368204.704 [WetLabsUBAT ThreadHandler](DEBUG): Created PCaller Thread at 40B934E0
2020-08-25T15:10:04.704Z,1598368204.704 [WetLabsUBAT ThreadHandler](INFO): Protected caller Thread ID is 815
2020-08-25T15:10:04.705Z,1598368204.705 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2020-08-25T15:10:04.709Z,1598368204.709 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2020-08-25T15:10:04.709Z,1598368204.709 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2020-08-25T15:10:04.716Z,1598368204.716 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2020-08-25T15:10:04.717Z,1598368204.717 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40BC34E0
2020-08-25T15:10:04.717Z,1598368204.717 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 816
2020-08-25T15:10:04.722Z,1598368204.722 [Supervisor](INFO): Main Thread ID is 715
2020-08-25T15:10:04.722Z,1598368204.722 [Supervisor](DEBUG): Running supervisor.
2020-08-25T15:10:04.723Z,1598368204.723 [CommandLine ThreadHandler](INFO): Handler Thread ID is 817
2020-08-25T15:10:04.728Z,1598368204.728 [controlThread ThreadHandler](INFO): Handler Thread ID is 818
2020-08-25T15:10:04.728Z,1598368204.728 [controlThread](DEBUG): Initializing ControlThread
2020-08-25T15:10:04.729Z,1598368204.729 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2020-08-25T15:10:04.731Z,1598368204.731 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2020-08-25T15:10:04.732Z,1598368204.732 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2020-08-25T15:10:04.732Z,1598368204.732 [LoopControl](DEBUG): Initialize LoopControlComponent.
2020-08-25T15:10:04.732Z,1598368204.732 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2020-08-25T15:10:04.733Z,1598368204.733 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2020-08-25T15:10:04.733Z,1598368204.733 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2020-08-25T15:10:04.733Z,1598368204.733 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2020-08-25T15:10:04.734Z,1598368204.734 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2020-08-25T15:10:04.734Z,1598368204.734 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2020-08-25T15:10:04.741Z,1598368204.741 [NavChart](DEBUG): Initialize NavChart Navigation.
2020-08-25T15:10:04.742Z,1598368204.742 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2020-08-25T15:10:04.742Z,1598368204.742 [SBIT](INFO): Initialize SBIT Component.
2020-08-25T15:10:04.742Z,1598368204.742 [SBIT](IMPORTANT): git: 2020-08-18a-31-gbd628322e
2020-08-25T15:10:04.743Z,1598368204.743 [SBIT](INFO): git hash: bd628322e6debfac9e6880a33269f73ad5816ff1
2020-08-25T15:10:04.743Z,1598368204.743 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2020-08-25T15:10:04.744Z,1598368204.744 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #1 PREEMPT Thu Feb 21 11:17:40 PST 2019
Kernel Reported: #1 PREEMPT Thu Aug 6 12:04:53 PDT 2020
2020-08-25T15:10:04.745Z,1598368204.745 [SBIT](INFO): Beginning SBIT in 39.000000 seconds.
2020-08-25T15:10:04.746Z,1598368204.746 [IBIT](INFO): Initialize IBIT Component.
2020-08-25T15:10:04.747Z,1598368204.747 [CBIT](DEBUG): Initialize CBIT Component.
2020-08-25T15:10:04.748Z,1598368204.748 [logger ThreadHandler](INFO): Handler Thread ID is 820
2020-08-25T15:10:04.758Z,1598368204.758 [CBIT](DEBUG): Initialized mux pins.
2020-08-25T15:10:04.758Z,1598368204.758 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL.
2020-08-25T15:10:04.759Z,1598368204.759 [CBIT](DEBUG): Initializing the watchdog timer.
2020-08-25T15:10:04.767Z,1598368204.767 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 821
2020-08-25T15:10:04.768Z,1598368204.768 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2020-08-25T15:10:04.779Z,1598368204.779 [Onboard ThreadHandler](INFO): Handler Thread ID is 822
2020-08-25T15:10:04.783Z,1598368204.783 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2020-08-25T15:10:04.783Z,1598368204.783 [CBIT](DEBUG): Initializing heartbeat.
2020-08-25T15:10:04.797Z,1598368204.797 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 823
2020-08-25T15:10:04.816Z,1598368204.816 [BackSeatDriver ThreadHandler](INFO): Handler Thread ID is 824
2020-08-25T15:10:04.827Z,1598368204.827 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 825
2020-08-25T15:10:04.827Z,1598368204.827 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2020-08-25T15:10:04.832Z,1598368204.832 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 827
2020-08-25T15:10:04.833Z,1598368204.833 [WetLabsBB2FL](INFO): Powering down
2020-08-25T15:10:04.843Z,1598368204.843 [WetLabsUBAT ThreadHandler](INFO): Handler Thread ID is 828
2020-08-25T15:10:04.851Z,1598368204.851 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 829
2020-08-25T15:10:04.854Z,1598368204.854 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2020-08-25T15:10:04.854Z,1598368204.854 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2020-08-25T15:10:04.854Z,1598368204.854 [CBIT](DEBUG): Deactivating GF circuits.
2020-08-25T15:10:04.854Z,1598368204.854 [CBIT](DEBUG): Deactivating emergency mode.
2020-08-25T15:10:04.855Z,1598368204.855 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2020-08-25T15:10:04.855Z,1598368204.855 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2020-08-25T15:10:04.855Z,1598368204.855 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2020-08-25T15:10:04.855Z,1598368204.855 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2020-08-25T15:10:04.855Z,1598368204.855 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2020-08-25T15:10:04.856Z,1598368204.856 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2020-08-25T15:10:04.856Z,1598368204.856 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2020-08-25T15:10:04.856Z,1598368204.856 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2020-08-25T15:10:04.856Z,1598368204.856 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2020-08-25T15:10:04.856Z,1598368204.856 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2020-08-25T15:10:04.856Z,1598368204.856 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2020-08-25T15:10:04.857Z,1598368204.857 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2020-08-25T15:10:04.857Z,1598368204.857 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2020-08-25T15:10:04.857Z,1598368204.857 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2020-08-25T15:10:04.890Z,1598368204.890 [CBIT](DEBUG): Backplane powered.
2020-08-25T15:10:04.892Z,1598368204.892 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2020-08-25T15:10:04.902Z,1598368204.902 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2020-08-25T15:10:04.913Z,1598368204.913 [MissionManager](DEBUG):
2020-08-25T15:10:04.913Z,1598368204.913 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2020-08-25T15:10:04.984Z,1598368204.984 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2020-08-25T15:10:04.985Z,1598368204.985 [Default:A.Wait](DEBUG): Construct Wait.
2020-08-25T15:10:05.003Z,1598368205.003 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2020-08-25T15:10:05.030Z,1598368205.030 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2020-08-25T15:10:05.032Z,1598368205.032 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2020-08-25T15:10:05.050Z,1598368205.050 [Default:E.Execute](DEBUG): Construct Execute.
2020-08-25T15:10:05.053Z,1598368205.053 [MissionManager](DEBUG):
0
Wait a moment to see if the scheduler starts a new mission before
starting to actually run Default.
13
Burn on
Dropped weight due to communications timeout.
5
Default mission has been running for
Restarting logs and Default mission.
restart logs
2020-08-25T15:10:05.066Z,1598368205.066 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,NAL9602,RDI_Pathfinder,DAT,BPC1,AMEcho,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2020-08-25T15:10:05.097Z,1598368205.097 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2020-08-25T15:10:05.128Z,1598368205.128 [Depth_Keller](ERROR): Pressure reading out of range: 1650.297119 decibar
2020-08-25T15:10:05.137Z,1598368205.137 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2
2020-08-25T15:10:05.137Z,1598368205.137 [DAT](INFO): Powering up
2020-08-25T15:10:05.138Z,1598368205.138 [DAT](DEBUG): Initializing DAT.
2020-08-25T15:10:05.195Z,1598368205.195 [AMEcho](INFO): Powering up
2020-08-25T15:10:05.203Z,1598368205.203 [Radio_Surface](INFO): Powering up
2020-08-25T15:10:05.211Z,1598368205.211 [DepthRateCalculator](ERROR): Depth measurement is not active
2020-08-25T15:10:05.227Z,1598368205.227 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2
2020-08-25T15:10:05.269Z,1598368205.269 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2020-08-25T15:10:05.283Z,1598368205.283 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2020-08-25T15:10:05.284Z,1598368205.284 [ElevatorServo](DEBUG): Initializing EZServoServo.
2020-08-25T15:10:05.303Z,1598368205.303 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2020-08-25T15:10:05.304Z,1598368205.304 [MassServo](DEBUG): Initializing EZServoServo.
2020-08-25T15:10:05.315Z,1598368205.315 [MassServo](DEBUG): Initializing MassServo.
2020-08-25T15:10:05.316Z,1598368205.316 [RudderServo](DEBUG): Initializing EZServoServo.
2020-08-25T15:10:05.327Z,1598368205.327 [RudderServo](DEBUG): Initializing RudderServo.
2020-08-25T15:10:05.328Z,1598368205.328 [ThrusterServo](DEBUG): Initializing EZServoServo.
2020-08-25T15:10:05.339Z,1598368205.339 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2020-08-25T15:10:05.341Z,1598368205.341 [CommandLine](FAULT): Scheduling is paused
2020-08-25T15:10:05.342Z,1598368205.342 [CBIT](INFO): Critical error at 20200825T151004
2020-08-25T15:10:05.342Z,1598368205.342 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2020-08-25T15:10:05.346Z,1598368205.346 [CBIT](ERROR): Data Fault in component: WetLabsUBAT
2020-08-25T15:10:05.346Z,1598368205.346 [CBIT](INFO): Clearing failed state for component WetLabsUBAT
2020-08-25T15:10:05.346Z,1598368205.346 [WetLabsUBAT] No Fault, FailCount= 1
2020-08-25T15:10:05.519Z,1598368205.519 [DropWeight](CRITICAL): DROP WEIGHT MISSING.
2020-08-25T15:10:05.519Z,1598368205.519 [DropWeight] Hardware Fault, FailCount= 1
2020-08-25T15:10:05.519Z,1598368205.519 [DropWeight](ERROR): Hardware Fault
2020-08-25T15:10:05.535Z,1598368205.535 [DepthRateCalculator](ERROR): Depth measurement is not active
2020-08-25T15:10:05.550Z,1598368205.550 [CBIT](INFO): Critical error at 20200825T151005
2020-08-25T15:10:05.552Z,1598368205.552 [CBIT](ERROR): Hardware Fault in component: DropWeight
2020-08-25T15:10:05.553Z,1598368205.553 [CBIT](CRITICAL): Hardware Fault in component: DropWeight
2020-08-25T15:10:05.651Z,1598368205.651 [WetLabsUBAT](INFO): Initializing
2020-08-25T15:10:05.653Z,1598368205.653 [WetLabsUBAT](INFO): readConfig(): serialNo_: UBAT0051, uartName_: /dev/ttyC1, optionalArgs_: nan n/a
2020-08-25T15:10:05.653Z,1598368205.653 [WetLabsUBAT](INFO): Powering up
2020-08-25T15:10:05.653Z,1598368205.653 [WetLabsUBAT](INFO): Checking LCM
2020-08-25T15:10:05.653Z,1598368205.653 [WetLabsUBAT](INFO): LCM OK
2020-08-25T15:10:05.662Z,1598368205.662 [WetLabsUBAT](ERROR): Error configuring driver
2020-08-25T15:10:05.662Z,1598368205.662 [WetLabsUBAT] Software Fault, FailCount= 2
2020-08-25T15:10:05.662Z,1598368205.662 [WetLabsUBAT](ERROR): Software Fault
2020-08-25T15:10:06.066Z,1598368206.066 [WetLabsUBAT](INFO): Powering down
2020-08-25T15:10:06.202Z,1598368206.202 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2020-08-25T15:10:06.203Z,1598368206.203 [RudderServo](FAULT): Rudder failed to initialize
2020-08-25T15:10:06.203Z,1598368206.203 [RudderServo] Communications Fault, FailCount= 1
2020-08-25T15:10:06.203Z,1598368206.203 [RudderServo](ERROR): Communications Fault
2020-08-25T15:10:06.312Z,1598368206.312 [CBIT](INFO): Critical error at 20200825T151005
2020-08-25T15:10:06.314Z,1598368206.314 [CBIT](ERROR): Communications Fault in component: RudderServo
2020-08-25T15:10:06.315Z,1598368206.315 [CBIT](ERROR): Software Fault in component: WetLabsUBAT
2020-08-25T15:10:06.478Z,1598368206.478 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2020-08-25T15:10:06.478Z,1598368206.478 [RudderServo](INFO): Powering down
2020-08-25T15:10:07.142Z,1598368207.142 [RudderServo](DEBUG): Initializing EZServoServo.
2020-08-25T15:10:07.263Z,1598368207.263 [RudderServo](DEBUG): Initializing RudderServo.
2020-08-25T15:10:07.267Z,1598368207.267 [CBIT](INFO): Clearing failed state for component RudderServo
2020-08-25T15:10:07.268Z,1598368207.268 [RudderServo] No Fault, FailCount= 1
2020-08-25T15:10:07.268Z,1598368207.268 [CBIT](INFO): Clearing failed state for component WetLabsUBAT
2020-08-25T15:10:07.268Z,1598368207.268 [WetLabsUBAT] No Fault, FailCount= 2
2020-08-25T15:10:07.282Z,1598368207.282 [WetLabsUBAT](INFO): Initializing
2020-08-25T15:10:07.284Z,1598368207.284 [WetLabsUBAT](INFO): readConfig(): serialNo_: UBAT0051, uartName_: /dev/ttyC1, optionalArgs_: nan n/a
2020-08-25T15:10:07.284Z,1598368207.284 [WetLabsUBAT](INFO): Powering up
2020-08-25T15:10:07.285Z,1598368207.285 [WetLabsUBAT](INFO): Checking LCM
2020-08-25T15:10:07.285Z,1598368207.285 [WetLabsUBAT](INFO): LCM OK
2020-08-25T15:10:07.285Z,1598368207.285 [WetLabsUBAT](ERROR): Error configuring driver
2020-08-25T15:10:07.285Z,1598368207.285 [WetLabsUBAT] Software Fault, FailCount= 3
2020-08-25T15:10:07.286Z,1598368207.286 [WetLabsUBAT](ERROR): Software Fault
2020-08-25T15:10:07.550Z,1598368207.550 [CBIT](ERROR): Software Fault in component: WetLabsUBAT
2020-08-25T15:10:07.690Z,1598368207.690 [WetLabsUBAT](INFO): Powering down
2020-08-25T15:10:08.942Z,1598368208.942 [CBIT](INFO): Clearing failed state for component WetLabsUBAT
2020-08-25T15:10:08.942Z,1598368208.942 [WetLabsUBAT] No Fault, FailCount= 3
2020-08-25T15:10:09.307Z,1598368209.307 [WetLabsUBAT](INFO): Initializing
2020-08-25T15:10:09.308Z,1598368209.308 [WetLabsUBAT](INFO): readConfig(): serialNo_: UBAT0051, uartName_: /dev/ttyC1, optionalArgs_: nan n/a
2020-08-25T15:10:09.309Z,1598368209.309 [WetLabsUBAT](INFO): Powering up
2020-08-25T15:10:09.309Z,1598368209.309 [WetLabsUBAT](INFO): Checking LCM
2020-08-25T15:10:09.309Z,1598368209.309 [WetLabsUBAT](INFO): LCM OK
2020-08-25T15:10:09.317Z,1598368209.317 [WetLabsUBAT](ERROR): Error configuring driver
2020-08-25T15:10:09.317Z,1598368209.317 [WetLabsUBAT] Software Fault, FailCount= 4
2020-08-25T15:10:09.317Z,1598368209.317 [WetLabsUBAT](ERROR): Software Fault
2020-08-25T15:10:09.382Z,1598368209.382 [CBIT](ERROR): Software Fault in component: WetLabsUBAT
2020-08-25T15:10:09.718Z,1598368209.718 [WetLabsUBAT](INFO): Powering down
2020-08-25T15:10:10.546Z,1598368210.546 [CBIT](INFO): Clearing failed state for component WetLabsUBAT
2020-08-25T15:10:10.546Z,1598368210.546 [WetLabsUBAT] No Fault, FailCount= 4
2020-08-25T15:10:10.931Z,1598368210.931 [WetLabsUBAT](INFO): Initializing
2020-08-25T15:10:10.936Z,1598368210.936 [WetLabsUBAT](INFO): readConfig(): serialNo_: UBAT0051, uartName_: /dev/ttyC1, optionalArgs_: nan n/a
2020-08-25T15:10:10.936Z,1598368210.936 [WetLabsUBAT](INFO): Powering up
2020-08-25T15:10:10.936Z,1598368210.936 [WetLabsUBAT](INFO): Checking LCM
2020-08-25T15:10:10.936Z,1598368210.936 [WetLabsUBAT](INFO): LCM OK
2020-08-25T15:10:10.945Z,1598368210.945 [WetLabsUBAT](ERROR): Error configuring driver
2020-08-25T15:10:10.945Z,1598368210.945 [WetLabsUBAT] Software Fault, FailCount= 5
2020-08-25T15:10:10.945Z,1598368210.945 [WetLabsUBAT](ERROR): Software Fault
2020-08-25T15:10:10.954Z,1598368210.954 [CBIT](ERROR): Software Fault in component: WetLabsUBAT
2020-08-25T15:10:10.955Z,1598368210.955 [CBIT](CRITICAL): Software Fault in component: WetLabsUBAT
2020-08-25T15:10:11.346Z,1598368211.346 [WetLabsUBAT](INFO): Powering down
2020-08-25T15:10:11.400Z,1598368211.400 [CBIT](INFO): Critical error at 20200825T151010
2020-08-25T15:10:18.211Z,1598368218.211 [AMEcho](INFO): Powering down
2020-08-25T15:10:18.756Z,1598368218.756 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004380
2020-08-25T15:10:31.800Z,1598368231.800 [NAL9602](INFO): Powering up NAL9602
2020-08-25T15:10:44.345Z,1598368244.345 [SBIT](IMPORTANT): Beginning Startup BIT
2020-08-25T15:10:44.357Z,1598368244.357 [CBIT](IMPORTANT): Beginning ground fault scan
2020-08-25T15:10:52.405Z,1598368252.405 [NAL9602](ERROR): NAL9602 initialization error.
2020-08-25T15:10:52.405Z,1598368252.405 [NAL9602] Communications Fault, FailCount= 1
2020-08-25T15:10:52.405Z,1598368252.405 [NAL9602](ERROR): Communications Fault
2020-08-25T15:10:52.519Z,1598368252.519 [CBIT](ERROR): Communications Fault in component: NAL9602
2020-08-25T15:10:52.820Z,1598368252.820 [NAL9602](INFO): Powering down
2020-08-25T15:10:53.731Z,1598368253.731 [CBIT](INFO): Clearing failed state for component NAL9602
2020-08-25T15:10:53.731Z,1598368253.731 [NAL9602] No Fault, FailCount= 1
2020-08-25T15:10:55.354Z,1598368255.354 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): -0.009176
CHAN A1 (24V): 0.038984
CHAN A2 (12V): -0.006664
CHAN A3 (5V): -0.002230
CHAN B0 (3.3V): 0.000067
CHAN B1 (3.15aV): -0.000226
CHAN B2 (3.15bV): 0.000593
CHAN B3 (GND): 0.002015
OPEN: 0.005327
Full Scale Calc: 4.765 mA, -1.589 mA
2020-08-25T15:11:05.338Z,1598368265.338 [DAT](FAULT): failed to initialize, no bytes available on serial interface
2020-08-25T15:11:05.338Z,1598368265.338 [DAT] Communications Fault, FailCount= 1
2020-08-25T15:11:05.338Z,1598368265.338 [DAT](ERROR): Communications Fault
2020-08-25T15:11:05.419Z,1598368265.419 [CBIT](ERROR): Communications Fault in component: DAT
2020-08-25T15:11:05.770Z,1598368265.770 [DAT](INFO): Powering down
2020-08-25T15:11:06.616Z,1598368266.616 [CBIT](INFO): Clearing failed state for component DAT
2020-08-25T15:11:06.616Z,1598368266.616 [DAT] No Fault, FailCount= 1
2020-08-25T15:11:08.979Z,1598368268.979 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2
2020-08-25T15:11:08.980Z,1598368268.980 [DAT](INFO): Powering up
2020-08-25T15:11:08.980Z,1598368268.980 [DAT](DEBUG): Initializing DAT.
2020-08-25T15:11:09.071Z,1598368269.071 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2
2020-08-25T15:11:21.502Z,1598368281.502 [DAT](INFO): commRate: 800
2020-08-25T15:11:21.502Z,1598368281.502 [DAT](INFO): commRate: 800
2020-08-25T15:11:21.903Z,1598368281.903 [DAT](INFO): entering command mode
2020-08-25T15:11:22.300Z,1598368282.300 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T15:11:22.719Z,1598368282.719 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T15:11:23.112Z,1598368283.112 [NAL9602](INFO): Powering up NAL9602
2020-08-25T15:11:23.113Z,1598368283.113 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T15:11:23.512Z,1598368283.512 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T15:11:23.932Z,1598368283.932 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T15:11:24.320Z,1598368284.320 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T15:11:24.739Z,1598368284.739 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T15:11:25.129Z,1598368285.129 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T15:11:25.532Z,1598368285.532 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T15:11:25.946Z,1598368285.946 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T15:11:26.346Z,1598368286.346 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T15:11:26.765Z,1598368286.765 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T15:11:27.152Z,1598368287.152 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T15:11:27.552Z,1598368287.552 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T15:11:27.971Z,1598368287.971 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T15:11:28.360Z,1598368288.360 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T15:11:28.779Z,1598368288.779 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T15:11:29.168Z,1598368289.168 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T15:11:29.580Z,1598368289.580 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T15:11:29.997Z,1598368289.997 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T15:11:30.384Z,1598368290.384 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T15:11:30.794Z,1598368290.794 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T15:11:31.193Z,1598368291.193 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T15:11:31.589Z,1598368291.589 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T15:11:32.010Z,1598368292.010 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T15:11:32.405Z,1598368292.405 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T15:11:32.819Z,1598368292.819 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T15:11:33.208Z,1598368293.208 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T15:11:33.624Z,1598368293.624 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T15:11:34.012Z,1598368294.012 [NAL9602](INFO): NAL9602 initialized
2020-08-25T15:11:34.023Z,1598368294.023 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T15:11:34.430Z,1598368294.430 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T15:11:34.873Z,1598368294.873 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T15:11:35.239Z,1598368295.239 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T15:11:35.658Z,1598368295.658 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T15:11:35.979Z,1598368295.979 [CommandLine](IMPORTANT): got command configSet WetLabsUBAT.loadAtStartup 0.000000 bool persist
2020-08-25T15:11:35.980Z,1598368295.980 [CommandLine](IMPORTANT): configSet WetLabsUBAT.loadAtStartup requires a restart to take effect.
2020-08-25T15:11:35.980Z,1598368295.980 [CommandLine](FAULT): Not allowing to overwrite existing Data/persisted.cfg after unclean shutdown.
2020-08-25T15:11:36.056Z,1598368296.056 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T15:11:36.438Z,1598368296.438 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T15:11:36.876Z,1598368296.876 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T15:11:37.263Z,1598368297.263 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T15:11:37.264Z,1598368297.264 [DAT](FAULT): failed to enter command mode
2020-08-25T15:11:37.695Z,1598368297.695 [DAT](INFO): entering command mode
2020-08-25T15:11:38.058Z,1598368298.058 [DAT](INFO): setting verbose to 3
2020-08-25T15:11:38.095Z,1598368298.095 [SBIT](IMPORTANT): SBIT PASSED
2020-08-25T15:11:38.095Z,1598368298.095 [SBIT](FAULT): Ignoring configuration overrides from Data/persisted.cfg
2020-08-25T15:11:38.467Z,1598368298.467 [DAT](INFO): set verbose to 3
2020-08-25T15:11:38.467Z,1598368298.467 [DAT](INFO): setting DatVerbose to 27440
2020-08-25T15:11:38.517Z,1598368298.517 [MissionManager](IMPORTANT): Started mission Startup
2020-08-25T15:11:38.518Z,1598368298.518 [Startup] Running Loop=1
2020-08-25T15:11:38.518Z,1598368298.518 [Startup](DEBUG): Aggregate::initialize Startup
2020-08-25T15:11:38.518Z,1598368298.518 [Startup:A.GoToSurface] Running Loop=1
2020-08-25T15:11:38.518Z,1598368298.518 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2020-08-25T15:11:38.519Z,1598368298.519 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2020-08-25T15:11:38.519Z,1598368298.519 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2020-08-25T15:11:38.519Z,1598368298.519 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2020-08-25T15:11:38.520Z,1598368298.520 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2020-08-25T15:11:38.520Z,1598368298.520 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2020-08-25T15:11:38.523Z,1598368298.523 [Startup:StartupSatComms] Running Loop=1
2020-08-25T15:11:38.523Z,1598368298.523 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2020-08-25T15:11:38.523Z,1598368298.523 [Startup:StartupSatComms:A] Running Loop=1
2020-08-25T15:11:38.872Z,1598368298.872 [DAT](INFO): set DatVerbose to 27440
2020-08-25T15:11:38.872Z,1598368298.872 [DAT](INFO): setting transmit power to 8
2020-08-25T15:11:38.892Z,1598368298.892 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2020-08-25T15:11:39.278Z,1598368299.278 [DAT](INFO): set transmit power to 8
2020-08-25T15:11:39.278Z,1598368299.278 [DAT](INFO): setting local address to 9
2020-08-25T15:11:39.698Z,1598368299.698 [DAT](INFO): set local address to 9
2020-08-25T15:11:55.056Z,1598368315.056 [CommandLine](IMPORTANT): got command get AMEcho.altitude
2020-08-25T15:11:55.057Z,1598368315.057 [CommandLine](IMPORTANT): AMEcho.altitude nan m
2020-08-25T15:12:06.877Z,1598368326.877 [CommandLine](IMPORTANT): got command report mod AMEcho.altitude
2020-08-25T15:12:07.176Z,1598368327.176 [Reporter](INFO): AMEcho.altitude no_value
2020-08-25T15:12:18.477Z,1598368338.477 [CommandLine](IMPORTANT): got command report touch AMEcho.altitude
2020-08-25T15:12:35.049Z,1598368355.049 [NAL9602](INFO): SBD MO Status=2, MOMSN=8109, MT Status=2, MTMSN=0
2020-08-25T15:12:35.049Z,1598368355.049 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-08-25T15:12:38.715Z,1598368358.715 [Startup:StartupSatComms:A](INFO): Timed out from 2020-08-25T15:11:38.5Z
2020-08-25T15:12:38.715Z,1598368358.715 [Startup:StartupSatComms:A] Stopped
2020-08-25T15:12:38.715Z,1598368358.715 [Startup:StartupSatComms:B] Running Loop=1
2020-08-25T15:12:39.238Z,1598368359.238 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2020-08-25T15:12:46.506Z,1598368366.506 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20200825T144546/Courier0007.lzma
2020-08-25T15:12:47.508Z,1598368367.508 [DataOverHttps](INFO): Moved sent file to Logs/20200825T144546/Courier0007.lzma.bak
2020-08-25T15:12:47.508Z,1598368367.508 [DataOverHttps](INFO): SBD MOMSN=12613875
2020-08-25T15:12:52.857Z,1598368372.857 [CommandLine](IMPORTANT): got command show stack
2020-08-25T15:12:52.858Z,1598368372.858 [CommandLine](IMPORTANT): Behavior Stack:
2020-08-25T15:12:52.858Z,1598368372.858 [Startup](IMPORTANT): Priority 0: Startup:A.GoToSurface
2020-08-25T15:12:52.858Z,1598368372.858 [Startup:StartupSatComms](IMPORTANT): Priority 1: Startup:StartupSatComms:B
2020-08-25T15:13:03.912Z,1598368383.912 [DataOverHttps](INFO): Sending 426 bytes from file Logs/20200825T150954/Courier0000.lzma
2020-08-25T15:13:04.254Z,1598368384.254 [NAL9602](INFO): SBD MO Status=2, MOMSN=8109, MT Status=2, MTMSN=0
2020-08-25T15:13:04.255Z,1598368384.255 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-08-25T15:13:04.912Z,1598368384.912 [DataOverHttps](INFO): Moved sent file to Logs/20200825T150954/Courier0000.lzma.bak
2020-08-25T15:13:04.912Z,1598368384.912 [DataOverHttps](INFO): SBD MOMSN=12613877
2020-08-25T15:13:05.067Z,1598368385.067 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2020-08-25T15:13:05.067Z,1598368385.067 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-08-25T15:13:05.077Z,1598368385.077 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-08-25T15:13:05.480Z,1598368385.480 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-08-25T15:13:05.480Z,1598368385.480 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2020-08-25T15:13:22.730Z,1598368402.730 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20200825T144546/Express0008.lzma
2020-08-25T15:13:23.732Z,1598368403.732 [DataOverHttps](INFO): Moved sent file to Logs/20200825T144546/Express0008.lzma.bak
2020-08-25T15:13:23.732Z,1598368403.732 [DataOverHttps](INFO): SBD MOMSN=12613888
2020-08-25T15:13:25.055Z,1598368405.055 [CommandLine](IMPORTANT): got command get AMEcho.enabled
2020-08-25T15:13:25.055Z,1598368405.055 [CommandLine](IMPORTANT): AMEcho.enabled 0 bool
2020-08-25T15:13:39.026Z,1598368419.026 [Startup:StartupSatComms:B](INFO): Timed out from 2020-08-25T15:12:38.7Z
2020-08-25T15:13:39.026Z,1598368419.026 [Startup:StartupSatComms:B] Stopped
2020-08-25T15:13:39.030Z,1598368419.030 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2020-08-25T15:13:39.030Z,1598368419.030 [Startup:StartupSatComms] Stopped
2020-08-25T15:13:39.031Z,1598368419.031 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2020-08-25T15:13:39.031Z,1598368419.031 [Startup](INFO): Completed Startup
2020-08-25T15:13:39.031Z,1598368419.031 [MissionManager](INFO): Startup is completed.
2020-08-25T15:13:39.032Z,1598368419.032 [MissionManager](INFO): Uninitializing Mission Startup
2020-08-25T15:13:39.032Z,1598368419.032 [Startup] Stopped
2020-08-25T15:13:39.032Z,1598368419.032 [Startup](DEBUG): Aggregate::uninitialize Startup
2020-08-25T15:13:39.032Z,1598368419.032 [Startup:A.GoToSurface] Stopped
2020-08-25T15:13:39.032Z,1598368419.032 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2020-08-25T15:13:39.400Z,1598368419.400 [MissionManager](IMPORTANT): Started mission Default
2020-08-25T15:13:39.400Z,1598368419.400 [Default] Running Loop=1
2020-08-25T15:13:39.400Z,1598368419.400 [Default](DEBUG): Aggregate::initialize Default
2020-08-25T15:13:39.400Z,1598368419.400 [Default:B.GoToSurface] Running Loop=1
2020-08-25T15:13:39.401Z,1598368419.401 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2020-08-25T15:13:39.401Z,1598368419.401 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2020-08-25T15:13:39.401Z,1598368419.401 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2020-08-25T15:13:39.401Z,1598368419.401 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2020-08-25T15:13:39.402Z,1598368419.402 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2020-08-25T15:13:39.402Z,1598368419.402 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2020-08-25T15:13:39.402Z,1598368419.402 [Default:A.Wait] Running Loop=1
2020-08-25T15:13:39.402Z,1598368419.402 [Default:A.Wait](DEBUG): Initialize Wait Component.
2020-08-25T15:13:41.383Z,1598368421.383 [DataOverHttps](INFO): Sending 997 bytes from file Logs/20200825T150954/Express0001.lzma
2020-08-25T15:13:41.984Z,1598368421.984 [CommandLine](IMPORTANT): got command configSet AMEcho.enabled 1.000000 bool
2020-08-25T15:13:43.388Z,1598368423.388 [DataOverHttps](INFO): Moved sent file to Logs/20200825T150954/Express0001.lzma.bak
2020-08-25T15:13:43.388Z,1598368423.388 [DataOverHttps](INFO): SBD MOMSN=12613890
2020-08-25T15:13:52.751Z,1598368432.751 [Default:A.Wait](INFO): Done Waiting.
2020-08-25T15:13:52.751Z,1598368432.751 [Default:A.Wait] Stopped
2020-08-25T15:13:52.751Z,1598368432.751 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2020-08-25T15:13:53.140Z,1598368433.140 [Default:CheckIn] Running Loop=1
2020-08-25T15:13:53.140Z,1598368433.140 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-25T15:13:53.140Z,1598368433.140 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-25T15:13:53.539Z,1598368433.539 [CommandLine](IMPORTANT): got command get AMEcho.enabled
2020-08-25T15:13:53.540Z,1598368433.540 [CommandLine](IMPORTANT): AMEcho.enabled 1 bool
2020-08-25T15:13:53.553Z,1598368433.553 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2020-08-25T15:14:07.470Z,1598368447.470 [CommandLine](IMPORTANT): got command show stack
2020-08-25T15:14:07.471Z,1598368447.471 [CommandLine](IMPORTANT): Behavior Stack:
2020-08-25T15:14:07.471Z,1598368447.471 [Default](IMPORTANT): Priority 0: Default:B.GoToSurface
2020-08-25T15:14:07.471Z,1598368447.471 [Default:CheckIn](IMPORTANT): Priority 1: Default:CheckIn:Read_GPS
2020-08-25T15:14:26.574Z,1598368466.574 [CommandLine](IMPORTANT): got command report mod AMEcho.altitude
2020-08-25T15:14:26.688Z,1598368466.688 [NAL9602](INFO): SBD MO Status=2, MOMSN=8109, MT Status=2, MTMSN=0
2020-08-25T15:14:26.688Z,1598368466.688 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-08-25T15:14:58.586Z,1598368498.586 [NAL9602](INFO): SBD MO Status=2, MOMSN=8109, MT Status=2, MTMSN=0
2020-08-25T15:14:58.586Z,1598368498.586 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-08-25T15:16:06.478Z,1598368566.478 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2020-08-25T15:16:06.478Z,1598368566.478 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-08-25T15:16:06.488Z,1598368566.488 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-08-25T15:16:06.900Z,1598368566.900 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-08-25T15:16:06.900Z,1598368566.900 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2020-08-25T15:16:37.180Z,1598368597.180 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-08-25T15:16:38.389Z,1598368598.389 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,151637.00,A,3648.16123,N,12147.28465,W,0.058,154.44,250820,,,D*7C
2020-08-25T15:16:38.393Z,1598368598.393 [NAL9602](INFO): GPS fix at 20200825T151637: (36.802687, -121.788077)
2020-08-25T15:16:38.496Z,1598368598.496 [Default:CheckIn:Read_GPS] Stopped
2020-08-25T15:16:38.496Z,1598368598.496 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-25T15:16:38.846Z,1598368598.846 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2020-08-25T15:16:48.718Z,1598368608.718 [DataOverHttps](INFO): Sending 223 bytes from file Logs/20200825T150954/Courier0004.lzma
2020-08-25T15:16:49.837Z,1598368609.837 [DataOverHttps](INFO): Moved sent file to Logs/20200825T150954/Courier0004.lzma.bak
2020-08-25T15:16:49.837Z,1598368609.837 [DataOverHttps](INFO): SBD MOMSN=12613918
2020-08-25T15:17:11.119Z,1598368631.119 [NAL9602](INFO): Not Powering down - fast GPS
2020-08-25T15:17:11.523Z,1598368631.523 [DataOverHttps](INFO): Sending 563 bytes from file Logs/20200825T150954/Express0005.lzma
2020-08-25T15:17:12.524Z,1598368632.524 [DataOverHttps](INFO): Moved sent file to Logs/20200825T150954/Express0005.lzma.bak
2020-08-25T15:17:12.524Z,1598368632.524 [DataOverHttps](INFO): SBD MOMSN=12613926
2020-08-25T15:17:16.003Z,1598368636.003 [Default:CheckIn:Read_Iridium] Stopped
2020-08-25T15:17:16.003Z,1598368636.003 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-25T15:17:16.003Z,1598368636.003 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-25T15:17:16.578Z,1598368636.578 [CommandLine](IMPORTANT): got command restart application
2020-08-25T15:17:17.582Z,1598368637.582 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2020-08-25T15:17:17.583Z,1598368637.583 [CommandLine ThreadHandler](INFO): Thread cancelled.
2020-08-25T15:17:17.762Z,1598368637.762 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye!
2020-08-25T15:17:17.762Z,1598368637.762 [CommandLine ThreadHandler](INFO): Thread cancelled.
2020-08-25T15:17:17.763Z,1598368637.763 [CommandLine](INFO): Join timeout helper Thread ID is 891
2020-08-25T15:17:17.764Z,1598368637.764 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2020-08-25T15:17:17.764Z,1598368637.764 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2020-08-25T15:17:17.764Z,1598368637.764 [NavChartDb](INFO): Join timeout helper Thread ID is 892
2020-08-25T15:17:18.103Z,1598368638.103 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2020-08-25T15:17:18.103Z,1598368638.103 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2020-08-25T15:17:18.110Z,1598368638.110 [ComponentRegistry](INFO): Shutting down WetLabsUBAT ThreadHandler
2020-08-25T15:17:18.110Z,1598368638.110 [WetLabsUBAT ThreadHandler](INFO): Thread cancelled.
2020-08-25T15:17:18.111Z,1598368638.111 [WetLabsUBAT](INFO): Join timeout helper Thread ID is 893
2020-08-25T15:17:18.111Z,1598368638.111 [WetLabsUBAT ThreadHandler](INFO): Uninitializing protected caller thread.
2020-08-25T15:17:18.111Z,1598368638.111 [WetLabsUBAT](INFO): Powering down
2020-08-25T15:17:18.112Z,1598368638.112 [WetLabsUBAT ThreadHandler](INFO): Thread cancelled.
2020-08-25T15:17:18.113Z,1598368638.113 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2020-08-25T15:17:18.113Z,1598368638.113 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2020-08-25T15:17:18.113Z,1598368638.113 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 894
2020-08-25T15:17:18.607Z,1598368638.607 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2020-08-25T15:17:18.607Z,1598368638.607 [WetLabsBB2FL](INFO): Powering down
2020-08-25T15:17:18.608Z,1598368638.608 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2020-08-25T15:17:18.614Z,1598368638.614 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2020-08-25T15:17:18.615Z,1598368638.615 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2020-08-25T15:17:18.615Z,1598368638.615 [CTD_Seabird](INFO): Join timeout helper Thread ID is 895
2020-08-25T15:17:18.663Z,1598368638.663 [CTD_Seabird](INFO): Powering down
2020-08-25T15:17:18.679Z,1598368638.679 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2020-08-25T15:17:18.680Z,1598368638.680 [CTD_Seabird](INFO): Powering down
2020-08-25T15:17:18.694Z,1598368638.694 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2020-08-25T15:17:18.703Z,1598368638.703 [ComponentRegistry](INFO): Shutting down BackSeatDriver ThreadHandler
2020-08-25T15:17:18.703Z,1598368638.703 [BackSeatDriver ThreadHandler](INFO): Thread cancelled.
2020-08-25T15:17:18.704Z,1598368638.704 [BackSeatDriver](INFO): Join timeout helper Thread ID is 896
2020-08-25T15:17:18.895Z,1598368638.895 [BackSeatDriver ThreadHandler](INFO): Uninitializing protected caller thread.
2020-08-25T15:17:18.895Z,1598368638.895 [BackSeatDriver ThreadHandler](INFO): Thread cancelled.
2020-08-25T15:17:18.903Z,1598368638.903 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2020-08-25T15:17:18.903Z,1598368638.903 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2020-08-25T15:17:18.904Z,1598368638.904 [Radio_Surface](INFO): Join timeout helper Thread ID is 897
2020-08-25T15:17:19.158Z,1598368639.158 [Radio_Surface](INFO): Powering down
2020-08-25T15:17:19.159Z,1598368639.159 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2020-08-25T15:17:19.160Z,1598368639.160 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2020-08-25T15:17:19.179Z,1598368639.179 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler
2020-08-25T15:17:19.179Z,1598368639.179 [Onboard ThreadHandler](INFO): Thread cancelled.
2020-08-25T15:17:19.180Z,1598368639.180 [Onboard](INFO): Join timeout helper Thread ID is 898
2020-08-25T15:17:20.147Z,1598368640.147 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread.
2020-08-25T15:17:20.147Z,1598368640.147 [Onboard ThreadHandler](INFO): Thread cancelled.
2020-08-25T15:17:20.155Z,1598368640.155 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2020-08-25T15:17:20.155Z,1598368640.155 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2020-08-25T15:17:20.156Z,1598368640.156 [DataOverHttps](INFO): Join timeout helper Thread ID is 899
2020-08-25T15:17:20.426Z,1598368640.426 [CBIT](FAULT): Humidity exceeds 50% of running average: Humidity:2285304 %. Average:303724.250000
2020-08-25T15:17:21.929Z,1598368641.929 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2020-08-25T15:17:21.932Z,1598368641.932 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2020-08-25T15:17:21.935Z,1598368641.935 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2020-08-25T15:17:21.935Z,1598368641.935 [logger ThreadHandler](INFO): Thread cancelled.
2020-08-25T15:17:21.936Z,1598368641.936 [logger](INFO): Join timeout helper Thread ID is 900
2020-08-25T15:17:21.950Z,1598368641.950 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2020-08-25T15:17:21.951Z,1598368641.951 [logger ThreadHandler](INFO): Thread cancelled.
2020-08-25T15:17:21.955Z,1598368641.955 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2020-08-25T15:17:21.955Z,1598368641.955 [CommandLine ThreadHandler](INFO): Thread cancelled.
2020-08-25T15:17:21.955Z,1598368641.955 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2020-08-25T15:17:21.955Z,1598368641.955 [controlThread ThreadHandler](INFO): Thread cancelled.
2020-08-25T15:17:21.956Z,1598368641.956 [controlThread](INFO): Join timeout helper Thread ID is 901
2020-08-25T15:17:22.006Z,1598368642.006 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2020-08-25T15:17:22.007Z,1598368642.007 [controlThread](DEBUG): Uninitializing ControlThread
2020-08-25T15:17:22.007Z,1598368642.007 [AHRS_M2](INFO): Powering down
2020-08-25T15:17:22.079Z,1598368642.079 [NAL9602](INFO): Powering down
2020-08-25T15:17:22.151Z,1598368642.151 [RDI_Pathfinder](INFO): Powering down
2020-08-25T15:17:22.151Z,1598368642.151 [DAT](INFO): Powering down
2020-08-25T15:17:22.271Z,1598368642.271 [AMEcho](INFO): Powering down
2020-08-25T15:17:22.272Z,1598368642.272 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2020-08-25T15:17:22.273Z,1598368642.273 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2020-08-25T15:17:22.274Z,1598368642.274 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2020-08-25T15:17:22.275Z,1598368642.275 [MissionManager](INFO): Uninitializing Mission Default
2020-08-25T15:17:22.275Z,1598368642.275 [Default] Stopped
2020-08-25T15:17:22.275Z,1598368642.275 [Default](DEBUG): Aggregate::uninitialize Default
2020-08-25T15:17:22.275Z,1598368642.275 [Default:B.GoToSurface] Stopped
2020-08-25T15:17:22.275Z,1598368642.275 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2020-08-25T15:17:22.275Z,1598368642.275 [Default:CheckIn] Stopped
2020-08-25T15:17:22.275Z,1598368642.275 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-25T15:17:22.275Z,1598368642.275 [Default:CheckIn:C.Wait] Stopped
2020-08-25T15:17:22.275Z,1598368642.275 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-25T15:17:22.277Z,1598368642.277 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2020-08-25T15:17:22.278Z,1598368642.278 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2020-08-25T15:17:22.278Z,1598368642.278 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2020-08-25T15:17:22.279Z,1598368642.279 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2020-08-25T15:17:22.279Z,1598368642.279 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2020-08-25T15:17:22.279Z,1598368642.279 [BuoyancyServo](INFO): Powering down
2020-08-25T15:17:22.290Z,1598368642.290 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2020-08-25T15:17:22.291Z,1598368642.291 [ElevatorServo](INFO): Powering down
2020-08-25T15:17:22.291Z,1598368642.291 [MassServo](DEBUG): Uninitialize Mass Servo.
2020-08-25T15:17:22.291Z,1598368642.291 [MassServo](INFO): Powering down
2020-08-25T15:17:22.292Z,1598368642.292 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2020-08-25T15:17:22.292Z,1598368642.292 [RudderServo](INFO): Powering down
2020-08-25T15:17:22.293Z,1598368642.293 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2020-08-25T15:17:22.293Z,1598368642.293 [ThrusterServo](INFO): Powering down
2020-08-25T15:17:22.294Z,1598368642.294 [SBIT](DEBUG): Uninitialize SBIT Component.
2020-08-25T15:17:22.295Z,1598368642.295 [IBIT](DEBUG): Uninitialize IBIT Component.
2020-08-25T15:17:22.295Z,1598368642.295 [CBIT](DEBUG): Uninitialize CBIT Component.
2020-08-25T15:17:22.295Z,1598368642.295 [CBIT](DEBUG): Powering off loads.
2020-08-25T15:17:22.306Z,1598368642.306 [CBIT](DEBUG): Disabling WDT.
2020-08-25T15:17:22.318Z,1598368642.318 [CBIT](DEBUG): Opening all GF detection circuits.
2020-08-25T15:17:22.319Z,1598368642.319 [controlThread ThreadHandler](INFO): Thread cancelled.
2020-08-25T15:17:22.421Z,1598368642.421 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2020-08-25T15:17:22.423Z,1598368642.423 [Onboard ThreadHandler](INFO): Thread cancelled.
2020-08-25T15:17:22.429Z,1598368642.429 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2020-08-25T15:17:22.493Z,1598368642.493 [WetLabsUBAT ThreadHandler](INFO): Thread cancelled.
2020-08-25T15:17:22.494Z,1598368642.494 [WetLabsUBAT](INFO): WetLabs destructor: _dataLog is not open
2020-08-25T15:17:22.495Z,1598368642.495 [WetLabsUBAT](INFO): WetLabs destructor: done
2020-08-25T15:17:22.506Z,1598368642.506 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2020-08-25T15:17:22.509Z,1598368642.509 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2020-08-25T15:17:22.512Z,1598368642.512 [BackSeatDriver ThreadHandler](INFO): Thread cancelled.
2020-08-25T15:17:22.522Z,1598368642.522 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2020-08-25T15:17:22.602Z,1598368642.602 [logger ThreadHandler](INFO): Thread cancelled.