Bug 629253 - anaconda: system freezes on installing selinux
Summary: anaconda: system freezes on installing selinux
Keywords:
Status: CLOSED WONTFIX
Alias: None
Product: Fedora
Classification: Fedora
Component: anaconda
Version: 19
Hardware: All
OS: Linux
low
medium
Target Milestone: ---
Assignee: Anaconda Maintenance Team
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
: 696814 (view as bug list)
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2010-09-01 12:23 UTC by Jan Engelhardt
Modified: 2013-05-06 22:08 UTC (History)
4 users (show)

Fixed In Version:
Clone Of:
Environment:
Last Closed: 2013-05-06 22:08:15 UTC
Type: ---
Embargoed:


Attachments (Terms of Use)
/root/install.log from target (7.90 KB, text/plain)
2010-09-12 12:44 UTC, Steve Tyler
no flags Details
/root/install.log.syslog from target (3.65 KB, text/plain)
2010-09-12 12:44 UTC, Steve Tyler
no flags Details
screenshot of anaconda console after install failure (7.43 KB, image/png)
2010-09-13 10:30 UTC, Steve Tyler
no flags Details
screenshot of anaconda syslog console after install failure (20.70 KB, image/png)
2010-09-13 10:40 UTC, Steve Tyler
no flags Details
time series plot of memory and swap usage during minimal install (52.07 KB, image/png)
2010-09-17 16:50 UTC, Steve Tyler
no flags Details

Description Jan Engelhardt 2010-09-01 12:23:54 UTC
Description of problem:
Fedora-13-DVD graphical installer seems to freeze when installing selinux-targeted-policy. I am using rdesktop to install a VM, so there is no way to switch to tty2 since Ctrl-Alt-F2 is overridden.

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

How reproducible:
2 GB virtual disk, with a 128 MB swap and the rest for one / ext4 root filesystem, no LVM.

 
Actual results:
Installs up to 280/289 then freezes at selinux-targeted-policy.

Expected results:


Additional info:

Comment 1 Chris Lumens 2010-09-01 12:59:31 UTC
Does increasing the amount of memory in the VM fix this?

Comment 2 Jan Engelhardt 2010-09-01 13:11:53 UTC
Even more than 512? No, that does not work. Disabling selinux by using enforce=0 however made it proceed.

Comment 3 Jan Engelhardt 2010-09-01 13:12:44 UTC
Now it finally finished after putting in 1024. But that seems odd. That is why I prefer text installs. Because I can switch to tty2.. but text installs have been castrated by design. Sigh.

Comment 4 Chris Lumens 2010-09-01 20:08:08 UTC
If you can't switch VTs using ctrl and alt, that seems a pretty serious limitation of how rdesktop+VM works.  If you are able to install to a VM via different means, perhaps you can switch over to tty2 and see exactly what's going on - is the system completely locked up, is it just operating slowly, is there a package scriptlet that's taking way longer than it should?

Comment 5 Steve Tyler 2010-09-12 12:38:26 UTC
With the F14-Alpha net installer in a VM, I am seeing a similar install failure.

The VM has 512M memory and the target VM disk image is 3M with an ext4 (2.8G) and a swap (256M) partition. They are both formatted from the custom layout dialog.

The install fails at selinux-policy-targeted (pkg 189/194) with the anaconda console displaying:
"install exited abnormally [1/1]"
and suggestions for ways to reboot.

Unfortunately, qemu doesn't seem to have a way to switch to a console, however, the target can be examined from a working F14 VM (called "fir"). The partitions and filesystem look fine. There is plenty of disk space (1.9G avail). There are two log files in /root that I will attach separately.


[root@fir ~]# fdisk -lu /dev/sdb

Disk /dev/sdb: 3221 MB, 3221225472 bytes
255 heads, 63 sectors/track, 391 cylinders, total 6291456 sectors
Units = sectors of 1 * 512 = 512 bytes
Sector size (logical/physical): 512 bytes / 512 bytes
I/O size (minimum/optimal): 512 bytes / 512 bytes
Disk identifier: 0x000009f6

   Device Boot      Start         End      Blocks   Id  System
/dev/sdb1   *        2048     5779455     2888704   83  Linux
/dev/sdb2         5779456     6291455      256000   82  Linux swap / Solaris
[root@fir ~]# blkid | sort
/dev/mapper/vg_fir-lv_root: UUID="dacaefc0-fee4-49be-acf5-b117b7c76ea4" TYPE="ext4" 
/dev/mapper/vg_fir-lv_swap: UUID="06403a5e-0499-4905-8633-59998f73b2f3" TYPE="swap" 
/dev/sda1: UUID="fcd3a883-dbf4-444c-8705-5e40648d0af2" TYPE="ext4" 
/dev/sda2: UUID="hdaFMh-YUh4-Mkcj-vBdj-ZGYU-8lTc-X91uqN" TYPE="LVM2_member" 
/dev/sdb1: UUID="9b65f0a1-a858-49d5-913e-19c8c2e8361c" TYPE="ext4" 
/dev/sdb2: UUID="3247f571-e62c-4532-a34d-0c4291b03e8c" TYPE="swap" 
[root@fir ~]# e2fsck -fn /dev/sdb1
e2fsck 1.41.12 (17-May-2010)
Pass 1: Checking inodes, blocks, and sizes
Pass 2: Checking directory structure
Pass 3: Checking directory connectivity
Pass 4: Checking reference counts
Pass 5: Checking group summary information
/dev/sdb1: 17440/180688 files (0.2% non-contiguous), 202526/722176 blocks
[root@fir ~]# mount -r /dev/sdb1 /mnt/foobar
[root@fir ~]# cd /mnt/foobar
[root@fir foobar]# ls -F
bin/   dev/  home/  lib64/       media/  opt/   root/  selinux/  sys/  usr/
boot/  etc/  lib/   lost+found/  mnt/    proc/  sbin/  srv/      tmp/  var/
[root@fir foobar]# ls -F var/log
audit/  btmp  lastlog  mail/  maillog  messages  secure  spooler  tallylog  wtmp
[root@fir foobar]# ls -F root
install.log  install.log.syslog
[root@fir foobar]#

[root@fir ~]# df -h
Filesystem            Size  Used Avail Use% Mounted on
/dev/mapper/vg_fir-lv_root
                      6.5G  2.4G  3.8G  39% /
tmpfs                 241M  420K  240M   1% /dev/shm
/dev/sda1             485M   30M  430M   7% /boot
/dev/sdb1             2.8G  747M  1.9G  29% /mnt/foobar
[root@fir ~]#

Comment 6 Steve Tyler 2010-09-12 12:44:20 UTC
Created attachment 446747 [details]
/root/install.log from target

Comment 7 Steve Tyler 2010-09-12 12:44:47 UTC
Created attachment 446748 [details]
/root/install.log.syslog from target

Comment 8 Steve Tyler 2010-09-12 12:53:35 UTC
qemu commands for reference:
foobar.img is the target.
f14-alpha.img is the working F14 VM image.

Install:
$ qemu-kvm -cdrom Fedora-14-Alpha-x86_64-netinst.iso -m 512m -hda foobar.img
-boot menu=on

Examine:
$ qemu-kvm -m 512m -hda f14-alpha.img -hdb foobar.img -boot menu=on

$ qemu-img info foobar.img 
image: foobar.img
file format: raw
virtual size: 3.0G (3221225472 bytes)
disk size: 2.3G

Comment 9 Steve Tyler 2010-09-12 14:02:09 UTC
The install succeeds and the target boots with these configs:

1024M VM memory and 256M swap
 512M VM memory and 800M swap
(The second test used the defaults from the full-disk partition option.)

BTW, in the case of the install failure, chrooting to the target and running
rpm -V selinux-policy-targeted
shows that the package was installed.

For the record, these are minimal installs.

Comment 10 Steve Tyler 2010-09-12 20:23:22 UTC
This experiment shows that selinux-policy-targeted cannot be installed with 512M VM memory and no swap. The system runs out of memory.

Complete a minimal install with the default full-disk partitioning.
After rebooting, configure and start networking.

This succeeds:
# free
# yum reinstall selinux-policy-targeted
# free

This fails with a flurry of error messages, including "Out of memory":
# swapoff -a
# free
# yum reinstall selinux-policy-targeted
# free

After this, the shell is still functional and there is free memory.

This leads me to conclude that anaconda should be able to detect out-of-memory in this situation and report that on the console.

Comment 11 Steve Tyler 2010-09-13 10:30:17 UTC
Created attachment 446882 [details]
screenshot of anaconda console after install failure

$ qemu-kvm -m 512m -cdrom Fedora-14-Alpha-x86_64-netinst.iso -hda foobar.img -boot menu=on

swap partition is 256M.

Comment 12 Steve Tyler 2010-09-13 10:40:35 UTC
Created attachment 446886 [details]
screenshot of anaconda syslog console after install failure

This screenshot conclusively shows that anaconda runs out of memory while installing selinux-policy-targeted and that anaconda and loader are killed by the kernel.

The anaconda shell console is not responsive, so there doesn't seem to be a way to get the logs in this situation.

BTW, qemu does indeed allow switching to a console:
"sendkey ctrl-alt-fN" in the qemu monitor.

Comment 13 Steve Tyler 2010-09-14 13:10:54 UTC
Bug 633807 - semodule memory usage causes install failures on minimally configured VMs

Comment 14 Steve Tyler 2010-09-16 20:04:07 UTC
Out of curiosity, I did a quick-and-dirty memory usage profile of a minimal install (F14-Alpha DVD) using top. Here is the peak memory usage based on sampling every 0.1 seconds. Sorting is on RES ("The non-swapped physical memory a task has used.").

