all messages for Emacs-related lists mirrored at yhetil.org
 help / color / mirror / code / Atom feed
* bug#65590: 29.0.50; esh-var-test/interp-concat-cmd fails on macOS
@ 2023-08-29  6:44 Stefan Kangas
  2023-08-29 17:10 ` Jim Porter
  0 siblings, 1 reply; 24+ messages in thread
From: Stefan Kangas @ 2023-08-29  6:44 UTC (permalink / raw)
  To: 65590; +Cc: jporterbugs

X-Debbugs-CC: jporterbugs@gmail.com

I see the below test failure on macOS:

Test esh-var-test/interp-concat-cmd backtrace:
  signal(error ("echo: unrecognized option -b"))
  error("%s: unrecognized option -%c" "echo" 98)
  eshell--process-option("echo" "baz" 0 0 ((110 nil (nil) output-newli
  eshell--process-args("echo" ("-baz") ((110 nil (nil) output-newline
  eshell--do-opts("echo" ((110 nil (nil) output-newline "do not output
  eshell/echo("-baz")
  apply(eshell/echo "-baz")
  eshell-exec-lisp(eshell-print eshell-error eshell/echo ("-baz") nil)
  eshell-lisp-command(eshell/echo ("-baz"))
  eshell-plain-command("echo" ("-baz"))
  eshell-named-command("echo" ("-baz"))
  eval((eshell-named-command '"echo" '("-baz")))
  eshell-do-eval((eshell-named-command '"echo" '("-baz")) t)
  eshell-do-eval((prog1 (eshell-named-command '"echo" '("-baz")) (mapc
  (condition-case err (eshell-do-eval '(prog1 (eshell-named-command '"
  eval((condition-case err (eshell-do-eval '(prog1 (eshell-named-comma
  eshell-do-eval((condition-case err (eshell-do-eval '(prog1 (eshell-n
  #f(compiled-function () #<bytecode -0x107543402033a9af>)()
  funcall(#f(compiled-function () #<bytecode -0x107543402033a9af>))
  (let ((eshell-this-command-hook '(ignore))) (funcall '#f(compiled-fu
  eval((let ((eshell-this-command-hook '(ignore))) (funcall '#f(compil
  eshell-do-eval((let ((eshell-this-command-hook '(ignore))) (conditio
  #f(compiled-function () #<bytecode -0x107543402033a9af>)()
  funcall(#f(compiled-function () #<bytecode -0x107543402033a9af>))
  (let ((eshell-current-handles '[nil (((eshell-temp) . 2) t) (((eshel
  eval((let ((eshell-current-handles '[nil ((... . 2) t) ((... . 2) t)
  eshell-do-eval((let ((eshell-current-handles '[nil ((... . 2) t) ((.
  eshell-do-eval((progn (let ((eshell-current-handles '[nil (... t) (.
  #f(compiled-function () #<bytecode -0x107543402033a9af>)()
  funcall(#f(compiled-function () #<bytecode -0x107543402033a9af>))
  (let ((eshell-in-pipeline-p 'nil) (eshell-current-handles '[nil (((e
  eval((let ((eshell-in-pipeline-p 'nil) (eshell-current-handles '[nil
  eshell-do-eval((let ((eshell-in-pipeline-p 'nil) (eshell-current-han
  #f(compiled-function () #<bytecode -0x107543402033a9af>)()
  funcall(#f(compiled-function () #<bytecode -0x107543402033a9af>))
  (let ((eshell-current-handles '[nil (((t) . 2) t) (((t) . 2) t)]) (e
  eval((let ((eshell-current-handles '[nil ((... . 2) t) ((... . 2) t)
  eshell-do-eval((let ((eshell-current-handles '[nil ((... . 2) t) ((.
  eshell-command-result("echo ${*echo \"foo\nbar\"}-baz")
  eshell-test-command-result("echo ${*echo \"foo\nbar\"}-baz")
  eshell-command-result-equal("echo ${*echo \"foo\nbar\"}-baz" ("foo"
  #f(compiled-function () #<bytecode -0x1e41ac0e460bffe0>)()
  ert--run-test-internal(#s(ert--test-execution-info :test #s(ert-test
  ert-run-test(#s(ert-test :name esh-var-test/interp-concat-cmd :docum
  ert-run-or-rerun-test(#s(ert--stats :selector ... :tests ... :test-m
  ert-run-tests((not (or (tag :expensive-test) (tag :unstable) (tag :n
  ert-run-tests-batch((not (or (tag :expensive-test) (tag :unstable) (
  ert-run-tests-batch-and-exit((not (or (tag :expensive-test) (tag :un
  eval((ert-run-tests-batch-and-exit '(not (or (tag :expensive-test) (
  command-line-1(("-L" ":." "-l" "ert" "-l" "lisp/eshell/esh-var-tests
  command-line()
  normal-top-level()
Test esh-var-test/interp-concat-cmd condition:
    (error "echo: unrecognized option -b")
   FAILED   20/110  esh-var-test/interp-concat-cmd (0.616546 sec) at
lisp/eshell/esh-var-tests.el:275

In GNU Emacs 30.0.50 (build 2, x86_64-apple-darwin21.6.0, NS
 appkit-2113.60 Version 12.6.8 (Build 21G725)) of 2023-08-28 built on
 MY-MacBook-Pro.local
Repository revision: 7a55d7e8684c02551feb17168047c9192478e5a0
Repository branch: master
Windowing system distributor 'Apple', version 10.3.2113
System Description:  macOS 12.6.8

Configured features:
ACL GIF GMP GNUTLS JPEG JSON LCMS2 LIBXML2 MODULES NOTIFY KQUEUE NS
PDUMPER PNG SQLITE3 THREADS TIFF TOOLKIT_SCROLL_BARS TREE_SITTER WEBP
XIM ZLIB

Important settings:
  value of $LC_COLLATE: C
  value of $LC_CTYPE: sv_SE.UTF-8
  locale-coding-system: utf-8-unix

Major mode: Lisp Interaction

Minor modes in effect:
  tooltip-mode: t
  global-eldoc-mode: t
  eldoc-mode: t
  show-paren-mode: t
  electric-indent-mode: t
  mouse-wheel-mode: t
  tool-bar-mode: t
  menu-bar-mode: t
  file-name-shadow-mode: t
  global-font-lock-mode: t
  font-lock-mode: t
  blink-cursor-mode: t
  line-number-mode: t
  indent-tabs-mode: t
  transient-mark-mode: t
  auto-composition-mode: t
  auto-encryption-mode: t
  auto-compression-mode: t

Load-path shadows:
None found.

Features:
(shadow sort mail-extr emacsbug message mailcap yank-media puny dired
dired-loaddefs rfc822 mml mml-sec password-cache epa derived epg rfc6068
epg-config gnus-util text-property-search time-date subr-x mm-decode
mm-bodies mm-encode mail-parse rfc2231 mailabbrev gmm-utils mailheader
cl-loaddefs cl-lib sendmail rfc2047 rfc2045 ietf-drums mm-util
mail-prsvr mail-utils rmc iso-transl tooltip cconv eldoc paren electric
uniquify ediff-hook vc-hooks lisp-float-type elisp-mode mwheel
term/ns-win ns-win ucs-normalize mule-util term/common-win touch-screen
tool-bar dnd fontset image regexp-opt fringe tabulated-list replace
newcomment text-mode lisp-mode prog-mode register page tab-bar menu-bar
rfn-eshadow isearch easymenu timer select scroll-bar mouse jit-lock
font-lock syntax font-core term/tty-colors frame minibuffer nadvice seq
simple cl-generic indonesian philippine cham georgian utf-8-lang
misc-lang vietnamese tibetan thai tai-viet lao korean japanese eucjp-ms
cp51932 hebrew greek romanian slovak czech european ethiopic indian
cyrillic chinese composite emoji-zwj charscript charprop case-table
epa-hook jka-cmpr-hook help abbrev obarray oclosure cl-preloaded button
loaddefs theme-loaddefs faces cus-face macroexp files window
text-properties overlay sha1 md5 base64 format env code-pages mule
custom widget keymap hashtable-print-readable backquote threads kqueue
cocoa ns lcms2 multi-tty make-network-process emacs)

Memory information:
((conses 16 36151 9219) (symbols 48 5093 0) (strings 32 12636 1004)
 (string-bytes 1 352850) (vectors 16 9370)
 (vector-slots 8 147689 12388) (floats 8 21 23) (intervals 56 202 0)
 (buffers 992 10))





^ permalink raw reply	[flat|nested] 24+ messages in thread

* bug#65590: 29.0.50; esh-var-test/interp-concat-cmd fails on macOS
  2023-08-29  6:44 bug#65590: 29.0.50; esh-var-test/interp-concat-cmd fails on macOS Stefan Kangas
@ 2023-08-29 17:10 ` Jim Porter
  2023-08-29 18:59   ` Stefan Kangas
  0 siblings, 1 reply; 24+ messages in thread
From: Jim Porter @ 2023-08-29 17:10 UTC (permalink / raw)
  To: Stefan Kangas, 65590, michael.albinus

On 8/28/2023 11:44 PM, Stefan Kangas wrote:
> X-Debbugs-CC: jporterbugs@gmail.com
> 
> I see the below test failure on macOS:
> 
> Test esh-var-test/interp-concat-cmd backtrace:
>    signal(error ("echo: unrecognized option -b"))
>    error("%s: unrecognized option -%c" "echo" 98)
>    eshell--process-option("echo" "baz" 0 0 ((110 nil (nil) output-newli
>    eshell--process-args("echo" ("-baz") ((110 nil (nil) output-newline
>    eshell--do-opts("echo" ((110 nil (nil) output-newline "do not output
>    eshell/echo("-baz")
>    apply(eshell/echo "-baz")
[snip]
>    eshell-command-result("echo ${*echo \"foo\nbar\"}-baz")
>    eshell-test-command-result("echo ${*echo \"foo\nbar\"}-baz")
>    eshell-command-result-equal("echo ${*echo \"foo\nbar\"}-baz" ("foo"
>    #f(compiled-function () #<bytecode -0x1e41ac0e460bffe0>)()
>    ert--run-test-internal(#s(ert--test-execution-info :test #s(ert-test
>    ert-run-test(#s(ert-test :name esh-var-test/interp-concat-cmd :docum
>    ert-run-or-rerun-test(#s(ert--stats :selector ... :tests ... :test-m
>    ert-run-tests((not (or (tag :expensive-test) (tag :unstable) (tag :n
>    ert-run-tests-batch((not (or (tag :expensive-test) (tag :unstable) (
>    ert-run-tests-batch-and-exit((not (or (tag :expensive-test) (tag :un
>    eval((ert-run-tests-batch-and-exit '(not (or (tag :expensive-test) (
>    command-line-1(("-L" ":." "-l" "ert" "-l" "lisp/eshell/esh-var-tests
>    command-line()
>    normal-top-level()
> Test esh-var-test/interp-concat-cmd condition:
>      (error "echo: unrecognized option -b")
>     FAILED   20/110  esh-var-test/interp-concat-cmd (0.616546 sec) at
> lisp/eshell/esh-var-tests.el:275

This looks like a race condition when executing this command:

   echo ${*echo "foo\nbar"}-baz

That *should* print "foo\nbar-baz", but it tries to print "-baz" (and 
fails). That appears to be because the subcommand (*echo "foo\nbar") 
produces no output.

I'll inspect the code here more to see if there are any obvious places 
that we're not waiting long enough for the output. However, I've never 
been able to reproduce this locally, so it might be time to add more 
debug instrumentation to Eshell...

(Michael Albinus - CCed - has also seen similar sorts of issues on EMBA. 
They're usually different tests that fail, but they all look like 
similar issues where we get no output from a subcommand.)





^ permalink raw reply	[flat|nested] 24+ messages in thread

* bug#65590: 29.0.50; esh-var-test/interp-concat-cmd fails on macOS
  2023-08-29 17:10 ` Jim Porter
@ 2023-08-29 18:59   ` Stefan Kangas
  2023-08-29 19:15     ` Stefan Kangas
  2023-08-30  0:44     ` Jim Porter
  0 siblings, 2 replies; 24+ messages in thread
From: Stefan Kangas @ 2023-08-29 18:59 UTC (permalink / raw)
  To: Jim Porter; +Cc: michael.albinus, 65590

Jim Porter <jporterbugs@gmail.com> writes:

> This looks like a race condition when executing this command:
>
>    echo ${*echo "foo\nbar"}-baz
>
> That *should* print "foo\nbar-baz", but it tries to print "-baz" (and
> fails). That appears to be because the subcommand (*echo "foo\nbar")
> produces no output.

I can confirm that the error is intermittent, as I'm not seeing it on a re-run.





^ permalink raw reply	[flat|nested] 24+ messages in thread

* bug#65590: 29.0.50; esh-var-test/interp-concat-cmd fails on macOS
  2023-08-29 18:59   ` Stefan Kangas
@ 2023-08-29 19:15     ` Stefan Kangas
  2023-08-30  0:44     ` Jim Porter
  1 sibling, 0 replies; 24+ messages in thread
From: Stefan Kangas @ 2023-08-29 19:15 UTC (permalink / raw)
  To: Jim Porter; +Cc: michael.albinus, 65590

Den tis 29 aug. 2023 kl 20:59 skrev Stefan Kangas <stefankangas@gmail.com>:
>
> Jim Porter <jporterbugs@gmail.com> writes:
>
> > This looks like a race condition when executing this command:
> >
> >    echo ${*echo "foo\nbar"}-baz
> >
> > That *should* print "foo\nbar-baz", but it tries to print "-baz" (and
> > fails). That appears to be because the subcommand (*echo "foo\nbar")
> > produces no output.
>
> I can confirm that the error is intermittent, as I'm not seeing it on a re-run.

(I put "29.0.50" in the subject, but that should be "30.0.50".  Sorry
about the typo.)

And on yet another re-run, this one cropped up in the same file:

Test esh-var-test/quote-interp-var-indices-subcommand backtrace:
  signal(ert-test-failed (((should (eshell-command-result--equal comma
  ert-fail(((should (eshell-command-result--equal command (eshell-test
  eshell-command-result-equal("echo \"$eshell-test-value[${*echo 0}]\"
  #f(compiled-function () #<bytecode -0x3e28235b46afdbe>)()
  ert--run-test-internal(#s(ert--test-execution-info :test #s(ert-test
  ert-run-test(#s(ert-test :name esh-var-test/quote-interp-var-indices
  ert-run-or-rerun-test(#s(ert--stats :selector ... :tests ... :test-m
  ert-run-tests((not (or (tag :expensive-test) (tag :unstable) (tag :n
  ert-run-tests-batch((not (or (tag :expensive-test) (tag :unstable) (
  ert-run-tests-batch-and-exit((not (or (tag :expensive-test) (tag :un
  eval((ert-run-tests-batch-and-exit '(not (or (tag :expensive-test) (
  command-line-1(("-L" ":." "-l" "ert" "-l" "lisp/eshell/esh-var-tests
  command-line()
  normal-top-level()
Test esh-var-test/quote-interp-var-indices-subcommand condition:
    (ert-test-failed
     ((should
       (eshell-command-result--equal command
                     (eshell-test-command-result command)
                     result))
      :form
      (eshell-command-result--equal
       "echo \"$eshell-test-value[${*echo 0}]\"" #("nil" 0 3 (escaped t))
       "zero")
      :value nil :explanation
      (nonequal-result (command "echo \"$eshell-test-value[${*echo 0}]\"")
               (result #("nil" 0 3 ...)) (expected "zero"))))
   FAILED   76/110  esh-var-test/quote-interp-var-indices-subcommand
(0.625851 sec) at lisp/eshell/esh-var-tests.el:341
[...]

Ran 110 tests, 108 results as expected, 2 unexpected (2023-08-29
21:10:03+0200, 10.074424 sec)

2 unexpected results:
   FAILED  esh-var-test/interp-cmd-external
   FAILED  esh-var-test/quote-interp-var-indices-subcommand

make[3]: *** [lisp/eshell/esh-var-tests.log] Error 1





^ permalink raw reply	[flat|nested] 24+ messages in thread

* bug#65590: 29.0.50; esh-var-test/interp-concat-cmd fails on macOS
  2023-08-29 18:59   ` Stefan Kangas
  2023-08-29 19:15     ` Stefan Kangas
@ 2023-08-30  0:44     ` Jim Porter
  2023-09-01  1:54       ` Jim Porter
  1 sibling, 1 reply; 24+ messages in thread
From: Jim Porter @ 2023-08-30  0:44 UTC (permalink / raw)
  To: Stefan Kangas; +Cc: 65590, michael.albinus

[-- Attachment #1: Type: text/plain, Size: 779 bytes --]

On 8/29/2023 11:59 AM, Stefan Kangas wrote:
> Jim Porter <jporterbugs@gmail.com> writes:
> 
>> This looks like a race condition when executing this command:
>>
>>     echo ${*echo "foo\nbar"}-baz
>>
>> That *should* print "foo\nbar-baz", but it tries to print "-baz" (and
>> fails). That appears to be because the subcommand (*echo "foo\nbar")
>> produces no output.
> 
> I can confirm that the error is intermittent, as I'm not seeing it on a re-run.

Can you try the following patches? They shouldn't change the behavior, 
but they do add some extra debugging information to failed tests.

If you can get this to occur when using Eshell interactively, you can 
also enable this output by calling "eshell-debug process" at an Eshell 
prompt before running the offending command.

[-- Attachment #2: 0001-Fix-handling-of-Eshell-debug-modes.patch --]
[-- Type: text/plain, Size: 15826 bytes --]

From 62019d9ff4b8af07bbfb8294751811dcad79ed99 Mon Sep 17 00:00:00 2001
From: Jim Porter <jporterbugs@gmail.com>
Date: Tue, 29 Aug 2023 17:02:40 -0700
Subject: [PATCH 1/2] Fix handling of Eshell debug modes

Previously, these were enabled/disabled at byte-compilation time, but
we want to control them at runtime.

* lisp/eshell/esh-cmd.el (eshell-eval-command): Call
'eshell-debug-command-start'.
(eshell-manipulate): Check 'eshell-debug-command' at runtime.  Update
callers.
(eshell-debug-command): Move to "esh-util.el".
(eshell/eshell-debug, pcomplate/eshell-mode/eshell-debug): Move to
"em-basic.el".
(eshell-debug-show-parsed-args): Update implementation.

* lisp/eshell/esh-util.el (eshell-debug-command): Move from
"esh-cmd.el" and convert to a list.
(eshell-debug-command-buffer): New variable.
(eshell-condition-case): Check 'eshell-handle-errors' at runtime.
(eshell-debug-command-start): New function.
(eshell-debug-command): Move from "esh-cmd.el" and convert to a macro.

* lisp/eshell/em-basic.el (eshell/eshell-debug)
(pcomplete/eshell-mode/eshell-debug): Move from "esh-cmd.el" and
reimplement.

* lisp/eshell/eshell.el (eshell-command): Pass the original input to
'eshell-eval-command'.

* doc/misc/eshell.texi (Built-ins): Update documentation for
'eshell-debug'.
---
 doc/misc/eshell.texi    |  21 ++++++--
 lisp/eshell/em-basic.el |  32 ++++++++++++
 lisp/eshell/esh-cmd.el  | 105 +++++++++-------------------------------
 lisp/eshell/esh-util.el |  44 +++++++++++++++--
 lisp/eshell/eshell.el   |   3 +-
 5 files changed, 113 insertions(+), 92 deletions(-)

diff --git a/doc/misc/eshell.texi b/doc/misc/eshell.texi
index f8f60bae13a..09aafdcf070 100644
--- a/doc/misc/eshell.texi
+++ b/doc/misc/eshell.texi
@@ -619,10 +619,23 @@ Built-ins
 @item eshell-debug
 @cmindex eshell-debug
 Toggle debugging information for Eshell itself.  You can pass this
-command the argument @code{errors} to enable/disable Eshell trapping
-errors when evaluating commands, or the argument @code{commands} to
-show/hide command execution progress in the buffer @code{*eshell last
-cmd*}.
+command one or more of the following arguments:
+
+@itemize @bullet
+
+@item
+@code{error}, to enable/disable Eshell trapping errors when evaluating
+commands;
+
+@item
+@code{form}, to show/hide Eshell command form manipulation in the
+buffer @code{*eshell last cmd*}; or
+
+@item
+@code{process}, to show/hide external process events in the buffer
+@code{*eshell last cmd*}.
+
+@end itemize
 
 @item exit
 @cmindex exit
diff --git a/lisp/eshell/em-basic.el b/lisp/eshell/em-basic.el
index 016afe811b2..cea4b78129f 100644
--- a/lisp/eshell/em-basic.el
+++ b/lisp/eshell/em-basic.el
@@ -188,6 +188,38 @@ eshell/umask
 
 (put 'eshell/umask 'eshell-no-numeric-conversions t)
 
+(defun eshell/eshell-debug (&rest args)
+  "A command for toggling certain debug variables."
+  (eshell-eval-using-options
+   "eshell-debug" args
+   '((?h "help" nil nil "display this usage message")
+     :usage "[kinds]...
+This command is used to aid in debugging problems related to Eshell
+itself.  It is not useful for anything else.  The recognized `kinds'
+are:
+
+   error       stops Eshell from trapping errors
+   form        shows command form manipulation in `*eshell last cmd*'
+   process     shows process events in `*eshell last cmd*'")
+   (if args
+       (dolist (kind args)
+         (if (equal kind "error")
+             (setq eshell-handle-errors (not eshell-handle-errors))
+           (let ((kind-sym (intern kind)))
+             (if (memq kind-sym eshell-debug-command)
+                 (setq eshell-debug-command
+                       (delq kind-sym eshell-debug-command))
+               (push kind-sym eshell-debug-command)))))
+     ;; Output the currently-enabled debug kinds.
+     (unless eshell-handle-errors
+       (eshell-print "error\n"))
+     (dolist (kind eshell-debug-command)
+       (eshell-printn (symbol-name kind))))))
+
+(defun pcomplete/eshell-mode/eshell-debug ()
+  "Completion for the `debug' command."
+  (while (pcomplete-here '("error" "form" "process"))))
+
 (provide 'em-basic)
 
 ;; Local Variables:
diff --git a/lisp/eshell/esh-cmd.el b/lisp/eshell/esh-cmd.el
index 80066263396..ed2d6c71fc8 100644
--- a/lisp/eshell/esh-cmd.el
+++ b/lisp/eshell/esh-cmd.el
@@ -237,17 +237,6 @@ eshell-cmd-load-hook
   :version "24.1"		       ; removed eshell-cmd-initialize
   :type 'hook)
 
-(defcustom eshell-debug-command nil
-  "If non-nil, enable Eshell debugging code.
-This is slow, and only useful for debugging problems with Eshell.
-If you change this without using customize after Eshell has loaded,
-you must re-load `esh-cmd.el'."
-  :initialize 'custom-initialize-default
-  :set (lambda (symbol value)
-	 (set symbol value)
-	 (load "esh-cmd"))
-  :type 'boolean)
-
 (defcustom eshell-deferrable-commands
   '(eshell-named-command
     eshell-lisp-command
@@ -436,22 +425,9 @@ eshell-parse-command
                             (run-hooks 'eshell-post-command-hook)))
       (macroexp-progn commands))))
 
-(defun eshell-debug-command (tag subform)
-  "Output a debugging message to `*eshell last cmd*'."
-  (let ((buf (get-buffer-create "*eshell last cmd*"))
-	(text (eshell-stringify eshell-current-command)))
-    (with-current-buffer buf
-      (if (not tag)
-	  (erase-buffer)
-	(insert "\n\C-l\n" tag "\n\n" text
-		(if subform
-		    (concat "\n\n" (eshell-stringify subform)) ""))))))
-
 (defun eshell-debug-show-parsed-args (terms)
   "Display parsed arguments in the debug buffer."
-  (ignore
-   (if eshell-debug-command
-       (eshell-debug-command "parsed arguments" terms))))
+  (ignore (eshell-debug-command 'form "parsed arguments" terms)))
 
 (defun eshell-no-command-conversion (terms)
   "Don't convert the command argument."
@@ -942,38 +918,6 @@ eshell-command-to-value
 ;; finishes, it will resume the evaluation using the remainder of the
 ;; command tree.
 
-(defun eshell/eshell-debug (&rest args)
-  "A command for toggling certain debug variables."
-  (ignore
-   (cond
-    ((not args)
-     (if eshell-handle-errors
-	 (eshell-print "errors\n"))
-     (if eshell-debug-command
-	 (eshell-print "commands\n")))
-    ((member (car args) '("-h" "--help"))
-     (eshell-print "usage: eshell-debug [kinds]
-
-This command is used to aid in debugging problems related to Eshell
-itself.  It is not useful for anything else.  The recognized `kinds'
-at the moment are:
-
-  errors       stops Eshell from trapping errors
-  commands     shows command execution progress in `*eshell last cmd*'
-"))
-    (t
-     (while args
-       (cond
-	((string= (car args) "errors")
-	 (setq eshell-handle-errors (not eshell-handle-errors)))
-	((string= (car args) "commands")
-	 (setq eshell-debug-command (not eshell-debug-command))))
-       (setq args (cdr args)))))))
-
-(defun pcomplete/eshell-mode/eshell-debug ()
-  "Completion for the `debug' command."
-  (while (pcomplete-here '("errors" "commands"))))
-
 (iter-defun eshell--find-subcommands (haystack)
   "Recursively search for subcommand forms in HAYSTACK.
 This yields the SUBCOMMANDs when found in forms like
@@ -1049,10 +993,7 @@ eshell-eval-command
                        (if here
                            (eshell-update-markers here))
                        (eshell-do-eval ',command))))
-    (and eshell-debug-command
-         (with-current-buffer (get-buffer-create "*eshell last cmd*")
-           (erase-buffer)
-           (insert "command: \"" input "\"\n")))
+    (eshell-debug-command-start input)
     (setq eshell-current-command command)
     (let* (result
            (delim (catch 'eshell-incomplete
@@ -1088,17 +1029,17 @@ eshell-resume-eval
     (error
      (error (error-message-string err)))))
 
-(defmacro eshell-manipulate (tag &rest commands)
-  "Manipulate a COMMAND form, with TAG as a debug identifier."
-  (declare (indent 1))
-  ;; Check `bound'ness since at compile time the code until here has not
-  ;; executed yet.
-  (if (not (and (boundp 'eshell-debug-command) eshell-debug-command))
-      `(progn ,@commands)
-    `(progn
-       (eshell-debug-command ,(eval tag) form)
-       ,@commands
-       (eshell-debug-command ,(concat "done " (eval tag)) form))))
+(defmacro eshell-manipulate (form tag &rest body)
+  "Manipulate a command FORM with BODY, using TAG as a debug identifier."
+  (declare (indent 2))
+  (let ((tag-symbol (make-symbol "tag")))
+    `(if (not (memq 'form eshell-debug-command))
+         (progn ,@body)
+       (let ((,tag-symbol ,tag))
+         (eshell-debug-command 'form ,tag-symbol ,form 'always)
+         ,@body
+         (eshell-debug-command 'form (concat "done " ,tag-symbol) ,form
+                               'always)))))
 
 (defun eshell-do-eval (form &optional synchronous-p)
   "Evaluate FORM, simplifying it as we go.
@@ -1125,8 +1066,8 @@ eshell-do-eval
     ;; we can modify any `let' forms to evaluate only once.
     (if (macrop (car form))
         (let ((exp (copy-tree (macroexpand form))))
-	  (eshell-manipulate (format-message "expanding macro `%s'"
-					     (symbol-name (car form)))
+          (eshell-manipulate form
+              (format-message "expanding macro `%s'" (symbol-name (car form)))
 	    (setcar form (car exp))
 	    (setcdr form (cdr exp)))))
     (let ((args (cdr form)))
@@ -1138,7 +1079,7 @@ eshell-do-eval
         (let ((new-form (copy-tree `(let ((eshell--command-body nil)
                                           (eshell--test-body nil))
                                       (eshell--wrapped-while ,@args)))))
-          (eshell-manipulate "modifying while form"
+          (eshell-manipulate form "modifying while form"
             (setcar form (car new-form))
             (setcdr form (cdr new-form)))
           (eshell-do-eval form synchronous-p)))
@@ -1161,7 +1102,7 @@ eshell-do-eval
           (setq eshell--command-body nil
                 eshell--test-body (copy-tree (car args)))))
        ((eq (car form) 'if)
-        (eshell-manipulate "evaluating if condition"
+        (eshell-manipulate form "evaluating if condition"
           (setcar args (eshell-do-eval (car args) synchronous-p)))
         (eshell-do-eval
          (cond
@@ -1180,7 +1121,7 @@ eshell-do-eval
 	(eval form))
        ((eq (car form) 'let)
         (unless (eq (car-safe (cadr args)) 'eshell-do-eval)
-          (eshell-manipulate "evaluating let args"
+          (eshell-manipulate form "evaluating let args"
             (dolist (letarg (car args))
               (when (and (listp letarg)
                          (not (eq (cadr letarg) 'quote)))
@@ -1207,7 +1148,7 @@ eshell-do-eval
             ;; the let-bindings' values so that those values are
             ;; correct when we resume evaluation of this form.
             (when deferred
-              (eshell-manipulate "rebinding let args after `eshell-defer'"
+              (eshell-manipulate form "rebinding let args after `eshell-defer'"
                 (let ((bindings (car args)))
                   (while bindings
                     (let ((binding (if (consp (car bindings))
@@ -1232,7 +1173,7 @@ eshell-do-eval
 	(unless (eq (car form) 'unwind-protect)
 	  (setq args (cdr args)))
 	(unless (eq (caar args) 'eshell-do-eval)
-	  (eshell-manipulate "handling special form"
+          (eshell-manipulate form "handling special form"
 	    (setcar args `(eshell-do-eval ',(car args) ,synchronous-p))))
 	(eval form))
        ((eq (car form) 'setq)
@@ -1242,7 +1183,7 @@ eshell-do-eval
 	(list 'quote (eval form)))
        (t
 	(if (and args (not (memq (car form) '(run-hooks))))
-	    (eshell-manipulate
+            (eshell-manipulate form
 		(format-message "evaluating arguments to `%s'"
 				(symbol-name (car form)))
 	      (while args
@@ -1283,7 +1224,7 @@ eshell-do-eval
                      (setq result (eval form))))))
 	    (if new-form
 		(progn
-		  (eshell-manipulate "substituting replacement form"
+                  (eshell-manipulate form "substituting replacement form"
 		    (setcar form (car new-form))
 		    (setcdr form (cdr new-form)))
 		  (eshell-do-eval form synchronous-p))
@@ -1292,7 +1233,7 @@ eshell-do-eval
                        (procs (eshell-make-process-pair result)))
                   (if synchronous-p
 		      (eshell/wait (cdr procs))
-		    (eshell-manipulate "inserting ignore form"
+                    (eshell-manipulate form "inserting ignore form"
 		      (setcar form 'ignore)
 		      (setcdr form nil))
 		    (throw 'eshell-defer procs))
diff --git a/lisp/eshell/esh-util.el b/lisp/eshell/esh-util.el
index 87cd1f5dcb2..3a318056445 100644
--- a/lisp/eshell/esh-util.el
+++ b/lisp/eshell/esh-util.el
@@ -102,6 +102,15 @@ eshell-ange-ls-uids
 				     (string :tag "Username")
 				     (repeat :tag "UIDs" string))))))
 
+(defcustom eshell-debug-command nil
+  "A list of debug features to enable when running Eshell commands.
+Possible entries are `form', to log the manipulation of Eshell
+command forms, and `io', to log I/O operations.
+
+If nil, don't debug commands at all."
+  :version "30.1"
+  :type '(set (const :tag "Form manipulation" form)))
+
 ;;; Internal Variables:
 
 (defvar eshell-number-regexp
@@ -145,6 +154,9 @@ eshell-command-output-properties
                             ,#'eshell--mark-yanked-as-output))
   "A list of text properties to apply to command output.")
 
+(defvar eshell-debug-command-buffer "*eshell last cmd*"
+  "The name of the buffer to log debug messages about command invocation.")
+
 ;;; Obsolete variables:
 
 (define-obsolete-variable-alias 'eshell-host-names
@@ -164,11 +176,33 @@ eshell-condition-case
   "If `eshell-handle-errors' is non-nil, this is `condition-case'.
 Otherwise, evaluates FORM with no error handling."
   (declare (indent 2) (debug (sexp form &rest form)))
-  (if eshell-handle-errors
-      `(condition-case-unless-debug ,tag
-	   ,form
-	 ,@handlers)
-    form))
+  `(if eshell-handle-errors
+       (condition-case-unless-debug ,tag
+           ,form
+         ,@handlers)
+     ,form))
+
+(defun eshell-debug-command-start (command)
+  "Start debugging output for the command string COMMAND.
+If debugging is enabled (see `eshell-debug-command'), this will
+start logging to `*eshell last cmd*'."
+  (when eshell-debug-command
+    (with-current-buffer (get-buffer-create eshell-debug-command-buffer)
+      (erase-buffer)
+      (insert "command: \"" command "\"\n"))))
+
+(defmacro eshell-debug-command (kind message &optional form always)
+  "Output a debugging message to `*eshell last cmd*' if debugging is enabled.
+KIND is the kind of message to log (either `form' or `io').  If
+present in `eshell-debug-command' (or if ALWAYS is non-nil),
+output this message; otherwise, ignore it."
+  (let ((kind-sym (make-symbol "kind")))
+    `(let ((,kind-sym ,kind))
+       (when ,(or always `(memq ,kind-sym eshell-debug-command))
+         (with-current-buffer (get-buffer-create eshell-debug-command-buffer)
+           (insert "\n\C-l\n[" (symbol-name ,kind-sym) "] " ,message)
+           (when-let ((form ,form))
+             (insert "\n\n" (eshell-stringify form))))))))
 
 (defun eshell--mark-as-output (start end &optional object)
   "Mark the text from START to END as Eshell output.
diff --git a/lisp/eshell/eshell.el b/lisp/eshell/eshell.el
index 15fc2ae6310..cbd0de3c093 100644
--- a/lisp/eshell/eshell.el
+++ b/lisp/eshell/eshell.el
@@ -301,7 +301,8 @@ eshell-command
                     `(let ((eshell-current-handles
                             (eshell-create-handles ,stdout 'insert))
                            (eshell-current-subjob-p))
-		       ,(eshell-parse-command command))))
+		       ,(eshell-parse-command command))
+                    command))
 	     intr
 	     (bufname (if (eq (car-safe proc) :eshell-background)
 			  "*Eshell Async Command Output*"
-- 
2.25.1


[-- Attachment #3: 0002-Add-debug-instrumentation-for-Eshell-process-managem.patch --]
[-- Type: text/plain, Size: 6889 bytes --]

From b8ca3d6d8ee1b1a66d0c8dac88e2cebce43722ac Mon Sep 17 00:00:00 2001
From: Jim Porter <jporterbugs@gmail.com>
Date: Tue, 29 Aug 2023 17:11:42 -0700
Subject: [PATCH 2/2] Add debug instrumentation for Eshell process management

* lisp/eshell/esh-util.el (eshell-debug-command): Add 'process' type.

* lisp/eshell/esh-proc.el (eshell-gather-process-output)
(eshell-interactive-process-filter, eshell-insertion-filter)
(eshell-sentinel): Call 'eshell-debug-command'.

* test/lisp/eshell/eshell-tests-helpers.el (with-temp-eshell): Add
'process' to 'eshell-debug'command'
(eshell-get-debug-logs): New function...
(eshell-match-command-output, eshell-command-result-equal): ... use
it.
---
 lisp/eshell/esh-proc.el                  | 17 ++++++++++++-
 lisp/eshell/esh-util.el                  |  3 ++-
 test/lisp/eshell/eshell-tests-helpers.el | 31 ++++++++++++++++++------
 3 files changed, 41 insertions(+), 10 deletions(-)

diff --git a/lisp/eshell/esh-proc.el b/lisp/eshell/esh-proc.el
index 9c4036004ff..87719c019cb 100644
--- a/lisp/eshell/esh-proc.el
+++ b/lisp/eshell/esh-proc.el
@@ -332,6 +332,8 @@ eshell-gather-process-output
                :connection-type conn-type
                :stderr stderr-proc
                :file-handler t)))
+      (eshell-debug-command
+       'process (format-message "started external process `%s'" proc))
       (eshell-record-process-object proc)
       (eshell-record-process-properties proc)
       (run-hook-with-args 'eshell-exec-hook proc)
@@ -410,6 +412,9 @@ eshell-interactive-process-filter
   "Send the output from PROCESS (STRING) to the interactive display.
 This is done after all necessary filtering has been done."
   (when string
+    (eshell-debug-command
+     'process (format-message "received output from process `%s'\n\n%s"
+                              process string))
     (eshell--mark-as-output 0 (length string) string)
     (require 'esh-mode)
     (declare-function eshell-interactive-filter "esh-mode" (buffer string))
@@ -436,6 +441,9 @@ eshell-insertion-filter
                 (data (process-get proc :eshell-pending)))
             (process-put proc :eshell-pending nil)
             (process-put proc :eshell-busy t)
+            (eshell-debug-command
+             'process (format-message "received output from process `%s'\n\n%s"
+                                      proc string))
             (unwind-protect
                 (condition-case nil
                     (eshell-output-object data index handles)
@@ -460,6 +468,9 @@ eshell-insertion-filter
 (defun eshell-sentinel (proc string)
   "Generic sentinel for command processes.  Reports only signals.
 PROC is the process that's exiting.  STRING is the exit message."
+  (eshell-debug-command
+   'process (format-message "sentinel for external process `%s': %S"
+                            proc string))
   (when (buffer-live-p (process-buffer proc))
     (with-current-buffer (process-buffer proc)
       (unwind-protect
@@ -492,7 +503,11 @@ eshell-sentinel
                              status
                              (when status (list 'quote (= status 0)))
                              handles)
-                            (eshell-kill-process-function proc string)))))
+                            (eshell-kill-process-function proc string)
+                            (eshell-debug-command
+                             'process
+                             (format-message
+                              "finished external process `%s'" proc))))))
                 (funcall finish-io))))
         (when-let ((entry (assq proc eshell-process-list)))
           (eshell-remove-process-entry entry))))))
diff --git a/lisp/eshell/esh-util.el b/lisp/eshell/esh-util.el
index 3a318056445..5f7ac82ae57 100644
--- a/lisp/eshell/esh-util.el
+++ b/lisp/eshell/esh-util.el
@@ -109,7 +109,8 @@ eshell-debug-command
 
 If nil, don't debug commands at all."
   :version "30.1"
-  :type '(set (const :tag "Form manipulation" form)))
+  :type '(set (const :tag "Form manipulation" form)
+              (const :tag "Process operations" process)))
 
 ;;; Internal Variables:
 
diff --git a/test/lisp/eshell/eshell-tests-helpers.el b/test/lisp/eshell/eshell-tests-helpers.el
index 2c913d71cb4..e300f3d657a 100644
--- a/test/lisp/eshell/eshell-tests-helpers.el
+++ b/test/lisp/eshell/eshell-tests-helpers.el
@@ -54,6 +54,12 @@ with-temp-eshell
        (let* (;; We want no history file, so prevent Eshell from falling
               ;; back on $HISTFILE.
               (process-environment (cons "HISTFILE" process-environment))
+              ;; Enable process debug instrumentation.  We may be able
+              ;; to remove this eventually once we're confident that
+              ;; all the process bugs have been worked out.  (At that
+              ;; point, we can just enable this selectively when
+              ;; needed.)
+              (eshell-debug-command (cons 'process eshell-debug-command))
               (eshell-history-file-name nil)
               (eshell-last-dir-ring-file-name nil)
               (eshell-buffer (eshell t)))
@@ -96,6 +102,13 @@ eshell-wait-for-subprocess
    (lambda ()
      (not (if all eshell-process-list (eshell-interactive-process-p))))))
 
+(defun eshell-get-debug-logs ()
+  "Get debug command logs for displaying on test failures."
+  (when (get-buffer eshell-debug-command-buffer)
+    (let ((separator (make-string 40 ?-)))
+      (with-current-buffer eshell-debug-command-buffer
+        (string-replace "\f" separator (buffer-string))))))
+
 (defun eshell-insert-command (command &optional func)
   "Insert a COMMAND at the end of the buffer.
 After inserting, call FUNC.  If FUNC is nil, instead call
@@ -135,10 +148,11 @@ eshell-match-command-output
 
 If IGNORE-ERRORS is non-nil, ignore any errors signaled when
 inserting the command."
-  (let ((debug-on-error (and (not ignore-errors) debug-on-error)))
-    (eshell-insert-command command func))
-  (eshell-wait-for-subprocess)
-  (should (eshell-match-output regexp)))
+  (ert-info (#'eshell-get-debug-logs :prefix "Command logs: ")
+    (let ((debug-on-error (and (not ignore-errors) debug-on-error)))
+      (eshell-insert-command command func))
+    (eshell-wait-for-subprocess)
+    (should (eshell-match-output regexp))))
 
 (defvar eshell-history-file-name)
 
@@ -164,10 +178,11 @@ eshell-command-result--equal-explainer
 
 (defun eshell-command-result-equal (command result)
   "Execute COMMAND non-interactively and compare it to RESULT."
-  (should (eshell-command-result--equal
-           command
-           (eshell-test-command-result command)
-           result)))
+  (ert-info (#'eshell-get-debug-logs :prefix "Command logs: ")
+    (should (eshell-command-result--equal
+             command
+             (eshell-test-command-result command)
+             result))))
 
 (provide 'eshell-tests-helpers)
 
-- 
2.25.1


^ permalink raw reply related	[flat|nested] 24+ messages in thread

* bug#65590: 29.0.50; esh-var-test/interp-concat-cmd fails on macOS
  2023-08-30  0:44     ` Jim Porter
@ 2023-09-01  1:54       ` Jim Porter
  2023-09-01 16:03         ` Stefan Kangas
  0 siblings, 1 reply; 24+ messages in thread
From: Jim Porter @ 2023-09-01  1:54 UTC (permalink / raw)
  To: Stefan Kangas; +Cc: michael.albinus, 65590

On 8/29/2023 5:44 PM, Jim Porter wrote:
> Can you try the following patches? They shouldn't change the behavior, 
> but they do add some extra debugging information to failed tests.

To help diagnose some similar EMBA failures, I've pushed these patches 
to master. Hopefully, we'll get some useful debug info.






^ permalink raw reply	[flat|nested] 24+ messages in thread

* bug#65590: 29.0.50; esh-var-test/interp-concat-cmd fails on macOS
  2023-09-01  1:54       ` Jim Porter
@ 2023-09-01 16:03         ` Stefan Kangas
  2023-09-01 16:30           ` Jim Porter
  0 siblings, 1 reply; 24+ messages in thread
From: Stefan Kangas @ 2023-09-01 16:03 UTC (permalink / raw)
  To: Jim Porter; +Cc: michael.albinus, 65590

[-- Attachment #1: Type: text/plain, Size: 1105 bytes --]

Jim Porter <jporterbugs@gmail.com> writes:
>
> On 8/29/2023 5:44 PM, Jim Porter wrote:
> > Can you try the following patches? They shouldn't change the behavior,
> > but they do add some extra debugging information to failed tests.
>
> To help diagnose some similar EMBA failures, I've pushed these patches
> to master. Hopefully, we'll get some useful debug info.

Thanks.  Please see the attached files, with debug logs from these
test failures:

SUMMARY OF TEST RESULTS
-----------------------
Files examined: 492
Ran 7306 tests, 6974 results as expected, 5 unexpected, 233 skipped
4 files did not finish:
  lisp/eshell/eshell-tests.log
  lisp/eshell/esh-var-tests.log
  lisp/eshell/esh-io-tests.log
  lisp/eshell/esh-cmd-tests.log
5 files contained unexpected results:
  lisp/progmodes/etags-tests.log
  lisp/eshell/eshell-tests.log
  lisp/eshell/esh-var-tests.log
  lisp/eshell/esh-io-tests.log
  lisp/eshell/esh-cmd-tests.log
make[2]: *** [check-doit] Error 2
make[1]: *** [check] Error 2
make: *** [check] Error 2

Compilation exited abnormally with code 2 at Fri Sep  1 17:51:35,
duration 0:08:10

[-- Attachment #2: esh-io-tests.log.gz --]
[-- Type: application/x-gzip, Size: 7310 bytes --]

[-- Attachment #3: esh-cmd-tests.log.gz --]
[-- Type: application/x-gzip, Size: 12266 bytes --]

[-- Attachment #4: eshell-tests.log.gz --]
[-- Type: application/x-gzip, Size: 11683 bytes --]

[-- Attachment #5: esh-var-tests.log.gz --]
[-- Type: application/x-gzip, Size: 226253 bytes --]

^ permalink raw reply	[flat|nested] 24+ messages in thread

* bug#65590: 29.0.50; esh-var-test/interp-concat-cmd fails on macOS
  2023-09-01 16:03         ` Stefan Kangas
@ 2023-09-01 16:30           ` Jim Porter
  2023-09-01 17:00             ` Jim Porter
  0 siblings, 1 reply; 24+ messages in thread
From: Jim Porter @ 2023-09-01 16:30 UTC (permalink / raw)
  To: Stefan Kangas; +Cc: 65590, michael.albinus

On 9/1/2023 9:03 AM, Stefan Kangas wrote:
> Jim Porter <jporterbugs@gmail.com> writes:
>>
>> On 8/29/2023 5:44 PM, Jim Porter wrote:
>>> Can you try the following patches? They shouldn't change the behavior,
>>> but they do add some extra debugging information to failed tests.
>>
>> To help diagnose some similar EMBA failures, I've pushed these patches
>> to master. Hopefully, we'll get some useful debug info.
> 
> Thanks.  Please see the attached files, with debug logs from these
> test failures:

Hmm, that's not right. Did you do a full recompile of all the Eshell 
code/tests? The errors should look something like this (just an example 
from me forcing a test to fail):

------------------------------------------------------------

Test esh-proc-test/output/to-screen condition:
     Command logs: command: "sh -c 'echo stdout; echo stderr >&2'"

                   ----------------------------------------
                   [process] started external process `sh'
                   ----------------------------------------
                   [process] received output from process `sh'

                   stdout
                   stderr

                   ----------------------------------------
                   [process] sentinel for external process `sh': "finished
                   "
                   ----------------------------------------
                   [process] finished external process `sh'
     (ert-test-failed
      ((should (eshell-match-output regexp)) :form
       (eshell-match-output "[TEST]stdout\nstderr\n") :value nil
       :explanation
       (mismatched-output
        (command "sh -c 'echo stdout; echo stderr >&2'\n")
        (output "stdout\nstderr\n") (regexp "[TEST]stdout\nstderr\n"))))
    FAILED  11/21  esh-proc-test/output/to-screen (0.105507 sec) at 
../../test/lisp/eshell/esh-proc-tests.el:52





^ permalink raw reply	[flat|nested] 24+ messages in thread

* bug#65590: 29.0.50; esh-var-test/interp-concat-cmd fails on macOS
  2023-09-01 16:30           ` Jim Porter
@ 2023-09-01 17:00             ` Jim Porter
  2023-09-12 18:53               ` Jim Porter
  0 siblings, 1 reply; 24+ messages in thread
From: Jim Porter @ 2023-09-01 17:00 UTC (permalink / raw)
  To: Stefan Kangas; +Cc: michael.albinus, 65590

On 9/1/2023 9:30 AM, Jim Porter wrote:
> On 9/1/2023 9:03 AM, Stefan Kangas wrote:
>> Thanks.  Please see the attached files, with debug logs from these
>> test failures:
> 
> Hmm, that's not right. Did you do a full recompile of all the Eshell 
> code/tests?

I also pushed a small fix to the debugging code to master as 
da8b323f82417697f9b772689810099f426fe616, but that shouldn't affect this 
case (much).





^ permalink raw reply	[flat|nested] 24+ messages in thread

* bug#65590: 29.0.50; esh-var-test/interp-concat-cmd fails on macOS
  2023-09-01 17:00             ` Jim Porter
@ 2023-09-12 18:53               ` Jim Porter
  2023-09-13 16:10                 ` Stefan Kangas
  0 siblings, 1 reply; 24+ messages in thread
From: Jim Porter @ 2023-09-12 18:53 UTC (permalink / raw)
  To: Stefan Kangas; +Cc: 65590, michael.albinus

On 9/1/2023 10:00 AM, Jim Porter wrote:
> I also pushed a small fix to the debugging code to master as 
> da8b323f82417697f9b772689810099f426fe616, but that shouldn't affect this 
> case (much).

I pushed a couple more correctness fixes for Eshell's process management 
to master as fad91b56d13. Hopefully these will help matters (but to be 
fair, I'm a little skeptical that the bug I fixed is the same as this 
bug...)





^ permalink raw reply	[flat|nested] 24+ messages in thread

* bug#65590: 29.0.50; esh-var-test/interp-concat-cmd fails on macOS
  2023-09-12 18:53               ` Jim Porter
@ 2023-09-13 16:10                 ` Stefan Kangas
  2023-09-13 18:54                   ` Jim Porter
  0 siblings, 1 reply; 24+ messages in thread
From: Stefan Kangas @ 2023-09-13 16:10 UTC (permalink / raw)
  To: Jim Porter; +Cc: 65590, michael.albinus

Jim Porter <jporterbugs@gmail.com> writes:

> On 9/1/2023 10:00 AM, Jim Porter wrote:
>> I also pushed a small fix to the debugging code to master as
>> da8b323f82417697f9b772689810099f426fe616, but that shouldn't affect this
>> case (much).
>
> I pushed a couple more correctness fixes for Eshell's process management
> to master as fad91b56d13. Hopefully these will help matters (but to be
> fair, I'm a little skeptical that the bug I fixed is the same as this
> bug...)

Sorry for the slow turnaround time.

I'm currently seeing these test failures on master:

Running 46 tests (2023-09-13 16:46:00+0200, selector ‘(not (or (tag
:expensive-test) (tag :unstable) (tag :nativecomp)))’)
Loading em-alias...
Loading em-banner...
Loading em-basic...
Loading em-cmpl...
Loading em-extpipe...
Loading em-glob...
Loading em-hist...
Loading em-ls...
Loading em-pred...
Loading em-prompt...
Loading em-script...
Loading em-term...
Loading em-unix...
   passed   1/46  esh-cmd-test/and-operator (0.259946 sec)
   passed   2/46  esh-cmd-test/backquoted-lisp-form (0.001679 sec)
   passed   3/46  esh-cmd-test/backquoted-lisp-form/splice (0.001686 sec)
   passed   4/46  esh-cmd-test/for-loop (0.006714 sec)
   passed   5/46  esh-cmd-test/for-loop-for-items-shadow (0.004334 sec)
   passed   6/46  esh-cmd-test/for-loop-list (0.003476 sec)
   passed   7/46  esh-cmd-test/for-loop-multiple-args (0.006086 sec)
   passed   8/46  esh-cmd-test/for-loop-name (0.002023 sec)
   passed   9/46  esh-cmd-test/for-loop-name-shadow (0.003343 sec)
   passed  10/46  esh-cmd-test/for-loop-pipe (0.112573 sec)
   passed  11/46  esh-cmd-test/if-else-statement (0.031268 sec)
   passed  12/46  esh-cmd-test/if-else-statement-ext-cmd (0.126054 sec)
   passed  13/46  esh-cmd-test/if-else-statement-lisp-form (0.005082 sec)
   passed  14/46  esh-cmd-test/if-else-statement-lisp-form-2 (0.004613 sec)
   passed  15/46  esh-cmd-test/if-else-statement-pipe (0.239692 sec)
   passed  16/46  esh-cmd-test/if-statement (0.003869 sec)
   passed  17/46  esh-cmd-test/if-statement-pipe (0.226295 sec)
   passed  18/46  esh-cmd-test/let-rebinds-after-defer (0.113418 sec)
   passed  19/46  esh-cmd-test/lisp-command (0.002054 sec)
   passed  20/46  esh-cmd-test/lisp-command-args (0.002587 sec)
   passed  21/46  esh-cmd-test/lisp-command-with-quote (0.001719 sec)
   passed  22/46  esh-cmd-test/or-operator (0.233849 sec)
   passed  23/46  esh-cmd-test/pipeline-wait/head-proc (0.113463 sec)
   passed  24/46  esh-cmd-test/pipeline-wait/multi-proc (1.045003 sec)
   passed  25/46  esh-cmd-test/pipeline-wait/subcommand (0.119225 sec)
   passed  26/46  esh-cmd-test/pipeline-wait/subcommand-with-pipe (0.137609 sec)
   passed  27/46  esh-cmd-test/pipeline-wait/tail-proc (0.124454 sec)
   passed  28/46  esh-cmd-test/quoted-lisp-form (0.002298 sec)
Test esh-cmd-test/reset-in-pipeline/lisp backtrace:
  signal(ert-test-failed (((should (eshell-command-result--equal comma
  ert-fail(((should (eshell-command-result--equal command (eshell-test
  eshell-command-result-equal("echo $(format \"%s\" eshell-in-pipeline
  #f(compiled-function () #<bytecode 0xaa47d7f4bc36b29>)()
  ert--run-test-internal(#s(ert--test-execution-info :test #s(ert-test
  ert-run-test(#s(ert-test :name esh-cmd-test/reset-in-pipeline/lisp :
  ert-run-or-rerun-test(#s(ert--stats :selector ... :tests ... :test-m
  ert-run-tests((not (or (tag :expensive-test) (tag :unstable) (tag :n
  ert-run-tests-batch((not (or (tag :expensive-test) (tag :unstable) (
  ert-run-tests-batch-and-exit((not (or (tag :expensive-test) (tag :un
  eval((ert-run-tests-batch-and-exit '(not (or (tag :expensive-test) (
  command-line-1(("-L" ":." "-l" "ert" "-l" "lisp/eshell/esh-cmd-tests
  command-line()
  normal-top-level()
Test esh-cmd-test/reset-in-pipeline/lisp condition:
    Command logs: command: "echo $(format "%s" eshell-in-pipeline-p) | *cat"

                  ----------------------------------------
                  [process] started external process ‘cat’
    (ert-test-failed
     ((should
       (eshell-command-result--equal command
				     (eshell-test-command-result command)
				     result))
      :form
      (eshell-command-result--equal
       "echo $(format \"%s\" eshell-in-pipeline-p) | *cat" nil "nil")
      :value nil :explanation
      (nonequal-result
       (command "echo $(format \"%s\" eshell-in-pipeline-p) | *cat")
       (result nil) (expected "nil"))))
   FAILED  29/46  esh-cmd-test/reset-in-pipeline/lisp (0.087616 sec)
at lisp/eshell/esh-cmd-tests.el:203
Test esh-cmd-test/reset-in-pipeline/subcommand backtrace:
  signal(ert-test-failed (((should (eshell-command-result--equal comma
  ert-fail(((should (eshell-command-result--equal command (eshell-test
  eshell-command-result-equal("echo {echo | echo $eshell-in-pipeline-p
  #f(compiled-function () #<bytecode 0x1a4482f59c3edde8>)()
  ert--run-test-internal(#s(ert--test-execution-info :test #s(ert-test
  ert-run-test(#s(ert-test :name esh-cmd-test/reset-in-pipeline/subcom
  ert-run-or-rerun-test(#s(ert--stats :selector ... :tests ... :test-m
  ert-run-tests((not (or (tag :expensive-test) (tag :unstable) (tag :n
  ert-run-tests-batch((not (or (tag :expensive-test) (tag :unstable) (
  ert-run-tests-batch-and-exit((not (or (tag :expensive-test) (tag :un
  eval((ert-run-tests-batch-and-exit '(not (or (tag :expensive-test) (
  command-line-1(("-L" ":." "-l" "ert" "-l" "lisp/eshell/esh-cmd-tests
  command-line()
  normal-top-level()
Test esh-cmd-test/reset-in-pipeline/subcommand condition:
    Command logs: command: "echo {echo | echo $eshell-in-pipeline-p} | *cat"

                  ----------------------------------------
                  [process] started external process ‘cat’
    (ert-test-failed
     ((should
       (eshell-command-result--equal command
				     (eshell-test-command-result command)
				     result))
      :form
      (eshell-command-result--equal
       "echo {echo | echo $eshell-in-pipeline-p} | *cat" nil "last")
      :value nil :explanation
      (nonequal-result
       (command "echo {echo | echo $eshell-in-pipeline-p} | *cat")
       (result nil) (expected "last"))))
   FAILED  30/46  esh-cmd-test/reset-in-pipeline/subcommand (0.078130
sec) at lisp/eshell/esh-cmd-tests.el:184
   passed  31/46  esh-cmd-test/simple-command-result (0.003985 sec)
   passed  32/46  esh-cmd-test/subcommand (0.005324 sec)
   passed  33/46  esh-cmd-test/subcommand-args (0.002383 sec)
   passed  34/46  esh-cmd-test/subcommand-lisp (0.001339 sec)
   passed  35/46  esh-cmd-test/subcommand-shadow-value (0.002534 sec)
   passed  36/46  esh-cmd-test/unless-else-statement (0.017221 sec)
Test esh-cmd-test/unless-else-statement-ext-cmd backtrace:
  signal(ert-test-failed (((should (eshell-command-result--equal comma
  ert-fail(((should (eshell-command-result--equal command (eshell-test
  eshell-command-result-equal("unless {[ foo = bar ]} {echo no} {echo
  #f(compiled-function () #<bytecode -0x9ffeea180f72755>)()
  ert--run-test-internal(#s(ert--test-execution-info :test #s(ert-test
  ert-run-test(#s(ert-test :name esh-cmd-test/unless-else-statement-ex
  ert-run-or-rerun-test(#s(ert--stats :selector ... :tests ... :test-m
  ert-run-tests((not (or (tag :expensive-test) (tag :unstable) (tag :n
  ert-run-tests-batch((not (or (tag :expensive-test) (tag :unstable) (
  ert-run-tests-batch-and-exit((not (or (tag :expensive-test) (tag :un
  eval((ert-run-tests-batch-and-exit '(not (or (tag :expensive-test) (
  command-line-1(("-L" ":." "-l" "ert" "-l" "lisp/eshell/esh-cmd-tests
  command-line()
  normal-top-level()
Test esh-cmd-test/unless-else-statement-ext-cmd condition:
    Command logs: command: "unless {[ foo = bar ]} {echo no} {echo yes}"

                  ----------------------------------------
                  [process] started external process ‘[<1>’
    (ert-test-failed
     ((should
       (eshell-command-result--equal command
				     (eshell-test-command-result command)
				     result))
      :form
      (eshell-command-result--equal
       "unless {[ foo = bar ]} {echo no} {echo yes}" "yes" "no")
      :value nil :explanation
      (nonequal-result
       (command "unless {[ foo = bar ]} {echo no} {echo yes}")
       (result "yes") (expected "no"))))
   FAILED  37/46  esh-cmd-test/unless-else-statement-ext-cmd (0.031509
sec) at lisp/eshell/esh-cmd-tests.el:431
   passed  38/46  esh-cmd-test/unless-else-statement-lisp-form (0.007760 sec)
   passed  39/46  esh-cmd-test/unless-statement (0.003845 sec)
   passed  40/46  esh-cmd-test/until-loop (0.010837 sec)
   passed  41/46  esh-cmd-test/until-loop-ext-cmd (0.125156 sec)
   passed  42/46  esh-cmd-test/until-loop-lisp-form (0.009843 sec)
   passed  43/46  esh-cmd-test/while-loop (0.012687 sec)
   passed  44/46  esh-cmd-test/while-loop-ext-cmd (0.155605 sec)
   passed  45/46  esh-cmd-test/while-loop-lisp-form (0.004418 sec)
   passed  46/46  esh-cmd-test/while-loop-pipe (0.120805 sec)

Ran 46 tests, 43 results as expected, 3 unexpected (2023-09-13
16:46:05+0200, 4.562085 sec)

3 unexpected results:
   FAILED  esh-cmd-test/reset-in-pipeline/lisp
   FAILED  esh-cmd-test/reset-in-pipeline/subcommand
   FAILED  esh-cmd-test/unless-else-statement-ext-cmd





^ permalink raw reply	[flat|nested] 24+ messages in thread

* bug#65590: 29.0.50; esh-var-test/interp-concat-cmd fails on macOS
  2023-09-13 16:10                 ` Stefan Kangas
@ 2023-09-13 18:54                   ` Jim Porter
  2023-09-13 20:34                     ` Stefan Kangas
  0 siblings, 1 reply; 24+ messages in thread
From: Jim Porter @ 2023-09-13 18:54 UTC (permalink / raw)
  To: Stefan Kangas; +Cc: michael.albinus, 65590

[-- Attachment #1: Type: text/plain, Size: 229 bytes --]

On 9/13/2023 9:10 AM, Stefan Kangas wrote:
> Sorry for the slow turnaround time.
> 
> I'm currently seeing these test failures on master: [snip]
Thanks for the logs. Could you try the attached patch to see if it 
improves things?

[-- Attachment #2: 0001-When-waiting-for-processes-in-Eshell-wait-until-all-.patch --]
[-- Type: text/plain, Size: 1779 bytes --]

From 26b8f18dbff1ccbf0d6c91b7208cb0a4c6d73e4c Mon Sep 17 00:00:00 2001
From: Jim Porter <jporterbugs@gmail.com>
Date: Wed, 13 Sep 2023 11:50:39 -0700
Subject: [PATCH] When waiting for processes in Eshell, wait until all the I/O
 is complete

* lisp/eshell/esh-proc.el (eshell-sentinel): Set ':eshell-handles' to
nil when finished with I/O.
(eshell-wait-for-process): Wait until ':eshell-handles' is nil.
---
 lisp/eshell/esh-proc.el | 9 ++++++++-
 1 file changed, 8 insertions(+), 1 deletion(-)

diff --git a/lisp/eshell/esh-proc.el b/lisp/eshell/esh-proc.el
index 5df68947ec2..afd0ed80132 100644
--- a/lisp/eshell/esh-proc.el
+++ b/lisp/eshell/esh-proc.el
@@ -161,7 +161,11 @@ eshell-wait-for-process
   "Wait until PROCS have successfully completed."
   (dolist (proc procs)
     (when (eshell-processp proc)
-      (while (process-live-p proc)
+      (while (or (process-live-p proc)
+                 ;; If we have handles, this is an Eshell-managed
+                 ;; process.  Wait until we're 100% done and have
+                 ;; cleared out the handles (see `eshell-sentinel').
+                 (process-get proc :eshell-handles))
         (when (input-pending-p)
           (discard-input))
         (sit-for eshell-process-wait-seconds
@@ -530,6 +534,9 @@ eshell-sentinel
                            status
                            (when status (list 'quote (= status 0)))
                            handles)
+                          ;; Clear the handles to mark that we're 100%
+                          ;; finished with the I/O for this process.
+                          (process-put proc :eshell-handles nil)
                           (eshell-debug-command
                            'process
                            (format-message
-- 
2.25.1


^ permalink raw reply related	[flat|nested] 24+ messages in thread

* bug#65590: 29.0.50; esh-var-test/interp-concat-cmd fails on macOS
  2023-09-13 18:54                   ` Jim Porter
@ 2023-09-13 20:34                     ` Stefan Kangas
  2023-09-13 20:41                       ` Jim Porter
  0 siblings, 1 reply; 24+ messages in thread
From: Stefan Kangas @ 2023-09-13 20:34 UTC (permalink / raw)
  To: Jim Porter; +Cc: michael.albinus, 65590

Jim Porter <jporterbugs@gmail.com> writes:

> Thanks for the logs. Could you try the attached patch to see if it
> improves things?

Thanks.  The tests do not seem to fail with that patch:

  GEN      lisp/eshell/esh-cmd-tests.log

I was seeing some intermittent deadlocks in esh-cmd-tests.el at first,
but not yet after I rebased your patch on top of the fixes you just
pushed to master.

So for now, your patch seems to improve things.  I'll report back if I
see the deadlocks again.





^ permalink raw reply	[flat|nested] 24+ messages in thread

* bug#65590: 29.0.50; esh-var-test/interp-concat-cmd fails on macOS
  2023-09-13 20:34                     ` Stefan Kangas
@ 2023-09-13 20:41                       ` Jim Porter
  2023-09-13 20:48                         ` Stefan Kangas
  2023-09-13 21:13                         ` bug#65590: " Stefan Kangas
  0 siblings, 2 replies; 24+ messages in thread
From: Jim Porter @ 2023-09-13 20:41 UTC (permalink / raw)
  To: Stefan Kangas; +Cc: 65590, michael.albinus

On 9/13/2023 1:34 PM, Stefan Kangas wrote:
> Jim Porter <jporterbugs@gmail.com> writes:
> 
>> Thanks for the logs. Could you try the attached patch to see if it
>> improves things?
> 
> Thanks.  The tests do not seem to fail with that patch:
> 
>    GEN      lisp/eshell/esh-cmd-tests.log
> 
> I was seeing some intermittent deadlocks in esh-cmd-tests.el at first,
> but not yet after I rebased your patch on top of the fixes you just
> pushed to master.
> 
> So for now, your patch seems to improve things.  I'll report back if I
> see the deadlocks again.

Thanks. Pushed to master as 9838f786ded. This hopefully resolves this 
bug, along with bug#59103 and bug#65601.





^ permalink raw reply	[flat|nested] 24+ messages in thread

* bug#65590: 29.0.50; esh-var-test/interp-concat-cmd fails on macOS
  2023-09-13 20:41                       ` Jim Porter
@ 2023-09-13 20:48                         ` Stefan Kangas
  2023-09-13 21:10                           ` bug#65590: bug#65602: 30.0.50; eshell-test/{elisp,subcommand}-reset-in-pipeline fails intermittently " Stefan Kangas
  2023-09-13 21:13                         ` bug#65590: " Stefan Kangas
  1 sibling, 1 reply; 24+ messages in thread
From: Stefan Kangas @ 2023-09-13 20:48 UTC (permalink / raw)
  To: Jim Porter; +Cc: 65590, michael.albinus

Jim Porter <jporterbugs@gmail.com> writes:

> Thanks. Pushed to master as 9838f786ded. This hopefully resolves this
> bug, along with bug#59103 and bug#65601.

Thanks for the fix, and feel free to close this bug and the others (note
that I merged some of them).

We can always reopen this if these issues resurface.





^ permalink raw reply	[flat|nested] 24+ messages in thread

* bug#65590: bug#65602: 30.0.50; eshell-test/{elisp,subcommand}-reset-in-pipeline fails intermittently on macOS
  2023-09-13 20:48                         ` Stefan Kangas
@ 2023-09-13 21:10                           ` Stefan Kangas
  2023-09-13 21:33                             ` Stefan Kangas
  0 siblings, 1 reply; 24+ messages in thread
From: Stefan Kangas @ 2023-09-13 21:10 UTC (permalink / raw)
  To: Jim Porter; +Cc: michael.albinus, 65590, 65602

Stefan Kangas <stefankangas@gmail.com> writes:

> Jim Porter <jporterbugs@gmail.com> writes:
>
>> Thanks. Pushed to master as 9838f786ded. This hopefully resolves this
>> bug, along with bug#59103 and bug#65601.
>
> Thanks for the fix, and feel free to close this bug and the others (note
> that I merged some of them).
>
> We can always reopen this if these issues resurface.

I spoke too soon, as I'm now seeing the below two failures.

   FAILED   42/110  esh-var-test/interp-var-indices-subcommand
(0.787189 sec) at lisp/eshell/esh-var-tests.el:184

   FAILED   5/11  eshell-test/eshell-command/simple (0.670351 sec) at
lisp/eshell/eshell-tests.el:41

I'm trying to reproduce it a second time, but they don't always show up.

Meanwhile, here is the complete log:

Running 110 tests (2023-09-13 22:35:13+0200, selector ‘(not (or (tag
:expensive-test) (tag :unstable) (tag :nativecomp)))’)
Loading em-alias...
Loading em-banner...
Loading em-basic...
Loading em-cmpl...
Loading em-extpipe...
Loading em-glob...
Loading em-hist...
Loading em-ls...
Loading em-pred...
Loading em-prompt...
Loading em-script...
Loading em-term...
Loading em-unix...
   passed    1/110  esh-var-test/alias/export (0.088465 sec)
   passed    2/110  esh-var-test/alias/function (0.002535 sec)
   passed    3/110  esh-var-test/alias/function-pair (0.001671 sec)
   passed    4/110  esh-var-test/alias/local-variables (0.005713 sec)
   passed    5/110  esh-var-test/alias/string (0.003960 sec)
   passed    6/110  esh-var-test/alias/string/prefer-lisp (0.002671 sec)
   passed    7/110  esh-var-test/alias/symbol (0.003753 sec)
   passed    8/110  esh-var-test/alias/symbol-pair (0.002834 sec)
   passed    9/110  esh-var-test/columns-var (0.002136 sec)
   passed   10/110  esh-var-test/command-interp (0.001959 sec)
   passed   11/110  esh-var-test/command-interp-splice (0.002680 sec)
   passed   12/110  esh-var-test/export (0.002692 sec)
   passed   13/110  esh-var-test/gid-var (0.001037 sec)
   passed   14/110  esh-var-test/inside-emacs-var (0.003868 sec)
   passed   15/110  esh-var-test/inside-emacs-var-split-indices (0.002742 sec)
   passed   16/110  esh-var-test/interp-cmd (0.010029 sec)
   passed   17/110  esh-var-test/interp-cmd-external (0.109887 sec)
   passed   18/110  esh-var-test/interp-cmd-external-indices (0.119196 sec)
   passed   19/110  esh-var-test/interp-cmd-indices (0.017139 sec)
   passed   20/110  esh-var-test/interp-concat-cmd (0.230823 sec)
   passed   21/110  esh-var-test/interp-concat-cmd-external (0.113160 sec)
   passed   22/110  esh-var-test/interp-concat-cmd2 (0.006122 sec)
   passed   23/110  esh-var-test/interp-concat-lisp (0.002987 sec)
   passed   24/110  esh-var-test/interp-concat-lisp2 (0.002998 sec)
   passed   25/110  esh-var-test/interp-convert-cmd-multiline (0.006679 sec)
   passed   26/110  esh-var-test/interp-convert-cmd-number (0.001994 sec)
   passed   27/110  esh-var-test/interp-convert-cmd-split-indices (0.003176 sec)
   passed   28/110  esh-var-test/interp-convert-cmd-string-newline
(0.001614 sec)
   passed   29/110  esh-var-test/interp-convert-quoted-var-number (0.004028 sec)
   passed   30/110
esh-var-test/interp-convert-quoted-var-split-indices (0.002890 sec)
   passed   31/110  esh-var-test/interp-convert-var-number (0.002947 sec)
   passed   32/110  esh-var-test/interp-convert-var-split-indices (0.007150 sec)
   passed   33/110  esh-var-test/interp-lisp (0.001717 sec)
   passed   34/110  esh-var-test/interp-lisp-indices (0.001671 sec)
   passed   35/110  esh-var-test/interp-list-var (0.001838 sec)
   passed   36/110  esh-var-test/interp-list-var-concat (0.001501 sec)
   passed   37/110  esh-var-test/interp-quoted-var (0.003192 sec)
   passed   38/110  esh-var-test/interp-quoted-var-concat (0.003008 sec)
   passed   39/110  esh-var-test/interp-temp-cmd (0.015746 sec)
   passed   40/110  esh-var-test/interp-var (0.001530 sec)
   passed   41/110  esh-var-test/interp-var-assoc (0.004526 sec)
Test esh-var-test/interp-var-indices-subcommand backtrace:
  signal(ert-test-failed (((should (eshell-command-result--equal comma
  ert-fail(((should (eshell-command-result--equal command (eshell-test
  eshell-command-result-equal("echo $eshell-test-value[${*echo 0} ${*e
  #f(compiled-function () #<bytecode 0xa6a8df2b60ef482>)()
  ert--run-test-internal(#s(ert--test-execution-info :test #s(ert-test
  ert-run-test(#s(ert-test :name esh-var-test/interp-var-indices-subco
  ert-run-or-rerun-test(#s(ert--stats :selector ... :tests ... :test-m
  ert-run-tests((not (or (tag :expensive-test) (tag :unstable) (tag :n
  ert-run-tests-batch((not (or (tag :expensive-test) (tag :unstable) (
  ert-run-tests-batch-and-exit((not (or (tag :expensive-test) (tag :un
  eval((ert-run-tests-batch-and-exit '(not (or (tag :expensive-test) (
  command-line-1(("-L" ":." "-l" "ert" "-l" "lisp/eshell/esh-var-tests
  command-line()
  normal-top-level()
Test esh-var-test/interp-var-indices-subcommand condition:
    Command logs: command: "echo $eshell-test-value[${*echo 0} ${*echo 2}]"

                  ----------------------------------------
                  [process] started external process ‘echo’
                  ----------------------------------------
                  [process] sentinel for external process ‘echo’: "finished
                  "
                  ----------------------------------------
                  [process] finished external process ‘echo’
                  ----------------------------------------
                  [process] started external process ‘echo’
                  ----------------------------------------
                  [process] received output from process ‘echo’

                  2

                  ----------------------------------------
                  [process] sentinel for external process ‘echo’: "finished
                  "
                  ----------------------------------------
                  [process] finished external process ‘echo’
    (ert-test-failed
     ((should
       (eshell-command-result--equal command
				     (eshell-test-command-result command)
				     result))
      :form
      (eshell-command-result--equal
       "echo $eshell-test-value[${*echo 0} ${*echo 2}]" (nil "two")
       ("zero" "two"))
      :value nil :explanation
      (nonequal-result
       (command "echo $eshell-test-value[${*echo 0} ${*echo 2}]")
       (result (nil "two")) (expected ("zero" "two")))))
   FAILED   42/110  esh-var-test/interp-var-indices-subcommand
(0.787189 sec) at lisp/eshell/esh-var-tests.el:184
   passed   43/110  esh-var-test/interp-var-indices/list (0.019358 sec)
   passed   44/110  esh-var-test/interp-var-indices/ring (0.020269 sec)
   passed   45/110  esh-var-test/interp-var-indices/split (0.037000 sec)
   passed   46/110  esh-var-test/interp-var-indices/vector (0.026923 sec)
   passed   47/110  esh-var-test/interp-var-length-alist (0.010415 sec)
   passed   48/110  esh-var-test/interp-var-length-list (0.006603 sec)
   passed   49/110  esh-var-test/interp-var-length-string (0.002292 sec)
   passed   50/110  esh-var-test/interp-var-regexp-split-indices (0.242747 sec)
   passed   51/110  esh-var-test/interp-var-splice (0.002365 sec)
   passed   52/110  esh-var-test/interp-var-splice-concat (0.004213 sec)
   passed   53/110  esh-var-test/interp-var-string-split-indices (0.016318 sec)
   passed   54/110  esh-var-test/last-arg-var (0.009780 sec)
   passed   55/110  esh-var-test/last-arg-var-indices (0.039239 sec)
   passed   56/110  esh-var-test/last-arg-var-split-indices (0.028203 sec)
   passed   57/110  esh-var-test/last-result-var (0.006147 sec)
   passed   58/110  esh-var-test/last-result-var-ext-cmd (0.266221 sec)
   passed   59/110  esh-var-test/last-result-var-split-indices (0.010959 sec)
   passed   60/110  esh-var-test/last-result-var-twice (0.006037 sec)
   passed   61/110  esh-var-test/last-status-var-ext-cmd (0.231988 sec)
   passed   62/110  esh-var-test/last-status-var-lisp-command (0.009926 sec)
   passed   63/110  esh-var-test/last-status-var-lisp-form (0.006611 sec)
   passed   64/110  esh-var-test/last-status-var-lisp-form-2 (0.005176 sec)
   passed   65/110  esh-var-test/lines-var (0.002246 sec)
   passed   66/110  esh-var-test/local-variables (0.006088 sec)
   passed   67/110  esh-var-test/pager-var/default (0.003803 sec)
   passed   68/110  esh-var-test/pager-var/set (0.005817 sec)
   passed   69/110  esh-var-test/pager-var/set-locally (0.012370 sec)
   passed   70/110  esh-var-test/pager-var/unset (0.005745 sec)
   passed   71/110  esh-var-test/path-var/local-directory (0.002657 sec)
Tramp: Sending command ‘exec sh -i’
Tramp: Found remote shell prompt on ‘SK-MacBook-Pro’
   passed   72/110  esh-var-test/path-var/preserve-across-hosts (0.633738 sec)
   passed   73/110  esh-var-test/path-var/remote-directory (0.008255 sec)
   passed   74/110  esh-var-test/path-var/set (0.002298 sec)
   passed   75/110  esh-var-test/path-var/set-locally (0.006185 sec)
   passed   76/110  esh-var-test/quote-interp-var-indices-subcommand
(0.200504 sec)
   passed   77/110  esh-var-test/quoted-interp-cmd (0.003089 sec)
   passed   78/110  esh-var-test/quoted-interp-cmd-indices (0.003972 sec)
   passed   79/110  esh-var-test/quoted-interp-concat-cmd (0.002686 sec)
   passed   80/110  esh-var-test/quoted-interp-convert-cmd-multiline
(0.002652 sec)
   passed   81/110  esh-var-test/quoted-interp-convert-cmd-number (0.002783 sec)
   passed   82/110
esh-var-test/quoted-interp-convert-cmd-split-indices (0.003088 sec)
   passed   83/110
esh-var-test/quoted-interp-convert-cmd-string-newline (0.004199 sec)
   passed   84/110
esh-var-test/quoted-interp-convert-quoted-var-number (0.006084 sec)
   passed   85/110
esh-var-test/quoted-interp-convert-quoted-var-split-indices (0.004098
sec)
   passed   86/110  esh-var-test/quoted-interp-convert-var-number (0.002988 sec)
   passed   87/110
esh-var-test/quoted-interp-convert-var-split-indices (0.004272 sec)
   passed   88/110  esh-var-test/quoted-interp-lisp (0.001916 sec)
   passed   89/110  esh-var-test/quoted-interp-lisp-indices (0.003084 sec)
   passed   90/110  esh-var-test/quoted-interp-list-var (0.001994 sec)
   passed   91/110  esh-var-test/quoted-interp-list-var-concat (0.001896 sec)
   passed   92/110  esh-var-test/quoted-interp-quoted-var (0.002696 sec)
   passed   93/110  esh-var-test/quoted-interp-temp-cmd (0.014113 sec)
   passed   94/110  esh-var-test/quoted-interp-var (0.001652 sec)
   passed   95/110  esh-var-test/quoted-interp-var-assoc (0.003079 sec)
   passed   96/110  esh-var-test/quoted-interp-var-indices (0.006305 sec)
   passed   97/110  esh-var-test/quoted-interp-var-length-alist (0.004078 sec)
   passed   98/110  esh-var-test/quoted-interp-var-length-list (0.005522 sec)
   passed   99/110  esh-var-test/quoted-interp-var-length-string (0.001733 sec)
   passed  100/110
esh-var-test/quoted-interp-var-regexp-split-indices (0.006641 sec)
   passed  101/110  esh-var-test/quoted-interp-var-splice (0.001625 sec)
   passed  102/110  esh-var-test/quoted-interp-var-splice-concat (0.001853 sec)
   passed  103/110  esh-var-test/quoted-interp-var-split-indices (0.004032 sec)
   passed  104/110
esh-var-test/quoted-interp-var-string-split-indices (0.011405 sec)
   passed  105/110  esh-var-test/set/env-var (0.002622 sec)
   passed  106/110  esh-var-test/set/symbol (0.001815 sec)
   passed  107/110  esh-var-test/setq (0.001772 sec)
   passed  108/110  esh-var-test/uid-var (0.001575 sec)
   passed  109/110  esh-var-test/unset/env-var (0.002218 sec)
   passed  110/110  esh-var-test/unset/symbol (0.001740 sec)

Ran 110 tests, 109 results as expected, 1 unexpected (2023-09-13
22:35:17+0200, 3.917546 sec)

1 unexpected results:
   FAILED  esh-var-test/interp-var-indices-subcommand

Running 11 tests (2023-09-13 22:35:15+0200, selector ‘(not (or (tag
:expensive-test) (tag :unstable) (tag :nativecomp)))’)
Loading em-alias...
Loading em-banner...
Loading em-basic...
Loading em-cmpl...
Loading em-extpipe...
Loading em-glob...
Loading em-hist...
Loading em-ls...
Loading em-pred...
Loading em-prompt...
Loading em-script...
Loading em-term...
Loading em-unix...
   passed   1/11  eshell-test/command-running-p (0.091010 sec)
[echo]+ Done (/bin/echo hi)
   passed   2/11  eshell-test/eshell-command/background (0.127438 sec)
[echo]+ Done (/bin/echo hi)
[cat]+ Done (/bin/cat)
   passed   3/11  eshell-test/eshell-command/background-pipeline (0.128145 sec)
   passed   4/11  eshell-test/eshell-command/pipeline (0.082343 sec)
Test eshell-test/eshell-command/simple backtrace:
  signal(ert-test-failed (((should (equal (buffer-string) "hi\n")) :fo
  ert-fail(((should (equal (buffer-string) "hi\n")) :form (equal "" "h
  #f(compiled-function () #<bytecode -0x15f19fdff774913f>)()
  ert--run-test-internal(#s(ert--test-execution-info :test #s(ert-test
  ert-run-test(#s(ert-test :name eshell-test/eshell-command/simple :do
  ert-run-or-rerun-test(#s(ert--stats :selector (not (or ... ... ...))
  ert-run-tests((not (or (tag :expensive-test) (tag :unstable) (tag :n
  ert-run-tests-batch((not (or (tag :expensive-test) (tag :unstable) (
  ert-run-tests-batch-and-exit((not (or (tag :expensive-test) (tag :un
  eval((ert-run-tests-batch-and-exit '(not (or (tag :expensive-test) (
  command-line-1(("-L" ":." "-l" "ert" "-l" "lisp/eshell/eshell-tests"
  command-line()
  normal-top-level()
Test eshell-test/eshell-command/simple condition:
    (ert-test-failed
     ((should (equal (buffer-string) "hi\n")) :form (equal "" "hi\n")
      :value nil :explanation
      (arrays-of-different-length 0 3 "" "hi\n" first-mismatch-at 0)))
   FAILED   5/11  eshell-test/eshell-command/simple (0.670351 sec) at
lisp/eshell/eshell-tests.el:41
   passed   6/11  eshell-test/flush-output (0.006822 sec)
   passed   7/11  eshell-test/forward-arg (0.004067 sec)
   passed   8/11  eshell-test/get-old-input (0.001915 sec)
   passed   9/11  eshell-test/get-old-input/rerun-command (0.007355 sec)
   passed  10/11  eshell-test/get-old-input/run-output (0.002997 sec)
   passed  11/11  eshell-test/queue-input (1.041617 sec)

Ran 11 tests, 10 results as expected, 1 unexpected (2023-09-13
22:35:17+0200, 2.483635 sec)

1 unexpected results:
   FAILED  eshell-test/eshell-command/simple

  GEN      lisp/format-spec-tests.log
make[3]: *** [lisp/eshell/eshell-tests.log] Error 1
make[3]: *** [lisp/eshell/esh-var-tests.log] Error 1





^ permalink raw reply	[flat|nested] 24+ messages in thread

* bug#65590: bug#65602: 30.0.50; eshell-test/{elisp,subcommand}-reset-in-pipeline fails intermittently on macOS
  2023-09-13 20:41                       ` Jim Porter
  2023-09-13 20:48                         ` Stefan Kangas
@ 2023-09-13 21:13                         ` Stefan Kangas
  1 sibling, 0 replies; 24+ messages in thread
From: Stefan Kangas @ 2023-09-13 21:13 UTC (permalink / raw)
  To: Jim Porter; +Cc: michael.albinus, 65590, 65602

Jim Porter <jporterbugs@gmail.com> writes:

> Thanks. Pushed to master as 9838f786ded. This hopefully resolves this
> bug, along with bug#59103 and bug#65601.

On a subsequent re-run, I'm now seeing this failure in em-unix-tests.el
too:

Running 4 tests (2023-09-13 23:09:59+0200, selector ‘(not (or (tag
:expensive-test) (tag :unstable) (tag :nativecomp)))’)
Loading em-alias...
Loading em-banner...
Loading em-basic...
Loading em-cmpl...
Loading em-extpipe...
Loading em-glob...
Loading em-hist...
Loading em-ls...
Loading em-pred...
Loading em-prompt...
Loading em-script...
Loading em-term...

   passed  1/4  em-unix-test/compile/interactive (0.126190 sec)
Compilation finished
   passed  2/4  em-unix-test/compile/noninteractive (0.065006 sec)
   passed  3/4  em-unix-test/compile/pipeline (0.148928 sec)
Test em-unix-test/compile/subcommand backtrace:
  signal(ert-test-failed (((should (eshell-match-output regexp)) :form
  ert-fail(((should (eshell-match-output regexp)) :form (eshell-match-
  eshell-match-command-output("echo ${compile echo hello}" "\\`hello\n
  #f(compiled-function () #<bytecode 0x407c24691ea495>)()
  ert--run-test-internal(#s(ert--test-execution-info :test #s(ert-test
  ert-run-test(#s(ert-test :name em-unix-test/compile/subcommand :docu
  ert-run-or-rerun-test(#s(ert--stats :selector (not (or ... ... ...))
  ert-run-tests((not (or (tag :expensive-test) (tag :unstable) (tag :n
  ert-run-tests-batch((not (or (tag :expensive-test) (tag :unstable) (
  ert-run-tests-batch-and-exit((not (or (tag :expensive-test) (tag :un
  eval((ert-run-tests-batch-and-exit '(not (or (tag :expensive-test) (
  command-line-1(("-L" ":." "-l" "ert" "-l" "lisp/eshell/em-unix-tests
  command-line()
  normal-top-level()
Test em-unix-test/compile/subcommand condition:
    Command logs: command: "echo ${compile echo hello}"

                  ----------------------------------------
                  [process] started external process ‘echo’
                  ----------------------------------------
                  [process] sentinel for external process ‘echo’: "finished
                  "
                  ----------------------------------------
                  [process] finished external process ‘echo’
    (ert-test-failed
     ((should (eshell-match-output regexp)) :form
      (eshell-match-output "\\`hello\n") :value nil :explanation
      (mismatched-output (command "echo ${compile echo hello}\n")
			 (output "") (regexp "\\`hello\n"))))
   FAILED  4/4  em-unix-test/compile/subcommand (0.727038 sec) at
lisp/eshell/em-unix-tests.el:60

Ran 4 tests, 3 results as expected, 1 unexpected (2023-09-13
23:10:00+0200, 1.300818 sec)

1 unexpected results:
   FAILED  em-unix-test/compile/subcommand

make[3]: *** [lisp/eshell/em-unix-tests.log] Error 1





^ permalink raw reply	[flat|nested] 24+ messages in thread

* bug#65602: 30.0.50; eshell-test/{elisp,subcommand}-reset-in-pipeline fails intermittently on macOS
  2023-09-13 21:10                           ` bug#65590: bug#65602: 30.0.50; eshell-test/{elisp,subcommand}-reset-in-pipeline fails intermittently " Stefan Kangas
@ 2023-09-13 21:33                             ` Stefan Kangas
  2023-09-14  1:24                               ` Jim Porter
  0 siblings, 1 reply; 24+ messages in thread
From: Stefan Kangas @ 2023-09-13 21:33 UTC (permalink / raw)
  To: Jim Porter; +Cc: michael.albinus, 65590, 65602

Stefan Kangas <stefankangas@gmail.com> writes:

> I spoke too soon, as I'm now seeing the below two failures.
>
>    FAILED   42/110  esh-var-test/interp-var-indices-subcommand (0.787189 sec) at lisp/eshell/esh-var-tests.el:184
>
>    FAILED   5/11  eshell-test/eshell-command/simple (0.670351 sec) at lisp/eshell/eshell-tests.el:41

Here's another one I saw in another rerun:

   FAILED  esh-var-test/interp-concat-cmd-external

Running 110 tests (2023-09-13 23:19:42+0200, selector ‘(not (or (tag
:expensive-test) (tag :unstable) (tag :nativecomp)))’)
Loading em-alias...
Loading em-banner...
Loading em-basic...
Loading em-cmpl...
Loading em-extpipe...
Loading em-glob...
Loading em-hist...
Loading em-ls...
Loading em-pred...
Loading em-prompt...
Loading em-script...
Loading em-term...
Loading em-unix...
   passed    1/110  esh-var-test/alias/export (0.178462 sec)
   passed    2/110  esh-var-test/alias/function (0.003780 sec)
   passed    3/110  esh-var-test/alias/function-pair (0.004611 sec)
   passed    4/110  esh-var-test/alias/local-variables (0.006019 sec)
   passed    5/110  esh-var-test/alias/string (0.004543 sec)
   passed    6/110  esh-var-test/alias/string/prefer-lisp (0.002898 sec)
   passed    7/110  esh-var-test/alias/symbol (0.003406 sec)
   passed    8/110  esh-var-test/alias/symbol-pair (0.007461 sec)
   passed    9/110  esh-var-test/columns-var (0.012501 sec)
   passed   10/110  esh-var-test/command-interp (0.007292 sec)
   passed   11/110  esh-var-test/command-interp-splice (0.004153 sec)
   passed   12/110  esh-var-test/export (0.006411 sec)
   passed   13/110  esh-var-test/gid-var (0.002620 sec)
   passed   14/110  esh-var-test/inside-emacs-var (0.004839 sec)
   passed   15/110  esh-var-test/inside-emacs-var-split-indices (0.002154 sec)
   passed   16/110  esh-var-test/interp-cmd (0.004522 sec)
   passed   17/110  esh-var-test/interp-cmd-external (0.112656 sec)
   passed   18/110  esh-var-test/interp-cmd-external-indices (0.113898 sec)
   passed   19/110  esh-var-test/interp-cmd-indices (0.003645 sec)
   passed   20/110  esh-var-test/interp-concat-cmd (0.205057 sec)
Test esh-var-test/interp-concat-cmd-external backtrace:
  signal(ert-test-failed (((should (eshell-match-output regexp)) :form
  ert-fail(((should (eshell-match-output regexp)) :form (eshell-match-
  eshell-match-command-output("echo ${echo hi}-${*echo there}" "hi-the
  #f(compiled-function () #<bytecode 0x498530d8d28fcbf>)()
  ert--run-test-internal(#s(ert--test-execution-info :test #s(ert-test
  ert-run-test(#s(ert-test :name esh-var-test/interp-concat-cmd-extern
  ert-run-or-rerun-test(#s(ert--stats :selector ... :tests ... :test-m
  ert-run-tests((not (or (tag :expensive-test) (tag :unstable) (tag :n
  ert-run-tests-batch((not (or (tag :expensive-test) (tag :unstable) (
  ert-run-tests-batch-and-exit((not (or (tag :expensive-test) (tag :un
  eval((ert-run-tests-batch-and-exit '(not (or (tag :expensive-test) (
  command-line-1(("-L" ":." "-l" "ert" "-l" "lisp/eshell/esh-var-tests
  command-line()
  normal-top-level()
Test esh-var-test/interp-concat-cmd-external condition:
    Command logs: command: "echo ${echo hi}-${*echo there}"

                  ----------------------------------------
                  [process] started external process ‘echo’
                  ----------------------------------------
                  [process] sentinel for external process ‘echo’: "finished
                  "
                  ----------------------------------------
                  [process] finished external process ‘echo’
    (ert-test-failed
     ((should (eshell-match-output regexp)) :form
      (eshell-match-output "hi-there\n") :value nil :explanation
      (mismatched-output (command "echo ${echo hi}-${*echo there}\n")
			 (output "hi-\n") (regexp "hi-there\n"))))
   FAILED   21/110  esh-var-test/interp-concat-cmd-external (0.728591
sec) at lisp/eshell/esh-var-tests.el:292
   passed   22/110  esh-var-test/interp-concat-cmd2 (0.004187 sec)
   passed   23/110  esh-var-test/interp-concat-lisp (0.002859 sec)
   passed   24/110  esh-var-test/interp-concat-lisp2 (0.004121 sec)
   passed   25/110  esh-var-test/interp-convert-cmd-multiline (0.004131 sec)
   passed   26/110  esh-var-test/interp-convert-cmd-number (0.001232 sec)
   passed   27/110  esh-var-test/interp-convert-cmd-split-indices (0.005519 sec)
   passed   28/110  esh-var-test/interp-convert-cmd-string-newline
(0.001249 sec)
   passed   29/110  esh-var-test/interp-convert-quoted-var-number (0.003763 sec)
   passed   30/110
esh-var-test/interp-convert-quoted-var-split-indices (0.002441 sec)
   passed   31/110  esh-var-test/interp-convert-var-number (0.004204 sec)
   passed   32/110  esh-var-test/interp-convert-var-split-indices (0.007541 sec)
   passed   33/110  esh-var-test/interp-lisp (0.003046 sec)
   passed   34/110  esh-var-test/interp-lisp-indices (0.003134 sec)
   passed   35/110  esh-var-test/interp-list-var (0.002291 sec)
   passed   36/110  esh-var-test/interp-list-var-concat (0.001819 sec)
   passed   37/110  esh-var-test/interp-quoted-var (0.003009 sec)
   passed   38/110  esh-var-test/interp-quoted-var-concat (0.003025 sec)
   passed   39/110  esh-var-test/interp-temp-cmd (0.013814 sec)
   passed   40/110  esh-var-test/interp-var (0.001271 sec)
   passed   41/110  esh-var-test/interp-var-assoc (0.004091 sec)
   passed   42/110  esh-var-test/interp-var-indices-subcommand (0.176522 sec)
   passed   43/110  esh-var-test/interp-var-indices/list (0.013073 sec)
   passed   44/110  esh-var-test/interp-var-indices/ring (0.011317 sec)
   passed   45/110  esh-var-test/interp-var-indices/split (0.011973 sec)
   passed   46/110  esh-var-test/interp-var-indices/vector (0.012646 sec)
   passed   47/110  esh-var-test/interp-var-length-alist (0.002014 sec)
   passed   48/110  esh-var-test/interp-var-length-list (0.005285 sec)
   passed   49/110  esh-var-test/interp-var-length-string (0.001555 sec)
   passed   50/110  esh-var-test/interp-var-regexp-split-indices (0.010098 sec)
   passed   51/110  esh-var-test/interp-var-splice (0.001259 sec)
   passed   52/110  esh-var-test/interp-var-splice-concat (0.002406 sec)
   passed   53/110  esh-var-test/interp-var-string-split-indices (0.009873 sec)
   passed   54/110  esh-var-test/last-arg-var (0.005632 sec)
   passed   55/110  esh-var-test/last-arg-var-indices (0.021506 sec)
   passed   56/110  esh-var-test/last-arg-var-split-indices (0.011228 sec)
   passed   57/110  esh-var-test/last-result-var (0.005804 sec)
   passed   58/110  esh-var-test/last-result-var-ext-cmd (0.226047 sec)
   passed   59/110  esh-var-test/last-result-var-split-indices (0.031719 sec)
   passed   60/110  esh-var-test/last-result-var-twice (0.004827 sec)
   passed   61/110  esh-var-test/last-status-var-ext-cmd (0.242608 sec)
   passed   62/110  esh-var-test/last-status-var-lisp-command (0.010839 sec)
   passed   63/110  esh-var-test/last-status-var-lisp-form (0.005407 sec)
   passed   64/110  esh-var-test/last-status-var-lisp-form-2 (0.006529 sec)
   passed   65/110  esh-var-test/lines-var (0.003589 sec)
   passed   66/110  esh-var-test/local-variables (0.023687 sec)
   passed   67/110  esh-var-test/pager-var/default (0.017587 sec)
   passed   68/110  esh-var-test/pager-var/set (0.087502 sec)
   passed   69/110  esh-var-test/pager-var/set-locally (0.012173 sec)
   passed   70/110  esh-var-test/pager-var/unset (0.005189 sec)
   passed   71/110  esh-var-test/path-var/local-directory (0.003602 sec)
Tramp: Sending command ‘exec sh -i’
Tramp: Found remote shell prompt on ‘SK-MacBook-Pro’
   passed   72/110  esh-var-test/path-var/preserve-across-hosts (0.866043 sec)
   passed   73/110  esh-var-test/path-var/remote-directory (0.083372 sec)
   passed   74/110  esh-var-test/path-var/set (0.014802 sec)
   passed   75/110  esh-var-test/path-var/set-locally (0.008608 sec)
   passed   76/110  esh-var-test/quote-interp-var-indices-subcommand
(0.236072 sec)
   passed   77/110  esh-var-test/quoted-interp-cmd (0.004823 sec)
   passed   78/110  esh-var-test/quoted-interp-cmd-indices (0.047686 sec)
   passed   79/110  esh-var-test/quoted-interp-concat-cmd (0.002995 sec)
   passed   80/110  esh-var-test/quoted-interp-convert-cmd-multiline
(0.002892 sec)
   passed   81/110  esh-var-test/quoted-interp-convert-cmd-number (0.002594 sec)
   passed   82/110
esh-var-test/quoted-interp-convert-cmd-split-indices (0.002789 sec)
   passed   83/110
esh-var-test/quoted-interp-convert-cmd-string-newline (0.005021 sec)
   passed   84/110
esh-var-test/quoted-interp-convert-quoted-var-number (0.008607 sec)
   passed   85/110
esh-var-test/quoted-interp-convert-quoted-var-split-indices (0.007789
sec)
   passed   86/110  esh-var-test/quoted-interp-convert-var-number (0.002748 sec)
   passed   87/110
esh-var-test/quoted-interp-convert-var-split-indices (0.007919 sec)
   passed   88/110  esh-var-test/quoted-interp-lisp (0.001791 sec)
   passed   89/110  esh-var-test/quoted-interp-lisp-indices (0.003300 sec)
   passed   90/110  esh-var-test/quoted-interp-list-var (0.001912 sec)
   passed   91/110  esh-var-test/quoted-interp-list-var-concat (0.002009 sec)
   passed   92/110  esh-var-test/quoted-interp-quoted-var (0.003799 sec)
   passed   93/110  esh-var-test/quoted-interp-temp-cmd (0.017058 sec)
   passed   94/110  esh-var-test/quoted-interp-var (0.001892 sec)
   passed   95/110  esh-var-test/quoted-interp-var-assoc (0.021957 sec)
   passed   96/110  esh-var-test/quoted-interp-var-indices (0.017924 sec)
   passed   97/110  esh-var-test/quoted-interp-var-length-alist (0.017236 sec)
   passed   98/110  esh-var-test/quoted-interp-var-length-list (0.006038 sec)
   passed   99/110  esh-var-test/quoted-interp-var-length-string (0.001831 sec)
   passed  100/110
esh-var-test/quoted-interp-var-regexp-split-indices (0.017895 sec)
   passed  101/110  esh-var-test/quoted-interp-var-splice (0.005310 sec)
   passed  102/110  esh-var-test/quoted-interp-var-splice-concat (0.002805 sec)
   passed  103/110  esh-var-test/quoted-interp-var-split-indices (0.005452 sec)
   passed  104/110
esh-var-test/quoted-interp-var-string-split-indices (0.029075 sec)
   passed  105/110  esh-var-test/set/env-var (0.002507 sec)
   passed  106/110  esh-var-test/set/symbol (0.002819 sec)
   passed  107/110  esh-var-test/setq (0.005122 sec)
   passed  108/110  esh-var-test/uid-var (0.021527 sec)
   passed  109/110  esh-var-test/unset/env-var (0.002078 sec)
   passed  110/110  esh-var-test/unset/symbol (0.002711 sec)

Ran 110 tests, 109 results as expected, 1 unexpected (2023-09-13
23:19:46+0200, 4.193564 sec)

1 unexpected results:
   FAILED  esh-var-test/interp-concat-cmd-external

make[3]: *** [lisp/eshell/esh-var-tests.log] Error 1





^ permalink raw reply	[flat|nested] 24+ messages in thread

* bug#65602: 30.0.50; eshell-test/{elisp,subcommand}-reset-in-pipeline fails intermittently on macOS
  2023-09-13 21:33                             ` Stefan Kangas
@ 2023-09-14  1:24                               ` Jim Porter
  2023-09-14 19:14                                 ` Stefan Kangas
  0 siblings, 1 reply; 24+ messages in thread
From: Jim Porter @ 2023-09-14  1:24 UTC (permalink / raw)
  To: Stefan Kangas; +Cc: 65602

On 9/13/2023 2:33 PM, Stefan Kangas wrote:
> Stefan Kangas <stefankangas@gmail.com> writes:
> 
>> I spoke too soon, as I'm now seeing the below two failures.
>>
>>     FAILED   42/110  esh-var-test/interp-var-indices-subcommand (0.787189 sec) at lisp/eshell/esh-var-tests.el:184
>>
>>     FAILED   5/11  eshell-test/eshell-command/simple (0.670351 sec) at lisp/eshell/eshell-tests.el:41
> 
> Here's another one I saw in another rerun:
> 
>     FAILED  esh-var-test/interp-concat-cmd-external

Hmm. I pushed a commit to add additional instrumentation to this code 
(ef2bd5e4875). Could you try that out and report the results?

You could also try adding something like "(setq eshell-debug-command 
'(form))" to the top of "test/lisp/eshell/eshell-tests-helpers.el", and 
then "rm test/lisp/eshell/*.elc" to force a full recompile of the tests. 
That'll add excessive amounts of logging for Eshell's s-expr 
manipulation, and it might produce something useful. (Warning that it 
can also include things like your env vars in the logs, so be careful 
about uploading it.)





^ permalink raw reply	[flat|nested] 24+ messages in thread

* bug#65602: 30.0.50; eshell-test/{elisp,subcommand}-reset-in-pipeline fails intermittently on macOS
  2023-09-14  1:24                               ` Jim Porter
@ 2023-09-14 19:14                                 ` Stefan Kangas
  2023-09-14 19:33                                   ` Jim Porter
  0 siblings, 1 reply; 24+ messages in thread
From: Stefan Kangas @ 2023-09-14 19:14 UTC (permalink / raw)
  To: Jim Porter; +Cc: 65602

Jim Porter <jporterbugs@gmail.com> writes:

> Hmm. I pushed a commit to add additional instrumentation to this code
> (ef2bd5e4875). Could you try that out and report the results?

I see more failures now, which might indicate that they are more easily
triggered.  I only did one run so far though.

> You could also try adding something like "(setq eshell-debug-command
> '(form))" to the top of "test/lisp/eshell/eshell-tests-helpers.el", and
> then "rm test/lisp/eshell/*.elc" to force a full recompile of the tests.
> That'll add excessive amounts of logging for Eshell's s-expr
> manipulation, and it might produce something useful.

I have sent the logs to you off-list.

> (Warning that it can also include things like your env vars in the
> logs, so be careful about uploading it.)

Noted, thanks for the heads up.





^ permalink raw reply	[flat|nested] 24+ messages in thread

* bug#65602: 30.0.50; eshell-test/{elisp,subcommand}-reset-in-pipeline fails intermittently on macOS
  2023-09-14 19:14                                 ` Stefan Kangas
@ 2023-09-14 19:33                                   ` Jim Porter
  2023-09-15  0:59                                     ` Jim Porter
  0 siblings, 1 reply; 24+ messages in thread
From: Jim Porter @ 2023-09-14 19:33 UTC (permalink / raw)
  To: Stefan Kangas; +Cc: 65602

On 9/14/2023 12:14 PM, Stefan Kangas wrote:
> I have sent the logs to you off-list.

Thanks for the logs. They're pretty large, so I'll have to take some 
extra time to look them over, but I'm beginning to wonder if there's a 
bug in process.c. In the logs for em-unix-tests, I see messages for the 
start of the "echo" process and its sentinel, but nothing for the output 
filter, even though we *should* be getting output. I'll keep thinking 
about this, and possibly add some further instrumentation to narrow this 
down...






^ permalink raw reply	[flat|nested] 24+ messages in thread

* bug#65602: 30.0.50; eshell-test/{elisp,subcommand}-reset-in-pipeline fails intermittently on macOS
  2023-09-14 19:33                                   ` Jim Porter
@ 2023-09-15  0:59                                     ` Jim Porter
  2023-09-15 12:14                                       ` Stefan Kangas
  0 siblings, 1 reply; 24+ messages in thread
From: Jim Porter @ 2023-09-15  0:59 UTC (permalink / raw)
  To: Stefan Kangas; +Cc: 65602

On 9/14/2023 12:33 PM, Jim Porter wrote:
> On 9/14/2023 12:14 PM, Stefan Kangas wrote:
>> I have sent the logs to you off-list.
> 
> Thanks for the logs. They're pretty large, so I'll have to take some 
> extra time to look them over, but I'm beginning to wonder if there's a 
> bug in process.c. In the logs for em-unix-tests, I see messages for the 
> start of the "echo" process and its sentinel, but nothing for the output 
> filter, even though we *should* be getting output. I'll keep thinking 
> about this, and possibly add some further instrumentation to narrow this 
> down...

I pushed some minor changes to the logging (cadd3326625), and a 
mostly-unrelated fix to Eshell's iterative evaluation that I noticed 
from perusing the logs (one day I should really just rip that out and 
replace it with generator.el...).

In particular, I added logging for the actual command-line args that we 
pass to external commands. That should help to narrow down whether we're 
calling the subprocess correctly, or if there's some issue where the 
expected output gets lost on the way somewhere...





^ permalink raw reply	[flat|nested] 24+ messages in thread

* bug#65602: 30.0.50; eshell-test/{elisp,subcommand}-reset-in-pipeline fails intermittently on macOS
  2023-09-15  0:59                                     ` Jim Porter
@ 2023-09-15 12:14                                       ` Stefan Kangas
  2023-09-18 17:30                                         ` Jim Porter
  0 siblings, 1 reply; 24+ messages in thread
From: Stefan Kangas @ 2023-09-15 12:14 UTC (permalink / raw)
  To: Jim Porter; +Cc: 65602

Jim Porter <jporterbugs@gmail.com> writes:

> I pushed some minor changes to the logging (cadd3326625), and a
> mostly-unrelated fix to Eshell's iterative evaluation that I noticed
> from perusing the logs (one day I should really just rip that out and
> replace it with generator.el...).
>
> In particular, I added logging for the actual command-line args that we
> pass to external commands. That should help to narrow down whether we're
> calling the subprocess correctly, or if there's some issue where the
> expected output gets lost on the way somewhere...

After several reruns, I was able to reproduce some additional failures,
but they are getting harder to reproduce.  I just switched to using a
native-comp build, and I'm not sure if that will affect the result.

I've sent you these log files off-list:

* -rw------- 1 sk staff 3.8K 2023-09-15 13:38 esh-var-tests.log.gz
* -rw------- 1 sk staff  877 2023-09-15 13:38 eshell-tests.log.gz





^ permalink raw reply	[flat|nested] 24+ messages in thread

* bug#65602: 30.0.50; eshell-test/{elisp,subcommand}-reset-in-pipeline fails intermittently on macOS
  2023-09-15 12:14                                       ` Stefan Kangas
@ 2023-09-18 17:30                                         ` Jim Porter
  0 siblings, 0 replies; 24+ messages in thread
From: Jim Porter @ 2023-09-18 17:30 UTC (permalink / raw)
  To: Stefan Kangas; +Cc: 65602

On 9/15/2023 5:14 AM, Stefan Kangas wrote:
> After several reruns, I was able to reproduce some additional failures,
> but they are getting harder to reproduce.  I just switched to using a
> native-comp build, and I'm not sure if that will affect the result.

That's good. At least we're making progress.

While testing out some other in-progress patches, I managed to change 
the timings of things locally by enough that I could reliably trigger 
some similar failures. I've pushed my fix to master as 146bd41ddef.

Hopefully these are the same that you're seeing, but I'm not 100% 
certain. (I've also recently pushed a couple of fixes to the debug 
instrumentation - I had broken the "form" instrumentation - but I think 
all the issues we're seeing are related to process timings anyway.)





^ permalink raw reply	[flat|nested] 24+ messages in thread

end of thread, other threads:[~2023-09-18 17:30 UTC | newest]

Thread overview: 24+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2023-08-29  6:44 bug#65590: 29.0.50; esh-var-test/interp-concat-cmd fails on macOS Stefan Kangas
2023-08-29 17:10 ` Jim Porter
2023-08-29 18:59   ` Stefan Kangas
2023-08-29 19:15     ` Stefan Kangas
2023-08-30  0:44     ` Jim Porter
2023-09-01  1:54       ` Jim Porter
2023-09-01 16:03         ` Stefan Kangas
2023-09-01 16:30           ` Jim Porter
2023-09-01 17:00             ` Jim Porter
2023-09-12 18:53               ` Jim Porter
2023-09-13 16:10                 ` Stefan Kangas
2023-09-13 18:54                   ` Jim Porter
2023-09-13 20:34                     ` Stefan Kangas
2023-09-13 20:41                       ` Jim Porter
2023-09-13 20:48                         ` Stefan Kangas
2023-09-13 21:10                           ` bug#65590: bug#65602: 30.0.50; eshell-test/{elisp,subcommand}-reset-in-pipeline fails intermittently " Stefan Kangas
2023-09-13 21:33                             ` Stefan Kangas
2023-09-14  1:24                               ` Jim Porter
2023-09-14 19:14                                 ` Stefan Kangas
2023-09-14 19:33                                   ` Jim Porter
2023-09-15  0:59                                     ` Jim Porter
2023-09-15 12:14                                       ` Stefan Kangas
2023-09-18 17:30                                         ` Jim Porter
2023-09-13 21:13                         ` bug#65590: " Stefan Kangas

Code repositories for project(s) associated with this external index

	https://git.savannah.gnu.org/cgit/emacs.git
	https://git.savannah.gnu.org/cgit/emacs/org-mode.git

This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.