Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Trace2FileWriter: ignore some exceptions on write #1340

Merged
merged 1 commit into from
Jul 17, 2023

Conversation

derrickstolee
Copy link
Contributor

These exceptions were discovered while exploring trace2 settings with a full Git client.

Git can take a directory location as a trace2 target and will create new files for every process. GCM currently throws a
DirectoryNotFoundException given such a parameter.

Git processes somehow can append to the same file across multiple subprocesses. When GCM attempts to append to the file, it gets an UnauthorizedAccessException on Windows due to multiple writers being problematic. This exception could also happen on other platforms if the setting is pointing to a file with restricted permissions.

In both of these cases, we chose to do nothing. The traces are lost, but that's better than crashing the process.

Future directions could include:

  1. Sending a warning over stderr if these exceptions occur, to make it clear why trace2 are not showing up.

  2. Directories could be noticed as a different kind of trace target and we create a new file for the process before passing it to the Trace2FileWriter.

  3. Perhaps there is a way for Git to pass the handle to the trace file so we can append to the file that Git was using. (Alternatively, Git could close the file and then reopen it after running the GCM subprocess.)

Each of these issues are a bit complicated, so this quick fix is chosen as a stop gap to avoid this problem for current users.

@derrickstolee derrickstolee self-assigned this Jul 17, 2023
These exceptions were discovered while exploring trace2 settings with a
full Git client.

Git can take a directory location as a trace2 target and will create new
files for every process. GCM currently throws a
DirectoryNotFoundException given such a parameter.

Git processes somehow can append to the same file across multiple
subprocesses. When GCM attempts to append to the file, it gets an
UnauthorizedAccessException on Windows due to multiple writers being
problematic. This exception could also happen on other platforms if the
setting is pointing to a file with restricted permissions.

In both of these cases, we chose to do nothing. The traces are lost, but
that's better than crashing the process.

Future directions could include:

1. Sending a warning over stderr if these exceptions occur, to make it
   clear why trace2 are not showing up.

2. Directories could be noticed as a different kind of trace target and
   we create a new file for the process before passing it to the
   Trace2FileWriter.

3. Perhaps there is a way for Git to pass the handle to the trace file
   so we can append to the file that Git was using. (Alternatively, Git
   could close the file and then reopen it after running the GCM
   subprocess.)

Each of these issues are a bit complicated, so this quick fix is chosen
as a stop gap to avoid this problem for current users.
@derrickstolee derrickstolee force-pushed the stolee/trace2-exceptions branch from 6eedd36 to 92cc905 Compare July 17, 2023 19:15
@jeffhostetler
Copy link

if we get that error, we should just disable telemetry so that we won't keep trying to write to the file.

@jeffhostetler
Copy link

but that isn't important right now for testing purposes.

@derrickstolee
Copy link
Contributor Author

if we get that error, we should just disable telemetry so that we won't keep trying to write to the file.

That's effectively what we're doing. It's just that this is the layer where we actually try appending to the file.

An alternative would be to mark this Trace2FileWriter as inactive or something, so we don't even try to write again when a later trace message arrives.

@jeffhostetler
Copy link

Where is the call that passes (the equivalent of) O_APPEND to the kernel? AKA FILE_APPEND_DATA ?

@derrickstolee
Copy link
Contributor Author

Where is the call that passes (the equivalent of) O_APPEND to the kernel? AKA FILE_APPEND_DATA ?

File.AppendAllText() opens the file with O_APPEND, writes the line, then closes the file. This is a bit different from opening the file in the constructor and then using the stream from then on.

It might be worthwhile to rearrange the class to operate that way.

@jeffhostetler
Copy link

yeah, marking it inactive is what i was implying.

@mjcheetham
Copy link
Collaborator

Where is the call that passes (the equivalent of) O_APPEND to the kernel? AKA FILE_APPEND_DATA ?

File.AppendAllText() opens the file with O_APPEND, writes the line, then closes the file. This is a bit different from opening the file in the constructor and then using the stream from then on.

It might be worthwhile to rearrange the class to operate that way.

I believe this is how @ldennington originally had this, operating on a handle that we'd opened once, but there was lots of problems with ensure writes were flushed (calling Flush didn't work). Ended up with intermingled output lines from Git, GCM, and other GCM processes.

@derrickstolee
Copy link
Contributor Author

Where is the call that passes (the equivalent of) O_APPEND to the kernel? AKA FILE_APPEND_DATA ?

File.AppendAllText() opens the file with O_APPEND, writes the line, then closes the file. This is a bit different from opening the file in the constructor and then using the stream from then on.
It might be worthwhile to rearrange the class to operate that way.

I believe this is how @ldennington originally had this, operating on a handle that we'd opened once, but there was lots of problems with ensure writes were flushed (calling Flush didn't work). Ended up with intermingled output lines from Git, GCM, and other GCM processes.

Thanks for that context! I will stop my attempts at swapping the order.

@derrickstolee derrickstolee merged commit cc77173 into main Jul 17, 2023
@jeffhostetler
Copy link

In both of these cases, we chose to do nothing. The traces are lost, but that's better than crashing the process.

Future directions could include:

  1. Sending a warning over stderr if these exceptions occur, to make it clear why trace2 are not showing up.

