Timing tests

July 19, 2006 at 6:45 pm · Filed under WSOP06-Gnome

After take many profiles with sysprof, I wanted to measure time of switching.

* Syscall times() at the function e_shell_window_switch_to_component();
fprintf() of the component switched.

* Evolution starts up. Load of the last active component (contacts).
Time of switching: user 0,200000 seg, system: 0,020000 seg

* Switch of components once. Command: Ctrl + [1,2,3,4,5]
Component_id: mail;  Time of switching: user 0,400000 seg, system: 0,020000 seg
Component_id: contacts; Time of switching: user 0,120000 seg, system: 0,000000 seg
Component_id: calendar; Time of switching: user 0,320000 seg, system: 0,020000 seg
Component_id: tasks; Time of switching: user 0,070000 seg, system: 0,000000 seg
Component_id: memos; Time of switching: user 0,080000 seg, system: 0,000000 seg

* Switch many times from memos to mail.
It takes always the same time:
Component_id: mail
Time of switching: user 0,310000 seg, system: 0,000000 seg
We see that the time is less than the first time (due to the cache…).
But the component memos takes a little more time:
Component_id: memos
Time of switching: user 0,120000 seg, system: 0,000000 seg
-> Does it depends from which component we did the swtich?
Let’s take more timings.
What happens if I switch indiscriminately from task to mail? Ah! The times are different in every execution. For example:
Firstly:
Component_id: mail
Time of switching: user 0,340000 seg, system: 0,000000 seg

Component_id: tasks
Time of switching: user 0,150000 seg, system: 0,010000 seg

Component_id: mail
Time of switching: user 0,330000 seg, system: 0,000000 seg

Component_id: tasks
Time of switching: user 0,140000 seg, system: 0,000000 seg

Component_id: mail
Time of switching: user 0,350000 seg, system: 0,000000 seg

And later, when we do a lot of swiching, time increase (both mail and task):

Component_id: mail
Time of switching: user 0,450000 seg, system: 0,010000 seg

Component_id: tasks
Time of switching: user 0,180000 seg, system: 0,000000 seg

Component_id: mail
Time of switching: user 0,460000 seg, system: 0,000000 seg

Component_id: tasks
Time of switching: user 0,240000 seg, system: 0,010000 seg

Component_id: mail
Time of switching: user 0,550000 seg, system: 0,000000 seg

Component_id: tasks
Time of switching: user 0,250000 seg, system: 0,000000 seg

Then, I tested again mail-memo switch. No more identical times (like
the first test):

Component_id: mail
Time of switching: user 0,390000 seg, system: 0,000000 seg

Component_id: memos
Time of switching: user 0,160000 seg, system: 0,000000 seg

Component_id: mail
Time of switching: user 0,430000 seg, system: 0,000000 seg

Component_id: memos
Time of switching: user 0,240000 seg, system: 0,000000 seg

Component_id: mail
Time of switching: user 0,440000 seg, system: 0,010000 seg

Component_id: memos
Time of switching: user 0,250000 seg, system: 0,000000 seg

–> Any pattern?? Don’t know…

Let’s try other tests.

I put an extra button on the ESidebar. When it’s selected, it switches 100 times to the component mail.
It’s funny; the first and the second call takes:
Time of switching: user 0,420000 seg, system: 0,050000 seg
Time of switching: user 0,320000 seg, system: 0,000000 seg
And the last call #100:
Time of switching: user 1,340000 seg, system: 0,000000 seg
Note that the time increases for each new call. WHY?

More timing tests will be needed.
And I need a trace of this time increasing too!

Permalink