2020-09-29T20:11:50.540Z,1601410310.540 [Supervisor](DEBUG): Initializing supervisor.
2020-09-29T20:11:50.542Z,1601410310.542 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2020-09-29T20:11:50.543Z,1601410310.543 [SyncHandler](INFO): Protected caller Thread ID is 1221
2020-09-29T20:11:50.543Z,1601410310.543 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2020-09-29T20:11:50.544Z,1601410310.544 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2020-09-29T20:11:50.545Z,1601410310.545 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 1222
2020-09-29T20:11:50.547Z,1601410310.547 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2020-09-29T20:11:50.560Z,1601410310.560 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2020-09-29T20:11:50.561Z,1601410310.561 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2020-09-29T20:11:50.561Z,1601410310.561 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 1223
2020-09-29T20:11:50.562Z,1601410310.562 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2020-09-29T20:11:50.563Z,1601410310.563 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2020-09-29T20:11:50.563Z,1601410310.563 [logger ThreadHandler](INFO): Protected caller Thread ID is 1224
2020-09-29T20:11:50.565Z,1601410310.565 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2020-09-29T20:11:50.566Z,1601410310.566 [Supervisor](INFO): Looking for Config files in directory: Config/
2020-09-29T20:11:50.567Z,1601410310.567 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2020-09-29T20:11:50.659Z,1601410310.659 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2020-09-29T20:11:50.660Z,1601410310.660 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2020-09-29T20:11:51.243Z,1601410311.243 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2020-09-29T20:11:51.243Z,1601410311.243 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2020-09-29T20:11:51.429Z,1601410311.429 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2020-09-29T20:11:51.430Z,1601410311.430 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2020-09-29T20:11:51.526Z,1601410311.526 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2020-09-29T20:11:51.526Z,1601410311.526 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2020-09-29T20:11:51.626Z,1601410311.626 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2020-09-29T20:11:51.627Z,1601410311.627 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2020-09-29T20:11:51.705Z,1601410311.705 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2020-09-29T20:11:51.838Z,1601410311.838 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2020-09-29T20:11:51.839Z,1601410311.839 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2020-09-29T20:11:52.122Z,1601410312.122 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2020-09-29T20:11:52.122Z,1601410312.122 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2020-09-29T20:11:52.561Z,1601410312.561 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2020-09-29T20:11:52.562Z,1601410312.562 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2020-09-29T20:11:52.701Z,1601410312.701 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2020-09-29T20:11:52.701Z,1601410312.701 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2020-09-29T20:11:52.888Z,1601410312.888 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2020-09-29T20:11:52.888Z,1601410312.888 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2020-09-29T20:11:53.425Z,1601410313.425 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2020-09-29T20:11:53.426Z,1601410313.426 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2020-09-29T20:11:53.634Z,1601410313.634 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2020-09-29T20:11:53.635Z,1601410313.635 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2020-09-29T20:11:53.831Z,1601410313.831 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2020-09-29T20:11:53.831Z,1601410313.831 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2020-09-29T20:11:54.227Z,1601410314.227 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2020-09-29T20:11:54.228Z,1601410314.228 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2020-09-29T20:11:54.554Z,1601410314.554 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2020-09-29T20:11:54.556Z,1601410314.556 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-pontus/
2020-09-29T20:11:54.557Z,1601410314.557 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/secure.cfg
2020-09-29T20:11:54.637Z,1601410314.637 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Sensor.cfg
2020-09-29T20:11:54.785Z,1601410314.785 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Servo.cfg
2020-09-29T20:11:54.889Z,1601410314.889 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Simulator.cfg
2020-09-29T20:11:54.972Z,1601410314.972 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/logger.cfg
2020-09-29T20:11:55.064Z,1601410315.064 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/vehicle.cfg
2020-09-29T20:11:55.250Z,1601410315.250 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Battery.cfg
2020-09-29T20:11:55.519Z,1601410315.519 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2020-09-29T20:11:55.520Z,1601410315.520 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Navigation.cfg
2020-09-29T20:11:55.798Z,1601410315.798 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/BIT.cfg
2020-09-29T20:11:55.940Z,1601410315.940 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Science.cfg
2020-09-29T20:11:56.287Z,1601410316.287 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Control.cfg
2020-09-29T20:11:56.533Z,1601410316.533 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-pontus/root/
2020-09-29T20:11:56.534Z,1601410316.534 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2020-09-29T20:11:56.615Z,1601410316.615 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2020-09-29T20:11:56.690Z,1601410316.690 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2020-09-29T20:11:56.691Z,1601410316.691 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2020-09-29T20:11:56.736Z,1601410316.736 [VerticalControl](DEBUG): Construct VerticalControl.
2020-09-29T20:11:56.842Z,1601410316.842 [VerticalControl] Loaded
2020-09-29T20:11:56.843Z,1601410316.843 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2020-09-29T20:11:56.843Z,1601410316.843 [HorizontalControl](DEBUG): Construct HorizontalControl.
2020-09-29T20:11:56.919Z,1601410316.919 [HorizontalControl] Loaded
2020-09-29T20:11:56.919Z,1601410316.919 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2020-09-29T20:11:56.920Z,1601410316.920 [SpeedControl](DEBUG): Construct SpeedControl.
2020-09-29T20:11:56.925Z,1601410316.925 [SpeedControl] Loaded
2020-09-29T20:11:56.925Z,1601410316.925 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2020-09-29T20:11:56.926Z,1601410316.926 [LoopControl](DEBUG): Construct LoopControl.
2020-09-29T20:11:56.927Z,1601410316.927 [LoopControl] Loaded
2020-09-29T20:11:56.927Z,1601410316.927 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2020-09-29T20:11:56.927Z,1601410316.927 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2020-09-29T20:11:56.928Z,1601410316.928 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2020-09-29T20:11:56.967Z,1601410316.967 [DepthRateCalculator] Loaded
2020-09-29T20:11:56.968Z,1601410316.968 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2020-09-29T20:11:56.973Z,1601410316.973 [PitchRateCalculator] Loaded
2020-09-29T20:11:56.973Z,1601410316.973 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2020-09-29T20:11:56.988Z,1601410316.988 [SpeedCalculator] Loaded
2020-09-29T20:11:56.988Z,1601410316.988 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2020-09-29T20:11:57.008Z,1601410317.008 [TempGradientCalculator] Loaded
2020-09-29T20:11:57.008Z,1601410317.008 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2020-09-29T20:11:57.013Z,1601410317.013 [YawRateCalculator] Loaded
2020-09-29T20:11:57.013Z,1601410317.013 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2020-09-29T20:11:57.042Z,1601410317.042 [ElevatorOffsetCalculator] Loaded
2020-09-29T20:11:57.042Z,1601410317.042 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2020-09-29T20:11:57.043Z,1601410317.043 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2020-09-29T20:11:57.043Z,1601410317.043 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2020-09-29T20:11:57.069Z,1601410317.069 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2020-09-29T20:11:57.070Z,1601410317.070 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2020-09-29T20:11:57.151Z,1601410317.151 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2020-09-29T20:11:57.152Z,1601410317.152 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2020-09-29T20:11:57.427Z,1601410317.427 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2020-09-29T20:11:57.427Z,1601410317.427 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2020-09-29T20:11:57.521Z,1601410317.521 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2020-09-29T20:11:57.522Z,1601410317.522 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2020-09-29T20:11:57.818Z,1601410317.818 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_orientation
2020-09-29T20:11:57.823Z,1601410317.823 [AHRS_M2](INFO): created writer for : platform_orientation
2020-09-29T20:11:57.825Z,1601410317.825 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_magnetic_orientation
2020-09-29T20:11:57.830Z,1601410317.830 [AHRS_M2](INFO): created writer for : platform_magnetic_orientation
2020-09-29T20:11:57.831Z,1601410317.831 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_pitch_angle
2020-09-29T20:11:57.835Z,1601410317.835 [AHRS_M2](INFO): created writer for : platform_pitch_angle
2020-09-29T20:11:57.836Z,1601410317.836 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_roll_angle
2020-09-29T20:11:57.841Z,1601410317.841 [AHRS_M2](INFO): created writer for : platform_roll_angle
2020-09-29T20:11:57.909Z,1601410317.909 [AHRS_M2] Loaded
2020-09-29T20:11:57.909Z,1601410317.909 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2020-09-29T20:11:57.984Z,1601410317.984 [DataOverHttps] Loaded
2020-09-29T20:11:57.984Z,1601410317.984 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2020-09-29T20:11:57.985Z,1601410317.985 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4090D4E0
2020-09-29T20:11:57.986Z,1601410317.986 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 1307
2020-09-29T20:11:58.015Z,1601410318.015 [Depth_Keller] Loaded
2020-09-29T20:11:58.015Z,1601410318.015 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2020-09-29T20:11:58.125Z,1601410318.125 [NAL9602] Loaded
2020-09-29T20:11:58.125Z,1601410318.125 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2020-09-29T20:11:58.172Z,1601410318.172 [Onboard] Loaded
2020-09-29T20:11:58.172Z,1601410318.172 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2020-09-29T20:11:58.173Z,1601410318.173 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 4093D4E0
2020-09-29T20:11:58.174Z,1601410318.174 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 1308
2020-09-29T20:11:58.192Z,1601410318.192 [Radio_Surface] Loaded
2020-09-29T20:11:58.192Z,1601410318.192 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2020-09-29T20:11:58.193Z,1601410318.193 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4096D4E0
2020-09-29T20:11:58.194Z,1601410318.194 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 1309
2020-09-29T20:11:58.252Z,1601410318.252 [RDI_Pathfinder] Loaded
2020-09-29T20:11:58.252Z,1601410318.252 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread.
2020-09-29T20:11:58.396Z,1601410318.396 [DAT] Loaded
2020-09-29T20:11:58.397Z,1601410318.397 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread.
2020-09-29T20:11:59.847Z,1601410319.847 [BPC1] Loaded
2020-09-29T20:11:59.847Z,1601410319.847 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2020-09-29T20:11:59.847Z,1601410319.847 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2020-09-29T20:11:59.848Z,1601410319.848 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2020-09-29T20:11:59.960Z,1601410319.960 [DeadReckonUsingMultipleVelocitySources] Loaded
2020-09-29T20:11:59.960Z,1601410319.960 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2020-09-29T20:11:59.980Z,1601410319.980 [NavChart] Loaded
2020-09-29T20:11:59.980Z,1601410319.980 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2020-09-29T20:11:59.984Z,1601410319.984 [UniversalFixResidualReporter] Loaded
2020-09-29T20:11:59.984Z,1601410319.984 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2020-09-29T20:11:59.985Z,1601410319.985 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2020-09-29T20:11:59.985Z,1601410319.985 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2020-09-29T20:12:00.116Z,1601410320.116 [SBIT](DEBUG): Construct Startup Built In Test.
2020-09-29T20:12:00.126Z,1601410320.126 [SBIT] Loaded
2020-09-29T20:12:00.127Z,1601410320.127 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2020-09-29T20:12:00.128Z,1601410320.128 [IBIT](DEBUG): Construct Initiated Built In Test.
2020-09-29T20:12:00.140Z,1601410320.140 [IBIT] Loaded
2020-09-29T20:12:00.140Z,1601410320.140 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2020-09-29T20:12:00.143Z,1601410320.143 [CBIT](DEBUG): Construct Continuous Built In Test.
2020-09-29T20:12:00.277Z,1601410320.277 [CBIT] Loaded
2020-09-29T20:12:00.278Z,1601410320.278 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2020-09-29T20:12:00.278Z,1601410320.278 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2020-09-29T20:12:00.278Z,1601410320.278 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2020-09-29T20:12:00.390Z,1601410320.390 [ElevatorServo] Loaded
2020-09-29T20:12:00.390Z,1601410320.390 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2020-09-29T20:12:00.417Z,1601410320.417 [MassServo] Loaded
2020-09-29T20:12:00.417Z,1601410320.417 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2020-09-29T20:12:00.444Z,1601410320.444 [RudderServo] Loaded
2020-09-29T20:12:00.444Z,1601410320.444 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2020-09-29T20:12:00.470Z,1601410320.470 [ThrusterServo] Loaded
2020-09-29T20:12:00.470Z,1601410320.470 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2020-09-29T20:12:00.470Z,1601410320.470 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2020-09-29T20:12:00.471Z,1601410320.471 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2020-09-29T20:12:00.489Z,1601410320.489 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2020-09-29T20:12:00.490Z,1601410320.490 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2020-09-29T20:12:00.718Z,1601410320.718 [BackSeatDriver] Loaded
2020-09-29T20:12:00.718Z,1601410320.718 [ComponentRegistry](DEBUG): Component "BackSeatDriver" handled in its own thread.
2020-09-29T20:12:00.719Z,1601410320.719 [BackSeatDriver ThreadHandler](DEBUG): Created PCaller Thread at 40B054E0
2020-09-29T20:12:00.720Z,1601410320.720 [BackSeatDriver ThreadHandler](INFO): Protected caller Thread ID is 1310
2020-09-29T20:12:00.747Z,1601410320.747 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_density
2020-09-29T20:12:00.752Z,1601410320.752 [CTD_Seabird](INFO): created writer for : sea_water_density
2020-09-29T20:12:00.753Z,1601410320.753 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): depth
2020-09-29T20:12:00.757Z,1601410320.757 [CTD_Seabird](INFO): created writer for : depth
2020-09-29T20:12:00.758Z,1601410320.758 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_pressure
2020-09-29T20:12:00.762Z,1601410320.762 [CTD_Seabird](INFO): created writer for : sea_water_pressure
2020-09-29T20:12:00.763Z,1601410320.763 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_salinity
2020-09-29T20:12:00.768Z,1601410320.768 [CTD_Seabird](INFO): created writer for : sea_water_salinity
2020-09-29T20:12:00.768Z,1601410320.768 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_temperature
2020-09-29T20:12:00.773Z,1601410320.773 [CTD_Seabird](INFO): created writer for : sea_water_temperature
2020-09-29T20:12:00.774Z,1601410320.774 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_electrical_conductivity
2020-09-29T20:12:00.779Z,1601410320.779 [CTD_Seabird](INFO): created writer for : sea_water_electrical_conductivity
2020-09-29T20:12:00.780Z,1601410320.780 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): speed_of_sound_in_sea_water
2020-09-29T20:12:00.785Z,1601410320.785 [CTD_Seabird](INFO): created writer for : speed_of_sound_in_sea_water
2020-09-29T20:12:00.812Z,1601410320.812 [CTD_Seabird] Loaded
2020-09-29T20:12:00.812Z,1601410320.812 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2020-09-29T20:12:00.813Z,1601410320.813 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40B354E0
2020-09-29T20:12:00.813Z,1601410320.813 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 1311
2020-09-29T20:12:00.863Z,1601410320.863 [ESPComponent] Loaded
2020-09-29T20:12:00.863Z,1601410320.863 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2020-09-29T20:12:00.884Z,1601410320.884 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.Output470
2020-09-29T20:12:00.884Z,1601410320.884 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: Output470
2020-09-29T20:12:00.888Z,1601410320.888 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.Output650
2020-09-29T20:12:00.888Z,1601410320.888 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: Output650
2020-09-29T20:12:00.893Z,1601410320.893 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.OutputChl
2020-09-29T20:12:00.893Z,1601410320.893 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: OutputChl
2020-09-29T20:12:00.897Z,1601410320.897 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.VolumeScatCoeff117deg470nm
2020-09-29T20:12:00.897Z,1601410320.897 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: VolumeScatCoeff117deg470nm
2020-09-29T20:12:00.901Z,1601410320.901 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.VolumeScatCoeff117deg650nm
2020-09-29T20:12:00.901Z,1601410320.901 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: VolumeScatCoeff117deg650nm
2020-09-29T20:12:00.906Z,1601410320.906 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.BackscatteringCoeff470nm
2020-09-29T20:12:00.906Z,1601410320.906 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: BackscatteringCoeff470nm
2020-09-29T20:12:00.910Z,1601410320.910 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.BackscatteringCoeff650nm
2020-09-29T20:12:00.910Z,1601410320.910 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: BackscatteringCoeff650nm
2020-09-29T20:12:00.914Z,1601410320.914 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): mass_concentration_of_chlorophyll_in_sea_water
2020-09-29T20:12:00.918Z,1601410320.918 [WetLabsBB2FL](INFO): created writer for : mass_concentration_of_chlorophyll_in_sea_water
2020-09-29T20:12:00.919Z,1601410320.919 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_median_mass_concentration_of_chlorophyll_in_sea_water
2020-09-29T20:12:00.919Z,1601410320.919 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_median_mass_concentration_of_chlorophyll_in_sea_water
2020-09-29T20:12:00.923Z,1601410320.923 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water
2020-09-29T20:12:00.923Z,1601410320.923 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_mean_mass_concentration_of_chlorophyll_in_sea_water
2020-09-29T20:12:00.927Z,1601410320.927 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_variance_mass_concentration_of_chlorophyll_in_sea_water
2020-09-29T20:12:00.928Z,1601410320.928 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_variance_mass_concentration_of_chlorophyll_in_sea_water
2020-09-29T20:12:00.932Z,1601410320.932 [WetLabsBB2FL] Loaded
2020-09-29T20:12:00.932Z,1601410320.932 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2020-09-29T20:12:00.933Z,1601410320.933 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40B654E0
2020-09-29T20:12:00.933Z,1601410320.933 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 1312
2020-09-29T20:12:00.934Z,1601410320.934 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2020-09-29T20:12:00.951Z,1601410320.951 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2020-09-29T20:12:00.952Z,1601410320.952 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2020-09-29T20:12:00.962Z,1601410320.962 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2020-09-29T20:12:00.963Z,1601410320.963 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B954E0
2020-09-29T20:12:00.963Z,1601410320.963 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 1313
2020-09-29T20:12:00.967Z,1601410320.967 [Supervisor](INFO): Main Thread ID is 1220
2020-09-29T20:12:00.968Z,1601410320.968 [Supervisor](DEBUG): Running supervisor.
2020-09-29T20:12:00.968Z,1601410320.968 [CommandLine ThreadHandler](INFO): Handler Thread ID is 1314
2020-09-29T20:12:00.971Z,1601410320.971 [controlThread ThreadHandler](INFO): Handler Thread ID is 1315
2020-09-29T20:12:00.971Z,1601410320.971 [controlThread](DEBUG): Initializing ControlThread
2020-09-29T20:12:00.972Z,1601410320.972 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2020-09-29T20:12:00.974Z,1601410320.974 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2020-09-29T20:12:00.974Z,1601410320.974 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2020-09-29T20:12:00.975Z,1601410320.975 [LoopControl](DEBUG): Initialize LoopControlComponent.
2020-09-29T20:12:00.975Z,1601410320.975 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2020-09-29T20:12:00.976Z,1601410320.976 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2020-09-29T20:12:00.976Z,1601410320.976 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2020-09-29T20:12:00.976Z,1601410320.976 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2020-09-29T20:12:00.977Z,1601410320.977 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2020-09-29T20:12:00.977Z,1601410320.977 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2020-09-29T20:12:00.980Z,1601410320.980 [NavChart](DEBUG): Initialize NavChart Navigation.
2020-09-29T20:12:00.981Z,1601410320.981 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2020-09-29T20:12:00.981Z,1601410320.981 [SBIT](INFO): Initialize SBIT Component.
2020-09-29T20:12:00.982Z,1601410320.981 [SBIT](IMPORTANT): git: 2020-08-31-22-g228fdf4
2020-09-29T20:12:00.982Z,1601410320.982 [SBIT](INFO): git hash: 228fdf421bf98e6496346bd11bd08684ab6db7ac
2020-09-29T20:12:00.982Z,1601410320.982 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2020-09-29T20:12:00.983Z,1601410320.983 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #1 PREEMPT Thu Feb 21 11:17:40 PST 2019
Kernel Reported: #1 PREEMPT Thu Aug 6 12:04:53 PDT 2020
2020-09-29T20:12:00.984Z,1601410320.984 [SBIT](INFO): Beginning SBIT in 99.000000 seconds.
2020-09-29T20:12:00.985Z,1601410320.985 [IBIT](INFO): Initialize IBIT Component.
2020-09-29T20:12:00.986Z,1601410320.986 [CBIT](DEBUG): Initialize CBIT Component.
2020-09-29T20:12:00.987Z,1601410320.987 [logger ThreadHandler](INFO): Handler Thread ID is 1316
2020-09-29T20:12:00.999Z,1601410320.999 [CBIT](DEBUG): Initialized mux pins.
2020-09-29T20:12:00.999Z,1601410320.999 [CBIT](DEBUG): Initializing the watchdog timer.
2020-09-29T20:12:01.007Z,1601410321.007 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 1317
2020-09-29T20:12:01.008Z,1601410321.008 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2020-09-29T20:12:01.020Z,1601410321.020 [Onboard ThreadHandler](INFO): Handler Thread ID is 1318
2020-09-29T20:12:01.024Z,1601410321.024 [CBIT](CRITICAL): LAST REBOOT DUE TO WATCHDOG TIMER RESET.
2020-09-29T20:12:01.024Z,1601410321.024 [CBIT](DEBUG): Initializing heartbeat.
2020-09-29T20:12:01.040Z,1601410321.040 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 1319
2020-09-29T20:12:01.059Z,1601410321.059 [BackSeatDriver ThreadHandler](INFO): Handler Thread ID is 1320
2020-09-29T20:12:01.079Z,1601410321.079 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 1321
2020-09-29T20:12:01.080Z,1601410321.080 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2020-09-29T20:12:01.084Z,1601410321.084 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 1323
2020-09-29T20:12:01.085Z,1601410321.085 [WetLabsBB2FL](INFO): Powering down
2020-09-29T20:12:01.095Z,1601410321.095 [CBIT](DEBUG): Deactivating GF circuits.
2020-09-29T20:12:01.095Z,1601410321.095 [CBIT](DEBUG): Deactivating emergency mode.
2020-09-29T20:12:01.119Z,1601410321.119 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 1324
2020-09-29T20:12:01.122Z,1601410321.122 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2020-09-29T20:12:01.123Z,1601410321.123 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2020-09-29T20:12:01.123Z,1601410321.123 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2020-09-29T20:12:01.123Z,1601410321.123 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2020-09-29T20:12:01.123Z,1601410321.123 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2020-09-29T20:12:01.123Z,1601410321.123 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2020-09-29T20:12:01.124Z,1601410321.124 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2020-09-29T20:12:01.124Z,1601410321.124 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2020-09-29T20:12:01.124Z,1601410321.124 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2020-09-29T20:12:01.124Z,1601410321.124 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2020-09-29T20:12:01.124Z,1601410321.124 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2020-09-29T20:12:01.124Z,1601410321.124 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2020-09-29T20:12:01.125Z,1601410321.125 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2020-09-29T20:12:01.125Z,1601410321.125 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2020-09-29T20:12:01.125Z,1601410321.125 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2020-09-29T20:12:01.125Z,1601410321.125 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2020-09-29T20:12:01.131Z,1601410321.131 [CBIT](DEBUG): Backplane powered.
2020-09-29T20:12:01.133Z,1601410321.133 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2020-09-29T20:12:01.147Z,1601410321.147 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2020-09-29T20:12:01.166Z,1601410321.166 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Units="Tethys/Units"
       xmlns:Universal="Tethys/Universal"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
       Id="Startup">

    <Guidance:GoToSurface>
        <Progression/>
    </Guidance:GoToSurface>

    <Aggregate Id="StartupSatComms">

        <Sequence/>

        <ReadDatum>
            <Timeout Duration="P1M" />
            <Universal:latitude_fix/>
        </ReadDatum>

        <ReadDatum>
            <Timeout Duration="P1M" />
            <Universal:platform_communications/>
        </ReadDatum>

    </Aggregate>

