classification
Title: File read silently stops after EIO I/O error
Type: Stage:
Components: IO Versions: Python 3.4, Python 2.7
process
Status: open Resolution:
Dependencies: Superseder:
Assigned To: Nosy List: haypo, ivank, neologix, pitrou, python-dev
Priority: normal Keywords: patch

Created on 2014-03-28 22:29 by ivank, last changed 2014-11-12 20:53 by haypo.

Files
File name Uploaded Description Edit
fileio_readall_eio.patch haypo, 2014-07-01 15:07 review
fileobject.patch haypo, 2014-07-02 22:38 review
Messages (16)
msg215085 - (view) Author: ivank (ivank) Date: 2014-03-28 22:29
I intentionally corrupted a zpool to induce an I/O error in a file, in this case, /usr/lib/x86_64-linux-gnu/gconv/IBM1390.so

# ls -l /usr/lib/x86_64-linux-gnu/gconv/IBM1390.so
-rw-r--r-- 1 root root 231,496 2014-03-24 06:26 /usr/lib/x86_64-linux-gnu/gconv/IBM1390.so

# cat /usr/lib/x86_64-linux-gnu/gconv/IBM1390.so > /dev/null
cat: /usr/lib/x86_64-linux-gnu/gconv/IBM1390.so: Input/output error

When I read the file, Python 3.3.5 and 3.4.0 check for EIO and raise an exception:

>>> open("/usr/lib/x86_64-linux-gnu/gconv/IBM1390.so", "rb").read()
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
OSError: [Errno 5] Input/output error

but Python 2.7.6 does not:

# python2
Python 2.7.6 (default, Mar 22 2014, 22:59:56) 
[GCC 4.8.2] on linux2
Type "help", "copyright", "credits" or "license" for more information.
>>> x = open("/usr/lib/x86_64-linux-gnu/gconv/IBM1390.so", "rb").read()
>>> len(x)
131072
msg215213 - (view) Author: Antoine Pitrou (pitrou) * (Python committer) Date: 2014-03-30 22:51
Python 2.7 uses C fopen() and fread(), so what happens probably is that fread() silences the error.
msg215533 - (view) Author: STINNER Victor (haypo) * (Python committer) Date: 2014-04-04 16:26
> Python 2.7 uses C fopen() and fread(), so what happens probably is that fread() silences the error.

I see that file_read() checks ferror() if fread() returned 0. I would nice to run the test in strace and attach the output of strace to see if the EIO is returneded by the kernel at least.
msg217234 - (view) Author: STINNER Victor (haypo) * (Python committer) Date: 2014-04-27 00:28
@ivank: Can you please answer to questions? It's hard to understand the issue. Without more information, I would suggest to close the issue.
msg217237 - (view) Author: ivank (ivank) Date: 2014-04-27 03:26
I'm finding it hard to reproduce the bug again with more zpool corruption.  (I see the `IOError: [Errno 5] Input/output error` exception now.)  I do remember that in the reported case, Python 3.4, node.js, and OpenJDK 7 threw an EIO exception, but Python 2.7 did not.  I tested this multiple times.

Right now I can only speculate that Python 2.7 silently stops reading only in certain cases, e.g. depending on how Python's reads are aligned with the first byte that causes EIO.

I'm still working on getting it reproduced, please hold off on closing.
msg217244 - (view) Author: STINNER Victor (haypo) * (Python committer) Date: 2014-04-27 09:49
2014-04-27 5:26 GMT+02:00 ivank <report@bugs.python.org>:
> (I see the `IOError: [Errno 5] Input/output error` exception now.)

Can you please run your test in strace to see system calls?
msg217265 - (view) Author: Charles-Fran├žois Natali (neologix) * (Python committer) Date: 2014-04-27 14:18
I'm with Antoine, it's likely a glibc bug.

We already had a similar issue with fwrite():
http://bugs.python.org/issue17976
msg217266 - (view) Author: Antoine Pitrou (pitrou) * (Python committer) Date: 2014-04-27 14:20
ivank, if you know some C, perhaps you could write a trivial program that does an fopen() followed by an fread() of 131072 bytes, and see if the fread() errors out.
msg221864 - (view) Author: ivank (ivank) Date: 2014-06-29 17:05
I managed to reproduce this again, this time by corrupting data on a btrfs filesystem.

