error updating chronyd.service: cpio: lsetfilecon

Description of problem: "yum update" from
---> Package chrony.x86_64 0:1.26-2.fc16 will be updated
---> Package chrony.x86_64 0:1.26-3.20110831gitb088b7.fc16 will be an update
gives an error.

Version-Release number of selected component (if applicable):

How reproducible:

Steps to Reproduce:
1. "yum update" # from Fedora 16 beta x86_64 DVD to fedora.repo and fedora-updates-testing.repo of Oct.13 (Thurs.)
2.
3.

Actual results:
---> Package chrony.x86_64 0:1.26-2.fc16 will be updated
---> Package chrony.x86_64 0:1.26-3.20110831gitb088b7.fc16 will be an update
 chrony x86_64 1.26-3.20110831gitb088b7.fc16
(15/210): chrony-1.26-2.fc16_1.26-3.20110831gitb088b7.fc16.x86_ | 163 kB 00:00
  Updating : chrony-1.26-3.20110831gitb088b7.fc16.x86_64 339/803
Error unpacking rpm package chrony-1.26-3.20110831gitb088b7.fc16.x86_64
error: unpacking of archive failed on file /lib/systemd/system/chronyd.service: cpio: lsetfilecon
error: chrony-1.26-3.20110831gitb088b7.fc16.x86_64: install failed
error: chrony-1.26-2.fc16.x86_64: erase skipped
chrony-1.26-2.fc16.x86_64 was supposed to be removed but is not!

Expected results: Success.

Additional info:

This looks like an rpm problem or somewhere close to it.

It's failing to set the selinux context on /lib/systemd/system/chronyd.service. If you can try updating it manually with debugging enabled, that might give some further clues:

rpm -Uvvh --fsmdebug chrony-1.26-3.20110831gitb088b7.fc16.x86_64.rpm

Created attachment 528557
transcript of "rpm -Uvvh --fsmdebug chrony-1.26-3.20110831gitb088b7.fc16.x86_64.rpm"

Apparently the original "yum update" succeeded, because the first attempt at
   rpm -Uvvh --fsmdebug chrony-1.26-3.20110831gitb088b7.fc16.x86_64.rpm
said that version was already installed. So I "yum erase chrony", then ran rpm again. The attachment is the console output. I see no complaints this time.

Unfortunately log of success doesn't really help figuring out what went wrong the first time :)

Was there a selinux-policy[-targeted] update involved in the original transaction where the upgrade failed, and if so, what were their versions (/var/log/yum.log and/or yum history should have this information)?

I suspect this was a transient error caused selinux-policy changing incompatibly within the transaction (afaict selinux-policy has seen quite some changes recently), in which case there's not a whole lot that can be done about it with the currently available mechanisms: rpm loads the contexts at the beginning of transaction and if some of those contexts significantly change/go away, you'll see errors like this as rpm is trying to use the contexts that were defined when the transaction started. Or so the theory goes...

Yes, it looks like selinux-* was in the same update batch. The "ts_done name in te is ... should be ..." is peculiar (several places).

From /var/log/yum.log:

:g/chrony/p # all lines containing 'chrony'
Oct 13 12:15:11 chrony-1.26-3.20110831gitb088b7.fc16.x86_64: 100
Oct 13 12:19:04 systemd-sysv-35-1.fc16.x86_64: ts_done name in te is chrony should be systemd-sysv-35-1.fc16.x86_64
Oct 16 08:18:35 Updated: chrony-1.26-3.20110831gitb088b7.fc16.x86_64

