Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

JSON output of several commands includes unexpected log entries #3099

Open
5 tasks
chatton opened this issue Feb 17, 2023 · 3 comments
Open
5 tasks

JSON output of several commands includes unexpected log entries #3099

chatton opened this issue Feb 17, 2023 · 3 comments
Labels
A: question Admin: further information is requested I: CLI Internal: related to the relayer's CLI O: usability Objective: cause to improve the user experience (UX) and ease using the product

Comments

@chatton
Copy link

chatton commented Feb 17, 2023

Summary of Bug

When using the --json flag to get json output, additional log lines being displayed to stdout in addition to the expected result.

hermes --json create client --host-chain cosmoshub-0 --reference-chain cosmoshub-1
{"timestamp":"2023-02-16T14:24:21.514413Z","level":"INFO","fields":{"message":"using default configuration from '/home/hermes/.hermes/config.toml'"},"threadId":"ThreadId(1)"}
{"timestamp":"2023-02-16T14:24:21.530391Z","level":"INFO","fields":{"message":"running Hermes v1.2.0+061f14f"},"threadId":"ThreadId(1)"}
{"result":{"CreateClient":{"client_id":"07-tendermint-0","client_type":"Tendermint","consensus_height":{"revision_height":9,"revision_number":1}}},"status":"success"}

When working on integrating hermes in to interchaintest, I used the json output to be more easily able to programatically interact with the hermes cli. However the json output does not produce a single json object, it outputs multiple distinct json objects which are not directly parsable without some additional pre-processing of the stdout. E.g.

func extractJsonResult(stdout []byte) []byte {
	stdoutLines := strings.Split(string(stdout), "\n")
	var jsonOutput string
	for _, line := range stdoutLines {
		if strings.Contains(line, "result") {
			jsonOutput = line
			break
		}
	}
	return []byte(jsonOutput)
}

which is a bit of a hack.

My expectation would be that just the final line is displayed to stdout

{"result":{"CreateClient":{"client_id":"07-tendermint-0","client_type":"Tendermint","consensus_height":{"revision_height":9,"revision_number":1}}},"status":"success"}

and the other ones would get appended to a log file.

This parsing needing to be done with outputs for several commands including querying channels, creating connections and creating clients.

Note: I did not encounter this issue in hermes v1.0.0

Version

v1.2.0+061f14f ( using docker container: docker.io/informalsystems/hermes:v1.2.0 )

Steps to Reproduce

Attempt to create a client, e.g. hermes --json create client --host-chain cosmoshub-0 --reference-chain cosmoshub-1

Acceptance Criteria

raw stdout when using --json command is directly unmarshallable into an equivalent data structure.


For Admin Use

  • Not duplicate issue
  • Appropriate labels applied
  • Appropriate milestone (priority) applied
  • Appropriate contributors tagged
  • Contributor assigned/self-assigned
@romac romac added A: bug Admin: something isn't working I: CLI Internal: related to the relayer's CLI O: usability Objective: cause to improve the user experience (UX) and ease using the product and removed A: bug Admin: something isn't working labels Mar 7, 2023
@romac
Copy link
Member

romac commented Mar 7, 2023

Hermes used to output log messages to stderr and the final result line to stdout (and still does for the human-readable textual output) but we decided to change this for the JSON output in order to make it easier to ingest the full output of start command into other systems.

I agree that for commands other than start, it would make more sense to only output the result line to stdout. Unfortunately, that would also make start and other commands inconsistent with each other, which is not great either.

In the meantime, you can either do exactly as you've shown above (which is a totally fine solution imho) or you can just process the last line of the output.

I will think more on this.

@chatton
Copy link
Author

chatton commented Mar 7, 2023

Hi @romac, I understand your concerns about commands being inconsistent, maybe I can provide two other suggestions that you might prefer.

  1. display a json list [{log1Object}, {log2Object}, {resultObject}] this would make the stdout directly marshal-able into a json list. The caller can simply discard all that they don't care of and use myStruct.Results[len(myStruct.Results)-1] in my opinion this is not ideal but preferable to parsing stdout manually to find the json.
  2. display a single json object where logs is an entry
{
    "logs": [{}, {}, {}],
    "result": {}
}

Similar to option one we can discard logs if they are not desired and we would have easy access to the result. Of these options I prefer the second and I think would result in a consistent API let me know what you think!

@romac
Copy link
Member

romac commented Mar 7, 2023

Unfortunately, we cannot really implement either solution with how our logging infrastructure is setup, as we do not emit all the output at once but rather each log line may be emitted at a different time during the execution of the command and the last result line is emitted when the command completes.

I will think about reverting to outputting log lines on stderr and the result line of stdout, but I can't promise we will end up doing that given that Hermes is not the only software which outputs JSON line-by-line, and it is straightforward to only process the very last line emitted.

@romac romac changed the title Json output of several commands includes unexpected log entries JSON output of several commands includes unexpected log entries Mar 7, 2023
@romac romac added the A: question Admin: further information is requested label Mar 7, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
A: question Admin: further information is requested I: CLI Internal: related to the relayer's CLI O: usability Objective: cause to improve the user experience (UX) and ease using the product
Projects
None yet
Development

No branches or pull requests

2 participants