Monitoring Plugin should enqueue archiving requests

Paolo_Manili · February 7, 2019, 2:31pm

Hi,
we noticed that when clients aggressively ask for user messaging history (using XEP 0313) some of the requests get dropped (Imagine a new client for an existing user making a bulk fetch of his conversations), looking into the server logs we found (Openfire 4.2.3 ) that the server was running out of it’s available DB connections (We use MySQL), thinking the 25 default might be low I raised to a 100, but the problem still occurs.
This results in dropped requests for monitoring but also from other plugins that might be asking for database access.

Thanks in advance,
Paolo Manili

speedy · February 7, 2019, 3:09pm

Ciao Paolo,
Are you seeing anything on the MySQL side? Perhaps adjusting a few settings in my.cnf will work around your issue?

Paolo_Manili · February 7, 2019, 3:13pm

I thought about it, and I suppose I could scale upwards on the threadpool side, but I reasoned that if a single client can exhaust a 100 connections in the threadpool there’s bound to be a problem. What would happen if 100 clients request the archive?
Unless I’m really missing something basic, I don’t think it should be possible for a plugin to cripple a server under a fairly basic load.
Sorry, just realized I didn’t really answer the question, no the MySQL doesn’t show excessive load or anything.

speedy · February 7, 2019, 3:16pm

I’m not sure anyone else has reported this issue…perhaps one of the devs will see this, and be able to offer some insight. by any chances did you search the forums for similar issues? if so, could you link a few here for reference.

Paolo_Manili · February 7, 2019, 3:23pm

Yes I know, and I have to say that I hadn’t noticed it on older installations either (have been running various various versions since 3.9.3 days ), but our two newest 4.2.3 and 4.3.0 setups both show exhausted threadpools under archiving requests.
It could be due to said clients asking for the archive aggressively, but it shouldn’t cause such a large hiccup.
I had a look in the forums and didn’t see other mentions of it. I’ll see if I can gather more data (as in which specific function call runs out of connections).

guus · February 7, 2019, 3:29pm

For the record: what version of the monitoring plugin are you using?

Could you please use Mysql’s SHOW PROCESSLIST to see what those connections are doing?

Also, it would be very helpful to have a Java threaddump of Openfire when the issue occurs.

Paolo_Manili · February 7, 2019, 4:30pm

Ok, here we go, we’re running monitoring 1.6.2 on openfire 4.2.3.
I haven’t got the thread dump yet but this is the process list from mysql and a typical entry from Openfire error log.


2019.02.07 17:14:04 org.logicalcobwebs.proxool.openfire - 594565 -008068 (100/100/00) - Couldn't get connection because we are at maximum connection count and there are none available
2019.02.07 17:14:04 org.jivesoftware.database.DbConnectionManager - Unable to get a connection from the database pool (attempt 0 out of 10).
java.sql.SQLException: Couldn't get connection because we are at maximum connection count (100/100) and there are none available
	at org.logicalcobwebs.proxool.Prototyper.quickRefuse(Prototyper.java:309)
	at org.logicalcobwebs.proxool.ConnectionPool.getConnection(ConnectionPool.java:152)
	at org.logicalcobwebs.proxool.ProxoolDriver.connect(ProxoolDriver.java:89)
	at java.sql.DriverManager.getConnection(DriverManager.java:664)
	at java.sql.DriverManager.getConnection(DriverManager.java:208)
	at org.jivesoftware.database.DefaultConnectionProvider.getConnection(DefaultConnectionProvider.java:82)
	at org.jivesoftware.database.DbConnectionManager.getConnection(DbConnectionManager.java:125)
	at com.reucon.openfire.plugin.archive.impl.JdbcPersistenceManager.findMessages(JdbcPersistenceManager.java:556)
	at com.reucon.openfire.plugin.archive.xep0313.IQQueryHandler.retrieveMessages(IQQueryHandler.java:295)
	at com.reucon.openfire.plugin.archive.xep0313.IQQueryHandler.access$100(IQQueryHandler.java:43)
	at com.reucon.openfire.plugin.archive.xep0313.IQQueryHandler$1.run(IQQueryHandler.java:214)
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at java.lang.Thread.run(Thread.java:748)




