Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

LightDM logs to /var/log rather than journal #26172

Open
lheckemann opened this issue May 28, 2017 · 13 comments
Open

LightDM logs to /var/log rather than journal #26172

lheckemann opened this issue May 28, 2017 · 13 comments
Labels
2.status: stale https://github.com/NixOS/nixpkgs/blob/master/.github/STALE-BOT.md 2.status: wait-for-upstream Waiting for upstream fix (or their other action).

Comments

@lheckemann
Copy link
Member

Issue description

When using lightdm, the X server log goes to /var/log/X.0.log and /var/log/x-0.log (the former is with timestamps, the latter without) and the display manager log goes to /var/log/lightdm.log. All of this should instead go to the journal. This seems to be hard-coded behaviour in lightdm (X server, lightdm). This makes debugging errors more difficult and inconsistent with other display managers.

Steps to reproduce

Enable and start lightdm.

Technical details

  • System: 17.03.1203.58e227052d (Gorilla)
  • Nix version: nix-env (Nix) 1.11.8
  • Nixpkgs version: "17.03.1203.58e227052d"
  • Sandboxing enabled: true
@pbogdan
Copy link
Member

pbogdan commented May 29, 2017

There is a --debug flag for lightdm which if I'm reading correctly duplicates all log messages on stderr, with that passed in I get:

$ journalctl -u display-manager
May 29 13:27:59 laptop display-manager[1171]: [+0.00s] DEBUG: Logging to /var/log/lightdm.log
May 29 13:27:59 laptop display-manager[1171]: [+0.00s] DEBUG: Starting Light Display Manager 1.22.0, UID=0 PID=1171
May 29 13:27:59 laptop display-manager[1171]: [+0.00s] DEBUG: Loading configuration dirs from /usr/share/lightdm/lightd
May 29 13:27:59 laptop display-manager[1171]: [+0.00s] DEBUG: Loading configuration dirs from /usr/local/share/lightdm/
May 29 13:27:59 laptop display-manager[1171]: [+0.00s] DEBUG: Loading configuration dirs from /etc/xdg/lightdm/lightdm.
May 29 13:27:59 laptop display-manager[1171]: [+0.00s] DEBUG: Loading configuration from /etc/lightdm/lightdm.conf
May 29 13:27:59 laptop display-manager[1171]: [+0.00s] DEBUG: Registered seat module local
May 29 13:27:59 laptop display-manager[1171]: [+0.00s] DEBUG: Registered seat module xremote
May 29 13:27:59 laptop display-manager[1171]: [+0.00s] DEBUG: Registered seat module unity
May 29 13:27:59 laptop display-manager[1171]: [+0.00s] DEBUG: Using D-Bus name org.freedesktop.DisplayManager
May 29 13:27:59 laptop display-manager[1171]: [+0.01s] DEBUG: Monitoring logind for seats
May 29 13:27:59 laptop display-manager[1171]: [+0.01s] DEBUG: New seat added from logind: seat0
May 29 13:27:59 laptop display-manager[1171]: [+0.01s] DEBUG: Seat seat0: Loading properties from config section Seat:*
May 29 13:27:59 laptop display-manager[1171]: [+0.01s] DEBUG: Seat seat0: Starting
May 29 13:27:59 laptop display-manager[1171]: [+0.01s] DEBUG: Seat seat0: Creating greeter session
May 29 13:27:59 laptop display-manager[1171]: [+0.01s] DEBUG: Seat seat0: Creating display server of type x
May 29 13:27:59 laptop display-manager[1171]: [+0.01s] DEBUG: Could not run plymouth --ping: Failed to execute child pr
May 29 13:27:59 laptop display-manager[1171]: [+0.01s] DEBUG: Using VT 7
May 29 13:27:59 laptop display-manager[1171]: [+0.01s] DEBUG: Seat seat0: Starting local X display on VT 7
May 29 13:27:59 laptop display-manager[1171]: [+0.01s] DEBUG: XServer 0: Logging to /var/log/x-0.log
May 29 13:27:59 laptop display-manager[1171]: [+0.01s] DEBUG: XServer 0: Writing X server authority to /run/root/:0
May 29 13:27:59 laptop display-manager[1171]: [+0.01s] DEBUG: XServer 0: Launching X Server
May 29 13:27:59 laptop display-manager[1171]: [+0.01s] DEBUG: Launching process 1179: /nix/store/f5pmddlpdya382wr3pfafd
May 29 13:27:59 laptop display-manager[1171]: [+0.01s] DEBUG: XServer 0: Waiting for ready signal from X server :0
May 29 13:27:59 laptop display-manager[1171]: [+0.01s] DEBUG: Acquired bus name org.freedesktop.DisplayManager
May 29 13:27:59 laptop display-manager[1171]: [+0.01s] DEBUG: Registering seat with bus path /org/freedesktop/DisplayMa
May 29 13:27:59 laptop display-manager[1171]: [+0.09s] DEBUG: Loading users from org.freedesktop.Accounts
May 29 13:27:59 laptop display-manager[1171]: [+0.10s] DEBUG: User /org/freedesktop/Accounts/User1000 added
May 29 13:27:59 laptop display-manager[1171]: [+0.10s] WARNING: Could not delete unused user data directory /var/lib/li
May 29 13:27:59 laptop display-manager[1171]: [+0.10s] WARNING: Could not delete unused user data directory /var/lib/li
May 29 13:27:59 laptop display-manager[1171]: [+0.11s] WARNING: Could not delete unused user data directory /var/lib/li
May 29 13:27:59 laptop display-manager[1171]: [+0.11s] WARNING: Could not delete unused user data directory /var/lib/li
May 29 13:27:59 laptop display-manager[1171]: [+0.11s] WARNING: Could not delete unused user data directory /var/lib/li
May 29 13:27:59 laptop display-manager[1171]: [+0.11s] WARNING: Could not delete unused user data directory /var/lib/li
May 29 13:27:59 laptop display-manager[1171]: [+0.11s] WARNING: Could not delete unused user data directory /var/lib/li
May 29 13:27:59 laptop display-manager[1171]: [+0.58s] DEBUG: Got signal 10 from process 1179
May 29 13:27:59 laptop display-manager[1171]: [+0.58s] DEBUG: XServer 0: Got signal from X server :0
May 29 13:27:59 laptop display-manager[1171]: [+0.58s] DEBUG: XServer 0: Connecting to XServer :0
May 29 13:27:59 laptop display-manager[1171]: [+0.58s] CRITICAL: g_object_unref: assertion 'G_IS_OBJECT (object)' faile
May 29 13:27:59 laptop display-manager[1171]: [+0.58s] DEBUG: Seat seat0: Display server ready, starting session authen
May 29 13:27:59 laptop display-manager[1171]: [+0.58s] DEBUG: Session pid=1397: Started with service 'lightdm-greeter',
May 29 13:27:59 laptop display-manager[1171]: [+0.60s] DEBUG: Session pid=1397: Authentication complete with return val
May 29 13:27:59 laptop display-manager[1171]: [+0.60s] DEBUG: Seat seat0: Session authenticated, running command
May 29 13:27:59 laptop display-manager[1171]: [+0.60s] DEBUG: Session pid=1397: Running command /nix/store/li3kfdv3yfsp
May 29 13:27:59 laptop display-manager[1171]: [+0.60s] DEBUG: Creating shared data directory /var/lib/lightdm-data/ligh
May 29 13:27:59 laptop display-manager[1171]: [+0.60s] DEBUG: Session pid=1397: Logging to /var/log/seat0-greeter.log
May 29 13:27:59 laptop lightdm[1397]: pam_unix(lightdm-greeter:session): session opened for user lightdm by (uid=0)
May 29 13:28:00 laptop display-manager[1171]: [+0.91s] DEBUG: Activating VT 7
May 29 13:28:00 laptop display-manager[1171]: [+0.91s] DEBUG: Activating login1 session c1
May 29 13:28:00 laptop display-manager[1171]: [+1.08s] DEBUG: Greeter connected version=1.22.0 api=1 resettable=false
May 29 13:28:01 laptop display-manager[1171]: [+1.87s] DEBUG: Greeter start authentication for pbogdan
May 29 13:28:01 laptop display-manager[1171]: [+1.87s] DEBUG: Session pid=1621: Started with service 'lightdm', usernam
May 29 13:28:01 laptop display-manager[1171]: [+1.88s] DEBUG: Session pid=1621: Got 1 message(s) from PAM
May 29 13:28:01 laptop display-manager[1171]: [+1.88s] DEBUG: Prompt greeter with 1 message(s)
May 29 13:28:02 laptop display-manager[1171]: [+3.42s] DEBUG: Continue authentication
May 29 13:28:02 laptop display-manager[1171]: [+3.44s] DEBUG: Session pid=1621: Authentication complete with return val
May 29 13:28:02 laptop display-manager[1171]: [+3.44s] DEBUG: Authenticate result for user pbogdan: Success
May 29 13:28:02 laptop display-manager[1171]: [+3.44s] DEBUG: User pbogdan authorized
May 29 13:28:02 laptop display-manager[1171]: [+3.46s] DEBUG: Greeter sets language en_GB.utf8
May 29 13:28:02 laptop display-manager[1171]: [+3.56s] DEBUG: Greeter requests session none+xmonad
May 29 13:28:02 laptop display-manager[1171]: [+3.56s] DEBUG: Seat seat0: Stopping greeter; display server will be re-u
May 29 13:28:02 laptop display-manager[1171]: [+3.56s] DEBUG: Terminating login1 session c1
May 29 13:28:02 laptop display-manager[1171]: [+3.56s] DEBUG: Session pid=1397: Sending SIGTERM
May 29 13:28:02 laptop display-manager[1171]: [+3.58s] DEBUG: Greeter closed communication channel
May 29 13:28:02 laptop display-manager[1171]: [+3.58s] DEBUG: Session pid=1397: Exited with return value 0
May 29 13:28:02 laptop display-manager[1171]: [+3.58s] DEBUG: Seat seat0: Session stopped
May 29 13:28:02 laptop display-manager[1171]: [+3.58s] DEBUG: Seat seat0: Greeter stopped, running session
May 29 13:28:02 laptop display-manager[1171]: [+3.58s] DEBUG: Registering session with bus path /org/freedesktop/Displa
May 29 13:28:02 laptop display-manager[1171]: [+3.58s] CRITICAL: g_object_unref: assertion 'G_IS_OBJECT (object)' faile
May 29 13:28:02 laptop display-manager[1171]: [+3.58s] DEBUG: Session pid=1621: Running command /nix/store/bywkls5bii13
May 29 13:28:02 laptop display-manager[1171]: [+3.58s] DEBUG: Creating shared data directory /var/lib/lightdm-data/pbog
May 29 13:28:02 laptop display-manager[1171]: [+3.58s] DEBUG: Session pid=1621: Logging to .xsession-errors
May 29 13:28:02 laptop lightdm[1621]: pam_unix(lightdm:session): session opened for user pbogdan by (uid=0)
May 29 13:28:04 laptop display-manager[1171]: [+5.38s] DEBUG: Activating VT 7
May 29 13:28:04 laptop display-manager[1171]: [+5.38s] DEBUG: Activating login1 session 2

