Realtime Logging: Streaming Your App's Logs to Wherever You Keep Them

Almost every example in this series has reported what it found by writing it into the response body. The few that printed anything used println!, which goes straight to the terminal running fastly compute serve, through wasi:cli/stdout at the ABI level, as the very first post established.

Both work on a laptop, and neither helps once the service is deployed. A response body goes to whoever sent the request, not to you, and nobody is watching a terminal at a POP. What a running service needs is a way to record what happened somewhere you can read it later. That's realtime logging, and in compute.wit it's one of the smallest interfaces in the file.

What realtime logging does

Logging endpoints belong to the service, not the program. Each one has a name and points at a destination, and Fastly's developer guide to third-party logging (opens in a new window) keeps the list of what's supported. As of this writing, the guide lists generic endpoints for running your own log receiver (HTTPS, Syslog, SFTP, Kafka, Log Shuttle, and OpenStack) and dedicated integrations for third-party services, among them Amazon S3, Datadog, Google BigQuery, Honeycomb, New Relic, Splunk, and Sumo Logic.

Your program opens an endpoint by name and writes events to it. From there, Fastly's guide to real-time log streaming (opens in a new window) says, log records go to a log aggregator, which streams them "in near-real-time to the logging endpoint you configure."

What goes into each event is up to you: it's the message your program writes. The developer guide warns that providers "may vary substantially in the constraints they impose on log messages," and gives its own examples: by its account, Datadog and Google BigQuery both require JSON, with different requirements for date and time values, while Amazon S3 accepts nearly anything. Fastly's guide to logging for Compute (opens in a new window) builds a JSON object by hand for exactly that reason. The destination decides what it accepts, and your code writes that.

Setting up an endpoint

On a real service, you create an endpoint for a provider, in the control panel or with the CLI, and the name you give it is the name your program opens. An HTTPS endpoint called my_endpoint, for example:

fastly logging https create --name=my_endpoint --url=https://logs.example.com/ --version=latest --autoclone

An HTTPS endpoint has one more requirement: you have to prove you control the domain in its URL (opens in a new window). Fastly sends a challenge request to /.well-known/fastly/logging/challenge on that host, and the response must include the SHA-256 hash of your service ID, as a hex string on its own line. The developer guide has the details.

Then activate the new version. fastly.toml can also record that the package expects an endpoint by that name, under [setup.log_endpoints]:

[setup]

  [setup.log_endpoints]

    [setup.log_endpoints.my_endpoint]
      provider = "HTTPS"

That declares the requirement rather than creating the endpoint. The fastly.toml reference describes provider as "used as part of a generic message to the user indicating the type of provider needed."

Locally there's nothing to configure, and the example's fastly.toml has no [local_server] section for logging at all. Viceroy prints every event it receives to the terminal it's running in, whatever name it was written to.

println! output takes a different route. On a real service it doesn't go to a logging endpoint at all. The Compute logging guide points to log tailing, fastly log-tail (opens in a new window), as the way to see stdout and stderr from a deployed service. The first time you run it against a service, it turns on managed logging for that service. Against this post's example, the println! line took a few minutes to start arriving, so if nothing shows up at first, keep the tail running.

The whole interface

This is the whole thing, not an excerpt:

interface log {
  use types.{error, open-error};

  /// A logging endpoint.
  resource endpoint {
    /// Tries to get an endpoint by name.
    ///
    /// Currently, the conditions on an endpoint name are:
    /// - It must not be empty.
    /// - It must not contain newlines (`\n`) or colons (`:`).
    /// - It must not be `stdout` or `stderr`, which are reserved for debugging.
    ///
    /// Names are case sensitive. Calling `get-endpoint` with a name that doesn't correspond to any
    /// logging endpoint available in your service will still return a usable endpoint, and writes
    /// to that endpoint will succeed. Refer to your service dashboard to diagnose missing log
    /// events.
    open: static func(name: string) -> result<endpoint, open-error>;

    /// Writes a data to the given endpoint.
    ///
    /// Each call to `write` with a non-empty message produces a single log event.
    write: func(msg: list<u8>);
  }
}

That's twenty-four lines, with one resource and two functions. open is the static func shape you've seen on every store since Config Store, returning the same shared open-error. write sends one event, and list<u8> is the right type for it, since the message is whatever format your destination wants.

