ghost users impossbile to kick with admin interface

You think you've found a bug? Please report it here.

Moderators: Lapo, Bax

Post Reply
leonidas
Posts: 7
Joined: 07 Jul 2008, 09:03

ghost users impossbile to kick with admin interface

Post by leonidas »

Hi,
I've done a search on GHOST on the forum but found no answer to my questions.

I have users that get disconnected in room , but they remain visible in this room and block them forever.
I have an MaxUserIdleTime set to 300 but the user never gets kicked even after hours :shock:

The admin tool sees them in the zone browser, but when clicking on the pseudo the admin can't fetch the user details and I get an exception

2008/07/07 12:06:13.707 - [ WARNING ] [id: 13] (ExtensionHandler.processEvent): Exception in ExtensionHandler: java.lang.NullPointerException
in the server logs.

As a consequence, I'm unable to kick those users with the admin, and I also fail to delete the room with the same admin tool (but this time no exception visible.

I have an unlimited SFS PRO in production since last friday, in version 1.6.2 and an admin tool in v1.4.0.

Please help !!!
User avatar
Lapo
Site Admin
Posts: 23438
Joined: 21 Mar 2005, 09:50
Location: Italy

Post by Lapo »

I have users that get disconnected in room , but they remain visible in this room and block them forever.
It's not really clear, do they remain connected in the room or not?
Maybe the user fails to join the initial room? How does the lobby works? Is it a Limbo room? Regular room?

Please provide as many details as possible
Lapo
--
gotoAndPlay()
...addicted to flash games
leonidas
Posts: 7
Joined: 07 Jul 2008, 09:03

Post by leonidas »

Hi Lapo,
sorry for remaining silent, I didn't receive a notification of your reply and wasn't aware of it.

Let me give you more details.

- we have a lobby which is a limbo room
- our server extension (java) does an autoconnect in the lobby and immediately tries to find an available room for the player to join. If no available room is found a new room is created dynamically (all our rooms are dynamic and empty rooms are closed)
- there can be up to 5 players per room, and up to 50 spectators
- at the end of a game, a player gets moved to the lobby and back in the room as a spectator

After one day of usage, I end up with 5 to 10 percent of the rooms which show connected users that are idle. I can't kick them with the admin tool.

When I try to kick one of those players with a server side extension (tested successfully with non ghost users) :

Code: Select all

User kick_user = zone.getUserByName(params[0]);
helper.disconnectUser(kick_user);
(I checked that the kick_user object is correctly fetched with those ghost user)

I just get the following message :
INFO | jvm 1 | 2008/07/23 05:26:10 | 05:26:10.413 - [ FINE ] > User [ java.nio.channels.SocketChannel[closed] ] removed

but the user will still be there in the room !

Then we try do delete the room with the following code (tested successfully with non ghost users)

Code: Select all

			Room destroy_room = zone.getRoomByName(params[0]);
			
			if(destroy_room.isTemp()){
				
				User[] users_in_room = destroy_room.getAllUsers();
				
				for(int i = 0; i < users_in_room.length; i++){
					helper.disconnectUser(users_in_room[i]);
				}
				
				gameMap.remove(destroy_room.getName());
				this.trace("Gameroom " + destroy_room.getName() + " has been removed from HashMap.");	
				
				helper.destroyRoom(zone, destroy_room.getId());
				
			}
but didn't get more lucky : we get the following trace :
INFO | jvm 1 | 2008/07/23 05:29:40 | 05:29:40.868 - [ FINE ] > User [ java.nio.channels.SocketChannel[closed] ] removed
INFO | jvm 1 | 2008/07/23 05:29:40 | [ it.gotoandplay.extensions.dm.DuelManager ]: Gameroom gameroom_1557 has been removed from HashMap.

but guess what, the room is still there.

I managed to catch the creation of one of those ghost users, here is the log for the soon to be "ghost" user : the player "ULYSSE320"

Code: Select all