I have git.exe only emit such warnings if GIT_TRACE2_DST_DEBUG or trace2.destinationdebug are set to keep down the noise.

  1. Directories could be noticed as a different kind of trace target and we create a new file for the process before passing it to the Trace2FileWriter.

this is what we should do. detect a directory pathname and create a unique log file in the constructor.

  1. Perhaps there is a way for Git to pass the handle to the trace file so we can append to the file that Git was using. (Alternatively, Git could close the file and then reopen it after running the GCM subprocess.)

Sharing a file descriptor might work, but there are upstream concerns here.

Closing and re-opening is problematic. We have no guarantees that git.exe is Sync WRT GCM -- there could be other background threads doing things in git.exe. GCM should create it's own file in this case.

In the normal file case, GCM is appending to a flat file that git.exe is also writing to, so we know that the file sharing bits are ok, right?

@mjcheetham mjcheetham added the bug A bug in Git Credential Manager label Jul 17, 2023
@ldennington ldennington mentioned this pull request Aug 1, 2023
ldennington added a commit that referenced this pull request Aug 1, 2023
**Changes since 2.2.2:**

- Fix a GCM/Git Trace2 file locking issue
  - Issue: #1323 
  - PR: #1340
- Remove symlinks to `git-credential-manager-core` exe
  - Issue: #1322
  - PR: #1327 
- Add fallback http uri to `diagnose` command
  - Issue: #1215
  - PR: #1339
- Workaround MSAL tenant issue with silent auth
  - Issue: #1297
  - PR: #1321
derrickstolee added a commit that referenced this pull request Aug 14, 2023
In #1340, we tried to suppress errors during the modification of a
trace2 file. However, those exceptions were too specific to the errors I
had discovered during local testing.

On the 2.3.1 release, I see the following stack error happening:

Unhandled Exception: System.IO.IOException: The process cannot access the file 'C:\Users\dstolee\Downloads\trace.txt' because it is being used by another process.
   at System.IO.__Error.WinIOError(Int32 errorCode, String maybeFullPath)
   at System.IO.FileStream.Init(String path, FileMode mode, FileAccess access, Int32 rights, Boolean useRights, FileShare share, Int32 bufferSize, FileOptions options, SECURITY_ATTRIBUTES secAttrs, String msgPath, Boolean bFromProxy, Boolean useLongPath, Boolean checkHost)
   at System.IO.FileStream..ctor(String path, FileMode mode, FileAccess access, FileShare share, Int32 bufferSize, FileOptions options, String msgPath, Boolean bFromProxy, Boolean useLongPath, Boolean checkHost)
   at System.IO.StreamWriter.CreateFile(String path, Boolean append, Boolean checkHost)
   at System.IO.StreamWriter..ctor(String path, Boolean append, Encoding encoding, Int32 bufferSize, Boolean checkHost)
   at System.IO.StreamWriter..ctor(String path, Boolean append, Encoding encoding)
   at System.IO.File.InternalAppendAllText(String path, String contents, Encoding encoding)
   at System.IO.File.AppendAllText(String path, String contents)
   at GitCredentialManager.Trace2FileWriter.Write(Trace2Message message)
   ...

This very general 'IOException' catch is necessary to avoid this issue.
derrickstolee added a commit that referenced this pull request Aug 14, 2023
In #1340, we tried to suppress errors during the modification of a
trace2 file. However, those exceptions were too specific to the errors I
had discovered during local testing.

On the 2.3.1 release, I see the following stack error happening:

```
Unhandled Exception: System.IO.IOException: The process cannot access the file 'C:\Users\dstolee\Downloads\trace.txt' because it is being used by another process.
   at System.IO.__Error.WinIOError(Int32 errorCode, String maybeFullPath)
   at System.IO.FileStream.Init(String path, FileMode mode, FileAccess access, Int32 rights, Boolean useRights, FileShare share, Int32 bufferSize, FileOptions options, SECURITY_ATTRIBUTES secAttrs, String msgPath, Boolean bFromProxy, Boolean useLongPath, Boolean checkHost)
   at System.IO.FileStream..ctor(String path, FileMode mode, FileAccess access, FileShare share, Int32 bufferSize, FileOptions options, String msgPath, Boolean bFromProxy, Boolean useLongPath, Boolean checkHost)
   at System.IO.StreamWriter.CreateFile(String path, Boolean append, Boolean checkHost)
   at System.IO.StreamWriter..ctor(String path, Boolean append, Encoding encoding, Int32 bufferSize, Boolean checkHost)
   at System.IO.StreamWriter..ctor(String path, Boolean append, Encoding encoding)
   at System.IO.File.InternalAppendAllText(String path, String contents, Encoding encoding)
   at System.IO.File.AppendAllText(String path, String contents)
   at GitCredentialManager.Trace2FileWriter.Write(Trace2Message message)
   ...
```

This very general 'IOException' catch is necessary to avoid this issue.
@mjcheetham mjcheetham deleted the stolee/trace2-exceptions branch December 5, 2023 18:28
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug A bug in Git Credential Manager
Projects
None yet
Development

Successfully merging this pull request may close these issues.

3 participants