Bug #85910 Increased Performance_Schema overhead on Sending data
Submitted: 12 Apr 2017 3:00 Modified: 14 Apr 2017 6:02
Reporter: Jervin R Email Updates:
Status: Verified Impact on me:
None 
Category:MySQL Server: Performance Schema Severity:S3 (Non-critical)
Version:5.6.35, 5.6.36 OS:Any
Assigned to: Marc Alff CPU Architecture:Any

[12 Apr 2017 3:00] Jervin R
Description:
When working with large resultsets, i.e. reading millions of rows, performance_schema on 5.6 with default settings has significant overhead. See procedure below:

How to repeat:
mysql> create table ps (id int unsigned not null auto_increment primary key, a char(5) not null, key (a)) engine=innodb;
Query OK, 0 rows affected (0.01 sec)

mysql> insert into ps (a) values ('aaaaa');
Query OK, 1 row affected (0.00 sec)

mysql> insert into ps (a) select a from ps;
Query OK, 1 row affected (0.00 sec)
Records: 1  Duplicates: 0  Warnings: 0
...
mysql> insert into ps (a) select a from ps;
Query OK, 2097152 rows affected (20.23 sec)
Records: 2097152  Duplicates: 0  Warnings: 0

With PS disabled:

vagrant@trusty:~$ time mysql test -e 'select a from ps where id between 1 and 2000000' > /dev/null

real	0m1.015s
user	0m0.340s
sys	0m0.038s

With PS enabled:

vagrant@trusty:~$ time mysql test -e 'select a from ps where id between 1 and 2000000' > /dev/null

real	0m4.591s
user	0m0.272s
sys	0m0.040s

my.cnf:

innodb_buffer_pool_size = 6G
innodb_log_file_size = 2G
innodb_flush_log_at_trx_commit = 2
innodb_flush_neighbors = 0
innodb_flush_method = O_DIRECT
innodb_file_format = Barracuda
innodb_buffer_pool_instances = 1
#performance_schema = 0
[12 Apr 2017 4:03] Jervin R
vagrant@trusty:~$ mysql -e 'select version(), @@version_comment'
+-----------+------------------------------+
| version() | @@version_comment            |
+-----------+------------------------------+
| 5.6.36    | MySQL Community Server (GPL) |
+-----------+------------------------------+

PS ON

vagrant@trusty:~$ time mysql test -e 'select a from ps where id between 1 and 2000000' > /dev/null

real	0m4.718s
user	0m0.270s
sys	0m0.029s

PS OFF

vagrant@trusty:~$ time mysql test -e 'select a from ps where id between 1 and 2000000' > /dev/null

real	0m0.948s
user	0m0.350s
sys	0m0.021s

vagrant@trusty:~$ cat /etc/issue.net
Ubuntu 14.04.5 LTS

vagrant@trusty:~$ uname -a
Linux trusty 3.13.0-113-generic #160-Ubuntu SMP Thu Mar 9 09:27:29 UTC 2017 x86_64 x86_64 x86_64 GNU/Linux
[12 Apr 2017 5:35] Jervin R
Seems to be platform dependent, I tested on Xenial and performance is the same with PS on or off.

revin@acme:/data/msb/msb_5_6_36$ time ./use test -e 'select a from ps where id between 1 and 2000000' > /dev/null

real	0m0.887s
user	0m0.404s
sys	0m0.036s

revin@acme:/data/msb/msb_5_6_36$ uname -a
Linux acme 4.4.0-64-generic #85-Ubuntu SMP Mon Feb 20 11:50:30 UTC 2017 x86_64 x86_64 x86_64 GNU/Linux

revin@acme:/data/msb/msb_5_6_36$ cat /etc/issue.net
Ubuntu 16.04.2 LTS
revin@acme:/data/msb/msb_5_6_36$
[12 Apr 2017 15:15] Shane Bester
this is a known issue on 5.6. If you look deeper, I suppose poor mans profiler will show up with many my_timer_cycles or rdtsc in the stacks?  
5.7+ is better for this case.
[13 Apr 2017 8:50] Umesh Shastry
Hello Jervin R,

Thank you for the report.
Observed a very minor performance impact when p_s enabled and disabled.
Also, this overhead seems to be fixed in 5.7, after http://dev.mysql.com/worklog/task/?id=7802

Thanks,
Umesh
[13 Apr 2017 8:51] Umesh Shastry
test results

Attachment: 85910_5.6.36 (application/octet-stream, text), 3.84 KiB.

[14 Apr 2017 6:02] Jervin R
Umesh, thanks for the verification.

Shane, interesting - Indeed, that's what I am seeing from perf. Any particular reason why the tests on Ubuntu 14.04 varies widely against 16.04?