Hallo,
Nach dem Update auf 4.4-7 erta 829 öffnen sich Ordner mit vielen Unterordner sehr langsam. Es kommt häufig zu dem roten popup ‚Server nicht erreichbar‘.
Dovecot log unauffällig, Open-Xchange log unauffällig, Hardware nicht am Ende.
Hätte jemand einen Tipp?
Hallo zusammen,
mittlerweile kann ich noch ein Paar Informationen zu dem noch immer nicht gelösten Problem hinzufügen. Vielleicht hat jemand von Euch die zündende Idee, denn bisher kommen wir hier nicht wirklich weiter…
Nochmal kurz das Fehlerbild:
IMAP Folder öffnen sich (erst) seit dem genannten Update extrem langsam (bis zu 10 Minuten) in der OX GUI. Ist der Baum einmal offen, läuft alles wieder wie gewünscht.
Es scheint so, als ob der Befehl
GET folders?action=list...
im OX schon Ewigkeiten dauert,.
Das Problem existiert bei direkter Verwendung von Thunderbird als Client nicht.
Dort werden die Imapfolder in annehmbarer Zeit aufgeklappt.
Nach den bisher verfügbaren Informationen stößt die OX-Middleware auf ungewöhnlich lange Wartezeiten beim Versuch, die Anzahl der gesamten und ungesehenen Nachrichten für die Ordner zu sammeln, die dem Benutzer angezeigt werden sollen.
Konkret wartet die Middleware auf den Abschluss des IMAP-Befehls STATUS INBOX (MESSAGES UNSEEN), der gegen den IMAP-Server gesendet wurde.
Während des Wartens auf das sich Öffnen der IMAP-Folder kann ich folgende Einträge in den jeweiligen Logs sehen:
apache error.log:
[Tue Jan 19 20:59:16.952968 2021] [proxy_http:error] [pid 9217] (20014)Internal error (specific information not available): [client 7
8.94.179.71:35132] AH01102: error reading status line from remote server localhost:8009, referer: https://webmail.foobar.de/appsuite/
ui
[Tue Jan 19 20:59:27.077144 2021] [proxy_http:error] [pid 10702] (20014)Internal error (specific information not available): [client
78.94.179.71:35136] AH01102: error reading status line from remote server localhost:8009, referer: https://webmail.foobar.de/appsuite
/ui
[Tue Jan 19 21:00:36.921697 2021] [proxy_http:error] [pid 11548] (70007)The timeout specified has expired: [client 78.94.179.71:35162
] AH01102: error reading status line from remote server localhost:8009, referer: https://webmail.foobar.de/appsuite/ui
[Tue Jan 19 21:00:36.921831 2021] [proxy:error] [pid 11548] [client 78.94.179.71:35162] AH00898: Error reading from remote server ret
urned by /appsuite/api/folders, referer: https://webmail.foobar.de/appsuite/ui
[Tue Jan 19 21:00:38.213505 2021] [proxy_http:error] [pid 8498] (70007)The timeout specified has expired: [client 78.94.179.71:35148]
AH01102: error reading status line from remote server localhost:8009, referer: https://webmail.foobar.de/appsuite/ui
[Tue Jan 19 21:00:38.213624 2021] [proxy:error] [pid 8498] [client 78.94.179.71:35148] AH00898: Error reading from remote server retu
rned by /appsuite/api/folders, referer: https://webmail.foobar.de/appsuite/ui
apache access.log:
127.0.0.1 - - [19/Jan/2021:21:02:42 +0100] "GET /ajax/mail?action=get&session=d0fd4dd8e27d4f0391b47187c275bc1b&view=raw&folder=defaul
t0%2FGesendete+Objekte&attach_src=1&id=10007&unseen=1&timezone=UTC HTTP/1.1" 200 244341 "-" "Open-Xchange USM HTTP Client"
127.0.0.1 - - [19/Jan/2021:21:02:43 +0100] "GET /ajax/mail?action=get&session=d0fd4dd8e27d4f0391b47187c275bc1b&view=raw&folder=defaul
t0%2FGesendete+Objekte&attach_src=1&id=10249&unseen=1&timezone=UTC HTTP/1.1" 200 46429 "-" "Open-Xchange USM HTTP Client"
127.0.0.1 - - [19/Jan/2021:21:02:43 +0100] "GET /ajax/mail?action=get&session=d0fd4dd8e27d4f0391b47187c275bc1b&view=raw&folder=defaul
t0%2FGesendete+Objekte&attach_src=1&id=10802&unseen=1&timezone=UTC HTTP/1.1" 200 166823 "-" "Open-Xchange USM HTTP Client"
127.0.0.1 - - [19/Jan/2021:21:02:44 +0100] "GET /ajax/mail?action=get&session=d0fd4dd8e27d4f0391b47187c275bc1b&view=raw&folder=defaul
t0%2FGesendete+Objekte&attach_src=1&id=10801&unseen=1&timezone=UTC HTTP/1.1" 200 59994 "-" "Open-Xchange USM HTTP Client"
127.0.0.1 - - [19/Jan/2021:21:02:44 +0100] "GET /ajax/mail?action=get&session=d0fd4dd8e27d4f0391b47187c275bc1b&view=raw&folder=defaul
t0%2FGesendete+Objekte&attach_src=1&id=10804&unseen=1&timezone=UTC HTTP/1.1" 200 39902 "-" "Open-Xchange USM HTTP Client"
127.0.0.1 - - [19/Jan/2021:21:02:45 +0100] "GET /ajax/mail?action=get&session=d0fd4dd8e27d4f0391b47187c275bc1b&view=raw&folder=defaul
t0%2FGesendete+Objekte&attach_src=1&id=10803&unseen=1&timezone=UTC HTTP/1.1" 200 9162 "-" "Open-Xchange USM HTTP Client"
127.0.0.1 - - [19/Jan/2021:21:02:45 +0100] "GET /ajax/mail?action=get&session=d0fd4dd8e27d4f0391b47187c275bc1b&view=raw&folder=defaul
t0%2FGesendete+Objekte&attach_src=1&id=10806&unseen=1&timezone=UTC HTTP/1.1" 200 2643 "-" "Open-Xchange USM HTTP Client"
127.0.0.1 - - [19/Jan/2021:21:02:45 +0100] "GET /ajax/mail?action=get&session=d0fd4dd8e27d4f0391b47187c275bc1b&view=raw&folder=defaul
t0%2FGesendete+Objekte&attach_src=1&id=10805&unseen=1&timezone=UTC HTTP/1.1" 200 1987 "-" "Open-Xchange USM HTTP Client"
127.0.0.1 - - [19/Jan/2021:21:02:45 +0100] "GET /ajax/mail?action=get&session=d0fd4dd8e27d4f0391b47187c275bc1b&view=raw&folder=defaul
t0%2FGesendete+Objekte&attach_src=1&id=10242&unseen=1&timezone=UTC HTTP/1.1" 200 91734 "-" "Open-Xchange USM HTTP Client"
127.0.0.1 - - [19/Jan/2021:21:02:46 +0100] "GET /ajax/mail?action=get&session=d0fd4dd8e27d4f0391b47187c275bc1b&view=raw&folder=defaul
t0%2FGesendete+Objekte&attach_src=1&id=10363&unseen=1&timezone=UTC HTTP/1.1" 200 595682 "-" "Open-Xchange USM HTTP Client"
127.0.0.1 - - [19/Jan/2021:21:02:47 +0100] "GET /ajax/mail?action=get&session=d0fd4dd8e27d4f0391b47187c275bc1b&view=raw&folder=defaul
t0%2FGesendete+Objekte&attach_src=1&id=10241&unseen=1&timezone=UTC HTTP/1.1" 200 65306 "-" "Open-Xchange USM HTTP Client"
127.0.0.1 - - [19/Jan/2021:21:02:47 +0100] "GET /ajax/mail?action=get&session=d0fd4dd8e27d4f0391b47187c275bc1b&view=raw&folder=defaul
t0%2FGesendete+Objekte&attach_src=1&id=10362&unseen=1&timezone=UTC HTTP/1.1" 200 122098 "-" "Open-Xchange USM HTTP Client"
127.0.0.1 - - [19/Jan/2021:21:02:48 +0100] "GET /ajax/mail?action=get&session=d0fd4dd8e27d4f0391b47187c275bc1b&view=raw&folder=defaul
t0%2FGesendete+Objekte&attach_src=1&id=10002&unseen=1&timezone=UTC HTTP/1.1" 200 15334 "-" "Open-Xchange USM HTTP Client"
127.0.0.1 - - [19/Jan/2021:21:02:48 +0100] "GET /ajax/mail?action=get&session=d0fd4dd8e27d4f0391b47187c275bc1b&view=raw&folder=defaul
t0%2FGesendete+Objekte&attach_src=1&id=10244&unseen=1&timezone=UTC HTTP/1.1" 200 9088 "-" "Open-Xchange USM HTTP Client"
127.0.0.1 - - [19/Jan/2021:21:02:48 +0100] "GET /ajax/mail?action=get&session=d0fd4dd8e27d4f0391b47187c275bc1b&view=raw&folder=defaul
t0%2FGesendete+Objekte&attach_src=1&id=10365&unseen=1&timezone=UTC HTTP/1.1" 200 172898 "-" "Open-Xchange USM HTTP Client"
127.0.0.1 - - [19/Jan/2021:21:02:49 +0100] "GET /ajax/mail?action=get&session=d0fd4dd8e27d4f0391b47187c275bc1b&view=raw&folder=defaul
t0%2FGesendete+Objekte&attach_src=1&id=10486&unseen=1&timezone=UTC HTTP/1.1" 200 19587 "-" "Open-Xchange USM HTTP Client"
127.0.0.1 - - [19/Jan/2021:21:02:49 +0100] "GET /ajax/mail?action=get&session=d0fd4dd8e27d4f0391b47187c275bc1b&view=raw&folder=defaul
t0%2FGesendete+Objekte&attach_src=1&id=10001&unseen=1&timezone=UTC HTTP/1.1" 200 34195 "-" "Open-Xchange USM HTTP Client"
127.0.0.1 - - [19/Jan/2021:21:02:49 +0100] "GET /ajax/mail?action=get&session=d0fd4dd8e27d4f0391b47187c275bc1b&view=raw&folder=defaul
t0%2FGesendete+Objekte&attach_src=1&id=10243&unseen=1&timezone=UTC HTTP/1.1" 200 30292 "-" "Open-Xchange USM HTTP Client"
127.0.0.1 - - [19/Jan/2021:21:02:50 +0100] "GET /ajax/mail?action=get&session=d0fd4dd8e27d4f0391b47187c275bc1b&view=raw&folder=defaul
t0%2FGesendete+Objekte&attach_src=1&id=10364&unseen=1&timezone=UTC HTTP/1.1" 200 56812 "-" "Open-Xchange USM HTTP Client"
127.0.0.1 - - [19/Jan/2021:21:02:50 +0100] "GET /ajax/mail?action=get&session=d0fd4dd8e27d4f0391b47187c275bc1b&view=raw&folder=defaul
t0%2FGesendete+Objekte&attach_src=1&id=10485&unseen=1&timezone=UTC HTTP/1.1" 200 8471 "-" "Open-Xchange USM HTTP Client"
127.0.0.1 - - [19/Jan/2021:21:02:51 +0100] "GET /ajax/mail?action=get&session=d0fd4dd8e27d4f0391b47187c275bc1b&view=raw&folder=defaul
t0%2FGesendete+Objekte&attach_src=1&id=10004&unseen=1&timezone=UTC HTTP/1.1" 200 26035 "-" "Open-Xchange USM HTTP Client"
127.0.0.1 - - [19/Jan/2021:21:02:51 +0100] "GET /ajax/mail?action=get&session=d0fd4dd8e27d4f0391b47187c275bc1b&view=raw&folder=defaul
t0%2FGesendete+Objekte&attach_src=1&id=10246&unseen=1&timezone=UTC HTTP/1.1" 200 68802 "-" "Open-Xchange USM HTTP Client"
Open-Xchange-log:
2021-02-01T15:57:21,779+0100 INFO [OXTimer-0000017] com.openexchange.mail.api.MailAccess.logTrace(MailAccess.java:1129)
UNCLOSED MAIL CONNECTION AFTER 63747msec:__threadId=50com.openexchange.ajax.action=listcom.openexchange.ajax.module=folderscom.openexchange.grizzly.method=GETcom.openexchange.grizzly.queryString=action=list&all=0&altNames=true&parent=default40%2FINBOX&timezone=UTC&tree=0&session=3779d07a0d09494986477abfe0121bb9&columns=1%2C2%2C3%2C4%2C5%2C6%2C20%2C23%2C300%2C301%2C302%2C304%2C305%2C306%2C307%2C308%2C309%2C310%2C311%2C312%2C313%2C314%2C315%2C316%2C317%2C318%2C319%2C321%2C3010%2C3020%2C3030%2C3050%2C3201%2C3203%2C3204%2C3205%2C3220com.openexchange.grizzly.remoteAddress=195.53.0.63com.openexchange.grizzly.remotePort=41910com.openexchange.grizzly.requestURI=/ajax/folderscom.openexchange.grizzly.serverName=webmail.foobar.decom.openexchange.grizzly.servletPath=/ajax/folderscom.openexchange.grizzly.threadName=OXWorker-0000006com.openexchange.grizzly.userAgent=Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/88.0.4324.104 Safari/537.36com.openexchange.hostname=webmail.foobar.decom.openexchange.localhost.ipAddress=192.68.0.1com.openexchange.localhost.version=7.10.4-Rev17com.openexchange.mail.accountId=40com.openexchange.mail.host=mail.foobar.de:993com.openexchange.mail.host.remoteAddress=192.68.0.1com.openexchange.mail.login=verkaufcom.openexchange.mail.session=3779d07a0d09494986477abfe0121bb9-32-10-90582dab0d2a7a53com.openexchange.request.trackingId=516083186-258041725com.openexchange.session.authId=d1ca7f79213f4aea8ae6f2b318942ce9com.openexchange.session.clientId=open-xchange-appsuitecom.openexchange.session.contextId=10com.openexchange.session.loginName=pficom.openexchange.session.sessionId=3779d07a0d09494986477abfe0121bb9com.openexchange.session.userId=32com.openexchange.session.userName=pfiimap://verkauf@mail.foobar.de:993Mail connection established (or fetched from cache) at:
java.lang.Throwable: null
at com.openexchange.folderstorage.mail.MailFolderStorage.getFolder(MailFolderStorage.java:1083)
at com.openexchange.folderstorage.mail.MailFolderStorage.getFolders(MailFolderStorage.java:997)
at com.openexchange.folderstorage.cache.CacheFolderStorage$4.call(CacheFolderStorage.java:2124)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at com.openexchange.concurrent.CallerRunsCompletionService.submit(CallerRunsCompletionService.java:134)
at com.openexchange.folderstorage.cache.CacheFolderStorage.loadFolders(CacheFolderStorage.java:2112)
at com.openexchange.folderstorage.cache.CacheFolderStorage.getFolders(CacheFolderStorage.java:1454)
at com.openexchange.folderstorage.cache.CacheFolderStorage.getFolders(CacheFolderStorage.java:1328)
at com.openexchange.folderstorage.internal.performers.ListPerformer.getFolders(ListPerformer.java:604)
at com.openexchange.folderstorage.internal.performers.ListPerformer.loadFoldersFromStorage(ListPerformer.java:556)
at com.openexchange.folderstorage.internal.performers.ListPerformer$3.call(ListPerformer.java:532)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at com.openexchange.concurrent.CallerRunsCompletionService.submit(CallerRunsCompletionService.java:134)
at com.openexchange.folderstorage.internal.performers.ListPerformer.loadFolders(ListPerformer.java:529)
at com.openexchange.folderstorage.internal.performers.ListPerformer.getSubfoldersFromStorages(ListPerformer.java:397)
at com.openexchange.folderstorage.internal.performers.ListPerformer.doList(ListPerformer.java:263)
at com.openexchange.folderstorage.internal.performers.ListPerformer.doList(ListPerformer.java:195)
at com.openexchange.folderstorage.internal.performers.ListPerformer.doList(ListPerformer.java:172)
at com.openexchange.folderstorage.internal.FolderServiceImpl.getSubfolders(FolderServiceImpl.java:259)
at com.openexchange.folderstorage.internal.FilteringFolderService.getSubfolders(FilteringFolderService.java:250)
at com.openexchange.folder.json.actions.ListAction.doPerform(ListAction.java:129)
at com.openexchange.folder.json.actions.AbstractFolderAction.perform(AbstractFolderAction.java:140)
at com.openexchange.ajax.requesthandler.DefaultDispatcher.doCallAction(DefaultDispatcher.java:659)
at com.openexchange.ajax.requesthandler.DefaultDispatcher.callAction(DefaultDispatcher.java:635)
at com.openexchange.ajax.requesthandler.DefaultDispatcher.doPerform(DefaultDispatcher.java:603)
at com.openexchange.ajax.requesthandler.DefaultDispatcher.perform(DefaultDispatcher.java:277)
at com.openexchange.ajax.requesthandler.DispatcherServlet.handle(DispatcherServlet.java:479)
at com.openexchange.ajax.requesthandler.DispatcherServlet.doGet(DispatcherServlet.java:372)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:686)
at com.openexchange.ajax.AJAXServlet.doService(AJAXServlet.java:577)
at com.openexchange.ajax.SessionServlet.doService(SessionServlet.java:181)
at com.openexchange.ajax.requesthandler.DispatcherServlet.service(DispatcherServlet.java:272)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:791)
at org.glassfish.grizzly.servlet.FilterChainImpl.doFilter(FilterChainImpl.java:124)
at com.openexchange.http.grizzly.servletfilter.RequestReportingFilter.doFilter(RequestReportingFilter.java:137)
at org.glassfish.grizzly.servlet.FilterChainImpl.doFilter(FilterChainImpl.java:114)
at com.openexchange.http.grizzly.servletfilter.WrappingFilter.doFilter(WrappingFilter.java:223)
at org.glassfish.grizzly.servlet.FilterChainImpl.doFilter(FilterChainImpl.java:114)
at com.openexchange.http.grizzly.service.http.OSGiAuthFilter.doFilter(OSGiAuthFilter.java:139)
at org.glassfish.grizzly.servlet.FilterChainImpl.doFilter(FilterChainImpl.java:114)
at org.glassfish.grizzly.servlet.FilterChainImpl.invokeFilterChain(FilterChainImpl.java:83)
at org.glassfish.grizzly.servlet.ServletHandler.doServletService(ServletHandler.java:202)
at org.glassfish.grizzly.servlet.ServletHandler.service(ServletHandler.java:154)
at com.openexchange.http.grizzly.service.http.OSGiMainHandler.service(OSGiMainHandler.java:302)
at org.glassfish.grizzly.http.server.HttpHandler$1.run(HttpHandler.java:200)
at com.openexchange.threadpool.internal.CustomThreadPoolExecutor$MDCProvidingRunnable.run(CustomThreadPoolExecutor.java:2621)
at com.openexchange.threadpool.internal.CustomThreadPoolExecutor$Worker.runTask(CustomThreadPoolExecutor.java:834)
at com.openexchange.threadpool.internal.CustomThreadPoolExecutor$Worker.run(CustomThreadPoolExecutor.java:861)
at java.lang.Thread.run(Thread.java:748)
2021-02-01T15:57:21,781+0100 INFO [OXTimer-0000017] com.openexchange.mail.api.MailAccess.logTrace(MailAccess.java:1142)
Current Using Thread: OXWorker-0000006
com.openexchange.mail.api.MailAccess$FastThrowable: tracked mail connection usage
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
at java.net.SocketInputStream.read(SocketInputStream.java:171)
at java.net.SocketInputStream.read(SocketInputStream.java:141)
at sun.security.ssl.SSLSocketInputRecord.read(SSLSocketInputRecord.java:457)
at sun.security.ssl.SSLSocketInputRecord.bytesInCompletePacket(SSLSocketInputRecord.java:68)
at sun.security.ssl.SSLSocketImpl.readApplicationRecord(SSLSocketImpl.java:1095)
at sun.security.ssl.SSLSocketImpl.access$200(SSLSocketImpl.java:72)
at sun.security.ssl.SSLSocketImpl$AppInputStream.read(SSLSocketImpl.java:815)
at com.openexchange.tools.ssl.DelegatingSSLSocket$LoggingInputStream.read(DelegatingSSLSocket.java:582)
at com.sun.mail.util.TraceInputStream.read(TraceInputStream.java:129)
at java.io.BufferedInputStream.fill(BufferedInputStream.java:246)
at java.io.BufferedInputStream.read(BufferedInputStream.java:265)
at com.sun.mail.iap.ResponseInputStream.readResponse(ResponseInputStream.java:104)
at com.sun.mail.iap.Response.<init>(Response.java:135)
at com.sun.mail.imap.protocol.IMAPResponse.<init>(IMAPResponse.java:63)
at com.sun.mail.imap.protocol.IMAPProtocol.readResponse(IMAPProtocol.java:523)
at com.sun.mail.iap.Protocol.executeCommand(Protocol.java:499)
at com.openexchange.imap.commandexecutor.MonitoringCommandExecutor.executeCommandExtended(MonitoringCommandExecutor.java:253)
at com.openexchange.imap.commandexecutor.MonitoringCommandExecutor.executeCommand(MonitoringCommandExecutor.java:232)
at com.sun.mail.iap.Protocol.command(Protocol.java:433)
at com.sun.mail.iap.Protocol.command(Protocol.java:412)
at com.sun.mail.imap.protocol.IMAPProtocol.myRights(IMAPProtocol.java:3684)
at com.sun.mail.imap.IMAPFolder$18.doCommand(IMAPFolder.java:3517)
at com.sun.mail.imap.IMAPFolder.doProtocolCommand(IMAPFolder.java:4434)
at com.sun.mail.imap.IMAPFolder.doOptionalCommand(IMAPFolder.java:4387)
at com.sun.mail.imap.IMAPFolder.myRights(IMAPFolder.java:3512)
at com.openexchange.imap.cache.RightsCache.getCachedRights(RightsCache.java:92)
at com.openexchange.imap.converters.IMAPFolderConverter.getOwnRights(IMAPFolderConverter.java:781)
at com.openexchange.imap.converters.IMAPFolderConverter.convertFolder(IMAPFolderConverter.java:398)
at com.openexchange.imap.util.FolderUtility.loadFolder(FolderUtility.java:136)
at com.openexchange.imap.util.FolderUtility.loadFolder(FolderUtility.java:92)
at com.openexchange.imap.IMAPFolderStorage.getFolder(IMAPFolderStorage.java:909)
at com.openexchange.folderstorage.mail.MailFolderStorage.getMailFolder(MailFolderStorage.java:1245)
at com.openexchange.folderstorage.mail.MailFolderStorage.getFolder(MailFolderStorage.java:1084)
at com.openexchange.folderstorage.mail.MailFolderStorage.getFolders(MailFolderStorage.java:997)
at com.openexchange.folderstorage.cache.CacheFolderStorage$4.call(CacheFolderStorage.java:2124)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at com.openexchange.concurrent.CallerRunsCompletionService.submit(CallerRunsCompletionService.java:134)
at com.openexchange.folderstorage.cache.CacheFolderStorage.loadFolders(CacheFolderStorage.java:2112)
at com.openexchange.folderstorage.cache.CacheFolderStorage.getFolders(CacheFolderStorage.java:1454)
at com.openexchange.folderstorage.cache.CacheFolderStorage.getFolders(CacheFolderStorage.java:1328)
at com.openexchange.folderstorage.internal.performers.ListPerformer.getFolders(ListPerformer.java:604)
at com.openexchange.folderstorage.internal.performers.ListPerformer.loadFoldersFromStorage(ListPerformer.java:556)
at com.openexchange.folderstorage.internal.performers.ListPerformer$3.call(ListPerformer.java:532)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at com.openexchange.concurrent.CallerRunsCompletionService.submit(CallerRunsCompletionService.java:134)
at com.openexchange.folderstorage.internal.performers.ListPerformer.loadFolders(ListPerformer.java:529)
at com.openexchange.folderstorage.internal.performers.ListPerformer.getSubfoldersFromStorages(ListPerformer.java:397)
at com.openexchange.folderstorage.internal.performers.ListPerformer.doList(ListPerformer.java:263)
at com.openexchange.folderstorage.internal.performers.ListPerformer.doList(ListPerformer.java:195)
at com.openexchange.folderstorage.internal.performers.ListPerformer.doList(ListPerformer.java:172)
at com.openexchange.folderstorage.internal.FolderServiceImpl.getSubfolders(FolderServiceImpl.java:259)
at com.openexchange.folderstorage.internal.FilteringFolderService.getSubfolders(FilteringFolderService.java:250)
at com.openexchange.folder.json.actions.ListAction.doPerform(ListAction.java:129)
at com.openexchange.folder.json.actions.AbstractFolderAction.perform(AbstractFolderAction.java:140)
at com.openexchange.ajax.requesthandler.DefaultDispatcher.doCallAction(DefaultDispatcher.java:659)
at com.openexchange.ajax.requesthandler.DefaultDispatcher.callAction(DefaultDispatcher.java:635)
at com.openexchange.ajax.requesthandler.DefaultDispatcher.doPerform(DefaultDispatcher.java:603)
at com.openexchange.ajax.requesthandler.DefaultDispatcher.perform(DefaultDispatcher.java:277)
at com.openexchange.ajax.requesthandler.DispatcherServlet.handle(DispatcherServlet.java:479)
at com.openexchange.ajax.requesthandler.DispatcherServlet.doGet(DispatcherServlet.java:372)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:686)
at com.openexchange.ajax.AJAXServlet.doService(AJAXServlet.java:577)
at com.openexchange.ajax.SessionServlet.doService(SessionServlet.java:181)
at com.openexchange.ajax.requesthandler.DispatcherServlet.service(DispatcherServlet.java:272)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:791)
at org.glassfish.grizzly.servlet.FilterChainImpl.doFilter(FilterChainImpl.java:124)
at com.openexchange.http.grizzly.servletfilter.RequestReportingFilter.doFilter(RequestReportingFilter.java:137)
at org.glassfish.grizzly.servlet.FilterChainImpl.doFilter(FilterChainImpl.java:114)
at com.openexchange.http.grizzly.servletfilter.WrappingFilter.doFilter(WrappingFilter.java:223)
at org.glassfish.grizzly.servlet.FilterChainImpl.doFilter(FilterChainImpl.java:114)
at com.openexchange.http.grizzly.service.http.OSGiAuthFilter.doFilter(OSGiAuthFilter.java:139)
at org.glassfish.grizzly.servlet.FilterChainImpl.doFilter(FilterChainImpl.java:114)
at org.glassfish.grizzly.servlet.FilterChainImpl.invokeFilterChain(FilterChainImpl.java:83)
at org.glassfish.grizzly.servlet.ServletHandler.doServletService(ServletHandler.java:202)
at org.glassfish.grizzly.servlet.ServletHandler.service(ServletHandler.java:154)
at com.openexchange.http.grizzly.service.http.OSGiMainHandler.service(OSGiMainHandler.java:302)
at org.glassfish.grizzly.http.server.HttpHandler$1.run(HttpHandler.java:200)
at com.openexchange.threadpool.internal.CustomThreadPoolExecutor$MDCProvidingRunnable.run(CustomThreadPoolExecutor.java:2621)
at com.openexchange.threadpool.internal.CustomThreadPoolExecutor$Worker.runTask(CustomThreadPoolExecutor.java:834)
at com.openexchange.threadpool.internal.CustomThreadPoolExecutor$Worker.run(CustomThreadPoolExecutor.java:861)
at java.lang.Thread.run(Thread.java:748)
Da wir dieses Problem nur auf dem einen System haben und sonst nicht beobachten können, glauben wir nicht so recht an ein OX-Problem, sondern vielmehr an eine falsche / kaputte Einstellung irgendwo im UCS auf diesem Setup.
Wir wären für jede Hilfe oder Idee dankbar.
Danke
Sascha
Hi, wirklich niemand hat eine Idee?
Danke
Sascha
Hallo,
von den Systemen, auf die ich so schauen kann, habe ich erstmal keine Rückmeldungen über signifikante Verlangsamungen nach Updates auf UCS 4.4-7 oder OX 7.10.4.
Als Ursache würde ich nur Apache oder Dovecot sehen mit Tendenz zu Letzterem und wahrscheinlich etwas Umgebungsspezifisches. Mein nächster Ansatz wäre, einzelne Dovecot-Komponenten gezielt geschwätziger protokollieren zu lassen. Dafür gibts nach meiner Erinnerung sogar UCR-Variablen.
Was noch fürs Bild fehlt wäre eine Betrachtung, wo /var/spool/dovecot liegt und ob abseits der Aussage “Hardware nicht am Ende” diesbezüglich irgendetwas Besonderes bei dieser Installation gegenüber Anderen zu melden wäre.
hth,
Dirk
Hi Dirk,
Danke für Deine Antwort.
Hm, nein, das sieht alles ziemlich ok aus.
/var liegt zwar auf einem eigenen LV, aber darin sieht alles gut aus:
/dev/mapper/vg_ucs-var 453G 149G 285G 35% /var
ls -lah /var/spool/dovecot
insgesamt 16K
drwxr-xr-x 4 dovemail dovemail 4,0K Jun 10 2016 .
drwxr-xr-x 11 root root 4,0K Jun 27 2016 ..
drwxr-s--- 5 dovemail dovemail 4,0K Mai 4 2019 private
drwxr-s--- 2 dovemail dovemail 4,0K Jan 19 2016 public
auch die entsprechenden Ordner zu den so langsamen Imap-Konten scheinen zumindest rechtemäßig ok zu sein.
drwx--S--- 4 dovemail dovemail
Irgendwie scheint es das also eher nicht zu sein.
Wie mache ich jetzt am besten Dovecot gesprächiger?
In den Regs finde ich nichts dazu:
ucr get mail/dovecot
mail/dovecot mail/dovecot/mailboxes/special/confirmed-spam
mail/dovecot/auth/allowplaintext mail/dovecot/mailboxes/special/Drafts
mail/dovecot/auth/ldap/user/attributes mail/dovecot/mailboxes/special/Entwürfe
mail/dovecot/auth/ldap/user/objectclasses mail/dovecot/mailboxes/special/Gesendete
mail/dovecot/folder/ham mail/dovecot/mailboxes/special/Junk
mail/dovecot/folder/spam mail/dovecot/mailboxes/special/Papierkorb
mail/dovecot/imap mail/dovecot/mailboxes/special/Sent
mail/dovecot/limits/default_vsz_limit mail/dovecot/mailboxes/special/Spam
mail/dovecot/limits/imap-login/vsz_limit mail/dovecot/mailboxes/special/Trash
mail/dovecot/limits/imap/process_limit mail/dovecot/mailbox/rename
mail/dovecot/limits/imap/vsz_limit mail/dovecot/pop3
mail/dovecot/logging/auth_verbose_passwords mail/dovecot/pop3/client_workarounds
mail/dovecot/logging/log_path mail/dovecot/quota/warning/subject
mail/dovecot/logging/syslog_facility mail/dovecot/quota/warning/text/80
mail/dovecot/mailbox/delete mail/dovecot/quota/warning/text/95
mail/dovecot/mailboxes/auto/Entwürfe mail/dovecot/sieve/port
mail/dovecot/mailboxes/auto/Gesendete mail/dovecot/sieve/spam
mail/dovecot/mailboxes/auto/Ham mail/dovecot/ssl/certificate
mail/dovecot/mailboxes/auto/Papierkorb mail/dovecot/ssl/key
mail/dovecot/mailboxes/auto/Spam
Oder übersehe ich etwas?
Danke
Sascha
Dovecot debugging hab ich gerade gefunden, ich schau gleich mal, ob das noch so funktioniert:
ucr set mail/dovecot/logging/auth_debug=yes mail/dovecot/logging/auth_verbose=yes mail/dovecot/logging/mail_debug=yes mail/dovecot/logging/auth_debug_passwords=yes
Hi,
ich glaub ich hab’s:
Feb 9 18:47:07 mail dovecot: auth: Debug: ldap(einkauf,192.68.0.1,): username changed einkauf -> einkauf@foobar.de
Es war wohl nur der Name und nicht die Mailadresse bei den zusätzlichen Mailkonten eingepflegt
Mit Mailadresse dauert es nicht 8 sondern höchstens 1 Minute…
Wurde denn seitens OX oder UCS irgendwas an der Authentifizierungslogik geändert?
Hat ja bis zum Update mit dem Usernamen wunderbar funktioniert?
Danke
Sascha
/Edit:
Hm, zu früh gefreut.
Es war erst wirklich merklich schneller ist aber jetzt wieder genauso langsam wie vorher.
Es ist zum Verzweifeln.
Wenn ich das dovecot.log nach einkauf@ greppe sehe ich, dass es jede Menge logins und logouts für das Konto gibt.
Muss ich vielleicht irgendein Timeout für dovecot anderseinstellen?
tail -f /var/log/dovecot.log | grep -i einkauf
Feb 10 15:57:59 mail dovecot: imap-login: Login: user=<einkauf>, method=PLAIN, rip=192.68.0.1, lip=192.68.0.1, mpid=18818, TLS, session=<zMgDofy6kIvARAAB>
Feb 10 15:57:59 mail dovecot: imap(einkauf@foobar.de): Logged out in=24 out=889
Feb 10 15:58:00 mail dovecot: imap-login: Login: user=<einkauf>, method=PLAIN, rip=192.68.0.1, lip=192.68.0.1, mpid=18825, TLS, session=<9DQMofy6oIvARAAB>
Feb 10 15:58:58 mail dovecot: lmtp(einkauf@foobar.de): kGibNLL0I2C4SQAAo8sN6g: sieve: msgid=<001CB706.602402B2@192.168.32.13>: stored mail into mailbox 'INBOX'
Feb 10 15:59:02 mail dovecot: imap-login: Login: user=<einkauf>, method=PLAIN, rip=192.68.0.1, lip=192.68.0.1, mpid=18885, TLS, session=<52DDpPy6OuTARAAB>
Feb 10 15:59:10 mail dovecot: imap-login: Login: user=<einkauf>, method=PLAIN, rip=192.68.0.1, lip=192.68.0.1, mpid=18899, TLS, session=<G/dBpfy6ZuTARAAB>
Feb 10 15:59:15 mail dovecot: imap(einkauf@foobar.de): Logged out in=268 out=1483
Feb 10 15:59:58 mail dovecot: imap-login: Login: user=<einkauf>, method=PLAIN, rip=192.68.0.1, lip=192.68.0.1, mpid=18993, TLS, session=<t5oaqPy6aOXARAAB>
Feb 10 16:00:09 mail dovecot: imap(einkauf@foobar.de): Logged out in=110920 out=397703
Feb 10 16:00:15 mail dovecot: imap(einkauf@foobar.de): Logged out in=66572 out=266130
Feb 10 16:00:18 mail dovecot: imap-login: Login: user=<einkauf>, method=PLAIN, rip=192.68.0.1, lip=192.68.0.1, mpid=19522, TLS, session=<O29Kqfy6xOXARAAB>
Feb 10 16:00:24 mail dovecot: imap(einkauf@foobar.de): Logged out in=259 out=3773
Feb 10 16:00:27 mail dovecot: imap-login: Login: user=<einkauf>, method=PLAIN, rip=192.68.0.1, lip=192.68.0.1, mpid=19548, TLS, session=<8AXWqfy6yuXARAAB>
Feb 10 16:00:35 mail dovecot: imap-login: Login: user=<einkauf>, method=PLAIN, rip=192.68.0.1, lip=192.68.0.1, mpid=19564, TLS, session=<OelPqvy67OXARAAB>
Feb 10 16:01:09 mail dovecot: imap(einkauf@foobar.de): Logged out in=65103 out=263677
Feb 10 16:01:30 mail dovecot: imap-login: Login: user=<einkauf>, method=PLAIN, rip=192.68.0.1, lip=192.68.0.1, mpid=19601, TLS, session=<o7ydrfy6LObARAAB>
Feb 10 16:01:31 mail dovecot: imap-login: Login: user=<einkauf>, method=PLAIN, rip=192.68.0.1, lip=192.68.0.1, mpid=19604, TLS, session=<IHGnrfy6MubARAAB>
Feb 10 16:01:45 mail dovecot: imap(einkauf@foobar.de): Logged out in=69880 out=273073
Feb 10 16:01:45 mail dovecot: imap(einkauf@foobar.de): Logged out in=62347 out=133043
Feb 10 16:01:50 mail dovecot: imap-login: Login: user=<einkauf>, method=PLAIN, rip=192.68.0.1, lip=192.68.0.1, mpid=19666, TLS, session=<6cnBrvy6wubARAAB>
Feb 10 16:01:57 mail dovecot: imap(einkauf@foobar.de): Logged out in=268 out=1475
Feb 10 16:02:45 mail dovecot: imap(einkauf@foobar.de): Logged out in=33040 out=70840
Feb 10 16:02:45 mail dovecot: imap(einkauf@foobar.de): Logged out in=33119 out=198263
/EDIT:
Ich hab noch einen neuen Ansatz:
Feb 12 12:57:38 mail dovecot: master: Warning: fd limit (ulimit -n) is lower than required under max. l
oad (1024 < 2000), because of service auth { client_limit }
Feb 12 12:57:38 mail dovecot: config: Warning: service auth { client_limit=2000 } is lower than require
d under max. load (2400)
Das könnte doch eigentlich auch alles erklären, oder?
Allerdings hat
ucr set mail/dovecot/limits/default_client_limit=30000
und
ucr set mail/dovecot/limits/default_process_limit=30000
nicht den gewünschten Effekt gebracht
Wo genau muss ich das einstellen?
Danke
Sascha