Safe from the Losing Fight

Like most services these days, my Vapor side project needs to send welcome emails when a user signs up for the service. While I could write my own SMTP client, it would still require a lot of DNS setup to make sure those emails made it through various spam countermeasures. Given this is a side project, and sending email is a minor component of it, that didn’t seem worthwhile to me. So I decided to use a 3rd party service who would take care of all of that.

I chose Mailgun for a couple of reasons:

1. I’m hosting my side project on Heroku, and they provide a convenient Mailgun add on that I can provision.
2. Mailgun offers a free tier, appropriate for my side project
3. There’s already a Swift package for Mailgun’s API.

The Swift package for Mailgun got me most of the way there. However, I still needed a bit of infrastructure to render the emails, and then to validate the emails were correctly sent in my integration tests.

In this post I’m going to cover how I went about generating the email content, sending the email to Mailgun, and finally how I ensured I could test it all. I’m not going to cover how to set up Mailgun and all the DNS stuff because that’s very app specific, and is documented in Mailgun’s docs already.

Example use

I find it helpful when building a subsystem to sketch out what the use site will look like. It helps me determine if I’m building something that will meet my needs, and gives me a concrete target to build toward. With that in mind, I thought the ideal for my project was to define an email template for each kind of email I wanted to send, have a method that could render that down to a final email to send, then send it via an abstract email delivery service. The email body allows both text and html, and the body template was defined in Leaf.

Here’s how that looked in code:

struct WelcomeData: Encodable {
    let verifyLink: String

    init(user: User) {
        self.verifyLink = "myapp://verify/\(user.verifyToken)"
    }
}
...
let template = EmailTemplate(from: "donotreply@myapp.com",
                             to: email,
                             subject: "Welcome to MyApp!",
                             bodyTemplate: "WelcomeEmail")
let welcomeData = WelcomeData(user: user)
return template.render(welcomeData, on: container).flatMap { message -> Future<Void> in
    let deliveryService = try container.make(EmailDeliveryService.self)
    return deliveryService.send(message, on: container)
}

The first step is to create the EmailTemplate for the email I want to send and render it. The from, to, and subject properties are Strings that will be passed through unchanged to the final email. The bodyTemplate is the base name for the Leaf templates that will be rendered in the render() method. WelcomeData is the Leaf context for the templates; it defines anything that the the Leaf template will need. I like to think of it as a view model. It takes a model object and transforms it into values that the view (i.e. the Leaf template) needs. In this example, the WelcomeEmail template needs an email verification link, so WelcomeData constructs that based on a token assumed to be on the User model. To render the EmailTemplate into something that can be sent, render() is called, passing in WelcomeData.

The second step is to send the resulting EmailMessage. The dependency injection framework is asked to produce a EmailDeliveryService object, which can send an EmailMessage. EmailDeliveryService is a protocol, meaning it can be swapped out later, without the client code knowing or caring. This enables testing fakes to be injected during tests, as well as making it possible to move to a new email service should I ever decide to do that.

That covers the Swift code for creating and sending the email. I still need to define the Leaf templates though. I want to send both plain text and HTML MIME parts in my email, so regardless of the user’s email app they’ll see something reasonable. Since the email body template parts are Leaf templates, I put them in the standard location: Resources/Views. I also follow a naming convention so EmailTemplate.render() can find them at runtime.

Here’s the contents of WelcomeEmail.html.leaf:

<html>
<head></head>
<body>
<p>Hello!</p>

<p>Welcome to MyApp!</p>

<p><a href="#(verifyLink)">Verify your email address</a></p>

<p>The MyApp Team.</p>
</body>
</html>

And the contents of WelcomeEmail.text.leaf:

Hello!

Welcome to MyApp!

Verify your email address by clicking on this link: #(verifyLink)

The MyApp Team.

Both templates represent the same email, but the content changes based on the format they’re being rendered into. The #(verifyLink) placeholder is filled in with value in WelcomeData.verifyLink.

Now that I’ve defined my target API, I can start building the implementation.

Rendering email with Leaf

First I need to define what an email message is, because it is the type everything else is dependent on. The EmailTemplate needs to render to it, and EmailDeliveryService needs to send it. I decided to define my own types for this because it reduces coupling on a specific service, plus it more accurately represents what my app thinks an email is. Also, the necessary types are pretty simple, so I did’t think they’d increase my maintenance burden any.

Here’s my definition:

struct EmailBody {
    let text: String
    let html: String
}

struct EmailMessage {
    let from: String
    let to: String
    let subject: String
    let body: EmailBody
}

My app’s idea of an email is simple. It has a from, to, subject, and body fields. The only thing that might look out of the ordinary is the the body has two parts: HTML and plain text. My app doesn’t care about attachments or other features, so they don’t show up here.

With email defined, I could create the EmailTemplate which takes care of rendering Leaf templates down to a EmailMessage. I started by defining the properties of the EmailTemplate:

import Vapor
import Leaf
import TemplateKit

struct EmailTemplate {
    private let from: String
    private let to: String
    private let subject: String
    private let bodyTemplate: String

    init(from: String, to: String, subject: String, bodyTemplate: String) {
        self.from = from
        self.to = to
        self.subject = subject
        self.bodyTemplate = bodyTemplate
    }
    ...
}

The template is the same as the EmailMessage with the exception of bodyTemplate, which is the base name of the Leaf templates for the email body. Most of the work of EmailTemplate is to convert the bodyTemplate into a EmailBody. The top level render method looks like:

struct EmailTemplate {
    ...
    private static let htmlExtension = ".html"
    private static let textExtension = ".text"

    func render<E>(_ context: E, on container: Container) -> Future<EmailMessage> where E: Encodable {
        let htmlRender = render(bodyTemplate + EmailTemplate.htmlExtension, context, on: container)
        let textRender = render(bodyTemplate + EmailTemplate.textExtension, context, on: container)
        return htmlRender.and(textRender)
            .map { EmailBody(text: $1, html: $0) }
            .map { EmailMessage(from: self.from, to: self.to, subject: self.subject, body: $0) }
    }
    ...
}

The render() method takes the Leaf template context and a dependency injection container, and returns the promise of an EmailMessage. The implementation relies on a helper render() method that renders one Leaf template at a time. This top level render() calls it twice: once for the plain text template, and once for the html template. It uses the and operator to let the template renders run concurrently if possible, then combines the results into an EmailBody, before a final map that mixes in the from, to, and subject fields.

The helper render() method is similarly straight forward:

enum EmailError: Error {
    case invalidStringEncoding
    case emailProviderNotConfigured
}
...
struct EmailTemplate {
    ...
    private func render<E>(_ name: String, _ context: E, on container: Container) -> Future<String> where E: Encodable {
        do {
            let leaf = try container.make(LeafRenderer.self)
            return leaf.render(name, context).map { view in
                guard let str = String(data: view.data, encoding: .utf8) else {
                    throw EmailError.invalidStringEncoding
                }
                return str
            }
        } catch let error {
            return container.future(error: error)
        }
    }
}

The helper method here takes the full Leaf template name, its context, a dependency injection container and returns a promise of String, which is the fully rendered body. To achieve this, it creates a LeafRenderer and asks it to render the template. This results in view data, which it decodes into a String and returns. If any error is thrown, it’ll convert it into a rejected promise for convenience.

The email template rendering is fairly simple, but creating the EmailTemplate type reduces the boilerplate code needed for sending an email.

Sending email

I now have a fully rendered email message, and I need to send it. As I mentioned up top, I’m used a 3rd party Swift package to actually talk to Mailgun’s API. However, I wanted an easy way to inject testing fakes, and the ability to swap out email services later if necessary. So I’m first going to show how I integrated the Swift Mailgun package, then how I abstracted it with a generic interface that can be faked.

Since it’s a Swift package, I added it to my Package.swift file:

    dependencies: [
        ...
        .package(url: "https://github.com/twof/VaporMailgunService.git", from: "1.1.0"),
        ...
    ],
    ...
    targets: [
        ...
        .target(name: "App", dependencies: [
            ...
            "Mailgun",
            ...
            ]),
        ...
    ]

Running vapor update from the command line pulled down the package and updated all my dependencies. I decided to use a Provider to set up the Mailgun package in my app:

import Vapor
import Mailgun

struct MailgunProvider: Provider {
    private let config: MailgunConfigurationType

    init(mailgunConfig: MailgunConfigurationType) {
        self.config = mailgunConfig
    }

    func register(_ services: inout Services) throws {
        services.register(Mailgun(apiKey: config.apiKey, domain: config.domain), as: EmailDeliveryService.self)
    }

    func didBoot(_ container: Container) throws -> EventLoopFuture<Void> {
        return .done(on: container)
    }
}

