Gitlab::Git::WikiPage eager-loading causes entire wiki to be rendered, then discarded, on every request

Summary

Every single request for a wiki page or file triggers a re-render of the first 15 pages in the wiki.

Steps to reproduce

Create an empty project
Check in 15 or more *.rst.txt files to its wiki.
Check in a single image file to its wiki
Try to view the image

Example Project

Here's the same file on two different wikis on two different projects, both here on gitlab.com. If you reload this issue with a clean browser cache, you'll see the one in the "Fast" column loads much, much faster than the one in the "Slow" column.

The only meaningful difference between the two wikis is that the Slow one has .rst.txt files in it. I'm using rst here because the renderer for those is a very slow python subprocess call, so it demonstrates the problem best. Choosing a different markdown format does not circumvent this bug, merely makes it harder to notice (because the unnecessary work for each request gets done faster).

	Fast	Slow
Image
Path	`https://gitlab.com/drmoose/wiki-files-issue-example/wikis/sunset.jpg`	`https://gitlab.com/drmoose/wiki-renders-all-the-things/wikis/sunset.jpg`

What is the current bug behavior?

Behind the scenes, Gitlab is re-rendering the first 15 pages in the wiki and then discarding the result, causing asset load to take a very long time (7 to 15 sec depending on server load). A wiki page with a lot of images causes lag spikes on my CE instance because it's spending all its resources rendering stuff it doesn't need.

When server load is high, the slow-column image may not load at all (error 500).

What is the expected correct behavior?

With my patch below, assets load in around 150ms on my local instance. Gitlab.com serves "Fast" column above in about 250ms.

Relevant logs and/or screenshots

Stack Trace

Full Stack Trace

	/opt/gitlab/embedded/lib/ruby/gems/2.3.0/gems/gitlab-markup-1.6.3/lib/github/markup.rb:23:in `render'
	/opt/gitlab/embedded/lib/ruby/gems/2.3.0/gems/gollum-lib-4.2.7/lib/gollum-lib/filter/render.rb:6:in `extract'
	/opt/gitlab/embedded/lib/ruby/gems/2.3.0/gems/gollum-lib-4.2.7/lib/gollum-lib/markup.rb:120:in `block in process_chain'
	/opt/gitlab/embedded/lib/ruby/gems/2.3.0/gems/gollum-lib-4.2.7/lib/gollum-lib/markup.rb:119:in `each'
	/opt/gitlab/embedded/lib/ruby/gems/2.3.0/gems/gollum-lib-4.2.7/lib/gollum-lib/markup.rb:119:in `process_chain'
	/opt/gitlab/embedded/lib/ruby/gems/2.3.0/gems/gollum-lib-4.2.7/lib/gollum-lib/markup.rb:164:in `render'
	/opt/gitlab/embedded/lib/ruby/gems/2.3.0/gems/gollum-lib-4.2.7/lib/gollum-lib/page.rb:227:in `formatted_data'
	/opt/gitlab/embedded/service/gitlab-rails/lib/gitlab/git/wiki_page.rb:24:in `initialize'
	/opt/gitlab/embedded/service/gitlab-rails/lib/gitlab/git/wiki.rb:173:in `new'
	/opt/gitlab/embedded/service/gitlab-rails/lib/gitlab/git/wiki.rb:173:in `new_page'
	/opt/gitlab/embedded/service/gitlab-rails/lib/gitlab/git/wiki.rb:257:in `block in gollum_get_all_pages'
	/opt/gitlab/embedded/service/gitlab-rails/lib/gitlab/git/wiki.rb:257:in `map'
	/opt/gitlab/embedded/service/gitlab-rails/lib/gitlab/git/wiki.rb:257:in `gollum_get_all_pages'
	/opt/gitlab/embedded/service/gitlab-rails/lib/gitlab/git/wiki.rb:63:in `block in pages'
	/opt/gitlab/embedded/service/gitlab-rails/lib/gitlab/gitaly_client.rb:268:in `block (2 levels) in migrate'
	/opt/gitlab/embedded/service/gitlab-rails/lib/gitlab/gitaly_client.rb:312:in `allow_n_plus_1_calls'
	/opt/gitlab/embedded/service/gitlab-rails/lib/gitlab/gitaly_client.rb:261:in `block in migrate'
	/opt/gitlab/embedded/service/gitlab-rails/lib/gitlab/metrics/influx_db.rb:98:in `measure'
	/opt/gitlab/embedded/service/gitlab-rails/lib/gitlab/gitaly_client.rb:259:in `migrate'
	/opt/gitlab/embedded/service/gitlab-rails/lib/gitlab/git/repository.rb:1370:in `gitaly_migrate'
	/opt/gitlab/embedded/service/gitlab-rails/lib/gitlab/git/wiki.rb:59:in `pages'
	/opt/gitlab/embedded/service/gitlab-rails/app/models/project_wiki.rb:80:in `pages'
	/opt/gitlab/embedded/service/gitlab-rails/app/controllers/projects/wikis_controller.rb:109:in `load_project_wiki'

The relevant entries are:

Projects::WikisController.load_project_wiki called by rails as a before_action, wants to populate @sidebar_wiki_entries and to do that calls...
ProjectWiki.pages which forwards the call to...
Gilab::Git::Wiki where it is either handled by gitaly_get_all_pages or gollum_get_all_pages, both of which return instances of...
Gitlab::Git::WikiPage, which has a constructor that eager-loads @formatted_data with a call to...
Gollum::Page.formatted_data which picks and calls an appropriate renderer based on file extension.

Output of checks

Reproduced on gitlab.com above, but just for kicks here's my CE instance:

Results of GitLab environment info

Expand for output related to GitLab environment info

System information System: Ubuntu 16.04 Current User: git Using RVM: no Ruby Version: 2.3.6p384 Gem Version: 2.6.13 Bundler Version:1.13.7 Rake Version: 12.3.0 Redis Version: 3.2.11 Git Version: 2.14.3 Sidekiq Version:5.0.5 Go Version: unknown

GitLab information Version: 10.7.1 Revision: 0d49bb8 Directory: /opt/gitlab/embedded/service/gitlab-rails DB Adapter: postgresql URL: HTTP Clone URL: SSH Clone URL: Using LDAP: no Using Omniauth: no

GitLab Shell Version: 7.1.2 Repository storage paths:

default: /var/opt/gitlab/git-data/repositories Hooks: /opt/gitlab/embedded/service/gitlab-shell/hooks Git: /opt/gitlab/embedded/bin/git

Results of GitLab application Check

All pass.

Possible fixes

Local-Only Workaround

On my local instance, I am working around the bug with this patch, which changes :formatted_data from an eager- to a lazy-load. This solves the problem on my company's omnibus instance, but it can't be merged because it only works for people who aren't using a remote Gitaly server.

--- a/after/lib/gitlab/git/wiki_page.rb
+++ b/after/lib/gitlab/git/wiki_page.rb
@@ -1,7 +1,7 @@
 module Gitlab
   module Git
     class WikiPage
-      attr_reader :url_path, :title, :format, :path, :version, :raw_data, :name, :text_data, :historical, :formatted_data
+      attr_reader :url_path, :title, :format, :path, :version, :raw_data, :name, :text_data, :historical
 
       # This class is meant to be serializable so that it can be constructed
       # by Gitaly and sent over the network to GitLab.
@@ -21,7 +21,7 @@ module Gitlab
         @raw_data = gollum_page.raw_data
         @name = gollum_page.name
         @historical = gollum_page.historical?
-        @formatted_data = gollum_page.formatted_data if gollum_page.is_a?(Gollum::Page)
+        @gollum_page = gollum_page if gollum_page.is_a?(Gollum::Page)
 
         @version = version
       end
@@ -35,6 +35,10 @@ module Gitlab
 
         @text_data = @raw_data && Gitlab::EncodingHelper.encode!(@raw_data.dup)
       end
+
+      def formatted_data
+        @formatted_data ||= @gollum_page && @gollum_page.formatted_data
+      end
     end
   end
 end

Suggested Fix

Ideally, the wiki controller should only populate @sidebar_wiki_entries when it is serving a page rather than a file, since in that case it is immediately discarded. For pages that have the sidebar, the performance issue would remain. A particularly large or difficult-to-render rst file in one of the top 15 could still make wiki pages unusably slow.
This problem was introduced by !16682 (merged) (and only recently started affecting me because my users started using .rst in the wiki and then complained everything was loading slowly). A comment on that MR's related issue lead to the creation of gitaly#822 (closed), which will one day make it possible to lazy-load formatted_data properly, instead of with my hacky patch there.

Edited May 01, 2018 by Dan