Git-Credential-Manager-for-Windows icon indicating copy to clipboard operation
Git-Credential-Manager-for-Windows copied to clipboard

Unhandled Exception: System.ObjectDisposedException: Cannot access a closed file.

Open chucklu opened this issue 8 years ago • 30 comments

Hi, When I try to git push ,I got this exception.

$ git push
fatal: TaskCanceledException encountered.
   A task was canceled.

Unhandled Exception: System.ObjectDisposedException: Cannot access a closed file.
   at System.IO.__Error.FileNotOpen()
   at System.IO.FileStream.Flush(Boolean flushToDisk)
   at System.IO.StreamWriter.Flush(Boolean flushStream, Boolean flushEncoder)
   at Microsoft.Alm.Git.Trace.Microsoft.Alm.Git.ITrace.Flush()
   at Microsoft.Alm.Cli.ConsoleFunctions.Exit(Program program, Int32 exitcode, String message, String path, Int32 line, String name)
   at Microsoft.Alm.Cli.Program.Exit(Int32 exitcode, String message, String path, Int32 line, String name)
   at Microsoft.Alm.Cli.CommonFunctions.DieMessage(Program program, String message, String path, Int32 line, String name)
   at Microsoft.Alm.Cli.Program.Die(String message, String path, Int32 line, String name)
   at Microsoft.Alm.Cli.CommonFunctions.DieException(Program program, Exception exception, String path, Int32 line, String name)
   at Microsoft.Alm.Cli.Program.Die(Exception exception, String path, Int32 line, String name)
   at Microsoft.Alm.Cli.Program.Run(String[] args)
   at Microsoft.Alm.Cli.Program.Main(String[] args)
fatal: TaskCanceledException encountered.
   A task was canceled.

Unhandled Exception: System.ObjectDisposedException: Cannot access a closed file.
   at System.IO.__Error.FileNotOpen()
   at System.IO.FileStream.Flush(Boolean flushToDisk)
   at System.IO.StreamWriter.Flush(Boolean flushStream, Boolean flushEncoder)
   at Microsoft.Alm.Git.Trace.Microsoft.Alm.Git.ITrace.Flush()
   at Microsoft.Alm.Cli.ConsoleFunctions.Exit(Program program, Int32 exitcode, String message, String path, Int32 line, String name)
   at Microsoft.Alm.Cli.Program.Exit(Int32 exitcode, String message, String path, Int32 line, String name)
   at Microsoft.Alm.Cli.CommonFunctions.DieMessage(Program program, String message, String path, Int32 line, String name)
   at Microsoft.Alm.Cli.Program.Die(String message, String path, Int32 line, String name)
   at Microsoft.Alm.Cli.CommonFunctions.DieException(Program program, Exception exception, String path, Int32 line, String name)
   at Microsoft.Alm.Cli.Program.Die(Exception exception, String path, Int32 line, String name)
   at Microsoft.Alm.Cli.Program.Run(String[] args)
   at Microsoft.Alm.Cli.Program.Main(String[] args)

chucklu avatar Aug 16 '17 10:08 chucklu

@chucklu the stack trace you've shared points to the standard pipe being closed prior to the GCM exiting, which caused the GCM to hit an access violation.

Could you setup some log gathering to provide additional data/information? If so:

  1. Open Command Prompt
  2. Run SET GIT_TRACE 1
  3. Run SET GCM_TRACE 1
  4. cd into the root of the repository where the error occurs.
  5. Run git push
  6. Copy the output and paste into this thread as a response - please remove any private and/or secret data contained in the output.

whoisj avatar Aug 16 '17 17:08 whoisj

@whoisj hi,what did you mean by “Command Prompt”? I try to run the command in cmd.exe of windows,I got this "Environment variable git_trace 1 not defined". I try to run the command in git bash,then git push again. I just got the same exception as I submit above.

