Slow list-virtual.php after upgrade to 3.0.x about postfixadmin HOT 11 CLOSED

7000 mysqli_query() calls indeed sounds extremely strange. I never counted them, but this number is much bigger than what I'd expect.

I wonder if mysqli_real_escape string counts towards mysqli_query() - your graph shows 2400 escape_string() calls for list-virtual.

Do you have $CONF['show_status'] enabled? Its implementation does quite some queries. Yes, it can probably be optimized, but I'm afraid I have more important things on my TODO list :-(

I also wonder if introducing a cache array in escape_string() would improve the speed. Can you please try if this proof-of-concept patch improves the performance?

--- a/functions.inc.php
+++ b/functions.inc.php
@@ -292,6 +300,14 @@ function escape_string ($string) {
         }
         return $clean;
     }
+
+    static $escape_string_cache = array();
+    if (isset($escape_string_cache[$string])) {
+        # error_log("escape_string IS cached: $string");
+        return $escape_string_cache[$string];
+    }
+    # error_log("escape_string NOT cached: $string");
+
     if (get_magic_quotes_gpc ()) {
         $string = stripslashes($string);
     }
@@ -317,6 +333,8 @@ function escape_string ($string) {
     } else {
         $escaped_string = $string;
     }
+
+    $escape_string_cache[$string] = $escaped_string;
     return $escaped_string;
 }
 

With this patch applied, I see 330 cached and only 50 not cached escape_string() calls in my small test setup (30 domains with 100 mailboxes and 300 aliases, so you should see even bigger effects).

If you really want to know all details, enable query logging in MySQL or let db_query() in functions.inc.php log all queries.

from postfixadmin.

You have delays in interesting[tm] places - at least some of them use queries that should be "cheap". For example, 6s between 2.2 and 2.3 (which basically means getting a list of all AliasDomains) sounds too long. (This doesn't mean it can't be optimized ;-)

Knowing the size of your complete setup might help - how many domains, aliases and mailboxes do you have in total? How many of your domains are setup as alias domains?

Can you enable the MySQL slow query log and check if a specific query causes the delays? (If everything else fails, change db_query() to log all queries with timestamp and duration.)

Do you have $CONF['show_status'] enabled? If yes, disable it for testing.

Just to clarify - did I get it right that your MySQL is not on the server hosting PostfixAdmin? If so, how good/fast is the connection between the two servers? How long does SELECT COUNT(*) FROM mailbox ; need when run from the webserver?

from postfixadmin.

It is weird. Setup size:

+-----------------------+------------+
| TABLE_NAME            | TABLE_ROWS |
+-----------------------+------------+
| admin                 |          6 |
| alias                 |        293 |
| alias_domain          |         14 |
| config                |          1 |
| domain                |         42 |
| domain_admins         |          7 |
| fetchmail             |          0 |
| log                   |        756 |
| mailbox               |        163 |
| quota                 |          0 |
| quota2                |          0 |
| transport             |         16 |
| vacation              |          7 |
| vacation_notification |          0 |
+-----------------------+------------+

Slow queries logging didn't show anything.

$CONF['show_status'] is disabled.

Yes, webserver is placed in CZ datahouse, Mailserver is placed in DE datahouse. But the connection is pretty fast.
Mailbox count query is done within miliseconds:

+----------+
| COUNT(*) |
+----------+
|      163 |
+----------+

real	0m0.063s
user	0m0.010s
sys	0m0.000s

After digging deeper within the code of PFAHandler.php (attached with debugging to syslog()
PFAHandler.php.debug.zip) it shows:

Feb 17 10:46:03 [PFA] PFA: Begining of read_from_db()
Feb 17 10:46:03 [PFA] PFA: Begining of build_select_query()
Feb 17 10:46:03 [PFA] PFA: End of DB format decision
Feb 17 10:46:03 [PFA] PFA: End of building colformat array
Feb 17 10:46:03 [PFA] PFA: End of get list of fields to display
Feb 17 10:46:03 [PFA] PFA: End of cosl join
Feb 17 10:46:03 [PFA] PFA: End of table_by_key()
Feb 17 10:46:07 [PFA] PFA: End of building additional_where 1/2
Feb 17 10:46:07 [PFA] PFA: End of building additional_where 2/2
Feb 17 10:46:07 [PFA] PFA: Before return from build_select_query()
Feb 17 10:46:07 [PFA] PFA: End of build_select_query()
Feb 17 10:46:07 [PFA] PFA: Start of DB query
Feb 17 10:46:07 [PFA] PFA: End of DB query
Feb 17 10:46:07 [PFA] PFA: End of result processing
Feb 17 10:46:07 [PFA] PFA: End of result postprocessing

that the problem is somewhere in db_in_clause() function (which is a simple implode, right?). After commenting out this condition, page loading got to 20s, so there has to be another problem somewhere else. Any thoughts?

from postfixadmin.

Your setup is pretty small - one of my servers has about 3 times your numbers (1000 aliases and 450 mailboxes on 300 domains) and list-virtual loads instantly. And even that is small - a while ago, we had a bugreport which IIRC mentioned 10000 mailboxes ;-)

You are right that db_in_clause() is basically a simple implode(), but it's not that simple - it calls escape_string(), and that calls mysqli_real_escape_string() for each item in the array. I have no idea how mysqli_real_escape_string() works internally, but it expects $link as parameter. If each call needs a roundtrip to the database server, doing it for 42 domains could already explain the delay.

An interesting test would be to use a local database. Even if counting the mailboxes was fast (you did this from the webserver, right?) - if you can copy the database to the web server without too much effort, it would be worth a test.

BTW: does the page load faster (or at least db_in_clause() run faster) if you log in as a domain admin who has only permissions for one or two domains?

Even if it's unlikely - what does free -m say on both servers? PostfixAdmin 3.0 uses more complex queries than 2.3.x, so it would be interesting how full your 4 and 8 GB of RAM are.

And yes, there must be more bottlenecks - but let's first find out what happens here before searching for them ;-)

from postfixadmin.

Yes, it is small. Thank you for pointing that out 👍

It took 3s to load list-virtual.php with DB on localhost.

Yes, page is loaded in 10s under an admin user with permissions for 4 domains.

WEBserver - 3GB of 8GB used
MAILserver - 1GB of 4GB used

• plenty of computing power and not more than 25% overall CPU used within a work week.

from postfixadmin.

Hey, I'd like to say this is something that I am dealing with as well.

This isn't something I'd classify as a big instance,

mysql> select count(*) from alias;
+----------+
| count(*) |
+----------+
|     2072 |
+----------+
1 row in set (0.00 sec)

mysql> select count(*) from mailbox;
+----------+
| count(*) |
+----------+
|     1051 |
+----------+
1 row in set (0.00 sec)

mysql> select count(*) from domain;
+----------+
| count(*) |
+----------+
|      344 |
+----------+
1 row in set (0.00 sec)

Here are some xdebug pictures, to understand with the timings in milliseconds.

list-virtual.php:

(Why do you need to do nearly 7000 mysqli_query commands?)

list.php?table=domain

DB is in Amazon. Takes 0.00 seconds to count rows.

from postfixadmin.

Perhaps it would be a good idea to pass a database connection into escape_string() so it doesn't need to keep reopening one/calling db_connect().
i.e.

function escape_string($string, $db = null) {
    if($db === null) { $db = db_connect() ... } 
        // .. as normal.
}```

from postfixadmin.

Caching made it usable again, at least for me. Page load decreased to 1-2s. Thanks!

from postfixadmin.

c253ef7 should fix it too...

from postfixadmin.

@DavidGoodwin Thanks alot! I've confirmed this fixes my issue and results in a 2-3 second page load across all functionality.

You can probably close the issue now.

from postfixadmin.

I've merged #41 today which does the connection caching directly in db_connect() - and reverted most of c253ef7 - having the connection cache at one place is enough ;-)

This also means I consider this issue finally fixed in a clean way, and therefore close it.

from postfixadmin.