2019-04-10T14:59:59.075Z,1554908399.075 [Supervisor](DEBUG): Initializing supervisor.
2019-04-10T14:59:59.078Z,1554908399.078 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2019-04-10T14:59:59.078Z,1554908399.078 [SyncHandler](INFO): Protected caller Thread ID is 7726
2019-04-10T14:59:59.079Z,1554908399.079 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2019-04-10T14:59:59.080Z,1554908399.080 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2019-04-10T14:59:59.080Z,1554908399.080 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 7727
2019-04-10T14:59:59.084Z,1554908399.084 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2019-04-10T14:59:59.096Z,1554908399.096 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2019-04-10T14:59:59.097Z,1554908399.097 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2019-04-10T14:59:59.097Z,1554908399.097 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 7728
2019-04-10T14:59:59.098Z,1554908399.098 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2019-04-10T14:59:59.099Z,1554908399.099 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2019-04-10T14:59:59.100Z,1554908399.100 [logger ThreadHandler](INFO): Protected caller Thread ID is 7729
2019-04-10T14:59:59.102Z,1554908399.102 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2019-04-10T14:59:59.102Z,1554908399.102 [Supervisor](INFO): Looking for Config files in directory: Config/
2019-04-10T14:59:59.103Z,1554908399.103 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2019-04-10T14:59:59.198Z,1554908399.198 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2019-04-10T14:59:59.199Z,1554908399.199 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2019-04-10T14:59:59.399Z,1554908399.399 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2019-04-10T14:59:59.400Z,1554908399.400 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2019-04-10T14:59:59.535Z,1554908399.535 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2019-04-10T14:59:59.536Z,1554908399.536 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2019-04-10T14:59:59.993Z,1554908399.993 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2019-04-10T14:59:59.994Z,1554908399.994 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2019-04-10T15:00:00.435Z,1554908400.435 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2019-04-10T15:00:00.436Z,1554908400.436 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2019-04-10T15:00:00.903Z,1554908400.903 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2019-04-10T15:00:00.903Z,1554908400.903 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2019-04-10T15:00:01.217Z,1554908401.217 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2019-04-10T15:00:01.218Z,1554908401.218 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2019-04-10T15:00:01.828Z,1554908401.828 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2019-04-10T15:00:01.828Z,1554908401.828 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2019-04-10T15:00:02.221Z,1554908402.221 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2019-04-10T15:00:02.222Z,1554908402.222 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2019-04-10T15:00:02.371Z,1554908402.371 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2019-04-10T15:00:02.371Z,1554908402.371 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2019-04-10T15:00:02.474Z,1554908402.474 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2019-04-10T15:00:02.475Z,1554908402.475 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2019-04-10T15:00:02.555Z,1554908402.555 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2019-04-10T15:00:02.655Z,1554908402.655 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2019-04-10T15:00:02.655Z,1554908402.655 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2019-04-10T15:00:02.850Z,1554908402.850 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2019-04-10T15:00:02.851Z,1554908402.851 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2019-04-10T15:00:03.057Z,1554908403.057 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2019-04-10T15:00:03.060Z,1554908403.060 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/
2019-04-10T15:00:03.060Z,1554908403.060 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg
2019-04-10T15:00:03.145Z,1554908403.145 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg
2019-04-10T15:00:03.375Z,1554908403.375 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2019-04-10T15:00:03.376Z,1554908403.376 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg
2019-04-10T15:00:03.470Z,1554908403.470 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg
2019-04-10T15:00:03.643Z,1554908403.643 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg
2019-04-10T15:00:03.856Z,1554908403.856 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg
2019-04-10T15:00:03.940Z,1554908403.940 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg
2019-04-10T15:00:04.036Z,1554908404.036 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg
2019-04-10T15:00:04.128Z,1554908404.128 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg
2019-04-10T15:00:04.279Z,1554908404.279 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg
2019-04-10T15:00:04.382Z,1554908404.382 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg
2019-04-10T15:00:04.479Z,1554908404.479 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/root/
2019-04-10T15:00:04.480Z,1554908404.480 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2019-04-10T15:00:04.484Z,1554908404.484 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2019-04-10T15:00:04.582Z,1554908404.582 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2019-04-10T15:00:04.583Z,1554908404.583 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2019-04-10T15:00:04.709Z,1554908404.709 [BuoyancyServo] Loaded
2019-04-10T15:00:04.709Z,1554908404.709 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2019-04-10T15:00:04.724Z,1554908404.724 [ElevatorServo] Loaded
2019-04-10T15:00:04.725Z,1554908404.725 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2019-04-10T15:00:04.740Z,1554908404.740 [MassServo] Loaded
2019-04-10T15:00:04.740Z,1554908404.740 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2019-04-10T15:00:04.755Z,1554908404.755 [RudderServo] Loaded
2019-04-10T15:00:04.755Z,1554908404.755 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2019-04-10T15:00:04.769Z,1554908404.769 [ThrusterServo] Loaded
2019-04-10T15:00:04.770Z,1554908404.770 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2019-04-10T15:00:04.770Z,1554908404.770 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2019-04-10T15:00:04.771Z,1554908404.771 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2019-04-10T15:00:04.905Z,1554908404.905 [SBIT](DEBUG): Construct Startup Built In Test.
2019-04-10T15:00:04.933Z,1554908404.933 [SBIT] Loaded
2019-04-10T15:00:04.933Z,1554908404.933 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2019-04-10T15:00:04.934Z,1554908404.934 [IBIT](DEBUG): Construct Initiated Built In Test.
2019-04-10T15:00:04.962Z,1554908404.962 [IBIT] Loaded
2019-04-10T15:00:04.962Z,1554908404.962 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2019-04-10T15:00:04.965Z,1554908404.965 [CBIT](DEBUG): Construct Continuous Built In Test.
2019-04-10T15:00:05.352Z,1554908405.352 [CBIT] Loaded
2019-04-10T15:00:05.352Z,1554908405.352 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2019-04-10T15:00:05.352Z,1554908405.352 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2019-04-10T15:00:05.353Z,1554908405.353 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2019-04-10T15:00:05.777Z,1554908405.777 [Aanderaa_O2] Loaded
2019-04-10T15:00:05.778Z,1554908405.778 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2019-04-10T15:00:05.787Z,1554908405.787 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_density
2019-04-10T15:00:05.793Z,1554908405.793 [CTD_Seabird](INFO): created writer for : sea_water_density
2019-04-10T15:00:05.794Z,1554908405.794 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): depth
2019-04-10T15:00:05.799Z,1554908405.799 [CTD_Seabird](INFO): created writer for : depth
2019-04-10T15:00:05.800Z,1554908405.800 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_pressure
2019-04-10T15:00:05.805Z,1554908405.805 [CTD_Seabird](INFO): created writer for : sea_water_pressure
2019-04-10T15:00:05.806Z,1554908405.806 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_salinity
2019-04-10T15:00:05.811Z,1554908405.811 [CTD_Seabird](INFO): created writer for : sea_water_salinity
2019-04-10T15:00:05.811Z,1554908405.811 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_temperature
2019-04-10T15:00:05.817Z,1554908405.817 [CTD_Seabird](INFO): created writer for : sea_water_temperature
2019-04-10T15:00:05.818Z,1554908405.818 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_electrical_conductivity
2019-04-10T15:00:05.823Z,1554908405.823 [CTD_Seabird](INFO): created writer for : sea_water_electrical_conductivity
2019-04-10T15:00:05.823Z,1554908405.823 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): speed_of_sound_in_sea_water
2019-04-10T15:00:05.829Z,1554908405.829 [CTD_Seabird](INFO): created writer for : speed_of_sound_in_sea_water
2019-04-10T15:00:05.855Z,1554908405.855 [CTD_Seabird] Loaded
2019-04-10T15:00:05.855Z,1554908405.855 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2019-04-10T15:00:05.856Z,1554908405.856 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 406654E0
2019-04-10T15:00:05.857Z,1554908405.857 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 7808
2019-04-10T15:00:05.883Z,1554908405.883 [ESPComponent] Loaded
2019-04-10T15:00:05.883Z,1554908405.883 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2019-04-10T15:00:05.897Z,1554908405.897 [PAR_Licor] Loaded
2019-04-10T15:00:05.897Z,1554908405.897 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2019-04-10T15:00:05.945Z,1554908405.945 [WetLabsBB2FL] Loaded
2019-04-10T15:00:05.945Z,1554908405.945 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2019-04-10T15:00:05.946Z,1554908405.946 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 406954E0
2019-04-10T15:00:05.947Z,1554908405.947 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 7809
2019-04-10T15:00:05.947Z,1554908405.947 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2019-04-10T15:00:05.948Z,1554908405.948 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2019-04-10T15:00:05.988Z,1554908405.988 [DepthRateCalculator] Loaded
2019-04-10T15:00:05.988Z,1554908405.988 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2019-04-10T15:00:05.994Z,1554908405.994 [PitchRateCalculator] Loaded
2019-04-10T15:00:05.994Z,1554908405.994 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2019-04-10T15:00:06.010Z,1554908406.010 [SpeedCalculator] Loaded
2019-04-10T15:00:06.010Z,1554908406.010 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2019-04-10T15:00:06.032Z,1554908406.032 [TempGradientCalculator] Loaded
2019-04-10T15:00:06.032Z,1554908406.032 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2019-04-10T15:00:06.038Z,1554908406.038 [YawRateCalculator] Loaded
2019-04-10T15:00:06.038Z,1554908406.038 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2019-04-10T15:00:06.071Z,1554908406.071 [ElevatorOffsetCalculator] Loaded
2019-04-10T15:00:06.071Z,1554908406.071 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2019-04-10T15:00:06.072Z,1554908406.072 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2019-04-10T15:00:06.072Z,1554908406.072 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2019-04-10T15:00:06.099Z,1554908406.099 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2019-04-10T15:00:06.099Z,1554908406.099 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2019-04-10T15:00:06.202Z,1554908406.202 [DeadReckonUsingMultipleVelocitySources] Loaded
2019-04-10T15:00:06.202Z,1554908406.202 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2019-04-10T15:00:06.262Z,1554908406.262 [DeadReckonUsingSpeedCalculator] Loaded
2019-04-10T15:00:06.262Z,1554908406.262 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2019-04-10T15:00:06.322Z,1554908406.322 [DeadReckonWithRespectToSeafloor] Loaded
2019-04-10T15:00:06.322Z,1554908406.322 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonWithRespectToSeafloor" handled in the control thread.
2019-04-10T15:00:06.343Z,1554908406.343 [NavChart] Loaded
2019-04-10T15:00:06.343Z,1554908406.343 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2019-04-10T15:00:06.347Z,1554908406.347 [UniversalFixResidualReporter] Loaded
2019-04-10T15:00:06.347Z,1554908406.347 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2019-04-10T15:00:06.348Z,1554908406.348 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2019-04-10T15:00:06.348Z,1554908406.348 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2019-04-10T15:00:07.403Z,1554908407.403 [AcousticModem_Benthos_ATM900] Loaded
2019-04-10T15:00:07.403Z,1554908407.403 [ComponentRegistry](DEBUG): SyncComponent "AcousticModem_Benthos_ATM900" handled in the control thread.
2019-04-10T15:00:07.509Z,1554908407.509 [DataOverHttps] Loaded
2019-04-10T15:00:07.509Z,1554908407.509 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2019-04-10T15:00:07.510Z,1554908407.510 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 409714E0
2019-04-10T15:00:07.511Z,1554908407.511 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 7810
2019-04-10T15:00:07.524Z,1554908407.524 [Depth_Keller] Loaded
2019-04-10T15:00:07.524Z,1554908407.524 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2019-04-10T15:00:07.765Z,1554908407.765 [NAL9602] Loaded
2019-04-10T15:00:07.765Z,1554908407.765 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2019-04-10T15:00:07.771Z,1554908407.771 [Onboard] Loaded
2019-04-10T15:00:07.771Z,1554908407.771 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2019-04-10T15:00:07.774Z,1554908407.774 [Radio_Surface] Loaded
2019-04-10T15:00:07.775Z,1554908407.775 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2019-04-10T15:00:07.776Z,1554908407.776 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409A14E0
2019-04-10T15:00:07.776Z,1554908407.776 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 7811
2019-04-10T15:00:09.068Z,1554908409.068 [BPC1] Loaded
2019-04-10T15:00:09.068Z,1554908409.068 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2019-04-10T15:00:09.099Z,1554908409.099 [BR_Ping1D](CRITICAL): No configuration setting for: BR_Ping1D.minrange
2019-04-10T15:00:09.101Z,1554908409.101 [BR_Ping1D](CRITICAL): No configuration setting for: BR_Ping1D.maxrange
2019-04-10T15:00:09.103Z,1554908409.103 [BR_Ping1D](CRITICAL): No configuration setting for: BR_Ping1D.soundspeed
2019-04-10T15:00:09.105Z,1554908409.105 [BR_Ping1D](CRITICAL): No configuration setting for: BR_Ping1D.automode
2019-04-10T15:00:09.107Z,1554908409.107 [BR_Ping1D](CRITICAL): No configuration setting for: BR_Ping1D.gainindex
2019-04-10T15:00:09.109Z,1554908409.109 [BR_Ping1D](CRITICAL): No configuration setting for: BR_Ping1D.minconfidence
2019-04-10T15:00:09.111Z,1554908409.111 [BR_Ping1D](CRITICAL): No configuration setting for: BR_Ping1D.pingenable
2019-04-10T15:00:09.113Z,1554908409.113 [BR_Ping1D] Loaded
2019-04-10T15:00:09.114Z,1554908409.114 [ComponentRegistry](DEBUG): SyncComponent "BR_Ping1D" handled in the control thread.
2019-04-10T15:00:09.114Z,1554908409.114 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2019-04-10T15:00:09.115Z,1554908409.115 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2019-04-10T15:00:09.178Z,1554908409.178 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2019-04-10T15:00:09.179Z,1554908409.179 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2019-04-10T15:00:09.245Z,1554908409.245 [VerticalControl](DEBUG): Construct VerticalControl.
2019-04-10T15:00:09.329Z,1554908409.329 [VerticalControl] Loaded
2019-04-10T15:00:09.330Z,1554908409.330 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2019-04-10T15:00:09.331Z,1554908409.331 [HorizontalControl](DEBUG): Construct HorizontalControl.
2019-04-10T15:00:09.388Z,1554908409.388 [HorizontalControl] Loaded
2019-04-10T15:00:09.388Z,1554908409.388 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2019-04-10T15:00:09.389Z,1554908409.389 [SpeedControl](DEBUG): Construct SpeedControl.
2019-04-10T15:00:09.391Z,1554908409.391 [SpeedControl] Loaded
2019-04-10T15:00:09.391Z,1554908409.391 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2019-04-10T15:00:09.392Z,1554908409.392 [LoopControl](DEBUG): Construct LoopControl.
2019-04-10T15:00:09.392Z,1554908409.392 [LoopControl] Loaded
2019-04-10T15:00:09.393Z,1554908409.393 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2019-04-10T15:00:09.393Z,1554908409.393 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2019-04-10T15:00:09.394Z,1554908409.394 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2019-04-10T15:00:09.407Z,1554908409.407 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2019-04-10T15:00:09.408Z,1554908409.408 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2019-04-10T15:00:09.683Z,1554908409.683 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2019-04-10T15:00:09.687Z,1554908409.687 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2019-04-10T15:00:09.687Z,1554908409.687 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2019-04-10T15:00:09.694Z,1554908409.694 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2019-04-10T15:00:09.695Z,1554908409.695 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40ACE4E0
2019-04-10T15:00:09.696Z,1554908409.696 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 7812
2019-04-10T15:00:09.701Z,1554908409.701 [Supervisor](INFO): Main Thread ID is 7333
2019-04-10T15:00:09.701Z,1554908409.701 [Supervisor](DEBUG): Running supervisor.
2019-04-10T15:00:09.701Z,1554908409.701 [CommandLine ThreadHandler](INFO): Handler Thread ID is 7813
2019-04-10T15:00:09.704Z,1554908409.704 [controlThread ThreadHandler](INFO): Handler Thread ID is 7814
2019-04-10T15:00:09.704Z,1554908409.704 [controlThread](DEBUG): Initializing ControlThread
2019-04-10T15:00:09.706Z,1554908409.706 [SBIT](INFO): Initialize SBIT Component.
2019-04-10T15:00:09.707Z,1554908409.707 [SBIT](IMPORTANT): git: 2019-03-18-31-ge98d5dc
2019-04-10T15:00:09.707Z,1554908409.707 [SBIT](INFO): git hash: e98d5dc50cbc39e402f19b9946ff4dc0776c8725
2019-04-10T15:00:09.707Z,1554908409.707 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2019-04-10T15:00:09.709Z,1554908409.709 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
Kernel Reported: #1 PREEMPT Thu Feb 21 11:17:40 PST 2019
2019-04-10T15:00:09.710Z,1554908409.710 [SBIT](INFO): Beginning SBIT in 24.000000 seconds.
2019-04-10T15:00:09.710Z,1554908409.710 [IBIT](INFO): Initialize IBIT Component.
2019-04-10T15:00:09.711Z,1554908409.711 [CBIT](DEBUG): Initialize CBIT Component.
2019-04-10T15:00:09.712Z,1554908409.712 [logger ThreadHandler](INFO): Handler Thread ID is 7815
2019-04-10T15:00:09.722Z,1554908409.722 [CBIT](DEBUG): Initialized mux pins.
2019-04-10T15:00:09.722Z,1554908409.722 [CBIT](DEBUG): Initializing the watchdog timer.
2019-04-10T15:00:09.730Z,1554908409.730 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 7816
2019-04-10T15:00:09.731Z,1554908409.731 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2019-04-10T15:00:09.735Z,1554908409.735 [CTD_Seabird](INFO): Opening uart, block timeout 10ths=20
2019-04-10T15:00:09.736Z,1554908409.736 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 7818
2019-04-10T15:00:09.737Z,1554908409.737 [WetLabsBB2FL](INFO): Powering down
2019-04-10T15:00:09.746Z,1554908409.746 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2019-04-10T15:00:09.747Z,1554908409.747 [CBIT](DEBUG): Initializing heartbeat.
2019-04-10T15:00:09.767Z,1554908409.767 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 7819
2019-04-10T15:00:09.768Z,1554908409.768 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2019-04-10T15:00:09.775Z,1554908409.775 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 7820
2019-04-10T15:00:09.794Z,1554908409.794 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 7821
2019-04-10T15:00:09.797Z,1554908409.797 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2019-04-10T15:00:09.798Z,1554908409.798 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2019-04-10T15:00:09.798Z,1554908409.798 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2019-04-10T15:00:09.798Z,1554908409.798 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2019-04-10T15:00:09.798Z,1554908409.798 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2019-04-10T15:00:09.798Z,1554908409.798 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2019-04-10T15:00:09.799Z,1554908409.799 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2019-04-10T15:00:09.799Z,1554908409.799 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2019-04-10T15:00:09.799Z,1554908409.799 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2019-04-10T15:00:09.799Z,1554908409.799 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2019-04-10T15:00:09.799Z,1554908409.799 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2019-04-10T15:00:09.800Z,1554908409.800 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2019-04-10T15:00:09.800Z,1554908409.800 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2019-04-10T15:00:09.800Z,1554908409.800 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2019-04-10T15:00:09.800Z,1554908409.800 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2019-04-10T15:00:09.800Z,1554908409.800 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2019-04-10T15:00:09.818Z,1554908409.818 [CBIT](DEBUG): Deactivating GF circuits.
2019-04-10T15:00:09.818Z,1554908409.818 [CBIT](DEBUG): Deactivating emergency mode.
2019-04-10T15:00:09.854Z,1554908409.854 [CBIT](DEBUG): Backplane powered.
2019-04-10T15:00:09.858Z,1554908409.858 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2019-04-10T15:00:09.859Z,1554908409.859 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2019-04-10T15:00:09.859Z,1554908409.859 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2019-04-10T15:00:09.859Z,1554908409.859 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2019-04-10T15:00:09.860Z,1554908409.860 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2019-04-10T15:00:09.860Z,1554908409.860 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2019-04-10T15:00:09.861Z,1554908409.861 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2019-04-10T15:00:09.862Z,1554908409.862 [NavChart](DEBUG): Initialize NavChart Navigation.
2019-04-10T15:00:09.863Z,1554908409.863 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2019-04-10T15:00:09.867Z,1554908409.867 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2019-04-10T15:00:09.869Z,1554908409.869 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2019-04-10T15:00:09.870Z,1554908409.870 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2019-04-10T15:00:09.870Z,1554908409.870 [LoopControl](DEBUG): Initialize LoopControlComponent.
2019-04-10T15:00:09.871Z,1554908409.871 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2019-04-10T15:00:09.893Z,1554908409.893 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2019-04-10T15:00:09.929Z,1554908409.929 [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-04-10T15:00:09.930Z,1554908409.930 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2019-04-10T15:00:10.013Z,1554908410.013 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2019-04-10T15:00:10.014Z,1554908410.014 [Default:A.Wait](DEBUG): Construct Wait.
2019-04-10T15:00:10.016Z,1554908410.016 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2019-04-10T15:00:10.067Z,1554908410.067 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2019-04-10T15:00:10.070Z,1554908410.070 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2019-04-10T15:00:10.084Z,1554908410.084 [Default:E.Execute](DEBUG): Construct Execute.
2019-04-10T15:00:10.087Z,1554908410.087 [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-04-10T15:00:10.106Z,1554908410.106 [controlThread](DEBUG): Component order: CycleStarter,Aanderaa_O2,ESPComponent,PAR_Licor,AcousticModem_Benthos_ATM900,Depth_Keller,NAL9602,Onboard,BPC1,BR_Ping1D,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,DeadReckonUsingSpeedCalculator,DeadReckonWithRespectToSeafloor,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2019-04-10T15:00:10.139Z,1554908410.139 [ESPComponent](INFO): powering down ESP
2019-04-10T15:00:10.178Z,1554908410.178 [Radio_Surface](INFO): Powering up
2019-04-10T15:00:10.566Z,1554908410.566 [PAR_Licor](INFO): A/D timeout, 8 tries over 132 ms

2019-04-10T15:00:10.566Z,1554908410.566 [PAR_Licor] Data Fault, FailCount= 1
2019-04-10T15:00:10.567Z,1554908410.567 [PAR_Licor](ERROR): Data Fault
2019-04-10T15:00:10.567Z,1554908410.567 [AcousticModem_Benthos_ATM900](INFO): Powering up
2019-04-10T15:00:10.567Z,1554908410.567 [AcousticModem_Benthos_ATM900](DEBUG): Initializing AcousticModem_Benthos_ATM900.
2019-04-10T15:00:10.784Z,1554908410.784 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2019-04-10T15:00:10.790Z,1554908410.790 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2019-04-10T15:00:10.791Z,1554908410.791 [ElevatorServo](DEBUG): Initializing EZServoServo.
2019-04-10T15:00:10.798Z,1554908410.798 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2019-04-10T15:00:10.799Z,1554908410.799 [MassServo](DEBUG): Initializing EZServoServo.
2019-04-10T15:00:10.806Z,1554908410.806 [MassServo](DEBUG): Initializing MassServo.
2019-04-10T15:00:10.807Z,1554908410.807 [RudderServo](DEBUG): Initializing EZServoServo.
2019-04-10T15:00:10.814Z,1554908410.814 [RudderServo](DEBUG): Initializing RudderServo.
2019-04-10T15:00:10.815Z,1554908410.815 [ThrusterServo](DEBUG): Initializing EZServoServo.
2019-04-10T15:00:10.822Z,1554908410.822 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2019-04-10T15:00:10.825Z,1554908410.825 [CommandLine](FAULT): Scheduling is paused
2019-04-10T15:00:10.825Z,1554908410.825 [CBIT](INFO): Critical error at 20190410T150009
2019-04-10T15:00:10.825Z,1554908410.825 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2019-04-10T15:00:10.830Z,1554908410.830 [CBIT](ERROR): Data Fault in component: PAR_Licor
2019-04-10T15:00:10.830Z,1554908410.830 [CBIT](INFO): Clearing failed state for component PAR_Licor
2019-04-10T15:00:10.830Z,1554908410.830 [PAR_Licor] No Fault, FailCount= 1
2019-04-10T15:00:11.383Z,1554908411.383 [PAR_Licor](INFO): A/D timeout, 10 tries over 143 ms

2019-04-10T15:00:11.383Z,1554908411.383 [PAR_Licor] Data Fault, FailCount= 2
2019-04-10T15:00:11.383Z,1554908411.383 [PAR_Licor](ERROR): Data Fault
2019-04-10T15:00:11.436Z,1554908411.436 [BR_Ping1D](INFO): startup: 0
2019-04-10T15:00:11.436Z,1554908411.436 [BR_Ping1D](INFO): recvData: FFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFF
2019-04-10T15:00:11.437Z,1554908411.437 [BR_Ping1D](INFO): UART setting parameters ...
2019-04-10T15:00:11.450Z,1554908411.450 [BR_Ping1D](INFO): 4CD70200EC030000F4010903
2019-04-10T15:00:11.450Z,1554908411.450 [BR_Ping1D](INFO): 4CD70100EB030000011302
2019-04-10T15:00:11.450Z,1554908411.450 [BR_Ping1D](INFO): 4CD70400EA03000060E316006D03
2019-04-10T15:00:11.451Z,1554908411.451 [BR_Ping1D](INFO): 4CD70100EE030000011602
2019-04-10T15:00:11.781Z,1554908411.781 [CBIT](ERROR): Data Fault in component: PAR_Licor
2019-04-10T15:00:11.782Z,1554908411.782 [CBIT](INFO): Clearing failed state for component PAR_Licor
2019-04-10T15:00:11.782Z,1554908411.782 [PAR_Licor] No Fault, FailCount= 2
2019-04-10T15:00:11.829Z,1554908411.829 [BR_Ping1D](INFO): Starting
2019-04-10T15:00:12.214Z,1554908412.214 [BR_Ping1D](INFO): Starting
2019-04-10T15:00:12.214Z,1554908412.214 [BR_Ping1D](INFO): readConfig
2019-04-10T15:00:12.214Z,1554908412.214 [BR_Ping1D](INFO): startup: 1
2019-04-10T15:00:12.214Z,1554908412.214 [BR_Ping1D](INFO): UART requesting status
2019-04-10T15:00:12.214Z,1554908412.214 [BR_Ping1D](INFO): 4CE50000BA040000EF01
2019-04-10T15:00:12.226Z,1554908412.226 [BR_Ping1D](INFO): 4CD00000BF040000DF01
2019-04-10T15:00:12.238Z,1554908412.238 [BR_Ping1D](INFO): 4CD00000B3040000D301
2019-04-10T15:00:12.734Z,1554908412.734 [PAR_Licor](INFO): A/D timeout, 9 tries over 138 ms

2019-04-10T15:00:12.734Z,1554908412.734 [PAR_Licor] Data Fault, FailCount= 1
2019-04-10T15:00:12.734Z,1554908412.734 [PAR_Licor](ERROR): Data Fault
2019-04-10T15:00:12.771Z,1554908412.771 [BR_Ping1D](INFO): Starting
2019-04-10T15:00:12.772Z,1554908412.772 [BR_Ping1D](INFO): readConfig
2019-04-10T15:00:12.772Z,1554908412.772 [BR_Ping1D](INFO): startup: 2
2019-04-10T15:00:12.772Z,1554908412.772 [BR_Ping1D](INFO): UART waiting for response
2019-04-10T15:00:12.772Z,1554908412.772 [BR_Ping1D](INFO): elapsed 1.3355
2019-04-10T15:00:12.772Z,1554908412.772 [BR_Ping1D](INFO): timeout 5.0000
2019-04-10T15:00:12.773Z,1554908412.773 [BR_Ping1D](INFO): No UART data
2019-04-10T15:00:12.773Z,1554908412.773 [BR_Ping1D](INFO): received UART packets: 0
2019-04-10T15:00:12.773Z,1554908412.773 [BR_Ping1D](INFO): not all values verified yet
2019-04-10T15:00:12.806Z,1554908412.806 [CBIT](ERROR): Data Fault in component: PAR_Licor
2019-04-10T15:00:12.806Z,1554908412.806 [CBIT](INFO): Clearing failed state for component PAR_Licor
2019-04-10T15:00:12.806Z,1554908412.806 [PAR_Licor] No Fault, FailCount= 1
2019-04-10T15:00:13.022Z,1554908413.022 [BR_Ping1D](INFO): Starting
2019-04-10T15:00:13.022Z,1554908413.022 [BR_Ping1D](INFO): readConfig
2019-04-10T15:00:13.022Z,1554908413.022 [BR_Ping1D](INFO): startup: 2
2019-04-10T15:00:13.022Z,1554908413.022 [BR_Ping1D](INFO): UART waiting for response
2019-04-10T15:00:13.022Z,1554908413.022 [BR_Ping1D](INFO): elapsed 1.5857
2019-04-10T15:00:13.023Z,1554908413.023 [BR_Ping1D](INFO): timeout 5.0000
2019-04-10T15:00:13.023Z,1554908413.023 [BR_Ping1D](INFO): No UART data
2019-04-10T15:00:13.023Z,1554908413.023 [BR_Ping1D](INFO): received UART packets: 0
2019-04-10T15:00:13.023Z,1554908413.023 [BR_Ping1D](INFO): not all values verified yet
2019-04-10T15:00:13.546Z,1554908413.546 [PAR_Licor](INFO): A/D timeout, 9 tries over 142 ms

2019-04-10T15:00:13.546Z,1554908413.546 [PAR_Licor] Data Fault, FailCount= 2
2019-04-10T15:00:13.546Z,1554908413.546 [PAR_Licor](ERROR): Data Fault
2019-04-10T15:00:13.587Z,1554908413.587 [BR_Ping1D](INFO): Starting
2019-04-10T15:00:13.587Z,1554908413.587 [BR_Ping1D](INFO): readConfig
2019-04-10T15:00:13.587Z,1554908413.587 [BR_Ping1D](INFO): startup: 2
2019-04-10T15:00:13.587Z,1554908413.587 [BR_Ping1D](INFO): UART waiting for response
2019-04-10T15:00:13.587Z,1554908413.587 [BR_Ping1D](INFO): elapsed 2.1506
2019-04-10T15:00:13.588Z,1554908413.588 [BR_Ping1D](INFO): timeout 5.0000
2019-04-10T15:00:13.588Z,1554908413.588 [BR_Ping1D](INFO): No UART data
2019-04-10T15:00:13.588Z,1554908413.588 [BR_Ping1D](INFO): received UART packets: 0
2019-04-10T15:00:13.588Z,1554908413.588 [BR_Ping1D](INFO): not all values verified yet
2019-04-10T15:00:13.698Z,1554908413.698 [CBIT](ERROR): Data Fault in component: PAR_Licor
2019-04-10T15:00:13.698Z,1554908413.698 [CBIT](INFO): Clearing failed state for component PAR_Licor
2019-04-10T15:00:13.699Z,1554908413.699 [PAR_Licor] No Fault, FailCount= 2
2019-04-10T15:00:13.830Z,1554908413.830 [BR_Ping1D](INFO): Starting
2019-04-10T15:00:13.830Z,1554908413.830 [BR_Ping1D](INFO): readConfig
2019-04-10T15:00:13.830Z,1554908413.830 [BR_Ping1D](INFO): startup: 2
2019-04-10T15:00:13.830Z,1554908413.830 [BR_Ping1D](INFO): UART waiting for response
2019-04-10T15:00:13.831Z,1554908413.831 [BR_Ping1D](INFO): elapsed 2.3940
2019-04-10T15:00:13.831Z,1554908413.831 [BR_Ping1D](INFO): timeout 5.0000
2019-04-10T15:00:13.831Z,1554908413.831 [BR_Ping1D](INFO): No UART data
2019-04-10T15:00:13.831Z,1554908413.831 [BR_Ping1D](INFO): received UART packets: 0
2019-04-10T15:00:13.831Z,1554908413.831 [BR_Ping1D](INFO): not all values verified yet
2019-04-10T15:00:14.238Z,1554908414.238 [BR_Ping1D](INFO): Starting
2019-04-10T15:00:14.238Z,1554908414.238 [BR_Ping1D](INFO): readConfig
2019-04-10T15:00:14.238Z,1554908414.238 [BR_Ping1D](INFO): startup: 2
2019-04-10T15:00:14.238Z,1554908414.238 [BR_Ping1D](INFO): UART waiting for response
2019-04-10T15:00:14.238Z,1554908414.238 [BR_Ping1D](INFO): elapsed 2.8017
2019-04-10T15:00:14.239Z,1554908414.239 [BR_Ping1D](INFO): timeout 5.0000
2019-04-10T15:00:14.239Z,1554908414.239 [BR_Ping1D](INFO): No UART data
2019-04-10T15:00:14.239Z,1554908414.239 [BR_Ping1D](INFO): received UART packets: 0
2019-04-10T15:00:14.239Z,1554908414.239 [BR_Ping1D](INFO): not all values verified yet
2019-04-10T15:00:14.818Z,1554908414.818 [PAR_Licor](INFO): A/D timeout, 7 tries over 149 ms

2019-04-10T15:00:14.818Z,1554908414.818 [PAR_Licor] Data Fault, FailCount= 1
2019-04-10T15:00:14.818Z,1554908414.818 [PAR_Licor](ERROR): Data Fault
2019-04-10T15:00:14.853Z,1554908414.853 [BR_Ping1D](INFO): Starting
2019-04-10T15:00:14.853Z,1554908414.853 [BR_Ping1D](INFO): readConfig
2019-04-10T15:00:14.854Z,1554908414.854 [BR_Ping1D](INFO): startup: 2
2019-04-10T15:00:14.854Z,1554908414.854 [BR_Ping1D](INFO): UART waiting for response
2019-04-10T15:00:14.854Z,1554908414.854 [BR_Ping1D](INFO): elapsed 3.4173
2019-04-10T15:00:14.854Z,1554908414.854 [BR_Ping1D](INFO): timeout 5.0000
2019-04-10T15:00:14.854Z,1554908414.854 [BR_Ping1D](INFO): No UART data
2019-04-10T15:00:14.855Z,1554908414.855 [BR_Ping1D](INFO): received UART packets: 0
2019-04-10T15:00:14.855Z,1554908414.855 [BR_Ping1D](INFO): not all values verified yet
2019-04-10T15:00:14.930Z,1554908414.930 [CBIT](ERROR): Data Fault in component: PAR_Licor
2019-04-10T15:00:14.930Z,1554908414.930 [CBIT](INFO): Clearing failed state for component PAR_Licor
2019-04-10T15:00:14.931Z,1554908414.931 [PAR_Licor] No Fault, FailCount= 1
2019-04-10T15:00:15.095Z,1554908415.095 [BR_Ping1D](INFO): Starting
2019-04-10T15:00:15.095Z,1554908415.095 [BR_Ping1D](INFO): readConfig
2019-04-10T15:00:15.095Z,1554908415.095 [BR_Ping1D](INFO): startup: 2
2019-04-10T15:00:15.095Z,1554908415.095 [BR_Ping1D](INFO): UART waiting for response
2019-04-10T15:00:15.096Z,1554908415.096 [BR_Ping1D](INFO): elapsed 3.6589
2019-04-10T15:00:15.096Z,1554908415.096 [BR_Ping1D](INFO): timeout 5.0000
2019-04-10T15:00:15.096Z,1554908415.096 [BR_Ping1D](INFO): No UART data
2019-04-10T15:00:15.096Z,1554908415.096 [BR_Ping1D](INFO): received UART packets: 0
2019-04-10T15:00:15.096Z,1554908415.096 [BR_Ping1D](INFO): not all values verified yet
2019-04-10T15:00:15.618Z,1554908415.618 [PAR_Licor](INFO): A/D timeout, 10 tries over 142 ms

2019-04-10T15:00:15.618Z,1554908415.618 [PAR_Licor] Data Fault, FailCount= 2
2019-04-10T15:00:15.618Z,1554908415.618 [PAR_Licor](ERROR): Data Fault
2019-04-10T15:00:15.652Z,1554908415.652 [BR_Ping1D](INFO): Starting
2019-04-10T15:00:15.652Z,1554908415.652 [BR_Ping1D](INFO): readConfig
2019-04-10T15:00:15.652Z,1554908415.652 [BR_Ping1D](INFO): startup: 2
2019-04-10T15:00:15.652Z,1554908415.652 [BR_Ping1D](INFO): UART waiting for response
2019-04-10T15:00:15.652Z,1554908415.652 [BR_Ping1D](INFO): elapsed 4.2158
2019-04-10T15:00:15.653Z,1554908415.653 [BR_Ping1D](INFO): timeout 5.0000
2019-04-10T15:00:15.653Z,1554908415.653 [BR_Ping1D](INFO): No UART data
2019-04-10T15:00:15.653Z,1554908415.653 [BR_Ping1D](INFO): received UART packets: 0
2019-04-10T15:00:15.653Z,1554908415.653 [BR_Ping1D](INFO): not all values verified yet
2019-04-10T15:00:15.734Z,1554908415.734 [CBIT](ERROR): Data Fault in component: PAR_Licor
2019-04-10T15:00:15.734Z,1554908415.734 [CBIT](INFO): Clearing failed state for component PAR_Licor
2019-04-10T15:00:15.734Z,1554908415.734 [PAR_Licor] No Fault, FailCount= 2
2019-04-10T15:00:15.902Z,1554908415.902 [BR_Ping1D](INFO): Starting
2019-04-10T15:00:15.902Z,1554908415.902 [BR_Ping1D](INFO): readConfig
2019-04-10T15:00:15.902Z,1554908415.902 [BR_Ping1D](INFO): startup: 2
2019-04-10T15:00:15.903Z,1554908415.903 [BR_Ping1D](INFO): UART waiting for response
2019-04-10T15:00:15.903Z,1554908415.903 [BR_Ping1D](INFO): elapsed 4.4661
2019-04-10T15:00:15.903Z,1554908415.903 [BR_Ping1D](INFO): timeout 5.0000
2019-04-10T15:00:15.903Z,1554908415.903 [BR_Ping1D](INFO): No UART data
2019-04-10T15:00:15.903Z,1554908415.903 [BR_Ping1D](INFO): received UART packets: 0
2019-04-10T15:00:15.903Z,1554908415.903 [BR_Ping1D](INFO): not all values verified yet
2019-04-10T15:00:16.422Z,1554908416.422 [PAR_Licor](INFO): A/D timeout, 9 tries over 138 ms

2019-04-10T15:00:16.422Z,1554908416.422 [PAR_Licor] Data Fault, FailCount= 3
2019-04-10T15:00:16.422Z,1554908416.422 [PAR_Licor](ERROR): Data Fault
2019-04-10T15:00:16.469Z,1554908416.469 [BR_Ping1D](INFO): Starting
2019-04-10T15:00:16.469Z,1554908416.469 [BR_Ping1D](INFO): readConfig
2019-04-10T15:00:16.469Z,1554908416.469 [BR_Ping1D](INFO): startup: 2
2019-04-10T15:00:16.470Z,1554908416.470 [BR_Ping1D](INFO): UART waiting for response
2019-04-10T15:00:16.470Z,1554908416.470 [BR_Ping1D](INFO): elapsed 5.0332
2019-04-10T15:00:16.470Z,1554908416.470 [BR_Ping1D](INFO): timeout 5.0000
2019-04-10T15:00:16.470Z,1554908416.470 [BR_Ping1D](FAULT): Failed to set parameters in time during initialization.
2019-04-10T15:00:16.470Z,1554908416.470 [BR_Ping1D] Data Fault, FailCount= 1
2019-04-10T15:00:16.470Z,1554908416.470 [BR_Ping1D](ERROR): Data Fault
2019-04-10T15:00:16.742Z,1554908416.742 [CBIT](ERROR): Data Fault in component: PAR_Licor
2019-04-10T15:00:16.743Z,1554908416.743 [CBIT](CRITICAL): Data Fault in component: PAR_Licor
2019-04-10T15:00:16.743Z,1554908416.743 [CBIT](ERROR): Data Fault in component: BR_Ping1D
2019-04-10T15:00:16.767Z,1554908416.767 [BR_Ping1D](INFO): Stop
2019-04-10T15:00:16.767Z,1554908416.767 [BR_Ping1D](INFO): uninitialize
2019-04-10T15:00:16.768Z,1554908416.768 [BR_Ping1D](INFO): Powering down
2019-04-10T15:00:16.950Z,1554908416.950 [CBIT](INFO): Critical error at 20190410T150016
2019-04-10T15:00:17.170Z,1554908417.170 [BR_Ping1D](INFO): Stopping
2019-04-10T15:00:17.573Z,1554908417.573 [BR_Ping1D](INFO): Stopping
2019-04-10T15:00:17.978Z,1554908417.978 [BR_Ping1D](INFO): Stopped
2019-04-10T15:00:18.031Z,1554908418.031 [CBIT](INFO): Clearing failed state for component BR_Ping1D
2019-04-10T15:00:18.031Z,1554908418.031 [BR_Ping1D] No Fault, FailCount= 1
2019-04-10T15:00:18.382Z,1554908418.382 [BR_Ping1D](INFO): Start
2019-04-10T15:00:18.785Z,1554908418.785 [BR_Ping1D](INFO): Starting
2019-04-10T15:00:19.189Z,1554908419.189 [BR_Ping1D](INFO): Starting
2019-04-10T15:00:19.190Z,1554908419.190 [BR_Ping1D](INFO): readConfig
2019-04-10T15:00:19.190Z,1554908419.190 [BR_Ping1D](INFO): startup: 0
2019-04-10T15:00:19.190Z,1554908419.190 [BR_Ping1D](INFO): recvData: FFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFF
2019-04-10T15:00:19.190Z,1554908419.190 [BR_Ping1D](INFO): UART setting parameters ...
2019-04-10T15:00:19.202Z,1554908419.202 [BR_Ping1D](INFO): 4CE50200EC030000F4011703
2019-04-10T15:00:19.202Z,1554908419.202 [BR_Ping1D](INFO): 4CE50100EB030000012102
2019-04-10T15:00:19.202Z,1554908419.202 [BR_Ping1D](INFO): 4CE50400EA03000060E316007B03
2019-04-10T15:00:19.202Z,1554908419.202 [BR_Ping1D](INFO): 4CE50100EE030000012402
2019-04-10T15:00:19.595Z,1554908419.595 [BR_Ping1D](INFO): Starting
2019-04-10T15:00:19.771Z,1554908419.771 [CBIT](CRITICAL): Environmental Failure. Press:14.879421 PSI. Humidity:32%. Temp:26 C. ABORTING MISSION
2019-04-10T15:00:19.998Z,1554908419.998 [BR_Ping1D](INFO): Starting
2019-04-10T15:00:19.998Z,1554908419.998 [BR_Ping1D](INFO): readConfig
2019-04-10T15:00:19.998Z,1554908419.998 [BR_Ping1D](INFO): startup: 1
2019-04-10T15:00:19.998Z,1554908419.998 [BR_Ping1D](INFO): UART requesting status
2019-04-10T15:00:19.998Z,1554908419.998 [BR_Ping1D](INFO): 4CE50000BA040000EF01
2019-04-10T15:00:20.010Z,1554908420.010 [BR_Ping1D](INFO): 4CE50000BF040000F401
2019-04-10T15:00:20.022Z,1554908420.022 [BR_Ping1D](INFO): 4CE50000B3040000E801
2019-04-10T15:00:20.042Z,1554908420.042 [CBIT](INFO): Critical error at 20190410T150019
2019-04-10T15:00:20.383Z,1554908420.383 [Aanderaa_O2](FAULT): Failed to initialize within timeout.
2019-04-10T15:00:20.383Z,1554908420.383 [Aanderaa_O2] Communications Fault, FailCount= 1
2019-04-10T15:00:20.383Z,1554908420.383 [Aanderaa_O2](ERROR): Communications Fault
2019-04-10T15:00:20.402Z,1554908420.402 [BR_Ping1D](INFO): Starting
2019-04-10T15:00:20.402Z,1554908420.402 [BR_Ping1D](INFO): readConfig
2019-04-10T15:00:20.403Z,1554908420.403 [BR_Ping1D](INFO): startup: 2
2019-04-10T15:00:20.403Z,1554908420.403 [BR_Ping1D](INFO): UART waiting for response
2019-04-10T15:00:20.403Z,1554908420.403 [BR_Ping1D](INFO): elapsed 1.2126
2019-04-10T15:00:20.403Z,1554908420.403 [BR_Ping1D](INFO): timeout 5.0000
2019-04-10T15:00:20.404Z,1554908420.404 [BR_Ping1D](INFO): No UART data
2019-04-10T15:00:20.404Z,1554908420.404 [BR_Ping1D](INFO): received UART packets: 0
2019-04-10T15:00:20.404Z,1554908420.404 [BR_Ping1D](INFO): not all values verified yet
2019-04-10T15:00:20.419Z,1554908420.419 [CBIT](ERROR): Communications Fault in component: Aanderaa_O2
2019-04-10T15:00:20.906Z,1554908420.906 [Aanderaa_O2](INFO): Powering down
2019-04-10T15:00:20.994Z,1554908420.994 [BR_Ping1D](INFO): Starting
2019-04-10T15:00:20.994Z,1554908420.994 [BR_Ping1D](INFO): readConfig
2019-04-10T15:00:20.994Z,1554908420.994 [BR_Ping1D](INFO): startup: 2
2019-04-10T15:00:20.994Z,1554908420.994 [BR_Ping1D](INFO): UART waiting for response
2019-04-10T15:00:20.994Z,1554908420.994 [BR_Ping1D](INFO): elapsed 1.8038
2019-04-10T15:00:20.995Z,1554908420.995 [BR_Ping1D](INFO): timeout 5.0000
2019-04-10T15:00:20.995Z,1554908420.995 [BR_Ping1D](INFO): No UART data
2019-04-10T15:00:20.995Z,1554908420.995 [BR_Ping1D](INFO): received UART packets: 0
2019-04-10T15:00:20.995Z,1554908420.995 [BR_Ping1D](INFO): not all values verified yet
2019-04-10T15:00:21.209Z,1554908421.209 [BR_Ping1D](INFO): Starting
2019-04-10T15:00:21.209Z,1554908421.209 [BR_Ping1D](INFO): readConfig
2019-04-10T15:00:21.210Z,1554908421.210 [BR_Ping1D](INFO): startup: 2
2019-04-10T15:00:21.210Z,1554908421.210 [BR_Ping1D](INFO): UART waiting for response
2019-04-10T15:00:21.210Z,1554908421.210 [BR_Ping1D](INFO): elapsed 2.0197
2019-04-10T15:00:21.210Z,1554908421.210 [BR_Ping1D](INFO): timeout 5.0000
2019-04-10T15:00:21.211Z,1554908421.211 [BR_Ping1D](INFO): No UART data
2019-04-10T15:00:21.211Z,1554908421.211 [BR_Ping1D](INFO): received UART packets: 0
2019-04-10T15:00:21.211Z,1554908421.211 [BR_Ping1D](INFO): not all values verified yet
2019-04-10T15:00:21.614Z,1554908421.614 [BR_Ping1D](INFO): Starting
2019-04-10T15:00:21.614Z,1554908421.614 [BR_Ping1D](INFO): readConfig
2019-04-10T15:00:21.614Z,1554908421.614 [BR_Ping1D](INFO): startup: 2
2019-04-10T15:00:21.614Z,1554908421.614 [BR_Ping1D](INFO): UART waiting for response
2019-04-10T15:00:21.615Z,1554908421.615 [BR_Ping1D](INFO): elapsed 2.4242
2019-04-10T15:00:21.615Z,1554908421.615 [BR_Ping1D](INFO): timeout 5.0000
2019-04-10T15:00:21.615Z,1554908421.615 [BR_Ping1D](INFO): No UART data
2019-04-10T15:00:21.615Z,1554908421.615 [BR_Ping1D](INFO): received UART packets: 0
2019-04-10T15:00:21.615Z,1554908421.615 [BR_Ping1D](INFO): not all values verified yet
2019-04-10T15:00:21.647Z,1554908421.647 [CBIT](INFO): Clearing failed state for component Aanderaa_O2
2019-04-10T15:00:21.647Z,1554908421.647 [Aanderaa_O2] No Fault, FailCount= 1
2019-04-10T15:00:22.019Z,1554908422.019 [BR_Ping1D](INFO): Starting
2019-04-10T15:00:22.019Z,1554908422.019 [BR_Ping1D](INFO): readConfig
2019-04-10T15:00:22.020Z,1554908422.020 [BR_Ping1D](INFO): startup: 2
2019-04-10T15:00:22.020Z,1554908422.020 [BR_Ping1D](INFO): UART waiting for response
2019-04-10T15:00:22.020Z,1554908422.020 [BR_Ping1D](INFO): elapsed 2.8298
2019-04-10T15:00:22.020Z,1554908422.020 [BR_Ping1D](INFO): timeout 5.0000
2019-04-10T15:00:22.021Z,1554908422.021 [BR_Ping1D](INFO): No UART data
2019-04-10T15:00:22.021Z,1554908422.021 [BR_Ping1D](INFO): received UART packets: 0
2019-04-10T15:00:22.021Z,1554908422.021 [BR_Ping1D](INFO): not all values verified yet
2019-04-10T15:00:22.435Z,1554908422.435 [BR_Ping1D](INFO): Starting
2019-04-10T15:00:22.435Z,1554908422.435 [BR_Ping1D](INFO): readConfig
2019-04-10T15:00:22.435Z,1554908422.435 [BR_Ping1D](INFO): startup: 2
2019-04-10T15:00:22.435Z,1554908422.435 [BR_Ping1D](INFO): UART waiting for response
2019-04-10T15:00:22.436Z,1554908422.436 [BR_Ping1D](INFO): elapsed 3.2452
2019-04-10T15:00:22.436Z,1554908422.436 [BR_Ping1D](INFO): timeout 5.0000
2019-04-10T15:00:22.436Z,1554908422.436 [BR_Ping1D](INFO): No UART data
2019-04-10T15:00:22.436Z,1554908422.436 [BR_Ping1D](INFO): received UART packets: 0
2019-04-10T15:00:22.436Z,1554908422.436 [BR_Ping1D](INFO): not all values verified yet
2019-04-10T15:00:22.782Z,1554908422.782 [CTD_Seabird](FAULT): Failed to initialize within timeout.
2019-04-10T15:00:22.782Z,1554908422.782 [CTD_Seabird] Communications Fault, FailCount= 1
2019-04-10T15:00:22.782Z,1554908422.782 [CTD_Seabird](ERROR): Communications Fault
2019-04-10T15:00:22.825Z,1554908422.825 [BR_Ping1D](INFO): Starting
2019-04-10T15:00:22.825Z,1554908422.825 [BR_Ping1D](INFO): readConfig
2019-04-10T15:00:22.826Z,1554908422.826 [BR_Ping1