SWA: Your request to the server has timed out. Keep trying?

[jennix]

Hi all,

between the Years i've made an update from Scalix 11.4.3 to 11.4.6 (on top of openSUSE 11.0 32bit). It doesnt went very smooth, because it wont get my old settings without error messages. So i deleted all in /etc/opt/scalix and some in /var/opt/scalix and made a complete reinstall. Mails and Appointments were reserved.

But since that update i have in many, many times problems with webmail. Somewhen i got the message "Your request to the server has timed out. Keep trying?" and after this, i have in 8 of 10 times no other choice as to restart the scalix-services. I looked at these logfiles:

/var/opt/scalix/mr/s/logs/fatal
/var/opt/scalix/mr/tomcat/logs/scalix-res.log
/var/opt/scalix/mr/tomcat/logs/scalix-caa.log
/var/opt/scalix/mr/tomcat/logs/scalix-swa.log
/var/opt/scalix/mr/tomcat/logs/catalina.out
/var/log/messages

Only two log-files contains messages for the corresponding time, one is scalix-caa.log:

Code: Select all

2010-01-08 08:07:19,409  INFO [RESMonitor.run:115] Server miniserver.lan up 21 hrs, 46 mins, 55 secs
2010-01-08 08:07:29,149  INFO [NotificationEventListener$WorkerThread.run:51] Event Notification: heartbeat|http://miniserver.lan:8080/res/RESDispatcher|LISTEN|300|miniserver|miniserver.lan|11.4.6 from host:miniserver.lan
2010-01-08 08:08:19,410  INFO [RESMonitor.run:115] Server miniserver.lan up 21 hrs, 47 mins, 55 secs
2010-01-08 08:08:29,149  INFO [NotificationEventListener$WorkerThread.run:51] Event Notification: heartbeat|http://miniserver.lan:8080/res/RESDispatcher|LISTEN|300|miniserver|miniserver.lan|11.4.6 from host:miniserver.lan


and the other is /var/log/messages:

Code: Select all

Jan  8 08:08:04 miniserver omslapd[23718]: conn=1223 fd=9 connection from unknown (127.0.0.2)
Jan  8 08:08:04 miniserver omslapd[23718]: conn=1223 op=0 SRCH base="o=scalix" scope=2 filter="(&(|(&(objectclass=scalixPerson)(omulcaps=*))(objectclass=scalixDistributionList)(sn=+bb)(sn=+req))(mail=root@miniserver.lan))"
Jan  8 08:08:04 miniserver omslapd[23718]: conn=1223 op=0 RESULT err=0 tag=101 nentries=0
Jan  8 08:08:04 miniserver omslapd[23718]: conn=1224 fd=11 connection from unknown (127.0.0.2)
Jan  8 08:08:04 miniserver omslapd[23718]: conn=1223 op=1 UNBIND
Jan  8 08:08:04 miniserver omslapd[23718]: conn=1223 op=1 fd=9 closed errno=0
Jan  8 08:08:04 miniserver omslapd[23718]: conn=1224 op=0 SRCH base="o=scalix" scope=2 filter="(&(|(&(objectclass=scalixPerson)(omulcaps=*))(objectclass=scalixDistributionList)(sn=+bb)(sn=+req))(mail=root@miniserver.lan))"
Jan  8 08:08:04 miniserver omslapd[23718]: conn=1224 op=0 RESULT err=0 tag=101 nentries=0
Jan  8 08:08:04 miniserver omslapd[23718]: conn=1224 op=1 UNBIND
Jan  8 08:08:04 miniserver omslapd[23718]: conn=1224 op=1 fd=11 closed errno=0
Jan  8 08:08:04 miniserver omslapd[23718]: conn=1225 fd=9 connection from unknown (127.0.0.2)
Jan  8 08:08:04 miniserver omslapd[23718]: conn=1225 op=0 SRCH base="o=scalix" scope=2 filter="(&(|(&(objectclass=scalixPerson)(omulcaps=*))(objectclass=scalixDistributionList)(sn=+bb)(sn=+req))(mail=root@miniserver.lan))"
Jan  8 08:08:04 miniserver omslapd[23718]: conn=1225 op=0 RESULT err=0 tag=101 nentries=0
Jan  8 08:08:04 miniserver omslapd[23718]: conn=1225 op=1 UNBIND
Jan  8 08:08:04 miniserver omslapd[23718]: conn=1225 op=1 fd=9 closed errno=0
Jan  8 08:08:04 miniserver omslapd[23718]: conn=1226 fd=9 connection from unknown (127.0.0.2)
Jan  8 08:08:04 miniserver omslapd[23718]: conn=1226 op=0 SRCH base="o=scalix" scope=2 filter="(&(|(&(objectclass=scalixPerson)(omulcaps=*))(objectclass=scalixDistributionList)(sn=+bb)(sn=+req))(mail=root@miniserver.lan))"
Jan  8 08:08:04 miniserver omslapd[23718]: conn=1226 op=1 UNBIND
Jan  8 08:08:04 miniserver omslapd[23718]: conn=1226 op=0 RESULT err=0 tag=101 nentries=0
Jan  8 08:08:04 miniserver omslapd[23718]: conn=1226 op=-1 fd=9 closed errno=0


