Re: Angular -> Apache 2.4.57 -> Tomcat 10.1.10 over HTTP2
Dan, On 7/11/23 13:10, Dan McLaughlin wrote: One other note, is I can switch to h2c, and it still fails, and a packet capture shows the entire JSON is delivered to Tomcat, and when I put the JSON from the packet inspection together (Packets 10199 --> 10208) and compare it to what the browser says was sent, they are identical. There are no signs of TCP retransmissions or other things you might expect to see if there was a networking related issue. Thanks for providing all the data you have so far. I'm sorry I can't help with h2, but I wonder if you would be willing to try this setup instead: Angular app <--h2--> httpd Tomcat Assuming you are already using mod_proxy (you said mod_http2), just change your configuration URLs from h2://node/app to https://node/app and see if that works. If that works (using HTTP/1.1 instead of h2), then there is likely a problem with mod_proxy_http2 or Tomcat, or the interaction between the two (and not your application!). -chris 1048 2.473101 sourceip destinationip TCP 71 58116 → 18443 [PSH, ACK] Seq=1 Ack=1 Win=8212 Len=17 1049 2.473232 sourceip destinationip TCP 1514 58116 → 18443 [ACK] Seq=18 Ack=1 Win=8212 Len=1460 1050 2.473232 sourceip destinationip TCP 1155 58116 → 18443 [PSH, ACK] Seq=1478 Ack=1 Win=8212 Len=1101 1053 2.484659 sourceip destinationip TCP 60 58116 → 18443 [ACK] Seq=2579 Ack=18 Win=8212 Len=0 1055 2.487967 sourceip destinationip TCP 71 58116 → 18443 [PSH, ACK] Seq=2579 Ack=35 Win=8212 Len=17 10199 22.689703 sourceip destinationip TCP 1514 58116 → 18443 [ACK] Seq=2596 Ack=147 Win=8211 Len=1460 10200 22.689703 sourceip destinationip TCP 1514 58116 → 18443 [ACK] Seq=4056 Ack=147 Win=8211 Len=1460 10201 22.689703 sourceip destinationip TCP 1514 58116 → 18443 [ACK] Seq=5516 Ack=147 Win=8211 Len=1460 10202 22.689703 sourceip destinationip TCP 1514 58116 → 18443 [ACK] Seq=6976 Ack=147 Win=8211 Len=1460 10203 22.689703 sourceip destinationip TCP 1514 58116 → 18443 [ACK] Seq=8436 Ack=147 Win=8211 Len=1460 10204 22.689703 sourceip destinationip TCP 1514 58116 → 18443 [ACK] Seq=9896 Ack=147 Win=8211 Len=1460 10205 22.689703 sourceip destinationip TCP 1514 58116 → 18443 [ACK] Seq=11356 Ack=147 Win=8211 Len=1460 10206 22.689703 sourceip destinationip TCP 1514 58116 → 18443 [ACK] Seq=12816 Ack=147 Win=8211 Len=1460 10207 22.689703 sourceip destinationip TCP 1514 58116 → 18443 [ACK] Seq=14276 Ack=147 Win=8211 Len=1460 10208 22.689703 sourceip destinationip TCP 873 58116 → 18443 [PSH, ACK] Seq=15736 Ack=147 Win=8211 Len=819 10212 22.691800 sourceip destinationip TCP 60 58116 → 18443 [ACK] Seq=16555 Ack=177 Win=8211 Len=0 10216 22.701706 sourceip destinationip TCP 60 58116 → 18443 [ACK] Seq=16555 Ack=190 Win=8211 Len=0 1. There is a significant time gap between the packets indexed at 1055 and 10199. The timestamp jumps from 2.487967 to 22.689703, a difference of about 20 seconds, which matches up with the timeout of 20 seconds. 2. The acknowledgement number (Ack) remains constant at 147 from packet 10199 to 10208, which may suggest that the recipient has not yet acknowledged receipt of these packets. Then it increases to 177 at packet 10212, and to 190 at 10216, suggesting acknowledgements were received for those packets. 3. Packets 10199 --> 10208 contain the full contents of the JSON. Thanks, Dan On Tue, Jul 11, 2023 at 11:43 AM Dan McLaughlin wrote: I was already using the latest Amazon Corretto 20, so I tried moving to the latest OpenJDK 20, which made no difference. So I'm now using the latest Apache HTTPD 2.4, Tomcat 10.1, and JDK20. So it's either some configuration in Apache or Tomcat that needs to be tweaked, an issue with our app (but moving back to mod_jk over AJP works), or it's a bug in either mod_http2 or Tomcat 10.1. If someone at Apache thinks this might be a bug let me know and I'll open a bug report, I just need to know if you think the issue might be with mod_http2 or Tomcat, and I honestly don't know how to tell at this point. So some guidance from someone that knows the code might be of some help at this point. In case it helps any, here are the logs from mod_http2 that match with the failed POST that match the tomcat logs that I posted earlier in this thread if it helps point in at Apache or Tomcat as the source of the problem... One thing to point out is that at the time Tomcat says: "11-Jul-2023 08:27:31.166 FINE [https-openssl-nio-x.x.x.x-18443-exec-8] org.apache.coyote.http2.Stream$StandardStreamInputBuffer.doRead The Stream input buffer is empty. Waiting for more data" Apache repeatedly logs: [Tue Jul 11 08:27:31.061803 2023] [proxy_http2:trace3] [pid 14776:tid 5676] h2_proxy_session.c(1047): (11)Resource temporarily unavailable: [remote x.x.x.x:18443] h2_proxy_session(499): read from conn [Tue Jul 11 08:27:31.061803 2023] [proxy_http2:debug] [pid 14776:tid 5676] h2_proxy_session.c(1201): [remote x.x.x.x:18443] AH03345: h2_proxy_session(499): transit [BUSY] -- no io --> [WAIT] Here is the full log from
Re: Tomcat 9.0.76 Memory leak with Java 17
James, On 7/11/23 10:21, James Boggs wrote: We had a stable SSL enabled website with Apache Tomcat 9.0.73 on Windows Server 2012 o/s, Java 8, Oracle ORDS 21.4 and SSL. We simultaneously upgraded to Tomcat 9.0.75, upgraded to Java 17 and to ORDS 22.1, then used Java 17 to create a new Java Keystore and a new SSL csr file, and imported a new SSL certificate from the CA into the new keystore. The website works but after logging in there are memory leak warnings and the Tomcat service crashes within just a couple of minutes. We even upgraded to 9.0.76 and the issue persists. Below is an excerpt from the stderr log file. I have been unable to find any recent threads on this, any help is appreciated. Is any other information needed? I think you have included all necessary information. I'm chopping-out the irrrelevant bits: 2023-07-10T21:35:40.939Z WARNING The web application [rplans-vpd] registered the JDBC driver [oracle.jdbc.OracleDriver] but failed to unregister it when the web application was stopped. To prevent a memory leak, the JDBC Driver has been forcibly unregistered. This is actually "okay" in that Tomcat has detected a global JDBC driver registration performed by the application, and is fixing the problem for you. The application, however, is making a mistake by not de-registering that JDBC driver. Your options are to move the driver library from your application into Tomcat's lib/ directory, fix the application to de-register the driver when it shuts down, or just ignore the warning. But you should fix the application. 2023-07-10T21:35:40.944Z WARNING The web application [rplans-vpd] appears to have started a thread named [oracle.jdbc.driver.BlockSource.ThreadedCachingBlockSource.BlockReleaser] but has failed to stop it. This is very likely to create a memory leak. Stack trace of thread: There are multiple instances of this same message and THIS is your problem. The problem is what the error message says: your application has started a Thread and never stopped it. The "memory leak" comes from the fact that the Thread has inherited the web application's ClassLoader and the web application is being re-loaded. When that happens, Tomcat discards the ClassLoader which usually means the GC will clean up after it at some point in the future. But that Thread is still running and will keep the ClassLoader in memory, likely forever. You have a few options: 1. Fix the application. The application needs to shut-down any threads is starts during its operation, preferrably in a ServletContextListener's destroy method or similar. 2. Don't hot-reload your application. Instead, shut-down the JVM and re-start it. Ovbviously, this may have availability implications, but then again so does running out of memory and having to bounce the JVM, anyway. 2023-07-10T21:35:40.944Z SEVERE The web application [rplans-vpd] created a ThreadLocal with key of type [java.lang.ThreadLocal.SuppliedThreadLocal] (value [java.lang.ThreadLocal$SuppliedThreadLocal@427241b4]) and a value of type [oracle.ucp.common.Core.Match] (value [UNKNOWN]) but failed to remove it when the web application was stopped. Threads are going to be renewed over time to try and avoid a probable memory leak. This is actually "okay" in that Tomcat has detected your application's ThreadLocal variables (objects bound to one or more Threads which are owned by the application) which are not being cleaned-up by the application, and it's fixing the problem for you by, over time, killing each of those Threads and replacing them in the Thread pool for you. Your options are to fix the application or to ignore the warning. But you should fix the application. It appears that your upgrade of ORDS has introduced a lot of stuff that doesn't play well with hot-reloading of the application. I'm assuming that you aren't responsible for maintaining ORDS... Oracle is. You should report all of the previous issues to Oracle against their ORDS version 22.1 and ask them to fix them. It's why you write those big, fat checks in the first place ;) -chris - To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org For additional commands, e-mail: users-h...@tomcat.apache.org
Re: Tomcat9 silently ignores web application
Graham, (Sorry, just getting back to your messages in this thread.) On 7/8/23 06:20, Graham Leggett wrote: On 08 Jul 2023, at 10:08, Graham Leggett wrote: Another data point - when starting the application up under tomcat9 in eclipse, there is also no mention in the logs of the web application having been deployed, however I am able to hit the application with curl and receive a sensible result. The application has been silently started. On the target machine, we get no log line same as under eclipse, and no application (404 Not Found). The application might have been silently started at a different URL and with no log line we’ll never know, or it silently failed to start and with no error we’ll never know. Having switched from declaring a context in server.xml to Catalina/localhost we now get the startup line - it seems that applications defined in server.xml are silently deployed, but the behaviour hasn’t changed, we still get 404 on the application. Maybe this is what Konstantin meant when he said that server.xml-defined applications don't quite behave the same way. 08-Jul-2023 11:59:59.016 INFO [main] org.apache.catalina.startup.HostConfig.deployDescriptor Deployment of deployment descriptor [/var/lib/tomcats/xxx-service-test/conf/Catalina/localhost/xxx-service-test.xml] has finished in [5,334] ms Well, that's encouraging. A further data point - the access_log as defined by default under the Host is created but stays empty: In summary, the client hits tomcat, tomcat returns 404 on the request, and there is no trace in the access logfile that the client was ever there. Anyone seen behaviour like this before? Absolutely stupid question: are you sure that the port number you are contacting to is being served by /this/ Tomcat process? -chris - To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org For additional commands, e-mail: users-h...@tomcat.apache.org
Re: Angular -> Apache 2.4.57 -> Tomcat 10.1.10 over HTTP2
One other note, is I can switch to h2c, and it still fails, and a packet capture shows the entire JSON is delivered to Tomcat, and when I put the JSON from the packet inspection together (Packets 10199 --> 10208) and compare it to what the browser says was sent, they are identical. There are no signs of TCP retransmissions or other things you might expect to see if there was a networking related issue. 1048 2.473101 sourceip destinationip TCP 71 58116 → 18443 [PSH, ACK] Seq=1 Ack=1 Win=8212 Len=17 1049 2.473232 sourceip destinationip TCP 1514 58116 → 18443 [ACK] Seq=18 Ack=1 Win=8212 Len=1460 1050 2.473232 sourceip destinationip TCP 1155 58116 → 18443 [PSH, ACK] Seq=1478 Ack=1 Win=8212 Len=1101 1053 2.484659 sourceip destinationip TCP 60 58116 → 18443 [ACK] Seq=2579 Ack=18 Win=8212 Len=0 1055 2.487967 sourceip destinationip TCP 71 58116 → 18443 [PSH, ACK] Seq=2579 Ack=35 Win=8212 Len=17 10199 22.689703 sourceip destinationip TCP 1514 58116 → 18443 [ACK] Seq=2596 Ack=147 Win=8211 Len=1460 10200 22.689703 sourceip destinationip TCP 1514 58116 → 18443 [ACK] Seq=4056 Ack=147 Win=8211 Len=1460 10201 22.689703 sourceip destinationip TCP 1514 58116 → 18443 [ACK] Seq=5516 Ack=147 Win=8211 Len=1460 10202 22.689703 sourceip destinationip TCP 1514 58116 → 18443 [ACK] Seq=6976 Ack=147 Win=8211 Len=1460 10203 22.689703 sourceip destinationip TCP 1514 58116 → 18443 [ACK] Seq=8436 Ack=147 Win=8211 Len=1460 10204 22.689703 sourceip destinationip TCP 1514 58116 → 18443 [ACK] Seq=9896 Ack=147 Win=8211 Len=1460 10205 22.689703 sourceip destinationip TCP 1514 58116 → 18443 [ACK] Seq=11356 Ack=147 Win=8211 Len=1460 10206 22.689703 sourceip destinationip TCP 1514 58116 → 18443 [ACK] Seq=12816 Ack=147 Win=8211 Len=1460 10207 22.689703 sourceip destinationip TCP 1514 58116 → 18443 [ACK] Seq=14276 Ack=147 Win=8211 Len=1460 10208 22.689703 sourceip destinationip TCP 873 58116 → 18443 [PSH, ACK] Seq=15736 Ack=147 Win=8211 Len=819 10212 22.691800 sourceip destinationip TCP 60 58116 → 18443 [ACK] Seq=16555 Ack=177 Win=8211 Len=0 10216 22.701706 sourceip destinationip TCP 60 58116 → 18443 [ACK] Seq=16555 Ack=190 Win=8211 Len=0 1. There is a significant time gap between the packets indexed at 1055 and 10199. The timestamp jumps from 2.487967 to 22.689703, a difference of about 20 seconds, which matches up with the timeout of 20 seconds. 2. The acknowledgement number (Ack) remains constant at 147 from packet 10199 to 10208, which may suggest that the recipient has not yet acknowledged receipt of these packets. Then it increases to 177 at packet 10212, and to 190 at 10216, suggesting acknowledgements were received for those packets. 3. Packets 10199 --> 10208 contain the full contents of the JSON. Thanks, Dan On Tue, Jul 11, 2023 at 11:43 AM Dan McLaughlin wrote: > I was already using the latest Amazon Corretto 20, so I tried moving to > the latest OpenJDK 20, which made no difference. So I'm now using the > latest Apache HTTPD 2.4, Tomcat 10.1, and JDK20. > > So it's either some configuration in Apache or Tomcat that needs to be > tweaked, an issue with our app (but moving back to mod_jk over AJP works), > or it's a bug in either mod_http2 or Tomcat 10.1. > > If someone at Apache thinks this might be a bug let me know and I'll open > a bug report, I just need to know if you think the issue might be with > mod_http2 or Tomcat, and I honestly don't know how to tell at this point. > So some guidance from someone that knows the code might be of some help at > this point. > > In case it helps any, here are the logs from mod_http2 that match with the > failed POST that match the tomcat logs that I posted earlier in this thread > if it helps point in at Apache or Tomcat as the source of the problem... > > One thing to point out is that at the time Tomcat says: > > "11-Jul-2023 08:27:31.166 FINE [https-openssl-nio-x.x.x.x-18443-exec-8] > org.apache.coyote.http2.Stream$StandardStreamInputBuffer.doRead The Stream > input buffer is empty. Waiting for more data" > > Apache repeatedly logs: > > [Tue Jul 11 08:27:31.061803 2023] [proxy_http2:trace3] [pid 14776:tid > 5676] h2_proxy_session.c(1047): (11)Resource temporarily unavailable: > [remote x.x.x.x:18443] h2_proxy_session(499): read from conn > [Tue Jul 11 08:27:31.061803 2023] [proxy_http2:debug] [pid 14776:tid 5676] > h2_proxy_session.c(1201): [remote x.x.x.x:18443] AH03345: > h2_proxy_session(499): transit [BUSY] -- no io --> [WAIT] > > Here is the full log from Apache... > > [Tue Jul 11 08:27:31.048120 2023] [proxy:trace2] [pid 14776:tid 5676] > mod_proxy.c(884): [remote x.x.x.x:63451] AH03461: attempting to match URI > path '/MyApp/rest/savejson' against prefix '/MyApp' for proxying, referer: > https://myapp.mydomain.com/MyApp/app/reporting/report/424243 > [Tue Jul 11 08:27:31.048793 2023] [proxy:trace1] [pid 14776:tid 5676] > mod_proxy.c(1005): [remote x.x.x.x:63451] AH03464: URI path > '/MyApp/rest/savejson' matches proxy handler > 'proxy:h2://as01:18443/MyApp/rest/savejson',
Re: Angular -> Apache 2.4.57 -> Tomcat 10.1.10 over HTTP2
I was already using the latest Amazon Corretto 20, so I tried moving to the latest OpenJDK 20, which made no difference. So I'm now using the latest Apache HTTPD 2.4, Tomcat 10.1, and JDK20. So it's either some configuration in Apache or Tomcat that needs to be tweaked, an issue with our app (but moving back to mod_jk over AJP works), or it's a bug in either mod_http2 or Tomcat 10.1. If someone at Apache thinks this might be a bug let me know and I'll open a bug report, I just need to know if you think the issue might be with mod_http2 or Tomcat, and I honestly don't know how to tell at this point. So some guidance from someone that knows the code might be of some help at this point. In case it helps any, here are the logs from mod_http2 that match with the failed POST that match the tomcat logs that I posted earlier in this thread if it helps point in at Apache or Tomcat as the source of the problem... One thing to point out is that at the time Tomcat says: "11-Jul-2023 08:27:31.166 FINE [https-openssl-nio-x.x.x.x-18443-exec-8] org.apache.coyote.http2.Stream$StandardStreamInputBuffer.doRead The Stream input buffer is empty. Waiting for more data" Apache repeatedly logs: [Tue Jul 11 08:27:31.061803 2023] [proxy_http2:trace3] [pid 14776:tid 5676] h2_proxy_session.c(1047): (11)Resource temporarily unavailable: [remote x.x.x.x:18443] h2_proxy_session(499): read from conn [Tue Jul 11 08:27:31.061803 2023] [proxy_http2:debug] [pid 14776:tid 5676] h2_proxy_session.c(1201): [remote x.x.x.x:18443] AH03345: h2_proxy_session(499): transit [BUSY] -- no io --> [WAIT] Here is the full log from Apache... [Tue Jul 11 08:27:31.048120 2023] [proxy:trace2] [pid 14776:tid 5676] mod_proxy.c(884): [remote x.x.x.x:63451] AH03461: attempting to match URI path '/MyApp/rest/savejson' against prefix '/MyApp' for proxying, referer: https://myapp.mydomain.com/MyApp/app/reporting/report/424243 [Tue Jul 11 08:27:31.048793 2023] [proxy:trace1] [pid 14776:tid 5676] mod_proxy.c(1005): [remote x.x.x.x:63451] AH03464: URI path '/MyApp/rest/savejson' matches proxy handler 'proxy:h2://as01:18443/MyApp/rest/savejson', referer: https://myapp.mydomain.com/MyApp/app/reporting/report/424243 [Tue Jul 11 08:27:31.049791 2023] [proxy_http2:trace1] [pid 14776:tid 5676] mod_proxy_http2.c(130): [remote x.x.x.x:63451] HTTP2: canonicalising URL //as01:18443/MyApp/rest/savejson, referer: https://myapp.mydomain.com/MyApp/app/reporting/report/424243 [Tue Jul 11 08:27:31.049791 2023] [proxy:trace2] [pid 14776:tid 5676] proxy_util.c(2370): [remote x.x.x.x:63451] h2: found worker h2://as01:18443/MyApp for h2://as01:18443/MyApp/rest/savejson, referer: https://myapp.mydomain.com/MyApp/app/reporting/report/424243 [Tue Jul 11 08:27:31.049791 2023] [proxy:debug] [pid 14776:tid 5676] mod_proxy.c(1511): [remote x.x.x.x:63451] AH01143: Running scheme h2 handler (attempt 0), referer: https://myapp.mydomain.com/MyApp/app/reporting/report/424243 [Tue Jul 11 08:27:31.049791 2023] [proxy_http2:trace1] [pid 14776:tid 5676] mod_proxy_http2.c(366): [remote x.x.x.x:63451] H2: serving URL h2://as01:18443/MyApp/rest/savejson, referer: https://myapp.mydomain.com/MyApp/app/reporting/report/424243 [Tue Jul 11 08:27:31.049791 2023] [proxy:debug] [pid 14776:tid 5676] proxy_util.c(2568): AH00942: H2: has acquired connection for (as01:18443) [Tue Jul 11 08:27:31.049791 2023] [proxy:debug] [pid 14776:tid 5676] proxy_util.c(2626): [remote x.x.x.x:63451] AH00944: connecting h2://as01:18443/MyApp/rest/savejson to as01:18443, referer: https://myapp.mydomain.com/MyApp/app/reporting/report/424243 [Tue Jul 11 08:27:31.049791 2023] [proxy:debug] [pid 14776:tid 5676] proxy_util.c(2849): [remote x.x.x.x:63451] AH00947: connected /MyApp/rest/savejson to as01:18443, referer: https://myapp.mydomain.com/MyApp/app/reporting/report/424243 [Tue Jul 11 08:27:31.049791 2023] [proxy:trace2] [pid 14776:tid 5676] proxy_util.c(3131): H2: reusing backend connection x.x.x.x:55549<>x.x.x.x:18443 [Tue Jul 11 08:27:31.049791 2023] [proxy_http2:debug] [pid 14776:tid 5676] mod_proxy_http2.c(267): [remote x.x.x.x:63451] AH03373: eng(499): run session 499 [Tue Jul 11 08:27:31.049791 2023] [proxy_http2:debug] [pid 14776:tid 5676] h2_proxy_session.c(1078): [remote x.x.x.x:63451] AH03381: process stream(0): POST myapp.mydomain.com/MyApp/rest/savejson, original: POST /MyApp/rest/savejson HTTP/2.0, referer: https://myapp.mydomain.com/MyApp/app/reporting/report/424243 [Tue Jul 11 08:27:31.049791 2023] [proxy_http2:debug] [pid 14776:tid 5676] h2_proxy_session.c(946): [remote x.x.x.x:18443] AH03363: h2_proxy_session(499): submit myapp.mydomain.com/MyApp/rest/savejson -> 23 [Tue Jul 11 08:27:31.049791 2023] [proxy_http2:trace2] [pid 14776:tid 5676] h2_proxy_session.c(1534): [remote x.x.x.x:18443] h2_proxy_session(499): process [Tue Jul 11 08:27:31.049791 2023] [proxy_http2:debug] [pid 14776:tid 5676] h2_proxy_session.c(346): [remote x.x.x.x:18443] AH03343: h2_proxy_session(499): sent FRAME[PING[length=8, ack=0,
Re: Angular -> Apache 2.4.57 -> Tomcat 10.1.10 over HTTP2
I just upgraded to Tomcat 10.1.11, and it still fails. A comparison of the logs between a failed POST on 10.1.10 and 10.1.11 look slightly different, but it still fails for the same reason. I'm going to try updating the JDK and see if that helps. -- Thanks, Dan On Tue, Jul 11, 2023 at 10:32 AM Dan McLaughlin wrote: > @markt > > I was looking over the latest release notes for 10.1.11. Any chance either > of these changes could be related... > > >- [image: Fix:] Refactor blocking reads and writes for the NIO >connector to remove code paths that could allow a notification from the >Poller to be missed resuting in a timeout rather than the expected read or >write. (markt) >- [image: Fix:] Refactor waiting for an HTTP/2 stream or connection >window update to handle spurious wake-ups during the wait. (markt) > > > -- > > Thanks, > > Dan > > On Tue, Jul 11, 2023 at 9:43 AM Dan McLaughlin wrote: > >> We have many Angular applications, and we currently use Angular 15. I'm >> using Apache 2.4.57 and Tomcat 10.1.10/JDK20 on Windows 2019 (don't ask). >> >> For several years now, I've used the following configuration without >> issues. >> >> Angular <-H2-> Apache <-MOD_JK/AJP 1.3--> Tomcat >> >> This week I've been working on replacing mod_jk with mod_http2, and for >> the most part, things are working, but I'm running into issues where we do >> HTTP POSTs of JSON to Rest APIs. We are using Spring Framework 6.0.10. The >> only things I have yet to try are upgrading to Tomcat 10.1.11 and >> updating to the latest JDK20 release. We are using Amazon Corretto. >> >> Angular <-H2-> Apache <-MOD_HTTP2/H2--> Tomcat >> >> Everything seems to be working fine except for places in our apps where >> we do things like a POST of JSON to a Rest API. To debug what's going on, >> I've enabled dumpio on Apache, and I can see the entire JSON getting >> posted. I've installed Wireshark on the backend where Tomcat is running, >> and I've captured the TCP packets containing the JSON, and I can see that >> the entire JSON is making it to Tomcat. When I compare the JSON in a diff >> tool, the JSON is the same, so I know it's making it intact. So I enabled >> FINE logging for HTTP2 on Tomcat, and I see everything looks to come >> through to Tomcat fine until it hits... >> >> org.apache.coyote.http2.Stream$StandardStreamInputBuffer.doRead The >> Stream input buffer is empty. Waiting for more data >> >> At this point, things hang for 20 seconds until a timeout occurs, and >> Tomcat closes the connection. >> >> Here's the odd thing, the same post doesn't always fail. In about 1 out >> of 10 attempts, the POST will succeed. When it does succeed and I compare >> the HTTP2 logs in Tomcat, everything looks the same until the end of the >> connection. Here are the logs showing a POST that succeeds vs. one that >> fails. Is there something we should be doing in our Angular apps >> differently when HTTP2 is used in place of AJP, or is this potentially a >> bug? >> >> Success... >> >> 11-Jul-2023 08:51:45.427 FINE [https-openssl-nio-exec-15] >> org.apache.coyote.http2.Http2UpgradeHandler.updateOverheadCount Connection >> [18], Stream [0], Frame type [HEADERS] resulted in new overhead count of >> [-260] >> 11-Jul-2023 08:51:45.427 FINE [https-openssl-nio-exec-15] >> org.apache.coyote.http2.Http2Parser.validateFrame Connection [18], Stream >> [0], Frame type [PING], Flags [1], Payload size [8] >> 11-Jul-2023 08:51:45.427 FINE [https-openssl-nio-exec-15] >> org.apache.coyote.http2.Http2UpgradeHandler$PingManager.receivePing >> Connection [18] Round trip time measured as [11,769,300]ns >> 11-Jul-2023 08:51:45.427 FINE [https-openssl-nio-exec-15] >> org.apache.coyote.http2.Http2Parser.validateFrame Connection [18], Stream >> [13], Frame type [DATA], Flags [0], Payload size [8000] >> 11-Jul-2023 08:51:45.427 FINE [https-openssl-nio-exec-15] >> org.apache.coyote.http2.Http2Parser.readDataFrame Connection [18], Stream >> [13], Data length [8000], Padding length [none] >> 11-Jul-2023 08:51:45.427 FINE [https-openssl-nio-exec-15] >> org.apache.coyote.http2.Http2UpgradeHandler.updateOverheadCount Connection >> [18], Stream [0], Frame type [DATA] resulted in new overhead count of [-280] >> 11-Jul-2023 08:51:45.428 FINE [https-openssl-nio-exec-15] >> org.apache.coyote.http2.Http2UpgradeHandler.startRequestBodyFrame >> Connection [18], Stream [13] startRequestBodyFrame returned >> [java.nio.HeapByteBuffer[pos=0 lim=65535 cap=65535]] >> 11-Jul-2023 08:51:45.428 FINE [https-openssl-nio-exec-15] >> org.apache.coyote.http2.Stream$StandardStreamInputBuffer.onDataAvailable >> Data added to inBuffer when read thread is waiting. Signalling that thread >> to continue >> 11-Jul-2023 08:51:45.428 FINE [https-openssl-nio-exec-15] >> org.apache.coyote.http2.Http2Parser.validateFrame Connection [18], Stream >> [13], Frame type [DATA], Flags [1], Payload size [5878] >> 11-Jul-2023 08:51:45.428 FINE [https-openssl-nio-exec-15] >>
Re: Angular -> Apache 2.4.57 -> Tomcat 10.1.10 over HTTP2
@markt I was looking over the latest release notes for 10.1.11. Any chance either of these changes could be related... - [image: Fix:] Refactor blocking reads and writes for the NIO connector to remove code paths that could allow a notification from the Poller to be missed resuting in a timeout rather than the expected read or write. (markt) - [image: Fix:] Refactor waiting for an HTTP/2 stream or connection window update to handle spurious wake-ups during the wait. (markt) -- Thanks, Dan On Tue, Jul 11, 2023 at 9:43 AM Dan McLaughlin wrote: > We have many Angular applications, and we currently use Angular 15. I'm > using Apache 2.4.57 and Tomcat 10.1.10/JDK20 on Windows 2019 (don't ask). > > For several years now, I've used the following configuration without > issues. > > Angular <-H2-> Apache <-MOD_JK/AJP 1.3--> Tomcat > > This week I've been working on replacing mod_jk with mod_http2, and for > the most part, things are working, but I'm running into issues where we do > HTTP POSTs of JSON to Rest APIs. We are using Spring Framework 6.0.10. The > only things I have yet to try are upgrading to Tomcat 10.1.11 and > updating to the latest JDK20 release. We are using Amazon Corretto. > > Angular <-H2-> Apache <-MOD_HTTP2/H2--> Tomcat > > Everything seems to be working fine except for places in our apps where we > do things like a POST of JSON to a Rest API. To debug what's going on, > I've enabled dumpio on Apache, and I can see the entire JSON getting > posted. I've installed Wireshark on the backend where Tomcat is running, > and I've captured the TCP packets containing the JSON, and I can see that > the entire JSON is making it to Tomcat. When I compare the JSON in a diff > tool, the JSON is the same, so I know it's making it intact. So I enabled > FINE logging for HTTP2 on Tomcat, and I see everything looks to come > through to Tomcat fine until it hits... > > org.apache.coyote.http2.Stream$StandardStreamInputBuffer.doRead The Stream > input buffer is empty. Waiting for more data > > At this point, things hang for 20 seconds until a timeout occurs, and > Tomcat closes the connection. > > Here's the odd thing, the same post doesn't always fail. In about 1 out of > 10 attempts, the POST will succeed. When it does succeed and I compare the > HTTP2 logs in Tomcat, everything looks the same until the end of the > connection. Here are the logs showing a POST that succeeds vs. one that > fails. Is there something we should be doing in our Angular apps > differently when HTTP2 is used in place of AJP, or is this potentially a > bug? > > Success... > > 11-Jul-2023 08:51:45.427 FINE [https-openssl-nio-exec-15] > org.apache.coyote.http2.Http2UpgradeHandler.updateOverheadCount Connection > [18], Stream [0], Frame type [HEADERS] resulted in new overhead count of > [-260] > 11-Jul-2023 08:51:45.427 FINE [https-openssl-nio-exec-15] > org.apache.coyote.http2.Http2Parser.validateFrame Connection [18], Stream > [0], Frame type [PING], Flags [1], Payload size [8] > 11-Jul-2023 08:51:45.427 FINE [https-openssl-nio-exec-15] > org.apache.coyote.http2.Http2UpgradeHandler$PingManager.receivePing > Connection [18] Round trip time measured as [11,769,300]ns > 11-Jul-2023 08:51:45.427 FINE [https-openssl-nio-exec-15] > org.apache.coyote.http2.Http2Parser.validateFrame Connection [18], Stream > [13], Frame type [DATA], Flags [0], Payload size [8000] > 11-Jul-2023 08:51:45.427 FINE [https-openssl-nio-exec-15] > org.apache.coyote.http2.Http2Parser.readDataFrame Connection [18], Stream > [13], Data length [8000], Padding length [none] > 11-Jul-2023 08:51:45.427 FINE [https-openssl-nio-exec-15] > org.apache.coyote.http2.Http2UpgradeHandler.updateOverheadCount Connection > [18], Stream [0], Frame type [DATA] resulted in new overhead count of [-280] > 11-Jul-2023 08:51:45.428 FINE [https-openssl-nio-exec-15] > org.apache.coyote.http2.Http2UpgradeHandler.startRequestBodyFrame > Connection [18], Stream [13] startRequestBodyFrame returned > [java.nio.HeapByteBuffer[pos=0 lim=65535 cap=65535]] > 11-Jul-2023 08:51:45.428 FINE [https-openssl-nio-exec-15] > org.apache.coyote.http2.Stream$StandardStreamInputBuffer.onDataAvailable > Data added to inBuffer when read thread is waiting. Signalling that thread > to continue > 11-Jul-2023 08:51:45.428 FINE [https-openssl-nio-exec-15] > org.apache.coyote.http2.Http2Parser.validateFrame Connection [18], Stream > [13], Frame type [DATA], Flags [1], Payload size [5878] > 11-Jul-2023 08:51:45.428 FINE [https-openssl-nio-exec-15] > org.apache.coyote.http2.Http2Parser.readDataFrame Connection [18], Stream > [13], Data length [5878], Padding length [none] > 11-Jul-2023 08:51:45.428 FINE [https-openssl-nio-exec-15] > org.apache.coyote.http2.Http2UpgradeHandler.updateOverheadCount Connection > [18], Stream [0], Frame type [DATA] resulted in new overhead count of [-300] > 11-Jul-2023 08:51:45.428 FINE [https-openssl-nio-exec-15] >
Angular -> Apache 2.4.57 -> Tomcat 10.1.10 over HTTP2
We have many Angular applications, and we currently use Angular 15. I'm using Apache 2.4.57 and Tomcat 10.1.10/JDK20 on Windows 2019 (don't ask). For several years now, I've used the following configuration without issues. Angular <-H2-> Apache <-MOD_JK/AJP 1.3--> Tomcat This week I've been working on replacing mod_jk with mod_http2, and for the most part, things are working, but I'm running into issues where we do HTTP POSTs of JSON to Rest APIs. We are using Spring Framework 6.0.10. The only things I have yet to try are upgrading to Tomcat 10.1.11 and updating to the latest JDK20 release. We are using Amazon Corretto. Angular <-H2-> Apache <-MOD_HTTP2/H2--> Tomcat Everything seems to be working fine except for places in our apps where we do things like a POST of JSON to a Rest API. To debug what's going on, I've enabled dumpio on Apache, and I can see the entire JSON getting posted. I've installed Wireshark on the backend where Tomcat is running, and I've captured the TCP packets containing the JSON, and I can see that the entire JSON is making it to Tomcat. When I compare the JSON in a diff tool, the JSON is the same, so I know it's making it intact. So I enabled FINE logging for HTTP2 on Tomcat, and I see everything looks to come through to Tomcat fine until it hits... org.apache.coyote.http2.Stream$StandardStreamInputBuffer.doRead The Stream input buffer is empty. Waiting for more data At this point, things hang for 20 seconds until a timeout occurs, and Tomcat closes the connection. Here's the odd thing, the same post doesn't always fail. In about 1 out of 10 attempts, the POST will succeed. When it does succeed and I compare the HTTP2 logs in Tomcat, everything looks the same until the end of the connection. Here are the logs showing a POST that succeeds vs. one that fails. Is there something we should be doing in our Angular apps differently when HTTP2 is used in place of AJP, or is this potentially a bug? Success... 11-Jul-2023 08:51:45.427 FINE [https-openssl-nio-exec-15] org.apache.coyote.http2.Http2UpgradeHandler.updateOverheadCount Connection [18], Stream [0], Frame type [HEADERS] resulted in new overhead count of [-260] 11-Jul-2023 08:51:45.427 FINE [https-openssl-nio-exec-15] org.apache.coyote.http2.Http2Parser.validateFrame Connection [18], Stream [0], Frame type [PING], Flags [1], Payload size [8] 11-Jul-2023 08:51:45.427 FINE [https-openssl-nio-exec-15] org.apache.coyote.http2.Http2UpgradeHandler$PingManager.receivePing Connection [18] Round trip time measured as [11,769,300]ns 11-Jul-2023 08:51:45.427 FINE [https-openssl-nio-exec-15] org.apache.coyote.http2.Http2Parser.validateFrame Connection [18], Stream [13], Frame type [DATA], Flags [0], Payload size [8000] 11-Jul-2023 08:51:45.427 FINE [https-openssl-nio-exec-15] org.apache.coyote.http2.Http2Parser.readDataFrame Connection [18], Stream [13], Data length [8000], Padding length [none] 11-Jul-2023 08:51:45.427 FINE [https-openssl-nio-exec-15] org.apache.coyote.http2.Http2UpgradeHandler.updateOverheadCount Connection [18], Stream [0], Frame type [DATA] resulted in new overhead count of [-280] 11-Jul-2023 08:51:45.428 FINE [https-openssl-nio-exec-15] org.apache.coyote.http2.Http2UpgradeHandler.startRequestBodyFrame Connection [18], Stream [13] startRequestBodyFrame returned [java.nio.HeapByteBuffer[pos=0 lim=65535 cap=65535]] 11-Jul-2023 08:51:45.428 FINE [https-openssl-nio-exec-15] org.apache.coyote.http2.Stream$StandardStreamInputBuffer.onDataAvailable Data added to inBuffer when read thread is waiting. Signalling that thread to continue 11-Jul-2023 08:51:45.428 FINE [https-openssl-nio-exec-15] org.apache.coyote.http2.Http2Parser.validateFrame Connection [18], Stream [13], Frame type [DATA], Flags [1], Payload size [5878] 11-Jul-2023 08:51:45.428 FINE [https-openssl-nio-exec-15] org.apache.coyote.http2.Http2Parser.readDataFrame Connection [18], Stream [13], Data length [5878], Padding length [none] 11-Jul-2023 08:51:45.428 FINE [https-openssl-nio-exec-15] org.apache.coyote.http2.Http2UpgradeHandler.updateOverheadCount Connection [18], Stream [0], Frame type [DATA] resulted in new overhead count of [-300] 11-Jul-2023 08:51:45.428 FINE [https-openssl-nio-exec-15] org.apache.coyote.http2.Http2UpgradeHandler.startRequestBodyFrame Connection [18], Stream [13] startRequestBodyFrame returned [java.nio.HeapByteBuffer[pos=8000 lim=65535 cap=65535]] 11-Jul-2023 08:51:45.428 FINE [https-openssl-nio-exec-15] org.apache.coyote.http2.StreamStateMachine.stateChange Connection [18], Stream [13], State changed from [OPEN] to [HALF_CLOSED_REMOTE] 11-Jul-2023 08:51:45.428 FINE [https-openssl-nio-exec-15] org.apache.coyote.http2.Stream$StandardStreamInputBuffer.onDataAvailable Data added to inBuffer when read thread is waiting. Signalling that thread to continue 11-Jul-2023 08:51:45.428 FINE [https-openssl-nio-exec-15] org.apache.coyote.http2.Http2UpgradeHandler.upgradeDispatch Exit, Connection [18], SocketState [ASYNC_IO] 11-Jul-2023
Tomcat 9.0.76 Memory leak with Java 17
Hi, We had a stable SSL enabled website with Apache Tomcat 9.0.73 on Windows Server 2012 o/s, Java 8, Oracle ORDS 21.4 and SSL. We simultaneously upgraded to Tomcat 9.0.75, upgraded to Java 17 and to ORDS 22.1, then used Java 17 to create a new Java Keystore and a new SSL csr file, and imported a new SSL certificate from the CA into the new keystore. The website works but after logging in there are memory leak warnings and the Tomcat service crashes within just a couple of minutes. We even upgraded to 9.0.76 and the issue persists. Below is an excerpt from the stderr log file. I have been unable to find any recent threads on this, any help is appreciated. Is any other information needed? -- start of logfile 2023-07-10 16:51:33 Apache Commons Daemon procrun stderr initialized. 10-Jul-2023 16:51:35.434 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Server version name: Apache Tomcat/9.0.76 10-Jul-2023 16:51:35.449 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Server built: Jun 5 2023 07:17:04 UTC 10-Jul-2023 16:51:35.451 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Server version number: 9.0.76.0 10-Jul-2023 16:51:35.451 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log OS Name: Windows Server 2012 R2 10-Jul-2023 16:51:35.451 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log OS Version:6.3 10-Jul-2023 16:51:35.451 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Architecture: amd64 10-Jul-2023 16:51:35.452 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Java Home: D:\JAVA\JDK 10-Jul-2023 16:51:35.452 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log JVM Version: 17.0.7+8-LTS-224 10-Jul-2023 16:51:35.452 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log JVM Vendor: Oracle Corporation 10-Jul-2023 16:51:35.452 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log CATALINA_BASE: D:\tomcat9 10-Jul-2023 16:51:35.454 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log CATALINA_HOME: D:\tomcat9 10-Jul-2023 16:51:35.481 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dconfig.url=D:\ords222 10-Jul-2023 16:51:35.481 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Xms1024M 10-Jul-2023 16:51:35.481 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Xmx1024M 10-Jul-2023 16:51:35.481 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dcatalina.home=D:\tomcat9 10-Jul-2023 16:51:35.481 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dcatalina.base=D:\tomcat9 10-Jul-2023 16:51:35.481 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dignore.endorsed.dirs=D:\tomcat9\endorsed 10-Jul-2023 16:51:35.481 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.io.tmpdir=D:\tomcat9\temp 10-Jul-2023 16:51:35.486 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager 10-Jul-2023 16:51:35.486 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.util.logging.config.file=D:\tomcat9\conf\logging.properties 10-Jul-2023 16:51:35.486 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: --add-opens=java.base/java.lang=ALL-UNNAMED 10-Jul-2023 16:51:35.486 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: --add-opens=java.base/java.io=ALL-UNNAMED 10-Jul-2023 16:51:35.486 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: --add-opens=java.base/java.util=ALL-UNNAMED 10-Jul-2023 16:51:35.486 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: --add-opens=java.base/java.util.concurrent=ALL-UNNAMED 10-Jul-2023 16:51:35.486 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: --add-opens=java.rmi/sun.rmi.transport=ALL-UNNAMED 10-Jul-2023 16:51:35.486 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: exit 10-Jul-2023 16:51:35.486 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: abort 10-Jul-2023 16:51:35.486 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Xms128m 10-Jul-2023 16:51:35.486 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Xmx256m 10-Jul-2023 16:51:35.496 INFO [main]
[ANN] Apache Tomcat 11.0.0-M9 (alpha) available
The Apache Tomcat team announces the immediate availability of Apache Tomcat 11.0.0-M9 (alpha). Apache Tomcat 11 is an open source software implementation of the Jakarta Servlet, Jakarta Server Pages, Jakarta Expression Language, Jakarta WebSocket, Jakarta Authentication and Jakarta Annotations specifications. Users of Tomcat 10 onwards should be aware that, as a result of the move from Java EE to Jakarta EE as part of the transfer of Java EE to the Eclipse Foundation, the primary package for all implemented APIs has changed from javax.* to jakarta.*. This will almost certainly require code changes to enable applications to migrate from Tomcat 9 and earlier to Tomcat 10 and later. A migration tool is available to aid this process. Apache Tomcat 11.0.0-M9 is a milestone release of the 11.0.x branch and has been made to provide users with early access to the new features in Apache Tomcat 11.0.x so that they may provide feedback. The notable changes compared to 11.0.0-M7 include: - Add ContextNamingInfoListener, a listener which creates context naming information environment entries - Add PropertiesRoleMappingListener, a listener which populates the context's role mapping from a properties file. - Update the Jakarta EL and Jakarta WebSocket implementations to align with the latest changes planned for Jakarta EE 11 Please refer to the change log for the complete list of changes: http://tomcat.apache.org/tomcat-11.0-doc/changelog.html Downloads: http://tomcat.apache.org/download-11.cgi Migration guides from Apache Tomcat 8.5.x, 9.0.x and 10.1.x: http://tomcat.apache.org/migration.html Enjoy! - The Apache Tomcat team - To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org For additional commands, e-mail: users-h...@tomcat.apache.org
