[3/3] pseries: Improve tracing of CPU compatibility negotiation

This makes some improvements to the debug tracepoints around the
negotiation of CPU compatibility mode during CAS.  The traces are
reorganized to emphasise what the inputs and outputs of the process are,
then distinguish the internal state of the two possible negotiation paths
(current and pre-2.8 machine type compatibility).

Signed-off-by: David Gibson <david@gibson.dropbear.id.au>
---
 hw/ppc/spapr_hcall.c | 14 ++++++++------
 hw/ppc/trace-events  |  6 ++++--
 2 files changed, 12 insertions(+), 8 deletions(-)

On 18/05/2017 07:45, David Gibson wrote:
> This makes some improvements to the debug tracepoints around the
> negotiation of CPU compatibility mode during CAS.  The traces are
> reorganized to emphasise what the inputs and outputs of the process are,
> then distinguish the internal state of the two possible negotiation paths
> (current and pre-2.8 machine type compatibility).
> 
> Signed-off-by: David Gibson <david@gibson.dropbear.id.au>

Reviewed-by: Laurent Vivier <lvivier@redhat.com>

> ---
>  hw/ppc/spapr_hcall.c | 14 ++++++++------
>  hw/ppc/trace-events  |  6 ++++--
>  2 files changed, 12 insertions(+), 8 deletions(-)
> 
> diff --git a/hw/ppc/spapr_hcall.c b/hw/ppc/spapr_hcall.c
> index a790da7..cea5d99 100644
> --- a/hw/ppc/spapr_hcall.c
> +++ b/hw/ppc/spapr_hcall.c
> @@ -1109,7 +1109,6 @@ static uint32_t cas_check_pvr_pre_2_9(PowerPCCPU *cpu, target_ulong *addr,
>              break; /* Terminator record */
>          }
>  
> -        trace_spapr_cas_pvr_try(pvr);
>          if (!max_lvl &&
>              ((cpu->env.spr[SPR_PVR] & pvr_mask) == (pvr & pvr_mask))) {
>              cpu_match = true;
> @@ -1120,10 +1119,10 @@ static uint32_t cas_check_pvr_pre_2_9(PowerPCCPU *cpu, target_ulong *addr,
>          } else if (!cpu_match) {
>              cas_handle_compat_cpu(pcc, pvr, max_lvl, &compat_lvl, &compat_pvr);
>          }
> +        trace_cas_check_pvr_pre_2_9(pvr, pvr_mask, cpu_match,
> +                                    compat_lvl, compat_pvr);
>      }
>  
> -    trace_spapr_cas_pvr(cpu->compat_pvr, cpu_match, compat_pvr);
> -
>      return compat_pvr;
>  }
>  
> @@ -1158,6 +1157,7 @@ static uint32_t cas_check_pvr(PowerPCCPU *cpu, target_ulong *addr,
>                  best_compat = pvr;
>              }
>          }
> +        trace_cas_check_pvr(pvr, pvr_mask, explicit_match, best_compat);
>      }
>  
>      if ((best_compat == 0) && (!explicit_match || max_compat)) {
> @@ -1168,9 +1168,6 @@ static uint32_t cas_check_pvr(PowerPCCPU *cpu, target_ulong *addr,
>          return 0;
>      }
>  
> -    /* Parsing finished */
> -    trace_spapr_cas_pvr(cpu->compat_pvr, explicit_match, best_compat);
> -
>      return best_compat;
>  }
>  
> @@ -1188,6 +1185,9 @@ static target_ulong h_client_architecture_support(PowerPCCPU *cpu,
>      bool guest_radix;
>      Error *local_err = NULL;
>  
> +    trace_cas_check_pvr_start(cpu->compat_pvr, cpu->max_compat,
> +                              cpu->env.spr[SPR_PVR]);
> +
>      if (smc->pre_2_9_cas_pvr) {
>          cas_pvr = cas_check_pvr_pre_2_9(cpu, &addr, &local_err);
>      } else {
> @@ -1198,6 +1198,8 @@ static target_ulong h_client_architecture_support(PowerPCCPU *cpu,
>          return H_HARDWARE;
>      }
>  
> +    trace_cas_check_pvr_complete(cpu->compat_pvr, cas_pvr);
> +
>      /* Update CPUs */
>      if (cpu->compat_pvr != cas_pvr) {
>          ppc_set_compat_all(cas_pvr, &local_err);
> diff --git a/hw/ppc/trace-events b/hw/ppc/trace-events
> index 43d265f..5329740 100644
> --- a/hw/ppc/trace-events
> +++ b/hw/ppc/trace-events
> @@ -14,8 +14,10 @@ spapr_cas_failed(unsigned long n) "DT diff buffer is too small: %ld bytes"
>  spapr_cas_continue(unsigned long n) "Copy changes to the guest: %ld bytes"
>  
>  # hw/ppc/spapr_hcall.c
> -spapr_cas_pvr_try(uint32_t pvr) "%x"
> -spapr_cas_pvr(uint32_t cur_pvr, bool explicit_match, uint32_t new_pvr) "current=%x, explicit_match=%u, new=%x"
> +cas_check_pvr_pre_2_9(uint32_t pvr, uint32_t mask, bool match, unsigned lvl, uint32_t compat_pvr) "0x%08x/0x%08x match=%d lvl=%d compat_pvr=0x%x"
> +cas_check_pvr(uint32_t pvr, uint32_t pvr_mask, bool explicit_match, uint32_t best_compat) "0x%08x/0x%08x explicit_match=%d best_compat=0x%08x"
> +cas_check_pvr_start(uint32_t compat_pvr, uint32_t max_compat, uint32_t phys_pvr) "Initial compat PVR 0x%08x, max compat 0x%08x (real PVR 0x%08x)"
> +cas_check_pvr_complete(uint32_t old_pvr, uint32_t new_pvr) "Compatibility PVR was 0x%08x, now 0x%08x"
>  
>  # hw/ppc/spapr_iommu.c
>  spapr_iommu_put(uint64_t liobn, uint64_t ioba, uint64_t tce, uint64_t ret) "liobn=%"PRIx64" ioba=0x%"PRIx64" tce=0x%"PRIx64" ret=%"PRId64
>

On Thu, 18 May 2017 15:45:22 +1000
David Gibson <david@gibson.dropbear.id.au> wrote:

> This makes some improvements to the debug tracepoints around the
> negotiation of CPU compatibility mode during CAS.  The traces are
> reorganized to emphasise what the inputs and outputs of the process are,
> then distinguish the internal state of the two possible negotiation paths
> (current and pre-2.8 machine type compatibility).
> 
> Signed-off-by: David Gibson <david@gibson.dropbear.id.au>
> ---

Reviewed-by: Greg Kurz <groug@kaod.org>

>  hw/ppc/spapr_hcall.c | 14 ++++++++------
>  hw/ppc/trace-events  |  6 ++++--
>  2 files changed, 12 insertions(+), 8 deletions(-)
> 
> diff --git a/hw/ppc/spapr_hcall.c b/hw/ppc/spapr_hcall.c
> index a790da7..cea5d99 100644
> --- a/hw/ppc/spapr_hcall.c
> +++ b/hw/ppc/spapr_hcall.c
> @@ -1109,7 +1109,6 @@ static uint32_t cas_check_pvr_pre_2_9(PowerPCCPU *cpu, target_ulong *addr,
>              break; /* Terminator record */
>          }
>  
> -        trace_spapr_cas_pvr_try(pvr);
>          if (!max_lvl &&
>              ((cpu->env.spr[SPR_PVR] & pvr_mask) == (pvr & pvr_mask))) {
>              cpu_match = true;
> @@ -1120,10 +1119,10 @@ static uint32_t cas_check_pvr_pre_2_9(PowerPCCPU *cpu, target_ulong *addr,
>          } else if (!cpu_match) {
>              cas_handle_compat_cpu(pcc, pvr, max_lvl, &compat_lvl, &compat_pvr);
>          }
> +        trace_cas_check_pvr_pre_2_9(pvr, pvr_mask, cpu_match,
> +                                    compat_lvl, compat_pvr);
>      }
>  
> -    trace_spapr_cas_pvr(cpu->compat_pvr, cpu_match, compat_pvr);
> -
>      return compat_pvr;
>  }
>  
> @@ -1158,6 +1157,7 @@ static uint32_t cas_check_pvr(PowerPCCPU *cpu, target_ulong *addr,
>                  best_compat = pvr;
>              }
>          }
> +        trace_cas_check_pvr(pvr, pvr_mask, explicit_match, best_compat);
>      }
>  
>      if ((best_compat == 0) && (!explicit_match || max_compat)) {
> @@ -1168,9 +1168,6 @@ static uint32_t cas_check_pvr(PowerPCCPU *cpu, target_ulong *addr,
>          return 0;
>      }
>  
> -    /* Parsing finished */
> -    trace_spapr_cas_pvr(cpu->compat_pvr, explicit_match, best_compat);
> -
>      return best_compat;
>  }
>  
> @@ -1188,6 +1185,9 @@ static target_ulong h_client_architecture_support(PowerPCCPU *cpu,
>      bool guest_radix;
>      Error *local_err = NULL;
>  
> +    trace_cas_check_pvr_start(cpu->compat_pvr, cpu->max_compat,
> +                              cpu->env.spr[SPR_PVR]);
> +
>      if (smc->pre_2_9_cas_pvr) {
>          cas_pvr = cas_check_pvr_pre_2_9(cpu, &addr, &local_err);
>      } else {
> @@ -1198,6 +1198,8 @@ static target_ulong h_client_architecture_support(PowerPCCPU *cpu,
>          return H_HARDWARE;
>      }
>  
> +    trace_cas_check_pvr_complete(cpu->compat_pvr, cas_pvr);
> +
>      /* Update CPUs */
>      if (cpu->compat_pvr != cas_pvr) {
>          ppc_set_compat_all(cas_pvr, &local_err);
> diff --git a/hw/ppc/trace-events b/hw/ppc/trace-events
> index 43d265f..5329740 100644
> --- a/hw/ppc/trace-events
> +++ b/hw/ppc/trace-events
> @@ -14,8 +14,10 @@ spapr_cas_failed(unsigned long n) "DT diff buffer is too small: %ld bytes"
>  spapr_cas_continue(unsigned long n) "Copy changes to the guest: %ld bytes"
>  
>  # hw/ppc/spapr_hcall.c
> -spapr_cas_pvr_try(uint32_t pvr) "%x"
> -spapr_cas_pvr(uint32_t cur_pvr, bool explicit_match, uint32_t new_pvr) "current=%x, explicit_match=%u, new=%x"
> +cas_check_pvr_pre_2_9(uint32_t pvr, uint32_t mask, bool match, unsigned lvl, uint32_t compat_pvr) "0x%08x/0x%08x match=%d lvl=%d compat_pvr=0x%x"
> +cas_check_pvr(uint32_t pvr, uint32_t pvr_mask, bool explicit_match, uint32_t best_compat) "0x%08x/0x%08x explicit_match=%d best_compat=0x%08x"
> +cas_check_pvr_start(uint32_t compat_pvr, uint32_t max_compat, uint32_t phys_pvr) "Initial compat PVR 0x%08x, max compat 0x%08x (real PVR 0x%08x)"
> +cas_check_pvr_complete(uint32_t old_pvr, uint32_t new_pvr) "Compatibility PVR was 0x%08x, now 0x%08x"
>  
>  # hw/ppc/spapr_iommu.c
>  spapr_iommu_put(uint64_t liobn, uint64_t ioba, uint64_t tce, uint64_t ret) "liobn=%"PRIx64" ioba=0x%"PRIx64" tce=0x%"PRIx64" ret=%"PRId64