Patchwork Fix for Bug #5807

login
register
mail settings
Submitter Sascha Nemecek
Date March 1, 2018, 10:06 a.m.
Message ID <0e93f89b-c52a-0378-eaf8-4d136ad46960@wienfluss.net>
Download mbox | patch
Permalink /patch/28545/
State Accepted
Headers show

Comments

Sascha Nemecek - March 1, 2018, 10:06 a.m.
# HG changeset patch
# User Sascha Nemecek <nemecek@wienfluss.net>
# Date 1519831479 -3600
#      Wed Feb 28 16:24:39 2018 +0100
# Node ID 42ddf4ee4f91d76f19ca0c3efc4c8e4c1c6fa96c
# Parent  1bd132a021dd00f96604e33a8fb5306d37e56007
Don't close 'fp' (= 'ui.fout') stream to prevent 'ValueError: I/O 
operation on closed file' (Bug #5807).

Regression of changeset 30261:6bed17ba00a1 
(https://www.mercurial-scm.org/repo/hg/rev/6bed17ba00a1)
Augie Fackler - March 1, 2018, 7:38 p.m.
On Thu, Mar 01, 2018 at 11:06:59AM +0100, Sascha Nemecek wrote:
> # HG changeset patch
> # User Sascha Nemecek <nemecek@wienfluss.net>
> # Date 1519831479 -3600
> #      Wed Feb 28 16:24:39 2018 +0100
> # Node ID 42ddf4ee4f91d76f19ca0c3efc4c8e4c1c6fa96c
> # Parent  1bd132a021dd00f96604e33a8fb5306d37e56007
> Don't close 'fp' (= 'ui.fout') stream to prevent 'ValueError: I/O operation

Queued, thanks. Congrats on your first hg patch!

(In the future please read up on
https://www.mercurial-scm.org/wiki/ContributingChanges - this patch
appears to have gotten damaged in transit, requring some manual fixing
on my end)
Yuya Nishihara - March 2, 2018, 4:14 a.m.
On Thu, 1 Mar 2018 11:06:59 +0100, Sascha Nemecek wrote:
> # HG changeset patch
> # User Sascha Nemecek <nemecek@wienfluss.net>
> # Date 1519831479 -3600
> #      Wed Feb 28 16:24:39 2018 +0100
> # Node ID 42ddf4ee4f91d76f19ca0c3efc4c8e4c1c6fa96c
> # Parent  1bd132a021dd00f96604e33a8fb5306d37e56007
> Don't close 'fp' (= 'ui.fout') stream to prevent 'ValueError: I/O 
> operation on closed file' (Bug #5807).
> 
> Regression of changeset 30261:6bed17ba00a1 
> (https://www.mercurial-scm.org/repo/hg/rev/6bed17ba00a1)
> 
> diff -r 1bd132a021dd -r 42ddf4ee4f91 hgext/convert/subversion.py
> --- a/hgext/convert/subversion.py	Wed Feb 21 14:36:42 2018 +0530
> +++ b/hgext/convert/subversion.py	Wed Feb 28 16:24:39 2018 +0100
> @@ -149,7 +149,7 @@
>           pickle.dump(str(inst), fp, protocol)
>       else:
>           pickle.dump(None, fp, protocol)
> -    fp.close()
> +    fp.flush()
>       # With large history, cleanup process goes crazy and suddenly
>       # consumes *huge* amount of memory. The output file being closed,
>       # there is no need for clean termination.

I don't think fp.close() was the source of the problem. Here the process
_exit()s so no cleanup would be run.

I suspect that some hidden bug was disclosed by the change 3a4c0905f357,
"util: always force line buffered stdout when stdout is a tty." Before,
ui.fout.close() just called fflush() because sys.stdout.close() doesn't
close the underlying file stream. This no longer applies to the current
ui.fout as it is created by fdopen(1).
Sascha Nemecek - March 7, 2018, 9:48 p.m.
Am 2018-03-02 um 05:14 schrieb Yuya Nishihara:
> On Thu, 1 Mar 2018 11:06:59 +0100, Sascha Nemecek wrote:
>> # HG changeset patch
>> # User Sascha Nemecek <nemecek@wienfluss.net>
>> # Date 1519831479 -3600
>> #      Wed Feb 28 16:24:39 2018 +0100
>> # Node ID 42ddf4ee4f91d76f19ca0c3efc4c8e4c1c6fa96c
>> # Parent  1bd132a021dd00f96604e33a8fb5306d37e56007
>> Don't close 'fp' (= 'ui.fout') stream to prevent 'ValueError: I/O 
>> operation on closed file' (Bug #5807).
>>
>> Regression of changeset 30261:6bed17ba00a1 
>> (https://www.mercurial-scm.org/repo/hg/rev/6bed17ba00a1)
>>
>> diff -r 1bd132a021dd -r 42ddf4ee4f91 hgext/convert/subversion.py
>> --- a/hgext/convert/subversion.py	Wed Feb 21 14:36:42 2018 +0530
>> +++ b/hgext/convert/subversion.py	Wed Feb 28 16:24:39 2018 +0100
>> @@ -149,7 +149,7 @@
>>           pickle.dump(str(inst), fp, protocol)
>>       else:
>>           pickle.dump(None, fp, protocol)
>> -    fp.close()
>> +    fp.flush()
>>       # With large history, cleanup process goes crazy and suddenly
>>       # consumes *huge* amount of memory. The output file being closed,
>>       # there is no need for clean termination.
> 
> I don't think fp.close() was the source of the problem. Here the process
> _exit()s so no cleanup would be run.

Of course, the problem might lie deeper. Empirically tested, the
fp.close() triggered the reported error output. From my observation, the
fp.close() affected stdout of the convert function and also pdb.
Therefore I came to the conclusion that the fp.close() / ui.fout.close()
was the culprit.


> I suspect that some hidden bug was disclosed by the change 3a4c0905f357,
> "util: always force line buffered stdout when stdout is a tty." Before,
> ui.fout.close() just called fflush() because sys.stdout.close() doesn't
> close the underlying file stream. This no longer applies to the current
> ui.fout as it is created by fdopen(1).

This sounds reasonable to me.

Since I'm not a python developer and lack the insight into the project,
I did not and could not dig deeper. So there might be a better fix than
my humble patch.


Best regards,
Sascha

PS: Thanks fly to Augie for fixing my damaged patch. I'll try to do
better next time.
Yuya Nishihara - March 8, 2018, 12:16 p.m.
On Wed, 7 Mar 2018 22:48:01 +0100, Sascha Nemecek wrote:
> Am 2018-03-02 um 05:14 schrieb Yuya Nishihara:
> > On Thu, 1 Mar 2018 11:06:59 +0100, Sascha Nemecek wrote:
> >> # HG changeset patch
> >> # User Sascha Nemecek <nemecek@wienfluss.net>
> >> # Date 1519831479 -3600
> >> #      Wed Feb 28 16:24:39 2018 +0100
> >> # Node ID 42ddf4ee4f91d76f19ca0c3efc4c8e4c1c6fa96c
> >> # Parent  1bd132a021dd00f96604e33a8fb5306d37e56007
> >> Don't close 'fp' (= 'ui.fout') stream to prevent 'ValueError: I/O 
> >> operation on closed file' (Bug #5807).
> >>
> >> Regression of changeset 30261:6bed17ba00a1 
> >> (https://www.mercurial-scm.org/repo/hg/rev/6bed17ba00a1)
> >>
> >> diff -r 1bd132a021dd -r 42ddf4ee4f91 hgext/convert/subversion.py
> >> --- a/hgext/convert/subversion.py	Wed Feb 21 14:36:42 2018 +0530
> >> +++ b/hgext/convert/subversion.py	Wed Feb 28 16:24:39 2018 +0100
> >> @@ -149,7 +149,7 @@
> >>           pickle.dump(str(inst), fp, protocol)
> >>       else:
> >>           pickle.dump(None, fp, protocol)
> >> -    fp.close()
> >> +    fp.flush()
> >>       # With large history, cleanup process goes crazy and suddenly
> >>       # consumes *huge* amount of memory. The output file being closed,
> >>       # there is no need for clean termination.
> > 
> > I don't think fp.close() was the source of the problem. Here the process
> > _exit()s so no cleanup would be run.
> 
> Of course, the problem might lie deeper. Empirically tested, the
> fp.close() triggered the reported error output. From my observation, the
> fp.close() affected stdout of the convert function and also pdb.
> Therefore I came to the conclusion that the fp.close() / ui.fout.close()
> was the culprit.

If this patch magically fixes the issue, that's fine. It's also harmless
to do fflush() instead of fclose() here. I'm just saying that the process
exits immediately after the fp.close() with no cleanup, so I have no idea
why that matters.

  -fp.close()
  +fp.flush()
   os._exit(0)
Sascha Nemecek - March 8, 2018, 12:42 p.m.
On 08/03/18 13:16, Yuya Nishihara wrote:
> On Wed, 7 Mar 2018 22:48:01 +0100, Sascha Nemecek wrote:
>> Am 2018-03-02 um 05:14 schrieb Yuya Nishihara:
>>> On Thu, 1 Mar 2018 11:06:59 +0100, Sascha Nemecek wrote:
>>>> # HG changeset patch
>>>> # User Sascha Nemecek <nemecek@wienfluss.net>
>>>> # Date 1519831479 -3600
>>>> #      Wed Feb 28 16:24:39 2018 +0100
>>>> # Node ID 42ddf4ee4f91d76f19ca0c3efc4c8e4c1c6fa96c
>>>> # Parent  1bd132a021dd00f96604e33a8fb5306d37e56007
>>>> Don't close 'fp' (= 'ui.fout') stream to prevent 'ValueError: I/O
>>>> operation on closed file' (Bug #5807).
>>>>
>>>> Regression of changeset 30261:6bed17ba00a1
>>>> (https://www.mercurial-scm.org/repo/hg/rev/6bed17ba00a1)
>>>>
>>>> diff -r 1bd132a021dd -r 42ddf4ee4f91 hgext/convert/subversion.py
>>>> --- a/hgext/convert/subversion.py	Wed Feb 21 14:36:42 2018 +0530
>>>> +++ b/hgext/convert/subversion.py	Wed Feb 28 16:24:39 2018 +0100
>>>> @@ -149,7 +149,7 @@
>>>>            pickle.dump(str(inst), fp, protocol)
>>>>        else:
>>>>            pickle.dump(None, fp, protocol)
>>>> -    fp.close()
>>>> +    fp.flush()
>>>>        # With large history, cleanup process goes crazy and suddenly
>>>>        # consumes *huge* amount of memory. The output file being closed,
>>>>        # there is no need for clean termination.
>>>
>>> I don't think fp.close() was the source of the problem. Here the process
>>> _exit()s so no cleanup would be run.
>>
>> Of course, the problem might lie deeper. Empirically tested, the
>> fp.close() triggered the reported error output. From my observation, the
>> fp.close() affected stdout of the convert function and also pdb.
>> Therefore I came to the conclusion that the fp.close() / ui.fout.close()
>> was the culprit.
> 
> If this patch magically fixes the issue, that's fine. It's also harmless
> to do fflush() instead of fclose() here. I'm just saying that the process
> exits immediately after the fp.close() with no cleanup, so I have no idea
> why that matters.
> 
>    -fp.close()
>    +fp.flush()
>     os._exit(0)

My guess/interpretation is, that this happens in a child process. When 
closing ui.fout, the parent and all other process run into closed doors.


Best regards,
Sascha
Yuya Nishihara - March 8, 2018, 1:07 p.m.
On Thu, 8 Mar 2018 13:42:42 +0100, Sascha Nemecek wrote:
> On 08/03/18 13:16, Yuya Nishihara wrote:
> > On Wed, 7 Mar 2018 22:48:01 +0100, Sascha Nemecek wrote:
> >> Am 2018-03-02 um 05:14 schrieb Yuya Nishihara:
> >>> On Thu, 1 Mar 2018 11:06:59 +0100, Sascha Nemecek wrote:
> >>>> # HG changeset patch
> >>>> # User Sascha Nemecek <nemecek@wienfluss.net>
> >>>> # Date 1519831479 -3600
> >>>> #      Wed Feb 28 16:24:39 2018 +0100
> >>>> # Node ID 42ddf4ee4f91d76f19ca0c3efc4c8e4c1c6fa96c
> >>>> # Parent  1bd132a021dd00f96604e33a8fb5306d37e56007
> >>>> Don't close 'fp' (= 'ui.fout') stream to prevent 'ValueError: I/O
> >>>> operation on closed file' (Bug #5807).
> >>>>
> >>>> Regression of changeset 30261:6bed17ba00a1
> >>>> (https://www.mercurial-scm.org/repo/hg/rev/6bed17ba00a1)
> >>>>
> >>>> diff -r 1bd132a021dd -r 42ddf4ee4f91 hgext/convert/subversion.py
> >>>> --- a/hgext/convert/subversion.py	Wed Feb 21 14:36:42 2018 +0530
> >>>> +++ b/hgext/convert/subversion.py	Wed Feb 28 16:24:39 2018 +0100
> >>>> @@ -149,7 +149,7 @@
> >>>>            pickle.dump(str(inst), fp, protocol)
> >>>>        else:
> >>>>            pickle.dump(None, fp, protocol)
> >>>> -    fp.close()
> >>>> +    fp.flush()
> >>>>        # With large history, cleanup process goes crazy and suddenly
> >>>>        # consumes *huge* amount of memory. The output file being closed,
> >>>>        # there is no need for clean termination.
> >>>
> >>> I don't think fp.close() was the source of the problem. Here the process
> >>> _exit()s so no cleanup would be run.
> >>
> >> Of course, the problem might lie deeper. Empirically tested, the
> >> fp.close() triggered the reported error output. From my observation, the
> >> fp.close() affected stdout of the convert function and also pdb.
> >> Therefore I came to the conclusion that the fp.close() / ui.fout.close()
> >> was the culprit.
> > 
> > If this patch magically fixes the issue, that's fine. It's also harmless
> > to do fflush() instead of fclose() here. I'm just saying that the process
> > exits immediately after the fp.close() with no cleanup, so I have no idea
> > why that matters.
> > 
> >    -fp.close()
> >    +fp.flush()
> >     os._exit(0)
> 
> My guess/interpretation is, that this happens in a child process. When 
> closing ui.fout, the parent and all other process run into closed doors.

Nah, file descriptors should be duplicated to child processes. And _exit()
closes all of them in the parent process anyway.

Patch

diff -r 1bd132a021dd -r 42ddf4ee4f91 hgext/convert/subversion.py
--- a/hgext/convert/subversion.py	Wed Feb 21 14:36:42 2018 +0530
+++ b/hgext/convert/subversion.py	Wed Feb 28 16:24:39 2018 +0100
@@ -149,7 +149,7 @@ 
          pickle.dump(str(inst), fp, protocol)
      else:
          pickle.dump(None, fp, protocol)
-    fp.close()
+    fp.flush()
      # With large history, cleanup process goes crazy and suddenly
      # consumes *huge* amount of memory. The output file being closed,
      # there is no need for clean termination.