I’ve been working at getting Solr working under Tomcat, and spent most of a day working on fixing these problems. The fixes didn’t take so much time as the trying to grok the Java app ecosystem.

My Solr install worked well. I was able to import records and search them through the interface. Where I ran into trouble was with the Velocity search browser that comes with Solr.

I’m documenting my troubles and their solutions here because otherwise they won’t exist on the web for people to find. Putting solutions to problems on the web makes them findable for the next poor guy who has the same problem. I figure that if I spend a day working on fixing problems, I can spend another hour publishing them so others can benefit.

These are for Solr 3.5 running under Tomcat 6.0.24.

Unable to open velocity.log

Velocity tries to create a file velocity.log and gets a permission failure.

HTTP Status 500 - org.apache.velocity.exception.VelocityException:
Failed to initialize an instance of
org.apache.velocity.runtime.log.Log4JLogChute with the current
runtime configuration. java.lang.RuntimeException:
org.apache.velocity.exception.VelocityException: Failed to initialize
an instance of org.apache.velocity.runtime.log.Log4JLogChute with
the current runtime configuration. at
...
Caused by: java.io.FileNotFoundException: velocity.log
(Permission denied) at java.io.FileOutputStream.openAppend(Native
Method) at java.io.FileOutputStream.<init>(FileOutputStream.java:207)
...

But where is it trying to create the file? What directory? Since no pathname was specified, it seemed that the file would be created in the current working directory of Tomcat. What would that be?

First I had to figure out what process that Tomcat was running as:

frisbee:~ $ ps aux | grep tomcat
tomcat     498  0.6  1.3 6240056 214880 ?      Sl   09:27   0:10 /usr/lib/jvm/java/bin/java ....

In this case, it’s PID 498. So we go to the /proc/498 directory and see what’s in there.

frisbee:~ $ cd /proc/498
frisbee:/proc/498 $ ls -al
ls: cannot read symbolic link cwd: Permission denied
ls: cannot read symbolic link root: Permission denied
ls: cannot read symbolic link exe: Permission denied
total 0
dr-xr-xr-x   7 tomcat tomcat 0 May 22 09:27 ./
dr-xr-xr-x 173 root   root   0 May 17 11:33 ../
dr-xr-xr-x   2 tomcat tomcat 0 May 22 09:58 attr/
-rw-r--r--   1 tomcat tomcat 0 May 22 09:58 autogroup
-r--------   1 tomcat tomcat 0 May 22 09:58 auxv
-r--r--r--   1 tomcat tomcat 0 May 22 09:58 cgroup
--w-------   1 tomcat tomcat 0 May 22 09:58 clear_refs
-r--r--r--   1 tomcat tomcat 0 May 22 09:56 cmdline
-rw-r--r--   1 tomcat tomcat 0 May 22 09:58 coredump_filter
-r--r--r--   1 tomcat tomcat 0 May 22 09:58 cpuset
lrwxrwxrwx   1 tomcat tomcat 0 May 22 09:58 cwd
...

We can see that cwd is a symlink to a directory, but we have to be root to see what the target directory is. I have to run ls again as root.

frisbee:/proc/498 $ sudo ls -al
[sudo] password for alester:
total 0
dr-xr-xr-x   7 tomcat tomcat 0 May 22 09:27 .
dr-xr-xr-x 174 root   root   0 May 17 11:33 ..
dr-xr-xr-x   2 tomcat tomcat 0 May 22 09:58 attr
-rw-r--r--   1 tomcat tomcat 0 May 22 09:58 autogroup
-r--------   1 tomcat tomcat 0 May 22 09:58 auxv
-r--r--r--   1 tomcat tomcat 0 May 22 09:58 cgroup
--w-------   1 tomcat tomcat 0 May 22 09:58 clear_refs
-r--r--r--   1 tomcat tomcat 0 May 22 09:56 cmdline
-rw-r--r--   1 tomcat tomcat 0 May 22 09:58 coredump_filter
-r--r--r--   1 tomcat tomcat 0 May 22 09:58 cpuset
lrwxrwxrwx   1 tomcat tomcat 0 May 22 09:58 cwd -> /usr/share/tomcat6

