Out of Memory/ Command.process

[Migrated From Jforum.net]

Hi. I am receiving an Out of Memory error when trying to access any forum Category. There are roughly 1000 messages in the system. We are using HSQLDB as the db backend.

JForum version is: 2.1.4

I have attempted to run Tomcat with increasing amounts of Heap space, however it uses it all and pegs the processor at 99% use.

This is the Exception we are seeing:

<!-- BEGIN ERROR STACK TRACE <br /> java.lang.reflect.InvocationTargetException <br /> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) <br /> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) <br /> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) <br /> at java.lang.reflect.Method.invoke(Method.java:585) <br /> at net.jforum.Command.process(Command.java:106) <br /> at net.jforum.JForum.service(JForum.java:298) <br /> at javax.servlet.http.HttpServlet.service(HttpServlet.java:802) <br /> at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:237) <br /> at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:157) <br /> at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:214) <br /> at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:104) <br /> at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:520) <br /> at org.apache.catalina.core.StandardContextValve.invokeInternal(StandardContextValve.java:198) <br /> at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:152) <br /> at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:104) <br /> at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:520) <br /> at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:137) <br /> at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:104) <br /> at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:118) <br /> at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:102) <br /> at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:520) <br /> at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109) <br /> at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:104) <br /> at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:520) <br /> at org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:929) <br /> at org.apache.coyote.tomcat5.CoyoteAdapter.service(CoyoteAdapter.java:160) <br /> at org.apache.jk.server.JkCoyoteHandler.invoke(JkCoyoteHandler.java:300) <br /> at org.apache.jk.common.HandlerRequest.invoke(HandlerRequest.java:374) <br /> at org.apache.jk.common.ChannelSocket.invoke(ChannelSocket.java:743) <br /> at org.apache.jk.common.ChannelSocket.processConnection(ChannelSocket.java:675) <br /> at org.apache.jk.common.SocketConnection.runIt(ChannelSocket.java:866) <br /> at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:683) <br /> at java.lang.Thread.run(Thread.java:595) <br /> Caused by: java.lang.OutOfMemoryError: Java heap space <br /> <br /> <br /> Any help would be appreciated. <br /> <br /> <br /> Thanks. <br /> <br /> T. <br /> [originally posted on jforum.net by tbos]

[Migrated From Jforum.net]

update:

I picked up the source, and tracked down the actual location of the problem.
It was in processSmilies, the admin had created 5 smilies without names, but the images where there.
[originally posted on jforum.net by Anonymous]

[Migrated From Jforum.net]

Hmm... are you able to reproduce the bug? Also, are you sure it is not happening because of a small tomcat heap?

Rafael
[originally posted on jforum.net by Rafael Steil]

[Migrated From Jforum.net]

I have not attempted to re-produce it yet, I will give it a try tonight.
During debugging, I ran Tomcat with various heap settings. My last attempt was to give it 1024M on a server with 2GB. It used it all, and then ran out of memory. Is there some recursion happening in processSmilies?

T.
[originally posted on jforum.net by tbos]

[Migrated From Jforum.net]

I don't think processSmilies() should be the root of the problem.

Well, 1GB heap is big... Why don't you try version 2.1.5? Get the pre-release from http://www.jforum.net/upload/JForum-2.1.5.zip

Rafael
[originally posted on jforum.net by Rafael Steil]

[Migrated From Jforum.net]

Yes, 1GB is big. Once I gave the smilies names, it ran fine, and only uses about 70MB.

Here is the iterator loop from processSmilies in PostCommon.java

Iterator iter = smilies.iterator();
    while (iter.hasNext()) {
      Smilie s = (Smilie) iter.next();
      System.out.println("testing smilie: "+s.getCode());
      int index = text.indexOf(s.getCode());
      if (index > -1) {
        System.out.println("smilie exists!:");
        text = text.replaceAll("\\Q" + s.getCode() + "\\E", s.getUrl());
      }
    }

When run with the bogus smilies, it would print out this repeatedly:
testing smilie:
smilie exists!:
testing smilie:
smilie exists!:
testing smilie:
smilie exists!:
testing smilie:
smilie exists!:
testing smilie:
smilie exists!:


Getting slower and slower between each testing/exists..


I will give 2.1.5 a try. Thanks for your help.

T.
[originally posted on jforum.net by tbos]

[Migrated From Jforum.net]

Yes, once of forum admins added serveral smilies, but somehow was able leave the name blank.

There are even stranger things happening today though:

