Goconvey parser crashes on appengine output

[Netherdrake]

On output like this, goconvey parser runs fine.

2014/01/15 19:16:49 appengine: not running under devappserver2; using some default configuration

Running Suite: Spotlight
========================
Random Seed: 1389838609
Will run 0 of 0 specs

Ran 0 of 0 Specs in 0.000 seconds
SUCCESS! -- 0 Passed | 0 Failed | 0 Pending | 0 Skipped

PASS
ok      bitbucket.org/furion/spotlight/spotlight-gae    0.023s

However asap as appengine/aetest fake AppEngine context is injected into the tests, it crashes:

// main
package spotlight

import (
    "appengine"
)

func ApiRoot(c appengine.Context) (int, string) {
    return 200, "OK"
}

// test
package spotlight

import (
    . "github.com/onsi/ginkgo"
    . "github.com/onsi/gomega"

    "appengine/aetest"
)

var _ = Describe("ApiRoot", func() {
    var c aetest.Context

    BeforeEach(func() {
        c, _ = aetest.NewContext(nil)
        defer c.Close()
    })

    It("should return 200", func() {
        i, s := ApiRoot(c)
        Expect(i).To(Equal(200))
        Expect(s).To(Equal("OK"))
    })

})

Output of goapp test:

2014/01/15 19:20:06 appengine: not running under devappserver2; using some default configuration

Running Suite: Spotlight
========================
Random Seed: 1389838806
Will run 1 of 1 specs

INFO     2014-01-16 02:20:06,701 devappserver2.py:660] Skipping SDK update check.
WARNING  2014-01-16 02:20:06,701 devappserver2.py:665] DEFAULT_VERSION_HOSTNAME will not be set correctly with --port=0
WARNING  2014-01-16 02:20:06,713 api_server.py:331] Could not initialize images API; you are likely missing the Python "PIL" module.
INFO     2014-01-16 02:20:06,717 api_server.py:138] Starting API server at: http://localhost:60376
INFO     2014-01-16 02:20:06,720 dispatcher.py:171] Starting module "default" running at: http://localhost:60377
INFO     2014-01-16 02:20:06,725 admin_server.py:117] Starting admin server at: http://localhost:60378
•
Ran 1 of 1 Specs in 0.517 seconds
SUCCESS! -- 1 Passed | 0 Failed | 0 Pending | 0 Skipped

PASS
ok      bitbucket.org/furion/spotlight/spotlight-gae    0.540s

Goconvey server:

~/D/g/s/b/f/spotlight % goconvey -port=3333
2014/01/15 19:20:26 goconvey.go:43: Initial configuration: [host: 127.0.0.1] [port: 3333] [poll 250ms]
2014/01/15 19:20:26 goconvey.go:84: Constructing components...
2014/01/15 19:20:26 watcher.go:30: Adjusting to watch new root: /Users/jan/Documents/go/src/bitbucket.org/furion/spotlight
2014/01/15 19:20:26 watcher.go:40: Including: /Users/jan/Documents/go/src/bitbucket.org/furion/spotlight
2014/01/15 19:20:26 watcher.go:40: Including: /Users/jan/Documents/go/src/bitbucket.org/furion/spotlight/spotlight-gae
2014/01/15 19:20:26 tester.go:15: Now configured to test 10 packages concurrently.
2014/01/15 19:20:26 watcher.go:72: Number of watched folders: 2
2014/01/15 19:20:26 goconvey.go:76: Serving HTTP at: http://127.0.0.1:3333
2014/01/15 19:20:26 monitor.go:16: Engaging monitoring loop...
2014/01/15 19:20:26 scanner.go:31: Updating root in scanner: /Users/jan/Documents/go/src/bitbucket.org/furion/spotlight
2014/01/15 19:20:26 watcher.go:72: Number of watched folders: 2
2014/01/15 19:20:26 monitor.go:33: Preparing for test run (watching 2 folders)...
2014/01/15 19:20:26 executor.go:56: Executor status: 'executing'
2014/01/15 19:20:26 coordinator.go:37: Executing concurrent tests: bitbucket.org/furion/spotlight
2014/01/15 19:20:26 coordinator.go:37: Executing concurrent tests: bitbucket.org/furion/spotlight/spotlight-gae

