Bug (1.0.2): timer is created on every login but not removed on logout

Openfire Plugins Kraken - IM Gateway
1

hy,

we have some problems with our server. after 3 weeks we got an OutOfMemory problem. we have 2 GB heap space and only around 50 concurrent users. so there have to be some memory problems.

the first i have found is in the gateway plugin. on every login there is an timer created that will not be removed on logout. after ~320 logins from a test-script i got this open threads:

“Timer-318” daemon prio=10 tid=0x08226400 nid=0x1c68 in Object.wait()

“Timer-317” daemon prio=10 tid=0x08227400 nid=0x1c58 in Object.wait()

“Timer-316” daemon prio=10 tid=0x08224800 nid=0x1c3c in Object.wait()

“Timer-315” daemon prio=10 tid=0x08941800 nid=0x1c2c in Object.wait()

“Timer-314” daemon prio=10 tid=0x08227c00 nid=0x1c1c in Object.wait()

“Timer-313” daemon prio=10 tid=0x08941000 nid=0x1c05 in Object.wait()

“Timer-312” daemon prio=10 tid=0x08944400 nid=0x1bf5 in Object.wait()

“Timer-311” daemon prio=10 tid=0x08a28000 nid=0x1be5 in Object.wait()

“Timer-310” daemon prio=10 tid=0x080d5800 nid=0x1bd4 in Object.wait()

“Timer-309” daemon prio=10 tid=0x080d3400 nid=0x1bc4 in Object.wait()

“Timer-308” daemon prio=10 tid=0x08b15800 nid=0x1bb3 in Object.wait()

“Timer-307” daemon prio=10 tid=0x08b17c00 nid=0x1b9f in Object.wait()

.

.

.

“Timer-11” daemon prio=10 tid=0x08669800 nid=0x681 in Object.wait()

“Timer-10” daemon prio=10 tid=0x086a2400 nid=0x66f in Object.wait()

“Timer-9” daemon prio=10 tid=0x0835e000 nid=0x65d in Object.wait()

“Timer-8” daemon prio=10 tid=0x084e6c00 nid=0x64b in Object.wait()

“Timer-7” daemon prio=10 tid=0x0887a000 nid=0x637 in Object.wait()

“Timer-6” daemon prio=10 tid=0x084e8000 nid=0x60a in Object.wait()

“Timer-5” daemon prio=10 tid=0x08444000 nid=0x326 in Object.wait()

“Timer-4” daemon prio=10 tid=0x08534800 nid=0x25d in Object.wait()

“Timer-3” prio=10 tid=0x08790000 nid=0x7dc4 in Object.wait()

“Timer-2” prio=10 tid=0x0869a400 nid=0x7dc3 in Object.wait()

“Timer-1” prio=10 tid=0x08699800 nid=0x7dc2 in Object.wait()

“Timer-0” prio=10 tid=0x08681000 nid=0x7dc1 in Object.wait()

the account has an registered an aim/icq/msn account (aim/icq fails after some logins - too many logins)

after restarting the plugin i have the same amount of “timer threads”:

“Timer-322” prio=10 tid=0x088d0000 nid=0x219b in Object.wait()

“Timer-321” prio=10 tid=0x08e4c000 nid=0x2199 in Object.wait()

“Timer-320” prio=10 tid=0x08c99800 nid=0x2197 in Object.wait()

“Timer-319” prio=10 tid=0x08ead000 nid=0x2194 in Object.wait()

“Timer-318” daemon prio=10 tid=0x08226400 nid=0x1c68 in Object.wait()

“Timer-317” daemon prio=10 tid=0x08227400 nid=0x1c58 in Object.wait()

“Timer-316” daemon prio=10 tid=0x08224800 nid=0x1c3c in Object.wait()

“Timer-315” daemon prio=10 tid=0x08941800 nid=0x1c2c in Object.wait()

“Timer-314” daemon prio=10 tid=0x08227c00 nid=0x1c1c in Object.wait()

.

.

.

.

“Timer-10” daemon prio=10 tid=0x086a2400 nid=0x66f in Object.wait()

“Timer-9” daemon prio=10 tid=0x0835e000 nid=0x65d in Object.wait()

