refs CNVS-27581
this ensures we have one correlation ID for a request coming
through the ecosystem rather than a seperate ID for each request
at each service. Each request id must be signed to make sure
others can't just submit whatever they want.
TEST PLAN:
1) make an API request and provide the header 'X-Request-Context-Id'
2) make sure to include the X-Request-Context-Signature header, which
should have the value of the sha512 signature with the shared
secret for the services ecosystem
2) the logs should show your provided value as the context Id for that
canvas request
Change-Id: I610fbe8c4df355d43c05360670f80971d1459644
Reviewed-on: https://gerrit.instructure.com/73166
Tested-by: Jenkins
Reviewed-by: Simon Williams <simon@instructure.com>
QA-Review: Jeremy Putnam <jeremyp@instructure.com>
Product-Review: Ethan Vizitei <evizitei@instructure.com>
if the http server passes the "X-Request-Start" header, compute the
difference in microseconds between that time and the time the request
begins processing in rails, and return it as "q" in the canvas meta
header.
fixes CNVS-25192
test plan:
- configure apache to set the X-Request-Start time to the current time
in microseconds, formated as "t=XXX"
- make a canvas request
- inspect the X-Canvas-Meta header returned
- it should include a "q=XXX" value
Change-Id: I3f1c5d6448ac8b53cb2d254ae86b5629cb003db1
Reviewed-on: https://gerrit.instructure.com/67736
Tested-by: Jenkins
Reviewed-by: Ethan Vizitei <evizitei@instructure.com>
Product-Review: Simon Williams <simon@instructure.com>
QA-Review: Simon Williams <simon@instructure.com>
Closes CNVS-23363
Closes CNVS-24692
Include interaction_seconds updates to previous requests in
request metadata.
Instead of passing around a page view id, we are now passing around the
URL used to update the current page view. This URL includes a page_view
token, which is a JWT including the page view id, user id, and page view
creation time.
Previously the DOM was used to store the page view id of the current
page and the update URL. The update URL now is sent via js_env. The
DOM node with the page_view_id is left in place in case any 3rd party
javascript is querying it (but nothing in Canvas should be).
This change also logs in metadata the page view creation time. This
is so we can correctly correlate the updated page view with the original
page view (using its id and creation time).
There is also a mechanism to send a new update URL in AJAX requests,
which is preserved with this change.
Some code to send the page view id with every ajaxJSON request was
removed, as it appears completely unused.
Also fixed a bug that was preventing the "store page view info
in cookie on pageunload so the next request can send the update"
code from working. When setting the cookie, it was not specifying
a Path, so the cookie only got set on the current path. Now it
will always be handled on the next request.
test plan:
* Open Network Inspector to see requests being made
* Open a page that constitutes a "page view" (like a course's
discussion page)
* Note the X-Request-Context-Id response header for the request you
just made. This is your current page view id.
* Move your mouse around a whole bunch on the page you're on. This
generates "interaction time".
* Eventually, you'll see a new request pop up to /page_views. Look
at the response headers for X-Canvas-Meta. It should have a field
r=<guid>|<timestamp>|<seconds>. The `guid` field should match the
page view id from the original page you loaded, and `seconds`
should be about how long you've been moving your mouse around.
Change-Id: I7c418c1c690e7c2384fbcae86f21f5081b834a7e
Reviewed-on: https://gerrit.instructure.com/63818
QA-Review: August Thornton <august@instructure.com>
Reviewed-by: Cody Cutrer <cody@instructure.com>
Tested-by: Jenkins
Product-Review: Zach Wily <zach@instructure.com>
Rack generates a session_id internally which we like to include in logs
for tracking requests. This session_id wasn't getting picked up by out
log wrapper because of interdependencies in the middleware call stack
and bugs in rack/rails. Read on for details:
See the order of the middleware stack by running: `rake middleware`
The main players in this saga are:
- RequestContextGenerate middleware
- session store middleware:
ActionDispatch::Session::EncryptedCookieStore <
ActionDispatch::Session::CookieStore <
Rack::Session::Cookie <
Rack::Session::Abstract::ID
- Rack::Session::Abstract::SessionHash
How to intercept the session_id:
The Rack session_id is generated lazily the first time the SessionHash
(which is a thin wrapper around a ruby hash) is read from or written to.
This needs to happen after the session has been loaded out of the cookie
by the session store middleware, which happens after our
RequestContextGenerate middleware. We don't just want to move the
generation of the request id later, because then the first couple log
lines will not tagged with a request id.
So our idea was to capture the session_id in an un-encrypted cookie that
could be read early in the middleware call stack (which is fine to be
public, and only used for logs to not a big deal if it's tampered with).
Again, this happens lazily on first access, so our best bet is to catch
it on the way out of the middleware stack. But when
RequestContextGenerator returns it's already too late, because cookies
have already been written to the header. So we introduce a new
middleware that captures the session_id, writes it to a cookie, and then
modify RequestContextGenerator to read from the cookie.
This works great except that with this setup, after a log in attempt the
redirect after login would still be logged with the old "unknown"
session_id and not the new, logged-in session_id. When a session is
cleared (what happens at log in time), ActionDispatch implements
a `reset_session` that we call, which calls session.destroy, but rack
had not implemented session.destroy, so rails patched it, but then after
calling destroy, they reset the session to a plain hash (not
a SessionHash), so an id isn't generated until the plain-hash session is
written to the cookie, which happens AFTER our new middleware finishes
in the stack (and never sets it in the place we look for it).
Rails 4:
Rack internals changed somewhat between rack-1.4 and rack-1.5 and the id
moves from being stored in the session options hash to the main session
hash. We'll need to fix this for rails 4.
A better way:
It may be better to try to keep a handle on the actual SessionHash so
that we can dynamically load the id for log lines, and pick up id
changes immediately as they happen, mid-request. We'd have to make sure
the lookups weren't too expensive though, vs just saving a string.
fixes CNVS-15259
Test plan:
- start a server, make a request
- you should see log lines start with [session_id, request_id] and
session_id should be present, not just "-"
Change-Id: I0289db255b2b0bc3b118e32fc1d0d9381455b1ec
Reviewed-on: https://gerrit.instructure.com/64092
Reviewed-by: Brian Palmer <brianp@instructure.com>
Tested-by: Jenkins
QA-Review: August Thornton <august@instructure.com>
Product-Review: Simon Williams <simon@instructure.com>
fixes CNVS-21479
test plan: make API requests to canvas, and verify that the X-Canvas-Meta
response header includes the controller, action, and context fields.
Change-Id: Ib2c8724d295d192c8b80125439cf68a7a6215c6f
Reviewed-on: https://gerrit.instructure.com/57143
Reviewed-by: Cody Cutrer <cody@instructure.com>
Reviewed-by: Zach Wily <zach@instructure.com>
QA-Review: August Thornton <august@instructure.com>
Tested-by: Jenkins
Product-Review: Brian Palmer <brianp@instructure.com>
Include relevant request information, for easy storing in web access
logs
closes CNVS-11044
test plan: Make web requests, use your browser's web inspector to verify
the x-canvas-meta response header.
Change-Id: I07e31b571bd9a946c9bc753c60eb8872ff456ff7
Reviewed-on: https://gerrit.instructure.com/37276
Product-Review: Brian Palmer <brianp@instructure.com>
QA-Review: Brian Palmer <brianp@instructure.com>
Tested-by: Brian Palmer <brianp@instructure.com>
Reviewed-by: Cody Cutrer <cody@instructure.com>
Ethan Vizitei