2019-02-22T00:52:51.799Z,1550796771.799 [Supervisor](DEBUG): Initializing supervisor.
2019-02-22T00:52:51.802Z,1550796771.802 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2019-02-22T00:52:51.803Z,1550796771.803 [SyncHandler](INFO): Protected caller Thread ID is 807
2019-02-22T00:52:51.803Z,1550796771.803 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2019-02-22T00:52:51.804Z,1550796771.804 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2019-02-22T00:52:51.804Z,1550796771.804 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 808
2019-02-22T00:52:51.807Z,1550796771.807 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2019-02-22T00:52:51.818Z,1550796771.818 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2019-02-22T00:52:51.819Z,1550796771.819 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2019-02-22T00:52:51.820Z,1550796771.820 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 809
2019-02-22T00:52:51.821Z,1550796771.821 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2019-02-22T00:52:51.822Z,1550796771.822 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2019-02-22T00:52:51.822Z,1550796771.822 [logger ThreadHandler](INFO): Protected caller Thread ID is 810
2019-02-22T00:52:51.824Z,1550796771.824 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2019-02-22T00:52:51.824Z,1550796771.824 [Supervisor](INFO): Looking for Config files in directory: Config/
2019-02-22T00:52:51.828Z,1550796771.828 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2019-02-22T00:52:51.923Z,1550796771.923 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2019-02-22T00:52:51.925Z,1550796771.925 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2019-02-22T00:52:52.120Z,1550796772.120 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2019-02-22T00:52:52.121Z,1550796772.121 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2019-02-22T00:52:52.256Z,1550796772.256 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2019-02-22T00:52:52.257Z,1550796772.257 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2019-02-22T00:52:52.706Z,1550796772.706 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2019-02-22T00:52:52.707Z,1550796772.707 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2019-02-22T00:52:53.143Z,1550796773.143 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2019-02-22T00:52:53.143Z,1550796773.143 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2019-02-22T00:52:53.603Z,1550796773.603 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2019-02-22T00:52:53.603Z,1550796773.603 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2019-02-22T00:52:53.906Z,1550796773.906 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2019-02-22T00:52:53.907Z,1550796773.907 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2019-02-22T00:52:54.237Z,1550796774.237 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2019-02-22T00:52:54.239Z,1550796774.239 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2019-02-22T00:52:54.632Z,1550796774.632 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2019-02-22T00:52:54.632Z,1550796774.632 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2019-02-22T00:52:54.780Z,1550796774.780 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2019-02-22T00:52:54.781Z,1550796774.781 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2019-02-22T00:52:54.886Z,1550796774.886 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2019-02-22T00:52:54.887Z,1550796774.887 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2019-02-22T00:52:54.967Z,1550796774.967 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2019-02-22T00:52:55.068Z,1550796775.068 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2019-02-22T00:52:55.069Z,1550796775.069 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2019-02-22T00:52:55.265Z,1550796775.265 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2019-02-22T00:52:55.266Z,1550796775.266 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2019-02-22T00:52:56.441Z,1550796776.441 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2019-02-22T00:52:56.443Z,1550796776.443 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/
2019-02-22T00:52:56.447Z,1550796776.447 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg
2019-02-22T00:52:56.531Z,1550796776.531 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg
2019-02-22T00:52:56.756Z,1550796776.756 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2019-02-22T00:52:56.756Z,1550796776.756 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg
2019-02-22T00:52:56.851Z,1550796776.851 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg
2019-02-22T00:52:57.011Z,1550796777.011 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg
2019-02-22T00:52:57.213Z,1550796777.213 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg
2019-02-22T00:52:57.298Z,1550796777.298 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg
2019-02-22T00:52:57.395Z,1550796777.395 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg
2019-02-22T00:52:57.488Z,1550796777.488 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg
2019-02-22T00:52:57.638Z,1550796777.638 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg
2019-02-22T00:52:57.742Z,1550796777.742 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg
2019-02-22T00:52:57.838Z,1550796777.838 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg
2019-02-22T00:52:57.841Z,1550796777.841 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2019-02-22T00:52:57.966Z,1550796777.966 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2019-02-22T00:52:57.968Z,1550796777.968 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2019-02-22T00:52:58.111Z,1550796778.111 [BuoyancyServo] Loaded
2019-02-22T00:52:58.111Z,1550796778.111 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2019-02-22T00:52:58.126Z,1550796778.126 [ElevatorServo] Loaded
2019-02-22T00:52:58.126Z,1550796778.126 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2019-02-22T00:52:58.140Z,1550796778.140 [MassServo] Loaded
2019-02-22T00:52:58.141Z,1550796778.141 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2019-02-22T00:52:58.156Z,1550796778.156 [RudderServo] Loaded
2019-02-22T00:52:58.156Z,1550796778.156 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2019-02-22T00:52:58.170Z,1550796778.170 [ThrusterServo] Loaded
2019-02-22T00:52:58.170Z,1550796778.170 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2019-02-22T00:52:58.171Z,1550796778.171 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2019-02-22T00:52:58.171Z,1550796778.171 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2019-02-22T00:52:58.326Z,1550796778.326 [SBIT](DEBUG): Construct Startup Built In Test.
2019-02-22T00:52:58.353Z,1550796778.353 [SBIT] Loaded
2019-02-22T00:52:58.354Z,1550796778.354 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2019-02-22T00:52:58.354Z,1550796778.354 [IBIT](DEBUG): Construct Initiated Built In Test.
2019-02-22T00:52:58.382Z,1550796778.382 [IBIT] Loaded
2019-02-22T00:52:58.383Z,1550796778.383 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2019-02-22T00:52:58.386Z,1550796778.386 [CBIT](DEBUG): Construct Continuous Built In Test.
2019-02-22T00:52:58.760Z,1550796778.760 [CBIT] Loaded
2019-02-22T00:52:58.760Z,1550796778.760 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2019-02-22T00:52:58.760Z,1550796778.760 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2019-02-22T00:52:58.761Z,1550796778.761 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2019-02-22T00:52:59.010Z,1550796779.010 [Aanderaa_O2] Loaded
2019-02-22T00:52:59.010Z,1550796779.010 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2019-02-22T00:52:59.020Z,1550796779.020 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_density
2019-02-22T00:52:59.025Z,1550796779.025 [CTD_Seabird](INFO): created writer for : sea_water_density
2019-02-22T00:52:59.026Z,1550796779.026 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): depth
2019-02-22T00:52:59.031Z,1550796779.031 [CTD_Seabird](INFO): created writer for : depth
2019-02-22T00:52:59.032Z,1550796779.032 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_pressure
2019-02-22T00:52:59.037Z,1550796779.037 [CTD_Seabird](INFO): created writer for : sea_water_pressure
2019-02-22T00:52:59.037Z,1550796779.037 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_salinity
2019-02-22T00:52:59.043Z,1550796779.043 [CTD_Seabird](INFO): created writer for : sea_water_salinity
2019-02-22T00:52:59.043Z,1550796779.043 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_temperature
2019-02-22T00:52:59.048Z,1550796779.048 [CTD_Seabird](INFO): created writer for : sea_water_temperature
2019-02-22T00:52:59.049Z,1550796779.049 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_electrical_conductivity
2019-02-22T00:52:59.054Z,1550796779.054 [CTD_Seabird](INFO): created writer for : sea_water_electrical_conductivity
2019-02-22T00:52:59.055Z,1550796779.055 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): speed_of_sound_in_sea_water
2019-02-22T00:52:59.060Z,1550796779.060 [CTD_Seabird](INFO): created writer for : speed_of_sound_in_sea_water
2019-02-22T00:52:59.085Z,1550796779.085 [CTD_Seabird] Loaded
2019-02-22T00:52:59.086Z,1550796779.086 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2019-02-22T00:52:59.087Z,1550796779.087 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 406644E0
2019-02-22T00:52:59.087Z,1550796779.087 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 889
2019-02-22T00:52:59.108Z,1550796779.108 [ESPComponent] Loaded
2019-02-22T00:52:59.108Z,1550796779.108 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2019-02-22T00:52:59.122Z,1550796779.122 [PAR_Licor] Loaded
2019-02-22T00:52:59.122Z,1550796779.122 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2019-02-22T00:52:59.169Z,1550796779.169 [WetLabsBB2FL] Loaded
2019-02-22T00:52:59.169Z,1550796779.169 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2019-02-22T00:52:59.170Z,1550796779.170 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 406944E0
2019-02-22T00:52:59.171Z,1550796779.171 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 890
2019-02-22T00:52:59.172Z,1550796779.172 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2019-02-22T00:52:59.172Z,1550796779.172 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2019-02-22T00:52:59.227Z,1550796779.227 [DepthRateCalculator] Loaded
2019-02-22T00:52:59.227Z,1550796779.227 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2019-02-22T00:52:59.233Z,1550796779.233 [PitchRateCalculator] Loaded
2019-02-22T00:52:59.233Z,1550796779.233 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2019-02-22T00:52:59.248Z,1550796779.248 [SpeedCalculator] Loaded
2019-02-22T00:52:59.249Z,1550796779.249 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2019-02-22T00:52:59.269Z,1550796779.269 [TempGradientCalculator] Loaded
2019-02-22T00:52:59.269Z,1550796779.269 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2019-02-22T00:52:59.275Z,1550796779.275 [YawRateCalculator] Loaded
2019-02-22T00:52:59.275Z,1550796779.275 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2019-02-22T00:52:59.308Z,1550796779.308 [ElevatorOffsetCalculator] Loaded
2019-02-22T00:52:59.308Z,1550796779.308 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2019-02-22T00:52:59.308Z,1550796779.308 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2019-02-22T00:52:59.309Z,1550796779.309 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2019-02-22T00:52:59.350Z,1550796779.350 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2019-02-22T00:52:59.350Z,1550796779.350 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2019-02-22T00:52:59.467Z,1550796779.467 [DeadReckonUsingMultipleVelocitySources] Loaded
2019-02-22T00:52:59.467Z,1550796779.467 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2019-02-22T00:52:59.524Z,1550796779.524 [DeadReckonUsingSpeedCalculator] Loaded
2019-02-22T00:52:59.524Z,1550796779.524 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2019-02-22T00:52:59.582Z,1550796779.582 [DeadReckonWithRespectToSeafloor] Loaded
2019-02-22T00:52:59.582Z,1550796779.582 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonWithRespectToSeafloor" handled in the control thread.
2019-02-22T00:52:59.598Z,1550796779.598 [NavChart] Loaded
2019-02-22T00:52:59.599Z,1550796779.599 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2019-02-22T00:52:59.603Z,1550796779.603 [UniversalFixResidualReporter] Loaded
2019-02-22T00:52:59.603Z,1550796779.603 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2019-02-22T00:52:59.603Z,1550796779.603 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2019-02-22T00:52:59.604Z,1550796779.604 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2019-02-22T00:53:00.097Z,1550796780.097 [AcousticModem_Benthos_ATM900] Loaded
2019-02-22T00:53:00.097Z,1550796780.097 [ComponentRegistry](DEBUG): SyncComponent "AcousticModem_Benthos_ATM900" handled in the control thread.
2019-02-22T00:53:00.235Z,1550796780.235 [DataOverHttps] Loaded
2019-02-22T00:53:00.236Z,1550796780.236 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2019-02-22T00:53:00.237Z,1550796780.237 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4095B4E0
2019-02-22T00:53:00.237Z,1550796780.237 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 891
2019-02-22T00:53:00.250Z,1550796780.250 [Depth_Keller] Loaded
2019-02-22T00:53:00.250Z,1550796780.250 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2019-02-22T00:53:00.255Z,1550796780.255 [DropWeight] Loaded
2019-02-22T00:53:00.255Z,1550796780.255 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2019-02-22T00:53:00.343Z,1550796780.343 [NAL9602] Loaded
2019-02-22T00:53:00.343Z,1550796780.343 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2019-02-22T00:53:00.348Z,1550796780.348 [Onboard] Loaded
2019-02-22T00:53:00.348Z,1550796780.348 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2019-02-22T00:53:00.352Z,1550796780.352 [Radio_Surface] Loaded
2019-02-22T00:53:00.352Z,1550796780.352 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2019-02-22T00:53:00.353Z,1550796780.353 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4098B4E0
2019-02-22T00:53:00.353Z,1550796780.353 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 892
2019-02-22T00:53:00.515Z,1550796780.515 [PNI_TCM] Loaded
2019-02-22T00:53:00.517Z,1550796780.517 [ComponentRegistry](DEBUG): SyncComponent "PNI_TCM" handled in the control thread.
2019-02-22T00:53:00.728Z,1550796780.728 [Rowe_600LCM] Loaded
2019-02-22T00:53:00.729Z,1550796780.729 [ComponentRegistry](DEBUG): Component "Rowe_600LCM" handled in its own thread.
2019-02-22T00:53:00.730Z,1550796780.730 [Rowe_600LCM ThreadHandler](DEBUG): Created PCaller Thread at 409BB4E0
2019-02-22T00:53:00.730Z,1550796780.730 [Rowe_600LCM ThreadHandler](INFO): Protected caller Thread ID is 893
2019-02-22T00:53:02.485Z,1550796782.485 [BPC1] Loaded
2019-02-22T00:53:02.485Z,1550796782.485 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2019-02-22T00:53:02.485Z,1550796782.485 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2019-02-22T00:53:02.486Z,1550796782.486 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2019-02-22T00:53:02.587Z,1550796782.587 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2019-02-22T00:53:02.588Z,1550796782.588 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2019-02-22T00:53:02.673Z,1550796782.673 [VerticalControl](DEBUG): Construct VerticalControl.
2019-02-22T00:53:02.755Z,1550796782.755 [VerticalControl] Loaded
2019-02-22T00:53:02.756Z,1550796782.756 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2019-02-22T00:53:02.756Z,1550796782.756 [HorizontalControl](DEBUG): Construct HorizontalControl.
2019-02-22T00:53:02.812Z,1550796782.812 [HorizontalControl] Loaded
2019-02-22T00:53:02.812Z,1550796782.812 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2019-02-22T00:53:02.813Z,1550796782.813 [SpeedControl](DEBUG): Construct SpeedControl.
2019-02-22T00:53:02.814Z,1550796782.814 [SpeedControl] Loaded
2019-02-22T00:53:02.815Z,1550796782.815 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2019-02-22T00:53:02.815Z,1550796782.815 [LoopControl](DEBUG): Construct LoopControl.
2019-02-22T00:53:02.816Z,1550796782.816 [LoopControl] Loaded
2019-02-22T00:53:02.816Z,1550796782.816 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2019-02-22T00:53:02.817Z,1550796782.817 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2019-02-22T00:53:02.817Z,1550796782.817 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2019-02-22T00:53:02.841Z,1550796782.841 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2019-02-22T00:53:02.842Z,1550796782.842 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2019-02-22T00:53:03.158Z,1550796783.158 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2019-02-22T00:53:03.162Z,1550796783.162 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2019-02-22T00:53:03.163Z,1550796783.163 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2019-02-22T00:53:03.170Z,1550796783.170 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2019-02-22T00:53:03.171Z,1550796783.171 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40ADD4E0
2019-02-22T00:53:03.171Z,1550796783.171 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 895
2019-02-22T00:53:03.175Z,1550796783.175 [Supervisor](INFO): Main Thread ID is 803
2019-02-22T00:53:03.176Z,1550796783.176 [Supervisor](DEBUG): Running supervisor.
2019-02-22T00:53:03.176Z,1550796783.176 [CommandLine ThreadHandler](INFO): Handler Thread ID is 896
2019-02-22T00:53:03.178Z,1550796783.178 [controlThread ThreadHandler](INFO): Handler Thread ID is 897
2019-02-22T00:53:03.179Z,1550796783.179 [controlThread](DEBUG): Initializing ControlThread
2019-02-22T00:53:03.181Z,1550796783.181 [SBIT](INFO): Initialize SBIT Component.
2019-02-22T00:53:03.181Z,1550796783.181 [SBIT](IMPORTANT): git: 2019-02-11-71-g9c7399e
2019-02-22T00:53:03.181Z,1550796783.181 [SBIT](INFO): git hash: 9c7399e77d563bdda1c6e0d72b5b07cc90ba4f4b
2019-02-22T00:53:03.182Z,1550796783.182 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2019-02-22T00:53:03.183Z,1550796783.183 [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-02-22T00:53:03.184Z,1550796783.184 [SBIT](INFO): Beginning SBIT in 24.000000 seconds.
2019-02-22T00:53:03.185Z,1550796783.185 [IBIT](INFO): Initialize IBIT Component.
2019-02-22T00:53:03.186Z,1550796783.186 [CBIT](DEBUG): Initialize CBIT Component.
2019-02-22T00:53:03.187Z,1550796783.187 [logger ThreadHandler](INFO): Handler Thread ID is 898
2019-02-22T00:53:03.197Z,1550796783.197 [CBIT](DEBUG): Initialized mux pins.
2019-02-22T00:53:03.197Z,1550796783.197 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL.
2019-02-22T00:53:03.197Z,1550796783.197 [CBIT](DEBUG): Initializing the watchdog timer.
2019-02-22T00:53:03.205Z,1550796783.205 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 899
2019-02-22T00:53:03.206Z,1550796783.206 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2019-02-22T00:53:03.209Z,1550796783.209 [CTD_Seabird](INFO): Opening uart, block timeout 10ths=20
2019-02-22T00:53:03.211Z,1550796783.211 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 901
2019-02-22T00:53:03.212Z,1550796783.212 [WetLabsBB2FL](INFO): Powering down
2019-02-22T00:53:03.221Z,1550796783.221 [CBIT](CRITICAL): LAST REBOOT DUE TO WATCHDOG TIMER RESET.
2019-02-22T00:53:03.221Z,1550796783.221 [CBIT](DEBUG): Initializing heartbeat.
2019-02-22T00:53:03.265Z,1550796783.265 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 902
2019-02-22T00:53:03.266Z,1550796783.266 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2019-02-22T00:53:03.293Z,1550796783.293 [CBIT](DEBUG): Deactivating GF circuits.
2019-02-22T00:53:03.293Z,1550796783.293 [CBIT](DEBUG): Deactivating emergency mode.
2019-02-22T00:53:03.294Z,1550796783.294 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 903
2019-02-22T00:53:03.317Z,1550796783.317 [Rowe_600LCM ThreadHandler](INFO): Handler Thread ID is 904
2019-02-22T00:53:03.318Z,1550796783.318 [Rowe_600LCM](INFO): Initializing
2019-02-22T00:53:03.333Z,1550796783.333 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2019-02-22T00:53:03.333Z,1550796783.333 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2019-02-22T00:53:03.334Z,1550796783.334 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2019-02-22T00:53:03.334Z,1550796783.334 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2019-02-22T00:53:03.335Z,1550796783.335 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2019-02-22T00:53:03.335Z,1550796783.335 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2019-02-22T00:53:03.336Z,1550796783.336 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2019-02-22T00:53:03.337Z,1550796783.337 [NavChart](DEBUG): Initialize NavChart Navigation.
2019-02-22T00:53:03.338Z,1550796783.338 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2019-02-22T00:53:03.343Z,1550796783.343 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2019-02-22T00:53:03.348Z,1550796783.348 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2019-02-22T00:53:03.353Z,1550796783.353 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2019-02-22T00:53:03.356Z,1550796783.356 [LoopControl](DEBUG): Initialize LoopControlComponent.
2019-02-22T00:53:03.359Z,1550796783.359 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2019-02-22T00:53:03.472Z,1550796783.472 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 905
2019-02-22T00:53:03.689Z,1550796783.689 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2019-02-22T00:53:03.693Z,1550796783.693 [NavChartDb](FAULT): Change detected in ENC collection. Wiping NavChart Directory
2019-02-22T00:53:03.697Z,1550796783.697 [Radio_Surface](INFO): Powering up
2019-02-22T00:53:03.707Z,1550796783.707 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2019-02-22T00:53:03.708Z,1550796783.708 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US1WC07M.000
2019-02-22T00:53:03.708Z,1550796783.708 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2019-02-22T00:53:03.717Z,1550796783.717 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US2WC11M.000
2019-02-22T00:53:03.717Z,1550796783.717 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2019-02-22T00:53:03.790Z,1550796783.790 [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-02-22T00:53:03.791Z,1550796783.791 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2019-02-22T00:53:03.801Z,1550796783.801 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US3CA52M.000
2019-02-22T00:53:03.802Z,1550796783.802 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2019-02-22T00:53:03.803Z,1550796783.803 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US4CA60M.000
2019-02-22T00:53:03.803Z,1550796783.803 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2019-02-22T00:53:03.811Z,1550796783.811 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US5CA50M.000
2019-02-22T00:53:03.812Z,1550796783.812 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2019-02-22T00:53:03.813Z,1550796783.813 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US5CA61M.000
2019-02-22T00:53:03.814Z,1550796783.814 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2019-02-22T00:53:03.815Z,1550796783.815 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US5CA62M.000
2019-02-22T00:53:03.815Z,1550796783.815 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2019-02-22T00:53:03.825Z,1550796783.825 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US5CA83M.000
2019-02-22T00:53:03.828Z,1550796783.828 [NavChartDb](INFO): Setup scan of Resources/ElectronicNavigationCharts/US5CA83M.000
2019-02-22T00:53:03.922Z,1550796783.922 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2019-02-22T00:53:03.923Z,1550796783.923 [Default:A.Wait](DEBUG): Construct Wait.
2019-02-22T00:53:03.941Z,1550796783.941 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2019-02-22T00:53:03.946Z,1550796783.946 [Rowe_600LCM](INFO): Powering up
2019-02-22T00:53:04.006Z,1550796784.006 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2019-02-22T00:53:04.008Z,1550796784.008 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2019-02-22T00:53:04.030Z,1550796784.030 [Default:E.Execute](DEBUG): Construct Execute.
2019-02-22T00:53:04.070Z,1550796784.070 [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-02-22T00:53:04.075Z,1550796784.075 [controlThread](DEBUG): Component order: CycleStarter,Aanderaa_O2,ESPComponent,PAR_Licor,AcousticModem_Benthos_ATM900,Depth_Keller,DropWeight,NAL9602,Onboard,PNI_TCM,BPC1,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-02-22T00:53:04.090Z,1550796784.090 [ESPComponent](INFO): powering down ESP
2019-02-22T00:53:04.514Z,1550796784.514 [AcousticModem_Benthos_ATM900](INFO): Powering up
2019-02-22T00:53:04.514Z,1550796784.514 [AcousticModem_Benthos_ATM900](DEBUG): Initializing AcousticModem_Benthos_ATM900.
2019-02-22T00:53:04.920Z,1550796784.920 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2019-02-22T00:53:04.933Z,1550796784.933 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2019-02-22T00:53:04.934Z,1550796784.934 [ElevatorServo](DEBUG): Initializing EZServoServo.
2019-02-22T00:53:04.945Z,1550796784.945 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2019-02-22T00:53:04.946Z,1550796784.946 [MassServo](DEBUG): Initializing EZServoServo.
2019-02-22T00:53:04.957Z,1550796784.957 [MassServo](DEBUG): Initializing MassServo.
2019-02-22T00:53:04.958Z,1550796784.958 [RudderServo](DEBUG): Initializing EZServoServo.
2019-02-22T00:53:04.985Z,1550796784.985 [RudderServo](DEBUG): Initializing RudderServo.
2019-02-22T00:53:04.986Z,1550796784.986 [ThrusterServo](DEBUG): Initializing EZServoServo.
2019-02-22T00:53:05.005Z,1550796785.005 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2019-02-22T00:53:05.007Z,1550796785.007 [CommandLine](FAULT): Scheduling is paused
2019-02-22T00:53:05.008Z,1550796785.008 [CBIT](INFO): Critical error at 20190222T005303
2019-02-22T00:53:05.008Z,1550796785.008 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2019-02-22T00:53:05.119Z,1550796785.119 [DropWeight](CRITICAL): DROP WEIGHT MISSING.

2019-02-22T00:53:05.119Z,1550796785.119 [DropWeight] Hardware Fault, FailCount= 1
2019-02-22T00:53:05.119Z,1550796785.119 [DropWeight](ERROR): Hardware Fault
2019-02-22T00:53:05.168Z,1550796785.168 [CBIT](INFO): Critical error at 20190222T005305
2019-02-22T00:53:05.171Z,1550796785.171 [CBIT](ERROR): Hardware Fault in component: DropWeight
2019-02-22T00:53:05.171Z,1550796785.171 [CBIT](CRITICAL): Hardware Fault in component: DropWeight
2019-02-22T00:53:05.809Z,1550796785.809 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2019-02-22T00:53:05.809Z,1550796785.809 [RudderServo](FAULT): Rudder failed to initialize
2019-02-22T00:53:05.809Z,1550796785.809 [RudderServo] Communications Fault, FailCount= 1
2019-02-22T00:53:05.809Z,1550796785.809 [RudderServo](ERROR): Communications Fault
2019-02-22T00:53:06.014Z,1550796786.014 [CBIT](INFO): Critical error at 20190222T005305
2019-02-22T00:53:06.017Z,1550796786.017 [CBIT](ERROR): Communications Fault in component: RudderServo
2019-02-22T00:53:06.207Z,1550796786.207 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-02-22T00:53:06.208Z,1550796786.208 [RudderServo](INFO): Powering down
2019-02-22T00:53:06.977Z,1550796786.977 [PAR_Licor](INFO): A/D timeout, 8 tries over 144 ms

2019-02-22T00:53:06.977Z,1550796786.977 [PAR_Licor] Data Fault, FailCount= 1
2019-02-22T00:53:06.977Z,1550796786.977 [PAR_Licor](ERROR): Data Fault
2019-02-22T00:53:07.039Z,1550796787.039 [RudderServo](DEBUG): Initializing EZServoServo.
2019-02-22T00:53:07.161Z,1550796787.161 [RudderServo](DEBUG): Initializing RudderServo.
2019-02-22T00:53:07.165Z,1550796787.165 [CBIT](INFO): Clearing failed state for component RudderServo
2019-02-22T00:53:07.165Z,1550796787.165 [RudderServo] No Fault, FailCount= 1
2019-02-22T00:53:07.166Z,1550796787.166 [CBIT](ERROR): Data Fault in component: PAR_Licor
2019-02-22T00:53:07.166Z,1550796787.166 [CBIT](INFO): Clearing failed state for component PAR_Licor
2019-02-22T00:53:07.166Z,1550796787.166 [PAR_Licor] No Fault, FailCount= 1
2019-02-22T00:53:07.353Z,1550796787.353 [Aanderaa_O2](INFO): Powering down
2019-02-22T00:53:08.027Z,1550796788.027 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2019-02-22T00:53:08.200Z,1550796788.200 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null &
2019-02-22T00:53:12.213Z,1550796792.213 [AcousticModem_Benthos_ATM900](DEBUG): 
2019-02-22T00:53:13.194Z,1550796793.194 [CBIT](CRITICAL): Environmental Failure. Press:14.676660 PSI. Humidity:17%. Temp:26 C. ABORTING MISSION
2019-02-22T00:53:13.431Z,1550796793.431 [AcousticModem_Benthos_ATM900](DEBUG): Teledyne Benthos ATM-900 Series OEM w/burn wire
2019-02-22T00:53:13.431Z,1550796793.431 [AcousticModem_Benthos_ATM900](DEBUG): MF Frequency Band
2019-02-22T00:53:13.432Z,1550796793.432 [AcousticModem_Benthos_ATM900](DEBUG): Standard version 8.6.3
2019-02-22T00:53:13.432Z,1550796793.432 [AcousticModem_Benthos_ATM900](DEBUG): Feb 12 2019 22:20:13 
2019-02-22T00:53:13.527Z,1550796793.527 [CBIT](INFO): Critical error at 20190222T005313
2019-02-22T00:53:13.845Z,1550796793.845 [AcousticModem_Benthos_ATM900](DEBUG): WARNING: battery low
2019-02-22T00:53:14.641Z,1550796794.641 [AcousticModem_Benthos_ATM900](INFO): entering command mode
2019-02-22T00:53:15.045Z,1550796795.045 [AcousticModem_Benthos_ATM900](DEBUG): checking for command mode acknowledgment
2019-02-22T00:53:15.046Z,1550796795.046 [AcousticModem_Benthos_ATM900](DEBUG): read user prompt 1: user:1>
2019-02-22T00:53:15.046Z,1550796795.046 [AcousticModem_Benthos_ATM900](INFO): command mode acknowledged
2019-02-22T00:53:15.450Z,1550796795.450 [AcousticModem_Benthos_ATM900](INFO): setting local address to 3
2019-02-22T00:53:15.853Z,1550796795.853 [AcousticModem_Benthos_ATM900](DEBUG): checking for local address setting acknowledgment
2019-02-22T00:53:15.854Z,1550796795.854 [AcousticModem_Benthos_ATM900](INFO): set local address to 3
2019-02-22T00:53:16.258Z,1550796796.258 [AcousticModem_Benthos_ATM900](DEBUG): read user prompt 2: user:2>
2019-02-22T00:53:21.327Z,1550796801.327 [NavChartDb](INFO): Done scanning features of Resources/ElectronicNavigationCharts/US5CA83M.000
2019-02-22T00:53:27.634Z,1550796807.634 [SBIT](IMPORTANT): Beginning Startup BIT
2019-02-22T00:53:27.638Z,1550796807.638 [CBIT](IMPORTANT): Beginning ground fault scan
2019-02-22T00:53:30.617Z,1550796810.617 [NAL9602](INFO): Powering up NAL9602
2019-02-22T00:53:38.390Z,1550796818.390 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.009218
CHAN A1 (24V): -0.012443
CHAN A2 (12V): -0.004995
CHAN A3 (5V): -0.002018
CHAN B0 (3.3V): -0.000886
CHAN B1 (3.15aV): -0.001225
CHAN B2 (3.15bV): -0.001203
CHAN B3 (GND): 0.000809
OPEN: 0.004179
Full Scale Calc: 4.765 mA, -1.589 mA
2019-02-22T00:53:41.522Z,1550796821.522 [NAL9602](INFO): NAL9602 initialized
2019-02-22T00:53:42.341Z,1550796822.341 [NAL9602](DEBUG): Fix Requested
2019-02-22T00:53:45.504Z,1550796825.504 [NavChartDb](INFO): # of records loaded: 5000
2019-02-22T00:54:21.476Z,1550796861.476 [SBIT](IMPORTANT): SBIT PASSED
2019-02-22T00:54:21.570Z,1550796861.570 [CommandLine](IMPORTANT): got command configSet list
2019-02-22T00:54:21.570Z,1550796861.570 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2019-02-22T00:54:21.573Z,1550796861.573 [CommandLine](IMPORTANT): DropWeight.loadAtStartup=0 bool;

2019-02-22T00:54:21.574Z,1550796861.574 [CommandLine](IMPORTANT): Rowe_600LCM.loadAtStartup=0 bool;

2019-02-22T00:54:21.976Z,1550796861.976 [MissionManager](IMPORTANT): Started mission Startup
2019-02-22T00:54:21.976Z,1550796861.976 [Startup] Running Loop=1
2019-02-22T00:54:21.977Z,1550796861.977 [Startup](DEBUG): Aggregate::initialize Startup
2019-02-22T00:54:21.977Z,1550796861.977 [Startup:A.GoToSurface] Running Loop=1
2019-02-22T00:54:21.977Z,1550796861.977 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-02-22T00:54:21.978Z,1550796861.978 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-02-22T00:54:21.978Z,1550796861.978 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-02-22T00:54:21.978Z,1550796861.978 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-02-22T00:54:21.979Z,1550796861.979 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-02-22T00:54:21.979Z,1550796861.979 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-02-22T00:54:21.980Z,1550796861.980 [Startup:StartupSatComms] Running Loop=1
2019-02-22T00:54:21.981Z,1550796861.981 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2019-02-22T00:54:21.981Z,1550796861.981 [Startup:StartupSatComms:A] Running Loop=1
2019-02-22T00:54:22.312Z,1550796862.312 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2019-02-22T00:54:25.686Z,1550796865.686 [NavChartDb](INFO): # of records loaded: 10000
2019-02-22T00:54:31.957Z,1550796871.957 [NavChartDb](INFO): Calculating coverage of Resources/ElectronicNavigationCharts/US5CA83M.000
2019-02-22T00:54:35.498Z,1550796875.498 [NavChartDb](INFO): # of records loaded: 15000
2019-02-22T00:54:37.870Z,1550796877.870 [NavChartDb](INFO): Done scanning edges of Resources/ElectronicNavigationCharts/US5CA83M.000
2019-02-22T00:54:43.357Z,1550796883.357 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-02-22T00:55:04.718Z,1550796904.718 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2019-02-22T00:55:04.718Z,1550796904.718 [Rowe_600LCM] Communications Fault, FailCount= 1
2019-02-22T00:55:04.718Z,1550796904.718 [Rowe_600LCM](ERROR): Communications Fault
2019-02-22T00:55:04.778Z,1550796904.778 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2019-02-22T00:55:05.121Z,1550796905.121 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2019-02-22T00:55:05.289Z,1550796905.289 [Rowe_600LCM](INFO): Powering down
2019-02-22T00:55:06.814Z,1550796906.814 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2019-02-22T00:55:06.814Z,1550796906.814 [Rowe_600LCM] No Fault, FailCount= 1
2019-02-22T00:55:06.905Z,1550796906.905 [Rowe_600LCM](INFO): Initializing
2019-02-22T00:55:06.906Z,1550796906.906 [Rowe_600LCM](INFO): Powering up
2019-02-22T00:55:11.053Z,1550796911.053 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2019-02-22T00:55:11.230Z,1550796911.230 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null &
2019-02-22T00:55:16.163Z,1550796916.163 [NavChartDb](INFO): Done scanning nodes of Resources/ElectronicNavigationCharts/US5CA83M.000
2019-02-22T00:55:16.179Z,1550796916.179 [NavChartDb](INFO): # of records loaded: 19732
2019-02-22T00:55:16.193Z,1550796916.193 [NavChartDb](IMPORTANT): Loaded Electronic Nav Chart data from US5CA83M.000
2019-02-22T00:55:16.226Z,1550796916.226 [NavChartDb](INFO): Setup scan of Resources/ElectronicNavigationCharts/US5CA62M.000
2019-02-22T00:55:22.068Z,1550796922.068 [Startup:StartupSatComms:A](INFO): Timed out from 2019-02-22T00:54:21.0Z
2019-02-22T00:55:22.068Z,1550796922.068 [Startup:StartupSatComms:A] Stopped
2019-02-22T00:55:22.068Z,1550796922.068 [Startup:StartupSatComms:B] Running Loop=1
2019-02-22T00:55:22.474Z,1550796922.474 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-02-22T00:55:24.211Z,1550796924.211 [NavChartDb](INFO): Done scanning features of Resources/ElectronicNavigationCharts/US5CA62M.000
2019-02-22T00:55:32.455Z,1550796932.455 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.005097
2019-02-22T00:55:37.170Z,1550796937.170 [PAR_Licor](INFO): A/D timeout, 8 tries over 138 ms

2019-02-22T00:55:37.171Z,1550796937.171 [PAR_Licor] Data Fault, FailCount= 1
2019-02-22T00:55:37.172Z,1550796937.172 [PAR_Licor](ERROR): Data Fault
2019-02-22T00:55:37.354Z,1550796937.354 [CBIT](ERROR): Data Fault in component: PAR_Licor
2019-02-22T00:55:37.354Z,1550796937.354 [CBIT](INFO): Clearing failed state for component PAR_Licor
2019-02-22T00:55:37.354Z,1550796937.354 [PAR_Licor] No Fault, FailCount= 1
2019-02-22T00:55:47.772Z,1550796947.772 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20190222T004247/Courier0004.lzma
2019-02-22T00:55:48.579Z,1550796948.579 [DataOverHttps](INFO): Moved sent file to Logs/20190222T004247/Courier0004.lzma.bak
2019-02-22T00:55:48.579Z,1550796948.579 [DataOverHttps](INFO): SBD MOMSN=10068445
2019-02-22T00:55:51.658Z,1550796951.658 [BPC1](ERROR): BPC1B: No match for serial number 1717 in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2019-02-22T00:55:52.302Z,1550796952.302 [NavChartDb](INFO): # of records loaded: 5000
2019-02-22T00:56:03.382Z,1550796963.382 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2019-02-22T00:56:03.382Z,1550796963.382 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-02-22T00:56:03.383Z,1550796963.383 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 1
2019-02-22T00:56:03.383Z,1550796963.383 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2019-02-22T00:56:03.384Z,1550796963.384 [DeadReckonWithRespectToSeafloor] Software Fault, FailCount= 1
2019-02-22T00:56:03.384Z,1550796963.384 [DeadReckonWithRespectToSeafloor](ERROR): Software Fault
2019-02-22T00:56:03.439Z,1550796963.439 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-02-22T00:56:03.439Z,1550796963.439 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2019-02-22T00:56:03.439Z,1550796963.439 [CBIT](ERROR): Software Fault in component: DeadReckonWithRespectToSeafloor
2019-02-22T00:56:03.848Z,1550796963.848 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-02-22T00:56:03.848Z,1550796963.848 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2019-02-22T00:56:03.848Z,1550796963.848 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2019-02-22T00:56:03.848Z,1550796963.848 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 1
2019-02-22T00:56:03.857Z,1550796963.857 [CBIT](INFO): Clearing failed state for component DeadReckonWithRespectToSeafloor
2019-02-22T00:56:03.857Z,1550796963.857 [DeadReckonWithRespectToSeafloor] No Fault, FailCount= 1
2019-02-22T00:56:04.188Z,1550796964.188 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2019-02-22T00:56:06.928Z,1550796966.928 [DataOverHttps](INFO): Sending 252 bytes from file Logs/20190222T005251/Courier0000.lzma
2019-02-22T00:56:07.734Z,1550796967.734 [DataOverHttps](INFO): Moved sent file to Logs/20190222T005251/Courier0000.lzma.bak
2019-02-22T00:56:07.734Z,1550796967.734 [DataOverHttps](INFO): SBD MOMSN=10068447
2019-02-22T00:56:10.967Z,1550796970.967 [NavChartDb](INFO): # of records loaded: 10000
2019-02-22T00:56:22.388Z,1550796982.388 [Startup:StartupSatComms:B](INFO): Timed out from 2019-02-22T00:55:22.1Z
2019-02-22T00:56:22.388Z,1550796982.388 [Startup:StartupSatComms:B] Stopped
2019-02-22T00:56:22.388Z,1550796982.388 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2019-02-22T00:56:22.388Z,1550796982.388 [Startup:StartupSatComms] Stopped
2019-02-22T00:56:22.388Z,1550796982.388 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2019-02-22T00:56:22.397Z,1550796982.397 [Startup](INFO): Completed Startup
2019-02-22T00:56:22.397Z,1550796982.397 [MissionManager](INFO): Startup is completed.
2019-02-22T00:56:22.398Z,1550796982.398 [MissionManager](INFO): Uninitializing Mission Startup
2019-02-22T00:56:22.398Z,1550796982.398 [Startup] Stopped
2019-02-22T00:56:22.398Z,1550796982.398 [Startup](DEBUG): Aggregate::uninitialize Startup
2019-02-22T00:56:22.398Z,1550796982.398 [Startup:A.GoToSurface] Stopped
2019-02-22T00:56:22.398Z,1550796982.398 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-02-22T00:56:22.783Z,1550796982.783 [MissionManager](IMPORTANT): Started mission Default
2019-02-22T00:56:22.783Z,1550796982.783 [Default] Running Loop=1
2019-02-22T00:56:22.783Z,1550796982.783 [Default](DEBUG): Aggregate::initialize Default
2019-02-22T00:56:22.784Z,1550796982.784 [Default:B.GoToSurface] Running Loop=1
2019-02-22T00:56:22.784Z,1550796982.784 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-02-22T00:56:22.784Z,1550796982.784 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-02-22T00:56:22.784Z,1550796982.784 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-02-22T00:56:22.793Z,1550796982.793 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-02-22T00:56:22.793Z,1550796982.793 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-02-22T00:56:22.794Z,1550796982.794 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-02-22T00:56:22.794Z,1550796982.794 [Default:A.Wait] Running Loop=1
2019-02-22T00:56:22.794Z,1550796982.794 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-02-22T00:56:28.158Z,1550796988.158 [DataOverHttps](INFO): Sending 93 bytes from file Logs/20190222T003635/Express0005.lzma
2019-02-22T00:56:28.750Z,1550796988.750 [NavChartDb](INFO): # of records loaded: 15000
2019-02-22T00:56:28.966Z,1550796988.966 [DataOverHttps](INFO): Moved sent file to Logs/20190222T003635/Express0005.lzma.bak
2019-02-22T00:56:28.967Z,1550796988.967 [DataOverHttps](INFO): SBD MOMSN=10068465
2019-02-22T00:56:36.114Z,1550796996.114 [Default:A.Wait](INFO): Done Waiting.
2019-02-22T00:56:36.114Z,1550796996.114 [Default:A.Wait] Stopped
2019-02-22T00:56:36.115Z,1550796996.115 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-02-22T00:56:36.628Z,1550796996.628 [Default:CheckIn] Running Loop=1
2019-02-22T00:56:36.628Z,1550796996.628 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-02-22T00:56:36.629Z,1550796996.629 [Default:CheckIn:Read_GPS] Running Loop=1
2019-02-22T00:56:36.962Z,1550796996.962 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2019-02-22T00:56:44.410Z,1550797004.410 [NavChartDb](INFO): # of records loaded: 20000
2019-02-22T00:57:01.854Z,1550797021.854 [NavChartDb](INFO): # of records loaded: 25000
2019-02-22T00:57:07.477Z,1550797027.477 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2019-02-22T00:57:07.477Z,1550797027.477 [Rowe_600LCM] Communications Fault, FailCount= 2
2019-02-22T00:57:07.477Z,1550797027.477 [Rowe_600LCM](ERROR): Communications Fault
2019-02-22T00:57:07.666Z,1550797027.666 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2019-02-22T00:57:07.881Z,1550797027.881 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2019-02-22T00:57:08.155Z,1550797028.155 [Rowe_600LCM](INFO): Powering down
2019-02-22T00:57:09.674Z,1550797029.674 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2019-02-22T00:57:09.674Z,1550797029.674 [Rowe_600LCM] No Fault, FailCount= 2
2019-02-22T00:57:09.769Z,1550797029.769 [Rowe_600LCM](INFO): Initializing
2019-02-22T00:57:09.770Z,1550797029.770 [Rowe_600LCM](INFO): Powering up
2019-02-22T00:57:12.309Z,1550797032.309 [NavChartDb](INFO): Calculating coverage of Resources/ElectronicNavigationCharts/US5CA62M.000
2019-02-22T00:57:13.954Z,1550797033.954 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2019-02-22T00:57:14.039Z,1550797034.039 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null &
2019-02-22T00:57:14.175Z,1550797034.175 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-02-22T00:57:18.421Z,1550797038.421 [NavChartDb](INFO): Done scanning edges of Resources/ElectronicNavigationCharts/US5CA62M.000
2019-02-22T00:57:18.716Z,1550797038.716 [NavChartDb](INFO): # of records loaded: 30000
2019-02-22T00:57:41.004Z,1550797061.004 [NavChartDb](INFO): # of records loaded: 35000
2019-02-22T00:57:56.179Z,1550797076.179 [NavChartDb](INFO): Done scanning nodes of Resources/ElectronicNavigationCharts/US5CA62M.000
2019-02-22T00:57:56.205Z,1550797076.205 [NavChartDb](INFO): # of records loaded: 37376
2019-02-22T00:57:56.234Z,1550797076.234 [NavChartDb](IMPORTANT): Loaded Electronic Nav Chart data from US5CA62M.000
2019-02-22T00:57:56.282Z,1550797076.282 [NavChartDb](INFO): Setup scan of Resources/ElectronicNavigationCharts/US5CA61M.000
2019-02-22T00:57:58.205Z,1550797078.205 [PAR_Licor](INFO): A/D timeout, 10 tries over 148 ms

2019-02-22T00:57:58.205Z,1550797078.205 [PAR_Licor] Data Fault, FailCount= 1
2019-02-22T00:57:58.205Z,1550797078.205 [PAR_Licor](ERROR): Data Fault
2019-02-22T00:57:58.273Z,1550797078.273 [CBIT](ERROR): Data Fault in component: PAR_Licor
2019-02-22T00:57:58.273Z,1550797078.273 [CBIT](INFO): Clearing failed state for component PAR_Licor
2019-02-22T00:57:58.273Z,1550797078.273 [PAR_Licor] No Fault, FailCount= 1
2019-02-22T00:58:04.159Z,1550797084.159 [NavChartDb](INFO): Done scanning features of Resources/ElectronicNavigationCharts/US5CA61M.000
2019-02-22T00:58:22.478Z,1550797102.478 [NavChartDb](INFO): # of records loaded: 5000
2019-02-22T00:58:32.201Z,1550797112.201 [NavChartDb](INFO): # of records loaded: 10000
2019-02-22T00:58:43.833Z,1550797123.833 [NavChartDb](INFO): Calculating coverage of Resources/ElectronicNavigationCharts/US5CA61M.000
2019-02-22T00:58:45.362Z,1550797125.362 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-02-22T00:58:45.738Z,1550797125.738 [NavChartDb](INFO): Done scanning edges of Resources/ElectronicNavigationCharts/US5CA61M.000
2019-02-22T00:58:46.309Z,1550797126.309 [NAL9602](DEBUG): Fix Requested
2019-02-22T00:58:47.395Z,1550797127.395 [NavChartDb](INFO): # of records loaded: 15000
2019-02-22T00:58:50.689Z,1550797130.689 [NAL9602](DEBUG): Fix Requested
2019-02-22T00:58:53.885Z,1550797133.885 [NAL9602](DEBUG): Fix Requested
2019-02-22T00:58:56.721Z,1550797136.721 [NAL9602](DEBUG): Fix Requested
2019-02-22T00:58:59.921Z,1550797139.921 [NAL9602](DEBUG): Fix Requested
2019-02-22T00:59:00.283Z,1550797140.283 [NavChartDb](INFO): Done scanning nodes of Resources/ElectronicNavigationCharts/US5CA61M.000
2019-02-22T00:59:00.497Z,1550797140.497 [NavChartDb](INFO): # of records loaded: 16998
2019-02-22T00:59:00.501Z,1550797140.501 [NavChartDb](IMPORTANT): Loaded Electronic Nav Chart data from US5CA61M.000
2019-02-22T00:59:00.502Z,1550797140.502 [NavChartDb](INFO): Setup scan of Resources/ElectronicNavigationCharts/US5CA50M.000
2019-02-22T00:59:02.745Z,1550797142.745 [NAL9602](DEBUG): Fix Requested
2019-02-22T00:59:04.429Z,1550797144.429 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2019-02-22T00:59:04.429Z,1550797144.429 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-02-22T00:59:04.430Z,1550797144.430 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 2
2019-02-22T00:59:04.431Z,1550797144.431 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2019-02-22T00:59:04.432Z,1550797144.432 [DeadReckonWithRespectToSeafloor] Software Fault, FailCount= 2
2019-02-22T00:59:04.432Z,1550797144.432 [DeadReckonWithRespectToSeafloor](ERROR): Software Fault
2019-02-22T00:59:04.454Z,1550797144.454 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-02-22T00:59:04.454Z,1550797144.454 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2019-02-22T00:59:04.455Z,1550797144.455 [CBIT](ERROR): Software Fault in component: DeadReckonWithRespectToSeafloor
2019-02-22T00:59:04.964Z,1550797144.964 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-02-22T00:59:04.964Z,1550797144.964 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2019-02-22T00:59:04.964Z,1550797144.964 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2019-02-22T00:59:04.964Z,1550797144.964 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 2
2019-02-22T00:59:04.969Z,1550797144.969 [CBIT](INFO): Clearing failed state for component DeadReckonWithRespectToSeafloor
2019-02-22T00:59:04.969Z,1550797144.969 [DeadReckonWithRespectToSeafloor] No Fault, FailCount= 2
2019-02-22T00:59:05.257Z,1550797145.257 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2019-02-22T00:59:05.977Z,1550797145.977 [NAL9602](DEBUG): Fix Requested
2019-02-22T00:59:07.292Z,1550797147.292 [NavChartDb](INFO): Done scanning features of Resources/ElectronicNavigationCharts/US5CA50M.000
2019-02-22T00:59:08.821Z,1550797148.821 [NAL9602](DEBUG): Fix Requested
2019-02-22T00:59:10.313Z,1550797150.313 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2019-02-22T00:59:10.313Z,1550797150.313 [Rowe_600LCM] Communications Fault, FailCount= 3
2019-02-22T00:59:10.313Z,1550797150.313 [Rowe_600LCM](ERROR): Communications Fault
2019-02-22T00:59:10.488Z,1550797150.488 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2019-02-22T00:59:10.717Z,1550797150.717 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2019-02-22T00:59:10.930Z,1550797150.930 [Rowe_600LCM](INFO): Powering down
2019-02-22T00:59:11.633Z,1550797151.633 [NAL9602](DEBUG): Fix Requested
2019-02-22T00:59:12.520Z,1550797152.520 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2019-02-22T00:59:12.520Z,1550797152.520 [Rowe_600LCM] No Fault, FailCount= 3
2019-02-22T00:59:12.545Z,1550797152.545 [Rowe_600LCM](INFO): Initializing
2019-02-22T00:59:12.545Z,1550797152.545 [Rowe_600LCM](INFO): Powering up
2019-02-22T00:59:13.674Z,1550797153.674 [NAL9602](DEBUG): Fix Requested
2019-02-22T00:59:15.689Z,1550797155.689 [NAL9602](DEBUG): Fix Requested
2019-02-22T00:59:16.750Z,1550797156.750 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2019-02-22T00:59:16.852Z,1550797156.852 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null &
2019-02-22T00:59:17.693Z,1550797157.693 [NAL9602](DEBUG): Fix Requested
2019-02-22T00:59:20.925Z,1550797160.925 [NAL9602](DEBUG): Fix Requested
2019-02-22T00:59:21.416Z,1550797161.416 [NavChartDb](INFO): # of records loaded: 5000
2019-02-22T00:59:23.753Z,1550797163.753 [NAL9602](DEBUG): Fix Requested
2019-02-22T00:59:27.001Z,1550797167.001 [NAL9602](DEBUG): Fix Requested
2019-02-22T00:59:29.582Z,1550797169.582 [NavChartDb](INFO): # of records loaded: 10000
2019-02-22T00:59:29.816Z,1550797169.816 [NAL9602](DEBUG): Fix Requested
2019-02-22T00:59:32.641Z,1550797172.641 [NAL9602](DEBUG): Fix Requested
2019-02-22T00:59:35.973Z,1550797175.973 [NAL9602](DEBUG): Fix Requested
2019-02-22T00:59:38.761Z,1550797178.761 [NAL9602](DEBUG): Fix Requested
2019-02-22T00:59:40.619Z,1550797180.619 [NavChartDb](INFO): # of records loaded: 15000
2019-02-22T00:59:41.949Z,1550797181.949 [NAL9602](DEBUG): Fix Requested
2019-02-22T00:59:44.765Z,1550797184.765 [NAL9602](DEBUG): Fix Requested
2019-02-22T00:59:47.993Z,1550797187.993 [NAL9602](DEBUG): Fix Requested
2019-02-22T00:59:48.281Z,1550797188.281 [NavChartDb](INFO): # of records loaded: 20000
2019-02-22T00:59:50.837Z,1550797190.837 [NAL9602](DEBUG): Fix Requested
2019-02-22T00:59:54.061Z,1550797194.061 [NAL9602](DEBUG): Fix Requested
2019-02-22T00:59:55.604Z,1550797195.604 [NavChartDb](INFO): # of records loaded: 25000
2019-02-22T00:59:56.881Z,1550797196.881 [NAL9602](DEBUG): Fix Requested
2019-02-22T00:59:59.709Z,1550797199.709 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:00:01.729Z,1550797201.729 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:00:03.079Z,1550797203.079 [NavChartDb](INFO): # of records loaded: 30000
2019-02-22T01:00:03.749Z,1550797203.749 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:00:06.981Z,1550797206.981 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:00:09.809Z,1550797209.809 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:00:13.085Z,1550797213.085 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:00:15.877Z,1550797215.877 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:00:18.804Z,1550797218.804 [NavChartDb](INFO): # of records loaded: 35000
2019-02-22T01:00:19.161Z,1550797219.161 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:00:22.017Z,1550797222.017 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:00:24.829Z,1550797224.829 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:00:28.049Z,1550797228.049 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:00:29.475Z,1550797229.475 [NavChartDb](INFO): # of records loaded: 40000
2019-02-22T01:00:30.893Z,1550797230.893 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:00:34.109Z,1550797234.109 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:00:36.937Z,1550797236.937 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:00:39.765Z,1550797239.765 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:00:41.644Z,1550797241.644 [NavChartDb](INFO): # of records loaded: 45000
2019-02-22T01:00:41.785Z,1550797241.785 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:00:43.805Z,1550797243.805 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:00:47.053Z,1550797247.053 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:00:49.484Z,1550797249.484 [NavChartDb](INFO): # of records loaded: 50000
2019-02-22T01:00:49.881Z,1550797249.881 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:00:53.114Z,1550797253.114 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:00:55.925Z,1550797255.925 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:00:59.165Z,1550797259.165 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:01:00.877Z,1550797260.877 [NavChartDb](INFO): # of records loaded: 55000
2019-02-22T01:01:02.089Z,1550797262.089 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:01:02.588Z,1550797262.588 [NavChartDb](INFO): Calculating coverage of Resources/ElectronicNavigationCharts/US5CA50M.000
2019-02-22T01:01:04.897Z,1550797264.897 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:01:08.093Z,1550797268.093 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:01:09.822Z,1550797269.822 [NavChartDb](INFO): Done scanning edges of Resources/ElectronicNavigationCharts/US5CA50M.000
2019-02-22T01:01:10.889Z,1550797270.889 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:01:13.169Z,1550797273.169 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2019-02-22T01:01:13.169Z,1550797273.169 [Rowe_600LCM] Communications Fault, FailCount= 4
2019-02-22T01:01:13.169Z,1550797273.169 [Rowe_600LCM](ERROR): Communications Fault
2019-02-22T01:01:13.349Z,1550797273.349 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2019-02-22T01:01:13.573Z,1550797273.573 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2019-02-22T01:01:13.771Z,1550797273.771 [Rowe_600LCM](INFO): Powering down
2019-02-22T01:01:14.109Z,1550797274.109 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:01:14.698Z,1550797274.698 [NavChartDb](INFO): # of records loaded: 60000
2019-02-22T01:01:15.348Z,1550797275.348 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2019-02-22T01:01:15.348Z,1550797275.348 [Rowe_600LCM] No Fault, FailCount= 4
2019-02-22T01:01:15.385Z,1550797275.385 [Rowe_600LCM](INFO): Initializing
2019-02-22T01:01:15.385Z,1550797275.385 [Rowe_600LCM](INFO): Powering up
2019-02-22T01:01:16.956Z,1550797276.956 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:01:19.567Z,1550797279.567 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2019-02-22T01:01:19.652Z,1550797279.652 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null &
2019-02-22T01:01:20.196Z,1550797280.196 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:01:23.017Z,1550797283.017 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:01:26.225Z,1550797286.225 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:01:29.057Z,1550797289.057 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:01:29.361Z,1550797289.361 [NavChartDb](INFO): Done scanning nodes of Resources/ElectronicNavigationCharts/US5CA50M.000
2019-02-22T01:01:29.546Z,1550797289.546 [NavChartDb](INFO): # of records loaded: 62026
2019-02-22T01:01:29.552Z,1550797289.552 [NavChartDb](IMPORTANT): Loaded Electronic Nav Chart data from US5CA50M.000
2019-02-22T01:01:29.553Z,1550797289.553 [NavChartDb](INFO): Setup scan of Resources/ElectronicNavigationCharts/US4CA60M.000
2019-02-22T01:01:31.881Z,1550797291.881 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:01:35.129Z,1550797295.129 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:01:36.815Z,1550797296.815 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-02-22T00:56:36.6Z
2019-02-22T01:01:36.816Z,1550797296.816 [Default:CheckIn:Read_GPS] Stopped
2019-02-22T01:01:36.816Z,1550797296.816 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-02-22T01:01:37.196Z,1550797297.196 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-02-22T01:01:38.149Z,1550797298.149 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:01:38.628Z,1550797298.628 [NavChartDb](INFO): Done scanning features of Resources/ElectronicNavigationCharts/US4CA60M.000
2019-02-22T01:01:38.691Z,1550797298.691 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190222T005251/Courier0004.lzma
2019-02-22T01:01:39.214Z,1550797299.214 [DataOverHttps](INFO): Moved sent file to Logs/20190222T005251/Courier0004.lzma.bak
2019-02-22T01:01:39.214Z,1550797299.214 [DataOverHttps](INFO): SBD MOMSN=10068605
2019-02-22T01:01:40.969Z,1550797300.969 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:01:44.217Z,1550797304.217 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:01:47.033Z,1550797307.033 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:01:49.857Z,1550797309.857 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:01:51.913Z,1550797311.913 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:01:53.897Z,1550797313.897 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:01:55.925Z,1550797315.925 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:01:56.548Z,1550797316.548 [NavChartDb](INFO): # of records loaded: 5000
2019-02-22T01:01:57.945Z,1550797317.945 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:01:59.426Z,1550797319.426 [DataOverHttps](INFO): Sending 784 bytes from file Logs/20190222T004247/Express0001.lzma
2019-02-22T01:02:00.194Z,1550797320.194 [DataOverHttps](INFO): Moved sent file to Logs/20190222T004247/Express0001.lzma.bak
2019-02-22T01:02:00.194Z,1550797320.194 [DataOverHttps](INFO): SBD MOMSN=10068607
2019-02-22T01:02:01.169Z,1550797321.169 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:02:04.005Z,1550797324.005 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:02:05.250Z,1550797325.250 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2019-02-22T01:02:05.250Z,1550797325.250 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-02-22T01:02:05.286Z,1550797325.286 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-02-22T01:02:05.736Z,1550797325.736 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 3
2019-02-22T01:02:05.736Z,1550797325.736 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2019-02-22T01:02:05.754Z,1550797325.754 [DeadReckonWithRespectToSeafloor] Software Fault, FailCount= 3
2019-02-22T01:02:05.754Z,1550797325.754 [DeadReckonWithRespectToSeafloor](ERROR): Software Fault
2019-02-22T01:02:05.781Z,1550797325.781 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-02-22T01:02:05.781Z,1550797325.781 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2019-02-22T01:02:05.782Z,1550797325.782 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2019-02-22T01:02:05.782Z,1550797325.782 [CBIT](ERROR): Software Fault in component: DeadReckonWithRespectToSeafloor
2019-02-22T01:02:06.113Z,1550797326.113 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2019-02-22T01:02:06.113Z,1550797326.113 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 3
2019-02-22T01:02:06.114Z,1550797326.114 [CBIT](INFO): Clearing failed state for component DeadReckonWithRespectToSeafloor
2019-02-22T01:02:06.114Z,1550797326.114 [DeadReckonWithRespectToSeafloor] No Fault, FailCount= 3
2019-02-22T01:02:06.474Z,1550797326.474 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2019-02-22T01:02:07.237Z,1550797327.237 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:02:10.077Z,1550797330.077 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:02:10.948Z,1550797330.948 [NavChartDb](INFO): # of records loaded: 10000
2019-02-22T01:02:11.385Z,1550797331.385 [PAR_Licor](INFO): A/D timeout, 9 tries over 128 ms

2019-02-22T01:02:11.385Z,1550797331.385 [PAR_Licor] Data Fault, FailCount= 1
2019-02-22T01:02:11.385Z,1550797331.385 [PAR_Licor](ERROR): Data Fault
2019-02-22T01:02:11.471Z,1550797331.471 [CBIT](ERROR): Data Fault in component: PAR_Licor
2019-02-22T01:02:11.472Z,1550797331.472 [CBIT](INFO): Clearing failed state for component PAR_Licor
2019-02-22T01:02:11.472Z,1550797331.472 [PAR_Licor] No Fault, FailCount= 1
2019-02-22T01:02:13.037Z,1550797333.037 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:02:14.937Z,1550797334.937 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:02:18.213Z,1550797338.213 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:02:19.132Z,1550797339.132 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20190222T004247/Express0005.lzma
2019-02-22T01:02:19.938Z,1550797339.938 [DataOverHttps](INFO): Moved sent file to Logs/20190222T004247/Express0005.lzma.bak
2019-02-22T01:02:19.939Z,1550797339.939 [DataOverHttps](INFO): SBD MOMSN=10068631
2019-02-22T01:02:20.997Z,1550797340.997 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:02:24.229Z,1550797344.229 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:02:24.843Z,1550797344.843 [NavChartDb](INFO): # of records loaded: 15000
2019-02-22T01:02:27.061Z,1550797347.061 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:02:30.305Z,1550797350.305 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:02:33.133Z,1550797353.133 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:02:35.977Z,1550797355.977 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:02:37.981Z,1550797357.981 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:02:39.416Z,1550797359.416 [DataOverHttps](INFO): Sending 946 bytes from file Logs/20190222T005251/Express0001.lzma
2019-02-22T01:02:39.791Z,1550797359.791 [NavChartDb](INFO): # of records loaded: 20000
2019-02-22T01:02:39.985Z,1550797359.985 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:02:40.218Z,1550797360.218 [DataOverHttps](INFO): Moved sent file to Logs/20190222T005251/Express0001.lzma.bak
2019-02-22T01:02:40.219Z,1550797360.219 [DataOverHttps](INFO): SBD MOMSN=10068633
2019-02-22T01:02:42.005Z,1550797362.005 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:02:45.253Z,1550797365.253 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:02:48.065Z,1550797368.065 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:02:51.313Z,1550797371.313 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:02:53.537Z,1550797373.537 [NavChartDb](INFO): # of records loaded: 25000
2019-02-22T01:02:54.125Z,1550797374.125 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:02:56.957Z,1550797376.957 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:02:57.789Z,1550797377.789 [PAR_Licor](INFO): A/D timeout, 2 tries over 147 ms

2019-02-22T01:02:57.789Z,1550797377.789 [PAR_Licor] Data Fault, FailCount= 1
2019-02-22T01:02:57.789Z,1550797377.789 [PAR_Licor](ERROR): Data Fault
2019-02-22T01:02:57.926Z,1550797377.926 [CBIT](ERROR): Data Fault in component: PAR_Licor
2019-02-22T01:02:57.927Z,1550797377.927 [CBIT](INFO): Clearing failed state for component PAR_Licor
2019-02-22T01:02:57.927Z,1550797377.927 [PAR_Licor] No Fault, FailCount= 1
2019-02-22T01:02:59.077Z,1550797379.077 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:02:59.467Z,1550797379.467 [DataOverHttps](INFO): Sending 319 bytes from file Logs/20190222T005251/Express0005.lzma
2019-02-22T01:03:00.271Z,1550797380.271 [DataOverHttps](INFO): Moved sent file to Logs/20190222T005251/Express0005.lzma.bak
2019-02-22T01:03:00.272Z,1550797380.272 [DataOverHttps](INFO): SBD MOMSN=10068661
2019-02-22T01:03:00.997Z,1550797380.997 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:03:01.551Z,1550797381.551 [Default:CheckIn:Read_Iridium] Stopped
2019-02-22T01:03:01.551Z,1550797381.551 [Default:CheckIn:C.Wait] Running Loop=1
2019-02-22T01:03:01.551Z,1550797381.551 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-02-22T01:03:03.081Z,1550797383.081 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:03:06.293Z,1550797386.293 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:03:09.113Z,1550797389.113 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:03:10.130Z,1550797390.130 [NavChartDb](INFO): # of records loaded: 30000
2019-02-22T01:03:12.317Z,1550797392.317 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:03:15.137Z,1550797395.137 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:03:15.921Z,1550797395.921 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2019-02-22T01:03:15.921Z,1550797395.921 [Rowe_600LCM] Communications Fault, FailCount= 5
2019-02-22T01:03:15.921Z,1550797395.921 [Rowe_600LCM](ERROR): Communications Fault
2019-02-22T01:03:16.027Z,1550797396.027 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2019-02-22T01:03:16.027Z,1550797396.027 [CBIT](FAULT): Communications Fault in component: Rowe_600LCM
2019-02-22T01:03:16.339Z,1550797396.339 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2019-02-22T01:03:16.639Z,1550797396.639 [Rowe_600LCM](INFO): Powering down
2019-02-22T01:03:18.377Z,1550797398.377 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:03:21.201Z,1550797401.201 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:03:21.526Z,1550797401.526 [NavChartDb](INFO): # of records loaded: 35000
2019-02-22T01:03:24.037Z,1550797404.037 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:03:26.065Z,1550797406.065 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:03:28.065Z,1550797408.065 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:03:31.313Z,1550797411.313 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:03:34.125Z,1550797414.125 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:03:35.807Z,1550797415.807 [NavChartDb](INFO): # of records loaded: 40000
2019-02-22T01:03:37.393Z,1550797417.393 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:03:40.185Z,1550797420.185 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:03:42.717Z,1550797422.717 [PAR_Licor](INFO): A/D timeout, 8 tries over 125 ms

2019-02-22T01:03:42.717Z,1550797422.717 [PAR_Licor] Data Fault, FailCount= 1
2019-02-22T01:03:42.717Z,1550797422.717 [PAR_Licor](ERROR): Data Fault
2019-02-22T01:03:42.823Z,1550797422.823 [CBIT](ERROR): Data Fault in component: PAR_Licor
2019-02-22T01:03:42.823Z,1550797422.823 [CBIT](INFO): Clearing failed state for component PAR_Licor
2019-02-22T01:03:42.823Z,1550797422.823 [PAR_Licor] No Fault, FailCount= 1
2019-02-22T01:03:43.406Z,1550797423.406 [NAL9602](FAULT): GPS failed to acquire within timeout.
2019-02-22T01:03:43.406Z,1550797423.406 [NAL9602] Data Fault, FailCount= 1
2019-02-22T01:03:43.406Z,1550797423.406 [NAL9602](ERROR): Data Fault
2019-02-22T01:03:43.497Z,1550797423.497 [CBIT](ERROR): Data Fault in component: NAL9602
2019-02-22T01:03:43.810Z,1550797423.810 [NAL9602](INFO): Powering down
2019-02-22T01:03:44.717Z,1550797424.717 [CBIT](INFO): Clearing failed state for component NAL9602
2019-02-22T01:03:44.717Z,1550797424.717 [NAL9602] No Fault, FailCount= 1
2019-02-22T01:03:48.249Z,1550797428.249 [PAR_Licor](INFO): A/D timeout, 1 tries over 124 ms

2019-02-22T01:03:48.249Z,1550797428.249 [PAR_Licor] Data Fault, FailCount= 1
2019-02-22T01:03:48.249Z,1550797428.249 [PAR_Licor](ERROR): Data Fault
2019-02-22T01:03:48.390Z,1550797428.390 [CBIT](ERROR): Data Fault in component: PAR_Licor
2019-02-22T01:03:48.391Z,1550797428.391 [CBIT](INFO): Clearing failed state for component PAR_Licor
2019-02-22T01:03:48.391Z,1550797428.391 [PAR_Licor] No Fault, FailCount= 1
2019-02-22T01:03:56.837Z,1550797436.837 [NavChartDb](INFO): # of records loaded: 45000
2019-02-22T01:03:59.756Z,1550797439.756 [NavChartDb](INFO): Calculating coverage of Resources/ElectronicNavigationCharts/US4CA60M.000
2019-02-22T01:04:01.419Z,1550797441.419 [NavChartDb](INFO): Done scanning edges of Resources/ElectronicNavigationCharts/US4CA60M.000
2019-02-22T01:04:01.743Z,1550797441.743 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-02-22T01:04:13.471Z,1550797453.471 [NavChartDb](INFO): # of records loaded: 50000
2019-02-22T01:04:14.118Z,1550797454.118 [NAL9602](INFO): Powering up NAL9602
2019-02-22T01:04:25.038Z,1550797465.038 [NAL9602](INFO): NAL9602 initialized
2019-02-22T01:04:25.857Z,1550797465.857 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:04:28.669Z,1550797468.669 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:04:31.993Z,1550797471.993 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:04:34.807Z,1550797474.807 [NavChartDb](INFO): Done scanning nodes of Resources/ElectronicNavigationCharts/US4CA60M.000
2019-02-22T01:04:34.817Z,1550797474.817 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:04:34.985Z,1550797474.985 [NavChartDb](INFO): # of records loaded: 53494
2019-02-22T01:04:35.011Z,1550797475.011 [NavChartDb](IMPORTANT): Loaded Electronic Nav Chart data from US4CA60M.000
2019-02-22T01:04:35.012Z,1550797475.012 [NavChartDb](INFO): Setup scan of Resources/ElectronicNavigationCharts/US3CA52M.000
2019-02-22T01:04:37.557Z,1550797477.557 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:04:37.834Z,1550797477.834 [NavChartDb](INFO): Done scanning features of Resources/ElectronicNavigationCharts/US3CA52M.000
2019-02-22T01:04:39.625Z,1550797479.625 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:04:42.829Z,1550797482.829 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:04:45.637Z,1550797485.637 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:04:48.869Z,1550797488.869 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:04:50.737Z,1550797490.737 [NavChartDb](INFO): # of records loaded: 5000
2019-02-22T01:04:51.693Z,1550797491.693 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:04:54.929Z,1550797494.929 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:04:57.757Z,1550797497.757 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:05:00.349Z,1550797500.349 [NavChartDb](INFO): # of records loaded: 10000
2019-02-22T01:05:01.005Z,1550797501.005 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:05:03.817Z,1550797503.817 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:05:06.275Z,1550797506.275 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2019-02-22T01:05:06.275Z,1550797506.275 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-02-22T01:05:06.304Z,1550797506.304 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-02-22T01:05:06.645Z,1550797506.645 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:05:06.694Z,1550797506.694 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 4
2019-02-22T01:05:06.694Z,1550797506.694 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2019-02-22T01:05:06.695Z,1550797506.695 [DeadReckonWithRespectToSeafloor] Software Fault, FailCount= 4
2019-02-22T01:05:06.695Z,1550797506.695 [DeadReckonWithRespectToSeafloor](ERROR): Software Fault
2019-02-22T01:05:06.718Z,1550797506.718 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-02-22T01:05:06.718Z,1550797506.718 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2019-02-22T01:05:06.719Z,1550797506.719 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2019-02-22T01:05:06.719Z,1550797506.719 [CBIT](ERROR): Software Fault in component: DeadReckonWithRespectToSeafloor
2019-02-22T01:05:07.138Z,1550797507.138 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2019-02-22T01:05:07.138Z,1550797507.138 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 4
2019-02-22T01:05:07.139Z,1550797507.139 [CBIT](INFO): Clearing failed state for component DeadReckonWithRespectToSeafloor
2019-02-22T01:05:07.139Z,1550797507.139 [DeadReckonWithRespectToSeafloor] No Fault, FailCount= 4
2019-02-22T01:05:07.484Z,1550797507.484 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2019-02-22T01:05:07.730Z,1550797507.730 [NavChartDb](INFO): # of records loaded: 15000
2019-02-22T01:05:08.661Z,1550797508.661 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:05:10.685Z,1550797510.685 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:05:13.917Z,1550797513.917 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:05:16.757Z,1550797516.757 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:05:17.199Z,1550797517.199 [NavChartDb](INFO): # of records loaded: 20000
2019-02-22T01:05:19.977Z,1550797519.977 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:05:22.805Z,1550797522.805 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:05:25.598Z,1550797525.598 [NavChartDb](INFO): # of records loaded: 25000
2019-02-22T01:05:25.721Z,1550797525.721 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:05:27.669Z,1550797527.669 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:05:29.689Z,1550797529.689 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:05:31.717Z,1550797531.717 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:05:33.717Z,1550797533.717 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:05:35.925Z,1550797535.925 [NavChartDb](INFO): # of records loaded: 30000
2019-02-22T01:05:36.961Z,1550797536.961 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:05:39.777Z,1550797539.777 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:05:43.021Z,1550797543.021 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:05:45.857Z,1550797545.857 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:05:46.940Z,1550797546.940 [NavChartDb](INFO): # of records loaded: 35000
2019-02-22T01:05:49.085Z,1550797549.085 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:05:51.897Z,1550797551.897 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:05:54.725Z,1550797554.725 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:05:56.158Z,1550797556.158 [NavChartDb](INFO): # of records loaded: 40000
2019-02-22T01:05:56.753Z,1550797556.753 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:05:59.985Z,1550797559.985 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:06:02.813Z,1550797562.813 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:06:03.454Z,1550797563.454 [NavChartDb](INFO): # of records loaded: 45000
2019-02-22T01:06:06.053Z,1550797566.053 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:06:08.869Z,1550797568.869 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:06:11.076Z,1550797571.076 [NavChartDb](INFO): # of records loaded: 50000
2019-02-22T01:06:11.809Z,1550797571.809 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:06:13.726Z,1550797573.726 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:06:15.777Z,1550797575.777 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:06:18.973Z,1550797578.973 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:06:21.805Z,1550797581.805 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:06:22.103Z,1550797582.103 [NavChartDb](INFO): # of records loaded: 55000
2019-02-22T01:06:25.033Z,1550797585.033 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:06:27.861Z,1550797587.861 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:06:29.425Z,1550797589.425 [NavChartDb](INFO): # of records loaded: 60000
2019-02-22T01:06:31.093Z,1550797591.093 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:06:33.929Z,1550797593.929 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:06:36.711Z,1550797596.711 [NavChartDb](INFO): # of records loaded: 65000
2019-02-22T01:06:37.153Z,1550797597.153 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:06:39.981Z,1550797599.981 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:06:42.813Z,1550797602.813 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:06:44.833Z,1550797604.833 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:06:45.968Z,1550797605.968 [NavChartDb](INFO): # of records loaded: 70000
2019-02-22T01:06:48.053Z,1550797608.053 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:06:50.889Z,1550797610.889 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:06:54.113Z,1550797614.113 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:06:55.326Z,1550797615.326 [NavChartDb](INFO): # of records loaded: 75000
2019-02-22T01:06:56.949Z,1550797616.949 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:06:59.769Z,1550797619.769 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:07:02.193Z,1550797622.193 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:07:02.899Z,1550797622.899 [NavChartDb](INFO): # of records loaded: 80000
2019-02-22T01:07:05.073Z,1550797625.073 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:07:07.869Z,1550797627.869 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:07:09.909Z,1550797629.909 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:07:10.273Z,1550797630.273 [NavChartDb](INFO): # of records loaded: 85000
2019-02-22T01:07:13.101Z,1550797633.101 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:07:15.937Z,1550797635.937 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:07:19.165Z,1550797639.165 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:07:21.382Z,1550797641.382 [NavChartDb](INFO): # of records loaded: 90000
2019-02-22T01:07:21.989Z,1550797641.989 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:07:25.221Z,1550797645.221 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:07:28.057Z,1550797648.057 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:07:28.961Z,1550797648.961 [NavChartDb](INFO): # of records loaded: 95000
2019-02-22T01:07:30.885Z,1550797650.885 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:07:32.897Z,1550797652.897 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:07:36.129Z,1550797656.129 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:07:36.615Z,1550797656.615 [NavChartDb](INFO): # of records loaded: 100000
2019-02-22T01:07:38.965Z,1550797658.965 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:07:41.493Z,1550797661.493 [PAR_Licor](INFO): A/D timeout, 9 tries over 128 ms

2019-02-22T01:07:41.493Z,1550797661.493 [PAR_Licor] Data Fault, FailCount= 1
2019-02-22T01:07:41.493Z,1550797661.493 [PAR_Licor](ERROR): Data Fault
2019-02-22T01:07:41.579Z,1550797661.579 [CBIT](ERROR): Data Fault in component: PAR_Licor
2019-02-22T01:07:41.579Z,1550797661.579 [CBIT](INFO): Clearing failed state for component PAR_Licor
2019-02-22T01:07:41.579Z,1550797661.579 [PAR_Licor] No Fault, FailCount= 1
2019-02-22T01:07:42.189Z,1550797662.189 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:07:44.966Z,1550797664.966 [NavChartDb](INFO): # of records loaded: 105000
2019-02-22T01:07:45.137Z,1550797665.137 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:07:48.265Z,1550797668.265 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:07:51.133Z,1550797671.133 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:07:53.925Z,1550797673.925 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:07:55.941Z,1550797675.941 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:07:56.231Z,1550797676.231 [NavChartDb](INFO): # of records loaded: 110000
2019-02-22T01:07:59.165Z,1550797679.165 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:08:01.997Z,1550797681.997 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:08:02.056Z,1550797682.056 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-02-22T01:08:02.056Z,1550797682.056 [Default:CheckIn:C.Wait] Stopped
2019-02-22T01:08:02.056Z,1550797682.056 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-02-22T01:08:02.056Z,1550797682.056 [Default:CheckIn:D] Running Loop=1
2019-02-22T01:08:02.459Z,1550797682.459 [Default:CheckIn:D] Stopped
2019-02-22T01:08:02.460Z,1550797682.460 [Default:CheckIn:E] Running Loop=1
2019-02-22T01:08:02.849Z,1550797682.849 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 11.661266 min 
2019-02-22T01:08:02.849Z,1550797682.849 [Default:CheckIn:E] Stopped
2019-02-22T01:08:02.850Z,1550797682.850 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-02-22T01:08:02.850Z,1550797682.850 [Default:CheckIn] Stopped
2019-02-22T01:08:02.850Z,1550797682.850 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-02-22T01:08:02.850Z,1550797682.850 [Default:CheckIn](INFO): Running loop #2
2019-02-22T01:08:02.850Z,1550797682.850 [Default:CheckIn] Running Loop=2
2019-02-22T01:08:02.850Z,1550797682.850 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-02-22T01:08:02.850Z,1550797682.850 [Default:CheckIn:Read_GPS] Running Loop=1
2019-02-22T01:08:03.942Z,1550797683.942 [NavChartDb](INFO): Calculating coverage of Resources/ElectronicNavigationCharts/US3CA52M.000
2019-02-22T01:08:04.785Z,1550797684.785 [NavChartDb](INFO): Done scanning edges of Resources/ElectronicNavigationCharts/US3CA52M.000
2019-02-22T01:08:05.233Z,1550797685.233 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:08:05.294Z,1550797685.294 [CBIT](INFO): Clearing failed state for component DropWeight
2019-02-22T01:08:05.294Z,1550797685.294 [DropWeight] No Fault, FailCount= 1
2019-02-22T01:08:07.311Z,1550797687.311 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5
2019-02-22T01:08:07.311Z,1550797687.311 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-02-22T01:08:07.331Z,1550797687.331 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-02-22T01:08:07.565Z,1550797687.565 [NavChartDb](INFO): # of records loaded: 115000
2019-02-22T01:08:07.685Z,1550797687.685 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 5
2019-02-22T01:08:07.686Z,1550797687.686 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2019-02-22T01:08:07.687Z,1550797687.687 [DeadReckonWithRespectToSeafloor] Software Fault, FailCount= 5
2019-02-22T01:08:07.687Z,1550797687.687 [DeadReckonWithRespectToSeafloor](ERROR): Software Fault
2019-02-22T01:08:07.705Z,1550797687.705 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-02-22T01:08:07.705Z,1550797687.705 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5
2019-02-22T01:08:07.706Z,1550797687.706 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2019-02-22T01:08:07.706Z,1550797687.706 [CBIT](ERROR): Software Fault in component: DeadReckonWithRespectToSeafloor
2019-02-22T01:08:08.045Z,1550797688.045 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:08:08.092Z,1550797688.092 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2019-02-22T01:08:08.092Z,1550797688.092 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 5
2019-02-22T01:08:08.097Z,1550797688.097 [CBIT](INFO): Clearing failed state for component DeadReckonWithRespectToSeafloor
2019-02-22T01:08:08.097Z,1550797688.097 [DeadReckonWithRespectToSeafloor] No Fault, FailCount= 5
2019-02-22T01:08:08.492Z,1550797688.492 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2019-02-22T01:08:11.285Z,1550797691.285 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:08:14.113Z,1550797694.113 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:08:15.242Z,1550797695.242 [NavChartDb](INFO): Done scanning nodes of Resources/ElectronicNavigationCharts/US3CA52M.000
2019-02-22T01:08:15.673Z,1550797695.673 [NavChartDb](INFO): # of records loaded: 117290
2019-02-22T01:08:15.682Z,1550797695.682 [NavChartDb](IMPORTANT): Loaded Electronic Nav Chart data from US3CA52M.000
2019-02-22T01:08:15.682Z,1550797695.682 [NavChartDb](INFO): Setup scan of Resources/ElectronicNavigationCharts/US2WC11M.000
2019-02-22T01:08:16.965Z,1550797696.965 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:08:18.441Z,1550797698.441 [NavChartDb](INFO): Done scanning features of Resources/ElectronicNavigationCharts/US2WC11M.000
2019-02-22T01:08:18.965Z,1550797698.965 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:08:20.981Z,1550797700.981 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:08:24.229Z,1550797704.229 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:08:26.792Z,1550797706.792 [NavChartDb](INFO): # of records loaded: 5000
2019-02-22T01:08:27.041Z,1550797707.041 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:08:30.273Z,1550797710.273 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:08:33.097Z,1550797713.097 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:08:34.150Z,1550797714.150 [NavChartDb](INFO): # of records loaded: 10000
2019-02-22T01:08:36.017Z,1550797716.017 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:08:37.949Z,1550797717.949 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:08:39.985Z,1550797719.985 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:08:41.605Z,1550797721.605 [NavChartDb](INFO): # of records loaded: 15000
2019-02-22T01:08:43.201Z,1550797723.201 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:08:46.042Z,1550797726.042 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:08:49.261Z,1550797729.261 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:08:52.089Z,1550797732.089 [NAL9602](DEBUG): Fix Requested
2019-02-22T01:08:52.770Z,1550797732.770 [NavChartDb](INFO): # of records