Slow Query only Once a Day

[ABGenc]

I have been having a problem for a while but it is very weird.

The following is a log from slow queries log. When almost everything seems fine, once a day, I experience this slow query. It happens when I click on "New Content" button and only after it has been a while since I last visited. When I click it second time it does not happen and new content displays very quickly.

I have checked my slow queries log and it seems only I am (index_author=2) expriencing this issue. (I dont know if it is related bu I have over 60.000 posts)

Any idea ?

# Time: 180512 10:14:32
# User@Host: myuser[myhost] @ localhost []  Id: 94473
# Query_time: 27.990759  Lock_time: 0.000026 Rows_sent: 235  Rows_examined: 55674
use myuser;
SET timestamp=1526109272;
/*IPS\Content\Search\Mysql\_Index::iPostedIn:239*/ SELECT index_item_index_id FROM `ips_core_search_index` AS `core_search_index` WHERE ( index_item_index_id IN(503445,503386,503377,97004,4462,182935,287014,4546,17764,503410,503399,26804,7873,6949,5820,4507,4498,4793,4767,27973,51089,495235,4618,299934,6574) ) AND index_author=2;

 

[RevengeFNF]

Run mysqltuner.pl and post here the result.

[ABGenc]

8 hours ago, RevengeFNF said:

Run mysqltuner.pl and post here the result.

Seems there are some major issues with variables ?

>>  MySQLTuner 1.7.9 - Major Hayden <major@mhtx.net>
 >>  Bug reports, feature requests, and downloads at http://mysqltuner.com/
 >>  Run with '--help' for additional options and output filtering

[--] Skipped version check for MySQLTuner script
[OK] Currently running supported MySQL version 5.6.39-log
[OK] Operating on 64-bit architecture

-------- Log file Recommendations ----------------------------------------------                  --------------------
[--] Log file: /var/lib/mysql/sg1.err(0B)
[!!] Log file /var/lib/mysql/sg1.err doesn't exist
[!!] Log file /var/lib/mysql/sg1.err isn't readable.

-------- Storage Engine Statistics ---------------------------------------------                  --------------------
[--] Status: +ARCHIVE +BLACKHOLE +CSV -FEDERATED +InnoDB +MEMORY +MRG_MYISAM +My                  ISAM +PERFORMANCE_SCHEMA
[--] Data in MyISAM tables: 509M (Tables: 198)
[--] Data in InnoDB tables: 2G (Tables: 401)
[OK] Total fragmented tables: 0

-------- Security Recommendations ----------------------------------------------                  --------------------
[OK] There are no anonymous accounts for any database users
[OK] All database users have passwords assigned
[!!] There is no basic password file list!

-------- CVE Security Recommendations ------------------------------------------                  --------------------
[--] Skipped due to --cvefile option undefined

-------- Performance Metrics ---------------------------------------------------                  --------------------
[--] Up for: 22h 59m 41s (3M q [39.264 qps], 195K conn, TX: 55G, RX: 1G)
[--] Reads / Writes: 83% / 17%
[--] Binary logging is disabled
[--] Physical Memory     : 2.0G
[--] Max MySQL memory    : 4.1G
[--] Other process memory: 1.6G
[--] Total buffers: 2.1G global + 33.0M per thread (60 max threads)
[--] P_S Max memory usage: 0B
[--] Galera GCache Max memory usage: 0B
[!!] Maximum reached memory usage: 2.6G (130.52% of installed RAM)
[!!] Maximum possible memory usage: 4.1G (203.03% of installed RAM)
[!!] Overall possible memory usage with other process exceeded memory
[OK] Slow queries: 0% (121/3M)
[OK] Highest usage of available connections: 25% (15/60)
[OK] Aborted connections: 0.01%  (11/195945)
[--] Skipped name resolution test due to skip_networking=ON in system variables.
[!!] Query cache may be disabled by default due to mutex contention.
[OK] Query cache efficiency: 53.5% (1M cached / 2M selects)
[!!] Query cache prunes per day: 831068
[OK] Sorts requiring temporary tables: 0% (32 temp sorts / 101K sorts)
[!!] Joins performed without indexes: 8969
[!!] Temporary tables created on disk: 53% (27K on disk / 50K total)
[OK] Thread cache hit rate: 99% (15 created / 195K connections)
[OK] Table cache hit rate: 99% (1K open / 1K opened)
[OK] Open file limit used: 6% (641/10K)
[OK] Table locks acquired immediately: 99% (1M immediate / 1M locks)

-------- Performance schema ----------------------------------------------------                  --------------------
[--] Performance schema is disabled.
[--] Memory used by P_S: 0B
[--] Sys schema isn't installed.

-------- ThreadPool Metrics ----------------------------------------------------                  --------------------
[--] ThreadPool stat is disabled.

-------- MyISAM Metrics --------------------------------------------------------                  --------------------
[!!] Key buffer used: 37.0% (3M used / 8M cache)
[!!] Key buffer size / total MyISAM indexes: 8.0M/175.6M
[!!] Read Key buffer hit rate: 86.6% (11K cached / 1K reads)
[!!] Write Key buffer hit rate: 0.0% (373 cached / 0 writes)

