1043945 - Corredor should have an "output" module that directly hooks into mozlog.structured

Status: RESOLVED FIXED

(Testing :: General, defect)

Comment 1

[Andrew Halberstadt [:ahal]]

Forgot to add a description..

Corredor lives here: https://github.com/ahal/corredor

Currently it uses a very similar protocol to mozlog.structured (uses JSON with an action key) to send messages between two parts of a test harness. It should have a built in "output" or "results" module that receives structured test result messages and passes them through to mozlog.structured handlers.

Comment 2

[Andrew Halberstadt [:ahal]]

Attachment: Add ResultBridge class to corredor with tests

I know you aren't familiar with corredor (no one is!), but this is structured logging related, so would you mind having a look?

Comment 3

[Chris Manchester (limited bugmail, email directly)]

(In reply to Andrew Halberstadt [:ahal] from comment #2)
> Created attachment 8465744 [details] [diff] [review]
> Add ResultBridge class to corredor with tests
> 
> I know you aren't familiar with corredor (no one is!), but this is
> structured logging related, so would you mind having a look?

Glad to take a look. I'll check this out sometime tomorrow if not before!

Comment 4

[Chris Manchester (limited bugmail, email directly)]

Comment on attachment 8465744 [details] [diff] [review]
Add ResultBridge class to corredor with tests

Review of attachment 8465744 [details] [diff] [review]:
-----------------------------------------------------------------

My comments risk irrelevance because I'm not too familiar with the context, but this seems pretty reasonable!

::: corredor/testing/result.py
@@ +11,5 @@
> +  'test_end',
> +  'test_status',
> +  'process_output',
> +  'log',
> +]

Hardcoding these seems brittle, because the protocol may change. I think this has come up before -- mozlog.structured could expose a module constant that enumerates these.

@@ +33,5 @@
> +        sub = Subscriber()
> +        sub.bind(self.address)
> +
> +        for action in STRUCTURED_ACTIONS:
> +            sub.subscribe(action, self.logger.log_raw)

I don't have a great big picture idea of the system, but if there are multiple subscribers it seems like you might have a name collision problem for actions with general names like "test_end". If it seems like that might be a problem, maybe you could have a special prefix, like "structlog_<action>".

::: tests/test_result_bridge.py
@@ +49,5 @@
> +            recv = json.loads(recv)
> +            msg = messages[i]
> +
> +            for key in msg.keys():
> +                self.assertEquals(recv[key], msg[key])

I can't imagine how this would happen, but the loop doesn't fail if there are more messages sent than received or if there are extra keys in recv.

Comment 5

[Andrew Halberstadt [:ahal]]

(In reply to Chris Manchester [:chmanchester] from comment #4)
> My comments risk irrelevance because I'm not too familiar with the context,
> but this seems pretty reasonable!

Yeah, I know.. it's ok though, it's still helpful!

> Hardcoding these seems brittle, because the protocol may change. I think
> this has come up before -- mozlog.structured could expose a module constant
> that enumerates these.

I agree. For some reason I feel like that was proposed and shot down before.. Is there a bug on file for it?

> I don't have a great big picture idea of the system, but if there are
> multiple subscribers it seems like you might have a name collision problem
> for actions with general names like "test_end". If it seems like that might
> be a problem, maybe you could have a special prefix, like
> "structlog_<action>".

I think this is ok. Multiple subscribers all get the same messages and shouldn't interfere with one another. It's up to the user to make sure they connect the subscriber to an address that is streaming structured log data.

> I can't imagine how this would happen, but the loop doesn't fail if there
> are more messages sent than received or if there are extra keys in recv.

Yeah, this could probably be done better. The recv message has all the structured log defaults in it (e.g thread, timestamp, etc..) so it's hard to compare the two to make sure they are the exact same.

Comment 6

[Andrew Halberstadt [:ahal]]

I changed the name from ResultBridge to StructuredLoggerBridge (which is more verbose, but at least it's easier to tell what it does).

https://github.com/ahal/corredor/commit/bd70ff3cfde43823e59c0b9ebc1fe8a8b7d18620