iCAL Connection Problem

[aebir]

Hi,
i have the following problem:
after a few minutes, ical can no longer connect to the scalix server and displays a 'login window' on which i have to specify the uid /pw. I enter the correct pw, but i get always back 'wrong pw/uid).
If i have a look to the tomcat logs i found the following message:

Mar 6, 2008 6:03:11 PM org.apache.jk.common.ChannelSocket acceptConnections
WARNING: Exception executing accept
java.net.SocketException: Too many open files
at java.net.PlainSocketImpl.socketAccept(Native Method)
at java.net.PlainSocketImpl.accept(Unknown Source)
at java.net.ServerSocket.implAccept(Unknown Source)
at java.net.ServerSocket.accept(Unknown Source)
at org.apache.jk.common.ChannelSocket.accept(ChannelSocket.java:312)
at org.apache.jk.common.ChannelSocket.acceptConnections(ChannelSocket.java:666)
at org.apache.jk.common.ChannelSocket$SocketAcceptor.runIt(ChannelSocket.java:876)
at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:689)
at java.lang.Thread.run(Unknown Source)
Mar 6, 2008 6:16:57 PM org.apache.catalina.connector.CoyoteAdapter service
SEVERE: An exception or error occurred in the container during the request processing
java.lang.NoClassDefFoundError: org/apache/log4j/spi/ThrowableInformation
at org.apache.log4j.spi.LoggingEvent.<init>(LoggingEvent.java:154)
at org.apache.log4j.Category.forcedLog(Category.java:388)
at org.apache.log4j.Category.log(Category.java:853)
at org.apache.commons.logging.impl.Log4JLogger.error(Log4JLogger.java:251)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:253)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:174)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:117)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:108)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:151)
at org.apache.jk.server.JkCoyoteHandler.invoke(JkCoyoteHandler.java:200)
at org.apache.jk.common.HandlerRequest.invoke(HandlerRequest.java:283)
at org.apache.jk.common.ChannelSocket.invoke(ChannelSocket.java:773)
at org.apache.jk.common.ChannelSocket.processConnection(ChannelSocket.java:703)
at org.apache.jk.common.ChannelSocket$SocketConnection.runIt(ChannelSocket.java:895)
at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:689)
at java.lang.Thread.run(Unknown Source)
Exception in thread "PeriodTasks[com.scalix.api.init.Platform@38ffd135]" java.lang.NoClassDefFoundError: com/scalix/api/imap/XNotifyCancel
at com.scalix.api.imap.Imap.stopNotification(Imap.java:1479)
at com.scalix.api.imap.Imap.shutdown(Imap.java:336)
at com.scalix.api.imap.ImapService.cleanup(ImapService.java:65)
at com.scalix.api.service.Context.close(Context.java:117)
at com.scalix.api.session.PlatformSession.destroy(PlatformSession.java:109)
at com.scalix.api.session.SessionManager.expireCleanup(SessionManager.java:124)
at com.scalix.api.init.Platform$PeriodTasks.run(Platform.java:182)
at java.lang.Thread.run(Unknown Source)



I had a look to this forum and found some hints regarding the open files problem, which i have implemented:

- file-max is increased to 999999
- inodes are 2% used
- KERNEL_MIN_file_max is 99999 in /etc/sysconfig/scalix

If i restart tomcat, it will work for a few minutes, then i get the same errors again

Here is my config:

OS : CentOS 5
Scalix: 11.3.0-U1 Community
Java: Java(TM) 2 Runtime Environment, Standard Edition (build 1.5.0_13-b05)
Java HotSpot(TM) 64-Bit Server VM (build 1.5.0_13-b05, mixed mode)

Any ideas what i can do next ?

Thank you very much for your help

Rolf

[aebir]

Hi,

does really nobody has a idea what i can do next ?
The whole 'web' part is newrly unusable doe to this problem (SAC/WEBMAIL)

Thanks

Rolf

[aebir]

Is there really no solution to his problem ?
In this case i will continue to evaluate zimbra instead of scalix, since the web access and ical is not usable due to this open file error

Rgds

Rolf

[ls-al]

beside adjusting ULIMIT_NUM_FILES in /etc/opt/scalix-tomcat/scalix-tomcat.conf it might be worth checking *which* files are opened by the java process.
see http://www.scalix.com/wiki/index.php?ti ... ptor_Usage

