Error.log while server runs correctly

Openfire Openfire Support
1

First one - at home Win2000 JM 2.2.0 beta 1 (2005-07-03) with embedded-db:

2005.07.04 09:53:43 [org.jivesoftware.database.ConnectionPool.(ConnectionPool.java:106)

] Failed to create new connections on startup. Attempt 0 of 3

java.sql.SQLException: The database is already in use by another process: org.hsqldb.NIOLockFile@b27997b8[file =C:\Program Files\Jive Messenger\embedded-db\messenger.lck, exists=true, locked=false, valid=false, fl =null]: java.lang.Exception: checkHeartbeat(): lock file is presumably locked by another process.

at org.hsqldb.jdbc.jdbcUtil.sqlException(Unknown Source)

at org.hsqldb.jdbc.jdbcConnection.(XMPPServer.java:117)

at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)

at sun.reflect.NativeConstructorAccessorImpl.newInstance(Unknown Source)

at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(Unknown Source)

at java.lang.reflect.Constructor.newInstance(Unknown Source)

at java.lang.Class.newInstance0(Unknown Source)

at java.lang.Class.newInstance(Unknown Source)

at org.jivesoftware.messenger.starter.ServerStarter.start(ServerStarter.java:82)

at org.jivesoftware.messenger.starter.ServerStarter.main(ServerStarter.java:46)

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.exe4j.runtime.LauncherEngine.launch(Unknown Source)

at com.exe4j.runtime.WinLauncher.main(Unknown Source)

2

at work, Archlinux 0.7 + JM 2.1.5 embedded-db, i think while restarting server:

2005.08.05 16:21:05 org.jivesoftware.messenger.PrivateStorage.get(PrivateStorage.java:161) Internal server error

org.dom4j.DocumentException: FWK005 parse may not be called while parsing. Nested exception: FWK005 parse may not be called while parsing.

at org.dom4j.io.SAXReader.read(SAXReader.java:484)

at org.dom4j.io.SAXReader.read(SAXReader.java:365)

at org.jivesoftware.messenger.PrivateStorage.get(PrivateStorage.java:155)

at org.jivesoftware.messenger.handler.IQPrivateHandler.handleIQ(IQPrivateHandler.j ava:66)

at org.jivesoftware.messenger.handler.IQHandler.process(IQHandler.java:48)

at org.jivesoftware.messenger.IQRouter.handle(IQRouter.java:202)

at org.jivesoftware.messenger.IQRouter.route(IQRouter.java:73)

at org.jivesoftware.messenger.PacketRouter.route(PacketRouter.java:65)

at org.jivesoftware.messenger.net.SocketReadThread.readStream(SocketReadThread.jav a:285)

at org.jivesoftware.messenger.net.SocketReadThread.run(SocketReadThread.java:105)

Nested exception:

org.xml.sax.SAXException: FWK005 parse may not be called while parsing.

at com.sun.org.apache.xerces.internal.parsers.AbstractSAXParser.parse(Unknown Source)

at org.dom4j.io.SAXReader.read(SAXReader.java:465)

at org.dom4j.io.SAXReader.read(SAXReader.java:365)

at org.jivesoftware.messenger.PrivateStorage.get(PrivateStorage.java:155)

at org.jivesoftware.messenger.handler.IQPrivateHandler.handleIQ(IQPrivateHandler.j ava:66)

at org.jivesoftware.messenger.handler.IQHandler.process(IQHandler.java:48)

at org.jivesoftware.messenger.IQRouter.handle(IQRouter.java:202)

at org.jivesoftware.messenger.IQRouter.route(IQRouter.java:73)

at org.jivesoftware.messenger.PacketRouter.route(PacketRouter.java:65)

at org.jivesoftware.messenger.net.SocketReadThread.readStream(SocketReadThread.jav a:285)

at org.jivesoftware.messenger.net.SocketReadThread.run(SocketReadThread.java:105)

