better error messages

added support for capturing stderr when you expect stuff to fail in
order to capture all error messages from the child process.

simplify ServerCmd to always be verbose (print stdin/stdout(stderr)
interactions).

improve ServerCmd to enable explicitly checking the child process exit
code.

fixed test dependency on binary for eval expr and analyze model tests.

9 files changed, 232 insertions, 31 deletions

diff --git a/eval/src/apps/analyze_onnx_model/analyze_onnx_model.cpp b/eval/src/apps/analyze_onnx_model/analyze_onnx_model.cpp
index 506073ae8b3..868e9d036f1 100644
--- a/eval/src/apps/analyze_onnx_model/analyze_onnx_model.cpp
+++ b/eval/src/apps/analyze_onnx_model/analyze_onnx_model.cpp
@@ -20,6 +20,10 @@ using vespalib::FilePointer;
 using namespace vespalib::eval;
 using namespace vespalib::eval::test;
 
+struct MyError {
+    vespalib::string msg;
+};
+
 bool read_line(FilePointer &file, vespalib::string &line) {
     char line_buffer[1024];
     char *res = fgets(line_buffer, sizeof(line_buffer), file.fp());
@@ -139,16 +143,50 @@ struct MakeInputType {
     }
 };
 
+vespalib::string make_bound_str(const std::map<vespalib::string,size_t> &bound) {
+    vespalib::string result;
+    if (!bound.empty()) {
+        for (const auto &[name, size]: bound) {
+            if (result.empty()) {
+                result.append(" (");
+            } else {
+                result.append(",");
+            }
+            result.append(fmt("%s=%zu", name.c_str(), size));
+        }
+        result.append(")");
+    }
+    return result;
+}
+
+void bind_input(Onnx::WirePlanner &planner, const Onnx::TensorInfo &input, const ValueType &type) {
+    auto bound = planner.get_bound_sizes(input);
+    if (!planner.bind_input_type(type, input)) {
+        auto bound_str = make_bound_str(bound);
+        throw MyError{fmt("incompatible type for input '%s': %s -> %s%s",
+                          input.name.c_str(), type.to_spec().c_str(), input.type_as_string().c_str(), bound_str.c_str())};
+    }
+}
+
+ValueType make_output(const Onnx::WirePlanner &planner, const Onnx::TensorInfo &output) {
+    auto type = planner.make_output_type(output);
+    if (type.is_error()) {
+        throw MyError{fmt("unable to make compatible type for output '%s': %s -> error",
+                          output.name.c_str(), output.type_as_string().c_str())};
+    }
+    return type;
+}
+
 Onnx::WireInfo make_plan(Options &opts, const Onnx &model) {
     Onnx::WirePlanner planner;
     MakeInputType make_input_type(opts);
     for (const auto &input: model.inputs()) {
         auto type = make_input_type(input);
-        REQUIRE(planner.bind_input_type(type, input));
+        bind_input(planner, input, type);
     }
     planner.prepare_output_types(model);
     for (const auto &output: model.outputs()) {
-        REQUIRE(!planner.make_output_type(output).is_error());
+        make_output(planner, output);
     }
     return planner.get_wire_info(model);
 }
