Bug 1195244

Summary: Mis-configured logging mutes log messages
Product: [Fedora] Fedora Reporter: Alec Leamas <leamas.alec>
Component: javapackages-toolsAssignee: Michal Srb <msrb>
Status: CLOSED INSUFFICIENT_DATA QA Contact: Fedora Extras Quality Assurance <extras-qa>
Severity: unspecified Docs Contact:
Priority: unspecified    
Version: 22CC: java-sig-commits, mizdebsk, msimacek, msrb
Target Milestone: ---   
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2015-12-21 09:21:18 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:
Attachments:
Description Flags
Test case provoking bug with non-readable metadata.
none
File referenced in maven.req none

Description Alec Leamas 2015-02-23 13:20:53 UTC
Created attachment 994371 [details]
Test case provoking bug with non-readable metadata.

Description of problem:


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


How reproducible: Always


Steps to Reproduce:
1. Install DecodeIrCaller from 
   https://copr.fedoraproject.org/coprs/leamas/harctoolbox/
2. For the example, create a bug:
   $ sudo chmod 600 /usr/share/maven-metadata/DecodeIrCaller.xml
3.Run attached maven.req. It is a patched version of the thing
  run by rpmbuild
   $ ./maven.req
4. Watch in output
    Processing files: IrpMaster-1.0.2-1.fc21.noarch
    No handlers could be found for logger "pyxb.binding.basis"
    No handlers could be found for logger "pyxb.binding.basis"

The messages stems from the XML parsing in 
javapackages/metadata/pyxbmetadata.py around line 59. Obviously, they are not really helpful, loggers should be configure

Actual results:
   Useless messages


Expected results:
   Good messages.

Additional info:

Same thing is likely to happen for any maven-driver spec given a non-readable metadata dependency. And there are other things which might got wrong, needing configured logger I guess.

Comment 1 Michal Srb 2015-02-23 13:52:19 UTC
Hmm... I think that the problem lies somewhere else. pyxbmetadata.py takes already opened file, so it must have been accessible.

What version of javapackages-tools are we talking about here?

Comment 2 Alec Leamas 2015-02-23 13:54:29 UTC
javapackages-tools-4.1.0-7.fc21.noarch

Comment 3 Alec Leamas 2015-02-23 13:56:17 UTC
(In reply to Michal Srb from comment #1)
> Hmm... I think that the problem lies somewhere else. pyxbmetadata.py takes
> already opened file, so it must have been accessible.

Well, when I step the thing (pdb) the log message is in the parsing statement

Comment 4 Michal Srb 2015-02-23 13:59:31 UTC
(In reply to Alec Leamas from comment #3)
> 
> Well, when I step the thing (pdb) the log message is in the parsing statement

The problem is that you can't parse what you can't read. Do you have a build.log from build when this error actually happened?

Comment 5 Michael Simacek 2015-02-23 14:06:56 UTC
The message about misconfigured logging appears always, it's not related to the problem you're having. The current upstream version (unreleased) no longer uses PyXB, so such message can no longer happen.

To Michal:
IMO, the problem is that metadata cache simply ignores anything it cannot read.

The problematic part of code (cache/metadata.py:55):
for path in metadata_paths:
            try:
                metadata = Metadata.create_from_file(path)
                if metadata:
                    cache.update({path: metadata})
            except MetadataLoadingException:
                continue

Comment 6 Michael Simacek 2015-02-23 14:53:58 UTC
Nevermind, the metadata cache wasn't used back then in the version thats on f21. Can you provide a full reproducer SRPM? (the attached thing points to your home)

Comment 7 Alec Leamas 2015-02-23 15:06:14 UTC
Sort of. Using my copr at  [1]:

- Install DecodeIrCaller.
- chmod 600 /usr/share/maven-metadata/DecodeIrCaller.xml
- Download the IrpMaster srpm
- Install builddeps for IrpMaster srpm
- Rebuild IrpMaster srpm

Havn't checked, but it should "work" (in the sense that it fails...). 

https://copr.fedoraproject.org/coprs/leamas/harctoolbox/

Comment 8 Alec Leamas 2015-02-23 15:09:04 UTC

(In reply to Michael Simacek from comment #6)
> Nevermind, the metadata cache wasn't used back then in the version thats on
> f21. Can you provide a full reproducer SRPM? (the attached thing points to
> your home)

Oops, sorry. Attaching that file, just store it somewhere and patch maven-req. That should be simpler and faster while testing.

Comment 9 Alec Leamas 2015-02-23 15:10:30 UTC
Created attachment 994406 [details]
File referenced in maven.req

Comment 10 Michal Srb 2015-02-23 15:33:07 UTC
(In reply to Alec Leamas from comment #7)
> Sort of. Using my copr at  [1]:
> 
> - Install DecodeIrCaller.
> - chmod 600 /usr/share/maven-metadata/DecodeIrCaller.xml
> - Download the IrpMaster srpm
> - Install builddeps for IrpMaster srpm
> - Rebuild IrpMaster srpm
> 
> Havn't checked, but it should "work" (in the sense that it fails...). 
> 
> https://copr.fedoraproject.org/coprs/leamas/harctoolbox/


I am getting completely different error:

[ERROR] Failed to execute goal on project IrpMaster: Could not resolve dependencies for project org.harctoolbox:IrpMaster:jar:1.0.2: Cannot access repo.jenkins-ci.org (http://repo.jenkins-ci.org/public/) in offline mode and the artifact com.hifiremote:DecodeIrCaller:jar:0.1314 has not been downloaded from it before. -> [Help 1]

Comment 11 Alec Leamas 2015-02-23 15:47:17 UTC
Hey, I made my first maven pom-file some days ago...maven is certainly full of surprises... you have installed DecodeIrCaller, have you?

Comment 12 Michal Srb 2015-02-23 15:59:30 UTC
(In reply to Alec Leamas from comment #11)
> Hey, I made my first maven pom-file some days ago...maven is certainly full
> of surprises... you have installed DecodeIrCaller, have you?

Yes, I have. I am just trying to understand where the problem could be. I have installed DecodeIrCaller, but since permissions are 600, even Maven/XMvn can't read it.

Comment 13 Michal Srb 2015-12-21 09:09:34 UTC
Moving back to NEW as I never actually started working on a fix. The discussion here was just an attempt to triage the bug.

Comment 14 Michal Srb 2015-12-21 09:21:18 UTC
Actually, I am going to close this bug as I wasn't able to reproduce it. To my best knowledge, it doesn't seem to be a bug in javapackages-tools.

Alec, please feel free to reopen this bug if you're still able to reproduce it. Thanks ;)