Another detail is ,I have run the command "git config credential.writelog true ". But when I open the .git\credential.log,there is nothing in it,just an empty file.

chucklu avatar Aug 17 '17 02:08 chucklu

Hi, I find how to run the command you mentioned above How can I debug git/git-shell related problems? Then I got the detail: 10:35:36.004889 ...tionArguments.cs:528 trace: [SetProxy] failed to parse 'domain:port'. 10:35:36.004889 ...tionArguments.cs:531 trace: [SetProxy] proxy cleared. 10:35:36.005892 ...\Common.cs:243 trace: [EnableTraceLogging] trace logging enabled. 10:35:36.027952 ...\Common.cs:74 trace: [CreateAuthentication] detecting authority type for 'https://github.com/'. 10:35:36.037978 ...uthentication.cs:134 trace: [GetAuthentication] created GitHub authentication for 'https://github.com/'. 10:35:36.037978 ...\Common.cs:139 trace: [CreateAuthentication] authority for 'https://github.com/' is GitHub. 10:35:36.048005 ...seSecureStore.cs:134 trace: [ReadCredentials] credentials for 'git:https://github.com' read from store. 10:35:36.049008 ...uthentication.cs:163 trace: [GetCredentials] credentials for 'https://github.com/' found. 10:35:51.075325 ...\Program.cs:422 trace: [Run] System.Threading.Tasks.TaskCanceledException: A task was canceled. 10:35:51.076326 ...\Common.cs:492 trace: [LogEvent] System.Threading.Tasks.TaskCanceledException: A task was canceled.

chucklu avatar Aug 17 '17 02:08 chucklu

Thanks for that!

10:35:36.004889 ...tionArguments.cs:528 trace: [SetProxy] failed to parse 'domain:port'.

Given the above error, what does your remote URL look like?

whoisj avatar Aug 17 '17 05:08 whoisj

13:18:44.118297 ...\Common.cs:461 trace: [LoadOperationArguments] http.pro xy = 'shanghai01prx11_p.net.github.net:8080'.

@whoisj something like this

chucklu avatar Aug 17 '17 05:08 chucklu

@whoisj hi, I have test the SetProxy method in class Impl in file git-credential-manager-for-windows\cli-shared\operationarguments.cs It seems that I need add http:// for the proxy, otherwise Uri.TryCreate(url, UriKind.Absolute, out tmp) will return false.

chucklu avatar Aug 17 '17 05:08 chucklu

I add the http:// for the http.proxy,then the gcm works.

hi,I think you can add the http:// for the url without it automatically.

chucklu avatar Aug 17 '17 06:08 chucklu

I think you can add the http:// for the url without it automatically.

I could, but it's the .NET Framework complaining about the URL format. To detect and correct, I'd have to design, author, develop, and maintain URL parsing code for the GCM. That seems fraught with error - additionally, proxies can use any protocol so assuming "http://" could be even worse as the network attempt would just fail without much feedback as to why.

I am very happy that you figured out the issues. Enjoy!

whoisj avatar Aug 17 '17 13:08 whoisj

@whoisj hi ,I understand your concern. But the git for windows can recognize the proxy url without http:// .

chucklu avatar Aug 18 '17 01:08 chucklu

@whoisj hi ,I understand your concern. But the git for windows can recognize the proxy url without http:// .

Fair enough then, I'll take a note and see what can be done. Thanks again. 😄

whoisj avatar Aug 18 '17 03:08 whoisj

Am experiencing this this evening. No proxies involved.

fatal: HttpRequestException encountered.
   An error occurred while sending the request.

Unhandled Exception: System.ObjectDisposedException: Cannot access a closed file.
   at System.IO.__Error.FileNotOpen()
   at System.IO.FileStream.Flush(Boolean flushToDisk)
   at System.IO.StreamWriter.Flush(Boolean flushStream, Boolean flushEncoder)
   at Microsoft.Alm.Git.Trace.Microsoft.Alm.Git.ITrace.Flush()
   at Microsoft.Alm.Cli.Program.Die(String message)
   at Microsoft.Alm.Cli.Program.Die(Exception exception)
   at Microsoft.Alm.Cli.Program.Main(String[] args)

