From mboxrd@z Thu Jan 1 00:00:00 1970 Path: news.gmane.io!.POSTED.blaine.gmane.org!not-for-mail From: "J.P." Newsgroups: gmane.emacs.bugs Subject: bug#50009: 28.0.50; add CRLF to outgoing ERC protocol logger lines Date: Sun, 12 Sep 2021 20:04:47 -0700 Message-ID: <87y281tbu8.fsf@neverwas.me> References: <87v94chxbh.fsf@neverwas.me> Mime-Version: 1.0 Content-Type: multipart/mixed; boundary="=-=-=" Injection-Info: ciao.gmane.io; posting-host="blaine.gmane.org:116.202.254.214"; logging-data="11150"; mail-complaints-to="usenet@ciao.gmane.io" User-Agent: Gnus/5.13 (Gnus v5.13) Emacs/28.0.50 (gnu/linux) To: 50009@debbugs.gnu.org Original-X-From: bug-gnu-emacs-bounces+geb-bug-gnu-emacs=m.gmane-mx.org@gnu.org Mon Sep 13 05:06:17 2021 Return-path: Envelope-to: geb-bug-gnu-emacs@m.gmane-mx.org Original-Received: from lists.gnu.org ([209.51.188.17]) by ciao.gmane.io with esmtps (TLS1.2:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.92) (envelope-from ) id 1mPcIS-0002jk-OA for geb-bug-gnu-emacs@m.gmane-mx.org; Mon, 13 Sep 2021 05:06:16 +0200 Original-Received: from localhost ([::1]:57126 helo=lists1p.gnu.org) by lists.gnu.org with esmtp (Exim 4.90_1) (envelope-from ) id 1mPcIQ-0004Qf-MR for geb-bug-gnu-emacs@m.gmane-mx.org; Sun, 12 Sep 2021 23:06:14 -0400 Original-Received: from eggs.gnu.org ([2001:470:142:3::10]:33592) by lists.gnu.org with esmtps (TLS1.2:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.90_1) (envelope-from ) id 1mPcIE-0004QH-EQ for bug-gnu-emacs@gnu.org; Sun, 12 Sep 2021 23:06:02 -0400 Original-Received: from debbugs.gnu.org ([209.51.188.43]:60495) by eggs.gnu.org with esmtps (TLS1.2:ECDHE_RSA_AES_128_GCM_SHA256:128) (Exim 4.90_1) (envelope-from ) id 1mPcIE-0000Gq-6s for bug-gnu-emacs@gnu.org; Sun, 12 Sep 2021 23:06:02 -0400 Original-Received: from Debian-debbugs by debbugs.gnu.org with local (Exim 4.84_2) (envelope-from ) id 1mPcID-0001lC-SV for bug-gnu-emacs@gnu.org; Sun, 12 Sep 2021 23:06:01 -0400 X-Loop: help-debbugs@gnu.org Resent-From: "J.P." Original-Sender: "Debbugs-submit" Resent-CC: bug-gnu-emacs@gnu.org Resent-Date: Mon, 13 Sep 2021 03:06:01 +0000 Resent-Message-ID: Resent-Sender: help-debbugs@gnu.org X-GNU-PR-Message: followup 50009 X-GNU-PR-Package: emacs X-GNU-PR-Keywords: patch Original-Received: via spool by 50009-submit@debbugs.gnu.org id=B50009.16315023036693 (code B ref 50009); Mon, 13 Sep 2021 03:06:01 +0000 Original-Received: (at 50009) by debbugs.gnu.org; 13 Sep 2021 03:05:03 +0000 Original-Received: from localhost ([127.0.0.1]:43808 helo=debbugs.gnu.org) by debbugs.gnu.org with esmtp (Exim 4.84_2) (envelope-from ) id 1mPcHG-0001js-Ls for submit@debbugs.gnu.org; Sun, 12 Sep 2021 23:05:03 -0400 Original-Received: from mail-108-mta7.mxroute.com ([136.175.108.7]:45135) by debbugs.gnu.org with esmtp (Exim 4.84_2) (envelope-from ) id 1mPcHB-0001jI-T1 for 50009@debbugs.gnu.org; Sun, 12 Sep 2021 23:05:01 -0400 Original-Received: from filter004.mxroute.com ([149.28.56.236] filter004.mxroute.com) (Authenticated sender: mN4UYu2MZsgR) by mail-108-mta7.mxroute.com (ZoneMTA) with ESMTPSA id 17bdd1d4a4100074ba.001 for <50009@debbugs.gnu.org> (version=TLSv1/SSLv3 cipher=ECDHE-RSA-AES128-GCM-SHA256); Mon, 13 Sep 2021 03:04:49 +0000 X-Zone-Loop: ab936c35e1adf1c92963ceeb98bd0286a57c83e6df36 X-Originating-IP: [149.28.56.236] In-Reply-To: <87v94chxbh.fsf@neverwas.me> (J. P.'s message of "Wed, 11 Aug 2021 07:26:26 -0700") X-AuthUser: masked@neverwas.me X-BeenThere: debbugs-submit@debbugs.gnu.org X-Mailman-Version: 2.1.18 Precedence: list X-BeenThere: bug-gnu-emacs@gnu.org List-Id: "Bug reports for GNU Emacs, the Swiss army knife of text editors" List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Errors-To: bug-gnu-emacs-bounces+geb-bug-gnu-emacs=m.gmane-mx.org@gnu.org Original-Sender: "bug-gnu-emacs" Xref: news.gmane.io gmane.emacs.bugs:214173 Archived-At: --=-=-= Content-Type: text/plain v4. Ugh, so the last one was still failing intermittently (on 27). Should be good now. --=-=-= Content-Type: text/x-patch Content-Disposition: attachment; filename=0000-NOT-A-PATCH-v3-v4.diff >From 10aa53faea8b17ef659f166fdaf6da4191831aa1 Mon Sep 17 00:00:00 2001 From: "F. Jason Park" 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 --=-=-= Content-Type: text/x-patch Content-Disposition: attachment; filename=0001-Add-CRLF-to-outgoing-ERC-protocol-logger-lines.patch >From 10aa53faea8b17ef659f166fdaf6da4191831aa1 Mon Sep 17 00:00:00 2001 From: "F. Jason Park" 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 :. +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 --=-=-=--