17

I depend on the *Messages* buffer a lot, but entries are not timestamped.

How can one add a timestamp to each entry in Emacs' Messages buffer?

So that something like this:

Loading /Users/gsl/lisp.d/init.el (source)...
No outline structure detected
For information about GNU Emacs and the GNU system, type C-h C-a.
Loading /Users/gsl/lisp.d/var/recentf...done
Error running timer: (wrong-number-of-arguments (lambda nil (setq gc-cons-threshold (* 64 1024 1024)) (message "WARNING: gc-cons-threshold restored to %S")) 1)
[yas] Prepared just-in-time loading of snippets successfully.
M-] is undefined
CHILDREN [2 times]
‘show-all’ is an obsolete command (as of 25.1); use ‘outline-show-all’ instead.
Invalid face reference: nil [33 times]
Auto-saving...done
Saving file /Users/gsl/lisp.d/init.el...
Wrote /Users/gsl/lisp.d/init.el
mwheel-scroll: Beginning of buffer [5 times]
Mark set
previous-line: Beginning of buffer [10 times]
Quit [4 times]

will become something like this:

2017-02-14-18:50:01 Loading /Users/gsl/lisp.d/init.el (source)...
2017-02-14-18:50:02 No outline structure detected
2017-02-14-18:50:03 For information about GNU Emacs and the GNU system, type C-h C-a.
2017-02-14-18:50:05 Loading /Users/gsl/lisp.d/var/recentf...done
2017-02-14-18:50:10 Error running timer: (wrong-number-of-arguments (lambda nil (setq gc-cons-threshold (* 64 1024 1024)) (message "WARNING: gc-cons-threshold restored     to %S")) 1)
2017-02-14-18:50:12 [yas] Prepared just-in-time loading of snippets successfully.
2017-02-14-18:50:40 M-] is undefined
2017-02-14-18:50:41 CHILDREN [2 times]
2017-02-14-18:50:00 ‘show-all’ is an obsolete command (as of 25.1); use ‘outline-show-all’ instead.
2017-02-14-18:50:01 Invalid face reference: nil [33 times]
2017-02-14-18:51:01 Auto-saving...done
2017-02-14-18:51:03 Saving file /Users/gsl/lisp.d/init.el...
2017-02-14-18:51:06 Wrote /Users/gsl/lisp.d/init.el
2017-02-14-18:51:09 mwheel-scroll: Beginning of buffer [5 times]
2017-02-14-18:51:11 Mark set
2017-02-14-18:51:21 previous-line: Beginning of buffer [10 times]

I searched on EmacsWiki, Reddit and emacs.sx of course, to no avail.

I am aware of command-log-mode, which can be adjusted to log with timestamps, but it is useful only for interactive commands, not all messages, including Emacs' "system" ones.

Instead, every message logged to the Messages buffer should be timestamped.

How can one add a timestamp to each entry in Emacs' Messages buffer, no matter its source?

4
  • 2
    This sounds like a feature request for Emacs. The message command is implemented in C and likely has direct callers, so you won't be able to ensure every logged message gets a timestamp without building Emacs yourself. That said, you may be able to advise the message command to introduce a time stamp when it is called from Elisp. Some caution is required: message can be called with no args, an empty format string, etc. You also want to avoid a recursive loop should your timestamp advice itself call message in some code path.
    – glucas
    Commented Apr 14, 2017 at 18:33
  • 1
    I have not tried it but it seems like you should be able to advice onto message emacswiki.org/emacs/AdvisingFunctions stackoverflow.com/questions/21524488/… superuser.com/questions/669701/… Commented Apr 14, 2017 at 21:29
  • 1
    I'd be inclined to use after-change-functions (in the messages buffer) to implement that. Whenever something is inserted at the end of the buffer, prefix a timestamp to it.
    – phils
    Commented Jun 14, 2017 at 9:41
  • 2
    @phils Refer from gnu.org/software/emacs/manual/html_node/elisp/Change-Hooks.html Output of messages into the Messages buffer does not call these functions, and neither do certain internal buffer changes, such as changes in buffers created by Emacs internally for certain jobs, that should not be visible to Lisp programs.
    – xinfa tang
    Commented Mar 2, 2018 at 2:48

4 Answers 4

14

I have the following snippet in my init.el, which was adapted from an original I found in the following Reddit thread: http://www.reddit.com/r/emacs/comments/16tzu9/anyone_know_of_a_reasonable_way_to_timestamp/

(EDIT: modernised to advice-add and removed clumsy read-only buffer handling on advice of @blujay)

(defun sh/current-time-microseconds ()
  "Return the current time formatted to include microseconds."
  (let* ((nowtime (current-time))
         (now-ms (nth 2 nowtime)))
    (concat (format-time-string "[%Y-%m-%dT%T" nowtime) (format ".%d]" now-ms))))

(defun sh/ad-timestamp-message (FORMAT-STRING &rest args)
  "Advice to run before `message' that prepends a timestamp to each message.

Activate this advice with:
(advice-add 'message :before 'sh/ad-timestamp-message)"
  (unless (string-equal FORMAT-STRING "%s%s")
    (let ((deactivate-mark nil)
          (inhibit-read-only t))
      (with-current-buffer "*Messages*"
        (goto-char (point-max))
        (if (not (bolp))
          (newline))
        (insert (sh/current-time-microseconds) " ")))))

(advice-add 'message :before 'sh/ad-timestamp-message)

This results in decoration of the *Messages* buffer as follows:

[2017-06-13T07:21:13.270070] Turning on magit-auto-revert-mode...
[2017-06-13T07:21:13.467317] Turning on magit-auto-revert-mode...done
[2017-06-13T07:21:13.557918] For information about GNU Emacs and the GNU system, type C-h C-a.
7
  • 4
    I wonder why this isn't provided as an option by default.
    – bertfred
    Commented Jun 14, 2017 at 12:04
  • 1
    Brilliant, this is exactly what I was looking for. Thank you.
    – gsl
    Commented Jun 14, 2017 at 14:15
  • 4
    @bertfred Because no one has made it happen. Perhaps, that's you?
    – Phil Lord
    Commented Jun 15, 2017 at 19:30
  • 3
    Could you rewrite the advice using advice-add? It's the preferred method now, as it knows how to handle situations that defadvice can't. Also, you should probably not do (read-only-mode 0), because that is probably permanent. You can bind inhibit-read-only to t around the code that modifies the buffer.
    – user3871
    Commented Aug 6, 2017 at 6:10
  • 3
    I use your code, but display many messages just a timestamp
    – xinfa tang
    Commented Feb 1, 2018 at 3:27
9

The translation of @xinfatang's simple solution to the new advice-add syntax as a wrapper around the message function is:

(defun my-message-with-timestamp (old-func fmt-string &rest args)
   "Prepend current timestamp (with microsecond precision) to a message"
   (apply old-func
          (concat (format-time-string "[%F %T.%3N %Z] ")
                   fmt-string)
          args))

Outputs *Messages* like:

[2018-02-25 10:13:45.442 PST] Mark set

To add:

 (advice-add 'message :around #'my-message-with-timestamp)

To remove:

 (advice-remove 'message #'my-message-with-timestamp)
2
  • 3
    You could also just filter the args, rather than using around advice: (advice-add 'message :filter-args 'with-timestamp) would work with a function like this: (defun with-timestamp (args) (push (concat (format-time-string "[%F %T.%3N] ") (car args)) (cdr args)))
    – glucas
    Commented Feb 25, 2018 at 19:50
  • 2
    @glucas Nice! I get timestamps w/o message though when I hover the mouse over the minibuffer. Is there a way to avoid that?
    – AstroFloyd
    Commented Dec 23, 2019 at 19:59
6

Refer to https://www.emacswiki.org/emacs/DebugMessages:

        (defadvice message (before when-was-that activate)
          "Add timestamps to `message' output."
          (ad-set-arg 0 (concat (format-time-string "[%Y-%m-%d %T %Z] ") 
                                (ad-get-arg 0)) ))

Finally, I still like Stuart Hickinbottom 's answer, because it avoids showing timestamp in the minibuffer. The following is a modified version which I use, it ignores messages only shown in the echo area(by letting message-log-max to nil before message function call):

    (defun my/ad-timestamp-message (FORMAT-STRING &rest args)
      "Advice to run before `message' that prepends a timestamp to each message.
        Activate this advice with:
          (advice-add 'message :before 'my/ad-timestamp-message)
        Deactivate this advice with:
          (advice-remove 'message 'my/ad-timestamp-message)"
      (if message-log-max
          (let ((deactivate-mark nil)
                (inhibit-read-only t))
            (with-current-buffer "*Messages*"
              (goto-char (point-max))
              (if (not (bolp))
                  (newline))
              (insert (format-time-string "[%F %T.%3N] "))))))
     (advice-add 'message :before 'my/ad-timestamp-message)
1
  • 2
    Change timestamp format to %F %T.%3N for show microseconds
    – xinfa tang
    Commented Feb 1, 2018 at 3:29
2

My solution expands on Stuart Hickinbottom 's and xinfa tang 's answers by NOT printing the timestamp of repeated messages:

(defvar my-package--last-message nil
  "Last message with timestamp appended to it.")

(defun my-package-ad-timestamp-message (format-string &rest args)
  "Prepend timestamp to each message in message buffer.

FORMAT-STRING and ARGS are used by `message' to print a formatted string.

Enable with (add-hook 'find-file-hook 'my-package-ad-timestamp-message)"
  (when (and message-log-max
             (not (string-equal format-string "%s%s")))
    (let ((formatted-message-string (if args
                                        (apply 'format `(,format-string ,@args))
                                      format-string)))
      (unless (string= formatted-message-string my-package--last-message)
        (setq my-package--last-message formatted-message-string)
        (let ((deactivate-mark nil)
              (inhibit-read-only t))
          (with-current-buffer "*Messages*"
            (goto-char (point-max))
            (when (not (bolp))
              (newline))
            (insert (format-time-string "[%F %T.%3N] "))))))))

It accomplishes this by comparing the current message to the last message printed with a timestamp.

1
  • Thanks, very useful to have the option not to print timestamps of repeated messages.
    – gsl
    Commented Apr 24, 2021 at 12:09

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service and acknowledge you have read our privacy policy.

Not the answer you're looking for? Browse other questions tagged or ask your own question.