Mike Griese b0006f4af2 Write the entire exporting & logging spec

2021-08-31 10:58:32 -05:00

17 KiB

Raw Blame History

author	created on	last updated	issue id
Mike Griese @zadjii-msft	2021-08-31	2021-08-31

Buffer Exporting and Logging

Abstract

A common user need is the ability to export the history of a terminal session to a file, for later inspection or validation. This is something that could be triggered manually. Many terminal emulators provide the ability to automatically log the output of a session to a file, so the history is always captured. This spec will address improvements to the Windows Terminal to enable these kinds of exporting and logging scenarios.

Background

Inspiration

Below are screenshots from the settings pages of three different terminal emulators with similar features - PuTTY, SecureCRT, and ConEmu:

figure 1: PuTTY settings

figure 2: SecureCRT settings

figure 3: ConEmu settings

These applications all offer some settings in common. Primarily, the important feature is the ability to specify a path to a log file which contains some special string formatting. This allows the user to log to different files based on the time & date of the session, or based on the session name.

User Stories

Story A: The user is able to use a context menu entry on the tab to export the contents of the buffer to a file, which they are prompted for.
- This is explicitly what was requested in #642
Story B: The user can bind an action to export the contents of the buffer to a file, which they are prompted for.
- Very similar to A, but via the command palette or a keybinding.
Story C: The user can export to an explicit file via an action
- similar to B, but allowing for declaring the path to a file rather than prompting at runtime.
Story D: The user can choose to append to a file when exporting, rather than overwritting.
Story E: The user can specify a format string in the path to the file to export to, which the Terminal will automatically replace with variables like the time, date, and profile name.
Story F: When opening a specific profile, the user can automatically log to a file
Story G: The user can execute an action to start or stop logging to a given file.

Solution Design

I'm proposing the following actions and profile settings

