Sign in to follow this  
razoreqx

Lag detect loops

Recommended Posts

Anyone seen this type of activity before?  

 

 

server uptime: 63903 seconds. Unanswered questions:0
[02:24:43 PM] INFO com.wurmonline.server.Server: Lag detected at Zones.pollnextzones (0.5): 12.184 seconds
[02:24:43 PM] INFO com.wurmonline.server.Server: Elapsed time (12200ms) for this loop was more than 1 second so adding it to the lag count, which is now: 984
[02:24:58 PM] INFO com.wurmonline.server.zones.Zone: Zone at 2304, 1344 polled 54 tiles. That took 6510.884 millis.
[02:24:58 PM] INFO com.wurmonline.server.Server: Lag detected at Zones.pollnextzones (0.5): 6.521 seconds
[02:24:58 PM] INFO com.wurmonline.server.Server: Elapsed time (6521ms) for this loop was more than 1 second so adding it to the lag count, which is now: 990
[02:25:15 PM] INFO com.wurmonline.server.zones.Zone: Zone at 2240, 2624 polled 61 tiles. That took 7092.5317 millis.
[02:25:15 PM] INFO com.wurmonline.server.Server: Lag detected at Zones.pollnextzones (0.5): 7.098 seconds
[02:25:15 PM] INFO com.wurmonline.server.structures.Blocking: Razor checking 3.0 meters failed. Checks=62
[02:25:15 PM] INFO com.wurmonline.server.Server: Elapsed time (7098ms) for this loop was more than 1 second so adding it to the lag count, which is now: 997
[02:25:33 PM] INFO com.wurmonline.server.zones.Zone: Zone at 3840, 2368 polled 132 tiles. That took 6711.432 millis.
[02:25:33 PM] INFO com.wurmonline.server.Server: Lag detected at Zones.pollnextzones (0.5): 6.724 seconds
[02:25:33 PM] INFO com.wurmonline.server.Server: Elapsed time (6724ms) for this loop was more than 1 second so adding it to the lag count, which is now: 1003
[02:25:50 PM] INFO com.wurmonline.server.Server: Lag detected at Zones.pollnextzones (0.5): 6.911 seconds
[02:25:50 PM] INFO com.wurmonline.server.Server: Elapsed time (6911ms) for this loop was more than 1 second so adding it to the lag count, which is now: 1009

 

Share this post


Link to post
Share on other sites

[09:25:37 PM] WARNING com.wurmonline.server.webinterface.WebInterfaceImpl: Could not get ClientHost details due to not in a remote call
java.rmi.server.ServerNotActiveException: not in a remote call
    at sun.rmi.transport.tcp.TCPTransport.getClientHost(Unknown Source)
    at java.rmi.server.RemoteServer.getClientHost(Unknown Source)
    at com.wurmonline.server.webinterface.WebInterfaceImpl.getRemoteClientDetails(WebInterfaceImpl.java:201)
    at com.wurmonline.server.webinterface.WebInterfaceImpl.addMoneyToBank(WebInterfaceImpl.java:1845)
    at com.wurmonline.server.webinterface.WebInterfaceImpl.addMoneyToBank(WebInterfaceImpl.java:1773)
    at com.wurmonline.server.LoginServerWebConnection.addMoney(LoginServerWebConnection.java:240)
    at com.wurmonline.server.players.Player.poll(Player.java:3541)
    at com.wurmonline.server.creatures.Creatures.pollAllCreatures(Creatures.java:1706)
    at com.wurmonline.server.zones.Zones.pollNextZones(Zones.java:1543)
    at com.wurmonline.server.Server.run(Server.java:1812)
    at java.util.TimerThread.mainLoop(Unknown Source)
    at java.util.TimerThread.run(Unknown Source)

 

Share this post


Link to post
Share on other sites

Gotta love these.

 

[07:11:40 PM] WARNING com.wurmonline.server.webinterface.WebInterfaceImpl: Could not get ClientHost details due to not in a remote call
java.rmi.server.ServerNotActiveException: not in a remote call
    at sun.rmi.transport.tcp.TCPTransport.getClientHost(Unknown Source)
    at java.rmi.server.RemoteServer.getClientHost(Unknown Source)
    at com.wurmonline.server.webinterface.WebInterfaceImpl.getRemoteClientDetails(WebInterfaceImpl.java:201)
    at com.wurmonline.server.webinterface.WebInterfaceImpl.addMoneyToBank(WebInterfaceImpl.java:1845)
    at com.wurmonline.server.webinterface.WebInterfaceImpl.addMoneyToBank(WebInterfaceImpl.java:1773)
    at com.wurmonline.server.LoginServerWebConnection.addMoney(LoginServerWebConnection.java:240)
    at com.wurmonline.server.players.Player.poll(Player.java:3541)
    at com.wurmonline.server.creatures.Creatures.pollAllCreatures(Creatures.java:1706)
    at com.wurmonline.server.zones.Zones.pollNextZones(Zones.java:1543)
    at com.wurmonline.server.Server.run(Server.java:1812)
    at java.util.TimerThread.mainLoop(Unknown Source)

