Bug 755135 - gnome-session spams syslog with DEBUG messages
Summary: gnome-session spams syslog with DEBUG messages
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Fedora
Classification: Fedora
Component: gnome-session
Version: 16
Hardware: x86_64
OS: Linux
unspecified
medium
Target Milestone: ---
Assignee: Ray Strode [halfline]
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2011-11-19 00:17 UTC by Ben Webb
Modified: 2012-07-12 18:54 UTC (History)
10 users (show)

Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2012-06-15 00:21:58 UTC
Type: ---
Embargoed:


Attachments (Terms of Use)


Links
System ID Private Priority Status Summary Last Updated
GNOME Bugzilla 672801 0 High RESOLVED [gdm] always starts gnome-session with debugging enabled 2020-10-06 18:00:34 UTC

Description Ben Webb 2011-11-19 00:17:29 UTC
Description of problem:
gnome-session sends a log of messages prefixed with DEBUG(+) to syslog. This seems like an odd choice for a production release.

Version-Release number of selected component (if applicable):
gnome-session-3.2.1-2.fc16.x86_64

How reproducible:
Always.

Steps to Reproduce:
1. Log in to GNOME.
  
Actual results:
/var/log/messages contains a lot of debug messages such as the following:
Nov 18 11:12:51 myhost gnome-session[1459]: DEBUG(+): Searching for 4194308 in 4194307,4194308
Nov 18 11:12:51 myhost gnome-session[1459]: DEBUG(+): Watch 1 fired, idle time = 0
Nov 18 11:12:51 myhost gnome-session[1459]: DEBUG(+): GsmPresence: setting idle: 0
Nov 18 11:12:51 myhost gnome-session[1459]: DEBUG(+): Updating ConsoleKit idle status: 0
Nov 18 11:13:04 myhost gnome-session[1459]: DEBUG(+): GdmSignalHandler: handling signal 15
Nov 18 11:13:04 myhost gnome-session[1459]: DEBUG(+): GdmSignalHandler: Found 1 callbacks
Nov 18 11:13:04 myhost gnome-session[1459]: DEBUG(+): GdmSignalHandler: running 15 handler: 0x41bf30
Nov 18 11:13:04 myhost gnome-session[1459]: DEBUG(+): Got callback for signal 15
Nov 18 11:13:04 myhost gnome-session[1459]: DEBUG(+): GsmManager: Logout called
Nov 18 11:13:04 myhost gnome-session[1459]: DEBUG(+): GsmShell: Connected to the shell
Nov 18 11:13:04 myhost gnome-session[1459]: DEBUG(+): GsmManager: requesting logout
Nov 18 11:13:04 myhost gnome-session[1459]: DEBUG(+): GsmManager: ending phase RUNNING#012

(I count 90 debug log messages from gnome-session for a single login.)

Expected results:
Much less verbose logs by default.

Comment 1 Alan Stern 2011-12-04 23:23:22 UTC
Yhis affects me as well.  And it seems to have been solved already, two years ago:

  http://web.archiveorange.com/archive/v/iRKxr60MhF8qkzSuXvpT

Why the regression in Fedora 16?

Comment 2 udo 2012-01-28 13:58:57 UTC
Same as https://bugzilla.redhat.com/show_bug.cgi?id=759737 ?
I see this too.
Got no real response nor a workaround.

Comment 3 Hugh Sparks 2012-01-30 01:44:49 UTC
Here's a simple workaround:

Create the file:

	/etc/rsyslog.d/gnome-session-log.conf

With contents:

	:programname,isequal,"gnome-session" ~

That will throw away all messages from gnome-session.

If you prefer to save the most recent messages, change the contents to:

	:programname,isequal,"gnome-session" /var/log/gnome-session.log 
	& ~

Then you'll need to create the file:

	/etc/logrotate.d/gnome-session.rotate

With contents:

	/var/log/gnome-session.log {
	    missingok
	    notifempty
	    size 200k
	    daily
	    create 0644 root root
	}

QED.

Comment 4 DaveG 2012-02-02 18:17:28 UTC
Seeing this too, so I took a quick look at the source code.

See: http://git.gnome.org/browse/gnome-session/tree/gnome-session/gdm-log.c
Commit: 51129099fd2771a3a7a57452c8dfbb2f42c9acfe
Line 76 - 86.

The routine handles log levels through a case structure but the debug case has a handy little "fix" to circumvent syslog settings when "debugging is enabled". 
I think the "if" test needs to be removed. If debugging is enabled by the administrator in the application then they should know to handle the messages in syslog. The application should not try to second guess the administrator.

Fix?
===%<---
--- gdm-log.c.orig	2012-02-02 18:03:02.329812240 +0000
+++ gdm-log.c	2012-02-02 18:03:21.423853142 +0000
@@ -74,15 +74,8 @@
                 prefix = "INFO";
                 break;
         case G_LOG_LEVEL_DEBUG:
-                /* if debug was requested then bump this up to ERROR
-                 * to ensure it is seen in a log */
-                if (syslog_levels & G_LOG_LEVEL_DEBUG) {
-                        priority = LOG_WARNING;
-                        prefix = "DEBUG(+)";
-                } else {
-                        priority = LOG_DEBUG;
-                        prefix = "DEBUG";
-                }
+                priority = LOG_DEBUG;
+                prefix = "DEBUG";
                 break;
         default:
                 priority = LOG_DEBUG;
===%<---

How the syslog_levels debug flag is being set is another matter - I'll try to track that down later.

--DaveG.

Comment 5 Alan Stern 2012-02-02 21:23:20 UTC
IMO, if G_LOG_LEVEL_DEBUG isn't set then the message shouldn't be logged at all.  And it if is set, the message should have LOG_DEBUG priority.

Still, you're right.  The real problem is that syslog_levels is set wrongly.

Comment 6 DaveG 2012-02-02 21:32:51 UTC
After looking at the source code for a while (and a few beers) I don't see (from the source code, `cat /proc/###/cmdline`) how debug is being enabled. I MUST be enabled in main(), the only call that sets debug mode in the source: The first syslog message nails that.

My F16 is an upgrade from F14 and I'm still sorting through the debris...

Question: Is this restricted to upgrades?

Nailing the issue is going to require some debug work. The command line from the process does not show any '--debug' options, but are there a GTK option to set this by default? Beyond me.

More debug and more beer required...

--DaveG.

Comment 7 udo 2012-02-03 04:04:12 UTC
Maybe related I see also Xorg being started with logverbose 7 without reason, does this have the same reason, cause or something?
I am running upgraded F16's so I cna't help with that question.

Comment 8 Hugh Sparks 2012-02-03 05:01:55 UTC
The problem occurs for me and I have a freshly installed Fedora 16.

Comment 9 David Dreggors 2012-06-08 00:37:24 UTC
I can also confirm this in Fedora 17.

This is annoying and makes it hard to actually track down REAL issues because we have to wade through tons of DEBUG messages.

Why is there no answer for this yet?

We have gone through a whole release and into yet another release and no way to get this spam removed from our logs?

Comment 10 David Dreggors 2012-06-08 00:54:11 UTC
This is a duplicate bug, while this report was opened first... bug #759737 has more info and has an external tracker link to the bugzilla.gnome.org but.

It may be better to mark this as a duplicate of #759737

Comment 11 David Dreggors 2012-06-08 21:14:07 UTC
While this is not news to Ray Stroder, it may be news for the others here...


The upstream patch to fix this issues is in according to the external bug tracker at Gnomes bugzilla:

https://bugzilla.gnome.org/show_bug.cgi?id=672801

Comment 12 David Dreggors 2012-06-08 21:17:23 UTC
Sorry, that is Ray Strode (not Stroder).

Comment 13 Fedora Update System 2012-06-08 23:10:14 UTC
gdm-3.2.1.1-10.fc16 has been submitted as an update for Fedora 16.
https://admin.fedoraproject.org/updates/gdm-3.2.1.1-10.fc16

Comment 14 Fedora Update System 2012-06-08 23:12:32 UTC
gdm-3.4.1-3.fc17 has been submitted as an update for Fedora 17.
https://admin.fedoraproject.org/updates/gdm-3.4.1-3.fc17

Comment 15 David Dreggors 2012-06-09 00:48:54 UTC
Thanks Ray!

Comment 16 Fedora Update System 2012-06-10 01:29:29 UTC
Package gdm-3.4.1-3.fc17:
* should fix your issue,
* was pushed to the Fedora 17 testing repository,
* should be available at your local mirror within two days.
Update it with:
# su -c 'yum update --enablerepo=updates-testing gdm-3.4.1-3.fc17'
as soon as you are able to.
Please go to the following url:
https://admin.fedoraproject.org/updates/FEDORA-2012-9175/gdm-3.4.1-3.fc17
then log in and leave karma (feedback).

Comment 17 David Dreggors 2012-06-10 04:04:57 UTC
Works for me, and I left Karma.

Comment 18 Fedora Update System 2012-06-15 00:21:58 UTC
gdm-3.4.1-3.fc17 has been pushed to the Fedora 17 stable repository.  If problems still persist, please make note of it in this bug report.

Comment 19 Fedora Update System 2012-07-12 18:54:47 UTC
gdm-3.2.1.1-10.fc16 has been pushed to the Fedora 16 stable repository.  If problems still persist, please make note of it in this bug report.


Note You need to log in before you can comment on or make changes to this bug.