Address Search error

[kaosfury]

Whenever we try to search for address, either by clicking on the address book or setting permissions on a calendar, we get "An error has occurred. Contact your *garbled* administrator if the problem persists. #AS020"

Scalix Web Access version 11.4.3.11863
Platform Version 11.4.3.2239
Server Version 11.4.3.12339

[schmoe90]

What's in the tomcat logs when this happens?

[kaosfury]

I logged in to swa and ran a search. There were only two logs that changed at that time:

scalix-caa.log
2009-03-25 09:42:59,324 INFO [NotificationEventListener$WorkerThread.run:51] Event Notification: heartbeat|http://hidden.scalixserver.com/res/RESDispatcher|LISTEN|300|scalix|hidden.scalixserver.com|11.4.3 from host:hidden.scalixserver.com
2009-03-25 09:43:01,275 INFO [RESMonitor.run:115] Server hidden.scalixserver.com up 28 days, 17 hrs, 29 mins, 1 secs
2009-03-25 09:43:59,327 INFO [NotificationEventListener$WorkerThread.run:51] Event Notification: heartbeat|http://hidden.scalixserver.com/res/RESDispatcher|LISTEN|300|scalix|hidden.scalixserver.com|11.4.3 from host:hidden.scalixserver.com
2009-03-25 09:44:01,278 INFO [RESMonitor.run:115] Server hidden.scalixserver.com up 28 days, 17 hrs, 30 mins, 1 secs
2009-03-25 09:44:59,329 INFO [NotificationEventListener$WorkerThread.run:51] Event Notification: heartbeat|http://hidden.scalixserver.com/res/RESDispatcher|LISTEN|300|scalix|hidden.scalixserver.com|11.4.3 from host:hidden.scalixserver.com
2009-03-25 09:45:01,281 INFO [RESMonitor.run:115] Server hidden.scalixserver.com up 28 days, 17 hrs, 31 mins, 1 secs
2009-03-25 09:45:59,333 INFO [NotificationEventListener$WorkerThread.run:51] Event Notification: heartbeat|http://hidden.scalixserver.com/res/RESDispatcher|LISTEN|300|scalix|hidden.scalixserver.com|11.4.3 from host:hidden.scalixserver.com
2009-03-25 09:46:01,285 INFO [RESMonitor.run:115] Server hidden.scalixserver.com up 28 days, 17 hrs, 32 mins, 1 secs
2009-03-25 09:46:59,336 INFO [NotificationEventListener$WorkerThread.run:51] Event Notification: heartbeat|http://hidden.scalixserver.com/res/RESDispatcher|LISTEN|300|scalix|hidden.scalixserver.com|11.4.3 from host:hidden.scalixserver.com
2009-03-25 09:47:01,288 INFO [RESMonitor.run:115] Server hidden.scalixserver.com up 28 days, 17 hrs, 33 mins, 1 secs

scalix-sis-indexer.log
2009-03-24 15:28:17,171 INFO [QueueManager] [BatchUpdater.processMods:149] User 0f120000d1a71294-4.09.54.321: added 1 content, added 1 refs, deleted 1 content, deleted 2 refs in 29 ms
2009-03-24 15:31:16,488 INFO [QueueManager] [BatchUpdater.processMods:149] User 0f120000d1a71294-4.09.54.321: added 1 content, added 1 refs, deleted 1 content, deleted 2 refs in 66 ms
2009-03-24 15:34:15,723 INFO [QueueManager] [BatchUpdater.processMods:149] User 0f120000d1a71294-4.09.54.321: added 1 content, added 1 refs, deleted 1 content, deleted 2 refs in 30 ms
2009-03-24 15:37:21,919 INFO [QueueManager] [BatchUpdater.processMods:149] User 05320000d1a71294-4.09.54.321: added 0 content, added 0 refs, deleted 0 content, deleted 2 refs in 17 ms
2009-03-24 15:38:17,554 WARN [TP-Processor89] [IndexableMimeMessage.addContent:346] No extractor could be found to process message content with type text/x-vcard
2009-03-24 15:38:32,614 INFO [QueueManager] [BatchUpdater.processMods:149] User 05320000d1a71294-4.09.54.321: added 1 content, added 1 refs, deleted 0 content, deleted 1 refs in 58 ms
2009-03-25 07:51:57,767 INFO [QueueManager] [BatchUpdater.processMods:149] User 0b420000d1a71294-4.09.54.321: added 0 content, added 0 refs, deleted 0 content, deleted 2 refs in 9 ms
2009-03-25 09:06:10,877 INFO [QueueManager] [BatchUpdater.processMods:149] User 0b420000d1a71294-4.09.54.321: added 1 content, added 1 refs, deleted 1 content, deleted 2 refs in 410 ms
2009-03-25 09:42:00,787 INFO [QueueManager] [BatchUpdater.processMods:149] User 05320000d1a71294-4.09.54.321: added 0 content, added 0 refs, deleted 0 content, deleted 2 refs in 12 ms
2009-03-25 09:47:19,043 INFO [QueueManager] [BatchUpdater.processMods:149] User 05320000d1a71294-4.09.54.321: added 0 content, added 0 refs, deleted 0 content, deleted 2 refs in 2 ms

