hbase-issues mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "stack (JIRA)" <j...@apache.org>
Subject [jira] [Commented] (HBASE-8629) More log edits: we log too much
Date Wed, 29 May 2013 19:14:20 GMT

    [ https://issues.apache.org/jira/browse/HBASE-8629?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13669589#comment-13669589
] 

stack commented on HBASE-8629:
------------------------------

Grepping for 'hbase.*' won't get you all of the hbase logs if we log only the last three subparts
of the class full package name.  If we go to four parts, we might as well just keep the full
class package name -- there will be little savings.  Here is sample w/ three parts of the
fully-qualified package name showing:

{code}
151 2013-05-29 11:01:31,752 DEBUG [Master:0;192.168.67.83,56593,1369850491032] hbase.executor.ExecutorService:
Starting executor service name=MASTER_OPEN_REGION-192.168.67.83,56593,1369850491032, corePoo#
152 2013-05-29 11:01:31,752 DEBUG [Master:0;192.168.67.83,56593,1369850491032] hbase.executor.ExecutorService:
Starting executor service name=MASTER_CLOSE_REGION-192.168.67.83,56593,1369850491032, corePo#
153 2013-05-29 11:01:31,752 DEBUG [Master:0;192.168.67.83,56593,1369850491032] hbase.executor.ExecutorService:
Starting executor service name=MASTER_SERVER_OPERATIONS-192.168.67.83,56593,1369850491032,
c#
154 2013-05-29 11:01:31,752 DEBUG [Master:0;192.168.67.83,56593,1369850491032] hbase.executor.ExecutorService:
Starting executor service name=MASTER_META_SERVER_OPERATIONS-192.168.67.83,56593,13698504910#
155 2013-05-29 11:01:31,752 DEBUG [Master:0;192.168.67.83,56593,1369850491032] hbase.executor.ExecutorService:
Starting executor service name=MASTER_TABLE_OPERATIONS-192.168.67.83,56593,1369850491032,
co#
156 2013-05-29 11:01:31,754 DEBUG [Master:0;192.168.67.83,56593,1369850491032] master.cleaner.CleanerChore:
initialize cleaner=org.apache.hadoop.hbase.master.cleaner.TimeToLiveLogCleaner
157 2013-05-29 11:01:31,758 DEBUG [Master:0;192.168.67.83,56593,1369850491032] master.cleaner.CleanerChore:
initialize cleaner=org.apache.hadoop.hbase.master.snapshot.SnapshotLogCleaner
158 2013-05-29 11:01:31,761 DEBUG [Master:0;192.168.67.83,56593,1369850491032] master.cleaner.CleanerChore:
initialize cleaner=org.apache.hadoop.hbase.master.cleaner.HFileLinkCleaner
159 2013-05-29 11:01:31,762 DEBUG [Master:0;192.168.67.83,56593,1369850491032] master.cleaner.CleanerChore:
initialize cleaner=org.apache.hadoop.hbase.master.snapshot.SnapshotHFileCleaner
160 2013-05-29 11:01:31,763 DEBUG [Master:0;192.168.67.83,56593,1369850491032] master.cleaner.CleanerChore:
initialize cleaner=org.apache.hadoop.hbase.master.cleaner.TimeToLiveHFileCleaner
161 2013-05-29 11:01:31,810 INFO  [Master:0;192.168.67.83,56593,1369850491032] org.mortbay.log:
Logging to org.slf4j.impl.Log4jLoggerAdapter(org.mortbay.log) via org.mortbay.log.Slf4jLog
162 2013-05-29 11:01:31,867 INFO  [Master:0;192.168.67.83,56593,1369850491032] hadoop.http.HttpServer:
Added global filtersafety (class=org.apache.hadoop.http.HttpServer$QuotingInputFilter)
163 2013-05-29 11:01:31,875 INFO  [Master:0;192.168.67.83,56593,1369850491032] hadoop.http.HttpServer:
Port returned by webServer.getConnectors()[0].getLocalPort() before open() is -1. Opening
the listen#
164 2013-05-29 11:01:31,877 INFO  [Master:0;192.168.67.83,56593,1369850491032] hadoop.http.HttpServer:
listener.getLocalPort() returned 60010 webServer.getConnectors()[0].getLocalPort() returned
60010
165 2013-05-29 11:01:31,877 INFO  [Master:0;192.168.67.83,56593,1369850491032] hadoop.http.HttpServer:
Jetty bound to port 60010
166 2013-05-29 11:01:31,877 INFO  [Master:0;192.168.67.83,56593,1369850491032] org.mortbay.log:
jetty-6.1.26
167 2013-05-29 11:01:32,203 INFO  [Master:0;192.168.67.83,56593,1369850491032] org.mortbay.log:
Started SelectChannelConnector@0.0.0.0:60010
168 2013-05-29 11:01:32,203 INFO  [Master:0;192.168.67.83,56593,1369850491032] hbase.master.ServerManager:
Waiting for region servers count to settle; currently checked in 0, slept for 0 ms, expecting
mi#
169 2013-05-29 11:01:32,228 INFO  [IPC Server handler 0 on 56593] hbase.master.ServerManager:
Registering server=192.168.67.83,56595,1369850491424
170 2013-05-29 11:01:32,234 DEBUG [RegionServer:0;192.168.67.83,56595,1369850491424] hbase.regionserver.HRegionServer:
Config from master: hbase.rootdir=file:///var/folders/bp/2z1cykc92rs6j24251cg__ph000#
171 2013-05-29 11:01:32,234 DEBUG [RegionServer:0;192.168.67.83,56595,1369850491424] hbase.regionserver.HRegionServer:
Config from master: fs.default.name=file:/
172 2013-05-29 11:01:32,234 INFO  [RegionServer:0;192.168.67.83,56595,1369850491424] hbase.regionserver.HRegionServer:
Master passed us a different hostname to use; was=192.168.67.83, but now=192.168.67.#
173 2013-05-29 11:01:32,239 DEBUG [RegionServer:0;192.168.67.83,56595,1369850491424] hbase.fs.HFileSystem:
The file system is not a DistributedFileSystem. Skipping on block location reordering
174 2013-05-29 11:01:32,240 DEBUG [RegionServer:0;192.168.67.83,56595,1369850491424] hbase.regionserver.HRegionServer:
logdir=file:/var/folders/bp/2z1cykc92rs6j24251cg__ph0000gp/T/hbase-stack/hbase/.logs#
175 2013-05-29 11:01:32,248 INFO  [RegionServer:0;192.168.67.83,56595,1369850491424] regionserver.wal.FSHLog:
WAL/HLog configuration: blocksize=32 MB, rollsize=30.4 MB, enabled=true, optionallogflushinte#
176 2013-05-29 11:01:32,254 WARN  [RegionServer:0;192.168.67.83,56595,1369850491424] hadoop.util.NativeCodeLoader:
Unable to load native-hadoop library for your platform... using builtin-java classes whe#
177 2013-05-29 11:01:32,254 INFO  [Master:0;192.168.67.83,56593,1369850491032] hbase.master.ServerManager:
Waiting for region servers count to settle; currently checked in 1, slept for 51 ms, expecting
m#
178 2013-05-29 11:01:32,259 INFO  [RegionServer:0;192.168.67.83,56595,1369850491424] regionserver.wal.FSHLog:
New WAL /var/folders/bp/2z1cykc92rs6j24251cg__ph0000gp/T/hbase-stack/hbase/.logs/192.168.67.8#
179 2013-05-29 11:01:32,259 INFO  [RegionServer:0;192.168.67.83,56595,1369850491424] regionserver.wal.FSHLog:
FileSystem's output stream doesn't support getNumCurrentReplicas; --HDFS-826 not available;
f#
180 2013-05-29 11:01:32,261 INFO  [RegionServer:0;192.168.67.83,56595,1369850491424] metrics2.impl.MetricsSourceAdapter:
MBean for source RegionServer,sub=WAL registered.
181 2013-05-29 11:01:32,267 INFO  [RegionServer:0;192.168.67.83,56595,1369850491424] metrics2.impl.MetricsSourceAdapter:
MBean for source RegionServer,sub=Server registered.
182 2013-05-29 11:01:32,267 DEBUG [RegionServer:0;192.168.67.83,56595,1369850491424] hbase.executor.ExecutorService:
Starting executor service name=RS_OPEN_REGION-192.168.67.83,56595,1369850491424, coreP#
183 2013-05-29 11:01:32,267 DEBUG [RegionServer:0;192.168.67.83,56595,1369850491424] hbase.executor.ExecutorService:
Starting executor service name=RS_OPEN_META-192.168.67.83,56595,1369850491424, corePoo#
184 2013-05-29 11:01:32,267 DEBUG [RegionServer:0;192.168.67.83,56595,1369850491424] hbase.executor.ExecutorService:
Starting executor service name=RS_CLOSE_REGION-192.168.67.83,56595,1369850491424, core#
185 2013-05-29 11:01:32,268 DEBUG [RegionServer:0;192.168.67.83,56595,1369850491424] hbase.executor.ExecutorService:
Starting executor service name=RS_CLOSE_META-192.168.67.83,56595,1369850491424, corePo#
186 2013-05-29 11:01:32,269 INFO  [RegionServer:0;192.168.67.83,56595,1369850491424] hadoop.http.HttpServer:
Added global filtersafety (class=org.apache.hadoop.http.HttpServer$QuotingInputFilter)
187 2013-05-29 11:01:32,270 INFO  [RegionServer:0;192.168.67.83,56595,1369850491424] hadoop.http.HttpServer:
Port returned by webServer.getConnectors()[0].getLocalPort() before open() is -1. Opening
the #
188 2013-05-29 11:01:32,270 INFO  [RegionServer:0;192.168.67.83,56595,1369850491424] hadoop.http.HttpServer:
listener.getLocalPort() returned 60030 webServer.getConnectors()[0].getLocalPort() returned
60#
189 2013-05-29 11:01:32,270 INFO  [RegionServer:0;192.168.67.83,56595,1369850491424] hadoop.http.HttpServer:
Jetty bound to port 60030
{code}
                
