diff mbox

PCI: print out exact timeout in pciehp for wait_cmd

Message ID 20140923023501.GO1880@google.com (mailing list archive)
State New, archived
Delegated to: Bjorn Helgaas
Headers show

Commit Message

Bjorn Helgaas Sept. 23, 2014, 2:35 a.m. UTC 
On Fri, Aug 22, 2014 at 06:15:09PM -0700, Yinghai Lu wrote:
> debug print out should add back timeout that pass during wait event or
> polling.
> 
> That now is cached vaule before wait.
> 
> Signed-off-by: Yinghai Lu <yinghai@kernel.org>
> 
> ---
>  drivers/pci/hotplug/pciehp_hpc.c |    2 +-
>  1 file changed, 1 insertion(+), 1 deletion(-)
> 
> Index: linux-2.6/drivers/pci/hotplug/pciehp_hpc.c
> ===================================================================
> --- linux-2.6.orig/drivers/pci/hotplug/pciehp_hpc.c
> +++ linux-2.6/drivers/pci/hotplug/pciehp_hpc.c
> @@ -173,7 +173,7 @@ static void pcie_wait_cmd(struct control
>  	if (!rc)
>  		ctrl_info(ctrl, "Timeout on hotplug command %#010x (issued %u msec ago)\n",
>  			  ctrl->slot_ctrl,
> -			  jiffies_to_msecs(now - ctrl->cmd_started));
> +			  jiffies_to_msecs(now - ctrl->cmd_started + timeout));
>  }
>  
>  /**

I propose the modification below because I think it's more direct.  Does it
make sense to you, or am I still missing something?


commit 83d752536aa9dfb1fddb04d6ef8c6bdc75492d4f
Author: Yinghai Lu <yinghai@kernel.org>
Date:   Mon Sep 22 20:07:35 2014 -0600

    PCI: pciehp: Fix wait time in timeout message
    
    When we warned about a timeout on a hotplug command, we previously printed
    the time between calls to pcie_write_cmd(), without accounting for any time
    spent actually waiting.  Consider this sequence:
    
      pcie_write_cmd
        write SLTCTL
        cmd_started = jiffies          # T1
    
      pcie_write_cmd
        pcie_wait_cmd
          now = jiffies                # T2
          wait_event_timeout           # we may wait here
          if (timeout)
            ctrl_info("Timeout on command issued %u msec ago",
                      jiffies_to_msecs(now - cmd_started))
    
    We previously printed (T2 - T1), but that doesn't include the time spent in
    wait_event_timeout().
    
    Fix this by using the current jiffies value, not the one cached before
    calling wait_event_timeout().
    
    [bhelgaas: changelog, use current jiffies instead of adding timeout]
    Fixes: 40b960831cfa ("PCI: pciehp: Compute timeout from hotplug command start time")
    Signed-off-by: Yinghai Lu <yinghai@kernel.org>
    Signed-off-by: Bjorn Helgaas <bhelgaas@google.com>

--
To unsubscribe from this list: send the line "unsubscribe linux-pci" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Comments

Yinghai Lu Sept. 24, 2014, 1:53 a.m. UTC | #1 
On Mon, Sep 22, 2014 at 7:35 PM, Bjorn Helgaas <bhelgaas@google.com> wrote:
>
>     [bhelgaas: changelog, use current jiffies instead of adding timeout]

> diff --git a/drivers/pci/hotplug/pciehp_hpc.c b/drivers/pci/hotplug/pciehp_hpc.c
> index 9e0f4aec5f0c..3673a913379f 100644
> --- a/drivers/pci/hotplug/pciehp_hpc.c
> +++ b/drivers/pci/hotplug/pciehp_hpc.c
> @@ -173,7 +173,7 @@ static void pcie_wait_cmd(struct controller *ctrl)
>         if (!rc)
>                 ctrl_info(ctrl, "Timeout on hotplug command %#06x (issued %u msec ago)\n",
>                           ctrl->slot_ctrl,
> -                         jiffies_to_msecs(now - ctrl->cmd_started));
> +                         jiffies_to_msecs(jiffies - ctrl->cmd_started));
>  }
>
>  /**

Yeah, that is more simple.

Thanks

Yinghai
--
To unsubscribe from this list: send the line "unsubscribe linux-pci" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
diff mbox

Patch

diff --git a/drivers/pci/hotplug/pciehp_hpc.c b/drivers/pci/hotplug/pciehp_hpc.c
index 9e0f4aec5f0c..3673a913379f 100644
--- a/drivers/pci/hotplug/pciehp_hpc.c
+++ b/drivers/pci/hotplug/pciehp_hpc.c
@@ -173,7 +173,7 @@  static void pcie_wait_cmd(struct controller *ctrl)
 	if (!rc)
 		ctrl_info(ctrl, "Timeout on hotplug command %#06x (issued %u msec ago)\n",
 			  ctrl->slot_ctrl,
-			  jiffies_to_msecs(now - ctrl->cmd_started));
+			  jiffies_to_msecs(jiffies - ctrl->cmd_started));
 }
 
 /**