hadoop-common-user mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Todd Lipcon <t...@cloudera.com>
Subject Re: Error register getProtocolVersion
Date Wed, 14 Oct 2009 17:22:14 GMT
Hi Tim,

I have also seen this error, but it's not fatal.

Is this log from just the NameNode or did you tail multiple logs? It
seems odd that your namenode would be trying to make an IPC client to
itself (port 8020).

After you see these messages, does your namenode shut down? Does jps
show it running? Is the web interface available at port 50070?

-Todd


On Wed, Oct 14, 2009 at 2:33 AM, tim robertson
<timrobertson100@gmail.com> wrote:
> Hi all,
>
> Using hadoop 0.20.1 I am seeing the following on my namenode startup.
>
> 2009-10-14 11:09:54,232 INFO org.apache.hadoop.ipc.Server: Error
> register getProtocolVersion
> java.lang.IllegalArgumentException: Duplicate metricsName:getProtocolVersion
>
> Could someone please point me in the right direction for diagnosing
> where I have gone wrong?
>
> Thanks
> Tim
>
>
>
> /************************************************************
> STARTUP_MSG: Starting NameNode
> STARTUP_MSG:   host = cluma.gbif.org/192.38.28.77
> STARTUP_MSG:   args = []
> STARTUP_MSG:   version = 0.20.1
> STARTUP_MSG:   build =
> http://svn.apache.org/repos/asf/hadoop/common/tags/release-0.20.1-rc1
> -r 810220; compiled by 'oom' on Tue Sep  1 20:55:56 UTC 2009
> ************************************************************/
> 2009-10-14 11:09:53,010 INFO org.apache.hadoop.ipc.metrics.RpcMetrics:
> Initializing RPC Metrics with hostName=NameNode, port=8020
> 2009-10-14 11:09:53,013 INFO
> org.apache.hadoop.hdfs.server.namenode.NameNode: Namenode up at:
> cluma.gbif.clu/192.168.76.254:8020
> 2009-10-14 11:09:53,015 INFO org.apache.hadoop.metrics.jvm.JvmMetrics:
> Initializing JVM Metrics with processName=NameNode, sessionId=null
> 2009-10-14 11:09:53,019 INFO
> org.apache.hadoop.hdfs.server.namenode.metrics.NameNodeMetrics:
> Initializing NameNodeMeterics using context
> object:org.apache.hadoop.metrics.spi.NullContext
> 2009-10-14 11:09:53,056 INFO
> org.apache.hadoop.hdfs.server.namenode.FSNamesystem:
> fsOwner=root,root,bin,daemon,sys,adm,disk,wheel
> 2009-10-14 11:09:53,057 INFO
> org.apache.hadoop.hdfs.server.namenode.FSNamesystem:
> supergroup=supergroup
> 2009-10-14 11:09:53,057 INFO
> org.apache.hadoop.hdfs.server.namenode.FSNamesystem:
> isPermissionEnabled=true
> 2009-10-14 11:09:53,064 INFO
> org.apache.hadoop.hdfs.server.namenode.metrics.FSNamesystemMetrics:
> Initializing FSNamesystemMetrics using context
> object:org.apache.hadoop.metrics.spi.NullContext
> 2009-10-14 11:09:53,065 INFO
> org.apache.hadoop.hdfs.server.namenode.FSNamesystem: Registered
> FSNamesystemStatusMBean
> 2009-10-14 11:09:53,090 INFO
> org.apache.hadoop.hdfs.server.common.Storage: Number of files = 1
> 2009-10-14 11:09:53,094 INFO
> org.apache.hadoop.hdfs.server.common.Storage: Number of files under
> construction = 0
> 2009-10-14 11:09:53,094 INFO
> org.apache.hadoop.hdfs.server.common.Storage: Image file of size 94
> loaded in 0 seconds.
> 2009-10-14 11:09:53,094 INFO
> org.apache.hadoop.hdfs.server.common.Storage: Edits file
> /hadoop/name/current/edits of size 4 edits # 0 loaded in 0 seconds.
> 2009-10-14 11:09:53,098 INFO
> org.apache.hadoop.hdfs.server.common.Storage: Image file of size 94
> saved in 0 seconds.
> 2009-10-14 11:09:53,113 INFO
> org.apache.hadoop.hdfs.server.namenode.FSNamesystem: Finished loading
> FSImage in 72 msecs
> 2009-10-14 11:09:53,114 INFO
> org.apache.hadoop.hdfs.server.namenode.FSNamesystem: Total number of
> blocks = 0
> 2009-10-14 11:09:53,114 INFO
> org.apache.hadoop.hdfs.server.namenode.FSNamesystem: Number of invalid
> blocks = 0
> 2009-10-14 11:09:53,114 INFO
> org.apache.hadoop.hdfs.server.namenode.FSNamesystem: Number of
> under-replicated blocks = 0
> 2009-10-14 11:09:53,114 INFO
> org.apache.hadoop.hdfs.server.namenode.FSNamesystem: Number of
> over-replicated blocks = 0
> 2009-10-14 11:09:53,114 INFO org.apache.hadoop.hdfs.StateChange:
> STATE* Leaving safe mode after 0 secs.
> 2009-10-14 11:09:53,114 INFO org.apache.hadoop.hdfs.StateChange:
> STATE* Network topology has 0 racks and 0 datanodes
> 2009-10-14 11:09:53,114 INFO org.apache.hadoop.hdfs.StateChange:
> STATE* UnderReplicatedBlocks has 0 blocks
> 2009-10-14 11:09:53,198 INFO org.mortbay.log: Logging to
> org.slf4j.impl.Log4jLoggerAdapter(org.mortbay.log) via
> org.mortbay.log.Slf4jLog
> 2009-10-14 11:09:53,242 INFO org.apache.hadoop.http.HttpServer: Port
> returned by webServer.getConnectors()[0].getLocalPort() before open()
> is -1. Opening the listener on 50070
> 2009-10-14 11:09:53,243 INFO org.apache.hadoop.http.HttpServer:
> listener.getLocalPort() returned 50070
> webServer.getConnectors()[0].getLocalPort() returned 50070
> 2009-10-14 11:09:53,243 INFO org.apache.hadoop.http.HttpServer: Jetty
> bound to port 50070
> 2009-10-14 11:09:53,243 INFO org.mortbay.log: jetty-6.1.14
> 2009-10-14 11:09:53,433 INFO org.mortbay.log: Started
> SelectChannelConnector@0.0.0.0:50070
> 2009-10-14 11:09:53,434 INFO
> org.apache.hadoop.hdfs.server.namenode.NameNode: Web-server up at:
> 0.0.0.0:50070
> 2009-10-14 11:09:53,434 INFO org.apache.hadoop.ipc.Server: IPC Server
> Responder: starting
> 2009-10-14 11:09:53,435 INFO org.apache.hadoop.ipc.Server: IPC Server
> listener on 8020: starting
> 2009-10-14 11:09:53,438 INFO org.apache.hadoop.ipc.Server: IPC Server
> handler 0 on 8020: starting
> 2009-10-14 11:09:53,438 INFO org.apache.hadoop.ipc.Server: IPC Server
> handler 1 on 8020: starting
> 2009-10-14 11:09:53,438 INFO org.apache.hadoop.ipc.Server: IPC Server
> handler 2 on 8020: starting
> 2009-10-14 11:09:53,438 INFO org.apache.hadoop.ipc.Server: IPC Server
> handler 3 on 8020: starting
> 2009-10-14 11:09:53,438 INFO org.apache.hadoop.ipc.Server: IPC Server
> handler 4 on 8020: starting
> 2009-10-14 11:09:53,439 INFO org.apache.hadoop.ipc.Server: IPC Server
> handler 6 on 8020: starting
> 2009-10-14 11:09:53,439 INFO org.apache.hadoop.ipc.Server: IPC Server
> handler 7 on 8020: starting
> 2009-10-14 11:09:53,439 INFO org.apache.hadoop.ipc.Server: IPC Server
> handler 8 on 8020: starting
> 2009-10-14 11:09:53,441 INFO org.apache.hadoop.ipc.Server: IPC Server
> handler 9 on 8020: starting
> 2009-10-14 11:09:53,444 INFO org.apache.hadoop.ipc.Server: IPC Server
> handler 5 on 8020: starting
> 2009-10-14 11:09:54,232 INFO org.apache.hadoop.ipc.Server: Error
> register getProtocolVersion
> java.lang.IllegalArgumentException: Duplicate metricsName:getProtocolVersion
>        at org.apache.hadoop.metrics.util.MetricsRegistry.add(MetricsRegistry.java:53)
>        at org.apache.hadoop.metrics.util.MetricsTimeVaryingRate.<init>(MetricsTimeVaryingRate.java:89)
>        at org.apache.hadoop.metrics.util.MetricsTimeVaryingRate.<init>(MetricsTimeVaryingRate.java:99)
>        at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:523)
>        at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:959)
>        at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:955)
>        at java.security.AccessController.doPrivileged(Native Method)
>        at javax.security.auth.Subject.doAs(Subject.java:396)
>        at org.apache.hadoop.ipc.Server$Handler.run(Server.java:953)
> 2009-10-14 11:09:54,667 INFO org.apache.hadoop.hdfs.StateChange:
> BLOCK* NameSystem.registerDatanode: node registration from
> 192.168.76.3:50010 storage
> DS-551038728-192.168.76.3-50010-1255511394664
> 2009-10-14 11:09:54,668 INFO org.apache.hadoop.net.NetworkTopology:
> Adding a new node: /default-rack/192.168.76.3:50010
> 2009-10-14 11:09:54,673 INFO org.apache.hadoop.hdfs.StateChange:
> BLOCK* NameSystem.registerDatanode: node registration from
> 192.168.76.2:50010 storage
> DS-681115827-192.168.76.2-50010-1255511394673
> 2009-10-14 11:09:54,674 INFO org.apache.hadoop.net.NetworkTopology:
> Adding a new node: /default-rack/192.168.76.2:50010
> 2009-10-14 11:09:54,689 INFO org.apache.hadoop.hdfs.StateChange:
> BLOCK* NameSystem.registerDatanode: node registration from
> 192.168.76.7:50010 storage
> DS-1731752631-192.168.76.7-50010-1255511394688
> 2009-10-14 11:09:54,689 INFO org.apache.hadoop.net.NetworkTopology:
> Adding a new node: /default-rack/192.168.76.7:50010
> 2009-10-14 11:09:54,701 INFO org.apache.hadoop.hdfs.StateChange:
> BLOCK* NameSystem.registerDatanode: node registration from
> 192.168.76.6:50010 storage
> DS-338163265-192.168.76.6-50010-1255511394698
> 2009-10-14 11:09:54,701 INFO org.apache.hadoop.net.NetworkTopology:
> Adding a new node: /default-rack/192.168.76.6:50010
> 2009-10-14 11:09:59,688 INFO org.apache.hadoop.hdfs.StateChange:
> BLOCK* NameSystem.registerDatanode: node registration from
> 192.168.76.1:50010 storage
> DS-988595128-192.168.76.1-50010-1255511399688
> 2009-10-14 11:09:59,689 INFO org.apache.hadoop.net.NetworkTopology:
> Adding a new node: /default-rack/192.168.76.1:50010
> 2009-10-14 11:10:04,277 INFO org.apache.hadoop.hdfs.StateChange:
> BLOCK* NameSystem.registerDatanode: node registration from
> 192.168.76.9:50010 storage
> DS-1096719686-192.168.76.9-50010-1255511404276
> 2009-10-14 11:10:04,278 INFO org.apache.hadoop.net.NetworkTopology:
> Adding a new node: /default-rack/192.168.76.9:50010
> 2009-10-14 11:10:04,289 INFO org.apache.hadoop.hdfs.StateChange:
> BLOCK* NameSystem.registerDatanode: node registration from
> 192.168.76.5:50010 storage
> DS-1405051412-192.168.76.5-50010-1255511404288
> 2009-10-14 11:10:04,289 INFO org.apache.hadoop.net.NetworkTopology:
> Adding a new node: /default-rack/192.168.76.5:50010
> 2009-10-14 11:10:05,961 INFO org.apache.hadoop.hdfs.StateChange:
> BLOCK* NameSystem.registerDatanode: node registration from
> 192.168.76.8:50010 storage
> DS-1138617755-192.168.76.8-50010-1255511405960
> 2009-10-14 11:10:05,961 INFO org.apache.hadoop.net.NetworkTopology:
> Adding a new node: /default-rack/192.168.76.8:50010
> 2009-10-14 11:10:06,154 INFO org.apache.hadoop.hdfs.StateChange:
> BLOCK* NameSystem.registerDatanode: node registration from
> 192.168.76.4:50010 storage
> DS-569548170-192.168.76.4-50010-1255511406153
> 2009-10-14 11:10:06,154 INFO org.apache.hadoop.net.NetworkTopology:
> Adding a new node: /default-rack/192.168.76.4:50010
> 2009-10-14 11:10:14,480 INFO org.apache.hadoop.ipc.Client: Retrying
> connect to server: cluma.gbif.clu/192.168.76.254:8020. Already tried 0
> time(s).
> 2009-10-14 11:10:35,483 INFO org.apache.hadoop.ipc.Client: Retrying
> connect to server: cluma.gbif.clu/192.168.76.254:8020. Already tried 1
> time(s).
> 2009-10-14 11:10:56,486 INFO org.apache.hadoop.ipc.Client: Retrying
> connect to server: cluma.gbif.clu/192.168.76.254:8020. Already tried 2
> time(s).
> 2009-10-14 11:11:17,489 INFO org.apache.hadoop.ipc.Client: Retrying
> connect to server: cluma.gbif.clu/192.168.76.254:8020. Already tried 3
> time(s).
> 2009-10-14 11:11:38,492 INFO org.apache.hadoop.ipc.Client: Retrying
> connect to server: cluma.gbif.clu/192.168.76.254:8020. Already tried 4
> time(s).
> 2009-10-14 11:11:59,495 INFO org.apache.hadoop.ipc.Client: Retrying
> connect to server: cluma.gbif.clu/192.168.76.254:8020. Already tried 5
> time(s).
> 2009-10-14 11:12:20,498 INFO org.apache.hadoop.ipc.Client: Retrying
> connect to server: cluma.gbif.clu/192.168.76.254:8020. Already tried 6
> time(s).
> 2009-10-14 11:12:41,501 INFO org.apache.hadoop.ipc.Client: Retrying
> connect to server: cluma.gbif.clu/192.168.76.254:8020. Already tried 7
> time(s).
> 2009-10-14 11:13:02,504 INFO org.apache.hadoop.ipc.Client: Retrying
> connect to server: cluma.gbif.clu/192.168.76.254:8020. Already tried 8
> time(s).
> 2009-10-14 11:13:23,506 INFO org.apache.hadoop.ipc.Client: Retrying
> connect to server: cluma.gbif.clu/192.168.76.254:8020. Already tried 9
> time(s).
> etc.
>

Mime
View raw message