Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Fix excessive logging on P2P retry #8511

Merged
merged 3 commits into from
Feb 26, 2024

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

Sorry, something went wrong.

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.

@hendrikmakait hendrikmakait merged commit 390a5b5 into dask:main Feb 26, 2024
30 of 34 checks passed
@hendrikmakait hendrikmakait deleted the fix-excessive-logging branch February 26, 2024 14:25
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.

None yet

3 participants