Обсуждение: "make check" changes have caused buildfarm deterioration.

Somewhere along the way some changes to the way we do "make check" have 
caused a significant deterioration in the buildfarm's logging. Compare 
these two from animal crake, which happens to be my test instance: 
<http://www.pgbuildfarm.org/cgi-bin/show_stage_log.pl?nm=crake&dt=2015-07-20%2013%3A09%3A02&stg=check> 
and 
<http://www.pgbuildfarm.org/cgi-bin/show_stage_log.pl?nm=crake&dt=2015-07-20%2017%3A23%3A08&stg=check> 


In the first place, we now have all that extraneous installation logging 
at the top, and the stuff we are most likely to be interested in right 
at the bottom. But more importantly, we are now missing the initdb log 
and the postmaster log, and the function to get a stack trace if 
required is almost certainly going to be broken as well.

What's most annoying is that some of the  stuff for this hasn't just 
moved, but some is now apparently now cleaned up and removed so the 
buildfarm script can't get at it at all.

I'm going to look at what can be done to repair the damage. No doubt I 
should have been paying more attention, but sometimes I just can't keep 
track of everything going on. Fixing this will almost certainly involve 
some core changes, though.

Incidentally, this has real consequences: I just went looking to find 
the postmaster log of a case that had an error and it was missing - 
that's how I noticed this.

cheers

andrew

Andrew Dunstan <andrew.dunstan@pgexperts.com> writes:
> Somewhere along the way some changes to the way we do "make check" have 
> caused a significant deterioration in the buildfarm's logging. Compare 
> these two from animal crake, which happens to be my test instance: 
> <http://www.pgbuildfarm.org/cgi-bin/show_stage_log.pl?nm=crake&dt=2015-07-20%2013%3A09%3A02&stg=check> 
> and 
> <http://www.pgbuildfarm.org/cgi-bin/show_stage_log.pl?nm=crake&dt=2015-07-20%2017%3A23%3A08&stg=check> 

Yeah, I've been bitching about the poor logging for awhile, but I had
not realized that it's still working as-expected in the back branches.

Comparing different branches, it looks like "somewhere along the way"
means "between 9.4 and 9.5".  I suspect that commit dcae5faccab64776, or
perhaps the followon dbf2ec1a1c053379, is to blame.
        regards, tom lane

On Tue, Jul 21, 2015 at 6:17 AM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
> Andrew Dunstan <andrew.dunstan@pgexperts.com> writes:
>> Somewhere along the way some changes to the way we do "make check" have
>> caused a significant deterioration in the buildfarm's logging. Compare
>> these two from animal crake, which happens to be my test instance:
>> <http://www.pgbuildfarm.org/cgi-bin/show_stage_log.pl?nm=crake&dt=2015-07-20%2013%3A09%3A02&stg=check>
>> and
>> <http://www.pgbuildfarm.org/cgi-bin/show_stage_log.pl?nm=crake&dt=2015-07-20%2017%3A23%3A08&stg=check>
>
> Yeah, I've been bitching about the poor logging for awhile, but I had
> not realized that it's still working as-expected in the back branches.
>
> Comparing different branches, it looks like "somewhere along the way"
> means "between 9.4 and 9.5".  I suspect that commit dcae5faccab64776, or
> perhaps the followon dbf2ec1a1c053379, is to blame.

Regarding install.log, the use of stdout/stderr instead of a log file
has been changed in dbf2ec1a after that:
http://www.postgresql.org/message-id/553FE7FC.2040707@gmx.net
Since 9.5 as the location of the temporary installation is global, we
could basically revert some parts of dcae5fac if that helps so as
install.log is saved in $ROOT/tmp_install/log/install.log... But I am
not sure what we win with that, and the argument to remove install.log
is that now the temporary installation is a make target. Both ways
have advantages and disadvantages.

Regarding initdb.log and postmaster.log, this is definitely a bug.
Those have been moved by dcae5fa from log/ to tmp_check/log/,
tmp_check/ getting removed at the end of pg_regress if there are no
failures counted. Both files will be saved in log/ at the location
pg_regress is called using outputdir whose default is ".". This way
behavior is similar to ~9.4. Attached is a patch to fix this for 9.5
and master.
Regards,
--
Michael

