Bug 753363

Summary: Console Kit Daemon slows down login, never finishes to start
Product: [Fedora] Fedora Reporter: Rudd-O DragonFear <rudd-o>
Component: systemdAssignee: systemd-maint
Status: CLOSED DUPLICATE QA Contact: Fedora Extras Quality Assurance <extras-qa>
Severity: unspecified Docs Contact:
Priority: unspecified    
Version: 16CC: johannbg, johannbg, lpoetter, metherid, mschmidt, notting, plautrba, systemd-maint
Target Milestone: ---   
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2012-02-01 01:32:39 UTC Type: ---
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Attachments:
Description Flags
SVG file showing consol-ekit-daemon-.service stuck
none
var log messages
none
debug.log (all syslogoutput) none

Description Rudd-O DragonFear 2011-11-12 01:00:40 UTC
Created attachment 533196 [details]
SVG file showing consol-ekit-daemon-.service stuck

Description of problem:

Machine starts up, then I try to log in (console or graphical).  The console login takes my username/pw quickly but then takes forever to give me a prompt, the graphical login just stays there spinning until the display manager finally displays (after a good while)

Version-Release number of selected component (if applicable):

Fedora 16, latest updates

How reproducible:

Always

Steps to Reproduce:
1. bootup
2. attempt to login
3. wait forever


Interestingly, console-kit-daemon.service appears "stuck".

how best to debug the problem?

Comment 1 Michal Schmidt 2011-11-14 13:34:11 UTC
Edit /lib/systemd/system/console-kit-daemon.service to add "--debug" to the command line of console-kit-daemon. It will make c-k-d write its debug logs to  /var/log/messages after reboot.

Comment 2 Rudd-O DragonFear 2011-11-14 21:38:48 UTC
K.

I will do that.

Comment 3 Rudd-O DragonFear 2011-11-14 22:49:44 UTC
Attached file.  I see absolutely nothing that would help me debug the problem.

Comment 4 Rudd-O DragonFear 2011-11-14 22:50:19 UTC
Created attachment 533647 [details]
var log messages

Comment 5 Michal Schmidt 2011-11-18 10:15:27 UTC
I see two weird things in the log:

Nov 14 22:39:24 karen rtkit-daemon[1787]: Warning: PolicyKit call failed: Did not receive a reply. Possible causes include: the remote application did not send a reply, the message bus security policy blocked the reply, the reply timeout expired, or the network connection was broken.
Nov 14 14:39:25 karen dbus[1772]: [system] Failed to activate service 'org.freedesktop.ConsoleKit': timed out

First, for some reason the line about rtkit-daemon seems to have a different idea about the timezone than the rest of the system.
Second, the failure to get a response from PolicyKit. If PolicyKit is not responding, then perhaps it influences ConsoleKit too.
PolicyKit is started by dbus as specified in /usr/share/dbus-1/system-services/org.freedesktop.PolicyKit1.service:
  Exec=/usr/libexec/polkit-1/polkitd --no-debug
Try deleting that "--no-debug".

And this is unfortunate:
Nov 14 14:39:25 karen rsyslogd-2177: imuxsock lost 100 messages from pid 1823 due to rate-limiting

Try to configure rsyslog's imuxsock to do less rate-limiting. I don't know rsyslog well enough to tell you how.

Comment 6 Michal Schmidt 2011-11-18 10:21:33 UTC
(In reply to comment #5)
> First, for some reason the line about rtkit-daemon seems to have a different
> idea about the timezone than the rest of the system.

This is likely due to rtkit-daemon running in a chroot. rsyslog has a fix for this in its devel branches. It is unrelated to the ConsoleKit problem.

Comment 7 Jóhann B. Guðmundsson 2011-11-18 11:22:46 UTC
(In reply to comment #5)
<snip>
> Try to configure rsyslog's imuxsock to do less rate-limiting. I don't know
> rsyslog well enough to tell you how.

There are two settings that you use in rsyslog for rate limit 

$SystemLogRateLimitInterval [number]
$SystemLogRateLimitBurst [number]

First setting determines the amount of time that is being measured for rate limiting

$SystemLogRateLimitInterval

And the second defines the amount of messages, that have to occur in the time limit of SystemLogRateLimitInterval, to trigger rate limiting.

$SystemLogRateLimitBurst 

By default this is set to 

$SystemLogRateLimitInterval 5
$SystemLogRateLimitBurst 200

Which means that rate limiting will take place if a process sends more than 200 messages in 5 seconds.

Note when changing these settings you should use the upstream syslog tester which can be found in the test folder to confirm if rsyslog picked up the new values ( + it's a good way to stress-testing for your rsyslog installation ) 

Simply cd into that directory then run make syslog_caller and then

./syslog_caller -m 3000

Which will send 3000 messages in one burst ( other switches can be found in the .c file of the tool. ).

Comment 8 Rudd-O DragonFear 2011-11-18 22:06:38 UTC
OK, I have performed the two steps required of me here.  When I reboot the machine, I will collect the new info and re-upload.

Comment 9 Rudd-O DragonFear 2011-11-22 03:58:37 UTC
Created attachment 534910 [details]
debug.log (all syslogoutput)

Comment 10 Michal Schmidt 2011-12-17 00:00:06 UTC
Still a mystery. Could you try if disabling rsyslog makes the bug go away?
systemctl disable rsyslog.service

Comment 11 Jóhann B. Guðmundsson 2012-01-29 20:12:00 UTC
Is this still an issue with on a fully updated release or can this
bug be closed?

Comment 12 Rudd-O DragonFear 2012-02-01 01:32:39 UTC
This is a dupe of this:

https://bugzilla.redhat.com/show_bug.cgi?id=708866

*** This bug has been marked as a duplicate of bug 708866 ***