Caused by: java.sql.SQLException: S1000 General error java.lang.NegativeArraySizeException in statement [UPDATE jforum_topics SET topic_views = topic_views + 1 WHERE topic_id = ?]
at org.hsqldb.jdbc.Util.throwError(Unknown Source)
at org.hsqldb.jdbc.jdbcPreparedStatement.executeUpdate(Unknown Source)
at net.jforum.drivers.generic.TopicModel.incrementTotalViews(TopicModel.java:246)
at net.jforum.view.forum.PostAction.list(PostAction.java:145)
... 37 more


AND

Caused by: java.sql.SQLException: S1000 General error java.lang.IndexOutOfBoundsException in statement [SELECT session_time, session_start, session_id FROM jforum_sessions WHERE session_user_id = ?]
at org.hsqldb.jdbc.Util.throwError(Unknown Source)
at org.hsqldb.jdbc.jdbcPreparedStatement.executeQuery(Unknown Source)
at net.jforum.drivers.generic.UserSessionModel.selectById(UserSessionModel.java:110)
at net.jforum.view.forum.UserAction.validateLogin(UserAction.java:310)
... 38 more

And on login:

<!-- BEGIN ERROR STACK TRACE

MethodgetLastPostInfo on net.jforum.repository.ForumRepository
The problematic instruction:
----------
==> assignment: lpi=fir.getLastPostInfo(forum.id) [on line 40, column 41 in default/forum_list.htm]
 in include moduleAction [on line 76, column 21 in default/forum_base.htm]
----------

Java backtrace for programmers:
----------
freemarker.template.TemplateModelException: MethodgetLastPostInfo on net.jforum.repository.ForumRepository
	at freemarker.ext.beans.OverloadedMethodModel.exec(OverloadedMethodModel.java:112)
	at freemarker.core.MethodCall._getAsTemplateModel(MethodCall.java:93)
	at freemarker.core.Expression.getAsTemplateModel(Expression.java:89)
	at freemarker.core.Assignment.accept(Assignment.java:91)
	at freemarker.core.Environment.visit(Environment.java:171)
	at freemarker.core.MixedContent.accept(MixedContent.java:92)
	at freemarker.core.Environment.visit(Environment.java:171)
	at freemarker.core.IteratorBlock$Context.runLoop(IteratorBlock.java:160)
	at freemarker.core.Environment.visit(Environment.java:284)
	at freemarker.core.IteratorBlock.accept(IteratorBlock.java:95)
	at freemarker.core.Environment.visit(Environment.java:171)
	at freemarker.core.MixedContent.accept(MixedContent.java:92)
	at freemarker.core.Environment.visit(Environment.java:171)
	at freemarker.core.IteratorBlock$Context.runLoop(IteratorBlock.java:160)
	at freemarker.core.Environment.visit(Environment.java:284)
	at freemarker.core.IteratorBlock.accept(IteratorBlock.java:95)
	at freemarker.core.Environment.visit(Environment.java:171)
	at freemarker.core.MixedContent.accept(MixedContent.java:92)
	at freemarker.core.Environment.visit(Environment.java:171)
	at freemarker.core.Environment.include(Environment.java:1256)
	at freemarker.core.Include.accept(Include.java:156)
	at freemarker.core.Environment.visit(Environment.java:171)
	at freemarker.core.MixedContent.accept(MixedContent.java:92)
	at freemarker.core.Environment.visit(Environment.java:171)
	at freemarker.core.Environment.process(Environment.java:156)
	at freemarker.template.Template.process(Template.java:219)
	at net.jforum.JForum.service(JForum.java:314)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(Unknown Source)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(Unknown Source)
	at org.apache.catalina.core.StandardWrapperValve.invoke(Unknown Source)
	at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(Unknown Source)
	at org.apache.catalina.core.StandardPipeline.invoke(Unknown Source)
	at org.apache.catalina.core.ContainerBase.invoke(Unknown Source)
	at org.apache.catalina.core.StandardContextValve.invoke(Unknown Source)
	at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(Unknown Source)
	at org.apache.catalina.core.StandardPipeline.invoke(Unknown Source)
	at org.apache.catalina.core.ContainerBase.invoke(Unknown Source)
	at org.apache.catalina.core.StandardContext.invoke(Unknown Source)
	at org.apache.catalina.core.StandardHostValve.invoke(Unknown Source)
	at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(Unknown Source)
	at org.apache.catalina.valves.ErrorDispatcherValve.invoke(Unknown Source)
	at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(Unknown Source)
	at org.apache.catalina.valves.ErrorReportValve.invoke(Unknown Source)
	at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(Unknown Source)
	at org.apache.catalina.core.StandardPipeline.invoke(Unknown Source)
	at org.apache.catalina.core.ContainerBase.invoke(Unknown Source)
	at org.apache.catalina.core.StandardEngineValve.invoke(Unknown Source)
	at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(Unknown Source)
	at org.apache.catalina.core.StandardPipeline.invoke(Unknown Source)
	at org.apache.catalina.core.ContainerBase.invoke(Unknown Source)
	at org.apache.coyote.tomcat4.CoyoteAdapter.service(CoyoteAdapter.java:223)
	at org.apache.jk.server.JkCoyoteHandler.invoke(JkCoyoteHandler.java:261)
	at org.apache.jk.common.HandlerRequest.invoke(HandlerRequest.java:360)
	at org.apache.jk.common.ChannelSocket.invoke(ChannelSocket.java:604)
	at org.apache.jk.common.ChannelSocket.processConnection(ChannelSocket.java:562)
	at org.apache.jk.common.SocketConnection.runIt(ChannelSocket.java:679)
	at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:619)
	at java.lang.Thread.run(Thread.java:595)
