[FEATURE] Sort keys in log output for better human readability

[sparr]

Is your feature request related to a problem? Please describe. The human readability of the log output from soci-snapshotter-grpc is significantly impaired by the keys being sorted alphabetically, especially with different keys in different entries.

Describe the solution you'd like Sort the output such that the lowest cardinality always-present keys appear first (preferably starting with "level", then the highest cardinality always-present keys, then optional keys.

Describe alternatives you've considered Piping log output through jq with key order specified when I need to read long logs.

Additional context Go's json encoder can't re-order map keys. This could be implemented with a small amount of encoding glue code like https://stackoverflow.com/a/25183429/13675 for ordering and keys, along with https://cs.opensource.google/go/go/+/refs/tags/go1.19.5:src/encoding/json/stream.go;l=201 for values. Alternately, a library such as https://gitlab.com/c0b/go-ordered-json or https://github.com/iancoleman/orderedmap could be used.

[sbuckfelder]

Could you add an example current output of log and ideal output?

[sparr]

Here's an approximate example. I didn't entirely re-arrange the keys, and the specific order of less common keys could be implemented in whatever way is convenient, including keeping the current alphabetical sort. The primary point here is getting the always-present keys and the most important usually-present keys in an order that is easy for a human to read. From my perspective, that would certainly start with time, level, msg, then maybe error which is less common but more important, or key parent digest which are more common.

Current:

{"fetchPeriod":500000000,"level":"info","maxQueueSize":100,"msg":"constructing background fetcher","silencePeriod":30000000000,"time":"2023-01-30T18:53:35.123049386Z"}
{"key":"default/1/extract-896701523-UN9I sha256:0002c93bdb3704dd9e36ce5153ef637f84de253015f3ee330468dccdeacad60b","level":"info","msg":"preparing filesystem mount at mountpoint=/var/lib/soci-snapshotter-grpc/snapshotter/snapshots/1/fs","parent":"","time":"2023-01-30T18:53:39.907408742Z"}
{"digest":"sha256:fa9bd640876aabcf3d718a91a81b7cc84d5cb2c49bd8282c8d08f59dc281e5c2","key":"default/1/extract-896701523-UN9I sha256:0002c93bdb3704dd9e36ce5153ef637f84de253015f3ee330468dccdeacad60b","level":"info","mountpoint":"/var/lib/soci-snapshotter-grpc/snapshotter/snapshots/1/fs","msg":"fetching SOCI artifacts using index descriptor","parent":"","time":"2023-01-30T18:53:39.907481978Z"}
{"digest":"sha256:fa9bd640876aabcf3d718a91a81b7cc84d5cb2c49bd8282c8d08f59dc281e5c2","key":"default/1/extract-896701523-UN9I sha256:0002c93bdb3704dd9e36ce5153ef637f84de253015f3ee330468dccdeacad60b","level":"info","mountpoint":"/var/lib/soci-snapshotter-grpc/snapshotter/snapshots/1/fs","msg":"fetching SOCI index from remote registry","parent":"","time":"2023-01-30T18:53:39.907544880Z"}
{"digest":"sha256:fa9bd640876aabcf3d718a91a81b7cc84d5cb2c49bd8282c8d08f59dc281e5c2","key":"default/1/extract-896701523-UN9I sha256:0002c93bdb3704dd9e36ce5153ef637f84de253015f3ee330468dccdeacad60b","level":"info","mountpoint":"/var/lib/soci-snapshotter-grpc/snapshotter/snapshots/1/fs","msg":"fetching artifact from remote","parent":"","time":"2023-01-30T18:53:39.907797958Z"}
{"digest":"sha256:fa9bd640876aabcf3d718a91a81b7cc84d5cb2c49bd8282c8d08f59dc281e5c2","key":"default/1/extract-896701523-UN9I sha256:0002c93bdb3704dd9e36ce5153ef637f84de253015f3ee330468dccdeacad60b","level":"warning","mountpoint":"/var/lib/soci-snapshotter-grpc/snapshotter/snapshots/1/fs","msg":"size of descriptor is 0, trying to resolve it...","parent":"","time":"2023-01-30T18:53:39.907808703Z"}
{"digest":"sha256:38902e5b8587d142e2dbc2f16bbcb045e02a8de9ad38f7c91427fbe62a937f1c","key":"default/1/extract-896701523-UN9I sha256:0002c93bdb3704dd9e36ce5153ef637f84de253015f3ee330468dccdeacad60b","level":"info","mountpoint":"/var/lib/soci-snapshotter-grpc/snapshotter/snapshots/1/fs","msg":"fetching artifact from remote","parent":"","time":"2023-01-30T18:53:40.942140053Z"}
{"key":"default/1/extract-896701523-UN9I sha256:0002c93bdb3704dd9e36ce5153ef637f84de253015f3ee330468dccdeacad60b","level":"info","mountpoint":"/var/lib/soci-snapshotter-grpc/snapshotter/snapshots/1/fs","msg":"Received status code: 401 Unauthorized. Refreshing creds...","parent":"","src":"558770595227.dkr.starport.us-west-2.amazonaws.com/soci-test-registry:rabbitmq/sha256:846c0b181fff0c667d9444f8378e8fcfa13116da8d308bf21673f7e4bea8d580","time":"2023-01-30T18:53:42.197794615Z"}
{"key":"default/1/extract-896701523-UN9I sha256:0002c93bdb3704dd9e36ce5153ef637f84de253015f3ee330468dccdeacad60b","level":"info","mountpoint":"/var/lib/soci-snapshotter-grpc/snapshotter/snapshots/1/fs","msg":"Verification forcefully skipped","parent":"","time":"2023-01-30T18:53:42.987257593Z"}
{"error":"exec: \"fusermount\": executable file not found in $PATH","key":"default/1/extract-896701523-UN9I sha256:0002c93bdb3704dd9e36ce5153ef637f84de253015f3ee330468dccdeacad60b","level":"info","mountpoint":"/var/lib/soci-snapshotter-grpc/snapshotter/snapshots/1/fs","msg":"fusermount not installed; trying direct mount","parent":"","time":"2023-01-30T18:53:42.987396569Z"}
{"key":"default/1/extract-896701523-UN9I sha256:0002c93bdb3704dd9e36ce5153ef637f84de253015f3ee330468dccdeacad60b","level":"info","msg":"Remote snapshot successfully prepared.","parent":"","remote-snapshot-prepared":"true","time":"2023-01-30T18:53:43.127493923Z"}
{"key":"default/2/extract-131513338-rBr1 sha256:074026c275f4eac5c25d3bd6348a7dccc61735f8b3cc345922e76742b2081d73","level":"info","msg":"Layer size less than runtime min_layer_size, skipping remote snapshot preparation","parent":"sha256:0002c93bdb3704dd9e36ce5153ef637f84de253015f3ee330468dccdeacad60b","time":"2023-01-30T18:53:43.135578628Z"}
{"layerDigest":"sha256:03dea6b5e70e630bb5bf621528463788e46cf2571f98f3f591e10633f1b650d9","level":"info","msg":"preparing snapshot as local snapshot","time":"2023-01-30T18:53:43.135679949Z"}
{"error":"exec: \"fusermount\": executable file not found in $PATH","key":"default/4/extract-601839790-hFNE sha256:abeed4e4be424121066f5c59dc839f510ff606e062dd99286af3dc0508a9a675","level":"info","mountpoint":"/var/lib/soci-snapshotter-grpc/snapshotter/snapshots/4/fs","msg":"fusermount not installed; trying direct mount","parent":"sha256:e870a9bc12d517809dcf9b4fb0d4f1671d56c2c8183319f2913d5fc803e0189c","time":"2023-01-30T18:53:43.606024995Z"}
{"layerDigest":"sha256:78982783d77fdd7e67c9fad506b1cbc640b55a3e5df3f240e0ba581385fad4e0","level":"info","msg":"preparing snapshot as local snapshot","time":"2023-01-30T18:53:44.404175048Z"}
{"key":"default/10/extract-400286448-CbbC sha256:353cc837e0576f9d78bd3fb10c2d5e9183eeade837d6486a458a527601920d20","level":"info","msg":"preparing local filesystem at mountpoint=/var/lib/soci-snapshotter-grpc/snapshotter/snapshots/10/fs","parent":"sha256:1a24565a06b98a38a042a97ae5a3b4c8de47709c35cc2c0b8730631e210ca584","time":"2023-01-30T18:53:44.404211986Z"}
{"digest":"sha256:78982783d77fdd7e67c9fad506b1cbc640b55a3e5df3f240e0ba581385fad4e0","key":"default/10/extract-400286448-CbbC sha256:353cc837e0576f9d78bd3fb10c2d5e9183eeade837d6486a458a527601920d20","level":"info","msg":"fetching artifact from remote","parent":"sha256:1a24565a06b98a38a042a97ae5a3b4c8de47709c35cc2c0b8730631e210ca584","time":"2023-01-30T18:53:44.404272132Z"}
{"key":"default/10/extract-400286448-CbbC sha256:353cc837e0576f9d78bd3fb10c2d5e9183eeade837d6486a458a527601920d20","level":"info","msg":"Local snapshot successfully prepared","parent":"sha256:1a24565a06b98a38a042a97ae5a3b4c8de47709c35cc2c0b8730631e210ca584","remote-snapshot-prepared":"true","time":"2023-01-30T18:53:44.585224830Z"}

Desired:

{"time":"2023-01-30T18:53:35.123049386Z", "level":"info", "msg":"constructing background fetcher", "fetchPeriod":500000000,"maxQueueSize":100,"silencePeriod":30000000000}
{"time":"2023-01-30T18:53:39.907408742Z", "level":"info", "msg":"preparing filesystem mount at mountpoint=/var/lib/soci-snapshotter-grpc/snapshotter/snapshots/1/fs", "key":"default/1/extract-896701523-UN9I sha256:0002c93bdb3704dd9e36ce5153ef637f84de253015f3ee330468dccdeacad60b","parent":""}
{"time":"2023-01-30T18:53:39.907481978Z", "level":"info", "msg":"fetching SOCI artifacts using index descriptor", "key":"default/1/extract-896701523-UN9I sha256:0002c93bdb3704dd9e36ce5153ef637f84de253015f3ee330468dccdeacad60b", "parent":"", "digest":"sha256:fa9bd640876aabcf3d718a91a81b7cc84d5cb2c49bd8282c8d08f59dc281e5c2","mountpoint":"/var/lib/soci-snapshotter-grpc/snapshotter/snapshots/1/fs"}
{"time":"2023-01-30T18:53:39.907544880Z", "level":"info", "msg":"fetching SOCI index from remote registry", "key":"default/1/extract-896701523-UN9I sha256:0002c93bdb3704dd9e36ce5153ef637f84de253015f3ee330468dccdeacad60b", "parent":"", "digest":"sha256:fa9bd640876aabcf3d718a91a81b7cc84d5cb2c49bd8282c8d08f59dc281e5c2","mountpoint":"/var/lib/soci-snapshotter-grpc/snapshotter/snapshots/1/fs"}
{"time":"2023-01-30T18:53:39.907797958Z", "level":"info", "msg":"fetching artifact from remote", "key":"default/1/extract-896701523-UN9I sha256:0002c93bdb3704dd9e36ce5153ef637f84de253015f3ee330468dccdeacad60b", "parent":"", "digest":"sha256:fa9bd640876aabcf3d718a91a81b7cc84d5cb2c49bd8282c8d08f59dc281e5c2","mountpoint":"/var/lib/soci-snapshotter-grpc/snapshotter/snapshots/1/fs"}
{"time":"2023-01-30T18:53:39.907808703Z", "level":"warning", "msg":"size of descriptor is 0, trying to resolve it...", "key":"default/1/extract-896701523-UN9I sha256:0002c93bdb3704dd9e36ce5153ef637f84de253015f3ee330468dccdeacad60b", "parent":"", "digest":"sha256:fa9bd640876aabcf3d718a91a81b7cc84d5cb2c49bd8282c8d08f59dc281e5c2","mountpoint":"/var/lib/soci-snapshotter-grpc/snapshotter/snapshots/1/fs"}
{"time":"2023-01-30T18:53:40.942140053Z", "level":"info", "msg":"fetching artifact from remote", "key":"default/1/extract-896701523-UN9I sha256:0002c93bdb3704dd9e36ce5153ef637f84de253015f3ee330468dccdeacad60b", "parent":"", "digest":"sha256:38902e5b8587d142e2dbc2f16bbcb045e02a8de9ad38f7c91427fbe62a937f1c","mountpoint":"/var/lib/soci-snapshotter-grpc/snapshotter/snapshots/1/fs"}
{"time":"2023-01-30T18:53:42.197794615Z", "level":"info", "msg":"Received status code: 401 Unauthorized. Refreshing creds...", "key":"default/1/extract-896701523-UN9I sha256:0002c93bdb3704dd9e36ce5153ef637f84de253015f3ee330468dccdeacad60b","mountpoint":"/var/lib/soci-snapshotter-grpc/snapshotter/snapshots/1/fs","parent":"","src":"558770595227.dkr.starport.us-west-2.amazonaws.com/soci-test-registry:rabbitmq/sha256:846c0b181fff0c667d9444f8378e8fcfa13116da8d308bf21673f7e4bea8d580"}
{"time":"2023-01-30T18:53:42.987257593Z", "level":"info", "msg":"Verification forcefully skipped", "key":"default/1/extract-896701523-UN9I sha256:0002c93bdb3704dd9e36ce5153ef637f84de253015f3ee330468dccdeacad60b","mountpoint":"/var/lib/soci-snapshotter-grpc/snapshotter/snapshots/1/fs","parent":""}
{"time":"2023-01-30T18:53:42.987396569Z", "level":"info", "msg":"fusermount not installed; trying direct mount", "key":"default/1/extract-896701523-UN9I sha256:0002c93bdb3704dd9e36ce5153ef637f84de253015f3ee330468dccdeacad60b", "parent":"", "error":"exec: \"fusermount\": executable file not found in $PATH","mountpoint":"/var/lib/soci-snapshotter-grpc/snapshotter/snapshots/1/fs"}
{"time":"2023-01-30T18:53:43.127493923Z", "level":"info", "msg":"Remote snapshot successfully prepared.", "key":"default/1/extract-896701523-UN9I sha256:0002c93bdb3704dd9e36ce5153ef637f84de253015f3ee330468dccdeacad60b","parent":"","remote-snapshot-prepared":"true"}
{"time":"2023-01-30T18:53:43.135578628Z", "level":"info", "msg":"Layer size less than runtime min_layer_size, skipping remote snapshot preparation", "key":"default/2/extract-131513338-rBr1 sha256:074026c275f4eac5c25d3bd6348a7dccc61735f8b3cc345922e76742b2081d73","parent":"sha256:0002c93bdb3704dd9e36ce5153ef637f84de253015f3ee330468dccdeacad60b"}
{"time":"2023-01-30T18:53:43.135679949Z", "level":"info", "msg":"preparing snapshot as local snapshot", "layerDigest":"sha256:03dea6b5e70e630bb5bf621528463788e46cf2571f98f3f591e10633f1b650d9"}
{"time":"2023-01-30T18:53:43.606024995Z", "level":"info", "msg":"fusermount not installed; trying direct mount", "key":"default/4/extract-601839790-hFNE sha256:abeed4e4be424121066f5c59dc839f510ff606e062dd99286af3dc0508a9a675", "parent":"sha256:e870a9bc12d517809dcf9b4fb0d4f1671d56c2c8183319f2913d5fc803e0189c", "error":"exec: \"fusermount\": executable file not found in $PATH","mountpoint":"/var/lib/soci-snapshotter-grpc/snapshotter/snapshots/4/fs"}