Software Tuning, Performance Optimization & Platform Monitoring
Discussion regarding monitoring and software tuning methodologies, Performance Monitoring Unit (PMU) of Intel microprocessors, and platform updating.

Strange behaviour of Intel Xeon E3-1220v2

Tommy_F_
Beginner
1,319 Views

Hi All

I have bought Intel Xeon E3-1220 v2 processor.

I am testing Linux on this processor. I created a test to see the time it takes for the OS to handle the clock tick.

My test is as following: I create a thread with highest priority ( can be preempted only by interrupts), whose task is just to do a small calculation in a loop of 45000 times. Here is the code:

long LoopCounter = 45000; 

while ( lLoopCounter > 0 )

   {

   Value =  (( Value * 3 ) + 5);

      lLoopCounter--;

   }

This task takes 102 µs to be finished.

If a clock tick happens while the task is executing, then this task is interrupted for some time until the interrupt is handled. ( aka: in normal case, the task takes 112 µs and if a tick happens, then the task takes 120 µs, which means that 8 µs are spent by the OS to handle the clock tick interrupt). I did this procedure around 100 times and I saw that each 1 ms I got a clock interrupt as the OS clock tick is running at 1000 Hz. so the normal values should be 102 µs if no tick happens, and 110µs if a clock tick happens.

This was perfect test on Intel core i7-930 @2.8GHz.

If I do the test on processor Xeon E3-1220 v2 @ 3.1 GHz, the task takes shorter time ( 102 µs) as it is faster processor. it takes 110 µs if a tick happens.

The strange thing I see on this processor that sometimes I get values around 120 µs, which means that some kind of interrupt happened and preempted the task for 18 µs. If it was clock tick, then it should take 110 µs.

so the processor is generating some kind of interrupts.

If I do the test with loop of 5000 instead of 45000, I do not see anymore such strange values.

 

Synthesis: if I do a task which is looping 45000 times on intel xeon, I start to get strange interrupts, which is not the case on i7-930.

If I do the test with loop of 5000, the interrupts disappear.

what could be the issue?

 

Regards

0 Kudos
31 Replies
Bernard
Valued Contributor I
275 Views

IF the only interrupt is clock onterrupt so how do you know that other interrupt is preempting your task.I think that your task is preempted maybe by some kernel code like scheduler.

0 Kudos
Tommy_F_
Beginner
275 Views

In the beginning of the discussion, I attached a word document which shows how do i know that my task is preempted.

please give it a look.

0 Kudos
Bernard
Valued Contributor I
275 Views

At the beginning of the discussion I did not read word document.Sorry:)

After reading your document I tend to agree that the source of interrupt is not from external device and it is more related to internal behaviour of processor. Here I would like to advise running tests with VTune.

0 Kudos
Tommy_F_
Beginner
275 Views

Thanks iliya

I never used VTune tool, but i will see if it helps. My question was if you have any clue what could be the reason for such strange behaviour. what could be the processor doing?

0 Kudos
Patrick_F_Intel1
Employee
275 Views

Hello Tommy,

VTune may not be very useful in this case. The reason is that Tommy needs to profile interrupts. When an interrupt starts, it disables interrupts so the interrupt doesn't get interrupted. VTune gets its samples by (you guessed it) an interrupt. So the Tommy's region of interest can effectively be hidden from VTune. There is a way around this using PEBS events.

But a second problem remains. The 'thing' that Tommy wants to debug is a relatively rare and short event (once per ms or less lasting for a maybe dozens of microseconds). VTune works best when you can get lots of samples. If you have to increase the frequency of VTune sampling to more than 1 sample per ms you can start to impact the application you are measuring. In this case, with just a microkernel test case, that might not be too bad. But you will be introducing more interrupts, that is how VTune gets a sample.

I'd really recommend a linux kernel trace such as ftrace to see each and every interrupt, context switch, etc. This will tell you exactly what is going on.

Have you already tried linux kernel tracing Tommy?

Pat

0 Kudos
Bernard
Valued Contributor I
275 Views

