We got 2 exceptions a number of times for the last 24 hours. They are reproducible every time we try to load an empty user roster. The exceptions do not affect the normal functioning of the server, but pollute the logs and create false alarms in the Nagios log monitor.
The problem seems to be in RosterItemProvider.getItems(String).
public Iterator();
Connection con = null;
PreparedStatement pstmt = null;
try {
con = DbConnectionManager.getConnection();
pstmt = con.prepareStatement(…);
ResultSet rs = pstmt.executeQuery();
while (rs.next()) {
RosterItem item = new RosterItem(/* USE DATA FROM THE RESULT SET*/);
itemList.add(item);
}
pstmt.close();
rs.close();
// NOTE THAT THE pstmt!=null AND IS CLOSED AT THIS POINT
for (RosterItem item : itemList) {
pstmt = con.prepareStatement(…);
rs = pstmt.executeQuery();
// PROCESS ITEMS
rs.close();
}
}
catch (SQLException e) {
Log.error(LocaleUtils.getLocalizedString(…), e);
}
finally {
// IF THE itemList COLLECTION IS EMPTY, THE FOLLOWING LINE WILL THROW EXCEPTION
try { if (pstmt != null) { pstmt.close(); } }
catch (Exception e) { Log.error(e); }
try { if (con != null) { con.close(); } }
catch (Exception e) { Log.error(e); }
}
return itemList.iterator();
}
/code
One easy way to fix this is to set the statement to null after we close it. Another, IMHO but better way is to use an SQL join, so we can avoid the n+1 select altogether.
Here are the exceptions themselves:
2006.02.18 13:01:58 org.jivesoftware.wildfire.roster.RosterItemProvider.getItems(RosterItemProvider. java:325)
2006.02.18 10:11:44 org.jivesoftware.wildfire.roster.RosterItemProvider.getItems(RosterItemProvider. java:325)
2006.02.18 05:59:07 org.jivesoftware.wildfire.roster.RosterItemProvider.getItems(RosterItemProvider. java:325)
2006.02.18 15:35:38 org.jivesoftware.wildfire.roster.RosterItemProvider.getItems(RosterItemProvider. java:325)
2006.02.18 05:33:54 org.jivesoftware.wildfire.roster.RosterItemProvider.getItems(RosterItemProvider. java:325)
java.sql.SQLException: JZ0S2: Statement object has already been closed.
at com.sybase.jdbc3.jdbc.ErrorMessage.raiseError(ErrorMessage.java:572)
at com.sybase.jdbc3.jdbc.SybStatement.checkDead(SybStatement.java:2058)
at com.sybase.jdbc3.jdbc.SybStatement.close(SybStatement.java:494)
at com.sybase.jdbc3.jdbc.SybStatement.close(SybStatement.java:482)
at org.jivesoftware.wildfire.roster.RosterItemProvider.getItems(RosterItemProvider .java:324)
at org.jivesoftware.wildfire.roster.Roster.(Roster.java:98)
at org.jivesoftware.wildfire.roster.RosterManager.getRoster(RosterManager.java:76)
at org.jivesoftware.wildfire.user.User.getRoster(User.java:243)
at org.jivesoftware.wildfire.handler.IQRosterHandler.manageRoster(IQRosterHandler. java:183)
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:261)
at org.jivesoftware.wildfire.IQRouter.route(IQRouter.java:94)
at org.jivesoftware.wildfire.PacketRouter.route(PacketRouter.java:65)
at org.jivesoftware.wildfire.net.SocketReader.processIQ(SocketReader.java:394)
at org.jivesoftware.wildfire.net.ClientSocketReader.processIQ(ClientSocketReader.j ava:50)
at org.jivesoftware.wildfire.net.SocketReader.readStream(SocketReader.java:262)
at org.jivesoftware.wildfire.net.SocketReader.run(SocketReader.java:119)
at java.lang.Thread.run(Unknown Source)
2006.02.18 05:11:08 org.jivesoftware.wildfire.roster.RosterItemProvider.getItems(RosterItemProvider. java:325)
2006.02.18 05:11:14 org.jivesoftware.wildfire.roster.RosterItemProvider.getItems(RosterItemProvider. java:325)
2006.02.18 10:34:38 org.jivesoftware.wildfire.roster.RosterItemProvider.getItems(RosterItemProvider. java:325)
2006.02.18 06:23:36 org.jivesoftware.wildfire.roster.RosterItemProvider.getItems(RosterItemProvider. java:325)
2006.02.18 10:01:04 org.jivesoftware.wildfire.roster.RosterItemProvider.getItems(RosterItemProvider. java:325)
2006.02.18 15:12:01 org.jivesoftware.wildfire.roster.RosterItemProvider.getItems(RosterItemProvider. java:325)
java.sql.SQLException: JZ0S2: Statement object has already been closed.
at com.sybase.jdbc3.jdbc.ErrorMessage.raiseError(ErrorMessage.java:572)
at com.sybase.jdbc3.jdbc.SybStatement.checkDead(SybStatement.java:2058)
at com.sybase.jdbc3.jdbc.SybStatement.close(SybStatement.java:494)
at com.sybase.jdbc3.jdbc.SybStatement.close(SybStatement.java:482)
at org.jivesoftware.wildfire.roster.RosterItemProvider.getItems(RosterItemProvider .java:324)
at org.jivesoftware.wildfire.roster.Roster.(Roster.java:98)
at org.jivesoftware.wildfire.handler.PresenceSubscribeHandler.getRoster(PresenceSu bscribeHandler.java:194)
at org.jivesoftware.wildfire.handler.PresenceSubscribeHandler.process(PresenceSubs cribeHandler.java:98)
at org.jivesoftware.wildfire.PresenceRouter.handle(PresenceRouter.java:116)
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 3)
at org.jivesoftware.wildfire.net.ClientSocketReader.processPresence(ClientSocketRe ader.java:56)
at org.jivesoftware.wildfire.net.SocketReader.readStream(SocketReader.java:240)
at org.jivesoftware.wildfire.net.SocketReader.run(SocketReader.java:119)
at java.lang.Thread.run(Unknown Source)
/code