Bug 769928

Summary: lorax loses stderr of mkfs subprocess
Product: [Fedora] Fedora Reporter: John Reiser <jreiser>
Component: loraxAssignee: Martin Gracik <mgracik>
Status: CLOSED ERRATA QA Contact: Fedora Extras Quality Assurance <extras-qa>
Severity: unspecified Docs Contact:
Priority: unspecified    
Version: rawhideCC: bcl, dmach, mgracik
Target Milestone: ---   
Target Release: ---   
Hardware: Unspecified   
OS: Linux   
Whiteboard:
Fixed In Version: lorax-17.12-1.fc17 Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2012-03-14 09:56:01 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:

Description John Reiser 2011-12-22 18:55:41 UTC
Description of problem: stderr of the subprocess for mkfs root.img is not logged, so the log omits necessary information when the mkfs fails.


Version-Release number of selected component (if applicable):
lorax-17.1-1.fc17.x86_64


How reproducible: every time


Steps to Reproduce:
1. Setup mkfs.ext4 to fail during resolution of shared libraries.  For instance, install
  libcom_err.x86_64 0:1.41.14-2.fc15
instead of
  libcom_err.x86_64 0:1.42-1.fc17
so that the symbol
  set_com_err_gettext
will be missing for
  e2fsprogs-1.42-1.fc17.x86_64
2. Invoke pungi-2.9-1.fc16.noarch to create an install DVD for rawhide for Fedora 17, for instance via
   setenforce 0
   /usr/bin/pungi -c fedora-install-fedora-17.ks \
        --destdir=$DESTDIR --name Fedora --ver $VERSION --nosource

3.
  
Actual results:  lorax log file logs/x86_64.log ends with:
-----
pylorax.ltmpl.DEBUG: template line 846: runcmd chroot /ext4/Fedora17/work/x86_64/yumroot find -L /etc /usr /lib -xdev -type l -delete
pylorax.INFO: creating the runtime image
-----
Note in particular there is no message regarding failure of mkfs.

Console terminal stdout ends with:
-----
creating the runtime image
Traceback (most recent call last):
  File "/usr/bin/pungi", line 222, in <module>
    main()
  File "/usr/bin/pungi", line 124, in main
    mypungi.doBuildinstall()
  File "/usr/lib/python2.7/site-packages/pypungi/__init__.py", line 845, in doBuildinstall
    workdir=workdir, outputdir=outputdir)
  File "/usr/lib/python2.7/site-packages/pylorax/__init__.py", line 225, in run
    compression=compression, compressargs=compressargs)
  File "/usr/lib/python2.7/site-packages/pylorax/treebuilder.py", line 139, in create_runtime
    label="Anaconda", size=fssize) 
  File "/usr/lib/python2.7/site-packages/pylorax/imgutils.py", line 284, in mkext4img
    mkfsargs=["-L", label, "-b", "1024", "-m", "0"], graft=graft)
  File "/usr/lib/python2.7/site-packages/pylorax/imgutils.py", line 271, in mkfsimage
    stdout=PIPE, stderr=PIPE)
  File "/usr/lib64/python2.7/subprocess.py", line 511, in check_call
    raise CalledProcessError(retcode, cmd)
subprocess.CalledProcessError: Command '['mkfs.ext4', '-L', 'Anaconda', '-b', '1024', '-m', '0', '/dev/loop0']' returned non-zero exit status 127
-----

The actual circumstances of the status 127 failure are revealed by using "strace -f pungi ...":
-----
30833 execve("/sbin/mkfs.ext4", ["mkfs.ext4", "-L", "Anaconda", "-b", "1024", "-m", "0", "/dev/loop0"], [/* 51 vars */] <unfinished ...>
  [snip]
30833 writev(2, [{"mkfs.ext4", 9}, {": ", 2}, {"symbol lookup error", 19}, {": ", 2}, {"mkfs.ext4", 9}, {": ", 2}, {"undefined symbol: set_com_err_gettext", 37}, {"", 0}, {"", 0}, {"\n", 1}], 10) = 81
30833 exit_group(127)                   = ?
-----
Note that the writev to stderr succeeded (transferred 81 bytes); the message was available to be logged.

Expected results: The error message about "undefined symbol: set_com_err_gettext" should appear in the lorax log so that the user gets a good clue about what is wrong and how to fix it.


Additional info:

Comment 1 John Reiser 2011-12-22 19:29:51 UTC
logs/x86_64.log is the pungi log.  I forgot to look at work/x86_64/log/pylorax.log but perhaps the console message could remind me.

Looking through the output from "strace -f -s 256 pungi ..." I see that the text "undefined symbol: set_com_err_gettext" appears only once, where it is first generated.  So if that message was written to a log somewhere, then it is not in the first 256 characters of the write*().

Comment 2 Fedora Update System 2012-03-16 22:46:32 UTC
lorax-17.10-1.fc17 has been submitted as an update for Fedora 17.
https://admin.fedoraproject.org/updates/lorax-17.10-1.fc17

Comment 3 Fedora Update System 2012-03-22 01:03:29 UTC
lorax-17.12-1.fc17 has been submitted as an update for Fedora 17.
https://admin.fedoraproject.org/updates/lorax-17.12-1.fc17

Comment 4 Fedora Update System 2012-03-23 17:43:37 UTC
lorax-17.12-1.fc17 has been pushed to the Fedora 17 stable repository.  If problems still persist, please make note of it in this bug report.