-------- InnoDB Metrics --------------------------------------------------------                  --------------------
[--] InnoDB is enabled.
[--] InnoDB Thread Concurrency: 16
[OK] InnoDB File per table is activated
[!!] InnoDB buffer pool / data size: 640.0M/2.2G
[!!] Ratio InnoDB log file size / InnoDB Buffer pool size (160 %): 512.0M * 2/64                  0.0M should be equal 25%
[!!] InnoDB buffer pool <= 1G and Innodb_buffer_pool_instances(!=1).
[--] InnoDB Buffer Pool Chunk Size not used or defined in your version
[OK] InnoDB Read buffer efficiency: 99.84% (187739872 hits/ 188034834 total)
[OK] InnoDB Write log efficiency: 96.22% (1336443 hits/ 1388956 total)
[OK] InnoDB log waits: 0.00% (0 waits / 52513 writes)

-------- AriaDB Metrics --------------------------------------------------------                  --------------------
[--] AriaDB is disabled.

-------- TokuDB Metrics --------------------------------------------------------                  --------------------
[--] TokuDB is disabled.

-------- XtraDB Metrics --------------------------------------------------------                  --------------------
[--] XtraDB is disabled.

-------- RocksDB Metrics -------------------------------------------------------                  --------------------
[--] RocksDB is disabled.

-------- Spider Metrics --------------------------------------------------------                  --------------------
[--] Spider is disabled.

-------- Connect Metrics -------------------------------------------------------                  --------------------
[--] Connect is disabled.

-------- Galera Metrics --------------------------------------------------------                  --------------------
[--] Galera is disabled.

-------- Replication Metrics ---------------------------------------------------                  --------------------
[--] Galera Synchronous replication: NO
[--] No replication slave(s) for this server.
[--] Binlog format: STATEMENT
[--] XA support enabled: ON
[--] Semi synchronous replication Master: Not Activated
[--] Semi synchronous replication Slave: Not Activated
[--] This is a standalone server

-------- Recommendations -------------------------------------------------------                  --------------------
General recommendations:
    MySQL started within last 24 hours - recommendations may be inaccurate
    Reduce your overall MySQL memory footprint for system stability
    Dedicate this server to your database for highest performance.
    Adjust your join queries to always utilize indexes
    Temporary table size is already large - reduce result set size
    Reduce your SELECT DISTINCT queries without LIMIT clauses
    Performance should be activated for better diagnostics
    Consider installing Sys schema from https://github.com/mysql/mysql-sys
    Read this before changing innodb_log_file_size and/or innodb_log_files_in_gr                  oup: http://bit.ly/2wgkDvS
Variables to adjust:
  *** MySQL's maximum memory usage is dangerously high ***
  *** Add RAM before increasing MySQL buffer variables ***
    query_cache_size (=0)
    query_cache_type (=0)
    query_cache_size (> 10M)
    join_buffer_size (> 256.0K, or always use indexes with joins)
    performance_schema = ON enable PFS
    key_buffer_size (> 175.6M)
    innodb_buffer_pool_size (>= 2G) if possible.
    innodb_log_file_size should be (=80M) if possible, so InnoDB total log files                   size equals to 25% of buffer pool size.
    innodb_buffer_pool_instances (=1)

 

[RevengeFNF]

You tables in InnoDB and MyIsam. Your IPS database is in which of them?

Yep, you have to adjust many variables there, but the most important one is that you only have 2 GB of Ram and you are allocating more than that just for Mysql, and your Operating System and all the other processes also need resources.

My personal opinion, can you get a server/vps with more Ram? At least 4Gb.

[ABGenc]

Just now, RevengeFNF said:

You tables in InnoDB and MyIsam. Your IPS database is in which of them?

Yep, you have to adjust many variables there, but the most important one is that you only have 2 GB of Ram and you are allocating more than that just for Mysql, and your Operating System and all the other processes also need resources.

My personal opinion, can you get a server/vps with more Ram? At least 4Gb.

All prod DBs are InnoDB . I have not converted test DBs to MyIsam. Thats the reason.

I have realised that there were per thread settings making the memory usage over the limit. Adjeusted them. Does any of the outcome of the script explain the bahaviour I have told above ?

[RevengeFNF]

6 minutes ago, ABGenc said:

All prod DBs are InnoDB . I have not converted test DBs to MyIsam. Thats the reason.

I have realised that there were per thread settings making the memory usage over the limit. Adjeusted them. Does any of the outcome of the script explain the bahaviour I have told above ?

Probably not, and you say that issue didn't occur with ips 4,2 correct? 
You also need to take into account the capabilities of your server. Optimizations per se can't do much if the server is not capable enough. 

[ABGenc]

1 minute ago, RevengeFNF said:

Probably not, and you say that issue didn't occur with ips 4,2 correct?

Nope that was the other problem related to locked tasks.

