drillDown test failures correlated with advance to super commit a12d23c

[philrz]

The app has had its super dependency stuck at commit b0dc059 because once it advances to a12d23c (associated with the changes in brimdata/super#6453) or newer, yarn test has the following failures:

 FAIL  src/js/models/program.test.ts (6.03 s)
  ● drill down › when there is no leading filter

    "i d" no such field at line 1, column 12:
    count() by this["i d"]["orig h"]
               ~~~~

      61 |   async function run(value: any, text: string) {
      62 |     const info = await fetchQueryInfo(text, "test")
    > 63 |     if (info.error) throw new Error(info.error.error)
         |                           ^
      64 |     const hasAggs = !!info.channels[0].aggregations_keys
      65 |     return drillDown(text, value, hasAggs, info.channels[0].aggregation_keys)
      66 |   }

      at run (src/js/models/program.test.ts:63:27)
      at Object.<anonymous> (src/js/models/program.test.ts:69:20)

  ● drill down › when there is a sort on there

    "name" no such field at line 1, column 1:
    name=="james" | count() by proto | sort -r count
    ~~~~
    "proto" no such field at line 1, column 28:
    name=="james" | count() by proto | sort -r count
                               ~~~~~

      61 |   async function run(value: any, text: string) {
      62 |     const info = await fetchQueryInfo(text, "test")
    > 63 |     if (info.error) throw new Error(info.error.error)
         |                           ^
      at run (src/js/models/program.test.ts:63:27)
      at Object.<anonymous> (src/js/models/program.test.ts:94:20)

  ● drill down › easy peasy

    "name" no such field at line 1, column 1:
    name=="james" | count() by proto
    ~~~~
    "proto" no such field at line 1, column 28:
    name=="james" | count() by proto
                               ~~~~~

      61 |   async function run(value: any, text: string) {
      62 |     const info = await fetchQueryInfo(text, "test")
    > 63 |     if (info.error) throw new Error(info.error.error)
         |                           ^
      64 |     const hasAggs = !!info.channels[0].aggregations_keys
      65 |     return drillDown(text, value, hasAggs, info.channels[0].aggregation_keys)
      66 |   }

      at run (src/js/models/program.test.ts:63:27)
      at Object.<anonymous> (src/js/models/program.test.ts:105:20)

  ● drill down › count by and filter the same

    "md5" no such field at line 1, column 1:
    md5=="123" | count() by md5 | sort -r | head 5
    ~~~
    "md5" no such field at line 1, column 25:
    md5=="123" | count() by md5 | sort -r | head 5
                            ~~~

      61 |   async function run(value: any, text: string) {
      62 |     const info = await fetchQueryInfo(text, "test")
    > 63 |     if (info.error) throw new Error(info.error.error)
         |                           ^
      64 |     const hasAggs = !!info.channels[0].aggregations_keys
      65 |     return drillDown(text, value, hasAggs, info.channels[0].aggregation_keys)
      66 |   }

      at run (src/js/models/program.test.ts:63:27)
      at Object.<anonymous> (src/js/models/program.test.ts:113:20)

  ● drill down › filter query

    "_path" no such field at line 1, column 1:
    _path=="files" | filename!="-" | count() by md5,filename | count() by md5 | sort -r | count > 1
    ~~~~~
    "filename" no such field at line 1, column 18:
    _path=="files" | filename!="-" | count() by md5,filename | count() by md5 | sort -r | count > 1
                     ~~~~~~~~
    "md5" no such field at line 1, column 45:
    _path=="files" | filename!="-" | count() by md5,filename | count() by md5 | sort -r | count > 1
                                                ~~~
    "filename" no such field at line 1, column 49:
    _path=="files" | filename!="-" | count() by md5,filename | count() by md5 | sort -r | count > 1
                                                    ~~~~~~~~

      61 |   async function run(value: any, text: string) {
      62 |     const info = await fetchQueryInfo(text, "test")
    > 63 |     if (info.error) throw new Error(info.error.error)
         |                           ^
      64 |     const hasAggs = !!info.channels[0].aggregations_keys
      65 |     return drillDown(text, value, hasAggs, info.channels[0].aggregation_keys)
      66 |   }

      at run (src/js/models/program.test.ts:63:27)
      at Object.<anonymous> (src/js/models/program.test.ts:127:20)

I've hacked at this a bit and I have some sense of what's going on, so I'll add a comment with more details.

[philrz]

I confess I have some difficulty understanding quite what this has been testing for us, and open issue #3217 that was left behind after our last breakage/fix described in #3210 indicates there's been some ongoing mystery here. But I've looked at it like a black box and did some Wireshark sniffing before/after the failure.

It's not clear to me if the tests actually care about the data shown in the call to createRecord being present, but with the service running at the "before" commit, I do that for good measure using the contents of attached data.json.

$ curl http://localhost:9867/version
{"version":"b0dc05915"}

$ super db create test
pool created: test 37Of3ZTkho6gk676QJcCWeWL4xb

$ super db use test
Switched to branch "main" on pool "test"

$ super db load data.json 
(2/1) 116B/116B 116B/s 100.00%
37Of3uNf3NbGs4utDWkn9mRZFKa committed

$ super db -c "from 'test'"
{id:{orig_h:"192.168.0.54"},"i d":{"orig h":"192.168.0.54"},proto:"udp",query:"WPAD",count:24}

It looks like the call to fetchQueryInfo ultimately results in a call to the SuperDB service API's DESCRIBE endpoint. At this super commit, my sniffs for one of the test queries looked like the following:

$ curl -X POST -H "Accept: application/json" -H "Content-Type: application/json" -d '{"query":"name==\"james\" | count() by proto | sort -r count","head":{"pool":"test"}}' http://127.0.0.1:9867/query/describe
{"sources":[{"kind":"Null"}],"channels":[{"name":"main","aggregation_keys":[["proto"]],"sort":[{"order":"desc","key":["count"]}]}]}

But if I restart the service at the commit where the test fails, now it looks like:

$ curl http://localhost:9867/version
{"version":"a12d23cc5"}

$ curl -X POST -H "Accept: application/json" -H "Content-Type: application/json" -d '{"query":"name==\"james\" | count() by proto | sort -r count","head":{"pool":"test"}}' http://127.0.0.1:9867/query/describe
{"type":"Error","kind":"invalid operation","error":"\"name\" no such field at line 1, column 1:\nname==\"james\" | count() by proto | sort -r count\n~~~~\n\"proto\" no such field at line 1, column 28:\nname==\"james\" | count() by proto | sort -r count\n                           ~~~~~","compilation_errors":[{"Msg":"\"name\" no such field","Pos":0,"End":3},{"Msg":"\"proto\" no such field","Pos":27,"End":31}]}

What's suspicious to me is that if the test does care about the data that's loaded, then error seems to make sense, i.e., there isn't a field called name in the data, and indeed the error matches what I see if I do:

$ super -version
Version: a12d23cc5

$ super -c "name==\"james\" | count() by proto | sort -r count" data.json 
no such field "name" at line 1, column 1:
name=="james" | count() by proto | sort -r count
~~~~

That said, this query that matches the data works:

$ super -version
Version: a12d23cc5

$ super -c "query==\"WPAD\" | count() by proto | sort -r count" data.json 
{proto:"udp",count:1::uint64}

But attempting that same query against the DESCRIBE endpoint once again fails.

$ curl http://localhost:9867/version
{"version":"a12d23cc5"}

$ curl -X POST -H "Accept: application/json" -H "Content-Type: application/json" -d '{"query":"query==\"WPAD\" | count() by proto | sort -r count","head":{"pool":"test"}}' http://127.0.0.1:9867/query/describe
{"type":"Error","kind":"invalid operation","error":"\"query\" no such field at line 1, column 1:\nquery==\"WPAD\" | count() by proto | sort -r count\n~~~~~\n\"proto\" no such field at line 1, column 28:\nquery==\"WPAD\" | count() by proto | sort -r count\n                           ~~~~~","compilation_errors":[{"Msg":"\"query\" no such field","Pos":0,"End":4},{"Msg":"\"proto\" no such field","Pos":27,"End":31}]}

Finally, when I attempt what I think are equivalent operations in the app, I see that the calls to the DESCRIBE endpoint look different, such that they have the leading from and "head":null, and they get a successful response.

$ curl http://localhost:9867/version
{"version":"a12d23cc5"}

$ curl -X POST -H "Accept: application/json" -H "Content-Type: application/json" -d '{"query":"from 'test' | query==\"WPAD\" | count() by proto | sort -r count","head":null}' http://127.0.0.1:9867/query/describe
{"sources":[{"kind":"Pool","name":"test","id":"0x15dc99d7635383cdacd12cc8e4b74077f9d72fd7"}],"channels":[{"name":"main","aggregation_keys":[["proto"]],"sort":[{"order":"desc","key":["count"]}]}]}