2005.08.05 16:21:04 org.jivesoftware.messenger.PrivateStorage.get(PrivateStorage.java:161) Internal server error

org.dom4j.DocumentException: FWK005 parse may not be called while parsing. Nested exception: FWK005 parse may not be called while parsing.

at org.dom4j.io.SAXReader.read(SAXReader.java:484)

at org.dom4j.io.SAXReader.read(SAXReader.java:365)

at org.jivesoftware.messenger.PrivateStorage.get(PrivateStorage.java:155)

at org.jivesoftware.messenger.handler.IQPrivateHandler.handleIQ(IQPrivateHandler.j ava:66)

at org.jivesoftware.messenger.handler.IQHandler.process(IQHandler.java:48)

at org.jivesoftware.messenger.IQRouter.handle(IQRouter.java:202)

at org.jivesoftware.messenger.IQRouter.route(IQRouter.java:73)

at org.jivesoftware.messenger.PacketRouter.route(PacketRouter.java:65)

at org.jivesoftware.messenger.net.SocketReadThread.readStream(SocketReadThread.jav a:285)

at org.jivesoftware.messenger.net.SocketReadThread.run(SocketReadThread.java:105)

Nested exception:

org.xml.sax.SAXException: FWK005 parse may not be called while parsing.

at com.sun.org.apache.xerces.internal.parsers.AbstractSAXParser.parse(Unknown Source)

at org.dom4j.io.SAXReader.read(SAXReader.java:465)

at org.dom4j.io.SAXReader.read(SAXReader.java:365)

at org.jivesoftware.messenger.PrivateStorage.get(PrivateStorage.java:155)

at org.jivesoftware.messenger.handler.IQPrivateHandler.handleIQ(IQPrivateHandler.j ava:66)

at org.jivesoftware.messenger.handler.IQHandler.process(IQHandler.java:48)

at org.jivesoftware.messenger.IQRouter.handle(IQRouter.java:202)

at org.jivesoftware.messenger.IQRouter.route(IQRouter.java:73)

at org.jivesoftware.messenger.PacketRouter.route(PacketRouter.java:65)

at org.jivesoftware.messenger.net.SocketReadThread.readStream(SocketReadThread.jav a:285)

at org.jivesoftware.messenger.net.SocketReadThread.run(SocketReadThread.java:105)

3

Hi wroot,

The first item is a hypersonic db message. The in-memory db is persisted to a file, when its loaded into memory a lock file is written. The error you are seeing usually occurs when a second process tries to access the db, this is not allowed with in-memory db.

So either you tried to run a second JM instance while the other was still running or perhaps had another process attached to the database or JM itself is doing something odd.

Don’'t know about the second item.

Hope that helps

Conor.

4

in answer to your second item have a look at this thread:

http://www.jivesoftware.org/forums/thread.jspa?threadID=15084&tstart=0

Cheers,

Conor.

5

thanx for pointing. I will not close this thread yet, in case i’'ll have some errors in log after upgrade.

6

Wroot,

Yesterday I figured out the reason of this problem. I will try to have a fix today for this issue. Jira issue is JM-364.

Regards,

– Gato

7

Hey Wroot,

The issue has been fixed. You can try again using the next nightly build.

Regards,

– Gato

8

No, i’'ll wait for 2.2.1 Thanx.

9

What about this?

2005.10.07 16:26:26 org.jivesoftware.messenger.container.PluginServlet.service(PluginServlet.java:10 4)

java.lang.IllegalStateException

at org.mortbay.jetty.servlet.ServletHttpResponse.getWriter(ServletHttpResponse.jav a:561)

at org.apache.jasper.runtime.JspWriterImpl.initOut(JspWriterImpl.java:122)

at org.apache.jasper.runtime.JspWriterImpl.flushBuffer(JspWriterImpl.java:115)

at org.apache.jasper.runtime.PageContextImpl.release(PageContextImpl.java:190)

at org.apache.jasper.runtime.JspFactoryImpl.internalReleasePageContext(JspFactoryI mpl.java:115)

at org.apache.jasper.runtime.JspFactoryImpl.releasePageContext(JspFactoryImpl.java :75)

at org.jivesoftware.messenger.plugin.userImportExport.export_002dfile_jsp._jspServ ice(export_002dfile_jsp.java:80)

at org.apache.jasper.runtime.HttpJspBase.service(HttpJspBase.java:94)

at javax.servlet.http.HttpServlet.service(HttpServlet.java:688)

at org.jivesoftware.messenger.container.PluginServlet.handleJSP(PluginServlet.java :231)

at org.jivesoftware.messenger.container.PluginServlet.service(PluginServlet.java:8 5)

at javax.servlet.http.HttpServlet.service(HttpServlet.java:688)

at org.mortbay.jetty.servlet.ServletHolder.handle(ServletHolder.java:427)

at org.mortbay.jetty.servlet.WebApplicationHandler$CachedChain.doFilter(WebApplica tionHandler.java:822)

at org.jivesoftware.admin.AuthCheckFilter.doFilter(AuthCheckFilter.java:98)

at org.mortbay.jetty.servlet.WebApplicationHandler$CachedChain.doFilter(WebApplica tionHandler.java:813)

at org.jivesoftware.util.LocaleFilter.doFilter(LocaleFilter.java:43)

at org.mortbay.jetty.servlet.WebApplicationHandler$CachedChain.doFilter(WebApplica tionHandler.java:813)

at org.jivesoftware.util.SetCharacterEncodingFilter.doFilter(SetCharacterEncodingF ilter.java:41)

at org.mortbay.jetty.servlet.WebApplicationHandler$CachedChain.doFilter(WebApplica tionHandler.java:813)

at org.jivesoftware.admin.AuthCheckFilter.doFilter(AuthCheckFilter.java:98)

at org.mortbay.jetty.servlet.WebApplicationHandler$CachedChain.doFilter(WebApplica tionHandler.java:813)

at org.mortbay.jetty.servlet.WebApplicationHandler.dispatch(WebApplicationHandler. java:494)

at org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:569)

at org.mortbay.http.HttpContext.handle(HttpContext.java:1482)

at org.mortbay.jetty.servlet.WebApplicationContext.handle(WebApplicationContext.ja va:624)

at org.mortbay.http.HttpContext.handle(HttpContext.java:1434)

at org.mortbay.http.HttpServer.service(HttpServer.java:896)

at org.mortbay.http.HttpConnection.service(HttpConnection.java:814)

at org.mortbay.http.HttpConnection.handleNext(HttpConnection.java:981)

at org.mortbay.http.HttpConnection.handle(HttpConnection.java:831)

at org.mortbay.http.SocketListener.handleConnection(SocketListener.java:244)

at org.mortbay.util.ThreadedServer.handle(ThreadedServer.java:366)

at org.mortbay.util.ThreadPool$PoolThread.run(ThreadPool.java:534)

2005.10.07 16:33:21 org.jivesoftware.messenger.handler.PresenceUpdateHandler.process(PresenceUpdateH andler.java:130) Internal server error

java.lang.NullPointerException

at org.jivesoftware.messenger.SessionManager.sessionAvailable(SessionManager.java: 532)

at org.jivesoftware.messenger.ClientSession.setPresence(ClientSession.java:479)

at org.jivesoftware.messenger.handler.PresenceUpdateHandler.process(PresenceUpdate Handler.java:92)

at org.jivesoftware.messenger.handler.PresenceUpdateHandler.process(PresenceUpdate Handler.java:141)

at org.jivesoftware.messenger.PresenceRouter.handle(PresenceRouter.java:87)

at org.jivesoftware.messenger.PresenceRouter.route(PresenceRouter.java:61)

at org.jivesoftware.messenger.PacketRouter.route(PacketRouter.java:73)

at org.jivesoftware.messenger.net.SocketReader.processPresence(SocketReader.java:3 01)