This problem is here for a while, probably since 4.1s . I did not get any complaints about it cause seems I am one of the limited group being affected. ( according to slow query logs ) and it is hard to diagnose cause happens once..

[bfarber]

Take the slow query and run it in mysql directly with EXPLAIN prefixed, and with query cache disabled.

EXPLAIN SELECT SQL_NO_CACHE index_item_index_id FROM `ips_core_search_index` AS `core_search_index` WHERE ( index_item_index_id IN(503445,503386,503377,97004,4462,182935,287014,4546,17764,503410,503399,26804,7873,6949,5820,4507,4498,4793,4767,27973,51089,495235,4618,299934,6574) ) AND index_author=2;

What is the output?

[ABGenc]

1 hour ago, bfarber said:

Take the slow query and run it in mysql directly with EXPLAIN prefixed, and with query cache disabled.

EXPLAIN SELECT SQL_NO_CACHE index_item_index_id FROM `ips_core_search_index` AS `core_search_index` WHERE ( index_item_index_id IN(503445,503386,503377,97004,4462,182935,287014,4546,17764,503410,503399,26804,7873,6949,5820,4507,4498,4793,4767,27973,51089,495235,4618,299934,6574) ) AND index_author=2;

What is the output?

 

id	select_type	table	type	possible_keys	key	key_len	ref	rows	Extra
1	SIMPLE	core_search_index	ref	author_lookup	author_lookup	4	const	76620	Using where

[bfarber]

Run this query (it may take a little while so be prepared):

ALTER TABLE core_search_index ADD INDEX author_posted_in (author_id, index_item_index_id);

Run the EXPLAIN query again and confirm that 'key' is now 'author_posted_in', and that 'rows' is no longer 76620. Then verify if it resolves the issue and let me know - assuming it does, we'll add the index to a future maintenance release.

[ABGenc]

3 hours ago, bfarber said:

Run this query (it may take a little while so be prepared):

ALTER TABLE core_search_index ADD INDEX author_posted_in (author_id, index_item_index_id);

Run the EXPLAIN query again and confirm that 'key' is now 'author_posted_in', and that 'rows' is no longer 76620. Then verify if it resolves the issue and let me know - assuming it does, we'll add the index to a future maintenance release.

It gives an error ;

#1072 - Key column 'author_id' doesn't exist in table

[bfarber]

Sorry, it's index_author

ALTER TABLE core_search_index ADD INDEX author_posted_in (index_author, index_item_index_id);

 

[ABGenc]

15 minutes ago, bfarber said:

Sorry, it's index_author

ALTER TABLE core_search_index ADD INDEX author_posted_in (index_author, index_item_index_id);

 

Thanks ? the new output is ;

can this index be also used in 4.2.7 ?

[bfarber]

Yes it can - that looks a lot better. I'll log a bug report internally to take a closer look at this, thanks.

[ABGenc]

10 hours ago, bfarber said:

Yes it can - that looks a lot better. I'll log a bug report internally to take a closer look at this, thanks.

I believe this also means if I have to recreate search index through ACP I will have to re add the index, right ?

[bfarber]

Nope - the only thing you may need to watch out for is when upgrading to a future release if we add this same index, then you may get an error because you already have it. You would be able to drop your copy and let the software create it again, or just ignore the error during that upgrade step.

Rebuilding the search index does not change the table structure, it just empties and repopulates the table.

[RevengeFNF]

54 minutes ago, bfarber said:

Nope - the only thing you may need to watch out for is when upgrading to a future release if we add this same index, then you may get an error because you already have it. You would be able to drop your copy and let the software create it again, or just ignore the error during that upgrade step.

Rebuilding the search index does not change the table structure, it just empties and repopulates the table.

Just because we are talking about performance. Since IPS 4.0 i noticed that it does many joins without indexes.

For example in my board in the last 5 days it did this amount:

Quote

[!!] Joins performed without indexes: 20072

Nothing that can be done? I don't even know if this would improve the performance, because the truth is that i never saw my site feeling faster like it is now with IPS 4.3.

[bfarber]

We spent a load of time working on performance with 4.3 (and I already have 3 or 4 performance branches lined up for 4.4 going through review processes), so I'm glad you are seeing it performing well.

Sometimes "joins without indexes" can be addressed, and sometimes not (or at least, you don't net a performance gain). I will review MySQL queries again in the not too distant future to see what other improvements are possible.

[RevengeFNF]

6 minutes ago, bfarber said:

We spent a load of time working on performance with 4.3 (and I already have 3 or 4 performance branches lined up for 4.4 going through review processes), so I'm glad you are seeing it performing well.

Sometimes "joins without indexes" can be addressed, and sometimes not (or at least, you don't net a performance gain). I will review MySQL queries again in the not too distant future to see what other improvements are possible.

Thank you for the explanation. What i can say is that the time you guys spent on performance reviews was not a waste because me and my users noticed it with IPS 4.3

[ASTRAPI]

Yes 4.3 performs much better :)

Thank you