with tracing:

D:\src\mws-advanced>git push origin master
01:13:32.033344 git.c:371               trace: built-in: git 'push' 'origin' 'master'
01:13:32.073357 run-command.c:369       trace: run_command: 'git-remote-https' 'origin' 'https://github.com/ericblade/mws-advanced.git'
01:13:36.510318 run-command.c:369       trace: run_command: 'git credential-manager get'
01:13:36.580816 git.c:596               trace: exec: 'git-credential-manager' 'get'
01:13:36.580816 run-command.c:369       trace: run_command: 'git-credential-manager' 'get'
01:13:36.650816 ...\Program.cs:671      trace: [Main] git-credential-manager (v1.9.0) 'get'
01:13:36.680825 ...Configuration.cs:243 trace: [LoadGitConfiguration] git Portable, UserOnly config read, 35 entries.
01:13:36.698823 ...\Where.cs:231        trace: [FindGitInstallations] found 1 Git installation(s).
01:13:36.700824 ...Configuration.cs:243 trace: [LoadGitConfiguration] git All config read, 49 entries.
01:13:36.702823 ...\Program.cs:686      trace: [EnableTraceLogging] trace logging enabled.
01:13:36.702823 ...\Program.cs:691      trace: [EnableTraceLogging] git local config found at 'D:\src\mws-advanced\.git\config'.
01:13:36.704823 ...\Program.cs:737      trace: [EnableTraceLogging] trace log destination is 'D:\src\mws-advanced\.git'.
01:13:36.714825 ...\Program.cs:384      trace: [CreateAuthentication] detecting authority type for 'https://github.com/'.
01:13:36.720826 ...uthentication.cs:126 trace: [GetAuthentication] created GitHub authentication for 'https://github.com/'.
01:13:36.720826 ...\Program.cs:442      trace: [CreateAuthentication] authority for 'https://github.com/' is GitHub.
01:13:36.726822 ...seSecureStore.cs:134 trace: [ReadCredentials] credentials for 'git:https://github.com' read from store.
01:13:36.726822 ...uthentication.cs:153 trace: [GetCredentials] credentials for 'https://github.com/' found.
01:13:36.834312 ...\Program.cs:152      trace: [Die] System.Net.Http.HttpRequestException: An error occurred while sending the request. ---> System.Net.WebException: The request was aborted: Could not create SSL/TLS secure channel.
   at System.Net.HttpWebRequest.EndGetResponse(IAsyncResult asyncResult)
   at System.Net.Http.HttpClientHandler.GetResponseCallback(IAsyncResult ar)
   --- End of inner exception stack trace ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at GitHub.Authentication.Authority.<ValidateCredentials>d__6.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at GitHub.Authentication.Authentication.<ValidateCredentials>d__29.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Microsoft.Alm.Cli.Program.<>c__DisplayClass99_4.<<QueryCredentials>b__4>d.MoveNext()
01:13:36.835305 ...\Program.cs:193      trace: [LogEvent] System.Net.Http.HttpRequestException: An error occurred while sending the request. ---> System.Net.WebException: The request was aborted: Could not create SSL/TLS secure channel.
   at System.Net.HttpWebRequest.EndGetResponse(IAsyncResult asyncResult)
   at System.Net.Http.HttpClientHandler.GetResponseCallback(IAsyncResult ar)
   --- End of inner exception stack trace ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at GitHub.Authentication.Authority.<ValidateCredentials>d__6.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at GitHub.Authentication.Authentication.<ValidateCredentials>d__29.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Microsoft.Alm.Cli.Program.<>c__DisplayClass99_4.<<QueryCredentials>b__4>d.MoveNext()
