This issue tracker has been migrated to GitHub, and is currently read-only.
For more information, see the GitHub FAQs in the Python's Developer Guide.

classification
Title: Bad formatting in WinError 193 when using subprocess.check_call
Type: enhancement Stage: needs patch
Components: Windows Versions: Python 3.8
process
Status: open Resolution:
Dependencies: Superseder:
Assigned To: Nosy List: Raúl Núñez de Arenas, berker.peksag, eryksun, paul.moore, steve.dower, tim.golden, zach.ware
Priority: normal Keywords:

Created on 2016-03-06 16:56 by Raúl Núñez de Arenas, last changed 2022-04-11 14:58 by admin.

Messages (14)
msg261262 - (view) Author: Raúl Núñez de Arenas (Raúl Núñez de Arenas) Date: 2016-03-06 16:56
Python 3.5.1 x64 @ Windows 10 x64

The error message in the traceback for OSError/WinError 193 has bad formatting and the offending file name is not printed.

For example, this code:
----
import subprocess

testfile = open('testfile.notexecutable', 'wb')
testfile.close()
subprocess.check_call(['testfile.notexecutable'])
----

produces this output:
----
Traceback (most recent call last):
  File "test.py", line 6, in <module>
    subprocess.check_call(['testfile.notexecutable'])
  File "C:\Program Files\Python35\lib\subprocess.py", line 579, in check_call
    retcode = call(*popenargs, **kwargs)
  File "C:\Program Files\Python35\lib\subprocess.py", line 560, in call
    with Popen(*popenargs, **kwargs) as p:
  File "C:\Program Files\Python35\lib\subprocess.py", line 950, in __init__
    restore_signals, start_new_session)
  File "C:\Program Files\Python35\lib\subprocess.py", line 1220, in _execute_child
    startupinfo)
OSError: [WinError 193] %1 is not a valid Win32 application
----

Please note the "%1 is not a valid..." on the last line. Instead of the "%1" placeholder, the filename ("testfile.notexecutable") should appear instead.

Thanks :)
msg261268 - (view) Author: Eryk Sun (eryksun) * (Python triager) Date: 2016-03-06 19:58
When Python creates an exception generically from a Windows error code, it calls WinAPI FormatMessage with the flag FORMAT_MESSAGE_IGNORE_INSERTS. The reason for this is explained in a blog post written by Raymond Chen[1]: "when you are not in control of the message, you had better pass the FORMAT_MESSAGE_IGNORE_INSERTS flag."

[1]: https://blogs.msdn.microsoft.com/oldnewthing/20071128-00/?p=24353

Some extension modules in the code base get this wrong. For example, ctypes.FormatError() doesn't use FORMAT_MESSAGE_IGNORE_INSERTS, so it fails to get the system error message for ERROR_BAD_EXE_FORMAT (193) and just returns its default string "<no description>":

    >>> ctypes.FormatError(193)
    '<no description>'
msg261284 - (view) Author: Raúl Núñez de Arenas (Raúl Núñez de Arenas) Date: 2016-03-07 07:26
Thanks for the information, Eryk, I've read the blog.
msg261315 - (view) Author: Eryk Sun (eryksun) * (Python triager) Date: 2016-03-07 21:21
It would be possible for subprocess to replace "%1" with the filename parsed from the command line and then re-raise the exception. That said, it's not as if this is a deficiency in the Windows implementation relative to subprocess on POSIX. For example, in 3.4 on Linux it raises a generic ENOEXEC error:

    >>> os.access('./test.txt', os.X_OK)
    True
    >>> subprocess.call(['./test.txt'])
    Traceback (most recent call last):
      File "<stdin>", line 1, in <module>
      File "/usr/lib/python3.4/subprocess.py", line 537, in call
        with Popen(*popenargs, **kwargs) as p:
      File "/usr/lib/python3.4/subprocess.py", line 859, in __init__
        restore_signals, start_new_session)
      File "/usr/lib/python3.4/subprocess.py", line 1457, in _execute_child
        raise child_exception_type(errno_num, err_msg)
    OSError: [Errno 8] Exec format error

It could provide the filename, for example:

    >>> raise OSError(errno.ENOEXEC, os.strerror(errno.ENOEXEC), './test.txt')
    Traceback (most recent call last):
      File "<stdin>", line 1, in <module>
    OSError: [Errno 8] Exec format error: './test.txt'

A new issue should be raised to fix the FormatMessage calls in the standard library that mistakenly leave out FORMAT_MESSAGE_IGNORE_INSERTS.
msg261350 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2016-03-08 11:54
> A new issue should be raised to fix the FormatMessage calls in the standard library that mistakenly leave out FORMAT_MESSAGE_IGNORE_INSERTS.

Do you suggest to modify OSError constructor to modify the call to FormatMessageW(): don't pass the FORMAT_MESSAGE_IGNORE_INSERTS flag?

I prefer "%1 is not a valid Win32 application" message than "<no description>".

Currently, PyErr_SetFromErrnoWithFilenameObjects() doesn't pass any argument to FormatMessageW(). The problem is that it looks like the expected argument depends a lot of the failing system call. I don't think that it's ok to always pass the filename (or two filenames when we get two filenames, ex: os.rename) to FormatMessageW().

For example, _winapi.CreateProcess() doesn't pass any filename to OSError constructor.


> It would be possible for subprocess to replace "%1" with the filename parsed from the command line and then re-raise the exception.

I like the idea of formatting the error message in the subprocess module. IMHO it's much safer to reformat the error message from the function which raises the exception, since the function knows the system call, has all parameters to the system call, and may expect some specific system calls.

There is no need to re-raise the exception: the "strerror" attribute contains the error message and it can be modified.

We need an helper function or add a new method to the OSError class. Example of method:

def reformat_strerror(self, *args):
   sef.strerror = FormatMessageW(..., self.strerror, ..., args)

For this specific issue, I don't know if reformat_strerror() should be called from subprocess.py or CreateProcess function of Modules/_winapi.c.

I understand that we should call reformat_strerror() with application_name (first parameter of CreateProcess, "executable" in subprocess), but only if the error message is 193.

Since there are "a lot" of error messages and a lot of functions calling system calls, I don't think that it will be possible to handle all possible error messages in all Python functions. I suggest to only call reformat_strerror() when an user complains, only promise best effort ;-)
msg261351 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2016-03-08 11:56
See also issue #25585: "DLL load failed: %1 is not a valid Win32 application" message of ImportError exception. Hum, so maybe a function is better, since ImportError doesn't inherit from OSError.
msg341090 - (view) Author: Raúl Núñez de Arenas (Raúl Núñez de Arenas) Date: 2019-04-29 15:23
I'm sorry to say that this still happens in Python 3.7.0...
msg341091 - (view) Author: Steve Dower (steve.dower) * (Python committer) Date: 2019-04-29 15:31
It still happens because nobody has proposed a patch to specially handle this one particular error code. The earlier messages explained why we can't do formatting on error messages.

If this one is particularly common, then it's best for it to be handled in Python code at the point where it shows up and converted into something more readable.
msg341093 - (view) Author: Raúl Núñez de Arenas (Raúl Núñez de Arenas) Date: 2019-04-29 15:52
Hi Steve :) I assumed that the issue was solved, that's why I warned, in case a patch was applied and it didn't work.

When I did read "I suggest to only call reformat_strerror() when an user complains", I supposed a patch was ready O:)

No big deal, I can deal with that particular error in my code.
msg341103 - (view) Author: Berker Peksag (berker.peksag) * (Python committer) Date: 2019-04-29 17:34
FYI, in msg261315, Eryk has mentioned about possible improvement of the exception message on POSIX. The filename has been added to the exception message in 8621bb5d93239316f97281826461b85072ff6db7:

>>> import subprocess, os
>>> os.access('log.txt', os.X_OK)
True
>>> subprocess.call(['./log.txt'])
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
  File "/Users/berkerpeksag/projects/cpython/Lib/subprocess.py", line 325, in call
    with Popen(*popenargs, **kwargs) as p:
  File "/Users/berkerpeksag/projects/cpython/Lib/subprocess.py", line 830, in __init__
    self._execute_child(args, executable, preexec_fn, close_fds,
  File "/Users/berkerpeksag/projects/cpython/Lib/subprocess.py", line 1648, in _execute_child
    raise child_exception_type(errno_num, err_msg, err_filename)
OSError: [Errno 8] Exec format error: './log.txt'
msg341146 - (view) Author: Raúl Núñez de Arenas (Raúl Núñez de Arenas) Date: 2019-04-30 10:42
That's the kind of patch I assumed was created for the Windows part, Berker, that's why I reopened the issue.

Thanks for the information.
msg341170 - (view) Author: Eryk Sun (eryksun) * (Python triager) Date: 2019-05-01 00:12
>> A new issue should be raised to fix the FormatMessage calls in the 
>> standard library that mistakenly leave out 
>> FORMAT_MESSAGE_IGNORE_INSERTS.
>
> Do you suggest to modify OSError constructor to modify the call to
> FormatMessageW(): don't pass the FORMAT_MESSAGE_IGNORE_INSERTS flag?
> I prefer "%1 is not a valid Win32 application" message than 
> "<no description>".

I suggested creating a new issue to fix the calls that omit this flag. I think it's just two modules: Modules/overlapped.c and Modules/_ctypes/callproc.c. If there are more inserts than arguments (i.e. any inserts in our case since we pass no arguments), then FormatMessageW fails and the above modules use a default message. For example:

    >>> _overlapped.FormatMessage(193)
    'unknown error code 193'
    >>> _ctypes.FormatError(193)
    '<no description>'

> There is no need to re-raise the exception: the "strerror" attribute 
> contains the error message and it can be modified.

I meant that Popen._execute_child would handle the exception by modifying and reraising it. In general for OSError exceptions, we could set `filename` to either `executable`, if it's defined, or else parse it out of the commandline. For ERROR_BAD_EXE_FORMAT (193), we could also change `strerror` to something like "Invalid executable format" instead of "%1 is not a valid Win32 application". This is more consistent with how we append ": {filename}" to the message.
msg341199 - (view) Author: Steve Dower (steve.dower) * (Python committer) Date: 2019-05-01 14:26
> I suggested creating a new issue to fix the calls that omit this flag.

Right, that's a separate issue that is easily fixed (and backported, IMHO). Though I suspect that we've not used the flags in those ones because we think we *can* properly format the message, so fixing the use of inserts is a better option than simply going back to the unformatted message.
msg341225 - (view) Author: Eryk Sun (eryksun) * (Python triager) Date: 2019-05-01 18:28
> I suspect that we've not used the flags in those ones because we 
> think we *can* properly format the message, so fixing the use of 
> inserts is a better option than simply going back to the 
> unformatted message.

We're advised that it's "unsafe to take an arbitrary system error code returned from an API and use FORMAT_MESSAGE_FROM_SYSTEM without FORMAT_MESSAGE_IGNORE_INSERTS". We don't control the content of system error messages. If we get the number and type of arguments wrong for the message inserts, then FormatMessageW may fail with an invalid parameter error, as it does in the examples I showed, or return nonsense, or even crash the process due to an unhandled access violation. 

Also, nothing was implemented in _overlapped.FormatMessage or _ctypes.FormatError to special case an `Arguments` array for particular error codes, or even to expose this capability to Python code. I think omitting the flag was just a mistake.
History
Date User Action Args
2022-04-11 14:58:28adminsetgithub: 70680
2019-05-01 18:28:25eryksunsetmessages: + msg341225
2019-05-01 14:26:57steve.dowersetmessages: + msg341199
2019-05-01 00:12:53eryksunsetmessages: + msg341170
2019-04-30 10:42:40Raúl Núñez de Arenassetmessages: + msg341146
2019-04-29 17:34:55berker.peksagsetversions: + Python 3.8, - Python 3.5
nosy: + berker.peksag

messages: + msg341103

stage: needs patch
2019-04-29 15:53:50vstinnersetnosy: - vstinner
2019-04-29 15:52:25Raúl Núñez de Arenassetmessages: + msg341093
2019-04-29 15:31:35steve.dowersetmessages: + msg341091
2019-04-29 15:23:25Raúl Núñez de Arenassetmessages: + msg341090
2016-03-08 11:56:04vstinnersetmessages: + msg261351
2016-03-08 11:54:22vstinnersetmessages: + msg261350
2016-03-08 11:23:55vstinnersetnosy: + vstinner
2016-03-07 21:21:25eryksunsettype: behavior -> enhancement
messages: + msg261315
2016-03-07 07:26:02Raúl Núñez de Arenassetmessages: + msg261284
2016-03-06 19:58:45eryksunsetnosy: + paul.moore, tim.golden, eryksun, zach.ware, steve.dower
messages: + msg261268

components: + Windows
type: behavior
2016-03-06 16:56:29Raúl Núñez de Arenascreate