Bug 584991

Created attachment 408441 [details]
File: backtrace

I was not able to reproduce the crash.
Are you able to reproduce it again ?

Yes but not always, problem seems to occur about 8 out of 10 times. abrt reports an error (notification icon appears), but does not generate a new traceback. This is within a print job involving 14 batches of 30 copies each and I have done testing by resetting after every send to printer.

The problem never occurs when changing number of printed copies from 1 to 30, but only appears when pressing "reset" and then either "apply" or "okay". I have not tried rolling number back down from 30 to 1 (and my print job is done so I won't have the opportunity to test that).

At times, the problem appears at authentication time (the Authentication window opens but does not complete, stays grey), then Authentication, Printer Properties, and Printer Configuration windows all close with abrt notification. Other times Authentication window does not appear at all (there is a timeout for this? which has not been reached?), but other two windows close with abrt notification. Yet other times, number of copy change appears to work okay in Printer Properties window and I can close that window okay, but then abrt notification occurs when I close Printer Configuration window.

Let's try running it under valgrind.  Please run this from a terminal window:

valgrind --log-file=valgrind.txt python \
  /usr/share/system-config-printer/system-config-printer.py

(Warning -- it will be slow!)

Please attach the valgrind.txt file even if you can't get it to crash in the same way.

(I've tried running it under valgrind here and don't see anything unusual...)

Created attachment 408676 [details]
generated under valgrind

Ran under valgrind 3 times: changed number of copies from 1 to 30, clicked "ok", then re-opened Printer Properties window, clicked "reset" then "ok". Then closed Printer Configuration window. No crashes. Each time, content/length of valgrind.txt was different.

Because three valgrind.txt files were different and no crash, and because crashes occurred when resetting copies back to 1 from 30, I ran Printer Configuration the usual way (from control panel) to change number of copies from 1 to 30. Then I ran Printer Configuration again but under valgrind to reset copies from 30 to 1. Got request for authorization both times, with no crash. Valgrind.txt file attached is output from this last run.

I have renamed output files from each of the earlier runs and can supply them if required.

OK, so this is quite noisy because some parts of Python always seem to generate warnings with valgrind.  But there are some interesting bits, which I found by searching for 'cups.so'.  Here is one:

==10425== Invalid write of size 1
==10425==    at 0xAFDC3C: _IO_default_xsputn (in /lib/libc-2.11.1.so)
==10425==    by 0xAD02ED: vfprintf (in /lib/libc-2.11.1.so)
==10425==    by 0xB82AC6: __vsprintf_chk (in /lib/libc-2.11.1.so)
==10425==    by 0xB82A0C: __sprintf_chk (in /lib/libc-2.11.1.so)
==10425==    by 0x580D0CF: ??? (in /usr/lib/python2.6/site-packages/cups.so)
==10425==    by 0x7DE8089: PyCFunction_Call (in /usr/lib/libpython2.6.so.1.0)
==10425==    by 0x7DA780C: PyObject_Call (in /usr/lib/libpython2.6.so.1.0)
==10425==    by 0x7E42FF7: PyEval_EvalFrameEx (in /usr/lib/libpython2.6.so.1.0)
==10425==    by 0x7E45EE9: PyEval_EvalCodeEx (in /usr/lib/libpython2.6.so.1.0)
==10425==    by 0x7DD4387: ??? (in /usr/lib/libpython2.6.so.1.0)
==10425==    by 0x7DA780C: PyObject_Call (in /usr/lib/libpython2.6.so.1.0)
==10425==    by 0x7E42FF7: PyEval_EvalFrameEx (in /usr/lib/libpython2.6.so.1.0)
==10425==  Address 0x75be753 is 0 bytes after a block of size 11 alloc'd
==10425==    at 0x4005BDC: malloc (vg_replace_malloc.c:195)
==10425==    by 0x580D091: ??? (in /usr/lib/python2.6/site-packages/cups.so)
==10425==    by 0x7DE8089: PyCFunction_Call (in /usr/lib/libpython2.6.so.1.0)
==10425==    by 0x7DA780C: PyObject_Call (in /usr/lib/libpython2.6.so.1.0)
==10425==    by 0x7E42FF7: PyEval_EvalFrameEx (in /usr/lib/libpython2.6.so.1.0)
==10425==    by 0x7E45EE9: PyEval_EvalCodeEx (in /usr/lib/libpython2.6.so.1.0)
==10425==    by 0x7DD4387: ??? (in /usr/lib/libpython2.6.so.1.0)
==10425==    by 0x7DA780C: PyObject_Call (in /usr/lib/libpython2.6.so.1.0)
==10425==    by 0x7E42FF7: PyEval_EvalFrameEx (in /usr/lib/libpython2.6.so.1.0)
==10425==    by 0x7E45EE9: PyEval_EvalCodeEx (in /usr/lib/libpython2.6.so.1.0)
==10425==    by 0x7DD4387: ??? (in /usr/lib/libpython2.6.so.1.0)
==10425==    by 0x7DA780C: PyObject_Call (in /usr/lib/libpython2.6.so.1.0)

Unfortunately you didn't have system-config-printer-debuginfo installed, or else valgrind decided not to find any symbols for cups.so, so we just have this:

==10425==    at 0xAFDC3C: _IO_default_xsputn (in /lib/libc-2.11.1.so)
==10425==    by 0xAD02ED: vfprintf (in /lib/libc-2.11.1.so)
==10425==    by 0xB82AC6: __vsprintf_chk (in /lib/libc-2.11.1.so)
==10425==    by 0xB82A0C: __sprintf_chk (in /lib/libc-2.11.1.so)
==10425==    by 0x580D0CF: ??? (in /usr/lib/python2.6/site-packages/cups.so)

But luckily there are only two places in pycups that use sprintf, and I found a bug in one of them. :-)

