Repository: dask/dask
Pull request: Add Tom's log config example
Fixes https://github.com/dask/distributed/issues/3669


Problem statement:
Write logs to disk as well
IIUC the scheduler and workers currently only log in memory. This works fine except if the scheduler or worker dies, in which case these logs are lost. It would be useful for logs to also be written to disk. This would allow users to inspect logs from dead workers to better understand what is happening.

Hints from issue discussion:
I think the scheduler and workers will log to stdout (or may stderr?). For example:

```python
In [1]: from distributed import Scheduler

In [2]: s = await Scheduler(host="localhost")
distributed.scheduler - INFO - Clear task state
distributed.scheduler - INFO -   Scheduler at:     tcp://127.0.0.1:51582

In [3]: await s.close()
distributed.scheduler - INFO - Scheduler closing...
distributed.core - INFO - Event loop was unresponsive in Scheduler for 3.35s.  This is often caused by long-running GIL-holding functions or moving large chunks of data. This can cause timeouts and instability.
distributed.scheduler - INFO - Scheduler closing all comms

In [4]:
```

Depending on your deployment there may be a built-in way to save stdout/stderr to log files on disk 
Yeah we could duplicate the file descriptors and redirect them. Could also add a `FileHandler`. Redirection may also be an option. Maybe there are other options? 🙂
I think documenting how to use a FileHandler in the dask config

```python
import dask

logging_config = {
    "version": 1,
    "handlers": {
        "file": {
            "class": "logging.handlers.RotatingFileHandler",
            "filename": "output.log",
            "level": "INFO",
        },
        "console": {
            "class": "logging.StreamHandler",
            "level": "INFO",
        }
    },
    "loggers": {
        "distributed.worker": {
            "level": "INFO",
            "handlers": ["file", "console"],
        },
        "distributed.scheduler": {
            "level": "INFO",
            "handlers": ["file", "console"],
        }
    }
}
dask.config.config['logging'] = logging_config

from distributed import Client

client = Client()
```

```
$ cat output.log
Clear task state
  Scheduler at:     tcp://127.0.0.1:51929
  dashboard at:            127.0.0.1:8787
Register worker <Worker 'tcp://127.0.0.1:51935', name: 2, memory: 0, processing: 0>
Starting worker compute stream, tcp://127.0.0.1:51935
Register worker <Worker 'tcp://127.0.0.1:51937', name: 3, memory: 0, processing: 0>
Starting worker compute stream, tcp://127.0.0.1:51937
Register worker <Worker 'tcp://127.0.0.1:51939', name: 0, memory: 0, processing: 0>
Starting worker compute stream, tcp://127.0.0.1:51939
Register worker <Worker 'tcp://127.0.0.1:51941', name: 1, memory: 0, processing: 0>
Starting worker compute stream, tcp://127.0.0.1:51941
Receive client connection: Client-c2f3dd12-75b6-11ea-9777-186590cd1c87
```
Thanks Tom! 😄 Wasn't aware this already existed. Yes, docs about this feature would be useful.

Do you know if we also have logs of the `Nanny`s somewhere as well?
I think providing a 

```yaml
logger:
  distributed.nanny:
    level: ...
```

will configure the nanny logger.
The `Nanny`s have a similar logging setup to the `Scheduler` and `Worker`s. For example, adding a `"distributed.nanny"` entry to Tom's example would also out `Nanny` logs to `output.log`

Commit message: Add Tom's log config example

Patch to review:
diff --git a/docs/source/debugging.rst b/docs/source/debugging.rst
index ba3c4aef402..7a32ce087b9 100644
--- a/docs/source/debugging.rst
+++ b/docs/source/debugging.rst
@@ -179,7 +179,8 @@ launching Dask on your own, they will probably dump to the screen unless you
 <https://en.wikipedia.org/wiki/Redirection_(computing)#Redirecting_to_and_from_the_standard_file_handles>`_
 .
 
-You can control the logging verbosity in the ``~/.dask/config.yaml`` file.
+You can control the logging verbosity in the :doc:`configuration`, for example,
+the ``~/.dask/config.yaml`` file.
 Defaults currently look like the following:
 
 .. code-block:: yaml
@@ -189,9 +190,48 @@ Defaults currently look like the following:
      distributed.client: warning
      bokeh: error
 
-So, for example, you could add a line like ``distributed.worker: debug`` to get
+The specific components which you can set are ``distributed.client``,  ``distributed.scheduler``,
+``distributed.nanny``, and ``distributed.worker`` so, for example, you could add a line
+like ``distributed.worker: debug`` to get
 *very* verbose output from the workers.
 
+Furthermore, you can explicitly assign handlers to loggers. The following example
+assigns both file ("output.log") and console output to the scheduler and workers; this case is done
+in code. See the `python logging`_ documentation for information on the meaning of
+specific terms here.
+
+.. code-block:: python
+
+    import dask
+
+    logging_config = {
+        "version": 1,
+        "handlers": {
+            "file": {
+                "class": "logging.handlers.RotatingFileHandler",
+                "filename": "output.log",
+                "level": "INFO",
+            },
+            "console": {
+                "class": "logging.StreamHandler",
+                "level": "INFO",
+            }
+        },
+        "loggers": {
+            "distributed.worker": {
+                "level": "INFO",
+                "handlers": ["file", "console"],
+            },
+            "distributed.scheduler": {
+                "level": "INFO",
+                "handlers": ["file", "console"],
+            }
+        }
+    }
+    dask.config.config['logging'] = logging_config
+
+.. _python logging: https://docs.python.org/3/library/logging.html
+
 
 LocalCluster
 ------------


Code review comments:
diff_hunk: @@ -189,9 +190,48 @@ Defaults currently look like the following:
      distributed.client: warning
      bokeh: error
 
-So, for example, you could add a line like ``distributed.worker: debug`` to get
+The specific components which you can set are ``distributed.client``,  ``distributed.scheduler``,
+``distributed.nanny``, and ``distributed.worker`` so, for example, you could add a line
+like ``distributed.worker: debug`` to get
 *very* verbose output from the workers.
 
+Furthermore, you can explicitly assign handlers to loggers. The following example
+assigns both file ("output.log") and console output to the scheduler and workers; this case is done
+in code. See the `python logging`_ documentation for information on the meaning of
+specific terms here.
+
+.. code-block:: python
path: docs/source/debugging.rst
text: @user1:
Thoughts on converting this to YAML and writing the example as if you're in the dask-config?

Otherwise we should have a strong warning that the changes here need to be applied before any workers are created (and perhaps before distributed is even imported. I don't recall what all is done at import time).


@author:
It would be nice to have both, but that would be rather long. I don't think there's an example of complex configuration by code elsewhere ( @user2 ?)

@user1:
To be clear, I'd say just have the YAML version.


```yaml
# ~/.config/dask/dask.yaml
logging:
  version: 1
  handlers:
    file:
      class: logging.handlers.RotatingFileHandler
...
```

I *think* that should work.


@author:
What is the `version: 1`, by the way?

@user1:
It's required by Python's logging config: https://docs.python.org/3/library/logging.config.html#dictionary-schema-details