Uploaded image for project: 'Crucible'
  1. Crucible
  2. CRUC-8560

Load time for the "Activity" page is long for repositories with thousands of branches

    XMLWordPrintable

Details

    Description

      Issue Summary

      Load time for the "Activity" page is long for repos with a lot of branches (e.g. tens of thousands or hundreds of thousands of branches).

      Issue is observed starting in Fisheye/Crucible 4.8.12, where the bug for calculating the "Last Commit" date is fixed (CRUC-6866)

      Steps to Reproduce

      1. Create a repo with tens or hundreds of thousands of branches
        e.g.
        • Create new SVN repo
        • Create trunk and add files to trunk
        • Run sample script to create thousands of branches 
          #!/bin/bash

for n in {1..100000}
do
  num=$(printf "%06d" $n)
  newbranch="branch$num"
  svn --username admin --password admin copy svn://localhost:3690/smallrepo/trunk svn://localhost:3690/smallrepo/branches/$newbranch -m "new branch $newbranch"
done
      2. Load the "Activity" page for the repo (<FECRU_BASE_URL>/changelog/<REPO_NAME>)

      Expected Results

      The "Activity" page loads in a timely manner.

      Actual Results

      The response time for loading the "Activity" page takes longer for repos with tens or hundreds of thousands of branches.

       

      Page load time increases as the number of branches and ordered revisions increase.

      To capture the timings for getting the last commit date,

      • Enable Byteman for additional logging in Fisheye and Crucible
      • Load the following Byteman script 
        RULE com.cenqua.fisheye.web.ChangelogServlet#determineLastCommitUsingWaybackSpec at entry
CLASS com.cenqua.fisheye.web.ChangelogServlet
METHOD determineLastCommitUsingWaybackSpec
AT ENTRY
BIND entryTime = System.nanoTime();
        thread = Thread.currentThread();
        mapName = "com.cenqua.fisheye.web.ChangelogServlet#determineLastCommitUsingWaybackSpec"
IF TRUE
DO link(mapName, thread, entryTime);
ENDRULE

RULE com.cenqua.fisheye.web.ChangelogServlet#determineLastCommitUsingWaybackSpec at exit
CLASS com.cenqua.fisheye.web.ChangelogServlet
METHOD determineLastCommitUsingWaybackSpec
AT EXIT
BIND exitTime:Long = System.nanoTime();
        thread = Thread.currentThread();
        mapName = "com.cenqua.fisheye.web.ChangelogServlet#determineLastCommitUsingWaybackSpec";
        entryTime:Long = Long.parseLong(linked(mapName, thread).toString());
        elapsedTime:Long = exitTime - entryTime
IF TRUE
DO  org.slf4j.LoggerFactory.getLogger("Byteman").info("<- determineLastCommitUsingWaybackSpec check: {} - {} = ", Long.toString(exitTime), Long.toString(entryTime));
    org.slf4j.LoggerFactory.getLogger("Byteman").info("<- {}; elapsed time: {} ns", mapName, Long.toString(elapsedTime));
ENDRULE

RULE com.cenqua.fisheye.web.ChangelogServlet#calculateLastBranchHeadDate at entry
CLASS com.cenqua.fisheye.web.ChangelogServlet
METHOD calculateLastBranchHeadDate
AT ENTRY
BIND entryTime = System.nanoTime();
        thread = Thread.currentThread();
        mapName = "com.cenqua.fisheye.web.ChangelogServlet#calculateLastBranchHeadDate"
IF TRUE
DO link(mapName, thread, entryTime);
ENDRULE

RULE com.cenqua.fisheye.web.ChangelogServlet#calculateLastBranchHeadDate at exit
CLASS com.cenqua.fisheye.web.ChangelogServlet
METHOD calculateLastBranchHeadDate
AT EXIT
BIND exitTime:Long = System.nanoTime();
        thread = Thread.currentThread();
        mapName = "com.cenqua.fisheye.web.ChangelogServlet#calculateLastBranchHeadDate";
        entryTime:Long = Long.parseLong(linked(mapName, thread).toString());
        elapsedTime:Long = exitTime - entryTime
IF TRUE
DO  org.slf4j.LoggerFactory.getLogger("Byteman").info("<- calculateLastBranchHeadDate check: {} - {} = ", Long.toString(exitTime), Long.toString(entryTime));
    org.slf4j.LoggerFactory.getLogger("Byteman").info("<- {}; elapsed time: {} ns", mapName, Long.toString(elapsedTime));
ENDRULE

RULE com.cenqua.fisheye.cache.BaseDirInfoCache#getLastCommitDate after write
CLASS com.cenqua.fisheye.cache.BaseDirInfoCache
METHOD getLastCommitDate
AFTER WRITE $orderedRevisions
IF TRUE
DO org.slf4j.LoggerFactory.getLogger("Byteman").info("<- com.cenqua.fisheye.cache.BaseDirInfoCache#getLastCommitDate; number of orderedRevisions: " + String.valueOf($orderedRevisions.size()))
ENDRULE

RULE com.cenqua.fisheye.rep.impl.CommonRevInfoDAO#orderAndCollapseRevisions at entry
CLASS com.cenqua.fisheye.rep.impl.CommonRevInfoDAO
METHOD orderAndCollapseRevisions
AT ENTRY
BIND entryTime = System.nanoTime();
        thread = Thread.currentThread();
        mapName = "com.cenqua.fisheye.rep.impl.CommonRevInfoDAO#orderAndCollapseRevisions"
IF TRUE
DO link(mapName, thread, entryTime);
ENDRULE

RULE com.cenqua.fisheye.rep.impl.CommonRevInfoDAO#orderAndCollapseRevisions at exit
CLASS com.cenqua.fisheye.rep.impl.CommonRevInfoDAO
METHOD orderAndCollapseRevisions
AT EXIT
BIND exitTime:Long = System.nanoTime();
        thread = Thread.currentThread();
        mapName = "com.cenqua.fisheye.rep.impl.CommonRevInfoDAO#orderAndCollapseRevisions";
        entryTime:Long = Long.parseLong(linked(mapName, thread).toString());
        elapsedTime:Long = exitTime - entryTime
IF TRUE
DO  org.slf4j.LoggerFactory.getLogger("Byteman").info("<- orderAndCollapseRevisions check: {} - {} = ", Long.toString(exitTime), Long.toString(entryTime));
    org.slf4j.LoggerFactory.getLogger("Byteman").info("<- {}; elapsed time: {} ns", mapName, Long.toString(elapsedTime));
ENDRULE

RULE com.cenqua.fisheye.rep.impl.CommonRevInfoDAO#collapse at entry
CLASS com.cenqua.fisheye.rep.impl.CommonRevInfoDAO
METHOD collapse
AT ENTRY
BIND entryTime = System.nanoTime();
        thread = Thread.currentThread();
        mapName = "com.cenqua.fisheye.rep.impl.CommonRevInfoDAO#collapse"
IF TRUE
DO link(mapName, thread, entryTime);
ENDRULE

RULE com.cenqua.fisheye.rep.impl.CommonRevInfoDAO#collapse at exit
CLASS com.cenqua.fisheye.rep.impl.CommonRevInfoDAO
METHOD collapse
AT EXIT
BIND exitTime:Long = System.nanoTime();
        thread = Thread.currentThread();
        mapName = "com.cenqua.fisheye.rep.impl.CommonRevInfoDAO#collapse";
        entryTime:Long = Long.parseLong(linked(mapName, thread).toString());
        elapsedTime:Long = exitTime - entryTime
IF TRUE
DO  org.slf4j.LoggerFactory.getLogger("Byteman").info("<- collapse check: {} - {} = ", Long.toString(exitTime), Long.toString(entryTime));
    org.slf4j.LoggerFactory.getLogger("Byteman").info("<- {}; elapsed time: {} ns", mapName, Long.toString(elapsedTime));
ENDRULE

RULE com.atlassian.fisheye.svn.Svn2Cache#getFileRevision at entry
CLASS com.atlassian.fisheye.svn.Svn2Cache
METHOD getFileRevision(int)
AT ENTRY
BIND entryTime = System.nanoTime();
        thread = Thread.currentThread();
        mapName = "com.atlassian.fisheye.svn.Svn2Cache#getFileRevision"
IF TRUE
DO link(mapName, thread, entryTime);
ENDRULE

RULE com.atlassian.fisheye.svn.Svn2Cache#getFileRevision at exit
CLASS com.atlassian.fisheye.svn.Svn2Cache
METHOD getFileRevision(int)
AT EXIT
BIND exitTime:Long = System.nanoTime();
        thread = Thread.currentThread();
        mapName = "com.atlassian.fisheye.svn.Svn2Cache#getFileRevision";
        entryTime:Long = Long.parseLong(linked(mapName, thread).toString());
        elapsedTime:Long = exitTime - entryTime
IF TRUE
DO  org.slf4j.LoggerFactory.getLogger("Byteman").info("<- getFileRevision check: {} - {} = ", Long.toString(exitTime), Long.toString(entryTime));
    org.slf4j.LoggerFactory.getLogger("Byteman").info("<- {}; elapsed time: {} ns", mapName, Long.toString(elapsedTime));
ENDRULE

RULE com.cenqua.fisheye.svn.db.SvnRevInfoDAO#load at entry
CLASS com.cenqua.fisheye.svn.db.SvnRevInfoDAO
METHOD load
AT ENTRY
BIND entryTime = System.nanoTime();
        thread = Thread.currentThread();
        mapName = "com.cenqua.fisheye.svn.db.SvnRevInfoDAO#load"
IF TRUE
DO link(mapName, thread, entryTime);
ENDRULE

RULE com.cenqua.fisheye.svn.db.SvnRevInfoDAO#load at exit
CLASS com.cenqua.fisheye.svn.db.SvnRevInfoDAO
METHOD load
AT EXIT
BIND exitTime:Long = System.nanoTime();
        thread = Thread.currentThread();
        mapName = "com.cenqua.fisheye.svn.db.SvnRevInfoDAO#load";
        entryTime:Long = Long.parseLong(linked(mapName, thread).toString());
        elapsedTime:Long = exitTime - entryTime
IF TRUE
DO  org.slf4j.LoggerFactory.getLogger("Byteman").info("<- load check: {} - {} = ", Long.toString(exitTime), Long.toString(entryTime));
    org.slf4j.LoggerFactory.getLogger("Byteman").info("<- {}; elapsed time: {} ns", mapName, Long.toString(elapsedTime));
ENDRULE
      • Load the "Activity" page
      • check the Fecru logs

      Sample log output for timer:

      • Repo with 15K branches - took ~9 seconds 
        2023-06-13 05:48:33,950 INFO  [qtp1472216456-2450 url: /changelog/multiproject; user: admin ] Byteman GeneratedMethodAccessor927-invoke - <- com.cenqua.fisheye.cache.BaseDirInfoCache#getLastCommitDate; timer started 
2023-06-13 05:48:43,130 INFO  [qtp1472216456-2450 url: /changelog/multiproject; user: admin ] Byteman GeneratedMethodAccessor927-invoke - <- com.cenqua.fisheye.cache.BaseDirInfoCache#getLastCommitDate; number of orderedRevisions: 15014
2023-06-13 05:48:43,133 INFO  [qtp1472216456-2450 url: /changelog/multiproject; user: admin ] Byteman GeneratedMethodAccessor962-invoke - <- com.cenqua.fisheye.cache.BaseDirInfoCache#getLastCommitDate; timer done - elapsed time: 9183 ms
      • Repo with 28K branches - took ~25 seconds 
        2023-06-13 05:23:28,989 INFO  [qtp1472216456-2439 url: /changelog/smallrepo; user: admin ] Byteman GeneratedMethodAccessor927-invoke - <- com.cenqua.fisheye.cache.BaseDirInfoCache#getLastCommitDate; timer started 
2023-06-13 05:23:54,795 INFO  [qtp1472216456-2439 url: /changelog/smallrepo; user: admin ] Byteman GeneratedMethodAccessor927-invoke - <- com.cenqua.fisheye.cache.BaseDirInfoCache#getLastCommitDate; number of orderedRevisions: 28665
2023-06-13 05:23:54,798 INFO  [qtp1472216456-2439 url: /changelog/smallrepo; user: admin ] Byteman GeneratedMethodAccessor962-invoke - <- com.cenqua.fisheye.cache.BaseDirInfoCache#getLastCommitDate; timer done - elapsed time: 25809 ms

      Workaround

      • Enable Byteman
      • Load the following Byteman script to disable the "Last Commit" date calculation 
        RULE com.cenqua.fisheye.web.ChangelogServlet#determineLastCommitUsingWaybackSpec at entry
CLASS com.cenqua.fisheye.web.ChangelogServlet
METHOD determineLastCommitUsingWaybackSpec
AT ENTRY
IF TRUE
DO 
org.slf4j.LoggerFactory.getLogger("Byteman").info("<- com.cenqua.fisheye.web.ChangelogServlet#determineLastCommitUsingWaybackSpec; last commit calc disabled");
return null;
ENDRULE

        When this rule is loaded, the "Stats > Last Commit" date field will be empty in the "Activity" page for all repos.

      Attachments

        1. manyBranches.png
          manyBranches.png
          180 kB
        2. manyCommits2Branch.png
          manyCommits2Branch.png
          171 kB
        3. manyCommitsActivity.png
          manyCommitsActivity.png
          163 kB

        Issue Links

          has a derivative of

          Suggestion - FE-7498 Asynchronous Last Commit Date for Activity and Project View

          • Gathering Interest
          mentioned in

          Page Loading...

          Page Loading...

          Page Loading...

          Page Loading...

          Activity

            People

              nhansberry Nate Hansberry
              jmariano@atlassian.com JP Mariano
              Votes:
              2 Vote for this issue
              Watchers:
              10 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved:

                Time Tracking

                  Estimated:
                  Original Estimate - Not Specified
                  Not Specified
                  Remaining:
                  Time Spent - 40.75h Remaining Estimate - 47.5h
                  47.5h
                  Logged:
                  Time Spent - 40.75h Remaining Estimate - 47.5h
                  40.75h