Re: [easybuild] Raw output for debugging

[Gunnar Sauer]

Hello Davide and Kenneth,
during my few tests with EasyBuild I would have preferred to have the
option to include all intermediate logs (configure step etc.) in
EasyBuild's stdout or stderr. The first reason is that the logs below /tmp
are not available on a cluster from the login node, when EasyBuild is
executed on compute nodes from a job scheduler, and it is difficult to
parse the output to find out which files need to be copied at the end of a
job.
Secondly, it is much easier to find the point of failure if all output is
written linearly into one file rather than distributed over several folders.

The condensed output, which is implemented right now, is perfect for
production systems. But for development or debugging, all output being sent
to stdout, as Davide suggested, would help a lot. As far as I can see, the
--debug option just provides some more details, but doesn't include
configure and test outputs.

Gunnar

2017-01-31 19:06 GMT+01:00 Vanzo, Davide :

> Kenneth,
> thank for rephrasing my request in a more comprehensible way. ;)
> Yes, that functionality may be very useful for overall log completeness.
> IMHO I would like having everything in the same log file, but I am not too
> picky.
>
> DV
>
>
> On Jan 31 2017, at 11:48 am, Kenneth Hoste 
> wrote:
>
>> Hi Davide,
>>
>> On 31/01/2017 16:38, Vanzo, Davide wrote:
>>
>> Yes, no luck even with the debug flag. Here are the last last log lines
>> before my SIGINT:
>>
>> == 2017-01-31 09:07:15,484 easyblock.py:2263 DEBUG Not skipping test step
>> (skippable: True, skip: None, skipsteps: [], module_only: False, force:
>> False
>> == 2017-01-31 09:07:15,484 build_log.py:216 INFO testing...
>> == 2017-01-31 09:07:15,485 easyblock.py:2271 INFO Starting test step
>> == 2017-01-31 09:07:15,485 templates.py:151 DEBUG config:
>> > 0x7f1d37e88c50>
>> == 2017-01-31 09:07:15,485 templates.py:175 DEBUG version found in
>> easyconfig is 5.24.0
>> == 2017-01-31 09:07:15,485 templates.py:219 DEBUG name: github_account,
>> config: None
>> == 2017-01-31 09:07:15,485 templates.py:219 DEBUG name: name, config: Perl
>> == 2017-01-31 09:07:15,486 templates.py:219 DEBUG name: version, config:
>> 5.24.0
>> == 2017-01-31 09:07:15,486 templates.py:219 DEBUG name: versionsuffix,
>> config:
>> == 2017-01-31 09:07:15,486 templates.py:219 DEBUG name: versionprefix,
>> config:
>> == 2017-01-31 09:07:15,486 templates.py:151 DEBUG config:
>> > 0x7f1d37e88c50>
>> == 2017-01-31 09:07:15,486 templates.py:175 DEBUG version found in
>> easyconfig is 5.24.0
>> == 2017-01-31 09:07:15,487 templates.py:219 DEBUG name: github_account,
>> config: None
>> == 2017-01-31 09:07:15,487 templates.py:219 DEBUG name: name, config: Perl
>> == 2017-01-31 09:07:15,487 templates.py:219 DEBUG name: version, config:
>> 5.24.0
>> == 2017-01-31 09:07:15,487 templates.py:219 DEBUG name: versionsuffix,
>> config:
>> == 2017-01-31 09:07:15,487 templates.py:219 DEBUG name: versionprefix,
>> config:
>> == 2017-01-31 09:07:15,488 easyblock.py:2274 INFO Running method
>> test_step part of step test
>> == 2017-01-31 09:07:15,488 run.py:137 DEBUG run_cmd: running cmd export
>> LC_ALL=C && make test (in /mnt/ramdisk/Perl/5.24.0/GCC-
>> 5.4.0-2.26/perl-5.24.0)
>>
>>
>> OK, basically what you are asking is that a running command would
>> generate output in the EasyBuild log file, I think.
>> This has been discussed/considered before, see
>> https://github.com/hpcugent/easybuild-framework/issues/581 .
>>
>> There's one way to get what you want, which is making the run_cmd
>> function collect output in a separate temporary log file specific to that
>> command while the command is still running.
>>
>> Right now, this is not done by default, but we could change that...
>>
>> Of course, the other option would be to just let run_cmd stream the
>> output of the command into the main log, as the command is running.
>> That's certainly doable too, but is a bit more tedious (certainly w.r.t.
>> backward compatibility).
>>
>>
>> regards,
>>
>> Kenneth
>>
>>
>> DV
>>
>>
>> On Jan 31 2017, at 9:31 am, Kenneth Hoste 
>>  wrote:
>>
>> Hi Davide,
>>
>> On 31/01/2017 16:01, Vanzo, Davide wrote:
>>
>> Kenneth,
>> yes, for the configure and build steps I have the output in the log filed
>> (sorry for the confusion before), but I don't see anything for the test
>> step. For example, for both Tcl and Perl the last thing I see is:
>>
>> == 2017-01-30 17:55:58,057 easyblock.py:2274 INFO Running method
>> test_step part of step test
>>
>> If the test hangs (as happened in both cases for me) I have no clue what
>> is going wrong.
>>
>>
>> Have you tried running with "eb --debug" to get a debug log?
>>
>> The test step for Tcl is nothing more than a 'make test' afaik.
>>
>> A non-debug log probably only shows which commands were run after they
>> completed (we should probably change that).
>>
>>
>> regards,
>>
>> Kenneth
>>
>>
>> DV
>>
>>
>> On 

