log output ignores verbose option in submodules

[Christian Ehrhardt ]

While debugging a MP I reviewed I found that -v is somewhat ignored in submodules.
I assume this is to some extend since 0c515af9

Although without the history on that I'm not sure which way you want to solve it.

But as an example any logging of level info/debug in gitubuntu/build.py does not get out.
Found while running:
git ubuntu lint -v paelzer/lp1734207-fix-mulsipsk-zesty

Which should have like:
01/10/2018 15:42:50 - DEBUG:Successfully fetched :
../strongswan_5.5.1.orig.tar.bz2
 using fetch_orig_from_parent_dir(source=None)

But it was not appearing.
I found that the current init of loglevel in main is not correctly passed.
So all submodules use the default of >=warn and that way out verbose logs are much less useful.

[Nish Aravamudan (nacc)]

On 10.01.2018 [14:55:30 -0000], ChristianEhrhardt wrote:
> Public bug reported:
>
> While debugging a MP I reviewed I found that -v is somewhat ignored in
> submodules. I assume this is to some extend since 0c515af9
>
> Although without the history on that I'm not sure which way you want to
> solve it.
>
> But as an example any logging of level info/debug in
> gitubuntu/build.py does not get out.
> Found while running:
> git ubuntu lint -v paelzer/lp1734207-fix-mulsipsk-zesty

Do you have more examples than lint -> build?

> Which should have like:
> 01/10/2018 15:42:50 - DEBUG:Successfully fetched :
> ../strongswan_5.5.1.orig.tar.bz2
> using fetch_orig_from_parent_dir(source=None)
>
> But it was not appearing.
> I found that the current init of loglevel in main is not correctly passed.
> So all submodules use the default of >=warn and that way out verbose
> logs are much less useful.

This is intentional in this case, because the above output would be
surprising in general. You are right, though, if verbose is set in the
caller we should send it to the callee. We don't currently have any
mechanism for this, I don't think, but I'll look (at the lowest level
like this in lint, we no longer necessarily know if we are verbose or
not).

[Christian Ehrhardt  (paelzer)]

I did not spot other cases affected yet, I happened to find the same message I missed hear in "git ubuntu export-orig -v" so I knew not all cases are broken.
But I don't have a list of affected subcommands :-/

The solution will likely be pretty generic anyway, so if a generic solution is implemented in all modules and we see lint working we can almost expect to have them all covered.

And if not, throw generated info level logs everywhere - like with unique IDs.
And then see which ones are not showing up in test logs :-)

[Nish Aravamudan (nacc)]

On Thu, Jan 11, 2018 at 12:16 AM, ChristianEhrhardt
<email address hidden> wrote:
> I did not spot other cases affected yet, I happened to find the same message I missed hear in "git ubuntu export-orig -v" so I knew not all cases are broken.

Yeah, both builld and export-orig expect to have resulted in tarballs
in the pardir. But lint, IMO, does not.

> But I don't have a list of affected subcommands :-/
>
> The solution will likely be pretty generic anyway, so if a generic
> solution is implemented in all modules and we see lint working we can
> almost expect to have them all covered.
>
> And if not, throw generated info level logs everywhere - like with unique IDs.
> And then see which ones are not showing up in test logs :-)

Yeah. TBH, I think we need to rethink our logging, which is currently
mis-engineered.