:g/selinux/p # all lines containing 'selinux'
Oct 13 12:05:27 Updated: libselinux-2.1.5-5.1.fc16.x86_64
Oct 13 12:08:35 Updated: libselinux-utils-2.1.5-5.1.fc16.x86_64
Oct 13 12:09:24 Updated: libselinux-python-2.1.5-5.1.fc16.x86_64
Oct 13 12:11:29 Updated: selinux-policy-3.10.0-38.fc16.noarch
Oct 13 12:14:40 Updated: selinux-policy-targeted-3.10.0-38.fc16.noarch
Oct 13 12:18:45 selinux-policy-3.10.0-32.fc16.noarch: ts_done name in te is dhcp-libs should be selinux-policy-3.10.0-32.fc16.noarch
Oct 13 12:18:45 policycoreutils-2.0.86-18.fc16.x86_64: ts_done name in te is selinux-policy should be policycoreutils-2.0.86-18.fc16.x86_64
Oct 13 12:18:46 libselinux-utils-2.1.5-5.fc16.x86_64: ts_done name in te is policycoreutils should be libselinux-utils-2.1.5-5.fc16.x86_64
Oct 13 12:18:46 xmlrpc-c-1.27.0-1600.svn2145.fc16.x86_64: ts_done name in te is libselinux-utils should be xmlrpc-c-1.27.0-1600.svn2145.fc16.x86_64
Oct 13 12:18:47 libselinux-python-2.1.5-5.fc16.x86_64: ts_done name in te is abrt-libs should be libselinux-python-2.1.5-5.fc16.x86_64
Oct 13 12:18:48 libsemanage-python-2.0.46-6.fc16.x86_64: ts_done name in te is libselinux-python should be libsemanage-python-2.0.46-6.fc16.x86_64
Oct 13 12:19:55 libselinux-2.1.5-5.fc16.x86_64: ts_done name in te is lohit-gujarati-fonts should be libselinux-2.1.5-5.fc16.x86_64
Oct 13 12:19:56 glibc-2.14.90-8.x86_64: ts_done name in te is libselinux should be glibc-2.14.90-8.x86_64
Oct 16 08:17:56 Updated: selinux-policy-3.10.0-40.fc16.noarch
Oct 16 08:18:19 Updated: selinux-policy-targeted-3.10.0-40.fc16.noarch
-----

(In reply to comment #4)

> I suspect this was a transient error caused selinux-policy changing
> incompatibly within the transaction (afaict selinux-policy has seen quite some
> changes recently), in which case there's not a whole lot that can be done about
> it with the currently available mechanisms: rpm loads the contexts at the
> beginning of transaction and if some of those contexts significantly change/go
> away, you'll see errors like this as rpm is trying to use the contexts that
> were defined when the transaction started. Or so the theory goes...

The specific error message may be transient, but I would call this a _design_ failure in BOTH rpm and selinux. Rpm has failed to preserve transaction integrity, and selinux is a willing accomplice. The only workaround is for rpm to require that no other modules may accompany selinux-* in the same transaction.

I'm seeing a couple of these on a random 'yum update' to Rawhide
today:

[...]

  Updating : nspluginwrapper-1.4.4-2.fc17.x86_64 724/1746
Error unpacking rpm package nspluginwrapper-1.4.4-2.fc17.x86_64
error: unpacking of archive failed on file /usr/lib64/nspluginwrapper/npviewer.bin: cpio: lsetfilecon
  Updating : sudo-1.8.3p1-1.fc17.x86_64 725/1746
error: nspluginwrapper-1.4.4-2.fc17.x86_64: install failed
  Updating : pam_pkcs11-0.6.2-7.fc17.x86_64 726/1746
  Updating : nss-tools-3.13.1-5.fc17.x86_64 727/1746
  Updating : 32:bind-utils-9.9.0-0.3.b2.fc17.x86_64 728/1746
  Updating : jnr-posix-1.1.8-1.fc17.noarch 729/1746
  Updating : 1:java-1.6.0-openjdk-devel-1.6.0.0-61.1.10.4.fc17.x8 730/1746
Error unpacking rpm package 1:java-1.6.0-openjdk-devel-1.6.0.0-61.1.10.4.fc17.x86_64
error: unpacking of archive failed on file /usr/lib/jvm/java-1.6.0-openjdk-1.6.0.0.x86_64/bin/appletviewer: cpio: lsetfilecon
  Updating : joda-time-1.6.2-6.tzdata2011f.fc17.noarch 731/1746
error: java-1.6.0-openjdk-devel-1:1.6.0.0-61.1.10.4.fc17.x86_64: install failed

[...]

SELinux policy versions before and after the update:

selinux-policy-3.10.0-24.fc17.noarch
selinux-policy-3.10.0-65.fc17.noarch

I have filed Bug #765910 against selinux-policy for not getting together with "yum update" to prevent these problems. I believe that selinux-policy should be updated only by itself, and never in a batch with any other package.

In Fedora 17 I remove nsplugin.pp and merged with mozilla_plugin. So this is a case where the update should have setup alias so this would work properly.

The best case would be to specify policy files somehow in the payload and then have rpm execute a transaction before laying down additional files. Or adding a mechanism for a package to tell rpm to reload its labeling.

OK, I can reproduce this locally in a f16 machine by updating:

selinux-policy-3.10.0-32.fc16.noarch
selinux-policy-targeted-3.10.0-32.fc16.noarch
chrony-1.26-2.fc16.x86_64

to:

selinux-policy-targeted-3.10.0-38.fc16.noarch
selinux-policy-3.10.0-38.fc16.noarch
chrony-1.26-3.20110831gitb088b7.x86_64.

selinux has to be enforcing.

Ales what did you see?

(In reply to comment #11)
> Ales what did you see?

Something similar to what John saw in comment 0:

[root@dhcp-25-135 data]# rpm -Uvh chrony-1.26-3.20110831gitb088b7.fc16.x86_64.rpm selinux-policy-3.10.0-38.fc16.noarch.rpm selinux-policy-targeted-3.10.0-38.fc16.noarch.rpm
Preparing... ########################################### [100%]
   1:selinux-policy ########################################### [ 33%]
   2:selinux-policy-targeted########################################### [ 67%]
   3:chrony ########################################### [100%]
error: unpacking of archive failed on file /lib/systemd/system/chronyd.service: cpio: lsetfilecon failed - Invalid argument
error: chrony-1.26-3.20110831gitb088b7.fc16.x86_64: install failed
error: chrony-1.26-2.fc16.x86_64: erase skipped
[root@dhcp-25-135 data]#

I would like to sum this up so everyone is on the same
page. There is one latent and one real issue here:

Latent one: rpm currently does not know which packages in a
transaction change selinux policices. Those should be processed
first so the new policies can be used for later transaction
elements (see bug 760793). As far as I understand it, the rpm
sepolicy plugin (disabled now) can be a first step in remedy of
this but package specs will need to use some new selinux tags.

The real one: before starting the transaction, rpm calls
selabel_open(SELABEL_CTX_FILE, ...) and stores the returned
handle for the entire transaction's duration. If (as in this
case) we are upgrading selinux-policy early and that involves
upgrading the context db (not all selinux-policy updates update
the contexts), the handle we remembered can no longer be used:
the call to selabel_lookup_raw(handle, ...) provides a valid
non-null context but a later lsetfilecon() fails. In other words
it seems that the handle is no longer valid after this particular
selinux-policy update.

What are the options to fix the second problem for F16:

1) close and reopen the label handle after each processed
transaction element. this is ugly and probably expensive (how
expensive?).