I don't however see what can be done about the output of the X server :-(.

@pbogdan
Copy link
Member

pbogdan commented May 29, 2017

It ain't pretty but hey it works 😄

diff --git a/nixos/modules/services/x11/display-managers/lightdm.nix b/nixos/modules/services/x11/display-managers/lightdm.nix
index 256bfb9ce3..57a6de5e3c 100644
--- a/nixos/modules/services/x11/display-managers/lightdm.nix
+++ b/nixos/modules/services/x11/display-managers/lightdm.nix
@@ -19,11 +19,11 @@ let
 
       display=$(echo "$@" | xargs -n 1 | grep -P ^:\\d\$ | head -n 1 | sed s/^://)
       if [ -z "$display" ]
-      then additionalArgs=":0 -logfile /var/log/X.0.log"
-      else additionalArgs="-logfile /var/log/X.$display.log"
+      then additionalArgs=":0 -logfile /dev/null"
+      else additionalArgs="-logfile /dev/null"
       fi
 
-      exec ${dmcfg.xserverBin} ${toString dmcfg.xserverArgs} $additionalArgs "$@"
+      exec systemd-cat ${dmcfg.xserverBin} ${toString dmcfg.xserverArgs} $additionalArgs "$@"
     '';
 
   usersConf = writeText "users.conf"
@@ -195,7 +195,7 @@ in
       # lightdm relaunches itself via just `lightdm`, so needs to be on the PATH
       execCmd = ''
         export PATH=${lightdm}/sbin:$PATH
-        exec ${lightdm}/sbin/lightdm --log-dir=/var/log --run-dir=/run
+        exec ${lightdm}/sbin/lightdm --log-dir=/var/log --run-dir=/run --debug
       '';
     };
