Bug 1516678

Summary: [abrt] bcc-tools: print_event(): ext4slower:313:print_event:UnicodeDecodeError: 'utf-8' codec can't decode byte 0xd0 in position 31: unexpected end of data
Product: [Fedora] Fedora Reporter: kartochka378
Component: bccAssignee: Jerome Marchand <jmarchan>
Status: CLOSED ERRATA QA Contact: Fedora Extras Quality Assurance <extras-qa>
Severity: unspecified Docs Contact:
Priority: unspecified    
Version: 27CC: jolsa, kartochka378, rdossant, skozina
Target Milestone: ---   
Target Release: ---   
Hardware: x86_64   
OS: Unspecified   
URL: https://retrace.fedoraproject.org/faf/reports/bthash/63eb9828be3d72b49cb3897e5e9eda8582a08276
Whiteboard: abrt_hash:36e90be04820f0b821eccfc8184f2e70415c69f3;VARIANT_ID=workstation;
Fixed In Version: bcc-0.7.0-3.fc29 bcc-0.7.0-3.fc28 Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2018-11-03 00:00:51 UTC Type: ---
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Attachments:
Description Flags
File: backtrace
none
File: cgroup
none
File: cpuinfo
none
File: environ
none
File: mountinfo
none
File: namespaces
none
File: open_fds none

Description kartochka378 2017-11-23 09:19:02 UTC
Description of problem:
Run /usr/share/bcc/tools/ext4slower 1 in gnome terminal, open nautilus. It seems to be related with russian letters in some file names in home dir.

Version-Release number of selected component:
bcc-tools-0.4.0-1.fc27

Additional info:
reporter:       libreport-2.9.3
cmdline:        /usr/bin/python3 /usr/share/bcc/tools/ext4slower 1
crash_function: print_event
exception_type: UnicodeDecodeError
executable:     /usr/share/bcc/tools/ext4slower
kernel:         4.13.15-300.fc27.x86_64
runlevel:       N 5
type:           Python3
uid:            0

Truncated backtrace:
ext4slower:313:print_event:UnicodeDecodeError: 'utf-8' codec can't decode byte 0xd0 in position 31: unexpected end of data

Traceback (most recent call last):
  File "_ctypes/callbacks.c", line 234, in 'calling callback function'
  File "/usr/lib/python3.6/site-packages/bcc/table.py", line 526, in <lambda>
    fn = _RAW_CB_TYPE(lambda _, data, size: callback(cpu, data, size))
  File "/usr/share/bcc/tools/ext4slower", line 313, in print_event
    float(event.delta_us) / 1000, event.file.decode()))
UnicodeDecodeError: 'utf-8' codec can't decode byte 0xd0 in position 31: unexpected end of data

Local variables in innermost frame:
type: 'R'
event: <__main__.Data object at 0x7f11a50f2598>
size: 100
data: 139713759059340
cpu: 3

Comment 1 kartochka378 2017-11-23 09:19:09 UTC
Created attachment 1358079 [details]
File: backtrace

Comment 2 kartochka378 2017-11-23 09:19:10 UTC
Created attachment 1358080 [details]
File: cgroup

Comment 3 kartochka378 2017-11-23 09:19:12 UTC
Created attachment 1358081 [details]
File: cpuinfo

Comment 4 kartochka378 2017-11-23 09:19:14 UTC
Created attachment 1358082 [details]
File: environ

Comment 5 kartochka378 2017-11-23 09:19:16 UTC
Created attachment 1358083 [details]
File: mountinfo

Comment 6 kartochka378 2017-11-23 09:19:17 UTC
Created attachment 1358084 [details]
File: namespaces

Comment 7 kartochka378 2017-11-23 09:19:19 UTC
Created attachment 1358085 [details]
File: open_fds

Comment 8 Rafael Fonseca 2017-11-23 09:27:53 UTC
Thank you for the report.

Would you mind giving some examples of Russian letters so that I can try to reproduce the issue?

Comment 9 kartochka378 2017-11-23 16:48:21 UTC
No idea. Beside, need to reboot every time to reproduce it, as it stop crashing after nautilus started once. But after full reboot it crash 100%.

I did not want to share all my homedir file names, still i hope copy of terminal output will be useful

