Bug 155897

Summary: kernel badness during rpm transactions
Product: [Fedora] Fedora Reporter: Dan Williams <dcbw>
Component: kernelAssignee: Kernel Maintainer List <kernel-maint>
Status: CLOSED RAWHIDE QA Contact: Brian Brock <bbrock>
Severity: medium Docs Contact:
Priority: medium    
Version: rawhideCC: dwalsh, wtogami
Target Milestone: ---   
Target Release: ---   
Hardware: All   
OS: Linux   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2005-07-27 04:58:05 UTC Type: ---
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Bug Depends On:    
Bug Blocks: 136450    
Attachments:
Description Flags
avc messages from /var/log/messages none

Description Dan Williams 2005-04-25 15:04:52 UTC
Linux localhost.localdomain 2.6.11-1.1261_FC4smp #1 SMP Fri Apr 22 21:33:11 EDT
2005 i686 i686 i386 GNU/Linux

selinux-policy-targeted-1.23.12-4

Whenever I run an 'rpm' transaction, all scripts (like preun, postun, etc) that
get run exit with status 255.  When that happens, I see the following in
/var/log/messages:

Apr 25 10:54:52 dcbw kernel: Unable to handle kernel NULL pointer dereference at
virtual address 00000000
Apr 25 10:54:52 dcbw kernel:  printing eip:
Apr 25 10:54:52 dcbw kernel: 00000000
Apr 25 10:54:52 dcbw kernel: *pde = 14a39001
Apr 25 10:54:52 dcbw kernel: Oops: 0000 [#1]
Apr 25 10:54:52 dcbw kernel: SMP
Apr 25 10:54:52 dcbw kernel: Modules linked in: loop parport_pc lp parport
autofs4 nfs lockd sunrpc dm_mod video button battery ac md5 ipv6 uhci_hcd
ehci_hcd tpm_nsc tpm i2c_i801 i2c_core snd_intel8x0 snd_ac97_codec snd_pcm_oss
snd_mixer_oss
snd_pcm snd_timer snd soundcore snd_page_alloc orinoco_pci orinoco hermes e1000
floppy ext3 jbd
Apr 25 10:54:52 dcbw kernel: CPU:    1
Apr 25 10:54:52 dcbw kernel: EIP:    0060:[<00000000>]    Not tainted VLI
Apr 25 10:54:52 dcbw kernel: EFLAGS: 00210286   (2.6.11-1.1261_FC4smp)
Apr 25 10:54:52 dcbw kernel: EIP is at 0x0
Apr 25 10:54:52 dcbw kernel: eax: e8771000   ebx: 01200011   ecx: 00000000  
edx: 00000000
Apr 25 10:54:52 dcbw kernel: esi: c1b0a540   edi: ddae9000   ebp: e8771000  
esp: e8771fc4
Apr 25 10:54:52 dcbw kernel: ds: 007b   es: 007b   ss: 0068
Apr 25 10:54:52 dcbw kernel: Process rpm (pid: 18861, threadinfo=e8771000
task=e23faa80)
Apr 25 10:54:52 dcbw kernel: Stack: 01202011 00000000 00000000 00000000 b7f8fa28
bfca6efc 00000000 c010007b
Apr 25 10:54:52 dcbw kernel:        c010007b 00000078 005ff7e2 00000073 00200286
bfca6e8c 0000007b
Apr 25 10:54:52 dcbw kernel: Call Trace:
Apr 25 10:54:52 dcbw kernel: Code:  Bad EIP value.


Current audit2allow -d:
allow hotplug_t file_t:file { execute execute_no_trans getattr read };
allow hotplug_t file_t:lnk_file read;
allow hotplug_t self:process setsched;
allow hotplug_t self:unix_dgram_socket sendto;
allow hotplug_t selinux_config_t:dir search;
allow hotplug_t selinux_config_t:file { getattr read };
allow kernel_t agp_device_t:chr_file { getattr relabelfrom relabelto setattr };
allow kernel_t clock_device_t:chr_file { getattr ioctl read relabelfrom relabelt
o setattr };
allow kernel_t console_device_t:chr_file { create relabelfrom relabelto rename s
etattr unlink };
allow kernel_t device_t:blk_file { create getattr ioctl read relabelfrom write } ;
allow kernel_t device_t:chr_file create getattr ioctl read relabelfrom relabelto
 rename setattr write;
allow kernel_t device_t:dir { mounton relabelto };
allow kernel_t device_t:file relabelto;
allow kernel_t device_t:sock_file { create setattr write };
allow kernel_t devpts_t:chr_file { getattr ioctl read setattr write };
allow kernel_t devpts_t:dir { getattr read search };
allow kernel_t devtty_t:chr_file create getattr ioctl read relabelfrom relabelto
 rename setattr unlink write;
allow kernel_t dhcpc_port_t:udp_socket name_bind;
allow kernel_t etc_runtime_t:file relabelto;
allow kernel_t etc_t:dir mounton;
allow kernel_t etc_t:file { execute execute_no_trans };
allow kernel_t event_device_t:chr_file { create getattr ioctl read setattr };
allow kernel_t file_t:file relabelfrom;
allow kernel_t file_t:sock_file { getattr unlink };
allow kernel_t fixed_disk_device_t:blk_file create getattr ioctl read relabelfro
m relabelto rename setattr write;
allow kernel_t hotplug_t:dir search;
allow kernel_t hotplug_t:file { getattr read };
allow kernel_t hotplug_t:lnk_file read;
allow kernel_t howl_port_t:tcp_socket name_bind;
allow kernel_t howl_port_t:udp_socket name_bind;
allow kernel_t i18n_input_var_run_t:sock_file create;
allow kernel_t initctl_t:fifo_file { getattr read relabelto write };
allow kernel_t initrc_exec_t:file { execute execute_no_trans };
allow kernel_t ipp_port_t:tcp_socket name_bind;
allow kernel_t ipp_port_t:udp_socket name_bind;
allow kernel_t self:file write;
allow kernel_t self:netlink_audit_socket create;
allow kernel_t self:netlink_kobject_uevent_socket { create getattr };
allow kernel_t self:netlink_route_socket create;
allow kernel_t self:netlink_selinux_socket create;
allow kernel_t self:packet_socket { create ioctl read };
allow kernel_t self:process { execmem setexec setfscreate };
allow kernel_t self:system { syslog_console syslog_mod syslog_read };
allow kernel_t ld_so_cache_t:file relabelto;
allow kernel_t lib_t:file execute_no_trans;
allow kernel_t memory_device_t:chr_file { execute getattr read relabelfrom relab
elto setattr write };
allow kernel_t mnt_t:dir mounton;
allow kernel_t mouse_device_t:chr_file { create getattr ioctl read relabelto set
attr write };
allow kernel_t mtrr_device_t:file { ioctl write };
allow kernel_t nfs_t:dir { getattr search };
allow kernel_t nfs_t:file { append getattr read };
allow kernel_t ntp_port_t:udp_socket name_bind;
allow kernel_t ntpd_exec_t:file { execute execute_no_trans };
allow kernel_t ntpdate_exec_t:file { execute execute_no_trans };
allow kernel_t null_device_t:chr_file { create relabelfrom relabelto rename seta
ttr unlink };
allow kernel_t port_t:tcp_socket name_connect;
allow kernel_t portmap_exec_t:file { execute execute_no_trans };
allow kernel_t portmap_port_t:tcp_socket { name_bind name_connect };
allow kernel_t portmap_port_t:udp_socket name_bind;
allow kernel_t printer_device_t:chr_file { create getattr rename setattr write } ;
allow kernel_t proc_kmsg_t:file read;
allow kernel_t proc_t:dir mounton;
allow kernel_t proc_t:file write;
allow kernel_t ptmx_t:chr_file { getattr ioctl read relabelfrom relabelto setatt
r write };
allow kernel_t ramfs_t:dir { add_name remove_name search setattr write };
allow kernel_t ramfs_t:fifo_file { create getattr ioctl read unlink write };
allow kernel_t ramfs_t:file { create unlink write };
allow kernel_t ramfs_t:sock_file { create setattr unlink write };
allow kernel_t random_device_t:chr_file { getattr read relabelfrom relabelto set
attr };
allow kernel_t removable_device_t:blk_file { create getattr ioctl read relabelto
 setattr write };
allow kernel_t reserved_port_t:tcp_socket { name_bind name_connect };
allow kernel_t reserved_port_t:udp_socket name_bind;
allow kernel_t rpc_pipefs_t:dir { getattr read search };
allow kernel_t sbin_t:file { execute execute_no_trans };
allow kernel_t security_t:security { check_context compute_av compute_user };
allow kernel_t sendmail_exec_t:file { execute execute_no_trans };
allow kernel_t smtp_port_t:tcp_socket name_bind;
allow kernel_t sound_device_t:chr_file { create getattr ioctl read setattr write  };
allow kernel_t ssh_port_t:tcp_socket name_bind;
allow kernel_t sysctl_dev_t:dir search;
allow kernel_t sysctl_dev_t:file { getattr read };
allow kernel_t sysctl_hotplug_t:file { getattr read write };
allow kernel_t sysctl_modprobe_t:file { getattr write };
allow kernel_t sysctl_net_t:dir search;
allow kernel_t sysctl_net_t:file { getattr write };
allow kernel_t sysctl_rpc_t:dir search;
allow kernel_t sysctl_t:dir { getattr mounton };
allow kernel_t sysfs_t:dir { getattr read };
allow kernel_t sysfs_t:file { getattr read };
allow kernel_t sysfs_t:lnk_file { getattr read };
allow kernel_t syslogd_exec_t:file { execute execute_no_trans };
allow kernel_t tmp_t:sock_file { create getattr setattr write };
allow kernel_t tmpfs_t:blk_file { getattr relabelfrom };
allow kernel_t tmpfs_t:chr_file { getattr ioctl read relabelfrom write };
allow kernel_t tmpfs_t:dir { mounton relabelfrom };
allow kernel_t tmpfs_t:fifo_file { create getattr read relabelfrom write };
allow kernel_t tmpfs_t:file relabelfrom;
allow kernel_t tty_device_t:chr_file create getattr ioctl read relabelfrom relab
elto rename setattr unlink write;
allow kernel_t tun_tap_device_t:chr_file { create getattr rename setattr };
allow kernel_t udev_helper_exec_t:file { execute execute_no_trans };
allow kernel_t unconfined_t:dir search;
allow kernel_t unconfined_t:file read;
allow kernel_t unconfined_t:process { noatsecure rlimitinh siginh transition };
allow kernel_t unconfined_t:shm { associate getattr read unix_read unix_write wr
ite };
allow kernel_t urandom_device_t:chr_file { getattr ioctl read relabelfrom relabe
lto setattr write };
allow kernel_t usbfs_t:dir getattr;
allow kernel_t user_home_dir_t:dir mounton;
allow kernel_t var_lib_nfs_t:dir mounton;
allow kernel_t var_run_t:sock_file { create setattr write };
allow kernel_t xserver_log_t:fifo_file { create getattr read setattr write };
allow kernel_t xserver_port_t:tcp_socket { name_bind name_connect };
allow kernel_t zero_device_t:chr_file { create getattr relabelfrom relabelto ren
ame setattr unlink };

Comment 1 Daniel Walsh 2005-04-25 15:09:52 UTC
This looks like a process transition is not happening can you attach the AVC
messages from you log files.

Dan

Comment 2 Dan Williams 2005-04-25 15:12:34 UTC
Ok, I can only trigger this issue with "strace -f" as in:

strace -f  /bin/rpm -Uhvvvv
/mnt/redhat/dist/fc4/java-1.4.2-gcj-compat/1.4.2.0-40jpp_18rh/i386/java-1.4.2-gcj-compat-devel-1.4.2.0-40jpp_18rh.i386.rpm
--force

It does not happen when using plain "strace".

Comment 3 Dan Williams 2005-04-25 15:14:16 UTC
Created attachment 113634 [details]
avc messages from /var/log/messages

Comment 4 Dan Williams 2005-04-25 15:17:20 UTC
Relevant RPM debug output with "vvvv" is:

D:   install: %post(java-1.4.2-gcj-compat-devel-1.4.2.0-40jpp_18rh.i386)
asynchronous scriptlet start
D:   install: %post(java-1.4.2-gcj-compat-devel-1.4.2.0-40jpp_18rh.i386)       
execv(/bin/sh) pid 19036
D:   install: waitpid(19036) rc 19036 status ff00 secs 0.002
error: %post(java-1.4.2-gcj-compat-devel-1.4.2.0-40jpp_18rh.i386) scriptlet
failed, exit status 255


Comment 5 Dan Williams 2005-04-25 15:18:32 UTC
relevant strace output of the rpm transaction with "strace" (no -f) is:

write(2, "D: ", 3D: )                      = 3
write(2, "  install: %post(java-1.4.2-gcj-"..., 99  install:
%post(java-1.4.2-gcj-compat-devel-1.4.2.0-40jpp_18rh.i386) asynchronous
scriptlet start
) = 99
stat64("/", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
stat64("/var/", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
stat64("/var/tmp", {st_mode=S_IFDIR|S_ISVTX|0777, st_size=4096, ...}) = 0
time(NULL)                              = 1114442251
open("/var/tmp/rpm-tmp.23817", O_RDWR|O_CREAT|O_TRUNC|O_EXCL|O_LARGEFILE, 0666) = 19
fcntl64(19, F_SETFD, FD_CLOEXEC)        = 0
stat64("/var/tmp/rpm-tmp.23817", {st_mode=S_IFREG|0644, st_size=0, ...}) = 0
fstat64(19, {st_mode=S_IFREG|0644, st_size=0, ...}) = 0
mmap2(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) =
0xb7bcf000
poll([{fd=19, events=POLLOUT, revents=POLLOUT}], 1, 2000) = 1
write(19, "set -x\n\nupdate-alternatives \\\n  "..., 1419) = 1419
close(19)                               = 0
munmap(0xb7bcf000, 8192)                = 0
dup(1)                                  = 19
rt_sigprocmask(SIG_SETMASK, NULL, [], 8) = 0
rt_sigprocmask(SIG_SETMASK, [CHLD], NULL, 8) = 0
rt_sigprocmask(SIG_SETMASK, NULL, [CHLD], 8) = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
rt_sigaction(SIGCHLD, NULL, {SIG_DFL}, 8) = 0
rt_sigaction(SIGCHLD, {0xb840d8, [], SA_RESTORER|SA_SIGINFO, 0x878310},
{SIG_DFL}, 8) = 0
pipe([20, 21])                          = 0
rt_sigprocmask(SIG_SETMASK, NULL, [], 8) = 0
rt_sigprocmask(SIG_SETMASK, [CHLD], NULL, 8) = 0
clone(child_stack=0, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD,
child_tidptr=0xb7f89a28) = 19042
rt_sigprocmask(SIG_SETMASK, NULL, [CHLD], 8) = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
rt_sigprocmask(SIG_SETMASK, NULL, [], 8) = 0
rt_sigprocmask(SIG_SETMASK, [CHLD], NULL, 8) = 0
close(20)                               = 0
close(21)                               = 0
rt_sigprocmask(SIG_SETMASK, NULL, [CHLD], 8) = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
futex(0x9ab2b40, FUTEX_WAIT, 1, NULLD:   install:
%post(java-1.4.2-gcj-compat-devel-1.4.2.0-40jpp_18rh.i386)    execv(/bin/sh) pid
19042
)   = -1 EINTR (Interrupted system call)
--- SIGCHLD (Child exited) @ 0 (0) ---
waitpid(0, [{WIFEXITED(s) && WEXITSTATUS(s) == 255}], WNOHANG) = 19042
futex(0x9ab2b40, FUTEX_WAKE, 1)         = 0
waitpid(0, 0xbf9a067c, WNOHANG)         = -1 ECHILD (No child processes)
rt_sigreturn(0x9ab2b40)                 = -1 EINTR (Interrupted system call)
rt_sigprocmask(SIG_SETMASK, NULL, [], 8) = 0
rt_sigprocmask(SIG_SETMASK, [CHLD], NULL, 8) = 0
futex(0x9ab2b24, FUTEX_WAKE, 1)         = 0
rt_sigprocmask(SIG_SETMASK, NULL, [CHLD], 8) = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
rt_sigprocmask(SIG_SETMASK, NULL, [], 8) = 0
rt_sigprocmask(SIG_SETMASK, [CHLD], NULL, 8) = 0
close(-1)                               = -1 EBADF (Bad file descriptor)
close(-1)                               = -1 EBADF (Bad file descriptor)
rt_sigprocmask(SIG_SETMASK, NULL, [CHLD], 8) = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
rt_sigaction(SIGCHLD, {SIG_DFL}, NULL, 8) = 0
write(2, "D: ", 3D: )                      = 3
write(2, "  install: waitpid(19042) rc 190"..., 58  install: waitpid(19042) rc
19042 status ff00 secs 0.003
) = 58
write(2, "error: ", 7error: )                  = 7
write(2, "%post(java-1.4.2-gcj-compat-deve"...,
93%post(java-1.4.2-gcj-compat-devel-1.4.2.0-40jpp_18rh.i386) scriptlet failed,
exit status 255
) = 93


Comment 6 Dan Williams 2005-04-25 15:19:52 UTC
relevant strace of the rpm transaction _with_ the "-f" is:

write(2, "D: ", 3D: )                      = 3
write(2, "  install: %post(java-1.4.2-gcj-"..., 99  install:
%post(java-1.4.2-gcj-compat-devel-1.4.2.0-40jpp_18rh.i386) asynchronous
scriptlet start
) = 99
stat64("/", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
stat64("/var/", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
stat64("/var/tmp", {st_mode=S_IFDIR|S_ISVTX|0777, st_size=4096, ...}) = 0
time(NULL)                              = 1114442319
open("/var/tmp/rpm-tmp.94618", O_RDWR|O_CREAT|O_TRUNC|O_EXCL|O_LARGEFILE, 0666) = 19
fcntl64(19, F_SETFD, FD_CLOEXEC)        = 0
stat64("/var/tmp/rpm-tmp.94618", {st_mode=S_IFREG|0644, st_size=0, ...}) = 0
fstat64(19, {st_mode=S_IFREG|0644, st_size=0, ...}) = 0
mmap2(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) =
0xb7b71000
poll([{fd=19, events=POLLOUT, revents=POLLOUT}], 1, 2000) = 1
write(19, "set -x\n\nupdate-alternatives \\\n  "..., 1419) = 1419
close(19)                               = 0
munmap(0xb7b71000, 8192)                = 0
dup(1)                                  = 19
rt_sigprocmask(SIG_SETMASK, NULL, [], 8) = 0
rt_sigprocmask(SIG_SETMASK, [CHLD], NULL, 8) = 0
rt_sigprocmask(SIG_SETMASK, NULL, [CHLD], 8) = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
rt_sigaction(SIGCHLD, NULL, {SIG_DFL}, 8) = 0
rt_sigaction(SIGCHLD, {0xb840d8, [], SA_RESTORER|SA_SIGINFO, 0x878310},
{SIG_DFL}, 8) = 0
pipe([20, 21])                          = 0
rt_sigprocmask(SIG_SETMASK, NULL, [], 8) = 0
rt_sigprocmask(SIG_SETMASK, [CHLD], NULL, 8) = 0
clone(Process 19045 attached
child_stack=0, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD,
child_tidptr=0xb7f2ba28) = 19045
[pid 19044] rt_sigprocmask(SIG_SETMASK, NULL, [CHLD], 8) = 0
[pid 19045] +++ killed by SIGSEGV +++
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
--- SIGCHLD (Child exited) @ 0 (0) ---
waitpid(0, [{WIFSIGNALED(s) && WTERMSIG(s) == SIGSEGV}], WNOHANG) = 19045
waitpid(0, 0xbff4268c, WNOHANG)         = -1 ECHILD (No child processes)
rt_sigreturn(0x2)                       = 0
rt_sigprocmask(SIG_SETMASK, NULL, [], 8) = 0
rt_sigprocmask(SIG_SETMASK, [CHLD], NULL, 8) = 0
close(20)                               = 0
close(21)                               = 0
rt_sigprocmask(SIG_SETMASK, NULL, [CHLD], 8) = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
rt_sigprocmask(SIG_SETMASK, NULL, [], 8) = 0
rt_sigprocmask(SIG_SETMASK, [CHLD], NULL, 8) = 0
close(-1)                               = -1 EBADF (Bad file descriptor)
close(-1)                               = -1 EBADF (Bad file descriptor)
rt_sigprocmask(SIG_SETMASK, NULL, [CHLD], 8) = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
rt_sigaction(SIGCHLD, {SIG_DFL}, NULL, 8) = 0
write(2, "D: ", 3D: )                      = 3
write(2, "  install: waitpid(19045) rc 190"..., 55  install: waitpid(19045) rc
19045 status b secs 0.000
) = 55
write(2, "error: ", 7error: )                  = 7
write(2, "%post(java-1.4.2-gcj-compat-deve"...,
91%post(java-1.4.2-gcj-compat-devel-1.4.2.0-40jpp_18rh.i386) scriptlet failed,
exit status 0
) = 91

Interesting that the exit status of this one is 0 while before it was 255?  The
transaction still fails in both cases.

Comment 7 Daniel Walsh 2005-04-25 15:47:07 UTC
This is most definitely a labeling problem.

Need to 
touch /.autorelabel
reboot.

Comment 8 Dan Williams 2005-07-27 04:58:05 UTC
closing as it works now