• Jacob Keller's avatar
    ice: add trace events for tx timestamps · 4c120218
    Jacob Keller authored
    We've previously run into many issues related to the latency of a Tx
    timestamp completion with the ice hardware. It can be difficult to
    determine the root cause of a slow Tx timestamp. To aid in this,
    introduce new trace events which capture timing data about when the
    driver reaches certain points while processing a transmit timestamp
    
     * ice_tx_tstamp_request: Trace when the stack initiates a new timestamp
       request.
    
     * ice_tx_tstamp_fw_req: Trace when the driver begins a read of the
       timestamp register in the work thread.
    
     * ice_tx_tstamp_fw_done: Trace when the driver finishes reading a
       timestamp register in the work thread.
    
     * ice_tx_tstamp_complete: Trace when the driver submits the skb back to
       the stack with a completed Tx timestamp.
    
    These trace events can be enabled using the standard trace event
    subsystem exposed by the ice driver. If they are disabled, they become
    no-ops with no run time cost.
    
    The following is a simple GNU AWK script which can highlight one
    potential way to use the trace events to capture latency data from the
    trace buffer about how long the driver takes to process a timestamp:
    
    -----
      BEGIN {
          PREC=256
      }
    
      # Detect requests
      /tx_tstamp_request/ {
          time=strtonum($4)
          skb=$7
    
          # Store the time of request for this skb
          requests[skb] = time
          printf("skb %s: idx %d at %.6f\n", skb, idx, time)
      }
    
      # Detect completions
      /tx_tstamp_complete/ {
          time=strtonum($4)
          skb=$7
          idx=$9
    
          if (skb in requests) {
              latency = (time - requests[skb]) * 1000
              printf("skb %s: %.3f to complete\n", skb, latency)
              if (latency > 4) {
                  printf(">>> HIGH LATENCY <<<\n")
              }
              printf("\n")
          } else {
              printf("!!! skb %s (idx %d) at %.6f\n", skb, idx, time)
          }
      }
    -----
    Signed-off-by: default avatarJacob Keller <jacob.e.keller@intel.com>
    Tested-by: Gurucharan <gurucharanx.g@intel.com> (A Contingent worker at Intel)
    Signed-off-by: default avatarTony Nguyen <anthony.l.nguyen@intel.com>
    4c120218
ice_ptp.c 71.1 KB