diff mbox

dma-buf/fence: Avoid use of uninitialised timestamp

Message ID 20170214124001.1930-1-chris@chris-wilson.co.uk (mailing list archive)
State New, archived
Headers show

Commit Message

Chris Wilson Feb. 14, 2017, 12:40 p.m. UTC
[  236.821534] WARNING: kmemcheck: Caught 64-bit read from uninitialized memory (ffff8802538683d0)
[  236.828642] 420000001e7f0000000000000000000000080000000000000000000000000000
[  236.839543]  i i i i u u u u i i i i i i i i u u u u u u u u u u u u u u u u
[  236.850420]                                  ^
[  236.854123] RIP: 0010:[<ffffffff81396f07>]  [<ffffffff81396f07>] fence_signal+0x17/0xd0
[  236.861313] RSP: 0018:ffff88024acd7ba0  EFLAGS: 00010282
[  236.865027] RAX: ffffffff812f6a90 RBX: ffff8802527ca800 RCX: ffff880252cb30e0
[  236.868801] RDX: ffff88024ac5d918 RSI: ffff880252f780e0 RDI: ffff880253868380
[  236.872579] RBP: ffff88024acd7bc0 R08: ffff88024acd7be0 R09: 0000000000000000
[  236.876407] R10: 0000000000000000 R11: 0000000000000000 R12: ffff880253868380
[  236.880185] R13: ffff8802538684d0 R14: ffff880253868380 R15: ffff88024cd48e00
[  236.883983] FS:  00007f1646d1a740(0000) GS:ffff88025d000000(0000) knlGS:0000000000000000
[  236.890959] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[  236.894702] CR2: ffff880251360318 CR3: 000000024ad21000 CR4: 00000000001406f0
[  236.898481]  [<ffffffff8130d1ad>] i915_gem_request_retire+0x1cd/0x230
[  236.902439]  [<ffffffff8130e2b3>] i915_gem_request_alloc+0xa3/0x2f0
[  236.906435]  [<ffffffff812fb1bd>] i915_gem_do_execbuffer.isra.41+0xb6d/0x18b0
[  236.910434]  [<ffffffff812fc265>] i915_gem_execbuffer2+0x95/0x1e0
[  236.914390]  [<ffffffff812ad625>] drm_ioctl+0x1e5/0x460
[  236.918275]  [<ffffffff8110d4cf>] do_vfs_ioctl+0x8f/0x5c0
[  236.922168]  [<ffffffff8110da3c>] SyS_ioctl+0x3c/0x70
[  236.926090]  [<ffffffff814b7a5f>] entry_SYSCALL_64_fastpath+0x17/0x93
[  236.930045]  [<ffffffffffffffff>] 0xffffffffffffffff

We only set the timestamp before we mark the fence as signaled. It is
done before to avoid observers having a window in which they may see the
fence as complete but no timestamp. Having it does incur a potential for
the timestamp to be written twice, and even for it to be corrupted if
the u64 write is not atomic. Instead use a new bit to record the
presence of the timestamp, and teach the readers to wait until it is set
if the fence is complete. There still remains a race where the timestamp
for the signaled fence may be shown before the fence is reported as
signaled, but that's a pre-existing error.

Signed-off-by: Chris Wilson <chris@chris-wilson.co.uk>
Cc: Sumit Semwal <sumit.semwal@linaro.org>
Cc: Gustavo Padovan <gustavo@padovan.org>
Cc: Daniel Vetter <daniel.vetter@intel.com>
---
 drivers/dma-buf/dma-fence.c  | 17 ++++++-----------
 drivers/dma-buf/sync_debug.c |  2 +-
 drivers/dma-buf/sync_file.c  |  8 +++++++-
 include/linux/dma-fence.h    |  2 ++
 4 files changed, 16 insertions(+), 13 deletions(-)

Comments

Gustavo Padovan Feb. 14, 2017, 1:40 p.m. UTC | #1
Hi Chris,

2017-02-14 Chris Wilson <chris@chris-wilson.co.uk>:

> [  236.821534] WARNING: kmemcheck: Caught 64-bit read from uninitialized memory (ffff8802538683d0)
> [  236.828642] 420000001e7f0000000000000000000000080000000000000000000000000000
> [  236.839543]  i i i i u u u u i i i i i i i i u u u u u u u u u u u u u u u u
> [  236.850420]                                  ^
> [  236.854123] RIP: 0010:[<ffffffff81396f07>]  [<ffffffff81396f07>] fence_signal+0x17/0xd0
> [  236.861313] RSP: 0018:ffff88024acd7ba0  EFLAGS: 00010282
> [  236.865027] RAX: ffffffff812f6a90 RBX: ffff8802527ca800 RCX: ffff880252cb30e0
> [  236.868801] RDX: ffff88024ac5d918 RSI: ffff880252f780e0 RDI: ffff880253868380
> [  236.872579] RBP: ffff88024acd7bc0 R08: ffff88024acd7be0 R09: 0000000000000000
> [  236.876407] R10: 0000000000000000 R11: 0000000000000000 R12: ffff880253868380
> [  236.880185] R13: ffff8802538684d0 R14: ffff880253868380 R15: ffff88024cd48e00
> [  236.883983] FS:  00007f1646d1a740(0000) GS:ffff88025d000000(0000) knlGS:0000000000000000
> [  236.890959] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [  236.894702] CR2: ffff880251360318 CR3: 000000024ad21000 CR4: 00000000001406f0
> [  236.898481]  [<ffffffff8130d1ad>] i915_gem_request_retire+0x1cd/0x230
> [  236.902439]  [<ffffffff8130e2b3>] i915_gem_request_alloc+0xa3/0x2f0
> [  236.906435]  [<ffffffff812fb1bd>] i915_gem_do_execbuffer.isra.41+0xb6d/0x18b0
> [  236.910434]  [<ffffffff812fc265>] i915_gem_execbuffer2+0x95/0x1e0
> [  236.914390]  [<ffffffff812ad625>] drm_ioctl+0x1e5/0x460
> [  236.918275]  [<ffffffff8110d4cf>] do_vfs_ioctl+0x8f/0x5c0
> [  236.922168]  [<ffffffff8110da3c>] SyS_ioctl+0x3c/0x70
> [  236.926090]  [<ffffffff814b7a5f>] entry_SYSCALL_64_fastpath+0x17/0x93
> [  236.930045]  [<ffffffffffffffff>] 0xffffffffffffffff
> 
> We only set the timestamp before we mark the fence as signaled. It is
> done before to avoid observers having a window in which they may see the
> fence as complete but no timestamp. Having it does incur a potential for
> the timestamp to be written twice, and even for it to be corrupted if
> the u64 write is not atomic. Instead use a new bit to record the
> presence of the timestamp, and teach the readers to wait until it is set
> if the fence is complete. There still remains a race where the timestamp
> for the signaled fence may be shown before the fence is reported as
> signaled, but that's a pre-existing error.
> 
> Signed-off-by: Chris Wilson <chris@chris-wilson.co.uk>
> Cc: Sumit Semwal <sumit.semwal@linaro.org>
> Cc: Gustavo Padovan <gustavo@padovan.org>
> Cc: Daniel Vetter <daniel.vetter@intel.com>
> ---
>  drivers/dma-buf/dma-fence.c  | 17 ++++++-----------
>  drivers/dma-buf/sync_debug.c |  2 +-
>  drivers/dma-buf/sync_file.c  |  8 +++++++-
>  include/linux/dma-fence.h    |  2 ++
>  4 files changed, 16 insertions(+), 13 deletions(-)
> 
> diff --git a/drivers/dma-buf/dma-fence.c b/drivers/dma-buf/dma-fence.c
> index d1f1f456f5c4..dd2d7b6d2831 100644
> --- a/drivers/dma-buf/dma-fence.c
> +++ b/drivers/dma-buf/dma-fence.c
> @@ -74,11 +74,6 @@ int dma_fence_signal_locked(struct dma_fence *fence)
>  	if (WARN_ON(!fence))
>  		return -EINVAL;
>  
> -	if (!ktime_to_ns(fence->timestamp)) {
> -		fence->timestamp = ktime_get();
> -		smp_mb__before_atomic();
> -	}
> -
>  	if (test_and_set_bit(DMA_FENCE_FLAG_SIGNALED_BIT, &fence->flags)) {
>  		ret = -EINVAL;
>  
> @@ -86,8 +81,11 @@ int dma_fence_signal_locked(struct dma_fence *fence)
>  		 * we might have raced with the unlocked dma_fence_signal,
>  		 * still run through all callbacks
>  		 */
> -	} else
> +	} else {
> +		fence->timestamp = ktime_get();
> +		set_bit(DMA_FENCE_FLAG_TIMESTAMP_BIT, &fence->flags);
>  		trace_dma_fence_signaled(fence);
> +	}
>  
>  	list_for_each_entry_safe(cur, tmp, &fence->cb_list, node) {
>  		list_del_init(&cur->node);
> @@ -114,14 +112,11 @@ int dma_fence_signal(struct dma_fence *fence)
>  	if (!fence)
>  		return -EINVAL;
>  
> -	if (!ktime_to_ns(fence->timestamp)) {
> -		fence->timestamp = ktime_get();
> -		smp_mb__before_atomic();
> -	}
> -
>  	if (test_and_set_bit(DMA_FENCE_FLAG_SIGNALED_BIT, &fence->flags))
>  		return -EINVAL;
>  
> +	fence->timestamp = ktime_get();
> +	set_bit(DMA_FENCE_FLAG_TIMESTAMP_BIT, &fence->flags);
>  	trace_dma_fence_signaled(fence);
>  
>  	if (test_bit(DMA_FENCE_FLAG_ENABLE_SIGNAL_BIT, &fence->flags)) {
> diff --git a/drivers/dma-buf/sync_debug.c b/drivers/dma-buf/sync_debug.c
> index c769dc653b34..bfead12390f2 100644
> --- a/drivers/dma-buf/sync_debug.c
> +++ b/drivers/dma-buf/sync_debug.c
> @@ -84,7 +84,7 @@ static void sync_print_fence(struct seq_file *s,
>  		   show ? "_" : "",
>  		   sync_status_str(status));
>  
> -	if (status) {
> +	if (test_bit(DMA_FENCE_FLAG_TIMESTAMP_BIT, &fence->flags)) {
>  		struct timespec64 ts64 =
>  			ktime_to_timespec64(fence->timestamp);

How about add this test_bit() to dma_fence_is_signaled_locked() so
we test both for DMA_FENCE_FLAG_SIGNALED_BIT and
DMA_FENCE_FLAG_TIMESTAMP_BIT there at the same time?

Gustavo
Chris Wilson Feb. 14, 2017, 1:52 p.m. UTC | #2
On Tue, Feb 14, 2017 at 11:40:38AM -0200, Gustavo Padovan wrote:
> Hi Chris,
> 
> 2017-02-14 Chris Wilson <chris@chris-wilson.co.uk>:
> > diff --git a/drivers/dma-buf/sync_debug.c b/drivers/dma-buf/sync_debug.c
> > index c769dc653b34..bfead12390f2 100644
> > --- a/drivers/dma-buf/sync_debug.c
> > +++ b/drivers/dma-buf/sync_debug.c
> > @@ -84,7 +84,7 @@ static void sync_print_fence(struct seq_file *s,
> >  		   show ? "_" : "",
> >  		   sync_status_str(status));
> >  
> > -	if (status) {
> > +	if (test_bit(DMA_FENCE_FLAG_TIMESTAMP_BIT, &fence->flags)) {
> >  		struct timespec64 ts64 =
> >  			ktime_to_timespec64(fence->timestamp);
> 
> How about add this test_bit() to dma_fence_is_signaled_locked() so
> we test both for DMA_FENCE_FLAG_SIGNALED_BIT and
> DMA_FENCE_FLAG_TIMESTAMP_BIT there at the same time?

I was thinking of only using it as communication with the timestamp
user. That avoids getting into the situation as to which bit truly means
is-signaled and we still only synchronize on SIGNALED_BIT.

It would be possible, but I don't think it makes anything simpler.

One thing that occurs to me is whether we should be setting the
timestamp when we set an error. The above (sync_debug though) implies
that it expects the error to have the timestamp. sync_fence_info could
go either way.
-Chris
Gustavo Padovan Feb. 14, 2017, 2:22 p.m. UTC | #3
2017-02-14 Chris Wilson <chris@chris-wilson.co.uk>:

> On Tue, Feb 14, 2017 at 11:40:38AM -0200, Gustavo Padovan wrote:
> > Hi Chris,
> > 
> > 2017-02-14 Chris Wilson <chris@chris-wilson.co.uk>:
> > > diff --git a/drivers/dma-buf/sync_debug.c b/drivers/dma-buf/sync_debug.c
> > > index c769dc653b34..bfead12390f2 100644
> > > --- a/drivers/dma-buf/sync_debug.c
> > > +++ b/drivers/dma-buf/sync_debug.c
> > > @@ -84,7 +84,7 @@ static void sync_print_fence(struct seq_file *s,
> > >  		   show ? "_" : "",
> > >  		   sync_status_str(status));
> > >  
> > > -	if (status) {
> > > +	if (test_bit(DMA_FENCE_FLAG_TIMESTAMP_BIT, &fence->flags)) {
> > >  		struct timespec64 ts64 =
> > >  			ktime_to_timespec64(fence->timestamp);
> > 
> > How about add this test_bit() to dma_fence_is_signaled_locked() so
> > we test both for DMA_FENCE_FLAG_SIGNALED_BIT and
> > DMA_FENCE_FLAG_TIMESTAMP_BIT there at the same time?
> 
> I was thinking of only using it as communication with the timestamp
> user. That avoids getting into the situation as to which bit truly means
> is-signaled and we still only synchronize on SIGNALED_BIT.
> 
> It would be possible, but I don't think it makes anything simpler.

Yes, it doesn't make anything better. We should keep it that way for
users that doesn't need timestamp.

> 
> One thing that occurs to me is whether we should be setting the
> timestamp when we set an error. The above (sync_debug though) implies
> that it expects the error to have the timestamp. sync_fence_info could
> go either way.

We could do it. I don't see any reason against it.

Gustavo
Chris Wilson Feb. 14, 2017, 2:28 p.m. UTC | #4
On Tue, Feb 14, 2017 at 12:22:02PM -0200, Gustavo Padovan wrote:
> 2017-02-14 Chris Wilson <chris@chris-wilson.co.uk>:
> 
> > On Tue, Feb 14, 2017 at 11:40:38AM -0200, Gustavo Padovan wrote:
> > > Hi Chris,
> > > 
> > > 2017-02-14 Chris Wilson <chris@chris-wilson.co.uk>:
> > One thing that occurs to me is whether we should be setting the
> > timestamp when we set an error. The above (sync_debug though) implies
> > that it expects the error to have the timestamp. sync_fence_info could
> > go either way.
> 
> We could do it. I don't see any reason against it.

It is just uncertain as to what timestamp means, and what the user
wants. In i915 we may end up flagging an error on a fence long (many
10s) before the fence is signaled. It still feels more appropriate to
set the timestamp on when the fence is complete - certainly for the case
where we replay the request (and we flag fence->error that we did so as
there may have been side-effects that we should inform the user about).
-Chris
Chris Wilson July 11, 2017, 5:09 p.m. UTC | #5
Quoting Chris Wilson (2017-02-14 12:40:01)
> [  236.821534] WARNING: kmemcheck: Caught 64-bit read from uninitialized memory (ffff8802538683d0)
> [  236.828642] 420000001e7f0000000000000000000000080000000000000000000000000000
> [  236.839543]  i i i i u u u u i i i i i i i i u u u u u u u u u u u u u u u u
> [  236.850420]                                  ^
> [  236.854123] RIP: 0010:[<ffffffff81396f07>]  [<ffffffff81396f07>] fence_signal+0x17/0xd0
> [  236.861313] RSP: 0018:ffff88024acd7ba0  EFLAGS: 00010282
> [  236.865027] RAX: ffffffff812f6a90 RBX: ffff8802527ca800 RCX: ffff880252cb30e0
> [  236.868801] RDX: ffff88024ac5d918 RSI: ffff880252f780e0 RDI: ffff880253868380
> [  236.872579] RBP: ffff88024acd7bc0 R08: ffff88024acd7be0 R09: 0000000000000000
> [  236.876407] R10: 0000000000000000 R11: 0000000000000000 R12: ffff880253868380
> [  236.880185] R13: ffff8802538684d0 R14: ffff880253868380 R15: ffff88024cd48e00
> [  236.883983] FS:  00007f1646d1a740(0000) GS:ffff88025d000000(0000) knlGS:0000000000000000
> [  236.890959] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [  236.894702] CR2: ffff880251360318 CR3: 000000024ad21000 CR4: 00000000001406f0
> [  236.898481]  [<ffffffff8130d1ad>] i915_gem_request_retire+0x1cd/0x230
> [  236.902439]  [<ffffffff8130e2b3>] i915_gem_request_alloc+0xa3/0x2f0
> [  236.906435]  [<ffffffff812fb1bd>] i915_gem_do_execbuffer.isra.41+0xb6d/0x18b0
> [  236.910434]  [<ffffffff812fc265>] i915_gem_execbuffer2+0x95/0x1e0
> [  236.914390]  [<ffffffff812ad625>] drm_ioctl+0x1e5/0x460
> [  236.918275]  [<ffffffff8110d4cf>] do_vfs_ioctl+0x8f/0x5c0
> [  236.922168]  [<ffffffff8110da3c>] SyS_ioctl+0x3c/0x70
> [  236.926090]  [<ffffffff814b7a5f>] entry_SYSCALL_64_fastpath+0x17/0x93
> [  236.930045]  [<ffffffffffffffff>] 0xffffffffffffffff

Ah something that I didn't take into account, and indeed gives this a bit
more urgency than I realised, is that the timestamp is exposed to
userspace. As such we are feeding it garbage, at best.

The trivial option is just to clear it in dma_fence_init(). I still have
the slight preference for the extra complication here (for the reader) as
it should be quicker for the more common path of signaling the fence.

> We only set the timestamp before we mark the fence as signaled. It is
> done before to avoid observers having a window in which they may see the
> fence as complete but no timestamp. Having it does incur a potential for
> the timestamp to be written twice, and even for it to be corrupted if
> the u64 write is not atomic. Instead use a new bit to record the
> presence of the timestamp, and teach the readers to wait until it is set
> if the fence is complete. There still remains a race where the timestamp
> for the signaled fence may be shown before the fence is reported as
> signaled, but that's a pre-existing error.

Now deserves a
Reported-by: Rafael Antognolli <rafael.antognolli@intel.com>

> Signed-off-by: Chris Wilson <chris@chris-wilson.co.uk>
> Cc: Sumit Semwal <sumit.semwal@linaro.org>
> Cc: Gustavo Padovan <gustavo@padovan.org>
> Cc: Daniel Vetter <daniel.vetter@intel.com>
Cc: Rafael Antognolli <rafael.antognolli@intel.com>

> ---
>  drivers/dma-buf/dma-fence.c  | 17 ++++++-----------
>  drivers/dma-buf/sync_debug.c |  2 +-
>  drivers/dma-buf/sync_file.c  |  8 +++++++-
>  include/linux/dma-fence.h    |  2 ++
>  4 files changed, 16 insertions(+), 13 deletions(-)
> 
> diff --git a/drivers/dma-buf/dma-fence.c b/drivers/dma-buf/dma-fence.c
> index d1f1f456f5c4..dd2d7b6d2831 100644
> --- a/drivers/dma-buf/dma-fence.c
> +++ b/drivers/dma-buf/dma-fence.c
> @@ -74,11 +74,6 @@ int dma_fence_signal_locked(struct dma_fence *fence)
>         if (WARN_ON(!fence))
>                 return -EINVAL;
>  
> -       if (!ktime_to_ns(fence->timestamp)) {
> -               fence->timestamp = ktime_get();
> -               smp_mb__before_atomic();
> -       }
> -
>         if (test_and_set_bit(DMA_FENCE_FLAG_SIGNALED_BIT, &fence->flags)) {
>                 ret = -EINVAL;
>  
> @@ -86,8 +81,11 @@ int dma_fence_signal_locked(struct dma_fence *fence)
>                  * we might have raced with the unlocked dma_fence_signal,
>                  * still run through all callbacks
>                  */
> -       } else
> +       } else {
> +               fence->timestamp = ktime_get();
> +               set_bit(DMA_FENCE_FLAG_TIMESTAMP_BIT, &fence->flags);
>                 trace_dma_fence_signaled(fence);
> +       }
>  
>         list_for_each_entry_safe(cur, tmp, &fence->cb_list, node) {
>                 list_del_init(&cur->node);
> @@ -114,14 +112,11 @@ int dma_fence_signal(struct dma_fence *fence)
>         if (!fence)
>                 return -EINVAL;
>  
> -       if (!ktime_to_ns(fence->timestamp)) {
> -               fence->timestamp = ktime_get();
> -               smp_mb__before_atomic();
> -       }
> -
>         if (test_and_set_bit(DMA_FENCE_FLAG_SIGNALED_BIT, &fence->flags))
>                 return -EINVAL;
>  
> +       fence->timestamp = ktime_get();
> +       set_bit(DMA_FENCE_FLAG_TIMESTAMP_BIT, &fence->flags);
>         trace_dma_fence_signaled(fence);
>  
>         if (test_bit(DMA_FENCE_FLAG_ENABLE_SIGNAL_BIT, &fence->flags)) {
> diff --git a/drivers/dma-buf/sync_debug.c b/drivers/dma-buf/sync_debug.c
> index c769dc653b34..bfead12390f2 100644
> --- a/drivers/dma-buf/sync_debug.c
> +++ b/drivers/dma-buf/sync_debug.c
> @@ -84,7 +84,7 @@ static void sync_print_fence(struct seq_file *s,
>                    show ? "_" : "",
>                    sync_status_str(status));
>  
> -       if (status) {
> +       if (test_bit(DMA_FENCE_FLAG_TIMESTAMP_BIT, &fence->flags)) {
>                 struct timespec64 ts64 =
>                         ktime_to_timespec64(fence->timestamp);
>  
> diff --git a/drivers/dma-buf/sync_file.c b/drivers/dma-buf/sync_file.c
> index 2321035f6204..95f259b719fc 100644
> --- a/drivers/dma-buf/sync_file.c
> +++ b/drivers/dma-buf/sync_file.c
> @@ -375,7 +375,13 @@ static void sync_fill_fence_info(struct dma_fence *fence,
>                 sizeof(info->driver_name));
>  
>         info->status = dma_fence_get_status(fence);
> -       info->timestamp_ns = ktime_to_ns(fence->timestamp);
> +       while (test_bit(DMA_FENCE_FLAG_SIGNALED_BIT, &fence->flags) &&
> +              !test_bit(DMA_FENCE_FLAG_TIMESTAMP_BIT, &fence->flags))
> +               cpu_relax();
> +       info->timestamp_ns =
> +               test_bit(DMA_FENCE_FLAG_TIMESTAMP_BIT, &fence->flags) ?
> +               ktime_to_ns(fence->timestamp) :
> +               ktime_set(0, 0);
>  }
>  
>  static long sync_file_ioctl_fence_info(struct sync_file *sync_file,
> diff --git a/include/linux/dma-fence.h b/include/linux/dma-fence.h
> index 6048fa404e57..c3969e8b112a 100644
> --- a/include/linux/dma-fence.h
> +++ b/include/linux/dma-fence.h
> @@ -55,6 +55,7 @@ struct dma_fence_cb;
>   * of the time.
>   *
>   * DMA_FENCE_FLAG_SIGNALED_BIT - fence is already signaled
> + * DMA_FENCE_FLAG_TIMESTAMP_BIT - timestamp recorded for fence signaling
>   * DMA_FENCE_FLAG_ENABLE_SIGNAL_BIT - enable_signaling might have been called
>   * DMA_FENCE_FLAG_USER_BITS - start of the unused bits, can be used by the
>   * implementer of the fence for its own purposes. Can be used in different
> @@ -84,6 +85,7 @@ struct dma_fence {
>  
>  enum dma_fence_flag_bits {
>         DMA_FENCE_FLAG_SIGNALED_BIT,
> +       DMA_FENCE_FLAG_TIMESTAMP_BIT,
>         DMA_FENCE_FLAG_ENABLE_SIGNAL_BIT,
>         DMA_FENCE_FLAG_USER_BITS, /* must always be last member */
>  };
> -- 
> 2.11.0
>
Gustavo Padovan July 14, 2017, 7:20 p.m. UTC | #6
2017-07-11 Chris Wilson <chris@chris-wilson.co.uk>:

> Quoting Chris Wilson (2017-02-14 12:40:01)
> > [  236.821534] WARNING: kmemcheck: Caught 64-bit read from uninitialized memory (ffff8802538683d0)
> > [  236.828642] 420000001e7f0000000000000000000000080000000000000000000000000000
> > [  236.839543]  i i i i u u u u i i i i i i i i u u u u u u u u u u u u u u u u
> > [  236.850420]                                  ^
> > [  236.854123] RIP: 0010:[<ffffffff81396f07>]  [<ffffffff81396f07>] fence_signal+0x17/0xd0
> > [  236.861313] RSP: 0018:ffff88024acd7ba0  EFLAGS: 00010282
> > [  236.865027] RAX: ffffffff812f6a90 RBX: ffff8802527ca800 RCX: ffff880252cb30e0
> > [  236.868801] RDX: ffff88024ac5d918 RSI: ffff880252f780e0 RDI: ffff880253868380
> > [  236.872579] RBP: ffff88024acd7bc0 R08: ffff88024acd7be0 R09: 0000000000000000
> > [  236.876407] R10: 0000000000000000 R11: 0000000000000000 R12: ffff880253868380
> > [  236.880185] R13: ffff8802538684d0 R14: ffff880253868380 R15: ffff88024cd48e00
> > [  236.883983] FS:  00007f1646d1a740(0000) GS:ffff88025d000000(0000) knlGS:0000000000000000
> > [  236.890959] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> > [  236.894702] CR2: ffff880251360318 CR3: 000000024ad21000 CR4: 00000000001406f0
> > [  236.898481]  [<ffffffff8130d1ad>] i915_gem_request_retire+0x1cd/0x230
> > [  236.902439]  [<ffffffff8130e2b3>] i915_gem_request_alloc+0xa3/0x2f0
> > [  236.906435]  [<ffffffff812fb1bd>] i915_gem_do_execbuffer.isra.41+0xb6d/0x18b0
> > [  236.910434]  [<ffffffff812fc265>] i915_gem_execbuffer2+0x95/0x1e0
> > [  236.914390]  [<ffffffff812ad625>] drm_ioctl+0x1e5/0x460
> > [  236.918275]  [<ffffffff8110d4cf>] do_vfs_ioctl+0x8f/0x5c0
> > [  236.922168]  [<ffffffff8110da3c>] SyS_ioctl+0x3c/0x70
> > [  236.926090]  [<ffffffff814b7a5f>] entry_SYSCALL_64_fastpath+0x17/0x93
> > [  236.930045]  [<ffffffffffffffff>] 0xffffffffffffffff
> 
> Ah something that I didn't take into account, and indeed gives this a bit
> more urgency than I realised, is that the timestamp is exposed to
> userspace. As such we are feeding it garbage, at best.
> 
> The trivial option is just to clear it in dma_fence_init(). I still have
> the slight preference for the extra complication here (for the reader) as
> it should be quicker for the more common path of signaling the fence.
> 
> > We only set the timestamp before we mark the fence as signaled. It is
> > done before to avoid observers having a window in which they may see the
> > fence as complete but no timestamp. Having it does incur a potential for
> > the timestamp to be written twice, and even for it to be corrupted if
> > the u64 write is not atomic. Instead use a new bit to record the
> > presence of the timestamp, and teach the readers to wait until it is set
> > if the fence is complete. There still remains a race where the timestamp
> > for the signaled fence may be shown before the fence is reported as
> > signaled, but that's a pre-existing error.
> 
> Now deserves a
> Reported-by: Rafael Antognolli <rafael.antognolli@intel.com>
> 
> > Signed-off-by: Chris Wilson <chris@chris-wilson.co.uk>
> > Cc: Sumit Semwal <sumit.semwal@linaro.org>
> > Cc: Gustavo Padovan <gustavo@padovan.org>
> > Cc: Daniel Vetter <daniel.vetter@intel.com>
> Cc: Rafael Antognolli <rafael.antognolli@intel.com>
> 
> > ---
> >  drivers/dma-buf/dma-fence.c  | 17 ++++++-----------
> >  drivers/dma-buf/sync_debug.c |  2 +-
> >  drivers/dma-buf/sync_file.c  |  8 +++++++-
> >  include/linux/dma-fence.h    |  2 ++
> >  4 files changed, 16 insertions(+), 13 deletions(-)

Finally pushed this one to drm-misc-fixes. Thanks.

	Gustavo
diff mbox

Patch

diff --git a/drivers/dma-buf/dma-fence.c b/drivers/dma-buf/dma-fence.c
index d1f1f456f5c4..dd2d7b6d2831 100644
--- a/drivers/dma-buf/dma-fence.c
+++ b/drivers/dma-buf/dma-fence.c
@@ -74,11 +74,6 @@  int dma_fence_signal_locked(struct dma_fence *fence)
 	if (WARN_ON(!fence))
 		return -EINVAL;
 
-	if (!ktime_to_ns(fence->timestamp)) {
-		fence->timestamp = ktime_get();
-		smp_mb__before_atomic();
-	}
-
 	if (test_and_set_bit(DMA_FENCE_FLAG_SIGNALED_BIT, &fence->flags)) {
 		ret = -EINVAL;
 
@@ -86,8 +81,11 @@  int dma_fence_signal_locked(struct dma_fence *fence)
 		 * we might have raced with the unlocked dma_fence_signal,
 		 * still run through all callbacks
 		 */
-	} else
+	} else {
+		fence->timestamp = ktime_get();
+		set_bit(DMA_FENCE_FLAG_TIMESTAMP_BIT, &fence->flags);
 		trace_dma_fence_signaled(fence);
+	}
 
 	list_for_each_entry_safe(cur, tmp, &fence->cb_list, node) {
 		list_del_init(&cur->node);
@@ -114,14 +112,11 @@  int dma_fence_signal(struct dma_fence *fence)
 	if (!fence)
 		return -EINVAL;
 
-	if (!ktime_to_ns(fence->timestamp)) {
-		fence->timestamp = ktime_get();
-		smp_mb__before_atomic();
-	}
-
 	if (test_and_set_bit(DMA_FENCE_FLAG_SIGNALED_BIT, &fence->flags))
 		return -EINVAL;
 
+	fence->timestamp = ktime_get();
+	set_bit(DMA_FENCE_FLAG_TIMESTAMP_BIT, &fence->flags);
 	trace_dma_fence_signaled(fence);
 
 	if (test_bit(DMA_FENCE_FLAG_ENABLE_SIGNAL_BIT, &fence->flags)) {
diff --git a/drivers/dma-buf/sync_debug.c b/drivers/dma-buf/sync_debug.c
index c769dc653b34..bfead12390f2 100644
--- a/drivers/dma-buf/sync_debug.c
+++ b/drivers/dma-buf/sync_debug.c
@@ -84,7 +84,7 @@  static void sync_print_fence(struct seq_file *s,
 		   show ? "_" : "",
 		   sync_status_str(status));
 
-	if (status) {
+	if (test_bit(DMA_FENCE_FLAG_TIMESTAMP_BIT, &fence->flags)) {
 		struct timespec64 ts64 =
 			ktime_to_timespec64(fence->timestamp);
 
diff --git a/drivers/dma-buf/sync_file.c b/drivers/dma-buf/sync_file.c
index 2321035f6204..95f259b719fc 100644
--- a/drivers/dma-buf/sync_file.c
+++ b/drivers/dma-buf/sync_file.c
@@ -375,7 +375,13 @@  static void sync_fill_fence_info(struct dma_fence *fence,
 		sizeof(info->driver_name));
 
 	info->status = dma_fence_get_status(fence);
-	info->timestamp_ns = ktime_to_ns(fence->timestamp);
+	while (test_bit(DMA_FENCE_FLAG_SIGNALED_BIT, &fence->flags) &&
+	       !test_bit(DMA_FENCE_FLAG_TIMESTAMP_BIT, &fence->flags))
+		cpu_relax();
+	info->timestamp_ns =
+		test_bit(DMA_FENCE_FLAG_TIMESTAMP_BIT, &fence->flags) ?
+		ktime_to_ns(fence->timestamp) :
+		ktime_set(0, 0);
 }
 
 static long sync_file_ioctl_fence_info(struct sync_file *sync_file,
diff --git a/include/linux/dma-fence.h b/include/linux/dma-fence.h
index 6048fa404e57..c3969e8b112a 100644
--- a/include/linux/dma-fence.h
+++ b/include/linux/dma-fence.h
@@ -55,6 +55,7 @@  struct dma_fence_cb;
  * of the time.
  *
  * DMA_FENCE_FLAG_SIGNALED_BIT - fence is already signaled
+ * DMA_FENCE_FLAG_TIMESTAMP_BIT - timestamp recorded for fence signaling
  * DMA_FENCE_FLAG_ENABLE_SIGNAL_BIT - enable_signaling might have been called
  * DMA_FENCE_FLAG_USER_BITS - start of the unused bits, can be used by the
  * implementer of the fence for its own purposes. Can be used in different
@@ -84,6 +85,7 @@  struct dma_fence {
 
 enum dma_fence_flag_bits {
 	DMA_FENCE_FLAG_SIGNALED_BIT,
+	DMA_FENCE_FLAG_TIMESTAMP_BIT,
 	DMA_FENCE_FLAG_ENABLE_SIGNAL_BIT,
 	DMA_FENCE_FLAG_USER_BITS, /* must always be last member */
 };