2) suitable selinux callback where we will update the handle:
selinux_set_callback() with SELINUX_CB_POLICYLOAD could be it but
unfortunately it won't let us give it a callback void* for the
transaction.

3) other callback to do the same -- e.g. is avc_open an option?

4) have selinux keep the handle always valid even after policy
changes. Is that possible?

Selinux guys -- which way do you consider the optimal?

Eric, Miroslav suggested asking you---how would you recommend we deal with this?

1) Definitely no

2) This would be my selection Not sure what problem you were seeing when handing it the callback. udev and dbus use this interface now.This should happen very infrequently, within a transaction.

3) setlinux_set_callback is the correct callback

4) Doing it internally would be problematic, I guess we could return an error if the file_context file changed, but that could be costly.

> 2) This would be my selection Not sure what problem you were seeing when
> handing it the callback. udev and dbus use this interface now.This should

Let me explain in more detail: typically, callback setting functions accept two parameters: a pointer to a function (i.e. the callback handler) to call when an event occurs and a void pointer. The void pointer is just stored by the framework/library and when the handler is invoked it is passed this pointer. The handler uses the pointer to store information it needs to perform the handling (in our case the pointer would point to the transaction structure).

IOW, what we need is the SELINUX_CB_POLICYLOAD prototype to instead of:

int (*func_policyload) (int seqno)

be:

int (*func_policyload) (int seqno, void *data), where data would the value we'd provide to selinux_set_callback().

Should I open a BZ for selinux requesting this change, or are there other options for us still?

Stephen, will setfscreatcon or any of the labeling function calls, cause the selinux_cb_polyload callback to fire?

One suggestion we have come up with is for rpm to call selinux_status_updated before each package labels are going to be put down. This should fix the biggest problem. Only problem with this is what happens if the labeling is modified in the #pre section of the transaction. But I think this is a lot better then where we are now.

Patch posted for a review:

http://lists.rpm.org/pipermail/rpm-maint/2011-December/003143.html

Patch 7a8b75d26605cf7a3fde9f624a80d6fb8390fcbd on rpm master branch deals with this specific selinux error.