This is a problem detected while testing bug #230252. From comments there: Yum version: yum-3.2.7-1.fc8 -- Additional comment from skvidal.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 is a feature. -- Additional comment from ehabkost 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.
I can make it abort on ctrl-c during pkg download every time. Here is what I'm running: rpm -q yum rpm python yum-3.2.7-1.fc8 rpm-4.4.2.2-3.fc8 python-2.5.1-14.fc8 all from rawhide. Is that the same for you?
The same here: # rpm -q yum rpm python yum-3.2.7-1.fc8 rpm-4.4.2.2-3.fc8 python-2.5.1-14.fc8
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 problem.
Additional info: # rpm -q python-urlgrabber python-urlgrabber-3.0.0-3.fc8
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.
same ver of python-urlgrabber here.
(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.
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 _fill_buffer 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 = opener.open('http://download.fedora.redhat.com/pub/fedora/linux/development/x86_64/os/Packages/CGAL-devel-3.3.1-2.fc8.i386.rpm') >>> 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) KeyboardInterrupt Maybe some library is using the SIGINT handler, making Python not catch SIGINT, hence not raising KeyboardInterrupt.
yes - in the past it was rpm that was grabbing sigint - that's what we're handling now inside rpm and inside yum.
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 rpm-libs-4.4.2.2-3.fc8
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.
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. Hmm...
I find this particularly annoying as well. Whoever solves it will be my personal hero for the week. :)
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 - self._last_interrupt else: 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.