[PATCH 1/2] i2c: omap: fix NACK and Arbitration Lost irq handling

[PATCH 1/2] i2c: omap: fix NACK and Arbitration Lost irq handling

[Alexander Kochetkov]

commit 1d7afc95946487945cc7f5019b41255b72224b70 (i2c: omap: ack IRQ in parts)
changed the interrupt handler to complete transfers without clearing
XRDY (AL case) and ARDY (NACK case) flags. XRDY or ARDY interrupt will be
fired again (in parallel with omap_i2c_xfer_msg). Interrupt handler will
complete transfers second time. As a result, NACK and AL transfers
terminates with "transfer timeout" and sometimes client code segfault.

The patch restore original logic of handling NACK and AL interrupts and
fix race between interrupt handler and omap_i2c_xfer_msg (for AL and
NACK case only).

Tested on Beagleboard XM C.

Signed-off-by: Alexander Kochetkov <al.kochet-Re5JQEeQqe8AvxtiuMwx3w@public.gmane.org>
---
 drivers/i2c/busses/i2c-omap.c |    2 --
 1 file changed, 2 deletions(-)

diff --git a/drivers/i2c/busses/i2c-omap.c b/drivers/i2c/busses/i2c-omap.c
index 90dcc2e..9af7095 100644
--- a/drivers/i2c/busses/i2c-omap.c
+++ b/drivers/i2c/busses/i2c-omap.c
@@ -926,14 +926,12 @@ omap_i2c_isr_thread(int this_irq, void *dev_id)
 		if (stat & OMAP_I2C_STAT_NACK) {
 			err |= OMAP_I2C_STAT_NACK;
 			omap_i2c_ack_stat(dev, OMAP_I2C_STAT_NACK);
-			break;
 		}
 
 		if (stat & OMAP_I2C_STAT_AL) {
 			dev_err(dev->dev, "Arbitration lost\n");
 			err |= OMAP_I2C_STAT_AL;
 			omap_i2c_ack_stat(dev, OMAP_I2C_STAT_AL);
-			break;
 		}
 
 		/*
-- 
1.7.9.5

[PATCH 2/2] i2c: omap: fix "Too much work in one IRQ" irq handling

[Alexander Kochetkov]

commit 66b9298878742f08cb6e79b7c7d5632d782fd1e1 (i2c: omap: switch over
to do {} while loop) changed the interrupt handler to abort transfers
in case interrupt serviced 100 times but commit's comment states that
"No functional changes otherwise.".

Also, original commit could report status 0 (no error) on aborted transfers.

The patch restore original logic. In case interrupt serviced 100 times just
quit interrupt handler and don't abort active transfer.

Signed-off-by: Alexander Kochetkov <al.kochet-Re5JQEeQqe8AvxtiuMwx3w@public.gmane.org>
---
 drivers/i2c/busses/i2c-omap.c |    2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/drivers/i2c/busses/i2c-omap.c b/drivers/i2c/busses/i2c-omap.c
index 9af7095..34b9011 100644
--- a/drivers/i2c/busses/i2c-omap.c
+++ b/drivers/i2c/busses/i2c-omap.c
@@ -920,7 +920,7 @@ omap_i2c_isr_thread(int this_irq, void *dev_id)
 		dev_dbg(dev->dev, "IRQ (ISR = 0x%04x)\n", stat);
 		if (count++ == 100) {
 			dev_warn(dev->dev, "Too much work in one IRQ\n");
-			break;
+			goto out;
 		}
 
 		if (stat & OMAP_I2C_STAT_NACK) {
-- 
1.7.9.5

Re: [PATCH 1/2] i2c: omap: fix NACK and Arbitration Lost irq handling

[Felipe Balbi]

[-- Attachment #1: Type: text/plain, Size: 1803 bytes --]

On Sat, Nov 15, 2014 at 05:20:51AM +0400, Alexander Kochetkov wrote:
> commit 1d7afc95946487945cc7f5019b41255b72224b70 (i2c: omap: ack IRQ in parts)
> changed the interrupt handler to complete transfers without clearing
> XRDY (AL case) and ARDY (NACK case) flags. XRDY or ARDY interrupt will be
> fired again (in parallel with omap_i2c_xfer_msg). Interrupt handler will
> complete transfers second time. As a result, NACK and AL transfers
> terminates with "transfer timeout" and sometimes client code segfault.
> 
> The patch restore original logic of handling NACK and AL interrupts and
> fix race between interrupt handler and omap_i2c_xfer_msg (for AL and
> NACK case only).
> 
> Tested on Beagleboard XM C.
> 

Assuming this is really correct (I haven't tested), you need to add:

Fixes: 1d7afc9 i2c: omap: ack IRQ in parts
Cc: <stable-u79uwXL29TY76Z2rM5mHXA@public.gmane.org> # v3.7+

here and resend, so it gets backported to older kernels.

> Signed-off-by: Alexander Kochetkov <al.kochet-Re5JQEeQqe8AvxtiuMwx3w@public.gmane.org>
> ---
>  drivers/i2c/busses/i2c-omap.c |    2 --
>  1 file changed, 2 deletions(-)
> 
> diff --git a/drivers/i2c/busses/i2c-omap.c b/drivers/i2c/busses/i2c-omap.c
> index 90dcc2e..9af7095 100644
> --- a/drivers/i2c/busses/i2c-omap.c
> +++ b/drivers/i2c/busses/i2c-omap.c
> @@ -926,14 +926,12 @@ omap_i2c_isr_thread(int this_irq, void *dev_id)
>  		if (stat & OMAP_I2C_STAT_NACK) {
>  			err |= OMAP_I2C_STAT_NACK;
>  			omap_i2c_ack_stat(dev, OMAP_I2C_STAT_NACK);
> -			break;
>  		}
>  
>  		if (stat & OMAP_I2C_STAT_AL) {
>  			dev_err(dev->dev, "Arbitration lost\n");
>  			err |= OMAP_I2C_STAT_AL;
>  			omap_i2c_ack_stat(dev, OMAP_I2C_STAT_AL);
> -			break;
>  		}
>  
>  		/*
> -- 
> 1.7.9.5
> 

-- 
balbi

[-- Attachment #2: Digital signature --]
[-- Type: application/pgp-signature, Size: 819 bytes --]

Re: [PATCH 2/2] i2c: omap: fix "Too much work in one IRQ" irq handling

[Felipe Balbi]

[-- Attachment #1: Type: text/plain, Size: 1911 bytes --]

Hi,

On Sat, Nov 15, 2014 at 05:20:52AM +0400, Alexander Kochetkov wrote:
> commit 66b9298878742f08cb6e79b7c7d5632d782fd1e1 (i2c: omap: switch over
> to do {} while loop) changed the interrupt handler to abort transfers
> in case interrupt serviced 100 times but commit's comment states that
> "No functional changes otherwise.".

look at the patch again, the commit you describe is *not* the one giving
up on servicing interrupts after 100 times. That commit, really, *only*
switched over from while() {} to do {} while(), the only functional
change there is that the while loop will always execute at least once.

> Also, original commit could report status 0 (no error) on aborted transfers.

how ? This is an interesting bug which deserves further explanation.

> The patch restore original logic. In case interrupt serviced 100 times just
> quit interrupt handler and don't abort active transfer.
> 
> Signed-off-by: Alexander Kochetkov <al.kochet-Re5JQEeQqe8AvxtiuMwx3w@public.gmane.org>
> ---
>  drivers/i2c/busses/i2c-omap.c |    2 +-
>  1 file changed, 1 insertion(+), 1 deletion(-)
> 
> diff --git a/drivers/i2c/busses/i2c-omap.c b/drivers/i2c/busses/i2c-omap.c
> index 9af7095..34b9011 100644
> --- a/drivers/i2c/busses/i2c-omap.c
> +++ b/drivers/i2c/busses/i2c-omap.c
> @@ -920,7 +920,7 @@ omap_i2c_isr_thread(int this_irq, void *dev_id)
>  		dev_dbg(dev->dev, "IRQ (ISR = 0x%04x)\n", stat);
>  		if (count++ == 100) {
>  			dev_warn(dev->dev, "Too much work in one IRQ\n");
> -			break;
> +			goto out;

quite frankly, this looks *very* wrong. It creates the possibility for
us never completing a command which would cause several timeouts.

How have you tested this and how have you figured this was the actual
bug ? Based on commit log not matching the patch body (which 'original
logic' are you talking about ?), I have to NAK this patch.

-- 
balbi

[-- Attachment #2: Digital signature --]
[-- Type: application/pgp-signature, Size: 819 bytes --]

Re: [PATCH 2/2] i2c: omap: fix "Too much work in one IRQ" irq handling

[Alexander Kochetkov]

Hi Felipe,

Initially you made the change (66b9298878742f08cb6e79b7c7d5632d782fd1e1):
https://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git/commit/drivers/i2c/busses/i2c-omap.c?id=66b9298878742f08cb6e79b7c7d5632d782fd1e1

 		dev_dbg(dev->dev, "IRQ (ISR = 0x%04x)\n", stat);

 		if (count++ == 100) {
 			dev_warn(dev->dev, "Too much work in one IRQ\n");
-			break;
+			omap_i2c_complete_cmd(dev, err);
+			return IRQ_HANDLED;
 		}


Than that change transformed into (4a7ec4eda58269a507501f240955d99312fdfd5f):
https://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git/commit/drivers/i2c/busses/i2c-omap.c?id=4a7ec4eda58269a507501f240955d99312fdfd5f

@@ -853,24 +853,21 @@ omap_i2c_isr(int this_irq, void *dev_id)
 		dev_dbg(dev->dev, "IRQ (ISR = 0x%04x)\n", stat);
 		if (count++ == 100) {
 			dev_warn(dev->dev, "Too much work in one IRQ\n");
-			omap_i2c_complete_cmd(dev, err);
-			return IRQ_HANDLED;
+			goto out;
 		}


+out:
+	omap_i2c_complete_cmd(dev, err);
 	return IRQ_HANDLED;
 }

As a result we have in master:
https://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git/tree/drivers/i2c/busses/i2c-omap.c

	do {
		bits = omap_i2c_read_reg(dev, OMAP_I2C_IE_REG);
		stat = omap_i2c_read_reg(dev, OMAP_I2C_STAT_REG);
		stat &= bits;
		...

		dev_dbg(dev->dev, "IRQ (ISR = 0x%04x)\n", stat);
		if (count++ == 100) {
			dev_warn(dev->dev, "Too much work in one IRQ\n");
			break;
		}
                ...

	} while (stat);

	omap_i2c_complete_cmd(dev, err);

out:
	spin_unlock_irqrestore(&dev->lock, flags);

While original code was:

{
	bits = omap_i2c_read_reg(dev, OMAP_I2C_IE_REG);
	while ((stat = (omap_i2c_read_reg(dev, OMAP_I2C_STAT_REG))) & bits) {
		dev_dbg(dev->dev, "IRQ (ISR = 0x%04x)\n", stat);
		if (count++ == 100) {
			dev_warn(dev->dev, "Too much work in one IRQ\n");
			break;
		}

		err = 0;
complete:
                ...

		if (stat & (OMAP_I2C_STAT_ARDY | OMAP_I2C_STAT_NACK |
					OMAP_I2C_STAT_AL)) {
			...
			omap_i2c_complete_cmd(dev, err);
			return IRQ_HANDLED;
		}
		...
	}
	return count ? IRQ_HANDLED : IRQ_NONE;
}


> how ? This is an interesting bug which deserves further explanation.

Look at the loops above, and at the omap_i2c_complete_cmd:

static inline void
omap_i2c_complete_cmd(struct omap_i2c_dev *dev, u16 err)
{
	dev->cmd_err |= err;
	complete(&dev->cmd_complete);
}

You can see, loop will be aborted if counter reached 100. Final state of transfer depends on
values stored in the 'err' and 'dev->cmd_err'. If 'err' and 'dev->cmd_err' are zero, than transfer
would be aborted with status 0.

> quite frankly, this looks *very* wrong. It creates the possibility for
> us never completing a command which would cause several timeouts.

Pre 66b9298878742f08cb6e79b7c7d5632d782fd1e1 omap-i2c.c version didn't cause deadlocks.

> 
> How have you tested this and how have you figured this was the actual
> bug ? Based on commit log not matching the patch body (which 'original
> logic' are you talking about ?), I have to NAK this patch.

Well, I tried to debug I2C ISR hang issue (thats another question I want to discuss later)
using output to console. I places few dev_warn (not dev_dbg) messages into ISR 
(like got NACK, got ARDY and so on) and got "Too much work  in one IRQ" with incorrect booting.

Re: [PATCH 1/2] i2c: omap: fix NACK and Arbitration Lost irq handling

[Alexander Kochetkov]

> Assuming this is really correct (I haven't tested), you need to add:

To help understanding logic, I'd like to provide event traces (with the patch applied):

See i2c-omap.c dc418f6e6a8f5021ccf9e9c0957eefae3737168d as a reference.
https://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git/tree/drivers/i2c/busses/i2c-omap.c?id=dc418f6e6a8f5021ccf9e9c0957eefae3737168d

Typical event sequence for Arbitration Lost case looks like:
addr: 0x0058, len: 4, flags: 0x1, stop: 1
omap_i2c_xfer_msg:564 (STAT=0x0140; IE=0x601f; CON=0x8200)
omap_i2c_xfer_msg:565 omap_i2c_write_reg(dev, OMAP_I2C_CON_REG, w);
omap_i2c_xfer_msg:566 (STAT=0x0140; IE=0x601f; CON=0x8403)
omap_i2c_isr:886 (STAT=0x1141; IE=0x601f; CON=0x8000)
omap_i2c_isr_thread:906 (STAT=0x1141; IE=0x601f; CON=0x8000)
IRQ (ISR = 0x0001)
Arbitration lost

Typical event sequence for NACK case looks like:
addr: 0x0068, len: 4, flags: 0x1, stop: 1
omap_i2c_xfer_msg:564 (STAT=0x0040; IE=0x601f; CON=0x8000)
omap_i2c_xfer_msg:566 (STAT=0x0040; IE=0x601f; CON=0x8403)
omap_i2c_isr:886 (STAT=0x0146; IE=0x601f; CON=0x8000)
omap_i2c_isr_thread:906 (STAT=0x0146; IE=0x601f; CON=0x8000)
IRQ (ISR = 0x0006)
NACK
IRQ (ISR = 0x0004)
ARDY
omap_i2c_isr_thread:1030 (STAT=0x0140; IE=0x601f; CON=0x8000)

> 
> Fixes: 1d7afc9 i2c: omap: ack IRQ in parts
> Cc: <stable-u79uwXL29TY76Z2rM5mHXA@public.gmane.org> # v3.7+
> 
> here and resend, so it gets backported to older kernels.
> 

I'll resend. Thanks.

Re: [PATCH 2/2] i2c: omap: fix "Too much work in one IRQ" irq handling

[Felipe Balbi]

[-- Attachment #1: Type: text/plain, Size: 5062 bytes --]

Hi,

(please, never top-post)

On Sat, Nov 15, 2014 at 05:37:41AM +0300, Alexander Kochetkov wrote:
> Hi Felipe,
> 
> Initially you made the change (66b9298878742f08cb6e79b7c7d5632d782fd1e1):
> https://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git/commit/drivers/i2c/busses/i2c-omap.c?id=66b9298878742f08cb6e79b7c7d5632d782fd1e1
> 
>  		dev_dbg(dev->dev, "IRQ (ISR = 0x%04x)\n", stat);
> 
>  		if (count++ == 100) {
>  			dev_warn(dev->dev, "Too much work in one IRQ\n");
> -			break;
> +			omap_i2c_complete_cmd(dev, err);
> +			return IRQ_HANDLED;
>  		}
> 
> 
> Than that change transformed into (4a7ec4eda58269a507501f240955d99312fdfd5f):
> https://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git/commit/drivers/i2c/busses/i2c-omap.c?id=4a7ec4eda58269a507501f240955d99312fdfd5f
> 
> @@ -853,24 +853,21 @@ omap_i2c_isr(int this_irq, void *dev_id)
>  		dev_dbg(dev->dev, "IRQ (ISR = 0x%04x)\n", stat);
>  		if (count++ == 100) {
>  			dev_warn(dev->dev, "Too much work in one IRQ\n");
> -			omap_i2c_complete_cmd(dev, err);
> -			return IRQ_HANDLED;
> +			goto out;
>  		}
> 
> 
> +out:
> +	omap_i2c_complete_cmd(dev, err);
>  	return IRQ_HANDLED;

look how in both of these commits, omap_i2c_complete_cmd() is called as
it was before they existed. So, at a minimum, you're blaming the wrong
commit.

The commit which changed that was commit 0bdfe0c (i2c: omap: sanitize
exit path) and note how the behavior is still the same because when we
reach our counter, we will 'break' instead of 'goto out'. So, in all of
this, omap_i2c_complete_cmd() is still called just as it was before all
three commits referenced in this thread existed.

If there is a bug (which I'm not yet convinced there is), it already
existed way back.

> As a result we have in master:
> https://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git/tree/drivers/i2c/busses/i2c-omap.c
> 
> 	do {
> 		bits = omap_i2c_read_reg(dev, OMAP_I2C_IE_REG);
> 		stat = omap_i2c_read_reg(dev, OMAP_I2C_STAT_REG);
> 		stat &= bits;
> 		...
> 
> 		dev_dbg(dev->dev, "IRQ (ISR = 0x%04x)\n", stat);
> 		if (count++ == 100) {
> 			dev_warn(dev->dev, "Too much work in one IRQ\n");
> 			break;
> 		}
>                 ...
> 
> 	} while (stat);
> 
> 	omap_i2c_complete_cmd(dev, err);
> 
> out:
> 	spin_unlock_irqrestore(&dev->lock, flags);

how can this be a result of the two commits you pointed above ? In which
world can the two commits you referenced result in this placement for
the 'out' label ?

'out' was moved by commit 0bdfe0c (i2c: omap: sanitize exit path), but
that still guaranteed that omap_i2c_complete_cmd() was going to be
called just as before. The logic hasn't changed, actually.

> While original code was:
> 
> {
> 	bits = omap_i2c_read_reg(dev, OMAP_I2C_IE_REG);
> 	while ((stat = (omap_i2c_read_reg(dev, OMAP_I2C_STAT_REG))) & bits) {
> 		dev_dbg(dev->dev, "IRQ (ISR = 0x%04x)\n", stat);
> 		if (count++ == 100) {
> 			dev_warn(dev->dev, "Too much work in one IRQ\n");
> 			break;
> 		}
> 
> 		err = 0;
> complete:
>                 ...
> 
> 		if (stat & (OMAP_I2C_STAT_ARDY | OMAP_I2C_STAT_NACK |
> 					OMAP_I2C_STAT_AL)) {
> 			...
> 			omap_i2c_complete_cmd(dev, err);
> 			return IRQ_HANDLED;
> 		}
> 		...
> 	}
> 	return count ? IRQ_HANDLED : IRQ_NONE;
> }
> 
> 
> > how ? This is an interesting bug which deserves further explanation.
> 
> Look at the loops above, and at the omap_i2c_complete_cmd:
> 
> static inline void
> omap_i2c_complete_cmd(struct omap_i2c_dev *dev, u16 err)
> {
> 	dev->cmd_err |= err;
> 	complete(&dev->cmd_complete);
> }
> 
> You can see, loop will be aborted if counter reached 100. Final state
> of transfer depends on values stored in the 'err' and 'dev->cmd_err'.
> If 'err' and 'dev->cmd_err' are zero, than transfer would be aborted
> with status 0.

right, this is the same as it was before. If count reaches 100 we will
omap_i2c_complete_cmd().

> > quite frankly, this looks *very* wrong. It creates the possibility
> > for us never completing a command which would cause several
> > timeouts.
> 
> Pre 66b9298878742f08cb6e79b7c7d5632d782fd1e1 omap-i2c.c version didn't
> cause deadlocks.

which deadlock are you talking about ? How do you trigger it ? Where are
the lockup debug traces ?

> > How have you tested this and how have you figured this was the actual
> > bug ? Based on commit log not matching the patch body (which 'original
> > logic' are you talking about ?), I have to NAK this patch.
> 
> Well, I tried to debug I2C ISR hang issue (thats another question I
> want to discuss later) using output to console. I places few dev_warn

if you found a bug with the ISR, why discuss it later ? How can I
understand if you found a real bug without proper logs ?

> (not dev_dbg) messages into ISR (like got NACK, got ARDY and so on)
> and got "Too much work  in one IRQ" with incorrect booting.

what do you mean by incorrect booting ?

regards

-- 
balbi

[-- Attachment #2: Digital signature --]
[-- Type: application/pgp-signature, Size: 819 bytes --]

Re: [PATCH 2/2] i2c: omap: fix "Too much work in one IRQ" irq handling

[Felipe Balbi]

[-- Attachment #1: Type: text/plain, Size: 1543 bytes --]

Hi again,

On Fri, Nov 14, 2014 at 09:47:56PM -0600, Felipe Balbi wrote:
> > > how ? This is an interesting bug which deserves further explanation.
> > 
> > Look at the loops above, and at the omap_i2c_complete_cmd:
> > 
> > static inline void
> > omap_i2c_complete_cmd(struct omap_i2c_dev *dev, u16 err)
> > {
> > 	dev->cmd_err |= err;
> > 	complete(&dev->cmd_complete);
> > }
> > 
> > You can see, loop will be aborted if counter reached 100. Final state
> > of transfer depends on values stored in the 'err' and 'dev->cmd_err'.
> > If 'err' and 'dev->cmd_err' are zero, than transfer would be aborted
> > with status 0.

look at the IRQ handler again:

| omap_i2c_isr_thread(int this_irq, void *dev_id)
| {
| 	struct omap_i2c_dev *dev = dev_id;
| 	unsigned long flags;
| 	u16 bits;
| 	u16 stat;
| 	int err = 0, count = 0;
| 
| 	spin_lock_irqsave(&dev->lock, flags);
| 	do {

[...]

| 		if (stat & OMAP_I2C_STAT_NACK) {
| 			err |= OMAP_I2C_STAT_NACK;
| 			omap_i2c_ack_stat(dev, OMAP_I2C_STAT_NACK);
| 			break;
| 		}
| 
| 		if (stat & OMAP_I2C_STAT_AL) {
| 			dev_err(dev->dev, "Arbitration lost\n");
| 			err |= OMAP_I2C_STAT_AL;
| 			omap_i2c_ack_stat(dev, OMAP_I2C_STAT_AL);
| 			break;
| 		}

[...]

| 
| 	} while (stat);
| 
| 	omap_i2c_complete_cmd(dev, err);
| 
| out:
| 	spin_unlock_irqrestore(&dev->lock, flags);
| 
| 	return IRQ_HANDLED;
| }

How could I ever call omap_i2c_complete_cmd() with 'err' set as 0 if I
had either a NACK or Arbitration Lost ?

-- 
balbi

[-- Attachment #2: Digital signature --]
[-- Type: application/pgp-signature, Size: 819 bytes --]

Re: [PATCH 2/2] i2c: omap: fix "Too much work in one IRQ" irq handling

[Alexander Kochetkov]

Hello again.

> (please, never top-post)
Sorry.

Sorry for the inaccurate presentation of ideas. I am not a native English speaker.

First about patches:
[PATCH 1/2] and [PATCH 2/2] - intended to solve two independent problems.
They were sent as series, In the future, try not to do so, In order not to mislead.

> How could I ever call omap_i2c_complete_cmd() with 'err' set as 0 if I
> had either a NACK or Arbitration Lost ?

[PATCH 1/2] - fix AL, NACK handling and does not apply to [PATCH 2/2].
It not cause of problem solved of [PATCH 2/2].

> \bright, this is the same as it was before. If count reaches 100 we will
> omap_i2c_complete_cmd().
*No*

During refactoring submitted a series of patches was made the mistake.
This error alters the behavior of the interrupt handler, if it ends with the message 
"Too much work in one IRQ".

Error in the commit 66b9298878742f08cb6e79b7c7d5632d782fd1e1. 
All subsequent commits were correct and translate this error further.

In the parent commit 3312d25e1abdc41be8a75a1b2c3ccaa39a14ed99
(the commit before 66b9298878742f08cb6e79b7c7d5632d782fd1e1) in case
count reaches 100, loop breaks *without* calling omap_i2c_complete_cmd().

In commit 66b9298878742f08cb6e79b7c7d5632d782fd1e1, in case
count reaches 100, loop breaks and omap_i2c_complete_cmd() *get called*.

To see that, you need to open two versions of a file i2c-omap.c, side by side.

i2c-omap.c version corresponding to parent commit:
https://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git/tree/drivers/i2c/busses/i2c-omap.c?id=3312d25e1abdc41be8a75a1b2c3ccaa39a14ed99#n823

i2c-omap.c version corresponding next commit:
https://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git/tree/drivers/i2c/busses/i2c-omap.c?id=66b9298878742f08cb6e79b7c7d5632d782fd1e1#n823

According to wikipedia: "Code refactoring is the process of restructuring existing computer code – changing the factoring – 
without changing its external behavior.'

And commit's (66b9298878742f08cb6e79b7c7d5632d782fd1e1) message states what:
i2c: omap: switch over to do {} while loop
this will make sure that we execute at least once.
No functional changes otherwise.

But functional change present!
It's call of omap_i2c_complete_cmd()!

The next question: What affects this change?
If count reaches 100 and loop breaks and no error occupy during loop processing,
and no error would be set in err_cmd, omap_i2c_complete_cmd will set 0 as
result of transfer and wakeup omap_i2c_xfer. In other words, current i2c transfer
will be aborted with incorrect (success) status set. But, does transfer completed in real?
Do buf data was sent to i2c slave device or received from it in real?
Upper layer code would thing, that data was sent successfully.

How to see that bug in real live? Just add extra delayes into isr thread.
I did it unintentionally inserting dev_warn into isr thread.

BTW. I made more testing and provide more logs to demonstrate affected changes.


> which deadlock are you talking about ? How do you trigger it ? Where are
> the lockup debug traces ?
> 
> Well, I tried to debug I2C ISR hang issue (thats another question I
> want to discuss later) using output to console. I places few dev_warn
> 
> if you found a bug with the ISR, why discuss it later ? How can I
> understand if you found a real bug without proper logs ?


I put in order my thoughts and describe. It's next problem, not related to patch1/patch2.

In general, the problem (the 3rd one) is that linux either hang or segfault
in the i2c-omap driver if another master on the i2c bus (multimaster environment),
submit write request to General Call Address. In that case ISR could not correctly
handle RDR (or XRDY, ARDY, or that ever). Thats becase i2c-omap driver doesn't
correctly handle i2c-controller's slave mode. But controller enter slave mode
after each master transfer. Yes, AAS and GC interrupts masked, but i2c-controller
still sends RDR (or that ever events) when it detect slave access from another master on the bus.

I have two safe solutions of the (3rd) problem in the mind:
- keep interrupts disabled between i2c-master access (I think about implementing
i2c_omap_interrupt_enable_clr/i2c_omap_interrupt_enable_set helpers and putting
them in the right places)
- keep controller disabled between i2c-master access (keep EN-bit of CON register 0)

That solutions also help with races between isr and xfer_msg.

What do you think about that?

How to reproduce 3-rd problem:
In order to ease reproduce, you should disable i2c controller from entering suspend mode:
echo on > /sys/devices/platform/omap/omap_i2c.2/power/control

And then, using another i2c-master, connected to the same (i2c.2) bus,
initiate I2C write transfer to Generall Call Address, than linux ether hang or isr thread segfault :)

Re: [PATCH 2/2] i2c: omap: fix "Too much work in one IRQ" irq handling

[Felipe Balbi]

[-- Attachment #1: Type: text/plain, Size: 6495 bytes --]

Hi,

On Sat, Nov 15, 2014 at 08:42:03AM +0300, Alexander Kochetkov wrote:
> Hello again.
> 
> > (please, never top-post)
> Sorry.
> 
> Sorry for the inaccurate presentation of ideas. I am not a native
> English speaker.

neither am I ;-)

> First about patches:
> [PATCH 1/2] and [PATCH 2/2] - intended to solve two independent problems.
> They were sent as series, In the future, try not to do so, In order
> not to mislead.

sending several fixes as a series is not a problem, a problem would be
to make fixes depend on new features or cleanups.

> > How could I ever call omap_i2c_complete_cmd() with 'err' set as 0 if I
> > had either a NACK or Arbitration Lost ?
> 
> [PATCH 1/2] - fix AL, NACK handling and does not apply to [PATCH 2/2].
> It not cause of problem solved of [PATCH 2/2].

still, how could we ever have that situation ? We break out of the loop
as soon as an error is encountered.

> > \bright, this is the same as it was before. If count reaches 100 we will
> > omap_i2c_complete_cmd().
> *No*
> 
> During refactoring submitted a series of patches was made the mistake.
> This error alters the behavior of the interrupt handler, if it ends
> with the message "Too much work in one IRQ".
>
> Error in the commit 66b9298878742f08cb6e79b7c7d5632d782fd1e1. 
> All subsequent commits were correct and translate this error further.
> 
> In the parent commit 3312d25e1abdc41be8a75a1b2c3ccaa39a14ed99
> (the commit before 66b9298878742f08cb6e79b7c7d5632d782fd1e1) in case
> count reaches 100, loop breaks *without* calling omap_i2c_complete_cmd().
> 
> In commit 66b9298878742f08cb6e79b7c7d5632d782fd1e1, in case
> count reaches 100, loop breaks and omap_i2c_complete_cmd() *get called*.

aaa, now I see what you're talking about. I'll review that code on
Monday. Let me see if that was intentional or I missed something.

> To see that, you need to open two versions of a file i2c-omap.c, side
> by side.
> 
> i2c-omap.c version corresponding to parent commit:
> https://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git/tree/drivers/i2c/busses/i2c-omap.c?id=3312d25e1abdc41be8a75a1b2c3ccaa39a14ed99#n823
> 
> i2c-omap.c version corresponding next commit:
> https://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git/tree/drivers/i2c/busses/i2c-omap.c?id=66b9298878742f08cb6e79b7c7d5632d782fd1e1#n823
> 
> According to wikipedia: "Code refactoring is the process of
> restructuring existing computer code – changing the factoring –
> without changing its external behavior.'
> 
> And commit's (66b9298878742f08cb6e79b7c7d5632d782fd1e1) message states what:
> i2c: omap: switch over to do {} while loop
> this will make sure that we execute at least once.
> No functional changes otherwise.
> 
> But functional change present!
> It's call of omap_i2c_complete_cmd()!
> 
> The next question: What affects this change?
> If count reaches 100 and loop breaks and no error occupy during loop processing,
> and no error would be set in err_cmd, omap_i2c_complete_cmd will set 0 as
> result of transfer and wakeup omap_i2c_xfer. In other words, current i2c transfer
> will be aborted with incorrect (success) status set. But, does transfer completed in real?
> Do buf data was sent to i2c slave device or received from it in real?
> Upper layer code would thing, that data was sent successfully.
> 
> How to see that bug in real live? Just add extra delayes into isr thread.
> I did it unintentionally inserting dev_warn into isr thread.

right, apparently it is a bug, but it's very difficult to reproduce
considering we break out of IRQ handler as soon as something gets
transferred. The possibility of that count reaching 100 is very minor. A
bug nevertheless.

> BTW. I made more testing and provide more logs to demonstrate affected
> changes.
> 
> 
> > which deadlock are you talking about ? How do you trigger it ? Where are
> > the lockup debug traces ?
> > 
> > Well, I tried to debug I2C ISR hang issue (thats another question I
> > want to discuss later) using output to console. I places few dev_warn
> > 
> > if you found a bug with the ISR, why discuss it later ? How can I
> > understand if you found a real bug without proper logs ?
> 
> 
> I put in order my thoughts and describe. It's next problem, not
> related to patch1/patch2.
> 
> In general, the problem (the 3rd one) is that linux either hang or
> segfault in the i2c-omap driver if another master on the i2c bus
> (multimaster environment),

multimaster is not supported by this driver, so you can't call that a
bug. It's a missing feature, it needs to be implemented. Nobody has ever
had access to a multimaster environment where to develop it, so it was
never done.

> submit write request to General Call Address. In that case ISR could
> not correctly handle RDR (or XRDY, ARDY, or that ever). Thats becase
> i2c-omap driver doesn't correctly handle i2c-controller's slave mode.

right, Linux doesn't support being the slave. That's also a missing
feature, not a bug.

> But controller enter slave mode after each master transfer. Yes, AAS
> and GC interrupts masked, but i2c-controller still sends RDR (or that
> ever events) when it detect slave access from another master on the
> bus.
> 
> I have two safe solutions of the (3rd) problem in the mind:
> - keep interrupts disabled between i2c-master access (I think about implementing
> i2c_omap_interrupt_enable_clr/i2c_omap_interrupt_enable_set helpers and putting
> them in the right places)
> - keep controller disabled between i2c-master access (keep EN-bit of CON register 0)

send a patch and we'll see, but keep in mind if you want to support
multimaster, you need to implement it as per documentation.

> That solutions also help with races between isr and xfer_msg.

what races ? If you found races, that's another problem which should be
fixed separately from implementing a new feature.

> What do you think about that?
> 
> How to reproduce 3-rd problem:
> In order to ease reproduce, you should disable i2c controller from
> entering suspend mode:
> echo on > /sys/devices/platform/omap/omap_i2c.2/power/control
> 
> And then, using another i2c-master, connected to the same (i2c.2) bus,
> initiate I2C write transfer to Generall Call Address, than linux ether
> hang or isr thread segfault :)

right, it has never been implemented, what would you expect ? ;-)

-- 
balbi

[-- Attachment #2: Digital signature --]
[-- Type: application/pgp-signature, Size: 819 bytes --]

Re: [PATCH 2/2] i2c: omap: fix "Too much work in one IRQ" irq handling

[Wolfram Sang]

[-- Attachment #1: Type: text/plain, Size: 596 bytes --]


> > submit write request to General Call Address. In that case ISR could
> > not correctly handle RDR (or XRDY, ARDY, or that ever). Thats becase
> > i2c-omap driver doesn't correctly handle i2c-controller's slave mode.
> 
> right, Linux doesn't support being the slave. That's also a missing
> feature, not a bug.

This is going to change. I sent out RFC patches for slave support [1]
and will send V1 this week. This won't affect your driver, though,
unless you implement the backend into it.

Just to keep your heads up.

[1] http://thread.gmane.org/gmane.linux.kernel/1783295

[-- Attachment #2: Digital signature --]
[-- Type: application/pgp-signature, Size: 819 bytes --]

Re: [PATCH 2/2] i2c: omap: fix "Too much work in one IRQ" irq handling

[Felipe Balbi]

[-- Attachment #1: Type: text/plain, Size: 835 bytes --]

On Mon, Nov 17, 2014 at 03:41:53PM +0100, Wolfram Sang wrote:
> 
> > > submit write request to General Call Address. In that case ISR could
> > > not correctly handle RDR (or XRDY, ARDY, or that ever). Thats becase
> > > i2c-omap driver doesn't correctly handle i2c-controller's slave mode.
> > 
> > right, Linux doesn't support being the slave. That's also a missing
> > feature, not a bug.
> 
> This is going to change. I sent out RFC patches for slave support [1]
> and will send V1 this week. This won't affect your driver, though,
> unless you implement the backend into it.
> 
> Just to keep your heads up.
> 
> [1] http://thread.gmane.org/gmane.linux.kernel/1783295

sweet :-)

Still, as of now we can't consider what Alexander mentions a bug. Good
to get it sorted out, but not -rc material.

-- 
balbi

[-- Attachment #2: Digital signature --]
[-- Type: application/pgp-signature, Size: 819 bytes --]

Re: [PATCH 2/2] i2c: omap: fix "Too much work in one IRQ" irq handling

[Wolfram Sang]

[-- Attachment #1: Type: text/plain, Size: 835 bytes --]


> > > right, Linux doesn't support being the slave. That's also a missing
> > > feature, not a bug.
> > 
> > This is going to change. I sent out RFC patches for slave support [1]
> > and will send V1 this week. This won't affect your driver, though,
> > unless you implement the backend into it.
> > 
> > Just to keep your heads up.
> > 
> > [1] http://thread.gmane.org/gmane.linux.kernel/1783295
> 
> sweet :-)

V1 was sent out a few seconds ago :)

https://lkml.org/lkml/2014/11/18/678

> Still, as of now we can't consider what Alexander mentions a bug. Good
> to get it sorted out, but not -rc material.

I got confused with all the patches sent out for his issues. Can you ack
them once you are fine and mention if you consider them important for
this or the next release? That would be really helpful!


[-- Attachment #2: Digital signature --]
[-- Type: application/pgp-signature, Size: 819 bytes --]

Re: [PATCH 2/2] i2c: omap: fix "Too much work in one IRQ" irq handling

[Alexander Kochetkov]

> Still, as of now we can't consider what Alexander mentions a bug. Good
> to get it sorted out, but not -rc material.
> 

Actually, I focused on fixing issues then i2c-omap acts as master in a multi master environment.
And must say, that current linux/mainline driver work perfectly with minor fixes.

I could take a look how to switch the driver into mixed master/slave mode, but later.

Sad to say, I encountered undocumented i2c- hardware issue.
In short: BB-bit doesn't reflect I2C-bus state after soft reset if SDA or SCL line was low during reset
until i2c-controller again detect START or STOP condition on the wire.

More over, if SDA was low during reset, than next submitted transfer will not start ("controller timeout"),
if SCL was low during reset, than next submitted transfer will start and corrupt signals on wire :(

I'm checking it now. And going to post results to ti forum.

BB-bit reflect I2C-bus state, between power-down/power-up modes.

Alexander.

Re: [PATCH 2/2] i2c: omap: fix "Too much work in one IRQ" irq handling

[Felipe Balbi]

[-- Attachment #1: Type: text/plain, Size: 1612 bytes --]

On Tue, Nov 18, 2014 at 07:31:44PM +0300, Alexander Kochetkov wrote:
> 
> > Still, as of now we can't consider what Alexander mentions a bug. Good
> > to get it sorted out, but not -rc material.
> > 
> 
> Actually, I focused on fixing issues then i2c-omap acts as master in a
> multi master environment.

but that's not supported either. If you wanna do that, then go through
the TRM and implement what's missing. Then give a good commit log
explaining the issues and how you solved them :-)

Still not -rc material :-)

> And must say, that current linux/mainline driver work perfectly with
> minor fixes.

that's good to know. I know some folks still have a few hick ups. The IP
isn't all that great, I'm afraid.

> I could take a look how to switch the driver into mixed master/slave
> mode, but later.
> 
> Sad to say, I encountered undocumented i2c- hardware issue.
> In short: BB-bit doesn't reflect I2C-bus state after soft reset if SDA
> or SCL line was low during reset until i2c-controller again detect
> START or STOP condition on the wire.

this is another of those which really deserves a mention in code comment
or commit log :-)

> More over, if SDA was low during reset, than next submitted transfer
> will not start ("controller timeout"), if SCL was low during reset,
> than next submitted transfer will start and corrupt signals on wire :(

another thing to add as comment to code :-)

> I'm checking it now. And going to post results to ti forum.
> 
> BB-bit reflect I2C-bus state, between power-down/power-up modes.

alright, thanks.

-- 
balbi

[-- Attachment #2: Digital signature --]
[-- Type: application/pgp-signature, Size: 819 bytes --]

Re: [PATCH 2/2] i2c: omap: fix "Too much work in one IRQ" irq handling

[Alexander Kochetkov]

Hello, 

18 нояб. 2014 г., в 19:12, Wolfram Sang <wsa-z923LK4zBo2bacvFa/9K2g@public.gmane.org> написал(а):

> I got confused with all the patches sent out for his issues. Can you ack
> them once you are fine and mention if you consider them important for
> this or the next release? That would be really helpful!

Duplicate/Obsolete (v1):
https://patchwork.ozlabs.org/patch/411059/
https://patchwork.ozlabs.org/patch/411060/
https://patchwork.ozlabs.org/patch/411081/
https://patchwork.ozlabs.org/patch/411084/

v2 (in review by Aaro)
https://patchwork.ozlabs.org/patch/411714/

comment to v2:
https://patchwork.ozlabs.org/patch/411740/

latest, v3 (same as v2, fixed subject line):
https://patchwork.ozlabs.org/patch/412095/

So, for now only one (v2 or v3) patch should be accepted or declined.
All others should be dropped and forgotten.

Sorry, for making so much noise.

Alexander.

Re: [PATCH 2/2] i2c: omap: fix "Too much work in one IRQ" irq handling

[Wolfram Sang]

[-- Attachment #1: Type: text/plain, Size: 419 bytes --]

Hi,

thanks for the list!

> latest, v3 (same as v2, fixed subject line):
> https://patchwork.ozlabs.org/patch/412095/

Yes, I have an eye on this one. Only waiting for the test results from
older platforms by Aaro.

> Sorry, for making so much noise.

No problem, this is part of the process. Still, assistance like yours
with this list is very much appreciated so I can focus on actual review!

Regards,

   Wolfram


[-- Attachment #2: Digital signature --]
[-- Type: application/pgp-signature, Size: 819 bytes --]