You are viewing a plain text version of this content. The canonical link for it is here.
Posted to common-dev@hadoop.apache.org by "Koji Noguchi (JIRA)" <ji...@apache.org> on 2006/11/28 01:32:21 UTC

[jira] Created: (HADOOP-751) Namenode constantly using up 100% CPU

Namenode constantly using up 100% CPU 
--------------------------------------

                 Key: HADOOP-751
                 URL: http://issues.apache.org/jira/browse/HADOOP-751
             Project: Hadoop
          Issue Type: Bug
          Components: dfs
    Affects Versions: 0.8.0
            Reporter: Koji Noguchi


Trying to figure out the exact cause, but CPU load of the namenode is constantly 100% without any file exchanges.

.log file of the namenode showing the following exception about every 20 seconds.

2006-11-27 16:02:07,199 INFO org.apache.hadoop.ipc.Server: IPC Server handler 5 on 8020 call error: java.io.IOException: java.util.NoSuchElementException
java.io.IOException: java.util.NoSuchElementException
  at java.util.TreeMap$PrivateEntryIterator.nextEntry(TreeMap.java:1029)
  at java.util.TreeMap$KeyIterator.next(TreeMap.java:1058)
  at java.util.AbstractCollection.toArray(AbstractCollection.java:176)
  at org.apache.hadoop.dfs.DatanodeDescriptor.getBlocks(DatanodeDescriptor.java:96)
  at org.apache.hadoop.dfs.FSNamesystem.processReport(FSNamesystem.java:1446)
  at org.apache.hadoop.dfs.NameNode.blockReport(NameNode.java:506)
  at sun.reflect.GeneratedMethodAccessor11.invoke(Unknown Source)
  at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
  at java.lang.reflect.Method.invoke(Method.java:585)
  at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:387)
  at org.apache.hadoop.ipc.Server$Handler.run(Server.java:518)



On some of the datanodes, .log file is showing

2006-11-27 16:03:57,542 WARN org.apache.hadoop.dfs.DataNode: org.apache.hadoop.ipc.RemoteException: java.io.IOException: java.util.NoSuchElementException
  at java.util.TreeMap$PrivateEntryIterator.nextEntry(TreeMap.java:1029)
  at java.util.TreeMap$KeyIterator.next(TreeMap.java:1058)
  at java.util.AbstractCollection.toArray(AbstractCollection.java:176)
  at org.apache.hadoop.dfs.DatanodeDescriptor.getBlocks(DatanodeDescriptor.java:96)
  at org.apache.hadoop.dfs.FSNamesystem.processReport(FSNamesystem.java:1446)
  at org.apache.hadoop.dfs.NameNode.blockReport(NameNode.java:506)
  at sun.reflect.GeneratedMethodAccessor11.invoke(Unknown Source)
  at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
  at java.lang.reflect.Method.invoke(Method.java:585)
  at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:387)
  at org.apache.hadoop.ipc.Server$Handler.run(Server.java:518)

  at org.apache.hadoop.ipc.Client$Connection.run(Client.java:248)


-- 
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators: http://issues.apache.org/jira/secure/Administrators.jspa
-
For more information on JIRA, see: http://www.atlassian.com/software/jira

        

[jira] Commented: (HADOOP-751) Namenode constantly using up 100% CPU

