strange latency problem with local_irqs_disabled in kernel mode.

[Patrick Fritzsch]

Hallo,

I have a dual core CPU, where i made a linux kernel thread, which i
wanted to run on CPU1 without interruption.
so i disabled in a critical test-section the local IRQs and made some
time accounting, to see how much time the CPU needs to do his work,
which should be always the same. i moved all processes, which are not
binded to CPU1, to CPU0 before this.
I my theory there shouldnt be any interruption of the code....so the
time needed for it should always be the same, but thats not really true.

I have this (next paragraph) in my log, where the second big number is
the amount of instructions the CPU needed to do his work (which should
always be the same). The first is the current worst number. As you can
see the actual work the CPU did is jumping around from 68719579672 to
73014444248, but those 2 numbers seem to be quite, but not 100%, stable.
I am sorry to bother you guys with this in such a loaded mailing list,
but i think i have one (or maybe more?) basic missunterstaning in this
matter (maybe in relation with the linux kernel/or in relation with the
CPU), which someone perhaps could show me. Why is this number of
instructions not always exactly the same?

=== log:
May 17 20:31:29 localhost kernel: [  647.836400] New worst 68719579672
68719579672 1
May 17 20:31:50 localhost kernel: [  669.311268] New worst 68719579672
68719477376 2
May 17 20:32:13 localhost kernel: [  692.128314] New worst 73014444664
73014444664 3
May 17 20:32:36 localhost kernel: [  714.945358] New worst 73014444664
73014444248 4
May 17 20:32:59 localhost kernel: [  737.762401] New worst 73014444664
73014444224 5
May 17 20:33:20 localhost kernel: [  759.237266] New worst 73014444664
68719476976 6
May 17 20:34:48 localhost kernel: [  780.712130] New worst 73014444664
68719476976 7
May 17 20:34:48 localhost kernel: [  802.186996] New worst 73014444664
68719476976 8
May 17 20:34:48 localhost kernel: [  823.661861] New worst 73014444664
68719476976 9
May 17 20:34:48 localhost kernel: [  846.478903] New worst 73014444664
73014444224 10
===

I have all Power Management support (acpi/apm/cpu frequency code)
disabled is my linux kernel

cat /proc/version
Linux version 2.6.15.1 (root@atknoll6) (gcc version 3.3.6 (Ubuntu
1:3.3.6-8ubuntu1)) #13 SMP Wed May 17 20:13:33 CEST 2006


Thats the code snipplet, running in a kthread binded on CPU1, creating
the logs from above:

#define RDTSC(X) __asm__ __volatile__("rdtsc":"=A" (X))
[...]
 while (err < 10)
 {
    err++;
    i=1;
    /* bad hack, that CPU0 doesnt expect CPU1 to respond to anything */
    cpu_online_map = cpumask_of_cpu(0);
    local_irq_disable();
    RDTSC(ini);
/* some work which should need always the same time */
    while(i!=0)
    {
      i++; /* always +1 until we are overflowing */
      if(i==0)
      {
        j++;
      }
    }

    RDTSC(end);
    local_irq_enable();
    cpu_online_map = tmp_cpumask;
    now = end - ini;
    if (now > worst)
    {
      worst = now;
    }
    printk("New worst %lli %lli %i %i %i\n", worst,now, j,
           my_lug_test, my_lug_test2);

  }



This is my CPU:
cat /proc/cpuinfo
processor       : 0
vendor_id       : GenuineIntel
cpu family      : 15
model           : 4
model name      : Intel(R) Pentium(R) D CPU 3.20GHz
stepping        : 4
cpu MHz         : 3192.671
cache size      : 1024 KB
[...]
which is a dual core CPU.

The full (very simple and i guess very ugly, because fast hack) module
code is uploaded here:
http://www.cip.physik.uni-muenchen.de/~fritzsch/tmp/module2.tar.gz

greetings & thx in advance for taking your time to read this and maybe
giving some advice.
patrick
-
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/