Advanced debugging of OpenWhisk actions

Sometimes it is helpful to develop and test an action locally before deploying to the cloud. In this article, I’ll describe how to test an Apache OpenWhisk action locally using Docker and a helper Python script. This is an advanced feature. For a more friendly debugging experience, you may want to consider using the OpenWhisk Debugger instead.

What follows will work for Node.js, Python and Swift actions. I will show you an example for each of these language runtimes. I’ll start with a Node.js action. In OpenWhisk, each action runs inside a Docker container. The system currently interacts with the action inside the container via a REST interface. There are two endpoints in each action container:

1. /init: receives the code to execute inside the container.
2. /run: receives the arguments for the action and runs the code.

Bare in mind that this interface is not officially documented and may change in the future. It is not difficult however to reverse engineer the protocol if one is determined to do so. This Python script makes it obvious and is convenient for the purpose of testing one’s code locally before deploying it to OpenWhisk. Download the script to run through the rest of the article:

> wget --no-check-certificate https://raw.githubusercontent.com/apache/incubator-openwhisk/master/tools/actionProxy/invoke.py
> chmod +x invoke.py

The script assumes that your Docker host is either running on localhost or that your environment defines the DOCKER_HOST property. Further, it assumes that the action container is accessible on port 8080.

Working with source code

Let’s create a Node.js action to run.

> cat hello.js 
function main(args) {
    const name = args.name || "stranger"
    const greeting = "Hello " + name + "!"
    console.log(greeting)
    return {"greeting": greeting}
}

We can run the hello.js code locally without an OpenWhisk deployment by explicitly creating a container to run this code, just as the OpenWhisk system would do.

> docker run -i -t -p 8080:8080 openwhisk/nodejs6action

Now we have a running container ready to receive and execute Node.js code. From another terminal window, initialize the container with hello.js.

> invoke.py init hello.js 
{"OK":true}

Notice the response is OK. It is possible to initialize the container with "bad" code - in which case an appropriate error is returned. It is important to note that once a container fails to initialize it is unusable. You must tear down and restart the action container.

Now that the container is initialized, you can invoke the action by sending it arguments.

> invoke.py run '{"name":"manual invoke"}'
{"greeting":"Hello manual invoke!"}

You can reinitialize the container with new code and rerun. As long as the container has not failed, it is generally reusable. So let’s reinitialize the container, this time using a non-standard entry point.

> cat niam.js
function niam(args) {
    const name = args.name || "stranger"
    const greeting = "Hello " + name + "!"
    console.log(greeting)
    return {"greeting": greeting}
}
# notice passing in an additional parameter which is the entry point
> invoke.py init niam.js niam
{"OK":true}
> invoke.py run '{"name":"again"}'
{"greeting":"Hello again!"}

If you’re watching the output of the container, you will see some messages appearing to the console. The example actions above log the greeting. The container also injects markers at the end of each activation (to both stdout and stderr) to assist the system in extracting logs out of the action container and determining when the logs are flushed.

Working with Zip files

It is possible to initialize the container with a Zip file that contains the code to run as well as additional dependencies. It is here where the value of having direct access to the container begins to show. For example, below is a Node.js action which receives some text as an input argument, writes that text out to a file, calls a native executable to process the file and then ingests the resultant file to produce the action result. Several things may go wrong with this action. Maybe the file is not written to the location you expect. Or maybe the native executable does not run properly inside the container. Maybe its output is not where you expect it... With direct access to the container, you may inspect it and see what went wrong and even experiment with fixing it live.

Here is the example Node.js action in a file called index.js.

var fs = require('fs'),
    spawn = require('child_process').spawn;
function main(msg) {
    // write the received "txt" to a file in "/tmp"
    const inputFile = `/tmp/${msg.id}.txt`;
    fs.writeFileSync(inputFile, msg.txt);
    console.log('msg written to file', inputFile);
    return new Promise(function(resolve, reject) {
            // spawn process to run native executable
            const exec = spawn('reverse.sh', [ inputFile ]);
            exec.on('error', (error) => {
                    console.log(error)
                    reject({exitCode: -1});
                });
            exec.on('close', (code) => {
                    if (code == 0) {
                        // if the process succeeds
                        // ingest the file that it generated...
                        const reversed = fs.readFileSync(
                            `/tmp/${msg.id}.txt-reversed`,
                             {encoding: 'utf-8'});
                        // ... and return it as the action result
                        resolve({reversed: reversed.trim()});
                    } else {
                        reject({exitCode: code});
                    }
                });
    });
}
exports.main = main;

The action delegates the actual processing to an executable called reverse.sh which in this case reverses each line of text that is receives. While I'm using a shell script for illustration purposes, this could be any executable including third party binaries.

> cat reverse.sh
#!/bin/bash
cat $1 | rev > $1-reversed

We can first test this code locally and confirm that it works.

> node                            # start Node.js interpreter
> require('./index.js').main({id:"foo", txt:"abcdef"})
msg written to file /tmp/foo.txt
Promise { <pending> }
[Control-D]                       # exit the interpreter 
> cat /tmp/foo.txt-reversed
fedcba

So all appears to be in order. The action code checks out locally. Let’s bundle it to run it as an OpenWhisk action. We’ll need a package.json file.

{
  "name": "reverse",
  "version": "1.0.0",
  "main": "index.js",
  "dependencies" : {}
}
> zip reverse.zip index.js reverse.sh package.json

Now we can run the action inside the OpenWhisk container as before, expect we will specify the Zip file as an argument to init instead of the .js file.

> invoke.py init reverse.zip 
{"OK":true}

And now the container is ready to receive the arguments and run the action.

> invoke.py run '{"id":"foo", "txt":"abcdef"}'
{"error":{"exitCode":-1}}

Error! What happened? The action ran locally why did it fail inside the container? This can be frustrating to unravel without access to the container even though the action logs might give us a hint of what went wrong.

msg written to file /tmp/foo.txt
{ Error: spawn reverse.sh ENOENT
    at exports._errnoException (util.js:1026:11)
    at Process.ChildProcess._handle.onexit (internal/child_process.js:193:32)
    at onErrorNT (internal/child_process.js:359:16)
    at _combinedTickCallback (internal/process/next_tick.js:74:11)
    at process._tickCallback (internal/process/next_tick.js:98:9)
  code: 'ENOENT',
  errno: 'ENOENT',
  syscall: 'spawn reverse.sh',
  path: 'reverse.sh',
  spawnargs: [ '/tmp/foo.txt' ] }

So it’s evident that the script reverse.sh was not found. But we know that it's in the Zip file. We can confirm that it exists inside the container by docker exec into the running instance.

> docker exec -it `docker ps | grep nodejs6action | \
  cut -f 1 -d ' '` bash
> find . -name reverse.sh
./LK0ADcnU/reverse.sh

Once inside the container, we can confirm that the script exists and it is in the same directory as index.js. But the action code is running out of a different directory than the node process! So while the script exists, the index.js code must refer to it relative to the module's directory name. This can rectified using the __dirname. So we change one line of our code and repeat the steps above to Zip and ship the code into the container.

# replace this line of code in index.js as follows
- const exec = spawn('reverse.sh', [ inputFile ]);
+ const exec = spawn(__dirname + '/reverse.sh', [ inputFile ]);
> zip reverse.zip index.js reverse.sh package.json
> invoke.py init reverse.zip 
{"OK":true}
> invoke.py run '{"id":"foo", "txt":"abcdef"}'
{"reversed":"fedcba"}

Rinse and repeat

The same invoke.py script can be used with Python and Swift actions.

Here’s a Python example using this sample action.

> docker run -p 8080:8080 openwhisk/pythonaction > /dev/null 2>&1 &
> invoke.py init hello.py
OK
> invoke.py run '{"name":"python"}'
{
  "greeting": "Hello python!"
}

And now Swift using this sample action.

> docker run -p 8080:8080 openwhisk/swift3action > /dev/null 2>&1 &
> invoke.py init hello.swift
OK
> invoke.py run '{"name":"swift"}'
{
  "greeting": "Hello swift!"
}

Parting words

While I didn’t show an example for Java actions, the same process will work for all runtimes supported by Apache OpenWhisk. Keep in mind however that the feature described here is not intended to be used as a general debugging mechanism; for that npm wskdb is usually the way to go. This article requires Docker expertise as you'll be bringing up and tearing down containers explicitly. You also need Python installed to use the referenced script. Lastly, the exposition uses an undocumented interface which may change. That said, the information herein may prove useful when you're really stuck.

Happy whisking.