test jiffies on ARM SMP board

test jiffies on ARM SMP board

[buyitian]

i am confused about my test. in one device driver, 
i put below code:

    printk("start to test test jiffies\n");

    local_irq_save(flags);

    jf1 = jiffies; // read jiffies first time

    // hold cpu for about 2 seconds(do some calculation)

    jf2 = jiffies; // read jiffies after 2 seconds

    local_irq_restore(flags);

    printk("jf1:%lu, jf2:%lu\n", jf1, jf2);

and the output is as below:

    <4>[  108.551124]start to test test jiffies
    <4>[  110.367604]jf1:4294948151, jf2:4294948151

the jf1 and jf2 are the same value, although they are
read between 2 seconds interval, i think this is because
i disabled local interrupt.
but the printk timestamp is from 108.551124 to 110.367604,
which is about 2 seconds. and on my platform, printk timestamp
is got from the function read_sched_clock:
   static u32 __read_mostly (*read_sched_clock)(void) = jiffy_sched_clock_read;

and function jiffy_sched_clock_read() is to read from jiffies.

it seems that the jiffies is frozen when local irq is disabled,
but after local_irq_restore(), the jiffies not only start
to run, but also recover the lost 2 seconds.

is the jiffies updated from another cpu when irq is disabled on
local cpu? 

is there some internel processor interrupt between cpu1 and cpu0
after local irq is re-enabled so that jiffies recover the lost 2 seconds? 		 	   		  

test jiffies on ARM SMP board

[Dave Hylands]

Hi,

On Wed, Feb 20, 2013 at 8:39 AM, buyitian <buyit@live.cn> wrote:
>
> i am confused about my test. in one device driver,
> i put below code:
>
>     printk("start to test test jiffies\n");
>
>     local_irq_save(flags);
>
>     jf1 = jiffies; // read jiffies first time
>
>     // hold cpu for about 2 seconds(do some calculation)
>
>     jf2 = jiffies; // read jiffies after 2 seconds
>
>     local_irq_restore(flags);
>
>     printk("jf1:%lu, jf2:%lu\n", jf1, jf2);
>
> and the output is as below:
>
>     <4>[  108.551124]start to test test jiffies
>     <4>[  110.367604]jf1:4294948151, jf2:4294948151
>
> the jf1 and jf2 are the same value, although they are
> read between 2 seconds interval, i think this is because
> i disabled local interrupt.
> but the printk timestamp is from 108.551124 to 110.367604,
> which is about 2 seconds. and on my platform, printk timestamp
> is got from the function read_sched_clock:
>    static u32 __read_mostly (*read_sched_clock)(void) =
jiffy_sched_clock_read;
>
> and function jiffy_sched_clock_read() is to read from jiffies.
>
> it seems that the jiffies is frozen when local irq is disabled,
> but after local_irq_restore(), the jiffies not only start
> to run, but also recover the lost 2 seconds.

That's correct. You disabled interrupts so the timer interrupt can't update
the jiffies. Although on an SMP system, it may be possible for that timer
irq to be serviced on a different core.

> is the jiffies updated from another cpu when irq is disabled on
> local cpu?

That's really HW/platform dependant.

Some systems only have a periodic timer which fires every N microseconds,
and if you miss an interrupt you miss a jiffy increment. Other systems have
a HW timer that has an incrementing register so that jiffies can be
recovered properly when the timer IRQ is actually serviced (because the
underlying HW timer still increments even though irqs are disabled).

--
Dave Hylands
Shuswap, BC, Canada
http://www.davehylands.com
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.kernelnewbies.org/pipermail/kernelnewbies/attachments/20130220/c97a6da4/attachment.html 

test jiffies on ARM SMP board

[anish kumar]