Re: [easybuild] Raw output for debugging

[Kenneth Hoste]

Hi Davide,

On 31/01/2017 16:38, Vanzo, Davide wrote:
Yes, no luck even with the debug flag. Here are the last last log 
lines before my SIGINT:


== 2017-01-31 09:07:15,484 easyblock.py:2263 DEBUG Not skipping test 
step (skippable: True, skip: None, skipsteps: [], module_only: False, 
force: False

== 2017-01-31 09:07:15,484 build_log.py:216 INFO testing...
== 2017-01-31 09:07:15,485 easyblock.py:2271 INFO Starting test step
== 2017-01-31 09:07:15,485 templates.py:151 DEBUG config: 
0x7f1d37e88c50>
== 2017-01-31 09:07:15,485 templates.py:175 DEBUG version found in 
easyconfig is 5.24.0
== 2017-01-31 09:07:15,485 templates.py:219 DEBUG name: 
github_account, config: None

== 2017-01-31 09:07:15,485 templates.py:219 DEBUG name: name, config: Perl
== 2017-01-31 09:07:15,486 templates.py:219 DEBUG name: version, 
config: 5.24.0
== 2017-01-31 09:07:15,486 templates.py:219 DEBUG name: versionsuffix, 
config:
== 2017-01-31 09:07:15,486 templates.py:219 DEBUG name: versionprefix, 
config:
== 2017-01-31 09:07:15,486 templates.py:151 DEBUG config: 
0x7f1d37e88c50>
== 2017-01-31 09:07:15,486 templates.py:175 DEBUG version found in 
easyconfig is 5.24.0
== 2017-01-31 09:07:15,487 templates.py:219 DEBUG name: 
github_account, config: None

== 2017-01-31 09:07:15,487 templates.py:219 DEBUG name: name, config: Perl
== 2017-01-31 09:07:15,487 templates.py:219 DEBUG name: version, 
config: 5.24.0
== 2017-01-31 09:07:15,487 templates.py:219 DEBUG name: versionsuffix, 
config:
== 2017-01-31 09:07:15,487 templates.py:219 DEBUG name: versionprefix, 
config:
== 2017-01-31 09:07:15,488 easyblock.py:2274 INFO Running method 
test_step part of step test
== 2017-01-31 09:07:15,488 run.py:137 DEBUG run_cmd: running cmd 
export LC_ALL=C && make test (in 
/mnt/ramdisk/Perl/5.24.0/GCC-5.4.0-2.26/perl-5.24.0)


OK, basically what you are asking is that a running command would 
generate output in the EasyBuild log file, I think.
This has been discussed/considered before, see 
https://github.com/hpcugent/easybuild-framework/issues/581 .


There's one way to get what you want, which is making the run_cmd 
function collect output in a separate temporary log file specific to 
that command while the command is still running.


Right now, this is not done by default, but we could change that...

Of course, the other option would be to just let run_cmd stream the 
output of the command into the main log, as the command is running.
That's certainly doable too, but is a bit more tedious (certainly w.r.t. 
backward compatibility).



regards,

Kenneth



DV


On Jan 31 2017, at 9:31 am, Kenneth Hoste  wrote:

Hi Davide,

On 31/01/2017 16:01, Vanzo, Davide wrote:

Kenneth,
yes, for the configure and build steps I have the output in the
log filed (sorry for the confusion before), but I don't see
anything for the test step. For example, for both Tcl and Perl
the last thing I see is:

== 2017-01-30 17:55:58,057 easyblock.py:2274 INFO Running method
test_step part of step test

If the test hangs (as happened in both cases for me) I have no
clue what is going wrong.


Have you tried running with "eb --debug" to get a debug log?

The test step for Tcl is nothing more than a 'make test' afaik.

A non-debug log probably only shows which commands were run after
they completed (we should probably change that).


regards,

Kenneth


DV


On Jan 31 2017, at 4:09 am, Kenneth Hoste
  wrote:

Hi Davide,

On 30/01/2017 23:08, Vanzo, Davide wrote:

Hello world,
I would find quite useful to have an option (or maybe make
it a default behavior) to get the full raw standard output
and error from whatever EB is running (make, test, etc.).
For example, while installing Tcl it was hanging at the test
section. After trying manually, I realized it was the httpd
test that was hanging because of the iptables rules on that
port. If I would have had access to the raw output I could
have figured it out without having to redo the test manually
outside EB. This would be even more useful when developing
an easyconfig or easyblock.
Have I missed the option or is it something that should be
implemented on EB?


This output should be available in the log file that
EasyBuild collects?
The location of the (temporary) log file is printed at the
start of EB.

With the hanging Tcl installation, you should be able to just
dive into the log file after hitting Ctrl-C?

If needed, you could pass --debug to get a debug log, but the
info you're looking for should be there by default already...


regards,

Kenneth



Thanks!

-- 
Davide Vanzo, PhD

Application Developer
Adjunct Assistant Professor of 

Re: [easybuild] Raw output for debugging

[Vanzo, Davide]

Yes, no luck even with the debug flag. Here are the last last log lines before 
my SIGINT:

== 2017-01-31 09:07:15,484 easyblock.py:2263 DEBUG Not skipping test step 
(skippable: True, skip: None, skipsteps: [], module_only: False, force: False
== 2017-01-31 09:07:15,484 build_log.py:216 INFO testing...
== 2017-01-31 09:07:15,485 easyblock.py:2271 INFO Starting test step
== 2017-01-31 09:07:15,485 templates.py:151 DEBUG config: 

== 2017-01-31 09:07:15,485 templates.py:175 DEBUG version found in easyconfig 
is 5.24.0
== 2017-01-31 09:07:15,485 templates.py:219 DEBUG name: github_account, config: 
None
== 2017-01-31 09:07:15,485 templates.py:219 DEBUG name: name, config: Perl
== 2017-01-31 09:07:15,486 templates.py:219 DEBUG name: version, config: 5.24.0
== 2017-01-31 09:07:15,486 templates.py:219 DEBUG name: versionsuffix, config:
== 2017-01-31 09:07:15,486 templates.py:219 DEBUG name: versionprefix, config:
== 2017-01-31 09:07:15,486 templates.py:151 DEBUG config: 

== 2017-01-31 09:07:15,486 templates.py:175 DEBUG version found in easyconfig 
is 5.24.0
== 2017-01-31 09:07:15,487 templates.py:219 DEBUG name: github_account, config: 
None
== 2017-01-31 09:07:15,487 templates.py:219 DEBUG name: name, config: Perl
== 2017-01-31 09:07:15,487 templates.py:219 DEBUG name: version, config: 5.24.0
== 2017-01-31 09:07:15,487 templates.py:219 DEBUG name: versionsuffix, config:
== 2017-01-31 09:07:15,487 templates.py:219 DEBUG name: versionprefix, config:
== 2017-01-31 09:07:15,488 easyblock.py:2274 INFO Running method test_step part 
of step test
== 2017-01-31 09:07:15,488 run.py:137 DEBUG run_cmd: running cmd export 
LC_ALL=C && make test (in /mnt/ramdisk/Perl/5.24.0/GCC-5.4.0-2.26/perl-5.24.0)

DV


On Jan 31 2017, at 9:31 am, Kenneth Hoste  wrote:
Hi Davide,

On 31/01/2017 16:01, Vanzo, Davide wrote:
Kenneth,
yes, for the configure and build steps I have the output in the log filed 
(sorry for the confusion before), but I don't see anything for the test step. 
For example, for both Tcl and Perl the last thing I see is:

== 2017-01-30 17:55:58,057 easyblock.py:2274 INFO Running method test_step part 
of step test

If the test hangs (as happened in both cases for me) I have no clue what is 
going wrong.

Have you tried running with "eb --debug" to get a debug log?

The test step for Tcl is nothing more than a 'make test' afaik.

A non-debug log probably only shows which commands were run after they 
completed (we should probably change that).


regards,

Kenneth

DV


On Jan 31 2017, at 4:09 am, Kenneth Hoste 
 wrote:
Hi Davide,

On 30/01/2017 23:08, Vanzo, Davide wrote:
Hello world,
I would find quite useful to have an option (or maybe make it a default 
behavior) to get the full raw standard output and error from whatever EB is 
running (make, test, etc.). For example, while installing Tcl it was hanging at 
the test section. After trying manually, I realized it was the httpd test that 
was hanging because of the iptables rules on that port. If I would have had 
access to the raw output I could have figured it out without having to redo the 
test manually outside EB. This would be even more useful when developing an 
easyconfig or easyblock.
Have I missed the option or is it something that should be implemented on EB?

This output should be available in the log file that EasyBuild collects?
The location of the (temporary) log file is printed at the start of EB.

With the hanging Tcl installation, you should be able to just dive into the log 
file after hitting Ctrl-C?

If needed, you could pass --debug to get a debug log, but the info you're 
looking for should be there by default already...


regards,

Kenneth


Thanks!

--
Davide Vanzo, PhD
Application Developer
Adjunct Assistant Professor of Chemical and Biomolecular Engineering
Advanced Computing Center for Research and Education (ACCRE)
Vanderbilt University - Hill Center 201
(615)-875-9137
www.accre.vanderbilt.edu

Re: [easybuild] Raw output for debugging

[Kenneth Hoste]

Hi Davide,

On 31/01/2017 16:01, Vanzo, Davide wrote:

Kenneth,
yes, for the configure and build steps I have the output in the log 
filed (sorry for the confusion before), but I don't see anything for 
the test step. For example, for both Tcl and Perl the last thing I see is:


== 2017-01-30 17:55:58,057 easyblock.py:2274 INFO Running method 
test_step part of step test


If the test hangs (as happened in both cases for me) I have no clue 
what is going wrong.


Have you tried running with "eb --debug" to get a debug log?

The test step for Tcl is nothing more than a 'make test' afaik.

A non-debug log probably only shows which commands were run after they 
completed (we should probably change that).



regards,

Kenneth


DV


On Jan 31 2017, at 4:09 am, Kenneth Hoste  wrote:

Hi Davide,

On 30/01/2017 23:08, Vanzo, Davide wrote:

Hello world,
I would find quite useful to have an option (or maybe make it a
default behavior) to get the full raw standard output and error
from whatever EB is running (make, test, etc.). For example,
while installing Tcl it was hanging at the test section. After
trying manually, I realized it was the httpd test that was
hanging because of the iptables rules on that port. If I would
have had access to the raw output I could have figured it out
without having to redo the test manually outside EB. This would
be even more useful when developing an easyconfig or easyblock.
Have I missed the option or is it something that should be
implemented on EB?


This output should be available in the log file that EasyBuild
collects?
The location of the (temporary) log file is printed at the start
of EB.

With the hanging Tcl installation, you should be able to just dive
into the log file after hitting Ctrl-C?

If needed, you could pass --debug to get a debug log, but the info
you're looking for should be there by default already...


regards,

Kenneth



Thanks!

-- 
Davide Vanzo, PhD

Application Developer
Adjunct Assistant Professor of Chemical and Biomolecular Engineering
Advanced Computing Center for Research and Education (ACCRE)
Vanderbilt University - Hill Center 201
(615)-875-9137
www.accre.vanderbilt.edu 

Re: [easybuild] Raw output for debugging

[Vanzo, Davide]

Kenneth,
yes, for the configure and build steps I have the output in the log filed 
(sorry for the confusion before), but I don't see anything for the test step. 
For example, for both Tcl and Perl the last thing I see is:

== 2017-01-30 17:55:58,057 easyblock.py:2274 INFO Running method test_step part 
of step test

If the test hangs (as happened in both cases for me) I have no clue what is 
going wrong.

DV


On Jan 31 2017, at 4:09 am, Kenneth Hoste  wrote:
Hi Davide,

On 30/01/2017 23:08, Vanzo, Davide wrote:
Hello world,
I would find quite useful to have an option (or maybe make it a default 
behavior) to get the full raw standard output and error from whatever EB is 
running (make, test, etc.). For example, while installing Tcl it was hanging at 
the test section. After trying manually, I realized it was the httpd test that 
was hanging because of the iptables rules on that port. If I would have had 
access to the raw output I could have figured it out without having to redo the 
test manually outside EB. This would be even more useful when developing an 
easyconfig or easyblock.
Have I missed the option or is it something that should be implemented on EB?

This output should be available in the log file that EasyBuild collects?
The location of the (temporary) log file is printed at the start of EB.

With the hanging Tcl installation, you should be able to just dive into the log 
file after hitting Ctrl-C?

If needed, you could pass --debug to get a debug log, but the info you're 
looking for should be there by default already...


regards,

Kenneth


Thanks!

--
Davide Vanzo, PhD
Application Developer
Adjunct Assistant Professor of Chemical and Biomolecular Engineering
Advanced Computing Center for Research and Education (ACCRE)
Vanderbilt University - Hill Center 201
(615)-875-9137
www.accre.vanderbilt.edu

Re: [easybuild] Raw output for debugging

[Kenneth Hoste]

Hi Davide,

On 30/01/2017 23:08, Vanzo, Davide wrote:

Hello world,
I would find quite useful to have an option (or maybe make it a 
default behavior) to get the full raw standard output and error from 
whatever EB is running (make, test, etc.). For example, while 
installing Tcl it was hanging at the test section. After trying 
manually, I realized it was the httpd test that was hanging because of 
the iptables rules on that port. If I would have had access to the raw 
output I could have figured it out without having to redo the test 
manually outside EB. This would be even more useful when developing an 
easyconfig or easyblock.
Have I missed the option or is it something that should be implemented 
on EB?


This output should be available in the log file that EasyBuild collects?
The location of the (temporary) log file is printed at the start of EB.

With the hanging Tcl installation, you should be able to just dive into 
the log file after hitting Ctrl-C?


If needed, you could pass --debug to get a debug log, but the info 
you're looking for should be there by default already...



regards,

Kenneth



Thanks!

--
Davide Vanzo, PhD
Application Developer
Adjunct Assistant Professor of Chemical and Biomolecular Engineering
Advanced Computing Center for Research and Education (ACCRE)
Vanderbilt University - Hill Center 201
(615)-875-9137
www.accre.vanderbilt.edu

[easybuild] Raw output for debugging

[Vanzo, Davide]

Hello world,
I would find quite useful to have an option (or maybe make it a default 
behavior) to get the full raw standard output and error from whatever EB is 
running (make, test, etc.). For example, while installing Tcl it was hanging at 
the test section. After trying manually, I realized it was the httpd test that 
was hanging because of the iptables rules on that port. If I would have had 
access to the raw output I could have figured it out without having to redo the 
test manually outside EB. This would be even more useful when developing an 
easyconfig or easyblock.
Have I missed the option or is it something that should be implemented on EB?

Thanks!

--
Davide Vanzo, PhD
Application Developer
Adjunct Assistant Professor of Chemical and Biomolecular Engineering
Advanced Computing Center for Research and Education (ACCRE)
Vanderbilt University - Hill Center 201
(615)-875-9137
www.accre.vanderbilt.edu