Posted by "Koji Noguchi (JIRA)" <ji...@apache.org>.
    [ http://issues.apache.org/jira/browse/HADOOP-751?page=comments#action_12454521 ] 
            
Koji Noguchi commented on HADOOP-751:
-------------------------------------

The error messages I initially copy&pasted are probably not directly related to this problem.
Once I increased the HADOOP_HEAPSIZE, this high CPU load problem went away.

Raghu pointed out 
"If increase of 500mb fixed the issue, wouldn't the main suspect be Java  GC?"

"attaching gdb to the pid shows jvm is handling "failed allocation" most of the time. I don't know if it is possible to check java stack for a given pid. I tried attaching multiple times and stack looks pretty much the same each time: "

#0  0xf771bea8 in instanceKlass::oop_adjust_pointers ()
   from libjvm.so
#1  0xf7937999 in PSMarkSweepDecorator::adjust_pointers ()
   from libjvm.so
#2  0xf79383af in PSOldGen::adjust_pointers () from libjvm.so
#3  0xf79370d6 in PSMarkSweep::mark_sweep_phase3 ()
   from libjvm.so
#4  0xf7936184 in PSMarkSweep::invoke_no_policy ()
   from libjvm.so
#5  0xf7940e7d in PSScavenge::invoke () from libjvm.so
#6  0xf790b40f in ParallelScavengeHeap::failed_mem_allocate ()
   from libjvm.so
#7  0xf79dfa6f in VM_ParallelGCFailedAllocation::doit ()
   from libjvm.so
#8  0xf79df466 in VM_Operation::evaluate () from libjvm.so
#9  0xf79dea77 in VMThread::evaluate_operation ()
   from libjvm.so
#10 0xf79dece5 in VMThread::loop () from libjvm.so
#11 0xf79de850 in VMThread::run () fromlibjvm.so
#12 0xf78fe338 in _start () from libjvm.so
#13 0xf7fd4341 in start_thread () from /lib/tls/libpthread.so.0
#14 0xf7f686fe in clone () from /lib/tls/libc.so.6 





> Namenode constantly using up 100% CPU
> -------------------------------------
>
>                 Key: HADOOP-751
>                 URL: http://issues.apache.org/jira/browse/HADOOP-751
>             Project: Hadoop
>          Issue Type: Bug
>          Components: dfs
>    Affects Versions: 0.8.0
>            Reporter: Koji Noguchi
>
> Trying to figure out the exact cause, but CPU load of the namenode is constantly 100% without any file exchanges.
> .log file of the namenode showing the following exception about every 20 seconds.
> 2006-11-27 16:02:07,199 INFO org.apache.hadoop.ipc.Server: IPC Server handler 5 on 8020 call error: java.io.IOException: java.util.NoSuchElementException
> java.io.IOException: java.util.NoSuchElementException
>   at java.util.TreeMap$PrivateEntryIterator.nextEntry(TreeMap.java:1029)
>   at java.util.TreeMap$KeyIterator.next(TreeMap.java:1058)
>   at java.util.AbstractCollection.toArray(AbstractCollection.java:176)
>   at org.apache.hadoop.dfs.DatanodeDescriptor.getBlocks(DatanodeDescriptor.java:96)
>   at org.apache.hadoop.dfs.FSNamesystem.processReport(FSNamesystem.java:1446)
>   at org.apache.hadoop.dfs.NameNode.blockReport(NameNode.java:506)
>   at sun.reflect.GeneratedMethodAccessor11.invoke(Unknown Source)
>   at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
>   at java.lang.reflect.Method.invoke(Method.java:585)
>   at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:387)
>   at org.apache.hadoop.ipc.Server$Handler.run(Server.java:518)
> On some of the datanodes, .log file is showing
> 2006-11-27 16:03:57,542 WARN org.apache.hadoop.dfs.DataNode: org.apache.hadoop.ipc.RemoteException: java.io.IOException: java.util.NoSuchElementException
>   at java.util.TreeMap$PrivateEntryIterator.nextEntry(TreeMap.java:1029)
>   at java.util.TreeMap$KeyIterator.next(TreeMap.java:1058)
>   at java.util.AbstractCollection.toArray(AbstractCollection.java:176)
>   at org.apache.hadoop.dfs.DatanodeDescriptor.getBlocks(DatanodeDescriptor.java:96)
>   at org.apache.hadoop.dfs.FSNamesystem.processReport(FSNamesystem.java:1446)
>   at org.apache.hadoop.dfs.NameNode.blockReport(NameNode.java:506)
>   at sun.reflect.GeneratedMethodAccessor11.invoke(Unknown Source)
>   at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
>   at java.lang.reflect.Method.invoke(Method.java:585)
>   at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:387)
>   at org.apache.hadoop.ipc.Server$Handler.run(Server.java:518)
>   at org.apache.hadoop.ipc.Client$Connection.run(Client.java:248)

-- 
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators: http://issues.apache.org/jira/secure/Administrators.jspa
-
For more information on JIRA, see: http://www.atlassian.com/software/jira

        

[jira] Resolved: (HADOOP-751) Namenode constantly using up 100% CPU