What your program can't see

You'll need to watch out for two things about this interface once the service is live, because both are invisible from inside the program.

The first is in write's signature:

write: func(msg: list<u8>);

There's no result here. Every other function in this ABI that sends data somewhere returns one. http-body.write returns the number of bytes it actually took, because it might take fewer than you gave it. cache.transaction-insert returns a body or an error. Even purge-surrogate-key, which is fire-and-forget as far as your request is concerned, comes back with result<_, error>. This one function returns nothing at all.

The WIT doesn't say why, but the delivery model suggests a reason. The streaming guide says delivery "operates on a best-effort basis and is not guaranteed," and it happens after the call, on the platform's schedule rather than yours. So there's no point during the call when "did that get delivered" has an answer, and never anything truthful for the function to return. An ok would promise more than best-effort, and an error couldn't report a meaningful failure, because those would only happen later.

The second is in open's doc comment:

Calling get-endpoint with a name that doesn't correspond to any logging endpoint available in your service will still return a usable endpoint, and writes to that endpoint will succeed.

Now, that's pretty weird. That's right, it says that a name matching nothing in your service configuration does not raise an error. You still get an endpoint resource, your writes succeed, and the events just go ... nowhere. The doc comment's advice for noticing is to "refer to your service dashboard," which is to say: out of band, later, by a human.

So open's result is narrower than it looks: by the doc comment's account it rejects malformed names, not wrong ones, and the example below finds that Viceroy and a real service don't agree on which malformed names those are. Put the two together and a mistyped endpoint name looks exactly like a working one. No call you make can reveal the difference, so the place to check is the destination: if the events aren't arriving there, nothing inside the program will tell you why.

Reading it directly

The doc comment puts three conditions on a name: it must not be empty, it must not contain a newline or a colon, and it must not be stdout or stderr. That's a precise enough list to test, so the example tests it, along with a name you'd configure on a real service and one that isn't configured anywhere.

Full working code: full example on GitHub (opens in a new window).

imports and the response helper (15 lines)
mod bindings;

use bindings::{
    exports::fastly::compute::http_incoming,
    fastly::compute::{http_body, http_resp, log},
};

fn send(lines: String) -> Result<(), ()> {
    let response = http_resp::Response::new().map_err(|_| ())?;
    response.insert_header("content-type", b"text/plain").map_err(|_| ())?;
    let out_body = http_body::new().map_err(|_| ())?;
    http_body::write(&out_body, lines.as_bytes()).map_err(|_| ())?;
    http_resp::send_downstream(response, out_body).map_err(|_| ())?;
    Ok(())
}

/// Reports what `open` did with a given name, and writes to the endpoint if
/// it produced one. `write` has no return value to report.
fn probe(lines: &mut String, label: &str, name: &str) {
    match log::Endpoint::open(name) {
        Ok(endpoint) => {
            endpoint.write(format!("hello from {label}").as_bytes());
            lines.push_str(&format!("{label:<22} open: Ok, wrote 1 event\n"));
        }
        Err(e) => lines.push_str(&format!("{label:<22} open: Err({e:?})\n")),
    }
}

struct RealtimeLogging;

impl http_incoming::Guest for RealtimeLogging {
    fn handle(_request: http_incoming::Request, _request_body: http_body::Body) -> Result<(), ()> {
        let mut lines = String::new();

        // A name you'd configure as a logging endpoint on a real service.
        // Locally, nothing configures it.
        probe(&mut lines, "\"my_endpoint\"", "my_endpoint");

        // A name that is not configured anywhere. The doc comment says this
        // still returns a usable endpoint, and that writes to it succeed.
        probe(&mut lines, "\"not_configured\"", "not_configured");

        // The three conditions the doc comment puts on a name.
        probe(&mut lines, "\"\" (empty)", "");
        probe(&mut lines, "\"has:colon\"", "has:colon");
        probe(&mut lines, "\"has\\nnewline\"", "has\nnewline");

        // Reserved for debugging, per the same doc comment.
        probe(&mut lines, "\"stdout\"", "stdout");
        probe(&mut lines, "\"stderr\"", "stderr");

        // For contrast: the WASI path println! takes.
        println!("this line went to wasi:cli/stdout, not to a log endpoint");

        send(lines)
    }
}

