"Users and Groups" hangs for a minute when listing ~150 users

Submitted by Locutus on Fri, 07/22/2011 - 07:55

I just noticed this when listing the users of my main hosting system; has about 150 entries.

Calling up the user list in the "Users and Groups" module needs about a minute.

Webmin Debug Log (all entries activated) says:

16163 [22/Jul/2011 14:43:41.841120] - 87.79.76.199 - START "script=index.cgi"
16163 [22/Jul/2011 14:43:41.841366] - 87.79.76.199 - READ "/etc/webmin/miniserv.conf"
16163 [22/Jul/2011 14:43:41.841857] root 87.79.76.199 - READ "/etc/webmin/useradmin/config"
16163 [22/Jul/2011 14:43:41.842287] root 87.79.76.199 - READ "/usr/share/webmin/virtual-server-theme/config"
16163 [22/Jul/2011 14:43:41.843719] root 87.79.76.199 - READ "/etc/webmin/custom-lang"
16163 [22/Jul/2011 14:43:41.844926] root 87.79.76.199 - READ "/etc/webmin/useradmin/custom-lang"
16163 [22/Jul/2011 14:43:41.845942] root 87.79.76.199 - READ "/etc/webmin/module.infos.cache"
16163 [22/Jul/2011 14:43:41.864674] root 87.79.76.199 - READ "/usr/share/webmin//defaultacl"
16163 [22/Jul/2011 14:43:41.864967] root 87.79.76.199 - READ "/etc/webmin/root.acl"
16163 [22/Jul/2011 14:43:41.865215] root 87.79.76.199 - READ "/etc/webmin//root.acl"
16163 [22/Jul/2011 14:43:41.865469] root 87.79.76.199 - READ "/etc/webmin/installed.cache"
16163 [22/Jul/2011 14:43:41.866840] root 87.79.76.199 - READ "/usr/share/webmin/useradmin/module.info"
16163 [22/Jul/2011 14:43:41.867317] root 87.79.76.199 - READ "/etc/webmin/webmin.cats"
16163 [22/Jul/2011 14:43:41.867508] root 87.79.76.199 - READ "/etc/webmin/webmin.descs"
16163 [22/Jul/2011 14:43:41.871527] root 87.79.76.199 useradmin READ "/usr/share/webmin/useradmin/defaultacl"
16163 [22/Jul/2011 14:43:41.871920] root 87.79.76.199 useradmin READ "/etc/webmin/useradmin/root.acl"
16163 [22/Jul/2011 14:43:41.872194] root 87.79.76.199 useradmin READ "/usr/share/webmin/man/module.info"
16163 [22/Jul/2011 14:43:41.928792] root 87.79.76.199 useradmin READ "/etc/hostname"
16163 [22/Jul/2011 14:43:41.929044] root 87.79.76.199 useradmin CMD "cmd=hostname"
16163 [22/Jul/2011 14:43:41.932370] root 87.79.76.199 useradmin CMD "cmd=hostname -f"
16163 [22/Jul/2011 14:43:41.946808] root 87.79.76.199 useradmin READ "/etc/shadow"
16163 [22/Jul/2011 14:43:41.947010] root 87.79.76.199 useradmin READ "/etc/passwd"
16163 [22/Jul/2011 14:43:41.948930] root 87.79.76.199 useradmin READ "/etc/shadow"
16163 [22/Jul/2011 14:43:41.951132] root 87.79.76.199 useradmin READ "/etc/gshadow"
16163 [22/Jul/2011 14:43:41.951308] root 87.79.76.199 useradmin READ "/etc/group"
16163 [22/Jul/2011 14:43:41.952059] root 87.79.76.199 useradmin READ "/etc/gshadow"
16163 [22/Jul/2011 14:44:52.289476] root 87.79.76.199 - STOP "runtime=71"

It seems to hang for a minute on the "read /etc/gshadow" step.

atop reports a process last (no further command line; probably used in a pipe) using 99% CPU during that minute.

Memory allocation of miniserv.pl increases from ~50 MB to ~120 MB during that time.

I can send you the contents of my files if that helps hunting for the "CPU cycles waster" there. :) Let me know if you need further information.

Status: 
Closed (fixed)

Comments

Submitted by Locutus on Fri, 07/22/2011 - 08:13

Okay, found the culprit. My /var/log/wtmp (containing the log data for the last command) was over 90 MB. Seems one certain user is logging in four times per minute to the FTP service.

I suppose Webmin uses the last command to retrieve the users' last logins?

I'm not sure, but maybe you could use and parse the lastlog command instead? At least on my Ubuntu, that command does not parse the whole wtmp file, but uses /var/log/lastlog, which only records the last login of every user, not all logins.

Example:

root@orion:/var/log# lastlog -u invertoforum
Username         Port     From             Latest
invertoforum     pts/2    217.91.62.7      Mon Nov  8 19:13:23 +0100 2010

This command completes instantaneously, also with very large wtmp files.

Submitted by JamieCameron on Fri, 07/22/2011 - 11:35

At Module Config -> Display options, do you have "Show last login in user list?" set to "Yes" ?

Submitted by Locutus on Fri, 07/22/2011 - 11:54

Yep, that's set to "Yes". I'm quite positive that fetching the "last" list is what took so long. Cause as soon as I removed /var/log/wtmp, the user list was fetched instantaneously.

Submitted by JamieCameron on Fri, 07/22/2011 - 12:32

Thanks for the suggestion .. I will use the lastlog command to populate that field in the next Webmin release (1.560).

Submitted by Locutus on Fri, 07/22/2011 - 17:18

Rogerroger. Until then I'll turn off "show last login". Don't really need that info on the page anyway. :)