Prev: [PATCH 1/1] AGP: amd64, fix pci reference leaks
Next: [PATCH 2/3] viafb: remove unused structure member
From: Jens Axboe on 10 Sep 2009 04:00 On Thu, Sep 10 2009, Ingo Molnar wrote: > > * Jens Axboe <jens.axboe(a)oracle.com> wrote: > > > On Thu, Sep 10 2009, Jens Axboe wrote: > > > On Thu, Sep 10 2009, Peter Zijlstra wrote: > > > > On Wed, 2009-09-09 at 14:20 +0200, Jens Axboe wrote: > > > > > > > > > > One thing I also noticed is that when I have logged in, I > > > > > run xmodmap manually to load some keymappings (I always tell > > > > > myself to add this to the log in scripts, but I > > > > > suspend/resume this laptop for weeks at the time and forget > > > > > before the next boot). With the stock kernel, xmodmap will > > > > > halt X updates and take forever to run. With BFS, it > > > > > returned instantly. As I would expect. > > > > > > > > Can you provide a little more detail (I'm a xmodmap n00b), how does one > > > > run xmodmap and maybe provide your xmodmap config? > > > > > > Will do, let me get the notebook and strace time it on both bfs and > > > mainline. > > > > Here's the result of running perf stat xmodmap .xmodmap-carl on > > the notebook. I have attached the .xmodmap-carl file, it's pretty > > simple. I have also attached the output of strace -o foo -f -tt > > xmodmap .xmodmap-carl when run on 2.6.31-rc9. > > > > 2.6.31-rc9-bfs210 > > > > Performance counter stats for 'xmodmap .xmodmap-carl': > > > > 153.994976 task-clock-msecs # 0.990 CPUs (scaled from 99.86%) > > 0 context-switches # 0.000 M/sec (scaled from 99.86%) > > 0 CPU-migrations # 0.000 M/sec (scaled from 99.86%) > > 315 page-faults # 0.002 M/sec (scaled from 99.86%) > > <not counted> cycles > > <not counted> instructions > > <not counted> cache-references > > <not counted> cache-misses > > > > 0.155573406 seconds time elapsed > > (Side question: what hardware is this - why are there no hw > counters? Could you post the /proc/cpuinfo?) Sure, attached. It's a Thinkpad x60, core duo. Nothing fancy. The perf may be a bit dated. I went to try -tip btw, but it crashes on boot. Here's the backtrace, typed manually, it's crashing in queue_work_on+0x28/0x60. Call Trace: queue_work schedule_work clocksource_mark_unstable mark_tsc_unstable check_tsc_sync_source native_cpu_up relay_hotcpu_callback do_forK_idle _cpu_up cpu_up kernel_init kernel_thread_helper > > Performance counter stats for 'xmodmap .xmodmap-carl': > > > > 8.529265 task-clock-msecs # 0.001 CPUs > > 23 context-switches # 0.003 M/sec > > 1 CPU-migrations # 0.000 M/sec > > 315 page-faults # 0.037 M/sec > > <not counted> cycles > > <not counted> instructions > > <not counted> cache-references > > <not counted> cache-misses > > > > 11.804293482 seconds time elapsed > > Thanks - so we context-switch 23 times - possibly to Xorg. But 11 > seconds is extremely long. Will try to reproduce it. There's also the strace info with timings. Xorg is definitely involved, during those 11s things stop updating completely. -- Jens Axboe -- To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to majordomo(a)vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
From: Jens Axboe on 10 Sep 2009 05:50 On Thu, Sep 10 2009, Ingo Molnar wrote: > > * Jens Axboe <jens.axboe(a)oracle.com> wrote: > > > On Thu, Sep 10 2009, Peter Zijlstra wrote: > > > On Wed, 2009-09-09 at 14:20 +0200, Jens Axboe wrote: > > > > > > > > One thing I also noticed is that when I have logged in, I run xmodmap > > > > manually to load some keymappings (I always tell myself to add this to > > > > the log in scripts, but I suspend/resume this laptop for weeks at the > > > > time and forget before the next boot). With the stock kernel, xmodmap > > > > will halt X updates and take forever to run. With BFS, it returned > > > > instantly. As I would expect. > > > > > > Can you provide a little more detail (I'm a xmodmap n00b), how > > > does one run xmodmap and maybe provide your xmodmap config? > > > > Will do, let me get the notebook and strace time it on both bfs > > and mainline. > > A 'perf stat' comparison would be nice as well - that will show us > events strace doesnt show, and shows us the basic scheduler behavior > as well. > > A 'full' trace could be done as well via trace-cmd.c (attached), if > you enable: > > CONFIG_CONTEXT_SWITCH_TRACER=y > > and did something like: > > trace-cmd -s xmodmap ... > trace.txt trace.txt attached. Steven, you seem to go through a lot of trouble to find the debugfs path, yet at the very end do: > system("cat /debug/tracing/trace"); which doesn't seem quite right :-) -- Jens Axboe -- To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to majordomo(a)vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
From: Jens Axboe on 10 Sep 2009 05:50 On Wed, Sep 09 2009, Ingo Molnar wrote: > At least in my tests these latencies were mainly due to a bug in > latt.c - i've attached the fixed version. What bug? I don't see any functional change between the version you attach and the current one. -- Jens Axboe -- To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to majordomo(a)vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
From: Jens Axboe on 10 Sep 2009 05:50 On Thu, Sep 10 2009, Jens Axboe wrote: > trace.txt attached. Now it really is, I very much need a more clever MUA to help me with these things :-) -- Jens Axboe
From: Ingo Molnar on 10 Sep 2009 06:00
* Jens Axboe <jens.axboe(a)oracle.com> wrote: > On Wed, Sep 09 2009, Ingo Molnar wrote: > > At least in my tests these latencies were mainly due to a bug in > > latt.c - i've attached the fixed version. > > What bug? I don't see any functional change between the version > you attach and the current one. Here's the diff of what i fixed yesterday over the last latt.c version i found in this thread. The poll() thing is the significant one. Ingo --- latt.c.orig +++ latt.c @@ -39,6 +39,7 @@ static unsigned int verbose; struct stats { double n, mean, M2, max; + int max_pid; }; static void update_stats(struct stats *stats, unsigned long long val) @@ -85,22 +86,6 @@ static double stddev_stats(struct stats return sqrt(variance); } -/* - * The std dev of the mean is related to the std dev by: - * - * s - * s_mean = ------- - * sqrt(n) - * - */ -static double stddev_mean_stats(struct stats *stats) -{ - double variance = stats->M2 / (stats->n - 1); - double variance_mean = variance / stats->n; - - return sqrt(variance_mean); -} - struct stats delay_stats; static int pipes[MAX_CLIENTS*2][2]; @@ -212,7 +197,7 @@ static unsigned long usec_since(struct t static void log_delay(unsigned long delay) { if (verbose) { - fprintf(stderr, "log delay %8lu usec\n", delay); + fprintf(stderr, "log delay %8lu usec (pid %d)\n", delay, getpid()); fflush(stderr); } @@ -300,7 +285,7 @@ static int __write_ts(int i, struct time return write(fd, ts, sizeof(*ts)) != sizeof(*ts); } -static long __read_ts(int i, struct timespec *ts) +static long __read_ts(int i, struct timespec *ts, pid_t *cpids) { int fd = pipes[2*i+1][0]; struct timespec t; @@ -309,11 +294,14 @@ static long __read_ts(int i, struct time return -1; log_delay(usec_since(ts, &t)); + if (verbose) + fprintf(stderr, "got delay %ld from child %d [pid %d]\n", usec_since(ts, &t), i, cpids[i]); return 0; } -static int read_ts(struct pollfd *pfd, unsigned int nr, struct timespec *ts) +static int read_ts(struct pollfd *pfd, unsigned int nr, struct timespec *ts, + pid_t *cpids) { unsigned int i; @@ -322,7 +310,7 @@ static int read_ts(struct pollfd *pfd, u return -1L; if (pfd[i].revents & POLLIN) { pfd[i].events = 0; - if (__read_ts(i, &ts[i])) + if (__read_ts(i, &ts[i], cpids)) return -1L; nr--; } @@ -368,7 +356,6 @@ static void run_parent(pid_t *cpids) srand(1234); do { - unsigned long delay; unsigned pending_events; do_rand_sleep(); @@ -404,17 +391,17 @@ static void run_parent(pid_t *cpids) */ pending_events = clients; while (pending_events) { - int evts = poll(ipfd, clients, 0); + int evts = poll(ipfd, clients, -1); if (evts < 0) { do_exit = 1; break; } else if (!evts) { - /* printf("bugger2\n"); */ + printf("bugger2\n"); continue; } - if (read_ts(ipfd, evts, t1)) { + if (read_ts(ipfd, evts, t1, cpids)) { do_exit = 1; break; } -- To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to majordomo(a)vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/ |