Bug 863387

Summary: [abrt] cups-1.5.4-2.fc17: _dbus_abort: Process /usr/lib/cups/notifier/dbus was killed by signal 6 (SIGABRT)
Product: [Fedora] Fedora Reporter: Nikolay Logvinov <NLogvinov>
Component: cupsAssignee: Tim Waugh <twaugh>
Status: CLOSED CURRENTRELEASE QA Contact: Fedora Extras Quality Assurance <extras-qa>
Severity: unspecified Docs Contact:
Priority: unspecified    
Version: 17CC: jpopelka, twaugh
Target Milestone: ---Keywords: Reopened
Target Release: ---   
Hardware: i686   
OS: Unspecified   
Whiteboard: abrt_hash:d658bd0a882cbcac575516b83c9d7a9f973c8153
Fixed In Version: cups-1.5.4-10.fc17 Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2012-11-19 02:22:18 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: core_backtrace
none
File: environ
none
File: limits
none
File: backtrace
none
File: cgroup
none
File: maps
none
File: dso_list
none
File: var_log_messages
none
File: open_fds none

Description Nikolay Logvinov 2012-10-05 10:17:46 UTC
Version-Release number of selected component:
cups-1.5.4-2.fc17

Additional info:
libreport version: 2.0.14
abrt_version:   2.0.13
backtrace_rating: 4
cmdline:        /usr/lib/cups/notifier/dbus dbus:// ''
crash_function: _dbus_abort
kernel:         3.5.4-2.fc17.i686.PAE

truncated backtrace:
:Thread no. 1 (3 frames)
: #3 _dbus_abort at dbus-sysdeps.c:94
: #4 _dbus_warn_check_failed at dbus-internals.c:289
: #5 dbus_message_iter_append_basic at dbus-message.c:2514

Comment 1 Nikolay Logvinov 2012-10-05 10:17:49 UTC
Created attachment 622077 [details]
File: core_backtrace

Comment 2 Nikolay Logvinov 2012-10-05 10:17:51 UTC
Created attachment 622078 [details]
File: environ

Comment 3 Nikolay Logvinov 2012-10-05 10:17:53 UTC
Created attachment 622079 [details]
File: limits

Comment 4 Nikolay Logvinov 2012-10-05 10:17:55 UTC
Created attachment 622080 [details]
File: backtrace

Comment 5 Nikolay Logvinov 2012-10-05 10:17:57 UTC
Created attachment 622081 [details]
File: cgroup

Comment 6 Nikolay Logvinov 2012-10-05 10:17:59 UTC
Created attachment 622082 [details]
File: maps

Comment 7 Nikolay Logvinov 2012-10-05 10:18:01 UTC
Created attachment 622083 [details]
File: dso_list

Comment 8 Nikolay Logvinov 2012-10-05 10:18:03 UTC
Created attachment 622084 [details]
File: var_log_messages

Comment 9 Nikolay Logvinov 2012-10-05 10:18:05 UTC
Created attachment 622085 [details]
File: open_fds

Comment 10 Tim Waugh 2012-10-19 08:54:05 UTC
DBus requires string arguments to be valid UTF-8, but the CUPS dbus notifier doesn't validate them (my fault).  The particular attribute that triggered this was job-name.

Are you able to check in the log files in /var/log/cups/ to see what job ID was being operated on at this exact time (2012-10-05 14:11:33)?

Something like this (as root) ought to show the relevant lines:

grep 05/Oct/2012:14:1 /var/log/cups/*

Comment 11 Nikolay Logvinov 2012-10-19 09:41:36 UTC
Yes, you are right. Job name was in IBM-866 codepage.
error_log-20121007:D [05/Oct/2012:14:11:33 +0400] [Job 152] Sending job to queue tagged as raw...
error_log-20121007:D [05/Oct/2012:14:11:33 +0400] [Job 152] job-sheets=none,none
error_log-20121007:D [05/Oct/2012:14:11:33 +0400] [Job 152] argv[0]="tubatch"
error_log-20121007:D [05/Oct/2012:14:11:33 +0400] [Job 152] argv[1]="152"
error_log-20121007:D [05/Oct/2012:14:11:33 +0400] [Job 152] argv[2]="nl"
error_log-20121007:D [05/Oct/2012:14:11:33 +0400] [Job 152] argv[3]="�⥦��� ����祭�� � �����ﬨ"
error_log-20121007:D [05/Oct/2012:14:11:33 +0400] [Job 152] argv[4]="1"
error_log-20121007:D [05/Oct/2012:14:11:33 +0400] [Job 152] argv[5]="finishings=3 jobsheets=none number-up=1 PRINTER_TeX=pdf_ps job-uuid=urn:uuid:fee2592e-6207-3469-5d75-1f834e24ad16 job-originating-host-name=localhost time-at-creation=1349431893 time-at-processing=1349431893"
error_log-20121007:D [05/Oct/2012:14:11:33 +0400] [Job 152] argv[6]="/var/spool/cups/d00152-001"
error_log-20121007:D [05/Oct/2012:14:11:33 +0400] [Job 152] envp[0]="CUPS_CACHEDIR=/var/cache/cups"
error_log-20121007:D [05/Oct/2012:14:11:33 +0400] [Job 152] envp[1]="CUPS_DATADIR=/usr/share/cups"
error_log-20121007:D [05/Oct/2012:14:11:33 +0400] [Job 152] envp[2]="CUPS_DOCROOT=/usr/share/cups/www"
error_log-20121007:D [05/Oct/2012:14:11:33 +0400] [Job 152] envp[3]="CUPS_FONTPATH=/usr/share/cups/fonts"
error_log-20121007:D [05/Oct/2012:14:11:33 +0400] [Job 152] envp[4]="CUPS_REQUESTROOT=/var/spool/cups"
error_log-20121007:D [05/Oct/2012:14:11:33 +0400] [Job 152] envp[5]="CUPS_SERVERBIN=/usr/lib/cups"
error_log-20121007:D [05/Oct/2012:14:11:33 +0400] [Job 152] envp[6]="CUPS_SERVERROOT=/etc/cups"
error_log-20121007:D [05/Oct/2012:14:11:33 +0400] [Job 152] envp[7]="CUPS_STATEDIR=/var/run/cups"
error_log-20121007:D [05/Oct/2012:14:11:33 +0400] [Job 152] envp[8]="HOME=/var/spool/cups/tmp"
error_log-20121007:D [05/Oct/2012:14:11:33 +0400] [Job 152] envp[9]="PATH=/usr/lib/cups/filter:/usr/bin:/usr/sbin:/bin:/usr/bin"
error_log-20121007:D [05/Oct/2012:14:11:33 +0400] [Job 152] envp[10]="SERVER_ADMIN=root.rpb.ru"
error_log-20121007:D [05/Oct/2012:14:11:33 +0400] [Job 152] envp[11]="SOFTWARE=CUPS/1.5.4"
error_log-20121007:D [05/Oct/2012:14:11:33 +0400] [Job 152] envp[12]="TMPDIR=/var/spool/cups/tmp"
error_log-20121007:D [05/Oct/2012:14:11:33 +0400] [Job 152] envp[13]="USER=root"
error_log-20121007:D [05/Oct/2012:14:11:33 +0400] [Job 152] envp[14]="CUPS_MAX_MESSAGE=2047"
error_log-20121007:D [05/Oct/2012:14:11:33 +0400] [Job 152] envp[15]="CUPS_SERVER=/var/run/cups/cups.sock"
error_log-20121007:D [05/Oct/2012:14:11:33 +0400] [Job 152] envp[16]="CUPS_ENCRYPTION=IfRequested"
error_log-20121007:D [05/Oct/2012:14:11:33 +0400] [Job 152] envp[17]="IPP_PORT=631"
error_log-20121007:D [05/Oct/2012:14:11:33 +0400] [Job 152] envp[18]="CHARSET=utf-8"
error_log-20121007:D [05/Oct/2012:14:11:33 +0400] [Job 152] envp[19]="LANG=ru_RU.UTF-8"
error_log-20121007:D [05/Oct/2012:14:11:33 +0400] [Job 152] envp[20]="PPD=/etc/cups/ppd/tubatch.ppd"
error_log-20121007:D [05/Oct/2012:14:11:33 +0400] [Job 152] envp[21]="RIP_MAX_CACHE=128m"
error_log-20121007:D [05/Oct/2012:14:11:33 +0400] [Job 152] envp[22]="CONTENT_TYPE=application/vnd.cups-raw"
error_log-20121007:D [05/Oct/2012:14:11:33 +0400] [Job 152] envp[23]="DEVICE_URI=ubatch:/usr/local/bzr/fstream/fstream/bin/ubatcher FSDIR=/usr/local/bzr/fstream/fstream USE_MICO=1 MICORC=/usr/local/etc/micorc LANG=ru_RU.CP866"
error_log-20121007:D [05/Oct/2012:14:11:33 +0400] [Job 152] envp[24]="PRINTER_INFO=tubatch"
error_log-20121007:D [05/Oct/2012:14:11:33 +0400] [Job 152] envp[25]="PRINTER_LOCATION="
error_log-20121007:D [05/Oct/2012:14:11:33 +0400] [Job 152] envp[26]="PRINTER=tubatch"
error_log-20121007:D [05/Oct/2012:14:11:33 +0400] [Job 152] envp[27]="PRINTER_STATE_REASONS=none"
error_log-20121007:D [05/Oct/2012:14:11:33 +0400] [Job 152] envp[28]="CUPS_FILETYPE=document"
error_log-20121007:D [05/Oct/2012:14:11:33 +0400] [Job 152] envp[29]="AUTH_I****"
error_log-20121007:I [05/Oct/2012:14:11:33 +0400] [Job 152] Started backend /usr/lib/cups/backend/uba

Comment 12 Tim Waugh 2012-10-19 11:14:06 UTC
Thanks.  Reported upstream.  I think the scheduler ought to make sure that the attributes are UTF-8 from the time they are set.

Comment 13 Tim Waugh 2012-10-31 12:20:31 UTC
Meanwhile, I've modified the dbus notifier so that it replaces bad UTF-8 characters with '?'.

Comment 14 Fedora Update System 2012-10-31 13:02:08 UTC
cups-1.5.4-12.fc18 has been submitted as an update for Fedora 18.
https://admin.fedoraproject.org/updates/FEDORA-2012-15936/cups-1.5.4-12.fc18

Comment 15 Fedora Update System 2012-10-31 13:07:44 UTC
cups-1.5.4-10.fc17 has been submitted as an update for Fedora 17.
https://admin.fedoraproject.org/updates/FEDORA-2012-14508/cups-1.5.4-10.fc17

Comment 16 Fedora Update System 2012-10-31 18:08:49 UTC
Package cups-1.5.4-13.fc18:
* should fix your issue,
* was pushed to the Fedora 18 testing repository,
* should be available at your local mirror within two days.
Update it with:
# su -c 'yum update --enablerepo=updates-testing cups-1.5.4-13.fc18'
as soon as you are able to.
Please go to the following url:
https://admin.fedoraproject.org/updates/FEDORA-2012-15936/cups-1.5.4-13.fc18
then log in and leave karma (feedback).

Comment 17 Fedora Update System 2012-11-19 02:22:19 UTC
cups-1.5.4-11.fc17 has been pushed to the Fedora 17 stable repository.  If problems still persist, please make note of it in this bug report.

Comment 18 Fedora Update System 2012-11-23 07:13:11 UTC
cups-1.5.4-14.fc18 has been pushed to the Fedora 18 stable repository.  If problems still persist, please make note of it in this bug report.