Skip to content

Comments

Fix excessive logging on P2P retry#8511

Merged
hendrikmakait merged 3 commits intodask:mainfrom
hendrikmakait:fix-excessive-logging
Feb 26, 2024
Merged

Fix excessive logging on P2P retry#8511
hendrikmakait merged 3 commits intodask:mainfrom
hendrikmakait:fix-excessive-logging

Conversation

@hendrikmakait
Copy link
Member

@hendrikmakait hendrikmakait commented Feb 16, 2024

This PR avoids logging the entire retried partial including the applied arguments.

Previously, retrying in P2P would log excessively on retry:

2024-01-17 10:47:07,146 - distributed.utils_comm - INFO - Retrying functools.partial(<bound method ShuffleRun._send of <DataFrameShuffleRun: id='77201d9aa0bf473b1451a90af7e015de', run_id=6, local_address='tls://10.164.0.24:38325', closed=False,
transferred=False>>, 'tls://10.164.0.7:34781', [(33, b'\xff\xff\xff\xff\xa0\x05\x00\x00\x10\x00\x00\x00\x00\x00\n\x00\x0e\x00\x06\x00\x05\x00\x08\x00\n\x00\x00\x00\x00\x01\x04\x00\x10\x00\x00\x00\x00\x00\n\x00\x0c\x00\x00\x00\x04\x00\x08\x00\n\x
00\x00\x00(\x04\x00\x00\x04\x00\x00\x00\x01\x00\x00\x00\x0c\x00\x00\x00\x08\x00\x0c\x00\x04\x00\x08\x00\x08\x00\x00\x00\x08\x00\x00\x00\x10\x00\x00\x00\x06\x00\x00\x00pandas\x00\x00\xf2\x03\x00\x00{"index_columns": ["__index_level_0__"], "column
_indexes": [{"name": null, "field_name": null, "pandas_type": "unicode", "numpy_type": "object", "metadata": {"encoding": "UTF-8"}}], "columns": [{"name": "id", "field_name": "id", "pandas_type": "int64", "numpy_type": "Int64",
 "metadata": null}, {"name": "date "field_name": "date", "pandas_type": "datetime", "numpy_type": "datetime64[ns]", "metadata": null}, {"name": "value", "field_name": "value", "pandas_type": "int32", "numpy_ty
pe": "Int32", "metadata": null}, {"name": "__hash_partition", "field_name": "__hash_partition", "pandas_type": "uint64", "numpy_type": "uint64", "metadata": null}, {"name": "_worker", "field_name": "_worker", "pandas_type": "int8", "numpy_type":
 "int8", "metadata": null}, {"name": null, "field_name": "__index_level_0__", "pandas_type": "int64", "numpy_type": "int64", "metadata": null}], "creator": {"library": "pyarrow", "version": "14.0.2"}, "pandas_version": "2.1.4"}\x00\x00\x05\x00\x
00\x00\x0c\x01\x00\x00\xc4\x00\x00\x00\x84\x00\x00\x00D\x00\x00\x00\x04\x00\x00\x00\x18\xff\xff\xff\x00\x00\x01\x02\x10\x00\x00\x00$\x00\x00\x00\x04\x00\x00\x00\x00\x00\x00\x00\x11\x00\x00\x00__index_level_0__\x00\x00\x00\x10\xff\xff\xff\x00\x00
\x00\x01@\x00\x00\x00T\xff\xff\xff\x00\x00\x01\x02\x10\x00\x00\x00(\x00\x00\x00\x04\x00\x00\x00\x00\x00\x00\x00\x10\x00\x00\x00__hash_partition\x00\x00\x06\x00\x08\x00\x04\x00\x06\x00\x00\x00@\x00\x00\x00\x90\xff\xff\xff\x00\x00\x01\x02\x10\x00\
x00\x00$\x00\x00\x00\x04\x00\x00\x00\x00\x00\x00\x00\x11\x00\x00\x00value\x00\x00\x00\x88\xff\xff\xff\x00\x00\x00\x01 \x00\x00\x00\xcc\xff\xff\xff\x00\x00\x01\n\x10\x00\x00\x00 \x00\x00\x00\x04\x00\x00\x00\x00\x00\x00\x00\t\x00\x00\x
00date\x00\x06\x00\x08\x00\x06\x00\x06\x00\x00\x00\x00\x00\x03\x00\x10\x00\x14\x00\x08\x00\x06\x00\x07\x00\x0c\x00\x00\x00\x10\x00\x10\x00\x00\x00\x00\x00\x01\x02\x10\x00\x00\x00$\x00\x00\x00\x04\x00\x00\x00\x00\x00\x00\x00\x0b\x00\x00\x00id
\x00\x08\x00\x0c\x00\x08\x00\x07\x00\x08\x00\x00\x00\x00\x00\x00\x01@\x00\x00\x00\xff\xff\xff\xffH\x01\x00\x00\x14\x00\x00\x00\x00\x00\x00\x00\x0c\x00\x16\x00\x06\x00\x05\x00\x08\x00\x0c\x00\x0c\x00\x00\x00\x00\x03\x04\x00\x18\x00\x00\
x00\x80\x9e\x99\x00\x00\x00\x00\x00\x00\x00\n\x00\x18\x00\x0c\x00\x04\x00\x08\x00\n\x00\x00\x00\xbc\x00\x00\x00\x10\x00\x00\x00gD\x04\x00\x00\x00\x00\x00\x00\x00\x00\x00\n\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x
00\x00\x00\x00\x00\x00\x00\x00\x008#"\x00\x00\x00\x00\x008#"\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x008#"\x00\x00\x00\x00\x008#"\x00\x00\x00\x00\x00pFD\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00pFD\x00\x00\x00\x00\x00\xa0\x11\
x11\x00\x00\x00\x00\x00\x10XU\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x10XU\x00\x00\x00\x00\x008#"\x00\x00\x00\x00\x00H{w\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00H{w\x00\x00\x00\x00\x008#"\x00\x00\x00\x00\x00\x00\x00\x00\x
00\x05\x00\x00\x00gD\x04\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00gD\x04\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00gD\x04\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00gD\x04\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x0
0\x00gD\x04\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\xd5\x07\x00\x00\x00\x00\x00\x00\xd5\x07\x00\x00\x00\x00\x00\x00\xd5\x07\x00\x00\x00\x00\x00\x00\xd5\x07\x00\x00\x00\x00\x00\x00\xd5\x07\x00\x00\x00\x00\x00\x00\xd5\x07\x00\x00\x00\x
00\x00\x00\xd5\x07\x00\x00\x00\x00\x00\x00\xd5\x07\x00\x00\x00\x00\x00\x00\xd5\x07\x00\x00\x00\x00\x00\x00\xd5\x07\x00\x00\x00\x00\x00\x00\xd5\x07\x00\x00\x00\x00\x00\x00\xd5\x07\x00\x00\x00\x00\x00\x00\xd5\x07\x00\x00\x00\x00\x00\x00\xd5\x07\x0
0\x00\x00\x00\x00\x00\xd5\x07\x00\x00\x00\x00\x00\x00\xd5\x07\x00\x00\x00\x00\x00\x00\xd5\x07\x00\x00\x00\x00\x00\x00\xd5\x07\x00\x00\x00\x00\x00\x00\xd5\x07\x00\x00\x00\x00\x00\x00\xf2\t\x00\x00\x00\x00\x00\x00\xf2\t\x00\x00\x00\x00\x00\x00\xf2
\t\x00\x00\x00\x00\x00\x00\xf2\t\x00\x00\x00\x00\x00\x00\xf2\t\x00\x00\x00\x00\x00\x00\xf2\t\x00\x00\x00\x00\x00\x00\xf2\t\x00\x00\x00\x00\x00\x00\xf2\t\x00\x00\x00\x00\x00\x00\xf2\t\x00\x00\x00\x00\x00\x00\xf2\t\x00\x00\x00\x00\x00\x00\xf2\t\x0
0\x00\x00\x00\x00\x00\xf2\t\x00\x00\x00\x00\x00\x00\xf2\t\x00\x00\x00\x00\x00\x00\xf2\t\x00\x00\x00\x00\x00\x00K\n\x00\x00\x00\x00\x00\x00K\n\x00\x00\x00\x00\x00\x00K\n\x00\x00\x00\x00\x00\x00K\n\x00\x00\x00\x00\x00\x00K\n\x00\x00\x00\x00\x00\x0
0K\n\x00\x00\x00\x00\x00\x00K\n\x00\x00\x00\x00\x00\x00K\n\x00\x00\x00\x00\x00\x00K\n\x00\x00\x00\x00\x00\x00K\n\x00\x00\x00\x00\x00\x00K\n\x00\x00\x00\x00\x00\x00K\n\x00\x00\x00\x00\x00\x00K\n\x00\x00\x00\x00\x00\x00\x12\x13\x00\x00\x00

Partially addresses #8465

  • Tests added / passed
  • Passes pre-commit run --all-files

@github-actions
Copy link
Contributor

github-actions bot commented Feb 16, 2024

Unit Test Results

See test report for an extended history of previous test failures. This is useful for diagnosing flaky tests.

    27 files  ±0      27 suites  ±0   10h 15m 5s ⏱️ + 22m 15s
 3 995 tests ±0   3 883 ✅ ±0    110 💤 ±0  2 ❌ ±0 
50 241 runs  ±0  47 944 ✅ +1  2 295 💤 ±0  2 ❌  - 1 

For more details on these failures, see this check.

Results for commit cb05f69. ± Comparison against base commit fcfa7bc.

♻️ This comment has been updated with latest results.

@crusaderky
Copy link
Collaborator

crusaderky commented Feb 26, 2024

Can't say I'm too happy about this. partials are neat to read and I'm sure that someone else will walk in on your code, look at it, think "this would be much more readable with a partial" and change it.

Wouldn't it be better to truncate the repr of the function at ~200 characters?
This would make sense at high level in the logger mechanism (not sure if easy to do) or more likely in retry() on the specific log line logger.info("Retrying %s")

@hendrikmakait
Copy link
Member Author

Can't say I'm too happy about this. partials are neat to read and I'm sure that someone else will walk in on your code, look at it, think "this would be much more readable with a partial" and change it.

I'm not too happy about it either but it patches an immediate pain for now. This has a test attached to it, so if someone changes this, they will trigger the test.

Wouldn't it be better to truncate the repr of the function at ~200 characters? This would make sense at high level in the logger mechanism (not sure if easy to do) or more likely in retry() on the specific log line logger.info("Retrying %s")

I would like the former; it should also address #8465. However, I'm not sure yet how to best approach this and it's not that high of a high priority for me. Regarding the latter, I don't have strong preferences when it comes to this vs my solution. I went with mine because it's more isolated, and I'm not sure if there are any situations where a hard truncate would remove relevant information, but if you prefer that, we can also truncate it over in retry.

@hendrikmakait
Copy link
Member Author

I'll merge this PR, and I've opened up #8529 for the truncation in retry.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

3 participants