Bug 1660112

(In reply to nyelle from comment #0)
> Description of problem:
> 
> [root@rhel8-nightly tools]# ./dbslower mysql -x $(which mysqld)
> Traceback (most recent call last):
>   File "./dbslower", line 72, in <module>
>     if mysql_func_name.find("COM_DATA") >= 0:
> TypeError: a bytes-like object is required, not 'str'
> 
> 
> Version-Release number of selected component (if applicable):
> 
> [root@rhel8-nightly ~]# rpm -q bcc bcc-tools
> bcc-0.7.0-5.el8.x86_64
> bcc-tools-0.7.0-5.el8.x86_64
> 
> 
> How reproducible:
> Veriy
> 
> Steps to Reproduce:
> 1. Install bcc-tools
> 2. start mysql 5.7 instance (same issue should occurs with 5.6)
> 3. Run ./dbslower mysql -x $(which mysqld)
> 

Hmm... That option need to be documented in the man page. It's also missing from dbslower_example.txt.

> Actual results:
> dbslower errors out
> 
> Expected results:
> dbslower starts running
> 
> Additional info:
> 
> I fixed this issue by casting "COM_DATA" string to byte object
> [root@rhel8-nightly tools]# diff ./dbslower ./dbslower-debug 
> 72c72
> <         if mysql_func_name.find("COM_DATA") >= 0:
> ---
> >         if mysql_func_name.find(b'COM_DATA') >= 0:
> 
> 
> I'm not sure if this is an issue with my python version or some other
> package in my environment. This server is running a nightly build from Dec
> 6ish plus the latest bcc/bcc-tools.

This is definitely a python2 to python3 bytes/string issue. Upstream need to be fixed too.

> 
> Mode then get's set and dbslower runs.
> 
> [root@rhel8-nightly tools]# ./dbslower-debug1 mysql -x $(which mysqld) -m0
> Mode: MYSQL57
> Tracing database queries for application /usr/sbin/mysqld slower than 0 ms...
> TIME(s)        PID          MS QUERY
> 21.704478      11576     0.148 b'select @@version_comment limit 1'
> 39.517898      11576     0.338 b'CREATE DATABASE test'
> 44.198380      11576     0.043 b'SELECT DATABASE()'
> 44.199555      11576     0.257 b'show databases'
> 44.199897      11576     0.098 b'show tables'
> 46.544536      11576    67.234 b"CREATE TABLE shop (\n    article INT(4)
> UNSIGNED ZEROFILL DEFAULT '0000' NOT NULL,\n    dealer  CHAR(20)            
> DEFAULT ''     NOT NULL,\n    price   DOUBLE(16,2)             DEFAULT
> '0.00' NOT NULL,\n    PRIMARY KEY(article, dealer))"
> 47.933111      11576     6.059 b"INSERT INTO shop VALUES\n   
> (1,'A',3.45),(1,'B',3.99),(2,'A',10.99),(3,'B',1.45),\n   
> (3,'C',1.69),(3,'D',1.25),(4,'D',19.95)"
> 62.887507      11576     0.140 b'SELECT * FROM shop ORDER BY article'

Thanks for the quick response. 

There's another issue with both dbstat and dbslower which I think is py2 v py3 related.

[root@rhel8-nightly tools]# ./dbstat postgres
Traceback (most recent call last):
  File "./dbstat", line 95, in <module>
    bpf = BPF(text=program, usdt_contexts=usdts)
  File "/usr/lib/python3.6/site-packages/bcc/__init__.py", line 303, in __init__
    ctx_array = (ct.c_void_p * len(usdt_contexts))()
TypeError: object of type 'map' has no len()

Return from map() on line 86 (dbstat) 192 (dbslower) needs to be cast as a list:

# diff ./dbstat ./dbstat-working
86c86
< usdts = map(lambda pid: USDT(pid=pid), args.pids)
---
> usdts = list(map(lambda pid: USDT(pid=pid), args.pids))



Small typo as that's unique to dbstat, default interval is too large

[root@rhel8-nightly tools]# ./dbstat-deb postgres
Tracing database queries for pids  slower than 0 ms...
Traceback (most recent call last):
  File "./dbstat-deb", line 111, in <module>
    sleep(args.interval)
OverflowError: timestamp too large to convert to C _PyTime_t


