My Oracle Support Banner

EM 12c : Agent Consumes High CPU due to Threads Stuck in "jdbc.driver.NTFConnection.run" "NTFConnection.readFromNetwork" (Doc ID 1474263.1)

Last updated on APRIL 19, 2018

Applies to:

Enterprise Manager Base Platform - Version 12.1.0.1.0 to 12.1.0.5.0 [Release 12.1]
Information in this document applies to any platform.

Symptoms

The Enterprise Manager 12.1.0.1/2 Cloud Control Management Agent consumes high CPU.

Using the "$top" or  "$prstat"  utilities (Solaris  OS)  the high consuming processes can be identified:

$ top
load averages:  8.87,  9.12,  9.33;                    up 51+01:25:14                                                14:05:00
2574 processes: 2571 sleeping, 3 on cpu
CPU states: 78.5% idle, 12.1% user,  9.4% kernel,  0.0% iowait,  0.0% swap
Memory: 256G phys mem, 100G free mem, 99G total swap, 99G free swap

  PID USERNAME LWP PRI NICE  SIZE   RES STATE    TIME    CPU COMMAND
   13782 oracle   999  59    0 1197M 1089M sleep  236.3H  4.71% java
   19552 oracle     1  59    0 1240M 1067M sleep  102.4H    2.66% oracle

 

$ prstat
  PID USERNAME  SIZE   RSS STATE  PRI NICE      TIME  CPU PROCESS/NLWP      
  12147 oracle    397M  341M cpu37   21    0  14:34:24  17% java/110
  27545 oracle   2433M 2166M sleep   58    0   0:05:13  0.0% oracle/1
  25136 oracle   2445M 2178M sleep   11    0   0:30:49  0.0% oracle/11
  16852 oracle   2437M 2075M sleep    4    0   3:57:20  0.0% oracle/15

 

-  Checking the details of the pid associated with the java process consuming the most CPU shows the agent process:

$ ps -ef | grep 12147
   oracle 12147 12111   2   May 17 ?         915:40
  /ora01/app/oracle/product/agent12c/core/12.1.0.1.0/jdk/bin/sparcv9/java -Xmx128

  

-  From a thread dump:

"main - Thread-58" prio= 5 tid=0x6000000001791400 nid=12516lwp_id=6859193runnable [0x9fffffffb3681000..0x9fffffffb3701000]
   12491 system thread 6858768  Priority:137  0xc00000000042e910:0 in __ksleep
  +0x30 () from /usr/lib/hpux64/libc.so.1
 "main - Thread-45" prio= 5 tid=0x600000000178f800 nid=12491lwp_id=6858768runnable [0x9fffffffb6081000..0x9fffffffb6101000]
   12462 system thread 6857927  Priority:137  0xc000000000435a70:0 in _nanosleep_sys+0x30 () from /usr/lib/hpux64/libc.so.1
 "main - ContextCleaner" prio= 4 tid=0x6000000003539800 nid=12462lwp_id=6857927waiting for monitor entry [0x9fffffffb2c81000..0x9fffffffb2d01000]
   12449 system thread 6857029  Priority:137  0xc00000000042e910:0 in __ksleep
  +0x30 () from /usr/lib/hpux64/libc.so.1
 "main - Thread-29" prio= 5 tid=0x600000000178e000 nid=12449lwp_id=6857029runnable [0x9fffffffb3a81000..0x9fffffffb3b01000]
   12516 system thread 6859193  Priority:137  0xc00000000042e910:0 in __ksleep
---Type <return> to continue, or q <return> to quit---
  +0x30 () from /usr/lib/hpux64/libc.so.1

 

-  From jstack:

"Thread-29" prio=5 tid=600000000178e000 nid=12449 lwp_id=6857029 runnable [9fffffffb3b00000]
  java.lang.Thread.State: RUNNABLE
       at oracle.jdbc.driver.NTFConnection.unmarshalOneNSPacket(NTFConnection.java:313) <----------
       at oracle.jdbc.driver.NTFConnection.run(NTFConnection.java:181) <----------
  Locked ownable synchronizers:
       - None
"Thread-45" prio=5 tid=600000000178f800 nid=12491 lwp_id=6858768 runnable [9fffffffb6100000]
  java.lang.Thread.State: RUNNABLE
       at oracle.jdbc.driver.NTFConnection.unmarshalOneNSPacket(NTFConnection.java:313)  <----------
       at oracle.jdbc.driver.NTFConnection.run(NTFConnection.java:181)  <----------
  Locked ownable synchronizers:

      - None
