Re: [PATCH v2 1/1] scripts/performance: Add dissect.py script

[Ahmed Karaman]

On Wed, Jul 8, 2020 at 5:41 PM Philippe Mathieu-Daudé <philmd@redhat.com> wrote:
>
> Hi Ahmed,
>
> On 7/2/20 4:29 PM, Ahmed Karaman wrote:
> > Python script that dissects QEMU execution into three main phases:
> > code generation, JIT execution and helpers execution.
> >
> > Syntax:
> > dissect.py [-h] -- <qemu executable> [<qemu executable options>] \
> >                  <target executable> [<target executable options>]
> >
> > [-h] - Print the script arguments help message.
> >
> > Example of usage:
> > dissect.py -- qemu-arm coulomb_double-arm
> >
> > Example output:
> > Total Instructions:        4,702,865,362
> >
> > Code Generation:             115,819,309       2.463%
> > JIT Execution:             1,081,980,528      23.007%
> > Helpers:                   3,505,065,525      74.530%
> >
> > Signed-off-by: Ahmed Karaman <ahmedkhaledkaraman@gmail.com>
> > ---
> >  scripts/performance/dissect.py | 165 +++++++++++++++++++++++++++++++++
> >  1 file changed, 165 insertions(+)
> >  create mode 100755 scripts/performance/dissect.py
> >
> > diff --git a/scripts/performance/dissect.py b/scripts/performance/dissect.py
> > new file mode 100755
> > index 0000000000..8c2967d082
> > --- /dev/null
> > +++ b/scripts/performance/dissect.py
> > @@ -0,0 +1,165 @@
> > +#!/usr/bin/env python3
> > +
> > +#  Print the percentage of instructions spent in each phase of QEMU
> > +#  execution.
> > +#
> > +#  Syntax:
> > +#  dissect.py [-h] -- <qemu executable> [<qemu executable options>] \
> > +#                   <target executable> [<target executable options>]
> > +#
> > +#  [-h] - Print the script arguments help message.
> > +#
> > +#  Example of usage:
> > +#  dissect.py -- qemu-arm coulomb_double-arm
> > +#
> > +#  This file is a part of the project "TCG Continuous Benchmarking".
> > +#
> > +#  Copyright (C) 2020  Ahmed Karaman <ahmedkhaledkaraman@gmail.com>
> > +#  Copyright (C) 2020  Aleksandar Markovic 
> > <aleksandar.qemu.devel@gmail.com>
> > +#
> > +#  This program is free software: you can redistribute it and/or modify
> > +#  it under the terms of the GNU General Public License as published by
> > +#  the Free Software Foundation, either version 2 of the License, or
> > +#  (at your option) any later version.
> > +#
> > +#  This program is distributed in the hope that it will be useful,
> > +#  but WITHOUT ANY WARRANTY; without even the implied warranty of
> > +#  MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
> > +#  GNU General Public License for more details.
> > +#
> > +#  You should have received a copy of the GNU General Public License
> > +#  along with this program. If not, see <https://www.gnu.org/licenses/>.
> > +
> > +import argparse
> > +import os
> > +import subprocess
> > +import sys
> > +
> > +
> > +def get_JIT_line(callgrind_data):
> > +    """
> > +    Search for the first instance of the JIT call in
> > +    the callgrind_annotate output when ran using --tree=caller
> > +    This is equivalent to the self number of instructions of JIT.
> > +
> > +    Parameters:
> > +    callgrind_data (list): callgrind_annotate output
> > +
> > +    Returns:
> > +    (int): Line number
> > +   """
>
> Alignment off by 1 ;)

Thanks, didn't notice that!

>
> > +    line = -1
> > +    for i in range(len(callgrind_data)):
> > +        if callgrind_data[i].strip('\n') and \
> > +                callgrind_data[i].split()[-1] == "[???]":
> > +            line = i
> > +            break
> > +    if line == -1:
> > +        sys.exit("Couldn't locate the JIT call ... Exiting.")
> > +    return line
> > +
> > +
> > +def main():
> > +    # Parse the command line arguments
> > +    parser = argparse.ArgumentParser(
> > +        usage='dissect.py [-h] -- '
> > +        '<qemu executable> [<qemu executable options>] '
> > +        '<target executable> [<target executable options>]')
> > +
> > +    parser.add_argument('command', type=str, nargs='+', 
> > help=argparse.SUPPRESS)
> > +
> > +    args = parser.parse_args()
> > +
> > +    # Extract the needed variables from the args
> > +    command = args.command
> > +
> > +    # Insure that valgrind is installed
> > +    check_valgrind = subprocess.run(
> > +        ["which", "valgrind"], stdout=subprocess.DEVNULL)
> > +    if check_valgrind.returncode:
> > +        sys.exit("Please install valgrind before running the script.")
> > +
> > +    # Run callgrind
> > +    callgrind = subprocess.run((["valgrind",
> > +                                 "--tool=callgrind",
> > +                                 
> > "--callgrind-out-file=/tmp/callgrind.data"]
>
> Maybe "/path/to/callgrind.data" in the help?

The user doesn't need to provide this path to the script. Callgrind
output is generated automatically for them.

>
> > +                                + command),
> > +                               stdout=subprocess.DEVNULL,
> > +                               stderr=subprocess.PIPE)
> > +    if callgrind.returncode:
> > +        sys.exit(callgrind.stderr.decode("utf-8"))
> > +
> > +    # Save callgrind_annotate output to /tmp/callgrind_annotate.out
>
> 1/ You use these files multiples time, please use a variable for each.
> 2/ This won't work on Windows
> 3/ This bypass the TMPDIR envirnoment variable
>   a/ Darwin sets it to /var/folders/$user/$random/
>   b/ Some users prefer to set TMPDIR on dedicated fast memory support
>
> This is more portable:
>
>   import tempfile
>
>   annotated_path = os.path.join(tempfile.gettempdir(),
>                                 "callgrind_annotate.out")
>   data_path = os.path.join(tempfile.gettempdir(), "callgrind.data")
>
> Now, apparently both are temporary, so you can use a context manager
> to get a temporary directory, and the context manager will remove it
> when you are done.
>
> Something like:
>
>        with tempfile.TemporaryDirectory() as tmpdirname:
>            annotated_path = os.path.join(tmpdirname,
>                                          "callgrind_annotate.out")
>            data_path = os.path.join(tmpdirname, "callgrind.data")
>
>            with open(annotated_path, "w") as output:
>                 ....
>
> No need to unlink/rmdir.