On Thu, 2013-02-21 at 00:39 +0800, buyitian wrote:
> i am confused about my test. in one device driver, 
> i put below code:
> 
>     printk("start to test test jiffies\n");
> 
>     local_irq_save(flags);
> 
>     jf1 = jiffies; // read jiffies first time
> 
>     // hold cpu for about 2 seconds(do some calculation)
> 
>     jf2 = jiffies; // read jiffies after 2 seconds
> 
>     local_irq_restore(flags);
> 
>     printk("jf1:%lu, jf2:%lu\n", jf1, jf2);
> 
> and the output is as below:
> 
>     <4>[  108.551124]start to test test jiffies
>     <4>[  110.367604]jf1:4294948151, jf2:4294948151
> 
> the jf1 and jf2 are the same value, although they are
> read between 2 seconds interval, i think this is because
> i disabled local interrupt.
> but the printk timestamp is from 108.551124 to 110.367604,
> which is about 2 seconds. and on my platform, printk timestamp
> is got from the function read_sched_clock:
>    static u32 __read_mostly (*read_sched_clock)(void) = jiffy_sched_clock_read;
> 
> and function jiffy_sched_clock_read() is to read from jiffies.
> 
> it seems that the jiffies is frozen when local irq is disabled,
> but after local_irq_restore(), the jiffies not only start
> to run, but also recover the lost 2 seconds.
> 
> is the jiffies updated from another cpu when irq is disabled on
> local cpu? 
> 
> is there some internel processor interrupt between cpu1 and cpu0
> after local irq is re-enabled so that jiffies recover the lost 2 seconds? 		 	   		  
I think it is because of the fact that some RTC registers keep the
elapsed time and when the irq is re-enabled the kernel reads these
registers to be in sync with time.
However I am not that sure which registers as I think that depends on
the RTC chip and chip changes based on different boards.
I hope some expert on these matters can pitch in here.
> _______________________________________________
> Kernelnewbies mailing list
> Kernelnewbies at kernelnewbies.org
> http://lists.kernelnewbies.org/mailman/listinfo/kernelnewbies

test jiffies on ARM SMP board

[anish kumar]

On Wed, 2013-02-20 at 17:30 +0000, Russell King - ARM Linux wrote:
> On Wed, Feb 20, 2013 at 10:54:41PM +0530, anish kumar wrote:
> > On Thu, 2013-02-21 at 00:39 +0800, buyitian wrote:
> > > i am confused about my test. in one device driver, 
> > > i put below code:
> > > 
> > >     printk("start to test test jiffies\n");
> > > 
> > >     local_irq_save(flags);
> > > 
> > >     jf1 = jiffies; // read jiffies first time
> > > 
> > >     // hold cpu for about 2 seconds(do some calculation)
> > > 
> > >     jf2 = jiffies; // read jiffies after 2 seconds
> > > 
> > >     local_irq_restore(flags);
> > > 
> > >     printk("jf1:%lu, jf2:%lu\n", jf1, jf2);
> > > 
> > > and the output is as below:
> > > 
> > >     <4>[  108.551124]start to test test jiffies
> > >     <4>[  110.367604]jf1:4294948151, jf2:4294948151
> > > 
> > > the jf1 and jf2 are the same value, although they are
> > > read between 2 seconds interval, i think this is because
> > > i disabled local interrupt.
> > > but the printk timestamp is from 108.551124 to 110.367604,
> > > which is about 2 seconds. and on my platform, printk timestamp
> > > is got from the function read_sched_clock:
> > >    static u32 __read_mostly (*read_sched_clock)(void) = jiffy_sched_clock_read;
> > > 
> > > and function jiffy_sched_clock_read() is to read from jiffies.
> > > 
> > > it seems that the jiffies is frozen when local irq is disabled,
> > > but after local_irq_restore(), the jiffies not only start
> > > to run, but also recover the lost 2 seconds.
> > > 
> > > is the jiffies updated from another cpu when irq is disabled on
> > > local cpu? 
> > > 
> > > is there some internel processor interrupt between cpu1 and cpu0
> > > after local irq is re-enabled so that jiffies recover the lost 2 seconds? 		 	   		  
> > I think it is because of the fact that some RTC registers keep the
> 
> The RTC has nothing to do with this.
> 
> As soon as the IRQs are allowed again (immediately after the
> local_irq_restore()) the pending interrupt - including the timer
> interrupt will be processed.
> 
> At this point, because we read the clocksource, we can see that two
> seconds have passed, and so we advance jiffies by the elapsed time.
So I understand there is some register which stores the elapsed time and
in my understanding it was RTC register which is wrong as suggested by
you.I suppose some timer register is used for this information on the
SOC.
> 
> This means printk() sees that the two seconds have passed.  But because
> you're reading from jiffies within the interrupt disabled region, that
> code can't see the missed ticks.

test jiffies on ARM SMP board

[Mandeep Sandhu]

