[
https://issues.apache.org/jira/browse/THRIFT-5494?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Jens Geyer resolved THRIFT-5494.
--------------------------------
Fix Version/s: 0.17.0
Resolution: Fixed
> byte count of FrameBuffer(AbstractNonblockingServer.readBufferBytesAllocated)
> is not subtracted
> -----------------------------------------------------------------------------------------------
>
> Key: THRIFT-5494
> URL: https://issues.apache.org/jira/browse/THRIFT-5494
> Project: Thrift
> Issue Type: Bug
> Components: Java - Library
> Affects Versions: 0.9.1
> Reporter: shanzhongkai
> Assignee: wangfan
> Priority: Major
> Fix For: 0.17.0
>
> Attachments: image-2022-02-24-11-31-50-880.png,
> image-2022-02-24-11-40-14-321.png, image-2022-02-24-11-45-24-002.png,
> image-2022-02-24-11-49-57-579.png
>
> Time Spent: 4h 20m
> Remaining Estimate: 0h
>
> AbstractNonblockingServer.readbufferbytesallocated is used to indicate “How
> many bytes are currently allocated to read buffers.”, however, we find that
> readbufferbytesallocated does not decrease as expected in rare cases. we
> added the following logs in FrameBuffer.read:
> {code:java}
> // if this frame will push us over the memory limit, then return.
> // with luck, more memory will free up the next time around.
> LOGGER.info("print readBufferBytesAllocated: {}, {}",
> readBufferBytesAllocated.get(), frameSize);
> if (readBufferBytesAllocated.get() + frameSize > MAX_READ_BUFFER_BYTES) {
> return true;
> } {code}
> and we found:
> {panel}
> 2022-01-04,11:30:06,795 \{Thread-104} [INFO]
> libthrift091.server.AbstractNonblockingServer$AsyncFrameBuffer: print
> readBufferBytesAllocated: 141028722, 135
> 2022-01-04,11:30:06,795 \{Thread-106} [INFO]
> libthrift091.server.AbstractNonblockingServer$AsyncFrameBuffer: print
> readBufferBytesAllocated: 141028722, 144
> 2022-01-04,11:30:06,795 \{Thread-107} [INFO]
> libthrift091.server.AbstractNonblockingServer$AsyncFrameBuffer: print
> readBufferBytesAllocated: 141028722, 51315
> 2022-01-04,11:30:06,795 \{Thread-118} [INFO]
> libthrift091.server.AbstractNonblockingServer$AsyncFrameBuffer: print
> readBufferBytesAllocated: 141028722, 135
> 2022-01-04,11:30:06,795 \{Thread-121} [INFO]
> libthrift091.server.AbstractNonblockingServer$AsyncFrameBuffer: print
> readBufferBytesAllocated: 141028722, 170
> 2022-01-04,11:30:06,795 \{Thread-124} [INFO]
> libthrift091.server.AbstractNonblockingServer$AsyncFrameBuffer: print
> readBufferBytesAllocated: 141028722, 360495
> 2022-01-04,11:30:06,795 \{Thread-107} [INFO]
> libthrift091.server.AbstractNonblockingServer$AsyncFrameBuffer: print
> readBufferBytesAllocated: 141441140, 140
> 2022-01-04,11:30:06,807 \{Thread-114} [INFO]
> libthrift091.server.AbstractNonblockingServer$AsyncFrameBuffer: print
> readBufferBytesAllocated: 141028722, 257970
> 2022-01-04,11:30:06,823 \{Thread-112} [INFO]
> libthrift091.server.AbstractNonblockingServer$AsyncFrameBuffer: print
> readBufferBytesAllocated: 141028722, 139
> 2022-01-04,11:30:06,839 \{Thread-110} [INFO]
> libthrift091.server.AbstractNonblockingServer$AsyncFrameBuffer: print
> readBufferBytesAllocated: 141028722, 30308
> 2022-01-04,11:30:06,843 \{Thread-110} [INFO]
> libthrift091.server.AbstractNonblockingServer$AsyncFrameBuffer: print
> readBufferBytesAllocated: 141028722, 34608
> 2022-01-04,11:30:06,868 \{Thread-120} [INFO]
> libthrift091.server.AbstractNonblockingServer$AsyncFrameBuffer: print
> readBufferBytesAllocated: 141028722, 162
> 2022-01-04,11:30:06,872 \{Thread-107} [INFO]
> libthrift091.server.AbstractNonblockingServer$AsyncFrameBuffer: print
> readBufferBytesAllocated: 141028722, 144
> 2022-01-04,11:30:06,879 \{Thread-125} [INFO]
> libthrift091.server.AbstractNonblockingServer$AsyncFrameBuffer: print
> readBufferBytesAllocated: 141028722, 279360
> 2022-01-04,11:30:06,918 \{Thread-106} [INFO]
> libthrift091.server.AbstractNonblockingServer$AsyncFrameBuffer: print
> readBufferBytesAllocated: 141028722, 118
> 2022-01-04,11:30:06,924 \{Thread-104} [INFO]
> libthrift091.server.AbstractNonblockingServer$AsyncFrameBuffer: print
> readBufferBytesAllocated: 141028722, 158
> 2022-01-04,11:30:06,971 \{Thread-115} [INFO]
> libthrift091.server.AbstractNonblockingServer$AsyncFrameBuffer: print
> readBufferBytesAllocated: 141028722, 36964
> 2022-01-04,11:30:06,974 \{Thread-115} [INFO]
> libthrift091.server.AbstractNonblockingServer$AsyncFrameBuffer: print
> readBufferBytesAllocated: 141028722, 129
> 2022-01-04,11:30:07,033 \{Thread-121} [INFO]
> libthrift091.server.AbstractNonblockingServer$AsyncFrameBuffer: print
> readBufferBytesAllocated: 141028722, 170
> 2022-01-04,11:30:07,036 \{Thread-112} [INFO]
> libthrift091.server.AbstractNonblockingServer$AsyncFrameBuffer: print
> readBufferBytesAllocated: 141028722, 26714
> 2022-01-04,11:30:07,038 \{Thread-121} [INFO]
> libthrift091.server.AbstractNonblockingServer$AsyncFrameBuffer: print
> readBufferBytesAllocated: 141028722, 132
> 2022-01-04,11:30:07,074 \{Thread-107} [INFO]
> libthrift091.server.AbstractNonblockingServer$AsyncFrameBuffer: print
> readBufferBytesAllocated: 141028722, 33878
> 2022-01-04,11:30:07,079 \{Thread-120} [INFO]
> libthrift091.server.AbstractNonblockingServer$AsyncFrameBuffer: print
> readBufferBytesAllocated: 141028722, 162
> 2022-01-04,11:30:07,113 \{Thread-122} [INFO]
> libthrift091.server.AbstractNonblockingServer$AsyncFrameBuffer: print
> readBufferBytesAllocated: 141028722, 132
> 2022-01-04,11:30:07,149 \{Thread-108} [INFO]
> libthrift091.server.AbstractNonblockingServer$AsyncFrameBuffer: print
> readBufferBytesAllocated: 141028722, 26607
> 2022-01-04,11:30:07,192 \{Thread-110} [INFO]
> libthrift091.server.AbstractNonblockingServer$AsyncFrameBuffer: print
> readBufferBytesAllocated: 141028722, 31055
> 2022-01-04,11:30:07,244 \{Thread-114} [INFO]
> libthrift091.server.AbstractNonblockingServer$AsyncFrameBuffer: print
> readBufferBytesAllocated: 141028722, 166
> 2022-01-04,11:30:07,260 \{Thread-121} [INFO]
> libthrift091.server.AbstractNonblockingServer$AsyncFrameBuffer: print
> readBufferBytesAllocated: 141028722, 170
> 2022-01-04,11:30:07,288 \{Thread-106} [INFO]
> libthrift091.server.AbstractNonblockingServer$AsyncFrameBuffer: print
> readBufferBytesAllocated: 141028722, 108
> 2022-01-04,11:30:07,417 \{Thread-124} [INFO]
> libthrift091.server.AbstractNonblockingServer$AsyncFrameBuffer: print
> readBufferBytesAllocated: 141028722, 132
> 2022-01-04,11:30:07,441 \{Thread-110} [INFO]
> libthrift091.server.AbstractNonblockingServer$AsyncFrameBuffer: print
> readBufferBytesAllocated: 141028722, 135
> 2022-01-04,11:30:07,469 \{Thread-115} [INFO]
> libthrift091.server.AbstractNonblockingServer$AsyncFrameBuffer: print
> readBufferBytesAllocated: 141028722, 35387
> 2022-01-04,11:30:07,571 \{Thread-121} [INFO]
> libthrift091.server.AbstractNonblockingServer$AsyncFrameBuffer: print
> readBufferBytesAllocated: 141028722, 170
> 2022-01-04,11:30:07,571 \{Thread-122} [INFO]
> libthrift091.server.AbstractNonblockingServer$AsyncFrameBuffer: print
> readBufferBytesAllocated: 141028722, 131
> 2022-01-04,11:30:07,571 \{Thread-105} [INFO]
> libthrift091.server.AbstractNonblockingServer$AsyncFrameBuffer: print
> readBufferBytesAllocated: 141028722, 132
> 2022-01-04,11:30:07,571 \{Thread-102} [INFO]
> libthrift091.server.AbstractNonblockingServer$AsyncFrameBuffer: print
> readBufferBytesAllocated: 141028722, 143
> 2022-01-04,11:30:07,571 \{Thread-117} [INFO]
> libthrift091.server.AbstractNonblockingServer$AsyncFrameBuffer: print
> readBufferBytesAllocated: 141028722, 125
> 2022-01-04,11:30:07,615 \{Thread-114} [INFO]
> libthrift091.server.AbstractNonblockingServer$AsyncFrameBuffer: print
> readBufferBytesAllocated: 141028722, 885819
> 2022-01-04,11:30:07,623 \{Thread-116} [INFO]
> libthrift091.server.AbstractNonblockingServer$AsyncFrameBuffer: print
> readBufferBytesAllocated: 141914545, 36155
> 2022-01-04,11:30:07,624 \{Thread-112} [INFO]
> libthrift091.server.AbstractNonblockingServer$AsyncFrameBuffer: print
> readBufferBytesAllocated: 141914545, 16293
> 2022-01-04,11:30:07,636 \{Thread-107} [INFO]
> libthrift091.server.AbstractNonblockingServer$AsyncFrameBuffer: print
> readBufferBytesAllocated: 141028722, 1119
> 2022-01-04,11:30:07,683 \{Thread-106} [INFO]
> libthrift091.server.AbstractNonblockingServer$AsyncFrameBuffer: print
> readBufferBytesAllocated: 141028722, 131
> 2022-01-04,11:30:07,686 \{Thread-123} [INFO]
> libthrift091.server.AbstractNonblockingServer$AsyncFrameBuffer: print
> readBufferBytesAllocated: 141028722, 7875
> {panel}
> It seems that readbufferbytesallocated has not decreased as expected. The
> ultimate performance of this problem is that the CPU is getting higher and
> higher, because the cache is less and less, the incoming large requests
> cannot allocate the cache, resulting in the large requests falling into an
> endless loop.
>
> [https://issues.apache.org/jira/projects/THRIFT/issues/THRIFT-5468?filter=allopenissues]
> The problem in this link is different from ours, because this problem has
> been fixed in 0.9.1. What may be the reason why the readbufferbytesallocated
> has not decreased?
--
This message was sent by Atlassian Jira
(v8.20.1#820001)