This is a very nice trick! Thanks for the suggestion.

>
> > +    with open("/tmp/callgrind_annotate.out", "w") as output:
> > +        callgrind_annotate = subprocess.run(
> > +            ["callgrind_annotate", "/tmp/callgrind.data", "--tree=caller"],
> > +            stdout=output,
> > +            stderr=subprocess.PIPE)
> > +        if callgrind_annotate.returncode:
> > +            os.unlink('/tmp/callgrind.data')
>
> Maybe display a hint to the user? "Something went wrong. Is
> callgrind_annotate installed?"

callgrind_annotate is already installed by default with Valgrind. An
error happening here might be because of an empty callgrind output.

>
> > +            output.close()
>
> You used a context manager (with open ...) so no need to call close(),
> it will be called when you are done with the context.
>
> > +            os.unlink('/tmp/callgrind_annotate.out')
> > +            sys.exit(callgrind_annotate.stderr.decode("utf-8"))
> > +
> > +    # Read the callgrind_annotate output to callgrind_data[]
> > +    callgrind_data = []
> > +    with open('/tmp/callgrind_annotate.out', 'r') as data:
> > +        callgrind_data = data.readlines()
>
> Here you didn't call close(), good :)
>
> > +
> > +    # Line number with the total number of instructions
> > +    total_instructions_line_number = 20
> > +    # Get the total number of instructions
> > +    total_instructions_line_data = \
> > +        callgrind_data[total_instructions_line_number]
> > +    total_instructions = total_instructions_line_data.split()[0]
> > +    total_instructions = int(total_instructions.replace(',', ''))
> > +
> > +    # Line number with the JIT self number of instructions
> > +    JIT_self_instructions_line_number = get_JIT_line(callgrind_data)
> > +    # Get the JIT self number of instructions
> > +    JIT_self_instructions_line_data = \
> > +        callgrind_data[JIT_self_instructions_line_number]
> > +    JIT_self_instructions = JIT_self_instructions_line_data.split()[0]
> > +    JIT_self_instructions = int(JIT_self_instructions.replace(',', ''))
> > +
> > +    # Line number with the JIT self + inclusive number of instructions
> > +    # It's the line above the first JIT call when running with 
> > --tree=caller
> > +    JIT_total_instructions_line_number = JIT_self_instructions_line_number 
> > - 1
> > +    # Get the JIT self + inclusive number of instructions
> > +    JIT_total_instructions_line_data = \
> > +        callgrind_data[JIT_total_instructions_line_number]
> > +    JIT_total_instructions = JIT_total_instructions_line_data.split()[0]
> > +    JIT_total_instructions = int(JIT_total_instructions.replace(',', ''))
> > +
> > +    # Calculate number of instructions in helpers and code generation
> > +    helpers_instructions = JIT_total_instructions - JIT_self_instructions
> > +    code_generation_instructions = total_instructions - 
> > JIT_total_instructions
> > +
> > +    # Print results (Insert commas in large numbers)
> > +    # Print total number of instructions
> > +    print('{:<20}{:>20}\n'.
> > +          format("Total Instructions:",
> > +                 format(total_instructions, ',')))
> > +    # Print code generation instructions and percentage
> > +    print('{:<20}{:>20}\t{:>6.3f}%'.
> > +          format("Code Generation:",
> > +                 format(code_generation_instructions, ","),
> > +                 (code_generation_instructions / total_instructions) * 
> > 100))
> > +    # Print JIT instructions and percentage
> > +    print('{:<20}{:>20}\t{:>6.3f}%'.
> > +          format("JIT Execution:",
> > +                 format(JIT_self_instructions, ","),
> > +                 (JIT_self_instructions / total_instructions) * 100))
> > +    # Print helpers instructions and percentage
> > +    print('{:<20}{:>20}\t{:>6.3f}%'.
> > +          format("Helpers:",
> > +                 format(helpers_instructions, ","),
> > +                 (helpers_instructions/total_instructions)*100))
> > +
> > +    # Remove intermediate files
> > +    os.unlink('/tmp/callgrind.data')
> > +    os.unlink('/tmp/callgrind_annotate.out')
>
> No need for these unlink if using tempfile.TemporaryDirectory().
>
> Regards,
>
> Phil.
>
> > +
> > +
> > +if __name__ == "__main__":
> > +    main()
> >
>

Thanks a lot Mr. Philippe for your feedback. I'll post a v3 with the updates.

Best regards,
Ahmed Karaman