Bug 1528414

Summary: util.py attempts to write into a non-existent directory, and fails
Product: [Fedora] Fedora EPEL Reporter: R P Herrold <herrold>
Component: mockAssignee: Pavel Raiskup <praiskup>
Status: CLOSED CURRENTRELEASE QA Contact: Fedora Extras Quality Assurance <extras-qa>
Severity: unspecified Docs Contact:
Priority: unspecified    
Version: epel7CC: jdisnard, jkeating, mebrown, msuchy, praiskup, williams
Target Milestone: ---   
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of:
: 1536579 (view as bug list) Environment:
Last Closed: 2020-08-04 15:11:48 UTC Type: Bug
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: 1536579    
Attachments:
Description Flags
testing path on mkdir once hash name is known
none
some success none

Description R P Herrold 2017-12-21 19:41:12 UTC
[herrold@centos-7 bin]$ ./which-signer.sh mock
mock-1.4.7-2.el7.noarch
Fedora EPEL (7) <epel> 352c64e5 52ae6884 


Description of problem:

DEBUG util.py:561:  Executing command: ['/usr/bin/systemd-nspawn', '-q', '-M', 'c
adf290b528048bfba7174105818f630', '-D', '/var/lib/mock/epel-7-x86_64/root', '--se
tenv=LANG=en_US.UTF-8', '--setenv=TERM=vt100', '--setenv=SHELL=/bin/bash', '--set
env=HOSTNAME=mock', '--setenv=PROMPT_COMMAND=printf "\\033]0;<mock-chroot>\\007"'
, '--setenv=HOME=/builddir', '--setenv=PATH=/usr/bin:/bin:/usr/sbin:/sbin', '--se
tenv=PS1=<mock-chroot> \\s-\\v\\$ ', '/usr/sbin/usermod', '-u', '500', 'mockbuild
'] with env {'LANG': 'en_US.UTF-8', 'TERM': 'vt100', 'SHELL': '/bin/bash', 'HOSTN
AME': 'mock', 'PROMPT_COMMAND': 'printf "\\033]0;<mock-chroot>\\007"', 'HOME': '/
builddir', 'PATH': '/usr/bin:/bin:/usr/sbin:/sbin', 'PS1': '<mock-chroot> \\s-\\v
\\$ '} and shell False


DEBUG util.py:478:  readlink(/var/log/journal/de6af7385add4afea672a37d3c11fa20) failed: Not a directory

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

mock-1.4.7-2.el7.noarch

How reproducible:

0. install fedora-review

1. mkdir a temporary directory 

2. place a SRPM and accompanying SPEC file in a directory

3. run: fedora-review -n ./directory/${packagename}

this eventually shells off into mock, and dies (it does a couple retries) for want of the needed directory

everything is 'stock'

[herrold@centos-7 bin]$ sudo rpm -V fedora-review mock
[sudo] password for herrold: 
[herrold@centos-7 bin]$

Comment 1 Miroslav Suchý 2017-12-22 09:55:47 UTC
Hmm, I spent 30 minutes debugging it and I have no idea, why this is happening. :(

Comment 2 R P Herrold 2018-01-18 23:10:03 UTC
I see:

py/mockbuild/util.py:def mkdirIfAbsent(*args):


and isn't it this at 478


[herrold@centos-7 mock-1.4.8]$ nl -ba   ./py/mockbuild/util.py | grep -b5 -A5 478
18696-   473                        lines = [process_input(line) for line in lines]
18771-   474                    processed_input = '\n'.join(lines) + '\n'
18836-   475                    if logger is not None:
18882-   476                        for line in lines:
18928-   477                            if line != '':

18974:   478                                line = ansi_escape.sub('', line)

19042-   479                                logger.debug(line)
19096-   480                        for h in logger.handlers:
19149-   481                            h.flush()
19190-   482                    if returnOutput:
19230-   483                        output += processed_input
[herrold@centos-7 mock-1.4.8]$ 

which fails at 479  because the logging path for 'logger.debug(line)' to write to, did not exist?

I am certainly no expert in reading Python error messages, but there is a line number there

let me know if you need anything

Comment 3 R P Herrold 2018-01-19 15:09:13 UTC
The path into which it seeks to write exists (partially)

ls -al [herrold@centos-7 ~]$ ls -al /var/log/journal
-rwxr-sr-x+ 1 root systemd-journal 0 Dec 14 15:03 /var/log/journal
[herrold@centos-7 ~]$ 


note the unusual SGID permissions

As I said off bug:

The fix for:
        https://bugzilla.redhat.com/show_bug.cgi?id=1528414

looks like a simple:
        
         mkdir -p ` dirname logfile_name `

and so, an EASYFIX and low (negligible) risk

I cannot fix it in the .spec file, as the sub-directory seems to be a hash.  It is unclear to me _how_ that hash is arrived at.  I _think_ it is set here (two places):

[herrold@centos-7 mock-1.4.8]$ egrep -r logger * | grep "py" | nl -ba | grep "logging.getLogger" 

    13  py/mockbuild/trace_decorator.py:        logger = logging.getLogger(self.name)

    29  py/mockbuild/util.py:    mockbuild_logger = logging.getLogger('mockbuild')

and adding the utility function after each sub-directory is identified may solve this:

py/mockbuild/util.py:def mkdirIfAbsent(*args):

Comment 4 R P Herrold 2018-01-19 15:26:50 UTC
Created attachment 1383477 [details]
testing path on mkdir once hash name is known

I am testing this presently

Comment 5 R P Herrold 2018-01-19 15:36:03 UTC
Created attachment 1383479 [details]
some success

Tere is a transcript of the build with that patch in place ... it got past the earlier failure point, and now has a more useful log

I make no claim to being Python literate, but perhaps this rubric:

   adding those: mkdirIfAbsent() at a point of failure

is a way to partition the problem?

I suspect I also have a mkdir where it should not be in those eight I added in the attached prior patch

[root@centos-7 mock-1.4.8]# grep "mkdirIfAbsent" util-mkdir.patch | wc -l
8

Comment 6 R P Herrold 2018-01-19 15:37:58 UTC
in case it matters, the 'fedora-review' I am using is:

fedora-review    /var/ftp/pub/nfs/mirror/redhat/epel/7/Packages/f/fedora-review-0.5.3-2.el7.src.rpm

Comment 7 R P Herrold 2018-01-19 16:43:37 UTC
interestingly, I am not getting SElinux denials once past the first item

type=USER_AVC msg=audit(1516379905.117:47328): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='avc:  denied  { stop } for auid=n/a uid=0 gid=0 path="/run/systemd/system/machine-86355ec3dedd4b5784e215aefd50b775.scope" cmdline="/usr/lib/systemd/systemd-machined" scontext=system_u:system_r:systemd_machined_t:s0 tcontext=system_u:object_r:systemd_unit_file_t:s0 tclass=service  exe="/usr/lib/systemd/systemd" sauid=0 hostname=? addr=? terminal=?'


Do you want this in a separate bug, cloned from this one?

Comment 8 Fedora Admin XMLRPC Client 2020-03-17 04:43:25 UTC
This package has changed maintainer in the Fedora.
Reassigning to the new maintainer of this component.

Comment 9 Pavel Raiskup 2020-04-01 09:32:30 UTC
I can not reproduce with the version of mock that is right now in
epel-testing, even though fedora-review tool fails on something
different (see bug 1819642).

That said, I believe the original traceback _is_ fixed in current v2.1
mock so I'll attach this bug to the existing bodhi update.

Comment 10 Fedora Update System 2020-04-01 09:33:28 UTC
FEDORA-EPEL-2020-88ef4b4d66 has been submitted as an update to Fedora EPEL 7. https://bodhi.fedoraproject.org/updates/FEDORA-EPEL-2020-88ef4b4d66

Comment 11 Fedora Update System 2020-04-02 07:54:38 UTC
FEDORA-EPEL-2020-88ef4b4d66 has been submitted as an update to Fedora EPEL 7. https://bodhi.fedoraproject.org/updates/FEDORA-EPEL-2020-88ef4b4d66

Comment 12 Fedora Update System 2020-04-03 21:18:09 UTC
FEDORA-EPEL-2020-88ef4b4d66 has been pushed to the Fedora EPEL 7 testing repository.

You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-EPEL-2020-88ef4b4d66

See also https://fedoraproject.org/wiki/QA:Updates_Testing for more information on how to test updates.

Comment 13 Fedora Update System 2020-05-05 07:17:11 UTC
FEDORA-EPEL-2020-88ef4b4d66 has been pushed to the Fedora EPEL 7 stable repository.
If problem still persists, please make note of it in this bug report.