Log dir tidy

[datamel]

These changes close #4802

Log directory renaming:

• log/flow-config => log/config
• log/workflow => log/scheduler

New Directory for remote install logs: log/remote-install/

Filenames for remote file installation are now on an install-target basis with filename format: <timestamp>-<start/restart/reload>-<install-target>.log

Filename format change for scheduler log:

<log number>-<start/restart>-<start_number>.log
(log/scheduler/log remains a symlink to the current log)

Filename format change for config log:

After a lengthy discussion UK end,
<log number>-<start/restart/reload>-<start_number>.log
The reload start number should correspond to the current start number when the reload took place.

Requirements check-list

• I have read CONTRIBUTING.md and added my name as a Code Contributor.
• Contains logically grouped changes (else tidy your branch by rebase).
• Does not contain off-topic changes (use other PRs for other changes).
• Applied any dependency changes to both setup.cfg and conda-environment.yml.
• Appropriate tests are included (unit and/or functional).
• Appropriate change log entry included.
• (master branch) I have opened a documentation PR at log tidy changes cylc-doc#463.

[hjoliver]

Looks good, just a few minor suggestions.

[wxtim]

Adding a pointless comment so that I get a notification when this gets merged, so that I can start work on cylc-review.

[oliver-sanders]

Adding a pointless comment so that I get a notification

BTW you can [un]subscribe to an issue/pr from the pane on the right hand side (under milestone), especially useful for tracking issues in other projects.

[oliver-sanders]

Looks good, one small efficiency comment:

[oliver-sanders]

Looks good.

I think I found one issue in testing, cylc cat-log has a feature for setting the log rotation number which I think needs to be updated to the new filename pattern?:

cylc cat-log <workflow> -r 1

Reviewing I've had a couple of ideas (whoops):

1) Use log number in log filenames

Here is the log directory for a workflow I have run, then consequently restarted, the log files have "rolled over" three times:

`-- scheduler
    |-- 20220509T111659+01-start.log
    |-- 20220509T111701+01-start.log
    |-- 20220509T111704+01-start.log
    |-- 20220509T111722+01-restart.log
    |-- 20220509T111732+01-restart.log
    `-- log -> 20220509T111732+01-restart.log

Internally we keep a record of the "log number" which gets incremented with each "rollover", you can find this near the top of each file e.g:

 Run: (re)start=1 log=1

We might be able to template this into the filename e.g:

`-- scheduler
    |-- 01-20220509T111659+01-start.log
    |-- 02-20220509T111701+01-start.log
    |-- 03-20220509T111704+01-start.log
    |-- 04-20220509T111722+01-restart.log
    |-- 05-20220509T111732+01-restart.log
    `-- log -> 05-20220509T111732+01-restart.log

Or:

`-- scheduler
    |-- 20220509T111659+01-01-start.log
    |-- 20220509T111701+01-02-start.log
    |-- 20220509T111704+01-03-start.log
    |-- 20220509T111722+01-04-restart.log
    |-- 20220509T111732+01-05-restart.log
    `-- log -> 20220509T111732+01-05-restart.log

Or possibly even (after all there are timestamps in the log [by default]):

`-- scheduler
    |-- 01-start-01.log
    |-- 02-start-01.log
    |-- 03-start-01.log
    |-- 04-restart-02.log
    |-- 05-restart-02.log
    `-- log -> 05-restart-02.log

Ideas?

Would be good if we could differentiate a rollover from a restart from the filename as workflows are often "restarted in anger" when problems occur.

2) Write the rsync command to the file install log

Might be nice to log the rsync command at the top of the fileinstall log. Makes it clearer what fileinstall means and how to interpret the stdout e.g:

diff --git a/cylc/flow/task_remote_mgr.py b/cylc/flow/task_remote_mgr.py
index 0c3a78768..be72ceb2e 100644
--- a/cylc/flow/task_remote_mgr.py
+++ b/cylc/flow/task_remote_mgr.py
@@ -56,6 +56,7 @@ from cylc.flow.platforms import (
 )
 from cylc.flow.remote import construct_rsync_over_ssh_cmd, construct_ssh_cmd
 from cylc.flow.subprocctx import SubProcContext
+from cylc.flow.util import format_cmd
 from cylc.flow.wallclock import get_current_time_string
 from cylc.flow.workflow_files import (
     KeyInfo,
@@ -532,13 +533,14 @@ class TaskRemoteMgr:
             Path(install_log_path).parent.mkdir(parents=True, exist_ok=True)
             with open(install_log_path, 'a') as install_log:
                 install_log.write(
-                    'File installation information for '
-                    f'{install_target}:\n{ctx.out}'
+                    f'$ {format_cmd(ctx.cmd, maxlen=80)}'
+                    '\n\n### STDOUT:'
+                    f'\n{ctx.out}'
                 )
                 if ctx.err:
                     install_log.write(
-                        '\n File installation error for '
-                        f'{install_target}:\n{ctx.err}'
+                        '\n\n### STDERR:'
+                        f'\n{ctx.err}'
                     )
         if ctx.ret_code == 0:
             # Both file installation and remote init success

That produces files like this:

$ rsync --delete \ 
    --rsh=ssh -oBatchMode=yes -oConnectTimeout=10 \ 
    --include=/.service/ --include=/.service/server.key -a \ 
    --checksum --out-format=%o %n%L --no-t --exclude=log \ 
    --exclude=share --exclude=work --include=/app/*** \ 
    --include=/bin/*** --include=/etc/*** --include=/lib/*** \ 
    --exclude=* ~/cylc-run/remotes/run4/ \ 
    myhost:$HOME/cylc-run/remotes/run4/

### STDOUT:
send .service/server.key


### STDERR:
some stderr...

[datamel]

Thanks for the review.

I think I found one issue in testing, cylc cat-log has a feature for setting the log rotation number which I think needs to be updated to the new filename pattern?:

I'll have a look into this now.

1) Use log number in log filenames

...
We might be able to template this into the filename

Yes, good idea, I'll give this a whirl.
My preference would be for

-- scheduler
    |-- 01-start.log
    |-- 02-start.log
    |-- 03-start.log
    |-- 04-restart.log
    |-- 05-restart.log
    `-- log -> 05-restart.log

As it seems tidier to me, like you said we have timestamp in the files.

2) Write the rsync command to the file install log

Yes, love this idea. That would be super helpful for debugging.

[hjoliver]

Yes, good idea, I'll give this a whirl.
My preference would be for ...

👍 mine too!

[hjoliver]

One typing issue causing trouble:

 cylc/flow/loggingutil.py:148: error: Need type annotation for "header_records" (hint: "header_records: List[<type>] = ...")  [var-annotated]

[oliver-sanders]

Have done a quick functional review, looks good. The log numbers increment correctly, the housekeeping is working well.

One small thing, the start number in the filename is one higher than the start number in the log itself, easy fix:

$ head scheduler/32-start-01.log 
2022-06-08T12:47:49Z INFO - Run: (re)start=0 log=32
$ head scheduler/37-restart-02.log 
2022-06-08T12:48:28Z INFO - Run: (re)start=1 log=5

[oliver-sanders]

The config logs look ok, however, I think the log number here is not needed? Just need the start number?

|-- config
|   |-- 01-start-01.cylc
|   |-- 02-restart-02.cylc
|   `-- flow-processed.cylc

[MetRonnie]

Partial review.

I am a little confused by the numbers e.g. 03-restart-04.log. What do the 2 numbers mean? It doesn't match the PR description

Filename format change for scheduler log:
<timestamp>-<start/restart>.log