PAM Modules debugging

chrisdb · 2019-03-27 13:28:47

Hi,

I hope someone can help me with the following:
What is the recommended way to find (debug) logs of PAM modules? I can't find them in the journal.

I've been reading about it and almost everywhere I look, the following procedure is mentioned:

https://www.ibm.com/support/knowledgece … _debug.htm

Is this still the way to go? I mean, wasn't syslog replaced by the Journal?

Thx

Last edited by chrisdb (2019-03-27 13:50:15)

Trilby · 2019-03-27 13:40:13

chrisdb wrote:

I can't find them in the journal.

Did you look? I believe debug messages are logged to the journal by default:

journalctl -g pam

Note that you may want to update your title to better represent your issue.

Last edited by Trilby (2019-03-27 13:40:53)

loqs · 2019-03-27 14:06:10

Looking in https://github.com/linux-pam/linux-pam/tree/v1.3.1 I can not find find any code that relies upon /etc/pam_debug.
There is code that would be enabled if the package was built with configure --enable-debug (which it is not) then additional output would be written to /var/run/pam-debug.log.
The pam_debug module can be added to the pam stack for additional output. Also many pam modules have a debug option.
Is this an X-Y problem where you are trying to debug pam to resolve some issue?

chrisdb · 2019-03-27 14:44:20

loqs wrote:

Is this an X-Y problem where you are trying to debug pam to resolve some issue?

Yes, it is related to the following issue:

https://bbs.archlinux.org/viewtopic.php?id=245171

From what I can guess from the code(see below), the env variable 'XDG_RUNTIME_DIR' is not configured on time.

control_root = get_any_env (ph, ENV_CONTROL);
	if (control_root == NULL) {
		control_root = get_any_env (ph, "XDG_RUNTIME_DIR");
		if (control_root == NULL)
			return GKD_CONTROL_RESULT_NO_DAEMON;
		suffix = "/keyring/control";
	} else {
		suffix = "/control";
	}

Although it should've been set within module "pam_systemd.so" which comes before the call to "pam_gnome_keyring.so"
I wanted to check if my assumption was correct

******EDIT
I just enabled debug and here's the result:

ar 27 20:35:23 myarch systemd[1]: systemd 241.7-2-arch running in system mode. (+PAM +AUDIT -SELINUX -IMA -APPARMOR +SMACK -SYSVINIT +UTMP +LIBCRYPTSETUP +GCR>
Mar 27 20:35:45 myarch lightdm[493]: pam_unix(lightdm-greeter:session): session opened for user lightdm by (uid=0)
Mar 27 20:35:45 myarch systemd[497]: pam_unix(systemd-user:session): session opened for user lightdm by (uid=0)
Mar 27 20:35:45 myarch systemd[497]: pam_systemd(systemd-user:session): pam-systemd initializing
Mar 27 20:35:53 myarch lightdm[548]: gkr-pam: unable to locate daemon control file
Mar 27 20:35:53 myarch lightdm[493]: pam_unix(lightdm-greeter:session): session closed for user lightdm
Mar 27 20:35:54 myarch lightdm[548]: pam_unix(lightdm:session): session opened for user chris by (uid=0)
Mar 27 20:35:54 myarch lightdm[548]: pam_systemd(lightdm:session): pam-systemd initializing
Mar 27 20:35:54 myarch lightdm[548]: pam_systemd(lightdm:session): Asking logind to create session: uid=1000 pid=548 service=lightdm type=x11 class=user deskto>
Mar 27 20:35:54 myarch lightdm[548]: pam_systemd(lightdm:session): Session limits: memory_max=n/a tasks_max=n/a cpu_weight=n/a io_weight=n/a
Mar 27 20:35:54 myarch systemd[554]: pam_unix(systemd-user:session): session opened for user chris by (uid=0)
Mar 27 20:35:54 myarch systemd[554]: pam_systemd(systemd-user:session): pam-systemd initializing
Mar 27 20:35:54 myarch lightdm[548]: pam_systemd(lightdm:session): Reply from logind: id=2 object_path=/org/freedesktop/login1/session/_32 runtime_path=/run/us>
Mar 27 20:36:03 myarch pkexec[706]: pam_unix(polkit-1:session): session opened for user root by (uid=1000)
Mar 27 20:36:04 myarch systemd[498]: pam_unix(systemd-user:session): session closed for user lightdm
Mar 27 20:36:17 myarch sudo[784]: pam_unix(sudo:session): session opened for user root by (uid=0)
Mar 27 20:36:17 myarch sudo[784]: pam_unix(sudo:session): session closed for user root
Mar 27 20:36:22 myarch sudo[787]:    chris : TTY=pts/0 ; PWD=/home/chris ; USER=root ; COMMAND=/usr/bin/journalctl -g pam
Mar 27 20:36:22 myarch sudo[787]: pam_unix(sudo:session): session opened for user root by (uid=0)

why is pam_systemd initialized twice?

Last edited by chrisdb (2019-03-27 19:41:00)

loqs · 2019-03-28 23:34:23

I think there are multiple sessions but pam_systemd is only initialized once per session

Mar 27 20:35:45 myarch lightdm[493]: pam_unix(lightdm-greeter:session): session opened for user lightdm by (uid=0)
Mar 27 20:35:45 myarch systemd[497]: pam_unix(systemd-user:session): session opened for user lightdm by (uid=0)
Mar 27 20:35:45 myarch systemd[497]: pam_systemd(systemd-user:session): pam-systemd initializing
Mar 27 20:35:53 myarch lightdm[548]: gkr-pam: unable to locate daemon control file
Mar 27 20:35:53 myarch lightdm[493]: pam_unix(lightdm-greeter:session): session closed for user lightdm

Mar 27 20:35:54 myarch lightdm[548]: pam_unix(lightdm:session): session opened for user chris by (uid=0)
Mar 27 20:35:54 myarch lightdm[548]: pam_systemd(lightdm:session): pam-systemd initializing
Mar 27 20:35:54 myarch lightdm[548]: pam_systemd(lightdm:session): Asking logind to create session: uid=1000 pid=548 service=lightdm type=x11 class=user deskto>
Mar 27 20:35:54 myarch lightdm[548]: pam_systemd(lightdm:session): Session limits: memory_max=n/a tasks_max=n/a cpu_weight=n/a io_weight=n/a

Mar 27 20:35:54 myarch systemd[554]: pam_unix(systemd-user:session): session opened for user chris by (uid=0)
Mar 27 20:35:54 myarch systemd[554]: pam_systemd(systemd-user:session): pam-systemd initializing
Mar 27 20:35:54 myarch lightdm[548]: pam_systemd(lightdm:session): Reply from logind: id=2 object_path=/org/freedesktop/login1/session/_32 runtime_path=/run/us>

Arch Linux

#1 2019-03-27 13:28:47

PAM Modules debugging

#2 2019-03-27 13:40:13

Re: PAM Modules debugging

#3 2019-03-27 14:06:10

Re: PAM Modules debugging

#4 2019-03-27 14:44:20

Re: PAM Modules debugging

#5 2019-03-28 23:34:23

Re: PAM Modules debugging

Board footer