+---------+----------------------+------------------+----------+---------+------+----------------------+------------------------------------------------------------------------------------------------------+----------+
| Id      | User                 | Host             | db       | Command | Time | State                | Info                                                                                                 | Progress |
+---------+----------------------+------------------+----------+---------+------+----------------------+------------------------------------------------------------------------------------------------------+----------+
| 5438413 | our_user | our_ip:52486 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5438414 | our_user | our_ip:52488 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5438415 | our_user | our_ip:52490 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5438416 | our_user | our_ip:52492 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5438417 | our_user | our_ip:52494 | our_database | Sleep   |    0 |                      | NULL                                                                                                 |    0.000 |
| 5440658 | our_user | our_ip:52504 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5440935 | our_user | our_ip:52506 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5440936 | our_user | our_ip:52508 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5440937 | our_user | our_ip:52510 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5440938 | our_user | our_ip:52512 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5440939 | our_user | our_ip:52514 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5440940 | our_user | our_ip:52516 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5440941 | our_user | our_ip:52518 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5440942 | our_user | our_ip:52520 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5440943 | our_user | our_ip:52522 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5440944 | our_user | our_ip:52524 | our_database | Sleep   |    0 |                      | NULL                                                                                                 |    0.000 |
| 5440945 | our_user | our_ip:52526 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5440946 | our_user | our_ip:52528 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5440947 | our_user | our_ip:52530 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5440948 | our_user | our_ip:52532 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5440949 | our_user | our_ip:52534 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5442957 | our_user | our_ip:52538 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5442958 | our_user | our_ip:52540 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5442959 | our_user | our_ip:52542 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5442961 | our_user | our_ip:52546 | our_database | Sleep   |    0 |                      | NULL                                                                                                 |    0.000 |
| 5442960 | our_user | our_ip:52544 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5454194 | our_user | our_ip:52572 | our_database | Sleep   |    0 |                      | NULL                                                                                                 |    0.000 |
| 5454189 | our_user | our_ip:52562 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5454190 | our_user | our_ip:52564 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5454191 | our_user | our_ip:52566 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5454192 | our_user | our_ip:52568 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5454193 | our_user | our_ip:52570 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5454195 | our_user | our_ip:52574 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5454196 | our_user | our_ip:52576 | our_database | Query   |    0 | removing tmp table   | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5454197 | our_user | our_ip:52578 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5454198 | our_user | our_ip:52580 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5454199 | our_user | our_ip:52582 | our_database | Sleep   |    0 |                      | NULL                                                                                                 |    0.000 |
| 5454200 | our_user | our_ip:52584 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5454201 | our_user | our_ip:52586 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5454202 | our_user | our_ip:52588 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5454203 | our_user | our_ip:52590 | our_database | Sleep   |    0 |                      | NULL                                                                                                 |    0.000 |
| 5454204 | our_user | our_ip:52592 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5454205 | our_user | our_ip:52594 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5454206 | our_user | our_ip:52596 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5454207 | our_user | our_ip:52598 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5454208 | our_user | our_ip:52600 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5454209 | our_user | our_ip:52602 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5454210 | our_user | our_ip:52604 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5454211 | our_user | our_ip:52606 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5454212 | our_user | our_ip:52608 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5454213 | our_user | our_ip:52610 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5454214 | our_user | our_ip:52612 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5454215 | our_user | our_ip:52614 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5454216 | our_user | our_ip:52616 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5454217 | our_user | our_ip:52618 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5454218 | our_user | our_ip:52620 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5454219 | our_user | our_ip:52622 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5454220 | our_user | our_ip:52624 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5454221 | our_user | our_ip:52626 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5454222 | our_user | our_ip:52628 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5454223 | our_user | our_ip:52630 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5454224 | our_user | our_ip:52632 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5454225 | our_user | our_ip:52634 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5454226 | our_user | our_ip:52636 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5454227 | our_user | our_ip:52638 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5454228 | our_user | our_ip:52640 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5454229 | our_user | our_ip:52642 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5454230 | our_user | our_ip:52644 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5454231 | our_user | our_ip:52646 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5454232 | our_user | our_ip:52648 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5454233 | our_user | our_ip:52650 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5454234 | our_user | our_ip:52652 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5454235 | our_user | our_ip:52654 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5454236 | our_user | our_ip:52656 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5454237 | our_user | our_ip:52658 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5454238 | our_user | our_ip:52660 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5454239 | our_user | our_ip:52662 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5454240 | our_user | our_ip:52664 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5454241 | our_user | our_ip:52666 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5454242 | our_user | our_ip:52668 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5454243 | our_user | our_ip:52670 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5454244 | our_user | our_ip:52672 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5454245 | our_user | our_ip:52674 | our_database | Sleep   |    0 |                      | NULL                                                                                                 |    0.000 |
| 5454246 | our_user | our_ip:52676 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5454247 | our_user | our_ip:52678 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5454248 | our_user | our_ip:52680 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5454249 | our_user | our_ip:52682 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5454250 | our_user | our_ip:52684 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5454251 | our_user | our_ip:52686 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5454252 | our_user | our_ip:52688 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5454253 | our_user | our_ip:52690 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5454254 | our_user | our_ip:52692 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5454255 | our_user | our_ip:52694 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5454256 | our_user | our_ip:52696 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5454257 | our_user | our_ip:52698 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5454258 | our_user | our_ip:52700 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5454259 | our_user | our_ip:52704 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5454260 | our_user | our_ip:52706 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5454261 | our_user | our_ip:52708 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5454262 | our_user | our_ip:52710 | our_database | Query   |    0 | Copying to tmp table | SELECT DISTINCT ofMessageArchive.fromJID, ofMessageArchive.toJID, ofMessageArchive.sentDate, ofMessa |    0.000 |
| 5462031 | our_user | our_ip:52746 | our_database | Query   |    0 | init                 | show processlist                                                                                     |    0.000 |
+---------+----------------------+------------------+----------+---------+------+----------------------+-----------------------------

