spi: trigger trace event for message-done before mesg->complete
diff mbox

Message ID 1426674448-8246-1-git-send-email-u.kleine-koenig@pengutronix.de
State New
Headers show

Commit Message

Uwe Kleine-König March 18, 2015, 10:27 a.m. UTC
With spidev the mesg->complete callback points to spidev_complete.
Calling this unblocks spidev_sync and so spidev_sync_write finishes. As
the struct spi_message just read is a local variable in
spidev_sync_write and recording the trace event accesses this message
the recording is better done first. The same can happen for
spidev_sync_read.

This fixes an oops observed on a 3.14-rt system with spidev activity
after

	echo 1 > /sys/kernel/debug/tracing/events/spi/enable

.

Signed-off-by: Uwe Kleine-König <u.kleine-koenig@pengutronix.de>
---
 drivers/spi/spi.c | 5 +++--
 1 file changed, 3 insertions(+), 2 deletions(-)

Comments

Mark Brown March 18, 2015, 11:36 a.m. UTC | #1
On Wed, Mar 18, 2015 at 11:27:28AM +0100, Uwe Kleine-König wrote:
> With spidev the mesg->complete callback points to spidev_complete.
> Calling this unblocks spidev_sync and so spidev_sync_write finishes. As
> the struct spi_message just read is a local variable in
> spidev_sync_write and recording the trace event accesses this message
> the recording is better done first. The same can happen for
> spidev_sync_read.

Applied, thanks.  I'm a bit suspicious that the changelog talks only
about spidev though...
Uwe Kleine-König March 18, 2015, 1:32 p.m. UTC | #2
On Wed, Mar 18, 2015 at 11:36:35AM +0000, Mark Brown wrote:
> On Wed, Mar 18, 2015 at 11:27:28AM +0100, Uwe Kleine-König wrote:
> > With spidev the mesg->complete callback points to spidev_complete.
> > Calling this unblocks spidev_sync and so spidev_sync_write finishes. As
> > the struct spi_message just read is a local variable in
> > spidev_sync_write and recording the trace event accesses this message
> > the recording is better done first. The same can happen for
> > spidev_sync_read.
> 
> Applied, thanks.  I'm a bit suspicious that the changelog talks only
> about spidev though...
That's my workflow. Maybe the important thing here is also that I use
-rt?!

Best regards
Uwe
Mark Brown March 18, 2015, 1:58 p.m. UTC | #3
On Wed, Mar 18, 2015 at 02:32:26PM +0100, Uwe Kleine-König wrote:
> On Wed, Mar 18, 2015 at 11:36:35AM +0000, Mark Brown wrote:

> > Applied, thanks.  I'm a bit suspicious that the changelog talks only
> > about spidev though...

> That's my workflow. Maybe the important thing here is also that I use
> -rt?!

My point here is that the analysis of the issue shouldn't depend on
spidev in particular, if you need to call out the specific driver you're
working with that's an alarm sign that it's doing something weird and
perhaps the problem is with the driver.
Uwe Kleine-König March 18, 2015, 2:48 p.m. UTC | #4
On Wed, Mar 18, 2015 at 01:58:54PM +0000, Mark Brown wrote:
> On Wed, Mar 18, 2015 at 02:32:26PM +0100, Uwe Kleine-König wrote:
> > On Wed, Mar 18, 2015 at 11:36:35AM +0000, Mark Brown wrote:
> 
> > > Applied, thanks.  I'm a bit suspicious that the changelog talks only
> > > about spidev though...
> 
> > That's my workflow. Maybe the important thing here is also that I use
> > -rt?!
> 
> My point here is that the analysis of the issue shouldn't depend on
> spidev in particular, if you need to call out the specific driver you're
> working with that's an alarm sign that it's doing something weird and
> perhaps the problem is with the driver.
This just happens to be the driver I saw the problem with. Don't have
another spi device on that bus to cross check with other drivers. I
wouldn't be too concerned here.

