bastianplsfix

← Deno

The console

This entry expects you to code along. Every claim in it is observable, and the observations are the point. Open a fresh terminal at the root of the examples project, so the prompt sits in examples rather than one of its subfolders. Nothing beyond that setup is assumed: where a concept from outside JavaScript is needed, it is explained on the spot.

a report that ruins itself

Create programs/printing.ts with this small report:

console.log("apples: 6");
console.log("bread: 4");
console.log("report complete");

First, the ingredients. console.log is a function you call with a value, and it prints that value to the terminal followed by a newline, so the next print starts on its own line. Three calls, three lines. Run it:

deno run programs/printing.ts
apples: 6
bread: 4
report complete

Everything looks fine. Before going on, read the three lines again: one of them is different in kind from the other two. Which one, and what would you call the difference?

Whatever you called it, whether data versus status or the report versus a remark about the report, the program does not honor it. Seeing that takes one piece of shell knowledge. The terminal you are typing into is run by a program called a shell, and the shell can do more than start programs. Its > operator is called redirection: it sends a program's printed output into a file instead of onto the screen. Redirection matters because you are rarely the only consumer of a program's output. Sooner or later the thing reading it is a file or another program, not you. Run the report the way a consumer would:

deno run programs/printing.ts > out.txt

The terminal stays silent. Open out.txt:

apples: 6
bread: 4
report complete

report complete is inside the data file, and anything that parses out.txt now receives it as a third grocery item. The reverse failure is quieter and worse: when a real error message travels the same channel as the data, silencing one silences the other.

The distinction you articulated a moment ago exists in the machinery. When you run a program, the operating system starts a process: a running instance of the program, with its own memory and its own connections to the outside world. Among those connections, every process is given two output channels, called streams. A stream is nothing exotic; it is text flowing from one place to another, in order. The first stream is standard output, stdout for short, and it is for the program's real output, the data. The second is standard error, stderr, and it is for diagnostics: progress, warnings, errors, anything addressed to the human rather than to the next program. console.log writes to stdout. Its twin console.error takes the same arguments and prints the same way, but writes to stderr. The > redirect captures only stdout, which is why all three lines landed in the file: all three went through console.log.

Why two channels rather than one? The design is roughly twenty years older than JavaScript. In the early 1970s, Unix made it easy to chain programs together, one program's output feeding the next program's input, and that immediately exposed the problem you just reproduced: error messages traveled with the data. In the often-told version of the story, the breaking point at Bell Labs was a phototypesetter. A program's output was being typeset, so when something went wrong, the complaints were typeset too, onto expensive photographic film, instead of reaching the person who could fix them. The remedy was a second channel reserved for talking to the human, and every operating system and programming language since has kept the pair. console.log and console.error are simply JavaScript's names for writing to one or the other.

So the question to ask of every line a program prints is: is this the output, or is this me talking about the output?

Now fix the report. report complete is a remark about the report, so it moves to the other stream, and nothing else changes:

console.log("apples: 6");
console.log("bread: 4");
console.error("report complete");

Run the redirect again:

deno run programs/printing.ts > out.txt
report complete

Success has two parts: the terminal prints report complete, because stderr was not redirected, and out.txt now contains only the two report lines:

apples: 6
bread: 4

Then run the opposite experiments. The shell numbers the streams, stdout as 1 and stderr as 2, and > is shorthand for 1>. So 2> redirects stderr instead, and /dev/null is a destination the operating system provides whose only job is to discard whatever is written to it:

deno run programs/printing.ts 2> errors.txt
deno run programs/printing.ts 2>/dev/null
apples: 6
bread: 4

Both runs print the same two lines: the first sends report complete into errors.txt, and the second discards it. Passing all three checks means your program's data and its diagnostics can be consumed independently, which is the entire reason the two streams exist.

One more pass before moving on. Three lines from programs you will eventually write: a progress percentage during a long download, the CSV rows the program exists to produce, and a warning about one malformed row it skipped. Decide which method prints each, all three, before reading on. The progress and the warning are you talking about the output, so console.error; only the CSV rows are the output. If you hesitated on the warning, apply the test: a consumer piping the CSV into another tool must not find a warning sentence in row 3,000.

