[solved] pkg freezes at "Cleaning up old Version" (12.1-RELEASE-p3 amd64)

Hey Guys!

Yesterday, I updatet our Blade Servers PKG to Version 1.13.2. However, when I try to upgrade a Package, PKG installs the new Version of the Package, delete the old one (I guess), freezes and won't finish. In our Jails however, PKG works fine.

I don't know whats the Problem is. Our blades have only fail2ban, iocage and its dependencies installed. The initial Install was FreeBSD 12.1-RELEASE.

Here an output of PKG in debug mode, trying to reinstall python-3.7.7
Code:
# pkg -d install -f python37
DBG(1)[76957]> pkg initialized
Updating FreeBSD repository catalogue...
DBG(1)[76957]> PkgRepo: verifying update for FreeBSD
DBG(1)[76957]> Pkgrepo, begin update of '/var/db/pkg/repo-FreeBSD.sqlite'
DBG(1)[76957]> Fetch: fetching from: http://pkgmir.geo.freebsd.org/FreeBSD:12:amd64/quarterly/meta.conf with opts "i"
DBG(1)[76957]> Fetch: fetching from: http://pkgmir.geo.freebsd.org/FreeBSD:12:amd64/quarterly/meta.txz with opts "i"
DBG(1)[76957]> Fetch: fetching from: http://pkgmir.geo.freebsd.org/FreeBSD:12:amd64/quarterly/packagesite.txz with opts "i"
FreeBSD repository is up to date.
All repositories are up to date.
DBG(1)[76957]> want to get an advisory lock on a database
DBG(1)[76957]> found stale pid 69634 in lock database, my pid is: 76957
DBG(1)[76957]> no concurrent processes found, cleanup the lock
DBG(1)[76957]> want to get an advisory lock on a database
DBG(1)[76957]> Binary> loading /var/cache/pkg/python37-3.7.7-6486f83221.txz
Checking integrity...DBG(1)[76957]> check integrity for 1 items added
 done (0 conflicting)
The following 1 package(s) will be affected (of 0 checked):

Installed packages to be REINSTALLED:
    python37-3.7.7

Number of packages to be reinstalled: 1

Proceed with this action? [y/N]: y
DBG(1)[76957]> want to upgrade advisory to exclusive lock
[1/1] Reinstalling python37-3.7.7...
[1/1] Extracting python37-3.7.7: 100%
DBG(1)[76957]> Cleaning up old version

or perl5:
Code:
# pkg -d install -f perl5
DBG(1)[77236]> pkg initialized
Updating FreeBSD repository catalogue...
DBG(1)[77236]> PkgRepo: verifying update for FreeBSD
DBG(1)[77236]> Pkgrepo, begin update of '/var/db/pkg/repo-FreeBSD.sqlite'
DBG(1)[77236]> Fetch: fetching from: http://pkgmir.geo.freebsd.org/FreeBSD:12:amd64/quarterly/meta.conf with opts "i"
DBG(1)[77236]> Fetch: fetching from: http://pkgmir.geo.freebsd.org/FreeBSD:12:amd64/quarterly/meta.txz with opts "i"
DBG(1)[77236]> Fetch: fetching from: http://pkgmir.geo.freebsd.org/FreeBSD:12:amd64/quarterly/packagesite.txz with opts "i"
FreeBSD repository is up to date.
All repositories are up to date.
DBG(1)[77236]> want to get an advisory lock on a database
DBG(1)[77236]> found stale pid 76957 in lock database, my pid is: 77236
DBG(1)[77236]> no concurrent processes found, cleanup the lock
DBG(1)[77236]> want to get an advisory lock on a database
DBG(1)[77236]> Binary> loading /var/cache/pkg/perl5-5.30.2-1dc1f8bd5e.txz
Checking integrity...DBG(1)[77236]> check integrity for 1 items added
 done (0 conflicting)
The following 1 package(s) will be affected (of 0 checked):