[root@localhost ~]# /usr/share/bcc/tools/ext4slower 1
Tracing ext4 operations slower than 1 ms
TIME     COMM           PID    T BYTES   OFF_KB   LAT(ms) FILENAME
19:37:01 pool           1755   R 4072    0          12.09 org.gnome.Nautilus-symbolic.svg
19:37:01 nautilus       2927   R 340     0           4.52 document-open-recent-symbolic.sy
19:37:01 nautilus       2927   R 257     0           3.54 user-home-symbolic.symbolic.png
19:37:01 nautilus       2927   R 161     0           6.15 folder-documents-symbolic.symbol
19:37:01 nautilus       2927   R 280     0           7.07 drive-harddisk-symbolic.symbolic
19:37:01 nautilus       2927   R 149     0          29.69 go-previous-symbolic.symbolic.pn
19:37:02 dconf-service  2185   S 0       0          46.75 user.UAW79Y
19:37:02 nautilus       2927   R 153     0          24.40 go-next-symbolic.symbolic.png
19:37:02 nautilus       2927   R 104     0           2.35 open-menu-symbolic.symbolic.png
19:37:02 nautilus       2927   R 894     0           2.83 org.gnome.Nautilus.png
19:37:02 nautilus       2927   R 672     0           6.79 org.gnome.Nautilus.png
19:37:02 nautilus       2927   R 922     0           5.15 org.gnome.Nautilus.png
19:37:02 nautilus       2927   R 1284    0           2.34 org.gnome.Nautilus.png
19:37:02 nautilus       2927   R 353     0          14.06 user-trash-full-symbolic.symboli
19:37:02 dconf-service  2185   S 0       0          91.16 user.01T59Y
19:37:02 nautilus       2927   R 154     0           9.50 view-list-symbolic.symbolic.png
19:37:02 dconf-service  2185   S 0       0          33.01 user.CP529Y
19:37:02 pool           2927   R 18      0          13.97 .bash_logout
19:37:02 pool           2927   R 4096    0           6.90 steam
19:37:02 pool           2927   R 5       0          11.73 steam.pid
19:37:02 pool           2927   R 1210    0           6.96 .wxMaxima
19:37:02 pool           2927   R 2011    0           6.10 .nvidia-settings-rc
19:37:02 pool           2927   R 256     0           2.77 .pulse-cookie
19:37:02 pool           2927   R 4096    0           1.80 .freeciv-client-rc-2.5
19:37:02 pool           2927   R 55      0           4.88 .gitconfig
19:37:02 pool           2927   R 221     0           5.23 .lesshst
19:37:02 pool           2927   R 473     0           4.43 .python_history
19:37:02 pool           2927   R 4096    0           4.87 TargetIPS234_1.cal
19:37:02 pool           2927   R 4096    0          14.64 lede-17.01.1-ar71xx-generic-tl-w
19:37:02 pool           2927   R 4096    0           7.25 lede-wr740n-v5.bin
19:37:02 pool           2927   R 4096    0           8.38 matlib_cycles_tests2_firefly_nod
19:37:02 pool           2927   R 4096    0           9.26 mlt_hole1_mcmc.blend1
19:37:02 pool           2927   R 4096    0           6.77 mlt_hole1_mcmc_bands.blend1
19:37:02 pool           2927   R 4096    0           6.71 my_18.SciFiction_bidir_example_v
19:37:02 pool           2927   R 4096    0           5.99 my_CornelTest_bidir_bug.blend1
19:37:02 pool           2927   R 4096    0          14.40 my_CornelTest_vol_new_kelemen.bl
19:37:02 pool           2927   R 4096    0          24.55 my_Kitchen(Cycles)Updated_black.
19:37:02 nautilus       2927   R 8192    0          29.61 process-working-symbolic.svg
19:37:02 pool           2927   R 4096    0          30.57 my_Maxwell Room_cekuhnen.blend1
19:37:02 pool           2927   R 4096    0           7.07 my_Pot scene_a_Fatesailor_cycles
19:37:02 pool           2927   R 4096    0           6.50 my_RenderEngineComparison_exampl
19:37:02 pool           2927   R 4096    0          11.67 my_Staircase_blenderjunky_MIS_tr
19:37:02 pool           2927   R 4096    0          10.80 my_color_test_mira.blend1
19:37:02 pool           2927   R 4096    0           6.07 my_cornell-box-cycles.blend1
19:37:02 pool           2927   R 4096    0           7.14 my_psorcube Cycles_egg_mcmc_exam
19:37:02 pool           2927   R 4096    0          10.36 my_sponza_benchmark_new.blend1
19:37:02 pool           2927   R 4096    0           3.23 my_sponza_cycles_benchmark.blend
19:37:02 pool           2927   R 4096    0          14.62 my_theCabin_vol.blend1
19:37:02 pool           2927   R 4096    0           9.93 my_vol_bidir_issue.blend1
19:37:02 pool           2927   R 4096    0          10.51 mycamaleon_skin_bidir_mcmc_bug.b
19:37:02 pool           2927   R 4096    0           5.34 mydragon_anim_new_bug.blend1
19:37:02 pool           2927   R 4096    0          13.92 myglass_milk_balls_new_curve.ble
19:37:02 pool           2927   R 4096    0           8.14 myglass_milk_balls_orange.blend1
19:37:02 pool           2927   R 4096    0           9.10 myglass_milk_balls_white.blend1
19:37:02 pool           2927   R 4096    0           6.80 ring_tst_banding.blend1
19:37:02 pool           2927   R 4096    0           6.80 ru
19:37:02 pool           2927   R 4096    0           4.51 vol1_modern.blend1
19:37:02 pool           2927   R 4096    0           3.84 vol7_err_bidir_point.blend1
19:37:02 pool           2927   R 4096    0           2.38 vol7_err_bidir_point_smooth_mirr
19:37:02 pool           2927   R 4096    0          13.56 vol_street_1_bidir_mcmc_qmc.blen
19:37:02 pool           2927   R 4096    0           7.77 wr740nv5_ru_3_14_0_up_boot(16011
Traceback (most recent call last):
  File "_ctypes/callbacks.c", line 234, in 'calling callback function'
  File "/usr/lib/python3.6/site-packages/bcc/table.py", line 526, in <lambda>
    fn = _RAW_CB_TYPE(lambda _, data, size: callback(cpu, data, size))
  File "/usr/share/bcc/tools/ext4slower", line 313, in print_event
    float(event.delta_us) / 1000, event.file.decode()))