The bug was like this:

const char *const suffix = "-default";
...
optionlen = strlen (option);
p = malloc (optionlen + sizeof (suffix) + 1);
memcpy (p, option, optionlen);
sprintf (p + optionlen, suffix);

Here, suffix should have been declared like this:

const char const suffix[] = "-default";

i.e. an automatic array, where sizeof(suffix) tells us the string length.  As it was declared as a pointer, sizeof() just tells us the size of a pointer.  Coincidentally, the string length (8) is the same as the pointer size on the architecture I'm using here (x86_64), so it wasn't possible for me to reproduce the error.  You're using a 32-bit platform though, so our malloc size is 4 bytes too short.

I've built a system-config-printer package incorporating this fix.  Could you please give it a go?  Fetch all the packages for your architecture and then run:

yum update --nogpgcheck system-config-printer*1.1.19-2.fc12*

http://koji.fedoraproject.org/koji/buildinfo?buildID=174174

*ping*

Setting this to modified in the absence of other feedback.

Hi Tim. Sorry for the delay, work keep getting in the way.

I tried the update but get this message:
--snip--
No Match for argument: system-config-printer*1.1.19-2.fc12*
No package system-config-printer*1.1.19-2.fc12* available.
No Packages marked for Update
--snip--

I'm not sure where the problem is but here's my procedure:

Download all i686 packages from
http://koji.fedoraproject.org/koji/buildinfo?buildID=174174
into empty directory, go into that directory and run
yum --nogpgcheck localupdate *.rpm

Thanks for holding my hand Jiri.

updated system-config-printer from 1.1.18-2.fc12 to 1.1.19-2.fc12 and now cannot make it crash after ten to twelve tries.

system-config-printer-1.1.19-3.fc12 has been submitted as an update for Fedora 12.
http://admin.fedoraproject.org/updates/system-config-printer-1.1.19-3.fc12

system-config-printer-1.1.19-3.fc12 has been pushed to the Fedora 12 testing repository.  If problems still persist, please make note of it in this bug report.
 If you want to test the update, you can install it with 
 su -c 'yum --enablerepo=updates-testing update system-config-printer'.  You can provide feedback for this update here: http://admin.fedoraproject.org/updates/system-config-printer-1.1.19-3.fc12

system-config-printer-1.1.19-3.fc12 has been pushed to the Fedora 12 stable repository.  If problems still persist, please make note of it in this bug report.