</Mission>


2020-09-29T20:12:01.166Z,1601410321.166 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2020-09-29T20:12:01.251Z,1601410321.251 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2020-09-29T20:12:01.268Z,1601410321.268 [Default:A.Wait](DEBUG): Construct Wait.
2020-09-29T20:12:01.270Z,1601410321.270 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2020-09-29T20:12:01.300Z,1601410321.300 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2020-09-29T20:12:01.303Z,1601410321.303 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2020-09-29T20:12:01.323Z,1601410321.323 [Default:E.Execute](DEBUG): Construct Execute.
2020-09-29T20:12:01.326Z,1601410321.326 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Universal="Tethys/Universal"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                             Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                             Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
         Id="Default">

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

    <Guidance:Wait>
        <Description>
            Wait a moment to see if the scheduler starts a new mission before
            starting to actually run Default.
        </Description>
        <Sequence/>
        <Setting><Guidance:Wait.duration/><Units:second/><Value>13</Value></Setting>
    </Guidance:Wait>

    <Guidance:GoToSurface>
        <Progression/>
    </Guidance:GoToSurface>

    <Aggregate Id="CheckIn">

        <Sequence Repeat="288"/>

        <ReadDatum Id="Read_GPS">
            <Timeout Duration="P5M"/>
            <Universal:time_fix/>
        </ReadDatum>

        <ReadDatum Id="Read_Iridium">
            <Timeout Duration="P2H">
                <Guidance:Execute>
                    <Sequence/>
                    <Setting><Guidance:Execute.command/><String>Burn on</String></Setting>
                </Guidance:Execute>
                <Syslog Severity="Critical">Dropped weight due to communications timeout.</Syslog>
            </Timeout>
            <Universal:platform_communications/>
        </ReadDatum>

        <Guidance:Wait>
            <Sequence/>
            <Setting><Guidance:Wait.duration/><Units:minute/><Value>5</Value></Setting>
        </Guidance:Wait>

        <Assign><Sequence/><Arg Name="ElapsedSinceDefaultStarted"/><Elapsed><Universal:mission_started/></Elapsed></Assign>

        <Syslog Severity="Important">Default mission has been running for <Arg Name="ElapsedSinceDefaultStarted"/><Units:minute/></Syslog>

    </Aggregate>

    <Syslog Severity="Important">Restarting logs and Default mission.</Syslog>

    <Guidance:Execute>
        <Sequence/>
        <Setting><Guidance:Execute.command/><String>restart logs</String></Setting>
    </Guidance:Execute>

