2.13.0 Not saving MySQL changes on restart/plugin reload on Paper 1.12.2

[roinujnosde]

2.13.0 Not saving MySQL changes on restart/plugin reload on Paper 1.12.2

[RoinujNosde]

Thanks again for testing!

I also tested setting the save-interval to 1 instead of 10 I'm assuming this is in minutes? This ones really weird, as this actually works if I change it this low!

Nice find!

whats super weird, is that ALL I changed was the crew balance yet its updating EVERYTHING in the crew, not just what I changed.

It's coded like that. Otherwise I would need a query for every field a clan/clanplayer has. (Which are a lot)

[RoinujNosde]

Try this in your test server, please:
SimpleClans.zip

I've added some debug messages.

[FireController1847]

Subscribing to this thread. I am also having this issue. Using Paper 1.16.3 Build 196 with SimpleClans 2.13.1. I am using MySQL 5.7.31 running on Ubuntu 18.04.5 LTS. Upon turning off save-periodically, the issue is solved.

My server restarts every night so I can leave this off for now, however it is not ideal.

Let me know if there is anything I can do to help.

[FireController1847]

Oh, yeah. Okay. I accidentally left the whitelist on for 12 hours last night so that would make sense.

[RoinujNosde]

Changes are held in memory, like crews creating ranks, adding permissions, adding or removing people, but when a restart happens none of it is saved.

No errors on console?

Its as if it was using loaded memory and saving that into the database?

If save-periodically is true, changes are saved every X minutes, also on /clan reload and /restart.

[TomLewis]

Everything was working perfectly fine for 5+ years on older versions until I updated to 2.13.0.

I have not changed anything else.

save-periodically: true

So its not saving periodically, /clan reload or /restart then! None of them are saving/reverting the MySQL changes.

[RoinujNosde]

Send me your latest log.

[TomLewis]

I cant post my latest.log public for many reasons. but SimpleClans is connecting to the database fine and its reading the database as people have their crews from where they have created and used them over the last 5+ years, but no changes are being saved.

[10:31:10] [Server thread/INFO]: [SimpleClans] Loading SimpleClans v2.13.0
[10:31:34] [Server thread/INFO]: [SimpleClans] Enabling SimpleClans v2.13.0
[10:31:34] [Server thread/INFO]: [SimpleClans] MySQL Connection successful
[10:31:34] [Server thread/INFO]: [SimpleClans] Purging clan: Vrajeshkumar Kambojia
[10:31:34] [Server thread/INFO]: [SimpleClans] Purging clan: oduncu degil oyuncu
[10:31:34] [Server thread/INFO]: [SimpleClans] Purging clan: The Grim Reapers
[10:31:34] [Server thread/INFO]: [SimpleClans] Purging clan: Craptains
[10:31:34] [Server thread/INFO]: [SimpleClans] Purging clan: Dreadnought Pirates
[10:31:34] [Server thread/INFO]: [SimpleClans] Purging clan: Boyos
[10:31:34] [Server thread/INFO]: [SimpleClans] Clans: 1,387
[10:31:35] [Server thread/INFO]: [SimpleClans] purging players data: {0}
[10:31:35] [Server thread/INFO]: [SimpleClans] purging players data: {0}
[10:31:35] [Server thread/INFO]: [SimpleClans] purging players data: {0}
[10:31:35] [Server thread/INFO]: [SimpleClans] purging players data: {0}
[10:31:35] [Server thread/INFO]: [SimpleClans] purging players data: {0}
[10:31:35] [Server thread/INFO]: [SimpleClans] purging players data: {0}
[10:31:35] [Server thread/INFO]: [SimpleClans] purging players data: {0}
[10:31:35] [Server thread/INFO]: [SimpleClans] purging players data: {0}
[10:31:35] [Server thread/INFO]: [SimpleClans] purging players data: {0}
[10:31:35] [Server thread/INFO]: [SimpleClans] purging players data: {0}
[10:31:35] [Server thread/INFO]: [SimpleClans] purging players data: {0}
[10:31:35] [Server thread/INFO]: [SimpleClans] purging players data: {0}
[10:31:36] [Server thread/INFO]: [SimpleClans] purging players data: {0}
[10:31:36] [Server thread/INFO]: [SimpleClans] purging players data: {0}
[10:31:36] [Server thread/INFO]: [SimpleClans] purging players data: {0}
[10:31:36] [Server thread/INFO]: [SimpleClans] purging players data: {0}
[10:31:36] [Server thread/INFO]: [SimpleClans] purging players data: {0}
[10:31:36] [Server thread/INFO]: [SimpleClans] purging players data: {0}
[10:31:36] [Server thread/INFO]: [SimpleClans] purging players data: {0}
[10:31:36] [Server thread/INFO]: [SimpleClans] purging players data: {0}
[10:31:36] [Server thread/INFO]: [SimpleClans] purging players data: {0}
[10:31:36] [Server thread/INFO]: [SimpleClans] purging players data: {0}
[10:31:36] [Server thread/INFO]: [SimpleClans] purging players data: {0}
[10:31:36] [Server thread/INFO]: [SimpleClans] purging players data: {0}
[10:31:36] [Server thread/INFO]: [SimpleClans] purging players data: {0}
[10:31:36] [Server thread/INFO]: [SimpleClans] purging players data: {0}
[10:31:36] [Server thread/INFO]: [SimpleClans] purging players data: {0}
[10:31:36] [Server thread/INFO]: [SimpleClans] purging players data: {0}
[10:31:36] [Server thread/INFO]: [SimpleClans] purging players data: {0}
[10:31:37] [Server thread/INFO]: [SimpleClans] purging players data: {0}
[10:31:37] [Server thread/INFO]: [SimpleClans] purging players data: {0}
[10:31:37] [Server thread/INFO]: [SimpleClans] purging players data: {0}
[10:31:37] [Server thread/INFO]: [SimpleClans] purging players data: {0}
[10:31:37] [Server thread/INFO]: [SimpleClans] purging players data: {0}
[10:31:37] [Server thread/INFO]: [SimpleClans] purging players data: {0}
[10:31:37] [Server thread/INFO]: [SimpleClans] purging players data: {0}
[10:31:37] [Server thread/INFO]: [SimpleClans] Clan players: 13,301
[10:31:37] [Server thread/INFO]: [SimpleClans] Multithreading: false
[10:31:37] [Server thread/INFO]: [SimpleClans] BungeeCord: false
[10:31:37] [Server thread/INFO]: [SimpleClans] Help us translate SimpleClans to your language! Access https://crowdin.com/project/simpleclans/
[10:31:37] [Server thread/INFO]: [SimpleClans] PlaceholderAPI found. Registering hook...

I scanned all my latest.log for [SimpleClans] and apart from those messages above the only messages were inside my crews/clans chat.

[TomLewis]

I know that you changed the database schema to include ranks & banner columns. So just incase there is an issue with the conversion/addition in the schema here is what my production was updated to;

CREATE TABLE `sc_clans` (
	`id` BIGINT(20) NOT NULL AUTO_INCREMENT,
	`verified` TINYINT(1) NULL DEFAULT '0',
	`tag` VARCHAR(25) NOT NULL COLLATE 'latin1_swedish_ci',
	`color_tag` VARCHAR(25) NOT NULL COLLATE 'latin1_swedish_ci',
	`name` VARCHAR(100) NOT NULL COLLATE 'latin1_swedish_ci',
	`friendly_fire` TINYINT(1) NULL DEFAULT '1',
	`founded` BIGINT(20) NOT NULL,
	`last_used` BIGINT(20) NOT NULL,
	`packed_allies` TEXT NOT NULL COLLATE 'latin1_swedish_ci',
	`packed_rivals` TEXT NOT NULL COLLATE 'latin1_swedish_ci',
	`packed_bb` MEDIUMTEXT NOT NULL COLLATE 'latin1_swedish_ci',
	`cape_url` VARCHAR(255) NOT NULL COLLATE 'latin1_swedish_ci',
	`flags` TEXT NOT NULL COLLATE 'latin1_swedish_ci',
	`balance` DOUBLE(64,2) NULL DEFAULT NULL,
	`fee_enabled` TINYINT(1) NULL DEFAULT '0',
	`fee_value` DOUBLE(64,2) NULL DEFAULT NULL,
	`description` VARCHAR(255) NULL DEFAULT NULL COLLATE 'latin1_swedish_ci',
	`ranks` TEXT NULL DEFAULT NULL COLLATE 'latin1_swedish_ci',
	`banner` TEXT NULL DEFAULT NULL COLLATE 'latin1_swedish_ci',
	PRIMARY KEY (`id`) USING BTREE,
	UNIQUE INDEX `uq_simpleclans_1` (`tag`) USING BTREE
)
COLLATE='latin1_swedish_ci'
ENGINE=InnoDB
AUTO_INCREMENT=6744
;

Not sure if you changed the users table, but anyway;

CREATE TABLE `sc_players` (
	`id` BIGINT(20) NOT NULL AUTO_INCREMENT,
	`name` VARCHAR(40) NOT NULL COLLATE 'latin1_swedish_ci',
	`leader` TINYINT(1) NULL DEFAULT '0',
	`tag` VARCHAR(25) NOT NULL COLLATE 'latin1_swedish_ci',
	`friendly_fire` TINYINT(1) NULL DEFAULT '1',
	`neutral_kills` INT(11) NULL DEFAULT NULL,
	`rival_kills` INT(11) NULL DEFAULT NULL,
	`civilian_kills` INT(11) NULL DEFAULT NULL,
	`deaths` INT(11) NULL DEFAULT NULL,
	`last_seen` BIGINT(20) NOT NULL,
	`join_date` BIGINT(20) NOT NULL,
	`trusted` TINYINT(1) NULL DEFAULT '0',
	`flags` TEXT NOT NULL COLLATE 'latin1_swedish_ci',
	`packed_past_clans` TEXT NULL DEFAULT NULL COLLATE 'latin1_swedish_ci',
	`uuid` VARCHAR(38) NULL DEFAULT NULL COLLATE 'latin1_swedish_ci',
	`resign_times` TEXT NULL DEFAULT NULL COLLATE 'latin1_swedish_ci',
	`locale` VARCHAR(10) NULL DEFAULT NULL COLLATE 'latin1_swedish_ci',
	PRIMARY KEY (`id`) USING BTREE,
	UNIQUE INDEX `uq_player_uuid` (`uuid`) USING BTREE,
	INDEX `sc_players_by_tag` (`tag`) USING BTREE
)
COLLATE='latin1_swedish_ci'
ENGINE=InnoDB
AUTO_INCREMENT=31514
;

[RoinujNosde]

I just tested with paper 1.15.2, saving fine on MySQL.
Just in case I will try with 1.12.

See if disabling save-periodically works.

[TomLewis]

I specifically use Paper https://papermc.io/api/v1/paper/1.12.2/1618/download

[RoinujNosde]

1.12.2 works as expected.

See if disabling save-periodically works.

Do this and let me know.

[TomLewis]

I set save-periodically: false did /crew reload then changed a value in the database, did /crew reload again and it saved this time! You might have found the issue!
What I will do, is inform my users to make changes tonight & report back to me tomorrow morning when we have a scheduled reboot, just in-case!

[RoinujNosde]

Maybe there is something interfering with the save task? Can you use only SC on your test server and see if it saves?

[TomLewis]

Morning update. its definitely save-periodically as I asked users to make changes last night to users/ranks/perms and they were there after this mornings restart.

I updated the SimpleClans on my test server which has very few plugins but kept save-periodically: true and the same bug happens here too, is there any debug I can turn on?

[RoinujNosde]

is there any debug I can turn on?

You could turn MySQL debug on (https://serverfault.com/questions/71071/how-to-enable-mysql-logging).

What save-periodically does is store the changes in memory and at specific times (the ones I mentioned) it saves them using a batch update.
The batch is the only difference here.
At first I thought maybe some optimization system of yours could be cancelling the save task, but on reload/restart it's directly on the main thread.

Maybe you have some different batch settings? Or your MySQL version doesn't support it? What's its version, btw?

[TomLewis]

I'm using mariadb Ver 15.1 Distrib 10.4.14-MariaDB which is the most stable for Debian 10 as I use their direct repo.
Using OpenJDK 64-Bit Server VM AdoptOpenJDK (build 11.0.8+10, mixed mode). If anything it would be the OpenJDK AdoptOpenJDK. Are you using MySQL classes built into JDK or a library?

I don't have any unique configurations for MySQL, MariaDB is very common.

There must be something with save-periodically memory that is messing it up, as it now works on plugin reload and server reload with it turned off.

what is batch settings?

[RoinujNosde]

Were you able to turn logging on? https://mariadb.com/kb/en/general-query-log/

[TomLewis]

Were you able to turn logging on? https://mariadb.com/kb/en/general-query-log/
I have now, enabled.

Im not sure what im suppose to look at now I have enabled this, I assume somewhere a log is created and I should try save-periodically on my test server?

Edit: apparently its written to SHOW VARIABLES LIKE 'datadir'; value.

[RoinujNosde]

Im not sure what im suppose to look at now I have enabled this, I assume somewhere a log is created and I should try save-periodically on my test server?

Yeah. Then we can see what happens during the saves.

I will also try your version of mariadb.

[TomLewis]

Im not sure what im suppose to look at now I have enabled this, I assume somewhere a log is created and I should try save-periodically on my test server?

Yeah. Then we can see what happens during the saves.

I will also try your version of mariadb.

Jesus Christ this log moves at the speed of light as its running on the same database as my prod server, I can tail -f /var/lib/mysql/DatabaseName.log and its about 50 queries a second! Holy shit!

I wonder if theres a way to tell it to just query one database... my Test server is a separate database...

[TomLewis]

Right. So I run my log, and I made a change in the database manually so I could easily find where to look in the logs as a starting point.
On my test server, I again kept periodically enabled, I changed my crew balance to 100, I then did a /clan reload in game and it vanished as usual, but this time I had the DatabaseName.log I was able to filter out based on my database name, and it found my manual change for changing my crew balance to 100, so I knew thats where I to start, so I deleted everything before it, then I searched for everything with the prefix sc_ to find anything and everything simpleclans.

This is the entire history of queries for anything sc_

		 39274 Query	UPDATE `PirateCraft_Test`.`sc_clans` SET `balance`='100.00' WHERE  `id`=53
		 39274 Query	SELECT `id`, `verified`, `tag`, `color_tag`, `name`, `friendly_fire`, `founded`, `last_used`, `packed_allies`, `packed_rivals`, `packed_bb`, `cape_url`, `flags`, `balance`, `fee_enabled`, `fee_value`, `description`, `ranks`, `banner` FROM `PirateCraft_Test`.`sc_clans` WHERE  `id`=53
		 40482 Query	SELECT * FROM  `sc_clans`
		 40482 Query	SELECT * FROM  `sc_players`

My clan id is 53, so That first query is me changing my balance to 100 to test it, the second query is me doing a select to make sure its saved by re-listing the selection, then in-game I did a /clan reload or in my case /crew reload which by the looks of things you just pull all from sc_clans and sc_players.

So you are doing a fresh pull from the database, so its not the queries that are an issue, it must be something to do with your cache/memory management for current loaded database results for when the plugin booted on the server, and you must not be updating that cache/array when a reload happens when using periodically.

[RoinujNosde]

Let's go back a little.
What's really the issue here?

A. If you manually change something on the db and the same record (clan or player) is changed in-game, the manual change will get lost.

-> This is currently how it works. If this is the problem, it can easily be fixed.

B. You said ALL changes in-game were lost on reload/restart, right?

-> Your test didn't cover it. You should make a change in-game and see the log after a reload.

[TomLewis]

Let's go back a little.
What's really the issue here?

A. If you manually change something on the db and the same record (clan or player) is changed in-game, the manual change will get lost.

-> This is currently how it works. If this is the problem, it can easily be fixed.

B. You said ALL changes in-game were lost on reload/restart, right?

-> Your test didn't cover it. You should make a change in-game and see the log after a reload.

It will have the exact same results as the reload, as when I turn off periodically any manual changes work when I reload in-game. Which means its definitely something in the periodically code as when reloading it acts the same.
Dousnt matter if I change the database, or SimpleClans changes the database, the changes are reverted by SimpleClans either way.
You most likely do a "save to the database" when the plugin shuts down right? I would assume this is also pulled from the cache/array that periodically is holding, which is the exact same outcome. I mean if you want me to spend another 30m doing it, I can.

[RoinujNosde]

If it's not too much trouble I really need to see what the log says when reloading after in-game changes.

[TomLewis]

Ok tested!
I tested a few things, I tested everything in-game and from 2.13.1 it seems to be saving on restart changes made in game on my test server if I make the changes and restart (I didn't wait for for save-interval to trigger, as I have no idea when it actually triggers.

1. I tested adding money to my clan bank in-game and restarting (Not waiting for save-interval) this saved.
2. I tested a person leaving their crew and joining my crew and restarting (Not waiting for save-interval) this saved.

BUT

If I make any of these changes and just wait for the periodically save-interval, it never saves to the database, eve after a restart
So, if you make changes and restart instantly it will save the changes, but if you wait for the save-interval time in periodically it wont save at the time or at restart.

And any changes made to the MySQL database can be reloaded in-game with periodically turned off, but as soon as I turn on periodically it breaks, and no longer works.

This is the log from making changes to the bank in-game and restarting the server with periodically turned on.

		 42718 Connect	test_SimpleClans@localhost as anonymous on PirateCraft_Test
		 42718 Query	/* mysql-connector-java-8.0.15 (Revision: 79a4336f140499bd22dd07f02b708e163844e3d5) */SELECT  @@session.auto_increment_increment AS auto_increment_increment, @@character_set_client AS character_set_client, @@character_set_connection AS character_set_connection, @@character_set_results AS character_set_results, @@character_set_server AS character_set_server, @@collation_server AS collation_server, @@collation_connection AS collation_connection, @@init_connect AS init_connect, @@interactive_timeout AS interactive_timeout, @@license AS license, @@lower_case_table_names AS lower_case_table_names, @@max_allowed_packet AS max_allowed_packet, @@net_write_timeout AS net_write_timeout, @@query_cache_size AS query_cache_size, @@query_cache_type AS query_cache_type, @@sql_mode AS sql_mode, @@system_time_zone AS system_time_zone, @@time_zone AS time_zone, @@tx_isolation AS transaction_isolation, @@wait_timeout AS wait_timeout
		 42718 Query	SET NAMES utf8mb4
		 42718 Query	SET character_set_results = NULL
		 42718 Query	SET autocommit=1
		 42718 Query	SHOW DATABASES
		 42718 Query	SHOW FULL TABLES FROM `PirateCraft_Test` LIKE 'sc_clans'
		 42718 Query	SHOW FULL TABLES FROM `information_schema` LIKE 'sc_clans'
		 42718 Query	SHOW DATABASES
		 42718 Query	SHOW FULL TABLES FROM `PirateCraft_Test` LIKE 'sc_players'
		 42718 Query	SHOW FULL TABLES FROM `information_schema` LIKE 'sc_players'
		 42718 Query	SHOW DATABASES
		 42718 Query	SHOW FULL TABLES FROM `PirateCraft_Test` LIKE 'sc_kills'
		 42718 Query	SHOW FULL TABLES FROM `information_schema` LIKE 'sc_kills'
		 42718 Query	SHOW DATABASES
		 42718 Query	SHOW FULL TABLES FROM `PirateCraft_Test` LIKE 'sc_clans'
		 42718 Query	SHOW FULL COLUMNS FROM `sc_clans` FROM `PirateCraft_Test`
		 42718 Query	SHOW FULL COLUMNS FROM `sc_clans` FROM `PirateCraft_Test` LIKE 'balance'
		 42415 Query	SET autocommit=1
		 42415 Query	SET autocommit=1
		 42415 Query	SELECT `id` FROM `CMI_playtime` WHERE `player_id` = 153258 AND `date` = 200830 LIMIT 1
		 42718 Query	SHOW FULL TABLES FROM `information_schema` LIKE 'sc_clans'
		 42718 Query	SHOW DATABASES
		 42718 Query	SHOW FULL TABLES FROM `PirateCraft_Test` LIKE 'sc_clans'
		 42718 Query	SHOW FULL COLUMNS FROM `sc_clans` FROM `PirateCraft_Test`
		 42718 Query	SHOW FULL COLUMNS FROM `sc_clans` FROM `PirateCraft_Test` LIKE 'fee_enabled'
		 42718 Query	SHOW FULL TABLES FROM `information_schema` LIKE 'sc_clans'
		 42718 Query	SHOW DATABASES
		 42718 Query	SHOW FULL TABLES FROM `PirateCraft_Test` LIKE 'sc_clans'
		 42718 Query	SHOW FULL COLUMNS FROM `sc_clans` FROM `PirateCraft_Test`
		 42718 Query	SHOW FULL COLUMNS FROM `sc_clans` FROM `PirateCraft_Test` LIKE 'fee_value'
		 42718 Query	SHOW FULL TABLES FROM `information_schema` LIKE 'sc_clans'
		 42718 Query	SHOW DATABASES
		 42718 Query	SHOW FULL TABLES FROM `PirateCraft_Test` LIKE 'sc_clans'
		 42718 Query	SHOW FULL COLUMNS FROM `sc_clans` FROM `PirateCraft_Test`
		 42718 Query	SHOW FULL COLUMNS FROM `sc_clans` FROM `PirateCraft_Test` LIKE 'description'
		 42718 Query	SHOW FULL TABLES FROM `information_schema` LIKE 'sc_clans'
		 42718 Query	SHOW DATABASES
		 42718 Query	SHOW FULL TABLES FROM `PirateCraft_Test` LIKE 'sc_players'
		 42718 Query	SHOW FULL COLUMNS FROM `sc_players` FROM `PirateCraft_Test`
		 42718 Query	SHOW FULL COLUMNS FROM `sc_players` FROM `PirateCraft_Test` LIKE 'resign_times'
		 42718 Query	SHOW FULL TABLES FROM `information_schema` LIKE 'sc_players'
		 42718 Query	SHOW DATABASES
		 42718 Query	SHOW FULL TABLES FROM `PirateCraft_Test` LIKE 'sc_clans'
		 42718 Query	SHOW FULL COLUMNS FROM `sc_clans` FROM `PirateCraft_Test`
		 42718 Query	SHOW FULL COLUMNS FROM `sc_clans` FROM `PirateCraft_Test` LIKE 'ranks'
		 42718 Query	SHOW FULL TABLES FROM `information_schema` LIKE 'sc_clans'
		 42718 Query	SHOW DATABASES
		 42718 Query	SHOW FULL TABLES FROM `PirateCraft_Test` LIKE 'sc_players'
		 42718 Query	SHOW FULL COLUMNS FROM `sc_players` FROM `PirateCraft_Test`
		 42718 Query	SHOW FULL COLUMNS FROM `sc_players` FROM `PirateCraft_Test` LIKE 'locale'
		 42718 Query	SHOW FULL TABLES FROM `information_schema` LIKE 'sc_players'
		 42718 Query	SHOW DATABASES
		 42718 Query	SHOW FULL TABLES FROM `PirateCraft_Test` LIKE 'sc_clans'
		 42718 Query	SHOW FULL COLUMNS FROM `sc_clans` FROM `PirateCraft_Test`
		 42718 Query	SHOW FULL COLUMNS FROM `sc_clans` FROM `PirateCraft_Test` LIKE 'banner'
		 42718 Query	SHOW FULL TABLES FROM `information_schema` LIKE 'sc_clans'
		 42718 Query	SHOW DATABASES
		 42718 Query	SHOW FULL TABLES FROM `PirateCraft_Test` LIKE 'sc_kills'
		 42718 Query	SHOW FULL COLUMNS FROM `sc_kills` FROM `PirateCraft_Test`
		 42718 Query	SHOW FULL COLUMNS FROM `sc_kills` FROM `PirateCraft_Test` LIKE 'attacker_uuid'
		 42718 Query	SHOW FULL TABLES FROM `information_schema` LIKE 'sc_kills'
		 42718 Query	SHOW DATABASES
		 42718 Query	SHOW FULL TABLES FROM `PirateCraft_Test` LIKE 'sc_kills'
		 42718 Query	SHOW FULL COLUMNS FROM `sc_kills` FROM `PirateCraft_Test`
		 42718 Query	SHOW FULL COLUMNS FROM `sc_kills` FROM `PirateCraft_Test` LIKE 'victim_uuid'
		 42718 Query	SHOW FULL TABLES FROM `information_schema` LIKE 'sc_kills'
		 42718 Query	SHOW DATABASES
		 42718 Query	SHOW FULL TABLES FROM `PirateCraft_Test` LIKE 'sc_players'
		 42718 Query	SHOW FULL COLUMNS FROM `sc_players` FROM `PirateCraft_Test`
200830 12:16:48	 42718 Query	SHOW FULL COLUMNS FROM `sc_players` FROM `PirateCraft_Test` LIKE 'uuid'
		 42718 Query	SHOW FULL TABLES FROM `information_schema` LIKE 'sc_players'
		 42718 Query	SHOW DATABASES
		 42718 Query	SHOW FULL TABLES FROM `PirateCraft_Test` LIKE 'sc_players'
		 42718 Query	SHOW FULL COLUMNS FROM `sc_players` FROM `PirateCraft_Test`
		 42718 Query	SHOW FULL COLUMNS FROM `sc_players` FROM `PirateCraft_Test` LIKE 'uuid'
		 42718 Query	SHOW FULL TABLES FROM `information_schema` LIKE 'sc_players'
		 42718 Query	SELECT * FROM  `sc_clans`
		 42718 Query	SELECT * FROM  `sc_players`
		 42704 Query	START TRANSACTION
		 42704 Query	COMMIT
		 42704 Query	START TRANSACTION
		 42704 Query	COMMIT
		 42695 Query	commit
		 42695 Query	SET autocommit=1
		 42695 Query	SET autocommit=0

I also tested setting the save-interval to 1 instead of 10 I'm assuming this is in minutes? This ones really weird, as this actually works if I change it this low!
and I can see this;
42718 Query UPDATE `sc_clans` SET ranks = '{"ranks":[]}', banner = '', description = 'The overlords!', fee_enabled = 0, fee_value = '0.0', verified = 1, tag = 'cove', color_tag = '§6Cove', name = '', friendly_fire = 1, founded = '1462104000000', last_used = '1598786709000', packed_allies = 'be|atl|bwp|cltn|tas|kon|tne|pl|xenia|hi|xd|le|rop|cult|csn|rome|froge|sct|isen', packed_rivals = 'mafia|cotij', packed_bb = '1598786018599_§e§b100 $ were deposited|1598786019249_§e§b100 $ were deposited|1598786083541_§e§b100 $ were deposited|1598786084191_§e§b100 $ were deposited|1598786084842_§e§b100 $ were deposited|1598786625476_§e§b200 $ were deposited|1598786709000_§e§b200 $ were deposited', cape_url = '', cape_url = '', balance = '1350.0', flags = '{"homeX":-338,"homeZ":-823,"homeY":72,"homeWorld":"PirateCraft_1","warring":[]}' WHERE tag = 'cove' 200830 12:25:59 42521 Query SELECT balance FROM sc_clans WHERE tag ="cove"

So im utterly lost why it sometimes decides to do it, and then others it just never does it, whats super weird, is that ALL I changed was the crew balance yet its updating EVERYTHING in the crew, not just what I changed.

[TomLewis]

Thanks again for testing!

I also tested setting the save-interval to 1 instead of 10 I'm assuming this is in minutes? This ones really weird, as this actually works if I change it this low!

Nice find!

whats super weird, is that ALL I changed was the crew balance yet its updating EVERYTHING in the crew, not just what I changed.

It's coded like that. Otherwise I would need a query for every field a clan/clanplayer has. (Which are a lot)

Well I tested as much as I could think of that could be a variable or cause, hopefully something there helps figure it out!

Maybe it is something to do with having everything be sent in one query, maybe that's where the issue lies, certain methods not updating that held data somehow in a certain circumstance? I'm out of ideas for what I can test, I scanned your code base to see if I could work it out, but my scripting is limited to PHP/Python & Bash! Im fine with SQL but Java throws me off!

[RoinujNosde]

The periodically code is basically like this:
When a change is made, the object (clan or clanplayer) is stored in a set;
Every X minutes, or on reload/restart, this set is looped and added to a sql batch, which then is sent to the db;
The set is cleared.

[RoinujNosde]

@FireController1847 if possible, test using the version with debug:

#43 (comment)

[FireController1847]

This is strange. Using that version, on a local test server using Paper 1.16.3 Build 228 with SimpleClans 2.13.1 (Custom Build), running alongside MariaDB 15.1 and Windows 10 2004 Build 19041.508. I will see if I can create a more identical environment and continue testing.

Using the same paper build and same MySQL version (not MariaDB) does not make the error happen. MySQL 5.7.31 with Paper 1.16.3 Build 196. SimpleClans 2.13.1 (Custom Build) and Windows 10 2004 Build 19041.508 are the same. I will now attempt to copy my configuration from the main server.

I was unable to reproduce the issue using that version on a local test server using the specs in the second paragraph. I do not know what this means. I will try and use a test server on my host.

[FireController1847]

After much testing I am having strong issues being able to consistently reproduce the issue. It is clear it is happening on my production server I have yet to be able to figure out anything on my test servers. I am unsure of how to continue on this point.

I do notice while looking in my database that quite a few sc_players are missing the 'tag' value; it's not null, it's just blank for some reason. Could this be an attribute to what's happening?

[RoinujNosde]

I do notice while looking in my database that quite a few sc_players are missing the 'tag' value; it's not null, it's just blank for some reason. Could this be an attribute to what's happening?

Probably players without a clan.

This is strange. Using that version, on a local test server using Paper 1.16.3 Build 228 with SimpleClans 2.13.1 (Custom Build), running alongside MariaDB 15.1 and Windows 10 2004 Build 19041.508. I will see if I can create a more identical environment and continue testing.

What do you mean here? Did the issue occur using these specs?

[FireController1847]

My apologies for not making that clear. Yes, I was unable to reproduce the issue on all of my test servers, but it is clear the issue is still happening on my production server

[RoinujNosde]

@FireController1847 are you able to run a test server on the same machine as the production one?

[FireController1847]

Sorry for my delay. I will possibly be able to run it on the same machine, however I likely won't be able to run it using the same MySQL database or the same Minecraft server. I can copy over the settings and try and match them as much as possible however. I'll look into doing this in the next day or two and report back here.

If it would help at all, I wouldn't mind dumping the three sc_ tables to let you see the data and see if everything matches up with what's expected

[RoinujNosde]

I will possibly be able to run it on the same machine, however I likely won't be able to run it using the same MySQL database or the same Minecraft server.

It's alright.

If it would help at all, I wouldn't mind dumping the three sc_ tables to let you see the data and see if everything matches up with what's expected

There is no need.

[FireController1847]

In the production server I just got the following error:

[13:48:25 ERROR]: [SimpleClans] [Thread] Error at SQL UPDATE Query: com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: The last packet successfully received from the server was 39,988,849 milliseconds ago.  The last packet sent successfully to the server was 39,988,852 milliseconds ago. is longer than the server configured value of 'wait_timeout'. You should consider either expiring and/or testing connection validity before use in your application, increasing the server configured values for client timeouts, or using the Connector/J connection property 'autoReconnect=true' to avoid this problem.
[13:48:25 ERROR]: [SimpleClans] [Thread] Query: UPDATE `sc_players` SET locale = 'en', resign_times = '{}', leader = 0, tag = 'firestorm', friendly_fire = 0, neutral_kills = 0, rival_kills = 0, civilian_kills = 0, deaths = 0, last_seen = '1602874105591', packed_past_clans = '', trusted = 0, flags = '{"bb-enabled":true,"channel-state":[true,true,true],"cape-enabled":true,"channel":"NONE","chat-shortcut":false,"rank":"","hide-tag":true}', name = 'ItzNathaniel' WHERE `uuid` = 'ab64d88f-1084-40ab-a47c-1cd2135030f3';
[13:48:25 ERROR]: Error at SQL Query: The last packet successfully received from the server was 39,988,669 milliseconds ago.  The last packet sent successfully to the server was 39,988,672 milliseconds ago. is longer than the server configured value of 'wait_timeout'. You should consider either expiring and/or testing connection validity before use in your application, increasing the server configured values for client timeouts, or using the Connector/J connection property 'autoReconnect=true' to avoid this problem.
[13:48:25 ERROR]: Query: SELECT * FROM pstone_players WHERE uuid = 'ab64d88f-1084-40ab-a47c-1cd2135030f3';

This is not my test server, as I have not set that up yet. The MySQL database is still online and my other plugins are still connected. I wonder what could be causing this?

[RoinujNosde]

@FireController1847 this error doesn't seem to be related.
Were there players online? This error means that the connection was not used for more than 10 hours. (longer than what your current mysql config allows)

[FireController1847]

Alright, I said "screw it" and shoved the debug version on the production server and had a few friends help me test it. I was unable to reproduce the issue. I do not understand why. Clearly this is an issue that happened (three of my clans got removed because of it at one point).

Is there an option that will purge members on a team if they haven't been seen in 'x' amount of time? Could it possible the entire team got purged because they hadn't been seen for a long time?

But that wouldn't make sense. I do wonder if the two issues might actually be related - what if, after 12 hours of nobody on the server, I then try and add someone into the clan? Does it automatically reconnect? If not, then I could assume that it would not be able to run the periodic saves, or server closing saves for that matter. So if I created a team after 12 hours of inactivity, then theoretically it would not save. Though, again then it wouldn't make sense why it would purge upon next restart, because obviously that means it saved to MySQL somehow....

This is the most confusing and intermittent issue I've ever looked at before. Sorry I'm not really able to provide anything more helpful. I will send another comment with the stripped logs of my tests.

[FireController1847]

2020-10-16-4.log
2020-10-16-5.log
2020-10-16-6.log
2020-10-16-7.log
2020-10-16-8.log

Here are the stripped down log files. These should contain everything relating to the experiment, and I stripped out anything not relating to SimpleClans.

[RoinujNosde]

Is there an option that will purge members on a team if they haven't been seen in 'x' amount of time? Could it possible the entire team got purged because they hadn't been seen for a long time?

Yes, there is a config for changing the purge days. If they were purged, it would appear in the log. Something like "purging clan"...

But that wouldn't make sense. I do wonder if the two issues might actually be related - what if, after 12 hours of nobody on the server, I then try and add someone into the clan?

You would get an error. And it would try to save the data again after X minutes (after reconnecting, I think).

[FireController1847]

Okay, I think my issue may be somewhat related, but also I didn't know about this purging feature. If the MySQL delete issue comes up again, I will reply here, because I am fairly certain it happened within a day (but also, I don't know if it was just an unverified clan and deleted in two days).

[TomLewis]

Sorry I have no idea why I've been putting this off, its a 10 min test.
Set my 'save-interval: 10' updated my crew balance in-game by adding 100, waited 10 mins and I actually get an error now with this test version, what is weird is that if I set 'save-interval: 1' it actually saves to the database, not sure how consistent it would be on prod tho, so it didn't save on schedule and it didn't save when I restarted the server when set at 10 mins.

So yes, we actually have an error now, I'm sorry for taking so long to test this again!
Latest.log with times and error/full process.

It looks like a conflict with BanManager? @FireController1847 do you have BanManager installed also? (Unlesss BanManager also has a 10 min interval for saving.....)

So in this one log you can see the error that happens at the save-interval but you can also see the error it causes when the server stops/reboots.
https://gist.github.com/TomLewis/0d35ba8eead974bf400dc8ce7a77fc95

[TomLewis]

I tried it with a save-interval: 5 and it seemed to save, I wonder if its specifically 10 or just double digits, im going to try 12 mins after this.

[17:36:58] [Server thread/INFO]: GodsDead issued server command: /crew bank deposit 100
[17:36:58] [Server thread/INFO]: StorageManager.updateClan
[17:36:58] [Server thread/INFO]: clan = cove
[17:36:58] [Server thread/INFO]: [Crew Announce] [GodsDead &7»&f] * 100 $ were deposited
[17:36:58] [Server thread/INFO]: StorageManager.updateClan
[17:36:58] [Server thread/INFO]: clan = cove
[17:37:01] [Server thread/INFO]: GodsDead issued server command: /crew bank status
[17:40:44] [Craft Scheduler Thread - 34/INFO]: SaveDataTask.run
[17:40:44] [Craft Scheduler Thread - 34/INFO]: StorageManager.saveModified
[17:40:44] [Craft Scheduler Thread - 34/INFO]: clan = cove
[17:40:44] [Craft Scheduler Thread - 34/INFO]: cp = GodsDead
[17:40:44] [Craft Scheduler Thread - 34/INFO]: StorageManager.saveModified - batch executed

Either way this debug you have is really useful, this should be in the main plugin anyway as a toggle so we can actually get information for when it fails!

[TomLewis]

Tested with 12 mins and it works, so its precisely with that 10 mins, so im going to assume my guess with banmanager also doing something at 10 mins that blocks it, but what it doesn't explain is why it also breaks it saving on restart!

[RoinujNosde]

@TomLewis FireController's problem was a different one. It was about the purge feature.
If you had the same problem, all of your clans would be lost.

About the save-periodically feature: when you first reported you weren't getting errors, right? I wonder what changed.

[TomLewis]

@RoinujNosde it's your custom debug version! You asked me to test using that version! That showed these verbose messages! Which is showing the problem now!

[RoinujNosde]

@TomLewis The debug version only added those messages:
[17:40:44] [Craft Scheduler Thread - 34/INFO]: SaveDataTask.run
[17:40:44] [Craft Scheduler Thread - 34/INFO]: StorageManager.saveModified
[17:40:44] [Craft Scheduler Thread - 34/INFO]: clan = cove
[17:40:44] [Craft Scheduler Thread - 34/INFO]: cp = GodsDead
[17:40:44] [Craft Scheduler Thread - 34/INFO]: StorageManager.saveModified - batch executed

The error could've been displayed by the other one. That's what's strange...

Anyway, since BanManager could be interfering with this save task, I'm going to close this and if it does happen again let me know...