error updating chronyd.service: cpio: lsetfilecon

[Jeff Johnson]

tracker.

This bug indicates the complexity of handling SELinux policy
upgrades WHILE INSTALLING where a change to the security policy metadata
needs to track (through what may be a netlink callback, ick) and
reopen a just changed file as part of the installation.

The better engineering (imho) is to pin down the point in time where
policy can be changed. The easiest time point to understand
is "before anything else is done" which is the %pretrans stage in
rpm's state machines. The main issue there is that %pretrans dependency
assertions are moderately difficult to accommodate if scripting
(through #!/bin/sh) is used.

The other time points that are well defined are "after everything has been installed"
with a delayed relabeling. Its also feasible to attempt "just in time labeling"
by integrating the labeling needs within RPM's topological sort (as the
Tresys patch -- so far unused in production -- @rpm.org is attempting).

Avoiding the need for dependency assertions if %pretrans is written in
shell scripts is in fact why embeddings for lua (and perl/python/tcl/ruby/javascript/more)
were undertaken @rpm5.org. The chosen embedding @rpm5.org development
is kavascript, but there are various advantages/disadvantages to other embeddings,
too numerous to mention, and out-of-scope for this bug report: the relevant
portion is that embedding rather than invoking /bin/sh scripts avoids the
need for dependency assertions in %pretrans).

Note that semanage embedding into @rpm5.org code has also been started, is
perhaps 50% done, with embedded javascript bindings under unit test, and
more) but there hasn't been any reason (till SELinux -> ROSA) to pursue the
ability to undertake installing SELinux policy incrementally @rpm5.org.

[John (john-redhat-bugs)]

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:

[Miroslav (miroslav-redhat-bugs)]

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

[Panu (panu-redhat-bugs)]

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

[John (john-redhat-bugs)]

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.

[Panu (panu-redhat-bugs)]

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...

[John (john-redhat-bugs)]

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
-----

[John (john-redhat-bugs)]

(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.

[Richard (richard-redhat-bugs)]

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

[John (john-redhat-bugs)]

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.

[Daniel (daniel-redhat-bugs)]

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.

[Ales (ales-redhat-bugs)]

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.

[Daniel (daniel-redhat-bugs)]

Ales what did you see?

[Ales (ales-redhat-bugs)]

(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]#

[Ales (ales-redhat-bugs)]

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?

[Ales (ales-redhat-bugs)]

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

[Daniel (daniel-redhat-bugs)]

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.

[Ales (ales-redhat-bugs)]

> 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?

[Daniel (daniel-redhat-bugs)]

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

[Daniel (daniel-redhat-bugs)]

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.

[Ales (ales-redhat-bugs)]

Patch posted for a review:

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

[Ales (ales-redhat-bugs)]

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

[Jeff Johnson (n3npq)]

here is the patch that was just checked in to fix the attached problem:

    http://bazaar.launchpad.net/~rpm5/rpm/rpm.org/revision/11237

[Jeff Johnson (n3npq)]

here are Tizen's (nee MeeGo's) attempts to (re|ab)-use the Tresys patch for
the purposes of modularly/opaquely extending RPM's state machine to
install blobs of metadata opaquely carried in *.rpm header's:
    http://lists.rpm.org/pipermail/rpm-maint/2011-December/003135.html

[Jeff Johnson (n3npq)]

here is the final (it took ~2 years to craft an acceptable patch) Tresys
patch that Tizen (and Selinux) are attempting to extend RPM's state
machine through modular hooking:
    http://lists.rpm.org/pipermail/rpm-maint/2010-June/002762.html

Note that -- IF THIS PATCH IS USED -- the blob's will increase the
size of /var/lib/rpm/Packages significantly: the uncompressed
size of the blobs was estimated at ~40Mb.

The bzip2 compression makes the information opaque to rpm queries,
and also adds additional performance overhead to remove the chosen
bzip2 compression in order to access the STILL OPAQUE gunk inside.

[Jeff Johnson (n3npq)]

Also note the consequences of adding SELinux policy metadata directly in
*.rpm headers.

An rpmdb has a KISS (and rather generally extensible) scheme that is essentially
equivalent to an "inverted list"; i.e. a KEY -> VAL association is optimized by creating
an index for VAL -> BLOB and then doing a secondary lookup within a header to
retrieve the information that is desired.

The point relevant here isn't whether compression saves bytes (it does) or
whether its valid to argue that 40Mb of uncompressed data is relevant to
the actual size of the information stored in /var/lib/rpm/Packages, but
rather that the additional SELinux policy metadata -- WITH SIGNIFICANT SIZE --
is an I/O performance cost for EVERY retrieval, not just for the accesses
of the security sensitive data that SELinux and Tizen are adding to *.rpm packaging.

Undertaking the schema changes necessary to avoid the additional performance cost
imposed by the added security metadata is way out-of-scope for this bug report, and
is essentially equivalent to writing an entire package manager from scratch.

RPM's success has been from the crude (but simple) transfer of a blob of metadata
from a *.rpm package directly into /var/lib/rpm/Packages WITH NO OTHER CHANGES.