Dont know whether or not these messages have something to to with the TimeOut-problems. In which logfiles i have to look further? What can i do to avoid these problems?

Beside this things webmail is generally much much slower than before.

With 11.4.3 (and before) i never had such a problem. This server (miniserver) runs also some other webapplications, which doesnt have any connection problems, so i dont believe in network-problems.

regards, Jens

[jangi]

Did you upgrade from 11.4.3 -> 11.4.6 at the same time you did an OS upgrade, or were you just pointing out what OS you were running? In any case, and as a sidenote, I would highly recommend getting off opensuse and switching to CentOS. It Just Works, and if you search around the forums you'll find a lot of reasons why and many people saying it.

Anyways, I'm also running into an issue with 11.4.6 where swa becomes completely unresponsive. I'm trying to track it down, but it's proving difficult. I didn't have this issue at all on 11.4.5. That being said, it could be a corrupt mailbox/message I haven't found yet. Do you only need to restart scalix-tomcat, or other services as well?


Is anyone else having an issue with 11.4.6 swa that requires a restart of scalix-tomcat?

[jennix]

Hi,

sorry for the delayed answer, but i didnt had access to the server at weekend. Today i tried if a restart of scalix-tomcat is enough, and it is. No need to restart all of the scalix services to get swa back to work.

regards, Jens

[jennix]

I found something interesting, but didnt know, if it is something important to this problem. When scalix-tomcat will be restarted, it shows that it uses its java-classes from CLASSPATH: /usr/java/jre1.5.0_21/lib.... (its the JRE which is delivered together with Scalix 11.4.6). But JRE_HOME is /usr/lib/jvm/jre. This is a symlink, which points to /etc/alternatives/jre, which is also a link which is pointing to /usr/lib/jvm/jre-1.6.0-sun. Could this be the cause of my problem?

regards, Jens

[jennix]

More tests, more results, more new questions: I've started audit logging to see, whats happen when these timeout-messages are appearing. Unfortunately, even when i put all loglevels up to 15, there ist no entry in /var/opt/scalix/??/s/logs/audit with any reference to this problem. But some other courious entries appearing in this log, when after a server-restart i want to start a connection with swa to this server. Though i've been the only user at this time (all xxxxxxx are replacements for my name), in the audit-Logfile are multiple log-on- and log-off-messages, until SWA is ready to work:

Code: Select all

user-signon
time 1264077430 Thu Jan 21 13:37:10 2010 +60
user-agent-id SWA client
client-type 12
client-ip 192.168.1.250
user 104 xxxxxxxxx/miniserver/CN=xxxxxxxxx 60537 60537
signon-status 0

user-signon
time 1264077435 Thu Jan 21 13:37:15 2010 +60
user-agent-id SWA client
client-type 12
client-ip 192.168.1.250
user 104 xxxxxxxxx/miniserver/CN=xxxxxxxxx 60537 60537
signon-status 0

