Access denied error in latest nightly on Windows

[daniilS]

Since updating to 0.5.427 (sadly not sure what my previously installed version was exactly, I only know that I installed it at some point last week), I keep getting "Access is denied. (os error 5)" errors on Windows, usually with "Failed to fetch" or "Failed load remote branches". This happens when first opening Gitbutler, or trying to switch or add a new project. Sometimes closing and reopening Gitbutler will load the project and just display the toast, other times it won't load the project at all. When a project does load, actions like creating or deleting a virtual branch sometimes have no effect, and work fine at other times. I've tried running Gitbutler with admin privileges, which didn't solve the problem.

[daniilS]

Update - can confirm the issue isn't present in stale 0.11.4, if that helps narrow down when it was introduced.

[Byron]

Thanks a lot for reporting!

The very low-level error is probably a result of #3582, which is intended as with help of the logs we should be able to see where it is coming from. If you could find such errors in the logs and post them here, we could identify what's happening and tune the errors to be more descriptive.

The root cause here is probably that reads and writes happen in parallel, which isn't allowed on Windows and GitButler has to get better at coordinating these tasks.

[akbar-mirza]

I’m encountering a similar issue. It seems to have surfaced in the latest 2-3 nightly builds. Based on the logs, this issue first occurred with app version 0.5.428.

Latest logs (0.5.429) :

Caused by:
    Access is denied. (os error 5)) project_id=d19669c3-798e-4b64-bfb3-b6458dca4b2e action=Some("auto")