On Tue, Jul 21, 2015 at 2:39 PM, Michael Paquier
<michael.paquier@gmail.com> wrote:
> On Tue, Jul 21, 2015 at 6:17 AM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
>> Andrew Dunstan <andrew.dunstan@pgexperts.com> writes:
>>> Somewhere along the way some changes to the way we do "make check" have
>>> caused a significant deterioration in the buildfarm's logging. Compare
>>> these two from animal crake, which happens to be my test instance:
>>> <http://www.pgbuildfarm.org/cgi-bin/show_stage_log.pl?nm=crake&dt=2015-07-20%2013%3A09%3A02&stg=check>
>>> and
>>> <http://www.pgbuildfarm.org/cgi-bin/show_stage_log.pl?nm=crake&dt=2015-07-20%2017%3A23%3A08&stg=check>
>>
>> Yeah, I've been bitching about the poor logging for awhile, but I had
>> not realized that it's still working as-expected in the back branches.
>>
>> Comparing different branches, it looks like "somewhere along the way"
>> means "between 9.4 and 9.5".  I suspect that commit dcae5faccab64776, or
>> perhaps the followon dbf2ec1a1c053379, is to blame.
>
> Regarding install.log, the use of stdout/stderr instead of a log file
> has been changed in dbf2ec1a after that:
> http://www.postgresql.org/message-id/553FE7FC.2040707@gmx.net
> Since 9.5 as the location of the temporary installation is global, we
> could basically revert some parts of dcae5fac if that helps so as
> install.log is saved in $ROOT/tmp_install/log/install.log... But I am
> not sure what we win with that, and the argument to remove install.log
> is that now the temporary installation is a make target. Both ways
> have advantages and disadvantages.
>
> Regarding initdb.log and postmaster.log, this is definitely a bug.
> Those have been moved by dcae5fa from log/ to tmp_check/log/,
> tmp_check/ getting removed at the end of pg_regress if there are no
> failures counted. Both files will be saved in log/ at the location
> pg_regress is called using outputdir whose default is ".". This way
> behavior is similar to ~9.4. Attached is a patch to fix this for 9.5
> and master.

Something I just noticed: an entry for log/ in test_ddl_deparse's
gitignore is missing.
-- 
Michael

Michael Paquier wrote:
> On Tue, Jul 21, 2015 at 2:39 PM, Michael Paquier
> <michael.paquier@gmail.com> wrote:

> > Regarding initdb.log and postmaster.log, this is definitely a bug.
> > Those have been moved by dcae5fa from log/ to tmp_check/log/,
> > tmp_check/ getting removed at the end of pg_regress if there are no
> > failures counted. Both files will be saved in log/ at the location
> > pg_regress is called using outputdir whose default is ".". This way
> > behavior is similar to ~9.4. Attached is a patch to fix this for 9.5
> > and master.
> 
> Something I just noticed: an entry for log/ in test_ddl_deparse's
> gitignore is missing.

Well, three things: 1) the entry is not missing right now, but it will
be missing if we apply your patch; 2) the file is inconsistent with the
other test modules anyway so we might as well apply your patch to make
them all alike; 3) we shouldn't really do anything about that until the
other patch's fate is decided.

So, regarding the other patch, I don't know if it's that useful to keep
the log files when the check succeeds; and if it fails, the only problem
we have, I think, is that the path is wrong in the buildfarm code and
that seems easily fixed, but do we want to make the master branch
different from the others?  Maybe the BF code can look up the new path
first, and if it can't find the file then look in the old path.

Unless I'm misunderstanding the whole thing.

-- 
Álvaro Herrera                http://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services

On 2015-07-21 14:39:42 +0900, Michael Paquier wrote:
> Regarding initdb.log and postmaster.log, this is definitely a bug.
> Those have been moved by dcae5fa from log/ to tmp_check/log/,
> tmp_check/ getting removed at the end of pg_regress if there are no
> failures counted.

FWIW, I think that's bad TM. Especially when comparing good/bad
buildfarm runs the ability to get logs from good runs is essential.

Andres

Andres Freund wrote:
> On 2015-07-21 14:39:42 +0900, Michael Paquier wrote:
> > Regarding initdb.log and postmaster.log, this is definitely a bug.
> > Those have been moved by dcae5fa from log/ to tmp_check/log/,
> > tmp_check/ getting removed at the end of pg_regress if there are no
> > failures counted.
> 
> FWIW, I think that's bad TM. Especially when comparing good/bad
> buildfarm runs the ability to get logs from good runs is essential.

Hm, okay, so let's put it back where it was.

-- 
Álvaro Herrera                http://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services

