Tomcat fails to restart with "Address already in use" exception

[Alexey Andreev]

Hi!

Our custom java web application is running on:

Dedicated Linux server, Tomcat 5.5.23.0, JVM 1.5.0_12

Tomcat run parameters:

java -server -Xms1000m -Xmx2000m -Xmn756m -XX:MaxPermSize=128m -Djava.awt.headless=true -verbose:gc -XX:+PrintGCTimeStamps -XX:+PrintGCDetails -Xloggc:/usr/local/tomcat/logs/gc.log -XX:+UseParallelGC -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager -Djava.util.logging.config.file=/usr/local/tomcat/conf/logging.properties -Djava.endorsed.dirs=/usr/local/tomcat/common/endorsed -classpath :/usr/local/tomcat/bin/bootstrap.jar:/usr/local/tomcat/bin/commons-logging-api.jar -Dcatalina.base=/usr/local/tomcat -Dcatalina.home=/usr/local/tomcat -Djava.io.tmpdir=/usr/local/tomcat/temp org.apache.catalina.startup.Bootstrap start

Recently we started getting a strange problem while restarting the tomcat.

After running "service tomcat restart" (or stop-start it actually doesn't matter) the server fails to start and the following is written to catalina.out :

INFO: Starting Servlet Engine: Apache Tomcat/5.5.23
Jun 15, 2009 10:16:53 AM org.apache.catalina.core.AprLifecycleListener lifecycleEvent
INFO: The Apache Tomcat Native library which allows optimal performance in production environments was not found on the java.library.path: /usr/java/jdk1.5.0_12/jre/lib/i386/server:/usr/java/jdk1.5.0_12/jre/lib/i386:/usr/java/jdk1.5.0_12/jre/../lib/i386
Jun 15, 2009 10:16:53 AM org.apache.catalina.core.StandardHost start
INFO: XML validation disabled
Jun 15, 2009 10:16:53 AM org.apache.coyote.http11.Http11BaseProtocol init
SEVERE: Error initializing endpoint
java.net.BindException: Address already in use:8080
        at org.apache.tomcat.util.net.PoolTcpEndpoint.initEndpoint(PoolTcpEndpoint.java:298)
        at org.apache.coyote.http11.Http11BaseProtocol.init(Http11BaseProtocol.java:139)
        at org.apache.catalina.connector.Connector.initialize(Connector.java:1017)
        at org.apache.catalina.core.StandardService.initialize(StandardService.java:578)
        at org.apache.catalina.core.StandardServer.initialize(StandardServer.java:782)
        at org.apache.catalina.startup.Catalina.load(Catalina.java:504)
        at org.apache.catalina.startup.Catalina.load(Catalina.java:524)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:585)
        at org.apache.catalina.startup.Bootstrap.load(Bootstrap.java:267)
        at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:432)
Jun 15, 2009 10:16:53 AM org.apache.catalina.startup.Catalina load
SEVERE: Catalina.start
LifecycleException:  Protocol handler initialization failed: java.net.BindException: Address already in use:8080
        at org.apache.catalina.connector.Connector.initialize(Connector.java:1019)
        at org.apache.catalina.core.StandardService.initialize(StandardService.java:578)
        at org.apache.catalina.core.StandardServer.initialize(StandardServer.java:782)
        at org.apache.catalina.startup.Catalina.load(Catalina.java:504)
        at org.apache.catalina.startup.Catalina.load(Catalina.java:524)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:585)
        at org.apache.catalina.startup.Bootstrap.load(Bootstrap.java:267)
        at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:432)

No other software is running on port 8080 on the server. And I even check that there is no active connection before restart, and still get the same.
If I do the second restart of tomcat after several minutes it goes fine and quick, but if I try to do it after an hour it almost everytime fails.

Any help is appreciated.

Thank you very much in advance.

[Damayanti Samal]

sometimes it found same , just you change the port number to some other port like 7777 and check .

[William Brogden]

Exactly how are you starting and stopping Tomcat.

Exactly how are you checking the 8080 port for an existing user?

Bill

[Kees Jan Koster]

Dear Alexey,

You can check who is listening using the commands in this article: http://java-monitor.com/forum/showthread.php?t=22

Make sure you check on the right interface on a multi-homed machine. Also, there may be background processes automatically starting Tomcat servers. Finally, it is very easy for developers to make a mistake so that Tomcat will not terminate properly. Thus, after stopping Tomcat, check that is dead before starting. So don't do "restart", but "stop, check, start".

[Alexey Andreev]

Thanks for your replies.

Before restart I am stopping monitoring software which watches for tomcat process (MONIT). So it can not be started automatically.
I stop the tomcat. Check the process with "ps -ef | grep java". Check the 8080 port with "netstat -t -a -n -v | grep :8080"
Everything is clean and I do start. And get the exception in logs.

Must admit that often stop command takes a long time to complete if it can give you a clue.

I am using s standard tomcat service script for starts/stops.

here is an excerpt from it

START:

setpslist() {
        if [ ! -z "$GREPSTRING" ]; then
        pslist=`ps a --width=1000 --User "$TOMCAT_USER" -o  pid,user,command  | grep "$GREPSTRING" | grep -v PID | awk '{printf $1 " "}'`
        else
        pslist=`ps a --width=1000 --User "$TOMCAT_USER" -o  pid,user,command  | grep "$STARTGREPTEXT" | grep -v PID | awk '{printf $1 " "}'`
        fi
}
start() {
    setpslist
    if [ ! -z "$pslist" ]; then
        echo "$APPNAME already running, can't start it" >&2
        return 1
    fi
    echo -n "Starting $APPNAME: "
    if [ ! -e "$LOGFILE" -a ! -e "`dirname \"$LOGFILE\"`" ]; then
        mkdir -p `dirname "$LOGFILE"`
    fi
    for ((  i = 9 ;  i > 0;  i--  ))
    do
     if [ -e "$LOGFILE.$i" ]; then
        mv "$LOGFILE.$i" "$LOGFILE".`expr $i + 1`
     fi
    done
    if [ -e "$LOGFILE" ]; then
        mv "$LOGFILE" "$LOGFILE".1
    fi

    chown -R $TOMCAT_USER $HOMEDIR
    exec su - -p --shell=/bin/sh $TOMCAT_USER -c "cd $(dirname $INITSCRIPT); $RUNCOMMAND >\"$LOGFILE\"" 2>&1 &
    local starttime=`date +"%s"`
    while true; do
        sleep 3
        local now=`date +"%s"`
        if wget --tries=1 --timeout=1 --server-response -O - $TESTURL 2>&1 | grep -qai " HTTP/1.1 "; then
          echo "Started"
          break
        fi
        if [ $(($now - 10)) -gt $starttime ]; then
            setpslist
            if [ -z "$pslist" ]; then
                echo "Java not starting up, $APPNAME not running.  Last few lines from the startup log follow:">&2
                tail -4 $LOGFILE
                return 1
            fi
        fi
        if [ $(($now - 70)) -gt $starttime ]; then
            echo "startup taking too long, not getting a response on $TESTURL, giving up" >&2;
            return 1
        fi
        echo -n .
    done
}

STOP:

stop() {
    setpslist
    if [ -z "$pslist" ]; then
        echo "$APPNAME not running, no need to stop it"
        return 0
    fi
    echo -n $"Shutting down $APPNAME: "
    # Write thread dump before shutting down
    kill -3 $pslist
    waslistening=N
    needtokill=N
    if wget --tries=1 --timeout=1 --server-response -O - $TESTURL 2>&1 | grep -qai " HTTP/1.1 "; then
       waslistening=Y
    fi

    suoutput=`su - --shell=/bin/bash -p $TOMCAT_USER -c "$STOPCOMMAND"`
    local starttime=`date +"%s"`
    while true; do
        sleep 3
        local now=`date +"%s"`
        setpslist
        if [ -z "$pslist" ]; then
            echo "  Stopped"
            return 0
        fi
        if echo $suoutput | grep -qai Refused; then
            echo -n "  'stop' signal refused, killing $APPNAME."
            kill -SIGTERM $pslist
        elif [ $(($now - 50)) -gt $starttime ]; then
            echo -n "  graceful shutdown taking too long, terminating it.";
            kill -SIGTERM $pslist
        elif [ $(($now - 50)) -gt $starttime ]; then
            echo -n "  graceful shutdown taking too long, killing it.";
            kill -SIGKILL $pslist
        elif [ "$needtokill" = "Y" ]; then
            echo -n "  Killing. "
            kill -SIGKILL $pslist
        elif [ "$waslistening" = "Y" -a "$needtokill" = "N" ]; then
            if  ! wget --tries=1 --timeout=1 --server-response -O - $TESTURL 2>&1 | grep -qai " HTTP/1.1 " ; then
            echo -n "  Stopped listening on http, but not shutting down fully. "
            needtokill=Y
            sleep 20
            fi
        fi
        # echo -n `echo $pslist | wc -w` " "
    done
}

[Tim Holloway]

Tomcat shuts down in an orderly way. If one or more of the installed webapps isn't well-behaved, you'll have problems. One of the most common of these is webapps that run a scheduler service such as Quartz and don't shutdown the Quartz scheduler threads (in the servlet destroy() method). That will hang the Tomcat shutdown process forever - or until you forcibly terminate the JVM, since as long as even one thread is alive, the JVM cannot terminate.

Ordinarily the Tomcat shutdown process happens fairly quickly. The "Tomcat restart" process consists of a catalina stop, immediately followed by catalina start. Both of these operations are asynchronous - they don't wait for any sort of event to be posted before returning. So if shutdown takes too long, the catalina start may fail because the catalina stop is still running and hasn't yet released the server network ports.

The cure for that is to either make the webapp shut down faster, or to introduce a delay between stop and start.

[S Shehab]

Damayanti Samal wrote:sometimes it found same , just you change the port number to some other port like 7777 and check .

Right try to change the port to anything else rather 8080 and it will works fine

[Alexey Andreev]

Sherif Shehab wrote:

Damayanti Samal wrote:sometimes it found same , just you change the port number to some other port like 7777 and check .

Right try to change the port to anything else rather 8080 and it will works fine

I will be surprised if that will help, but why not to try. I changed the port to 8084. I will report the situation with restarts in the next couple of days.

[Alexey Andreev]

Nope, all the same on another port (used 8084).

I also checked quartz and it shutdowns properly.

It's all a big mystery for me.

Maybe something connected directly with Linux OS? Sockets left in TIMED_WAIT state or any tricky things?

[Tim Holloway]

Alexey Andreev wrote:

Maybe something connected directly with Linux OS? Sockets left in TIMED_WAIT state or any tricky things?

I doubt it. I've worked with Tomcat since about 2.0. When the apps are all shut down, the rest of the server quickly follows. You might try the JMX console and see if there's something still happening. Or put the whole thing under a debugger and see what threads hang around the longest.

An easy way to tell if it's Tomcat or something in an app is to remove all the webapps and see if it still holds the port too long after shutdown.