“Timer-8” daemon prio=10 tid=0x084e6c00 nid=0x64b in Object.wait()

“Timer-7” daemon prio=10 tid=0x0887a000 nid=0x637 in Object.wait()

“Timer-6” daemon prio=10 tid=0x084e8000 nid=0x60a in Object.wait()

“Timer-5” daemon prio=10 tid=0x08444000 nid=0x326 in Object.wait()

“Timer-4” daemon prio=10 tid=0x08534800 nid=0x25d in Object.wait()

so only 4 timers have been removed an where added again.

we currently use version 1.0.2.

notz

2

Eww, is this new as of 1.0.2?

3

i have now tried it with version 1.0.1. there is also the same issue.

4

What java version are you using?

5

java version “1.6.0”

Java™ SE Runtime Environment (build 1.6.0-b105)

Java HotSpot™ Client VM (build 1.6.0-b105, mixed mode, sharing)

6

Where are you seeing these log entries? Would you mind sharing your test script?

7

We saw a similar problem this morning:

When starting the JVM with “-XX:+TraceClassUnloading” and unloading the im gateway module from the admin panel of Openfire, nothing is printed in the stdout/stderr logs about the unloading of classes. This suggests classes aren’'t unloaded properly.

We are still investigating, but this could very well be related to the Timer threads not being cleaned up.

Regards,

Lars

8

I wonder why I’'m not seeing this? =/ I reload the plugin all the time in testing.

9

We made some changes to the plugin, so it could well be that the problem is caused by some of our own code. We will look into it and let you know.

Lars

10

rrr, the board software is very bad - no code pasting possible , and after switching to preview and back to plain text i lost my already written message.

so again:

i get the output with jstack. the command looks like these (linux):

jstack xxxx | grep ‘’"Timer-’’

xxxx … process id from openfire

p.s.: i think jstack is only available on linux (i didn’'t tried it on windows, but the doc says that)

11

so here is my test script:

http://pastebin.ca/503651

it uses the smack library.

i tried with account that the has some gateways registered and one without gateways registered, and the timer will only be created and not deleted on the account with the gateways registered.

12

What transports in particular are you using? Do you happen to be using IRC or MSN? (which one(s) if so)

13

Actually, code pasting is possible:

class CodePasting {
     public static void main(String[] args)      {
          System.out.println("Hello World!");
     }
}

You can activate it by enclosing your code in tags (without the spaces)

14

i have tried it now with a single aim/icq/msn registration. and it only occurs on msn.

15

hmm, if i remove all code that referrs to the typing notification in “MSNListener” the issue is gone.

16

the, problem have to be in this in function “msnMessenger.logout();”; it seems that the Listener is keept in memory.

public void logOut() {
        if (this.isLoggedIn()) {
            setLoginStatus(TransportLoginStatus.LOGGING_OUT);
            msnMessenger.logout();
        }
        Presence p = new Presence(Presence.Type.unavailable);
        p.setTo(getJID());
        p.setFrom(getTransport().getJID());
        getTransport().sendPacket(p);
        setLoginStatus(TransportLoginStatus.LOGGED_OUT);
    }
17

In 1.0.2 though:

/**
     * Log out of MSN.
     */
    public void logOut() {
        cleanUp();
        sessionDisconnectedNoReconnect(null);
    }     public void cleanUp() {
        if (msnMessenger != null) {
            if (msnListener != null) {
                msnMessenger.removeListener(msnListener);
            }
            msnMessenger.logout();
        }
    }

So in theory it’‘s supposed to be cleaning that up. Then again . . . maybe not. All it’'s doing is removing the listener, not actually destroying the object. Hrm. GATE-226

18

thank you. have you an expected date for the 1.1 release or should i use in the meantime a svn snapshot ?

19

I generally never recommend running directly out of SVN unless I explicitly recommend you do. '‘cause you are bound to run into problems that I am in the middle of working on. That said, I plan to have 1.1.0 out “real soon now” but I have oral surgery tomorrow so… I’‘m not sure I’'ll be like… “up” for working on the plugin this weekend. =)

20

so today my server was the second time out fo memory. hope to see a new release soon, because it’'s currently not usable with msn transport.