Items Disappear from Database

[Brian 16]

I've been having items, usually large ones like ovens and food storage bins, mysteriously disappear from the database. This appears to happen while the server is running.

 

What happens is that I will right-click an oven, for example, and the popup menu gets stuck in a "refreshing" state while it presumably tries to access the database. If you restart the server, the oven has vanished.  This suggests to me that it was there when the server had previously started (allowing it to be visible), but disappeared sometime after, leading to the "refresh" behavior.  

 

Looking at the database, the Wurm ID entry for the item is no longer present when this happens, though if you search for it in the Parent ID field, it is referenced by all the items that were inside; they are still in the database.

I've tried searching on the item name ("oven") and it appears that the entire entry was deleted, not just that the wurm ID was modified somehow.

 

I can go back to a previous backup and use data there to re-add an entry for the item, and it comes back with all the items inside.

 

My wurm.ini file contains bdew's USE_SCHEDULED_EXECUTOR fix, so I don't think it's that; the behavior is a little different as well.

 

Does anyone know what could be going on? Is this a known issue?

[Sklo:D 2,210]

The logs usually give a good explanation of what's going on. Make sure to post the wurm.log.0 here.

Edited September 9, 2018 by Sklo:D

[Brian 16]

Here's the most recent log I could find (these are 3rd-party hosted servers). I think the problem I most recently experienced must have occurred before this; I'll try to find any older logs that may contain info.

 

However, this one does show a suspicious exception further down: an "Unable to find top parent" error. It's strange, because that wurm ID (7234023769602) is in the most recent wurmitems.db that should have been there when the server started up; it's a venerable gray horse corpse. I had just uploaded that db (because it had the entry I had added to restore the missing oven) before starting the server.

 

Also, fyi, this is a clustered server that connects to the Riddleridge login server.

 

Next time it happens, I'll grab the log ASAP to see if it has more info.

 

 

----------------------------------------------------------------
Wurm Server logging started at Sun Sep 09 15:52:09 GMT+01:00 2018
----------------------------------------------------------------
[03:52:10 PM] INFO com.wurmonline.server.Constants: motd: Welcome to Watercrest!
[03:52:10 PM] INFO com.wurmonline.server.Constants: 
[03:52:10 PM] INFO com.wurmonline.server.Constants: fileName: Creative_custom\wurm.ini
[03:52:10 PM] INFO com.wurmonline.server.Constants: 
[03:52:10 PM] INFO com.wurmonline.server.Constants: Check WURMLOGS: false
[03:52:10 PM] INFO com.wurmonline.server.Constants: isGameServer: true
[03:52:10 PM] INFO com.wurmonline.server.Constants: devmode: false
[03:52:10 PM] INFO com.wurmonline.server.Constants: maintaining: false
[03:52:10 PM] INFO com.wurmonline.server.Constants: crashed: false
[03:52:10 PM] INFO com.wurmonline.server.Constants: RUNBATCH: false
[03:52:10 PM] INFO com.wurmonline.server.Constants: pruneDb: true
[03:52:10 PM] INFO com.wurmonline.server.Constants: reprospect: false
[03:52:10 PM] INFO com.wurmonline.server.Constants: caveImg: false
[03:52:10 PM] INFO com.wurmonline.server.Constants: createSeeds: false
[03:52:10 PM] INFO com.wurmonline.server.Constants: Min millis between player connections: 1000
[03:52:10 PM] INFO com.wurmonline.server.Constants: 
[03:52:10 PM] INFO com.wurmonline.server.Constants: fileDBPath: Creative_custom\
[03:52:10 PM] INFO com.wurmonline.server.Constants: dbHost: Creative_custom
[03:52:10 PM] INFO com.wurmonline.server.Constants: useSplitCreaturesTable: false
[03:52:10 PM] INFO com.wurmonline.server.Constants: analyseAllDbTables: false
[03:52:10 PM] INFO com.wurmonline.server.Constants: checkAllDbTables: true
[03:52:10 PM] INFO com.wurmonline.server.Constants: optimiseAllDbTables: false
[03:52:10 PM] INFO com.wurmonline.server.Constants: createTemporaryDatabaseIndicesAtStartup: true
[03:52:10 PM] INFO com.wurmonline.server.Constants: dropTemporaryDatabaseIndicesAtStartup: true
[03:52:10 PM] INFO com.wurmonline.server.Constants: usePrepStmts: false
[03:52:10 PM] INFO com.wurmonline.server.Constants: gatherDbStats: false
[03:52:10 PM] INFO com.wurmonline.server.Constants: 
[03:52:10 PM] INFO com.wurmonline.server.Constants: 
[03:52:10 PM] INFO com.wurmonline.server.Constants: 
[03:52:10 PM] INFO com.wurmonline.server.Constants: dbUser: root
[03:52:10 PM] INFO com.wurmonline.server.Constants: dbDriver: 
[03:52:10 PM] INFO com.wurmonline.server.Constants: useDb: true
[03:52:10 PM] INFO com.wurmonline.server.Constants: usePooledDb: false
[03:52:10 PM] INFO com.wurmonline.server.Constants: dbPort: 
[03:52:10 PM] INFO com.wurmonline.server.Constants: trackOpenDatabaseResources: false
[03:52:10 PM] INFO com.wurmonline.server.Constants: 
[03:52:10 PM] INFO com.wurmonline.server.Constants: numberOfDirtyMeshRowsToSaveEachCall: 10
[03:52:10 PM] INFO com.wurmonline.server.Constants: useDirectByteBuffersForMeshIO: true
[03:52:10 PM] INFO com.wurmonline.server.Constants: 
[03:52:10 PM] INFO com.wurmonline.server.Constants: webPath: .
[03:52:10 PM] INFO com.wurmonline.server.Constants: skillTemplatesDBPath: templates\skills\
[03:52:10 PM] INFO com.wurmonline.server.Constants: zonesDBPath: zones\
[03:52:10 PM] INFO com.wurmonline.server.Constants: itemTemplatesDBPath: templates\items\
[03:52:10 PM] INFO com.wurmonline.server.Constants: creatureStatsDBPath: creatures\
[03:52:10 PM] INFO com.wurmonline.server.Constants: playerStatsDBPath: players\
[03:52:10 PM] INFO com.wurmonline.server.Constants: itemStatsDBPath: items\
[03:52:10 PM] INFO com.wurmonline.server.Constants: tileStatsDBPath: tiles\
[03:52:10 PM] INFO com.wurmonline.server.Constants: itemOldStatsDBPath: olditems\
[03:52:10 PM] INFO com.wurmonline.server.Constants: creatureOldStatsDBPath: deadCreatures\
[03:52:10 PM] INFO com.wurmonline.server.Constants: useQueueToSendDataToPlayers: false
[03:52:10 PM] INFO com.wurmonline.server.Constants: useMultiThreadedBankPolling: false
[03:52:10 PM] INFO com.wurmonline.server.Constants: useScheduledExecutorToCountEggs: true
[03:52:10 PM] INFO com.wurmonline.server.Constants: useScheduledExecutorToSaveConstants: false
[03:52:10 PM] INFO com.wurmonline.server.Constants: useScheduledExecutorToSaveDirtyMeshRows: true
[03:52:10 PM] INFO com.wurmonline.server.Constants: useScheduledExecutorToSendTimeSync: true
[03:52:10 PM] INFO com.wurmonline.server.Constants: useScheduledExecutorToSwitchFatigue: false
[03:52:10 PM] INFO com.wurmonline.server.Constants: useScheduledExecutorToTickCalendar: true
[03:52:10 PM] INFO com.wurmonline.server.Constants: useScheduledExecutorToWriteLogs: true
[03:52:10 PM] INFO com.wurmonline.server.Constants: useScheduledExecutorForServer: false
[03:52:10 PM] INFO com.wurmonline.server.Constants: scheduledExecutorServiceThreads: 20
[03:52:10 PM] INFO com.wurmonline.server.Constants: useItemTransferLog: false
[03:52:10 PM] INFO com.wurmonline.server.Constants: useTileEventLog: false
[03:52:10 PM] INFO com.wurmonline.server.Constants: useDatabaseForServerStatisticsLog: false
[03:52:10 PM] INFO com.wurmonline.server.Constants: useScheduledExecutorToUpdateCreaturePositionInDatabase: false
[03:52:10 PM] INFO com.wurmonline.server.Constants: useScheduledExecutorToUpdatePlayerPositionInDatabase: true
[03:52:10 PM] INFO com.wurmonline.server.Constants: useScheduledExecutorToUpdateItemDamageInDatabase: true
[03:52:10 PM] INFO com.wurmonline.server.Constants: useScheduledExecutorToUpdateItemOwnerInDatabase: false
[03:52:10 PM] INFO com.wurmonline.server.Constants: useScheduledExecutorToUpdateItemLastOwnerInDatabase: false
[03:52:10 PM] INFO com.wurmonline.server.Constants: useScheduledExecutorToUpdateItemParentInDatabase: false
[03:52:10 PM] INFO com.wurmonline.server.Constants: useScheduledExecutorToConnectToTwitter: true
[03:52:10 PM] INFO com.wurmonline.server.Constants: numberOfDbCreaturePositionsToUpdateEachTime: 500
[03:52:10 PM] INFO com.wurmonline.server.Constants: numberOfDbPlayerPositionsToUpdateEachTime: 500
[03:52:10 PM] INFO com.wurmonline.server.Constants: numberOfDbItemDamagesToUpdateEachTime: 500
[03:52:10 PM] INFO com.wurmonline.server.Constants: numberOfDbItemOwnersToUpdateEachTime: 500
[03:52:10 PM] INFO com.wurmonline.server.Constants: playerStatLog: numplayers.log
[03:52:10 PM] INFO com.wurmonline.server.Constants: logonStatLog: numlogons.log
[03:52:10 PM] INFO com.wurmonline.server.Constants: ipStatLog: numips.log
[03:52:10 PM] INFO com.wurmonline.server.Constants: newbieStatLog: newbies.log
[03:52:10 PM] INFO com.wurmonline.server.Constants: totIpStatLog: totalips.log
[03:52:10 PM] INFO com.wurmonline.server.Constants: payingLog: paying.log
[03:52:10 PM] INFO com.wurmonline.server.Constants: moneyLog: mrtgmoney.log
[03:52:10 PM] INFO com.wurmonline.server.Constants: lagLog: lag.log
[03:52:10 PM] INFO com.wurmonline.server.Constants: lagThreshold: 1000
[03:52:10 PM] INFO com.wurmonline.server.Constants: Eigc enabled false
[03:52:10 PM] INFO com.wurmonline.server.Constants: useIncomingRMI: true
[03:52:10 PM] INFO com.wurmonline.server.Server: Adding Shutdown Hook
[03:52:10 PM] INFO com.wurmonline.server.Server: Wurm Impl Title: Wurm Server
[03:52:10 PM] INFO com.wurmonline.server.Server: Wurm Impl Vendor: CodeClub AB
[03:52:10 PM] INFO com.wurmonline.server.Server: Wurm Impl Version: 1.6.0.2-SNAPSHOT
[03:52:10 PM] INFO com.wurmonline.server.Server: Wurm Common Impl Title: Wurm Common
[03:52:10 PM] INFO com.wurmonline.server.Server: Wurm Common Impl Vendor: CodeClub AB
[03:52:10 PM] INFO com.wurmonline.server.Server: Wurm Common Impl Version: 1.7.0.0
[03:52:10 PM] INFO com.wurmonline.server.Server: MySQL JDBC Spec Title: null
[03:52:10 PM] INFO com.wurmonline.server.Server: MySQL JDBC Spec Vendor: null
[03:52:10 PM] INFO com.wurmonline.server.Server: MySQL JDBC Spec Version: null
[03:52:10 PM] INFO com.wurmonline.server.Server: MySQL JDBC Impl Title: null
[03:52:10 PM] INFO com.wurmonline.server.Server: MySQL JDBC Impl Vendor: null
[03:52:10 PM] INFO com.wurmonline.server.Server: MySQL JDBC Impl Version: null
[03:52:10 PM] INFO com.wurmonline.server.Server: Javax Mail Spec Title: JavaMail(TM) API Design Specification
[03:52:10 PM] INFO com.wurmonline.server.Server: Javax Mail Spec Vendor: Sun Microsystems, Inc.
[03:52:10 PM] INFO com.wurmonline.server.Server: Javax Mail Spec Version: 1.3
[03:52:10 PM] INFO com.wurmonline.server.Server: Javax Mail Impl Title: javax.mail
[03:52:10 PM] INFO com.wurmonline.server.Server: Javax Mail Impl Vendor: Sun Microsystems, Inc.
[03:52:10 PM] INFO com.wurmonline.server.Server: Javax Mail Impl Version: 1.4
[03:52:10 PM] INFO com.wurmonline.server.Server: Javax Activation Spec Title: Java Platform API Specification
[03:52:10 PM] INFO com.wurmonline.server.Server: Javax Activation Spec Vendor: Oracle Corporation
[03:52:10 PM] INFO com.wurmonline.server.Server: Javax Activation Spec Version: 1.8
[03:52:10 PM] INFO com.wurmonline.server.Server: Javax Activation Impl Title: Java Runtime Environment
[03:52:10 PM] INFO com.wurmonline.server.Server: Javax Activation Impl Vendor: Oracle Corporation
[03:52:10 PM] INFO com.wurmonline.server.Server: Javax Activation Impl Version: 1.8.0_172
[03:52:10 PM] INFO org.flywaydb.core.internal.dbsupport.sqlite.SQLiteDbSupport: SQLite does not support setting the schema. Default schema NOT changed to main
[03:52:10 PM] INFO org.flywaydb.core.internal.dbsupport.sqlite.SQLiteDbSupport: SQLite does not support setting the schema. Default schema NOT changed to main
[03:52:10 PM] INFO org.flywaydb.core.internal.dbsupport.sqlite.SQLiteDbSupport: SQLite does not support setting the schema. Default schema NOT changed to main
[03:52:10 PM] INFO org.flywaydb.core.internal.dbsupport.sqlite.SQLiteDbSupport: SQLite does not support setting the schema. Default schema NOT changed to main
[03:52:10 PM] INFO org.flywaydb.core.internal.dbsupport.sqlite.SQLiteDbSupport: SQLite does not support setting the schema. Default schema NOT changed to main
[03:52:10 PM] INFO org.flywaydb.core.internal.dbsupport.sqlite.SQLiteDbSupport: SQLite does not support setting the schema. Default schema NOT changed to main
[03:52:10 PM] INFO org.flywaydb.core.internal.dbsupport.sqlite.SQLiteDbSupport: SQLite does not support setting the schema. Default schema NOT changed to main
[03:52:10 PM] INFO org.flywaydb.core.internal.dbsupport.sqlite.SQLiteDbSupport: SQLite does not support setting the schema. Default schema NOT changed to main
[03:52:10 PM] INFO org.flywaydb.core.internal.dbsupport.sqlite.SQLiteDbSupport: SQLite does not support setting the schema. Default schema NOT changed to main
[03:52:10 PM] INFO com.wurmonline.server.utils.DbUtilities: Performing CHECK_MEDIUM on all Wurm database tables
[03:52:10 PM] INFO com.wurmonline.server.utils.DbUtilities: Finished performing CHECK_MEDIUM on all database tables, which took 0.072787 millis.
[03:52:10 PM] INFO com.wurmonline.server.Server: analyseAllDbTables is false so not analysing database tables to update indices.
[03:52:10 PM] INFO com.wurmonline.server.Server: OptimizeAllDbTables is false so not optimising database tables.
[03:52:10 PM] INFO com.wurmonline.server.Servers: Loading all servers.
[03:52:10 PM] INFO com.wurmonline.server.Servers: Loading Watercrest - 27334
[03:52:10 PM] INFO com.wurmonline.server.Servers: Using database entry for time 106894200
[03:52:10 PM] INFO com.wurmonline.server.zones.TilePoller: Current polltile=1842451, rest=0 pollmodifier=58171, pollround=161
[03:52:10 PM] INFO com.wurmonline.server.zones.TilePoller: tiles=4194304, mask=-1 ticksperday=3456000, Nthick=1, rest=0, manypertick=true
[03:52:10 PM] INFO com.wurmonline.server.Servers: Loading RiddleRidge - 5823
[03:52:10 PM] INFO com.wurmonline.server.Servers: Loaded 2 servers from the database
[03:52:10 PM] INFO com.wurmonline.server.Servers: found neighbour RiddleRidge WEST
[03:52:10 PM] INFO com.wurmonline.server.Servers: WEST neighbour RiddleRidge WEST
[03:52:10 PM] INFO com.wurmonline.server.Servers: Created properties table in the database
[03:52:10 PM] INFO com.wurmonline.mesh.MeshIO: Creative_custom\top_layer.map size is 16778240
[03:52:10 PM] INFO com.wurmonline.server.Server: Loading world mesh, size: 2048 took 97.25271 ms
[03:52:10 PM] INFO com.wurmonline.mesh.MeshIO: Creative_custom\map_cave.map size is 16778240
[03:52:10 PM] INFO com.wurmonline.server.Server: Loading cave mesh, size: 2048 took 27.653292 ms
[03:52:10 PM] INFO com.wurmonline.mesh.MeshIO: Creative_custom\resources.map size is 16778240
[03:52:10 PM] INFO com.wurmonline.server.Server: Loading resource mesh, size: 2048 took 107.001205 ms
[03:52:10 PM] INFO com.wurmonline.mesh.MeshIO: Creative_custom\rock_layer.map size is 16778240
[03:52:10 PM] INFO com.wurmonline.server.Server: Loading rock mesh, size: 2048 took 23.823248 ms
[03:52:10 PM] INFO com.wurmonline.mesh.MeshIO: Creative_custom\flags.map size is 16778240
[03:52:11 PM] INFO com.wurmonline.server.Server: Loading flags mesh, size: 2048 took 130.52225 ms
[03:52:11 PM] INFO com.wurmonline.server.Server: Max height: 4957
[03:52:11 PM] INFO com.wurmonline.server.Features: Loading all overridden features for production version: 129 and isTestServer: false.
[03:52:11 PM] INFO com.wurmonline.server.Features: Loaded 0 overridden features from the database
[03:52:11 PM] INFO com.wurmonline.server.Features: Feature [Name: Dummy entry - do not use, Id: 0, Version: 1, Default: false, Overridden: false, Enabled: false]
[03:52:11 PM] INFO com.wurmonline.server.Features: Feature [Name: Name change, Id: 31, Version: 999, Default: false, Overridden: false, Enabled: false]
[03:52:11 PM] INFO com.wurmonline.server.Features: Feature [Name: Surface Water, Id: 32, Version: 140, Default: false, Overridden: false, Enabled: false]
[03:52:11 PM] INFO com.wurmonline.server.Features: Feature [Name: Cave Water, Id: 33, Version: 999, Default: false, Overridden: false, Enabled: false]
[03:52:11 PM] INFO com.wurmonline.server.Features: Feature [Name: New skill system, Id: 38, Version: 125, Default: true, Overridden: false, Enabled: true]
[03:52:11 PM] INFO com.wurmonline.server.Features: Feature [Name: Blocked Traders, Id: 41, Version: 121, Default: true, Overridden: false, Enabled: true]
[03:52:11 PM] INFO com.wurmonline.server.Features: Feature [Name: Combat system changes for creatures, Id: 51, Version: 201, Default: false, Overridden: false, Enabled: false]
[03:52:11 PM] INFO com.wurmonline.server.Features: Feature [Name: Blocked HOTA terraforming and building, Id: 55, Version: 201, Default: false, Overridden: false, Enabled: false]
[03:52:11 PM] INFO com.wurmonline.server.Features: Feature [Name: Free armour and weapons on spawn, Id: 56, Version: 201, Default: false, Overridden: false, Enabled: false]
[03:52:11 PM] INFO com.wurmonline.server.Features: Feature [Name: Random treasure chests, Id: 57, Version: 201, Default: false, Overridden: false, Enabled: false]
[03:52:11 PM] INFO com.wurmonline.server.Features: Feature [Name: Ownership Papers, Id: 70, Version: 999, Default: false, Overridden: false, Enabled: false]
[03:52:11 PM] INFO com.wurmonline.server.Features: Feature [Name: Valrei map, Id: 72, Version: 125, Default: true, Overridden: false, Enabled: true]
[03:52:11 PM] INFO com.wurmonline.server.Features: Feature [Name: Crop tile poller split, Id: 75, Version: 125, Default: true, Overridden: false, Enabled: true]
[03:52:11 PM] INFO com.wurmonline.server.Features: Feature [Name: Single Player Bridges, Id: 76, Version: 125, Default: true, Overridden: false, Enabled: true]
[03:52:11 PM] INFO com.wurmonline.server.Features: Feature [Name: Amphora, Id: 77, Version: 126, Default: true, Overridden: false, Enabled: true]
[03:52:11 PM] INFO com.wurmonline.server.Features: Feature [Name: Set as a chaos server (test pvp only), Id: 78, Version: 999, Default: false, Overridden: false, Enabled: false]
[03:52:11 PM] INFO com.wurmonline.server.Features: Feature [Name: Set a destination on a boat, Id: 79, Version: 126, Default: true, Overridden: false, Enabled: true]
[03:52:11 PM] INFO com.wurmonline.server.Features: Feature [Name: New portals, Id: 80, Version: 999, Default: false, Overridden: false, Enabled: false]
[03:52:11 PM] INFO com.wurmonline.server.Features: Feature [Name: Transform from resource tiles, Id: 81, Version: 126, Default: true, Overridden: false, Enabled: true]
[03:52:11 PM] INFO com.wurmonline.server.Features: Feature [Name: Wagon Passenger, Id: 82, Version: 126, Default: true, Overridden: false, Enabled: true]
[03:52:11 PM] INFO com.wurmonline.server.Features: Feature [Name: Cave Dwellings, Id: 85, Version: 128, Default: true, Overridden: false, Enabled: true]
[03:52:11 PM] INFO com.wurmonline.server.Features: Feature [Name: Placing items on furniture, Id: 86, Version: 999, Default: false, Overridden: false, Enabled: false]
[03:52:11 PM] INFO com.wurmonline.server.Features: Feature [Name: Rifts, Id: 87, Version: 128, Default: false, Overridden: false, Enabled: false]
[03:52:11 PM] INFO com.wurmonline.server.Features: Feature [Name: Transform to resource tiles, Id: 88, Version: 126, Default: true, Overridden: false, Enabled: true]
[03:52:11 PM] INFO com.wurmonline.server.Features: Feature [Name: Cave Bridges, Id: 89, Version: 129, Default: true, Overridden: false, Enabled: true]
[03:52:11 PM] INFO com.wurmonline.server.Features: Feature [Name: Gift packs, Id: 90, Version: 128, Default: false, Overridden: false, Enabled: false]
[03:52:11 PM] INFO com.wurmonline.server.Features: Feature [Name: Returner pack registration, Id: 91, Version: 127, Default: false, Overridden: false, Enabled: false]
[03:52:11 PM] INFO com.wurmonline.server.Features: Feature [Name: Rift Loot Based on Participation, Id: 92, Version: 140, Default: false, Overridden: false, Enabled: false]
[03:52:11 PM] INFO com.wurmonline.server.Features: Feature [Name: Extra Anniversary Gift, Id: 93, Version: 128, Default: false, Overridden: false, Enabled: false]
[03:52:11 PM] INFO com.wurmonline.server.Features: Feature [Name: New Domain System - Override requires restart, Id: 94, Version: 128, Default: true, Overridden: false, Enabled: true]
[03:52:11 PM] INFO com.wurmonline.server.Features: Feature [Name: Allow Meditation Path Change (Insanity Only), Id: 95, Version: 130, Default: false, Overridden: false, Enabled: false]
[03:52:11 PM] INFO com.wurmonline.server.Features: Feature [Name: New Highway System - Override requires restart, Id: 96, Version: 129, Default: true, Overridden: false, Enabled: true]
[03:52:11 PM] INFO com.wurmonline.server.Features: Feature [Name: New Projectile Calculations, Id: 97, Version: 128, Default: true, Overridden: false, Enabled: true]
[03:52:11 PM] INFO com.wurmonline.server.Features: Feature [Name: New Kingdom Influence, Id: 98, Version: 140, Default: false, Overridden: false, Enabled: false]
[03:52:11 PM] INFO com.wurmonline.server.Features: Feature [Name: Wagoner System, Id: 99, Version: 129, Default: false, Overridden: false, Enabled: false]
[03:52:11 PM] INFO com.wurmonline.server.Features: Feature [Name: Creature Movement Changes, Id: 100, Version: 129, Default: true, Overridden: false, Enabled: true]
[03:52:11 PM] INFO com.wurmonline.server.Features: Feature [Name: Polling Optimisation - Tile Array Copying Changes, Id: 101, Version: 999, Default: false, Overridden: false, Enabled: false]
[03:52:11 PM] INFO com.wurmonline.server.Features: Feature [Name: Wagoner Drive On Left, Id: 102, Version: 129, Default: false, Overridden: false, Enabled: false]
[03:52:11 PM] INFO com.wurmonline.server.Features: Feature [Name: Allows for transportation of creatures, Id: 103, Version: 129, Default: true, Overridden: false, Enabled: true]
[03:52:11 PM] INFO com.wurmonline.server.Features: Feature [Name: Move from one bulk container to another as action, Id: 104, Version: 129, Default: true, Overridden: false, Enabled: true]
[03:52:11 PM] INFO com.wurmonline.server.Features: Feature [Name: Wagoner Drive on One Side, Id: 105, Version: 129, Default: false, Overridden: false, Enabled: false]
[03:52:11 PM] INFO com.wurmonline.server.Features: Feature [Name: Chance to gain affinities from skill usage, Id: 106, Version: 140, Default: false, Overridden: false, Enabled: false]
[03:52:11 PM] INFO com.wurmonline.server.Features: Feature [Name: All metals make all metal items, Id: 107, Version: 129, Default: true, Overridden: false, Enabled: true]
[03:52:11 PM] INFO com.wurmonline.server.MessageServer: Initialising MessageServer
[03:52:11 PM] INFO com.wurmonline.server.Server: Protocol: 250990040
[03:52:11 PM] INFO com.wurmonline.server.deities.Deities: Loading deities 
[03:52:11 PM] WARNING com.wurmonline.server.items.ItemTemplateFactory: Template eye already being used.
[03:52:11 PM] INFO com.wurmonline.server.items.ItemTemplateCreator: Initialising the Item Templates took 167 milliseconds
[03:52:11 PM] INFO org.gotti.wurmunlimited.mods.hitchingpost.HitchingPostMod: Adding hitchingpost
[03:52:11 PM] INFO org.gotti.wurmunlimited.modsupport.IdFactory: Using id 22767 for itemtemplate ago.hitchingpost
[03:52:11 PM] INFO org.gotti.wurmunlimited.mods.hitchingpost.HitchingPostMod: Using template id 22767
[03:52:11 PM] INFO org.gotti.wurmunlimited.modsupport.IdFactory: Using id 22766 for itemtemplate bdew.3d.hook
[03:52:11 PM] WARNING com.wurmonline.server.items.ItemTemplate: Modelname was null for template with id=22766
[03:52:11 PM] INFO com.wurmonline.server.spells.SpellGenerator: Starting to create spells
[03:52:11 PM] INFO com.wurmonline.server.spells.SpellGenerator: Generating spells took 29.737823 ms
[03:52:11 PM] INFO com.wurmonline.server.creatures.CreatureTemplateCreator: Starting to create Creature Templates
[03:52:11 PM] INFO com.wurmonline.server.skills.Skill: Calculating skill chances...
[03:52:11 PM] INFO com.wurmonline.server.skills.Skill: Loaded skill chances succeeded.
[03:52:11 PM] INFO com.wurmonline.server.skills.Skill: Done. Loading/Calculating skill chances from the database took 42.736275 millis.
[03:52:11 PM] INFO com.wurmonline.server.creatures.CreatureTemplateCreator: Creating Creature Templates took 80 ms
[03:52:11 PM] INFO org.gotti.wurmunlimited.modsupport.IdFactory: Using id 2147483647 for creaturetemplate mod.creature.panda
[03:52:11 PM] INFO org.gotti.wurmunlimited.modsupport.IdFactory: Using id 2147483646 for creaturetemplate mod.creature.zebra
[03:52:11 PM] INFO org.gotti.wurmunlimited.modsupport.IdFactory: Using id 2147483645 for creaturetemplate mod.creature.ocelot
[03:52:11 PM] INFO com.wurmonline.server.zones.CropTilePoller: CROPS_POLLER: Collecting tile data.
[03:52:11 PM] INFO com.wurmonline.server.zones.CropTilePoller: 

[03:52:11 PM] INFO com.wurmonline.server.zones.CropTilePoller: CROPS_POLLER: Collecting tile Finished.
[03:52:11 PM] INFO com.wurmonline.server.effects.EffectFactory: Loaded 4 effects from database took 3.75255 ms
[03:52:11 PM] INFO com.wurmonline.server.creatures.AnimalSettings: Loading all animal settings.
[03:52:11 PM] INFO com.wurmonline.server.creatures.AnimalSettings: Loaded 96 animal settings. That took 6.056275 ms.
[03:52:11 PM] INFO com.wurmonline.server.items.ItemSettings: Loading all item settings.
[03:52:11 PM] INFO com.wurmonline.server.items.ItemSettings: Loaded 67 item settings. That took 1.956396 ms.
[03:52:11 PM] INFO com.wurmonline.server.structures.DoorSettings: Loading all door (and gate) settings.
[03:52:11 PM] INFO com.wurmonline.server.structures.DoorSettings: Loaded 0 door (and gate) settings. That took 2.40834 ms.
[03:52:11 PM] INFO com.wurmonline.server.structures.StructureSettings: Loading all structure settings.
[03:52:11 PM] INFO com.wurmonline.server.structures.StructureSettings: Loaded 38 structure settings (guests). That took 0.288381 ms.
[03:52:11 PM] INFO com.wurmonline.server.creatures.MineDoorSettings: Loading all minedoor settings.
[03:52:11 PM] INFO com.wurmonline.server.creatures.MineDoorSettings: Loaded 11 minedoor settings. That took 0.277034 ms.
[03:52:11 PM] INFO com.wurmonline.server.players.PermissionsHistories: Purging permissions history over 6 months old.
[03:52:11 PM] INFO com.wurmonline.server.players.PermissionsHistories: Purged 0 permissions history. That took 2.018943 ms.
[03:52:11 PM] INFO com.wurmonline.server.players.PermissionsHistories: Loading all permissions history.
[03:52:12 PM] INFO com.wurmonline.server.players.PermissionsHistories: Loaded 91 permissions history. That took 55.5695 ms.
[03:52:12 PM] INFO com.wurmonline.server.Items: Loaded 731 item data entries, that took 8.454376 ms
[03:52:12 PM] INFO com.wurmonline.server.WurmId: Loading ids.
[03:52:12 PM] INFO com.wurmonline.server.WurmId: Added to ids, creatrureIdcounter is now 1393195
[03:52:12 PM] INFO com.wurmonline.server.WurmId: Finished loading Wurm IDs, that took 1.101217 millis.
[03:52:12 PM] INFO com.wurmonline.server.items.ItemSpellEffects: Loaded 11 Spell Effects For Items, that took 10.047389 ms
[03:52:12 PM] INFO com.wurmonline.server.Items: Loaded 72 item inscription data entries, that took 1.692093 ms
[03:52:12 PM] INFO com.wurmonline.server.Items: Loading all static preloaded items
[03:52:12 PM] INFO com.wurmonline.server.utils.logging.DatabaseLogger: Creating Database logger Item transfer logger for WurmLoggable type: com.wurmonline.server.utils.logging.ItemTransfer, MaxLoggablesToRemovePerCycle: 500
[03:52:12 PM] INFO com.wurmonline.server.utils.logging.ItemTransferDatabaseLogger: Creating Item Transfer logger, System useItemTransferLog option: false
[03:52:12 PM] INFO com.wurmonline.server.utils.DatabaseUpdater: Creating Database updater Item Database Damage Updater for WurmDbUpdatable type: com.wurmonline.server.utils.ItemDamageDatabaseUpdatable, MaxUpdatablesToRemovePerCycle: 500
[03:52:12 PM] INFO com.wurmonline.server.utils.ItemDamageDatabaseUpdater: Creating Item Damage Updater.
[03:52:12 PM] INFO com.wurmonline.server.utils.DatabaseUpdater: Creating Database updater Item Database Owner Updater for WurmDbUpdatable type: com.wurmonline.server.utils.ItemOwnerDatabaseUpdatable, MaxUpdatablesToRemovePerCycle: 500
[03:52:12 PM] INFO com.wurmonline.server.utils.ItemOwnerDatabaseUpdater: Creating Item Owner Updater.
[03:52:12 PM] INFO com.wurmonline.server.utils.DatabaseUpdater: Creating Database updater Item Database Last Owner Updater for WurmDbUpdatable type: com.wurmonline.server.utils.ItemLastOwnerDatabaseUpdatable, MaxUpdatablesToRemovePerCycle: 500
[03:52:12 PM] INFO com.wurmonline.server.utils.ItemOwnerDatabaseUpdater: Creating Item Last Owner Updater.
[03:52:12 PM] INFO com.wurmonline.server.utils.DatabaseUpdater: Creating Database updater Item Database Parent Updater for WurmDbUpdatable type: com.wurmonline.server.utils.ItemParentDatabaseUpdatable, MaxUpdatablesToRemovePerCycle: 500
[03:52:12 PM] INFO com.wurmonline.server.utils.ItemParentDatabaseUpdater: Creating Item Parent Updater.
[03:52:12 PM] INFO com.wurmonline.server.Players: Loaded 0 banned IPs
[03:52:12 PM] INFO com.wurmonline.server.Items: Loaded all static preloaded items, that took 179.10861 ms
[03:52:12 PM] INFO com.wurmonline.server.Items: Loaded 0 protected corpse entries, that took 0.093821 ms
[03:52:12 PM] INFO com.wurmonline.server.Items: Loading all zone items using com.wurmonline.server.items.BodyDbStrings@2d6c53fc
[03:52:12 PM] INFO com.wurmonline.server.Items: Loaded 38 zone items. That took 0.332109 ms.
[03:52:12 PM] INFO com.wurmonline.server.Items: Loading all zone items using com.wurmonline.server.items.ItemDbStrings@7fbdb894
[03:52:12 PM] INFO com.wurmonline.server.Items: Loaded 3321 zone items. That took 237.80435 ms.
[03:52:12 PM] INFO com.wurmonline.server.Items: Loading all zone items using com.wurmonline.server.items.CoinDbStrings@6e005dc9
[03:52:12 PM] INFO com.wurmonline.server.Items: Loaded 3399 zone items. That took 47.049812 ms.
[03:52:12 PM] INFO com.wurmonline.server.combat.WeaponCreator: Creating weapons
[03:52:12 PM] INFO com.wurmonline.server.combat.WeaponCreator: Creating weapons took 0.807577 ms
[03:52:12 PM] INFO com.wurmonline.server.banks.Banks: Loaded 4 banks from database took 4.320178 ms
[03:52:12 PM] INFO com.wurmonline.server.structures.Wall: Loading all walls.
[03:52:12 PM] INFO com.wurmonline.server.structures.Wall: Loaded 17 wall. That took 17.395012 ms.
[03:52:12 PM] INFO com.wurmonline.server.structures.Wall: Loading all floors.
[03:52:12 PM] INFO com.wurmonline.server.structures.Wall: Loaded 16 floors. That took 14.318304 ms.
[03:52:12 PM] INFO com.wurmonline.server.structures.Wall: Loading all bridge parts.
[03:52:12 PM] INFO com.wurmonline.server.structures.Wall: Loaded 54 bridge parts. That took 3.477729 ms.
[03:52:12 PM] INFO com.wurmonline.server.kingdom.Kingdom: Loading all kingdoms.
[03:52:12 PM] INFO com.wurmonline.server.kingdom.Kingdom: Loaded kingdoms from database took 2.254186 ms
[03:52:12 PM] INFO com.wurmonline.server.kingdom.King: Loading all kingdom eras.
[03:52:12 PM] INFO com.wurmonline.server.kingdom.King: Loaded kingdom eras from database took 0.223343 ms
[03:52:12 PM] INFO com.wurmonline.server.kingdom.Appointments: Loading era -1 for kingdom 1 current=true
[03:52:12 PM] INFO com.wurmonline.server.kingdom.Appointments: Loading era -3 for kingdom 3 current=true
[03:52:12 PM] INFO com.wurmonline.server.kingdom.Appointments: Loading era -2 for kingdom 2 current=true
[03:52:12 PM] INFO com.wurmonline.server.kingdom.Appointments: Loading era -5 for kingdom 0 current=true
[03:52:12 PM] INFO com.wurmonline.server.spells.Cooldowns: Loading all cooldowns.
[03:52:12 PM] INFO com.wurmonline.server.spells.Cooldowns: Loaded cooldowns from database took 0.202032 ms
[03:52:12 PM] INFO com.wurmonline.server.zones.Zones: Creating zones: size is 2048, 2048
[03:52:12 PM] INFO com.wurmonline.server.zones.Zones: Initialised surface zones - array size: [32][32];
[03:52:12 PM] INFO com.wurmonline.server.zones.Zones: Initialised cave zones - array size: [32][32];
[03:52:12 PM] INFO com.wurmonline.server.zones.Zones: Seconds between polls=800, zonespolled=2, maxnumberofzonespolled=1024
[03:52:12 PM] INFO com.wurmonline.server.zones.Zones: Loading surface and cave zone structures
[03:52:12 PM] INFO com.wurmonline.server.structures.Structures: Loading all Structures
[03:52:12 PM] INFO com.wurmonline.server.structures.Structures: Structures loaded. Number of structures=21. That took 3.667585 ms.
[03:52:13 PM] INFO com.wurmonline.server.zones.Zones: Loaded fences
[03:52:13 PM] INFO com.wurmonline.server.zones.Zones: Loaded build tiles
[03:52:13 PM] INFO com.wurmonline.server.zones.Zones: Ended loading of structures
[03:52:13 PM] INFO com.wurmonline.server.zones.Zones: Loaded zone items
[03:52:13 PM] INFO com.wurmonline.server.zones.Zones: Loaded 1024 surface and cave zones
[03:52:13 PM] INFO com.wurmonline.server.zones.Zones: Zones created and loaded. Number of zones=1024. PollFraction is 24. That took 962.52545 millis.
[03:52:13 PM] INFO com.wurmonline.server.zones.Zones: Loaded 168 mining tiles, that took 2.973202 ms
[03:52:13 PM] INFO com.wurmonline.server.zones.SpawnTable: Creating Encounters
[03:52:13 PM] INFO com.wurmonline.server.zones.SpawnTable: Created Encounters. It took 0.598902 ms.
[03:52:13 PM] INFO com.wurmonline.server.zones.Zones: Initialising walked tiles
[03:52:13 PM] INFO com.wurmonline.server.zones.Zones: Initialised walked tiles. It took 13.088672 ms.
[03:52:13 PM] INFO com.wurmonline.server.zones.Zones: Loading protected tiles from file: Creative_custom\\protectedTiles.bmap
[03:52:13 PM] INFO com.wurmonline.server.zones.Zones: Loaded 0 protected tiles. It took 98.54905 ms.
[03:52:13 PM] INFO com.wurmonline.server.villages.Villages: Loading villages.
[03:52:14 PM] INFO com.wurmonline.server.villages.Village: Calculating outside spawn for Watercrest
[03:52:14 PM] INFO com.wurmonline.server.villages.Village: Calculating outside spawn for Crestview Isle
[03:52:14 PM] INFO com.wurmonline.server.villages.Village: Calculating outside spawn for Sea Pass Village
[03:52:14 PM] INFO com.wurmonline.server.villages.Villages: Loaded 3 villages from the database took 72.16137 ms
[03:52:14 PM] INFO com.wurmonline.server.highways.Routes: Calculating All routes.
[03:52:14 PM] INFO com.wurmonline.server.highways.Routes: Calculated 0 routes and 0 nodes.That took 0.075277 ms.
[03:52:14 PM] INFO com.wurmonline.server.utils.DatabaseUpdater: Creating Database updater Creature Database Position Updater for WurmDbUpdatable type: com.wurmonline.server.utils.CreaturePositionDbUpdatable, MaxUpdatablesToRemovePerCycle: 500
[03:52:14 PM] INFO com.wurmonline.server.utils.CreaturePositionDatabaseUpdater: Creating Creature Position Updater.
[03:52:14 PM] INFO com.wurmonline.server.utils.DatabaseUpdater: Creating Database updater Player Database Position Updater for WurmDbUpdatable type: com.wurmonline.server.utils.PlayerPositionDbUpdatable, MaxUpdatablesToRemovePerCycle: 500
[03:52:14 PM] INFO com.wurmonline.server.utils.PlayerPositionDatabaseUpdater: Creating Player Position Updater.
[03:52:14 PM] INFO com.wurmonline.server.creatures.Brand: Loading Brands
[03:52:14 PM] INFO com.wurmonline.server.creatures.Creatures: Loading all skills for creatures
[03:52:14 PM] INFO com.wurmonline.server.creatures.Creatures: Loaded creature skills. That took 0.657852
[03:52:14 PM] INFO com.wurmonline.server.creatures.Creatures: Loading Creatures
[03:52:14 PM] INFO com.wurmonline.server.creatures.Creatures: Loading all items for creatures
[03:52:14 PM] INFO com.wurmonline.server.creatures.Creatures: Loaded creature items. That took 12.119193 ms for 314 items and 3 coins.
[03:52:17 PM] INFO com.wurmonline.server.creatures.Creatures: Loaded 7849 creatures. Destroyed 0. That took 3166.7344 ms. CheckPoints cp1=658.4978, cp2=0.0, cp3=0.0, cp4=0.0
[03:52:17 PM] INFO com.wurmonline.server.creatures.Creatures: Loaded items for creature. CheckPoints cp1=4.063642, cp2=0.0, cp3=64.57521, cp4=28.199053
[03:52:17 PM] INFO com.wurmonline.server.villages.Villages: Loading dead villages.
[03:52:17 PM] INFO com.wurmonline.server.villages.Villages: Loaded 1 dead villages from the database took 1.037562 ms
[03:52:17 PM] INFO com.wurmonline.server.villages.Villages: Loading villages citizens.
[03:52:17 PM] INFO com.wurmonline.server.villages.Villages: Loading villages guards.
[03:52:17 PM] INFO com.wurmonline.server.Server: Fixing cave entrances.
[03:52:17 PM] INFO com.wurmonline.server.Server: Set 0 cave entrances to rock out of 5
[03:52:17 PM] INFO com.wurmonline.server.Server: Fixing cave entrances took 340.93262 ms
[03:52:17 PM] INFO com.wurmonline.server.Items: Loading item effects.
[03:52:17 PM] INFO com.wurmonline.server.Items: Loaded 126 item effects. That took 28.628305 ms.
[03:52:17 PM] INFO com.wurmonline.server.zones.Zones: Loading guard towers.
[03:52:17 PM] INFO com.wurmonline.server.zones.Zones: Loaded 0 Guard towers. That took 0.079706 ms.
[03:52:17 PM] INFO com.wurmonline.server.villages.PvPAlliance: Loading all PVP Alliances.
[03:52:17 PM] INFO com.wurmonline.server.villages.PvPAlliance: Loaded PVP Alliances from database took 0.265687 ms
[03:52:17 PM] INFO com.wurmonline.server.villages.Villages: Loading all wars.
[03:52:17 PM] INFO com.wurmonline.server.villages.Villages: Loaded 0 wars from the database took 0.090222 ms
[03:52:17 PM] INFO com.wurmonline.server.villages.RecruitmentAds: Loaded 0 ads from the database took 0.101016 ms
[03:52:17 PM] INFO com.wurmonline.server.economy.DbEconomy: Iron=38
[03:52:17 PM] INFO com.wurmonline.server.economy.DbEconomy: Copper=46
[03:52:17 PM] INFO com.wurmonline.server.economy.DbEconomy: Silver=53
[03:52:17 PM] INFO com.wurmonline.server.economy.DbEconomy: Gold=4
[03:52:17 PM] INFO com.wurmonline.server.economy.Economy: Loading economy took 13.115241 ms.
[03:52:17 PM] INFO com.wurmonline.server.Server: Loading economy took 15.271733 ms.
[03:52:17 PM] INFO com.wurmonline.server.endgames.EndGameItems: Loading End Game Items.
[03:52:17 PM] INFO com.wurmonline.server.endgames.EndGameItems: Loaded 2 altars and 12 artifacts. That took 1.943388 ms.
[03:52:17 PM] INFO com.wurmonline.server.players.PlayerInfoFactory: Loading player infos. Going to prune DB.
[03:52:17 PM] INFO com.wurmonline.server.players.PlayerInfoFactory: Loaded 13 PlayerInfos from the database took 34 ms
[03:52:17 PM] INFO com.wurmonline.server.players.WurmRecord: Loaded 0 champ records from the database took 0 ms
[03:52:17 PM] INFO com.wurmonline.server.skills.Affinities: Loaded 15 affinities from the database took 0.353142 ms
[03:52:17 PM] INFO com.wurmonline.server.players.PlayerInfoFactory: Not Loading referrers from the database as this is not the login server
[03:52:17 PM] INFO com.wurmonline.server.zones.Dens: Loading dens
[03:52:17 PM] INFO com.wurmonline.server.zones.Dens: Loaded 12 dens from the database took 8.613234 ms
[03:52:17 PM] INFO com.wurmonline.server.players.Reimbursement: Did not load reimbursements from the database as this is not the login server, which has id: 5823
[03:52:17 PM] INFO com.wurmonline.server.players.PendingAccount: Loaded 0 pending accounts from the database took 0.187364 ms
[03:52:17 PM] INFO com.wurmonline.server.intra.PasswordTransfer: Loaded 0 PasswordTransfers from the database took 0.112363 ms
[03:52:17 PM] INFO com.wurmonline.server.players.AchievementGenerator: Loading achievement templates.
[03:52:17 PM] INFO com.wurmonline.server.players.Achievements: Loaded 730 achievements from the database took 46.346016 ms
[03:52:17 PM] INFO com.wurmonline.server.players.Achievements: Generated 19 personal goals, took 2.326143 ms
[03:52:17 PM] INFO com.wurmonline.server.zones.FocusZone: Loaded 6 focus zones. It took 2.488323 millis.
[03:52:17 PM] INFO com.wurmonline.server.epic.Hota: Loaded 0 HOTA items. It took 0.164947 millis.
[03:52:17 PM] INFO com.wurmonline.server.epic.Hota: Loaded 0 HOTA helpers. It took 0.056182 millis.
[03:52:17 PM] INFO com.wurmonline.communication.SocketServer: Creating Wurm SocketServer on /192.99.147.196:28043
[03:52:17 PM] INFO com.wurmonline.server.intra.IntraServer: Intraserver listening on /192.99.147.196:28043
[03:52:17 PM] INFO com.wurmonline.server.WurmHarvestables: Current wurm time: 106894200 - It is 04:50:00 on day of Sleep in week 1 of the Raven's starfall in the year of 983.
start apple season: 107845052 - 04:57:32 on day of the Wurm in week 3 of the Raven's starfall in the year of 983.
start blueberry season: (harvestable) 104954004 - 17:53:24 on Wrath day in week 2 of the starfall of Fires in the year of 983.
start camellia season: 125289954 - 02:45:54 on Luck day in week 4 of the starfall of the Leaf in the year of 984.
start cherry season: 130764655 - 11:30:55 on Luck day in week 1 of the White Shark starfall in the year of 984.
start chestnut season: 108790348 - 03:32:28 on day of Awakening in week 4 of the Raven's starfall in the year of 983.
start grape season: (harvestable) 106709738 - 01:35:38 on Wrath day in week 1 of the Raven's starfall in the year of 983.
start hazel season: 110333197 - 00:06:37 on Wrath day in week 3 of the starfall of Dancers in the year of 983.
start hops season: (harvestable) 105208680 - 16:38:00 on day of Awakening in week 2 of the starfall of Fires in the year of 983.
start lavender season: 126738705 - 21:11:45 on Wrath day in week 2 of the Bear's starfall in the year of 984.
start lemon season: 107163041 - 07:30:41 on Luck day in week 2 of the Raven's starfall in the year of 983.
start lingonberry season: 110943649 - 01:40:49 on Wrath day in week 4 of the starfall of Dancers in the year of 983.
start maple season: 127990400 - 08:53:20 on day of Tears in week 4 of the Bear's starfall in the year of 984.
start oak season: 129257576 - 00:52:56 on day of Sleep in week 2 of the Snake's starfall in the year of 984.
start oleander season: 124383108 - 14:51:48 on day of Tears in week 2 of the starfall of the Leaf in the year of 984.
start olive season: 133137919 - 22:45:19 on day of the Ant in week 1 of the starfall of Fires in the year of 984.
start orange season: (harvestable) 106224009 - 10:40:09 on day of Tears in week 4 of the starfall of Fires in the year of 983.
start pine season: 116289302 - 22:35:02 on Luck day in week 1 of the starfall of Diamonds in the year of 984.
start raspberry season: 109052559 - 04:22:39 on day of the Wurm in week 1 of the starfall of Dancers in the year of 983.
start rose season: 127427740 - 20:35:40 on day of Tears in week 3 of the Bear's starfall in the year of 984.
start walnut season: 109913165 - 03:26:05 on day of Sleep in week 2 of the starfall of Dancers in the year of 983.
[03:52:17 PM] INFO com.wurmonline.server.WurmHarvestables: Set harvest start dates. It took 3.073664 millis.
[03:52:17 PM] INFO com.wurmonline.server.items.WurmMail: Loaded 0 Mails from the database took 0.154708 ms
[03:52:17 PM] INFO com.wurmonline.server.HistoryManager: Loaded 4 HISTORY events from the database took 0.379988 ms
[03:52:17 PM] INFO com.wurmonline.server.players.Cultist: Loaded all cultists. It took 0.185151 millis.
[03:52:17 PM] INFO com.wurmonline.server.epic.EpicServerStatus: LOADING LOCAL EPIC MISSIONS
[03:52:17 PM] INFO com.wurmonline.server.epic.EpicScenario: Loaded current scenario Marble Strands lost
[03:52:17 PM] INFO com.wurmonline.server.support.Tickets: Loaded 0 Tickets. It took 0.387737 millis.
[03:52:17 PM] INFO com.wurmonline.server.support.VoteQuestions: Loaded 0 Vote Questions. It took 0.23552 millis.
[03:52:17 PM] INFO com.wurmonline.server.players.PlayerVotes: Loaded 0 Player Votes. It took 0.089947 millis.
[03:52:17 PM] INFO com.wurmonline.server.items.Recipes: Loading all Recipes
[03:52:18 PM] INFO com.wurmonline.server.items.Recipes: Total number of recipes=580.
[03:52:18 PM] INFO com.wurmonline.server.items.Recipes: Number of player known recipes=220.
[03:52:18 PM] INFO com.wurmonline.server.items.Recipes: Number of named recipes=0.
[03:52:18 PM] INFO com.wurmonline.server.items.Recipes: Recipes loaded. That took 199.67969 ms.
[03:52:18 PM] INFO com.wurmonline.server.items.Recipes: Loading all Recipes
[03:52:18 PM] INFO com.wurmonline.server.items.Recipes: Total number of recipes=580.
[03:52:18 PM] INFO com.wurmonline.server.items.Recipes: Number of player known recipes=220.
[03:52:18 PM] INFO com.wurmonline.server.items.Recipes: Number of named recipes=0.
[03:52:18 PM] INFO com.wurmonline.server.items.Recipes: Recipes loaded. That took 8.760192 ms.
[03:52:18 PM] INFO com.wurmonline.server.skills.AffinitiesTimed: Loading all Player Timed Affinities
[03:52:18 PM] INFO com.wurmonline.server.skills.AffinitiesTimed: Number of player timed affinities=0.
[03:52:18 PM] INFO com.wurmonline.server.skills.AffinitiesTimed: Player timed affinities loaded. That took 0.230538 ms.
[03:52:18 PM] INFO com.wurmonline.server.villages.VillageMessages: Loaded 0 village messages from the database took 0.084688 ms
[03:52:18 PM] INFO com.wurmonline.server.Server: Going to use a ScheduledExecutorService to write logs
[03:52:18 PM] INFO com.wurmonline.server.Server: Going to use a ScheduledExecutorService to count eggs
[03:52:18 PM] INFO com.wurmonline.server.Server: Going to use a ScheduledExecutorService to call MeshIO.saveNextDirtyRow()
[03:52:18 PM] INFO com.wurmonline.server.MeshSaver: Created MeshSaver for map layer: 'SurfaceMesh', MeshIO [Size: 2048, linesPerRow: 16, rowId: 0, size_level: 11]@295633618, rowsPerCall: 10
[03:52:18 PM] INFO com.wurmonline.server.MeshSaver: Created MeshSaver for map layer: 'CaveMesh', MeshIO [Size: 2048, linesPerRow: 16, rowId: 0, size_level: 11]@1678770626, rowsPerCall: 10
[03:52:18 PM] INFO com.wurmonline.server.MeshSaver: Created MeshSaver for map layer: 'RockMesh', MeshIO [Size: 2048, linesPerRow: 16, rowId: 0, size_level: 11]@804105878, rowsPerCall: 10
[03:52:18 PM] INFO com.wurmonline.server.MeshSaver: Created MeshSaver for map layer: 'ResourceMesh', MeshIO [Size: 2048, linesPerRow: 16, rowId: 0, size_level: 11]@767544292, rowsPerCall: 10
[03:52:18 PM] INFO com.wurmonline.server.MeshSaver: Created MeshSaver for map layer: 'FlagsMesh', MeshIO [Size: 2048, linesPerRow: 16, rowId: 0, size_level: 11]@1152035207, rowsPerCall: 10
[03:52:18 PM] INFO com.wurmonline.server.Server: Going to use a ScheduledExecutorService to send TimeSync commands
[03:52:18 PM] INFO com.wurmonline.server.Server: Going to use a ScheduledExecutorService to call WurmCalendar.tickSeconds()
[03:52:18 PM] INFO com.wurmonline.server.Server: Going to use a ScheduledExecutorService to update player positions in database
[03:52:18 PM] INFO com.wurmonline.server.Server: Going to use a ScheduledExecutorService to update item damage in database
[03:52:18 PM] INFO com.wurmonline.server.Server: Going to use a ScheduledExecutorService to connect to twitter
[03:52:18 PM] INFO com.wurmonline.server.Eigc: Loaded 0 eigc accounts.
[03:52:18 PM] INFO com.wurmonline.communication.SocketServer: Creating Wurm SocketServer on /192.99.147.196:3764
[03:52:18 PM] INFO com.wurmonline.server.Server: The Wurm Server is listening on ip 192.99.147.196 and port 3764. Min time between same ip connections=1000
[03:52:18 PM] INFO com.wurmonline.server.Server: commPollCounterInit=1
[03:52:18 PM] INFO com.wurmonline.server.steam.SteamHandler: Starting the server
[03:52:18 PM] INFO com.wurmonline.server.Server: End of game server initialisation
[03:52:18 PM] INFO com.wurmonline.server.items.CreationEntryCreator: Initialising the CreationEntries took 14.064519 millis.
[03:52:18 PM] WARNING com.wurmonline.server.skills.SkillStat: Polling 187 skills for stats v2 took 2 ms.
[03:52:18 PM] INFO com.wurmonline.server.players.AwardLadder: Finished generating AwardLadder
[03:52:18 PM] INFO com.wurmonline.server.webinterface.WebInterfaceImpl: Hostname of local machine used to send registration emails: ns510241
[03:52:18 PM] INFO com.wurmonline.server.gui.WurmServerGuiMain: WurmServerGuiMain finished
[03:52:18 PM] INFO com.wurmonline.server.console.CommandReader: Starting command reader for console input
[03:52:19 PM] INFO com.wurmonline.server.Items: Current number of eggs is 1 (max eggs is 1000) That took 38.117477 ms.
[03:52:19 PM] INFO com.wurmonline.server.Items: Current number of wild hives is 9 and domestic hives is 4.
[03:52:19 PM] INFO com.wurmonline.server.steam.SteamHandler: Server connected to steam
[03:52:19 PM] INFO com.wurmonline.server.intra.IntraClient: The server just synched wurm clock. New wurm time=106896210. Difference was -2001 wurm seconds.
[03:52:19 PM] INFO com.wurmonline.server.webinterface.WebInterfaceImpl: 198.100.153.87 RMI client. Received weather data from login server. Propagating windrot=332.85245
[03:52:19 PM] INFO com.wurmonline.server.webinterface.WebInterfaceImpl: serverId:5823 kingdom id 4 exists=true
[03:52:19 PM] INFO com.wurmonline.server.webinterface.WebInterfaceImpl: RiddleRidge kingdom id 4 exists=true
[03:52:19 PM] INFO org.gotti.wurmunlimited.modcomm.intra.playertransfer.GetRemoteTemplatesMessage: bdew.3d.hook=22766
[03:52:19 PM] INFO org.gotti.wurmunlimited.modcomm.intra.playertransfer.GetRemoteTemplatesMessage: ago.hitchingpost=22767
[03:52:19 PM] INFO org.gotti.wurmunlimited.modcomm.intra.playertransfer.GetRemoteTemplatesMessage: mod.creature.ocelot=2147483645
[03:52:19 PM] INFO org.gotti.wurmunlimited.modcomm.intra.playertransfer.GetRemoteTemplatesMessage: mod.creature.zebra=2147483646
[03:52:19 PM] INFO org.gotti.wurmunlimited.modcomm.intra.playertransfer.GetRemoteTemplatesMessage: mod.creature.panda=2147483647
[03:52:19 PM] WARNING com.wurmonline.server.LoginServerWebConnection: Failed to contact the login server  5823 Server unavailable
[03:52:19 PM] WARNING com.wurmonline.server.players.PlayerInfoFactory: Failed to contact the login server. Please try later.
com.wurmonline.shared.exceptions.WurmServerException: Failed to contact the login server. Please try later.
    at com.wurmonline.server.LoginServerWebConnection.getPlayerStates(LoginServerWebConnection.java:569)
    at com.wurmonline.server.players.PlayerInfoFactory.getPlayerStates(PlayerInfoFactory.java:1262)
    at com.wurmonline.server.players.PlayerInfoFactory.grabPlayerStates(PlayerInfoFactory.java:1841)
    at com.wurmonline.server.players.PlayerInfoFactory.whosOnline(PlayerInfoFactory.java:1822)
    at com.wurmonline.server.webinterface.WcPlayerStatus$1.run(WcPlayerStatus.java:233)

[03:52:24 PM] INFO com.wurmonline.server.ServerEntry: RiddleRidge is now available.
[03:52:24 PM] INFO com.wurmonline.server.intra.ModIntraServerMessage: connecting to 5823
[03:52:24 PM] INFO com.wurmonline.server.players.PlayerInfoFactory: Got 42 player status
[03:52:24 PM] INFO org.gotti.wurmunlimited.modcomm.intra.playertransfer.GetRemoteTemplatesMessage: 5823> bdew.3d.hook=22764
[03:52:24 PM] INFO org.gotti.wurmunlimited.modcomm.intra.playertransfer.GetRemoteTemplatesMessage: 5823> ago.hitchingpost=22765
[03:52:24 PM] INFO org.gotti.wurmunlimited.modcomm.intra.playertransfer.GetRemoteTemplatesMessage: 5823> mod.creature.ocelot=2147483645
[03:52:24 PM] INFO org.gotti.wurmunlimited.modcomm.intra.playertransfer.GetRemoteTemplatesMessage: 5823> mod.creature.zebra=2147483646
[03:52:24 PM] INFO org.gotti.wurmunlimited.modcomm.intra.playertransfer.GetRemoteTemplatesMessage: 5823> mod.creature.panda=2147483647
[03:53:08 PM] INFO com.wurmonline.communication.SocketServer: Accepted player connection: Socket[addr=/209.201.79.245,port=41708,localport=3764]
[03:53:08 PM] INFO com.wurmonline.server.steam.SteamHandler: Client was Authenticated
[03:53:09 PM] INFO com.wurmonline.server.LoginHandler: /209.201.79.245,Lebrian successfully logged on, id: 13439172263680.
[03:53:15 PM] INFO ModComm: Received client handshake from Lebrian, 1 channels, protocol version 1
[03:53:15 PM] INFO ModComm: Activating 1 channels for player Lebrian
[03:53:49 PM] INFO com.wurmonline.server.steam.SteamHandler: Client was  NOT Authenticated
[03:53:49 PM] INFO com.wurmonline.server.players.Player: Lebrian lost link 5 secstologout.
[03:53:54 PM] INFO com.wurmonline.server.players.Player: Logout complete for Player [id: 13439172263680, name: Lebrian]
[03:57:17 PM] INFO com.wurmonline.server.Server: current mem in use: 1022M free mem: 706M Max mem: 1022M
player count: 0
bytes in: 0 bytes out: 0 total in: 0 total out: 0
Server uptime: 300 seconds. Unanswered questions:0
[04:02:17 PM] INFO com.wurmonline.server.Server: current mem in use: 1022M free mem: 540M Max mem: 1022M
player count: 0
bytes in: 0 bytes out: 0 total in: 0 total out: 0
Server uptime: 600 seconds. Unanswered questions:0
[04:07:17 PM] INFO com.wurmonline.server.Server: current mem in use: 1022M free mem: 583M Max mem: 1022M
player count: 0
bytes in: 0 bytes out: 0 total in: 0 total out: 0
Server uptime: 900 seconds. Unanswered questions:0
[04:07:28 PM] WARNING com.wurmonline.server.items.Item: Unable to find top parent with ID: 7234023769602.
com.wurmonline.server.NoSuchItemException: No item found with id 7234023769602
    at com.wurmonline.server.Items.getItem(Items.java:248)
    at com.wurmonline.server.items.Item.getTopParentOrNull(Item.java:2692)
    at com.wurmonline.server.items.Item.getDecayMultiplier(Item.java:9903)
    at com.wurmonline.server.items.Item.poll(Item.java:9096)
    at com.wurmonline.server.zones.VolaTileItems.poll(VolaTileItems.java:407)
    at com.wurmonline.server.zones.VolaTile.poll(VolaTile.java:981)
    at com.wurmonline.server.zones.Zone.poll(Zone.java:516)
    at com.wurmonline.server.zones.Zones.pollNextZones(Zones.java:2019)
    at com.wurmonline.server.Server.run(Server.java:1902)
    at java.util.TimerThread.mainLoop(Timer.java:555)
    at java.util.TimerThread.run(Timer.java:505)

[04:07:28 PM] INFO com.wurmonline.server.Items: Destroying 7234023769602
com.wurmonline.server.NoSuchItemException: No item found with id 7234023769602
    at com.wurmonline.server.Items.getItem(Items.java:248)
    at com.wurmonline.server.Items.destroyItem(Items.java:555)
    at com.wurmonline.server.Items.destroyItem(Items.java:547)
    at com.wurmonline.server.Items.destroyItem(Items.java:542)
    at com.wurmonline.server.items.Item.checkDecay(Item.java:7426)
    at com.wurmonline.server.items.DbItem.setDamage(DbItem.java:1958)
    at com.wurmonline.server.items.DbItem.setDamage(DbItem.java:1925)
    at com.wurmonline.server.items.Item.poll(Item.java:9167)
    at com.wurmonline.server.zones.VolaTileItems.poll(VolaTileItems.java:407)
    at com.wurmonline.server.zones.VolaTile.poll(VolaTile.java:981)
    at com.wurmonline.server.zones.Zone.poll(Zone.java:516)
    at com.wurmonline.server.zones.Zones.pollNextZones(Zones.java:2019)
    at com.wurmonline.server.Server.run(Server.java:1902)
    at java.util.TimerThread.mainLoop(Timer.java:555)
    at java.util.TimerThread.run(Timer.java:505)

[04:09:19 PM] INFO com.wurmonline.server.webinterface.WebInterfaceImpl: 198.100.153.87 RMI client. Received weather data from login server. Propagating windrot=311.5153
[04:12:17 PM] INFO com.wurmonline.server.Server: current mem in use: 1022M free mem: 626M Max mem: 1022M
player count: 0
bytes in: 0 bytes out: 0 total in: 0 total out: 0
Server uptime: 1200 seconds. Unanswered questions:0
[04:17:17 PM] INFO com.wurmonline.server.Server: current mem in use: 1022M free mem: 670M Max mem: 1022M
player count: 0
bytes in: 0 bytes out: 0 total in: 0 total out: 0
Server uptime: 1500 seconds. Unanswered questions:0
[04:22:17 PM] INFO com.wurmonline.server.Server: current mem in use: 1022M free mem: 724M Max mem: 1022M
player count: 0
bytes in: 0 bytes out: 0 total in: 0 total out: 0
Server uptime: 1800 seconds. Unanswered questions:0
[04:27:17 PM] INFO com.wurmonline.server.Server: current mem in use: 1022M free mem: 569M Max mem: 1022M
player count: 0
bytes in: 0 bytes out: 0 total in: 0 total out: 0
Server uptime: 2100 seconds. Unanswered questions:0
[04:32:17 PM] INFO com.wurmonline.server.Server: current mem in use: 1022M free mem: 620M Max mem: 1022M
player count: 0
bytes in: 0 bytes out: 0 total in: 0 total out: 0
Server uptime: 2400 seconds. Unanswered questions:0
[04:33:51 PM] INFO com.wurmonline.server.webinterface.WebInterfaceImpl: 198.100.153.87 RMI client. Received weather data from login server. Propagating windrot=314.4048
[04:37:17 PM] INFO com.wurmonline.server.Server: current mem in use: 1022M free mem: 662M Max mem: 1022M
player count: 0
bytes in: 0 bytes out: 0 total in: 0 total out: 0
Server uptime: 2700 seconds. Unanswered questions:0
[04:42:17 PM] INFO com.wurmonline.server.Server: current mem in use: 1022M free mem: 711M Max mem: 1022M
player count: 0
bytes in: 0 bytes out: 0 total in: 0 total out: 0
Server uptime: 3000 seconds. Unanswered questions:0
[04:47:17 PM] INFO com.wurmonline.server.Server: current mem in use: 1022M free mem: 732M Max mem: 1022M
player count: 0
bytes in: 0 bytes out: 0 total in: 0 total out: 0
Server uptime: 3300 seconds. Unanswered questions:0
[04:52:17 PM] INFO com.wurmonline.server.Server: current mem in use: 1022M free mem: 543M Max mem: 1022M
player count: 0
bytes in: 0 bytes out: 0 total in: 0 total out: 0
Server uptime: 3600 seconds. Unanswered questions:0
[04:52:19 PM] INFO com.wurmonline.server.Items: Current number of eggs is 1 (max eggs is 1000) That took 16.050802 ms.
[04:52:19 PM] INFO com.wurmonline.server.Items: Current number of wild hives is 9 and domestic hives is 4.
[04:52:19 PM] INFO com.wurmonline.server.intra.IntraClient: The server just synched wurm clock. New wurm time=106924949. Difference was -6 wurm seconds.
[04:57:17 PM] INFO com.wurmonline.server.Server: current mem in use: 1022M free mem: 590M Max mem: 1022M
player count: 0
bytes in: 0 bytes out: 0 total in: 0 total out: 0
Server uptime: 3900 seconds. Unanswered questions:0
[04:57:18 PM] INFO com.wurmonline.server.DbConnector: Recreating playerDbcon
[04:57:18 PM] INFO com.wurmonline.server.creatures.CreaturePos: Creatures Position saved batch size 334
[04:58:24 PM] INFO com.wurmonline.server.webinterface.WebInterfaceImpl: 198.100.153.87 RMI client. Received weather data from login server. Propagating windrot=318.32535
[04:59:47 PM] INFO com.wurmonline.communication.SocketServer: Accepted player connection: Socket[addr=/184.59.95.172,port=61095,localport=3764]
[04:59:48 PM] INFO com.wurmonline.server.steam.SteamHandler: Client was Authenticated
[04:59:48 PM] INFO com.wurmonline.server.LoginHandler: /184.59.95.172,Deanna successfully logged on, id: 5134215462656.
[04:59:53 PM] INFO ModComm: Received client handshake from Deanna, 1 channels, protocol version 1
[04:59:53 PM] INFO ModComm: Activating 1 channels for player Deanna
[05:01:15 PM] INFO com.wurmonline.server.utils.logging.DatabaseLogger: Creating Database logger Tile logger for WurmLoggable type: com.wurmonline.server.utils.logging.TileEvent, MaxLoggablesToRemovePerCycle: 500
[05:01:15 PM] INFO com.wurmonline.server.utils.logging.TileEventDatabaseLogger: Creating Tile Event logger, System useTileLog option: false
[05:02:17 PM] INFO com.wurmonline.server.Server: current mem in use: 1022M free mem: 567M Max mem: 1022M
player count: 1
bytes in: 49856 bytes out: 1316024 total in: 49856 total out: 1316024
Server uptime: 4200 seconds. Unanswered questions:0
[05:07:17 PM] INFO com.wurmonline.server.Server: current mem in use: 1022M free mem: 592M Max mem: 1022M
player count: 1
bytes in: 130118 bytes out: 681150 total in: 179974 total out: 1997174
Server uptime: 4500 seconds. Unanswered questions:0
[05:12:17 PM] INFO com.wurmonline.server.Server: current mem in use: 1022M free mem: 574M Max mem: 1022M
player count: 1
bytes in: 29862 bytes out: 114097 total in: 209836 total out: 2111271
Server uptime: 4800 seconds. Unanswered questions:0
 

[Brian 16]

I went in with my GM toon and teleported to the location that the dead horse was at in the database.  It is there, but it had been transformed into a marble shard (template ID 785, and is such in the database I see now).  A few weeks ago, I had a wooden barrel full of lye change into a marble shard a little while back, for no good reason. Changing the template ID brought it back, with the lye still there.

 

Anyway, if I right-click the "marble corpse of venerable horse (grey)" I get the same "refresh" behavior with the pop-up menu, that never finishes. Presumably because the entry was deleted from the database. I'm sure the next time the server restarts, it will be gone.

 

So at least in this case, it appears that the template ID had changed in the database at some point, leading to the log exception and db deletion at the most recent startup.

Edited September 9, 2018 by Brian

[Sklo:D 2,210]

19 minutes ago, Brian said:

I went in with my GM toon and teleported to the location that the dead horse was at in the database.  It is there, but it had been transformed into a marble shard (template ID 785, and is such in the database I see now).  A few weeks ago, I had a wooden barrel full of lye change into a marble shard a little while back, for no good reason. Changing the template ID brought it back, with the lye still there.

 

Anyway, if I right-click the "marble corpse of venerable horse (grey)" I get the same "refresh" behavior with the pop-up menu, that never finishes. Presumably because the entry was deleted from the database. I'm sure the next time the server restarts, it will be gone.

 

So at least in this case, it appears that the template ID had changed in the database at some point, leading to the log exception and db deletion at the most recent startup.

 

Sounds like a very common problem. Do you have long time backups?

[Brian 16]

I usually back up once or twice each week. I do have some pretty old ones.

[Sklo:D 2,210]

Roll back your server to a state before the problem has been present.

 

The ids of the items have been messed up due to a mismatch of the current id stored and the highest item id around, there is no way to really undo what happened.

If the current id stored is way smaller than the highest item id stored, it will begin to overwrite items and they will become clay, shards, dirt or something else.

Edited September 9, 2018 by Sklo:D

[Brian 16]

On 9/9/2018 at 12:02 PM, Sklo:D said:

Roll back your server to a state before the problem has been present.

 

The ids of the items have been messed up due to a mismatch of the current id stored and the highest item id around, there is no way to really undo what happened.

If the current id stored is way smaller than the highest item id stored, it will begin to overwrite items and they will become clay, shards, dirt or something else.

Ugh, that's going to be very difficult to determine. I'm not sure if this was happening to some obscure item that we never noticed; plus, quite a bit of terraforming etc. has been done since it began happening frequently.

 

Is there no way to determine and set the current ID? It looks like my highest Wurm ID is 43424201228034. (Seems like a pretty big number.)

 

If I sort by creation date, I see 508384689922 and 507881373442, followed by that highest ID. Then there are a few thousand before I get back down to those lower numbers.

 

Someone suggested I run the sql command "delete from IDS;" against the wurmlogin.db to trigger manual ID loading, though it didn't work as he had hoped in his case. Is that, or some variation, likely to help?

 

By the way, my ITEMIDS for that server is 557504.

Edited September 15, 2018 by Brian

[Brian 16]

A little more info: I logged my GM toon on to destroy some bugged items (some rock shards in a pile that were showing wrong icons) and saw a bunch of exceptions in the server while I did that, mostly looking like these:

 

[04:04:54 AM] WARNING com.wurmonline.server.zones.Zone: Old virtualzone being removed:Lebrian
java.lang.Exception
    at com.wurmonline.server.zones.Zone.addWatcher(Zone.java:2168)
    at com.wurmonline.server.zones.VirtualZone.initialize(VirtualZone.java:244)
    at com.wurmonline.server.creatures.VisionArea.sendNextStrip(VisionArea.java:420)
    at com.wurmonline.server.Server.run(Server.java:2458)
    at java.util.TimerThread.mainLoop(Timer.java:555)
    at java.util.TimerThread.run(Timer.java:505)
 
[04:05:11 AM] INFO com.wurmonline.server.Server: VisionArea null for Lebrian, creating one.
[04:06:15 AM] INFO com.wurmonline.server.Items: Destroying 8917533509122
com.wurmonline.server.NoSuchItemException: No item found with id 8917533509122
    at com.wurmonline.server.Items.getItem(Items.java:248)
    at com.wurmonline.server.Items.destroyItem(Items.java:555)
    at com.wurmonline.server.Items.destroyItem(Items.java:547)
    at com.wurmonline.server.Items.destroyItem(Items.java:542)
    at com.wurmonline.server.behaviours.ItemBehaviour.action(ItemBehaviour.java:7275)
    at com.wurmonline.server.behaviours.Action.poll(Action.java:3593)
    at com.wurmonline.server.behaviours.ActionStack.poll(ActionStack.java:243)
    at com.wurmonline.server.players.Player.pollActions(Player.java:9534)
    at com.wurmonline.server.Players.pollPlayers$1(Players.java:4543)
    at sun.reflect.GeneratedMethodAccessor3.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:498)
    at org.gotti.wurmunlimited.modloader.server.ProxyServerHook$6$1.invoke(ProxyServerHook.java:181)
    at org.gotti.wurmunlimited.modloader.classhooks.HookManager.invoke(HookManager.java:344)
    at com.wurmonline.server.Players.pollPlayers(Players.java)
    at com.wurmonline.server.Server.run(Server.java:1907)
    at java.util.TimerThread.mainLoop(Timer.java:555)
    at java.util.TimerThread.run(Timer.java:505)
 

The items were removed successfully, in spite of the errors. 

[Sklo:D 2,210]

5 hours ago, Brian said:

A little more info: I logged my GM toon on to destroy some bugged items (some rock shards in a pile that were showing wrong icons) and saw a bunch of exceptions in the server while I did that, mostly looking like these:

 

[04:04:54 AM] WARNING com.wurmonline.server.zones.Zone: Old virtualzone being removed:Lebrian
java.lang.Exception
    at com.wurmonline.server.zones.Zone.addWatcher(Zone.java:2168)
    at com.wurmonline.server.zones.VirtualZone.initialize(VirtualZone.java:244)
    at com.wurmonline.server.creatures.VisionArea.sendNextStrip(VisionArea.java:420)
    at com.wurmonline.server.Server.run(Server.java:2458)
    at java.util.TimerThread.mainLoop(Timer.java:555)
    at java.util.TimerThread.run(Timer.java:505)
 
[04:05:11 AM] INFO com.wurmonline.server.Server: VisionArea null for Lebrian, creating one.
[04:06:15 AM] INFO com.wurmonline.server.Items: Destroying 8917533509122
com.wurmonline.server.NoSuchItemException: No item found with id 8917533509122
    at com.wurmonline.server.Items.getItem(Items.java:248)
    at com.wurmonline.server.Items.destroyItem(Items.java:555)
    at com.wurmonline.server.Items.destroyItem(Items.java:547)
    at com.wurmonline.server.Items.destroyItem(Items.java:542)
    at com.wurmonline.server.behaviours.ItemBehaviour.action(ItemBehaviour.java:7275)
    at com.wurmonline.server.behaviours.Action.poll(Action.java:3593)
    at com.wurmonline.server.behaviours.ActionStack.poll(ActionStack.java:243)
    at com.wurmonline.server.players.Player.pollActions(Player.java:9534)
    at com.wurmonline.server.Players.pollPlayers$1(Players.java:4543)
    at sun.reflect.GeneratedMethodAccessor3.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:498)
    at org.gotti.wurmunlimited.modloader.server.ProxyServerHook$6$1.invoke(ProxyServerHook.java:181)
    at org.gotti.wurmunlimited.modloader.classhooks.HookManager.invoke(HookManager.java:344)
    at com.wurmonline.server.Players.pollPlayers(Players.java)
    at com.wurmonline.server.Server.run(Server.java:1907)
    at java.util.TimerThread.mainLoop(Timer.java:555)
    at java.util.TimerThread.run(Timer.java:505)
 

The items were removed successfully, in spite of the errors. 

 

Both errors have nothing to do with each other and both are nothing critical either.

 

The first error happens from time to time just the view zone is removed and the second error is a bug:

This bug has been reported here: 

 

 

 

 

 

[Brian 16]

On 9/9/2018 at 12:02 PM, Sklo:D said:

Roll back your server to a state before the problem has been present.

 

The ids of the items have been messed up due to a mismatch of the current id stored and the highest item id around, there is no way to really undo what happened.

If the current id stored is way smaller than the highest item id stored, it will begin to overwrite items and they will become clay, shards, dirt or something else.

 

So this current ID must be stored somewhere in the database, correct? Otherwise it could not survive server restarts.

 

What if I were to set it just above the largest item Wurm ID in the database? Would that fix the situation, and if so, where could I find it?

[Sklo:D 2,210]

49 minutes ago, Brian said:

 

So this current ID must be stored somewhere in the database, correct? Otherwise it could not survive server restarts.

 

What if I were to set it just above the largest item Wurm ID in the database? Would that fix the situation, and if so, where could I find it?

 

Of course the problem can be fixed, but the damage is already done. Even after making sure the ids are stored correctly again, it is not possible to restore the server to the state it was before. This way you have items which travelled through the map, iron items made from clay or such things.

 

You can find the ids in the wurmlogin.db in the table IDS.

Edited September 15, 2018 by Sklo:D

[Brian 16]

There's been a bunch of terraforming and a village constructed in a cave, so I'm going to try this. I've been deleting items that I find that are corrupted as I find them.

 

Is there an merit to wiping out the IDS table to allow the server to reconstruct the values?

 

BTW, I have two servers clustered together, but I wouldn't expect that to affect things. However, I first noticed the problem on the login server, then it happened about a week or two later on the other, FWIW.

[Sklo:D 2,210]

18 minutes ago, Brian said:

There's been a bunch of terraforming and a village constructed in a cave, so I'm going to try this. I've been deleting items that I find that are corrupted as I find them.

 

Is there an merit to wiping out the IDS table to allow the server to reconstruct the values?

 

BTW, I have two servers clustered together, but I wouldn't expect that to affect things. However, I first noticed the problem on the login server, then it happened about a week or two later on the other, FWIW.

 

Wiping the IDS table will just make things worse, the server will NOT create a new IDS table nor will it update the IDS to the values which they should have.

 

The ids are different for every server, so no that can not be related. On one server the id 378123786128 can exist but on another server this id will never be used because the server id is used as some kind of an offset, so two servers can NOT create items with the same id, which is smart obviously.

 

Usually this error appears with changing the wurmlogin.db to some old state or to a state of another server. Don't be lazy and copy the wurmlogin.db from login server to your live server, this will break the live server for sure, even if you adapt the server settings.

[Brian 16]

Okay, thanks. Yes, I've been careful to only modify each wurmlogin.db separately, and only while the servers are shutdown. I've had to do this to set the treegrowth value in the past, since they're hosted on the Citadel Servers platform whose configuration interface is a little shaky. 

 

So I'll try setting the item IDS value for each server to something slightly higher than the highest item ID in each database.

 

 

[Sklo:D 2,210]

12 minutes ago, Brian said:

Okay, thanks. Yes, I've been careful to only modify each wurmlogin.db separately, and only while the servers are shutdown. I've had to do this to set the treegrowth value in the past, since they're hosted on the Citadel Servers platform whose configuration interface is a little shaky. 

 

So I'll try setting the item IDS value for each server to something slightly higher than the highest item ID in each database.

 

 

 

Yep this works.

Could be Citadel servers causing this issue, since I have been hearing a lot reports about this error in the last time.

Edited September 15, 2018 by Sklo:D

[Brian 16]

They've been looking at it as well, but so far no luck. The servers seem to shutdown cleanly, etc.

 

But I'm wondering now, since the last update, we've been doing quite a bit of inter-server commerce, particularly with animals via the creature cages.  Sure there are some protections in place to prevent IDs from conflicting when an item or creature is moved to another server, correct?

[Sklo:D 2,210]

3 minutes ago, Brian said:

They've been looking at it as well, but so far no luck. The servers seem to shutdown cleanly, etc.

 

But I'm wondering now, since the last update, we've been doing quite a bit of inter-server commerce, particularly with animals via the creature cages.  Sure there are some protections in place to prevent IDs from conflicting when an item or creature is moved to another server, correct?

 

Well, if the servers have the same server id, then this would also happen I guess after some time. Not sure how citadel makes sure that all server ids connected are different.

Edited September 15, 2018 by Sklo:D

[Brian 16]

The server IDs are definitely different; they ensure that when the cluster is configured.

 

I'm still wondering about the item IDs though. If I brought a crate of lumber across with an ID of 555333222 or such, what happens if there's a rock shard with that ID on the destination server? 

[Sklo:D 2,210]

21 minutes ago, Brian said:

The server IDs are definitely different; they ensure that when the cluster is configured.

 

I'm still wondering about the item IDs though. If I brought a crate of lumber across with an ID of 555333222 or such, what happens if there's a rock shard with that ID on the destination server? 

 

There can't, because as I mentioned before the said id 555333222 can only exists on one of the servers, because the server id is used in the generation.

 

 

[Brian 16]

Ah okay, I'd missed that. Makes perfect sense, thanks.

 

But now that throws a monkey wrench into my plan for fixing the IDS value. Can you tell me the algorithm used to generate the WURM ID? Presumably, when I sort the database to find the highest ID, that ID includes the server ID as a multiplier or something, which would mean I can't simply put that highest ID + 1 into the Server IDs value.

 

Checking a couple values, it looks like WURMID = SERVERID * ITEMIDS++. Does this seem right?

Edited September 15, 2018 by Brian

[Sklo:D 2,210]

9 minutes ago, Brian said:

Ah okay, I'd missed that. Makes perfect sense, thanks.

 

But now that throws a monkey wrench into my plan for fixing the IDS value. Can you tell me the algorithm used to generate the WURM ID? Presumably, when I sort the database to find the highest ID, that ID includes the server ID as a multiplier or something, which would mean I can't simply put that highest ID + 1 into the Server IDs value.

 

The calculation goes as follows for items

 

Next id = ItemidCounterFromWurmLoginDB << 24 + SERVER_ID << 8 + 2

Edited September 15, 2018 by Sklo:D

[Brian 16]

Thanks!

[Sklo:D 2,210]

17 minutes ago, Brian said:

Thanks!

 

No problem, you are welcome. 

[Brian 16]

Another related question, if you don't mind:

 

I'm looking at my IDS table on the wurmlogin.db for my two servers. My login server has just one line, for that server ID. The other server has two lines, one for each of the servers; but the entry here for the login server is considerably different, the ITEMIDS value is roughly 3 times what it is on the actual login server's value.

 

Is the second line of the non-login server (the line containing the login server values) ignored, or should it have the same values as are configured on the login server's wurmlogin.db?

 

Login Server (ID 5823):

SERVER ... ITEMIDS

5823           558127

 

Non-Login Server (ID 27334):

SERVER ... ITEMIDS

27334         563729

5823           1539233

 

Understand that there was quite a bit of mucking about with these configurations when we first struggled to get clustering to work.

Edited September 16, 2018 by Brian