[ https://issues.apache.org/jira/browse/THRIFT-5494?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Jens Geyer reassigned THRIFT-5494: ---------------------------------- Assignee: wangfan > 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 > 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)