You are viewing a plain text version of this content. The canonical link for it is here.
Posted to github@datafusion.apache.org by "andygrove (via GitHub)" <gi...@apache.org> on 2025/09/26 18:20:40 UTC
[PR] minor: improve logging when `acquireMemory` returns less memory than requested [datafusion-comet]
andygrove opened a new pull request, #2467:
URL: https://github.com/apache/datafusion-comet/pull/2467
## Which issue does this PR close?
<!--
We generally require a GitHub issue to be filed for all bug fixes and enhancements and this helps us generate change logs for our releases. You can link an issue to this PR using the GitHub syntax. For example `Closes #123` indicates that this PR will close issue #123.
-->
Closes #.
## Rationale for this change
<!--
Why are you proposing this change? If this is already explained clearly in the issue then this section is not needed.
Explaining clearly why changes are proposed helps reviewers understand your changes and offer better suggestions for fixes.
-->
## What changes are included in this PR?
<!--
There is no need to duplicate the description in the issue here but it is sometimes worth providing a summary of the individual changes in this PR.
-->
## How are these changes tested?
<!--
We typically require tests for all PRs in order to:
1. Prevent the code from being accidentally broken by subsequent changes
2. Serve as another way to document the expected behavior of the code
If tests are not included in your PR, please explain why (for example, are they covered by existing tests)?
-->
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: github-unsubscribe@datafusion.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
---------------------------------------------------------------------
To unsubscribe, e-mail: github-unsubscribe@datafusion.apache.org
For additional commands, e-mail: github-help@datafusion.apache.org
Re: [PR] minor: include taskAttemptId in log messages [datafusion-comet]
Posted by "andygrove (via GitHub)" <gi...@apache.org>.
andygrove commented on code in PR #2467:
URL: https://github.com/apache/datafusion-comet/pull/2467#discussion_r2395526166
##########
native/core/src/execution/memory_pools/unified_pool.rs:
##########
@@ -96,13 +104,20 @@ impl MemoryPool for CometUnifiedMemoryPool {
}
fn shrink(&self, _: &MemoryReservation, size: usize) {
- self.release_to_spark(size)
- .unwrap_or_else(|_| panic!("Failed to release {size} bytes"));
+ if let Err(e) = self.release_to_spark(size) {
+ panic!(
+ "Task {} failed to return {size} bytes to Spark: {e:?}",
Review Comment:
I was following Spark's convention for logging so that we can use grep to search for `Task 1234` and view the combined logging from both Spark and Comet.
```
~/git/apache/apache-spark-3.5.6$ find . -name "*.scala" -exec grep taskAttemptId {} \; | grep log
logDebug(s"Starting pushing blocks for the task ${context.taskAttemptId()}")
logWarning(s"Task ${taskAttemptId.get} already completed, not releasing lock for $blockId")
logTrace(s"Task $taskAttemptId trying to acquire read lock for $blockId")
logTrace(s"Task $taskAttemptId acquired read lock for $blockId")
logTrace(s"Task $taskAttemptId trying to acquire write lock for $blockId")
logTrace(s"Task $taskAttemptId acquired write lock for $blockId")
logTrace(s"Task $taskAttemptId downgrading write lock for $blockId")
logTrace(s"Task $taskAttemptId releasing lock for $blockId")
logTrace(s"Task $taskAttemptId trying to remove block $blockId")
logInfo(s"Task ${TaskContext.get().taskAttemptId} force spilling in-memory map to disk " +
logInfo(s"Task ${context.taskAttemptId} force spilling in-memory map to disk and " +
logInfo(s"TID $taskAttemptId waiting for at least 1/2N of $poolName pool to be free")
logInfo(s"Task $taskAttemptId from Stage $stageId(Attempt $stageAttemptNumber) has entered " +
logInfo(s"Task $taskAttemptId from Stage $stageId(Attempt $stageAttemptNumber) waiting " +
logInfo(s"Task $taskAttemptId from Stage $stageId(Attempt $stageAttemptNumber) finished " +
logInfo(s"Task $taskAttemptId from Stage $stageId(Attempt $stageAttemptNumber) failed " +
``
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: github-unsubscribe@datafusion.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
---------------------------------------------------------------------
To unsubscribe, e-mail: github-unsubscribe@datafusion.apache.org
For additional commands, e-mail: github-help@datafusion.apache.org
Re: [PR] minor: include taskAttemptId in log messages [datafusion-comet]
Posted by "andygrove (via GitHub)" <gi...@apache.org>.
andygrove merged PR #2467:
URL: https://github.com/apache/datafusion-comet/pull/2467
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: github-unsubscribe@datafusion.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
---------------------------------------------------------------------
To unsubscribe, e-mail: github-unsubscribe@datafusion.apache.org
For additional commands, e-mail: github-help@datafusion.apache.org
Re: [PR] minor: include taskAttemptId in log messages [datafusion-comet]
Posted by "comphead (via GitHub)" <gi...@apache.org>.
comphead commented on code in PR #2467:
URL: https://github.com/apache/datafusion-comet/pull/2467#discussion_r2395586093
##########
native/core/src/execution/memory_pools/unified_pool.rs:
##########
@@ -96,13 +104,20 @@ impl MemoryPool for CometUnifiedMemoryPool {
}
fn shrink(&self, _: &MemoryReservation, size: usize) {
- self.release_to_spark(size)
- .unwrap_or_else(|_| panic!("Failed to release {size} bytes"));
+ if let Err(e) = self.release_to_spark(size) {
+ panic!(
+ "Task {} failed to return {size} bytes to Spark: {e:?}",
Review Comment:
Sounds good!
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: github-unsubscribe@datafusion.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
---------------------------------------------------------------------
To unsubscribe, e-mail: github-unsubscribe@datafusion.apache.org
For additional commands, e-mail: github-help@datafusion.apache.org
Re: [PR] minor: improve logging when `acquireMemory` returns less memory than requested [WIP] [datafusion-comet]
Posted by "codecov-commenter (via GitHub)" <gi...@apache.org>.
codecov-commenter commented on PR #2467:
URL: https://github.com/apache/datafusion-comet/pull/2467#issuecomment-3340045015
## [Codecov](https://app.codecov.io/gh/apache/datafusion-comet/pull/2467?dropdown=coverage&src=pr&el=h1&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=apache) Report
:x: Patch coverage is `0%` with `7 lines` in your changes missing coverage. Please review.
:white_check_mark: Project coverage is 10.48%. Comparing base ([`f09f8af`](https://app.codecov.io/gh/apache/datafusion-comet/commit/f09f8af64c6599255e116a376f4f008f2fd63b43?dropdown=coverage&el=desc&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=apache)) to head ([`93e2517`](https://app.codecov.io/gh/apache/datafusion-comet/commit/93e2517439facbadca9704578a5ddfb465d949a1?dropdown=coverage&el=desc&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=apache)).
:warning: Report is 546 commits behind head on main.
| [Files with missing lines](https://app.codecov.io/gh/apache/datafusion-comet/pull/2467?dropdown=coverage&src=pr&el=tree&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=apache) | Patch % | Lines |
|---|---|---|
| [.../java/org/apache/spark/CometTaskMemoryManager.java](https://app.codecov.io/gh/apache/datafusion-comet/pull/2467?src=pr&el=tree&filepath=spark%2Fsrc%2Fmain%2Fjava%2Forg%2Fapache%2Fspark%2FCometTaskMemoryManager.java&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=apache#diff-c3Bhcmsvc3JjL21haW4vamF2YS9vcmcvYXBhY2hlL3NwYXJrL0NvbWV0VGFza01lbW9yeU1hbmFnZXIuamF2YQ==) | 0.00% | [7 Missing :warning: ](https://app.codecov.io/gh/apache/datafusion-comet/pull/2467?src=pr&el=tree&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=apache) |
<details><summary>Additional details and impacted files</summary>
```diff
@@ Coverage Diff @@
## main #2467 +/- ##
=============================================
- Coverage 56.12% 10.48% -45.65%
+ Complexity 976 232 -744
=============================================
Files 119 146 +27
Lines 11743 13503 +1760
Branches 2251 2332 +81
=============================================
- Hits 6591 1416 -5175
- Misses 4012 11910 +7898
+ Partials 1140 177 -963
```
</details>
[:umbrella: View full report in Codecov by Sentry](https://app.codecov.io/gh/apache/datafusion-comet/pull/2467?dropdown=coverage&src=pr&el=continue&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=apache).
:loudspeaker: Have feedback on the report? [Share it here](https://about.codecov.io/codecov-pr-comment-feedback/?utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=apache).
<details><summary> :rocket: New features to boost your workflow: </summary>
- :snowflake: [Test Analytics](https://docs.codecov.com/docs/test-analytics): Detect flaky tests, report on failures, and find test suite problems.
</details>
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: github-unsubscribe@datafusion.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
---------------------------------------------------------------------
To unsubscribe, e-mail: github-unsubscribe@datafusion.apache.org
For additional commands, e-mail: github-help@datafusion.apache.org
Re: [PR] minor: include taskAttemptId in log messages [datafusion-comet]
Posted by "comphead (via GitHub)" <gi...@apache.org>.
comphead commented on code in PR #2467:
URL: https://github.com/apache/datafusion-comet/pull/2467#discussion_r2395486489
##########
native/core/src/execution/memory_pools/unified_pool.rs:
##########
@@ -96,13 +104,20 @@ impl MemoryPool for CometUnifiedMemoryPool {
}
fn shrink(&self, _: &MemoryReservation, size: usize) {
- self.release_to_spark(size)
- .unwrap_or_else(|_| panic!("Failed to release {size} bytes"));
+ if let Err(e) = self.release_to_spark(size) {
+ panic!(
+ "Task {} failed to return {size} bytes to Spark: {e:?}",
+ self.task_attempt_id
+ );
+ }
if let Err(prev) = self
.used
.fetch_update(Relaxed, Relaxed, |old| old.checked_sub(size))
{
- panic!("overflow when releasing {size} of {prev} bytes");
+ panic!(
+ "Task {} overflow when releasing {size} of {prev} bytes",
Review Comment:
```suggestion
"Task ID {} overflow when releasing {size} of {prev} bytes",
```
##########
native/core/src/execution/memory_pools/unified_pool.rs:
##########
@@ -82,7 +87,10 @@ impl Drop for CometUnifiedMemoryPool {
fn drop(&mut self) {
let used = self.used.load(Relaxed);
if used != 0 {
- warn!("CometUnifiedMemoryPool dropped with {used} bytes still reserved");
+ warn!(
+ "Task {} dropped CometUnifiedMemoryPool with {used} bytes still reserved",
Review Comment:
```suggestion
"Task ID {} dropped CometUnifiedMemoryPool with {used} bytes still reserved",
```
##########
spark/src/main/java/org/apache/spark/CometTaskMemoryManager.java:
##########
@@ -40,22 +40,36 @@ public class CometTaskMemoryManager {
/** The id uniquely identifies the native plan this memory manager is associated to */
private final long id;
+ private final long taskAttemptId;
+
public final TaskMemoryManager internal;
private final NativeMemoryConsumer nativeMemoryConsumer;
private final AtomicLong used = new AtomicLong();
- public CometTaskMemoryManager(long id) {
+ public CometTaskMemoryManager(long id, long taskAttemptId) {
this.id = id;
+ this.taskAttemptId = taskAttemptId;
this.internal = TaskContext$.MODULE$.get().taskMemoryManager();
this.nativeMemoryConsumer = new NativeMemoryConsumer();
}
// Called by Comet native through JNI.
// Returns the actual amount of memory (in bytes) granted.
public long acquireMemory(long size) {
+ if (logger.isTraceEnabled()) {
+ logger.trace("Task {} requested {} bytes", taskAttemptId, size);
Review Comment:
```suggestion
logger.trace("Task ID {} requested {} bytes", taskAttemptId, size);
```
##########
native/core/src/execution/memory_pools/unified_pool.rs:
##########
@@ -127,7 +143,8 @@ impl MemoryPool for CometUnifiedMemoryPool {
.fetch_update(Relaxed, Relaxed, |old| old.checked_add(acquired as usize))
{
return Err(resources_datafusion_err!(
- "Failed to acquire {} bytes due to overflow. Reserved: {}",
+ "Task {} failed to acquire {} bytes due to overflow. Reserved: {}",
Review Comment:
```suggestion
"Task ID {} failed to acquire {} bytes due to overflow. Reserved: {}",
```
##########
spark/src/main/java/org/apache/spark/CometTaskMemoryManager.java:
##########
@@ -64,10 +78,16 @@ public long acquireMemory(long size) {
// Called by Comet native through JNI
public void releaseMemory(long size) {
+ if (logger.isTraceEnabled()) {
+ logger.trace("Task {} released {} bytes", taskAttemptId, size);
Review Comment:
```suggestion
logger.trace("Task ID {} released {} bytes", taskAttemptId, size);
```
##########
native/core/src/execution/memory_pools/unified_pool.rs:
##########
@@ -116,7 +131,8 @@ impl MemoryPool for CometUnifiedMemoryPool {
self.release_to_spark(acquired as usize)?;
return Err(resources_datafusion_err!(
- "Failed to acquire {} bytes, only got {}. Reserved: {}",
+ "Task {} failed to acquire {} bytes, only got {}. Reserved: {}",
Review Comment:
```suggestion
"Task ID {} failed to acquire {} bytes, only got {}. Reserved: {}",
```
##########
native/core/src/execution/memory_pools/unified_pool.rs:
##########
@@ -96,13 +104,20 @@ impl MemoryPool for CometUnifiedMemoryPool {
}
fn shrink(&self, _: &MemoryReservation, size: usize) {
- self.release_to_spark(size)
- .unwrap_or_else(|_| panic!("Failed to release {size} bytes"));
+ if let Err(e) = self.release_to_spark(size) {
+ panic!(
+ "Task {} failed to return {size} bytes to Spark: {e:?}",
Review Comment:
```suggestion
"Task ID {} failed to return {size} bytes to Spark: {e:?}",
```
##########
spark/src/main/java/org/apache/spark/CometTaskMemoryManager.java:
##########
@@ -64,10 +78,16 @@ public long acquireMemory(long size) {
// Called by Comet native through JNI
public void releaseMemory(long size) {
+ if (logger.isTraceEnabled()) {
+ logger.trace("Task {} released {} bytes", taskAttemptId, size);
+ }
long newUsed = used.addAndGet(-size);
if (newUsed < 0) {
logger.error(
- "Used memory is negative: " + newUsed + " after releasing memory chunk of: " + size);
+ "Task {} used memory is negative ({}) after releasing {} bytes",
Review Comment:
```suggestion
"Task ID {} used memory is negative ({}) after releasing {} bytes",
```
##########
spark/src/main/java/org/apache/spark/CometTaskMemoryManager.java:
##########
@@ -40,22 +40,36 @@ public class CometTaskMemoryManager {
/** The id uniquely identifies the native plan this memory manager is associated to */
private final long id;
+ private final long taskAttemptId;
+
public final TaskMemoryManager internal;
private final NativeMemoryConsumer nativeMemoryConsumer;
private final AtomicLong used = new AtomicLong();
- public CometTaskMemoryManager(long id) {
+ public CometTaskMemoryManager(long id, long taskAttemptId) {
this.id = id;
+ this.taskAttemptId = taskAttemptId;
this.internal = TaskContext$.MODULE$.get().taskMemoryManager();
this.nativeMemoryConsumer = new NativeMemoryConsumer();
}
// Called by Comet native through JNI.
// Returns the actual amount of memory (in bytes) granted.
public long acquireMemory(long size) {
+ if (logger.isTraceEnabled()) {
+ logger.trace("Task {} requested {} bytes", taskAttemptId, size);
+ }
long acquired = internal.acquireExecutionMemory(size, nativeMemoryConsumer);
- used.addAndGet(acquired);
+ long newUsed = used.addAndGet(acquired);
if (acquired < size) {
+ logger.warn(
+ "Task {} requested {} bytes but only received {} bytes. Current allocation is {} and "
Review Comment:
```suggestion
"Task ID {} requested {} bytes but only received {} bytes. Current allocation is {} and "
```
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: github-unsubscribe@datafusion.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
---------------------------------------------------------------------
To unsubscribe, e-mail: github-unsubscribe@datafusion.apache.org
For additional commands, e-mail: github-help@datafusion.apache.org