btrfs-defrag-pl defuncts after zypper update

As soon as I update or remove a package from my system, this is what happens:


root      2935  0.0  0.0      0     0 pts/1    Z+   22:35   0:00 [btrfs-defrag-pl] <defunct>
root      2936  0.0  0.0      0     0 pts/1    Z+   22:35   0:00 [snapper.py] <defunct>

Any ideas ?

More info from the zypper.log file:


2016-07-17 23:53:22 <1> macbook(2159) [zypper++] prompt.cc(getReplyIndex):107  reply: y (y lowercase)
2016-07-17 23:53:22 <1> macbook(2159) [zypper++] prompt.cc(getReplyIndex):112 index: 0 option: y
2016-07-17 23:53:22 <1> macbook(2159) [zypper] prompt.cc(get_prompt_reply):337 reply: y (0)
2016-07-17 23:53:22 <1> macbook(2159) [zypper] solve-commit.cc(solve_and_commit):765 committing...
2016-07-17 23:53:22 <1> macbook(2159) [zypper] solve-commit.cc(get_commit_policy):419 Using commit policy: CommitPolicy( DownloadDefault )
2016-07-17 23:53:22 <1> macbook(2159) [zypp] ZYppImpl.cc(commit):157 Attempt to commit (CommitPolicy( DownloadDefault ))
2016-07-17 23:53:22 <1> macbook(2159) [zypp] TargetImpl.cc(commit):1113 TargetImpl::commit(<pool>, CommitPolicy( DownloadInHeaps ))
2016-07-17 23:53:22 <1> macbook(2159) [libsolv++] PoolImpl.cc(logSat):114 ordering transaction
2016-07-17 23:53:22 <1> macbook(2159) [libsolv++] PoolImpl.cc(logSat):114 transaction elements: 1
2016-07-17 23:53:22 <1> macbook(2159) [libsolv++] PoolImpl.cc(logSat):114 edges: 0, edge space: 0
2016-07-17 23:53:22 <1> macbook(2159) [libsolv++] PoolImpl.cc(logSat):114 edge creation took 0 ms
2016-07-17 23:53:22 <1> macbook(2159) [libsolv++] PoolImpl.cc(logSat):114 cycles broken: 0
2016-07-17 23:53:22 <1> macbook(2159) [libsolv++] PoolImpl.cc(logSat):114 cycle breaking took 0 ms
2016-07-17 23:53:22 <1> macbook(2159) [libsolv++] PoolImpl.cc(logSat):114 cycle edge creation took 0 ms
2016-07-17 23:53:22 <1> macbook(2159) [libsolv++] PoolImpl.cc(logSat):114 invedge space: 3
2016-07-17 23:53:22 <1> macbook(2159) [libsolv++] PoolImpl.cc(logSat):114 creating new transaction took 0 ms
2016-07-17 23:53:22 <1> macbook(2159) [libsolv++] PoolImpl.cc(logSat):114 transaction ordering took 0 ms
2016-07-17 23:53:22 <1> macbook(2159) [zypp] TargetImpl.cc(commit):1139 Todo: CommitResult  (total 1, done 0, error 0, skipped 1, updateMessages 0)
2016-07-17 23:53:22 <1> macbook(2159) [zypp::plugin++] PluginExecutor.cc(load):53 +++++++++++++++ load /usr/lib/zypp/plugins/commit{d 0755 0/0}
2016-07-17 23:53:22 <1> macbook(2159) [zypp] PathInfo.cc(dirForEach):553 readdir /usr/lib/zypp/plugins/commit 
2016-07-17 23:53:22 <1> macbook(2159) [zypp::plugin] PluginExecutor.cc(doLoad):104 Load plugin: /usr/lib/zypp/plugins/commit/btrfs-defrag-plugin.py{- 0755 0/0 size 2172}
2016-07-17 23:53:22 <1> macbook(2159) [zypp::plugin++] PluginScript.cc(open):193 Open /usr/lib/zypp/plugins/commit/btrfs-defrag-plugin.py()
2016-07-17 23:53:22 <1> macbook(2159) [zypp++] ExternalProgram.cc(start_program):249 Executing '/usr/lib/zypp/plugins/commit/btrfs-defrag-plugin.py'
2016-07-17 23:53:22 <1> macbook(2159) [zypp++] ExternalProgram.cc(start_program):412 pid 2161 launched
2016-07-17 23:53:22 <1> macbook(2159) [zypp::plugin++] PluginScript.cc(open):222 PluginScript[2161] /usr/lib/zypp/plugins/commit/btrfs-defrag-plugin.py()
2016-07-17 23:53:22 <1> macbook(2159) [zypp::plugin++] PluginScript.cc(send):272 PluginScript[2161] /usr/lib/zypp/plugins/commit/btrfs-defrag-plugin.py ->send PluginFrame[PLUGINBEGIN](0){0}
2016-07-17 23:53:22 <1> macbook(2159) [zypp::plugin++] PluginScript.cc(receive):426 PluginScript[2161] /usr/lib/zypp/plugins/commit/btrfs-defrag-plugin.py <-PluginFrame[ACK](0){0}
2016-07-17 23:53:22 <1> macbook(2159) [zypp::plugin++] PluginExecutor.cc(load):80 --------------- load /usr/lib/zypp/plugins/commit{d 0755 0/0}
2016-07-17 23:53:22 <1> macbook(2159) [zypp::plugin++] PluginExecutor.cc(send):85 +++++++++++++++ send PluginFrame[COMMITBEGIN](0){113}
2016-07-17 23:53:22 <1> macbook(2159) [zypp::plugin++] PluginScript.cc(send):272 PluginScript[2161] /usr/lib/zypp/plugins/commit/btrfs-defrag-plugin.py ->send PluginFrame[COMMITBEGIN](0){113}
2016-07-17 23:53:22 <1> macbook(2159) [zypp::plugin++] PluginScript.cc(receive):426 PluginScript[2161] /usr/lib/zypp/plugins/commit/btrfs-defrag-plugin.py <-PluginFrame[_ENOMETHOD](1){0}
2016-07-17 23:53:22 <1> macbook(2159) [zypp::plugin++] PluginExecutor.cc(send):94 --------------- send PluginFrame[COMMITBEGIN](0){113}
2016-07-17 23:53:22 <1> macbook(2159) [zypp++] TargetImpl.cc(commit):1231 commit log file is set to: /var/log/zypp/history
2016-07-17 23:53:22 <1> macbook(2159) [zypp] TargetImpl.commitFindFileConflicts.cc(commitFindFileConflicts):127 Checking for file conflicts in 0 new packages...
2016-07-17 23:53:22 <1> macbook(2159) [zypp] TargetImpl.cc(commit):1380 TargetImpl::commit(<list>CommitPolicy( DownloadInHeaps ))1
2016-07-17 23:53:22 <1> macbook(2159) [zypp] RpmDb.cc(doRemovePackage):2117 RpmDb::doRemovePackage(iotop-0.6-8.6.noarch,0x00000008)
2016-07-17 23:53:22 <1> macbook(2159) [zypp++] ExternalProgram.cc(start_program):249 Executing 'rpm' '--root' '/' '--dbpath' '/var/lib/rpm' '-e' '--allmatches' '--nodeps' '--' 'iotop-0.6-8.6.noarch'
2016-07-17 23:53:22 <1> macbook(2159) [zypp++] ExternalProgram.cc(start_program):412 pid 2162 launched
2016-07-17 23:53:22 <1> macbook(2159) [zypp++] ExternalProgram.cc(checkStatus):513 Pid 2162 successfully completed
2016-07-17 23:53:22 <1> macbook(2159) [Progress++] ProgressData.cc(report):88 {#6|Removing iotop-0.6-8.6.noarch}END
2016-07-17 23:53:22 <1> macbook(2159) [zypp::plugin++] PluginExecutor.cc(send):85 +++++++++++++++ send PluginFrame[COMMITEND](0){128}
2016-07-17 23:53:22 <1> macbook(2159) [zypp::plugin++] PluginScript.cc(send):272 PluginScript[2161] /usr/lib/zypp/plugins/commit/btrfs-defrag-plugin.py ->send PluginFrame[COMMITEND](0){128}
2016-07-17 23:53:22 <1> macbook(2159) [zypp::plugin++] PluginScript.cc(receive):426 PluginScript[2161] /usr/lib/zypp/plugins/commit/btrfs-defrag-plugin.py <-PluginFrame[_ENOMETHOD](1){0}
2016-07-17 23:53:22 <1> macbook(2159) [zypp::plugin++] PluginExecutor.cc(send):94 --------------- send PluginFrame[COMMITEND](0){128}
2016-07-17 23:53:22 <1> macbook(2159) [zypp] PathInfo.cc(dirForEach):553 readdir /etc/products.d 
2016-07-17 23:53:22 <1> macbook(2159) [zypp] TargetImpl.cc(buildCache):848 Read cookie: /var/cache/zypp/solv/@System/cookie{- 0644 0/0 size 52}
2016-07-17 23:53:22 <1> macbook(2159) [zypp] TargetImpl.cc(buildCache):855 Read cookie: /var/cache/zypp/solv/@System/cookie says: outdated
2016-07-17 23:53:22 <1> macbook(2159) [zypp++] ExternalProgram.cc(start_program):249 Executing 'rpmdb2solv' '-r' '/' '-X' '-A' '-p' '/etc/products.d' '/var/cache/zypp/solv/@System/solv' '-o' '/var/cache/zypp/solv/@System/solvXCWeRb'
2016-07-17 23:53:22 <1> macbook(2159) [zypp++] ExternalProgram.cc(start_program):412 pid 2163 launched
2016-07-17 23:53:22 <1> macbook(2159) [zypp++] ExternalProgram.cc(checkStatus):513 Pid 2163 successfully completed
2016-07-17 23:53:22 <1> macbook(2159) [zypp] PathInfo.cc(rename):673 rename /var/cache/zypp/solv/@System/solvXCWeRb -> /var/cache/zypp/solv/@System/solv
2016-07-17 23:53:22 <1> macbook(2159) [zypp] PathInfo.cc(chmod):1021 chmod /var/cache/zypp/solv/@System/solv 00644
2016-07-17 23:53:23 <1> macbook(2159) [zypp::plugin++] PluginExecutor.cc(load):53 +++++++++++++++ load /usr/lib/zypp/plugins/system{d 0755 0/0}
2016-07-17 23:53:23 <1> macbook(2159) [zypp] PathInfo.cc(dirForEach):553 readdir /usr/lib/zypp/plugins/system 
2016-07-17 23:53:23 <1> macbook(2159) [zypp::plugin++] PluginExecutor.cc(load):80 --------------- load /usr/lib/zypp/plugins/system{d 0755 0/0}
2016-07-17 23:53:23 <1> macbook(2159) [zypp] TargetImpl.cc(commit):1351 TargetImpl::commit(<pool>, CommitPolicy( DownloadInHeaps )) returns: CommitResult  (total 1, done 1, error 0, skipped 0, updateMessages 0)
2016-07-17 23:53:23 <1> macbook(2159) [zypp::plugin++] PluginExecutor.cc(send):85 +++++++++++++++ send PluginFrame[PLUGINEND](0){0}
2016-07-17 23:53:23 <1> macbook(2159) [zypp::plugin++] PluginScript.cc(send):272 PluginScript[2161] /usr/lib/zypp/plugins/commit/btrfs-defrag-plugin.py ->send PluginFrame[PLUGINEND](0){0}
2016-07-17 23:53:23 <1> macbook(2159) [zypp::plugin++] PluginScript.cc(receive):426 PluginScript[2161] /usr/lib/zypp/plugins/commit/btrfs-defrag-plugin.py <-PluginFrame[ACK](0){0}
2016-07-17 23:53:23 <1> macbook(2159) [zypp::plugin++] PluginExecutor.cc(send):94 --------------- send PluginFrame[PLUGINEND](0){0}
2016-07-17 23:53:23 <1> macbook(2159) [zypp::plugin++] PluginScript.cc(close):229 Close:PluginScript[2161] /usr/lib/zypp/plugins/commit/btrfs-defrag-plugin.py
2016-07-17 23:53:23 <1> macbook(2159) [zypp::plugin++] PluginScript.cc(send):272 PluginScript[2161] /usr/lib/zypp/plugins/commit/btrfs-defrag-plugin.py ->send PluginFrame[_DISCONNECT](0){0}
2016-07-17 23:53:23 <1> macbook(2159) [zypp::plugin++] PluginScript.cc(receive):426 PluginScript[2161] /usr/lib/zypp/plugins/commit/btrfs-defrag-plugin.py <-PluginFrame[ACK](1){10}
2016-07-17 23:53:23 <1> macbook(2159) [zypp::plugin++] PluginScript.cc(close):251 PluginScript[2161] /usr/lib/zypp/plugins/commit/btrfs-defrag-plugin.py -> [0] Disconnect
2016-07-17 23:53:23 <1> macbook(2159) [zypp++] ZYppImpl.cc(commit):173 unloading @System repo from pool
2016-07-17 23:53:23 <1> macbook(2159) [zypp] Repository.cc(eraseFromPool):300 sat::repo(@System){prio -99.0, size 2587} removed from pool
2016-07-17 23:53:23 <1> macbook(2159) [zypp::satpool] PoolImpl.cc(setDirty):228 _deleteRepo @System
2016-07-17 23:53:23 <1> macbook(2159) [zypp] ZYppImpl.cc(commit):178 Commit (CommitPolicy( DownloadDefault )) returned: CommitResult  (total 1, done 1, error 0, skipped 0, updateMessages 0)
2016-07-17 23:53:23 <1> macbook(2159) [zypper] solve-commit.cc(solve_and_commit):782 
2016-07-17 23:53:23 <1> macbook(2159) [zypper] solve-commit.cc(solve_and_commit):782 DONE
2016-07-17 23:53:23 <1> macbook(2159) [zypp++] ExternalProgram.cc(start_program):249 Executing 'lsof' '-n' '-FpcuLRftkn0'
2016-07-17 23:53:23 <1> macbook(2159) [zypp++] ExternalProgram.cc(start_program):412 pid 2167 launched

So, as you can see it hangs after running the command:

lsof -n -FpcuLRftkn0

so:


drpaneas@macbook:~> ps aux | grep 2167
root      2167  0.2  0.3  30792 13052 pts/0    S+   23:53   0:00 lsof -n -FpcuLRftkn0

In case it helps, here’s the last fraction of strace (lsof -n -FpcuLRftkn0)


poll({fd=7, events=POLLIN}], 1, 5000)  = 0 (Timeout)
socket(PF_NETLINK, SOCK_RAW, NETLINK_ROUTE) = 4
bind(4, {sa_family=AF_NETLINK, pid=0, groups=00000000}, 12) = 0
getsockname(4, {sa_family=AF_NETLINK, pid=2321, groups=00000000}, [12]) = 0
sendto(4, "\24\0\0\0\22\0\1\3\372\377\213W\0\0\0\0\0\0\0\0", 20, 0, {sa_family=AF_NETLINK, pid=0, groups=00000000}, 12) = 20
recvmsg(4, {msg_name(12)={sa_family=AF_NETLINK, pid=0, groups=00000000}, msg_iov(1)={"\214\4\0\0\20\0\2\0\372\377\213W\21	\0\0\0\0\4\3\1\0\0\0I\0\1\0\0\0\0\0"..., 4096}], msg_controllen=0, msg_flags=0}, 0) = 2328
recvmsg(4, {msg_name(12)={sa_family=AF_NETLINK, pid=0, groups=00000000}, msg_iov(1)={"\24\0\0\0\3\0\2\0\372\377\213W\21	\0\0\0\0\0\0", 4096}], msg_controllen=0, msg_flags=0}, 0) = 20
sendto(4, "\24\0\0\0\26\0\1\3\373\377\213W\0\0\0\0\0\0\0\0", 20, 0, {sa_family=AF_NETLINK, pid=0, groups=00000000}, 12) = 20
recvmsg(4, {msg_name(12)={sa_family=AF_NETLINK, pid=0, groups=00000000}, msg_iov(1)={"L\0\0\0\24\0\2\0\373\377\213W\21	\0\0\2\10\200\376\1\0\0\0\10\0\1\0\177\0\0\1"..., 4096}], msg_controllen=0, msg_flags=0}, 0) = 164
recvmsg(4, {msg_name(12)={sa_family=AF_NETLINK, pid=0, groups=00000000}, msg_iov(1)={"H\0\0\0\24\0\2\0\373\377\213W\21	\0\0
\200\200\376\1\0\0\0\24\0\1\0\0\0\0\0"..., 4096}], msg_controllen=0, msg_flags=0}, 0) = 144
recvmsg(4, {msg_name(12)={sa_family=AF_NETLINK, pid=0, groups=00000000}, msg_iov(1)={"\24\0\0\0\3\0\2\0\373\377\213W\21	\0\0\0\0\0\0", 4096}], msg_controllen=0, msg_flags=0}, 0) = 20
close(4)                                = 0
futex(0x7fca05add000, FUTEX_WAKE_PRIVATE, 2147483647) = 0
write(2, "do_ypcall: clnt_call: RPC: Timed"..., 37do_ypcall: clnt_call: RPC: Timed out
) = 37
close(7)                                = 0
socket(PF_INET, SOCK_STREAM, IPPROTO_TCP) = 4
bind(4, {sa_family=AF_INET, sin_port=htons(0), sin_addr=inet_addr("0.0.0.0")}, 16) = 0
connect(4, {sa_family=AF_INET, sin_port=htons(111), sin_addr=inet_addr("127.0.0.1")}, 16) = 0
write(4, "\200\0\0008\17\330\263(\0\0\0\0\0\0\0\2\0\1\206\240\0\0\0\2\0\0\0\3\0\0\0\0"..., 60) = 60
poll({fd=4, events=POLLIN}], 1, 60000) = 1 ({fd=4, revents=POLLIN}])
read(4, "\200\0\0\34\17\330\263(\0\0\0\1\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0", 400) = 32
close(4)                                = 0
open("/var/yp/binding/suse.de.2", O_RDONLY) = 4
pread(4, "\1\0\0\0
\240\0\1\3\277\0\0", 12, 2) = 12
socket(PF_INET, SOCK_DGRAM|SOCK_CLOEXEC|SOCK_NONBLOCK, IPPROTO_UDP) = 7
bind(7, {sa_family=AF_INET, sin_port=htons(801), sin_addr=inet_addr("0.0.0.0")}, 16) = 0
setsockopt(7, SOL_IP, IP_RECVERR, [1], 4) = 0
close(4)                                = 0
close(7)                                = 0
socket(PF_INET, SOCK_STREAM, IPPROTO_TCP) = 4
bind(4, {sa_family=AF_INET, sin_port=htons(0), sin_addr=inet_addr("0.0.0.0")}, 16) = 0
connect(4, {sa_family=AF_INET, sin_port=htons(111), sin_addr=inet_addr("10.160.0.1")}, 16

I solved it by removing


yp-tools ypbind