Uploaded image for project: 'JDK'
  1. JDK
  2. JDK-8320566

Delay in select call on sockets

XMLWordPrintable

      Submitter reports that NIOSocketMuxer is used and it is fully java based and depends on JDK implementation of socket related classes and artifacts. Once WLS debug flags were enabled, it is noticed in WLS logs that though WLS is waiting for data on particular connection, sometimes it gets delayed as much as 25 seconds or so (as compared to arrival of request packet and ack sent at TCP layer).

      JFR logs received.

      Reviewed thread dumps and pointed out to many non-WLS threads making select calls in parallel with 3 socket-reader Muxer threads of WLS. All those threads (100+ "I/O dispatcher threads") making select calls are related to Elastic Search used by CRM team. CRM team needs to check why so many I/O dispatcher threads are making select calls simultaneously and how to reduce their number. Also, by doing so, whether the original issue is getting resolved or not.

      From thread dump:

      "I/O dispatcher 9" #365 prio=5 os_prio=0 cpu=709.11ms elapsed=31886.70s tid=0x00007f66a3749f00 nid=0x1f40 runnable [0x00007f660dafc000]
         java.lang.Thread.State: RUNNABLE
          at sun.nio.ch.EPollArrayWrapper.epollWait(java.base/Native Method)
          at sun.nio.ch.EPollArrayWrapper.poll(java.base/EPollArrayWrapper.java:269)
          at sun.nio.ch.EPollSelectorImpl.doSelect(java.base/EPollSelectorImpl.java:93)
          at sun.nio.ch.SelectorImpl.lockAndDoSelect(java.base/SelectorImpl.java:86)
          - locked <0x00000004dedc34c8> (a sun.nio.ch.Util$3)
          - locked <0x00000004dedc34b8> (a java.util.Collections$UnmodifiableSet)
          - locked <0x00000004dedc3380> (a sun.nio.ch.EPollSelectorImpl)
          at sun.nio.ch.SelectorImpl.select(java.base/SelectorImpl.java:97)
          at com.oracle.es.apache.http.impl.nio.reactor.AbstractIOReactor.execute(java.base/AbstractIOReactor.java:255)
          at com.oracle.es.apache.http.impl.nio.reactor.BaseIOReactor.execute(java.base/BaseIOReactor.java:104)
          at com.oracle.es.apache.http.impl.nio.reactor.AbstractMultiworkerIOReactor$Worker.run(java.base/AbstractMultiworkerIOReactor.java:591)
          at java.lang.Thread.run(java.base/Thread.java:755)

      From a heap dump:
      Class Name | Shallow Heap | Retained Heap
      ----------------------------------------------------------------------------------------------------------------------------------------------
      com.oracle.es.apache.http.impl.nio.reactor.AbstractMultiworkerIOReactor$Worker @ 0x58a6df2c0 | 24 | 24
      |- [0] com.oracle.es.apache.http.impl.nio.reactor.AbstractMultiworkerIOReactor$Worker[28] @ 0x58a6defb8 | 128 | 128
      | '- workers com.oracle.es.apache.http.impl.nio.reactor.DefaultConnectingIOReactor @ 0x58a4ee610 | 88 | 656
      | |- ioReactor com.oracle.es.apache.http.impl.nio.conn.PoolingNHttpClientConnectionManager @ 0x58a4ee5e0 | 32 | 1,808
      | |- ioReactor com.oracle.es.apache.http.impl.nio.conn.CPool @ 0x58a718198 | 88 | 1,448
      | | |- pool com.oracle.es.apache.http.impl.nio.conn.PoolingNHttpClientConnectionManager @ 0x58a4ee5e0 | 32 | 1,808
      | | | |- connmgr, connmgr com.oracle.es.apache.http.impl.nio.client.InternalHttpAsyncClient @ 0x58a4ee588| 72 | 4,960
      | | | | |- client com.oracle.es.elasticsearch.client.RestClient @ 0x58a4ee550 | 56 | 832
      | | | | | '- client oracle.apps.crmCommon.elasticSearch.rest.client.facade.ClientImpl @ 0x58a4ee508 | 72 | 944
      | | | | | '- val java.util.concurrent.ConcurrentHashMap$Node @ 0x58a4ee4e8 | 32 | 976
      ----------------------------------------------------------------------------------------------------------------------------------------------


            coffeys Sean Coffey
            shadowbug Shadow Bug
            Votes:
            0 Vote for this issue
            Watchers:
            3 Start watching this issue

              Created:
              Updated:
              Resolved: