Gather Logs

[mrocklin]

There is some talk of standardizing a "please get me the logs for this worker" interface for the different resource managers (kubernetes, yarn, jobqueue) here: https://github.com/dask/distributed/pull/2874/files#r306986962

Is this something that we could easily implement in Dask-Jobqueue? What form would it take? Presumably we would find the out/err files, read their contents, and send them back to the caller.

• Are these files usually made available during the job?
• Is this uniform enough across deployments so that it is feasible?

[lesteve]

Are these files usually made available during the job?

Yes at least for the job schedulers I am familiar with: log files are created when the job is submitted and updated during the job execution. Note there may be some significant delay between the execution of a print statement on the worker and the content of the log file (~1 minute even with sys.stdout.flush() on our cluster).

More details

in my experience there are some buffers here and there so that there is a significant delay between the content of the log file and what has been executed on the worker. In some experiments I ran on our cluster a while ago, even when using sys.stdout.flush() (or using PYTHONUNBUFFERED) there was a delay of ~1 minute between the time a function doing a print was submitted and the time the line reached the log file. FWIW in our cluster, using os.fsync(sys.stdout.filename()) would make the delay a lot shorter (~1 second), this may be highly cluster-specific.

Is this uniform enough across deployments so that it is feasible?

it seems feasible but is always going to be fragile ... we have the log_directory parameter that indicates where the logs end up. I reckon the jobid is in the log filename for most job schedulers by default (but of course this may not be true for some job schedulers and/or some cluster-specific setups). Note that this is always going to be a bit fragile, since the user can override the name of the logfile if he wants by using job_extra.

cc @guillaumeeb @willirath in case they have more comments about this.

[guillaumeeb]

With PBS Pro, you've got the qpeek $JOB_ID command to get the stdout, and qpeek -e $JOB_ID for stderr.

As far as I know, output files are not availabe until the end of the job, you need to use these commands when the job is running. But maybe you can go and find them on the node where the job is running...

Nonetheless, there is a way to get those logs. It is just already different from what @lesteve is used to...

[lesteve]

Ahhh the wonderful world of HPC clusters, where everybody does something just slighly different than everybody else ;-)

[bw4sz]

Is there suggested best practice for dask-jobqueue for flushing worker logs on SLURM. I'm finding that i'm not getting print statements until the process is tearing down, sometimes hours later. Where should I flush to try to improve?

From the local worker directory I see lots of logs, but they are empty for long periods of time. Everything prints eventually without an issue.

cat dask-worker-49747319.out

---

EDIT: For anyone arriving here. Adding sys.stdout.flush() to the scheduler, not the workers, is the key, atleast for SLURM.

[lesteve]

I would guess this is not specific to dask-jobqueue but to log buffering from your job scheduler and/or your cluster filesystem so this is likely to be very cluster-specific.

I found this in my notes from a while ago on my SGE cluster. Note some of this may have performance implications. Here is the different options that "worked" for me:

• Adding in env_extra works: export PYTHONUNBUFFERED=non_empty. delay ~1
  minute (SGE log in my $HOME).
• Using sys.stdout.flush() delay of ~1 minute (SGE log in my $HOME). Note for stderr
  sys.stderr.flush() does help as well for some reason (I thought stderr was
  not buffered but it might be by Python ...).
• sys.stdout.flush() + os.fsync(sys.stdout.fileno()) is instant.