The model so far: a program prints on two streams. console.log is for the output itself; console.error is for commentary about it; the consumer, not the program, decides which stream to keep.

the object that prints as [object Object]

The report above printed labeled values by baking the label into the string: "apples: 6". Real programs hold values in variables, so the natural next move is to glue a label onto a variable with +. Create programs/rendering.ts and try both spellings side by side:

const cart = { apples: 6, bread: 4 };

console.log("cart: " + cart);
console.log("cart:", cart);
console.log(new Map([["a", 1]]));
console.log("oak", 123, true, null, undefined);
cart: [object Object]
cart: { apples: 6, bread: 4 }
Map(1) { "a" => 1 }
oak 123 true null undefined

The first line is the failure. When + has a string on one side, JavaScript converts the other side to a string and joins the two, and for plain objects the default conversion does not look inside the object at all: it produces the fixed text [object Object] no matter what the object contains. The second line is the fix. Passed as its own argument, the value is rendered structurally: the console walks into the object and prints its actual shape. That holds for any value, including ones whose string conversion is useless, which is what the Map line shows: a Map rendered with its size and contents without being asked.

The last line is the general behavior: console.log takes any number of values, of any type, renders each, joins the renderings with single spaces, and ends with a newline. Called with no arguments, it prints just the newline. While you are here, make the labeling a habit: a bare 4 in a long run of output is a riddle by tomorrow, and console.log("score:", score) reads as well in the terminal as it does in the code.

One boundary to file away: none of this is guaranteed by the JavaScript language, whose specification does not define console at all. Each host, meaning each program that runs your JavaScript, provides its own version: Deno, Node, and every browser each carry one, which is why the same call can render differently in each. There is a standard, maintained by the WHATWG, the group behind several of the web's living standards, and Deno follows it while keeping some Node extensions for compatibility. Treat the rendering as a convenience for human eyes. When another program will read your output, print a format you control, such as JSON, rather than a rendering you don't.

The model so far: hand console.log the values themselves, labeled by a leading string, and it renders each one structurally, a host-provided convenience for human eyes rather than a format for machines.

the score that changed on the way to the screen

Create programs/formatting.ts:

const name = "ada";
const score = 4.7;

console.log("%s scored %d", name, score);

Run it:

deno run programs/formatting.ts
ada scored 4

The score is 4.7. Nothing errored, nothing warned, and the program printed a wrong number. Where did the decimal go?

When the first argument to console.log is a string containing directives, the %-prefixed markers listed below, the call changes meaning: the first argument becomes a pattern, and the directives consume the arguments after it, each imposing its own conversion. %d inserts a value as an integer, and that conversion truncates: 4.7 does not round up to 5, it is cut to 4. The score never changed; the call asked for a rendering that drops decimals.

The full set, to recognize in code you read rather than to reach for:

DirectiveEffect
%sinsert as a string
%d, %iinsert as an integer, truncating
%finsert as a number, keeping decimals
%o, %Oinsert a structural rendering of an object
%capply CSS styling to what follows
%%a literal %

A few behaviors you may meet in the wild, all observable in one file. Create programs/directives.ts:

console.log("%f", 4.7);
console.log("%j", { a: 1 });
console.log("%q", "x");
console.log("%s scored", "ada", 4.7, true);
4.7
{"a":1}
%q x
ada scored 4.7 true

%f keeps the decimal. %j inserts JSON, a Node extension Deno honors that is absent from the WHATWG standard, so it will not travel to a browser. An unrecognized directive passes through untouched, and arguments past the last directive are appended as if passed plainly.

Directives are a survival from an era before template literals, the backtick-quoted strings with ${...} holes in them that the strings page covers. Template literals do the same work more legibly, with no per-directive conversion rule to remember. Two reasons remain to reach for a directive: %c styling, which has no other spelling, and %s on a value whose own string conversion you would rather not trigger. Otherwise, prefer interpolation. Fix the program:

const name = "ada";
const score = 4.7;

console.log(`${name} scored ${score}`);
ada scored 4.7

%f would also have preserved the decimal; the template literal wins because there is no conversion rule to remember at all.

The model so far: a first argument with % directives is a pattern, and each directive imposes its own conversion on the value it consumes. Template literals say the same thing without the hidden conversions.

the field that was definitely there

Every debugging session that ends in "but the field is definitely there, I can see the object" has met what comes next. Create programs/truncation.ts:

const deep = { a: { b: { c: { d: { e: { f: 1 } } } } } };

console.log(deep);

The value plainly contains f: 1. Run the program and find the place where the rendering stops:

deno run programs/truncation.ts
{
  a: {
    b: { c: { d: { e: [Object] } } }
  }
}

That [Object] is not an empty object and not an error. It is the console declining to go further. The console is a debugging aid, and it optimizes for a readable line, not a faithful one: objects nested more than four levels deep get abbreviated, silently.

Depth is one of two ways it shortens. The other is length: iterables, meaning arrays and any other value you can walk through element by element, are cut off past 100 entries. Create programs/length.ts with a 120-element array, printed plainly and printed through the function the console formats with, Deno.inspect, exposed for direct use:

const long = Array.from({ length: 120 }, (_, i) => i);

console.log(long);
console.log(Deno.inspect(long, { iterableLimit: 200 }));
[
   0,  1,  2,  3,  4,  5,  6,  7,  8,  9, 10, 11,
  12, 13, 14, 15, 16, 17, 18, 19, 20, 21, 22, 23,
  24, 25, 26, 27, 28, 29, 30, 31, 32, 33, 34, 35,
  36, 37, 38, 39, 40, 41, 42, 43, 44, 45, 46, 47,
  48, 49, 50, 51, 52, 53, 54, 55, 56, 57, 58, 59,
  60, 61, 62, 63, 64, 65, 66, 67, 68, 69, 70, 71,
  72, 73, 74, 75, 76, 77, 78, 79, 80, 81, 82, 83,
  84, 85, 86, 87, 88, 89, 90, 91, 92, 93, 94, 95,
  96, 97, 98, 99,
  ... 20 more items
]
[
    0,   1,   2,   3,   4,   5,   6,   7,   8,   9,  10,  11,
   12,  13,  14,  15,  16,  17,  18,  19,  20,  21,  22,  23,
   24,  25,  26,  27,  28,  29,  30,  31,  32,  33,  34,  35,
   36,  37,  38,  39,  40,  41,  42,  43,  44,  45,  46,  47,
   48,  49,  50,  51,  52,  53,  54,  55,  56,  57,  58,  59,
   60,  61,  62,  63,  64,  65,  66,  67,  68,  69,  70,  71,
   72,  73,  74,  75,  76,  77,  78,  79,  80,  81,  82,  83,
   84,  85,  86,  87,  88,  89,  90,  91,  92,  93,  94,  95,
   96,  97,  98,  99, 100, 101, 102, 103, 104, 105, 106, 107,
  108, 109, 110, 111, 112, 113, 114, 115, 116, 117, 118, 119
]

... 20 more items in the first rendering, all 120 in the second. Deno.inspect also takes depth, colors, compact, and sorted. Reach for it whenever a console.log looks like it is hiding something. It is Deno-specific, so it belongs in scripts and debugging rather than in portable library code.

Now use the depth option: extend programs/truncation.ts to print the same deep value a second time with f: 1 visible, without changing the value itself:

const deep = { a: { b: { c: { d: { e: { f: 1 } } } } } };

console.log(deep);
console.log(Deno.inspect(deep, { depth: 10 }));
{
  a: {
    b: { c: { d: { e: [Object] } } }
  }
}
{
  a: {
    b: {
      c: { d: { e: { f: 1 } } }
    }
  }
}

The second rendering reaches f: 1. Lower the depth one step at a time, running after every edit, until [Object] returns: that boundary is now something you found rather than something you memorized. One more question, reaching back a section: suppose that inspection line is temporary debugging in a program whose stdout is being piped into a file. Which method should print it? If the answer is not immediate, rerun the out.txt experiment from the first section. An inspection dump is you talking about the output, so it belongs on stderr.

The model so far: the console's rendering is a summary, not the value. It cuts depth past four levels and iterables past 100 entries, both silently, and Deno.inspect with explicit options is how you see past the cut.

JSON.stringify, the lens for programs

Twice now this entry has said: when another program will read your output, print a format you control. Here is where that promise gets kept. Think back to the report from the first section. A program consuming out.txt has to split apples: 6 on a colon and hope nobody ever renames the item to red: delicious apples. The rendering was designed for your eyes, and a parser can only guess at its rules.