Installed packages to be REINSTALLED:
    perl5-5.30.2

Number of packages to be reinstalled: 1

Proceed with this action? [y/N]: y
DBG(1)[77236]> want to upgrade advisory to exclusive lock
[1/1] Reinstalling perl5-5.30.2...
[1/1] Extracting perl5-5.30.2: 100%
DBG(1)[77236]> Cleaning up old version
DBG(1)[77236]> Adding to deletion usr/local/lib/perl5/site_perl/man/man3/
DBG(1)[77236]> Adding to deletion usr/local/lib/perl5/site_perl/man/man1/
DBG(1)[77236]> Adding to deletion usr/local/lib/perl5/site_perl/mach/5.30/auto/
DBG(1)[77236]> Adding to deletion usr/local/lib/perl5/site_perl/auto/
DBG(1)[77236]> Number of packages owning the directory '/usr/local/lib/perl5/site_perl/man/man3': 1
DBG(1)[77236]> Number of packages owning the directory '/usr/local/lib/perl5/site_perl/man/man1': 1
DBG(1)[77236]> Number of packages owning the directory '/usr/local/lib/perl5/site_perl/mach/5.30/auto': 1
DBG(1)[77236]> Number of packages owning the directory '/usr/local/lib/perl5/site_perl/auto': 1

I am looking forward to any help.

-Tranalogic
 
Hi, suntzu00.

