linux-kernel - Re: [PATCH 3/7] Add IRQ_TIME_ACCOUNTING, finer accounting of irq time -v3

lists.openwall.net		lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC
Open Source and information security mailing list archives

Hash Suite: Windows password security audit tool. GUI, reports in PDF.

[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]

Message-ID: <AANLkTikHfyjjZfDcoO-yDW+JTnpDb42VxRMckk55Xp+O@mail.gmail.com>
Date:	Thu, 30 Sep 2010 13:38:49 -0700
From:	Venkatesh Pallipadi <venki@...gle.com>
To:	Peter Zijlstra <peterz@...radead.org>
Cc:	Ingo Molnar <mingo@...e.hu>, "H. Peter Anvin" <hpa@...or.com>,
	Thomas Gleixner <tglx@...utronix.de>,
	Balbir Singh <balbir@...ux.vnet.ibm.com>,
	Martin Schwidefsky <schwidefsky@...ibm.com>,
	linux-kernel@...r.kernel.org, Paul Turner <pjt@...gle.com>,
	Eric Dumazet <eric.dumazet@...il.com>
Subject: Re: [PATCH 3/7] Add IRQ_TIME_ACCOUNTING, finer accounting of irq time -v3

On Thu, Sep 30, 2010 at 9:29 AM, Venkatesh Pallipadi <venki@...gle.com> wrote:
> On Thu, Sep 30, 2010 at 4:06 AM, Peter Zijlstra <peterz@...radead.org> wrote:
>> On Wed, 2010-09-29 at 12:21 -0700, Venkatesh Pallipadi wrote:
>>> +void account_system_vtime(struct task_struct *curr)
>>> +{
>>> +       unsigned long flags;
>>> +       int cpu;
>>> +       u64 now, delta;
>>> +
>>> +       if (!sched_clock_irqtime)
>>> +               return;
>>> +
>>> +       local_irq_save(flags);
>>> +
>>> +       now = sched_clock();
>>> +       cpu = smp_processor_id();
>>
>> Like said before, that really wants to read like:
>>
>>        cpu = smp_processor_id();
>>        now = sched_clock_cpu(cpu);
>>
>> sched_clock() is raw tsc + ns conversion and can go all over the place.
>
> sched_clock_cpu() won't really work for here, due to what looks like
> idle and timer tick dependencies. Using sched_clock_cpu(), I end up
> accounting CPU idle time to hardirq due to time captured before the
> handler and after the handler.
>

Specifically, here is the now and delta log from my test setup with
using sched_clock_cpu() above (data below from a particular CPU)

          <idle>-0     [001]  1697.910060: account_system_vtime:
SOFTIRQ STOP 1700897011613, delta 3555
          <idle>-0     [001]  1697.911047: account_system_vtime: IRQ
START 1700897999028
          <idle>-0     [001]  1697.911051: account_system_vtime:
HARDIRQ STOP 1700898005071, delta 6043
          <idle>-0     [001]  1697.911052: account_system_vtime: IRQ
START 1700898006003
          <idle>-0     [001]  1697.911057: account_system_vtime:
SOFTIRQ STOP 1700898010685, delta 4682
          <idle>-0     [001]  1697.911931: account_system_vtime: IRQ
START 1700898884039
          <idle>-0     [001]  1697.911935: account_system_vtime:
HARDIRQ STOP 1700898890304, delta 6265
          <idle>-0     [001]  1697.915040: account_system_vtime: IRQ
START 1700899887146
          <idle>-0     [001]  1697.915047: account_system_vtime:
HARDIRQ STOP 1700902008678, delta 2121532
          <idle>-0     [001]  1697.915048: account_system_vtime: IRQ
START 1700902009617
          <idle>-0     [001]  1697.915055: account_system_vtime:
SOFTIRQ STOP 1700902015924, delta 6307
          <idle>-0     [001]  1697.918958: account_system_vtime: IRQ
START 1700903006980
          <idle>-0     [001]  1697.918963: account_system_vtime:
HARDIRQ STOP 1700905931367, delta 2924387
          <idle>-0     [001]  1697.919553: account_system_vtime: IRQ
START 1700906521486
          <idle>-0     [001]  1697.919557: account_system_vtime:
HARDIRQ STOP 1700906527006, delta 5520
          <idle>-0     [001]  1697.933420: account_system_vtime: IRQ
START 1700907524219
          <idle>-0     [001]  1697.933428: account_system_vtime:
HARDIRQ STOP 1700920424020, delta 12899801
          <idle>-0     [001]  1697.936512: account_system_vtime: IRQ
START 1700921418037
          <idle>-0     [001]  1697.936523: account_system_vtime:
HARDIRQ STOP 1700923524497, delta 2106460
           <...>-13891 [001]  1697.937001: account_system_vtime: IRQ
START 1700924001105
           <...>-13891 [001]  1697.937013: account_system_vtime:
HARDIRQ STOP 1700924015861, delta 14756
           <...>-13891 [001]  1697.937015: account_system_vtime: IRQ
START 1700924017841
           <...>-13891 [001]  1697.937020: account_system_vtime:
SOFTIRQ STOP 1700924023189, delta 5348
           <...>-13891 [001]  1697.937188: account_system_vtime: IRQ
START 1700924191127
           <...>-13891 [001]  1697.937197: account_system_vtime:
HARDIRQ STOP 1700924199862, delta 8735
          <idle>-0     [001]  1697.938000: account_system_vtime: IRQ
START 1700924999818
          <idle>-0     [001]  1697.938013: account_system_vtime:
HARDIRQ STOP 1700925017573, delta 17755
          <idle>-0     [001]  1697.938015: account_system_vtime: IRQ
START 1700925019459
          <idle>-0     [001]  1697.938031: account_system_vtime:
SOFTIRQ STOP 1700925034677, delta 15218

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