</Mission>


2020-09-29T20:12:01.330Z,1601410321.330 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,NAL9602,RDI_Pathfinder,DAT,BPC1,ESPComponent,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2020-09-29T20:12:01.355Z,1601410321.355 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2020-09-29T20:12:01.395Z,1601410321.395 [Depth_Keller](ERROR): Pressure reading out of range: 1650.297119 decibar
2020-09-29T20:12:01.422Z,1601410321.422 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2
2020-09-29T20:12:01.422Z,1601410321.422 [DAT](INFO): Powering up
2020-09-29T20:12:01.422Z,1601410321.422 [DAT](DEBUG): Initializing DAT.
2020-09-29T20:12:01.443Z,1601410321.443 [Radio_Surface](INFO): Powering up
2020-09-29T20:12:01.475Z,1601410321.475 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2
2020-09-29T20:12:01.499Z,1601410321.499 [DepthRateCalculator](ERROR): Depth measurement is not active
2020-09-29T20:12:01.522Z,1601410321.522 [ElevatorServo](DEBUG): Initializing EZServoServo.
2020-09-29T20:12:01.555Z,1601410321.555 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2020-09-29T20:12:01.557Z,1601410321.557 [MassServo](DEBUG): Initializing EZServoServo.
2020-09-29T20:12:01.567Z,1601410321.567 [MassServo](DEBUG): Initializing MassServo.
2020-09-29T20:12:01.568Z,1601410321.568 [RudderServo](DEBUG): Initializing EZServoServo.
2020-09-29T20:12:01.579Z,1601410321.579 [RudderServo](DEBUG): Initializing RudderServo.
2020-09-29T20:12:01.580Z,1601410321.580 [ThrusterServo](DEBUG): Initializing EZServoServo.
2020-09-29T20:12:01.592Z,1601410321.592 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2020-09-29T20:12:01.594Z,1601410321.594 [CommandLine](FAULT): Scheduling is paused
2020-09-29T20:12:01.594Z,1601410321.594 [CBIT](INFO): Critical error at 20200929T201201
2020-09-29T20:12:01.595Z,1601410321.595 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2020-09-29T20:12:01.771Z,1601410321.771 [DepthRateCalculator](ERROR): Depth measurement is not active
2020-09-29T20:12:02.455Z,1601410322.455 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2020-09-29T20:12:02.455Z,1601410322.455 [RudderServo](FAULT): Rudder failed to initialize
2020-09-29T20:12:02.455Z,1601410322.455 [RudderServo] Communications Fault, FailCount= 1
2020-09-29T20:12:02.455Z,1601410322.455 [RudderServo](ERROR): Communications Fault
2020-09-29T20:12:02.566Z,1601410322.566 [CBIT](ERROR): Communications Fault in component: RudderServo
2020-09-29T20:12:02.652Z,1601410322.652 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2020-09-29T20:12:02.652Z,1601410322.652 [RudderServo](INFO): Powering down
2020-09-29T20:12:03.394Z,1601410323.394 [RudderServo](DEBUG): Initializing EZServoServo.
2020-09-29T20:12:03.512Z,1601410323.512 [RudderServo](DEBUG): Initializing RudderServo.
2020-09-29T20:12:03.516Z,1601410323.516 [CBIT](INFO): Clearing failed state for component RudderServo
2020-09-29T20:12:03.516Z,1601410323.516 [RudderServo] No Fault, FailCount= 1
2020-09-29T20:12:11.184Z,1601410331.184 [CBIT](CRITICAL): Environmental Failure. Press:14.486802 PSI. Humidity:54%. Temp:22 C. ABORTING MISSION
2020-09-29T20:12:11.505Z,1601410331.505 [CBIT](INFO): Critical error at 20200929T201211
2020-09-29T20:12:15.511Z,1601410335.511 [DAT](INFO): commRate: 800
2020-09-29T20:12:15.511Z,1601410335.511 [DAT](INFO): commRate: 800
2020-09-29T20:12:15.913Z,1601410335.913 [DAT](INFO): entering command mode
2020-09-29T20:12:16.324Z,1601410336.324 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-29T20:12:16.721Z,1601410336.721 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-29T20:12:17.125Z,1601410337.125 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-29T20:12:17.540Z,1601410337.540 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-29T20:12:17.933Z,1601410337.933 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-29T20:12:18.337Z,1601410338.337 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-29T20:12:18.752Z,1601410338.752 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-29T20:12:19.156Z,1601410339.156 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-29T20:12:19.553Z,1601410339.553 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-29T20:12:19.968Z,1601410339.968 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-29T20:12:20.357Z,1601410340.357 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-29T20:12:20.765Z,1601410340.765 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-29T20:12:21.175Z,1601410341.175 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-29T20:12:21.569Z,1601410341.569 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-29T20:12:21.984Z,1601410341.984 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-29T20:12:22.373Z,1601410342.373 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-29T20:12:22.781Z,1601410342.781 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-29T20:12:23.203Z,1601410343.203 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-29T20:12:23.589Z,1601410343.589 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-29T20:12:24.039Z,1601410344.039 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-29T20:12:24.397Z,1601410344.397 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-29T20:12:24.802Z,1601410344.802 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-29T20:12:25.231Z,1601410345.231 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-29T20:12:25.605Z,1601410345.605 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-29T20:12:26.009Z,1601410346.009 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-29T20:12:26.487Z,1601410346.487 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-29T20:12:26.817Z,1601410346.817 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-29T20:12:27.221Z,1601410347.221 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-29T20:12:27.651Z,1601410347.651 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-29T20:12:28.060Z,1601410348.060 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-29T20:12:28.436Z,1601410348.436 [NAL9602](INFO): Powering up NAL9602
2020-09-29T20:12:28.438Z,1601410348.438 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-29T20:12:28.841Z,1601410348.841 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-29T20:12:29.260Z,1601410349.260 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-29T20:12:29.661Z,1601410349.661 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-29T20:12:30.092Z,1601410350.092 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-29T20:12:30.453Z,1601410350.453 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-29T20:12:30.861Z,1601410350.861 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-29T20:12:31.291Z,1601410351.291 [DAT](DEBUG): checking for command mode acknowledgment
2020-09-29T20:12:31.291Z,1601410351.291 [DAT](FAULT): failed to enter command mode
2020-09-29T20:12:31.669Z,1601410351.669 [DAT](INFO): entering command mode
2020-09-29T20:12:32.085Z,1601410352.085 [DAT](INFO): setting verbose to 3
2020-09-29T20:12:32.482Z,1601410352.482 [DAT](INFO): set verbose to 3
2020-09-29T20:12:32.482Z,1601410352.482 [DAT](INFO): setting DatVerbose to 27440
2020-09-29T20:12:32.878Z,1601410352.878 [DAT](INFO): set DatVerbose to 27440
2020-09-29T20:12:32.879Z,1601410352.879 [DAT](INFO): setting transmit power to 8
2020-09-29T20:12:33.297Z,1601410353.297 [DAT](INFO): set transmit power to 8
2020-09-29T20:12:33.297Z,1601410353.297 [DAT](INFO): setting local address to 9
2020-09-29T20:12:33.690Z,1601410353.690 [DAT](INFO): set local address to 9
2020-09-29T20:12:37.926Z,1601410357.926 [CommandLine](IMPORTANT): got command show variable fwd
2020-09-29T20:12:38.016Z,1601410358.016 [CommandLine](IMPORTANT): VerticalControl.massPositionLimitFwd (millimeter)
2020-09-29T20:12:39.340Z,1601410359.340 [NAL9602](INFO): NAL9602 initialized
2020-09-29T20:12:44.605Z,1601410364.605 [CommandLine](IMPORTANT): got command get VerticalControl.massPositionLimitFwd
2020-09-29T20:12:44.605Z,1601410364.605 [CommandLine](IMPORTANT): VerticalControl.massPositionLimitFwd 40.000000 mm
2020-09-29T20:13:02.044Z,1601410382.044 [CommandLine](IMPORTANT): got command maintain control VerticalControl.massPositionAction 40.000000 millimeter
2020-09-29T20:13:02.046Z,1601410382.046 [ComponentRegistry](DEBUG): SyncComponent "Maintain_VerticalControl.massPositionAction" handled in the control thread.
2020-09-29T20:13:02.462Z,1601410382.462 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,NAL9602,RDI_Pathfinder,DAT,BPC1,ESPComponent,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,Maintain_VerticalControl.massPositionAction,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2020-09-29T20:13:31.365Z,1601410411.365 [CommandLine](IMPORTANT): got command quit
2020-09-29T20:13:32.371Z,1601410412.371 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2020-09-29T20:13:32.371Z,1601410412.371 [CommandLine ThreadHandler](INFO): Thread cancelled.
2020-09-29T20:13:32.559Z,1601410412.559 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2020-09-29T20:13:32.559Z,1601410412.559 [CommandLine ThreadHandler](INFO): Thread cancelled.
2020-09-29T20:13:32.560Z,1601410412.560 [CommandLine](INFO): Join timeout helper Thread ID is 1335
2020-09-29T20:13:32.563Z,1601410412.563 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2020-09-29T20:13:32.563Z,1601410412.563 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2020-09-29T20:13:32.564Z,1601410412.564 [NavChartDb](INFO): Join timeout helper Thread ID is 1336
2020-09-29T20:13:32.884Z,1601410412.884 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2020-09-29T20:13:32.884Z,1601410412.884 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2020-09-29T20:13:32.887Z,1601410412.887 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2020-09-29T20:13:32.887Z,1601410412.887 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2020-09-29T20:13:32.888Z,1601410412.888 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 1337
2020-09-29T20:13:33.359Z,1601410413.359 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2020-09-29T20:13:33.360Z,1601410413.360 [WetLabsBB2FL](INFO): Powering down
2020-09-29T20:13:33.360Z,1601410413.360 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2020-09-29T20:13:33.379Z,1601410413.379 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2020-09-29T20:13:33.379Z,1601410413.379 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2020-09-29T20:13:33.379Z,1601410413.379 [CTD_Seabird](INFO): Join timeout helper Thread ID is 1338
2020-09-29T20:13:33.487Z,1601410413.487 [CTD_Seabird](INFO): Powering down
2020-09-29T20:13:33.499Z,1601410413.499 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2020-09-29T20:13:33.499Z,1601410413.499 [CTD_Seabird](INFO): Powering down
2020-09-29T20:13:33.520Z,1601410413.520 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2020-09-29T20:13:33.540Z,1601410413.540 [ComponentRegistry](INFO): Shutting down BackSeatDriver ThreadHandler
2020-09-29T20:13:33.540Z,1601410413.540 [BackSeatDriver ThreadHandler](INFO): Thread cancelled.
2020-09-29T20:13:33.541Z,1601410413.541 [BackSeatDriver](INFO): Join timeout helper Thread ID is 1339
2020-09-29T20:13:33.595Z,1601410413.595 [BackSeatDriver ThreadHandler](INFO): Uninitializing protected caller thread.
2020-09-29T20:13:33.595Z,1601410413.595 [BackSeatDriver ThreadHandler](INFO): Thread cancelled.
2020-09-29T20:13:33.612Z,1601410413.612 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2020-09-29T20:13:33.612Z,1601410413.612 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2020-09-29T20:13:33.612Z,1601410413.612 [Radio_Surface](INFO): Join timeout helper Thread ID is 1340
2020-09-29T20:13:33.968Z,1601410413.968 [Radio_Surface](INFO): Powering down
2020-09-29T20:13:33.969Z,1601410413.969 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2020-09-29T20:13:33.969Z,1601410413.969 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2020-09-29T20:13:33.976Z,1601410413.976 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler
2020-09-29T20:13:33.976Z,1601410413.976 [Onboard ThreadHandler](INFO): Thread cancelled.
2020-09-29T20:13:33.976Z,1601410413.976 [Onboard](INFO): Join timeout helper Thread ID is 1341
2020-09-29T20:13:36.095Z,1601410416.095 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread.
2020-09-29T20:13:36.095Z,1601410416.095 [Onboard ThreadHandler](INFO): Thread cancelled.
2020-09-29T20:13:36.119Z,1601410416.119 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2020-09-29T20:13:36.119Z,1601410416.119 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2020-09-29T20:13:36.119Z,1601410416.119 [DataOverHttps](INFO): Join timeout helper Thread ID is 1342
2020-09-29T20:13:36.396Z,1601410416.396 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2020-09-29T20:13:36.398Z,1601410416.398 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2020-09-29T20:13:36.401Z,1601410416.401 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2020-09-29T20:13:36.401Z,1601410416.401 [logger ThreadHandler](INFO): Thread cancelled.
2020-09-29T20:13:36.402Z,1601410416.402 [logger](INFO): Join timeout helper Thread ID is 1343
2020-09-29T20:13:36.427Z,1601410416.427 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2020-09-29T20:13:36.427Z,1601410416.427 [logger ThreadHandler](INFO): Thread cancelled.
2020-09-29T20:13:36.440Z,1601410416.440 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2020-09-29T20:13:36.440Z,1601410416.440 [CommandLine ThreadHandler](INFO): Thread cancelled.
2020-09-29T20:13:36.440Z,1601410416.440 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2020-09-29T20:13:36.440Z,1601410416.440 [controlThread ThreadHandler](INFO): Thread cancelled.
2020-09-29T20:13:36.440Z,1601410416.440 [controlThread](INFO): Join timeout helper Thread ID is 1344
2020-09-29T20:13:36.699Z,1601410416.699 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2020-09-29T20:13:36.699Z,1601410416.699 [controlThread](DEBUG): Uninitializing ControlThread
2020-09-29T20:13:36.700Z,1601410416.700 [AHRS_M2](INFO): Powering down
2020-09-29T20:13:36.772Z,1601410416.772 [NAL9602](INFO): Powering down
2020-09-29T20:13:36.843Z,1601410416.843 [RDI_Pathfinder](INFO): Powering down
2020-09-29T20:13:36.844Z,1601410416.844 [DAT](INFO): Powering down
2020-09-29T20:13:36.965Z,1601410416.965 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2020-09-29T20:13:36.966Z,1601410416.966 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2020-09-29T20:13:36.967Z,1601410416.967 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2020-09-29T20:13:36.967Z,1601410416.967 [MissionManager](INFO): Uninitializing Mission Default
2020-09-29T20:13:36.970Z,1601410416.970 [MissionManager](INFO): Uninitializing Mission Startup
2020-09-29T20:13:36.971Z,1601410416.971 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2020-09-29T20:13:36.971Z,1601410416.971 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2020-09-29T20:13:36.972Z,1601410416.972 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2020-09-29T20:13:36.972Z,1601410416.972 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2020-09-29T20:13:36.972Z,1601410416.972 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2020-09-29T20:13:36.972Z,1601410416.972 [ElevatorServo](INFO): Powering down
2020-09-29T20:13:36.973Z,1601410416.973 [MassServo](DEBUG): Uninitialize Mass Servo.
2020-09-29T20:13:36.973Z,1601410416.973 [MassServo](INFO): Powering down
2020-09-29T20:13:36.974Z,1601410416.974 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2020-09-29T20:13:36.974Z,1601410416.974 [RudderServo](INFO): Powering down
2020-09-29T20:13:36.975Z,1601410416.975 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2020-09-29T20:13:36.975Z,1601410416.975 [ThrusterServo](INFO): Powering down
2020-09-29T20:13:36.976Z,1601410416.976 [SBIT](DEBUG): Uninitialize SBIT Component.
2020-09-29T20:13:36.976Z,1601410416.976 [IBIT](DEBUG): Uninitialize IBIT Component.
2020-09-29T20:13:36.977Z,1601410416.977 [CBIT](DEBUG): Uninitialize CBIT Component.
2020-09-29T20:13:36.977Z,1601410416.977 [CBIT](DEBUG): Powering off loads.
2020-09-29T20:13:36.991Z,1601410416.991 [CBIT](DEBUG): Disabling WDT.
2020-09-29T20:13:37.003Z,1601410417.003 [CBIT](DEBUG): Opening all GF detection circuits.
2020-09-29T20:13:37.004Z,1601410417.004 [controlThread ThreadHandler](INFO): Thread cancelled.
2020-09-29T20:13:37.105Z,1601410417.105 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2020-09-29T20:13:37.108Z,1601410417.108 [Onboard ThreadHandler](INFO): Thread cancelled.
2020-09-29T20:13:37.113Z,1601410417.113 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2020-09-29T20:13:37.406Z,1601410417.406 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2020-09-29T20:13:37.411Z,1601410417.411 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2020-09-29T20:13:37.414Z,1601410417.414 [BackSeatDriver ThreadHandler](INFO): Thread cancelled.
2020-09-29T20:13:37.425Z,1601410417.425 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2020-09-29T20:13:37.486Z,1601410417.486 [logger ThreadHandler](INFO): Thread cancelled.