Printing for a program means serializing: turning the value into text with rules firm enough that the value can be rebuilt from it later. The standard text format for that is JSON, which has its own entry on the JSON page, and it comes as a built-in pair: JSON.stringify turns a value into JSON text, and JSON.parse turns that text back into a value. Whatever your program prints with the first, a consuming program can reconstruct with the second, and nobody splits strings on a colon and hopes.

Serializing has a useful side effect for debugging, too. Add a third line to programs/truncation.ts and run the file again:

const deep = { a: { b: { c: { d: { e: { f: 1 } } } } } };

console.log(deep);
console.log(Deno.inspect(deep, { depth: 10 }));
console.log(JSON.stringify(deep));
{
  a: {
    b: { c: { d: { e: [Object] } } }
  }
}
{
  a: {
    b: {
      c: { d: { e: { f: 1 } } }
    }
  }
}
{"a":{"b":{"c":{"d":{"e":{"f":1}}}}}}

One dense line, reaching f: 1 with no depth option in sight. A value that cannot be rebuilt from its text is not serialized, so JSON.stringify never summarizes: it descends to any depth or it fails, and that makes it a second lens on structures the console shortens.

That completeness is paid for with real losses, and the quickest way to respect them is to watch them happen. Create programs/serializing.ts:

console.log(JSON.stringify({ apples: 6, bread: 4 }, null, 2));
console.log(JSON.stringify(new Map([["a", 1]])));
console.log(JSON.stringify({ keep: 1, gone: undefined, alsoGone: () => 1 }));

const loop: { self?: unknown } = {};
loop.self = loop;

console.log(loop);
console.log(JSON.stringify(loop));
{
  "apples": 6,
  "bread": 4
}
{}
{"keep":1}
<ref *1> { self: [Circular *1] }
error: Uncaught (in promise) TypeError: Converting circular structure to JSON
    --> starting at object with constructor 'Object'
    --- property 'self' closes the circle
console.log(JSON.stringify(loop));
                 ^
    at JSON.stringify (<anonymous>)
    at file:///programs/serializing.ts:9:18

The first block is the indented form: the third argument is the indent, the second is a replacer you will rarely need, and JSON.stringify(value, null, 2) is worth committing to muscle memory. Then the losses, one per line. A Map with a visible entry comes out as {}, not an error, not a warning, because JSON has no notation for a Map, and a Set flattens the same way. Properties holding undefined or a function disappear from the output. A bigint throws, with "Do not know how to serialize a BigInt". And a cycle, an object that contains itself somewhere down the chain, is the last two lines: the console prints <ref *1> { self: [Circular *1] } and keeps going, and JSON.stringify throws a TypeError that names the property that closes the circle.

So you hold two lenses, and they fail in opposite directions. Check that you can choose between them, deciding both before reading on: which lens shows a config object eight levels deep whole, and which shows a cache built on Map? The config is safe in either lens, and JSON.stringify does not even need a depth option. The cache is a job for the console alone: JSON flattens every Map to {} without comment, which is this lens's own quiet lie.

The model so far: JSON.stringify prints a format programs can parse back, and because it never summarizes, it doubles as the lens that shows deep structures whole. It pays by refusing or dropping what JSON cannot say, so the console renders anything but shortens, and JSON is complete but narrow. Neither is a serializer for arbitrary values.

the model to carry

A program prints on two streams: console.log for the output, console.error for you talking about the output, and every line is one or the other. Hand the console values, not strings made from them, with a leading label, and it renders them structurally, a host convenience for human eyes that quietly truncates depth and length. A suspiciously shallow rendering means Deno.inspect with a larger depth, or JSON.stringify(value, null, 2) when nothing in the value is a Map, a Set, or a bigint. And when another program will read your output, do not print for humans at all: emit a format you control and can test, which is what the understanding testing page is for.

Run one final check from the project root:

deno fmt --check programs/printing.ts programs/rendering.ts programs/formatting.ts programs/directives.ts programs/truncation.ts programs/length.ts programs/serializing.ts
Checked 7 files

If a file stopped matching along the way, the versions shown in each section above are the answers.