CoreSight

coresight@lists.linaro.org

7 participants
2372 discussions

Re: [PATCH v2 1/3] coresight: cti: use device_* to iterate over device child nodes

by Mike Leach

On Thu, 8 Aug 2024 at 16:12, Javier Carrasco <javier.carrasco.cruz(a)gmail.com> wrote: > > Drop the manual access to the fwnode of the device to iterate over its > child nodes. `device_for_each_child_node` macro provides direct access > to the child nodes, and given that they are only required within the > loop, the scoped variant of the macro can be used. > > Use the `device_for_each_child_node_scoped` macro to iterate over the > direct child nodes of the device. > > Signed-off-by: Javier Carrasco <javier.carrasco.cruz(a)gmail.com> > --- > drivers/hwtracing/coresight/coresight-cti-platform.c | 10 +++------- > 1 file changed, 3 insertions(+), 7 deletions(-) > > diff --git a/drivers/hwtracing/coresight/coresight-cti-platform.c b/drivers/hwtracing/coresight/coresight-cti-platform.c > index ccef04f27f12..d0ae10bf6128 100644 > --- a/drivers/hwtracing/coresight/coresight-cti-platform.c > +++ b/drivers/hwtracing/coresight/coresight-cti-platform.c > @@ -416,20 +416,16 @@ static int cti_plat_create_impdef_connections(struct device *dev, > struct cti_drvdata *drvdata) > { > int rc = 0; > - struct fwnode_handle *fwnode = dev_fwnode(dev); > - struct fwnode_handle *child = NULL; > > - if (IS_ERR_OR_NULL(fwnode)) > + if (IS_ERR_OR_NULL(dev_fwnode(dev))) > return -EINVAL; > > - fwnode_for_each_child_node(fwnode, child) { > + device_for_each_child_node_scoped(dev, child) { > if (cti_plat_node_name_eq(child, CTI_DT_CONNS)) > - rc = cti_plat_create_connection(dev, drvdata, > - child); > + rc = cti_plat_create_connection(dev, drvdata, child); > if (rc != 0) > break; > } > - fwnode_handle_put(child); > > return rc; > } > > -- > 2.43.0 > Reviewed-by: Mike Leach <mike.leach(a)linaro.org> -- Mike Leach Principal Engineer, ARM Ltd. Manchester Design Centre. UK

10 months, 1 week

[PATCH v2 0/2] coresight: Add remote etm support

by Mao Jinlong

The system on chip (SoC) consists of main APSS(Applications processor subsytem) and additional processors like modem, lpass. There is coresight-etm driver for etm trace of APSS. Coresight remote etm driver is for enabling and disabling the etm trace of remote processors. It uses QMI interface to communicate with remote processors' software and uses coresight framework to configure the connection from remote etm source to TMC sinks. Example to capture the remote etm trace: Enable source: echo 1 > /sys/bus/coresight/devices/tmc_etf0/enable_sink echo 1 > /sys/bus/coresight/devices/remote_etm0/enable_source Capture the trace: cat /dev/tmc_etf0 > /data/remote_etm.bin Disable source: echo 0 > /sys/bus/coresight/devices/remote_etm0/enable_source Changes since V1: 1. Remove unused content 2. Use CORESIGHT_DEV_SUBTYPE_SOURCE_OTHERS as remote etm source type. 3. Use enabled instead of enable in driver data. 4. Validate instance id value where it's read from the DT. Mao Jinlong (2): dt-bindings: arm: Add qcom,inst-id for remote etm coresight: Add remote etm support .../arm/qcom,coresight-remote-etm.yaml | 10 + drivers/hwtracing/coresight/Kconfig | 13 + drivers/hwtracing/coresight/Makefile | 1 + drivers/hwtracing/coresight/coresight-qmi.h | 89 +++++ .../coresight/coresight-remote-etm.c | 308 ++++++++++++++++++ 5 files changed, 421 insertions(+) create mode 100644 drivers/hwtracing/coresight/coresight-qmi.h create mode 100644 drivers/hwtracing/coresight/coresight-remote-etm.c -- 2.41.0

10 months, 1 week

[PATCH v2 0/3] Add source filtering for multi-port output

by Tao Zhang

In our hardware design, by combining a funnel and a replicator, it implement a hardware device with one-to-one correspondence between output ports and input ports. The programming usage on this device is the same as funnel. The software uses a funnel and a static replicator to implement the driver of this device. Since original funnels only support a single output connection and original replicator only support a single input connection, the code needs to be modified to support this new feature. The following is a typical topology diagram of multi-port output mechanism. |----------| |---------| |----------| |---------| | TPDM 0 | | Source0 | | Source 1 | | TPDM 1 | |----------| |---------| |----------| |---------| | | | | | | | | | --------- | | | | | | | | | | | | | | | \-------------/ ---------------------- | \ Funnel 0 / | | ----------- | ------------------------------ | | | | | | \------------------/ \ Funnel 1 / ----| \--------------/ | | |----> Combine a funnel and a | | static replicator /-----------------\ | / replicator 0 \ ----| /---------------------\ | | | | | |-----------| | |---------| | | |TPDM0 |TPDM1 | \-----------------/ | \ TPDA 0 / | \-------------/ | | | | |Source0/1 | \-------------------------------/ \ Funnel 2 / \---------------------------/ Changes in V2: 1. Change the reference for endpoint property in dt-binding. -- Krzysztof Kozlowski 2. Change the property name "filter_src" to "filter-src". -- Krzysztof Kozlowski 3. Fix the errors in running 'make dt_binding_check'. -- Rob Herring 4. Pass in the source parameter instead of path. -- Suzuki K Poulose 5. Reset the "filter_src_dev" if the "src" csdev is being removed. -- Suzuki K Poulose 6. Add a warning if the "filter_src_dev" is of not the type DEV_TYPE_SOURCE. -- Suzuki K Poulose 7. Optimize the procedure for handling all possible cases. -- Suzuki K Poulose Changes in V1: 1. Add a static replicator connect to a funnel to implement the correspondence between the output ports and the input ports on funnels. -- Suzuki K Poulose 2. Add filter_src_dev and filter_src_dev phandle to "coresight_connection" struct, and populate them if there is one. -- Suzuki K Poulose 3. To look at the phandle and then fixup/remove the filter_src device in fixup/remove connections. -- Suzuki K Poulose 4. When TPDA reads DSB/CMB element size, it is implemented by looking up filter src device in the connections. -- Suzuki K Poulose Tao Zhang (3): dt-bindings: arm: qcom,coresight-static-replicator: Add property for source filtering coresight: Add source filtering for multi-port output coresight-tpda: Optimize the function of reading element size .../arm/arm,coresight-static-replicator.yaml | 19 ++- drivers/hwtracing/coresight/coresight-core.c | 125 ++++++++++++++++-- .../hwtracing/coresight/coresight-platform.c | 18 +++ drivers/hwtracing/coresight/coresight-tpda.c | 3 +- include/linux/coresight.h | 5 + 5 files changed, 155 insertions(+), 15 deletions(-) -- 2.17.1

10 months, 2 weeks

Re: [PATCH v1 3/9] perf auxtrace: Refactor auxtrace__evsel_is_auxtrace()

by James Clark

On 08/08/2024 1:58 pm, Adrian Hunter wrote: > On 6/08/24 23:41, Leo Yan wrote: >> The auxtrace__evsel_is_auxtrace() function invokes the callback >> .evsel_is_auxtrace() to check if an event is an AUX trace. In the >> low-level code, every AUX trace module provides its callback to >> compare the PMU type. >> >> This commit refactors auxtrace__evsel_is_auxtrace() by simply >> calling evsel__is_aux_event() rather than using the callback function. >> As a result, the callback .evsel_is_auxtrace() is no longer needed, so >> the definition and implementations are removed. > > evsel__is_aux_event() assumes it is on the target machine e.g. > being called from perf record. It indirectly reads from sysfs > to find PMUs, which will not necessarily be the same a different > machine. > > For example, what happens if a perf data file from one arch is > being processed on a machine from another arch. > I think this does go a bit wrong. If I open an SPE file on x86 it finds the intel_pt PMU which both have the same type number. But because that's also an auxtrace one it appears to work.

10 months, 2 weeks

Re: [PATCH] perf scripts python arm-cs-trace-disasm.py: Skip disasm if address continuity is broken

by Mike Leach

On Thu, 8 Aug 2024 at 12:15, Ganapatrao Kulkarni <gankulkarni(a)os.amperecomputing.com> wrote: > > > > On 08-08-2024 04:21 pm, James Clark wrote: > > > > > > On 08/08/2024 10:21 am, James Clark wrote: > >> > >> > >> On 08/08/2024 8:42 am, Leo Yan wrote: > >>> On 8/8/2024 5:36 AM, Ganapatrao Kulkarni wrote: > >>>> > >>>> On 08-08-2024 12:50 am, Leo Yan wrote: > >>>>> On 8/7/2024 5:18 PM, Ganapatrao Kulkarni wrote: > >>>>> > >>>>>> Is below diff with force option looks good? > >>>>>> > >>>>>> diff --git a/tools/perf/scripts/python/arm-cs-trace-disasm.py > >>>>>> b/tools/perf/scripts/python/arm-cs-trace-disasm.py > >>>>>> index d973c2baed1c..efe34f308beb 100755 > >>>>>> --- a/tools/perf/scripts/python/arm-cs-trace-disasm.py > >>>>>> +++ b/tools/perf/scripts/python/arm-cs-trace-disasm.py > >>>>>> @@ -36,7 +36,10 @@ option_list = [ > >>>>>> help="Set path to objdump executable file"), > >>>>>> make_option("-v", "--verbose", dest="verbose", > >>>>>> action="store_true", default=False, > >>>>>> - help="Enable debugging log") > >>>>>> + help="Enable debugging log"), > >>>>>> + make_option("-f", "--force", dest="force", > >>>>>> + action="store_true", default=False, > >>>>>> + help="Force decoder to continue") > >>>>>> ] > >>>>>> > >>>>>> parser = OptionParser(option_list=option_list) > >>>>>> @@ -257,6 +260,12 @@ def process_event(param_dict): > >>>>>> print("Stop address 0x%x is out of range [ 0x%x > >>>>>> .. 0x%x > >>>>>> ] for dso %s" % (stop_addr, int(dso_start), int(dso_end), dso)) > >>>>>> return > >>>>>> > >>>>>> + if (stop_addr < start_addr): > >>>>>> + if (options.verbose == True or options.force): > >>>>>> + print("Packet Discontinuity detected > >>>>>> [stop_add:0x%x start_addr:0x%x ] for dso %s" % (stop_addr, > >>>>>> start_addr, dso)) > >> > >> The options.force for the print should be "options.verbose or not > >> options.force" I think? You want to print the error until the user > >> adds -f, then hide it. Unless verbose is on. > >> > >>>>>> + if (options.force): > >>>>>> + return > >> > >> Oops I had this one the wrong way around in my example. This way is > >> correct. > >> > >>>>> > >>>>> I struggled a bit for the code - it is confused that force mode > >>>>> bails out > >>>>> and the non-force mode continues to run. I prefer to always bail > >>>>> out for > >>>>> the discontinuity case, as it is pointless to continue in this case. > >>>> > >>>> Kept bail out with force option since I though it is not good to hide > >>>> the error in normal use, otherwise we never able to notice this > >>>> error in > >>>> the future and it becomes default hidden. Eventually this error should > >>>> be fixed. > >>> > >>> As James said, the issue should be fixed in OpenCSD or Perf decoding > >>> flow. > >>> > >>> Thus, perf tool should be tolerant errors - report warning and drop > >>> discontinuous samples. This would be easier for developers later if face > >>> the same issue, they don't need to spend time to locate issue and > >>> struggle > >>> for overriding the error. > >>> > >>> If you prefer to use force option, it might be better to give > >>> reasoning and > >>> *suggestion* in one go, something like: > >>> > >>> if (stop_addr < start_addr): > >>> print("Packet Discontinuity detected [stop_add:0x%x > >>> start_addr:0x%x ] for dso %s" % (stop_addr, start_addr, dso)) > >>> print("Use option '-f' following the script for force mode" > >>> if (options.force) > >>> return > >>> > >>> Either way is fine for me. Thanks a lot for taking time on the issue. > >>> > >>> Leo > >> > >> But your diff looks good Ganapat, I think send a patch with Leo's > >> extra help message added and the first force flipped. > > > > One other small detail about Leo's suggestion print out. Can you add an > > instruction of how to keep the warnings as well: > > > > print("Use option '-f' following the script for force mode. Add '-v' \ > > to continue printing decode warnings.") > > > > Thanks James and Leo for your comments. > I will send the V2 with the changes as discussed. > > Thanks. > Ganapat > Certainly any ARM trace decode is dependent on accurate program images being input to provide correct trace decode at the output. So if an OpenCSD client does not provide accurate information then it should not really expect to get accurate trace as an output! That said there are certainly a couple of changes that can be made:- 1) Clearly outputting a trace range with a finish address lower than the start address is incorrect. This can unconditionally output a hard error. 2) Detection of non-cond not taken should be added as a configurable option. - either all, or direct only. This can be achieved by adding flags to the library configuration API. For a client like perf - these could be controlled by the verbose level - which I believe is an int in the range 0-10 or something? However - when we do detect these errors, it is essential that the entire decoder is reset and tracing not restarted till the next sync point in the trace data. i.e. assuming that the next range that happens to be consecutive after a break, given a prior input of incorrect address data is simply invalid. There is no way of knowing if the branch taken / not taken sequence matches the addresses in the program image any more. The solution that James proposes above, needs to actually generate an error which will then automatically reset the decoder to an unsynced state. Regards Mike -- Mike Leach Principal Engineer, ARM Ltd. Manchester Design Centre. UK

10 months, 2 weeks

Re: [PATCH] perf scripts python arm-cs-trace-disasm.py: Skip disasm if address continuity is broken

by James Clark

On 08/08/2024 8:42 am, Leo Yan wrote: > On 8/8/2024 5:36 AM, Ganapatrao Kulkarni wrote: >> >> On 08-08-2024 12:50 am, Leo Yan wrote: >>> On 8/7/2024 5:18 PM, Ganapatrao Kulkarni wrote: >>> >>>> Is below diff with force option looks good? >>>> >>>> diff --git a/tools/perf/scripts/python/arm-cs-trace-disasm.py >>>> b/tools/perf/scripts/python/arm-cs-trace-disasm.py >>>> index d973c2baed1c..efe34f308beb 100755 >>>> --- a/tools/perf/scripts/python/arm-cs-trace-disasm.py >>>> +++ b/tools/perf/scripts/python/arm-cs-trace-disasm.py >>>> @@ -36,7 +36,10 @@ option_list = [ >>>> help="Set path to objdump executable file"), >>>> make_option("-v", "--verbose", dest="verbose", >>>> action="store_true", default=False, >>>> - help="Enable debugging log") >>>> + help="Enable debugging log"), >>>> + make_option("-f", "--force", dest="force", >>>> + action="store_true", default=False, >>>> + help="Force decoder to continue") >>>> ] >>>> >>>> parser = OptionParser(option_list=option_list) >>>> @@ -257,6 +260,12 @@ def process_event(param_dict): >>>> print("Stop address 0x%x is out of range [ 0x%x .. 0x%x >>>> ] for dso %s" % (stop_addr, int(dso_start), int(dso_end), dso)) >>>> return >>>> >>>> + if (stop_addr < start_addr): >>>> + if (options.verbose == True or options.force): >>>> + print("Packet Discontinuity detected [stop_add:0x%x start_addr:0x%x ] for dso %s" % (stop_addr, start_addr, dso)) The options.force for the print should be "options.verbose or not options.force" I think? You want to print the error until the user adds -f, then hide it. Unless verbose is on. >>>> + if (options.force): >>>> + return Oops I had this one the wrong way around in my example. This way is correct. >>> >>> I struggled a bit for the code - it is confused that force mode bails out >>> and the non-force mode continues to run. I prefer to always bail out for >>> the discontinuity case, as it is pointless to continue in this case. >> >> Kept bail out with force option since I though it is not good to hide >> the error in normal use, otherwise we never able to notice this error in >> the future and it becomes default hidden. Eventually this error should >> be fixed. > > As James said, the issue should be fixed in OpenCSD or Perf decoding flow. > > Thus, perf tool should be tolerant errors - report warning and drop > discontinuous samples. This would be easier for developers later if face > the same issue, they don't need to spend time to locate issue and struggle > for overriding the error. > > If you prefer to use force option, it might be better to give reasoning and > *suggestion* in one go, something like: > > if (stop_addr < start_addr): > print("Packet Discontinuity detected [stop_add:0x%x start_addr:0x%x ] for dso %s" % (stop_addr, start_addr, dso)) > print("Use option '-f' following the script for force mode" > if (options.force) > return > > Either way is fine for me. Thanks a lot for taking time on the issue. > > Leo > But your diff looks good Ganapat, I think send a patch with Leo's extra help message added and the first force flipped.

10 months, 2 weeks

Re: [PATCH] perf scripts python arm-cs-trace-disasm.py: Skip disasm if address continuity is broken

by James Clark

On 07/08/2024 1:17 pm, Ganapatrao Kulkarni wrote: > > > On 06-08-2024 09:44 pm, James Clark wrote: >> >> >> On 06/08/2024 4:02 pm, Steve Clevenger wrote: >>> >>> >>> On 8/6/2024 2:57 AM, James Clark wrote: >>>> >>>> >>>> On 06/08/2024 10:47 am, James Clark wrote: >>>>> >>>>> >>>>> On 06/08/2024 8:02 am, Ganapatrao Kulkarni wrote: >>>>>> >>>>>> >>>>>> On 05-08-2024 07:29 pm, James Clark wrote: >>>>>>> >>>>>>> >>>>>>> On 05/08/2024 1:22 pm, Ganapatrao Kulkarni wrote: >>>>>>>> >>>>>>>> >>>>>>>> On 01-08-2024 03:30 pm, James Clark wrote: >>>>>>>>> >>>>>>>>> >>>>>>>>> On 24/07/2024 3:45 pm, James Clark wrote: >>>>>>>>>> >>>>>>>>>> >>>>>>>>>> On 24/07/2024 7:38 am, Ganapatrao Kulkarni wrote: >>>>>>>>>>> >>>>>>>>>>> >>>>>>>>>>> On 23-07-2024 09:16 pm, James Clark wrote: >>>>>>>>>>>> >>>>>>>>>>>> >>>>>>>>>>>> On 23/07/2024 4:26 pm, Ganapatrao Kulkarni wrote: >>>>>>>>>>>>> >>>>>>>>>>>>> >>>>>>>>>>>>> On 23-07-2024 06:40 pm, James Clark wrote: >>>>>>>>>>>>>> >>>>>>>>>>>>>> >>>>>>>>>>>>>> On 22/07/2024 11:02 am, Ganapatrao Kulkarni wrote: >>>>>>>>>>>>>>> >>>>>>>>>>>>>>> Hi James, >>>>>>>>>>>>>>> >>>>>>>>>>>>>>> On 19-07-2024 08:09 pm, James Clark wrote: >>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>> On 19/07/2024 10:26 am, Ganapatrao Kulkarni wrote: >>>>>>>>>>>>>>>>> To generate the instruction tracing, script uses 2 >>>>>>>>>>>>>>>>> contiguous packets >>>>>>>>>>>>>>>>> address range. If there a continuity brake due to >>>>>>>>>>>>>>>>> discontiguous branch >>>>>>>>>>>>>>>>> address, it is required to reset the tracing and start >>>>>>>>>>>>>>>>> tracing with the >>>>>>>>>>>>>>>>> new set of contiguous packets. >>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>> Adding change to identify the break and complete the >>>>>>>>>>>>>>>>> remaining tracing >>>>>>>>>>>>>>>>> of current packets and restart tracing from new set of >>>>>>>>>>>>>>>>> packets, if >>>>>>>>>>>>>>>>> continuity is established. >>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>> Hi Ganapatrao, >>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>> Can you add a before and after example of what's changed to >>>>>>>>>>>>>>>> the commit message? It wasn't immediately obvious to me if >>>>>>>>>>>>>>>> this is adding missing output, or it was correcting the >>>>>>>>>>>>>>>> tail end of the output that was previously wrong. >>>>>>>>>>>>>>> >>>>>>>>>>>>>>> It is adding tail end of the trace as well avoiding the >>>>>>>>>>>>>>> segfault of the perf application. With out this change the >>>>>>>>>>>>>>> perf segfaults with as below log >>>>>>>>>>>>>>> >>>>>>>>>>>>>>> >>>>>>>>>>>>>>> ./perf script >>>>>>>>>>>>>>> --script=python:./scripts/python/arm-cs-trace-disasm.py -- >>>>>>>>>>>>>>> -d objdump -k ../../vmlinux -v $* > dump >>>>>>>>>>>>>>> objdump: error: the stop address should be after the start >>>>>>>>>>>>>>> address >>>>>>>>>>>>>>> Traceback (most recent call last): >>>>>>>>>>>>>>> File "./scripts/python/arm-cs-trace-disasm.py", line >>>>>>>>>>>>>>> 271, >>>>>>>>>>>>>>> in process_event >>>>>>>>>>>>>>> print_disam(dso_fname, dso_vm_start, start_addr, >>>>>>>>>>>>>>> stop_addr) >>>>>>>>>>>>>>> File "./scripts/python/arm-cs-trace-disasm.py", line >>>>>>>>>>>>>>> 105, >>>>>>>>>>>>>>> in print_disam >>>>>>>>>>>>>>> for line in read_disam(dso_fname, dso_start, >>>>>>>>>>>>>>> start_addr, stop_addr): >>>>>>>>>>>>>>> ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ >>>>>>>>>>>>>>> File "./scripts/python/arm-cs-trace-disasm.py", line 99, >>>>>>>>>>>>>>> in read_disam >>>>>>>>>>>>>>> disasm_output = >>>>>>>>>>>>>>> check_output(disasm).decode('utf-8').split('\n') >>>>>>>>>>>>>>> ^^^^^^^^^^^^^^^^^^^^ >>>>>>>>>>>>>>> File "/usr/lib64/python3.12/subprocess.py", line 466, in >>>>>>>>>>>>>>> check_output >>>>>>>>>>>>>>> return run(*popenargs, stdout=PIPE, timeout=timeout, >>>>>>>>>>>>>>> check=True, >>>>>>>>>>>>>>> ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ >>>>>>>>>>>>>>> File "/usr/lib64/python3.12/subprocess.py", line 571, >>>>>>>>>>>>>>> in run >>>>>>>>>>>>>>> raise CalledProcessError(retcode, process.args, >>>>>>>>>>>>>>> subprocess.CalledProcessError: Command '['objdump', '-d', >>>>>>>>>>>>>>> '-z', '--start-address=0xffff80008125b758', >>>>>>>>>>>>>>> '--stop-address=0xffff80008125a934', '../../vmlinux']' >>>>>>>>>>>>>>> returned non-zero exit status 1. >>>>>>>>>>>>>>> Fatal Python error: handler_call_die: problem in Python >>>>>>>>>>>>>>> trace event handler >>>>>>>>>>>>>>> Python runtime state: initialized >>>>>>>>>>>>>>> >>>>>>>>>>>>>>> Current thread 0x0000ffffb05054e0 (most recent call first): >>>>>>>>>>>>>>> <no Python frame> >>>>>>>>>>>>>>> >>>>>>>>>>>>>>> Extension modules: perf_trace_context, systemd._journal, >>>>>>>>>>>>>>> systemd._reader, systemd.id128, report._py3report, >>>>>>>>>>>>>>> _dbus_bindings, problem._py3abrt (total: 7) >>>>>>>>>>>>>>> Aborted (core dumped) >>>>>>>>>>>>>>> >>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>> Signed-off-by: Ganapatrao Kulkarni >>>>>>>>>>>>>>>>> <gankulkarni(a)os.amperecomputing.com> >>>>>>>>>>>>>>>>> --- >>>>>>>>>>>>>>>>> tools/perf/scripts/python/arm-cs-trace-disasm.py | 10 >>>>>>>>>>>>>>>>> ++++++++++ >>>>>>>>>>>>>>>>> 1 file changed, 10 insertions(+) >>>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>>> diff --git >>>>>>>>>>>>>>>>> a/tools/perf/scripts/python/arm-cs-trace-disasm.py >>>>>>>>>>>>>>>>> b/tools/perf/scripts/python/arm-cs-trace-disasm.py >>>>>>>>>>>>>>>>> index d973c2baed1c..ad10cee2c35e 100755 >>>>>>>>>>>>>>>>> --- a/tools/perf/scripts/python/arm-cs-trace-disasm.py >>>>>>>>>>>>>>>>> +++ b/tools/perf/scripts/python/arm-cs-trace-disasm.py >>>>>>>>>>>>>>>>> @@ -198,6 +198,10 @@ def process_event(param_dict): >>>>>>>>>>>>>>>>> cpu_data[str(cpu) + 'addr'] = addr >>>>>>>>>>>>>>>>> return >>>>>>>>>>>>>>>>> + if (cpu_data.get(str(cpu) + 'ip') == None): >>>>>>>>>>>>>>>>> + cpu_data[str(cpu) + 'ip'] = ip >>>>>>>>>>>>>>>>> + >>>>>>>>>>>>>>>> >>>>>>>>>>>>>>>> Do you need to write into the global cpu_data here? Doesn't >>>>>>>>>>>>>>>> it get overwritten after you load it back into 'prev_ip' >>>>>>>>>>>>>>> >>>>>>>>>>>>>>> No, the logic is same as holding the addr of previous >>>>>>>>>>>>>>> packet. >>>>>>>>>>>>>>> Saving the previous packet saved ip in to prev_ip before >>>>>>>>>>>>>>> overwriting with the current packet. >>>>>>>>>>>>>> >>>>>>>>>>>>>> It's not exactly the same logic as holding the addr of the >>>>>>>>>>>>>> previous sample. For addr, we return on the first None, with >>>>>>>>>>>>>> your change we now "pretend" that the second one is also the >>>>>>>>>>>>>> previous one: >>>>>>>>>>>>>> >>>>>>>>>>>>>> if (cpu_data.get(str(cpu) + 'addr') == None): >>>>>>>>>>>>>> cpu_data[str(cpu) + 'addr'] = addr >>>>>>>>>>>>>> return <----------------------------sample 0 return >>>>>>>>>>>>>> >>>>>>>>>>>>>> if (cpu_data.get(str(cpu) + 'ip') == None): >>>>>>>>>>>>>> cpu_data[str(cpu) + 'ip'] = ip <---- sample 1 save >>>>>>>>>>>>>> but >>>>>>>>>>>>>> no return >>>>>>>>>>>>>> >>>>>>>>>>>>>> Then for sample 1 'prev_ip' is actually now the 'current' IP: >>>>>>>>>>>>> >>>>>>>>>>>>> Yes, it is dummy for first packet. Added anticipating that we >>>>>>>>>>>>> wont hit the discontinuity for the first packet itself. >>>>>>>>>>>>> >>>>>>>>>>>>> Can this be changed to more intuitive like below? >>>>>>>>>>>>> >>>>>>>>>>>>> diff --git a/tools/perf/scripts/python/arm-cs-trace-disasm.py >>>>>>>>>>>>> b/tools/perf/scripts/python/arm-cs-trace-disasm.py >>>>>>>>>>>>> index d973c2baed1c..d49f5090059f 100755 >>>>>>>>>>>>> --- a/tools/perf/scripts/python/arm-cs-trace-disasm.py >>>>>>>>>>>>> +++ b/tools/perf/scripts/python/arm-cs-trace-disasm.py >>>>>>>>>>>>> @@ -198,6 +198,8 @@ def process_event(param_dict): >>>>>>>>>>>>> cpu_data[str(cpu) + 'addr'] = addr >>>>>>>>>>>>> return >>>>>>>>>>>>> >>>>>>>>>>>>> + if (cpu_data.get(str(cpu) + 'ip') != None): >>>>>>>>>>>>> + prev_ip = cpu_data[str(cpu) + 'ip'] >>>>>>>>>>>>> >>>>>>>>>>>>> if (options.verbose == True): >>>>>>>>>>>>> print("Event type: %s" % name) >>>>>>>>>>>>> @@ -243,12 +245,18 @@ def process_event(param_dict): >>>>>>>>>>>>> >>>>>>>>>>>>> # Record for previous sample packet >>>>>>>>>>>>> cpu_data[str(cpu) + 'addr'] = addr >>>>>>>>>>>>> + cpu_data[str(cpu) + 'ip'] = stop_addr >>>>>>>>>>>>> >>>>>>>>>>>>> # Handle CS_ETM_TRACE_ON packet if start_addr=0 and >>>>>>>>>>>>> stop_addr=4 >>>>>>>>>>>>> if (start_addr == 0 and stop_addr == 4): >>>>>>>>>>>>> print("CPU%d: CS_ETM_TRACE_ON packet is >>>>>>>>>>>>> inserted" % cpu) >>>>>>>>>>>>> return >>>>>>>>>>>>> >>>>>>>>>>>>> + if (stop_addr < start_addr and prev_ip != 0): >>>>>>>>>>>>> + # Continuity of the Packets broken, set >>>>>>>>>>>>> start_addr to previous >>>>>>>>>>>>> + # packet ip to complete the remaining tracing >>>>>>>>>>>>> of the address range. >>>>>>>>>>>>> + start_addr = prev_ip >>>>>>>>>>>>> + >>>>>>>>>>>>> if (start_addr < int(dso_start) or start_addr > >>>>>>>>>>>>> int(dso_end)): >>>>>>>>>>>>> print("Start address 0x%x is out of range [ >>>>>>>>>>>>> 0x%x .. 0x%x ] for dso %s" % (start_addr, int(dso_start), >>>>>>>>>>>>> int(dso_end), dso)) >>>>>>>>>>>>> return >>>>>>>>>>>>> >>>>>>>>>>>>> Without this patch below is the failure log(with segfault) for >>>>>>>>>>>>> reference. >>>>>>>>>>>>> >>>>>>>>>>>>> [root@sut01sys-r214 perf]# timeout 4s ./perf record -e >>>>>>>>>>>>> cs_etm// -C 1 dd if=/dev/zero of=/dev/null >>>>>>>>>>>>> [ perf record: Woken up 1 times to write data ] >>>>>>>>>>>>> [ perf record: Captured and wrote 1.087 MB perf.data ] >>>>>>>>>>>>> [root@sut01sys-r214 perf]# ./perf script >>>>>>>>>>>>> --script=python:./scripts/python/arm-cs-trace-disasm.py -- -d >>>>>>>>>>>>> objdump -k ../../vmlinux -v $* > dump >>>>>>>>>>>>> objdump: error: the stop address should be after the start >>>>>>>>>>>>> address >>>>>>>>>>>>> Traceback (most recent call last): >>>>>>>>>>>>> File "./scripts/python/arm-cs-trace-disasm.py", line 271, >>>>>>>>>>>>> in process_event >>>>>>>>>>>>> print_disam(dso_fname, dso_vm_start, start_addr, >>>>>>>>>>>>> stop_addr) >>>>>>>>>>>>> File "./scripts/python/arm-cs-trace-disasm.py", line 105, >>>>>>>>>>>>> in print_disam >>>>>>>>>>>>> for line in read_disam(dso_fname, dso_start, start_addr, >>>>>>>>>>>>> stop_addr): >>>>>>>>>>>>> ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ >>>>>>>>>>>>> File "./scripts/python/arm-cs-trace-disasm.py", line >>>>>>>>>>>>> 99, in >>>>>>>>>>>>> read_disam >>>>>>>>>>>>> disasm_output = >>>>>>>>>>>>> check_output(disasm).decode('utf-8').split('\n') >>>>>>>>>>>>> ^^^^^^^^^^^^^^^^^^^^ >>>>>>>>>>>>> File "/usr/lib64/python3.12/subprocess.py", line 466, in >>>>>>>>>>>>> check_output >>>>>>>>>>>>> return run(*popenargs, stdout=PIPE, timeout=timeout, >>>>>>>>>>>>> check=True, >>>>>>>>>>>>> ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ >>>>>>>>>>>>> File "/usr/lib64/python3.12/subprocess.py", line 571, >>>>>>>>>>>>> in run >>>>>>>>>>>>> raise CalledProcessError(retcode, process.args, >>>>>>>>>>>>> subprocess.CalledProcessError: Command '['objdump', '-d', >>>>>>>>>>>>> '-z', '--start-address=0xffff80008125b758', >>>>>>>>>>>>> '--stop-address=0xffff80008125a934', '../../vmlinux']' >>>>>>>>>>>>> returned non-zero exit status 1. >>>>>>>>>>>>> Fatal Python error: handler_call_die: problem in Python trace >>>>>>>>>>>>> event handler >>>>>>>>>>>>> Python runtime state: initialized >>>>>>>>>>>>> >>>>>>>>>>>>> Current thread 0x0000ffffb90d54e0 (most recent call first): >>>>>>>>>>>>> <no Python frame> >>>>>>>>>>>>> >>>>>>>>>>>>> Extension modules: perf_trace_context, systemd._journal, >>>>>>>>>>>>> systemd._reader, systemd.id128, report._py3report, >>>>>>>>>>>>> _dbus_bindings, problem._py3abrt (total: 7) >>>>>>>>>>>>> Aborted (core dumped) >>>>>>>>>>>>> >>>>>>>>>>>>> >>>>>>>>>>>>> dump snippet: >>>>>>>>>>>>> ============ >>>>>>>>>>>>> Event type: branches >>>>>>>>>>>>> Sample = { cpu: 0001 addr: 0xffff80008030cb00 phys_addr: >>>>>>>>>>>>> 0x0000000000000000 ip: 0xffff800080313f0c pid: 12720 tid: >>>>>>>>>>>>> 12720 period: 1 time: 5986372298040 } >>>>>>>>>>>>> ffff800080313f04 >>>>>>>>>>>>> <__perf_event_header__init_id+0x4c>: >>>>>>>>>>>>> ffff800080313f04: 36100094 tbz w20, >>>>>>>>>>>>> #2, ffff800080313f14 <__perf_event_header__init_id+0x5c> >>>>>>>>>>>>> ffff800080313f08: f941e6a0 ldr x0, >>>>>>>>>>>>> [x21, #968] >>>>>>>>>>>>> ffff800080313f0c: d63f0000 blr x0 >>>>>>>>>>>>> perf 12720/12720 [0001] 5986.372298040 >>>>>>>>>>>>> __perf_event_header__init_id+0x54 >>>>>>>>>>>>> .../coresight/linux/kernel/events/core.c 586 return >>>>>>>>>>>>> event->clock(); >>>>>>>>>>>>> Event type: branches >>>>>>>>>>>>> Sample = { cpu: 0001 addr: 0xffff8000801bb4a8 phys_addr: >>>>>>>>>>>>> 0x0000000000000000 ip: 0xffff80008030cb0c pid: 12720 tid: >>>>>>>>>>>>> 12720 period: 1 time: 5986372298040 } >>>>>>>>>>>>> ffff80008030cb00 <local_clock>: >>>>>>>>>>>>> ffff80008030cb00: d503233f paciasp >>>>>>>>>>>>> ffff80008030cb04: a9bf7bfd stp x29, >>>>>>>>>>>>> x30, [sp, #-16]! >>>>>>>>>>>>> ffff80008030cb08: 910003fd mov x29, sp >>>>>>>>>>>>> ffff80008030cb0c: 97faba67 bl >>>>>>>>>>>>> ffff8000801bb4a8 <sched_clock> >>>>>>>>>>>>> perf 12720/12720 [0001] 5986.372298040 >>>>>>>>>>>>> local_clock+0xc ...t/linux/./include/linux/sched/clock.h 64 >>>>>>>>>>>>> return sched_clock(); >>>>>>>>>>>>> Event type: branches >>>>>>>>>>>>> Sample = { cpu: 0001 addr: 0xffff80008125a8a8 phys_addr: >>>>>>>>>>>>> 0x0000000000000000 ip: 0xffff8000801bb4c8 pid: 12720 tid: >>>>>>>>>>>>> 12720 period: 1 time: 5986372298040 } >>>>>>>>>>>>> ffff8000801bb4a8 <sched_clock>: >>>>>>>>>>>>> ffff8000801bb4a8: d503233f paciasp >>>>>>>>>>>>> ffff8000801bb4ac: a9be7bfd stp x29, >>>>>>>>>>>>> x30, [sp, #-32]! >>>>>>>>>>>>> ffff8000801bb4b0: 910003fd mov x29, sp >>>>>>>>>>>>> ffff8000801bb4b4: a90153f3 stp x19, >>>>>>>>>>>>> x20, [sp, #16] >>>>>>>>>>>>> ffff8000801bb4b8: d5384113 mrs x19, >>>>>>>>>>>>> sp_el0 >>>>>>>>>>>>> ffff8000801bb4bc: b9401260 ldr w0, >>>>>>>>>>>>> [x19, #16] >>>>>>>>>>>>> ffff8000801bb4c0: 11000400 add w0, >>>>>>>>>>>>> w0, #0x1 >>>>>>>>>>>>> ffff8000801bb4c4: b9001260 str w0, >>>>>>>>>>>>> [x19, #16] >>>>>>>>>>>>> ffff8000801bb4c8: 94427cf8 bl >>>>>>>>>>>>> ffff80008125a8a8 <sched_clock_noinstr> >>>>>>>>>>>>> perf 12720/12720 [0001] 5986.372298040 >>>>>>>>>>>>> sched_clock+0x20 ...sight/linux/kernel/time/sched_clock.c 105 >>>>>>>>>>>>> ns = sched_clock_noinstr(); >>>>>>>>>>>>> Event type: branches >>>>>>>>>>>>> Sample = { cpu: 0001 addr: 0xffff80008125b758 phys_addr: >>>>>>>>>>>>> 0x0000000000000000 ip: 0xffff80008125a8e4 pid: 12720 tid: >>>>>>>>>>>>> 12720 period: 1 time: 5986372298040 } >>>>>>>>>>>>> ffff80008125a8a8 <sched_clock_noinstr>: >>>>>>>>>>>>> ffff80008125a8a8: d503233f paciasp >>>>>>>>>>>>> ffff80008125a8ac: a9bc7bfd stp x29, >>>>>>>>>>>>> x30, [sp, #-64]! >>>>>>>>>>>>> ffff80008125a8b0: 910003fd mov x29, sp >>>>>>>>>>>>> ffff80008125a8b4: a90153f3 stp x19, >>>>>>>>>>>>> x20, [sp, #16] >>>>>>>>>>>>> ffff80008125a8b8: b000e354 adrp x20, >>>>>>>>>>>>> ffff800082ec3000 <tick_bc_dev+0x140> >>>>>>>>>>>>> ffff80008125a8bc: 910d0294 add x20, >>>>>>>>>>>>> x20, #0x340 >>>>>>>>>>>>> ffff80008125a8c0: a90363f7 stp x23, >>>>>>>>>>>>> x24, [sp, #48] >>>>>>>>>>>>> ffff80008125a8c4: 91002297 add x23, >>>>>>>>>>>>> x20, #0x8 >>>>>>>>>>>>> ffff80008125a8c8: 52800518 mov w24, >>>>>>>>>>>>> #0x28 // #40 >>>>>>>>>>>>> ffff80008125a8cc: a9025bf5 stp x21, >>>>>>>>>>>>> x22, [sp, #32] >>>>>>>>>>>>> ffff80008125a8d0: b9400296 ldr w22, >>>>>>>>>>>>> [x20] >>>>>>>>>>>>> ffff80008125a8d4: 120002d5 and w21, >>>>>>>>>>>>> w22, #0x1 >>>>>>>>>>>>> ffff80008125a8d8: 9bb87eb5 umull x21, >>>>>>>>>>>>> w21, w24 >>>>>>>>>>>>> ffff80008125a8dc: 8b1502f3 add x19, >>>>>>>>>>>>> x23, x21 >>>>>>>>>>>>> ffff80008125a8e0: f9400e60 ldr x0, >>>>>>>>>>>>> [x19, #24] >>>>>>>>>>>>> ffff80008125a8e4: d63f0000 blr x0 >>>>>>>>>>>>> perf 12720/12720 [0001] 5986.372298040 >>>>>>>>>>>>> sched_clock_noinstr+0x3c >>>>>>>>>>>>> ...sight/linux/kernel/time/sched_clock.c 93 >>>>>>>>>>>>> cyc = (rd->read_sched_clock() - rd->epoch_cyc) & >>>>>>>>>>>>> Event type: branches >>>>>>>>>>>>> Sample = { cpu: 0001 addr: 0xffff8000801bb4cc phys_addr: >>>>>>>>>>>>> 0x0000000000000000 ip: 0xffff80008125a930 pid: 12720 tid: >>>>>>>>>>>>> 12720 period: 1 time: 5986372298040 } >>>>>>>>>>>>> >>>>>>>>>>>>> >>>>>>>>>>>>> With fix: >>>>>>>>>>>>> ========= >>>>>>>>>>>>> >>>>>>>>>>>>> Event type: branches >>>>>>>>>>>>> Sample = { cpu: 0001 addr: 0xffff80008030cb00 phys_addr: >>>>>>>>>>>>> 0x0000000000000000 ip: 0xffff800080313f0c pid: 12720 tid: >>>>>>>>>>>>> 12720 period: 1 time: 5986372298040 } >>>>>>>>>>>>> ffff800080313f04 >>>>>>>>>>>>> <__perf_event_header__init_id+0x4c>: >>>>>>>>>>>>> ffff800080313f04: 36100094 tbz w20, >>>>>>>>>>>>> #2, ffff800080313f14 <__perf_event_header__init_id+0x5c> >>>>>>>>>>>>> ffff800080313f08: f941e6a0 ldr x0, >>>>>>>>>>>>> [x21, #968] >>>>>>>>>>>>> ffff800080313f0c: d63f0000 blr x0 >>>>>>>>>>>>> perf 12720/12720 [0001] 5986.372298040 >>>>>>>>>>>>> __perf_event_header__init_id+0x54 >>>>>>>>>>>>> .../coresight/linux/kernel/events/core.c 586 return >>>>>>>>>>>>> event->clock(); >>>>>>>>>>>>> Event type: branches >>>>>>>>>>>>> Sample = { cpu: 0001 addr: 0xffff8000801bb4a8 phys_addr: >>>>>>>>>>>>> 0x0000000000000000 ip: 0xffff80008030cb0c pid: 12720 tid: >>>>>>>>>>>>> 12720 period: 1 time: 5986372298040 } >>>>>>>>>>>>> ffff80008030cb00 <local_clock>: >>>>>>>>>>>>> ffff80008030cb00: d503233f paciasp >>>>>>>>>>>>> ffff80008030cb04: a9bf7bfd stp x29, >>>>>>>>>>>>> x30, [sp, #-16]! >>>>>>>>>>>>> ffff80008030cb08: 910003fd mov x29, sp >>>>>>>>>>>>> ffff80008030cb0c: 97faba67 bl >>>>>>>>>>>>> ffff8000801bb4a8 <sched_clock> >>>>>>>>>>>>> perf 12720/12720 [0001] 5986.372298040 >>>>>>>>>>>>> local_clock+0xc ...t/linux/./include/linux/sched/clock.h 64 >>>>>>>>>>>>> return sched_clock(); >>>>>>>>>>>>> Event type: branches >>>>>>>>>>>>> Sample = { cpu: 0001 addr: 0xffff80008125a8a8 phys_addr: >>>>>>>>>>>>> 0x0000000000000000 ip: 0xffff8000801bb4c8 pid: 12720 tid: >>>>>>>>>>>>> 12720 period: 1 time: 5986372298040 } >>>>>>>>>>>>> ffff8000801bb4a8 <sched_clock>: >>>>>>>>>>>>> ffff8000801bb4a8: d503233f paciasp >>>>>>>>>>>>> ffff8000801bb4ac: a9be7bfd stp x29, >>>>>>>>>>>>> x30, [sp, #-32]! >>>>>>>>>>>>> ffff8000801bb4b0: 910003fd mov x29, sp >>>>>>>>>>>>> ffff8000801bb4b4: a90153f3 stp x19, >>>>>>>>>>>>> x20, [sp, #16] >>>>>>>>>>>>> ffff8000801bb4b8: d5384113 mrs x19, >>>>>>>>>>>>> sp_el0 >>>>>>>>>>>>> ffff8000801bb4bc: b9401260 ldr w0, >>>>>>>>>>>>> [x19, #16] >>>>>>>>>>>>> ffff8000801bb4c0: 11000400 add w0, >>>>>>>>>>>>> w0, #0x1 >>>>>>>>>>>>> ffff8000801bb4c4: b9001260 str w0, >>>>>>>>>>>>> [x19, #16] >>>>>>>>>>>>> ffff8000801bb4c8: 94427cf8 bl >>>>>>>>>>>>> ffff80008125a8a8 <sched_clock_noinstr> >>>>>>>>>>>>> perf 12720/12720 [0001] 5986.372298040 >>>>>>>>>>>>> sched_clock+0x20 ...sight/linux/kernel/time/sched_clock.c 105 >>>>>>>>>>>>> ns = sched_clock_noinstr(); >>>>>>>>>>>>> Event type: branches >>>>>>>>>>>>> Sample = { cpu: 0001 addr: 0xffff80008125b758 phys_addr: >>>>>>>>>>>>> 0x0000000000000000 ip: 0xffff80008125a8e4 pid: 12720 tid: >>>>>>>>>>>>> 12720 period: 1 time: 5986372298040 } >>>>>>>>>>>>> ffff80008125a8a8 <sched_clock_noinstr>: >>>>>>>>>>>>> ffff80008125a8a8: d503233f paciasp >>>>>>>>>>>>> ffff80008125a8ac: a9bc7bfd stp x29, >>>>>>>>>>>>> x30, [sp, #-64]! >>>>>>>>>>>>> ffff80008125a8b0: 910003fd mov x29, sp >>>>>>>>>>>>> ffff80008125a8b4: a90153f3 stp x19, >>>>>>>>>>>>> x20, [sp, #16] >>>>>>>>>>>>> ffff80008125a8b8: b000e354 adrp x20, >>>>>>>>>>>>> ffff800082ec3000 <tick_bc_dev+0x140> >>>>>>>>>>>>> ffff80008125a8bc: 910d0294 add x20, >>>>>>>>>>>>> x20, #0x340 >>>>>>>>>>>>> ffff80008125a8c0: a90363f7 stp x23, >>>>>>>>>>>>> x24, [sp, #48] >>>>>>>>>>>>> ffff80008125a8c4: 91002297 add x23, >>>>>>>>>>>>> x20, #0x8 >>>>>>>>>>>>> ffff80008125a8c8: 52800518 mov w24, >>>>>>>>>>>>> #0x28 // #40 >>>>>>>>>>>>> ffff80008125a8cc: a9025bf5 stp x21, >>>>>>>>>>>>> x22, [sp, #32] >>>>>>>>>>>>> ffff80008125a8d0: b9400296 ldr w22, >>>>>>>>>>>>> [x20] >>>>>>>>>>>>> ffff80008125a8d4: 120002d5 and w21, >>>>>>>>>>>>> w22, #0x1 >>>>>>>>>>>>> ffff80008125a8d8: 9bb87eb5 umull x21, >>>>>>>>>>>>> w21, w24 >>>>>>>>>>>>> ffff80008125a8dc: 8b1502f3 add x19, >>>>>>>>>>>>> x23, x21 >>>>>>>>>>>>> ffff80008125a8e0: f9400e60 ldr x0, >>>>>>>>>>>>> [x19, #24] >>>>>>>>>>>>> ffff80008125a8e4: d63f0000 blr x0 >>>>>>>>>>>> >>>>>>>>>>>> It looks like the disassembly now assumes this BLR wasn't >>>>>>>>>>>> taken. We go from ffff80008125a8e4 straight through to ... >>>>>>>>>>>> >>>>>>>>>>>>> perf 12720/12720 [0001] 5986.372298040 >>>>>>>>>>>>> sched_clock_noinstr+0x3c >>>>>>>>>>>>> ...sight/linux/kernel/time/sched_clock.c 93 >>>>>>>>>>>>> cyc = (rd->read_sched_clock() - rd->epoch_cyc) & >>>>>>>>>>>>> Event type: branches >>>>>>>>>>>>> Sample = { cpu: 0001 addr: 0xffff8000801bb4cc phys_addr: >>>>>>>>>>>>> 0x0000000000000000 ip: 0xffff80008125a930 pid: 12720 tid: >>>>>>>>>>>>> 12720 period: 1 time: 5986372298040 } >>>>>>>>>>>>> ffff80008125a8e8 <sched_clock_noinstr+0x40>: >>>>>>>>>>>>> ffff80008125a8e8: f8756ae3 ldr x3, >>>>>>>>>>>>> [x23, x21] >>>>>>>>>>>> >>>>>>>>>>>> ffff80008125a8e4 which is just the previous one +4. Isn't your >>>>>>>>>>>> issue actually a decode issue in Perf itself? Why is there a >>>>>>>>>>>> discontinuity without branch samples being generated where >>>>>>>>>>>> either the source or destination address is 0? >>>>>>>>>>>> >>>>>>>>>>>> What are your record options to create this issue? As I >>>>>>>>>>>> mentioned in the previous reply I haven't been able to >>>>>>>>>>>> reproduce it. >>>>>>>>>>> >>>>>>>>>>> I am using below perf record command. >>>>>>>>>>> >>>>>>>>>>> timeout 4s ./perf record -e cs_etm// -C 1 dd if=/dev/zero >>>>>>>>>>> of=/dev/null >>>>>>>>>>> >>>>>>>>>> >>>>>>>>>> Thanks I managed to reproduce it. I'll take a look to see if I >>>>>>>>>> think the issue is somewhere else. >>>>>>>>>> >>>>>>>>> >>>>>>>>> At least for the failures I encountered, the issue is due to the >>>>>>>>> alternatives runtime instruction patching mechanism. vmlinux ends >>>>>>>>> up being the wrong image to decode with because a load of branches >>>>>>>>> are actually turned into nops. >>>>>>>>> >>>>>>>>> Can you confirm if you use --kcore instead of vmlinux that you >>>>>>>>> still get failures: >>>>>>>>> >>>>>>>>> sudo perf record -e cs_etm// -C 1 --kcore -o >>>>>>>>> <output-folder.data> -- \ >>>>>>>>> dd if=/dev/zero of=/dev/null >>>>>>>>> >>>>>>>>> perf script -i <output-folder.data> \ >>>>>>>>> tools/perf/scripts/python/arm-cs-trace-disasm.py -d >>>>>>>>> llvm-objdump \ >>>>>>>>> -k <output-folder.data>/kcore_dir/kcore >>>>>>>>> >>>>>>>> >>>>>>>> With below command combination with kcore also the issue is seen, >>>>>>>> as reported in this email chain. >>>>>>>> >>>>>>>> timeout 8s ./perf record -e cs_etm// -C 1 --kcore -o kcore \ >>>>>>>> dd if=/dev/zero of=/dev/null >>>>>>>> >>>>>>>> ./perf script -i kcore/data \ >>>>>>>> --script=python:./scripts/python/arm-cs-trace-disasm.py -- \ >>>>>>>> -d objdump -k kcore/kcore_dir/kcore >>>>>>>> >>>>>>>> >>>>>>>> However, with below sequence(same as your command) the issue is >>>>>>>> *not* seen. >>>>>>>> >>>>>>>> timeout 8s ./perf record -e cs_etm// -C 1 --kcore -o kcore \ >>>>>>>> dd if=/dev/zero of=/dev/null >>>>>>>> >>>>>>>> ./perf script -i kcore/data >>>>>>>> ./scripts/python/arm-cs-trace-disasm.py \ >>>>>>>> -- -d objdump -k kcore/kcore_dir/kcore >>>>>>>> >>>>>>>> Do you see any issue with the command, which is showing the >>>>>>>> problem? >>>>>>>> Also the output log produced by these both commands is different. >>>>>>>> >>>>> >>>>> BTW are you running this on the target or somewhere else? It's >>>>> suspicious that "-i kcore/data" works at all because there is no >>>>> kernel image given to Perf. Unless you are running on the target and >>>>> then I think it will just open the one from /proc. Or maybe it uses >>>>> /boot/vmlinux by default which also wouldn't work. >>>>> > > Yes All tests are done natively on Ampere's ARM64 platform. > some more combination of commands which are also failing. > > ./perf script -i ./kcore -s scripts/python/arm-cs-trace-disasm.py -- -d > objdump -k kcore/kcore_dir/kcore > > ./perf script -i ./kcore -s scripts/python/arm-cs-trace-disasm.py -F > cpu,event,ip,addr,sym -- -d objdump -k kcore/kcore_dir/kcore > > ./perf script -i ./kcore scripts/python/arm-cs-trace-disasm.py -d > objdump -k kcore/kcore_dir/kcore > >>>>> Also the difference between "--script=python:" and just giving the >>>>> script name is in the parsing of the arguments following " -- ". >>>>> Sometimes they're also parsed as Perf arguments (like the -v becomes >>>>> perf verbose and -k becomes the Perf vmlinux rather than the script). >>>>> >>>>> I _think_ you want the " -- " when "--script" is used, and no "--" >>>>> when it's not. But there are some other combinations and you'll have >>>>> to debug it to compare your two exact scenarios to see why they're >>>>> different. >>>>> >>>>> But ignoring that issue with the argument format, you mentioned you >>>>> didn't see the issue any more with one version of --kcore. So I'm >>>>> assuming that confirms the issue is just a decode image issue, so we >>>>> shouldn't try to patch this script? >>>>> >>>> >>>> Although one change we should make to the script is change the example >>>> to use kcore. We can leave in one vmlinux one as an example if kcore >>>> isn't available, but add a note that it will fail if any patched >>>> code is >>>> traced (which is almost always). >>> >>> James, you may recall the year old thread >>> https://lore.kernel.org/all/ed8cea4c-a261-60ca-f4e1-333ec73cca8f@os.amperec…. >>> I described there an awkward workaround Ampere has used to solve the >>> patched code problem. At the time, it sounded like the maintainers were >>> interested in getting away from using the python script, mostly for >>> speed purposes. I didn't see the discussion go any further. >>> >> >> Oh yes thanks for the reminder. I wasn't thinking about the source >> code lines and debug symbols in this thread. I suppose your merging of >> kcore and vmlinux gives both the correct image and the symbols, but I >> was only focused on the image being correct, so only kcore was enough. >> >> It looks like everything we want to do from your previous thread is in >> addition to the fixes from this one. Even if we auto merge kcore + >> symbols and move the disassembly into Perf, we still want to detect >> decode issues earlier and not have IPs jumping backwards. Whether it's >> the script or Perf doing that the behavior should be the same. >> > > Since it is breaking the decode, can we please add as a fix to drop the > packets from decode when the discontinuity is seen (with warning message > in verbose mode)? like below diff? > > --- a/tools/perf/scripts/python/arm-cs-trace-disasm.py > +++ b/tools/perf/scripts/python/arm-cs-trace-disasm.py > @@ -257,6 +257,11 @@ def process_event(param_dict): > print("Stop address 0x%x is out of range [ 0x%x .. 0x%x > ] for dso %s" % (stop_addr, int(dso_start), int(dso_end), dso)) > return > > + if (stop_addr < start_addr): > + if (options.verbose == True): > + print("Packet Dropped, Discontinuity detected > [stop_add:0x%x start_addr:0x%x ] for dso %s" % (stop_addr, start_addr, > dso)) > + return > + I suppose my only concern with this is that it hides real errors and Perf shouldn't be outputting samples that go backwards. Considering that fixing this in OpenCSD and Perf has a much wider benefit I think that should be the ultimate goal. I'm putting this on my todo list for now (including Steve's merging idea). But in the mean time what about having a force option? > + if (stop_addr < start_addr): > + if (options.verbose == True or not options.force): > + print("Packet Dropped, Discontinuity detected > [stop_add:0x%x start_addr:0x%x ] for dso %s" % (stop_addr, start_addr, > dso)) > + if (not options.force): > + return > + That way in the future we'll still get reports if something new goes wrong. > if (options.objdump_name != None): > # It doesn't need to decrease virtual memory offset for > disassembly > # for kernel dso and executable file dso, so in this > case we set > > >> To summarise I think these are the changes to make: >> >> * Improve bad decode detection in OpenCSD >> * Get the script to auto merge kcore and vmlinux >> * Maybe we could get Perf to do this if both a kcore folder and -k >> vmlinux are used? >> * Improve the performance, either in the script or move more >> functionality into Perf > > Thanks, > Ganapat

10 months, 2 weeks

Re: [PATCH] perf scripts python arm-cs-trace-disasm.py: Skip disasm if address continuity is broken

by James Clark

On 06/08/2024 4:02 pm, Steve Clevenger wrote: > > > On 8/6/2024 2:57 AM, James Clark wrote: >> >> >> On 06/08/2024 10:47 am, James Clark wrote: >>> >>> >>> On 06/08/2024 8:02 am, Ganapatrao Kulkarni wrote: >>>> >>>> >>>> On 05-08-2024 07:29 pm, James Clark wrote: >>>>> >>>>> >>>>> On 05/08/2024 1:22 pm, Ganapatrao Kulkarni wrote: >>>>>> >>>>>> >>>>>> On 01-08-2024 03:30 pm, James Clark wrote: >>>>>>> >>>>>>> >>>>>>> On 24/07/2024 3:45 pm, James Clark wrote: >>>>>>>> >>>>>>>> >>>>>>>> On 24/07/2024 7:38 am, Ganapatrao Kulkarni wrote: >>>>>>>>> >>>>>>>>> >>>>>>>>> On 23-07-2024 09:16 pm, James Clark wrote: >>>>>>>>>> >>>>>>>>>> >>>>>>>>>> On 23/07/2024 4:26 pm, Ganapatrao Kulkarni wrote: >>>>>>>>>>> >>>>>>>>>>> >>>>>>>>>>> On 23-07-2024 06:40 pm, James Clark wrote: >>>>>>>>>>>> >>>>>>>>>>>> >>>>>>>>>>>> On 22/07/2024 11:02 am, Ganapatrao Kulkarni wrote: >>>>>>>>>>>>> >>>>>>>>>>>>> Hi James, >>>>>>>>>>>>> >>>>>>>>>>>>> On 19-07-2024 08:09 pm, James Clark wrote: >>>>>>>>>>>>>> >>>>>>>>>>>>>> >>>>>>>>>>>>>> On 19/07/2024 10:26 am, Ganapatrao Kulkarni wrote: >>>>>>>>>>>>>>> To generate the instruction tracing, script uses 2 >>>>>>>>>>>>>>> contiguous packets >>>>>>>>>>>>>>> address range. If there a continuity brake due to >>>>>>>>>>>>>>> discontiguous branch >>>>>>>>>>>>>>> address, it is required to reset the tracing and start >>>>>>>>>>>>>>> tracing with the >>>>>>>>>>>>>>> new set of contiguous packets. >>>>>>>>>>>>>>> >>>>>>>>>>>>>>> Adding change to identify the break and complete the >>>>>>>>>>>>>>> remaining tracing >>>>>>>>>>>>>>> of current packets and restart tracing from new set of >>>>>>>>>>>>>>> packets, if >>>>>>>>>>>>>>> continuity is established. >>>>>>>>>>>>>>> >>>>>>>>>>>>>> >>>>>>>>>>>>>> Hi Ganapatrao, >>>>>>>>>>>>>> >>>>>>>>>>>>>> Can you add a before and after example of what's changed to >>>>>>>>>>>>>> the commit message? It wasn't immediately obvious to me if >>>>>>>>>>>>>> this is adding missing output, or it was correcting the >>>>>>>>>>>>>> tail end of the output that was previously wrong. >>>>>>>>>>>>> >>>>>>>>>>>>> It is adding tail end of the trace as well avoiding the >>>>>>>>>>>>> segfault of the perf application. With out this change the >>>>>>>>>>>>> perf segfaults with as below log >>>>>>>>>>>>> >>>>>>>>>>>>> >>>>>>>>>>>>> ./perf script >>>>>>>>>>>>> --script=python:./scripts/python/arm-cs-trace-disasm.py -- >>>>>>>>>>>>> -d objdump -k ../../vmlinux -v $* > dump >>>>>>>>>>>>> objdump: error: the stop address should be after the start >>>>>>>>>>>>> address >>>>>>>>>>>>> Traceback (most recent call last): >>>>>>>>>>>>> File "./scripts/python/arm-cs-trace-disasm.py", line 271, >>>>>>>>>>>>> in process_event >>>>>>>>>>>>> print_disam(dso_fname, dso_vm_start, start_addr, >>>>>>>>>>>>> stop_addr) >>>>>>>>>>>>> File "./scripts/python/arm-cs-trace-disasm.py", line 105, >>>>>>>>>>>>> in print_disam >>>>>>>>>>>>> for line in read_disam(dso_fname, dso_start, >>>>>>>>>>>>> start_addr, stop_addr): >>>>>>>>>>>>> ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ >>>>>>>>>>>>> File "./scripts/python/arm-cs-trace-disasm.py", line 99, >>>>>>>>>>>>> in read_disam >>>>>>>>>>>>> disasm_output = >>>>>>>>>>>>> check_output(disasm).decode('utf-8').split('\n') >>>>>>>>>>>>> ^^^^^^^^^^^^^^^^^^^^ >>>>>>>>>>>>> File "/usr/lib64/python3.12/subprocess.py", line 466, in >>>>>>>>>>>>> check_output >>>>>>>>>>>>> return run(*popenargs, stdout=PIPE, timeout=timeout, >>>>>>>>>>>>> check=True, >>>>>>>>>>>>> ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ >>>>>>>>>>>>> File "/usr/lib64/python3.12/subprocess.py", line 571, in run >>>>>>>>>>>>> raise CalledProcessError(retcode, process.args, >>>>>>>>>>>>> subprocess.CalledProcessError: Command '['objdump', '-d', >>>>>>>>>>>>> '-z', '--start-address=0xffff80008125b758', >>>>>>>>>>>>> '--stop-address=0xffff80008125a934', '../../vmlinux']' >>>>>>>>>>>>> returned non-zero exit status 1. >>>>>>>>>>>>> Fatal Python error: handler_call_die: problem in Python >>>>>>>>>>>>> trace event handler >>>>>>>>>>>>> Python runtime state: initialized >>>>>>>>>>>>> >>>>>>>>>>>>> Current thread 0x0000ffffb05054e0 (most recent call first): >>>>>>>>>>>>> <no Python frame> >>>>>>>>>>>>> >>>>>>>>>>>>> Extension modules: perf_trace_context, systemd._journal, >>>>>>>>>>>>> systemd._reader, systemd.id128, report._py3report, >>>>>>>>>>>>> _dbus_bindings, problem._py3abrt (total: 7) >>>>>>>>>>>>> Aborted (core dumped) >>>>>>>>>>>>> >>>>>>>>>>>>>> >>>>>>>>>>>>>>> Signed-off-by: Ganapatrao Kulkarni >>>>>>>>>>>>>>> <gankulkarni(a)os.amperecomputing.com> >>>>>>>>>>>>>>> --- >>>>>>>>>>>>>>> tools/perf/scripts/python/arm-cs-trace-disasm.py | 10 >>>>>>>>>>>>>>> ++++++++++ >>>>>>>>>>>>>>> 1 file changed, 10 insertions(+) >>>>>>>>>>>>>>> >>>>>>>>>>>>>>> diff --git >>>>>>>>>>>>>>> a/tools/perf/scripts/python/arm-cs-trace-disasm.py >>>>>>>>>>>>>>> b/tools/perf/scripts/python/arm-cs-trace-disasm.py >>>>>>>>>>>>>>> index d973c2baed1c..ad10cee2c35e 100755 >>>>>>>>>>>>>>> --- a/tools/perf/scripts/python/arm-cs-trace-disasm.py >>>>>>>>>>>>>>> +++ b/tools/perf/scripts/python/arm-cs-trace-disasm.py >>>>>>>>>>>>>>> @@ -198,6 +198,10 @@ def process_event(param_dict): >>>>>>>>>>>>>>> cpu_data[str(cpu) + 'addr'] = addr >>>>>>>>>>>>>>> return >>>>>>>>>>>>>>> + if (cpu_data.get(str(cpu) + 'ip') == None): >>>>>>>>>>>>>>> + cpu_data[str(cpu) + 'ip'] = ip >>>>>>>>>>>>>>> + >>>>>>>>>>>>>> >>>>>>>>>>>>>> Do you need to write into the global cpu_data here? Doesn't >>>>>>>>>>>>>> it get overwritten after you load it back into 'prev_ip' >>>>>>>>>>>>> >>>>>>>>>>>>> No, the logic is same as holding the addr of previous packet. >>>>>>>>>>>>> Saving the previous packet saved ip in to prev_ip before >>>>>>>>>>>>> overwriting with the current packet. >>>>>>>>>>>> >>>>>>>>>>>> It's not exactly the same logic as holding the addr of the >>>>>>>>>>>> previous sample. For addr, we return on the first None, with >>>>>>>>>>>> your change we now "pretend" that the second one is also the >>>>>>>>>>>> previous one: >>>>>>>>>>>> >>>>>>>>>>>> if (cpu_data.get(str(cpu) + 'addr') == None): >>>>>>>>>>>> cpu_data[str(cpu) + 'addr'] = addr >>>>>>>>>>>> return <----------------------------sample 0 return >>>>>>>>>>>> >>>>>>>>>>>> if (cpu_data.get(str(cpu) + 'ip') == None): >>>>>>>>>>>> cpu_data[str(cpu) + 'ip'] = ip <---- sample 1 save but >>>>>>>>>>>> no return >>>>>>>>>>>> >>>>>>>>>>>> Then for sample 1 'prev_ip' is actually now the 'current' IP: >>>>>>>>>>> >>>>>>>>>>> Yes, it is dummy for first packet. Added anticipating that we >>>>>>>>>>> wont hit the discontinuity for the first packet itself. >>>>>>>>>>> >>>>>>>>>>> Can this be changed to more intuitive like below? >>>>>>>>>>> >>>>>>>>>>> diff --git a/tools/perf/scripts/python/arm-cs-trace-disasm.py >>>>>>>>>>> b/tools/perf/scripts/python/arm-cs-trace-disasm.py >>>>>>>>>>> index d973c2baed1c..d49f5090059f 100755 >>>>>>>>>>> --- a/tools/perf/scripts/python/arm-cs-trace-disasm.py >>>>>>>>>>> +++ b/tools/perf/scripts/python/arm-cs-trace-disasm.py >>>>>>>>>>> @@ -198,6 +198,8 @@ def process_event(param_dict): >>>>>>>>>>> cpu_data[str(cpu) + 'addr'] = addr >>>>>>>>>>> return >>>>>>>>>>> >>>>>>>>>>> + if (cpu_data.get(str(cpu) + 'ip') != None): >>>>>>>>>>> + prev_ip = cpu_data[str(cpu) + 'ip'] >>>>>>>>>>> >>>>>>>>>>> if (options.verbose == True): >>>>>>>>>>> print("Event type: %s" % name) >>>>>>>>>>> @@ -243,12 +245,18 @@ def process_event(param_dict): >>>>>>>>>>> >>>>>>>>>>> # Record for previous sample packet >>>>>>>>>>> cpu_data[str(cpu) + 'addr'] = addr >>>>>>>>>>> + cpu_data[str(cpu) + 'ip'] = stop_addr >>>>>>>>>>> >>>>>>>>>>> # Handle CS_ETM_TRACE_ON packet if start_addr=0 and >>>>>>>>>>> stop_addr=4 >>>>>>>>>>> if (start_addr == 0 and stop_addr == 4): >>>>>>>>>>> print("CPU%d: CS_ETM_TRACE_ON packet is >>>>>>>>>>> inserted" % cpu) >>>>>>>>>>> return >>>>>>>>>>> >>>>>>>>>>> + if (stop_addr < start_addr and prev_ip != 0): >>>>>>>>>>> + # Continuity of the Packets broken, set >>>>>>>>>>> start_addr to previous >>>>>>>>>>> + # packet ip to complete the remaining tracing >>>>>>>>>>> of the address range. >>>>>>>>>>> + start_addr = prev_ip >>>>>>>>>>> + >>>>>>>>>>> if (start_addr < int(dso_start) or start_addr > >>>>>>>>>>> int(dso_end)): >>>>>>>>>>> print("Start address 0x%x is out of range [ >>>>>>>>>>> 0x%x .. 0x%x ] for dso %s" % (start_addr, int(dso_start), >>>>>>>>>>> int(dso_end), dso)) >>>>>>>>>>> return >>>>>>>>>>> >>>>>>>>>>> Without this patch below is the failure log(with segfault) for >>>>>>>>>>> reference. >>>>>>>>>>> >>>>>>>>>>> [root@sut01sys-r214 perf]# timeout 4s ./perf record -e >>>>>>>>>>> cs_etm// -C 1 dd if=/dev/zero of=/dev/null >>>>>>>>>>> [ perf record: Woken up 1 times to write data ] >>>>>>>>>>> [ perf record: Captured and wrote 1.087 MB perf.data ] >>>>>>>>>>> [root@sut01sys-r214 perf]# ./perf script >>>>>>>>>>> --script=python:./scripts/python/arm-cs-trace-disasm.py -- -d >>>>>>>>>>> objdump -k ../../vmlinux -v $* > dump >>>>>>>>>>> objdump: error: the stop address should be after the start >>>>>>>>>>> address >>>>>>>>>>> Traceback (most recent call last): >>>>>>>>>>> File "./scripts/python/arm-cs-trace-disasm.py", line 271, >>>>>>>>>>> in process_event >>>>>>>>>>> print_disam(dso_fname, dso_vm_start, start_addr, stop_addr) >>>>>>>>>>> File "./scripts/python/arm-cs-trace-disasm.py", line 105, >>>>>>>>>>> in print_disam >>>>>>>>>>> for line in read_disam(dso_fname, dso_start, start_addr, >>>>>>>>>>> stop_addr): >>>>>>>>>>> ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ >>>>>>>>>>> File "./scripts/python/arm-cs-trace-disasm.py", line 99, in >>>>>>>>>>> read_disam >>>>>>>>>>> disasm_output = >>>>>>>>>>> check_output(disasm).decode('utf-8').split('\n') >>>>>>>>>>> ^^^^^^^^^^^^^^^^^^^^ >>>>>>>>>>> File "/usr/lib64/python3.12/subprocess.py", line 466, in >>>>>>>>>>> check_output >>>>>>>>>>> return run(*popenargs, stdout=PIPE, timeout=timeout, >>>>>>>>>>> check=True, >>>>>>>>>>> ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ >>>>>>>>>>> File "/usr/lib64/python3.12/subprocess.py", line 571, in run >>>>>>>>>>> raise CalledProcessError(retcode, process.args, >>>>>>>>>>> subprocess.CalledProcessError: Command '['objdump', '-d', >>>>>>>>>>> '-z', '--start-address=0xffff80008125b758', >>>>>>>>>>> '--stop-address=0xffff80008125a934', '../../vmlinux']' >>>>>>>>>>> returned non-zero exit status 1. >>>>>>>>>>> Fatal Python error: handler_call_die: problem in Python trace >>>>>>>>>>> event handler >>>>>>>>>>> Python runtime state: initialized >>>>>>>>>>> >>>>>>>>>>> Current thread 0x0000ffffb90d54e0 (most recent call first): >>>>>>>>>>> <no Python frame> >>>>>>>>>>> >>>>>>>>>>> Extension modules: perf_trace_context, systemd._journal, >>>>>>>>>>> systemd._reader, systemd.id128, report._py3report, >>>>>>>>>>> _dbus_bindings, problem._py3abrt (total: 7) >>>>>>>>>>> Aborted (core dumped) >>>>>>>>>>> >>>>>>>>>>> >>>>>>>>>>> dump snippet: >>>>>>>>>>> ============ >>>>>>>>>>> Event type: branches >>>>>>>>>>> Sample = { cpu: 0001 addr: 0xffff80008030cb00 phys_addr: >>>>>>>>>>> 0x0000000000000000 ip: 0xffff800080313f0c pid: 12720 tid: >>>>>>>>>>> 12720 period: 1 time: 5986372298040 } >>>>>>>>>>> ffff800080313f04 <__perf_event_header__init_id+0x4c>: >>>>>>>>>>> ffff800080313f04: 36100094 tbz w20, >>>>>>>>>>> #2, ffff800080313f14 <__perf_event_header__init_id+0x5c> >>>>>>>>>>> ffff800080313f08: f941e6a0 ldr x0, >>>>>>>>>>> [x21, #968] >>>>>>>>>>> ffff800080313f0c: d63f0000 blr x0 >>>>>>>>>>> perf 12720/12720 [0001] 5986.372298040 >>>>>>>>>>> __perf_event_header__init_id+0x54 >>>>>>>>>>> .../coresight/linux/kernel/events/core.c 586 return >>>>>>>>>>> event->clock(); >>>>>>>>>>> Event type: branches >>>>>>>>>>> Sample = { cpu: 0001 addr: 0xffff8000801bb4a8 phys_addr: >>>>>>>>>>> 0x0000000000000000 ip: 0xffff80008030cb0c pid: 12720 tid: >>>>>>>>>>> 12720 period: 1 time: 5986372298040 } >>>>>>>>>>> ffff80008030cb00 <local_clock>: >>>>>>>>>>> ffff80008030cb00: d503233f paciasp >>>>>>>>>>> ffff80008030cb04: a9bf7bfd stp x29, >>>>>>>>>>> x30, [sp, #-16]! >>>>>>>>>>> ffff80008030cb08: 910003fd mov x29, sp >>>>>>>>>>> ffff80008030cb0c: 97faba67 bl >>>>>>>>>>> ffff8000801bb4a8 <sched_clock> >>>>>>>>>>> perf 12720/12720 [0001] 5986.372298040 >>>>>>>>>>> local_clock+0xc ...t/linux/./include/linux/sched/clock.h 64 >>>>>>>>>>> return sched_clock(); >>>>>>>>>>> Event type: branches >>>>>>>>>>> Sample = { cpu: 0001 addr: 0xffff80008125a8a8 phys_addr: >>>>>>>>>>> 0x0000000000000000 ip: 0xffff8000801bb4c8 pid: 12720 tid: >>>>>>>>>>> 12720 period: 1 time: 5986372298040 } >>>>>>>>>>> ffff8000801bb4a8 <sched_clock>: >>>>>>>>>>> ffff8000801bb4a8: d503233f paciasp >>>>>>>>>>> ffff8000801bb4ac: a9be7bfd stp x29, >>>>>>>>>>> x30, [sp, #-32]! >>>>>>>>>>> ffff8000801bb4b0: 910003fd mov x29, sp >>>>>>>>>>> ffff8000801bb4b4: a90153f3 stp x19, >>>>>>>>>>> x20, [sp, #16] >>>>>>>>>>> ffff8000801bb4b8: d5384113 mrs x19, >>>>>>>>>>> sp_el0 >>>>>>>>>>> ffff8000801bb4bc: b9401260 ldr w0, >>>>>>>>>>> [x19, #16] >>>>>>>>>>> ffff8000801bb4c0: 11000400 add w0, >>>>>>>>>>> w0, #0x1 >>>>>>>>>>> ffff8000801bb4c4: b9001260 str w0, >>>>>>>>>>> [x19, #16] >>>>>>>>>>> ffff8000801bb4c8: 94427cf8 bl >>>>>>>>>>> ffff80008125a8a8 <sched_clock_noinstr> >>>>>>>>>>> perf 12720/12720 [0001] 5986.372298040 >>>>>>>>>>> sched_clock+0x20 ...sight/linux/kernel/time/sched_clock.c 105 >>>>>>>>>>> ns = sched_clock_noinstr(); >>>>>>>>>>> Event type: branches >>>>>>>>>>> Sample = { cpu: 0001 addr: 0xffff80008125b758 phys_addr: >>>>>>>>>>> 0x0000000000000000 ip: 0xffff80008125a8e4 pid: 12720 tid: >>>>>>>>>>> 12720 period: 1 time: 5986372298040 } >>>>>>>>>>> ffff80008125a8a8 <sched_clock_noinstr>: >>>>>>>>>>> ffff80008125a8a8: d503233f paciasp >>>>>>>>>>> ffff80008125a8ac: a9bc7bfd stp x29, >>>>>>>>>>> x30, [sp, #-64]! >>>>>>>>>>> ffff80008125a8b0: 910003fd mov x29, sp >>>>>>>>>>> ffff80008125a8b4: a90153f3 stp x19, >>>>>>>>>>> x20, [sp, #16] >>>>>>>>>>> ffff80008125a8b8: b000e354 adrp x20, >>>>>>>>>>> ffff800082ec3000 <tick_bc_dev+0x140> >>>>>>>>>>> ffff80008125a8bc: 910d0294 add x20, >>>>>>>>>>> x20, #0x340 >>>>>>>>>>> ffff80008125a8c0: a90363f7 stp x23, >>>>>>>>>>> x24, [sp, #48] >>>>>>>>>>> ffff80008125a8c4: 91002297 add x23, >>>>>>>>>>> x20, #0x8 >>>>>>>>>>> ffff80008125a8c8: 52800518 mov w24, >>>>>>>>>>> #0x28 // #40 >>>>>>>>>>> ffff80008125a8cc: a9025bf5 stp x21, >>>>>>>>>>> x22, [sp, #32] >>>>>>>>>>> ffff80008125a8d0: b9400296 ldr w22, >>>>>>>>>>> [x20] >>>>>>>>>>> ffff80008125a8d4: 120002d5 and w21, >>>>>>>>>>> w22, #0x1 >>>>>>>>>>> ffff80008125a8d8: 9bb87eb5 umull x21, >>>>>>>>>>> w21, w24 >>>>>>>>>>> ffff80008125a8dc: 8b1502f3 add x19, >>>>>>>>>>> x23, x21 >>>>>>>>>>> ffff80008125a8e0: f9400e60 ldr x0, >>>>>>>>>>> [x19, #24] >>>>>>>>>>> ffff80008125a8e4: d63f0000 blr x0 >>>>>>>>>>> perf 12720/12720 [0001] 5986.372298040 >>>>>>>>>>> sched_clock_noinstr+0x3c >>>>>>>>>>> ...sight/linux/kernel/time/sched_clock.c 93 >>>>>>>>>>> cyc = (rd->read_sched_clock() - rd->epoch_cyc) & >>>>>>>>>>> Event type: branches >>>>>>>>>>> Sample = { cpu: 0001 addr: 0xffff8000801bb4cc phys_addr: >>>>>>>>>>> 0x0000000000000000 ip: 0xffff80008125a930 pid: 12720 tid: >>>>>>>>>>> 12720 period: 1 time: 5986372298040 } >>>>>>>>>>> >>>>>>>>>>> >>>>>>>>>>> With fix: >>>>>>>>>>> ========= >>>>>>>>>>> >>>>>>>>>>> Event type: branches >>>>>>>>>>> Sample = { cpu: 0001 addr: 0xffff80008030cb00 phys_addr: >>>>>>>>>>> 0x0000000000000000 ip: 0xffff800080313f0c pid: 12720 tid: >>>>>>>>>>> 12720 period: 1 time: 5986372298040 } >>>>>>>>>>> ffff800080313f04 <__perf_event_header__init_id+0x4c>: >>>>>>>>>>> ffff800080313f04: 36100094 tbz w20, >>>>>>>>>>> #2, ffff800080313f14 <__perf_event_header__init_id+0x5c> >>>>>>>>>>> ffff800080313f08: f941e6a0 ldr x0, >>>>>>>>>>> [x21, #968] >>>>>>>>>>> ffff800080313f0c: d63f0000 blr x0 >>>>>>>>>>> perf 12720/12720 [0001] 5986.372298040 >>>>>>>>>>> __perf_event_header__init_id+0x54 >>>>>>>>>>> .../coresight/linux/kernel/events/core.c 586 return >>>>>>>>>>> event->clock(); >>>>>>>>>>> Event type: branches >>>>>>>>>>> Sample = { cpu: 0001 addr: 0xffff8000801bb4a8 phys_addr: >>>>>>>>>>> 0x0000000000000000 ip: 0xffff80008030cb0c pid: 12720 tid: >>>>>>>>>>> 12720 period: 1 time: 5986372298040 } >>>>>>>>>>> ffff80008030cb00 <local_clock>: >>>>>>>>>>> ffff80008030cb00: d503233f paciasp >>>>>>>>>>> ffff80008030cb04: a9bf7bfd stp x29, >>>>>>>>>>> x30, [sp, #-16]! >>>>>>>>>>> ffff80008030cb08: 910003fd mov x29, sp >>>>>>>>>>> ffff80008030cb0c: 97faba67 bl >>>>>>>>>>> ffff8000801bb4a8 <sched_clock> >>>>>>>>>>> perf 12720/12720 [0001] 5986.372298040 >>>>>>>>>>> local_clock+0xc ...t/linux/./include/linux/sched/clock.h 64 >>>>>>>>>>> return sched_clock(); >>>>>>>>>>> Event type: branches >>>>>>>>>>> Sample = { cpu: 0001 addr: 0xffff80008125a8a8 phys_addr: >>>>>>>>>>> 0x0000000000000000 ip: 0xffff8000801bb4c8 pid: 12720 tid: >>>>>>>>>>> 12720 period: 1 time: 5986372298040 } >>>>>>>>>>> ffff8000801bb4a8 <sched_clock>: >>>>>>>>>>> ffff8000801bb4a8: d503233f paciasp >>>>>>>>>>> ffff8000801bb4ac: a9be7bfd stp x29, >>>>>>>>>>> x30, [sp, #-32]! >>>>>>>>>>> ffff8000801bb4b0: 910003fd mov x29, sp >>>>>>>>>>> ffff8000801bb4b4: a90153f3 stp x19, >>>>>>>>>>> x20, [sp, #16] >>>>>>>>>>> ffff8000801bb4b8: d5384113 mrs x19, >>>>>>>>>>> sp_el0 >>>>>>>>>>> ffff8000801bb4bc: b9401260 ldr w0, >>>>>>>>>>> [x19, #16] >>>>>>>>>>> ffff8000801bb4c0: 11000400 add w0, >>>>>>>>>>> w0, #0x1 >>>>>>>>>>> ffff8000801bb4c4: b9001260 str w0, >>>>>>>>>>> [x19, #16] >>>>>>>>>>> ffff8000801bb4c8: 94427cf8 bl >>>>>>>>>>> ffff80008125a8a8 <sched_clock_noinstr> >>>>>>>>>>> perf 12720/12720 [0001] 5986.372298040 >>>>>>>>>>> sched_clock+0x20 ...sight/linux/kernel/time/sched_clock.c 105 >>>>>>>>>>> ns = sched_clock_noinstr(); >>>>>>>>>>> Event type: branches >>>>>>>>>>> Sample = { cpu: 0001 addr: 0xffff80008125b758 phys_addr: >>>>>>>>>>> 0x0000000000000000 ip: 0xffff80008125a8e4 pid: 12720 tid: >>>>>>>>>>> 12720 period: 1 time: 5986372298040 } >>>>>>>>>>> ffff80008125a8a8 <sched_clock_noinstr>: >>>>>>>>>>> ffff80008125a8a8: d503233f paciasp >>>>>>>>>>> ffff80008125a8ac: a9bc7bfd stp x29, >>>>>>>>>>> x30, [sp, #-64]! >>>>>>>>>>> ffff80008125a8b0: 910003fd mov x29, sp >>>>>>>>>>> ffff80008125a8b4: a90153f3 stp x19, >>>>>>>>>>> x20, [sp, #16] >>>>>>>>>>> ffff80008125a8b8: b000e354 adrp x20, >>>>>>>>>>> ffff800082ec3000 <tick_bc_dev+0x140> >>>>>>>>>>> ffff80008125a8bc: 910d0294 add x20, >>>>>>>>>>> x20, #0x340 >>>>>>>>>>> ffff80008125a8c0: a90363f7 stp x23, >>>>>>>>>>> x24, [sp, #48] >>>>>>>>>>> ffff80008125a8c4: 91002297 add x23, >>>>>>>>>>> x20, #0x8 >>>>>>>>>>> ffff80008125a8c8: 52800518 mov w24, >>>>>>>>>>> #0x28 // #40 >>>>>>>>>>> ffff80008125a8cc: a9025bf5 stp x21, >>>>>>>>>>> x22, [sp, #32] >>>>>>>>>>> ffff80008125a8d0: b9400296 ldr w22, >>>>>>>>>>> [x20] >>>>>>>>>>> ffff80008125a8d4: 120002d5 and w21, >>>>>>>>>>> w22, #0x1 >>>>>>>>>>> ffff80008125a8d8: 9bb87eb5 umull x21, >>>>>>>>>>> w21, w24 >>>>>>>>>>> ffff80008125a8dc: 8b1502f3 add x19, >>>>>>>>>>> x23, x21 >>>>>>>>>>> ffff80008125a8e0: f9400e60 ldr x0, >>>>>>>>>>> [x19, #24] >>>>>>>>>>> ffff80008125a8e4: d63f0000 blr x0 >>>>>>>>>> >>>>>>>>>> It looks like the disassembly now assumes this BLR wasn't >>>>>>>>>> taken. We go from ffff80008125a8e4 straight through to ... >>>>>>>>>> >>>>>>>>>>> perf 12720/12720 [0001] 5986.372298040 >>>>>>>>>>> sched_clock_noinstr+0x3c >>>>>>>>>>> ...sight/linux/kernel/time/sched_clock.c 93 >>>>>>>>>>> cyc = (rd->read_sched_clock() - rd->epoch_cyc) & >>>>>>>>>>> Event type: branches >>>>>>>>>>> Sample = { cpu: 0001 addr: 0xffff8000801bb4cc phys_addr: >>>>>>>>>>> 0x0000000000000000 ip: 0xffff80008125a930 pid: 12720 tid: >>>>>>>>>>> 12720 period: 1 time: 5986372298040 } >>>>>>>>>>> ffff80008125a8e8 <sched_clock_noinstr+0x40>: >>>>>>>>>>> ffff80008125a8e8: f8756ae3 ldr x3, >>>>>>>>>>> [x23, x21] >>>>>>>>>> >>>>>>>>>> ffff80008125a8e4 which is just the previous one +4. Isn't your >>>>>>>>>> issue actually a decode issue in Perf itself? Why is there a >>>>>>>>>> discontinuity without branch samples being generated where >>>>>>>>>> either the source or destination address is 0? >>>>>>>>>> >>>>>>>>>> What are your record options to create this issue? As I >>>>>>>>>> mentioned in the previous reply I haven't been able to >>>>>>>>>> reproduce it. >>>>>>>>> >>>>>>>>> I am using below perf record command. >>>>>>>>> >>>>>>>>> timeout 4s ./perf record -e cs_etm// -C 1 dd if=/dev/zero >>>>>>>>> of=/dev/null >>>>>>>>> >>>>>>>> >>>>>>>> Thanks I managed to reproduce it. I'll take a look to see if I >>>>>>>> think the issue is somewhere else. >>>>>>>> >>>>>>> >>>>>>> At least for the failures I encountered, the issue is due to the >>>>>>> alternatives runtime instruction patching mechanism. vmlinux ends >>>>>>> up being the wrong image to decode with because a load of branches >>>>>>> are actually turned into nops. >>>>>>> >>>>>>> Can you confirm if you use --kcore instead of vmlinux that you >>>>>>> still get failures: >>>>>>> >>>>>>> sudo perf record -e cs_etm// -C 1 --kcore -o >>>>>>> <output-folder.data> -- \ >>>>>>> dd if=/dev/zero of=/dev/null >>>>>>> >>>>>>> perf script -i <output-folder.data> \ >>>>>>> tools/perf/scripts/python/arm-cs-trace-disasm.py -d >>>>>>> llvm-objdump \ >>>>>>> -k <output-folder.data>/kcore_dir/kcore >>>>>>> >>>>>> >>>>>> With below command combination with kcore also the issue is seen, >>>>>> as reported in this email chain. >>>>>> >>>>>> timeout 8s ./perf record -e cs_etm// -C 1 --kcore -o kcore \ >>>>>> dd if=/dev/zero of=/dev/null >>>>>> >>>>>> ./perf script -i kcore/data \ >>>>>> --script=python:./scripts/python/arm-cs-trace-disasm.py -- \ >>>>>> -d objdump -k kcore/kcore_dir/kcore >>>>>> >>>>>> >>>>>> However, with below sequence(same as your command) the issue is >>>>>> *not* seen. >>>>>> >>>>>> timeout 8s ./perf record -e cs_etm// -C 1 --kcore -o kcore \ >>>>>> dd if=/dev/zero of=/dev/null >>>>>> >>>>>> ./perf script -i kcore/data ./scripts/python/arm-cs-trace-disasm.py \ >>>>>> -- -d objdump -k kcore/kcore_dir/kcore >>>>>> >>>>>> Do you see any issue with the command, which is showing the problem? >>>>>> Also the output log produced by these both commands is different. >>>>>> >>> >>> BTW are you running this on the target or somewhere else? It's >>> suspicious that "-i kcore/data" works at all because there is no >>> kernel image given to Perf. Unless you are running on the target and >>> then I think it will just open the one from /proc. Or maybe it uses >>> /boot/vmlinux by default which also wouldn't work. >>> >>> Also the difference between "--script=python:" and just giving the >>> script name is in the parsing of the arguments following " -- ". >>> Sometimes they're also parsed as Perf arguments (like the -v becomes >>> perf verbose and -k becomes the Perf vmlinux rather than the script). >>> >>> I _think_ you want the " -- " when "--script" is used, and no "--" >>> when it's not. But there are some other combinations and you'll have >>> to debug it to compare your two exact scenarios to see why they're >>> different. >>> >>> But ignoring that issue with the argument format, you mentioned you >>> didn't see the issue any more with one version of --kcore. So I'm >>> assuming that confirms the issue is just a decode image issue, so we >>> shouldn't try to patch this script? >>> >> >> Although one change we should make to the script is change the example >> to use kcore. We can leave in one vmlinux one as an example if kcore >> isn't available, but add a note that it will fail if any patched code is >> traced (which is almost always). > > James, you may recall the year old thread > https://lore.kernel.org/all/ed8cea4c-a261-60ca-f4e1-333ec73cca8f@os.amperec…. > I described there an awkward workaround Ampere has used to solve the > patched code problem. At the time, it sounded like the maintainers were > interested in getting away from using the python script, mostly for > speed purposes. I didn't see the discussion go any further. > Oh yes thanks for the reminder. I wasn't thinking about the source code lines and debug symbols in this thread. I suppose your merging of kcore and vmlinux gives both the correct image and the symbols, but I was only focused on the image being correct, so only kcore was enough. It looks like everything we want to do from your previous thread is in addition to the fixes from this one. Even if we auto merge kcore + symbols and move the disassembly into Perf, we still want to detect decode issues earlier and not have IPs jumping backwards. Whether it's the script or Perf doing that the behavior should be the same. To summarise I think these are the changes to make: * Improve bad decode detection in OpenCSD * Get the script to auto merge kcore and vmlinux * Maybe we could get Perf to do this if both a kcore folder and -k vmlinux are used? * Improve the performance, either in the script or move more functionality into Perf

10 months, 2 weeks

Re: [PATCH] perf scripts python arm-cs-trace-disasm.py: Skip disasm if address continuity is broken

by James Clark

On 06/08/2024 8:02 am, Ganapatrao Kulkarni wrote: > > > On 05-08-2024 07:29 pm, James Clark wrote: >> >> >> On 05/08/2024 1:22 pm, Ganapatrao Kulkarni wrote: >>> >>> >>> On 01-08-2024 03:30 pm, James Clark wrote: >>>> >>>> >>>> On 24/07/2024 3:45 pm, James Clark wrote: >>>>> >>>>> >>>>> On 24/07/2024 7:38 am, Ganapatrao Kulkarni wrote: >>>>>> >>>>>> >>>>>> On 23-07-2024 09:16 pm, James Clark wrote: >>>>>>> >>>>>>> >>>>>>> On 23/07/2024 4:26 pm, Ganapatrao Kulkarni wrote: >>>>>>>> >>>>>>>> >>>>>>>> On 23-07-2024 06:40 pm, James Clark wrote: >>>>>>>>> >>>>>>>>> >>>>>>>>> On 22/07/2024 11:02 am, Ganapatrao Kulkarni wrote: >>>>>>>>>> >>>>>>>>>> Hi James, >>>>>>>>>> >>>>>>>>>> On 19-07-2024 08:09 pm, James Clark wrote: >>>>>>>>>>> >>>>>>>>>>> >>>>>>>>>>> On 19/07/2024 10:26 am, Ganapatrao Kulkarni wrote: >>>>>>>>>>>> To generate the instruction tracing, script uses 2 >>>>>>>>>>>> contiguous packets >>>>>>>>>>>> address range. If there a continuity brake due to >>>>>>>>>>>> discontiguous branch >>>>>>>>>>>> address, it is required to reset the tracing and start >>>>>>>>>>>> tracing with the >>>>>>>>>>>> new set of contiguous packets. >>>>>>>>>>>> >>>>>>>>>>>> Adding change to identify the break and complete the >>>>>>>>>>>> remaining tracing >>>>>>>>>>>> of current packets and restart tracing from new set of >>>>>>>>>>>> packets, if >>>>>>>>>>>> continuity is established. >>>>>>>>>>>> >>>>>>>>>>> >>>>>>>>>>> Hi Ganapatrao, >>>>>>>>>>> >>>>>>>>>>> Can you add a before and after example of what's changed to >>>>>>>>>>> the commit message? It wasn't immediately obvious to me if >>>>>>>>>>> this is adding missing output, or it was correcting the tail >>>>>>>>>>> end of the output that was previously wrong. >>>>>>>>>> >>>>>>>>>> It is adding tail end of the trace as well avoiding the >>>>>>>>>> segfault of the perf application. With out this change the >>>>>>>>>> perf segfaults with as below log >>>>>>>>>> >>>>>>>>>> >>>>>>>>>> ./perf script >>>>>>>>>> --script=python:./scripts/python/arm-cs-trace-disasm.py -- -d >>>>>>>>>> objdump -k ../../vmlinux -v $* > dump >>>>>>>>>> objdump: error: the stop address should be after the start >>>>>>>>>> address >>>>>>>>>> Traceback (most recent call last): >>>>>>>>>> File "./scripts/python/arm-cs-trace-disasm.py", line 271, >>>>>>>>>> in process_event >>>>>>>>>> print_disam(dso_fname, dso_vm_start, start_addr, stop_addr) >>>>>>>>>> File "./scripts/python/arm-cs-trace-disasm.py", line 105, >>>>>>>>>> in print_disam >>>>>>>>>> for line in read_disam(dso_fname, dso_start, start_addr, >>>>>>>>>> stop_addr): >>>>>>>>>> ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ >>>>>>>>>> File "./scripts/python/arm-cs-trace-disasm.py", line 99, in >>>>>>>>>> read_disam >>>>>>>>>> disasm_output = >>>>>>>>>> check_output(disasm).decode('utf-8').split('\n') >>>>>>>>>> ^^^^^^^^^^^^^^^^^^^^ >>>>>>>>>> File "/usr/lib64/python3.12/subprocess.py", line 466, in >>>>>>>>>> check_output >>>>>>>>>> return run(*popenargs, stdout=PIPE, timeout=timeout, >>>>>>>>>> check=True, >>>>>>>>>> ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ >>>>>>>>>> File "/usr/lib64/python3.12/subprocess.py", line 571, in run >>>>>>>>>> raise CalledProcessError(retcode, process.args, >>>>>>>>>> subprocess.CalledProcessError: Command '['objdump', '-d', >>>>>>>>>> '-z', '--start-address=0xffff80008125b758', >>>>>>>>>> '--stop-address=0xffff80008125a934', '../../vmlinux']' >>>>>>>>>> returned non-zero exit status 1. >>>>>>>>>> Fatal Python error: handler_call_die: problem in Python trace >>>>>>>>>> event handler >>>>>>>>>> Python runtime state: initialized >>>>>>>>>> >>>>>>>>>> Current thread 0x0000ffffb05054e0 (most recent call first): >>>>>>>>>> <no Python frame> >>>>>>>>>> >>>>>>>>>> Extension modules: perf_trace_context, systemd._journal, >>>>>>>>>> systemd._reader, systemd.id128, report._py3report, >>>>>>>>>> _dbus_bindings, problem._py3abrt (total: 7) >>>>>>>>>> Aborted (core dumped) >>>>>>>>>> >>>>>>>>>>> >>>>>>>>>>>> Signed-off-by: Ganapatrao Kulkarni >>>>>>>>>>>> <gankulkarni(a)os.amperecomputing.com> >>>>>>>>>>>> --- >>>>>>>>>>>> tools/perf/scripts/python/arm-cs-trace-disasm.py | 10 >>>>>>>>>>>> ++++++++++ >>>>>>>>>>>> 1 file changed, 10 insertions(+) >>>>>>>>>>>> >>>>>>>>>>>> diff --git >>>>>>>>>>>> a/tools/perf/scripts/python/arm-cs-trace-disasm.py >>>>>>>>>>>> b/tools/perf/scripts/python/arm-cs-trace-disasm.py >>>>>>>>>>>> index d973c2baed1c..ad10cee2c35e 100755 >>>>>>>>>>>> --- a/tools/perf/scripts/python/arm-cs-trace-disasm.py >>>>>>>>>>>> +++ b/tools/perf/scripts/python/arm-cs-trace-disasm.py >>>>>>>>>>>> @@ -198,6 +198,10 @@ def process_event(param_dict): >>>>>>>>>>>> cpu_data[str(cpu) + 'addr'] = addr >>>>>>>>>>>> return >>>>>>>>>>>> + if (cpu_data.get(str(cpu) + 'ip') == None): >>>>>>>>>>>> + cpu_data[str(cpu) + 'ip'] = ip >>>>>>>>>>>> + >>>>>>>>>>> >>>>>>>>>>> Do you need to write into the global cpu_data here? Doesn't >>>>>>>>>>> it get overwritten after you load it back into 'prev_ip' >>>>>>>>>> >>>>>>>>>> No, the logic is same as holding the addr of previous packet. >>>>>>>>>> Saving the previous packet saved ip in to prev_ip before >>>>>>>>>> overwriting with the current packet. >>>>>>>>> >>>>>>>>> It's not exactly the same logic as holding the addr of the >>>>>>>>> previous sample. For addr, we return on the first None, with >>>>>>>>> your change we now "pretend" that the second one is also the >>>>>>>>> previous one: >>>>>>>>> >>>>>>>>> if (cpu_data.get(str(cpu) + 'addr') == None): >>>>>>>>> cpu_data[str(cpu) + 'addr'] = addr >>>>>>>>> return <----------------------------sample 0 return >>>>>>>>> >>>>>>>>> if (cpu_data.get(str(cpu) + 'ip') == None): >>>>>>>>> cpu_data[str(cpu) + 'ip'] = ip <---- sample 1 save but >>>>>>>>> no return >>>>>>>>> >>>>>>>>> Then for sample 1 'prev_ip' is actually now the 'current' IP: >>>>>>>> >>>>>>>> Yes, it is dummy for first packet. Added anticipating that we >>>>>>>> wont hit the discontinuity for the first packet itself. >>>>>>>> >>>>>>>> Can this be changed to more intuitive like below? >>>>>>>> >>>>>>>> diff --git a/tools/perf/scripts/python/arm-cs-trace-disasm.py >>>>>>>> b/tools/perf/scripts/python/arm-cs-trace-disasm.py >>>>>>>> index d973c2baed1c..d49f5090059f 100755 >>>>>>>> --- a/tools/perf/scripts/python/arm-cs-trace-disasm.py >>>>>>>> +++ b/tools/perf/scripts/python/arm-cs-trace-disasm.py >>>>>>>> @@ -198,6 +198,8 @@ def process_event(param_dict): >>>>>>>> cpu_data[str(cpu) + 'addr'] = addr >>>>>>>> return >>>>>>>> >>>>>>>> + if (cpu_data.get(str(cpu) + 'ip') != None): >>>>>>>> + prev_ip = cpu_data[str(cpu) + 'ip'] >>>>>>>> >>>>>>>> if (options.verbose == True): >>>>>>>> print("Event type: %s" % name) >>>>>>>> @@ -243,12 +245,18 @@ def process_event(param_dict): >>>>>>>> >>>>>>>> # Record for previous sample packet >>>>>>>> cpu_data[str(cpu) + 'addr'] = addr >>>>>>>> + cpu_data[str(cpu) + 'ip'] = stop_addr >>>>>>>> >>>>>>>> # Handle CS_ETM_TRACE_ON packet if start_addr=0 and >>>>>>>> stop_addr=4 >>>>>>>> if (start_addr == 0 and stop_addr == 4): >>>>>>>> print("CPU%d: CS_ETM_TRACE_ON packet is >>>>>>>> inserted" % cpu) >>>>>>>> return >>>>>>>> >>>>>>>> + if (stop_addr < start_addr and prev_ip != 0): >>>>>>>> + # Continuity of the Packets broken, set >>>>>>>> start_addr to previous >>>>>>>> + # packet ip to complete the remaining tracing of >>>>>>>> the address range. >>>>>>>> + start_addr = prev_ip >>>>>>>> + >>>>>>>> if (start_addr < int(dso_start) or start_addr > >>>>>>>> int(dso_end)): >>>>>>>> print("Start address 0x%x is out of range [ >>>>>>>> 0x%x .. 0x%x ] for dso %s" % (start_addr, int(dso_start), >>>>>>>> int(dso_end), dso)) >>>>>>>> return >>>>>>>> >>>>>>>> Without this patch below is the failure log(with segfault) for >>>>>>>> reference. >>>>>>>> >>>>>>>> [root@sut01sys-r214 perf]# timeout 4s ./perf record -e cs_etm// >>>>>>>> -C 1 dd if=/dev/zero of=/dev/null >>>>>>>> [ perf record: Woken up 1 times to write data ] >>>>>>>> [ perf record: Captured and wrote 1.087 MB perf.data ] >>>>>>>> [root@sut01sys-r214 perf]# ./perf script >>>>>>>> --script=python:./scripts/python/arm-cs-trace-disasm.py -- -d >>>>>>>> objdump -k ../../vmlinux -v $* > dump >>>>>>>> objdump: error: the stop address should be after the start address >>>>>>>> Traceback (most recent call last): >>>>>>>> File "./scripts/python/arm-cs-trace-disasm.py", line 271, in >>>>>>>> process_event >>>>>>>> print_disam(dso_fname, dso_vm_start, start_addr, stop_addr) >>>>>>>> File "./scripts/python/arm-cs-trace-disasm.py", line 105, in >>>>>>>> print_disam >>>>>>>> for line in read_disam(dso_fname, dso_start, start_addr, >>>>>>>> stop_addr): >>>>>>>> ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ >>>>>>>> File "./scripts/python/arm-cs-trace-disasm.py", line 99, in >>>>>>>> read_disam >>>>>>>> disasm_output = >>>>>>>> check_output(disasm).decode('utf-8').split('\n') >>>>>>>> ^^^^^^^^^^^^^^^^^^^^ >>>>>>>> File "/usr/lib64/python3.12/subprocess.py", line 466, in >>>>>>>> check_output >>>>>>>> return run(*popenargs, stdout=PIPE, timeout=timeout, >>>>>>>> check=True, >>>>>>>> ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ >>>>>>>> File "/usr/lib64/python3.12/subprocess.py", line 571, in run >>>>>>>> raise CalledProcessError(retcode, process.args, >>>>>>>> subprocess.CalledProcessError: Command '['objdump', '-d', '-z', >>>>>>>> '--start-address=0xffff80008125b758', >>>>>>>> '--stop-address=0xffff80008125a934', '../../vmlinux']' returned >>>>>>>> non-zero exit status 1. >>>>>>>> Fatal Python error: handler_call_die: problem in Python trace >>>>>>>> event handler >>>>>>>> Python runtime state: initialized >>>>>>>> >>>>>>>> Current thread 0x0000ffffb90d54e0 (most recent call first): >>>>>>>> <no Python frame> >>>>>>>> >>>>>>>> Extension modules: perf_trace_context, systemd._journal, >>>>>>>> systemd._reader, systemd.id128, report._py3report, >>>>>>>> _dbus_bindings, problem._py3abrt (total: 7) >>>>>>>> Aborted (core dumped) >>>>>>>> >>>>>>>> >>>>>>>> dump snippet: >>>>>>>> ============ >>>>>>>> Event type: branches >>>>>>>> Sample = { cpu: 0001 addr: 0xffff80008030cb00 phys_addr: >>>>>>>> 0x0000000000000000 ip: 0xffff800080313f0c pid: 12720 tid: 12720 >>>>>>>> period: 1 time: 5986372298040 } >>>>>>>> ffff800080313f04 <__perf_event_header__init_id+0x4c>: >>>>>>>> ffff800080313f04: 36100094 tbz w20, >>>>>>>> #2, ffff800080313f14 <__perf_event_header__init_id+0x5c> >>>>>>>> ffff800080313f08: f941e6a0 ldr x0, >>>>>>>> [x21, #968] >>>>>>>> ffff800080313f0c: d63f0000 blr x0 >>>>>>>> perf 12720/12720 [0001] 5986.372298040 >>>>>>>> __perf_event_header__init_id+0x54 >>>>>>>> .../coresight/linux/kernel/events/core.c 586 return >>>>>>>> event->clock(); >>>>>>>> Event type: branches >>>>>>>> Sample = { cpu: 0001 addr: 0xffff8000801bb4a8 phys_addr: >>>>>>>> 0x0000000000000000 ip: 0xffff80008030cb0c pid: 12720 tid: 12720 >>>>>>>> period: 1 time: 5986372298040 } >>>>>>>> ffff80008030cb00 <local_clock>: >>>>>>>> ffff80008030cb00: d503233f paciasp >>>>>>>> ffff80008030cb04: a9bf7bfd stp x29, >>>>>>>> x30, [sp, #-16]! >>>>>>>> ffff80008030cb08: 910003fd mov x29, sp >>>>>>>> ffff80008030cb0c: 97faba67 bl >>>>>>>> ffff8000801bb4a8 <sched_clock> >>>>>>>> perf 12720/12720 [0001] 5986.372298040 >>>>>>>> local_clock+0xc ...t/linux/./include/linux/sched/clock.h 64 >>>>>>>> return sched_clock(); >>>>>>>> Event type: branches >>>>>>>> Sample = { cpu: 0001 addr: 0xffff80008125a8a8 phys_addr: >>>>>>>> 0x0000000000000000 ip: 0xffff8000801bb4c8 pid: 12720 tid: 12720 >>>>>>>> period: 1 time: 5986372298040 } >>>>>>>> ffff8000801bb4a8 <sched_clock>: >>>>>>>> ffff8000801bb4a8: d503233f paciasp >>>>>>>> ffff8000801bb4ac: a9be7bfd stp x29, >>>>>>>> x30, [sp, #-32]! >>>>>>>> ffff8000801bb4b0: 910003fd mov x29, sp >>>>>>>> ffff8000801bb4b4: a90153f3 stp x19, >>>>>>>> x20, [sp, #16] >>>>>>>> ffff8000801bb4b8: d5384113 mrs x19, >>>>>>>> sp_el0 >>>>>>>> ffff8000801bb4bc: b9401260 ldr w0, >>>>>>>> [x19, #16] >>>>>>>> ffff8000801bb4c0: 11000400 add w0, w0, >>>>>>>> #0x1 >>>>>>>> ffff8000801bb4c4: b9001260 str w0, >>>>>>>> [x19, #16] >>>>>>>> ffff8000801bb4c8: 94427cf8 bl >>>>>>>> ffff80008125a8a8 <sched_clock_noinstr> >>>>>>>> perf 12720/12720 [0001] 5986.372298040 >>>>>>>> sched_clock+0x20 ...sight/linux/kernel/time/sched_clock.c 105 >>>>>>>> ns = sched_clock_noinstr(); >>>>>>>> Event type: branches >>>>>>>> Sample = { cpu: 0001 addr: 0xffff80008125b758 phys_addr: >>>>>>>> 0x0000000000000000 ip: 0xffff80008125a8e4 pid: 12720 tid: 12720 >>>>>>>> period: 1 time: 5986372298040 } >>>>>>>> ffff80008125a8a8 <sched_clock_noinstr>: >>>>>>>> ffff80008125a8a8: d503233f paciasp >>>>>>>> ffff80008125a8ac: a9bc7bfd stp x29, >>>>>>>> x30, [sp, #-64]! >>>>>>>> ffff80008125a8b0: 910003fd mov x29, sp >>>>>>>> ffff80008125a8b4: a90153f3 stp x19, >>>>>>>> x20, [sp, #16] >>>>>>>> ffff80008125a8b8: b000e354 adrp x20, >>>>>>>> ffff800082ec3000 <tick_bc_dev+0x140> >>>>>>>> ffff80008125a8bc: 910d0294 add x20, >>>>>>>> x20, #0x340 >>>>>>>> ffff80008125a8c0: a90363f7 stp x23, >>>>>>>> x24, [sp, #48] >>>>>>>> ffff80008125a8c4: 91002297 add x23, >>>>>>>> x20, #0x8 >>>>>>>> ffff80008125a8c8: 52800518 mov w24, >>>>>>>> #0x28 // #40 >>>>>>>> ffff80008125a8cc: a9025bf5 stp x21, >>>>>>>> x22, [sp, #32] >>>>>>>> ffff80008125a8d0: b9400296 ldr w22, [x20] >>>>>>>> ffff80008125a8d4: 120002d5 and w21, >>>>>>>> w22, #0x1 >>>>>>>> ffff80008125a8d8: 9bb87eb5 umull x21, >>>>>>>> w21, w24 >>>>>>>> ffff80008125a8dc: 8b1502f3 add x19, >>>>>>>> x23, x21 >>>>>>>> ffff80008125a8e0: f9400e60 ldr x0, >>>>>>>> [x19, #24] >>>>>>>> ffff80008125a8e4: d63f0000 blr x0 >>>>>>>> perf 12720/12720 [0001] 5986.372298040 >>>>>>>> sched_clock_noinstr+0x3c >>>>>>>> ...sight/linux/kernel/time/sched_clock.c 93 cyc >>>>>>>> = (rd->read_sched_clock() - rd->epoch_cyc) & >>>>>>>> Event type: branches >>>>>>>> Sample = { cpu: 0001 addr: 0xffff8000801bb4cc phys_addr: >>>>>>>> 0x0000000000000000 ip: 0xffff80008125a930 pid: 12720 tid: 12720 >>>>>>>> period: 1 time: 5986372298040 } >>>>>>>> >>>>>>>> >>>>>>>> With fix: >>>>>>>> ========= >>>>>>>> >>>>>>>> Event type: branches >>>>>>>> Sample = { cpu: 0001 addr: 0xffff80008030cb00 phys_addr: >>>>>>>> 0x0000000000000000 ip: 0xffff800080313f0c pid: 12720 tid: 12720 >>>>>>>> period: 1 time: 5986372298040 } >>>>>>>> ffff800080313f04 <__perf_event_header__init_id+0x4c>: >>>>>>>> ffff800080313f04: 36100094 tbz w20, >>>>>>>> #2, ffff800080313f14 <__perf_event_header__init_id+0x5c> >>>>>>>> ffff800080313f08: f941e6a0 ldr x0, >>>>>>>> [x21, #968] >>>>>>>> ffff800080313f0c: d63f0000 blr x0 >>>>>>>> perf 12720/12720 [0001] 5986.372298040 >>>>>>>> __perf_event_header__init_id+0x54 >>>>>>>> .../coresight/linux/kernel/events/core.c 586 return >>>>>>>> event->clock(); >>>>>>>> Event type: branches >>>>>>>> Sample = { cpu: 0001 addr: 0xffff8000801bb4a8 phys_addr: >>>>>>>> 0x0000000000000000 ip: 0xffff80008030cb0c pid: 12720 tid: 12720 >>>>>>>> period: 1 time: 5986372298040 } >>>>>>>> ffff80008030cb00 <local_clock>: >>>>>>>> ffff80008030cb00: d503233f paciasp >>>>>>>> ffff80008030cb04: a9bf7bfd stp x29, >>>>>>>> x30, [sp, #-16]! >>>>>>>> ffff80008030cb08: 910003fd mov x29, sp >>>>>>>> ffff80008030cb0c: 97faba67 bl >>>>>>>> ffff8000801bb4a8 <sched_clock> >>>>>>>> perf 12720/12720 [0001] 5986.372298040 >>>>>>>> local_clock+0xc ...t/linux/./include/linux/sched/clock.h 64 >>>>>>>> return sched_clock(); >>>>>>>> Event type: branches >>>>>>>> Sample = { cpu: 0001 addr: 0xffff80008125a8a8 phys_addr: >>>>>>>> 0x0000000000000000 ip: 0xffff8000801bb4c8 pid: 12720 tid: 12720 >>>>>>>> period: 1 time: 5986372298040 } >>>>>>>> ffff8000801bb4a8 <sched_clock>: >>>>>>>> ffff8000801bb4a8: d503233f paciasp >>>>>>>> ffff8000801bb4ac: a9be7bfd stp x29, >>>>>>>> x30, [sp, #-32]! >>>>>>>> ffff8000801bb4b0: 910003fd mov x29, sp >>>>>>>> ffff8000801bb4b4: a90153f3 stp x19, >>>>>>>> x20, [sp, #16] >>>>>>>> ffff8000801bb4b8: d5384113 mrs x19, >>>>>>>> sp_el0 >>>>>>>> ffff8000801bb4bc: b9401260 ldr w0, >>>>>>>> [x19, #16] >>>>>>>> ffff8000801bb4c0: 11000400 add w0, w0, >>>>>>>> #0x1 >>>>>>>> ffff8000801bb4c4: b9001260 str w0, >>>>>>>> [x19, #16] >>>>>>>> ffff8000801bb4c8: 94427cf8 bl >>>>>>>> ffff80008125a8a8 <sched_clock_noinstr> >>>>>>>> perf 12720/12720 [0001] 5986.372298040 >>>>>>>> sched_clock+0x20 ...sight/linux/kernel/time/sched_clock.c 105 >>>>>>>> ns = sched_clock_noinstr(); >>>>>>>> Event type: branches >>>>>>>> Sample = { cpu: 0001 addr: 0xffff80008125b758 phys_addr: >>>>>>>> 0x0000000000000000 ip: 0xffff80008125a8e4 pid: 12720 tid: 12720 >>>>>>>> period: 1 time: 5986372298040 } >>>>>>>> ffff80008125a8a8 <sched_clock_noinstr>: >>>>>>>> ffff80008125a8a8: d503233f paciasp >>>>>>>> ffff80008125a8ac: a9bc7bfd stp x29, >>>>>>>> x30, [sp, #-64]! >>>>>>>> ffff80008125a8b0: 910003fd mov x29, sp >>>>>>>> ffff80008125a8b4: a90153f3 stp x19, >>>>>>>> x20, [sp, #16] >>>>>>>> ffff80008125a8b8: b000e354 adrp x20, >>>>>>>> ffff800082ec3000 <tick_bc_dev+0x140> >>>>>>>> ffff80008125a8bc: 910d0294 add x20, >>>>>>>> x20, #0x340 >>>>>>>> ffff80008125a8c0: a90363f7 stp x23, >>>>>>>> x24, [sp, #48] >>>>>>>> ffff80008125a8c4: 91002297 add x23, >>>>>>>> x20, #0x8 >>>>>>>> ffff80008125a8c8: 52800518 mov w24, >>>>>>>> #0x28 // #40 >>>>>>>> ffff80008125a8cc: a9025bf5 stp x21, >>>>>>>> x22, [sp, #32] >>>>>>>> ffff80008125a8d0: b9400296 ldr w22, [x20] >>>>>>>> ffff80008125a8d4: 120002d5 and w21, >>>>>>>> w22, #0x1 >>>>>>>> ffff80008125a8d8: 9bb87eb5 umull x21, >>>>>>>> w21, w24 >>>>>>>> ffff80008125a8dc: 8b1502f3 add x19, >>>>>>>> x23, x21 >>>>>>>> ffff80008125a8e0: f9400e60 ldr x0, >>>>>>>> [x19, #24] >>>>>>>> ffff80008125a8e4: d63f0000 blr x0 >>>>>>> >>>>>>> It looks like the disassembly now assumes this BLR wasn't taken. >>>>>>> We go from ffff80008125a8e4 straight through to ... >>>>>>> >>>>>>>> perf 12720/12720 [0001] 5986.372298040 >>>>>>>> sched_clock_noinstr+0x3c >>>>>>>> ...sight/linux/kernel/time/sched_clock.c 93 cyc >>>>>>>> = (rd->read_sched_clock() - rd->epoch_cyc) & >>>>>>>> Event type: branches >>>>>>>> Sample = { cpu: 0001 addr: 0xffff8000801bb4cc phys_addr: >>>>>>>> 0x0000000000000000 ip: 0xffff80008125a930 pid: 12720 tid: 12720 >>>>>>>> period: 1 time: 5986372298040 } >>>>>>>> ffff80008125a8e8 <sched_clock_noinstr+0x40>: >>>>>>>> ffff80008125a8e8: f8756ae3 ldr x3, >>>>>>>> [x23, x21] >>>>>>> >>>>>>> ffff80008125a8e4 which is just the previous one +4. Isn't your >>>>>>> issue actually a decode issue in Perf itself? Why is there a >>>>>>> discontinuity without branch samples being generated where either >>>>>>> the source or destination address is 0? >>>>>>> >>>>>>> What are your record options to create this issue? As I mentioned >>>>>>> in the previous reply I haven't been able to reproduce it. >>>>>> >>>>>> I am using below perf record command. >>>>>> >>>>>> timeout 4s ./perf record -e cs_etm// -C 1 dd if=/dev/zero >>>>>> of=/dev/null >>>>>> >>>>> >>>>> Thanks I managed to reproduce it. I'll take a look to see if I >>>>> think the issue is somewhere else. >>>>> >>>> >>>> At least for the failures I encountered, the issue is due to the >>>> alternatives runtime instruction patching mechanism. vmlinux ends up >>>> being the wrong image to decode with because a load of branches are >>>> actually turned into nops. >>>> >>>> Can you confirm if you use --kcore instead of vmlinux that you still >>>> get failures: >>>> >>>> sudo perf record -e cs_etm// -C 1 --kcore -o <output-folder.data> >>>> -- \ >>>> dd if=/dev/zero of=/dev/null >>>> >>>> perf script -i <output-folder.data> \ >>>> tools/perf/scripts/python/arm-cs-trace-disasm.py -d llvm-objdump \ >>>> -k <output-folder.data>/kcore_dir/kcore >>>> >>> >>> With below command combination with kcore also the issue is seen, as >>> reported in this email chain. >>> >>> timeout 8s ./perf record -e cs_etm// -C 1 --kcore -o kcore \ >>> dd if=/dev/zero of=/dev/null >>> >>> ./perf script -i kcore/data \ >>> --script=python:./scripts/python/arm-cs-trace-disasm.py -- \ >>> -d objdump -k kcore/kcore_dir/kcore >>> >>> >>> However, with below sequence(same as your command) the issue is *not* >>> seen. >>> >>> timeout 8s ./perf record -e cs_etm// -C 1 --kcore -o kcore \ >>> dd if=/dev/zero of=/dev/null >>> >>> ./perf script -i kcore/data ./scripts/python/arm-cs-trace-disasm.py \ >>> -- -d objdump -k kcore/kcore_dir/kcore >>> >>> Do you see any issue with the command, which is showing the problem? >>> Also the output log produced by these both commands is different. >>> BTW are you running this on the target or somewhere else? It's suspicious that "-i kcore/data" works at all because there is no kernel image given to Perf. Unless you are running on the target and then I think it will just open the one from /proc. Or maybe it uses /boot/vmlinux by default which also wouldn't work. Also the difference between "--script=python:" and just giving the script name is in the parsing of the arguments following " -- ". Sometimes they're also parsed as Perf arguments (like the -v becomes perf verbose and -k becomes the Perf vmlinux rather than the script). I _think_ you want the " -- " when "--script" is used, and no "--" when it's not. But there are some other combinations and you'll have to debug it to compare your two exact scenarios to see why they're different. But ignoring that issue with the argument format, you mentioned you didn't see the issue any more with one version of --kcore. So I'm assuming that confirms the issue is just a decode image issue, so we shouldn't try to patch this script? >> >> Double check the command I gave. "-i" needs to be the same as "-o" >> (it's the folder, not the data file). I think this could be causing >> your issue. Unless you give it the folder it doesn't open kcore along >> with the data file. >> > > As per 'perf script --help' > > -i, --input= > Input file name. (default: perf.data unless stdin is a fifo) > That could probably say "file name, or folder when --kcore is used", if you mean that you think it's not accurate? But when you use --kcore the default folder (not file) name is still perf.data, so the default argument gives you a clue that you're not supposed to descend into the folder. > Also tried just giving dir as you suggested and still the same. > > ./perf script -i kcore > --script=python:./scripts/python/arm-cs-trace-disasm.py -- -d objdump -k > kcore/kcore_dir/kcore > >>> The below diff that you have shared has no effect on the failing case. >>> >>>> But I still think bad decode detection should be moved as much as >>>> possible into OpenCSD and Perf rather than this script. Otherwise >>>> every tool will have to re-implement it, and OpenCSD has a lot more >>>> info to make decisions with. >>>> >>>> One change we can make is to desynchronize when an N atom is an >>>> unconditional branch: >>>> >>>> diff --git a/decoder/source/etmv4/trc_pkt_decode_etmv4i.cpp >>>> b/decoder/source/etmv4/trc_pkt_decode_etmv4i.cpp >>>> index c557998..3eefd5d 100644 >>>> --- a/decoder/source/etmv4/trc_pkt_decode_etmv4i.cpp >>>> +++ b/decoder/source/etmv4/trc_pkt_decode_etmv4i.cpp >>>> @@ -1341,6 +1341,14 @@ ocsd_err_t >>>> TrcPktDecodeEtmV4I::processAtom(const ocsd_atm_val atom) >>>> // save recorded next instuction address >>>> ocsd_vaddr_t nextAddr = m_instr_info.instr_addr; >>>> >>>> + // must have lost sync if an unconditional branch wasn't taken >>>> + if (atom == ATOM_N && !m_instr_info.is_conditional) { >>>> + m_need_addr = true; >>>> + m_out_elem.addElemType(m_index_curr_pkt, >>>> OCSD_GEN_TRC_ELEM_NO_SYNC); >>>> + // wait for next address >>>> + return OCSD_OK; >>>> + } >>>> + >>>> >>>> Another one we can spot is when a new address comes that is before >>>> the current decode address (basically the backwards check that you >>>> added). >>>> >>>> There are probably others that can be spotted like an address >>>> appearing after a direct branch that doesn't match the branch target. >>>> >>>> I think at that point, desynchronising should cause the disassembly >>>> script to throw away the last bit, rather than force it to be >>>> printed as in this patch. As I mentioned above in the thread, it >>>> leads to printing disassembly that's implausible and misleading >>>> (where an unconditional branch wasn't taken). >>> > > Thanks, > Ganapat

10 months, 2 weeks

Re: [PATCH] perf scripts python arm-cs-trace-disasm.py: Skip disasm if address continuity is broken

by James Clark

On 05/08/2024 1:22 pm, Ganapatrao Kulkarni wrote: > > > On 01-08-2024 03:30 pm, James Clark wrote: >> >> >> On 24/07/2024 3:45 pm, James Clark wrote: >>> >>> >>> On 24/07/2024 7:38 am, Ganapatrao Kulkarni wrote: >>>> >>>> >>>> On 23-07-2024 09:16 pm, James Clark wrote: >>>>> >>>>> >>>>> On 23/07/2024 4:26 pm, Ganapatrao Kulkarni wrote: >>>>>> >>>>>> >>>>>> On 23-07-2024 06:40 pm, James Clark wrote: >>>>>>> >>>>>>> >>>>>>> On 22/07/2024 11:02 am, Ganapatrao Kulkarni wrote: >>>>>>>> >>>>>>>> Hi James, >>>>>>>> >>>>>>>> On 19-07-2024 08:09 pm, James Clark wrote: >>>>>>>>> >>>>>>>>> >>>>>>>>> On 19/07/2024 10:26 am, Ganapatrao Kulkarni wrote: >>>>>>>>>> To generate the instruction tracing, script uses 2 contiguous >>>>>>>>>> packets >>>>>>>>>> address range. If there a continuity brake due to >>>>>>>>>> discontiguous branch >>>>>>>>>> address, it is required to reset the tracing and start tracing >>>>>>>>>> with the >>>>>>>>>> new set of contiguous packets. >>>>>>>>>> >>>>>>>>>> Adding change to identify the break and complete the remaining >>>>>>>>>> tracing >>>>>>>>>> of current packets and restart tracing from new set of >>>>>>>>>> packets, if >>>>>>>>>> continuity is established. >>>>>>>>>> >>>>>>>>> >>>>>>>>> Hi Ganapatrao, >>>>>>>>> >>>>>>>>> Can you add a before and after example of what's changed to the >>>>>>>>> commit message? It wasn't immediately obvious to me if this is >>>>>>>>> adding missing output, or it was correcting the tail end of the >>>>>>>>> output that was previously wrong. >>>>>>>> >>>>>>>> It is adding tail end of the trace as well avoiding the segfault >>>>>>>> of the perf application. With out this change the perf segfaults >>>>>>>> with as below log >>>>>>>> >>>>>>>> >>>>>>>> ./perf script >>>>>>>> --script=python:./scripts/python/arm-cs-trace-disasm.py -- -d >>>>>>>> objdump -k ../../vmlinux -v $* > dump >>>>>>>> objdump: error: the stop address should be after the start address >>>>>>>> Traceback (most recent call last): >>>>>>>> File "./scripts/python/arm-cs-trace-disasm.py", line 271, in >>>>>>>> process_event >>>>>>>> print_disam(dso_fname, dso_vm_start, start_addr, stop_addr) >>>>>>>> File "./scripts/python/arm-cs-trace-disasm.py", line 105, in >>>>>>>> print_disam >>>>>>>> for line in read_disam(dso_fname, dso_start, start_addr, >>>>>>>> stop_addr): >>>>>>>> ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ >>>>>>>> File "./scripts/python/arm-cs-trace-disasm.py", line 99, in >>>>>>>> read_disam >>>>>>>> disasm_output = >>>>>>>> check_output(disasm).decode('utf-8').split('\n') >>>>>>>> ^^^^^^^^^^^^^^^^^^^^ >>>>>>>> File "/usr/lib64/python3.12/subprocess.py", line 466, in >>>>>>>> check_output >>>>>>>> return run(*popenargs, stdout=PIPE, timeout=timeout, >>>>>>>> check=True, >>>>>>>> ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ >>>>>>>> File "/usr/lib64/python3.12/subprocess.py", line 571, in run >>>>>>>> raise CalledProcessError(retcode, process.args, >>>>>>>> subprocess.CalledProcessError: Command '['objdump', '-d', '-z', >>>>>>>> '--start-address=0xffff80008125b758', >>>>>>>> '--stop-address=0xffff80008125a934', '../../vmlinux']' returned >>>>>>>> non-zero exit status 1. >>>>>>>> Fatal Python error: handler_call_die: problem in Python trace >>>>>>>> event handler >>>>>>>> Python runtime state: initialized >>>>>>>> >>>>>>>> Current thread 0x0000ffffb05054e0 (most recent call first): >>>>>>>> <no Python frame> >>>>>>>> >>>>>>>> Extension modules: perf_trace_context, systemd._journal, >>>>>>>> systemd._reader, systemd.id128, report._py3report, >>>>>>>> _dbus_bindings, problem._py3abrt (total: 7) >>>>>>>> Aborted (core dumped) >>>>>>>> >>>>>>>>> >>>>>>>>>> Signed-off-by: Ganapatrao Kulkarni >>>>>>>>>> <gankulkarni(a)os.amperecomputing.com> >>>>>>>>>> --- >>>>>>>>>> tools/perf/scripts/python/arm-cs-trace-disasm.py | 10 >>>>>>>>>> ++++++++++ >>>>>>>>>> 1 file changed, 10 insertions(+) >>>>>>>>>> >>>>>>>>>> diff --git a/tools/perf/scripts/python/arm-cs-trace-disasm.py >>>>>>>>>> b/tools/perf/scripts/python/arm-cs-trace-disasm.py >>>>>>>>>> index d973c2baed1c..ad10cee2c35e 100755 >>>>>>>>>> --- a/tools/perf/scripts/python/arm-cs-trace-disasm.py >>>>>>>>>> +++ b/tools/perf/scripts/python/arm-cs-trace-disasm.py >>>>>>>>>> @@ -198,6 +198,10 @@ def process_event(param_dict): >>>>>>>>>> cpu_data[str(cpu) + 'addr'] = addr >>>>>>>>>> return >>>>>>>>>> + if (cpu_data.get(str(cpu) + 'ip') == None): >>>>>>>>>> + cpu_data[str(cpu) + 'ip'] = ip >>>>>>>>>> + >>>>>>>>> >>>>>>>>> Do you need to write into the global cpu_data here? Doesn't it >>>>>>>>> get overwritten after you load it back into 'prev_ip' >>>>>>>> >>>>>>>> No, the logic is same as holding the addr of previous packet. >>>>>>>> Saving the previous packet saved ip in to prev_ip before >>>>>>>> overwriting with the current packet. >>>>>>> >>>>>>> It's not exactly the same logic as holding the addr of the >>>>>>> previous sample. For addr, we return on the first None, with your >>>>>>> change we now "pretend" that the second one is also the previous >>>>>>> one: >>>>>>> >>>>>>> if (cpu_data.get(str(cpu) + 'addr') == None): >>>>>>> cpu_data[str(cpu) + 'addr'] = addr >>>>>>> return <----------------------------sample 0 return >>>>>>> >>>>>>> if (cpu_data.get(str(cpu) + 'ip') == None): >>>>>>> cpu_data[str(cpu) + 'ip'] = ip <---- sample 1 save but no >>>>>>> return >>>>>>> >>>>>>> Then for sample 1 'prev_ip' is actually now the 'current' IP: >>>>>> >>>>>> Yes, it is dummy for first packet. Added anticipating that we wont >>>>>> hit the discontinuity for the first packet itself. >>>>>> >>>>>> Can this be changed to more intuitive like below? >>>>>> >>>>>> diff --git a/tools/perf/scripts/python/arm-cs-trace-disasm.py >>>>>> b/tools/perf/scripts/python/arm-cs-trace-disasm.py >>>>>> index d973c2baed1c..d49f5090059f 100755 >>>>>> --- a/tools/perf/scripts/python/arm-cs-trace-disasm.py >>>>>> +++ b/tools/perf/scripts/python/arm-cs-trace-disasm.py >>>>>> @@ -198,6 +198,8 @@ def process_event(param_dict): >>>>>> cpu_data[str(cpu) + 'addr'] = addr >>>>>> return >>>>>> >>>>>> + if (cpu_data.get(str(cpu) + 'ip') != None): >>>>>> + prev_ip = cpu_data[str(cpu) + 'ip'] >>>>>> >>>>>> if (options.verbose == True): >>>>>> print("Event type: %s" % name) >>>>>> @@ -243,12 +245,18 @@ def process_event(param_dict): >>>>>> >>>>>> # Record for previous sample packet >>>>>> cpu_data[str(cpu) + 'addr'] = addr >>>>>> + cpu_data[str(cpu) + 'ip'] = stop_addr >>>>>> >>>>>> # Handle CS_ETM_TRACE_ON packet if start_addr=0 and >>>>>> stop_addr=4 >>>>>> if (start_addr == 0 and stop_addr == 4): >>>>>> print("CPU%d: CS_ETM_TRACE_ON packet is inserted" >>>>>> % cpu) >>>>>> return >>>>>> >>>>>> + if (stop_addr < start_addr and prev_ip != 0): >>>>>> + # Continuity of the Packets broken, set start_addr >>>>>> to previous >>>>>> + # packet ip to complete the remaining tracing of >>>>>> the address range. >>>>>> + start_addr = prev_ip >>>>>> + >>>>>> if (start_addr < int(dso_start) or start_addr > >>>>>> int(dso_end)): >>>>>> print("Start address 0x%x is out of range [ 0x%x >>>>>> .. 0x%x ] for dso %s" % (start_addr, int(dso_start), int(dso_end), >>>>>> dso)) >>>>>> return >>>>>> >>>>>> Without this patch below is the failure log(with segfault) for >>>>>> reference. >>>>>> >>>>>> [root@sut01sys-r214 perf]# timeout 4s ./perf record -e cs_etm// -C >>>>>> 1 dd if=/dev/zero of=/dev/null >>>>>> [ perf record: Woken up 1 times to write data ] >>>>>> [ perf record: Captured and wrote 1.087 MB perf.data ] >>>>>> [root@sut01sys-r214 perf]# ./perf script >>>>>> --script=python:./scripts/python/arm-cs-trace-disasm.py -- -d >>>>>> objdump -k ../../vmlinux -v $* > dump >>>>>> objdump: error: the stop address should be after the start address >>>>>> Traceback (most recent call last): >>>>>> File "./scripts/python/arm-cs-trace-disasm.py", line 271, in >>>>>> process_event >>>>>> print_disam(dso_fname, dso_vm_start, start_addr, stop_addr) >>>>>> File "./scripts/python/arm-cs-trace-disasm.py", line 105, in >>>>>> print_disam >>>>>> for line in read_disam(dso_fname, dso_start, start_addr, >>>>>> stop_addr): >>>>>> ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ >>>>>> File "./scripts/python/arm-cs-trace-disasm.py", line 99, in >>>>>> read_disam >>>>>> disasm_output = check_output(disasm).decode('utf-8').split('\n') >>>>>> ^^^^^^^^^^^^^^^^^^^^ >>>>>> File "/usr/lib64/python3.12/subprocess.py", line 466, in >>>>>> check_output >>>>>> return run(*popenargs, stdout=PIPE, timeout=timeout, check=True, >>>>>> ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ >>>>>> File "/usr/lib64/python3.12/subprocess.py", line 571, in run >>>>>> raise CalledProcessError(retcode, process.args, >>>>>> subprocess.CalledProcessError: Command '['objdump', '-d', '-z', >>>>>> '--start-address=0xffff80008125b758', >>>>>> '--stop-address=0xffff80008125a934', '../../vmlinux']' returned >>>>>> non-zero exit status 1. >>>>>> Fatal Python error: handler_call_die: problem in Python trace >>>>>> event handler >>>>>> Python runtime state: initialized >>>>>> >>>>>> Current thread 0x0000ffffb90d54e0 (most recent call first): >>>>>> <no Python frame> >>>>>> >>>>>> Extension modules: perf_trace_context, systemd._journal, >>>>>> systemd._reader, systemd.id128, report._py3report, _dbus_bindings, >>>>>> problem._py3abrt (total: 7) >>>>>> Aborted (core dumped) >>>>>> >>>>>> >>>>>> dump snippet: >>>>>> ============ >>>>>> Event type: branches >>>>>> Sample = { cpu: 0001 addr: 0xffff80008030cb00 phys_addr: >>>>>> 0x0000000000000000 ip: 0xffff800080313f0c pid: 12720 tid: 12720 >>>>>> period: 1 time: 5986372298040 } >>>>>> ffff800080313f04 <__perf_event_header__init_id+0x4c>: >>>>>> ffff800080313f04: 36100094 tbz w20, #2, >>>>>> ffff800080313f14 <__perf_event_header__init_id+0x5c> >>>>>> ffff800080313f08: f941e6a0 ldr x0, [x21, >>>>>> #968] >>>>>> ffff800080313f0c: d63f0000 blr x0 >>>>>> perf 12720/12720 [0001] 5986.372298040 >>>>>> __perf_event_header__init_id+0x54 >>>>>> .../coresight/linux/kernel/events/core.c 586 return >>>>>> event->clock(); >>>>>> Event type: branches >>>>>> Sample = { cpu: 0001 addr: 0xffff8000801bb4a8 phys_addr: >>>>>> 0x0000000000000000 ip: 0xffff80008030cb0c pid: 12720 tid: 12720 >>>>>> period: 1 time: 5986372298040 } >>>>>> ffff80008030cb00 <local_clock>: >>>>>> ffff80008030cb00: d503233f paciasp >>>>>> ffff80008030cb04: a9bf7bfd stp x29, x30, >>>>>> [sp, #-16]! >>>>>> ffff80008030cb08: 910003fd mov x29, sp >>>>>> ffff80008030cb0c: 97faba67 bl >>>>>> ffff8000801bb4a8 <sched_clock> >>>>>> perf 12720/12720 [0001] 5986.372298040 >>>>>> local_clock+0xc ...t/linux/./include/linux/sched/clock.h 64 >>>>>> return sched_clock(); >>>>>> Event type: branches >>>>>> Sample = { cpu: 0001 addr: 0xffff80008125a8a8 phys_addr: >>>>>> 0x0000000000000000 ip: 0xffff8000801bb4c8 pid: 12720 tid: 12720 >>>>>> period: 1 time: 5986372298040 } >>>>>> ffff8000801bb4a8 <sched_clock>: >>>>>> ffff8000801bb4a8: d503233f paciasp >>>>>> ffff8000801bb4ac: a9be7bfd stp x29, x30, >>>>>> [sp, #-32]! >>>>>> ffff8000801bb4b0: 910003fd mov x29, sp >>>>>> ffff8000801bb4b4: a90153f3 stp x19, x20, >>>>>> [sp, #16] >>>>>> ffff8000801bb4b8: d5384113 mrs x19, sp_el0 >>>>>> ffff8000801bb4bc: b9401260 ldr w0, [x19, >>>>>> #16] >>>>>> ffff8000801bb4c0: 11000400 add w0, w0, #0x1 >>>>>> ffff8000801bb4c4: b9001260 str w0, [x19, >>>>>> #16] >>>>>> ffff8000801bb4c8: 94427cf8 bl >>>>>> ffff80008125a8a8 <sched_clock_noinstr> >>>>>> perf 12720/12720 [0001] 5986.372298040 >>>>>> sched_clock+0x20 ...sight/linux/kernel/time/sched_clock.c 105 ns >>>>>> = sched_clock_noinstr(); >>>>>> Event type: branches >>>>>> Sample = { cpu: 0001 addr: 0xffff80008125b758 phys_addr: >>>>>> 0x0000000000000000 ip: 0xffff80008125a8e4 pid: 12720 tid: 12720 >>>>>> period: 1 time: 5986372298040 } >>>>>> ffff80008125a8a8 <sched_clock_noinstr>: >>>>>> ffff80008125a8a8: d503233f paciasp >>>>>> ffff80008125a8ac: a9bc7bfd stp x29, x30, >>>>>> [sp, #-64]! >>>>>> ffff80008125a8b0: 910003fd mov x29, sp >>>>>> ffff80008125a8b4: a90153f3 stp x19, x20, >>>>>> [sp, #16] >>>>>> ffff80008125a8b8: b000e354 adrp x20, >>>>>> ffff800082ec3000 <tick_bc_dev+0x140> >>>>>> ffff80008125a8bc: 910d0294 add x20, x20, >>>>>> #0x340 >>>>>> ffff80008125a8c0: a90363f7 stp x23, x24, >>>>>> [sp, #48] >>>>>> ffff80008125a8c4: 91002297 add x23, x20, >>>>>> #0x8 >>>>>> ffff80008125a8c8: 52800518 mov w24, >>>>>> #0x28 // #40 >>>>>> ffff80008125a8cc: a9025bf5 stp x21, x22, >>>>>> [sp, #32] >>>>>> ffff80008125a8d0: b9400296 ldr w22, [x20] >>>>>> ffff80008125a8d4: 120002d5 and w21, w22, >>>>>> #0x1 >>>>>> ffff80008125a8d8: 9bb87eb5 umull x21, w21, >>>>>> w24 >>>>>> ffff80008125a8dc: 8b1502f3 add x19, x23, >>>>>> x21 >>>>>> ffff80008125a8e0: f9400e60 ldr x0, [x19, >>>>>> #24] >>>>>> ffff80008125a8e4: d63f0000 blr x0 >>>>>> perf 12720/12720 [0001] 5986.372298040 >>>>>> sched_clock_noinstr+0x3c ...sight/linux/kernel/time/sched_clock.c >>>>>> 93 cyc = (rd->read_sched_clock() - rd->epoch_cyc) & >>>>>> Event type: branches >>>>>> Sample = { cpu: 0001 addr: 0xffff8000801bb4cc phys_addr: >>>>>> 0x0000000000000000 ip: 0xffff80008125a930 pid: 12720 tid: 12720 >>>>>> period: 1 time: 5986372298040 } >>>>>> >>>>>> >>>>>> With fix: >>>>>> ========= >>>>>> >>>>>> Event type: branches >>>>>> Sample = { cpu: 0001 addr: 0xffff80008030cb00 phys_addr: >>>>>> 0x0000000000000000 ip: 0xffff800080313f0c pid: 12720 tid: 12720 >>>>>> period: 1 time: 5986372298040 } >>>>>> ffff800080313f04 <__perf_event_header__init_id+0x4c>: >>>>>> ffff800080313f04: 36100094 tbz w20, #2, >>>>>> ffff800080313f14 <__perf_event_header__init_id+0x5c> >>>>>> ffff800080313f08: f941e6a0 ldr x0, [x21, >>>>>> #968] >>>>>> ffff800080313f0c: d63f0000 blr x0 >>>>>> perf 12720/12720 [0001] 5986.372298040 >>>>>> __perf_event_header__init_id+0x54 >>>>>> .../coresight/linux/kernel/events/core.c 586 return >>>>>> event->clock(); >>>>>> Event type: branches >>>>>> Sample = { cpu: 0001 addr: 0xffff8000801bb4a8 phys_addr: >>>>>> 0x0000000000000000 ip: 0xffff80008030cb0c pid: 12720 tid: 12720 >>>>>> period: 1 time: 5986372298040 } >>>>>> ffff80008030cb00 <local_clock>: >>>>>> ffff80008030cb00: d503233f paciasp >>>>>> ffff80008030cb04: a9bf7bfd stp x29, x30, >>>>>> [sp, #-16]! >>>>>> ffff80008030cb08: 910003fd mov x29, sp >>>>>> ffff80008030cb0c: 97faba67 bl >>>>>> ffff8000801bb4a8 <sched_clock> >>>>>> perf 12720/12720 [0001] 5986.372298040 >>>>>> local_clock+0xc ...t/linux/./include/linux/sched/clock.h 64 >>>>>> return sched_clock(); >>>>>> Event type: branches >>>>>> Sample = { cpu: 0001 addr: 0xffff80008125a8a8 phys_addr: >>>>>> 0x0000000000000000 ip: 0xffff8000801bb4c8 pid: 12720 tid: 12720 >>>>>> period: 1 time: 5986372298040 } >>>>>> ffff8000801bb4a8 <sched_clock>: >>>>>> ffff8000801bb4a8: d503233f paciasp >>>>>> ffff8000801bb4ac: a9be7bfd stp x29, x30, >>>>>> [sp, #-32]! >>>>>> ffff8000801bb4b0: 910003fd mov x29, sp >>>>>> ffff8000801bb4b4: a90153f3 stp x19, x20, >>>>>> [sp, #16] >>>>>> ffff8000801bb4b8: d5384113 mrs x19, sp_el0 >>>>>> ffff8000801bb4bc: b9401260 ldr w0, [x19, >>>>>> #16] >>>>>> ffff8000801bb4c0: 11000400 add w0, w0, #0x1 >>>>>> ffff8000801bb4c4: b9001260 str w0, [x19, >>>>>> #16] >>>>>> ffff8000801bb4c8: 94427cf8 bl >>>>>> ffff80008125a8a8 <sched_clock_noinstr> >>>>>> perf 12720/12720 [0001] 5986.372298040 >>>>>> sched_clock+0x20 ...sight/linux/kernel/time/sched_clock.c 105 ns >>>>>> = sched_clock_noinstr(); >>>>>> Event type: branches >>>>>> Sample = { cpu: 0001 addr: 0xffff80008125b758 phys_addr: >>>>>> 0x0000000000000000 ip: 0xffff80008125a8e4 pid: 12720 tid: 12720 >>>>>> period: 1 time: 5986372298040 } >>>>>> ffff80008125a8a8 <sched_clock_noinstr>: >>>>>> ffff80008125a8a8: d503233f paciasp >>>>>> ffff80008125a8ac: a9bc7bfd stp x29, x30, >>>>>> [sp, #-64]! >>>>>> ffff80008125a8b0: 910003fd mov x29, sp >>>>>> ffff80008125a8b4: a90153f3 stp x19, x20, >>>>>> [sp, #16] >>>>>> ffff80008125a8b8: b000e354 adrp x20, >>>>>> ffff800082ec3000 <tick_bc_dev+0x140> >>>>>> ffff80008125a8bc: 910d0294 add x20, x20, >>>>>> #0x340 >>>>>> ffff80008125a8c0: a90363f7 stp x23, x24, >>>>>> [sp, #48] >>>>>> ffff80008125a8c4: 91002297 add x23, x20, >>>>>> #0x8 >>>>>> ffff80008125a8c8: 52800518 mov w24, >>>>>> #0x28 // #40 >>>>>> ffff80008125a8cc: a9025bf5 stp x21, x22, >>>>>> [sp, #32] >>>>>> ffff80008125a8d0: b9400296 ldr w22, [x20] >>>>>> ffff80008125a8d4: 120002d5 and w21, w22, >>>>>> #0x1 >>>>>> ffff80008125a8d8: 9bb87eb5 umull x21, w21, >>>>>> w24 >>>>>> ffff80008125a8dc: 8b1502f3 add x19, x23, >>>>>> x21 >>>>>> ffff80008125a8e0: f9400e60 ldr x0, [x19, >>>>>> #24] >>>>>> ffff80008125a8e4: d63f0000 blr x0 >>>>> >>>>> It looks like the disassembly now assumes this BLR wasn't taken. We >>>>> go from ffff80008125a8e4 straight through to ... >>>>> >>>>>> perf 12720/12720 [0001] 5986.372298040 >>>>>> sched_clock_noinstr+0x3c ...sight/linux/kernel/time/sched_clock.c >>>>>> 93 cyc = (rd->read_sched_clock() - rd->epoch_cyc) & >>>>>> Event type: branches >>>>>> Sample = { cpu: 0001 addr: 0xffff8000801bb4cc phys_addr: >>>>>> 0x0000000000000000 ip: 0xffff80008125a930 pid: 12720 tid: 12720 >>>>>> period: 1 time: 5986372298040 } >>>>>> ffff80008125a8e8 <sched_clock_noinstr+0x40>: >>>>>> ffff80008125a8e8: f8756ae3 ldr x3, [x23, >>>>>> x21] >>>>> >>>>> ffff80008125a8e4 which is just the previous one +4. Isn't your >>>>> issue actually a decode issue in Perf itself? Why is there a >>>>> discontinuity without branch samples being generated where either >>>>> the source or destination address is 0? >>>>> >>>>> What are your record options to create this issue? As I mentioned >>>>> in the previous reply I haven't been able to reproduce it. >>>> >>>> I am using below perf record command. >>>> >>>> timeout 4s ./perf record -e cs_etm// -C 1 dd if=/dev/zero of=/dev/null >>>> >>> >>> Thanks I managed to reproduce it. I'll take a look to see if I think >>> the issue is somewhere else. >>> >> >> At least for the failures I encountered, the issue is due to the >> alternatives runtime instruction patching mechanism. vmlinux ends up >> being the wrong image to decode with because a load of branches are >> actually turned into nops. >> >> Can you confirm if you use --kcore instead of vmlinux that you still >> get failures: >> >> sudo perf record -e cs_etm// -C 1 --kcore -o <output-folder.data> -- \ >> dd if=/dev/zero of=/dev/null >> >> perf script -i <output-folder.data> \ >> tools/perf/scripts/python/arm-cs-trace-disasm.py -d llvm-objdump \ >> -k <output-folder.data>/kcore_dir/kcore >> > > With below command combination with kcore also the issue is seen, as > reported in this email chain. > > timeout 8s ./perf record -e cs_etm// -C 1 --kcore -o kcore \ > dd if=/dev/zero of=/dev/null > > ./perf script -i kcore/data \ > --script=python:./scripts/python/arm-cs-trace-disasm.py -- \ > -d objdump -k kcore/kcore_dir/kcore > > > However, with below sequence(same as your command) the issue is *not* seen. > > timeout 8s ./perf record -e cs_etm// -C 1 --kcore -o kcore \ > dd if=/dev/zero of=/dev/null > > ./perf script -i kcore/data ./scripts/python/arm-cs-trace-disasm.py \ > -- -d objdump -k kcore/kcore_dir/kcore > > Do you see any issue with the command, which is showing the problem? > Also the output log produced by these both commands is different. > Double check the command I gave. "-i" needs to be the same as "-o" (it's the folder, not the data file). I think this could be causing your issue. Unless you give it the folder it doesn't open kcore along with the data file. > The below diff that you have shared has no effect on the failing case. > >> But I still think bad decode detection should be moved as much as >> possible into OpenCSD and Perf rather than this script. Otherwise >> every tool will have to re-implement it, and OpenCSD has a lot more >> info to make decisions with. >> >> One change we can make is to desynchronize when an N atom is an >> unconditional branch: >> >> diff --git a/decoder/source/etmv4/trc_pkt_decode_etmv4i.cpp >> b/decoder/source/etmv4/trc_pkt_decode_etmv4i.cpp >> index c557998..3eefd5d 100644 >> --- a/decoder/source/etmv4/trc_pkt_decode_etmv4i.cpp >> +++ b/decoder/source/etmv4/trc_pkt_decode_etmv4i.cpp >> @@ -1341,6 +1341,14 @@ ocsd_err_t >> TrcPktDecodeEtmV4I::processAtom(const ocsd_atm_val atom) >> // save recorded next instuction address >> ocsd_vaddr_t nextAddr = m_instr_info.instr_addr; >> >> + // must have lost sync if an unconditional branch wasn't taken >> + if (atom == ATOM_N && !m_instr_info.is_conditional) { >> + m_need_addr = true; >> + m_out_elem.addElemType(m_index_curr_pkt, >> OCSD_GEN_TRC_ELEM_NO_SYNC); >> + // wait for next address >> + return OCSD_OK; >> + } >> + >> >> Another one we can spot is when a new address comes that is before the >> current decode address (basically the backwards check that you added). >> >> There are probably others that can be spotted like an address >> appearing after a direct branch that doesn't match the branch target. >> >> I think at that point, desynchronising should cause the disassembly >> script to throw away the last bit, rather than force it to be printed >> as in this patch. As I mentioned above in the thread, it leads to >> printing disassembly that's implausible and misleading (where an >> unconditional branch wasn't taken). > > Thanks, > Ganapat

10 months, 3 weeks

Jump to page:

2025

2024

2023

2022

2021

2020

2019

2018

2017

2016

2015

CoreSight