SAC was working, now can't login

[jmason1182]

I have been using SAC, webmail, etc. for about a month or two with no problems. However, now I can't get into SAC! I really can't think of a single change that has been made to the server since I first got it up and running.

So, after scouring the forums for any solutions, and trying about three or four of them, I am at a dead end.

I have verified all my ports (I am using 11. something past the RC's.... the scalix-installer set up the apache proxy stuff for tomcat, etc.... no problem until now) and I've verified my usernames. sxqueryadmin exists and has the right password, my mail administrator (not sxadmin, but mailadmin) is correct and has the right password. Also, webmail works wonderful still, as does pop3, smtp, imap, etc. etc. JUST the SAC doesn't work!

When I try to login to the SAC I get: "Could Not Login, Could not fetch configuration information. Possible problem with administration server"


So, here's 100 lines from my /var/opt/scalix/m2/tomcat/logs/scalix-caa.log (already in debug mode).

Code: Select all

2007-08-07 14:02:29,757 DEBUG [SAAJUtils.dumpHeaders:129] -----> Header user-agent:Mozilla/5.0 (X11; U; Linux i686; en-US; rv:1.8.1.5) Gecko/20070718 Fedora/2.0.0.5-1.fc7 Firefox/2.0.0.5
2007-08-07 14:02:29,757 DEBUG [SAAJUtils.dumpHeaders:129] -----> Header accept:text/xml,application/xml,application/xhtml+xml,text/html;q=0.9,text/plain;q=0.8,image/png,*/*;q=0.5
2007-08-07 14:02:29,758 DEBUG [SAAJUtils.dumpHeaders:129] -----> Header accept-language:en-us,en;q=0.5
2007-08-07 14:02:29,758 DEBUG [SAAJUtils.dumpHeaders:129] -----> Header accept-encoding:gzip,deflate
2007-08-07 14:02:29,758 DEBUG [SAAJUtils.dumpHeaders:129] -----> Header accept-charset:ISO-8859-1,utf-8;q=0.7,*;q=0.7
2007-08-07 14:02:29,759 DEBUG [SAAJUtils.dumpHeaders:129] -----> Header Keep-Alive:300
2007-08-07 14:02:29,759 DEBUG [SAAJUtils.dumpHeaders:129] -----> Header connection:keep-alive
2007-08-07 14:02:29,759 DEBUG [SAAJUtils.dumpHeaders:129] -----> Header content-type:text/xml
2007-08-07 14:02:29,760 DEBUG [SAAJUtils.dumpHeaders:129] -----> Header referer:https://scalix.mydomain.com/sac/AdminApp.jsp
2007-08-07 14:02:29,760 DEBUG [SAAJUtils.dumpHeaders:129] -----> Header content-length:435
2007-08-07 14:02:29,760 DEBUG [SAAJUtils.dumpHeaders:129] -----> Header cookie:opPrefs=wl_null%3A0%26wt_null%3A3%26btph_jmason%3A200%26wl_jmason%3A0%26wt_jmason%3A3%26ww_jmason%3A1680%26wh_jmason%3A922%26ww_scalixadmin%3A931%26wh_scalixadmin%3A541%26wl_scalixadmin%3A86%26wt_scalixadmin%3A306; OPENscalix_USER=scalixadmin(32)(47)scalix(47)CN(61)Administrator; mws_login=6da3980d6c0e1e2be10341d9c2dc187f1fbfa52a6ce4f49d66e7cc7ff9780e24
2007-08-07 14:02:29,761 DEBUG [SAAJUtils.dumpHeaders:129] -----> Header pragma:no-cache
2007-08-07 14:02:29,761 DEBUG [SAAJUtils.dumpHeaders:129] -----> Header Cache-Control:no-cache
2007-08-07 14:02:29,761 DEBUG [SAAJUtils.dumpHeaders:129] -----> Header Max-Forwards:10
2007-08-07 14:02:29,795 DEBUG [SOAPDispatcherServlet.onMessage:159] **** Start of Message Handling ****
2007-08-07 14:02:29,797 DEBUG [SOAPHelper.getElementValue:144] Found ServiceType
2007-08-07 14:02:29,798 DEBUG [CAAConfigLoader.getValue:56] Looking for config for scalix.res, key disabled found null
2007-08-07 14:02:29,798 DEBUG [SOAPHelperUtils.getSoapBodyElement:179] Body element1 CAARequestMessage = null
2007-08-07 14:02:29,798 DEBUG [SOAPHelperUtils.getSoapBodyElement:187] Body element2 ServiceType = scalix.res
2007-08-07 14:02:29,799 DEBUG [SOAPHelperUtils.getSoapBodyElement:187] Body element2 Credentials = null
2007-08-07 14:02:29,799 DEBUG [SOAPHelperUtils.getSoapBodyElement:190] Found Credentials
2007-08-07 14:02:29,799 DEBUG [SOAPHelperUtils.getCredentials:255] local name=id
2007-08-07 14:02:29,800 DEBUG [SOAPHelperUtils.getCredentials:256] qualified name=id
2007-08-07 14:02:29,800 DEBUG [SOAPHelperUtils.getCredentials:272] local name=name
2007-08-07 14:02:29,800 DEBUG [SOAPHelperUtils.getCredentials:273] qualified name=name
2007-08-07 14:02:29,801 DEBUG [SOAPHelperUtils.getCredentials:277] value=scalixadmin
2007-08-07 14:02:29,801 DEBUG [SOAPHelperUtils.getCredentials:272] local name=passwd
2007-08-07 14:02:29,801 DEBUG [SOAPHelperUtils.getCredentials:273] qualified name=passwd
2007-08-07 14:02:29,802 DEBUG [SOAPHelperUtils.getCredentials:282] value=xxxxxxxxx
2007-08-07 14:02:29,802 DEBUG [SOAPHelperUtils.getSOAPBodyElementValue:69] Body element1 CAARequestMessage = null
2007-08-07 14:02:29,802 DEBUG [SOAPHelperUtils.getSOAPBodyElementValue:77] Body element2 ServiceType = scalix.res
2007-08-07 14:02:29,803 DEBUG [SOAPHelperUtils.getSOAPBodyElementValue:77] Body element2 Credentials = null
2007-08-07 14:02:29,803 DEBUG [SOAPHelperUtils.getSOAPBodyElementValue:77] Body element2 FunctionName = GetscalixNodesList
2007-08-07 14:02:29,803 DEBUG [SOAPHelperUtils.getSOAPBodyElementValue:80] Found FunctionName
2007-08-07 14:02:29,804 DEBUG [SOAPHelperUtils.getSOAPBodyElementValue:81] value =GetscalixNodesList
2007-08-07 14:02:29,804 DEBUG [SOAPHelperUtils.getSoapBodyElement:179] Body element1 CAARequestMessage = null
2007-08-07 14:02:29,805 DEBUG [SOAPHelperUtils.getSoapBodyElement:187] Body element2 ServiceType = scalix.res
2007-08-07 14:02:29,805 DEBUG [SOAPHelperUtils.getSoapBodyElement:187] Body element2 Credentials = null
2007-08-07 14:02:29,805 DEBUG [SOAPHelperUtils.getSoapBodyElement:187] Body element2 FunctionName = GetscalixNodesList
2007-08-07 14:02:29,806 DEBUG [SOAPHelperUtils.getSoapBodyElement:187] Body element2 GetscalixNodesListParameters = null
2007-08-07 14:02:29,806 DEBUG [SOAPHelperUtils.getSoapBodyElement:200] No SoapBodyElement of type ScalixServers found.
2007-08-07 14:02:29,806 DEBUG [SOAPHelperUtils.getSOAPBodyElementValue:69] Body element1 CAARequestMessage = null
2007-08-07 14:02:29,807 DEBUG [SOAPHelperUtils.getSOAPBodyElementValue:77] Body element2 ServiceType = scalix.res
2007-08-07 14:02:29,807 DEBUG [SOAPHelperUtils.getSOAPBodyElementValue:80] Found ServiceType
2007-08-07 14:02:29,807 DEBUG [SOAPHelperUtils.getSOAPBodyElementValue:81] value =scalix.res
2007-08-07 14:02:29,808 DEBUG [SOAPHelperUtils.getSOAPBodyElementValue:69] Body element1 CAARequestMessage = null
2007-08-07 14:02:29,808 DEBUG [SOAPHelperUtils.getSOAPBodyElementValue:77] Body element2 ServiceType = scalix.res
2007-08-07 14:02:29,808 DEBUG [SOAPHelperUtils.getSOAPBodyElementValue:77] Body element2 Credentials = null
2007-08-07 14:02:29,809 DEBUG [SOAPHelperUtils.getSOAPBodyElementValue:77] Body element2 FunctionName = GetscalixNodesList
2007-08-07 14:02:29,809 DEBUG [SOAPHelperUtils.getSOAPBodyElementValue:80] Found FunctionName
2007-08-07 14:02:29,809 DEBUG [SOAPHelperUtils.getSOAPBodyElementValue:81] value =GetscalixNodesList
2007-08-07 14:02:29,811 DEBUG [CAAServiceFactory.getService:52] Looking for service called scalix.res
2007-08-07 14:02:29,811 DEBUG [CAAConfigLoader.getValue:56] Looking for config for scalix.res, key service.class found com.scalix.sac.ubermgr.caa.RESService
2007-08-07 14:02:29,812 DEBUG [SOAPDispatcherServlet.onMessage:266] Calling doRequest() on service com.scalix.sac.ubermgr.caa.RESService@508be
2007-08-07 14:02:29,812 DEBUG [CAAConfigLoader.getValue:56] Looking for config for scalix.res, key connection.mode found 1
2007-08-07 14:02:29,813 DEBUG [CAAConnectionManager.getConnection:71] Connection mode is 1
2007-08-07 14:02:29,813 DEBUG [CAAConfigLoader.getValue:56] Looking for config for scalix.res, key connection.configurator.class found com.scalix.caa.framework.CAAConnectionPoolManager
2007-08-07 14:02:29,813 DEBUG [CAAConnectionPoolManager.logConnectionPool:315] Connection pool scalix.res status: min=2,max=10,size=2,used=0
2007-08-07 14:02:29,814 DEBUG [CAAConnectionPoolManager.getFreeConnectionFromPool:129] Looking at connection 0
2007-08-07 14:02:29,814 DEBUG [CAAConnectionPoolManager.getFreeConnectionFromPool:146] Found a free connection (0) for scalix.res and endpoint http://scalix.mydomain.com/res/RESDispatcher
2007-08-07 14:02:29,815 DEBUG [CAAConnectionPoolManager.getFreeConnectionFromPool:199] Retrieved connection from pool for scalix.res and endpoint http://scalix.mydomain.com/res/RESDispatcher
2007-08-07 14:02:29,815 DEBUG [CAAConnectionPoolManager.logConnectionPool:315] Connection pool scalix.res status: min=2,max=10,size=2,used=1
2007-08-07 14:02:29,816 DEBUG [ConnectionHelperUtils.sendAndReceiveMessage:162] System is not configured to talk to scalix.mydomain.com securely, OK
2007-08-07 14:02:29,818 FATAL [RESServiceHandler.GetscalixNodesList:965] java.io.FileNotFoundException: http://scalix.mydomain.com/res/RESDispatcher:scalix.mydomain.com
java.io.FileNotFoundException: http://scalix.mydomain.com/res/RESDispatcher
        at sun.net.www.protocol.http.HttpURLConnection.getInputStream(Unknown Source)
        at java.net.URLConnection.getContent(Unknown Source)
        at com.scalix.sac.ubermgr.caa.RESConnection.receiveMessage(RESConnection.java:114)
        at com.scalix.sac.ubermgr.util.ConnectionHelperUtils.sendAndReceiveMessage(ConnectionHelperUtils.java:166)
        at com.scalix.sac.ubermgr.res.RESServiceHandler.GetscalixNodesList(RESServiceHandler.java:948)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
        at java.lang.reflect.Method.invoke(Unknown Source)
        at com.scalix.sac.ubermgr.caa.RESService.doRequest(RESService.java:109)
        at com.scalix.caa.soap.SOAPDispatcherServlet.onMessage(SOAPDispatcherServlet.java:268)
        at com.scalix.caa.soap.SAAJServlet.doPost(SAAJServlet.java:123)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:710)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:803)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:269)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:188)
        at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:210)
        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:685)
        at java.lang.Thread.run(Unknown Source)
2007-08-07 14:02:29,819 DEBUG [CAAConnectionPoolManager.freeConnection:88] Freeing a connection
2007-08-07 14:02:29,819 DEBUG [CAAConnectionPoolManager.logConnectionPool:315] Connection pool scalix.res status: min=2,max=10,size=2,used=0
2007-08-07 14:02:29,819 ERROR [GetscalixNodesList.buildResponseMessage:104] Skipping server scalix.mydomain.com. No document received!
2007-08-07 14:02:29,822 DEBUG [SAAJServlet.doPost:130] ************ Request End Success ***************
2007-08-07 14:03:02,119 DEBUG [RESMonitor.run:67] There are 1 remote servers registered
2007-08-07 14:03:02,120  INFO [RESMonitor.run:115] Server scalix.mydomain.com up 4 mins, 58 secs

While it isn't life or death to get this figured out (I have gotten to be pretty good with the om commands) I would REALLY like it!

[jmason1182]

And another thing.... when I try to go directly to http://scalix.mydomain.com/res/RESDispatcher I get a file not found error too. But, if i go to http://scalix.mydomain.com:8009/res/RESDispatcher I get an empty file.

I have not changed ANYTHING in my apache and/or ajp or jk configurations. I just know it was working fine and now it is kaput.

[dannyt]

Hi,

If you have not tried this already, it is worth running the installer again and chose to reconfigure SAC (Management Services) and RES (Management Agent). From the log it would appear that RES is not sending any heartbeat so potentially it may be talking to another server or have problem starting.

Regards,
Danny

[jmason1182]

This is my second Scalix server to setup. First I set it up on an old machine that we *supposedly* had a gig or so of RAM available to add to it. But when that turned out to be a rumour, I had no choice but to do a fresh install on a more reliable machine.

Both the first install (only had 256 MB but still ran well... but had to be restarted every night) and this second install worked perfectly until the SAC shutdown.

I tried reconfiguring both the Management Services as well as the Management Agent.
Still no change.

But here's a valid question I didn't catch until now. See, I removed my domain name from the logs of the machine in order to post them. BUT you mentioned that perhaps it is trying to talk to a different server....... well.... <enter ridiculous complexity>

I have three domain names. One is internal, two are external. I was trying to get the SMTP daemon to stop revealing my internal domain.... which is the domain my scalix server was installed under. I then added my external domains to the domain list. In order to get the SMTP daemon to reveal an external domain, I changed the hostname, /etc/hosts file, etc. (to no avail I might add).... so could the RES be considering the new hostname as an incorrect connection attempt?

[jmason1182]

Well I tried changing the hostname back, this time my scalix-tomcat didn't give me a "Service unavailable" error.... usually I have to restart apache entirely or else the tomcat server won't respond. However, the RES still isn't working.

This time I said forget the domain name changing.... so here's a raw log (caa)

Code: Select all

2007-08-09 07:44:34,094  INFO [RESMonitor.run:115] Server midsl052.masonco.local up 58 secs
2007-08-09 07:44:40,951  INFO [NotificationEventListener$WorkerThread.run:50] Event Notification: heartbeat|http://midsl052.masonco.local/res/RESDispatcher|LISTEN|300|midsl052|midsl052.masonco.local|11.1.0 from host:mail.masondrywall.com
2007-08-09 07:45:34,104  INFO [RESMonitor.run:115] Server midsl052.masonco.local up 1 mins, 58 secs
2007-08-09 07:45:40,962  INFO [NotificationEventListener$WorkerThread.run:50] Event Notification: heartbeat|http://midsl052.masonco.local/res/RESDispatcher|LISTEN|300|midsl052|midsl052.masonco.local|11.1.0 from host:midsl052.masonco.local
2007-08-09 07:46:34,114  INFO [RESMonitor.run:115] Server midsl052.masonco.local up 2 mins, 58 secs
2007-08-09 07:46:40,972  INFO [NotificationEventListener$WorkerThread.run:50] Event Notification: heartbeat|http://midsl052.masonco.local/res/RESDispatcher|LISTEN|300|midsl052|midsl052.masonco.local|11.1.0 from host:midsl052.masonco.local
2007-08-09 07:46:55,428  INFO [RESInitializer.terminate:256] Shutting down UberManager and all its threads...
2007-08-09 07:46:55,430  INFO [RESMonitor.halt:157] RESMonitor-thread Thread shutting down
2007-08-09 07:46:55,432  INFO [NotificationEventListener.cleanup:267] NotificationEventListener-Thread closing UDP socket...
2007-08-09 07:46:55,434 ERROR [NotificationEventListener.run:232] java.net.SocketException: Socket closed
2007-08-09 07:46:55,435  INFO [NotificationEventListener$WorkerThread.halt:119] com.scalix.sac.ubermgr.events.NotificationEventListener$WorkerThread-thread-0 Thread shutting down...
2007-08-09 07:46:55,436  INFO [NotificationEventListener$WorkerThread.halt:119] com.scalix.sac.ubermgr.events.NotificationEventListener$WorkerThread-thread-1 Thread shutting down...
2007-08-09 07:46:55,438  INFO [GuidToServerCache$CleanupThread.stopThread:54] com.scalix.sac.ubermgr.data.GuidToServerCache$CleanupThread-thread Shutting down...
2007-08-09 07:47:42,125  INFO [SOAPDispatcherServlet.init:77] ====> CAA is starting up, standby <====
2007-08-09 07:47:42,187  WARN [CAAConfigLoader.parseConfigDocument:224] No services are configured in this config file
2007-08-09 07:47:42,365  INFO [GuidToServerCache$CleanupThread.run:39] Guid2Server cache is empty. Skipping cleanup
2007-08-09 07:47:42,366  INFO [NotificationEventListener.launch:242] Main Notification Event Listener thread launched...
2007-08-09 07:47:42,367  INFO [NotificationEventListener.launch:245] Notification Worker thread com.scalix.sac.ubermgr.events.NotificationEventListener$WorkerThread-thread-0 launched...
2007-08-09 07:47:42,368  INFO [NotificationEventListener.launch:245] Notification Worker thread com.scalix.sac.ubermgr.events.NotificationEventListener$WorkerThread-thread-1 launched...
2007-08-09 07:47:42,371  INFO [RESInitializer.initNotificationListener:220] RESMonitor-thread Thread launched...
2007-08-09 07:47:42,382  INFO [SOAPDispatcherServlet.init:119] ====> CAA started, you may fire when ready <====
2007-08-09 07:47:43,370  INFO [NotificationEventListener$WorkerThread.run:50] Event Notification: register|http://midsl052.masonco.local/res/RESDispatcher|LISTEN|300|midsl052|midsl052.masonco.local|11.1.0 from host:midsl052.masonco.local
2007-08-09 07:47:43,405  INFO [NotificationEventListener$WorkerThread.run:50] Event Notification: register|http://midsl052.masonco.local/res/RESDispatcher|LISTEN|300|midsl052|midsl052.masonco.local|11.1.0 from host:midsl052.masonco.local
2007-08-09 07:47:48,390  INFO [NotificationEventListener$WorkerThread.run:50] Event Notification: heartbeat|http://midsl052.masonco.local/res/RESDispatcher|LISTEN|300|midsl052|midsl052.masonco.local|11.1.0 from host:midsl052.masonco.local
2007-08-09 07:48:42,390  INFO [RESMonitor.run:115] Server midsl052.masonco.local up 58 secs
2007-08-09 07:48:48,401  INFO [NotificationEventListener$WorkerThread.run:50] Event Notification: heartbeat|http://midsl052.masonco.local/res/RESDispatcher|LISTEN|300|midsl052|midsl052.masonco.local|11.1.0 from host:midsl052.masonco.local
2007-08-09 07:49:42,398  INFO [RESMonitor.run:115] Server midsl052.masonco.local up 1 mins, 58 secs
2007-08-09 07:49:48,412  INFO [NotificationEventListener$WorkerThread.run:50] Event Notification: heartbeat|http://midsl052.masonco.local/res/RESDispatcher|LISTEN|300|midsl052|midsl052.masonco.local|11.1.0 from host:midsl052.masonco.local
2007-08-09 07:49:58,540 FATAL [RESServiceHandler.executeRESCommand:2021] java.io.FileNotFoundException: http://midsl052.masonco.local/res/RESDispatcher
2007-08-09 07:49:58,541 FATAL [RESServiceHandler.executeRESCommand:2030] com.scalix.sac.ubermgr.res.RESServiceHandler:Fatal Exception raised. Check the CAA logs
2007-08-09 07:49:58,623 FATAL [RESServiceHandler.executeRESCommand:2021] java.io.FileNotFoundException: http://midsl052.masonco.local/res/RESDispatcher
2007-08-09 07:49:58,624 FATAL [RESServiceHandler.executeRESCommand:2030] com.scalix.sac.ubermgr.res.RESServiceHandler:Fatal Exception raised. Check the CAA logs
2007-08-09 07:49:58,627 FATAL [RESServiceHandler.executeRESCommand:2021] java.io.FileNotFoundException: http://midsl052.masonco.local/res/RESDispatcher
2007-08-09 07:49:58,627 FATAL [RESServiceHandler.executeRESCommand:2030] com.scalix.sac.ubermgr.res.RESServiceHandler:Fatal Exception raised. Check the CAA logs
2007-08-09 07:49:58,630 FATAL [RESServiceHandler.executeRESCommand:2021] java.io.FileNotFoundException: http://midsl052.masonco.local/res/RESDispatcher
2007-08-09 07:49:58,631 FATAL [RESServiceHandler.executeRESCommand:2030] com.scalix.sac.ubermgr.res.RESServiceHandler:Fatal Exception raised. Check the CAA logs
2007-08-09 07:49:58,633 FATAL [RESServiceHandler.executeRESCommand:2021] java.io.FileNotFoundException: http://midsl052.masonco.local/res/RESDispatcher
2007-08-09 07:49:58,634 FATAL [RESServiceHandler.executeRESCommand:2030] com.scalix.sac.ubermgr.res.RESServiceHandler:Fatal Exception raised. Check the CAA logs
2007-08-09 07:49:58,637 FATAL [RESServiceHandler.executeRESCommand:2021] java.io.FileNotFoundException: http://midsl052.masonco.local/res/RESDispatcher
2007-08-09 07:49:58,638 FATAL [RESServiceHandler.executeRESCommand:2030] com.scalix.sac.ubermgr.res.RESServiceHandler:Fatal Exception raised. Check the CAA logs
2007-08-09 07:49:58,655 FATAL [RESServiceHandler.executeRESCommand:2021] java.io.FileNotFoundException: http://midsl052.masonco.local/res/RESDispatcher
2007-08-09 07:49:58,659 FATAL [RESServiceHandler.executeRESCommand:2030] com.scalix.sac.ubermgr.res.RESServiceHandler:Fatal Exception raised. Check the CAA logs
2007-08-09 07:49:58,670 FATAL [RESServiceHandler.executeRESCommand:2021] java.io.FileNotFoundException: http://midsl052.masonco.local/res/RESDispatcher
2007-08-09 07:49:58,670 FATAL [RESServiceHandler.executeRESCommand:2030] com.scalix.sac.ubermgr.res.RESServiceHandler:Fatal Exception raised. Check the CAA logs
2007-08-09 07:49:58,673 FATAL [RESServiceHandler.executeRESCommand:2021] java.io.FileNotFoundException: http://midsl052.masonco.local/res/RESDispatcher
2007-08-09 07:49:58,674 FATAL [RESServiceHandler.executeRESCommand:2030] com.scalix.sac.ubermgr.res.RESServiceHandler:Fatal Exception raised. Check the CAA logs
2007-08-09 07:49:58,676 FATAL [RESServiceHandler.executeRESCommand:2021] java.io.FileNotFoundException: http://midsl052.masonco.local/res/RESDispatcher
2007-08-09 07:49:58,677 FATAL [RESServiceHandler.executeRESCommand:2030] com.scalix.sac.ubermgr.res.RESServiceHandler:Fatal Exception raised. Check the CAA logs
2007-08-09 07:49:58,731 FATAL [RESServiceHandler.executeRESCommand:2021] java.io.FileNotFoundException: http://midsl052.masonco.local/res/RESDispatcher
2007-08-09 07:49:58,732 FATAL [RESServiceHandler.executeRESCommand:2030] com.scalix.sac.ubermgr.res.RESServiceHandler:Fatal Exception raised. Check the CAA logs
2007-08-09 07:49:58,740  WARN [GetServerNameGenerationRules.createSOAPResponseMessage:102] Skipping server midsl052.masonco.local no document received.
2007-08-09 07:49:58,802 FATAL [RESServiceHandler.executeRESCommand:2021] java.io.FileNotFoundException: http://midsl052.masonco.local/res/RESDispatcher
2007-08-09 07:49:58,803 FATAL [RESServiceHandler.executeRESCommand:2030] com.scalix.sac.ubermgr.res.RESServiceHandler:Fatal Exception raised. Check the CAA logs
2007-08-09 07:49:58,806  WARN [GetServerMailAddressGenerationRules.createSOAPResponseMessage:96] Skipping server midsl052.masonco.local no document received.
2007-08-09 07:49:58,870 FATAL [RESServiceHandler.executeRESCommand:2021] java.io.FileNotFoundException: http://midsl052.masonco.local/res/RESDispatcher
2007-08-09 07:49:58,871 FATAL [RESServiceHandler.executeRESCommand:2030] com.scalix.sac.ubermgr.res.RESServiceHandler:Fatal Exception raised. Check the CAA logs
2007-08-09 07:49:58,874  WARN [GetPasswordSettings.createSOAPResponseMessage:108] Skipping server midsl052.masonco.local no document received.
2007-08-09 07:49:58,951 FATAL [RESServiceHandler.GetMailNodesList:965] java.io.FileNotFoundException: http://midsl052.masonco.local/res/RESDispatcher:midsl052.masonco.local
java.io.FileNotFoundException: http://midsl052.masonco.local/res/RESDispatcher
        at sun.net.www.protocol.http.HttpURLConnection.getInputStream(Unknown Source)
        at java.net.URLConnection.getContent(Unknown Source)
        at com.scalix.sac.ubermgr.caa.RESConnection.receiveMessage(RESConnection.java:114)
        at com.scalix.sac.ubermgr.util.ConnectionHelperUtils.sendAndReceiveMessage(ConnectionHelperUtils.java:166)
        at com.scalix.sac.ubermgr.res.RESServiceHandler.GetMailNodesList(RESServiceHandler.java:948)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
        at java.lang.reflect.Method.invoke(Unknown Source)
        at com.scalix.sac.ubermgr.caa.RESService.doRequest(RESService.java:109)
        at com.scalix.caa.soap.SOAPDispatcherServlet.onMessage(SOAPDispatcherServlet.java:268)
        at com.scalix.caa.soap.SAAJServlet.doPost(SAAJServlet.java:123)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:710)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:803)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:269)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:188)
        at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:210)
        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:685)
        at java.lang.Thread.run(Unknown Source)
2007-08-09 07:49:58,954 ERROR [GetMailNodesList.buildResponseMessage:104] Skipping server midsl052.masonco.local. No document received!




[jmason1182]

What other logs can I look at?

And if I may subject a small constructive criticism... while the SAC is FABULOUS and all, it would be great to have a true "LOGS" directory.... even if it was just a directory of symlinks to the real logs for every part of the system. That way someone can figure out what's wrong with the SMTP relay, the CAA, the SWA, the Print Daemon.... all in one directory.

[jmason1182]

Another quick question, my tomcat configuration files all say:

ProxyPass /res ajp://midsl052.masonco.local:8009/res

(with each respective /res, /api, /caa, etc.) I look in my apache error logs and it says that midsl052.masonco.local/res does not exist....

Also, my instance-midsl052.conf only has port 80 and port 443 used....

So is my port stuff an issue? I used the scalix-install command to install and so I never had to mess with the ports. But the ~/res/config/res.properties file has no port listed for tomcat port.

[jmason1182]

And on that note, apache is reporting this every ten seconds:

[Mon Aug 06 19:18:49 2007] [error] [client 10.20.20.52] File does not exist: /var/www/html/sis

[jmason1182]

I just noticed that no mail was received today... that is bad.... it means that the scalix server isn't working at all!

My backup server sends me logs every night about the backup.... I see on the backup server the sendmail logs say the mail was sent. Same here on this box... maillog says the mail was received. But when I check my mail, no mail is in my inbox!

[jmason1182]

Now that my SMTPD debug logs have been running for a little bit, here's the logs:

[2007-08-09 09:01:14] Logging Started pid 29793
[2007-08-09 09:01:14] SMTP Relay 11.1.0.10849 started (29793): Thu, 09 Aug 2007 09:01:14 -0500 (CDT) for SMTP
[2007-08-09 09:01:17] Accepted client 1 from ()
[2007-08-09 09:01:17] Cli 29793/1 sent :
220 midsl052.masonco.local ESMTP Scalix SMTP Relay 11.1.0.10849; Thu, 09 Aug 2007 09:01:17 -0500 (CDT)
[2007-08-09 09:01:26] Cli 29793/1 failed: Internal error
[2007-08-09 09:01:56] Accepted client 1 from ()
[2007-08-09 09:01:56] Cli 29793/1 sent :
220 midsl052.masonco.local ESMTP Scalix SMTP Relay 11.1.0.10849; Thu, 09 Aug 2007 09:01:56 -0500 (CDT)
[2007-08-09 09:01:56] Cli 29793/1 failed: Internal error
[2007-08-09 09:02:40] Accepted client 1 from ()
[2007-08-09 09:02:40] Cli 29793/1 sent :
220 midsl052.masonco.local ESMTP Scalix SMTP Relay 11.1.0.10849; Thu, 09 Aug 2007 09:02:40 -0500 (CDT)
[2007-08-09 09:02:40] Cli 29793/1 failed: Internal error
[2007-08-09 09:03:18] Accepted client 1 from ()
[2007-08-09 09:03:18] Cli 29793/1 sent :
220 midsl052.masonco.local ESMTP Scalix SMTP Relay 11.1.0.10849; Thu, 09 Aug 2007 09:03:18 -0500 (CDT)
[2007-08-09 09:03:18] Cli 29793/1 failed: Internal error
[2007-08-09 09:03:51] Accepted client 1 from ()
[2007-08-09 09:03:51] Cli 29793/1 sent :
220 midsl052.masonco.local ESMTP Scalix SMTP Relay 11.1.0.10849; Thu, 09 Aug 2007 09:03:51 -0500 (CDT)
[2007-08-09 09:03:51] Cli 29793/1 failed: Internal error
[2007-08-09 09:04:37] Accepted client 1 from ()
[2007-08-09 09:04:37] Cli 29793/1 sent :
220 midsl052.masonco.local ESMTP Scalix SMTP Relay 11.1.0.10849; Thu, 09 Aug 2007 09:04:37 -0500 (CDT)
[2007-08-09 09:04:37] Cli 29793/1 failed: Internal error
[2007-08-09 09:05:23] Accepted client 1 from ()
[2007-08-09 09:05:23] Cli 29793/1 sent :
220 midsl052.masonco.local ESMTP Scalix SMTP Relay 11.1.0.10849; Thu, 09 Aug 2007 09:05:23 -0500 (CDT)
[2007-08-09 09:05:23] Cli 29793/1 rcvd: 'EHLO HAPPY'
[2007-08-09 09:05:23] Cli 29793/1 sent :
250-midsl052.masonco.local Hello [125.143.12.97], pleased to meet you
250-AUTH LOGIN PLAIN CRAM-MD5 DIGEST-MD5 GSSAPI
250-AUTH=LOGIN
250-DSN
250 8BITMIME
[2007-08-09 09:05:24] Cli 29793/1 rcvd: 'MAIL FROM: <glcxoyaagwt@rrmediainc.com>'
[2007-08-09 09:05:24] Cli 29793/1 sent :
250 glcxoyaagwt@rrmediainc.com... Sender ok
[2007-08-09 09:05:24] Cli 29793/1 rcvd: 'RCPT TO: <<<<<<email ommitted>>>>>>>>>>'
[2007-08-09 09:05:24] ... new process 29843
[2007-08-09 09:05:24] 29793: Allocate new sendmail process 29843
[2007-08-09 09:05:24] Cli 29793/1 rcvd S: '220 midsl052.masonco.local ESMTP Sendmail 8.13.8/8.13.8/Submit; Thu, 9 Aug 2007 09:05:24 -0500'
[2007-08-09 09:05:25] Cli 29793/1 rcvd S: '250 2.1.0 <glcxoyaagwt@rrmediainc.com>... Sender ok'
[2007-08-09 09:05:25] Cli 29793/1 sent S:
rcpt to: <<<<<<email ommitted>>>>>>>>>>
[2007-08-09 09:05:25] Cli 29793/1 rcvd S: '250 2.1.5 <<<<<<email ommitted>>>>>>>>>>... Recipient ok'
[2007-08-09 09:05:25] Cli 29793/1 sent :
250 2.1.5 <<<<<<email ommitted>>>>>>>>>>... Recipient ok
[2007-08-09 09:05:25] Cli 29793/1 rcvd: 'DATA'
[2007-08-09 09:05:25] Cli 29793/1 sent :
354 Enter mail, end with "." on a line by itself (relay)
[2007-08-09 09:05:25] Cli 29793/1 sent S:
data
[2007-08-09 09:05:25] Cli 29793/1 rcvd S: '354 Enter mail, end with "." on a line by itself'
[2007-08-09 09:05:25] Cli 29793/1 sent S:

<<<<message ommitted>>>>>>>

[2007-08-09 09:05:27] Cli 29793/1 rcvd S: '250 2.0.0 l79E5ONr029843 Message accepted for delivery'
[2007-08-09 09:05:27] Cli 29793/1: Submitted message ': <74692540839957.7BA9840D61@SN1SQ19>' to sendmail.
response: '250 2.0.0 l79E5ONr029843 Message accepted for delivery'
[2007-08-09 09:05:27] Cli 29793/1 Finished submitting msg : <74692540839957.7BA9840D61@SN1SQ19>
[2007-08-09 09:05:27] Cli 29793/1 sent :
250 2.0.0 l79E5ONr029843 Message accepted for delivery
[2007-08-09 09:05:27] Cli 29793/1 rcvd: 'QUIT'
[2007-08-09 09:05:27] Cli 29793/1 sent :
221 midsl052.masonco.local closing connection
[2007-08-09 09:13:28] Accepted client 1 from ()
[2007-08-09 09:13:28] Cli 29793/1 failed: Internal error

[jmason1182]

And in my /var/log/maillog I get the following for EVERY message that is received:

Code: Select all

Aug  9 09:24:58 mail sendmail[30667]: l79EOvbG030667: SYSERR(root): ldap_init/ldap_bind failed to localhost in map ldapsx: Unknown error 325


I tried restarting sendmail itself, but it didn't solve anything.


Feel free to use IMAP, POP3, or telnet to connect to our external mail domain: mail.masondrywall.com.

[jmason1182]

And because I've seen it on other posts, here's omshowlog:

Code: Select all

WARNING                        Internet Mail (Incoming      ) 08.05.07 20:31:36
[OM.UX 1401] Cannot read message data.
        <- inet_ConvArpaORNToORN
        -> nm_ParseORN
        <- nm_ParseORN
        -> nm_PutFieldStr
        -> nm_PutFieldMem
        -> nm_UpdateFieldMem
        <- nm_UpdateFieldMem
        <- nm_PutFieldMem
        <- nm_PutFieldStr
        <- ux_InConvArpaORNToORN
        -> im_GetNewItemNum
        <- im_GetNewItemNum
        -> ux_InReadMailText
        <- /build/11.1.0/src/bin/ux/ux_in.c:1120[102,1401]
        <- /build/11.1.0/src/bin/ux/ux_in.c:4625[102,1401]
        <- /build/11.1.0/src/bin/ux/ux_in.c:2013[102,1401]


WARNING                        Shared memory (Shared memory ) 08.07.07 12:57:36
[OM 24142] Conversion from ISO2022CN to UCS2 not found.


WARNING                        Shared memory (Shared memory ) 08.07.07 12:57:36
[OM 24142] Conversion from KSC5601 to UCS2 not found.


WARNING                        Shared memory (Shared memory ) 08.07.07 13:53:09
[OM 24142] Conversion from ISO2022CN to UCS2 not found.


WARNING                        Shared memory (Shared memory ) 08.07.07 13:53:09
[OM 24142] Conversion from KSC5601 to UCS2 not found.


WARNING                        Shared memory (Shared memory ) 08.07.07 13:57:13
[OM 24142] Conversion from ISO2022CN to UCS2 not found.


WARNING                        Shared memory (Shared memory ) 08.07.07 13:57:13
[OM 24142] Conversion from KSC5601 to UCS2 not found.


SERIOUS ERROR                  POP3 interface(POP3 Process  ) 08.07.07 17:20:27
[OM 10270] Process about to terminate due to error.
Signal (Segmentation Violation) trapped by process 2153
Procedure trace follows:
  -> ul_CloseUL
  <- ul_CloseUL
  -> ul_CloseUL
  <- ul_CloseUL
  -> ul_OpenUL
  <- ul_OpenUL
  -> ul_utGetUserEntryById
  -> dr_ACIModContextFlags
  <- dr_ACIModContextFlags
  -> dr_ACICheckReadPerm
  <- dr_ACICheckReadPerm
  -> dr_ACIModContextFlags
  <- dr_ACIModContextFlags
  <- ul_utGetUserEntryById
  -> ul_CloseUL
  <- ul_CloseUL


SERIOUS ERROR                  POP3 interface(POP3 Process  ) 08.07.07 17:20:27
[OM 10272] BACKTRACE:
/opt/scalix/lib/libom_er.so(er_add_backtrace+0xb3)[0xfd2dc3]
/opt/scalix/lib/libom_er.so[0xfd30ac]
/opt/scalix/lib/libom_er.so(er_DumpProcAndExit+0x1f)[0xfd323f]
[0x9df420]
/lib/libc.so.6(_IO_vfprintf+0x8f)[0x80a188]
/lib/libc.so.6(vsnprintf+0xae)[0x82bd8f]
/opt/scalix/lib/libom_pam.so(pam_vsyslog+0x39)[0x361fc5]
/lib/libpam.so.0(pam_syslog+0x35)[0x60b805]
/lib/security/pam_unix.so[0xc91308]
/lib/security/pam_unix.so(pam_sm_authenticate+0x2d8)[0xc8dd78]
/opt/scalix/lib/libom_pam.so[0x35eecb]
/opt/scalix/lib/libom_pam.so(_pam_dispatch+0x1ca)[0x35f1f0]
/opt/scalix/lib/libom_pam.so(pam_authenticate+0x71)[0x35e6fd]
/opt/scalix/lib/libom_signon.so(signon_CheckSignon+0xc8)[0x377f20]
/opt/scalix/lib/libom_signon.so[0x378920]
/opt/scalix/lib/libom_signon.so(signon_SignOn+0x1d9)[0x379047]
pop3.server[0x8054875]
pop3.server[0x804be1e]
pop3.server[0x8051f01]
pop3.server[0x8052240]
pop3.server[0x80526b6]
pop3.server[0x8052b57]
/lib/libpthread.so.0[0x63d3b6]
/lib/libc.so.6(__clone+0x5e)[0x89833e]


WARNING                        Shared memory (Shared memory ) 08.09.07 07:46:44
[OM 24142] Conversion from ISO2022CN to UCS2 not found.


WARNING                        Shared memory (Shared memory ) 08.09.07 07:46:44
[OM 24142] Conversion from KSC5601 to UCS2 not found.


ERROR                          Administration(Scalix Admin C) 08.09.07 07:59:35
[SYS 2] No such file or directory
Current errno value: 2
        <- /build/11.1.0/src/lib/ombase/os/os_stat.c:58[1,2]


ERROR                          Administration(Scalix Admin C) 08.09.07 08:01:37
[SYS 2] No such file or directory
Current errno value: 2
        <- /build/11.1.0/src/lib/ombase/os/os_stat.c:58[1,2]


WARNING                        Shared memory (Shared memory ) 08.09.07 08:15:44
[OM 24142] Conversion from ISO2022CN to UCS2 not found.


WARNING                        Shared memory (Shared memory ) 08.09.07 08:15:44
[OM 24142] Conversion from KSC5601 to UCS2 not found.


And I only have like 12 users, all using thunderbird via IMAP, and a few using SWA. BUT like I've mentioned before, we had absolutely no problems prior to about the 5th of August or so. I just know that I used the SAC on Friday the 3rd and it was all great. Then, on Monday the 6th I tried to get in and it has not been up since.

[jmason1182]

And another post suggested running sendmail -bt to make sure that sendmail isn't an issue.... of course it is.

sendmail -bt gives me:

Code: Select all

> 3,0 myemail@masonco.local
canonify           input: myemail @ masonco . local
Canonify2          input: myemail < @ masonco . local >
Canonify2        returns: myemail < @ masonco . local . >
canonify         returns: myemail < @ masonco . local . >
parse              input: myemail < @ masonco . local . >
Parse0             input: myemail < @ masonco . local . >
Parse0           returns: myemail < @ masonco . local . >
ParseLocal         input: myemail < @ masonco . local . >
ScalixMapper       input: < myemail < @ masonco . local . > > < myemail @ masonco . local >
ldap_init/ldap_bind failed to localhost in map ldapsx: Unknown error 325
ScalixMapper     returns: myemail < @ masonco . local . >
ParseLocal       returns: myemail < @ masonco . local . >
Parse1             input: myemail < @ masonco . local . >
Parse1           returns: $# local $: myemail
parse            returns: $# local $: myemail
== Ruleset 0 (0) status 75
> 3,0 bogus@masonco.local
canonify           input: bogus @ masonco . local
Canonify2          input: bogus < @ masonco . local >
Canonify2        returns: bogus < @ masonco . local . >
canonify         returns: bogus < @ masonco . local . >
parse              input: bogus < @ masonco . local . >
Parse0             input: bogus < @ masonco . local . >
Parse0           returns: bogus < @ masonco . local . >
ParseLocal         input: bogus < @ masonco . local . >
ScalixMapper       input: < bogus < @ masonco . local . > > < bogus @ masonco . local >
ScalixMapper     returns: bogus < @ masonco . local . >
ParseLocal       returns: bogus < @ masonco . local . >
Parse1             input: bogus < @ masonco . local . >
Parse1           returns: $# local $: bogus
parse            returns: $# local $: bogus
== Ruleset 0 (0) status 75


So bogus emails are seen the same as myemail.... and notice the one that is looking up myemail has that ldap_init/ldap_bind failure....... whereas the bogus one does not.

To test a theory... I checked to make sure that the ldap was listening:

Code: Select all

[root@midsl052 s]# lsof -i:389
COMMAND   PID USER   FD   TYPE DEVICE SIZE NODE NAME
omslapd 27456 root    8u  IPv4 459916       TCP *:ldap (LISTEN)
omslapd 27456 root    9u  IPv4 463263       TCP midsl052.masonco.local:ldap->midsl052.masonco.local:51657 (ESTABLISHED)
omslapd 27456 root   11u  IPv4 463466       TCP midsl052.masonco.local:ldap->midsl052.masonco.local:40197 (ESTABLISHED)
java    27711 root   54u  IPv4 463262       TCP midsl052.masonco.local:51657->midsl052.masonco.local:ldap (ESTABLISHED)
java    27711 root   56u  IPv4 463465       TCP midsl052.masonco.local:40197->midsl052.masonco.local:ldap (ESTABLISHED)


So there goes that theory.... ldap is listening just fine.

[jmason1182]

OK, somewhere someone should have said something about ldapmapper.... I restarted it and now my sendmail is going great... I think.... and now I have confirmed it.

In-going mail and out-going mail are now flowing normally. Internal mail is also being handled.


So now... I still can't get into the SAC. is there a log file I'm missing? Perhaps a service outside of scalix I'm missing? (Kinda like the ldap-mapper service)

[jmason1182]

SIDENOTE: Someone should mention to the scalix-install script people that ldapmapper isn't run on startup..... it was needed for my sendmail to run and the scalix processes have been running ok... but I had to do a manual

Code: Select all

chkconfig --list ldapmapper

In order to make sure that ldapmapper is running on server reboot!