Problems with Enterprise v5 derivatives

[neilwilson]

I'm having a bit of fun with CentOS 5 and SL 5 builds using the meta-appliance.

I'm using a JEOS appliance definition file.

name: JEOS
os:
  name: centos
  version: 5
appliances:
  - jeos

with a base jeos.appl file of:

name: JEOS
summary: RPM Based JEOS
hardware:
  partitions:
    "/":
      size: 5
      type: ext4

This setup works just fine with Enterprise 6 derivatives and Fedora builds.

On Enterprise 5 X86_64 derivatives the build issues a warning

W, [2012-07-03T08:53:19.088481 #19115]  WARN -- : Loading SELinux policy failed. SELinux may be not fully initialized.

and this seems to lead to errors in using the image:

Jul  3 09:19:01 srv-5qvia kernel: type=1400 audit(1341307140.893:31): avc:  denied  { read } for  pid=1725 comm="dbus-daemon" name="config" dev=vda1 ino=133576 scontext=system_u:system_r:system_dbusd_t:s0 tcontext=system_u:object_r:unlabeled_t:s0 tclass=file

Jul  3 09:19:01 srv-5qvia kernel: inode_doinit_with_dentry:  context_to_sid(unconfined_u:object_r:etc_t:s0) returned 22 for dev=vda1 ino=132373

Jul  3 09:19:01 srv-5qvia kernel: inode_doinit_with_dentry:  context_to_sid(unconfined_u:object_r:etc_t:s0) returned 22 for dev=vda1 ino=133285

Jul  3 09:19:03 srv-5qvia kernel: inode_doinit_with_dentry:  context_to_sid(unconfined_u:object_r:etc_t:s0) returned 22 for dev=vda1 ino=133871

Jul  3 09:19:04 srv-5qvia kernel: inode_doinit_with_dentry:  context_to_sid(unconfined_u:object_r:etc_t:s0) returned 22 for dev=vda1 ino=132394

Jul  3 09:19:17 srv-5qvia kernel: inode_doinit_with_dentry:  context_to_sid(unconfined_u:object_r:etc_t:s0) returned 22 for dev=vda1 ino=131998

Jul  3 09:19:17 srv-5qvia kernel: inode_doinit_with_dentry:  context_to_sid(unconfined_u:object_r:etc_t:s0) returned 22 for dev=vda1 ino=128290

Jul  3 09:19:17 srv-5qvia kernel: inode_doinit_with_dentry:  context_to_sid(unconfined_u:object_r:selinux_config_t:s0) returned 22 for dev=vda1 ino=133938

which for Scientific Linux 5 means that it won't pick up a DHCP address (although CentOS5 appears to).

On Enterprise 5 the i686 version build just fails with:

F, [2012-07-03T08:56:55.173875 #21044] FATAL -- : RuntimeError: An error occurred while executing command: 'appliance-creator -d -v -t 'build/appliances/i686/centos/5/JEOS/1.0/centos-plugin/tmp' --cache=/var/cache/boxgrinder/rpms-cache/i686/centos/5 --config 'build/appliances/i686/centos/5/JEOS/1.0/centos-plugin/tmp/JEOS.ks' -o 'build/appliances/i686/centos/5/JEOS/1.0/centos-plugin/tmp' --name 'JEOS' --vmem 256 --vcpu 1 --format raw', process exited with wrong exit status: 1

Something seems to be missing from the default base package list. Anybody any idea what it is?

[goldmann]

Hi Neil,

Do you have more logs from the fail on CentOS5? The most important part is above or below the RuntimeError line you pasted above.

--Marek

[neilwilson]

Yep. Very similar to the trace in https://issues.jboss.org/browse/BGBUILD-350

for the i686 failure.

Doing a side by side analysis on the logs to get more data.

[neilwilson]

Ok.

On i686 you get

D, [2012-07-03T09:39:03.179845 #22205] DEBUG -- : warning: %post(pam-0.99.6.2-6.el5_5.2.i386) scriptlet failed, exit status 127

which you don't on x86_64.

Creator then fails on grub installation with

D, [2012-07-03T09:39:30.231114 #22205] DEBUG -- : Installing grub to /dev/loop0

D, [2012-07-03T09:39:30.262257 #22205] DEBUG -- : Installing: hdparm                       ##################### [192/192]

D, [2012-07-03T09:39:30.262539 #22205] DEBUG -- :

D, [2012-07-03T09:39:30.263016 #22205] DEBUG -- : Traceback (most recent call last):

D, [2012-07-03T09:39:30.263387 #22205] DEBUG -- : File "/usr/bin/appliance-creator", line 164, in <module>

D, [2012-07-03T09:39:30.263896 #22205] DEBUG -- : sys.exit(main())

D, [2012-07-03T09:39:30.264207 #22205] DEBUG -- : File "/usr/bin/appliance-creator", line 150, in main

D, [2012-07-03T09:39:30.264634 #22205] DEBUG -- : creator.configure()

D, [2012-07-03T09:39:30.265116 #22205] DEBUG -- : File "/usr/lib/python2.7/site-packages/imgcreate/creator.py", line 743, in configure

D, [2012-07-03T09:39:30.273391 #22205] DEBUG -- : self._create_bootconfig()

D, [2012-07-03T09:39:30.273813 #22205] DEBUG -- : File "/usr/lib/python2.7/site-packages/appcreate/appliance.py", line 374, in _create_bootconfig

D, [2012-07-03T09:39:30.276317 #22205] DEBUG -- : self._install_grub()

D, [2012-07-03T09:39:30.276767 #22205] DEBUG -- : File "/usr/lib/python2.7/site-packages/appcreate/appliance.py", line 305, in _install_grub

D, [2012-07-03T09:39:30.277221 #22205] DEBUG -- : stdin=subprocess.PIPE)

D, [2012-07-03T09:39:30.277622 #22205] DEBUG -- : File "/usr/lib64/python2.7/subprocess.py", line 672, in __init__

D, [2012-07-03T09:39:30.278118 #22205] DEBUG -- : errread, errwrite)

D, [2012-07-03T09:39:30.278397 #22205] DEBUG -- : File "/usr/lib64/python2.7/subprocess.py", line 1202, in _execute_child

D, [2012-07-03T09:39:30.279051 #22205] DEBUG -- : raise child_exception

D, [2012-07-03T09:39:30.279510 #22205] DEBUG -- : OSError: [Errno 2] No such file or directory

[neilwilson]

On X86_64 with SELinux you get

T, [2012-07-02T11:45:10.169791 #3215] TRACE -- : Loading SElinux policy...

D, [2012-07-02T11:45:10.169975 #3215] DEBUG -- : GFS: aug_init "/" 32

T, [2012-07-02T11:45:10.172035 #3215] TRACE -- : GFS: guestfsd: main_loop: proc 36 (exists) took 0.08 seconds^M

guestfsd: main_loop: new request, len 0x34

D, [2012-07-02T11:45:15.430448 #3215] DEBUG -- : GFS: aug_init = 0

D, [2012-07-02T11:45:15.430698 #3215] DEBUG -- : GFS: aug_rm "/augeas/load//incl[. != '/etc/sysconfig/selinux']"

T, [2012-07-02T11:45:15.432367 #3215] TRACE -- : GFS: guestfsd: main_loop: proc 16 (aug_init) took 5.25 seconds^M

guestfsd: main_loop: new request, len 0x60

D, [2012-07-02T11:45:15.439541 #3215] DEBUG -- : GFS: aug_rm = 208

D, [2012-07-02T11:45:15.439767 #3215] DEBUG -- : GFS: aug_load

T, [2012-07-02T11:45:15.441174 #3215] TRACE -- : GFS: guestfsd: main_loop: proc 22 (aug_rm) took 0.00 seconds^M

guestfsd: main_loop: new request, len 0x28

D, [2012-07-02T11:45:15.623759 #3215] DEBUG -- : GFS: aug_load = 0

D, [2012-07-02T11:45:15.623987 #3215] DEBUG -- : GFS: aug_get "/files/etc/sysconfig/selinux/SELINUX"

T, [2012-07-02T11:45:15.625547 #3215] TRACE -- : GFS: guestfsd: main_loop: proc 27 (aug_load) took 0.18 seconds^M

guestfsd: main_loop: new request, len 0x50

D, [2012-07-02T11:45:15.626276 #3215] DEBUG -- : GFS: aug_get = "permissive"

D, [2012-07-02T11:45:15.626387 #3215] DEBUG -- : GFS: sh "/usr/sbin/load_policy"

T, [2012-07-02T11:45:15.627923 #3215] TRACE -- : GFS: guestfsd: main_loop: proc 19 (aug_get) took 0.00 seconds^M

guestfsd: main_loop: new request, len 0x44

T, [2012-07-02T11:45:15.630167 #3215] TRACE -- : GFS: mount --bind /dev /sysroot/dev

T, [2012-07-02T11:45:15.714249 #3215] TRACE -- : GFS: mount --bind /dev/pts /sysroot/dev/pts

T, [2012-07-02T11:45:15.798630 #3215] TRACE -- : GFS: mount --bind /proc /sysroot/proc

T, [2012-07-02T11:45:15.883450 #3215] TRACE -- : GFS: mount --bind /selinux /sysroot/selinux

T, [2012-07-02T11:45:15.967626 #3215] TRACE -- : GFS: mount --bind /sys /sysroot/sys

T, [2012-07-02T11:45:16.112315 #3215] TRACE -- : GFS: /bin/sh -c /usr/sbin/load_policy

T, [2012-07-02T11:45:28.269882 #3215] TRACE -- : GFS: libsepol.policydb_write:

T, [2012-07-02T11:45:28.271563 #3215] TRACE -- : GFS: Discarding booleans and conditional rules

T, [2012-07-02T11:45:41.772730 #3215] TRACE -- : GFS: libsepol.policydb_write: Discarding booleans and conditional rules

T, [2012-07-02T11:45:45.898444 #3215] TRACE -- : GFS: libsepol.context_read_and_validate: invalid security context

T, [2012-07-02T11:45:45.900373 #3215] TRACE -- : GFS: libsepol.policydb_to_image: new policy image is invalid

T, [2012-07-02T11:45:45.901912 #3215] TRACE -- : GFS: libsepol.policydb_to_image: could not create policy image

T, [2012-07-02T11:45:46.063137 #3215] TRACE -- : GFS: /usr/sbin/load_policy:  Can't load policy:  No such file or directory

T, [2012-07-02T11:45:46.170764 #3215] TRACE -- : GFS: umount /sysroot/sys

T, [2012-07-02T11:45:46.245151 #3215] TRACE -- : GFS: umount /sysroot/selinux

T, [2012-07-02T11:45:46.300414 #3215] TRACE -- : GFS: umount /sysroot/proc

T, [2012-07-02T11:45:46.353215 #3215] TRACE -- : GFS: umount /sysroot/dev/pts

T, [2012-07-02T11:45:46.406380 #3215] TRACE -- : GFS: umount /sysroot/dev

T, [2012-07-02T11:45:46.460562 #3215] TRACE -- : GFS: guestfsd: error: libsepol.policydb_write: Discarding booleans and conditional rules^M

libsepol.policydb_write: Discarding booleans and conditional rules^M

libsepol.context_read_and_validate: invalid security context^M

libsepol.policydb_to_image: new policy image is invalid^M

libsepol.policydb_to_image: could not create policy image^M

/usr/sbin/load_policy:  Can't load policy:  No such file or directory

T, [2012-07-02T11:45:46.462235 #3215] TRACE -- : GFS:

D, [2012-07-02T11:45:46.462492 #3215] DEBUG -- : GFS: sh = NULL (error)

W, [2012-07-02T11:45:46.462792 #3215]  WARN -- : Loading SELinux policy failed. SELinux may be not fully initialized.

D, [2012-07-02T11:45:46.463245 #3215] DEBUG -- : GFS: aug_close

T, [2012-07-02T11:45:46.467022 #3215] TRACE -- : GFS: guestfsd: main_loop: proc 111 (sh) took 30.83 seconds^M

So looks like two separate issues.

[goldmann]

Neil,

What do you mean by SELinux enabled? SELinux running in permissive or enforcing mode? Enforcing mode will not play nicely with BG and is unsupported. On the other hand permissive mode shouldn't hurt BoxGrinder builds.

--Marek

[neilwilson]

It's just a standard build on the meta-appliance.

So whatever you guys set it to.

What appears to be happening is that the SEL tags on the files aren't been set correctly, so when the image is booted you get the 'dentry' errors.

Again its all default build stuff.

[msavy]

I've had a look at this, I think it might just be that selinux is set into permissive mode and therefore spits out warning messages, and does not actually do anthing (but probably annoy you).  We're looking at selinux in the near future, but have plenty of other issues that we're looking to address more immediately.

[neilwilson]

I hate to point this out but I suspect that it isn't much to do with SElinux and more to do with.

D, [2012-07-03T09:39:03.179845 #22205] DEBUG -- : warning: %post(pam-0.99.6.2-6.el5_5.2.i386) scriptlet failed, exit status 127.

above.

Which is stopping the i686 build from completing.

[goldmann]

Such post failures can be related to SELinux. Could you please check your SELinux settings and paste the /ets/sysconfig/selinux file content?

--Marek

[neilwilson]

Marek,

As I mentioned above it's on the meta appliance that the el5 i686 build is failing.

Are you saying that the meta appliance is broken and that I shouldn't use that?

Rgs

NeilW

[goldmann]

Which meta appliance version you use? Which format? I sassume it's 64 bit, correct?

I checked 1.7, 64 bit, on EC2:

$ cat /etc/sysconfig/selinux 
# This file controls the state of SELinux on the system.
# SELINUX= can take one of these three values:
#    enforcing - SELinux security policy is enforced.
#    permissive - SELinux prints warnings instead of enforcing.
#    disabled - SELinux is fully disabled.
SELINUX=permissive
# SELINUXTYPE= type of policy in use. Possible values are:
#    targeted - Only targeted network daemons are protected.
#    strict - Full SELinux protection.
SELINUXTYPE=targeted

It should be fine with permissive.

--Marek

[neilwilson]

Unfortunately not.

I'm using the RAW x86_64 appliance at http://boxgrinder.org/download/boxgrinder-build-meta-appliance/

It's marked as 1.7 on the web page but comes up as "BoxGrinder Meta Appliance 1.8 "

Kernel is

"Linux srv-h90ja 2.6.42.3-2.fc15.x86_64 #1 SMP Thu Feb 9 01:42:06 UTC 2012 x86_64 x86_64 x86_64 GNU/Linux"

Running a centos 5 i686 build using the appliance files at the top of this thread gives me the same problem.

"D, [2012-08-08T05:14:55.833102 #3693] DEBUG -- : warning: %post(pam-0.99.6.2-6.el5_5.2.i386) scriptlet failed, exit status 127"

[neilwilson]

Just to be sure SELinux file is the same :

# This file controls the state of SELinux on the system.

# SELINUX= can take one of these three values:

#          enforcing - SELinux security policy is enforced.

#          permissive - SELinux prints warnings instead of enforcing.

#          disabled - SELinux is fully disabled.

SELINUX=permissive

# SELINUXTYPE= type of policy in use. Possible values are:

#          targeted - Only targeted network daemons are protected.

#          strict - Full SELinux protection.

SELINUXTYPE=targeted