elpaca icon indicating copy to clipboard operation
elpaca copied to clipboard

[Bug/Support]: Fetch/Update logging operations causes subprocess error

Open celadevra opened this issue 6 months ago • 9 comments

Confirmation

  • [x] I have checked the documentation (README, Wiki, docstrings, etc)
  • [ ] I am checking these without reading them.
  • [x] I have searched previous issues to see if my question is a duplicate.

Elpaca Version

Elpaca 5b3aeb2 HEAD -> master ## I have committed my edits locally so this might not be useful. I am only 1 commit ahead of origin/master (400eb4c) installer: 0.11 emacs-version: GNU Emacs 30.1 (build 2, x86_64-w64-mingw32) of 2025-02-24 git --version: git version 2.48.1

Operating System

Windows 11

Description

How to reproduce: start elpaca-manager, g i to list installed packages, pick any one and press f x to fetch updates.

Error message in *elpaca-info* buffer:

[2025-05-16 13:09:07] $git fetch --all -v [2025-05-16 13:09:13] Subprocess error (see previous log entries)

Expected behaviour: package fetched/updated successfully.

Possible cause: run the git log command in a terminal, and the current command for getting commit messages causes the shell to report error.

fatal: invalid object name '18'.

This might be because the date and the formatting characters as part of the --pretty= arguments are not quoted, and Windows system does not recognize them correctly.

I have tried to modify the corresponding function elpaca--log-updates in elpaca.el. After a rebuild and restart, elpaca-fetch etc. works as expected.

diff --git a/elpaca.el b/elpaca.el
index 07eecfe..f9d44c4 100644
--- a/elpaca.el
+++ b/elpaca.el
@@ -1817,8 +1817,8 @@ With a prefix argument, rebuild current file's package or prompt if none found."
     (elpaca--make-process e
       :name "log-updates"
       ;; Pager breaks pipe process.
-      :command (list "git" "--no-pager" "log" "--reverse" (concat "--since=" date)
-                     "--pretty=%h %s (%ch)" "..@{u}")
+      :command (list "git" "--no-pager" "log" "--reverse" (concat "--since=\"" date "\"")
+                     "--pretty=\"%h %s (%ch)\"" "\"..@{u}\"")
       :sentinel (lambda (process event) (elpaca--process-sentinel nil nil process event)))))
 
 (defun elpaca--fetch (e &rest command)

I can create a pull request if this is indeed the cause of the problem, and the fix does not break other things.

celadevra avatar May 16 '25 05:05 celadevra

I'm unable to reproduce the issue so far. How do you have git installed?

progfolio avatar May 17 '25 01:05 progfolio

Git is msys/git 2.48.1-1, installed via msys2's pacman tool.

celadevra avatar May 19 '25 00:05 celadevra

Is the variable w32-quote-process-args set to a non-nil value?

progfolio avatar May 19 '25 02:05 progfolio

Yes, the value of w32-quote-process-args is t, is the case both starting with the init file and with -Q.

I have run emacs GUI with a mininum config, installing markdown-mode:

(setq package-enable-at-startup nil)
;; Proxies
(setq url-proxy-services '(("http" . "localhost:7890")
                           ("https" . "localhost:7890")
                           ("no_proxy" . "^\\(localhost\\|127.*\\|melpa.org\\|nongnu.org\\|gnu.org\\)")))


(defvar elpaca-installer-version 0.11)
(defvar elpaca-directory (expand-file-name "elpaca/" user-emacs-directory))
(defvar elpaca-builds-directory (expand-file-name "builds/" elpaca-directory))
(defvar elpaca-repos-directory (expand-file-name "repos/" elpaca-directory))
(defvar elpaca-order '(elpaca :repo "https://github.com/progfolio/elpaca.git"
                              :ref nil :depth 1 :inherit ignore
                              :files (:defaults "elpaca-test.el" (:exclude "extensions"))
                              :build (:not elpaca--activate-package)))
