Patchwork chg: suppress OSError in _restoreio() and add some logging (issue6330)

login
register
mail settings
Submitter Pulkit Goyal
Date July 3, 2020, 9:37 a.m.
Message ID <fa76d3882134a36dc13b.1593769072@workspace>
Download mbox | patch
Permalink /patch/46614/
State Accepted
Headers show

Comments

Pulkit Goyal - July 3, 2020, 9:37 a.m.
# HG changeset patch
# User Pulkit Goyal <7895pulkit@gmail.com>
# Date 1593764159 -19800
#      Fri Jul 03 13:45:59 2020 +0530
# Node ID fa76d3882134a36dc13bba6a3499e11590505258
# Parent  3707f6e7e04e071c7a87f781718701b28bd9a877
# EXP-Topic issue6330
chg: suppress OSError in _restoreio() and add some logging (issue6330)

According to issue6330, running chg on heavy loaded systems can lead to
following error:

```
Traceback (most recent call last):
  File "path-to-hg/mercurial/commandserver.py", line 650, in _acceptnewconnection
    self._runworker(conn)
  File "path-to-hg/mercurial/commandserver.py", line 701, in _runworker
    prereposetups=[self._reposetup],
  File "path-to-hg/mercurial/commandserver.py", line 470, in _serverequest
    sv.cleanup()
  File "path-to-hg/mercurial/chgserver.py", line 381, in cleanup
    self._restoreio()
  File "path-to-hg/mercurial/chgserver.py", line 444, in _restoreio
    os.dup2(fd, fp.fileno())
OSError: [Errno 16] Device or resource busy
```

[man dup2] indicates that, on Linux, EBUSY comes from a race condition
between open() and dup2().

However it's not clear why open() race occurred for newfd=stdin/out/err.

We suppress the OSError in _restoreio() since the forked worker process will
finish anyway and add some logging.

Thanks to Mitchell Plamann for a detailed bug description and Yuya Nishihara for
suggesting the fix.
Yuya Nishihara - July 3, 2020, 10:22 a.m.
On Fri, 03 Jul 2020 15:07:52 +0530, Pulkit Goyal wrote:
> # HG changeset patch
> # User Pulkit Goyal <7895pulkit@gmail.com>
> # Date 1593764159 -19800
> #      Fri Jul 03 13:45:59 2020 +0530
> # Node ID fa76d3882134a36dc13bba6a3499e11590505258
> # Parent  3707f6e7e04e071c7a87f781718701b28bd9a877
> # EXP-Topic issue6330
> chg: suppress OSError in _restoreio() and add some logging (issue6330)

Queued with minor tweaks, thanks.

> According to issue6330, running chg on heavy loaded systems can lead to
> following error:
> 
> ```
> Traceback (most recent call last):
>   File "path-to-hg/mercurial/commandserver.py", line 650, in _acceptnewconnection
>     self._runworker(conn)
>   File "path-to-hg/mercurial/commandserver.py", line 701, in _runworker
>     prereposetups=[self._reposetup],
>   File "path-to-hg/mercurial/commandserver.py", line 470, in _serverequest
>     sv.cleanup()
>   File "path-to-hg/mercurial/chgserver.py", line 381, in cleanup
>     self._restoreio()
>   File "path-to-hg/mercurial/chgserver.py", line 444, in _restoreio
>     os.dup2(fd, fp.fileno())
> OSError: [Errno 16] Device or resource busy
> ```
> 
> [man dup2] indicates that, on Linux, EBUSY comes from a race condition
> between open() and dup2().
> 
> However it's not clear why open() race occurred for newfd=stdin/out/err.

Copied to inline comment.