New Action: exportBuffer().
- Export the contents of the buffer to a file.
- path (string, defaults to ""): When empty, prompt the user for a name of a file to export to, using a file picker. This path accepts special formatting strings that will be substituted with certain variables (discussed below).
- append (boolean, defaults to false): When false, the file's contents will be overwritten. When true, the buffer contents will be appended to the end of the file.
New Profile Settings object: logSettings
- This is an object that describes a set of behavior for logging a profile.
- path: Same as the path in the ExportBufferArgs above
- append: Same as the append in the ExportBufferArgs above
- captureAllOutput: (boolean, defaults to false) When true, don't log only printable characters, also log non-printable escape characters written to the Terminal.
- captureInput: (boolean, defaults to false) Additionally log input to the Terminal to the file. Input will be formatted as the traditional VT sequences, rather than the full win32-input encoding.
- newFileEveryDay: (boolean, defaults to false) This requires the day to be an element of the path format string. When logging with this setting, opens a new file at midnight and starts writing that one.
New Profile setting: logAutomatically (boolean, default false). When true, terminals with this profile will begin logging automatically.
New Action: toggleLogging().
- Start or stop logging to the configured file. If the terminal is already logging with different settings than in this action, then stop logging regardless (don't just start logging to the new file)
- This action accepts all the same args the profile's logSettings object.
- If any args are provided, use those args. If none are provided, then use the logging settings present in the profile (if there are any).
- If there's not path provided (either in the args to the action or in the profile), prompt the user to pick a file to log to.

Examples

{
    "actions": [
        { "keys": "f1", "command": "exportBuffer" },
        { "keys": "f2", "command": { "action": "exportBuffer", "path": "c:\\logs\\${year}-${month}-${date}\\{profile}.txt" } },

        { "keys": "f3", "command": "toggleLogging" },
        { "keys": "f4", "command": { "action": "toggleLogging", "path": "c:\\logs\\${profile}.log", "append": true } },
    ],
    "profiles": [
        {
            "name": "foo",
            "logging": {
                "path": "c:\\foo.txt",
                "append": true
            },
            "automaticallyLog": false
        },
        {
            "name": "bar",
            "logging": {
                "path": "c:\\logs\\${date}\\bar.txt",
                "append": false
            },
            "automaticallyLog": true
        }
    ]
}

Revisiting our original stories:

Story A: This is already implemented in #11062
Story B: This is the action bound to f1.
Story C: This is the action bound to f2.
Story D: This is the append property in the actions, profile settings.
Story E: An example of this is in the action bound to f2, f4, and in the profile "bar"'s logging settings.
Story F: The profile "bar" is configured to automatically log when opened.
Story G: This is the action bound to f4.

In addition,

When opening the profile "foo", it will not automatically log to a file.
- Pressing f3 will begin logging to c:\foo.txt
- Pressing f4 will begin logging to c:\logs\foo.log

Path formatting

[TODO!]: # TODO!

For discussion: What syntax do we want?

PuTTY uses &Y, &M, &D, &T, &H, &P for year, month, day, time, host and port respectively.
SecureCRT uses:
- %H – hostname
- %S – session name
- %Y – four-digit year
- %M – two-digit month
- %D – two-digit day of the month
- %h – two-digit hour
- %m – two-digit minute
- %s – two-digit seconds
- %t – three-digit milliseconds
- %% – percent (%)
- %envvar% – environment variable (for instance %USERNAME%)

We have some precedent for formatting with ${braces}, a la the iterable command in the Command Palette (e.g ${profile.name}). Additionally, #9287 implements support for environment variables in the Terminal with the ${env:VARIABLE} syntax.

What variables do we want exposed, and how do we want users to be able to format them?

This doc was initially authored assuming we'd go with a ${braces} syntax, like:

${profile} – profile name
${year} – four-digit year
${month} – two-digit month
${day} – two-digit day of the month
${hour} – two-digit hour
${minute} – two-digit minute
${second} – two-digit second
${ms} – three-digit milliseconds
${env:variable} – environment variable (for instance ${env:USERPROFILE}) (inspired by #9287)

Exporting vs Logging

As far as specific implementation details goes, exporting is the easier work to do. #11062 already wires up the TerminalApp to retrieve the buffer contents from the TermControl, so writing them at request is easy.

Logging is harder. We don't want the TermControl telling the TerminalApp layer about every piece of output logged. Especially in the post-#5000 world where that's a cross-process hop. Instead, we'll want the ControlCore / ControlInteractivity to do logging themselves.

Logging Mechanics

When do we log?

[TODO!]: # TODO!

When do we decide to actually log? Take for example typing in a pwsh or bash prompt. Imagine the user types asdf, then hits BkspBksp, such that the prompt is just as. What should the log contain? asdf^h ^h^h ^h^[1]? as?

My worry with logging the backspaces is that conpty is sometimes a bit noisier than it needs to be with using ^H as a cursor positioning sequence. Should we only log lines when the cursor newlines or otherwise moves from the line it is currently on?

I'll need to look at what PuTTY emits for the "Printable output" option.

What happens when we start logging?

If the user has a terminal that did not start with logging enabled, but then started logging with toggleLogging, what should we log? All future output? Or should we log the current buffer contents as well?

I'm inclined to lean towards simply "all future output", and ignore any current buffer content. If the user rally wants to log the current buffer contents and start logging, they can use a multipleActions action (#11045) to exportBuffer to a file, then toggleLogging to that same file with "append":true.

Potential Issues

Compatibility	Since this functionality is entirely new, nothing here should negatively affect existing functionality.
Performance, Power, and Efficiency	When logging, it's expected there will be a measurable performance hit. We can try to mitigate this by only writing to the file on a background thread, separate from the connection or rendering thread. Since auto-logging will only take place in the content process, we're not worried about the file writing occuring on the UI thread.

Also frequently requested is the ability to log timestamps of when commands are executed. I don't think that this is a valuable feature for the Terminal to implement ourselves. Windows Terminal is fundamentally just a terminal emulator, it doesn't really know what's going on behind the scenes with whatever client application (cmd, powershell, bash, vim) that is connected to it. WT doesn't know when the user is typing in commands to the shell, or if the user is just typing in text in emacs or something. There's no way for the terminal to know that. It's typically the client application's responsibility to save it's own command history. bash and powershell both do a pretty good job of saving this to another file to restore across sessions, while cmd.exe doesn't.

Windows is a messy world and this model gets a little tricky here. cmd.exe isn't actually managing it's own command history at all. conhost is doing that work on behalf of the client applications. Some long time ago someone thought it would be a good idea to have the readline functionality baked directly into the console host. Whether that was a good idea or not remains to be seen - it's certainly made things like python.exe's REPL easier to implement, since they don't need to maintain their own history buffer, but it makes it hard to de-tangle behavior like this from the console itself.

I'm not sure how it would be possible to add a keybinding to the Windows Terminal that would be able to save the console's command history. Especially considering the Terminal might not be connected to a console host session at all. If the Windows Terminal were directly running a wsl instance (something that's not possible today, but something we've considered adding in the future), then there wouldn't be a conhost in the process tree at all, and now requesting the command history from the console wouldn't work mysteriously.

Furthermore, shells can always be configured to emit timestamps in their prompts themselves. Since the Terminal has no knowledge of when a command is actually entered, but the shell does, it makes the most sense to configure the user's shell to emit that information. The Terminal will then dutifully log that output along with everything else.

Implementation Plan

Below is a rough outline of how I'd go about implementing these features. Each lop-level checkbox could be its own PR, following from #11062.