On Wed, Feb 20, 2013 at 10:54 PM, anish kumar
<anish198519851985@gmail.com> wrote:
> On Thu, 2013-02-21 at 00:39 +0800, buyitian wrote:
>> i am confused about my test. in one device driver,
>> i put below code:
>>
>>     printk("start to test test jiffies\n");
>>
>>     local_irq_save(flags);
>>
>>     jf1 = jiffies; // read jiffies first time
>>
>>     // hold cpu for about 2 seconds(do some calculation)
>>
>>     jf2 = jiffies; // read jiffies after 2 seconds
>>
>>     local_irq_restore(flags);
>>
>>     printk("jf1:%lu, jf2:%lu\n", jf1, jf2);
>>
>> and the output is as below:
>>
>>     <4>[  108.551124]start to test test jiffies
>>     <4>[  110.367604]jf1:4294948151, jf2:4294948151
>>
>> the jf1 and jf2 are the same value, although they are
>> read between 2 seconds interval, i think this is because
>> i disabled local interrupt.
>> but the printk timestamp is from 108.551124 to 110.367604,
>> which is about 2 seconds. and on my platform, printk timestamp
>> is got from the function read_sched_clock:
>>    static u32 __read_mostly (*read_sched_clock)(void) = jiffy_sched_clock_read;
>>
>> and function jiffy_sched_clock_read() is to read from jiffies.
>>
>> it seems that the jiffies is frozen when local irq is disabled,
>> but after local_irq_restore(), the jiffies not only start
>> to run, but also recover the lost 2 seconds.
>>
>> is the jiffies updated from another cpu when irq is disabled on
>> local cpu?
>>
>> is there some internel processor interrupt between cpu1 and cpu0
>> after local irq is re-enabled so that jiffies recover the lost 2 seconds?
> I think it is because of the fact that some RTC registers keep the

RTC (real time clock) chips are not very common in embedded SoCs. So
I'm not sure if they are involved here. Eg: we work on multi-core
media SoC and it doesn't have a RTC attached (if its needed it will
have to be added as an external peripheral). The SoC does however have
a couple of different clock sources for driving CPU, media decoder
cores etc.

HTH,
-mandeep

> elapsed time and when the irq is re-enabled the kernel reads these
> registers to be in sync with time.
> However I am not that sure which registers as I think that depends on
> the RTC chip and chip changes based on different boards.
> I hope some expert on these matters can pitch in here.
>> _______________________________________________
>> Kernelnewbies mailing list
>> Kernelnewbies at kernelnewbies.org
>> http://lists.kernelnewbies.org/mailman/listinfo/kernelnewbies
>
>
>
> _______________________________________________
> Kernelnewbies mailing list
> Kernelnewbies at kernelnewbies.org
> http://lists.kernelnewbies.org/mailman/listinfo/kernelnewbies

test jiffies on ARM SMP board

[bill4carson]

On 2013?02?21? 00:39, buyitian wrote:
> i am confused about my test. in one device driver,
> i put below code:
>
>      printk("start to test test jiffies\n");
>
>      local_irq_save(flags);
>
>      jf1 = jiffies; // read jiffies first time
>
>      // hold cpu for about 2 seconds(do some calculation)
>
>      jf2 = jiffies; // read jiffies after 2 seconds
>
>      local_irq_restore(flags);
>
>      printk("jf1:%lu, jf2:%lu\n", jf1, jf2);
>
> and the output is as below:
>
>      <4>[  108.551124]start to test test jiffies
>      <4>[  110.367604]jf1:4294948151, jf2:4294948151
>
> the jf1 and jf2 are the same value, although they are
> read between 2 seconds interval, i think this is because
> i disabled local interrupt.
> but the printk timestamp is from 108.551124 to 110.367604,
> which is about 2 seconds. and on my platform, printk timestamp
> is got from the function read_sched_clock:
>     static u32 __read_mostly (*read_sched_clock)(void) = jiffy_sched_clock_read;
>
> and function jiffy_sched_clock_read() is to read from jiffies.
>
> it seems that the jiffies is frozen when local irq is disabled,
> but after local_irq_restore(), the jiffies not only start
> to run, but also recover the lost 2 seconds.
>
> is the jiffies updated from another cpu when irq is disabled on
> local cpu?
>
> is there some internel processor interrupt between cpu1 and cpu0
> after local irq is re-enabled so that jiffies recover the lost 2 seconds?


  80 /*
  81  * Event handler for periodic ticks
  82  */
  83 void tick_handle_periodic(struct clock_event_device *dev)
  84 {
  85     int cpu = smp_processor_id();
  86     ktime_t next;
  87
  88     tick_periodic(cpu);
  89
  90     if (dev->mode != CLOCK_EVT_MODE_ONESHOT)
  91         return;
  92     /*
  93      * Setup the next period for devices, which do not have
  94      * periodic mode:
  95      */
  96     next = ktime_add(dev->next_event, tick_period);
  97     for (;;) {
  98         if (!clockevents_program_event(dev, next, ktime_get()))   <--- once irq enabled, here we got -ETIME, then
  99             return;
100         /*
101          * Have to be careful here. If we're in oneshot mode,
102          * before we call tick_periodic() in a loop, we need
103          * to be sure we're using a real hardware clocksource.
104          * Otherwise we could get trapped in an infinite
105          * loop, as the tick_periodic() increments jiffies,
106          * when then will increment time, posibly causing
107          * the loop to trigger again and again.
108          */
109         if (timekeeping_valid_for_hres())
110             tick_periodic(cpu);                                  <---- here, we add missing jiffies
111         next = ktime_add(next, tick_period);
112     }
113 }



  		 	   		
> _______________________________________________
> Kernelnewbies mailing list
> Kernelnewbies at kernelnewbies.org
> http://lists.kernelnewbies.org/mailman/listinfo/kernelnewbies
>