I'd suggest a smaller default interval like 1 or 2 sec. 
# diff ./dbstat ./dbstat-working
42c42
< parser.add_argument("-i", "--interval", type=int, default=99999999999,
---
> parser.add_argument("-i", "--interval", type=int, default=1,

(In reply to nyelle from comment #2)
> Thanks for the quick response. 
> 
> There's another issue with both dbstat and dbslower which I think is py2 v
> py3 related.
> 
> [root@rhel8-nightly tools]# ./dbstat postgres
> Traceback (most recent call last):
>   File "./dbstat", line 95, in <module>
>     bpf = BPF(text=program, usdt_contexts=usdts)
>   File "/usr/lib/python3.6/site-packages/bcc/__init__.py", line 303, in
> __init__
>     ctx_array = (ct.c_void_p * len(usdt_contexts))()
> TypeError: object of type 'map' has no len()
> 
> Return from map() on line 86 (dbstat) 192 (dbslower) needs to be cast as a
> list:
> 
> # diff ./dbstat ./dbstat-working
> 86c86
> < usdts = map(lambda pid: USDT(pid=pid), args.pids)
> ---
> > usdts = list(map(lambda pid: USDT(pid=pid), args.pids))
> 

I don't know about that specific py2/py3 issue, but that seems to work on python2 too.

> 
> 
> Small typo as that's unique to dbstat, default interval is too large
> 
> [root@rhel8-nightly tools]# ./dbstat-deb postgres
> Tracing database queries for pids  slower than 0 ms...
> Traceback (most recent call last):
>   File "./dbstat-deb", line 111, in <module>
>     sleep(args.interval)
> OverflowError: timestamp too large to convert to C _PyTime_t
> 
> 
> I'd suggest a smaller default interval like 1 or 2 sec. 
> # diff ./dbstat ./dbstat-working
> 42c42
> < parser.add_argument("-i", "--interval", type=int, default=99999999999,
> ---
> > parser.add_argument("-i", "--interval", type=int, default=1,

That's not a typo. This value is huge so that by default dbstat shows only one histogram for the entire run (that is until it's interrupted by ctrl-c).

Hi Jerome,

I think this failed my test on version bcc-tools-0.8.0-2.el8.x86_64. To be specific, there is another map issue like happening, similar to that of comment 2.

[root@dell-per720-01 ~]# /usr/share/bcc/tools/dbstat postgres
Traceback (most recent call last):
  File "/usr/share/bcc/tools/dbstat", line 95, in <module>
    bpf = BPF(text=program, usdt_contexts=usdts)
  File "/usr/lib/python3.6/site-packages/bcc/__init__.py", line 305, in __init__
    ctx_array = (ct.c_void_p * len(usdt_contexts))()
TypeError: object of type 'map' has no len()

And dbstat do not work with mysql

[root@dell-per720-01 ~]# pidof mysqld
3945
[root@dell-per720-01 ~]# /usr/share/bcc/tools/dbstat mysql -p $(pidof mysqld) 
Traceback (most recent call last):
  File "/usr/share/bcc/tools/dbstat", line 88, in <module>
    usdt.enable_probe("query__start", "probe_start")
  File "/usr/lib/python3.6/site-packages/bcc/usdt.py", line 154, in enable_probe
    probe
bcc.usdt.USDTException: failed to enable probe 'query__start'; a possible cause can be that the probe requires a pid to enable

... although dbslower works with mysql

[root@dell-per720-01 ~]# /usr/share/bcc/tools/dbslower mysql -x $(which mysqld)
Tracing database queries for application /usr/sbin/mysqld slower than 1 ms...
TIME(s)        PID          MS QUERY
^C

Can you take a look at this?

(In reply to Ziqian SUN (Zamir) from comment #7)
> Hi Jerome,
> 
> I think this failed my test on version bcc-tools-0.8.0-2.el8.x86_64. To be
> specific, there is another map issue like happening, similar to that of
> comment 2.

Hmm. Those issue mentioned in comment 2 fell through the cracks. We probably should have open an other bz for them.

> 
> [root@dell-per720-01 ~]# /usr/share/bcc/tools/dbstat postgres
> Traceback (most recent call last):
>   File "/usr/share/bcc/tools/dbstat", line 95, in <module>
>     bpf = BPF(text=program, usdt_contexts=usdts)
>   File "/usr/lib/python3.6/site-packages/bcc/__init__.py", line 305, in
> __init__
>     ctx_array = (ct.c_void_p * len(usdt_contexts))()
> TypeError: object of type 'map' has no len()
> 
> And dbstat do not work with mysql
> 
> [root@dell-per720-01 ~]# pidof mysqld
> 3945
> [root@dell-per720-01 ~]# /usr/share/bcc/tools/dbstat mysql -p $(pidof
> mysqld) 
> Traceback (most recent call last):
>   File "/usr/share/bcc/tools/dbstat", line 88, in <module>
>     usdt.enable_probe("query__start", "probe_start")
>   File "/usr/lib/python3.6/site-packages/bcc/usdt.py", line 154, in
> enable_probe
>     probe
> bcc.usdt.USDTException: failed to enable probe 'query__start'; a possible
> cause can be that the probe requires a pid to enable
> 
> ... although dbslower works with mysql
> 
> [root@dell-per720-01 ~]# /usr/share/bcc/tools/dbslower mysql -x $(which
> mysqld)
> Tracing database queries for application /usr/sbin/mysqld slower than 1 ms...
> TIME(s)        PID          MS QUERY
> ^C
> 
> Can you take a look at this?

Based on comment 8, moving back to ON_QA. The issue mentioned in comment 7 is now tracing by the cloned bug 1719522.

Hi Nick,

Can you help check if dbslower for mysql works for your or not with bcc-tools-0.8.0-2.el8.x86_64? I don't have knowledge about making slow mysql actions.

Please note, I did find some problems (mentioned in comment 7) which is now tracking by the cloned bug.

Thanks.

Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://access.redhat.com/errata/RHBA-2019:3327