Skip to content
Snippets Groups Projects

Remove redundant counts in snippets search

Merged Heinrich Lee Yu requested to merge 44353-improve-snippet-search-performance into master
All threads resolved!

What does this MR do?

Removes redundant counts caused by code in search_entries_info

This also improves performance for other search results pages that are paginated.

What are the relevant issue numbers?

Closes #44353 (closed)

Does this MR meet the acceptance criteria?

Edited by 🤖 GitLab Bot 🤖

Merge request reports

Loading
Loading

Activity

Filter activity
  • Approvals
  • Assignees & reviewers
  • Comments (from bots)
  • Comments (from users)
  • Commits & branches
  • Edits
  • Labels
  • Lock status
  • Mentions
  • Merge request status
  • Tracking
  • added 1 commit

    • 488e89e2 - Add trigram index to snippets content

    Compare with previous version

  • Heinrich Lee Yu marked the checklist item Changelog entry added, if necessary as completed

    marked the checklist item Changelog entry added, if necessary as completed

  • mentioned in issue #44353 (closed)

  • 1 Warning
    :warning: You’ve made some app changes, but didn’t add any tests.
    That’s OK as long as you’re refactoring existing code,
    but please consider adding any of the ~backstage, ~Documentation, QA labels.

    Generated by :no_entry_sign: Danger

    Edited by 🤖 GitLab Bot 🤖
  • added 1 commit

    • 5d912d2c - Add trigram index to snippets content

    Compare with previous version

  • added 1 commit

    • c0b1b980 - Add trigram index to snippets content

    Compare with previous version

  • @ngwan thanks! This does improve things (no individual queries time out) but the page as a whole still exceeds the deadline due to repeated slow queries:

    [ gstg ] production> Gitlab::Profiler.profile('https://gitlab.com/search?search=foo&snippets=true', user: User.find_by(username: 'smcgivern'), logger: Logger.new(STDOUT))
    Started GET "/search?search=foo&snippets=true" for 127.0.0.1 at 2018-12-21 09:31:57 +0000
    I, [2018-12-21T09:31:57.135774 #3596]  INFO -- : Processing by SearchController#show as HTML
    I, [2018-12-21T09:31:57.136203 #3596]  INFO -- :   Parameters: {"search"=>"foo", "snippets"=>"true"}
    D, [2018-12-21T09:31:57.153102 #3596] DEBUG -- :   Identity Exists (1.3ms)  SELECT  1 AS one FROM "identities" WHERE "identities"."user_id" = 443319 AND (provider LIKE 'ldap%' AND extern_uid IS NOT NULL) LIMIT 1
    D, [2018-12-21T09:31:57.157325 #3596] DEBUG -- :   ↳ app/models/user.rb:895:in `ldap_user?'
    D, [2018-12-21T09:31:57.157643 #3596] DEBUG -- :   ↳ app/models/user.rb:820:in `allow_password_authentication_for_web?'
    D, [2018-12-21T09:31:57.157811 #3596] DEBUG -- :   ↳ app/models/user.rb:816:in `allow_password_authentication?'
    D, [2018-12-21T09:31:57.158033 #3596] DEBUG -- :   ↳ app/controllers/application_controller.rb:275:in `check_password_expiration'
    D, [2018-12-21T09:31:57.158207 #3596] DEBUG -- :   ↳ ee/lib/omni_auth/strategies/group_saml.rb:33:in `other_phase'
    D, [2018-12-21T09:31:57.158355 #3596] DEBUG -- :   ↳ ee/lib/gitlab/jira/middleware.rb:15:in `call'
    D, [2018-12-21T09:31:57.158495 #3596] DEBUG -- :   ↳ lib/gitlab/correlation_id.rb:15:in `use_id'
    D, [2018-12-21T09:31:57.158660 #3596] DEBUG -- :   ↳ (irb):36:in `irb_binding'
    D, [2018-12-21T09:31:57.261756 #3596] DEBUG -- :    (0.8ms)  SELECT EXTRACT(EPOCH FROM (now() - pg_last_xact_replay_timestamp()))::float as lag
    D, [2018-12-21T09:31:57.266456 #3596] DEBUG -- :   ↳ app/models/concerns/avatarable.rb:89:in `block in retrieve_upload_from_batch'
    D, [2018-12-21T09:31:57.266784 #3596] DEBUG -- :   ↳ app/models/concerns/avatarable.rb:33:in `retrieve_upload'
    D, [2018-12-21T09:31:57.266952 #3596] DEBUG -- :   ↳ app/uploaders/object_storage.rb:49:in `retrieve_from_store!'
    D, [2018-12-21T09:31:57.267126 #3596] DEBUG -- :   ↳ app/models/concerns/avatarable.rb:71:in `avatar_path'
    D, [2018-12-21T09:31:57.267279 #3596] DEBUG -- :   ↳ app/models/concerns/avatarable.rb:24:in `avatar_url'
    D, [2018-12-21T09:31:57.267440 #3596] DEBUG -- :   ↳ lib/gitlab/gon_helper.rb:35:in `add_gon_variables'
    D, [2018-12-21T09:31:57.267591 #3596] DEBUG -- :   ↳ ee/lib/omni_auth/strategies/group_saml.rb:33:in `other_phase'
    D, [2018-12-21T09:31:57.267741 #3596] DEBUG -- :   ↳ ee/lib/gitlab/jira/middleware.rb:15:in `call'
    D, [2018-12-21T09:31:57.267895 #3596] DEBUG -- :   ↳ lib/gitlab/correlation_id.rb:15:in `use_id'
    D, [2018-12-21T09:31:57.268100 #3596] DEBUG -- :   ↳ (irb):36:in `irb_binding'
    Host patroni-04-db-gstg.c.gitlab-staging-1.internal came back online
    D, [2018-12-21T09:31:57.273622 #3596] DEBUG -- :   Upload Load (2.4ms)  SELECT  "uploads".* FROM "uploads" WHERE "uploads"."uploader" = 'AvatarUploader' AND "uploads"."path" IN ('uploads/-/system/user/avatar/443319/avatar.png', 'user/avatar/443319/avatar.png') ORDER BY "uploads"."id" ASC LIMIT 1000
    D, [2018-12-21T09:31:57.277646 #3596] DEBUG -- :   ↳ app/models/concerns/avatarable.rb:89:in `block in retrieve_upload_from_batch'
    D, [2018-12-21T09:31:57.277915 #3596] DEBUG -- :   ↳ app/models/concerns/avatarable.rb:33:in `retrieve_upload'
    D, [2018-12-21T09:31:57.278121 #3596] DEBUG -- :   ↳ app/uploaders/object_storage.rb:49:in `retrieve_from_store!'
    D, [2018-12-21T09:31:57.278279 #3596] DEBUG -- :   ↳ app/models/concerns/avatarable.rb:71:in `avatar_path'
    D, [2018-12-21T09:31:57.278439 #3596] DEBUG -- :   ↳ app/models/concerns/avatarable.rb:24:in `avatar_url'
    D, [2018-12-21T09:31:57.278599 #3596] DEBUG -- :   ↳ lib/gitlab/gon_helper.rb:35:in `add_gon_variables'
    D, [2018-12-21T09:31:57.278755 #3596] DEBUG -- :   ↳ ee/lib/omni_auth/strategies/group_saml.rb:33:in `other_phase'
    D, [2018-12-21T09:31:57.278924 #3596] DEBUG -- :   ↳ ee/lib/gitlab/jira/middleware.rb:15:in `call'
    D, [2018-12-21T09:31:57.279116 #3596] DEBUG -- :   ↳ lib/gitlab/correlation_id.rb:15:in `use_id'
    D, [2018-12-21T09:31:57.279257 #3596] DEBUG -- :   ↳ (irb):36:in `irb_binding'
    D, [2018-12-21T09:31:57.298409 #3596] DEBUG -- :   License Load (1.3ms)  SELECT  "licenses".* FROM "licenses" ORDER BY "licenses"."id" DESC LIMIT 1
    D, [2018-12-21T09:31:57.304146 #3596] DEBUG -- :   ↳ ee/app/models/license.rb:227:in `load_license'
    D, [2018-12-21T09:31:57.304488 #3596] DEBUG -- :   ↳ ee/app/models/license.rb:212:in `block in current'
    D, [2018-12-21T09:31:57.304669 #3596] DEBUG -- :   ↳ ee/app/models/license.rb:212:in `current'
    D, [2018-12-21T09:31:57.304810 #3596] DEBUG -- :   ↳ ee/app/models/license.rb:218:in `feature_available?'
    D, [2018-12-21T09:31:57.304966 #3596] DEBUG -- :   ↳ ee/app/models/ee/application_setting.rb:180:in `external_authorization_service_enabled'
    D, [2018-12-21T09:31:57.305139 #3596] DEBUG -- :   ↳ ee/lib/ee/gitlab/external_authorization/config.rb:16:in `enabled?'
    D, [2018-12-21T09:31:57.305353 #3596] DEBUG -- :   ↳ ee/lib/ee/gitlab/external_authorization/config.rb:20:in `perform_check?'
    D, [2018-12-21T09:31:57.305508 #3596] DEBUG -- :   ↳ ee/app/policies/ee/base_policy.rb:9:in `block (2 levels) in <module:BasePolicy>'
    D, [2018-12-21T09:31:57.305671 #3596] DEBUG -- :   ↳ lib/declarative_policy/condition.rb:23:in `instance_eval'
    D, [2018-12-21T09:31:57.305812 #3596] DEBUG -- :   ↳ lib/declarative_policy/condition.rb:23:in `compute'
    D, [2018-12-21T09:31:57.305955 #3596] DEBUG -- :   ↳ lib/declarative_policy/condition.rb:44:in `block in pass?'
    D, [2018-12-21T09:31:57.306122 #3596] DEBUG -- :   ↳ lib/declarative_policy/base.rb:282:in `cache'
    D, [2018-12-21T09:31:57.306267 #3596] DEBUG -- :   ↳ lib/declarative_policy/condition.rb:44:in `pass?'
    D, [2018-12-21T09:31:57.306412 #3596] DEBUG -- :   ↳ lib/declarative_policy/rule.rb:81:in `pass?'
    D, [2018-12-21T09:31:57.306570 #3596] DEBUG -- :   ↳ lib/declarative_policy/rule.rb:211:in `block in pass?'
    D, [2018-12-21T09:31:57.306735 #3596] DEBUG -- :   ↳ lib/declarative_policy/rule.rb:211:in `each'
    D, [2018-12-21T09:31:57.306889 #3596] DEBUG -- :   ↳ lib/declarative_policy/rule.rb:211:in `all?'
    D, [2018-12-21T09:31:57.307037 #3596] DEBUG -- :   ↳ lib/declarative_policy/rule.rb:211:in `pass?'
    D, [2018-12-21T09:31:57.307200 #3596] DEBUG -- :   ↳ lib/declarative_policy/step.rb:81:in `pass?'
    D, [2018-12-21T09:31:57.307340 #3596] DEBUG -- :   ↳ lib/declarative_policy/runner.rb:100:in `block in run'
    D, [2018-12-21T09:31:57.307479 #3596] DEBUG -- :   ↳ lib/declarative_policy/runner.rb:179:in `block in steps_by_score'
    D, [2018-12-21T09:31:57.307630 #3596] DEBUG -- :   ↳ lib/declarative_policy/runner.rb:148:in `loop'
    D, [2018-12-21T09:31:57.307779 #3596] DEBUG -- :   ↳ lib/declarative_policy/runner.rb:148:in `steps_by_score'
    D, [2018-12-21T09:31:57.307913 #3596] DEBUG -- :   ↳ lib/declarative_policy/runner.rb:81:in `run'
    D, [2018-12-21T09:31:57.308123 #3596] DEBUG -- :   ↳ lib/declarative_policy/runner.rb:59:in `pass?'
    D, [2018-12-21T09:31:57.308264 #3596] DEBUG -- :   ↳ lib/declarative_policy/base.rb:217:in `block in allowed?'
    D, [2018-12-21T09:31:57.308405 #3596] DEBUG -- :   ↳ lib/declarative_policy/base.rb:217:in `each'
    D, [2018-12-21T09:31:57.308558 #3596] DEBUG -- :   ↳ lib/declarative_policy/base.rb:217:in `all?'
    D, [2018-12-21T09:31:57.308690 #3596] DEBUG -- :   ↳ lib/declarative_policy/base.rb:217:in `allowed?'
    D, [2018-12-21T09:31:57.308851 #3596] DEBUG -- :   ↳ lib/declarative_policy/base.rb:209:in `can?'
    D, [2018-12-21T09:31:57.308987 #3596] DEBUG -- :   ↳ app/models/ability.rb:72:in `allowed?'
    D, [2018-12-21T09:31:57.309161 #3596] DEBUG -- :   ↳ app/controllers/application_controller.rb:183:in `can?'
    D, [2018-12-21T09:31:57.309300 #3596] DEBUG -- :   ↳ app/controllers/concerns/controller_with_cross_project_access_check.rb:18:in `authorize_cross_project_page!'
    D, [2018-12-21T09:31:57.309454 #3596] DEBUG -- :   ↳ app/controllers/concerns/controller_with_cross_project_access_check.rb:13:in `cross_project_check'
    D, [2018-12-21T09:31:57.309605 #3596] DEBUG -- :   ↳ app/controllers/application_controller.rb:428:in `set_locale'
    D, [2018-12-21T09:31:57.309750 #3596] DEBUG -- :   ↳ ee/lib/omni_auth/strategies/group_saml.rb:33:in `other_phase'
    D, [2018-12-21T09:31:57.309911 #3596] DEBUG -- :   ↳ ee/lib/gitlab/jira/middleware.rb:15:in `call'
    D, [2018-12-21T09:31:57.310085 #3596] DEBUG -- :   ↳ lib/gitlab/correlation_id.rb:15:in `use_id'
    D, [2018-12-21T09:31:57.310235 #3596] DEBUG -- :   ↳ (irb):36:in `irb_binding'
    D, [2018-12-21T09:31:57.315128 #3596] DEBUG -- :    (1.2ms)  SELECT "features"."key" FROM "features"
    D, [2018-12-21T09:31:57.320875 #3596] DEBUG -- :   ↳ lib/feature.rb:15:in `feature_names'
    D, [2018-12-21T09:31:57.321190 #3596] DEBUG -- :   ↳ lib/feature.rb:35:in `persisted_names'
    D, [2018-12-21T09:31:57.321363 #3596] DEBUG -- :   ↳ lib/feature.rb:42:in `persisted?'
    D, [2018-12-21T09:31:57.321582 #3596] DEBUG -- :   ↳ lib/feature.rb:54:in `enabled?'
    D, [2018-12-21T09:31:57.321736 #3596] DEBUG -- :   ↳ ee/app/models/license.rb:308:in `feature_available?'
    D, [2018-12-21T09:31:57.321971 #3596] DEBUG -- :   ↳ ee/app/models/license.rb:218:in `feature_available?'
    D, [2018-12-21T09:31:57.322145 #3596] DEBUG -- :   ↳ ee/app/models/ee/application_setting.rb:180:in `external_authorization_service_enabled'
    D, [2018-12-21T09:31:57.322287 #3596] DEBUG -- :   ↳ ee/lib/ee/gitlab/external_authorization/config.rb:16:in `enabled?'
    D, [2018-12-21T09:31:57.322453 #3596] DEBUG -- :   ↳ ee/lib/ee/gitlab/external_authorization/config.rb:20:in `perform_check?'
    D, [2018-12-21T09:31:57.322608 #3596] DEBUG -- :   ↳ ee/app/policies/ee/base_policy.rb:9:in `block (2 levels) in <module:BasePolicy>'
    D, [2018-12-21T09:31:57.322749 #3596] DEBUG -- :   ↳ lib/declarative_policy/condition.rb:23:in `instance_eval'
    D, [2018-12-21T09:31:57.322896 #3596] DEBUG -- :   ↳ lib/declarative_policy/condition.rb:23:in `compute'
    D, [2018-12-21T09:31:57.323210 #3596] DEBUG -- :   ↳ lib/declarative_policy/condition.rb:44:in `block in pass?'
    D, [2018-12-21T09:31:57.323374 #3596] DEBUG -- :   ↳ lib/declarative_policy/base.rb:282:in `cache'
    D, [2018-12-21T09:31:57.323513 #3596] DEBUG -- :   ↳ lib/declarative_policy/condition.rb:44:in `pass?'
    D, [2018-12-21T09:31:57.323673 #3596] DEBUG -- :   ↳ lib/declarative_policy/rule.rb:81:in `pass?'
    D, [2018-12-21T09:31:57.323834 #3596] DEBUG -- :   ↳ lib/declarative_policy/rule.rb:211:in `block in pass?'
    D, [2018-12-21T09:31:57.324006 #3596] DEBUG -- :   ↳ lib/declarative_policy/rule.rb:211:in `each'
    D, [2018-12-21T09:31:57.324169 #3596] DEBUG -- :   ↳ lib/declarative_policy/rule.rb:211:in `all?'
    D, [2018-12-21T09:31:57.324312 #3596] DEBUG -- :   ↳ lib/declarative_policy/rule.rb:211:in `pass?'
    D, [2018-12-21T09:31:57.324455 #3596] DEBUG -- :   ↳ lib/declarative_policy/step.rb:81:in `pass?'
    D, [2018-12-21T09:31:57.324616 #3596] DEBUG -- :   ↳ lib/declarative_policy/runner.rb:100:in `block in run'
    D, [2018-12-21T09:31:57.324752 #3596] DEBUG -- :   ↳ lib/declarative_policy/runner.rb:179:in `block in steps_by_score'
    D, [2018-12-21T09:31:57.324896 #3596] DEBUG -- :   ↳ lib/declarative_policy/runner.rb:148:in `loop'
    D, [2018-12-21T09:31:57.325042 #3596] DEBUG -- :   ↳ lib/declarative_policy/runner.rb:148:in `steps_by_score'
    D, [2018-12-21T09:31:57.325206 #3596] DEBUG -- :   ↳ lib/declarative_policy/runner.rb:81:in `run'
    D, [2018-12-21T09:31:57.325341 #3596] DEBUG -- :   ↳ lib/declarative_policy/runner.rb:59:in `pass?'
    D, [2018-12-21T09:31:57.325484 #3596] DEBUG -- :   ↳ lib/declarative_policy/base.rb:217:in `block in allowed?'
    D, [2018-12-21T09:31:57.325644 #3596] DEBUG -- :   ↳ lib/declarative_policy/base.rb:217:in `each'
    D, [2018-12-21T09:31:57.325785 #3596] DEBUG -- :   ↳ lib/declarative_policy/base.rb:217:in `all?'
    D, [2018-12-21T09:31:57.325924 #3596] DEBUG -- :   ↳ lib/declarative_policy/base.rb:217:in `allowed?'
    D, [2018-12-21T09:31:57.326061 #3596] DEBUG -- :   ↳ lib/declarative_policy/base.rb:209:in `can?'
    D, [2018-12-21T09:31:57.326223 #3596] DEBUG -- :   ↳ app/models/ability.rb:72:in `allowed?'
    D, [2018-12-21T09:31:57.326361 #3596] DEBUG -- :   ↳ app/controllers/application_controller.rb:183:in `can?'
    D, [2018-12-21T09:31:57.326514 #3596] DEBUG -- :   ↳ app/controllers/concerns/controller_with_cross_project_access_check.rb:18:in `authorize_cross_project_page!'
    D, [2018-12-21T09:31:57.326687 #3596] DEBUG -- :   ↳ app/controllers/concerns/controller_with_cross_project_access_check.rb:13:in `cross_project_check'
    D, [2018-12-21T09:31:57.326885 #3596] DEBUG -- :   ↳ app/controllers/application_controller.rb:428:in `set_locale'
    D, [2018-12-21T09:31:57.327035 #3596] DEBUG -- :   ↳ ee/lib/omni_auth/strategies/group_saml.rb:33:in `other_phase'
    D, [2018-12-21T09:31:57.327206 #3596] DEBUG -- :   ↳ ee/lib/gitlab/jira/middleware.rb:15:in `call'
    D, [2018-12-21T09:31:57.327356 #3596] DEBUG -- :   ↳ lib/gitlab/correlation_id.rb:15:in `use_id'
    D, [2018-12-21T09:31:57.327551 #3596] DEBUG -- :   ↳ (irb):36:in `irb_binding'
    D, [2018-12-21T09:32:08.361379 #3596] DEBUG -- :    (10838.9ms)  SELECT COUNT(*) FROM (SELECT "snippets".* FROM "snippets" WHERE (snippets.visibility_level IN (10,20) OR snippets.author_id = 443319) AND "snippets"."project_id" IS NULL
    UNION
    SELECT "snippets".* FROM "snippets" INNER JOIN "projects" ON "projects"."id" = "snippets"."project_id" INNER JOIN "project_features" ON "project_features"."project_id" = "projects"."id" WHERE (snippets.visibility_level IN (10,20) OR snippets.author_id = 443319) AND (projects.visibility_level IN (10,20)) AND "project_features"."snippets_access_level" IN (20, 30)
    UNION
    SELECT "snippets".* FROM "snippets" INNER JOIN "projects" ON "projects"."id" = "snippets"."project_id" INNER JOIN "project_features" ON "project_features"."project_id" = "projects"."id" WHERE "project_features"."snippets_access_level" IN (20, 30, 10) AND (EXISTS (SELECT 1 FROM "project_authorizations" WHERE (project_id = snippets.project_id) AND "project_authorizations"."user_id" = 443319))) snippets WHERE ("snippets"."content" ILIKE '%foo%')
    D, [2018-12-21T09:32:08.365956 #3596] DEBUG -- :   ↳ lib/gitlab/snippet_search_results.rb:30:in `snippet_blobs_count'
    D, [2018-12-21T09:32:08.366267 #3596] DEBUG -- :   ↳ app/views/search/_category.html.haml:54:in `block in _app_views_search__category_html_haml___4355918592463104154_70261310510300'
    D, [2018-12-21T09:32:08.366429 #3596] DEBUG -- :   ↳ app/views/search/_category.html.haml:51:in `_app_views_search__category_html_haml___4355918592463104154_70261310510300'
    D, [2018-12-21T09:32:08.366588 #3596] DEBUG -- :   ↳ app/views/search/show.html.haml:8:in `_app_views_search_show_html_haml__1054639231877476174_70261308841480'
    D, [2018-12-21T09:32:08.366759 #3596] DEBUG -- :   ↳ app/controllers/application_controller.rb:116:in `render'
    D, [2018-12-21T09:32:08.366918 #3596] DEBUG -- :   ↳ app/controllers/application_controller.rb:428:in `set_locale'
    D, [2018-12-21T09:32:08.367058 #3596] DEBUG -- :   ↳ ee/lib/omni_auth/strategies/group_saml.rb:33:in `other_phase'
    D, [2018-12-21T09:32:08.367248 #3596] DEBUG -- :   ↳ ee/lib/gitlab/jira/middleware.rb:15:in `call'
    D, [2018-12-21T09:32:08.367412 #3596] DEBUG -- :   ↳ lib/gitlab/correlation_id.rb:15:in `use_id'
    D, [2018-12-21T09:32:08.367560 #3596] DEBUG -- :   ↳ (irb):36:in `irb_binding'
    D, [2018-12-21T09:32:08.384251 #3596] DEBUG -- :    (13.0ms)  SELECT COUNT(*) FROM (SELECT "snippets".* FROM "snippets" WHERE (snippets.visibility_level IN (10,20) OR snippets.author_id = 443319) AND "snippets"."project_id" IS NULL
    UNION
    SELECT "snippets".* FROM "snippets" INNER JOIN "projects" ON "projects"."id" = "snippets"."project_id" INNER JOIN "project_features" ON "project_features"."project_id" = "projects"."id" WHERE (snippets.visibility_level IN (10,20) OR snippets.author_id = 443319) AND (projects.visibility_level IN (10,20)) AND "project_features"."snippets_access_level" IN (20, 30)
    UNION
    SELECT "snippets".* FROM "snippets" INNER JOIN "projects" ON "projects"."id" = "snippets"."project_id" INNER JOIN "project_features" ON "project_features"."project_id" = "projects"."id" WHERE "project_features"."snippets_access_level" IN (20, 30, 10) AND (EXISTS (SELECT 1 FROM "project_authorizations" WHERE (project_id = snippets.project_id) AND "project_authorizations"."user_id" = 443319))) snippets WHERE ("snippets"."title" ILIKE '%foo%' OR "snippets"."file_name" ILIKE '%foo%')
    D, [2018-12-21T09:32:08.388983 #3596] DEBUG -- :   ↳ lib/gitlab/snippet_search_results.rb:26:in `snippet_titles_count'
    D, [2018-12-21T09:32:08.389296 #3596] DEBUG -- :   ↳ app/views/search/_category.html.haml:59:in `block in _app_views_search__category_html_haml___4355918592463104154_70261310510300'
    D, [2018-12-21T09:32:08.389464 #3596] DEBUG -- :   ↳ app/views/search/_category.html.haml:56:in `_app_views_search__category_html_haml___4355918592463104154_70261310510300'
    D, [2018-12-21T09:32:08.389630 #3596] DEBUG -- :   ↳ app/views/search/show.html.haml:8:in `_app_views_search_show_html_haml__1054639231877476174_70261308841480'
    D, [2018-12-21T09:32:08.389803 #3596] DEBUG -- :   ↳ app/controllers/application_controller.rb:116:in `render'
    D, [2018-12-21T09:32:08.389946 #3596] DEBUG -- :   ↳ app/controllers/application_controller.rb:428:in `set_locale'
    D, [2018-12-21T09:32:08.390104 #3596] DEBUG -- :   ↳ ee/lib/omni_auth/strategies/group_saml.rb:33:in `other_phase'
    D, [2018-12-21T09:32:08.390258 #3596] DEBUG -- :   ↳ ee/lib/gitlab/jira/middleware.rb:15:in `call'
    D, [2018-12-21T09:32:08.390404 #3596] DEBUG -- :   ↳ lib/gitlab/correlation_id.rb:15:in `use_id'
    D, [2018-12-21T09:32:08.390561 #3596] DEBUG -- :   ↳ (irb):36:in `irb_binding'
    D, [2018-12-21T09:32:18.860598 #3596] DEBUG -- :    (10439.6ms)  SELECT COUNT(count_column) FROM (SELECT  1 AS count_column FROM (SELECT "snippets".* FROM "snippets" WHERE (snippets.visibility_level IN (10,20) OR snippets.author_id = 443319) AND "snippets"."project_id" IS NULL
    UNION
    SELECT "snippets".* FROM "snippets" INNER JOIN "projects" ON "projects"."id" = "snippets"."project_id" INNER JOIN "project_features" ON "project_features"."project_id" = "projects"."id" WHERE (snippets.visibility_level IN (10,20) OR snippets.author_id = 443319) AND (projects.visibility_level IN (10,20)) AND "project_features"."snippets_access_level" IN (20, 30)
    UNION
    SELECT "snippets".* FROM "snippets" INNER JOIN "projects" ON "projects"."id" = "snippets"."project_id" INNER JOIN "project_features" ON "project_features"."project_id" = "projects"."id" WHERE "project_features"."snippets_access_level" IN (20, 30, 10) AND (EXISTS (SELECT 1 FROM "project_authorizations" WHERE (project_id = snippets.project_id) AND "project_authorizations"."user_id" = 443319))) snippets WHERE ("snippets"."content" ILIKE '%foo%') LIMIT 20 OFFSET 0) subquery_for_count
    D, [2018-12-21T09:32:18.865911 #3596] DEBUG -- :   ↳ app/views/search/_results.html.haml:1:in `_app_views_search__results_html_haml__2982905386654181198_70261317294400'
    D, [2018-12-21T09:32:18.866359 #3596] DEBUG -- :   ↳ app/views/search/show.html.haml:9:in `_app_views_search_show_html_haml__1054639231877476174_70261308841480'
    D, [2018-12-21T09:32:18.866547 #3596] DEBUG -- :   ↳ app/controllers/application_controller.rb:116:in `render'
    D, [2018-12-21T09:32:18.866786 #3596] DEBUG -- :   ↳ app/controllers/application_controller.rb:428:in `set_locale'
    D, [2018-12-21T09:32:18.867007 #3596] DEBUG -- :   ↳ ee/lib/omni_auth/strategies/group_saml.rb:33:in `other_phase'
    D, [2018-12-21T09:32:18.867209 #3596] DEBUG -- :   ↳ ee/lib/gitlab/jira/middleware.rb:15:in `call'
    D, [2018-12-21T09:32:18.867368 #3596] DEBUG -- :   ↳ lib/gitlab/correlation_id.rb:15:in `use_id'
    D, [2018-12-21T09:32:18.867515 #3596] DEBUG -- :   ↳ (irb):36:in `irb_binding'
    D, [2018-12-21T09:32:29.279717 #3596] DEBUG -- :    (10409.4ms)  SELECT COUNT(count_column) FROM (SELECT  1 AS count_column FROM (SELECT "snippets".* FROM "snippets" WHERE (snippets.visibility_level IN (10,20) OR snippets.author_id = 443319) AND "snippets"."project_id" IS NULL
    UNION
    SELECT "snippets".* FROM "snippets" INNER JOIN "projects" ON "projects"."id" = "snippets"."project_id" INNER JOIN "project_features" ON "project_features"."project_id" = "projects"."id" WHERE (snippets.visibility_level IN (10,20) OR snippets.author_id = 443319) AND (projects.visibility_level IN (10,20)) AND "project_features"."snippets_access_level" IN (20, 30)
    UNION
    SELECT "snippets".* FROM "snippets" INNER JOIN "projects" ON "projects"."id" = "snippets"."project_id" INNER JOIN "project_features" ON "project_features"."project_id" = "projects"."id" WHERE "project_features"."snippets_access_level" IN (20, 30, 10) AND (EXISTS (SELECT 1 FROM "project_authorizations" WHERE (project_id = snippets.project_id) AND "project_authorizations"."user_id" = 443319))) snippets WHERE ("snippets"."content" ILIKE '%foo%') LIMIT 20 OFFSET 0) subquery_for_count
    D, [2018-12-21T09:32:29.283658 #3596] DEBUG -- :   ↳ app/helpers/search_helper.rb:27:in `search_entries_info'
    D, [2018-12-21T09:32:29.283765 #3596] DEBUG -- :   ↳ app/views/search/_results.html.haml:7:in `_app_views_search__results_html_haml__2982905386654181198_70261317294400'
    D, [2018-12-21T09:32:29.283798 #3596] DEBUG -- :   ↳ app/views/search/show.html.haml:9:in `_app_views_search_show_html_haml__1054639231877476174_70261308841480'
    D, [2018-12-21T09:32:29.283837 #3596] DEBUG -- :   ↳ app/controllers/application_controller.rb:116:in `render'
    D, [2018-12-21T09:32:29.283874 #3596] DEBUG -- :   ↳ app/controllers/application_controller.rb:428:in `set_locale'
    D, [2018-12-21T09:32:29.283903 #3596] DEBUG -- :   ↳ ee/lib/omni_auth/strategies/group_saml.rb:33:in `other_phase'
    D, [2018-12-21T09:32:29.284311 #3596] DEBUG -- :   ↳ ee/lib/gitlab/jira/middleware.rb:15:in `call'
    D, [2018-12-21T09:32:29.284477 #3596] DEBUG -- :   ↳ lib/gitlab/correlation_id.rb:15:in `use_id'
    D, [2018-12-21T09:32:29.284629 #3596] DEBUG -- :   ↳ (irb):36:in `irb_binding'
    D, [2018-12-21T09:32:39.818233 #3596] DEBUG -- :    (10531.3ms)  SELECT COUNT(count_column) FROM (SELECT  1 AS count_column FROM (SELECT "snippets".* FROM "snippets" WHERE (snippets.visibility_level IN (10,20) OR snippets.author_id = 443319) AND "snippets"."project_id" IS NULL
    UNION
    SELECT "snippets".* FROM "snippets" INNER JOIN "projects" ON "projects"."id" = "snippets"."project_id" INNER JOIN "project_features" ON "project_features"."project_id" = "projects"."id" WHERE (snippets.visibility_level IN (10,20) OR snippets.author_id = 443319) AND (projects.visibility_level IN (10,20)) AND "project_features"."snippets_access_level" IN (20, 30)
    UNION
    SELECT "snippets".* FROM "snippets" INNER JOIN "projects" ON "projects"."id" = "snippets"."project_id" INNER JOIN "project_features" ON "project_features"."project_id" = "projects"."id" WHERE "project_features"."snippets_access_level" IN (20, 30, 10) AND (EXISTS (SELECT 1 FROM "project_authorizations" WHERE (project_id = snippets.project_id) AND "project_authorizations"."user_id" = 443319))) snippets WHERE ("snippets"."content" ILIKE '%foo%') LIMIT 20 OFFSET 0) subquery_for_count
    D, [2018-12-21T09:32:39.822173 #3596] DEBUG -- :   ↳ app/helpers/search_helper.rb:30:in `search_entries_info'
    D, [2018-12-21T09:32:39.822276 #3596] DEBUG -- :   ↳ app/views/search/_results.html.haml:7:in `_app_views_search__results_html_haml__2982905386654181198_70261317294400'
    D, [2018-12-21T09:32:39.822309 #3596] DEBUG -- :   ↳ app/views/search/show.html.haml:9:in `_app_views_search_show_html_haml__1054639231877476174_70261308841480'
    D, [2018-12-21T09:32:39.822338 #3596] DEBUG -- :   ↳ app/controllers/application_controller.rb:116:in `render'
    D, [2018-12-21T09:32:39.822369 #3596] DEBUG -- :   ↳ app/controllers/application_controller.rb:428:in `set_locale'
    D, [2018-12-21T09:32:39.822405 #3596] DEBUG -- :   ↳ ee/lib/omni_auth/strategies/group_saml.rb:33:in `other_phase'
    D, [2018-12-21T09:32:39.822432 #3596] DEBUG -- :   ↳ ee/lib/gitlab/jira/middleware.rb:15:in `call'
    D, [2018-12-21T09:32:39.822458 #3596] DEBUG -- :   ↳ lib/gitlab/correlation_id.rb:15:in `use_id'
    D, [2018-12-21T09:32:39.822493 #3596] DEBUG -- :   ↳ (irb):36:in `irb_binding'
    D, [2018-12-21T09:32:50.303638 #3596] DEBUG -- :    (10478.2ms)  SELECT COUNT(*) FROM (SELECT "snippets".* FROM "snippets" WHERE (snippets.visibility_level IN (10,20) OR snippets.author_id = 443319) AND "snippets"."project_id" IS NULL
    UNION
    SELECT "snippets".* FROM "snippets" INNER JOIN "projects" ON "projects"."id" = "snippets"."project_id" INNER JOIN "project_features" ON "project_features"."project_id" = "projects"."id" WHERE (snippets.visibility_level IN (10,20) OR snippets.author_id = 443319) AND (projects.visibility_level IN (10,20)) AND "project_features"."snippets_access_level" IN (20, 30)
    UNION
    SELECT "snippets".* FROM "snippets" INNER JOIN "projects" ON "projects"."id" = "snippets"."project_id" INNER JOIN "project_features" ON "project_features"."project_id" = "projects"."id" WHERE "project_features"."snippets_access_level" IN (20, 30, 10) AND (EXISTS (SELECT 1 FROM "project_authorizations" WHERE (project_id = snippets.project_id) AND "project_authorizations"."user_id" = 443319))) snippets WHERE ("snippets"."content" ILIKE '%foo%')
    D, [2018-12-21T09:32:50.307495 #3596] DEBUG -- :   ↳ app/helpers/search_helper.rb:31:in `search_entries_info'
    D, [2018-12-21T09:32:50.307597 #3596] DEBUG -- :   ↳ app/views/search/_results.html.haml:7:in `_app_views_search__results_html_haml__2982905386654181198_70261317294400'
    D, [2018-12-21T09:32:50.307629 #3596] DEBUG -- :   ↳ app/views/search/show.html.haml:9:in `_app_views_search_show_html_haml__1054639231877476174_70261308841480'
    D, [2018-12-21T09:32:50.307659 #3596] DEBUG -- :   ↳ app/controllers/application_controller.rb:116:in `render'
    D, [2018-12-21T09:32:50.307695 #3596] DEBUG -- :   ↳ app/controllers/application_controller.rb:428:in `set_locale'
    D, [2018-12-21T09:32:50.307724 #3596] DEBUG -- :   ↳ ee/lib/omni_auth/strategies/group_saml.rb:33:in `other_phase'
    D, [2018-12-21T09:32:50.307752 #3596] DEBUG -- :   ↳ ee/lib/gitlab/jira/middleware.rb:15:in `call'
    D, [2018-12-21T09:32:50.307778 #3596] DEBUG -- :   ↳ lib/gitlab/correlation_id.rb:15:in `use_id'
    D, [2018-12-21T09:32:50.307804 #3596] DEBUG -- :   ↳ (irb):36:in `irb_binding'
    D, [2018-12-21T09:33:01.000620 #3596] DEBUG -- :   Snippet Load (10663.9ms)  SELECT  "snippets".* FROM (SELECT "snippets".* FROM "snippets" WHERE (snippets.visibility_level IN (10,20) OR snippets.author_id = 443319) AND "snippets"."project_id" IS NULL
    UNION
    SELECT "snippets".* FROM "snippets" INNER JOIN "projects" ON "projects"."id" = "snippets"."project_id" INNER JOIN "project_features" ON "project_features"."project_id" = "projects"."id" WHERE (snippets.visibility_level IN (10,20) OR snippets.author_id = 443319) AND (projects.visibility_level IN (10,20)) AND "project_features"."snippets_access_level" IN (20, 30)
    UNION
    SELECT "snippets".* FROM "snippets" INNER JOIN "projects" ON "projects"."id" = "snippets"."project_id" INNER JOIN "project_features" ON "project_features"."project_id" = "projects"."id" WHERE "project_features"."snippets_access_level" IN (20, 30, 10) AND (EXISTS (SELECT 1 FROM "project_authorizations" WHERE (project_id = snippets.project_id) AND "project_authorizations"."user_id" = 443319))) snippets WHERE ("snippets"."content" ILIKE '%foo%') ORDER BY created_at DESC, updated_at DESC LIMIT 20 OFFSET 0
    D, [2018-12-21T09:33:01.005906 #3596] DEBUG -- :   ↳ app/views/search/_results.html.haml:24:in `_app_views_search__results_html_haml__2982905386654181198_70261317294400'
    D, [2018-12-21T09:33:01.006269 #3596] DEBUG -- :   ↳ app/views/search/show.html.haml:9:in `_app_views_search_show_html_haml__1054639231877476174_70261308841480'
    D, [2018-12-21T09:33:01.006520 #3596] DEBUG -- :   ↳ app/controllers/application_controller.rb:116:in `render'
    D, [2018-12-21T09:33:01.006683 #3596] DEBUG -- :   ↳ app/controllers/application_controller.rb:428:in `set_locale'
    D, [2018-12-21T09:33:01.006826 #3596] DEBUG -- :   ↳ ee/lib/omni_auth/strategies/group_saml.rb:33:in `other_phase'
    D, [2018-12-21T09:33:01.006974 #3596] DEBUG -- :   ↳ ee/lib/gitlab/jira/middleware.rb:15:in `call'
    D, [2018-12-21T09:33:01.007151 #3596] DEBUG -- :   ↳ lib/gitlab/correlation_id.rb:15:in `use_id'
    D, [2018-12-21T09:33:01.007292 #3596] DEBUG -- :   ↳ (irb):36:in `irb_binding'
    D, [2018-12-21T09:33:01.089240 #3596] DEBUG -- :   User Load (4.9ms)  SELECT "users".* FROM "users" WHERE "users"."id" IN (443319, 726421, 829774)
    D, [2018-12-21T09:33:01.094013 #3596] DEBUG -- :   ↳ app/views/search/_results.html.haml:24:in `_app_views_search__results_html_haml__2982905386654181198_70261317294400'
    D, [2018-12-21T09:33:01.094353 #3596] DEBUG -- :   ↳ app/views/search/show.html.haml:9:in `_app_views_search_show_html_haml__1054639231877476174_70261308841480'
    D, [2018-12-21T09:33:01.094531 #3596] DEBUG -- :   ↳ app/controllers/application_controller.rb:116:in `render'
    D, [2018-12-21T09:33:01.094686 #3596] DEBUG -- :   ↳ app/controllers/application_controller.rb:428:in `set_locale'
    D, [2018-12-21T09:33:01.094903 #3596] DEBUG -- :   ↳ ee/lib/omni_auth/strategies/group_saml.rb:33:in `other_phase'
    D, [2018-12-21T09:33:01.095057 #3596] DEBUG -- :   ↳ ee/lib/gitlab/jira/middleware.rb:15:in `call'
    D, [2018-12-21T09:33:01.095232 #3596] DEBUG -- :   ↳ lib/gitlab/correlation_id.rb:15:in `use_id'
    D, [2018-12-21T09:33:01.095384 #3596] DEBUG -- :   ↳ (irb):36:in `irb_binding'
    D, [2018-12-21T09:33:01.131682 #3596] DEBUG -- :   User Load (29.6ms)  SELECT "users".* FROM "users" WHERE "users"."id" IN (727859, 1656227, 720526, 1315003, 1542438, 832912, 552560, 670452, 892863, 1479830, 409720, 1402582, 440064, 340637)
    D, [2018-12-21T09:33:01.136333 #3596] DEBUG -- :   ↳ app/views/search/_results.html.haml:24:in `_app_views_search__results_html_haml__2982905386654181198_70261317294400'
    D, [2018-12-21T09:33:01.136659 #3596] DEBUG -- :   ↳ app/views/search/show.html.haml:9:in `_app_views_search_show_html_haml__1054639231877476174_70261308841480'
    D, [2018-12-21T09:33:01.136824 #3596] DEBUG -- :   ↳ app/controllers/application_controller.rb:116:in `render'
    D, [2018-12-21T09:33:01.136970 #3596] DEBUG -- :   ↳ app/controllers/application_controller.rb:428:in `set_locale'
    D, [2018-12-21T09:33:01.137163 #3596] DEBUG -- :   ↳ ee/lib/omni_auth/strategies/group_saml.rb:33:in `other_phase'
    D, [2018-12-21T09:33:01.137311 #3596] DEBUG -- :   ↳ ee/lib/gitlab/jira/middleware.rb:15:in `call'
    D, [2018-12-21T09:33:01.137456 #3596] DEBUG -- :   ↳ lib/gitlab/correlation_id.rb:15:in `use_id'
    D, [2018-12-21T09:33:01.137615 #3596] DEBUG -- :   ↳ (irb):36:in `irb_binding'
    D, [2018-12-21T09:33:01.198175 #3596] DEBUG -- :   Project Load (2.4ms)  SELECT  "projects".* FROM "projects" WHERE "projects"."id" = 13083 LIMIT 1
    D, [2018-12-21T09:33:01.202714 #3596] DEBUG -- :   ↳ app/helpers/snippets_helper.rb:6:in `reliable_snippet_path'
    D, [2018-12-21T09:33:01.203019 #3596] DEBUG -- :   ↳ app/views/search/results/_snippet_blob.html.haml:14:in `_app_views_search_results__snippet_blob_html_haml__2559751097944676510_70261323061520'
    D, [2018-12-21T09:33:01.203208 #3596] DEBUG -- :   ↳ app/views/search/_results.html.haml:24:in `_app_views_search__results_html_haml__2982905386654181198_70261317294400'
    D, [2018-12-21T09:33:01.203353 #3596] DEBUG -- :   ↳ app/views/search/show.html.haml:9:in `_app_views_search_show_html_haml__1054639231877476174_70261308841480'
    D, [2018-12-21T09:33:01.203514 #3596] DEBUG -- :   ↳ app/controllers/application_controller.rb:116:in `render'
    D, [2018-12-21T09:33:01.203652 #3596] DEBUG -- :   ↳ app/controllers/application_controller.rb:428:in `set_locale'
    D, [2018-12-21T09:33:01.203817 #3596] DEBUG -- :   ↳ ee/lib/omni_auth/strategies/group_saml.rb:33:in `other_phase'
    D, [2018-12-21T09:33:01.203992 #3596] DEBUG -- :   ↳ ee/lib/gitlab/jira/middleware.rb:15:in `call'
    D, [2018-12-21T09:33:01.204163 #3596] DEBUG -- :   ↳ lib/gitlab/correlation_id.rb:15:in `use_id'
    D, [2018-12-21T09:33:01.204311 #3596] DEBUG -- :   ↳ (irb):36:in `irb_binding'
    D, [2018-12-21T09:33:01.282636 #3596] DEBUG -- :   Namespace Load (2.1ms)  SELECT  "namespaces".* FROM "namespaces" WHERE "namespaces"."id" = 9970 LIMIT 1
    D, [2018-12-21T09:33:01.286911 #3596] DEBUG -- :   ↳ config/application.rb:270:in `block (4 levels) in <class:Application>'
    D, [2018-12-21T09:33:01.287212 #3596] DEBUG -- :   ↳ app/helpers/snippets_helper.rb:6:in `reliable_snippet_path'
    D, [2018-12-21T09:33:01.287387 #3596] DEBUG -- :   ↳ app/views/search/results/_snippet_blob.html.haml:14:in `_app_views_search_results__snippet_blob_html_haml__2559751097944676510_70261323061520'
    D, [2018-12-21T09:33:01.287553 #3596] DEBUG -- :   ↳ app/views/search/_results.html.haml:24:in `_app_views_search__results_html_haml__2982905386654181198_70261317294400'
    D, [2018-12-21T09:33:01.287709 #3596] DEBUG -- :   ↳ app/views/search/show.html.haml:9:in `_app_views_search_show_html_haml__1054639231877476174_70261308841480'
    D, [2018-12-21T09:33:01.287855 #3596] DEBUG -- :   ↳ app/controllers/application_controller.rb:116:in `render'
    D, [2018-12-21T09:33:01.288111 #3596] DEBUG -- :   ↳ app/controllers/application_controller.rb:428:in `set_locale'
    D, [2018-12-21T09:33:01.288264 #3596] DEBUG -- :   ↳ ee/lib/omni_auth/strategies/group_saml.rb:33:in `other_phase'
    D, [2018-12-21T09:33:01.288407 #3596] DEBUG -- :   ↳ ee/lib/gitlab/jira/middleware.rb:15:in `call'
    D, [2018-12-21T09:33:01.288580 #3596] DEBUG -- :   ↳ lib/gitlab/correlation_id.rb:15:in `use_id'
    D, [2018-12-21T09:33:01.288728 #3596] DEBUG -- :   ↳ (irb):36:in `irb_binding'
    D, [2018-12-21T09:33:01.359736 #3596] DEBUG -- :   Route Load (3.0ms)  SELECT  "routes".* FROM "routes" WHERE "routes"."source_id" = 9970 AND "routes"."source_type" = 'Namespace' LIMIT 1
    D, [2018-12-21T09:33:01.364391 #3596] DEBUG -- :   ↳ app/models/concerns/routable.rb:99:in `full_path'
    D, [2018-12-21T09:33:01.364687 #3596] DEBUG -- :   ↳ app/models/namespace.rb:126:in `to_param'
    D, [2018-12-21T09:33:01.364846 #3596] DEBUG -- :   ↳ config/application.rb:270:in `block (4 levels) in <class:Application>'
    D, [2018-12-21T09:33:01.365010 #3596] DEBUG -- :   ↳ app/helpers/snippets_helper.rb:6:in `reliable_snippet_path'
    D, [2018-12-21T09:33:01.365182 #3596] DEBUG -- :   ↳ app/views/search/results/_snippet_blob.html.haml:14:in `_app_views_search_results__snippet_blob_html_haml__2559751097944676510_70261323061520'
    D, [2018-12-21T09:33:01.365324 #3596] DEBUG -- :   ↳ app/views/search/_results.html.haml:24:in `_app_views_search__results_html_haml__2982905386654181198_70261317294400'
    D, [2018-12-21T09:33:01.365474 #3596] DEBUG -- :   ↳ app/views/search/show.html.haml:9:in `_app_views_search_show_html_haml__1054639231877476174_70261308841480'
    D, [2018-12-21T09:33:01.365627 #3596] DEBUG -- :   ↳ app/controllers/application_controller.rb:116:in `render'
    D, [2018-12-21T09:33:01.365781 #3596] DEBUG -- :   ↳ app/controllers/application_controller.rb:428:in `set_locale'
    D, [2018-12-21T09:33:01.365942 #3596] DEBUG -- :   ↳ ee/lib/omni_auth/strategies/group_saml.rb:33:in `other_phase'
    D, [2018-12-21T09:33:01.366103 #3596] DEBUG -- :   ↳ ee/lib/gitlab/jira/middleware.rb:15:in `call'
    D, [2018-12-21T09:33:01.366244 #3596] DEBUG -- :   ↳ lib/gitlab/correlation_id.rb:15:in `use_id'
    D, [2018-12-21T09:33:01.366388 #3596] DEBUG -- :   ↳ (irb):36:in `irb_binding'
    D, [2018-12-21T09:33:01.386849 #3596] DEBUG -- :   Project Load (1.3ms)  SELECT  "projects".* FROM "projects" WHERE "projects"."id" = 4063376 LIMIT 1
    D, [2018-12-21T09:33:01.391265 #3596] DEBUG -- :   ↳ app/helpers/snippets_helper.rb:6:in `reliable_snippet_path'
    D, [2018-12-21T09:33:01.391574 #3596] DEBUG -- :   ↳ app/views/search/results/_snippet_blob.html.haml:14:in `_app_views_search_results__snippet_blob_html_haml__2559751097944676510_70261323061520'
    D, [2018-12-21T09:33:01.391738 #3596] DEBUG -- :   ↳ app/views/search/_results.html.haml:24:in `_app_views_search__results_html_haml__2982905386654181198_70261317294400'
    D, [2018-12-21T09:33:01.391889 #3596] DEBUG -- :   ↳ app/views/search/show.html.haml:9:in `_app_views_search_show_html_haml__1054639231877476174_70261308841480'
    D, [2018-12-21T09:33:01.392106 #3596] DEBUG -- :   ↳ app/controllers/application_controller.rb:116:in `render'
    D, [2018-12-21T09:33:01.392293 #3596] DEBUG -- :   ↳ app/controllers/application_controller.rb:428:in `set_locale'
    D, [2018-12-21T09:33:01.392456 #3596] DEBUG -- :   ↳ ee/lib/omni_auth/strategies/group_saml.rb:33:in `other_phase'
    D, [2018-12-21T09:33:01.392612 #3596] DEBUG -- :   ↳ ee/lib/gitlab/jira/middleware.rb:15:in `call'
    D, [2018-12-21T09:33:01.392767 #3596] DEBUG -- :   ↳ lib/gitlab/correlation_id.rb:15:in `use_id'
    D, [2018-12-21T09:33:01.392906 #3596] DEBUG -- :   ↳ (irb):36:in `irb_binding'
    D, [2018-12-21T09:33:01.399009 #3596] DEBUG -- :   Namespace Load (1.1ms)  SELECT  "namespaces".* FROM "namespaces" WHERE "namespaces"."id" = 1846145 LIMIT 1
    D, [2018-12-21T09:33:01.403505 #3596] DEBUG -- :   ↳ config/application.rb:270:in `block (4 levels) in <class:Application>'
    D, [2018-12-21T09:33:01.403765 #3596] DEBUG -- :   ↳ app/helpers/snippets_helper.rb:6:in `reliable_snippet_path'
    D, [2018-12-21T09:33:01.404057 #3596] DEBUG -- :   ↳ app/views/search/results/_snippet_blob.html.haml:14:in `_app_views_search_results__snippet_blob_html_haml__2559751097944676510_70261323061520'
    D, [2018-12-21T09:33:01.404238 #3596] DEBUG -- :   ↳ app/views/search/_results.html.haml:24:in `_app_views_search__results_html_haml__2982905386654181198_70261317294400'
    D, [2018-12-21T09:33:01.404389 #3596] DEBUG -- :   ↳ app/views/search/show.html.haml:9:in `_app_views_search_show_html_haml__1054639231877476174_70261308841480'
    D, [2018-12-21T09:33:01.404540 #3596] DEBUG -- :   ↳ app/controllers/application_controller.rb:116:in `render'
    D, [2018-12-21T09:33:01.404686 #3596] DEBUG -- :   ↳ app/controllers/application_controller.rb:428:in `set_locale'
    D, [2018-12-21T09:33:01.404835 #3596] DEBUG -- :   ↳ ee/lib/omni_auth/strategies/group_saml.rb:33:in `other_phase'
    D, [2018-12-21T09:33:01.404978 #3596] DEBUG -- :   ↳ ee/lib/gitlab/jira/middleware.rb:15:in `call'
    D, [2018-12-21T09:33:01.405170 #3596] DEBUG -- :   ↳ lib/gitlab/correlation_id.rb:15:in `use_id'
    D, [2018-12-21T09:33:01.405310 #3596] DEBUG -- :   ↳ (irb):36:in `irb_binding'
    D, [2018-12-21T09:33:01.410740 #3596] DEBUG -- :   Route Load (1.0ms)  SELECT  "routes".* FROM "routes" WHERE "routes"."source_id" = 1846145 AND "routes"."source_type" = 'Namespace' LIMIT 1
    D, [2018-12-21T09:33:01.415113 #3596] DEBUG -- :   ↳ app/models/concerns/routable.rb:99:in `full_path'
    D, [2018-12-21T09:33:01.415405 #3596] DEBUG -- :   ↳ app/models/namespace.rb:126:in `to_param'
    D, [2018-12-21T09:33:01.415587 #3596] DEBUG -- :   ↳ config/application.rb:270:in `block (4 levels) in <class:Application>'
    D, [2018-12-21T09:33:01.415735 #3596] DEBUG -- :   ↳ app/helpers/snippets_helper.rb:6:in `reliable_snippet_path'
    D, [2018-12-21T09:33:01.415886 #3596] DEBUG -- :   ↳ app/views/search/results/_snippet_blob.html.haml:14:in `_app_views_search_results__snippet_blob_html_haml__2559751097944676510_70261323061520'
    D, [2018-12-21T09:33:01.416056 #3596] DEBUG -- :   ↳ app/views/search/_results.html.haml:24:in `_app_views_search__results_html_haml__2982905386654181198_70261317294400'
    D, [2018-12-21T09:33:01.416220 #3596] DEBUG -- :   ↳ app/views/search/show.html.haml:9:in `_app_views_search_show_html_haml__1054639231877476174_70261308841480'
    D, [2018-12-21T09:33:01.416363 #3596] DEBUG -- :   ↳ app/controllers/application_controller.rb:116:in `render'
    D, [2018-12-21T09:33:01.416538 #3596] DEBUG -- :   ↳ app/controllers/application_controller.rb:428:in `set_locale'
    D, [2018-12-21T09:33:01.416685 #3596] DEBUG -- :   ↳ ee/lib/omni_auth/strategies/group_saml.rb:33:in `other_phase'
    D, [2018-12-21T09:33:01.416825 #3596] DEBUG -- :   ↳ ee/lib/gitlab/jira/middleware.rb:15:in `call'
    D, [2018-12-21T09:33:01.416968 #3596] DEBUG -- :   ↳ lib/gitlab/correlation_id.rb:15:in `use_id'
    D, [2018-12-21T09:33:01.417128 #3596] DEBUG -- :   ↳ (irb):36:in `irb_binding'
    D, [2018-12-21T09:33:01.483696 #3596] DEBUG -- :   Upload Load (17.4ms)  SELECT  "uploads".* FROM "uploads" WHERE "uploads"."uploader" = 'AvatarUploader' AND "uploads"."path" IN ('uploads/-/system/user/avatar/443319/avatar.png', 'user/avatar/443319/avatar.png', 'uploads/-/system/user/avatar/409720/avatar.png', 'user/avatar/409720/avatar.png', 'uploads/-/system/user/avatar/440064/avatar.png', 'user/avatar/440064/avatar.png', 'uploads/-/system/user/avatar/1315003/avatar.png', 'user/avatar/1315003/avatar.png', 'uploads/-/system/user/avatar/1402582/avatar.png', 'user/avatar/1402582/avatar.png', 'uploads/-/system/user/avatar/1479830/avatar.png', 'user/avatar/1479830/avatar.png') ORDER BY "uploads"."id" ASC LIMIT 1000
    D, [2018-12-21T09:33:01.489079 #3596] DEBUG -- :   ↳ app/models/concerns/avatarable.rb:89:in `block in retrieve_upload_from_batch'
    D, [2018-12-21T09:33:01.489468 #3596] DEBUG -- :   ↳ app/models/concerns/avatarable.rb:33:in `retrieve_upload'
    D, [2018-12-21T09:33:01.489677 #3596] DEBUG -- :   ↳ app/uploaders/object_storage.rb:49:in `retrieve_from_store!'
    D, [2018-12-21T09:33:01.489904 #3596] DEBUG -- :   ↳ app/models/concerns/avatarable.rb:71:in `avatar_path'
    D, [2018-12-21T09:33:01.490054 #3596] DEBUG -- :   ↳ app/models/concerns/avatarable.rb:24:in `avatar_url'
    D, [2018-12-21T09:33:01.490221 #3596] DEBUG -- :   ↳ app/helpers/avatars_helper.rb:35:in `avatar_icon_for_user'
    D, [2018-12-21T09:33:01.490372 #3596] DEBUG -- :   ↳ app/views/search/results/_snippet_blob.html.haml:10:in `block in _app_views_search_results__snippet_blob_html_haml__2559751097944676510_70261323061520'
    D, [2018-12-21T09:33:01.490547 #3596] DEBUG -- :   ↳ app/views/search/results/_snippet_blob.html.haml:9:in `_app_views_search_results__snippet_blob_html_haml__2559751097944676510_70261323061520'
    D, [2018-12-21T09:33:01.490689 #3596] DEBUG -- :   ↳ app/views/search/_results.html.haml:24:in `_app_views_search__results_html_haml__2982905386654181198_70261317294400'
    D, [2018-12-21T09:33:01.490831 #3596] DEBUG -- :   ↳ app/views/search/show.html.haml:9:in `_app_views_search_show_html_haml__1054639231877476174_70261308841480'
    D, [2018-12-21T09:33:01.490983 #3596] DEBUG -- :   ↳ app/controllers/application_controller.rb:116:in `render'
    D, [2018-12-21T09:33:01.491150 #3596] DEBUG -- :   ↳ app/controllers/application_controller.rb:428:in `set_locale'
    D, [2018-12-21T09:33:01.491288 #3596] DEBUG -- :   ↳ ee/lib/omni_auth/strategies/group_saml.rb:33:in `other_phase'
    D, [2018-12-21T09:33:01.491451 #3596] DEBUG -- :   ↳ ee/lib/gitlab/jira/middleware.rb:15:in `call'
    D, [2018-12-21T09:33:01.491614 #3596] DEBUG -- :   ↳ lib/gitlab/correlation_id.rb:15:in `use_id'
    D, [2018-12-21T09:33:01.491759 #3596] DEBUG -- :   ↳ (irb):36:in `irb_binding'
    D, [2018-12-21T09:33:01.856880 #3596] DEBUG -- :   Project Load (1.4ms)  SELECT  "projects".* FROM "projects" WHERE "projects"."id" = 7764 LIMIT 1
    D, [2018-12-21T09:33:01.862854 #3596] DEBUG -- :   ↳ app/helpers/snippets_helper.rb:6:in `reliable_snippet_path'
    D, [2018-12-21T09:33:01.863215 #3596] DEBUG -- :   ↳ app/views/search/results/_snippet_blob.html.haml:14:in `_app_views_search_results__snippet_blob_html_haml__2559751097944676510_70261323061520'
    D, [2018-12-21T09:33:01.863384 #3596] DEBUG -- :   ↳ app/views/search/_results.html.haml:24:in `_app_views_search__results_html_haml__2982905386654181198_70261317294400'
    D, [2018-12-21T09:33:01.863555 #3596] DEBUG -- :   ↳ app/views/search/show.html.haml:9:in `_app_views_search_show_html_haml__1054639231877476174_70261308841480'
    D, [2018-12-21T09:33:01.863701 #3596] DEBUG -- :   ↳ app/controllers/application_controller.rb:116:in `render'
    D, [2018-12-21T09:33:01.863854 #3596] DEBUG -- :   ↳ app/controllers/application_controller.rb:428:in `set_locale'
    D, [2018-12-21T09:33:01.864045 #3596] DEBUG -- :   ↳ ee/lib/omni_auth/strategies/group_saml.rb:33:in `other_phase'
    D, [2018-12-21T09:33:01.864211 #3596] DEBUG -- :   ↳ ee/lib/gitlab/jira/middleware.rb:15:in `call'
    D, [2018-12-21T09:33:01.864355 #3596] DEBUG -- :   ↳ lib/gitlab/correlation_id.rb:15:in `use_id'
    D, [2018-12-21T09:33:01.864493 #3596] DEBUG -- :   ↳ (irb):36:in `irb_binding'
    D, [2018-12-21T09:33:01.870419 #3596] DEBUG -- :   Namespace Load (1.1ms)  SELECT  "namespaces".* FROM "namespaces" WHERE "namespaces"."id" = 6543 LIMIT 1
    D, [2018-12-21T09:33:01.877188 #3596] DEBUG -- :   ↳ config/application.rb:270:in `block (4 levels) in <class:Application>'
    D, [2018-12-21T09:33:01.877460 #3596] DEBUG -- :   ↳ app/helpers/snippets_helper.rb:6:in `reliable_snippet_path'
    D, [2018-12-21T09:33:01.877683 #3596] DEBUG -- :   ↳ app/views/search/results/_snippet_blob.html.haml:14:in `_app_views_search_results__snippet_blob_html_haml__2559751097944676510_70261323061520'
    D, [2018-12-21T09:33:01.877832 #3596] DEBUG -- :   ↳ app/views/search/_results.html.haml:24:in `_app_views_search__results_html_haml__2982905386654181198_70261317294400'
    D, [2018-12-21T09:33:01.877978 #3596] DEBUG -- :   ↳ app/views/search/show.html.haml:9:in `_app_views_search_show_html_haml__1054639231877476174_70261308841480'
    D, [2018-12-21T09:33:01.878168 #3596] DEBUG -- :   ↳ app/controllers/application_controller.rb:116:in `render'
    D, [2018-12-21T09:33:01.878318 #3596] DEBUG -- :   ↳ app/controllers/application_controller.rb:428:in `set_locale'
    D, [2018-12-21T09:33:01.878463 #3596] DEBUG -- :   ↳ ee/lib/omni_auth/strategies/group_saml.rb:33:in `other_phase'
    D, [2018-12-21T09:33:01.878627 #3596] DEBUG -- :   ↳ ee/lib/gitlab/jira/middleware.rb:15:in `call'
    D, [2018-12-21T09:33:01.878771 #3596] DEBUG -- :   ↳ lib/gitlab/correlation_id.rb:15:in `use_id'
    D, [2018-12-21T09:33:01.878914 #3596] DEBUG -- :   ↳ (irb):36:in `irb_binding'
    D, [2018-12-21T09:33:01.884750 #3596] DEBUG -- :   Route Load (0.9ms)  SELECT  "routes".* FROM "routes" WHERE "routes"."source_id" = 6543 AND "routes"."source_type" = 'Namespace' LIMIT 1
    D, [2018-12-21T09:33:01.891085 #3596] DEBUG -- :   ↳ app/models/concerns/routable.rb:99:in `full_path'
    D, [2018-12-21T09:33:01.891350 #3596] DEBUG -- :   ↳ app/models/namespace.rb:126:in `to_param'
    D, [2018-12-21T09:33:01.891521 #3596] DEBUG -- :   ↳ config/application.rb:270:in `block (4 levels) in <class:Application>'
    D, [2018-12-21T09:33:01.891670 #3596] DEBUG -- :   ↳ app/helpers/snippets_helper.rb:6:in `reliable_snippet_path'
    D, [2018-12-21T09:33:01.891821 #3596] DEBUG -- :   ↳ app/views/search/results/_snippet_blob.html.haml:14:in `_app_views_search_results__snippet_blob_html_haml__2559751097944676510_70261323061520'
    D, [2018-12-21T09:33:01.891993 #3596] DEBUG -- :   ↳ app/views/search/_results.html.haml:24:in `_app_views_search__results_html_haml__2982905386654181198_70261317294400'
    D, [2018-12-21T09:33:01.892169 #3596] DEBUG -- :   ↳ app/views/search/show.html.haml:9:in `_app_views_search_show_html_haml__1054639231877476174_70261308841480'
    D, [2018-12-21T09:33:01.892315 #3596] DEBUG -- :   ↳ app/controllers/application_controller.rb:116:in `render'
    D, [2018-12-21T09:33:01.892459 #3596] DEBUG -- :   ↳ app/controllers/application_controller.rb:428:in `set_locale'
    D, [2018-12-21T09:33:01.892654 #3596] DEBUG -- :   ↳ ee/lib/omni_auth/strategies/group_saml.rb:33:in `other_phase'
    D, [2018-12-21T09:33:01.892816 #3596] DEBUG -- :   ↳ ee/lib/gitlab/jira/middleware.rb:15:in `call'
    D, [2018-12-21T09:33:01.892956 #3596] DEBUG -- :   ↳ lib/gitlab/correlation_id.rb:15:in `use_id'
    D, [2018-12-21T09:33:01.893126 #3596] DEBUG -- :   ↳ (irb):36:in `irb_binding'
    D, [2018-12-21T09:33:03.937873 #3596] DEBUG -- :    (9.4ms)  SELECT COUNT(*) FROM "projects" INNER JOIN "namespaces" ON "projects"."namespace_id" = "namespaces"."id" WHERE "namespaces"."owner_id" = 443319 AND "namespaces"."type" IS NULL
    D, [2018-12-21T09:33:03.946715 #3596] DEBUG -- :   ↳ app/models/user.rb:1257:in `block in personal_projects_count'
    D, [2018-12-21T09:33:03.947158 #3596] DEBUG -- :   ↳ app/models/user.rb:1256:in `personal_projects_count'
    D, [2018-12-21T09:33:03.947323 #3596] DEBUG -- :   ↳ app/models/user.rb:856:in `projects_limit_left'
    D, [2018-12-21T09:33:03.947487 #3596] DEBUG -- :   ↳ app/models/user.rb:832:in `can_create_project?'
    D, [2018-12-21T09:33:03.947630 #3596] DEBUG -- :   ↳ app/views/layouts/header/_new_dropdown.haml:37:in `_app_views_layouts_header__new_dropdown_haml__3530087435991488584_70261346395680'
    D, [2018-12-21T09:33:03.947781 #3596] DEBUG -- :   ↳ app/views/layouts/header/_default.html.haml:29:in `_app_views_layouts_header__default_html_haml__1534231405165970829_70261364420500'
    D, [2018-12-21T09:33:03.947977 #3596] DEBUG -- :   ↳ app/views/layouts/application.html.haml:8:in `_app_views_layouts_application_html_haml__4332018328837795379_70261354748380'
    D, [2018-12-21T09:33:03.948153 #3596] DEBUG -- :   ↳ app/views/layouts/search.html.haml:4:in `_app_views_layouts_search_html_haml__639507232145452707_70261308767860'
    D, [2018-12-21T09:33:03.948295 #3596] DEBUG -- :   ↳ app/controllers/application_controller.rb:116:in `render'
    D, [2018-12-21T09:33:03.948447 #3596] DEBUG -- :   ↳ app/controllers/application_controller.rb:428:in `set_locale'
    D, [2018-12-21T09:33:03.948655 #3596] DEBUG -- :   ↳ ee/lib/omni_auth/strategies/group_saml.rb:33:in `other_phase'
    D, [2018-12-21T09:33:03.948803 #3596] DEBUG -- :   ↳ ee/lib/gitlab/jira/middleware.rb:15:in `call'
    D, [2018-12-21T09:33:03.948948 #3596] DEBUG -- :   ↳ lib/gitlab/correlation_id.rb:15:in `use_id'
    D, [2018-12-21T09:33:03.949115 #3596] DEBUG -- :   ↳ (irb):36:in `irb_binding'
    D, [2018-12-21T09:33:04.001450 #3596] DEBUG -- :   User Load (1.4ms)  SELECT  "users".* FROM "users" WHERE "users"."id" = 443319 LIMIT 1
    D, [2018-12-21T09:33:04.012253 #3596] DEBUG -- :   ↳ app/finders/issuable_finder.rb:252:in `assignee'
    D, [2018-12-21T09:33:04.012653 #3596] DEBUG -- :   ↳ app/finders/issues_finder.rb:143:in `by_assignee'
    D, [2018-12-21T09:33:04.012844 #3596] DEBUG -- :   ↳ ee/app/finders/ee/issues_finder.rb:61:in `by_assignee'
    D, [2018-12-21T09:33:04.013026 #3596] DEBUG -- :   ↳ app/finders/issuable_finder.rb:97:in `filter_items'
    D, [2018-12-21T09:33:04.013204 #3596] DEBUG -- :   ↳ app/finders/issues_finder.rb:71:in `filter_items'
    D, [2018-12-21T09:33:04.013359 #3596] DEBUG -- :   ↳ ee/app/finders/ee/issues_finder.rb:20:in `filter_items'
    D, [2018-12-21T09:33:04.013511 #3596] DEBUG -- :   ↳ app/finders/issuable_finder.rb:77:in `execute'
    D, [2018-12-21T09:33:04.013713 #3596] DEBUG -- :   ↳ app/finders/concerns/finder_with_cross_project_access.rb:21:in `execute'
    D, [2018-12-21T09:33:04.013871 #3596] DEBUG -- :   ↳ app/models/user.rb:1239:in `block in assigned_open_issues_count'
    D, [2018-12-21T09:33:04.014025 #3596] DEBUG -- :   ↳ app/models/user.rb:1238:in `assigned_open_issues_count'
    D, [2018-12-21T09:33:04.014205 #3596] DEBUG -- :   ↳ app/helpers/issuables_helper.rb:247:in `assigned_issuables_count'
    D, [2018-12-21T09:33:04.014361 #3596] DEBUG -- :   ↳ app/views/layouts/header/_default.html.haml:40:in `block (2 levels) in _app_views_layouts_header__default_html_haml__1534231405165970829_70261364420500'
    D, [2018-12-21T09:33:04.014503 #3596] DEBUG -- :   ↳ app/views/layouts/header/_default.html.haml:38:in `block in _app_views_layouts_header__default_html_haml__1534231405165970829_70261364420500'
    D, [2018-12-21T09:33:04.014651 #3596] DEBUG -- :   ↳ app/helpers/tab_helper.rb:69:in `nav_link'
    D, [2018-12-21T09:33:04.014801 #3596] DEBUG -- :   ↳ app/views/layouts/header/_default.html.haml:37:in `_app_views_layouts_header__default_html_haml__1534231405165970829_70261364420500'
    D, [2018-12-21T09:33:04.014946 #3596] DEBUG -- :   ↳ app/views/layouts/application.html.haml:8:in `_app_views_layouts_application_html_haml__4332018328837795379_70261354748380'
    D, [2018-12-21T09:33:04.015116 #3596] DEBUG -- :   ↳ app/views/layouts/search.html.haml:4:in `_app_views_layouts_search_html_haml__639507232145452707_70261308767860'
    D, [2018-12-21T09:33:04.015283 #3596] DEBUG -- :   ↳ app/controllers/application_controller.rb:116:in `render'
    D, [2018-12-21T09:33:04.015429 #3596] DEBUG -- :   ↳ app/controllers/application_controller.rb:428:in `set_locale'
    D, [2018-12-21T09:33:04.015569 #3596] DEBUG -- :   ↳ ee/lib/omni_auth/strategies/group_saml.rb:33:in `other_phase'
    D, [2018-12-21T09:33:04.015719 #3596] DEBUG -- :   ↳ ee/lib/gitlab/jira/middleware.rb:15:in `call'
    D, [2018-12-21T09:33:04.015860 #3596] DEBUG -- :   ↳ lib/gitlab/correlation_id.rb:15:in `use_id'
    D, [2018-12-21T09:33:04.016068 #3596] DEBUG -- :   ↳ (irb):36:in `irb_binding'
    D, [2018-12-21T09:33:04.436350 #3596] DEBUG -- :    (393.3ms)  SELECT COUNT(*) FROM "issues" INNER JOIN "projects" ON "projects"."id" = "issues"."project_id" LEFT JOIN project_features ON projects.id = project_features.project_id WHERE (
          issues.confidential IS NOT TRUE
          OR (issues.confidential = TRUE
            AND (issues.author_id = 443319
              OR EXISTS (SELECT TRUE FROM issue_assignees WHERE user_id = 443319 AND issue_id = issues.id)
              OR issues.project_id IN(SELECT "projects"."id" FROM "projects" INNER JOIN "project_authorizations" ON "projects"."id" = "project_authorizations"."project_id" WHERE "project_authorizations"."user_id" = 443319 AND (project_authorizations.access_level >= 20))))) AND (EXISTS (SELECT 1 FROM "project_authorizations" WHERE "project_authorizations"."user_id" = 443319 AND (project_authorizations.project_id = projects.id)) OR projects.visibility_level IN (10,20)) AND ("project_features"."issues_access_level" IN (NULL,20,30) OR ("project_features"."issues_access_level" = 10 AND EXISTS (SELECT 1 FROM "project_authorizations" WHERE "project_authorizations"."user_id" = 443319 AND (project_authorizations.project_id = projects.id)))) AND ("issues"."state" IN ('opened')) AND (EXISTS (SELECT TRUE FROM issue_assignees WHERE user_id = 443319 AND issue_id = issues.id)) AND "projects"."archived" = 'f'
    D, [2018-12-21T09:33:04.444067 #3596] DEBUG -- :   ↳ app/models/user.rb:1239:in `block in assigned_open_issues_count'
    D, [2018-12-21T09:33:04.444463 #3596] DEBUG -- :   ↳ app/models/user.rb:1238:in `assigned_open_issues_count'
    D, [2018-12-21T09:33:04.444646 #3596] DEBUG -- :   ↳ app/helpers/issuables_helper.rb:247:in `assigned_issuables_count'
    D, [2018-12-21T09:33:04.444801 #3596] DEBUG -- :   ↳ app/views/layouts/header/_default.html.haml:40:in `block (2 levels) in _app_views_layouts_header__default_html_haml__1534231405165970829_70261364420500'
    D, [2018-12-21T09:33:04.444950 #3596] DEBUG -- :   ↳ app/views/layouts/header/_default.html.haml:38:in `block in _app_views_layouts_header__default_html_haml__1534231405165970829_70261364420500'
    D, [2018-12-21T09:33:04.445126 #3596] DEBUG -- :   ↳ app/helpers/tab_helper.rb:69:in `nav_link'
    D, [2018-12-21T09:33:04.445279 #3596] DEBUG -- :   ↳ app/views/layouts/header/_default.html.haml:37:in `_app_views_layouts_header__default_html_haml__1534231405165970829_70261364420500'
    D, [2018-12-21T09:33:04.445426 #3596] DEBUG -- :   ↳ app/views/layouts/application.html.haml:8:in `_app_views_layouts_application_html_haml__4332018328837795379_70261354748380'
    D, [2018-12-21T09:33:04.445590 #3596] DEBUG -- :   ↳ app/views/layouts/search.html.haml:4:in `_app_views_layouts_search_html_haml__639507232145452707_70261308767860'
    D, [2018-12-21T09:33:04.445738 #3596] DEBUG -- :   ↳ app/controllers/application_controller.rb:116:in `render'
    D, [2018-12-21T09:33:04.445872 #3596] DEBUG -- :   ↳ app/controllers/application_controller.rb:428:in `set_locale'
    D, [2018-12-21T09:33:04.446017 #3596] DEBUG -- :   ↳ ee/lib/omni_auth/strategies/group_saml.rb:33:in `other_phase'
    D, [2018-12-21T09:33:04.446193 #3596] DEBUG -- :   ↳ ee/lib/gitlab/jira/middleware.rb:15:in `call'
    D, [2018-12-21T09:33:04.446335 #3596] DEBUG -- :   ↳ lib/gitlab/correlation_id.rb:15:in `use_id'
    D, [2018-12-21T09:33:04.446471 #3596] DEBUG -- :   ↳ (irb):36:in `irb_binding'
    D, [2018-12-21T09:33:04.477929 #3596] DEBUG -- :   User Load (1.4ms)  SELECT  "users".* FROM "users" WHERE "users"."id" = 443319 LIMIT 1
    D, [2018-12-21T09:33:04.486412 #3596] DEBUG -- :   ↳ app/finders/issuable_finder.rb:252:in `assignee'
    D, [2018-12-21T09:33:04.486864 #3596] DEBUG -- :   ↳ app/finders/issuable_finder.rb:421:in `by_assignee'
    D, [2018-12-21T09:33:04.487049 #3596] DEBUG -- :   ↳ app/finders/issuable_finder.rb:97:in `filter_items'
    D, [2018-12-21T09:33:04.487267 #3596] DEBUG -- :   ↳ app/finders/merge_requests_finder.rb:39:in `filter_items'
    D, [2018-12-21T09:33:04.488231 #3596] DEBUG -- :   ↳ app/finders/issuable_finder.rb:77:in `execute'
    D, [2018-12-21T09:33:04.488389 #3596] DEBUG -- :   ↳ app/finders/concerns/finder_with_cross_project_access.rb:21:in `execute'
    D, [2018-12-21T09:33:04.488557 #3596] DEBUG -- :   ↳ app/models/user.rb:1233:in `block in assigned_open_merge_requests_count'
    D, [2018-12-21T09:33:04.488705 #3596] DEBUG -- :   ↳ app/models/user.rb:1232:in `assigned_open_merge_requests_count'
    D, [2018-12-21T09:33:04.488852 #3596] DEBUG -- :   ↳ app/helpers/issuables_helper.rb:249:in `assigned_issuables_count'
    D, [2018-12-21T09:33:04.489009 #3596] DEBUG -- :   ↳ app/views/layouts/header/_default.html.haml:47:in `block (2 levels) in _app_views_layouts_header__default_html_haml__1534231405165970829_70261364420500'
    D, [2018-12-21T09:33:04.489241 #3596] DEBUG -- :   ↳ app/views/layouts/header/_default.html.haml:45:in `block in _app_views_layouts_header__default_html_haml__1534231405165970829_70261364420500'
    D, [2018-12-21T09:33:04.489437 #3596] DEBUG -- :   ↳ app/helpers/tab_helper.rb:69:in `nav_link'
    D, [2018-12-21T09:33:04.489589 #3596] DEBUG -- :   ↳ app/views/layouts/header/_default.html.haml:44:in `_app_views_layouts_header__default_html_haml__1534231405165970829_70261364420500'
    D, [2018-12-21T09:33:04.489731 #3596] DEBUG -- :   ↳ app/views/layouts/application.html.haml:8:in `_app_views_layouts_application_html_haml__4332018328837795379_70261354748380'
    D, [2018-12-21T09:33:04.489872 #3596] DEBUG -- :   ↳ app/views/layouts/search.html.haml:4:in `_app_views_layouts_search_html_haml__639507232145452707_70261308767860'
    D, [2018-12-21T09:33:04.490014 #3596] DEBUG -- :   ↳ app/controllers/application_controller.rb:116:in `render'
    D, [2018-12-21T09:33:04.490181 #3596] DEBUG -- :   ↳ app/controllers/application_controller.rb:428:in `set_locale'
    D, [2018-12-21T09:33:04.490343 #3596] DEBUG -- :   ↳ ee/lib/omni_auth/strategies/group_saml.rb:33:in `other_phase'
    D, [2018-12-21T09:33:04.490482 #3596] DEBUG -- :   ↳ ee/lib/gitlab/jira/middleware.rb:15:in `call'
    D, [2018-12-21T09:33:04.490646 #3596] DEBUG -- :   ↳ lib/gitlab/correlation_id.rb:15:in `use_id'
    D, [2018-12-21T09:33:04.490789 #3596] DEBUG -- :   ↳ (irb):36:in `irb_binding'
    D, [2018-12-21T09:33:04.722259 #3596] DEBUG -- :    (204.9ms)  SELECT COUNT(*) FROM "merge_requests" INNER JOIN "projects" ON "projects"."id" = "merge_requests"."target_project_id" LEFT JOIN project_features ON projects.id = project_features.project_id WHERE (EXISTS (SELECT 1 FROM "project_authorizations" WHERE "project_authorizations"."user_id" = 443319 AND (project_authorizations.project_id = projects.id)) OR projects.visibility_level IN (10,20)) AND ("project_features"."merge_requests_access_level" IN (NULL,20,30) OR ("project_features"."merge_requests_access_level" = 10 AND EXISTS (SELECT 1 FROM "project_authorizations" WHERE "project_authorizations"."user_id" = 443319 AND (project_authorizations.project_id = projects.id)))) AND ("merge_requests"."state" IN ('opened')) AND "merge_requests"."assignee_id" = 443319 AND "projects"."archived" = 'f'
    D, [2018-12-21T09:33:04.729456 #3596] DEBUG -- :   ↳ app/models/user.rb:1233:in `block in assigned_open_merge_requests_count'
    D, [2018-12-21T09:33:04.729862 #3596] DEBUG -- :   ↳ app/models/user.rb:1232:in `assigned_open_merge_requests_count'
    D, [2018-12-21T09:33:04.730026 #3596] DEBUG -- :   ↳ app/helpers/issuables_helper.rb:249:in `assigned_issuables_count'
    D, [2018-12-21T09:33:04.730204 #3596] DEBUG -- :   ↳ app/views/layouts/header/_default.html.haml:47:in `block (2 levels) in _app_views_layouts_header__default_html_haml__1534231405165970829_70261364420500'
    D, [2018-12-21T09:33:04.730349 #3596] DEBUG -- :   ↳ app/views/layouts/header/_default.html.haml:45:in `block in _app_views_layouts_header__default_html_haml__1534231405165970829_70261364420500'
    D, [2018-12-21T09:33:04.730517 #3596] DEBUG -- :   ↳ app/helpers/tab_helper.rb:69:in `nav_link'
    D, [2018-12-21T09:33:04.730671 #3596] DEBUG -- :   ↳ app/views/layouts/header/_default.html.haml:44:in `_app_views_layouts_header__default_html_haml__1534231405165970829_70261364420500'
    D, [2018-12-21T09:33:04.730846 #3596] DEBUG -- :   ↳ app/views/layouts/application.html.haml:8:in `_app_views_layouts_application_html_haml__4332018328837795379_70261354748380'
    D, [2018-12-21T09:33:04.730990 #3596] DEBUG -- :   ↳ app/views/layouts/search.html.haml:4:in `_app_views_layouts_search_html_haml__639507232145452707_70261308767860'
    D, [2018-12-21T09:33:04.731165 #3596] DEBUG -- :   ↳ app/controllers/application_controller.rb:116:in `render'
    D, [2018-12-21T09:33:04.731311 #3596] DEBUG -- :   ↳ app/controllers/application_controller.rb:428:in `set_locale'
    D, [2018-12-21T09:33:04.731476 #3596] DEBUG -- :   ↳ ee/lib/omni_auth/strategies/group_saml.rb:33:in `other_phase'
    D, [2018-12-21T09:33:04.731697 #3596] DEBUG -- :   ↳ ee/lib/gitlab/jira/middleware.rb:15:in `call'
    D, [2018-12-21T09:33:04.731842 #3596] DEBUG -- :   ↳ lib/gitlab/correlation_id.rb:15:in `use_id'
    D, [2018-12-21T09:33:04.732020 #3596] DEBUG -- :   ↳ (irb):36:in `irb_binding'
    D, [2018-12-21T09:33:04.753661 #3596] DEBUG -- :    (4.9ms)  SELECT COUNT(*) FROM "todos" WHERE "todos"."user_id" = 443319 AND ("todos"."state" IN ('pending'))
    D, [2018-12-21T09:33:04.762339 #3596] DEBUG -- :   ↳ app/models/user.rb:1251:in `block in todos_pending_count'
    D, [2018-12-21T09:33:04.762743 #3596] DEBUG -- :   ↳ app/models/user.rb:1250:in `todos_pending_count'
    D, [2018-12-21T09:33:04.762917 #3596] DEBUG -- :   ↳ app/helpers/todos_helper.rb:5:in `todos_pending_count'
    D, [2018-12-21T09:33:04.763096 #3596] DEBUG -- :   ↳ app/views/layouts/header/_default.html.haml:54:in `block (2 levels) in _app_views_layouts_header__default_html_haml__1534231405165970829_70261364420500'
    D, [2018-12-21T09:33:04.763261 #3596] DEBUG -- :   ↳ app/views/layouts/header/_default.html.haml:52:in `block in _app_views_layouts_header__default_html_haml__1534231405165970829_70261364420500'
    D, [2018-12-21T09:33:04.763407 #3596] DEBUG -- :   ↳ app/helpers/tab_helper.rb:69:in `nav_link'
    D, [2018-12-21T09:33:04.763574 #3596] DEBUG -- :   ↳ app/views/layouts/header/_default.html.haml:51:in `_app_views_layouts_header__default_html_haml__1534231405165970829_70261364420500'
    D, [2018-12-21T09:33:04.763726 #3596] DEBUG -- :   ↳ app/views/layouts/application.html.haml:8:in `_app_views_layouts_application_html_haml__4332018328837795379_70261354748380'
    D, [2018-12-21T09:33:04.763915 #3596] DEBUG -- :   ↳ app/views/layouts/search.html.haml:4:in `_app_views_layouts_search_html_haml__639507232145452707_70261308767860'
    D, [2018-12-21T09:33:04.764158 #3596] DEBUG -- :   ↳ app/controllers/application_controller.rb:116:in `render'
    D, [2018-12-21T09:33:04.764302 #3596] DEBUG -- :   ↳ app/controllers/application_controller.rb:428:in `set_locale'
    D, [2018-12-21T09:33:04.764456 #3596] DEBUG -- :   ↳ ee/lib/omni_auth/strategies/group_saml.rb:33:in `other_phase'
    D, [2018-12-21T09:33:04.764619 #3596] DEBUG -- :   ↳ ee/lib/gitlab/jira/middleware.rb:15:in `call'
    D, [2018-12-21T09:33:04.764764 #3596] DEBUG -- :   ↳ lib/gitlab/correlation_id.rb:15:in `use_id'
    D, [2018-12-21T09:33:04.764925 #3596] DEBUG -- :   ↳ (irb):36:in `irb_binding'
    D, [2018-12-21T09:33:04.915526 #3596] DEBUG -- :   UserStatus Load (1.3ms)  SELECT  "user_statuses".* FROM "user_statuses" WHERE "user_statuses"."user_id" = 443319 LIMIT 1
    D, [2018-12-21T09:33:04.922313 #3596] DEBUG -- :   ↳ app/views/layouts/header/_current_user_dropdown.html.haml:8:in `_app_views_layouts_header__current_user_dropdown_html_haml__1456687932340784650_70261324121880'
    D, [2018-12-21T09:33:04.922675 #3596] DEBUG -- :   ↳ app/views/layouts/header/_default.html.haml:68:in `_app_views_layouts_header__default_html_haml__1534231405165970829_70261364420500'
    D, [2018-12-21T09:33:04.922892 #3596] DEBUG -- :   ↳ app/views/layouts/application.html.haml:8:in `_app_views_layouts_application_html_haml__4332018328837795379_70261354748380'
    D, [2018-12-21T09:33:04.923048 #3596] DEBUG -- :   ↳ app/views/layouts/search.html.haml:4:in `_app_views_layouts_search_html_haml__639507232145452707_70261308767860'
    D, [2018-12-21T09:33:04.923256 #3596] DEBUG -- :   ↳ app/controllers/application_controller.rb:116:in `render'
    D, [2018-12-21T09:33:04.923416 #3596] DEBUG -- :   ↳ app/controllers/application_controller.rb:428:in `set_locale'
    D, [2018-12-21T09:33:04.923574 #3596] DEBUG -- :   ↳ ee/lib/omni_auth/strategies/group_saml.rb:33:in `other_phase'
    D, [2018-12-21T09:33:04.923711 #3596] DEBUG -- :   ↳ ee/lib/gitlab/jira/middleware.rb:15:in `call'
    D, [2018-12-21T09:33:04.923850 #3596] DEBUG -- :   ↳ lib/gitlab/correlation_id.rb:15:in `use_id'
    D, [2018-12-21T09:33:04.924026 #3596] DEBUG -- :   ↳ (irb):36:in `irb_binding'
    I, [2018-12-21T09:33:05.537888 #3596]  INFO -- : Completed 200 OK in 68401ms (Views: 4080.1ms | ActiveRecord: 64120.3ms | Elasticsearch: 0.0ms)
    I, [2018-12-21T09:33:05.555612 #3596]  INFO -- : Snippet total (1): 10663.9ms
    I, [2018-12-21T09:33:05.555906 #3596]  INFO -- : User total (4): 37.3ms
    I, [2018-12-21T09:33:05.556158 #3596]  INFO -- : Upload total (2): 19.8ms
    I, [2018-12-21T09:33:05.556297 #3596]  INFO -- : Project total (3): 5.1ms
    I, [2018-12-21T09:33:05.556417 #3596]  INFO -- : Route total (3): 4.9ms
    I, [2018-12-21T09:33:05.556548 #3596]  INFO -- : Namespace total (3): 4.3ms
    I, [2018-12-21T09:33:05.556670 #3596]  INFO -- : UserStatus total (1): 1.3ms
    I, [2018-12-21T09:33:05.556805 #3596]  INFO -- : License total (1): 1.3ms
  • Author Maintainer

    Thanks @smcgivern.

    Hmm.. I will investigate the repeated counts. Not sure why I didn't see it when I tested locally. Maybe it does only when there are results.

    I think removing the repeated counts will be good enough and we won't need to add limits like in the previous WIP MR?

  • @engwan hopefully, yes!

  • added 1 commit

    • f0f3ef64 - Reduce counts in search_entries_info

    Compare with previous version

  • added 1 commit

    • 6f413fdd - Reduce counts in search_entries_info

    Compare with previous version

  • Author Maintainer

    @smcgivern I found the code causing the extra counts.

    This reduces the counts to just 2. One for content and one for title and filename

    It also saves us some queries in other "paginated with count" search results.

    Edited by Heinrich Lee Yu
  • Heinrich Lee Yu added 168 commits

    added 168 commits

    Compare with previous version

  • added 1 commit

    • db853acb - Reduce counts in search_entries_info

    Compare with previous version

  • added 1 commit

    • 6b858e5f - Reduce counts in search_entries_info

    Compare with previous version

  • added 1 commit

    Compare with previous version

  • Thanks @engwan! Updated results:

    [ gstg ] production> Gitlab::Profiler.profile('https://gitlab.com/search?search=foo&snippets=true', user: User.find_by(username: 'smcgivern'), logger: Logger.new(STDOUT))
    Started GET "/api/v4/users" for 127.0.0.1 at 2018-12-24 10:04:42 +0000
    Processing by Gitlab::RequestForgeryProtection::Controller#index as HTML
    Completed 200 OK in 1ms (ActiveRecord: 0.0ms | Elasticsearch: 0.0ms)
    Started GET "/search?search=foo&snippets=true" for 127.0.0.1 at 2018-12-24 10:04:45 +0000
    I, [2018-12-24T10:04:45.143014 #17199]  INFO -- : Processing by SearchController#show as HTML
    I, [2018-12-24T10:04:45.143399 #17199]  INFO -- :   Parameters: {"search"=>"foo", "snippets"=>"true"}
    D, [2018-12-24T10:04:45.163825 #17199] DEBUG -- :   Identity Exists (3.7ms)  SELECT  1 AS one FROM "identities" WHERE "identities"."user_id" = 443319 AND (provider LIKE 'ldap%' AND extern_uid IS NOT NULL) LIMIT 1
    D, [2018-12-24T10:04:45.167853 #17199] DEBUG -- :   ↳ app/models/user.rb:895:in `ldap_user?'
    D, [2018-12-24T10:04:45.168234 #17199] DEBUG -- :   ↳ app/models/user.rb:820:in `allow_password_authentication_for_web?'
    D, [2018-12-24T10:04:45.168426 #17199] DEBUG -- :   ↳ app/models/user.rb:816:in `allow_password_authentication?'
    D, [2018-12-24T10:04:45.168600 #17199] DEBUG -- :   ↳ app/controllers/application_controller.rb:275:in `check_password_expiration'
    D, [2018-12-24T10:04:45.168800 #17199] DEBUG -- :   ↳ ee/lib/omni_auth/strategies/group_saml.rb:33:in `other_phase'
    D, [2018-12-24T10:04:45.168958 #17199] DEBUG -- :   ↳ ee/lib/gitlab/jira/middleware.rb:15:in `call'
    D, [2018-12-24T10:04:45.169123 #17199] DEBUG -- :   ↳ lib/gitlab/correlation_id.rb:15:in `use_id'
    D, [2018-12-24T10:04:45.169268 #17199] DEBUG -- :   ↳ (irb):48:in `irb_binding'
    D, [2018-12-24T10:04:45.224539 #17199] DEBUG -- :   Upload Load (2.4ms)  SELECT  "uploads".* FROM "uploads" WHERE "uploads"."uploader" = 'AvatarUploader' AND "uploads"."path" IN ('uploads/-/system/user/avatar/443319/avatar.png', 'user/avatar/443319/avatar.png') ORDER BY "uploads"."id" ASC LIMIT 1000
    D, [2018-12-24T10:04:45.228674 #17199] DEBUG -- :   ↳ app/models/concerns/avatarable.rb:89:in `block in retrieve_upload_from_batch'
    D, [2018-12-24T10:04:45.229020 #17199] DEBUG -- :   ↳ app/models/concerns/avatarable.rb:33:in `retrieve_upload'
    D, [2018-12-24T10:04:45.229228 #17199] DEBUG -- :   ↳ app/uploaders/object_storage.rb:49:in `retrieve_from_store!'
    D, [2018-12-24T10:04:45.229424 #17199] DEBUG -- :   ↳ app/models/concerns/avatarable.rb:71:in `avatar_path'
    D, [2018-12-24T10:04:45.229580 #17199] DEBUG -- :   ↳ app/models/concerns/avatarable.rb:24:in `avatar_url'
    D, [2018-12-24T10:04:45.229731 #17199] DEBUG -- :   ↳ lib/gitlab/gon_helper.rb:35:in `add_gon_variables'
    D, [2018-12-24T10:04:45.229883 #17199] DEBUG -- :   ↳ ee/lib/omni_auth/strategies/group_saml.rb:33:in `other_phase'
    D, [2018-12-24T10:04:45.230037 #17199] DEBUG -- :   ↳ ee/lib/gitlab/jira/middleware.rb:15:in `call'
    D, [2018-12-24T10:04:45.230210 #17199] DEBUG -- :   ↳ lib/gitlab/correlation_id.rb:15:in `use_id'
    D, [2018-12-24T10:04:45.230393 #17199] DEBUG -- :   ↳ (irb):48:in `irb_binding'
    D, [2018-12-24T10:04:45.249000 #17199] DEBUG -- :   License Load (1.5ms)  SELECT  "licenses".* FROM "licenses" ORDER BY "licenses"."id" DESC LIMIT 1
    D, [2018-12-24T10:04:45.254216 #17199] DEBUG -- :   ↳ ee/app/models/license.rb:227:in `load_license'
    D, [2018-12-24T10:04:45.254587 #17199] DEBUG -- :   ↳ ee/app/models/license.rb:212:in `block in current'
    D, [2018-12-24T10:04:45.254740 #17199] DEBUG -- :   ↳ ee/app/models/license.rb:212:in `current'
    D, [2018-12-24T10:04:45.254902 #17199] DEBUG -- :   ↳ ee/app/models/license.rb:218:in `feature_available?'
    D, [2018-12-24T10:04:45.255097 #17199] DEBUG -- :   ↳ ee/app/models/ee/application_setting.rb:180:in `external_authorization_service_enabled'
    D, [2018-12-24T10:04:45.255270 #17199] DEBUG -- :   ↳ ee/lib/ee/gitlab/external_authorization/config.rb:16:in `enabled?'
    D, [2018-12-24T10:04:45.255447 #17199] DEBUG -- :   ↳ ee/lib/ee/gitlab/external_authorization/config.rb:20:in `perform_check?'
    D, [2018-12-24T10:04:45.255594 #17199] DEBUG -- :   ↳ ee/app/policies/ee/base_policy.rb:9:in `block (2 levels) in <module:BasePolicy>'
    D, [2018-12-24T10:04:45.255750 #17199] DEBUG -- :   ↳ lib/declarative_policy/condition.rb:23:in `instance_eval'
    D, [2018-12-24T10:04:45.255902 #17199] DEBUG -- :   ↳ lib/declarative_policy/condition.rb:23:in `compute'
    D, [2018-12-24T10:04:45.256113 #17199] DEBUG -- :   ↳ lib/declarative_policy/condition.rb:44:in `block in pass?'
    D, [2018-12-24T10:04:45.256263 #17199] DEBUG -- :   ↳ lib/declarative_policy/base.rb:282:in `cache'
    D, [2018-12-24T10:04:45.256424 #17199] DEBUG -- :   ↳ lib/declarative_policy/condition.rb:44:in `pass?'
    D, [2018-12-24T10:04:45.256603 #17199] DEBUG -- :   ↳ lib/declarative_policy/rule.rb:81:in `pass?'
    D, [2018-12-24T10:04:45.256752 #17199] DEBUG -- :   ↳ lib/declarative_policy/rule.rb:211:in `block in pass?'
    D, [2018-12-24T10:04:45.256931 #17199] DEBUG -- :   ↳ lib/declarative_policy/rule.rb:211:in `each'
    D, [2018-12-24T10:04:45.257101 #17199] DEBUG -- :   ↳ lib/declarative_policy/rule.rb:211:in `all?'
    D, [2018-12-24T10:04:45.257275 #17199] DEBUG -- :   ↳ lib/declarative_policy/rule.rb:211:in `pass?'
    D, [2018-12-24T10:04:45.257435 #17199] DEBUG -- :   ↳ lib/declarative_policy/step.rb:81:in `pass?'
    D, [2018-12-24T10:04:45.257612 #17199] DEBUG -- :   ↳ lib/declarative_policy/runner.rb:100:in `block in run'
    D, [2018-12-24T10:04:45.257765 #17199] DEBUG -- :   ↳ lib/declarative_policy/runner.rb:179:in `block in steps_by_score'
    D, [2018-12-24T10:04:45.257908 #17199] DEBUG -- :   ↳ lib/declarative_policy/runner.rb:148:in `loop'
    D, [2018-12-24T10:04:45.258074 #17199] DEBUG -- :   ↳ lib/declarative_policy/runner.rb:148:in `steps_by_score'
    D, [2018-12-24T10:04:45.258226 #17199] DEBUG -- :   ↳ lib/declarative_policy/runner.rb:81:in `run'
    D, [2018-12-24T10:04:45.258387 #17199] DEBUG -- :   ↳ lib/declarative_policy/runner.rb:59:in `pass?'
    D, [2018-12-24T10:04:45.258528 #17199] DEBUG -- :   ↳ lib/declarative_policy/base.rb:217:in `block in allowed?'
    D, [2018-12-24T10:04:45.258680 #17199] DEBUG -- :   ↳ lib/declarative_policy/base.rb:217:in `each'
    D, [2018-12-24T10:04:45.258831 #17199] DEBUG -- :   ↳ lib/declarative_policy/base.rb:217:in `all?'
    D, [2018-12-24T10:04:45.258974 #17199] DEBUG -- :   ↳ lib/declarative_policy/base.rb:217:in `allowed?'
    D, [2018-12-24T10:04:45.259139 #17199] DEBUG -- :   ↳ lib/declarative_policy/base.rb:209:in `can?'
    D, [2018-12-24T10:04:45.259278 #17199] DEBUG -- :   ↳ app/models/ability.rb:72:in `allowed?'
    D, [2018-12-24T10:04:45.259501 #17199] DEBUG -- :   ↳ app/controllers/application_controller.rb:183:in `can?'
    D, [2018-12-24T10:04:45.259654 #17199] DEBUG -- :   ↳ app/controllers/concerns/controller_with_cross_project_access_check.rb:18:in `authorize_cross_project_page!'
    D, [2018-12-24T10:04:45.259796 #17199] DEBUG -- :   ↳ app/controllers/concerns/controller_with_cross_project_access_check.rb:13:in `cross_project_check'
    D, [2018-12-24T10:04:45.259969 #17199] DEBUG -- :   ↳ app/controllers/application_controller.rb:428:in `set_locale'
    D, [2018-12-24T10:04:45.260132 #17199] DEBUG -- :   ↳ ee/lib/omni_auth/strategies/group_saml.rb:33:in `other_phase'
    D, [2018-12-24T10:04:45.260295 #17199] DEBUG -- :   ↳ ee/lib/gitlab/jira/middleware.rb:15:in `call'
    D, [2018-12-24T10:04:45.260471 #17199] DEBUG -- :   ↳ lib/gitlab/correlation_id.rb:15:in `use_id'
    D, [2018-12-24T10:04:45.260616 #17199] DEBUG -- :   ↳ (irb):48:in `irb_binding'
    D, [2018-12-24T10:04:45.265577 #17199] DEBUG -- :    (1.4ms)  SELECT "features"."key" FROM "features"
    D, [2018-12-24T10:04:45.270783 #17199] DEBUG -- :   ↳ lib/feature.rb:15:in `feature_names'
    D, [2018-12-24T10:04:45.271140 #17199] DEBUG -- :   ↳ lib/feature.rb:35:in `persisted_names'
    D, [2018-12-24T10:04:45.271307 #17199] DEBUG -- :   ↳ lib/feature.rb:42:in `persisted?'
    D, [2018-12-24T10:04:45.271472 #17199] DEBUG -- :   ↳ lib/feature.rb:54:in `enabled?'
    D, [2018-12-24T10:04:45.271622 #17199] DEBUG -- :   ↳ ee/app/models/license.rb:308:in `feature_available?'
    D, [2018-12-24T10:04:45.271763 #17199] DEBUG -- :   ↳ ee/app/models/license.rb:218:in `feature_available?'
    D, [2018-12-24T10:04:45.271962 #17199] DEBUG -- :   ↳ ee/app/models/ee/application_setting.rb:180:in `external_authorization_service_enabled'
    D, [2018-12-24T10:04:45.272133 #17199] DEBUG -- :   ↳ ee/lib/ee/gitlab/external_authorization/config.rb:16:in `enabled?'
    D, [2018-12-24T10:04:45.272288 #17199] DEBUG -- :   ↳ ee/lib/ee/gitlab/external_authorization/config.rb:20:in `perform_check?'
    D, [2018-12-24T10:04:45.272470 #17199] DEBUG -- :   ↳ ee/app/policies/ee/base_policy.rb:9:in `block (2 levels) in <module:BasePolicy>'
    D, [2018-12-24T10:04:45.272674 #17199] DEBUG -- :   ↳ lib/declarative_policy/condition.rb:23:in `instance_eval'
    D, [2018-12-24T10:04:45.272855 #17199] DEBUG -- :   ↳ lib/declarative_policy/condition.rb:23:in `compute'
    D, [2018-12-24T10:04:45.273003 #17199] DEBUG -- :   ↳ lib/declarative_policy/condition.rb:44:in `block in pass?'
    D, [2018-12-24T10:04:45.273167 #17199] DEBUG -- :   ↳ lib/declarative_policy/base.rb:282:in `cache'
    D, [2018-12-24T10:04:45.273320 #17199] DEBUG -- :   ↳ lib/declarative_policy/condition.rb:44:in `pass?'
    D, [2018-12-24T10:04:45.273498 #17199] DEBUG -- :   ↳ lib/declarative_policy/rule.rb:81:in `pass?'
    D, [2018-12-24T10:04:45.273682 #17199] DEBUG -- :   ↳ lib/declarative_policy/rule.rb:211:in `block in pass?'
    D, [2018-12-24T10:04:45.273847 #17199] DEBUG -- :   ↳ lib/declarative_policy/rule.rb:211:in `each'
    D, [2018-12-24T10:04:45.273986 #17199] DEBUG -- :   ↳ lib/declarative_policy/rule.rb:211:in `all?'
    D, [2018-12-24T10:04:45.274175 #17199] DEBUG -- :   ↳ lib/declarative_policy/rule.rb:211:in `pass?'
    D, [2018-12-24T10:04:45.274348 #17199] DEBUG -- :   ↳ lib/declarative_policy/step.rb:81:in `pass?'
    D, [2018-12-24T10:04:45.274516 #17199] DEBUG -- :   ↳ lib/declarative_policy/runner.rb:100:in `block in run'
    D, [2018-12-24T10:04:45.274661 #17199] DEBUG -- :   ↳ lib/declarative_policy/runner.rb:179:in `block in steps_by_score'
    D, [2018-12-24T10:04:45.274802 #17199] DEBUG -- :   ↳ lib/declarative_policy/runner.rb:148:in `loop'
    D, [2018-12-24T10:04:45.274955 #17199] DEBUG -- :   ↳ lib/declarative_policy/runner.rb:148:in `steps_by_score'
    D, [2018-12-24T10:04:45.275132 #17199] DEBUG -- :   ↳ lib/declarative_policy/runner.rb:81:in `run'
    D, [2018-12-24T10:04:45.275289 #17199] DEBUG -- :   ↳ lib/declarative_policy/runner.rb:59:in `pass?'
    D, [2018-12-24T10:04:45.275449 #17199] DEBUG -- :   ↳ lib/declarative_policy/base.rb:217:in `block in allowed?'
    D, [2018-12-24T10:04:45.275594 #17199] DEBUG -- :   ↳ lib/declarative_policy/base.rb:217:in `each'
    D, [2018-12-24T10:04:45.275741 #17199] DEBUG -- :   ↳ lib/declarative_policy/base.rb:217:in `all?'
    D, [2018-12-24T10:04:45.275970 #17199] DEBUG -- :   ↳ lib/declarative_policy/base.rb:217:in `allowed?'
    D, [2018-12-24T10:04:45.276141 #17199] DEBUG -- :   ↳ lib/declarative_policy/base.rb:209:in `can?'
    D, [2018-12-24T10:04:45.276306 #17199] DEBUG -- :   ↳ app/models/ability.rb:72:in `allowed?'
    D, [2018-12-24T10:04:45.276509 #17199] DEBUG -- :   ↳ app/controllers/application_controller.rb:183:in `can?'
    D, [2018-12-24T10:04:45.276668 #17199] DEBUG -- :   ↳ app/controllers/concerns/controller_with_cross_project_access_check.rb:18:in `authorize_cross_project_page!'
    D, [2018-12-24T10:04:45.276814 #17199] DEBUG -- :   ↳ app/controllers/concerns/controller_with_cross_project_access_check.rb:13:in `cross_project_check'
    D, [2018-12-24T10:04:45.276961 #17199] DEBUG -- :   ↳ app/controllers/application_controller.rb:428:in `set_locale'
    D, [2018-12-24T10:04:45.277135 #17199] DEBUG -- :   ↳ ee/lib/omni_auth/strategies/group_saml.rb:33:in `other_phase'
    D, [2018-12-24T10:04:45.277303 #17199] DEBUG -- :   ↳ ee/lib/gitlab/jira/middleware.rb:15:in `call'
    D, [2018-12-24T10:04:45.277460 #17199] DEBUG -- :   ↳ lib/gitlab/correlation_id.rb:15:in `use_id'
    D, [2018-12-24T10:04:45.277671 #17199] DEBUG -- :   ↳ (irb):48:in `irb_binding'
    D, [2018-12-24T10:04:59.991541 #17199] DEBUG -- :    (14500.4ms)  SELECT COUNT(*) FROM (SELECT "snippets".* FROM "snippets" WHERE (snippets.visibility_level IN (10,20) OR snippets.author_id = 443319) AND "snippets"."project_id" IS NULL
    UNION
    SELECT "snippets".* FROM "snippets" INNER JOIN "projects" ON "projects"."id" = "snippets"."project_id" INNER JOIN "project_features" ON "project_features"."project_id" = "projects"."id" WHERE (snippets.visibility_level IN (10,20) OR snippets.author_id = 443319) AND (projects.visibility_level IN (10,20)) AND "project_features"."snippets_access_level" IN (20, 30)
    UNION
    SELECT "snippets".* FROM "snippets" INNER JOIN "projects" ON "projects"."id" = "snippets"."project_id" INNER JOIN "project_features" ON "project_features"."project_id" = "projects"."id" WHERE "project_features"."snippets_access_level" IN (20, 30, 10) AND (EXISTS (SELECT 1 FROM "project_authorizations" WHERE (project_id = snippets.project_id) AND "project_authorizations"."user_id" = 443319))) snippets WHERE ("snippets"."content" ILIKE '%foo%')
    D, [2018-12-24T10:04:59.996202 #17199] DEBUG -- :   ↳ lib/gitlab/snippet_search_results.rb:30:in `snippet_blobs_count'
    D, [2018-12-24T10:04:59.996565 #17199] DEBUG -- :   ↳ app/views/search/_category.html.haml:54:in `block in _app_views_search__category_html_haml___3677121854433339619_70066264674160'
    D, [2018-12-24T10:04:59.996721 #17199] DEBUG -- :   ↳ app/views/search/_category.html.haml:51:in `_app_views_search__category_html_haml___3677121854433339619_70066264674160'
    D, [2018-12-24T10:04:59.996885 #17199] DEBUG -- :   ↳ app/views/search/show.html.haml:8:in `_app_views_search_show_html_haml___3699216624438440937_70066274144220'
    D, [2018-12-24T10:04:59.997083 #17199] DEBUG -- :   ↳ app/controllers/application_controller.rb:116:in `render'
    D, [2018-12-24T10:04:59.997236 #17199] DEBUG -- :   ↳ app/controllers/application_controller.rb:428:in `set_locale'
    D, [2018-12-24T10:04:59.997402 #17199] DEBUG -- :   ↳ ee/lib/omni_auth/strategies/group_saml.rb:33:in `other_phase'
    D, [2018-12-24T10:04:59.997557 #17199] DEBUG -- :   ↳ ee/lib/gitlab/jira/middleware.rb:15:in `call'
    D, [2018-12-24T10:04:59.997704 #17199] DEBUG -- :   ↳ lib/gitlab/correlation_id.rb:15:in `use_id'
    D, [2018-12-24T10:04:59.997852 #17199] DEBUG -- :   ↳ (irb):48:in `irb_binding'
    D, [2018-12-24T10:05:00.112629 #17199] DEBUG -- :    (111.0ms)  SELECT COUNT(*) FROM (SELECT "snippets".* FROM "snippets" WHERE (snippets.visibility_level IN (10,20) OR snippets.author_id = 443319) AND "snippets"."project_id" IS NULL
    UNION
    SELECT "snippets".* FROM "snippets" INNER JOIN "projects" ON "projects"."id" = "snippets"."project_id" INNER JOIN "project_features" ON "project_features"."project_id" = "projects"."id" WHERE (snippets.visibility_level IN (10,20) OR snippets.author_id = 443319) AND (projects.visibility_level IN (10,20)) AND "project_features"."snippets_access_level" IN (20, 30)
    UNION
    SELECT "snippets".* FROM "snippets" INNER JOIN "projects" ON "projects"."id" = "snippets"."project_id" INNER JOIN "project_features" ON "project_features"."project_id" = "projects"."id" WHERE "project_features"."snippets_access_level" IN (20, 30, 10) AND (EXISTS (SELECT 1 FROM "project_authorizations" WHERE (project_id = snippets.project_id) AND "project_authorizations"."user_id" = 443319))) snippets WHERE ("snippets"."title" ILIKE '%foo%' OR "snippets"."file_name" ILIKE '%foo%')
    D, [2018-12-24T10:05:00.117264 #17199] DEBUG -- :   ↳ lib/gitlab/snippet_search_results.rb:26:in `snippet_titles_count'
    D, [2018-12-24T10:05:00.117639 #17199] DEBUG -- :   ↳ app/views/search/_category.html.haml:59:in `block in _app_views_search__category_html_haml___3677121854433339619_70066264674160'
    D, [2018-12-24T10:05:00.117811 #17199] DEBUG -- :   ↳ app/views/search/_category.html.haml:56:in `_app_views_search__category_html_haml___3677121854433339619_70066264674160'
    D, [2018-12-24T10:05:00.117966 #17199] DEBUG -- :   ↳ app/views/search/show.html.haml:8:in `_app_views_search_show_html_haml___3699216624438440937_70066274144220'
    D, [2018-12-24T10:05:00.118142 #17199] DEBUG -- :   ↳ app/controllers/application_controller.rb:116:in `render'
    D, [2018-12-24T10:05:00.118288 #17199] DEBUG -- :   ↳ app/controllers/application_controller.rb:428:in `set_locale'
    D, [2018-12-24T10:05:00.118442 #17199] DEBUG -- :   ↳ ee/lib/omni_auth/strategies/group_saml.rb:33:in `other_phase'
    D, [2018-12-24T10:05:00.118615 #17199] DEBUG -- :   ↳ ee/lib/gitlab/jira/middleware.rb:15:in `call'
    D, [2018-12-24T10:05:00.118762 #17199] DEBUG -- :   ↳ lib/gitlab/correlation_id.rb:15:in `use_id'
    D, [2018-12-24T10:05:00.118916 #17199] DEBUG -- :   ↳ (irb):48:in `irb_binding'
    D, [2018-12-24T10:05:10.504349 #17199] DEBUG -- :    (10350.4ms)  SELECT COUNT(count_column) FROM (SELECT  1 AS count_column FROM (SELECT "snippets".* FROM "snippets" WHERE (snippets.visibility_level IN (10,20) OR snippets.author_id = 443319) AND "snippets"."project_id" IS NULL
    UNION
    SELECT "snippets".* FROM "snippets" INNER JOIN "projects" ON "projects"."id" = "snippets"."project_id" INNER JOIN "project_features" ON "project_features"."project_id" = "projects"."id" WHERE (snippets.visibility_level IN (10,20) OR snippets.author_id = 443319) AND (projects.visibility_level IN (10,20)) AND "project_features"."snippets_access_level" IN (20, 30)
    UNION
    SELECT "snippets".* FROM "snippets" INNER JOIN "projects" ON "projects"."id" = "snippets"."project_id" INNER JOIN "project_features" ON "project_features"."project_id" = "projects"."id" WHERE "project_features"."snippets_access_level" IN (20, 30, 10) AND (EXISTS (SELECT 1 FROM "project_authorizations" WHERE (project_id = snippets.project_id) AND "project_authorizations"."user_id" = 443319))) snippets WHERE ("snippets"."content" ILIKE '%foo%') LIMIT 20 OFFSET 0) subquery_for_count
    D, [2018-12-24T10:05:10.508655 #17199] DEBUG -- :   ↳ app/views/search/_results.html.haml:1:in `_app_views_search__results_html_haml__1710043260050147053_70066258712080'
    D, [2018-12-24T10:05:10.508874 #17199] DEBUG -- :   ↳ app/views/search/show.html.haml:9:in `_app_views_search_show_html_haml___3699216624438440937_70066274144220'
    D, [2018-12-24T10:05:10.509035 #17199] DEBUG -- :   ↳ app/controllers/application_controller.rb:116:in `render'
    D, [2018-12-24T10:05:10.509196 #17199] DEBUG -- :   ↳ app/controllers/application_controller.rb:428:in `set_locale'
    D, [2018-12-24T10:05:10.509371 #17199] DEBUG -- :   ↳ ee/lib/omni_auth/strategies/group_saml.rb:33:in `other_phase'
    D, [2018-12-24T10:05:10.509546 #17199] DEBUG -- :   ↳ ee/lib/gitlab/jira/middleware.rb:15:in `call'
    D, [2018-12-24T10:05:10.509692 #17199] DEBUG -- :   ↳ lib/gitlab/correlation_id.rb:15:in `use_id'
    D, [2018-12-24T10:05:10.509840 #17199] DEBUG -- :   ↳ (irb):48:in `irb_binding'
    D, [2018-12-24T10:05:20.933940 #17199] DEBUG -- :   Snippet Load (10422.0ms)  SELECT  "snippets".* FROM (SELECT "snippets".* FROM "snippets" WHERE (snippets.visibility_level IN (10,20) OR snippets.author_id = 443319) AND "snippets"."project_id" IS NULL
    UNION
    SELECT "snippets".* FROM "snippets" INNER JOIN "projects" ON "projects"."id" = "snippets"."project_id" INNER JOIN "project_features" ON "project_features"."project_id" = "projects"."id" WHERE (snippets.visibility_level IN (10,20) OR snippets.author_id = 443319) AND (projects.visibility_level IN (10,20)) AND "project_features"."snippets_access_level" IN (20, 30)
    UNION
    SELECT "snippets".* FROM "snippets" INNER JOIN "projects" ON "projects"."id" = "snippets"."project_id" INNER JOIN "project_features" ON "project_features"."project_id" = "projects"."id" WHERE "project_features"."snippets_access_level" IN (20, 30, 10) AND (EXISTS (SELECT 1 FROM "project_authorizations" WHERE (project_id = snippets.project_id) AND "project_authorizations"."user_id" = 443319))) snippets WHERE ("snippets"."content" ILIKE '%foo%') ORDER BY created_at DESC, updated_at DESC LIMIT 20 OFFSET 0
    D, [2018-12-24T10:05:20.938722 #17199] DEBUG -- :   ↳ (irb):38:in `search_entries_info'
    D, [2018-12-24T10:05:20.939032 #17199] DEBUG -- :   ↳ app/views/search/_results.html.haml:7:in `_app_views_search__results_html_haml__1710043260050147053_70066258712080'
    D, [2018-12-24T10:05:20.939222 #17199] DEBUG -- :   ↳ app/views/search/show.html.haml:9:in `_app_views_search_show_html_haml___3699216624438440937_70066274144220'
    D, [2018-12-24T10:05:20.939372 #17199] DEBUG -- :   ↳ app/controllers/application_controller.rb:116:in `render'
    D, [2018-12-24T10:05:20.939535 #17199] DEBUG -- :   ↳ app/controllers/application_controller.rb:428:in `set_locale'
    D, [2018-12-24T10:05:20.939686 #17199] DEBUG -- :   ↳ ee/lib/omni_auth/strategies/group_saml.rb:33:in `other_phase'
    D, [2018-12-24T10:05:20.939850 #17199] DEBUG -- :   ↳ ee/lib/gitlab/jira/middleware.rb:15:in `call'
    D, [2018-12-24T10:05:20.940026 #17199] DEBUG -- :   ↳ lib/gitlab/correlation_id.rb:15:in `use_id'
    D, [2018-12-24T10:05:20.940196 #17199] DEBUG -- :   ↳ (irb):48:in `irb_binding'
    D, [2018-12-24T10:05:21.038549 #17199] DEBUG -- :   User Load (5.4ms)  SELECT "users".* FROM "users" WHERE "users"."id" IN (443319, 726421, 829774)
    D, [2018-12-24T10:05:21.042794 #17199] DEBUG -- :   ↳ (irb):38:in `search_entries_info'
    D, [2018-12-24T10:05:21.043089 #17199] DEBUG -- :   ↳ app/views/search/_results.html.haml:7:in `_app_views_search__results_html_haml__1710043260050147053_70066258712080'
    D, [2018-12-24T10:05:21.043251 #17199] DEBUG -- :   ↳ app/views/search/show.html.haml:9:in `_app_views_search_show_html_haml___3699216624438440937_70066274144220'
    D, [2018-12-24T10:05:21.043409 #17199] DEBUG -- :   ↳ app/controllers/application_controller.rb:116:in `render'
    D, [2018-12-24T10:05:21.043581 #17199] DEBUG -- :   ↳ app/controllers/application_controller.rb:428:in `set_locale'
    D, [2018-12-24T10:05:21.043730 #17199] DEBUG -- :   ↳ ee/lib/omni_auth/strategies/group_saml.rb:33:in `other_phase'
    D, [2018-12-24T10:05:21.043881 #17199] DEBUG -- :   ↳ ee/lib/gitlab/jira/middleware.rb:15:in `call'
    D, [2018-12-24T10:05:21.044080 #17199] DEBUG -- :   ↳ lib/gitlab/correlation_id.rb:15:in `use_id'
    D, [2018-12-24T10:05:21.044226 #17199] DEBUG -- :   ↳ (irb):48:in `irb_binding'
    D, [2018-12-24T10:05:21.070622 #17199] DEBUG -- :   User Load (20.0ms)  SELECT "users".* FROM "users" WHERE "users"."id" IN (727859, 1656227, 720526, 1315003, 1542438, 832912, 552560, 670452, 892863, 1479830, 409720, 1402582, 440064, 340637)
    D, [2018-12-24T10:05:21.074956 #17199] DEBUG -- :   ↳ (irb):38:in `search_entries_info'
    D, [2018-12-24T10:05:21.075253 #17199] DEBUG -- :   ↳ app/views/search/_results.html.haml:7:in `_app_views_search__results_html_haml__1710043260050147053_70066258712080'
    D, [2018-12-24T10:05:21.075430 #17199] DEBUG -- :   ↳ app/views/search/show.html.haml:9:in `_app_views_search_show_html_haml___3699216624438440937_70066274144220'
    D, [2018-12-24T10:05:21.075600 #17199] DEBUG -- :   ↳ app/controllers/application_controller.rb:116:in `render'
    D, [2018-12-24T10:05:21.075744 #17199] DEBUG -- :   ↳ app/controllers/application_controller.rb:428:in `set_locale'
    D, [2018-12-24T10:05:21.075906 #17199] DEBUG -- :   ↳ ee/lib/omni_auth/strategies/group_saml.rb:33:in `other_phase'
    D, [2018-12-24T10:05:21.076124 #17199] DEBUG -- :   ↳ ee/lib/gitlab/jira/middleware.rb:15:in `call'
    D, [2018-12-24T10:05:21.076346 #17199] DEBUG -- :   ↳ lib/gitlab/correlation_id.rb:15:in `use_id'
    D, [2018-12-24T10:05:21.076504 #17199] DEBUG -- :   ↳ (irb):48:in `irb_binding'
    D, [2018-12-24T10:05:31.508449 #17199] DEBUG -- :    (10422.5ms)  SELECT COUNT(*) FROM (SELECT "snippets".* FROM "snippets" WHERE (snippets.visibility_level IN (10,20) OR snippets.author_id = 443319) AND "snippets"."project_id" IS NULL
    UNION
    SELECT "snippets".* FROM "snippets" INNER JOIN "projects" ON "projects"."id" = "snippets"."project_id" INNER JOIN "project_features" ON "project_features"."project_id" = "projects"."id" WHERE (snippets.visibility_level IN (10,20) OR snippets.author_id = 443319) AND (projects.visibility_level IN (10,20)) AND "project_features"."snippets_access_level" IN (20, 30)
    UNION
    SELECT "snippets".* FROM "snippets" INNER JOIN "projects" ON "projects"."id" = "snippets"."project_id" INNER JOIN "project_features" ON "project_features"."project_id" = "projects"."id" WHERE "project_features"."snippets_access_level" IN (20, 30, 10) AND (EXISTS (SELECT 1 FROM "project_authorizations" WHERE (project_id = snippets.project_id) AND "project_authorizations"."user_id" = 443319))) snippets WHERE ("snippets"."content" ILIKE '%foo%')
    D, [2018-12-24T10:05:31.512832 #17199] DEBUG -- :   ↳ (irb):42:in `search_entries_info'
    D, [2018-12-24T10:05:31.513075 #17199] DEBUG -- :   ↳ app/views/search/_results.html.haml:7:in `_app_views_search__results_html_haml__1710043260050147053_70066258712080'
    D, [2018-12-24T10:05:31.513261 #17199] DEBUG -- :   ↳ app/views/search/show.html.haml:9:in `_app_views_search_show_html_haml___3699216624438440937_70066274144220'
    D, [2018-12-24T10:05:31.513444 #17199] DEBUG -- :   ↳ app/controllers/application_controller.rb:116:in `render'
    D, [2018-12-24T10:05:31.513619 #17199] DEBUG -- :   ↳ app/controllers/application_controller.rb:428:in `set_locale'
    D, [2018-12-24T10:05:31.513766 #17199] DEBUG -- :   ↳ ee/lib/omni_auth/strategies/group_saml.rb:33:in `other_phase'
    D, [2018-12-24T10:05:31.513917 #17199] DEBUG -- :   ↳ ee/lib/gitlab/jira/middleware.rb:15:in `call'
    D, [2018-12-24T10:05:31.514087 #17199] DEBUG -- :   ↳ lib/gitlab/correlation_id.rb:15:in `use_id'
    D, [2018-12-24T10:05:31.514241 #17199] DEBUG -- :   ↳ (irb):48:in `irb_binding'
    D, [2018-12-24T10:05:31.586656 #17199] DEBUG -- :   Project Load (3.0ms)  SELECT  "projects".* FROM "projects" WHERE "projects"."id" = 13083 LIMIT 1
    D, [2018-12-24T10:05:31.590940 #17199] DEBUG -- :   ↳ app/helpers/snippets_helper.rb:6:in `reliable_snippet_path'
    D, [2018-12-24T10:05:31.591231 #17199] DEBUG -- :   ↳ app/views/search/results/_snippet_blob.html.haml:14:in `_app_views_search_results__snippet_blob_html_haml__761421932838641359_70066218636360'
    D, [2018-12-24T10:05:31.591414 #17199] DEBUG -- :   ↳ app/views/search/_results.html.haml:24:in `_app_views_search__results_html_haml__1710043260050147053_70066258712080'
    D, [2018-12-24T10:05:31.591587 #17199] DEBUG -- :   ↳ app/views/search/show.html.haml:9:in `_app_views_search_show_html_haml___3699216624438440937_70066274144220'
    D, [2018-12-24T10:05:31.591740 #17199] DEBUG -- :   ↳ app/controllers/application_controller.rb:116:in `render'
    D, [2018-12-24T10:05:31.591895 #17199] DEBUG -- :   ↳ app/controllers/application_controller.rb:428:in `set_locale'
    D, [2018-12-24T10:05:31.592113 #17199] DEBUG -- :   ↳ ee/lib/omni_auth/strategies/group_saml.rb:33:in `other_phase'
    D, [2018-12-24T10:05:31.592271 #17199] DEBUG -- :   ↳ ee/lib/gitlab/jira/middleware.rb:15:in `call'
    D, [2018-12-24T10:05:31.592419 #17199] DEBUG -- :   ↳ lib/gitlab/correlation_id.rb:15:in `use_id'
    D, [2018-12-24T10:05:31.592599 #17199] DEBUG -- :   ↳ (irb):48:in `irb_binding'
    D, [2018-12-24T10:05:31.668902 #17199] DEBUG -- :   Namespace Load (2.6ms)  SELECT  "namespaces".* FROM "namespaces" WHERE "namespaces"."id" = 9970 LIMIT 1
    D, [2018-12-24T10:05:31.673527 #17199] DEBUG -- :   ↳ config/application.rb:270:in `block (4 levels) in <class:Application>'
    D, [2018-12-24T10:05:31.673798 #17199] DEBUG -- :   ↳ app/helpers/snippets_helper.rb:6:in `reliable_snippet_path'
    D, [2018-12-24T10:05:31.673958 #17199] DEBUG -- :   ↳ app/views/search/results/_snippet_blob.html.haml:14:in `_app_views_search_results__snippet_blob_html_haml__761421932838641359_70066218636360'
    D, [2018-12-24T10:05:31.674135 #17199] DEBUG -- :   ↳ app/views/search/_results.html.haml:24:in `_app_views_search__results_html_haml__1710043260050147053_70066258712080'
    D, [2018-12-24T10:05:31.674292 #17199] DEBUG -- :   ↳ app/views/search/show.html.haml:9:in `_app_views_search_show_html_haml___3699216624438440937_70066274144220'
    D, [2018-12-24T10:05:31.674443 #17199] DEBUG -- :   ↳ app/controllers/application_controller.rb:116:in `render'
    D, [2018-12-24T10:05:31.674608 #17199] DEBUG -- :   ↳ app/controllers/application_controller.rb:428:in `set_locale'
    D, [2018-12-24T10:05:31.674760 #17199] DEBUG -- :   ↳ ee/lib/omni_auth/strategies/group_saml.rb:33:in `other_phase'
    D, [2018-12-24T10:05:31.674900 #17199] DEBUG -- :   ↳ ee/lib/gitlab/jira/middleware.rb:15:in `call'
    D, [2018-12-24T10:05:31.675068 #17199] DEBUG -- :   ↳ lib/gitlab/correlation_id.rb:15:in `use_id'
    D, [2018-12-24T10:05:31.675221 #17199] DEBUG -- :   ↳ (irb):48:in `irb_binding'
    D, [2018-12-24T10:05:31.740906 #17199] DEBUG -- :   Route Load (2.1ms)  SELECT  "routes".* FROM "routes" WHERE "routes"."source_id" = 9970 AND "routes"."source_type" = 'Namespace' LIMIT 1
    D, [2018-12-24T10:05:31.745645 #17199] DEBUG -- :   ↳ app/models/concerns/routable.rb:99:in `full_path'
    D, [2018-12-24T10:05:31.745975 #17199] DEBUG -- :   ↳ app/models/namespace.rb:126:in `to_param'
    D, [2018-12-24T10:05:31.746166 #17199] DEBUG -- :   ↳ config/application.rb:270:in `block (4 levels) in <class:Application>'
    D, [2018-12-24T10:05:31.746321 #17199] DEBUG -- :   ↳ app/helpers/snippets_helper.rb:6:in `reliable_snippet_path'
    D, [2018-12-24T10:05:31.746489 #17199] DEBUG -- :   ↳ app/views/search/results/_snippet_blob.html.haml:14:in `_app_views_search_results__snippet_blob_html_haml__761421932838641359_70066218636360'
    D, [2018-12-24T10:05:31.746643 #17199] DEBUG -- :   ↳ app/views/search/_results.html.haml:24:in `_app_views_search__results_html_haml__1710043260050147053_70066258712080'
    D, [2018-12-24T10:05:31.746796 #17199] DEBUG -- :   ↳ app/views/search/show.html.haml:9:in `_app_views_search_show_html_haml___3699216624438440937_70066274144220'
    D, [2018-12-24T10:05:31.746947 #17199] DEBUG -- :   ↳ app/controllers/application_controller.rb:116:in `render'
    D, [2018-12-24T10:05:31.747116 #17199] DEBUG -- :   ↳ app/controllers/application_controller.rb:428:in `set_locale'
    D, [2018-12-24T10:05:31.747265 #17199] DEBUG -- :   ↳ ee/lib/omni_auth/strategies/group_saml.rb:33:in `other_phase'
    D, [2018-12-24T10:05:31.747412 #17199] DEBUG -- :   ↳ ee/lib/gitlab/jira/middleware.rb:15:in `call'
    D, [2018-12-24T10:05:31.747575 #17199] DEBUG -- :   ↳ lib/gitlab/correlation_id.rb:15:in `use_id'
    D, [2018-12-24T10:05:31.747726 #17199] DEBUG -- :   ↳ (irb):48:in `irb_binding'
    D, [2018-12-24T10:05:31.768525 #17199] DEBUG -- :   Project Load (1.9ms)  SELECT  "projects".* FROM "projects" WHERE "projects"."id" = 4063376 LIMIT 1
    D, [2018-12-24T10:05:31.772796 #17199] DEBUG -- :   ↳ app/helpers/snippets_helper.rb:6:in `reliable_snippet_path'
    D, [2018-12-24T10:05:31.773103 #17199] DEBUG -- :   ↳ app/views/search/results/_snippet_blob.html.haml:14:in `_app_views_search_results__snippet_blob_html_haml__761421932838641359_70066218636360'
    D, [2018-12-24T10:05:31.773274 #17199] DEBUG -- :   ↳ app/views/search/_results.html.haml:24:in `_app_views_search__results_html_haml__1710043260050147053_70066258712080'
    D, [2018-12-24T10:05:31.773443 #17199] DEBUG -- :   ↳ app/views/search/show.html.haml:9:in `_app_views_search_show_html_haml___3699216624438440937_70066274144220'
    D, [2018-12-24T10:05:31.773597 #17199] DEBUG -- :   ↳ app/controllers/application_controller.rb:116:in `render'
    D, [2018-12-24T10:05:31.773751 #17199] DEBUG -- :   ↳ app/controllers/application_controller.rb:428:in `set_locale'
    D, [2018-12-24T10:05:31.773902 #17199] DEBUG -- :   ↳ ee/lib/omni_auth/strategies/group_saml.rb:33:in `other_phase'
    D, [2018-12-24T10:05:31.774047 #17199] DEBUG -- :   ↳ ee/lib/gitlab/jira/middleware.rb:15:in `call'
    D, [2018-12-24T10:05:31.774214 #17199] DEBUG -- :   ↳ lib/gitlab/correlation_id.rb:15:in `use_id'
    D, [2018-12-24T10:05:31.774373 #17199] DEBUG -- :   ↳ (irb):48:in `irb_binding'
    D, [2018-12-24T10:05:31.780085 #17199] DEBUG -- :   Namespace Load (1.2ms)  SELECT  "namespaces".* FROM "namespaces" WHERE "namespaces"."id" = 1846145 LIMIT 1
    D, [2018-12-24T10:05:31.784543 #17199] DEBUG -- :   ↳ config/application.rb:270:in `block (4 levels) in <class:Application>'
    D, [2018-12-24T10:05:31.784802 #17199] DEBUG -- :   ↳ app/helpers/snippets_helper.rb:6:in `reliable_snippet_path'
    D, [2018-12-24T10:05:31.784965 #17199] DEBUG -- :   ↳ app/views/search/results/_snippet_blob.html.haml:14:in `_app_views_search_results__snippet_blob_html_haml__761421932838641359_70066218636360'
    D, [2018-12-24T10:05:31.785141 #17199] DEBUG -- :   ↳ app/views/search/_results.html.haml:24:in `_app_views_search__results_html_haml__1710043260050147053_70066258712080'
    D, [2018-12-24T10:05:31.785293 #17199] DEBUG -- :   ↳ app/views/search/show.html.haml:9:in `_app_views_search_show_html_haml___3699216624438440937_70066274144220'
    D, [2018-12-24T10:05:31.785453 #17199] DEBUG -- :   ↳ app/controllers/application_controller.rb:116:in `render'
    D, [2018-12-24T10:05:31.785615 #17199] DEBUG -- :   ↳ app/controllers/application_controller.rb:428:in `set_locale'
    D, [2018-12-24T10:05:31.785761 #17199] DEBUG -- :   ↳ ee/lib/omni_auth/strategies/group_saml.rb:33:in `other_phase'
    D, [2018-12-24T10:05:31.785907 #17199] DEBUG -- :   ↳ ee/lib/gitlab/jira/middleware.rb:15:in `call'
    D, [2018-12-24T10:05:31.786198 #17199] DEBUG -- :   ↳ lib/gitlab/correlation_id.rb:15:in `use_id'
    D, [2018-12-24T10:05:31.786388 #17199] DEBUG -- :   ↳ (irb):48:in `irb_binding'
    D, [2018-12-24T10:05:31.791565 #17199] DEBUG -- :   Route Load (1.0ms)  SELECT  "routes".* FROM "routes" WHERE "routes"."source_id" = 1846145 AND "routes"."source_type" = 'Namespace' LIMIT 1
    D, [2018-12-24T10:05:31.796175 #17199] DEBUG -- :   ↳ app/models/concerns/routable.rb:99:in `full_path'
    D, [2018-12-24T10:05:31.796441 #17199] DEBUG -- :   ↳ app/models/namespace.rb:126:in `to_param'
    D, [2018-12-24T10:05:31.796614 #17199] DEBUG -- :   ↳ config/application.rb:270:in `block (4 levels) in <class:Application>'
    D, [2018-12-24T10:05:31.796767 #17199] DEBUG -- :   ↳ app/helpers/snippets_helper.rb:6:in `reliable_snippet_path'
    D, [2018-12-24T10:05:31.796929 #17199] DEBUG -- :   ↳ app/views/search/results/_snippet_blob.html.haml:14:in `_app_views_search_results__snippet_blob_html_haml__761421932838641359_70066218636360'
    D, [2018-12-24T10:05:31.797106 #17199] DEBUG -- :   ↳ app/views/search/_results.html.haml:24:in `_app_views_search__results_html_haml__1710043260050147053_70066258712080'
    D, [2018-12-24T10:05:31.797264 #17199] DEBUG -- :   ↳ app/views/search/show.html.haml:9:in `_app_views_search_show_html_haml___3699216624438440937_70066274144220'
    D, [2018-12-24T10:05:31.797408 #17199] DEBUG -- :   ↳ app/controllers/application_controller.rb:116:in `render'
    D, [2018-12-24T10:05:31.797586 #17199] DEBUG -- :   ↳ app/controllers/application_controller.rb:428:in `set_locale'
    D, [2018-12-24T10:05:31.797735 #17199] DEBUG -- :   ↳ ee/lib/omni_auth/strategies/group_saml.rb:33:in `other_phase'
    D, [2018-12-24T10:05:31.797898 #17199] DEBUG -- :   ↳ ee/lib/gitlab/jira/middleware.rb:15:in `call'
    D, [2018-12-24T10:05:31.798082 #17199] DEBUG -- :   ↳ lib/gitlab/correlation_id.rb:15:in `use_id'
    D, [2018-12-24T10:05:31.798230 #17199] DEBUG -- :   ↳ (irb):48:in `irb_binding'
    D, [2018-12-24T10:05:31.861404 #17199] DEBUG -- :   Upload Load (16.7ms)  SELECT  "uploads".* FROM "uploads" WHERE "uploads"."uploader" = 'AvatarUploader' AND "uploads"."path" IN ('uploads/-/system/user/avatar/443319/avatar.png', 'user/avatar/443319/avatar.png', 'uploads/-/system/user/avatar/409720/avatar.png', 'user/avatar/409720/avatar.png', 'uploads/-/system/user/avatar/440064/avatar.png', 'user/avatar/440064/avatar.png', 'uploads/-/system/user/avatar/1315003/avatar.png', 'user/avatar/1315003/avatar.png', 'uploads/-/system/user/avatar/1402582/avatar.png', 'user/avatar/1402582/avatar.png', 'uploads/-/system/user/avatar/1479830/avatar.png', 'user/avatar/1479830/avatar.png') ORDER BY "uploads"."id" ASC LIMIT 1000
    D, [2018-12-24T10:05:31.866274 #17199] DEBUG -- :   ↳ app/models/concerns/avatarable.rb:89:in `block in retrieve_upload_from_batch'
    D, [2018-12-24T10:05:31.866640 #17199] DEBUG -- :   ↳ app/models/concerns/avatarable.rb:33:in `retrieve_upload'
    D, [2018-12-24T10:05:31.866804 #17199] DEBUG -- :   ↳ app/uploaders/object_storage.rb:49:in `retrieve_from_store!'
    D, [2018-12-24T10:05:31.866973 #17199] DEBUG -- :   ↳ app/models/concerns/avatarable.rb:71:in `avatar_path'
    D, [2018-12-24T10:05:31.867147 #17199] DEBUG -- :   ↳ app/models/concerns/avatarable.rb:24:in `avatar_url'
    D, [2018-12-24T10:05:31.867286 #17199] DEBUG -- :   ↳ app/helpers/avatars_helper.rb:35:in `avatar_icon_for_user'
    D, [2018-12-24T10:05:31.867584 #17199] DEBUG -- :   ↳ app/views/search/results/_snippet_blob.html.haml:10:in `block in _app_views_search_results__snippet_blob_html_haml__761421932838641359_70066218636360'
    D, [2018-12-24T10:05:31.867739 #17199] DEBUG -- :   ↳ app/views/search/results/_snippet_blob.html.haml:9:in `_app_views_search_results__snippet_blob_html_haml__761421932838641359_70066218636360'
    D, [2018-12-24T10:05:31.867997 #17199] DEBUG -- :   ↳ app/views/search/_results.html.haml:24:in `_app_views_search__results_html_haml__1710043260050147053_70066258712080'
    D, [2018-12-24T10:05:31.868166 #17199] DEBUG -- :   ↳ app/views/search/show.html.haml:9:in `_app_views_search_show_html_haml___3699216624438440937_70066274144220'
    D, [2018-12-24T10:05:31.868313 #17199] DEBUG -- :   ↳ app/controllers/application_controller.rb:116:in `render'
    D, [2018-12-24T10:05:31.868486 #17199] DEBUG -- :   ↳ app/controllers/application_controller.rb:428:in `set_locale'
    D, [2018-12-24T10:05:31.868637 #17199] DEBUG -- :   ↳ ee/lib/omni_auth/strategies/group_saml.rb:33:in `other_phase'
    D, [2018-12-24T10:05:31.868782 #17199] DEBUG -- :   ↳ ee/lib/gitlab/jira/middleware.rb:15:in `call'
    D, [2018-12-24T10:05:31.868933 #17199] DEBUG -- :   ↳ lib/gitlab/correlation_id.rb:15:in `use_id'
    D, [2018-12-24T10:05:31.869105 #17199] DEBUG -- :   ↳ (irb):48:in `irb_binding'
    D, [2018-12-24T10:05:32.098074 #17199] DEBUG -- :   Project Load (1.5ms)  SELECT  "projects".* FROM "projects" WHERE "projects"."id" = 7764 LIMIT 1
    D, [2018-12-24T10:05:32.105202 #17199] DEBUG -- :   ↳ app/helpers/snippets_helper.rb:6:in `reliable_snippet_path'
    D, [2018-12-24T10:05:32.105542 #17199] DEBUG -- :   ↳ app/views/search/results/_snippet_blob.html.haml:14:in `_app_views_search_results__snippet_blob_html_haml__761421932838641359_70066218636360'
    D, [2018-12-24T10:05:32.106559 #17199] DEBUG -- :   ↳ app/views/search/_results.html.haml:24:in `_app_views_search__results_html_haml__1710043260050147053_70066258712080'
    D, [2018-12-24T10:05:32.106725 #17199] DEBUG -- :   ↳ app/views/search/show.html.haml:9:in `_app_views_search_show_html_haml___3699216624438440937_70066274144220'
    D, [2018-12-24T10:05:32.106875 #17199] DEBUG -- :   ↳ app/controllers/application_controller.rb:116:in `render'
    D, [2018-12-24T10:05:32.107028 #17199] DEBUG -- :   ↳ app/controllers/application_controller.rb:428:in `set_locale'
    D, [2018-12-24T10:05:32.107198 #17199] DEBUG -- :   ↳ ee/lib/omni_auth/strategies/group_saml.rb:33:in `other_phase'
    D, [2018-12-24T10:05:32.107349 #17199] DEBUG -- :   ↳ ee/lib/gitlab/jira/middleware.rb:15:in `call'
    D, [2018-12-24T10:05:32.107512 #17199] DEBUG -- :   ↳ lib/gitlab/correlation_id.rb:15:in `use_id'
    D, [2018-12-24T10:05:32.107668 #17199] DEBUG -- :   ↳ (irb):48:in `irb_binding'
    D, [2018-12-24T10:05:32.114369 #17199] DEBUG -- :   Namespace Load (1.2ms)  SELECT  "namespaces".* FROM "namespaces" WHERE "namespaces"."id" = 6543 LIMIT 1
    D, [2018-12-24T10:05:32.122686 #17199] DEBUG -- :   ↳ config/application.rb:270:in `block (4 levels) in <class:Application>'
    D, [2018-12-24T10:05:32.122984 #17199] DEBUG -- :   ↳ app/helpers/snippets_helper.rb:6:in `reliable_snippet_path'
    D, [2018-12-24T10:05:32.123163 #17199] DEBUG -- :   ↳ app/views/search/results/_snippet_blob.html.haml:14:in `_app_views_search_results__snippet_blob_html_haml__761421932838641359_70066218636360'
    D, [2018-12-24T10:05:32.123316 #17199] DEBUG -- :   ↳ app/views/search/_results.html.haml:24:in `_app_views_search__results_html_haml__1710043260050147053_70066258712080'
    D, [2018-12-24T10:05:32.123477 #17199] DEBUG -- :   ↳ app/views/search/show.html.haml:9:in `_app_views_search_show_html_haml___3699216624438440937_70066274144220'
    D, [2018-12-24T10:05:32.123634 #17199] DEBUG -- :   ↳ app/controllers/application_controller.rb:116:in `render'
    D, [2018-12-24T10:05:32.123797 #17199] DEBUG -- :   ↳ app/controllers/application_controller.rb:428:in `set_locale'
    D, [2018-12-24T10:05:32.123975 #17199] DEBUG -- :   ↳ ee/lib/omni_auth/strategies/group_saml.rb:33:in `other_phase'
    D, [2018-12-24T10:05:32.124154 #17199] DEBUG -- :   ↳ ee/lib/gitlab/jira/middleware.rb:15:in `call'
    D, [2018-12-24T10:05:32.124301 #17199] DEBUG -- :   ↳ lib/gitlab/correlation_id.rb:15:in `use_id'
    D, [2018-12-24T10:05:32.124457 #17199] DEBUG -- :   ↳ (irb):48:in `irb_binding'
    D, [2018-12-24T10:05:32.131038 #17199] DEBUG -- :   Route Load (1.1ms)  SELECT  "routes".* FROM "routes" WHERE "routes"."source_id" = 6543 AND "routes"."source_type" = 'Namespace' LIMIT 1
    D, [2018-12-24T10:05:32.140344 #17199] DEBUG -- :   ↳ app/models/concerns/routable.rb:99:in `full_path'
    D, [2018-12-24T10:05:32.140603 #17199] DEBUG -- :   ↳ app/models/namespace.rb:126:in `to_param'
    D, [2018-12-24T10:05:32.140777 #17199] DEBUG -- :   ↳ config/application.rb:270:in `block (4 levels) in <class:Application>'
    D, [2018-12-24T10:05:32.140934 #17199] DEBUG -- :   ↳ app/helpers/snippets_helper.rb:6:in `reliable_snippet_path'
    D, [2018-12-24T10:05:32.141125 #17199] DEBUG -- :   ↳ app/views/search/results/_snippet_blob.html.haml:14:in `_app_views_search_results__snippet_blob_html_haml__761421932838641359_70066218636360'
    D, [2018-12-24T10:05:32.141357 #17199] DEBUG -- :   ↳ app/views/search/_results.html.haml:24:in `_app_views_search__results_html_haml__1710043260050147053_70066258712080'
    D, [2018-12-24T10:05:32.141523 #17199] DEBUG -- :   ↳ app/views/search/show.html.haml:9:in `_app_views_search_show_html_haml___3699216624438440937_70066274144220'
    D, [2018-12-24T10:05:32.141673 #17199] DEBUG -- :   ↳ app/controllers/application_controller.rb:116:in `render'
    D, [2018-12-24T10:05:32.141822 #17199] DEBUG -- :   ↳ app/controllers/application_controller.rb:428:in `set_locale'
    D, [2018-12-24T10:05:32.141994 #17199] DEBUG -- :   ↳ ee/lib/omni_auth/strategies/group_saml.rb:33:in `other_phase'
    D, [2018-12-24T10:05:32.142157 #17199] DEBUG -- :   ↳ ee/lib/gitlab/jira/middleware.rb:15:in `call'
    D, [2018-12-24T10:05:32.142314 #17199] DEBUG -- :   ↳ lib/gitlab/correlation_id.rb:15:in `use_id'
    D, [2018-12-24T10:05:32.142463 #17199] DEBUG -- :   ↳ (irb):48:in `irb_binding'
    D, [2018-12-24T10:05:33.992678 #17199] DEBUG -- :    (7.5ms)  SELECT COUNT(*) FROM "projects" INNER JOIN "namespaces" ON "projects"."namespace_id" = "namespaces"."id" WHERE "namespaces"."owner_id" = 443319 AND "namespaces"."type" IS NULL
    D, [2018-12-24T10:05:34.002016 #17199] DEBUG -- :   ↳ app/models/user.rb:1257:in `block in personal_projects_count'
    D, [2018-12-24T10:05:34.002433 #17199] DEBUG -- :   ↳ app/models/user.rb:1256:in `personal_projects_count'
    D, [2018-12-24T10:05:34.002616 #17199] DEBUG -- :   ↳ app/models/user.rb:856:in `projects_limit_left'
    D, [2018-12-24T10:05:34.002791 #17199] DEBUG -- :   ↳ app/models/user.rb:832:in `can_create_project?'
    D, [2018-12-24T10:05:34.002959 #17199] DEBUG -- :   ↳ app/views/layouts/header/_new_dropdown.haml:37:in `_app_views_layouts_header__new_dropdown_haml___4144007761816136631_70066232230540'
    D, [2018-12-24T10:05:34.003158 #17199] DEBUG -- :   ↳ app/views/layouts/header/_default.html.haml:29:in `_app_views_layouts_header__default_html_haml__2319627010720596557_70066262547260'
    D, [2018-12-24T10:05:34.003314 #17199] DEBUG -- :   ↳ app/views/layouts/application.html.haml:8:in `_app_views_layouts_application_html_haml___273937070633193600_70066239227280'
    D, [2018-12-24T10:05:34.003483 #17199] DEBUG -- :   ↳ app/views/layouts/search.html.haml:4:in `_app_views_layouts_search_html_haml___3900652658685492482_70066274668120'
    D, [2018-12-24T10:05:34.003643 #17199] DEBUG -- :   ↳ app/controllers/application_controller.rb:116:in `render'
    D, [2018-12-24T10:05:34.004759 #17199] DEBUG -- :   ↳ app/controllers/application_controller.rb:428:in `set_locale'
    D, [2018-12-24T10:05:34.004964 #17199] DEBUG -- :   ↳ ee/lib/omni_auth/strategies/group_saml.rb:33:in `other_phase'
    D, [2018-12-24T10:05:34.005140 #17199] DEBUG -- :   ↳ ee/lib/gitlab/jira/middleware.rb:15:in `call'
    D, [2018-12-24T10:05:34.005288 #17199] DEBUG -- :   ↳ lib/gitlab/correlation_id.rb:15:in `use_id'
    D, [2018-12-24T10:05:34.005454 #17199] DEBUG -- :   ↳ (irb):48:in `irb_binding'
    D, [2018-12-24T10:05:34.044440 #17199] DEBUG -- :   User Load (1.4ms)  SELECT  "users".* FROM "users" WHERE "users"."id" = 443319 LIMIT 1
    D, [2018-12-24T10:05:34.052283 #17199] DEBUG -- :   ↳ app/finders/issuable_finder.rb:252:in `assignee'
    D, [2018-12-24T10:05:34.052639 #17199] DEBUG -- :   ↳ app/finders/issues_finder.rb:143:in `by_assignee'
    D, [2018-12-24T10:05:34.052795 #17199] DEBUG -- :   ↳ ee/app/finders/ee/issues_finder.rb:61:in `by_assignee'
    D, [2018-12-24T10:05:34.052975 #17199] DEBUG -- :   ↳ app/finders/issuable_finder.rb:97:in `filter_items'
    D, [2018-12-24T10:05:34.053153 #17199] DEBUG -- :   ↳ app/finders/issues_finder.rb:71:in `filter_items'
    D, [2018-12-24T10:05:34.053820 #17199] DEBUG -- :   ↳ ee/app/finders/ee/issues_finder.rb:20:in `filter_items'
    D, [2018-12-24T10:05:34.054001 #17199] DEBUG -- :   ↳ app/finders/issuable_finder.rb:77:in `execute'
    D, [2018-12-24T10:05:34.054213 #17199] DEBUG -- :   ↳ app/finders/concerns/finder_with_cross_project_access.rb:21:in `execute'
    D, [2018-12-24T10:05:34.054367 #17199] DEBUG -- :   ↳ app/models/user.rb:1239:in `block in assigned_open_issues_count'
    D, [2018-12-24T10:05:34.054531 #17199] DEBUG -- :   ↳ app/models/user.rb:1238:in `assigned_open_issues_count'
    D, [2018-12-24T10:05:34.054679 #17199] DEBUG -- :   ↳ app/helpers/issuables_helper.rb:247:in `assigned_issuables_count'
    D, [2018-12-24T10:05:34.054838 #17199] DEBUG -- :   ↳ app/views/layouts/header/_default.html.haml:40:in `block (2 levels) in _app_views_layouts_header__default_html_haml__2319627010720596557_70066262547260'
    D, [2018-12-24T10:05:34.055004 #17199] DEBUG -- :   ↳ app/views/layouts/header/_default.html.haml:38:in `block in _app_views_layouts_header__default_html_haml__2319627010720596557_70066262547260'
    D, [2018-12-24T10:05:34.055170 #17199] DEBUG -- :   ↳ app/helpers/tab_helper.rb:69:in `nav_link'
    D, [2018-12-24T10:05:34.055326 #17199] DEBUG -- :   ↳ app/views/layouts/header/_default.html.haml:37:in `_app_views_layouts_header__default_html_haml__2319627010720596557_70066262547260'
    D, [2018-12-24T10:05:34.055521 #17199] DEBUG -- :   ↳ app/views/layouts/application.html.haml:8:in `_app_views_layouts_application_html_haml___273937070633193600_70066239227280'
    D, [2018-12-24T10:05:34.055662 #17199] DEBUG -- :   ↳ app/views/layouts/search.html.haml:4:in `_app_views_layouts_search_html_haml___3900652658685492482_70066274668120'
    D, [2018-12-24T10:05:34.055816 #17199] DEBUG -- :   ↳ app/controllers/application_controller.rb:116:in `render'
    D, [2018-12-24T10:05:34.055990 #17199] DEBUG -- :   ↳ app/controllers/application_controller.rb:428:in `set_locale'
    D, [2018-12-24T10:05:34.056158 #17199] DEBUG -- :   ↳ ee/lib/omni_auth/strategies/group_saml.rb:33:in `other_phase'
    D, [2018-12-24T10:05:34.056321 #17199] DEBUG -- :   ↳ ee/lib/gitlab/jira/middleware.rb:15:in `call'
    D, [2018-12-24T10:05:34.056478 #17199] DEBUG -- :   ↳ lib/gitlab/correlation_id.rb:15:in `use_id'
    D, [2018-12-24T10:05:34.056621 #17199] DEBUG -- :   ↳ (irb):48:in `irb_binding'
    D, [2018-12-24T10:05:34.310621 #17199] DEBUG -- :    (235.4ms)  SELECT COUNT(*) FROM "issues" INNER JOIN "projects" ON "projects"."id" = "issues"."project_id" LEFT JOIN project_features ON projects.id = project_features.project_id WHERE (
          issues.confidential IS NOT TRUE
          OR (issues.confidential = TRUE
            AND (issues.author_id = 443319
              OR EXISTS (SELECT TRUE FROM issue_assignees WHERE user_id = 443319 AND issue_id = issues.id)
              OR issues.project_id IN(SELECT "projects"."id" FROM "projects" INNER JOIN "project_authorizations" ON "projects"."id" = "project_authorizations"."project_id" WHERE "project_authorizations"."user_id" = 443319 AND (project_authorizations.access_level >= 20))))) AND (EXISTS (SELECT 1 FROM "project_authorizations" WHERE "project_authorizations"."user_id" = 443319 AND (project_authorizations.project_id = projects.id)) OR projects.visibility_level IN (10,20)) AND ("project_features"."issues_access_level" IN (NULL,20,30) OR ("project_features"."issues_access_level" = 10 AND EXISTS (SELECT 1 FROM "project_authorizations" WHERE "project_authorizations"."user_id" = 443319 AND (project_authorizations.project_id = projects.id)))) AND ("issues"."state" IN ('opened')) AND (EXISTS (SELECT TRUE FROM issue_assignees WHERE user_id = 443319 AND issue_id = issues.id)) AND "projects"."archived" = 'f'
    D, [2018-12-24T10:05:34.318005 #17199] DEBUG -- :   ↳ app/models/user.rb:1239:in `block in assigned_open_issues_count'
    D, [2018-12-24T10:05:34.318362 #17199] DEBUG -- :   ↳ app/models/user.rb:1238:in `assigned_open_issues_count'
    D, [2018-12-24T10:05:34.318553 #17199] DEBUG -- :   ↳ app/helpers/issuables_helper.rb:247:in `assigned_issuables_count'
    D, [2018-12-24T10:05:34.318705 #17199] DEBUG -- :   ↳ app/views/layouts/header/_default.html.haml:40:in `block (2 levels) in _app_views_layouts_header__default_html_haml__2319627010720596557_70066262547260'
    D, [2018-12-24T10:05:34.318864 #17199] DEBUG -- :   ↳ app/views/layouts/header/_default.html.haml:38:in `block in _app_views_layouts_header__default_html_haml__2319627010720596557_70066262547260'
    D, [2018-12-24T10:05:34.319042 #17199] DEBUG -- :   ↳ app/helpers/tab_helper.rb:69:in `nav_link'
    D, [2018-12-24T10:05:34.319245 #17199] DEBUG -- :   ↳ app/views/layouts/header/_default.html.haml:37:in `_app_views_layouts_header__default_html_haml__2319627010720596557_70066262547260'
    D, [2018-12-24T10:05:34.319430 #17199] DEBUG -- :   ↳ app/views/layouts/application.html.haml:8:in `_app_views_layouts_application_html_haml___273937070633193600_70066239227280'
    D, [2018-12-24T10:05:34.319608 #17199] DEBUG -- :   ↳ app/views/layouts/search.html.haml:4:in `_app_views_layouts_search_html_haml___3900652658685492482_70066274668120'
    D, [2018-12-24T10:05:34.319784 #17199] DEBUG -- :   ↳ app/controllers/application_controller.rb:116:in `render'
    D, [2018-12-24T10:05:34.320534 #17199] DEBUG -- :   ↳ app/controllers/application_controller.rb:428:in `set_locale'
    D, [2018-12-24T10:05:34.320702 #17199] DEBUG -- :   ↳ ee/lib/omni_auth/strategies/group_saml.rb:33:in `other_phase'
    D, [2018-12-24T10:05:34.320880 #17199] DEBUG -- :   ↳ ee/lib/gitlab/jira/middleware.rb:15:in `call'
    D, [2018-12-24T10:05:34.321082 #17199] DEBUG -- :   ↳ lib/gitlab/correlation_id.rb:15:in `use_id'
    D, [2018-12-24T10:05:34.321247 #17199] DEBUG -- :   ↳ (irb):48:in `irb_binding'
    D, [2018-12-24T10:05:34.343242 #17199] DEBUG -- :   User Load (1.4ms)  SELECT  "users".* FROM "users" WHERE "users"."id" = 443319 LIMIT 1
    D, [2018-12-24T10:05:34.350802 #17199] DEBUG -- :   ↳ app/finders/issuable_finder.rb:252:in `assignee'
    D, [2018-12-24T10:05:34.351127 #17199] DEBUG -- :   ↳ app/finders/issuable_finder.rb:421:in `by_assignee'
    D, [2018-12-24T10:05:34.351320 #17199] DEBUG -- :   ↳ app/finders/issuable_finder.rb:97:in `filter_items'
    D, [2018-12-24T10:05:34.351518 #17199] DEBUG -- :   ↳ app/finders/merge_requests_finder.rb:39:in `filter_items'
    D, [2018-12-24T10:05:34.351692 #17199] DEBUG -- :   ↳ app/finders/issuable_finder.rb:77:in `execute'
    D, [2018-12-24T10:05:34.351845 #17199] DEBUG -- :   ↳ app/finders/concerns/finder_with_cross_project_access.rb:21:in `execute'
    D, [2018-12-24T10:05:34.352027 #17199] DEBUG -- :   ↳ app/models/user.rb:1233:in `block in assigned_open_merge_requests_count'
    D, [2018-12-24T10:05:34.352193 #17199] DEBUG -- :   ↳ app/models/user.rb:1232:in `assigned_open_merge_requests_count'
    D, [2018-12-24T10:05:34.352359 #17199] DEBUG -- :   ↳ app/helpers/issuables_helper.rb:249:in `assigned_issuables_count'
    D, [2018-12-24T10:05:34.352558 #17199] DEBUG -- :   ↳ app/views/layouts/header/_default.html.haml:47:in `block (2 levels) in _app_views_layouts_header__default_html_haml__2319627010720596557_70066262547260'
    D, [2018-12-24T10:05:34.352728 #17199] DEBUG -- :   ↳ app/views/layouts/header/_default.html.haml:45:in `block in _app_views_layouts_header__default_html_haml__2319627010720596557_70066262547260'
    D, [2018-12-24T10:05:34.352878 #17199] DEBUG -- :   ↳ app/helpers/tab_helper.rb:69:in `nav_link'
    D, [2018-12-24T10:05:34.353095 #17199] DEBUG -- :   ↳ app/views/layouts/header/_default.html.haml:44:in `_app_views_layouts_header__default_html_haml__2319627010720596557_70066262547260'
    D, [2018-12-24T10:05:34.353264 #17199] DEBUG -- :   ↳ app/views/layouts/application.html.haml:8:in `_app_views_layouts_application_html_haml___273937070633193600_70066239227280'
    D, [2018-12-24T10:05:34.353463 #17199] DEBUG -- :   ↳ app/views/layouts/search.html.haml:4:in `_app_views_layouts_search_html_haml___3900652658685492482_70066274668120'
    D, [2018-12-24T10:05:34.353631 #17199] DEBUG -- :   ↳ app/controllers/application_controller.rb:116:in `render'
    D, [2018-12-24T10:05:34.353802 #17199] DEBUG -- :   ↳ app/controllers/application_controller.rb:428:in `set_locale'
    D, [2018-12-24T10:05:34.353957 #17199] DEBUG -- :   ↳ ee/lib/omni_auth/strategies/group_saml.rb:33:in `other_phase'
    D, [2018-12-24T10:05:34.354158 #17199] DEBUG -- :   ↳ ee/lib/gitlab/jira/middleware.rb:15:in `call'
    D, [2018-12-24T10:05:34.354328 #17199] DEBUG -- :   ↳ lib/gitlab/correlation_id.rb:15:in `use_id'
    D, [2018-12-24T10:05:34.354507 #17199] DEBUG -- :   ↳ (irb):48:in `irb_binding'
    D, [2018-12-24T10:05:34.597526 #17199] DEBUG -- :    (221.8ms)  SELECT COUNT(*) FROM "merge_requests" INNER JOIN "projects" ON "projects"."id" = "merge_requests"."target_project_id" LEFT JOIN project_features ON projects.id = project_features.project_id WHERE (EXISTS (SELECT 1 FROM "project_authorizations" WHERE "project_authorizations"."user_id" = 443319 AND (project_authorizations.project_id = projects.id)) OR projects.visibility_level IN (10,20)) AND ("project_features"."merge_requests_access_level" IN (NULL,20,30) OR ("project_features"."merge_requests_access_level" = 10 AND EXISTS (SELECT 1 FROM "project_authorizations" WHERE "project_authorizations"."user_id" = 443319 AND (project_authorizations.project_id = projects.id)))) AND ("merge_requests"."state" IN ('opened')) AND "merge_requests"."assignee_id" = 443319 AND "projects"."archived" = 'f'
    D, [2018-12-24T10:05:34.605148 #17199] DEBUG -- :   ↳ app/models/user.rb:1233:in `block in assigned_open_merge_requests_count'
    D, [2018-12-24T10:05:34.605510 #17199] DEBUG -- :   ↳ app/models/user.rb:1232:in `assigned_open_merge_requests_count'
    D, [2018-12-24T10:05:34.606726 #17199] DEBUG -- :   ↳ app/helpers/issuables_helper.rb:249:in `assigned_issuables_count'
    D, [2018-12-24T10:05:34.606929 #17199] DEBUG -- :   ↳ app/views/layouts/header/_default.html.haml:47:in `block (2 levels) in _app_views_layouts_header__default_html_haml__2319627010720596557_70066262547260'
    D, [2018-12-24T10:05:34.607114 #17199] DEBUG -- :   ↳ app/views/layouts/header/_default.html.haml:45:in `block in _app_views_layouts_header__default_html_haml__2319627010720596557_70066262547260'
    D, [2018-12-24T10:05:34.607305 #17199] DEBUG -- :   ↳ app/helpers/tab_helper.rb:69:in `nav_link'
    D, [2018-12-24T10:05:34.607487 #17199] DEBUG -- :   ↳ app/views/layouts/header/_default.html.haml:44:in `_app_views_layouts_header__default_html_haml__2319627010720596557_70066262547260'
    D, [2018-12-24T10:05:34.607661 #17199] DEBUG -- :   ↳ app/views/layouts/application.html.haml:8:in `_app_views_layouts_application_html_haml___273937070633193600_70066239227280'
    D, [2018-12-24T10:05:34.607838 #17199] DEBUG -- :   ↳ app/views/layouts/search.html.haml:4:in `_app_views_layouts_search_html_haml___3900652658685492482_70066274668120'
    D, [2018-12-24T10:05:34.608032 #17199] DEBUG -- :   ↳ app/controllers/application_controller.rb:116:in `render'
    D, [2018-12-24T10:05:34.608200 #17199] DEBUG -- :   ↳ app/controllers/application_controller.rb:428:in `set_locale'
    D, [2018-12-24T10:05:34.608367 #17199] DEBUG -- :   ↳ ee/lib/omni_auth/strategies/group_saml.rb:33:in `other_phase'
    D, [2018-12-24T10:05:34.608534 #17199] DEBUG -- :   ↳ ee/lib/gitlab/jira/middleware.rb:15:in `call'
    D, [2018-12-24T10:05:34.608688 #17199] DEBUG -- :   ↳ lib/gitlab/correlation_id.rb:15:in `use_id'
    D, [2018-12-24T10:05:34.608860 #17199] DEBUG -- :   ↳ (irb):48:in `irb_binding'
    D, [2018-12-24T10:05:34.636176 #17199] DEBUG -- :    (9.8ms)  SELECT COUNT(*) FROM "todos" WHERE "todos"."user_id" = 443319 AND ("todos"."state" IN ('pending'))
    D, [2018-12-24T10:05:34.643786 #17199] DEBUG -- :   ↳ app/models/user.rb:1251:in `block in todos_pending_count'
    D, [2018-12-24T10:05:34.644260 #17199] DEBUG -- :   ↳ app/models/user.rb:1250:in `todos_pending_count'
    D, [2018-12-24T10:05:34.644449 #17199] DEBUG -- :   ↳ app/helpers/todos_helper.rb:5:in `todos_pending_count'
    D, [2018-12-24T10:05:34.644627 #17199] DEBUG -- :   ↳ app/views/layouts/header/_default.html.haml:54:in `block (2 levels) in _app_views_layouts_header__default_html_haml__2319627010720596557_70066262547260'
    D, [2018-12-24T10:05:34.644788 #17199] DEBUG -- :   ↳ app/views/layouts/header/_default.html.haml:52:in `block in _app_views_layouts_header__default_html_haml__2319627010720596557_70066262547260'
    D, [2018-12-24T10:05:34.644966 #17199] DEBUG -- :   ↳ app/helpers/tab_helper.rb:69:in `nav_link'
    D, [2018-12-24T10:05:34.645142 #17199] DEBUG -- :   ↳ app/views/layouts/header/_default.html.haml:51:in `_app_views_layouts_header__default_html_haml__2319627010720596557_70066262547260'
    D, [2018-12-24T10:05:34.645751 #17199] DEBUG -- :   ↳ app/views/layouts/application.html.haml:8:in `_app_views_layouts_application_html_haml___273937070633193600_70066239227280'
    D, [2018-12-24T10:05:34.645960 #17199] DEBUG -- :   ↳ app/views/layouts/search.html.haml:4:in `_app_views_layouts_search_html_haml___3900652658685492482_70066274668120'
    D, [2018-12-24T10:05:34.646156 #17199] DEBUG -- :   ↳ app/controllers/application_controller.rb:116:in `render'
    D, [2018-12-24T10:05:34.646350 #17199] DEBUG -- :   ↳ app/controllers/application_controller.rb:428:in `set_locale'
    D, [2018-12-24T10:05:34.646531 #17199] DEBUG -- :   ↳ ee/lib/omni_auth/strategies/group_saml.rb:33:in `other_phase'
    D, [2018-12-24T10:05:34.646691 #17199] DEBUG -- :   ↳ ee/lib/gitlab/jira/middleware.rb:15:in `call'
    D, [2018-12-24T10:05:34.646882 #17199] DEBUG -- :   ↳ lib/gitlab/correlation_id.rb:15:in `use_id'
    D, [2018-12-24T10:05:34.647068 #17199] DEBUG -- :   ↳ (irb):48:in `irb_binding'
    D, [2018-12-24T10:05:34.772013 #17199] DEBUG -- :   UserStatus Load (1.1ms)  SELECT  "user_statuses".* FROM "user_statuses" WHERE "user_statuses"."user_id" = 443319 LIMIT 1
    D, [2018-12-24T10:05:34.779495 #17199] DEBUG -- :   ↳ app/views/layouts/header/_current_user_dropdown.html.haml:8:in `_app_views_layouts_header__current_user_dropdown_html_haml__2487065352224017801_70066227382000'
    D, [2018-12-24T10:05:34.779802 #17199] DEBUG -- :   ↳ app/views/layouts/header/_default.html.haml:68:in `_app_views_layouts_header__default_html_haml__2319627010720596557_70066262547260'
    D, [2018-12-24T10:05:34.780019 #17199] DEBUG -- :   ↳ app/views/layouts/application.html.haml:8:in `_app_views_layouts_application_html_haml___273937070633193600_70066239227280'
    D, [2018-12-24T10:05:34.780209 #17199] DEBUG -- :   ↳ app/views/layouts/search.html.haml:4:in `_app_views_layouts_search_html_haml___3900652658685492482_70066274668120'
    D, [2018-12-24T10:05:34.780397 #17199] DEBUG -- :   ↳ app/controllers/application_controller.rb:116:in `render'
    D, [2018-12-24T10:05:34.780556 #17199] DEBUG -- :   ↳ app/controllers/application_controller.rb:428:in `set_locale'
    D, [2018-12-24T10:05:34.780745 #17199] DEBUG -- :   ↳ ee/lib/omni_auth/strategies/group_saml.rb:33:in `other_phase'
    D, [2018-12-24T10:05:34.780901 #17199] DEBUG -- :   ↳ ee/lib/gitlab/jira/middleware.rb:15:in `call'
    D, [2018-12-24T10:05:34.781091 #17199] DEBUG -- :   ↳ lib/gitlab/correlation_id.rb:15:in `use_id'
    D, [2018-12-24T10:05:34.781234 #17199] DEBUG -- :   ↳ (irb):48:in `irb_binding'
    I, [2018-12-24T10:05:35.319828 #17199]  INFO -- : Completed 200 OK in 50176ms (Views: 3617.6ms | ActiveRecord: 46411.1ms | Elasticsearch: 0.0ms)
    I, [2018-12-24T10:05:35.330973 #17199]  INFO -- : Snippet total (1): 10422.0ms
    I, [2018-12-24T10:05:35.331209 #17199]  INFO -- : User total (4): 28.2ms
    I, [2018-12-24T10:05:35.331359 #17199]  INFO -- : Upload total (2): 19.1ms
    I, [2018-12-24T10:05:35.331510 #17199]  INFO -- : Project total (3): 6.4ms
    I, [2018-12-24T10:05:35.331635 #17199]  INFO -- : Namespace total (3): 5.0ms
    I, [2018-12-24T10:05:35.331821 #17199]  INFO -- : Route total (3): 4.2ms
    I, [2018-12-24T10:05:35.331987 #17199]  INFO -- : License total (1): 1.5ms
    I, [2018-12-24T10:05:35.332129 #17199]  INFO -- : UserStatus total (1): 1.1ms

    Note that this does not include the change to the view as I don't know how to do that from a console session, but it will load now, so we can iterate and improve :slight_smile:

    Is this ready for merge?

  • Heinrich Lee Yu added 84 commits

    added 84 commits

    Compare with previous version

  • Author Maintainer

    @smcgivern That looks good. The duplicate count there should be fixed with the view change.

    Yeah, this is ready for merge, pending approval from db team for the additional index?

  • Right, good point. @abrandl wdyt of the index added here? A trigram isn't really ideal for 'code search' (which is what our snippet search is, in theory), but we're already using ILIKE, so I figure it's better than any short-term alternatives we have.

  • assigned to @abrandl

  • Sean McGivern approved this merge request

    approved this merge request

  • A trigram isn't really ideal for 'code search' (which is what our snippet search is, in theory)

    Actually interesting topic! @smcgivern Google Code Search allowed to search with regular expressions and was based on a trigram index. Google proposed the basic mechanic to translate regular expressions to a boolean trigram lookup query that can be used on a trigram index. I based my master thesis on Google's paper and was working on that topic a bit. Unfortunately, it really depends on the regular expression if a trigram index would help or not (there are quite simple cases where the trigram index lookup degenerates to a sequential scan) - I would agree that it's not "ideal".

    With my reminiscent remarks out of the way, let's look at this query (taken from https://gitlab.com/gitlab-org/gitlab-ce/issues/44353#note_63871537).

    SELECT
        COUNT(*)
    FROM
        "snippets"
    WHERE ("snippets"."project_id" IN (
            SELECT
                "id"
            FROM (
                SELECT
                    projects.id
                FROM
                    "projects"
                LEFT JOIN project_features ON projects.id = project_features.project_id
            WHERE (EXISTS (
                    SELECT
                        1
                    FROM
                        "project_authorizations"
                    WHERE
                        "project_authorizations"."user_id" = 1642716
                        AND (project_authorizations.project_id = projects.id)))
                AND ("project_features"."snippets_access_level" IN (NULL, 20)
                    OR ("project_features"."snippets_access_level" = 10
                        AND EXISTS (
                            SELECT
                                1
                            FROM
                                "project_authorizations"
                            WHERE
                                "project_authorizations"."user_id" = 1642716
                                AND (project_authorizations.project_id = projects.id))))
                UNION
                SELECT
                    projects.id
                FROM
                    "projects"
                LEFT JOIN project_features ON projects.id = project_features.project_id
            WHERE
                "projects"."visibility_level" IN (10, 20)
                AND ("project_features"."snippets_access_level" IN (NULL, 20)
                    OR ("project_features"."snippets_access_level" = 10
                        AND EXISTS (
                            SELECT
                                1
                            FROM
                                "project_authorizations"
                            WHERE
                                "project_authorizations"."user_id" = 1642716
                                AND (project_authorizations.project_id = projects.id))))) AS projects)
            OR "snippets"."project_id" IS NULL)
        AND (EXISTS (
                SELECT
                    1
                FROM
                    "project_authorizations"
                WHERE
                    "project_authorizations"."user_id" = 1642716
                    AND (project_authorizations.project_id = snippets.project_id))
                OR snippets.visibility_level IN (10, 20)
                OR snippets.author_id = (1642716))
            AND ("snippets"."content" ILIKE '%foo%')

    Without a trigram index, we're at 195s with this plan: https://explain.depesz.com/s/LWSv This is basically a seqscan on snippets while evaluating conditions (also checking content).

    With the trigram index in place, we're still in the same ballpark area (182s): https://explain.depesz.com/s/b5nx

    The plan is a bit hard to read, here is a simplified version:

    1. Use the trigram index to find all snippets with ILIKE '%foo%'
    2. Recheck condition ILIKE '%foo%' after retrieving the full record (this is always necessary with a trigram index for regex search)
    3. Iterate records and check each if it fulfills the other conditions (based on SubPlan 5,6,7)

    There's one big issue with (3): It materializes a full sub plan with 0.6M rows - which is really costly.

    Let's try to "fix" this by increasing work_mem (from 16 MB to 1 GB):

    set work_mem='1GB';
    explain analyze SELECT COUNT(*) ...

    This results in a 14s plan because now we can keep those records in memory! https://explain.depesz.com/s/pSQZ

    So it boils down to:

    1. The trigram index lookup is reasonably fast (here: < 1ms plus heap access for rechecking, which dominates)
    2. Checking all the other conditions is dead slow if the data is materialized and still slow if held in memory

    I would have to discuss if we want to consider increasing work_mem a bit (seems low but then again we have quite a lot connections). However, this would only be a band-aid to the problematic query here.

    Looking at what "all the other conditions" are, it seems like a few disjunctions (condition1 OR condition2 OR condition3 clauses). It may be worth to explore translating snippets wildcard lookup AND (condition1 OR condition2 OR condition3) to (snippets wildcard lookup AND condition1) UNION (snippets wildcard lookup AND condition2) ..., but I'm not sure.

    The number of records "all other conditions" yield does not heavily depend on the user_id since we also include public snippets in that. As such, we would always have around 0.65M records that would have to be checked (and queries/materialized before this).

    In that sense - the wildcard lookup is not the problem! The "other conditions" are much more problematic to this query.

    There are a few oddities with those queries as well. Example: "snippets_access_level" IN (NULL, 20) would never yield records with a null value for snippets_access_level.

    I don't have a strong suggestion how to fix the other conditions at the moment. I tend to think the trigram index should be added for wildcard search anyways, but let's not expect this fixes the performance problem.

    Let's see if we can invest more time on the query. Meanwhile, I'll re-assign back to @engwan.

  • assigned to @engwan

  • @abrandl thanks, that's really fascinating :slight_smile:

    I don't think we would actually execute a query in that form right now, but @engwan can confirm. If we do, we should definitely address that, yes.

  • Author Maintainer

    @abrandl I think that query has been changed since that comment was made 9 months ago.

    Basing on the comments made by @smcgivern when he profiled the request on staging recently (https://gitlab.com/gitlab-org/gitlab-ce/merge_requests/23952#note_127071009), here's the full SQL:

    SELECT COUNT(*)
    FROM
      (SELECT "snippets".*
       FROM "snippets"
       WHERE (snippets.visibility_level IN (10,
                                            20)
              OR snippets.author_id = 443319)
         AND "snippets"."project_id" IS NULL
       UNION SELECT "snippets".*
       FROM "snippets"
       INNER JOIN "projects" ON "projects"."id" = "snippets"."project_id"
       INNER JOIN "project_features" ON "project_features"."project_id" = "projects"."id"
       WHERE (snippets.visibility_level IN (10,
                                            20)
              OR snippets.author_id = 443319)
         AND (projects.visibility_level IN (10,
                                            20))
         AND "project_features"."snippets_access_level" IN (20,
                                                            30)
       UNION SELECT "snippets".*
       FROM "snippets"
       INNER JOIN "projects" ON "projects"."id" = "snippets"."project_id"
       INNER JOIN "project_features" ON "project_features"."project_id" = "projects"."id"
       WHERE "project_features"."snippets_access_level" IN (20,
                                                            30,
                                                            10)
         AND (EXISTS
                (SELECT 1
                 FROM "project_authorizations"
                 WHERE (project_id = snippets.project_id)
                   AND "project_authorizations"."user_id" = 443319))) snippets
    WHERE ("snippets"."content" ILIKE '%foo%')

    If the trigram index needs more discussion we can also split that into a separate MR since removing the useless counts is pretty big and it would be good to have it merged as soon as possible.

  • Thanks @engwan - I overlooked the query log Sean posted earlier.

    Here's a plan for the query

    I verified the numbers on the GitLab.com database (with warm caches) because I didn't believe my test database.

    So in this case, the trigram index actually harms performance. Not because the index lookup takes forever but because a different plan is chosen which turns out to perform worse than the other. In fact, without the index, we first lookup by all the other conditions and then evaluate the expression. With the index, this is the other way around.

    So basically the argument stays the same as above: The other conditions make this query perform badly, not necessarily the wildcard search.

    This may be a good example where we would want staging to be equally sized as production to get reliable profiling numbers. I have not found an issue for this even though this is subject of discussion for sure. @smcgivern @engwan Are you aware of an existing issue?

    If the trigram index needs more discussion we can also split that into a separate MR since removing the useless counts is pretty big and it would be good to have it merged as soon as possible.

    @engwan Removing useless counts sounds good! Let's extract that and ship it! :thumbsup:

  • mentioned in issue #55904 (moved)

  • Created https://gitlab.com/gitlab-org/gitlab-ce/issues/55904 to discuss the query improvements further.

  • Heinrich Lee Yu added 232 commits

    added 232 commits

    Compare with previous version

  • Heinrich Lee Yu changed title from Add trigram index to snippets content to Remove redundant counts in snippets search

    changed title from Add trigram index to snippets content to Remove redundant counts in snippets search

  • Heinrich Lee Yu changed the description

    changed the description

  • Author Maintainer

    Thanks @abrandl, that's interesting. I don't know of any existing issue re: making staging equally sized.

    @smcgivern I've removed the migration from this MR. It's now just removing duplicate counts. I believe this should be enough to prevent the timeouts.

  • Andreas Brandl approved this merge request

    approved this merge request

  • @engwan , @abrandl , just curious does it get better if we merge first 2 selects from snippets? Idea is to get rid of duplicated heap scan in non-indexed case, which does more or less same job twice

    SELECT COUNT(*)   
    FROM
     (SELECT "snippets".*
      FROM "snippets"
      LEFT OUTER JOIN (
          "projects" 
          INNER JOIN "project_features" ON "project_features"."project_id" = "projects"."id"
                                        AND "projects"."visibility_level" IN (10, 20)
                                        AND "project_features"."snippets_access_level" IN (20, 30)
      ) ON "projects"."id" = "snippets"."project_id"
      WHERE (snippets.visibility_level IN (10,
                                           20)
             OR snippets.author_id = 443319)
            AND ("snippets"."project_id" IS NULL OR "projects"."id" IS NOT NULL)
      UNION SELECT "snippets".*
      FROM "snippets"
      INNER JOIN "projects" ON "projects"."id" = "snippets"."project_id"
      INNER JOIN "project_features" ON "project_features"."project_id" = "projects"."id"
      WHERE "project_features"."snippets_access_level" IN (20,
                                                           30,
                                                           10)
        AND (EXISTS
               (SELECT 1
                FROM "project_authorizations"
                WHERE (project_id = snippets.project_id)
                  AND "project_authorizations"."user_id" = 443319))) snippets
    WHERE ("snippets"."content" ILIKE '%foo%')
    Edited by Maxim Ivanov
  • Author Maintainer

    Thanks @redbaron1. This does require a non-trivial change to SnippetsFinder.

    If its impact is significant, it may be worth it. We could do this in a follow-up MR.

  • Did it have positive effect at all though? (I cant test myself now)

  • Author Maintainer

    ChatOps is failing for me so I can't test. I think @smcgivern or @abrandl can test on staging console.

  • Sean McGivern resolved all discussions

    resolved all discussions

  • @redbaron1 that does look promising, indeed: https://explain.depesz.com/s/ocafB (And it is possible that would be able to use the index.)

    @abrandl I knew that staging would not always be representative, but that is amazing ... ly disappointing :disappointed: I couldn't find an issue either; the closest I came up with was https://gitlab.com/gitlab-com/gl-infra/infrastructure/issues/5265, which you created, and is still very relevant.

    @engwan thanks, I'm going to merge this as it stands as it's a strict (if small) improvement. We can always iterate on this later. Shall we move the issue to 11.8 for now, or create a new one? Do whatever you think makes most sense :slight_smile:

  • merged

  • Sean McGivern mentioned in commit 4543ef09

    mentioned in commit 4543ef09

  • added typebug label

  • mentioned in issue #56279 (moved)

  • mentioned in issue #56627 (closed)

  • 🤖 GitLab Bot 🤖 changed the description

    changed the description

  • added Category:Source Code Management snippets labels and removed 1 deleted label

  • Please register or sign in to reply
    Loading