Loadable-components: Performance degradation over time (starts at around 100ms and grows to over 400).

[peeter-tomberg]

🐛 Bug Report

Over time, extracting chunks leads to the following graph:

To Reproduce

For each request (we use express), we set up server side rendering as follows:

import { readFileSync } from 'fs';
import * as path from 'path';
import { ChunkExtractor } from '@loadable/server';
import { Request } from 'express';

const statsFile = path.resolve('./build/client/bundles/chunks.json');
// https://github.com/gregberge/loadable-components/issues/560
const stats = JSON.parse(readFileSync(statsFile).toString('utf8'));

export const getChunkExtractor = (request: Request) => {
  const { cdnHost } = request.user.siteSettings;
  const cdnUrl = cdnHost ? `https://${cdnHost}` : '';
  const publicPath = `${cdnUrl}${request.pluginOptions.settings.portalPrefix}/bundles/`;

  return new ChunkExtractor({
    stats,
    publicPath,
  });
};

    request.pluginOptions = Object.assign({}, options);
    request.applicationContext = getApplicationContext(request);
    request.i18nContext = getI18nContext(request);
    request.helmetContext = {};
    request.routerContext = {};
    request.shouldDoServerSideRendering = shouldDoServerSideRendering(request);
    request.apolloCache = getApolloCache(request);
    request.apolloLink = getApolloLink(request);
    request.apolloClient = getApolloClient(request);
    request.chunkExtractor = getChunkExtractor(request);
    request.styleExtractor = new ServerStyleSheet();

    const cleanup = async () => {
      request.styleExtractor.seal();
      await request.apolloClient.clearStore();
      await request.apolloCache.reset();
      request.apolloClient.link = null;
      request.apolloClient.cache = null;

      const keysToGarbageCollect = [
        'pluginOptions',
        'applicationContext',
        'i18nContext',
        'helmetContext',
        'routerContext',
        'shouldDoServerSideRendering',
        'apolloCache',
        'apolloLink',
        'apolloClient',
        'chunkExtractor',
        'styleExtractor',
      ];
      keysToGarbageCollect.forEach(key => {
        const subKeys = Object.keys(request[key]) || [];
        subKeys.forEach(subKey => {
          request[key][subKey] = null;
        });
        request[key] = null;
      });
    };

    await prePopulateCacheWithData(request);

    const Application = request.pluginOptions.getApplication(request);
    request.performance.startMeasure('ssr-extract-styles');
    const noSsrHtml = renderToString(
      <StyleSheetManager sheet={request.styleExtractor.instance}>
        <Application />
      </StyleSheetManager>
    );
    request.performance.stopMeasure('ssr-extract-styles');

    request.performance.startMeasure('ssr-extract-chunks');
    request.chunkExtractor.collectChunks(<Application />);
    renderToString(
      <ChunkExtractorManager extractor={request.chunkExtractor}>
        <Application />
      </ChunkExtractorManager>
    );
    request.performance.stopMeasure('ssr-extract-chunks');

    if (request.routerContext.url) {
      return response.redirect(request.routerContext.url);
    }
    if (request.routerContext.statusCode && request.routerContext.statusCode !== 200) {
      return next(
        new Boom(`Response code not 200 - ${request.routerContext.statusCode}`, {
          statusCode: request.routerContext.statusCode,
        })
      );
    }

    response.type('html');
    sendPreloadHeaders(request, response);
    sendHeadHtml(request, response);
    sendBodyHtml(request, response, noSsrHtml);
    response.end();
    cleanup();

Expected behavior

I've setup a manual cleanup process to make sure we are cleaning up everything. During the making of this bug, I also noticed that we are collecting chunks twice. I also am aware, that we could theoretically combine collecting styles and chunks into one, but I separate them to pinpoint the issue. I also am aware of #560 which is why I am using stats and not statsPath.

Any idea on what I could check next?

[open-collective-bot[bot]]

Hey @peeter-tomberg :wave:,
Thank you for opening an issue. We'll get back to you as soon as we can.
Please, consider supporting us on Open Collective. We give a special attention to issues opened by backers.
If you use Loadable at work, you can also ask your company to sponsor us :heart:.

[peeter-tomberg]

After removing the duplicates as well as disabling apollo fetching data in the background ( https://github.com/apollographql/apollo-client/issues/6681 ), I'm still observing this issue:

Extracting chunks:

Extracting css:

I see an uptick in CSS extraction as well, but not as drastic as this.

[theKashey]

Any idea on what I could check next?

• Memory consumption please. Just to double check that there is no other memory leak.
• Then please remove ChunkExtractor __at all__, just to double check that it's all is bound to it

[peeter-tomberg]

Memory consumption did grow, and it was related to https://github.com/styled-components/styled-components/issues/3022
I pushed the fix to production this morning and will monitor. Memory consumption seems to be stable, but will know more later on. I do see extract chunks growing though.

[peeter-tomberg]

So, memory consumption is ok after the latest deploy:

However extracting chunks is still growing:

It also seems like I am fetching a lot of un-unsed javascript on the client side:

My webpack optimisation configuration is as following:

module.exports.optimisation = () => {
  return {
    nodeEnv: process.env.NODE_ENV,
    usedExports: true,
    sideEffects: true,
    // more aggressive optimisation settings than default, drops about an extra 20%, including dead code elimination
    minimizer: [
      new TerserPlugin({
        parallel: true,
        cache: true,
        sourceMap: true,
        terserOptions: {
          module: true,
          toplevel: true,
          mangle: true,
          warnings: false,
          compress: {
            defaults: true,
            dead_code: true,
            module: true,
            toplevel: true,
          },
          output: null,
          ie8: false,
          safari10: false,
          keep_classnames: undefined,
          keep_fnames: false,
        },
      }),
    ],
    runtimeChunk: true, // <-- to avoid all hashes of generated file change every time a piece of code change in 1 file ... (and spare 4kb)
    splitChunks: {
      chunks: 'all',
      maxInitialRequests: 30,
      maxAsyncRequests: 30,
      maxSize: 100000,
    },
  };
};

The general idea is to create a bundle for each node module, instead of bundling things together. This does mean, the client it split up into hunders of files. Could this affect extracting chunks?

[theKashey]

Could you explain be what your code is actually doing

const Application = request.pluginOptions.getApplication(request);
    request.performance.startMeasure('ssr-extract-styles');
    const noSsrHtml = renderToString(
      <StyleSheetManager sheet={request.styleExtractor.instance}>
        <Application />  <--- 👈👈👈 FIRST RENDER
      </StyleSheetManager>
    );
    request.performance.stopMeasure('ssr-extract-styles');

    request.performance.startMeasure('ssr-extract-chunks');
    request.chunkExtractor.collectChunks(<Application />); <--- 👈👈👈 SECOND RENDER
    renderToString(
      <ChunkExtractorManager extractor={request.chunkExtractor}>
        <Application /> <--- 👈👈👈 THIRD RENDER
      </ChunkExtractorManager>
    );
    request.performance.stopMeasure('ssr-extract-chunks');

From your graphs I've noticed that ssr-extract-styles is also growing, and it's rendering application one time, whilessr-extract-chunks is rendering application two times - and its (very) roughly takes two times more.

So:

• could you render somewhere your app 3 times, and measure the time. Would rendering time of "only" application grow as well.
• you actually need only one render, and everything may go on the blue line

  const noSsrHtml = renderToString(
      <StyleSheetManager sheet={request.styleExtractor.instance}>
       <ChunkExtractorManager extractor={request.chunkExtractor}>
        <Application />
       </ChunkExtractorManager>
      </StyleSheetManager>
    );

[peeter-tomberg]

Hello!

So I changed my codebase to the following and will run it in production for a while to see what's what. Will report back later in the day.

    const Application = request.pluginOptions.getApplication(request);
    request.performance.startMeasure('ssr-extract-chunks-styles');
    const noSsrHtml = renderToString(
      <ChunkExtractorManager extractor={request.chunkExtractor}>
        <StyleSheetManager sheet={request.styleExtractor.instance}>
          <Application />
        </StyleSheetManager>
      </ChunkExtractorManager>
    );
    request.performance.stopMeasure('ssr-extract-chunks-styles');

    request.performance.startMeasure('ssr-render-to-string');
    renderToString(<Application />);
    request.performance.stopMeasure('ssr-render-to-string');

[peeter-tomberg]

Still an issue, ran the test for 3 hours. I see renderToString time increasing as well, but this is more in line with the load doubling. At 12:00, we had around 200 concurrent users, at 15:00 we have 400 right now (without any new instances being brought up)

[theKashey]

😢 look like the problem is really in ChunkExtractorManager. But I have no idea about the root cause - there is not much code used there, and that code has no side effects.

You are using static import for chunks.json, so everything should be "stable". I need some time to think about possible reasons.

[peeter-tomberg]

If you have any questions or want to set up a chat, I'm available.

[stale[bot]]

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. Thank you for your contributions.

[peeter-tomberg]

Hello!

So we finally found the issue, and it was not related to your code at all. I do apologise for the time wasted. What I did was I dumped memory every 30 minutes when the process was being bombarded with requests. It turns out, a specific React component was slowing down over time (with a very small memory leak).

I basically got lucky and found a hint in the memory dumps that a piece of our code might not be working properly. But this took months, any recommendations on what I could do to debug these issues better in the future?

[theKashey]

It all depends on the way you made that leak, but usually that's almost impossible to trace, unless you have a test which will do roughly the same as you did - trying to render something 100 times and checking that everything is still fine.
There are plenty of tools to debug memory issues and that a bigger part of Rust idealogy, but we have to work with javascript. Keep calm and carry on.