refactor(signin): Add support for sending flow metrics in email #1593
Conversation
| // Log flow metrics if `flowId` and `flowBeginTime` specified in headers | ||
| const flowId = getHeaderValue('X-Flow-Id', message) | ||
| const flowBeginTime = getHeaderValue('X-Flow-Begin-Time', message) | ||
| if (flowId && flowBeginTime) { |
vladikoff
Dec 19, 2016
Contributor
might need to validate that those values are in proper format in the future.
might need to validate that those values are in proper format in the future.
vladikoff
Dec 19, 2016
Contributor
actually, I guess these are coming from AWS, so it should be safe enough.
actually, I guess these are coming from AWS, so it should be safe enough.
| flow_time: (currentTime <= flowBeginTime) ? 0 : (currentTime - flowBeginTime) | ||
| } | ||
|
|
||
| log.info('flowEvent', flowEventInfo) |
vladikoff
Dec 19, 2016
Contributor
need to make sure that the flowEvent importer looks at bouncer logs
need to make sure that the flowEvent importer looks at bouncer logs
|
@philbooth Mind giving this a look over? I can update shrinkwrap to point to mailer once mozilla/fxa-auth-mailer#241 has merged. |
| event: eventName, | ||
| time: currentTime, | ||
| flow_id: flowId, | ||
| flow_time: (currentTime <= flowBeginTime) ? 0 : (currentTime - flowBeginTime) |
philbooth
Dec 19, 2016
Contributor
Rather than try to normalise this, I'd rather drop the event if currentTime is less than flowBeginTime. There is no legitimate situation in which that would be okay.
Rather than try to normalise this, I'd rather drop the event if currentTime is less than flowBeginTime. There is no legitimate situation in which that would be okay.
philbooth
Dec 19, 2016
Contributor
Alternatively, if we are confident that will never happen because flowBeginTime is ultimately the one we already validated on entry to the auth server, then just don't bother checking it all. But having the check like this sends a misleading message to future readers I think.
Alternatively, if we are confident that will never happen because flowBeginTime is ultimately the one we already validated on entry to the auth server, then just don't bother checking it all. But having the check like this sends a misleading message to future readers I think.
| const flowBeginTime = getHeaderValue('X-Flow-Begin-Time', message) | ||
| if (flowId && flowBeginTime) { | ||
| const eventName = 'email.' + templateName + '.bounced' | ||
| const currentTime = Date.now() |
philbooth
Dec 19, 2016
•
Contributor
Can we set this right at the top of the function, just to be as precise as possible about the time of the bounce(s)?
Can we set this right at the top of the function, just to be as precise as possible about the time of the bounce(s)?
philbooth
Dec 19, 2016
Contributor
(I mean at the top of the parent function, not the top of the iteratee)
(I mean at the top of the parent function, not the top of the iteratee)
| flowBeginTime = request.payload.metricsContext.flowBeginTime | ||
| } | ||
|
|
||
| request.validateMetricsContext() |
philbooth
Dec 19, 2016
Contributor
We should move this call to validateMetricsContext before we store flowId and flowBeginTime, otherwise we'll emit events containing bad data.
We should move this call to validateMetricsContext before we store flowId and flowBeginTime, otherwise we'll emit events containing bad data.
| flow_time: (currentTime <= flowBeginTime) ? 0 : (currentTime - flowBeginTime) | ||
| } | ||
|
|
||
| log.info('flowEvent', flowEventInfo) |
philbooth
Dec 19, 2016
•
Contributor
I get why you opted for this approach, because it saves the hassle of faking the request object required to call log.flowEvent directly. But I wonder whether it is worth moving this call and the preceding assignment to flowEventInfo into a function inside lib/log.js?
I have a slight concern that we're doing the same thing in two places, albeit it's not a huge amount. If the current log.flowEvent was renamed to something along the lines of log.flowEventFromRequest, it could call log.flowEvent to do this stuff and your code could call it too.
What do you think, worth it or am I dreaming up imaginary obstacles?
I get why you opted for this approach, because it saves the hassle of faking the request object required to call log.flowEvent directly. But I wonder whether it is worth moving this call and the preceding assignment to flowEventInfo into a function inside lib/log.js?
I have a slight concern that we're doing the same thing in two places, albeit it's not a huge amount. If the current log.flowEvent was renamed to something along the lines of log.flowEventFromRequest, it could call log.flowEvent to do this stuff and your code could call it too.
What do you think, worth it or am I dreaming up imaginary obstacles?
seanmonstar
Dec 20, 2016
Member
I agree with @philbooth, I think we probably want to instead call log.flowEvent, so that we have this logic in only 1 place. If it's cumbersome to create a fake request, that probably means we should update log.flowEvent to accept an alternative or easier structure.
I agree with @philbooth, I think we probably want to instead call log.flowEvent, so that we have this logic in only 1 place. If it's cumbersome to create a fake request, that probably means we should update log.flowEvent to accept an alternative or easier structure.
vbudhram
Dec 20, 2016
•
Author
Contributor
I think it is worthwhile to do both, but probably as a follow on issue/PR as to not clutter this one up too much?
I think it is worthwhile to do both, but probably as a follow on issue/PR as to not clutter this one up too much?
philbooth
Dec 20, 2016
Contributor
...as a follow on issue/PR as to not clutter this one up too much...
I'm totes okay with that, as long as we get the issue opened before this is merged. Otherwise we might forget.
...as a follow on issue/PR as to not clutter this one up too much...
I'm totes okay with that, as long as we get the issue opened before this is merged. Otherwise we might forget.
|
@vbudhram, I've left some inline comments that need addressing but other than those I'm r+, nice one! |
| @@ -111,16 +113,18 @@ module.exports = function (log, error) { | |||
| // Log flow metrics if `flowId` and `flowBeginTime` specified in headers | |||
| const flowId = getHeaderValue('X-Flow-Id', message) | |||
| const flowBeginTime = getHeaderValue('X-Flow-Begin-Time', message) | |||
| if (flowId && flowBeginTime) { | |||
| const elapsedTime = currentTime - flowBeginTime | |||
vladikoff
Dec 20, 2016
Contributor
sweeet!
sweeet!
| const eventName = 'email.' + templateName + '.bounced' | ||
|
|
||
| // Flow events have a specific event and structure that must be emitted. | ||
| // Ref: https://github.com/mozilla/fxa-auth-server/blob/master/lib/metrics/context.js#L122 |
philbooth
Dec 20, 2016
•
Contributor
Just a note on this comment, at some point lib/metrics/context.js will change then the line number will be wrong. Maybe just mention the file and function name or something?
Just a note on this comment, at some point lib/metrics/context.js will change then the line number will be wrong. Maybe just mention the file and function name or something?
| const elapsedTime = currentTime - flowBeginTime | ||
|
|
||
| if (flowId && flowBeginTime && (elapsedTime > 0)) { | ||
| const eventName = 'email.' + templateName + '.bounced' |
philbooth
Dec 20, 2016
Contributor
Would this be cleaner with a template string?
const eventName = `email.${templateName}.bounced`
Would this be cleaner with a template string?
const eventName = `email.${templateName}.bounced`
|
@philbooth Made updates you recommended and added changes to dynamically generate flow data in tests. I also update my refactor issue, #1597, to better expand generating mock flow data. Mind one more glance over before merge? |
…` in email headers
|
I've rebased and force-pushed this to fix the merge conflict, will merge once travis says it's OK |
2nd part of #1425