On Tue, Jul 21, 2015 at 7:01 PM, Alvaro Herrera
<alvherre@2ndquadrant.com> wrote:
> Michael Paquier wrote:
>> On Tue, Jul 21, 2015 at 2:39 PM, Michael Paquier
>> <michael.paquier@gmail.com> wrote:
>
>> > Regarding initdb.log and postmaster.log, this is definitely a bug.
>> > Those have been moved by dcae5fa from log/ to tmp_check/log/,
>> > tmp_check/ getting removed at the end of pg_regress if there are no
>> > failures counted. Both files will be saved in log/ at the location
>> > pg_regress is called using outputdir whose default is ".". This way
>> > behavior is similar to ~9.4. Attached is a patch to fix this for 9.5
>> > and master.
>>
>> Something I just noticed: an entry for log/ in test_ddl_deparse's
>> gitignore is missing.
>
> Well, three things: 1) the entry is not missing right now, but it will
> be missing if we apply your patch; 2) the file is inconsistent with the
> other test modules anyway so we might as well apply your patch to make
> them all alike; 3) we shouldn't really do anything about that until the
> other patch's fate is decided.

Well, just to be clear, I meant "with the previous patch I have attached".
-- 
Michael

On 07/21/2015 01:39 AM, Michael Paquier wrote:
> On Tue, Jul 21, 2015 at 6:17 AM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
>> Andrew Dunstan <andrew.dunstan@pgexperts.com> writes:
>>> Somewhere along the way some changes to the way we do "make check" have
>>> caused a significant deterioration in the buildfarm's logging. Compare
>>> these two from animal crake, which happens to be my test instance:
>>> <http://www.pgbuildfarm.org/cgi-bin/show_stage_log.pl?nm=crake&dt=2015-07-20%2013%3A09%3A02&stg=check>
>>> and
>>> <http://www.pgbuildfarm.org/cgi-bin/show_stage_log.pl?nm=crake&dt=2015-07-20%2017%3A23%3A08&stg=check>
>> Yeah, I've been bitching about the poor logging for awhile, but I had
>> not realized that it's still working as-expected in the back branches.
>>
>> Comparing different branches, it looks like "somewhere along the way"
>> means "between 9.4 and 9.5".  I suspect that commit dcae5faccab64776, or
>> perhaps the followon dbf2ec1a1c053379, is to blame.
> Regarding install.log, the use of stdout/stderr instead of a log file
> has been changed in dbf2ec1a after that:
> http://www.postgresql.org/message-id/553FE7FC.2040707@gmx.net
> Since 9.5 as the location of the temporary installation is global, we
> could basically revert some parts of dcae5fac if that helps so as
> install.log is saved in $ROOT/tmp_install/log/install.log... But I am
> not sure what we win with that, and the argument to remove install.log
> is that now the temporary installation is a make target. Both ways
> have advantages and disadvantages.


I'm quite unhappy about how we now pollute the output of "make check" 
with the install log. See the above links for why. And when I run it by 
hand I don't want all this scrolling by me on the screen. The previous 
output of "make check" was small and clean, and I want it to go back to 
that, with the other logs available as necessary. The reason the 
buildfarm client cd's into the regress directory to run "make check" is 
to avoid extraneous output.

>
> Regarding initdb.log and postmaster.log, this is definitely a bug.
> Those have been moved by dcae5fa from log/ to tmp_check/log/,
> tmp_check/ getting removed at the end of pg_regress if there are no
> failures counted. Both files will be saved in log/ at the location
> pg_regress is called using outputdir whose default is ".". This way
> behavior is similar to ~9.4. Attached is a patch to fix this for 9.5
> and master.



OK, looks sane enough. but please do address the other issue.

cheers

andrew

Andrew Dunstan <andrew.dunstan@pgexperts.com> writes:
> On 07/21/2015 01:39 AM, Michael Paquier wrote:
>> Regarding install.log, the use of stdout/stderr instead of a log file
>> has been changed in dbf2ec1a after that:
>> http://www.postgresql.org/message-id/553FE7FC.2040707@gmx.net
>> Since 9.5 as the location of the temporary installation is global, we
>> could basically revert some parts of dcae5fac if that helps so as
>> install.log is saved in $ROOT/tmp_install/log/install.log... But I am
>> not sure what we win with that, and the argument to remove install.log
>> is that now the temporary installation is a make target. Both ways
>> have advantages and disadvantages.

