2020-05-20T19:09:30.208Z,1590001770.208 [Supervisor](DEBUG): Initializing supervisor. 2020-05-20T19:09:30.210Z,1590001770.210 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2020-05-20T19:09:30.211Z,1590001770.211 [SyncHandler](INFO): Protected caller Thread ID is 8093 2020-05-20T19:09:30.211Z,1590001770.211 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2020-05-20T19:09:30.212Z,1590001770.212 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2020-05-20T19:09:30.212Z,1590001770.212 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 8094 2020-05-20T19:09:30.215Z,1590001770.215 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2020-05-20T19:09:30.228Z,1590001770.228 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2020-05-20T19:09:30.229Z,1590001770.229 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2020-05-20T19:09:30.229Z,1590001770.229 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 8095 2020-05-20T19:09:30.230Z,1590001770.230 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2020-05-20T19:09:30.231Z,1590001770.231 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2020-05-20T19:09:30.231Z,1590001770.231 [logger ThreadHandler](INFO): Protected caller Thread ID is 8096 2020-05-20T19:09:30.233Z,1590001770.233 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2020-05-20T19:09:30.233Z,1590001770.233 [Supervisor](INFO): Looking for Config files in directory: Config/ 2020-05-20T19:09:30.235Z,1590001770.235 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2020-05-20T19:09:30.328Z,1590001770.328 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2020-05-20T19:09:30.329Z,1590001770.329 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2020-05-20T19:09:30.919Z,1590001770.919 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2020-05-20T19:09:30.919Z,1590001770.919 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg 2020-05-20T19:09:31.111Z,1590001771.111 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock 2020-05-20T19:09:31.112Z,1590001771.112 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2020-05-20T19:09:31.253Z,1590001771.253 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2020-05-20T19:09:31.254Z,1590001771.254 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2020-05-20T19:09:31.353Z,1590001771.353 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2020-05-20T19:09:31.354Z,1590001771.354 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2020-05-20T19:09:31.432Z,1590001771.432 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2020-05-20T19:09:31.567Z,1590001771.567 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2020-05-20T19:09:31.568Z,1590001771.568 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2020-05-20T19:09:31.854Z,1590001771.854 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2020-05-20T19:09:31.854Z,1590001771.854 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2020-05-20T19:09:32.320Z,1590001772.320 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2020-05-20T19:09:32.320Z,1590001772.320 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2020-05-20T19:09:32.462Z,1590001772.462 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2020-05-20T19:09:32.463Z,1590001772.463 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2020-05-20T19:09:32.658Z,1590001772.658 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2020-05-20T19:09:32.658Z,1590001772.658 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2020-05-20T19:09:33.143Z,1590001773.143 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2020-05-20T19:09:33.143Z,1590001773.143 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2020-05-20T19:09:33.396Z,1590001773.396 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2020-05-20T19:09:33.396Z,1590001773.396 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2020-05-20T19:09:33.608Z,1590001773.608 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2020-05-20T19:09:33.609Z,1590001773.609 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2020-05-20T19:09:34.012Z,1590001774.012 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2020-05-20T19:09:34.013Z,1590001774.013 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2020-05-20T19:09:34.343Z,1590001774.343 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2020-05-20T19:09:34.345Z,1590001774.345 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-pontus/ 2020-05-20T19:09:34.346Z,1590001774.346 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/secure.cfg 2020-05-20T19:09:34.427Z,1590001774.427 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Sensor.cfg 2020-05-20T19:09:34.583Z,1590001774.583 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Servo.cfg 2020-05-20T19:09:34.689Z,1590001774.689 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Simulator.cfg 2020-05-20T19:09:34.773Z,1590001774.773 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/logger.cfg 2020-05-20T19:09:34.865Z,1590001774.865 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/vehicle.cfg 2020-05-20T19:09:35.066Z,1590001775.066 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Battery.cfg 2020-05-20T19:09:35.403Z,1590001775.403 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2020-05-20T19:09:35.404Z,1590001775.404 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Navigation.cfg 2020-05-20T19:09:35.595Z,1590001775.595 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/BIT.cfg 2020-05-20T19:09:35.713Z,1590001775.713 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Science.cfg 2020-05-20T19:09:36.080Z,1590001776.080 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Control.cfg 2020-05-20T19:09:36.243Z,1590001776.243 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg 2020-05-20T19:09:36.245Z,1590001776.245 [Module Loader](DEBUG): Loading Module at Modules/Dock.so 2020-05-20T19:09:36.323Z,1590001776.323 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking) 2020-05-20T19:09:36.323Z,1590001776.323 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2020-05-20T19:09:36.649Z,1590001776.649 [VerticalControl](DEBUG): Construct VerticalControl. 2020-05-20T19:09:36.758Z,1590001776.758 [VerticalControl] Loaded 2020-05-20T19:09:36.758Z,1590001776.758 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2020-05-20T19:09:36.759Z,1590001776.759 [HorizontalControl](DEBUG): Construct HorizontalControl. 2020-05-20T19:09:36.836Z,1590001776.836 [HorizontalControl] Loaded 2020-05-20T19:09:36.837Z,1590001776.837 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2020-05-20T19:09:36.837Z,1590001776.837 [SpeedControl](DEBUG): Construct SpeedControl. 2020-05-20T19:09:36.842Z,1590001776.842 [SpeedControl] Loaded 2020-05-20T19:09:36.843Z,1590001776.843 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2020-05-20T19:09:36.843Z,1590001776.843 [LoopControl](DEBUG): Construct LoopControl. 2020-05-20T19:09:36.844Z,1590001776.844 [LoopControl] Loaded 2020-05-20T19:09:36.844Z,1590001776.844 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2020-05-20T19:09:36.844Z,1590001776.844 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2020-05-20T19:09:36.845Z,1590001776.845 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2020-05-20T19:09:36.885Z,1590001776.885 [DepthRateCalculator] Loaded 2020-05-20T19:09:36.886Z,1590001776.886 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2020-05-20T19:09:36.891Z,1590001776.891 [PitchRateCalculator] Loaded 2020-05-20T19:09:36.891Z,1590001776.891 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2020-05-20T19:09:36.906Z,1590001776.906 [SpeedCalculator] Loaded 2020-05-20T19:09:36.906Z,1590001776.906 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2020-05-20T19:09:36.927Z,1590001776.927 [TempGradientCalculator] Loaded 2020-05-20T19:09:36.927Z,1590001776.927 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2020-05-20T19:09:36.932Z,1590001776.932 [YawRateCalculator] Loaded 2020-05-20T19:09:36.932Z,1590001776.932 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2020-05-20T19:09:36.961Z,1590001776.961 [ElevatorOffsetCalculator] Loaded 2020-05-20T19:09:36.961Z,1590001776.961 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2020-05-20T19:09:36.962Z,1590001776.962 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2020-05-20T19:09:36.962Z,1590001776.962 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2020-05-20T19:09:36.988Z,1590001776.988 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2020-05-20T19:09:36.989Z,1590001776.989 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2020-05-20T19:09:37.069Z,1590001777.069 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2020-05-20T19:09:37.070Z,1590001777.070 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2020-05-20T19:09:37.355Z,1590001777.355 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2020-05-20T19:09:37.355Z,1590001777.355 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2020-05-20T19:09:37.451Z,1590001777.451 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2020-05-20T19:09:37.452Z,1590001777.452 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2020-05-20T19:09:37.731Z,1590001777.731 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_orientation 2020-05-20T19:09:37.736Z,1590001777.736 [AHRS_M2](INFO): created writer for : platform_orientation 2020-05-20T19:09:37.738Z,1590001777.738 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_magnetic_orientation 2020-05-20T19:09:37.743Z,1590001777.743 [AHRS_M2](INFO): created writer for : platform_magnetic_orientation 2020-05-20T19:09:37.743Z,1590001777.743 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_pitch_angle 2020-05-20T19:09:37.748Z,1590001777.748 [AHRS_M2](INFO): created writer for : platform_pitch_angle 2020-05-20T19:09:37.748Z,1590001777.748 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_roll_angle 2020-05-20T19:09:37.754Z,1590001777.754 [AHRS_M2](INFO): created writer for : platform_roll_angle 2020-05-20T19:09:37.823Z,1590001777.823 [AHRS_M2] Loaded 2020-05-20T19:09:37.823Z,1590001777.823 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2020-05-20T19:09:37.901Z,1590001777.901 [DataOverHttps] Loaded 2020-05-20T19:09:37.902Z,1590001777.902 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2020-05-20T19:09:37.903Z,1590001777.903 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 409044E0 2020-05-20T19:09:37.903Z,1590001777.903 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 8181 2020-05-20T19:09:37.916Z,1590001777.916 [Depth_Keller] Loaded 2020-05-20T19:09:37.916Z,1590001777.916 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2020-05-20T19:09:37.921Z,1590001777.921 [DropWeight] Loaded 2020-05-20T19:09:37.921Z,1590001777.921 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2020-05-20T19:09:38.016Z,1590001778.016 [NAL9602] Loaded 2020-05-20T19:09:38.017Z,1590001778.017 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2020-05-20T19:09:38.053Z,1590001778.053 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-0/voltage_now 2020-05-20T19:09:38.053Z,1590001778.053 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-0/current_now 2020-05-20T19:09:38.054Z,1590001778.054 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-0/charge_now 2020-05-20T19:09:38.054Z,1590001778.054 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-0/charge_full 2020-05-20T19:09:38.055Z,1590001778.055 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-1/voltage_now 2020-05-20T19:09:38.055Z,1590001778.055 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-1/current_now 2020-05-20T19:09:38.056Z,1590001778.056 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-1/charge_now 2020-05-20T19:09:38.056Z,1590001778.056 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-1/charge_full 2020-05-20T19:09:38.056Z,1590001778.056 [Onboard] Loaded 2020-05-20T19:09:38.057Z,1590001778.057 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2020-05-20T19:09:38.060Z,1590001778.060 [Radio_Surface] Loaded 2020-05-20T19:09:38.060Z,1590001778.060 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2020-05-20T19:09:38.061Z,1590001778.061 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409344E0 2020-05-20T19:09:38.061Z,1590001778.061 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 8182 2020-05-20T19:09:38.104Z,1590001778.104 [RDI_Pathfinder] Loaded 2020-05-20T19:09:38.104Z,1590001778.104 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread. 2020-05-20T19:09:38.234Z,1590001778.234 [DAT] Loaded 2020-05-20T19:09:38.235Z,1590001778.235 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread. 2020-05-20T19:09:39.703Z,1590001779.703 [BPC1] Loaded 2020-05-20T19:09:39.703Z,1590001779.703 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2020-05-20T19:09:39.703Z,1590001779.703 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2020-05-20T19:09:39.704Z,1590001779.704 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2020-05-20T19:09:39.819Z,1590001779.819 [DeadReckonUsingMultipleVelocitySources] Loaded 2020-05-20T19:09:39.819Z,1590001779.819 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2020-05-20T19:09:39.839Z,1590001779.839 [NavChart] Loaded 2020-05-20T19:09:39.840Z,1590001779.840 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2020-05-20T19:09:39.844Z,1590001779.844 [UniversalFixResidualReporter] Loaded 2020-05-20T19:09:39.844Z,1590001779.844 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2020-05-20T19:09:39.844Z,1590001779.844 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2020-05-20T19:09:39.845Z,1590001779.845 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2020-05-20T19:09:39.980Z,1590001779.980 [SBIT](DEBUG): Construct Startup Built In Test. 2020-05-20T19:09:39.991Z,1590001779.991 [SBIT] Loaded 2020-05-20T19:09:39.991Z,1590001779.991 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2020-05-20T19:09:39.992Z,1590001779.992 [IBIT](DEBUG): Construct Initiated Built In Test. 2020-05-20T19:09:40.004Z,1590001780.004 [IBIT] Loaded 2020-05-20T19:09:40.004Z,1590001780.004 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2020-05-20T19:09:40.007Z,1590001780.007 [CBIT](DEBUG): Construct Continuous Built In Test. 2020-05-20T19:09:40.143Z,1590001780.143 [CBIT] Loaded 2020-05-20T19:09:40.143Z,1590001780.143 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2020-05-20T19:09:40.144Z,1590001780.144 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2020-05-20T19:09:40.144Z,1590001780.144 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2020-05-20T19:09:40.247Z,1590001780.247 [BuoyancyServo] Loaded 2020-05-20T19:09:40.247Z,1590001780.247 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2020-05-20T19:09:40.258Z,1590001780.258 [ElevatorServo] Loaded 2020-05-20T19:09:40.258Z,1590001780.258 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2020-05-20T19:09:40.269Z,1590001780.269 [MassServo] Loaded 2020-05-20T19:09:40.269Z,1590001780.269 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2020-05-20T19:09:40.280Z,1590001780.280 [RudderServo] Loaded 2020-05-20T19:09:40.280Z,1590001780.280 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2020-05-20T19:09:40.291Z,1590001780.291 [ThrusterServo] Loaded 2020-05-20T19:09:40.291Z,1590001780.291 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2020-05-20T19:09:40.292Z,1590001780.292 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2020-05-20T19:09:40.292Z,1590001780.292 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2020-05-20T19:09:40.311Z,1590001780.311 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2020-05-20T19:09:40.311Z,1590001780.311 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2020-05-20T19:09:40.528Z,1590001780.528 [BackSeatDriver] Loaded 2020-05-20T19:09:40.528Z,1590001780.528 [ComponentRegistry](DEBUG): Component "BackSeatDriver" handled in its own thread. 2020-05-20T19:09:40.529Z,1590001780.529 [BackSeatDriver ThreadHandler](DEBUG): Created PCaller Thread at 40ACA4E0 2020-05-20T19:09:40.530Z,1590001780.530 [BackSeatDriver ThreadHandler](INFO): Protected caller Thread ID is 8183 2020-05-20T19:09:40.539Z,1590001780.539 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_density 2020-05-20T19:09:40.544Z,1590001780.544 [CTD_Seabird](INFO): created writer for : sea_water_density 2020-05-20T19:09:40.544Z,1590001780.544 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): depth 2020-05-20T19:09:40.549Z,1590001780.549 [CTD_Seabird](INFO): created writer for : depth 2020-05-20T19:09:40.550Z,1590001780.550 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_pressure 2020-05-20T19:09:40.554Z,1590001780.554 [CTD_Seabird](INFO): created writer for : sea_water_pressure 2020-05-20T19:09:40.555Z,1590001780.555 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_salinity 2020-05-20T19:09:40.560Z,1590001780.560 [CTD_Seabird](INFO): created writer for : sea_water_salinity 2020-05-20T19:09:40.561Z,1590001780.561 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_temperature 2020-05-20T19:09:40.566Z,1590001780.566 [CTD_Seabird](INFO): created writer for : sea_water_temperature 2020-05-20T19:09:40.566Z,1590001780.566 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_electrical_conductivity 2020-05-20T19:09:40.572Z,1590001780.572 [CTD_Seabird](INFO): created writer for : sea_water_electrical_conductivity 2020-05-20T19:09:40.572Z,1590001780.572 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): speed_of_sound_in_sea_water 2020-05-20T19:09:40.577Z,1590001780.577 [CTD_Seabird](INFO): created writer for : speed_of_sound_in_sea_water 2020-05-20T19:09:40.604Z,1590001780.604 [CTD_Seabird] Loaded 2020-05-20T19:09:40.604Z,1590001780.604 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2020-05-20T19:09:40.605Z,1590001780.605 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40AFA4E0 2020-05-20T19:09:40.605Z,1590001780.605 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 8184 2020-05-20T19:09:40.612Z,1590001780.612 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.Output470 2020-05-20T19:09:40.612Z,1590001780.612 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: Output470 2020-05-20T19:09:40.616Z,1590001780.616 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.Output650 2020-05-20T19:09:40.616Z,1590001780.616 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: Output650 2020-05-20T19:09:40.620Z,1590001780.620 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.OutputChl 2020-05-20T19:09:40.620Z,1590001780.620 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: OutputChl 2020-05-20T19:09:40.625Z,1590001780.625 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.VolumeScatCoeff117deg470nm 2020-05-20T19:09:40.625Z,1590001780.625 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: VolumeScatCoeff117deg470nm 2020-05-20T19:09:40.629Z,1590001780.629 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.VolumeScatCoeff117deg650nm 2020-05-20T19:09:40.629Z,1590001780.629 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: VolumeScatCoeff117deg650nm 2020-05-20T19:09:40.633Z,1590001780.633 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.BackscatteringCoeff470nm 2020-05-20T19:09:40.633Z,1590001780.633 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: BackscatteringCoeff470nm 2020-05-20T19:09:40.638Z,1590001780.638 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.BackscatteringCoeff650nm 2020-05-20T19:09:40.638Z,1590001780.638 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: BackscatteringCoeff650nm 2020-05-20T19:09:40.642Z,1590001780.642 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): mass_concentration_of_chlorophyll_in_sea_water 2020-05-20T19:09:40.646Z,1590001780.646 [WetLabsBB2FL](INFO): created writer for : mass_concentration_of_chlorophyll_in_sea_water 2020-05-20T19:09:40.647Z,1590001780.647 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_median_mass_concentration_of_chlorophyll_in_sea_water 2020-05-20T19:09:40.647Z,1590001780.647 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_median_mass_concentration_of_chlorophyll_in_sea_water 2020-05-20T19:09:40.651Z,1590001780.651 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water 2020-05-20T19:09:40.651Z,1590001780.651 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_mean_mass_concentration_of_chlorophyll_in_sea_water 2020-05-20T19:09:40.656Z,1590001780.656 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_variance_mass_concentration_of_chlorophyll_in_sea_water 2020-05-20T19:09:40.656Z,1590001780.656 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_variance_mass_concentration_of_chlorophyll_in_sea_water 2020-05-20T19:09:40.660Z,1590001780.660 [WetLabsBB2FL] Loaded 2020-05-20T19:09:40.660Z,1590001780.660 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2020-05-20T19:09:40.661Z,1590001780.661 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40B2A4E0 2020-05-20T19:09:40.662Z,1590001780.662 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 8185 2020-05-20T19:09:40.676Z,1590001780.676 [WetLabsUBAT..SerialDriver](INFO): Created logger 2020-05-20T19:09:40.677Z,1590001780.677 [WetLabsUBAT..SerialDriver](INFO): publishing on LCM channel WetLabsUBAT 2020-05-20T19:09:40.677Z,1590001780.677 [WetLabsUBAT..StreamSerialDriver](INFO): Created logger 2020-05-20T19:09:40.682Z,1590001780.682 [WetLabsUBAT](INFO): readConfig(): serialNo_: UBAT0051, uartName_: /dev/ttyC1, optionalArgs_: -ldir /mnt/mmc/LRAUV/Logs/latest 2020-05-20T19:09:40.682Z,1590001780.682 [WetLabsUBAT](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsUBAT.biolum_potential 2020-05-20T19:09:40.682Z,1590001780.682 [WetLabsUBAT](DEBUG): LcmSlateWriter::add(): dataName: biolum_potential 2020-05-20T19:09:40.686Z,1590001780.686 [WetLabsUBAT](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsUBAT.flow_rate 2020-05-20T19:09:40.687Z,1590001780.687 [WetLabsUBAT](DEBUG): LcmSlateWriter::add(): dataName: flow_rate 2020-05-20T19:09:40.692Z,1590001780.692 [WetLabsUBAT] Loaded 2020-05-20T19:09:40.692Z,1590001780.692 [ComponentRegistry](DEBUG): Component "WetLabsUBAT" handled in its own thread. 2020-05-20T19:09:40.693Z,1590001780.693 [WetLabsUBAT ThreadHandler](DEBUG): Created PCaller Thread at 40B5A4E0 2020-05-20T19:09:40.693Z,1590001780.693 [WetLabsUBAT ThreadHandler](INFO): Protected caller Thread ID is 8186 2020-05-20T19:09:40.694Z,1590001780.694 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2020-05-20T19:09:40.711Z,1590001780.711 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2020-05-20T19:09:40.711Z,1590001780.711 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2020-05-20T19:09:40.737Z,1590001780.737 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2020-05-20T19:09:40.738Z,1590001780.738 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B8A4E0 2020-05-20T19:09:40.739Z,1590001780.739 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 8187 2020-05-20T19:09:40.744Z,1590001780.744 [Supervisor](INFO): Main Thread ID is 8092 2020-05-20T19:09:40.744Z,1590001780.744 [Supervisor](DEBUG): Running supervisor. 2020-05-20T19:09:40.746Z,1590001780.746 [CommandLine ThreadHandler](INFO): Handler Thread ID is 8188 2020-05-20T19:09:40.750Z,1590001780.750 [controlThread ThreadHandler](INFO): Handler Thread ID is 8189 2020-05-20T19:09:40.750Z,1590001780.750 [controlThread](DEBUG): Initializing ControlThread 2020-05-20T19:09:40.752Z,1590001780.752 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2020-05-20T19:09:40.753Z,1590001780.753 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2020-05-20T19:09:40.754Z,1590001780.754 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2020-05-20T19:09:40.754Z,1590001780.754 [LoopControl](DEBUG): Initialize LoopControlComponent. 2020-05-20T19:09:40.755Z,1590001780.755 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2020-05-20T19:09:40.755Z,1590001780.755 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2020-05-20T19:09:40.755Z,1590001780.755 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2020-05-20T19:09:40.756Z,1590001780.756 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2020-05-20T19:09:40.756Z,1590001780.756 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2020-05-20T19:09:40.757Z,1590001780.757 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2020-05-20T19:09:40.766Z,1590001780.766 [NavChart](DEBUG): Initialize NavChart Navigation. 2020-05-20T19:09:40.767Z,1590001780.767 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2020-05-20T19:09:40.767Z,1590001780.767 [SBIT](INFO): Initialize SBIT Component. 2020-05-20T19:09:40.767Z,1590001780.767 [SBIT](IMPORTANT): git: 2020-05-06_C 2020-05-20T19:09:40.768Z,1590001780.768 [SBIT](INFO): git hash: 0cf8c4e35deb3fff8b463df734a916cd7b4cfdba 2020-05-20T19:09:40.768Z,1590001780.768 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2020-05-20T19:09:40.768Z,1590001780.768 [SBIT](IMPORTANT): Kernel Version:#1 PREEMPT Thu Feb 21 11:17:40 PST 2019 2020-05-20T19:09:40.769Z,1590001780.769 [SBIT](INFO): Beginning SBIT in 39.000000 seconds. 2020-05-20T19:09:40.770Z,1590001780.770 [IBIT](INFO): Initialize IBIT Component. 2020-05-20T19:09:40.771Z,1590001780.771 [CBIT](DEBUG): Initialize CBIT Component. 2020-05-20T19:09:40.773Z,1590001780.773 [logger ThreadHandler](INFO): Handler Thread ID is 8190 2020-05-20T19:09:40.791Z,1590001780.791 [CBIT](DEBUG): Initialized mux pins. 2020-05-20T19:09:40.791Z,1590001780.791 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL. 2020-05-20T19:09:40.791Z,1590001780.791 [CBIT](DEBUG): Initializing the watchdog timer. 2020-05-20T19:09:40.804Z,1590001780.804 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 8191 2020-05-20T19:09:40.805Z,1590001780.805 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2020-05-20T19:09:40.812Z,1590001780.812 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 8192 2020-05-20T19:09:40.815Z,1590001780.815 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2020-05-20T19:09:40.815Z,1590001780.815 [CBIT](DEBUG): Initializing heartbeat. 2020-05-20T19:09:40.825Z,1590001780.825 [BackSeatDriver ThreadHandler](INFO): Handler Thread ID is 8193 2020-05-20T19:09:40.836Z,1590001780.836 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 8194 2020-05-20T19:09:40.836Z,1590001780.836 [CTD_Seabird](DEBUG): Initializing CTD_Seabird. 2020-05-20T19:09:40.841Z,1590001780.841 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 8196 2020-05-20T19:09:40.842Z,1590001780.842 [WetLabsBB2FL](INFO): Powering down 2020-05-20T19:09:40.872Z,1590001780.872 [WetLabsUBAT ThreadHandler](INFO): Handler Thread ID is 8197 2020-05-20T19:09:40.887Z,1590001780.887 [CBIT](DEBUG): Deactivating GF circuits. 2020-05-20T19:09:40.887Z,1590001780.887 [CBIT](DEBUG): Deactivating emergency mode. 2020-05-20T19:09:40.888Z,1590001780.888 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 8198 2020-05-20T19:09:40.891Z,1590001780.891 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2020-05-20T19:09:40.891Z,1590001780.891 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2020-05-20T19:09:40.892Z,1590001780.892 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2020-05-20T19:09:40.892Z,1590001780.892 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2020-05-20T19:09:40.892Z,1590001780.892 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2020-05-20T19:09:40.892Z,1590001780.892 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2020-05-20T19:09:40.892Z,1590001780.892 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000 2020-05-20T19:09:40.892Z,1590001780.892 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2020-05-20T19:09:40.893Z,1590001780.893 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2020-05-20T19:09:40.893Z,1590001780.893 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2020-05-20T19:09:40.893Z,1590001780.893 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000 2020-05-20T19:09:40.893Z,1590001780.893 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2020-05-20T19:09:40.893Z,1590001780.893 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000 2020-05-20T19:09:40.893Z,1590001780.893 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2020-05-20T19:09:40.894Z,1590001780.894 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000 2020-05-20T19:09:40.894Z,1590001780.894 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2020-05-20T19:09:40.923Z,1590001780.923 [CBIT](DEBUG): Backplane powered. 2020-05-20T19:09:40.925Z,1590001780.925 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2020-05-20T19:09:40.935Z,1590001780.935 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2020-05-20T19:09:40.946Z,1590001780.946 [MissionManager](DEBUG): 2020-05-20T19:09:40.946Z,1590001780.946 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2020-05-20T19:09:41.040Z,1590001781.040 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2020-05-20T19:09:41.041Z,1590001781.041 [Default:A.Wait](DEBUG): Construct Wait. 2020-05-20T19:09:41.043Z,1590001781.043 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2020-05-20T19:09:41.085Z,1590001781.085 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2020-05-20T19:09:41.107Z,1590001781.107 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2020-05-20T19:09:41.147Z,1590001781.147 [Default:E.Execute](DEBUG): Construct Execute. 2020-05-20T19:09:41.151Z,1590001781.151 [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-20T19:09:41.155Z,1590001781.155 [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-20T19:09:41.175Z,1590001781.175 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2020-05-20T19:09:41.215Z,1590001781.215 [Radio_Surface](INFO): Powering up 2020-05-20T19:09:41.254Z,1590001781.254 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2 2020-05-20T19:09:41.254Z,1590001781.254 [DAT](INFO): Powering up 2020-05-20T19:09:41.255Z,1590001781.255 [DAT](DEBUG): Initializing DAT. 2020-05-20T19:09:41.336Z,1590001781.336 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2020-05-20T19:09:41.344Z,1590001781.344 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2020-05-20T19:09:41.345Z,1590001781.345 [ElevatorServo](DEBUG): Initializing EZServoServo. 2020-05-20T19:09:41.348Z,1590001781.348 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2 2020-05-20T19:09:41.375Z,1590001781.375 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2020-05-20T19:09:41.377Z,1590001781.377 [MassServo](DEBUG): Initializing EZServoServo. 2020-05-20T19:09:41.380Z,1590001781.380 [MassServo](DEBUG): Initializing MassServo. 2020-05-20T19:09:41.381Z,1590001781.381 [RudderServo](DEBUG): Initializing EZServoServo. 2020-05-20T19:09:41.392Z,1590001781.392 [RudderServo](DEBUG): Initializing RudderServo. 2020-05-20T19:09:41.393Z,1590001781.393 [ThrusterServo](DEBUG): Initializing EZServoServo. 2020-05-20T19:09:41.404Z,1590001781.404 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2020-05-20T19:09:41.589Z,1590001781.589 [DropWeight](CRITICAL): DROP WEIGHT MISSING. 2020-05-20T19:09:41.589Z,1590001781.589 [DropWeight] Hardware Fault, FailCount= 1 2020-05-20T19:09:41.589Z,1590001781.589 [DropWeight](ERROR): Hardware Fault 2020-05-20T19:09:41.618Z,1590001781.618 [CommandLine](FAULT): Scheduling is paused 2020-05-20T19:09:41.618Z,1590001781.618 [CBIT](INFO): Critical error at 20200520T190941 2020-05-20T19:09:41.618Z,1590001781.618 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals 2020-05-20T19:09:41.629Z,1590001781.629 [CBIT](ERROR): Hardware Fault in component: DropWeight 2020-05-20T19:09:41.629Z,1590001781.629 [CBIT](CRITICAL): Hardware Fault in component: DropWeight 2020-05-20T19:09:42.315Z,1590001782.315 [RudderServo](ERROR): Rudder initialization uart error serial timeout 2020-05-20T19:09:42.315Z,1590001782.315 [RudderServo](FAULT): Rudder failed to initialize 2020-05-20T19:09:42.316Z,1590001782.316 [RudderServo] Communications Fault, FailCount= 1 2020-05-20T19:09:42.316Z,1590001782.316 [RudderServo](ERROR): Communications Fault 2020-05-20T19:09:42.425Z,1590001782.425 [CBIT](INFO): Critical error at 20200520T190941 2020-05-20T19:09:42.428Z,1590001782.428 [CBIT](ERROR): Communications Fault in component: RudderServo 2020-05-20T19:09:42.590Z,1590001782.590 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2020-05-20T19:09:42.590Z,1590001782.590 [RudderServo](INFO): Powering down 2020-05-20T19:09:43.275Z,1590001783.275 [RudderServo](DEBUG): Initializing EZServoServo. 2020-05-20T19:09:43.408Z,1590001783.408 [RudderServo](DEBUG): Initializing RudderServo. 2020-05-20T19:09:43.412Z,1590001783.412 [CBIT](INFO): Clearing failed state for component RudderServo 2020-05-20T19:09:43.413Z,1590001783.413 [RudderServo] No Fault, FailCount= 1 2020-05-20T19:10:08.293Z,1590001808.293 [NAL9602](INFO): Powering up NAL9602 2020-05-20T19:10:20.469Z,1590001820.469 [SBIT](IMPORTANT): Beginning Startup BIT 2020-05-20T19:10:20.481Z,1590001820.481 [CBIT](IMPORTANT): Beginning ground fault scan 2020-05-20T19:10:27.539Z,1590001827.539 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.005583 2020-05-20T19:10:29.059Z,1590001829.059 [NAL9602](ERROR): NAL9602 initialization error. 2020-05-20T19:10:29.059Z,1590001829.059 [NAL9602] Communications Fault, FailCount= 1 2020-05-20T19:10:29.059Z,1590001829.059 [NAL9602](ERROR): Communications Fault 2020-05-20T19:10:29.199Z,1590001829.199 [CBIT](ERROR): Communications Fault in component: NAL9602 2020-05-20T19:10:29.469Z,1590001829.469 [NAL9602](INFO): Powering down 2020-05-20T19:10:30.409Z,1590001830.409 [CBIT](INFO): Clearing failed state for component NAL9602 2020-05-20T19:10:30.409Z,1590001830.409 [NAL9602] No Fault, FailCount= 1 2020-05-20T19:10:31.576Z,1590001831.576 [CBIT](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): 0.000894 CHAN A1 (24V): 0.036440 CHAN A2 (12V): -0.007371 CHAN A3 (5V): -0.001907 CHAN B0 (3.3V): 0.000940 CHAN B1 (3.15aV): 0.000011 CHAN B2 (3.15bV): -0.000626 CHAN B3 (GND): 0.000974 OPEN: 0.005143 Full Scale Calc: 4.765 mA, -1.589 mA 2020-05-20T19:10:41.335Z,1590001841.335 [DAT](FAULT): failed to initialize, no bytes available on serial interface 2020-05-20T19:10:41.336Z,1590001841.336 [DAT] Communications Fault, FailCount= 1 2020-05-20T19:10:41.336Z,1590001841.336 [DAT](ERROR): Communications Fault 2020-05-20T19:10:41.548Z,1590001841.548 [CBIT](ERROR): Communications Fault in component: DAT 2020-05-20T19:10:41.790Z,1590001841.790 [DAT](INFO): Powering down 2020-05-20T19:10:42.619Z,1590001842.619 [CBIT](INFO): Clearing failed state for component DAT 2020-05-20T19:10:42.619Z,1590001842.619 [DAT] No Fault, FailCount= 1 2020-05-20T19:10:44.980Z,1590001844.980 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2 2020-05-20T19:10:44.981Z,1590001844.981 [DAT](INFO): Powering up 2020-05-20T19:10:44.981Z,1590001844.981 [DAT](DEBUG): Initializing DAT. 2020-05-20T19:10:45.068Z,1590001845.068 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2 2020-05-20T19:10:55.484Z,1590001855.484 [DAT](DEBUG): 2020-05-20T19:10:55.485Z,1590001855.485 [DAT](DEBUG): Teledyne Benthos DAT-900 Series 2020-05-20T19:10:56.702Z,1590001856.702 [DAT](DEBUG): MF Frequency Band 2020-05-20T19:10:56.703Z,1590001856.703 [DAT](DEBUG): Directional Acoustic Transponder version 8.12.21 2020-05-20T19:10:56.704Z,1590001856.704 [DAT](DEBUG): May 20 2020 19:10:35 2020-05-20T19:10:57.506Z,1590001857.506 [DAT](DEBUG): Features enabled [Bearing] 2020-05-20T19:10:57.507Z,1590001857.507 [DAT](DEBUG): CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP 2020-05-20T19:10:57.508Z,1590001857.508 [DAT](INFO): commRate: 800 2020-05-20T19:10:57.924Z,1590001857.924 [DAT](INFO): entering command mode 2020-05-20T19:10:58.307Z,1590001858.307 [DAT](DEBUG): checking for command mode acknowledgment 2020-05-20T19:10:58.727Z,1590001858.727 [DAT](DEBUG): checking for command mode acknowledgment 2020-05-20T19:10:58.728Z,1590001858.728 [DAT](INFO): command mode acknowledged 2020-05-20T19:10:58.728Z,1590001858.728 [DAT](INFO): setting verbose to 3 2020-05-20T19:10:59.122Z,1590001859.122 [DAT](DEBUG): checking for verbose setting acknowledgment 2020-05-20T19:10:59.123Z,1590001859.123 [DAT](INFO): set verbose to 3 2020-05-20T19:10:59.502Z,1590001859.502 [NAL9602](INFO): Powering up NAL9602 2020-05-20T19:10:59.518Z,1590001859.518 [DAT](INFO): setting transmit power to 8 2020-05-20T19:10:59.934Z,1590001859.934 [DAT](DEBUG): checking for transmit power setting acknowledgment 2020-05-20T19:11:00.327Z,1590001860.327 [DAT](DEBUG): checking for transmit power setting acknowledgment 2020-05-20T19:11:00.328Z,1590001860.328 [DAT](INFO): set transmit power to 8 2020-05-20T19:11:00.737Z,1590001860.737 [DAT](INFO): setting local address to 9 2020-05-20T19:11:01.158Z,1590001861.158 [DAT](DEBUG): checking for local address setting acknowledgment 2020-05-20T19:11:01.539Z,1590001861.539 [DAT](DEBUG): checking for local address setting acknowledgment 2020-05-20T19:11:01.540Z,1590001861.540 [DAT](INFO): set local address to 9 2020-05-20T19:11:10.526Z,1590001870.526 [NAL9602](INFO): NAL9602 initialized 2020-05-20T19:11:14.202Z,1590001874.202 [SBIT](IMPORTANT): SBIT PASSED 2020-05-20T19:11:14.202Z,1590001874.202 [SBIT](FAULT): Ignoring configuration overrides from Data/persisted.cfg 2020-05-20T19:11:14.615Z,1590001874.615 [MissionManager](IMPORTANT): Started mission Startup 2020-05-20T19:11:14.615Z,1590001874.615 [Startup] Running Loop=1 2020-05-20T19:11:14.615Z,1590001874.615 [Startup](DEBUG): Aggregate::initialize Startup 2020-05-20T19:11:14.615Z,1590001874.615 [Startup:A.GoToSurface] Running Loop=1 2020-05-20T19:11:14.616Z,1590001874.616 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2020-05-20T19:11:14.616Z,1590001874.616 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2020-05-20T19:11:14.617Z,1590001874.617 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2020-05-20T19:11:14.617Z,1590001874.617 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2020-05-20T19:11:14.617Z,1590001874.617 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2020-05-20T19:11:14.618Z,1590001874.618 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2020-05-20T19:11:14.619Z,1590001874.619 [Startup:StartupSatComms] Running Loop=1 2020-05-20T19:11:14.620Z,1590001874.620 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2020-05-20T19:11:14.620Z,1590001874.620 [Startup:StartupSatComms:A] Running Loop=1 2020-05-20T19:11:15.025Z,1590001875.025 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2020-05-20T19:12:14.801Z,1590001934.801 [Startup:StartupSatComms:A](INFO): Timed out from 2020-05-20T19:11:14.6Z 2020-05-20T19:12:14.801Z,1590001934.801 [Startup:StartupSatComms:A] Stopped 2020-05-20T19:12:14.801Z,1590001934.801 [Startup:StartupSatComms:B] Running Loop=1 2020-05-20T19:12:15.188Z,1590001935.188 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2020-05-20T19:12:22.404Z,1590001942.404 [DataOverHttps](INFO): Sending 494 bytes from file Logs/20200520T190057/Courier0004.lzma 2020-05-20T19:12:23.405Z,1590001943.405 [DataOverHttps](INFO): Moved sent file to Logs/20200520T190057/Courier0004.lzma.bak 2020-05-20T19:12:23.406Z,1590001943.406 [DataOverHttps](INFO): SBD MOMSN=12339505 2020-05-20T19:12:39.472Z,1590001959.472 [DataOverHttps](INFO): Sending 135 bytes from file Logs/20200520T190930/Courier0000.lzma 2020-05-20T19:12:40.473Z,1590001960.473 [DataOverHttps](INFO): Moved sent file to Logs/20200520T190930/Courier0000.lzma.bak 2020-05-20T19:12:40.473Z,1590001960.473 [DataOverHttps](INFO): SBD MOMSN=12339532 2020-05-20T19:12:41.066Z,1590001961.066 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2020-05-20T19:12:41.066Z,1590001961.066 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-05-20T19:12:41.075Z,1590001961.075 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-05-20T19:12:41.470Z,1590001961.470 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-05-20T19:12:41.470Z,1590001961.470 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2020-05-20T19:12:56.694Z,1590001976.694 [DataOverHttps](INFO): Sending 926 bytes from file Logs/20200504T180216/Express0001.lzma 2020-05-20T19:12:57.689Z,1590001977.689 [DataOverHttps](INFO): Moved sent file to Logs/20200504T180216/Express0001.lzma.bak 2020-05-20T19:12:57.689Z,1590001977.689 [DataOverHttps](INFO): SBD MOMSN=12339542 2020-05-20T19:13:13.821Z,1590001993.821 [DataOverHttps](INFO): Sending 176 bytes from file Logs/20200504T180216/Express0005.lzma 2020-05-20T19:13:14.821Z,1590001994.821 [DataOverHttps](INFO): Moved sent file to Logs/20200504T180216/Express0005.lzma.bak 2020-05-20T19:13:14.821Z,1590001994.821 [DataOverHttps](INFO): SBD MOMSN=12339576 2020-05-20T19:13:15.038Z,1590001995.038 [Startup:StartupSatComms:B](INFO): Timed out from 2020-05-20T19:12:14.8Z 2020-05-20T19:13:15.038Z,1590001995.038 [Startup:StartupSatComms:B] Stopped 2020-05-20T19:13:15.038Z,1590001995.038 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2020-05-20T19:13:15.038Z,1590001995.038 [Startup:StartupSatComms] Stopped 2020-05-20T19:13:15.039Z,1590001995.039 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2020-05-20T19:13:15.040Z,1590001995.040 [Startup](INFO): Completed Startup 2020-05-20T19:13:15.040Z,1590001995.040 [MissionManager](INFO): Startup is completed. 2020-05-20T19:13:15.040Z,1590001995.040 [MissionManager](INFO): Uninitializing Mission Startup 2020-05-20T19:13:15.040Z,1590001995.040 [Startup] Stopped 2020-05-20T19:13:15.040Z,1590001995.040 [Startup](DEBUG): Aggregate::uninitialize Startup 2020-05-20T19:13:15.040Z,1590001995.040 [Startup:A.GoToSurface] Stopped 2020-05-20T19:13:15.040Z,1590001995.040 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2020-05-20T19:13:15.408Z,1590001995.408 [MissionManager](IMPORTANT): Started mission Default 2020-05-20T19:13:15.409Z,1590001995.409 [Default] Running Loop=1 2020-05-20T19:13:15.409Z,1590001995.409 [Default](DEBUG): Aggregate::initialize Default 2020-05-20T19:13:15.409Z,1590001995.409 [Default:B.GoToSurface] Running Loop=1 2020-05-20T19:13:15.409Z,1590001995.409 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2020-05-20T19:13:15.409Z,1590001995.409 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2020-05-20T19:13:15.409Z,1590001995.409 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2020-05-20T19:13:15.410Z,1590001995.410 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2020-05-20T19:13:15.410Z,1590001995.410 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2020-05-20T19:13:15.410Z,1590001995.410 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2020-05-20T19:13:15.411Z,1590001995.411 [Default:A.Wait] Running Loop=1 2020-05-20T19:13:15.411Z,1590001995.411 [Default:A.Wait](DEBUG): Initialize Wait Component. 2020-05-20T19:13:28.751Z,1590002008.751 [Default:A.Wait](INFO): Done Waiting. 2020-05-20T19:13:28.752Z,1590002008.752 [Default:A.Wait] Stopped 2020-05-20T19:13:28.752Z,1590002008.752 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2020-05-20T19:13:29.120Z,1590002009.120 [Default:CheckIn] Running Loop=1 2020-05-20T19:13:29.120Z,1590002009.120 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-05-20T19:13:29.120Z,1590002009.120 [Default:CheckIn:Read_GPS] Running Loop=1 2020-05-20T19:13:29.533Z,1590002009.533 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2020-05-20T19:15:42.039Z,1590002142.039 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2 2020-05-20T19:15:42.039Z,1590002142.039 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-05-20T19:15:42.054Z,1590002142.054 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-05-20T19:15:42.490Z,1590002142.490 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-05-20T19:15:42.490Z,1590002142.490 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2 2020-05-20T19:16:09.982Z,1590002169.982 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2020-05-20T19:16:10.050Z,1590002170.050 [BPC1](INFO): Received data from all battery sticks. 2020-05-20T19:16:13.929Z,1590002173.929 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2020-05-20T19:16:59.017Z,1590002219.017 [CommandLine](IMPORTANT): got command run ./Missions/Demo/senddata_direct_test.xml 2020-05-20T19:16:59.017Z,1590002219.017 [MissionManager](INFO): Loading Mission: ./Missions/Demo/senddata_direct_test.xml 2020-05-20T19:16:59.051Z,1590002219.051 [MissionManager](DEBUG): 2020-05-20T19:16:59.053Z,1590002219.053 [CommandLine](IMPORTANT): Running ./Missions/Demo/senddata_direct_test.xml 2020-05-20T19:16:59.220Z,1590002219.220 [Default] Stopped 2020-05-20T19:16:59.220Z,1590002219.220 [Default](DEBUG): Aggregate::uninitialize Default 2020-05-20T19:16:59.220Z,1590002219.220 [Default:B.GoToSurface] Stopped 2020-05-20T19:16:59.220Z,1590002219.220 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2020-05-20T19:16:59.221Z,1590002219.221 [Default:CheckIn] Stopped 2020-05-20T19:16:59.221Z,1590002219.221 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-05-20T19:16:59.221Z,1590002219.221 [Default:CheckIn:Read_GPS] Stopped 2020-05-20T19:16:59.221Z,1590002219.221 [MissionManager](IMPORTANT): Started mission senddata_direct_test 2020-05-20T19:16:59.221Z,1590002219.221 [senddata_direct_test] Running Loop=1 2020-05-20T19:16:59.221Z,1590002219.221 [senddata_direct_test](DEBUG): Aggregate::initialize senddata_direct_test 2020-05-20T19:16:59.221Z,1590002219.221 [senddata_direct_test:A] Running Loop=1 2020-05-20T19:16:59.222Z,1590002219.222 [senddata_direct_test:A] Stopped 2020-05-20T19:16:59.222Z,1590002219.222 [senddata_direct_test:B] Running Loop=1 2020-05-20T19:16:59.631Z,1590002219.631 [DAT](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?) 2020-05-20T19:16:59.632Z,1590002219.632 [DAT](CRITICAL): Backtrace: ./bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x17ddfc] /lib/libstdc++.so.6 [0x4020bb88] /lib/libstdc++.so.6(_ZSt9terminatev+0x18) [0x4020bbc4] Modules/Sensor.so(_ZN3DAT8runnableEv+0x1a0) [0x406d3eac] ./bin/LRAUV(_ZN9Component7executeEv+0x31c) [0xd7d10] ./bin/LRAUV(_ZN7PCaller10PThreadRunEPv+0xc8) [0x17d948] 2020-05-20T19:16:59.632Z,1590002219.632 [DAT] Software Fault, FailCount= 2 2020-05-20T19:16:59.632Z,1590002219.632 [DAT](ERROR): Software Fault 2020-05-20T19:16:59.647Z,1590002219.647 [DAT](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?) 2020-05-20T19:16:59.648Z,1590002219.648 [DAT](CRITICAL): Backtrace: ./bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x17ddfc] /lib/libstdc++.so.6(_ZSt9terminatev+0x18) [0x4020bbc4] Modules/Sensor.so(_ZN3DAT8runnableEv+0x1a0) [0x406d3eac] ./bin/LRAUV(_ZN9Component7executeEv+0x31c) [0xd7d10] ./bin/LRAUV(_ZN7PCaller10PThreadRunEPv+0xc8) [0x17d948] 2020-05-20T19:16:59.653Z,1590002219.653 [DAT](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?) 2020-05-20T19:16:59.654Z,1590002219.654 [DAT](CRITICAL): Backtrace: ./bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x17ddfc] /lib/libstdc++.so.6 [0x4020bb88] /lib/libstdc++.so.6(_ZSt9terminatev+0x18) [0x4020bbc4] /lib/libgcc_s.so.1 [0x402e1264] [(nil)] 2020-05-20T19:16:59.662Z,1590002219.662 [DAT](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?) 2020-05-20T19:16:59.663Z,1590002219.663 [DAT](CRITICAL): Backtrace: ./bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x17ddfc] /lib/libstdc++.so.6 [0x4020bb88] /lib/libstdc++.so.6(_ZSt9terminatev+0x18) [0x4020bbc4] /lib/libstdc++.so.6 [0x4020bb98] /lib/libstdc++.so.6(_ZSt9terminatev+0x18) [0x4020bbc4] /lib/libgcc_s.so.1 [0x402e1264] [(nil)] 2020-05-20T19:16:59.739Z,1590002219.739 [DAT](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?) 2020-05-20T19:16:59.741Z,1590002219.741 [DAT](CRITICAL): Backtrace: ./bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x17ddfc] /lib/libstdc++.so.6 [0x4020bb88] /lib/libstdc++.so.6(_ZSt9terminatev+0x18) [0x4020bbc4] /lib/libstdc++.so.6 [0x4020bb98] /lib/libstdc++.so.6(_ZSt9terminatev+0x18) [0x4020bbc4] /lib/libstdc++.so.6 [0x4020bb98] /lib/libstdc++.so.6(_ZSt9terminatev+0x18) [0x4020bbc4] /lib/libgcc_s.so.1 [0x402e1264] [(nil)] 2020-05-20T19:16:59.797Z,1590002219.797 [DAT](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?) 2020-05-20T19:16:59.798Z,1590002219.798 [DAT](CRITICAL): Backtrace: ./bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x17ddfc] /lib/libstdc++.so.6 [0x4020bb88] /lib/libstdc++.so.6(_ZSt9terminatev+0x18) [0x4020bbc4] /lib/libstdc++.so.6 [0x4020bb98] /lib/libstdc++.so.6(_ZSt9terminatev+0x18) [0x4020bbc4] /lib/libstdc++.so.6 [0x4020bb98] /lib/libstdc++.so.6(_ZSt9terminatev+0x18) [0x4020bbc4] /lib/libstdc++.so.6 [0x4020bb98] /lib/libstdc++.so.6(_ZSt9terminatev+0x18) [0x4020bbc4] /lib/libgcc_s.so.1 [0x402e1264] [(nil)] 2020-05-20T19:17:00.233Z,1590002220.233 [DAT](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?) 2020-05-20T19:17:00.234Z,1590002220.234 [DAT](CRITICAL): Backtrace: ./bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x17ddfc] /lib/libstdc++.so.6 [0x4020bb88] /lib/libstdc++.so.6(_ZSt9terminatev+0x18) [0x4020bbc4] /lib/libstdc++.so.6 [0x4020bb98] /lib/libstdc++.so.6(_ZSt9terminatev+0x18) [0x4020bbc4] /lib/libstdc++.so.6 [0x4020bb98] /lib/libstdc++.so.6(_ZSt9terminatev+0x18) [0x4020bbc4] /lib/libstdc++.so.6 [0x4020bb98] /lib/libstdc++.so.6(_ZSt9terminatev+0x18) [0x4020bbc4] /lib/libstdc++.so.6 [0x4020bb98] /lib/libstdc++.so.6(_ZSt9terminatev+0x18) [0x4020bbc4] /lib/libgcc_s.so.1 [0x402e1264] [(nil)]