| Welcome to the Zimbra :: Forums! | |
Welcome, if you would like to post a comment please register.
We also encourage you to explore all things Zimbra with our team and members of the community.
|  | | 
12-03-2008, 05:46 AM
| | | Web sessions logged out all of a sudden Hi there,
first of all congrats for this awesome piece of software. We are very pleased.
Anyways, just today at ~12.40 we had all web sessions logged out, admin included.
Here's what I've just found in mailbox.log: Code: [...]
2008-12-03 12:39:14,172 WARN [btpool0-1731] [] SoapEngine - unable to construct SOAP context
com.zimbra.common.service.ServiceException: auth credentials have expired
ExceptionId:btpool0-1731:1228304354172:85d7468e46da65b8
Code:service.AUTH_EXPIRED
at com.zimbra.common.service.ServiceException.AUTH_EXPIRED(ServiceException.java:287)
at com.zimbra.soap.ZimbraSoapContext.<init>(ZimbraSoapContext.java:191)
at com.zimbra.soap.SoapEngine.dispatch(SoapEngine.java:190)
at com.zimbra.soap.SoapEngine.dispatch(SoapEngine.java:160)
at com.zimbra.soap.SoapServlet.doPost(SoapServlet.java:269)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:727)
at com.zimbra.cs.servlet.ZimbraServlet.service(ZimbraServlet.java:189)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:820)
at org.mortbay.jetty.servlet.ServletHolder.handle(ServletHolder.java:487)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1093)
at org.mortbay.servlet.UserAgentFilter.doFilter(UserAgentFilter.java:81)
at org.mortbay.servlet.GzipFilter.doFilter(GzipFilter.java:132)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1084)
at org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:360)
at org.mortbay.jetty.security.SecurityHandler.handle(SecurityHandler.java:216)
at org.mortbay.jetty.servlet.SessionHandler.handle(SessionHandler.java:181)
at org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java:716)
at org.mortbay.jetty.webapp.WebAppContext.handle(WebAppContext.java:406)
at org.mortbay.jetty.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:211)
at org.mortbay.jetty.handler.HandlerCollection.handle(HandlerCollection.java:114)
at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:139)
at org.mortbay.jetty.handler.rewrite.RewriteHandler.handle(RewriteHandler.java:350)
at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:139)
at org.mortbay.jetty.Server.handle(Server.java:313)
at org.mortbay.jetty.HttpConnection.handleRequest(HttpConnection.java:506)
at org.mortbay.jetty.HttpConnection$RequestHandler.content(HttpConnection.java:844)
at org.mortbay.jetty.HttpParser.parseNext(HttpParser.java:644)
at org.mortbay.jetty.HttpParser.parseAvailable(HttpParser.java:211)
at org.mortbay.jetty.HttpConnection.handle(HttpConnection.java:381)
at org.mortbay.io.nio.SelectChannelEndPoint.run(SelectChannelEndPoint.java:396)
at org.mortbay.thread.BoundedThreadPool$PoolThread.run(BoundedThreadPool.java:442)
[...]
2008-12-03 12:42:04,468 WARN [btpool0-1732] [] SoapEngine - unable to construct SOAP context
com.zimbra.common.service.ServiceException: auth credentials have expired
ExceptionId:btpool0-1732:1228304524468:85d7468e46da65b8
Code:service.AUTH_EXPIRED
at com.zimbra.common.service.ServiceException.AUTH_EXPIRED(ServiceException.java:287)
at com.zimbra.soap.ZimbraSoapContext.<init>(ZimbraSoapContext.java:191)
at com.zimbra.soap.SoapEngine.dispatch(SoapEngine.java:190)
at com.zimbra.soap.SoapEngine.dispatch(SoapEngine.java:160)
at com.zimbra.soap.SoapServlet.doPost(SoapServlet.java:269)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:727)
at com.zimbra.cs.servlet.ZimbraServlet.service(ZimbraServlet.java:189)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:820)
at org.mortbay.jetty.servlet.ServletHolder.handle(ServletHolder.java:487)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1093)
at org.mortbay.servlet.UserAgentFilter.doFilter(UserAgentFilter.java:81)
at org.mortbay.servlet.GzipFilter.doFilter(GzipFilter.java:132)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1084)
at org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:360)
at org.mortbay.jetty.security.SecurityHandler.handle(SecurityHandler.java:216)
at org.mortbay.jetty.servlet.SessionHandler.handle(SessionHandler.java:181)
at org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java:716)
at org.mortbay.jetty.webapp.WebAppContext.handle(WebAppContext.java:406)
at org.mortbay.jetty.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:211)
at org.mortbay.jetty.handler.HandlerCollection.handle(HandlerCollection.java:114)
at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:139)
at org.mortbay.jetty.handler.rewrite.RewriteHandler.handle(RewriteHandler.java:350)
at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:139)
at org.mortbay.jetty.Server.handle(Server.java:313)
at org.mortbay.jetty.HttpConnection.handleRequest(HttpConnection.java:506)
at org.mortbay.jetty.HttpConnection$RequestHandler.content(HttpConnection.java:844)
at org.mortbay.jetty.HttpParser.parseNext(HttpParser.java:644)
at org.mortbay.jetty.HttpParser.parseAvailable(HttpParser.java:211)
at org.mortbay.jetty.HttpConnection.handle(HttpConnection.java:381)
at org.mortbay.io.nio.SelectChannelEndPoint.run(SelectChannelEndPoint.java:396)
at org.mortbay.thread.BoundedThreadPool$PoolThread.run(BoundedThreadPool.java:442)
[...]
Notice that we've never faced a situation like this one before. Nothing serious, it just made users reauth again and that's it, but still it's something scary, you know... At least as long as I don't understand why it happened in the first place...!
I thank you all in advance.
Marcello | 
12-03-2008, 10:14 PM
| | Trained Alumni | |
Posts: 108
| | hmm that's odd. Does the mailbox.log file, in the entire Java Exception, say anything like "caused by ..." ?
Any chance ntpd/ntpclient would have set the clock forward ? | 
12-04-2008, 06:41 AM
| | | Txs buddy, fast reply!
Nope, both suggested causes don't apply here:
- I checked NTP, I see no evidence of it messing around with system time. Maybe its reference NTP servers did this? I doubt it thou...
- Java doesn't say anything else... :-(
In the mean time, thanks again. | 
12-04-2008, 06:47 AM
| | | Errr....
Paying some more attention, looks like it wasn't the first time... Code: #cd /opt/zimbra/log/ ; fgrep -r AUTH_EXPIRED *
mailbox.log:Code:service.AUTH_EXPIRED
mailbox.log: at com.zimbra.common.service.ServiceException.AUTH_EXPIRED(ServiceException.java:287)
mailbox.log:Code:service.AUTH_EXPIRED
mailbox.log: at com.zimbra.common.service.ServiceException.AUTH_EXPIRED(ServiceException.java:287)
mailbox.log.2008-11-26:Code:service.AUTH_EXPIRED
mailbox.log.2008-11-26: at com.zimbra.common.service.ServiceException.AUTH_EXPIRED(ServiceException.java:287)
mailbox.log.2008-11-26:Code:service.AUTH_EXPIRED
mailbox.log.2008-11-26: at com.zimbra.common.service.ServiceException.AUTH_EXPIRED(ServiceException.java:287)
mailbox.log.2008-11-28:Code:service.AUTH_EXPIRED
mailbox.log.2008-11-28: at com.zimbra.common.service.ServiceException.AUTH_EXPIRED(ServiceException.java:287)
mailbox.log.2008-12-03:Code:service.AUTH_EXPIRED
mailbox.log.2008-12-03: at com.zimbra.common.service.ServiceException.AUTH_EXPIRED(ServiceException.java:287)
mailbox.log.2008-12-03:Code:service.AUTH_EXPIRED
mailbox.log.2008-12-03: at com.zimbra.common.service.ServiceException.AUTH_EXPIRED(ServiceException.java:287) | 
12-04-2008, 12:14 PM
| | Trained Alumni | |
Posts: 108
| | Quote:
Originally Posted by caio80 Errr....
Paying some more attention, looks like it wasn't the first time... Code: #cd /opt/zimbra/log/ ; fgrep -r AUTH_EXPIRED *
mailbox.log:Code:service.AUTH_EXPIRED
mailbox.log: at com.zimbra.common.service.ServiceException.AUTH_EXPIRED(ServiceException.java:287)
mailbox.log:Code:service.AUTH_EXPIRED
mailbox.log: at com.zimbra.common.service.ServiceException.AUTH_EXPIRED(ServiceException.java:287)
mailbox.log.2008-11-26:Code:service.AUTH_EXPIRED
mailbox.log.2008-11-26: at com.zimbra.common.service.ServiceException.AUTH_EXPIRED(ServiceException.java:287)
mailbox.log.2008-11-26:Code:service.AUTH_EXPIRED
mailbox.log.2008-11-26: at com.zimbra.common.service.ServiceException.AUTH_EXPIRED(ServiceException.java:287)
mailbox.log.2008-11-28:Code:service.AUTH_EXPIRED
mailbox.log.2008-11-28: at com.zimbra.common.service.ServiceException.AUTH_EXPIRED(ServiceException.java:287)
mailbox.log.2008-12-03:Code:service.AUTH_EXPIRED
mailbox.log.2008-12-03: at com.zimbra.common.service.ServiceException.AUTH_EXPIRED(ServiceException.java:287)
mailbox.log.2008-12-03:Code:service.AUTH_EXPIRED
mailbox.log.2008-12-03: at com.zimbra.common.service.ServiceException.AUTH_EXPIRED(ServiceException.java:287) |
Did the problem occur on the same days that the AUTH_EXPIRED value is in those files ? | 
12-05-2008, 05:16 AM
| | | Yes and no...
I mean, even today it happened, at 12:41. People noticed it, being forced to reauth, and reported it to me. I then checked my webclient, but in my case I didn't need to reauth again (linux client, firefox 3.0.4).
At the same time according to the logs there has been another AUTH_EXPIRED at 11.20 today (1h20m before), but this time nobody had any problem client-side!
Whatta... :-o | 
12-05-2008, 07:08 AM
| | | UPDATE:
This time it happened again! But on a imap-client. It just said the "server wasn't reachable" or something like that.
By checking logs, there's another AUTH_EXPIRED just 10 minutes ago, but actually AFTER the user called me in to tell me his Thunderbird complained about not being able to communicate with the server... :-(
And now I start finding many of the following Java exceptions in the error log. Code: [...]
2008-12-05 11:51:16,570 INFO [ImapServer-7060] [] 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 java.io.BufferedInputStream.fill(BufferedInputStream.java:218)
at java.io.BufferedInputStream.read(BufferedInputStream.java:235)
at com.zimbra.cs.tcpserver.TcpServerInputStream.readLine(TcpServerInputStream.java:73)
at com.zimbra.cs.imap.TcpImapRequest.continuation(TcpImapRequest.java:52)
at com.zimbra.cs.imap.TcpImapHandler.processCommand(TcpImapHandler.java:106)
at com.zimbra.cs.tcpserver.ProtocolHandler.processConnection(ProtocolHandler.java:160)
at com.zimbra.cs.tcpserver.ProtocolHandler.run(ProtocolHandler.java:128)
at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(Unknown Source)
at java.lang.Thread.run(Thread.java:595)
2008-12-05 15:16:02,092 INFO [ImapServer-7444] [] ProtocolHandler - Handler exiting normally
[...] Whatta.... again!
Any idea folks?
I thank you all in advance | 
12-05-2008, 09:16 AM
| | | It looks like (at least some of these entries) are happening at ~12:40...is there a cron task that is running that might be causing this? | 
12-09-2008, 12:21 AM
| | | Quote: |
It looks like (at least some of these entries) are happening at ~12:40...is there a cron task that is running that might be causing this?
| Nope, already checked, but nothing's scheduled for ~12.40. And anyways time differs substantially (~2 mins, computer-wise though). Thanks anyways for the hint, ArcaneMagus. | 
12-09-2008, 12:22 AM
| | | UPDATE #2:
As soon as I sat down this tuesday morning, back from this past long week-end, I checked logs to see how it behaved: No AUTH_EXPIRED in 3 full days. Notice that nobody obviouosly worked in the meantime!
Looks like "no use" == "no problem"...
Last edited by caio80; 12-10-2008 at 06:39 AM..
| | Thread Tools | Search this Thread | | | | | Display Modes | Linear Mode | | Why Join? Registering let's you ask questions, makes it easier to search, displays any files attached to posts, and notifies you about replies.  |