01:13:36.836299 ...\Program.cs:170      trace: [Die] fatal: HttpRequestException encountered.
   An error occurred while sending the request.
fatal: HttpRequestException encountered.
   An error occurred while sending the request.

Unhandled Exception: System.ObjectDisposedException: Cannot access a closed file.
   at System.IO.__Error.FileNotOpen()
   at System.IO.FileStream.Flush(Boolean flushToDisk)
   at System.IO.StreamWriter.Flush(Boolean flushStream, Boolean flushEncoder)
   at Microsoft.Alm.Git.Trace.Microsoft.Alm.Git.ITrace.Flush()
   at Microsoft.Alm.Cli.Program.Die(String message)
   at Microsoft.Alm.Cli.Program.Die(Exception exception)
   at Microsoft.Alm.Cli.Program.Main(String[] args)
01:13:36.846432 run-command.c:369       trace: run_command: 'bash' '-c' 'cat >/dev/tty && read -r line </dev/tty && echo "$line"'
Username for 'https://github.com': ^C

WSL git is also not working, but setting GIT_TRACE there does nothing.

ericblade avatar Feb 23 '18 06:02 ericblade

Hi @ericblade , I find the error message in your output. "Could not create SSL/TLS secure channel" And I found someone else already submit another issue https://github.com/Microsoft/Git-Credential-Manager-for-Windows/issues/555 . There is a solution in that issue: Updating git to 2.16.2.windows.1 solved the issue.

chucklu avatar Feb 23 '18 06:02 chucklu

@ericblade the most likely root cause for you issue is that GitHub rolled out TLS 1.2 as a requirement today. The GCM was updated to meet the requirement as of v1.14.0 (Git for Windows v2.16.2 or better). Updating either ought to resolve your issue.

whoisj avatar Feb 23 '18 06:02 whoisj

great, that did it, thanks. was going to look at that today, but hadn't had time until just now. All good now.

ericblade avatar Feb 23 '18 23:02 ericblade

@whoisj I think my problems were caused by the GitHub TLS 1.2 roll out. First I had this issue which was fixed by installing the latest git for windows. This ObjectDisposedException was solved by installing the latest Visual Studio. I was not that far behind in updates. I assume many more will encounter this.

pauldendulk avatar Feb 24 '18 08:02 pauldendulk

I think my problems were caused the the GitHub TLS 1.2 roll out. First I had this issue which was fixed by installing the latest git for windows. This ObjectDisposedException was solved by installing the latest Visual Studio. I was not that far behind in updates. I assume many more will encounter this.

Highly possible. Visual Studio, prior to 15.5.7, had TLS 1.2 disabled for all of its .NET Framework dependent components (of which authentication is one of them). Starting with 15.5.7, we've scoured the product enabling TLS 1.2 every place possible.

Unfortunately, you're correct that many people will run into this problem. Luckily we've many, many channels for getting the necessary updates to them. Hopefully it'll work itself out quickly.

whoisj avatar Feb 24 '18 15:02 whoisj

@whoisj The update was an easy fix but there might be some frustration before they find out they need to update.

pauldendulk avatar Feb 25 '18 10:02 pauldendulk

@pauldendulk I agree and it's unfortunate. We (Microsoft) are working closely with GitHub at options to avoid sudden service interruptions like this one, in the future.

whoisj avatar Feb 25 '18 16:02 whoisj

@whoisj any luck on Visual studio fix? I updated git and Git bash is good not but VS2013 is still complaining.

anoop-sha avatar Feb 26 '18 19:02 anoop-sha

@anoopqai have you read this notice?

https://github.com/Microsoft/Git-Credential-Manager-for-Windows#notice-experiencing-github-pushfetch-problems

If not, please do. If that doesn't work for you, then we can dig in deeper.

whoisj avatar Feb 27 '18 19:02 whoisj

@whoisj I encounter the same problem again, however it will not block the push action.

15:18:42.690275 run-command.c:640 trace: run_command: git-credential-manag er get 15:18:42.814610 ...\Common.cs:636 trace: [Main] git-credential-manager (v1.15.2) 'get' 15:18:42.885309 ...\Where.cs:236 trace: [FindGitInstallations] found 1 Git installation(s). 15:18:42.891610 ...Configuration.cs:218 trace: [LoadGitConfiguration] git All config read, 35 entries. 15:18:42.895621 ...\Where.cs:236 trace: [FindGitInstallations] found 1 Git installation(s). 15:18:42.897624 ...Configuration.cs:218 trace: [LoadGitConfiguration] git All config read, 35 entries. 15:18:42.902638 ...\Common.cs:505 trace: [LoadOperationArguments] httpProxy = 'domain:port'. 15:18:42.903641 ...tionArguments.cs:430 trace: [SetProxy] failed to parse 'domain:port'. 15:18:42.903641 ...tionArguments.cs:433 trace: [SetProxy] proxy cleared. 15:18:42.934725 ...\Common.cs:80 trace: [CreateAuthentication] detecting authority type for 'https://github.com/'. 15:18:42.947771 ...uthentication.cs:130 trace: [GetAuthentication] created GitHub authentication for 'https://github.com/'. 15:18:42.947771 ...\Common.cs:147 trace: [CreateAuthentication] authority for 'https://github.com/' is GitHub. 15:18:42.972830 ...seSecureStore.cs:138 trace: [ReadCredentials] credentials for 'git:https://github.com' read from store. 15:18:42.973833 ...uthentication.cs:156 trace: [GetCredentials] credentials for 'https://github.com/' found. 15:18:58.010515 ...\Program.cs:492 trace: [Run] System.Threading.Tasks.TaskCanceledException: A task was canceled. 15:18:58.011518 ...\Common.cs:601 trace: [LogEvent] System.Threading.Tasks.TaskCanceledException: A task was canceled. 15:18:58.014526 ...\Program.cs:492 trace: [Run] fatal: TaskCanceledException encountered. A task was canceled. fatal: TaskCanceledException encountered. A task was canceled. 15:18:58.056637 run-command.c:640 trace: run_command: 'git credential-store get' 15:18:58.159470 git.c:576 trace: exec: git-credential-store get 15:18:58.161441 run-command.c:640 trace: run_command: git-credential-store get

It will continue the push task and do it successfully.

I have checked the proxy configured , it was set with http

git config --global --list http.proxy=http://domain:port

chucklu avatar Jun 19 '18 07:06 chucklu

15:18:42.903641 ...tionArguments.cs:430 trace: [SetProxy] failed to parse 'domain:port'. 15:18:42.903641 ...tionArguments.cs:433 trace: [SetProxy] proxy cleared.

This is the .NET Framework System.Uri giving me heartburn. Seriously becoming a non-fan of that type.

Thanks for the report, I'll try to look at the code this afternoon and see if there's anything I can do to work around System.Uri limitations.

whoisj avatar Jun 19 '18 14:06 whoisj

Hi, same issue here with the proxy. Using a localmachine px proxy to automatically login a company NTLM authenticated proxy.

Everything was working fine until I updated today Git for windows, since then I have the same issue:

16:57:09.800035 ...\Common.cs:464       trace: [LoadOperationArguments] http.proxy = '127.0.0.1:3128'.
16:57:09.801039 ...tionArguments.cs:524 trace: [SetProxy] failed to parse '127.0.0.1:3128'.
16:57:09.801039 ...tionArguments.cs:527 trace: [SetProxy] proxy cleared.

Using http made no difference to me but logs changed:

trace: [LoadOperationArguments] http.proxy = 'http://127.0.0.1:3128'.
trace: [SetProxy] successfully set proxy to 'http://127.0.0.1:3128/'.
trace: [CreateAuthentication] detecting authority type for 'https://aasolutions.visualstudio.com/'.
trace: [DetectAuthority] 'https://aasolutions.visualstudio.com/' is subdomain of 'visualstudio.com', checking AAD vs MSA.
trace: [CreateAuthentication] authority for 'https://aasolutions.visualstudio.com/' is Azure Directory.
trace: [DetectAuthority] 'https://aasolutions.visualstudio.com/' is subdomain of 'visualstudio.com', checking AAD vs MSA.
trace: [ReadCredentials] credentials for 'git:https://aasolutions.visualstudio.com' read from store.
trace: [GetCredentials] credentials for 'https://aasolutions.visualstudio.com/' found.
trace: [ValidateCredentials] validating credentials against 'https://aasolutions.visualstudio.com/_apis/connectiondata'.
trace: [ValidateCredentials] server returned: 'The remote server returned an error: (407) Proxy Authentication Required..
trace: [ValidateCredentials] credential validation for 'https://aasolutions.visualstudio.com/' failed.
trace: [Run] System.Net.Http.HttpRequestException: An error occurred while sending the request. ---> System.Net.WebException: The remote server returned an error: (407) Proxy Authentication Required.

In case it helps ...

ignaciosolergarcia avatar Jun 27 '18 15:06 ignaciosolergarcia

Notice http.proxy = 'http://127.0.0.1:3128'. vs http.proxy = '127.0.0.1:3128'..

What changed in your environment to cause the http:// protocol to be removed from your proxy address?

whoisj avatar Jun 27 '18 17:06 whoisj

Sorry if it was not clear last time. I always worked with proxy set as 127.0.0.1:3128. When today I upgraded to the latest version of Git I found out the error about proxy parsing so after reading this post I added the http:// to the url. Then it stopped complaining about the parsing but it failed anyway with the 407.

Then I posted here in case it helps finding out what's going out.

ignaciosolergarcia avatar Jun 27 '18 20:06 ignaciosolergarcia

@ignaciosolergarcia It's weird, after I upgraded the git for windows to version 2.18.0. Now the parse proxy error disappeared.

chucklu avatar Jun 28 '18 01:06 chucklu

@chucklu really weird because it started happening to me when I updated to windows version 2.18.0.windows.1 To be honest I'm not sure which version I was using before as I'm not a fan of upgrading versions ... and this confirms that not upgrading is the way to go in most situations ... as I really don't had a need to do it ¬.¬

ignaciosolergarcia avatar Jun 28 '18 07:06 ignaciosolergarcia

@ignaciosolergarcia @chucklu the lack of a protocol in the URL would cause the GCM to fail to parse the string value and recognize it as a URI (NetFx Uri type requires a protocol or scheme to be specified).

The most likely reason that the GCM began having problems after the upgrade was that, prior to v1.16 many of the network operation paths failed to correctly use the proxy information at all. This meant that the GCM was skipping the HTTP proxy completely, thus no parsing issues, no protocol issues. In v1.16 this oversight was fixed, and now you are running into proxy issues.

@ignaciosolergarcia how are you specifying the proxy address (git-config, environment variable, etc)?

whoisj avatar Jun 28 '18 14:06 whoisj

@whoisj I'm using global git config.

If the GCM was skipping the proxy configuration how is that it was working properly (all the normal operations worked normally). Is that even possible? We're using authenticated proxy here and there is no other way to access VSTS that going thru the proxy.

ignaciosolergarcia avatar Jun 28 '18 16:06 ignaciosolergarcia

If the GCM was skipping the proxy configuration how is that it was working properly (all the normal operations worked normally). Is that even possible?

I do not know. Best bet here is to setup a tool like Fiddler, downgrade to the older, but working GCM, and capture a trace. Then repeat with the current, but not working GCM. Then compare the logs.

whoisj avatar Jun 29 '18 01:06 whoisj