Best regards
Uwe
Mark Brown March 19, 2015, 11:24 a.m. UTC | #5
On Wed, Mar 18, 2015 at 03:48:54PM +0100, Uwe Kleine-König wrote:
> On Wed, Mar 18, 2015 at 01:58:54PM +0000, Mark Brown wrote:

> > My point here is that the analysis of the issue shouldn't depend on
> > spidev in particular, if you need to call out the specific driver you're
> > working with that's an alarm sign that it's doing something weird and
> > perhaps the problem is with the driver.

> This just happens to be the driver I saw the problem with. Don't have
> another spi device on that bus to cross check with other drivers. I
> wouldn't be too concerned here.

Sure, but it's better to write it up in terms of a generic driver - it's
the difference between "let's work around this driver" and "the core
isn't doing the right thing for drivers here".
Uwe Kleine-König March 19, 2015, 11:48 a.m. UTC | #6
Hello Mark,

On Thu, Mar 19, 2015 at 11:24:30AM +0000, Mark Brown wrote:
> On Wed, Mar 18, 2015 at 03:48:54PM +0100, Uwe Kleine-König wrote:
> > On Wed, Mar 18, 2015 at 01:58:54PM +0000, Mark Brown wrote:
> 
> > > My point here is that the analysis of the issue shouldn't depend on
> > > spidev in particular, if you need to call out the specific driver you're
> > > working with that's an alarm sign that it's doing something weird and
> > > perhaps the problem is with the driver.
> 
> > This just happens to be the driver I saw the problem with. Don't have
> > another spi device on that bus to cross check with other drivers. I
> > wouldn't be too concerned here.
> 
> Sure, but it's better to write it up in terms of a generic driver - it's
> the difference between "let's work around this driver" and "the core
> isn't doing the right thing for drivers here".
OK, so something like:

------------>8------------
spi: trigger trace event for message-done before mesg->complete

The message's complete callback might (permissibly) free the memory that
holds the message. As recording the trace event for the end of a
transfer accesses this message the recording is better done first.

This fixes an oops observed on a 3.14-rt system with bus activity using
spidev after

        echo 1 > /sys/kernel/debug/tracing/events/spi/enable

. (For spidev mesg->complete points to spidev_complete. Calling that
unblocks spidev_sync and so spidev_sync_write (or spidev_sync_read).
This in turn leaves the scope of the local variable that holds the
message.)
------------>8------------

Best regards
Uwe
Mark Brown March 19, 2015, 11:51 a.m. UTC | #7
On Thu, Mar 19, 2015 at 12:48:42PM +0100, Uwe Kleine-König wrote:
> On Thu, Mar 19, 2015 at 11:24:30AM +0000, Mark Brown wrote:

> > Sure, but it's better to write it up in terms of a generic driver - it's
> > the difference between "let's work around this driver" and "the core
> > isn't doing the right thing for drivers here".

> OK, so something like:

> spi: trigger trace event for message-done before mesg->complete
> 
> The message's complete callback might (permissibly) free the memory that
> holds the message. As recording the trace event for the end of a
> transfer accesses this message the recording is better done first.

Yes, that's the sort of thing I was looking for - it just makes the
review a bit easier.

Patch
diff mbox

diff --git a/drivers/spi/spi.c b/drivers/spi/spi.c
index 6d3b9b76c80b..df577518b770 100644
--- a/drivers/spi/spi.c
+++ b/drivers/spi/spi.c
@@ -994,13 +994,14 @@  void spi_finalize_current_message(struct spi_master *master)
 				"failed to unprepare message: %d\n", ret);
 		}
 	}
+
+	trace_spi_message_done(mesg);
+
 	master->cur_msg_prepared = false;
 
 	mesg->state = NULL;
 	if (mesg->complete)
 		mesg->complete(mesg->context);
-
-	trace_spi_message_done(mesg);
 }
 EXPORT_SYMBOL_GPL(spi_finalize_current_message);