guus · February 8, 2019, 9:45am

MySQL seems to be having trouble calculating the response to the query sufficiently fast. The query is complex, so that might be an issue. Increasing the connection pool might actually make the problem worse, as it’ll cause the database to do more things at the same time.

To my knowledge, you’re the first one to report this issue. I wonder what makes your setup different from others. Do you have an exceptional amount of data in the database? Do you use custom clients, or a non-standard use case for using XEP-313? You mentioned them being ‘aggressive’?

Paolo_Manili · February 8, 2019, 10:14am

I see, well yes, I’ll try and fill in the details,
size wise our message archive table runs slightly short of 30K messages (the server is a 2 node galera maria db cluster).
Yes we are using custom clients, mobile clients running MatriX and web clients running Strophe.
We are using in conjuction XEP 146 and 313. We used to use only 146 in previous projects but the fact it didn’t retrieve full stanza or give exact Timestamps for the messages became an issue.
So we currently fetch the list of conversations for the received roster items and then fetch conversations that haven’t been fetched already through 313, the way the code was written, all collections to be fetched are sent off in asynchronous IQs, so it is realistic for about 30 contacts and a dozen chatrooms for around 50 XEP 146 requests to shoot out and at least the same XEP 313 for the last chatsession to be shot out together. I am planning on refactoring that section of code so as to limit the concurrent fetches. The web client works over promises with much the same approach I think.

guus · February 8, 2019, 10:29am

I can see how that would add load to the database, yes.

Although we might be able to optimize things a little, I think we’ll have to build in some kind of throttling in the monitoring plugin, to make sure that one client cannot drain the connection pool, if used in the way you’re using.

If you find that clients are often querying “everything”, instead of incremental history, it might be worth exploring if it’s possible to query all history in one query, instead of doing a lot of history with context X queries. To do this, you should make a request that does not have the with filter.

Paolo_Manili · February 8, 2019, 10:39am

The web client will certainly find itself loading everything (Especially with Hard refresh happy users, but you can’t help PEBKACs more than much.
For the mobile client, in theory we should only be loading the latest session for each roster item, but on first logins it might be advantageous to fire off a single request.
So you are saying that we could straight off fire a single XEP 313 request and get everything or from a given date? (Sometimes I cling to old approaches for what were very old bugs in the monitoring plugin (Such as when it ignored requests that had a start date for xep 146 some 4 years ago)
I’ll fire up Psi and have a look at the results, it’s an exciting prospect.
Thank you very much in the meantime (I’ll report my findings )

guus · February 8, 2019, 10:42am

I’ll be honest and admit that I don’t know if it will work for you, but logic dictates that “give me all LEGO bricks” should be easier to do than “give me all blue LEGO bricks”, “now, give me all yellow LEGO bricks”, “now, give me all white LEGO bricks”, “now, give me all red LEGO bricks”, “now, give me all green LEGO bricks” etc.

Also, if you run into implementation issues, please let us know!

Paolo_Manili · March 12, 2019, 9:47am

Ok, after testing Openfire Monitoring seems to handle massive single queries much better than smaller sets, meaning we can handle at least first synchronization of new devices with a single big MAM fetch.
I still have to figure out whether we can disregard the server defined conversation ids.
We used to determine whether we had downloaded a given block of messages using XEP 136 conversation ids.
Would you know of a recommended approach for determining archive completeness using only XEP-0313? I am thinking maybe I can use the provided messageId used in first / last and the total count in the mamfin element, but really not sure if it’s solid.
Thanks in advance