Posted June 8, 2016 My server sometimes have "lag". version 1.0.0.6 , 3.19.0-49-generic 14.04.1-Ubuntu x86_64 Network Checked - medium latency 200-250 ms - i think it is good. no packet loss. Memory : 3gb max heap, 2-2.2 gb used from heap. no heap \ memory errors warnings. Cpu at most used 35 percents no other heavy tasks running. maybe some code not working good ? i collected warrings and errors from logs so maye someone know how to fix it or at least workaround to their influence on robustness. [01:11:17 PM] WARNING com.wurmonline.server.players.PermissionsHistories: Failed to add permissions history for object (4336326710788) java.sql.SQLException: [SQLITE_CONSTRAINT] Abort due to constraint violation (NOT NULL constraint failed: PERMISSIONSHISTORY.PK) at org.sqlite.core.DB.newSQLException(DB.java:890) at org.sqlite.core.DB.newSQLException(DB.java:901) at org.sqlite.core.DB.execute(DB.java:810) at org.sqlite.core.DB.executeUpdate(DB.java:847) at org.sqlite.jdbc3.JDBC3PreparedStatement.executeUpdate(JDBC3PreparedStatement.java:86) at com.wurmonline.server.players.PermissionsHistories.dbAddHistoryEvent(PermissionsHistories.java:205) at com.wurmonline.server.players.PermissionsHistories.addHistoryEntry(PermissionsHistories.java:183) at com.wurmonline.server.questions.ManagePermissions.answer(ManagePermissions.java:508) at com.wurmonline.server.creatures.Communicator.reallyHandle_CMD_PERMISSIONS(Communicator.java:2960) at com.wurmonline.server.creatures.Communicator.reallyHandle(Communicator.java:2527) 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(Timer.java:555) at java.util.TimerThread.run(Timer.java:505) As i understand here is a need of some "pre check" so it will not abort while execution but will be stoped from execution? [01:11:35 PM] WARNING com.wurmonline.server.behaviours.Terraforming: No template for flowers! com.wurmonline.server.items.NoSuchTemplateException: No item template with id -1 at com.wurmonline.server.items.ItemTemplateFactory.getTemplate(ItemTemplateFactory.java:81) at com.wurmonline.server.items.ItemFactory.createItem(ItemFactory.java:110) at com.wurmonline.server.items.ItemFactory.createItem(ItemFactory.java:88) at com.wurmonline.server.items.ItemFactory.createItem(ItemFactory.java:173) at com.wurmonline.server.behaviours.Terraforming.pickFlower(Terraforming.java:4526) at com.wurmonline.server.behaviours.TileGrassBehaviour.action(TileGrassBehaviour.java:784) at com.wurmonline.server.behaviours.Action.poll(Action.java:2854) at com.wurmonline.server.behaviours.ActionStack.poll(ActionStack.java:237) at com.wurmonline.server.players.Player.pollActions(Player.java:6708) at com.wurmonline.server.Players.pollPlayers(Players.java:4353) template cant have -1 number , correct? so somehow it got such id... i dont think it working as expected [01:17:30 PM] INFO com.wurmonline.server.creatures.Communicator: Unable to find dragged item com.wurmonline.server.NoSuchItemException: No item found with id 50730144011778 at com.wurmonline.server.Items.getItem(Items.java:245) at com.wurmonline.server.creatures.Communicator.reallyHandle_CMD_MOVE_INVENTORY(Communicator.java:3632) at com.wurmonline.server.creatures.Communicator.reallyHandle(Communicator.java:2400) 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(Timer.java:555) at java.util.TimerThread.run(Timer.java:505) Maybe here to can be inserted some sort of "pre check" ? or other way to make it work more ...stable [01:23:26 PM] WARNING com.wurmonline.server.creatures.MovementScheme: PLAYER_NAME TOO FAR, input=0.10635372, expected=0.105382815 : 13292.792(13292.699); 4018.2546(4018.2026) bridge=-10 [01:23:26 PM] INFO com.wurmonline.server.players.Player: PLAYER_NAME intrateleport to 13292.699,4018.2026, 15.8499, layer 0 currentTile:null=false reason=Moved too far hasVisionArea=true, initialized=true vehicle=-10 java.lang.Exception at com.wurmonline.server.players.Player.intraTeleport(Player.java:5059) at com.wurmonline.server.creatures.MovementScheme.handleMoveTooFar(MovementScheme.java:780) at com.wurmonline.shared.util.MovementChecker.movestep(MovementChecker.java:271) at com.wurmonline.server.creatures.Communicator.pollNextMove(Communicator.java:1125) at com.wurmonline.server.Server.pollComms(Server.java:2559) at com.wurmonline.server.Server.run(Server.java:2437) at java.util.TimerThread.mainLoop(Timer.java:555) at java.util.TimerThread.run(Timer.java:505) This happen then player connection become high latency (from 200-250 to 400-600 ms), can there be some sort of workaround applied? [01:25:55 PM] SEVERE org.gotti.wurmunlimited.mods.serverpacks.PackServer: Connection timed out java.io.IOException: Connection timed out at sun.nio.ch.FileDispatcherImpl.write0(Native Method) at sun.nio.ch.SocketDispatcher.write(SocketDispatcher.java:47) at sun.nio.ch.IOUtil.writeFromNativeBuffer(IOUtil.java:93) at sun.nio.ch.IOUtil.write(IOUtil.java:65) at sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:471) at sun.net.httpserver.Request$WriteStream.write(Request.java:391) at sun.net.httpserver.ChunkedOutputStream.writeChunk(ChunkedOutputStream.java:125) at sun.net.httpserver.ChunkedOutputStream.write(ChunkedOutputStream.java:95) at sun.net.httpserver.PlaceholderOutputStream.write(ExchangeImpl.java:444) at org.gotti.wurmunlimited.mods.serverpacks.PackServer$1.handle(PackServer.java:60) at com.sun.net.httpserver.Filter$Chain.doFilter(Filter.java:79) at sun.net.httpserver.AuthFilter.doFilter(AuthFilter.java:83) at com.sun.net.httpserver.Filter$Chain.doFilter(Filter.java:82) at sun.net.httpserver.ServerImpl$Exchange$LinkHandler.handle(ServerImpl.java:675) at com.sun.net.httpserver.Filter$Chain.doFilter(Filter.java:79) at sun.net.httpserver.ServerImpl$Exchange.run(ServerImpl.java:647) at sun.net.httpserver.ServerImpl$DefaultExecutor.execute(ServerImpl.java:158) at sun.net.httpserver.ServerImpl$Dispatcher.handle(ServerImpl.java:431) at sun.net.httpserver.ServerImpl$Dispatcher.run(ServerImpl.java:396) at java.lang.Thread.run(Thread.java:745) Suppressed: java.io.IOException: Broken pipe at sun.nio.ch.FileDispatcherImpl.write0(Native Method) at sun.nio.ch.SocketDispatcher.write(SocketDispatcher.java:47) at sun.nio.ch.IOUtil.writeFromNativeBuffer(IOUtil.java:93) at sun.nio.ch.IOUtil.write(IOUtil.java:65) at sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:471) at sun.net.httpserver.Request$WriteStream.write(Request.java:391) at sun.net.httpserver.ChunkedOutputStream.writeChunk(ChunkedOutputStream.java:125) at sun.net.httpserver.ChunkedOutputStream.flush(ChunkedOutputStream.java:159) at sun.net.httpserver.ChunkedOutputStream.close(ChunkedOutputStream.java:134) at sun.net.httpserver.PlaceholderOutputStream.close(ExchangeImpl.java:454) at org.gotti.wurmunlimited.mods.serverpacks.PackServer$1.handle(PackServer.java:63) ... 10 more i understand this is from mod (serverpacks) , but as i assume that this mod use almost everyone.. server behind nat port opened, and some times it even succed in delivering pakcs...but this should not happen, is it? [02:14:09 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(TCPTransport.java:613) at java.rmi.server.RemoteServer.getClientHost(RemoteServer.java:77) 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:2840) 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(Timer.java:555) at java.util.TimerThread.run(Timer.java:505) [02:14:09 PM] INFO com.wurmonline.server.webinterface.WebInterfaceImpl: Unknown Remote Client Add money to bank 2 , 10 for player name: PLAYER_NAME, wid -1 RMI disabled..it`s looks like exploit ,, and until 1.0.0.6 version, i dont seen such warrnings.. Also if anyone have some strategy to "hunt down lag" share them please. Share this post Link to post Share on other sites
Posted June 8, 2016 The last snippet looks like bountymod. Bountymod puts a message like that one in my server console - see where it is adding money to bank? Share this post Link to post Share on other sites
Posted June 8, 2016 2 hours ago, masaykh said: [01:11:17 PM] WARNING com.wurmonline.server.players.PermissionsHistories: Failed to add permissions history for object This is a problem with the creative template database as shipped with WU. See here for a fix: http://forum.wurmonline.com/index.php?/topic/138343-permission-histories-not-saving-how-to-fix/ 2 hours ago, masaykh said: [01:17:30 PM] INFO com.wurmonline.server.creatures.Communicator: Unable to find dragged item Probably just someone dragging an item twice due to latency. If you are having latency and/or packet loss issues - that's just a manifestation of that, not something that can be directly fixed. 2 hours ago, masaykh said: [01:23:26 PM] WARNING com.wurmonline.server.creatures.MovementScheme: PLAYER_NAME TOO FAR, Again, stuff caused by latency / desync. Same as above. 2 hours ago, masaykh said: [01:25:55 PM] SEVERE org.gotti.wurmunlimited.mods.serverpacks.PackServer: Connection timed out Someone downloading a pack and their connection is timing out. Not much the mod can do about that. 2 hours ago, masaykh said: [02:14:09 PM] WARNING com.wurmonline.server.webinterface.WebInterfaceImpl: Could not get ClientHost details due to not in a remote call That's a WU bug, generally harmless except for the log spam. Discussed in this thread if you want more info: http://forum.wurmonline.com/index.php?/topic/141931-lag-detect-loops/ 1 Share this post Link to post Share on other sites
Posted June 8, 2016 Bdew can you elaborate about this : [07:25:24 PM] SEVERE org.gotti.wurmunlimited.mods.serverpacks.PackServer: Connection reset by peer java.io.IOException: Connection reset by peer at sun.nio.ch.FileDispatcherImpl.write0(Native Method) at sun.nio.ch.SocketDispatcher.write(SocketDispatcher.java:47) at sun.nio.ch.IOUtil.writeFromNativeBuffer(IOUtil.java:93) at sun.nio.ch.IOUtil.write(IOUtil.java:65) at sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:471) at sun.net.httpserver.Request$WriteStream.write(Request.java:391) at sun.net.httpserver.ChunkedOutputStream.writeChunk(ChunkedOutputStream.java:125) at sun.net.httpserver.ChunkedOutputStream.write(ChunkedOutputStream.java:95) at sun.net.httpserver.PlaceholderOutputStream.write(ExchangeImpl.java:444) at org.gotti.wurmunlimited.mods.serverpacks.PackServer$1.handle(PackServer.java:60) at com.sun.net.httpserver.Filter$Chain.doFilter(Filter.java:79) at sun.net.httpserver.AuthFilter.doFilter(AuthFilter.java:83) at com.sun.net.httpserver.Filter$Chain.doFilter(Filter.java:82) at sun.net.httpserver.ServerImpl$Exchange$LinkHandler.handle(ServerImpl.java:675) at com.sun.net.httpserver.Filter$Chain.doFilter(Filter.java:79) at sun.net.httpserver.ServerImpl$Exchange.run(ServerImpl.java:647) at sun.net.httpserver.ServerImpl$DefaultExecutor.execute(ServerImpl.java:158) at sun.net.httpserver.ServerImpl$Dispatcher.handle(ServerImpl.java:431) at sun.net.httpserver.ServerImpl$Dispatcher.run(ServerImpl.java:396) at java.lang.Thread.run(Thread.java:745) Suppressed: java.io.IOException: Broken pipe at sun.nio.ch.FileDispatcherImpl.write0(Native Method) at sun.nio.ch.SocketDispatcher.write(SocketDispatcher.java:47) at sun.nio.ch.IOUtil.writeFromNativeBuffer(IOUtil.java:93) at sun.nio.ch.IOUtil.write(IOUtil.java:65) at sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:471) at sun.net.httpserver.Request$WriteStream.write(Request.java:391) at sun.net.httpserver.ChunkedOutputStream.writeChunk(ChunkedOutputStream.java:125) at sun.net.httpserver.ChunkedOutputStream.flush(ChunkedOutputStream.java:159) at sun.net.httpserver.ChunkedOutputStream.close(ChunkedOutputStream.java:134) at sun.net.httpserver.PlaceholderOutputStream.close(ExchangeImpl.java:454) at org.gotti.wurmunlimited.mods.serverpacks.PackServer$1.handle(PackServer.java:63) ... 10 more Share this post Link to post Share on other sites
Posted June 8, 2016 "Connection reset by peer" means the other side force-closed the connection. Possibly because the client was closed or crashed. Share this post Link to post Share on other sites
Posted June 8, 2016 this happen once player connected, player after this error not disconected, and keep playing fine..so you wrong here... Share this post Link to post Share on other sites
Posted June 9, 2016 (edited) I said "possibly". The message means your server received an RST packet, it's not possible to know why (or even by who) that packet was sent, i just gave some possible causes. Is there anything logged on the clients when this happens? Also is that server in a datacenter or a home broadband connection? Edited June 9, 2016 by bdew Share this post Link to post Share on other sites
Posted June 9, 2016 datacenter, nothing logged on playerside Share this post Link to post Share on other sites
Posted June 9, 2016 (edited) datacenter, nothing logged on playerside as i and players found : when server do this [07:35:22 PM] INFO com.wurmonline.server.zones.Zone: Zone at 2112, 896 polled 131 tiles. That took 642.14386 millis. [07:35:32 PM] INFO com.wurmonline.server.zones.Zone: Zone at 3008, 3392 polled 81 tiles. That took 467.0646 millis. [07:35:41 PM] INFO com.wurmonline.server.zones.Zone: Zone at 2048, 896 polled 198 tiles. That took 714.64514 millis. [07:35:50 PM] INFO com.wurmonline.server.zones.Zone: Zone at 3008, 640 polled 184 tiles. That took 628.92535 millis. players got lag that end when polling end what can be done? one more : [12:38:32 PM] WARNING com.wurmonline.server.behaviours.Action: Array index out of bounds while polling an action PLAYER_NAME due to null java.lang.ArrayIndexOutOfBoundsException Edited June 10, 2016 by masaykh Share this post Link to post Share on other sites
Posted June 13, 2016 How bad is the lag, is it frequent, or just a big spike every few hours, when did this start, what size is your map, how many players do you have, how many items in your database? Share this post Link to post Share on other sites
Posted June 13, 2016 medium off badnesses every few hours - then i investigated further - it led me to ZonePolling. lags started then player base grow beyond 40 players or so currently 55-75 players online. map size - 4096 size of wurmitems.db = 720kb Share this post Link to post Share on other sites