CPU usage on connectionLost

[xcv_]

Hi,

I'm writing a client Android application and I'm having issues when the client gets an unexpected connection loss. A "New I/O client worker #?-?" thread enters some kind of infinite loop, CPU usage increases and the GC starts working heavily. When it disconnects, I want to be able to display a "connection lost" dialog and let the user choose, but the whole application slows down. It persists after the connection.

Right now when I get the CONNECTION_LOST event I display the popup and if the user accepts, I start to connect from the beginning (connect, login, join a room...). Am I missing anything or is it a bug?

So far I have the following stack traces of the mentioned thread and a screenshot of the method profiler showing the high activity if it helps. I have also found a similar problem in this forum: http://forums.smartfoxserver.com/viewto ... 22&t=14568.

Code: Select all

  at libcore.io.Posix.poll(Native Method)	
  at libcore.io.BlockGuardOs.poll(BlockGuardOs.java:119)	
  at java.nio.SelectorImpl.selectInternal(SelectorImpl.java:179)	
  at java.nio.SelectorImpl.select(SelectorImpl.java:156)	
  at org.jboss.netty.channel.socket.nio.SelectorUtil.select(SelectorUtil.java:38)	
  at org.jboss.netty.channel.socket.nio.NioWorker.run(NioWorker.java:164)	
  at org.jboss.netty.util.ThreadRenamingRunnable.run(ThreadRenamingRunnable.java:108)	
  at org.jboss.netty.util.internal.IoWorkerRunnable.run(IoWorkerRunnable.java:46)	
  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1080)	
  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:573)	
  at java.lang.Thread.run(Thread.java:841)	

Code: Select all

  at java.util.HashMap$HashIterator.<init>(HashMap.java:790)	
  at java.util.HashMap$KeyIterator.<init>(HashMap.java:831)	
  at java.util.HashMap$KeyIterator.<init>(HashMap.java:831)	
  at java.util.HashMap.newKeyIterator(HashMap.java:907)	
  at java.util.HashMap$KeySet.iterator(HashMap.java:913)	
  at java.util.HashSet.iterator(HashSet.java:161)	
  at java.nio.SelectorImpl$UnaddableSet.iterator(SelectorImpl.java:365)	
  at org.jboss.netty.channel.socket.nio.NioWorker.processSelectedKeys(NioWorker.java:275)	
  at org.jboss.netty.channel.socket.nio.NioWorker.run(NioWorker.java:201)	
  at org.jboss.netty.util.ThreadRenamingRunnable.run(ThreadRenamingRunnable.java:108)	
  at org.jboss.netty.util.internal.IoWorkerRunnable.run(IoWorkerRunnable.java:46)	
  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1080)	
  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:573)	
  at java.lang.Thread.run(Thread.java:841)	

Thanks.

[Lapo]

It sounds like you are using an old version of the API
The latest Java/Android version is 1.2.0

Check via the SmartFox.getVersion() method.

Upgrade here --> http://www.smartfoxserver.com/download/sfs2x#p=client

Thanks

[xcv_]

I just checked it, I'm running the lastest version (1.2.0).

[Lapo]

Does the problem arise at the disconnection event? Or after, when you attempt to reconnect again.
Also in order to reconnect you should create a new SmartFox objects, making sure to release the listeners of the previous instance.

Is this that you are doing?

Thanks

[xcv_]

Indeed, it starts when it disconnects. I remove all listeners and create a new SmartFox instance in the event dispatch. The reconnection works perfectly when I use the new instance.

Thanks

[Lapo]

And what does the I/O thread do after the new connection? Does it persist looping? Or does it go away?

At the moment I am not able to reproduce this issue. I am testing in a regular JVM, not Dalvik, so there maybe something else going on which is platform specific.
I will report back when I have done the test on the Android simulator.

Thanks

[Lapo]

UPDATE:
I've tested on Dalvik using the Connector Example we provide in the default example package.
Running the application in debug mode I am not able to see any particular problem.

This is how the threads look like when the Example is connected:



And this is how the threads look like right after a disconnection:



In order to generate the disconnection I shut down the server forcefully.
Can you provide more info as to how this problem should be reproduced?

Thanks

[xcv_]

Can you provide more info as to how this problem should be reproduced?

In order to test the disconnection, I disable WiFi in the settings application. It usually happens 3/4 of the time. I haven't tested in the emulator though.

