Uploaded image for project: 'IMPALA'
  1. IMPALA
  2. IMPALA-4609

Make it clear that fragment thread counters are totals across all threads

    Details

    • Type: Bug
    • Status: Resolved
    • Priority: Critical
    • Resolution: Fixed
    • Affects Version/s: Impala 2.8.0
    • Fix Version/s: Impala 2.8.0
    • Component/s: Backend
    • Labels:

      Description

      In profiles there is no way for users to know that TotalWallClockTime refers to the total across all fragment threads. We should prefix the counters with a name that makes this clear.

       Averaged Fragment F00:(Total: 56s192ms, non-child: 0.000ns, % non-child: 0.00%)
            split sizes:  min: 18.14 GB, max: 18.31 GB, avg: 18.22 GB, stddev: 49.03 MB
            completion times: min:1m58s  max:2m20s  mean: 2m10s  stddev:8s108ms
            execution rates: min:133.10 MB/sec  max:157.85 MB/sec  mean:143.78 MB/sec  stddev:8.78 MB/sec
            num instances: 7
             - AverageThreadTokens: 6.55 
             - BloomFilterBytes: 1.00 MB (1048576)
             - InvoluntaryContextSwitches: 25.35K (25352)
             - PeakMemoryUsage: 15.75 GB (16908711123)
             - PerHostPeakMemUsage: 35.00 GB (37578534499)
             - RowsProduced: 69.25M (69246528)
             - TotalNetworkReceiveTime: 6s389ms
             - TotalNetworkSendTime: 4s881ms
             - TotalStorageWaitTime: 1s267ms
             - TotalWallClockTime: 14m17s
               - SysTime: 36s266ms
               - UserTime: 2m16s
             - VoluntaryContextSwitches: 1.00M (1000378)
            Fragment Instance Lifecycle Timings:
               - ExecTime: 1m14s
                 - ExecTreeExecTime: 45s547ms
               - OpenTime: 56s148ms
                 - ExecTreeOpenTime: 55s686ms
               - PrepareTime: 44.668ms
                 - ExecTreePrepareTime: 2.667ms
      

        Activity

        Hide
        tarmstrong Tim Armstrong added a comment -

        Henry Robinson suggested that "Speaking of which, completely agree that TotalWallClockTime is accurately, but badly named. Elsewhere in the profile we annotate non-wall-clock times with "" (e.g. SendersBlockedTotalTimer). How about "SumAllThreadWallClockTime" as a better, but clunky name?"

        Show
        tarmstrong Tim Armstrong added a comment - Henry Robinson suggested that "Speaking of which, completely agree that TotalWallClockTime is accurately, but badly named. Elsewhere in the profile we annotate non-wall-clock times with " " (e.g. SendersBlockedTotalTimer). How about "SumAllThreadWallClockTime" as a better, but clunky name?"
        Hide
        tarmstrong Tim Armstrong added a comment -

        IMPALA-4609: prefix thread counters in fragment profile

        This adds a prefix to the counter names so that it's more obvious that
        the thread counters are aggregates across all fragment threads.

        Example output for "select * from tpch_parquet.lineitem where l_orderkey < 0":

        Averaged Fragment F00:(Total: 102.949ms, non-child: 0.000ns, % non-child: 0.00%)
        split sizes: min: 55.70 MB, max: 69.10 MB, avg: 64.54 MB, stddev: 6.25 MB
        completion times: min:4s629ms max:5s542ms mean: 5s197ms stddev:404.911ms
        execution rates: min:12.03 MB/sec max:12.69 MB/sec mean:12.40 MB/sec stddev:281.88 KB/sec
        num instances: 3

        • AverageThreadTokens: 2.00
        • BloomFilterBytes: 0
        • PeakMemoryUsage: 88.46 MB (92753209)
        • PerHostPeakMemUsage: 88.46 MB (92755940)
        • RowsProduced: 0 (0)
        • TotalNetworkReceiveTime: 0.000ns
        • TotalNetworkSendTime: 307.000ns
        • TotalStorageWaitTime: 414.738ms
        • TotalThreadsInvoluntaryContextSwitches: 62 (62)
        • TotalThreadsTotalWallClockTime: 10s228ms
        • TotalThreadsSysTime: 118.666ms
        • TotalThreadsUserTime: 4s630ms
        • TotalThreadsVoluntaryContextSwitches: 174 (174)

        Change-Id: Icb8cfbddc758d06b25a14343310bfd9a932ad1f0
        Reviewed-on: http://gerrit.cloudera.org:8080/5392
        Reviewed-by: Tim Armstrong <tarmstrong@cloudera.com>
        Tested-by: Impala Public Jenkins

        Show
        tarmstrong Tim Armstrong added a comment - IMPALA-4609 : prefix thread counters in fragment profile This adds a prefix to the counter names so that it's more obvious that the thread counters are aggregates across all fragment threads. Example output for "select * from tpch_parquet.lineitem where l_orderkey < 0": Averaged Fragment F00:(Total: 102.949ms, non-child: 0.000ns, % non-child: 0.00%) split sizes: min: 55.70 MB, max: 69.10 MB, avg: 64.54 MB, stddev: 6.25 MB completion times: min:4s629ms max:5s542ms mean: 5s197ms stddev:404.911ms execution rates: min:12.03 MB/sec max:12.69 MB/sec mean:12.40 MB/sec stddev:281.88 KB/sec num instances: 3 AverageThreadTokens: 2.00 BloomFilterBytes: 0 PeakMemoryUsage: 88.46 MB (92753209) PerHostPeakMemUsage: 88.46 MB (92755940) RowsProduced: 0 (0) TotalNetworkReceiveTime: 0.000ns TotalNetworkSendTime: 307.000ns TotalStorageWaitTime: 414.738ms TotalThreadsInvoluntaryContextSwitches: 62 (62) TotalThreadsTotalWallClockTime: 10s228ms TotalThreadsSysTime: 118.666ms TotalThreadsUserTime: 4s630ms TotalThreadsVoluntaryContextSwitches: 174 (174) Change-Id: Icb8cfbddc758d06b25a14343310bfd9a932ad1f0 Reviewed-on: http://gerrit.cloudera.org:8080/5392 Reviewed-by: Tim Armstrong <tarmstrong@cloudera.com> Tested-by: Impala Public Jenkins

          People

          • Assignee:
            tarmstrong Tim Armstrong
            Reporter:
            tarmstrong Tim Armstrong
          • Votes:
            0 Vote for this issue
            Watchers:
            1 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved:

              Development