at org.jivesoftware.messenger.net.ClientSocketReader.processPresence(ClientSocketR eader.java:49)

at org.jivesoftware.messenger.net.SocketReader.readStream(SocketReader.java:208)

at org.jivesoftware.messenger.net.SocketReader.run(SocketReader.java:111)

at java.lang.Thread.run(Unknown Source)

10

Hey Wroot,

I figured out what was causing the exception you’'ve been seeing and will be checking in a fix for it today.

Thanks,

Ryan

11

Thanks

12

So, i’‘ll be pasting here until i’'ll find at least one error in logs

UPDATE - 2006-01-25 (Wildfire 2.4.3 - Exodus 0.9.1.0 - Archlinux 0.7.1 - JRE 1.5.0-6)

error.log:

at org.jivesoftware.wildfire.handler.IQRosterHandler.handleIQ(IQRosterHandler.java :103)

at org.jivesoftware.wildfire.handler.IQHandler.process(IQHandler.java:48)

at org.jivesoftware.wildfire.IQRouter.handle(IQRouter.java:256)

at org.jivesoftware.wildfire.IQRouter.route(IQRouter.java:79)

at org.jivesoftware.wildfire.PacketRouter.route(PacketRouter.java:65)

at org.jivesoftware.wildfire.net.SocketReader.processIQ(SocketReader.java:395)

at org.jivesoftware.wildfire.net.ClientSocketReader.processIQ(ClientSocketReader.j ava:50)

at org.jivesoftware.wildfire.net.SocketReader.readStream(SocketReader.java:263)

at org.jivesoftware.wildfire.net.SocketReader.run(SocketReader.java:119)

at java.lang.Thread.run(Unknown Source)

2006.01.24 13:08:38 org.jivesoftware.wildfire.handler.IQRosterHandler.handleIQ(IQRosterHandler.java: 118) Internal server error

java.lang.NullPointerException

at org.jivesoftware.wildfire.handler.IQRosterHandler.manageRoster(IQRosterHandler. java:172)

at org.jivesoftware.wildfire.handler.IQRosterHandler.handleIQ(IQRosterHandler.java :103)

at org.jivesoftware.wildfire.handler.IQHandler.process(IQHandler.java:48)

at org.jivesoftware.wildfire.IQRouter.handle(IQRouter.java:256)

at org.jivesoftware.wildfire.IQRouter.route(IQRouter.java:79)

at org.jivesoftware.wildfire.PacketRouter.route(PacketRouter.java:65)

at org.jivesoftware.wildfire.net.SocketReader.processIQ(SocketReader.java:395)

at org.jivesoftware.wildfire.net.ClientSocketReader.processIQ(ClientSocketReader.j ava:50)

at org.jivesoftware.wildfire.net.SocketReader.readStream(SocketReader.java:263)

at org.jivesoftware.wildfire.net.SocketReader.run(SocketReader.java:119)

at java.lang.Thread.run(Unknown Source)

2006.01.24 13:11:37 org.jivesoftware.wildfire.handler.IQRosterHandler.handleIQ(IQRosterHandler.java: 118) Internal server error

java.lang.NullPointerException

at org.jivesoftware.wildfire.handler.IQRosterHandler.manageRoster(IQRosterHandler. java:172)

at org.jivesoftware.wildfire.handler.IQRosterHandler.handleIQ(IQRosterHandler.java :103)

at org.jivesoftware.wildfire.handler.IQHandler.process(IQHandler.java:48)

at org.jivesoftware.wildfire.IQRouter.handle(IQRouter.java:256)

at org.jivesoftware.wildfire.IQRouter.route(IQRouter.java:79)

at org.jivesoftware.wildfire.PacketRouter.route(PacketRouter.java:65)

at org.jivesoftware.wildfire.net.SocketReader.processIQ(SocketReader.java:395)

at org.jivesoftware.wildfire.net.ClientSocketReader.processIQ(ClientSocketReader.j ava:50)

at org.jivesoftware.wildfire.net.SocketReader.readStream(SocketReader.java:263)

at org.jivesoftware.wildfire.net.SocketReader.run(SocketReader.java:119)

at java.lang.Thread.run(Unknown Source)

2006.01.24 18:20:55 org.jivesoftware.wildfire.handler.PresenceUpdateHandler.process(PresenceUpdateHa ndler.java:134) Internal server error

java.lang.NullPointerException

at org.jivesoftware.wildfire.SessionManager.sessionAvailable(SessionManager.java:5 72)

at org.jivesoftware.wildfire.ClientSession.setPresence(ClientSession.java:596)

at org.jivesoftware.wildfire.handler.PresenceUpdateHandler.process(PresenceUpdateH andler.java:96)

at org.jivesoftware.wildfire.handler.PresenceUpdateHandler.process(PresenceUpdateH andler.java:145)

at org.jivesoftware.wildfire.PresenceRouter.handle(PresenceRouter.java:92)

at org.jivesoftware.wildfire.PresenceRouter.route(PresenceRouter.java:61)

at org.jivesoftware.wildfire.PacketRouter.route(PacketRouter.java:73)

at org.jivesoftware.wildfire.net.SocketReader.processPresence(SocketReader.java:44 4)

at org.jivesoftware.wildfire.net.ClientSocketReader.processPresence(ClientSocketRe ader.java:56)

at org.jivesoftware.wildfire.net.SocketReader.readStream(SocketReader.java:241)

at org.jivesoftware.wildfire.net.SocketReader.run(SocketReader.java:119)

at java.lang.Thread.run(Unknown Source)

warn.log:

org.jivesoftware.wildfire.net.SocketConnection@14d55de socket: Socket[addr=/192.168.12.46,port=1160,localport=5222] session: org.jivesoftware.wildfire.ClientSession@19b6225 status: -1 address: user1@jiveserver/Exodus id: 2b8da11f presence:

2006.01.25 14:02:23 SaslException

javax.security.sasl.SaslException: DIGEST-MD5: digest response format violation. Mismatched response.

at com.sun.security.sasl.digest.DigestMD5Server.validateClientResponse(Unknown Source)

at com.sun.security.sasl.digest.DigestMD5Server.evaluateResponse(Unknown Source)

at org.jivesoftware.wildfire.net.SASLAuthentication.doHandshake(SASLAuthentication .java:192)

at org.jivesoftware.wildfire.net.SocketReader.authenticateClient(SocketReader.java :316)

at org.jivesoftware.wildfire.net.SocketReader.readStream(SocketReader.java:277)

at org.jivesoftware.wildfire.net.SocketReader.run(SocketReader.java:119)

at java.lang.Thread.run(Unknown Source)

13

Hola wroot,

Thanks for reporting those errors. My goal is also to have a zero error.log size. By coincidence, yesterday I fixed JM-538 that is related to the first 3 errors. I just added more error information regarding the 4th error. Are you using Wildfire 2.4.3 or a previous version? My guess is that the connection was lost while the buffer of received packets still contained packets to be processed. It would help if you can use the next nightly build and post again the errors that you might find.

Thanks,

– Gato

14

as i said in chat i’'ll wait for next release and then check it again

15

So, already 2.5.0, time to put some more errors here Well, i’'ve updated on Friday and was surprised to see only one error in log

error.log[code]

2006.02.27 09:09:28 org.jivesoftware.wildfire.net.SocketReader.run(SocketReader.java:159) Connection closed before session established

Socket[addr=/192.168.12.51,port=1040,localport=5222][/code]

192.168.12.51 is now online and ok. Probably this error appeared when she have logged in and Exodus started. At this time must be a higher load while everyone logging in.

warn.log[code]

2006.02.27 08:31:05 Could not route packet

[/code]

Well, probably nothing special, but would be good to know what that means. Second one maybe because of bug with File Proxy advertising even when Disabled?