MintPy icon indicating copy to clipboard operation
MintPy copied to clipboard

progress reporting / logging

Open falkamelung opened this issue 6 years ago • 6 comments

As mintpy uses print() statements to display progress to the screen (STDOUT), this information gets scrambled on clusters. For example under LSF bpeek command does not properly relay where mintpy is in the processing. I see two ways to resolve this.

  1. Proper logging using the python logging modules
  2. adding sys.stdout.flush() at the end of each print statement.

Obviously, (2) is much easier than (1). I will this unless somebody yells. I unlikely will do the entire code but only those scripts that occasionally give trouble. I could look for a student to do the entire code. Having a student adding proper logging may not be a good idea as this may need too much oversight.

falkamelung avatar Aug 02 '19 12:08 falkamelung

@falkamelung I have not seen (2) in other projects, could you give some references?

We should apply proper logging. I would recommend you to find a permanent solution with proper documentation so that other developers could easily follow it.

yunjunz avatar Aug 02 '19 14:08 yunjunz

This remains an issue

falkamelung avatar May 24 '20 14:05 falkamelung

Since this issue still remains, let's keep it open for future reference.

yunjunz avatar May 24 '20 22:05 yunjunz

A related/perhaps the same issue is relevant error reporting. I've run into issues where mintpy crashes and it turns out to be simple file naming conventions; e.g. underscores vs dashes in a name. Usually the crash point happens well after the actual issue code, so some sort of verbose log file could be helpful when sorting this out.

jlmaurer avatar May 25 '20 16:05 jlmaurer

@jlmaurer Could you post an example so that we could be more aware of the scenario? That would help shape the future logging style.

yunjunz avatar May 25 '20 17:05 yunjunz

Would it be useful to capture all print commands and then write it to a log file? I do that in my software. Here is the template I use for my own projects. I use 2 functions where 1 function is used to run the CLI and capture output, the 2nd function writes it to a log file.

I am sharing my CLI tool I use which I got from Whitebox Tools with some revisions for logging.

    def _run_command(self, cmd: str, cwd: Union[str, None]) -> int:
        """
        Run command and log to file
        :param cmd: Command to execute
        :param cwd: Current working directory
        :return: Return code 0 is success. 1 is failure
        """

        # Create file to capture output
        if not os.path.exists(self.log_file):
            with open(self.log_file, 'w', newline='') as f:
                f.write('DINSAR LOG FILE\n')
                f.write(f'TIMESTAMP: {self.timestamp}\n')
                f.write('======================================\n')

        proc = subprocess.Popen(cmd, shell=True, stdout=subprocess.PIPE,
                                stderr=subprocess.STDOUT, bufsize=0, universal_newlines=True,
                                cwd=cwd)
        return_code = 0
        while proc is not None:
            try:
                line = proc.stdout.readline()
            except UnicodeDecodeError:
                sys.stdout.flush()
                continue
            sys.stdout.flush()
            if line != '':
                print_line = line.replace('\n', '')
                print(print_line)
                with open(self.log_file, 'a', newline='') as f:
                    f.write(line)
                # Catch errors using string matching
                if 'Error:' in line:
                    msg = f'WARNING: Possible CLI failure'
                    self._print_to_log(msg)
                    return_code = 1
            else:
                break

        return return_code
    def _print_to_log(self, input_var, print_to_terminal=True) -> None:
        """
        Object print command that will also print to the log file
        :return:
        """
        input_var = str(input_var)
        if print_to_terminal:
            print(input_var)
        path = self.log_file
        file_exists = os.path.exists(path)
        with open(path, 'a', newline='') as f:
            if not file_exists:
                f.write('MINTPY LOG FILE\n')
                f.write(f'TIMESTAMP: {self.timestamp}\n')
                f.write('======================================\n')
            if not input_var.endswith('\n'):
                input_var += '\n'
            f.write(input_var)

Here is a sample log file from my own analyses:

image

Using the functions as an example, you will have to replace every print() statement with _print_to_log(). E.g., _print_to_log('Hello world').

If you just want to write it to the log file and not print on the terminal then set print_to_terminal=False.

pbrotoisworo avatar Mar 19 '21 03:03 pbrotoisworo

hi I am working in ISCE software, I want to download Dem but I can’t download. I have had this issue for 10 days I have an error: isce.contrib.demUtils.DemStitcher - WARNING - There was a problem in retrieving the file http://e4ftl01.cr.usgs.gov/MEASURES/SRTMGL1.003/2000.02.11/N30E048.SRTMGL1.hgt.zip. Exception

would like help me please.

sisi-ali avatar Aug 02 '22 06:08 sisi-ali