[aebir]

Thanks for your answer,

I increaded ULIMIT_NUM_FILES to 90000.
After more or less one hout i got again this message:

Apr 11, 2008 3:16:53 PM org.apache.jk.common.ChannelSocket acceptConnections
WARNING: Exception executing accept
java.net.SocketException: Too many open files
at java.net.PlainSocketImpl.socketAccept(Native Method)
at java.net.PlainSocketImpl.accept(Unknown Source)
at java.net.ServerSocket.implAccept(Unknown Source)
at java.net.ServerSocket.accept(Unknown Source)
at org.apache.jk.common.ChannelSocket.accept(ChannelSocket.java:312)
at org.apache.jk.common.ChannelSocket.acceptConnections(ChannelSocket.java:666)
at org.apache.jk.common.ChannelSocket$SocketAcceptor.runIt(ChannelSocket.java:876)
at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:689)
at java.lang.Thread.run(Unknown Source)


lsof of tomcat pid lists 90061 open files !

Seems Tomcat opens a lot of filese without closing it.
I can reproduce this behavior.

Thank you for yor help

Rolf

[ls-al]

ok, this is a bit too much.
can you do a count of the lsof output for strings like "indexes" or other terms that you see more often in the output?
In addition, a closer look at the scalix-* files in the tomcat logs directory may provide further informations.

[aebir]

Hi,

indeed, I have 89942 lines containing the string "indexes" out of 90061 lines in lsof output.
Here just a few of them:

java 2757 root *948r REG 253,0 80 10970108 /var/opt/scalix/sx/indexes/03100000fce97874-022.1.861.291/ref/_u.fdx
java 2757 root *949r REG 253,0 567 10970111 /var/opt/scalix/sx/indexes/03100000fce97874-022.1.861.291/ref/_u.tis
java 2757 root *950r REG 253,0 31 10970112 /var/opt/scalix/sx/indexes/03100000fce97874-022.1.861.291/ref/_u.tii
java 2757 root *951r REG 253,0 200 10970109 /var/opt/scalix/sx/indexes/03100000fce97874-022.1.861.291/ref/_u.frq
java 2757 root *952r REG 253,0 200 10970110 /var/opt/scalix/sx/indexes/03100000fce97874-022.1.861.291/ref/_u.prx
java 2757 root *953r REG 253,0 10 10970117 /var/opt/scalix/sx/indexes/03100000fce97874-022.1.861.291/ref/_u.f0
java 2757 root *954r REG 253,0 10 10970121 /var/opt/scalix/sx/indexes/03100000fce97874-022.1.861.291/ref/_u.f1
java 2757 root *955r REG 253,0 10 10970123 /var/opt/scalix/sx/indexes/03100000fce97874-022.1.861.291/ref/_u.f2
java 2757 root *956r REG 253,0 10 10970124 /var/opt/scalix/sx/indexes/03100000fce97874-022.1.861.291/ref/_u.f3
java 2757 root *957r REG 253,0 10 10970125 /var/opt/scalix/sx/indexes/03100000fce97874-022.1.861.291/ref/_u.f4
java 2757 root *958r REG 253,0 2502 10970127 /var/opt/scalix/sx/indexes/03100000fce97874-022.1.861.291/ref/_15.fdt
java 2757 root *959r REG 253,0 80 10970133 /var/opt/scalix/sx/indexes/03100000fce97874-022.1.861.291/ref/_15.fdx
java 2757 root *960r REG 253,0 567 10970145 /var/opt/scalix/sx/indexes/03100000fce97874-022.1.861.291/ref/_15.tis
java 2757 root *961r REG 253,0 31 10970148 /var/opt/scalix/sx/indexes/03100000fce97874-022.1.861.291/ref/_15.tii
java 2757 root *962r REG 253,0 200 10970140 /var/opt/scalix/sx/indexes/03100000fce97874-022.1.861.291/ref/_15.frq
java 2757 root *963r REG 253,0 200 10970141 /var/opt/scalix/sx/indexes/03100000fce97874-022.1.861.291/ref/_15.prx
java 2757 root *964r REG 253,0 10 10970149 /var/opt/scalix/sx/indexes/03100000fce97874-022.1.861.291/ref/_15.f0
java 2757 root *965r REG 253,0 10 10970152 /var/opt/scalix/sx/indexes/03100000fce97874-022.1.861.291/ref/_15.f1
java 2757 root *966r REG 253,0 10 10970164 /var/opt/scalix/sx/indexes/03100000fce97874-022.1.861.291/ref/_15.f2
java 2757 root *967r REG 253,0 10 10970166 /var/opt/scalix/sx/indexes/03100000fce97874-022.1.861.291/ref/_15.f3
java 2757 root *968r REG 253,0 10 10970167 /var/opt/scalix/sx/indexes/03100000fce97874-022.1.861.291/ref/_15.f4
java 2757 root *969r REG 253,0 2502 10970170 /var/opt/scalix/sx/indexes/03100000fce97874-022.1.861.291/ref/_1g.fdt
java 2757 root *970r REG 253,0 80 10970172 /var/opt/scalix/sx/indexes/03100000fce97874-022.1.861.291/ref/_1g.fdx
java 2757 root *971r REG 253,0 567 10970177 /var/opt/scalix/sx/indexes/03100000fce97874-022.1.861.291/ref/_1g.tis
java 2757 root *972r REG 253,0 31 10970180 /var/opt/scalix/sx/indexes/03100000fce97874-022.1.861.291/ref/_1g.tii
java 2757 root *973r REG 253,0 200 10970174 /var/opt/scalix/sx/indexes/03100000fce97874-022.1.861.291/ref/_1g.frq
java 2757 root *974r REG 253,0 200 10970176 /var/opt/scalix/sx/indexes/03100000fce97874-022.1.861.291/ref/_1g.prx
java 2757 root *975r REG 253,0 10 10970183 /var/opt/scalix/sx/indexes/03100000fce97874-022.1.861.291/ref/_1g.f0
java 2757 root *976r REG 253,0 10 10970185 /var/opt/scalix/sx/indexes/03100000fce97874-022.1.861.291/ref/_1g.f1
java 2757 root *977r REG 253,0 10 10970186 /var/opt/scalix/sx/indexes/03100000fce97874-022.1.861.291/ref/_1g.f2
java 2757 root *978r REG 253,0 10 10970187 /var/opt/scalix/sx/indexes/03100000fce97874-022.1.861.291/ref/_1g.f3
java 2757 root *979r REG 253,0 10 10970188 /var/opt/scalix/sx/indexes/03100000fce97874-022.1.861.291/ref/_1g.f4
java 2757 root *980r REG 253,0 2502 10970193 /var/opt/scalix/sx/indexes/03100000fce97874-022.1.861.291/ref/_1r.fdt
java 2757 root *981r REG 253,0 80 10970194 /var/opt/scalix/sx/indexes/03100000fce97874-022.1.861.291/ref/_1r.fdx
java 2757 root *982r REG 253,0 567 10970206 /var/opt/scalix/sx/indexes/03100000fce97874-022.1.861.291/ref/_1r.tis
java 2757 root *983r REG 253,0 31 10970207 /var/opt/scalix/sx/indexes/03100000fce97874-022.1.861.291/ref/_1r.tii
java 2757 root *984r REG 253,0 200 10970197 /var/opt/scalix/sx/indexes/03100000fce97874-022.1.861.291/ref/_1r.frq
java 2757 root *985r REG 253,0 200 10970201 /var/opt/scalix/sx/indexes/03100000fce97874-022.1.861.291/ref/_1r.prx
java 2757 root *986r REG 253,0 10 10970208 /var/opt/scalix/sx/indexes/03100000fce97874-022.1.861.291/ref/_1r.f0
java 2757 root *987r REG 253,0 10 10970209 /var/opt/scalix/sx/indexes/03100000fce97874-022.1.861.291/ref/_1r.f1
java 2757 root *988r REG 253,0 10 10970210 /var/opt/scalix/sx/indexes/03100000fce97874-022.1.861.291/ref/_1r.f2
java 2757 root *989r REG 253,0 10 10970211 /var/opt/scalix/sx/indexes/03100000fce97874-022.1.861.291/ref/_1r.f3
java 2757 root *990r REG 253,0 10 10970216 /var/opt/scalix/sx/indexes/03100000fce97874-022.1.861.291/ref/_1r.f4
java 2757 root *991r REG 253,0 2502 10970218 /var/opt/scalix/sx/indexes/03100000fce97874-022.1.861.291/ref/_22.fdt
java 2757 root *992r REG 253,0 80 10970219 /var/opt/scalix/sx/indexes/03100000fce97874-022.1.861.291/ref/_22.fdx
java 2757 root *993r REG 253,0 567 10970224 /var/opt/scalix/sx/indexes/03100000fce97874-022.1.861.291/ref/_22.tis
java 2757 root *994r REG 253,0 31 10970225 /var/opt/scalix/sx/indexes/03100000fce97874-022.1.861.291/ref/_22.tii
java 2757 root *995r REG 253,0 200 10970220 /var/opt/scalix/sx/indexes/03100000fce97874-022.1.861.291/ref/_22.frq
java 2757 root *996r REG 253,0 200 10970221 /var/opt/scalix/sx/indexes/03100000fce97874-022.1.861.291/ref/_22.prx
java 2757 root *997r REG 253,0 10 10970226 /var/opt/scalix/sx/indexes/03100000fce97874-022.1.861.291/ref/_22.f0
java 2757 root *998r REG 253,0 10 10970227 /var/opt/scalix/sx/indexes/03100000fce97874-022.1.861.291/ref/_22.f1
java 2757 root *999r REG 253,0 10 10970228 /var/opt/scalix/sx/indexes/03100000fce97874-022.1.

I had a look to the tomcat log files, two of them have maybe useful informations (beside catalina.out):

scalix-resi.log:

2008-03-28 15:14:20,647 INFO [RESDispatcherServlet.destroy:53] Shuting down...all threads...
2008-03-28 15:14:20,647 INFO [RESNotifier.stopPollingThreads:103] Stopping HeartBeat-thread
2008-03-28 15:14:20,649 INFO [RESNotifier.stopNotificationThreads:115] Stopping Notifier-thread-0
2008-03-28 15:14:20,649 INFO [RESNotifier.stopNotificationThreads:115] Stopping Notifier-thread-1
2008-03-28 15:14:20,649 INFO [RESNotifier.stopRegistrationThreads:91] Registration-thread Stopping thread...
2008-03-28 15:14:20,650 DEBUG [Notifier.run:52] Notifier-thread-1 Thread interrupted...
2008-03-28 15:14:20,650 DEBUG [Notifier.run:52] Notifier-thread-0 Thread interrupted...
2008-03-28 15:14:42,878 INFO [RESNamedInstances.initNamedInstances:61] Loading Scalix named instances.
2008-03-28 15:14:42,885 INFO [RESNamedInstances.initNamedInstances:100] Finised reading Named Instances. Total Named instances in the global config file are = 1
2008-03-28 15:14:42,886 INFO [RESNamedInstances.initNamedInstances:101] Checking Named Instances state..
2008-03-28 15:14:42,889 DEBUG [CmdExecution.executeCmd:141] ENVIRONMENT: LANG=en_US.UTF-8 OM_CHAR=UTF-8 HOME=/tmp PWD=/tmp
2008-03-28 15:14:42,890 DEBUG [CmdExecution.executeCmd:143] COMMAND: /opt/scalix/bin/sxchkinstances
2008-03-28 15:14:43,094 INFO [RESNamedInstances.initNamedInstances:116] scalix - is an Active named instance
2008-03-28 15:14:43,104 INFO [RESNotifier.startRegistrationThread:82] Launching Registration-thread
2008-03-28 15:14:43,106 DEBUG [RESDispatcherServlet.initialize:390] : Almost finished initialization, now waiting for registration
2008-03-28 15:14:43,235 INFO [RegistrationEventPoller.run:113] Added Registration event to the Notification Event Queue queue:Event=[register|http://scalix.rohnnet.ch/res/RESDispatcher|LISTEN|300
|scalix|scalix.rohnnet.ch|11.3.0] (try 100 retries)
2008-03-28 15:14:43,236 DEBUG [RegistrationEventPoller.run:116] Notified monitor queue that is has a new event
2008-03-28 15:14:43,240 DEBUG [RegistrationEventPoller.run:121] Sleeping for 5000 ms before trying again
2008-03-28 15:14:43,462 DEBUG [Notifier.sendNotification:132] Notifier-thread-0/ACK/Event=[register|http://scalix.rohnnet.ch/res/RESDispatcher|LISTEN|300|scalix|scalix.rohnnet.ch|11.3.0]
2008-03-28 15:14:48,663 INFO [RegistrationEventPoller.run:113] Added Registration event to the Notification Event Queue queue:Event=[register|http://scalix.rohnnet.ch/res/RESDispatcher|LISTEN|300
|scalix|scalix.rohnnet.ch|11.3.0] (try 100 retries)
2008-03-28 15:14:48,665 DEBUG [RegistrationEventPoller.run:116] Notified monitor queue that is has a new event
2008-03-28 15:14:48,666 DEBUG [RegistrationEventPoller.run:121] Sleeping for 5000 ms before trying again
2008-03-28 15:14:48,668 DEBUG [Notifier.sendNotification:132] Notifier-thread-0/ACK/Event=[register|http://scalix.rohnnet.ch/res/RESDispatcher|LISTEN|300|scalix|scalix.rohnnet.ch|11.3.0]
2008-03-28 15:14:53,785 INFO [RegistrationEventPoller.run:87] We are registered, stopping registration thread
2008-03-28 15:14:53,795 INFO [RESNotifier.startPollingThreads:68] Launching HeartBeat-thread
2008-03-28 15:14:53,797 INFO [RegistrationEventPoller.run:92] : Finished initialization
2008-03-28 15:14:53,799 DEBUG [HeartBeatEventPoller.run:69] Added heartbeatEventEvent=[heartbeat|http://scalix.rohnnet.ch/res/RESDispatcher|LISTEN|300|scalix|scalix.rohnnet.ch|11.3.0] to the Notif
ication Event Queue
2008-03-28 15:14:53,803 DEBUG [Notifier.sendNotification:132] Notifier-thread-0/ACK/Event=[heartbeat|http://scalix.rohnnet.ch/res/RESDispatcher|LISTEN|300|scalix|scalix.rohnnet.ch|11.3.0]
2008-03-28 15:15:53,803 DEBUG [HeartBeatEventPoller.run:69] Added heartbeatEventEvent=[heartbeat|http://scalix.rohnnet.ch/res/RESDispatcher|LISTEN|300|scalix|scalix.rohnnet.ch|11.3.0] to the Notif
ication Event Queue
2008-03-28 15:15:53,804 ERROR [Notifier.sendNotification:122] java.net.SocketException: Too many open files
2008-03-28 15:15:53,804 DEBUG [Notifier.sendNotification:134] Notifier-thread-0/ntries=4/Event=[heartbeat|http://scalix.rohnnet.ch/res/RESDispatcher|LISTEN|300|scalix|scalix.rohnnet.ch|11.3.0]
2008-03-28 15:16:53,807 DEBUG [HeartBeatEventPoller.run:69] Added heartbeatEventEvent=[heartbeat|http://scalix.rohnnet.ch/res/RESDispatcher|LISTEN|300|scalix|scalix.rohnnet.ch|11.3.0] to the Notif
ication Event Queue
2008-03-28 15:16:53,808 ERROR [Notifier.sendNotification:122] java.net.SocketException: Too many open files
2008-03-28 15:16:53,808 DEBUG [Notifier.sendNotification:134] Notifier-thread-0/ntries=4/Event=[heartbeat|http://scalix.rohnnet.ch/res/RESDispatcher|LISTEN|300|scalix|scalix.rohnnet.ch|11.3.0]
2008-03-28 15:17:53,810 DEBUG [HeartBeatEventPoller.run:69] Added heartbeatEventEvent=[heartbeat|http://scalix.rohnnet.ch/res/RESDispatcher|LISTEN|300|scalix|scalix.rohnnet.ch|11.3.0] to the Notif
ication Event Queue
2008-03-28 15:17:53,810 ERROR [Notifier.sendNotification:122] java.net.SocketException: Too many open files
2008-03-28 15:17:53,811 DEBUG [Notifier.sendNotification:134] Notifier-thread-0/ntries=4/Event=[heartbeat|http://scalix.rohnnet.ch/res/RESDispatcher|LISTEN|300|scalix|scalix.rohnnet.ch|11.3.0]
2008-03-28 15:18:53,812 DEBUG [HeartBeatEventPoller.run:69] Added heartbeatEventEvent=[heartbeat|http://scalix.rohnnet.ch/res/RESDispatcher|LISTEN|300|scalix|scalix.rohnnet.ch|11.3.0] to the Notif
ication Event Queue
2008-03-28 15:18:53,814 ERROR [Notifier.sendNotification:122] java.net.SocketException: Too many open files
2008-03-28 15:18:53,816 DEBUG [Notifier.sendNotification:134] Notifier-thread-0/ntries=4/Event=[heartbeat|http://scalix.rohnnet.ch/res/RESDispatcher|LISTEN|300|scalix|scalix.rohnnet.ch|11.3.0]
2008-03-28 15:19:53,815 DEBUG [HeartBeatEventPoller.run:69] Added heartbeatEventEvent=[heartbeat|http://scalix.rohnnet.ch/res/RESDispatcher|LISTEN|300|scalix|scalix.rohnnet.ch|11.3.0] to the Notif
ication Event Queue


scalix-sis-indexer.log:

008-04-10 23:58:29,496 ERROR [QueueManager] [BatchUpdater.processMods:58] Failed to get reference modifier for user 03100000fce97874-022.1.861.291
java.io.IOException: Too many open files
at java.io.UnixFileSystem.createFileExclusively(Native Method)
at java.io.File.createNewFile(Unknown Source)
at org.apache.lucene.store.FSDirectory$1.obtain(FSDirectory.java:363)
at org.apache.lucene.store.Lock.obtain(Lock.java:51)
at org.apache.lucene.index.IndexWriter.<init>(IndexWriter.java:254)
at org.apache.lucene.index.IndexWriter.<init>(IndexWriter.java:244)
at org.apache.lucene.index.IndexModifier.init(IndexModifier.java:148)
at org.apache.lucene.index.IndexModifier.<init>(IndexModifier.java:124)
at com.scalix.sis.util.IndexUtil.getReferenceIndexModifier(IndexUtil.java:62)
at com.scalix.index.manager.BatchUpdater.processMods(BatchUpdater.java:56)
at com.scalix.index.manager.QueueManager.processQueue(QueueManager.java:127)
at com.scalix.index.manager.QueueManager.run(QueueManager.java:73)
at java.lang.Thread.run(Unknown Source)
2008-04-10 23:58:44,498 ERROR [QueueManager] [BatchUpdater.processMods:58] Failed to get reference modifier for user 03100000fce97874-022.1.861.291
java.io.IOException: Too many open files
at java.io.UnixFileSystem.createFileExclusively(Native Method)
at java.io.File.createNewFile(Unknown Source)
at org.apache.lucene.store.FSDirectory$1.obtain(FSDirectory.java:363)
at org.apache.lucene.store.Lock.obtain(Lock.java:51)
at org.apache.lucene.index.IndexWriter.<init>(IndexWriter.java:254)
at org.apache.lucene.index.IndexWriter.<init>(IndexWriter.java:244)
at org.apache.lucene.index.IndexModifier.init(IndexModifier.java:148)
at org.apache.lucene.index.IndexModifier.<init>(IndexModifier.java:124)
at com.scalix.sis.util.IndexUtil.getReferenceIndexModifier(IndexUtil.java:62)
at com.scalix.index.manager.BatchUpdater.processMods(BatchUpdater.java:56)
at com.scalix.index.manager.QueueManager.processQueue(QueueManager.java:127)
at com.scalix.index.manager.QueueManager.run(QueueManager.java:73)
at java.lang.Thread.run(Unknown Source)
2008-04-10 23:58:59,500 ERROR [QueueManager] [BatchUpdater.processMods:58] Failed to get reference modifier for user 03100000fce97874-022.1.861.291
java.io.IOException: Too many open files
at java.io.UnixFileSystem.createFileExclusively(Native Method)
at java.io.File.createNewFile(Unknown Source)
at org.apache.lucene.store.FSDirectory$1.obtain(FSDirectory.java:363)
at org.apache.lucene.store.Lock.obtain(Lock.java:51)
at org.apache.lucene.index.IndexWriter.<init>(IndexWriter.java:254)
at org.apache.lucene.index.IndexWriter.<init>(IndexWriter.java:244)
at org.apache.lucene.index.IndexModifier.init(IndexModifier.java:148)
at org.apache.lucene.index.IndexModifier.<init>(IndexModifier.java:124)
at com.scalix.sis.util.IndexUtil.getReferenceIndexModifier(IndexUtil.java:62)
at com.scalix.index.manager.BatchUpdater.processMods(BatchUpdater.java:56)
at com.scalix.index.manager.QueueManager.processQueue(QueueManager.java:127)
at com.scalix.index.manager.QueueManager.run(QueueManager.java:73)
at java.lang.Thread.run(Unknown Source)

BTW i saw that we have also a problem with the CDA Server. I dont know if this is relevant, but I will add the error messages also here :

SERIOUS ERROR CDA Server (CDA Server ) 04.14.08 10:34:59
[OM 10270] Process about to terminate due to error.
Signal (Segmentation Violation) trapped by process 12418
Procedure trace follows:
-> aud_GetSetLogConfig
<- aud_GetSetLogConfig
-> cda_DaemonMain
-> ccs_DoInitTables
-> ccs_AttemptSMem
<- ccs_AttemptSMem
<- ccs_DoInitTables


SERIOUS ERROR CDA Server (CDA Server ) 04.14.08 10:34:59
[OM 10272] BACKTRACE:
/opt/scalix/lib/libom_er.so(er_add_backtrace+0xb3)[0xf7f5bb03]
/opt/scalix/lib/libom_er.so[0xf7f5bdf3]
/opt/scalix/lib/libom_er.so(er_DumpProcAndExit+0x1f)[0xf7f5bf7f]
[0xffffe500]
/lib/libc.so.6(__strtol_internal+0x3f)[0x859d1f]
/lib/libc.so.6(atoi+0x29)[0x857349]
cda.server[0x804db48]
/opt/scalix/lib/libom_cl.so(cl_CallProc+0x86)[0xf7fd4d4a]
cda.server[0x8051afa]
/lib/libc.so.6(__libc_start_main+0xdc)[0x842dec]
cda.server[0x804a411]



Thanks for your help

Rolf

[ls-al]

OS : CentOS 5
Scalix: 11.3.0-U1 Community
Java: Java(TM) 2 Runtime Environment, Standard Edition (build 1.5.0_13-b05)
Java HotSpot(TM) 64-Bit Server VM (build 1.5.0_13-b05, mixed mode)

I guess the JRE is not the version which comes with Scalix and I believe that Scalix QA does not test against other JREs.
Can you give it a try?

Regards,
Dirk

[aebir]

Hi,

this is the version which ships with scalix !

Java version "1.5.0_13"
Java(TM) 2 Runtime Environment, Standard Edition (build 1.5.0_13-b05)
Java HotSpot(TM) 64-Bit Server VM (build 1.5.0_13-b05, mixed mode)

I just deinstalled and installed it again to make it shure
The RPM i installed was out of scalix-11.3.0-GA/third_party/jre/amd64/jre-1_5_0_13-linux-amd64.rpm

Regards

Rolf

[ls-al]

Sorry, I didnt realise that you had posted the .../bin/java -version output and was irritated by the "-b05".

The normal calculation for the file handles is 20 files per mailbox (https://bugzilla.scalix.com/show_bug.cgi?id=15544).
This means your config should be pk for 4500 mailboxes. I just checked such a system and had a open file count of <50000 for the indexes.

Looking at the lsof listing I can see that there are much more files in the ../03100000fce97874-022.1.861.291 directory. This directory helds the index of one mailbox

I would start investigating if there is something wrong with the index of this mailbox.

The following line will show the name of the mailbox:

Code: Select all

omsearch -s -e "ul-sis-url=*03100000fce97874-022.1.861.291" -d userlist -t h | omfmtent -x

(there is possibly an easier way, but I know this works).

check size and message count, try to disable indexing for this mailbox (ommodu ... --index=none)

[aebir]

OK,
i switched off/on the index an the open files of Tomcat dropped from 50000 to approx 300 files
There was something wrong with the indexing, now it works !

Thanks for your help

Regards

Rolf

P.S I will open another thread for the CDA Server issue..