@@ -189,7 +227,7 @@ int probe_types() {
     StdOut std_out;
     Slime params;
     if (!JsonFormat::decode(std_in, params)) {
-        return 3;
+        throw MyError{"invalid json"};
     }
     Slime result;
     auto &root = result.setObject();
@@ -199,13 +237,20 @@ int probe_types() {
     for (size_t i = 0; i < model.inputs().size(); ++i) {
         auto spec = params["inputs"][model.inputs()[i].name].asString().make_string();
         auto input_type = ValueType::from_spec(spec);
-        REQUIRE(!input_type.is_error());
-        REQUIRE(planner.bind_input_type(input_type, model.inputs()[i]));
+        if (input_type.is_error()) {
+            if (!params["inputs"][model.inputs()[i].name].valid()) {
+                throw MyError{fmt("missing type for model input '%s'",
+                                  model.inputs()[i].name.c_str())};
+            } else {
+                throw MyError{fmt("invalid type for model input '%s': '%s'",
+                                  model.inputs()[i].name.c_str(), spec.c_str())};
+            }
+        }
+        bind_input(planner, model.inputs()[i], input_type);
     }
     planner.prepare_output_types(model);
     for (const auto &output: model.outputs()) {
-        auto output_type = planner.make_output_type(output);
-        REQUIRE(!output_type.is_error());
+        auto output_type = make_output(planner, output);
         types.setString(output.name, output_type.to_spec());
     }
     write_compact(result, std_out);
@@ -253,6 +298,9 @@ int my_main(int argc, char **argv) {
 int main(int argc, char **argv) {
     try {
         return my_main(argc, argv);
+    } catch (const MyError &err) {
+        fprintf(stderr, "error: %s\n", err.msg.c_str());
+        return 3;
     } catch (const std::exception &ex) {
         fprintf(stderr, "got exception: %s\n", ex.what());
         return 2;
diff --git a/eval/src/tests/apps/analyze_onnx_model/CMakeLists.txt b/eval/src/tests/apps/analyze_onnx_model/CMakeLists.txt
index 7b70360a622..06241b0add6 100644
--- a/eval/src/tests/apps/analyze_onnx_model/CMakeLists.txt
+++ b/eval/src/tests/apps/analyze_onnx_model/CMakeLists.txt
@@ -4,6 +4,7 @@ vespa_add_executable(eval_analyze_onnx_model_test_app TEST
     analyze_onnx_model_test.cpp
     DEPENDS
     vespaeval
+    AFTER
+    eval_analyze_onnx_model_app
 )
-vespa_add_test(NAME eval_analyze_onnx_model_test_app COMMAND eval_analyze_onnx_model_test_app
-               DEPENDS eval_analyze_onnx_model_test_app eval_analyze_onnx_model_app)
+vespa_add_test(NAME eval_analyze_onnx_model_test_app COMMAND eval_analyze_onnx_model_test_app)
diff --git a/eval/src/tests/apps/analyze_onnx_model/analyze_onnx_model_test.cpp b/eval/src/tests/apps/analyze_onnx_model/analyze_onnx_model_test.cpp
index 58cc7c22358..72ef0346ea3 100644
--- a/eval/src/tests/apps/analyze_onnx_model/analyze_onnx_model_test.cpp
+++ b/eval/src/tests/apps/analyze_onnx_model/analyze_onnx_model_test.cpp
@@ -17,10 +17,12 @@ vespalib::string get_source_dir() {
 }
 vespalib::string source_dir = get_source_dir();
 vespalib::string probe_model = source_dir + "/../../tensor/onnx_wrapper/probe_model.onnx";
+vespalib::string simple_model = source_dir + "/../../tensor/onnx_wrapper/simple.onnx";
+vespalib::string dynamic_model = source_dir + "/../../tensor/onnx_wrapper/dynamic.onnx";
 
 //-----------------------------------------------------------------------------
 
-TEST_F("require that output types can be probed", ServerCmd(probe_cmd, true)) {
+TEST_F("require that output types can be probed", ServerCmd(probe_cmd)) {
     Slime params;
     params.setObject();
     params.get().setString("model", probe_model);
@@ -32,6 +34,65 @@ TEST_F("require that output types can be probed", ServerCmd(probe_cmd, true)) {
     EXPECT_EQUAL(result["outputs"]["out1"].asString().make_string(), vespalib::string("tensor<float>(d0[2],d1[3])"));
     EXPECT_EQUAL(result["outputs"]["out2"].asString().make_string(), vespalib::string("tensor<float>(d0[2],d1[3])"));
     EXPECT_EQUAL(result["outputs"]["out3"].asString().make_string(), vespalib::string("tensor<float>(d0[2],d1[3])"));
+    EXPECT_EQUAL(f1.shutdown(), 0);
+}
+
+//-----------------------------------------------------------------------------
+
+TEST_F("test error: invalid json", ServerCmd(probe_cmd, ServerCmd::capture_stderr_tag())) {
+    auto out = f1.write_then_read_all("this is not valid json...\n");
+    EXPECT_TRUE(out.find("invalid json") < out.size());
+    EXPECT_EQUAL(f1.shutdown(), 3);
+}
+
+TEST_F("test error: missing input type", ServerCmd(probe_cmd, ServerCmd::capture_stderr_tag())) {
+    Slime params;
+    params.setObject();
+    params.get().setString("model", simple_model);
+    params.get().setObject("inputs");
+    auto out = f1.write_then_read_all(params.toString());
+    EXPECT_TRUE(out.find("missing type") < out.size());
+    EXPECT_EQUAL(f1.shutdown(), 3);
+}
+
+TEST_F("test error: invalid input type", ServerCmd(probe_cmd, ServerCmd::capture_stderr_tag())) {
+    Slime params;
+    params.setObject();
+    params.get().setString("model", simple_model);
+    params.get().setObject("inputs");
+    params["inputs"].setString("query_tensor", "bogus type string");
+    params["inputs"].setString("attribute_tensor", "tensor<float>(x[4],y[1])");
+    params["inputs"].setString("bias_tensor", "tensor<float>(x[1],y[1])");
+    auto out = f1.write_then_read_all(params.toString());
+    EXPECT_TRUE(out.find("invalid type") < out.size());
+    EXPECT_EQUAL(f1.shutdown(), 3);
+}
+
+TEST_F("test error: incompatible input type", ServerCmd(probe_cmd, ServerCmd::capture_stderr_tag())) {
+    Slime params;
+    params.setObject();
+    params.get().setString("model", simple_model);
+    params.get().setObject("inputs");
+    params["inputs"].setString("query_tensor", "tensor<float>(x[1],y[5])");
+    params["inputs"].setString("attribute_tensor", "tensor<float>(x[4],y[1])");
+    params["inputs"].setString("bias_tensor", "tensor<float>(x[1],y[1])");
+    auto out = f1.write_then_read_all(params.toString());
+    EXPECT_TRUE(out.find("incompatible type") < out.size());
+    EXPECT_EQUAL(f1.shutdown(), 3);
+}
+
+TEST_F("test error: symbolic size mismatch", ServerCmd(probe_cmd, ServerCmd::capture_stderr_tag())) {
+    Slime params;
+    params.setObject();
+    params.get().setString("model", dynamic_model);
+    params.get().setObject("inputs");
+    params["inputs"].setString("query_tensor", "tensor<float>(x[1],y[4])");
+    params["inputs"].setString("attribute_tensor", "tensor<float>(x[4],y[1])");
+    params["inputs"].setString("bias_tensor", "tensor<float>(x[2],y[1])");
+    auto out = f1.write_then_read_all(params.toString());
+    EXPECT_TRUE(out.find("incompatible type") < out.size());
+    EXPECT_TRUE(out.find("batch=1") < out.size());
+    EXPECT_EQUAL(f1.shutdown(), 3);
 }
 
 //-----------------------------------------------------------------------------
diff --git a/eval/src/tests/apps/eval_expr/CMakeLists.txt b/eval/src/tests/apps/eval_expr/CMakeLists.txt
index e36c5aafe23..c36cf33e2b2 100644
--- a/eval/src/tests/apps/eval_expr/CMakeLists.txt
+++ b/eval/src/tests/apps/eval_expr/CMakeLists.txt
@@ -4,6 +4,7 @@ vespa_add_executable(eval_eval_expr_test_app TEST
     eval_expr_test.cpp
     DEPENDS
     vespaeval
+    AFTER
+    eval_eval_expr_app
 )
-vespa_add_test(NAME eval_eval_expr_test_app COMMAND eval_eval_expr_test_app
-               DEPENDS eval_eval_expr_test_app eval_eval_expr_app)
+vespa_add_test(NAME eval_eval_expr_test_app COMMAND eval_eval_expr_test_app)
diff --git a/eval/src/tests/apps/eval_expr/eval_expr_test.cpp b/eval/src/tests/apps/eval_expr/eval_expr_test.cpp
index 3834ea0e4cc..fd103829618 100644
--- a/eval/src/tests/apps/eval_expr/eval_expr_test.cpp
+++ b/eval/src/tests/apps/eval_expr/eval_expr_test.cpp
@@ -56,7 +56,7 @@ Result::~Result() = default;
 
 struct Server : public ServerCmd {
     TimeBomb time_bomb;
-    Server() : ServerCmd(server_cmd, true), time_bomb(60) {}
+    Server() : ServerCmd(server_cmd), time_bomb(60) {}
     Result eval(const vespalib::string &expr, const vespalib::string &name = {}, bool verbose = false) {
         Slime req;
         auto &obj = req.setObject();
@@ -70,6 +70,9 @@ struct Server : public ServerCmd {
         Slime reply = invoke(req);
         return {reply.get()};
     }
+    ~Server() {
+        EXPECT_EQUAL(shutdown(), 0);
+    }
 };
 
 //-----------------------------------------------------------------------------
diff --git a/eval/src/vespa/eval/eval/test/test_io.cpp b/eval/src/vespa/eval/eval/test/test_io.cpp
index ed7723f0748..044b6779431 100644
--- a/eval/src/vespa/eval/eval/test/test_io.cpp
+++ b/eval/src/vespa/eval/eval/test/test_io.cpp
@@ -120,45 +120,104 @@ ChildOut::evict(size_t bytes)
 //-----------------------------------------------------------------------------
 
 void
-ServerCmd::maybe_dump_message(const char *prefix, const Slime &slime)
+ServerCmd::maybe_close()
 {
-    if (_verbose) {
-        SimpleBuffer buf;
-        slime::JsonFormat::encode(slime, buf, false);
-        auto str = buf.get().make_string();
-        fprintf(stderr, "%s%s: %s", prefix, _basename.c_str(), str.c_str());
+    if (!_closed) {
+        _child.close();
+        _closed = true;
     }
 }
 
-ServerCmd::ServerCmd(vespalib::string cmd, bool verbose)
+void
+ServerCmd::maybe_exit()
+{
+    if (!_exited) {
+        read_until_eof(_child_stdout);
+        assert(_child.wait());
+        assert(!_child.running());
+        _exit_code = _child.getExitCode();
+        _exited = true;
+    }
+}
+
+void
+ServerCmd::dump_string(const char *prefix, const vespalib::string &str)
+{
+    fprintf(stderr, "%s%s: '%s'\n", prefix, _basename.c_str(), str.c_str());
+}
+
+void
+ServerCmd::dump_message(const char *prefix, const Slime &slime)
+{
+    SimpleBuffer buf;
+    slime::JsonFormat::encode(slime, buf, false);
+    auto str = buf.get().make_string();
+    fprintf(stderr, "%s%s: %s", prefix, _basename.c_str(), str.c_str());
+}
+
+ServerCmd::ServerCmd(vespalib::string cmd)
   : _child(cmd.c_str()),
     _child_stdin(_child),
     _child_stdout(_child),
     _basename(fs::path(cmd).filename()),
-    _verbose(verbose)
+    _closed(false),
+    _exited(false),
+    _exit_code(31212)
+{
+}
+
+ServerCmd::ServerCmd(vespalib::string cmd, capture_stderr_tag)
+  : _child(cmd.c_str(), ChildProcess::capture_stderr_tag()),
+    _child_stdin(_child),
+    _child_stdout(_child),
+    _basename(fs::path(cmd).filename()),
+    _closed(false),
+    _exited(false),
+    _exit_code(31212)
 {
 }
 
 ServerCmd::~ServerCmd()
 {
-    _child.close();
-    read_until_eof(_child_stdout);
-    assert(_child.wait());
-    assert(!_child.running());
-    assert(!_child.failed());
+    maybe_close();
+    maybe_exit();
 }
 
 Slime
 ServerCmd::invoke(const Slime &req)
 {
-    maybe_dump_message("request --> ", req);
+    dump_message("request --> ", req);
     write_compact(req, _child_stdin);
     Slime reply;
     REQUIRE(JsonFormat::decode(_child_stdout, reply));
-    maybe_dump_message("reply <-- ", reply);
+    dump_message("reply <-- ", reply);
     return reply;
 }
 
+vespalib::string
+ServerCmd::write_then_read_all(const vespalib::string &input)
+{
+    vespalib::string result;
+    dump_string("input --> ", input);
+    memcpy(_child_stdin.reserve(input.size()).data, input.data(), input.size());
+    _child_stdin.commit(input.size());
+    maybe_close();
+    for (auto mem = _child_stdout.obtain(); mem.size > 0; mem = _child_stdout.obtain()) {
+        result.append(mem.data, mem.size);
+        _child_stdout.evict(mem.size);
+    }
+    dump_string("output <-- ", result);
+    return result;
+}
+
+int
+ServerCmd::shutdown()
+{
+    maybe_close();
+    maybe_exit();
+    return _exit_code;
+}
+
 //-----------------------------------------------------------------------------
 
 bool
diff --git a/eval/src/vespa/eval/eval/test/test_io.h b/eval/src/vespa/eval/eval/test/test_io.h
index cef6cd6ae40..62fd6588780 100644
--- a/eval/src/vespa/eval/eval/test/test_io.h
+++ b/eval/src/vespa/eval/eval/test/test_io.h
@@ -73,13 +73,24 @@ private:
     ChildIn _child_stdin;
     ChildOut _child_stdout;
     vespalib::string _basename;
-    bool _verbose;
+    bool _closed;
+    bool _exited;
+    int _exit_code;
+
+    void maybe_close();
+    void maybe_exit();
+
+    void dump_string(const char *prefix, const vespalib::string &str);
+    void dump_message(const char *prefix, const Slime &slime);
 
-    void maybe_dump_message(const char *prefix, const Slime &slime);
 public:
-    ServerCmd(vespalib::string cmd, bool verbose);
+    struct capture_stderr_tag{};
+    ServerCmd(vespalib::string cmd);
+    ServerCmd(vespalib::string cmd, capture_stderr_tag);
     ~ServerCmd();
     Slime invoke(const Slime &req);
+    vespalib::string write_then_read_all(const vespalib::string &input);
+    int shutdown();
 };
 
 /**
diff --git a/eval/src/vespa/eval/onnx/onnx_wrapper.cpp b/eval/src/vespa/eval/onnx/onnx_wrapper.cpp
index 54c4b863e35..ed38a385d25 100644
--- a/eval/src/vespa/eval/onnx/onnx_wrapper.cpp
+++ b/eval/src/vespa/eval/onnx/onnx_wrapper.cpp
@@ -382,6 +382,22 @@ Onnx::WirePlanner::bind_input_type(const ValueType &vespa_in, const TensorInfo &
     return true;
 }
 
+std::map<vespalib::string,size_t>
+Onnx::WirePlanner::get_bound_sizes(const TensorInfo &onnx_in) const
+{
+    std::map<vespalib::string,size_t> result;
+    for (const auto &dim: onnx_in.dimensions) {
+        if (dim.is_symbolic()) {
+            auto pos = _symbolic_sizes.find(dim.name);
+            if (pos != _symbolic_sizes.end()) {
+                assert(pos->second != 0);
+                result.emplace(dim.name, pos->second);
+            }
+        }
+    }
+    return result;
+}
+
 void
 Onnx::WirePlanner::prepare_output_types(const Onnx &model)
 {
diff --git a/eval/src/vespa/eval/onnx/onnx_wrapper.h b/eval/src/vespa/eval/onnx/onnx_wrapper.h
index 678a4e40563..31421019e3c 100644
--- a/eval/src/vespa/eval/onnx/onnx_wrapper.h
+++ b/eval/src/vespa/eval/onnx/onnx_wrapper.h
@@ -94,6 +94,7 @@ public:
         ~WirePlanner();
         static CellType best_cell_type(Onnx::ElementType type);
         bool bind_input_type(const ValueType &vespa_in, const TensorInfo &onnx_in);
+        std::map<vespalib::string,size_t> get_bound_sizes(const TensorInfo &onnx_in) const;
         void prepare_output_types(const Onnx &model);
         ValueType make_output_type(const TensorInfo &onnx_out) const;
         WireInfo get_wire_info(const Onnx &model) const;