Add debug instrumentation for Eshell process management

* lisp/eshell/esh-util.el (eshell-debug-command)
* lisp/eshell/em-basic.el (eshell/eshell-debug)
(pcomplete/eshell-mode/eshell-debug): 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.

* doc/misc/eshell.texi (Built-ins): Mention "process" debug type.

diff --git a/doc/misc/eshell.texi b/doc/misc/eshell.texi
index ee6c0f10b349c4975278afd2fab9a6e40329f38a..d3c055715f5c66e4f467013e4f71e30faca6d323 100644 (file)
--- a/doc/misc/eshell.texi
+++ b/doc/misc/eshell.texi
@@ -625,11 +625,15 @@ command one or more of the following arguments:
 
 @item
 @code{error}, to enable/disable Eshell trapping errors when
-evaluating commands; or
+evaluating commands;
 
 @item
 @code{form}, to show/hide Eshell command form manipulation in the
-buffer @code{*eshell last cmd*}.
+buffer @code{*eshell last cmd*}; or
+
+@item
+@code{process}, to show/hide external process events in the buffer
+@code{*eshell last cmd*}.
 
 @end itemize
 

diff --git a/lisp/eshell/em-basic.el b/lisp/eshell/em-basic.el
index 554ee83b015bf590e36aa755df63092d2d2f983e..95d7d8f4ebe8f6c17910a3cc5bd95a62e42e8a1c 100644 (file)
--- a/lisp/eshell/em-basic.el
+++ b/lisp/eshell/em-basic.el
@@ -199,7 +199,8 @@ 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*'")
+   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")
@@ -217,7 +218,7 @@ are:
 
 (defun pcomplete/eshell-mode/eshell-debug ()
   "Completion for the `debug' command."
-  (while (pcomplete-here '("error" "form"))))
+  (while (pcomplete-here '("error" "form" "process"))))
 
 (provide 'em-basic)
 

diff --git a/lisp/eshell/esh-proc.el b/lisp/eshell/esh-proc.el
index 9c4036004ff505707e115089d89e22c2c0ef4e50..87719c019cb6fcc35aa2e88b50c82734ace522ba 100644 (file)
--- a/lisp/eshell/esh-proc.el
+++ b/lisp/eshell/esh-proc.el
@@ -332,6 +332,8 @@ Used only on systems which do not support async subprocesses.")
                :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 @@ Used only on systems which do not support async subprocesses.")
   "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 @@ output."
                 (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 @@ output."
 (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 @@ PROC is the process that's exiting.  STRING is the exit message."
                              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 8be4536cff7d536bd587a4885e344ed266dc5e1c..ef10d89afc7b688ed6f28065352bfd1dd41900f2 100644 (file)
--- a/lisp/eshell/esh-util.el
+++ b/lisp/eshell/esh-util.el
@@ -105,11 +105,12 @@ argument matches `eshell-number-regexp'."
 (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.
+command forms, and `process', to log external process operations.
 
 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 2c913d71cb4e417674f82e2e073110957898b260..e300f3d657ac51c2857da53fbefa7f6c61d08429 100644 (file)
--- a/test/lisp/eshell/eshell-tests-helpers.el
+++ b/test/lisp/eshell/eshell-tests-helpers.el
@@ -54,6 +54,12 @@ beginning of the test file."
        (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 @@ raise an error."
    (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 @@ FUNC is the function to call after inserting the text (see
 
 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 @@ inserting the command."
 
 (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)