$ cat read_error_file.py    
import os

fname = "/usr/bin/Xorg"
size = os.stat(fname).st_size
print fname, "stat size:", size

f = open(fname, "rb")
print "len(f.read()): ", len(f.read())
f.close()

f = open(fname, "rb")
for i in xrange(size):
        try:
                f.read(1)
        except IOError:
                print "IOError at byte %d" % i
                break
f.close()

$ python read_error_file.py 
/usr/bin/Xorg stat size: 2331776
len(f.read()):  716800
IOError at byte 716800

Note how the first test does not throw an IOError, but the second one does.

The strace for the first test is:

open("/usr/bin/Xorg", O_RDONLY)         = 3
fstat(3, {st_mode=S_IFREG|0755, st_size=2331776, ...}) = 0
fstat(3, {st_mode=S_IFREG|0755, st_size=2331776, ...}) = 0
lseek(3, 0, SEEK_CUR)                   = 0
fstat(3, {st_mode=S_IFREG|0755, st_size=2331776, ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f1334bd6000
lseek(3, 0, SEEK_CUR)                   = 0
mmap(NULL, 2334720, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f1332ea6000
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\265M\4\0\0\0\0\0"..., 2330624) = 716800
read(3, 0x7f1332f55034, 1613824)        = -1 EIO (Input/output error)
mremap(0x7f1332ea6000, 2334720, 720896, MREMAP_MAYMOVE) = 0x7f1332ea6000
munmap(0x7f1332ea6000, 720896)          = 0
write(1, "len(f.read()):  716800\n", 23len(f.read()):  716800
) = 23

Note the "-1 EIO (Input/output error)" that gets ignored somewhere.
msg221865 - (view) Author: ivank (ivank) Date: 2014-06-29 17:11
This problem happens with Python 3.4 as well.

$ cat read_error_file.py 
from __future__ import print_function

import os

fname = "/usr/bin/Xorg"
size = os.stat(fname).st_size
print(fname, "stat size:", size)

f = open(fname, "rb")
print("len(f.read()): ", len(f.read()))
f.close()

f = open(fname, "rb")
for i in range(size):
        try:
                f.read(1)
        except IOError:
                print("IOError at byte %d" % i)
                break
f.close()

$ python3 --version
Python 3.4.1

$ python3 read_error_file.py
/usr/bin/Xorg stat size: 2331776
len(f.read()):  716800
IOError at byte 716800

strace for the first test is:

open("/usr/bin/Xorg", O_RDONLY|O_CLOEXEC) = 3
fstat(3, {st_mode=S_IFREG|0755, st_size=2331776, ...}) = 0
ioctl(3, SNDCTL_TMR_TIMEBASE or SNDRV_TIMER_IOCTL_NEXT_DEVICE or TCGETS, 0x7fff323ac8b0) = -1 ENOTTY (Inappropriate ioctl for device)
fstat(3, {st_mode=S_IFREG|0755, st_size=2331776, ...}) = 0
lseek(3, 0, SEEK_CUR)                   = 0
lseek(3, 0, SEEK_CUR)                   = 0
fstat(3, {st_mode=S_IFREG|0755, st_size=2331776, ...}) = 0
mmap(NULL, 2334720, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f57884cc000
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\265M\4\0\0\0\0\0"..., 2331777) = 716800
read(3, 0x7f578857b030, 1614977)        = -1 EIO (Input/output error)
mremap(0x7f57884cc000, 2334720, 720896, MREMAP_MAYMOVE) = 0x7f57884cc000
munmap(0x7f57884cc000, 720896)          = 0
write(1, "len(f.read()):  716800\n", 23len(f.read()):  716800
) = 23
close(3)
msg222043 - (view) Author: STINNER Victor (haypo) * (Python committer) Date: 2014-07-01 15:07
Here is a patch for FileIO.readall() which should fix the issue. Currently, readall() returns read bytes at the first read() error if a least one call to read() succeed.
msg222114 - (view) Author: Charles-Fran├žois Natali (neologix) * (Python committer) Date: 2014-07-02 17:25
LGTM.
msg222124 - (view) Author: Roundup Robot (python-dev) Date: 2014-07-02 21:01
New changeset 652b62213072 by Victor Stinner in branch '3.4':
Issue #21090: io.FileIO.readall() does not ignore I/O errors anymore. Before,
http://hg.python.org/cpython/rev/652b62213072

New changeset 440279cec378 by Victor Stinner in branch 'default':
(Merge 3.4) Issue #21090: io.FileIO.readall() does not ignore I/O errors
http://hg.python.org/cpython/rev/440279cec378
msg222126 - (view) Author: Roundup Robot (python-dev) Date: 2014-07-02 21:14
New changeset 1492a42b8308 by Victor Stinner in branch '2.7':
Issue #21090: io.FileIO.readall() does not ignore I/O errors anymore. Before,
http://hg.python.org/cpython/rev/1492a42b8308
msg222140 - (view) Author: STINNER Victor (haypo) * (Python committer) Date: 2014-07-02 22:38
For Python 2, file.read() looks wrong: if only checks ferror() if fread() returns 0, whereas Py_UniversalNewlineFread() can call fread() more than once, and according to fread() manual page, fread() result can be different than 0 on error.

"If an error occurs, or the end of the file is reached, the return value is a short item count (or zero)."
http://linux.die.net/man/3/fread

Attached fileobject.c rewrites error handling in fileobject.c. The main change if that ferror() is called even if fread() does not return 0.
msg231093 - (view) Author: STINNER Victor (haypo) * (Python committer) Date: 2014-11-12 20:53
On IRC, buck1 asked why the following code behaves differently on Python < 3.4 and Python >= 3.4. It is related to this issue in fact.

Code:
---
from __future__ import print_function

from os import openpty
read, write = openpty()

from subprocess import Popen
proc = Popen(
    ('echo', 'ok'),
    stdout=write,
    close_fds=True,
)

from os import fdopen
fdopen(write, 'w').close()
with fdopen(read) as stdout:
    print('STDOUT', stdout.read())

print('exit code:', proc.wait())
---

Simplified example:
---
import io, os
read, write = os.openpty()
os.write(write, b'ok\n')
os.close(write)
with io.FileIO(read, closefd=False) as fp:
    print(fp.readall())
---

On Python < 3.4, it displays "ok", whereas Python 3.4 and later fail with 
OSError(5, 'Input/output error' on readall().

Another example:
---
import os
read, write = os.openpty()
os.write(write, b'ok\n')
os.close(write)
print("read: %r" % os.read(read, 4096))
print("read: %r" % os.read(read, 4096))
---

The first read syscall succeed, even if the write end is already called. But the second read syscall fails with EIO.
History
Date User Action Args
2014-11-12 20:53:33hayposetmessages: + msg231093
2014-07-02 22:38:33hayposetfiles: + fileobject.patch

messages: + msg222140
2014-07-02 21:14:19python-devsetmessages: + msg222126
2014-07-02 21:01:34python-devsetnosy: + python-dev
messages: + msg222124
2014-07-02 17:25:04neologixsetmessages: + msg222114
2014-07-01 15:07:14hayposetfiles: + fileio_readall_eio.patch
keywords: + patch
messages: + msg222043
2014-06-29 17:11:58ivanksetmessages: + msg221865
versions: + Python 3.4
2014-06-29 17:05:35ivanksetmessages: + msg221864
2014-05-21 15:49:44Claudiu.Popasetnosy: - Claudiu.Popa
2014-04-27 14:20:08pitrousetmessages: + msg217266
2014-04-27 14:18:13neologixsetnosy: + neologix
messages: + msg217265
2014-04-27 09:49:21hayposetmessages: + msg217244
2014-04-27 03:26:50ivanksetmessages: + msg217237
2014-04-27 00:28:08hayposetmessages: + msg217234
2014-04-04 16:26:23hayposetmessages: + msg215533
2014-04-04 16:20:21hayposetnosy: + haypo
2014-03-30 22:51:54pitrousetnosy: + pitrou
messages: + msg215213
2014-03-29 19:40:43Claudiu.Popasetnosy: + Claudiu.Popa
2014-03-28 22:29:46ivankcreate