confluentinc / confluentinc/kafka-tutorials
harness_runner doesn't write errors from ksql-test-runner to file
- Dominant language
- Java
- Stars
- 39
- Forks
- 91
- PR merge metrics
- No merged PRs in 30d
Description
The `harness_runner` doesn't write error output from the `ksql-test-runner` process to file, but instead emits it to the stdout of the `make` process.
E.g.:
```
$ make
rm -r recipe-steps/dev/outputs || true
rm -r recipe-steps/test/outputs || true
mkdir recipe-steps/dev/outputs
mkdir recipe-steps/test/outputs
harness-runner ../../../../../_data/harnesses/aggregating-count/ksql.yml /var/folders/q9/2tg_lt9j6nx29rvr5r5jn_bw0000gp/T/tmp.6VK4eIja
Creating network "aggregate-count_default" with the default driver
Creating zookeeper ... done
Creating broker ... done
Creating schema-registry ... done
Creating ksql-server ... done
Creating ksql-cli ... done
[…]
schema-registry | [2019-08-02 09:58:00,212] INFO 192.168.80.5 - - [02/Aug/2019:09:58:00 +0000] "GET /schemas/ids/3 HTTP/1.1" 200 374 3 (io.confluent.rest-utils.requests)
schema-registry | [2019-08-02 09:58:00,230] INFO 192.168.80.5 - - [02/Aug/2019:09:58:00 +0000] "GET /schemas/ids/3 HTTP/1.1" 200 374 10 (io.confluent.rest-utils.requests)
schema-registry | [2019-08-02 09:58:00,247] INFO 192.168.80.5 - - [02/Aug/2019:09:58:00 +0000] "POST /subjects/_confluent-ksql-default_query_CTAS_MOVIE_TICKETS_SOLD_0-Aggregate-aggregate-changelog-value
?deleted=true HTTP/1.1" 200 497 10 (io.confluent.rest-utils.requests)
broker | [2019-08-02 09:58:00,851] INFO [GroupCoordinator 1]: Member _confluent-ksql-default_transient_2861502097993161666_1564739862810-c0de7125-4e65-4b3c-8910-0cd31044f233-StreamThread-1-cons
umer-28d6d9b8-8a0d-4f65-a616-2be13d36ede8 in group _confluent-ksql-default_transient_2861502097993161666_1564739862810 has failed, removing it from the group (kafka.coordinator.group.GroupCoordinator)
broker | [2019-08-02 09:58:00,855] INFO [GroupCoordinator 1]: Preparing to rebalance group _confluent-ksql-default_transient_2861502097993161666_1564739862810 in state PreparingRebalance with o
ld generation 2 (__consumer_offsets-29) (reason: removing member _confluent-ksql-default_transient_2861502097993161666_1564739862810-c0de7125-4e65-4b3c-8910-0cd31044f233-StreamThread-1-consumer-28d6d9b8-8a
0d-4f65-a616-2be13d36ede8 on heartbeat expiration) (kafka.coordinator.group.GroupCoordinator)
broker | [2019-08-02 09:58:00,855] INFO [GroupCoordinator 1]: Member _confluent-ksql-default_transient_2861502097993161666_1564739862810-c0de7125-4e65-4b3c-8910-0cd31044f233-StreamThread-2-cons
umer-6b259188-0529-4322-a1b4-49109e7e1a4f in group _confluent-ksql-default_transient_2861502097993161666_1564739862810 has failed, removing it from the group (kafka.coordinator.group.GroupCoordinator)
schema-registry | [2019-08-02 09:58:01,818] INFO Wait to catch up until the offset of the last message at 8 (io.confluent.kafka.schemaregistry.storage.KafkaStore)
schema-registry | [2019-08-02 09:58:01,861] INFO 192.168.80.5 - - [02/Aug/2019:09:58:01 +0000] "POST /subjects/MOVIE_TICKETS_SOLD-value/versions HTTP/1.1" 200 8 46 (io.confluent.rest-utils.requests)
schema-registry | [2019-08-02 09:58:01,945] INFO 192.168.80.5 - - [02/Aug/2019:09:58:01 +0000] "GET /schemas/ids/4 HTTP/1.1" 200 273 6 (io.confluent.rest-utils.requests)
broker | [2019-08-02 09:58:02,017] INFO [Log partition=_confluent-ksql-default_query_CTAS_MOVIE_TICKETS_SOLD_0-Aggregate-groupby-repartition-0, dir=/var/lib/kafka/data] Incrementing log start o
ffset to 9 (kafka.log.Log)
broker | [2019-08-02 09:58:03,953] INFO [GroupCoordinator 1]: Member _confluent-ksql-default_transient_2861502097993161666_1564739862810-c0de7125-4e65-4b3c-8910-0cd31044f233-StreamThread-3-cons
umer-827bed43-eda3-4707-bbf4-251c6846cc81 in group _confluent-ksql-default_transient_2861502097993161666_1564739862810 has failed, removing it from the group (kafka.coordinator.group.GroupCoordinator)
broker | [2019-08-02 09:58:03,953] INFO [GroupCoordinator 1]: Member _confluent-ksql-default_transient_2861502097993161666_1564739862810-c0de7125-4e65-4b3c-8910-0cd31044f233-StreamThread-4-cons
umer-8b1fa2a7-e2a1-4087-b676-c02af3a3fe39 in group _confluent-ksql-default_transient_2861502097993161666_1564739862810 has failed, removing it from the group (kafka.coordinator.group.GroupCoordinator)
broker | [2019-08-02 09:58:03,955] INFO [GroupCoordinator 1]: Group _confluent-ksql-default_transient_2861502097993161666_1564739862810 with generation 3 is now empty (__consumer_offsets-29) (k
afka.coordinator.group.GroupCoordinator)
>>>>> Test failed: Expected <9> records but it was <0>
Stopping ksql-cli ... done
Stopping ksql-server ...
Stopping schema-registry ...
Stopping ksql-server ... done
Stopping zookeeper ...
ksql-cli exited with code 137
ksql-server exited with code 143
schema-registry | [2019-08-02 09:58:28,170] INFO Stopped NetworkTrafficServerConnector@604f2bd2{HTTP/1.1,[http/1.1]}{0.0.0.0:8081} (org.eclipse.jetty.server.AbstractConnector)
schema-registry | [2019-08-02 09:58:28,171] INFO node0 Stopped scavenging (org.eclipse.jetty.server.session)
schema-registry | [2019-08-02 09:58:28,184] INFO Stopped o.e.j.s.ServletContextHandler@60957c0f{/ws,null,UNAVAILABLE} (org.eclipse.jetty.server.handler.ContextHandler)
schema-registry | [2019-08-02 09:58:28,232] INFO Stopped o.e.j.s.ServletContextHandler@293a5f75{/,null,UNAVAILABLE} (org.eclipse.jetty.server.handler.ContextHandler)
schema-registry | [2019-08-02 09:58:28,241] INFO Shutting down schema registry (io.confluent.kafka.schemaregistry.storage.KafkaSchemaRegistry)
schema-registry | [2019-08-02 09:58:28,243] INFO [kafka-store-reader-thread-_schemas]: Shutting down (io.confluent.kafka.schemaregistry.storage.KafkaStoreReaderThread)
schema-registry | [2019-08-02 09:58:28,246] INFO [kafka-store-reader-thread-_schemas]: Stopped (io.confluent.kafka.schemaregistry.storage.KafkaStoreReaderThread)
[…]
71216 already exited.
diff --strip-trailing-cr recipe-steps/dev/expected-transient-query.log recipe-steps/dev/outputs/transient-query/output-0.log
bash -c "diff --strip-trailing-cr <(cut -d ',' -f 3- recipe-steps/dev/expected-print-output-topic.log) <(cut -d ',' -f 3- recipe-steps/dev/outputs/print-output-topic/output-0.log)"
diff --strip-trailing-cr recipe-steps/test/expected-results.log recipe-steps/test/outputs/test-results.log
1d0
< >>> Test passed!
make: *** [recipe] Error 1
```
The output from `ksql-test-runner` is ` >>>>> Test failed: Expected <9> records but it was <0>` and should be written to the output file but isn't:
```
$ ls -l recipe-steps/test/outputs/test-results.log
-rw-r--r-- 1 Robin staff 0 2 Aug 11:08 recipe-steps/test/outputs/test-results.log
```
Contributor guide
Assessment
This issue has not been assessed yet.