Page 1 of 2 12 LastLast
Results 1 to 10 of 13

Thread: POP3 server dies every hour

  1. #1
    Join Date
    Aug 2007
    Location
    US
    Posts
    23
    Rep Power
    8

    Default POP3 server dies every hour

    I hope someone can help me with this. At about 11am this morning, the POP3 server in Zimbra 4.5.6 started dieing about every hour. IMAP still works, along with everything else. It's just POP3 that isn't working.

    Where would I start to look to find the problem?

    We are running Zimbra 4.5.6 Open Source Edition on CentOS 4.4.

  2. #2
    Join Date
    Oct 2005
    Location
    Thatcher, AZ
    Posts
    5,606
    Rep Power
    21

    Default

    Can you post your logs?

    Specifically:
    /opt/zimbra/log/mailbox.log

  3. #3
    Join Date
    Aug 2007
    Location
    US
    Posts
    23
    Rep Power
    8

    Default

    Here is mailbox.log - I've stripped out a lot of the entries that don't pertain to the Pop3 server:
    Here are the last few entries just before it stopped working
    Code:
    2007-09-27 14:02:04,467 INFO  [Pop3Server-527] [name=debbie@bgs.cc;ip=192.168.101.36;] pop - connected
    2007-09-27 14:02:04,752 INFO  [Pop3Server-527] [name=debbie@bgs.cc;ip=192.168.101.36;] pop - quit from client
    2007-09-27 14:02:04,753 INFO  [Pop3Server-527] [name=debbie@bgs.cc;ip=192.168.101.36;] ProtocolHandler - Handler exiting normally
    2007-09-27 14:02:06,165 INFO  [Pop3Server-527] [name=debbie@bgs.cc;ip=192.168.101.36;] pop - connected
    2007-09-27 14:02:06,448 INFO  [Pop3Server-527] [name=sue@bgs.cc;ip=192.168.101.46;] pop - quit from client
    2007-09-27 14:02:06,449 INFO  [Pop3Server-527] [name=sue@bgs.cc;ip=192.168.101.46;] ProtocolHandler - Handler exiting normally
    2007-09-27 14:02:08,222 INFO  [Pop3Server-527] [name=sue@bgs.cc;ip=192.168.101.46;] pop - connected
    2007-09-27 14:02:10,251 INFO  [Pop3Server-527] [name=kim@bgs.cc;ip=68.101.92.251;] pop - quit from client
    2007-09-27 14:02:10,252 INFO  [Pop3Server-527] [name=kim@bgs.cc;ip=68.101.92.251;] ProtocolHandler - Handler exiting normally
    2007-09-27 14:02:19,129 INFO  [Pop3Server-527] [name=kim@bgs.cc;ip=68.101.92.251;] pop - connected
    2007-09-27 14:02:19,403 INFO  [Pop3Server-527] [name=jim@bgs.cc;ip=192.168.101.40;] pop - quit from client
    2007-09-27 14:02:19,403 INFO  [Pop3Server-527] [name=jim@bgs.cc;ip=192.168.101.40;] ProtocolHandler - Handler exiting normally
    2007-09-27 14:02:27,576 INFO  [Pop3Server-527] [name=jim@bgs.cc;ip=192.168.101.40;] pop - connected
    And then here is what happened when I rebooted Zimbra:

    Code:
    2007-09-27 14:29:06,699 INFO  [SIGTERM handler] [] StatsImageServlet - Servlet StatsImageServlet shutting down
    2007-09-27 14:29:06,703 INFO  [SIGTERM handler] [] soap - Servlet AdminServlet shutting down
    2007-09-27 14:29:06,704 INFO  [SIGTERM handler] [] TcpServer/7025 - LmtpServer initiating shutdown
    2007-09-27 14:29:06,704 INFO  [LmtpServer] [] TcpServer/7025 - finished accept loop
    2007-09-27 14:29:06,770 INFO  [SIGTERM handler] [] TcpServer/7025 - LmtpServer shutting down idle thread pool
    2007-09-27 14:29:06,771 INFO  [SIGTERM handler] [] TcpServer/110 - Pop3Server initiating shutdown
    2007-09-27 14:29:06,772 INFO  [Pop3Server] [] TcpServer/110 - finished accept loop
    2007-09-27 14:29:06,772 INFO  [SIGTERM handler] [] ProtocolHandler - graceful shutdown requested
    2007-09-27 14:29:06,772 INFO  [SIGTERM handler] [] TcpServer/110 - Pop3Server waiting 10 seconds for thread pool shutdown
    2007-09-27 14:29:16,784 INFO  [SIGTERM handler] [] ProtocolHandler - hard shutdown requested
    2007-09-27 14:29:16,785 INFO  [SIGTERM handler] [] TcpServer/110 - Pop3Server shutdown complete
    2007-09-27 14:29:16,785 INFO  [SIGTERM handler] [] TcpServer/995 - Pop3Server initiating shutdown
    2007-09-27 14:29:16,787 INFO  [Pop3Server-2] [ip=192.168.101.53;] ProtocolHandler - Handler exiting normally
    2007-09-27 14:29:16,789 INFO  [Pop3Server] [] TcpServer/995 - finished accept loop
    2007-09-27 14:29:16,789 INFO  [SIGTERM handler] [] ProtocolHandler - graceful shutdown requested
    2007-09-27 14:29:16,791 INFO  [Pop3Server-361] [] ProtocolHandler - Exception occurred while handling connection
    java.net.SocketException: Socket closed
        at java.net.SocketInputStream.socketRead0(Native Method)
        at java.net.SocketInputStream.read(SocketInputStream.java:129)
        at com.sun.net.ssl.internal.ssl.InputRecord.readFully(InputRecord.java:293)
        at com.sun.net.ssl.internal.ssl.InputRecord.read(InputRecord.java:331)
        at com.sun.net.ssl.internal.ssl.SSLSocketImpl.readRecord(SSLSocketImpl.java:723)
        at com.sun.net.ssl.internal.ssl.SSLSocketImpl.performInitialHandshake(SSLSocketImpl.java:1030)
        at com.sun.net.ssl.internal.ssl.SSLSocketImpl.writeRecord(SSLSocketImpl.java:622)
        at com.sun.net.ssl.internal.ssl.AppOutputStream.write(AppOutputStream.java:59)
        at java.io.BufferedOutputStream.flushBuffer(BufferedOutputStream.java:65)
        at java.io.BufferedOutputStream.flush(BufferedOutputStream.java:123)
        at com.zimbra.cs.pop3.Pop3Handler.sendLine(Pop3Handler.java:382)
        at com.zimbra.cs.pop3.Pop3Handler.sendResponse(Pop3Handler.java:371)
        at com.zimbra.cs.pop3.Pop3Handler.sendOK(Pop3Handler.java:354)
        at com.zimbra.cs.pop3.Pop3Handler.setupConnection(Pop3Handler.java:115)
        at com.zimbra.cs.tcpserver.ProtocolHandler.run(ProtocolHandler.java:196)
        at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(Unknown Source)
        at java.lang.Thread.run(Thread.java:595)
    2007-09-27 14:29:16,793 INFO  [SIGTERM handler] [] ProtocolHandler - graceful shutdown requested
    2007-09-27 14:29:16,795 INFO  [Pop3Server-378] [] ProtocolHandler - Exception occurred while handling connection
    java.net.SocketException: Socket closed
        at java.net.SocketInputStream.socketRead0(Native Method)
        at java.net.SocketInputStream.read(SocketInputStream.java:129)
        at com.sun.net.ssl.internal.ssl.InputRecord.readFully(InputRecord.java:293)
        at com.sun.net.ssl.internal.ssl.InputRecord.read(InputRecord.java:331)
        at com.sun.net.ssl.internal.ssl.SSLSocketImpl.readRecord(SSLSocketImpl.java:723)
        at com.sun.net.ssl.internal.ssl.SSLSocketImpl.performInitialHandshake(SSLSocketImpl.java:1030)
        at com.sun.net.ssl.internal.ssl.SSLSocketImpl.writeRecord(SSLSocketImpl.java:622)
        at com.sun.net.ssl.internal.ssl.AppOutputStream.write(AppOutputStream.java:59)
        at java.io.BufferedOutputStream.flushBuffer(BufferedOutputStream.java:65)
        at java.io.BufferedOutputStream.flush(BufferedOutputStream.java:123)
        at com.zimbra.cs.pop3.Pop3Handler.sendLine(Pop3Handler.java:382)
        at com.zimbra.cs.pop3.Pop3Handler.sendResponse(Pop3Handler.java:371)
        at com.zimbra.cs.pop3.Pop3Handler.sendOK(Pop3Handler.java:354)
        at com.zimbra.cs.pop3.Pop3Handler.setupConnection(Pop3Handler.java:115)
        at com.zimbra.cs.tcpserver.ProtocolHandler.run(ProtocolHandler.java:196)
        at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(Unknown Source)
        at java.lang.Thread.run(Thread.java:595)
    That SocketException error repeats several times followed by this:

    Code:
    2007-09-27 14:29:16,832 INFO  [SIGTERM handler] [] ProtocolHandler - graceful shutdown requested
    2007-09-27 14:29:16,833 INFO  [Pop3Server-527] [name=jim@bgs.cc;ip=192.168.101.40;] ProtocolHandler - Exception occurred while handling connection
    java.net.SocketException: Socket closed
        at java.net.SocketInputStream.socketRead0(Native Method)
        at java.net.SocketInputStream.read(SocketInputStream.java:129)
        at com.sun.net.ssl.internal.ssl.InputRecord.readFully(InputRecord.java:293)
        at com.sun.net.ssl.internal.ssl.InputRecord.read(InputRecord.java:331)
        at com.sun.net.ssl.internal.ssl.SSLSocketImpl.readRecord(SSLSocketImpl.java:723)
        at com.sun.net.ssl.internal.ssl.SSLSocketImpl.performInitialHandshake(SSLSocketImpl.java:1030)
        at com.sun.net.ssl.internal.ssl.SSLSocketImpl.writeRecord(SSLSocketImpl.java:622)
        at com.sun.net.ssl.internal.ssl.AppOutputStream.write(AppOutputStream.java:59)
        at java.io.BufferedOutputStream.flushBuffer(BufferedOutputStream.java:65)
        at java.io.BufferedOutputStream.flush(BufferedOutputStream.java:123)
        at com.zimbra.cs.pop3.Pop3Handler.sendLine(Pop3Handler.java:382)
        at com.zimbra.cs.pop3.Pop3Handler.sendResponse(Pop3Handler.java:371)
        at com.zimbra.cs.pop3.Pop3Handler.sendOK(Pop3Handler.java:354)
        at com.zimbra.cs.pop3.Pop3Handler.setupConnection(Pop3Handler.java:115)
        at com.zimbra.cs.tcpserver.ProtocolHandler.run(ProtocolHandler.java:196)
        at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(Unknown Source)
        at java.lang.Thread.run(Thread.java:595)
    2007-09-27 14:29:16,834 INFO  [SIGTERM handler] [] TcpServer/995 - Pop3Server waiting 10 seconds for thread pool shutdown
    2007-09-27 14:29:16,834 INFO  [Pop3Server-413] [] ProtocolHandler - Handler exiting normally
    2007-09-27 14:29:16,834 INFO  [Pop3Server-476] [] ProtocolHandler - Handler exiting normally
    2007-09-27 14:29:16,835 INFO  [Pop3Server-522] [] ProtocolHandler - Handler exiting normally
    2007-09-27 14:29:16,835 INFO  [Pop3Server-523] [name=kim@bgs.cc;ip=68.101.92.251;] ProtocolHandler - Handler exiting normally
    2007-09-27 14:29:16,835 INFO  [Pop3Server-525] [name=sue@bgs.cc;ip=192.168.101.46;] ProtocolHandler - Handler exiting normally
    2007-09-27 14:29:16,836 INFO  [Pop3Server-524] [name=jessica@bgs.cc;ip=192.168.101.37;] ProtocolHandler - Handler exiting normally
    2007-09-27 14:29:16,836 INFO  [Pop3Server-526] [name=dave@bgs.cc;ip=70.121.191.0;] ProtocolHandler - Handler exiting normally
    2007-09-27 14:29:16,836 INFO  [Pop3Server-520] [] ProtocolHandler - Handler exiting normally
    2007-09-27 14:29:16,837 INFO  [Pop3Server-504] [] ProtocolHandler - Handler exiting normally
    2007-09-27 14:29:16,837 INFO  [Pop3Server-498] [] ProtocolHandler - Handler exiting normally
    2007-09-27 14:29:16,837 INFO  [Pop3Server-484] [] ProtocolHandler - Handler exiting normally
    2007-09-27 14:29:16,838 INFO  [Pop3Server-472] [] ProtocolHandler - Handler exiting normally
    2007-09-27 14:29:16,838 INFO  [Pop3Server-461] [] ProtocolHandler - Handler exiting normally
    2007-09-27 14:29:16,838 INFO  [Pop3Server-420] [name=chris@bgs.cc;ip=192.168.101.34;] ProtocolHandler - Handler exiting normally
    2007-09-27 14:29:16,839 INFO  [Pop3Server-419] [name=chris@bgs.cc;ip=192.168.101.34;] ProtocolHandler - Handler exiting normally
    2007-09-27 14:29:16,839 INFO  [Pop3Server-389] [] ProtocolHandler - Handler exiting normally
    2007-09-27 14:29:16,840 INFO  [Pop3Server-388] [] ProtocolHandler - Handler exiting normally
    2007-09-27 14:29:16,840 INFO  [Pop3Server-378] [] ProtocolHandler - Handler exiting normally
    2007-09-27 14:29:16,840 INFO  [Pop3Server-361] [] ProtocolHandler - Handler exiting normally
    2007-09-27 14:29:16,841 INFO  [Pop3Server-527] [name=jim@bgs.cc;ip=192.168.101.40;] ProtocolHandler - Handler exiting normally
    2007-09-27 14:29:16,841 INFO  [SIGTERM handler] [] TcpServer/995 - Pop3Server thread pool terminated
    2007-09-27 14:29:16,841 INFO  [SIGTERM handler] [] TcpServer/143 - ImapServer initiating shutdown
    2007-09-27 14:29:16,842 INFO  [ImapServer] [] TcpServer/143 - finished accept loop
    2007-09-27 14:29:16,842 INFO  [SIGTERM handler] [] TcpServer/143 - ImapServer shutting down idle thread pool
    2007-09-27 14:29:16,842 INFO  [SIGTERM handler] [] TcpServer/993 - ImapSSLServer initiating shutdown
    2007-09-27 14:29:16,843 INFO  [ImapSSLServer] [] TcpServer/993 - finished accept loop
    2007-09-27 14:29:16,843 INFO  [SIGTERM handler] [] ProtocolHandler - graceful shutdown requested
    2007-09-27 14:29:16,844 INFO  [ImapSSLServer-1] [name=jfd@bgs.cc;ip=71.52.10.255;] ProtocolHandler - Handler exiting normally
    2007-09-27 14:29:16,845 INFO  [SIGTERM handler] [] TcpServer/993 - ImapSSLServer shutting down idle thread pool
    2007-09-27 14:29:16,890 INFO  [NOTIFY-7035-Server] [] misc - spurious wakeup [1] [no attachment] interest=ACCEPT ready= key=1f217ec poolSize=0 queueSize=0

  4. #4
    Join Date
    Oct 2005
    Location
    Thatcher, AZ
    Posts
    5,606
    Rep Power
    21

    Default

    Shot in the dark here, but can you look to see if you have another pop3 server running on your box?

  5. #5
    Join Date
    Aug 2007
    Location
    US
    Posts
    23
    Rep Power
    8

    Default

    I thought about that too, but there isn't even another pop3 server installed.

    I used lsof to track down which process was listening on ports 110 and 995 and it does appear to be tomcat.

  6. #6
    Join Date
    Oct 2005
    Location
    Thatcher, AZ
    Posts
    5,606
    Rep Power
    21

    Default

    Can you upload your whole log as a txt attachment? Be sure to wipe your server name.

    Thanks
    jh

  7. #7
    Join Date
    May 2006
    Location
    USA
    Posts
    6,242
    Rep Power
    21

    Default

    while your doing that-just out of curiosity-what's your max allowed pop threads set at?
    (yes I know that shows as a different error-usually a direct refused or timeout) I just want to get a feel for the number of users you have, etc.
    Last edited by mmorse; 09-27-2007 at 01:53 PM.

  8. #8
    Join Date
    Aug 2007
    Location
    US
    Posts
    23
    Rep Power
    8

    Default

    It's funny. The number of pop threads field is blank in Global Settings. I entered '200' and clicked Save, but it just goes blank again. When I go to the server to set it, it comes up with '20'. I changed it to '200' and clicked Save, and it seems to save it. But if I click the "Reset to Global value" button, it changes to '20'.

  9. #9
    Join Date
    May 2006
    Location
    USA
    Posts
    6,242
    Rep Power
    21

    Default

    - that '20' in global settings issue may already be an open bug...

    -you could set it using zmprov/zmlocalconfig on the global & server levels, then restart to be sure it applies properly
    zmprov ms servername zimbraPop3NumThreads 200

    (This was the RFE for increasing the initial/default # of zimbraPop3NumThreads to something more than 20: Bug 18388 - increase default value of POP3 threads)

    (The reason I asked before is because I knew the logs wouldn't tell us your max threads value: Bug 7928 - add # of threads for log info)
    Last edited by mmorse; 09-27-2007 at 01:54 PM.

  10. #10
    Join Date
    Aug 2007
    Location
    US
    Posts
    23
    Rep Power
    8

    Default

    I used zmprov to change it to 200 since I couldn't be sure what the Global value was in the UI. I'm going to let it run like that for awhile and see what happens.

Similar Threads

  1. Daily mail report always reports "No messages found"
    By McPringle in forum Installation
    Replies: 42
    Last Post: 06-13-2011, 09:57 AM
  2. Zimbra fails after working for 2 weeks
    By Linsys in forum Administrators
    Replies: 10
    Last Post: 10-07-2008, 01:42 AM
  3. need advice on configuring zimbra to work with fax server
    By pheonix1t in forum Administrators
    Replies: 0
    Last Post: 07-11-2007, 08:46 PM
  4. Server/Disk Statistics revisited
    By phoenix in forum Administrators
    Replies: 16
    Last Post: 03-07-2006, 03:18 PM
  5. No data in server statistics
    By zap in forum Administrators
    Replies: 63
    Last Post: 02-13-2006, 11:39 AM

Posting Permissions

  • You may not post new threads
  • You may not post replies
  • You may not post attachments
  • You may not edit your posts
  •