Bug 4978

Created attachment 3722 [details]
xorg.conf

Feel free to add this as a 6.9 blocker since I'm building from CVS and can test
any patches you throw at me.

Anything that indicates where exactly the CPU time is being spent (oprofile
report, gdb backtrace, strace output, X server log file, ...) would be interesting.

Is this with a compositing manager running BTW?

I'm not too familiar with how to get any reasonable profiling. X is a rather big
beast with lots of things happening all the time. But if you give me some
pointers I can set it up for a run tonight.

The log-file doesn't show a damn thing (a diff from a "good" run is empty apart
from lines with times in them). But if you want I can attach one from the next run.

A composition manager is not running during this, but composite is enabled.

Since I use the machine during the day I only have time for one test a day. So
we need to select test scenarios carefully. :)

oprofile would be the best bet I know about. It profiles kernel and user space
and can even provide backtraces.

FWIW, someone on IRC just told me that sysprof is similar to oprofile but easier
to use...

Created attachment 3728 [details]
Xorg.log

Created attachment 3729 [details]
opreport

Created attachment 3730 [details]
opreport -l

I tried doing an strace but I had the bad judgement to do it from with the X
server. So that got X to lock up completely. Once I killed the strace the CPU
usage was gone. The oprofile was running during the problem though so it will
hopefully give something meaningful.

Please point oprofile to the vmlinux file corresponding to your kernel so it
will show where exactly in the kernel the time is spent. Also, if opreport -c
provides meaningful backtraces, they would be interesting.

Bug 4633 caused me to update to the latest CVS and during the nights run it
didn't malfunction. I'll do another test tonight but it seems as though the bug
is gone.

Created attachment 3771 [details]
opreport -g -l

It seems my oprofile skills could use some improvement. I still do not get
every symbol translated in the kernel. It seems to be satisified with the
vmlinux I gave it though since some kernel addresses get resolved.

Created attachment 3772 [details]
opreport -c

I was also able to do a strace. And it's full of these:

gettimeofday({1131692379, 591502}, NULL) = 0
gettimeofday({1131692379, 591532}, NULL) = 0
select(256, [1 3 4 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29
30 31 32 33 34 35 36 37 38 39 40 41 42 43], NULL, NULL, {167, 641000}) = 1 (in
[3], left {167, 644000})
read(3, "", 80)                         = 0
gettimeofday({1131692379, 591671}, NULL) = 0
gettimeofday({1131692379, 591701}, NULL) = 0
select(256, [1 3 4 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29
30 31 32 33 34 35 36 37 38 39 40 41 42 43], NULL, NULL, {167, 641000}) = 1 (in
[3], left {167, 644000})
read(3, "", 80)                         = 0
gettimeofday({1131692379, 591840}, NULL) = 0
gettimeofday({1131692379, 591870}, NULL) = 0
select(256, [1 3 4 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29
30 31 32 33 34 35 36 37 38 39 40 41 42 43], NULL, NULL, {167, 641000}) = 1 (in
[3], left {167, 644000})
read(3, "", 80)                         = 0
gettimeofday({1131692379, 592010}, NULL) = 0
gettimeofday({1131692379, 592040}, NULL) = 0
select(256, [1 3 4 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29
30 31 32 33 34 35 36 37 38 39 40 41 42 43], NULL, NULL, {167, 640000}) = 1 (in
[3], left {167, 640000})
read(3, "", 80)                         = 0

Occasionally also an SIGALARM:

--- SIGALRM (Alarm clock) @ 0 (0) ---
setitimer(ITIMER_REAL, {it_interval={0, 0}, it_value={0, 0}}, NULL) = 0
sigreturn()                             = ? (mask now [])
setitimer(ITIMER_REAL, {it_interval={0, 20000}, it_value={0, 20000}}, NULL) = 0

(In reply to comment #12)
> 
> It seems my oprofile skills could use some improvement. I still do not get
> every symbol translated in the kernel. It seems to be satisified with the
> vmlinux I gave it though since some kernel addresses get resolved.

Maybe you forgot to clear the previous data with opcontrol --reset before the
last profiling run? Also, it might be a good idea to compress the opreport
output before attaching it, and the opreport -c output seems useless, your
kernel probably doesn't support it.

Created attachment 3810 [details]
opreport -l

New attempt, hopefully with better information.

Created attachment 3811 [details]
opreport -c

Are you still experiencing this problem using a more current version of xorg?

No, haven't seen it for some time now.

I'm closing this one, if the problem still persists, please reopen