Share this post


Link to post
Share on other sites

Dev's even looking at this stuff anymore?  

The polling is horrible with any kind of population on it.... LOL 

Edited by razoreqx

Share this post


Link to post
Share on other sites

[01:06:10 PM] WARNING com.wurmonline.server.zones.Zone: 2014 tile 2022,1927 where Connak should be didn't contain it. The creature.currentTile removed it=false
java.lang.Exception
    at com.wurmonline.server.zones.Zone.deleteCreature(Zone.java:1799)
    at com.wurmonline.server.creatures.Creature.startTeleporting(Creature.java:3272)
    at com.wurmonline.server.creatures.Creature.startTeleporting(Creature.java:3179)
    at com.wurmonline.server.questions.SelectSpawnQuestion.answer(SelectSpawnQuestion.java:127)
    at com.wurmonline.server.creatures.Communicator.reallyHandle_CMD_BML_FORM(Communicator.java:3494)
    at com.wurmonline.server.creatures.Communicator.reallyHandle(Communicator.java:2413)
    at com.wurmonline.communication.SocketConnection.tick(SocketConnection.java:615)
    at com.wurmonline.communication.SocketServer.tick(SocketServer.java:172)
    at com.wurmonline.server.Server.run(Server.java:2422)
    at java.util.TimerThread.mainLoop(Unknown Source)
    at java.util.TimerThread.run(Unknown Source)

Share this post


Link to post
Share on other sites
On 6/4/2016 at 4:28 AM, razoreqx said:

java.rmi.server.ServerNotActiveException: not in a remote call

 

I think this happens when a player on the login server gets money via COD mail. Probably missed by the devs since nobody is sending COD mails on GV (which is the login server for WO) nowadays :P - Not sure if it causes any actual issues except log spam, needs testing.

 

10 hours ago, razoreqx said:

[01:06:10 PM] WARNING com.wurmonline.server.zones.Zone: 2014 tile 2022,1927 where Connak should be didn't contain it. The creature.currentTile removed it=false

 

Caused by a new player spawning in, they are in limbo while they answer that select your gender (and kingdom if not home server) popup. Once the server puts them into the actual spawn location - this error is logged. AFAIK it's just log spam, no other ill effects.

 

10 hours ago, razoreqx said:

Dev's even looking at this stuff anymore?  

 

Probably not, each time i got the devs to fix anything it was by poking people in PMs :(

Edited by bdew

Share this post


Link to post
Share on other sites
3 hours ago, bdew said:

Probably not, each time i got the devs to fix anything it was by poking people in PMs :(

 

they ever patch that steam auth btw?

Share this post


Link to post
Share on other sites

I have seen these things, and they do not cause any problems. Bdew is correct the first one is COD mail, but the money does go into the bank appropriately. The one thing missed in Bdew's explanation is this only happens when the person receiving the money is offline. This error also triggers if you use the #addmoney command and give a player silver, and they are not online. The reason this happens "not in a remote call" is because they player is not logged in, therefore the communicator has no client to send the "You now have xxx in the bank" message to. That is what the error boils down to, the only issue that the server is trying to report is that the communicator could not communicate with the player.

 

So it just outputs this into the log, just in case a rare circumstance happens it is an issue, but in every case for me so far (thousands) it has had no effect on the server itself or the bank of the player.

Edited by Xyp
Small clarification fix

Share this post


Link to post
Share on other sites

Now I wanted to make this a separate reply because you could see issues with the following:

 

server uptime: 63903 seconds. Unanswered questions:0
[02:24:43 PM] INFO com.wurmonline.server.Server: Lag detected at Zones.pollnextzones (0.5): 12.184 seconds
[02:24:43 PM] INFO com.wurmonline.server.Server: Elapsed time (12200ms) for this loop was more than 1 second so adding it to the lag count, which is now: 984

 

This is only an INFO error, which in most cases is no big deal, INFO is just that, server is just letting you know stuff that happened.

 

You can get less of these errors by increasing the LAG_THRESHOLD in the wurm.ini For example if you up it to 10000 instead of the default 1000 it will only inform you of actions that take longer than 10 seconds.

 

One thing I would note is this seems like a lot, something is going on.

 

I used to have a lot of these until I increased my LAG_THRESHOLD to 10000, now I almost never get these. However I notice you have some that are over 10 seconds long, which would concern me. Is your server using SSD drives? Also is your server set to use enough Ram to operate the amount of activity/map size that you have. Remember by default the server is only set to use 2 gigs of ram, which is not enough for larger active maps. I have my set to use up to a max of 10 gigs of ram, while my main server rarely uses more than 4-4.5 gigs, its still nice to have that cushion.

 

Edited by Xyp

Share this post


Link to post
Share on other sites
3 hours ago, akaedis said:

 

they ever patch that steam auth btw?

 

The exploit that allowed to login as other accounts is fixed, the bug that causes Duplicate Authentication errors isn't AFAIK.

 

2 hours ago, Xyp said:

The reason this happens "not in a remote call" is because they player is not logged in, therefore the communicator has no client to send the "You now have xxx in the bank" message to.

 

Not exactly. The server is using an RMI call to inform the login server that money was added. The login server tries to log the IP where that call originated from, but if the game and login server are the same thing - the call gets short-circuited directly to the RMI handler without going through the Java RMI system (you can see that in LoginServerWebConnection.connect()), so there is no address because you are "not in a remote call". If you look at the stacktrace you will see the exception is thrown in "java.rmi.server.RemoteServer.getClientHost".

 

This doesn't happen in clusters when the player is not on the login server. I'm not sure why it doesn't happen for logged in players, probably a different code path is taken... somewhere.

 

If you look at Player.addMoney - there is a check that would prevent this error, but that check is not present in Player.poll

 

2 hours ago, Xyp said:

Is your server using SSD drives?

 

I'm curious how much that actually helps. Seems to me that wurm holds most stuff in memory so reading should be minimal and most writing is done in separate threads. Anyone did any real comparisons?

Edited by bdew

Share this post


Link to post
Share on other sites

Bdew first of all, I dare you to test giving of money to a player via cod or #addmoney with them logged in, and logged out, on a connected server, and not. I dare you, as I have watched it a thousand times to come to my conclusions lol. It is calling in RemoteServer.getClientHost because if it cant find the client locally it will try to find it remotely. Now with this I will say I have never bothered to check with a server not connected to other servers, and I suspect neither has Razor as I know he runs connected servers as well.

 

Beyond that, yes I have tried with 7200 RPM disc drives, and they are terrible almost unusable, and your server will lag like holy heck.

Share this post


Link to post
Share on other sites
20 minutes ago, Xyp said:

Bdew first of all, I dare you to test giving of money to a player via cod or #addmoney with them logged in, and logged out, on a connected server, and not. I dare you, as I have watched it a thousand times to come to my conclusions lol. It is calling in RemoteServer.getClientHost because if it cant find the client locally it will try to find it remotely. Now with this I will say I have never bothered to check with a server not connected to other servers, and I suspect neither has Razor as I know he runs connected servers as well.

 

 

I'm standing by what i said, though i don't have the time to do proper testing right now. Do note that i analyzed it from the point of getting money from mail rather than a gm-issued commad. For the command case i think the difference would be on what server the command was issued on, rather than the server where the player itself is located.

 

The specific call that fails is this:

WebInterfaceImpl.logger.log(Level.INFO, String.valueOf(this.getRemoteClientDetails()) + " Add money to bank 2 , " + moneyToAdd + " for player name: " + name + ", wid " + wurmId);

with getRemoteClientDetails reffering to the RMI client (= the originating server), not the player.

 

 

20 minutes ago, Xyp said:

Beyond that, yes I have tried with 7200 RPM disc drives, and they are terrible almost unusable, and your server will lag like holy heck.

 

Interesting. My server is pretty small (2048 map, not a lot of players) but it runs along with a bunch of other stuff on a server with 2x 7200 RPM drives in a RAID1 setup (not even hardware raid, just md). I haven't noticed any IO bottlenecks and my "lag count" is usually at solid 0.

Edited by bdew

Share this post


Link to post
Share on other sites

The main thing I noticed with the RPM drives I started out with, was right click lag was more apparent, with SSD its pretty instant.

 

All and all with the remote issue, I can tell you this, no matter what server the player is on, no matter what server you are on, no matter COD or Command, if the player is online you will not get this error. HOWEVER, funny enough, if the player on a server that is not the login server, adds money to the bank, sometimes the error will spam, that one I havnt figured out yet.

 

Important thing is its still some weird communication issue even with add to bank. So they still get their money properly.

Edited by Xyp

Share this post


Link to post
Share on other sites
8 hours ago, bdew said:

 

I think this happens when a player on the login server gets money via COD mail. Probably missed by the devs since nobody is sending COD mails on GV (which is the login server for WO) nowadays :P - Not sure if it causes any actual issues except log spam, needs testing.

 

 

Caused by a new player spawning in, they are in limbo while they answer that select your gender (and kingdom if not home server) popup. Once the server puts them into the actual spawn location - this error is logged. AFAIK it's just log spam, no other ill effects.

 

 

Probably not, each time i got the devs to fix anything it was by poking people in PMs :(

 

Thanks for the follow up bdew! 

Share this post


Link to post
Share on other sites

Create an account or sign in to comment

You need to be a member in order to leave a comment

Create an account

Sign up for a new account in our community. It's easy!

Register a new account

Sign in

Already have an account? Sign in here.

Sign In Now
Sign in to follow this