2024-04-25T03:43:39.513733Z  INFO fetch_from_target: crates\gitbutler-tauri\src\virtual_branches.rs:411: close time.busy=5.10ms time.idle=53.9µs project_id=d19669c3-798e-4b64-bfb3-b6458dca4b2e action=Some("auto")
2024-04-25T03:43:39.517170Z  INFO list_projects: crates\gitbutler-tauri\src\projects.rs:51: new
2024-04-25T03:43:39.517442Z  INFO list_projects: crates\gitbutler-tauri\src\projects.rs:51: close time.busy=219µs time.idle=75.7µs
2024-04-25T03:44:33.481377Z  INFO set_project_active:watch:file monitor:handle debounced events: crates\gitbutler-watcher\src\file_monitor.rs:77: new id=d19669c3-798e-4b64-bfb3-b6458dca4b2e project_id=d19669c3-798e-4b64-bfb3-b6458dca4b2e
2024-04-25T03:44:33.484237Z  INFO set_project_active:watch:file monitor:handle debounced events: crates\gitbutler-watcher\src\file_monitor.rs:77: close time.busy=2.13ms time.idle=748µs id=d19669c3-798e-4b64-bfb3-b6458dca4b2e project_id=d19669c3-798e-4b64-bfb3-b6458dca4b2e fs_events=1 fs_events=1 ignored=0 ignored=0 git_noop=1 git_noop=1 git=0 git=0 project=0 project=0
2024-04-25T03:45:15.765393Z  INFO crates\gitbutler-tauri\src/main.rs:82: starting app version=0.5.429 name=GitButler Nightly
2024-04-25T03:45:16.444132Z  INFO get_user: crates\gitbutler-tauri\src\users.rs:13: new
2024-04-25T03:45:16.444528Z  INFO get_user: crates\gitbutler-tauri\src\users.rs:13: close time.busy=327µs time.idle=112µs
2024-04-25T03:45:16.449106Z  INFO list_projects: crates\gitbutler-tauri\src\projects.rs:51: new
2024-04-25T03:45:16.449355Z  INFO list_projects: crates\gitbutler-tauri\src\projects.rs:51: close time.busy=212µs time.idle=48.6µs
2024-04-25T03:45:16.699283Z  INFO get_project: crates\gitbutler-tauri\src\projects.rs:39: new id=d19669c3-798e-4b64-bfb3-b6458dca4b2e
2024-04-25T03:45:16.703194Z  INFO get_project: crates\gitbutler-tauri\src\projects.rs:39: close time.busy=3.85ms time.idle=85.8µs id=d19669c3-798e-4b64-bfb3-b6458dca4b2e
2024-04-25T03:45:16.704559Z  INFO set_project_active: crates\gitbutler-tauri\src\projects.rs:60: new id=d19669c3-798e-4b64-bfb3-b6458dca4b2e
2024-04-25T03:45:16.704771Z  INFO git_head: crates\gitbutler-tauri\src\commands.rs:97: new project_id=d19669c3-798e-4b64-bfb3-b6458dca4b2e
2024-04-25T03:45:16.709110Z ERROR git_head: crates\gitbutler-tauri\src\commands.rs:97: error=Error(Access is denied. (os error 5)

[Byron]

Thanks for the logs, everyone!

It seems like the error chain is very short, and that it feels like GitButler is stepping onto its own feet. I will see to land some patches that might improve the situation in the interim, as truly fixing them requires more time.

[Byron]

A PR is now available which will make log-excerpts more readable, while trying to reduce the parallelism of the application. This will make it appear more laggy, but might also help reduce the probability of access-denied errors. Fingers crossed.

[Byron]

In conclusion to the failed experiment I can probably say that the issue is indeed caused by disk accesses within serial, unthreaded code. In the experiment, the filesystem monitor was set to only kick in after collecting events for 2 seconds, giving any write operation a long time to finish before reads (and possibly writes, due to lack of IO hygiene) would come in. Since that was ineffective, it must be serial code which is causing this, very reliably so as well.

As an interesting note: button-spamming can make it work after 20-or-so tries.

[Byron]

I managed to create a local Windows build (see #3505 for the tales of this adventure), and (unfortunately) could add a project without problems.

I tried a few bits of GItButler functionality, but wouldn't run into any access-denied issues.

Could it be that there is some supervisor-process that meddles with files of applications? Admittedly, I disabled all of these as well as I could, and it's impossible to say if my Parallels filesystem truly replicates typical Windows filesystems semantics.

I also couldn't reproduce the issue with GitButler from the release channel.

Hence, it might be worth trying again on a truly real Windows machine. CC @krlvi

[Byron]

It took me a while to realize that this issue is most likely related to the introduction of tempfile here: https://github.com/gitbutlerapp/gitbutler/commit/6665bc92898ba139114278dbc20c72ef466ec4cd .

There seem to be two writes in short succession, sometimes they succeed, but sometimes one of them fails. Both writes seem to originate in GitButler itself. @daniilS will check if other processes, like Virus Scanners, are interfering, but even if that is the case there was no issue with this previously before tempfiles were introduced.

As an immediate fix, one could selectively disable tempfiles on Windows as it seems to be a problem with consecutive writes, maybe due to some laziness in the filesystem?

[daniilS]

Think I've identified the root cause: tempfile's implementation of persist() on Windows uses MoveFileExW() to move the temporary file to the permanent one (source), which may return before the file is actually written to disk unless the MOVEFILE_WRITE_THROUGH flag is set (source). I suspect this means that if persist() is called in quick succession on different tempfiles, then there's a high chance that multiple writes to projects.json will happen simultaneously, leading to the permission error.

To use tempfiles on Windows, either the implementation of persist() will to set the extra flag, or the file needs to be manually synced before/after each update.

Also worth checking tempfile's implementations of persist() on other OSs to see if any other ones also don't guarantee that the file move is complete when the function returns.

[Byron]

Thanks so much for this investigation - very helpful, and much appreciated.

It seems like the semantics of perist() differ depending on the platform, as it's atomic on Unix - there isn't anything better than that. On Windows, without write-through, that apparently is not the case, at least not with a truly native filesystem. A good way to go about this could be to patch persist() locally, create a local Windows build, and provide that to you. If that's working, this means a PR should be created for tempfile, making this behaviour available one way or another.

Looking at the code in Git it becomes clear that it certainly is more advanced on Windows and persist() simply might not be on that level yet.

But this also means, that in the interim, on Windows, tempfiles shouldn't be used anymore until this is fixed upstream.

[daniilS]

Re: the mingw code, it seems to account for some cases where it doesn't have permissions to modify the file. If it does, but still gets an access denied error, it assumes that another process is using the file and just retries after a bit. In our case, I think it's reasonable to assume that gb is the only process using projects.json, and that it should have permissions to access the file, so more complex error handling isn't needed - we just need to make sure gb itself isn't writing to the file twice at the same time.

Agreed that an upstream fix would be ideal - but until then, would it work to call File::sync_all() on projects.json after each write in gix-tempfile?

[Byron]

Re: the mingw code, it seems to account for some cases where it doesn't have permissions to modify the file. If it does, but still gets an access denied error, it assumes that another process is using the file and just retries after a bit. In our case, I think it's reasonable to assume that gb is the only process using projects.json, and that it should have permissions to access the file, so more complex error handling isn't needed - we just need to make sure gb itself isn't writing to the file twice at the same time.

I absolutely agree with that - GitButler can avoid racing against itself.

Agreed that an upstream fix would be ideal - but until then, would it work to call File::sync_all() on projects.json after each write in gix-tempfile?

sync_all() can be its own bag of flees and I would avoid putting that into gix-tempfile and cause an extra syscall unless I know exactly what's going on. Fortunately, once a tempfile was persisted, one can call sync_all() in GitButler code. And that, we can try first in the next nightly, limiting it to Windows. Otherwise, one can still go back to the previous way of doing things until the upstream fix is available.

[Qix-]

@Byron since #3620, is this fixed? If so, should we close this or do you want to keep it open to track an upstream change?

[krlvi]

@Qix- we have this mitigated by not using temp files on windows for now (which exposes us to other problems). I found this very similar issue on cargo https://github.com/rust-lang/cargo/issues/11544 and I am still not sure how to do filesystem operations properly on windows.

[Byron]

Just as a summary, this issue was raised when atomic-writes were first introduced, in order to prevent half-written files to corrupt the GB repository.

Thus, getting this to work on Windows properly is still desirable. There is one more thing to try in the tempfile crate which will hopefully improve the overall stability, even though I am not sure it will help much with fast consecutive writes which could still clash in the destination.

For the latter case, rename failures, it seems that Git retries up to 5 times on Windows with pre-defined delays, which is something that could be implemented in gix-tempfile.

Of course, fast consecutive writes, even if they go through with trickery, might not necessarily go through in the right order anymore, potentially causing a different set of issues. This PR aims to help with making this less likely.

[Byron]

After talking to @anaisbetts I also learned that there is a FILE_SHARE_DELETE flag which should allow the deletion of files that are currently opened. So if mv a.lock a just replaced a, and Windows Defender opens a, the next mv a.lock a would fail as a is opened. But if FILE_SHARE_DELETE is set on a, it can be overwritten while still being available to the reader.

With that, the MOVEFILE_WRITE_THROUGH might not be needed as we wouldn't care anymore if a is truly already there, after all, now we should always be able to overwrite it.

[Byron]

Finally I was able to create the test-build which contains some tempfile modifications which might just make this work.

It will run on x86-64 Windows systems.

gitbutler-tauri-2024-05-25-01.exe.zip

How this binary is different?

The build uses a locally modified tempfile crate, with these modifications. In theory, this should allow the Windows filesystem to be more lenient and allow tempfiles to be overwritten while opened, and if that's not enough, it should also wait until the rename operation is complete, ideally without just failing.

Resources

• https://learn.microsoft.com/en-us/windows/win32/api/fileapi/nf-fileapi-createfilea
• https://learn.microsoft.com/en-us/windows/win32/api/winbase/nf-winbase-movefileexa

Next steps

The idea is that if this does indeed work, I will produce another binary without the MOVEFILE_WRITE_THROUGH flag set to be sure it isn't actually required, or more generally to find the minimal fix. Then I will try to get this change accepted in the upstream crate.

More Notes

When opening source-code in the RustRover IDE on Windows, it popped up a message saying that Windows Defender was enabled and the project path should be excluded from it to avoid severe performance degradation. It then offers to run an admin-script to make these exclusions for you.

It would probably be too much for GitButler to offer doing so as well, but it might be something to try out doing by hand - do the access-denied problems go away once Defender doesn't interfere?

[anaisbetts]

It would probably be too much for GitButler to offer doing so as well, but it might be something to try out doing by hand - do the access-denied problems go away once Defender doesn't interfere?

While this is probably good for users to do for performance reasons, it is also something that GitButler shouldn't do - we want to solve locking bugs, not hide them!

[Byron]

we want to solve locking bugs, not hide them!

I meant it as a test to see if Defender is a common reason for these errors, and not to say that should be the (only) way GitButler can work correctly on Windows. So I really hope this executable is working.

[slingshotvfx]

Just for reference, I still receive a lot of access denied errors on windows 11 with the latest gitbutler v0.12.2

Here's a recent one:

and the log:

2024-06-07T20:18:10.876268Z  INFO handle:calculate_virtual_branches:workdir: crates\gitbutler-core\src\git\diff.rs:146: new event=VirtualBranch(573feb84-1a51-4d52-a85c-89faf4ee7fd1) commit_oid=b15b54f190c5946b385b3921093a3289f1bcd639
2024-06-07T20:18:11.181138Z  INFO handle:calculate_virtual_branches:workdir: crates\gitbutler-core\src\git\diff.rs:146: close time.busy=305ms time.idle=27.6µs event=VirtualBranch(573feb84-1a51-4d52-a85c-89faf4ee7fd1) commit_oid=b15b54f190c5946b385b3921093a3289f1bcd639
2024-06-07T20:18:11.206577Z  INFO handle:calculate_virtual_branches: crates\gitbutler-watcher\src\handler.rs:85: close time.busy=368ms time.idle=400ms event=VirtualBranch(573feb84-1a51-4d52-a85c-89faf4ee7fd1)
2024-06-07T20:18:11.206598Z ERROR handle: crates\gitbutler-watcher\src\handler.rs:54: error=failed to handle virtual branch event

Caused by:
    0: failed to list virtual branches
    1: failed to write virtual branch csv-import-error-handling-fixes
    2: Access is denied. (os error 5) event=VirtualBranch(573feb84-1a51-4d52-a85c-89faf4ee7fd1)
2024-06-07T20:18:11.206603Z  INFO handle: crates\gitbutler-watcher\src\handler.rs:54: close time.busy=368ms time.idle=400ms event=VirtualBranch(573feb84-1a51-4d52-a85c-89faf4ee7fd1)
2024-06-07T20:18:11.236620Z  INFO list_virtual_branches:workdir: crates\gitbutler-core\src\git\diff.rs:146: new project_id=573feb84-1a51-4d52-a85c-89faf4ee7fd1 commit_oid=57c5648a65152c85f1b467c4fc1b9acfefc806a8
2024-06-07T20:18:11.563077Z  INFO list_virtual_branches:workdir: crates\gitbutler-core\src\git\diff.rs:146: close time.busy=326ms time.idle=24.3µs project_id=573feb84-1a51-4d52-a85c-89faf4ee7fd1 commit_oid=57c5648a65152c85f1b467c4fc1b9acfefc806a8
2024-06-07T20:18:11.581593Z ERROR list_virtual_branches: crates\gitbutler-tauri\src\virtual_branches.rs:39: error=Error(failed to write virtual branch csv-import-error-handling-fixes

Caused by:
    Access is denied. (os error 5)) project_id=573feb84-1a51-4d52-a85c-89faf4ee7fd1
2024-06-07T20:18:11.581604Z  INFO list_virtual_branches: crates\gitbutler-tauri\src\virtual_branches.rs:39: close time.busy=375ms time.idle=767ms project_id=573feb84-1a51-4d52-a85c-89faf4ee7fd1
2024-06-07T20:18:12.174534Z  INFO set_project_active:watch:file monitor:handle debounced events: crates\gitbutler-watcher\src\file_monitor.rs:122: new id=573feb84-1a51-4d52-a85c-89faf4ee7fd1 project_id=573feb84-1a51-4d52-a85c-89faf4ee7fd1
2024-06-07T20:18:12.174891Z  INFO set_project_active:watch:file monitor:handle debounced events: crates\gitbutler-watcher\src\file_monitor.rs:122: close time.busy=336µs time.idle=23.2µs id=573feb84-1a51-4d52-a85c-89faf4ee7fd1 project_id=573feb84-1a51-4d52-a85c-89faf4ee7fd1 fs_events=379 fs_events=379 ignored=0 ignored=0 git_noop=378 git_noop=378 git=1 git=1 project=0 project=0 git_dedup=1 git_dedup=1

[Byron]

Thanks everyone for your help with testing this, and for bearing with us.

I have compiled another executable based on 0.12.2 (c6b22a727bef312708a1d0afe68ed756c264e408 specifically) which should in theory have less trouble with access-denied errors. It's an updated version of the executable from the earlier comment and if it proves to be better/more stable/more usable than the current stable or nightly I think we can go into further testing and finally, try to upstream the change I made to the Windows version of the tempfile crate.

Finally, after all that pre-amble, here is the new executable.

[slingshotvfx]

Hey @Byron,

Thanks for looking into this. I played around with that exe a bit. Unfortunately I'm not sure performance improved much (or at all?), and I still hit access denied errors.

initial open

First, I was simply trying to switch back to the gitbutler/integration branch and got

2024-06-10T18:59:01.832581Z  INFO set_project_active:watch:file monitor:handle debounced events: crates\gitbutler-watcher\src\file_monitor.rs:122: new id=3aa9ba5d-9859-4236-a625-edc3e341b303 project_id=3aa9ba5d-9859-4236-a625-edc3e341b303
2024-06-10T18:59:01.835046Z  INFO set_project_active:watch:file monitor:handle debounced events: crates\gitbutler-watcher\src\file_monitor.rs:122: close time.busy=2.44ms time.idle=32.9µs id=3aa9ba5d-9859-4236-a625-edc3e341b303 project_id=3aa9ba5d-9859-4236-a625-edc3e341b303 fs_events=8 fs_events=8 ignored=0 ignored=0 git_noop=2 git_noop=2 git=1 git=1 project=2 project=2 git_dedup=1 git_dedup=1 project_dedup=2 project_dedup=2
2024-06-10T18:59:01.835288Z  INFO handle: crates\gitbutler-watcher\src\handler.rs:54: new event=GitFileChange(3aa9ba5d-9859-4236-a625-edc3e341b303, index)
2024-06-10T18:59:01.835350Z  INFO handle: crates\gitbutler-watcher\src\handler.rs:54: new event=ProjectFileChange(3aa9ba5d-9859-4236-a625-edc3e341b303, <redacted>\<redacted>.py, <redacted>)
2024-06-10T18:59:01.835361Z  INFO handle:recalculate_everything: crates\gitbutler-watcher\src\handler.rs:114: new event=ProjectFileChange(3aa9ba5d-9859-4236-a625-edc3e341b303, <redacted>\<redacted>.py, <redacted>) paths=2
2024-06-10T18:59:01.835396Z  INFO handle:recalculate_everything:calculate_virtual_branches: crates\gitbutler-watcher\src\handler.rs:85: new event=ProjectFileChange(3aa9ba5d-9859-4236-a625-edc3e341b303, <redacted>\<redacted>.py, <redacted>) paths=2
2024-06-10T18:59:01.835451Z  INFO handle: crates\gitbutler-watcher\src\handler.rs:54: close time.busy=152µs time.idle=11.3µs event=GitFileChange(3aa9ba5d-9859-4236-a625-edc3e341b303, index)
2024-06-10T18:59:01.837257Z  INFO handle:recalculate_everything:calculate_virtual_branches: crates\gitbutler-watcher\src\handler.rs:85: close time.busy=1.85ms time.idle=10.4µs event=ProjectFileChange(3aa9ba5d-9859-4236-a625-edc3e341b303, <redacted>\<redacted>.py, <redacted>) paths=2
2024-06-10T18:59:01.837266Z  INFO handle:recalculate_everything: crates\gitbutler-watcher\src\handler.rs:114: close time.busy=1.90ms time.idle=7.40µs event=ProjectFileChange(3aa9ba5d-9859-4236-a625-edc3e341b303, <redacted>\<redacted>.py, <redacted>) paths=2
2024-06-10T18:59:01.837270Z  INFO handle: crates\gitbutler-watcher\src\handler.rs:54: close time.busy=1.91ms time.idle=11.9µs event=ProjectFileChange(3aa9ba5d-9859-4236-a625-edc3e341b303, <redacted>\<redacted>.py, <redacted>)
2024-06-10T18:59:09.493050Z  INFO set_base_branch: crates\gitbutler-tauri\src\virtual_branches.rs:121: new project_id=3aa9ba5d-9859-4236-a625-edc3e341b303 branch="origin/main" push_remote=None
2024-06-10T18:59:09.496900Z  INFO set_base_branch:create_snapshot: crates\gitbutler-core\src\ops\oplog.rs:250: new project_id=3aa9ba5d-9859-4236-a625-edc3e341b303 branch="origin/main" push_remote=None self=Project { id: 3aa9ba5d-9859-4236-a625-edc3e341b303, title: "main", description: None, path: "C:\\Users\\<redacted>\\Documents\\main", preferred_key: SystemExecutable, ok_with_force_push: true, api: None, gitbutler_data_last_fetch: None, gitbutler_code_push_state: None, project_data_last_fetch: Some(Error { timestamp: SystemTime { intervals: 133625191393713015 }, error: "backend error: failed to execute git command: The system cannot find the file specified. (os error 2)" }), omit_certificate_check: None, snapshot_lines_threshold: None, use_new_locking: false }
2024-06-10T18:59:09.544688Z  INFO set_base_branch:create_snapshot: crates\gitbutler-core\src\ops\oplog.rs:250: close time.busy=47.8ms time.idle=24.7µs project_id=3aa9ba5d-9859-4236-a625-edc3e341b303 branch="origin/main" push_remote=None self=Project { id: 3aa9ba5d-9859-4236-a625-edc3e341b303, title: "main", description: None, path: "C:\\Users\\<redacted>\\Documents\\main", preferred_key: SystemExecutable, ok_with_force_push: true, api: None, gitbutler_data_last_fetch: None, gitbutler_code_push_state: None, project_data_last_fetch: Some(Error { timestamp: SystemTime { intervals: 133625191393713015 }, error: "backend error: failed to execute git command: The system cannot find the file specified. (os error 2)" }), omit_certificate_check: None, snapshot_lines_threshold: None, use_new_locking: false }
2024-06-10T18:59:09.571516Z ERROR set_base_branch: crates\gitbutler-tauri\src\virtual_branches.rs:121: error=Error(failed to checkout tree

Caused by:
    failed rmdir - 'C:/Users/<redacted>/Documents/<redacted>/' is locked: Access is denied.
    ; class=Os (2); code=Locked (-14)) project_id=3aa9ba5d-9859-4236-a625-edc3e341b303 branch="origin/main" push_remote=None
2024-06-10T18:59:09.571530Z  INFO set_base_branch: crates\gitbutler-tauri\src\virtual_branches.rs:121: close time.busy=78.5ms time.idle=27.3µs project_id=3aa9ba5d-9859-4236-a625-edc3e341b303 branch="origin/main" push_remote=None
2024-06-10T18:59:09.673334Z  INFO get_base_branch_data: crates\gitbutler-tauri\src\virtual_branches.rs:103: new project_id=3aa9ba5d-9859-4236-a625-edc3e341b303
2024-06-10T18:59:09.678709Z  INFO get_base_branch_data: crates\gitbutler-tauri\src\virtual_branches.rs:103: close time.busy=5.35ms time.idle=24.2µs project_id=3aa9ba5d-9859-4236-a625-edc3e341b303
2024-06-10T18:59:10.341635Z  INFO set_project_active:watch:file monitor:handle debounced events: crates\gitbutler-watcher\src\file_monitor.rs:122: new id=3aa9ba5d-9859-4236-a625-edc3e341b303 project_id=3aa9ba5d-9859-4236-a625-edc3e341b303
2024-06-10T18:59:10.347150Z  INFO set_project_active:watch:file monitor:handle debounced events: crates\gitbutler-watcher\src\file_monitor.rs:122: close time.busy=5.48ms time.idle=38.6µs id=3aa9ba5d-9859-4236-a625-edc3e341b303 project_id=3aa9ba5d-9859-4236-a625-edc3e341b303 fs_events=90 fs_events=90 ignored=0 ignored=0 git_noop=82 git_noop=82 git=0 git=0 project=2 project=2 project_dedup=2 project_dedup=2
2024-06-10T18:59:10.347221Z  INFO handle: crates\gitbutler-watcher\src\handler.rs:54: new event=GitButlerOplogChange(3aa9ba5d-9859-4236-a625-edc3e341b303)
2024-06-10T18:59:10.347240Z  INFO handle: crates\gitbutler-watcher\src\handler.rs:54: new event=ProjectFileChange(3aa9ba5d-9859-4236-a625-edc3e341b303, <redacted>, <redacted>\<redacted>.py)
2024-06-10T18:59:10.347250Z  INFO handle:recalculate_everything: crates\gitbutler-watcher\src\handler.rs:114: new event=ProjectFileChange(3aa9ba5d-9859-4236-a625-edc3e341b303, <redacted>, <redacted>.py) paths=2
2024-06-10T18:59:10.347273Z  INFO handle:recalculate_everything:calculate_virtual_branches: crates\gitbutler-watcher\src\handler.rs:85: new event=ProjectFileChange(3aa9ba5d-9859-4236-a625-edc3e341b303, <redacted>, <redacted>.py) paths=2
2024-06-10T18:59:10.348128Z  INFO handle: crates\gitbutler-watcher\src\handler.rs:54: close time.busy=864µs time.idle=44.6µs event=GitButlerOplogChange(3aa9ba5d-9859-4236-a625-edc3e341b303)
2024-06-10T18:59:10.352311Z  INFO handle:recalculate_everything:calculate_virtual_branches: crates\gitbutler-watcher\src\handler.rs:85: close time.busy=5.02ms time.idle=13.6µs event=ProjectFileChange(3aa9ba5d-9859-4236-a625-edc3e341b303, <redacted>, <redacted>\<redacted>.py) paths=2
2024-06-10T18:59:10.352332Z  INFO handle:recalculate_everything: crates\gitbutler-watcher\src\handler.rs:114: close time.busy=5.07ms time.idle=14.8µs event=ProjectFileChange(3aa9ba5d-9859-4236-a625-edc3e341b303, <redacted>, <redacted>\<redacted>.py) paths=2
2024-06-10T18:59:10.352341Z  INFO handle: crates\gitbutler-watcher\src\handler.rs:54: close time.busy=5.09ms time.idle=16.6µs event=ProjectFileChange(3aa9ba5d-9859-4236-a625-edc3e341b303, <redacted>, <redacted>\<redacted>.py)

I can DM someone the logs without redacted paths, but every instance of was the exact same path, and the .py file was actually deleted.

updating workspace

I moved on from that by completely deleting and re-adding the project. I was able to commit a few changes and apply a few different virtual branches successfully. Unfortunately, after merging a PR/deleting a branch in github and then clicking the red "Update" workspace button in gitbutler, I encountered another access denied error:

2024-06-10T19:44:37.007770Z  INFO update_base_branch: crates\gitbutler-tauri\src\virtual_branches.rs:152: new project_id=46469d3a-393a-450c-8f07-f5520ddf033e
2024-06-10T19:44:37.015271Z  INFO update_base_branch:create_snapshot: crates\gitbutler-core\src\ops\oplog.rs:250: new project_id=46469d3a-393a-450c-8f07-f5520ddf033e self=Project { id: 46469d3a-393a-450c-8f07-f5520ddf033e, title: "main", description: None, path: "C:\\Users\\<redacted>\\Documents\\main", preferred_key: SystemExecutable, ok_with_force_push: true, api: None, gitbutler_data_last_fetch: None, gitbutler_code_push_state: None, project_data_last_fetch: Some(Fetched { timestamp: SystemTime { intervals: 133625222667112155 } }), omit_certificate_check: None, snapshot_lines_threshold: None, use_new_locking: true }
2024-06-10T19:44:37.091707Z  INFO update_base_branch:create_snapshot: crates\gitbutler-core\src\ops\oplog.rs:250: close time.busy=76.4ms time.idle=21.0µs project_id=46469d3a-393a-450c-8f07-f5520ddf033e self=Project { id: 46469d3a-393a-450c-8f07-f5520ddf033e, title: "main", description: None, path: "C:\\Users\\<redacted>\\Documents\\main", preferred_key: SystemExecutable, ok_with_force_push: true, api: None, gitbutler_data_last_fetch: None, gitbutler_code_push_state: None, project_data_last_fetch: Some(Fetched { timestamp: SystemTime { intervals: 133625222667112155 } }), omit_certificate_check: None, snapshot_lines_threshold: None, use_new_locking: true }
2024-06-10T19:44:37.099319Z  INFO update_base_branch:workdir: crates\gitbutler-core\src\git\diff.rs:146: new project_id=46469d3a-393a-450c-8f07-f5520ddf033e commit_oid=5efcc944de627de5baab84b11517011d2c82992c
2024-06-10T19:44:37.422071Z  INFO update_base_branch:workdir: crates\gitbutler-core\src\git\diff.rs:146: close time.busy=323ms time.idle=23.1µs project_id=46469d3a-393a-450c-8f07-f5520ddf033e commit_oid=5efcc944de627de5baab84b11517011d2c82992c
2024-06-10T19:44:37.432026Z ERROR update_base_branch: crates\gitbutler-tauri\src\virtual_branches.rs:152: error=Error(Access is denied. (os error 5)) project_id=46469d3a-393a-450c-8f07-f5520ddf033e
2024-06-10T19:44:37.432037Z  INFO update_base_branch: crates\gitbutler-tauri\src\virtual_branches.rs:152: close time.busy=424ms time.idle=19.3µs project_id=46469d3a-393a-450c-8f07-f5520ddf033e
2024-06-10T19:44:37.533287Z  INFO get_base_branch_data: crates\gitbutler-tauri\src\virtual_branches.rs:103: new project_id=46469d3a-393a-450c-8f07-f5520ddf033e
2024-06-10T19:44:37.539372Z  INFO get_base_branch_data: crates\gitbutler-tauri\src\virtual_branches.rs:103: close time.busy=6.06ms time.idle=23.2µs project_id=46469d3a-393a-450c-8f07-f5520ddf033e
2024-06-10T19:44:37.541081Z  INFO list_remote_branches: crates\gitbutler-tauri\src\virtual_branches.rs:452: new project_id=46469d3a-393a-450c-8f07-f5520ddf033e
2024-06-10T19:44:37.546124Z  INFO list_remote_branches: crates\gitbutler-tauri\src\virtual_branches.rs:452: close time.busy=5.03ms time.idle=15.4µs project_id=46469d3a-393a-450c-8f07-f5520ddf033e
2024-06-10T19:44:38.462619Z  INFO set_project_active:watch:file monitor:handle debounced events: crates\gitbutler-watcher\src\file_monitor.rs:122: new id=46469d3a-393a-450c-8f07-f5520ddf033e project_id=46469d3a-393a-450c-8f07-f5520ddf033e
2024-06-10T19:44:38.463079Z  INFO set_project_active:watch:file monitor:handle debounced events: crates\gitbutler-watcher\src\file_monitor.rs:122: close time.busy=406µs time.idle=57.0µs id=46469d3a-393a-450c-8f07-f5520ddf033e project_id=46469d3a-393a-450c-8f07-f5520ddf033e fs_events=180 fs_events=180 ignored=0 ignored=0 git_noop=176 git_noop=176 git=0 git=0 project=0 project=0
2024-06-10T19:44:38.463109Z  INFO handle: crates\gitbutler-watcher\src\handler.rs:54: new event=GitButlerOplogChange(46469d3a-393a-450c-8f07-f5520ddf033e)
2024-06-10T19:44:38.463577Z  INFO handle: crates\gitbutler-watcher\src\handler.rs:54: close time.busy=451µs time.idle=17.0µs event=GitButlerOplogChange(46469d3a-393a-450c-8f07-f5520ddf033e)

Clicking the red Update button a second time seemed to work.

applying branch

Then, I tried applying an old virtual branch with a lot more files and changes in it, and got another error:

2024-06-10T19:52:50.290002Z  INFO get_remote_branch_data: crates\gitbutler-tauri\src\virtual_branches.rs:465: new project_id=46469d3a-393a-450c-8f07-f5520ddf033e refname=Local(Refname { branch: "add-<redacted>", remote: None })
2024-06-10T19:52:50.295104Z  INFO get_remote_branch_data: crates\gitbutler-tauri\src\virtual_branches.rs:465: close time.busy=5.08ms time.idle=20.2µs project_id=46469d3a-393a-450c-8f07-f5520ddf033e refname=Local(Refname { branch: "add-<redacted>", remote: None })
2024-06-10T19:52:53.384827Z  INFO create_virtual_branch_from_branch: crates\gitbutler-tauri\src\virtual_branches.rs:73: new project_id=46469d3a-393a-450c-8f07-f5520ddf033e branch=Local(Refname { branch: "add-<redacted>", remote: None })
2024-06-10T19:52:53.392619Z  INFO create_virtual_branch_from_branch:create_snapshot: crates\gitbutler-core\src\ops\oplog.rs:250: new project_id=46469d3a-393a-450c-8f07-f5520ddf033e branch=Local(Refname { branch: "add-<redacted>", remote: None }) self=Project { id: 46469d3a-393a-450c-8f07-f5520ddf033e, title: "main", description: None, path: "C:\\Users\\<redacted>\\Documents\\main", preferred_key: SystemExecutable, ok_with_force_push: true, api: None, gitbutler_data_last_fetch: None, gitbutler_code_push_state: None, project_data_last_fetch: Some(Fetched { timestamp: SystemTime { intervals: 133625223150201638 } }), omit_certificate_check: None, snapshot_lines_threshold: None, use_new_locking: true }
2024-06-10T19:52:53.456294Z  INFO create_virtual_branch_from_branch:create_snapshot: crates\gitbutler-core\src\ops\oplog.rs:250: close time.busy=63.6ms time.idle=29.3µs project_id=46469d3a-393a-450c-8f07-f5520ddf033e branch=Local(Refname { branch: "add-<redacted>", remote: None }) self=Project { id: 46469d3a-393a-450c-8f07-f5520ddf033e, title: "main", description: None, path: "C:\\Users\\<redacted>\\Documents\\<redacted>", preferred_key: SystemExecutable, ok_with_force_push: true, api: None, gitbutler_data_last_fetch: None, gitbutler_code_push_state: None, project_data_last_fetch: Some(Fetched { timestamp: SystemTime { intervals: 133625223150201638 } }), omit_certificate_check: None, snapshot_lines_threshold: None, use_new_locking: true }
2024-06-10T19:52:53.776273Z  INFO set_project_active:watch:file monitor:handle debounced events: crates\gitbutler-watcher\src\file_monitor.rs:122: new id=46469d3a-393a-450c-8f07-f5520ddf033e project_id=46469d3a-393a-450c-8f07-f5520ddf033e
2024-06-10T19:52:53.776379Z  INFO set_project_active:watch:file monitor:handle debounced events: crates\gitbutler-watcher\src\file_monitor.rs:122: close time.busy=85.1µs time.idle=22.3µs id=46469d3a-393a-450c-8f07-f5520ddf033e project_id=46469d3a-393a-450c-8f07-f5520ddf033e fs_events=71 fs_events=71 ignored=0 ignored=0 git_noop=65 git_noop=65 git=0 git=0 project=0 project=0
2024-06-10T19:52:53.776523Z  INFO handle: crates\gitbutler-watcher\src\handler.rs:54: new event=GitButlerOplogChange(46469d3a-393a-450c-8f07-f5520ddf033e)
2024-06-10T19:52:53.776745Z  INFO handle: crates\gitbutler-watcher\src\handler.rs:54: close time.busy=209µs time.idle=15.6µs event=GitButlerOplogChange(46469d3a-393a-450c-8f07-f5520ddf033e)
2024-06-10T19:52:58.171309Z ERROR create_virtual_branch_from_branch: crates\gitbutler-tauri\src\virtual_branches.rs:73: error=Error(failed to apply

Caused by:
    0: failed to checkout index
    1: failed rmdir - 'C:/Users/<redacted>/Documents/<redacted>/' is locked: Access is denied.
       ; class=Os (2); code=Locked (-14)) project_id=46469d3a-393a-450c-8f07-f5520ddf033e branch=Local(Refname { branch: "add-<redacted>", remote: None })
2024-06-10T19:52:58.171322Z  INFO create_virtual_branch_from_branch: crates\gitbutler-tauri\src\virtual_branches.rs:73: close time.busy=4.79s time.idle=43.4µs project_id=46469d3a-393a-450c-8f07-f5520ddf033e branch=Local(Refname { branch: "add-<redacted>", remote: None })
2024-06-10T19:52:58.173124Z  INFO list_remote_branches: crates\gitbutler-tauri\src\virtual_branches.rs:452: new project_id=46469d3a-393a-450c-8f07-f5520ddf033e

It did completely delete a couple files, as well as leave gitbutler in a weird state where it thinks that branch is applied but with 52 changes and deleted files because it wasn't actually able to update the filesystem.

Once gitbutler is at this point I can't unapply that branch or consistently revert changes. Sometimes I can use the new snapshotting feature to get me back somewhere usable but more often than not when I play around with it too much I end up having to delete the project and re-adding it.

Let me know if there's anything else I can test or if you need any more information.

[Byron]

Thanks for the detailed account of what happens here, it's much appreciated and very useful!

It seems there are two different kinds of errors here - one is about failure to remove a directory during checkout, and the other one is a bit unclear as it only says 'access denied' happened in update_base_branch, without further trace or information.

And that is the error that interests me most (the one from updating workspace) as it might be related to the change that was done in the custom executable. That executable should prevent access denied errors when GitButler writes its own files, like projects.json, users.json, virtual_branches.toml and oplog.toml. All other sources of access-denied errors would remain unaffected (performance also wouldn't change thanks to it, that is expected).

[Rots]

after updating to 0.12.21 on win11 I started getting:

e.g. when clicking on the refresh button to fetch from remote. Dev console log entries below:

user.BhNVG3BU.js:4 ipc->fetch_from_remotes: {"projectId":"3a8e7a80-c8a4-4a46-ad21-1e4a1884bb76","action":"modal"} o: Backend error: failed to execute git command: The system cannot find the file specified. (os error 2) at o.fromError (https://tauri.localhost/_app/immutable/chunks/ipc.BUCpPWbY.js:1:855) at y (https://tauri.localhost/_app/immutable/chunks/ipc.BUCpPWbY.js:1:1013) at async g.fetchFromRemotes (https://tauri.localhost/_app/immutable/chunks/baseBranchService.BhVkQt-L.js:1:967) at async HTMLButtonElement.onmousedown [as mousedown] (https://tauri.localhost/_app/immutable/nodes/3.C5EfQUB-.js:1090:400) {code: 'errors.unknown', message: 'backend error: failed to execute git command: The …stem cannot find the file specified. (os error 2)'} user.BhNVG3BU.js:4 o: Backend error: failed to execute git command: The system cannot find the file specified. (os error 2) at o.fromError (https://tauri.localhost/_app/immutable/chunks/ipc.BUCpPWbY.js:1:855) at y (https://tauri.localhost/_app/immutable/chunks/ipc.BUCpPWbY.js:1:1013) at async g.fetchFromRemotes (https://tauri.localhost/_app/immutable/chunks/baseBranchService.BhVkQt-L.js:1:967) at async HTMLButtonElement.onmousedown [as mousedown] (https://tauri.localhost/_app/immutable/nodes/3.C5EfQUB-.js:1090:400)

makes this unusable now for me

[Byron]

Thanks for reporting!

I don't think anything change in that department, but I have added more logging to make clear which executable it would try to use.

While this trickles through to nightly, do you think you could share logs with us? They should contain more details, maybe even the path to git that it's trying to use.

If that would just be git.exe, you could double-check that git.exe is actually available from PATH - if not, it would try to find it in typical installation locations, maybe you could share the actual location with us as well.

Thanks a lot.

[Rots]

Funnily enough, the nightly works as expected again. No problems running the git command. I guess I'll wait for the next stable release and see what happens then.

[Rots]

0.12.22 works again. So from my perspective it's resolved for now.

I wonder if there's a difference in configuration/environment settings that get stored depending on how the application is installed. The last one (that didn't work) I did not install via the in-app "new release" popup because the windows elevation prompt just didn't show up and the installation wouldn't continue (that I assume is my local windows problem not of the Gitbutler app although I haven't noticed this behaviour with any other application).

[Byron]

I am glad to hear it works!

I wonder if there's a difference in configuration/environment settings that get stored depending on how the application is installed.

To me that seems unlikely as both use the same data, but maybe there is a difference in what Windows Defender or other AntiVirus programs do depending on its location or installation type.

The last one (that didn't work) I did not install via the in-app "new release" popup because the windows elevation prompt just didn't show up and the installation wouldn't continue (that I assume is my local windows problem not of the Gitbutler app although I haven't noticed this behaviour with any other application).

If that's reproducible to you, I think it's worth opening a new issue about it - auto-update should always work or fail loudly (not silently).

[Rots]

The git command started failing again with 0.12.25:

2024-09-18T06:14:24.307336Z  INFO crates\gitbutler-tauri\src/main.rs:64: system git executable for fetch/push: "git.exe"
2024-09-18T06:14:24.309106Z  INFO crates\gitbutler-tauri\src/main.rs:101: starting app version=0.12.25 name=GitButler
2024-09-18T06:14:24.888338Z  INFO list_projects: crates\gitbutler-tauri\src\projects.rs:46: new
2024-09-18T06:14:24.889868Z  INFO list_projects: crates\gitbutler-tauri\src\projects.rs:46: close time.busy=1.48ms time.idle=50.0µs
2024-09-18T06:14:24.910614Z  INFO get_user: crates\gitbutler-tauri\src\users.rs:10: new
2024-09-18T06:14:24.910904Z  INFO get_user: crates\gitbutler-tauri\src\users.rs:10: close time.busy=258µs time.idle=33.8µs
2024-09-18T06:14:25.159911Z  INFO get_project: crates\gitbutler-tauri\src\projects.rs:32: new id=8defc6d3-b7df-4214-a225-8957432136f7 no_validation=None
2024-09-18T06:14:25.180197Z  INFO get_project: crates\gitbutler-tauri\src\projects.rs:32: close time.busy=20.2ms time.idle=69.5µs id=8defc6d3-b7df-4214-a225-8957432136f7 no_validation=None
2024-09-18T06:14:25.182175Z  INFO set_project_active: crates\gitbutler-tauri\src\projects.rs:67: new id=8defc6d3-b7df-4214-a225-8957432136f7
2024-09-18T06:14:25.192593Z  INFO set_project_active:set_project_to_window: crates\gitbutler-tauri\src\window.rs:129: new id=8defc6d3-b7df-4214-a225-8957432136f7 window="main"
2024-09-18T06:14:25.204410Z  INFO set_project_active:set_project_to_window:file monitor: crates\gitbutler-watcher\src\file_monitor.rs:115: new id=8defc6d3-b7df-4214-a225-8957432136f7 window="main" project_id=8defc6d3-b7df-4214-a225-8957432136f7
2024-09-18T06:14:25.206692Z  INFO list_branches: crates\gitbutler-tauri\src\virtual_branches.rs:481: new project_id=8defc6d3-b7df-4214-a225-8957432136f7 filter=Some(BranchListingFilter { local: None, applied: None })
2024-09-18T06:14:25.209063Z  INFO get_base_branch_data: crates\gitbutler-tauri\src\virtual_branches.rs:127: new project_id=8defc6d3-b7df-4214-a225-8957432136f7
2024-09-18T06:14:25.210204Z  INFO get_base_branch_data:get_base_branch_data: crates\gitbutler-branch-actions\src\actions.rs:133: new project_id=8defc6d3-b7df-4214-a225-8957432136f7
2024-09-18T06:14:25.213709Z  INFO git_head: crates\gitbutler-tauri\src\commands.rs:56: new project_id=8defc6d3-b7df-4214-a225-8957432136f7
2024-09-18T06:14:25.214060Z  INFO fetch_from_remotes: crates\gitbutler-tauri\src\virtual_branches.rs:533: new project_id=8defc6d3-b7df-4214-a225-8957432136f7 action=Some("auto")
2024-09-18T06:14:25.227726Z  INFO git_head: crates\gitbutler-tauri\src\commands.rs:56: close time.busy=14.0ms time.idle=27.0µs project_id=8defc6d3-b7df-4214-a225-8957432136f7
2024-09-18T06:14:25.231072Z  INFO operating_mode: crates\gitbutler-tauri\src\modes.rs:13: new project_id=8defc6d3-b7df-4214-a225-8957432136f7
2024-09-18T06:14:25.246153Z  INFO operating_mode: crates\gitbutler-tauri\src\modes.rs:13: close time.busy=15.1ms time.idle=23.8µs project_id=8defc6d3-b7df-4214-a225-8957432136f7
2024-09-18T06:14:25.246682Z ERROR fetch_from_remotes: crates\gitbutler-tauri\src\virtual_branches.rs:533: error=Error(backend error: failed to execute git command: The system cannot find the file specified. (os error 2)) project_id=8defc6d3-b7df-4214-a225-8957432136f7 action=Some("auto")
2024-09-18T06:14:25.246731Z  INFO fetch_from_remotes: crates\gitbutler-tauri\src\virtual_branches.rs:533: close time.busy=32.6ms time.idle=71.2µs project_id=8defc6d3-b7df-4214-a225-8957432136f7 action=Some("auto")
2024-09-18T06:14:25.468855Z  INFO get_base_branch_data:get_base_branch_data: crates\gitbutler-branch-actions\src\actions.rs:133: close time.busy=259ms time.idle=32.6µs project_id=8defc6d3-b7df-4214-a225-8957432136f7
2024-09-18T06:14:25.468913Z  INFO get_base_branch_data: crates\gitbutler-tauri\src\virtual_branches.rs:127: close time.busy=260ms time.idle=35.4µs project_id=8defc6d3-b7df-4214-a225-8957432136f7
...

For reference: the start of the last run with 0.12.24 (which didn't have any problems):

2024-09-14T07:49:14.393531Z  INFO crates\gitbutler-tauri\src/main.rs:65: system git executable for fetch/push: "git.exe"
2024-09-14T07:49:14.394128Z  INFO crates\gitbutler-tauri\src/main.rs:102: starting app version=0.12.24 name=GitButler
2024-09-14T07:49:14.630276Z  INFO list_projects: crates\gitbutler-tauri\src\projects.rs:46: new
2024-09-14T07:49:14.630984Z  INFO list_projects: crates\gitbutler-tauri\src\projects.rs:46: close time.busy=683µs time.idle=26.3µs
2024-09-14T07:49:14.643926Z  INFO get_user: crates\gitbutler-tauri\src\users.rs:10: new
2024-09-14T07:49:14.644229Z  INFO get_user: crates\gitbutler-tauri\src\users.rs:10: close time.busy=272µs time.idle=33.0µs
2024-09-14T07:49:14.779975Z  INFO get_project: crates\gitbutler-tauri\src\projects.rs:32: new id=3a8e7a80-c8a4-4a46-ad21-1e4a1884bb76 no_validation=None
2024-09-14T07:49:14.794610Z  INFO get_project: crates\gitbutler-tauri\src\projects.rs:32: close time.busy=14.6ms time.idle=13.0µs id=3a8e7a80-c8a4-4a46-ad21-1e4a1884bb76 no_validation=None
2024-09-14T07:49:14.795533Z  INFO set_project_active: crates\gitbutler-tauri\src\projects.rs:67: new id=3a8e7a80-c8a4-4a46-ad21-1e4a1884bb76
2024-09-14T07:49:14.798593Z  INFO set_project_active:set_project_to_window: crates\gitbutler-tauri\src\window.rs:129: new id=3a8e7a80-c8a4-4a46-ad21-1e4a1884bb76 window="main"
2024-09-14T07:49:14.802904Z  INFO set_project_active:set_project_to_window:file monitor: crates\gitbutler-watcher\src\file_monitor.rs:115: new id=3a8e7a80-c8a4-4a46-ad21-1e4a1884bb76 window="main" project_id=3a8e7a80-c8a4-4a46-ad21-1e4a1884bb76
2024-09-14T07:49:14.803769Z  INFO list_branches: crates\gitbutler-tauri\src\virtual_branches.rs:473: new project_id=3a8e7a80-c8a4-4a46-ad21-1e4a1884bb76 filter=Some(BranchListingFilter { local: None, applied: None })
2024-09-14T07:49:14.805458Z  INFO git_head: crates\gitbutler-tauri\src\commands.rs:61: new project_id=3a8e7a80-c8a4-4a46-ad21-1e4a1884bb76
2024-09-14T07:49:14.805771Z  INFO get_base_branch_data: crates\gitbutler-tauri\src\virtual_branches.rs:128: new project_id=3a8e7a80-c8a4-4a46-ad21-1e4a1884bb76
2024-09-14T07:49:14.806335Z  INFO get_base_branch_data:get_base_branch_data: crates\gitbutler-branch-actions\src\actions.rs:157: new project_id=3a8e7a80-c8a4-4a46-ad21-1e4a1884bb76
2024-09-14T07:49:14.808714Z  INFO fetch_from_remotes: crates\gitbutler-tauri\src\virtual_branches.rs:525: new project_id=3a8e7a80-c8a4-4a46-ad21-1e4a1884bb76 action=Some("auto")
2024-09-14T07:49:14.813821Z  INFO git_head: crates\gitbutler-tauri\src\commands.rs:61: close time.busy=8.35ms time.idle=16.8µs project_id=3a8e7a80-c8a4-4a46-ad21-1e4a1884bb76
2024-09-14T07:49:14.822358Z  INFO operating_mode: crates\gitbutler-tauri\src\modes.rs:13: new project_id=3a8e7a80-c8a4-4a46-ad21-1e4a1884bb76
2024-09-14T07:49:14.828023Z  INFO operating_mode: crates\gitbutler-tauri\src\modes.rs:13: close time.busy=5.65ms time.idle=13.8µs project_id=3a8e7a80-c8a4-4a46-ad21-1e4a1884bb76
2024-09-14T07:49:14.888974Z  INFO get_base_branch_data:get_base_branch_data: crates\gitbutler-branch-actions\src\actions.rs:157: close time.busy=82.6ms time.idle=19.4µs project_id=3a8e7a80-c8a4-4a46-ad21-1e4a1884bb76
2024-09-14T07:49:14.889007Z  INFO get_base_branch_data: crates\gitbutler-tauri\src\virtual_branches.rs:128: close time.busy=83.2ms time.idle=18.3µs project_id=3a8e7a80-c8a4-4a46-ad21-1e4a1884bb76
...

Is there a way to debug the environment in which the application is run in windows? The PATH looks ok

• on the terminal I can invoke git command
• PATH contains C:\Program Files\Git\cmd which contains the git.exe
• the app appears to also recognise the executable as the log entry in the beginning of the log Also the issue seems to appear per installation (rather than per run or per windows login session).

Possible cause... I tried uninstall-installing the application and during the installation I got a popup notification from CrowdStrike about quarantining a file as it was found malicious. The CS event log doesn't really tell me which file it was. And I don't have access to the Falcon console for further investigation :( At least the nightly seems to work for now.

[Byron]

Thanks so much for reporting!

Indeed, as the log suggests it would try to launch Git using git.exe, but it also means it couldn't find it in the PATH (it would be absolute then), nor did it find its installation which is in C:\Program Files\Git.

I would think that if GitButler would be opened from a terminal, it would inherit its PATH and one would see an absolute Git executable path in the logs. But most importantly, since the binary location didn't change between the versions of GitButler, I'd think that executing Git isn't the problem. For instance, on a public repository, I'd expect it to work still.

Given the presence of CrowdStrike I'd think there might be outside interference here, especially since GitButler didn't change between the versions, or at least not enough to do more than trying to find git.exe. Assuming that, could it be that one of GitButler's utilities was quarantined? There should be gitbutler-git-askpass and gitbutler-git-setsid along with the main GitButler binary. If one of these is missing, we might also see such an error.

I am looking forward to reading what you find out, thanks in advance for your help.

[Rots]

Indeed we found the issue now. The gitbutler-git-askpass.exe was not there in C:\Program Files\GitButler. I copied the binary from the nightly and now it works. So apparently CS doesn't like the askpass. I guess it's on the gitbutler team after all to follow this up with them and to implement measures so it won't be flagged up. Would be interesting to know why it is marked as malicious.

[Byron]

Thanks a lot, I am glad we figured this out! CC @krlvi , who usually is submitting signatures to various anti-virus providers already. Maybe CS is not yet among them?