bindings::export!(RealtimeLogging with_types_in bindings);

The response, against Viceroy:

"my_endpoint"          open: Ok, wrote 1 event
"not_configured"       open: Ok, wrote 1 event
"" (empty)             open: Ok, wrote 1 event
"has:colon"            open: Ok, wrote 1 event
"has\nnewline"         open: Ok, wrote 1 event
"stdout"               open: Err(OpenError { code: 2, name: "reserved", message: "The given name is a reserved name that may not be opened." })
"stderr"               open: Err(OpenError { code: 2, name: "reserved", message: "The given name is a reserved name that may not be opened." })

Locally, one of the three conditions is enforced. stdout and stderr come back as open-error.reserved (one variant Config Store enumerated and had no reason to trigger). The other two are stated and not checked: an empty name opens, a name containing a colon opens, and a name containing a newline opens, and all three accept writes.

That's where a local-only result usually needs a caveat, so this one got deployed to a real Compute service instead. It's the same code, with no logging endpoints configured:

"my_endpoint"          open: Ok, wrote 1 event
"not_configured"       open: Ok, wrote 1 event
"" (empty)             open: Ok, wrote 1 event
"has:colon"            open: Err(OpenError { code: 0, name: "invalid-syntax", message: "The given name of the entity to open was invalid." })
"has\nnewline"         open: Err(OpenError { code: 0, name: "invalid-syntax", message: "The given name of the entity to open was invalid." })
"stdout"               open: Err(OpenError { code: 2, name: "reserved", message: "The given name is a reserved name that may not be opened." })
"stderr"               open: Err(OpenError { code: 2, name: "reserved", message: "The given name is a reserved name that may not be opened." })

A real service refuses the colon and the newline, as open-error.invalid-syntax, and the reserved names as before. So a name that opens fine under Viceroy can fail after you deploy. That's worth knowing if any part of an endpoint name ever comes from data rather than a constant. The empty name, meanwhile, opened on both hosts, so the first condition isn't enforced by either of them, at least as of this writing.

my_endpoint and not_configured behaved identically on both hosts too. Neither name exists on the test service, and, just as the doc comment promises, open still hands back an endpoint and write still succeeds. Only the destination would ever tell you the difference.

Beyond the WIT

The two forbidden characters are the interesting part, because the doc comment doesn't say why they're forbidden. The terminal suggests a reason.

Here is what Viceroy printed while serving that request:

my_endpoint :: hello from "my_endpoint"
not_configured :: hello from "not_configured"
 :: hello from "" (empty)
has:colon :: hello from "has:colon"
has
newline :: hello from "has\nnewline"
this line went to wasi:cli/stdout, not to a log endpoint

Viceroy frames each event as name :: message, one per line. That's the local server's format, not something the ABI promises about a real service, where events go out to whatever endpoint you configured. But it shows how the rule could matter. A colon and a newline are exactly the characters that break a line-oriented name-and-message format. A colon blurs where the name ends. A newline splits one event into two, and the second half arrives looking exactly like an event from an endpoint called newline. The doc comment never gives that as the reason. A real service does refuse exactly those two characters while Viceroy accepts both, which makes the explanation more likely without making it the documented one.

The last line of that output is the other thing to notice. It's the println!, arriving in the same stream as the log events, and the only difference is the missing name and separator. The doc comment's reason for reserving stdout and stderr is that they're "reserved for debugging," meaning that channel. Seeing both in one terminal shows what the reservation protects: an endpoint allowed to call itself stdout would be hard to tell apart from real debugging output. They're also the only names Viceroy refuses.

That's the shape of the whole interface, and it's worth naming for anyone binding it. This is a text protocol with a WIT type in front of it. The list<u8> is bytes because a message is arbitrary, but the name is a string that can end up inside a text format the type system knows nothing about, with a rule about it written in prose and enforced differently by the two hosts you'll run it on. A binding that takes an endpoint name as a plain string passes that straight through to its callers, who find out about a bad name only after they deploy. One that validates the name at construction, or offers a typed handle you can only obtain through a checked constructor, spends a few lines to get the same answer under Viceroy as in production, and makes the whole class of problem unreachable.

Next: compute.wit has one interface with a function for asking whether the POP you're running on is a shield, and another for building a backend that points at one. We'll find out what shielding looks like from inside guest code.