topmem - 11:49:49 up 27 min,  0 users,  load average: 1.66, 0.98, 0.44
Mem:    491984k total,   486832k used,     5152k free,      928k buffers
Swap:   983036k total,   188552k used,   794484k free,    66320k cached

%MEM  RES SWAP  VIRT  SHR CODE DATA nFLT %CPU    TIME+    PID  UID COMMAND      
55.6 267m  19m  286m  844   12 267m 1967 88.0   0:34.78  1728    0 semodule     
 1.0 4988 151m  156m 4988  208 1404    0  0.0   0:00.35    69    0 loader       
 0.6 3156  89m 94328 3156  660  16m    6  0.0   0:00.05   374    0 NetworkManage
 0.4 2040  77m 81692 2040   36  420    0  0.0   0:01.38     1    0 init         
 0.4 1840 692m  693m  316    4 167m 1122  0.0   1:26.46   438    0 anaconda     
 0.4 1732  45m 48236 1732 1572 2764    0  0.0   0:00.01   377    0 dhclient     
 0.2 1004 309m  310m  908  300 288m   15  0.0   0:00.20    53    0 rsyslogd     
 0.2  952  20m 21568  952  336  472    2  0.0   0:00.06    62   81 dbus-daemon  

Second place goes to depmod:
%MEM  RES SWAP  VIRT  SHR CODE DATA nFLT %CPU    TIME+    PID  UID COMMAND      
35.9 172m  30m  202m  584  132 198m   19 81.3   0:02.51  1774    0 depmod       

Command run on the VM from the installer's shell console was:
./topmem -b -d 0.1 | ssh stephent@walnut 'cat > tmp/topmem.2.log'
with a custom top rc file to select memory columns.

Comment 15 Steve Tyler 2010-09-17 16:50:37 UTC
Created attachment 448058 [details]
time series plot of memory and swap usage during minimal install

This plot shows the memory and swap usage over time as reported by top during a
minimal install on a 512 mb VM. The total is simply the computed sum of the
two.

The top memory users in time order are here:
$ cat tm2.3.csv | cut -d ':' -f 6 | uniq -c | tail -n +2
   1607 anaconda
    353 semodule
      3 loader
      1 restorecon
      7 loader
    164 anaconda
     40 depmod
    625 anaconda

A custom perl script was used to convert the top batch reports into colon
separated records that can imported into gnumeric for plotting.

$ cat tm2.3.csv
rec_num:mem:swap:tot:top_frac:top_proc:anaconda:depmod:loader:restorecon:semodule
1:405360:0:405360:16.7:anaconda:1:0:0:0:0
2:405360:0:405360:16.7:anaconda:1:0:0:0:0
...
2799:485124:84480:569604:24.4:anaconda:1:0:0:0:0
2800:485124:84480:569604:24.4:anaconda:1:0:0:0:0

Comment 16 Steve Tyler 2010-10-29 15:57:09 UTC
(In reply to comment #12)
...
> This screenshot conclusively shows that anaconda runs out of memory while
> installing selinux-policy-targeted and that anaconda and loader are killed by
> the kernel.
> 
> The anaconda shell console is not responsive, so there doesn't seem to be a way
> to get the logs in this situation.

In an experiment in a VM to see if it is possible to recover from OOM, I manually set the oom_adj value to "-17" for both anaconda processes and the loader process that was not already set to "-17". With this configuration, when the system runs out of memory while installing selinux-policy-targeted, the kernel kills dbus-daemon and that causes NetworkManager to exit. The good news is that the installer shell console is functional and the logs can be examined.

Tested with:
$ qemu-kvm -m 512m -cdrom F14-Final-RC1/Fedora-14-x86_64-DVD.iso -hda f14-pine.img -boot menu=on

The installer insisted that swap be configured, so I set it to 128M.

Taming the OOM killer
http://lwn.net/Articles/317814/

Kernel OOM handling appears to be a work in progress:

Date	Mon, 15 Feb 2010 14:19:57 -0800 (PST)
From	David Rientjes <>
Subject	[patch -mm 0/9 v2] oom killer rewrite
http://lkml.org/lkml/2010/2/15/315

Comment 17 Steve Tyler 2011-04-15 11:18:30 UTC
*** Bug 696814 has been marked as a duplicate of this bug. ***

Comment 18 Fedora End Of Life 2013-04-03 18:26:39 UTC
This bug appears to have been reported against 'rawhide' during the Fedora 19 development cycle.
Changing version to '19'.

(As we did not run this process for some time, it could affect also pre-Fedora 19 development
cycle bugs. We are very sorry. It will help us with cleanup during Fedora 19 End Of Life. Thank you.)

More information and reason for this action is here:
https://fedoraproject.org/wiki/BugZappers/HouseKeeping/Fedora19


Note You need to log in before you can comment on or make changes to this bug.