DEV Community: Brennon Loveless

Test-Driven Development With The oclif Testing Library: Part Two

Brennon Loveless — Thu, 11 Nov 2021 05:34:51 +0000

In Part One of this series on the oclif testing library, we used a test-driven development approach to building our time-tracker CLI. We talked about the oclif framework, which helps developers dispense with the setup and boilerplate so that they can get to writing the meat of their CLI applications. We also talked about @oclif/test and @oclif/fancy-test, which take care of the repetitive setup and teardown so that developers can focus on writing their Mocha tests.

Our time-tracker application is a multi-command CLI. We’ve already written tests and implemented our first command for adding a new project to our tracker. Next, we’re going to write tests and implement our “start timer” command.

Just as a reminder, the final application is posted on GitHub as a reference in case you hit a roadblock.

First Test for the Start Timer Command

Now that we can add a new project to our time tracker, we need to be able to start the timer for that project. The command usage would look like this:

time-tracker start-timer project-one

Since we’re taking a TDD approach, we’ll start by writing the test. For our happy path test, "project-one" already exists, and we can simply start the timer for it.

// PATH: test/commands/start-timer.test.js

const {expect, test} = require('@oclif/test')
const StartTimerCommand = require('../../src/commands/start-timer')
const MemoryStorage = require('../../src/storage/memory')
const {generateDb} = require('../test-helpers')

const someDate = 1631943984467

describe('start timer', () => {
  test
  .stdout()
  .stub(StartTimerCommand, 'storage', new MemoryStorage(generateDb('project-one')))
  .stub(Date, 'now', () => someDate)
  .command(['start-timer', 'project-one'])
  .it('should start a timer for "project-one"', async ctx => {
    expect(await StartTimerCommand.storage.load()).to.eql({
      activeProject: 'project-one',
      projects: {
        'project-one': {
          activeEntry: 0,
          entries: [
            {
              startTime: new Date(someDate),
              endTime: null,
            },
          ],
        },
      },
    })
    expect(ctx.stdout).to.contain('Started a new time entry on "project-one"')
  })
})

There is a lot of similarity between this test and the first test of our “add project” command. One difference, however, is the additional stub() call. Since we will start the timer with new Date(Date.now()), our test code will preemptively stub out Date.now() to return someDate. Though we don’t care what the value of someDate is, what’s important is that it is fixed.

When we run our test, we get the following error:

Error: Cannot find module '../../src/commands/start-timer'

It’s time to write some implementation code!

Beginning to Implement the Start Time Command

We need to create a file for our start-timer command. We duplicate the add-project.js file and rename it as start-timer.js. We clear out most of the run method, and we rename the command class to StartTimerCommand.

const {Command, flags} = require('@oclif/command')
const FilesystemStorage = require('../storage/filesystem')

class StartTimerCommand extends Command {
  async run() {
    const {args} = this.parse(StartTimerCommand)
    const db = await StartTimerCommand.storage.load()

    await StartTimerCommand.storage.save(db)
  }
}

StartTimerCommand.storage = new FilesystemStorage()

StartTimerCommand.description = `Start a new timer for a project`

StartTimerCommand.flags = {
  name: flags.string({char: 'n', description: 'name to print'}),
}

module.exports = StartTimerCommand

Now, when we run the test again, we see that the db has not been updated as we had expected.

1) start timer
       should start a timer for "project-one":

      AssertionError: expected { Object (activeProject, projects) } to deeply equal { Object (activeProject, projects) }
      + expected - actual

       {
      -  "activeProject": [null]
      +  "activeProject": "project-one"
         "projects": {
           "project-one": {
      -      "activeEntry": [null]
      -      "entries": []
      +      "activeEntry": 0
      +      "entries": [
      +        {
      +          "endTime": [null]
      +          "startTime": [Date: 2021-09-18T05:46:24.467Z]
      +        }
      +      ]
           }
         }
       }

      at Context.<anonymous> (test/commands/start-timer.test.js:16:55)
      at async Object.run (node_modules/fancy-test/lib/base.js:44:29)
      at async Context.run (node_modules/fancy-test/lib/base.js:68:25)

While we’re at it, we also know that we should be logging something to tell the user what just happened. So let's update the run method with code to do that.

const {args} = this.parse(StartTimerCommand)
const db = await StartTimerCommand.storage.load()

if (db.projects && db.projects[args.projectName]) {
    db.activeProject = args.projectName
    // Set the active entry before we push so we can take advantage of the fact
    // that the current length is the index of the next insert
    db.projects[args.projectName].activeEntry = db.projects[args.projectName].entries.length
    db.projects[args.projectName].entries.push({startTime: new Date(Date.now()), endTime: null})
}

this.log(`Started a new time entry on "${args.projectName}"`)

await StartTimerCommand.storage.save(db)

Running the test again, we see that our tests are all passing!

add project
    ✓ should add a new project
    ✓ should return an error if the project already exists (59ms)

start timer
    ✓ should start a timer for "project-one"

Sad Path: Starting a Timer on a Non-Existent Project

Next, we should notify the user if they attempt to start a timer on a project that doesn't exist. Let's start by writing a test for this.

test
  .stdout()
  .stub(StartTimerCommand, 'storage', new MemoryStorage(generateDb('project-one')))
  .stub(Date, 'now', () => someDate)
  .command(['start-timer', 'project-does-not-exist'])
  .catch('Project "project-does-not-exist" does not exist')
  .it('should return an error if the user attempts to start a timer on a project that doesn\'t exist', async _ => {
    // Expect that the storage is unchanged
    expect(await StartTimerCommand.storage.load()).to.eql({
      activeProject: null,
      projects: {
        'project-one': {
          activeEntry: null,
          entries: [],
        },
      },
    })
  })

And, we are failing again.

1 failing

  1) start timer
       should return an error if the user attempts to start a timer on a project that doesn't exist:
     Error: expected error to be thrown
      at Object.run (node_modules/fancy-test/lib/catch.js:8:19)
      at Context.run (node_modules/fancy-test/lib/base.js:68:36)

Let's write some code to fix that error. We add the following snippet of code to the beginning of the run method, right after we load the db from storage.

if (!db.projects?.[args.projectName]) {
    this.error(`Project "${args.projectName}" does not exist`)
}

We run the tests again.

add project
    ✓ should add a new project (47ms)
    ✓ should return an error if the project already exists (75ms)

start timer
    ✓ should start a timer for "project-one"
    ✓ should return an error if the user attempts to start a timer on a project that doesn't exist

Nailed it! Of course, there is one more thing that this command should do. Let's imagine that we've already started a timer on project-one and we want to quickly switch the timer to project-two. We'd expect that the running timer on project-one will stop and a new timer on project-two will begin.

Stop One Timer, Start Another

We repeat our TDD red-green cycle by first writing a test to represent the missing functionality.

test
  .stdout()
  .stub(StartTimerCommand, 'storage', new MemoryStorage({
    activeProject: 'project-one',
    projects: {
      'project-one': {
        activeEntry: 0,
        entries: [
          {
            startTime: new Date(someStartDate),
            endTime: null,
          },
        ],
      },
      'project-two': {
        activeEntry: null,
        entries: [],
      },
    },
  }))
  .stub(Date, 'now', () => someDate)
  .command(['start-timer', 'project-two'])
  .it('should end the running timer from another project before starting a timer on the requested one', async ctx => {
    // Expect that the storage is unchanged
    expect(await StartTimerCommand.storage.load()).to.eql({
      activeProject: 'project-two',
      projects: {
        'project-one': {
          activeEntry: null,
          entries: [
            {
              startTime: new Date(someStartDate),
              endTime: new Date(someDate),
            },
          ],
        },
        'project-two': {
          activeEntry: 0,
          entries: [
            {
              startTime: new Date(someDate),
              endTime: null,
            },
          ],
        },
      },
    })

    expect(ctx.stdout).to.contain('Started a new time entry on "project-two"')
  })

This test requires another timestamp, which we call someStartDate. We add that near the top of our start-timer.test.js file:

...
const someStartDate = 1631936940178
const someDate = 1631943984467

This test is longer than the other tests, but that’s because we needed a very specific db initialized within MemoryStorage to represent this test case. You can see that, initially, we have an entry with a startTime and no endTime in project-one. In the assertion, you'll notice that the endTime in project-one is populated, and there is a new active entry in project-two with a startTime and no endTime.

When we run our test suite, we see the following error:

1) start timer
       should end the running timer from another project before starting a timer on the requested one:

      AssertionError: expected { Object (activeProject, projects) } to deeply equal { Object (activeProject, projects) }
      + expected - actual

       {
         "activeProject": "project-two"
         "projects": {
           "project-one": {
      -      "activeEntry": 0
      +      "activeEntry": [null]
             "entries": [
               {
      -          "endTime": [null]
      +          "endTime": [Date: 2021-09-18T05:46:24.467Z]
                 "startTime": [Date: 2021-09-18T03:49:00.178Z]
               }
             ]
           }

      at Context.<anonymous> (test/commands/start-timer.test.js:76:55)
      at async Object.run (node_modules/fancy-test/lib/base.js:44:29)
      at async Context.run (node_modules/fancy-test/lib/base.js:68:25)

This error tells us that our CLI correctly created a new entry in project-two, but it didn't first end the timer on project-one. Our application also didn't change the activeEntry from 0 to null in project-one as we expected.

Let's fix up the code to solve this issue. Right after we check that the requested project exists, we can add this block of code which will end a running timer on another project and unset the activeEntry in that project, and it does that all before we create a new timer on the requested project.

// Check to see if there is a timer running on another project and end it
if (db.activeProject && db.activeProject !== args.projectName) {
    db.projects[db.activeProject].entries[db.projects[db.activeProject].activeEntry].endTime = new Date(Date.now())
    db.projects[db.activeProject].activeEntry = null
}

And there we have it! All our tests are passing once again!

add project
    ✓ should add a new project (47ms)
    ✓ should return an error if the project already exists (72ms)

  start timer
    ✓ should start a timer for "project-one"
    ✓ should return an error if the user attempts to start a timer on a project that doesn't exist
    ✓ should end the running timer from another project before starting a timer on the requested one

Conclusion

If you’ve been tracking with our CLI development over Part One and Part Two of this oclif testing series, you’ll see that we’ve covered the add-project and start-timer commands. We’ve been demonstrating how easy it is to use TDD to build these commands with oclif and @oclif/test.

Because the end-timer and list-projects commands are so similar to what we’ve already walked through, we’ll leave their development using TDD as an exercise for the reader. The project repository has those commands implemented as well as the tests used to validate the implementation.

In summary, we laid out plans for using TDD to build a CLI application using the oclif framework. We spent some time getting to know the @oclif/test package and some of the helpers provided by that library. Specifically, we talked about:

Using the command method for calling our command and passing it arguments
Methods provided by @oclif/fancy-test for stubbing parts of our application, catching errors, mocking stdout and stderr, and asserting on those results
Using TDD to build out a large portion of a CLI using a red-green cycle by writing tests first and then writing the minimal amount of code to get our tests to pass

Just like that… you've got another tool in your dev belt—this time, for writing and testing your own CLIs!

Running Concurrent Requests with async/await and Promise.all

Brennon Loveless — Tue, 18 May 2021 02:55:31 +0000

Introduction

In this article I’d like to touch on async, await, and Promise.all in JavaScript. First, I’ll talk about concurrency vs parallelism and why we will be targeting parallelism in this article. Then, I’ll talk about how to use async and await to implement a parallel algorithm in serial and how to make it work in parallel by using Promise.all. Finally, I’ll create an example project using Salesforce’s Lightning Web Components where I will build an art gallery using Harvard’s Art Gallery API.

Concurrency Vs Parallelism

I want to quickly touch on the difference between concurrency and parallelism. You can relate concurrency to how a single-threaded CPU processes multiple tasks. Single-threaded CPUs emulate parallelism by switching between processes quickly enough that it seems like multiple things are happening at the same time. Parallelism is when a CPU has multiple cores and can actually run two tasks at the exact same time. Another great example is this:

Concurrency is two lines of customers ordering from a single cashier (lines take turns ordering); Parallelism is two lines of customers ordering from two cashiers (each line gets its own cashier). [1]

Knowing this difference helps us consider what options we have from an algorithmic standpoint. Our goal is to make these HTTP requests in parallel. Due to some limitations in JavaScript implementation and browser variability, we don’t actually get to determine if our algorithm will be run concurrently or in parallel. Luckily, I don’t need to change our algorithm at all. The underlying JavaScript event loop will make it seem like the code is running in parallel, which is good enough for this article!

Async/Await in Serial

In order to understand this parallel algorithm, I’ll first use async and await to build a serial algorithm. If you write this code in an IDE, you’ll likely get a notification saying that using await in a loop is a missed optimization opportunity — and your IDE would be correct.

(async () => {
    const urls = [
        "https://example.com/posts/1/",
        "https://example.com/posts/1/tags/",
    ];

    const data = [];
  for (url of urls) {
    await fetch(url)
      .then((response) => response.json())
      .then((jsonResponse) => data.push(jsonResponse));
  }

  console.log(data);
})();

One reason that you might implement an algorithm like this is if you need to get the data from two different URLs, then blend that data together to create your final object. In the code above, you can imagine that we are gathering some data about a post, then grabbing the data about the post's tags, and finally merging that data into the object you’d actually use later on.

While this code will work, you might notice that we await on each fetch. You'll see something like:

Start to fetch post one
Wait for fetch post one to complete
Get post one response
Start to fetch post one tags
Wait for post one tags to complete
Get post one tags response

The problem is we’re waiting serially for each network request to complete before starting the next request. There’s no need for this: Computers are perfectly capable of executing more than one network request at the same time.

So how can we make this algorithm better?

Async/Await in Parallel

The easiest way to make this algorithm faster is to remove the await keyword before the fetch command. This will tell JavaScript to start the execution of all the requests in parallel. But in order to pause execution and wait for all of the promises to return, we need to await on something. We'll use Promise.all to do just that.

When we use await Promise.all, JavaScript will wait for the entire array of promises passed to Promise.all to resolve. Only then will it return all the results at the same time. A rewrite looks like this:

(async () => {
    const urls = [
        "https://example.com/posts/1/",
        "https://example.com/posts/1/tags/",
    ];

    const promises = urls.map((url) =>
        fetch(url).then((response) => response.json())
    );

    const data = await Promise.all(promises);

    console.log(data);
})();

This code will map each URL into a promise and then await for all of those promises to complete. Now when we pass the await Promise.all portion of the code, we can be sure that both fetch requests have resolved and the responses are in the data array in the correct position. So data[0] will be our post data and data[1] will be our tags data.

An Example

Now that we have all the necessary building blocks to implement our pre-fetched image gallery, let’s build it.

Below is a screenshot of the app I built for this article, and here is the link to the documentation about the Harvard Art Museum API docs [2]. You’ll need to apply for your own API key if you’d like to follow along. The process seemed pretty automatic to me since you just fill out a Google Form and then receive your API key in your email instantly.

It doesn’t look like much, but as you navigate through the gallery, it pre-fetches the next pages of data automatically. That way, the user viewing the gallery shouldn’t see any loading time for the actual data. The images are only loaded when they are displayed on the page. And while those do load after the fact, the actual data for the page is loaded instantly since it is cached in the component. Finally, as a challenge to myself, I’m using Salesforce’s Lightning Web Components for this project — a completely new technology to me. Let’s get into building the component.

Here are some of the resources that I used while learning about Lightning Web Components. If you’d like to follow along, then you’ll at least need to set up your local dev environment and create a “hello world” Lightning Web Component.

Setup A Local Development Environment [3]

Create a Hello World Lightning Web Component [4]

LWC Sample Gallery [5]

LWC Component Reference [6]

Alright, now that your environment is set up and you’ve created your first LWC, let’s get started. By the way, all the code for this article can be found at my GitHub repo [7].

A quick aside: Lightning Web Components are a little more limited than components you might be used to if you are coming from a React background. For example, you can’t use JavaScript expressions in component properties, i.e. the image src, in the following example:

<template for:each={records} for:item="record">
    <img src={record.images[0].baseimageurl}>
</template>

The reason for that is when you force all of your code to happen in the JavaScript files rather than in the HTML template files, your code becomes much easier to test. So let’s chalk this up to “it’s better for testing” and move on with our lives.

In order to create this gallery, we’ll need to build two components. The first component is for displaying each gallery image, and the second component is for pre-fetching and pagination.

The first component is the simpler of the two. In VSCode, execute the command SFDX: Create Lightning Web Component and name the component harvardArtMuseumGalleryItem. This will create three files for us: an HTML, JavaScript, and XML file. This component will not need any changes to the XML file since the item itself isn't visible in any Salesforce admin pages.

Next, change the contents of the HTML file to the following:

# force-app/main/default/lwc/harvardArtMuseumGalleryItem/harvardArtMuseumGalleryItem.html

<template>
    <div class="gallery-item" style={backgroundStyle}></div>
    {title}
</template>

Note that in this HTML file, the style property is set to {backgroundStyle} which is a function in our JavaScript file, so let's work on that one.

Change the contents of the JS file to the following:

# force-app/main/default/lwc/harvardArtMuseumGalleryItem/harvardArtMuseumGalleryItem.js

import { LightningElement, api } from 'lwc';

export default class HarvardArtMuseumGalleryItem extends LightningElement {
    @api
    record;

    get image() {
        if (this.record.images && this.record.images.length > 0) {
            return this.record.images[0].baseimageurl;
        }

        return "";
    }

    get title() {
        return this.record.title;
    }

    get backgroundStyle() {
        return `background-image:url('${this.image}');`
    }
}

There are a few things to notice here. First, the record property is decorated with @api which allows us to assign to this property from other components. Keep an eye out for this record property on the main gallery component. Also, since we can't have JavaScript expressions in our HTML files, I've also brought the background image inline CSS into the JavaScript file. This allows me to use string interpolation with the image. The image function is nothing special as it is — just an easy way for me to get the first image URL from the record that we received from the Harvard Art Gallery API.

Our final step of this component is to add a CSS file that wasn’t created for us automatically. So create harvardArtMuseumGalleryItem.css in the harvardArtMuseumGalleryItem directory. You don't need to tell the application to use this file as it is included automatically just by its existence.

Change the contents of your newly created CSS file to the following:

# force-app/main/default/lwc/harvardArtMuseumGalleryItem/harvardArtMuseumGalleryItem.css

.gallery-item {
    height: 150px;
    width: 100%;
    background-size: cover;
}

Now that our busy work is out of the way, we can get to the actual gallery.

Run SFDX: Create Lightning Web Component in VSCode again and name the component harvardArtMuseumGallery. This will, once again, generate our HTML, JavaScript, and XML files. We need to pay close attention to the XML file this time. The XML file is what tells Salesforce where our component is allowed to be located as well as how we will store our API key in the component.

# force-app/main/default/lwc/harvardArtMuseumGallery/harvardArtMuseumGallery.js-meta.xml

<?xml version="1.0" encoding="UTF-8"?>
<LightningComponentBundle xmlns="<http://soap.sforce.com/2006/04/metadata>">
    <apiVersion>51.0</apiVersion>
    <isExposed>true</isExposed>
    <targets>
        <target>lightning__HomePage</target>
    </targets>
    <targetConfigs>
        <targetConfig targets="lightning__HomePage">
            <property name="harvardApiKey" type="String" default=""></property>
        </targetConfig>
    </targetConfigs>
</LightningComponentBundle>

There are three key things to pay attention to in this XML file. The first is isExposed which will allow our component to be found in the Salesforce admin. The second is the target which says which areas of the Salesforce site our component can be used. This one says that we are allowing our component to be displayed on HomePage type pages. Finally, the targetConfigs section will display a text box when adding the component. There, we can paste our API key (as seen in the following screenshot). You can find more information about this XML file here [8].

Next, let’s take care of the HTML and CSS files.

# force-app/main/default/lwc/harvardArtMuseumGallery/harvardArtMuseumGallery.html

<template>
    <lightning-card title="HelloWorld" icon-name="custom:custom14">
        <div class="slds-m-around_medium">
          <h1>Harvard Gallery</h1>
          <div class="gallery-container">
            <template for:each={records} for:item="record">
              <div key={record.index} class="row">
                <template for:each={record.value} for:item="item">
                  <c-harvard-art-museum-gallery-item if:true={item} key={item.id} record={item}></c-harvard-art-museum-gallery-item>
                </template>
              </div>
            </template>
          </div>
          <div class="pagination-container">
            <button type="button" onclick={previousPage}>&lt;</button>
            <span class="current-page">
              {currentPage}
            </span>
            <button type="button" onclick={nextPage}>&gt;</button>
          </div>
        </div>
      </lightning-card>
</template>

Most of this is standard HTML with some custom components. The line I want you to pay attention to most is the tag and its record property. You’ll remember that this is the property we decorated with @api in the gallery item JavaScript file. The @api decoration allows us to pass in the record through this property.

Next, onto the CSS file:

# force-app/main/default/lwc/harvardArtMuseumGallery/harvardArtMuseumGallery.css

h1 {
  font-size: 2em;
  font-weight: bolder;
  margin-bottom: .5em;
}

.gallery-container .row {
  display: flex;
}

c-harvard-art-museum-gallery-item {
  margin: 1em;
  flex-grow: 1;
  width: calc(25% - 2em);
}

.pagination-container {
  text-align: center;
}

.pagination-container .current-page {
  display: inline-block;
  margin: 0 .5em;
}

I’ve saved the most interesting for last! The JavaScript file includes our pre-fetching logic and page-rolling algorithm.

# force-app/main/default/lwc/harvardArtMuseumGallery/harvardArtMuseumGallery.js

import { LightningElement, api } from "lwc";

const BASE_URL =
  "https://api.harvardartmuseums.org/object?apikey=$1&size=8&hasimage=1&page=$2";

export default class HarvardArtMuseumGallery extends LightningElement {
  @api harvardApiKey;

  error;
  records;
  currentPage = 1;
  pagesCache = [];

  chunkArray(array, size) {
    let result = [];
    for (let value of array) {
      let lastArray = result[result.length - 1];
      if (!lastArray || lastArray.length === size) {
        result.push([value]);
      } else {
        lastArray.push(value);
      }
    }

    return result.map((item, index) => ({ value: item, index: index }));
  }

  nextPage() {
    this.currentPage++;
    this.changePage(this.currentPage);
  }

  previousPage() {
    if (this.currentPage > 1) {
      this.currentPage--;
      this.changePage(this.currentPage);
    }
  }

  connectedCallback() {
    this.changePage(1);
  }

  async changePage(page) {
    let lowerBound = ((page - 3) < 0) ? 0 : page - 3;
    const upperBound = page + 3;

    // Cache the extra pages
    const promises = [];
    for (let i = lowerBound; i <= upperBound; i++) {
      promises.push(this.getRecords(i));
    }

    Promise.all(promises).then(() => console.log('finished caching pages'));

    // Now this.pages has all the data for the current page and the next/previous pages
    // The idea is that we will start the previous promises in order to prefrech the pages
    // and here we will wait for the current page to either be delivered from the cache or
    // the api call
    this.records = await this.getRecords(page);
  }

  async getRecords(page) {
    if (page in this.pagesCache) {
      return Promise.resolve(this.pagesCache[page]);
    }

    const url = BASE_URL.replace("$1", this.harvardApiKey).replace("$2", page);
    return fetch(url)
      .then((response) => {
        if (!response.ok) {
          this.error = response;
        }

        return response.json();
      })
      .then((responseJson) => {
        this.pagesCache[page] = this.chunkArray(responseJson.records, 4);
        return this.pagesCache[page];
      })
      .catch((errorResponse) => {
        this.error = errorResponse;
      });
  }
}

Notice that we are decorating the harvardApiKey with @api. This is how the targetConfig property from our XML file will be injected into our component. Most of the code in this file facilitates changing pages and chunking the response so that we get rows of four gallery items. Pay attention to changePage as well as getRecords: this is where the magic happens. First, notice that changePage calculates a range of pages from whatever the current requested page is. If the current requested page is five, then we will cache all pages from two until page eight. We then loop over the pages and create a promise for each page.

Originally, I was thinking that we’d need to await on the Promise.all in order to avoid loading a page twice. But then I realized it is a low cost to pay in order to not wait for all of the pages to be returned from the API. So the current algorithm is as follows:

User requests page five.
Bounds are calculated as page two through page eight, and promises are created for those requests.
Since we aren’t waiting for the promises to return, we will again request page five and make an extra API request (but this only happens for pages that aren’t in the cache).
So let's say that the user progresses to page six.
Bounds are calculated as pages three through nine, and promises are created for those requests.
Since we already have pages two through eight in the cache, and since we didn’t await on those promises, page six will immediately load from the cache while the promise for page nine is being fulfilled (since it is the only page missing from the cache).

Conclusion

And there you have it! We’ve explored concurrency and parallelism. We learned how to build an async/await flow in serial (which you should never do). We then upgraded our serial flow to be in parallel and learned how to wait for all the promises to resolve before continuing. Finally, we’ve built a Lightning Web Component for the Harvard Art Museum using async/await and Promise.all. (Although in this case, we didn't need the Promise.all since the algorithm works better if we don't wait for all the promises to resolve before continuing on.)

Thanks for reading and feel free to leave any comments and questions below.

Citations:

[1] https://stackoverflow.com/questions/1050222/what-is-the-difference-between-concurrency-and-parallelism

[2] https://github.com/harvardartmuseums/api-docs

[3] https://trailhead.salesforce.com/content/learn/projects/quick-start-lightning-web-components/set-up-salesforce-dx

[4] https://trailhead.salesforce.com/content/learn/projects/quick-start-lightning-web-components/create-a-hello-world-lightning-web-component

[5] https://trailhead.salesforce.com/sample-gallery

[6] https://developer.salesforce.com/docs/component-library/overview/components

[7] https://github.com/bloveless/AsyncAwaitPromiseAllLWC

[8] https://developer.salesforce.com/docs/atlas.en-us.api_meta.meta/api_meta/meta_lightningcomponentbundle.htm

Logging Best Practices: Part 2

Brennon Loveless — Wed, 03 Feb 2021 13:00:48 +0000

Best Practices for Logging

In part one I discussed why monitoring matters and some ways to implement that. Now let’s talk about some best practices we can implement to make monitoring easier. Let’s start with some best practices for logging — formatting, context, and level.

First, be sure you “log a lot and then log some more.” Log everything you might need in both the happy path and error path since you’ll only be armed with these logs when another error occurs in the future.

Until recently, I didn’t think I needed as many logs in the happy path. Meanwhile, my error path is full of helpful logging messages. Here is one example that just happened to me this week. I had some code that would read messages from a Kafka topic, validate them, and then pass them off to the DB to be persisted. Well, I forgot to actually push the message into the validated-messages array, which resulted in it always being empty. My point here is that everything was part of the happy path, so there weren’t any error logs for me to check. It took me a full day of adding logging and enabling debugging in production to find my mistake (that I forgot to push to the array). If I had messages like “Validating 1000 messages” and “Found 0 valid messages to be persisted,” it would have been immediately obvious that none of my messages were making it through. I could have solved it in an hour if I had “logged a lot and then logged some more.”

Formatting

This is another logging tip that I had taken for granted until recently. The format of your log messages matters…. and it matters a lot.

People use JSON-formatted logs more and more these days and I’m starting to lean into it myself. After all, there are many benefits to using JSON as your logging format. That said, if you pick a different log format, stick to it across all your systems and services. One of the major JSON-format benefits is that it is super easy to have generic error messages, and then add additional data/context. For example. . .

{
  "message": "Validating messages", 
  "message_count": 1000
}

{
  "message": "Persisting messages", 
  "message_count": 0
}

These messages are harder for humans to read, but easy to group, filter, and read for machines. In the end, we want to push as much processing onto the machine as possible anyway!

Another tip about your actual log message: In many cases, you’ll be looking to find similar events that occurred. Maybe you found an error and you want to know how many times it occurred over the last seven days. If the error message is something like “System X failed because Z > Y” — where X, Y, and Z are all changing between each error message — then it will be difficult to classify those errors as the same.

To solve this, use a general message for the actual log message so you can search by the exact error wording. For example: “This system failed because there are more users than there are slots available.” Within the context of the log message, you can attach all the variables specific to this current failure.

This does require you to have an advanced-enough logging framework to attach context. But if you are using JSON for your log messages, then you could have the “message” field be the same string for every event; any other context would appear as additional fields in the JSON blob. That way, grouping messages is easy, and specific error data is still logged. Although, if you are using a JSON format, then I’d suggest that you have a “message” and a “display.” That way, you get the best of both worlds.

Context

Rarely does a single log message paint the entire picture; including additional context with it will pay off. There is nothing more frustrating than when you get an alert saying “All your base are belong to us” and you have no idea what bases are missing or who “us” is referencing.

Whenever you are writing a log message, imagine receiving it at 1am. Include all the relevant information your sleepy self would need to look into the issue as quickly as possible. You may also choose to log a transaction ID as part of your context. We’ll chat about those later.

Level

Always use the correct level when writing your log messages. Ideally, your team will have different uses for the different log levels. Make sure you and your team are logging at the agreed-upon level when writing messages.

Some examples are INFO for general system state and probably happy-path code, ERROR for exceptions and non-happy-path code, WARN for things that might cause errors later or are approaching a limit, DEBUG for everything else. Obviously, these are just how I use some of the log levels. Try and lay out a log-level strategy with your team and stick to it.

Also, ensure that whatever logging aggregator you use allows for filtering by specific log levels or groups of log levels. When you view the state of your system, you probably don’t care about DEBUG level logs and want to just search for everything INFO and above, for example.

Log Storage

In order for your logs to be accessible, you’ll need to store them somewhere. These days, it is unlikely that you’ll have a single log file that represents your entire system. Even if you have a monolithic application, you likely host it on more than one server. As such, you’ll need a system that can aggregate all these log files.

I prefer to store my logs in Elasticsearch, but if you are in another ecosystem like Heroku, then you can use one of the provided logging add-ons. There are even some free ones to get you started.

You may also prefer third-party logging services like Splunk or Datadog to ship your logs and monitor, analyze, and alert from there.

Filtering

If you have logged all your messages at the correct levels and have used easily group-able log messages, then filtering becomes simple in any system configuration. Writing a query in Elasticsearch will be so much simpler when you’ve planned your log messages with this in mind.

Transaction IDs

Let’s face it: Gone are the days when a single service handled the full request path. Only in rare cases or demo projects will your services be completely isolated from other services. Even something as simple as a front-end and a separate backend API can benefit from having transaction IDs. The idea is that you generate a transaction ID (which can be as simple as a UUID) as early as possible in your request path. That transaction ID gets passed through every request and stored with the data in whichever systems store it. This way, when there is an error four of five levels deep in your system, you can trace that request back to when the user first clicked the button. Using transaction IDs makes it easier to bridge the gap between systems. If you see an error in InfluxDB, then you can use the transaction ID to find any related messages in Elasticsearch.

Other interesting metrics

Just recording log messages probably won’t provide the whole picture of your system. Here are a few more metrics that may interest you.

Throughput

Keeping track of how quickly your system processes a batch of messages — or finishes some job — can easily illuminate subtler errors. You may also be able to detect errors or slowness in your downstream systems by using throughput monitoring. Maybe a database is acting slower than usual, or your database switched to an inefficient query plan. Well, throughput monitoring is a great way to detect these types of errors.

Success vs Error

Of course, no system will ever have a 100% success rate. Maybe you expect your system to return a success error code at least 95% of the time. Logging your response codes will help you gauge if your expected success rates are dropping.

Response Times

The last interesting metric I’ll discuss is response times. Especially when you’ve got a bunch of developers all pushing to a single code base, it is difficult to realize when you’ve impacted the response times of another endpoint. Capturing the overall response time of every request may give you the insight necessary to realize when response times increase. If you catch it early enough, it may not be hard to identify the commit that caused the issue.

Conclusion

In this article, I’ve talked about the differences between logging and monitoring and why they are both necessary in a robust system. I’ve talked about some monitoring practices as well as some monitoring tools I like using. We experimented with a system and learned how to install and set up some monitoring tools for that system. Finally, I talked about some logging best practices that will make your life much easier and how better logging will make your monitoring tools much more useful.

If you have any questions, comments, or suggestions please leave them in the comments below and together we can all implement better monitors and build more reliable systems!

Logging V Monitoring: Part 1

Brennon Loveless — Wed, 03 Feb 2021 12:56:27 +0000

Introduction

What do you do when your application is down? Better yet: How can you predict when your application may go down? How do you begin an investigation in the most efficient way possible and resolve issues quickly?

Understanding the difference between logging and monitoring is critical, and can make all the difference in your ability to trace issues back to their root cause. If you confuse the two or use one without the other, you’re setting yourself up for long nights and weekends debugging your app.

In this article, we’ll look at how to effectively log and monitor your systems. I’ll tell you about a few good practices that I’ve learned over the years and some interesting metrics that you may want to monitor in your systems. Finally, I’ll show you a small web application that had no monitoring, alerting, or logging. I’ll demonstrate how I fixed the logging and how I’ve implemented monitoring and alerting around those logs.

Everyone has some sort of logging in their applications, even if it’s just writing to a file to review later. By the end of this article, I hope to convince you that logging without monitoring is about as good as no logging at all. Along the way, we can review some best practices for becoming a better logger.

Logging vs Monitoring

For a while, I conflated logging and monitoring. At least, I thought they were two sides of the same coin. I hadn’t considered how uniquely necessary they each were, and how they supported each other.

Logging tells you what happened, and gives you the raw data to track down the issue.

Monitoring tells you how your application is behaving and can alert you when there are issues.

Can’t Have One Without the Other

Let’s consider a system that has fantastic logging but no monitoring. It’s obvious why this doesn’t work. No matter how good our logs are, I guarantee that nobody actively reads them — especially when our logs get verbose or use formatting like JSON. It is impractical to assume that someone will comb all those logs and look for errors. Maybe when we have a small set of beta users, we can expect them to report every error so we can go back and look at what happened. But what if we have a million users? We can’t expect every one of those users to report each error they encounter.

This is where monitoring comes in. We need to put the systems in place that can do the looking up and coordinating for us. We need a system that will let us know when an error happens and, if it is good enough, why that error occurred.

Monitoring

Let’s begin by talking about monitoring goals and what makes a great monitoring system. First, our system must be able to notify us when it detects errors. Second, we should be able to create alerts based on the needs of our system.

We want to lay out the specific types of events that will determine if our system is performing correctly or not. You may want to be alerted about every error that gets logged. Alternatively, you may be more interested in how fast your system responds in cases. Or, you might be focused on whether your error rates are normal or increasing. You may also be interested in security monitoring and what solution suits your cases. For some additional examples of things to monitor, I’d suggest you check out a great article written by Heroku here.

One final thing to consider is how our monitoring system can point us toward solutions. This will vary greatly depending on your application; still, it is something to consider when picking your tools.

Speaking of tools, here are some of my favorite tools to use when I’m monitoring an application. I’m sure there are more specific ones out there. If you’ve got some tools that you really love, then feel free to leave them in the comments!

Elasticsearch: This is where I store my logs. It lets me set up monitors and alerts in Grafana based on log messages. With Elasticsearch, I can also do full-text searches when I’m trying to find an error’s cause.

Kibana: This lets me easily perform live queries against Elasticsearch to assist in debugging.

Grafana: Here, I create dashboards that provide high-level overviews of my applications. I also use Grafana for its alerting system.

InfluxDB: This time-series database records things like response times, response codes, and any interesting point-in-time data (like success vs error messages within a batch).

Pushover: When working as a single engineer in a project, Pushover gives me a simple and cheap notification interface. It directly pushes a notification to my phone whenever an alert is triggered. Grafana also has native support for Pushover, so I only have to put in a few API keys and I am ready to go.

PagerDuty: If you are working on a larger project or with a team, then I would suggest PagerDuty. With it, you can schedule specific times when different people (like individuals on your team) receive notifications. You can also create escalation policies in case someone can’t respond quickly enough. Again, Granafa offers native support for PagerDuty.

Heroku: There are other monitoring best practices in this article from Heroku. If you are within the Heroku ecosystem, then you can look at their logging add-ons (most of which include alerting).

Monitoring Example Project

Let’s look at an example project: a Kubernetes-powered web application behind an NGINX proxy, whose log output and response codes/times we want to monitor. If you aren’t interested in the implementation of these tools, feel free to skip to the next section.

Kubernetes automatically writes all logs to stderr and stdout to files on the file system. We can monitor these logs easily, so long as our application correctly writes logs to these streams. As an aside, it is also possible to send your log files directly to Elasticsearch from your application. But for our example project, we want the lowest barrier to entry.

Now that our application is writing logs to the correct locations, let’s set up Elasticsearch, Kibana, and Filebeat to collect the output from the container. Additional and more up-to-date information can be found on the Elastic Cloud Quickstart page.

First, we deploy the Elastic Cloud Operator and RBAC rules.

kubectl apply -f https://download.elastic.co/downloads/eck/1.3.1/all-in-one.yaml

# Monitor the output from the operator
kubectl -n elastic-system logs -f statefulset.apps/elastic-operator

Next, let’s actually deploy the Elasticsearch cluster.

cat <<EOF | kubectl apply -f -
apiVersion: elasticsearch.k8s.elastic.co/v1
kind: Elasticsearch
metadata:
  name: quickstart
spec:
  version: 7.10.2
  nodeSets:
  - name: default
    count: 1
    config:
      node.store.allow_mmap: false
EOF

# Wait for the cluster to go green
kubectl get elasticsearch

Now that we have an Elasticsearch cluster, let’s deploy Kibana so we can visually query Elasticsearch.

cat <<EOF | kubectl apply -f -
apiVersion: kibana.k8s.elastic.co/v1
kind: Kibana
metadata:
  name: quickstart
spec:
  version: 7.10.2
  count: 1
  elasticsearchRef:
    name: quickstart
EOF

# Get information about the kibana deployment
kubectl get kibana

Review this page for more information about accessing Kibana.

Finally, we’ll add FileBeat, using this guide, to monitor the Kubernetes logs and ship them to Elasticsearch.

cat <<EOF | kubectl apply -f -
apiVersion: beat.k8s.elastic.co/v1beta1
kind: Beat
metadata:
  name: quickstart
spec:
  type: filebeat
  version: 7.10.2
  elasticsearchRef:
    name: quickstart
  config:
    filebeat.inputs:
    - type: container
      paths:
      - /var/log/containers/*.log
  daemonSet:
    podTemplate:
      spec:
        dnsPolicy: ClusterFirstWithHostNet
        hostNetwork: true
        securityContext:
          runAsUser: 0
        containers:
        - name: filebeat
          volumeMounts:
          - name: varlogcontainers
            mountPath: /var/log/containers
          - name: varlogpods
            mountPath: /var/log/pods
          - name: varlibdockercontainers
            mountPath: /var/lib/docker/containers
        volumes:
        - name: varlogcontainers
          hostPath:
            path: /var/log/containers
        - name: varlogpods
          hostPath:
            path: /var/log/pods
        - name: varlibdockercontainers
          hostPath:
            path: /var/lib/docker/containers
EOF

# Wait for the beat to go green
kubectl get beat

Since our application uses NGINX as a proxy, we can use this wonderful module to write the response codes and times to InfluxDB.

Next, you can follow this guide to get Grafana running in your Kubernetes cluster. After that, set up the two data sources we are using: InfluxDB and Elasticsearch.

Finally, set up whatever alert channel notifiers you wish to use. In my case, I’d use Pushover since I’m just one developer. You may be more interested in something like PagerDuty if you need a fully-featured notification channel.

And there you have it! We’ve got an application — one we can set up dashboards and alerts for using Grafana.

This setup can notify us about all sorts of issues. For example:

We detected any ERROR level logs.
We are receiving too many error response codes from our system.
We are noticing our application responding slower than usual.

We did all this without making many changes to our application; and yet, we now have a lot of tools available to us. We can now instrument our code to record interesting points in time using InfluxDB. For example, if we received a batch of 500 messages and 39 of them were unable to be parsed, we can post a message to InfluxDB telling us that we received 461 valid messages and 39 invalid messages. We can then set up an alert in Grafana to let us know if that ratio of valid to invalid messages spikes.

Essentially, anything that is interesting to code should be interesting to monitor; now, we have the tools necessary to monitor anything interesting in our application.

As a small bonus, here is a Pushover alert that I received from a setup similar to the one described above. I accidentally took down my father’s website during an experiment and this was the result.

At this point, I’ll give you a break to digest everything I’ve talked about. In part two I’ll be discussing some logging best practices.

Adding IoT to my home office desk: Part 2

Brennon Loveless — Thu, 19 Nov 2020 22:13:32 +0000

In part one I discussed the first version/Bluetooth version of my desk upgrade.

In this article, I’ll discuss upgrading the desk to use Google Smart Home so I can control my desk with my voice.

WiFi and Google Smart Home

Adding WiFi to the desk was actually pretty simple. I swapped out the microcontroller from the Nordic NRF52 to an ESP32 since the ESP32 has WiFi built in. Most of the control software was portable since it was written in C++, and both devices could be programmed with Platform.IO and the Arduino libraries, including my own tfmini-s library that I wrote to measure the current height of the desk.

Here is the necessary system architecture to get my desk to talk to Google. Let’s first talk about the interaction between myself and Google.

Full architecture/technology diagram

So, the desk was now WiFi enabled, then it was time to figure out how to interface with Google Smart Home. Google Smart Home is controlled through Smart Home Actions. What is interesting about Smart Home actions is that your service acts as the OAuth2 server and not as a client. Most of the work that I put into the server was related to implementing the OAuth2 Node.js Express app, which will eventually find its way up to Heroku and act as the proxy between Google and my desk.

I was lucky enough that there is a decent implementation of a server through two libraries. The first was the underlying server implementation, called node-oauth2-server and found here. The second was the adapter to hook the library up to express, called express-oauth-server and found here. The example in the GitHub repo for the adapter left a lot to be desired and didn’t really work. It took me a while to reverse engineer how to use the two libraries together. Now I have a decent model that supports registering accounts, refreshing tokens, and validating tokens. The following code snippet shows all the functions that are necessary for the OAuth2 server but you can see the full file here.

const { Pool } = require("pg");
const crypto = require("crypto");
const pool = new Pool({
   connectionString: process.env.DATABASE_URL
});

module.exports.pool = pool;
module.exports.getAccessToken = (bearerToken) => {...};
module.exports.getClient = (clientId, clientSecret) => {...};
module.exports.getRefreshToken = (bearerToken) => {...};
module.exports.getUser = (email, password) => {...};
module.exports.getUserFromAccessToken = (token) => {...};
module.exports.getDevicesFromUserId = (userId) => {...};
module.exports.getDevicesByUserIdAndIds = (userId, deviceIds) => {...};
module.exports.setDeviceHeight = (userId, deviceId, newCurrentHeight) => {...};
module.exports.createUser = (email, password) => {...};
module.exports.saveToken = (token, client, user) => {...};
module.exports.saveAuthorizationCode = (code, client, user) => {...};
module.exports.getAuthorizationCode = (code) => {...};
module.exports.revokeAuthorizationCode = (code) => {...};
module.exports.revokeToken = (code) => {...};

Next is setting up the actual express app. Below are the endpoints necessary for the OAuth server but you can read the full file here.

const express = require("express");
const OAuth2Server = require("express-oauth-server");
const bodyParser = require("body-parser");
const cookieParser = require("cookie-parser");
const flash = require("express-flash-2");
const session = require("express-session");
const pgSession = require("connect-pg-simple")(session);
const morgan = require("morgan");

const { google_actions_app } = require("./google_actions");
const model = require("./model");
const { getVariablesForAuthorization, getQueryStringForLogin } = require("./util");
const port = process.env.PORT || 3000;

// Create an Express application.
const app = express();
app.set("view engine", "pug");
app.use(morgan("dev"));

// Add OAuth server.
app.oauth = new OAuth2Server({
   model,
   debug: true,
});

// Add body parser.
app.use(bodyParser.urlencoded({ extended: false }));
app.use(bodyParser.json());
app.use(express.static("public"));

// initialize cookie-parser to allow us access the cookies stored in the browser.
app.use(cookieParser(process.env.APP_KEY));

// initialize express-session to allow us track the logged-in user across sessions.
app.use(session({...}));

app.use(flash());

// This middleware will check if user's cookie is still saved in browser and user is not set, then automatically log the user out.
// This usually happens when you stop your express server after login, your cookie still remains saved in the browser.
app.use((req, res, next) => {...});

// Post token.
app.post("/oauth/token", app.oauth.token());

// Get authorization.
app.get("/oauth/authorize", (req, res, next) => {...}, app.oauth.authorize({...}));

// Post authorization.
app.post("/oauth/authorize", function (req, res) {...});
app.get("/log-in", (req, res) => {...});
app.post("/log-in", async (req, res) => {...});
app.get("/log-out", (req, res) => {...});
app.get("/sign-up", async (req, res) => {...});
app.post("/sign-up", async (req, res) => {...});
app.post("/gaction/fulfillment", app.oauth.authenticate(), google_actions_app);
app.get('/healthz', ((req, res) => {...}));
app.listen(port, () => {
   console.log(`Example app listening at port ${port}`);
});

There is quite a bit of code there but I’ll explain the highlights. The two routes that are used for the OAuth2 server are /oauth/token and /oauth/authorize. These are used for getting a new token or refreshing expired tokens. Next is getting the server to respond to the actual Google Action. You’ll notice that the /gaction/fulfillment endpoint points to a google_actions_app object. Google sends requests to your server in a specific format and provides a library to help you process those requests. Below are the functions necessary to communicate with Google but you can view the entire file here. Finally, there is a /healthz endpoint that I’ll talk about at the end of this article.

The /gaction/fulfillment endpoint uses a middleware called app.oauth.authenticate() and all of my hard work getting the OAuth2 server working was so that this middleware would work. This middleware validates that the Bearer token that Google provides us references a valid user and has not expired. Next, the route sends the request and response to a google_actions_app object. Google sends requests to your server in a specific format and provides a library to help you parse and process those requests. Below are the functions necessary to communicate with Google but you can view the entire file here.

const { smarthome } = require('actions-on-google');
const mqtt = require('mqtt');
const mqtt_client = mqtt.connect(process.env.CLOUDMQTT_URL);

const model = require('./model');
const { getTokenFromHeader } = require('./util');

mqtt_client.on('connect', () => {
   console.log('Connected to mqtt');
});

const updateHeight = {
   "preset one": (deviceId) => {
       mqtt_client.publish(`/esp32_iot_desk/${deviceId}/command`, "1");
   },
   "preset two": (deviceId) => {
       mqtt_client.publish(`/esp32_iot_desk/${deviceId}/command`, "2");
   },
   "preset three": (deviceId) => {
       mqtt_client.publish(`/esp32_iot_desk/${deviceId}/command`, "3");
   },
};

const google_actions_app = smarthome({...});
google_actions_app.onSync(async (body, headers) => {...});
google_actions_app.onQuery(async (body, headers) => {...});
google_actions_app.onExecute(async (body, headers) => {...});
module.exports = { google_actions_app };

When you add a Smart Action to your Google account, Google will then perform a sync request. This request lets Google know what devices your account has access to. The next is a query request which is how Google queries your devices to determine their current state.

When you first add a Google Action to your Smart Home account, you’ll notice that Google first sends a sync request and then a query request to get the holistic view of your devices. The final request is an execute request which is how Google tells your devices to actually do things.

Google Smart Home Device Traits

Google uses device traits to control your devices. Google uses these traits to provide UI elements on your Google devices as well as to build communication patterns for voice control. Some of the traits include ColorSetting, Modes, OnOff, and StartStop. It took me a while to decide which trait would work best for my application, but I later selected on Modes.

You can think of modes as a drop down where you can select one of N predefined values, or height presets, in my case. I called my Mode "height" and the possible values are "preset one", "preset two", and "preset three". This allows me to control my desk by saying "Hey Google, set my desk height to preset one," and Google will send the appropriate execute request to my system. You can read more about Google device traits here.

Off To Production

Finally, Google Smart Home and my computer were communicating. Up until this point, I was using ngrok to run my express server locally. Now that I finally had my server working well enough it was time to make it accessible to Google at all times. This meant using Heroku to host my app. Heroku is a PaaS provider that makes it easy to deploy and manage applications.

One of the major benefits of using Heroku is the add-ons. Heroku add-ons made it super simple to add a CloudMQTT and Postgres server to my application. Another benefit of using Heroku is how simple it is to build and deploy. Heroku automatically detects what code you are using and builds/deploys your code for you. You can find more information about this by reading about Heroku Buildpacks. In my case whenever I push code to the Heroku git remote it will install all of my packages, strip out any development dependencies, and deploy my application all by simply issuing "git push heroku main".

With a few clicks I had CloudMQTT and Postgres available to my app, and I only needed to use a few environment variables to integrate those services with my application. Everything I’ve done on Heroku was built for free. However, CloudMQTT is a third-party add-on and costs $5/month.

I believe the need for Postgres is self explanatory but CloudMQTT deserves a little more explanation.

From The Internet to a Private Network, The Hard Way

There are a few ways to expose an application, or in my case an IoT device, to the internet. The first is to open a port in my home network to expose the device to the internet. In this case, my Heroku Express app would post a request to my device by using a public IP address. This would require me to have a public static IP address as well as a static IP address for my ESP32. My ESP32 would also have to act as an HTTP server and be listening all the time for instructions from Heroku. This is a lot of overhead for a device that will only receive instructions a few times a day.

The second way is called "hole-punching". This is how you can use a third-party external server to expose a device to the internet without having to use port-forwarding. Your device basically connects to the server, which establishes an open port. Then, the other service can connect directly to your internal device by retrieving the open port from the external server. Finally, it connects directly to the device using that open port. (This may or may not be entirely correct since I only read part of a paper about it.)

A lot goes into "hole-punching" and I don’t fully understand it. However, if you are curious, there are some interesting articles that explain it more. These are the two articles that I read to better understand "hole-punching": Wikipedia and a paper from MIT written by Bryan Ford et al.

From The Internet to a Private Network, The IoT Way

I wasn’t very happy with those two solutions. I’ve added many smart devices to my home and I’ve never had to open a port on my router so port forwarding was out. Also, hole-punching seems far more difficult than what I’m looking to implement and is better suited for P2P networks. Through further research I discovered MQTT and found out that it is the protocol for IoT. It has some benefits like low power, configurable resiliency, and it doesn’t require port forwarding. MQTT is a publisher/subscriber protocol which means that the desk is a subscriber of a specific topic and the Heroku app is a publisher to that same topic.

So Google communicates with Heroku, that request is parsed to determine the requested device and what its new state/mode is to be. Then, the Heroku app publishes a message to the CloudMQTT server, deployed as an add-on on Heroku, telling the desk to go to a new preset. Finally, the desk subscribes to a topic and receives the message that the Heroku app published, and the desk adjusts its height to match the request! You’ll notice in the google_actions_app file that there is an updateHeight function which publishes a single number to an MQTT topic for a specific device ID. This is how the Heroku app publishes to MQTT asking the desk to move.

The final step is to receive the message on the ESP32 and move the desk. I’ll show some highlights of the desk code below but the full source code is here.

void setup()
{
 Serial.begin(115200);
...
 tfminis.begin(&Serial2);
 tfminis.setFrameRate(0);

...

 state_machine = new StateMachine();
 state_machine->begin(*t_desk_height, UP_PWM_CHANNEL, DOWN_PWM_CHANNEL);

 setup_wifi();

 client.setServer(MQTT_SERVER_DOMAIN, MQTT_SERVER_PORT);
 client.setCallback(callback);
...
}

When the desk is booted up we first begin communication between the TFMini-S, which is a distance sensor, to get the current desk height. We then set up a state machine for the actual desk movement. The state machine receives commands through MQTT and then is responsible for aligning the user’s request with the actual height of the desk read from the distance sensor. Finally, we connect to the WiFi network, connect to the MQTT server, and configure the callback for any data we receive on the MQTT topic we are subscribed to. I’ll show the callback function next.

void callback(char *topic, byte *message, unsigned int length)
{
 ...

 String messageTemp;

 for (int i = 0; i < length; i++)
 {
   messageTemp += (char)message[i];
 }

 if (messageTemp == "1") {
   state_machine->requestStateChange(ADJUST_TO_PRESET_1_HEIGHT_STATE);
 }

 if (messageTemp == "2") {
   state_machine->requestStateChange(ADJUST_TO_PRESET_2_HEIGHT_STATE);
 }

 if (messageTemp == "3") {
   state_machine->requestStateChange(ADJUST_TO_PRESET_3_HEIGHT_STATE);
 }
...
}

The state machine registers a state change received on the MQTT topic. Then, the state machine in the main loop processes the new state.

void loop()
{
 if (!client.connected())
 {
   reconnect();
 }
 client.loop();
 state_machine->processCurrentState();
}

The main loop does a few things: First, it reconnects to the MQTT server if it wasn’t already connected. Then, it processes any data it received on the subscribed MQTT topic. Finally, it works to put the desk into the correct location according to the state requested over the MQTT topic.

There you have it! My desk is completely voice-controlled and communicating with Google to receive commands!

Final Notes

The last endpoint that I didn’t discuss is the /healthz endpoint. This is because Google expects you to respond rather quickly and booting up a Heroku application upon every request wasn’t going to work for me. I set up a ping service to ping the /healthz endpoint every minute to keep the service alive and ready to respond on Heroku. If you plan on doing something like this, then remember that this will use up all of your available free dyno hours. This is fine for now since this is the only app I'm running on Heroku. Alternatively, for $7/month, you can upgrade to Heroku’s Hobby plan, which keeps the app "alive".

Conclusion

Building an IoT device has a lot of overhead to get started. I constructed the actual hardware, built the control circuitry, set up an MQTT server, built an Express OAuth2 server, and learned to interface with Google Smart Home through Actions. The initial overhead was a lot but I feel like I’ve accomplished a lot as well! Not to mention that the MQTT server, Express OAuth2 app server, and Google Smart Home Actions are all reusable. I’m really interested in the Smart Home space, and I may try to expand my IoT devices repertoire to include some sensors that can monitor various things around my house and report back over MQTT. Soil monitor sensors, temperature sensors, and light sensors will be a lot of fun to monitor and analyze.

Where to Go Next

The way I’m measuring the height of the desk right now is flakey at best. I’m using an IR distance sensor called a TFMini-S which mostly works. I’ve noticed that the height of the desk changes a little bit throughout the day as the ambient lighting of the room changes. I’ve ordered a rotary encoder so I can count the number of turns the rod running through the desk actually makes. This should give me much more accurate movements any time of the day. I also have access to a server that I host out of a basement somewhere that I might investigate running my own Mosquitto MQTT server, Node-RED server, and Express OAuth2 app if I’m feeling up to hosting something myself. Finally, right now all the electronics are just out in the open on my desk. I plan to enclose those so everything looks nice and tidy!

Thanks for reading! Here are all the links from above for easy reference.

Adding IoT to my home office desk: Part 1

Brennon Loveless — Thu, 19 Nov 2020 21:55:36 +0000

Introduction

In this article, I will show you how I converted my manual hand crank desk into an automated IoT connected desk. I’ll be talking about how to size and pick motors, and how to connect your custom IoT devices to Google using Heroku as a public interface.

In short, there are two sides of this tech project: the first is to get from Google to Heroku using voice commands, and the second is to get from Heroku to the desk using MQTT. MQTT is the protocol of IoT, and I’ll explain some of the reasons why it is a good solution for IoT as well as some hurdles that it will help you overcome.

First and foremost, I’m doing this just for fun! I’m completely open to suggestions and I’m more than happy to learn something new from you, so feel free to leave me any suggestions. Hopefully you’ll find something entertaining in this article and that motivates you to get out there and build something!

With that being said, let’s get started!

The original hand crank for the desk

Hardware

The first, and arguably the most difficult, part was to modify the desk. In its past life, the desk had a removable hand crank that sat at the edge of the desk. Initially I thought about attaching something to the hand crank port so that the desk would remain unaltered. I purchased various gears to figure out how to attach the motor to the desk, but to no avail. Then I had an idea: There is a rod that runs the length of the desk that connects the two legs of the desk so they can be raised and lowered at the same time. If I fastened a gear that fit around the rod, then I would be able to use a belt to connect the rod to a motor. I would also still be able to add a motor to the desk without altering the desk all that much.

Torque Matters

I ordered the necessary gears and belt, and then searched Amazon for “High Torque Motor”. Lo and behold, I found a multitude of motors that matched my specific needs — or so I thought. I bought a small “high torque” motor and waited nearly a month for the gears to ship from China. I was so excited when they arrived! I couldn’t wait for the weekend to put it all together and finally have my motorized desk.

Things did not go according to plan. I spent the day cutting a hole in a metal shield on the desk to run the belt through. At the time, I only had manual tools, so it took longer than I’m willing to admit. As it got closer to the end of the day, I finally finished putting everything together and was ready to try out the desk.

I plugged in the motor, turned the voltage up on my bench power supply, and… nothing happened. A few moments later, the motor started spinning and grinding the teeth off the belt I purchased. I learned two important lessons from this: First of all, the belt was obviously not up to the challenge and a “high torque” motor doesn’t mean “I can lift anything in the world”. Secondly, look at how small that motor is compared to my fingers. It’s tiny!

The photo on the left is the motor and the belt. Top right is the gear attached to the desk (you’ll see later more of what is going on here). Bottom right is the motor in position on the desk.

An appropriate motor

I needed to do some math to calculate how much torque was required to lift the desk so I could select the right motor. Off to Google for this one!

I was surprised to discover how simple it was to calculate the torque necessary.

T = F * r

Or torque is a function of force multiplied by the lever arm length.

Well, I had a lever arm (the hand crank) now I just needed a way to measure the force necessary to easily turn the lever arm. I loaded up my desk, tied a milk jug to the handle, and gradually added water to it until the lever arm spun. Then, I rotated the handle to the top with the filled milk jug and made sure that the weight could easily turn the handle. I discovered that the lever arm was 11cm and the force required was 4 lbs. I used this calculator to figure out that I needed a motor capable of providing at least 19.95 kg/cm of torque. Let the shopping begin!

I decided to make irreversible changes to the desk. I also knew that the rod that ran through the middle of the desk was hollow. I searched for a double shaft motor so I could cut the rod into pieces and reassemble it with the motor in the middle. I bought two 20 kg/cm motors to ensure I had plenty of torque necessary to lift the desk.

Another beautiful Saturday rolled around and I hacked my desk to pieces. I split the rod in four places and filed down the shafts of the motors so they could be used to connect the rod back together again. I cut more holes in the metal shield for the two new motors to fit in. There was no belt this time, and the motors connected directly to the rod so these holes were quite large. As the evening approached I put all the pieces back together and loaded my desk with my office equipment.

The top two photos are the motors completely installed in the desk. The bottom photo is the rod that runs the length of the desk with the motors integrated with it.

I wired up the motors and connected them to my bench power supply. Then, I turned it on and… THE DESK MOVED! I was more confident this time since I sized the motors appropriately. I had also doubled up on the motors just to be sure, but seeing it move was an awesome feeling.

Let me tell you though, the desk was slow. Like really slow. I took a video to show one of my friends that it worked and had to use the time-lapse feature of my iPhone so he didn’t have to watch a five-minute video of my desk going from a sitting to a standing position. It was slow enough that I could start the desk movement, go grab a cup of coffee, come back, and still have to wait a minute before it reached the standing position.

RPM Matters, Final Version

Finally, what I learned boils down to two things: RPM and torque. I had nailed down the torque and now I just needed to find a motor with high enough RPM’s while maintaining the torque necessary to lift the desk.

This wasn’t too hard to do, but I couldn’t find a double shaft motor like I had used previously so I had to find a 90 degree 1:1 gear box that could convert the motor into a double shaft motor.

Long story short, after another month of waiting for the perfect gear box to show up from China, and another Saturday, I had the desk moving at the speed I wanted!

My latest high torque motor on the left. Installed on the right.

A little more hardware and a lot more software

I wasn’t satisfied with a huge bench power supply on my desk at all times just to adjust the height of my desk. I was also swapping the power leads of the supply in order to reverse the direction of the desk. Not a big deal but the goal of the desk project was to use up and down buttons as well as several presets to tell the desk to adjust to my preferred height.

Bluetooth

My first foray was to add Bluetooth to the desk. After all, it seems that nearly every device has Bluetooth these days. The phone also seems like a great interface for controlling something like this.

I purchased a motor controller board, a Nordic NRF52 dev board (eventually I switch the Bluetooth board to an ESP32), some distance measuring sensors, and began mucking around with some control firmware.

I’ll post links at the end of the article for all the software and firmware that I wrote for this project. Feel free to comment on that code as well since I’m in no way a firmware engineer and would love some pointers!

As a quick introduction, the ESP32 is written in C++ using Arduino libraries to communicate with the BLE Terminal app on the phone. Setting up and configuring BLE is pretty complicated. Initially, you need to create all the characteristics for the values you’d like to control over BLE. Think of a characteristic like a single variable in your code. BLE wraps this variable in a bunch of handlers to retrieve and set the value of this variable.

Then, your characteristics are packaged up in a service with a custom UUID that you provide to make your service unique and identifiable from the app. Finally, you must add this service to the advertisement payload in order for your service to be discoverable by other devices. When a remote device connects to your service and sends data via a characteristic, the desk will recognize that a user wants the desk to adjust to another preset height and will begin its work.

In order to adjust the height, the desk has an TFMini-S LiDAR sensor mounted to the bottom to determine the current height. This sensor is funny because it is named LiDAR but doesn’t actually use a laser. It uses an LED and optics to determine the time-of-flight of the IR light. Anyway, the sensor determines the current height of the desk. Then, the control board determines the difference between the current height and the requested height, and activates the motor to spin in the necessary direction. Some of the code highlights are below but you can read the entire file here.

void setup()
{
   Serial.begin(115200);
   Serial2.begin(TFMINIS_BAUDRATE);
   EEPROM.begin(3); // used for saving the height presets between reboots

   tfminis.begin(&Serial2);
   tfminis.setFrameRate(0);

   ledcSetup(UP_PWM_CHANNEL, PWM_FREQUENCY, PWM_RESOLUTION);
   ledcAttachPin(UP_PWM_PIN, UP_PWM_CHANNEL);

   ledcSetup(DOWN_PWM_CHANNEL, PWM_FREQUENCY, PWM_RESOLUTION);
   ledcAttachPin(DOWN_PWM_PIN, DOWN_PWM_CHANNEL);

   state_machine = new StateMachine();
   state_machine->begin(*t_desk_height, UP_PWM_CHANNEL, DOWN_PWM_CHANNEL);

   BLEDevice::init("ESP32_Desk");
  ...

   BLEServer *p_server = BLEDevice::createServer();
   BLEService *p_service = p_server->createService(BLEUUID(SERVICE_UUID), 20);

   /* ------------------- SET HEIGHT TO PRESET CHARACTERISTIC -------------------------------------- */
   BLECharacteristic *p_set_height_to_preset_characteristic = p_service->createCharacteristic(...);
   p_set_height_to_preset_characteristic->setCallbacks(new SetHeightToPresetCallbacks());
   /* ------------------- MOVE DESK UP CHARACTERISTIC ---------------------------------------------- */
   BLECharacteristic *p_move_desk_up_characteristic = p_service->createCharacteristic(...);
   p_move_desk_up_characteristic->setCallbacks(new MoveDeskUpCallbacks());
   /* ------------------- MOVE DESK UP CHARACTERISTIC ---------------------------------------------- */
   BLECharacteristic *p_move_desk_down_characteristic = p_service->createCharacteristic(...);
   p_move_desk_down_characteristic->setCallbacks(new MoveDeskDownCallbacks());
   /* ------------------- GET/SET HEIGHT 1 CHARACTERISTIC ------------------------------------------ */
   BLECharacteristic *p_get_height_1_characteristic = p_service->createCharacteristic(...);
   p_get_height_1_characteristic->setValue(state_machine->getHeightPreset1(), 1);
   BLECharacteristic *p_save_current_height_as_height_1_characteristic = p_service->createCharacteristic(...);
   p_save_current_height_as_height_1_characteristic->setCallbacks(new SaveCurrentHeightAsHeight1Callbacks());
   /* ------------------- GET/SET HEIGHT 2 CHARACTERISTIC ------------------------------------------ */
  ...
   /* ------------------- GET/SET HEIGHT 3 CHARACTERISTIC ------------------------------------------ */
  ...
   /* ------------------- END CHARACTERISTIC DEFINITIONS ------------------------------------------ */
   p_service->start();

   BLEAdvertising *p_advertising = p_server->getAdvertising();
   p_advertising->start();

   xTaskCreate(
       updateDeskHeight,     // Function that should be called
       "Update Desk Height", // Name of the task (for debugging)
       1024,                 // Stack size
       NULL,                 // Parameter to pass
       5,                    // Task priority
       NULL                  // Task handle
   );
}

There is a lot more going on in the main file but this code has enough context for us to see what is happening. You’ll notice that we are creating and configuring all the BLE callbacks for all the characteristics, including moving the desk manually, setting/retrieving the preset values, and most importantly, adjusting the desk to a specific preset.

The image below shows me interacting with that characteristic to adjust the desk height. The last piece of the puzzle is the state machine, which knows the current height of the desk, the requested height of the desk from the user, and works to align those two pieces of data.

So I finally had the desk doing everything I wanted. I could save heights into presets and recall those heights to move the desk into my favorite positions. I was using a BLE Terminal app on my phone and computer so I could send the raw messages to my desk in order to control its position. This worked but I knew that the battle with BLE was just beginning. In order to have a seamless interface with my desk I would also need to learn how to write an iOS app so I didn’t have to remember the HEX codes to send to my desk to save a preset and recall a position.

The raw bluetooth interface… all that was left at this point was to learn how to program an iOS app…

Then my wife said something that would change everything… "What if you could control it with your voice?"

In addition to being way cooler, and adding to our growing list of Google Assistant devices in our house, I wouldn’t have to write an iOS app to control it. I also wouldn’t have to take my phone out of my pocket to set the desk height. The little wins!

This article is getting a little long so I’ll split this into a second article where I discuss adding Google Smart Home IoT here.