[-- Attachment #1: Type: text/plain, Size: 3651 bytes --] Tags: patch Hi, this patch or similar would really make generating test data a lot easier (please see the behavioral tests in these bugs [1] for examples). If it were up to me, we'd also get rid of the interactive toggling, at least while sessions are ongoing. The reason is that I find the most interesting/important parts of a session to be the initial "connection registration" phase and subsequent server burst (and possibly any NickServ interactions and early JOIN activity that immediately follow). But out of respect for tradition, I've left all of that alone. Thanks. [1] https://debbugs.gnu.org/cgi/bugreport.cgi?bug=48598 https://debbugs.gnu.org/cgi/bugreport.cgi?bug=49860 In GNU Emacs 28.0.50 (build 1, x86_64-pc-linux-gnu, GTK+ Version 3.24.30, cairo version 1.17.4) of 2021-08-09 built on localhost Repository revision: aeec97fae0ccfcc4dc406a5e0e4c0a94b834cac4 Repository branch: master Windowing system distributor 'The X.Org Foundation', version 11.0.12011000 System Description: Fedora 34 (Workstation Edition) Configured features: ACL CAIRO DBUS FREETYPE GIF GLIB GMP GNUTLS GPM GSETTINGS HARFBUZZ JPEG JSON LCMS2 LIBOTF LIBSELINUX LIBSYSTEMD LIBXML2 M17N_FLT MODULES NOTIFY INOTIFY PDUMPER PNG RSVG SECCOMP SOUND THREADS TIFF TOOLKIT_SCROLL_BARS X11 XDBE XIM XPM GTK3 ZLIB Important settings: value of $LANG: en_US.UTF-8 value of $XMODIFIERS: @im=ibus locale-coding-system: utf-8-unix Major mode: Lisp Interaction Minor modes in effect: tooltip-mode: t global-eldoc-mode: t eldoc-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 auto-composition-mode: t auto-encryption-mode: t auto-compression-mode: t line-number-mode: t indent-tabs-mode: t transient-mark-mode: t Load-path shadows: None found. Features: (shadow sort mail-extr emacsbug message rmc puny dired dired-loaddefs rfc822 mml mml-sec epa derived epg epg-config gnus-util rmail rmail-loaddefs auth-source cl-seq eieio eieio-core cl-macs eieio-loaddefs password-cache json map text-property-search time-date subr-x seq byte-opt gv bytecomp byte-compile cconv 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 iso-transl tooltip eldoc electric uniquify ediff-hook vc-hooks lisp-float-type mwheel term/x-win x-win term/common-win x-dnd tool-bar dnd fontset image regexp-opt fringe tabulated-list replace newcomment text-mode elisp-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 cl-generic 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 charscript charprop case-table epa-hook jka-cmpr-hook help simple abbrev obarray cl-preloaded nadvice button loaddefs faces cus-face macroexp files window text-properties overlay sha1 md5 base64 format env code-pages mule custom widget hashtable-print-readable backquote threads dbusbind inotify lcms2 dynamic-setting system-font-setting font-render-setting cairo move-toolbar gtk x-toolkit x multi-tty make-network-process emacs) Memory information: ((conses 16 51538 6355) (symbols 48 6607 1) (strings 32 18255 1368) (string-bytes 1 616656) (vectors 16 14292) (vector-slots 8 185252 10153) (floats 8 21 47) (intervals 56 205 0) (buffers 992 10)) [-- Warning: decoded text below may be mangled, UTF-8 assumed --] [-- Attachment #2: 0001-Add-CRLF-to-outgoing-ERC-protocol-logger-lines.patch --] [-- Type: text/x-patch, Size: 7290 bytes --] From 871669a52a6a410f17e1d22960490a274cc36f54 Mon Sep 17 00:00:00 2001 From: "F. Jason Park" <jp@neverwas.me> Date: Mon, 14 Jun 2021 22:24:01 -0700 Subject: [PATCH] Add CRLF to outgoing ERC protocol logger lines * erc.el (erc-debug-irc-protocol): Previously, the newline handling was disguising a subtle, semi-important bug in which phantom line feeds were accidentally being sent to servers. Also, there was a harmless but annoying mismatch between outgoing and incoming lines: the latter lacked carriage returns. This adds them everywhere to make machine parsing easier. This also makes room for the addition of a session identifier, if one is ever introduced. When set, such a variable would make logging more meaningful when multiple sessions exist for the same network. Also added are timestamps to aid in reproducing bugs. And outgoing lines are no longer propertized. (erc-debug-irc-protocol-time-format): Add new variable to help with reproducing bugs. (erc-debug-irc-protocol-version): Add new variable to print atop erc-protocol log files for tracking format used for logging. (erc-toggle-debug-irc-protocol): Add headers to log buffer for the benefit of bug-reproduction tools, so they can detect the format used in a log. Clean up overlong lines. --- lisp/erc/erc.el | 74 ++++++++++++++++++++++++++++++++----------------- 1 file changed, 48 insertions(+), 26 deletions(-) diff --git a/lisp/erc/erc.el b/lisp/erc/erc.el index 73202016ba..2eba4a900c 100644 --- a/lisp/erc/erc.el +++ b/lisp/erc/erc.el @@ -2312,6 +2312,14 @@ erc-error ;;; Debugging the protocol +(defvar erc-debug-irc-protocol-time-format "%FT%T.%6N%z " + "An optional format string for optional I/O timestamps.") + +(defconst erc-debug-irc-protocol-version "1" + "Protocol log format version number. +These logs are machine-readable, but external tools used in bug +reproduction, etc. need a way to track changes to the format.") + (defvar erc-debug-irc-protocol nil "If non-nil, log all IRC protocol traffic to the buffer \"*erc-protocol*\". @@ -2333,32 +2341,36 @@ erc-log-irc-protocol The buffer is created if it doesn't exist. -If OUTBOUND is non-nil, STRING is being sent to the IRC server -and appears in face `erc-input-face' in the buffer." +If OUTBOUND is non-nil, STRING is being sent to the IRC server and +appears in face `erc-input-face' in the buffer. Lines must already +contain CRLF endings. Peer is identified by the most precise label +available at run time, starting with the network name, followed by the +self-reported host name, and falling back to the dialed <server>:<port>. +When capturing logs for multiple peers and sorting them into buckets, +such inconsistent labeling may pose a problem during an initial server +burst. For now, the recommended approach is to wrap this function with +advice that temporarily redefines the symbol-function `erc-network'." (when erc-debug-irc-protocol - (let ((network-name (or (ignore-errors (erc-network-name)) - "???"))) + (let ((esid (or (and (fboundp 'erc-network) + (erc-network) + (erc-network-name)) + erc-server-announced-name + (format "%s:%s" erc-session-server erc-session-port))) + (ts (when erc-debug-irc-protocol-time-format + (format-time-string erc-debug-irc-protocol-time-format)))) (with-current-buffer (get-buffer-create "*erc-protocol*") (save-excursion (goto-char (point-max)) (let ((inhibit-read-only t)) - (insert (if (not outbound) - ;; Cope with the fact that string might - ;; contain multiple lines of text. - (let ((lines (delete "" (split-string string - "\n\\|\r\n"))) - (result "")) - (dolist (line lines) - (setq result (concat result network-name - " << " line "\n"))) - result) - (propertize - (concat network-name " >> " string - (if (/= ?\n - (aref string - (1- (length string)))) - "\n")) - 'font-lock-face 'erc-input-face))))) + (insert (if outbound + (concat ts esid " >> " string) + ;; Cope with multi-line messages + (let ((lines (split-string string "[\r\n]+" t)) + result) + (dolist (line lines) + (setq result (concat result ts esid + " << " line "\r\n"))) + result))))) (let ((orig-win (selected-window)) (debug-buffer-window (get-buffer-window (current-buffer) t))) (when debug-buffer-window @@ -2371,24 +2383,34 @@ erc-log-irc-protocol (defun erc-toggle-debug-irc-protocol (&optional arg) "Toggle the value of `erc-debug-irc-protocol'. -If ARG is non-nil, show the *erc-protocol* buffer." +If ARG is non-nil, show the *erc-protocol* buffer. Everything before +the first CRLF is front matter. Everything before the first double +linefeed is a header." (interactive "P") (let* ((buf (get-buffer-create "*erc-protocol*"))) (with-current-buffer buf (view-mode-enter) (when (null (current-local-map)) - (let ((inhibit-read-only t)) - (insert (erc-make-notice "This buffer displays all IRC protocol traffic exchanged with each server.\n")) - (insert (erc-make-notice "Kill this buffer to terminate protocol logging.\n\n"))) + (let ((inhibit-read-only t) + (headers (concat "Version: " erc-debug-irc-protocol-version "\n" + "Emacs-Version: " emacs-version "\n" + "\n")) + (msg (concat "This buffer displays all IRC protocol traffic " + "exchanged with servers.\n" + "Kill it to disable logging.\n" + "Press `t' to toggle.\n"))) + (insert headers (erc-make-notice msg))) (use-local-map (make-sparse-keymap)) (local-set-key (kbd "t") 'erc-toggle-debug-irc-protocol)) (add-hook 'kill-buffer-hook (lambda () (setq erc-debug-irc-protocol nil)) nil 'local) (goto-char (point-max)) + ;; Searchable phrase printed twice between logs and once before + ;; the first. This is a single line with CRLF endings. (let ((inhibit-read-only t)) (insert (erc-make-notice - (format "IRC protocol logging %s at %s -- Press `t' to toggle logging.\n" + (format "IRC protocol logging %s at %s\r\n" (if erc-debug-irc-protocol "disabled" "enabled") (current-time-string)))))) (setq erc-debug-irc-protocol (not erc-debug-irc-protocol)) -- 2.31.1
[-- Attachment #1: Type: text/plain, Size: 165 bytes --] v2. Tweaked some spacing and borrowed a unit test from bug#48598. (Note: the first attachment just shows the changes from the last set and is not itself a patch.) [-- Warning: decoded text below may be mangled, UTF-8 assumed --] [-- Attachment #2: 0000-v1-v2.diff --] [-- Type: text/x-patch, Size: 4516 bytes --] From c4127a84f084166f2267c9745d1fc1f06ebbead2 Mon Sep 17 00:00:00 2001 From: "F. Jason Park" <jp@neverwas.me> Date: Sun, 12 Sep 2021 04:44:23 -0700 Subject: [PATCH 0/1] *** SUBJECT HERE *** *** BLURB HERE *** F. Jason Park (1): Add CRLF to outgoing ERC protocol logger lines lisp/erc/erc.el | 79 ++++++++++++++++++++++++-------------- test/lisp/erc/erc-tests.el | 35 +++++++++++++++++ 2 files changed, 86 insertions(+), 28 deletions(-) Interdiff: diff --git a/lisp/erc/erc.el b/lisp/erc/erc.el index f5ecb043b0..ead82b794d 100644 --- a/lisp/erc/erc.el +++ b/lisp/erc/erc.el @@ -2313,12 +2313,11 @@ erc-error ;;; Debugging the protocol (defvar erc-debug-irc-protocol-time-format "%FT%T.%6N%z " - "An optional format string for optional I/O timestamps.") + "Timestamp format string for protocol logger.") (defconst erc-debug-irc-protocol-version "1" "Protocol log format version number. -These logs are machine-readable, but external tools used in bug -reproduction, etc. need a way to track changes to the format.") +This is to help tooling track changes to the format.") (defvar erc-debug-irc-protocol nil "If non-nil, log all IRC protocol traffic to the buffer \"*erc-protocol*\". @@ -2384,8 +2383,8 @@ erc-toggle-debug-irc-protocol "Toggle the value of `erc-debug-irc-protocol'. If ARG is non-nil, show the *erc-protocol* buffer. Everything before -the first CRLF is front matter. Everything before the first double -linefeed is a header." +and including the first double CRLF is front matter. Everything before +the first double linefeed is a header." (interactive "P") (let* ((buf (get-buffer-create "*erc-protocol*"))) (with-current-buffer buf @@ -2409,10 +2408,12 @@ erc-toggle-debug-irc-protocol ;; Searchable phrase printed twice between logs and once before ;; the first. This is a single line with CRLF endings. (let ((inhibit-read-only t)) - (insert (erc-make-notice - (format "IRC protocol logging %s at %s\r\n" + (insert (if erc-debug-irc-protocol "\r\n" "") + (erc-make-notice + (format "IRC protocol logging %s at %s" (if erc-debug-irc-protocol "disabled" "enabled") - (current-time-string)))))) + (current-time-string))) + (if erc-debug-irc-protocol "\r\n" "\r\n\r\n")))) (setq erc-debug-irc-protocol (not erc-debug-irc-protocol)) (if (and arg (not (get-buffer-window "*erc-protocol*" t))) diff --git a/test/lisp/erc/erc-tests.el b/test/lisp/erc/erc-tests.el index d13397274a..5a362628fa 100644 --- a/test/lisp/erc/erc-tests.el +++ b/test/lisp/erc/erc-tests.el @@ -24,6 +24,7 @@ (require 'ert) (require 'erc) (require 'erc-ring) +(require 'erc-networks) (ert-deftest erc--read-time-period () (cl-letf (((symbol-function 'read-string) (lambda (&rest _) ""))) @@ -109,3 +110,37 @@ erc-ring-previous-command (should (looking-at "abc"))))) (when noninteractive (kill-buffer "*#fake*"))) + +(ert-deftest erc-log-irc-protocol () + (should-not erc-debug-irc-protocol) + (with-temp-buffer + (let (erc-server-announced-name + erc-network + (erc-server-process (start-process "fake" (current-buffer) "true")) + (erc-server-current-nick "tester") + (erc-session-server "myproxy.localhost") + (erc-session-port 6667) + (inhibit-message t)) + (erc-toggle-debug-irc-protocol) + (erc-log-irc-protocol "PASS changeme\r\n" 'outgoing) + (setq erc-server-announced-name "irc.gnu.org") + (erc-log-irc-protocol ":irc.gnu.org 001 tester :Welcome") + (erc-log-irc-protocol ":irc.gnu.org 002 tester :Your host is irc.gnu.org") + (setq erc-network 'FooNet) + (erc-log-irc-protocol ":irc.gnu.org 422 tester :MOTD missing") + (setq erc-network 'BarNet) + (erc-log-irc-protocol ":irc.gnu.org 221 tester +i"))) + (with-current-buffer "*erc-protocol*" + (goto-char (point-min)) + (search-forward "myproxy.localhost:6667 >> PASS") + (forward-line) + (search-forward "irc.gnu.org << :irc.gnu.org 001") + (forward-line) + (search-forward "irc.gnu.org << :irc.gnu.org 002") + (forward-line) + (search-forward "FooNet << :irc.gnu.org 422") + (forward-line) + (search-forward "BarNet << :irc.gnu.org 221")) + (when noninteractive + (kill-buffer "*erc-protocol*") + (should-not erc-debug-irc-protocol))) -- 2.31.1 [-- Warning: decoded text below may be mangled, UTF-8 assumed --] [-- Attachment #3: 0001-Add-CRLF-to-outgoing-ERC-protocol-logger-lines.patch --] [-- Type: text/x-patch, Size: 9130 bytes --] From c4127a84f084166f2267c9745d1fc1f06ebbead2 Mon Sep 17 00:00:00 2001 From: "F. Jason Park" <jp@neverwas.me> Date: Mon, 14 Jun 2021 22:24:01 -0700 Subject: [PATCH 1/1] Add CRLF to outgoing ERC protocol logger lines * erc.el (erc-debug-irc-protocol): Fix line-ending mismatch between incoming and outgoing logger lines without changing interface. Do this by adding carriage returns to the latter to improve machine readability. Change printed peer labels to most accurately reflect logical endpoints. (erc-debug-irc-protocol-time-format): Add new variable to support timestamps in protocol logger output. (erc-debug-irc-protocol-version): Add new variable to help tooling track logging format independent of ERC and Emacs versions. (erc-toggle-debug-irc-protocol): Add headers to protocol-log buffer to aid future bug-reproduction tools. Clean up overlong lines. This is bug#50009. --- lisp/erc/erc.el | 79 ++++++++++++++++++++++++-------------- test/lisp/erc/erc-tests.el | 35 +++++++++++++++++ 2 files changed, 86 insertions(+), 28 deletions(-) diff --git a/lisp/erc/erc.el b/lisp/erc/erc.el index e0fda41f8e..ead82b794d 100644 --- a/lisp/erc/erc.el +++ b/lisp/erc/erc.el @@ -2312,6 +2312,13 @@ erc-error ;;; Debugging the protocol +(defvar erc-debug-irc-protocol-time-format "%FT%T.%6N%z " + "Timestamp format string for protocol logger.") + +(defconst erc-debug-irc-protocol-version "1" + "Protocol log format version number. +This is to help tooling track changes to the format.") + (defvar erc-debug-irc-protocol nil "If non-nil, log all IRC protocol traffic to the buffer \"*erc-protocol*\". @@ -2333,32 +2340,36 @@ erc-log-irc-protocol The buffer is created if it doesn't exist. -If OUTBOUND is non-nil, STRING is being sent to the IRC server -and appears in face `erc-input-face' in the buffer." +If OUTBOUND is non-nil, STRING is being sent to the IRC server and +appears in face `erc-input-face' in the buffer. Lines must already +contain CRLF endings. Peer is identified by the most precise label +available at run time, starting with the network name, followed by the +self-reported host name, and falling back to the dialed <server>:<port>. +When capturing logs for multiple peers and sorting them into buckets, +such inconsistent labeling may pose a problem during an initial server +burst. For now, the recommended approach is to wrap this function with +advice that temporarily redefines the symbol-function `erc-network'." (when erc-debug-irc-protocol - (let ((network-name (or (ignore-errors (erc-network-name)) - "???"))) + (let ((esid (or (and (fboundp 'erc-network) + (erc-network) + (erc-network-name)) + erc-server-announced-name + (format "%s:%s" erc-session-server erc-session-port))) + (ts (when erc-debug-irc-protocol-time-format + (format-time-string erc-debug-irc-protocol-time-format)))) (with-current-buffer (get-buffer-create "*erc-protocol*") (save-excursion (goto-char (point-max)) (let ((inhibit-read-only t)) - (insert (if (not outbound) - ;; Cope with the fact that string might - ;; contain multiple lines of text. - (let ((lines (delete "" (split-string string - "\n\\|\r\n"))) - (result "")) - (dolist (line lines) - (setq result (concat result network-name - " << " line "\n"))) - result) - (propertize - (concat network-name " >> " string - (if (/= ?\n - (aref string - (1- (length string)))) - "\n")) - 'font-lock-face 'erc-input-face))))) + (insert (if outbound + (concat ts esid " >> " string) + ;; Cope with multi-line messages + (let ((lines (split-string string "[\r\n]+" t)) + result) + (dolist (line lines) + (setq result (concat result ts esid + " << " line "\r\n"))) + result))))) (let ((orig-win (selected-window)) (debug-buffer-window (get-buffer-window (current-buffer) t))) (when debug-buffer-window @@ -2371,26 +2382,38 @@ erc-log-irc-protocol (defun erc-toggle-debug-irc-protocol (&optional arg) "Toggle the value of `erc-debug-irc-protocol'. -If ARG is non-nil, show the *erc-protocol* buffer." +If ARG is non-nil, show the *erc-protocol* buffer. Everything before +and including the first double CRLF is front matter. Everything before +the first double linefeed is a header." (interactive "P") (let* ((buf (get-buffer-create "*erc-protocol*"))) (with-current-buffer buf (view-mode-enter) (when (null (current-local-map)) - (let ((inhibit-read-only t)) - (insert (erc-make-notice "This buffer displays all IRC protocol traffic exchanged with each server.\n")) - (insert (erc-make-notice "Kill this buffer to terminate protocol logging.\n\n"))) + (let ((inhibit-read-only t) + (headers (concat "Version: " erc-debug-irc-protocol-version "\n" + "Emacs-Version: " emacs-version "\n" + "\n")) + (msg (concat "This buffer displays all IRC protocol traffic " + "exchanged with servers.\n" + "Kill it to disable logging.\n" + "Press `t' to toggle.\n"))) + (insert headers (erc-make-notice msg))) (use-local-map (make-sparse-keymap)) (local-set-key (kbd "t") 'erc-toggle-debug-irc-protocol)) (add-hook 'kill-buffer-hook (lambda () (setq erc-debug-irc-protocol nil)) nil 'local) (goto-char (point-max)) + ;; Searchable phrase printed twice between logs and once before + ;; the first. This is a single line with CRLF endings. (let ((inhibit-read-only t)) - (insert (erc-make-notice - (format "IRC protocol logging %s at %s -- Press `t' to toggle logging.\n" + (insert (if erc-debug-irc-protocol "\r\n" "") + (erc-make-notice + (format "IRC protocol logging %s at %s" (if erc-debug-irc-protocol "disabled" "enabled") - (current-time-string)))))) + (current-time-string))) + (if erc-debug-irc-protocol "\r\n" "\r\n\r\n")))) (setq erc-debug-irc-protocol (not erc-debug-irc-protocol)) (if (and arg (not (get-buffer-window "*erc-protocol*" t))) diff --git a/test/lisp/erc/erc-tests.el b/test/lisp/erc/erc-tests.el index d13397274a..5a362628fa 100644 --- a/test/lisp/erc/erc-tests.el +++ b/test/lisp/erc/erc-tests.el @@ -24,6 +24,7 @@ (require 'ert) (require 'erc) (require 'erc-ring) +(require 'erc-networks) (ert-deftest erc--read-time-period () (cl-letf (((symbol-function 'read-string) (lambda (&rest _) ""))) @@ -109,3 +110,37 @@ erc-ring-previous-command (should (looking-at "abc"))))) (when noninteractive (kill-buffer "*#fake*"))) + +(ert-deftest erc-log-irc-protocol () + (should-not erc-debug-irc-protocol) + (with-temp-buffer + (let (erc-server-announced-name + erc-network + (erc-server-process (start-process "fake" (current-buffer) "true")) + (erc-server-current-nick "tester") + (erc-session-server "myproxy.localhost") + (erc-session-port 6667) + (inhibit-message t)) + (erc-toggle-debug-irc-protocol) + (erc-log-irc-protocol "PASS changeme\r\n" 'outgoing) + (setq erc-server-announced-name "irc.gnu.org") + (erc-log-irc-protocol ":irc.gnu.org 001 tester :Welcome") + (erc-log-irc-protocol ":irc.gnu.org 002 tester :Your host is irc.gnu.org") + (setq erc-network 'FooNet) + (erc-log-irc-protocol ":irc.gnu.org 422 tester :MOTD missing") + (setq erc-network 'BarNet) + (erc-log-irc-protocol ":irc.gnu.org 221 tester +i"))) + (with-current-buffer "*erc-protocol*" + (goto-char (point-min)) + (search-forward "myproxy.localhost:6667 >> PASS") + (forward-line) + (search-forward "irc.gnu.org << :irc.gnu.org 001") + (forward-line) + (search-forward "irc.gnu.org << :irc.gnu.org 002") + (forward-line) + (search-forward "FooNet << :irc.gnu.org 422") + (forward-line) + (search-forward "BarNet << :irc.gnu.org 221")) + (when noninteractive + (kill-buffer "*erc-protocol*") + (should-not erc-debug-irc-protocol))) -- 2.31.1
[-- Attachment #1: Type: text/plain, Size: 52 bytes --] v3. Fix process-query-on-exit problem in unit test. [-- Warning: decoded text below may be mangled, UTF-8 assumed --] [-- Attachment #2: 0000-NOT-A-PATCH-v2-v3.diff --] [-- Type: text/x-patch, Size: 1119 bytes --] From c9c51984e2caa303e7f008272ea2bc806dbf3cc0 Mon Sep 17 00:00:00 2001 From: "F. Jason Park" <jp@neverwas.me> Date: Sun, 12 Sep 2021 17:34:16 -0700 Subject: [PATCH 0/1] *** SUBJECT HERE *** *** BLURB HERE *** F. Jason Park (1): Add CRLF to outgoing ERC protocol logger lines lisp/erc/erc.el | 79 ++++++++++++++++++++++++-------------- test/lisp/erc/erc-tests.el | 36 +++++++++++++++++ 2 files changed, 87 insertions(+), 28 deletions(-) Interdiff: diff --git a/test/lisp/erc/erc-tests.el b/test/lisp/erc/erc-tests.el index 5a362628fa..f94b52ec9f 100644 --- a/test/lisp/erc/erc-tests.el +++ b/test/lisp/erc/erc-tests.el @@ -129,7 +129,8 @@ erc-log-irc-protocol (setq erc-network 'FooNet) (erc-log-irc-protocol ":irc.gnu.org 422 tester :MOTD missing") (setq erc-network 'BarNet) - (erc-log-irc-protocol ":irc.gnu.org 221 tester +i"))) + (erc-log-irc-protocol ":irc.gnu.org 221 tester +i") + (delete-process erc-server-process))) (with-current-buffer "*erc-protocol*" (goto-char (point-min)) (search-forward "myproxy.localhost:6667 >> PASS") -- 2.31.1 [-- Warning: decoded text below may be mangled, UTF-8 assumed --] [-- Attachment #3: 0001-Add-CRLF-to-outgoing-ERC-protocol-logger-lines.patch --] [-- Type: text/x-patch, Size: 9173 bytes --] From c9c51984e2caa303e7f008272ea2bc806dbf3cc0 Mon Sep 17 00:00:00 2001 From: "F. Jason Park" <jp@neverwas.me> Date: Mon, 14 Jun 2021 22:24:01 -0700 Subject: [PATCH 1/1] Add CRLF to outgoing ERC protocol logger lines * erc.el (erc-debug-irc-protocol): Fix line-ending mismatch between incoming and outgoing logger lines without changing interface. Do this by adding carriage returns to the latter to improve machine readability. Change printed peer labels to most accurately reflect logical endpoints. (erc-debug-irc-protocol-time-format): Add new variable to support timestamps in protocol logger output. (erc-debug-irc-protocol-version): Add new variable to help tooling track logging format independent of ERC and Emacs versions. (erc-toggle-debug-irc-protocol): Add headers to protocol-log buffer to aid future bug-reproduction tools. Clean up overlong lines. This is bug#50009. --- lisp/erc/erc.el | 79 ++++++++++++++++++++++++-------------- test/lisp/erc/erc-tests.el | 36 +++++++++++++++++ 2 files changed, 87 insertions(+), 28 deletions(-) diff --git a/lisp/erc/erc.el b/lisp/erc/erc.el index f01a99a30a..033c392502 100644 --- a/lisp/erc/erc.el +++ b/lisp/erc/erc.el @@ -2312,6 +2312,13 @@ erc-error ;;; Debugging the protocol +(defvar erc-debug-irc-protocol-time-format "%FT%T.%6N%z " + "Timestamp format string for protocol logger.") + +(defconst erc-debug-irc-protocol-version "1" + "Protocol log format version number. +This is to help tooling track changes to the format.") + (defvar erc-debug-irc-protocol nil "If non-nil, log all IRC protocol traffic to the buffer \"*erc-protocol*\". @@ -2333,32 +2340,36 @@ erc-log-irc-protocol The buffer is created if it doesn't exist. -If OUTBOUND is non-nil, STRING is being sent to the IRC server -and appears in face `erc-input-face' in the buffer." +If OUTBOUND is non-nil, STRING is being sent to the IRC server and +appears in face `erc-input-face' in the buffer. Lines must already +contain CRLF endings. Peer is identified by the most precise label +available at run time, starting with the network name, followed by the +self-reported host name, and falling back to the dialed <server>:<port>. +When capturing logs for multiple peers and sorting them into buckets, +such inconsistent labeling may pose a problem during an initial server +burst. For now, the recommended approach is to wrap this function with +advice that temporarily redefines the symbol-function `erc-network'." (when erc-debug-irc-protocol - (let ((network-name (or (ignore-errors (erc-network-name)) - "???"))) + (let ((esid (or (and (fboundp 'erc-network) + (erc-network) + (erc-network-name)) + erc-server-announced-name + (format "%s:%s" erc-session-server erc-session-port))) + (ts (when erc-debug-irc-protocol-time-format + (format-time-string erc-debug-irc-protocol-time-format)))) (with-current-buffer (get-buffer-create "*erc-protocol*") (save-excursion (goto-char (point-max)) (let ((inhibit-read-only t)) - (insert (if (not outbound) - ;; Cope with the fact that string might - ;; contain multiple lines of text. - (let ((lines (delete "" (split-string string - "\n\\|\r\n"))) - (result "")) - (dolist (line lines) - (setq result (concat result network-name - " << " line "\n"))) - result) - (propertize - (concat network-name " >> " string - (if (/= ?\n - (aref string - (1- (length string)))) - "\n")) - 'font-lock-face 'erc-input-face))))) + (insert (if outbound + (concat ts esid " >> " string) + ;; Cope with multi-line messages + (let ((lines (split-string string "[\r\n]+" t)) + result) + (dolist (line lines) + (setq result (concat result ts esid + " << " line "\r\n"))) + result))))) (let ((orig-win (selected-window)) (debug-buffer-window (get-buffer-window (current-buffer) t))) (when debug-buffer-window @@ -2371,26 +2382,38 @@ erc-log-irc-protocol (defun erc-toggle-debug-irc-protocol (&optional arg) "Toggle the value of `erc-debug-irc-protocol'. -If ARG is non-nil, show the *erc-protocol* buffer." +If ARG is non-nil, show the *erc-protocol* buffer. Everything before +and including the first double CRLF is front matter. Everything before +the first double linefeed is a header." (interactive "P") (let* ((buf (get-buffer-create "*erc-protocol*"))) (with-current-buffer buf (view-mode-enter) (when (null (current-local-map)) - (let ((inhibit-read-only t)) - (insert (erc-make-notice "This buffer displays all IRC protocol traffic exchanged with each server.\n")) - (insert (erc-make-notice "Kill this buffer to terminate protocol logging.\n\n"))) + (let ((inhibit-read-only t) + (headers (concat "Version: " erc-debug-irc-protocol-version "\n" + "Emacs-Version: " emacs-version "\n" + "\n")) + (msg (concat "This buffer displays all IRC protocol traffic " + "exchanged with servers.\n" + "Kill it to disable logging.\n" + "Press `t' to toggle.\n"))) + (insert headers (erc-make-notice msg))) (use-local-map (make-sparse-keymap)) (local-set-key (kbd "t") 'erc-toggle-debug-irc-protocol)) (add-hook 'kill-buffer-hook (lambda () (setq erc-debug-irc-protocol nil)) nil 'local) (goto-char (point-max)) + ;; Searchable phrase printed twice between logs and once before + ;; the first. This is a single line with CRLF endings. (let ((inhibit-read-only t)) - (insert (erc-make-notice - (format "IRC protocol logging %s at %s -- Press `t' to toggle logging.\n" + (insert (if erc-debug-irc-protocol "\r\n" "") + (erc-make-notice + (format "IRC protocol logging %s at %s" (if erc-debug-irc-protocol "disabled" "enabled") - (current-time-string)))))) + (current-time-string))) + (if erc-debug-irc-protocol "\r\n" "\r\n\r\n")))) (setq erc-debug-irc-protocol (not erc-debug-irc-protocol)) (if (and arg (not (get-buffer-window "*erc-protocol*" t))) diff --git a/test/lisp/erc/erc-tests.el b/test/lisp/erc/erc-tests.el index d13397274a..f94b52ec9f 100644 --- a/test/lisp/erc/erc-tests.el +++ b/test/lisp/erc/erc-tests.el @@ -24,6 +24,7 @@ (require 'ert) (require 'erc) (require 'erc-ring) +(require 'erc-networks) (ert-deftest erc--read-time-period () (cl-letf (((symbol-function 'read-string) (lambda (&rest _) ""))) @@ -109,3 +110,38 @@ erc-ring-previous-command (should (looking-at "abc"))))) (when noninteractive (kill-buffer "*#fake*"))) + +(ert-deftest erc-log-irc-protocol () + (should-not erc-debug-irc-protocol) + (with-temp-buffer + (let (erc-server-announced-name + erc-network + (erc-server-process (start-process "fake" (current-buffer) "true")) + (erc-server-current-nick "tester") + (erc-session-server "myproxy.localhost") + (erc-session-port 6667) + (inhibit-message t)) + (erc-toggle-debug-irc-protocol) + (erc-log-irc-protocol "PASS changeme\r\n" 'outgoing) + (setq erc-server-announced-name "irc.gnu.org") + (erc-log-irc-protocol ":irc.gnu.org 001 tester :Welcome") + (erc-log-irc-protocol ":irc.gnu.org 002 tester :Your host is irc.gnu.org") + (setq erc-network 'FooNet) + (erc-log-irc-protocol ":irc.gnu.org 422 tester :MOTD missing") + (setq erc-network 'BarNet) + (erc-log-irc-protocol ":irc.gnu.org 221 tester +i") + (delete-process erc-server-process))) + (with-current-buffer "*erc-protocol*" + (goto-char (point-min)) + (search-forward "myproxy.localhost:6667 >> PASS") + (forward-line) + (search-forward "irc.gnu.org << :irc.gnu.org 001") + (forward-line) + (search-forward "irc.gnu.org << :irc.gnu.org 002") + (forward-line) + (search-forward "FooNet << :irc.gnu.org 422") + (forward-line) + (search-forward "BarNet << :irc.gnu.org 221")) + (when noninteractive + (kill-buffer "*erc-protocol*") + (should-not erc-debug-irc-protocol))) -- 2.31.1
[-- Attachment #1: Type: text/plain, Size: 88 bytes --] v4. Ugh, so the last one was still failing intermittently (on 27). Should be good now. [-- Warning: decoded text below may be mangled, UTF-8 assumed --] [-- Attachment #2: 0000-NOT-A-PATCH-v3-v4.diff --] [-- Type: text/x-patch, Size: 3338 bytes --] From 10aa53faea8b17ef659f166fdaf6da4191831aa1 Mon Sep 17 00:00:00 2001 From: "F. Jason Park" <jp@neverwas.me> Date: Sun, 12 Sep 2021 19:25:41 -0700 Subject: [PATCH 0/1] *** SUBJECT HERE *** *** BLURB HERE *** F. Jason Park (1): Add CRLF to outgoing ERC protocol logger lines lisp/erc/erc.el | 77 ++++++++++++++++++++++++-------------- test/lisp/erc/erc-tests.el | 36 ++++++++++++++++++ 2 files changed, 85 insertions(+), 28 deletions(-) Interdiff: diff --git a/lisp/erc/erc.el b/lisp/erc/erc.el index 033c392502..524a22e5a1 100644 --- a/lisp/erc/erc.el +++ b/lisp/erc/erc.el @@ -2405,8 +2405,6 @@ erc-toggle-debug-irc-protocol (lambda () (setq erc-debug-irc-protocol nil)) nil 'local) (goto-char (point-max)) - ;; Searchable phrase printed twice between logs and once before - ;; the first. This is a single line with CRLF endings. (let ((inhibit-read-only t)) (insert (if erc-debug-irc-protocol "\r\n" "") (erc-make-notice diff --git a/test/lisp/erc/erc-tests.el b/test/lisp/erc/erc-tests.el index f94b52ec9f..7a0867a0a1 100644 --- a/test/lisp/erc/erc-tests.el +++ b/test/lisp/erc/erc-tests.el @@ -114,13 +114,11 @@ erc-ring-previous-command (ert-deftest erc-log-irc-protocol () (should-not erc-debug-irc-protocol) (with-temp-buffer - (let (erc-server-announced-name - erc-network - (erc-server-process (start-process "fake" (current-buffer) "true")) - (erc-server-current-nick "tester") - (erc-session-server "myproxy.localhost") - (erc-session-port 6667) - (inhibit-message t)) + (setq erc-server-process (start-process "fake" (current-buffer) "true") + erc-server-current-nick "tester" + erc-session-server "myproxy.localhost" + erc-session-port 6667) + (let ((inhibit-message noninteractive)) (erc-toggle-debug-irc-protocol) (erc-log-irc-protocol "PASS changeme\r\n" 'outgoing) (setq erc-server-announced-name "irc.gnu.org") @@ -130,18 +128,20 @@ erc-log-irc-protocol (erc-log-irc-protocol ":irc.gnu.org 422 tester :MOTD missing") (setq erc-network 'BarNet) (erc-log-irc-protocol ":irc.gnu.org 221 tester +i") - (delete-process erc-server-process))) + (set-process-query-on-exit-flag erc-server-process nil))) (with-current-buffer "*erc-protocol*" (goto-char (point-min)) - (search-forward "myproxy.localhost:6667 >> PASS") + (search-forward "Version") + (search-forward "\r\n\r\n") + (search-forward "myproxy.localhost:6667 >> PASS" (line-end-position)) (forward-line) - (search-forward "irc.gnu.org << :irc.gnu.org 001") + (search-forward "irc.gnu.org << :irc.gnu.org 001" (line-end-position)) (forward-line) - (search-forward "irc.gnu.org << :irc.gnu.org 002") + (search-forward "irc.gnu.org << :irc.gnu.org 002" (line-end-position)) (forward-line) - (search-forward "FooNet << :irc.gnu.org 422") + (search-forward "FooNet << :irc.gnu.org 422" (line-end-position)) (forward-line) - (search-forward "BarNet << :irc.gnu.org 221")) + (search-forward "BarNet << :irc.gnu.org 221" (line-end-position))) (when noninteractive (kill-buffer "*erc-protocol*") (should-not erc-debug-irc-protocol))) -- 2.31.1 [-- Warning: decoded text below may be mangled, UTF-8 assumed --] [-- Attachment #3: 0001-Add-CRLF-to-outgoing-ERC-protocol-logger-lines.patch --] [-- Type: text/x-patch, Size: 9163 bytes --] From 10aa53faea8b17ef659f166fdaf6da4191831aa1 Mon Sep 17 00:00:00 2001 From: "F. Jason Park" <jp@neverwas.me> Date: Mon, 14 Jun 2021 22:24:01 -0700 Subject: [PATCH 1/1] Add CRLF to outgoing ERC protocol logger lines * erc.el (erc-debug-irc-protocol): Fix line-ending mismatch between incoming and outgoing logger lines without changing interface. Do this by adding carriage returns to the latter to improve machine readability. Change printed peer labels to most accurately reflect logical endpoints. (erc-debug-irc-protocol-time-format): Add new variable to support timestamps in protocol logger output. (erc-debug-irc-protocol-version): Add new variable to help tooling track logging format independent of ERC and Emacs versions. (erc-toggle-debug-irc-protocol): Add headers to protocol-log buffer to aid future bug-reproduction tools. Clean up overlong lines. This is bug#50009. --- lisp/erc/erc.el | 77 ++++++++++++++++++++++++-------------- test/lisp/erc/erc-tests.el | 36 ++++++++++++++++++ 2 files changed, 85 insertions(+), 28 deletions(-) diff --git a/lisp/erc/erc.el b/lisp/erc/erc.el index f01a99a30a..524a22e5a1 100644 --- a/lisp/erc/erc.el +++ b/lisp/erc/erc.el @@ -2312,6 +2312,13 @@ erc-error ;;; Debugging the protocol +(defvar erc-debug-irc-protocol-time-format "%FT%T.%6N%z " + "Timestamp format string for protocol logger.") + +(defconst erc-debug-irc-protocol-version "1" + "Protocol log format version number. +This is to help tooling track changes to the format.") + (defvar erc-debug-irc-protocol nil "If non-nil, log all IRC protocol traffic to the buffer \"*erc-protocol*\". @@ -2333,32 +2340,36 @@ erc-log-irc-protocol The buffer is created if it doesn't exist. -If OUTBOUND is non-nil, STRING is being sent to the IRC server -and appears in face `erc-input-face' in the buffer." +If OUTBOUND is non-nil, STRING is being sent to the IRC server and +appears in face `erc-input-face' in the buffer. Lines must already +contain CRLF endings. Peer is identified by the most precise label +available at run time, starting with the network name, followed by the +self-reported host name, and falling back to the dialed <server>:<port>. +When capturing logs for multiple peers and sorting them into buckets, +such inconsistent labeling may pose a problem during an initial server +burst. For now, the recommended approach is to wrap this function with +advice that temporarily redefines the symbol-function `erc-network'." (when erc-debug-irc-protocol - (let ((network-name (or (ignore-errors (erc-network-name)) - "???"))) + (let ((esid (or (and (fboundp 'erc-network) + (erc-network) + (erc-network-name)) + erc-server-announced-name + (format "%s:%s" erc-session-server erc-session-port))) + (ts (when erc-debug-irc-protocol-time-format + (format-time-string erc-debug-irc-protocol-time-format)))) (with-current-buffer (get-buffer-create "*erc-protocol*") (save-excursion (goto-char (point-max)) (let ((inhibit-read-only t)) - (insert (if (not outbound) - ;; Cope with the fact that string might - ;; contain multiple lines of text. - (let ((lines (delete "" (split-string string - "\n\\|\r\n"))) - (result "")) - (dolist (line lines) - (setq result (concat result network-name - " << " line "\n"))) - result) - (propertize - (concat network-name " >> " string - (if (/= ?\n - (aref string - (1- (length string)))) - "\n")) - 'font-lock-face 'erc-input-face))))) + (insert (if outbound + (concat ts esid " >> " string) + ;; Cope with multi-line messages + (let ((lines (split-string string "[\r\n]+" t)) + result) + (dolist (line lines) + (setq result (concat result ts esid + " << " line "\r\n"))) + result))))) (let ((orig-win (selected-window)) (debug-buffer-window (get-buffer-window (current-buffer) t))) (when debug-buffer-window @@ -2371,15 +2382,23 @@ erc-log-irc-protocol (defun erc-toggle-debug-irc-protocol (&optional arg) "Toggle the value of `erc-debug-irc-protocol'. -If ARG is non-nil, show the *erc-protocol* buffer." +If ARG is non-nil, show the *erc-protocol* buffer. Everything before +and including the first double CRLF is front matter. Everything before +the first double linefeed is a header." (interactive "P") (let* ((buf (get-buffer-create "*erc-protocol*"))) (with-current-buffer buf (view-mode-enter) (when (null (current-local-map)) - (let ((inhibit-read-only t)) - (insert (erc-make-notice "This buffer displays all IRC protocol traffic exchanged with each server.\n")) - (insert (erc-make-notice "Kill this buffer to terminate protocol logging.\n\n"))) + (let ((inhibit-read-only t) + (headers (concat "Version: " erc-debug-irc-protocol-version "\n" + "Emacs-Version: " emacs-version "\n" + "\n")) + (msg (concat "This buffer displays all IRC protocol traffic " + "exchanged with servers.\n" + "Kill it to disable logging.\n" + "Press `t' to toggle.\n"))) + (insert headers (erc-make-notice msg))) (use-local-map (make-sparse-keymap)) (local-set-key (kbd "t") 'erc-toggle-debug-irc-protocol)) (add-hook 'kill-buffer-hook @@ -2387,10 +2406,12 @@ erc-toggle-debug-irc-protocol nil 'local) (goto-char (point-max)) (let ((inhibit-read-only t)) - (insert (erc-make-notice - (format "IRC protocol logging %s at %s -- Press `t' to toggle logging.\n" + (insert (if erc-debug-irc-protocol "\r\n" "") + (erc-make-notice + (format "IRC protocol logging %s at %s" (if erc-debug-irc-protocol "disabled" "enabled") - (current-time-string)))))) + (current-time-string))) + (if erc-debug-irc-protocol "\r\n" "\r\n\r\n")))) (setq erc-debug-irc-protocol (not erc-debug-irc-protocol)) (if (and arg (not (get-buffer-window "*erc-protocol*" t))) diff --git a/test/lisp/erc/erc-tests.el b/test/lisp/erc/erc-tests.el index d13397274a..7a0867a0a1 100644 --- a/test/lisp/erc/erc-tests.el +++ b/test/lisp/erc/erc-tests.el @@ -24,6 +24,7 @@ (require 'ert) (require 'erc) (require 'erc-ring) +(require 'erc-networks) (ert-deftest erc--read-time-period () (cl-letf (((symbol-function 'read-string) (lambda (&rest _) ""))) @@ -109,3 +110,38 @@ erc-ring-previous-command (should (looking-at "abc"))))) (when noninteractive (kill-buffer "*#fake*"))) + +(ert-deftest erc-log-irc-protocol () + (should-not erc-debug-irc-protocol) + (with-temp-buffer + (setq erc-server-process (start-process "fake" (current-buffer) "true") + erc-server-current-nick "tester" + erc-session-server "myproxy.localhost" + erc-session-port 6667) + (let ((inhibit-message noninteractive)) + (erc-toggle-debug-irc-protocol) + (erc-log-irc-protocol "PASS changeme\r\n" 'outgoing) + (setq erc-server-announced-name "irc.gnu.org") + (erc-log-irc-protocol ":irc.gnu.org 001 tester :Welcome") + (erc-log-irc-protocol ":irc.gnu.org 002 tester :Your host is irc.gnu.org") + (setq erc-network 'FooNet) + (erc-log-irc-protocol ":irc.gnu.org 422 tester :MOTD missing") + (setq erc-network 'BarNet) + (erc-log-irc-protocol ":irc.gnu.org 221 tester +i") + (set-process-query-on-exit-flag erc-server-process nil))) + (with-current-buffer "*erc-protocol*" + (goto-char (point-min)) + (search-forward "Version") + (search-forward "\r\n\r\n") + (search-forward "myproxy.localhost:6667 >> PASS" (line-end-position)) + (forward-line) + (search-forward "irc.gnu.org << :irc.gnu.org 001" (line-end-position)) + (forward-line) + (search-forward "irc.gnu.org << :irc.gnu.org 002" (line-end-position)) + (forward-line) + (search-forward "FooNet << :irc.gnu.org 422" (line-end-position)) + (forward-line) + (search-forward "BarNet << :irc.gnu.org 221" (line-end-position))) + (when noninteractive + (kill-buffer "*erc-protocol*") + (should-not erc-debug-irc-protocol))) -- 2.31.1
[-- Attachment #1: Type: text/plain, Size: 235 bytes --] v5. Having two styles of line terminator (both CRLF and LF) present in the same buffer was dumb. So now it's just CRLF everywhere. I've also explained a bit about the format in the doc string for the version number variable. Thanks. . [-- Warning: decoded text below may be mangled, UTF-8 assumed --] [-- Attachment #2: 0000-v4-v5.diff --] [-- Type: text/x-patch, Size: 4053 bytes --] From 2dcb68486a49d59376778aea97a23ada1af5c1f4 Mon Sep 17 00:00:00 2001 From: "F. Jason Park" <jp@neverwas.me> Date: Tue, 14 Sep 2021 01:43:43 -0700 Subject: NOT A PATCH F. Jason Park (1): Add CRLF to outgoing ERC protocol logger lines lisp/erc/erc.el | 79 +++++++++++++++++++++++++------------- test/lisp/erc/erc-tests.el | 36 +++++++++++++++++ 2 files changed, 88 insertions(+), 27 deletions(-) Interdiff: diff --git a/lisp/erc/erc.el b/lisp/erc/erc.el index 524a22e5a1..fe4ec52880 100644 --- a/lisp/erc/erc.el +++ b/lisp/erc/erc.el @@ -2317,7 +2317,16 @@ erc-debug-irc-protocol-time-format (defconst erc-debug-irc-protocol-version "1" "Protocol log format version number. -This is to help tooling track changes to the format.") +This exists to help tooling track changes to the format. + +In version 1, everything before and including the first double CRLF is +front matter, which must also be CRLF terminated. Lines beginning with +three asterisks must be ignored as comments. Other lines should be +interpreted as email-style headers. Folding is not supported. A second +double CRLF, if present, signals the end of a log. Session resumption +is not supported. Logger lines must adhere to the following format: +TIMESTAMP PEER-NAME FLOW-INDICATOR IRC-MESSAGE CRLF. Outgoing messages +are indicated with a >> and incoming with a <<.") (defvar erc-debug-irc-protocol nil "If non-nil, log all IRC protocol traffic to the buffer \"*erc-protocol*\". @@ -2344,11 +2353,7 @@ erc-log-irc-protocol appears in face `erc-input-face' in the buffer. Lines must already contain CRLF endings. Peer is identified by the most precise label available at run time, starting with the network name, followed by the -self-reported host name, and falling back to the dialed <server>:<port>. -When capturing logs for multiple peers and sorting them into buckets, -such inconsistent labeling may pose a problem during an initial server -burst. For now, the recommended approach is to wrap this function with -advice that temporarily redefines the symbol-function `erc-network'." +announced host name, and falling back to the dialed <server>:<port>." (when erc-debug-irc-protocol (let ((esid (or (and (fboundp 'erc-network) (erc-network) @@ -2382,23 +2387,22 @@ erc-log-irc-protocol (defun erc-toggle-debug-irc-protocol (&optional arg) "Toggle the value of `erc-debug-irc-protocol'. -If ARG is non-nil, show the *erc-protocol* buffer. Everything before -and including the first double CRLF is front matter. Everything before -the first double linefeed is a header." +If ARG is non-nil, show the *erc-protocol* buffer." (interactive "P") (let* ((buf (get-buffer-create "*erc-protocol*"))) (with-current-buffer buf (view-mode-enter) (when (null (current-local-map)) (let ((inhibit-read-only t) - (headers (concat "Version: " erc-debug-irc-protocol-version "\n" - "Emacs-Version: " emacs-version "\n" - "\n")) - (msg (concat "This buffer displays all IRC protocol traffic " - "exchanged with servers.\n" - "Kill it to disable logging.\n" - "Press `t' to toggle.\n"))) - (insert headers (erc-make-notice msg))) + (msg (list + (concat "Version: " erc-debug-irc-protocol-version) + (concat "Emacs-Version: " emacs-version) + (erc-make-notice + (concat "This buffer displays all IRC protocol " + "traffic exchanged with servers.")) + (erc-make-notice "Kill it to disable logging.") + (erc-make-notice "Press `t' to toggle.")))) + (insert (string-join msg "\r\n"))) (use-local-map (make-sparse-keymap)) (local-set-key (kbd "t") 'erc-toggle-debug-irc-protocol)) (add-hook 'kill-buffer-hook -- 2.31.1 [-- Warning: decoded text below may be mangled, UTF-8 assumed --] [-- Attachment #3: 0001-Add-CRLF-to-outgoing-ERC-protocol-logger-lines.patch --] [-- Type: text/x-patch, Size: 9047 bytes --] From 2dcb68486a49d59376778aea97a23ada1af5c1f4 Mon Sep 17 00:00:00 2001 From: "F. Jason Park" <jp@neverwas.me> Date: Mon, 14 Jun 2021 22:24:01 -0700 Subject: [PATCH 1/1] Add CRLF to outgoing ERC protocol logger lines * erc.el (erc-debug-irc-protocol): Fix line-ending mismatch between incoming and outgoing logger lines without changing interface. Do this by adding carriage returns to the latter to improve machine readability. Change printed peer labels to most accurately reflect logical endpoints. (erc-debug-irc-protocol-time-format): Add new variable to support timestamps in protocol logger output. (erc-debug-irc-protocol-version): Add new variable to help tooling track logging format independent of ERC and Emacs versions. (erc-toggle-debug-irc-protocol): Add headers to protocol-log buffer to aid future bug-reproduction tools. Clean up overlong lines. This is bug#50009. --- lisp/erc/erc.el | 79 +++++++++++++++++++++++++------------- test/lisp/erc/erc-tests.el | 36 +++++++++++++++++ 2 files changed, 88 insertions(+), 27 deletions(-) diff --git a/lisp/erc/erc.el b/lisp/erc/erc.el index f01a99a30a..fe4ec52880 100644 --- a/lisp/erc/erc.el +++ b/lisp/erc/erc.el @@ -2312,6 +2312,22 @@ erc-error ;;; Debugging the protocol +(defvar erc-debug-irc-protocol-time-format "%FT%T.%6N%z " + "Timestamp format string for protocol logger.") + +(defconst erc-debug-irc-protocol-version "1" + "Protocol log format version number. +This exists to help tooling track changes to the format. + +In version 1, everything before and including the first double CRLF is +front matter, which must also be CRLF terminated. Lines beginning with +three asterisks must be ignored as comments. Other lines should be +interpreted as email-style headers. Folding is not supported. A second +double CRLF, if present, signals the end of a log. Session resumption +is not supported. Logger lines must adhere to the following format: +TIMESTAMP PEER-NAME FLOW-INDICATOR IRC-MESSAGE CRLF. Outgoing messages +are indicated with a >> and incoming with a <<.") + (defvar erc-debug-irc-protocol nil "If non-nil, log all IRC protocol traffic to the buffer \"*erc-protocol*\". @@ -2333,32 +2349,32 @@ erc-log-irc-protocol The buffer is created if it doesn't exist. -If OUTBOUND is non-nil, STRING is being sent to the IRC server -and appears in face `erc-input-face' in the buffer." +If OUTBOUND is non-nil, STRING is being sent to the IRC server and +appears in face `erc-input-face' in the buffer. Lines must already +contain CRLF endings. Peer is identified by the most precise label +available at run time, starting with the network name, followed by the +announced host name, and falling back to the dialed <server>:<port>." (when erc-debug-irc-protocol - (let ((network-name (or (ignore-errors (erc-network-name)) - "???"))) + (let ((esid (or (and (fboundp 'erc-network) + (erc-network) + (erc-network-name)) + erc-server-announced-name + (format "%s:%s" erc-session-server erc-session-port))) + (ts (when erc-debug-irc-protocol-time-format + (format-time-string erc-debug-irc-protocol-time-format)))) (with-current-buffer (get-buffer-create "*erc-protocol*") (save-excursion (goto-char (point-max)) (let ((inhibit-read-only t)) - (insert (if (not outbound) - ;; Cope with the fact that string might - ;; contain multiple lines of text. - (let ((lines (delete "" (split-string string - "\n\\|\r\n"))) - (result "")) - (dolist (line lines) - (setq result (concat result network-name - " << " line "\n"))) - result) - (propertize - (concat network-name " >> " string - (if (/= ?\n - (aref string - (1- (length string)))) - "\n")) - 'font-lock-face 'erc-input-face))))) + (insert (if outbound + (concat ts esid " >> " string) + ;; Cope with multi-line messages + (let ((lines (split-string string "[\r\n]+" t)) + result) + (dolist (line lines) + (setq result (concat result ts esid + " << " line "\r\n"))) + result))))) (let ((orig-win (selected-window)) (debug-buffer-window (get-buffer-window (current-buffer) t))) (when debug-buffer-window @@ -2377,9 +2393,16 @@ erc-toggle-debug-irc-protocol (with-current-buffer buf (view-mode-enter) (when (null (current-local-map)) - (let ((inhibit-read-only t)) - (insert (erc-make-notice "This buffer displays all IRC protocol traffic exchanged with each server.\n")) - (insert (erc-make-notice "Kill this buffer to terminate protocol logging.\n\n"))) + (let ((inhibit-read-only t) + (msg (list + (concat "Version: " erc-debug-irc-protocol-version) + (concat "Emacs-Version: " emacs-version) + (erc-make-notice + (concat "This buffer displays all IRC protocol " + "traffic exchanged with servers.")) + (erc-make-notice "Kill it to disable logging.") + (erc-make-notice "Press `t' to toggle.")))) + (insert (string-join msg "\r\n"))) (use-local-map (make-sparse-keymap)) (local-set-key (kbd "t") 'erc-toggle-debug-irc-protocol)) (add-hook 'kill-buffer-hook @@ -2387,10 +2410,12 @@ erc-toggle-debug-irc-protocol nil 'local) (goto-char (point-max)) (let ((inhibit-read-only t)) - (insert (erc-make-notice - (format "IRC protocol logging %s at %s -- Press `t' to toggle logging.\n" + (insert (if erc-debug-irc-protocol "\r\n" "") + (erc-make-notice + (format "IRC protocol logging %s at %s" (if erc-debug-irc-protocol "disabled" "enabled") - (current-time-string)))))) + (current-time-string))) + (if erc-debug-irc-protocol "\r\n" "\r\n\r\n")))) (setq erc-debug-irc-protocol (not erc-debug-irc-protocol)) (if (and arg (not (get-buffer-window "*erc-protocol*" t))) diff --git a/test/lisp/erc/erc-tests.el b/test/lisp/erc/erc-tests.el index d13397274a..7a0867a0a1 100644 --- a/test/lisp/erc/erc-tests.el +++ b/test/lisp/erc/erc-tests.el @@ -24,6 +24,7 @@ (require 'ert) (require 'erc) (require 'erc-ring) +(require 'erc-networks) (ert-deftest erc--read-time-period () (cl-letf (((symbol-function 'read-string) (lambda (&rest _) ""))) @@ -109,3 +110,38 @@ erc-ring-previous-command (should (looking-at "abc"))))) (when noninteractive (kill-buffer "*#fake*"))) + +(ert-deftest erc-log-irc-protocol () + (should-not erc-debug-irc-protocol) + (with-temp-buffer + (setq erc-server-process (start-process "fake" (current-buffer) "true") + erc-server-current-nick "tester" + erc-session-server "myproxy.localhost" + erc-session-port 6667) + (let ((inhibit-message noninteractive)) + (erc-toggle-debug-irc-protocol) + (erc-log-irc-protocol "PASS changeme\r\n" 'outgoing) + (setq erc-server-announced-name "irc.gnu.org") + (erc-log-irc-protocol ":irc.gnu.org 001 tester :Welcome") + (erc-log-irc-protocol ":irc.gnu.org 002 tester :Your host is irc.gnu.org") + (setq erc-network 'FooNet) + (erc-log-irc-protocol ":irc.gnu.org 422 tester :MOTD missing") + (setq erc-network 'BarNet) + (erc-log-irc-protocol ":irc.gnu.org 221 tester +i") + (set-process-query-on-exit-flag erc-server-process nil))) + (with-current-buffer "*erc-protocol*" + (goto-char (point-min)) + (search-forward "Version") + (search-forward "\r\n\r\n") + (search-forward "myproxy.localhost:6667 >> PASS" (line-end-position)) + (forward-line) + (search-forward "irc.gnu.org << :irc.gnu.org 001" (line-end-position)) + (forward-line) + (search-forward "irc.gnu.org << :irc.gnu.org 002" (line-end-position)) + (forward-line) + (search-forward "FooNet << :irc.gnu.org 422" (line-end-position)) + (forward-line) + (search-forward "BarNet << :irc.gnu.org 221" (line-end-position))) + (when noninteractive + (kill-buffer "*erc-protocol*") + (should-not erc-debug-irc-protocol))) -- 2.31.1
I think we can all agree this kind of "come to think of it" iteration is why PR-based submission is superior to patches.
dick writes:
> I think we can all agree this kind of "come to think of it" iteration is why
> PR-based submission is superior to patches.
Do we? What's superior about it?
Sigh, it pains me to have to add to the verbiage maelstrom that is debbugs when the antiquity of GNU patch is self-evident. A maintainer's sanity is inversely related to how much reading he has to do. In a PR-based workflow, the changeset is unambiguous. On a platform like Github, the changeset is manifest (in pretty colors) from the "Files Changed" tab in a PR submission. Eleventh-hour revisions get incorporated without fuss via the mild genius of git. Here, OP has submitted several changesets, of which only the chronologically latest he wishes the maintainer to consider. To ascertain this fact, the maintainer must read, and recall his happiness is inversely proportional to how much reading he has to do. In a cluster**** like bug#45474 where literally every one and their third cousin is espousing a changeset, the maintainer not only has to read, he has to decide, and that is a whole other circle of hell. The programmer's tendency to pontificate and obfuscate (of which the present missive is a fine example) does not help matters.
> From: dick <dick.r.chiang@gmail.com>
> Date: Wed, 15 Sep 2021 12:35:00 -0400
> Cc: 50009@debbugs.gnu.org, "J.P." <jp@neverwas.me>
>
> Sigh, it pains me to have to add to the verbiage maelstrom that is debbugs
> when the antiquity of GNU patch is self-evident.
You are not helping, so please at least don't interfere.
There's no problem knowing which patch is the latest one, contrary to
your propaganda.
EZ> You are not helping, so please at least don't interfere. Your hamfisted use of the terms "helping" and "interfere" presuppose a notion of progress, one which is premised on the status quo.
> From: dick <dick.r.chiang@gmail.com>
> Cc: 50009@debbugs.gnu.org, bandali@gnu.org, jp@neverwas.me
> Date: Wed, 15 Sep 2021 13:49:46 -0400
>
> EZ> You are not helping, so please at least don't interfere.
>
> Your hamfisted use of the terms "helping" and "interfere" presuppose a notion
> of progress, one which is premised on the status quo.
No, I mean helping and interfering with us, the maintainers, doing our
job.
dick writes: > Sigh, it pains me to have to add to the verbiage maelstrom that is debbugs > when the antiquity of GNU patch is self-evident. To be clear, GNU is by far not the only project that uses patch-driven workflows. > A maintainer's sanity is inversely related to how much reading he has to do. > In a PR-based workflow, the changeset is unambiguous. On a platform like > Github, the changeset is manifest (in pretty colors) from the "Files Changed" > tab in a PR submission. Eleventh-hour revisions get incorporated without fuss > via the mild genius of git. I don't see how a GitHub-like interface which separates code from surrounding context/discussion is any more helpful. PR comments are also meant to be read and responded to -- much like email threads -- only they're more poorly implemented and often require a full blown web browser to interact with. I get the 'pretty colors' and syntax highlighting in my MUA (email client), which happens to be Emacs-based, just fine. For Emacs, there's even a wonderful 'debbugs' package on GNU ELPA that I highly encourage folks to try, if they use the debbugs bug tracker regularly. > Here, OP has submitted several changesets, of which only the chronologically > latest he wishes the maintainer to consider. To ascertain this fact, the > maintainer must read, and recall his happiness is inversely proportional to > how much reading he has to do. I mean, using a decent MUA one could easily skip or move back and forth between various replies in a thread, and fairly quickly tell which attached patch needs review/merging, like Eli alluded to. > In a cluster**** like bug#45474 where literally every one and their third > cousin is espousing a changeset, the maintainer not only has to read, he has > to decide, and that is a whole other circle of hell. The programmer's > tendency to pontificate and obfuscate (of which the present missive is a fine > example) does not help matters. I'm not sure what to say to this, other than 1. those sound to me like rather unkind characterizations of the people involved in that discussion and their work, and 2. I've seen my fair share of similarly long yet considerably worse GitHub discussions/comments. As far as I could tell from a quick glance, people in bug#45474 seem to be discussing/collaborating in good faith, and amicably. Yet I wouldn't attribute that to the underlying piece of software (Debbugs) or workflow (patch-based) being used. To wrap up this wall of text and move on, I get that different people have different preferences of workflow, but I don't see how the things you said describe any inherent advantage/"superior"ity of the PR-based workflow. If your point is about pushing code to some branch for review and subsequent updates being more convenient, people already do that for larger changes to Emacs (e.g. native-comp) by developing their work in an auxiliary 'feature/...' branch in emacs.git, which is then reviewed and hopefully merged into the main development branch at some point.
> I've seen my fair share of similarly long yet considerably worse GitHub
> discussions
"Considerably worse" would be an understatement. Verbosity is a function of
the age and number of participants, and Github skews unfavorably in both those
categories.
My point was the verbosity, a systemic cost to doing business, does not
under a PR-based workflow occlude the proposed changeset, whereas under
"wonderful" Debbugs the proliferation of proposed patches could.
Your raising the example of native-comp merely reinforces my point that
branch-based schemes are superior to ad hoc email-based ones.
It's clear we've already made our minds about it. But you asked, so I
answered. Pardon the "interference" to those trying to "do their job."
> From: Amin Bandali <bandali@gnu.org>
> Date: Wed, 15 Sep 2021 20:03:24 -0400
> Cc: 50009@debbugs.gnu.org, "J.P." <jp@neverwas.me>
>
> dick writes:
>
> > Sigh, it pains me to have to add to the verbiage maelstrom that is debbugs
> > when the antiquity of GNU patch is self-evident.
>
> To be clear, GNU is by far not the only project that uses patch-driven
> workflows.
This discussion doesn't belong here. Here we discus a specific issue
submitted to the Emacs issue tracker. Broad discussions about our
development workflows should be held on emacs-devel. Please move it
there (if you must have this discussion, which is about the umpteenth
time it is being brought up, including very recently).
Whatever you do, please STOP discussing it here. Right now, the only
effect this has is to make following the discussions of bug#50009 much
harder by polluting it with unrelated messages, which are not even
tangents.
"J.P." <jp@neverwas.me> writes: > v5. Having two styles of line terminator (both CRLF and LF) present in > the same buffer was dumb. So now it's just CRLF everywhere. I've also > explained a bit about the format in the doc string for the version > number variable. Thanks. Thanks; makes sense to me (and seems to work well when testing it), so I've pushed it to Emacs 28. -- (domestic pets only, the antidote for overdose, milk.) bloggy blog: http://lars.ingebrigtsen.no
[[[ To any NSA and FBI agents reading my email: please consider ]]] [[[ whether defending the US Constitution against all enemies, ]]] [[[ foreign or domestic, requires you to follow Snowden's example. ]]] Can a PR-based workflow be made to operate via email, in a way that doesn't require a net connection? (Except, at some later time, for committing a change.) That is a requisite for us. -- Dr Richard Stallman (https://stallman.org) Chief GNUisance of the GNU Project (https://gnu.org) Founder, Free Software Foundation (https://fsf.org) Internet Hall-of-Famer (https://internethalloffame.org)
You may construe my reticence on the matter as dutiful compliance to the maintainer's exhortations.
> From: Richard Stallman <rms@gnu.org>
> Date: Thu, 16 Sep 2021 20:13:56 -0400
> Cc: 50009@debbugs.gnu.org, bandali@gnu.org, jp@neverwas.me
>
> Can a PR-based workflow be made to operate via email, in a way that
> doesn't require a net connection? (Except, at some later time, for
> committing a change.) That is a requisite for us.
As I said, we should NOT discuss these matters in an unrelated bug
report.
Our prerequisite is not to have the PR workflow work via email, it is
that the maintainer's part of the workflow could be done via email.