-- 
?????????,??????????

--bill

test jiffies on ARM SMP board

[bill4carson]

On 2013?02?21? 01:30, Russell King - ARM Linux wrote:
> On Wed, Feb 20, 2013 at 10:54:41PM +0530, anish kumar wrote:
>> On Thu, 2013-02-21 at 00:39 +0800, buyitian wrote:
>>> i am confused about my test. in one device driver,
>>> i put below code:
>>>
>>>      printk("start to test test jiffies\n");
>>>
>>>      local_irq_save(flags);
>>>
>>>      jf1 = jiffies; // read jiffies first time
>>>
>>>      // hold cpu for about 2 seconds(do some calculation)
>>>
>>>      jf2 = jiffies; // read jiffies after 2 seconds
>>>
>>>      local_irq_restore(flags);
>>>
>>>      printk("jf1:%lu, jf2:%lu\n", jf1, jf2);
>>>
>>> and the output is as below:
>>>
>>>      <4>[  108.551124]start to test test jiffies
>>>      <4>[  110.367604]jf1:4294948151, jf2:4294948151
>>>
>>> the jf1 and jf2 are the same value, although they are
>>> read between 2 seconds interval, i think this is because
>>> i disabled local interrupt.
>>> but the printk timestamp is from 108.551124 to 110.367604,
>>> which is about 2 seconds. and on my platform, printk timestamp
>>> is got from the function read_sched_clock:
>>>     static u32 __read_mostly (*read_sched_clock)(void) = jiffy_sched_clock_read;
>>>
>>> and function jiffy_sched_clock_read() is to read from jiffies.
>>>
>>> it seems that the jiffies is frozen when local irq is disabled,
>>> but after local_irq_restore(), the jiffies not only start
>>> to run, but also recover the lost 2 seconds.
>>>
>>> is the jiffies updated from another cpu when irq is disabled on
>>> local cpu?
>>>
>>> is there some internel processor interrupt between cpu1 and cpu0
>>> after local irq is re-enabled so that jiffies recover the lost 2 seconds? 		 	   		
>> I think it is because of the fact that some RTC registers keep the
>
> The RTC has nothing to do with this.
>
> As soon as the IRQs are allowed again (immediately after the
> local_irq_restore()) the pending interrupt - including the timer
> interrupt will be processed.
>
> At this point, because we read the clocksource, we can see that two
> seconds have passed, and so we advance jiffies by the elapsed time.

  80 /*
  81  * Event handler for periodic ticks
  82  */
  83 void tick_handle_periodic(struct clock_event_device *dev)
  84 {
  85     int cpu = smp_processor_id();
  86     ktime_t next;
  87
  88     tick_periodic(cpu);
  89
  90     if (dev->mode != CLOCK_EVT_MODE_ONESHOT)
  91         return;
  92     /*
  93      * Setup the next period for devices, which do not have
  94      * periodic mode:
  95      */
  96     next = ktime_add(dev->next_event, tick_period);
  97     for (;;) {
  98         if (!clockevents_program_event(dev, next, ktime_get()))   <--- once irq enabled, here we got -ETIME, then
  99             return;
100         /*
101          * Have to be careful here. If we're in oneshot mode,
102          * before we call tick_periodic() in a loop, we need
103          * to be sure we're using a real hardware clocksource.
104          * Otherwise we could get trapped in an infinite
105          * loop, as the tick_periodic() increments jiffies,
106          * when then will increment time, posibly causing
107          * the loop to trigger again and again.
108          */
109         if (timekeeping_valid_for_hres())
110             tick_periodic(cpu);                                  <---- here, we add missing jiffies
111         next = ktime_add(next, tick_period);
112     }
113 }


>
> This means printk() sees that the two seconds have passed.  But because
> you're reading from jiffies within the interrupt disabled region, that
> code can't see the missed ticks.
>
> _______________________________________________
> linux-arm-kernel mailing list
> linux-arm-kernel at lists.infradead.org
> http://lists.infradead.org/mailman/listinfo/linux-arm-kernel
>

-- 
?????????,??????????

--bill