Caused by: java.lang.reflect.InvocationTargetException
	at sun.reflect.GeneratedMethodAccessor92.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
	at java.lang.reflect.Method.invoke(Method.java:585)
	at freemarker.ext.beans.BeansWrapper.invokeMethod(BeansWrapper.java:462)
	at freemarker.ext.beans.OverloadedMethodModel.exec(OverloadedMethodModel.java:108)
	... 58 more
Caused by: java.sql.SQLException: S1000 General error java.util.NoSuchElementException in statement [SELECT post_time, p.topic_id, t.topic_replies, post_id, u.user_id, username FROM jforum_posts p, jforum_users u, jforum_topics t , jforum_forums f WHERE t.forum_id = f.forum_id AND t.topic_id = p.topic_id AND f.forum_last_post_id = t.topic_last_post_id AND t.topic_last_post_id = p.post_id AND p.forum_id = ? AND p.user_id = u.user_id]
	at org.hsqldb.jdbc.Util.throwError(Unknown Source)
	at org.hsqldb.jdbc.jdbcPreparedStatement.executeQuery(Unknown Source)
	at net.jforum.drivers.generic.ForumModel.getLastPostInfo(ForumModel.java:275)
	at net.jforum.drivers.generic.ForumModel.getLastPostInfo(ForumModel.java:336)
	at net.jforum.repository.ForumRepository.getLastPostInfo(ForumRepository.java:469)
	at net.jforum.repository.ForumRepository.getLastPostInfo(ForumRepository.java:485)
	... 63 more
Underlying cause: 
java.lang.reflect.InvocationTargetException
	at sun.reflect.GeneratedMethodAccessor92.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
	at java.lang.reflect.Method.invoke(Method.java:585)
	at freemarker.ext.beans.BeansWrapper.invokeMethod(BeansWrapper.java:462)
	at freemarker.ext.beans.OverloadedMethodModel.exec(OverloadedMethodModel.java:108)
	at freemarker.core.MethodCall._getAsTemplateModel(MethodCall.java:93)
	at freemarker.core.Expression.getAsTemplateModel(Expression.java:89)
	at freemarker.core.Assignment.accept(Assignment.java:91)
	at freemarker.core.Environment.visit(Environment.java:171)
	at freemarker.core.MixedContent.accept(MixedContent.java:92)
	at freemarker.core.Environment.visit(Environment.java:171)
	at freemarker.core.IteratorBlock$Context.runLoop(IteratorBlock.java:160)
	at freemarker.core.Environment.visit(Environment.java:284)
	at freemarker.core.IteratorBlock.accept(IteratorBlock.java:95)
	at freemarker.core.Environment.visit(Environment.java:171)
	at freemarker.core.MixedContent.accept(MixedContent.java:92)
	at freemarker.core.Environment.visit(Environment.java:171)
	at freemarker.core.IteratorBlock$Context.runLoop(IteratorBlock.java:160)
	at freemarker.core.Environment.visit(Environment.java:284)
	at freemarker.core.IteratorBlock.accept(IteratorBlock.java:95)
	at freemarker.core.Environment.visit(Environment.java:171)
	at freemarker.core.MixedContent.accept(MixedContent.java:92)
	at freemarker.core.Environment.visit(Environment.java:171)
	at freemarker.core.Environment.include(Environment.java:1256)
	at freemarker.core.Include.accept(Include.java:156)
	at freemarker.core.Environment.visit(Environment.java:171)
	at freemarker.core.MixedContent.accept(MixedContent.java:92)
	at freemarker.core.Environment.visit(Environment.java:171)
	at freemarker.core.Environment.process(Environment.java:156)
	at freemarker.template.Template.process(Template.java:219)
	at net.jforum.JForum.service(JForum.java:314)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(Unknown Source)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(Unknown Source)
	at org.apache.catalina.core.StandardWrapperValve.invoke(Unknown Source)
	at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(Unknown Source)
	at org.apache.catalina.core.StandardPipeline.invoke(Unknown Source)
	at org.apache.catalina.core.ContainerBase.invoke(Unknown Source)
	at org.apache.catalina.core.StandardContextValve.invoke(Unknown Source)
	at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(Unknown Source)
	at org.apache.catalina.core.StandardPipeline.invoke(Unknown Source)
	at org.apache.catalina.core.ContainerBase.invoke(Unknown Source)
	at org.apache.catalina.core.StandardContext.invoke(Unknown Source)
	at org.apache.catalina.core.StandardHostValve.invoke(Unknown Source)
	at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(Unknown Source)
	at org.apache.catalina.valves.ErrorDispatcherValve.invoke(Unknown Source)
	at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(Unknown Source)
	at org.apache.catalina.valves.ErrorReportValve.invoke(Unknown Source)
	at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(Unknown Source)
	at org.apache.catalina.core.StandardPipeline.invoke(Unknown Source)
	at org.apache.catalina.core.ContainerBase.invoke(Unknown Source)
	at org.apache.catalina.core.StandardEngineValve.invoke(Unknown Source)
	at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(Unknown Source)
	at org.apache.catalina.core.StandardPipeline.invoke(Unknown Source)
	at org.apache.catalina.core.ContainerBase.invoke(Unknown Source)
	at org.apache.coyote.tomcat4.CoyoteAdapter.service(CoyoteAdapter.java:223)
	at org.apache.jk.server.JkCoyoteHandler.invoke(JkCoyoteHandler.java:261)
	at org.apache.jk.common.HandlerRequest.invoke(HandlerRequest.java:360)
	at org.apache.jk.common.ChannelSocket.invoke(ChannelSocket.java:604)
	at org.apache.jk.common.ChannelSocket.processConnection(ChannelSocket.java:562)
	at org.apache.jk.common.SocketConnection.runIt(ChannelSocket.java:679)
	at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:619)
	at java.lang.Thread.run(Thread.java:595)
Caused by: java.sql.SQLException: S1000 General error java.util.NoSuchElementException in statement [SELECT post_time, p.topic_id, t.topic_replies, post_id, u.user_id, username FROM jforum_posts p, jforum_users u, jforum_topics t , jforum_forums f WHERE t.forum_id = f.forum_id AND t.topic_id = p.topic_id AND f.forum_last_post_id = t.topic_last_post_id AND t.topic_last_post_id = p.post_id AND p.forum_id = ? AND p.user_id = u.user_id]
	at org.hsqldb.jdbc.Util.throwError(Unknown Source)
	at org.hsqldb.jdbc.jdbcPreparedStatement.executeQuery(Unknown Source)
	at net.jforum.drivers.generic.ForumModel.getLastPostInfo(ForumModel.java:275)
	at net.jforum.drivers.generic.ForumModel.getLastPostInfo(ForumModel.java:336)
	at net.jforum.repository.ForumRepository.getLastPostInfo(ForumRepository.java:469)
	at net.jforum.repository.ForumRepository.getLastPostInfo(ForumRepository.java:485)
	... 63 more

END ERROR STACK TRACE-->

very odd.

thanks.

T.
[originally posted on jforum.net by tbos]

[Migrated From Jforum.net]

hhm... I see

Did you add some new smilies to the forum, or were you running it with the default ones?

This (possible) bug is new to me.

Rafael
[originally posted on jforum.net by Rafael Steil]

[Migrated From Jforum.net]

Hi.

After a little more work, I discovered that all There were NULL's in the jforum_search_words table, and the jforum_search_wordmatch table could not be read at all without throwing an exception.

I dropped and recreated all of the search tables, and the error went away, but now(of course) all of the post indexing is gone.

Is there a wat to regenerate the search hashes from existing posts and topics?

thanks

T.
[originally posted on jforum.net by tbos]

[Migrated From Jforum.net]

I wish I had that tool also. Maybe I will get the time...
[originally posted on jforum.net by time]

[Migrated From Jforum.net]

There is that tool, yes:

http://jforum-tools.dev.java.net

If you can get it from cvs, please do!

Rafael
[originally posted on jforum.net by Rafael Steil]