2019-02-16T01:33:31.578Z,1550280811.578 [Supervisor](DEBUG): Initializing supervisor.
2019-02-16T01:33:31.581Z,1550280811.581 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2019-02-16T01:33:31.582Z,1550280811.582 [SyncHandler](INFO): Protected caller Thread ID is 3927
2019-02-16T01:33:31.582Z,1550280811.582 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2019-02-16T01:33:31.583Z,1550280811.583 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2019-02-16T01:33:31.584Z,1550280811.584 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 3928
2019-02-16T01:33:31.587Z,1550280811.587 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2019-02-16T01:33:31.598Z,1550280811.598 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2019-02-16T01:33:31.599Z,1550280811.599 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2019-02-16T01:33:31.600Z,1550280811.600 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 3929
2019-02-16T01:33:31.601Z,1550280811.601 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2019-02-16T01:33:31.602Z,1550280811.602 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2019-02-16T01:33:31.602Z,1550280811.602 [logger ThreadHandler](INFO): Protected caller Thread ID is 3930
2019-02-16T01:33:31.604Z,1550280811.604 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2019-02-16T01:33:31.604Z,1550280811.604 [Supervisor](INFO): Looking for Config files in directory: Config/
2019-02-16T01:33:31.606Z,1550280811.606 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2019-02-16T01:33:31.702Z,1550280811.702 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2019-02-16T01:33:31.703Z,1550280811.703 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2019-02-16T01:33:31.901Z,1550280811.901 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2019-02-16T01:33:31.901Z,1550280811.901 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2019-02-16T01:33:32.037Z,1550280812.037 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2019-02-16T01:33:32.038Z,1550280812.038 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2019-02-16T01:33:32.551Z,1550280812.551 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2019-02-16T01:33:32.551Z,1550280812.551 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2019-02-16T01:33:32.989Z,1550280812.989 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2019-02-16T01:33:32.990Z,1550280812.990 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2019-02-16T01:33:33.463Z,1550280813.463 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2019-02-16T01:33:33.463Z,1550280813.463 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2019-02-16T01:33:33.770Z,1550280813.770 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2019-02-16T01:33:33.771Z,1550280813.771 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2019-02-16T01:33:34.119Z,1550280814.119 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2019-02-16T01:33:34.120Z,1550280814.120 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2019-02-16T01:33:34.510Z,1550280814.510 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2019-02-16T01:33:34.510Z,1550280814.510 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2019-02-16T01:33:34.660Z,1550280814.660 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2019-02-16T01:33:34.660Z,1550280814.660 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2019-02-16T01:33:34.767Z,1550280814.767 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2019-02-16T01:33:34.768Z,1550280814.768 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2019-02-16T01:33:34.849Z,1550280814.849 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2019-02-16T01:33:34.950Z,1550280814.950 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2019-02-16T01:33:34.950Z,1550280814.950 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2019-02-16T01:33:35.148Z,1550280815.148 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2019-02-16T01:33:35.149Z,1550280815.149 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2019-02-16T01:33:35.356Z,1550280815.356 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2019-02-16T01:33:35.358Z,1550280815.358 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/
2019-02-16T01:33:35.359Z,1550280815.359 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg
2019-02-16T01:33:35.442Z,1550280815.442 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg
2019-02-16T01:33:35.677Z,1550280815.677 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2019-02-16T01:33:35.677Z,1550280815.677 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg
2019-02-16T01:33:35.772Z,1550280815.772 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg
2019-02-16T01:33:35.932Z,1550280815.932 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg
2019-02-16T01:33:36.138Z,1550280816.138 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg
2019-02-16T01:33:36.222Z,1550280816.222 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg
2019-02-16T01:33:36.320Z,1550280816.320 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg
2019-02-16T01:33:36.413Z,1550280816.413 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg
2019-02-16T01:33:36.565Z,1550280816.565 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg
2019-02-16T01:33:36.669Z,1550280816.669 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg
2019-02-16T01:33:36.768Z,1550280816.768 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/root/
2019-02-16T01:33:36.768Z,1550280816.768 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2019-02-16T01:33:36.771Z,1550280816.771 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2019-02-16T01:33:36.873Z,1550280816.873 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2019-02-16T01:33:36.874Z,1550280816.874 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2019-02-16T01:33:37.004Z,1550280817.004 [BuoyancyServo] Loaded
2019-02-16T01:33:37.004Z,1550280817.004 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2019-02-16T01:33:37.020Z,1550280817.020 [ElevatorServo] Loaded
2019-02-16T01:33:37.020Z,1550280817.020 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2019-02-16T01:33:37.035Z,1550280817.035 [MassServo] Loaded
2019-02-16T01:33:37.035Z,1550280817.035 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2019-02-16T01:33:37.050Z,1550280817.050 [RudderServo] Loaded
2019-02-16T01:33:37.051Z,1550280817.051 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2019-02-16T01:33:37.065Z,1550280817.065 [ThrusterServo] Loaded
2019-02-16T01:33:37.065Z,1550280817.065 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2019-02-16T01:33:37.066Z,1550280817.066 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2019-02-16T01:33:37.066Z,1550280817.066 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2019-02-16T01:33:37.200Z,1550280817.200 [SBIT](DEBUG): Construct Startup Built In Test.
2019-02-16T01:33:37.229Z,1550280817.229 [SBIT] Loaded
2019-02-16T01:33:37.229Z,1550280817.229 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2019-02-16T01:33:37.230Z,1550280817.230 [IBIT](DEBUG): Construct Initiated Built In Test.
2019-02-16T01:33:37.258Z,1550280817.258 [IBIT] Loaded
2019-02-16T01:33:37.258Z,1550280817.258 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2019-02-16T01:33:37.261Z,1550280817.261 [CBIT](DEBUG): Construct Continuous Built In Test.
2019-02-16T01:33:37.662Z,1550280817.662 [CBIT] Loaded
2019-02-16T01:33:37.662Z,1550280817.662 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2019-02-16T01:33:37.662Z,1550280817.662 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2019-02-16T01:33:37.663Z,1550280817.663 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2019-02-16T01:33:38.434Z,1550280818.434 [Aanderaa_O2] Loaded
2019-02-16T01:33:38.434Z,1550280818.434 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2019-02-16T01:33:38.468Z,1550280818.468 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_density
2019-02-16T01:33:38.473Z,1550280818.473 [CTD_Seabird](INFO): created writer for : sea_water_density
2019-02-16T01:33:38.480Z,1550280818.480 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): depth
2019-02-16T01:33:38.485Z,1550280818.485 [CTD_Seabird](INFO): created writer for : depth
2019-02-16T01:33:38.486Z,1550280818.486 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_pressure
2019-02-16T01:33:38.491Z,1550280818.491 [CTD_Seabird](INFO): created writer for : sea_water_pressure
2019-02-16T01:33:38.492Z,1550280818.492 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_salinity
2019-02-16T01:33:38.497Z,1550280818.497 [CTD_Seabird](INFO): created writer for : sea_water_salinity
2019-02-16T01:33:38.498Z,1550280818.498 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_temperature
2019-02-16T01:33:38.503Z,1550280818.503 [CTD_Seabird](INFO): created writer for : sea_water_temperature
2019-02-16T01:33:38.504Z,1550280818.504 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_electrical_conductivity
2019-02-16T01:33:38.510Z,1550280818.510 [CTD_Seabird](INFO): created writer for : sea_water_electrical_conductivity
2019-02-16T01:33:38.510Z,1550280818.510 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): speed_of_sound_in_sea_water
2019-02-16T01:33:38.515Z,1550280818.515 [CTD_Seabird](INFO): created writer for : speed_of_sound_in_sea_water
2019-02-16T01:33:38.542Z,1550280818.542 [CTD_Seabird] Loaded
2019-02-16T01:33:38.543Z,1550280818.543 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2019-02-16T01:33:38.544Z,1550280818.544 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 4062F4E0
2019-02-16T01:33:38.544Z,1550280818.544 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 4009
2019-02-16T01:33:38.566Z,1550280818.566 [ESPComponent] Loaded
2019-02-16T01:33:38.566Z,1550280818.566 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2019-02-16T01:33:38.580Z,1550280818.580 [PAR_Licor] Loaded
2019-02-16T01:33:38.580Z,1550280818.580 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2019-02-16T01:33:38.633Z,1550280818.633 [WetLabsBB2FL] Loaded
2019-02-16T01:33:38.634Z,1550280818.634 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2019-02-16T01:33:38.635Z,1550280818.635 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 4065F4E0
2019-02-16T01:33:38.635Z,1550280818.635 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 4010
2019-02-16T01:33:38.636Z,1550280818.636 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2019-02-16T01:33:38.636Z,1550280818.636 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2019-02-16T01:33:38.678Z,1550280818.678 [DepthRateCalculator] Loaded
2019-02-16T01:33:38.678Z,1550280818.678 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2019-02-16T01:33:38.683Z,1550280818.683 [PitchRateCalculator] Loaded
2019-02-16T01:33:38.684Z,1550280818.684 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2019-02-16T01:33:38.700Z,1550280818.700 [SpeedCalculator] Loaded
2019-02-16T01:33:38.700Z,1550280818.700 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2019-02-16T01:33:38.721Z,1550280818.721 [TempGradientCalculator] Loaded
2019-02-16T01:33:38.721Z,1550280818.721 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2019-02-16T01:33:38.727Z,1550280818.727 [YawRateCalculator] Loaded
2019-02-16T01:33:38.728Z,1550280818.728 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2019-02-16T01:33:38.761Z,1550280818.761 [ElevatorOffsetCalculator] Loaded
2019-02-16T01:33:38.762Z,1550280818.762 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2019-02-16T01:33:38.762Z,1550280818.762 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2019-02-16T01:33:38.763Z,1550280818.763 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2019-02-16T01:33:38.790Z,1550280818.790 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2019-02-16T01:33:38.791Z,1550280818.791 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2019-02-16T01:33:38.894Z,1550280818.894 [DeadReckonUsingMultipleVelocitySources] Loaded
2019-02-16T01:33:38.894Z,1550280818.894 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2019-02-16T01:33:38.955Z,1550280818.955 [DeadReckonUsingSpeedCalculator] Loaded
2019-02-16T01:33:38.955Z,1550280818.955 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2019-02-16T01:33:39.016Z,1550280819.016 [DeadReckonWithRespectToSeafloor] Loaded
2019-02-16T01:33:39.016Z,1550280819.016 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonWithRespectToSeafloor" handled in the control thread.
2019-02-16T01:33:39.032Z,1550280819.032 [NavChart] Loaded
2019-02-16T01:33:39.033Z,1550280819.033 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2019-02-16T01:33:39.037Z,1550280819.037 [UniversalFixResidualReporter] Loaded
2019-02-16T01:33:39.037Z,1550280819.037 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2019-02-16T01:33:39.037Z,1550280819.037 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2019-02-16T01:33:39.038Z,1550280819.038 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2019-02-16T01:33:39.316Z,1550280819.316 [AcousticModem_Benthos_ATM900] Loaded
2019-02-16T01:33:39.316Z,1550280819.316 [ComponentRegistry](DEBUG): SyncComponent "AcousticModem_Benthos_ATM900" handled in the control thread.
2019-02-16T01:33:39.395Z,1550280819.395 [DataOverHttps] Loaded
2019-02-16T01:33:39.395Z,1550280819.395 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2019-02-16T01:33:39.396Z,1550280819.396 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 409264E0
2019-02-16T01:33:39.396Z,1550280819.396 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 4011
2019-02-16T01:33:39.409Z,1550280819.409 [Depth_Keller] Loaded
2019-02-16T01:33:39.410Z,1550280819.410 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2019-02-16T01:33:39.502Z,1550280819.502 [NAL9602] Loaded
2019-02-16T01:33:39.502Z,1550280819.502 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2019-02-16T01:33:39.507Z,1550280819.507 [Onboard] Loaded
2019-02-16T01:33:39.508Z,1550280819.508 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2019-02-16T01:33:39.515Z,1550280819.515 [Radio_Surface] Loaded
2019-02-16T01:33:39.515Z,1550280819.515 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2019-02-16T01:33:39.516Z,1550280819.516 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409564E0
2019-02-16T01:33:39.517Z,1550280819.517 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 4012
2019-02-16T01:33:39.564Z,1550280819.564 [PNI_TCM] Loaded
2019-02-16T01:33:39.565Z,1550280819.565 [ComponentRegistry](DEBUG): SyncComponent "PNI_TCM" handled in the control thread.
2019-02-16T01:33:39.626Z,1550280819.626 [Rowe_600LCM] Loaded
2019-02-16T01:33:39.626Z,1550280819.626 [ComponentRegistry](DEBUG): Component "Rowe_600LCM" handled in its own thread.
2019-02-16T01:33:39.627Z,1550280819.627 [Rowe_600LCM ThreadHandler](DEBUG): Created PCaller Thread at 409864E0
2019-02-16T01:33:39.628Z,1550280819.628 [Rowe_600LCM ThreadHandler](INFO): Protected caller Thread ID is 4013
2019-02-16T01:33:41.226Z,1550280821.226 [BPC1] Loaded
2019-02-16T01:33:41.226Z,1550280821.226 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2019-02-16T01:33:41.226Z,1550280821.226 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2019-02-16T01:33:41.227Z,1550280821.227 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2019-02-16T01:33:41.292Z,1550280821.292 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2019-02-16T01:33:41.293Z,1550280821.293 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2019-02-16T01:33:41.361Z,1550280821.361 [VerticalControl](DEBUG): Construct VerticalControl.
2019-02-16T01:33:41.446Z,1550280821.446 [VerticalControl] Loaded
2019-02-16T01:33:41.446Z,1550280821.446 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2019-02-16T01:33:41.447Z,1550280821.447 [HorizontalControl](DEBUG): Construct HorizontalControl.
2019-02-16T01:33:41.506Z,1550280821.506 [HorizontalControl] Loaded
2019-02-16T01:33:41.506Z,1550280821.506 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2019-02-16T01:33:41.507Z,1550280821.507 [SpeedControl](DEBUG): Construct SpeedControl.
2019-02-16T01:33:41.509Z,1550280821.509 [SpeedControl] Loaded
2019-02-16T01:33:41.509Z,1550280821.509 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2019-02-16T01:33:41.510Z,1550280821.510 [LoopControl](DEBUG): Construct LoopControl.
2019-02-16T01:33:41.510Z,1550280821.510 [LoopControl] Loaded
2019-02-16T01:33:41.511Z,1550280821.511 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2019-02-16T01:33:41.511Z,1550280821.511 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2019-02-16T01:33:41.512Z,1550280821.512 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2019-02-16T01:33:41.525Z,1550280821.525 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2019-02-16T01:33:41.526Z,1550280821.526 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2019-02-16T01:33:41.765Z,1550280821.765 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2019-02-16T01:33:41.768Z,1550280821.768 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2019-02-16T01:33:41.770Z,1550280821.770 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2019-02-16T01:33:41.777Z,1550280821.777 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2019-02-16T01:33:41.778Z,1550280821.778 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40AA84E0
2019-02-16T01:33:41.778Z,1550280821.778 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 4014
2019-02-16T01:33:41.783Z,1550280821.783 [Supervisor](INFO): Main Thread ID is 3562
2019-02-16T01:33:41.783Z,1550280821.783 [Supervisor](DEBUG): Running supervisor.
2019-02-16T01:33:41.784Z,1550280821.784 [CommandLine ThreadHandler](INFO): Handler Thread ID is 4015
2019-02-16T01:33:41.787Z,1550280821.787 [controlThread ThreadHandler](INFO): Handler Thread ID is 4016
2019-02-16T01:33:41.787Z,1550280821.787 [controlThread](DEBUG): Initializing ControlThread
2019-02-16T01:33:41.789Z,1550280821.789 [SBIT](INFO): Initialize SBIT Component.
2019-02-16T01:33:41.790Z,1550280821.790 [SBIT](IMPORTANT): git: 2019-02-11-18-g088f29c
2019-02-16T01:33:41.790Z,1550280821.790 [SBIT](INFO): git hash: 088f29c08f1651a006237423a6ffed1cbba6c6ba
2019-02-16T01:33:41.790Z,1550280821.790 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2019-02-16T01:33:41.791Z,1550280821.791 [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-16T01:33:41.793Z,1550280821.793 [SBIT](INFO): Beginning SBIT in 24.000000 seconds.
2019-02-16T01:33:41.793Z,1550280821.793 [IBIT](INFO): Initialize IBIT Component.
2019-02-16T01:33:41.794Z,1550280821.794 [CBIT](DEBUG): Initialize CBIT Component.
2019-02-16T01:33:41.795Z,1550280821.795 [logger ThreadHandler](INFO): Handler Thread ID is 4017
2019-02-16T01:33:41.805Z,1550280821.805 [CBIT](DEBUG): Initialized mux pins.
2019-02-16T01:33:41.805Z,1550280821.805 [CBIT](DEBUG): Initializing the watchdog timer.
2019-02-16T01:33:41.814Z,1550280821.814 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 4018
2019-02-16T01:33:41.814Z,1550280821.814 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2019-02-16T01:33:41.818Z,1550280821.818 [CTD_Seabird](INFO): Opening uart, block timeout 10ths=20
2019-02-16T01:33:41.819Z,1550280821.819 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 4020
2019-02-16T01:33:41.820Z,1550280821.820 [WetLabsBB2FL](INFO): Powering down
2019-02-16T01:33:41.833Z,1550280821.833 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2019-02-16T01:33:41.834Z,1550280821.834 [CBIT](DEBUG): Initializing heartbeat.
2019-02-16T01:33:41.854Z,1550280821.854 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 4021
2019-02-16T01:33:41.862Z,1550280821.862 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2019-02-16T01:33:41.869Z,1550280821.869 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 4022
2019-02-16T01:33:41.886Z,1550280821.886 [Rowe_600LCM ThreadHandler](INFO): Handler Thread ID is 4023
2019-02-16T01:33:41.887Z,1550280821.887 [Rowe_600LCM](INFO): Initializing
2019-02-16T01:33:41.896Z,1550280821.896 [Rowe_600LCM](INFO): Powering up
2019-02-16T01:33:41.905Z,1550280821.905 [CBIT](DEBUG): Deactivating GF circuits.
2019-02-16T01:33:41.906Z,1550280821.906 [CBIT](DEBUG): Deactivating emergency mode.
2019-02-16T01:33:41.906Z,1550280821.906 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 4024
2019-02-16T01:33:41.910Z,1550280821.910 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2019-02-16T01:33:41.910Z,1550280821.910 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2019-02-16T01:33:41.910Z,1550280821.910 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2019-02-16T01:33:41.910Z,1550280821.910 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2019-02-16T01:33:41.911Z,1550280821.911 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2019-02-16T01:33:41.911Z,1550280821.911 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2019-02-16T01:33:41.911Z,1550280821.911 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2019-02-16T01:33:41.911Z,1550280821.911 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2019-02-16T01:33:41.911Z,1550280821.911 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2019-02-16T01:33:41.911Z,1550280821.911 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2019-02-16T01:33:41.912Z,1550280821.912 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2019-02-16T01:33:41.912Z,1550280821.912 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2019-02-16T01:33:41.912Z,1550280821.912 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2019-02-16T01:33:41.912Z,1550280821.912 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2019-02-16T01:33:41.912Z,1550280821.912 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2019-02-16T01:33:41.913Z,1550280821.913 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2019-02-16T01:33:41.946Z,1550280821.946 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2019-02-16T01:33:41.946Z,1550280821.946 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2019-02-16T01:33:41.946Z,1550280821.946 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2019-02-16T01:33:41.947Z,1550280821.947 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2019-02-16T01:33:41.947Z,1550280821.947 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2019-02-16T01:33:41.948Z,1550280821.948 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2019-02-16T01:33:41.949Z,1550280821.949 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2019-02-16T01:33:41.950Z,1550280821.950 [NavChart](DEBUG): Initialize NavChart Navigation.
2019-02-16T01:33:41.950Z,1550280821.950 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2019-02-16T01:33:41.955Z,1550280821.955 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2019-02-16T01:33:41.957Z,1550280821.957 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2019-02-16T01:33:41.958Z,1550280821.958 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2019-02-16T01:33:41.958Z,1550280821.958 [LoopControl](DEBUG): Initialize LoopControlComponent.
2019-02-16T01:33:41.959Z,1550280821.959 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2019-02-16T01:33:41.979Z,1550280821.979 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2019-02-16T01:33:42.011Z,1550280822.011 [MissionManager](DEBUG):
2019-02-16T01:33:42.012Z,1550280822.012 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2019-02-16T01:33:42.084Z,1550280822.084 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2019-02-16T01:33:42.101Z,1550280822.101 [Default:A.Wait](DEBUG): Construct Wait.
2019-02-16T01:33:42.103Z,1550280822.103 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2019-02-16T01:33:42.125Z,1550280822.125 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2019-02-16T01:33:42.155Z,1550280822.155 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2019-02-16T01:33:42.178Z,1550280822.178 [Default:E.Execute](DEBUG): Construct Execute.
2019-02-16T01:33:42.182Z,1550280822.182 [MissionManager](DEBUG):
0
Wait a moment to see if the scheduler starts a new mission before
starting to actually run Default.
13
Burn on
Dropped weight due to communications timeout.
5
Default mission has been running for
Restarting logs and Default mission.
restart logs
2019-02-16T01:33:42.190Z,1550280822.190 [controlThread](DEBUG): Component order: CycleStarter,Aanderaa_O2,ESPComponent,PAR_Licor,AcousticModem_Benthos_ATM900,Depth_Keller,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-16T01:33:42.273Z,1550280822.273 [Radio_Surface](INFO): Powering up
2019-02-16T01:33:42.274Z,1550280822.274 [ESPComponent](INFO): powering down ESP
2019-02-16T01:33:42.592Z,1550280822.592 [AcousticModem_Benthos_ATM900](INFO): Powering up
2019-02-16T01:33:42.592Z,1550280822.592 [AcousticModem_Benthos_ATM900](DEBUG): Initializing AcousticModem_Benthos_ATM900.
2019-02-16T01:33:43.083Z,1550280823.083 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2019-02-16T01:33:43.098Z,1550280823.098 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2019-02-16T01:33:43.132Z,1550280823.132 [ElevatorServo](DEBUG): Initializing EZServoServo.
2019-02-16T01:33:43.138Z,1550280823.138 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2019-02-16T01:33:43.160Z,1550280823.160 [MassServo](DEBUG): Initializing EZServoServo.
2019-02-16T01:33:43.166Z,1550280823.166 [MassServo](DEBUG): Initializing MassServo.
2019-02-16T01:33:43.172Z,1550280823.172 [RudderServo](DEBUG): Initializing EZServoServo.
2019-02-16T01:33:43.178Z,1550280823.178 [RudderServo](DEBUG): Initializing RudderServo.
2019-02-16T01:33:43.184Z,1550280823.184 [ThrusterServo](DEBUG): Initializing EZServoServo.
2019-02-16T01:33:43.190Z,1550280823.190 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2019-02-16T01:33:44.041Z,1550280824.041 [BuoyancyServo](ERROR): Buoyancy initialization uart error serial timeout
2019-02-16T01:33:44.042Z,1550280824.042 [BuoyancyServo](FAULT): Buoyancy failed to initialize
2019-02-16T01:33:44.042Z,1550280824.042 [BuoyancyServo] Communications Fault, FailCount= 1
2019-02-16T01:33:44.042Z,1550280824.042 [BuoyancyServo](ERROR): Communications Fault
2019-02-16T01:33:44.253Z,1550280824.253 [CBIT](ERROR): Communications Fault in component: BuoyancyServo
2019-02-16T01:33:45.590Z,1550280825.590 [Aanderaa_O2](INFO): Powering down
2019-02-16T01:33:46.188Z,1550280826.188 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2019-02-16T01:33:46.331Z,1550280826.331 [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-16T01:33:46.463Z,1550280826.463 [CBIT](INFO): Clearing failed state for component BuoyancyServo
2019-02-16T01:33:46.463Z,1550280826.463 [BuoyancyServo] No Fault, FailCount= 1
2019-02-16T01:33:46.769Z,1550280826.769 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2019-02-16T01:33:46.886Z,1550280826.886 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2019-02-16T01:33:48.871Z,1550280828.871 [CTD_Seabird](ERROR): Device message queue exceeded the allowed limit.
2019-02-16T01:33:49.978Z,1550280829.978 [AcousticModem_Benthos_ATM900](DEBUG):
2019-02-16T01:33:51.192Z,1550280831.192 [AcousticModem_Benthos_ATM900](DEBUG): Teledyne Benthos ATM-900 Series OEM w/burn wire
2019-02-16T01:33:51.591Z,1550280831.591 [AcousticModem_Benthos_ATM900](DEBUG): MF Frequency Band
2019-02-16T01:33:51.591Z,1550280831.591 [AcousticModem_Benthos_ATM900](DEBUG): Standard version 8.6.3
2019-02-16T01:33:51.592Z,1550280831.592 [AcousticModem_Benthos_ATM900](DEBUG): Feb 11 2019 20:18:26
2019-02-16T01:33:52.007Z,1550280832.007 [AcousticModem_Benthos_ATM900](DEBUG): WARNING: battery low
2019-02-16T01:33:52.311Z,1550280832.311 [CBIT](CRITICAL): Environmental Failure. Press:14.712484 PSI. Humidity:30%. Temp:25 C. ABORTING MISSION
2019-02-16T01:33:52.312Z,1550280832.312 [Supervisor](INFO): Stop Mission called by CBIT::monitorEnvironmentals
2019-02-16T01:33:52.507Z,1550280832.507 [CommandLine](FAULT): Scheduling is paused
2019-02-16T01:33:52.507Z,1550280832.507 [CBIT](INFO): Critical error at 20190216T013352
2019-02-16T01:33:52.802Z,1550280832.802 [AcousticModem_Benthos_ATM900](INFO): entering command mode
2019-02-16T01:33:53.218Z,1550280833.218 [AcousticModem_Benthos_ATM900](DEBUG): checking for command mode acknowledgment
2019-02-16T01:33:53.219Z,1550280833.219 [AcousticModem_Benthos_ATM900](DEBUG): read user prompt 1: user:1>
2019-02-16T01:33:53.219Z,1550280833.219 [AcousticModem_Benthos_ATM900](INFO): command mode acknowledged
2019-02-16T01:33:53.610Z,1550280833.610 [AcousticModem_Benthos_ATM900](INFO): setting local address to 3
2019-02-16T01:33:54.014Z,1550280834.014 [AcousticModem_Benthos_ATM900](DEBUG): checking for local address setting acknowledgment
2019-02-16T01:33:54.015Z,1550280834.015 [AcousticModem_Benthos_ATM900](INFO): set local address to 3
2019-02-16T01:33:54.419Z,1550280834.419 [AcousticModem_Benthos_ATM900](DEBUG): read user prompt 2: user:2>
2019-02-16T01:34:06.210Z,1550280846.210 [SBIT](IMPORTANT): Beginning Startup BIT
2019-02-16T01:34:06.222Z,1550280846.222 [CBIT](IMPORTANT): Beginning ground fault scan
2019-02-16T01:34:09.899Z,1550280849.899 [NAL9602](INFO): Powering up NAL9602
2019-02-16T01:34:17.287Z,1550280857.287 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.008842
CHAN A1 (24V): -0.013162
CHAN A2 (12V): -0.004663
CHAN A3 (5V): -0.004116
CHAN B0 (3.3V): -0.001207
CHAN B1 (3.15aV): -0.001553
CHAN B2 (3.15bV): -0.000828
CHAN B3 (GND): -0.000083
OPEN: 0.004376
Full Scale Calc: 4.765 mA, -1.589 mA
2019-02-16T01:34:20.800Z,1550280860.800 [NAL9602](INFO): NAL9602 initialized
2019-02-16T01:34:21.889Z,1550280861.889 [NAL9602](DEBUG): Fix Requested
2019-02-16T01:34:25.690Z,1550280865.690 [CommandLine](IMPORTANT): got command report touch Radio_Surface.durationOfLastRun
2019-02-16T01:34:26.072Z,1550280866.072 [Reporter](INFO): Radio_Surface.durationOfLastRun 0.001157 s
2019-02-16T01:34:26.475Z,1550280866.475 [Reporter](INFO): Radio_Surface.durationOfLastRun 0.000411 s
2019-02-16T01:34:27.019Z,1550280867.019 [Reporter](INFO): Radio_Surface.durationOfLastRun 0.000193 s
2019-02-16T01:34:27.355Z,1550280867.355 [Reporter](INFO): Radio_Surface.durationOfLastRun 0.000123 s
2019-02-16T01:34:27.672Z,1550280867.672 [Reporter](INFO): Radio_Surface.durationOfLastRun 0.000400 s
2019-02-16T01:34:28.024Z,1550280868.024 [Reporter](INFO): Radio_Surface.durationOfLastRun 0.000188 s
2019-02-16T01:34:28.438Z,1550280868.438 [Reporter](INFO): Radio_Surface.durationOfLastRun 0.000128 s
2019-02-16T01:34:28.844Z,1550280868.844 [Reporter](INFO): Radio_Surface.durationOfLastRun 0.000412 s
2019-02-16T01:34:29.260Z,1550280869.260 [Reporter](INFO): Radio_Surface.durationOfLastRun 0.000190 s
2019-02-16T01:34:29.680Z,1550280869.680 [Reporter](INFO): Radio_Surface.durationOfLastRun 0.000123 s
2019-02-16T01:34:30.068Z,1550280870.068 [Reporter](INFO): Radio_Surface.durationOfLastRun 0.000398 s
2019-02-16T01:34:30.480Z,1550280870.480 [Reporter](INFO): Radio_Surface.durationOfLastRun 0.000192 s
2019-02-16T01:34:30.888Z,1550280870.888 [Reporter](INFO): Radio_Surface.durationOfLastRun 0.000122 s
2019-02-16T01:34:31.268Z,1550280871.268 [Reporter](INFO): Radio_Surface.durationOfLastRun 0.000403 s
2019-02-16T01:34:31.684Z,1550280871.684 [Reporter](INFO): Radio_Surface.durationOfLastRun 0.000193 s
2019-02-16T01:34:32.068Z,1550280872.068 [Reporter](INFO): Radio_Surface.durationOfLastRun 0.000124 s
2019-02-16T01:34:32.489Z,1550280872.489 [Reporter](INFO): Radio_Surface.durationOfLastRun 0.000399 s
2019-02-16T01:34:32.876Z,1550280872.876 [Reporter](INFO): Radio_Surface.durationOfLastRun 0.000193 s
2019-02-16T01:34:33.288Z,1550280873.288 [Reporter](INFO): Radio_Surface.durationOfLastRun 0.001152 s
2019-02-16T01:34:33.708Z,1550280873.708 [Reporter](INFO): Radio_Surface.durationOfLastRun 0.000421 s
2019-02-16T01:34:34.108Z,1550280874.108 [Reporter](INFO): Radio_Surface.durationOfLastRun 0.000191 s
2019-02-16T01:34:34.524Z,1550280874.524 [Reporter](INFO): Radio_Surface.durationOfLastRun 0.000129 s
2019-02-16T01:34:34.932Z,1550280874.932 [Reporter](INFO): Radio_Surface.durationOfLastRun 0.000148 s
2019-02-16T01:34:35.324Z,1550280875.324 [Reporter](INFO): Radio_Surface.durationOfLastRun 0.000193 s
2019-02-16T01:34:35.796Z,1550280875.796 [Reporter](INFO): Radio_Surface.durationOfLastRun 0.000125 s
2019-02-16T01:34:36.089Z,1550280876.089 [Reporter](INFO): Radio_Surface.durationOfLastRun 0.000158 s
2019-02-16T01:34:36.488Z,1550280876.488 [Reporter](INFO): Radio_Surface.durationOfLastRun 0.001208 s
2019-02-16T01:34:36.885Z,1550280876.885 [Reporter](INFO): Radio_Surface.durationOfLastRun 0.000130 s
2019-02-16T01:34:37.308Z,1550280877.308 [Reporter](INFO): Radio_Surface.durationOfLastRun 0.000606 s
2019-02-16T01:34:37.719Z,1550280877.719 [Reporter](INFO): Radio_Surface.durationOfLastRun 0.000197 s
2019-02-16T01:34:38.116Z,1550280878.116 [Reporter](INFO): Radio_Surface.durationOfLastRun 0.000120 s
2019-02-16T01:34:38.480Z,1550280878.480 [Reporter](INFO): Radio_Surface.durationOfLastRun 0.000588 s
2019-02-16T01:34:38.889Z,1550280878.889 [Reporter](INFO): Radio_Surface.durationOfLastRun 0.000263 s
2019-02-16T01:34:39.289Z,1550280879.289 [Reporter](INFO): Radio_Surface.durationOfLastRun 0.000129 s
2019-02-16T01:34:39.706Z,1550280879.706 [Reporter](INFO): Radio_Surface.durationOfLastRun 0.000582 s
2019-02-16T01:34:40.117Z,1550280880.117 [Reporter](INFO): Radio_Surface.durationOfLastRun 0.000261 s
2019-02-16T01:34:40.522Z,1550280880.522 [Reporter](INFO): Radio_Surface.durationOfLastRun 0.000116 s
2019-02-16T01:34:40.936Z,1550280880.936 [Reporter](INFO): Radio_Surface.durationOfLastRun 0.000614 s
2019-02-16T01:34:41.307Z,1550280881.307 [Reporter](INFO): Radio_Surface.durationOfLastRun 0.000252 s
2019-02-16T01:34:41.711Z,1550280881.711 [Reporter](INFO): Radio_Surface.durationOfLastRun 0.000117 s
2019-02-16T01:34:42.115Z,1550280882.115 [Reporter](INFO): Radio_Surface.durationOfLastRun 0.000390 s
2019-02-16T01:34:42.518Z,1550280882.518 [Reporter](INFO): Radio_Surface.durationOfLastRun 0.000195 s
2019-02-16T01:34:42.934Z,1550280882.934 [Reporter](INFO): Radio_Surface.durationOfLastRun 0.000120 s
2019-02-16T01:34:43.369Z,1550280883.369 [Reporter](INFO): Radio_Surface.durationOfLastRun 0.000396 s
2019-02-16T01:34:43.761Z,1550280883.761 [Reporter](INFO): Radio_Surface.durationOfLastRun 0.000256 s
2019-02-16T01:34:44.156Z,1550280884.156 [Reporter](INFO): Radio_Surface.durationOfLastRun 0.000114 s
2019-02-16T01:34:44.540Z,1550280884.540 [Reporter](INFO): Radio_Surface.durationOfLastRun 0.000384 s
2019-02-16T01:34:44.959Z,1550280884.959 [Reporter](INFO): Radio_Surface.durationOfLastRun 0.000257 s
2019-02-16T01:34:45.362Z,1550280885.362 [Reporter](INFO): Radio_Surface.durationOfLastRun 0.000118 s
2019-02-16T01:34:45.777Z,1550280885.777 [Reporter](INFO): Radio_Surface.durationOfLastRun 0.000405 s
2019-02-16T01:34:45.982Z,1550280885.982 [CommandLine](IMPORTANT): got command report clear
2019-02-16T01:34:49.482Z,1550280889.482 [BPC1](FAULT): Failed to parse data from all battery packs.
2019-02-16T01:34:49.482Z,1550280889.482 [BPC1] Data Fault, FailCount= 1
2019-02-16T01:34:49.482Z,1550280889.482 [BPC1](ERROR): Data Fault
2019-02-16T01:34:49.603Z,1550280889.603 [CBIT](ERROR): Data Fault in component: BPC1
2019-02-16T01:34:59.595Z,1550280899.595 [SBIT](IMPORTANT): SBIT PASSED
2019-02-16T01:34:59.623Z,1550280899.623 [CommandLine](IMPORTANT): got command configSet list
2019-02-16T01:34:59.623Z,1550280899.623 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2019-02-16T01:34:59.624Z,1550280899.624 [CommandLine](IMPORTANT): DropWeight.loadAtStartup=0 bool;
2019-02-16T01:34:59.971Z,1550280899.971 [MissionManager](IMPORTANT): Started mission Startup
2019-02-16T01:34:59.971Z,1550280899.971 [Startup] Running Loop=1
2019-02-16T01:34:59.972Z,1550280899.972 [Startup](DEBUG): Aggregate::initialize Startup
2019-02-16T01:34:59.972Z,1550280899.972 [Startup:A.GoToSurface] Running Loop=1
2019-02-16T01:34:59.972Z,1550280899.972 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-02-16T01:34:59.972Z,1550280899.972 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-02-16T01:34:59.973Z,1550280899.973 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-02-16T01:34:59.973Z,1550280899.973 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-02-16T01:34:59.990Z,1550280899.990 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-02-16T01:34:59.990Z,1550280899.990 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-02-16T01:35:00.000Z,1550280900.000 [Startup:StartupSatComms] Running Loop=1
2019-02-16T01:35:00.000Z,1550280900.000 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2019-02-16T01:35:00.000Z,1550280900.000 [Startup:StartupSatComms:A] Running Loop=1
2019-02-16T01:35:00.410Z,1550280900.410 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2019-02-16T01:35:42.641Z,1550280942.641 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2019-02-16T01:35:42.641Z,1550280942.641 [Rowe_600LCM] Communications Fault, FailCount= 1
2019-02-16T01:35:42.641Z,1550280942.641 [Rowe_600LCM](ERROR): Communications Fault
2019-02-16T01:35:42.814Z,1550280942.814 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2019-02-16T01:35:43.045Z,1550280943.045 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2019-02-16T01:35:43.140Z,1550280943.140 [Rowe_600LCM](INFO): Powering down
2019-02-16T01:35:44.417Z,1550280944.417 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2019-02-16T01:35:44.417Z,1550280944.417 [Rowe_600LCM] No Fault, FailCount= 1
2019-02-16T01:35:44.757Z,1550280944.757 [Rowe_600LCM](INFO): Initializing
2019-02-16T01:35:44.758Z,1550280944.758 [Rowe_600LCM](INFO): Powering up
2019-02-16T01:35:48.970Z,1550280948.970 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2019-02-16T01:35:49.068Z,1550280949.068 [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-16T01:36:00.181Z,1550280960.181 [Startup:StartupSatComms:A](INFO): Timed out from 2019-02-16T01:35:00.0Z
2019-02-16T01:36:00.181Z,1550280960.181 [Startup:StartupSatComms:A] Stopped
2019-02-16T01:36:00.181Z,1550280960.181 [Startup:StartupSatComms:B] Running Loop=1
2019-02-16T01:36:00.566Z,1550280960.566 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-02-16T01:36:42.201Z,1550281002.201 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2019-02-16T01:36:42.201Z,1550281002.201 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-02-16T01:36:42.202Z,1550281002.202 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 1
2019-02-16T01:36:42.202Z,1550281002.202 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2019-02-16T01:36:42.203Z,1550281002.203 [DeadReckonWithRespectToSeafloor] Software Fault, FailCount= 1
2019-02-16T01:36:42.204Z,1550281002.204 [DeadReckonWithRespectToSeafloor](ERROR): Software Fault
2019-02-16T01:36:42.220Z,1550281002.220 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-02-16T01:36:42.221Z,1550281002.221 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2019-02-16T01:36:42.221Z,1550281002.221 [CBIT](ERROR): Software Fault in component: DeadReckonWithRespectToSeafloor
2019-02-16T01:36:42.592Z,1550281002.592 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-02-16T01:36:42.592Z,1550281002.592 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2019-02-16T01:36:42.593Z,1550281002.593 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2019-02-16T01:36:42.593Z,1550281002.593 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 1
2019-02-16T01:36:42.594Z,1550281002.594 [CBIT](INFO): Clearing failed state for component DeadReckonWithRespectToSeafloor
2019-02-16T01:36:42.594Z,1550281002.594 [DeadReckonWithRespectToSeafloor] No Fault, FailCount= 1
2019-02-16T01:36:42.984Z,1550281002.984 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2019-02-16T01:36:48.056Z,1550281008.056 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.005116
2019-02-16T01:36:54.245Z,1550281014.245 [DataOverHttps](INFO): Sending 142 bytes from file Logs/20190216T012955/Courier0000.lzma
2019-02-16T01:36:55.051Z,1550281015.051 [DataOverHttps](INFO): Moved sent file to Logs/20190216T012955/Courier0000.lzma.bak
2019-02-16T01:36:55.051Z,1550281015.051 [DataOverHttps](INFO): SBD MOMSN=9925105
2019-02-16T01:37:00.370Z,1550281020.370 [Startup:StartupSatComms:B](INFO): Timed out from 2019-02-16T01:36:00.2Z
2019-02-16T01:37:00.370Z,1550281020.370 [Startup:StartupSatComms:B] Stopped
2019-02-16T01:37:00.370Z,1550281020.370 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2019-02-16T01:37:00.370Z,1550281020.370 [Startup:StartupSatComms] Stopped
2019-02-16T01:37:00.371Z,1550281020.371 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2019-02-16T01:37:00.371Z,1550281020.371 [Startup](INFO): Completed Startup
2019-02-16T01:37:00.372Z,1550281020.372 [MissionManager](INFO): Startup is completed.
2019-02-16T01:37:00.372Z,1550281020.372 [MissionManager](INFO): Uninitializing Mission Startup
2019-02-16T01:37:00.372Z,1550281020.372 [Startup] Stopped
2019-02-16T01:37:00.372Z,1550281020.372 [Startup](DEBUG): Aggregate::uninitialize Startup
2019-02-16T01:37:00.372Z,1550281020.372 [Startup:A.GoToSurface] Stopped
2019-02-16T01:37:00.372Z,1550281020.372 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-02-16T01:37:00.798Z,1550281020.798 [MissionManager](IMPORTANT): Started mission Default
2019-02-16T01:37:00.798Z,1550281020.798 [Default] Running Loop=1
2019-02-16T01:37:00.798Z,1550281020.798 [Default](DEBUG): Aggregate::initialize Default
2019-02-16T01:37:00.798Z,1550281020.798 [Default:B.GoToSurface] Running Loop=1
2019-02-16T01:37:00.798Z,1550281020.798 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-02-16T01:37:00.799Z,1550281020.799 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-02-16T01:37:00.799Z,1550281020.799 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-02-16T01:37:00.799Z,1550281020.799 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-02-16T01:37:00.800Z,1550281020.800 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-02-16T01:37:00.800Z,1550281020.800 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-02-16T01:37:00.800Z,1550281020.800 [Default:A.Wait] Running Loop=1
2019-02-16T01:37:00.800Z,1550281020.800 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-02-16T01:37:01.218Z,1550281021.218 [CommandLine](IMPORTANT): got command quit
2019-02-16T01:37:02.225Z,1550281022.225 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2019-02-16T01:37:02.225Z,1550281022.225 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-02-16T01:37:02.241Z,1550281022.241 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye!
2019-02-16T01:37:02.241Z,1550281022.241 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-02-16T01:37:02.242Z,1550281022.242 [CommandLine](INFO): Join timeout helper Thread ID is 4057
2019-02-16T01:37:02.243Z,1550281022.243 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2019-02-16T01:37:02.243Z,1550281022.243 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-02-16T01:37:02.243Z,1550281022.243 [NavChartDb](INFO): Join timeout helper Thread ID is 4058
2019-02-16T01:37:02.614Z,1550281022.614 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2019-02-16T01:37:02.614Z,1550281022.614 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-02-16T01:37:02.625Z,1550281022.625 [ComponentRegistry](INFO): Shutting down Rowe_600LCM ThreadHandler
2019-02-16T01:37:02.626Z,1550281022.626 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2019-02-16T01:37:02.626Z,1550281022.626 [Rowe_600LCM](INFO): Join timeout helper Thread ID is 4059
2019-02-16T01:37:02.706Z,1550281022.706 [Rowe_600LCM ThreadHandler](INFO): Uninitializing protected caller thread.
2019-02-16T01:37:02.706Z,1550281022.706 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2019-02-16T01:37:02.860Z,1550281022.860 [Rowe_600LCM](INFO): Powering down
2019-02-16T01:37:02.862Z,1550281022.862 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2019-02-16T01:37:02.870Z,1550281022.870 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2019-02-16T01:37:02.870Z,1550281022.870 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-02-16T01:37:02.870Z,1550281022.870 [Radio_Surface](INFO): Join timeout helper Thread ID is 4061
2019-02-16T01:37:03.066Z,1550281023.066 [Radio_Surface](INFO): Powering down
2019-02-16T01:37:03.067Z,1550281023.067 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2019-02-16T01:37:03.067Z,1550281023.067 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-02-16T01:37:03.073Z,1550281023.073 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2019-02-16T01:37:03.074Z,1550281023.074 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-02-16T01:37:03.074Z,1550281023.074 [DataOverHttps](INFO): Join timeout helper Thread ID is 4062
2019-02-16T01:37:03.389Z,1550281023.389 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2019-02-16T01:37:03.390Z,1550281023.390 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-02-16T01:37:03.394Z,1550281023.394 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2019-02-16T01:37:03.395Z,1550281023.395 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-02-16T01:37:03.395Z,1550281023.395 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 4063
2019-02-16T01:37:03.498Z,1550281023.498 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2019-02-16T01:37:03.498Z,1550281023.498 [WetLabsBB2FL](INFO): Powering down
2019-02-16T01:37:03.499Z,1550281023.499 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-02-16T01:37:03.514Z,1550281023.514 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2019-02-16T01:37:03.514Z,1550281023.514 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2019-02-16T01:37:03.515Z,1550281023.515 [CTD_Seabird](INFO): Join timeout helper Thread ID is 4064
2019-02-16T01:37:03.658Z,1550281023.658 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2019-02-16T01:37:03.658Z,1550281023.658 [CTD_Seabird](INFO): Powering down
2019-02-16T01:37:03.669Z,1550281023.669 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2019-02-16T01:37:03.674Z,1550281023.674 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2019-02-16T01:37:03.674Z,1550281023.674 [logger ThreadHandler](INFO): Thread cancelled.
2019-02-16T01:37:03.675Z,1550281023.675 [logger](INFO): Join timeout helper Thread ID is 4065
2019-02-16T01:37:03.726Z,1550281023.726 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2019-02-16T01:37:03.726Z,1550281023.726 [logger ThreadHandler](INFO): Thread cancelled.
2019-02-16T01:37:03.734Z,1550281023.734 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2019-02-16T01:37:03.734Z,1550281023.734 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-02-16T01:37:03.734Z,1550281023.734 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2019-02-16T01:37:03.734Z,1550281023.734 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-02-16T01:37:03.735Z,1550281023.735 [controlThread](INFO): Join timeout helper Thread ID is 4066
2019-02-16T01:37:03.966Z,1550281023.966 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2019-02-16T01:37:03.966Z,1550281023.966 [controlThread](DEBUG): Uninitializing ControlThread
2019-02-16T01:37:03.966Z,1550281023.966 [Aanderaa_O2](INFO): Powering down
2019-02-16T01:37:03.969Z,1550281023.969 [AcousticModem_Benthos_ATM900](INFO): Powering down
2019-02-16T01:37:04.090Z,1550281024.090 [NAL9602](INFO): Powering down
2019-02-16T01:37:04.091Z,1550281024.091 [PNI_TCM](INFO): Powering down
2019-02-16T01:37:04.178Z,1550281024.178 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2019-02-16T01:37:04.179Z,1550281024.179 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2019-02-16T01:37:04.180Z,1550281024.180 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2019-02-16T01:37:04.180Z,1550281024.180 [MissionManager](INFO): Uninitializing Mission Default
2019-02-16T01:37:04.181Z,1550281024.181 [Default] Stopped
2019-02-16T01:37:04.181Z,1550281024.181 [Default](DEBUG): Aggregate::uninitialize Default
2019-02-16T01:37:04.181Z,1550281024.181 [Default:A.Wait] Stopped
2019-02-16T01:37:04.181Z,1550281024.181 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-02-16T01:37:04.181Z,1550281024.181 [Default:B.GoToSurface] Stopped
2019-02-16T01:37:04.181Z,1550281024.181 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-02-16T01:37:04.184Z,1550281024.184 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2019-02-16T01:37:04.184Z,1550281024.184 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2019-02-16T01:37:04.184Z,1550281024.184 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2019-02-16T01:37:04.185Z,1550281024.185 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2019-02-16T01:37:04.185Z,1550281024.185 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2019-02-16T01:37:04.185Z,1550281024.185 [BuoyancyServo](INFO): Powering down
2019-02-16T01:37:04.198Z,1550281024.198 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2019-02-16T01:37:04.198Z,1550281024.198 [ElevatorServo](INFO): Powering down
2019-02-16T01:37:04.199Z,1550281024.199 [MassServo](DEBUG): Uninitialize Mass Servo.
2019-02-16T01:37:04.199Z,1550281024.199 [MassServo](INFO): Powering down
2019-02-16T01:37:04.199Z,1550281024.199 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-02-16T01:37:04.200Z,1550281024.200 [RudderServo](INFO): Powering down
2019-02-16T01:37:04.200Z,1550281024.200 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2019-02-16T01:37:04.201Z,1550281024.201 [ThrusterServo](INFO): Powering down
2019-02-16T01:37:04.202Z,1550281024.202 [SBIT](DEBUG): Uninitialize SBIT Component.
2019-02-16T01:37:04.202Z,1550281024.202 [IBIT](DEBUG): Uninitialize IBIT Component.
2019-02-16T01:37:04.202Z,1550281024.202 [CBIT](DEBUG): Uninitialize CBIT Component.
2019-02-16T01:37:04.202Z,1550281024.202 [CBIT](DEBUG): Powering off loads.
2019-02-16T01:37:04.213Z,1550281024.213 [CBIT](DEBUG): Disabling WDT.
2019-02-16T01:37:04.225Z,1550281024.225 [CBIT](DEBUG): Opening all GF detection circuits.
2019-02-16T01:37:04.226Z,1550281024.226 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-02-16T01:37:04.274Z,1550281024.274 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-02-16T01:37:04.279Z,1550281024.279 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2019-02-16T01:37:04.361Z,1550281024.361 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2019-02-16T01:37:04.367Z,1550281024.367 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-02-16T01:37:04.372Z,1550281024.372 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-02-16T01:37:04.418Z,1550281024.418 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-02-16T01:37:04.477Z,1550281024.477 [logger ThreadHandler](INFO): Thread cancelled.