Posted by "Sameer Paranjpye (JIRA)" <ji...@apache.org>.
     [ https://issues.apache.org/jira/browse/HADOOP-751?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Sameer Paranjpye resolved HADOOP-751.
-------------------------------------

    Resolution: Invalid

Investigation revealed that the Namenode CPU usage was caused by lack of heap space. Reducing memory consumption in the Namenode is partially addressed by HADOOP-803. More improvements will follow.

> Namenode constantly using up 100% CPU
> -------------------------------------
>
>                 Key: HADOOP-751
>                 URL: https://issues.apache.org/jira/browse/HADOOP-751
>             Project: Hadoop
>          Issue Type: Bug
>          Components: dfs
>    Affects Versions: 0.8.0
>            Reporter: Koji Noguchi
>         Assigned To: Sameer Paranjpye
>
> Trying to figure out the exact cause, but CPU load of the namenode is constantly 100% without any file exchanges.
> .log file of the namenode showing the following exception about every 20 seconds.
> 2006-11-27 16:02:07,199 INFO org.apache.hadoop.ipc.Server: IPC Server handler 5 on 8020 call error: java.io.IOException: java.util.NoSuchElementException
> java.io.IOException: java.util.NoSuchElementException
>   at java.util.TreeMap$PrivateEntryIterator.nextEntry(TreeMap.java:1029)
>   at java.util.TreeMap$KeyIterator.next(TreeMap.java:1058)
>   at java.util.AbstractCollection.toArray(AbstractCollection.java:176)
>   at org.apache.hadoop.dfs.DatanodeDescriptor.getBlocks(DatanodeDescriptor.java:96)
>   at org.apache.hadoop.dfs.FSNamesystem.processReport(FSNamesystem.java:1446)
>   at org.apache.hadoop.dfs.NameNode.blockReport(NameNode.java:506)
>   at sun.reflect.GeneratedMethodAccessor11.invoke(Unknown Source)
>   at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
>   at java.lang.reflect.Method.invoke(Method.java:585)
>   at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:387)
>   at org.apache.hadoop.ipc.Server$Handler.run(Server.java:518)
> On some of the datanodes, .log file is showing
> 2006-11-27 16:03:57,542 WARN org.apache.hadoop.dfs.DataNode: org.apache.hadoop.ipc.RemoteException: java.io.IOException: java.util.NoSuchElementException
>   at java.util.TreeMap$PrivateEntryIterator.nextEntry(TreeMap.java:1029)
>   at java.util.TreeMap$KeyIterator.next(TreeMap.java:1058)
>   at java.util.AbstractCollection.toArray(AbstractCollection.java:176)
>   at org.apache.hadoop.dfs.DatanodeDescriptor.getBlocks(DatanodeDescriptor.java:96)
>   at org.apache.hadoop.dfs.FSNamesystem.processReport(FSNamesystem.java:1446)
>   at org.apache.hadoop.dfs.NameNode.blockReport(NameNode.java:506)
>   at sun.reflect.GeneratedMethodAccessor11.invoke(Unknown Source)
>   at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
>   at java.lang.reflect.Method.invoke(Method.java:585)
>   at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:387)
>   at org.apache.hadoop.ipc.Server$Handler.run(Server.java:518)
>   at org.apache.hadoop.ipc.Client$Connection.run(Client.java:248)

-- 
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.


[jira] Commented: (HADOOP-751) Namenode constantly using up 100% CPU

Posted by "dhruba borthakur (JIRA)" <ji...@apache.org>.
    [ http://issues.apache.org/jira/browse/HADOOP-751?page=comments#action_12456697 ] 
            
dhruba borthakur commented on HADOOP-751:
-----------------------------------------

For the records, the namenode been stable after applying Raghu's directio-memory leak fix.  

> Namenode constantly using up 100% CPU
> -------------------------------------
>
>                 Key: HADOOP-751
>                 URL: http://issues.apache.org/jira/browse/HADOOP-751
>             Project: Hadoop
>          Issue Type: Bug
>          Components: dfs
>    Affects Versions: 0.8.0
>            Reporter: Koji Noguchi
>
> Trying to figure out the exact cause, but CPU load of the namenode is constantly 100% without any file exchanges.
> .log file of the namenode showing the following exception about every 20 seconds.
> 2006-11-27 16:02:07,199 INFO org.apache.hadoop.ipc.Server: IPC Server handler 5 on 8020 call error: java.io.IOException: java.util.NoSuchElementException
> java.io.IOException: java.util.NoSuchElementException
>   at java.util.TreeMap$PrivateEntryIterator.nextEntry(TreeMap.java:1029)
>   at java.util.TreeMap$KeyIterator.next(TreeMap.java:1058)
>   at java.util.AbstractCollection.toArray(AbstractCollection.java:176)
>   at org.apache.hadoop.dfs.DatanodeDescriptor.getBlocks(DatanodeDescriptor.java:96)
>   at org.apache.hadoop.dfs.FSNamesystem.processReport(FSNamesystem.java:1446)
>   at org.apache.hadoop.dfs.NameNode.blockReport(NameNode.java:506)
>   at sun.reflect.GeneratedMethodAccessor11.invoke(Unknown Source)
>   at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
>   at java.lang.reflect.Method.invoke(Method.java:585)
>   at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:387)
>   at org.apache.hadoop.ipc.Server$Handler.run(Server.java:518)
> On some of the datanodes, .log file is showing
> 2006-11-27 16:03:57,542 WARN org.apache.hadoop.dfs.DataNode: org.apache.hadoop.ipc.RemoteException: java.io.IOException: java.util.NoSuchElementException
>   at java.util.TreeMap$PrivateEntryIterator.nextEntry(TreeMap.java:1029)
>   at java.util.TreeMap$KeyIterator.next(TreeMap.java:1058)
>   at java.util.AbstractCollection.toArray(AbstractCollection.java:176)
>   at org.apache.hadoop.dfs.DatanodeDescriptor.getBlocks(DatanodeDescriptor.java:96)
>   at org.apache.hadoop.dfs.FSNamesystem.processReport(FSNamesystem.java:1446)
>   at org.apache.hadoop.dfs.NameNode.blockReport(NameNode.java:506)
>   at sun.reflect.GeneratedMethodAccessor11.invoke(Unknown Source)
>   at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
>   at java.lang.reflect.Method.invoke(Method.java:585)
>   at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:387)
>   at org.apache.hadoop.ipc.Server$Handler.run(Server.java:518)
>   at org.apache.hadoop.ipc.Client$Connection.run(Client.java:248)

