When an error happens in a test, it's hard to track down #16

techwraith · 2014-05-24T02:26:45Z

Right now I'm seeing this error when running my test suite. I suspect one of my test files is throwing an error, but Prova doesn't show me any useful information. What can we do about this?

https://cloudup.com/cjJhMEU817G

techwraith · 2014-05-24T02:32:12Z

Sorry, I just updated Prova and everything is working just fine!

techwraith · 2014-05-24T02:34:15Z

Sorry to reopen this, but the callstacks in these errors aren't helpful - is there a way to fix this? https://cloudup.com/c4X6Pbo0IrY

techwraith · 2014-05-27T19:52:31Z

Just checking in on this one after the weekend

azer · 2014-05-28T01:17:53Z

@techwraith I'm in Portland until the next sunday, will have rare access to my computer

techwraith · 2014-05-28T01:18:49Z

No problem, thanks for looking getting back to me :)

On Tuesday, May 27, 2014, Azer Koçulu notifications@github.com wrote:

@techwraith https://github.com/Techwraith I'm in Portland until the
next sunday, will have rare access to my computer

—
Reply to this email directly or view it on GitHubhttps://github.com//issues/16#issuecomment-44355102
.

azer · 2014-06-05T18:51:19Z

Hi, sorry for the late reply

Could you give me a sample test case that I can get the same output?

techwraith · 2014-06-05T19:26:10Z

Just clone this down:

https://github.com/Techwraith/prova-test-example

and run this command:

./node_modules/prova/bin/prova -b test.js -t hbsfy

azer · 2014-06-05T19:43:32Z

thanks! I'll try it tonight

techwraith · 2014-06-06T19:36:36Z

How'd this go? Were you able to reproduce the issue that that code sample?

On Thu, Jun 5, 2014 at 12:43 PM, Azer Koçulu notifications@github.com
wrote:

thanks! I'll try it tonight

—
Reply to this email directly or view it on GitHub
#16 (comment).

azer · 2014-06-06T20:26:45Z

I was actually working on domquery last night and already saw this error there too... We need some enhancements on generally showing the errors on the browsers actually. It's kinda tricky and definitely the first priority right now.

For now, you can open the source code on /assets/run.js and check the failing code with the line numbers.

azer · 2014-06-09T06:00:29Z

I've just released a new version of Prova that allows you browse around the error stack. You can click the stack lines and see the source code immediately. I hope it helps!

techwraith · 2014-06-09T16:14:17Z

I just updated prova and I'm not seeing any different functionality. What should I be looking for?

joeybaker · 2014-06-09T16:54:45Z

@azer kinda cool! It doesn't solve the problem for me, but it's nifty functionality.

azer · 2014-06-09T17:25:46Z

Actual improvements on this case actually would happen on the Tape side since we get the error objects from Tape stream

techwraith · 2014-06-09T19:43:49Z

Can you point me to the place in the code where that error comes from? If I use tape on it's own I get good error messages.

techwraith · 2014-06-09T19:45:21Z

Also, if I run Prova on the command line (not in the browser) I get good error messages. It seems to be a problem with Prova's front end reporting, not tape.

azer · 2014-06-09T19:52:25Z

Does Tape also give better error messages on browser? tape.createObjectStream is where we get the errors.

techwraith · 2014-06-10T00:23:58Z

This worked in a previous version of Prova. @joeybaker is going to track it down and report back. Thanks for looking into this.

joeybaker · 2014-06-10T00:57:04Z

I went back to 1.2.0 50cebaa and unfortunately, this is still broken :/

@azer does tape.createObjectStream not output the correct callstack?

azer · 2014-06-10T01:00:08Z

@joeybaker yeah, because the error produced is an uncatched JS error

azer · 2014-06-30T01:15:43Z

just noticed that tape throws the correct stack trace within the "actual" property instead "error" (which has another error object) and released a patch to switch between the correct error stack traces, now we show the correct failing lines on browsers too. hope it's gonna be helpful!

version :1.13.0
commit: da2139e

joeybaker · 2014-06-30T16:49:56Z

Nifty! Unfortunately, I'm still seeing stack traces coming from the prova stack:


        37709. = function (err, msg, extra) {
        37710.     this._assert(!err, {
        37711.         message : defined(msg, String(err)),
                        ^
        Error: TypeError: Attempted to wrap undefined property offrentItem as function
            at Test.assert (http://0.0.0.0:7559/assets/run.js:37602:54)
            at Test.bound [as _assert] (http://0.0.0.0:7559/assets/run.js:37466:32)
            at Test.error.Test.ifError.Test.ifErr.Test.iferror (http://0.0.0.0:7559/assets/run.js:37710:10)
            at Test.bound (http://0.0.0.0:7559/assets/run.js:37466:32)
            at Test.run (http://0.0.0.0:7559/assets/run.js:37483:14)
            at Test.bound [as run] (http://0.0.0.0:7559/assets/run.js:37466:32)
            at next (http://0.0.0.0:7559/assets/run.js:37280:15)
            at http://0.0.0.0:7559/assets/run.js:60952:21

My start command: prova -bel chrome -t hbsfy 'test/**/*test.js' Is there something additional that I should be doing?

azer · 2014-06-30T18:01:32Z

@joeybaker notice that it's showing the third line (37710) on the stack. any chance you accidentally clicked that line? it'd show the first line by default and you can navigate between those lines by just clicking

joeybaker · 2014-06-30T18:18:42Z

@azer No, The top image is a screen cap from in-browser and the second is a dump from the console (no clicking possible there :] ).

azer · 2014-06-30T18:26:58Z

@joeybaker notice the line number in the first row of the error stack in the screenshot: 37602. and the line in the source code: 37710. Are you able to click and switch to the first line? (e.g https://i.cloudup.com/42iYw0WnPP.gif)

And could you make sure that you're using the correct prova version? (if you're running the tests by "node test -b" command use "node test -v" for showing the version, if you're using the global command like "prova test -b" then see the version by "prova -v")

joeybaker · 2014-06-30T18:47:26Z

@azer yea, I can switch lines, but it doesn't tell me much.

> cat test/test.js
var test = require('prova')

test('stack traces', function (t){
  t.ok(false, 'ok!')
})
> ./node_modules/.bin/prova -v

  prova v1.13.0

> ./node_modules/.bin/prova -bel chrome test/**

  prova:browser Visit 0.0.0.0:7559 with a browser to start running the tests. +0ms

 { [Error: spawn ENOENT] code: 'ENOENT', errno: 'ENOENT', syscall: 'spawn' }
  prova:launch Launched chrome to visit http://0.0.0.0:7559 headlessly. +511ms

    stack traces
    Browser: Chrome v35 Engine: WebKit v537.36 OS: Mac OS X v10.9.3

        ok! http://0.0.0.0:7559/assets/run.js
                       v
        5425. = function (value, msg, extra) {
        5426.     this._assert(value, {
        5427.         message : msg,
                       ^
        Error: ok!
            at Test.assert (http://0.0.0.0:7559/assets/run.js:5345:54)
            at Test.bound [as _assert] (http://0.0.0.0:7559/assets/run.js:5209:32)
            at Test.ok.Test.true.Test.assert (http://0.0.0.0:7559/assets/run.js:5426:10)
            at Test.bound [as ok] (http://0.0.0.0:7559/assets/run.js:5209:32)
            at Test.<anonymous> (http://0.0.0.0:7559/assets/run.js:6005:5)
            at Test.bound [as _cb] (http://0.0.0.0:7559/assets/run.js:5209:32)
            at Test.run (http://0.0.0.0:7559/assets/run.js:5223:14)
            at Test.bound [as run] (http://0.0.0.0:7559/assets/run.js:5209:32)
            at next (http://0.0.0.0:7559/assets/run.js:5023:15)
            at http://0.0.0.0:7559/assets/run.js:2177:21

    Expected: true
    Actual:   ""

Compare to running the test only through node:

> prova test/**

    stack traces
    ok! /Users/joeybaker/server/prova-client-test-bug/test/test.js
               v
        3. test('stack traces', function (t){
        4.   t.ok(false, 'ok!')
        5.   t.end()
               ^
        Error: ok!
            at Test.<anonymous> (/Users/joeybaker/server/prova-client-test-bug/test/test.js:4:5)
            at processImmediate [as _immediateCallback] (timers.js:336:15)


        Expected: true
        Actual:   false




    1 failed, 0 passed assertions.

Here's the code: https://github.com/joeybaker/prova-client-test-bug

azer · 2014-06-30T19:01:24Z

The first line of the stack trace should show the failing line, rest will be tape and prova lines... so I'm curious what you see when you click "at Test.assert (http://0.0.0.0:7559/assets/run.js:5345:54)"

joeybaker · 2014-06-30T19:18:16Z

Gotcha. Here's what I get:

joeybaker · 2014-06-30T19:18:49Z

(worth noting: the actual value is set to "", when it should report false.)

azer · 2014-06-30T19:28:33Z

just fixed the bug about showing the false value, released as 1.13.1.

now it looks like this in my local:

test('stack traces', function (t){
  t.ok(false, 'ok!')
  t.end()

joeybaker · 2014-06-30T19:48:54Z

@azer that's great! On two levels!

thanks for the fast false fix!
your screen grab is just what I'd expect to see, but I'm still stuck on the screen grabs I showed above.

Let me get some other co-workers to look at this on different machines, maybe my local env is messed up?

azer · 2014-06-30T20:58:20Z

arright, thanks a lot for reporting this and sorry for late fix! I hope it'll work

techwraith · 2014-06-30T21:55:05Z

I'm still seeing the wrong stack trace on my local machine:

techwraith · 2014-06-30T21:58:27Z

To clarify:

I cloned the test repo that @joeybaker linked to, did an npm install, and then did npm test. I didn't click anything, and this is the error that I'm getting.

azer · 2014-06-30T21:59:53Z

@techwraith what happens if you start with "node test -b" ?

techwraith · 2014-06-30T22:20:32Z

Sure, this is what I get when I run ./node_modules/.bin/prova test/** -b

techwraith · 2014-06-30T22:26:34Z

Same thing if I run node tests/test/js -b

azer · 2014-06-30T22:44:09Z

I'm out of ideas unfortunately

techwraith closed this as completed May 24, 2014

techwraith reopened this May 24, 2014

azer closed this as completed Jun 30, 2014

When an error happens in a test, it's hard to track down #16

When an error happens in a test, it's hard to track down #16

Comments

techwraith commented May 24, 2014

techwraith commented May 24, 2014

techwraith commented May 24, 2014

techwraith commented May 27, 2014

azer commented May 28, 2014

techwraith commented May 28, 2014

azer commented Jun 5, 2014

techwraith commented Jun 5, 2014

azer commented Jun 5, 2014

techwraith commented Jun 6, 2014

azer commented Jun 6, 2014

azer commented Jun 9, 2014

techwraith commented Jun 9, 2014

joeybaker commented Jun 9, 2014

azer commented Jun 9, 2014

techwraith commented Jun 9, 2014

techwraith commented Jun 9, 2014

azer commented Jun 9, 2014

techwraith commented Jun 10, 2014

joeybaker commented Jun 10, 2014

azer commented Jun 10, 2014

azer commented Jun 30, 2014

joeybaker commented Jun 30, 2014

azer commented Jun 30, 2014

joeybaker commented Jun 30, 2014

azer commented Jun 30, 2014

joeybaker commented Jun 30, 2014

azer commented Jun 30, 2014

joeybaker commented Jun 30, 2014

joeybaker commented Jun 30, 2014

azer commented Jun 30, 2014

joeybaker commented Jun 30, 2014

azer commented Jun 30, 2014

techwraith commented Jun 30, 2014

techwraith commented Jun 30, 2014

azer commented Jun 30, 2014

techwraith commented Jun 30, 2014

techwraith commented Jun 30, 2014

azer commented Jun 30, 2014