{"thread":{"id":"37850","subject":"[RFC] Git.pm: stat the FD to ensure the file is really open","startedAt":"2014-10-30T22:08:36Z","lastAt":"2014-10-31T01:26:48Z","messageCount":3,"participants":["Eric Wong","Kyle J. McKay"],"isPatch":false,"patchVersion":null,"patchTotal":null},"messages":[{"id":"251249","messageId":"20141030220836.GA7873@dcvr.yhbt.net","threadId":"37850","inReplyTo":null,"subject":"[RFC] Git.pm: stat the FD to ensure the file is really open","fromName":"Eric Wong","fromEmail":"normalperson@yhbt.net","sentAt":"2014-10-30T22:08:36Z","receivedAt":"2014-10-30T22:08:36Z","isPatch":false,"sender":{"key":"e@80x24.org","avatar":null},"body":"For a (currently) unknown reason, Git::SVN::Fetcher::close_file\nsometimes triggers \"Bad file descriptor\" errors on syswrite when\nwriting symlink contents on the \"svn_hash\" tempfile.\n\nThe current IO::Handle::opened call in Git.pm is not a\nsufficient check, as the underlying file descriptor is closed\nwithout the PerlIO layer knowing about it.  This is likely a bug\ninside libsvn (1.6.17), as none of the Git.pm or Git::SVN\nmodules close IOs without the knowledge of the PerlIO layer.\n\nCc: Kyle J. McKay <mackyle@gmail.com>\nSigned-off-by: Eric Wong <normalperson@yhbt.net>\n---\n Kyle/Junio: thoughts?  I'm running out of time to track this down\n so it might be necessary for 2.2-rc0.  What's even stranger is\n I cannot always reproduce the problem even without this patch,\n so it may be only triggered by network latency...\n Thanks.\n\n perl/Git.pm | 18 ++++++++++++++----\n 1 file changed, 14 insertions(+), 4 deletions(-)\n\ndiff --git a/perl/Git.pm b/perl/Git.pm\nindex b5905ee..f1f210b 100644\n--- a/perl/Git.pm\n+++ b/perl/Git.pm\n@@ -99,7 +99,7 @@ increase notwithstanding).\n =cut\n \n \n-use Carp qw(carp croak); # but croak is bad - throw instead\n+use Carp qw(carp croak cluck); # but croak is bad - throw instead\n use Error qw(:try);\n use Cwd qw(abs_path cwd);\n use IPC::Open2 qw(open2);\n@@ -1206,6 +1206,16 @@ sub temp_acquire {\n \t$temp_fd;\n }\n \n+sub _temp_really_open {\n+\tmy ($fh) = @_;\n+\n+\tif (defined($fh) && $fh->opened) {\n+\t\treturn 1 if stat($fh);\n+\t\tcluck(\"$fh closed independently of PerlIO\\n\");\n+\t}\n+\treturn 0;\n+}\n+\n =item temp_is_locked ( NAME )\n \n Returns true if the internal lock created by a previous C<temp_acquire()>\n@@ -1232,7 +1242,7 @@ sub temp_is_locked {\n \tmy ($self, $name) = _maybe_self(@_);\n \tmy $temp_fd = \\$TEMP_FILEMAP{$name};\n \n-\tdefined $$temp_fd && $$temp_fd->opened && $TEMP_FILES{$$temp_fd}{locked};\n+\t_temp_really_open($$temp_fd) && $TEMP_FILES{$$temp_fd}{locked};\n }\n \n =item temp_release ( NAME )\n@@ -1264,7 +1274,7 @@ sub temp_release {\n \t\tcarp \"Attempt to release temp file '\",\n \t\t\t$temp_fd, \"' that has not been locked\";\n \t}\n-\ttemp_reset($temp_fd) if $trunc and $temp_fd->opened;\n+\ttemp_reset($temp_fd) if $trunc && _temp_really_open($temp_fd);\n \n \t$TEMP_FILES{$temp_fd}{locked} = 0;\n \tundef;\n@@ -1276,7 +1286,7 @@ sub _temp_cache {\n \t_verify_require();\n \n \tmy $temp_fd = \\$TEMP_FILEMAP{$name};\n-\tif (defined $$temp_fd and $$temp_fd->opened) {\n+\tif (_temp_really_open($$temp_fd)) {\n \t\tif ($TEMP_FILES{$$temp_fd}{locked}) {\n \t\t\tthrow Error::Simple(\"Temp file with moniker '\" .\n \t\t\t\t$name . \"' already in use\");\n-- \nEW\n"},{"id":"251254","messageId":"4DCE1FB9-F0FA-48FD-866C-67E7C2E97951@gmail.com","threadId":"37850","inReplyTo":"20141030220836.GA7873@dcvr.yhbt.net","subject":"Re: [RFC] Git.pm: stat the FD to ensure the file is really open","fromName":"Kyle J. McKay","fromEmail":"mackyle@gmail.com","sentAt":"2014-10-31T00:13:51Z","receivedAt":"2014-10-31T00:13:51Z","isPatch":false,"sender":{"key":"mackyle@gmail.com","avatar":"https://avatars.githubusercontent.com/u/813346?v=4"},"body":"On Oct 30, 2014, at 15:08, Eric Wong wrote:\n> For a (currently) unknown reason, Git::SVN::Fetcher::close_file\n> sometimes triggers \"Bad file descriptor\" errors on syswrite when\n> writing symlink contents on the \"svn_hash\" tempfile.\n>\n> The current IO::Handle::opened call in Git.pm is not a\n> sufficient check, as the underlying file descriptor is closed\n> without the PerlIO layer knowing about it.  This is likely a bug\n> inside libsvn (1.6.17), as none of the Git.pm or Git::SVN\n> modules close IOs without the knowledge of the PerlIO layer.\n>\n> Cc: Kyle J. McKay <mackyle@gmail.com>\n> Signed-off-by: Eric Wong <normalperson@yhbt.net>\n> ---\n> Kyle/Junio: thoughts?  I'm running out of time to track this down\n> so it might be necessary for 2.2-rc0.  What's even stranger is\n> I cannot always reproduce the problem even without this patch,\n> so it may be only triggered by network latency...\n> Thanks.\n\nWith this patch added, do you then see the warning:\n\n   carp \"Temp file '\", $name,\n\t\"' was closed. Opening replacement.\";\n\n From _temp_cache?  It would seem odd if you didn't unless there was  \nonly one symlink involved.\n\nI suspect that symlinks were rare in the repositories I was testing  \nagainst.  I wonder if having a test svn repo that adds several new  \nsymlinks for several revisions in a row might trigger this problem  \nmore robustly.\n\nThe _repository->temp_acquire('svn_hash') call is assigned to a \"my\"  \nvariable and then has Git::temp_release called on it later in the same  \nfunction and the only calls made on it in between are Git::temp_path,  \nso I don't see how the libsvn library could be responsible for closing  \nit since it looks to me like it never sees it.  But I'm looking at  \nv2.1.2 of Fetcher.pm, so if some other calls have been inserted there  \nsince then.\n\n> perl/Git.pm | 18 ++++++++++++++----\n> 1 file changed, 14 insertions(+), 4 deletions(-)\n>\n> diff --git a/perl/Git.pm b/perl/Git.pm\n> index b5905ee..f1f210b 100644\n> --- a/perl/Git.pm\n> +++ b/perl/Git.pm\n> @@ -99,7 +99,7 @@ increase notwithstanding).\n> =cut\n>\n>\n> -use Carp qw(carp croak); # but croak is bad - throw instead\n> +use Carp qw(carp croak cluck); # but croak is bad - throw instead\n> use Error qw(:try);\n> use Cwd qw(abs_path cwd);\n> use IPC::Open2 qw(open2);\n> @@ -1206,6 +1206,16 @@ sub temp_acquire {\n> \t$temp_fd;\n> }\n>\n> +sub _temp_really_open {\n> +\tmy ($fh) = @_;\n> +\n> +\tif (defined($fh) && $fh->opened) {\n> +\t\treturn 1 if stat($fh);\n> +\t\tcluck(\"$fh closed independently of PerlIO\\n\");\n> +\t}\n> +\treturn 0;\n> +}\n> +\n> =item temp_is_locked ( NAME )\n>\n> Returns true if the internal lock created by a previous  \n> C<temp_acquire()>\n> @@ -1232,7 +1242,7 @@ sub temp_is_locked {\n> \tmy ($self, $name) = _maybe_self(@_);\n> \tmy $temp_fd = \\$TEMP_FILEMAP{$name};\n>\n> -\tdefined $$temp_fd && $$temp_fd->opened && $TEMP_FILES{$$temp_fd} \n> {locked};\n> +\t_temp_really_open($$temp_fd) && $TEMP_FILES{$$temp_fd}{locked};\n> }\n>\n> =item temp_release ( NAME )\n> @@ -1264,7 +1274,7 @@ sub temp_release {\n> \t\tcarp \"Attempt to release temp file '\",\n> \t\t\t$temp_fd, \"' that has not been locked\";\n> \t}\n> -\ttemp_reset($temp_fd) if $trunc and $temp_fd->opened;\n> +\ttemp_reset($temp_fd) if $trunc && _temp_really_open($temp_fd);\n>\n> \t$TEMP_FILES{$temp_fd}{locked} = 0;\n> \tundef;\n> @@ -1276,7 +1286,7 @@ sub _temp_cache {\n> \t_verify_require();\n>\n> \tmy $temp_fd = \\$TEMP_FILEMAP{$name};\n> -\tif (defined $$temp_fd and $$temp_fd->opened) {\n> +\tif (_temp_really_open($$temp_fd)) {\n> \t\tif ($TEMP_FILES{$$temp_fd}{locked}) {\n> \t\t\tthrow Error::Simple(\"Temp file with moniker '\" .\n> \t\t\t\t$name . \"' already in use\");\n> -- \n> EW\n\nThe changes themselves look okay, but eeewwww.  I don't see how libsvn  \ncan see the svn_hash fd to close it unless it's randomly closing fds.\n\n--Kyle\n"},{"id":"251256","messageId":"20141031012648.GA25698@dcvr.yhbt.net","threadId":"37850","inReplyTo":"4DCE1FB9-F0FA-48FD-866C-67E7C2E97951@gmail.com","subject":"Re: [RFC] Git.pm: stat the FD to ensure the file is really open","fromName":"Eric Wong","fromEmail":"normalperson@yhbt.net","sentAt":"2014-10-31T01:26:48Z","receivedAt":"2014-10-31T01:26:48Z","isPatch":false,"sender":{"key":"e@80x24.org","avatar":null},"body":"\"Kyle J. McKay\" <mackyle@gmail.com> wrote:\n> On Oct 30, 2014, at 15:08, Eric Wong wrote:\n> >For a (currently) unknown reason, Git::SVN::Fetcher::close_file\n> >sometimes triggers \"Bad file descriptor\" errors on syswrite when\n> >writing symlink contents on the \"svn_hash\" tempfile.\n> >\n> >The current IO::Handle::opened call in Git.pm is not a\n> >sufficient check, as the underlying file descriptor is closed\n> >without the PerlIO layer knowing about it.  This is likely a bug\n> >inside libsvn (1.6.17), as none of the Git.pm or Git::SVN\n> >modules close IOs without the knowledge of the PerlIO layer.\n> >\n> >Cc: Kyle J. McKay <mackyle@gmail.com>\n> >Signed-off-by: Eric Wong <normalperson@yhbt.net>\n> >---\n> >Kyle/Junio: thoughts?  I'm running out of time to track this down\n> >so it might be necessary for 2.2-rc0.  What's even stranger is\n> >I cannot always reproduce the problem even without this patch,\n> >so it may be only triggered by network latency...\n> >Thanks.\n> \n> With this patch added, do you then see the warning:\n> \n>   carp \"Temp file '\", $name,\n> \t\"' was closed. Opening replacement.\";\n> \n> From _temp_cache?  It would seem odd if you didn't unless there was\n> only one symlink involved.\n\nNope.  $$temp_fd was defined so the message is not hit.\nIs suppose we can also make the following change:\n\n--- a/perl/Git.pm\n+++ b/perl/Git.pm\n@@ -1282,11 +1282,9 @@ sub _temp_cache {\n \t\t\t\t$name . \"' already in use\");\n \t\t}\n \t} else {\n-\t\tif (defined $$temp_fd) {\n-\t\t\t# then we're here because of a closed handle.\n-\t\t\tcarp \"Temp file '\", $name,\n-\t\t\t\t\"' was closed. Opening replacement.\";\n-\t\t}\n+\t\t# then we're here because of a closed handle.\n+\t\tcarp \"Temp file '\", $name,\n+\t\t\t\"' was closed. Opening replacement.\";\n \t\tmy $fname;\n \n \t\tmy $tmpdir;\n\n> I suspect that symlinks were rare in the repositories I was testing\n> against.  I wonder if having a test svn repo that adds several new\n> symlinks for several revisions in a row might trigger this problem\n> more robustly.\n> \n> The _repository->temp_acquire('svn_hash') call is assigned to a \"my\"\n> variable and then has Git::temp_release called on it later in the\n> same function and the only calls made on it in between are\n> Git::temp_path, so I don't see how the libsvn library could be\n> responsible for closing it since it looks to me like it never sees\n> it.  But I'm looking at v2.1.2 of Fetcher.pm, so if some other calls\n> have been inserted there since then.\n\nI stared at it for a long while and could not figure out what was going\non, either.  The other temp_acquire users are far less straightforward\nand did not get mysteriously closed.\n\n> The changes themselves look okay, but eeewwww.  I don't see how\n> libsvn can see the svn_hash fd to close it unless it's randomly\n> closing fds.\n\nRight.  Even worse, I can't even get it to trigger anymore...\nThanks for your response!\n"}]}