Performance regression from 5.6.1 to 6.0.7

[rmoe]

Loading notebooks and running jupyter nbconvert commands became much slower after we upgraded from 5.6.1 to 6.x. Our notebook load times went from 400-500ms to 30s or more. Our user notebooks run on kubernetes and use s3fs for the home directory.

jovyan@jupyter-5f1f30d0679987001a6cfef6:~$ time jupyter nbconvert --help
...
To see all available configurables, use `--help-all`.

real    0m31.991s
user    0m1.925s
sys     0m0.361s

Nbconvert version: 6.0.7

This was introduced in #1273. Previously get_export_names just returned the list of exporters in the nbconvert.exporters group. Now it loads and instantiates each one to check its enabled attribute. This causes a lot of stat calls and listing of directories which is very slow on s3fs.

[mriedem]

Performance regression from 5.6.1 to 6.0.7

A nit but to be clear I think the regression was introduced in 6.0.

[mriedem]

This causes a lot of stat calls and listing of directories which is very slow on s3fs.

Is it the file system work or the python module importing with the extensions? I thought it was the latter. The stat calls have always been around because the notebook server does a lot of lstat calls to check file existence.

[rmoe]

Is it the file system work or the python module importing with the extensions? I thought it was the latter. The stat calls have always been around because the notebook server does a lot of lstat calls to check file existence.

Instantiating the extensions to check their enabled attribute is what causes the increased file system activity (importing python modules, searching for configs, etc.). Running the same test on another filesystem is around 15 times faster.

[MSeal]

Ahh, yes s3fs is pretty slow and the get_export_names is fetching config files to confirm their enabled status.

I see that get_export_names is now called to build the help string for nbconvertapp... we could change that function to optionally check for enabled / disabled and not load all exporters by default on app load for help strings. Would one of you be willing to try this change out and see if performance improves back to pre 6.0 speeds for you? (I don't have a quick s3fs setup to check atm)

[rmoe]

Ahh, yes s3fs is pretty slow and the get_export_names is fetching config files to confirm their enabled status.

I see that get_export_names is now called to build the help string for nbconvertapp... we could change that function to optionally check for enabled / disabled and not load all exporters by default on app load for help strings. Would one of you be willing to try this change out and see if performance improves back to pre 6.0 speeds for you? (I don't have a quick s3fs setup to check atm)

The help string was just a quick way to demonstrate that get_export_names is slow on s3fs. The real issue that led us to this is that our notebook load times got a lot slower because get_export_names is called as part of rendering the notebook. I'm willing to try out any potential fixes.

[MSeal]

I believe from searching the repo that get_export_names is only used in help strings and error messaging. get_exporter is used when loading a specific exporter definition, and not across all templates so it shouldn't have the negative load time issue. Can you try changing get_export_names to just return sorted(entrypoints.get_group_named('nbconvert.exporters')) and see if the performance improves? If so I think we can avoid the extra cost for help strings and potentially just leave it for exception reporting.

[rmoe]

I believe from searching the repo that get_export_names is only used in help strings and error messaging. get_exporter is used when loading a specific exporter definition, and not across all templates so it shouldn't have the negative load time issue. Can you try changing get_export_names to just return sorted(entrypoints.get_group_named('nbconvert.exporters')) and see if the performance improves? If so I think we can avoid the extra cost for help strings and potentially just leave it for exception reporting.

Changing get_export_names to just return the entrypoints makes 6.0.7 run just as fast as 5.6.1.

The specific place we're seeing the issue is here. When the notebook template is rendered get_frontend_exporters is called here to create a drop-down containing the available exporters. get_frontend_exporters calls get_export_names to get all of the enabled exporters.

[rmoe]

I also did some experimenting today and found that having $HOME on a regular file system and mounting the s3fs volume in a subdirectory there reduced notebook load times to 1.5-1.7s. This is a significant improvement over having all of home on s3fs but is still 3-4x slower than 5.6.1 is.

[MSeal]

Ahh I see. Yes outside of nbconvert calling the function would trigger disk loads on each call. We could cache the result so it's only loaded once but the first load would be slow. I'm still a little surprised with the times you posted which suggests there's more calls being made than expected in those class loads.

The upgrade was from #1273 to allow for the download options to be disabled by application config. This means that the intent was to read from the config and find what classes are enabled, where the class loading disk all the disk attributes was somewhat unnecessary to determine enabled state. Rebuilding the correct config hierarchy without loading the class would be a bit of a headache to do... maybe a shortcut could be taken.

Another option here would be to have an environment variable or argument to disable the enablement check. That way you could launch with the feature check disabled.

[mriedem]

We could cache the result so it's only loaded once but the first load would be slow.

Yeah with 30s+ load times on loading the first notebook we probably can't go with that.

Another option here would be to have an environment variable or argument to disable the enablement check. That way you could launch with the feature check disabled.

FWIW this is kind of what I was thinking.

[MSeal]

Another option here would be to have an environment variable or argument to disable the enablement check. That way you could launch with the feature check disabled.

FWIW this is kind of what I was thinking.

Shoot a PR along, happy to merge it.