* 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 public inbox
https://git.savannah.gnu.org/cgit/emacs.git
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for read-only IMAP folder(s) and NNTP newsgroup(s).