> I'm quite unhappy about how we now pollute the output of "make check" 
> with the install log. See the above links for why. And when I run it by 
> hand I don't want all this scrolling by me on the screen. The previous 
> output of "make check" was small and clean, and I want it to go back to 
> that, with the other logs available as necessary. The reason the 
> buildfarm client cd's into the regress directory to run "make check" is 
> to avoid extraneous output.

I agree; this change may have seemed like a good idea at the time, but
it was not.  Failures during "make check"'s install step are rare enough
that you don't really need all that output in your face to help with the
rare situation where it fails.  And for the buildfarm's purposes, it is
surely desirable to segregate that output from the actual check step.

A possible alternative is to run the "make install" sub-step with -s,
but that could be objected to on the grounds that if it did fail, you'd
have a hard time telling exactly which step failed.
        regards, tom lane

On 7/21/15 10:00 AM, Tom Lane wrote:
> I agree; this change may have seemed like a good idea at the time, but
> it was not.  Failures during "make check"'s install step are rare enough
> that you don't really need all that output in your face to help with the
> rare situation where it fails.  And for the buildfarm's purposes, it is
> surely desirable to segregate that output from the actual check step.

It wasn't really an idea; it was just not necessary anymore.  We can put
it [directing the make install output into a file] back if that's what
people prefer.

> A possible alternative is to run the "make install" sub-step with -s,
> but that could be objected to on the grounds that if it did fail, you'd
> have a hard time telling exactly which step failed.

I usually run the whole make check with -s.

On Tue, Jul 21, 2015 at 10:34 PM, Andrew Dunstan wrote:
> OK, looks sane enough. but please do address the other issue.

Okidoki.
-- 
Michael

On Wed, Jul 22, 2015 at 10:04 AM, Peter Eisentraut <peter_e@gmx.net> wrote:
> On 7/21/15 10:00 AM, Tom Lane wrote:
>> I agree; this change may have seemed like a good idea at the time, but
>> it was not.  Failures during "make check"'s install step are rare enough
>> that you don't really need all that output in your face to help with the
>> rare situation where it fails.  And for the buildfarm's purposes, it is
>> surely desirable to segregate that output from the actual check step.
>
> It wasn't really an idea; it was just not necessary anymore.  We can put
> it [directing the make install output into a file] back if that's what
> people prefer.

OK... Attached are two patches (please merge them into a single
commit, I am just separating them as they are separate issues):
- 0001 adds a missing entry in test_ddl_deparse's .gitignore. I
mentioned that upthread.
- 0002 redirects the installation logs into
abs_top_builddir/tmp_install/log/install.log. We could redirect it
only to abs_top_builddir/log/ but tmp_install is not removed after a
run of a regression make target.
--
Michael

On 07/24/2015 01:21 PM, Jeff Janes wrote:
> On Tue, Jul 21, 2015 at 6:31 PM, Michael Paquier 
> <michael.paquier@gmail.com <mailto:michael.paquier@gmail.com>> wrote:
>
>     On Wed, Jul 22, 2015 at 10:04 AM, Peter Eisentraut
>     <peter_e@gmx.net <mailto:peter_e@gmx.net>> wrote:
>     > On 7/21/15 10:00 AM, Tom Lane wrote:
>     >> I agree; this change may have seemed like a good idea at the
>     time, but
>     >> it was not.  Failures during "make check"'s install step are
>     rare enough
>     >> that you don't really need all that output in your face to help
>     with the
>     >> rare situation where it fails.  And for the buildfarm's
>     purposes, it is
>     >> surely desirable to segregate that output from the actual check
>     step.
>     >
>     > It wasn't really an idea; it was just not necessary anymore.  We
>     can put
>     > it [directing the make install output into a file] back if
>     that's what
>     > people prefer.
>
>     OK... Attached are two patches (please merge them into a single
>     commit, I am just separating them as they are separate issues):
>     - 0001 adds a missing entry in test_ddl_deparse's .gitignore. I
>     mentioned that upthread.
>     - 0002 redirects the installation logs into
>     abs_top_builddir/tmp_install/log/install.log. We could redirect it
>     only to abs_top_builddir/log/ but tmp_install is not removed after a
>     run of a regression make target.
>
>
> If I run 'make check' on an unbuilt tree, any compiler warnings 
> emitted during the build phase now get directed into the install log.  
> Was that intentional or a side effect?
>
>


Probably not, but you could get around it easily by doing "make && make 
check". Getting around the previous behavior was not nearly so easy.

cheers

andrew