Re: Possible AbstractProtocol.waitingProcessors leak in Tomcat 9.0.75
I met the same problem on Tomcat 9.0.74 these days and I think I have found the answer. Our case is: 1. Open serveral Chrome tabs and each tab establish a websocket connection and a websocket session with Tomcat. To keep the connection and session alive, there is a JS timer who send a STOMP heartbeat message to Tomcat server every 10 seconds. Tomcat will send a STOMP heart beat to Chrome every 10 seconds too. The timeout is 30 seconds on both sides. JS will establish a new websocket connection if the old connection is closed. Open dev tools for each tabs to observe and record the websocket connections. 2. Wait a few minutes and do nothing, we may find that: 1) the AbstractProtocol.waitingProcessors leak probably. 2) the hidden Chrome tab establish serveral websocket connections, only one alive, others are closed by Tomcat server. 3) look at the closed websocket conenctions carefully, we find that the heartbeats from the server are normal, but there is no heartbeat to the server in the last 30 seconds before the connection is closed. 4) many TCP connections are in TIME_WAIT state. The leak may happen when the WsSessions expired on the server side. I think the process is: 1. Chrome's Intensive Throttling will prevent the JS timer to send heartbeat messages on the hidden tabs in 1 Minute. 2. Tomcat check WsSession expiration every second by WsBackgroundThread. The WsSession will expire, and then Tomcat will send a close message to the client/ Chrome, and the client will send a close message as response. 3. In order to fix BZ 66508 dead-locks, https://bz.apache.org/bugzilla/ show_bug.cgi?id=66508, WsRemoteEndpointImplServer will release controll of processor(UpgradeInteralProcessor for websocket) and the socket lock, then re-take controll. The fix may set the socketWrapper.currentProcessor to null when semaphore(messagePartInProgress) contention happens. Now, WsSession is OUTPUT_CLOSED while the socket is not closed. 4. Client send a close message or a normal message to Tomcat, but socketWrapper.currentProcessor is null now instead of a UpgradeInteralProcessor, the AbstractProtocol/Http11NioProtocol will take a Http11Processor to process the websocket message, this causes protocol error which leads to Tocmat close socket immediately. Now, WsSession is OUTPUT_CLOSED and the socket is closed. Normally, processor is released by SocketWrapperBase.close(). SocketWrapperBase will remove its currentProcessor from AbstractProtocol.waitingProcessors. But the currentProcessor is null now and thus cannot be removed. There is no more chance to remove UpgradeInteralProcessor of the expired WsSession. Here is my solution: I think the key point is socketWrapper.currentProcessor should not be set to null when WsSession expires. socketWrapper.currentProcessor is changed by setCurrentProcessor() and takeCurrentProcessor() which both are invoked by client massage processing and protected by socketWrapper.lock. I've create a pr, please reveiw and check it, tks. https://github.com/apache/tomcat/pull/683 Liang - To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org For additional commands, e-mail: users-h...@tomcat.apache.org
Re: Possible AbstractProtocol.waitingProcessors leak in Tomcat 9.0.75
I have spent some more time on this today and I am still unable to recreate these results on either Linux or Windows using the Snake WebSocket example that ships with Tomcat. To make progress I need a reproducible test case, ideally using the Tomcat examples from the latest release of any currently supported version. Failing that, the source code for the bare minimum web application required to reproduce the issue. At this point, it is still not clear if this is a Tomcat or an application issue. Mark On 06/12/2023 07:34, Jakub Remenec wrote: Hi, I've experienced the same issue as described on Apache Tomcat 10.1.13. After downgrading to 10.1.5 it started to work correctly. I also inspected the heapdump of the application with memory problems and found out that there were many org.apache.tomcat.websocket.WsSession present in OUTPUT_CLOSED state. When I tried locally, I found out, that when I open few websocket connections from Chrome and then go to Offline mode the WsSessions remain in OUTPUT_CLOSED state. New connections afterwards have state OPEN. In heapdump from production I saw around 4600 WsSessions but only 40 were open. The rest was in the output closed state. WsSessions are accessible through org.apache.coyote.AbstractProtocol -> waitingProcessors Set. In heapdump and it was clearly visible that 49% of heap was taken by the waitingProcessors set. When tomcat was downgraded to 10.1.5, I saw that WsSessions got cleared after going to offline mode. Additional info - I've set the session timeout to 10minutes. The app uses Java 17 with Spring Boot 3.1.x stack. It does not use any external STOMP broker relay. Regards, Jakub. On 2023/08/20 22:44:46 Mark Thomas wrote: On 20/08/2023 05:21, Mark Thomas wrote: On 18/08/2023 11:28, Rubén Pérez wrote: I started experiencing exactly the same issue when updating from Spring 6.0.7 to 6.0.9, therefore updating tomcat from 10.1.5 to 10.1.8. The Memory leak is very clearly visible in my monitoring tools. A further heap dump reveals like many times more entries in waitingProcessors map than real active connections, and we end up with like 8 retained GB in memory full of those entries. I believe I have found a way to reproduce the issue locally. Open a websocket session from a client in Chrome, go to dev-tools and switch the tab to offline mode, wait > 50secs, go and switch it back to No Throttling. Sometimes I get an error back to the client like: a["ERROR\nmessage:AMQ229014\\c Did not receive data from /192.168.0.1\\c12720 within the 5ms connection TTL. The connection will now be closed.\ncontent-length:0\n\n\u"] And other times I get instead something like c[1002, ""] from Artemis followed by an "Invalid frame header" error from Chrome (websockets view in dev-tools). Only when it is the latter case, looks to be leaking things in that map. Maybe it is a casualty or not, but that is what I have observed at least 2 times. After the error appeared, I waited long enough for FE to reconnect the session, and then I just quitted Chrome. Thanks for the steps to reproduce. That is helpful. I'll let you know how I get on. Unfortunately, I didn't get very far. Based on the log messages it looks very much like those are application generated rather than Tomcat generated. At this point I am wondering if this is an application or a Tomcat issue. I'm going to need a sample application (ideally as cut down as possible) that demonstrates the issue to make progress on this. Another option is debugging this yourself to figure out what has changed. I can provide some pointers if this is of interest. Giv en you can repeat the issue reaosnable reliably, tracking down the commit that trigger the change isn't too hard. Again, after forcefully downgrading Tomcat 10.1.8 to 10.1.5 while preserving the same Spring version, the issue is gone (confirmed in production), in fact I have never managed to get an "Invalid frame header" in Chrome again with Tomcat 10.1.5 (in like 10 attempts). Before I got it in 2 out of 4 attempts. Could you do some further testing and see if you can narrow down exactly which version (10.1.6, 10.1.7 or 10.1.8) the issue first appears in? It would also be helpful to confirm if the issue is still present in 10.1.12. Answers to the above would still be helpful. Mark - To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org For additional commands, e-mail: users-h...@tomcat.apache.org - To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org For additional commands, e-mail: users-h...@tomcat.apache.org
Re: Possible AbstractProtocol.waitingProcessors leak in Tomcat 9.0.75
Hi, I've experienced the same issue as described on Apache Tomcat 10.1.13. After downgrading to 10.1.5 it started to work correctly. I also inspected the heapdump of the application with memory problems and found out that there were many org.apache.tomcat.websocket.WsSession present in OUTPUT_CLOSED state. When I tried locally, I found out, that when I open few websocket connections from Chrome and then go to Offline mode the WsSessions remain in OUTPUT_CLOSED state. New connections afterwards have state OPEN. In heapdump from production I saw around 4600 WsSessions but only 40 were open. The rest was in the output closed state. WsSessions are accessible through org.apache.coyote.AbstractProtocol -> waitingProcessors Set. In heapdump and it was clearly visible that 49% of heap was taken by the waitingProcessors set. When tomcat was downgraded to 10.1.5, I saw that WsSessions got cleared after going to offline mode. Additional info - I've set the session timeout to 10minutes. The app uses Java 17 with Spring Boot 3.1.x stack. It does not use any external STOMP broker relay. Regards, Jakub. On 2023/08/20 22:44:46 Mark Thomas wrote: > On 20/08/2023 05:21, Mark Thomas wrote: > > On 18/08/2023 11:28, Rubén Pérez wrote: > > > > >> I started experiencing exactly the same issue when updating from Spring > >> 6.0.7 to 6.0.9, therefore updating tomcat from 10.1.5 to 10.1.8. The > >> Memory > >> leak is very clearly visible in my monitoring tools. A further heap dump > >> reveals like many times more entries in waitingProcessors map than real > >> active connections, and we end up with like 8 retained GB in memory > >> full of > >> those entries. > >> > >> I believe I have found a way to reproduce the issue locally. Open a > >> websocket session from a client in Chrome, go to dev-tools and switch the > >> tab to offline mode, wait > 50secs, go and switch it back to No > >> Throttling. > >> Sometimes I get an error back to the client like: > >> > >> a["ERROR\nmessage:AMQ229014\\c Did not receive data from > >> /192.168.0.1\\c12720 > >> within the 5ms connection TTL. The connection will now be > >> closed.\ncontent-length:0\n\n\u"] > >> > >> And other times I get instead something like c[1002, ""] from Artemis > >> followed by an "Invalid frame header" error from Chrome (websockets > >> view in > >> dev-tools). > >> > >> Only when it is the latter case, looks to be leaking things in that map. > >> Maybe it is a casualty or not, but that is what I have observed at > >> least 2 > >> times. > >> > >> After the error appeared, I waited long enough for FE to reconnect the > >> session, and then I just quitted Chrome. > > > > Thanks for the steps to reproduce. That is helpful. I'll let you know > > how I get on. > > Unfortunately, I didn't get very far. Based on the log messages it looks > very much like those are application generated rather than Tomcat generated. > > At this point I am wondering if this is an application or a Tomcat > issue. I'm going to need a sample application (ideally as cut down as > possible) that demonstrates the issue to make progress on this. > > Another option is debugging this yourself to figure out what has > changed. I can provide some pointers if this is of interest. Giv en you > can repeat the issue reaosnable reliably, tracking down the commit that > trigger the change isn't too hard. > > >> Again, after forcefully downgrading Tomcat 10.1.8 to 10.1.5 while > >> preserving the same Spring version, the issue is gone (confirmed in > >> production), in fact I have never managed to get an "Invalid frame > >> header" > >> in Chrome again with Tomcat 10.1.5 (in like 10 attempts). Before I got it > >> in 2 out of 4 attempts. > > > > Could you do some further testing and see if you can narrow down exactly > > which version (10.1.6, 10.1.7 or 10.1.8) the issue first appears in? > > > > It would also be helpful to confirm if the issue is still present in > > 10.1.12. > > Answers to the above would still be helpful. > > Mark > > - > To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org > For additional commands, e-mail: users-h...@tomcat.apache.org > >
RE: Re: Possible AbstractProtocol.waitingProcessors leak in Tomcat 9.0.75
Hi, I've experienced the same issue as described on Apache Tomcat 10.1.13. After downgrading to 10.1.5 it started to work correctly. I also inspected the heapdump of the application with memory problems and found out that there were many org.apache.tomcat.websocket.WsSession present in OUTPUT_CLOSED state. When I tried locally, I found out, that when I open few websocket connections from Chrome and then go to Offline mode the WsSessions remain in OUTPUT_CLOSED state. New connections afterwards have state OPEN. In heapdump from production I saw around 4600 WsSessions but only 40 were open. The rest was in the output closed state. WsSessions are accessible through org.apache.coyote.AbstractProtocol -> waitingProcessors Set. In heapdump and it was clearly visible that 49% of heap was taken by the waitingProcessors set. When tomcat was downgraded to 10.1.5, I saw that WsSessions got cleared after going to offline mode. Additional info - I've set the session timeout to 10minutes. The app uses Java 17 with Spring Boot 3.1.x stack. It does not use any external STOMP broker relay. Regards, Jakub.
Re: Possible AbstractProtocol.waitingProcessors leak in Tomcat 9.0.75
On 20/08/2023 05:21, Mark Thomas wrote: On 18/08/2023 11:28, Rubén Pérez wrote: I started experiencing exactly the same issue when updating from Spring 6.0.7 to 6.0.9, therefore updating tomcat from 10.1.5 to 10.1.8. The Memory leak is very clearly visible in my monitoring tools. A further heap dump reveals like many times more entries in waitingProcessors map than real active connections, and we end up with like 8 retained GB in memory full of those entries. I believe I have found a way to reproduce the issue locally. Open a websocket session from a client in Chrome, go to dev-tools and switch the tab to offline mode, wait > 50secs, go and switch it back to No Throttling. Sometimes I get an error back to the client like: a["ERROR\nmessage:AMQ229014\\c Did not receive data from /192.168.0.1\\c12720 within the 5ms connection TTL. The connection will now be closed.\ncontent-length:0\n\n\u"] And other times I get instead something like c[1002, ""] from Artemis followed by an "Invalid frame header" error from Chrome (websockets view in dev-tools). Only when it is the latter case, looks to be leaking things in that map. Maybe it is a casualty or not, but that is what I have observed at least 2 times. After the error appeared, I waited long enough for FE to reconnect the session, and then I just quitted Chrome. Thanks for the steps to reproduce. That is helpful. I'll let you know how I get on. Unfortunately, I didn't get very far. Based on the log messages it looks very much like those are application generated rather than Tomcat generated. At this point I am wondering if this is an application or a Tomcat issue. I'm going to need a sample application (ideally as cut down as possible) that demonstrates the issue to make progress on this. Another option is debugging this yourself to figure out what has changed. I can provide some pointers if this is of interest. Giv en you can repeat the issue reaosnable reliably, tracking down the commit that trigger the change isn't too hard. Again, after forcefully downgrading Tomcat 10.1.8 to 10.1.5 while preserving the same Spring version, the issue is gone (confirmed in production), in fact I have never managed to get an "Invalid frame header" in Chrome again with Tomcat 10.1.5 (in like 10 attempts). Before I got it in 2 out of 4 attempts. Could you do some further testing and see if you can narrow down exactly which version (10.1.6, 10.1.7 or 10.1.8) the issue first appears in? It would also be helpful to confirm if the issue is still present in 10.1.12. Answers to the above would still be helpful. Mark - To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org For additional commands, e-mail: users-h...@tomcat.apache.org
Re: Possible AbstractProtocol.waitingProcessors leak in Tomcat 9.0.75
On 18/08/2023 11:28, Rubén Pérez wrote: This is a response to an existing thread (about Memory leak in recent versions of Tomcat): https://www.mail-archive.com/users@tomcat.apache.org/msg141882.html I haven't found a way to reply publicly as a continuation of that thread. You need to reply to one of the messages from the original thread. That is a little tricky (but not impossible) if you weren't subscribed at the time. lists.apache.org should allow you to do that fairly easily. Anyway... So here it goes what I am trying to say: I started experiencing exactly the same issue when updating from Spring 6.0.7 to 6.0.9, therefore updating tomcat from 10.1.5 to 10.1.8. The Memory leak is very clearly visible in my monitoring tools. A further heap dump reveals like many times more entries in waitingProcessors map than real active connections, and we end up with like 8 retained GB in memory full of those entries. I believe I have found a way to reproduce the issue locally. Open a websocket session from a client in Chrome, go to dev-tools and switch the tab to offline mode, wait > 50secs, go and switch it back to No Throttling. Sometimes I get an error back to the client like: a["ERROR\nmessage:AMQ229014\\c Did not receive data from /192.168.0.1\\c12720 within the 5ms connection TTL. The connection will now be closed.\ncontent-length:0\n\n\u"] And other times I get instead something like c[1002, ""] from Artemis followed by an "Invalid frame header" error from Chrome (websockets view in dev-tools). Only when it is the latter case, looks to be leaking things in that map. Maybe it is a casualty or not, but that is what I have observed at least 2 times. After the error appeared, I waited long enough for FE to reconnect the session, and then I just quitted Chrome. Thanks for the steps to reproduce. That is helpful. I'll let you know how I get on. Again, after forcefully downgrading Tomcat 10.1.8 to 10.1.5 while preserving the same Spring version, the issue is gone (confirmed in production), in fact I have never managed to get an "Invalid frame header" in Chrome again with Tomcat 10.1.5 (in like 10 attempts). Before I got it in 2 out of 4 attempts. Could you do some further testing and see if you can narrow down exactly which version (10.1.6, 10.1.7 or 10.1.8) the issue first appears in? It would also be helpful to confirm if the issue is still present in 10.1.12. Is this something already tracked? Not that I am aware of. Mark - To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org For additional commands, e-mail: users-h...@tomcat.apache.org
Re: Possible AbstractProtocol.waitingProcessors leak in Tomcat 9.0.75
This is a response to an existing thread (about Memory leak in recent versions of Tomcat): https://www.mail-archive.com/users@tomcat.apache.org/msg141882.html I haven't found a way to reply publicly as a continuation of that thread. So here it goes what I am trying to say: I started experiencing exactly the same issue when updating from Spring 6.0.7 to 6.0.9, therefore updating tomcat from 10.1.5 to 10.1.8. The Memory leak is very clearly visible in my monitoring tools. A further heap dump reveals like many times more entries in waitingProcessors map than real active connections, and we end up with like 8 retained GB in memory full of those entries. I believe I have found a way to reproduce the issue locally. Open a websocket session from a client in Chrome, go to dev-tools and switch the tab to offline mode, wait > 50secs, go and switch it back to No Throttling. Sometimes I get an error back to the client like: a["ERROR\nmessage:AMQ229014\\c Did not receive data from /192.168.0.1\\c12720 within the 5ms connection TTL. The connection will now be closed.\ncontent-length:0\n\n\u"] And other times I get instead something like c[1002, ""] from Artemis followed by an "Invalid frame header" error from Chrome (websockets view in dev-tools). Only when it is the latter case, looks to be leaking things in that map. Maybe it is a casualty or not, but that is what I have observed at least 2 times. After the error appeared, I waited long enough for FE to reconnect the session, and then I just quitted Chrome. Again, after forcefully downgrading Tomcat 10.1.8 to 10.1.5 while preserving the same Spring version, the issue is gone (confirmed in production), in fact I have never managed to get an "Invalid frame header" in Chrome again with Tomcat 10.1.5 (in like 10 attempts). Before I got it in 2 out of 4 attempts. Is this something already tracked? Best regards, Ruben
Re: Possible AbstractProtocol.waitingProcessors leak in Tomcat 9.0.75
I also spent quite some time already to create such a test case, but did not yet manage to find something. For now it works in Production to remove those dangling processes once per hour (via bad reflection stuff ;-) ) … will try to add some logging to probably get a grasp about what is going on. Best regards, Mario > Am 27.07.2023 um 12:45 schrieb Mark Thomas : > > I've taken a look at the code and can't see how this might be happening. I > think a reproducible test case is going to be required to investigate this > further. > > Mark > > > On 12/07/2023 09:25, Mark Thomas wrote: >> Hi Mario, >> That does look like a possible bug. >> I'll try and do a code review before the next release but from experience f >> you are able to figure out how to reproduce it that would help a lot. >> Thanks, >> Mark >> On 06/07/2023 15:19, ma...@datenwort.at.INVALID wrote: >>> Hello! >>> >>> I guess I found a memory leak which I am not quite sure how to reproduce >>> yet. >>> Our application is using WebSockets and sometimes it seems that Tomcat >>> 9.0.75 does not always remove the „UpgradeProcessorInternal“ process from >>> the list of „waitingProcessors“ in „org.apache.coyote.AbstractProtocol“. >>> >>> I managed to create a dump (in that e-mail below) of that data from a live >>> VM and found that some of those UpgradeProcessorInternal instances are >>> referencing a "Closed Socket", which somehow feels odd to me. This list >>> slowly grows. The entries are never removed. >>> Those UpgradeProcessorInternal-s referencing a live socket are matching >>> exactly the number of live WebSocket sessions. >>> >>> What do you think? >>> >>> Env: >>> Tomcat: 9.0.75.0 >>> Spring Boot: 2.7.12 >>> Java: 17.0.7 >>> >>> >>> Best regards, >>> Mario >>> >>> >>> connector :Connector[HTTP/1.1-2888] >>> waitingProcessors: 325 >>> processor#1: UpgradeProcessorInternal@1087825622 socketWrapper state: >>> Closed NioChannel msgSent=11 msgReceived=13 >>> processor#2: UpgradeProcessorInternal@92090237 socketWrapper state: Closed >>> NioChannel msgSent=10 msgReceived=13 >>> processor#3: UpgradeProcessorInternal@1641815002 socketWrapper state: >>> Closed NioChannel msgSent=11 msgReceived=9 >>> processor#4: UpgradeProcessorInternal@1749164616 socketWrapper state: >>> Closed NioChannel msgSent=10 msgReceived=13 >>> processor#5: UpgradeProcessorInternal@508142663 socketWrapper state: Closed >>> NioChannel msgSent=11 msgReceived=12 >>> processor#6: UpgradeProcessorInternal@1482593872 socketWrapper state: >>> Closed NioChannel msgSent=11 msgReceived=12 >>> processor#7: UpgradeProcessorInternal@1176145940 socketWrapper state: >>> Closed NioChannel msgSent=4389 msgReceived=205 >>> processor#8: UpgradeProcessorInternal@1420482234 socketWrapper state: >>> Closed NioChannel msgSent=10 msgReceived=12 >>> processor#9: UpgradeProcessorInternal@31846900 socketWrapper state: Closed >>> NioChannel msgSent=10 msgReceived=9 >>> processor#10: UpgradeProcessorInternal@1726295282 socketWrapper state: >>> Closed NioChannel msgSent=10 msgReceived=12 >>> processor#11: UpgradeProcessorInternal@288536869 socketWrapper state: >>> Closed NioChannel msgSent=10 msgReceived=13 >>> processor#12: UpgradeProcessorInternal@969872343 socketWrapper state: >>> Closed NioChannel msgSent=10 msgReceived=13 >>> processor#13: UpgradeProcessorInternal@420227862 socketWrapper state: >>> Closed NioChannel msgSent=10 msgReceived=13 >>> processor#14: UpgradeProcessorInternal@552002299 socketWrapper state: >>> Closed NioChannel msgSent=10 msgReceived=12 >>> processor#15: UpgradeProcessorInternal@255507237 socketWrapper state: >>> Closed NioChannel msgSent=10 msgReceived=12 >>> processor#16: UpgradeProcessorInternal@724602640 socketWrapper state: >>> Closed NioChannel msgSent=10 msgReceived=9 >>> processor#17: UpgradeProcessorInternal@1706491794 socketWrapper state: >>> Closed NioChannel msgSent=10 msgReceived=12 >>> processor#18: UpgradeProcessorInternal@1925947118 socketWrapper state: >>> Closed NioChannel msgSent=10 msgReceived=13 >>> processor#19: UpgradeProcessorInternal@2044888516 socketWrapper state: >>> Closed NioChannel msgSent=10 msgReceived=12 >>> processor#20: UpgradeProcessorInternal@905596380 socketWrapper state: >>> Closed NioChannel msgSent=10 msgReceived=13 >>> processor#21: UpgradeProcessorInternal@897538387 socketWrapper state: >>> org.apache.tomcat.util.net.SecureNioChannel@61aa8978:java.nio.channels.SocketChannel[connected >>> local=/***.***.***.***:2888 remote=/***.***.***.***:40566] msgSent=7277 >>> msgReceived=447 >>> processor#22: UpgradeProcessorInternal@1070005238 socketWrapper state: >>> Closed NioChannel msgSent=10 msgReceived=13 >>> processor#23: UpgradeProcessorInternal@34919463 socketWrapper state: Closed >>> NioChannel msgSent=10 msgReceived=9 >>> processor#24: UpgradeProcessorInternal@565924232 socketWrapper state: >>> Closed NioChannel msgSent=12 msgReceived=14 >>> processor#25:
Re: Possible AbstractProtocol.waitingProcessors leak in Tomcat 9.0.75
I've taken a look at the code and can't see how this might be happening. I think a reproducible test case is going to be required to investigate this further. Mark On 12/07/2023 09:25, Mark Thomas wrote: Hi Mario, That does look like a possible bug. I'll try and do a code review before the next release but from experience f you are able to figure out how to reproduce it that would help a lot. Thanks, Mark On 06/07/2023 15:19, ma...@datenwort.at.INVALID wrote: Hello! I guess I found a memory leak which I am not quite sure how to reproduce yet. Our application is using WebSockets and sometimes it seems that Tomcat 9.0.75 does not always remove the „UpgradeProcessorInternal“ process from the list of „waitingProcessors“ in „org.apache.coyote.AbstractProtocol“. I managed to create a dump (in that e-mail below) of that data from a live VM and found that some of those UpgradeProcessorInternal instances are referencing a "Closed Socket", which somehow feels odd to me. This list slowly grows. The entries are never removed. Those UpgradeProcessorInternal-s referencing a live socket are matching exactly the number of live WebSocket sessions. What do you think? Env: Tomcat: 9.0.75.0 Spring Boot: 2.7.12 Java: 17.0.7 Best regards, Mario connector :Connector[HTTP/1.1-2888] waitingProcessors: 325 processor#1: UpgradeProcessorInternal@1087825622 socketWrapper state: Closed NioChannel msgSent=11 msgReceived=13 processor#2: UpgradeProcessorInternal@92090237 socketWrapper state: Closed NioChannel msgSent=10 msgReceived=13 processor#3: UpgradeProcessorInternal@1641815002 socketWrapper state: Closed NioChannel msgSent=11 msgReceived=9 processor#4: UpgradeProcessorInternal@1749164616 socketWrapper state: Closed NioChannel msgSent=10 msgReceived=13 processor#5: UpgradeProcessorInternal@508142663 socketWrapper state: Closed NioChannel msgSent=11 msgReceived=12 processor#6: UpgradeProcessorInternal@1482593872 socketWrapper state: Closed NioChannel msgSent=11 msgReceived=12 processor#7: UpgradeProcessorInternal@1176145940 socketWrapper state: Closed NioChannel msgSent=4389 msgReceived=205 processor#8: UpgradeProcessorInternal@1420482234 socketWrapper state: Closed NioChannel msgSent=10 msgReceived=12 processor#9: UpgradeProcessorInternal@31846900 socketWrapper state: Closed NioChannel msgSent=10 msgReceived=9 processor#10: UpgradeProcessorInternal@1726295282 socketWrapper state: Closed NioChannel msgSent=10 msgReceived=12 processor#11: UpgradeProcessorInternal@288536869 socketWrapper state: Closed NioChannel msgSent=10 msgReceived=13 processor#12: UpgradeProcessorInternal@969872343 socketWrapper state: Closed NioChannel msgSent=10 msgReceived=13 processor#13: UpgradeProcessorInternal@420227862 socketWrapper state: Closed NioChannel msgSent=10 msgReceived=13 processor#14: UpgradeProcessorInternal@552002299 socketWrapper state: Closed NioChannel msgSent=10 msgReceived=12 processor#15: UpgradeProcessorInternal@255507237 socketWrapper state: Closed NioChannel msgSent=10 msgReceived=12 processor#16: UpgradeProcessorInternal@724602640 socketWrapper state: Closed NioChannel msgSent=10 msgReceived=9 processor#17: UpgradeProcessorInternal@1706491794 socketWrapper state: Closed NioChannel msgSent=10 msgReceived=12 processor#18: UpgradeProcessorInternal@1925947118 socketWrapper state: Closed NioChannel msgSent=10 msgReceived=13 processor#19: UpgradeProcessorInternal@2044888516 socketWrapper state: Closed NioChannel msgSent=10 msgReceived=12 processor#20: UpgradeProcessorInternal@905596380 socketWrapper state: Closed NioChannel msgSent=10 msgReceived=13 processor#21: UpgradeProcessorInternal@897538387 socketWrapper state: org.apache.tomcat.util.net.SecureNioChannel@61aa8978:java.nio.channels.SocketChannel[connected local=/***.***.***.***:2888 remote=/***.***.***.***:40566] msgSent=7277 msgReceived=447 processor#22: UpgradeProcessorInternal@1070005238 socketWrapper state: Closed NioChannel msgSent=10 msgReceived=13 processor#23: UpgradeProcessorInternal@34919463 socketWrapper state: Closed NioChannel msgSent=10 msgReceived=9 processor#24: UpgradeProcessorInternal@565924232 socketWrapper state: Closed NioChannel msgSent=12 msgReceived=14 processor#25: UpgradeProcessorInternal@1146279009 socketWrapper state: Closed NioChannel msgSent=10 msgReceived=9 processor#26: UpgradeProcessorInternal@1467208007 socketWrapper state: Closed NioChannel msgSent=11 msgReceived=9 processor#27: UpgradeProcessorInternal@348911347 socketWrapper state: Closed NioChannel msgSent=10 msgReceived=9 processor#28: UpgradeProcessorInternal@38694518 socketWrapper state: Closed NioChannel msgSent=10 msgReceived=9 processor#29: UpgradeProcessorInternal@1164156250 socketWrapper state: Closed NioChannel msgSent=10 msgReceived=9 processor#30: UpgradeProcessorInternal@1675936734 socketWrapper state: Closed NioChannel msgSent=10 msgReceived=13 processor#31: UpgradeProcessorInternal@441511021 socketWrapper state:
Re: Possible AbstractProtocol.waitingProcessors leak in Tomcat 9.0.75
Hi Mario, That does look like a possible bug. I'll try and do a code review before the next release but from experience f you are able to figure out how to reproduce it that would help a lot. Thanks, Mark On 06/07/2023 15:19, ma...@datenwort.at.INVALID wrote: Hello! I guess I found a memory leak which I am not quite sure how to reproduce yet. Our application is using WebSockets and sometimes it seems that Tomcat 9.0.75 does not always remove the „UpgradeProcessorInternal“ process from the list of „waitingProcessors“ in „org.apache.coyote.AbstractProtocol“. I managed to create a dump (in that e-mail below) of that data from a live VM and found that some of those UpgradeProcessorInternal instances are referencing a "Closed Socket", which somehow feels odd to me. This list slowly grows. The entries are never removed. Those UpgradeProcessorInternal-s referencing a live socket are matching exactly the number of live WebSocket sessions. What do you think? Env: Tomcat: 9.0.75.0 Spring Boot: 2.7.12 Java: 17.0.7 Best regards, Mario connector :Connector[HTTP/1.1-2888] waitingProcessors: 325 processor#1: UpgradeProcessorInternal@1087825622 socketWrapper state: Closed NioChannel msgSent=11 msgReceived=13 processor#2: UpgradeProcessorInternal@92090237 socketWrapper state: Closed NioChannel msgSent=10 msgReceived=13 processor#3: UpgradeProcessorInternal@1641815002 socketWrapper state: Closed NioChannel msgSent=11 msgReceived=9 processor#4: UpgradeProcessorInternal@1749164616 socketWrapper state: Closed NioChannel msgSent=10 msgReceived=13 processor#5: UpgradeProcessorInternal@508142663 socketWrapper state: Closed NioChannel msgSent=11 msgReceived=12 processor#6: UpgradeProcessorInternal@1482593872 socketWrapper state: Closed NioChannel msgSent=11 msgReceived=12 processor#7: UpgradeProcessorInternal@1176145940 socketWrapper state: Closed NioChannel msgSent=4389 msgReceived=205 processor#8: UpgradeProcessorInternal@1420482234 socketWrapper state: Closed NioChannel msgSent=10 msgReceived=12 processor#9: UpgradeProcessorInternal@31846900 socketWrapper state: Closed NioChannel msgSent=10 msgReceived=9 processor#10: UpgradeProcessorInternal@1726295282 socketWrapper state: Closed NioChannel msgSent=10 msgReceived=12 processor#11: UpgradeProcessorInternal@288536869 socketWrapper state: Closed NioChannel msgSent=10 msgReceived=13 processor#12: UpgradeProcessorInternal@969872343 socketWrapper state: Closed NioChannel msgSent=10 msgReceived=13 processor#13: UpgradeProcessorInternal@420227862 socketWrapper state: Closed NioChannel msgSent=10 msgReceived=13 processor#14: UpgradeProcessorInternal@552002299 socketWrapper state: Closed NioChannel msgSent=10 msgReceived=12 processor#15: UpgradeProcessorInternal@255507237 socketWrapper state: Closed NioChannel msgSent=10 msgReceived=12 processor#16: UpgradeProcessorInternal@724602640 socketWrapper state: Closed NioChannel msgSent=10 msgReceived=9 processor#17: UpgradeProcessorInternal@1706491794 socketWrapper state: Closed NioChannel msgSent=10 msgReceived=12 processor#18: UpgradeProcessorInternal@1925947118 socketWrapper state: Closed NioChannel msgSent=10 msgReceived=13 processor#19: UpgradeProcessorInternal@2044888516 socketWrapper state: Closed NioChannel msgSent=10 msgReceived=12 processor#20: UpgradeProcessorInternal@905596380 socketWrapper state: Closed NioChannel msgSent=10 msgReceived=13 processor#21: UpgradeProcessorInternal@897538387 socketWrapper state: org.apache.tomcat.util.net.SecureNioChannel@61aa8978:java.nio.channels.SocketChannel[connected local=/***.***.***.***:2888 remote=/***.***.***.***:40566] msgSent=7277 msgReceived=447 processor#22: UpgradeProcessorInternal@1070005238 socketWrapper state: Closed NioChannel msgSent=10 msgReceived=13 processor#23: UpgradeProcessorInternal@34919463 socketWrapper state: Closed NioChannel msgSent=10 msgReceived=9 processor#24: UpgradeProcessorInternal@565924232 socketWrapper state: Closed NioChannel msgSent=12 msgReceived=14 processor#25: UpgradeProcessorInternal@1146279009 socketWrapper state: Closed NioChannel msgSent=10 msgReceived=9 processor#26: UpgradeProcessorInternal@1467208007 socketWrapper state: Closed NioChannel msgSent=11 msgReceived=9 processor#27: UpgradeProcessorInternal@348911347 socketWrapper state: Closed NioChannel msgSent=10 msgReceived=9 processor#28: UpgradeProcessorInternal@38694518 socketWrapper state: Closed NioChannel msgSent=10 msgReceived=9 processor#29: UpgradeProcessorInternal@1164156250 socketWrapper state: Closed NioChannel msgSent=10 msgReceived=9 processor#30: UpgradeProcessorInternal@1675936734 socketWrapper state: Closed NioChannel msgSent=10 msgReceived=13 processor#31: UpgradeProcessorInternal@441511021 socketWrapper state: Closed NioChannel msgSent=10 msgReceived=13 processor#32: UpgradeProcessorInternal@59206586 socketWrapper state: org.apache.tomcat.util.net.SecureNioChannel@5910f8ae:java.nio.channels.SocketChannel[connected
Possible AbstractProtocol.waitingProcessors leak in Tomcat 9.0.75
Hello! I guess I found a memory leak which I am not quite sure how to reproduce yet. Our application is using WebSockets and sometimes it seems that Tomcat 9.0.75 does not always remove the „UpgradeProcessorInternal“ process from the list of „waitingProcessors“ in „org.apache.coyote.AbstractProtocol“. I managed to create a dump (in that e-mail below) of that data from a live VM and found that some of those UpgradeProcessorInternal instances are referencing a "Closed Socket", which somehow feels odd to me. This list slowly grows. The entries are never removed. Those UpgradeProcessorInternal-s referencing a live socket are matching exactly the number of live WebSocket sessions. What do you think? Env: Tomcat: 9.0.75.0 Spring Boot: 2.7.12 Java: 17.0.7 Best regards, Mario connector :Connector[HTTP/1.1-2888] waitingProcessors: 325 processor#1: UpgradeProcessorInternal@1087825622 socketWrapper state: Closed NioChannel msgSent=11 msgReceived=13 processor#2: UpgradeProcessorInternal@92090237 socketWrapper state: Closed NioChannel msgSent=10 msgReceived=13 processor#3: UpgradeProcessorInternal@1641815002 socketWrapper state: Closed NioChannel msgSent=11 msgReceived=9 processor#4: UpgradeProcessorInternal@1749164616 socketWrapper state: Closed NioChannel msgSent=10 msgReceived=13 processor#5: UpgradeProcessorInternal@508142663 socketWrapper state: Closed NioChannel msgSent=11 msgReceived=12 processor#6: UpgradeProcessorInternal@1482593872 socketWrapper state: Closed NioChannel msgSent=11 msgReceived=12 processor#7: UpgradeProcessorInternal@1176145940 socketWrapper state: Closed NioChannel msgSent=4389 msgReceived=205 processor#8: UpgradeProcessorInternal@1420482234 socketWrapper state: Closed NioChannel msgSent=10 msgReceived=12 processor#9: UpgradeProcessorInternal@31846900 socketWrapper state: Closed NioChannel msgSent=10 msgReceived=9 processor#10: UpgradeProcessorInternal@1726295282 socketWrapper state: Closed NioChannel msgSent=10 msgReceived=12 processor#11: UpgradeProcessorInternal@288536869 socketWrapper state: Closed NioChannel msgSent=10 msgReceived=13 processor#12: UpgradeProcessorInternal@969872343 socketWrapper state: Closed NioChannel msgSent=10 msgReceived=13 processor#13: UpgradeProcessorInternal@420227862 socketWrapper state: Closed NioChannel msgSent=10 msgReceived=13 processor#14: UpgradeProcessorInternal@552002299 socketWrapper state: Closed NioChannel msgSent=10 msgReceived=12 processor#15: UpgradeProcessorInternal@255507237 socketWrapper state: Closed NioChannel msgSent=10 msgReceived=12 processor#16: UpgradeProcessorInternal@724602640 socketWrapper state: Closed NioChannel msgSent=10 msgReceived=9 processor#17: UpgradeProcessorInternal@1706491794 socketWrapper state: Closed NioChannel msgSent=10 msgReceived=12 processor#18: UpgradeProcessorInternal@1925947118 socketWrapper state: Closed NioChannel msgSent=10 msgReceived=13 processor#19: UpgradeProcessorInternal@2044888516 socketWrapper state: Closed NioChannel msgSent=10 msgReceived=12 processor#20: UpgradeProcessorInternal@905596380 socketWrapper state: Closed NioChannel msgSent=10 msgReceived=13 processor#21: UpgradeProcessorInternal@897538387 socketWrapper state: org.apache.tomcat.util.net.SecureNioChannel@61aa8978:java.nio.channels.SocketChannel[connected local=/***.***.***.***:2888 remote=/***.***.***.***:40566] msgSent=7277 msgReceived=447 processor#22: UpgradeProcessorInternal@1070005238 socketWrapper state: Closed NioChannel msgSent=10 msgReceived=13 processor#23: UpgradeProcessorInternal@34919463 socketWrapper state: Closed NioChannel msgSent=10 msgReceived=9 processor#24: UpgradeProcessorInternal@565924232 socketWrapper state: Closed NioChannel msgSent=12 msgReceived=14 processor#25: UpgradeProcessorInternal@1146279009 socketWrapper state: Closed NioChannel msgSent=10 msgReceived=9 processor#26: UpgradeProcessorInternal@1467208007 socketWrapper state: Closed NioChannel msgSent=11 msgReceived=9 processor#27: UpgradeProcessorInternal@348911347 socketWrapper state: Closed NioChannel msgSent=10 msgReceived=9 processor#28: UpgradeProcessorInternal@38694518 socketWrapper state: Closed NioChannel msgSent=10 msgReceived=9 processor#29: UpgradeProcessorInternal@1164156250 socketWrapper state: Closed NioChannel msgSent=10 msgReceived=9 processor#30: UpgradeProcessorInternal@1675936734 socketWrapper state: Closed NioChannel msgSent=10 msgReceived=13 processor#31: UpgradeProcessorInternal@441511021 socketWrapper state: Closed NioChannel msgSent=10 msgReceived=13 processor#32: UpgradeProcessorInternal@59206586 socketWrapper state: org.apache.tomcat.util.net.SecureNioChannel@5910f8ae:java.nio.channels.SocketChannel[connected local=/***.***.***.***:2888 remote=/***.***.***.***:50444] msgSent=3684 msgReceived=449 processor#33: UpgradeProcessorInternal@1027164423 socketWrapper state: Closed NioChannel msgSent=10 msgReceived=12 processor#34: UpgradeProcessorInternal@2101191939 socketWrapper state:
