On Sat, Dec 19, 2015 at 1:30 AM, Micah Anderson micah@riseup.net wrote:

Hi,

I've got the database_attachments plugin enabled because I have multiple machines with a memcached session store. It seems to work fairly well... except that I am replicating the database to a read-only slave for redundancy (and read-balancing) and the replication keeps breaking.

The slave will get this error:

Could not execute Delete_rows event on table roundcube.cache; Can't find record in 'cache', Error_code: 1032; handler error HA_ERR_KEY_NOT_FOUND; the event's master log mysql-bin.000151, end_log_pos 182376

I've got a db_dnsw and db_dnsr configured in my roundcube config, could it be that roundcube is also writing to the db_dnsr causing entries to be removed on the slave, and then when the replication happens it fails because it has been removed on the slave already?

This should not happen. All INSERT/UPDATE/DELETE queries go to dsnw and also subsequent reads from the same PHP process should use that connection in order to not hit any replication delays. Can you log all SQL queries and compare that with the replication log?

I tried to look at mysql-bin.000151 for the 182376 event, but couldn't find it.

Ideally, I wouldn't even replicate the roundcube.cache table, because its a *lot* of data, but if I dont replicate it, I suspect the db_dnsr would fail to find the records?

You might look into the 'db_table_dsn' config option: https://github.com/roundcube/roundcubemail/blob/master/config/defaults.inc.p...

This was added for exactly this case. You can define 'r' or 'w' connections to be used on a per-table basis.

~Thomas

Micah Anderson micah@riseup.net writes:

Thomas Bruederli thomas-tZJS5fsp0j0qcZcGjlUOXw@public.gmane.org writes:

...

On Sat, Dec 19, 2015 at 1:30 AM, Micah Anderson micah-sGOZH3hwPm2sTnJN9+BGXg@public.gmane.org wrote:

This should not happen. All INSERT/UPDATE/DELETE queries go to dsnw and also subsequent reads from the same PHP process should use that connection in order to not hit any replication delays. Can you log all SQL queries and compare that with the replication log?

So I turned on the general global query log on the slave (SET global general_log = 1;) and waited for replication to break again. Eventually it failed again and I looked at what queries were done on the replicated slave that were not SELECT queries and found these:

(in case the formatting is impossible to read, you can view these on this pastebin: https://share.riseup.net/#aqcIrGmnJ_2LmC2EtphXCQ)

mysql> SELECT * FROM mysql.general_log where user_host LIKE 'roundcube%' and command_type NOT LIKE 'Connect' and command_type NOT LIKE 'Quit' and argument not LIKE 'SELECT%' and argument not LIKE 'SET NAMES%' and argument not LIKE 'SHOW%'; +---------------------+-------------------------------------+-----------+-----------+--------------+----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+ | event_time | user_host | thread_id | server_id | command_type | argument | +---------------------+-------------------------------------+-----------+-----------+--------------+----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+ | 2015-12-29 00:22:03 | roundcube[roundcube] @ [127.0.0.1] | 18882611 | 3 | Query | DELETE FROM cache WHERE user_id = '85143' AND cache_key LIKE 'ATTACHqifhfjuoliugv5l1d9i39hvqu2.%' | | 2015-12-29 00:22:03 | roundcube[roundcube] @ [127.0.0.1] | 18882600 | 3 | Query | UPDATE users SET last_login = now() WHERE user_id = '31643' | | 2015-12-29 00:22:09 | roundcube[roundcube] @ [127.0.0.1] | 18882446 | 3 | Query | DELETE FROM cache WHERE user_id = '263603' AND cache_key LIKE 'ATTACHisvbumgsk5ouoi367ilhkej5m2.18922776125681d17a7aa22%' | | 2015-12-29 00:22:16 | roundcube[roundcube] @ [127.0.0.1] | 18882737 | 3 | Query | UPDATE users SET last_login = now() WHERE user_id = '28113' | | 2015-12-29 00:22:24 | roundcube[roundcube] @ [127.0.0.1] | 18882792 | 3 | Query | UPDATE users SET last_login = now() WHERE user_id = '28913' | | 2015-12-29 00:22:24 | roundcube[roundcube] @ [127.0.0.1] | 18882797 | 3 | Query | DELETE FROM cache WHERE user_id = '31643' AND cache_key LIKE 'ATTACHfvs4pntjvdt54pvh791nd5l4i1.%' | | 2015-12-29 00:22:25 | roundcube[roundcube] @ [127.0.0.1] | 18882803 | 3 | Query | UPDATE users SET last_login = now() WHERE user_id = '514963' | | 2015-12-29 00:22:26 | roundcube[roundcube] @ [127.0.0.1] | 18882810 | 3 | Query | UPDATE users SET last_login = now() WHERE user_id = '211493' | | 2015-12-29 00:22:28 | roundcube[roundcube] @ [127.0.0.1] | 18882832 | 3 | Query | DELETE FROM cache WHERE user_id = '250093' AND cache_key LIKE 'ATTACHmp7m6d9qppv4kr0ulla861h0v0.%' | | 2015-12-29 00:22:53 | roundcube[roundcube] @ [127.0.0.1] | 18882957 | 3 | Query | UPDATE users SET last_login = now() WHERE user_id = '20893' | | 2015-12-29 00:22:55 | roundcube[roundcube] @ [127.0.0.1] | 18883026 | 3 | Query | UPDATE users SET last_login = now() WHERE user_id = '619173' | | 2015-12-29 00:23:14 | roundcube[roundcube] @ [127.0.0.1] | 18882991 | 3 | Query | UPDATE users SET last_login = now() WHERE user_id = '377533' | | 2015-12-29 01:30:11 | roundcube[roundcube] @ [127.0.0.1] | 18917716 | 3 | Query | UPDATE users SET last_login = now() WHERE user_id = '55803' | | 2015-12-29 01:30:11 | roundcube[roundcube] @ [127.0.0.1] | 18917596 | 3 | Query | UPDATE users SET last_login = now() WHERE user_id = '446603' | | 2015-12-29 01:30:20 | roundcube[roundcube] @ [127.0.0.1] | 18917657 | 3 | Query | UPDATE users SET last_login = now() WHERE user_id = '485343' | | 2015-12-29 01:30:29 | roundcube[roundcube] @ [127.0.0.1] | 18917514 | 3 | Query | DELETE FROM cache WHERE user_id = '72113' AND cache_key LIKE 'ATTACH36nq1uh6qr32lq2ecjtm8pa6m7.17460303925681e13b51d0c%' | | 2015-12-29 01:30:29 | roundcube[roundcube] @ [127.0.0.1] | 18918008 | 3 | Query | DELETE FROM cache WHERE user_id = '484413' AND cache_key LIKE 'ATTACHfjmgl3j151qgg3d4acu35lsre0.%' | | 2015-12-29 01:30:29 | roundcube[roundcube] @ [127.0.0.1] | 18917660 | 3 | Query | UPDATE users SET preferences = 'a:14:{s:16:"message_sort_col";s:4:"date";s:18:"message_sort_order";s:3:"ASC";s:11:"search_mods";a:3:{s:1:"*";a:2:{s:7:"subject";i:1;s:4:"from";i:1;}s:4:"Sent";a:2:{s:7:"subject";i:1;s:2:"to";i:1;}s:6:"Drafts";a:2:{s:7:"subject";i:1;s:2:"to";i:1;}}s:17:"message_threading";a:3:{s:8:"redacted";b:0;s:5:"INBOX";b:0;s:9:"redacted";b:0;}s:12:"mdn_requests";i:2;s:13:"mail_pagesize";i:200;s:11:"prefer_html";b:1;s:12:"display_next";b:0;s:10:"htmleditor";i:1;s:10:"reply_mode";i:1;s:9:"sig_below";b:1;s:17:"compose_responses";a:1:{i:0;a:4:{s:4:"name";s:3:"lol";s:4:"text";s:6:"lollek";s:6:"format";s:4:"text";s:3:"key";s:16:"9cdfb439c7876e70";}}s:9:"list_cols";a:8:{i:0;s:7:"threads";i:1;s:7:"subject";i:2;s:6:"status";i:3;s:6:"fromto";i:4;s:4:"date";i:5;s:4:"size";i:6;s:4:"flag";i:7;s:10:"attachment";}s:11:"client_hash";s:32:"6c4b47cb03199d019a39ad9fb461e018";}', language = 'pl_PL' WHERE user_id = '658183' | | 2015-12-29 01:30:30 | roundcube[roundcube] @ [127.0.0.1] | 18917876 | 3 | Query | UPDATE users SET last_login = now() WHERE user_id = '37433' | | 2015-12-29 01:30:30 | roundcube[roundcube] @ [127.0.0.1] | 18917968 | 3 | Query | UPDATE users SET last_login = now() WHERE user_id = '74373' | | 2015-12-29 01:30:30 | roundcube[roundcube] @ [127.0.0.1] | 18917950 | 3 | Query | UPDATE users SET last_login = now() WHERE user_id = '126763' | | 2015-12-29 01:30:30 | roundcube[roundcube] @ [127.0.0.1] | 18917733 | 3 | Query | DELETE FROM cache WHERE expires < now() | | 2015-12-29 01:30:30 | roundcube[roundcube] @ [127.0.0.1] | 18917733 | 3 | Query | DELETE FROM cache_shared WHERE expires < now() | | 2015-12-29 01:30:30 | roundcube[roundcube] @ [127.0.0.1] | 18917733 | 3 | Query | DELETE FROM cache_messages WHERE expires < now() | | 2015-12-29 01:30:31 | roundcube[roundcube] @ [127.0.0.1] | 18917733 | 3 | Query | DELETE FROM cache_index WHERE expires < now() | | 2015-12-29 01:30:31 | roundcube[roundcube] @ [127.0.0.1] | 18917733 | 3 | Query | DELETE FROM cache_thread WHERE expires < now() | | 2015-12-29 01:30:32 | roundcube[roundcube] @ [127.0.0.1] | 18918155 | 3 | Query | UPDATE users SET last_login = now() WHERE user_id = '292603' | | 2015-12-29 01:30:37 | roundcube[roundcube] @ [127.0.0.1] | 18918193 | 3 | Query | UPDATE users SET last_login = now() WHERE user_id = '58623' | | 2015-12-29 01:30:39 | roundcube[roundcube] @ [127.0.0.1] | 18917938 | 3 | Query | DELETE FROM cache WHERE user_id = '335783' AND cache_key LIKE 'ATTACH5r67jlimb24etuhcvd638u4jf1.6098462345681e1118692c%' | | 2015-12-29 01:30:41 | roundcube[roundcube] @ [127.0.0.1] | 18918165 | 3 | Query | DELETE FROM cache WHERE user_id = '614823' AND cache_key LIKE 'ATTACH2hjt6m819f76h3hah3ibqfkda4.4718250645681dada9ba06%' | +---------------------+-------------------------------------+-----------+-----------+--------------+----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+ 30 rows in set (3 min 46.24 sec)

mysql>

As you can see, there are UPDATE and DELETE queries for the 'cache' and 'users' tables (last_login and preferences).

To work around this, I've done:

REVOKE ALL PRIVILEGES ON roundcube.* FROM 'roundcube'@'localhost' GRANT SELECT on roundcube.* TO 'roundcube'@'localhost'; flush priviledges;

But obviously something is wrong here.

...

You might look into the 'db_table_dsn' config option: https://github.com/roundcube/roundcubemail/blob/master/config/defaults.inc.p...

This was added for exactly this case. You can define 'r' or 'w' connections to be used on a per-table basis.

Thanks for that, although I don't quite understand how this works, the example you linked to seems to be related to the cache table, and it has 'r' set for cache, cache_index, cache_thread and cache_messages... what does this example do? It sets that table read-only on the master? How does this allow configuration on a per-table basis?

I'm still curious about how this config option works, I understand holidaze, etc. just dont want to lose this part in the thread :)

micah

Thomas Bruederli thomas@roundcube.net writes:

On Tue, Dec 29, 2015 at 8:30 PM, micah micah@riseup.net wrote:

...

Micah Anderson micah@riseup.net writes:

...

Thomas Bruederli thomas-tZJS5fsp0j0qcZcGjlUOXw@public.gmane.org writes:

...

On Sat, Dec 19, 2015 at 1:30 AM, Micah Anderson micah-sGOZH3hwPm2sTnJN9+BGXg@public.gmane.org wrote:

This should not happen. All INSERT/UPDATE/DELETE queries go to dsnw and also subsequent reads from the same PHP process should use that connection in order to not hit any replication delays. Can you log all SQL queries and compare that with the replication log?

So I turned on the general global query log on the slave (SET global general_log = 1;) and waited for replication to break again. Eventually it failed again and I looked at what queries were done on the replicated slave that were not SELECT queries and found these:

(in case the formatting is impossible to read, you can view these on this pastebin: https://share.riseup.net/#aqcIrGmnJ_2LmC2EtphXCQ)

[...]

As you can see, there are UPDATE and DELETE queries for the 'cache' and 'users' tables (last_login and preferences).

Hmm, that doesn't look good. Can you maybe share your database connection config options with us? Config options 'db_dsnw', 'db_dsnr', 'db_dsnw_noread', 'db_persistent' and 'db_table_dsn' are relevant for this. Replace sensitive information accordingly before posting them here.

These are implementation details, but I'm explaining for clarity: We run tunnels on the machines to connect to the two databases, that means that the db connection happens to the local machine, which then gets tunneled to the actual machine. So below you see the dsnw and dsnr both are on a 127.0.0.x address, the database 'master' is the one on 127.0.0.2, and the read-only slave is at 127.0.0.1, the stunnel configurations are setup to direct connections on each of those ips to the right machines:

$config['db_dsnw'] = "mysql://roundcube:xxx@127.0.0.2:3310/roundcube"; $config['db_dsnr'] = "mysql://roundcube:xxx@127.0.0.1:3310/roundcube"; $config['db_dsnw_noread'] = true; $config['db_persistent'] = false; $config['db_prefix'] = ''; $config['db_table_dsn'] = array( // 'cache' => 'r', // 'cache_index' => 'r', // 'cache_thread' => 'r', // 'cache_messages' => 'r', );

I'll note I also have session storage setup to use memcache, one on each machine, so these are also set (but probably irrelevant):

$config['imap_cache'] = 'memcache'; $config['session_storage'] = 'memcache'; $config['memcache_hosts'] = array('10.0.1.164:11211', '10.0.1.163:11211');

and in php.ini, I've also got the memcache settings:

session.save_path = "tcp://10.0.1.163:11211?persistent=1&weight=1&timeout=1&retry_interval=15,tcp://10.0.1.164:11211?persistent=1&weight=1&timeout=1&retry_interval=15" memcache.hash_strategy = "consistent" memcache.max_failover_attempts = 100 memcache.allow_failover = 1

The decision which connection to use is made in rcube_db::dsn_select() https://github.com/roundcube/roundcubemail/blob/master/program/lib/Roundcube...

This is done for each query and we need to investigate if there's a major issue in this part of the code. Although you're the first to report problems like this...

I have "ROW" based replication setup, instead of the default "STATEMENT", I believe that I did this because the slave couldn't keep up with all the statements that were being done to the cache tables.

I switched this back to STATEMENT based replication to see if this helps.

...

To work around this, I've done:

REVOKE ALL PRIVILEGES ON roundcube.* FROM 'roundcube'@'localhost' GRANT SELECT on roundcube.* TO 'roundcube'@'localhost'; flush priviledges;

But obviously something is wrong here.

That's not the preferred way to do it and will probably result in database failures due to missing prifileges.

Well the replication slave shouldn't have *any* write priviledges at all (except for the replication itself), so this shouldn't cause database failures because roundcube shouldn't be trying to write there.

...

...

...

You might look into the 'db_table_dsn' config option: https://github.com/roundcube/roundcubemail/blob/master/config/defaults.inc.p...

This was added for exactly this case. You can define 'r' or 'w' connections to be used on a per-table basis.

Thanks for that, although I don't quite understand how this works, the example you linked to seems to be related to the cache table, and it has 'r' set for cache, cache_index, cache_thread and cache_messages... what does this example do? It sets that table read-only on the master? How does this allow configuration on a per-table basis?

I'm still curious about how this config option works, I understand holidaze, etc. just dont want to lose this part in the thread :)

Yeah, sorry for the delay.

No problems, being off the computer and enjoying the holiday and family is more important! :)

Anyway, the 'db_table_dsn' property holds a map of table names and connection identifiers. You can set either 'r' for using the 'db_dsnr' or 'w' for using the 'db_dsnw' connection for all interactions with the according table. This will overrule the default determination whether to use the read or write connection.

The example given in the default config would keep all cache data in the local database. In such a scenario, you would not create these tables on the master and therefore also not replicate them to the slaves.

However, the database_attachments plugin uses the cache table for storing the uploaded attachments. This is something you want to share amongst all nodes and therefore you should not be using this configuration for the 'cache' table.

If I have two machines running roundcube, and they both connect to the same roundcube database on the same server, then they both have access to the cache table, so it is already shared amongst all the nodes involved. There is no reason to replicate this table to the database slave, if everything can be pulled from the master.

If I can configure that, then I can configure mysql to not replicate that table. If mysql doesn't replicate that table, then the replication errors will go away, and the high replication traffic that comes with that would also go away.