There’s not much to this. The only interesting bit is the register() implementation. It registers the Mailgun service from the Mailgun framework as the implementation for the EmailDeliveryService protocol. It uses apiKey and domain fields from the configuration passed in, which will come from the appropriate environment configuration. In my case, since I’m using Heroku, the production environment configuration will pull from the MAILGUN_API_KEY and MAILGUN_DOMAIN environment variables. Additionally, the production configuration will take care of registering this provider.

I decided to use a provider pattern for the sake of the testing configuration. The production provider here doesn’t really need to be a provider; it only registers one service. But since the testing configuration does make full use of the Provider protocol, I decided to make the production configuration follow suite.

Now that I had Mailgun in my app, I needed to put it behind a generic protocol so all the client code could be agnostic about the email service being used. I started by defining a simple protocol:

import Vapor

protocol EmailDeliveryService: Service {
    func send(_ message: EmailMessage, on container: Container) -> Future<Void>
}

An EmailDeliveryService is a Service (in the dependency injection sense) that implements a send() method. The send() method takes an EmailMessage and returns a Void promise, which can be used to know if the send succeeded or failed.

For the final bit of sending an email, I need to conform the Mailgun service to my generic EmailDeliveryService protocol:

import Vapor
import Mailgun

extension Mailgun: EmailDeliveryService {
    func send(_ message: EmailMessage, on container: Container) -> Future<Void> {
        do {
            let mailgunMessage = Mailgun.Message(
                from: message.from,
                to: message.to,
                subject: message.subject,
                text: message.body.text,
                html: message.body.html
            )

            return try self.send(mailgunMessage, on: container).transform(to: ())
        } catch let error {
            return container.future(error: error)
        }
    }
}

The implementation is intentionally as thin as possible. This is partly because it’s hard to test protocol extensions. If I had needed anything more complicated, I would have opted to wrap Mailgun in another type that conformed to EmailDeliveryService. In any case, this simply converts my EmailMessage type into Mailgun’s version and sends it. It also wraps any thrown errors into a rejected promise for the convenience of any calling code.

And, with that, my app is now sending email via Mailgun! But is it sending the correct emails? Well…

Testing

The goal of a couple of design decisions was to make the testing of emails possible, or at least easier. The choice of abstracting out the email service into a generic protocol means I can inject a testing fake. Making the email template rendering separate from the email sending means I can still test the template rendering, even if I swap out the email service with a fake.

For my integration testing, I didn’t actually want to send any emails to Mailgun. That means my tests aren’t full integration tests, and won’t catch a misconfigured Mailgun setup. But I didn’t want my integration tests dependent on an external, non-local service to run; that would make them too flaky. Plus I’d likely run into an Mailgun API quota pretty quick. However, even with this limitation, I was able to verify that the correct emails got sent at the correct time.

Like with building the initial email types, I prefer to start out with what a final test might look like. Here’s a simplified test from my app that validates a welcome email was sent:

func testCreate_emailShouldSend() throws {
    app.emailDeliveryService.send_stubbed?.succeed()
    ...
    // Do something that should send an email
    ...
    XCTAssertTrue(app.emailDeliveryService.send_wasCalled)
    XCTAssertEqual(app.emailDeliveryService.send_wasCalled_withMessage!.to, "bob.jimbob@example.com")
    XCTAssertEqual(app.emailDeliveryService.send_wasCalled_withMessage!.from, "donotreply@myapp.com")
    XCTAssertEqual(app.emailDeliveryService.send_wasCalled_withMessage!.subject, "Welcome to MyApp!")

    let link = "myapp://verify/\(user!.verifyToken)"
    XCTAssertTrue(app.emailDeliveryService.send_wasCalled_withMessage!.body.html.contains(link))
    XCTAssertTrue(app.emailDeliveryService.send_wasCalled_withMessage!.body.text.contains(link))
}

The first line tells the email service testing fake that the next call to send() should return success. Next the test calls into the app in a way that should send a welcome email (as represented by the comment). The final lines assert that send was called, and with the correct parameters. The test also validates that the most important piece of information — the verify link — appears in both the plain text and HTML parts of the email message. I didn’t do a full text comparison because most of the body is static content, and comparing all of it makes the test more fragile than it needs to be.

With this test written, I can work backwards and define what my email service testing fake should implement.

import Vapor
import Mailgun

final class FakeEmailDeliveryService: EmailDeliveryService {
    var send_wasCalled = false
    var send_wasCalled_withMessage: EmailMessage?
    var send_stubbed: Promise<Void>?
    func send(_ message: EmailMessage, on container: Container) -> Future<Void> {
        send_wasCalled = true
        send_wasCalled_withMessage = message
        return send_stubbed!.futureResult
    }
    ...
}

The testing fake, FakeEmailDeliveryService, records if send() was called along with the EmailMessage it was called with. It only keeps track of the last message because my tests only send one at a time. The fake also has the ability to return a stubbed value from send(). This is useful for validating what happens if there’s a failure on the email service’s end. The fake send() assumes that the stubbed promise has been allocated elsewhere before it’s invoked.

Speaking of allocating the stubbed promise, there’s a bit of cleanup that’s required because of the way Vapor’s promises work:

final class FakeEmailDeliveryService: EmailDeliveryService {
    ...
    deinit {
        // Vapor does not like a promise created but not resolved before it is destroyed. It calls them "leaked" and crashes the tests. So make sure nothing is "leaked" in our tests.
        send_stubbed?.succeed()
    }
}

As the comment states, Vapor will crash a test if there are any promises left unresolved. This happens in any of my tests that don’t exercise the email functionality of the app. I could go through all of those tests and add code to resolve the send_stubbed promise, but that’d be verbose and tedious. Instead, I opted to have deinit forcefully resolve the promise if it hasn’t already been.

The FakeEmailDeliveryService needs to be registered with the dependency injection system so that code asking for a EmailDeliveryService will get an instance of it. As with the production version of EmailDeliveryService, I used a Provider:

struct TestMailProvider: Provider {
    var emailDeliveryService = FakeEmailDeliveryService()

    func register(_ services: inout Services) throws {
        services.register(emailDeliveryService, as: EmailDeliveryService.self)
    }

    func didBoot(_ container: Container) throws -> EventLoopFuture<Void> {
        emailDeliveryService.send_stubbed = container.eventLoop.newPromise()
        return .done(on: container)
    }
}

The first thing the provider does is create the FakeEmailDeliveryService and stash in a public member variable. It does this so tests can get ahold of it and validate the send() parameters, or resolve its return value. The register() method then registers the fake as the implementation of EmailDeliveryService. The didBoot() method takes care of creating the unresolved promise for send()‘s stubbed return value. Creating promises require an event loop, and didBoot() is the earliest place in the test code that I had access to one. I chose to allocate the stubbed promise this early because it allowed tests to assume its existence during set up without worrying about race conditions.

With the registering of TestMailProvider all of testing fakes are set up and ready to be used. However, FakeEmailDeliveryService wasn’t yet accessible to the test cases, which were expecting it as a property on TestApplication called emailDeliveryService. The rest of this section is showing the plumbing of TestMailProvider.emailDeliveryService property up through to TestApplication.

I started at the TestingConfiguration level, which is where the TestMailProvider is created and registered:

struct TestingConfiguration: ConfigurationType {
    ...
    let mailProvider = TestMailProvider()

    func configure(_ services: inout Services) throws {
        try services.register(mailProvider)
    }
    ...
}

This exposes TestMailProvider on the TestConfiguration, which TestApplication can then use:

class TestApplication {
    ...
    private let configuration: TestingConfiguration
    ...
    var emailDeliveryService: FakeEmailDeliveryService {
        return configuration.mailProvider.emailDeliveryService
    }
    ...
}

And now my tests could validate emails by using the FakeEmailDeliveryService exposed on TestApplication.

Conclusion

My Vapor side project needed to send emails on user registration, which could potentially be a complicated setup. Since email isn’t a major feature of my app, it made sense to delegate sending emails out to a third party service like Mailgun. Although there’s a convenient Mailgun Swift package, I still needed to build out infrastructure for rendering emails from Leaf templates and abstracting out the emailing sending so I can test my app’s email handling.

For my little Vapor side project, I need to have some visibility into what’s going on when it’s deployed. There are lots of solutions for this sort of thing, but since this is side project, I don’t need anything fancy. I think some basic logging infrastructure will be more than adequate for now. There are two parts to my logging “strategy.” First, I need to decided what to log out, and second, where to log it out.

As far as what to log out, I’m going to start with the basic request and response information. That is: the method and path of the request, the response status code, and how long it took for my server to process the request. This should give me some idea of the health of my server. I’m not going to log out request headers, or the request or response bodies. They could have sensitive information in them that I don’t want to end up in logs.

The question of where to log this information out to is a slightly more interesting question. I want a convenient place to get at the logs, plus the ability to easily search those logs. And, theoretically, if I needed to scale up my server to multiple instances (lol), I would want the logs all in one place. In the end, I decided on Papertrail for a couple of reasons:

1. I’m hosting my side project on Heroku, and they provide a convenient Papertrail add on that I can trivially provision.
2. Papertrail offers a free tier, appropriate for side projects
3. Papertrail doesn’t require my app to know about it directly. Papertrail installs a daemon on the monitored system that grabs the syslog and sends it to its servers. Which means if my app logs out to syslog, Papertrail will take care of the rest.

My plan for adding logging to my Vapor 3 server: first, create a logger type that will log out to syslog. Second, create a Vapor middleware that will intercept requests and responses, and log those out to the logger created in step one. Finally, update the configuration to include the logging middleware.

Logging out to syslog

Logging out to syslog turned out to be mildly interesting because I’m developing in Swift on a macOS system, but deploying to a Linux system.

The first thing I found out about syslog is Apple considers it deprecated on macOS, and would really rather I use os_log. os_log does sound fancy, but it doesn’t exist on Linux, and Papertrail doesn’t use it. So I have to ignore Apple’s advice on this one. Secondly, while syslog() the function is exposed in Swift, it doesn’t have convenient bindings, so I had to create one.

Here’s the start of my Vapor syslog logger:

import Foundation
import Vapor

final class SyslogLogger: Logger {
    func log(_ string: String, at level: LogLevel, file: String, function: String, line: UInt, column: UInt) {
        let message = "\(string) [\(function)@\(file):\(line):\(column)]"
        syslog(message, at: level)
    }
    ...
}

Logger is a protocol that Vapor defines, and the log() method here is its only requirement. I format the message given all the logging information, and then send the message with the log level to a helper function. That helper function takes care of actually calling syslog():

final class SyslogLogger: Logger {
    ...
    private func syslog(_ message: String, at level: LogLevel) {
        message.withCString { cstring in
            withVaList([cstring]) { varArgs in
                vsyslog(level.syslogLevel, "%s", varArgs)
            }
        }
    }
}

I’m calling the vsyslog() variant of syslog because that’s the one exposed to Swift. It requires a C variable argument list. Fortunately, Swift provides a way to convert a Swift array into one of those with withVaList(). Since I’ve already formatted my message using Swift’s string interpolation, I don’t actually want any further formatting from vsyslog(). However, as Sven Weidauer points out, if message contains any formatting placeholders (e.g. %d), it would cause problems because vsyslog() would try to format them. Therefore, I use %s as the format string, and pass my message in the var args. However, there’s another wrinkle here. On iOS/macOS a String is considered a CVarArg and can be passed directly into withVaList(). Unfortunately, on Linux — where this code will be deployed — String is not a CVarArg. So I have to convert the Swift String to a C string with withCString before passing it into withVaList(). Finally, I convert Vapor’s LogLevel type into a level that syslog understands, and call vsyslog().

Here’s my log level mapping:

private extension LogLevel {
    var syslogLevel: Int32 {
        switch self {
        case .verbose: return LOG_DEBUG
        case .debug: return LOG_DEBUG
        case .info: return LOG_INFO
        case .warning: return LOG_WARNING
        case .error: return LOG_ERR
        case .fatal: return LOG_CRIT
        case .custom(_): return LOG_NOTICE
        }
    }
}

I’m not entirely happy with the log level mapping, but from what I can gather from the docs, this is as close of a mapping as any. The .custom(String) log level in Vapor is a bit puzzling, but I guess the authors felt they needed an escape hatch in case they forgot a level. The other perhaps slightly surprising bit is that .verbose and .debug both map to syslog’s idea of LOG_DEBUG, since syslog doesn’t have a counterpart to .
verbose.

I have one final bit to my logger:

extension SyslogLogger: ServiceType {
    static func makeService(for worker: Container) throws -> SyslogLogger {
        return SyslogLogger()
    }
}

This is some boilerplate code to make my SyslogLogger type able to be created by Vapor’s dependency injection system by conforming it to the ServiceType protocol. It’ll be used when I go to configure logging for the app.

Logging requests and responses

Now that I have a logger that will send information to syslog, I need to take advantage of it. As I mentioned at the start, I want to log: a request HTTP method and path, the response status code, and how long it took to service the request. Fortunately, Vapor’s middleware provides a convenient place to monitor requests and their responses.

I’ll start with declaring my middleware type and defining the middleware entry point:

import Foundation
import Vapor

final class LogMiddleware: Middleware {
    private let logger: Logger

    init(logger: Logger) {
        self.logger = logger
    }

    func respond(to request: Request, chainingTo next: Responder) throws -> EventLoopFuture<Response> {
        let startTime = Date()
        return try next.respond(to: request).map { response in
            self.log(response, for: request, whichStartedAt: startTime)
            return response
        }
    }
    ...
}

My middleware class takes a generic Logger type in its init, so it can work any logger that I choose in the future. The respond(to:chainingTo:) method is the middleware entry point. The idea is to wrap the request processing so I know how long it takes. Once the request is processed and the response generated, then I can log all that information. To accomplish that, the code notes the current time, then calls through to the rest of stack to actually handle the request. It then grabs the response that results, and passes it along with the request and start time to a helper method called log():

final class LogMiddleware: Middleware {
    ...
    private func log(_ response: Response, for request: Request, whichStartedAt startTime: Date) {
        let requestInfo = "\(request.http.method.string) \(request.http.url.path)" + (request.http.url.query.map { "?\($0)" } ?? "")
        let responseInfo = "\(response.http.status.code) \(response.http.status.reasonPhrase)"
        let time = format(Date().timeIntervalSince(startTime))
        logger.info("\(requestInfo) -> \(responseInfo) [\(time)]")
    }
    ...
}

This is the method where I construct the message to be logged. I build it piecemeal by the three main parts: the request, the response, and the time it took. For the request, I put together the method, path, and the query parameters, if there are any. For the response, I put together the HTTP status code, plus the human readable version of the status code. Vapor helpfully provides that on the reasonPhrase property. Finally, I compute the time elapsed and format that. Once I have all three pieces, I put them together into one string. The resulting message looks something like GET /my/path?p1=y&p2 -> 200 OK [98.20ms].

Formatting time is a bit verbose, so I put that into its own method:

final class LogMiddleware: Middleware {
    ...
    private let intervalFormatter: NumberFormatter = {
        let formatter = NumberFormatter()
        formatter.numberStyle = .decimal
        formatter.maximumFractionDigits = 2
        formatter.multiplier = 1000
        return formatter
    }()
    ...
    private func format(_ interval: TimeInterval) -> String {
        return intervalFormatter.string(for: interval).map { $0 + "ms" } ?? "???ms"
    }
}

I’m leveraging NumberFormatter to do all the hard work. I set it up to create decimal numbers with no more than 2 digits after the decimal point, and 1000 as a multiplier. That’s because I’m giving the formatter seconds, but I want it displayed in milliseconds. My format() method simply calls the NumberFormatter, and appends “ms” as the units. The trailing ?? "???ms" shouldn’t ever be executed, and is there to satisfy the compiler, since string(for:) can technically return nil.

The final bit for the logging middleware is to hook into the dependency injection system:

extension LogMiddleware: ServiceType {
    static func makeService(for worker: Container) throws -> LogMiddleware {
        return try LogMiddleware(logger: worker.make())
    }
}

This is also where the Logger used by the middleware will be instantiated and passed into the init method.

Configuring logging for the app

The last little bit is to register my logger and middleware with the dependency injection framework, and add the logging middleware in the correct order. That means modifying my configure() method:

/// Called before your application initializes.
public func configure(_ config: inout Config, _ env: inout Environment, _ services: inout Services, _ configuration: ConfigurationType) throws {
    ...
    services.register(LogMiddleware.self)
    services.register(SyslogLogger.self)
    ...
    /// Register middleware
    var middlewares = MiddlewareConfig()
    middlewares.use(LogMiddleware.self)
    ...
}

Here I register LogMiddleware and SyslogLogger with the dependency injection framework. Then, in the middleware configuration, I add my log middleware first, before all other middlewares. This will allow it to measure as much of the time it takes processing the request as possible. It will be the first middleware called when a request is received, and the last to be called when the response is returned.

Conclusion

While I need to have some visibility into how my Vapor server is doing in production, my side project doesn’t need anything overly complicated. I chose to use Papertrail because it provided an easy and convenient place to aggregate my logs. To get logs to Papertrail, I added middleware to my app that logs out basic request and response information to syslog.