Groups | Search | Server Info | Keyboard shortcuts | Login | Register [http] [https] [nntp] [nntps]

Groups > linux.kernel > #1298200 > unrolled thread

timerfd_settime/timerfd_gettime issue ?

Back to article view | Back to linux.kernel

Contents

  timerfd_settime/timerfd_gettime issue ? Helge Deller <deller@gmx.de> - 2015-12-26 13:30 +0100
    Re: timerfd_settime/timerfd_gettime issue ? Thomas Gleixner <tglx@linutronix.de> - 2015-12-29 10:50 +0100
      Re: timerfd_settime/timerfd_gettime issue ? Helge Deller <deller@gmx.de> - 2015-12-29 21:20 +0100
        Re: timerfd_settime/timerfd_gettime issue ? Thomas Gleixner <tglx@linutronix.de> - 2015-12-30 11:00 +0100

#1298200 — timerfd_settime/timerfd_gettime issue ?

Hi Thomas,

I see a strange behavior on the parisc platform, for which I'm not sure if it's intended or
if there is a bug somewhere.

The program calls timerfd_settime() and sets a timer (e.g. sec=0, nsec=100000000).
Directly after setting the timer it calls timerfd_gettime() and receives (sec=0, nsec=103914413).
The second nsec is higher than the initial nsec value which was set.

Does timerfd_settime() maybe tries to add the initial time it takes to start the timer?
Any idea or hint?

Thanks,
Helge

Background:
I'm debugging the build-failure on debian for the liblinux-fd-perl package:
https://buildd.debian.org/status/fetch.php?pkg=liblinux-fd-perl&arch=hppa&ver=0.011-1&stamp=1443355593

Here is a log which I get from kernel after adding some printks.
The problematic line is #3. 
[  465.888000] timerfd_settime: interval (sec=0, nsec=0)         it_value (sec=0, nsec=100000000) 
[  466.196000] timerfd_settime: interval (sec=0, nsec=100000000) it_value (sec=0, nsec=100000000) 
[  466.300000] timerfd_gettime: interval (sec=0, nsec=100000000) it_value (sec=0, nsec=103914413) 
[  466.404000] timerfd_gettime: interval (sec=0, nsec=100000000) it_value (sec=0, nsec=97444552) 
[  466.508000] timerfd_gettime: interval (sec=0, nsec=100000000) it_value (sec=0, nsec=92611704) 
[  466.616000] timerfd_gettime: interval (sec=0, nsec=100000000) it_value (sec=0, nsec=87376859) 
[  466.720000] timerfd_gettime: interval (sec=0, nsec=100000000) it_value (sec=0, nsec=82538534) 
[  466.824000] timerfd_gettime: interval (sec=0, nsec=100000000) it_value (sec=0, nsec=77293289) 
[  466.928000] timerfd_gettime: interval (sec=0, nsec=100000000) it_value (sec=0, nsec=72501584) 
[  467.036000] timerfd_gettime: interval (sec=0, nsec=100000000) it_value (sec=0, nsec=67377673) 
[  467.140000] timerfd_gettime: interval (sec=0, nsec=100000000) it_value (sec=0, nsec=62631601) 
[  467.244000] timerfd_gettime: interval (sec=0, nsec=100000000) it_value (sec=0, nsec=57401824) 
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/

[toc] | [next] | [standalone]

#1298929

Helge,

On Sat, 26 Dec 2015, Helge Deller wrote:

> I see a strange behavior on the parisc platform, for which I'm not sure if
> it's intended or if there is a bug somewhere.

> The program calls timerfd_settime() and sets a timer (e.g. sec=0, nsec=100000000).
> Directly after setting the timer it calls timerfd_gettime() and receives
> (sec=0, nsec=103914413).
> The second nsec is higher than the initial nsec value which was set.
> 
> Does timerfd_settime() maybe tries to add the initial time it takes to start
> the timer?
>
> Any idea or hint?

Yes. This is a fallout from the power aware batching magic. Interesting that
nobody noticed this within 7 years.

Does the patch below fix your issue?

Thanks,

	tglx

8<----------------

diff --git a/include/linux/hrtimer.h b/include/linux/hrtimer.h
index 76dd4f0da5ca..0f4a3e8734f1 100644
--- a/include/linux/hrtimer.h
+++ b/include/linux/hrtimer.h
@@ -268,7 +268,7 @@ static inline s64 hrtimer_get_expires_ns(const struct hrtimer *timer)
 
 static inline ktime_t hrtimer_expires_remaining(const struct hrtimer *timer)
 {
-	return ktime_sub(timer->node.expires, timer->base->get_time());
+	return ktime_sub(timer->_softexpires, timer->base->get_time());
 }
 
 static inline ktime_t hrtimer_cb_get_time(struct hrtimer *timer)
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/

[toc] | [prev] | [next] | [standalone]

#1299116

On 29.12.2015 10:44, Thomas Gleixner wrote:
> On Sat, 26 Dec 2015, Helge Deller wrote:
>> I see a strange behavior on the parisc platform, for which I'm not sure if
>> it's intended or if there is a bug somewhere.
> 
>> The program calls timerfd_settime() and sets a timer (e.g. sec=0, nsec=100000000).
>> Directly after setting the timer it calls timerfd_gettime() and receives
>> (sec=0, nsec=103914413).
>> The second nsec is higher than the initial nsec value which was set.
>>
>> Does timerfd_settime() maybe tries to add the initial time it takes to start
>> the timer?
>>
>> Any idea or hint?
> 
> Yes. This is a fallout from the power aware batching magic. Interesting that
> nobody noticed this within 7 years.
> 
> Does the patch below fix your issue?

No, the patch below doesn't help.

I still see:
[  644.916000] timerfd_settime: interval (sec=0, nsec=100000000) it_value (sec=0, nsec=100000000) 
[  645.024000] timerfd_gettime: interval (sec=0, nsec=100000000) it_value (sec=0, nsec=103029949) 

Helge


> diff --git a/include/linux/hrtimer.h b/include/linux/hrtimer.h
> index 76dd4f0da5ca..0f4a3e8734f1 100644
> --- a/include/linux/hrtimer.h
> +++ b/include/linux/hrtimer.h
> @@ -268,7 +268,7 @@ static inline s64 hrtimer_get_expires_ns(const struct hrtimer *timer)
>  
>  static inline ktime_t hrtimer_expires_remaining(const struct hrtimer *timer)
>  {
> -	return ktime_sub(timer->node.expires, timer->base->get_time());
> +	return ktime_sub(timer->_softexpires, timer->base->get_time());
>  }
>  
>  static inline ktime_t hrtimer_cb_get_time(struct hrtimer *timer)

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

[toc] | [prev] | [next] | [standalone]

#1299286

On Tue, 29 Dec 2015, Helge Deller wrote:
> No, the patch below doesn't help.
> 
> I still see:
> [  644.916000] timerfd_settime: interval (sec=0, nsec=100000000) it_value (sec=0, nsec=100000000) 
> [  645.024000] timerfd_gettime: interval (sec=0, nsec=100000000) it_value (sec=0, nsec=103029949) 
> 

Right. It can't help. Sorry for the distraction.

Looking deeper I found the issue. It's caused by CONFIG_TIME_LOW_RES. See the
comment in hrtimer_start_range_ns(). We round the expiry time to the next
jiffies period to avoid short timeouts. Assuming you are running with HZ=250
this is exactly 4ms. So that's where your extra time comes from.

Not sure what to do about that.

Thanks,

	tglx






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

[toc] | [prev] | [standalone]

Back to top | Article view | linux.kernel

csiph-web