I had Version 1.13.2 installed. Now I installed 1.14.2 from the Ports tree and I have the same issue.
This are the last lines of the truss output from #truss -f pkg install -f python37
Code:
IGWINCH|SIGINFO|SIGUSR1|SIGUSR2 },{ }) = 0 (0x0)
81309: mprotect(0x800416000,36864,PROT_READ|PROT_WRITE) = 0 (0x0)
81309: sigprocmask(SIG_SETMASK,{ },0x0)         = 0 (0x0)
81309: sigprocmask(SIG_BLOCK,{ SIGHUP|SIGINT|SIGQUIT|SIGKILL|SIGPIPE|SIGALRM|SIGTERM|SIGURG|SIGSTOP|SIGTSTP|SIGCONT|SIGCHLD|SIGTTIN|SIGTTOU|SIGIO|SIGXCPU|SIGXFSZ|SIGVTALRM|SIGPROF|SIGWINCH|SIGINFO|SIGUSR1|SIGUSR2 },{ }) = 0 (0x0)
81309: mprotect(0x800416000,36864,PROT_READ)     = 0 (0x0)
81309: sigprocmask(SIG_SETMASK,{ },0x0)         = 0 (0x0)
81309: readlink("/etc/malloc.conf",0x7fffffffd910,1024) ERR#2 'No such file or directory'
81309: issetugid()                 = 0 (0x0)
81309: __sysctl(0x7fffffffd878,0x2,0x7fffffffd874,0x7fffffffd880,0x0,0x0) = 0 (0x0)
81309: mmap(0x0,4096,PROT_READ|PROT_WRITE,MAP_PRIVATE|MAP_ANON,-1,0x0) = 34362146816 (0x80024c000)
81309: madvise(0x80024c000,4096,MADV_FREE)     = 0 (0x0)
81309: munmap(0x80024c000,4096)             = 0 (0x0)
81309: mmap(0x0,2097152,PROT_READ|PROT_WRITE,MAP_PRIVATE|MAP_ANON,-1,0x0) = 34366316544 (0x800646000)
81309: munmap(0x800646000,2097152)         = 0 (0x0)
81309: mmap(0x0,4190208,PROT_READ|PROT_WRITE,MAP_PRIVATE|MAP_ANON,-1,0x0) = 34366316544 (0x800646000)
81309: munmap(0x800646000,1810432)         = 0 (0x0)
81309: munmap(0x800a00000,282624)         = 0 (0x0)
81309: mmap(0x0,32768,PROT_READ|PROT_WRITE,MAP_PRIVATE|MAP_ANON,-1,0x0) = 34366316544 (0x800646000)
81309: mmap(0x0,4194304,PROT_READ|PROT_WRITE,MAP_PRIVATE|MAP_ANON,-1,0x0) = 34370224128 (0x800a00000)
81309: mmap(0x0,4096,PROT_READ|PROT_WRITE,MAP_PRIVATE|MAP_ANON,-1,0x0) = 34362146816 (0x80024c000)
81309: sigprocmask(SIG_BLOCK,{ SIGHUP|SIGINT|SIGQUIT|SIGKILL|SIGPIPE|SIGALRM|SIGTERM|SIGURG|SIGSTOP|SIGTSTP|SIGCONT|SIGCHLD|SIGTTIN|SIGTTOU|SIGIO|SIGXCPU|SIGXFSZ|SIGVTALRM|SIGPROF|SIGWINCH|SIGINFO|SIGUSR1|SIGUSR2 },{ }) = 0 (0x0)
81309: sigprocmask(SIG_SETMASK,{ },0x0)         = 0 (0x0)
81309: sigprocmask(SIG_BLOCK,{ SIGHUP|SIGINT|SIGQUIT|SIGKILL|SIGPIPE|SIGALRM|SIGTERM|SIGURG|SIGSTOP|SIGTSTP|SIGCONT|SIGCHLD|SIGTTIN|SIGTTOU|SIGIO|SIGXCPU|SIGXFSZ|SIGVTALRM|SIGPROF|SIGWINCH|SIGINFO|SIGUSR1|SIGUSR2 },{ }) = 0 (0x0)
81309: mprotect(0x207000,4096,PROT_READ)     = 0 (0x0)
81309: sigprocmask(SIG_SETMASK,{ },0x0)         = 0 (0x0)
81309: __sysctl(0x7fffffffe3b0,0x2,0x7fffffffe350,0x7fffffffdb50,0x7fffffffdf50,0xf) = 0 (0x0)
81309: __sysctl(0x7fffffffe7b0,0x4,0x7fffffffe3b0,0x7fffffffd748,0x0,0x0) = 0 (0x0)
81309: __sysctl(0x7fffffffc5e0,0x4,0x7fffffffca50,0x7fffffffc5d0,0x0,0x0) = 0 (0x0)
81309: __sysctl(0x7fffffffd650,0x4,0x7fffffffd250,0x7fffffffc5d8,0x0,0x0) = 0 (0x0)
81309: __sysctl(0x7fffffffe350,0x2,0x0,0x7fffffffc5d0,0x0,0x0) = 0 (0x0)
81309: mmap(0x0,4096,PROT_READ|PROT_WRITE,MAP_PRIVATE|MAP_ANON,-1,0x0) = 34366349312 (0x80064e000)
81309: __sysctl(0x7fffffffe350,0x2,0x80064e000,0x7fffffffd250,0x0,0x0) = 0 (0x0)
81309: write(1,"amd64",5)             = 5 (0x5)
81300: read(3,"amd64",128)             = 5 (0x5)
81309: write(1,"\n",1)                 = 1 (0x1)
81300: read(3,"\n",128)                 = 1 (0x1)
81309: sigprocmask(SIG_BLOCK,{ SIGHUP|SIGINT|SIGQUIT|SIGKILL|SIGPIPE|SIGALRM|SIGTERM|SIGURG|SIGSTOP|SIGTSTP|SIGCONT|SIGCHLD|SIGTTIN|SIGTTOU|SIGIO|SIGXCPU|SIGXFSZ|SIGVTALRM|SIGPROF|SIGWINCH|SIGINFO|SIGUSR1|SIGUSR2 },{ }) = 0 (0x0)
81309: sigprocmask(SIG_SETMASK,{ },0x0)         = 0 (0x0)
81309: sigprocmask(SIG_BLOCK,{ SIGHUP|SIGINT|SIGQUIT|SIGKILL|SIGPIPE|SIGALRM|SIGTERM|SIGURG|SIGSTOP|SIGTSTP|SIGCONT|SIGCHLD|SIGTTIN|SIGTTOU|SIGIO|SIGXCPU|SIGXFSZ|SIGVTALRM|SIGPROF|SIGWINCH|SIGINFO|SIGUSR1|SIGUSR2 },{ }) = 0 (0x0)
81309: sigprocmask(SIG_SETMASK,{ },0x0)         = 0 (0x0)
81309: sigprocmask(SIG_BLOCK,{ SIGHUP|SIGINT|SIGQUIT|SIGKILL|SIGPIPE|SIGALRM|SIGTERM|SIGURG|SIGSTOP|SIGTSTP|SIGCONT|SIGCHLD|SIGTTIN|SIGTTOU|SIGIO|SIGXCPU|SIGXFSZ|SIGVTALRM|SIGPROF|SIGWINCH|SIGINFO|SIGUSR1|SIGUSR2 },{ }) = 0 (0x0)
81309: sigprocmask(SIG_SETMASK,{ },0x0)         = 0 (0x0)
81300: read(3,0x7fffffffd9c0,128)         = 0 (0x0)
81300: close(3)                     = 0 (0x0)
81309: exit(0x0)               
81309: process exit, rval = 0
81300: wait4(-1,{ EXITED,val=0 },0x0,0x0)     = 81309 (0x13d9d)
81300: exit(0x0)               
81300: process exit, rval = 0
81292: wait4(-1,{ EXITED,val=0 },0x0,0x0)     = 81300 (0x13d94)
81292: read(10,0x2299d0,1024)             = 0 (0x0)
81292: exit(0x0)               
81292: process exit, rval = 0
81291: wait4(-1,{ EXITED,val=0 },0x0,0x0)     = 81292 (0x13d8c)
81291: exit(0x0)               
81291: process exit, rval = 0

and this is an output of #ps aux:
Code:
root       81287   0,0  0,0  11476   2436  2  I+   12:33          0:17,86 truss -f pkg install -f python37
root       81288   0,0  0,5  91956  82200  2  IX+  12:33          0:13,18 pkg install -f python37
root       81291   0,0  0,0      0      0  2  Z+   12:34          0:00,07 <defunct>

I can kill the 81291 PID, but the Process doesn't get stopped. When I try a #truss -f -p 81291, truss won't find the PID, but its still on ps. I don't know what else I can do. With pkg Version 1.12.x all worked perfectly. Maybe there is a Problem with the SQLite Database? I don't know where to find it. The Machine is just a host for Jails. It's only iocage, fail2ban, apcupsd and its dependencies installed. (all from pkg, not compiled from the Ports tree)


-Tranalogic
 
Hey guys!

I've solved it. The problem was, we use, from an old installation, expiretable for SSH unblocking. This is how we start expiretable from our rc.conf:
Code:
expiretable_enable = "YES"
expiretable_flags = "- v -d -t 24h bruteforce"
/usr/local/sbin/expiretable -v -d -t 24h bruteforce

With this way, expiretable gets started for over 20 times. I was surprised, why a new process got a PID over 70000. However, I stopped and killed expiretable, pkg works now perfectly. I try to change to blacklistd for SSH.

Thanks a lot for your help. I try to change the title of this Thread to solved.

-Tranalogic
 
Last edited by a moderator:
NEVER put commands in rc.conf. This file is sourced numerous times by all the various rc(8) scripts and your command would get executed each and every time it is sourced.

Why did you put it there in the first place? All you needed is expiretable_enable="YES" to get the service started. And check your spaces, not sure if it's because of a copy/paste error but you have a space between the variable and the equal sign.
Code:
expiretable_enable = "YES"  # This doesn't  work
expiretable_enable= "YES"    # This works
 
Back
Top