2019-02-08T03:29:47.113Z,1549596587.113 [Supervisor](DEBUG): Initializing supervisor.
2019-02-08T03:29:47.116Z,1549596587.116 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2019-02-08T03:29:47.116Z,1549596587.116 [SyncHandler](INFO): Protected caller Thread ID is 3558
2019-02-08T03:29:47.117Z,1549596587.117 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2019-02-08T03:29:47.118Z,1549596587.118 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2019-02-08T03:29:47.118Z,1549596587.118 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 3559
2019-02-08T03:29:47.121Z,1549596587.121 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2019-02-08T03:29:47.133Z,1549596587.133 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2019-02-08T03:29:47.134Z,1549596587.134 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2019-02-08T03:29:47.135Z,1549596587.135 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 3560
2019-02-08T03:29:47.136Z,1549596587.136 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2019-02-08T03:29:47.136Z,1549596587.136 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2019-02-08T03:29:47.137Z,1549596587.137 [logger ThreadHandler](INFO): Protected caller Thread ID is 3561
2019-02-08T03:29:47.139Z,1549596587.139 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2019-02-08T03:29:47.139Z,1549596587.139 [Supervisor](INFO): Looking for Config files in directory: Config/
2019-02-08T03:29:47.141Z,1549596587.141 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2019-02-08T03:29:47.234Z,1549596587.234 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2019-02-08T03:29:47.234Z,1549596587.234 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2019-02-08T03:29:47.425Z,1549596587.425 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2019-02-08T03:29:47.425Z,1549596587.425 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2019-02-08T03:29:47.557Z,1549596587.557 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2019-02-08T03:29:47.558Z,1549596587.558 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2019-02-08T03:29:48.005Z,1549596588.005 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2019-02-08T03:29:48.005Z,1549596588.005 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2019-02-08T03:29:48.428Z,1549596588.428 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2019-02-08T03:29:48.429Z,1549596588.429 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2019-02-08T03:29:48.888Z,1549596588.888 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2019-02-08T03:29:48.889Z,1549596588.889 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2019-02-08T03:29:49.186Z,1549596589.186 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2019-02-08T03:29:49.186Z,1549596589.186 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2019-02-08T03:29:49.556Z,1549596589.556 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2019-02-08T03:29:49.556Z,1549596589.556 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2019-02-08T03:29:50.092Z,1549596590.092 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2019-02-08T03:29:50.093Z,1549596590.093 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2019-02-08T03:29:50.238Z,1549596590.238 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2019-02-08T03:29:50.239Z,1549596590.239 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2019-02-08T03:29:50.342Z,1549596590.342 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2019-02-08T03:29:50.343Z,1549596590.343 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2019-02-08T03:29:50.422Z,1549596590.422 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2019-02-08T03:29:50.522Z,1549596590.522 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2019-02-08T03:29:50.523Z,1549596590.523 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2019-02-08T03:29:50.711Z,1549596590.711 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2019-02-08T03:29:50.712Z,1549596590.712 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2019-02-08T03:29:50.913Z,1549596590.913 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2019-02-08T03:29:50.915Z,1549596590.915 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/
2019-02-08T03:29:50.916Z,1549596590.916 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg
2019-02-08T03:29:50.999Z,1549596590.999 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg
2019-02-08T03:29:51.228Z,1549596591.228 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2019-02-08T03:29:51.229Z,1549596591.229 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg
2019-02-08T03:29:51.321Z,1549596591.321 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg
2019-02-08T03:29:51.476Z,1549596591.476 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg
2019-02-08T03:29:51.674Z,1549596591.674 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg
2019-02-08T03:29:51.758Z,1549596591.758 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg
2019-02-08T03:29:51.854Z,1549596591.854 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg
2019-02-08T03:29:51.945Z,1549596591.945 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg
2019-02-08T03:29:52.091Z,1549596592.091 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg
2019-02-08T03:29:52.193Z,1549596592.193 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg
2019-02-08T03:29:52.288Z,1549596592.288 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2019-02-08T03:29:52.289Z,1549596592.289 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2019-02-08T03:29:52.390Z,1549596592.390 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2019-02-08T03:29:52.390Z,1549596592.390 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2019-02-08T03:29:52.494Z,1549596592.494 [BuoyancyServo] Loaded
2019-02-08T03:29:52.495Z,1549596592.495 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2019-02-08T03:29:52.510Z,1549596592.510 [ElevatorServo] Loaded
2019-02-08T03:29:52.510Z,1549596592.510 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2019-02-08T03:29:52.524Z,1549596592.524 [MassServo] Loaded
2019-02-08T03:29:52.525Z,1549596592.525 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2019-02-08T03:29:52.540Z,1549596592.540 [RudderServo] Loaded
2019-02-08T03:29:52.540Z,1549596592.540 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2019-02-08T03:29:52.554Z,1549596592.554 [ThrusterServo] Loaded
2019-02-08T03:29:52.554Z,1549596592.554 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2019-02-08T03:29:52.555Z,1549596592.555 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2019-02-08T03:29:52.555Z,1549596592.555 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2019-02-08T03:29:52.690Z,1549596592.690 [SBIT](DEBUG): Construct Startup Built In Test.
2019-02-08T03:29:52.718Z,1549596592.718 [SBIT] Loaded
2019-02-08T03:29:52.718Z,1549596592.718 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2019-02-08T03:29:52.719Z,1549596592.719 [IBIT](DEBUG): Construct Initiated Built In Test.
2019-02-08T03:29:52.747Z,1549596592.747 [IBIT] Loaded
2019-02-08T03:29:52.747Z,1549596592.747 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2019-02-08T03:29:52.750Z,1549596592.750 [CBIT](DEBUG): Construct Continuous Built In Test.
2019-02-08T03:29:53.138Z,1549596593.138 [CBIT] Loaded
2019-02-08T03:29:53.139Z,1549596593.139 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2019-02-08T03:29:53.139Z,1549596593.139 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2019-02-08T03:29:53.140Z,1549596593.140 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2019-02-08T03:29:53.319Z,1549596593.319 [Aanderaa_O2] Loaded
2019-02-08T03:29:53.320Z,1549596593.320 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2019-02-08T03:29:53.329Z,1549596593.329 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_density
2019-02-08T03:29:53.334Z,1549596593.334 [CTD_Seabird](INFO): created writer for : sea_water_density
2019-02-08T03:29:53.337Z,1549596593.337 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): depth
2019-02-08T03:29:53.341Z,1549596593.341 [CTD_Seabird](INFO): created writer for : depth
2019-02-08T03:29:53.342Z,1549596593.342 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_pressure
2019-02-08T03:29:53.347Z,1549596593.347 [CTD_Seabird](INFO): created writer for : sea_water_pressure
2019-02-08T03:29:53.348Z,1549596593.348 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_salinity
2019-02-08T03:29:53.353Z,1549596593.353 [CTD_Seabird](INFO): created writer for : sea_water_salinity
2019-02-08T03:29:53.353Z,1549596593.353 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_temperature
2019-02-08T03:29:53.359Z,1549596593.359 [CTD_Seabird](INFO): created writer for : sea_water_temperature
2019-02-08T03:29:53.359Z,1549596593.359 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_electrical_conductivity
2019-02-08T03:29:53.365Z,1549596593.365 [CTD_Seabird](INFO): created writer for : sea_water_electrical_conductivity
2019-02-08T03:29:53.365Z,1549596593.365 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): speed_of_sound_in_sea_water
2019-02-08T03:29:53.371Z,1549596593.371 [CTD_Seabird](INFO): created writer for : speed_of_sound_in_sea_water
2019-02-08T03:29:53.397Z,1549596593.397 [CTD_Seabird] Loaded
2019-02-08T03:29:53.397Z,1549596593.397 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2019-02-08T03:29:53.398Z,1549596593.398 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 4062E4E0
2019-02-08T03:29:53.399Z,1549596593.399 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 3640
2019-02-08T03:29:53.420Z,1549596593.420 [ESPComponent] Loaded
2019-02-08T03:29:53.420Z,1549596593.420 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2019-02-08T03:29:53.434Z,1549596593.434 [PAR_Licor] Loaded
2019-02-08T03:29:53.434Z,1549596593.434 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2019-02-08T03:29:53.482Z,1549596593.482 [WetLabsBB2FL] Loaded
2019-02-08T03:29:53.482Z,1549596593.482 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2019-02-08T03:29:53.483Z,1549596593.483 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 4065E4E0
2019-02-08T03:29:53.483Z,1549596593.483 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 3641
2019-02-08T03:29:53.484Z,1549596593.484 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2019-02-08T03:29:53.484Z,1549596593.484 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2019-02-08T03:29:53.527Z,1549596593.527 [DepthRateCalculator] Loaded
2019-02-08T03:29:53.527Z,1549596593.527 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2019-02-08T03:29:53.532Z,1549596593.532 [PitchRateCalculator] Loaded
2019-02-08T03:29:53.533Z,1549596593.533 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2019-02-08T03:29:53.548Z,1549596593.548 [SpeedCalculator] Loaded
2019-02-08T03:29:53.548Z,1549596593.548 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2019-02-08T03:29:53.569Z,1549596593.569 [TempGradientCalculator] Loaded
2019-02-08T03:29:53.569Z,1549596593.569 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2019-02-08T03:29:53.575Z,1549596593.575 [YawRateCalculator] Loaded
2019-02-08T03:29:53.575Z,1549596593.575 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2019-02-08T03:29:53.608Z,1549596593.608 [ElevatorOffsetCalculator] Loaded
2019-02-08T03:29:53.609Z,1549596593.609 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2019-02-08T03:29:53.609Z,1549596593.609 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2019-02-08T03:29:53.610Z,1549596593.610 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2019-02-08T03:29:53.637Z,1549596593.637 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2019-02-08T03:29:53.638Z,1549596593.638 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2019-02-08T03:29:53.740Z,1549596593.740 [DeadReckonUsingMultipleVelocitySources] Loaded
2019-02-08T03:29:53.740Z,1549596593.740 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2019-02-08T03:29:53.800Z,1549596593.800 [DeadReckonUsingSpeedCalculator] Loaded
2019-02-08T03:29:53.800Z,1549596593.800 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2019-02-08T03:29:53.858Z,1549596593.858 [DeadReckonWithRespectToSeafloor] Loaded
2019-02-08T03:29:53.859Z,1549596593.859 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonWithRespectToSeafloor" handled in the control thread.
2019-02-08T03:29:53.875Z,1549596593.875 [NavChart] Loaded
2019-02-08T03:29:53.875Z,1549596593.875 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2019-02-08T03:29:53.879Z,1549596593.879 [UniversalFixResidualReporter] Loaded
2019-02-08T03:29:53.879Z,1549596593.879 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2019-02-08T03:29:53.880Z,1549596593.880 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2019-02-08T03:29:53.880Z,1549596593.880 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2019-02-08T03:29:54.165Z,1549596594.165 [AcousticModem_Benthos_ATM900] Loaded
2019-02-08T03:29:54.165Z,1549596594.165 [ComponentRegistry](DEBUG): SyncComponent "AcousticModem_Benthos_ATM900" handled in the control thread.
2019-02-08T03:29:54.233Z,1549596594.233 [DataOverHttps] Loaded
2019-02-08T03:29:54.234Z,1549596594.234 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2019-02-08T03:29:54.247Z,1549596594.247 [Depth_Keller] Loaded
2019-02-08T03:29:54.247Z,1549596594.247 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2019-02-08T03:29:54.252Z,1549596594.252 [DropWeight] Loaded
2019-02-08T03:29:54.252Z,1549596594.252 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2019-02-08T03:29:54.342Z,1549596594.342 [NAL9602] Loaded
2019-02-08T03:29:54.342Z,1549596594.342 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2019-02-08T03:29:54.347Z,1549596594.347 [Onboard] Loaded
2019-02-08T03:29:54.348Z,1549596594.348 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2019-02-08T03:29:54.354Z,1549596594.354 [Radio_Surface] Loaded
2019-02-08T03:29:54.355Z,1549596594.355 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2019-02-08T03:29:54.356Z,1549596594.356 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409254E0
2019-02-08T03:29:54.356Z,1549596594.356 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 3642
2019-02-08T03:29:54.402Z,1549596594.402 [PNI_TCM] Loaded
2019-02-08T03:29:54.403Z,1549596594.403 [ComponentRegistry](DEBUG): SyncComponent "PNI_TCM" handled in the control thread.
2019-02-08T03:29:54.463Z,1549596594.463 [Rowe_600LCM] Loaded
2019-02-08T03:29:54.463Z,1549596594.463 [ComponentRegistry](DEBUG): Component "Rowe_600LCM" handled in its own thread.
2019-02-08T03:29:54.464Z,1549596594.464 [Rowe_600LCM ThreadHandler](DEBUG): Created PCaller Thread at 409554E0
2019-02-08T03:29:54.464Z,1549596594.464 [Rowe_600LCM ThreadHandler](INFO): Protected caller Thread ID is 3643
2019-02-08T03:29:56.747Z,1549596596.747 [BPC1] Loaded
2019-02-08T03:29:56.748Z,1549596596.748 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2019-02-08T03:29:56.748Z,1549596596.748 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2019-02-08T03:29:56.749Z,1549596596.749 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2019-02-08T03:29:56.817Z,1549596596.817 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2019-02-08T03:29:56.817Z,1549596596.817 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2019-02-08T03:29:56.886Z,1549596596.886 [VerticalControl](DEBUG): Construct VerticalControl.
2019-02-08T03:29:56.969Z,1549596596.969 [VerticalControl] Loaded
2019-02-08T03:29:56.969Z,1549596596.969 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2019-02-08T03:29:56.970Z,1549596596.970 [HorizontalControl](DEBUG): Construct HorizontalControl.
2019-02-08T03:29:57.027Z,1549596597.027 [HorizontalControl] Loaded
2019-02-08T03:29:57.028Z,1549596597.028 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2019-02-08T03:29:57.028Z,1549596597.028 [SpeedControl](DEBUG): Construct SpeedControl.
2019-02-08T03:29:57.030Z,1549596597.030 [SpeedControl] Loaded
2019-02-08T03:29:57.030Z,1549596597.030 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2019-02-08T03:29:57.031Z,1549596597.031 [LoopControl](DEBUG): Construct LoopControl.
2019-02-08T03:29:57.031Z,1549596597.031 [LoopControl] Loaded
2019-02-08T03:29:57.032Z,1549596597.032 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2019-02-08T03:29:57.032Z,1549596597.032 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2019-02-08T03:29:57.033Z,1549596597.033 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2019-02-08T03:29:57.047Z,1549596597.047 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2019-02-08T03:29:57.047Z,1549596597.047 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2019-02-08T03:29:57.286Z,1549596597.286 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2019-02-08T03:29:57.289Z,1549596597.289 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2019-02-08T03:29:57.290Z,1549596597.290 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2019-02-08T03:29:57.297Z,1549596597.297 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2019-02-08T03:29:57.298Z,1549596597.298 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40A774E0
2019-02-08T03:29:57.299Z,1549596597.299 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 3644
2019-02-08T03:29:57.304Z,1549596597.304 [Supervisor](INFO): Main Thread ID is 3557
2019-02-08T03:29:57.304Z,1549596597.304 [Supervisor](DEBUG): Running supervisor.
2019-02-08T03:29:57.304Z,1549596597.304 [CommandLine ThreadHandler](INFO): Handler Thread ID is 3645
2019-02-08T03:29:57.307Z,1549596597.307 [controlThread ThreadHandler](INFO): Handler Thread ID is 3646
2019-02-08T03:29:57.307Z,1549596597.307 [controlThread](DEBUG): Initializing ControlThread
2019-02-08T03:29:57.309Z,1549596597.309 [SBIT](INFO): Initialize SBIT Component.
2019-02-08T03:29:57.309Z,1549596597.309 [SBIT](IMPORTANT): git: 2019-01-14A-57-g72ba51e
2019-02-08T03:29:57.310Z,1549596597.310 [SBIT](INFO): git hash: 72ba51edeec12b341e49a5bae224e2abbf93cde2
2019-02-08T03:29:57.310Z,1549596597.310 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2019-02-08T03:29:57.311Z,1549596597.311 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
Kernel Reported: #1 PREEMPT Tue Dec 18 21:19:28 PST 2018
2019-02-08T03:29:57.313Z,1549596597.313 [SBIT](INFO): Beginning SBIT in 24.000000 seconds.
2019-02-08T03:29:57.313Z,1549596597.313 [IBIT](INFO): Initialize IBIT Component.
2019-02-08T03:29:57.314Z,1549596597.314 [CBIT](DEBUG): Initialize CBIT Component.
2019-02-08T03:29:57.315Z,1549596597.315 [logger ThreadHandler](INFO): Handler Thread ID is 3647
2019-02-08T03:29:57.326Z,1549596597.326 [CBIT](DEBUG): Initialized mux pins.
2019-02-08T03:29:57.326Z,1549596597.326 [CBIT](DEBUG): Initializing the watchdog timer.
2019-02-08T03:29:57.334Z,1549596597.334 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 3648
2019-02-08T03:29:57.335Z,1549596597.335 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2019-02-08T03:29:57.339Z,1549596597.339 [CTD_Seabird](INFO): Opening uart, block timeout 10ths=20
2019-02-08T03:29:57.340Z,1549596597.340 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 3650
2019-02-08T03:29:57.341Z,1549596597.341 [WetLabsBB2FL](INFO): Powering down
2019-02-08T03:29:57.354Z,1549596597.354 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2019-02-08T03:29:57.354Z,1549596597.354 [CBIT](DEBUG): Initializing heartbeat.
2019-02-08T03:29:57.390Z,1549596597.390 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 3651
2019-02-08T03:29:57.396Z,1549596597.396 [Radio_Surface](INFO): Powering up
2019-02-08T03:29:57.423Z,1549596597.423 [Rowe_600LCM ThreadHandler](INFO): Handler Thread ID is 3652
2019-02-08T03:29:57.423Z,1549596597.423 [Rowe_600LCM](INFO): Initializing
2019-02-08T03:29:57.426Z,1549596597.426 [CBIT](DEBUG): Deactivating GF circuits.
2019-02-08T03:29:57.426Z,1549596597.426 [CBIT](DEBUG): Deactivating emergency mode.
2019-02-08T03:29:57.433Z,1549596597.433 [Rowe_600LCM](INFO): Powering up
2019-02-08T03:29:57.441Z,1549596597.441 [logger ThreadHandler](INFO): Cycle time is: 0.025247, Sleep time was: -0.025234
2019-02-08T03:29:57.450Z,1549596597.450 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 3653
2019-02-08T03:29:57.454Z,1549596597.454 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2019-02-08T03:29:57.454Z,1549596597.454 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2019-02-08T03:29:57.454Z,1549596597.454 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2019-02-08T03:29:57.455Z,1549596597.455 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2019-02-08T03:29:57.455Z,1549596597.455 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2019-02-08T03:29:57.455Z,1549596597.455 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2019-02-08T03:29:57.455Z,1549596597.455 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2019-02-08T03:29:57.455Z,1549596597.455 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2019-02-08T03:29:57.456Z,1549596597.456 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2019-02-08T03:29:57.456Z,1549596597.456 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2019-02-08T03:29:57.456Z,1549596597.456 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2019-02-08T03:29:57.456Z,1549596597.456 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2019-02-08T03:29:57.456Z,1549596597.456 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2019-02-08T03:29:57.456Z,1549596597.456 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2019-02-08T03:29:57.457Z,1549596597.457 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2019-02-08T03:29:57.457Z,1549596597.457 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2019-02-08T03:29:57.466Z,1549596597.466 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2019-02-08T03:29:57.467Z,1549596597.467 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2019-02-08T03:29:57.467Z,1549596597.467 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2019-02-08T03:29:57.467Z,1549596597.467 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2019-02-08T03:29:57.468Z,1549596597.468 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2019-02-08T03:29:57.468Z,1549596597.468 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2019-02-08T03:29:57.470Z,1549596597.470 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2019-02-08T03:29:57.475Z,1549596597.475 [NavChart](DEBUG): Initialize NavChart Navigation.
2019-02-08T03:29:57.475Z,1549596597.475 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2019-02-08T03:29:57.489Z,1549596597.489 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2019-02-08T03:29:57.503Z,1549596597.503 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2019-02-08T03:29:57.511Z,1549596597.511 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2019-02-08T03:29:57.511Z,1549596597.511 [LoopControl](DEBUG): Initialize LoopControlComponent.
2019-02-08T03:29:57.512Z,1549596597.512 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2019-02-08T03:29:57.543Z,1549596597.543 [logger ThreadHandler](INFO): Cycle time is: 0.001545, Sleep time was: -0.001532
2019-02-08T03:29:57.579Z,1549596597.579 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2019-02-08T03:29:57.610Z,1549596597.610 [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-08T03:29:57.611Z,1549596597.611 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2019-02-08T03:29:57.663Z,1549596597.663 [logger ThreadHandler](INFO): Cycle time is: 0.019939, Sleep time was: -0.019925
2019-02-08T03:29:57.719Z,1549596597.719 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2019-02-08T03:29:57.720Z,1549596597.720 [Default:A.Wait](DEBUG): Construct Wait.
2019-02-08T03:29:57.722Z,1549596597.722 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2019-02-08T03:29:57.765Z,1549596597.765 [logger ThreadHandler](INFO): Cycle time is: 0.000910, Sleep time was: -0.000896
2019-02-08T03:29:57.785Z,1549596597.785 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2019-02-08T03:29:57.787Z,1549596597.787 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2019-02-08T03:29:57.821Z,1549596597.821 [Default:E.Execute](DEBUG): Construct Execute.
2019-02-08T03:29:57.825Z,1549596597.825 [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-08T03:29:57.844Z,1549596597.844 [controlThread](DEBUG): Component order: CycleStarter,Aanderaa_O2,ESPComponent,PAR_Licor,AcousticModem_Benthos_ATM900,DataOverHttps,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-08T03:29:57.892Z,1549596597.892 [logger ThreadHandler](INFO): Cycle time is: 0.026406, Sleep time was: -0.026391
2019-02-08T03:29:57.940Z,1549596597.940 [ESPComponent](INFO): powering down ESP
2019-02-08T03:29:57.993Z,1549596597.993 [logger ThreadHandler](INFO): Cycle time is: 0.000939, Sleep time was: -0.000925
2019-02-08T03:29:58.119Z,1549596598.119 [logger ThreadHandler](INFO): Cycle time is: 0.025728, Sleep time was: -0.025714
2019-02-08T03:29:58.228Z,1549596598.228 [logger ThreadHandler](INFO): Cycle time is: 0.007549, Sleep time was: -0.007536
2019-02-08T03:29:58.348Z,1549596598.348 [logger ThreadHandler](INFO): Cycle time is: 0.019581, Sleep time was: -0.019568
2019-02-08T03:29:58.388Z,1549596598.388 [AcousticModem_Benthos_ATM900](INFO): Powering up
2019-02-08T03:29:58.388Z,1549596598.388 [AcousticModem_Benthos_ATM900](DEBUG): Initializing AcousticModem_Benthos_ATM900.
2019-02-08T03:29:58.416Z,1549596598.416 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2019-02-08T03:29:58.457Z,1549596598.457 [logger ThreadHandler](INFO): Cycle time is: 0.008410, Sleep time was: -0.008397
2019-02-08T03:29:58.577Z,1549596598.577 [logger ThreadHandler](INFO): Cycle time is: 0.019530, Sleep time was: -0.019517
2019-02-08T03:29:58.703Z,1549596598.703 [logger ThreadHandler](INFO): Cycle time is: 0.025514, Sleep time was: -0.025501
2019-02-08T03:29:58.806Z,1549596598.806 [logger ThreadHandler](INFO): Cycle time is: 0.002536, Sleep time was: -0.002523
2019-02-08T03:29:58.929Z,1549596598.929 [logger ThreadHandler](INFO): Cycle time is: 0.022480, Sleep time was: -0.022467
2019-02-08T03:29:59.032Z,1549596599.032 [logger ThreadHandler](INFO): Cycle time is: 0.002734, Sleep time was: -0.002722
2019-02-08T03:29:59.051Z,1549596599.051 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2019-02-08T03:29:59.058Z,1549596599.058 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2019-02-08T03:29:59.071Z,1549596599.071 [ElevatorServo](DEBUG): Initializing EZServoServo.
2019-02-08T03:29:59.086Z,1549596599.086 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2019-02-08T03:29:59.109Z,1549596599.109 [MassServo](DEBUG): Initializing EZServoServo.
2019-02-08T03:29:59.111Z,1549596599.111 [MassServo](DEBUG): Initializing MassServo.
2019-02-08T03:29:59.139Z,1549596599.139 [logger ThreadHandler](INFO): Cycle time is: 0.006137, Sleep time was: -0.006064
2019-02-08T03:29:59.163Z,1549596599.163 [RudderServo](DEBUG): Initializing EZServoServo.
2019-02-08T03:29:59.174Z,1549596599.174 [RudderServo](DEBUG): Initializing RudderServo.
2019-02-08T03:29:59.201Z,1549596599.201 [ThrusterServo](DEBUG): Initializing EZServoServo.
2019-02-08T03:29:59.206Z,1549596599.206 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2019-02-08T03:29:59.275Z,1549596599.275 [logger ThreadHandler](INFO): Cycle time is: 0.036073, Sleep time was: -0.036060
2019-02-08T03:29:59.319Z,1549596599.319 [controlThread ThreadHandler](INFO): Cycle time is: 1.075028, Sleep time was: -1.075013
2019-02-08T03:29:59.383Z,1549596599.383 [logger ThreadHandler](INFO): Cycle time is: 0.007059, Sleep time was: -0.007047
2019-02-08T03:29:59.492Z,1549596599.492 [logger ThreadHandler](INFO): Cycle time is: 0.008315, Sleep time was: -0.008300
2019-02-08T03:29:59.500Z,1549596599.500 [DropWeight](CRITICAL): DROP WEIGHT MISSING.

2019-02-08T03:29:59.500Z,1549596599.500 [DropWeight] Hardware Fault, FailCount= 1
2019-02-08T03:29:59.500Z,1549596599.500 [DropWeight](ERROR): Hardware Fault
2019-02-08T03:29:59.607Z,1549596599.607 [logger ThreadHandler](INFO): Cycle time is: 0.014096, Sleep time was: -0.014082
2019-02-08T03:29:59.719Z,1549596599.719 [logger ThreadHandler](INFO): Cycle time is: 0.011264, Sleep time was: -0.011251
2019-02-08T03:29:59.823Z,1549596599.823 [logger ThreadHandler](INFO): Cycle time is: 0.003572, Sleep time was: -0.003559
2019-02-08T03:29:59.935Z,1549596599.935 [logger ThreadHandler](INFO): Cycle time is: 0.011934, Sleep time was: -0.011922
2019-02-08T03:29:59.938Z,1549596599.938 [BuoyancyServo](ERROR): Buoyancy initialization uart error serial timeout
2019-02-08T03:29:59.938Z,1549596599.938 [BuoyancyServo](FAULT): Buoyancy failed to initialize
2019-02-08T03:29:59.938Z,1549596599.938 [BuoyancyServo] Communications Fault, FailCount= 1
2019-02-08T03:29:59.938Z,1549596599.938 [BuoyancyServo](ERROR): Communications Fault
2019-02-08T03:30:00.038Z,1549596600.038 [logger ThreadHandler](INFO): Cycle time is: 0.001823, Sleep time was: -0.001810
2019-02-08T03:30:00.151Z,1549596600.151 [logger ThreadHandler](INFO): Cycle time is: 0.012726, Sleep time was: -0.012657
2019-02-08T03:30:00.176Z,1549596600.176 [CommandLine](FAULT): Scheduling is paused
2019-02-08T03:30:00.176Z,1549596600.176 [CBIT](INFO): Critical error at 20190208T032959
2019-02-08T03:30:00.176Z,1549596600.176 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2019-02-08T03:30:00.179Z,1549596600.179 [CBIT](ERROR): Communications Fault in component: BuoyancyServo
2019-02-08T03:30:00.179Z,1549596600.179 [CBIT](ERROR): Hardware Fault in component: DropWeight
2019-02-08T03:30:00.180Z,1549596600.180 [CBIT](CRITICAL): Hardware Fault in component: DropWeight
2019-02-08T03:30:00.182Z,1549596600.182 [controlThread ThreadHandler](INFO): Cycle time is: 0.462129, Sleep time was: -0.462115
2019-02-08T03:30:00.264Z,1549596600.264 [logger ThreadHandler](INFO): Cycle time is: 0.012141, Sleep time was: -0.012128
2019-02-08T03:30:00.323Z,1549596600.323 [CBIT](INFO): Critical error at 20190208T033000
2019-02-08T03:30:00.375Z,1549596600.375 [logger ThreadHandler](INFO): Cycle time is: 0.010748, Sleep time was: -0.010735
2019-02-08T03:30:00.491Z,1549596600.491 [logger ThreadHandler](INFO): Cycle time is: 0.015533, Sleep time was: -0.015520
2019-02-08T03:30:00.586Z,1549596600.586 [controlThread ThreadHandler](INFO): Cycle time is: 0.003670, Sleep time was: 0.239245
2019-02-08T03:30:00.614Z,1549596600.614 [logger ThreadHandler](INFO): Cycle time is: 0.022382, Sleep time was: -0.022369
2019-02-08T03:30:00.744Z,1549596600.744 [logger ThreadHandler](INFO): Cycle time is: 0.029476, Sleep time was: -0.029463
2019-02-08T03:30:00.858Z,1549596600.858 [logger ThreadHandler](INFO): Cycle time is: 0.013654, Sleep time was: -0.013642
2019-02-08T03:30:00.971Z,1549596600.971 [logger ThreadHandler](INFO): Cycle time is: 0.012053, Sleep time was: -0.012040
2019-02-08T03:30:00.990Z,1549596600.990 [controlThread ThreadHandler](INFO): Cycle time is: 0.003497, Sleep time was: 0.235312
2019-02-08T03:30:01.101Z,1549596601.101 [logger ThreadHandler](INFO): Cycle time is: 0.029102, Sleep time was: -0.029055
2019-02-08T03:30:01.215Z,1549596601.215 [logger ThreadHandler](INFO): Cycle time is: 0.014062, Sleep time was: -0.014050
2019-02-08T03:30:01.327Z,1549596601.327 [logger ThreadHandler](INFO): Cycle time is: 0.010906, Sleep time was: -0.010894
2019-02-08T03:30:01.394Z,1549596601.394 [controlThread ThreadHandler](INFO): Cycle time is: 0.003511, Sleep time was: 0.239877
2019-02-08T03:30:01.431Z,1549596601.431 [logger ThreadHandler](INFO): Cycle time is: 0.002577, Sleep time was: -0.002563
2019-02-08T03:30:01.555Z,1549596601.555 [logger ThreadHandler](INFO): Cycle time is: 0.021528, Sleep time was: -0.021457
2019-02-08T03:30:01.675Z,1549596601.675 [logger ThreadHandler](INFO): Cycle time is: 0.019734, Sleep time was: -0.019721
2019-02-08T03:30:01.779Z,1549596601.779 [logger ThreadHandler](INFO): Cycle time is: 0.003667, Sleep time was: -0.003653
2019-02-08T03:30:01.798Z,1549596601.798 [controlThread ThreadHandler](INFO): Cycle time is: 0.003584, Sleep time was: 0.161435
2019-02-08T03:30:01.876Z,1549596601.876 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2019-02-08T03:30:01.915Z,1549596601.915 [logger ThreadHandler](INFO): Cycle time is: 0.034964, Sleep time was: -0.034950
2019-02-08T03:30:02.032Z,1549596602.032 [logger ThreadHandler](INFO): Cycle time is: 0.016060, Sleep time was: -0.015986
2019-02-08T03:30:02.035Z,1549596602.035 [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-08T03:30:02.148Z,1549596602.148 [logger ThreadHandler](INFO): Cycle time is: 0.015302, Sleep time was: -0.015287
2019-02-08T03:30:02.202Z,1549596602.202 [controlThread ThreadHandler](INFO): Cycle time is: 0.003453, Sleep time was: 0.225914
2019-02-08T03:30:02.256Z,1549596602.256 [logger ThreadHandler](INFO): Cycle time is: 0.007700, Sleep time was: -0.007687
2019-02-08T03:30:02.368Z,1549596602.368 [logger ThreadHandler](INFO): Cycle time is: 0.011430, Sleep time was: -0.011415
2019-02-08T03:30:02.422Z,1549596602.422 [CBIT](INFO): Clearing failed state for component BuoyancyServo
2019-02-08T03:30:02.422Z,1549596602.422 [BuoyancyServo] No Fault, FailCount= 1
2019-02-08T03:30:02.472Z,1549596602.472 [logger ThreadHandler](INFO): Cycle time is: 0.003463, Sleep time was: -0.003450
2019-02-08T03:30:02.575Z,1549596602.575 [logger ThreadHandler](INFO): Cycle time is: 0.002482, Sleep time was: -0.002468
2019-02-08T03:30:02.606Z,1549596602.606 [controlThread ThreadHandler](INFO): Cycle time is: 0.003601, Sleep time was: 0.178129
2019-02-08T03:30:02.679Z,1549596602.679 [logger ThreadHandler](INFO): Cycle time is: 0.003417, Sleep time was: -0.003403
2019-02-08T03:30:02.793Z,1549596602.793 [logger ThreadHandler](INFO): Cycle time is: 0.013207, Sleep time was: -0.013191
2019-02-08T03:30:02.915Z,1549596602.915 [logger ThreadHandler](INFO): Cycle time is: 0.021395, Sleep time was: -0.021379
2019-02-08T03:30:03.026Z,1549596603.026 [logger ThreadHandler](INFO): Cycle time is: 0.009928, Sleep time was: -0.009913
2019-02-08T03:30:03.128Z,1549596603.128 [logger ThreadHandler](INFO): Cycle time is: 0.001183, Sleep time was: -0.001140
2019-02-08T03:30:03.253Z,1549596603.253 [logger ThreadHandler](INFO): Cycle time is: 0.024863, Sleep time was: -0.024849
2019-02-08T03:30:03.378Z,1549596603.378 [logger ThreadHandler](INFO): Cycle time is: 0.024448, Sleep time was: -0.024435
2019-02-08T03:30:03.488Z,1549596603.488 [logger ThreadHandler](INFO): Cycle time is: 0.008579, Sleep time was: -0.008506
2019-02-08T03:30:03.596Z,1549596603.596 [logger ThreadHandler](INFO): Cycle time is: 0.006859, Sleep time was: -0.006812
2019-02-08T03:30:03.733Z,1549596603.733 [logger ThreadHandler](INFO): Cycle time is: 0.036146, Sleep time was: -0.036128
2019-02-08T03:30:03.847Z,1549596603.847 [logger ThreadHandler](INFO): Cycle time is: 0.012989, Sleep time was: -0.012829
2019-02-08T03:30:03.965Z,1549596603.965 [logger ThreadHandler](INFO): Cycle time is: 0.016999, Sleep time was: -0.016982
2019-02-08T03:30:04.118Z,1549596604.118 [logger ThreadHandler](INFO): Cycle time is: 0.051309, Sleep time was: -0.051234
2019-02-08T03:30:04.227Z,1549596604.227 [logger ThreadHandler](INFO): Cycle time is: 0.008832, Sleep time was: -0.008814
2019-02-08T03:30:04.344Z,1549596604.344 [logger ThreadHandler](INFO): Cycle time is: 0.015162, Sleep time was: -0.015144
2019-02-08T03:30:04.456Z,1549596604.456 [logger ThreadHandler](INFO): Cycle time is: 0.011448, Sleep time was: -0.011435
2019-02-08T03:30:04.557Z,1549596604.557 [logger ThreadHandler](INFO): Cycle time is: 0.000680, Sleep time was: -0.000667
2019-02-08T03:30:04.675Z,1549596604.675 [logger ThreadHandler](INFO): Cycle time is: 0.017530, Sleep time was: -0.017516
2019-02-08T03:30:04.791Z,1549596604.791 [logger ThreadHandler](INFO): Cycle time is: 0.015371, Sleep time was: -0.015358
2019-02-08T03:30:04.907Z,1549596604.907 [logger ThreadHandler](INFO): Cycle time is: 0.015475, Sleep time was: -0.015461
2019-02-08T03:30:05.011Z,1549596605.011 [logger ThreadHandler](INFO): Cycle time is: 0.002984, Sleep time was: -0.002969
2019-02-08T03:30:05.119Z,1549596605.119 [logger ThreadHandler](INFO): Cycle time is: 0.008318, Sleep time was: -0.008246
2019-02-08T03:30:05.235Z,1549596605.235 [logger ThreadHandler](INFO): Cycle time is: 0.015164, Sleep time was: -0.015151
2019-02-08T03:30:05.351Z,1549596605.351 [logger ThreadHandler](INFO): Cycle time is: 0.015092, Sleep time was: -0.015079
2019-02-08T03:30:05.468Z,1549596605.468 [logger ThreadHandler](INFO): Cycle time is: 0.016761, Sleep time was: -0.016747
2019-02-08T03:30:05.571Z,1549596605.571 [logger ThreadHandler](INFO): Cycle time is: 0.002503, Sleep time was: -0.002489
2019-02-08T03:30:05.679Z,1549596605.679 [logger ThreadHandler](INFO): Cycle time is: 0.007560, Sleep time was: -0.007546
2019-02-08T03:30:05.787Z,1549596605.787 [logger ThreadHandler](INFO): Cycle time is: 0.007486, Sleep time was: -0.007473
2019-02-08T03:30:05.897Z,1549596605.897 [logger ThreadHandler](INFO): Cycle time is: 0.009760, Sleep time was: -0.009746
2019-02-08T03:30:06.004Z,1549596606.004 [logger ThreadHandler](INFO): Cycle time is: 0.006190, Sleep time was: -0.006177
2019-02-08T03:30:06.111Z,1549596606.111 [logger ThreadHandler](INFO): Cycle time is: 0.005963, Sleep time was: -0.005948
2019-02-08T03:30:06.227Z,1549596606.227 [logger ThreadHandler](INFO): Cycle time is: 0.015638, Sleep time was: -0.015625
2019-02-08T03:30:06.340Z,1549596606.340 [logger ThreadHandler](INFO): Cycle time is: 0.011896, Sleep time was: -0.011884
2019-02-08T03:30:06.454Z,1549596606.454 [logger ThreadHandler](INFO): Cycle time is: 0.014250, Sleep time was: -0.014234
2019-02-08T03:30:06.557Z,1549596606.557 [logger ThreadHandler](INFO): Cycle time is: 0.001733, Sleep time was: -0.001718
2019-02-08T03:30:06.671Z,1549596606.671 [logger ThreadHandler](INFO): Cycle time is: 0.013703, Sleep time was: -0.013690
2019-02-08T03:30:06.773Z,1549596606.773 [logger ThreadHandler](INFO): Cycle time is: 0.001195, Sleep time was: -0.001182
2019-02-08T03:30:06.876Z,1549596606.876 [logger ThreadHandler](INFO): Cycle time is: 0.002708, Sleep time was: -0.002691
2019-02-08T03:30:06.984Z,1549596606.984 [logger ThreadHandler](INFO): Cycle time is: 0.006844, Sleep time was: -0.006829
2019-02-08T03:30:07.086Z,1549596607.086 [NavChartDb ThreadHandler](INFO): Cycle time is: 9.494391, Sleep time was: -9.494378
2019-02-08T03:30:07.091Z,1549596607.091 [logger ThreadHandler](INFO): Cycle time is: 0.006082, Sleep time was: -0.006068
2019-02-08T03:30:07.204Z,1549596607.204 [logger ThreadHandler](INFO): Cycle time is: 0.012455, Sleep time was: -0.012441
2019-02-08T03:30:07.320Z,1549596607.320 [logger ThreadHandler](INFO): Cycle time is: 0.015920, Sleep time was: -0.015907
2019-02-08T03:30:07.427Z,1549596607.427 [logger ThreadHandler](INFO): Cycle time is: 0.006599, Sleep time was: -0.006586
2019-02-08T03:30:07.536Z,1549596607.536 [logger ThreadHandler](INFO): Cycle time is: 0.008345, Sleep time was: -0.008331
2019-02-08T03:30:07.652Z,1549596607.652 [logger ThreadHandler](INFO): Cycle time is: 0.015169, Sleep time was: -0.015156
2019-02-08T03:30:07.756Z,1549596607.756 [logger ThreadHandler](INFO): Cycle time is: 0.003853, Sleep time was: -0.003838
2019-02-08T03:30:07.863Z,1549596607.863 [logger ThreadHandler](INFO): Cycle time is: 0.005380, Sleep time was: -0.005364
2019-02-08T03:30:07.976Z,1549596607.976 [logger ThreadHandler](INFO): Cycle time is: 0.012917, Sleep time was: -0.012845
2019-02-08T03:30:08.080Z,1549596608.080 [logger ThreadHandler](INFO): Cycle time is: 0.003311, Sleep time was: -0.003297
2019-02-08T03:30:08.193Z,1549596608.193 [logger ThreadHandler](INFO): Cycle time is: 0.012222, Sleep time was: -0.012180
2019-02-08T03:30:08.311Z,1549596608.311 [logger ThreadHandler](INFO): Cycle time is: 0.017398, Sleep time was: -0.017384
2019-02-08T03:30:08.431Z,1549596608.431 [logger ThreadHandler](INFO): Cycle time is: 0.019485, Sleep time was: -0.019471
2019-02-08T03:30:08.538Z,1549596608.538 [logger ThreadHandler](INFO): Cycle time is: 0.006836, Sleep time was: -0.006822
2019-02-08T03:30:08.648Z,1549596608.648 [logger ThreadHandler](INFO): Cycle time is: 0.008753, Sleep time was: -0.008740
2019-02-08T03:30:08.763Z,1549596608.763 [logger ThreadHandler](INFO): Cycle time is: 0.015283, Sleep time was: -0.015270
2019-02-08T03:30:08.882Z,1549596608.882 [logger ThreadHandler](INFO): Cycle time is: 0.017663, Sleep time was: -0.017646
2019-02-08T03:30:08.994Z,1549596608.994 [logger ThreadHandler](INFO): Cycle time is: 0.011171, Sleep time was: -0.011154
2019-02-08T03:30:09.096Z,1549596609.096 [logger ThreadHandler](INFO): Cycle time is: 0.001849, Sleep time was: -0.001837
2019-02-08T03:30:09.200Z,1549596609.200 [logger ThreadHandler](INFO): Cycle time is: 0.003450, Sleep time was: -0.003436
2019-02-08T03:30:09.307Z,1549596609.307 [logger ThreadHandler](INFO): Cycle time is: 0.006111, Sleep time was: -0.006098
2019-02-08T03:30:09.416Z,1549596609.416 [logger ThreadHandler](INFO): Cycle time is: 0.008276, Sleep time was: -0.008263
2019-02-08T03:30:09.531Z,1549596609.531 [logger ThreadHandler](INFO): Cycle time is: 0.014796, Sleep time was: -0.014782
2019-02-08T03:30:09.647Z,1549596609.647 [logger ThreadHandler](INFO): Cycle time is: 0.015236, Sleep time was: -0.015223
2019-02-08T03:30:09.765Z,1549596609.765 [logger ThreadHandler](INFO): Cycle time is: 0.018080, Sleep time was: -0.018067
2019-02-08T03:30:09.870Z,1549596609.870 [logger ThreadHandler](INFO): Cycle time is: 0.003693, Sleep time was: -0.003677
2019-02-08T03:30:09.981Z,1549596609.981 [logger ThreadHandler](INFO): Cycle time is: 0.010327, Sleep time was: -0.010311
2019-02-08T03:30:10.087Z,1549596610.087 [logger ThreadHandler](INFO): Cycle time is: 0.005248, Sleep time was: -0.005234
2019-02-08T03:30:10.195Z,1549596610.195 [logger ThreadHandler](INFO): Cycle time is: 0.006758, Sleep time was: -0.006743
2019-02-08T03:30:10.312Z,1549596610.312 [logger ThreadHandler](INFO): Cycle time is: 0.016706, Sleep time was: -0.016692
2019-02-08T03:30:10.420Z,1549596610.420 [logger ThreadHandler](INFO): Cycle time is: 0.007688, Sleep time was: -0.007676
2019-02-08T03:30:10.528Z,1549596610.528 [logger ThreadHandler](INFO): Cycle time is: 0.007447, Sleep time was: -0.007434
2019-02-08T03:30:10.635Z,1549596610.635 [logger ThreadHandler](INFO): Cycle time is: 0.006132, Sleep time was: -0.006118
2019-02-08T03:30:10.736Z,1549596610.736 [logger ThreadHandler](INFO): Cycle time is: 0.000866, Sleep time was: -0.000852
2019-02-08T03:30:10.839Z,1549596610.839 [logger ThreadHandler](INFO): Cycle time is: 0.002048, Sleep time was: -0.002035
2019-02-08T03:30:10.945Z,1549596610.945 [logger ThreadHandler](INFO): Cycle time is: 0.005537, Sleep time was: -0.005520
2019-02-08T03:30:11.054Z,1549596611.054 [logger ThreadHandler](INFO): Cycle time is: 0.008620, Sleep time was: -0.008605
2019-02-08T03:30:11.156Z,1549596611.156 [logger ThreadHandler](INFO): Cycle time is: 0.001236, Sleep time was: -0.001222
2019-02-08T03:30:11.272Z,1549596611.272 [logger ThreadHandler](INFO): Cycle time is: 0.015269, Sleep time was: -0.015256
2019-02-08T03:30:11.392Z,1549596611.392 [logger ThreadHandler](INFO): Cycle time is: 0.019051, Sleep time was: -0.019037
2019-02-08T03:30:11.502Z,1549596611.502 [logger ThreadHandler](INFO): Cycle time is: 0.008685, Sleep time was: -0.008614
2019-02-08T03:30:11.607Z,1549596611.607 [logger ThreadHandler](INFO): Cycle time is: 0.004166, Sleep time was: -0.004153
2019-02-08T03:30:11.715Z,1549596611.715 [logger ThreadHandler](INFO): Cycle time is: 0.007726, Sleep time was: -0.007713
2019-02-08T03:30:11.824Z,1549596611.824 [logger ThreadHandler](INFO): Cycle time is: 0.008560, Sleep time was: -0.008547
2019-02-08T03:30:11.927Z,1549596611.927 [logger ThreadHandler](INFO): Cycle time is: 0.002374, Sleep time was: -0.002299
2019-02-08T03:30:12.030Z,1549596612.030 [logger ThreadHandler](INFO): Cycle time is: 0.001874, Sleep time was: -0.001861
2019-02-08T03:30:12.140Z,1549596612.140 [logger ThreadHandler](INFO): Cycle time is: 0.009302, Sleep time was: -0.009289
2019-02-08T03:30:12.247Z,1549596612.247 [logger ThreadHandler](INFO): Cycle time is: 0.006823, Sleep time was: -0.006809
2019-02-08T03:30:12.363Z,1549596612.363 [logger ThreadHandler](INFO): Cycle time is: 0.015540, Sleep time was: -0.015526
2019-02-08T03:30:12.479Z,1549596612.479 [logger ThreadHandler](INFO): Cycle time is: 0.015672, Sleep time was: -0.015659
2019-02-08T03:30:12.581Z,1549596612.581 [logger ThreadHandler](INFO): Cycle time is: 0.001430, Sleep time was: -0.001417
2019-02-08T03:30:12.690Z,1549596612.690 [logger ThreadHandler](INFO): Cycle time is: 0.008814, Sleep time was: -0.008799
2019-02-08T03:30:12.800Z,1549596612.800 [logger ThreadHandler](INFO): Cycle time is: 0.009050, Sleep time was: -0.009037
2019-02-08T03:30:12.904Z,1549596612.904 [logger ThreadHandler](INFO): Cycle time is: 0.003208, Sleep time was: -0.003191
2019-02-08T03:30:13.012Z,1549596613.012 [logger ThreadHandler](INFO): Cycle time is: 0.007151, Sleep time was: -0.007137
2019-02-08T03:30:13.113Z,1549596613.113 [logger ThreadHandler](INFO): Cycle time is: 0.000975, Sleep time was: -0.000961
2019-02-08T03:30:13.221Z,1549596613.221 [logger ThreadHandler](INFO): Cycle time is: 0.007182, Sleep time was: -0.007168
2019-02-08T03:30:13.315Z,1549596613.315 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2019-02-08T03:30:13.316Z,1549596613.316 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2019-02-08T03:30:13.327Z,1549596613.327 [logger ThreadHandler](INFO): Cycle time is: 0.005338, Sleep time was: -0.005325
2019-02-08T03:30:13.448Z,1549596613.448 [logger ThreadHandler](INFO): Cycle time is: 0.020454, Sleep time was: -0.020440
2019-02-08T03:30:13.486Z,1549596613.486 [CBIT](CRITICAL): Environmental Failure. Press:14.860636 PSI. Humidity:26%. Temp:26 C. ABORTING MISSION
2019-02-08T03:30:13.489Z,1549596613.489 [controlThread ThreadHandler](INFO): Cycle time is: 10.482334, Sleep time was: -10.482321
2019-02-08T03:30:13.494Z,1549596613.494 [Aanderaa_O2](INFO): Powering down
2019-02-08T03:30:13.553Z,1549596613.553 [logger ThreadHandler](INFO): Cycle time is: 0.004144, Sleep time was: -0.004130
2019-02-08T03:30:13.574Z,1549596613.574 [AcousticModem_Benthos_ATM900](DEBUG): 
2019-02-08T03:30:13.583Z,1549596613.583 [AcousticModem_Benthos_ATM900](DEBUG): Teledyne Benthos ATM-900 Series OEM w/burn wire
2019-02-08T03:30:13.584Z,1549596613.584 [AcousticModem_Benthos_ATM900](DEBUG): MF Frequency Band
2019-02-08T03:30:13.585Z,1549596613.585 [AcousticModem_Benthos_ATM900](DEBUG): Standard version 8.6.3
2019-02-08T03:30:13.586Z,1549596613.586 [AcousticModem_Benthos_ATM900](DEBUG): Feb  8 2019 03:33:05 
2019-02-08T03:30:13.595Z,1549596613.595 [AcousticModem_Benthos_ATM900](DEBUG): WARNING: battery low
2019-02-08T03:30:13.675Z,1549596613.675 [logger ThreadHandler](INFO): Cycle time is: 0.021430, Sleep time was: -0.021415
2019-02-08T03:30:13.764Z,1549596613.764 [CBIT](INFO): Critical error at 20190208T033013
2019-02-08T03:30:13.779Z,1549596613.779 [logger ThreadHandler](INFO): Cycle time is: 0.004137, Sleep time was: -0.004125
2019-02-08T03:30:13.885Z,1549596613.885 [logger ThreadHandler](INFO): Cycle time is: 0.004657, Sleep time was: -0.004640
2019-02-08T03:30:13.891Z,1549596613.891 [controlThread ThreadHandler](INFO): Cycle time is: 0.000744, Sleep time was: 0.113460
2019-02-08T03:30:13.989Z,1549596613.989 [logger ThreadHandler](INFO): Cycle time is: 0.003401, Sleep time was: -0.003384
2019-02-08T03:30:14.103Z,1549596614.103 [logger ThreadHandler](INFO): Cycle time is: 0.011943, Sleep time was: -0.011880
2019-02-08T03:30:14.211Z,1549596614.211 [logger ThreadHandler](INFO): Cycle time is: 0.007057, Sleep time was: -0.007044
2019-02-08T03:30:14.294Z,1549596614.294 [controlThread ThreadHandler](INFO): Cycle time is: 0.002683, Sleep time was: 0.102194
2019-02-08T03:30:14.303Z,1549596614.303 [AcousticModem_Benthos_ATM900](INFO): entering command mode
2019-02-08T03:30:14.310Z,1549596614.310 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.005539
2019-02-08T03:30:14.348Z,1549596614.348 [logger ThreadHandler](INFO): Cycle time is: 0.036395, Sleep time was: -0.036380
2019-02-08T03:30:14.449Z,1549596614.449 [logger ThreadHandler](INFO): Cycle time is: 0.000934, Sleep time was: -0.000921
2019-02-08T03:30:14.551Z,1549596614.551 [logger ThreadHandler](INFO): Cycle time is: 0.001396, Sleep time was: -0.001383
2019-02-08T03:30:14.655Z,1549596614.655 [logger ThreadHandler](INFO): Cycle time is: 0.003294, Sleep time was: -0.003280
2019-02-08T03:30:14.698Z,1549596614.698 [controlThread ThreadHandler](INFO): Cycle time is: 0.003523, Sleep time was: 0.253009
2019-02-08T03:30:14.709Z,1549596614.709 [AcousticModem_Benthos_ATM900](DEBUG): checking for command mode acknowledgment
2019-02-08T03:30:14.711Z,1549596614.711 [AcousticModem_Benthos_ATM900](DEBUG): read user prompt 1: user:1>
2019-02-08T03:30:14.711Z,1549596614.711 [AcousticModem_Benthos_ATM900](INFO): command mode acknowledged
2019-02-08T03:30:14.756Z,1549596614.756 [logger ThreadHandler](INFO): Cycle time is: 0.001030, Sleep time was: -0.001016
2019-02-08T03:30:14.861Z,1549596614.861 [logger ThreadHandler](INFO): Cycle time is: 0.003479, Sleep time was: -0.003330
2019-02-08T03:30:14.972Z,1549596614.972 [logger ThreadHandler](INFO): Cycle time is: 0.010850, Sleep time was: -0.010749
2019-02-08T03:30:15.079Z,1549596615.079 [logger ThreadHandler](INFO): Cycle time is: 0.006305, Sleep time was: -0.006291
2019-02-08T03:30:15.102Z,1549596615.102 [controlThread ThreadHandler](INFO): Cycle time is: 0.003412, Sleep time was: 0.281046
2019-02-08T03:30:15.111Z,1549596615.111 [AcousticModem_Benthos_ATM900](INFO): setting local address to 3
2019-02-08T03:30:15.199Z,1549596615.199 [logger ThreadHandler](INFO): Cycle time is: 0.019556, Sleep time was: -0.019541
2019-02-08T03:30:15.304Z,1549596615.304 [logger ThreadHandler](INFO): Cycle time is: 0.004278, Sleep time was: -0.004263
2019-02-08T03:30:15.407Z,1549596615.407 [logger ThreadHandler](INFO): Cycle time is: 0.002386, Sleep time was: -0.002374
2019-02-08T03:30:15.506Z,1549596615.506 [controlThread ThreadHandler](INFO): Cycle time is: 0.003589, Sleep time was: 0.225057
2019-02-08T03:30:15.533Z,1549596615.533 [AcousticModem_Benthos_ATM900](DEBUG): checking for local address setting acknowledgment
2019-02-08T03:30:15.538Z,1549596615.538 [AcousticModem_Benthos_ATM900](INFO): set local address to 3
2019-02-08T03:30:15.546Z,1549596615.546 [logger ThreadHandler](INFO): Cycle time is: 0.037635, Sleep time was: -0.037621
2019-02-08T03:30:15.655Z,1549596615.655 [logger ThreadHandler](INFO): Cycle time is: 0.008811, Sleep time was: -0.008798
2019-02-08T03:30:15.759Z,1549596615.759 [logger ThreadHandler](INFO): Cycle time is: 0.003008, Sleep time was: -0.002994
2019-02-08T03:30:15.865Z,1549596615.865 [logger ThreadHandler](INFO): Cycle time is: 0.005475, Sleep time was: -0.005458
2019-02-08T03:30:15.916Z,1549596615.916 [controlThread ThreadHandler](INFO): Cycle time is: 0.003586, Sleep time was: 0.252784
2019-02-08T03:30:15.932Z,1549596615.932 [AcousticModem_Benthos_ATM900](DEBUG): read user prompt 2: user:2>
2019-02-08T03:30:15.972Z,1549596615.972 [logger ThreadHandler](INFO): Cycle time is: 0.006104, Sleep time was: -0.006059
2019-02-08T03:30:16.073Z,1549596616.073 [logger ThreadHandler](INFO): Cycle time is: 0.001105, Sleep time was: -0.001093
2019-02-08T03:30:16.179Z,1549596616.179 [logger ThreadHandler](INFO): Cycle time is: 0.005090, Sleep time was: -0.005076
2019-02-08T03:30:16.280Z,1549596616.280 [logger ThreadHandler](INFO): Cycle time is: 0.001010, Sleep time was: -0.000997
2019-02-08T03:30:16.330Z,1549596616.330 [controlThread ThreadHandler](INFO): Cycle time is: 0.001731, Sleep time was: 0.243957
2019-02-08T03:30:16.390Z,1549596616.390 [logger ThreadHandler](INFO): Cycle time is: 0.009643, Sleep time was: -0.009628
2019-02-08T03:30:16.495Z,1549596616.495 [logger ThreadHandler](INFO): Cycle time is: 0.003911, Sleep time was: -0.003898
2019-02-08T03:30:16.599Z,1549596616.599 [logger ThreadHandler](INFO): Cycle time is: 0.004039, Sleep time was: -0.004026
2019-02-08T03:30:16.703Z,1549596616.703 [logger ThreadHandler](INFO): Cycle time is: 0.003071, Sleep time was: -0.003057
2019-02-08T03:30:16.734Z,1549596616.734 [controlThread ThreadHandler](INFO): Cycle time is: 0.003819, Sleep time was: 0.247606
2019-02-08T03:30:16.820Z,1549596616.820 [logger ThreadHandler](INFO): Cycle time is: 0.016113, Sleep time was: -0.016100
2019-02-08T03:30:16.929Z,1549596616.929 [logger ThreadHandler](INFO): Cycle time is: 0.008639, Sleep time was: -0.008625
2019-02-08T03:30:17.044Z,1549596617.044 [logger ThreadHandler](INFO): Cycle time is: 0.013819, Sleep time was: -0.013805
2019-02-08T03:30:17.138Z,1549596617.138 [controlThread ThreadHandler](INFO): Cycle time is: 0.003444, Sleep time was: 0.218573
2019-02-08T03:30:17.160Z,1549596617.160 [logger ThreadHandler](INFO): Cycle time is: 0.016148, Sleep time was: -0.016133
2019-02-08T03:30:17.264Z,1549596617.264 [logger ThreadHandler](INFO): Cycle time is: 0.003737, Sleep time was: -0.003724
2019-02-08T03:30:17.366Z,1549596617.366 [logger ThreadHandler](INFO): Cycle time is: 0.000661, Sleep time was: -0.000648
2019-02-08T03:30:17.471Z,1549596617.471 [logger ThreadHandler](INFO): Cycle time is: 0.004705, Sleep time was: -0.004692
2019-02-08T03:30:17.542Z,1549596617.542 [controlThread ThreadHandler](INFO): Cycle time is: 0.003500, Sleep time was: 0.236089
2019-02-08T03:30:17.595Z,1549596617.595 [logger ThreadHandler](INFO): Cycle time is: 0.023261, Sleep time was: -0.023247
2019-02-08T03:30:17.699Z,1549596617.699 [logger ThreadHandler](INFO): Cycle time is: 0.003416, Sleep time was: -0.003402
2019-02-08T03:30:17.803Z,1549596617.803 [logger ThreadHandler](INFO): Cycle time is: 0.003763, Sleep time was: -0.003749
2019-02-08T03:30:17.917Z,1549596617.917 [logger ThreadHandler](INFO): Cycle time is: 0.012699, Sleep time was: -0.012666
2019-02-08T03:30:17.947Z,1549596617.947 [controlThread ThreadHandler](INFO): Cycle time is: 0.004152, Sleep time was: 0.284320
2019-02-08T03:30:18.032Z,1549596618.032 [logger ThreadHandler](INFO): Cycle time is: 0.013783, Sleep time was: -0.013769
2019-02-08T03:30:18.133Z,1549596618.133 [logger ThreadHandler](INFO): Cycle time is: 0.000805, Sleep time was: -0.000792
2019-02-08T03:30:18.246Z,1549596618.246 [logger ThreadHandler](INFO): Cycle time is: 0.012846, Sleep time was: -0.012833
2019-02-08T03:30:18.349Z,1549596618.349 [logger ThreadHandler](INFO): Cycle time is: 0.001730, Sleep time was: -0.001715
2019-02-08T03:30:18.350Z,1549596618.350 [controlThread ThreadHandler](INFO): Cycle time is: 0.002417, Sleep time was: 0.224783
2019-02-08T03:30:18.460Z,1549596618.460 [logger ThreadHandler](INFO): Cycle time is: 0.010618, Sleep time was: -0.010605
2019-02-08T03:30:18.562Z,1549596618.562 [logger ThreadHandler](INFO): Cycle time is: 0.000909, Sleep time was: -0.000896
2019-02-08T03:30:18.675Z,1549596618.675 [logger ThreadHandler](INFO): Cycle time is: 0.012616, Sleep time was: -0.012602
2019-02-08T03:30:18.732Z,1549596618.732 [NavChartDb ThreadHandler](INFO): Cycle time is: 11.545214, Sleep time was: -11.545144
2019-02-08T03:30:18.754Z,1549596618.754 [controlThread ThreadHandler](INFO): Cycle time is: 0.003513, Sleep time was: 0.280606
2019-02-08T03:30:18.814Z,1549596618.814 [logger ThreadHandler](INFO): Cycle time is: 0.038984, Sleep time was: -0.038970
2019-02-08T03:30:18.919Z,1549596618.919 [logger ThreadHandler](INFO): Cycle time is: 0.004188, Sleep time was: -0.004171
2019-02-08T03:30:19.023Z,1549596619.023 [logger ThreadHandler](INFO): Cycle time is: 0.003459, Sleep time was: -0.003445
2019-02-08T03:30:19.130Z,1549596619.130 [logger ThreadHandler](INFO): Cycle time is: 0.005325, Sleep time was: -0.005255
2019-02-08T03:30:19.158Z,1549596619.158 [controlThread ThreadHandler](INFO): Cycle time is: 0.003570, Sleep time was: 0.324387
2019-02-08T03:30:19.244Z,1549596619.244 [logger ThreadHandler](INFO): Cycle time is: 0.013196, Sleep time was: -0.013183
2019-02-08T03:30:19.345Z,1549596619.345 [logger ThreadHandler](INFO): Cycle time is: 0.000765, Sleep time was: -0.000753
2019-02-08T03:30:19.448Z,1549596619.448 [logger ThreadHandler](INFO): Cycle time is: 0.002971, Sleep time was: -0.002958
2019-02-08T03:30:19.558Z,1549596619.558 [logger ThreadHandler](INFO): Cycle time is: 0.009587, Sleep time was: -0.009574
2019-02-08T03:30:19.563Z,1549596619.563 [controlThread ThreadHandler](INFO): Cycle time is: 0.004182, Sleep time was: 0.307614
2019-02-08T03:30:19.660Z,1549596619.660 [logger ThreadHandler](INFO): Cycle time is: 0.001140, Sleep time was: -0.001127
2019-02-08T03:30:19.763Z,1549596619.763 [logger ThreadHandler](INFO): Cycle time is: 0.002549, Sleep time was: -0.002537
2019-02-08T03:30:19.868Z,1549596619.868 [logger ThreadHandler](INFO): Cycle time is: 0.004485, Sleep time was: -0.004468
2019-02-08T03:30:19.966Z,1549596619.966 [controlThread ThreadHandler](INFO): Cycle time is: 0.002819, Sleep time was: 0.319635
2019-02-08T03:30:20.031Z,1549596620.031 [logger ThreadHandler](INFO): Cycle time is: 0.061448, Sleep time was: -0.061432
2019-02-08T03:30:20.142Z,1549596620.142 [logger ThreadHandler](INFO): Cycle time is: 0.011317, Sleep time was: -0.011302
2019-02-08T03:30:20.247Z,1549596620.247 [logger ThreadHandler](INFO): Cycle time is: 0.004136, Sleep time was: -0.004123
2019-02-08T03:30:20.358Z,1549596620.358 [logger ThreadHandler](INFO): Cycle time is: 0.010923, Sleep time was: -0.010908
2019-02-08T03:30:20.370Z,1549596620.370 [controlThread ThreadHandler](INFO): Cycle time is: 0.003443, Sleep time was: 0.225173
2019-02-08T03:30:20.464Z,1549596620.464 [logger ThreadHandler](INFO): Cycle time is: 0.004810, Sleep time was: -0.004797
2019-02-08T03:30:20.533Z,1549596620.533 [NavChartDb ThreadHandler](INFO): Cycle time is: 1.699973, Sleep time was: -1.699958
2019-02-08T03:30:20.567Z,1549596620.567 [logger ThreadHandler](INFO): Cycle time is: 0.002719, Sleep time was: -0.002706
2019-02-08T03:30:20.675Z,1549596620.675 [logger ThreadHandler](INFO): Cycle time is: 0.007201, Sleep time was: -0.007188
2019-02-08T03:30:20.774Z,1549596620.774 [controlThread ThreadHandler](INFO): Cycle time is: 0.003530, Sleep time was: 0.307762
2019-02-08T03:30:20.815Z,1549596620.815 [logger ThreadHandler](INFO): Cycle time is: 0.039456, Sleep time was: -0.039442
2019-02-08T03:30:20.921Z,1549596620.921 [logger ThreadHandler](INFO): Cycle time is: 0.005546, Sleep time was: -0.005530
2019-02-08T03:30:21.033Z,1549596621.033 [logger ThreadHandler](INFO): Cycle time is: 0.011384, Sleep time was: -0.011367
2019-02-08T03:30:21.141Z,1549596621.141 [logger ThreadHandler](INFO): Cycle time is: 0.007137, Sleep time was: -0.007124
2019-02-08T03:30:21.178Z,1549596621.178 [controlThread ThreadHandler](INFO): Cycle time is: 0.003641, Sleep time was: 0.229839
2019-02-08T03:30:21.261Z,1549596621.261 [logger ThreadHandler](INFO): Cycle time is: 0.019818, Sleep time was: -0.019807
2019-02-08T03:30:21.363Z,1549596621.363 [logger ThreadHandler](INFO): Cycle time is: 0.001353, Sleep time was: -0.001339
2019-02-08T03:30:21.467Z,1549596621.467 [logger ThreadHandler](INFO): Cycle time is: 0.003236, Sleep time was: -0.003223
2019-02-08T03:30:21.569Z,1549596621.569 [logger ThreadHandler](INFO): Cycle time is: 0.002007, Sleep time was: -0.001993
2019-02-08T03:30:21.582Z,1549596621.582 [controlThread ThreadHandler](INFO): Cycle time is: 0.003446, Sleep time was: 0.318127
2019-02-08T03:30:21.671Z,1549596621.671 [logger ThreadHandler](INFO): Cycle time is: 0.001393, Sleep time was: -0.001380
2019-02-08T03:30:21.773Z,1549596621.773 [logger ThreadHandler](INFO): Cycle time is: 0.001261, Sleep time was: -0.001247
2019-02-08T03:30:21.878Z,1549596621.878 [logger ThreadHandler](INFO): Cycle time is: 0.003557, Sleep time was: -0.003540
2019-02-08T03:30:21.982Z,1549596621.982 [logger ThreadHandler](INFO): Cycle time is: 0.004185, Sleep time was: -0.004050
2019-02-08T03:30:21.987Z,1549596621.987 [controlThread ThreadHandler](INFO): Cycle time is: 0.003710, Sleep time was: 0.320729
2019-02-08T03:30:22.084Z,1549596622.084 [logger ThreadHandler](INFO): Cycle time is: 0.001646, Sleep time was: -0.001633
2019-02-08T03:30:22.086Z,1549596622.086 [SBIT](IMPORTANT): Beginning Startup BIT
2019-02-08T03:30:22.099Z,1549596622.099 [CBIT](IMPORTANT): Beginning ground fault scan
2019-02-08T03:30:22.187Z,1549596622.187 [logger ThreadHandler](INFO): Cycle time is: 0.002464, Sleep time was: -0.002451
2019-02-08T03:30:22.300Z,1549596622.300 [logger ThreadHandler](INFO): Cycle time is: 0.012299, Sleep time was: -0.012286
2019-02-08T03:30:22.390Z,1549596622.390 [controlThread ThreadHandler](INFO): Cycle time is: 0.002998, Sleep time was: 0.286161
2019-02-08T03:30:22.409Z,1549596622.409 [logger ThreadHandler](INFO): Cycle time is: 0.005230, Sleep time was: -0.005216
2019-02-08T03:30:22.520Z,1549596622.520 [logger ThreadHandler](INFO): Cycle time is: 0.009491, Sleep time was: -0.009477
2019-02-08T03:30:22.621Z,1549596622.621 [logger ThreadHandler](INFO): Cycle time is: 0.001181, Sleep time was: -0.001168
2019-02-08T03:30:22.732Z,1549596622.732 [logger ThreadHandler](INFO): Cycle time is: 0.009697, Sleep time was: -0.009684
2019-02-08T03:30:22.768Z,1549596622.768 [NavChartDb ThreadHandler](INFO): Cycle time is: 2.134375, Sleep time was: -2.134361
2019-02-08T03:30:22.794Z,1549596622.794 [controlThread ThreadHandler](INFO): Cycle time is: 0.003548, Sleep time was: 0.214687
2019-02-08T03:30:22.839Z,1549596622.839 [logger ThreadHandler](INFO): Cycle time is: 0.006659, Sleep time was: -0.006645
2019-02-08T03:30:22.945Z,1549596622.945 [logger ThreadHandler](INFO): Cycle time is: 0.005056, Sleep time was: -0.005039
2019-02-08T03:30:23.064Z,1549596623.064 [logger ThreadHandler](INFO): Cycle time is: 0.018338, Sleep time was: -0.018325
2019-02-08T03:30:23.167Z,1549596623.167 [logger ThreadHandler](INFO): Cycle time is: 0.003123, Sleep time was: -0.003108
2019-02-08T03:30:23.198Z,1549596623.198 [controlThread ThreadHandler](INFO): Cycle time is: 0.003482, Sleep time was: 0.102907
2019-02-08T03:30:23.271Z,1549596623.271 [logger ThreadHandler](INFO): Cycle time is: 0.003199, Sleep time was: -0.003185
2019-02-08T03:30:23.373Z,1549596623.373 [logger ThreadHandler](INFO): Cycle time is: 0.000898, Sleep time was: -0.000884
2019-02-08T03:30:23.475Z,1549596623.475 [logger ThreadHandler](INFO): Cycle time is: 0.001930, Sleep time was: -0.001916
2019-02-08T03:30:23.579Z,1549596623.579 [logger ThreadHandler](INFO): Cycle time is: 0.003471, Sleep time was: -0.003458
2019-02-08T03:30:23.602Z,1549596623.602 [controlThread ThreadHandler](INFO): Cycle time is: 0.003471, Sleep time was: 0.263812
2019-02-08T03:30:23.683Z,1549596623.683 [logger ThreadHandler](INFO): Cycle time is: 0.003382, Sleep time was: -0.003370
2019-02-08T03:30:23.784Z,1549596623.784 [logger ThreadHandler](INFO): Cycle time is: 0.000821, Sleep time was: -0.000808
2019-02-08T03:30:23.897Z,1549596623.897 [logger ThreadHandler](INFO): Cycle time is: 0.012203, Sleep time was: -0.012126
2019-02-08T03:30:24.005Z,1549596624.005 [logger ThreadHandler](INFO): Cycle time is: 0.006866, Sleep time was: -0.006849
2019-02-08T03:30:24.006Z,1549596624.006 [controlThread ThreadHandler](INFO): Cycle time is: 0.003575, Sleep time was: 0.064052
2019-02-08T03:30:24.135Z,1549596624.135 [logger ThreadHandler](INFO): Cycle time is: 0.029960, Sleep time was: -0.029946
2019-02-08T03:30:24.237Z,1549596624.237 [logger ThreadHandler](INFO): Cycle time is: 0.000782, Sleep time was: -0.000770
2019-02-08T03:30:24.339Z,1549596624.339 [logger ThreadHandler](INFO): Cycle time is: 0.002137, Sleep time was: -0.002123
2019-02-08T03:30:24.441Z,1549596624.441 [logger ThreadHandler](INFO): Cycle time is: 0.001157, Sleep time was: -0.001142
2019-02-08T03:30:24.554Z,1549596624.554 [logger ThreadHandler](INFO): Cycle time is: 0.010870, Sleep time was: -0.010805
2019-02-08T03:30:24.583Z,1549596624.583 [controlThread ThreadHandler](INFO): Cycle time is: 0.175449, Sleep time was: -0.175436
2019-02-08T03:30:24.600Z,1549596624.600 [NAL9602](INFO): Powering up NAL9602
2019-02-08T03:30:24.663Z,1549596624.663 [logger ThreadHandler](INFO): Cycle time is: 0.008549, Sleep time was: -0.008536
2019-02-08T03:30:24.766Z,1549596624.766 [logger ThreadHandler](INFO): Cycle time is: 0.001878, Sleep time was: -0.001864
2019-02-08T03:30:24.876Z,1549596624.876 [logger ThreadHandler](INFO): Cycle time is: 0.009780, Sleep time was: -0.009680
2019-02-08T03:30:24.984Z,1549596624.984 [logger ThreadHandler](INFO): Cycle time is: 0.007409, Sleep time was: -0.007390
2019-02-08T03:30:24.987Z,1549596624.987 [controlThread ThreadHandler](INFO): Cycle time is: 0.003727, Sleep time was: 0.144650
2019-02-08T03:30:25.111Z,1549596625.111 [logger ThreadHandler](INFO): Cycle time is: 0.026075, Sleep time was: -0.026062
2019-02-08T03:30:25.215Z,1549596625.215 [logger ThreadHandler](INFO): Cycle time is: 0.003064, Sleep time was: -0.003052
2019-02-08T03:30:25.327Z,1549596625.327 [logger ThreadHandler](INFO): Cycle time is: 0.011729, Sleep time was: -0.011716
2019-02-08T03:30:25.390Z,1549596625.390 [controlThread ThreadHandler](INFO): Cycle time is: 0.002860, Sleep time was: 0.083790
2019-02-08T03:30:25.432Z,1549596625.432 [logger ThreadHandler](INFO): Cycle time is: 0.003131, Sleep time was: -0.003117
2019-02-08T03:30:25.536Z,1549596625.536 [logger ThreadHandler](INFO): Cycle time is: 0.002322, Sleep time was: -0.002250
2019-02-08T03:30:25.646Z,1549596625.646 [logger ThreadHandler](INFO): Cycle time is: 0.010186, Sleep time was: -0.010172
2019-02-08T03:30:25.755Z,1549596625.755 [logger ThreadHandler](INFO): Cycle time is: 0.008349, Sleep time was: -0.008336
2019-02-08T03:30:25.794Z,1549596625.794 [controlThread ThreadHandler](INFO): Cycle time is: 0.003398, Sleep time was: 0.153334
2019-02-08T03:30:25.859Z,1549596625.859 [logger ThreadHandler](INFO): Cycle time is: 0.003344, Sleep time was: -0.003330
2019-02-08T03:30:25.962Z,1549596625.962 [logger ThreadHandler](INFO): Cycle time is: 0.001939, Sleep time was: -0.001922
2019-02-08T03:30:26.065Z,1549596626.065 [logger ThreadHandler](INFO): Cycle time is: 0.002595, Sleep time was: -0.002582
2019-02-08T03:30:26.167Z,1549596626.167 [logger ThreadHandler](INFO): Cycle time is: 0.001109, Sleep time was: -0.001095
2019-02-08T03:30:26.198Z,1549596626.198 [controlThread ThreadHandler](INFO): Cycle time is: 0.003477, Sleep time was: 0.213552
2019-02-08T03:30:26.268Z,1549596626.268 [logger ThreadHandler](INFO): Cycle time is: 0.000805, Sleep time was: -0.000792
2019-02-08T03:30:26.369Z,1549596626.369 [logger ThreadHandler](INFO): Cycle time is: 0.000778, Sleep time was: -0.000764
2019-02-08T03:30:26.475Z,1549596626.475 [logger ThreadHandler](INFO): Cycle time is: 0.004921, Sleep time was: -0.004907
2019-02-08T03:30:26.579Z,1549596626.579 [logger ThreadHandler](INFO): Cycle time is: 0.003830, Sleep time was: -0.003816
2019-02-08T03:30:26.602Z,1549596626.602 [controlThread ThreadHandler](INFO): Cycle time is: 0.003501, Sleep time was: 0.159082
2019-02-08T03:30:26.681Z,1549596626.681 [logger ThreadHandler](INFO): Cycle time is: 0.000780, Sleep time was: -0.000767
2019-02-08T03:30:26.783Z,1549596626.783 [logger ThreadHandler](INFO): Cycle time is: 0.002129, Sleep time was: -0.002115
2019-02-08T03:30:26.891Z,1549596626.891 [logger ThreadHandler](INFO): Cycle time is: 0.006947, Sleep time was: -0.006869
2019-02-08T03:30:26.997Z,1549596626.997 [logger ThreadHandler](INFO): Cycle time is: 0.004579, Sleep time was: -0.004562
2019-02-08T03:30:27.007Z,1549596627.007 [controlThread ThreadHandler](INFO): Cycle time is: 0.003671, Sleep time was: 0.209548
2019-02-08T03:30:27.103Z,1549596627.103 [logger ThreadHandler](INFO): Cycle time is: 0.005928, Sleep time was: -0.005916
2019-02-08T03:30:27.207Z,1549596627.207 [logger ThreadHandler](INFO): Cycle time is: 0.003316, Sleep time was: -0.003303
2019-02-08T03:30:27.311Z,1549596627.311 [logger ThreadHandler](INFO): Cycle time is: 0.003388, Sleep time was: -0.003375
2019-02-08T03:30:27.371Z,1549596627.371 [NavChartDb ThreadHandler](INFO): Cycle time is: 4.502752, Sleep time was: -4.502738
2019-02-08T03:30:27.410Z,1549596627.410 [controlThread ThreadHandler](INFO): Cycle time is: 0.002868, Sleep time was: 0.257942
2019-02-08T03:30:27.438Z,1549596627.438 [logger ThreadHandler](INFO): Cycle time is: 0.025348, Sleep time was: -0.025334
2019-02-08T03:30:27.551Z,1549596627.551 [logger ThreadHandler](INFO): Cycle time is: 0.012753, Sleep time was: -0.012739
2019-02-08T03:30:27.659Z,1549596627.659 [logger ThreadHandler](INFO): Cycle time is: 0.007048, Sleep time was: -0.007036
2019-02-08T03:30:27.767Z,1549596627.767 [logger ThreadHandler](INFO): Cycle time is: 0.007745, Sleep time was: -0.007731
2019-02-08T03:30:27.814Z,1549596627.814 [controlThread ThreadHandler](INFO): Cycle time is: 0.003425, Sleep time was: 0.159182
2019-02-08T03:30:27.879Z,1549596627.879 [logger ThreadHandler](INFO): Cycle time is: 0.010211, Sleep time was: -0.010194
2019-02-08T03:30:27.985Z,1549596627.985 [logger ThreadHandler](INFO): Cycle time is: 0.005503, Sleep time was: -0.005400
2019-02-08T03:30:28.091Z,1549596628.091 [logger ThreadHandler](INFO): Cycle time is: 0.005398, Sleep time was: -0.005385
2019-02-08T03:30:28.197Z,1549596628.197 [logger ThreadHandler](INFO): Cycle time is: 0.005452, Sleep time was: -0.005437
2019-02-08T03:30:28.218Z,1549596628.218 [controlThread ThreadHandler](INFO): Cycle time is: 0.003458, Sleep time was: 0.112403
2019-02-08T03:30:28.307Z,1549596628.307 [logger ThreadHandler](INFO): Cycle time is: 0.009012, Sleep time was: -0.008999
2019-02-08T03:30:28.411Z,1549596628.411 [logger ThreadHandler](INFO): Cycle time is: 0.003568, Sleep time was: -0.003554
2019-02-08T03:30:28.515Z,1549596628.515 [logger ThreadHandler](INFO): Cycle time is: 0.003344, Sleep time was: -0.003330
2019-02-08T03:30:28.620Z,1549596628.620 [logger ThreadHandler](INFO): Cycle time is: 0.004428, Sleep time was: -0.004415
2019-02-08T03:30:28.622Z,1549596628.622 [controlThread ThreadHandler](INFO): Cycle time is: 0.003639, Sleep time was: 0.257700
2019-02-08T03:30:28.721Z,1549596628.721 [logger ThreadHandler](INFO): Cycle time is: 0.000891, Sleep time was: -0.000877
2019-02-08T03:30:28.824Z,1549596628.824 [logger ThreadHandler](INFO): Cycle time is: 0.002491, Sleep time was: -0.002477
2019-02-08T03:30:28.936Z,1549596628.936 [logger ThreadHandler](INFO): Cycle time is: 0.011189, Sleep time was: -0.011120
2019-02-08T03:30:29.027Z,1549596629.027 [controlThread ThreadHandler](INFO): Cycle time is: 0.003617, Sleep time was: 0.249263
2019-02-08T03:30:29.049Z,1549596629.049 [logger ThreadHandler](INFO): Cycle time is: 0.012761, Sleep time was: -0.012748
2019-02-08T03:30:29.151Z,1549596629.151 [logger ThreadHandler](INFO): Cycle time is: 0.000938, Sleep time was: -0.000925
2019-02-08T03:30:29.252Z,1549596629.252 [logger ThreadHandler](INFO): Cycle time is: 0.000828, Sleep time was: -0.000815
2019-02-08T03:30:29.364Z,1549596629.364 [logger ThreadHandler](INFO): Cycle time is: 0.011512, Sleep time was: -0.011498
2019-02-08T03:30:29.430Z,1549596629.430 [controlThread ThreadHandler](INFO): Cycle time is: 0.003024, Sleep time was: 0.123515
2019-02-08T03:30:29.484Z,1549596629.484 [logger ThreadHandler](INFO): Cycle time is: 0.018887, Sleep time was: -0.018875
2019-02-08T03:30:29.589Z,1549596629.589 [logger ThreadHandler](INFO): Cycle time is: 0.004806, Sleep time was: -0.004792
2019-02-08T03:30:29.699Z,1549596629.699 [logger ThreadHandler](INFO): Cycle time is: 0.009519, Sleep time was: -0.009505
2019-02-08T03:30:29.803Z,1549596629.803 [logger ThreadHandler](INFO): Cycle time is: 0.003480, Sleep time was: -0.003467
2019-02-08T03:30:29.834Z,1549596629.834 [controlThread ThreadHandler](INFO): Cycle time is: 0.003575, Sleep time was: 0.283783
2019-02-08T03:30:29.922Z,1549596629.922 [logger ThreadHandler](INFO): Cycle time is: 0.018047, Sleep time was: -0.018029
2019-02-08T03:30:30.043Z,1549596630.043 [logger ThreadHandler](INFO): Cycle time is: 0.020652, Sleep time was: -0.020638
2019-02-08T03:30:30.148Z,1549596630.148 [logger ThreadHandler](INFO): Cycle time is: 0.004275, Sleep time was: -0.004262
2019-02-08T03:30:30.238Z,1549596630.238 [controlThread ThreadHandler](INFO): Cycle time is: 0.003467, Sleep time was: 0.128260
2019-02-08T03:30:30.263Z,1549596630.263 [logger ThreadHandler](INFO): Cycle time is: 0.014532, Sleep time was: -0.014519
2019-02-08T03:30:30.365Z,1549596630.365 [logger ThreadHandler](INFO): Cycle time is: 0.001772, Sleep time was: -0.001757
2019-02-08T03:30:30.475Z,1549596630.475 [logger ThreadHandler](INFO): Cycle time is: 0.009116, Sleep time was: -0.009103
2019-02-08T03:30:30.576Z,1549596630.576 [logger ThreadHandler](INFO): Cycle time is: 0.000734, Sleep time was: -0.000720
2019-02-08T03:30:30.642Z,1549596630.642 [controlThread ThreadHandler](INFO): Cycle time is: 0.003486, Sleep time was: 0.110986
2019-02-08T03:30:30.681Z,1549596630.681 [logger ThreadHandler](INFO): Cycle time is: 0.004768, Sleep time was: -0.004755
2019-02-08T03:30:30.757Z,1549596630.757 [NavChartDb ThreadHandler](INFO): Cycle time is: 3.284964, Sleep time was: -3.284951
2019-02-08T03:30:30.784Z,1549596630.784 [logger ThreadHandler](INFO): Cycle time is: 0.002218, Sleep time was: -0.002204
2019-02-08T03:30:30.887Z,1549596630.887 [logger ThreadHandler](INFO): Cycle time is: 0.002078, Sleep time was: -0.002062
2019-02-08T03:30:30.991Z,1549596630.991 [logger ThreadHandler](INFO): Cycle time is: 0.003271, Sleep time was: -0.003254
2019-02-08T03:30:31.047Z,1549596631.047 [controlThread ThreadHandler](INFO): Cycle time is: 0.003759, Sleep time was: 0.292175
2019-02-08T03:30:31.099Z,1549596631.099 [logger ThreadHandler](INFO): Cycle time is: 0.007220, Sleep time was: -0.007207
2019-02-08T03:30:31.183Z,1549596631.183 [NavChartDb ThreadHandler](INFO): Cycle time is: 0.325591, Sleep time was: -0.325577
2019-02-08T03:30:31.203Z,1549596631.203 [logger ThreadHandler](INFO): Cycle time is: 0.003637, Sleep time was: -0.003624
2019-02-08T03:30:31.308Z,1549596631.308 [logger ThreadHandler](INFO): Cycle time is: 0.003959, Sleep time was: -0.003945
2019-02-08T03:30:31.409Z,1549596631.409 [logger ThreadHandler](INFO): Cycle time is: 0.000723, Sleep time was: -0.000709
2019-02-08T03:30:31.450Z,1549596631.450 [controlThread ThreadHandler](INFO): Cycle time is: 0.002932, Sleep time was: 0.196550
2019-02-08T03:30:31.510Z,1549596631.510 [logger ThreadHandler](INFO): Cycle time is: 0.000709, Sleep time was: -0.000601
2019-02-08T03:30:31.612Z,1549596631.612 [logger ThreadHandler](INFO): Cycle time is: 0.001080, Sleep time was: -0.001067
2019-02-08T03:30:31.713Z,1549596631.713 [logger ThreadHandler](INFO): Cycle time is: 0.000843, Sleep time was: -0.000829
2019-02-08T03:30:31.815Z,1549596631.815 [logger ThreadHandler](INFO): Cycle time is: 0.001585, Sleep time was: -0.001572
2019-02-08T03:30:31.854Z,1549596631.854 [controlThread ThreadHandler](INFO): Cycle time is: 0.003508, Sleep time was: 0.166296
2019-02-08T03:30:31.925Z,1549596631.925 [logger ThreadHandler](INFO): Cycle time is: 0.009261, Sleep time was: -0.009244
2019-02-08T03:30:32.030Z,1549596632.030 [logger ThreadHandler](INFO): Cycle time is: 0.003566, Sleep time was: -0.003549
2019-02-08T03:30:32.144Z,1549596632.144 [logger ThreadHandler](INFO): Cycle time is: 0.013555, Sleep time was: -0.013542
2019-02-08T03:30:32.249Z,1549596632.249 [logger ThreadHandler](INFO): Cycle time is: 0.004513, Sleep time was: -0.004498
2019-02-08T03:30:32.258Z,1549596632.258 [controlThread ThreadHandler](INFO): Cycle time is: 0.003549, Sleep time was: 0.148276
2019-02-08T03:30:32.359Z,1549596632.359 [logger ThreadHandler](INFO): Cycle time is: 0.008813, Sleep time was: -0.008799
2019-02-08T03:30:32.463Z,1549596632.463 [logger ThreadHandler](INFO): Cycle time is: 0.003635, Sleep time was: -0.003621
2019-02-08T03:30:32.566Z,1549596632.566 [logger ThreadHandler](INFO): Cycle time is: 0.002351, Sleep time was: -0.002337
2019-02-08T03:30:32.662Z,1549596632.662 [controlThread ThreadHandler](INFO): Cycle time is: 0.003404, Sleep time was: 0.248256
2019-02-08T03:30:32.687Z,1549596632.687 [logger ThreadHandler](INFO): Cycle time is: 0.019588, Sleep time was: -0.019574
2019-02-08T03:30:32.798Z,1549596632.798 [logger ThreadHandler](INFO): Cycle time is: 0.010605, Sleep time was: -0.010590
2019-02-08T03:30:32.921Z,1549596632.921 [logger ThreadHandler](INFO): Cycle time is: 0.021529, Sleep time was: -0.021512
2019-02-08T03:30:33.057Z,1549596633.057 [logger ThreadHandler](INFO): Cycle time is: 0.035490, Sleep time was: -0.035476
2019-02-08T03:30:33.066Z,1549596633.066 [controlThread ThreadHandler](INFO): Cycle time is: 0.003409, Sleep time was: 0.134811
2019-02-08T03:30:33.168Z,1549596633.168 [logger ThreadHandler](INFO): Cycle time is: 0.011002, Sleep time was: -0.010989
2019-02-08T03:30:33.216Z,1549596633.216 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.008114
CHAN A1 (24V): -0.017295
CHAN A2 (12V): -0.005128
CHAN A3 (5V): -0.003051
CHAN B0 (3.3V): -0.001523
CHAN B1 (3.15aV): -0.000937
CHAN B2 (3.15bV): -0.001228
CHAN B3 (GND): -0.000560
OPEN: 0.004711
Full Scale Calc: 4.765 mA, -1.589 mA
2019-02-08T03:30:33.275Z,1549596633.275 [logger ThreadHandler](INFO): Cycle time is: 0.006427, Sleep time was: -0.006413
2019-02-08T03:30:33.379Z,1549596633.379 [logger ThreadHandler](INFO): Cycle time is: 0.003253, Sleep time was: -0.003240
2019-02-08T03:30:33.470Z,1549596633.470 [controlThread ThreadHandler](INFO): Cycle time is: 0.003573, Sleep time was: 0.227797
2019-02-08T03:30:33.495Z,1549596633.495 [logger ThreadHandler](INFO): Cycle time is: 0.014395, Sleep time was: -0.014382
2019-02-08T03:30:33.608Z,1549596633.608 [logger ThreadHandler](INFO): Cycle time is: 0.012292, Sleep time was: -0.012281
2019-02-08T03:30:33.709Z,1549596633.709 [logger ThreadHandler](INFO): Cycle time is: 0.000808, Sleep time was: -0.000794
2019-02-08T03:30:33.811Z,1549596633.811 [logger ThreadHandler](INFO): Cycle time is: 0.001389, Sleep time was: -0.001376
2019-02-08T03:30:33.875Z,1549596633.875 [controlThread ThreadHandler](INFO): Cycle time is: 0.003577, Sleep time was: 0.263933
2019-02-08T03:30:33.968Z,1549596633.968 [logger ThreadHandler](INFO): Cycle time is: 0.056623, Sleep time was: -0.056550
2019-02-08T03:30:34.074Z,1549596634.074 [logger ThreadHandler](INFO): Cycle time is: 0.005508, Sleep time was: -0.005495
2019-02-08T03:30:34.179Z,1549596634.179 [logger ThreadHandler](INFO): Cycle time is: 0.004535, Sleep time was: -0.004521
2019-02-08T03:30:34.278Z,1549596634.278 [controlThread ThreadHandler](INFO): Cycle time is: 0.002891, Sleep time was: 0.149235
2019-02-08T03:30:34.307Z,1549596634.307 [logger ThreadHandler](INFO): Cycle time is: 0.027208, Sleep time was: -0.027195
2019-02-08T03:30:34.409Z,1549596634.409 [logger ThreadHandler](INFO): Cycle time is: 0.001558, Sleep time was: -0.001545
2019-02-08T03:30:34.516Z,1549596634.516 [logger ThreadHandler](INFO): Cycle time is: 0.006776, Sleep time was: -0.006762
2019-02-08T03:30:34.619Z,1549596634.619 [logger ThreadHandler](INFO): Cycle time is: 0.002239, Sleep time was: -0.002226
2019-02-08T03:30:34.683Z,1549596634.683 [controlThread ThreadHandler](INFO): Cycle time is: 0.004486, Sleep time was: 0.224278
2019-02-08T03:30:34.727Z,1549596634.727 [logger ThreadHandler](INFO): Cycle time is: 0.007568, Sleep time was: -0.007555
2019-02-08T03:30:34.829Z,1549596634.829 [logger ThreadHandler](INFO): Cycle time is: 0.000923, Sleep time was: -0.000910
2019-02-08T03:30:34.932Z,1549596634.932 [logger ThreadHandler](INFO): Cycle time is: 0.002326, Sleep time was: -0.002256
2019-02-08T03:30:35.050Z,1549596635.050 [logger ThreadHandler](INFO): Cycle time is: 0.018009, Sleep time was: -0.017996
2019-02-08T03:30:35.086Z,1549596635.086 [controlThread ThreadHandler](INFO): Cycle time is: 0.002501, Sleep time was: 0.258095
2019-02-08T03:30:35.159Z,1549596635.159 [logger ThreadHandler](INFO): Cycle time is: 0.008389, Sleep time was: -0.008376
2019-02-08T03:30:35.235Z,1549596635.235 [NavChartDb ThreadHandler](INFO): Cycle time is: 3.951584, Sleep time was: -3.951571
2019-02-08T03:30:35.263Z,1549596635.263 [logger ThreadHandler](INFO): Cycle time is: 0.003561, Sleep time was: -0.003549
2019-02-08T03:30:35.367Z,1549596635.367 [logger ThreadHandler](INFO): Cycle time is: 0.003200, Sleep time was: -0.003186
2019-02-08T03:30:35.471Z,1549596635.471 [logger ThreadHandler](INFO): Cycle time is: 0.003813, Sleep time was: -0.003800
2019-02-08T03:30:35.490Z,1549596635.490 [controlThread ThreadHandler](INFO): Cycle time is: 0.003576, Sleep time was: 0.271670
2019-02-08T03:30:35.503Z,1549596635.503 [NAL9602](INFO): NAL9602 initialized
2019-02-08T03:30:35.587Z,1549596635.587 [logger ThreadHandler](INFO): Cycle time is: 0.015149, Sleep time was: -0.015134
2019-02-08T03:30:35.696Z,1549596635.696 [logger ThreadHandler](INFO): Cycle time is: 0.008235, Sleep time was: -0.008222
2019-02-08T03:30:35.797Z,1549596635.797 [logger ThreadHandler](INFO): Cycle time is: 0.000666, Sleep time was: -0.000651
2019-02-08T03:30:35.895Z,1549596635.895 [controlThread ThreadHandler](INFO): Cycle time is: 0.003680, Sleep time was: 0.275865
2019-02-08T03:30:35.962Z,1549596635.962 [logger ThreadHandler](INFO): Cycle time is: 0.064109, Sleep time was: -0.064092
2019-02-08T03:30:36.091Z,1549596636.091 [logger ThreadHandler](INFO): Cycle time is: 0.028300, Sleep time was: -0.028287
2019-02-08T03:30:36.192Z,1549596636.192 [logger ThreadHandler](INFO): Cycle time is: 0.000800, Sleep time was: -0.000786
2019-02-08T03:30:36.298Z,1549596636.298 [controlThread ThreadHandler](INFO): Cycle time is: 0.003136, Sleep time was: 0.147579
2019-02-08T03:30:36.317Z,1549596636.317 [logger ThreadHandler](INFO): Cycle time is: 0.024007, Sleep time was: -0.023992
2019-02-08T03:30:36.322Z,1549596636.322 [NAL9602](DEBUG): Fix Requested
2019-02-08T03:30:36.418Z,1549596636.418 [logger ThreadHandler](INFO): Cycle time is: 0.000563, Sleep time was: -0.000550
2019-02-08T03:30:36.523Z,1549596636.523 [logger ThreadHandler](INFO): Cycle time is: 0.004564, Sleep time was: -0.004551
2019-02-08T03:30:36.625Z,1549596636.625 [logger ThreadHandler](INFO): Cycle time is: 0.001598, Sleep time was: -0.001585
2019-02-08T03:30:36.703Z,1549596636.703 [controlThread ThreadHandler](INFO): Cycle time is: 0.004305, Sleep time was: 0.259337
2019-02-08T03:30:36.726Z,1549596636.726 [logger ThreadHandler](INFO): Cycle time is: 0.000825, Sleep time was: -0.000811
2019-02-08T03:30:36.832Z,1549596636.832 [logger ThreadHandler](INFO): Cycle time is: 0.003380, Sleep time was: -0.003197
2019-02-08T03:30:36.957Z,1549596636.957 [logger ThreadHandler](INFO): Cycle time is: 0.023835, Sleep time was: -0.023818
2019-02-08T03:30:37.063Z,1549596637.063 [logger ThreadHandler](INFO): Cycle time is: 0.006014, Sleep time was: -0.006000
2019-02-08T03:30:37.106Z,1549596637.106 [controlThread ThreadHandler](INFO): Cycle time is: 0.002726, Sleep time was: 0.234289
2019-02-08T03:30:37.172Z,1549596637.172 [logger ThreadHandler](INFO): Cycle time is: 0.007401, Sleep time was: -0.007388
2019-02-08T03:30:37.276Z,1549596637.276 [logger ThreadHandler](INFO): Cycle time is: 0.002795, Sleep time was: -0.002780
2019-02-08T03:30:37.383Z,1549596637.383 [logger ThreadHandler](INFO): Cycle time is: 0.006530, Sleep time was: -0.006515
2019-02-08T03:30:37.491Z,1549596637.491 [logger ThreadHandler](INFO): Cycle time is: 0.007861, Sleep time was: -0.007848
2019-02-08T03:30:37.541Z,1549596637.541 [NavChartDb ThreadHandler](INFO): Cycle time is: 2.205393, Sleep time was: -2.205379
2019-02-08T03:30:37.592Z,1549596637.592 [logger ThreadHandler](INFO): Cycle time is: 0.000662, Sleep time was: -0.000648
2019-02-08T03:30:37.695Z,1549596637.695 [logger ThreadHandler](INFO): Cycle time is: 0.002338, Sleep time was: -0.002324
2019-02-08T03:30:37.769Z,1549596637.769 [controlThread ThreadHandler](INFO): Cycle time is: 0.262107, Sleep time was: -0.262095
2019-02-08T03:30:37.801Z,1549596637.801 [logger ThreadHandler](INFO): Cycle time is: 0.004616, Sleep time was: -0.004603
2019-02-08T03:30:37.905Z,1549596637.905 [logger ThreadHandler](INFO): Cycle time is: 0.002843, Sleep time was: -0.002774
2019-02-08T03:30:38.010Z,1549596638.010 [logger ThreadHandler](INFO): Cycle time is: 0.004291, Sleep time was: -0.004146
2019-02-08T03:30:38.119Z,1549596638.119 [logger ThreadHandler](INFO): Cycle time is: 0.008662, Sleep time was: -0.008649
2019-02-08T03:30:38.170Z,1549596638.170 [controlThread ThreadHandler](INFO): Cycle time is: 0.000819, Sleep time was: 0.104330
2019-02-08T03:30:38.221Z,1549596638.221 [logger ThreadHandler](INFO): Cycle time is: 0.001107, Sleep time was: -0.001093
2019-02-08T03:30:38.323Z,1549596638.323 [logger ThreadHandler](INFO): Cycle time is: 0.001171, Sleep time was: -0.001157
2019-02-08T03:30:38.435Z,1549596638.435 [logger ThreadHandler](INFO): Cycle time is: 0.012298, Sleep time was: -0.012284
2019-02-08T03:30:38.538Z,1549596638.538 [logger ThreadHandler](INFO): Cycle time is: 0.002131, Sleep time was: -0.002117
2019-02-08T03:30:38.574Z,1549596638.574 [controlThread ThreadHandler](INFO): Cycle time is: 0.003502, Sleep time was: 0.185740
2019-02-08T03:30:38.647Z,1549596638.647 [logger ThreadHandler](INFO): Cycle time is: 0.008330, Sleep time was: -0.008317
2019-02-08T03:30:38.750Z,1549596638.750 [logger ThreadHandler](INFO): Cycle time is: 0.002271, Sleep time was: -0.002236
2019-02-08T03:30:38.855Z,1549596638.855 [logger ThreadHandler](INFO): Cycle time is: 0.004201, Sleep time was: -0.004189
2019-02-08T03:30:38.958Z,1549596638.958 [logger ThreadHandler](INFO): Cycle time is: 0.001628, Sleep time was: -0.001611
2019-02-08T03:30:38.979Z,1549596638.979 [controlThread ThreadHandler](INFO): Cycle time is: 0.003713, Sleep time was: 0.213762
2019-02-08T03:30:39.062Z,1549596639.062 [logger ThreadHandler](INFO): Cycle time is: 0.003665, Sleep time was: -0.003652
2019-02-08T03:30:39.168Z,1549596639.168 [logger ThreadHandler](INFO): Cycle time is: 0.005228, Sleep time was: -0.005214
2019-02-08T03:30:39.279Z,1549596639.279 [logger ThreadHandler](INFO): Cycle time is: 0.010297, Sleep time was: -0.010284
2019-02-08T03:30:39.382Z,1549596639.382 [controlThread ThreadHandler](INFO): Cycle time is: 0.002821, Sleep time was: 0.162768
2019-02-08T03:30:39.397Z,1549596639.397 [logger ThreadHandler](INFO): Cycle time is: 0.017463, Sleep time was: -0.017449
2019-02-08T03:30:39.499Z,1549596639.499 [logger ThreadHandler](INFO): Cycle time is: 0.001765, Sleep time was: -0.001751
2019-02-08T03:30:39.600Z,1549596639.600 [logger ThreadHandler](INFO): Cycle time is: 0.000916, Sleep time was: -0.000903
2019-02-08T03:30:39.704Z,1549596639.704 [logger ThreadHandler](INFO): Cycle time is: 0.002774, Sleep time was: -0.002761
2019-02-08T03:30:39.787Z,1549596639.787 [controlThread ThreadHandler](INFO): Cycle time is: 0.003847, Sleep time was: 0.207118
2019-02-08T03:30:39.809Z,1549596639.809 [logger ThreadHandler](INFO): Cycle time is: 0.004546, Sleep time was: -0.004532
2019-02-08T03:30:39.921Z,1549596639.921 [logger ThreadHandler](INFO): Cycle time is: 0.011258, Sleep time was: -0.011241
2019-02-08T03:30:40.048Z,1549596640.048 [logger ThreadHandler](INFO): Cycle time is: 0.026402, Sleep time was: -0.026388
2019-02-08T03:30:40.150Z,1549596640.150 [logger ThreadHandler](INFO): Cycle time is: 0.000853, Sleep time was: -0.000839
2019-02-08T03:30:40.190Z,1549596640.190 [controlThread ThreadHandler](INFO): Cycle time is: 0.003122, Sleep time was: 0.062232
2019-02-08T03:30:40.255Z,1549596640.255 [logger ThreadHandler](INFO): Cycle time is: 0.004753, Sleep time was: -0.004739
2019-02-08T03:30:40.285Z,1549596640.285 [NavChartDb ThreadHandler](INFO): Cycle time is: 2.643766, Sleep time was: -2.643726
2019-02-08T03:30:40.365Z,1549596640.365 [logger ThreadHandler](INFO): Cycle time is: 0.009322, Sleep time was: -0.009307
2019-02-08T03:30:40.493Z,1549596640.493 [logger ThreadHandler](INFO): Cycle time is: 0.028195, Sleep time was: -0.028182
2019-02-08T03:30:40.594Z,1549596640.594 [controlThread ThreadHandler](INFO): Cycle time is: 0.003387, Sleep time was: 0.229389
2019-02-08T03:30:40.617Z,1549596640.617 [logger ThreadHandler](INFO): Cycle time is: 0.021621, Sleep time was: -0.021606
2019-02-08T03:30:40.718Z,1549596640.718 [logger ThreadHandler](INFO): Cycle time is: 0.000819, Sleep time was: -0.000806
2019-02-08T03:30:40.823Z,1549596640.823 [logger ThreadHandler](INFO): Cycle time is: 0.004557, Sleep time was: -0.004544
2019-02-08T03:30:40.927Z,1549596640.927 [logger ThreadHandler](INFO): Cycle time is: 0.003566, Sleep time was: -0.003443
2019-02-08T03:30:40.999Z,1549596640.999 [controlThread ThreadHandler](INFO): Cycle time is: 0.003794, Sleep time was: 0.207146
2019-02-08T03:30:41.059Z,1549596641.059 [logger ThreadHandler](INFO): Cycle time is: 0.030952, Sleep time was: -0.030938
2019-02-08T03:30:41.165Z,1549596641.165 [logger ThreadHandler](INFO): Cycle time is: 0.004400, Sleep time was: -0.004386
2019-02-08T03:30:41.271Z,1549596641.271 [logger ThreadHandler](INFO): Cycle time is: 0.005861, Sleep time was: -0.005844
2019-02-08T03:30:41.380Z,1549596641.380 [logger ThreadHandler](INFO): Cycle time is: 0.007987, Sleep time was: -0.007974
2019-02-08T03:30:41.402Z,1549596641.402 [controlThread ThreadHandler](INFO): Cycle time is: 0.003008, Sleep time was: 0.194330
2019-02-08T03:30:41.482Z,1549596641.482 [logger ThreadHandler](INFO): Cycle time is: 0.002258, Sleep time was: -0.002244
2019-02-08T03:30:41.593Z,1549596641.593 [logger ThreadHandler](INFO): Cycle time is: 0.009620, Sleep time was: -0.009606
2019-02-08T03:30:41.697Z,1549596641.697 [logger ThreadHandler](INFO): Cycle time is: 0.003861, Sleep time was: -0.003848
2019-02-08T03:30:41.707Z,1549596641.707 [NavChartDb ThreadHandler](INFO): Cycle time is: 1.321717, Sleep time was: -1.321702
2019-02-08T03:30:41.799Z,1549596641.799 [logger ThreadHandler](INFO): Cycle time is: 0.001567, Sleep time was: -0.001554
2019-02-08T03:30:41.806Z,1549596641.806 [controlThread ThreadHandler](INFO): Cycle time is: 0.003318, Sleep time was: 0.201868
2019-02-08T03:30:41.908Z,1549596641.908 [logger ThreadHandler](INFO): Cycle time is: 0.008070, Sleep time was: -0.008053
2019-02-08T03:30:42.011Z,1549596642.011 [logger ThreadHandler](INFO): Cycle time is: 0.002393, Sleep time was: -0.002323
2019-02-08T03:30:42.115Z,1549596642.115 [logger ThreadHandler](INFO): Cycle time is: 0.003179, Sleep time was: -0.003165
2019-02-08T03:30:42.210Z,1549596642.210 [controlThread ThreadHandler](INFO): Cycle time is: 0.003537, Sleep time was: 0.206541
2019-02-08T03:30:42.255Z,1549596642.255 [logger ThreadHandler](INFO): Cycle time is: 0.039642, Sleep time was: -0.039628
2019-02-08T03:30:42.357Z,1549596642.357 [logger ThreadHandler](INFO): Cycle time is: 0.001024, Sleep time was: -0.000943
2019-02-08T03:30:42.466Z,1549596642.466 [logger ThreadHandler](INFO): Cycle time is: 0.008473, Sleep time was: -0.008460
2019-02-08T03:30:42.568Z,1549596642.568 [logger ThreadHandler](INFO): Cycle time is: 0.000849, Sleep time was: -0.000836
2019-02-08T03:30:42.614Z,1549596642.614 [controlThread ThreadHandler](INFO): Cycle time is: 0.003276, Sleep time was: 0.177917
2019-02-08T03:30:42.669Z,1549596642.669 [logger ThreadHandler](INFO): Cycle time is: 0.000662, Sleep time was: -0.000650
2019-02-08T03:30:42.783Z,1549596642.783 [logger ThreadHandler](INFO): Cycle time is: 0.013785, Sleep time was: -0.013771
2019-02-08T03:30:42.887Z,1549596642.887 [logger ThreadHandler](INFO): Cycle time is: 0.003581, Sleep time was: -0.003511
2019-02-08T03:30:42.000Z,1549596643.000 [logger ThreadHandler](INFO): Cycle time is: 0.011966, Sleep time was: -0.011897
2019-02-08T03:30:43.019Z,1549596643.019 [controlThread ThreadHandler](INFO): Cycle time is: 0.003571, Sleep time was: 0.253478
2019-02-08T03:30:43.107Z,1549596643.107 [logger ThreadHandler](INFO): Cycle time is: 0.006831, Sleep time was: -0.006818
2019-02-08T03:30:43.222Z,1549596643.222 [logger ThreadHandler](INFO): Cycle time is: 0.014392, Sleep time was: -0.014379
2019-02-08T03:30:43.324Z,1549596643.324 [logger ThreadHandler](INFO): Cycle time is: 0.000987, Sleep time was: -0.000974
2019-02-08T03:30:43.422Z,1549596643.422 [controlThread ThreadHandler](INFO): Cycle time is: 0.003063, Sleep time was: 0.198009
2019-02-08T03:30:43.438Z,1549596643.438 [logger ThreadHandler](INFO): Cycle time is: 0.013928, Sleep time was: -0.013914
2019-02-08T03:30:43.563Z,1549596643.563 [logger ThreadHandler](INFO): Cycle time is: 0.024195, Sleep time was: -0.024183
2019-02-08T03:30:43.664Z,1549596643.664 [logger ThreadHandler](INFO): Cycle time is: 0.000885, Sleep time was: -0.000871
2019-02-08T03:30:43.770Z,1549596643.770 [logger ThreadHandler](INFO): Cycle time is: 0.004767, Sleep time was: -0.004753
2019-02-08T03:30:43.826Z,1549596643.826 [controlThread ThreadHandler](INFO): Cycle time is: 0.003399, Sleep time was: 0.253749
2019-02-08T03:30:43.909Z,1549596643.909 [logger ThreadHandler](INFO): Cycle time is: 0.038857, Sleep time was: -0.038840
2019-02-08T03:30:44.045Z,1549596644.045 [logger ThreadHandler](INFO): Cycle time is: 0.034627, Sleep time was: -0.034510
2019-02-08T03:30:44.148Z,1549596644.148 [logger ThreadHandler](INFO): Cycle time is: 0.002452, Sleep time was: -0.002438
2019-02-08T03:30:44.230Z,1549596644.230 [controlThread ThreadHandler](INFO): Cycle time is: 0.003448, Sleep time was: 0.107458
2019-02-08T03:30:44.249Z,1549596644.249 [logger ThreadHandler](INFO): Cycle time is: 0.000773, Sleep time was: -0.000760
2019-02-08T03:30:44.359Z,1549596644.359 [logger ThreadHandler](INFO): Cycle time is: 0.009637, Sleep time was: -0.009623
2019-02-08T03:30:44.469Z,1549596644.469 [logger ThreadHandler](INFO): Cycle time is: 0.009114, Sleep time was: -0.009100
2019-02-08T03:30:44.570Z,1549596644.570 [logger ThreadHandler](INFO): Cycle time is: 0.000731, Sleep time was: -0.000717
2019-02-08T03:30:44.634Z,1549596644.634 [controlThread ThreadHandler](INFO): Cycle time is: 0.003533, Sleep time was: 0.208425
2019-02-08T03:30:44.695Z,1549596644.695 [logger ThreadHandler](INFO): Cycle time is: 0.024341, Sleep time was: -0.024324
2019-02-08T03:30:44.792Z,1549596644.792 [NavChartDb ThreadHandler](INFO): Cycle time is: 2.984320, Sleep time was: -2.984307
2019-02-08T03:30:44.796Z,1549596644.796 [logger ThreadHandler](INFO): Cycle time is: 0.000638, Sleep time was: -0.000625
2019-02-08T03:30:44.900Z,1549596644.900 [logger ThreadHandler](INFO): Cycle time is: 0.002901, Sleep time was: -0.002884
2019-02-08T03:30:45.013Z,1549596645.013 [logger ThreadHandler](INFO): Cycle time is: 0.011556, Sleep time was: -0.011539
2019-02-08T03:30:45.039Z,1549596645.039 [controlThread ThreadHandler](INFO): Cycle time is: 0.003394, Sleep time was: 0.245238
2019-02-08T03:30:45.127Z,1549596645.127 [logger ThreadHandler](INFO): Cycle time is: 0.014028, Sleep time was: -0.014016
2019-02-08T03:30:45.228Z,1549596645.228 [logger ThreadHandler](INFO): Cycle time is: 0.000805, Sleep time was: -0.000792
2019-02-08T03:30:45.331Z,1549596645.331 [logger ThreadHandler](INFO): Cycle time is: 0.002030, Sleep time was: -0.002017
2019-02-08T03:30:45.432Z,1549596645.432 [logger ThreadHandler](INFO): Cycle time is: 0.000790, Sleep time was: -0.000777
2019-02-08T03:30:45.442Z,1549596645.442 [controlThread ThreadHandler](INFO): Cycle time is: 0.003010, Sleep time was: 0.228986
2019-02-08T03:30:45.538Z,1549596645.538 [logger ThreadHandler](INFO): Cycle time is: 0.005127, Sleep time was: -0.005063
2019-02-08T03:30:45.640Z,1549596645.640 [logger ThreadHandler](INFO): Cycle time is: 0.000985, Sleep time was: -0.000972
2019-02-08T03:30:45.741Z,1549596645.741 [logger ThreadHandler](INFO): Cycle time is: 0.000852, Sleep time was: -0.000839
2019-02-08T03:30:45.842Z,1549596645.842 [logger ThreadHandler](INFO): Cycle time is: 0.000962, Sleep time was: -0.000948
2019-02-08T03:30:45.846Z,1549596645.846 [controlThread ThreadHandler](INFO): Cycle time is: 0.003482, Sleep time was: 0.277063
2019-02-08T03:30:45.965Z,1549596645.965 [logger ThreadHandler](INFO): Cycle time is: 0.021822, Sleep time was: -0.021804
2019-02-08T03:30:46.085Z,1549596646.085 [logger ThreadHandler](INFO): Cycle time is: 0.019694, Sleep time was: -0.019681
2019-02-08T03:30:46.198Z,1549596646.198 [logger ThreadHandler](INFO): Cycle time is: 0.012513, Sleep time was: -0.012498
2019-02-08T03:30:46.250Z,1549596646.250 [controlThread ThreadHandler](INFO): Cycle time is: 0.003365, Sleep time was: 0.137068
2019-02-08T03:30:46.300Z,1549596646.300 [logger ThreadHandler](INFO): Cycle time is: 0.000850, Sleep time was: -0.000837
2019-02-08T03:30:46.405Z,1549596646.405 [logger ThreadHandler](INFO): Cycle time is: 0.005262, Sleep time was: -0.005248
2019-02-08T03:30:46.507Z,1549596646.507 [logger ThreadHandler](INFO): Cycle time is: 0.001402, Sleep time was: -0.001387
2019-02-08T03:30:46.610Z,1549596646.610 [logger ThreadHandler](INFO): Cycle time is: 0.002345, Sleep time was: 0.090984
2019-02-08T03:30:46.655Z,1549596646.655 [controlThread ThreadHandler](INFO): Cycle time is: 0.004117, Sleep time was: 0.278852
2019-02-08T03:30:46.714Z,1549596646.714 [logger ThreadHandler](INFO): Cycle time is: 0.003504, Sleep time was: 0.094497
2019-02-08T03:30:46.818Z,1549596646.818 [logger ThreadHandler](INFO): Cycle time is: 0.003413, Sleep time was: 0.033220
2019-02-08T03:30:46.923Z,1549596646.923 [logger ThreadHandler](INFO): Cycle time is: 0.003667, Sleep time was: 0.087735
2019-02-08T03:30:47.027Z,1549596647.027 [logger ThreadHandler](INFO): Cycle time is: 0.003333, Sleep time was: 0.092690
2019-02-08T03:30:47.059Z,1549596647.059 [controlThread ThreadHandler](INFO): Cycle time is: 0.003188, Sleep time was: 0.240417
2019-02-08T03:30:47.130Z,1549596647.130 [logger ThreadHandler](INFO): Cycle time is: 0.002687, Sleep time was: 0.092749
2019-02-08T03:30:47.234Z,1549596647.234 [logger ThreadHandler](INFO): Cycle time is: 0.003360, Sleep time was: 0.050954
2019-02-08T03:30:47.338Z,1549596647.338 [logger ThreadHandler](INFO): Cycle time is: 0.003466, Sleep time was: 0.088258
2019-02-08T03:30:47.442Z,1549596647.442 [logger ThreadHandler](INFO): Cycle time is: 0.003450, Sleep time was: 0.095520
2019-02-08T03:30:47.462Z,1549596647.462 [controlThread ThreadHandler](INFO): Cycle time is: 0.003154, Sleep time was: 0.245485
2019-02-08T03:30:47.546Z,1549596647.546 [logger ThreadHandler](INFO): Cycle time is: 0.003448, Sleep time was: 0.093876
2019-02-08T03:30:47.647Z,1549596647.647 [logger ThreadHandler](INFO): Cycle time is: 0.000167, Sleep time was: -0.000153
2019-02-08T03:30:47.750Z,1549596647.750 [logger ThreadHandler](INFO): Cycle time is: 0.002821, Sleep time was: 0.090144
2019-02-08T03:30:47.854Z,1549596647.854 [logger ThreadHandler](INFO): Cycle time is: 0.003409, Sleep time was: 0.094252
2019-02-08T03:30:47.866Z,1549596647.866 [controlThread ThreadHandler](INFO): Cycle time is: 0.003446, Sleep time was: 0.288235
2019-02-08T03:30:47.959Z,1549596647.959 [logger ThreadHandler](INFO): Cycle time is: 0.004608, Sleep time was: 0.094159
2019-02-08T03:30:48.067Z,1549596648.067 [logger ThreadHandler](INFO): Cycle time is: 0.007286, Sleep time was: -0.007274
2019-02-08T03:30:48.133Z,1549596648.133 [NavChartDb ThreadHandler](INFO): Cycle time is: 3.240421, Sleep time was: -3.240408
2019-02-08T03:30:48.170Z,1549596648.170 [logger ThreadHandler](INFO): Cycle time is: 0.002698, Sleep time was: 0.047745
2019-02-08T03:30:48.270Z,1549596648.270 [controlThread ThreadHandler](INFO): Cycle time is: 0.003541, Sleep time was: 0.136108
2019-02-08T03:30:48.275Z,1549596648.275 [logger ThreadHandler](INFO): Cycle time is: 0.003743, Sleep time was: 0.082824
2019-02-08T03:30:48.378Z,1549596648.378 [logger ThreadHandler](INFO): Cycle time is: 0.003050, Sleep time was: 0.072853
2019-02-08T03:30:48.482Z,1549596648.482 [logger ThreadHandler](INFO): Cycle time is: 0.003430, Sleep time was: 0.066916
2019-02-08T03:30:48.514Z,1549596648.514 [NavChartDb ThreadHandler](INFO): Cycle time is: 0.279876, Sleep time was: -0.279862
2019-02-08T03:30:48.586Z,1549596648.586 [logger ThreadHandler](INFO): Cycle time is: 0.003455, Sleep time was: 0.088368
2019-02-08T03:30:48.674Z,1549596648.674 [controlThread ThreadHandler](INFO): Cycle time is: 0.003344, Sleep time was: 0.232680
2019-02-08T03:30:48.690Z,1549596648.690 [logger ThreadHandler](INFO): Cycle time is: 0.003509, Sleep time was: 0.090610
2019-02-08T03:30:48.795Z,1549596648.795 [logger ThreadHandler](INFO): Cycle time is: 0.003579, Sleep time was: 0.084747
2019-02-08T03:30:48.899Z,1549596648.899 [logger ThreadHandler](INFO): Cycle time is: 0.002457, Sleep time was: 0.031935
2019-02-08T03:30:49.002Z,1549596649.002 [logger ThreadHandler](INFO): Cycle time is: 0.003034, Sleep time was: 0.088800
2019-02-08T03:30:49.078Z,1549596649.078 [controlThread ThreadHandler](INFO): Cycle time is: 0.003377, Sleep time was: 0.261044
2019-02-08T03:30:49.107Z,1549596649.107 [logger ThreadHandler](INFO): Cycle time is: 0.004209, Sleep time was: 0.092170
2019-02-08T03:30:49.210Z,1549596649.210 [logger ThreadHandler](INFO): Cycle time is: 0.002797, Sleep time was: 0.084472
2019-02-08T03:30:49.314Z,1549596649.314 [logger ThreadHandler](INFO): Cycle time is: 0.003337, Sleep time was: 0.050260
2019-02-08T03:30:49.418Z,1549596649.418 [logger ThreadHandler](INFO): Cycle time is: 0.003498, Sleep time was: 0.094764
2019-02-08T03:30:49.482Z,1549596649.482 [controlThread ThreadHandler](INFO): Cycle time is: 0.003524, Sleep time was: 0.248134
2019-02-08T03:30:49.522Z,1549596649.522 [logger ThreadHandler](INFO): Cycle time is: 0.003476, Sleep time was: 0.095046
2019-02-08T03:30:49.626Z,1549596649.626 [logger ThreadHandler](INFO): Cycle time is: 0.003532, Sleep time was: 0.082674
2019-02-08T03:30:49.730Z,1549596649.730 [logger ThreadHandler](INFO): Cycle time is: 0.003318, Sleep time was: 0.055432
2019-02-08T03:30:49.834Z,1549596649.834 [logger ThreadHandler](INFO): Cycle time is: 0.003455, Sleep time was: 0.094950
2019-02-08T03:30:49.887Z,1549596649.887 [controlThread ThreadHandler](INFO): Cycle time is: 0.003653, Sleep time was: 0.236194
2019-02-08T03:30:49.940Z,1549596649.940 [logger ThreadHandler](INFO): Cycle time is: 0.004875, Sleep time was: 0.094461
2019-02-08T03:30:50.049Z,1549596650.049 [logger ThreadHandler](INFO): Cycle time is: 0.008061, Sleep time was: -0.008044
2019-02-08T03:30:50.150Z,1549596650.150 [logger ThreadHandler](INFO): Cycle time is: 0.000706, Sleep time was: 0.024155
2019-02-08T03:30:50.186Z,1549596650.186 [NavChartDb ThreadHandler](INFO): Cycle time is: 1.571635, Sleep time was: -1.571621
2019-02-08T03:30:50.254Z,1549596650.254 [logger ThreadHandler](INFO): Cycle time is: 0.003401, Sleep time was: 0.080119
2019-02-08T03:30:50.290Z,1549596650.290 [controlThread ThreadHandler](INFO): Cycle time is: 0.002865, Sleep time was: 0.145017
2019-02-08T03:30:50.358Z,1549596650.358 [logger ThreadHandler](INFO): Cycle time is: 0.003644, Sleep time was: 0.090900
2019-02-08T03:30:50.462Z,1549596650.462 [logger ThreadHandler](INFO): Cycle time is: 0.003462, Sleep time was: 0.026926
2019-02-08T03:30:50.566Z,1549596650.566 [logger ThreadHandler](INFO): Cycle time is: 0.003334, Sleep time was: 0.090584
2019-02-08T03:30:50.581Z,1549596650.581 [NavChartDb ThreadHandler](INFO): Cycle time is: 0.294959, Sleep time was: -0.294945
2019-02-08T03:30:50.671Z,1549596650.671 [logger ThreadHandler](INFO): Cycle time is: 0.004029, Sleep time was: 0.092867
2019-02-08T03:30:50.694Z,1549596650.694 [controlThread ThreadHandler](INFO): Cycle time is: 0.003516, Sleep time was: 0.214056
2019-02-08T03:30:50.774Z,1549596650.774 [logger ThreadHandler](INFO): Cycle time is: 0.003038, Sleep time was: 0.089371
2019-02-08T03:30:50.876Z,1549596650.876 [logger ThreadHandler](INFO): Cycle time is: 0.000746, Sleep time was: -0.000733
2019-02-08T03:30:50.979Z,1549596650.979 [logger ThreadHandler](INFO): Cycle time is: 0.002252, Sleep time was: 0.090810
2019-02-08T03:30:51.082Z,1549596651.082 [logger ThreadHandler](INFO): Cycle time is: 0.003142, Sleep time was: 0.089467
2019-02-08T03:30:51.098Z,1549596651.098 [controlThread ThreadHandler](INFO): Cycle time is: 0.003492, Sleep time was: 0.268774
2019-02-08T03:30:51.186Z,1549596651.186 [logger ThreadHandler](INFO): Cycle time is: 0.003312, Sleep time was: 0.094815
2019-02-08T03:30:51.290Z,1549596651.290 [logger ThreadHandler](INFO): Cycle time is: 0.003407, Sleep time was: 0.006288
2019-02-08T03:30:51.394Z,1549596651.394 [logger ThreadHandler](INFO): Cycle time is: 0.003588, Sleep time was: 0.094864
2019-02-08T03:30:51.498Z,1549596651.498 [logger ThreadHandler](INFO): Cycle time is: 0.003304, Sleep time was: 0.094736
2019-02-08T03:30:51.502Z,1549596651.502 [controlThread ThreadHandler](INFO): Cycle time is: 0.003543, Sleep time was: 0.268011
2019-02-08T03:30:51.602Z,1549596651.602 [logger ThreadHandler](INFO): Cycle time is: 0.003567, Sleep time was: 0.082473
2019-02-08T03:30:51.706Z,1549596651.706 [logger ThreadHandler](INFO): Cycle time is: 0.003423, Sleep time was: 0.028865
2019-02-08T03:30:51.811Z,1549596651.811 [logger ThreadHandler](INFO): Cycle time is: 0.003792, Sleep time was: 0.094147
2019-02-08T03:30:51.907Z,1549596651.907 [controlThread ThreadHandler](INFO): Cycle time is: 0.003517, Sleep time was: 0.312329
2019-02-08T03:30:51.915Z,1549596651.915 [logger ThreadHandler](INFO): Cycle time is: 0.003214, Sleep time was: 0.094927
2019-02-08T03:30:52.018Z,1549596652.018 [logger ThreadHandler](INFO): Cycle time is: 0.003144, Sleep time was: 0.082562
2019-02-08T03:30:52.122Z,1549596652.122 [logger ThreadHandler](INFO): Cycle time is: 0.003299, Sleep time was: 0.076813
2019-02-08T03:30:52.226Z,1549596652.226 [logger ThreadHandler](INFO): Cycle time is: 0.003474, Sleep time was: 0.070561
2019-02-08T03:30:52.310Z,1549596652.310 [controlThread ThreadHandler](INFO): Cycle time is: 0.002919, Sleep time was: 0.194959
2019-02-08T03:30:52.324Z,1549596652.324 [NavChartDb ThreadHandler](INFO): Cycle time is: 1.628096, Sleep time was: -1.628082
2019-02-08T03:30:52.331Z,1549596652.331 [logger ThreadHandler](INFO): Cycle time is: 0.004146, Sleep time was: 0.095517
2019-02-08T03:30:52.434Z,1549596652.434 [logger ThreadHandler](INFO): Cycle time is: 0.002875, Sleep time was: 0.077364
2019-02-08T03:30:52.538Z,1549596652.538 [logger ThreadHandler](INFO): Cycle time is: 0.003347, Sleep time was: 0.058165
2019-02-08T03:30:52.642Z,1549596652.642 [logger ThreadHandler](INFO): Cycle time is: 0.003486, Sleep time was: 0.095526
2019-02-08T03:30:52.714Z,1549596652.714 [controlThread ThreadHandler](INFO): Cycle time is: 0.003479, Sleep time was: 0.278358
2019-02-08T03:30:52.746Z,1549596652.746 [logger ThreadHandler](INFO): Cycle time is: 0.003597, Sleep time was: 0.095500
2019-02-08T03:30:52.822Z,1549596652.822 [NavChartDb ThreadHandler](INFO): Cycle time is: 0.396909, Sleep time was: -0.396896
2019-02-08T03:30:52.850Z,1549596652.850 [logger ThreadHandler](INFO): Cycle time is: 0.003386, Sleep time was: 0.081679
2019-02-08T03:30:52.962Z,1549596652.962 [logger ThreadHandler](INFO): Cycle time is: 0.010335, Sleep time was: -0.010318
2019-02-08T03:30:53.066Z,1549596653.066 [logger ThreadHandler](INFO): Cycle time is: 0.004370, Sleep time was: 0.077940
2019-02-08T03:30:53.118Z,1549596653.118 [controlThread ThreadHandler](INFO): Cycle time is: 0.003500, Sleep time was: 0.296172
2019-02-08T03:30:53.171Z,1549596653.171 [logger ThreadHandler](INFO): Cycle time is: 0.003527, Sleep time was: 0.094875
2019-02-08T03:30:53.274Z,1549596653.274 [logger ThreadHandler](INFO): Cycle time is: 0.002444, Sleep time was: 0.004314
2019-02-08T03:30:53.378Z,1549596653.378 [logger ThreadHandler](INFO): Cycle time is: 0.003453, Sleep time was: 0.094567
2019-02-08T03:30:53.482Z,1549596653.482 [logger ThreadHandler](INFO): Cycle time is: 0.003469, Sleep time was: 0.094177
2019-02-08T03:30:53.522Z,1549596653.522 [controlThread ThreadHandler](INFO): Cycle time is: 0.003421, Sleep time was: 0.276215
2019-02-08T03:30:53.586Z,1549596653.586 [logger ThreadHandler](INFO): Cycle time is: 0.003654, Sleep time was: 0.094658
2019-02-08T03:30:53.691Z,1549596653.691 [logger ThreadHandler](INFO): Cycle time is: 0.004083, Sleep time was: -0.004070
2019-02-08T03:30:53.794Z,1549596653.794 [logger ThreadHandler](INFO): Cycle time is: 0.002672, Sleep time was: 0.084923
2019-02-08T03:30:53.899Z,1549596653.899 [logger ThreadHandler](INFO): Cycle time is: 0.003670, Sleep time was: 0.094977
2019-02-08T03:30:53.926Z,1549596653.926 [controlThread ThreadHandler](INFO): Cycle time is: 0.003699, Sleep time was: 0.285591
2019-02-08T03:30:54.003Z,1549596654.003 [logger ThreadHandler](INFO): Cycle time is: 0.003250, Sleep time was: 0.089803
2019-02-08T03:30:54.104Z,1549596654.104 [logger ThreadHandler](INFO): Cycle time is: 0.000722, Sleep time was: -0.000709
2019-02-08T03:30:54.206Z,1549596654.206 [logger ThreadHandler](INFO): Cycle time is: 0.001629, Sleep time was: 0.038581
2019-02-08T03:30:54.310Z,1549596654.310 [logger ThreadHandler](INFO): Cycle time is: 0.003451, Sleep time was: 0.095843
2019-02-08T03:30:54.330Z,1549596654.330 [controlThread ThreadHandler](INFO): Cycle time is: 0.003309, Sleep time was: 0.188505
2019-02-08T03:30:54.414Z,1549596654.414 [logger ThreadHandler](INFO): Cycle time is: 0.003479, Sleep time was: 0.095064
2019-02-08T03:30:54.518Z,1549596654.518 [logger ThreadHandler](INFO): Cycle time is: 0.003421, Sleep time was: 0.023808
2019-02-08T03:30:54.553Z,1549596654.553 [NavChartDb ThreadHandler](INFO): Cycle time is: 1.631447, Sleep time was: -1.631434
2019-02-08T03:30:54.622Z,1549596654.622 [logger ThreadHandler](INFO): Cycle time is: 0.003456, Sleep time was: 0.094597
2019-02-08T03:30:54.726Z,1549596654.726 [logger ThreadHandler](INFO): Cycle time is: 0.003427, Sleep time was: 0.090628
2019-02-08T03:30:54.734Z,1549596654.734 [controlThread ThreadHandler](INFO): Cycle time is: 0.003459, Sleep time was: 0.261755
2019-02-08T03:30:54.831Z,1549596654.831 [logger ThreadHandler](INFO): Cycle time is: 0.004415, Sleep time was: 0.094941
2019-02-08T03:30:54.944Z,1549596654.944 [logger ThreadHandler](INFO): Cycle time is: 0.011725, Sleep time was: -0.011651
2019-02-08T03:30:55.002Z,1549596655.002 [NavChartDb ThreadHandler](INFO): Cycle time is: 0.347521, Sleep time was: -0.347504
2019-02-08T03:30:55.047Z,1549596655.047 [logger ThreadHandler](INFO): Cycle time is: 0.002249, Sleep time was: 0.058560
2019-02-08T03:30:55.138Z,1549596655.138 [controlThread ThreadHandler](INFO): Cycle time is: 0.003433, Sleep time was: 0.283397
2019-02-08T03:30:55.150Z,1549596655.150 [logger ThreadHandler](INFO): Cycle time is: 0.003008, Sleep time was: 0.083196
2019-02-08T03:30:55.254Z,1549596655.254 [logger ThreadHandler](INFO): Cycle time is: 0.003496, Sleep time was: 0.087122
2019-02-08T03:30:55.358Z,1549596655.358 [logger ThreadHandler](INFO): Cycle time is: 0.003436, Sleep time was: 0.046035
2019-02-08T03:30:55.462Z,1549596655.462 [logger ThreadHandler](INFO): Cycle time is: 0.003445, Sleep time was: 0.091489
2019-02-08T03:30:55.542Z,1549596655.542 [controlThread ThreadHandler](INFO): Cycle time is: 0.003532, Sleep time was: 0.292277
2019-02-08T03:30:55.568Z,1549596655.568 [logger ThreadHandler](INFO): Cycle time is: 0.004068, Sleep time was: 0.094420
2019-02-08T03:30:55.670Z,1549596655.670 [logger ThreadHandler](INFO): Cycle time is: 0.001676, Sleep time was: 0.027130
2019-02-08T03:30:55.774Z,1549596655.774 [logger ThreadHandler](INFO): Cycle time is: 0.003397, Sleep time was: 0.052304
2019-02-08T03:30:55.878Z,1549596655.878 [logger ThreadHandler](INFO): Cycle time is: 0.003486, Sleep time was: 0.095122
2019-02-08T03:30:55.947Z,1549596655.947 [controlThread ThreadHandler](INFO): Cycle time is: 0.003706, Sleep time was: 0.247620
2019-02-08T03:30:55.983Z,1549596655.983 [logger ThreadHandler](INFO): Cycle time is: 0.003728, Sleep time was: 0.094553
2019-02-08T03:30:56.091Z,1549596656.091 [logger ThreadHandler](INFO): Cycle time is: 0.006782, Sleep time was: -0.006769
2019-02-08T03:30:56.194Z,1549596656.194 [logger ThreadHandler](INFO): Cycle time is: 0.002945, Sleep time was: 0.046370
2019-02-08T03:30:56.298Z,1549596656.298 [logger ThreadHandler](INFO): Cycle time is: 0.003323, Sleep time was: 0.094949
2019-02-08T03:30:56.350Z,1549596656.350 [controlThread ThreadHandler](INFO): Cycle time is: 0.003089, Sleep time was: 0.218535
2019-02-08T03:30:56.402Z,1549596656.402 [logger ThreadHandler](INFO): Cycle time is: 0.003501, Sleep time was: 0.095136
2019-02-08T03:30:56.506Z,1549596656.506 [logger ThreadHandler](INFO): Cycle time is: 0.003392, Sleep time was: 0.082906
2019-02-08T03:30:56.610Z,1549596656.610 [logger ThreadHandler](INFO): Cycle time is: 0.003443, Sleep time was: 0.054364
2019-02-08T03:30:56.714Z,1549596656.714 [logger ThreadHandler](INFO): Cycle time is: 0.003457, Sleep time was: 0.095079
2019-02-08T03:30:56.754Z,1549596656.754 [controlThread ThreadHandler](INFO): Cycle time is: 0.003435, Sleep time was: 0.289247
2019-02-08T03:30:56.818Z,1549596656.818 [logger ThreadHandler](INFO): Cycle time is: 0.003491, Sleep time was: 0.094367
2019-02-08T03:30:56.923Z,1549596656.923 [logger ThreadHandler](INFO): Cycle time is: 0.003574, Sleep time was: 0.064164
2019-02-08T03:30:57.033Z,1549596657.033 [logger ThreadHandler](INFO): Cycle time is: 0.009199, Sleep time was: -0.009182
2019-02-08T03:30:57.134Z,1549596657.134 [logger ThreadHandler](INFO): Cycle time is: 0.000713, Sleep time was: 0.053991
2019-02-08T03:30:57.158Z,1549596657.158 [controlThread ThreadHandler](INFO): Cycle time is: 0.003442, Sleep time was: 0.282721
2019-02-08T03:30:57.238Z,1549596657.238 [logger ThreadHandler](INFO): Cycle time is: 0.003579, Sleep time was: 0.095516
2019-02-08T03:30:57.342Z,1549596657.342 [logger ThreadHandler](INFO): Cycle time is: 0.003413, Sleep time was: 0.031281
2019-02-08T03:30:57.446Z,1549596657.446 [logger ThreadHandler](INFO): Cycle time is: 0.003441, Sleep time was: 0.094613
2019-02-08T03:30:57.550Z,1549596657.550 [logger ThreadHandler](INFO): Cycle time is: 0.003452, Sleep time was: 0.094240
2019-02-08T03:30:57.562Z,1549596657.562 [controlThread ThreadHandler](INFO): Cycle time is: 0.003463, Sleep time was: 0.278212
2019-02-08T03:30:57.611Z,1549596657.611 [NavChartDb ThreadHandler](INFO): Cycle time is: 2.508384, Sleep time was: -2.508370
2019-02-08T03:30:57.654Z,1549596657.654 [logger ThreadHandler](INFO): Cycle time is: 0.003509, Sleep time was: 0.094964
2019-02-08T03:30:57.714Z,1549596657.714 [NavChartDb ThreadHandler](INFO): Cycle time is: 0.002914, Sleep time was: 0.024920
2019-02-08T03:30:57.758Z,1549596657.758 [logger ThreadHandler](INFO): Cycle time is: 0.003394, Sleep time was: 0.042079
2019-02-08T03:30:57.862Z,1549596657.862 [logger ThreadHandler](INFO): Cycle time is: 0.003468, Sleep time was: 0.091684
2019-02-08T03:30:57.967Z,1549596657.967 [logger ThreadHandler](INFO): Cycle time is: 0.003698, Sleep time was: 0.094950
2019-02-08T03:30:57.982Z,1549596657.982 [controlThread ThreadHandler](INFO): Cycle time is: 0.019325, Sleep time was: 0.314844
2019-02-08T03:30:58.071Z,1549596658.071 [logger ThreadHandler](INFO): Cycle time is: 0.003118, Sleep time was: 0.085786
2019-02-08T03:30:58.174Z,1549596658.174 [logger ThreadHandler](INFO): Cycle time is: 0.003098, Sleep time was: 0.082035
2019-02-08T03:30:58.278Z,1549596658.278 [logger ThreadHandler](INFO): Cycle time is: 0.003406, Sleep time was: 0.067396
2019-02-08T03:30:58.382Z,1549596658.382 [logger ThreadHandler](INFO): Cycle time is: 0.003485, Sleep time was: 0.095444
2019-02-08T03:30:58.386Z,1549596658.386 [controlThread ThreadHandler](INFO): Cycle time is: 0.003609, Sleep time was: 0.231273
2019-02-08T03:30:58.484Z,1549596658.484 [logger ThreadHandler](INFO): Cycle time is: 0.000797, Sleep time was: -0.000784
2019-02-08T03:30:58.586Z,1549596658.586 [logger ThreadHandler](INFO): Cycle time is: 0.002212, Sleep time was: 0.041082
2019-02-08T03:30:58.690Z,1549596658.690 [logger ThreadHandler](INFO): Cycle time is: 0.003465, Sleep time was: 0.095116
2019-02-08T03:30:58.735Z,1549596658.735 [NavChartDb ThreadHandler](INFO): Cycle time is: 0.920526, Sleep time was: -0.920513
2019-02-08T03:30:58.791Z,1549596658.791 [controlThread ThreadHandler](INFO): Cycle time is: 0.003662, Sleep time was: 0.279009
2019-02-08T03:30:58.799Z,1549596658.799 [logger ThreadHandler](INFO): Cycle time is: 0.007678, Sleep time was: 0.094346
2019-02-08T03:30:58.859Z,1549596658.859 [NavChartDb ThreadHandler](INFO): Cycle time is: 0.023310, Sleep time was: -0.023295
2019-02-08T03:30:58.903Z,1549596658.903 [logger ThreadHandler](INFO): Cycle time is: 0.002556, Sleep time was: 0.071327
2019-02-08T03:30:59.026Z,1549596659.026 [logger ThreadHandler](INFO): Cycle time is: 0.021922, Sleep time was: -0.021904
2019-02-08T03:30:59.135Z,1549596659.135 [logger ThreadHandler](INFO): Cycle time is: 0.008367, Sleep time was: -0.008354
2019-02-08T03:30:59.194Z,1549596659.194 [controlThread ThreadHandler](INFO): Cycle time is: 0.002516, Sleep time was: 0.102816
2019-02-08T03:30:59.238Z,1549596659.238 [logger ThreadHandler](INFO): Cycle time is: 0.002956, Sleep time was: 0.073770
2019-02-08T03:30:59.342Z,1549596659.342 [logger ThreadHandler](INFO): Cycle time is: 0.003465, Sleep time was: 0.081847
2019-02-08T03:30:59.447Z,1549596659.447 [logger ThreadHandler](INFO): Cycle time is: 0.003369, Sleep time was: 0.030315
2019-02-08T03:30:59.550Z,1549596659.550 [logger ThreadHandler](INFO): Cycle time is: 0.003068, Sleep time was: 0.094762
2019-02-08T03:30:59.598Z,1549596659.598 [controlThread ThreadHandler](INFO): Cycle time is: 0.003208, Sleep time was: 0.226635
2019-02-08T03:30:59.654Z,1549596659.654 [logger ThreadHandler](INFO): Cycle time is: 0.003576, Sleep time was: 0.094678
2019-02-08T03:30:59.766Z,1549596659.766 [logger ThreadHandler](INFO): Cycle time is: 0.011616, Sleep time was: 0.087836
2019-02-08T03:30:59.870Z,1549596659.870 [logger ThreadHandler](INFO): Cycle time is: 0.003235, Sleep time was: 0.095017
2019-02-08T03:30:59.982Z,1549596659.982 [logger ThreadHandler](INFO): Cycle time is: 0.011715, Sleep time was: 0.095958
2019-02-08T03:31:00.086Z,1549596660.086 [logger ThreadHandler](INFO): Cycle time is: 0.003313, Sleep time was: 0.091341
2019-02-08T03:31:00.198Z,1549596660.198 [logger ThreadHandler](INFO): Cycle time is: 0.011402, Sleep time was: 0.094793
2019-02-08T03:31:00.302Z,1549596660.302 [logger ThreadHandler](INFO): Cycle time is: 0.003511, Sleep time was: 0.095515
2019-02-08T03:31:00.414Z,1549596660.414 [logger ThreadHandler](INFO): Cycle time is: 0.011385, Sleep time was: 0.095862
2019-02-08T03:31:00.518Z,1549596660.518 [logger ThreadHandler](INFO): Cycle time is: 0.003518, Sleep time was: 0.095529
2019-02-08T03:31:00.630Z,1549596660.630 [logger ThreadHandler](INFO): Cycle time is: 0.011397, Sleep time was: 0.094978
2019-02-08T03:31:00.734Z,1549596660.734 [logger ThreadHandler](INFO): Cycle time is: 0.003463, Sleep time was: 0.095538
2019-02-08T03:31:00.846Z,1549596660.846 [logger ThreadHandler](INFO): Cycle time is: 0.011483, Sleep time was: 0.094735
2019-02-08T03:31:00.951Z,1549596660.951 [logger ThreadHandler](INFO): Cycle time is: 0.003707, Sleep time was: 0.094677
2019-02-08T03:31:01.062Z,1549596661.062 [logger ThreadHandler](INFO): Cycle time is: 0.010944, Sleep time was: 0.082858
2019-02-08T03:31:01.166Z,1549596661.166 [logger ThreadHandler](INFO): Cycle time is: 0.003333, Sleep time was: 0.093470
2019-02-08T03:31:01.270Z,1549596661.270 [logger ThreadHandler](INFO): Cycle time is: 0.003500, Sleep time was: 0.095968
2019-02-08T03:31:01.374Z,1549596661.374 [logger ThreadHandler](INFO): Cycle time is: 0.003530, Sleep time was: 0.095986
2019-02-08T03:31:01.475Z,1549596661.475 [NavChartDb ThreadHandler](INFO): Cycle time is: 2.515245, Sleep time was: -2.515231
2019-02-08T03:31:01.478Z,1549596661.478 [logger ThreadHandler](INFO): Cycle time is: 0.003427, Sleep time was: 0.092923
2019-02-08T03:31:01.582Z,1549596661.582 [logger ThreadHandler](INFO): Cycle time is: 0.003331, Sleep time was: 0.092799
2019-02-08T03:31:01.686Z,1549596661.686 [logger ThreadHandler](INFO): Cycle time is: 0.003463, Sleep time was: 0.095957
2019-02-08T03:31:01.790Z,1549596661.790 [logger ThreadHandler](INFO): Cycle time is: 0.003606, Sleep time was: 0.096377
2019-02-08T03:31:01.894Z,1549596661.894 [logger ThreadHandler](INFO): Cycle time is: 0.003359, Sleep time was: 0.094068
2019-02-08T03:31:01.999Z,1549596661.999 [logger ThreadHandler](INFO): Cycle time is: 0.003616, Sleep time was: 0.095821
2019-02-08T03:31:02.102Z,1549596662.102 [logger ThreadHandler](INFO): Cycle time is: 0.002354, Sleep time was: 0.088120
2019-02-08T03:31:02.206Z,1549596662.206 [logger ThreadHandler](INFO): Cycle time is: 0.003372, Sleep time was: 0.095833
2019-02-08T03:31:02.310Z,1549596662.310 [logger ThreadHandler](INFO): Cycle time is: 0.003523, Sleep time was: 0.094359
2019-02-08T03:31:02.414Z,1549596662.414 [logger ThreadHandler](INFO): Cycle time is: 0.003456, Sleep time was: 0.095333
2019-02-08T03:31:02.518Z,1549596662.518 [logger ThreadHandler](INFO): Cycle time is: 0.003526, Sleep time was: 0.093089
2019-02-08T03:31:02.623Z,1549596662.623 [logger ThreadHandler](INFO): Cycle time is: 0.003728, Sleep time was: 0.095003
2019-02-08T03:31:02.726Z,1549596662.726 [logger ThreadHandler](INFO): Cycle time is: 0.003197, Sleep time was: 0.094928
2019-02-08T03:31:02.830Z,1549596662.830 [logger ThreadHandler](INFO): Cycle time is: 0.003511, Sleep time was: 0.095317
2019-02-08T03:31:02.935Z,1549596662.935 [logger ThreadHandler](INFO): Cycle time is: 0.003410, Sleep time was: 0.095635
2019-02-08T03:31:03.038Z,1549596663.038 [logger ThreadHandler](INFO): Cycle time is: 0.003082, Sleep time was: 0.084957
2019-02-08T03:31:03.142Z,1549596663.142 [logger ThreadHandler](INFO): Cycle time is: 0.003198, Sleep time was: 0.092349
2019-02-08T03:31:03.246Z,1549596663.246 [logger ThreadHandler](INFO): Cycle time is: 0.003464, Sleep time was: 0.095329
2019-02-08T03:31:03.350Z,1549596663.350 [logger ThreadHandler](INFO): Cycle time is: 0.003482, Sleep time was: 0.095498
2019-02-08T03:31:03.421Z,1549596663.421 [NavChartDb ThreadHandler](INFO): Cycle time is: 1.845777, Sleep time was: -1.845764
2019-02-08T03:31:03.454Z,1549596663.454 [logger ThreadHandler](INFO): Cycle time is: 0.003433, Sleep time was: 0.093932
2019-02-08T03:31:03.558Z,1549596663.558 [logger ThreadHandler](INFO): Cycle time is: 0.003331, Sleep time was: 0.090044
2019-02-08T03:31:03.662Z,1549596663.662 [logger ThreadHandler](INFO): Cycle time is: 0.003487, Sleep time was: 0.095058
2019-02-08T03:31:03.766Z,1549596663.766 [logger ThreadHandler](INFO): Cycle time is: 0.003665, Sleep time was: 0.095573
2019-02-08T03:31:03.870Z,1549596663.870 [logger ThreadHandler](INFO): Cycle time is: 0.003476, Sleep time was: 0.094366
2019-02-08T03:31:03.974Z,1549596663.974 [logger ThreadHandler](INFO): Cycle time is: 0.003456, Sleep time was: 0.095827
2019-02-08T03:31:04.079Z,1549596664.079 [logger ThreadHandler](INFO): Cycle time is: 0.003309, Sleep time was: 0.091673
2019-02-08T03:31:04.182Z,1549596664.182 [logger ThreadHandler](INFO): Cycle time is: 0.003092, Sleep time was: 0.094667
2019-02-08T03:31:04.286Z,1549596664.286 [logger ThreadHandler](INFO): Cycle time is: 0.003382, Sleep time was: 0.093791
2019-02-08T03:31:04.390Z,1549596664.390 [logger ThreadHandler](INFO): Cycle time is: 0.003516, Sleep time was: 0.095330
2019-02-08T03:31:04.494Z,1549596664.494 [logger ThreadHandler](INFO): Cycle time is: 0.003434, Sleep time was: 0.094814
2019-02-08T03:31:04.598Z,1549596664.598 [logger ThreadHandler](INFO): Cycle time is: 0.003496, Sleep time was: 0.095491
2019-02-08T03:31:04.702Z,1549596664.702 [logger ThreadHandler](INFO): Cycle time is: 0.003517, Sleep time was: 0.094316
2019-02-08T03:31:04.806Z,1549596664.806 [logger ThreadHandler](INFO): Cycle time is: 0.003378, Sleep time was: 0.095908
2019-02-08T03:31:04.911Z,1549596664.911 [logger ThreadHandler](INFO): Cycle time is: 0.003549, Sleep time was: 0.092378
2019-02-08T03:31:05.015Z,1549596665.015 [logger ThreadHandler](INFO): Cycle time is: 0.003232, Sleep time was: 0.092375
2019-02-08T03:31:05.118Z,1549596665.118 [logger ThreadHandler](INFO): Cycle time is: 0.002899, Sleep time was: 0.091327
2019-02-08T03:31:05.222Z,1549596665.222 [logger ThreadHandler](INFO): Cycle time is: 0.003393, Sleep time was: 0.095217
2019-02-08T03:31:05.276Z,1549596665.276 [NavChartDb ThreadHandler](INFO): Cycle time is: 1.754639, Sleep time was: -1.754626
2019-02-08T03:31:05.326Z,1549596665.326 [logger ThreadHandler](INFO): Cycle time is: 0.003514, Sleep time was: 0.094989
2019-02-08T03:31:05.430Z,1549596665.430 [logger ThreadHandler](INFO): Cycle time is: 0.003313, Sleep time was: 0.090332
2019-02-08T03:31:05.534Z,1549596665.534 [logger ThreadHandler](INFO): Cycle time is: 0.003686, Sleep time was: 0.093518
2019-02-08T03:31:05.638Z,1549596665.638 [logger ThreadHandler](INFO): Cycle time is: 0.003364, Sleep time was: 0.095255
2019-02-08T03:31:05.742Z,1549596665.742 [logger ThreadHandler](INFO): Cycle time is: 0.003387, Sleep time was: 0.095339
2019-02-08T03:31:05.846Z,1549596665.846 [logger ThreadHandler](INFO): Cycle time is: 0.003495, Sleep time was: 0.092882
2019-02-08T03:31:05.951Z,1549596665.951 [logger ThreadHandler](INFO): Cycle time is: 0.003482, Sleep time was: 0.094882
2019-02-08T03:31:06.055Z,1549596666.055 [logger ThreadHandler](INFO): Cycle time is: 0.003102, Sleep time was: 0.093196
2019-02-08T03:31:06.159Z,1549596666.159 [logger ThreadHandler](INFO): Cycle time is: 0.003292, Sleep time was: 0.090537
2019-02-08T03:31:06.262Z,1549596666.262 [logger ThreadHandler](INFO): Cycle time is: 0.003199, Sleep time was: 0.094659
2019-02-08T03:31:06.366Z,1549596666.366 [logger ThreadHandler](INFO): Cycle time is: 0.003382, Sleep time was: 0.095913
2019-02-08T03:31:06.471Z,1549596666.471 [logger ThreadHandler](INFO): Cycle time is: 0.003640, Sleep time was: 0.095334
2019-02-08T03:31:06.574Z,1549596666.574 [logger ThreadHandler](INFO): Cycle time is: 0.002960, Sleep time was: 0.094586
2019-02-08T03:31:06.678Z,1549596666.678 [logger ThreadHandler](INFO): Cycle time is: 0.003389, Sleep time was: 0.095612
2019-02-08T03:31:06.782Z,1549596666.782 [logger ThreadHandler](INFO): Cycle time is: 0.003600, Sleep time was: 0.095946
2019-02-08T03:31:06.886Z,1549596666.886 [logger ThreadHandler](INFO): Cycle time is: 0.003443, Sleep time was: 0.094417
2019-02-08T03:31:06.990Z,1549596666.990 [logger ThreadHandler](INFO): Cycle time is: 0.003506, Sleep time was: 0.095817
2019-02-08T03:31:07.095Z,1549596667.095 [logger ThreadHandler](INFO): Cycle time is: 0.003791, Sleep time was: 0.090068
2019-02-08T03:31:07.199Z,1549596667.199 [logger ThreadHandler](INFO): Cycle time is: 0.003086, Sleep time was: 0.093429
2019-02-08T03:31:07.302Z,1549596667.302 [logger ThreadHandler](INFO): Cycle time is: 0.002215, Sleep time was: 0.092987
2019-02-08T03:31:07.407Z,1549596667.407 [logger ThreadHandler](INFO): Cycle time is: 0.004674, Sleep time was: 0.095960
2019-02-08T03:31:07.510Z,1549596667.510 [logger ThreadHandler](INFO): Cycle time is: 0.002297, Sleep time was: 0.093472
2019-02-08T03:31:07.614Z,1549596667.614 [logger ThreadHandler](INFO): Cycle time is: 0.003575, Sleep time was: 0.095399
2019-02-08T03:31:07.718Z,1549596667.718 [logger ThreadHandler](INFO): Cycle time is: 0.003329, Sleep time was: 0.094807
2019-02-08T03:31:07.822Z,1549596667.822 [logger ThreadHandler](INFO): Cycle time is: 0.003391, Sleep time was: 0.095786
2019-02-08T03:31:07.927Z,1549596667.927 [logger ThreadHandler](INFO): Cycle time is: 0.003662, Sleep time was: 0.094263
2019-02-08T03:31:08.031Z,1549596668.031 [logger ThreadHandler](INFO): Cycle time is: 0.003069, Sleep time was: 0.092216
2019-02-08T03:31:08.134Z,1549596668.134 [logger ThreadHandler](INFO): Cycle time is: 0.002943, Sleep time was: 0.091672
2019-02-08T03:31:08.238Z,1549596668.238 [logger ThreadHandler](INFO): Cycle time is: 0.003517, Sleep time was: 0.094678
2019-02-08T03:31:08.342Z,1549596668.342 [logger ThreadHandler](INFO): Cycle time is: 0.003447, Sleep time was: 0.093476
2019-02-08T03:31:08.446Z,1549596668.446 [logger ThreadHandler](INFO): Cycle time is: 0.003409, Sleep time was: 0.095872
2019-02-08T03:31:08.550Z,1549596668.550 [logger ThreadHandler](INFO): Cycle time is: 0.003545, Sleep time was: 0.094959
2019-02-08T03:31:08.654Z,1549596668.654 [logger ThreadHandler](INFO): Cycle time is: 0.003431, Sleep time was: 0.094459
2019-02-08T03:31:08.758Z,1549596668.758 [logger ThreadHandler](INFO): Cycle time is: 0.003448, Sleep time was: 0.094251
2019-02-08T03:31:08.862Z,1549596668.862 [logger ThreadHandler](INFO): Cycle time is: 0.003379, Sleep time was: 0.093848
2019-02-08T03:31:08.967Z,1549596668.967 [logger ThreadHandler](INFO): Cycle time is: 0.003747, Sleep time was: 0.094661
2019-02-08T03:31:09.071Z,1549596669.071 [logger ThreadHandler](INFO): Cycle time is: 0.003052, Sleep time was: 0.091711
2019-02-08T03:31:09.174Z,1549596669.174 [logger ThreadHandler](INFO): Cycle time is: 0.003157, Sleep time was: 0.089816
2019-02-08T03:31:09.278Z,1549596669.278 [logger ThreadHandler](INFO): Cycle time is: 0.003434, Sleep time was: 0.095069
2019-02-08T03:31:09.382Z,1549596669.382 [logger ThreadHandler](INFO): Cycle time is: 0.003468, Sleep time was: 0.095063
2019-02-08T03:31:09.486Z,1549596669.486 [logger ThreadHandler](INFO): Cycle time is: 0.003541, Sleep time was: 0.092941
2019-02-08T03:31:09.548Z,1549596669.548 [controlThread ThreadHandler](INFO): Cycle time is: 9.548824, Sleep time was: -9.548811
2019-02-08T03:31:09.590Z,1549596669.590 [logger ThreadHandler](INFO): Cycle time is: 0.003428, Sleep time was: 0.082149
2019-02-08T03:31:09.692Z,1549596669.692 [logger ThreadHandler](INFO): Cycle time is: 0.000966, Sleep time was: -0.000952
2019-02-08T03:31:09.794Z,1549596669.794 [logger ThreadHandler](INFO): Cycle time is: 0.002131, Sleep time was: 0.023268
2019-02-08T03:31:09.845Z,1549596669.845 [NavChartDb ThreadHandler](INFO): Cycle time is: 4.468569, Sleep time was: -4.468557
2019-02-08T03:31:09.898Z,1549596669.898 [logger ThreadHandler](INFO): Cycle time is: 0.003360, Sleep time was: 0.094260
2019-02-08T03:31:09.951Z,1549596669.951 [controlThread ThreadHandler](INFO): Cycle time is: 0.002406, Sleep time was: 0.222468
2019-02-08T03:31:10.004Z,1549596670.004 [logger ThreadHandler](INFO): Cycle time is: 0.004210, Sleep time was: 0.087456
2019-02-08T03:31:10.111Z,1549596670.111 [logger ThreadHandler](INFO): Cycle time is: 0.006939, Sleep time was: -0.006925
2019-02-08T03:31:10.214Z,1549596670.214 [logger ThreadHandler](INFO): Cycle time is: 0.002738, Sleep time was: 0.022685
2019-02-08T03:31:10.318Z,1549596670.318 [logger ThreadHandler](INFO): Cycle time is: 0.003464, Sleep time was: 0.093842
2019-02-08T03:31:10.354Z,1549596670.354 [controlThread ThreadHandler](INFO): Cycle time is: 0.002831, Sleep time was: 0.204097
2019-02-08T03:31:10.422Z,1549596670.422 [logger ThreadHandler](INFO): Cycle time is: 0.003527, Sleep time was: 0.095038
2019-02-08T03:31:10.526Z,1549596670.526 [logger ThreadHandler](INFO): Cycle time is: 0.003363, Sleep time was: 0.076777
2019-02-08T03:31:10.630Z,1549596670.630 [logger ThreadHandler](INFO): Cycle time is: 0.003453, Sleep time was: 0.062472
2019-02-08T03:31:10.652Z,1549596670.652 [NavChartDb ThreadHandler](INFO): Cycle time is: 0.706192, Sleep time was: -0.706179
2019-02-08T03:31:10.734Z,1549596670.734 [logger ThreadHandler](INFO): Cycle time is: 0.003406, Sleep time was: 0.093492
2019-02-08T03:31:10.758Z,1549596670.758 [controlThread ThreadHandler](INFO): Cycle time is: 0.003410, Sleep time was: 0.266248
2019-02-08T03:31:10.838Z,1549596670.838 [logger ThreadHandler](INFO): Cycle time is: 0.003582, Sleep time was: 0.089754
2019-02-08T03:31:10.943Z,1549596670.943 [logger ThreadHandler](INFO): Cycle time is: 0.003882, Sleep time was: 0.031014
2019-02-08T03:31:11.047Z,1549596671.047 [logger ThreadHandler](INFO): Cycle time is: 0.003172, Sleep time was: 0.089795
2019-02-08T03:31:11.150Z,1549596671.150 [logger ThreadHandler](INFO): Cycle time is: 0.002852, Sleep time was: 0.091390
2019-02-08T03:31:11.162Z,1549596671.162 [controlThread ThreadHandler](INFO): Cycle time is: 0.003538, Sleep time was: 0.286394
2019-02-08T03:31:11.254Z,1549596671.254 [logger ThreadHandler](INFO): Cycle time is: 0.003465, Sleep time was: 0.094426
2019-02-08T03:31:11.358Z,1549596671.358 [logger ThreadHandler](INFO): Cycle time is: 0.003480, Sleep time was: 0.037589
2019-02-08T03:31:11.405Z,1549596671.405 [NavChartDb ThreadHandler](INFO): Cycle time is: 0.652691, Sleep time was: -0.652677
2019-02-08T03:31:11.462Z,1549596671.462 [logger ThreadHandler](INFO): Cycle time is: 0.003376, Sleep time was: 0.094260
2019-02-08T03:31:11.566Z,1549596671.566 [controlThread ThreadHandler](INFO): Cycle time is: 0.003413, Sleep time was: 0.117997
2019-02-08T03:31:11.586Z,1549596671.586 [logger ThreadHandler](INFO): Cycle time is: 0.023537, Sleep time was: 0.081955
2019-02-08T03:31:11.690Z,1549596671.690 [logger ThreadHandler](INFO): Cycle time is: 0.003466, Sleep time was: 0.085775
2019-02-08T03:31:11.794Z,1549596671.794 [logger ThreadHandler](INFO): Cycle time is: 0.003492, Sleep time was: 0.053741
2019-02-08T03:31:11.880Z,1549596671.880 [NavChartDb ThreadHandler](INFO): Cycle time is: 0.374436, Sleep time was: -0.374422
2019-02-08T03:31:11.898Z,1549596671.898 [logger ThreadHandler](INFO): Cycle time is: 0.003399, Sleep time was: 0.093976
2019-02-08T03:31:12.004Z,1549596672.004 [logger ThreadHandler](INFO): Cycle time is: 0.004024, Sleep time was: 0.088717
2019-02-08T03:31:12.107Z,1549596672.107 [logger ThreadHandler](INFO): Cycle time is: 0.002107, Sleep time was: 0.087678
2019-02-08T03:31:12.133Z,1549596672.133 [controlThread ThreadHandler](INFO): Cycle time is: 0.166355, Sleep time was: -0.166342
2019-02-08T03:31:12.211Z,1549596672.211 [logger ThreadHandler](INFO): Cycle time is: 0.003073, Sleep time was: 0.091619
2019-02-08T03:31:12.314Z,1549596672.314 [logger ThreadHandler](INFO): Cycle time is: 0.002673, Sleep time was: -0.002658
2019-02-08T03:31:12.418Z,1549596672.418 [logger ThreadHandler](INFO): Cycle time is: 0.003637, Sleep time was: 0.077775
2019-02-08T03:31:12.522Z,1549596672.522 [logger ThreadHandler](INFO): Cycle time is: 0.003449, Sleep time was: 0.093800
2019-02-08T03:31:12.534Z,1549596672.534 [controlThread ThreadHandler](INFO): Cycle time is: 0.000660, Sleep time was: 0.228615
2019-02-08T03:31:12.613Z,1549596672.613 [NavChartDb ThreadHandler](INFO): Cycle time is: 0.632073, Sleep time was: -0.632060
2019-02-08T03:31:12.626Z,1549596672.626 [logger ThreadHandler](INFO): Cycle time is: 0.003616, Sleep time was: 0.094479
2019-02-08T03:31:12.728Z,1549596672.728 [logger ThreadHandler](INFO): Cycle time is: 0.001019, Sleep time was: -0.001005
2019-02-08T03:31:12.831Z,1549596672.831 [logger ThreadHandler](INFO): Cycle time is: 0.001759, Sleep time was: 0.088577
2019-02-08T03:31:12.935Z,1549596672.935 [logger ThreadHandler](INFO): Cycle time is: 0.002799, Sleep time was: 0.093358
2019-02-08T03:31:12.939Z,1549596672.939 [controlThread ThreadHandler](INFO): Cycle time is: 0.003547, Sleep time was: 0.225739
2019-02-08T03:31:13.042Z,1549596673.042 [logger ThreadHandler](INFO): Cycle time is: 0.006296, Sleep time was: -0.006280
2019-02-08T03:31:13.147Z,1549596673.147 [logger ThreadHandler](INFO): Cycle time is: 0.004214, Sleep time was: -0.004202
2019-02-08T03:31:13.250Z,1549596673.250 [logger ThreadHandler](INFO): Cycle time is: 0.002716, Sleep time was: 0.061853
2019-02-08T03:31:13.342Z,1549596673.342 [controlThread ThreadHandler](INFO): Cycle time is: 0.002997, Sleep time was: 0.130225
2019-02-08T03:31:13.354Z,1549596673.354 [logger ThreadHandler](INFO): Cycle time is: 0.003454, Sleep time was: 0.087264
2019-02-08T03:31:13.458Z,1549596673.458 [logger ThreadHandler](INFO): Cycle time is: 0.003520, Sleep time was: 0.038043
2019-02-08T03:31:13.562Z,1549596673.562 [logger ThreadHandler](INFO): Cycle time is: 0.003468, Sleep time was: 0.088601
2019-02-08T03:31:13.666Z,1549596673.666 [logger ThreadHandler](INFO): Cycle time is: 0.003392, Sleep time was: 0.041963
2019-02-08T03:31:13.747Z,1549596673.747 [controlThread ThreadHandler](INFO): Cycle time is: 0.003890, Sleep time was: 0.153871
2019-02-08T03:31:13.771Z,1549596673.771 [logger ThreadHandler](INFO): Cycle time is: 0.004464, Sleep time was: 0.095124
2019-02-08T03:31:13.800Z,1549596673.800 [BPC1](FAULT): Failed to parse data from all battery packs.
2019-02-08T03:31:13.800Z,1549596673.800 [BPC1] Data Fault, FailCount= 1
2019-02-08T03:31:13.800Z,1549596673.800 [BPC1](ERROR): Data Fault
2019-02-08T03:31:13.848Z,1549596673.848 [NavChartDb ThreadHandler](INFO): Cycle time is: 1.134189, Sleep time was: -1.134175
2019-02-08T03:31:13.877Z,1549596673.877 [logger ThreadHandler](INFO): Cycle time is: 0.003631, Sleep time was: 0.084263
2019-02-08T03:31:13.936Z,1549596673.936 [CBIT](ERROR): Data Fault in component: BPC1
2019-02-08T03:31:13.982Z,1549596673.982 [logger ThreadHandler](INFO): Cycle time is: 0.003808, Sleep time was: -0.003791
2019-02-08T03:31:14.095Z,1549596674.095 [logger ThreadHandler](INFO): Cycle time is: 0.012651, Sleep time was: -0.012635
2019-02-08T03:31:14.150Z,1549596674.150 [controlThread ThreadHandler](INFO): Cycle time is: 0.003097, Sleep time was: 0.206124
2019-02-08T03:31:14.198Z,1549596674.198 [logger ThreadHandler](INFO): Cycle time is: 0.002444, Sleep time was: 0.059122
2019-02-08T03:31:14.304Z,1549596674.304 [logger ThreadHandler](INFO): Cycle time is: 0.003612, Sleep time was: 0.062865
2019-02-08T03:31:14.407Z,1549596674.407 [logger ThreadHandler](INFO): Cycle time is: 0.001858, Sleep time was: 0.056780
2019-02-08T03:31:14.511Z,1549596674.511 [logger ThreadHandler](INFO): Cycle time is: 0.004020, Sleep time was: 0.093803
2019-02-08T03:31:14.554Z,1549596674.554 [controlThread ThreadHandler](INFO): Cycle time is: 0.003429, Sleep time was: 0.114705
2019-02-08T03:31:14.614Z,1549596674.614 [logger ThreadHandler](INFO): Cycle time is: 0.002773, Sleep time was: 0.088252
2019-02-08T03:31:14.722Z,1549596674.722 [logger ThreadHandler](INFO): Cycle time is: 0.003856, Sleep time was: 0.032006
2019-02-08T03:31:14.779Z,1549596674.779 [NavChartDb ThreadHandler](INFO): Cycle time is: 0.831399, Sleep time was: -0.831386
2019-02-08T03:31:14.826Z,1549596674.826 [logger ThreadHandler](INFO): Cycle time is: 0.003497, Sleep time was: 0.086638
2019-02-08T03:31:14.931Z,1549596674.931 [logger ThreadHandler](INFO): Cycle time is: 0.004016, Sleep time was: 0.090159
2019-02-08T03:31:14.959Z,1549596674.959 [controlThread ThreadHandler](INFO): Cycle time is: 0.003664, Sleep time was: 0.243571
2019-02-08T03:31:15.035Z,1549596675.035 [logger ThreadHandler](INFO): Cycle time is: 0.002552, Sleep time was: 0.090807
2019-02-08T03:31:15.143Z,1549596675.143 [logger ThreadHandler](INFO): Cycle time is: 0.007453, Sleep time was: -0.007440
2019-02-08T03:31:15.246Z,1549596675.246 [logger ThreadHandler](INFO): Cycle time is: 0.003118, Sleep time was: 0.078116
2019-02-08T03:31:15.350Z,1549596675.350 [logger ThreadHandler](INFO): Cycle time is: 0.003389, Sleep time was: 0.086675
2019-02-08T03:31:15.362Z,1549596675.362 [controlThread ThreadHandler](INFO): Cycle time is: 0.002869, Sleep time was: 0.169413
2019-02-08T03:31:15.454Z,1549596675.454 [logger ThreadHandler](INFO): Cycle time is: 0.003516, Sleep time was: 0.094963
2019-02-08T03:31:15.535Z,1549596675.535 [NavChartDb ThreadHandler](INFO): Cycle time is: 0.655027, Sleep time was: -0.655012
2019-02-08T03:31:15.562Z,1549596675.562 [logger ThreadHandler](INFO): Cycle time is: 0.006858, Sleep time was: -0.006845
2019-02-08T03:31:15.666Z,1549596675.666 [logger ThreadHandler](INFO): Cycle time is: 0.003914, Sleep time was: 0.086648
2019-02-08T03:31:15.766Z,1549596675.766 [controlThread ThreadHandler](INFO): Cycle time is: 0.003438, Sleep time was: 0.252298
2019-02-08T03:31:15.770Z,1549596675.770 [logger ThreadHandler](INFO): Cycle time is: 0.003513, Sleep time was: 0.094325
2019-02-08T03:31:15.874Z,1549596675.874 [logger ThreadHandler](INFO): Cycle time is: 0.003405, Sleep time was: 0.091494
2019-02-08T03:31:15.979Z,1549596675.979 [logger ThreadHandler](INFO): Cycle time is: 0.003565, Sleep time was: 0.029542
2019-02-08T03:31:16.083Z,1549596676.083 [logger ThreadHandler](INFO): Cycle time is: 0.003335, Sleep time was: 0.089177
2019-02-08T03:31:16.128Z,1549596676.128 [NavChartDb ThreadHandler](INFO): Cycle time is: 0.492277, Sleep time was: -0.492264
2019-02-08T03:31:16.170Z,1549596676.170 [controlThread ThreadHandler](INFO): Cycle time is: 0.003441, Sleep time was: 0.306914
2019-02-08T03:31:16.186Z,1549596676.186 [logger ThreadHandler](INFO): Cycle time is: 0.002862, Sleep time was: 0.092065
2019-02-08T03:31:16.290Z,1549596676.290 [logger ThreadHandler](INFO): Cycle time is: 0.003429, Sleep time was: 0.081404
2019-02-08T03:31:16.382Z,1549596676.382 [NavChartDb ThreadHandler](INFO): Cycle time is: 0.153682, Sleep time was: -0.153669
2019-02-08T03:31:16.394Z,1549596676.394 [logger ThreadHandler](INFO): Cycle time is: 0.003583, Sleep time was: 0.051861
2019-02-08T03:31:16.498Z,1549596676.498 [logger ThreadHandler](INFO): Cycle time is: 0.003316, Sleep time was: 0.086914
2019-02-08T03:31:16.574Z,1549596676.574 [controlThread ThreadHandler](INFO): Cycle time is: 0.003457, Sleep time was: 0.306776
2019-02-08T03:31:16.602Z,1549596676.602 [logger ThreadHandler](INFO): Cycle time is: 0.003482, Sleep time was: 0.095108
2019-02-08T03:31:16.706Z,1549596676.706 [logger ThreadHandler](INFO): Cycle time is: 0.003373, Sleep time was: 0.083406
2019-02-08T03:31:16.812Z,1549596676.812 [logger ThreadHandler](INFO): Cycle time is: 0.004536, Sleep time was: 0.058539
2019-02-08T03:31:16.914Z,1549596676.914 [logger ThreadHandler](INFO): Cycle time is: 0.001434, Sleep time was: 0.089276
2019-02-08T03:31:16.979Z,1549596676.979 [controlThread ThreadHandler](INFO): Cycle time is: 0.003807, Sleep time was: 0.298380
2019-02-08T03:31:17.019Z,1549596677.019 [logger ThreadHandler](INFO): Cycle time is: 0.003632, Sleep time was: 0.094693
2019-02-08T03:31:17.122Z,1549596677.122 [logger ThreadHandler](INFO): Cycle time is: 0.003072, Sleep time was: 0.058591
2019-02-08T03:31:17.226Z,1549596677.226 [logger ThreadHandler](INFO): Cycle time is: 0.003425, Sleep time was: 0.083316
2019-02-08T03:31:17.330Z,1549596677.330 [logger ThreadHandler](INFO): Cycle time is: 0.003434, Sleep time was: 0.076719
2019-02-08T03:31:17.382Z,1549596677.382 [controlThread ThreadHandler](INFO): Cycle time is: 0.002827, Sleep time was: 0.211624
2019-02-08T03:31:17.434Z,1549596677.434 [logger ThreadHandler](INFO): Cycle time is: 0.003522, Sleep time was: 0.094570
2019-02-08T03:31:17.538Z,1549596677.538 [logger ThreadHandler](INFO): Cycle time is: 0.003454, Sleep time was: 0.023635
2019-02-08T03:31:17.642Z,1549596677.642 [logger ThreadHandler](INFO): Cycle time is: 0.003431, Sleep time was: 0.094003
2019-02-08T03:31:17.747Z,1549596677.747 [logger ThreadHandler](INFO): Cycle time is: 0.003793, Sleep time was: 0.093829
2019-02-08T03:31:17.786Z,1549596677.786 [controlThread ThreadHandler](INFO): Cycle time is: 0.003415, Sleep time was: 0.282367
2019-02-08T03:31:17.850Z,1549596677.850 [logger ThreadHandler](INFO): Cycle time is: 0.003041, Sleep time was: 0.095097
2019-02-08T03:31:17.955Z,1549596677.955 [logger ThreadHandler](INFO): Cycle time is: 0.003708, Sleep time was: 0.069276
2019-02-08T03:31:18.059Z,1549596678.059 [logger ThreadHandler](INFO): Cycle time is: 0.003034, Sleep time was: 0.051271
2019-02-08T03:31:18.162Z,1549596678.162 [logger ThreadHandler](INFO): Cycle time is: 0.003161, Sleep time was: 0.088801
2019-02-08T03:31:18.190Z,1549596678.190 [controlThread ThreadHandler](INFO): Cycle time is: 0.003507, Sleep time was: 0.276701
2019-02-08T03:31:18.266Z,1549596678.266 [logger ThreadHandler](INFO): Cycle time is: 0.003539, Sleep time was: 0.094788
2019-02-08T03:31:18.370Z,1549596678.370 [logger ThreadHandler](INFO): Cycle time is: 0.003420, Sleep time was: 0.030337
2019-02-08T03:31:18.474Z,1549596678.474 [logger ThreadHandler](INFO): Cycle time is: 0.003468, Sleep time was: 0.094591
2019-02-08T03:31:18.578Z,1549596678.578 [logger ThreadHandler](INFO): Cycle time is: 0.003447, Sleep time was: 0.094200
2019-02-08T03:31:18.594Z,1549596678.594 [controlThread ThreadHandler](INFO): Cycle time is: 0.003722, Sleep time was: 0.299294
2019-02-08T03:31:18.683Z,1549596678.683 [logger ThreadHandler](INFO): Cycle time is: 0.004138, Sleep time was: 0.094321
2019-02-08T03:31:18.786Z,1549596678.786 [logger ThreadHandler](INFO): Cycle time is: 0.002926, Sleep time was: 0.028741
2019-02-08T03:31:18.890Z,1549596678.890 [logger ThreadHandler](INFO): Cycle time is: 0.003365, Sleep time was: 0.094443
2019-02-08T03:31:18.995Z,1549596678.995 [logger ThreadHandler](INFO): Cycle time is: 0.003819, Sleep time was: 0.094350
2019-02-08T03:31:18.999Z,1549596678.999 [controlThread ThreadHandler](INFO): Cycle time is: 0.003976, Sleep time was: 0.314534
2019-02-08T03:31:19.097Z,1549596679.097 [logger ThreadHandler](INFO): Cycle time is: 0.001460, Sleep time was: -0.001447
2019-02-08T03:31:19.198Z,1549596679.198 [logger ThreadHandler](INFO): Cycle time is: 0.000471, Sleep time was: 0.018014
2019-02-08T03:31:19.302Z,1549596679.302 [logger ThreadHandler](INFO): Cycle time is: 0.003341, Sleep time was: 0.093578
2019-02-08T03:31:19.402Z,1549596679.402 [controlThread ThreadHandler](INFO): Cycle time is: 0.002821, Sleep time was: 0.252374
2019-02-08T03:31:19.406Z,1549596679.406 [logger ThreadHandler](INFO): Cycle time is: 0.003493, Sleep time was: 0.094836
2019-02-08T03:31:19.510Z,1549596679.510 [logger ThreadHandler](INFO): Cycle time is: 0.003536, Sleep time was: 0.091871
2019-02-08T03:31:19.614Z,1549596679.614 [logger ThreadHandler](INFO): Cycle time is: 0.003426, Sleep time was: 0.034667
2019-02-08T03:31:19.718Z,1549596679.718 [logger ThreadHandler](INFO): Cycle time is: 0.003453, Sleep time was: 0.095592
2019-02-08T03:31:19.807Z,1549596679.807 [controlThread ThreadHandler](INFO): Cycle time is: 0.004122, Sleep time was: 0.274886
2019-02-08T03:31:19.822Z,1549596679.822 [logger ThreadHandler](INFO): Cycle time is: 0.003508, Sleep time was: 0.095056
2019-02-08T03:31:19.934Z,1549596679.934 [logger ThreadHandler](INFO): Cycle time is: 0.010342, Sleep time was: -0.010325
2019-02-08T03:31:20.039Z,1549596680.039 [logger ThreadHandler](INFO): Cycle time is: 0.004396, Sleep time was: 0.007997
2019-02-08T03:31:20.142Z,1549596680.142 [logger ThreadHandler](INFO): Cycle time is: 0.002835, Sleep time was: 0.082560
2019-02-08T03:31:20.210Z,1549596680.210 [controlThread ThreadHandler](INFO): Cycle time is: 0.002916, Sleep time was: 0.279011
2019-02-08T03:31:20.247Z,1549596680.247 [logger ThreadHandler](INFO): Cycle time is: 0.004406, Sleep time was: 0.094103
2019-02-08T03:31:20.350Z,1549596680.350 [logger ThreadHandler](INFO): Cycle time is: 0.002460, Sleep time was: 0.083521
2019-02-08T03:31:20.454Z,1549596680.454 [logger ThreadHandler](INFO): Cycle time is: 0.003479, Sleep time was: 0.068793
2019-02-08T03:31:20.559Z,1549596680.559 [logger ThreadHandler](INFO): Cycle time is: 0.004284, Sleep time was: 0.094014
2019-02-08T03:31:20.614Z,1549596680.614 [controlThread ThreadHandler](INFO): Cycle time is: 0.003420, Sleep time was: 0.291398
2019-02-08T03:31:20.662Z,1549596680.662 [logger ThreadHandler](INFO): Cycle time is: 0.002733, Sleep time was: 0.094764
2019-02-08T03:31:20.766Z,1549596680.766 [logger ThreadHandler](INFO): Cycle time is: 0.003500, Sleep time was: 0.079956
2019-02-08T03:31:20.870Z,1549596680.870 [logger ThreadHandler](INFO): Cycle time is: 0.003426, Sleep time was: 0.055815
2019-02-08T03:31:20.975Z,1549596680.975 [logger ThreadHandler](INFO): Cycle time is: 0.003824, Sleep time was: 0.094366
2019-02-08T03:31:21.019Z,1549596681.019 [controlThread ThreadHandler](INFO): Cycle time is: 0.003664, Sleep time was: 0.287187
2019-02-08T03:31:21.079Z,1549596681.079 [logger ThreadHandler](INFO): Cycle time is: 0.002630, Sleep time was: 0.090632
2019-02-08T03:31:21.143Z,1549596681.143 [NavChartDb ThreadHandler](INFO): Cycle time is: 4.660564, Sleep time was: -4.660550
2019-02-08T03:31:21.182Z,1549596681.182 [logger ThreadHandler](INFO): Cycle time is: 0.002888, Sleep time was: 0.001508
2019-02-08T03:31:21.286Z,1549596681.286 [logger ThreadHandler](INFO): Cycle time is: 0.003473, Sleep time was: 0.094892
2019-02-08T03:31:21.390Z,1549596681.390 [logger ThreadHandler](INFO): Cycle time is: 0.003468, Sleep time was: 0.094957
2019-02-08T03:31:21.422Z,1549596681.422 [controlThread ThreadHandler](INFO): Cycle time is: 0.002999, Sleep time was: 0.259945
2019-02-08T03:31:21.494Z,1549596681.494 [logger ThreadHandler](INFO): Cycle time is: 0.003478, Sleep time was: 0.096207
2019-02-08T03:31:21.546Z,1549596681.546 [NavChartDb ThreadHandler](INFO): Cycle time is: 0.002541, Sleep time was: 0.399530
2019-02-08T03:31:21.598Z,1549596681.598 [logger ThreadHandler](INFO): Cycle time is: 0.003630, Sleep time was: 0.055801
2019-02-08T03:31:21.702Z,1549596681.702 [logger ThreadHandler](INFO): Cycle time is: 0.003371, Sleep time was: 0.090290
2019-02-08T03:31:21.806Z,1549596681.806 [logger ThreadHandler](INFO): Cycle time is: 0.003460, Sleep time was: 0.095166
2019-02-08T03:31:21.826Z,1549596681.826 [controlThread ThreadHandler](INFO): Cycle time is: 0.003443, Sleep time was: 0.339940
2019-02-08T03:31:21.910Z,1549596681.910 [logger ThreadHandler](INFO): Cycle time is: 0.003489, Sleep time was: 0.094819
2019-02-08T03:31:21.951Z,1549596681.951 [NavChartDb ThreadHandler](INFO): Cycle time is: 0.003754, Sleep time was: 0.399515
2019-02-08T03:31:22.020Z,1549596682.020 [logger ThreadHandler](INFO): Cycle time is: 0.008994, Sleep time was: -0.008977
2019-02-08T03:31:22.123Z,1549596682.123 [logger ThreadHandler](INFO): Cycle time is: 0.002040, Sleep time was: 0.082992
2019-02-08T03:31:22.226Z,1549596682.226 [logger ThreadHandler](INFO): Cycle time is: 0.002973, Sleep time was: 0.092133
2019-02-08T03:31:22.230Z,1549596682.230 [controlThread ThreadHandler](INFO): Cycle time is: 0.003650, Sleep time was: 0.342189
2019-02-08T03:31:22.330Z,1549596682.330 [logger ThreadHandler](INFO): Cycle time is: 0.003476, Sleep time was: 0.063075
2019-02-08T03:31:22.354Z,1549596682.354 [NavChartDb ThreadHandler](INFO): Cycle time is: 0.002975, Sleep time was: 0.398648
2019-02-08T03:31:22.434Z,1549596682.434 [logger ThreadHandler](INFO): Cycle time is: 0.003481, Sleep time was: 0.061279
2019-02-08T03:31:22.538Z,1549596682.538 [logger ThreadHandler](INFO): Cycle time is: 0.003471, Sleep time was: 0.089706
2019-02-08T03:31:22.634Z,1549596682.634 [controlThread ThreadHandler](INFO): Cycle time is: 0.003337, Sleep time was: 0.321435
2019-02-08T03:31:22.646Z,1549596682.646 [logger ThreadHandler](INFO): Cycle time is: 0.007474, Sleep time was: 0.094949
2019-02-08T03:31:22.750Z,1549596682.750 [logger ThreadHandler](INFO): Cycle time is: 0.003491, Sleep time was: 0.052121
2019-02-08T03:31:22.758Z,1549596682.758 [NavChartDb ThreadHandler](INFO): Cycle time is: 0.003432, Sleep time was: 0.399497
2019-02-08T03:31:22.854Z,1549596682.854 [logger ThreadHandler](INFO): Cycle time is: 0.003484, Sleep time was: 0.064809
2019-02-08T03:31:22.959Z,1549596682.959 [logger ThreadHandler](INFO): Cycle time is: 0.003784, Sleep time was: 0.094827
2019-02-08T03:31:23.039Z,1549596683.039 [controlThread ThreadHandler](INFO): Cycle time is: 0.003562, Sleep time was: 0.321695
2019-02-08T03:31:23.064Z,1549596683.064 [logger ThreadHandler](INFO): Cycle time is: 0.004521, Sleep time was: 0.089789
2019-02-08T03:31:23.162Z,1549596683.162 [NavChartDb ThreadHandler](INFO): Cycle time is: 0.003571, Sleep time was: 0.399549
2019-02-08T03:31:23.165Z,1549596683.165 [logger ThreadHandler](INFO): Cycle time is: 0.001001, Sleep time was: -0.000988
2019-02-08T03:31:23.266Z,1549596683.266 [logger ThreadHandler](INFO): Cycle time is: 0.000242, Sleep time was: 0.077339
2019-02-08T03:31:23.370Z,1549596683.370 [logger ThreadHandler](INFO): Cycle time is: 0.003474, Sleep time was: 0.094362
2019-02-08T03:31:23.442Z,1549596683.442 [controlThread ThreadHandler](INFO): Cycle time is: 0.002964, Sleep time was: 0.262782
2019-02-08T03:31:23.474Z,1549596683.474 [logger ThreadHandler](INFO): Cycle time is: 0.003587, Sleep time was: 0.096200
2019-02-08T03:31:23.515Z,1549596683.515 [SBIT](IMPORTANT): SBIT PASSED
2019-02-08T03:31:23.566Z,1549596683.566 [NavChartDb ThreadHandler](INFO): Cycle time is: 0.003362, Sleep time was: 0.399503
2019-02-08T03:31:23.578Z,1549596683.578 [logger ThreadHandler](INFO): Cycle time is: 0.003362, Sleep time was: 0.084401
2019-02-08T03:31:23.603Z,1549596683.603 [CommandLine](IMPORTANT): got command configSet list
2019-02-08T03:31:23.603Z,1549596683.603 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2019-02-08T03:31:23.604Z,1549596683.604 [CommandLine](IMPORTANT): No configSet variables persisted
2019-02-08T03:31:23.682Z,1549596683.682 [logger ThreadHandler](INFO): Cycle time is: 0.003601, Sleep time was: 0.035550
2019-02-08T03:31:23.786Z,1549596683.786 [logger ThreadHandler](INFO): Cycle time is: 0.003431, Sleep time was: 0.094872
2019-02-08T03:31:23.846Z,1549596683.846 [controlThread ThreadHandler](INFO): Cycle time is: 0.003492, Sleep time was: 0.307786
2019-02-08T03:31:23.890Z,1549596683.890 [logger ThreadHandler](INFO): Cycle time is: 0.003541, Sleep time was: 0.094937
2019-02-08T03:31:23.904Z,1549596683.904 [MissionManager](IMPORTANT): Started mission Startup
2019-02-08T03:31:23.905Z,1549596683.905 [Startup] Running Loop=1
2019-02-08T03:31:23.905Z,1549596683.905 [Startup](DEBUG): Aggregate::initialize Startup
2019-02-08T03:31:23.905Z,1549596683.905 [Startup:A.GoToSurface] Running Loop=1
2019-02-08T03:31:23.905Z,1549596683.905 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-02-08T03:31:23.906Z,1549596683.906 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-02-08T03:31:23.910Z,1549596683.910 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-02-08T03:31:23.911Z,1549596683.911 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-02-08T03:31:23.911Z,1549596683.911 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-02-08T03:31:23.911Z,1549596683.911 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-02-08T03:31:23.921Z,1549596683.921 [Startup:StartupSatComms] Running Loop=1
2019-02-08T03:31:23.921Z,1549596683.921 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2019-02-08T03:31:23.921Z,1549596683.921 [Startup:StartupSatComms:A] Running Loop=1
2019-02-08T03:31:23.971Z,1549596683.971 [NavChartDb ThreadHandler](INFO): Cycle time is: 0.003666, Sleep time was: 0.399421
2019-02-08T03:31:24.011Z,1549596684.011 [logger ThreadHandler](INFO): Cycle time is: 0.020116, Sleep time was: -0.020099
2019-02-08T03:31:24.114Z,1549596684.114 [logger ThreadHandler](INFO): Cycle time is: 0.002470, Sleep time was: -0.002455
2019-02-08T03:31:24.218Z,1549596684.218 [logger ThreadHandler](INFO): Cycle time is: 0.003305, Sleep time was: 0.077888
2019-02-08T03:31:24.250Z,1549596684.250 [controlThread ThreadHandler](INFO): Cycle time is: 0.003488, Sleep time was: 0.278414
2019-02-08T03:31:24.297Z,1549596684.297 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2019-02-08T03:31:24.322Z,1549596684.322 [logger ThreadHandler](INFO): Cycle time is: 0.003484, Sleep time was: 0.094075
2019-02-08T03:31:24.374Z,1549596684.374 [NavChartDb ThreadHandler](INFO): Cycle time is: 0.003022, Sleep time was: 0.399480
2019-02-08T03:31:24.426Z,1549596684.426 [logger ThreadHandler](INFO): Cycle time is: 0.003471, Sleep time was: 0.049989
2019-02-08T03:31:24.530Z,1549596684.530 [logger ThreadHandler](INFO): Cycle time is: 0.003504, Sleep time was: 0.082681
2019-02-08T03:31:24.634Z,1549596684.634 [logger ThreadHandler](INFO): Cycle time is: 0.003479, Sleep time was: 0.094925
2019-02-08T03:31:24.654Z,1549596684.654 [controlThread ThreadHandler](INFO): Cycle time is: 0.003520, Sleep time was: 0.339241
2019-02-08T03:31:24.738Z,1549596684.738 [logger ThreadHandler](INFO): Cycle time is: 0.003477, Sleep time was: 0.094632
2019-02-08T03:31:24.778Z,1549596684.778 [NavChartDb ThreadHandler](INFO): Cycle time is: 0.003473, Sleep time was: 0.399512
2019-02-08T03:31:24.842Z,1549596684.842 [logger ThreadHandler](INFO): Cycle time is: 0.003477, Sleep time was: 0.050965
2019-02-08T03:31:24.946Z,1549596684.946 [logger ThreadHandler](INFO): Cycle time is: 0.003555, Sleep time was: 0.094813
2019-02-08T03:31:25.051Z,1549596685.051 [logger ThreadHandler](INFO): Cycle time is: 0.003403, Sleep time was: 0.090227
2019-02-08T03:31:25.059Z,1549596685.059 [controlThread ThreadHandler](INFO): Cycle time is: 0.003812, Sleep time was: 0.326868
2019-02-08T03:31:25.154Z,1549596685.154 [logger ThreadHandler](INFO): Cycle time is: 0.003279, Sleep time was: 0.062336
2019-02-08T03:31:25.182Z,1549596685.182 [NavChartDb ThreadHandler](INFO): Cycle time is: 0.003464, Sleep time was: 0.399490
2019-02-08T03:31:25.258Z,1549596685.258 [logger ThreadHandler](INFO): Cycle time is: 0.003311, Sleep time was: 0.043738
2019-02-08T03:31:25.362Z,1549596685.362 [logger ThreadHandler](INFO): Cycle time is: 0.003466, Sleep time was: 0.094710
2019-02-08T03:31:25.462Z,1549596685.462 [controlThread ThreadHandler](INFO): Cycle time is: 0.003071, Sleep time was: 0.270570
2019-02-08T03:31:25.466Z,1549596685.466 [logger ThreadHandler](INFO): Cycle time is: 0.003553, Sleep time was: 0.095221
2019-02-08T03:31:25.570Z,1549596685.570 [logger ThreadHandler](INFO): Cycle time is: 0.003436, Sleep time was: 0.080018
2019-02-08T03:31:25.586Z,1549596685.586 [NavChartDb ThreadHandler](INFO): Cycle time is: 0.003364, Sleep time was: 0.399507
2019-02-08T03:31:25.674Z,1549596685.674 [logger ThreadHandler](INFO): Cycle time is: 0.003479, Sleep time was: 0.058013
2019-02-08T03:31:25.778Z,1549596685.778 [logger ThreadHandler](INFO): Cycle time is: 0.003484, Sleep time was: 0.094848
2019-02-08T03:31:25.866Z,1549596685.866 [controlThread ThreadHandler](INFO): Cycle time is: 0.003517, Sleep time was: 0.311081
2019-02-08T03:31:25.886Z,1549596685.886 [logger ThreadHandler](INFO): Cycle time is: 0.007614, Sleep time was: 0.094965
2019-02-08T03:31:25.991Z,1549596685.991 [logger ThreadHandler](INFO): Cycle time is: 0.003687, Sleep time was: 0.089149
2019-02-08T03:31:26.007Z,1549596686.007 [NavChartDb ThreadHandler](INFO): Cycle time is: 0.019719, Sleep time was: 0.399551
2019-02-08T03:31:26.103Z,1549596686.103 [logger ThreadHandler](INFO): Cycle time is: 0.009713, Sleep time was: -0.009586
2019-02-08T03:31:26.206Z,1549596686.206 [logger ThreadHandler](INFO): Cycle time is: 0.002188, Sleep time was: 0.062013
2019-02-08T03:31:26.270Z,1549596686.270 [controlThread ThreadHandler](INFO): Cycle time is: 0.003495, Sleep time was: 0.253288
2019-02-08T03:31:26.311Z,1549596686.311 [logger ThreadHandler](INFO): Cycle time is: 0.003786, Sleep time was: 0.094473
2019-02-08T03:31:26.410Z,1549596686.410 [NavChartDb ThreadHandler](INFO): Cycle time is: 0.003267, Sleep time was: 0.399150
2019-02-08T03:31:26.414Z,1549596686.414 [logger ThreadHandler](INFO): Cycle time is: 0.003170, Sleep time was: 0.035983
2019-02-08T03:31:26.518Z,1549596686.518 [logger ThreadHandler](INFO): Cycle time is: 0.003464, Sleep time was: 0.085531
2019-02-08T03:31:26.622Z,1549596686.622 [logger ThreadHandler](INFO): Cycle time is: 0.003480, Sleep time was: 0.095231
2019-02-08T03:31:26.674Z,1549596686.674 [controlThread ThreadHandler](INFO): Cycle time is: 0.003499, Sleep time was: 0.318180
2019-02-08T03:31:26.726Z,1549596686.726 [logger ThreadHandler](INFO): Cycle time is: 0.003604, Sleep time was: 0.094822
2019-02-08T03:31:26.816Z,1549596686.816 [NavChartDb ThreadHandler](INFO): Cycle time is: 0.003976, Sleep time was: 0.399420
2019-02-08T03:31:26.830Z,1549596686.830 [logger ThreadHandler](INFO): Cycle time is: 0.003343, Sleep time was: 0.049302
2019-02-08T03:31:26.934Z,1549596686.934 [logger ThreadHandler](INFO): Cycle time is: 0.003478, Sleep time was: 0.088449
2019-02-08T03:31:27.039Z,1549596687.039 [logger ThreadHandler](INFO): Cycle time is: 0.003555, Sleep time was: 0.096223
2019-02-08T03:31:27.078Z,1549596687.078 [controlThread ThreadHandler](INFO): Cycle time is: 0.003595, Sleep time was: 0.325265
2019-02-08T03:31:27.142Z,1549596687.142 [logger ThreadHandler](INFO): Cycle time is: 0.003048, Sleep time was: 0.091571
2019-02-08T03:31:27.218Z,1549596687.218 [NavChartDb ThreadHandler](INFO): Cycle time is: 0.001816, Sleep time was: 0.398659
2019-02-08T03:31:27.247Z,1549596687.247 [logger ThreadHandler](INFO): Cycle time is: 0.003478, Sleep time was: 0.076108
2019-02-08T03:31:27.350Z,1549596687.350 [logger ThreadHandler](INFO): Cycle time is: 0.002483, Sleep time was: 0.063548
2019-02-08T03:31:27.454Z,1549596687.454 [logger ThreadHandler](INFO): Cycle time is: 0.003495, Sleep time was: 0.094737
2019-02-08T03:31:27.482Z,1549596687.482 [controlThread ThreadHandler](INFO): Cycle time is: 0.003217, Sleep time was: 0.290494
2019-02-08T03:31:27.558Z,1549596687.558 [logger ThreadHandler](INFO): Cycle time is: 0.003481, Sleep time was: 0.094817
2019-02-08T03:31:27.622Z,1549596687.622 [NavChartDb ThreadHandler](INFO): Cycle time is: 0.003485, Sleep time was: 0.398891
2019-02-08T03:31:27.662Z,1549596687.662 [logger ThreadHandler](INFO): Cycle time is: 0.003466, Sleep time was: 0.055469
2019-02-08T03:31:27.766Z,1549596687.766 [logger ThreadHandler](INFO): Cycle time is: 0.003481, Sleep time was: 0.090072
2019-02-08T03:31:27.870Z,1549596687.870 [logger ThreadHandler](INFO): Cycle time is: 0.003482, Sleep time was: 0.095220
2019-02-08T03:31:27.886Z,1549596687.886 [controlThread ThreadHandler](INFO): Cycle time is: 0.003501, Sleep time was: 0.335124
2019-02-08T03:31:27.974Z,1549596687.974 [logger ThreadHandler](INFO): Cycle time is: 0.003636, Sleep time was: 0.094828
2019-02-08T03:31:28.028Z,1549596688.028 [NavChartDb ThreadHandler](INFO): Cycle time is: 0.004783, Sleep time was: 0.399422
2019-02-08T03:31:28.081Z,1549596688.081 [logger ThreadHandler](INFO): Cycle time is: 0.005560, Sleep time was: -0.005543
2019-02-08T03:31:28.182Z,1549596688.182 [logger ThreadHandler](INFO): Cycle time is: 0.000826, Sleep time was: 0.048907
2019-02-08T03:31:28.286Z,1549596688.286 [logger ThreadHandler](INFO): Cycle time is: 0.003485, Sleep time was: 0.094396
2019-02-08T03:31:28.290Z,1549596688.290 [controlThread ThreadHandler](INFO): Cycle time is: 0.003584, Sleep time was: 0.321824
2019-02-08T03:31:28.391Z,1549596688.391 [logger ThreadHandler](INFO): Cycle time is: 0.004554, Sleep time was: -0.004541
2019-02-08T03:31:28.430Z,1549596688.430 [NavChartDb ThreadHandler](INFO): Cycle time is: 0.001238, Sleep time was: 0.398128
2019-02-08T03:31:28.494Z,1549596688.494 [logger ThreadHandler](INFO): Cycle time is: 0.002415, Sleep time was: 0.079072
2019-02-08T03:31:28.598Z,1549596688.598 [logger ThreadHandler](INFO): Cycle time is: 0.003507, Sleep time was: 0.090553
2019-02-08T03:31:28.694Z,1549596688.694 [controlThread ThreadHandler](INFO): Cycle time is: 0.003688, Sleep time was: 0.293212
2019-02-08T03:31:28.702Z,1549596688.702 [logger ThreadHandler](INFO): Cycle time is: 0.003527, Sleep time was: 0.095007
2019-02-08T03:31:28.806Z,1549596688.806 [logger ThreadHandler](INFO): Cycle time is: 0.003529, Sleep time was: 0.083108
2019-02-08T03:31:28.834Z,1549596688.834 [NavChartDb ThreadHandler](INFO): Cycle time is: 0.003620, Sleep time was: 0.399363
2019-02-08T03:31:28.910Z,1549596688.910 [logger ThreadHandler](INFO): Cycle time is: 0.003375, Sleep time was: 0.040089
2019-02-08T03:31:29.015Z,1549596689.015 [logger ThreadHandler](INFO): Cycle time is: 0.003573, Sleep time was: 0.096044
2019-02-08T03:31:29.101Z,1549596689.101 [controlThread ThreadHandler](INFO): Cycle time is: 0.005265, Sleep time was: 0.313356
2019-02-08T03:31:29.121Z,1549596689.121 [logger ThreadHandler](INFO): Cycle time is: 0.004861, Sleep time was: 0.084312
2019-02-08T03:31:29.223Z,1549596689.223 [logger ThreadHandler](INFO): Cycle time is: 0.000891, Sleep time was: -0.000877
2019-02-08T03:31:29.239Z,1549596689.239 [NavChartDb ThreadHandler](INFO): Cycle time is: 0.003549, Sleep time was: 0.399482
2019-02-08T03:31:29.326Z,1549596689.326 [logger ThreadHandler](INFO): Cycle time is: 0.003076, Sleep time was: 0.088215
2019-02-08T03:31:29.430Z,1549596689.430 [logger ThreadHandler](INFO): Cycle time is: 0.003495, Sleep time was: 0.088120
2019-02-08T03:31:29.502Z,1549596689.502 [controlThread ThreadHandler](INFO): Cycle time is: 0.001028, Sleep time was: 0.296567
2019-02-08T03:31:29.534Z,1549596689.534 [logger ThreadHandler](INFO): Cycle time is: 0.003534, Sleep time was: 0.089081
2019-02-08T03:31:29.639Z,1549596689.639 [logger ThreadHandler](INFO): Cycle time is: 0.003986, Sleep time was: 0.017708
2019-02-08T03:31:29.642Z,1549596689.642 [NavChartDb ThreadHandler](INFO): Cycle time is: 0.002379, Sleep time was: 0.398730
2019-02-08T03:31:29.644Z,1549596689.644 [CommandLine](IMPORTANT): got command quit
2019-02-08T03:31:29.742Z,1549596689.742 [logger ThreadHandler](INFO): Cycle time is: 0.002746, Sleep time was: 0.086753
2019-02-08T03:31:29.847Z,1549596689.847 [logger ThreadHandler](INFO): Cycle time is: 0.003987, Sleep time was: 0.097607
2019-02-08T03:31:29.906Z,1549596689.906 [controlThread ThreadHandler](INFO): Cycle time is: 0.003482, Sleep time was: 0.293764
2019-02-08T03:31:29.951Z,1549596689.951 [logger ThreadHandler](INFO): Cycle time is: 0.003739, Sleep time was: 0.097300
2019-02-08T03:31:30.047Z,1549596690.047 [NavChartDb ThreadHandler](INFO): Cycle time is: 0.003548, Sleep time was: 0.399550
2019-02-08T03:31:30.055Z,1549596690.055 [logger ThreadHandler](INFO): Cycle time is: 0.002303, Sleep time was: 0.067743
2019-02-08T03:31:30.158Z,1549596690.158 [logger ThreadHandler](INFO): Cycle time is: 0.002922, Sleep time was: 0.010886
2019-02-08T03:31:30.262Z,1549596690.262 [logger ThreadHandler](INFO): Cycle time is: 0.003513, Sleep time was: 0.097808
2019-02-08T03:31:30.310Z,1549596690.310 [controlThread ThreadHandler](INFO): Cycle time is: 0.003520, Sleep time was: 0.182243
2019-02-08T03:31:30.366Z,1549596690.366 [logger ThreadHandler](INFO): Cycle time is: 0.003499, Sleep time was: 0.097341
2019-02-08T03:31:30.451Z,1549596690.451 [NavChartDb ThreadHandler](INFO): Cycle time is: 0.002962, Sleep time was: 0.399108
2019-02-08T03:31:30.470Z,1549596690.470 [logger ThreadHandler](INFO): Cycle time is: 0.003473, Sleep time was: 0.084934
2019-02-08T03:31:30.574Z,1549596690.574 [logger ThreadHandler](INFO): Cycle time is: 0.003478, Sleep time was: 0.074365
2019-02-08T03:31:30.649Z,1549596690.649 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2019-02-08T03:31:30.649Z,1549596690.649 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-02-08T03:31:30.678Z,1549596690.678 [logger ThreadHandler](INFO): Cycle time is: 0.003503, Sleep time was: 0.097741
2019-02-08T03:31:30.714Z,1549596690.714 [controlThread ThreadHandler](INFO): Cycle time is: 0.003516, Sleep time was: 0.306511
2019-02-08T03:31:30.782Z,1549596690.782 [logger ThreadHandler](INFO): Cycle time is: 0.003609, Sleep time was: 0.091275
2019-02-08T03:31:30.838Z,1549596690.838 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2019-02-08T03:31:30.838Z,1549596690.838 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-02-08T03:31:30.839Z,1549596690.839 [CommandLine](INFO): Join timeout helper Thread ID is 3675
2019-02-08T03:31:30.839Z,1549596690.839 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2019-02-08T03:31:30.839Z,1549596690.839 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-02-08T03:31:30.840Z,1549596690.840 [NavChartDb](INFO): Join timeout helper Thread ID is 3676
2019-02-08T03:31:30.854Z,1549596690.854 [NavChartDb ThreadHandler](INFO): Cycle time is: 0.002587, Sleep time was: 0.398528
2019-02-08T03:31:30.855Z,1549596690.855 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2019-02-08T03:31:30.855Z,1549596690.855 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-02-08T03:31:30.858Z,1549596690.858 [ComponentRegistry](INFO): Shutting down Rowe_600LCM ThreadHandler
2019-02-08T03:31:30.858Z,1549596690.858 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2019-02-08T03:31:30.858Z,1549596690.858 [Rowe_600LCM](INFO): Join timeout helper Thread ID is 3677
2019-02-08T03:31:30.886Z,1549596690.886 [logger ThreadHandler](INFO): Cycle time is: 0.003300, Sleep time was: 0.051911
2019-02-08T03:31:30.990Z,1549596690.990 [logger ThreadHandler](INFO): Cycle time is: 0.003717, Sleep time was: 0.081626
2019-02-08T03:31:31.008Z,1549596691.008 [Rowe_600LCM ThreadHandler](INFO): Uninitializing protected caller thread.
2019-02-08T03:31:31.009Z,1549596691.009 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2019-02-08T03:31:31.096Z,1549596691.096 [logger ThreadHandler](INFO): Cycle time is: 0.003701, Sleep time was: 0.096464
2019-02-08T03:31:31.119Z,1549596691.119 [controlThread ThreadHandler](INFO): Cycle time is: 0.004263, Sleep time was: 0.298292
2019-02-08T03:31:31.198Z,1549596691.198 [logger ThreadHandler](INFO): Cycle time is: 0.002181, Sleep time was: 0.090985
2019-02-08T03:31:31.302Z,1549596691.302 [logger ThreadHandler](INFO): Cycle time is: 0.003493, Sleep time was: 0.005118
2019-02-08T03:31:31.312Z,1549596691.312 [Rowe_600LCM](INFO): Powering down
2019-02-08T03:31:31.314Z,1549596691.314 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2019-02-08T03:31:31.315Z,1549596691.315 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2019-02-08T03:31:31.315Z,1549596691.315 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-02-08T03:31:31.315Z,1549596691.315 [Radio_Surface](INFO): Join timeout helper Thread ID is 3679
2019-02-08T03:31:31.406Z,1549596691.406 [logger ThreadHandler](INFO): Cycle time is: 0.003280, Sleep time was: 0.092296
2019-02-08T03:31:31.510Z,1549596691.510 [logger ThreadHandler](INFO): Cycle time is: 0.003476, Sleep time was: 0.089947
2019-02-08T03:31:31.522Z,1549596691.522 [controlThread ThreadHandler](INFO): Cycle time is: 0.002280, Sleep time was: 0.244121
2019-02-08T03:31:31.614Z,1549596691.614 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2019-02-08T03:31:31.615Z,1549596691.615 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-02-08T03:31:31.615Z,1549596691.615 [logger ThreadHandler](INFO): Cycle time is: 0.004654, Sleep time was: 0.097805
2019-02-08T03:31:31.616Z,1549596691.616 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2019-02-08T03:31:31.616Z,1549596691.616 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-02-08T03:31:31.616Z,1549596691.616 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 3680
2019-02-08T03:31:31.646Z,1549596691.646 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2019-02-08T03:31:31.647Z,1549596691.647 [WetLabsBB2FL](INFO): Powering down
2019-02-08T03:31:31.647Z,1549596691.647 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-02-08T03:31:31.651Z,1549596691.651 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2019-02-08T03:31:31.651Z,1549596691.651 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2019-02-08T03:31:31.652Z,1549596691.652 [CTD_Seabird](INFO): Join timeout helper Thread ID is 3681
2019-02-08T03:31:31.718Z,1549596691.718 [logger ThreadHandler](INFO): Cycle time is: 0.002372, Sleep time was: 0.036615
2019-02-08T03:31:31.822Z,1549596691.822 [logger ThreadHandler](INFO): Cycle time is: 0.003495, Sleep time was: 0.097679
2019-02-08T03:31:31.854Z,1549596691.854 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2019-02-08T03:31:31.855Z,1549596691.855 [CTD_Seabird](INFO): Powering down
2019-02-08T03:31:31.866Z,1549596691.866 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2019-02-08T03:31:31.879Z,1549596691.879 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2019-02-08T03:31:31.879Z,1549596691.879 [logger ThreadHandler](INFO): Thread cancelled.
2019-02-08T03:31:31.879Z,1549596691.879 [logger](INFO): Join timeout helper Thread ID is 3682
2019-02-08T03:31:31.926Z,1549596691.926 [logger ThreadHandler](INFO): Cycle time is: 0.003502, Sleep time was: 0.097682
2019-02-08T03:31:31.927Z,1549596691.927 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2019-02-08T03:31:31.927Z,1549596691.927 [logger ThreadHandler](INFO): Thread cancelled.
2019-02-08T03:31:31.928Z,1549596691.928 [controlThread ThreadHandler](INFO): Cycle time is: 0.004874, Sleep time was: 0.340222
2019-02-08T03:31:31.943Z,1549596691.943 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2019-02-08T03:31:31.943Z,1549596691.943 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-02-08T03:31:31.943Z,1549596691.943 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2019-02-08T03:31:31.943Z,1549596691.943 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-02-08T03:31:31.944Z,1549596691.944 [controlThread](INFO): Join timeout helper Thread ID is 3683
2019-02-08T03:31:31.991Z,1549596691.991 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2019-02-08T03:31:31.991Z,1549596691.991 [controlThread](DEBUG): Uninitializing ControlThread
2019-02-08T03:31:31.991Z,1549596691.991 [Aanderaa_O2](INFO): Powering down
2019-02-08T03:31:31.994Z,1549596691.994 [AcousticModem_Benthos_ATM900](INFO): Powering down
2019-02-08T03:31:32.115Z,1549596692.115 [NAL9602](INFO): Powering down
2019-02-08T03:31:32.116Z,1549596692.116 [PNI_TCM](INFO): Powering down
2019-02-08T03:31:32.203Z,1549596692.203 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2019-02-08T03:31:32.204Z,1549596692.204 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2019-02-08T03:31:32.205Z,1549596692.205 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2019-02-08T03:31:32.205Z,1549596692.205 [MissionManager](INFO): Uninitializing Mission Default
2019-02-08T03:31:32.208Z,1549596692.208 [MissionManager](INFO): Uninitializing Mission Startup
2019-02-08T03:31:32.208Z,1549596692.208 [Startup] Stopped
2019-02-08T03:31:32.208Z,1549596692.208 [Startup](DEBUG): Aggregate::uninitialize Startup
2019-02-08T03:31:32.208Z,1549596692.208 [Startup:A.GoToSurface] Stopped
2019-02-08T03:31:32.208Z,1549596692.208 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-02-08T03:31:32.208Z,1549596692.208 [Startup:StartupSatComms] Stopped
2019-02-08T03:31:32.208Z,1549596692.208 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2019-02-08T03:31:32.208Z,1549596692.208 [Startup:StartupSatComms:A] Stopped
2019-02-08T03:31:32.210Z,1549596692.210 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2019-02-08T03:31:32.210Z,1549596692.210 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2019-02-08T03:31:32.211Z,1549596692.211 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2019-02-08T03:31:32.211Z,1549596692.211 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2019-02-08T03:31:32.211Z,1549596692.211 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2019-02-08T03:31:32.211Z,1549596692.211 [BuoyancyServo](INFO): Powering down
2019-02-08T03:31:32.226Z,1549596692.226 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2019-02-08T03:31:32.226Z,1549596692.226 [ElevatorServo](INFO): Powering down
2019-02-08T03:31:32.227Z,1549596692.227 [MassServo](DEBUG): Uninitialize Mass Servo.
2019-02-08T03:31:32.227Z,1549596692.227 [MassServo](INFO): Powering down
2019-02-08T03:31:32.228Z,1549596692.228 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-02-08T03:31:32.228Z,1549596692.228 [RudderServo](INFO): Powering down
2019-02-08T03:31:32.229Z,1549596692.229 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2019-02-08T03:31:32.229Z,1549596692.229 [ThrusterServo](INFO): Powering down
2019-02-08T03:31:32.230Z,1549596692.230 [SBIT](DEBUG): Uninitialize SBIT Component.
2019-02-08T03:31:32.230Z,1549596692.230 [IBIT](DEBUG): Uninitialize IBIT Component.
2019-02-08T03:31:32.231Z,1549596692.231 [CBIT](DEBUG): Uninitialize CBIT Component.
2019-02-08T03:31:32.231Z,1549596692.231 [CBIT](DEBUG): Powering off loads.
2019-02-08T03:31:32.242Z,1549596692.242 [CBIT](DEBUG): Disabling WDT.
2019-02-08T03:31:32.254Z,1549596692.254 [CBIT](DEBUG): Opening all GF detection circuits.
2019-02-08T03:31:32.255Z,1549596692.255 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-02-08T03:31:32.307Z,1549596692.307 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-02-08T03:31:32.312Z,1549596692.312 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2019-02-08T03:31:32.392Z,1549596692.392 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2019-02-08T03:31:32.397Z,1549596692.397 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-02-08T03:31:32.448Z,1549596692.448 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-02-08T03:31:32.507Z,1549596692.507 [logger ThreadHandler](INFO): Thread cancelled.