Bug 358391 - Multiple Ctrl+C doesn't abort yum
Multiple Ctrl+C doesn't abort yum
Product: Fedora
Classification: Fedora
Component: yum (Show other bugs)
All Linux
medium Severity medium
: ---
: ---
Assigned To: James Antill
Fedora Extras Quality Assurance
Depends On:
  Show dependency treegraph
Reported: 2007-10-30 11:18 EDT by Eduardo Habkost
Modified: 2014-01-21 17:59 EST (History)
5 users (show)

See Also:
Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of:
Last Closed: 2008-01-17 09:15:07 EST
Type: ---
Regression: ---
Mount Type: ---
Documentation: ---
Verified Versions:
Category: ---
oVirt Team: ---
RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---

Attachments (Terms of Use)
Log of quickly-hitting-ctrl+c session (10.33 KB, text/plain)
2007-10-30 11:38 EDT, Eduardo Habkost
no flags Details

  None (edit)
Description Eduardo Habkost 2007-10-30 11:18:11 EDT
This is a problem detected while testing bug #230252. From comments there:

Yum version:

-- Additional comment from skvidal@linux.duke.edu on 2007-10-30 10:45 EST --
press ctrl-c twice in a row during a single download.

It should abort.
sometimes it takes 3 ctrl-c's. They're timed and ctrl-c once skipping mirrors 
a feature.

-- Additional comment from ehabkost@redhat.com on 2007-10-30 11:12 EST --
I have tried the multiple ctrl+c feature anyway, and it didn't work. I kept 
hitting ctrl+c during the download around 4 times per second. yum tried every 
single mirror and took 1 minute and 30 seconds (I was hitting quickly ctrl+c 
during all this time) until it finally aborted with "No more mirrors to try".

Additional info:
Just in case: I am running yum on a ssh terminal.
Comment 1 Seth Vidal 2007-10-30 11:20:23 EDT
I can make it abort on ctrl-c during pkg download every time.

Here is what I'm running:
rpm -q yum rpm python

all from rawhide. Is that the same for you?
Comment 2 Eduardo Habkost 2007-10-30 11:28:48 EDT
The same here:

# rpm -q yum rpm python
Comment 3 Eduardo Habkost 2007-10-30 11:38:35 EDT
Created attachment 243611 [details]
Log of quickly-hitting-ctrl+c session

Log of the full session where I kept hitting ctrl+c quickly. Maybe it won't be
useful, but maybe the error information shown by yum can be useful to find the
Comment 4 Eduardo Habkost 2007-10-30 11:45:35 EDT
Additional info:

# rpm -q python-urlgrabber
Comment 5 Seth Vidal 2007-10-30 11:46:58 EDT
are you pressing ctrl-c once per mirror-switch or more than once?

I'm testing the exact same thing and I can get it to terminate each time.
Comment 6 Seth Vidal 2007-10-30 11:47:20 EDT
same ver of python-urlgrabber here.

Comment 7 Eduardo Habkost 2007-10-30 11:58:27 EDT
(In reply to comment #5)
> are you pressing ctrl-c once per mirror-switch or more than once?

I am hitting Ctrl+C as quickly as I can (probably almost 10 times a second). I 
have tested pressing and holding ctrl+C, also.

What yum shows on the error message when Ctrl+C is pressed, for you? By 
looking at the code, it should be 'user interrupt'. For me, 'user interrupt' 
is never shown and "interrupt system call" is shown on most cases, that 
probably means that interrupt_callback() is not being called.

> I'm testing the exact same thing and I can get it to terminate each time.

That's weird.
Comment 8 Eduardo Habkost 2007-10-30 12:11:25 EDT
I have changed urlgrabber grabber.py to print exception info. What I get when 
I press Ctrl+C is:

Trying other mirror.
(1/1): kernel-devel-2.6.2  22% |=====                    | 1.1 MB    00:01 ETA 
Traceback (most recent call last):
  File "/usr/lib/python2.5/site-packages/urlgrabber/grabber.py", line 1259, in 
    new = self.fo.read(readamount)
  File "/usr/lib/python2.5/site-packages/urlgrabber/keepalive.py", line 404, 
in read
    s = self._rbuf + self._raw_read(amt)
  File "/usr/lib64/python2.5/httplib.py", line 529, in read
    s = self.fp.read(amt)
  File "/usr/lib64/python2.5/socket.py", line 309, in read
    data = self._sock.recv(recv_size)
error: (4, 'Interrupted system call')

This is strange. When I use urllib from a python console and interrupt read, I 
get KeyboardInterrupt as expected:

>> f = 
>>> f.read()
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
  File "/usr/lib64/python2.5/socket.py", line 291, in read
    data = self._sock.recv(recv_size)
  File "/usr/lib64/python2.5/httplib.py", line 529, in read
    s = self.fp.read(amt)
  File "/usr/lib64/python2.5/socket.py", line 309, in read
    data = self._sock.recv(recv_size)

Maybe some library is using the SIGINT handler, making Python not catch 
SIGINT, hence not raising KeyboardInterrupt.
Comment 9 Seth Vidal 2007-10-30 12:17:46 EDT
yes - in the past it was rpm that was grabbing sigint - that's what we're
handling now inside rpm and inside yum.
Comment 10 Eduardo Habkost 2007-10-30 13:34:54 EDT
Got it under gdb. Ctrl+C pressed during package download:

(gdb) bt 10
#0  0x00002aaab03aa0b0 in rpmsqAction () from /usr/lib64/librpmio-4.4.so
#1  <signal handler called>
#2  0x00000033412cbd2f in poll () from /lib64/libc.so.6
#3  0x00002aaab0ea6129 in ?? () 
from /usr/lib64/python2.5/lib-dynload/_socketmodule.so
#4  0x00002aaab0ea6c50 in ?? () 
from /usr/lib64/python2.5/lib-dynload/_socketmodule.so
#5  0x00002aaab0ea6e3e in ?? () 
from /usr/lib64/python2.5/lib-dynload/_socketmodule.so
#6  0x00002aaaaab73b79 in PyEval_EvalFrameEx () 
from /usr/lib64/libpython2.5.so.1.0
#7  0x00002aaaaab74862 in PyEval_EvalCodeEx () 
from /usr/lib64/libpython2.5.so.1.0

# rpm -qf  /usr/lib64/librpmio-4.4.so
Comment 11 Eduardo Habkost 2007-10-30 14:04:40 EDT
This is really weird:

If, and only if, I press ctrl+C multiple times, quickly (more than once a 
second), yum keeps trying mirrors until there is no more mirrors to try.

If I press ctrl+C a few times and then stop, yum shows "Trying other mirror" 
after the error, freeze for a few seconds, and eventually it exits (sometimes 
after trying one or two additional mirrors).

The worse is that the last message it shows before exiting is "Trying other 
mirror". I have no idea if this is the expected behavior (and what you see on 
your tests) or not. If this is the expected behavior, a message saying that it 
is exiting because it was interrupted would be useful.