user-signoff
time 1264077435 Thu Jan 21 13:37:15 2010 +60
user 104 xxxxxxxxx/miniserver/CN=xxxxxxxxx
duration 5
signoff-status 0

user-signon
time 1264077435 Thu Jan 21 13:37:15 2010 +60
user-agent-id IMAP4 Server 11.4.6.13676
client-type 14
client-ip 192.168.1.250
user 104 xxxxxxxxx/miniserver/CN=xxxxxxxxx 60537 60537
signon-status 0

user-signon
time 1264077435 Thu Jan 21 13:37:15 2010 +60
user-agent-id SWA client
client-type 12
client-ip 192.168.1.250
user 104 xxxxxxxxx/miniserver/CN=xxxxxxxxx 60537 60537
signon-status 0

user-signoff
time 1264077435 Thu Jan 21 13:37:15 2010 +60
user 104 xxxxxxxxx/miniserver/CN=xxxxxxxxx
duration 0
signoff-status 0

user-signon
time 1264077436 Thu Jan 21 13:37:16 2010 +60
user-agent-id IMAP4 Server 11.4.6.13676
client-type 14
client-ip 192.168.1.250
user 104 xxxxxxxxx/miniserver/CN=xxxxxxxxx 60537 60537
signon-status 0

user-signon
time 1264077437 Thu Jan 21 13:37:17 2010 +60
user-agent-id IMAP4 Server 11.4.6.13676
client-type 14
client-ip 192.168.1.250
user 104 xxxxxxxxx/miniserver/CN=xxxxxxxxx 60537 60537
signon-status 0

user-signoff
time 1264077437 Thu Jan 21 13:37:17 2010 +60
user 104 xxxxxxxxx/miniserver/CN=xxxxxxxxx
duration 0
signoff-status 0

user-signoff
time 1264077465 Thu Jan 21 13:37:45 2010 +60
user 104 xxxxxxxxx/miniserver/CN=xxxxxxxxx
duration 30
signoff-status 0

user-signon
time 1264077466 Thu Jan 21 13:37:46 2010 +60
user-agent-id SWA client
client-type 12
client-ip 192.168.1.250
user 104 xxxxxxxxx/miniserver/CN=xxxxxxxxx 60537 60537
signon-status 0

user-signoff
time 1264077479 Thu Jan 21 13:37:59 2010 +60
user 104 xxxxxxxxx/miniserver/CN=xxxxxxxxx
duration 44
signoff-status 0


Why? Is this OK?

regards, Jens

[jangi]

I opened a case with Scalix... my issue turned out to be a simple configuration error.

In the SWA config file (/var/opt/scalix/??/webmail/swa.properties) there are two lines:

Code: Select all

swa.platform.httpclient.maxConnectionsPerHost=XXX
swa.platform.httpclient.maxTotalConnections=XXX


In the postgres config file (/var/opt/scalix/XX/postgres/data/postgresql.conf) there is a line:

Code: Select all

max_connections = XXX

Apparently XXX should equal half the number of users on your system.

Voila! SWA rock solid for two weeks now. I haven't gone back and looked, but I really don't remember this being part of the installation guide. And the default (on my system anyway) was 15... way too low.

[PrisonMind]

hi,

has the scalix support something said about "shared_buffers"?

because in the config file is
"max_connections = 100
# note: increasing max_connections costs ~400 bytes of shared memory per
# connection slot, plus lock space (see max_locks_per_transaction). You
# might also need to raise shared_buffers to support more connections."

[jangi]

No, they didn't mention it.

[NoelProf]

I've had this issue after rebooting the host, migrating to a new server, or upgrading. Users would notice SWA would be very slow to load all the headers and most users would eventually receive the server timeout message after some use. What fixed the issue perfectly for a couple of Scalix instances that I manage, one large and commercial and one tiny with the community edition: Simply restart the scalix-postgres service. This was with Scalix 11.4.6 on RHEL 4.7 and Cent-OS 5.3.

Hope this helps,
-Noel Proffitt