[size=6]INFO   | jvm 1    | 2008/07/23 06:49:30 | 06:49:30.006 - [ FINE ] > Setting RoomVar [challengerChips]: 8, priv: true, persist: true, in room: gameroom_8
INFO   | jvm 1    | 2008/07/23 06:49:30 | 06:49:30.006 - [ FINE ] > Setting RoomVar [championChips]: 8, priv: true, persist: true, in room: gameroom_8
INFO   | jvm 1    | 2008/07/23 06:49:30 | 06:49:30.007 - [ FINE ] > Setting RoomVar [challengerId]: 0, priv: true, persist: true, in room: gameroom_8
INFO   | jvm 1    | 2008/07/23 06:49:30 | 06:49:30.007 - [ FINE ] > User [ ULYSSE320 ] removed
INFO   | jvm 1    | 2008/07/23 06:49:30 | 06:49:30.014 - [ FINE ] > Buddy List loaded --> ULYSSE320
INFO   | jvm 1    | 2008/07/23 06:49:30 | 06:49:30.014 - [ FINE ] > User [ ULYSSE320 ] logged in
INFO   | jvm 1    | 2008/07/23 06:49:30 | [ it.gotoandplay.extensions.dm.DuelManager ]: Exception Thrown at loginRequest(): java.lang.NullPointerException
INFO   | jvm 1    | 2008/07/23 06:49:30 | 06:49:30.067 - [ WARNING ] > Exception during client disconnection: java.lang.NullPointerException
INFO   | jvm 1    | 2008/07/23 06:49:30 | java.lang.NullPointerException
INFO   | jvm 1    | 2008/07/23 06:49:30 | 	at it.gotoandplay.extensions.dm.DuelManager.handleInternalEvent(DuelManager.java:1196)
INFO   | jvm 1    | 2008/07/23 06:49:30 | 	at it.gotoandplay.smartfoxserver.controllers.MessageHandler.dispatchEvent(MessageHandler.java:198)
INFO   | jvm 1    | 2008/07/23 06:49:30 | 	at it.gotoandplay.smartfoxserver.controllers.SystemHandler.broadcastUserLost(SystemHandler.java:3381)
INFO   | jvm 1    | 2008/07/23 06:49:30 | 	at it.gotoandplay.smartfoxserver.SmartFoxServer.lostConnection(SmartFoxServer.java:1465)
INFO   | jvm 1    | 2008/07/23 06:49:30 | 	at it.gotoandplay.smartfoxserver.SmartFoxServer.readIncomingMessages(SmartFoxServer.java:969)
INFO   | jvm 1    | 2008/07/23 06:49:30 | 	at it.gotoandplay.smartfoxserver.EventReader.run(EventReader.java:32)
INFO   | jvm 1    | 2008/07/23 06:49:30 | 	at java.lang.Thread.run(Unknown Source)
INFO   | jvm 1    | 2008/07/23 06:49:30 | 06:49:30.068 - [ FINE ] > User [ java.nio.channels.SocketChannel[closed] ] removed[/size]




Also, the list of all connected users show many of those ghost players even outside rooms.

We set up MaxUserIdleTime to 300 and also tried automated kick procedure where players do not send any messages, but none seem to work to get rid of those users.

Let me add the the admin tool get disconnected very frequently where the server becomes moderately loaded (or when there are around 250 ghosts ?). Sometimes I can't even get the list of the rooms available before I get disconnected.
Many of my users also complain of savage disconnection (connection to the SFS lost during a game), I hope this is related to our problem.

This is a big problem to us since some players get stuck in rooms for minutes before they relize something is frozen, and we are obliged to restart the SFS everyday since there is no other way to get rid of those ghosts.


We have SFS v1.6.2,

Please advise !

Thanks !
Pedro
leonidas
Posts: 7
Joined: 07 Jul 2008, 09:03

Post by leonidas »

we suspect some kind of memory shortage, yesterday the server just restarted after a memory exception

Code: Select all

INFO   | jvm 1    | 2008/08/04 17:45:57 | #
INFO   | jvm 1    | 2008/08/04 17:45:57 | # An unexpected error has been detected by Java Runtime Environment:
INFO   | jvm 1    | 2008/08/04 17:45:57 | #
INFO   | jvm 1    | 2008/08/04 17:45:57 | # java.lang.OutOfMemoryError: requested 32756 bytes for ChunkPool::allocate. Out of swap space?
INFO   | jvm 1    | 2008/08/04 17:45:57 | #
INFO   | jvm 1    | 2008/08/04 17:45:57 | #  Internal Error (414C4C4F434154494F4E0E4350500065), pid=22656, tid=3014146992
INFO   | jvm 1    | 2008/08/04 17:45:57 | #
INFO   | jvm 1    | 2008/08/04 17:45:57 | # Java VM: Java HotSpot(TM) Server VM (1.6.0_03-b05 mixed mode)
INFO   | jvm 1    | 2008/08/04 17:45:57 | # An error report file with more information is saved as hs_err_pid22656.log
INFO   | jvm 1    | 2008/08/04 17:46:00 | #
INFO   | jvm 1    | 2008/08/04 17:46:00 | # If you would like to submit a bug report, please visit:
INFO   | jvm 1    | 2008/08/04 17:46:00 | #   http://java.sun.com/webapps/bugreport/crash.jsp
INFO   | jvm 1    | 2008/08/04 17:46:00 | #
ERROR  | wrapper  | 2008/08/04 17:46:00 | JVM exited unexpectedly.
STATUS | wrapper  | 2008/08/04 17:46:00 | JVM exited in response to signal UNKNOWN (6).
STATUS | wrapper  | 2008/08/04 17:46:04 | Launching a JVM...
Here is what the admin says (when I can connect to it because periodically under "heavy" load (300 connected users) it can't fetch the stats from the server
You see quite a number of active thread (+3000), and dropped outbound packets (+500).
Does it make sense to you ?



Image
User avatar
Lapo
Site Admin
Posts: 23438
Joined: 21 Mar 2005, 09:50
Location: Italy

Post by Lapo »

Hi,
after a quick glance at your admin tool screenshot I noticed you have well over 3500 threads running :shock: :shock:

That's highly likely to be the major cause of your out-of-memory error :(

You are probably creating a lot of threads/setIntervals which are never cleared. Check your code!
Lapo
--
gotoAndPlay()
...addicted to flash games
leonidas
Posts: 7
Joined: 07 Jul 2008, 09:03

Post by leonidas »

Great suggestion, thanks Lapo :P ,
there were indeed some setInterval that were not cleared in some situations.
I'll monitor the entire day to see :
- if the thread count is contained
- if the zombie users disappeared

I'll post to let you know
thanks !
leonidas
Posts: 7
Joined: 07 Jul 2008, 09:03

Post by leonidas »

Hi again,

there's a big difference in the thread count, just 160 !

However I still have a few ghost users that block rooms

So here is a new snapshot, many you will find another unusual counter ?

- As you can see there are a few dropped out msgs, is it a normal behaviour or does it indicate the server has experienced difficulties ?

- the VM used memory is always close to the max, is it normal ? A top command shows only 96 megs used if I'm correct :

Code: Select all

  PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND
15782 root      20   0 1220m  96m 6620 S    4  2.5  15:05.94 java

- sometimes the output queue show around 50 messages, the number of rooms and users is not huge (60 and 170 respectively), and this is a dedicated box with large bandwidth. Does it look normal ?



Image


thanks again and best regards !
User avatar
Lapo
Site Admin
Posts: 23438
Joined: 21 Mar 2005, 09:50
Location: Italy

Post by Lapo »

- As you can see there are a few dropped out msgs, is it a normal behaviour or does it indicate the server has experienced difficulties ?
Yes it is and it depends alot on what your application does, the bandwidth etc...
You can also configure how the server handles queued messages, take a look at the config chapters (2.1 and 2.2) of the docs.

I also recommend searching this board for other discussions on this same topic, as I already explained how it works in details. (I should probably add a white paper related to these network topics... adding to the todo list :) )
- the VM used memory is always close to the max, is it normal ? A top command shows only 96 megs used if I'm correct :
Yes absolutely normal
- sometimes the output queue show around 50 messages, the number of rooms and users is not huge (60 and 170 respectively), and this is a dedicated box with large bandwidth. Does it look normal ?
Yes, no worries. You can start worrying when it goes into the thousands :)
(which will also spike the server load bar)
However I still have a few ghost users that block rooms
The server should remove them after the maxIdleTime has expired
Lapo
--
gotoAndPlay()
...addicted to flash games
leonidas
Posts: 7
Joined: 07 Jul 2008, 09:03

Post by leonidas »

thanks Lapo,

I have read all the posts on ghost users but mine don't get kicked after max idle time

I have put all the details in my first reply to you above :

in sumary :
- maxIdleTime expires and they are still there
- admin tool sees them but can't kick them and can't close the room
- issuing kick commands from an server extension fails also


see my first reply above for details
User avatar
Lapo
Site Admin
Posts: 23438
Joined: 21 Mar 2005, 09:50
Location: Italy

Post by Lapo »

We'd like to see your sever logs.
Before that we'd recommend to turn the file logging level to FINER in the config.xml and restart the server.
After a few days of activity send us a the zipped logs to our email (click Support > Contact Us)

Thanks
Lapo
--
gotoAndPlay()
...addicted to flash games
leonidas
Posts: 7
Joined: 07 Jul 2008, 09:03

Post by leonidas »

THE SOLUTIONS :

Thanks to Lapo's suggestions, I believe we have corrected almost all the problems, let me sum them up here so it can benefit to others.

the easy ones
- more testing for null objects when we got users joining and leaving notifications removed some nullpointerexceptions problems

the tough one
- we realized that we were not using the SFS DBManager and ran into synch problems since both system handler and extension handler would issue SQL queries in our extension. It seems that some synch issues could happen when disconnecting a user and result in a "ghost" player that we further could not remove even with the admin tool or user timeouts. Using the DBManager has removed the pb and removed the ghost users as far as I can observe !
Post Reply