2019-10-09T23:20:45.492Z,1570663245.492 [Supervisor](DEBUG): Initializing supervisor.
2019-10-09T23:20:45.495Z,1570663245.495 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2019-10-09T23:20:45.495Z,1570663245.495 [SyncHandler](INFO): Protected caller Thread ID is 6272
2019-10-09T23:20:45.496Z,1570663245.496 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2019-10-09T23:20:45.497Z,1570663245.497 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2019-10-09T23:20:45.497Z,1570663245.497 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 6273
2019-10-09T23:20:45.500Z,1570663245.500 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2019-10-09T23:20:45.511Z,1570663245.511 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2019-10-09T23:20:45.512Z,1570663245.512 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2019-10-09T23:20:45.512Z,1570663245.512 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 6274
2019-10-09T23:20:45.513Z,1570663245.513 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2019-10-09T23:20:45.514Z,1570663245.514 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2019-10-09T23:20:45.514Z,1570663245.514 [logger ThreadHandler](INFO): Protected caller Thread ID is 6275
2019-10-09T23:20:45.516Z,1570663245.516 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2019-10-09T23:20:45.517Z,1570663245.517 [Supervisor](INFO): Looking for Config files in directory: Config/
2019-10-09T23:20:45.518Z,1570663245.518 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2019-10-09T23:20:45.710Z,1570663245.710 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2019-10-09T23:20:45.711Z,1570663245.711 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2019-10-09T23:20:45.788Z,1570663245.788 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2019-10-09T23:20:46.207Z,1570663246.207 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2019-10-09T23:20:46.207Z,1570663246.207 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2019-10-09T23:20:46.521Z,1570663246.521 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2019-10-09T23:20:46.522Z,1570663246.522 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2019-10-09T23:20:46.614Z,1570663246.614 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2019-10-09T23:20:46.615Z,1570663246.615 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2019-10-09T23:20:46.900Z,1570663246.900 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2019-10-09T23:20:46.901Z,1570663246.901 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2019-10-09T23:20:47.088Z,1570663247.088 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2019-10-09T23:20:47.089Z,1570663247.089 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2019-10-09T23:20:47.526Z,1570663247.526 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2019-10-09T23:20:47.526Z,1570663247.526 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2019-10-09T23:20:47.627Z,1570663247.627 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2019-10-09T23:20:47.628Z,1570663247.628 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2019-10-09T23:20:47.726Z,1570663247.726 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2019-10-09T23:20:47.726Z,1570663247.726 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2019-10-09T23:20:48.305Z,1570663248.305 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2019-10-09T23:20:48.306Z,1570663248.306 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2019-10-09T23:20:48.687Z,1570663248.687 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2019-10-09T23:20:48.688Z,1570663248.688 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2019-10-09T23:20:48.874Z,1570663248.874 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2019-10-09T23:20:48.874Z,1570663248.874 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2019-10-09T23:20:49.016Z,1570663249.016 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2019-10-09T23:20:49.016Z,1570663249.016 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2019-10-09T23:20:49.160Z,1570663249.160 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2019-10-09T23:20:49.162Z,1570663249.162 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2019-10-09T23:20:49.163Z,1570663249.163 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg
2019-10-09T23:20:49.252Z,1570663249.252 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2019-10-09T23:20:49.335Z,1570663249.335 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2019-10-09T23:20:49.436Z,1570663249.436 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg
2019-10-09T23:20:49.517Z,1570663249.517 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2019-10-09T23:20:49.610Z,1570663249.610 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2019-10-09T23:20:49.708Z,1570663249.708 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2019-10-09T23:20:49.912Z,1570663249.912 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg
2019-10-09T23:20:49.987Z,1570663249.987 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2019-10-09T23:20:50.187Z,1570663250.187 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2019-10-09T23:20:50.403Z,1570663250.403 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2019-10-09T23:20:50.757Z,1570663250.757 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg
2019-10-09T23:20:51.632Z,1570663251.632 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2019-10-09T23:20:51.745Z,1570663251.745 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg
2019-10-09T23:20:51.746Z,1570663251.746 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2019-10-09T23:20:51.816Z,1570663251.816 [VerticalControl](DEBUG): Construct VerticalControl.
2019-10-09T23:20:51.930Z,1570663251.930 [VerticalControl] Loaded
2019-10-09T23:20:51.930Z,1570663251.930 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2019-10-09T23:20:51.931Z,1570663251.931 [HorizontalControl](DEBUG): Construct HorizontalControl.
2019-10-09T23:20:52.000Z,1570663252.000 [HorizontalControl] Loaded
2019-10-09T23:20:52.000Z,1570663252.000 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2019-10-09T23:20:52.001Z,1570663252.001 [SpeedControl](DEBUG): Construct SpeedControl.
2019-10-09T23:20:52.007Z,1570663252.007 [SpeedControl] Loaded
2019-10-09T23:20:52.007Z,1570663252.007 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2019-10-09T23:20:52.008Z,1570663252.008 [LoopControl](DEBUG): Construct LoopControl.
2019-10-09T23:20:52.008Z,1570663252.008 [LoopControl] Loaded
2019-10-09T23:20:52.009Z,1570663252.009 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2019-10-09T23:20:52.009Z,1570663252.009 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2019-10-09T23:20:52.010Z,1570663252.010 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2019-10-09T23:20:52.023Z,1570663252.023 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2019-10-09T23:20:52.023Z,1570663252.023 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2019-10-09T23:20:52.122Z,1570663252.122 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2019-10-09T23:20:52.122Z,1570663252.122 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2019-10-09T23:20:52.224Z,1570663252.224 [BuoyancyServo] Loaded
2019-10-09T23:20:52.224Z,1570663252.224 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2019-10-09T23:20:52.235Z,1570663252.235 [ElevatorServo] Loaded
2019-10-09T23:20:52.236Z,1570663252.236 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2019-10-09T23:20:52.247Z,1570663252.247 [MassServo] Loaded
2019-10-09T23:20:52.247Z,1570663252.247 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2019-10-09T23:20:52.258Z,1570663252.258 [RudderServo] Loaded
2019-10-09T23:20:52.258Z,1570663252.258 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2019-10-09T23:20:52.270Z,1570663252.270 [ThrusterServo] Loaded
2019-10-09T23:20:52.270Z,1570663252.270 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2019-10-09T23:20:52.270Z,1570663252.270 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2019-10-09T23:20:52.271Z,1570663252.271 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2019-10-09T23:20:52.378Z,1570663252.378 [DeadReckonUsingMultipleVelocitySources] Loaded
2019-10-09T23:20:52.379Z,1570663252.379 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2019-10-09T23:20:52.399Z,1570663252.399 [NavChart] Loaded
2019-10-09T23:20:52.400Z,1570663252.400 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2019-10-09T23:20:52.404Z,1570663252.404 [UniversalFixResidualReporter] Loaded
2019-10-09T23:20:52.404Z,1570663252.404 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2019-10-09T23:20:52.404Z,1570663252.404 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2019-10-09T23:20:52.405Z,1570663252.405 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2019-10-09T23:20:52.476Z,1570663252.476 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2019-10-09T23:20:52.476Z,1570663252.476 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2019-10-09T23:20:52.736Z,1570663252.736 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_orientation
2019-10-09T23:20:52.741Z,1570663252.741 [AHRS_M2](INFO): created writer for : platform_orientation
2019-10-09T23:20:52.743Z,1570663252.743 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_magnetic_orientation
2019-10-09T23:20:52.748Z,1570663252.748 [AHRS_M2](INFO): created writer for : platform_magnetic_orientation
2019-10-09T23:20:52.749Z,1570663252.749 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_pitch_angle
2019-10-09T23:20:52.753Z,1570663252.753 [AHRS_M2](INFO): created writer for : platform_pitch_angle
2019-10-09T23:20:52.754Z,1570663252.754 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_roll_angle
2019-10-09T23:20:52.759Z,1570663252.759 [AHRS_M2](INFO): created writer for : platform_roll_angle
2019-10-09T23:20:52.831Z,1570663252.831 [AHRS_M2] Loaded
2019-10-09T23:20:52.831Z,1570663252.831 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2019-10-09T23:20:52.908Z,1570663252.908 [DataOverHttps] Loaded
2019-10-09T23:20:52.908Z,1570663252.908 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2019-10-09T23:20:52.909Z,1570663252.909 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4087D4E0
2019-10-09T23:20:52.910Z,1570663252.910 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 6358
2019-10-09T23:20:52.923Z,1570663252.923 [Depth_Keller] Loaded
2019-10-09T23:20:52.924Z,1570663252.924 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2019-10-09T23:20:52.928Z,1570663252.928 [DropWeight] Loaded
2019-10-09T23:20:52.929Z,1570663252.929 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2019-10-09T23:20:53.058Z,1570663253.058 [DVL_micro] Loaded
2019-10-09T23:20:53.059Z,1570663253.059 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread.
2019-10-09T23:20:53.157Z,1570663253.157 [NAL9602] Loaded
2019-10-09T23:20:53.157Z,1570663253.157 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2019-10-09T23:20:53.173Z,1570663253.173 [Onboard] Loaded
2019-10-09T23:20:53.174Z,1570663253.174 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2019-10-09T23:20:53.177Z,1570663253.177 [Radio_Surface] Loaded
2019-10-09T23:20:53.177Z,1570663253.177 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2019-10-09T23:20:53.178Z,1570663253.178 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408AD4E0
2019-10-09T23:20:53.178Z,1570663253.178 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 6359
2019-10-09T23:20:53.307Z,1570663253.307 [DAT] Loaded
2019-10-09T23:20:53.307Z,1570663253.307 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread.
2019-10-09T23:20:54.832Z,1570663254.832 [BPC1] Loaded
2019-10-09T23:20:54.833Z,1570663254.833 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2019-10-09T23:20:54.833Z,1570663254.833 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2019-10-09T23:20:54.833Z,1570663254.833 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2019-10-09T23:20:54.874Z,1570663254.874 [DepthRateCalculator] Loaded
2019-10-09T23:20:54.874Z,1570663254.874 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2019-10-09T23:20:54.880Z,1570663254.880 [PitchRateCalculator] Loaded
2019-10-09T23:20:54.880Z,1570663254.880 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2019-10-09T23:20:54.891Z,1570663254.891 [SpeedCalculator] Loaded
2019-10-09T23:20:54.892Z,1570663254.892 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2019-10-09T23:20:54.913Z,1570663254.913 [TempGradientCalculator] Loaded
2019-10-09T23:20:54.913Z,1570663254.913 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2019-10-09T23:20:54.919Z,1570663254.919 [YawRateCalculator] Loaded
2019-10-09T23:20:54.919Z,1570663254.919 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2019-10-09T23:20:54.949Z,1570663254.949 [ElevatorOffsetCalculator] Loaded
2019-10-09T23:20:54.950Z,1570663254.950 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2019-10-09T23:20:54.950Z,1570663254.950 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2019-10-09T23:20:54.951Z,1570663254.951 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2019-10-09T23:20:55.136Z,1570663255.136 [Aanderaa_O2] Loaded
2019-10-09T23:20:55.137Z,1570663255.137 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2019-10-09T23:20:55.222Z,1570663255.222 [CTD_NeilBrown] Loaded
2019-10-09T23:20:55.222Z,1570663255.222 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2019-10-09T23:20:55.223Z,1570663255.223 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 409B04E0
2019-10-09T23:20:55.223Z,1570663255.223 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 6360
2019-10-09T23:20:55.233Z,1570663255.233 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_density
2019-10-09T23:20:55.237Z,1570663255.237 [CTD_Seabird](INFO): created writer for : sea_water_density
2019-10-09T23:20:55.238Z,1570663255.238 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): depth
2019-10-09T23:20:55.243Z,1570663255.243 [CTD_Seabird](INFO): created writer for : depth
2019-10-09T23:20:55.243Z,1570663255.243 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_pressure
2019-10-09T23:20:55.248Z,1570663255.248 [CTD_Seabird](INFO): created writer for : sea_water_pressure
2019-10-09T23:20:55.249Z,1570663255.249 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_salinity
2019-10-09T23:20:55.254Z,1570663255.254 [CTD_Seabird](INFO): created writer for : sea_water_salinity
2019-10-09T23:20:55.255Z,1570663255.255 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_temperature
2019-10-09T23:20:55.260Z,1570663255.260 [CTD_Seabird](INFO): created writer for : sea_water_temperature
2019-10-09T23:20:55.261Z,1570663255.261 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_electrical_conductivity
2019-10-09T23:20:55.267Z,1570663255.267 [CTD_Seabird](INFO): created writer for : sea_water_electrical_conductivity
2019-10-09T23:20:55.267Z,1570663255.267 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): speed_of_sound_in_sea_water
2019-10-09T23:20:55.272Z,1570663255.272 [CTD_Seabird](INFO): created writer for : speed_of_sound_in_sea_water
2019-10-09T23:20:55.300Z,1570663255.300 [CTD_Seabird] Loaded
2019-10-09T23:20:55.300Z,1570663255.300 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2019-10-09T23:20:55.302Z,1570663255.302 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 409E04E0
2019-10-09T23:20:55.302Z,1570663255.302 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 6361
2019-10-09T23:20:55.317Z,1570663255.317 [PAR_Licor] Loaded
2019-10-09T23:20:55.317Z,1570663255.317 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2019-10-09T23:20:55.366Z,1570663255.366 [WetLabsBB2FL] Loaded
2019-10-09T23:20:55.366Z,1570663255.366 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2019-10-09T23:20:55.367Z,1570663255.367 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40A104E0
2019-10-09T23:20:55.368Z,1570663255.368 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 6362
2019-10-09T23:20:55.368Z,1570663255.368 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2019-10-09T23:20:55.369Z,1570663255.369 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2019-10-09T23:20:55.401Z,1570663255.401 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2019-10-09T23:20:55.402Z,1570663255.402 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2019-10-09T23:20:55.819Z,1570663255.819 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2019-10-09T23:20:55.819Z,1570663255.819 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2019-10-09T23:20:55.955Z,1570663255.955 [SBIT](DEBUG): Construct Startup Built In Test.
2019-10-09T23:20:55.966Z,1570663255.966 [SBIT] Loaded
2019-10-09T23:20:55.967Z,1570663255.967 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2019-10-09T23:20:55.967Z,1570663255.967 [IBIT](DEBUG): Construct Initiated Built In Test.
2019-10-09T23:20:55.979Z,1570663255.979 [IBIT] Loaded
2019-10-09T23:20:55.979Z,1570663255.979 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2019-10-09T23:20:55.982Z,1570663255.982 [CBIT](DEBUG): Construct Continuous Built In Test.
2019-10-09T23:20:56.124Z,1570663256.124 [CBIT] Loaded
2019-10-09T23:20:56.125Z,1570663256.125 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2019-10-09T23:20:56.125Z,1570663256.125 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2019-10-09T23:20:56.129Z,1570663256.129 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2019-10-09T23:20:56.130Z,1570663256.130 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2019-10-09T23:20:56.137Z,1570663256.137 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2019-10-09T23:20:56.138Z,1570663256.138 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B0F4E0
2019-10-09T23:20:56.138Z,1570663256.138 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 6363
2019-10-09T23:20:56.143Z,1570663256.143 [Supervisor](INFO): Main Thread ID is 6271
2019-10-09T23:20:56.143Z,1570663256.143 [Supervisor](DEBUG): Running supervisor.
2019-10-09T23:20:56.143Z,1570663256.143 [CommandLine ThreadHandler](INFO): Handler Thread ID is 6364
2019-10-09T23:20:56.146Z,1570663256.146 [controlThread ThreadHandler](INFO): Handler Thread ID is 6365
2019-10-09T23:20:56.146Z,1570663256.146 [controlThread](DEBUG): Initializing ControlThread
2019-10-09T23:20:56.147Z,1570663256.147 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2019-10-09T23:20:56.149Z,1570663256.149 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2019-10-09T23:20:56.149Z,1570663256.149 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2019-10-09T23:20:56.150Z,1570663256.150 [LoopControl](DEBUG): Initialize LoopControlComponent.
2019-10-09T23:20:56.152Z,1570663256.152 [NavChart](DEBUG): Initialize NavChart Navigation.
2019-10-09T23:20:56.152Z,1570663256.152 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2019-10-09T23:20:56.159Z,1570663256.159 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2019-10-09T23:20:56.160Z,1570663256.160 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2019-10-09T23:20:56.160Z,1570663256.160 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2019-10-09T23:20:56.160Z,1570663256.160 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2019-10-09T23:20:56.161Z,1570663256.161 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2019-10-09T23:20:56.161Z,1570663256.161 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2019-10-09T23:20:56.165Z,1570663256.165 [SBIT](INFO): Initialize SBIT Component.
2019-10-09T23:20:56.166Z,1570663256.166 [SBIT](IMPORTANT): git: 2019-09-10
2019-10-09T23:20:56.166Z,1570663256.166 [SBIT](INFO): git hash: e950883795b57abbf97d89589ea0268241928c93
2019-10-09T23:20:56.166Z,1570663256.166 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2019-10-09T23:20:56.167Z,1570663256.167 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
Kernel Reported: #1 PREEMPT Tue Dec 18 21:19:28 PST 2018
2019-10-09T23:20:56.168Z,1570663256.168 [SBIT](INFO): Beginning SBIT in 23.000000 seconds.
2019-10-09T23:20:56.169Z,1570663256.169 [IBIT](INFO): Initialize IBIT Component.
2019-10-09T23:20:56.170Z,1570663256.170 [CBIT](DEBUG): Initialize CBIT Component.
2019-10-09T23:20:56.171Z,1570663256.171 [logger ThreadHandler](INFO): Handler Thread ID is 6366
2019-10-09T23:20:56.181Z,1570663256.181 [CBIT](DEBUG): Initialized mux pins.
2019-10-09T23:20:56.181Z,1570663256.181 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL.
2019-10-09T23:20:56.181Z,1570663256.181 [CBIT](DEBUG): Initializing the watchdog timer.
2019-10-09T23:20:56.189Z,1570663256.189 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 6367
2019-10-09T23:20:56.190Z,1570663256.190 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2019-10-09T23:20:56.201Z,1570663256.201 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 6368
2019-10-09T23:20:56.205Z,1570663256.205 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2019-10-09T23:20:56.205Z,1570663256.205 [CBIT](DEBUG): Initializing heartbeat.
2019-10-09T23:20:56.213Z,1570663256.213 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 6369
2019-10-09T23:20:56.214Z,1570663256.214 [CTD_NeilBrown](INFO): Powering down
2019-10-09T23:20:56.241Z,1570663256.241 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 6370
2019-10-09T23:20:56.242Z,1570663256.242 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2019-10-09T23:20:56.250Z,1570663256.250 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 6372
2019-10-09T23:20:56.251Z,1570663256.251 [WetLabsBB2FL](INFO): Powering down
2019-10-09T23:20:56.269Z,1570663256.269 [CTD_Seabird](INFO): Opening uart, block timeout 10ths=20
2019-10-09T23:20:56.277Z,1570663256.277 [CBIT](DEBUG): Deactivating GF circuits.
2019-10-09T23:20:56.277Z,1570663256.277 [CBIT](DEBUG): Deactivating emergency mode.
2019-10-09T23:20:56.278Z,1570663256.278 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 6373
2019-10-09T23:20:56.281Z,1570663256.281 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2019-10-09T23:20:56.281Z,1570663256.281 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2019-10-09T23:20:56.282Z,1570663256.282 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2019-10-09T23:20:56.282Z,1570663256.282 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2019-10-09T23:20:56.282Z,1570663256.282 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2019-10-09T23:20:56.282Z,1570663256.282 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2019-10-09T23:20:56.282Z,1570663256.282 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2019-10-09T23:20:56.283Z,1570663256.283 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2019-10-09T23:20:56.283Z,1570663256.283 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2019-10-09T23:20:56.283Z,1570663256.283 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2019-10-09T23:20:56.283Z,1570663256.283 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2019-10-09T23:20:56.283Z,1570663256.283 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2019-10-09T23:20:56.284Z,1570663256.284 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2019-10-09T23:20:56.284Z,1570663256.284 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2019-10-09T23:20:56.284Z,1570663256.284 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2019-10-09T23:20:56.284Z,1570663256.284 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2019-10-09T23:20:56.313Z,1570663256.313 [CBIT](DEBUG): Backplane powered.
2019-10-09T23:20:56.314Z,1570663256.314 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2019-10-09T23:20:56.323Z,1570663256.323 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2019-10-09T23:20:56.334Z,1570663256.334 [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>


2019-10-09T23:20:56.335Z,1570663256.335 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2019-10-09T23:20:56.398Z,1570663256.398 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2019-10-09T23:20:56.399Z,1570663256.399 [Default:A.Wait](DEBUG): Construct Wait.
2019-10-09T23:20:56.400Z,1570663256.400 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2019-10-09T23:20:56.443Z,1570663256.443 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2019-10-09T23:20:56.454Z,1570663256.454 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2019-10-09T23:20:56.459Z,1570663256.459 [Default:E.Execute](DEBUG): Construct Execute.
2019-10-09T23:20:56.478Z,1570663256.478 [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>


2019-10-09T23:20:56.483Z,1570663256.483 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,DVL_micro,NAL9602,Onboard,DAT,BPC1,Aanderaa_O2,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2019-10-09T23:20:56.493Z,1570663256.493 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2019-10-09T23:20:56.577Z,1570663256.577 [DVL_micro](INFO): Initializing
2019-10-09T23:20:56.603Z,1570663256.603 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2
2019-10-09T23:20:56.603Z,1570663256.603 [DAT](INFO): Powering up
2019-10-09T23:20:56.603Z,1570663256.603 [DAT](DEBUG): Initializing DAT.
2019-10-09T23:20:56.605Z,1570663256.605 [Radio_Surface](INFO): Powering up
2019-10-09T23:20:56.646Z,1570663256.646 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2
2019-10-09T23:20:56.730Z,1570663256.730 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2019-10-09T23:20:56.745Z,1570663256.745 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2019-10-09T23:20:56.747Z,1570663256.747 [ElevatorServo](DEBUG): Initializing EZServoServo.
2019-10-09T23:20:56.757Z,1570663256.757 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2019-10-09T23:20:56.758Z,1570663256.758 [MassServo](DEBUG): Initializing EZServoServo.
2019-10-09T23:20:56.769Z,1570663256.769 [MassServo](DEBUG): Initializing MassServo.
2019-10-09T23:20:56.770Z,1570663256.770 [RudderServo](DEBUG): Initializing EZServoServo.
2019-10-09T23:20:56.784Z,1570663256.784 [RudderServo](DEBUG): Initializing RudderServo.
2019-10-09T23:20:56.785Z,1570663256.785 [ThrusterServo](DEBUG): Initializing EZServoServo.
2019-10-09T23:20:56.793Z,1570663256.793 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2019-10-09T23:20:56.911Z,1570663256.911 [DropWeight](CRITICAL): DROP WEIGHT MISSING.

2019-10-09T23:20:56.911Z,1570663256.911 [DropWeight] Hardware Fault, FailCount= 1
2019-10-09T23:20:56.911Z,1570663256.911 [DropWeight](ERROR): Hardware Fault
2019-10-09T23:20:56.979Z,1570663256.979 [CommandLine](FAULT): Scheduling is paused
2019-10-09T23:20:56.979Z,1570663256.979 [CBIT](INFO): Critical error at 20191009T232056
2019-10-09T23:20:56.979Z,1570663256.979 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2019-10-09T23:20:56.982Z,1570663256.982 [CBIT](ERROR): Hardware Fault in component: DropWeight
2019-10-09T23:20:56.982Z,1570663256.982 [CBIT](CRITICAL): Hardware Fault in component: DropWeight
2019-10-09T23:20:57.673Z,1570663257.673 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2019-10-09T23:20:57.673Z,1570663257.673 [RudderServo](FAULT): Rudder failed to initialize
2019-10-09T23:20:57.673Z,1570663257.673 [RudderServo] Communications Fault, FailCount= 1
2019-10-09T23:20:57.673Z,1570663257.673 [RudderServo](ERROR): Communications Fault
2019-10-09T23:20:57.782Z,1570663257.782 [CBIT](INFO): Critical error at 20191009T232056
2019-10-09T23:20:57.785Z,1570663257.785 [CBIT](ERROR): Communications Fault in component: RudderServo
2019-10-09T23:20:57.982Z,1570663257.982 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-10-09T23:20:57.982Z,1570663257.982 [RudderServo](INFO): Powering down
2019-10-09T23:20:58.669Z,1570663258.669 [RudderServo](DEBUG): Initializing EZServoServo.
2019-10-09T23:20:58.790Z,1570663258.790 [RudderServo](DEBUG): Initializing RudderServo.
2019-10-09T23:20:58.794Z,1570663258.794 [CBIT](INFO): Clearing failed state for component RudderServo
2019-10-09T23:20:58.794Z,1570663258.794 [RudderServo] No Fault, FailCount= 1
2019-10-09T23:21:00.033Z,1570663260.033 [Aanderaa_O2](INFO): Powering down
2019-10-09T23:21:04.277Z,1570663264.277 [CTD_Seabird](ERROR): Device message queue exceeded the allowed limit.
2019-10-09T23:21:06.414Z,1570663266.414 [CBIT](CRITICAL): Environmental Failure. Press:14.622614 PSI. Humidity:38%. Temp:24 C. ABORTING MISSION
2019-10-09T23:21:06.836Z,1570663266.836 [CBIT](INFO): Critical error at 20191009T232106
2019-10-09T23:21:07.138Z,1570663267.138 [DVL_micro](ERROR): No DVL communication! Re-initializing
2019-10-09T23:21:07.138Z,1570663267.138 [DVL_micro] Communications Fault, FailCount= 1
2019-10-09T23:21:07.138Z,1570663267.138 [DVL_micro](ERROR): Communications Fault
2019-10-09T23:21:07.213Z,1570663267.213 [CBIT](ERROR): Communications Fault in component: DVL_micro
2019-10-09T23:21:07.605Z,1570663267.605 [DVL_micro](INFO): uninitialize:Powering down
2019-10-09T23:21:08.413Z,1570663268.413 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-10-09T23:21:08.413Z,1570663268.413 [DVL_micro] No Fault, FailCount= 1
2019-10-09T23:21:08.752Z,1570663268.752 [DVL_micro](INFO): Initializing
2019-10-09T23:21:09.972Z,1570663269.972 [DAT](INFO): setting local address to 2
2019-10-09T23:21:10.378Z,1570663270.378 [DAT](INFO): set local address to 2
2019-10-09T23:21:19.250Z,1570663279.250 [DVL_micro](ERROR): No DVL communication! Re-initializing
2019-10-09T23:21:19.250Z,1570663279.250 [DVL_micro] Communications Fault, FailCount= 2
2019-10-09T23:21:19.250Z,1570663279.250 [DVL_micro](ERROR): Communications Fault
2019-10-09T23:21:19.349Z,1570663279.349 [CBIT](ERROR): Communications Fault in component: DVL_micro
2019-10-09T23:21:19.721Z,1570663279.721 [DVL_micro](INFO): uninitialize:Powering down
2019-10-09T23:21:19.794Z,1570663279.794 [SBIT](IMPORTANT): Beginning Startup BIT
2019-10-09T23:21:19.798Z,1570663279.798 [CBIT](IMPORTANT): Beginning ground fault scan
2019-10-09T23:21:20.585Z,1570663280.585 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-10-09T23:21:20.585Z,1570663280.585 [DVL_micro] No Fault, FailCount= 2
2019-10-09T23:21:20.868Z,1570663280.868 [DVL_micro](INFO): Initializing
2019-10-09T23:21:23.286Z,1570663283.286 [NAL9602](INFO): Powering up NAL9602
2019-10-09T23:21:30.658Z,1570663290.658 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.011117
CHAN A1 (24V): 0.047624
CHAN A2 (12V): -0.002135
CHAN A3 (5V): -0.000932
CHAN B0 (3.3V): -0.000131
CHAN B1 (3.15aV): 0.000045
CHAN B2 (3.15bV): 0.000136
CHAN B3 (GND): 0.000121
OPEN: -0.000520
Full Scale Calc: 4.765 mA, -1.589 mA
2019-10-09T23:21:31.370Z,1570663291.370 [DVL_micro](ERROR): No DVL communication! Re-initializing
2019-10-09T23:21:31.370Z,1570663291.370 [DVL_micro] Communications Fault, FailCount= 3
2019-10-09T23:21:31.370Z,1570663291.370 [DVL_micro](ERROR): Communications Fault
2019-10-09T23:21:31.474Z,1570663291.474 [CBIT](ERROR): Communications Fault in component: DVL_micro
2019-10-09T23:21:31.841Z,1570663291.841 [DVL_micro](INFO): uninitialize:Powering down
2019-10-09T23:21:32.677Z,1570663292.677 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-10-09T23:21:32.678Z,1570663292.678 [DVL_micro] No Fault, FailCount= 3
2019-10-09T23:21:32.988Z,1570663292.988 [DVL_micro](INFO): Initializing
2019-10-09T23:21:33.147Z,1570663293.147 [SBIT](FAULT): Mass: EXPECTED:0.004450 ACTUAL:0.000003
2019-10-09T23:21:37.134Z,1570663297.134 [CommandLine](IMPORTANT): got command show variable par
2019-10-09T23:21:37.184Z,1570663297.184 [CommandLine](IMPORTANT): PAR_Licor.loadControl (none)
2019-10-09T23:21:37.184Z,1570663297.184 [CommandLine](IMPORTANT): PAR_Licor.ad (none)
2019-10-09T23:21:37.189Z,1570663297.189 [CommandLine](IMPORTANT): PAR_Licor.adRes (bit)
2019-10-09T23:21:37.189Z,1570663297.189 [CommandLine](IMPORTANT): PAR_Licor.adTimeout (millisecond)
2019-10-09T23:21:37.190Z,1570663297.190 [CommandLine](IMPORTANT): PAR_Licor.adVref (volt)
2019-10-09T23:21:37.265Z,1570663297.265 [CommandLine](IMPORTANT): PAR_Licor.loadAtStartup (bool)
2019-10-09T23:21:37.265Z,1570663297.265 [CommandLine](IMPORTANT): PAR_Licor.simulateHardware (bool)
2019-10-09T23:21:37.266Z,1570663297.266 [CommandLine](IMPORTANT): PAR_Licor.adcCal (microampere_per_count)
2019-10-09T23:21:37.266Z,1570663297.266 [CommandLine](IMPORTANT): PAR_Licor.darkCount (count)
2019-10-09T23:21:37.266Z,1570663297.266 [CommandLine](IMPORTANT): PAR_Licor.maxBound (micromole_per_second_per_square_meter)
2019-10-09T23:21:37.267Z,1570663297.267 [CommandLine](IMPORTANT): PAR_Licor.maxValidPitch (degree)
2019-10-09T23:21:37.267Z,1570663297.267 [CommandLine](IMPORTANT): PAR_Licor.minBound (micromole_per_second_per_square_meter)
2019-10-09T23:21:37.267Z,1570663297.267 [CommandLine](IMPORTANT): PAR_Licor.minValidPitch (degree)
2019-10-09T23:21:37.268Z,1570663297.268 [CommandLine](IMPORTANT): PAR_Licor.multiplier (micromole_per_second_per_square_meter_per_microampere)
2019-10-09T23:21:37.268Z,1570663297.268 [CommandLine](IMPORTANT): PAR_Licor.serial (none)
2019-10-09T23:21:37.402Z,1570663297.402 [CommandLine](IMPORTANT): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water (micromole_per_second_per_square_meter)
2019-10-09T23:21:37.402Z,1570663297.402 [CommandLine](IMPORTANT): PAR_Licor.adcCount (count)
2019-10-09T23:21:43.494Z,1570663303.494 [DVL_micro](ERROR): No DVL communication! Re-initializing
2019-10-09T23:21:43.494Z,1570663303.494 [DVL_micro] Communications Fault, FailCount= 4
2019-10-09T23:21:43.494Z,1570663303.494 [DVL_micro](ERROR): Communications Fault
2019-10-09T23:21:43.598Z,1570663303.598 [CBIT](ERROR): Communications Fault in component: DVL_micro
2019-10-09T23:21:43.961Z,1570663303.961 [DVL_micro](INFO): uninitialize:Powering down
2019-10-09T23:21:43.962Z,1570663303.962 [NAL9602](ERROR): NAL9602 initialization error.
2019-10-09T23:21:43.962Z,1570663303.962 [NAL9602] Communications Fault, FailCount= 1
2019-10-09T23:21:43.962Z,1570663303.962 [NAL9602](ERROR): Communications Fault
2019-10-09T23:21:44.058Z,1570663304.058 [CBIT](ERROR): Communications Fault in component: NAL9602
2019-10-09T23:21:44.294Z,1570663304.294 [NAL9602](INFO): Powering down
2019-10-09T23:21:44.774Z,1570663304.774 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-10-09T23:21:44.774Z,1570663304.774 [DVL_micro] No Fault, FailCount= 4
2019-10-09T23:21:45.114Z,1570663305.114 [DVL_micro](INFO): Initializing
2019-10-09T23:21:45.191Z,1570663305.191 [CBIT](INFO): Clearing failed state for component NAL9602
2019-10-09T23:21:45.191Z,1570663305.191 [NAL9602] No Fault, FailCount= 1
2019-10-09T23:21:55.614Z,1570663315.614 [DVL_micro](ERROR): No DVL communication! Re-initializing
2019-10-09T23:21:55.614Z,1570663315.614 [DVL_micro] Communications Fault, FailCount= 5
2019-10-09T23:21:55.614Z,1570663315.614 [DVL_micro](ERROR): Communications Fault
2019-10-09T23:21:55.677Z,1570663315.677 [CBIT](ERROR): Communications Fault in component: DVL_micro
2019-10-09T23:21:55.677Z,1570663315.677 [CBIT](CRITICAL): Communications Fault in component: DVL_micro
2019-10-09T23:21:56.081Z,1570663316.081 [DVL_micro](INFO): uninitialize:Powering down
2019-10-09T23:21:56.127Z,1570663316.127 [CBIT](INFO): Critical error at 20191009T232155
2019-10-09T23:22:13.518Z,1570663333.518 [SBIT](CRITICAL): SBIT FAILED
2019-10-09T23:22:13.536Z,1570663333.536 [CBIT](INFO): Critical error at 20191009T232213
2019-10-09T23:22:13.590Z,1570663333.590 [CommandLine](IMPORTANT): got command configSet list
2019-10-09T23:22:13.590Z,1570663333.590 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2019-10-09T23:22:13.591Z,1570663333.591 [CommandLine](IMPORTANT): CBIT.gf24Offset=154 microampere;

2019-10-09T23:22:13.591Z,1570663333.591 [CommandLine](IMPORTANT): CTD_NeilBrown.loadAtStartup=0 bool;

2019-10-09T23:22:13.591Z,1570663333.591 [CommandLine](IMPORTANT): DAT.loadAtStartup=0 bool;

2019-10-09T23:22:13.591Z,1570663333.591 [CommandLine](IMPORTANT): DVL_micro.loadAtStartup=0 bool;

2019-10-09T23:22:13.912Z,1570663333.912 [MissionManager](IMPORTANT): Started mission Startup
2019-10-09T23:22:13.929Z,1570663333.929 [Startup] Running Loop=1
2019-10-09T23:22:13.929Z,1570663333.929 [Startup](DEBUG): Aggregate::initialize Startup
2019-10-09T23:22:13.929Z,1570663333.929 [Startup:A.GoToSurface] Running Loop=1
2019-10-09T23:22:13.929Z,1570663333.929 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-10-09T23:22:13.930Z,1570663333.930 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-10-09T23:22:13.930Z,1570663333.930 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-10-09T23:22:13.931Z,1570663333.931 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-10-09T23:22:13.931Z,1570663333.931 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-10-09T23:22:13.931Z,1570663333.931 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-10-09T23:22:13.941Z,1570663333.941 [Startup:StartupSatComms] Running Loop=1
2019-10-09T23:22:13.945Z,1570663333.945 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2019-10-09T23:22:13.945Z,1570663333.945 [Startup:StartupSatComms:A] Running Loop=1
2019-10-09T23:22:14.316Z,1570663334.316 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2019-10-09T23:22:14.686Z,1570663334.686 [NAL9602](INFO): Powering up NAL9602
2019-10-09T23:22:25.590Z,1570663345.590 [CommandLine](IMPORTANT): got command report mod PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water
2019-10-09T23:22:25.616Z,1570663345.616 [NAL9602](INFO): NAL9602 initialized
2019-10-09T23:22:25.662Z,1570663345.662 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 19.315563 umol/s/m2
2019-10-09T23:22:26.042Z,1570663346.042 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 19.302845 umol/s/m2
2019-10-09T23:22:26.417Z,1570663346.417 [NAL9602](DEBUG): Fix Requested
2019-10-09T23:22:26.464Z,1570663346.464 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 19.285360 umol/s/m2
2019-10-09T23:22:26.876Z,1570663346.876 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 19.325098 umol/s/m2
2019-10-09T23:22:27.280Z,1570663347.280 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 19.372786 umol/s/m2
2019-10-09T23:22:27.657Z,1570663347.657 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 19.323509 umol/s/m2
2019-10-09T23:22:28.067Z,1570663348.067 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 19.325098 umol/s/m2
2019-10-09T23:22:28.477Z,1570663348.477 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 19.290129 umol/s/m2
2019-10-09T23:22:28.898Z,1570663348.898 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 19.326689 umol/s/m2
2019-10-09T23:22:29.289Z,1570663349.289 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 19.301256 umol/s/m2
2019-10-09T23:22:29.689Z,1570663349.689 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 19.296488 umol/s/m2
2019-10-09T23:22:30.146Z,1570663350.146 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 19.288540 umol/s/m2
2019-10-09T23:22:30.591Z,1570663350.591 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 19.280594 umol/s/m2
2019-10-09T23:22:30.925Z,1570663350.925 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 19.360067 umol/s/m2
2019-10-09T23:22:31.317Z,1570663351.317 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 19.344173 umol/s/m2
2019-10-09T23:22:31.728Z,1570663351.728 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 19.355301 umol/s/m2
2019-10-09T23:22:32.136Z,1570663352.136 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 19.358479 umol/s/m2
2019-10-09T23:22:32.547Z,1570663352.547 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 19.313972 umol/s/m2
2019-10-09T23:22:32.936Z,1570663352.936 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 19.288540 umol/s/m2
2019-10-09T23:22:33.354Z,1570663353.354 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 19.344173 umol/s/m2
2019-10-09T23:22:33.775Z,1570663353.775 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 19.366425 umol/s/m2
2019-10-09T23:22:34.172Z,1570663354.172 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 19.385500 umol/s/m2
2019-10-09T23:22:34.572Z,1570663354.572 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 19.323509 umol/s/m2
2019-10-09T23:22:34.987Z,1570663354.987 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 19.266287 umol/s/m2
2019-10-09T23:22:35.336Z,1570663355.336 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 19.342583 umol/s/m2
2019-10-09T23:22:35.738Z,1570663355.738 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 19.369604 umol/s/m2
2019-10-09T23:22:36.146Z,1570663356.146 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 0.060401 umol/s/m2
2019-10-09T23:22:36.557Z,1570663356.557 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 0.068348 umol/s/m2
2019-10-09T23:22:36.945Z,1570663356.945 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 0.085833 umol/s/m2
2019-10-09T23:22:37.359Z,1570663357.359 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 0.007947 umol/s/m2
2019-10-09T23:22:37.769Z,1570663357.769 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 0.025432 umol/s/m2
2019-10-09T23:22:38.071Z,1570663358.071 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004912
2019-10-09T23:22:38.179Z,1570663358.179 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water -0.004768 umol/s/m2
2019-10-09T23:22:38.566Z,1570663358.566 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 0.050864 umol/s/m2
2019-10-09T23:22:38.988Z,1570663358.988 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 0.233656 umol/s/m2
2019-10-09T23:22:39.391Z,1570663359.391 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 19.498354 umol/s/m2
2019-10-09T23:22:39.804Z,1570663359.804 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 19.606440 umol/s/m2
2019-10-09T23:22:40.209Z,1570663360.209 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 19.552399 umol/s/m2
2019-10-09T23:22:40.593Z,1570663360.593 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 89.833572 umol/s/m2
2019-10-09T23:22:40.998Z,1570663360.998 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 319.984741 umol/s/m2
2019-10-09T23:22:41.418Z,1570663361.418 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 926.274353 umol/s/m2
2019-10-09T23:22:41.800Z,1570663361.800 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 1489.636475 umol/s/m2
2019-10-09T23:22:42.213Z,1570663362.213 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 1216.112671 umol/s/m2
2019-10-09T23:22:42.619Z,1570663362.619 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 1296.269409 umol/s/m2
2019-10-09T23:22:43.023Z,1570663363.023 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 1035.471191 umol/s/m2
2019-10-09T23:22:43.472Z,1570663363.472 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 1233.242676 umol/s/m2
2019-10-09T23:22:43.921Z,1570663363.921 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 867.250000 umol/s/m2
2019-10-09T23:22:44.285Z,1570663364.285 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 19.447489 umol/s/m2
2019-10-09T23:22:44.672Z,1570663364.672 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 19.360067 umol/s/m2
2019-10-09T23:22:45.062Z,1570663365.062 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 19.320330 umol/s/m2
2019-10-09T23:22:45.476Z,1570663365.476 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 19.293310 umol/s/m2
2019-10-09T23:22:45.852Z,1570663365.852 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 19.259930 umol/s/m2
2019-10-09T23:22:46.265Z,1570663366.265 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 19.296488 umol/s/m2
2019-10-09T23:22:46.647Z,1570663366.647 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 19.333048 umol/s/m2
2019-10-09T23:22:47.061Z,1570663367.061 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 19.282183 umol/s/m2
2019-10-09T23:22:47.464Z,1570663367.464 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 19.339405 umol/s/m2
2019-10-09T23:22:47.875Z,1570663367.875 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 19.313972 umol/s/m2
2019-10-09T23:22:48.261Z,1570663368.261 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 19.288540 umol/s/m2
2019-10-09T23:22:48.673Z,1570663368.673 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 19.307613 umol/s/m2
2019-10-09T23:22:49.073Z,1570663369.073 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 19.345762 umol/s/m2
2019-10-09T23:22:49.497Z,1570663369.497 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 19.296488 umol/s/m2
2019-10-09T23:22:49.904Z,1570663369.904 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 19.320330 umol/s/m2
2019-10-09T23:22:50.296Z,1570663370.296 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 19.309204 umol/s/m2
2019-10-09T23:22:50.697Z,1570663370.697 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 19.285360 umol/s/m2
2019-10-09T23:22:51.113Z,1570663371.113 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 19.331457 umol/s/m2
2019-10-09T23:22:51.493Z,1570663371.493 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 19.288540 umol/s/m2
2019-10-09T23:22:51.905Z,1570663371.905 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 19.372786 umol/s/m2
2019-10-09T23:22:52.314Z,1570663372.314 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 19.361658 umol/s/m2
2019-10-09T23:22:52.718Z,1570663372.718 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 19.220192 umol/s/m2
2019-10-09T23:22:53.108Z,1570663373.108 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 19.317152 umol/s/m2
2019-10-09T23:22:53.518Z,1570663373.518 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 19.296488 umol/s/m2
2019-10-09T23:22:53.921Z,1570663373.921 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 19.283772 umol/s/m2
2019-10-09T23:22:54.337Z,1570663374.337 [Reporter](INFO): PAR_Licor.downwelling_photosynthetic_photon_flux_in_sea_water 19.291721 umol/s/m2
2019-10-09T23:22:54.494Z,1570663374.494 [CommandLine](IMPORTANT): got command report clear
2019-10-09T23:23:14.107Z,1570663394.107 [Startup:StartupSatComms:A](INFO): Timed out from 2019-10-09T23:22:13.9Z
2019-10-09T23:23:14.107Z,1570663394.107 [Startup:StartupSatComms:A] Stopped
2019-10-09T23:23:14.107Z,1570663394.107 [Startup:StartupSatComms:B] Running Loop=1
2019-10-09T23:23:14.516Z,1570663394.516 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-10-09T23:23:21.812Z,1570663401.812 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20191009T225628/Courier0010.lzma
2019-10-09T23:23:23.818Z,1570663403.818 [DataOverHttps](INFO): Moved sent file to Logs/20191009T225628/Courier0010.lzma.bak
2019-10-09T23:23:23.819Z,1570663403.819 [DataOverHttps](INFO): SBD MOMSN=11867868
2019-10-09T23:23:40.721Z,1570663420.721 [DataOverHttps](INFO): Sending 261 bytes from file Logs/20191009T232045/Courier0000.lzma
2019-10-09T23:23:42.726Z,1570663422.726 [DataOverHttps](INFO): Moved sent file to Logs/20191009T232045/Courier0000.lzma.bak
2019-10-09T23:23:42.726Z,1570663422.726 [DataOverHttps](INFO): SBD MOMSN=11867870
2019-10-09T23:23:56.537Z,1570663436.537 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2019-10-09T23:23:56.537Z,1570663436.537 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-10-09T23:23:56.555Z,1570663436.555 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-10-09T23:23:56.958Z,1570663436.958 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-10-09T23:23:56.958Z,1570663436.958 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2019-10-09T23:23:59.352Z,1570663439.352 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20191009T225628/Express0011.lzma
2019-10-09T23:24:01.358Z,1570663441.358 [DataOverHttps](INFO): Moved sent file to Logs/20191009T225628/Express0011.lzma.bak
2019-10-09T23:24:01.359Z,1570663441.359 [DataOverHttps](INFO): SBD MOMSN=11867878
2019-10-09T23:24:14.334Z,1570663454.334 [Startup:StartupSatComms:B](INFO): Timed out from 2019-10-09T23:23:14.1Z
2019-10-09T23:24:14.334Z,1570663454.334 [Startup:StartupSatComms:B] Stopped
2019-10-09T23:24:14.335Z,1570663454.335 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2019-10-09T23:24:14.335Z,1570663454.335 [Startup:StartupSatComms] Stopped
2019-10-09T23:24:14.335Z,1570663454.335 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2019-10-09T23:24:14.336Z,1570663454.336 [Startup](INFO): Completed Startup
2019-10-09T23:24:14.336Z,1570663454.336 [MissionManager](INFO): Startup is completed.
2019-10-09T23:24:14.336Z,1570663454.336 [MissionManager](INFO): Uninitializing Mission Startup
2019-10-09T23:24:14.336Z,1570663454.336 [Startup] Stopped
2019-10-09T23:24:14.336Z,1570663454.336 [Startup](DEBUG): Aggregate::uninitialize Startup
2019-10-09T23:24:14.336Z,1570663454.336 [Startup:A.GoToSurface] Stopped
2019-10-09T23:24:14.336Z,1570663454.336 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-10-09T23:24:14.738Z,1570663454.738 [MissionManager](IMPORTANT): Started mission Default
2019-10-09T23:24:14.738Z,1570663454.738 [Default] Running Loop=1
2019-10-09T23:24:14.738Z,1570663454.738 [Default](DEBUG): Aggregate::initialize Default
2019-10-09T23:24:14.738Z,1570663454.738 [Default:B.GoToSurface] Running Loop=1
2019-10-09T23:24:14.738Z,1570663454.738 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-10-09T23:24:14.739Z,1570663454.739 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-10-09T23:24:14.739Z,1570663454.739 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-10-09T23:24:14.739Z,1570663454.739 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-10-09T23:24:14.740Z,1570663454.740 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-10-09T23:24:14.740Z,1570663454.740 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-10-09T23:24:14.740Z,1570663454.740 [Default:A.Wait] Running Loop=1
2019-10-09T23:24:14.740Z,1570663454.740 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-10-09T23:24:18.218Z,1570663458.218 [DataOverHttps](INFO): Sending 1097 bytes from file Logs/20191009T232045/Express0001.lzma
2019-10-09T23:24:20.222Z,1570663460.222 [DataOverHttps](INFO): Moved sent file to Logs/20191009T232045/Express0001.lzma.bak
2019-10-09T23:24:20.222Z,1570663460.222 [DataOverHttps](INFO): SBD MOMSN=11867880
2019-10-09T23:24:28.043Z,1570663468.043 [Default:A.Wait](INFO): Done Waiting.
2019-10-09T23:24:28.044Z,1570663468.044 [Default:A.Wait] Stopped
2019-10-09T23:24:28.044Z,1570663468.044 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-10-09T23:24:28.441Z,1570663468.441 [Default:CheckIn] Running Loop=1
2019-10-09T23:24:28.441Z,1570663468.441 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-10-09T23:24:28.441Z,1570663468.441 [Default:CheckIn:Read_GPS] Running Loop=1
2019-10-09T23:24:28.853Z,1570663468.853 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2019-10-09T23:24:43.062Z,1570663483.062 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB3
2019-10-09T23:24:56.395Z,1570663496.395 [CommandLine](IMPORTANT): got command quit
2019-10-09T23:24:57.401Z,1570663497.401 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2019-10-09T23:24:57.401Z,1570663497.401 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-10-09T23:24:57.409Z,1570663497.409 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2019-10-09T23:24:57.409Z,1570663497.409 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-10-09T23:24:57.410Z,1570663497.410 [CommandLine](INFO): Join timeout helper Thread ID is 6396
2019-10-09T23:24:57.410Z,1570663497.410 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2019-10-09T23:24:57.410Z,1570663497.410 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-10-09T23:24:57.411Z,1570663497.411 [NavChartDb](INFO): Join timeout helper Thread ID is 6397
2019-10-09T23:24:57.721Z,1570663497.721 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2019-10-09T23:24:57.721Z,1570663497.721 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-10-09T23:24:57.733Z,1570663497.733 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2019-10-09T23:24:57.733Z,1570663497.733 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-10-09T23:24:57.733Z,1570663497.733 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 6398
2019-10-09T23:24:58.213Z,1570663498.213 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2019-10-09T23:24:58.213Z,1570663498.213 [WetLabsBB2FL](INFO): Powering down
2019-10-09T23:24:58.214Z,1570663498.214 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-10-09T23:24:58.233Z,1570663498.233 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2019-10-09T23:24:58.233Z,1570663498.233 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2019-10-09T23:24:58.233Z,1570663498.233 [CTD_Seabird](INFO): Join timeout helper Thread ID is 6399
2019-10-09T23:24:58.253Z,1570663498.253 [CTD_Seabird](INFO): Powering down
2019-10-09T23:24:58.265Z,1570663498.265 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2019-10-09T23:24:58.265Z,1570663498.265 [CTD_Seabird](INFO): Powering down
2019-10-09T23:24:58.277Z,1570663498.277 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2019-10-09T23:24:58.307Z,1570663498.307 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2019-10-09T23:24:58.307Z,1570663498.307 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-10-09T23:24:58.308Z,1570663498.308 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 6400
2019-10-09T23:24:58.397Z,1570663498.397 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread.
2019-10-09T23:24:58.398Z,1570663498.398 [CTD_NeilBrown](INFO): Powering down
2019-10-09T23:24:58.409Z,1570663498.409 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-10-09T23:24:58.414Z,1570663498.414 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2019-10-09T23:24:58.414Z,1570663498.414 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-10-09T23:24:58.414Z,1570663498.414 [Radio_Surface](INFO): Join timeout helper Thread ID is 6401
2019-10-09T23:24:58.605Z,1570663498.605 [Radio_Surface](INFO): Powering down
2019-10-09T23:24:58.606Z,1570663498.606 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2019-10-09T23:24:58.606Z,1570663498.606 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-10-09T23:24:58.617Z,1570663498.617 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2019-10-09T23:24:58.618Z,1570663498.618 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-10-09T23:24:58.618Z,1570663498.618 [DataOverHttps](INFO): Join timeout helper Thread ID is 6402
2019-10-09T23:24:59.185Z,1570663499.185 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2019-10-09T23:24:59.189Z,1570663499.189 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-10-09T23:24:59.198Z,1570663499.198 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2019-10-09T23:24:59.198Z,1570663499.198 [logger ThreadHandler](INFO): Thread cancelled.
2019-10-09T23:24:59.198Z,1570663499.198 [logger](INFO): Join timeout helper Thread ID is 6403
2019-10-09T23:24:59.210Z,1570663499.210 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2019-10-09T23:24:59.210Z,1570663499.210 [logger ThreadHandler](INFO): Thread cancelled.
2019-10-09T23:24:59.225Z,1570663499.225 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2019-10-09T23:24:59.226Z,1570663499.226 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-10-09T23:24:59.226Z,1570663499.226 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2019-10-09T23:24:59.226Z,1570663499.226 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-10-09T23:24:59.226Z,1570663499.226 [controlThread](INFO): Join timeout helper Thread ID is 6404
2019-10-09T23:24:59.509Z,1570663499.509 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2019-10-09T23:24:59.509Z,1570663499.509 [controlThread](DEBUG): Uninitializing ControlThread
2019-10-09T23:24:59.509Z,1570663499.509 [AHRS_M2](INFO): Powering down
2019-10-09T23:24:59.581Z,1570663499.581 [DVL_micro](INFO): uninitialize:Powering down
2019-10-09T23:24:59.582Z,1570663499.582 [NAL9602](INFO): Powering down
2019-10-09T23:24:59.584Z,1570663499.584 [DAT](INFO): Powering down
2019-10-09T23:24:59.702Z,1570663499.702 [Aanderaa_O2](INFO): Powering down
2019-10-09T23:24:59.703Z,1570663499.703 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2019-10-09T23:24:59.704Z,1570663499.704 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2019-10-09T23:24:59.705Z,1570663499.705 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2019-10-09T23:24:59.705Z,1570663499.705 [MissionManager](INFO): Uninitializing Mission Default
2019-10-09T23:24:59.705Z,1570663499.705 [Default] Stopped
2019-10-09T23:24:59.706Z,1570663499.706 [Default](DEBUG): Aggregate::uninitialize Default
2019-10-09T23:24:59.706Z,1570663499.706 [Default:B.GoToSurface] Stopped
2019-10-09T23:24:59.706Z,1570663499.706 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-10-09T23:24:59.706Z,1570663499.706 [Default:CheckIn] Stopped
2019-10-09T23:24:59.706Z,1570663499.706 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-10-09T23:24:59.706Z,1570663499.706 [Default:CheckIn:Read_GPS] Stopped
2019-10-09T23:24:59.708Z,1570663499.708 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2019-10-09T23:24:59.709Z,1570663499.709 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2019-10-09T23:24:59.709Z,1570663499.709 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2019-10-09T23:24:59.709Z,1570663499.709 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2019-10-09T23:24:59.710Z,1570663499.710 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2019-10-09T23:24:59.710Z,1570663499.710 [BuoyancyServo](INFO): Powering down
2019-10-09T23:24:59.721Z,1570663499.721 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2019-10-09T23:24:59.721Z,1570663499.721 [ElevatorServo](INFO): Powering down
2019-10-09T23:24:59.722Z,1570663499.722 [MassServo](DEBUG): Uninitialize Mass Servo.
2019-10-09T23:24:59.722Z,1570663499.722 [MassServo](INFO): Powering down
2019-10-09T23:24:59.723Z,1570663499.723 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-10-09T23:24:59.723Z,1570663499.723 [RudderServo](INFO): Powering down
2019-10-09T23:24:59.723Z,1570663499.723 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2019-10-09T23:24:59.724Z,1570663499.724 [ThrusterServo](INFO): Powering down
2019-10-09T23:24:59.724Z,1570663499.724 [SBIT](DEBUG): Uninitialize SBIT Component.
2019-10-09T23:24:59.725Z,1570663499.725 [IBIT](DEBUG): Uninitialize IBIT Component.
2019-10-09T23:24:59.725Z,1570663499.725 [CBIT](DEBUG): Uninitialize CBIT Component.
2019-10-09T23:24:59.725Z,1570663499.725 [CBIT](DEBUG): Powering off loads.
2019-10-09T23:24:59.737Z,1570663499.737 [CBIT](DEBUG): Disabling WDT.
2019-10-09T23:24:59.749Z,1570663499.749 [CBIT](DEBUG): Opening all GF detection circuits.
2019-10-09T23:24:59.749Z,1570663499.749 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-10-09T23:24:59.843Z,1570663499.843 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-10-09T23:24:59.853Z,1570663499.853 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-10-09T23:24:59.884Z,1570663499.884 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-10-09T23:24:59.887Z,1570663499.887 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2019-10-09T23:24:59.891Z,1570663499.891 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-10-09T23:24:59.928Z,1570663499.928 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-10-09T23:24:59.987Z,1570663499.987 [logger ThreadHandler](INFO): Thread cancelled.