diff mbox

spi: imx: wait_for_completion_timeout(..) for PIO transfers

Message ID 1466511174-17048-1-git-send-email-christian.gmeiner@gmail.com (mailing list archive)
State Accepted
Commit ff1ba3dac08eb10bd096d799430e5d1494f2ddfb
Headers show

Commit Message

Christian Gmeiner June 21, 2016, 12:12 p.m. UTC
In some rare cases I see the following 'task blocked' information. It
looks like the PIO transfer has some problems and never succeeds. Make
use of wait_for_completion_timeout(..) to detect this case and
return -ETIMEDOUT.

[ 240.246067] INFO: task hexdump:1660 blocked for more than 120 seconds.
[ 240.246089] Not tainted 4.1.17 0000001
[ 240.246099] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 240.246109] hexdump D c0575548 0 1660 1 0x00000000
[ 240.246132] Backtrace:
[ 240.246166] [<c057524c>] (__schedule) from [<c0575a84>] (schedule+0x40/0xa4)
[ 240.246176] r10:00000000 r9:c07f1300 r8:c07b8408 r7:c0576518 r6:7fffffff r5:7fffffff
[ 240.246210] r4:ee972e7c
[ 240.246233] [<c0575a44>] (schedule) from [<c0578544>] (schedule_timeout+0x174/0x274)
[ 240.246254] [<c05783d0>] (schedule_timeout) from [<c0576518>] (wait_for_common+0xc0/0x164)
[ 240.246263] r10:00000000 r9:c07f1300 r8:00000002 r7:00000000 r6:7fffffff r5:ee972e78
[ 240.246294] r4:ee972e7c
[ 240.246314] [<c0576458>] (wait_for_common) from [<c05765dc>] (wait_for_completion+0x20/0x24)
[ 240.246324] r10:ee972e50 r8:00000001 r7:c3976200 r6:ee972c00 r5:ee972e50 r4:c2c87d28
[ 240.246367] [<c05765bc>] (wait_for_completion) from [<c03f6b04>] (spi_imx_transfer+0xe8/0x3cc)
[ 240.246393] [<c03f6a1c>] (spi_imx_transfer) from [<c03f50e4>] (spi_bitbang_transfer_one+0xb4/0x250)
[ 240.246403] r10:ee972e50 r8:00000001 r7:00000000 r6:c2c87da0 r5:00000000 r4:c2c87d28
[ 240.246443] [<c03f5030>] (spi_bitbang_transfer_one) from [<c03f36e8>] (__spi_pump_messages+0x36c/0x6b4)
[ 240.246452] r10:ee9e5010 r9:00000001 r8:ee9e5010 r7:00000000 r6:c2c87da0 r5:c2c87d6c
[ 240.246483] r4:ee972c00
[ 240.246503] [<c03f337c>] (__spi_pump_messages) from [<c03f3b68>] (__spi_sync+0x138/0x1e4)
[ 240.246512] r10:00000000 r9:00000000 r8:c03f25a8 r7:00000000 r6:ee972c00 r5:c3976200
[ 240.246542] r4:c2c87da0
[ 240.246562] [<c03f3a30>] (__spi_sync) from [<c03f3c50>] (spi_sync+0x1c/0x20)
[ 240.246571] r10:00040000 r9:00000000 r8:c3976200 r7:00000000 r6:ee973300 r5:c2c87da0
[ 240.246602] r4:ee973014
[ 240.246623] [<c03f3c34>] (spi_sync) from [<c03f0210>] (m25p80_read+0xf8/0x124)
[ 240.246641] [<c03f0118>] (m25p80_read) from [<c03f1528>] (spi_nor_read+0x64/0x80)
[ 240.246651] r10:00004000 r8:00004000 r7:00000000 r6:00040000 r5:00000000 r4:ee973014
[ 240.246698] [<c03f14c4>] (spi_nor_read) from [<c03cdcb4>] (mtd_read+0x98/0xcc)
[ 240.246708] r7:c2c87ea0 r6:ee973098 r5:00000000 r4:001c0000
[ 240.246740] [<c03cdc1c>] (mtd_read) from [<c03d300c>] (mtdchar_read+0xcc/0x204)
[ 240.246750] r9:ed424000 r8:00000000 r7:b495d018 r6:c2c87f78 r5:00000000 r4:00040000
[ 240.246793] [<c03d2f40>] (mtdchar_read) from [<c013b1c4>] (__vfs_read+0x3c/0xe0)
[ 240.246803] r10:00004000 r9:00000000 r8:c2c87f78 r7:b495d018 r6:c2c87f78 r5:c05c8104
[ 240.246833] r4:c32fe600
[ 240.246852] [<c013b188>] (__vfs_read) from [<c013befc>] (vfs_read+0x98/0x154)
[ 240.246861] r10:00000000 r8:00040000 r7:00004000 r6:c2c87f78 r5:b495d018 r4:c32fe600
[ 240.246899] [<c013be64>] (vfs_read) from [<c013c008>] (SyS_read+0x50/0x90)
[ 240.246908] r10:00000000 r8:00040000 r7:b495d018 r6:00004000 r5:c32fe601 r4:c32fe600
[ 240.246953] [<c013bfb8>] (SyS_read) from [<c000fa60>] (ret_fast_syscall+0x0/0x3c)
[ 240.246962] r9:c2c86000 r8:c000fc04 r7:00000003 r6:00004000 r5:00000000 r4:b495d018

Signed-off-by: Christian Gmeiner <christian.gmeiner@gmail.com>
---
 drivers/spi/spi-imx.c | 12 +++++++++++-
 1 file changed, 11 insertions(+), 1 deletion(-)

Comments

Mark Brown June 21, 2016, 6:51 p.m. UTC | #1
On Tue, Jun 21, 2016 at 02:12:54PM +0200, Christian Gmeiner wrote:

> [ 240.246067] INFO: task hexdump:1660 blocked for more than 120 seconds.
> [ 240.246089] Not tainted 4.1.17 0000001
> [ 240.246099] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.

Please think hard before including complete backtraces in upstream
reports, they are very large and contain almost no useful information
relative to their size so often obscure the relevant content in your
message. If part of the backtrace is usefully illustrative then it's
usually better to pull out the relevant sections.
diff mbox

Patch

diff --git a/drivers/spi/spi-imx.c b/drivers/spi/spi-imx.c
index 50769078..d2b96b1 100644
--- a/drivers/spi/spi-imx.c
+++ b/drivers/spi/spi-imx.c
@@ -1050,6 +1050,8 @@  static int spi_imx_pio_transfer(struct spi_device *spi,
 				struct spi_transfer *transfer)
 {
 	struct spi_imx_data *spi_imx = spi_master_get_devdata(spi->master);
+	unsigned long transfer_timeout;
+	unsigned long timeout;
 
 	spi_imx->tx_buf = transfer->tx_buf;
 	spi_imx->rx_buf = transfer->rx_buf;
@@ -1062,7 +1064,15 @@  static int spi_imx_pio_transfer(struct spi_device *spi,
 
 	spi_imx->devtype_data->intctrl(spi_imx, MXC_INT_TE);
 
-	wait_for_completion(&spi_imx->xfer_done);
+	transfer_timeout = spi_imx_calculate_timeout(spi_imx, transfer->len);
+
+	timeout = wait_for_completion_timeout(&spi_imx->xfer_done,
+					      transfer_timeout);
+	if (!timeout) {
+		dev_err(&spi->dev, "I/O Error in PIO\n");
+		spi_imx->devtype_data->reset(spi_imx);
+		return -ETIMEDOUT;
+	}
 
 	return transfer->len;
 }