Git commit signing fails with `error: failed to fill whole buffer`

Options
robertodr
robertodr
Community Member

I've updated to Git 2.40.1 and it seems that broke commit signing. Prepending GIT_TRACE=2 to git commit gives as last message:

20:09:00.367459 run-command.c:655       trace: run_command: op-ssh-sign -Y sign -n git -f /tmp/.git_signing_key_tmpe1dbw6 -U /tmp/.git_signing_buffer_tmp0t7i5W

and after working on it for a bit, this gives:

error: failed to fill whole buffer

fatal: failed to write commit object

1Password Version: 8.10.6
Extension Version: 2.10.0
OS Version: NixOS 23.05.20230520.3005f20
Browser:_ Brave

Comments

  • floris_1P
    edited May 2023
    Options

    That's one we haven't seen before. Does it always fail consistently for each commit in each repo? And do other SSH authentication requests to the same Git remote work fine (e.g. git fetch)?

    And given that we haven't been able reproduce this yet, it could be helpful if you could provide the debug logs, by relaunching the 1Password app with the OP_LOG_LEVEL environment variable set to debug and running the failing commit request again.

    There's a shortcut to go to the logs directory in the Troubleshooting menu > Open Logs Folder.

  • dbarjs
    dbarjs
    Community Member
    edited May 2023
    Options

    I have de same issue with Git 2.40.1, Ubuntu 20.04 and the latest version of 1Password CLI avaiable (2.18.0).

    This is the output:

    git -c user.useConfigOnly=true commit --quiet --allow-empty-message --file -
    error: failed to fill whole buffer
    
    fatal: failed to write commit object
    

    I'm using Ubuntu 20.04 with the latest version of 1Password.

    I was able to commit again when fully restart the Ubuntu.

  • dbarjs
    dbarjs
    Community Member
    Options

    @floris_1P It's possible commit in any repo during some time after system restart, it's possible to run any Git work like git fetch, git merge etc. But at a random moment the error starts to creep and affects all repositories.

    The error (timeout) happens in only one branch, the others keep working normally.

    This is the git output after I try to commit changes:

    2023-05-26 17:43:10.913 [info] > git check-ignore -v -z --stdin [4ms]
    2023-05-26 17:44:00.055 [info] > git -c user.useConfigOnly=true commit --quiet --allow-empty-message --file - [60010ms]
    2023-05-26 17:44:00.055 [info] error: failed to fill whole buffer
    
    fatal: failed to write commit object
    2023-05-26 17:44:00.067 [info] > git config --get-all user.name [2ms]
    2023-05-26 17:44:00.078 [info] > git config --get-all user.email [1ms]
    2023-05-26 17:44:00.089 [info] > git config --get commit.template [1ms]
    2023-05-26 17:44:00.102 [info] > git for-each-ref --format=%(refname)%00%(upstream:short)%00%(objectname)%00%(upstream:track)%00%(upstream:remotename)%00%(upstream:remoteref) refs/heads/chore/sc-47656/hide-name-of-the-branch-here- refs/remotes/chore/sc-47656/hide-name-of-the-branch-here- [2ms]
    2023-05-26 17:44:00.121 [info] > git status -z -uall [8ms]
    

    (maybe the git check-ignore -v -z --stdin can be ignored, this happened after the commit command in vscode)

    This is the 1Password app log:

    INFO  2023-05-26T20:42:37.938 ThreadId(8) [client:typescript] Client starting.
    INFO  2023-05-26T20:42:37.999 tokio-runtime-worker(ThreadId(5)) [1P:native-messaging/op-native-core-integration/src/lib.rs:316] Starting IPC listener on 1Password-BrowserSupport
    INFO  2023-05-26T20:42:37.999 ThreadId(8) [1P:op-localization/src/lib.rs:225] system locale detected as 'pt-BR'
    INFO  2023-05-26T20:42:37.999 ThreadId(8) [1P:op-localization/src/lib.rs:251] selected translations for PT_BR based on detected locale pt-BR
    INFO  2023-05-26T20:42:37.999 tokio-runtime-worker(ThreadId(5)) [1P:native-messaging/op-native-core-integration/src/lib.rs:328] Active native core integration is awaiting messages
    INFO  2023-05-26T20:42:37.999 ThreadId(8) [status:op-app/src/app.rs:479] App::new(1Password for Linux/81006027 (PT_BR), /home/$USER/.config/1Password/1password.sqlite)
    INFO  2023-05-26T20:42:38.002 ThreadId(8) [1P:data/op-db/src/db.rs:127] Starting DB at version: 27
    INFO  2023-05-26T20:42:38.004 ThreadId(8) [1P:ssh/op-ssh-config/src/lib.rs:221] agent configured
    ERROR 2023-05-26T20:42:38.004 ThreadId(8) [1P:ffi/op-core-node/src/lib.rs:59] Attempted to notify uninitialized App
    ERROR 2023-05-26T20:42:38.004 ThreadId(8) [1P:ffi/op-core-node/src/lib.rs:59] Attempted to notify uninitialized App
    INFO  2023-05-26T20:42:38.004 invocation_loop(ThreadId(15)) [1P:native-messaging/op-nm-installer/src/nix_utils.rs:68] Created NMH manifest at /home/$USER/.config/google-chrome/NativeMessagingHosts/com.1password.1password.json
    INFO  2023-05-26T20:42:38.004 invocation_loop(ThreadId(15)) [1P:native-messaging/op-nm-installer/src/nix_utils.rs:68] Created NMH manifest at /home/$USER/.config/google-chrome-beta/NativeMessagingHosts/com.1password.1password.json
    INFO  2023-05-26T20:42:38.004 invocation_loop(ThreadId(15)) [1P:native-messaging/op-nm-installer/src/nix_utils.rs:68] Created NMH manifest at /home/$USER/.config/google-chrome-unstable/NativeMessagingHosts/com.1password.1password.json
    INFO  2023-05-26T20:42:38.004 invocation_loop(ThreadId(15)) [1P:native-messaging/op-nm-installer/src/nix_utils.rs:68] Created NMH manifest at /home/$USER/.config/chromium/NativeMessagingHosts/com.1password.1password.json
    INFO  2023-05-26T20:42:38.004 invocation_loop(ThreadId(15)) [1P:native-messaging/op-nm-installer/src/nix_utils.rs:68] Created NMH manifest at /home/$USER/.config/microsoft-edge-dev/NativeMessagingHosts/com.1password.1password.json
    INFO  2023-05-26T20:42:38.004 invocation_loop(ThreadId(15)) [1P:native-messaging/op-nm-installer/src/nix_utils.rs:68] Created NMH manifest at /home/$USER/.config/BraveSoftware/Brave-Browser/NativeMessagingHosts/com.1password.1password.json
    INFO  2023-05-26T20:42:38.004 invocation_loop(ThreadId(15)) [1P:native-messaging/op-nm-installer/src/nix_utils.rs:68] Created NMH manifest at /home/$USER/.config/vivaldi/NativeMessagingHosts/com.1password.1password.json
    INFO  2023-05-26T20:42:38.004 invocation_loop(ThreadId(15)) [1P:native-messaging/op-nm-installer/src/nix_utils.rs:68] Created NMH manifest at /home/$USER/.config/vivaldi-snapshot/NativeMessagingHosts/com.1password.1password.json
    INFO  2023-05-26T20:42:38.004 invocation_loop(ThreadId(15)) [1P:native-messaging/op-nm-installer/src/nix_utils.rs:68] Created NMH manifest at /home/$USER/.mozilla/native-messaging-hosts/com.1password.1password.json
    INFO  2023-05-26T20:42:38.004 invocation_loop(ThreadId(15)) [1P:native-messaging/op-nm-installer/src/nix_utils.rs:83] Successfully installed all native messaging manifests.
    INFO  2023-05-26T20:42:38.005 tokio-runtime-worker(ThreadId(5)) [1P:ssh/op-agent-controller/src/desktop.rs:474] SSH Agent has started.
    INFO  2023-05-26T20:42:50.435 tokio-runtime-worker(ThreadId(3)) [1P:data/ext/op-account-ext-search-weights/src/weights.rs:67] Search weights loaded for account with 7 entries (total bytes: 340)
    INFO  2023-05-26T20:42:50.439 tokio-runtime-worker(ThreadId(3)) [1P:data/ext/op-account-ext-items/src/lib.rs:236] loaded 476 items in 8 vaults for account: TYKZ75KOYFHANAHYGT6TUSRD7Q
    INFO  2023-05-26T20:42:50.441 invocation_loop(ThreadId(15)) [1P:op-app/src/app/backend/unlock.rs:151] Lock state changed: Unlocked
    INFO  2023-05-26T20:42:50.442 tokio-runtime-worker(ThreadId(6)) [1P:native-messaging/op-native-core-integration/src/lib.rs:342] Setting has been toggled on/off, restarting native core integration
    INFO  2023-05-26T20:42:50.442 tokio-runtime-worker(ThreadId(6)) [1P:native-messaging/op-native-core-integration/src/lib.rs:316] Starting IPC listener on 1Password-BrowserSupport
    INFO  2023-05-26T20:42:50.443 tokio-runtime-worker(ThreadId(3)) [1P:native-messaging/op-native-core-integration/src/lib.rs:328] Active native core integration is awaiting messages
    INFO  2023-05-26T20:42:51.459 tokio-runtime-worker(ThreadId(2)) [1P:op-b5-client/src/internal/unauthorized_session.rs:1163] Verifying device secret (MFA) with server...
    INFO  2023-05-26T20:42:51.635 tokio-runtime-worker(ThreadId(1)) [1P:op-b5-client/src/internal/unauthorized_session.rs:824] Device secret was verified
    INFO  2023-05-26T20:42:51.635 tokio-runtime-worker(ThreadId(1)) [1P:op-b5-client/src/internal/unauthorized_session.rs:842] No new device secret was given as current one is still valid and verified
    INFO  2023-05-26T20:42:52.105 tokio-runtime-worker(ThreadId(4)) [1P:op-syncer/src/sync_job.rs:306] synced account TYKZ75KOYFHANAHYGT6TUSRD7Q (0.170776069s)
    INFO  2023-05-26T20:42:52.105 tokio-runtime-worker(ThreadId(4)) [1P:data/op-file-transfer/src/lib.rs:565] find_and_complete_pending_uploads: 'TYKZ75KOYFHANAHYGT6TUSRD7Q'
    INFO  2023-05-26T20:42:52.499 tokio-runtime-worker(ThreadId(4)) [1P:data/ext/op-account-ext-syncer/src/lib.rs:256] The B5 Notifier for (TYKZ75KOYFHANAHYGT6TUSRD7Q) has connected, now monitoring for events.
    INFO  2023-05-26T20:43:01.056 tokio-runtime-worker(ThreadId(5)) [1P:ssh/op-ssh-agent/src/lib.rs:527] Notifying user through tray icon that they have a background prompt waiting
    INFO  2023-05-26T20:44:00.054 tokio-runtime-worker(ThreadId(5)) [1P:ssh/op-ssh-agent/src/lib.rs:358] ssh authorization prompt timed out
    INFO  2023-05-26T20:44:25.442 tokio-runtime-worker(ThreadId(4)) [1P:native-messaging/op-native-core-integration/src/lib.rs:353] Extension connecting.
    INFO  2023-05-26T20:44:25.442 tokio-runtime-worker(ThreadId(4)) [1P:native-messaging/op-native-core-integration/src/lib.rs:355] Extension connection accepted.
    INFO  2023-05-26T20:45:21.730 invocation_loop(ThreadId(15)) [1P:op-app/src/app/backend/frontend.rs:22] Front end event: window closed
    INFO  2023-05-26T20:45:21.732 invocation_loop(ThreadId(15)) [1P:op-app/src/app/backend/frontend.rs:51] Front end event: app will quit
    INFO  2023-05-26T20:45:21.732 invocation_loop(ThreadId(15)) [1P:op-app/src/app/shutdown.rs:65] starting app shutdown
    ERROR 2023-05-26T20:45:21.738 tokio-runtime-worker(ThreadId(5)) [1P:native-messaging/op-native-core-integration/src/connection_handler.rs:62] message from b5x was None: EndConnection
    ERROR 2023-05-26T20:45:21.738 tokio-runtime-worker(ThreadId(5)) [1P:native-messaging/op-native-core-integration/src/connection_handler.rs:31] Dropping connection with b5x due to error handling incoming message: EndConnection
    INFO  2023-05-26T20:45:21.837 ThreadId(12) [1P:data/op-db-queue/src/lib.rs:236] db shutdown requested
    INFO  2023-05-26T20:45:21.837 ThreadId(12) [1P:data/op-db-queue/src/lib.rs:244] db queue worker exiting
    INFO  2023-05-26T20:45:21.837 invocation_loop(ThreadId(15)) [1P:op-app/src/app/shutdown.rs:102] app shutdown complete
    

    I am at your disposal if you need more information.

  • robertodr
    robertodr
    Community Member
    Options

    Hello!
    For me git commit fails in every repo and for every commit. Whether I just restarted or the system has been up for a while doesn't matter. git commit with signing just doesn't work.

  • What you can do as a workaround while we investigate is to remove op-ssh-sign as the gpg.ssh.program in your Gitconfig, which will make it use the default ssh-keygen program. And then make sure it has SSH_AUTH_SOCK set to ~/.1password/agent.sock.

  • robertodr
    robertodr
    Community Member
    Options

    I've updated to the 1Password 8.10.7 for Linux and am running version 2.18.0 of the CLI. It does not help with the issue. Furthermore,
    it fails even with ssh-keygen:

    09:56:17.890957 run-command.c:655       trace: run_command: ssh-keygen -Y sign -n git -f /tmp/.git_signing_key_tmpjLtuG9 -U /tmp/.git_signing_buffer_tmpyIEiLZ
    error: Signing file /tmp/.git_signing_buffer_tmpyIEiLZ
    Couldn't sign message (signer): agent refused operation?
    Signing /tmp/.git_signing_buffer_tmpyIEiLZ failed: agent refused operation?
    
    fatal: failed to write commit object
    
  • @robertodr Did you set SSH_AUTH_SOCK? And do you see anything appear in the 1Password logs (~/.config/1Password/logs on Linux) when you run the failing command?

  • robertodr
    robertodr
    Community Member
    Options

    Yes, SSH_AUTH_SOCK is set. I can't see anything related to this in the logs, unfortunately...

  • Just checking to make sure: does this command return your signing key?

    SSH_AUTH_SOCK=~/.1password/agent.sock ssh-add -L | grep "$(git config user.signingkey)"
    

    And it could be useful to get your ssh-keygen -v logs. To add the -v flag, I believe you'll have to create a shim for the ssh-keygen command:

    #!/bin/sh
    ssh-keygen -v "$@"
    

    And run:

    chmod +x /path/to/shim
    git config gpg.ssh.program /path/to/shim
    
  • robertodr
    robertodr
    Community Member
    Options

    Running this:

    SSH_AUTH_SOCK=~/.1password/agent.sock ssh-add -L | grep "$(git config user.signingkey)"
    

    returns nothing, even though the output of SSH_AUTH_SOCK=~/.1password/agent.sock ssh-add -L:

    ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIAeqrr+kvXVWD+BdrP49t8ul/wvKQyXQ/bavjT5JJoLK JumpCloud
    ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIODV5S21+jV0900ubPoYvdHol/xfbJjVhxayuMEFuPKo GitHub signing key
    

    clearly contains the output of "$(git config user.signingkey)":

    ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIODV5S21+jV0900ubPoYvdHol/xfbJjVhxayuMEFuPKo
    

    And with the shim for ssh-keygen:

    git commit --allow-empty -m "foo" -S
    
    error: Signing file /tmp/.git_signing_buffer_tmpNpihD5
    Couldn't sign message (signer): communication with agent failed?
    Signing /tmp/.git_signing_buffer_tmpNpihD5 failed: communication with agent failed?
    
    fatal: failed to write commit object
    
  • Which versions of Git and OpenSSH are you using? git --version && ssh -V

  • robertodr
    robertodr
    Community Member
    Options
    git version 2.40.1
    OpenSSH_9.3p1, OpenSSL 3.0.9 30 May 2023
    
  • And the error message you're getting with op-ssh-sign, is that error: failed to fill whole buffer as well?

  • robertodr
    robertodr
    Community Member
    Options

    Correct. op-ssh-sign gives that whole buffer error.

  • asportnoy
    asportnoy
    Community Member
    edited June 2023
    Options

    I get this occasionally with the VSCode Git integration, though if I try again after it fails it usually works. I don't use the Git CLI very much but I don't think I've had the issue there, but could be wrong.

    I am on macOS Ventura with 1Password for Mac 8.10.7 (81007041).
    Git version: 2.41.0
    OpenSSH version: OpenSSH_9.0p1, LibreSSL 3.3.6

  • bmlewis1302
    bmlewis1302
    Community Member
    Options

    I am receiving the same error in the same situation. Is there a remedy for this problem yet?

  • robertodr
    robertodr
    Community Member
    Options

    Installing the latest version of 1Password fixed it for me!

    I'm now running 1Password 8.10.8, Git 2.41.0 and OpenSSH_9.3p1, OpenSSL 3.0.9 30 May 2023

  • asportnoy
    asportnoy
    Community Member
    Options

    Still happening for me intermittently on 1Password for Mac 8.10.9 (81009046).

  • talyh
    talyh
    Community Member
    Options

    Same issue here, using 1Password for Mac 8.10.9, only when using the VSCode integration. Using the git CLI works fine.

    Also worth noting that this was working and stopped "all of the sudden". The "all of the sudden" may have been related to me installing the 1P Extension for Safari, though uninstalling it didn't solve the issue.

  • talyh
    talyh
    Community Member
    Options

    One more thing I noticed. Disabling some of the steps of my pre-commit got it to work with the VSCode Integration, so may be a race condition or timeout when committing that way.

  • ammut
    ammut
    Community Member
    edited August 2023
    Options

    FWIW: I came across this Problem using the WebStorm git integration on Ubuntu. The solution for me: if the git operation doesn't go through immediately, check the 1Password tray icon for a red "notification" dot; if present: click it, there should be a "SSH request waiting..." menu entry. Click that and the 1Password dialog should pop up and after that the git operation went through for me.

    In other words: For me it was a timeout problem caused by the fact that the 1Password SSH-key-unlock-dialog didn't pop up.

  • @robertodr @dbarjs @asportnoy @bmlewis1302 @ammut
    We were finally able to reproduce the issue and fix it. The fix will be out in next week's beta release. If you already want it today, you can also find the fix on the nightly release channel.

    Let me know if it solved it for you!

  • sugendran
    sugendran
    Community Member
    Options

    @floris_1P what's the version that will get released in? I get it consistently in VSCode, but not in my shell.

  • CoHuK
    CoHuK
    Community Member
    Options

    @floris_1P I can confirm that this issue is fixed for me in the latest beta release.

  • ammut
    ammut
    Community Member
    Options

    @floris_1P works for me now out of WebStorm, using the latest production release, thank you so much!

  • bridiver
    bridiver
    Community Member
    edited January 19
    Options

    I'm still getting this same error when using vscode on mac using the remote plugin to access windows with 8.10.24

  • bridiver
    bridiver
    Community Member
    Options

    possibly related is that ssh-add -l fails over ssh to windows with
    error fetching identities: communication with agent failed