[schmoe90]

Nothing useful there. What does "*garbled*" actually show?

[kaosfury]

I can't tell. It's garbled.

[kaosfury]

I have a lot of logs I could go through, but no idea where to start. I checked the logs that changed after I attempted a search, scalix-api.log, scalix-swa.log, and scalix-caa.log. I have the following error in the api log if that helps:

2009-03-25 10:51:30,144 ERROR [Directory.getAttributesBySmtpAddress:85] Naming exception! ProviderURL=ldap://blanked.blanked.com:389
javax.naming.AuthenticationException: [LDAP: error code 49 - Invalid Credentials]

[schmoe90]

Check that the sxqueryadmin user isn't locked.

[kaosfury]

Code: Select all

# omshowu -n sxqueryadmin
Authentication ID: sxqueryadmin@hidden.com
Globally Unique ID: 11100000d1a71294-4.09.54.321
User Name : sxqueryadmin /CN=sxqueryadmin
MailNode : scalix
Internet Address : sxqueryadmin-scalix@hidden.com
System Login : 60535
Password : set
Admin Capabilities : YES
Mailbox Admin Capabilities : NO
Language : C
Mail Account: Unlocked
Last Signon : Never.
Receipt of mail : ENABLED
Service level : 0
Excluded from Tidying : NO
Recovery Folder visible : NO
User Class : Limited
SIS URL : sxidx://hidden.com/01100000d1a71294-4.09.54.321


Doesn't look like it.

[LeslieW]

Since you're not seeing anything in the Tomcat logs it looks like things on the desktop are working okay.

Try enabling logging in log4j.properties; set the following lines to DEBUG:
log4j.rootLogger
log4j.logger.SWA
log4j.logger.SWA-ACTIVITY

Then restart Tomcat (may not be necessary but let's do it just to be sure).
Then repeat your test of duplicating the error and immediately checking the Tomcat logs for updates.
Remember to set your logging back the way it was after duplicating the error

[kaosfury]

Which log4j.properties should I be editing? I find 14 total files with that name.

[kaosfury]

This is from scalix-api.log:

2009-04-01 14:30:08,648 ERROR [Directory.getAttributesBySmtpAddress:85] Naming exception! ProviderURL=ldap://scalix.hide.com:389
javax.naming.AuthenticationException: [LDAP: error code 49 - Invalid Credentials]
at com.sun.jndi.ldap.LdapCtx.mapErrorCode(Unknown Source)
at com.sun.jndi.ldap.LdapCtx.processReturnCode(Unknown Source)
at com.sun.jndi.ldap.LdapCtx.processReturnCode(Unknown Source)
at com.sun.jndi.ldap.LdapCtx.connect(Unknown Source)
at com.sun.jndi.ldap.LdapCtx.<init>(Unknown Source)
at com.sun.jndi.ldap.LdapCtxFactory.getUsingURL(Unknown Source)
at com.sun.jndi.ldap.LdapCtxFactory.getUsingURLs(Unknown Source)
at com.sun.jndi.ldap.LdapCtxFactory.getLdapCtxInstance(Unknown Source)
at com.sun.jndi.ldap.LdapCtxFactory.getInitialContext(Unknown Source)
at javax.naming.spi.NamingManager.getInitialContext(Unknown Source)
at javax.naming.InitialContext.getDefaultInitCtx(Unknown Source)
at javax.naming.InitialContext.init(Unknown Source)
at javax.naming.InitialContext.<init>(Unknown Source)
at javax.naming.directory.InitialDirContext.<init>(Unknown Source)
at com.scalix.api.directory.Directory.getAttributesBySmtpAddress(Directory.java:53)
at com.scalix.api.rest.ResolvePrincipalInterceptor.preHandle(ResolvePrincipalInterceptor.java:44)
at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:829)
at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:774)
at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:460)
at com.scalix.api.PlatformDispatcherServlet.service(PlatformDispatcherServlet.java:74)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:729)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:269)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:188)
at org.springframework.web.filter.AbstractRequestLoggingFilter.doFilterInternal(AbstractRequestLoggingFilter.java:133)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:75)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:215)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:188)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:213)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:172)
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:174)
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)

[kaosfury]

bump

[kaosfury]

bump

[kaosfury]

Could this have anything to do with our problems?

INFO: validateJarFile(/var/opt/scalix/sx/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