Change default log format to include timestamp (#5897)

distributed/cli/tests/test_dask_scheduler.py

@@ -218,13 +218,11 @@ def test_scheduler_port_zero(loop):
 def test_dashboard_port_zero(loop):
     pytest.importorskip("bokeh")
     with popen(["dask-scheduler", "--dashboard-address", ":0"]) as proc:
-        count = 0
-        while count < 1:
-            line = proc.stderr.readline()
-            if b"dashboard" in line.lower():
-                sleep(0.01)
-                count += 1
-                assert b":0" not in line
+        for line in proc.stderr:
+            if b"dashboard at" in line:
+                dashboard_port = int(line.decode().split(":")[-1].strip())
+                assert dashboard_port != 0
+                break
 
 
 PRELOAD_TEXT = """

distributed/distributed.yaml

@@ -269,7 +269,7 @@ distributed:
 
     max-error-length: 10000 # Maximum size traceback after error to return
     log-length: 10000  # default length of logs to keep in memory
-    log-format: '%(name)s - %(levelname)s - %(message)s'
+    log-format: '%(asctime)s - %(name)s - %(levelname)s - %(message)s'
     pdb-on-err: False       # enter debug mode on scheduling error
     system-monitor:
       interval: 500ms

distributed/tests/test_config.py

@@ -1,5 +1,6 @@
 import logging
 import os
+import re
 import subprocess
 import sys
 import tempfile
@@ -89,9 +90,18 @@ def test_logging_default():
 
         distributed_log = distributed_log.getvalue().splitlines()
         foreign_log = foreign_log.getvalue().splitlines()
+        # Filter out asctime
+        pattern = re.compile(r"^\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2},\d* - (.*)$")
+        without_timestamps = []
+        for msg in distributed_log:
+            m = re.match(pattern, msg)
+            if m:
+                without_timestamps.append(m.group(1))
+            else:
+                raise AssertionError(f"Unknown format encountered {msg}")
 
         # distributed log is configured at INFO level by default
-        assert distributed_log == [
+        assert without_timestamps == [
             "distributed - INFO - 2: info",
             "distributed.foo.bar - INFO - 3: info",
         ]
@@ -139,10 +149,7 @@ def test_logging_simple_under_distributed():
 
             distributed_log = distributed_log.getvalue().splitlines()
 
-            assert distributed_log == [
-                "distributed.foo - INFO - 1: info",
-                "distributed.foo.bar - ERROR - 3: error",
-                ], (dask.config.config, distributed_log)
+            assert len(distributed_log) == 2, (dask.config.config, distributed_log)
             """
 
         subprocess.check_call([sys.executable, "-c", code])
@@ -174,10 +181,7 @@ def test_logging_simple():
 
             distributed_log = distributed_log.getvalue().splitlines()
 
-            assert distributed_log == [
-                "distributed.foo - INFO - 1: info",
-                "distributed.foo.bar - ERROR - 3: error",
-                ], (dask.config.config, distributed_log)
+            assert len(distributed_log) == 2, (dask.config.config, distributed_log)
             """
 
         subprocess.check_call([sys.executable, "-c", code])

distributed/tests/test_versions.py

@@ -123,8 +123,8 @@ def test_python_mismatch(kwargs_matching):
 async def test_version_warning_in_cluster(s, a, b):
     s.workers[a.address].versions["packages"]["dask"] = "0.0.0"
 
-    with pytest.warns(None) as record:
-        async with Client(s.address, asynchronous=True) as client:
+    with pytest.warns(Warning) as record:
+        async with Client(s.address, asynchronous=True):
             pass
 
     assert record