Tracking issue for Ember FastBoot

[jtgeibel]

Recently I've been experimenting with the FastBoot PR, and below is my attempt at capturing the work that I think remains to enable FastBoot across the site.

Enable FastBoot for some static pages

As we previously discussed, the existing PR allows us to land support on a single static page to try this out in production:

• [x] /policies - added in #1900

Groundwork for enabling FastBoot on dynamic pages

Some tasks that I think will be necessary support more dynamic cases:

• [x] Find a way to show the <noscript> message only on pages that haven't been converted yet. - #2101 tweaks the message and placement, but leaves the message present on all pages.
• [ ] Ensure a complete set of headers is sent, based on what we do in the backend middleware. - #2100
• [ ] For a logged in user, their cookie should be included in the request to the backend.
• [x] When JS is enabled, after the pre-rendered HTML is loaded and Ember boots, a new set of requests are sent from the client to the backend. - ember-data-storefront added in #2087
• [ ] Requests to routes (/does-not-exist) or resources (/crates/does-not-exist) that don't exist, should respond with status 404 instead of 200.
• [ ] Update FastBoot logs to align with our typical log format, as described in https://github.com/rust-lang/crates.io/issues/1811#issuecomment-528419399 and https://github.com/rust-lang/crates.io/pull/1900#issuecomment-554496078
• [x] Pass User-Agent header to backend - fixed in #2048

Page specific bugs

Following are bugs I observed while testing with JS off:

• [x] / - Data doesn't load - fixed in #1937
• [ ] /login - TypeError: window.open is not a function
• [ ] /logout - completely blank page
• [ ] github_login, /authorize/github - Unclear how the login workflow should work without JS, or if we should even support that
• [ ] /crates/test-crate, /crates/test-crate/0.1.5 - "Authors" and "Owners" sections are not populated
• [ ] /crates/*/download - I think this endpoint can be removed, it doesn't have an associated route file in the frontend
• [x] `/crates/*/{docs,repo} - Doesn't actually redirect when the metadata is set - added in #1912
• [ ] /me/*, /dashboard - redirects to /
• [ ] /{categories,keywords,users,teams}/does-not-exist - results in a 500 server error
• [ ] /search - doesn't load any search results
• [x] /install - a redirect which doesn't work with JS disabled, would be nice to do an HTTP redirect - added in #1912

[smarnach]

We also need to get an estimate of the additional load we impose on our servers for rendering the pages – we may need to switch to bigger dynos.

[sivakumar-kailasam]

@locks directed me here to chime in. I'm from the ember learning team & I manage the API docs which runs on fastboot. We use one 2x dyno & we tunnel all our traffic to thar app via fastly.

If you'd like more detailed stats reach out to me on discord & I'll be able to share them.

[kzys]

Regarding the additional load, it would be helpful to share the stats about the endpoints. I assume that /policies is low-traffic but don't know much about other endpoints.

[sgrif]

We also need to get an estimate of the additional load we impose on our servers for rendering the pages – we may need to switch to bigger dynos.

Less than 1% of our traffic is from browsers. I'd be shocked if we needed to increase server capacity as a result of this.

[smarnach]

Less than 1% of our traffic is from browsers.

That's definitely less than I expected. The additional server process we will be running will still consume some memory, regardless of whether it receives any requests, so we should at least take a look at that.

[sgrif]

Do we have control over the logs fastboot produces? It'd be nice if it could match the format of our previous logs. Before fastboot it would look like:

Sept 05 14:59:58 crates-io app/web.1 at=info method=GET path="/policies" request_id=a-uuid-here fwd="1.2.3.4" service=0ms status=200 user_agent="Web Browser"

Now we have:

Sept 05 15:11:46 crates-io app/web.2 2019-09-05T15:11:46.678Z 200 OK /policies

We should at least have the same amount of information that was present before. It'd be nice to put some identifier in the log I can filter on to only see requests handled by fastboot as well

[sgrif]

fastboot appears to be using a ton of memory. Right now the only page being served by fastboot is /policies.

[kzys]

https://github.com/rust-lang/crates.io/pull/1827

This caused our memory usage to increase from 50MB to 350MB at boot, and I was able to trivially cause the server to run out of memory by hitting /policies repeatedly.

@sgrif - How much increase have you observed in the production environment? My change adds 2 node processes (foreman and the actual ember server), and it is super helpful to know which one is contributing how much.

[sgrif]

I observed roughly another 300MB from hitting /policies repeatedly before rolling back the deploy, so a total of 600MB difference from the previous deploy. I don't have per-process statistics.

[kzys]

300MB for keeping the processes + 300MB per request? Wow, that's a lot.

Do we have some limits regarding the memory consumption? There is a Heroku wiki about Node's memory usage and I will try to tune what we have.

Regarding memory consumption, do you have some numbers we need to hit?

Adding Node and loading Ember there definitely consume more memory, compared to having just a cargo server. If the minimal Node + Ember setups hits the limits, we probably need to give up Fastboot and try something else.

[sgrif]

Not per-request, that was the total increase in usage I saw after a few hundred requests. Our limit is 512MB, but honestly if this is using more than 100-150MB I will be extremely uncomfortable

[kzys]

I think that 512MB is coming from Heroku's Standard 1X Dyno. Would it be able to upgrade our Dyno to more powerful one, since the server is doing more work for more features?

If we cannot change our dyno and cannot hit the 150MB goal, we need to give up Fastboot.

[sgrif]

Let's see where we're at after someone investigates the memory usage in more depth

[kzys]

Reducing the number of the child processes fastboot-app-server starts seems the way to go.

From Node's perspective, Heroku's dyno has 8 cores and fastboot-app-server starts 8 child processes,

https://github.com/ember-fastboot/fastboot-app-server/blob/bc36d74bea137ca0d3fce35555c67e373d8e6290/src/fastboot-app-server.js#L55

which Heroku specifically says "a common mistake".

https://devcenter.heroku.com/articles/node-memory-use#running-multiple-processes

A common mistake is to determine the number of Node processes to run based on the number of CPUs, but the number of physical CPUs is not the best mechanism for scaling within a virtualized Linux container. The total amount of memory used by all node processes should remain within dyno memory limits.

[kzys]

Let me submit a few small pull requests (starting #1829) to reduce the size of an upcoming FastBoot pull request.

@jtgeibel Can you uncheck /policies since we have reverted the change?

[kzys]

@sgrif / @jtgeibel - Can you add the logging issue @sgrif mentioned on the list?

[jtgeibel]

I've updated the tracking issue to include aligning the FastBoot logs with our existing backend log format.

[kzys]

@jtgeibel Also please uncheck/update about /policies...

Can I be a collaborator on this repo? So I can keep this issue up-to-date.

[kzys]

#1886 is landed on master! Let me know when you deploy the revision to production.

#1892 is going to add Fastboot-related dependencies to package.json/package-lock.json.

[carols10cents]

I've deployed #1886!

[kzys]

Regarding logs, does the Rust backend write "at=info..." lines? My understanding is that the logs are coming from Heroku's router and won't be changed by ourselves.

2019-11-15T07:40:53.196098+00:00 heroku[router]: at=info method=GET path="/policies" host=fathomless-island-39956.herokuapp.com request_id=5ff37a7b-0014-4f5c-83a5-14f8ccf18b79 fwd="73.53.6.112" dyno=web.1 connect=0ms service=83ms status=200 bytes=13580 protocol=https
2019-11-15T07:40:53.195524+00:00 app[web.1]: 2019-11-15T07:40:53.195Z 200 OK /policies
2019-11-15T07:40:53.196540+00:00 app[web.1]: measure#nginx.service=0.083 request_id=5ff37a7b-0014-4f5c-83a5-14f8ccf18b79
2019-11-15T07:41:02.307556+00:00 heroku[router]: at=info method=GET path="/policies" host=fathomless-island-39956.herokuapp.com request_id=6cf587b8-4906-42f4-ae27-20eeba01f097 fwd="73.53.6.112" dyno=web.1 connect=0ms service=90ms status=200 bytes=13580 protocol=https
2019-11-15T07:41:02.304887+00:00 app[web.1]: 2019-11-15T07:41:02.304Z 200 OK /policies
2019-11-15T07:41:02.308467+00:00 app[web.1]: measure#nginx.service=0.089 request_id=6cf587b8-4906-42f4-ae27-20eeba01f097

[carols10cents]

The Rust backend writes some of the "at=info" lines, the ones that say app[web.1]. The ones that say heroku[router] are from the heroku router.

[kzys]

(the PR we are working right now is #1900. I cannot edit the TODO list on the top...)

Okay. I will do something similar on Fastboot-side at the end of an request as well.

The log stream might be messed up by sharing the same stdin between 2 processes. Not so sure they are doing per-line buffering. I think it is okay for /policies because of the traffic, but we probably should have something like foreman before having big pages.

[kzys]

#1900 has been merged. Waiting a deployment that enables USE_FASTBOOT=1.

(@jtgeibel - seems I cannot edit the issue still. Maybe the only administrator can edit others' comments).

[kzys]

After logging change (#1908) and /install (#1912), I'm going to edit the authentication part.

#1531 mentions the existence of cookies, but #1103 mentions the use of local storage instead of cookies. Are we using some cookies right now?

[carols10cents]

#1531 mentions the existence of cookies, but #1103 mentions the use of local storage instead of cookies. Are we using some cookies right now?

We are using a cookie in general to keep a session logged in managed by the conduit-cookie crate and used here. There is also an isLoggedIn value in local storage.

[kzys]

#1912 covers /install, /crates/*/docs and /crates/*/repo. We need to modify nginx.conf (I'd like to wait #1907) and deploy the changes (according to https://whatsdeployed.io/s/9IG/rust-lang/crates.io) though.

[kzys]

#1937 will fix /.

[kzys]

@jtgeibel Can you update this issue?

Alternatively, I think we could track the progress by having a kanban board on Projects. Not so sure I can update the progress by myself, but reviewers can add FastBoot-related PRs on the kanban, which may be more maintainable than updating this issue.

[kzys]

Regarding HTTP headers, here is what Fastboot sends:

% curl --dump-header - --silent -H 'Accept: text/html' 'https://staging.crates.io/policies' | head -20
HTTP/2 200 
content-type: text/html; charset=utf-8
content-length: 13292
server: nginx
date: Sat, 04 Jan 2020 14:14:27 GMT
x-powered-by: Express
etag: W/"33ec-t4eJnKmc8aHh6VR1aGSVaaSf4oo"
strict-transport-security: max-age=31536000
via: 1.1 vegur, 1.1 82ea95080f526df99896343fb7269b07.cloudfront.net (CloudFront)
vary: Accept-Encoding,Accept,Accept-Encoding,Cookie
x-cache: Miss from cloudfront
x-amz-cf-pop: SEA19-C2
x-amz-cf-id: WlD9lAQXOONJX_N1xWciEdrz4g8TCjTs3cUsDeTTBG_dzO6IDccAWg==

<!DOCTYPE html>
<html lang="en">
  <head>
    <meta charset="utf-8">
    <meta http-equiv="X-UA-Compatible" content="IE=edge">
    <meta name="viewport" content="width=device-width, initial-scale=1">

Here is what the backend sends:

% curl --dump-header - --silent https://crates.io/api/v1/site_metadata | head -20
HTTP/2 200 
content-type: application/json; charset=utf-8
content-length: 111
server: nginx
date: Sat, 04 Jan 2020 14:14:48 GMT
x-frame-options: SAMEORIGIN
set-cookie: cargo_session=sJIiNcfM9yvCHoGNENQaO8JrPoTF1c7xuZ6xe/LTieY=; HttpOnly; Secure; Path=/
x-xss-protection: 1; mode=block
x-content-type-options: nosniff
content-security-policy: default-src 'self'; connect-src 'self' https://docs.rs https://static.crates.io; script-src 'self' 'unsafe-eval' https://www.google.com; style-src 'self' https://www.google.com https://ajax.googleapis.com; img-src *; object-src 'none'
strict-transport-security: max-age=31536000
via: 1.1 vegur, 1.1 4c7c693b007dfce603c83f138e31bccb.cloudfront.net (CloudFront)
vary: Accept,Accept-Encoding,Cookie
x-cache: Miss from cloudfront
x-amz-cf-pop: SEA19-C2
x-amz-cf-id: RUV1DZ7Vcb4NkgWkeysOxSA5vl1WjkVNobky8sj8vMKhty100PzzdQ==

{"deployed_sha":"56fe7460f7a2684a5f6be414464480a5e5407754","commit":"56fe7460f7a2684a5f6be414464480a5e5407754"}% 

Right now both https://github.com/rust-lang/crates.io/blob/e2188043227bcf027233adf762510c9ca93f3733/config/nginx.conf.erb#L117 and https://github.com/rust-lang/crates.io/blob/e2188043227bcf027233adf762510c9ca93f3733/src/middleware/security_headers.rs#L12 are sending these headers. How about moving all of them to nginx.conf.erb?

Copying them to the FastBoot server means that we have three places to maintain regarding HTTP headers, which I'd like to avoid if we can.