Bug 1058297

Created attachment 856051 [details]
File: anaconda-tb

Created attachment 856052 [details]
File: anaconda.log

Created attachment 856053 [details]
File: environ

Created attachment 856054 [details]
File: lsblk_output

Created attachment 856055 [details]
File: nmcli_dev_list

Created attachment 856056 [details]
File: os_info

Created attachment 856057 [details]
File: program.log

Created attachment 856058 [details]
File: storage.log

Created attachment 856059 [details]
File: syslog

Created attachment 856060 [details]
File: ifcfg.log

Created attachment 856061 [details]
File: packaging.log

Exception appears to be happening in yum

 What does:

SystemError: error return without exception set

...mean? And while anaconda is pretty special, this bit of code is run pretty much all the time. I'd also guess it's impossible for yum to traceback at the line given, for any problem ... almost like the lowest part of the traceback is missing?
 I mean this line:

    l_csum = self._checksum(r_ctype, file, datasize=size)

...just calls a function with 3 args. as long as the function name is correct and the dito. the arg. names, it just can't fail.

*** Bug 1061664 has been marked as a duplicate of this bug. ***

(In reply to James Antill from comment #14)
>  What does:
> 
> SystemError: error return without exception set
> 
> ...mean?

Usually it means that a C-function called from Python isn't setting an error correctly, but the code that checks for this condition isn't specific to the C bindings. If it isn't a problem in functions being called by the yum checksum code, maybe there was a problem in the compiled yumRepo.pyc on the install media?

(In reply to David Shea from comment #16)
> If it isn't a problem in functions being called by the yum
> checksum code, maybe there was a problem in the compiled yumRepo.pyc on the
> install media?

That guess is as good to me as anything else ... which is to say I've no idea how it could happen or what could cause it. Going to NaB it on the yum side.

Created attachment 873363 [details]
anaconda-tb

I saw this issue on RHEL-7.0-20140311.n.0 with anaconda 19.31.66-1.

Please don't close this bug as notabug, this is bug and it should be investigated. Please change component if you think that it's not yum issue.

Reassigning to python as this appears to be an error caused by Python itself.

- Can anyone provide a working reproducer? I can't reproduce this bug.
- I have to admit I'm a bit confused about the line "threading.Thread.run(self, *args, **kwargs)" - how is this supposed to work? "threading.Thread.run" only takes "self" as an argument AFAICS. Does anaconda change this in some way?

The exception in question comes from this safety-check within the core bytecode evaluation loop, in Python/ceval.c:

  2838          /* Double-check exception status */
  2839  
  2840          if (why == WHY_EXCEPTION || why == WHY_RERAISE) {
  2841              if (!PyErr_Occurred()) {
  2842                  PyErr_SetString(PyExc_SystemError,
  2843                      "error return without exception set");
  2844                  why = WHY_EXCEPTION;
  2845              }
  2846          }

How is _checkMD implemented?  Is it in a C extension module?

I've seen this kind of exception before: within the internals of CPython, functions return a PyObject*, and the NULL value is used to indicate an exception has been thrown.  The exception itself is IIRC stored in a field of a per-thread struct.  So what has happened is a function has returned NULL (as if an exception has been thrown), and control has returned to ceval.c's bytecode evaluation loop, but the per-thread state doesn't have an exception set on it.  Hence when ceval.c goes into exception-throwing mode, but finds there isn't one, it synthesizes the exception you're seeing.

How could this happen:
(a) code in a C extension module is returning NULL, without an API call to set an exception having occurred (most likely IMHO)
(b) perhaps (I'm speculating) some weird threading issue that's causing the interpreter to pick up the wrong interpreter-state struct for the current thread - or maybe the exception is being set on the wrong thread?
(c) something else I'm not thinking of

(In reply to Dave Malcolm from comment #23)
> How is _checkMD implemented?  Is it in a C extension module?

Sorry, self._checksum, I think.

(In reply to Dave Malcolm from comment #25)
> (In reply to Dave Malcolm from comment #23)
> > How is _checkMD implemented?  Is it in a C extension module?
> 
> Sorry, self._checksum, I think.

It's roughly: self.checkMD => self._checksum => yum.misc.checksum => yum.misc.Checksums => file.read() / hashlib.*

I don't think there are any other C module calls, and I'd guess of the two that it's hashlib that's the more likely to be failing. But, again, I've never seen a report of this outside of anaconda ... so I'm very suspicious of the threading, or the general anaconda env.

- We *think* (and this is really just a hunch, although it seems to be working) that there may be a problem with buffered reading in multithreaded applications. - It seems that there was a remotely similar problem reported upstream without a reliable reproducer [1], so the upstream fix may haven't actually fixed it.
- During our debugging, we were getting output "close failed in file object destructor", which gets printed by file object destructor - this gets invoked by "del fo", line 363 in /usr/lib/python2.7/site-packages/yum/misc.py, method "checksum". After removing this line, we can't reproduce the problem any more.

I'm however still not sure that this is the right solution and why it works. James, why is the line there in the first place? Any reason to delete the file descriptor explicitly?

[1] http://bugs.python.org/issue9295

(In reply to Bohuslav "Slavek" Kabrda from comment #27)

> I'm however still not sure that this is the right solution and why it works.
> James, why is the line there in the first place? Any reason to delete the
> file descriptor explicitly?

 Not sure, git blame shows it's "from" 2004 but it might well have been pasted from somewhere else at that time making it much older ... I'd guess it's just someone from a C background being explicit.
 The only other thing I can think is that because the fo can be passed in there could have been some weird code path with an object that really wanted a __del__ method to be called there (but I hope that isn't true).

 I have no problem removing the del line, if you want me to.

(In reply to James Antill from comment #28)
> (In reply to Bohuslav "Slavek" Kabrda from comment #27)
> 
> > I'm however still not sure that this is the right solution and why it works.
> > James, why is the line there in the first place? Any reason to delete the
> > file descriptor explicitly?
> 
>  Not sure, git blame shows it's "from" 2004 but it might well have been
> pasted from somewhere else at that time making it much older ... I'd guess
> it's just someone from a C background being explicit.
>  The only other thing I can think is that because the fo can be passed in
> there could have been some weird code path with an object that really wanted
> a __del__ method to be called there (but I hope that isn't true).

Judging from anaconda-tb, the "file" argument passed into this function is a string, which means that fo is file opened inside this function. (That makes the problem even more weird, though...)

>  I have no problem removing the del line, if you want me to.

I'll try to confirm that removing this line solves the issue - if yes, I'll reassign this bug to Yum so that you can fix it.

(I'll continue investigating this problem, since it shouldn't be there in the first place - it's probably caused by a race condition inside Python's C code.)

The extra del(fo) in yum codebase seems to cause the issue (though it is a valid statement there). Reassigning.

Created attachment 883935 [details]
patch fixing the issue

Patch that seems to fix the issue. No additional info needed.

(In reply to Bohuslav "Slavek" Kabrda from comment #29)

> Judging from anaconda-tb, the "file" argument passed into this function is a
> string, which means that fo is file opened inside this function. (That makes
> the problem even more weird, though...)

 Yeh, missed that. It's only called when it's guaranteed to be a noop, nice :).
 On the upside there's roughly 0% chance of removing the del line causing a problem, given it doesn't do anything :).

Created attachment 885359 [details]
anaconda.log

Created attachment 885360 [details]
anaconda-tb-PxxtnE

Created attachment 885361 [details]
anaconda-tb-VDWZWJ

Created attachment 885362 [details]
program.log

Created attachment 885363 [details]
storage.log

Created attachment 885364 [details]
storage.state

Created attachment 885366 [details]
syslog

Created attachment 886071 [details]
proposed patch from the version 5 of the updates.img

 Vratislav, you want to remove the CHUNK argument to open?

 I assume you want to do this as well as the previous removal of the "del"?

 Should we be doing this upstream too, or is this a temporary workaround for an issue that'll be fixed in python?

The updates.img that is considired to be fixing the issue contains both changes, removing the "del()" call and removing the CHUNK argument to open. So I think these should both be applied.

And I believe it should be done upstream. It is, with high probability, a bug in Python (as per comment #27), but it is a long-term issue and nobody know when and if ever it gets resolved. On the other hand, that argument is unnecessary, it's better to let Python/OS decide on buffering.

Ok, thanks.

Hello,
do we have any update on this bug? Is this still an issue, eventually is anybody able to confirm the fix on recent compose?

So the reporter in bug 1103692 replied that they are seeing the issue ("return without exception set" in yum) in RC 3.1 DVD server variant only, not on workstation, compute node or desktop. This would indicate that the fix included in RC 3.1 and mentioned in comment 61 might be ineffective.

Radek Vykydal was able to reproduce the issue on a KVM VM booted from PXE, but only once. Subsequent runs did not reproduce it. This seems to be another indication that the issue is some sort of a race condition.

This request was resolved in Red Hat Enterprise Linux 7.0.

Contact your manager or support representative in case you have further questions about the request.