And what does the I/O thread do after the new connection? Does it persist looping? Or does it go away?

It keeps looping until I close the application. If it happens with the new connection, the new thread also starts looping and I end up with two threads consuming lots of CPU.

Thanks

[Lapo]

Can you please try by shutting down the server and see if does the same thing? At least we would have a track to follow if it is different.
Thanks

[xcv_]

I tested shutting down the server and everything worked perfectly, it just seems to happen following the steps above.

Thanks

[Lapo]

Deactivating the WiFi can have all sorts of unexpected consequences.
On a PC/Mac if you do that none of the current TCP connections will be closed for example, and consequently no event is ever fired.
When you reactivate the WiFi all connections will be up again as if nothing had happened.

I have tested your scenario on my Mac running the Connector Example on both a regular JVM and the Android Emulator. Shutting down the local WiFi doesn't trigger andy strange behavior.

I suppose this thing happens only on the device?
Is there anything strange in the client logs?

I have no idea why a new thread should be started, there is no good reason unless the new thread has to do with a new connection. Are you perchance using the HRC in your Zone? (the reconnection system)

[xcv_]

I haven't found a way to test on the emulator, sorry. There's no WiFi setting and the button in the developer tools doesn't seem to work properly for me.

When I deactivate the WiFi, it tries to reconnect using the fast reconnection (it's enabled), it fails and I get a normal connectionLost event plus the described behavior. I have also tried walking away from the WiFi signal and the same thing happened. After reactivating it, I can reconnect fine, it's just that the old thread keeps looping. Everything else in the logs makes sense.

By the way, here you have the stack traces of the allocations causing the garbage collection:

Code: Select all

  at java.util.HashMap.newKeyIterator(HashMap.java:907)	
  at java.util.HashMap$KeySet.iterator(HashMap.java:913)	
  at java.util.HashSet.iterator(HashSet.java:161)	
  at java.nio.SelectorImpl$UnaddableSet.iterator(SelectorImpl.java:365)	
  at org.jboss.netty.channel.socket.nio.NioWorker.processSelectedKeys(NioWorker.java:275)	
  at org.jboss.netty.channel.socket.nio.NioWorker.run(NioWorker.java:201)	
  at org.jboss.netty.util.ThreadRenamingRunnable.run(ThreadRenamingRunnable.java:108)	
  at org.jboss.netty.util.internal.IoWorkerRunnable.run(IoWorkerRunnable.java:46)	

Code: Select all

  at java.util.HashMap.newKeyIterator(HashMap.java:907)	
  at java.util.HashMap$KeySet.iterator(HashMap.java:913)	
  at java.util.HashSet.iterator(HashSet.java:161)	
  at java.nio.SelectorImpl.preparePollFds(SelectorImpl.java:208)	
  at java.nio.SelectorImpl.selectInternal(SelectorImpl.java:171)	
  at java.nio.SelectorImpl.select(SelectorImpl.java:156)	
  at org.jboss.netty.channel.socket.nio.SelectorUtil.select(SelectorUtil.java:38)	
  at org.jboss.netty.channel.socket.nio.NioWorker.run(NioWorker.java:164)	
  at org.jboss.netty.util.ThreadRenamingRunnable.run(ThreadRenamingRunnable.java:108)	
  at org.jboss.netty.util.internal.IoWorkerRunnable.run(IoWorkerRunnable.java:46)	

Thanks

[Lapo]

Thanks, the stack traces indicate that the problem is happening very down in the "guts" of the java.nio package, that's pretty strange in and of itself.
I could partially or entirely related with the Netty socket engine we use for the networking part, although it's difficult to say without any other details.

One thing you may attempt is to download the latest Netty release and substitute the jar in your project with the new one.
If the compilation is fine (which is expected) you can then deploy the app and see if the problem persists.
http://netty.io/downloads.html

p.s. = there are a 3.x and a 4.x versions. I recommend sticking with the 3.x since it is the same branch we have used. It's likely that 4.x has different interfaces and won't compile

[xcv_]

After upgrading to Netty 3.7 the problem persists. As you mentioned, 4.x releases are completely different and won't even start. I tried with both 3.2.7 and 3.7.0.

Do you need any other stack trace or dump?

Thanks

[xcv_]

Are there any news regarding this issue?

Thanks