2019-04-09T22:53:40.810Z,1554850420.810 [Supervisor](DEBUG): Initializing supervisor.
2019-04-09T22:53:40.813Z,1554850420.813 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2019-04-09T22:53:40.813Z,1554850420.813 [SyncHandler](INFO): Protected caller Thread ID is 7422
2019-04-09T22:53:40.814Z,1554850420.814 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2019-04-09T22:53:40.815Z,1554850420.815 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2019-04-09T22:53:40.815Z,1554850420.815 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 7423
2019-04-09T22:53:40.819Z,1554850420.819 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2019-04-09T22:53:40.831Z,1554850420.831 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2019-04-09T22:53:40.832Z,1554850420.832 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2019-04-09T22:53:40.832Z,1554850420.832 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 7424
2019-04-09T22:53:40.833Z,1554850420.833 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2019-04-09T22:53:40.834Z,1554850420.834 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2019-04-09T22:53:40.834Z,1554850420.834 [logger ThreadHandler](INFO): Protected caller Thread ID is 7425
2019-04-09T22:53:40.836Z,1554850420.836 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2019-04-09T22:53:40.837Z,1554850420.837 [Supervisor](INFO): Looking for Config files in directory: Config/
2019-04-09T22:53:40.838Z,1554850420.838 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2019-04-09T22:53:40.935Z,1554850420.935 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2019-04-09T22:53:40.935Z,1554850420.935 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2019-04-09T22:53:41.138Z,1554850421.138 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2019-04-09T22:53:41.139Z,1554850421.139 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2019-04-09T22:53:41.276Z,1554850421.276 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2019-04-09T22:53:41.277Z,1554850421.277 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2019-04-09T22:53:41.746Z,1554850421.746 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2019-04-09T22:53:41.747Z,1554850421.747 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2019-04-09T22:53:42.191Z,1554850422.191 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2019-04-09T22:53:42.191Z,1554850422.191 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2019-04-09T22:53:42.661Z,1554850422.661 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2019-04-09T22:53:42.661Z,1554850422.661 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2019-04-09T22:53:42.969Z,1554850422.969 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2019-04-09T22:53:42.970Z,1554850422.970 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2019-04-09T22:53:43.303Z,1554850423.303 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2019-04-09T22:53:43.304Z,1554850423.304 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2019-04-09T22:53:43.700Z,1554850423.700 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2019-04-09T22:53:43.701Z,1554850423.701 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2019-04-09T22:53:43.852Z,1554850423.852 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2019-04-09T22:53:43.852Z,1554850423.852 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2019-04-09T22:53:43.959Z,1554850423.959 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2019-04-09T22:53:43.959Z,1554850423.959 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2019-04-09T22:53:44.041Z,1554850424.041 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2019-04-09T22:53:44.224Z,1554850424.224 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2019-04-09T22:53:44.225Z,1554850424.225 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2019-04-09T22:53:44.905Z,1554850424.905 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2019-04-09T22:53:44.906Z,1554850424.906 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2019-04-09T22:53:45.126Z,1554850425.126 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2019-04-09T22:53:45.128Z,1554850425.128 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/
2019-04-09T22:53:45.129Z,1554850425.129 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg
2019-04-09T22:53:45.213Z,1554850425.213 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg
2019-04-09T22:53:45.447Z,1554850425.447 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2019-04-09T22:53:45.447Z,1554850425.447 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg
2019-04-09T22:53:45.544Z,1554850425.544 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg
2019-04-09T22:53:45.720Z,1554850425.720 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg
2019-04-09T22:53:45.936Z,1554850425.936 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg
2019-04-09T22:53:46.022Z,1554850426.022 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg
2019-04-09T22:53:46.121Z,1554850426.121 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg
2019-04-09T22:53:46.216Z,1554850426.216 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg
2019-04-09T22:53:46.369Z,1554850426.369 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg
2019-04-09T22:53:46.475Z,1554850426.475 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg
2019-04-09T22:53:46.575Z,1554850426.575 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/root/
2019-04-09T22:53:46.576Z,1554850426.576 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2019-04-09T22:53:46.580Z,1554850426.580 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2019-04-09T22:53:46.677Z,1554850426.677 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2019-04-09T22:53:46.678Z,1554850426.678 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2019-04-09T22:53:46.801Z,1554850426.801 [BuoyancyServo] Loaded
2019-04-09T22:53:46.801Z,1554850426.801 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2019-04-09T22:53:46.816Z,1554850426.816 [ElevatorServo] Loaded
2019-04-09T22:53:46.816Z,1554850426.816 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2019-04-09T22:53:46.831Z,1554850426.831 [MassServo] Loaded
2019-04-09T22:53:46.832Z,1554850426.832 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2019-04-09T22:53:46.847Z,1554850426.847 [RudderServo] Loaded
2019-04-09T22:53:46.847Z,1554850426.847 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2019-04-09T22:53:46.861Z,1554850426.861 [ThrusterServo] Loaded
2019-04-09T22:53:46.861Z,1554850426.861 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2019-04-09T22:53:46.862Z,1554850426.862 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2019-04-09T22:53:46.862Z,1554850426.862 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2019-04-09T22:53:46.996Z,1554850426.996 [SBIT](DEBUG): Construct Startup Built In Test.
2019-04-09T22:53:47.024Z,1554850427.024 [SBIT] Loaded
2019-04-09T22:53:47.025Z,1554850427.025 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2019-04-09T22:53:47.025Z,1554850427.025 [IBIT](DEBUG): Construct Initiated Built In Test.
2019-04-09T22:53:47.053Z,1554850427.053 [IBIT] Loaded
2019-04-09T22:53:47.054Z,1554850427.054 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2019-04-09T22:53:47.057Z,1554850427.057 [CBIT](DEBUG): Construct Continuous Built In Test.
2019-04-09T22:53:47.442Z,1554850427.442 [CBIT] Loaded
2019-04-09T22:53:47.442Z,1554850427.442 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2019-04-09T22:53:47.443Z,1554850427.443 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2019-04-09T22:53:47.443Z,1554850427.443 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2019-04-09T22:53:47.626Z,1554850427.626 [Aanderaa_O2] Loaded
2019-04-09T22:53:47.627Z,1554850427.627 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2019-04-09T22:53:47.636Z,1554850427.636 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_density
2019-04-09T22:53:47.641Z,1554850427.641 [CTD_Seabird](INFO): created writer for : sea_water_density
2019-04-09T22:53:47.643Z,1554850427.643 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): depth
2019-04-09T22:53:47.648Z,1554850427.648 [CTD_Seabird](INFO): created writer for : depth
2019-04-09T22:53:47.648Z,1554850427.648 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_pressure
2019-04-09T22:53:47.654Z,1554850427.654 [CTD_Seabird](INFO): created writer for : sea_water_pressure
2019-04-09T22:53:47.654Z,1554850427.654 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_salinity
2019-04-09T22:53:47.659Z,1554850427.659 [CTD_Seabird](INFO): created writer for : sea_water_salinity
2019-04-09T22:53:47.660Z,1554850427.660 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_temperature
2019-04-09T22:53:47.665Z,1554850427.665 [CTD_Seabird](INFO): created writer for : sea_water_temperature
2019-04-09T22:53:47.666Z,1554850427.666 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_electrical_conductivity
2019-04-09T22:53:47.671Z,1554850427.671 [CTD_Seabird](INFO): created writer for : sea_water_electrical_conductivity
2019-04-09T22:53:47.672Z,1554850427.672 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): speed_of_sound_in_sea_water
2019-04-09T22:53:47.677Z,1554850427.677 [CTD_Seabird](INFO): created writer for : speed_of_sound_in_sea_water
2019-04-09T22:53:47.703Z,1554850427.703 [CTD_Seabird] Loaded
2019-04-09T22:53:47.704Z,1554850427.704 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2019-04-09T22:53:47.705Z,1554850427.705 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 406654E0
2019-04-09T22:53:47.705Z,1554850427.705 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 7504
2019-04-09T22:53:47.731Z,1554850427.731 [ESPComponent] Loaded
2019-04-09T22:53:47.731Z,1554850427.731 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2019-04-09T22:53:47.745Z,1554850427.745 [PAR_Licor] Loaded
2019-04-09T22:53:47.745Z,1554850427.745 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2019-04-09T22:53:47.792Z,1554850427.792 [WetLabsBB2FL] Loaded
2019-04-09T22:53:47.793Z,1554850427.793 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2019-04-09T22:53:47.794Z,1554850427.794 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 406954E0
2019-04-09T22:53:47.794Z,1554850427.794 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 7505
2019-04-09T22:53:47.795Z,1554850427.795 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2019-04-09T22:53:47.795Z,1554850427.795 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2019-04-09T22:53:47.836Z,1554850427.836 [DepthRateCalculator] Loaded
2019-04-09T22:53:47.836Z,1554850427.836 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2019-04-09T22:53:47.842Z,1554850427.842 [PitchRateCalculator] Loaded
2019-04-09T22:53:47.842Z,1554850427.842 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2019-04-09T22:53:47.858Z,1554850427.858 [SpeedCalculator] Loaded
2019-04-09T22:53:47.858Z,1554850427.858 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2019-04-09T22:53:47.879Z,1554850427.879 [TempGradientCalculator] Loaded
2019-04-09T22:53:47.880Z,1554850427.880 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2019-04-09T22:53:47.886Z,1554850427.886 [YawRateCalculator] Loaded
2019-04-09T22:53:47.886Z,1554850427.886 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2019-04-09T22:53:47.918Z,1554850427.918 [ElevatorOffsetCalculator] Loaded
2019-04-09T22:53:47.919Z,1554850427.919 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2019-04-09T22:53:47.919Z,1554850427.919 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2019-04-09T22:53:47.920Z,1554850427.920 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2019-04-09T22:53:47.946Z,1554850427.946 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2019-04-09T22:53:47.947Z,1554850427.947 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2019-04-09T22:53:48.049Z,1554850428.049 [DeadReckonUsingMultipleVelocitySources] Loaded
2019-04-09T22:53:48.049Z,1554850428.049 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2019-04-09T22:53:48.109Z,1554850428.109 [DeadReckonUsingSpeedCalculator] Loaded
2019-04-09T22:53:48.109Z,1554850428.109 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2019-04-09T22:53:48.168Z,1554850428.168 [DeadReckonWithRespectToSeafloor] Loaded
2019-04-09T22:53:48.169Z,1554850428.169 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonWithRespectToSeafloor" handled in the control thread.
2019-04-09T22:53:48.189Z,1554850428.189 [NavChart] Loaded
2019-04-09T22:53:48.189Z,1554850428.189 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2019-04-09T22:53:48.193Z,1554850428.193 [UniversalFixResidualReporter] Loaded
2019-04-09T22:53:48.194Z,1554850428.194 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2019-04-09T22:53:48.194Z,1554850428.194 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2019-04-09T22:53:48.195Z,1554850428.195 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2019-04-09T22:53:48.502Z,1554850428.502 [AcousticModem_Benthos_ATM900] Loaded
2019-04-09T22:53:48.503Z,1554850428.503 [ComponentRegistry](DEBUG): SyncComponent "AcousticModem_Benthos_ATM900" handled in the control thread.
2019-04-09T22:53:48.575Z,1554850428.575 [DataOverHttps] Loaded
2019-04-09T22:53:48.575Z,1554850428.575 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2019-04-09T22:53:48.576Z,1554850428.576 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 409714E0
2019-04-09T22:53:48.576Z,1554850428.576 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 7506
2019-04-09T22:53:48.590Z,1554850428.590 [Depth_Keller] Loaded
2019-04-09T22:53:48.590Z,1554850428.590 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2019-04-09T22:53:48.681Z,1554850428.681 [NAL9602] Loaded
2019-04-09T22:53:48.681Z,1554850428.681 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2019-04-09T22:53:48.687Z,1554850428.687 [Onboard] Loaded
2019-04-09T22:53:48.687Z,1554850428.687 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2019-04-09T22:53:48.690Z,1554850428.690 [Radio_Surface] Loaded
2019-04-09T22:53:48.691Z,1554850428.691 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2019-04-09T22:53:48.692Z,1554850428.692 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409A14E0
2019-04-09T22:53:48.692Z,1554850428.692 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 7507
2019-04-09T22:53:50.631Z,1554850430.631 [BPC1] Loaded
2019-04-09T22:53:50.632Z,1554850430.632 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2019-04-09T22:53:50.662Z,1554850430.662 [BR_Ping1D](CRITICAL): No configuration setting for: BR_Ping1D.minrange
2019-04-09T22:53:50.664Z,1554850430.664 [BR_Ping1D](CRITICAL): No configuration setting for: BR_Ping1D.maxrange
2019-04-09T22:53:50.666Z,1554850430.666 [BR_Ping1D](CRITICAL): No configuration setting for: BR_Ping1D.soundspeed
2019-04-09T22:53:50.668Z,1554850430.668 [BR_Ping1D](CRITICAL): No configuration setting for: BR_Ping1D.automode
2019-04-09T22:53:50.670Z,1554850430.670 [BR_Ping1D](CRITICAL): No configuration setting for: BR_Ping1D.gainindex
2019-04-09T22:53:50.672Z,1554850430.672 [BR_Ping1D](CRITICAL): No configuration setting for: BR_Ping1D.minconfidence
2019-04-09T22:53:50.674Z,1554850430.674 [BR_Ping1D](CRITICAL): No configuration setting for: BR_Ping1D.pingenable
2019-04-09T22:53:50.677Z,1554850430.677 [BR_Ping1D] Loaded
2019-04-09T22:53:50.677Z,1554850430.677 [ComponentRegistry](DEBUG): SyncComponent "BR_Ping1D" handled in the control thread.
2019-04-09T22:53:50.677Z,1554850430.677 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2019-04-09T22:53:50.678Z,1554850430.678 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2019-04-09T22:53:50.741Z,1554850430.741 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2019-04-09T22:53:50.741Z,1554850430.741 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2019-04-09T22:53:50.807Z,1554850430.807 [VerticalControl](DEBUG): Construct VerticalControl.
2019-04-09T22:53:50.891Z,1554850430.891 [VerticalControl] Loaded
2019-04-09T22:53:50.891Z,1554850430.891 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2019-04-09T22:53:50.892Z,1554850430.892 [HorizontalControl](DEBUG): Construct HorizontalControl.
2019-04-09T22:53:50.949Z,1554850430.949 [HorizontalControl] Loaded
2019-04-09T22:53:50.949Z,1554850430.949 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2019-04-09T22:53:50.950Z,1554850430.950 [SpeedControl](DEBUG): Construct SpeedControl.
2019-04-09T22:53:50.951Z,1554850430.951 [SpeedControl] Loaded
2019-04-09T22:53:50.952Z,1554850430.952 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2019-04-09T22:53:50.952Z,1554850430.952 [LoopControl](DEBUG): Construct LoopControl.
2019-04-09T22:53:50.953Z,1554850430.953 [LoopControl] Loaded
2019-04-09T22:53:50.953Z,1554850430.953 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2019-04-09T22:53:50.954Z,1554850430.954 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2019-04-09T22:53:50.954Z,1554850430.954 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2019-04-09T22:53:50.968Z,1554850430.968 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2019-04-09T22:53:50.968Z,1554850430.968 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2019-04-09T22:53:51.242Z,1554850431.242 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2019-04-09T22:53:51.245Z,1554850431.245 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2019-04-09T22:53:51.246Z,1554850431.246 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2019-04-09T22:53:51.253Z,1554850431.253 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2019-04-09T22:53:51.254Z,1554850431.254 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40ACE4E0
2019-04-09T22:53:51.254Z,1554850431.254 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 7508
2019-04-09T22:53:51.259Z,1554850431.259 [Supervisor](INFO): Main Thread ID is 4347
2019-04-09T22:53:51.259Z,1554850431.259 [Supervisor](DEBUG): Running supervisor.
2019-04-09T22:53:51.260Z,1554850431.260 [CommandLine ThreadHandler](INFO): Handler Thread ID is 7509
2019-04-09T22:53:51.262Z,1554850431.262 [controlThread ThreadHandler](INFO): Handler Thread ID is 7510
2019-04-09T22:53:51.263Z,1554850431.263 [controlThread](DEBUG): Initializing ControlThread
2019-04-09T22:53:51.265Z,1554850431.265 [SBIT](INFO): Initialize SBIT Component.
2019-04-09T22:53:51.265Z,1554850431.265 [SBIT](IMPORTANT): git: 2019-03-18-31-ge98d5dc
2019-04-09T22:53:51.265Z,1554850431.265 [SBIT](INFO): git hash: e98d5dc50cbc39e402f19b9946ff4dc0776c8725
2019-04-09T22:53:51.266Z,1554850431.266 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2019-04-09T22:53:51.267Z,1554850431.267 [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-09T22:53:51.268Z,1554850431.268 [SBIT](INFO): Beginning SBIT in 24.000000 seconds.
2019-04-09T22:53:51.269Z,1554850431.269 [IBIT](INFO): Initialize IBIT Component.
2019-04-09T22:53:51.270Z,1554850431.270 [CBIT](DEBUG): Initialize CBIT Component.
2019-04-09T22:53:51.271Z,1554850431.271 [logger ThreadHandler](INFO): Handler Thread ID is 7511
2019-04-09T22:53:51.282Z,1554850431.282 [CBIT](DEBUG): Initialized mux pins.
2019-04-09T22:53:51.282Z,1554850431.282 [CBIT](DEBUG): Initializing the watchdog timer.
2019-04-09T22:53:51.290Z,1554850431.290 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 7512
2019-04-09T22:53:51.291Z,1554850431.291 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2019-04-09T22:53:51.295Z,1554850431.295 [CTD_Seabird](INFO): Opening uart, block timeout 10ths=20
2019-04-09T22:53:51.296Z,1554850431.296 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 7514
2019-04-09T22:53:51.297Z,1554850431.297 [WetLabsBB2FL](INFO): Powering down
2019-04-09T22:53:51.306Z,1554850431.306 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2019-04-09T22:53:51.306Z,1554850431.306 [CBIT](DEBUG): Initializing heartbeat.
2019-04-09T22:53:51.326Z,1554850431.326 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 7515
2019-04-09T22:53:51.327Z,1554850431.327 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2019-04-09T22:53:51.336Z,1554850431.336 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 7516
2019-04-09T22:53:51.354Z,1554850431.354 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 7517
2019-04-09T22:53:51.357Z,1554850431.357 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2019-04-09T22:53:51.357Z,1554850431.357 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2019-04-09T22:53:51.358Z,1554850431.358 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2019-04-09T22:53:51.358Z,1554850431.358 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2019-04-09T22:53:51.358Z,1554850431.358 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2019-04-09T22:53:51.358Z,1554850431.358 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2019-04-09T22:53:51.359Z,1554850431.359 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2019-04-09T22:53:51.359Z,1554850431.359 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2019-04-09T22:53:51.359Z,1554850431.359 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2019-04-09T22:53:51.359Z,1554850431.359 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2019-04-09T22:53:51.359Z,1554850431.359 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2019-04-09T22:53:51.359Z,1554850431.359 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2019-04-09T22:53:51.360Z,1554850431.360 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2019-04-09T22:53:51.360Z,1554850431.360 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2019-04-09T22:53:51.360Z,1554850431.360 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2019-04-09T22:53:51.360Z,1554850431.360 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2019-04-09T22:53:51.378Z,1554850431.378 [CBIT](DEBUG): Deactivating GF circuits.
2019-04-09T22:53:51.378Z,1554850431.378 [CBIT](DEBUG): Deactivating emergency mode.
2019-04-09T22:53:51.414Z,1554850431.414 [CBIT](DEBUG): Backplane powered.
2019-04-09T22:53:51.418Z,1554850431.418 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2019-04-09T22:53:51.419Z,1554850431.419 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2019-04-09T22:53:51.419Z,1554850431.419 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2019-04-09T22:53:51.419Z,1554850431.419 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2019-04-09T22:53:51.420Z,1554850431.420 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2019-04-09T22:53:51.420Z,1554850431.420 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2019-04-09T22:53:51.421Z,1554850431.421 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2019-04-09T22:53:51.422Z,1554850431.422 [NavChart](DEBUG): Initialize NavChart Navigation.
2019-04-09T22:53:51.423Z,1554850431.423 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2019-04-09T22:53:51.427Z,1554850431.427 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2019-04-09T22:53:51.429Z,1554850431.429 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2019-04-09T22:53:51.430Z,1554850431.430 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2019-04-09T22:53:51.430Z,1554850431.430 [LoopControl](DEBUG): Initialize LoopControlComponent.
2019-04-09T22:53:51.431Z,1554850431.431 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2019-04-09T22:53:51.453Z,1554850431.453 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2019-04-09T22:53:51.489Z,1554850431.489 [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-09T22:53:51.490Z,1554850431.490 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2019-04-09T22:53:51.580Z,1554850431.580 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2019-04-09T22:53:51.581Z,1554850431.581 [Default:A.Wait](DEBUG): Construct Wait.
2019-04-09T22:53:51.599Z,1554850431.599 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2019-04-09T22:53:51.618Z,1554850431.618 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2019-04-09T22:53:51.636Z,1554850431.636 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2019-04-09T22:53:51.642Z,1554850431.642 [Default:E.Execute](DEBUG): Construct Execute.
2019-04-09T22:53:51.665Z,1554850431.665 [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-09T22:53:51.670Z,1554850431.670 [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-09T22:53:51.699Z,1554850431.699 [ESPComponent](INFO): powering down ESP
2019-04-09T22:53:51.738Z,1554850431.738 [Radio_Surface](INFO): Powering up
2019-04-09T22:53:52.162Z,1554850432.162 [PAR_Licor](INFO): A/D timeout, 9 tries over 151 ms

2019-04-09T22:53:52.163Z,1554850432.163 [PAR_Licor] Data Fault, FailCount= 1
2019-04-09T22:53:52.163Z,1554850432.163 [PAR_Licor](ERROR): Data Fault
2019-04-09T22:53:52.163Z,1554850432.163 [AcousticModem_Benthos_ATM900](INFO): Powering up
2019-04-09T22:53:52.164Z,1554850432.164 [AcousticModem_Benthos_ATM900](DEBUG): Initializing AcousticModem_Benthos_ATM900.
2019-04-09T22:53:52.187Z,1554850432.187 [Depth_Keller](ERROR): Pressure reading out of range: 1895.684326 decibar
2019-04-09T22:53:52.254Z,1554850432.254 [DepthRateCalculator](ERROR): Depth measurement is not active
2019-04-09T22:53:52.297Z,1554850432.297 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2019-04-09T22:53:52.303Z,1554850432.303 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2019-04-09T22:53:52.304Z,1554850432.304 [ElevatorServo](DEBUG): Initializing EZServoServo.
2019-04-09T22:53:52.310Z,1554850432.310 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2019-04-09T22:53:52.311Z,1554850432.311 [MassServo](DEBUG): Initializing EZServoServo.
2019-04-09T22:53:52.318Z,1554850432.318 [MassServo](DEBUG): Initializing MassServo.
2019-04-09T22:53:52.319Z,1554850432.319 [RudderServo](DEBUG): Initializing EZServoServo.
2019-04-09T22:53:52.327Z,1554850432.327 [RudderServo](DEBUG): Initializing RudderServo.
2019-04-09T22:53:52.328Z,1554850432.328 [ThrusterServo](DEBUG): Initializing EZServoServo.
2019-04-09T22:53:52.334Z,1554850432.334 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2019-04-09T22:53:52.337Z,1554850432.337 [CommandLine](FAULT): Scheduling is paused
2019-04-09T22:53:52.337Z,1554850432.337 [CBIT](INFO): Critical error at 20190409T225350
2019-04-09T22:53:52.337Z,1554850432.337 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2019-04-09T22:53:52.341Z,1554850432.341 [CBIT](ERROR): Data Fault in component: PAR_Licor
2019-04-09T22:53:52.342Z,1554850432.342 [CBIT](INFO): Clearing failed state for component PAR_Licor
2019-04-09T22:53:52.342Z,1554850432.342 [PAR_Licor] No Fault, FailCount= 1
2019-04-09T22:53:52.882Z,1554850432.882 [PAR_Licor](INFO): A/D timeout, 8 tries over 130 ms

2019-04-09T22:53:52.882Z,1554850432.882 [PAR_Licor] Data Fault, FailCount= 2
2019-04-09T22:53:52.882Z,1554850432.882 [PAR_Licor](ERROR): Data Fault
2019-04-09T22:53:52.915Z,1554850432.915 [BR_Ping1D](INFO): startup: 0
2019-04-09T22:53:52.915Z,1554850432.915 [BR_Ping1D](INFO): UART setting parameters ...
2019-04-09T22:53:52.926Z,1554850432.926 [BR_Ping1D](INFO): sending request for Ping Interval: 500
2019-04-09T22:53:52.926Z,1554850432.926 [BR_Ping1D](INFO): data F401
2019-04-09T22:53:52.926Z,1554850432.926 [BR_Ping1D](INFO): test: ô

2019-04-09T22:53:52.927Z,1554850432.927 [BR_Ping1D](INFO): 42520200EC030000F4017A02
2019-04-09T22:53:52.927Z,1554850432.927 [BR_Ping1D](INFO): sending request for Auto Mode: 1
2019-04-09T22:53:52.927Z,1554850432.927 [BR_Ping1D](INFO): 42520100EB030000840115
2019-04-09T22:53:52.927Z,1554850432.927 [BR_Ping1D](INFO): sending request for Soundspeed: 1500000
2019-04-09T22:53:52.928Z,1554850432.928 [BR_Ping1D](INFO): 42520400EA03000060E31600DE02
2019-04-09T22:53:52.928Z,1554850432.928 [BR_Ping1D](INFO): sending request for Ping Enable: 1
2019-04-09T22:53:52.928Z,1554850432.928 [BR_Ping1D](INFO): 42520100EE030000870115
2019-04-09T22:53:53.302Z,1554850433.302 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2019-04-09T22:53:53.302Z,1554850433.302 [RudderServo](FAULT): Rudder failed to initialize
2019-04-09T22:53:53.302Z,1554850433.302 [RudderServo] Communications Fault, FailCount= 1
2019-04-09T22:53:53.302Z,1554850433.302 [RudderServo](ERROR): Communications Fault
2019-04-09T22:53:53.413Z,1554850433.413 [CBIT](ERROR): Communications Fault in component: RudderServo
2019-04-09T22:53:53.414Z,1554850433.414 [CBIT](ERROR): Data Fault in component: PAR_Licor
2019-04-09T22:53:53.414Z,1554850433.414 [CBIT](INFO): Clearing failed state for component PAR_Licor
2019-04-09T22:53:53.414Z,1554850433.414 [PAR_Licor] No Fault, FailCount= 2
2019-04-09T22:53:53.457Z,1554850433.457 [BR_Ping1D](INFO): Starting
2019-04-09T22:53:53.457Z,1554850433.457 [BR_Ping1D](INFO): readConfig
2019-04-09T22:53:53.458Z,1554850433.458 [BR_Ping1D](INFO): startup: 1
2019-04-09T22:53:53.458Z,1554850433.458 [BR_Ping1D](INFO): UART requesting status
2019-04-09T22:53:53.458Z,1554850433.458 [BR_Ping1D](INFO): 42520000BA0400005201
2019-04-09T22:53:53.466Z,1554850433.466 [BR_Ping1D](INFO): 42520000BF0400005701
2019-04-09T22:53:53.474Z,1554850433.474 [BR_Ping1D](INFO): 42520000B30400004B01
2019-04-09T22:53:53.625Z,1554850433.625 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-04-09T22:53:53.625Z,1554850433.625 [RudderServo](INFO): Powering down
2019-04-09T22:53:53.861Z,1554850433.861 [BR_Ping1D](INFO): Starting
2019-04-09T22:53:53.861Z,1554850433.861 [BR_Ping1D](INFO): readConfig
2019-04-09T22:53:53.862Z,1554850433.862 [BR_Ping1D](INFO): startup: 2
2019-04-09T22:53:53.862Z,1554850433.862 [BR_Ping1D](INFO): UART waiting for response
2019-04-09T22:53:53.862Z,1554850433.862 [BR_Ping1D](INFO): elapsed 0.9471
2019-04-09T22:53:53.863Z,1554850433.863 [BR_Ping1D](INFO): timeout 5.0000
2019-04-09T22:53:53.863Z,1554850433.863 [BR_Ping1D](INFO): No UART data
2019-04-09T22:53:53.863Z,1554850433.863 [BR_Ping1D](INFO): received UART packets: 0
2019-04-09T22:53:53.863Z,1554850433.863 [BR_Ping1D](INFO): not all values verified yet
2019-04-09T22:53:54.362Z,1554850434.362 [PAR_Licor](INFO): A/D timeout, 9 tries over 135 ms

2019-04-09T22:53:54.362Z,1554850434.362 [PAR_Licor] Data Fault, FailCount= 1
2019-04-09T22:53:54.362Z,1554850434.362 [PAR_Licor](ERROR): Data Fault
2019-04-09T22:53:54.408Z,1554850434.408 [BR_Ping1D](INFO): Starting
2019-04-09T22:53:54.408Z,1554850434.408 [BR_Ping1D](INFO): readConfig
2019-04-09T22:53:54.408Z,1554850434.408 [BR_Ping1D](INFO): startup: 2
2019-04-09T22:53:54.408Z,1554850434.408 [BR_Ping1D](INFO): UART waiting for response
2019-04-09T22:53:54.409Z,1554850434.409 [BR_Ping1D](INFO): elapsed 1.4934
2019-04-09T22:53:54.409Z,1554850434.409 [BR_Ping1D](INFO): timeout 5.0000
2019-04-09T22:53:54.409Z,1554850434.409 [BR_Ping1D](INFO): No UART data
2019-04-09T22:53:54.409Z,1554850434.409 [BR_Ping1D](INFO): received UART packets: 0
2019-04-09T22:53:54.409Z,1554850434.409 [BR_Ping1D](INFO): not all values verified yet
2019-04-09T22:53:54.431Z,1554850434.431 [RudderServo](DEBUG): Initializing EZServoServo.
2019-04-09T22:53:54.551Z,1554850434.551 [RudderServo](DEBUG): Initializing RudderServo.
2019-04-09T22:53:54.555Z,1554850434.555 [CBIT](INFO): Clearing failed state for component RudderServo
2019-04-09T22:53:54.555Z,1554850434.555 [RudderServo] No Fault, FailCount= 1
2019-04-09T22:53:54.555Z,1554850434.555 [CBIT](ERROR): Data Fault in component: PAR_Licor
2019-04-09T22:53:54.556Z,1554850434.556 [CBIT](INFO): Clearing failed state for component PAR_Licor
2019-04-09T22:53:54.556Z,1554850434.556 [PAR_Licor] No Fault, FailCount= 1
2019-04-09T22:53:54.650Z,1554850434.650 [BR_Ping1D](INFO): Starting
2019-04-09T22:53:54.650Z,1554850434.650 [BR_Ping1D](INFO): readConfig
2019-04-09T22:53:54.650Z,1554850434.650 [BR_Ping1D](INFO): startup: 2
2019-04-09T22:53:54.650Z,1554850434.650 [BR_Ping1D](INFO): UART waiting for response
2019-04-09T22:53:54.651Z,1554850434.651 [BR_Ping1D](INFO): elapsed 1.7354
2019-04-09T22:53:54.651Z,1554850434.651 [BR_Ping1D](INFO): timeout 5.0000
2019-04-09T22:53:54.651Z,1554850434.651 [BR_Ping1D](INFO): No UART data
2019-04-09T22:53:54.651Z,1554850434.651 [BR_Ping1D](INFO): received UART packets: 0
2019-04-09T22:53:54.651Z,1554850434.651 [BR_Ping1D](INFO): not all values verified yet
2019-04-09T22:53:55.174Z,1554850435.174 [PAR_Licor](INFO): A/D timeout, 8 tries over 138 ms

2019-04-09T22:53:55.174Z,1554850435.174 [PAR_Licor] Data Fault, FailCount= 2
2019-04-09T22:53:55.174Z,1554850435.174 [PAR_Licor](ERROR): Data Fault
2019-04-09T22:53:55.215Z,1554850435.215 [BR_Ping1D](INFO): Starting
2019-04-09T22:53:55.215Z,1554850435.215 [BR_Ping1D](INFO): readConfig
2019-04-09T22:53:55.215Z,1554850435.215 [BR_Ping1D](INFO): startup: 2
2019-04-09T22:53:55.215Z,1554850435.215 [BR_Ping1D](INFO): UART waiting for response
2019-04-09T22:53:55.215Z,1554850435.215 [BR_Ping1D](INFO): elapsed 2.3002
2019-04-09T22:53:55.216Z,1554850435.216 [BR_Ping1D](INFO): timeout 5.0000
2019-04-09T22:53:55.216Z,1554850435.216 [BR_Ping1D](INFO): No UART data
2019-04-09T22:53:55.216Z,1554850435.216 [BR_Ping1D](INFO): received UART packets: 0
2019-04-09T22:53:55.216Z,1554850435.216 [BR_Ping1D](INFO): not all values verified yet
2019-04-09T22:53:55.390Z,1554850435.390 [CBIT](ERROR): Data Fault in component: PAR_Licor
2019-04-09T22:53:55.390Z,1554850435.390 [CBIT](INFO): Clearing failed state for component PAR_Licor
2019-04-09T22:53:55.390Z,1554850435.390 [PAR_Licor] No Fault, FailCount= 2
2019-04-09T22:53:55.462Z,1554850435.462 [BR_Ping1D](INFO): Starting
2019-04-09T22:53:55.462Z,1554850435.462 [BR_Ping1D](INFO): readConfig
2019-04-09T22:53:55.462Z,1554850435.462 [BR_Ping1D](INFO): startup: 2
2019-04-09T22:53:55.463Z,1554850435.463 [BR_Ping1D](INFO): UART waiting for response
2019-04-09T22:53:55.463Z,1554850435.463 [BR_Ping1D](INFO): elapsed 2.5476
2019-04-09T22:53:55.463Z,1554850435.463 [BR_Ping1D](INFO): timeout 5.0000
2019-04-09T22:53:55.463Z,1554850435.463 [BR_Ping1D](INFO): No UART data
2019-04-09T22:53:55.463Z,1554850435.463 [BR_Ping1D](INFO): received UART packets: 0
2019-04-09T22:53:55.464Z,1554850435.464 [BR_Ping1D](INFO): not all values verified yet
2019-04-09T22:53:55.982Z,1554850435.982 [PAR_Licor](INFO): A/D timeout, 9 tries over 137 ms

2019-04-09T22:53:55.982Z,1554850435.982 [PAR_Licor] Data Fault, FailCount= 3
2019-04-09T22:53:55.982Z,1554850435.982 [PAR_Licor](ERROR): Data Fault
2019-04-09T22:53:56.002Z,1554850436.002 [BR_Ping1D](INFO): Starting
2019-04-09T22:53:56.002Z,1554850436.002 [BR_Ping1D](INFO): readConfig
2019-04-09T22:53:56.002Z,1554850436.002 [BR_Ping1D](INFO): startup: 2
2019-04-09T22:53:56.002Z,1554850436.002 [BR_Ping1D](INFO): UART waiting for response
2019-04-09T22:53:56.003Z,1554850436.003 [BR_Ping1D](INFO): elapsed 3.0874
2019-04-09T22:53:56.003Z,1554850436.003 [BR_Ping1D](INFO): timeout 5.0000
2019-04-09T22:53:56.003Z,1554850436.003 [BR_Ping1D](INFO): No UART data
2019-04-09T22:53:56.003Z,1554850436.003 [BR_Ping1D](INFO): received UART packets: 0
2019-04-09T22:53:56.003Z,1554850436.003 [BR_Ping1D](INFO): not all values verified yet
2019-04-09T22:53:56.274Z,1554850436.274 [CBIT](ERROR): Data Fault in component: PAR_Licor
2019-04-09T22:53:56.275Z,1554850436.275 [CBIT](CRITICAL): Data Fault in component: PAR_Licor
2019-04-09T22:53:56.324Z,1554850436.324 [BR_Ping1D](INFO): Starting
2019-04-09T22:53:56.324Z,1554850436.324 [BR_Ping1D](INFO): readConfig
2019-04-09T22:53:56.324Z,1554850436.324 [BR_Ping1D](INFO): startup: 2
2019-04-09T22:53:56.324Z,1554850436.324 [BR_Ping1D](INFO): UART waiting for response
2019-04-09T22:53:56.324Z,1554850436.324 [BR_Ping1D](INFO): elapsed 3.4093
2019-04-09T22:53:56.325Z,1554850436.325 [BR_Ping1D](INFO): timeout 5.0000
2019-04-09T22:53:56.325Z,1554850436.325 [BR_Ping1D](INFO): No UART data
2019-04-09T22:53:56.325Z,1554850436.325 [BR_Ping1D](INFO): received UART packets: 0
2019-04-09T22:53:56.325Z,1554850436.325 [BR_Ping1D](INFO): not all values verified yet
2019-04-09T22:53:56.400Z,1554850436.400 [CBIT](INFO): Critical error at 20190409T225356
2019-04-09T22:53:56.702Z,1554850436.702 [BR_Ping1D](INFO): Starting
2019-04-09T22:53:56.702Z,1554850436.702 [BR_Ping1D](INFO): readConfig
2019-04-09T22:53:56.702Z,1554850436.702 [BR_Ping1D](INFO): startup: 2
2019-04-09T22:53:56.702Z,1554850436.702 [BR_Ping1D](INFO): UART waiting for response
2019-04-09T22:53:56.702Z,1554850436.702 [BR_Ping1D](INFO): elapsed 3.7873
2019-04-09T22:53:56.703Z,1554850436.703 [BR_Ping1D](INFO): timeout 5.0000
2019-04-09T22:53:56.703Z,1554850436.703 [BR_Ping1D](INFO): No UART data
2019-04-09T22:53:56.703Z,1554850436.703 [BR_Ping1D](INFO): received UART packets: 0
2019-04-09T22:53:56.703Z,1554850436.703 [BR_Ping1D](INFO): not all values verified yet
2019-04-09T22:53:57.105Z,1554850437.105 [BR_Ping1D](INFO): Starting
2019-04-09T22:53:57.105Z,1554850437.105 [BR_Ping1D](INFO): readConfig
2019-04-09T22:53:57.105Z,1554850437.105 [BR_Ping1D](INFO): startup: 2
2019-04-09T22:53:57.106Z,1554850437.106 [BR_Ping1D](INFO): UART waiting for response
2019-04-09T22:53:57.106Z,1554850437.106 [BR_Ping1D](INFO): elapsed 4.1907
2019-04-09T22:53:57.106Z,1554850437.106 [BR_Ping1D](INFO): timeout 5.0000
2019-04-09T22:53:57.106Z,1554850437.106 [BR_Ping1D](INFO): No UART data
2019-04-09T22:53:57.106Z,1554850437.106 [BR_Ping1D](INFO): received UART packets: 0
2019-04-09T22:53:57.107Z,1554850437.107 [BR_Ping1D](INFO): not all values verified yet
2019-04-09T22:53:57.510Z,1554850437.510 [BR_Ping1D](INFO): Starting
2019-04-09T22:53:57.510Z,1554850437.510 [BR_Ping1D](INFO): readConfig
2019-04-09T22:53:57.511Z,1554850437.511 [BR_Ping1D](INFO): startup: 2
2019-04-09T22:53:57.511Z,1554850437.511 [BR_Ping1D](INFO): UART waiting for response
2019-04-09T22:53:57.511Z,1554850437.511 [BR_Ping1D](INFO): elapsed 4.5958
2019-04-09T22:53:57.511Z,1554850437.511 [BR_Ping1D](INFO): timeout 5.0000
2019-04-09T22:53:57.511Z,1554850437.511 [BR_Ping1D](INFO): No UART data
2019-04-09T22:53:57.511Z,1554850437.511 [BR_Ping1D](INFO): received UART packets: 0
2019-04-09T22:53:57.512Z,1554850437.512 [BR_Ping1D](INFO): not all values verified yet
2019-04-09T22:53:57.913Z,1554850437.913 [BR_Ping1D](INFO): Starting
2019-04-09T22:53:57.913Z,1554850437.913 [BR_Ping1D](INFO): readConfig
2019-04-09T22:53:57.914Z,1554850437.914 [BR_Ping1D](INFO): startup: 2
2019-04-09T22:53:57.914Z,1554850437.914 [BR_Ping1D](INFO): UART waiting for response
2019-04-09T22:53:57.914Z,1554850437.914 [BR_Ping1D](INFO): elapsed 4.9990
2019-04-09T22:53:57.914Z,1554850437.914 [BR_Ping1D](INFO): timeout 5.0000
2019-04-09T22:53:57.915Z,1554850437.915 [BR_Ping1D](INFO): No UART data
2019-04-09T22:53:57.915Z,1554850437.915 [BR_Ping1D](INFO): received UART packets: 0
2019-04-09T22:53:57.915Z,1554850437.915 [BR_Ping1D](INFO): not all values verified yet
2019-04-09T22:53:58.318Z,1554850438.318 [BR_Ping1D](INFO): Starting
2019-04-09T22:53:58.319Z,1554850438.319 [BR_Ping1D](INFO): readConfig
2019-04-09T22:53:58.319Z,1554850438.319 [BR_Ping1D](INFO): startup: 2
2019-04-09T22:53:58.319Z,1554850438.319 [BR_Ping1D](INFO): UART waiting for response
2019-04-09T22:53:58.319Z,1554850438.319 [BR_Ping1D](INFO): elapsed 5.4040
2019-04-09T22:53:58.319Z,1554850438.319 [BR_Ping1D](INFO): timeout 5.0000
2019-04-09T22:53:58.319Z,1554850438.319 [BR_Ping1D](FAULT): Failed to set parameters in time during initialization.
2019-04-09T22:53:58.320Z,1554850438.320 [BR_Ping1D] Data Fault, FailCount= 1
2019-04-09T22:53:58.320Z,1554850438.320 [BR_Ping1D](ERROR): Data Fault
2019-04-09T22:53:58.378Z,1554850438.378 [CBIT](ERROR): Data Fault in component: BR_Ping1D
2019-04-09T22:53:58.721Z,1554850438.721 [BR_Ping1D](INFO): Stop
2019-04-09T22:53:58.722Z,1554850438.722 [BR_Ping1D](INFO): uninitialize
2019-04-09T22:53:58.722Z,1554850438.722 [BR_Ping1D](INFO): Powering down
2019-04-09T22:53:59.125Z,1554850439.125 [BR_Ping1D](INFO): Stopping
2019-04-09T22:53:59.529Z,1554850439.529 [BR_Ping1D](INFO): Stopping
2019-04-09T22:53:59.934Z,1554850439.934 [BR_Ping1D](INFO): Stopped
2019-04-09T22:53:59.995Z,1554850439.995 [CBIT](INFO): Clearing failed state for component BR_Ping1D
2019-04-09T22:53:59.995Z,1554850439.995 [BR_Ping1D] No Fault, FailCount= 1
2019-04-09T22:54:00.338Z,1554850440.338 [BR_Ping1D](INFO): Start
2019-04-09T22:54:00.741Z,1554850440.741 [BR_Ping1D](INFO): Starting
2019-04-09T22:54:01.146Z,1554850441.146 [BR_Ping1D](INFO): Starting
2019-04-09T22:54:01.146Z,1554850441.146 [BR_Ping1D](INFO): readConfig
2019-04-09T22:54:01.146Z,1554850441.146 [BR_Ping1D](INFO): startup: 0
2019-04-09T22:54:01.146Z,1554850441.146 [BR_Ping1D](INFO): UART setting parameters ...
2019-04-09T22:54:01.158Z,1554850441.158 [BR_Ping1D](INFO): sending request for Ping Interval: 500
2019-04-09T22:54:01.158Z,1554850441.158 [BR_Ping1D](INFO): data F401
2019-04-09T22:54:01.158Z,1554850441.158 [BR_Ping1D](INFO): test: ô

2019-04-09T22:54:01.158Z,1554850441.158 [BR_Ping1D](INFO): 42520200EC030000F4017A02
2019-04-09T22:54:01.159Z,1554850441.159 [BR_Ping1D](INFO): sending request for Auto Mode: 1
2019-04-09T22:54:01.159Z,1554850441.159 [BR_Ping1D](INFO): 42520100EB030000840115
2019-04-09T22:54:01.159Z,1554850441.159 [BR_Ping1D](INFO): sending request for Soundspeed: 1500000
2019-04-09T22:54:01.159Z,1554850441.159 [BR_Ping1D](INFO): 42520400EA03000060E31600DE02
2019-04-09T22:54:01.159Z,1554850441.159 [BR_Ping1D](INFO): sending request for Ping Enable: 1
2019-04-09T22:54:01.160Z,1554850441.159 [BR_Ping1D](INFO): 42520100EE030000870115
2019-04-09T22:54:01.550Z,1554850441.550 [BR_Ping1D](INFO): Starting
2019-04-09T22:54:01.714Z,1554850441.714 [CBIT](CRITICAL): Environmental Failure. Press:14.787499 PSI. Humidity:38%. Temp:25 C. ABORTING MISSION
2019-04-09T22:54:01.934Z,1554850441.934 [Aanderaa_O2](FAULT): Failed to initialize within timeout.
2019-04-09T22:54:01.934Z,1554850441.934 [Aanderaa_O2] Communications Fault, FailCount= 1
2019-04-09T22:54:01.934Z,1554850441.934 [Aanderaa_O2](ERROR): Communications Fault
2019-04-09T22:54:01.953Z,1554850441.953 [BR_Ping1D](INFO): Starting
2019-04-09T22:54:01.953Z,1554850441.953 [BR_Ping1D](INFO): readConfig
2019-04-09T22:54:01.954Z,1554850441.954 [BR_Ping1D](INFO): startup: 1
2019-04-09T22:54:01.954Z,1554850441.954 [BR_Ping1D](INFO): UART requesting status
2019-04-09T22:54:01.954Z,1554850441.954 [BR_Ping1D](INFO): 42520000BA0400005201
2019-04-09T22:54:01.962Z,1554850441.962 [BR_Ping1D](INFO): 42520000BF0400005701
2019-04-09T22:54:01.970Z,1554850441.970 [BR_Ping1D](INFO): 42520000B30400004B01
2019-04-09T22:54:01.986Z,1554850441.986 [CBIT](INFO): Critical error at 20190409T225401
2019-04-09T22:54:01.989Z,1554850441.989 [CBIT](ERROR): Communications Fault in component: Aanderaa_O2
2019-04-09T22:54:02.458Z,1554850442.458 [Aanderaa_O2](INFO): Powering down
2019-04-09T22:54:02.540Z,1554850442.540 [BR_Ping1D](INFO): Starting
2019-04-09T22:54:02.540Z,1554850442.540 [BR_Ping1D](INFO): readConfig
2019-04-09T22:54:02.540Z,1554850442.540 [BR_Ping1D](INFO): startup: 2
2019-04-09T22:54:02.540Z,1554850442.540 [BR_Ping1D](INFO): UART waiting for response
2019-04-09T22:54:02.540Z,1554850442.540 [BR_Ping1D](INFO): elapsed 1.3940
2019-04-09T22:54:02.541Z,1554850442.541 [BR_Ping1D](INFO): timeout 5.0000
2019-04-09T22:54:02.541Z,1554850442.541 [BR_Ping1D](INFO): No UART data
2019-04-09T22:54:02.541Z,1554850442.541 [BR_Ping1D](INFO): received UART packets: 0
2019-04-09T22:54:02.541Z,1554850442.541 [BR_Ping1D](INFO): not all values verified yet
2019-04-09T22:54:02.761Z,1554850442.761 [BR_Ping1D](INFO): Starting
2019-04-09T22:54:02.762Z,1554850442.762 [BR_Ping1D](INFO): readConfig
2019-04-09T22:54:02.762Z,1554850442.762 [BR_Ping1D](INFO): startup: 2
2019-04-09T22:54:02.762Z,1554850442.762 [BR_Ping1D](INFO): UART waiting for response
2019-04-09T22:54:02.762Z,1554850442.762 [BR_Ping1D](INFO): elapsed 1.6159
2019-04-09T22:54:02.762Z,1554850442.762 [BR_Ping1D](INFO): timeout 5.0000
2019-04-09T22:54:02.763Z,1554850442.763 [BR_Ping1D](INFO): No UART data
2019-04-09T22:54:02.763Z,1554850442.763 [BR_Ping1D](INFO): received UART packets: 0
2019-04-09T22:54:02.763Z,1554850442.763 [BR_Ping1D](INFO): not all values verified yet
2019-04-09T22:54:03.166Z,1554850443.166 [BR_Ping1D](INFO): Starting
2019-04-09T22:54:03.166Z,1554850443.166 [BR_Ping1D](INFO): readConfig
2019-04-09T22:54:03.166Z,1554850443.166 [BR_Ping1D](INFO): startup: 2
2019-04-09T22:54:03.166Z,1554850443.166 [BR_Ping1D](INFO): UART waiting for response
2019-04-09T22:54:03.166Z,1554850443.166 [BR_Ping1D](INFO): elapsed 2.0201
2019-04-09T22:54:03.167Z,1554850443.167 [BR_Ping1D](INFO): timeout 5.0000
2019-04-09T22:54:03.167Z,1554850443.167 [BR_Ping1D](INFO): No UART data
2019-04-09T22:54:03.167Z,1554850443.167 [BR_Ping1D](INFO): received UART packets: 0
2019-04-09T22:54:03.167Z,1554850443.167 [BR_Ping1D](INFO): not all values verified yet
2019-04-09T22:54:03.183Z,1554850443.183 [CBIT](INFO): Clearing failed state for component Aanderaa_O2
2019-04-09T22:54:03.183Z,1554850443.183 [Aanderaa_O2] No Fault, FailCount= 1
2019-04-09T22:54:03.570Z,1554850443.570 [BR_Ping1D](INFO): Starting
2019-04-09T22:54:03.570Z,1554850443.570 [BR_Ping1D](INFO): readConfig
2019-04-09T22:54:03.570Z,1554850443.570 [BR_Ping1D](INFO): startup: 2
2019-04-09T22:54:03.570Z,1554850443.570 [BR_Ping1D](INFO): UART waiting for response
2019-04-09T22:54:03.570Z,1554850443.570 [BR_Ping1D](INFO): elapsed 2.4240
2019-04-09T22:54:03.571Z,1554850443.571 [BR_Ping1D](INFO): timeout 5.0000
2019-04-09T22:54:03.571Z,1554850443.571 [BR_Ping1D](INFO): No UART data
2019-04-09T22:54:03.571Z,1554850443.571 [BR_Ping1D](INFO): received UART packets: 0
2019-04-09T22:54:03.571Z,1554850443.571 [BR_Ping1D](INFO): not all values verified yet
2019-04-09T22:54:03.986Z,1554850443.986 [BR_Ping1D](INFO): Starting
2019-04-09T22:54:03.986Z,1554850443.986 [BR_Ping1D](INFO): readConfig
2019-04-09T22:54:03.986Z,1554850443.986 [BR_Ping1D](INFO): startup: 2
2019-04-09T22:54:03.986Z,1554850443.986 [BR_Ping1D](INFO): UART waiting for response
2019-04-09T22:54:03.986Z,1554850443.986 [BR_Ping1D](INFO): elapsed 2.8401
2019-04-09T22:54:03.987Z,1554850443.987 [BR_Ping1D](INFO): timeout 5.0000
2019-04-09T22:54:03.987Z,1554850443.987 [BR_Ping1D](INFO): No UART data
2019-04-09T22:54:03.987Z,1554850443.987 [BR_Ping1D](INFO): received UART packets: 0
2019-04-09T22:54:03.987Z,1554850443.987 [BR_Ping1D](INFO): not all values verified yet
2019-04-09T22:54:04.342Z,1554850444.342 [CTD_Seabird](FAULT): Failed to initialize within timeout.
2019-04-09T22:54:04.342Z,1554850444.342 [CTD_Seabird] Communications Fault, FailCount= 1
2019-04-09T22:54:04.342Z,1554850444.342 [CTD_Seabird](ERROR): Communications Fault
2019-04-09T22:54:04.377Z,1554850444.377 [BR_Ping1D](INFO): Starting
2019-04-09T22:54:04.377Z,1554850444.377 [BR_Ping1D](INFO): readConfig
2019-04-09T22:54:04.378Z,1554850444.378 [BR_Ping1D](INFO): startup: 2
2019-04-09T22:54:04.378Z,1554850444.378 [BR_Ping1D](INFO): UART waiting for response
2019-04-09T22:54:04.378Z,1554850444.378 [BR_Ping1D](INFO): elapsed 3.2317
2019-04-09T22:54:04.378Z,1554850444.378 [BR_Ping1D](INFO): timeout 5.0000
2019-04-09T22:54:04.378Z,1554850444.378 [BR_Ping1D](INFO): No UART data
2019-04-09T22:54:04.379Z,1554850444.379 [BR_Ping1D](INFO): received UART packets: 0
2019-04-09T22:54:04.379Z,1554850444.379 [BR_Ping1D](INFO): not all values verified yet
2019-04-09T22:54:04.414Z,1554850444.414 [CBIT](ERROR): Communications Fault in component: CTD_Seabird
2019-04-09T22:54:04.746Z,1554850444.746 [CTD_Seabird](INFO): Powering down
2019-04-09T22:54:04.783Z,1554850444.783 [BR_Ping1D](INFO): Starting
2019-04-09T22:54:04.783Z,1554850444.783 [BR_Ping1D](INFO): readConfig
2019-04-09T22:54:04.783Z,1554850444.783 [BR_Ping1D](INFO): startup: 2
2019-04-09T22:54:04.783Z,1554850444.783 [BR_Ping1D](INFO): UART waiting for response
2019-04-09T22:54:04.784Z,1554850444.784 [BR_Ping1D](INFO): elapsed 3.6372
2019-04-09T22:54:04.784Z,1554850444.784 [BR_Ping1D](INFO): timeout 5.0000
2019-04-09T22:54:04.784Z,1554850444.784 [BR_Ping1D](INFO): No UART data
2019-04-09T22:54:04.784Z,1554850444.784 [BR_Ping1D](INFO): received UART packets: 0
2019-04-09T22:54:04.784Z,1554850444.784 [BR_Ping1D](INFO): not all values verified yet
2019-04-09T22:54:05.185Z,1554850445.185 [BR_Ping1D](INFO): Starting
2019-04-09T22:54:05.185Z,1554850445.185 [BR_Ping1D](INFO): readConfig
2019-04-09T22:54:05.186Z,1554850445.186 [BR_Ping1D](INFO): startup: 2
2019-04-09T22:54:05.186Z,1554850445.186 [BR_Ping1D](INFO): UART waiting for response
2019-04-09T22:54:05.186Z,1554850445.186 [BR_Ping1D](INFO): elapsed 4.0396
2019-04-09T22:54:05.186Z,1554850445.186 [BR_Ping1D](INFO): timeout 5.0000
2019-04-09T22:54:05.186Z,1554850445.186 [BR_Ping1D](INFO): No UART data
2019-04-09T22:54:05.187Z,1554850445.187 [BR_Ping1D](INFO): received UART packets: 0
2019-04-09T22:54:05.187Z,1554850445.187 [BR_Ping1D](INFO): not all values verified yet
2019-04-09T22:54:05.589Z,1554850445.589 [BR_Ping1D](INFO): Starting
2019-04-09T22:54:05.590Z,1554850445.590 [BR_Ping1D](INFO): readConfig
2019-04-09T22:54:05.590Z,1554850445.590 [BR_Ping1D](INFO): startup: 2
2019-04-09T22:54:05.590Z,1554850445.590 [BR_Ping1D](INFO): UART waiting for response
2019-04-09T22:54:05.590Z,1554850445.590 [BR_Ping1D](INFO): elapsed 4.4440
2019-04-09T22:54:05.590Z,1554850445.590 [BR_Ping1D](INFO): timeout 5.0000
2019-04-09T22:54:05.591Z,1554850445.591 [BR_Ping1D](INFO): No UART data
2019-04-09T22:54:05.591Z,1554850445.591 [BR_Ping1D](INFO): received UART packets: 0
2019-04-09T22:54:05.591Z,1554850445.591 [BR_Ping1D](INFO): not all values verified yet
2019-04-09T22:54:05.994Z,1554850445.994 [BR_Ping1D](INFO): Starting
2019-04-09T22:54:05.994Z,1554850445.994 [BR_Ping1D](INFO): readConfig
2019-04-09T22:54:05.994Z,1554850445.994 [BR_Ping1D](INFO): startup: 2
2019-04-09T22:54:05.994Z,1554850445.994 [BR_Ping1D](INFO): UART waiting for response
2019-04-09T22:54:05.995Z,1554850445.995 [BR_Ping1D](INFO): elapsed 4.8483
2019-04-09T22:54:05.995Z,1554850445.995 [BR_Ping1D](INFO): timeout 5.0000
2019-04-09T22:54:05.995Z,1554850445.995 [BR_Ping1D](INFO): No UART data
2019-04-09T22:54:05.995Z,1554850445.995 [BR_Ping1D](INFO): received UART packets: 0
2019-04-09T22:54:05.995Z,1554850445.995 [BR_Ping1D](INFO): not all values verified yet
2019-04-09T22:54:06.027Z,1554850446.027 [CBIT](INFO): Clearing failed state for component CTD_Seabird
2019-04-09T22:54:06.027Z,1554850446.027 [CTD_Seabird] No Fault, FailCount= 1
2019-04-09T22:54:06.170Z,1554850446.170 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2019-04-09T22:54:06.174Z,1554850446.174 [CTD_Seabird](INFO): Opening uart, block timeout 10ths=20
2019-04-09T22:54:06.398Z,1554850446.398 [BR_Ping1D](INFO): Starting
2019-04-09T22:54:06.398Z,1554850446.398 [BR_Ping1D](INFO): readConfig
2019-04-09T22:54:06.398Z,1554850446.398 [BR_Ping1D](INFO): startup: 2
2019-04-09T22:54:06.398Z,1554850446.398 [BR_Ping1D](INFO): UART waiting for response
2019-04-09T22:54:06.399Z,1554850446.399 [BR_Ping1D](INFO): elapsed 5.2523
2019-04-09T22:54:06.399Z,1554850446.399 [BR_Ping1D](INFO): timeout 5.0000
2019-04-09T22:54:06.399Z,1554850446.399 [BR_Ping1D](FAULT): Failed to set parameters in time during initialization.
2019-04-09T22:54:06.399Z,1554850446.399 [BR_Ping1D] Data Fault, FailCount= 2
2019-04-09T22:54:06.399Z,1554850446.399 [BR_Ping1D](ERROR): Data Fault
2019-04-09T22:54:06.416Z,1554850446.416 [CBIT](ERROR): Data Fault in component: BR_Ping1D
2019-04-09T22:54:06.801Z,1554850446.801 [BR_Ping1D](INFO): Stop
2019-04-09T22:54:06.801Z,1554850446.801 [BR_Ping1D](INFO): uninitialize
2019-04-09T22:54:06.802Z,1554850446.802 [BR_Ping1D](INFO): Powering down
2019-04-09T22:54:07.206Z,1554850447.206 [BR_Ping1D](INFO): Stopping
2019-04-09T22:54:07.613Z,1554850447.613 [BR_Ping1D](INFO): Stopping
2019-04-09T22:54:08.014Z,1554850448.014 [BR_Ping1D](INFO): Stopped
2019-04-09T22:54:08.043Z,1554850448.043 [CBIT](INFO): Clearing failed state for component BR_Ping1D
2019-04-09T22:54:08.043Z,1554850448.043 [BR_Ping1D] No Fault, FailCount= 2
2019-04-09T22:54:08.417Z,1554850448.417 [BR_Ping1D](INFO): Start
2019-04-09T22:54:08.823Z,1554850448.823 [BR_Ping1D](INFO): Starting
2019-04-09T22:54:09.225Z,1554850449.225 [BR_Ping1D](INFO): Starting
2019-04-09T22:54:09.226Z,1554850449.226 [BR_Ping1D](INFO): readConfig
2019-04-09T22:54:09.226Z,1554850449.226 [BR_Ping1D](INFO): startup: 0
2019-04-09T22:54:09.226Z,1554850449.226 [BR_Ping1D](INFO): UART setting parameters ...
2019-04-09T22:54:09.238Z,1554850449.238 [BR_Ping1D](INFO): sending request for Ping Interval: 500
2019-04-09T22:54:09.238Z,1554850449.238 [BR_Ping1D](INFO): data F401
2019-04-09T22:54:09.238Z,1554850449.238 [BR_Ping1D](INFO): test: ô

2019-04-09T22:54:09.238Z,1554850449.238 [BR_Ping1D](INFO): 42520200EC030000F4017A02
2019-04-09T22:54:09.239Z,1554850449.239 [BR_Ping1D](INFO): sending request for Auto Mode: 1
2019-04-09T22:54:09.239Z,1554850449.239 [BR_Ping1D](INFO): 42520100EB030000840115
2019-04-09T22:54:09.239Z,1554850449.239 [BR_Ping1D](INFO): sending request for Soundspeed: 1500000
2019-04-09T22:54:09.239Z,1554850449.239 [BR_Ping1D](INFO): 42520400EA03000060E31600DE02
2019-04-09T22:54:09.239Z,1554850449.239 [BR_Ping1D](INFO): sending request for Ping Enable: 1
2019-04-09T22:54:09.239Z,1554850449.239 [BR_Ping1D](INFO): 42520100EE030000870115
2019-04-09T22:54:09.630Z,1554850449.630 [BR_Ping1D](INFO): Starting
2019-04-09T22:54:10.033Z,1554850450.033 [BR_Ping1D](INFO): Starting
2019-04-09T22:54:10.034Z,1554850450.034 [BR_Ping1D](INFO): readConfig
2019-04-09T22:54:10.034Z,1554850450.034 [BR_Ping1D](INFO): startup: 1
2019-04-09T22:54:10.034Z,1554850450.034 [BR_Ping1D](INFO): UART requesting status
2019-04-09T22:54:10.034Z,1554850450.034 [BR_Ping1D](INFO): 42520000BA0400005201
2019-04-09T22:54:10.042Z,1554850450.042 [BR_Ping1D](INFO): 42520000BF0400005701
2019-04-09T22:54:10.050Z,1554850450.050 [BR_Ping1D](INFO): 42520000B30400004B01
2019-04-09T22:54:10.438Z,1554850450.438 [BR_Ping1D](INFO): Starting
2019-04-09T22:54:10.438Z,1554850450.438 [BR_Ping1D](INFO): readConfig
2019-04-09T22:54:10.439Z,1554850450.439 [BR_Ping1D](INFO): startup: 2
2019-04-09T22:54:10.439Z,1554850450.439 [BR_Ping1D](INFO): UART waiting for response
2019-04-09T22:54:10.439Z,1554850450.439 [BR_Ping1D](INFO): elapsed 1.2126
2019-04-09T22:54:10.439Z,1554850450.439 [BR_Ping1D](INFO): timeout 5.0000
2019-04-09T22:54:10.439Z,1554850450.439 [BR_Ping1D](INFO): No UART data
2019-04-09T22:54:10.439Z,1554850450.439 [BR_Ping1D](INFO): received UART packets: 0
2019-04-09T22:54:10.440Z,1554850450.440 [BR_Ping1D](INFO): not all values verified yet
2019-04-09T22:54:10.842Z,1554850450.842 [BR_Ping1D](INFO): Starting
2019-04-09T22:54:10.842Z,1554850450.842 [BR_Ping1D](INFO): readConfig
2019-04-09T22:54:10.842Z,1554850450.842 [BR_Ping1D](INFO): startup: 2
2019-04-09T22:54:10.843Z,1554850450.843 [BR_Ping1D](INFO): UART waiting for response
2019-04-09T22:54:10.843Z,1554850450.843 [BR_Ping1D](INFO): elapsed 1.6166
2019-04-09T22:54:10.843Z,1554850450.843 [BR_Ping1D](INFO): timeout 5.0000
2019-04-09T22:54:10.843Z,1554850450.843 [BR_Ping1D](INFO): No UART data
2019-04-09T22:54:10.843Z,1554850450.843 [BR_Ping1D](INFO): received UART packets: 0
2019-04-09T22:54:10.843Z,1554850450.843 [BR_Ping1D](INFO): not all values verified yet
2019-04-09T22:54:11.246Z,1554850451.246 [BR_Ping1D](INFO): Starting
2019-04-09T22:54:11.246Z,1554850451.246 [BR_Ping1D](INFO): readConfig
2019-04-09T22:54:11.246Z,1554850451.246 [BR_Ping1D](INFO): startup: 2
2019-04-09T22:54:11.246Z,1554850451.246 [BR_Ping1D](INFO): UART waiting for response
2019-04-09T22:54:11.246Z,1554850451.246 [BR_Ping1D](INFO): elapsed 2.0203
2019-04-09T22:54:11.247Z,1554850451.247 [BR_Ping1D](INFO): timeout 5.0000
2019-04-09T22:54:11.247Z,1554850451.247 [BR_Ping1D](INFO): No UART data
2019-04-09T22:54:11.247Z,1554850451.247 [BR_Ping1D](INFO): received UART packets: 0
2019-04-09T22:54:11.247Z,1554850451.247 [BR_Ping1D](INFO): not all values verified yet
2019-04-09T22:54:11.650Z,1554850451.650 [BR_Ping1D](INFO): Starting
2019-04-09T22:54:11.650Z,1554850451.650 [BR_Ping1D](INFO): readConfig
2019-04-09T22:54:11.650Z,1554850451.650 [BR_Ping1D](INFO): startup: 2
2019-04-09T22:54:11.650Z,1554850451.650 [BR_Ping1D](INFO): UART waiting for response
2019-04-09T22:54:11.651Z,1554850451.651 [BR_Ping1D](INFO): elapsed 2.4243
2019-04-09T22:54:11.651Z,1554850451.651 [BR_Ping1D](INFO): timeout 5.0000
2019-04-09T22:54:11.651Z,1554850451.651 [BR_Ping1D](INFO): No UART data
2019-04-09T22:54:11.651Z,1554850451.651 [BR_Ping1D](INFO): received UART packets: 0
2019-04-09T22:54:11.651Z,1554850451.651 [BR_Ping1D](INFO): not all values verified yet
2019-04-09T22:54:12.054Z,1554850452.054 [BR_Ping1D](INFO): Starting
2019-04-09T22:54:12.054Z,1554850452.054 [BR_Ping1D](INFO): readConfig
2019-04-09T22:54:12.055Z,1554850452.055 [BR_Ping1D](INFO): startup: 2
2019-04-09T22:54:12.055Z,1554850452.055 [BR_Ping1D](INFO): UART waiting for response
2019-04-09T22:54:12.055Z,1554850452.055 [BR_Ping1D](INFO): elapsed 2.8286
2019-04-09T22:54:12.055Z,1554850452.055 [BR_Ping1D](INFO): timeout 5.0000
2019-04-09T22:54:12.055Z,1554850452.055 [BR_Ping1D](INFO): No UART data
2019-04-09T22:54:12.055Z,1554850452.055 [BR_Ping1D](INFO): received UART packets: 0
2019-04-09T22:54:12.056Z,1554850452.056 [BR_Ping1D](INFO): not all values verified yet
2019-04-09T22:54:12.439Z,1554850452.439 [AcousticModem_Benthos_ATM900](FAULT): failed to initialize, no bytes available on serial interface
2019-04-09T22:54:12.439Z,1554850452.439 [AcousticModem_Benthos_ATM900] Communications Fault, FailCount= 1
2019-04-09T22:54:12.439Z,1554850452.439 [AcousticModem_Benthos_ATM900](ERROR): Communications Fault
2019-04-09T22:54:12.457Z,1554850452.457 [BR_Ping1D](INFO): Starting
2019-04-09T22:54:12.457Z,1554850452.457 [BR_Ping1D](INFO): readConfig
2019-04-09T22:54:12.458Z,1554850452.458 [BR_Ping1D](INFO): startup: 2
2019-04-09T22:54:12.458Z,1554850452.458 [BR_Ping1D](INFO): UART waiting for response
2019-04-09T22:54:12.458Z,1554850452.458 [BR_Ping1D](INFO): elapsed 3.2318
2019-04-09T22:54:12.458Z,1554850452.458 [BR_Ping1D](INFO): timeout 5.0000
2019-04-09T22:54:12.458Z,1554850452.458 [BR_Ping1D](INFO): No UART data
2019-04-09T22:54:12.459Z,1554850452.459 [BR_Ping1D](INFO): received UART packets: 0
2019-04-09T22:54:12.459Z,1554850452.459 [BR_Ping1D](INFO): not all values verified yet
2019-04-09T22:54:12.476Z,1554850452.476 [CBIT](ERROR): Communications Fault in component: AcousticModem_Benthos_ATM900
2019-04-09T22:54:12.843Z,1554850452.843 [AcousticModem_Benthos_ATM900](INFO): Powering down
2019-04-09T22:54:13.006Z,1554850453.006 [BR_Ping1D](INFO): Starting
2019-04-09T22:54:13.006Z,1554850453.006 [BR_Ping1D](INFO): readConfig
2019-04-09T22:54:13.006Z,1554850453.006 [BR_Ping1D](INFO): startup: 2
2019-04-09T22:54:13.007Z,1554850453.007 [BR_Ping1D](INFO): UART waiting for response
2019-04-09T22:54:13.007Z,1554850453.007 [BR_Ping1D](INFO): elapsed 3.7806
2019-04-09T22:54:13.007Z,1554850453.007 [BR_Ping1D](INFO): timeout 5.0000
2019-04-09T22:54:13.007Z,1554850453.007 [BR_Ping1D](INFO): No UART data
2019-04-09T22:54:13.007Z,1554850453.007 [BR_Ping1D](INFO): received UART packets: 0
2019-04-09T22:54:13.007Z,1554850453.007 [BR_Ping1D](INFO): not all values verified yet
2019-04-09T22:54:13.266Z,1554850453.266 [BR_Ping1D](INFO): Starting
2019-04-09T22:54:13.266Z,1554850453.266 [BR_Ping1D](INFO): readConfig
2019-04-09T22:54:13.266Z,1554850453.266 [BR_Ping1D](INFO): startup: 2
2019-04-09T22:54:13.266Z,1554850453.266 [BR_Ping1D](INFO): UART waiting for response
2019-04-09T22:54:13.266Z,1554850453.266 [BR_Ping1D](INFO): elapsed 4.0401
2019-04-09T22:54:13.267Z,1554850453.267 [BR_Ping1D](INFO): timeout 5.0000
2019-04-09T22:54:13.267Z,1554850453.267 [BR_Ping1D](INFO): No UART data
2019-04-09T22:54:13.267Z,1554850453.267 [BR_Ping1D](INFO): received UART packets: 0
2019-04-09T22:54:13.267Z,1554850453.267 [BR_Ping1D](INFO): not all values verified yet
2019-04-09T22:54:13.650Z,1554850453.650 [Aanderaa_O2](FAULT): Failed to initialize within timeout.
2019-04-09T22:54:13.650Z,1554850453.650 [Aanderaa_O2] Communications Fault, FailCount= 2
2019-04-09T22:54:13.650Z,1554850453.650 [Aanderaa_O2](ERROR): Communications Fault
2019-04-09T22:54:13.669Z,1554850453.669 [BR_Ping1D](INFO): Starting
2019-04-09T22:54:13.669Z,1554850453.669 [BR_Ping1D](INFO): readConfig
2019-04-09T22:54:13.670Z,1554850453.670 [BR_Ping1D](INFO): startup: 2
2019-04-09T22:54:13.670Z,1554850453.670 [BR_Ping1D](INFO): UART waiting for response
2019-04-09T22:54:13.670Z,1554850453.670 [BR_Ping1D](INFO): elapsed 4.4439
2019-04-09T22:54:13.670Z,1554850453.670 [BR_Ping1D](INFO): timeout 5.0000
2019-04-09T22:54:13.671Z,1554850453.671 [BR_Ping1D](INFO): No UART data
2019-04-09T22:54:13.671Z,1554850453.671 [BR_Ping1D](INFO): received UART packets: 0
2019-04-09T22:54:13.671Z,1554850453.671 [BR_Ping1D](INFO): not all values verified yet
2019-04-09T22:54:13.699Z,1554850453.699 [CBIT](ERROR): Communications Fault in component: Aanderaa_O2
2019-04-09T22:54:13.699Z,1554850453.699 [CBIT](INFO): Clearing failed state for component AcousticModem_Benthos_ATM900
2019-04-09T22:54:13.699Z,1554850453.699 [AcousticModem_Benthos_ATM900] No Fault, FailCount= 1
2019-04-09T22:54:14.174Z,1554850454.174 [Aanderaa_O2](INFO): Powering down
2019-04-09T22:54:14.193Z,1554850454.193 [BR_Ping1D](INFO): Starting
2019-04-09T22:54:14.194Z,1554850454.194 [BR_Ping1D](INFO): readConfig
2019-04-09T22:54:14.194Z,1554850454.194 [BR_Ping1D](INFO): startup: 2
2019-04-09T22:54:14.194Z,1554850454.194 [BR_Ping1D](INFO): UART waiting for response
2019-04-09T22:54:14.194Z,1554850454.194 [BR_Ping1D](INFO): elapsed 4.9681
2019-04-09T22:54:14.194Z,1554850454.194 [BR_Ping1D](INFO): timeout 5.0000
2019-04-09T22:54:14.195Z,1554850454.195 [BR_Ping1D](INFO): No UART data
2019-04-09T22:54:14.195Z,1554850454.195 [BR_Ping1D](INFO): received UART packets: 0
2019-04-09T22:54:14.195Z,1554850454.195 [BR_Ping1D](INFO): not all values verified yet
2019-04-09T22:54:14.479Z,1554850454.479 [BR_Ping1D](INFO): Starting
2019-04-09T22:54:14.479Z,1554850454.479 [BR_Ping1D](INFO): readConfig
2019-04-09T22:54:14.479Z,1554850454.479 [BR_Ping1D](INFO): startup: 2
2019-04-09T22:54:14.479Z,1554850454.479 [BR_Ping1D](INFO): UART waiting for response
2019-04-09T22:54:14.479Z,1554850454.479 [BR_Ping1D](INFO): elapsed 5.2531
2019-04-09T22:54:14.479Z,1554850454.479 [BR_Ping1D](INFO): timeout 5.0000
2019-04-09T22:54:14.480Z,1554850454.480 [BR_Ping1D](FAULT): Failed to set parameters in time during initialization.
2019-04-09T22:54:14.480Z,1554850454.480 [BR_Ping1D] Data Fault, FailCount= 3
2019-04-09T22:54:14.480Z,1554850454.480 [BR_Ping1D](ERROR): Data Fault
2019-04-09T22:54:14.499Z,1554850454.499 [CBIT](ERROR): Data Fault in component: BR_Ping1D
2019-04-09T22:54:14.881Z,1554850454.881 [BR_Ping1D](INFO): Stop
2019-04-09T22:54:14.881Z,1554850454.881 [BR_Ping1D](INFO): uninitialize
2019-04-09T22:54:14.881Z,1554850454.881 [BR_Ping1D](INFO): Powering down
2019-04-09T22:54:14.986Z,1554850454.986 [CBIT](INFO): Clearing failed state for component Aanderaa_O2
2019-04-09T22:54:14.986Z,1554850454.986 [Aanderaa_O2] No Fault, FailCount= 2
2019-04-09T22:54:15.293Z,1554850455.293 [BR_Ping1D](INFO): Stopping
2019-04-09T22:54:15.701Z,1554850455.701 [BR_Ping1D](INFO): Stopping
2019-04-09T22:54:15.720Z,1554850455.720 [SBIT](IMPORTANT): Beginning Startup BIT
2019-04-09T22:54:15.729Z,1554850455.729 [CBIT](IMPORTANT): Beginning ground fault scan
2019-04-09T22:54:16.074Z,1554850456.074 [AcousticModem_Benthos_ATM900](INFO): Powering up
2019-04-09T22:54:16.075Z,1554850456.075 [AcousticModem_Benthos_ATM900](DEBUG): Initializing AcousticModem_Benthos_ATM900.
2019-04-09T22:54:16.118Z,1554850456.118 [BR_Ping1D](INFO): Stopped
2019-04-09T22:54:16.215Z,1554850456.215 [CBIT](INFO): Clearing failed state for component BR_Ping1D
2019-04-09T22:54:16.215Z,1554850456.215 [BR_Ping1D] No Fault, FailCount= 3
2019-04-09T22:54:16.499Z,1554850456.499 [BR_Ping1D](INFO): Start
2019-04-09T22:54:16.902Z,1554850456.902 [BR_Ping1D](INFO): Starting
2019-04-09T22:54:17.305Z,1554850457.305 [BR_Ping1D](INFO): Starting
2019-04-09T22:54:17.305Z,1554850457.305 [BR_Ping1D](INFO): readConfig
2019-04-09T22:54:17.305Z,1554850457.305 [BR_Ping1D](INFO): startup: 0
2019-04-09T22:54:17.306Z,1554850457.306 [BR_Ping1D](INFO): UART setting parameters ...
2019-04-09T22:54:17.318Z,1554850457.318 [BR_Ping1D](INFO): sending request for Ping Interval: 500
2019-04-09T22:54:17.318Z,1554850457.318 [BR_Ping1D](INFO): data F401
2019-04-09T22:54:17.318Z,1554850457.318 [BR_Ping1D](INFO): test: ô

2019-04-09T22:54:17.318Z,1554850457.318 [BR_Ping1D](INFO): 42520200EC030000F4017A02
2019-04-09T22:54:17.319Z,1554850457.319 [BR_Ping1D](INFO): sending request for Auto Mode: 1
2019-04-09T22:54:17.319Z,1554850457.319 [BR_Ping1D](INFO): 42520100EB030000840115
2019-04-09T22:54:17.319Z,1554850457.319 [BR_Ping1D](INFO): sending request for Soundspeed: 1500000
2019-04-09T22:54:17.319Z,1554850457.319 [BR_Ping1D](INFO): 42520400EA03000060E31600DE02
2019-04-09T22:54:17.319Z,1554850457.319 [BR_Ping1D](INFO): sending request for Ping Enable: 1
2019-04-09T22:54:17.319Z,1554850457.319 [BR_Ping1D](INFO): 42520100EE030000870115
2019-04-09T22:54:17.709Z,1554850457.709 [BR_Ping1D](INFO): Starting
2019-04-09T22:54:18.189Z,1554850458.189 [BR_Ping1D](INFO): Starting
2019-04-09T22:54:18.189Z,1554850458.189 [BR_Ping1D](INFO): readConfig
2019-04-09T22:54:18.189Z,1554850458.189 [BR_Ping1D](INFO): startup: 1
2019-04-09T22:54:18.189Z,1554850458.189 [BR_Ping1D](INFO): UART requesting status
2019-04-09T22:54:18.189Z,1554850458.189 [BR_Ping1D](INFO): 42520000BA0400005201
2019-04-09T22:54:18.198Z,1554850458.198 [BR_Ping1D](INFO): 42520000BF0400005701
2019-04-09T22:54:18.206Z,1554850458.206 [BR_Ping1D](INFO): 42520000B30400004B01
2019-04-09T22:54:18.582Z,1554850458.582 [BR_Ping1D](INFO): Starting
2019-04-09T22:54:18.582Z,1554850458.582 [BR_Ping1D](INFO): readConfig
2019-04-09T22:54:18.582Z,1554850458.582 [BR_Ping1D](INFO): startup: 2
2019-04-09T22:54:18.583Z,1554850458.583 [BR_Ping1D](INFO): UART waiting for response
2019-04-09T22:54:18.583Z,1554850458.583 [BR_Ping1D](INFO): elapsed 1.2770
2019-04-09T22:54:18.583Z,1554850458.583 [BR_Ping1D](INFO): timeout 5.0000
2019-04-09T22:54:18.583Z,1554850458.583 [BR_Ping1D](INFO): No UART data
2019-04-09T22:54:18.583Z,1554850458.583 [BR_Ping1D](INFO): received UART packets: 0
2019-04-09T22:54:18.583Z,1554850458.583 [BR_Ping1D](INFO): not all values verified yet
2019-04-09T22:54:18.971Z,1554850458.971 [NAL9602](INFO): Powering up NAL9602
2019-04-09T22:54:18.986Z,1554850458.986 [BR_Ping1D](INFO): Starting
2019-04-09T22:54:18.987Z,1554850458.987 [BR_Ping1D](INFO): readConfig
2019-04-09T22:54:18.987Z,1554850458.987 [BR_Ping1D](INFO): startup: 2
2019-04-09T22:54:18.987Z,1554850458.987 [BR_Ping1D](INFO): UART waiting for response
2019-04-09T22:54:18.987Z,1554850458.987 [BR_Ping1D](INFO): elapsed 1.6815
2019-04-09T22:54:18.987Z,1554850458.987 [BR_Ping1D](INFO): timeout 5.0000
2019-04-09T22:54:18.988Z,1554850458.988 [BR_Ping1D](INFO): No UART data
2019-04-09T22:54:18.988Z,1554850458.988 [BR_Ping1D](INFO): received UART packets: 0
2019-04-09T22:54:18.988Z,1554850458.988 [BR_Ping1D](INFO): not all values verified yet
2019-04-09T22:54:19.222Z,1554850459.222 [CTD_Seabird](FAULT): Failed to initialize within timeout.
2019-04-09T22:54:19.222Z,1554850459.222 [CTD_Seabird] Communications Fault, FailCount= 2
2019-04-09T22:54:19.222Z,1554850459.222 [CTD_Seabird](ERROR): Communications Fault
2019-04-09T22:54:19.390Z,1554850459.390 [BR_Ping1D](INFO): Starting
2019-04-09T22:54:19.390Z,1554850459.390 [BR_Ping1D](INFO): readConfig
2019-04-09T22:54:19.390Z,1554850459.390 [BR_Ping1D](INFO): startup: 2
2019-04-09T22:54:19.390Z,1554850459.390 [BR_Ping1D](INFO): UART waiting for response
2019-04-09T22:54:19.390Z,1554850459.390 [BR_Ping1D](INFO): elapsed 2.0848
2019-04-09T22:54:19.391Z,1554850459.391 [BR_Ping1D](INFO): timeout 5.0000
2019-04-09T22:54:19.391Z,1554850459.391 [BR_Ping1D](INFO): No UART data
2019-04-09T22:54:19.391Z,1554850459.391 [BR_Ping1D](INFO): received UART packets: 0
2019-04-09T22:54:19.391Z,1554850459.391 [BR_Ping1D](INFO): not all values verified yet
2019-04-09T22:54:19.587Z,1554850459.587 [CBIT](ERROR): Communications Fault in component: CTD_Seabird
2019-04-09T22:54:19.635Z,1554850459.635 [CTD_Seabird](INFO): Powering down
2019-04-09T22:54:19.793Z,1554850459.793 [BR_Ping1D](INFO): Starting
2019-04-09T22:54:19.793Z,1554850459.793 [BR_Ping1D](INFO): readConfig
2019-04-09T22:54:19.793Z,1554850459.793 [BR_Ping1D](INFO): startup: 2
2019-04-09T22:54:19.793Z,1554850459.793 [BR_Ping1D](INFO): UART waiting for response
2019-04-09T22:54:19.794Z,1554850459.794 [BR_Ping1D](INFO): elapsed 2.4879
2019-04-09T22:54:19.794Z,1554850459.794 [BR_Ping1D](INFO): timeout 5.0000
2019-04-09T22:54:19.794Z,1554850459.794 [BR_Ping1D](INFO): No UART data
2019-04-09T22:54:19.794Z,1554850459.794 [BR_Ping1D](INFO): received UART packets: 0
2019-04-09T22:54:19.794Z,1554850459.794 [BR_Ping1D](INFO): not all values verified yet
2019-04-09T22:54:20.197Z,1554850460.197 [BR_Ping1D](INFO): Starting
2019-04-09T22:54:20.198Z,1554850460.198 [BR_Ping1D](INFO): readConfig
2019-04-09T22:54:20.198Z,1554850460.198 [BR_Ping1D](INFO): startup: 2
2019-04-09T22:54:20.198Z,1554850460.198 [BR_Ping1D](INFO): UART waiting for response
2019-04-09T22:54:20.198Z,1554850460.198 [BR_Ping1D](INFO): elapsed 2.8925
2019-04-09T22:54:20.198Z,1554850460.198 [BR_Ping1D](INFO): timeout 5.0000
2019-04-09T22:54:20.199Z,1554850460.199 [BR_Ping1D](INFO): No UART data
2019-04-09T22:54:20.199Z,1554850460.199 [BR_Ping1D](INFO): received UART packets: 0
2019-04-09T22:54:20.199Z,1554850460.199 [BR_Ping1D](INFO): not all values verified yet
2019-04-09T22:54:20.601Z,1554850460.601 [BR_Ping1D](INFO): Starting
2019-04-09T22:54:20.602Z,1554850460.602 [BR_Ping1D](INFO): readConfig
2019-04-09T22:54:20.602Z,1554850460.602 [BR_Ping1D](INFO): startup: 2
2019-04-09T22:54:20.602Z,1554850460.602 [BR_Ping1D](INFO): UART waiting for response
2019-04-09T22:54:20.602Z,1554850460.602 [BR_Ping1D](INFO): elapsed 3.2965
2019-04-09T22:54:20.602Z,1554850460.602 [BR_Ping1D](INFO): timeout 5.0000
2019-04-09T22:54:20.603Z,1554850460.603 [BR_Ping1D](INFO): No UART data
2019-04-09T22:54:20.603Z,1554850460.603 [BR_Ping1D](INFO): received UART packets: 0
2019-04-09T22:54:20.603Z,1554850460.603 [BR_Ping1D](INFO): not all values verified yet
2019-04-09T22:54:20.779Z,1554850460.779 [CBIT](INFO): Clearing failed state for component CTD_Seabird
2019-04-09T22:54:20.779Z,1554850460.779 [CTD_Seabird] No Fault, FailCount= 2
2019-04-09T22:54:20.978Z,1554850460.978 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2019-04-09T22:54:20.980Z,1554850460.980 [CTD_Seabird](INFO): Opening uart, block timeout 10ths=20
2019-04-09T22:54:21.008Z,1554850461.008 [BR_Ping1D](INFO): Starting
2019-04-09T22:54:21.008Z,1554850461.008 [BR_Ping1D](INFO): readConfig
2019-04-09T22:54:21.009Z,1554850461.009 [BR_Ping1D](INFO): startup: 2
2019-04-09T22:54:21.009Z,1554850461.009 [BR_Ping1D](INFO): UART waiting for response
2019-04-09T22:54:21.009Z,1554850461.009 [BR_Ping1D](INFO): elapsed 3.7032
2019-04-09T22:54:21.009Z,1554850461.009 [BR_Ping1D](INFO): timeout 5.0000
2019-04-09T22:54:21.009Z,1554850461.009 [BR_Ping1D](INFO): No UART data
2019-04-09T22:54:21.010Z,1554850461.010 [BR_Ping1D](INFO): received UART packets: 0
2019-04-09T22:54:21.010Z,1554850461.010 [BR_Ping1D](INFO): not all values verified yet
2019-04-09T22:54:21.412Z,1554850461.412 [BR_Ping1D](INFO): Starting
2019-04-09T22:54:21.412Z,1554850461.412 [BR_Ping1D](INFO): readConfig
2019-04-09T22:54:21.412Z,1554850461.412 [BR_Ping1D](INFO): startup: 2
2019-04-09T22:54:21.412Z,1554850461.412 [BR_Ping1D](INFO): UART waiting for response
2019-04-09T22:54:21.412Z,1554850461.412 [BR_Ping1D](INFO): elapsed 4.1066
2019-04-09T22:54:21.413Z,1554850461.413 [BR_Ping1D](INFO): timeout 5.0000
2019-04-09T22:54:21.413Z,1554850461.413 [BR_Ping1D](INFO): No UART data
2019-04-09T22:54:21.413Z,1554850461.413 [BR_Ping1D](INFO): received UART packets: 0
2019-04-09T22:54:21.413Z,1554850461.413 [BR_Ping1D](INFO): not all values verified yet
2019-04-09T22:54:21.814Z,1554850461.814 [BR_Ping1D](INFO): Starting
2019-04-09T22:54:21.814Z,1554850461.814 [BR_Ping1D](INFO): readConfig
2019-04-09T22:54:21.814Z,1554850461.814 [BR_Ping1D](INFO): startup: 2
2019-04-09T22:54:21.814Z,1554850461.814 [BR_Ping1D](INFO): UART waiting for response
2019-04-09T22:54:21.815Z,1554850461.815 [BR_Ping1D](INFO): elapsed 4.5089
2019-04-09T22:54:21.815Z,1554850461.815 [BR_Ping1D](INFO): timeout 5.0000
2019-04-09T22:54:21.815Z,1554850461.815 [BR_Ping1D](INFO): No UART data
2019-04-09T22:54:21.815Z,1554850461.815 [BR_Ping1D](INFO): received UART packets: 0
2019-04-09T22:54:21.815Z,1554850461.815 [BR_Ping1D](INFO): not all values verified yet
2019-04-09T22:54:22.217Z,1554850462.217 [BR_Ping1D](INFO): Starting
2019-04-09T22:54:22.217Z,1554850462.217 [BR_Ping1D](INFO): readConfig
2019-04-09T22:54:22.217Z,1554850462.217 [BR_Ping1D](INFO): startup: 2
2019-04-09T22:54:22.218Z,1554850462.218 [BR_Ping1D](INFO): UART waiting for response
2019-04-09T22:54:22.218Z,1554850462.218 [BR_Ping1D](INFO): elapsed 4.9122
2019-04-09T22:54:22.218Z,1554850462.218 [BR_Ping1D](INFO): timeout 5.0000
2019-04-09T22:54:22.218Z,1554850462.218 [BR_Ping1D](INFO): No UART data
2019-04-09T22:54:22.218Z,1554850462.218 [BR_Ping1D](INFO): received UART packets: 0
2019-04-09T22:54:22.219Z,1554850462.219 [BR_Ping1D](INFO): not all values verified yet
2019-04-09T22:54:22.621Z,1554850462.621 [BR_Ping1D](INFO): Starting
2019-04-09T22:54:22.622Z,1554850462.622 [BR_Ping1D](INFO): readConfig
2019-04-09T22:54:22.622Z,1554850462.622 [BR_Ping1D](INFO): startup: 2
2019-04-09T22:54:22.622Z,1554850462.622 [BR_Ping1D](INFO): UART waiting for response
2019-04-09T22:54:22.622Z,1554850462.622 [BR_Ping1D](INFO): elapsed 5.3166
2019-04-09T22:54:22.622Z,1554850462.622 [BR_Ping1D](INFO): timeout 5.0000
2019-04-09T22:54:22.623Z,1554850462.623 [BR_Ping1D](FAULT): Failed to set parameters in time during initialization.
2019-04-09T22:54:22.623Z,1554850462.623 [BR_Ping1D] Data Fault, FailCount= 4
2019-04-09T22:54:22.623Z,1554850462.623 [BR_Ping1D](ERROR): Data Fault
2019-04-09T22:54:22.693Z,1554850462.693 [CBIT](ERROR): Data Fault in component: BR_Ping1D
2019-04-09T22:54:23.025Z,1554850463.025 [BR_Ping1D](INFO): Stop
2019-04-09T22:54:23.025Z,1554850463.025 [BR_Ping1D](INFO): uninitialize
2019-04-09T22:54:23.025Z,1554850463.025 [BR_Ping1D](INFO): Powering down
2019-04-09T22:54:23.429Z,1554850463.429 [BR_Ping1D](INFO): Stopping
2019-04-09T22:54:23.833Z,1554850463.833 [BR_Ping1D](INFO): Stopping
2019-04-09T22:54:24.238Z,1554850464.238 [BR_Ping1D](INFO): Stopped
2019-04-09T22:54:24.303Z,1554850464.303 [CBIT](INFO): Clearing failed state for component BR_Ping1D
2019-04-09T22:54:24.303Z,1554850464.303 [BR_Ping1D] No Fault, FailCount= 4
2019-04-09T22:54:24.644Z,1554850464.644 [BR_Ping1D](INFO): Start
2019-04-09T22:54:25.049Z,1554850465.049 [BR_Ping1D](INFO): Starting
2019-04-09T22:54:25.430Z,1554850465.430 [Aanderaa_O2](FAULT): Failed to initialize within timeout.
2019-04-09T22:54:25.431Z,1554850465.431 [Aanderaa_O2] Communications Fault, FailCount= 3
2019-04-09T22:54:25.431Z,1554850465.431 [Aanderaa_O2](ERROR): Communications Fault
2019-04-09T22:54:25.449Z,1554850465.449 [BR_Ping1D](INFO): Starting
2019-04-09T22:54:25.450Z,1554850465.450 [BR_Ping1D](INFO): readConfig
2019-04-09T22:54:25.450Z,1554850465.450 [BR_Ping1D](INFO): startup: 0
2019-04-09T22:54:25.450Z,1554850465.450 [BR_Ping1D](INFO): UART setting parameters ...
2019-04-09T22:54:25.462Z,1554850465.462 [BR_Ping1D](INFO): sending request for Ping Interval: 500
2019-04-09T22:54:25.462Z,1554850465.462 [BR_Ping1D](INFO): data F401
2019-04-09T22:54:25.462Z,1554850465.462 [BR_Ping1D](INFO): test: ô

2019-04-09T22:54:25.463Z,1554850465.463 [BR_Ping1D](INFO): 42520200EC030000F4017A02
2019-04-09T22:54:25.464Z,1554850465.464 [BR_Ping1D](INFO): sending request for Auto Mode: 1
2019-04-09T22:54:25.465Z,1554850465.465 [BR_Ping1D](INFO): 42520100EB030000840115
2019-04-09T22:54:25.486Z,1554850465.486 [BR_Ping1D](INFO): sending request for Soundspeed: 1500000
2019-04-09T22:54:25.486Z,1554850465.486 [BR_Ping1D](INFO): 42520400EA03000060E31600DE02
2019-04-09T22:54:25.488Z,1554850465.488 [BR_Ping1D](INFO): sending request for Ping Enable: 1
2019-04-09T22:54:25.488Z,1554850465.488 [BR_Ping1D](INFO): 42520100EE030000870115
2019-04-09T22:54:25.579Z,1554850465.579 [CBIT](ERROR): Communications Fault in component: Aanderaa_O2
2019-04-09T22:54:25.580Z,1554850465.580 [CBIT](FAULT): Communications Fault in component: Aanderaa_O2
2019-04-09T22:54:25.954Z,1554850465.954 [Aanderaa_O2](INFO): Powering down
2019-04-09T22:54:25.974Z,1554850465.974 [BR_Ping1D](INFO): Starting
2019-04-09T22:54:25.974Z,1554850465.974 [BR_Ping1D](INFO): readConfig
2019-04-09T22:54:25.974Z,1554850465.974 [BR_Ping1D](INFO): startup: 1
2019-04-09T22:54:25.974Z,1554850465.974 [BR_Ping1D](INFO): UART requesting status
2019-04-09T22:54:25.975Z,1554850465.975 [BR_Ping1D](INFO): 42520000BA0400005201
2019-04-09T22:54:25.982Z,1554850465.982 [BR_Ping1D](INFO): 42520000BF0400005701
2019-04-09T22:54:25.990Z,1554850465.990 [BR_Ping1D](INFO): 42520000B30400004B01
2019-04-09T22:54:26.257Z,1554850466.257 [BR_Ping1D](INFO): Starting
2019-04-09T22:54:26.257Z,1554850466.257 [BR_Ping1D](INFO): readConfig
2019-04-09T22:54:26.258Z,1554850466.258 [BR_Ping1D](INFO): startup: 2
2019-04-09T22:54:26.258Z,1554850466.258 [BR_Ping1D](INFO): UART waiting for response
2019-04-09T22:54:26.258Z,1554850466.258 [BR_Ping1D](INFO): elapsed 0.8078
2019-04-09T22:54:26.258Z,1554850466.258 [BR_Ping1D](INFO): timeout 5.0000
2019-04-09T22:54:26.258Z,1554850466.258 [BR_Ping1D](INFO): No UART data
2019-04-09T22:54:26.259Z,1554850466.259 [BR_Ping1D](INFO): received UART packets: 0
2019-04-09T22:54:26.259Z,1554850466.259 [BR_Ping1D](INFO): not all values verified yet
2019-04-09T22:54:26.670Z,1554850466.670 [BR_Ping1D](INFO): Starting
2019-04-09T22:54:26.670Z,1554850466.670 [BR_Ping1D](INFO): readConfig
2019-04-09T22:54:26.670Z,1554850466.670 [BR_Ping1D](INFO): startup: 2
2019-04-09T22:54:26.670Z,1554850466.670 [BR_Ping1D](INFO): UART waiting for response
2019-04-09T22:54:26.671Z,1554850466.671 [BR_Ping1D](INFO): elapsed 1.2204
2019-04-09T22:54:26.671Z,1554850466.671 [BR_Ping1D](INFO): timeout 5.0000
2019-04-09T22:54:26.671Z,1554850466.671 [BR_Ping1D](INFO): No UART data
2019-04-09T22:54:26.671Z,1554850466.671 [BR_Ping1D](INFO): received UART packets: 0
2019-04-09T22:54:26.671Z,1554850466.671 [BR_Ping1D](INFO): not all values verified yet
2019-04-09T22:54:26.745Z,1554850466.745 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): -0.006952
CHAN A1 (24V): -0.127273
CHAN A2 (12V): -0.005650
CHAN A3 (5V): -0.002922
CHAN B0 (3.3V): -0.001320
CHAN B1 (3.15aV): -0.001565
CHAN B2 (3.15bV): -0.000913
CHAN B3 (GND): -0.000636
OPEN: -0.001080
Full Scale Calc: 4.765 mA, -1.589 mA
2019-04-09T22:54:27.067Z,1554850467.067 [BR_Ping1D](INFO): Starting
2019-04-09T22:54:27.067Z,1554850467.067 [BR_Ping1D](INFO): readConfig
2019-04-09T22:54:27.067Z,1554850467.067 [BR_Ping1D](INFO): startup: 2
2019-04-09T22:54:27.068Z,1554850467.068 [BR_Ping1D](INFO): UART waiting for response
2019-04-09T22:54:27.068Z,1554850467.068 [BR_Ping1D](INFO): elapsed 1.6175
2019-04-09T22:54:27.068Z,1554850467.068 [BR_Ping1D](INFO): timeout 5.0000
2019-04-09T22:54:27.068Z,1554850467.068 [BR_Ping1D](INFO): No UART data
2019-04-09T22:54:27.068Z,1554850467.068 [BR_Ping1D](INFO): received UART packets: 0
2019-04-09T22:54:27.068Z,1554850467.068 [BR_Ping1D](INFO): not all values verified yet
2019-04-09T22:54:27.473Z,1554850467.473 [BR_Ping1D](INFO): Starting
2019-04-09T22:54:27.473Z,1554850467.473 [BR_Ping1D](INFO): readConfig
2019-04-09T22:54:27.473Z,1554850467.473 [BR_Ping1D](INFO): startup: 2
2019-04-09T22:54:27.473Z,1554850467.473 [BR_Ping1D](INFO): UART waiting for response
2019-04-09T22:54:27.474Z,1554850467.474 [BR_Ping1D](INFO): elapsed 2.0233
2019-04-09T22:54:27.474Z,1554850467.474 [BR_Ping1D](INFO): timeout 5.0000
2019-04-09T22:54:27.474Z,1554850467.474 [BR_Ping1D](INFO): No UART data
2019-04-09T22:54:27.474Z,1554850467.474 [BR_Ping1D](INFO): received UART packets: 0
2019-04-09T22:54:27.474Z,1554850467.474 [BR_Ping1D](INFO): not all values verified yet
2019-04-09T22:54:27.873Z,1554850467.873 [BR_Ping1D](INFO): Starting
2019-04-09T22:54:27.873Z,1554850467.873 [BR_Ping1D](INFO): readConfig
2019-04-09T22:54:27.874Z,1554850467.874 [BR_Ping1D](INFO): startup: 2
2019-04-09T22:54:27.874Z,1554850467.874 [BR_Ping1D](INFO): UART waiting for response
2019-04-09T22:54:27.874Z,1554850467.874 [BR_Ping1D](INFO): elapsed 2.4238
2019-04-09T22:54:27.874Z,1554850467.874 [BR_Ping1D](INFO): timeout 5.0000
2019-04-09T22:54:27.875Z,1554850467.875 [BR_Ping1D](INFO): No UART data
2019-04-09T22:54:27.875Z,1554850467.875 [BR_Ping1D](INFO): received UART packets: 0
2019-04-09T22:54:27.875Z,1554850467.875 [BR_Ping1D](INFO): not all values verified yet
2019-04-09T22:54:28.277Z,1554850468.277 [BR_Ping1D](INFO): Starting
2019-04-09T22:54:28.278Z,1554850468.278 [BR_Ping1D](INFO): readConfig
2019-04-09T22:54:28.278Z,1554850468.278 [BR_Ping1D](INFO): startup: 2
2019-04-09T22:54:28.278Z,1554850468.278 [BR_Ping1D](INFO): UART waiting for response
2019-04-09T22:54:28.278Z,1554850468.278 [BR_Ping1D](INFO): elapsed 2.8280
2019-04-09T22:54:28.278Z,1554850468.278 [BR_Ping1D](INFO): timeout 5.0000
2019-04-09T22:54:28.279Z,1554850468.279 [BR_Ping1D](INFO): No UART data
2019-04-09T22:54:28.279Z,1554850468.279 [BR_Ping1D](INFO): received UART packets: 0
2019-04-09T22:54:28.279Z,1554850468.279 [BR_Ping1D](INFO): not all values verified yet
2019-04-09T22:54:28.681Z,1554850468.681 [BR_Ping1D](INFO): Starting
2019-04-09T22:54:28.681Z,1554850468.681 [BR_Ping1D](INFO): readConfig
2019-04-09T22:54:28.681Z,1554850468.681 [BR_Ping1D](INFO): startup: 2
2019-04-09T22:54:28.681Z,1554850468.681 [BR_Ping1D](INFO): UART waiting for response
2019-04-09T22:54:28.682Z,1554850468.682 [BR_Ping1D](INFO): elapsed 3.2313
2019-04-09T22:54:28.682Z,1554850468.682 [BR_Ping1D](INFO): timeout 5.0000
2019-04-09T22:54:28.682Z,1554850468.682 [BR_Ping1D](INFO): No UART data
2019-04-09T22:54:28.682Z,1554850468.682 [BR_Ping1D](INFO): received UART packets: 0
2019-04-09T22:54:28.682Z,1554850468.682 [BR_Ping1D](INFO): not all values verified yet
2019-04-09T22:54:29.086Z,1554850469.086 [BR_Ping1D](INFO): Starting
2019-04-09T22:54:29.086Z,1554850469.086 [BR_Ping1D](INFO): readConfig
2019-04-09T22:54:29.086Z,1554850469.086 [BR_Ping1D](INFO): startup: 2
2019-04-09T22:54:29.086Z,1554850469.086 [BR_Ping1D](INFO): UART waiting for response
2019-04-09T22:54:29.087Z,1554850469.087 [BR_Ping1D](INFO): elapsed 3.6364
2019-04-09T22:54:29.087Z,1554850469.087 [BR_Ping1D](INFO): timeout 5.0000
2019-04-09T22:54:29.087Z,1554850469.087 [BR_Ping1D](INFO): No UART data
2019-04-09T22:54:29.087Z,1554850469.087 [BR_Ping1D](INFO): received UART packets: 0
2019-04-09T22:54:29.087Z,1554850469.087 [BR_Ping1D](INFO): not all values verified yet
2019-04-09T22:54:29.501Z,1554850469.501 [BR_Ping1D](INFO): Starting
2019-04-09T22:54:29.501Z,1554850469.501 [BR_Ping1D](INFO): readConfig
2019-04-09T22:54:29.501Z,1554850469.501 [BR_Ping1D](INFO): startup: 2
2019-04-09T22:54:29.501Z,1554850469.501 [BR_Ping1D](INFO): UART waiting for response
2019-04-09T22:54:29.502Z,1554850469.502 [BR_Ping1D](INFO): elapsed 4.0513
2019-04-09T22:54:29.502Z,1554850469.502 [BR_Ping1D](INFO): timeout 5.0000
2019-04-09T22:54:29.502Z,1554850469.502 [BR_Ping1D](INFO): No UART data
2019-04-09T22:54:29.502Z,1554850469.502 [BR_Ping1D](INFO): received UART packets: 0
2019-04-09T22:54:29.502Z,1554850469.502 [BR_Ping1D](INFO): not all values verified yet
2019-04-09T22:54:29.879Z,1554850469.879 [NAL9602](INFO): NAL9602 initialized
2019-04-09T22:54:29.894Z,1554850469.894 [BR_Ping1D](INFO): Starting
2019-04-09T22:54:29.894Z,1554850469.894 [BR_Ping1D](INFO): readConfig
2019-04-09T22:54:29.894Z,1554850469.894 [BR_Ping1D](INFO): startup: 2
2019-04-09T22:54:29.895Z,1554850469.895 [BR_Ping1D](INFO): UART waiting for response
2019-04-09T22:54:29.895Z,1554850469.895 [BR_Ping1D](INFO): elapsed 4.4445
2019-04-09T22:54:29.895Z,1554850469.895 [BR_Ping1D](INFO): timeout 5.0000
2019-04-09T22:54:29.895Z,1554850469.895 [BR_Ping1D](INFO): No UART data
2019-04-09T22:54:29.895Z,1554850469.895 [BR_Ping1D](INFO): received UART packets: 0
2019-04-09T22:54:29.895Z,1554850469.895 [BR_Ping1D](INFO): not all values verified yet
2019-04-09T22:54:30.307Z,1554850470.307 [BR_Ping1D](INFO): Starting
2019-04-09T22:54:30.307Z,1554850470.307 [BR_Ping1D](INFO): readConfig
2019-04-09T22:54:30.308Z,1554850470.308 [BR_Ping1D](INFO): startup: 2
2019-04-09T22:54:30.308Z,1554850470.308 [BR_Ping1D](INFO): UART waiting for response
2019-04-09T22:54:30.308Z,1554850470.308 [BR_Ping1D](INFO): elapsed 4.8576
2019-04-09T22:54:30.308Z,1554850470.308 [BR_Ping1D](INFO): timeout 5.0000
2019-04-09T22:54:30.308Z,1554850470.308 [BR_Ping1D](INFO): No UART data
2019-04-09T22:54:30.308Z,1554850470.308 [BR_Ping1D](INFO): received UART packets: 0
2019-04-09T22:54:30.309Z,1554850470.309 [BR_Ping1D](INFO): not all values verified yet
2019-04-09T22:54:30.698Z,1554850470.698 [NAL9602](DEBUG): Fix Requested
2019-04-09T22:54:30.713Z,1554850470.713 [BR_Ping1D](INFO): Starting
2019-04-09T22:54:30.713Z,1554850470.713 [BR_Ping1D](INFO): readConfig
2019-04-09T22:54:30.713Z,1554850470.713 [BR_Ping1D](INFO): startup: 2
2019-04-09T22:54:30.713Z,1554850470.713 [BR_Ping1D](INFO): UART waiting for response
2019-04-09T22:54:30.714Z,1554850470.714 [BR_Ping1D](INFO): elapsed 5.2633
2019-04-09T22:54:30.714Z,1554850470.714 [BR_Ping1D](INFO): timeout 5.0000
2019-04-09T22:54:30.714Z,1554850470.714 [BR_Ping1D](FAULT): Failed to set parameters in time during initialization.
2019-04-09T22:54:30.714Z,1554850470.714 [BR_Ping1D] Data Fault, FailCount= 5
2019-04-09T22:54:30.714Z,1554850470.714 [BR_Ping1D](ERROR): Data Fault
2019-04-09T22:54:31.243Z,1554850471.243 [CBIT](ERROR): Data Fault in component: BR_Ping1D
2019-04-09T22:54:31.243Z,1554850471.243 [CBIT](CRITICAL): Data Fault in component: BR_Ping1D
2019-04-09T22:54:31.304Z,1554850471.304 [BR_Ping1D](INFO): Stop
2019-04-09T22:54:31.304Z,1554850471.304 [BR_Ping1D](INFO): uninitialize
2019-04-09T22:54:31.304Z,1554850471.304 [BR_Ping1D](INFO): Powering down
2019-04-09T22:54:31.477Z,1554850471.477 [CBIT](INFO): Critical error at 20190409T225431
2019-04-09T22:54:31.688Z,1554850471.688 [BR_Ping1D](INFO): Stopping
2019-04-09T22:54:32.082Z,1554850472.082 [BR_Ping1D](INFO): Stopping
2019-04-09T22:54:32.476Z,1554850472.476 [BR_Ping1D](INFO): Stopped
2019-04-09T22:54:34.050Z,1554850474.050 [CTD_Seabird](FAULT): Failed to initialize within timeout.
2019-04-09T22:54:34.050Z,1554850474.050 [CTD_Seabird] Communications Fault, FailCount= 3
2019-04-09T22:54:34.050Z,1554850474.050 [CTD_Seabird](ERROR): Communications Fault
2019-04-09T22:54:34.223Z,1554850474.223 [CBIT](ERROR): Communications Fault in component: CTD_Seabird
2019-04-09T22:54:34.223Z,1554850474.223 [CBIT](FAULT): Communications Fault in component: CTD_Seabird
2019-04-09T22:54:34.454Z,1554850474.454 [CTD_Seabird](INFO): Powering down
2019-04-09T22:54:36.094Z,1554850476.094 [AcousticModem_Benthos_ATM900](FAULT): failed to initialize, no bytes available on serial interface
2019-04-09T22:54:36.094Z,1554850476.094 [AcousticModem_Benthos_ATM900] Communications Fault, FailCount= 2
2019-04-09T22:54:36.094Z,1554850476.094 [AcousticModem_Benthos_ATM900](ERROR): Communications Fault
2019-04-09T22:54:36.363Z,1554850476.363 [CBIT](ERROR): Communications Fault in component: AcousticModem_Benthos_ATM900
2019-04-09T22:54:36.499Z,1554850476.499 [AcousticModem_Benthos_ATM900](INFO): Powering down
2019-04-09T22:54:37.399Z,1554850477.399 [CBIT](INFO): Clearing failed state for component AcousticModem_Benthos_ATM900
2019-04-09T22:54:37.400Z,1554850477.400 [AcousticModem_Benthos_ATM900] No Fault, FailCount= 2
2019-04-09T22:54:39.730Z,1554850479.730 [AcousticModem_Benthos_ATM900](INFO): Powering up
2019-04-09T22:54:39.730Z,1554850479.730 [AcousticModem_Benthos_ATM900](DEBUG): Initializing AcousticModem_Benthos_ATM900.
2019-04-09T22:55:00.008Z,1554850500.008 [AcousticModem_Benthos_ATM900](FAULT): failed to initialize, no bytes available on serial interface
2019-04-09T22:55:00.008Z,1554850500.008 [AcousticModem_Benthos_ATM900] Communications Fault, FailCount= 3
2019-04-09T22:55:00.008Z,1554850500.008 [AcousticModem_Benthos_ATM900](ERROR): Communications Fault
2019-04-09T22:55:00.215Z,1554850500.215 [CBIT](ERROR): Communications Fault in component: AcousticModem_Benthos_ATM900
2019-04-09T22:55:00.411Z,1554850500.411 [AcousticModem_Benthos_ATM900](INFO): Powering down
2019-04-09T22:55:01.331Z,1554850501.331 [CBIT](INFO): Clearing failed state for component AcousticModem_Benthos_ATM900
2019-04-09T22:55:01.331Z,1554850501.331 [AcousticModem_Benthos_ATM900] No Fault, FailCount= 3
2019-04-09T22:55:03.671Z,1554850503.671 [AcousticModem_Benthos_ATM900](INFO): Powering up
2019-04-09T22:55:03.671Z,1554850503.671 [AcousticModem_Benthos_ATM900](DEBUG): Initializing AcousticModem_Benthos_ATM900.
2019-04-09T22:55:05.715Z,1554850505.715 [BPC1](ERROR): BPC1A: No match for serial number 0486 in BPC1A's battery stick inventory (sticks 1-32 in onboard configuration file).
2019-04-09T22:55:05.717Z,1554850505.717 [BPC1](ERROR): BPC1B: No match for serial number 04D7 in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2019-04-09T22:55:05.717Z,1554850505.717 [BPC1](FAULT): Failed to parse data from all battery packs.
2019-04-09T22:55:05.717Z,1554850505.717 [BPC1] Data Fault, FailCount= 1
2019-04-09T22:55:05.717Z,1554850505.717 [BPC1](ERROR): Data Fault
2019-04-09T22:55:05.736Z,1554850505.736 [CBIT](ERROR): Data Fault in component: BPC1
2019-04-09T22:55:08.972Z,1554850508.972 [SBIT](IMPORTANT): SBIT PASSED
2019-04-09T22:55:09.027Z,1554850509.027 [CommandLine](IMPORTANT): got command configSet list
2019-04-09T22:55:09.027Z,1554850509.027 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2019-04-09T22:55:09.028Z,1554850509.028 [CommandLine](IMPORTANT): DropWeight.loadAtStartup=0 bool;

2019-04-09T22:55:09.028Z,1554850509.028 [CommandLine](IMPORTANT): Rowe_600LCM.loadAtStartup=0 bool;

2019-04-09T22:55:09.363Z,1554850509.363 [MissionManager](IMPORTANT): Started mission Startup
2019-04-09T22:55:09.364Z,1554850509.364 [Startup] Running Loop=1
2019-04-09T22:55:09.364Z,1554850509.364 [Startup](DEBUG): Aggregate::initialize Startup
2019-04-09T22:55:09.364Z,1554850509.364 [Startup:A.GoToSurface] Running Loop=1
2019-04-09T22:55:09.364Z,1554850509.364 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-04-09T22:55:09.365Z,1554850509.365 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-04-09T22:55:09.365Z,1554850509.365 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-04-09T22:55:09.365Z,1554850509.365 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-04-09T22:55:09.366Z,1554850509.366 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-04-09T22:55:09.366Z,1554850509.366 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-04-09T22:55:09.368Z,1554850509.368 [Startup:StartupSatComms] Running Loop=1
2019-04-09T22:55:09.368Z,1554850509.368 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2019-04-09T22:55:09.368Z,1554850509.368 [Startup:StartupSatComms:A] Running Loop=1
2019-04-09T22:55:09.774Z,1554850509.774 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2019-04-09T22:55:23.870Z,1554850523.870 [AcousticModem_Benthos_ATM900](FAULT): failed to initialize, no bytes available on serial interface
2019-04-09T22:55:23.871Z,1554850523.871 [AcousticModem_Benthos_ATM900] Communications Fault, FailCount= 4
2019-04-09T22:55:23.871Z,1554850523.871 [AcousticModem_Benthos_ATM900](ERROR): Communications Fault
2019-04-09T22:55:23.919Z,1554850523.919 [CBIT](ERROR): Communications Fault in component: AcousticModem_Benthos_ATM900
2019-04-09T22:55:24.274Z,1554850524.274 [AcousticModem_Benthos_ATM900](INFO): Powering down
2019-04-09T22:55:25.131Z,1554850525.131 [CBIT](INFO): Clearing failed state for component AcousticModem_Benthos_ATM900
2019-04-09T22:55:25.131Z,1554850525.131 [AcousticModem_Benthos_ATM900] No Fault, FailCount= 4
2019-04-09T22:55:27.506Z,1554850527.506 [AcousticModem_Benthos_ATM900](INFO): Powering up
2019-04-09T22:55:27.507Z,1554850527.507 [AcousticModem_Benthos_ATM900](DEBUG): Initializing AcousticModem_Benthos_ATM900.
2019-04-09T22:55:47.707Z,1554850547.707 [AcousticModem_Benthos_ATM900](FAULT): failed to initialize, no bytes available on serial interface
2019-04-09T22:55:47.707Z,1554850547.707 [AcousticModem_Benthos_ATM900] Communications Fault, FailCount= 5
2019-04-09T22:55:47.707Z,1554850547.707 [AcousticModem_Benthos_ATM900](ERROR): Communications Fault
2019-04-09T22:55:47.761Z,1554850547.761 [CBIT](ERROR): Communications Fault in component: AcousticModem_Benthos_ATM900
2019-04-09T22:55:48.110Z,1554850548.110 [AcousticModem_Benthos_ATM900](INFO): Powering down
2019-04-09T22:55:48.956Z,1554850548.956 [CBIT](INFO): Clearing failed state for component AcousticModem_Benthos_ATM900
2019-04-09T22:55:48.956Z,1554850548.956 [AcousticModem_Benthos_ATM900] No Fault, FailCount= 5
2019-04-09T22:55:51.343Z,1554850551.343 [AcousticModem_Benthos_ATM900](INFO): Powering up
2019-04-09T22:55:51.343Z,1554850551.343 [AcousticModem_Benthos_ATM900](DEBUG): Initializing AcousticModem_Benthos_ATM900.
2019-04-09T22:55:51.784Z,1554850551.784 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2019-04-09T22:55:51.784Z,1554850551.784 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2019-04-09T22:55:51.784Z,1554850551.784 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-04-09T22:55:51.786Z,1554850551.786 [DeadReckonUsingSpeedCalculator](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2019-04-09T22:55:51.786Z,1554850551.786 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 1
2019-04-09T22:55:51.786Z,1554850551.786 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2019-04-09T22:55:51.787Z,1554850551.787 [DeadReckonWithRespectToSeafloor](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2019-04-09T22:55:51.787Z,1554850551.787 [DeadReckonWithRespectToSeafloor] Software Fault, FailCount= 1
2019-04-09T22:55:51.787Z,1554850551.787 [DeadReckonWithRespectToSeafloor](ERROR): Software Fault
2019-04-09T22:55:51.846Z,1554850551.846 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-04-09T22:55:51.846Z,1554850551.846 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2019-04-09T22:55:51.847Z,1554850551.847 [CBIT](ERROR): Software Fault in component: DeadReckonWithRespectToSeafloor
2019-04-09T22:55:52.180Z,1554850552.180 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-04-09T22:55:52.180Z,1554850552.180 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2019-04-09T22:55:52.180Z,1554850552.180 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2019-04-09T22:55:52.181Z,1554850552.181 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 1
2019-04-09T22:55:52.181Z,1554850552.181 [CBIT](INFO): Clearing failed state for component DeadReckonWithRespectToSeafloor
2019-04-09T22:55:52.181Z,1554850552.181 [DeadReckonWithRespectToSeafloor] No Fault, FailCount= 1
2019-04-09T22:55:52.585Z,1554850552.585 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2019-04-09T22:56:09.552Z,1554850569.552 [Startup:StartupSatComms:A](INFO): Timed out from 2019-04-09T22:55:09.4Z
2019-04-09T22:56:09.552Z,1554850569.552 [Startup:StartupSatComms:A] Stopped
2019-04-09T22:56:09.552Z,1554850569.552 [Startup:StartupSatComms:B] Running Loop=1
2019-04-09T22:56:09.956Z,1554850569.956 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-04-09T22:56:11.542Z,1554850571.542 [AcousticModem_Benthos_ATM900](FAULT): failed to initialize, no bytes available on serial interface
2019-04-09T22:56:11.543Z,1554850571.543 [AcousticModem_Benthos_ATM900] Communications Fault, FailCount= 6
2019-04-09T22:56:11.543Z,1554850571.543 [AcousticModem_Benthos_ATM900](ERROR): Communications Fault
2019-04-09T22:56:11.600Z,1554850571.600 [CBIT](ERROR): Communications Fault in component: AcousticModem_Benthos_ATM900
2019-04-09T22:56:11.946Z,1554850571.946 [AcousticModem_Benthos_ATM900](INFO): Powering down
2019-04-09T22:56:12.803Z,1554850572.803 [CBIT](INFO): Clearing failed state for component AcousticModem_Benthos_ATM900
2019-04-09T22:56:12.803Z,1554850572.803 [AcousticModem_Benthos_ATM900] No Fault, FailCount= 6
2019-04-09T22:56:15.178Z,1554850575.178 [AcousticModem_Benthos_ATM900](INFO): Powering up
2019-04-09T22:56:15.179Z,1554850575.179 [AcousticModem_Benthos_ATM900](DEBUG): Initializing AcousticModem_Benthos_ATM900.
2019-04-09T22:56:31.137Z,1554850591.137 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.005814
2019-04-09T22:56:35.378Z,1554850595.378 [AcousticModem_Benthos_ATM900](FAULT): failed to initialize, no bytes available on serial interface
2019-04-09T22:56:35.378Z,1554850595.378 [AcousticModem_Benthos_ATM900] Communications Fault, FailCount= 7
2019-04-09T22:56:35.379Z,1554850595.379 [AcousticModem_Benthos_ATM900](ERROR): Communications Fault
2019-04-09T22:56:35.430Z,1554850595.430 [CBIT](ERROR): Communications Fault in component: AcousticModem_Benthos_ATM900
2019-04-09T22:56:35.734Z,1554850595.734 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190409T224221/Courier0004.lzma
2019-04-09T22:56:35.782Z,1554850595.782 [AcousticModem_Benthos_ATM900](INFO): Powering down
2019-04-09T22:56:36.540Z,1554850596.540 [DataOverHttps](INFO): Moved sent file to Logs/20190409T224221/Courier0004.lzma.bak
2019-04-09T22:56:36.540Z,1554850596.540 [DataOverHttps](INFO): SBD MOMSN=10520515
2019-04-09T22:56:36.641Z,1554850596.641 [CBIT](INFO): Clearing failed state for component AcousticModem_Benthos_ATM900
2019-04-09T22:56:36.641Z,1554850596.641 [AcousticModem_Benthos_ATM900] No Fault, FailCount= 7
2019-04-09T22:56:39.014Z,1554850599.014 [AcousticModem_Benthos_ATM900](INFO): Powering up
2019-04-09T22:56:39.014Z,1554850599.014 [AcousticModem_Benthos_ATM900](DEBUG): Initializing AcousticModem_Benthos_ATM900.
2019-04-09T22:56:48.663Z,1554850608.663 [DataOverHttps](INFO): Sending 548 bytes from file Logs/20190409T224504/Courier0000.lzma
2019-04-09T22:56:49.467Z,1554850609.467 [DataOverHttps](INFO): Moved sent file to Logs/20190409T224504/Courier0000.lzma.bak
2019-04-09T22:56:49.468Z,1554850609.468 [DataOverHttps](INFO): SBD MOMSN=10520517
2019-04-09T22:56:55.624Z,1554850615.624 [CBIT](INFO): Clearing failed state for component Aanderaa_O2
2019-04-09T22:56:55.624Z,1554850615.624 [Aanderaa_O2] No Fault, FailCount= 3
2019-04-09T22:56:59.215Z,1554850619.215 [AcousticModem_Benthos_ATM900](FAULT): failed to initialize, no bytes available on serial interface
2019-04-09T22:56:59.215Z,1554850619.215 [AcousticModem_Benthos_ATM900] Communications Fault, FailCount= 8
2019-04-09T22:56:59.215Z,1554850619.215 [AcousticModem_Benthos_ATM900](ERROR): Communications Fault
2019-04-09T22:56:59.268Z,1554850619.268 [CBIT](ERROR): Communications Fault in component: AcousticModem_Benthos_ATM900
2019-04-09T22:56:59.269Z,1554850619.269 [CBIT](FAULT): Communications Fault in component: AcousticModem_Benthos_ATM900
2019-04-09T22:56:59.619Z,1554850619.619 [AcousticModem_Benthos_ATM900](INFO): Powering down
2019-04-09T22:57:04.112Z,1554850624.112 [CBIT](INFO): Clearing failed state for component CTD_Seabird
2019-04-09T22:57:04.112Z,1554850624.112 [CTD_Seabird] No Fault, FailCount= 3
2019-04-09T22:57:04.502Z,1554850624.502 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2019-04-09T22:57:04.510Z,1554850624.510 [CTD_Seabird](INFO): Opening uart, block timeout 10ths=20
2019-04-09T22:57:06.082Z,1554850626.082 [Aanderaa_O2](FAULT): Failed to initialize within timeout.
2019-04-09T22:57:06.082Z,1554850626.082 [Aanderaa_O2] Communications Fault, FailCount= 1
2019-04-09T22:57:06.082Z,1554850626.082 [Aanderaa_O2](ERROR): Communications Fault
2019-04-09T22:57:06.132Z,1554850626.132 [CBIT](ERROR): Communications Fault in component: Aanderaa_O2
2019-04-09T22:57:06.606Z,1554850626.606 [Aanderaa_O2](INFO): Powering down
2019-04-09T22:57:07.327Z,1554850627.327 [CBIT](INFO): Clearing failed state for component Aanderaa_O2
2019-04-09T22:57:07.327Z,1554850627.327 [Aanderaa_O2] No Fault, FailCount= 1
2019-04-09T22:57:08.982Z,1554850628.982 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190409T224504/Courier0004.lzma
2019-04-09T22:57:09.760Z,1554850629.760 [Startup:StartupSatComms:B](INFO): Timed out from 2019-04-09T22:56:09.6Z
2019-04-09T22:57:09.760Z,1554850629.760 [Startup:StartupSatComms:B] Stopped
2019-04-09T22:57:09.760Z,1554850629.760 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2019-04-09T22:57:09.760Z,1554850629.760 [Startup:StartupSatComms] Stopped
2019-04-09T22:57:09.760Z,1554850629.760 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2019-04-09T22:57:09.761Z,1554850629.761 [Startup](INFO): Completed Startup
2019-04-09T22:57:09.761Z,1554850629.761 [MissionManager](INFO): Startup is completed.
2019-04-09T22:57:09.761Z,1554850629.761 [MissionManager](INFO): Uninitializing Mission Startup
2019-04-09T22:57:09.761Z,1554850629.761 [Startup] Stopped
2019-04-09T22:57:09.761Z,1554850629.761 [Startup](DEBUG): Aggregate::uninitialize Startup
2019-04-09T22:57:09.761Z,1554850629.761 [Startup:A.GoToSurface] Stopped
2019-04-09T22:57:09.762Z,1554850629.762 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-04-09T22:57:09.787Z,1554850629.787 [DataOverHttps](INFO): Moved sent file to Logs/20190409T224504/Courier0004.lzma.bak
2019-04-09T22:57:09.788Z,1554850629.788 [DataOverHttps](INFO): SBD MOMSN=10520545
2019-04-09T22:57:10.173Z,1554850630.173 [MissionManager](IMPORTANT): Started mission Default
2019-04-09T22:57:10.173Z,1554850630.173 [Default] Running Loop=1
2019-04-09T22:57:10.173Z,1554850630.173 [Default](DEBUG): Aggregate::initialize Default
2019-04-09T22:57:10.173Z,1554850630.173 [Default:B.GoToSurface] Running Loop=1
2019-04-09T22:57:10.173Z,1554850630.173 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-04-09T22:57:10.173Z,1554850630.173 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-04-09T22:57:10.174Z,1554850630.174 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-04-09T22:57:10.174Z,1554850630.174 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-04-09T22:57:10.175Z,1554850630.175 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-04-09T22:57:10.175Z,1554850630.175 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-04-09T22:57:10.175Z,1554850630.175 [Default:A.Wait] Running Loop=1
2019-04-09T22:57:10.175Z,1554850630.175 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-04-09T22:57:17.554Z,1554850637.554 [CTD_Seabird](FAULT): Failed to initialize within timeout.
2019-04-09T22:57:17.554Z,1554850637.554 [CTD_Seabird] Communications Fault, FailCount= 1
2019-04-09T22:57:17.554Z,1554850637.554 [CTD_Seabird](ERROR): Communications Fault
2019-04-09T22:57:17.798Z,1554850637.798 [Aanderaa_O2](FAULT): Failed to initialize within timeout.
2019-04-09T22:57:17.798Z,1554850637.798 [Aanderaa_O2] Communications Fault, FailCount= 2
2019-04-09T22:57:17.798Z,1554850637.798 [Aanderaa_O2](ERROR): Communications Fault
2019-04-09T22:57:17.832Z,1554850637.832 [CBIT](ERROR): Communications Fault in component: Aanderaa_O2
2019-04-09T22:57:17.832Z,1554850637.832 [CBIT](ERROR): Communications Fault in component: CTD_Seabird
2019-04-09T22:57:17.958Z,1554850637.958 [CTD_Seabird](INFO): Powering down
2019-04-09T22:57:18.322Z,1554850638.322 [Aanderaa_O2](INFO): Powering down
2019-04-09T22:57:19.048Z,1554850639.048 [CBIT](INFO): Clearing failed state for component Aanderaa_O2
2019-04-09T22:57:19.048Z,1554850639.048 [Aanderaa_O2] No Fault, FailCount= 2
2019-04-09T22:57:19.048Z,1554850639.048 [CBIT](INFO): Clearing failed state for component CTD_Seabird
2019-04-09T22:57:19.048Z,1554850639.048 [CTD_Seabird] No Fault, FailCount= 1
2019-04-09T22:57:19.302Z,1554850639.302 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2019-04-09T22:57:19.304Z,1554850639.304 [CTD_Seabird](INFO): Opening uart, block timeout 10ths=20
2019-04-09T22:57:23.488Z,1554850643.488 [Default:A.Wait](INFO): Done Waiting.
2019-04-09T22:57:23.488Z,1554850643.488 [Default:A.Wait] Stopped
2019-04-09T22:57:23.488Z,1554850643.488 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-04-09T22:57:23.892Z,1554850643.892 [Default:CheckIn] Running Loop=1
2019-04-09T22:57:23.892Z,1554850643.892 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-04-09T22:57:23.893Z,1554850643.893 [Default:CheckIn:Read_GPS] Running Loop=1
2019-04-09T22:57:24.336Z,1554850644.336 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2019-04-09T22:57:29.515Z,1554850649.515 [Aanderaa_O2](FAULT): Failed to initialize within timeout.
2019-04-09T22:57:29.515Z,1554850649.515 [Aanderaa_O2] Communications Fault, FailCount= 3
2019-04-09T22:57:29.515Z,1554850649.515 [Aanderaa_O2](ERROR): Communications Fault
2019-04-09T22:57:29.571Z,1554850649.571 [CBIT](ERROR): Communications Fault in component: Aanderaa_O2
2019-04-09T22:57:29.573Z,1554850649.573 [CBIT](FAULT): Communications Fault in component: Aanderaa_O2
2019-04-09T22:57:30.038Z,1554850650.038 [Aanderaa_O2](INFO): Powering down
2019-04-09T22:57:32.355Z,1554850652.355 [CTD_Seabird](FAULT): Failed to initialize within timeout.
2019-04-09T22:57:32.355Z,1554850652.355 [CTD_Seabird] Communications Fault, FailCount= 2
2019-04-09T22:57:32.355Z,1554850652.355 [CTD_Seabird](ERROR): Communications Fault
2019-04-09T22:57:32.399Z,1554850652.399 [CBIT](ERROR): Communications Fault in component: CTD_Seabird
2019-04-09T22:57:32.759Z,1554850652.759 [CTD_Seabird](INFO): Powering down
2019-04-09T22:57:33.996Z,1554850653.996 [CBIT](INFO): Clearing failed state for component CTD_Seabird
2019-04-09T22:57:33.996Z,1554850653.996 [CTD_Seabird] No Fault, FailCount= 2
2019-04-09T22:57:34.106Z,1554850654.106 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2019-04-09T22:57:34.108Z,1554850654.108 [CTD_Seabird](INFO): Opening uart, block timeout 10ths=20
2019-04-09T22:57:34.191Z,1554850654.191 [CommandLine](IMPORTANT): got command restart application
2019-04-09T22:57:35.195Z,1554850655.195 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2019-04-09T22:57:35.195Z,1554850655.195 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-04-09T22:57:35.350Z,1554850655.350 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2019-04-09T22:57:35.350Z,1554850655.350 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-04-09T22:57:35.351Z,1554850655.351 [CommandLine](INFO): Join timeout helper Thread ID is 7566
2019-04-09T22:57:35.351Z,1554850655.351 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2019-04-09T22:57:35.351Z,1554850655.351 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-04-09T22:57:35.352Z,1554850655.352 [NavChartDb](INFO): Join timeout helper Thread ID is 7567
2019-04-09T22:57:35.563Z,1554850655.563 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2019-04-09T22:57:35.563Z,1554850655.563 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-04-09T22:57:35.570Z,1554850655.570 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2019-04-09T22:57:35.570Z,1554850655.570 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-04-09T22:57:35.571Z,1554850655.571 [Radio_Surface](INFO): Join timeout helper Thread ID is 7568
2019-04-09T22:57:35.966Z,1554850655.966 [Radio_Surface](INFO): Powering down
2019-04-09T22:57:35.967Z,1554850655.967 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2019-04-09T22:57:35.967Z,1554850655.967 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-04-09T22:57:35.974Z,1554850655.974 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2019-04-09T22:57:35.974Z,1554850655.974 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-04-09T22:57:35.975Z,1554850655.975 [DataOverHttps](INFO): Join timeout helper Thread ID is 7569
2019-04-09T22:57:36.210Z,1554850656.210 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2019-04-09T22:57:36.210Z,1554850656.210 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-04-09T22:57:36.230Z,1554850656.230 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2019-04-09T22:57:36.230Z,1554850656.230 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-04-09T22:57:36.230Z,1554850656.230 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 7570
2019-04-09T22:57:36.682Z,1554850656.682 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2019-04-09T22:57:36.683Z,1554850656.683 [WetLabsBB2FL](INFO): Powering down
2019-04-09T22:57:36.683Z,1554850656.683 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-04-09T22:57:36.691Z,1554850656.691 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2019-04-09T22:57:36.691Z,1554850656.691 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2019-04-09T22:57:36.691Z,1554850656.691 [CTD_Seabird](INFO): Join timeout helper Thread ID is 7571
2019-04-09T22:57:37.118Z,1554850657.118 [CTD_Seabird](INFO): Powering down
2019-04-09T22:57:37.263Z,1554850657.263 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2019-04-09T22:57:37.263Z,1554850657.263 [CTD_Seabird](INFO): Powering down
2019-04-09T22:57:37.278Z,1554850657.278 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2019-04-09T22:57:37.291Z,1554850657.291 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2019-04-09T22:57:37.291Z,1554850657.291 [logger ThreadHandler](INFO): Thread cancelled.
2019-04-09T22:57:37.291Z,1554850657.291 [logger](INFO): Join timeout helper Thread ID is 7572
2019-04-09T22:57:37.354Z,1554850657.354 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2019-04-09T22:57:37.354Z,1554850657.354 [logger ThreadHandler](INFO): Thread cancelled.
2019-04-09T22:57:37.371Z,1554850657.371 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2019-04-09T22:57:37.371Z,1554850657.371 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-04-09T22:57:37.371Z,1554850657.371 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2019-04-09T22:57:37.371Z,1554850657.371 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-04-09T22:57:37.371Z,1554850657.371 [controlThread](INFO): Join timeout helper Thread ID is 7573
2019-04-09T22:57:37.590Z,1554850657.590 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2019-04-09T22:57:37.590Z,1554850657.590 [controlThread](DEBUG): Uninitializing ControlThread
2019-04-09T22:57:37.591Z,1554850657.591 [Aanderaa_O2](INFO): Powering down
2019-04-09T22:57:37.593Z,1554850657.593 [AcousticModem_Benthos_ATM900](INFO): Powering down
2019-04-09T22:57:37.593Z,1554850657.593 [NAL9602](INFO): Powering down
2019-04-09T22:57:37.595Z,1554850657.595 [BR_Ping1D](INFO): uninitialize
2019-04-09T22:57:37.595Z,1554850657.595 [BR_Ping1D](INFO): Powering down
2019-04-09T22:57:37.596Z,1554850657.596 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2019-04-09T22:57:37.596Z,1554850657.596 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2019-04-09T22:57:37.597Z,1554850657.597 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2019-04-09T22:57:37.597Z,1554850657.597 [MissionManager](INFO): Uninitializing Mission Default
2019-04-09T22:57:37.597Z,1554850657.597 [Default] Stopped
2019-04-09T22:57:37.598Z,1554850657.598 [Default](DEBUG): Aggregate::uninitialize Default
2019-04-09T22:57:37.598Z,1554850657.598 [Default:B.GoToSurface] Stopped
2019-04-09T22:57:37.598Z,1554850657.598 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-04-09T22:57:37.598Z,1554850657.598 [Default:CheckIn] Stopped
2019-04-09T22:57:37.598Z,1554850657.598 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-04-09T22:57:37.598Z,1554850657.598 [Default:CheckIn:Read_GPS] Stopped
2019-04-09T22:57:37.600Z,1554850657.600 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2019-04-09T22:57:37.601Z,1554850657.601 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2019-04-09T22:57:37.601Z,1554850657.601 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2019-04-09T22:57:37.601Z,1554850657.601 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2019-04-09T22:57:37.601Z,1554850657.601 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2019-04-09T22:57:37.601Z,1554850657.601 [BuoyancyServo](INFO): Powering down
2019-04-09T22:57:37.614Z,1554850657.614 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2019-04-09T22:57:37.614Z,1554850657.614 [ElevatorServo](INFO): Powering down
2019-04-09T22:57:37.615Z,1554850657.615 [MassServo](DEBUG): Uninitialize Mass Servo.
2019-04-09T22:57:37.615Z,1554850657.615 [MassServo](INFO): Powering down
2019-04-09T22:57:37.616Z,1554850657.616 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-04-09T22:57:37.616Z,1554850657.616 [RudderServo](INFO): Powering down
2019-04-09T22:57:37.617Z,1554850657.617 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2019-04-09T22:57:37.617Z,1554850657.617 [ThrusterServo](INFO): Powering down
2019-04-09T22:57:37.618Z,1554850657.618 [SBIT](DEBUG): Uninitialize SBIT Component.
2019-04-09T22:57:37.618Z,1554850657.618 [IBIT](DEBUG): Uninitialize IBIT Component.
2019-04-09T22:57:37.618Z,1554850657.618 [CBIT](DEBUG): Uninitialize CBIT Component.
2019-04-09T22:57:37.618Z,1554850657.618 [CBIT](DEBUG): Powering off loads.
2019-04-09T22:57:37.630Z,1554850657.630 [CBIT](DEBUG): Disabling WDT.
2019-04-09T22:57:37.642Z,1554850657.642 [CBIT](DEBUG): Opening all GF detection circuits.
2019-04-09T22:57:37.643Z,1554850657.643 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-04-09T22:57:37.677Z,1554850657.677 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-04-09T22:57:37.683Z,1554850657.683 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2019-04-09T22:57:37.750Z,1554850657.750 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-04-09T22:57:37.755Z,1554850657.755 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-04-09T22:57:37.806Z,1554850657.806 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-04-09T22:57:37.866Z,1554850657.866 [logger ThreadHandler](INFO): Thread cancelled.