> diff --git a/mercurial/chgserver.py b/mercurial/chgserver.py
> --- a/mercurial/chgserver.py
> +++ b/mercurial/chgserver.py
> @@ -442,7 +442,14 @@ class chgcmdserver(commandserver.server)
>              if newfp is not fp:
>                  newfp.close()
>              # restore original fd: fp is open again
> -            os.dup2(fd, fp.fileno())
> +            try:
> +                os.dup2(fd, fp.fileno())
> +            except OSError as err:
> +                self.ui.log(
> +                    b'chgcmdserver',

s/chgcmdserver/chgserver/ for consistency.

> +                    b'got %s while duplicating %s',

'\n'

> +                    (pycompat.bytestr(err), fn),

stringutil.forcebytestr() in case err contained 8-bit character.
And dropped () as ui.log() takes *msgargs.
Pulkit Goyal - July 3, 2020, 10:50 a.m.
On Fri, Jul 3, 2020 at 3:55 PM Yuya Nishihara <yuya@tcha.org> wrote:
>
> On Fri, 03 Jul 2020 15:07:52 +0530, Pulkit Goyal wrote:
> > # HG changeset patch
> > # User Pulkit Goyal <7895pulkit@gmail.com>
> > # Date 1593764159 -19800
> > #      Fri Jul 03 13:45:59 2020 +0530
> > # Node ID fa76d3882134a36dc13bba6a3499e11590505258
> > # Parent  3707f6e7e04e071c7a87f781718701b28bd9a877
> > # EXP-Topic issue6330
> > chg: suppress OSError in _restoreio() and add some logging (issue6330)
>
> Queued with minor tweaks, thanks.

Thanks a lot for the tweaks Yuya!
>
> > According to issue6330, running chg on heavy loaded systems can lead to
> > following error:
> >
> > ```
> > Traceback (most recent call last):
> >   File "path-to-hg/mercurial/commandserver.py", line 650, in _acceptnewconnection
> >     self._runworker(conn)
> >   File "path-to-hg/mercurial/commandserver.py", line 701, in _runworker
> >     prereposetups=[self._reposetup],
> >   File "path-to-hg/mercurial/commandserver.py", line 470, in _serverequest
> >     sv.cleanup()
> >   File "path-to-hg/mercurial/chgserver.py", line 381, in cleanup
> >     self._restoreio()
> >   File "path-to-hg/mercurial/chgserver.py", line 444, in _restoreio
> >     os.dup2(fd, fp.fileno())
> > OSError: [Errno 16] Device or resource busy
> > ```
> >
> > [man dup2] indicates that, on Linux, EBUSY comes from a race condition
> > between open() and dup2().
> >
> > However it's not clear why open() race occurred for newfd=stdin/out/err.
>
> Copied to inline comment.
>
> > diff --git a/mercurial/chgserver.py b/mercurial/chgserver.py
> > --- a/mercurial/chgserver.py
> > +++ b/mercurial/chgserver.py
> > @@ -442,7 +442,14 @@ class chgcmdserver(commandserver.server)
> >              if newfp is not fp:
> >                  newfp.close()
> >              # restore original fd: fp is open again
> > -            os.dup2(fd, fp.fileno())
> > +            try:
> > +                os.dup2(fd, fp.fileno())
> > +            except OSError as err:
> > +                self.ui.log(
> > +                    b'chgcmdserver',
>
> s/chgcmdserver/chgserver/ for consistency.
>
> > +                    b'got %s while duplicating %s',
>
> '\n'
>
> > +                    (pycompat.bytestr(err), fn),
>
> stringutil.forcebytestr() in case err contained 8-bit character.
> And dropped () as ui.log() takes *msgargs.

Patch

diff --git a/mercurial/chgserver.py b/mercurial/chgserver.py
--- a/mercurial/chgserver.py
+++ b/mercurial/chgserver.py
@@ -442,7 +442,14 @@  class chgcmdserver(commandserver.server)
             if newfp is not fp:
                 newfp.close()
             # restore original fd: fp is open again
-            os.dup2(fd, fp.fileno())
+            try:
+                os.dup2(fd, fp.fileno())
+            except OSError as err:
+                self.ui.log(
+                    b'chgcmdserver',
+                    b'got %s while duplicating %s',
+                    (pycompat.bytestr(err), fn),
+                )
             os.close(fd)
             setattr(self, cn, ch)
             setattr(ui, fn, fp)