JMSLab / Template

Template for research repository using scons.
9 stars 1 forks source link

Pull Request for #19: Matlab builder issues #21

Closed mcaceresb closed 3 years ago

mcaceresb commented 3 years ago

@veli-m-andirin Please review the snippet works (in particular under Windows) and that it fixes the issues highlighted here.

veli-m-andirin commented 3 years ago

Thanks @mcaceresb! I had a look at the code and tried to test whether it fixes the issues that you higlighted.

First, it doesn't seem to save anything to the log file.

To test this I modified the matlab code here so that it gives a simple error. The resulting sconscript.log is here. The error is indeed printed out to the sconscript.log, but can you also add timestamps (builder log created: / builder log completed: )?

Second, matlab doesn't have a "batch mode" so if there is an error (or if a user forgets to put an exit in their .m file) matlab will not exit.

I confirm that it exits now.

Third, we copied the gslab builder, which makes a copy of the source file into the repository root and runs the copy. This means that matlab auxiliary programs, typically saved in the same directory as the source, are no longer available (since matlab is running from the repo's root).

By auxiliary programs, do you mean some other matlab script in the same directory? If that's the case, can't we just load them by giving their path relative to the root of the repository? I think this is what we do in other projects.

I see two minor style issues with this sconstruct.log.

mcaceresb commented 3 years ago

@veli-m-andirin Will work on the rest. Two replies:

By auxiliary programs, do you mean some other matlab script in the same directory? If that's the case, can't we just load them by giving their path relative to the root of the repository? I think this is what we do in other projects.

Yes, and this script should do that by the "addpath" line.

  • I noticed that the commands we use such as matlab, RScript etc are in quotation marks. This wasn't the case in GSLab Python. Although this doesn't seem to affect anything I wanted to flag this. Let me know if this has been discussed before and I have missed it.

The quotes are there in case the user passes a program path that has spaces. It doesn't affect anything when there are no spaces (normal use case) but it helps if there are (e.g. full path to Stata executable).

mcaceresb commented 3 years ago

To test this I modified the matlab code here so that it gives a simple error. The resulting sconscript.log is here. The error is indeed printed out to the sconscript.log, but can you also add timestamps (builder log created: / builder log completed: )?

@veli-m-andirin I have done this but to be clear this is new. The log start and end times get printed if there's no error, and if there is an error the program exited without it. I have made it so the error message is printed to the log along the time stamps in case there was an error. LMK how it looks. At the moment I think that the error message may be getting printed twice?

I also compressed the spacing.

veli-m-andirin commented 3 years ago

Thanks @mcaceresb!

mcaceresb commented 3 years ago

@veli-m-andirin

  • Regarding the timestamps, by getting printed twice, do you have in mind the error message being repeated in the same log file? If that's the case, I think it is printed only once.

it's printed twice for me if there's an error inside Matlab (at least for Matlab; see output/analysis/plots/sconscript.log if you run the script with an error).

  • One thing I noticed with sconstruct.log files is that we have two tracebacks now, see the file posted here. In Python2 version we used to have only one traceback. Just wanted to check if this is something we should worry about.

I'd be really surprised if that double stacktrace wasn't there before, but I took it out in latest commit.

mcaceresb commented 3 years ago

@veli-m-andirin i figured out what's up. There doesn't seem to be a good solution for either.

  1. The "double traceback" is due to scons. When it encounters an error tells you: I found an error and this is the error message. Python then proceeds to produce a stacktrace, but the stacktrace ends with our error message, so it gets printed twice.

  2. My theory: On Windows, Matlab is run on the background as a regular app, so the output captured in the log when there is an error is, I think, only captured inside Python. On nix (Linux and OSX) Matlab runs from the console, so all the output is captured. Since the error is printed to the console, it is captured both by the log capturing everything printed to the console (stdout) and by Python capturing the error. Hence it appears twice for me (but not for you).

mcaceresb commented 3 years ago

@veli-m-andirin Actually it seems the entire log is getting printed twice for me... I thought it was just the error message, but if it's the entire log then this really matters because on nix it will end up being possibly very very confusing.

mcaceresb commented 3 years ago

@veli-m-andirin Ok, I have made it so the console output gets redirected to /dev/null. This way, the scons log only has the our error message and the matlab log only has the matlab portion. Can you try it? Not 100% if the /dev/null thing will do anything on Windows or not. (PS: Can you also print things inside Matlab before you make your Matlab file fail? Just to make sure what is only printed to the Matlab log.)

veli-m-andirin commented 3 years ago

Thanks @mcaceresb!

Here are the new files: sconscript.log, sconstruct.log.

Regarding how we can prevent the error message appearing in sconscript.log, maybe we can revert the changes we made for timestamps to appear. sconscript.log here did not have the error message.

I also wonder why this double traceback issue didn't happen in Python2, but it may not be worth investigating.

mcaceresb commented 3 years ago

@veli-m-andirin

Did you run the latest? I don't see /dev/null included in your Matlab call?

veli-m-andirin commented 3 years ago

@mcaceresb,

Very sorry for that, I haven't pulled the changes. Here is the new version for the sconstruct.log file. This time output\analysis\plots\sconscript.log couldn't be created.

mcaceresb commented 3 years ago

@veli-m-andirin That's odd. Can you try again? Pushed a change.

veli-m-andirin commented 3 years ago

@mcaceresb still the same issue: sconstruct.log

mcaceresb commented 3 years ago

@veli-m-andirin To be clear, you didn't have this issue in commit #a5cb5fc3b15945f535d234ecfec82d8ae633c656?

veli-m-andirin commented 3 years ago

@mcaceresb, no, I didn't have this issue in that commit. Reverting back the changes made in later commits, this problem disappears.

mcaceresb commented 3 years ago

@veli-m-andirin Made another attempt; LMK if it happens in latest.

veli-m-andirin commented 3 years ago

Thanks @mcaceresb,

Here is how the new sconscript and sconstruct look like: sconstruct.log sconscript.log

In addition, we have source_289853d6f600671baef771a2e8cfdc336fcae735.log in the root of the repository which isn't removed.

mcaceresb commented 3 years ago

@veli-m-andirin Ok, the logs are looking good! (At least to me; I don't think the double printing of the error message in sconstruct is solvable, since it's a scons thing, but I also don't think that's such a big deal.)

The only issue now is the leftover dummy log I made to redirect output. I've created a cleanup method for the builders so that some post-execution commands can get run regardless of whether there were any errors. I delete the files in cleanup. LMK if it worked.

veli-m-andirin commented 3 years ago

Thanks @mcaceresb! It worked, the dummy log is removed.

mcaceresb commented 3 years ago

@veli-m-andirin Victory! Thanks.

mcaceresb commented 3 years ago

See summary here.