Turning CI Logs into Actions

When a CI job fails, the first thing you usually do is scroll through a wall of logs trying to spot the error. It’s tedious, slow, and often the exact same dance on every project. You could bolt on scripts to comment on PRs or ping Slack, but then you’re duplicating logic across repos and languages and spreading around more auth tokens than you’d like.

What if instead, your build just emitted special log lines, and a wrapper tool noticed them and took action? That way your CI stays simple, projects don’t need extra secrets, and you get rich behaviour like PR comments or Slack alerts “for free.”

One way around this is to do something similar to what Xcode does where if I emit a log like warning: This is a warning it will furnish the UI with a nice warning triangle. So in our case if we provide an executable that knows all about pinging slack, GitHub and other services we care about we can have this program wrap our build script and look for special logs. When it sees a log it knows how to handle it can perform the right action. With this new parent process being responsible for executing our build script we can choose to strip out any environment variables we don’t want to share, meaning the parent process can be auth’d to talk to slack and the child will know nothing about it.


Less writing more writing code

Thankfully swift-subprocess has us pretty nicely set up for running the child process and parsing logs.

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
import Foundation
import Subprocess

let terminationStatus = try await run(
    .path("/bin/bash"),
    arguments: ["-c", ProcessInfo.processInfo.arguments.dropFirst().joined(separator: " ")],
    error: .standardError
) { execution, standardOutput in
    for try await line in standardOutput.lines() {
        // Parse the log text
        print(line, terminator: "")
    }
}.terminationStatus

switch terminationStatus {
case let .exited(code):
    exit(code)
case let .unhandledException(code):
    exit(code)
}

Let’s unpack the interesting bits:

  • Lines 4-8 are going to execute the command we pass in a bash subprocess.
  • Line 6 is dropping the first argument as this will be the path to the executable. The rest is the command we want to execute.
  • Line 7 ensures that stderr isn’t dropped on the floor as we want our command to be as transparent as possible.
  • Lines 9-12 are where the magic is going to happen soon.
  • Line 11 is just printing stdout otherwise our program will appear to just swallow all output.
  • Lines 15-20 are just taking the result of the subprocess and making it the final result.

I haven’t explored the full API surface yet but this approach seems reasonable.

At a high level, we will invoke our new executable that I’ll call log-commander with our normal build script something like this

log-commander bundle exec fastlane build

Under the hood log-commander will essentially execute /bin/bash -c "bundle exec fastlane build" and then proxy all output and the final result.


Let’s make it do something interesting

As it stands we’ve not achieved much so let’s teach log-commander to comment on a PR. We’ll assume that log-commander will be provided the GITHUB_AUTH, GITHUB_ISSUE_ID, GITHUB_OWNER and GITHUB_REPO as environment variables. With this we can create a simple client to post a comment to a PR on GitHub

class GitHubClient {
    private let baseURL: URL
    private let session: URLSession

    init() {
        let sessionConfiguration = URLSessionConfiguration.default
        sessionConfiguration.httpAdditionalHeaders = [
            "Accept": "application/vnd.github.v3+json",
            "Authorization": "Bearer \(getOrFatalError("TOKEN"))",
            "X-GitHub-Api-Version": "2022-11-28",
        ]
        self.session = .init(configuration: sessionConfiguration)
        self.baseURL = URL(string: getOrFatalError("URL"))!
            .appending(components: "repos", getOrFatalError("OWNER"), getOrFatalError("REPO"))
    }

    func postComment(_ message: String) async throws {
        let url = baseURL.appending(components: "issues", getOrFatalError("ISSUE_ID"), "comments")
        var urlRequest = URLRequest(url: url)
        urlRequest.httpMethod = "POST"
        urlRequest.httpBody = try JSONEncoder().encode(["body": message])
        let (_, response) = try await session.data(for: urlRequest)

        if (response as? HTTPURLResponse)?.statusCode != 201 {
            throw NSError(domain: "GitHubClient", code: (response as? HTTPURLResponse)?.statusCode ?? -1, userInfo: nil)
        }
    }
}

private func getOrFatalError(_ key: String) -> String {
    if let value = ProcessInfo.processInfo.environment["GITHUB_\(key)"] {
        value
    } else {
        fatalError("Required 'GITHUB_\(key)' environment variable not set")
    }
}

* Proper error handling is left as an exercise for the reader.


Connecting the dots

Now we have the top level code to wrap our normal build process and a client to communicate with GitHub we just need to link them together. I’m going to go with the idea that if a line contains an opening and closing curly brace then I’ll attempt to parse it as a JSON payload. If it parses correctly then the log-commander will post the comment to GitHub. Any unsuccessful decoding will just be ignored.

To achieve this we’ll introduce a structure that represents the command we care about parsing

struct Action: Decodable {
    let prComment: PRComment?

    struct PRComment: Decodable {
        let message: String
    }
}

I’m nesting the PRComment under an Action struct so I can build up different actions that will require different data.

With this we can update our line parsing to something like this

let decoder = JSONDecoder()
decoder.keyDecodingStrategy = .convertFromSnakeCase

for try await line in standardOutput.lines() {
    print(line, terminator: "")

    guard
        let openingBrace = line.firstIndex(of: "{"),
        let closingBrace = line.lastIndex(of: "}"),
        let message = try? decoder.decode(Action.self, from: Data(line[openingBrace...closingBrace].utf8))
    else { continue }

    if let prComment = message.prComment?.message {
        try await client.postComment(prComment)
    }
}

Now if we just emit a log statement in our normal build tool that looks like this

{"pr_comment":{"message":"Example"}}

The log-commander will parse this out and post a comment on the PR with the message Example.


Tidying up

I mentioned that we don’t want the child process to know about GitHub auth and this can be taken care of by manipulating the environment in the initial run invocation something like this:

environment: .inherit.updating(["GITHUB_TOKEN": ""])

Wrap up

I like the idea of writing this logic once and then sharing it among teams to make debugging life easier. Instead of scrolling endlessly through CI logs or wiring up ad-hoc scripts for every project, you get a single wrapper that turns structured logs into actions. This blog showed GitHub PR comments but you could extend to do Slack alerts, build metrics or whatever if you can dream up. It also makes it super low friction to get rich behaviour - e.g. wrap your normal invocation to your build command with this tool and then create some specially formatted logs.

Self-hosting a Vapor app on a Raspberry Pi

There’s something oddly satisfying about seeing a piece of physical hardware with its little flashy light brrring along executing some Swift code I wrote to serve requests over the internet. The hardware is a tiny Raspberry Pi and the app was custom made purely to help my brother out who lives 200 miles away and doesn’t have a mac so software sharing options are complicated.

A blocker

After building an app I was then stuck with where do I actually deploy this? I’ll admit I looked around and got stuck because:

  • I’m not making any money from this so didn’t want to pay for hosting
  • Even if I pay there’s complexity with setting up accounts for docker repositories to host images and handing deployment etc

I gave up and resorted to just having my brother tell me when he needed the app, then I’d run it locally on my machine and then use ngrok to give him access over the public internet. Not ideal at all.

Some light

I was talking to my colleague Jack and he was telling me about how he uses a few Raspberry Pis for home automation and that he can access various bits over the public internet. This sounded cool so I bought a Raspberry Pi and then subsequently filed all this information under “I can’t do that” and moved on. Apparently Jack is on some kind of commission and kept asking how I was getting on with my Raspberry Pi, to the point where it was getting embarrassing that I hadn’t done anymore than turn the thing on. I explained that the thing really putting me off was opening ports and managing iptables etc, to which Jack said don’t do that use Cloudflare tunnels instead. A Cloudflare tunnel avoids the pain of opening ports because you run an app locally that makes an outbound connection to Cloudflare. Cloudflare then routes traffic from a public URL back down that secure tunnel to your app.

One late evening

I sat down and set myself the target of deploying this Vapor app so my brother could use it with having to have me fire it up on my mac. Here’s the set up steps:

  • Install an OS on the Raspberry Pi and get it connected to my network (you use the Raspberry Pi Imager for this)
  • Install Docker on the Pi - Raspbian is based off Debian so I used the instructions for debian
  • Run a docker registry on the Pi so I can build on my mac but push the image to the Pi
    I did originally try building on the Pi and it didn’t pan out well. I reckon it was having power spike issues based on the fact I was using a noddy phone charger and nothing beefier.
  • On my mac allow to push to my pi repository using insecure http (YOLO it’s only on my private network anyway)
    This involved adding some configuration like the following to the Docker Engine config
    "insecure-registries": [
      "raspberrypi.local:5000"
    ]
    
  • Build the app on my mac, tag it and push to the registry on my Pi
  • Configure a Cloudflare tunnel
    Using the config in the compose file in the next step I essentially need to configure Cloudflare to map a public url to http://app:8080. The odd url is taking advantage of the fact that the Cloudflare tunnel is running in Docker as well so we can use the app name to resolve to the app’s address
  • Create a compose file that will spin up my app and a Cloudflare tunnel
    I found a really good blog post that helped me write
    services:
      app:
        restart: unless-stopped
        container_name: app
        image: localhost:5000/app:0.0.1
        ports:
          - '8080:8080'
        command: ["serve", "--env", "production", "--hostname", "0.0.0.0", "--port", "8080"]
    
      tunnel:
        restart: unless-stopped
        container_name: tunnel
        image: cloudflare/cloudflared:latest
        command: tunnel run
        environment:
          - TUNNEL_TOKEN=
    

    This is going to pull my app’s image from the registry and spin it up on port 8080, whilst also starting a Cloudflare tunnel (the TUNNEL_TOKEN environment variable can be retrieved from your Cloudflare Zero Trust dashboard)

  • Spin up the containers and prosper

Wrap up

As per usual the hardest part of this project was actually getting started. Thanks to Jack for the initial idea and then pestering I managed to get this all set up and I’m pretty happy with how repeatable it all is. In fact if you are reading this blog post then boom, this is also running on the same Raspberry Pi via a different tunnel exposing a static webserver.

Subtle retain cycle is subtle

Retain cycles are often a pain to track down and here’s an example of a less obvious one we had recently.


The problem

Here’s a simplified reproduction of the issue

class Example {
    var task: Task<Void, Never>?

    init() {
        task = Task { [weak self] in
            guard let self else { return }

            repeat {
                performSomeWork()
            } while !Task.isCancelled
        }
    }

    func performSomeWork() { }

    deinit {
        print("deinit")
        task?.cancel()
    }
}

Let’s not focus too much on the exact code as it doesn’t do anything except illustrate the issue. When running this code the deinit will never run because the Task is creating a retain cycle keeping Example alive indefinitely.

At first glance this looks like fairly standard code - the part of interest is

task = Task { [weak self] in
    guard let self else { return }

    repeat {
        performSomeWork()
    } while !Task.isCancelled
}

In the above we see the common weak/strong dance that we are all used to but we still have a cycle so what gives?

We are spinning a loop in the task that only stops when the task is cancelled. The only place we currently call cancel is in the deinit of the Example class so this loop is partly responsible for the cycle. The key thing to look for is who is taking a strong reference and what is the scope of that reference?

task = Task { [weak self] in        //
    guard let self else { return }  // - strong reference taken here
                                    //
    repeat {                        //
        performSomeWork()           //
    } while !Task.isCancelled       //
}                                   // - goes out of scope here

The problem we have looking at the scope is that the strong reference is in scope until the end of the function, but we have our repeat loop before the end of the function so we will never get to the end.


Breaking the cycle

There’s many ways to break the cycle - let’s look at a few

Change the scope of the strong reference

task = Task { [weak self] in            //
    repeat {                            //
        guard let self else { return }  // - strong reference taken here
        performSomeWork()               //
    } while !Task.isCancelled           // - goes out of scope here
}                                       //

If we move the guard inside the repeat then it will only take a strong reference for the body of repeat. This means that the strong reference is released and retaken each time through the loop. Due to the guard being evaluated fresh each time this allows the cycle to be broken.

Use the weak reference everywhere

task = Task { [weak self] in
    repeat {
        self?.performSomeWork()
    } while !Task.isCancelled
}

In this example it looks pretty clean to do this but in real code you might not be able to have the nullability in which case you’d end up using guard or if let to unwrap things (just be careful on scope).

Manually break the cycle

task?.cancel()

For this you’d have to have some other code get a reference to the task and call cancel() at the appropriate time.


Be careful

Another thing you might try to break the cycle is using the capture groups.

task = Task { [performSomeWork] in
    repeat {
        performSomeWork()
    } while !Task.isCancelled
}

For this example we are back to retain cycle city. The issue is instance methods have an implicit reference to self so this won’t do the job.

The capture group would indeed work if we are getting a reference to something that doesn’t have a self reference for example instance properties.


You could write a unit to verify that the reference does not leak something like this. In this example though you’d need to add a short delay before you set the system under test to nil to ensure that the Task has had enough time to start working and take any strong reference you want to validate is held correctly.

Conclusion

Retain cycles are a pain and the ol’ chuck a weak on things doesn’t always work so it’s worth writing tests and using instruments to hunt things down.