Anyway, pressing Ctrl+C _more often_ makes yum not exit instead of exiting. 
This is definitely a bug.
Comment 12 Panu Matilainen 2007-10-31 02:24:04 EDT
Rpm still grabs ctrl-c (it has to, BDB can't be terminated from signal handler),
it just now exports an interface to poll for caught signals. Yum polls for
caught termination interrupts from the download progress updating. Running yum
with debuglevel 1 or 0 disables the progress meter -> no signal polling is done
-> yum is unterminable.

Looking at the log from comment 3, that doesn't seem to be the case here though.
Comment 13 Pierre Ossman 2007-11-16 15:37:10 EST
I find this particularly annoying as well. Whoever solves it will be my personal
hero for the week. :)
Comment 14 James Antill 2007-11-20 23:07:41 EST
 Ok, so I'd seen this but couldn't easily reproduce it. But I think I've found
the "problem", I'd put the following debug statements into interrupt_callback
(just after the now = time.time() line:

        print "JDBG: now=", now,
        if hasattr(self, '_last_interrupt'):
            print "JDBG: last=", self._last_interrupt, "diff=", now -
            print "JDBG: last=<none>"

...and again it mostly just worked, but here's what I got when I happened to
have "tracker" running today:

JDBG: now= 1195611137.55 JDBG: last=<none>
primary.sqlite.bz2        100% |=========================| 360 kB    00:03     
JDBG: now= 1195611142.61 JDBG: last= 1195611137.55 diff= 5.05578398705
primary.sqlite.bz2        100% |=========================|  72 kB    00:01     
JDBG: now= 1195611145.4 JDBG: last= 1195611142.61 diff= 2.7927479744
JDBG: now= 1195611145.6 JDBG: last= 1195611145.4 diff= 0.201518058777
JDBG: now= 1195611146.17 JDBG: last= 1195611145.6 diff= 0.568984031677
JDBG: now= 1195611146.44 JDBG: last= 1195611146.17 diff= 0.272680997849
JDBG: now= 1195611146.8 JDBG: last= 1195611146.44 diff= 0.356623888016
JDBG: now= 1195611147.34 JDBG: last= 1195611146.8 diff= 0.542190074921
JDBG: now= 1195611147.73 JDBG: last= 1195611147.34 diff= 0.384391069412
JDBG: now= 1195611148.84 JDBG: last= 1195611147.73 diff= 1.11596083641
JDBG: now= 1195611149.61 JDBG: last= 1195611148.84 diff= 0.764620065689
JDBG: now= 1195611150.09 JDBG: last= 1195611149.61 diff= 0.48238992691
JDBG: now= 1195611150.47 JDBG: last= 1195611150.09 diff= 0.379456043243
JDBG: now= 1195611151.19 JDBG: last= 1195611150.47 diff= 0.724066972733
JDBG: now= 1195611153.58 JDBG: last= 1195611151.19 diff= 2.38611412048
JDBG: now= 1195611153.94 JDBG: last= 1195611153.58 diff= 0.357396841049
JDBG: now= 1195611154.28 JDBG: last= 1195611153.94 diff= 0.344292163849
JDBG: now= 1195611154.69 JDBG: last= 1195611154.28 diff= 0.404276847839
JDBG: now= 1195611155.69 JDBG: last= 1195611154.69 diff= 1.00381207466
JDBG: now= 1195611156.36 JDBG: last= 1195611155.69 diff= 0.674350976944
JDBG: now= 1195611157.09 JDBG: last= 1195611156.36 diff= 0.721087932587
JDBG: now= 1195611157.44 JDBG: last= 1195611157.09 diff= 0.351754188538
JDBG: now= 1195611157.45 JDBG: last= 1195611157.44 diff= 0.0167148113251

...now for significant parts of the above I was hitting C-c as fast as possible
and/or holding C-c down. So I think we can fix this easily by upping the timeout
a little.

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