Java implementation of the structuredlog API

RESOLVED FIXED in Firefox 33

Status

()

defect
RESOLVED FIXED
5 years ago
5 years ago

People

(Reporter: akachkach, Assigned: akachkach)

Tracking

unspecified
Firefox 33
All
Android
Points:
---
Dependency tree / graph

Firefox Tracking Flags

(Not tracked)

Details

Attachments

(1 attachment, 5 obsolete attachments)

Assignee

Description

5 years ago
To transit mochitest to structured logs (bug 886570), we'll need to change the robocop Java code to output structured logs. Specifically, the FennecMochitestAssert class ( http://dxr.mozilla.org/mozilla-central/source/build/mobile/robocop/FennecMochitestAssert.java#85 ). A utility class similar to the Python implementation (StructuredLogger) seems like the best way to achieve this.

It's still unsure if this bug blocks bug 886570 (currently trying to find an interim solution) but this will definitely be needed to convert all mochitests to structured logs.
Assignee

Comment 1

5 years ago
Initial patch; We'll probably need to include GSON (https://code.google.com/p/google-gson/) as a dependency to dump the messages in the JSON format.
(In reply to Ahmed Kachkach [:akachkach] from comment #1)
> Created attachment 8450570 [details] [diff] [review]
> 0001-Bug-1034236-Java-implementation-of-StructuredLogger.patch
> 
> Initial patch; We'll probably need to include GSON
> (https://code.google.com/p/google-gson/) as a dependency to dump the
> messages in the JSON format.

I see org.json.* in the tree a lot, maybe that will do the job?
Assignee

Comment 3

5 years ago
Didn't notice we were already using org.json!

Working implementation, adapted for org.json ; For now it automatically dumps the JSON to stdout, still unsure what's the best way to pass handlers here.
Attachment #8450570 - Attachment is obsolete: true
Assignee

Comment 4

5 years ago
Added a LoggerCallback interface used for passing arbitrary callbacks to the structured logger (to print on stdout, save to a file, etc.)
Attachment #8450702 - Attachment is obsolete: true
Attachment #8452673 - Flags: review?(jmaher)
Attachment #8452673 - Flags: feedback?(james)
Comment on attachment 8452673 [details] [diff] [review]
0001-Bug-1034236-Java-implementation-of-StructuredLogger.patch

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

a lot of questions after reading this code, please resolve those.

I am still not sure how this will be used.  I would like to know if there is a second patch or what we plan to do with Robocop to make it use this new file.

::: build/mobile/robocop/StructuredLogger.java
@@ +10,5 @@
> +
> +import org.json.JSONObject;
> +
> +public class StructuredLogger {
> +    public static ArrayList<String> validTestStatus = new ArrayList(Arrays.asList("PASS", "FAIL", "TIMEOUT", "NOTRUN", "ASSERT"));

is there a possibility of todo here?  I see skip as a valid option for testend.

@@ +53,5 @@
> +    }
> +
> +    public void suiteStart(List<String> tests) {
> +        this.suiteStart(tests, null);
> +    }

I don't understand what suiteSTart is?  do we expect a full list of all tests that belong to the suite to be passed in?

@@ +57,5 @@
> +    }
> +
> +    public void suiteEnd() {
> +        this.logData("suite_end");
> +    }

what defined a suite?

@@ +81,5 @@
> +            data.put("message", message);
> +        }
> +        if (expected.equals(status)) {
> +            data.put("expected", expected);
> +        }

I don't understand why we would put expected in here if it equals status, why not just put it in there all the time or do logic in here to print pass/fail?

@@ +88,5 @@
> +    }
> +
> +    public void testStatus(String test, String subtest, String status, String message) {
> +        this.testStatus(test, subtest, status, "PASS", message);
> +    }

what is a subtest?

@@ +108,5 @@
> +            data.put("extra", extra);
> +        }
> +        if (expected.equals(status) && !status.equals("SKIP")) {
> +            data.put("expected", expected);
> +        }

please document why we would not put expected in there if it is 'SKIP'

@@ +154,5 @@
> +        allData.put("action", action);
> +        allData.put("time", System.currentTimeMillis());
> +        allData.put("thread", JSONObject.NULL);
> +        allData.put("pid", JSONObject.NULL);
> +        allData.put("source", mName);

why do we have thread/pid in here and we don't use them?

@@ +175,5 @@
> +    }
> +
> +    private void logData(String action) {
> +        this.logData(action, new HashMap<String, Object>());
> +    };

nit: you have a trailing semicolon here, all other methods do not, keep it consistent.
Attachment #8452673 - Flags: review?(jmaher) → review-
Assignee

Comment 6

5 years ago
Comment on attachment 8452673 [details] [diff] [review]
0001-Bug-1034236-Java-implementation-of-StructuredLogger.patch

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

Most of the comments refer to the structured logging API, not the implementation. Again, this is just translating the structured logging API to Java. More info here:
http://mozbase.readthedocs.org/en/latest/mozlog_structured.html

And especially the source of the Python StructuredLogger:
http://mozbase.readthedocs.org/en/latest/_modules/mozlog/structured/structuredlog.html#StructuredLogger

::: build/mobile/robocop/StructuredLogger.java
@@ +81,5 @@
> +            data.put("message", message);
> +        }
> +        if (expected.equals(status)) {
> +            data.put("expected", expected);
> +        }

This is actually a bug. It should be !expected.equals(status).
(and this is a convention with the structured logging API: if status == expected, we shouldn't have an expected field)

@@ +108,5 @@
> +            data.put("extra", extra);
> +        }
> +        if (expected.equals(status) && !status.equals("SKIP")) {
> +            data.put("expected", expected);
> +        }

Again here, it's a bug: should've put !expected.equals(status).
For "SKIP", I have no idea. (as with the rest this is merely an implementation of the conventions we have in the Python API)

@@ +154,5 @@
> +        allData.put("action", action);
> +        allData.put("time", System.currentTimeMillis());
> +        allData.put("thread", JSONObject.NULL);
> +        allData.put("pid", JSONObject.NULL);
> +        allData.put("source", mName);

Currently set to NULL as they're required field, but not used anywhere. Just an interim solution. Ideally we'd have the thread id / pid of the process/thread running the tests.

@@ +175,5 @@
> +    }
> +
> +    private void logData(String action) {
> +        this.logData(action, new HashMap<String, Object>());
> +    };

Fixed!
please add a comment at the top of the file marking this with an MPL license and a link to the structured logging api.

if there are parts of the structured logging that you don't understand (i.e. the skip), please file bugs to update the documentation (or just find the answers and update)
Assignee

Comment 8

5 years ago
Fixed bugs in the previous patch + added StructuredLogger.java to robocop's Makefile.in

By the way, this class will be used for bug 1034267. (I already have an initial patch, just having trouble compiling/executing robocop to test it)
Attachment #8452673 - Attachment is obsolete: true
Attachment #8452673 - Flags: feedback?(james)
Attachment #8453262 - Flags: review?(jmaher)
Attachment #8453262 - Flags: feedback?(james)
Comment on attachment 8453262 [details] [diff] [review]
0001-Bug-1034236-Java-implementation-of-StructuredLogger-.patch

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

please add a comment linking to the structured logging api documentation.

at the top, add:
http://dxr.mozilla.org/mozilla-central/source/build/mobile/robocop/FennecMochitestAssert.java#5

I assume a new patch with all items outlined here will be addressed if you are to carry forward the r+.

::: build/mobile/robocop/StructuredLogger.java
@@ +24,5 @@
> +    }
> +
> +    static class StandardLoggerCallback implements LoggerCallback {
> +        public void call(String output) {
> +            System.out.println(output);

we don't use system.out.println in robocop, instead we write to a file.  If this is written for posterity, please add a comment here explaining why we have it here and to NOT use it.

@@ +68,5 @@
> +
> +    public void testStatus(String test, String subtest, String status, String expected, String message) {
> +        status = status.toUpperCase();
> +        if (!StructuredLogger.validTestStatus.contains(status)) {
> +            throw new IllegalArgumentException("Unrecognised status: " + status);

s/Unrecognised/Unrecognized/

@@ +93,5 @@
> +
> +    public void testEnd(String test, String status, String expected, String message, Map<String, Object> extra) {
> +        status = status.toUpperCase();
> +        if (!StructuredLogger.validTestEnd.contains(status)) {
> +            throw new IllegalArgumentException("Unrecognised status: " + status);

s/Unrecognised/Unrecognized/
Attachment #8453262 - Flags: review?(jmaher) → review+
Comment on attachment 8453262 [details] [diff] [review]
0001-Bug-1034236-Java-implementation-of-StructuredLogger-.patch

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

::: build/mobile/robocop/StructuredLogger.java
@@ +12,5 @@
> +
> +public class StructuredLogger {
> +    public static ArrayList<String> validTestStatus = new ArrayList(Arrays.asList("PASS", "FAIL", "TIMEOUT", "NOTRUN", "ASSERT"));
> +    public static ArrayList<String> validTestEnd = new ArrayList(Arrays.asList("PASS", "FAIL", "OK", "ERROR", "TIMEOUT",
> +                                                                               "CRASH", "ASSERT", "SKIP"));

Why not private final? Also would use a set or maybe enum for both here.

@@ +43,5 @@
> +        this(name, null, new StandardLoggerCallback());
> +    }
> +
> +    public void suiteStart(List<String> tests, Map<String, Object> runInfo) {
> +        HashMap<String, Object> data = new HashMap<String, Object>();

I wonder whether we'll have a list of tests and info mapping available to us when we're using this is robocop.

@@ +144,5 @@
> +    }
> +
> +    private void log(String level, String message) {
> +        HashMap<String, Object> data = new HashMap<String, Object>();
> +        data.put("message", message);

Looks like you forgot to put the level in the map.

@@ +160,5 @@
> +            allData.put("component", mComponent);
> +        }
> +
> +        for (Map.Entry<String, Object> entry : data.entrySet())
> +        {

Brace on previous line?

@@ +161,5 @@
> +        }
> +
> +        for (Map.Entry<String, Object> entry : data.entrySet())
> +        {
> +            allData.put(entry.getKey(), entry.getValue());

So the idea is that the incoming data parameter should override everything in allData. As implemeneted I don't think there's ever an overlap in keys, but either way I think there's a version of this that has the same behavior without allocating a new map.
Assignee

Comment 11

5 years ago
carry forward r+ from jmaher
Attachment #8453262 - Attachment is obsolete: true
Attachment #8453262 - Flags: feedback?(james)
Attachment #8453358 - Flags: review+
Attachment #8453358 - Flags: checkin?
Assignee

Comment 12

5 years ago
Comment on attachment 8453358 [details] [diff] [review]
0001-Bug-1034236-Java-implementation-of-StructuredLogger-.patch

Didn't see chmanchester's review. Will try to address those points first.
Attachment #8453358 - Flags: checkin?
Assignee

Comment 13

5 years ago
carry r+ forward from jmaher

Fixed the issues raised by chmanchester
Attachment #8453358 - Attachment is obsolete: true
Attachment #8453439 - Flags: checkin?
Comment on attachment 8453439 [details] [diff] [review]
0001-Bug-1034236-Java-implementation-of-StructuredLogger-.patch

1.) Is there a Try link handy for this? :)
2.) Please use the checkin-needed bug keyword. It plays more nicely with our bug marking tools. The checkin? flag is more intended for bugs with multiple patches landing at different times.
Attachment #8453439 - Flags: checkin?
Assignee

Updated

5 years ago
Keywords: checkin-needed
Assignee

Comment 15

5 years ago
Sorry, forgot to do a try run. Here's one with the updated patch:

https://tbpl.mozilla.org/?tree=Try&rev=2c3e1f85927b
https://hg.mozilla.org/mozilla-central/rev/b578fd863c13
Status: NEW → RESOLVED
Closed: 5 years ago
Resolution: --- → FIXED
Whiteboard: [fixed-in-fx-team]
Target Milestone: --- → Firefox 33
You need to log in before you can comment on or make changes to this bug.