Output goes into the wrong tag

[ctron]

Output goes into the wrong tag

[johnterickson]

@ctron thanks for the pointers! Hmm, this is odd because my code is calling set_system_out. It appears the library I am using only uses system-out for successes: https://github.com/bachp/junit-report-rs/blob/36c3093e7c3c049fb5dc4aa77657938ea8c5ea1e/src/reports.rs#L104-L149

Could you share a sample input/expected-output pair?

[ctron]

Sure, here is an example: test-output.zip

It contains the raw output (mostly JSON). The markdown of our report generator (with the expected output rendered) and the file generated by cargo2junit.

[johnterickson]

@ctron Happy New Year! I looked at the output from your zip (thanks!) and I'm only seeing the string stderr inside the stdout field from cargo. Reformatted:

{
    "type": "test",
    "name": "tests::registry::test_registry_create_and_delete",
    "event": "failed",
    "exec_time": 7.918437536,
    "stdout": "[2021-09-17T08:19:49Z INFO  drogue_cloud_tests::init::drg] Endpoints: Object({\n        \"api\": String(\n            \"http://api.172.18.0.2.nip.io\",\n        ),\n        \"console\": String(\n            \"http://console.172.18.0.2.nip.io\",\n        ),\n        \"issuer_url\": String(\n            \"http://sso.172.18.0.2.nip.io/auth/realms/drogue\",\n        ),\n        \"registry\": Object({\n            \"url\": String(\n                \"http://api.172.18.0.2.nip.io\",\n            ),\n        }),\n        \"sso\": String(\n            \"http://sso.172.18.0.2.nip.io\",\n        ),\n    })\n[2021-09-17T08:19:53Z INFO  drogue_cloud_tests::init::drg] Refresh token: REDACTED\n[2021-09-17T08:19:53Z INFO  drogue_cloud_tests::init::drg] Running: \"drg\" \"context\" \"delete\" \"system-tests\"\n[2021-09-17T08:19:53Z INFO  drogue_cloud_tests::init::drg] Output: Ok(Output { status: ExitStatus(ExitStatus(0)), stdout: \"\", stderr: \"\" })\n[2021-09-17T08:19:53Z INFO  drogue_cloud_tests::init::drg] Running: \"drg\" \"login\" \"http://api.172.18.0.2.nip.io/\" \"-t\" \"REDACTED\" \"--context\" \"system-tests\"\n[2021-09-17T08:19:53Z INFO  drogue_cloud_tests::init::drg] Output: Ok(Output { status: ExitStatus(ExitStatus(0)), stdout: \"\\nSuccessfully authenticated to drogue cloud : http://api.172.18.0.2.nip.io/\\nSwitched active context to: system-tests\\n\", stderr: \"\" })\n[2021-09-17T08:19:54Z INFO  drogue_cloud_tests::resources::apps] Create application: fbdc3442-654f-4f1e-b5d0-dbdd09966c88\n[2021-09-17T08:19:54Z INFO  drogue_cloud_tests::init::drg] Running: \"drg\" \"create\" \"app\" \"fbdc3442-654f-4f1e-b5d0-dbdd09966c88\"\n[2021-09-17T08:19:54Z INFO  drogue_cloud_tests::init::drg] Output: Ok(Output { status: ExitStatus(ExitStatus(0)), stdout: \"App fbdc3442-654f-4f1e-b5d0-dbdd09966c88 created.\\n\", stderr: \"\" })\n[2021-09-17T08:19:54Z INFO  drogue_cloud_tests::init::drg] Running: \"drg\" \"get\" \"app\" \"fbdc3442-654f-4f1e-b5d0-dbdd09966c88\"\n[2021-09-17T08:19:54Z INFO  drogue_cloud_tests::init::drg] Output: Ok(Output { status: ExitStatus(ExitStatus(0)), stdout: \"{\\n  \\\"metadata\\\": {\\n    \\\"creationTimestamp\\\": \\\"2021-09-17T08:19:54.540768Z\\\",\\n    \\\"generation\\\": 0,\\n    \\\"name\\\": \\\"fbdc3442-654f-4f1e-b5d0-dbdd09966c88\\\",\\n    \\\"resourceVersion\\\": \\\"c180b095-f016-4293-bd14-389fd64acefc\\\",\\n    \\\"uid\\\": \\\"4e554a97-8ede-4a5b-9efd-ad1182a69767\\\"\\n  }\\n}\", stderr: \"\" })\n[2021-09-17T08:19:55Z INFO  drogue_cloud_tests::init::drg] Running: \"drg\" \"get\" \"app\" \"fbdc3442-654f-4f1e-b5d0-dbdd09966c88\"\n[2021-09-17T08:19:55Z INFO  drogue_cloud_tests::init::drg] Output: Ok(Output { status: ExitStatus(ExitStatus(0)), stdout: \"{\\n  \\\"metadata\\\": {\\n    \\\"creationTimestamp\\\": \\\"2021-09-17T08:19:54.540768Z\\\",\\n    \\\"finalizers\\\": [\\n      \\\"kafka\\\"\\n    ],\\n    \\\"generation\\\": 9,\\n    \\\"name\\\": \\\"fbdc3442-654f-4f1e-b5d0-dbdd09966c88\\\",\\n    \\\"resourceVersion\\\": \\\"b5b074e2-1d05-4bc3-ae22-6e047e058337\\\",\\n    \\\"uid\\\": \\\"4e554a97-8ede-4a5b-9efd-ad1182a69767\\\"\\n  },\\n  \\\"status\\\": {\\n    \\\"conditions\\\": [\\n      {\\n        \\\"lastTransitionTime\\\": \\\"2021-09-17T08:19:54.911921639Z\\\",\\n        \\\"status\\\": \\\"True\\\",\\n        \\\"type\\\": \\\"Ready\\\"\\n      },\\n      {\\n        \\\"lastTransitionTime\\\": \\\"2021-09-17T08:19:54.911883970Z\\\",\\n        \\\"status\\\": \\\"True\\\",\\n        \\\"type\\\": \\\"KafkaReady\\\"\\n      }\\n    ],\\n    \\\"kafka\\\": {\\n      \\\"conditions\\\": [\\n        {\\n          \\\"lastTransitionTime\\\": \\\"2021-09-17T08:19:54.609800578Z\\\",\\n          \\\"status\\\": \\\"True\\\",\\n          \\\"type\\\": \\\"HasFinalizer\\\"\\n        },\\n        {\\n          \\\"lastTransitionTime\\\": \\\"2021-09-17T08:19:54.618243467Z\\\",\\n          \\\"status\\\": \\\"True\\\",\\n          \\\"type\\\": \\\"CreateTopics\\\"\\n        },\\n        {\\n          \\\"lastTransitionTime\\\": \\\"2021-09-17T08:19:54.691776793Z\\\",\\n          \\\"status\\\": \\\"True\\\",\\n          \\\"type\\\": \\\"TopicsReady\\\"\\n        },\\n        {\\n          \\\"lastTransitionTime\\\": \\\"2021-09-17T08:19:54.709395537Z\\\",\\n          \\\"status\\\": \\\"True\\\",\\n          \\\"type\\\": \\\"CreateUser\\\"\\n        },\\n        {\\n          \\\"lastTransitionTime\\\": \\\"2021-09-17T08:19:54.911855667Z\\\",\\n          \\\"status\\\": \\\"True\\\",\\n          \\\"type\\\": \\\"UserReady\\\"\\n        },\\n        {\\n          \\\"lastTransitionTime\\\": \\\"2021-09-17T08:19:54.911857600Z\\\",\\n          \\\"reason\\\": \\\"AsExpected\\\",\\n          \\\"status\\\": \\\"True\\\",\\n          \\\"type\\\": \\\"Reconciled\\\"\\n        }\\n      ],\\n      \\\"observedGeneration\\\": 8,\\n      \\\"user\\\": {\\n        \\\"mechanism\\\": \\\"SCRAM-SHA-512\\\",\\n        \\\"password\\\": \\\"azZ3Zl3y6j4J\\\",\\n        \\\"username\\\": \\\"user-fbdc3442-654f-4f1e-b5d0-dbdd09966c88\\\"\\n      }\\n    }\\n  }\\n}\", stderr: \"\" })\n[2021-09-17T08:19:55Z INFO  drogue_cloud_tests::init::drg] Running: \"drg\" \"get\" \"app\" \"fbdc3442-654f-4f1e-b5d0-dbdd09966c88\"\n[2021-09-17T08:19:55Z INFO  drogue_cloud_tests::init::drg] Output: Ok(Output { status: ExitStatus(ExitStatus(0)), stdout: \"{\\n  \\\"metadata\\\": {\\n    \\\"creationTimestamp\\\": \\\"2021-09-17T08:19:54.540768Z\\\",\\n    \\\"finalizers\\\": [\\n      \\\"kafka\\\"\\n    ],\\n    \\\"generation\\\": 9,\\n    \\\"name\\\": \\\"fbdc3442-654f-4f1e-b5d0-dbdd09966c88\\\",\\n    \\\"resourceVersion\\\": \\\"b5b074e2-1d05-4bc3-ae22-6e047e058337\\\",\\n    \\\"uid\\\": \\\"4e554a97-8ede-4a5b-9efd-ad1182a69767\\\"\\n  },\\n  \\\"status\\\": {\\n    \\\"conditions\\\": [\\n      {\\n        \\\"lastTransitionTime\\\": \\\"2021-09-17T08:19:54.911921639Z\\\",\\n        \\\"status\\\": \\\"True\\\",\\n        \\\"type\\\": \\\"Ready\\\"\\n      },\\n      {\\n        \\\"lastTransitionTime\\\": \\\"2021-09-17T08:19:54.911883970Z\\\",\\n        \\\"status\\\": \\\"True\\\",\\n        \\\"type\\\": \\\"KafkaReady\\\"\\n      }\\n    ],\\n    \\\"kafka\\\": {\\n      \\\"conditions\\\": [\\n        {\\n          \\\"lastTransitionTime\\\": \\\"2021-09-17T08:19:54.609800578Z\\\",\\n          \\\"status\\\": \\\"True\\\",\\n          \\\"type\\\": \\\"HasFinalizer\\\"\\n        },\\n        {\\n          \\\"lastTransitionTime\\\": \\\"2021-09-17T08:19:54.618243467Z\\\",\\n          \\\"status\\\": \\\"True\\\",\\n          \\\"type\\\": \\\"CreateTopics\\\"\\n        },\\n        {\\n          \\\"lastTransitionTime\\\": \\\"2021-09-17T08:19:54.691776793Z\\\",\\n          \\\"status\\\": \\\"True\\\",\\n          \\\"type\\\": \\\"TopicsReady\\\"\\n        },\\n        {\\n          \\\"lastTransitionTime\\\": \\\"2021-09-17T08:19:54.709395537Z\\\",\\n          \\\"status\\\": \\\"True\\\",\\n          \\\"type\\\": \\\"CreateUser\\\"\\n        },\\n        {\\n          \\\"lastTransitionTime\\\": \\\"2021-09-17T08:19:54.911855667Z\\\",\\n          \\\"status\\\": \\\"True\\\",\\n          \\\"type\\\": \\\"UserReady\\\"\\n        },\\n        {\\n          \\\"lastTransitionTime\\\": \\\"2021-09-17T08:19:54.911857600Z\\\",\\n          \\\"reason\\\": \\\"AsExpected\\\",\\n          \\\"status\\\": \\\"True\\\",\\n          \\\"type\\\": \\\"Reconciled\\\"\\n        }\\n      ],\\n      \\\"observedGeneration\\\": 8,\\n      \\\"user\\\": {\\n        \\\"mechanism\\\": \\\"SCRAM-SHA-512\\\",\\n        \\\"password\\\": \\\"azZ3Zl3y6j4J\\\",\\n        \\\"username\\\": \\\"user-fbdc3442-654f-4f1e-b5d0-dbdd09966c88\\\"\\n      }\\n    }\\n  }\\n}\", stderr: \"\" })\n[2021-09-17T08:19:55Z INFO  drogue_cloud_tests::init::drg] Running: \"drg\" \"delete\" \"app\" \"fbdc3442-654f-4f1e-b5d0-dbdd09966c88\"\n[2021-09-17T08:19:55Z INFO  drogue_cloud_tests::init::drg] Output: Ok(Output { status: ExitStatus(ExitStatus(0)), stdout: \"App fbdc3442-654f-4f1e-b5d0-dbdd09966c88 deleted.\\n\", stderr: \"\" })\n[2021-09-17T08:19:55Z INFO  drogue_cloud_tests::init::drg] Running: \"drg\" \"delete\" \"app\" \"fbdc3442-654f-4f1e-b5d0-dbdd09966c88\"\n[2021-09-17T08:19:55Z INFO  drogue_cloud_tests::init::drg] Output: Ok(Output { status: ExitStatus(ExitStatus(0)), stdout: \"App fbdc3442-654f-4f1e-b5d0-dbdd09966c88 deleted.\\n\", stderr: \"\" })\nthread 'main' panicked at 'assertion failed: r.is_err()', src/tests/registry/mod.rs:53:5\n[2021-09-17T08:19:55Z INFO  drogue_cloud_tests::resources::apps] Destroy application 'fbdc3442-654f-4f1e-b5d0-dbdd09966c88'\n[2021-09-17T08:19:55Z INFO  drogue_cloud_tests::init::drg] Running: \"drg\" \"delete\" \"app\" \"fbdc3442-654f-4f1e-b5d0-dbdd09966c88\"\n[2021-09-17T08:19:55Z INFO  drogue_cloud_tests::init::drg] Output: Ok(Output { status: ExitStatus(ExitStatus(0)), stdout: \"App fbdc3442-654f-4f1e-b5d0-dbdd09966c88 deleted.\\n\", stderr: \"\" })\n"
}

It looks like the test is running a process, collecting it's stdout and stderr and then outputting both of those to stdout which cargo test collects and reports. That is, cargo test never sees anything output to stderr. Am I reading that right?

[ctron]

That could be the case, yes.