Jetty
  1. Jetty
  2. JETTY-1342

Acceptor is dead with lot's of Broken pipe exceptions in error log

    Details

    • Type: Bug Bug
    • Status: Resolved Resolved
    • Priority: Major Major
    • Resolution: Fixed
    • Affects Version/s: 6.1.22, 6.1.25
    • Fix Version/s: 6.1.27
    • Component/s: NIO
    • Labels:
      None
    • Environment:
      Linux 2.6.26-2-amd64 #1 SMP Thu Nov 25 04:30:55 UTC 2010 x86_64 GNU/Linux, Debian-5, 4 core CPU in KVM
    • Number of attachments :
      0

      Description

      Jetty6 handles about 13 000 connections, 1000 reqs/per sec, 2 acceptors.

      Sometime it shows Broken pipe exception in error log. After that acceptor seems to be dead. Exception in logged many times (huge logs up to 30gb and more). The only way to remove bug is to restart jetty.

      java.io.IOException: Broken pipe
      at sun.nio.ch.EPollArrayWrapper.interrupt(Native Method)
      at sun.nio.ch.EPollArrayWrapper.interrupt(EPollArrayWrapper.java:256)
      at sun.nio.ch.EPollSelectorImpl.wakeup(EPollSelectorImpl.java:175)
      at org.mortbay.io.nio.SelectorManager$SelectSet.wakeup(SelectorManager.java:831)
      at org.mortbay.io.nio.SelectorManager$SelectSet.doSelect(SelectorManager.java:709)
      at org.mortbay.io.nio.SelectorManager.doSelect(SelectorManager.java:192)
      at org.mortbay.jetty.nio.SelectChannelConnector.accept(SelectChannelConnector.java:124)
      at org.mortbay.jetty.AbstractConnector$Acceptor.run(AbstractConnector.java:708)
      at org.mortbay.thread.QueuedThreadPool$PoolThread.run(QueuedThreadPool.java:582)

        Activity

        Michael Gorovoy made changes -
        Field Original Value New Value
        Assignee Greg Wilkins [ gregw ]
        Hide
        Greg Wilkins added a comment -

        Hi,

        could you possibly try 6.1.26, as we made some changes to the selector manager that could improve handling of closing connections (JETTY-1296, JETTY-748, JETTY-1264). While none of these are directly related to a Broken Pipe, they may improve the selectors ability to recover from such and error.

        How frequently does this happen?

        Interestingly, Glassfish/Grizzly has had a similar issue reported: http://java.net/jira/browse/GRIZZLY-813, so we may have a look at their fix to see if this is an NIO issue.

        Show
        Greg Wilkins added a comment - Hi, could you possibly try 6.1.26, as we made some changes to the selector manager that could improve handling of closing connections ( JETTY-1296 , JETTY-748 , JETTY-1264 ). While none of these are directly related to a Broken Pipe, they may improve the selectors ability to recover from such and error. How frequently does this happen? Interestingly, Glassfish/Grizzly has had a similar issue reported: http://java.net/jira/browse/GRIZZLY-813 , so we may have a look at their fix to see if this is an NIO issue.
        Hide
        Greg Wilkins added a comment -

        The Grizzly fix was simply to catch an additional IOException and the cancel the key or close the exception.

        6.1.26 has already improved the exception handling around that area, so this may be fixed.
        If you can reproduce with 6.1.26, then we should similarly be able to cancel the key and re-register.

        Show
        Greg Wilkins added a comment - The Grizzly fix was simply to catch an additional IOException and the cancel the key or close the exception. 6.1.26 has already improved the exception handling around that area, so this may be fixed. If you can reproduce with 6.1.26, then we should similarly be able to cancel the key and re-register.
        Hide
        Viktor Kuzmin added a comment -

        I'm running 6.1.26 currently. It is reproduceable. BUT it seems that bug is reproduceable only if I set acceptors to 2, can't reproduce bug with acceptors set to 4.

        Show
        Viktor Kuzmin added a comment - I'm running 6.1.26 currently. It is reproduceable. BUT it seems that bug is reproduceable only if I set acceptors to 2, can't reproduce bug with acceptors set to 4.
        Hide
        Viktor Kuzmin added a comment -

        Today bug was reproduced again with acceptors set to 4...

        Show
        Viktor Kuzmin added a comment - Today bug was reproduced again with acceptors set to 4...
        Hide
        Viktor Kuzmin added a comment -

        System Debian-5
        Kernel: 2.6.26-2-amd64
        Java: java version "1.6.0_24"
        Java(TM) SE Runtime Environment (build 1.6.0_24-b07)
        Java HotSpot(TM) 64-Bit Server VM (build 19.1-b02, mixed mode)

        Additional java opts: -Xmx6144m
        Load is (all info is in seconds):
        avg: 0,0009, min: 0,0001, max: 3,4729, count: 449395, perSec: 748,9917

        Show
        Viktor Kuzmin added a comment - System Debian-5 Kernel: 2.6.26-2-amd64 Java: java version "1.6.0_24" Java(TM) SE Runtime Environment (build 1.6.0_24-b07) Java HotSpot(TM) 64-Bit Server VM (build 19.1-b02, mixed mode) Additional java opts: -Xmx6144m Load is (all info is in seconds): avg: 0,0009, min: 0,0001, max: 3,4729, count: 449395, perSec: 748,9917
        Hide
        Viktor Kuzmin added a comment -

        Also some config options:

        <New class="org.mortbay.thread.QueuedThreadPool">
        <Set name="minThreads">10</Set>
        <Set name="maxThreads">300</Set>
        <Set name="lowThreads">20</Set>
        <Set name="SpawnOrShrinkAt">10</Set>
        </New>

        <Call name="addConnector">
        <Arg>
        <New class="org.mortbay.jetty.nio.SelectChannelConnector">
        <Set name="host"><SystemProperty name="jetty.host" /></Set>
        <Set name="port"><SystemProperty name="jetty.port" default="8080"/></Set>
        <Set name="maxIdleTime">60000</Set>
        <Set name="Acceptors">4</Set>
        <Set name="acceptQueueSize">12000</Set>
        <Set name="statsOn">false</Set>
        <Set name="confidentialPort">8443</Set>
        <Set name="lowResourcesConnections">10000</Set>
        <Set name="lowResourcesMaxIdleTime">7000</Set>
        </New>
        </Arg>
        </Call>

        Jetty works behind nginx.
        Nginx configured to accept 20 000 connections.

        Show
        Viktor Kuzmin added a comment - Also some config options: <New class="org.mortbay.thread.QueuedThreadPool"> <Set name="minThreads">10</Set> <Set name="maxThreads">300</Set> <Set name="lowThreads">20</Set> <Set name="SpawnOrShrinkAt">10</Set> </New> <Call name="addConnector"> <Arg> <New class="org.mortbay.jetty.nio.SelectChannelConnector"> <Set name="host"><SystemProperty name="jetty.host" /></Set> <Set name="port"><SystemProperty name="jetty.port" default="8080"/></Set> <Set name="maxIdleTime">60000</Set> <Set name="Acceptors">4</Set> <Set name="acceptQueueSize">12000</Set> <Set name="statsOn">false</Set> <Set name="confidentialPort">8443</Set> <Set name="lowResourcesConnections">10000</Set> <Set name="lowResourcesMaxIdleTime">7000</Set> </New> </Arg> </Call> Jetty works behind nginx. Nginx configured to accept 20 000 connections.
        Hide
        Greg Wilkins added a comment -

        I've had another report about this issue. I will try to add some explicit handling into the server for it. As it appears the selector is dead or dying, I think the solution will have to remake a new selector (as we've done for other JVM bugs). Question is, will we lose existing connections?

        Also I wonder why we've not had this reported on jetty-7?

        Show
        Greg Wilkins added a comment - I've had another report about this issue. I will try to add some explicit handling into the server for it. As it appears the selector is dead or dying, I think the solution will have to remake a new selector (as we've done for other JVM bugs). Question is, will we lose existing connections? Also I wonder why we've not had this reported on jetty-7?
        Hide
        Greg Wilkins added a comment -


        I'm looking and better handling IOException in our wakeup code, but the problem is that IOException is not actually thrown by selector.wakeup. Can you tell from the log if the exception was caught and logged by jetty, or was it printed out by the JVM library itself?

        Show
        Greg Wilkins added a comment - I'm looking and better handling IOException in our wakeup code, but the problem is that IOException is not actually thrown by selector.wakeup. Can you tell from the log if the exception was caught and logged by jetty, or was it printed out by the JVM library itself?
        Hide
        Viktor Kuzmin added a comment -

        It was caught and logged by jetty.
        Also we have migrated to jetty-7 already and it seems that there is no such problem with it... So currently will be not able to reproduce/test this bug... Jetty-7 is running for four days without problems already.

        Show
        Viktor Kuzmin added a comment - It was caught and logged by jetty. Also we have migrated to jetty-7 already and it seems that there is no such problem with it... So currently will be not able to reproduce/test this bug... Jetty-7 is running for four days without problems already.
        Hide
        Dave Meibusch added a comment - - edited

        We're seeing this under high SOAP load with Jetty 6.1.22 (embedded in our server).

        583675662 2011-03-17 16:17:43,413 [30949593@qtp-10365435-9 - Acceptor0 SelectChannelConnector@10.64.24.157:8019] WARN  org.mortbay.log  - EXCEPTION 
        java.io.IOException: Broken pipe (errno:32)
                        at sun.nio.ch.PollArrayWrapper.interrupt(Native Method)
                        at sun.nio.ch.PollArrayWrapper.interrupt(PollArrayWrapper.java:175)
                        at sun.nio.ch.PollSelectorImpl.wakeup(PollSelectorImpl.java:84)
                        at org.mortbay.io.nio.SelectorManager$SelectSet.wakeup(SelectorManager.java:681)
                        at org.mortbay.io.nio.SelectorManager$SelectSet.doSelect(SelectorManager.java:563)
                        at org.mortbay.io.nio.SelectorManager.doSelect(SelectorManager.java:189)
                        at org.mortbay.jetty.nio.SelectChannelConnector.accept(SelectChannelConnector.java:124)
                        at org.mortbay.jetty.AbstractConnector$Acceptor.run(AbstractConnector.java:706)
                        at org.mortbay.thread.QueuedThreadPool$PoolThread.run(QueuedThreadPool.java:520)
        

        This stack trace certainly looks similar to the GRIZZLY-813 issue.

        This continually occurs for an hour and then these errors start to show up as we run out of file descriptors.

        587316759 2011-03-17 17:18:24,510 [30949593@qtp-10365435-9 - Acceptor0 SelectChannelConnector@10.64.24.157:8019] WARN  org.mortbay.log  - EXCEPTION 
        java.io.IOException: Too many open files (errno:24)
                        at sun.nio.ch.ServerSocketChannelImpl.accept0(Native Method)
                        at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:145)
                        at org.mortbay.jetty.nio.SelectChannelConnector$1.acceptChannel(SelectChannelConnector.java:75)
                        at org.mortbay.io.nio.SelectorManager$SelectSet.doSelect(SelectorManager.java:540)
                        at org.mortbay.io.nio.SelectorManager.doSelect(SelectorManager.java:189)
                        at org.mortbay.jetty.nio.SelectChannelConnector.accept(SelectChannelConnector.java:124)
                        at org.mortbay.jetty.AbstractConnector$Acceptor.run(AbstractConnector.java:706)
                        at org.mortbay.thread.QueuedThreadPool$PoolThread.run(QueuedThreadPool.java:520)
        

        Java(TM) 2 Runtime Environment, Standard Edition (build 1.5.0.14-_25_jul_2008_05_19)
        Java HotSpot(TM) Server VM (build 1.5.0.14 jinteg:07.25.08-11:41 IA64, mixed mode)

        Show
        Dave Meibusch added a comment - - edited We're seeing this under high SOAP load with Jetty 6.1.22 (embedded in our server). 583675662 2011-03-17 16:17:43,413 [30949593@qtp-10365435-9 - Acceptor0 SelectChannelConnector@10.64.24.157:8019] WARN org.mortbay.log - EXCEPTION java.io.IOException: Broken pipe (errno:32) at sun.nio.ch.PollArrayWrapper.interrupt(Native Method) at sun.nio.ch.PollArrayWrapper.interrupt(PollArrayWrapper.java:175) at sun.nio.ch.PollSelectorImpl.wakeup(PollSelectorImpl.java:84) at org.mortbay.io.nio.SelectorManager$SelectSet.wakeup(SelectorManager.java:681) at org.mortbay.io.nio.SelectorManager$SelectSet.doSelect(SelectorManager.java:563) at org.mortbay.io.nio.SelectorManager.doSelect(SelectorManager.java:189) at org.mortbay.jetty.nio.SelectChannelConnector.accept(SelectChannelConnector.java:124) at org.mortbay.jetty.AbstractConnector$Acceptor.run(AbstractConnector.java:706) at org.mortbay.thread.QueuedThreadPool$PoolThread.run(QueuedThreadPool.java:520) This stack trace certainly looks similar to the GRIZZLY-813 issue. This continually occurs for an hour and then these errors start to show up as we run out of file descriptors. 587316759 2011-03-17 17:18:24,510 [30949593@qtp-10365435-9 - Acceptor0 SelectChannelConnector@10.64.24.157:8019] WARN org.mortbay.log - EXCEPTION java.io.IOException: Too many open files (errno:24) at sun.nio.ch.ServerSocketChannelImpl.accept0(Native Method) at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:145) at org.mortbay.jetty.nio.SelectChannelConnector$1.acceptChannel(SelectChannelConnector.java:75) at org.mortbay.io.nio.SelectorManager$SelectSet.doSelect(SelectorManager.java:540) at org.mortbay.io.nio.SelectorManager.doSelect(SelectorManager.java:189) at org.mortbay.jetty.nio.SelectChannelConnector.accept(SelectChannelConnector.java:124) at org.mortbay.jetty.AbstractConnector$Acceptor.run(AbstractConnector.java:706) at org.mortbay.thread.QueuedThreadPool$PoolThread.run(QueuedThreadPool.java:520) Java(TM) 2 Runtime Environment, Standard Edition (build 1.5.0.14-_25_jul_2008_05_19) Java HotSpot(TM) Server VM (build 1.5.0.14 jinteg:07.25.08-11:41 IA64, mixed mode)
        Hide
        Greg Wilkins added a comment -

        I have raised a bug on the JVM for this:

        http://bugs.sun.com/bugdatabase/view_bug.do?bug_id=7042542

        Show
        Greg Wilkins added a comment - I have raised a bug on the JVM for this: http://bugs.sun.com/bugdatabase/view_bug.do?bug_id=7042542
        Hide
        Viktor Kuzmin added a comment -

        One little note: we have migrated to jetty 7 and we have no more such issue...

        Show
        Viktor Kuzmin added a comment - One little note: we have migrated to jetty 7 and we have no more such issue...
        Hide
        Thomas Graves added a comment -

        Does anyone know if there is a fix for this that could be put into Jetty 6?

        Show
        Thomas Graves added a comment - Does anyone know if there is a fix for this that could be put into Jetty 6?
        Hide
        Greg Wilkins added a comment -

        I don't know for sure if it is a fix, but I've committed some defensive code to jetty-6 trunk. If anybody that suffers from this bug could try it out and confirm that it works, then I would do a maintenance release of jetty-6

        Show
        Greg Wilkins added a comment - I don't know for sure if it is a fix, but I've committed some defensive code to jetty-6 trunk. If anybody that suffers from this bug could try it out and confirm that it works, then I would do a maintenance release of jetty-6
        Hide
        Jan Bartel added a comment -

        As no-one has commented since May, I'm assuming that Greg's fixes in 6.1 trunk are OK. If this is not the case, then please reopen this issue, providing stack traces etc and we will take another look at it, hopefully before 6.1.27 goes out the door.

        Jan

        Show
        Jan Bartel added a comment - As no-one has commented since May, I'm assuming that Greg's fixes in 6.1 trunk are OK. If this is not the case, then please reopen this issue, providing stack traces etc and we will take another look at it, hopefully before 6.1.27 goes out the door. Jan
        Jan Bartel made changes -
        Status Open [ 1 ] Resolved [ 5 ]
        Fix Version/s 6.1.27 [ 17238 ]
        Resolution Fixed [ 1 ]

          People

          • Assignee:
            Greg Wilkins
            Reporter:
            Viktor Kuzmin
          • Votes:
            0 Vote for this issue
            Watchers:
            1 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved: