Uploaded image for project: 'Bitbucket Server'
  1. Bitbucket Server
  2. BSERV-11720

Improve profiling logging by combining adjacent frames for the same timer

    XMLWordPrintable

    Details

    • Feedback Policy:
      We collect Bitbucket feedback from various sources, and we evaluate what we've collected when planning our product roadmap. To understand how this piece of feedback will be reviewed, see our Implementation of New Features Policy.

      Description

      Problem Definition

      The analysis of the profiling logs can be more difficult in cases when:

      • the same request is performed multiple times
      • such request completes very quickly

      In the example below, we can see that the /rest/api/latest/users request completed in over 10 seconds but the individual lines don't sum up to that value:

      [10383ms] - "GET /rest/api/latest/users HTTP/1.1"
        [6ms] - ApplicationUser com.atlassian.bitbucket.user.UserService.getUserById(int)
        [7ms] - Page com.atlassian.bitbucket.user.UserService.findGroupsByUser(String,PageRequest)
      ... 268 lines of
        [1ms] - Page com.atlassian.stash.internal.user.EffectivePermissionDao.findByGroup(String,PageRequest)
      

      What is happening here is that many com.atlassian.stash.internal.user.EffectivePermissionDao.findByGroup operations are being performed but, because they are faster than 1ms, they are not logged.

      The problem with the current implementation is:

      • it is not clear why the request is taking that amount of time
      • operations faster than 1ms are not logged
      • we cannot determine how many fast operations are being performed and how long they take on average

      Suggested Solution

      Combine adjacent frames for the same timer and:

      • show their count
      • add a calculate average of each frame

      The profiling log above would now look like the following:

      [10383ms] - "GET /rest/api/latest/users HTTP/1.1"
        [6ms] - ApplicationUser com.atlassian.bitbucket.user.UserService.getUserById(int)
        [7ms] - Page com.atlassian.bitbucket.user.UserService.findGroupsByUser(String,PageRequest)
      [10370ms] [count: 1728, avg: 0.6ms] -  Page com.atlassian.stash.internal.user.EffectivePermissionDao.findByGroup(String,PageRequest)
      

        Attachments

          Activity

            People

            Assignee:
            Unassigned
            Reporter:
            ccurti Caterina Curti
            Votes:
            0 Vote for this issue
            Watchers:
            0 Start watching this issue

              Dates

              Created:
              Updated:
              Resolved: