2020-05-22T19:14:19.197Z,1590174859.197 [Supervisor](DEBUG): Initializing supervisor. 2020-05-22T19:14:19.200Z,1590174859.200 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2020-05-22T19:14:19.201Z,1590174859.201 [SyncHandler](INFO): Protected caller Thread ID is 4380 2020-05-22T19:14:19.202Z,1590174859.202 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2020-05-22T19:14:19.203Z,1590174859.203 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2020-05-22T19:14:19.203Z,1590174859.203 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 4381 2020-05-22T19:14:19.208Z,1590174859.208 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2020-05-22T19:14:19.231Z,1590174859.231 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2020-05-22T19:14:19.232Z,1590174859.232 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2020-05-22T19:14:19.233Z,1590174859.233 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 4382 2020-05-22T19:14:19.234Z,1590174859.234 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2020-05-22T19:14:19.235Z,1590174859.235 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2020-05-22T19:14:19.235Z,1590174859.235 [logger ThreadHandler](INFO): Protected caller Thread ID is 4383 2020-05-22T19:14:19.238Z,1590174859.238 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2020-05-22T19:14:19.238Z,1590174859.238 [Supervisor](INFO): Looking for Config files in directory: Config/ 2020-05-22T19:14:19.240Z,1590174859.240 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2020-05-22T19:14:19.344Z,1590174859.344 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2020-05-22T19:14:19.345Z,1590174859.345 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2020-05-22T19:14:20.111Z,1590174860.111 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2020-05-22T19:14:20.112Z,1590174860.112 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg 2020-05-22T19:14:20.352Z,1590174860.352 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock 2020-05-22T19:14:20.352Z,1590174860.352 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2020-05-22T19:14:20.462Z,1590174860.462 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2020-05-22T19:14:20.462Z,1590174860.462 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2020-05-22T19:14:20.576Z,1590174860.576 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2020-05-22T19:14:20.576Z,1590174860.576 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2020-05-22T19:14:20.661Z,1590174860.661 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2020-05-22T19:14:20.826Z,1590174860.826 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2020-05-22T19:14:20.826Z,1590174860.826 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2020-05-22T19:14:21.203Z,1590174861.203 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2020-05-22T19:14:21.203Z,1590174861.203 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2020-05-22T19:14:21.827Z,1590174861.827 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2020-05-22T19:14:21.827Z,1590174861.827 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2020-05-22T19:14:22.041Z,1590174862.041 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2020-05-22T19:14:22.042Z,1590174862.042 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2020-05-22T19:14:22.465Z,1590174862.465 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2020-05-22T19:14:22.466Z,1590174862.466 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2020-05-22T19:14:23.106Z,1590174863.106 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2020-05-22T19:14:23.106Z,1590174863.106 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2020-05-22T19:14:23.384Z,1590174863.384 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2020-05-22T19:14:23.385Z,1590174863.385 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2020-05-22T19:14:23.645Z,1590174863.645 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2020-05-22T19:14:23.645Z,1590174863.645 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2020-05-22T19:14:24.211Z,1590174864.211 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2020-05-22T19:14:24.212Z,1590174864.212 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2020-05-22T19:14:24.635Z,1590174864.635 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2020-05-22T19:14:24.637Z,1590174864.637 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-pontus/ 2020-05-22T19:14:24.638Z,1590174864.638 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/secure.cfg 2020-05-22T19:14:24.725Z,1590174864.725 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Sensor.cfg 2020-05-22T19:14:24.915Z,1590174864.915 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Servo.cfg 2020-05-22T19:14:25.036Z,1590174865.036 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Simulator.cfg 2020-05-22T19:14:25.126Z,1590174865.126 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/logger.cfg 2020-05-22T19:14:25.228Z,1590174865.228 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/vehicle.cfg 2020-05-22T19:14:25.481Z,1590174865.481 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Battery.cfg 2020-05-22T19:14:25.796Z,1590174865.796 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2020-05-22T19:14:25.796Z,1590174865.796 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Navigation.cfg 2020-05-22T19:14:25.898Z,1590174865.898 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/BIT.cfg 2020-05-22T19:14:26.005Z,1590174866.005 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Science.cfg 2020-05-22T19:14:26.168Z,1590174866.168 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Control.cfg 2020-05-22T19:14:26.277Z,1590174866.277 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-pontus/LOGIN/ 2020-05-22T19:14:26.278Z,1590174866.277 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg 2020-05-22T19:14:26.279Z,1590174866.279 [Module Loader](DEBUG): Loading Module at Modules/Dock.so 2020-05-22T19:14:26.360Z,1590174866.360 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking) 2020-05-22T19:14:26.360Z,1590174866.360 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2020-05-22T19:14:26.411Z,1590174866.411 [VerticalControl](DEBUG): Construct VerticalControl. 2020-05-22T19:14:26.553Z,1590174866.553 [VerticalControl] Loaded 2020-05-22T19:14:26.554Z,1590174866.554 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2020-05-22T19:14:26.554Z,1590174866.554 [HorizontalControl](DEBUG): Construct HorizontalControl. 2020-05-22T19:14:26.658Z,1590174866.658 [HorizontalControl] Loaded 2020-05-22T19:14:26.659Z,1590174866.659 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2020-05-22T19:14:26.660Z,1590174866.660 [SpeedControl](DEBUG): Construct SpeedControl. 2020-05-22T19:14:26.666Z,1590174866.666 [SpeedControl] Loaded 2020-05-22T19:14:26.667Z,1590174866.667 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2020-05-22T19:14:26.668Z,1590174866.668 [LoopControl](DEBUG): Construct LoopControl. 2020-05-22T19:14:26.668Z,1590174866.668 [LoopControl] Loaded 2020-05-22T19:14:26.669Z,1590174866.669 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2020-05-22T19:14:26.669Z,1590174866.669 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2020-05-22T19:14:26.670Z,1590174866.670 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2020-05-22T19:14:26.713Z,1590174866.713 [DepthRateCalculator] Loaded 2020-05-22T19:14:26.714Z,1590174866.714 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2020-05-22T19:14:26.720Z,1590174866.720 [PitchRateCalculator] Loaded 2020-05-22T19:14:26.720Z,1590174866.720 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2020-05-22T19:14:26.739Z,1590174866.739 [SpeedCalculator] Loaded 2020-05-22T19:14:26.740Z,1590174866.740 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2020-05-22T19:14:26.767Z,1590174866.767 [TempGradientCalculator] Loaded 2020-05-22T19:14:26.767Z,1590174866.767 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2020-05-22T19:14:26.774Z,1590174866.774 [YawRateCalculator] Loaded 2020-05-22T19:14:26.774Z,1590174866.774 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2020-05-22T19:14:26.813Z,1590174866.813 [ElevatorOffsetCalculator] Loaded 2020-05-22T19:14:26.813Z,1590174866.813 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2020-05-22T19:14:26.814Z,1590174866.814 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2020-05-22T19:14:26.814Z,1590174866.814 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2020-05-22T19:14:26.842Z,1590174866.842 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2020-05-22T19:14:26.843Z,1590174866.843 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2020-05-22T19:14:26.929Z,1590174866.929 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2020-05-22T19:14:26.930Z,1590174866.930 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2020-05-22T19:14:27.744Z,1590174867.744 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2020-05-22T19:14:27.744Z,1590174867.744 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2020-05-22T19:14:27.850Z,1590174867.850 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2020-05-22T19:14:27.850Z,1590174867.850 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2020-05-22T19:14:29.036Z,1590174869.036 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_orientation 2020-05-22T19:14:29.046Z,1590174869.046 [AHRS_M2](INFO): created writer for : platform_orientation 2020-05-22T19:14:29.048Z,1590174869.048 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_magnetic_orientation 2020-05-22T19:14:29.055Z,1590174869.055 [AHRS_M2](INFO): created writer for : platform_magnetic_orientation 2020-05-22T19:14:29.056Z,1590174869.056 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_pitch_angle 2020-05-22T19:14:29.063Z,1590174869.063 [AHRS_M2](INFO): created writer for : platform_pitch_angle 2020-05-22T19:14:29.063Z,1590174869.063 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_roll_angle 2020-05-22T19:14:29.071Z,1590174869.071 [AHRS_M2](INFO): created writer for : platform_roll_angle 2020-05-22T19:14:29.169Z,1590174869.169 [AHRS_M2] Loaded 2020-05-22T19:14:29.169Z,1590174869.169 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2020-05-22T19:14:29.252Z,1590174869.252 [DataOverHttps] Loaded 2020-05-22T19:14:29.252Z,1590174869.252 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2020-05-22T19:14:29.254Z,1590174869.254 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 409F34E0 2020-05-22T19:14:29.254Z,1590174869.254 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 4465 2020-05-22T19:14:29.272Z,1590174869.272 [Depth_Keller] Loaded 2020-05-22T19:14:29.272Z,1590174869.272 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2020-05-22T19:14:29.278Z,1590174869.278 [DropWeight] Loaded 2020-05-22T19:14:29.279Z,1590174869.279 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2020-05-22T19:14:29.402Z,1590174869.402 [NAL9602] Loaded 2020-05-22T19:14:29.403Z,1590174869.403 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2020-05-22T19:14:29.449Z,1590174869.449 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-0/voltage_now 2020-05-22T19:14:29.450Z,1590174869.450 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-0/current_now 2020-05-22T19:14:29.451Z,1590174869.451 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-0/charge_now 2020-05-22T19:14:29.451Z,1590174869.451 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-0/charge_full 2020-05-22T19:14:29.452Z,1590174869.452 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-1/voltage_now 2020-05-22T19:14:29.452Z,1590174869.452 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-1/current_now 2020-05-22T19:14:29.453Z,1590174869.453 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-1/charge_now 2020-05-22T19:14:29.453Z,1590174869.453 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-1/charge_full 2020-05-22T19:14:29.453Z,1590174869.453 [Onboard] Loaded 2020-05-22T19:14:29.454Z,1590174869.454 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2020-05-22T19:14:29.458Z,1590174869.458 [Radio_Surface] Loaded 2020-05-22T19:14:29.458Z,1590174869.458 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2020-05-22T19:14:29.459Z,1590174869.459 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 40A234E0 2020-05-22T19:14:29.460Z,1590174869.460 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 4466 2020-05-22T19:14:29.515Z,1590174869.515 [RDI_Pathfinder] Loaded 2020-05-22T19:14:29.515Z,1590174869.515 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread. 2020-05-22T19:14:29.692Z,1590174869.692 [DAT] Loaded 2020-05-22T19:14:29.693Z,1590174869.693 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread. 2020-05-22T19:14:31.791Z,1590174871.791 [BPC1] Loaded 2020-05-22T19:14:31.791Z,1590174871.791 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2020-05-22T19:14:31.792Z,1590174871.792 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2020-05-22T19:14:31.792Z,1590174871.792 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2020-05-22T19:14:31.934Z,1590174871.934 [DeadReckonUsingMultipleVelocitySources] Loaded 2020-05-22T19:14:31.934Z,1590174871.934 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2020-05-22T19:14:31.961Z,1590174871.961 [NavChart] Loaded 2020-05-22T19:14:31.961Z,1590174871.961 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2020-05-22T19:14:31.969Z,1590174871.969 [UniversalFixResidualReporter] Loaded 2020-05-22T19:14:31.970Z,1590174871.970 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2020-05-22T19:14:31.970Z,1590174871.970 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2020-05-22T19:14:31.971Z,1590174871.971 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2020-05-22T19:14:32.463Z,1590174872.463 [SBIT](DEBUG): Construct Startup Built In Test. 2020-05-22T19:14:32.513Z,1590174872.513 [SBIT] Loaded 2020-05-22T19:14:32.513Z,1590174872.513 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2020-05-22T19:14:32.514Z,1590174872.514 [IBIT](DEBUG): Construct Initiated Built In Test. 2020-05-22T19:14:32.645Z,1590174872.645 [IBIT] Loaded 2020-05-22T19:14:32.645Z,1590174872.645 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2020-05-22T19:14:32.650Z,1590174872.650 [CBIT](DEBUG): Construct Continuous Built In Test. 2020-05-22T19:14:32.840Z,1590174872.840 [CBIT] Loaded 2020-05-22T19:14:32.840Z,1590174872.840 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2020-05-22T19:14:32.840Z,1590174872.840 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2020-05-22T19:14:32.841Z,1590174872.841 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2020-05-22T19:14:33.034Z,1590174873.034 [BuoyancyServo] Loaded 2020-05-22T19:14:33.034Z,1590174873.034 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2020-05-22T19:14:33.049Z,1590174873.049 [ElevatorServo] Loaded 2020-05-22T19:14:33.049Z,1590174873.049 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2020-05-22T19:14:33.064Z,1590174873.064 [MassServo] Loaded 2020-05-22T19:14:33.064Z,1590174873.064 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2020-05-22T19:14:33.078Z,1590174873.078 [RudderServo] Loaded 2020-05-22T19:14:33.079Z,1590174873.079 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2020-05-22T19:14:33.093Z,1590174873.093 [ThrusterServo] Loaded 2020-05-22T19:14:33.093Z,1590174873.093 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2020-05-22T19:14:33.093Z,1590174873.093 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2020-05-22T19:14:33.094Z,1590174873.094 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2020-05-22T19:14:33.114Z,1590174873.114 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2020-05-22T19:14:33.114Z,1590174873.114 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2020-05-22T19:14:33.358Z,1590174873.358 [BackSeatDriver] Loaded 2020-05-22T19:14:33.359Z,1590174873.359 [ComponentRegistry](DEBUG): Component "BackSeatDriver" handled in its own thread. 2020-05-22T19:14:33.360Z,1590174873.360 [BackSeatDriver ThreadHandler](DEBUG): Created PCaller Thread at 40C2C4E0 2020-05-22T19:14:33.361Z,1590174873.361 [BackSeatDriver ThreadHandler](INFO): Protected caller Thread ID is 4467 2020-05-22T19:14:33.373Z,1590174873.373 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_density 2020-05-22T19:14:33.380Z,1590174873.380 [CTD_Seabird](INFO): created writer for : sea_water_density 2020-05-22T19:14:33.381Z,1590174873.381 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): depth 2020-05-22T19:14:33.387Z,1590174873.387 [CTD_Seabird](INFO): created writer for : depth 2020-05-22T19:14:33.388Z,1590174873.388 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_pressure 2020-05-22T19:14:33.395Z,1590174873.395 [CTD_Seabird](INFO): created writer for : sea_water_pressure 2020-05-22T19:14:33.395Z,1590174873.395 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_salinity 2020-05-22T19:14:33.402Z,1590174873.402 [CTD_Seabird](INFO): created writer for : sea_water_salinity 2020-05-22T19:14:33.403Z,1590174873.403 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_temperature 2020-05-22T19:14:33.410Z,1590174873.410 [CTD_Seabird](INFO): created writer for : sea_water_temperature 2020-05-22T19:14:33.411Z,1590174873.411 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_electrical_conductivity 2020-05-22T19:14:33.418Z,1590174873.418 [CTD_Seabird](INFO): created writer for : sea_water_electrical_conductivity 2020-05-22T19:14:33.418Z,1590174873.418 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): speed_of_sound_in_sea_water 2020-05-22T19:14:33.425Z,1590174873.425 [CTD_Seabird](INFO): created writer for : speed_of_sound_in_sea_water 2020-05-22T19:14:33.463Z,1590174873.463 [CTD_Seabird] Loaded 2020-05-22T19:14:33.463Z,1590174873.463 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2020-05-22T19:14:33.464Z,1590174873.464 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40C5C4E0 2020-05-22T19:14:33.465Z,1590174873.465 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 4468 2020-05-22T19:14:33.473Z,1590174873.473 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.Output470 2020-05-22T19:14:33.473Z,1590174873.473 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: Output470 2020-05-22T19:14:33.479Z,1590174873.479 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.Output650 2020-05-22T19:14:33.479Z,1590174873.479 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: Output650 2020-05-22T19:14:33.484Z,1590174873.484 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.OutputChl 2020-05-22T19:14:33.484Z,1590174873.484 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: OutputChl 2020-05-22T19:14:33.489Z,1590174873.489 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.VolumeScatCoeff117deg470nm 2020-05-22T19:14:33.489Z,1590174873.489 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: VolumeScatCoeff117deg470nm 2020-05-22T19:14:33.494Z,1590174873.494 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.VolumeScatCoeff117deg650nm 2020-05-22T19:14:33.494Z,1590174873.494 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: VolumeScatCoeff117deg650nm 2020-05-22T19:14:33.500Z,1590174873.500 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.BackscatteringCoeff470nm 2020-05-22T19:14:33.500Z,1590174873.500 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: BackscatteringCoeff470nm 2020-05-22T19:14:33.505Z,1590174873.505 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.BackscatteringCoeff650nm 2020-05-22T19:14:33.505Z,1590174873.505 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: BackscatteringCoeff650nm 2020-05-22T19:14:33.510Z,1590174873.510 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): mass_concentration_of_chlorophyll_in_sea_water 2020-05-22T19:14:33.516Z,1590174873.516 [WetLabsBB2FL](INFO): created writer for : mass_concentration_of_chlorophyll_in_sea_water 2020-05-22T19:14:33.516Z,1590174873.516 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_median_mass_concentration_of_chlorophyll_in_sea_water 2020-05-22T19:14:33.517Z,1590174873.517 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_median_mass_concentration_of_chlorophyll_in_sea_water 2020-05-22T19:14:33.522Z,1590174873.522 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water 2020-05-22T19:14:33.522Z,1590174873.522 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_mean_mass_concentration_of_chlorophyll_in_sea_water 2020-05-22T19:14:33.527Z,1590174873.527 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_variance_mass_concentration_of_chlorophyll_in_sea_water 2020-05-22T19:14:33.527Z,1590174873.527 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_variance_mass_concentration_of_chlorophyll_in_sea_water 2020-05-22T19:14:33.533Z,1590174873.533 [WetLabsBB2FL] Loaded 2020-05-22T19:14:33.533Z,1590174873.533 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2020-05-22T19:14:33.534Z,1590174873.534 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40C8C4E0 2020-05-22T19:14:33.535Z,1590174873.535 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 4469 2020-05-22T19:14:33.548Z,1590174873.548 [WetLabsUBAT..SerialDriver](INFO): Created logger 2020-05-22T19:14:33.548Z,1590174873.548 [WetLabsUBAT..SerialDriver](INFO): publishing on LCM channel WetLabsUBAT 2020-05-22T19:14:33.549Z,1590174873.549 [WetLabsUBAT..StreamSerialDriver](INFO): Created logger 2020-05-22T19:14:33.555Z,1590174873.555 [WetLabsUBAT](INFO): readConfig(): serialNo_: UBAT0051, uartName_: /dev/ttyC1, optionalArgs_: -ldir /mnt/mmc/LRAUV/Logs/latest 2020-05-22T19:14:33.555Z,1590174873.555 [WetLabsUBAT](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsUBAT.biolum_potential 2020-05-22T19:14:33.555Z,1590174873.555 [WetLabsUBAT](DEBUG): LcmSlateWriter::add(): dataName: biolum_potential 2020-05-22T19:14:33.560Z,1590174873.560 [WetLabsUBAT](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsUBAT.flow_rate 2020-05-22T19:14:33.561Z,1590174873.561 [WetLabsUBAT](DEBUG): LcmSlateWriter::add(): dataName: flow_rate 2020-05-22T19:14:33.567Z,1590174873.567 [WetLabsUBAT] Loaded 2020-05-22T19:14:33.568Z,1590174873.568 [ComponentRegistry](DEBUG): Component "WetLabsUBAT" handled in its own thread. 2020-05-22T19:14:33.569Z,1590174873.569 [WetLabsUBAT ThreadHandler](DEBUG): Created PCaller Thread at 40CBC4E0 2020-05-22T19:14:33.569Z,1590174873.569 [WetLabsUBAT ThreadHandler](INFO): Protected caller Thread ID is 4470 2020-05-22T19:14:33.570Z,1590174873.570 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2020-05-22T19:14:33.575Z,1590174873.575 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2020-05-22T19:14:33.576Z,1590174873.576 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2020-05-22T19:14:33.587Z,1590174873.587 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2020-05-22T19:14:33.588Z,1590174873.588 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40CEC4E0 2020-05-22T19:14:33.588Z,1590174873.588 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 4471 2020-05-22T19:14:33.595Z,1590174873.595 [Supervisor](INFO): Main Thread ID is 4379 2020-05-22T19:14:33.595Z,1590174873.595 [Supervisor](DEBUG): Running supervisor. 2020-05-22T19:14:33.595Z,1590174873.595 [CommandLine ThreadHandler](INFO): Handler Thread ID is 4472 2020-05-22T19:14:33.598Z,1590174873.598 [controlThread ThreadHandler](INFO): Handler Thread ID is 4473 2020-05-22T19:14:33.598Z,1590174873.598 [controlThread](DEBUG): Initializing ControlThread 2020-05-22T19:14:33.599Z,1590174873.599 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2020-05-22T19:14:33.601Z,1590174873.601 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2020-05-22T19:14:33.602Z,1590174873.602 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2020-05-22T19:14:33.603Z,1590174873.603 [LoopControl](DEBUG): Initialize LoopControlComponent. 2020-05-22T19:14:33.603Z,1590174873.603 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2020-05-22T19:14:33.604Z,1590174873.604 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2020-05-22T19:14:33.604Z,1590174873.604 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2020-05-22T19:14:33.604Z,1590174873.604 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2020-05-22T19:14:33.605Z,1590174873.605 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2020-05-22T19:14:33.605Z,1590174873.605 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2020-05-22T19:14:33.615Z,1590174873.615 [NavChart](DEBUG): Initialize NavChart Navigation. 2020-05-22T19:14:33.616Z,1590174873.616 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2020-05-22T19:14:33.616Z,1590174873.616 [SBIT](INFO): Initialize SBIT Component. 2020-05-22T19:14:33.617Z,1590174873.617 [SBIT](IMPORTANT): git: 2020-05-06_C-4-ge907442 2020-05-22T19:14:33.617Z,1590174873.617 [SBIT](INFO): git hash: e907442e8d324ef9e313fad2e4afa1f9562153e8 2020-05-22T19:14:33.618Z,1590174873.618 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2020-05-22T19:14:33.618Z,1590174873.618 [SBIT](IMPORTANT): Kernel Version:#1 PREEMPT Thu Feb 21 11:17:40 PST 2019 2020-05-22T19:14:33.619Z,1590174873.619 [SBIT](INFO): Beginning SBIT in 39.000000 seconds. 2020-05-22T19:14:33.620Z,1590174873.620 [IBIT](INFO): Initialize IBIT Component. 2020-05-22T19:14:33.621Z,1590174873.621 [CBIT](DEBUG): Initialize CBIT Component. 2020-05-22T19:14:33.622Z,1590174873.622 [logger ThreadHandler](INFO): Handler Thread ID is 4474 2020-05-22T19:14:33.633Z,1590174873.633 [CBIT](DEBUG): Initialized mux pins. 2020-05-22T19:14:33.633Z,1590174873.633 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL. 2020-05-22T19:14:33.633Z,1590174873.633 [CBIT](DEBUG): Initializing the watchdog timer. 2020-05-22T19:14:33.641Z,1590174873.641 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 4475 2020-05-22T19:14:33.642Z,1590174873.642 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2020-05-22T19:14:33.653Z,1590174873.653 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 4476 2020-05-22T19:14:33.657Z,1590174873.657 [CBIT](CRITICAL): LAST REBOOT DUE TO WATCHDOG TIMER RESET. 2020-05-22T19:14:33.657Z,1590174873.657 [CBIT](DEBUG): Initializing heartbeat. 2020-05-22T19:14:33.665Z,1590174873.665 [BackSeatDriver ThreadHandler](INFO): Handler Thread ID is 4477 2020-05-22T19:14:33.685Z,1590174873.685 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 4478 2020-05-22T19:14:33.686Z,1590174873.686 [CTD_Seabird](DEBUG): Initializing CTD_Seabird. 2020-05-22T19:14:33.690Z,1590174873.690 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 4480 2020-05-22T19:14:33.691Z,1590174873.691 [WetLabsBB2FL](INFO): Powering down 2020-05-22T19:14:33.721Z,1590174873.721 [WetLabsUBAT ThreadHandler](INFO): Handler Thread ID is 4481 2020-05-22T19:14:33.729Z,1590174873.729 [CBIT](DEBUG): Deactivating GF circuits. 2020-05-22T19:14:33.729Z,1590174873.729 [CBIT](DEBUG): Deactivating emergency mode. 2020-05-22T19:14:33.737Z,1590174873.737 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 4482 2020-05-22T19:14:33.741Z,1590174873.741 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2020-05-22T19:14:33.742Z,1590174873.742 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2020-05-22T19:14:33.742Z,1590174873.742 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2020-05-22T19:14:33.742Z,1590174873.742 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2020-05-22T19:14:33.742Z,1590174873.742 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2020-05-22T19:14:33.742Z,1590174873.742 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2020-05-22T19:14:33.743Z,1590174873.743 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000 2020-05-22T19:14:33.743Z,1590174873.743 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2020-05-22T19:14:33.743Z,1590174873.743 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2020-05-22T19:14:33.743Z,1590174873.743 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2020-05-22T19:14:33.743Z,1590174873.743 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000 2020-05-22T19:14:33.744Z,1590174873.744 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2020-05-22T19:14:33.744Z,1590174873.744 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000 2020-05-22T19:14:33.744Z,1590174873.744 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2020-05-22T19:14:33.744Z,1590174873.744 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000 2020-05-22T19:14:33.745Z,1590174873.745 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2020-05-22T19:14:33.765Z,1590174873.765 [CBIT](DEBUG): Backplane powered. 2020-05-22T19:14:33.767Z,1590174873.767 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2020-05-22T19:14:33.779Z,1590174873.779 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2020-05-22T19:14:33.802Z,1590174873.802 [MissionManager](DEBUG): 2020-05-22T19:14:33.802Z,1590174873.802 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2020-05-22T19:14:33.889Z,1590174873.889 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2020-05-22T19:14:33.890Z,1590174873.890 [Default:A.Wait](DEBUG): Construct Wait. 2020-05-22T19:14:33.892Z,1590174873.892 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2020-05-22T19:14:33.938Z,1590174873.938 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2020-05-22T19:14:33.942Z,1590174873.942 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2020-05-22T19:14:33.965Z,1590174873.965 [Default:E.Execute](DEBUG): Construct Execute. 2020-05-22T19:14:33.968Z,1590174873.968 [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-05-22T19:14:33.993Z,1590174873.993 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,NAL9602,Onboard,RDI_Pathfinder,DAT,BPC1,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-05-22T19:14:34.008Z,1590174874.008 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2020-05-22T19:14:34.057Z,1590174874.057 [Radio_Surface](INFO): Powering up 2020-05-22T19:14:34.092Z,1590174874.092 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2 2020-05-22T19:14:34.093Z,1590174874.093 [DAT](INFO): Powering up 2020-05-22T19:14:34.093Z,1590174874.093 [DAT](DEBUG): Initializing DAT. 2020-05-22T19:14:34.097Z,1590174874.097 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2 2020-05-22T19:14:34.196Z,1590174874.196 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2020-05-22T19:14:34.201Z,1590174874.201 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2020-05-22T19:14:34.202Z,1590174874.202 [ElevatorServo](DEBUG): Initializing EZServoServo. 2020-05-22T19:14:34.213Z,1590174874.213 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2020-05-22T19:14:34.215Z,1590174874.215 [MassServo](DEBUG): Initializing EZServoServo. 2020-05-22T19:14:34.225Z,1590174874.225 [MassServo](DEBUG): Initializing MassServo. 2020-05-22T19:14:34.226Z,1590174874.226 [RudderServo](DEBUG): Initializing EZServoServo. 2020-05-22T19:14:34.233Z,1590174874.233 [RudderServo](DEBUG): Initializing RudderServo. 2020-05-22T19:14:34.234Z,1590174874.234 [ThrusterServo](DEBUG): Initializing EZServoServo. 2020-05-22T19:14:34.241Z,1590174874.241 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2020-05-22T19:14:34.244Z,1590174874.244 [CommandLine](FAULT): Scheduling is paused 2020-05-22T19:14:34.244Z,1590174874.244 [CBIT](INFO): Critical error at 20200522T191433 2020-05-22T19:14:34.245Z,1590174874.245 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals 2020-05-22T19:14:34.442Z,1590174874.442 [DropWeight](CRITICAL): DROP WEIGHT MISSING. 2020-05-22T19:14:34.442Z,1590174874.442 [DropWeight] Hardware Fault, FailCount= 1 2020-05-22T19:14:34.442Z,1590174874.442 [DropWeight](ERROR): Hardware Fault 2020-05-22T19:14:34.492Z,1590174874.492 [CBIT](INFO): Critical error at 20200522T191434 2020-05-22T19:14:34.495Z,1590174874.495 [CBIT](ERROR): Hardware Fault in component: DropWeight 2020-05-22T19:14:34.496Z,1590174874.496 [CBIT](CRITICAL): Hardware Fault in component: DropWeight 2020-05-22T19:14:35.170Z,1590174875.170 [RudderServo](ERROR): Rudder initialization uart error serial timeout 2020-05-22T19:14:35.170Z,1590174875.170 [RudderServo](FAULT): Rudder failed to initialize 2020-05-22T19:14:35.170Z,1590174875.170 [RudderServo] Communications Fault, FailCount= 1 2020-05-22T19:14:35.171Z,1590174875.171 [RudderServo](ERROR): Communications Fault 2020-05-22T19:14:35.282Z,1590174875.282 [CBIT](INFO): Critical error at 20200522T191434 2020-05-22T19:14:35.285Z,1590174875.285 [CBIT](ERROR): Communications Fault in component: RudderServo 2020-05-22T19:14:35.462Z,1590174875.462 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2020-05-22T19:14:35.462Z,1590174875.462 [RudderServo](INFO): Powering down 2020-05-22T19:14:36.127Z,1590174876.127 [RudderServo](DEBUG): Initializing EZServoServo. 2020-05-22T19:14:36.246Z,1590174876.246 [RudderServo](DEBUG): Initializing RudderServo. 2020-05-22T19:14:36.251Z,1590174876.251 [CBIT](INFO): Clearing failed state for component RudderServo 2020-05-22T19:14:36.251Z,1590174876.251 [RudderServo] No Fault, FailCount= 1 2020-05-22T19:14:47.003Z,1590174887.003 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004967 2020-05-22T19:14:59.411Z,1590174899.411 [NAL9602](INFO): Powering up NAL9602 2020-05-22T19:15:13.194Z,1590174913.194 [SBIT](IMPORTANT): Beginning Startup BIT 2020-05-22T19:15:13.237Z,1590174913.237 [CBIT](IMPORTANT): Beginning ground fault scan 2020-05-22T19:15:20.162Z,1590174920.162 [NAL9602](ERROR): NAL9602 initialization error. 2020-05-22T19:15:20.163Z,1590174920.163 [NAL9602] Communications Fault, FailCount= 1 2020-05-22T19:15:20.163Z,1590174920.163 [NAL9602](ERROR): Communications Fault 2020-05-22T19:15:20.279Z,1590174920.279 [CBIT](ERROR): Communications Fault in component: NAL9602 2020-05-22T19:15:20.554Z,1590174920.554 [NAL9602](INFO): Powering down 2020-05-22T19:15:21.471Z,1590174921.471 [CBIT](INFO): Clearing failed state for component NAL9602 2020-05-22T19:15:21.471Z,1590174921.471 [NAL9602] No Fault, FailCount= 1 2020-05-22T19:15:24.284Z,1590174924.284 [CBIT](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): 0.000538 CHAN A1 (24V): 0.036072 CHAN A2 (12V): -0.007829 CHAN A3 (5V): -0.003279 CHAN B0 (3.3V): -0.000899 CHAN B1 (3.15aV): -0.000760 CHAN B2 (3.15bV): 0.000413 CHAN B3 (GND): 0.002512 OPEN: -0.004529 Full Scale Calc: 4.765 mA, -1.589 mA 2020-05-22T19:15:31.616Z,1590174931.616 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2020-05-22T19:15:34.402Z,1590174934.402 [DAT](FAULT): failed to initialize, no bytes available on serial interface 2020-05-22T19:15:34.402Z,1590174934.402 [DAT] Communications Fault, FailCount= 1 2020-05-22T19:15:34.402Z,1590174934.402 [DAT](ERROR): Communications Fault 2020-05-22T19:15:34.487Z,1590174934.487 [CBIT](ERROR): Communications Fault in component: DAT 2020-05-22T19:15:34.826Z,1590174934.826 [DAT](INFO): Powering down 2020-05-22T19:15:35.719Z,1590174935.719 [CBIT](INFO): Clearing failed state for component DAT 2020-05-22T19:15:35.719Z,1590174935.719 [DAT] No Fault, FailCount= 1 2020-05-22T19:15:38.044Z,1590174938.044 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2 2020-05-22T19:15:38.044Z,1590174938.044 [DAT](INFO): Powering up 2020-05-22T19:15:38.044Z,1590174938.044 [DAT](DEBUG): Initializing DAT. 2020-05-22T19:15:38.069Z,1590174938.069 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2 2020-05-22T19:15:48.534Z,1590174948.534 [DAT](DEBUG): 2020-05-22T19:15:48.535Z,1590174948.535 [DAT](DEBUG): Teledyne Benthos DAT-900 Series 2020-05-22T19:15:49.786Z,1590174949.786 [DAT](DEBUG): MF Frequency Band 2020-05-22T19:15:49.788Z,1590174949.788 [DAT](DEBUG): Directional Acoustic Transponder version 8.12.21 2020-05-22T19:15:49.788Z,1590174949.788 [DAT](DEBUG): May 22 2020 19:11:49 2020-05-22T19:15:50.567Z,1590174950.567 [DAT](DEBUG): Features enabled [Bearing] 2020-05-22T19:15:50.572Z,1590174950.572 [DAT](DEBUG): CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP 2020-05-22T19:15:50.598Z,1590174950.598 [DAT](INFO): commRate: 800 2020-05-22T19:15:50.966Z,1590174950.966 [NAL9602](INFO): Powering up NAL9602 2020-05-22T19:15:51.039Z,1590174951.039 [DAT](INFO): entering command mode 2020-05-22T19:15:51.362Z,1590174951.362 [DAT](DEBUG): checking for command mode acknowledgment 2020-05-22T19:15:51.780Z,1590174951.780 [DAT](DEBUG): checking for command mode acknowledgment 2020-05-22T19:15:51.781Z,1590174951.781 [DAT](INFO): command mode acknowledged 2020-05-22T19:15:51.781Z,1590174951.781 [DAT](INFO): setting verbose to 3 2020-05-22T19:15:52.190Z,1590174952.190 [DAT](DEBUG): checking for verbose setting acknowledgment 2020-05-22T19:15:52.191Z,1590174952.191 [DAT](INFO): set verbose to 3 2020-05-22T19:15:52.273Z,1590174952.273 [CommandLine](IMPORTANT): got command show state 2020-05-22T19:15:52.273Z,1590174952.273 [CommandLine](IMPORTANT): Mission State: 2020-05-22T19:15:52.602Z,1590174952.602 [DAT](INFO): setting transmit power to 8 2020-05-22T19:15:53.035Z,1590174953.035 [DAT](DEBUG): checking for transmit power setting acknowledgment 2020-05-22T19:15:53.393Z,1590174953.393 [DAT](DEBUG): checking for transmit power setting acknowledgment 2020-05-22T19:15:53.394Z,1590174953.394 [DAT](INFO): set transmit power to 8 2020-05-22T19:15:53.874Z,1590174953.874 [DAT](INFO): setting local address to 9 2020-05-22T19:15:54.194Z,1590174954.194 [DAT](DEBUG): checking for local address setting acknowledgment 2020-05-22T19:15:54.605Z,1590174954.605 [DAT](DEBUG): checking for local address setting acknowledgment 2020-05-22T19:15:54.606Z,1590174954.606 [DAT](INFO): set local address to 9 2020-05-22T19:16:02.150Z,1590174962.150 [NAL9602](INFO): NAL9602 initialized 2020-05-22T19:16:06.750Z,1590174966.750 [SBIT](IMPORTANT): SBIT PASSED 2020-05-22T19:16:06.750Z,1590174966.750 [SBIT](FAULT): Ignoring configuration overrides from Data/persisted.cfg 2020-05-22T19:16:07.035Z,1590174967.035 [MissionManager](IMPORTANT): Started mission Startup 2020-05-22T19:16:07.036Z,1590174967.036 [Startup] Running Loop=1 2020-05-22T19:16:07.036Z,1590174967.036 [Startup](DEBUG): Aggregate::initialize Startup 2020-05-22T19:16:07.036Z,1590174967.036 [Startup:A.GoToSurface] Running Loop=1 2020-05-22T19:16:07.036Z,1590174967.036 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2020-05-22T19:16:07.041Z,1590174967.041 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2020-05-22T19:16:07.041Z,1590174967.041 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2020-05-22T19:16:07.041Z,1590174967.041 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2020-05-22T19:16:07.042Z,1590174967.042 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2020-05-22T19:16:07.042Z,1590174967.042 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2020-05-22T19:16:07.044Z,1590174967.044 [Startup:StartupSatComms] Running Loop=1 2020-05-22T19:16:07.044Z,1590174967.044 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2020-05-22T19:16:07.044Z,1590174967.044 [Startup:StartupSatComms:A] Running Loop=1 2020-05-22T19:16:07.432Z,1590174967.432 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2020-05-22T19:17:07.252Z,1590175027.252 [Startup:StartupSatComms:A](INFO): Timed out from 2020-05-22T19:16:07.0Z 2020-05-22T19:17:07.252Z,1590175027.252 [Startup:StartupSatComms:A] Stopped 2020-05-22T19:17:07.265Z,1590175027.265 [Startup:StartupSatComms:B] Running Loop=1 2020-05-22T19:17:07.648Z,1590175027.648 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2020-05-22T19:17:15.190Z,1590175035.190 [DataOverHttps](INFO): Sending 396 bytes from file Logs/20200522T185450/Courier0004.lzma 2020-05-22T19:17:16.191Z,1590175036.191 [DataOverHttps](INFO): Moved sent file to Logs/20200522T185450/Courier0004.lzma.bak 2020-05-22T19:17:16.191Z,1590175036.191 [DataOverHttps](INFO): SBD MOMSN=12355912 2020-05-22T19:17:33.028Z,1590175053.028 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20200522T190305/Courier0000.lzma 2020-05-22T19:17:33.882Z,1590175053.882 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2020-05-22T19:17:33.882Z,1590175053.882 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-05-22T19:17:33.910Z,1590175053.910 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-05-22T19:17:34.031Z,1590175054.031 [DataOverHttps](INFO): Moved sent file to Logs/20200522T190305/Courier0000.lzma.bak 2020-05-22T19:17:34.031Z,1590175054.031 [DataOverHttps](INFO): SBD MOMSN=12355918 2020-05-22T19:17:34.361Z,1590175054.361 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-05-22T19:17:34.361Z,1590175054.361 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2020-05-22T19:17:50.818Z,1590175070.818 [DataOverHttps](INFO): Sending 176 bytes from file Logs/20200522T191419/Courier0000.lzma 2020-05-22T19:17:51.815Z,1590175071.815 [DataOverHttps](INFO): Moved sent file to Logs/20200522T191419/Courier0000.lzma.bak 2020-05-22T19:17:51.815Z,1590175071.815 [DataOverHttps](INFO): SBD MOMSN=12355921 2020-05-22T19:18:07.459Z,1590175087.459 [Startup:StartupSatComms:B](INFO): Timed out from 2020-05-22T19:17:07.3Z 2020-05-22T19:18:07.459Z,1590175087.459 [Startup:StartupSatComms:B] Stopped 2020-05-22T19:18:07.459Z,1590175087.459 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2020-05-22T19:18:07.459Z,1590175087.459 [Startup:StartupSatComms] Stopped 2020-05-22T19:18:07.459Z,1590175087.459 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2020-05-22T19:18:07.460Z,1590175087.460 [Startup](INFO): Completed Startup 2020-05-22T19:18:07.460Z,1590175087.460 [MissionManager](INFO): Startup is completed. 2020-05-22T19:18:07.485Z,1590175087.485 [MissionManager](INFO): Uninitializing Mission Startup 2020-05-22T19:18:07.485Z,1590175087.485 [Startup] Stopped 2020-05-22T19:18:07.485Z,1590175087.485 [Startup](DEBUG): Aggregate::uninitialize Startup 2020-05-22T19:18:07.485Z,1590175087.485 [Startup:A.GoToSurface] Stopped 2020-05-22T19:18:07.485Z,1590175087.485 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2020-05-22T19:18:08.079Z,1590175088.079 [MissionManager](IMPORTANT): Started mission Default 2020-05-22T19:18:08.079Z,1590175088.079 [Default] Running Loop=1 2020-05-22T19:18:08.080Z,1590175088.080 [Default](DEBUG): Aggregate::initialize Default 2020-05-22T19:18:08.080Z,1590175088.080 [Default:B.GoToSurface] Running Loop=1 2020-05-22T19:18:08.080Z,1590175088.080 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2020-05-22T19:18:08.080Z,1590175088.080 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2020-05-22T19:18:08.080Z,1590175088.080 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2020-05-22T19:18:08.081Z,1590175088.081 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2020-05-22T19:18:08.081Z,1590175088.081 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2020-05-22T19:18:08.082Z,1590175088.082 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2020-05-22T19:18:08.082Z,1590175088.082 [Default:A.Wait] Running Loop=1 2020-05-22T19:18:08.082Z,1590175088.082 [Default:A.Wait](DEBUG): Initialize Wait Component. 2020-05-22T19:18:08.684Z,1590175088.684 [DataOverHttps](INFO): Sending 805 bytes from file Logs/20200522T174255/Express0001.lzma 2020-05-22T19:18:09.683Z,1590175089.683 [DataOverHttps](INFO): Moved sent file to Logs/20200522T174255/Express0001.lzma.bak 2020-05-22T19:18:09.683Z,1590175089.683 [DataOverHttps](INFO): SBD MOMSN=12355927 2020-05-22T19:18:21.275Z,1590175101.275 [Default:A.Wait](INFO): Done Waiting. 2020-05-22T19:18:21.275Z,1590175101.275 [Default:A.Wait] Stopped 2020-05-22T19:18:21.275Z,1590175101.275 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2020-05-22T19:18:21.781Z,1590175101.781 [Default:CheckIn] Running Loop=1 2020-05-22T19:18:21.781Z,1590175101.781 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-05-22T19:18:21.781Z,1590175101.781 [Default:CheckIn:Read_GPS] Running Loop=1 2020-05-22T19:18:22.048Z,1590175102.048 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2020-05-22T19:18:59.171Z,1590175139.171 [CommandLine](IMPORTANT): got command run ./Missions/Demo/senddata_direct_test.xml 2020-05-22T19:18:59.171Z,1590175139.171 [MissionManager](INFO): Loading Mission: ./Missions/Demo/senddata_direct_test.xml 2020-05-22T19:18:59.204Z,1590175139.204 [MissionManager](DEBUG): 2020-05-22T19:18:59.222Z,1590175139.222 [CommandLine](IMPORTANT): Running ./Missions/Demo/senddata_direct_test.xml 2020-05-22T19:18:59.245Z,1590175139.245 [Default] Stopped 2020-05-22T19:18:59.246Z,1590175139.246 [Default](DEBUG): Aggregate::uninitialize Default 2020-05-22T19:18:59.246Z,1590175139.246 [Default:B.GoToSurface] Stopped 2020-05-22T19:18:59.246Z,1590175139.246 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2020-05-22T19:18:59.246Z,1590175139.246 [Default:CheckIn] Stopped 2020-05-22T19:18:59.246Z,1590175139.246 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-05-22T19:18:59.246Z,1590175139.246 [Default:CheckIn:Read_GPS] Stopped 2020-05-22T19:18:59.246Z,1590175139.246 [MissionManager](IMPORTANT): Started mission senddata_direct_test 2020-05-22T19:18:59.247Z,1590175139.247 [senddata_direct_test] Running Loop=1 2020-05-22T19:18:59.247Z,1590175139.247 [senddata_direct_test](DEBUG): Aggregate::initialize senddata_direct_test 2020-05-22T19:18:59.247Z,1590175139.247 [senddata_direct_test:A] Running Loop=1 2020-05-22T19:18:59.247Z,1590175139.247 [senddata_direct_test:A] Stopped 2020-05-22T19:18:59.247Z,1590175139.247 [senddata_direct_test:B] Running Loop=1 2020-05-22T19:18:59.594Z,1590175139.594 [DAT](INFO): modem://1: set _.pressure 0.509676 atmosphere 2020-05-22T19:18:59.594Z,1590175139.594 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2020-05-22T19:18:59.626Z,1590175139.626 [senddata_direct_test:B] Stopped 2020-05-22T19:18:59.626Z,1590175139.626 [senddata_direct_test:C] Running Loop=1 2020-05-22T19:18:59.974Z,1590175139.974 [DAT](INFO): setting remote address to 1 2020-05-22T19:19:00.012Z,1590175140.012 [senddata_direct_test:C] Stopped 2020-05-22T19:19:00.012Z,1590175140.012 [senddata_direct_test](INFO): Completed senddata_direct_test 2020-05-22T19:19:00.012Z,1590175140.012 [MissionManager](INFO): senddata_direct_test is completed. 2020-05-22T19:19:00.012Z,1590175140.012 [MissionManager](INFO): Uninitializing Mission senddata_direct_test 2020-05-22T19:19:00.012Z,1590175140.012 [senddata_direct_test] Stopped 2020-05-22T19:19:00.012Z,1590175140.012 [senddata_direct_test](DEBUG): Aggregate::uninitialize senddata_direct_test 2020-05-22T19:19:00.398Z,1590175140.398 [DAT](DEBUG): checking for remote address setting acknowledgment 2020-05-22T19:19:00.399Z,1590175140.399 [DAT](INFO): set remote address to 1 2020-05-22T19:19:00.400Z,1590175140.400 [DAT](INFO): entering online mode 2020-05-22T19:19:00.422Z,1590175140.422 [MissionManager](IMPORTANT): Started mission Default 2020-05-22T19:19:00.422Z,1590175140.422 [Default] Running Loop=1 2020-05-22T19:19:00.422Z,1590175140.422 [Default](DEBUG): Aggregate::initialize Default 2020-05-22T19:19:00.423Z,1590175140.423 [Default:B.GoToSurface] Running Loop=1 2020-05-22T19:19:00.423Z,1590175140.423 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2020-05-22T19:19:00.423Z,1590175140.423 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2020-05-22T19:19:00.423Z,1590175140.423 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2020-05-22T19:19:00.424Z,1590175140.424 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2020-05-22T19:19:00.424Z,1590175140.424 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2020-05-22T19:19:00.424Z,1590175140.424 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2020-05-22T19:19:00.430Z,1590175140.430 [Default:A.Wait] Running Loop=1 2020-05-22T19:19:00.430Z,1590175140.430 [Default:A.Wait](DEBUG): Initialize Wait Component. 2020-05-22T19:19:00.778Z,1590175140.778 [DAT](DEBUG): checking for online mode acknowledgment 2020-05-22T19:19:00.793Z,1590175140.793 [DAT](INFO): online mode acknowledged 2020-05-22T19:19:00.794Z,1590175140.794 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2020-05-22T19:19:04.032Z,1590175144.032 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2020-05-22T19:19:13.736Z,1590175153.736 [Default:A.Wait](INFO): Done Waiting. 2020-05-22T19:19:13.736Z,1590175153.736 [Default:A.Wait] Stopped 2020-05-22T19:19:13.736Z,1590175153.736 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2020-05-22T19:19:14.144Z,1590175154.144 [Default:CheckIn] Running Loop=1 2020-05-22T19:19:14.144Z,1590175154.144 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-05-22T19:19:14.144Z,1590175154.144 [Default:CheckIn:Read_GPS] Running Loop=1 2020-05-22T19:19:20.975Z,1590175160.975 [DAT](FAULT): Ack receipt timeout failure. 2020-05-22T19:19:20.975Z,1590175160.975 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER 2020-05-22T19:19:21.387Z,1590175161.387 [DAT](INFO): modem://1: set _.temperature 21.922846 celsius 2020-05-22T19:19:21.388Z,1590175161.388 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2020-05-22T19:19:21.810Z,1590175161.810 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2020-05-22T19:19:25.063Z,1590175165.063 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2020-05-22T19:19:26.785Z,1590175166.785 [CommandLine](IMPORTANT): got command quit 2020-05-22T19:19:27.790Z,1590175167.790 [Supervisor](INFO): Stop Mission called by Supervisor::terminate 2020-05-22T19:19:27.791Z,1590175167.791 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2020-05-22T19:19:27.793Z,1590175167.793 [CommandLine ThreadHandler](INFO): Thread cancelled. 2020-05-22T19:19:27.929Z,1590175167.929 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2020-05-22T19:19:27.929Z,1590175167.929 [CommandLine ThreadHandler](INFO): Thread cancelled. 2020-05-22T19:19:27.930Z,1590175167.930 [CommandLine](INFO): Join timeout helper Thread ID is 4508 2020-05-22T19:19:27.930Z,1590175167.930 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2020-05-22T19:19:27.930Z,1590175167.930 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2020-05-22T19:19:27.931Z,1590175167.931 [NavChartDb](INFO): Join timeout helper Thread ID is 4509 2020-05-22T19:19:28.069Z,1590175168.069 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2020-05-22T19:19:28.069Z,1590175168.069 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2020-05-22T19:19:28.092Z,1590175168.092 [ComponentRegistry](INFO): Shutting down WetLabsUBAT ThreadHandler 2020-05-22T19:19:28.092Z,1590175168.092 [WetLabsUBAT ThreadHandler](INFO): Thread cancelled. 2020-05-22T19:19:28.093Z,1590175168.093 [WetLabsUBAT](INFO): Join timeout helper Thread ID is 4510 2020-05-22T19:19:28.345Z,1590175168.345 [WetLabsUBAT ThreadHandler](INFO): Uninitializing protected caller thread. 2020-05-22T19:19:28.345Z,1590175168.345 [WetLabsUBAT](INFO): Powering down 2020-05-22T19:19:28.386Z,1590175168.386 [WetLabsUBAT ThreadHandler](INFO): Thread cancelled. 2020-05-22T19:19:28.393Z,1590175168.393 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2020-05-22T19:19:28.393Z,1590175168.393 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2020-05-22T19:19:28.393Z,1590175168.393 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 4511 2020-05-22T19:19:28.741Z,1590175168.741 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2020-05-22T19:19:28.742Z,1590175168.742 [WetLabsBB2FL](INFO): Powering down 2020-05-22T19:19:28.742Z,1590175168.742 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2020-05-22T19:19:28.753Z,1590175168.753 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler 2020-05-22T19:19:28.753Z,1590175168.753 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2020-05-22T19:19:28.753Z,1590175168.753 [CTD_Seabird](INFO): Join timeout helper Thread ID is 4512 2020-05-22T19:19:42.032Z,1590175182.032 [DAT](FAULT): Ack receipt timeout failure. 2020-05-22T19:19:42.032Z,1590175182.032 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER 2020-05-22T19:19:42.390Z,1590175182.390 [DAT](INFO): modem://1: set _.humidity 15.047004 percent 2020-05-22T19:19:42.390Z,1590175182.390 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2020-05-22T19:19:42.950Z,1590175182.950 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2020-05-22T19:19:46.483Z,1590175186.483 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2020-05-22T19:19:58.953Z,1590175198.953 [ 2020-05-22T19:19:58.953Z,1590175198.953 [ 2020-05-22T19:19:58.954Z,1590175198.954 [ 2020-05-22T19:19:58.954Z,1590175198.954 [Unknown] 2020-05-22T19:19:58.954Z,1590175198.954 [ 2020-05-22T19:19:59.005Z,1590175199.005 [ 2020-05-22T19:19:59.005Z,1590175199.005 [