> More log edits: we log too much
> -------------------------------
>
>                 Key: HBASE-8629
>                 URL: https://issues.apache.org/jira/browse/HBASE-8629
>             Project: HBase
>          Issue Type: Umbrella
>            Reporter: stack
>         Attachments: 8629-shorter-classnames.txt
>
>
> + Our thread names are nice and descriptive and are useful particularly when running
standlone mode but it gets silly printing out full thread names when distributed on each log
(we could turn off printing thread name but can be helpful).
> + Do we have to print the fully qualified path for all files every time?  Lines get really
long and hard to read.  Ditto for region names.
> + Can we print out just the class name rather than full package qualified class name.
> For example:
> {code}
> 2013-05-25 12:21:01,912 DEBUG [RS_OPEN_REGION-sss-2.ent.cloudera.com,60020,1369507494038-2]
org.apache.hadoop.hbase.regionserver.handler.OpenRegionHandler: region transitioned to opened
in zookeeper: {NAME => 'IntegrationTestDataIngestWithChaosMonkey,c28f5c19,1369509660096.4e91d414f14a75cf367609ce9c4377c7.',
STARTKEY => 'c28f5c19', ENDKEY => 'ccccccbc', ENCODED => 4e91d414f14a75cf367609ce9c4377c7,},
server: sss-2.ent.cloudera.com,60020,1369507494038
> {code}
> Should the above just be:
> {code}
> 2013-05-25 12:21:01,912 DEBUG [RS_OPEN_REGION-sss-2.ent.cloudera.com,60020,1369507494038-2]
OpenRegionHandler: region 4e91d414f14a75cf367609ce9c4377c7 transitioned to opened
> {code}
> + Some logging is bound to freak operators.  We print out the full stack trace when we
are logging failed assignment because of connection refused.
> + Should  make sure we tell a decent story when INFO level only enabled.  At moment it
is scattershot.

--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira

Mime
View raw message