The localhost:3333 is than stuck on: Server is starting...

[mdwhatcott]

@Netherdrake - Wow, there's a lot going on here:

1. Your application is coupled to the Google App Engine framework, enough so that you require app-engine specific components in your unit tests.
2. Your application utilizes ginkgo/gomega for its test composition.
3. You're using the GoConvey web UI to execute the gingko + appengine tests.

While there's particularly nothing wrong with item 1 or item 2 in isolation, the combination of them with GoConvey (item 3) has my head spinning. I have nothing against AppEngine or Gingkgo but I personally didn't design GoConvey with either of them in mind since we don't use them at SmartyStreets. Unfortunately, you're on your own as I won't be much help with a fix here. This is just not a scenario that we will officially support (AppEngine + Ginkgo + GoConvey).

Not meaning to get preachy here but if I were using AppEngine I would try to put all of the logic I want tested in modules/classes that don't even touch the app-engine components directly, then I would use simple integration tests to test that app-engine and my application code are wired up correctly. See this wonderful talk or this wonderful blog post for more ideas about that. This kind of decoupling from a framework is good practice no matter what web (or database, etc...) framework you might be using (django, cherrypy, etc...).

In summary, if you really want to use the GoConvey web UI to run your tests then I would stick to traditional go test composition or just use the GoConvey DSL.

[Netherdrake]

I am trying to decouple as much as possible. The appengine context I use here is fake, its intended for writing tests. This allows me to write tests for each handler (almost integration level unit tests).

The reason why I use Ginkgo/Gomega is because its the most fully featured testing framework out there. I'm also very familiar with it, since its a Rspec remake in Go, and I come from Ruby so I know this stuff. It works well with GoConvey most of the time too.

I hope you will change your mind eventually, as your test runner is absolutely amazing. I'm really sad to see it go, its breaking my heart :(

[Netherdrake]

I rewrote it in Convey, and it works (although warnings kind of ruin the output

package spotlight

import (
    "testing"
    "appengine/aetest"

    . "github.com/smartystreets/goconvey/convey"
)

func TestApiRoot(t *testing.T) {
    var c aetest.Context

    Convey("ApiRoot should return OK", t, func() {
        So(1, ShouldEqual, 1)
        c, _ = aetest.NewContext(nil)
        defer c.Close()

        i, s := ApiRoot(c)
        So(i, ShouldEqual, 200)
        So(s, ShouldEqual, "OK")
    })
}

I really like GoConvey test runner as well as the framework, its semantically much cleaner, easier, just lovely.

But Ginkgo, even tho it has uglier syntax, I need to use it on this project. If you change your mind, and decide to give it a quick look, I'll buy you a beer (or two) :)

I suspect the issue is with the warnings that appengine outputs.

[mdwhatcott]

@Netherdrake - If only I was the drinking type... :)

What would I have to do/install to reproduce the bug? Just go get .../.../appengine? I'd rather not have to install an SDK, unless it's easy to get rid of when I'm done.

[Netherdrake]

Yes, you install SDK in different folder than your Go setup ($GOPATH). Installing = just extracting zip file. Than you set your ENV vars, and you're done.

Here are mine.

export GOROOT=/usr/local/Cellar/go/1.2/libexec/
export GOPATH=$HOME/Documents/go
export PATH=$GOPATH/bin:$PATH
export APPENGINE_SDK=$HOME/Documents/go/go_appengine
export PATH=$PATH:$APPENGINE_SDK

After, create links:

ln -s $APPENGINE_SDK/goroot/src/pkg/appengine $GOROOT/src/pkg/ 
ln -s $APPENGINE_SDK/goroot/src/pkg/appengine_internal $GOROOT/src/pkg/
mkdir -p $GOROOT/src/pkg/code.google.com/p/
ln -s $APPENGINE_SDK/goroot/src/pkg/code.google.com/p/goprotobuf
$GOROOT/src/pkg/code.google.com/p/

To install 3rd party dependencies, use goapp. Like goapp get github.com/foo. To run server, its goapp serve and tests is goapp test -v.

*It can be coffee or tea.

[mdwhatcott]

Ok, thanks for the tutorial. That doesn't sound too terrible but I'll probably setup a separate go workspace for it. I'll see what I can do. No guarantees here--appenging + ginkgo + goconvey is asking a lot...

• You're too kind. This one's on me (provided I can fix it...). Besides, we mormons can be real party-poopers :)

[Netherdrake]

Ok, I played with it a bit more, and now I know the source of issue. c, _ = aetest.NewContext(nil) calls bunch of python scripts in backend, which spam stdout with shitty logs. Which makes testing output look like this: http://imgur.com/vj3Of7o

Which breaks Convey's parser. In the case of ginkgo, it breaks it completely, with other suites, just the output.

Anyway, I'm thinking about converting into Convey for writing tests too, not just as runner. Will see. (also, I'm on mavericks, and for some reason colors don't work with convey test runner).

• How about a lemonade? Or a freshly squeezed orange juice?

[mdwhatcott]

Ouch--that output is nasty. When run from the command line I'm not doing any capturing of stdout. When invoked as a result of using the web UI all stdout is sent to the parser. Does goapp pass all arguments to the go test runner? If so, what do you see when you run this:

go test -v -timeout=-42s

That's the exact command that the GoConvey server uses to get JSON output that can be parsed for the web UI. Anything that doesn't look like JSON is displayed as output. I'd love to see the output of that... (That would be my first step in debugging this).

With that go test command above, you might need to say goapp test -test.v -test.timeout=-42 (note the 'test.' prefix). But that's only if goapp is bulding the test binary with go test -c and invoking it directly, per this explanation--search for text like:

When invoking the test binary directly, each of the standard flag names must be prefixed with 'test.'

• Now you're talkin'!

[Netherdrake]

K, the output of goapp test -test.v -test.timeout=-42s > test.json is:

=== RUN TestApiRoot
>>>>>
{
  "Title": "ApiRoot should return OK",
  "File": "/Users/jan/Documents/go/src/bitbucket.org/furion/spotlight/spotlight-gae/api_test.go",
  "Line": 20,
  "Depth": 0,
  "Assertions": [
    {
      "File": "/Users/jan/Documents/go/src/bitbucket.org/furion/spotlight/spotlight-gae/api_test.go",
      "Line": 18,
      "Expected": "",
      "Actual": "",
      "Failure": "",
      "Error": null,
      "StackTrace": "goroutine 4 [running]:\nbitbucket.org/furion/spotlight/spotlight-gae.func·002()\n\u0009/Users/jan/Documents/go/src/bitbucket.org/furion/spotlight/spotlight-gae/api_test.go:18 +0xeb\nbitbucket.org/furion/spotlight/spotlight-gae.TestApiRoot(0xc2000e5000)\n\u0009/Users/jan/Documents/go/src/bitbucket.org/furion/spotlight/spotlight-gae/api_test.go:20 +0x151\ntesting.tRunner(0xc2000e5000, 0x4d3fa0)\n\u0009/private/var/folders/00/0jth8000h01000cxqpysvccm0027_1/T/appengine/go_appengine/goroot/src/pkg/testing/testing.go:353 +0x8a\ncreated by testing.RunTests\n\u0009/private/var/folders/00/0jth8000h01000cxqpysvccm0027_1/T/appengine/go_appengine/goroot/src/pkg/testing/testing.go:433 +0x86b\n\ngoroutine 1 [chan receive]:\ntesting.RunTests(0x36df08, 0x4d3fa0, 0x1, 0x1, 0xac201, ...)\n\u0009/private/var/folders/00/0jth8000h01000cxqpysvccm0027_1/T/appengine/go_appengine/goroot/src/pkg/testing/testing.go:434 +0x88e\ntesting.Main(0x36df08, 0x4d3fa0, 0x1, 0x1, 0x4dcba0, ...)\n\u0009/private/var/folders/00/0jth8000h01000cxqpysvccm0027_1/T/appengine/go_appengine/goroot/src/pkg/testing/testing.go:365 +0x8a\nmain.main()\n\u0009bitbucket.org/furion/spotlight/spotlight-gae/_test/_testmain.go:43 +0x9a\n\ngoroutine 2 [syscall]:\n\ngoroutine 5 [syscall]:\nsyscall.Syscall()\n\u0009/private/var/folders/00/0jth8000h01000cxqpysvccm0027_1/T/appengine/go_appengine/goroot/src/pkg/syscall/asm_darwin_amd64.s:15 +0x5\nsyscall.read(0x4, 0xc20011c28a, 0xd76, 0xd76, 0xc2000c8f20, ...)\n\u0009/private/var/folders/00/0jth8000h01000cxqpysvccm0027_1/T/appengine/go_appengine/goroot/src/pkg/syscall/zsyscall_darwin_amd64.go:900 +0x70\nsyscall.Read(0x4, 0xc20011c28a, 0xd76, 0xd76, 0x4, ...)\n\u0009/private/var/folders/00/0jth8000h01000cxqpysvccm0027_1/T/appengine/go_appengine/goroot/src/pkg/syscall/syscall_unix.go:132 +0x5a\nos.(*File).read(0xc2000003d8, 0xc20011c28a, 0xd76, 0xd76, 0xc2000ad9d4, ...)\n\u0009/private/var/folders/00/0jth8000h01000cxqpysvccm0027_1/T/appengine/go_appengine/goroot/src/pkg/os/file_unix.go:178 +0x60\nos.(*File).Read(0xc2000003d8, 0xc20011c28a, 0xd76, 0xd76, 0x1d2fc, ...)\n\u0009/private/var/folders/00/0jth8000h01000cxqpysvccm0027_1/T/appengine/go_appengine/goroot/src/pkg/os/file.go:95 +0x96\nio.(*teeReader).Read(0xc2000f6740, 0xc20011c28a, 0xd76, 0xd76, 0xf6ae0, ...)\n\u0009/private/var/folders/00/0jth8000h01000cxqpysvccm0027_1/T/appengine/go_appengine/goroot/src/pkg/io/io.go:481 +0x68\nbufio.(*Scanner).Scan(0xc2000fed90, 0xc2000edb40)\n\u0009/private/var/folders/00/0jth8000h01000cxqpysvccm0027_1/T/appengine/go_appengine/goroot/src/pkg/bufio/scan.go:165 +0x47c\nappengine/aetest.func·004()\n\u0009/private/var/folders/00/0jth8000h01000cxqpysvccm0027_1/T/appengine/go_appengine/goroot/src/pkg/appengine/aetest/context.go:311 +0xe8\ncreated by appengine/aetest.(*context).startChild\n\u0009/private/var/folders/00/0jth8000h01000cxqpysvccm0027_1/T/appengine/go_appengine/goroot/src/pkg/appengine/aetest/context.go:322 +0x960\n",
      "Skipped": false
    },
    {
      "File": "/Users/jan/Documents/go/src/bitbucket.org/furion/spotlight/spotlight-gae/api_test.go",
      "Line": 19,
      "Expected": "",
      "Actual": "",
      "Failure": "",
      "Error": null,
      "StackTrace": "goroutine 4 [running]:\nbitbucket.org/furion/spotlight/spotlight-gae.func·002()\n\u0009/Users/jan/Documents/go/src/bitbucket.org/furion/spotlight/spotlight-gae/api_test.go:19 +0x1ba\nbitbucket.org/furion/spotlight/spotlight-gae.TestApiRoot(0xc2000e5000)\n\u0009/Users/jan/Documents/go/src/bitbucket.org/furion/spotlight/spotlight-gae/api_test.go:20 +0x151\ntesting.tRunner(0xc2000e5000, 0x4d3fa0)\n\u0009/private/var/folders/00/0jth8000h01000cxqpysvccm0027_1/T/appengine/go_appengine/goroot/src/pkg/testing/testing.go:353 +0x8a\ncreated by testing.RunTests\n\u0009/private/var/folders/00/0jth8000h01000cxqpysvccm0027_1/T/appengine/go_appengine/goroot/src/pkg/testing/testing.go:433 +0x86b\n\ngoroutine 1 [chan receive]:\ntesting.RunTests(0x36df08, 0x4d3fa0, 0x1, 0x1, 0xac201, ...)\n\u0009/private/var/folders/00/0jth8000h01000cxqpysvccm0027_1/T/appengine/go_appengine/goroot/src/pkg/testing/testing.go:434 +0x88e\ntesting.Main(0x36df08, 0x4d3fa0, 0x1, 0x1, 0x4dcba0, ...)\n\u0009/private/var/folders/00/0jth8000h01000cxqpysvccm0027_1/T/appengine/go_appengine/goroot/src/pkg/testing/testing.go:365 +0x8a\nmain.main()\n\u0009bitbucket.org/furion/spotlight/spotlight-gae/_test/_testmain.go:43 +0x9a\n\ngoroutine 2 [syscall]:\n\ngoroutine 5 [syscall]:\nsyscall.Syscall()\n\u0009/private/var/folders/00/0jth8000h01000cxqpysvccm0027_1/T/appengine/go_appengine/goroot/src/pkg/syscall/asm_darwin_amd64.s:15 +0x5\nsyscall.read(0x4, 0xc20011c28a, 0xd76, 0xd76, 0xc2000c8f20, ...)\n\u0009/private/var/folders/00/0jth8000h01000cxqpysvccm0027_1/T/appengine/go_appengine/goroot/src/pkg/syscall/zsyscall_darwin_amd64.go:900 +0x70\nsyscall.Read(0x4, 0xc20011c28a, 0xd76, 0xd76, 0x4, ...)\n\u0009/private/var/folders/00/0jth8000h01000cxqpysvccm0027_1/T/appengine/go_appengine/goroot/src/pkg/syscall/syscall_unix.go:132 +0x5a\nos.(*File).read(0xc2000003d8, 0xc20011c28a, 0xd76, 0xd76, 0xc2000ad9d4, ...)\n\u0009/private/var/folders/00/0jth8000h01000cxqpysvccm0027_1/T/appengine/go_appengine/goroot/src/pkg/os/file_unix.go:178 +0x60\nos.(*File).Read(0xc2000003d8, 0xc20011c28a, 0xd76, 0xd76, 0x1d2fc, ...)\n\u0009/private/var/folders/00/0jth8000h01000cxqpysvccm0027_1/T/appengine/go_appengine/goroot/src/pkg/os/file.go:95 +0x96\nio.(*teeReader).Read(0xc2000f6740, 0xc20011c28a, 0xd76, 0xd76, 0xf6ae0, ...)\n\u0009/private/var/folders/00/0jth8000h01000cxqpysvccm0027_1/T/appengine/go_appengine/goroot/src/pkg/io/io.go:481 +0x68\nbufio.(*Scanner).Scan(0xc2000fed90, 0xc2000edb40)\n\u0009/private/var/folders/00/0jth8000h01000cxqpysvccm0027_1/T/appengine/go_appengine/goroot/src/pkg/bufio/scan.go:165 +0x47c\nappengine/aetest.func·004()\n\u0009/private/var/folders/00/0jth8000h01000cxqpysvccm0027_1/T/appengine/go_appengine/goroot/src/pkg/appengine/aetest/context.go:311 +0xe8\ncreated by appengine/aetest.(*context).startChild\n\u0009/private/var/folders/00/0jth8000h01000cxqpysvccm0027_1/T/appengine/go_appengine/goroot/src/pkg/appengine/aetest/context.go:322 +0x960\n",
      "Skipped": false
    }
  ]
},
<<<<<
--- PASS: TestApiRoot (0.52 seconds)
PASS
ok      bitbucket.org/furion/spotlight/spotlight-gae    0.554s

And this goes to stdout:

2014/01/16 22:25:10 appengine: not running under devappserver2; using some default configuration
INFO     2014-01-17 05:25:11,219 devappserver2.py:660] Skipping SDK update check.
WARNING  2014-01-17 05:25:11,219 devappserver2.py:665] DEFAULT_VERSION_HOSTNAME will not be set correctly with --port=0
WARNING  2014-01-17 05:25:11,226 api_server.py:331] Could not initialize images API; you are likely missing the Python "PIL" module.
INFO     2014-01-17 05:25:11,229 api_server.py:138] Starting API server at: http://localhost:58463
INFO     2014-01-17 05:25:11,233 dispatcher.py:171] Starting module "default" running at: http://localhost:58464
INFO     2014-01-17 05:25:11,235 admin_server.py:117] Starting admin server at: http://localhost:58465

I ran the vimdiff against goapp test -v -timeout=-42s > test2.json and it looks like they both do the same thing (stdout is same too).

• I suppose the chances of you being in Calgary, CA are slim, so do you know of a thing called Bitcoin?

[mdwhatcott]

Ok, thanks for executing that command. I'll have to dig deeper...

• Never heard of it :)

[Netherdrake]

I've got the gingko tests to run by moving context creation to its suite runner.

package spotlight

import (
    . "github.com/onsi/ginkgo"
    . "github.com/onsi/gomega"

    "testing"
    "appengine/aetest"
)

var (
    err error
    c   aetest.Context
)

func TestSpotlight(t *testing.T) {
    c, err = aetest.NewContext(nil)
    if err != nil {
        t.Fatal(err)
    }
    defer c.Close()

    RegisterFailHandler(Fail)
    RunSpecs(t, "Spotlight")
}

However, I'm struggling as I'd much rather use Ginkgo framework for writing tests now, but I'm stuck with gingko due to necessary features (global tearups & teardowns, beforeEach, etc...).

• I think the best way to tip a coder for a juice is with magic internet money :)

[mdwhatcott]

Are you aware that GoConvey already supports Setups and Teardowns (at any level/scope)?

Setup and BeforeEach constructs are achieved by default using nested Convey calls:

https://github.com/smartystreets/goconvey/wiki/Execution-order

Teardown and AfterEach are achieved by judiciously placed Reset calls:

https://github.com/smartystreets/goconvey/wiki/Reset

• At this point, the more rewarding form of renumeration you could give would be to use the GoConvey framework for test composition!

[mholt]

@Netherdrake I'm pretty sure GoConvey's DSL mimics a "beforeEach" function with the nesting structure. And there's a Reset() function to do tear-downs at whichever levels you need. (Granted, there are some deficiencies in other open issues, which should be addressed in GoConvey DSL version 2.)

EDIT: D'oh. Mike beat me to it.

• @mdwhatcott Take the generous man's shiny Internet coins.

[Netherdrake]

@mdwhatcott gotcha! Now in my appengine case, the setup of testing context takes quite a bit of time (1-2s), so setting it up for each test is unacceptable. Is there a way to do global setup/teardown? Like I do with ginkgo in my previous post?

[Netherdrake]

BTW, solved my color problem by setting 'xterm-256color' as reported terminal by Tmux and Iterm2 :) One step closer to adopting GoConvey.

[mdwhatcott]

In GoConvey, the entire test suite for a given component is generally composed within a single test function. Forgive my complete ignorance of how to work with appengine and the Context thing but how about this:

package spotlight

import (
    . "github.com/smartystreets/goconvey/convey"

    "testing"
    "appengine/aetest"
)

var (
    err error
    c   aetest.Context
)

func TestSpotlight(t *testing.T) {
    c, err = aetest.NewContext(nil)
    if err != nil {
        t.Fatal(err)
    }

    Convey("Subject: The spotlight is bright...", t, func() {
        c.Prepare("or whatever you call to get the context ready for each nested test case...")

        Convey("When the star of the show comes on stage", func() {
            DrumRoll()
            AnnounceEntrance(c)
            Applause()

            Convey("The spotlight should have turned on", func() {
                So(c["spotlight"], ShouldEqual, "on")
            })

            Convey("During the finale", func() {
                BigFinish(c)

                Convey("The spotlight should be spinning", func() {
                    So(c["spotlight"], ShouldEqual, "spinning")
                })
            })
        })

        Convey("When cleaning the spotlight", func() {
            CleanSpotlight(c)

            Convey("It should be off", func() {
                So(c["spotlight"], ShouldEqual, "off")
            })
        })

        Reset(func() {
            c.Cleanup()
        })
    })

    defer c.Close()
}

[Netherdrake]

K, I think I understand the Convey way of doing things now.

This design is really nice actually, thanks! (Its so much cleaner than the Ruby/Rspec style I've grown up by)

Now the last thing I gotta figure out is how to remove the pesky python spam to stdout, and I'm all settled.

• Dropped ginkgo from testing stack. Vive la révolution!

[mdwhatcott]

"The Convey Way!" -- That's a new slogan if I've ever heard one. Glad you like the clean DSL.