1387444 - Add logging to TAAR

Status: RESOLVED FIXED

(Data Platform and Tools :: General, enhancement)

Description

[Alessio Placitelli [:Dexter]]

We need to add logging to TAAR and make sure that it gets properly captured to closely monitor the performances of TAAR once we go live.

We need to:

- Identify the edge cases that we cannot keep track of using the SHIELD addon.
- Figure out where to add logging to TAAR.
- Add the logging.
- Make sure it gets stored on our servers.
- Verify that we're able to query and draw meaningful conclusion out of the data.

Comment 1

[mlopatka]

Logged information must also include exactly which recommendation strategy was triggered in order to provide the list of guids recommended.

I.e. in a particular case only the collaborative filter is used, another case only the similarity-based recommender may have been called. These must be recorded for every time TAAR is called.

Comment 2

[mlopatka]

Hey Ben, 
We need to verify what logging functionality is required from the TAAR module that was originally assumed to take place inside the SHIELD study. Can you take a minute to just brain-dump any and all information that we should be keeping track of for the post-analysis.

Comment 3

[Ben Miroglio [:bmiroglio]]

The shield add-on will send a telemetry ping for 3 different actions:

1.) experiment initialization
2.) add-on installs
3.) add-on uninstalls/disabled

The ping will take the following form:

{
    "study_name": "TAARExperiment",
    "branch": string, "vanilla-disco-popup" / "taar-disco-popup" / "vanilla-disco" / "taar-disco"
    "addon_version": "1.0.0",
    "shield_version": "4.0.0",
    "type": "shield-study-addon",
    "data": {
        "attributes": {
            "clickedButton": boolean, did the user click the pop-up button
            "sawPopup": boolean, was the pop-up displayed
            "startTime": long, static time experiment was initialized for client 
            "addon_id": string, add-on guid (null if pingType=init)
            "srcURI": 'string, disco-pane' /'AMO' / 'other' (null if pingType=init)
            "pingType": string, 'init' / 'install' / 'uninstall'
        }
        
    }
}


From the TAAR-side, I'd want infomation on the chosen recommendation stategy by clientId as you mentioned in Comment 1. More specfically, I'd want to know if TAAR failed to provide a list of recommended add-ons (returned an empty list). This would allow us to identify "test" clients that were shown the vanilla disco-pane instead of personalized recommendations. 

FWIW there is the case when AMO fails to communicate with TAAR (i.e. HBase goes down), in which case we show the vanilla disco-pane--this is only log-able from the AMO-side. We've determined this risk is minmal and are not accounting for it.

Comment 4

[Alessio Placitelli [:Dexter]]

Hey Mauro, a couple of technical questions for you:

- do we need to use any specific python package to log in TAAR? Or is |print| enough?
- do we need to use any specific log format to make log parsing/aggregation easier?

Comment 5

[Mauro Doglio [:mdoglio]]

You can use the python standard library logging module. I would suggest to give the loggers the same name as the module that they belong to:
> logger = logging.getLogger(__name__)

The current log handler for taar-api uses a json output formatter, so the log lines will be easy to parse. I don't know where the logs are stored though, we should check that with Jason when he's back.

Comment 6

[Alessio Placitelli [:Dexter]]

Attachment: Logging PR

@Martin, would you kindly take a look at the PR to make sure that all the requested cases are correctly reported?

Comment 7

[mlopatka]

Looks good to me.

We have logging coverage of:
1- specific recommendation strategies
2- association of client_ids
3- Hbase failure
4- empty recommendation list returned
5- and the specific diagnostic messages that may help trouble shoot.

It seems to me like all failure and success edge cases are adequately covered.

Comment 8

[Alessio Placitelli [:Dexter]]

Comment on attachment 8900195 [details] [review]
Logging PR

Changing that to f+ as per comment 7.

Comment 9

[Alessio Placitelli [:Dexter]]

Comment on attachment 8900195 [details] [review]
Logging PR

This was reviewed by Mauro and merged.

Comment 10

[mlopatka]

"Changing that to f+ as per comment 7."

sorry about the accidental f-, early morning for me and after giving comment I fat-fingered the drop-down. F+ was the intended initial feedback.

Comment 11

[Jason Thomas [:jason]]

(In reply to Mauro Doglio [:mdoglio] from comment #5)
> You can use the python standard library logging module. I would suggest to
> give the loggers the same name as the module that they belong to:
> > logger = logging.getLogger(__name__)
> 
> The current log handler for taar-api uses a json output formatter, so the
> log lines will be easy to parse. I don't know where the logs are stored
> though, we should check that with Jason when he's back.

As long as we are using the mozlog format, which I believe we are, we can use logging 2.0 which includes several access interfaces[1].

[1] https://mana.mozilla.org/wiki/display/SVCOPS/Logging+2.0

Comment 12

[Alessio Placitelli [:Dexter]]

(In reply to Jason Thomas [:jason] from comment #11)
> (In reply to Mauro Doglio [:mdoglio] from comment #5)
> > You can use the python standard library logging module. I would suggest to
> > give the loggers the same name as the module that they belong to:
> > > logger = logging.getLogger(__name__)
> > 
> > The current log handler for taar-api uses a json output formatter, so the
> > log lines will be easy to parse. I don't know where the logs are stored
> > though, we should check that with Jason when he's back.
> 
> As long as we are using the mozlog format, which I believe we are, we can
> use logging 2.0 which includes several access interfaces[1].
> 
> [1] https://mana.mozilla.org/wiki/display/SVCOPS/Logging+2.0

Mh, I'm not sure we're using that format, but it should be fairly easy to use it. I believe we should be using this [1] python package for logging, as done by [2]. Mauro, just to double check, do you know if that's the class we should be using or if we're good to leave the prints as they are?

[1] - https://github.com/mozilla-services/python-dockerflow/blob/master/src/dockerflow/logging.py
[2] - https://github.com/mozilla/addons-server/pull/5120/files

Comment 13

[Mauro Doglio [:mdoglio]]

We are using mozlog indeed.

Comment 14

[Firefox Bug Husbandry Bot]

Moved to new component, per bug 1425844.