UnicodeDecodeError: 'utf-8' codec can't decode byte 0xd0 in position 31: unexpected end of data
19:37:02 pool           2927   R 4096    0          26.32 .viminfo
19:37:02 abrtd          2938   R 128     0          11.58 abrt-server
19:37:02 abrt-server    2938   W 31      0          10.42 last-via-server
19:37:02 ext4slower     2923   R 115     0          28.42 __init__.cpython-36.pyc
19:37:02 ext4slower     2923   R 20396   0          10.69 uuid.cpython-36.pyc
19:37:02 ext4slower     2923   R 7228    0           4.73 util.cpython-36.pyc
19:37:02 ext4slower     2923   R 832     0           1.97 _journal.cpython-36m-x86_64-linu
19:37:02 ext4slower     2923   R 4096    0           3.83 abrt_exception_handler3.py
19:37:02 ext4slower     2923   R 4096    0           6.38 table.py
19:37:02 ext4slower     2923   R 8192    12          1.34 table.py
19:37:02 nautilus       2927   R 15900   0           4.11 folder.png
19:37:02 nautilus       2927   R 17790   0           3.69 folder-documents.png
19:37:02 nautilus       2927   R 65536   0           3.11 video-x-generic.png
19:37:02 nautilus       2927   R 38899   0           9.99 text-x-generic.png
19:37:02 nautilus       2927   R 50534   0           1.18 image-x-generic.png
19:37:02 abrt-server    2939   R 128     0          46.96 abrt-handle-event
19:37:02 nautilus       2927   R 59728   0          16.44 audio-x-generic.png
19:37:02 abrt-handle-ev 2939   R 2408    0          25.61 report_event.conf
19:37:02 nautilus       2927   R 1751    0           5.37 emblem-readonly.png
19:37:02 abrt-handle-ev 2939   R 592     0          23.98 abrt_dbus_event.conf
19:37:02 abrt-handle-ev 2939   R 4096    0          10.64 ccpp_event.conf
19:37:02 abrt-handle-ev 2939   R 813     0           5.55 collect_dnf.conf
19:37:03 sh             2940   R 128     0           4.19 abrt-action-save-package-data
19:37:03 abrt-action-sa 2940   R 887     0           6.12 abrt-action-save-package-data.co
19:37:03 abrt-action-sa 2940   R 887     0           7.30 abrt-action-save-package-data.co
19:37:03 abrt-action-sa 2940   R 31      0           5.47 gpg_keys.conf
19:37:03 abrt-action-sa 2940   R 1670    0           2.90 RPM-GPG-KEY-fedora-26-primary
19:37:03 abrt-action-sa 2940   R 1704    0           7.59 RPM-GPG-KEY-rpmfusion-nonfree-fe
19:37:03 abrt-action-sa 2940   R 1700    0           3.98 RPM-GPG-KEY-rpmfusion-free-fedor
19:37:03 abrt-action-sa 2940   R 2380    0           4.46 RPM-GPG-KEY-fedora-10-primary
19:37:03 abrt-action-sa 2940   R 512     0          11.18 Basenames
19:37:03 abrt-handle-ev 2939   R 1       0           4.63 uid
19:37:03 abrt-handle-ev 2939   R 1       0           5.20 uid
19:37:03 abrt-handle-ev 2939   R 31      0           9.11 executable
19:37:03 sh             2942   R 128     0          10.21 dbus-send
19:37:03 sh             2944   R 128     0           6.06 abrt-action-notify
19:37:03 abrt-action-no 2944   R 11703   0           7.21 __init__.cpython-36.pyc
19:37:03 abrt-action-no 2944   R 5773    0           5.87 __init__.cpython-36.pyc
19:37:03 abrt-action-no 2944   R 832     0           9.43 _py3report.so
19:37:03 abrt-action-no 2944   R 441     0           6.87 GTKIO.cpython-36.pyc
19:37:03 abrt-action-no 2944   R 22      0           4.98 package
19:37:03 sh             2945   R 128     0           9.77 reporter-systemd-journal
19:37:03 reporter-syste 2945   R 129     0           8.34 namespaces
19:37:03 reporter-syste 2945   R 147     0           6.78 comment
19:37:03 reporter-syste 2945   R 596     0           7.75 os_info
19:37:03 reporter-syste 2945   R 4096    0           5.11 mountinfo
19:37:03 systemd-journa 586    S 0       0         459.86 system.journal
19:37:03 systemd-journa 586    S 0       0         460.02 user-1000.journal
19:37:03 systemd-journa 586    S 0       0          32.38 user-1000.journal
19:37:03 systemd-journa 586    S 0       0          32.57 system.journal
19:37:06 firefox        2616   R 832     0           8.83 libmozavutil.so
19:37:06 firefox        2616   R 832     0           5.70 libmozavcodec.so
19:37:32 systemd-journa 586    S 0       0          27.28 system.journal

Comment 10 Rafael Fonseca 2017-11-26 23:11:26 UTC
Reported upstream for now [1] while I'm also investigating the issue.

[1] https://github.com/iovisor/bcc/issues/1459

Comment 11 Rafael Fonseca 2018-10-09 14:39:11 UTC
A solution has been proposed [1]. I'll integrate the fix as soon as the fix is merged.

[1] https://github.com/iovisor/bcc/pull/2004

Comment 12 Fedora Update System 2018-10-22 11:19:53 UTC
bcc-0.7.0-3.fc29 has been submitted as an update to Fedora 29. https://bodhi.fedoraproject.org/updates/FEDORA-2018-e02f9f4072

Comment 13 Fedora Update System 2018-10-22 11:34:17 UTC
bcc-0.7.0-3.fc28 has been submitted as an update to Fedora 28. https://bodhi.fedoraproject.org/updates/FEDORA-2018-c725b64c41

Comment 14 Fedora Update System 2018-10-22 19:24:05 UTC
bcc-0.7.0-3.fc29 has been pushed to the Fedora 29 testing repository. If problems still persist, please make note of it in this bug report.
See https://fedoraproject.org/wiki/QA:Updates_Testing for
instructions on how to install test updates.
You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2018-e02f9f4072

Comment 15 Fedora Update System 2018-10-22 23:54:39 UTC
bcc-0.7.0-3.fc28 has been pushed to the Fedora 28 testing repository. If problems still persist, please make note of it in this bug report.
See https://fedoraproject.org/wiki/QA:Updates_Testing for
instructions on how to install test updates.
You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2018-c725b64c41

Comment 16 Fedora Update System 2018-11-03 00:00:51 UTC
bcc-0.7.0-3.fc29 has been pushed to the Fedora 29 stable repository. If problems still persist, please make note of it in this bug report.

Comment 17 Fedora Update System 2018-11-03 01:47:07 UTC
bcc-0.7.0-3.fc28 has been pushed to the Fedora 28 stable repository. If problems still persist, please make note of it in this bug report.