(let* ((repo  (expand-file-name "elpaca/" elpaca-repos-directory))
       (build (expand-file-name "elpaca/" elpaca-builds-directory))
       (order (cdr elpaca-order))
       (default-directory repo))
  (add-to-list 'load-path (if (file-exists-p build) build repo))
  (unless (file-exists-p repo)
    (make-directory repo t)
    (when (<= emacs-major-version 28) (require 'subr-x))
    (condition-case-unless-debug err
        (if-let* ((buffer (pop-to-buffer-same-window "*elpaca-bootstrap*"))
                  ((zerop (apply #'call-process `("git" nil ,buffer t "clone"
                                                  ,@(when-let* ((depth (plist-get order :depth)))
                                                      (list (format "--depth=%d" depth) "--no-single-branch"))
                                                  ,(plist-get order :repo) ,repo))))
                  ((zerop (call-process "git" nil buffer t "checkout"
                                        (or (plist-get order :ref) "--"))))
                  (emacs (concat invocation-directory invocation-name))
                  ((zerop (call-process emacs nil buffer nil "-Q" "-L" "." "--batch"
                                        "--eval" "(byte-recompile-directory \".\" 0 'force)")))
                  ((require 'elpaca))
                  ((elpaca-generate-autoloads "elpaca" repo)))
            (progn (message "%s" (buffer-string)) (kill-buffer buffer))
          (error "%s" (with-current-buffer buffer (buffer-string))))
      ((error) (warn "%s" err) (delete-directory repo 'recursive))))
  (unless (require 'elpaca-autoloads nil t)
    (require 'elpaca)
    (elpaca-generate-autoloads "elpaca" repo)
    (let ((load-source-file-function nil)) (load "./elpaca-autoloads"))))
(add-hook 'after-init-hook #'elpaca-process-queues)
(elpaca `(,@elpaca-order))
(elpaca elpaca-use-package
  (elpaca-use-package-mode))
(use-package markdown-mode :ensure t)

If I make elpaca fetch markdown-mode after it's installed, the error reappears on my system:

  $REPOS/markdown-mode/markdown-mode.el → $BUILDS/markdown-mode/markdown-mode.el
log:
  [2025-05-19 14:48:43] Package queued
  [2025-05-19 14:49:26] Continued by: elpaca--process
  [2025-05-19 14:49:26] Fetching remotes
  [2025-05-19 14:49:26] $git fetch --all -v
  [2025-05-19 14:49:29] Continued by: #[514 "\300\301\302$\207" [elpaca--process-sentinel "Remotes fetched" nil] 7 ("c:/Users/abc/.config/emacs/elpaca/builds/elpaca/elpaca.elc" . 81394)]
  [2025-05-19 14:49:29] Remotes fetched
  [2025-05-19 14:49:29] $git --no-pager log --reverse --since=2025-05-01 14:51:46 +0900 --pretty=%h %s (%ch) ..@{u} # NOT QUOTED
  [2025-05-19 14:49:29] Subprocess error (see previous log entries)

celadevra avatar May 19 '25 06:05 celadevra

My "fix" in the first comment don't always fix the problem, this works better:

diff --git a/elpaca.el b/elpaca.el
index 3b674ad..3cb1c8a 100644
--- a/elpaca.el
+++ b/elpaca.el
@@ -1817,8 +1817,8 @@ With a prefix argument, rebuild current file's package or prompt if none found."
     (elpaca--make-process e
       :name "log-updates"
       ;; Pager breaks pipe process.
-      :command (list "git" "--no-pager" "log" "--reverse" (concat "--since=" date)
-                     "--pretty=%h %s (%ch)" "..@{u}")
+      :command (list "git" "--no-pager" "log" "--reverse" (concat "--since=\"" date "\"")
+                     "--pretty=\"%h %s (%ch)\"" "..@\\{u\\}")
       :sentinel (lambda (process event) (elpaca--process-sentinel nil nil process event)))))
 
 (defun elpaca--fetch (e &rest command)

The problem aside from unquoted date and parameter is that ..@{u} is not recognized properly by cmd.exe. After the fix here fetch seems to work:

  [2025-05-19 16:01:33] $git fetch --all -v
  [2025-05-19 16:01:36] Continued by: #[514 "\300\301\302$\207" [elpaca--process-sentinel "Remotes fetched" nil] 7 ("c:/Users/abc/.config/emacs/elpaca/builds/elpaca/elpaca.elc" . 80947)]
  [2025-05-19 16:01:36] Remotes fetched
  [2025-05-19 16:01:36] $git --no-pager log --reverse --since="2025-04-15 14:23:24 +0800" --pretty="%h %s (%ch)" ..@\{u\}
  [2025-05-19 16:01:36] Continued by: #[514 "\300\301\211$\207" [elpaca--process-sentinel nil] 7 ("c:/Users/abc/.config/emacs/elpaca/builds/elpaca/elpaca.elc" . 80947)]
  [2025-05-19 16:01:36] ✓ 3.408 secs

celadevra avatar May 19 '25 08:05 celadevra

Unfortunately that fix will break things on the linux side of things. I'll have to play around more in a VM or on my work machine to see if I can reliably reproduce the issue. Apologies, but I won't be able to knock this one out as quickly as I'd l like.

progfolio avatar May 24 '25 15:05 progfolio

As for reproduction, exact same problem for me. And the above fix works. I was using emacs on windows + package.el and decided to switch to msys2/emacs and elpaca. It works well except this bug (and "too many files open" messages I've not yet looked into).

GNU Emacs 30.2 (build 2, x86_64-w64-mingw32) of 2025-08-17 git version 2.51.0 w32-quote-process-args set to t

voslin avatar Aug 25 '25 12:08 voslin

@voslin Thank you for the data point.

"too many files open" messages

Setting elpaca-queue-limit should help with that.

progfolio avatar Aug 30 '25 16:08 progfolio

Setting elpaca-queue-limit should help with that.

@progfolio Thank you. That did it.

voslin avatar Sep 01 '25 11:09 voslin

Recently I switched from git installed with MSYS2 pacman command, to Git's official windows client (https://git-scm.com/install/windows). And elpaca-fetch works without any change to the code as cloned from this repo. So it is very likely the problem I and @voslin encountered was due to how Emacs and MSYS2 git interpret command line quotes and escape characters.

celadevra avatar Nov 14 '25 01:11 celadevra