-- 
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators: http://issues.apache.org/jira/secure/Administrators.jspa
-
For more information on JIRA, see: http://www.atlassian.com/software/jira

        

[jira] Commented: (HADOOP-751) Namenode constantly using up 100% CPU

Posted by "Koji Noguchi (JIRA)" <ji...@apache.org>.
    [ http://issues.apache.org/jira/browse/HADOOP-751?page=comments#action_12454518 ] 
            
Koji Noguchi commented on HADOOP-751:
-------------------------------------

This high CPU load was caused by not enough heap size for the jvm.

> Namenode constantly using up 100% CPU
> -------------------------------------
>
>                 Key: HADOOP-751
>                 URL: http://issues.apache.org/jira/browse/HADOOP-751
>             Project: Hadoop
>          Issue Type: Bug
>          Components: dfs
>    Affects Versions: 0.8.0
>            Reporter: Koji Noguchi
>
> Trying to figure out the exact cause, but CPU load of the namenode is constantly 100% without any file exchanges.
> .log file of the namenode showing the following exception about every 20 seconds.
> 2006-11-27 16:02:07,199 INFO org.apache.hadoop.ipc.Server: IPC Server handler 5 on 8020 call error: java.io.IOException: java.util.NoSuchElementException
> java.io.IOException: java.util.NoSuchElementException
>   at java.util.TreeMap$PrivateEntryIterator.nextEntry(TreeMap.java:1029)
>   at java.util.TreeMap$KeyIterator.next(TreeMap.java:1058)
>   at java.util.AbstractCollection.toArray(AbstractCollection.java:176)
>   at org.apache.hadoop.dfs.DatanodeDescriptor.getBlocks(DatanodeDescriptor.java:96)
>   at org.apache.hadoop.dfs.FSNamesystem.processReport(FSNamesystem.java:1446)
>   at org.apache.hadoop.dfs.NameNode.blockReport(NameNode.java:506)
>   at sun.reflect.GeneratedMethodAccessor11.invoke(Unknown Source)
>   at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
>   at java.lang.reflect.Method.invoke(Method.java:585)
>   at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:387)
>   at org.apache.hadoop.ipc.Server$Handler.run(Server.java:518)
> On some of the datanodes, .log file is showing
> 2006-11-27 16:03:57,542 WARN org.apache.hadoop.dfs.DataNode: org.apache.hadoop.ipc.RemoteException: java.io.IOException: java.util.NoSuchElementException
>   at java.util.TreeMap$PrivateEntryIterator.nextEntry(TreeMap.java:1029)
>   at java.util.TreeMap$KeyIterator.next(TreeMap.java:1058)
>   at java.util.AbstractCollection.toArray(AbstractCollection.java:176)
>   at org.apache.hadoop.dfs.DatanodeDescriptor.getBlocks(DatanodeDescriptor.java:96)
>   at org.apache.hadoop.dfs.FSNamesystem.processReport(FSNamesystem.java:1446)
>   at org.apache.hadoop.dfs.NameNode.blockReport(NameNode.java:506)
>   at sun.reflect.GeneratedMethodAccessor11.invoke(Unknown Source)
>   at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
>   at java.lang.reflect.Method.invoke(Method.java:585)
>   at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:387)
>   at org.apache.hadoop.ipc.Server$Handler.run(Server.java:518)
>   at org.apache.hadoop.ipc.Client$Connection.run(Client.java:248)

-- 
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators: http://issues.apache.org/jira/secure/Administrators.jspa
-
For more information on JIRA, see: http://www.atlassian.com/software/jira