Hide Forgot
Description of problem: "su -" and screen unlock from gnome takes a long time to return from completion Version-Release number of selected component (if applicable): fedora 24 How reproducible: not sure if it reproducible in other F24 environments, but in a console or terminal, typing "su -" as a normal user, the password response is quick, but the authentication is really slow. Similar with screenlock (GNOME). Steps to Reproduce: 1. start terminal as normail user 2. at command prompt in terminal, type "su -" 3. the "Password:" prompt is quick, but after typing in the password, it takes a long time to return with the # prompt Actual results: As aboe. Expected results: the return should be very quick. Additional info: The same behaviour is seen with screenlock. I checked the ps -alt output and noticed that there were lots of: polkitd 17882 1161 0 17:27 ? 00:00:00 [pkla-check-auth] <defunct> polkitd 17901 1161 0 17:28 ? 00:00:00 [pkla-check-auth] <defunct> polkitd 17943 1161 0 17:29 ? 00:00:00 [pkla-check-auth] <defunct> polkitd 17961 1161 0 17:30 ? 00:00:00 [pkla-check-auth] <defunct> polkitd 18012 1161 0 17:31 ? 00:00:00 [pkla-check-auth] <defunct> polkitd 18040 1161 0 17:32 ? 00:00:00 [pkla-check-auth] <defunct> polkitd 18097 1161 0 17:33 ? 00:00:00 [pkla-check-auth] <defunct> polkitd 18130 1161 0 17:34 ? 00:00:00 [pkla-check-auth] <defunct> processes like them. I think that is the problem. polkitd is checking something and I am not sure how to debug this. Happy to provide any additional info.
Thanks for your report. My (ps -alt) uses a completely different output, no idea what the above means; anyway, polkit does create a pkla-check-auth child per each request, so mere presence or such processes does not necessarily indicate a problem. Anyway, I’m afraid I can’t reproduce this; so instead of chasing a guess, can you attach the entire journalctl output around the time of your (su -) attempt? Also reassigning to pam as the primary component known to be in common between su and screen locking.
Also can you attach your /etc/pam.d/system-auth?
(In reply to Miloslav Trmač from comment #1) > Thanks for your report. > > My (ps -alt) uses a completely different output, no idea what the above > means; anyway, polkit does create a pkla-check-auth child per each request, > so mere presence or such processes does not necessarily indicate a problem. > > > Anyway, I’m afraid I can’t reproduce this; so instead of chasing a guess, > can you attach the entire journalctl output around the time of your (su -) > attempt? > > Also reassigning to pam as the primary component known to be in common > between su and screen locking. I am trying to trace what I did to my system. I did add the finger print daemon to it (I've got a Lenovo t450s which has a thumbprint reader) and it was after that was added that I noticed the slowness. I did remove the fprint reader but I reckon some rules could have been added into the pam for that. Here's my current /etc/pam.d/system-auth: [harish@gillman ~]$ cat /etc/pam.d/system-auth #%PAM-1.0 # This file is auto-generated. # User changes will be destroyed the next time authconfig is run. auth required pam_env.so auth sufficient pam_fprintd.so auth [default=1 success=ok] pam_localuser.so auth [success=done ignore=ignore default=die] pam_unix.so nullok try_firs t_pass auth requisite pam_succeed_if.so uid >= 1000 quiet_success auth sufficient pam_sss.so forward_pass auth required pam_deny.so account required pam_unix.so account sufficient pam_localuser.so account sufficient pam_succeed_if.so uid < 1000 quiet account [default=bad success=ok user_unknown=ignore] pam_sss.so account required pam_permit.so password requisite pam_pwquality.so try_first_pass local_users_only retry =3 authtok_type= password sufficient pam_unix.so sha512 shadow nullok try_first_pass use_au thtok password sufficient pam_sss.so use_authtok password required pam_deny.so session optional pam_keyinit.so revoke session required pam_limits.so -session optional pam_systemd.so session optional pam_mkhomedir.so umask=0077 session [success=1 default=ignore] pam_succeed_if.so service in crond quiet use_uid session required pam_unix.so session optional pam_sss.so
(In reply to Tomas Mraz from comment #2) > Also can you attach your /etc/pam.d/system-auth? i've attached the /etc/pam.d/system-auth in the reply to the previous comment. i see that pam_fprintd.so is in it. i've just commented it out and it seems to be working better now. "su -" and gnome screenlock is not taking as long as it used to. So, if appears that the dnf remove fprintd did not remove the pam entry. I am Ok to close this report.
I did a systemctl restart polkit.service and the delay is still there but not as much as it was before. Will continue to investigate.
Been checking and monitoring the system and regrettably, the delay still is there and I am noticing that there are lots of defunct polkitd processes running as indicated in the initial report. Some observations: a) Clicking on the GNOME top right hand corner to invoke the VPN option, does not produce the usual VPN password dialog box. b) I have to use the CLI to connect to the vpn that I need to connect to. c) Even when "systemctl restart polkitd.service", the NetworkManager's dialog box does not appear, but it DOES clean out the defunct polkitd processes. I am not able to figure out what else I need to check. Appreciate any pointers.
Created attachment 1206764 [details] screenshot shoing the output of "ps -ef|grep polkit" this is the output of ps -ef|grep polkit. the pkla-check-authorization goes into a defunct mode and not sure why.
(man ps): > Processes marked <defunct> are dead processes (so-called "zombies") > that remain because their parent has not destroyed them properly. > These processes will be destroyed by init(8) if the parent process > exits. This just means that pkla-c-a has terminated, and it is quite uninteresting that these processes are being created and terminate; a new process is created for every polkit authorization request and terminates after returning one answer. It _might_ be interesting if polkitd (not pkla-c-a) were slow/hanging and failing to clean them up.
(In reply to Miloslav Trmač from comment #8) > (man ps): > > Processes marked <defunct> are dead processes (so-called "zombies") > > that remain because their parent has not destroyed them properly. > > These processes will be destroyed by init(8) if the parent process > > exits. > > This just means that pkla-c-a has terminated, and it is quite uninteresting > that these processes are being created and terminate; a new process is > created for every polkit authorization request and terminates after > returning one answer. It _might_ be interesting if polkitd (not pkla-c-a) > were slow/hanging and failing to clean them up. Understood. But it seems to be just lingering in the process table. If the task is done, it shouldn't it clean up? What I have been doing is to restart polkit.service to clean up the defunct processes.
> If the task is done, it shouldn't it clean up? Oh, sure; but it does work for me in ordinary use. So, please start with providing the requested logs, and if that doesn’t help, we might need to figure out a way to reproduce this.
Hi Miloslav, I am experiencing similar problem on Fedora 25 workstation. My case is sudo takes long time(several minutes) to return after system been up for around 5 days. - ps showed there were tons of: polkitd 12813 0.0 0.0 0 0 ? Z 11:05 0:00 [pkla-check-auth] <defunct> polkitd 12818 0.0 0.0 0 0 ? Z 11:06 0:00 [pkla-check-auth] <defunct> - /var/log/secure showed: Nov 30 11:25:04 localhost systemd: pam_unix(systemd-user:session): session opened for user pcp by (uid=0) Nov 30 11:25:54 localhost systemd: pam_unix(systemd-user:session): session closed for user pcp Nov 30 11:28:04 localhost systemd: pam_unix(systemd-user:session): session opened for user pcp by (uid=0) ... Dec 4 21:28:53 localhost systemd: pam_unix(systemd-user:session): session closed for user pcp Dec 4 21:55:07 localhost systemd: pam_unix(systemd-user:session): session opened for user pcp by (uid=0) Dec 4 21:56:27 localhost systemd: pam_unix(systemd-user:session): session closed for user pcp Dec 4 21:57:25 localhost polkitd[959]: /etc/polkit-1/rules.d/49-polkit-pkla-compat.rules:21: Error: Error spawning helper: Timed out after 10 seconds (g-io-error-quark, 24) Dec 4 21:57:25 localhost polkitd[959]: Error evaluating authorization rules Dec 4 21:58:23 localhost polkitd[959]: /etc/polkit-1/rules.d/49-polkit-pkla-compat.rules:21: Error: Error spawning helper: Timed out after 10 seconds (g-io-error-quark, 24) Dec 4 21:58:23 localhost polkitd[959]: Error evaluating authorization rules Dec 4 22:02:18 localhost crond[2170]: pam_systemd(crond:session): Failed to create session: Connection timed out Dec 4 22:03:01 localhost polkitd[959]: /etc/polkit-1/rules.d/49-polkit-pkla-compat.rules:21: Error: Error spawning helper: Timed out after 10 seconds (g-io-error-quark, 24) Any info you want me to provide?
> Any info you want me to provide? > can you attach the entire journalctl output around the time of your (su -) attempt?
(In reply to Miloslav Trmač from comment #12) > > Any info you want me to provide? > > > can you attach the entire journalctl output around the time of your (su -) attempt? su - worked fine to me, it returned with prompt for password immediately. Only sudo caused lag in my case. I issued: $ date; sudo ls /boot Tue Dec 6 09:25:51 CST 2016 then watched journalctl: -- Logs begin at Fri 2015-12-25 08:47:23 CST, end at Tue 2016-12-06 09:29:18 CST. -- Dec 06 09:29:18 localhost.localdomain polkit-mate-aut[3522]: Error enumerating temporary authorizations: Timeout was reached Dec 06 09:29:18 localhost.localdomain crond[31698]: pam_systemd(crond:session): Failed to create session: Connection timed out Dec 06 09:28:53 localhost.localdomain systemd[1]: Started Session 1101 of user pcp. Dec 06 09:28:53 localhost.localdomain systemd[1]: Starting User Manager for UID 982... Dec 06 09:28:53 localhost.localdomain systemd[1]: Created slice User Slice of pcp. Dec 06 09:28:51 localhost.localdomain audit[31768]: CRED_DISP pid=31768 uid=0 auid=1000 ses=3 subj=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 msg=' Dec 06 09:28:51 localhost.localdomain audit[31768]: USER_END pid=31768 uid=0 auid=1000 ses=3 subj=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 msg='o Dec 06 09:28:51 localhost.localdomain sudo[31768]: pam_unix(sudo:session): session closed for user root Dec 06 09:28:51 localhost.localdomain sudo[31768]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 06 09:28:51 localhost.localdomain audit[31768]: USER_START pid=31768 uid=0 auid=1000 ses=3 subj=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 msg= Dec 06 09:28:51 localhost.localdomain sudo[31768]: pam_systemd(sudo:session): Cannot create session: Already occupied by a session Dec 06 09:28:51 localhost.localdomain sudo[31768]: chayang : TTY=pts/6 ; PWD=/home/chayang ; USER=root ; COMMAND=/bin/ls /boot Dec 06 09:28:51 localhost.localdomain audit[31768]: CRED_REFR pid=31768 uid=0 auid=1000 ses=3 subj=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 msg=' Dec 06 09:28:51 localhost.localdomain audit[31768]: USER_CMD pid=31768 uid=1000 auid=1000 ses=3 subj=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 msg Dec 06 09:28:51 localhost.localdomain audit[31768]: USER_ACCT pid=31768 uid=1000 auid=1000 ses=3 subj=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 ms Dec 06 09:28:51 localhost.localdomain audit[31768]: USER_AUTH pid=31768 uid=1000 auid=1000 ses=3 subj=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 ms Dec 06 09:28:18 localhost.localdomain /usr/libexec/gdm-x-session[3320]: [4951:4985:1206/092818:ERROR:connection_factory_impl.cc(367)] Failed to connect to MCS Dec 06 09:28:18 localhost.localdomain /usr/libexec/gdm-x-session[3320]: [4951:4985:1206/092818:ERROR:socket_stream.cc(210)] Closing stream with result -100 Dec 06 09:28:01 localhost.localdomain audit[31798]: CRED_ACQ pid=31798 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:crond_t:s0-s0:c0.c1023 msg= Dec 06 09:28:01 localhost.localdomain audit[31798]: USER_ACCT pid=31798 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:crond_t:s0-s0:c0.c1023 msg Dec 06 09:25:46 localhost.localdomain sudo[31759]: pam_unix(sudo:auth): auth could not identify password for [chayang] Dec 06 09:25:46 localhost.localdomain audit[31759]: USER_CMD pid=31759 uid=1000 auid=1000 ses=3 subj=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 msg Dec 06 09:25:46 localhost.localdomain audit[31759]: USER_AUTH pid=31759 uid=1000 auid=1000 ses=3 subj=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 ms Dec 06 09:25:46 localhost.localdomain sudo[31759]: pam_unix(sudo:auth): conversation failed
(In reply to Miloslav Trmač from comment #12) > > Any info you want me to provide? > > > can you attach the entire journalctl output around the time of your (su -) attempt? Anything else I could provide in order for debugging?
I don't see this anymore so I am OK for it to be closed.