ck-history can take a *long* time to run, during which gdm is unusable

This was supposedly fixed by consolekit 0.3.0-2ubuntu7 by adding log rotation to the ConsoleKit history file:

consolekit (0.3.0-2ubuntu7) karmic; urgency=low

  * Install a logrotate configuration file for /var/log/ConsoleKit/history
    so that it doesn't get huge and cause ck-history to take a long while
    to run on login. ck-history already handles reading from rotated logs.

 -- James Westby Tue, 21 Jul 2009 10:41:19 +0100

We'll see if it actually addresses the issue sufficiently.

Reopening bug. Even with the logrotate file in place, and having verified that log rotation *has* occurred
ck-history still takes a prohibitively long time to run.

Indeed, now that some of the history is gzipped, ck-history is now up from taking 20 seconds to taking 40 seconds!

I have now realized that the reason one of my machines is so severely affected is because it has frequent cronjobs, causing the history to be extremely extensive.

I would like to propose that calling ck-history at all is rather unnecessary in the case of an average home user's desktop, where the number of non-system accounts will be very small.

I finally tried to figure out why gdm took so long to present the users names (30 seconds or more sometimes) and came across this bug. I'm going to add the regression-potential tag, since this is clearly a regression over Jaunty's login process.

$ ls -l /var/log/ConsoleKit/
total 6504
-rw-r--r-- 1 root root 108162 2009-08-16 18:30 history
-rw-r--r-- 1 root root 1795276 2009-08-16 08:35 history.1
-rw-r--r-- 1 root root 4740977 2009-08-09 22:50 history.2.gz

$ time ck-history

real 0m30.882s
user 0m30.654s
sys 0m0.220s

$ dpkg -l|egrep '(consolekit|gdm)'
ii consolekit 0.3.1-0ubuntu1 framework for defining and tracking users, s
ii gdm 2.27.4-0ubuntu11 GNOME Display Manager

I'm going to up the priority to Medium. While many average desktop users may not have cron jobs that make consolekit's history large, I daresay there is a significant percentage that do. This bug gets to be highly annoying fast for those users. Feel free to adjust the priority as necessary.

I'd like to reiterate that whilst waiting for ck-history, gdm does not even allow you to log in with a typed-in username. Which is kind of a separate bug, but not really entirely since if this delay wasn't there, you'd never notice.

This is a duplicate of bug #287715, whose root cause has been resolved; ck-history will be much faster once the old, cluttered history logs have rotated off.

There *should* be an option to disable the facebrowser - users are not enumerable in all contexts - but that's a separate bug.

did that change recently in karmic? when we looked at it at the distro sprint the rotation was not having any effect since the ck-history command look at all the files in the directory including the ones rotated and gziped

Bug 423450 is to have the user detection in the GDM server thus this delay would only be caused once.

Robert Ancell wrote:
> Bug 423450 is to have the user detection in the GDM server thus this
> delay would only be caused once.
>
Regardless, please could you provide a reference to the analysis of the
fastest we can get GDM up and running? I don't mind if remote user id's
are populated later dynamically, but local accounts should be available
immediately.

Mark

I've made a patch that caches the result of ck-history so there is no delay on startup (patch also upstream):
lp:~ubuntu-desktop/gdm/ubuntu

The cached version is used on startup and then updated once ck-history completes. The information is only used for ordering the user list so out-of-date information should not cause any serious problems. The first startup will be delayed until the cache has been written to.

This should have gotten a lot better since ConsoleKit was fixed to not create and log system sessions for cron, etc. But caching the result is still nice, thanks Robert!

This bug was fixed in the package gdm - 2.27.90-0ubuntu2

---------------
gdm (2.27.90-0ubuntu2) karmic; urgency=low

  [ Robert Ancell ]
  * debian/patches/13_cache_ck_history.patch:
    - Cache result of ck-history to make startup fast (LP: #400863)

  [ Martin Pitt ]
  * Add 14_guest_session.patch: Rewrite guest session support for new gdm
    architecture. This now adds a D-BUS operation StartGuestSession(), since
    gdmflexiserver is being deprecated. (LP: #404870)

 -- Martin Pitt <email address hidden> Mon, 07 Sep 2009 18:18:15 +0200

Thanks guys, it's a very noticeable improvement!

We have a Ubuntu 10.04 LTS machine set up in vmware for serving a git repository over ssh and our Hudson instance do several polls a minute.

This is how our /var/log/ConsoleKit looks:

root@Sandbox:/var/log/ConsoleKit# ls -l
total 457424
-rw-r--r-- 1 root root 228364612 2011-02-28 14:41 history
-rw-r--r-- 1 root root 210159903 2011-02-01 08:00 history.1
-rw-r--r-- 1 root root 12436950 2011-01-01 07:45 history.2.gz
-rw-r--r-- 1 root root 10235104 2010-12-01 07:46 history.3.gz
-rw-r--r-- 1 root root 6888399 2010-11-01 07:43 history.4.gz
-rw-r--r-- 1 root root 293954 2010-10-01 07:37 history.5.gz
-rw-r--r-- 1 root root 267 2010-09-14 15:56 history.6.gz
root@Sandbox:/var/log/ConsoleKit#

This has resulted in a load over 1 for the last couple of weeks as the vmware instance primarily is at the login screen, and I've just analyzed it and found that the culprit is ck-history with 99% cpu usage.

Is there any particular reason why fancy history parsing is necessary to provide a _server_ login screen?

How do I disable this behaviour?

Thanks in advance

/Thorbjørn Ravn Andersen