"Thread-58" prio=5 tid=6000000001791400 nid=12516 lwp_id=6859193 runnable [9fffffffb3700000]
  java.lang.Thread.State: RUNNABLE
       at oracle.jdbc.driver.NTFConnection.unmarshalOneNSPacket(NTFConnection.java:313) <----------
       at oracle.jdbc.driver.NTFConnection.run(NTFConnection.java:181) <----------
  Locked ownable synchronizers:       - None
"Thread-74" prio=5 tid=60000000017a8000 nid=12555 lwp_id=6861250 runnable [9fffffffb2f00000]
  java.lang.Thread.State: RUNNABLE
       at oracle.jdbc.driver.NTFConnection.unmarshalOneNSPacket(NTFConnection.java:313)  <----------
       at oracle.jdbc.driver.NTFConnection.run(NTFConnection.java:181)  <---------- 

 The agent uses port 47632 for NTFConnections.

When NTFConnection handles an nmap port scanning in the port used by the NTFConnection:

        $nmap -sV -p <port used> <host>

two threads are stuck using the port even when the port scanning has finished. 

Restarting the agent stops the cpu consumption,temporarily, but the symptom will reappear when port scanning is run again.

 

More about symptoms:

EM12c Agent java thread  consuming CPU.

 

 

Top pid: 20289 >> 225.8% CPU

Thread id :25893 (nid=0x6525) >> 37.3% of CPU
Thread id :10771 (nid=0x2a13)>> 31.8% of CPU
Thread id :10814 (nid=0x2a3e) >> 27.5% of CPU

 

java stack from agent_inst/sysman/log/emagent.nohup file.

"Thread-5602" prio=10 tid=0x00002aaac41ea800 nid=0x6525 runnable [0x000000007d202000]
  java.lang.Thread.State: RUNNABLE
at sun.nio.ch.EPollSelectorImpl.updateSelectedKeys(EPollSelectorImpl.java:92)
at sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:70)
at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:69)
- locked (a sun.nio.ch.Util$2)
- locked (a java.util.Collections$UnmodifiableSet)
- locked (a sun.nio.ch.EPollSelectorImpl)
at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:80)
at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:84)
at oracle.jdbc.driver.NTFConnection.readFromNetwork(NTFConnection.java:228)
at oracle.jdbc.driver.NTFConnection.getNextNSPacket(NTFConnection.java:290)
at oracle.jdbc.driver.NTFConnection.unmarshalOneNSPacket(NTFConnection.java:318)
at oracle.jdbc.driver.NTFConnection.run(NTFConnection.java:183)
"Thread-5597" prio=10 tid=0x0000000044038000 nid=0x2a13 runnable [0x000000007b4e5000]
  java.lang.Thread.State: RUNNABLE
at java.util.HashMap.newKeyIterator(HashMap.java:840)
at java.util.HashMap$KeySet.iterator(HashMap.java:874)
at java.util.HashSet.iterator(HashSet.java:153)
at sun.nio.ch.Util$2.iterator(Util.java:284)
at oracle.jdbc.driver.NTFConnection.readFromNetwork(NTFConnection.java:237)
at oracle.jdbc.driver.NTFConnection.getNextNSPacket(NTFConnection.java:290)
at oracle.jdbc.driver.NTFConnection.unmarshalOneNSPacket(NTFConnection.java:318)
at oracle.jdbc.driver.NTFConnection.run(NTFConnection.java:183)
"Thread-5598" prio=10 tid=0x00000000444de000 nid=0x2a3e runnable [0x000000007c5f6000]
  java.lang.Thread.State: RUNNABLE
at java.nio.HeapByteBuffer.slice(HeapByteBuffer.java:80)
at oracle.jdbc.driver.NTFConnection.getNextNSPacket(NTFConnection.java:299)
at oracle.jdbc.driver.NTFConnection.unmarshalOneNSPacket(NTFConnection.java:318)
at oracle.jdbc.driver.NTFConnection.run(NTFConnection.java:183)

 

Changes

 

Cause

To view full details, sign in with your My Oracle Support account.

Don't have a My Oracle Support account? Click to get started!


In this Document
Symptoms
Changes
Cause
Solution
 For customers having subscribed to the Oracle Database Extended Support
 For customer not allowed to download the patch 16479818/18502187 /10203435
References


My Oracle Support provides customers with access to over a million knowledge articles and a vibrant support community of peers and Oracle experts.