Sorry Tommy  for beign unable to help you more.My knowledge of Linux internals and its troubleshooting tools is very limited.

Pat can be more helpful in your case.

If you had been using Windows I would recommend you using Xperf to investigate your issue.This tool can track various interrupts and its handler routines and display load breakdown in nice graphical UI.In your case as Pat said  you must to get more clearer picture of interrupt activity on your system.

0 Kudos
Tommy_F_
Beginner
275 Views

Hi Patrick

The problem is that the Linux that i am testing is a leight one, so it just has the minimal component ( no network,...) to be sure that none of these component interrupt the performance.

I will try my tests on normal ubuntu, and see if i get the strange interrupts. Then I will use the ftrace to detect what is happening.

I will inform you by Tuesday.

Thanks for your support.

I have a question apart from that. Do you have any image which shows clearly how the caches are connected via buses between themselves and between the memory.

Another question: what is the reason that intel vt-d is just used for fully virtualized VMs and not for para-virtualized VMs in case of PCI-passthrough.

Regards

0 Kudos
Patrick_F_Intel1
Employee
275 Views

Kernel tracing is built in to most recent kernels (but not for some special cases... your kernel may be a special case).

Here is a 10 sec overview.

May need: mount -t debugfs none /sys/kernel/debug/
If above fails and /sys/kernel/debug doesn't exist, you don't have tracing on your box.

I use trace-cmd front-end to ftrace facility. Get it: ‘git clone http://git.kernel.org/?p=linux/kernel/git/rostedt/trace-cmd.git

Or git clone http://git.kernel.org/pub/scm/linux/kernel/git/rostedt/trace-cmd.git

Do ‘make’ to build it. Don’t build/install documentation. Maybe docs install now but it didn't work for me last year.
See ‘trace-cmd -h’ . List events: trace-cmd list
Record a trace: trace-cmd record -e all -b 10240
Convert binary trace to text: trace-cmd report -i trace.dat

Here is a code snippet I use to put a marker in the trace file to mark the start and end of the region I care about... the trace files can be huge so this cuts down how much you need to dig through.

static char marker_file[]={"/sys/kernel/debug/tracing/trace_marker"};
int trace_write_marker(char *str)
{
#ifdef __linux__
 FILE * fmarker = fopen(marker_file, "w");
 if (!fmarker)
 {
  printf("Open failed for tracing marker file: %s. Tracing will not be used.\n", marker_file);
  return -1;
 }
 fputs(str, fmarker);
 fclose(fmarker);
 return 0;
#endif
 return -1;
}

I have no images for how the caches are connected and I don't know much of anything about virtual VMs.

Sorry

Pat

0 Kudos
SergeyKostrov
Valued Contributor II
275 Views
Patrick, The piece of codes you've provided could Not be used in a really time critical environment to do very accurate tracing since every time when trace_write_marker function is called it opens a file, then writes something into it and closes the file. Every time it happens again, and again, and again. In order to do a similar tracing with a couple of tens of nano-seconds accuracy I use In-Memory Based tracing. It means, that I pre-allocated a buffer for some large structure with a small record size ( it could hold up to a million records ) and after all measurements are completed the application stores that structure into a file.
0 Kudos
Patrick_F_Intel1
Employee
275 Views

I didn't really say it was the most efficient way of putting a marker in the trace. You can leave the marker file open and write multiple markers, then close it once.

But the idea is:

start trace

start tommys_timing_program

Inside tommy's program, right before the main loop, he writes a trace marker,

loop in main loop until you see the anomaly.

exit main loop

write another marker

exit tommys_program

stop trace

So, the efficiency doesn't really matter. You aren't writing markers during the timing loop. Just before it and after it.

Pat

0 Kudos
Bernard
Valued Contributor I
275 Views

Tommy,

can you dump on Linux IDT table at least you will able enumerate Interrupt registered handlers.Next I would try to put a breakpoint on those handlers.You will be able to see which ISR are executing in runtime.

0 Kudos
Reply