I could also have used the stat command.

frisbee:/proc/498 $ sudo stat cwd
File: `cwd' -> `/usr/share/tomcat6'
Size: 0               Blocks: 0          IO Block: 1024   symbolic link
Device: 3h/3d   Inode: 100017      Links: 1
Access: (0777/lrwxrwxrwx)  Uid: (   91/  tomcat)   Gid: (   91/  tomcat)
Access: 2012-05-22 09:58:17.131009458 -0500
Modify: 2012-05-22 09:58:17.130009715 -0500
Change: 2012-05-22 09:58:17.130009715 -0500

So we find that the CWD is /usr/share/tomcat6. I don’t want the tomcat user to have rights to that directory, so instead I create a velocity.log file in a proper log directory and then symlink to it.

frisbee:/proc/498 $ cd /var/log/tomcat6
frisbee:/var/log/tomcat6 $ sudo touch velocity.log
frisbee:/var/log/tomcat6 $ sudo chown tomcat:tomcat velocity.log
frisbee:/var/log/tomcat6 $ cd /usr/share/tomcat6
frisbee:/usr/share/tomcat6 $ sudo ln -s /var/log/tomcat6/velocity.log velocity.log

Now the app is able to open /usr/share/tomcat6/velocity.log without error.

log4j error

Once I created a log file Velocity could write to, it stared throwing an error with log4j. log4j is the Java logging package.

org.apache.log4j.Logger.setAdditivity(Z)V java.lang.NoSuchMethodError:
org.apache.log4j.Logger.setAdditivity(Z)V at
org.apache.velocity.runtime.log.Log4JLogChute.initAppender(Log4JLogChute.java:126) at
org.apache.velocity.runtime.log.Log4JLogChute.init(Log4JLogChute.java:85) at
org.apache.velocity.runtime.log.LogManager.createLogChute(LogManager.java:157) at
org.apache.velocity.runtime.log.LogManager.updateLog(LogManager.java:255) at
org.apache.velocity.runtime.RuntimeInstance.initializeLog(RuntimeInstance.java:795) at
org.apache.velocity.runtime.RuntimeInstance.init(RuntimeInstance.java:250) at
org.apache.velocity.app.VelocityEngine.init(VelocityEngine.java:107) at
org.apache.solr.response.VelocityResponseWriter.getEngine(VelocityResponseWriter.java:132) at
org.apache.solr.response.VelocityResponseWriter.write(VelocityResponseWriter.java:40) at
org.apache.solr.core.SolrCore$LazyQueryResponseWriterWrapper.write(SolrCore.java:1774) at
org.apache.solr.servlet.SolrDispatchFilter.writeResponse(SolrDispatchFilter.java:352) at
org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:273) at
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235) at
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) at
org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233) at
org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191) at
org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127) at
org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102) at
org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:555) at
org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109) at
org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:298) at
org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:857) at
org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:588)
at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:489)
at java.lang.Thread.run(Thread.java:679)

In searching the web for this error, I found this ticket in the Solr bug tracker that says that the log4j .jar files should be removed from the Solr tarball, because they can conflict with existing .jars on the system. That conflict was exactly the error I was getting.

I wanted to remove the extra .jar files, so I used locate to search my system for any log4j .jars. Indeed, there was one installed with solr:

frisbee:~ $ locate log4j
...
/var/lib/tomcat6/webapps/solr/WEB-INF/lib/log4j-over-slf4j-1.6.1.jar
...

So I just changed the extension of the file so it wouldn’t get loaded as a .jar.

frisbee:~ $ sudo mv /var/lib/tomcat6/webapps/solr/WEB-INF/lib/log4j-over-slf4j-1.6.1.{jar,jarx}

Now Velocity loads beautifully. Now the real work starts: Configuration of Velocity to understand the schema in my Solr core.

I hope this helps someone in the future!