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.

Sign up for GitHub

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

Jump to bottom

[Java] Incorrect memory usage log statement #34723

Closed
dalle opened this issue Mar 24, 2023 · 0 comments · Fixed by #35314
Closed

[Java] Incorrect memory usage log statement #34723

dalle opened this issue Mar 24, 2023 · 0 comments · Fixed by #35314
Labels
Component: Java Type: bug
Milestone
13.0.0

Comments

@dalle
Copy link

dalle commented Mar 24, 2023

Describe the bug, including details regarding any error messages, version, and platform.

The log statement here:

arrow/java/memory/memory-netty/src/main/java/io/netty/buffer/PooledByteBufAllocatorL.java

Line 268 in 45918a9

memoryLogger.trace("Memory Usage: \n{}", PooledByteBufAllocatorL.this.toString());

Outputs the incorrect log message.

Actual:

Memory Usage:
io.netty.buffer.PooledByteBufAllocatorL@7241d783

Expected: the output from io.netty.buffer.PooledByteBufAllocatorL.InnerAllocator.toString(), similar to:

Memory Usage:
1 direct arena(s):
SomeByteBuffer[pos=12 lim=34 cap=56]

Large buffers outstanding: 12 totaling 34 bytes.
Normal buffers outstanding: 56 totaling 78 bytes.

Component(s)

Java
@AlenkaF AlenkaF changed the title Incorrect memory usage log statement [Java] Incorrect memory usage log statement Mar 27, 2023
@davisusanibar davisusanibar mentioned this issue Apr 25, 2023
Merged
davisusanibar added a commit to davisusanibar/arrow that referenced this issue Jun 2, 2023
@davisusanibar
Merge branch 'main' into apacheGH-34723
01e7dc8
davisusanibar added a commit to davisusanibar/arrow that referenced this issue Jun 13, 2023
@davisusanibar
Merge branch 'main' into apacheGH-34723
cc229c1
@lidavidm lidavidm added this to the 13.0.0 milestone Jun 14, 2023
lidavidm pushed a commit that referenced this issue Jun 14, 2023
@davisusanibar
GH-34723: [Java] Enable log trace for Netty allocator memory usage (#…
e4274c6 
…35314)

### Rationale for this change

To close #34723

### What changes are included in this PR?

Enable log trace for Netty allocator memory usage 

### Are these changes tested?

New log enabled:

```xml
<configuration>
  <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
    <encoder>
      <pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n</pattern>
    </encoder>
  </appender>

  <logger name="org.apache.arrow" additivity="false">
    <level value="trace" />
    <appender-ref ref="STDOUT" />
  </logger>

  <root level="trace">
    <appender-ref ref="STDOUT" />
  </root>

</configuration>
```

```java
try (ArrowBuf buf = new ArrowBuf(ReferenceManager.NO_OP, null,
    1024, new PooledByteBufAllocatorL().empty.memoryAddress())) {
  buf.memoryAddress();
}
```

Logs:

```
18:59:33.109 [allocation.logger] TRACE arrow.allocator - Memory Usage: 
32 direct arena(s):
Chunk(s) at 0~25%:
none
Chunk(s) at 0~50%:
none
Chunk(s) at 25~75%:
none
Chunk(s) at 50~100%:
none
Chunk(s) at 75~100%:
none
Chunk(s) at 100%:
none
small subpages:
Chunk(s) at 0~25%:
none
Chunk(s) at 0~50%:
none
Chunk(s) at 25~75%:
none
Chunk(s) at 50~100%:
none
Chunk(s) at 75~100%:
none
Chunk(s) at 100%:
none
small subpages:
Chunk(s) at 0~25%:
none
Chunk(s) at 0~50%:
none
Chunk(s) at 25~75%:
none
Chunk(s) at 50~100%:
none
Chunk(s) at 75~100%:
none
Chunk(s) at 100%:
none
small subpages:
Chunk(s) at 0~25%:
none
Chunk(s) at 0~50%:
none
Chunk(s) at 25~75%:
none
Chunk(s) at 50~100%:
none
Chunk(s) at 75~100%:
none
Chunk(s) at 100%:
none
small subpages:
Chunk(s) at 0~25%:
none
Chunk(s) at 0~50%:
none
Chunk(s) at 25~75%:
none
Chunk(s) at 50~100%:
none
Chunk(s) at 75~100%:
none
Chunk(s) at 100%:
none
small subpages:
Chunk(s) at 0~25%:
none
Chunk(s) at 0~50%:
none
Chunk(s) at 25~75%:
none
Chunk(s) at 50~100%:
none
Chunk(s) at 75~100%:
none
Chunk(s) at 100%:
none
small subpages:
Chunk(s) at 0~25%:
none
Chunk(s) at 0~50%:
none
Chunk(s) at 25~75%:
none
Chunk(s) at 50~100%:
none
Chunk(s) at 75~100%:
none
Chunk(s) at 100%:
none
small subpages:
Chunk(s) at 0~25%:
none
Chunk(s) at 0~50%:
none
Chunk(s) at 25~75%:
none
Chunk(s) at 50~100%:
none
Chunk(s) at 75~100%:
none
Chunk(s) at 100%:
none
small subpages:
Chunk(s) at 0~25%:
none
Chunk(s) at 0~50%:
none
Chunk(s) at 25~75%:
none
Chunk(s) at 50~100%:
none
Chunk(s) at 75~100%:
none
Chunk(s) at 100%:
none
small subpages:
Chunk(s) at 0~25%:
none
Chunk(s) at 0~50%:
none
Chunk(s) at 25~75%:
none
Chunk(s) at 50~100%:
none
Chunk(s) at 75~100%:
none
Chunk(s) at 100%:
none
small subpages:
Chunk(s) at 0~25%:
none
Chunk(s) at 0~50%:
none
Chunk(s) at 25~75%:
none
Chunk(s) at 50~100%:
none
Chunk(s) at 75~100%:
none
Chunk(s) at 100%:
none
small subpages:
Chunk(s) at 0~25%:
none
Chunk(s) at 0~50%:
none
Chunk(s) at 25~75%:
none
Chunk(s) at 50~100%:
none
Chunk(s) at 75~100%:
none
Chunk(s) at 100%:
none
small subpages:
Chunk(s) at 0~25%:
none
Chunk(s) at 0~50%:
none
Chunk(s) at 25~75%:
none
Chunk(s) at 50~100%:
none
Chunk(s) at 75~100%:
none
Chunk(s) at 100%:
none
small subpages:
Chunk(s) at 0~25%:
none
Chunk(s) at 0~50%:
none
Chunk(s) at 25~75%:
none
Chunk(s) at 50~100%:
none
Chunk(s) at 75~100%:
none
Chunk(s) at 100%:
none
small subpages:
Chunk(s) at 0~25%:
none
Chunk(s) at 0~50%:
none
Chunk(s) at 25~75%:
none
Chunk(s) at 50~100%:
none
Chunk(s) at 75~100%:
none
Chunk(s) at 100%:
none
small subpages:
Chunk(s) at 0~25%:
none
Chunk(s) at 0~50%:
none
Chunk(s) at 25~75%:
none
Chunk(s) at 50~100%:
none
Chunk(s) at 75~100%:
none
Chunk(s) at 100%:
none
small subpages:
Chunk(s) at 0~25%:
none
Chunk(s) at 0~50%:
none
Chunk(s) at 25~75%:
none
Chunk(s) at 50~100%:
none
Chunk(s) at 75~100%:
none
Chunk(s) at 100%:
none
small subpages:
Chunk(s) at 0~25%:
none
Chunk(s) at 0~50%:
none
Chunk(s) at 25~75%:
none
Chunk(s) at 50~100%:
none
Chunk(s) at 75~100%:
none
Chunk(s) at 100%:
none
small subpages:
Chunk(s) at 0~25%:
none
Chunk(s) at 0~50%:
none
Chunk(s) at 25~75%:
none
Chunk(s) at 50~100%:
none
Chunk(s) at 75~100%:
none
Chunk(s) at 100%:
none
small subpages:
Chunk(s) at 0~25%:
none
Chunk(s) at 0~50%:
none
Chunk(s) at 25~75%:
none
Chunk(s) at 50~100%:
none
Chunk(s) at 75~100%:
none
Chunk(s) at 100%:
none
small subpages:
Chunk(s) at 0~25%:
none
Chunk(s) at 0~50%:
none
Chunk(s) at 25~75%:
none
Chunk(s) at 50~100%:
none
Chunk(s) at 75~100%:
none
Chunk(s) at 100%:
none
small subpages:
Chunk(s) at 0~25%:
none
Chunk(s) at 0~50%:
none
Chunk(s) at 25~75%:
none
Chunk(s) at 50~100%:
none
Chunk(s) at 75~100%:
none
Chunk(s) at 100%:
none
small subpages:
Chunk(s) at 0~25%:
none
Chunk(s) at 0~50%:
none
Chunk(s) at 25~75%:
none
Chunk(s) at 50~100%:
none
Chunk(s) at 75~100%:
none
Chunk(s) at 100%:
none
small subpages:
Chunk(s) at 0~25%:
none
Chunk(s) at 0~50%:
none
Chunk(s) at 25~75%:
none
Chunk(s) at 50~100%:
none
Chunk(s) at 75~100%:
none
Chunk(s) at 100%:
none
small subpages:
Chunk(s) at 0~25%:
none
Chunk(s) at 0~50%:
none
Chunk(s) at 25~75%:
none
Chunk(s) at 50~100%:
none
Chunk(s) at 75~100%:
none
Chunk(s) at 100%:
none
small subpages:
Chunk(s) at 0~25%:
none
Chunk(s) at 0~50%:
none
Chunk(s) at 25~75%:
none
Chunk(s) at 50~100%:
none
Chunk(s) at 75~100%:
none
Chunk(s) at 100%:
none
small subpages:
Chunk(s) at 0~25%:
none
Chunk(s) at 0~50%:
none
Chunk(s) at 25~75%:
none
Chunk(s) at 50~100%:
none
Chunk(s) at 75~100%:
none
Chunk(s) at 100%:
none
small subpages:
Chunk(s) at 0~25%:
none
Chunk(s) at 0~50%:
none
Chunk(s) at 25~75%:
none
Chunk(s) at 50~100%:
none
Chunk(s) at 75~100%:
none
Chunk(s) at 100%:
none
small subpages:
Chunk(s) at 0~25%:
none
Chunk(s) at 0~50%:
none
Chunk(s) at 25~75%:
none
Chunk(s) at 50~100%:
none
Chunk(s) at 75~100%:
none
Chunk(s) at 100%:
none
small subpages:
Chunk(s) at 0~25%:
none
Chunk(s) at 0~50%:
none
Chunk(s) at 25~75%:
none
Chunk(s) at 50~100%:
none
Chunk(s) at 75~100%:
none
Chunk(s) at 100%:
none
small subpages:
Chunk(s) at 0~25%:
none
Chunk(s) at 0~50%:
none
Chunk(s) at 25~75%:
none
Chunk(s) at 50~100%:
none
Chunk(s) at 75~100%:
none
Chunk(s) at 100%:
none
small subpages:
Chunk(s) at 0~25%:
none
Chunk(s) at 0~50%:
none
Chunk(s) at 25~75%:
none
Chunk(s) at 50~100%:
none
Chunk(s) at 75~100%:
none
Chunk(s) at 100%:
none
small subpages:
Large buffers outstanding: 0 totaling 0 bytes.
Normal buffers outstanding: 0 totaling 0 bytes.
```

### Are there any user-facing changes?

No
* Closes: #34723

Authored-by: david dali susanibar arce <davi.sarces@gmail.com>
Signed-off-by: David Li <li.davidm96@gmail.com>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
Component: Java Type: bug
Projects
None yet
Milestone
13.0.0
Development

Successfully merging a pull request may close this issue.

GH-34723: [Java] Enable log trace for Netty allocator memory usage davisusanibar/arrow
2 participants
@lidavidm @dalle