Bug 739550 - Logging gone awry between mock 1.1.12 and 1.1.14
Summary: Logging gone awry between mock 1.1.12 and 1.1.14
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Fedora
Classification: Fedora
Component: mock
Version: 15
Hardware: Unspecified
OS: Unspecified
unspecified
unspecified
Target Milestone: ---
Assignee: Clark Williams
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2011-09-19 13:29 UTC by Paul Howarth
Modified: 2011-10-16 18:29 UTC (History)
3 users (show)

Fixed In Version: mock-1.1.15-1.el6
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2011-10-02 23:00:39 UTC


Attachments (Terms of Use)
changes to mock to correct logging issues (2.23 KB, patch)
2011-09-22 15:23 UTC, Clark Williams
no flags Details | Diff

Description Paul Howarth 2011-09-19 13:29:08 UTC
I've just updated my f15 builder from mock 1.1.12 to 1.1.14 and something strange has gone on with logging.

The terminal has additional logging, which appears to to of the debug variety, and has multiple logging of the mock version number:

$ mock -r epel-centos-5-x86_64 perl-Text-CSV_XS-0.72-1.el6.src.rpm
INFO: mock.py version 1.1.14 starting...
INFO: State Changed: init plugins
INFO: selinux enabled
INFO: State Changed: start
INFO: Start(perl-Text-CSV_XS-0.72-1.el6.src.rpm)  Config(epel-centos-5-x86_64)
INFO: State Changed: lock buildroot
INFO: State Changed: clean
INFO: chroot (/var/lib/mock/epel-centos-5-x86_64) unlocked and deleted
INFO: State Changed: unlock buildroot
INFO: State Changed: init
INFO: State Changed: lock buildroot
INFO: Mock Version: 1.1.14
INFO: Mock Version: 1.1.14
INFO: Mock Version: 1.1.14
INFO: mounting tmpfs.
INFO: enabled root cache
INFO: State Changed: unpacking root cache
INFO: enabled yum cache
INFO: State Changed: cleaning yum metadata
INFO: enabled ccache
INFO: State Changed: running yum
INFO: State Changed: unlock buildroot
INFO: State Changed: setup
INFO: ENTER do(['bash', '--login', '-c', 'rpmbuild -bs --target x86_64 --nodeps builddir/build/SPECS/perl-Text-CSV_XS.spec'], False, '/var/lib/mock/epel-centos-5-x86_64/root/', None, 0, True, False, 500, 101, None, logger=<mockbuild.trace_decorator.getLog object at 0x20f8b10>)
INFO: LEAVE do --> 

INFO: State Changed: build
INFO: ENTER do(['bash', '--login', '-c', 'rpmbuild -bb --target x86_64 --nodeps builddir/build/SPECS/perl-Text-CSV_XS.spec'], False, '/var/lib/mock/epel-centos-5-x86_64/root/', None, 0, True, False, 500, 101, None, logger=<mockbuild.trace_decorator.getLog object at 0x20f8b10>)
INFO: LEAVE do --> 

INFO: unmounting tmpfs.
INFO: Done(perl-Text-CSV_XS-0.72-1.el6.src.rpm) Config(epel-centos-5-x86_64) 0 minutes 13 seconds
INFO: Results and/or logs in: /var/lib/mock/epel-centos-5-x86_64/result
INFO: State Changed: end

The "ENTER/LEAVE do" logging seems out of place here.

More seriously, the root.log is longer including the yum output:

$ cat /var/lib/mock/epel-centos-5-x86_64/result/root.log 
INFO backend.py:833:  Mock Version: 1.1.14
DEBUG backend.py:274:  rootdir = /var/lib/mock/epel-centos-5-x86_64/root/
DEBUG backend.py:275:  resultdir = /var/lib/mock/epel-centos-5-x86_64/result
DEBUG backend.py:281:  create skeleton dirs
DEBUG backend.py:299:  touch required files
DEBUG backend.py:311:  configure yum
DEBUG backend.py:326:  configure yum rhnplugin
DEBUG backend.py:715:  mount -n -t proc   mock_chroot_proc   /var/lib/mock/epel-centos-5-x86_64/root/proc
DEBUG backend.py:715:  mount -n -t sysfs  mock_chroot_sysfs  /var/lib/mock/epel-centos-5-x86_64/root/sys
DEBUG backend.py:715:  mount -n --bind /var/cache/mock/epel-centos-5-x86_64/yum_cache/  /var/lib/mock/epel-centos-5-x86_64/root/var/cache/yum
DEBUG backend.py:715:  mount -n --bind /var/cache/mock/epel-centos-5-x86_64/ccache/  /var/lib/mock/epel-centos-5-x86_64/root/tmp/ccache
DEBUG backend.py:715:  mount -n --bind /tmp/mock-selinux-plugin.7jRT5x /var/lib/mock/epel-centos-5-x86_64/root/proc/filesystems
DEBUG backend.py:715:  mount -n -t devpts -o gid=5,mode=0620,ptmxmode=0666,newinstance mock_chroot_devpts /var/lib/mock/epel-centos-5-x86_64/root/dev/pts
DEBUG backend.py:715:  mount -n -t tmpfs mock_chroot_shmfs /var/lib/mock/epel-centos-5-x86_64/root/dev/shm
DEBUG backend.py:765:  ['/usr/bin/yum', '--installroot', '/var/lib/mock/epel-centos-5-x86_64/root/', 'update']
DEBUG backend.py:715:  mount -n -t proc   mock_chroot_proc   /var/lib/mock/epel-centos-5-x86_64/root/proc
DEBUG backend.py:715:  mount -n -t sysfs  mock_chroot_sysfs  /var/lib/mock/epel-centos-5-x86_64/root/sys
DEBUG backend.py:715:  mount -n --bind /var/cache/mock/epel-centos-5-x86_64/yum_cache/  /var/lib/mock/epel-centos-5-x86_64/root/var/cache/yum
DEBUG backend.py:715:  mount -n --bind /var/cache/mock/epel-centos-5-x86_64/ccache/  /var/lib/mock/epel-centos-5-x86_64/root/tmp/ccache
DEBUG backend.py:715:  mount -n --bind /tmp/mock-selinux-plugin.7jRT5x /var/lib/mock/epel-centos-5-x86_64/root/proc/filesystems
DEBUG backend.py:715:  mount -n -t devpts -o gid=5,mode=0620,ptmxmode=0666,newinstance mock_chroot_devpts /var/lib/mock/epel-centos-5-x86_64/root/dev/pts
DEBUG backend.py:715:  mount -n -t tmpfs mock_chroot_shmfs /var/lib/mock/epel-centos-5-x86_64/root/dev/shm
DEBUG backend.py:765:  ['/usr/bin/yum', '--installroot', '/var/lib/mock/epel-centos-5-x86_64/root/', 'resolvedep', 'ccache']
DEBUG backend.py:765:  ['/usr/bin/yum', '--installroot', '/var/lib/mock/epel-centos-5-x86_64/root/', 'install', 'ccache']
DEBUG backend.py:765:  ['/usr/bin/yum-builddep', '--installroot', '/var/lib/mock/epel-centos-5-x86_64/root/', '/var/lib/mock/epel-centos-5-x86_64/root///builddir/build/SRPMS/perl-Text-CSV_XS-0.72-1.rhel5.src.rpm']
DEBUG backend.py:601:  Copying packages to result dir

This will be a big problem for me before long when I need that output to debug something.

Comment 1 Peter Robinson 2011-09-19 14:19:31 UTC
reassign to proper component

Comment 2 Clark Williams 2011-09-21 20:23:02 UTC
I suspect this is fallout of the mock -> mockbuild change for namespace cleanup. Looking...

Comment 3 Clark Williams 2011-09-22 15:23:19 UTC
Created attachment 524433 [details]
changes to mock to correct logging issues

Straighten out confusion between /etc/mock/logging.ini and actual logging usage in mock.py and mockbuild/backend.py

Comment 4 Clark Williams 2011-09-22 15:23:54 UTC
Paul, 

Would you try the above patch and see if that straightens out your logging issues?

Comment 5 Paul Howarth 2011-09-23 08:37:15 UTC
(In reply to comment #4)
> Would you try the above patch and see if that straightens out your logging
> issues?

WORKSFORME.

Thanks.

Comment 6 Clark Williams 2011-09-23 18:51:14 UTC
excellent! Changes queued for 1.1.15

Comment 7 Fedora Update System 2011-09-23 20:55:04 UTC
mock-1.1.15-1.fc15 has been submitted as an update for Fedora 15.
https://admin.fedoraproject.org/updates/mock-1.1.15-1.fc15

Comment 8 Fedora Update System 2011-09-23 20:56:06 UTC
mock-1.1.15-1.el6 has been submitted as an update for Fedora EPEL 6.
https://admin.fedoraproject.org/updates/mock-1.1.15-1.el6

Comment 9 Fedora Update System 2011-09-23 20:56:59 UTC
mock-1.0.22-1.el5 has been submitted as an update for Fedora EPEL 5.
https://admin.fedoraproject.org/updates/mock-1.0.22-1.el5

Comment 10 Fedora Update System 2011-09-23 20:57:52 UTC
mock-1.1.15-1.fc14 has been submitted as an update for Fedora 14.
https://admin.fedoraproject.org/updates/mock-1.1.15-1.fc14

Comment 11 Fedora Update System 2011-09-24 21:59:19 UTC
Package mock-1.1.15-1.el6:
* should fix your issue,
* was pushed to the Fedora EPEL 6 testing repository,
* should be available at your local mirror within two days.
Update it with:
# su -c 'yum update --enablerepo=epel-testing mock-1.1.15-1.el6'
as soon as you are able to.
Please go to the following url:
https://admin.fedoraproject.org/updates/mock-1.1.15-1.el6
then log in and leave karma (feedback).

Comment 12 Fedora Update System 2011-10-02 22:59:37 UTC
mock-1.1.15-1.fc15 has been pushed to the Fedora 15 stable repository.  If problems still persist, please make note of it in this bug report.

Comment 13 Fedora Update System 2011-10-02 23:08:01 UTC
mock-1.1.15-1.fc14 has been pushed to the Fedora 14 stable repository.  If problems still persist, please make note of it in this bug report.

Comment 14 Fedora Update System 2011-10-16 18:27:38 UTC
mock-1.0.22-1.el5 has been pushed to the Fedora EPEL 5 stable repository.  If problems still persist, please make note of it in this bug report.

Comment 15 Fedora Update System 2011-10-16 18:29:22 UTC
mock-1.1.15-1.el6 has been pushed to the Fedora EPEL 6 stable repository.  If problems still persist, please make note of it in this bug report.


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