We tried to roll our fresh install of 11.0.2.1 into production on Saturday, but had to roll back due to numerous errors in the logs and severely degraded performance. Here is the rundown:
1. Details: RHEL4, fully patched; Scalix 11.0.2.1 Enterprise, fresh install, 4GB RAM, two dual core proc, no host firewall, in DMZ instead.
2. After reading posts about problems with dual honed machines, we removed the second nic from startup before reinstalling. Even though both IP's were listed everywhere, there were repeated errors about permissions and the IP's not being in the files (sis and pg_hba)... despite being there.
3. Now we have freshly loaded the machine, acting as single nic, and the following is working:
- Web Access (webmail and SAC)
- AD authentication
The following errors are showing up now that we are syncing messages and accessing SAC to enter in accounts and lists:
[root@rhel-sv-mail ~]# tail /var/opt/scalix/rl/s/logs/fatal
Last Msg Id: 027801c70871(044)2b3308c0(044)47fea8c0(a)hq.allstardirectories.com
Last Msg DirectRef: 00010172d38a860d
ERROR Browser (Service 14 ) Mon Mar 26 08:51:10 2007
[OM.MIME 4000] Browser Args :index.browse -c -o /var/opt/scalix/rl/s/temp/mime_cache/mime7CavCL 0001b20a84a2acf2
Pid of logging process: 9367
Last Msg Id: 000d01c76658(044)aff59150(044)97fea8c0(a)hq.allstardirectories.com
Last Msg DirectRef: 00017f6405975c2e
OMSHOWLOG
SERIOUS ERROR CDA Server (CDA Server ) 03.26.07 07:27:45
[OM 28664] There is already a CDA server process running
-> aud_GetSetLogConfig
<- aud_GetSetLogConfig
-> cda_DaemonMain
-> ccs_DoInitTables
-> ccs_AttemptSMem
<- ccs_AttemptSMem
<- ccs_DoInitTables
<- /build/11.0.2/src/bin/cda/cda_daemon.c:799[205,28664]
WARNING Shared memory (Shared memory ) 03.26.07 07:31:20
[OM 24142] Conversion from KSC5601 to UCS2 not found.
WARNING Shared memory (Shared memory ) 03.26.07 07:31:20
[OM 24142] Conversion from SJIS to UCS2 not found.
WARNING Remote Client (HTML Access ) 03.26.07 08:47:13
[OM 8013] The name/mailnode contains invalid characters
-> htuICE_IdentifyCmdArgs
<- htuICE_IdentifyCmdArgs
<- htuICE_ParseCommandData
-> htuICE_SetMainItemRef
-> htuICE_SetMainItemRef
-> htuICE_DoSignon
-> htuICE_GetConfig
<- htuICE_GetConfig
-> htuICE_SetProcessLang
<- htuICE_SetProcessLang
-> htuICE_ParseORNToTF
-> htuICE_GetProfile
-> htuICE_GetConfig
<- htuICE_GetConfig
<- htuICE_GetProfile
<- /build/11.0.2/src/lib/ombase/cl/cl_parse.c:379[100,8013]
ERROR Browser (Service 14 ) 03.26.07 08:51:09
[OM.MIME 4000] Browser Args :index.browse -c -o /var/opt/scalix/rl/s/temp/mime_cache/mimeYBbAhe 0001b20a84a2acf2
Last Msg Id: 000001c7239e(044)96f82c00(044)03fea8c0(a)hq.allstardirectories.com
Last Msg DirectRef: 0001058509b07095
ERROR Browser (Service 14 ) 03.26.07 08:51:10
[OM.MIME 4000] Browser Args :index.browse -c -o /var/opt/scalix/rl/s/temp/mime_cache/mime37FwbV 0001b20a84a2acf2
Last Msg Id: 1ADDE8D537076B4B85B61F74C1271C6C76B596(a)sea-mail.quardev.com
Last Msg DirectRef: 000183d66c2b95b9
ERROR Browser (Service 14 ) 03.26.07 08:51:10
[OM.MIME 4000] Browser Args :index.browse -c -o /var/opt/scalix/rl/s/temp/mime_cache/mimeuVaWvr 0001b20a84a2acf2
Last Msg Id: 027801c70871(044)2b3308c0(044)47fea8c0(a)hq.allstardirectories.com
Last Msg DirectRef: 00010172d38a860d
ERROR Browser (Service 14 ) 03.26.07 08:51:10
[OM.MIME 4000] Browser Args :index.browse -c -o /var/opt/scalix/rl/s/temp/mime_cache/mime7CavCL 0001b20a84a2acf2
Last Msg Id: 000d01c76658(044)aff59150(044)97fea8c0(a)hq.allstardirectories.com
Last Msg DirectRef: 00017f6405975c2e
WARNING Remote Client (HTML Access ) 03.26.07 08:51:29
[OM 8013] The name/mailnode contains invalid characters
-> htuICE_IdentifyCmdArgs
<- htuICE_IdentifyCmdArgs
<- htuICE_ParseCommandData
-> htuICE_SetMainItemRef
-> htuICE_SetMainItemRef
-> htuICE_DoSignon
-> htuICE_GetConfig
<- htuICE_GetConfig
-> htuICE_SetProcessLang
<- htuICE_SetProcessLang
-> htuICE_ParseORNToTF
-> htuICE_GetProfile
-> htuICE_GetConfig
<- htuICE_GetConfig
<- htuICE_GetProfile
<- /build/11.0.2/src/lib/ombase/cl/cl_parse.c:379[100,8013]
[root@rhel-sv-mail ~]# tail -n 25 /var/log/httpd/mod_jk.log
[Mon Mar 26 08:51:30 2007] [info] ajp_service::jk_ajp_common.c (1749): Sending request to tomcat failed, recoverable operation attempt=1
[Mon Mar 26 08:51:30 2007] [info] ajp_send_request::jk_ajp_common.c (1178): Socket 16 is not connected any more (errno=-1)
[Mon Mar 26 08:51:30 2007] [info] ajp_send_request::jk_ajp_common.c (1202): Error sending request. Will try another pooled connection
[Mon Mar 26 08:51:30 2007] [info] ajp_send_request::jk_ajp_common.c (1225): All endpoints are disconnected or dead
[Mon Mar 26 08:51:30 2007] [info] ajp_service::jk_ajp_common.c (1749): Sending request to tomcat failed, recoverable operation attempt=1
[Mon Mar 26 08:51:30 2007] [info] ajp_send_request::jk_ajp_common.c (1178): Socket 16 is not connected any more (errno=-1)
[Mon Mar 26 08:51:30 2007] [info] ajp_send_request::jk_ajp_common.c (1202): Error sending request. Will try another pooled connection
[Mon Mar 26 08:51:30 2007] [info] ajp_send_request::jk_ajp_common.c (1225): All endpoints are disconnected or dead
[Mon Mar 26 08:51:30 2007] [info] ajp_service::jk_ajp_common.c (1749): Sending request to tomcat failed, recoverable operation attempt=1
[Mon Mar 26 08:51:30 2007] [info] ajp_send_request::jk_ajp_common.c (1178): Socket 16 is not connected any more (errno=-1)
[Mon Mar 26 08:51:30 2007] [info] ajp_send_request::jk_ajp_common.c (1202): Error sending request. Will try another pooled connection
[Mon Mar 26 08:51:30 2007] [info] ajp_send_request::jk_ajp_common.c (1225): All endpoints are disconnected or dead
[Mon Mar 26 08:51:30 2007] [info] ajp_service::jk_ajp_common.c (1749): Sending request to tomcat failed, recoverable operation attempt=1
[Mon Mar 26 08:51:30 2007] [info] ajp_send_request::jk_ajp_common.c (1178): Socket 16 is not connected any more (errno=-1)
[Mon Mar 26 08:51:30 2007] [info] ajp_send_request::jk_ajp_common.c (1202): Error sending request. Will try another pooled connection
[Mon Mar 26 08:51:30 2007] [info] ajp_send_request::jk_ajp_common.c (1225): All endpoints are disconnected or dead
[Mon Mar 26 08:51:30 2007] [info] ajp_service::jk_ajp_common.c (1749): Sending request to tomcat failed, recoverable operation attempt=1
[Mon Mar 26 08:51:35 2007] [info] ajp_send_request::jk_ajp_common.c (1178): Socket 16 is not connected any more (errno=-1)
[Mon Mar 26 08:51:35 2007] [info] ajp_send_request::jk_ajp_common.c (1202): Error sending request. Will try another pooled connection
[Mon Mar 26 08:51:35 2007] [info] ajp_send_request::jk_ajp_common.c (1225): All endpoints are disconnected or dead
[Mon Mar 26 08:51:35 2007] [info] ajp_service::jk_ajp_common.c (1749): Sending request to tomcat failed, recoverable operation attempt=1
[Mon Mar 26 08:51:35 2007] [info] ajp_send_request::jk_ajp_common.c (1178): Socket 16 is not connected any more (errno=-1)
[Mon Mar 26 08:51:35 2007] [info] ajp_send_request::jk_ajp_common.c (1202): Error sending request. Will try another pooled connection
[Mon Mar 26 08:51:35 2007] [info] ajp_send_request::jk_ajp_common.c (1225): All endpoints are disconnected or dead
[Mon Mar 26 08:51:35 2007] [info] ajp_service::jk_ajp_common.c (1749): Sending request to tomcat failed, recoverable operation attempt=1
[root@rhel-sv-mail ~]# tail -n 25 /var/log/messages
Mar 26 07:28:46 rhel-sv-mail crond: crond startup succeeded
Mar 26 07:28:47 rhel-sv-mail startup.sh: Using CATALINA_BASE: /var/opt/scalix/rl/tomcat
Mar 26 07:28:47 rhel-sv-mail startup.sh: Using CATALINA_HOME: /opt/scalix-tomcat
Mar 26 07:28:47 rhel-sv-mail startup.sh: Using CATALINA_TMPDIR: /var/opt/scalix/rl/tomcat/temp
Mar 26 07:28:47 rhel-sv-mail startup.sh: Using JRE_HOME:
Mar 26 07:28:47 rhel-sv-mail scalix-tomcat: Starting Tomcat service (rhel-sv-mail): succeeded
Mar 26 07:28:47 rhel-sv-mail anacron: anacron startup succeeded
Mar 26 07:28:47 rhel-sv-mail atd: atd startup succeeded
Mar 26 07:28:47 rhel-sv-mail messagebus: messagebus startup succeeded
Mar 26 07:28:47 rhel-sv-mail rhnsd[3737]: Red Hat Network Services Daemon starting up.
Mar 26 07:28:47 rhel-sv-mail rhnsd: rhnsd startup succeeded
Mar 26 07:28:47 rhel-sv-mail haldaemon: haldaemon startup succeeded
Mar 26 07:28:47 rhel-sv-mail fstab-sync[4243]: removed all generated mount points
Mar 26 07:28:47 rhel-sv-mail fstab-sync[4318]: added mount point /media/cdrom for /dev/hda
Mar 26 07:30:48 rhel-sv-mail ntpd[3283]: synchronized to 164.67.62.194, stratum 1
Mar 26 07:30:48 rhel-sv-mail ntpd[3283]: kernel time sync disabled 0041
Mar 26 07:30:59 rhel-sv-mail sshd(pam_unix)[4469]: session opened for user root by root(uid=0)
Mar 26 07:36:09 rhel-sv-mail ntpd[3283]: kernel time sync enabled 0001
Mar 26 08:27:42 rhel-sv-mail clamd[3293]: No stats for Database check - forcing reload
Mar 26 08:27:42 rhel-sv-mail clamd[3293]: Reading databases from /var/clamav
Mar 26 08:27:44 rhel-sv-mail clamd[3293]: Database correctly reloaded (91196 viruses)
Mar 26 08:52:17 rhel-sv-mail sendmail[12142]: sql_select option missing
Mar 26 08:52:17 rhel-sv-mail sendmail[12142]: auxpropfunc error no mechanism available
Mar 26 08:57:19 rhel-sv-mail sshd(pam_unix)[19591]: session opened for user root by root(uid=0)
[root@rhel-sv-mail ~]# lsof -i :8009
COMMAND PID USER FD TYPE DEVICE SIZE NODE NAME
java 3694 root 30u IPv4 1298794 TCP rhel-sv-mail.allstardirectories.com:8009->rhel-sv-mail.allstardirectories.com:38755 (ESTABLISHED)
java 3694 root 37u IPv4 9592 TCP rhel-sv-mail.allstardirectories.com:8009 (LISTEN)
java 3694 root 39u IPv4 1534210 TCP rhel-sv-mail.allstardirectories.com:8009->rhel-sv-mail.allstardirectories.com:38799 (ESTABLISHED)
java 3694 root 51u IPv4 1535249 TCP rhel-sv-mail.allstardirectories.com:8009->rhel-sv-mail.allstardirectories.com:38837 (ESTABLISHED)
java 3694 root 65u IPv4 1535883 TCP rhel-sv-mail.allstardirectories.com:8009->rhel-sv-mail.allstardirectories.com:38839 (ESTABLISHED)
java 3694 root 113u IPv4 1535900 TCP rhel-sv-mail.allstardirectories.com:8009->rhel-sv-mail.allstardirectories.com:38911 (ESTABLISHED)
java 3694 root 120u IPv4 1537670 TCP rhel-sv-mail.allstardirectories.com:8009->rhel-sv-mail.allstardirectories.com:48215 (ESTABLISHED)
httpd 16690 apache 16u IPv4 1534209 TCP rhel-sv-mail.allstardirectories.com:38755->rhel-sv-mail.allstardirectories.com:8009 (ESTABLISHED)
httpd 16746 apache 16u IPv4 1535248 TCP rhel-sv-mail.allstardirectories.com:38799->rhel-sv-mail.allstardirectories.com:8009 (ESTABLISHED)
httpd 16774 apache 16u IPv4 1535899 TCP rhel-sv-mail.allstardirectories.com:38839->rhel-sv-mail.allstardirectories.com:8009 (ESTABLISHED)
httpd 16775 apache 16u IPv4 1535882 TCP rhel-sv-mail.allstardirectories.com:38837->rhel-sv-mail.allstardirectories.com:8009 (ESTABLISHED)
httpd 16876 apache 16u IPv4 1537669 TCP rhel-sv-mail.allstardirectories.com:38911->rhel-sv-mail.allstardirectories.com:8009 (ESTABLISHED)
httpd 27496 apache 16u IPv4 1755935 TCP rhel-sv-mail.allstardirectories.com:48215->rhel-sv-mail.allstardirectories.com:8009 (ESTABLISHED)
[root@rhel-sv-mail ~]#
[root@rhel-sv-mail ~]# lsof -i :25
COMMAND PID USER FD TYPE DEVICE SIZE NODE NAME
omsmtpd 4686 root 4u IPv4 10363 TCP rhel-sv-mail.allstardirectories.com:smtp (LISTEN)
[root@rhel-sv-mail ~]# tail -n 50 /var/opt/scalix/rl/tomcat/logs/catalina.2007-03-26.log
Mar 26, 2007 7:25:14 AM org.apache.catalina.connector.Connector pause
SEVERE: Protocol handler pause failed
java.net.SocketException: Network is unreachable
at java.net.PlainSocketImpl.socketConnect(Native Method)
at java.net.PlainSocketImpl.doConnect(Unknown Source)
at java.net.PlainSocketImpl.connectToAddress(Unknown Source)
at java.net.PlainSocketImpl.connect(Unknown Source)
at java.net.SocksSocketImpl.connect(Unknown Source)
at java.net.Socket.connect(Unknown Source)
at java.net.Socket.connect(Unknown Source)
at java.net.Socket.<init>(Unknown Source)
at java.net.Socket.<init>(Unknown Source)
at org.apache.jk.common.ChannelSocket.unLockSocket(ChannelSocket.java:473)
at org.apache.jk.common.ChannelSocket.pause(ChannelSocket.java:270)
at org.apache.jk.server.JkMain.pause(JkMain.java:679)
at org.apache.jk.server.JkCoyoteHandler.pause(JkCoyoteHandler.java:162)
at org.apache.catalina.connector.Connector.pause(Connector.java:1031)
at org.apache.catalina.core.StandardService.stop(StandardService.java:491)
at org.apache.catalina.core.StandardServer.stop(StandardServer.java:743)
at org.apache.catalina.startup.Catalina.stop(Catalina.java:601)
at org.apache.catalina.startup.Catalina$CatalinaShutdownHook.run(Catalina.java:644)
Mar 26, 2007 7:28:49 AM org.apache.catalina.core.AprLifecycleListener lifecycleEvent
INFO: The Apache Tomcat Native library which allows optimal performance in production environments was not found on the java.library.path: /usr/java/jre1.5.0_06/lib/i386/server:/usr/java/jre1.5.0_06/lib/i386:/usr/java/jre1.5.0_06/../lib/i386
Mar 26, 2007 7:28:49 AM org.apache.catalina.startup.Catalina load
INFO: Initialization processed in 678 ms
Mar 26, 2007 7:28:49 AM org.apache.catalina.core.StandardService start
INFO: Starting service Catalina
Mar 26, 2007 7:28:49 AM org.apache.catalina.core.StandardEngine start
INFO: Starting Servlet Engine: Apache Tomcat/5.5.16
Mar 26, 2007 7:28:49 AM org.apache.catalina.core.StandardHost start
INFO: XML validation disabled
Mar 26, 2007 7:28:53 AM org.apache.catalina.loader.WebappClassLoader validateJarFile
INFO: validateJarFile(/var/opt/scalix/rl/tomcat/webapps/caa/WEB-INF/lib/j2ee.jar) - jar not loaded. See Servlet Spec 2.3, section 9.7.2. Offending class: javax/servlet/Servlet.class
Mar 26, 2007 7:28:54 AM org.apache.jk.common.ChannelSocket init
INFO: JK: ajp13 listening on rhel-sv-mail/192.168.250.4:8009
Mar 26, 2007 7:28:54 AM org.apache.jk.server.JkMain start
INFO: Jk running ID=0 time=0/43 config=null
Mar 26, 2007 7:28:54 AM org.apache.catalina.storeconfig.StoreLoader load
INFO: Find registry server-registry.xml at classpath resource
Mar 26, 2007 7:28:54 AM org.apache.catalina.startup.Catalina start
INFO: Server startup in 5561 ms
[root@rhel-sv-mail ~]# tail -n 35 /var/opt/scalix/rl/tomcat/logs/catalina.out
Calling RichTextRun functions is likely to break things - see Bug #38544
Paragraph style ran out before character style did! Short by 90 characters.
Calling RichTextRun functions is likely to break things - see Bug #38544
Paragraph style ran out before character style did! Short by 142 characters.
Calling RichTextRun functions is likely to break things - see Bug #38544
Paragraph style ran out before character style did! Short by 1 characters.
Calling RichTextRun functions is likely to break things - see Bug #38544
No core record found with ID 5 based on PersistPtr lookup
No core record found with ID 8 based on PersistPtr lookup
No core record found with ID 9 based on PersistPtr lookup
No core record found with ID 10 based on PersistPtr lookup
No core record found with ID 11 based on PersistPtr lookup
No core record found with ID 12 based on PersistPtr lookup
No core record found with ID 13 based on PersistPtr lookup
No core record found with ID 14 based on PersistPtr lookup
No core record found with ID 15 based on PersistPtr lookup
No core record found with ID 16 based on PersistPtr lookup
No core record found with ID 17 based on PersistPtr lookup
No core record found with ID 18 based on PersistPtr lookup
No core record found with ID 19 based on PersistPtr lookup
No core record found with ID 20 based on PersistPtr lookup
No core record found with ID 21 based on PersistPtr lookup
Paragraph style ran out before character style did! Short by 169 characters.
Calling RichTextRun functions is likely to break things - see Bug #38544
Paragraph style ran out before character style did! Short by 158 characters.
Calling RichTextRun functions is likely to break things - see Bug #38544
Paragraph style ran out before character style did! Short by 3 characters.
Calling RichTextRun functions is likely to break things - see Bug #38544
Paragraph style ran out before character style did! Short by 1 characters.
Calling RichTextRun functions is likely to break things - see Bug #38544
Paragraph style ran out before character style did! Short by 101 characters.
Calling RichTextRun functions is likely to break things - see Bug #38544
Paragraph style ran out before character style did! Short by 160 characters.
Calling RichTextRun functions is likely to break things - see Bug #38544
No core record found with ID 3 based on PersistPtr lookup
[root@rhel-sv-mail ~]# ps aux | grep tomcat
root 3694 5.5 14.8 794808 617988 ? Sl 07:28 6:18 /usr/java/jre1.5.0_06/bin/java -server -Djava.net.preferIPv4Stack=true -Xms512m -Xmx512m -Dscalix.instance=/var/opt/scalix/rl -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager -Djava.util.logging.config.file=/var/opt/scalix/rl/tomcat/conf/logging.properties -Djava.endorsed.dirs=/opt/scalix-tomcat/common/endorsed -classpath /usr/java/jre1.5.0_06/lib/tools.jar:/opt/scalix-tomcat/bin/bootstrap.jar:/opt/scalix-tomcat/bin/commons-logging-api.jar -Dcatalina.base=/var/opt/scalix/rl/tomcat -Dcatalina.home=/opt/scalix-tomcat -Djava.io.tmpdir=/var/opt/scalix/rl/tomcat/temp org.apache.catalina.startup.Bootstrap start
root 26748 0.0 0.0 5244 656 pts/0 S+ 09:22 0:00 grep tomcat