$ journalctl -u display-manager
May 29 13:46:50 laptop X[1176]: X.Org X Server 1.19.3
May 29 13:46:50 laptop X[1176]: Release Date: 2017-03-15
May 29 13:46:50 laptop X[1176]: X Protocol Version 11, Revision 0
May 29 13:46:50 laptop X[1176]: Build Operating System: Linux 4.4.45 x86_64
May 29 13:46:50 laptop X[1176]: Current Operating System: Linux laptop 4.11.2 #1-NixOS SMP Sat May 20 12:50:04 UTC 2017 x86_64
May 29 13:46:50 laptop X[1176]: Kernel command line: BOOT_IMAGE=(lvm/vg-nixos--root)/nix/store/m1wqc9rnhkradhqf40z8b747a8b12xgc-linux-4.11.2/bzImage systemConfig=/nix/store/29ws2dpqlp0n2iizknnjqzfm4vrs7nhp-nixos-system-laptop-17.09.git.8f43
May 29 13:46:50 laptop X[1176]: Build Date: 11 May 2017  12:22:22AM
May 29 13:46:50 laptop X[1176]:  
May 29 13:46:50 laptop X[1176]: Current version of pixman: 0.34.0
May 29 13:46:50 laptop X[1176]:         Before reporting problems, check http://wiki.x.org
May 29 13:46:50 laptop X[1176]:         to make sure that you have the latest version.
May 29 13:46:50 laptop X[1176]: Markers: (--) probed, (**) from config file, (==) default setting,
May 29 13:46:50 laptop X[1176]:         (++) from command line, (!!) notice, (II) informational,
May 29 13:46:50 laptop X[1176]:         (WW) warning, (EE) error, (NI) not implemented, (??) unknown.
May 29 13:46:50 laptop X[1176]: (++) Log file: "/dev/null", Time: Mon May 29 13:46:50 2017
May 29 13:46:50 laptop X[1176]: (++) Using config file: "/nix/store/q4l7na13mz5gbplrsyzy607kcb18fa8w-xserver.conf"
May 29 13:46:50 laptop X[1176]: (==) Using config directory: "/etc/X11/xorg.conf.d"
May 29 13:46:50 laptop X[1176]: (==) Using system config directory "/nix/store/1xwbymcx0kcrbcbw32rh7mjphg6qic5x-xorg-server-1.19.3/share/X11/xorg.conf.d"
May 29 13:46:50 laptop X[1176]: (==) ServerLayout "Layout[all]"
May 29 13:46:50 laptop X[1176]: (**) |-->Screen "Screen-intel[0]" (0)
May 29 13:46:50 laptop X[1176]: (**) |   |-->Monitor "<default monitor>"
May 29 13:46:50 laptop X[1176]: (**) |   |-->Device "Device-intel[0]"
May 29 13:46:50 laptop X[1176]: (==) No monitor specified for screen "Screen-intel[0]".
May 29 13:46:50 laptop X[1176]:         Using a default monitor configuration.                                                                                                                                                                 
May 29 13:46:50 laptop X[1176]: (**) Option "DontZap" "on"                                                                                                                                                                                     
May 29 13:46:50 laptop X[1176]: (**) Option "AllowMouseOpenFail" "on"
May 29 13:46:50 laptop X[1176]: (==) Automatically adding devices
May 29 13:46:50 laptop X[1176]: (==) Automatically enabling devices
May 29 13:46:50 laptop X[1176]: (==) Automatically adding GPU devices
May 29 13:46:50 laptop X[1176]: (==) Max clients allowed: 256, resource mask: 0x1fffff

