usermin 1.861 crash when login from virtualmin

[aqueos]

hi,

Since the upgrade to 1.861 connecting to a user from virtualmin lead to usermin crash.

Commandline: apt-get install --reinstall usermin-webmail=1.823 Downgrade: usermin-webmail:amd64 (1.861, 1.823) Upgrade: usermin-webmail:amd64 (1.823, 1.861)

i am on debian 10.

usermin 1.823 works fine.

When you edit user in virtualmin you have an option to "connecto to usermin as this user". After the upgrade the usermin stack crash without messages in the log.

Here is a trace of the crash when i click in virtualmin on this button to connect to usermin:

stat("/var/usermin/restart-flag", 0x5578da52f478) = -1 ENOENT (No such file or directory)
stat("/var/usermin/reload-flag", 0x5578da52f478) = -1 ENOENT (No such file or directory)
stat("/var/usermin/stop-flag", 0x5578da52f478) = -1 ENOENT (No such file or directory)
wait4(-1, 0x7ffc5c171be4, WNOHANG, NULL) = -1 ECHILD (No child processes)
select(8, [5 6], NULL, NULL, {tv_sec=2, tv_usec=0}) = 0 (Timeout)
stat("/var/usermin/restart-flag", 0x5578da52f478) = -1 ENOENT (No such file or directory)
stat("/var/usermin/reload-flag", 0x5578da52f478) = -1 ENOENT (No such file or directory)
stat("/var/usermin/stop-flag", 0x5578da52f478) = -1 ENOENT (No such file or directory)
wait4(-1, 0x7ffc5c171be4, WNOHANG, NULL) = -1 ECHILD (No child processes)
select(8, [5 6], NULL, NULL, {tv_sec=2, tv_usec=0}) = 0 (Timeout)
stat("/var/usermin/restart-flag", 0x5578da52f478) = -1 ENOENT (No such file or directory)
stat("/var/usermin/reload-flag", 0x5578da52f478) = -1 ENOENT (No such file or directory)
stat("/var/usermin/stop-flag", 0x5578da52f478) = -1 ENOENT (No such file or directory)
wait4(-1, 0x7ffc5c171be4, WNOHANG, NULL) = -1 ECHILD (No child processes)
select(8, [5 6], NULL, NULL, {tv_sec=2, tv_usec=0}) = 0 (Timeout)
stat("/var/usermin/restart-flag", 0x5578da52f478) = -1 ENOENT (No such file or directory)
stat("/var/usermin/reload-flag", 0x5578da52f478) = -1 ENOENT (No such file or directory)
stat("/var/usermin/stop-flag", 0x5578da52f478) = -1 ENOENT (No such file or directory)
wait4(-1, 0x7ffc5c171be4, WNOHANG, NULL) = -1 ECHILD (No child processes)
select(8, [5 6], NULL, NULL, {tv_sec=2, tv_usec=0}) = 0 (Timeout)
stat("/var/usermin/restart-flag", 0x5578da52f478) = -1 ENOENT (No such file or directory)
stat("/var/usermin/reload-flag", 0x5578da52f478) = -1 ENOENT (No such file or directory)
stat("/var/usermin/stop-flag", 0x5578da52f478) = -1 ENOENT (No such file or directory)
wait4(-1, 0x7ffc5c171be4, WNOHANG, NULL) = -1 ECHILD (No child processes)
select(8, [5 6], NULL, NULL, {tv_sec=2, tv_usec=0}) = 0 (Timeout)
stat("/var/usermin/restart-flag", 0x5578da52f478) = -1 ENOENT (No such file or directory)
stat("/var/usermin/reload-flag", 0x5578da52f478) = -1 ENOENT (No such file or directory)
stat("/var/usermin/stop-flag", 0x5578da52f478) = -1 ENOENT (No such file or directory)
wait4(-1, 0x7ffc5c171be4, WNOHANG, NULL) = -1 ECHILD (No child processes)
select(8, [5 6], NULL, NULL, {tv_sec=2, tv_usec=0}) = 0 (Timeout)
stat("/var/usermin/restart-flag", 0x5578da52f478) = -1 ENOENT (No such file or directory)
stat("/var/usermin/reload-flag", 0x5578da52f478) = -1 ENOENT (No such file or directory)
stat("/var/usermin/stop-flag", 0x5578da52f478) = -1 ENOENT (No such file or directory)
wait4(-1, 0x7ffc5c171be4, WNOHANG, NULL) = -1 ECHILD (No child processes)
select(8, [5 6], NULL, NULL, {tv_sec=2, tv_usec=0}) = ? ERESTARTNOHAND (To be restarted if no handler)
--- SIGTERM {si_signo=SIGTERM, si_code=SI_USER, si_pid=52006, si_uid=0} ---
rt_sigreturn({mask=[]})                 = -1 EINTR (Interrupted system call)
rt_sigprocmask(SIG_BLOCK, [TERM], [], 8) = 0
rt_sigaction(SIGTERM, NULL, {sa_handler=0x5578d88c3000, sa_mask=[], sa_flags=SA_RESTORER, sa_restorer=0x7f0c798a1730}, 8) = 0
lseek(2, 0, SEEK_END)                   = 428510
lseek(2, 0, SEEK_CUR)                   = 428510
write(2, "[", 1)                        = 1
write(2, "30/Jan/2023:15:59:26 +0100", 26) = 26
write(2, "] ", 2)                       = 2
write(2, "Shutting down", 13)           = 13
write(2, "\n", 1)                       = 1
rt_sigprocmask(SIG_UNBLOCK, [TERM], NULL, 8) = 0
rt_sigaction(SIGHUP, NULL, {sa_handler=0x5578d88c3000, sa_mask=[], sa_flags=SA_RESTORER, sa_restorer=0x7f0c798a1730}, 8) = 0
rt_sigaction(SIGHUP, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=SA_RESTORER, sa_restorer=0x7f0c798a1730}, {sa_handler=0x5578d88c3000, sa_mask=[], sa_flags=SA_RESTORER, sa_restorer=0x7f0c798a1730}, 8) = 0
rt_sigaction(SIGINT, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGQUIT, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGILL, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGTRAP, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGABRT, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGBUS, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGFPE, NULL, {sa_handler=SIG_IGN, sa_mask=[FPE], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x7f0c79706970}, 8) = 0
rt_sigaction(SIGKILL, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGUSR1, NULL, {sa_handler=0x5578d88c3000, sa_mask=[], sa_flags=SA_RESTORER, sa_restorer=0x7f0c798a1730}, 8) = 0
rt_sigaction(SIGUSR1, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=SA_RESTORER, sa_restorer=0x7f0c798a1730}, {sa_handler=0x5578d88c3000, sa_mask=[], sa_flags=SA_RESTORER, sa_restorer=0x7f0c798a1730}, 8) = 0
rt_sigaction(SIGSEGV, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGUSR2, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGPIPE, NULL, {sa_handler=SIG_IGN, sa_mask=[], sa_flags=SA_RESTORER, sa_restorer=0x7f0c798a1730}, 8) = 0
rt_sigaction(SIGALRM, NULL, {sa_handler=0x5578d88c3000, sa_mask=[], sa_flags=SA_RESTORER, sa_restorer=0x7f0c798a1730}, 8) = 0
rt_sigaction(SIGALRM, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=SA_RESTORER, sa_restorer=0x7f0c798a1730}, {sa_handler=0x5578d88c3000, sa_mask=[], sa_flags=SA_RESTORER, sa_restorer=0x7f0c798a1730}, 8) = 0
rt_sigaction(SIGTERM, NULL, {sa_handler=0x5578d88c3000, sa_mask=[], sa_flags=SA_RESTORER, sa_restorer=0x7f0c798a1730}, 8) = 0
rt_sigaction(SIGTERM, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=SA_RESTORER, sa_restorer=0x7f0c798a1730}, {sa_handler=0x5578d88c3000, sa_mask=[], sa_flags=SA_RESTORER, sa_restorer=0x7f0c798a1730}, 8) = 0
rt_sigaction(SIGSTKFLT, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGCHLD, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGCONT, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGSTOP, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGTSTP, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGTTIN, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGTTOU, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGURG, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGXCPU, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGXFSZ, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGVTALRM, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGPROF, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGWINCH, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGIO, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGPWR, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGSYS, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_2, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_3, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_4, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_5, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_6, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_7, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_8, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_9, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_10, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_11, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_12, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_13, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_14, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_15, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_16, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_17, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_18, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_19, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_20, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_21, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_22, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_23, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_24, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_25, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_26, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_27, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_28, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_29, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_30, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_31, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_32, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGABRT, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGCHLD, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGIO, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
getpid()                                = 53023
close(8)                                = 0
close(7)                                = 0
close(5)                                = 0
close(6)                                = 0
close(4)                                = 0
exit_group(1)                           = ?
+++ exited with 1 +++

tell me if you need anything more ?

best regards, Adnet ghislain Aqueos.

[aqueos]

hard to read in the ticket here is the trace in txt file ! usermintrace.txt

[iliajie]

Webmin and Usermin usually never crash really. Although, it can be killed by kernel (OOM). Try checking this out, e.g.:

dmesg -T | grep -i 'kill'

[aqueos]

oh yes good idea i had not look there but i just reviewed all the kernel and syslog of the server and there is not any ooem or other messages.

the usermin log show only this when i click on it: ==> /var/usermin/miniserv.error <== [30/Jan/2023:17:45:34 +0100] Shutting down

best regards, Ghislain.

[swelljoe]

That indicates it was told to shut down. Quite different from a "crash".

[aqueos]

yes the strace show the same but the very same thing work on the previous version and here each click makes it shutdown for no reason.

i dont know what i can do more to debug this :(

[iliajie]

What is the output of systemctl restart usermin and then systemctl status usermin?

Also, check what is getting printed to /var/usermin/miniserv.error after running those commands.

[aqueos]

its a sysv system here it is:

VSGUEST:root@:[~]: /etc/init.d/usermin restart
Stopping Usermin server in /usr/share/usermin
/etc/usermin/.stop-init: 10: kill: No such process

Starting Usermin server in /usr/share/usermin

VSGUEST:root@:[~]: /etc/init.d/usermin restart
Stopping Usermin server in /usr/share/usermin
Starting Usermin server in /usr/share/usermin
VSGUEST:root@:[~]: 

resulting logs:

[30/Jan/2023:18:33:10 +0100] miniserv.pl started
[30/Jan/2023:18:33:10 +0100] Using MD5 module Digest::MD5
[30/Jan/2023:18:33:10 +0100] Using SHA512 module Crypt::SHA
[30/Jan/2023:18:33:10 +0100] PAM authentication enabled
[30/Jan/2023:18:33:13 +0100] Shutting down
[30/Jan/2023:18:33:16 +0100] miniserv.pl started
[30/Jan/2023:18:33:16 +0100] Using MD5 module Digest::MD5
[30/Jan/2023:18:33:16 +0100] Using SHA512 module Crypt::SHA
[30/Jan/2023:18:33:16 +0100] PAM authentication enabled

VSGUEST:root@:[~]: facter os
{
  architecture => "amd64",
  distro => {
    codename => "buster",
    description => "Debian GNU/Linux 10 (buster)",
    id => "Debian",
    release => {
      full => "10.13",
      major => "10",
      minor => "13"
    }
  },
  family => "Debian",
  hardware => "x86_64",
  name => "Debian",
  release => {
    full => "10.13",
    major => "10",
    minor => "13"
  },
  selinux => {
    enabled => false
  }
}

VSGUEST:root@:[~]: dpkg -l usermin-webmail
Desired=Unknown/Install/Remove/Purge/Hold
| Status=Not/Inst/Conf-files/Unpacked/halF-conf/Half-inst/trig-aWait/Trig-pend
|/ Err?=(none)/Reinst-required (Status,Err: uppercase=bad)
||/ Name            Version      Architecture Description
+++-===============-============-============-================================================================
ii  usermin-webmail 1.861        all          web-based user account administration interface for Unix systems

[iliajie]

I thought that Debian 10 is always a systemd system .. why not sticking with systemd anyway?

It is not clear what is happening with Usermin but you will have to debug it. Start from looking into available resources (memory and disk space/quota).

By the way, what about Webmin? Does it get killed too?

[aqueos]

no webmin/virtualmin are fine.

connecting directly from usermin with the user login/pass works. This is when i come from virtualmin that usermin is shutdown.

[Stephano2000]

I can reproduce that issue (Jan 7 Virtualmin install / Usermin 1.861). Actually I had been experiencing its side effects without realizing the cause. Steps to reproduce:

• Edit Users -> Click on a user
• Click "Login to Usermin"
• A new webpage will open, but with an "Unable to connect" error
• Refreshing that page once or twice brings up Usermin

Usermin log: [03/Apr/2023:12:28:52 +0000] PAM authentication enabled [03/Apr/2023:12:28:52 +0000] Using SHA512 module Crypt::SHA [03/Apr/2023:12:28:52 +0000] Using MD5 module Digest::MD5 [03/Apr/2023:12:28:52 +0000] miniserv.pl started [03/Apr/2023:12:28:48 +0000] Shutting down

Syslog: Apr 3 12:28:52 mars systemd[1]: Started Usermin server daemon. Apr 3 12:28:52 mars systemd[1]: usermin.service: Can't open PID file /var/usermin/miniserv.pid (yet?) after start: Operation not permitted Apr 3 12:28:50 mars systemd[1]: Starting Usermin server daemon... Apr 3 12:28:50 mars systemd[1]: usermin.service: Consumed 2.312s CPU time. Apr 3 12:28:50 mars systemd[1]: Stopped Usermin server daemon. Apr 3 12:28:50 mars systemd[1]: usermin.service: Scheduled restart job, restart counter is at 4. Apr 3 12:28:48 mars systemd[1]: usermin.service: Consumed 2.312s CPU time. Apr 3 12:28:48 mars systemd[1]: usermin.service: Failed with result 'signal'. Apr 3 12:28:48 mars systemd[1]: usermin.service: Main process exited, code=killed, status=10/USR1

[iliajie]

Confirmed.

The reason why this happens is because when setting a new session for the user, Usermin is getting killed and automatically restarted only in 3 seconds (by systemd). I will look into this problem deeper.

Thanks for reporting this.

[iliajie]

This issue will be fixed in the next Webmin release.

https://github.com/webmin/webmin/commit/eaaa47081892099bfdbe5b173dd712f870ce7243