6. Logging

Most often, the types of problems you will need to troubleshoot have to do specifically with your application code, and not the execution environment itself. The ZeroCloud execution environment tends to be less verbose about errors, in order to not leak potentially sensitive information to a client. Showing stacktraces, for example, is not always a good idea.

The lack of verbosity is there for a reason, but this of course can make troubleshooting and debugging difficult. This tutorial aims to illustrate what types of errors are often encountered when developing applications for ZeroCloud and what you can do catch and log these errors to aid you in debugging.

Jump to a section:

6.1. Environment Setup

See Setting up a development environment before continuing. If you’ve already done this, feel free to jump ahead to the next section.

6.2. The stderr device

The best way to log information or errors in your application is to use the stderr device. We’ll see how to do that by building a very simple “hello, world”zapp. Just by adding stderr to the application config, any crashes in the application code due to uncaught exceptions, or syntax errors will be logged. We can also explicitly log information to stderr by writing to the sys.stderr device or to the file /dev/stderr. In this guide, we’ll go through some examples to cover all of these cases.

To start with, create an application template with zpm:

$ zpm new
Created './zapp.yaml'

Open zapp.yaml in your favorite text editor. Modify the meta section, and set logtest for the name:

meta:
  Version: ""
  name: "logtest"
  Author-email: ""
  Summary: ""

Also modify the execution section, which by default looks something like this:

execution:
  groups:
    - name: ""
      path: file://python2.7:python
      args: ""
      devices:
      - name: python2.7
      - name: stdout

Edit the execution section and give the execution a name, args, and a stderr device. For example:

 execution:
   groups:
     - name: "logtest"
       path: file://python2.7:python
       args: "logtest.py"
       devices:
       - name: python2.7
       - name: stdout
       - name: stderr
         path: swift://~/logs/logtest.log

The group name can be anything you like. For this example, we just call it “logtest”. The args should at least be the name of a Python script. We will write that script below. For this example, we will just call it logtest.py.

The stderr device is one of the special built-in devices that any ZeroCloud application can use. We need to specify a Swift object path to write to in order to capture error output. In this example, we’ve chosen logtest.log in the logs container.

Finally, modify the bundling the section to include logtest.py:

bundling: ["logtest.py"]

6.3. Logging syntax errors

Let’s make our script into a basic “hello, world” application which has some syntax errors. Create the file logtest.py and add the following code:

print "hello, world"
foo = [1, 2, 3
print foo

The syntax error is the missing closing bracket on line 2.

Before we deploy, we’ll need to create the log container:

$ swift post logs

Now let’s bundle, deploy, and run the application to see what happens:

 $ zpm bundle
 created logtest.zapp
 $ zpm deploy logtest logtest.zapp
 $ curl -X POST -H "X-Zerovm-Execute: 1.0" -H "X-Zerovm-Source: swift://~/logtest/logtest.zapp" -H "X-Auth-Token: $OS_AUTH_TOKEN" $OS_STORAGE_URL
 (no output)

Notice that there is no output. Adding the -i/--include flag in the curl command will show us the HTTP response headers and give us a clue about what went wrong.

$ curl -i -X POST -H "X-Zerovm-Execute: 1.0" -H "X-Zerovm-Source: swift://~/logtest/logtest.zapp" -H "X-Auth-Token: $OS_AUTH_TOKEN" $OS_STORAGE_URL

The output should look something like this:

 HTTP/1.1 200 OK
 X-Nexe-Retcode: 1
 X-Nexe-System: logtest
 X-Nexe-Cdr-Line: 2.289, 2.260, 0.04 2.00 1021 66644156 34 88 0 0 0 0
 X-Zerovm-Device: stdout
 X-Nexe-Policy: Policy-0
 X-Nexe-Validation: 2
 Content-Length: 0
 X-Nexe-Etag: /dev/stdout d41d8cd98f00b204e9800998ecf8427e
 Connection: close
 Etag: 433f8ee1c8da2c16bb625e87a1e89e7f
 X-Timestamp: 1415976829.81199
 X-Nexe-Status: ok
 Date: Fri, 14 Nov 2014 14:53:49 GMT
 Content-Type: text/html
 X-Chain-Total-Time: 2.289
 X-Trans-Id: txac6be961d72141ba9dbdf-005466177b

The most important line here is highlighted: X-Nexe-Retcode: 1. This tells us that our application (not the execution environment; this is an important distinction) exited with a status code of 1. In other words, there was probably a crash.

Let’s download the log and see what it says:

$ swift download logs logtest.log
logtest.log [auth 0.030s, headers 0.038s, total 0.038s, 0.011 MB/s]
$ cat logtest.log
  File "logtest.py", line 3
    print foo
        ^
SyntaxError: invalid syntax

This is the same error output we would expect if we were to run logtest.py on local host:

$ python logtest.py
  File "logtest.py", line 3
    print foo
        ^
SyntaxError: invalid syntax

Fix the syntax error in logtest.py:

 print "hello, world"
 foo = [1, 2, 3]
 print foo

Then re-bundle, re-deploy, and run:

 $ zpm bundle
 Created logtest.zapp
 $ zpm deploy logtest logtest.zapp --force
 app deployed to
   http://127.0.0.1:8080/v1/AUTH_123def/logtest/
 $ curl -i -X POST -H "X-Zerovm-Execute: 1.0" -H "X-Zerovm-Source: swift://~/logtest/logtest.zapp" -H "X-Auth-Token: $OS_AUTH_TOKEN" $OS_STORAGE_URL
 HTTP/1.1 200 OK
 X-Nexe-Retcode: 0
 X-Nexe-System: logtest
 X-Nexe-Cdr-Line: 2.246, 2.229, 0.03 1.98 1021 66644156 11 23 0 0 0 0
 X-Zerovm-Device: stdout
 X-Nexe-Policy: Policy-0
 X-Nexe-Validation: 2
 Content-Length: 23
 X-Nexe-Etag: /dev/stdout c1def45af975364b4ee99d550d1d98da
 Connection: close
 Etag: d4c7b38bf909b5bc74eb81e73a5da81a
 X-Timestamp: 1415977445.97419
 X-Nexe-Status: ok
 Date: Fri, 14 Nov 2014 15:04:05 GMT
 Content-Type: text/html
 X-Chain-Total-Time: 2.246
 X-Trans-Id: tx40647fee812944ef80a99-00546619e3

 hello, world
 [1, 2, 3]

Note that the X-Nexe-Retcode is now 0, and we get the output we expect.

6.4. Logging exceptions

Let’s try raising an exception to see what happens. Add one more line of code to logtest.py:

 print "hello, world"
 foo = [1, 2, 3]
 print foo
 raise Exception("test exception")

Re-bundle, re-deploy, and run:

 $ zpm bundle
 Created logtest.zapp
 $ zpm deploy logtest logtest.zapp --force
 app deployed to
   http://127.0.0.1:8080/v1/AUTH_123def/logtest/
 $ curl -i -X POST -H "X-Zerovm-Execute: 1.0" -H "X-Zerovm-Source: swift://~/logtest/logtest.zapp" -H "X-Auth-Token: $OS_AUTH_TOKEN" $OS_STORAGE_URL
 HTTP/1.1 200 OK
 X-Nexe-Retcode: 1
 X-Nexe-System: logtest
 X-Nexe-Cdr-Line: 2.230, 2.211, 0.05 1.95 1021 66644156 19 163 0 0 0 0
 X-Zerovm-Device: stdout
 X-Nexe-Policy: Policy-0
 X-Nexe-Validation: 2
 Content-Length: 23
 X-Nexe-Etag: /dev/stdout c1def45af975364b4ee99d550d1d98da
 Connection: close
 Etag: a3afd778d9eafbf4d4429208d85aa35a
 X-Timestamp: 1415977837.42819
 X-Nexe-Status: ok
 Date: Fri, 14 Nov 2014 15:10:37 GMT
 Content-Type: text/html
 X-Chain-Total-Time: 2.230
 X-Trans-Id: txac87f5e842f04439b540c-0054661b6b

 hello, world
 [1, 2, 3]

This time we get the same output as above, but the X-Nexe-Retcode is 1. Let’s grab the log again to see what it says:

$ swift download logs logtest.log
logtest.log [auth 0.043s, headers 0.059s, total 0.060s, 0.009 MB/s]
$ cat logtest.log
Traceback (most recent call last):
  File "logtest.py", line 4, in <module>
    raise Exception("test exception")
Exception: test exception

Similar to syntax errors, any uncaught/unhandled exceptions will be logged to stderr.

6.5. Explicit logging

Let’s look at a case where we want to explicitly log something to stderr. We’ll keep building on the code we have already in logtest.py:

 import sys

 try:
     print "hello, world"
     foo = [1, 2, 3]
     print foo
     raise Exception("test exception")
 except Exception:
     sys.stderr.write("Something bad happened\n")

Here we are catching the exception and explictly logging a message instead of letting the exception get logged (as we experienced above).

Let’s test this to see what happens:

 $ zpm bundle
 Created logtest.zapp
 $ zpm deploy logtest logtest.zapp --force
 app deployed to
   http://127.0.0.1:8080/v1/AUTH_123def/logtest/
 $ curl -i -X POST -H "X-Zerovm-Execute: 1.0" -H "X-Zerovm-Source: swift://~/logtest/logtest.zapp" -H "X-Auth-Token: $OS_AUTH_TOKEN" $OS_STORAGE_URL
 HTTP/1.1 200 OK
 X-Nexe-Retcode: 0
 X-Nexe-System: logtest
 X-Nexe-Cdr-Line: 2.258, 2.239, 0.07 1.94 1021 66644156 12 45 0 0 0 0
 X-Zerovm-Device: stdout
 X-Nexe-Policy: Policy-0
 X-Nexe-Validation: 2
 Content-Length: 23
 X-Nexe-Etag: /dev/stdout c1def45af975364b4ee99d550d1d98da
 Connection: close
 Etag: 83c1b9378a58e72a87f3cc82af081b67
 X-Timestamp: 1415980070.92201
 X-Nexe-Status: ok
 Date: Fri, 14 Nov 2014 15:47:50 GMT
 Content-Type: text/html
 X-Chain-Total-Time: 2.258
 X-Trans-Id: tx89ceb1b12459438ab9e8c-0054662424

 hello, world
 [1, 2, 3]

Note that the X-Nexe-Retcode is 0, meaning the application exited gracefully.

Let’s have a log at the log:

$ swift download logs logtest.log
logtest.log [auth 0.047s, headers 0.063s, total 0.065s, 0.001 MB/s]
$ cat logtest.log
Something bad happened

As an alternative to using the sys.stderr device, you can write logging output to the file /dev/stderr. The following code will behave the exact same way as above:

 try:
     print "hello, world"
     foo = [1, 2, 3]
     print foo
     raise Exception("test exception")
 except Exception:
     with open("/dev/stderr", "a") as stderr:
         stderr.write("Something bad happened\n")

If you do it this way, note that you need to open the file with “append” mode (“a”) specified.