@dezgeg
Copy link
Contributor

dezgeg commented May 29, 2017

Maybe -logfile /dev/stderr works.

@pbogdan
Copy link
Member

pbogdan commented May 29, 2017

@dezgeg -logfile /dev/stderr didn't work on its own to capture output of X. With -logfile /dev/null + systemd-cat for X and --debug for lightdm output of both is captured (in the journal that is). Or did I misunderstand what you are saying?

@dezgeg
Copy link
Contributor

dezgeg commented May 29, 2017

Aha, indeed lightdm captures the stderr of the X server for its own purposes. How about -logfile /proc/$$/fd/2 (which should resolve to the bash script's stderr)?

@pbogdan
Copy link
Member

pbogdan commented May 30, 2017

Alas..

(EE) Cannot move old log file "/proc/1171/fd/2" to "/proc/1171/fd/2.old"

@pbogdan
Copy link
Member

pbogdan commented May 30, 2017

And annoyingly there doesn't seem to be a way to capture the output of the greeter process :/.

@dezgeg
Copy link
Contributor

dezgeg commented May 30, 2017

I guess patching is needed then... Fortunately, I think all that's needed to remove the calls to process_set_log_file().

@pbogdan
Copy link
Member

pbogdan commented May 30, 2017

I'm coming to a conclusion that capturing the output of the greeter as part of display-manager may not be possible. While I managed to get its output captured in the journal the greeter runs in a new user session and is no longer considered to be a part of display-manager and I believe there is no way to associate the greeter with it. So it seems that the output of lightdm and X is best that can be done, unless anyone has any other ideas.

@jtojnar
Copy link
Member

jtojnar commented Aug 1, 2018

I opened an issue about this upstream: canonical/lightdm#34

@timokau timokau added the 2.status: wait-for-upstream Waiting for upstream fix (or their other action). label Aug 16, 2018
@matthewbauer matthewbauer modified the milestones: 18.09, 19.03 Nov 5, 2018
@worldofpeace worldofpeace modified the milestones: 19.03, 19.09 May 8, 2019
@lheckemann lheckemann removed this from the 19.09 milestone Aug 21, 2019
@stale
Copy link

stale bot commented Jun 2, 2020

Thank you for your contributions.

This has been automatically marked as stale because it has had no activity for 180 days.

If this is still important to you, we ask that you leave a comment below. Your comment can be as simple as "still important to me". This lets people see that at least one person still cares about this. Someone will have to do this at most twice a year if there is no other activity.

Here are suggestions that might help resolve this more quickly:

  1. Search for maintainers and people that previously touched the related code and @ mention them in a comment.
  2. Ask on the NixOS Discourse.
  3. Ask on the #nixos channel on irc.freenode.net.

@stale stale bot added the 2.status: stale https://github.com/NixOS/nixpkgs/blob/master/.github/STALE-BOT.md label Jun 2, 2020
@lheckemann
Copy link
Member Author

Yes

@stale stale bot removed the 2.status: stale https://github.com/NixOS/nixpkgs/blob/master/.github/STALE-BOT.md label Jun 2, 2020
@stale
Copy link

stale bot commented Nov 29, 2020

I marked this as stale due to inactivity. → More info

@stale stale bot added the 2.status: stale https://github.com/NixOS/nixpkgs/blob/master/.github/STALE-BOT.md label Nov 29, 2020
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
2.status: stale https://github.com/NixOS/nixpkgs/blob/master/.github/STALE-BOT.md 2.status: wait-for-upstream Waiting for upstream fix (or their other action).
Projects
None yet
Development

No branches or pull requests

8 participants