Bug 1660112 - dbslower in mysql uprobe mode fails with "TypeError: a bytes-like object is required, not 'str'"
Summary: dbslower in mysql uprobe mode fails with "TypeError: a bytes-like object is r...
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Red Hat Enterprise Linux 8
Classification: Red Hat
Component: bcc
Version: 8.0
Hardware: x86_64
OS: Linux
unspecified
low
Target Milestone: rc
: 8.0
Assignee: Jerome Marchand
QA Contact: Ziqian SUN (Zamir)
URL:
Whiteboard:
Depends On: 1680631
Blocks: 1719522 1696304
TreeView+ depends on / blocked
 
Reported: 2018-12-17 14:16 UTC by nyelle@redhat.com
Modified: 2019-11-05 20:42 UTC (History)
6 users (show)

Fixed In Version: bcc-0.8.0-1.el8
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
: 1719522 (view as bug list)
Environment:
Last Closed: 2019-11-05 20:42:19 UTC
Type: Bug
Target Upstream Version:


Attachments (Terms of Use)


Links
System ID Priority Status Summary Last Updated
Red Hat Product Errata RHBA-2019:3327 None None None 2019-11-05 20:42:32 UTC

Description nyelle@redhat.com 2018-12-17 14:16:56 UTC
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)

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.

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'

Comment 1 Jerome Marchand 2018-12-17 15:38:55 UTC
(In reply to nyelle@redhat.com 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'

Comment 2 nyelle@redhat.com 2018-12-17 16:17:40 UTC
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,

Comment 3 Jerome Marchand 2018-12-17 16:35:20 UTC
(In reply to nyelle@redhat.com 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).

Comment 7 Ziqian SUN (Zamir) 2019-06-03 07:17:03 UTC
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?

Comment 8 Jerome Marchand 2019-06-11 17:13:29 UTC
(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?

Comment 9 Ziqian SUN (Zamir) 2019-06-12 02:04:41 UTC
Based on comment 8, moving back to ON_QA. The issue mentioned in comment 7 is now tracing by the cloned bug 1719522.

Comment 10 Ziqian SUN (Zamir) 2019-06-12 02:08:33 UTC
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.

Comment 14 errata-xmlrpc 2019-11-05 20:42:19 UTC
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


Note You need to log in before you can comment on or make changes to this bug.