Re: Servlet Threads Changing Instance Data
-BEGIN PGP SIGNED MESSAGE- Hash: SHA256 Jerry, On 8/15/18 4:00 PM, Jerry Malcolm wrote: > On 8/15/2018 1:50 PM, Olaf Kock wrote: >> Jerry, >> >> >> On 15.08.2018 18:14, Jerry Malcolm wrote: >>> I have a mobile app that issues several http web service calls >>> to initialize. I was making them sequentially with no issues. >>> I then changed to give them all separate threads so they could >>> load asynchronously. Then the bottom fell out. I started >>> getting empty responses and some responses with results of >>> three or four of the calls concatenated. I traced the problem >>> from the app back through apache through mod_jk and found the >>> culprit to be Tomcat. >>> >>> I'm a seasoned Tomcat developer for over 15 years. I've never >>> seen anything like this. But it's really scary. What I found >>> is that sometime during the execution of one servlet call, it's >>> thread data is swapped to thread data of another servlet call. >>> I know this sounds like Twilight Zone. But here is a log >>> output. At the beginning of doGet(), I generated a random text >>> string just to keep track of the thread data/:/ >>> >>> Thread: ajp-nio-8009-exec-24 uid: rclebgb --> Thread: >>> ajp-nio-8009-exec-29 uid: ceycfqd --> Thread: >>> ajp-nio-8009-exec-29 uid: ceycfqd <-- Thread: >>> ajp-nio-8009-exec-24 uid: ceycfqd <-- >>> >>> Note that when thread 24 starts I store the "rcl..." uid. >>> Another call comes in and starts thread 29. By the time thread >>> 24's servlet code is done, it now has thread 29's data. (The >>> uid is just a quick variable for reference. The request >>> object, response object, EVERYTHING is now thread 29's data). >>> >>> This explains why I'm getting empty responses and other >>> response with the data for multiple requests concatenated >>> together. The "rcl..." instance data has totally disappeared, >>> and all of the server calls are now using the "cey..." instance >>> data (i.e. response object). >>> >>> I figure this is some sort of timing/race condition that only >>> occurs with a second call coming in while the first call is >>> still in progress. I can go back to sending the mobile app >>> calls serially and probably work around this. But this is a >>> huge problem. >>> >>> Any ideas? (BTW... Tomcat 9.0.7) >>> >> >> As we don't know which code generates this log output, it's hard >> to judge what actually causes your problem. You say "thread data" >> is being swapped, and the very first aspect that comes to my mind >> is: Servlets are inherently multithreaded, and a common pattern >> of bugs is if a servlet has a member variable that is used for >> request processing: There typically is only one Servlet object >> ever, thus they all share the same state, if the state is stored >> in a member variable. This might be directly in the servlet or in >> some other component or singleton somewhere. >> >> Any state and request processing must be done on the >> request/response pair, and properly threadsafe in every other >> part of your code. >> >> And most likely this is an issue that luckily shows up when >> you're issuing a lot of parallel threads due to parallelizing one >> client. It'd be a lot harder to reproduce if it were individual >> users, who (very) occasionally see the wrong data. Consider >> yourself lucky to have such a nice and reproducible issue. >> >> Olaf > > Olaf, > > I'm having a bit of trouble feeling "lucky" that I have a problem > that is catastrophically blocking my development progress toward a > deadline. Uh hmm. > I'm not sure what you mean by typically there is only one servlet > object. There's one class. But a new instance is created on each > request, right? And all instance variables should be scoped to > that instance alone, right? Nope. I think that's where everything you're observing is coming from, then. > It's fundamental to Java that a private local variable can't > arbitrarily change to another value in the middle of executing a > method other than by the local code changing it itself, right? Since servlet instances are shared, so are all those private variable references. > Yet uid (and all the other variables including request and > response) changed.. somewhere between the beginning and ending of > doGet(). !! I'm not doing any singleton stuff. Simply > request-->Servlet-->response. So, that's a scary thing or me to hear: "and all the other variables including request and response". Are you asking about the parameters to the e.g. doGet() method, or are you saying that you also have "private HttpServletRequest request" defined in your servlet and you are somewhere doing this: public void doGet(HttpServletRequest request, HttpServletResponse response) { this.request = request; this.response = response; ... other stuff } ? > My servlet code is very basic. It is not multithreaded. > > public class MyServlet() { private String uid;// < > PRIVATE access!! Yes, privat
Re: Servlet Threads Changing Instance Data
Am 2018-08-15 um 22:00 schrieb Jerry Malcolm: On 8/15/2018 1:50 PM, Olaf Kock wrote: Jerry, On 15.08.2018 18:14, Jerry Malcolm wrote: I have a mobile app that issues several http web service calls to initialize. I was making them sequentially with no issues. I then changed to give them all separate threads so they could load asynchronously. Then the bottom fell out. I started getting empty responses and some responses with results of three or four of the calls concatenated. I traced the problem from the app back through apache through mod_jk and found the culprit to be Tomcat. I'm a seasoned Tomcat developer for over 15 years. I've never seen anything like this. But it's really scary. What I found is that sometime during the execution of one servlet call, it's thread data is swapped to thread data of another servlet call. I know this sounds like Twilight Zone. But here is a log output. At the beginning of doGet(), I generated a random text string just to keep track of the thread data/:/ Thread: ajp-nio-8009-exec-24 uid: rclebgb --> Thread: ajp-nio-8009-exec-29 uid: ceycfqd --> Thread: ajp-nio-8009-exec-29 uid: ceycfqd <-- Thread: ajp-nio-8009-exec-24 uid: ceycfqd <-- Note that when thread 24 starts I store the "rcl..." uid. Another call comes in and starts thread 29. By the time thread 24's servlet code is done, it now has thread 29's data. (The uid is just a quick variable for reference. The request object, response object, EVERYTHING is now thread 29's data). This explains why I'm getting empty responses and other response with the data for multiple requests concatenated together. The "rcl..." instance data has totally disappeared, and all of the server calls are now using the "cey..." instance data (i.e. response object). I figure this is some sort of timing/race condition that only occurs with a second call coming in while the first call is still in progress. I can go back to sending the mobile app calls serially and probably work around this. But this is a huge problem. Any ideas? (BTW... Tomcat 9.0.7) As we don't know which code generates this log output, it's hard to judge what actually causes your problem. You say "thread data" is being swapped, and the very first aspect that comes to my mind is: Servlets are inherently multithreaded, and a common pattern of bugs is if a servlet has a member variable that is used for request processing: There typically is only one Servlet object ever, thus they all share the same state, if the state is stored in a member variable. This might be directly in the servlet or in some other component or singleton somewhere. Any state and request processing must be done on the request/response pair, and properly threadsafe in every other part of your code. And most likely this is an issue that luckily shows up when you're issuing a lot of parallel threads due to parallelizing one client. It'd be a lot harder to reproduce if it were individual users, who (very) occasionally see the wrong data. Consider yourself lucky to have such a nice and reproducible issue. Olaf Olaf, I'm having a bit of trouble feeling "lucky" that I have a problem that is catastrophically blocking my development progress toward a deadline. I'm not sure what you mean by typically there is only one servlet object. There's one class. But a new instance is created on each request, right? And all instance variables should be scoped to that instance alone, right? It's fundamental to Java that a private local variable can't arbitrarily change to another value in the middle of executing a method other than by the local code changing it itself, right? Yet uid (and all the other variables including request and response) changed.. somewhere between the beginning and ending of doGet(). !! I'm not doing any singleton stuff. Simply request-->Servlet-->response. My servlet code is very basic. It is not multithreaded. public class MyServlet() { private String uid; // < PRIVATE access!! Oh hell, this is so wrong. The servlet instance exists only once in the webapp classloader. No one is creating a new instace on each an every request. You *cannot* share a variable like that, it is not threadsafe. This is your problem. You have to fix that. You also *must* review the rest of your code. Here is your exact problem: https://stackoverflow.com/a/2184147/696632. Trust Bauke Scholz! Michael - To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org For additional commands, e-mail: users-h...@tomcat.apache.org
RE: Servlet Threads Changing Instance Data
> From: Jerry Malcolm [mailto:techst...@malcolms.com] > Subject: Re: Servlet Threads Changing Instance Data > I'm not sure what you mean by typically there is only one servlet > object. There's one class. But a new instance is created on each > request, right? No - there's only one instance of each defined servlet. All requests for a particular servlet share that instance. - Chuck THIS COMMUNICATION MAY CONTAIN CONFIDENTIAL AND/OR OTHERWISE PROPRIETARY MATERIAL and is thus for use only by the intended recipient. If you received this in error, please contact the sender and delete the e-mail and its attachments from all computers. smime.p7s Description: S/MIME cryptographic signature
Re: Servlet Threads Changing Instance Data
On 8/15/2018 1:50 PM, Olaf Kock wrote: Jerry, On 15.08.2018 18:14, Jerry Malcolm wrote: I have a mobile app that issues several http web service calls to initialize. I was making them sequentially with no issues. I then changed to give them all separate threads so they could load asynchronously. Then the bottom fell out. I started getting empty responses and some responses with results of three or four of the calls concatenated. I traced the problem from the app back through apache through mod_jk and found the culprit to be Tomcat. I'm a seasoned Tomcat developer for over 15 years. I've never seen anything like this. But it's really scary. What I found is that sometime during the execution of one servlet call, it's thread data is swapped to thread data of another servlet call. I know this sounds like Twilight Zone. But here is a log output. At the beginning of doGet(), I generated a random text string just to keep track of the thread data/:/ Thread: ajp-nio-8009-exec-24 uid: rclebgb --> Thread: ajp-nio-8009-exec-29 uid: ceycfqd --> Thread: ajp-nio-8009-exec-29 uid: ceycfqd <-- Thread: ajp-nio-8009-exec-24 uid: ceycfqd <-- Note that when thread 24 starts I store the "rcl..." uid. Another call comes in and starts thread 29. By the time thread 24's servlet code is done, it now has thread 29's data. (The uid is just a quick variable for reference. The request object, response object, EVERYTHING is now thread 29's data). This explains why I'm getting empty responses and other response with the data for multiple requests concatenated together. The "rcl..." instance data has totally disappeared, and all of the server calls are now using the "cey..." instance data (i.e. response object). I figure this is some sort of timing/race condition that only occurs with a second call coming in while the first call is still in progress. I can go back to sending the mobile app calls serially and probably work around this. But this is a huge problem. Any ideas? (BTW... Tomcat 9.0.7) As we don't know which code generates this log output, it's hard to judge what actually causes your problem. You say "thread data" is being swapped, and the very first aspect that comes to my mind is: Servlets are inherently multithreaded, and a common pattern of bugs is if a servlet has a member variable that is used for request processing: There typically is only one Servlet object ever, thus they all share the same state, if the state is stored in a member variable. This might be directly in the servlet or in some other component or singleton somewhere. Any state and request processing must be done on the request/response pair, and properly threadsafe in every other part of your code. And most likely this is an issue that luckily shows up when you're issuing a lot of parallel threads due to parallelizing one client. It'd be a lot harder to reproduce if it were individual users, who (very) occasionally see the wrong data. Consider yourself lucky to have such a nice and reproducible issue. Olaf Olaf, I'm having a bit of trouble feeling "lucky" that I have a problem that is catastrophically blocking my development progress toward a deadline. I'm not sure what you mean by typically there is only one servlet object. There's one class. But a new instance is created on each request, right? And all instance variables should be scoped to that instance alone, right? It's fundamental to Java that a private local variable can't arbitrarily change to another value in the middle of executing a method other than by the local code changing it itself, right? Yet uid (and all the other variables including request and response) changed.. somewhere between the beginning and ending of doGet(). !! I'm not doing any singleton stuff. Simply request-->Servlet-->response. My servlet code is very basic. It is not multithreaded. public class MyServlet() { private String uid; // < PRIVATE access!! doGet() { uid = createUID(); System.out.println( "Thread: " + Thread.currentThread().getName() + " uid: " + uid + " -->"); (no new threads, totally synchronous, simply get a couple of vars from a JDBC call) System.out.println( "Thread: " + Thread.currentThread().getName() + " uid: " + uid + " <--"); } That's it. I can think of nothing I could be doing that would cause the PRIVATE uid varible to be different on the 2nd println from the 1st println. And furthermore, the 2nd println has a uid from a DIFFERENT request. What could I possibly be doing in this code above that could cause this? - To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org For additional commands, e-mail: users-h...@tomcat.apache.org
Re: Servlet Threads Changing Instance Data
-BEGIN PGP SIGNED MESSAGE- Hash: SHA256 Jerry, On 8/15/18 12:14 PM, Jerry Malcolm wrote: > I have a mobile app that issues several http web service calls to > initialize. I was making them sequentially with no issues. I > then changed to give them all separate threads so they could load > asynchronously. Then the bottom fell out. I started getting > empty responses and some responses with results of three or four of > the calls concatenated. I traced the problem from the app back > through apache through mod_jk and found the culprit to be Tomcat. > > I'm a seasoned Tomcat developer for over 15 years. I've never > seen anything like this. But it's really scary. What I found is > that sometime during the execution of one servlet call, it's thread > data is swapped to thread data of another servlet call. I know > this sounds like Twilight Zone. But here is a log output. At the > beginning of doGet(), I generated a random text string just to keep > track of the thread data/:/ > > Thread: ajp-nio-8009-exec-24 uid: rclebgb --> Thread: > ajp-nio-8009-exec-29 uid: ceycfqd --> Thread: ajp-nio-8009-exec-29 > uid: ceycfqd <-- Thread: ajp-nio-8009-exec-24 uid: ceycfqd <-- > > Note that when thread 24 starts I store the "rcl..." uid. Another > call comes in and starts thread 29. By the time thread 24's > servlet code is done, it now has thread 29's data. (The uid is > just a quick variable for reference. The request object, response > object, EVERYTHING is now thread 29's data). > > This explains why I'm getting empty responses and other response > with the data for multiple requests concatenated together. The > "rcl..." instance data has totally disappeared, and all of the > server calls are now using the "cey..." instance data (i.e. > response object). > > I figure this is some sort of timing/race condition that only > occurs with a second call coming in while the first call is still > in progress. I can go back to sending the mobile app calls serially > and probably work around this. But this is a huge problem. > > Any ideas? (BTW... Tomcat 9.0.7) Some more specific questions thatn what Olaf has already asked: 1. Where is your "uid" being stored? 2. What does your code look like? Can you just post some of it? We really don't care what your application is doing, of course. Just the parts that generate+log the "uids" you are showing to us. - -chris -BEGIN PGP SIGNATURE- Comment: GPGTools - http://gpgtools.org Comment: Using GnuPG with Thunderbird - https://www.enigmail.net/ iQIzBAEBCAAdFiEEMmKgYcQvxMe7tcJcHPApP6U8pFgFAlt0g7gACgkQHPApP6U8 pFjxcQ/9GdFR302AfkCzCW2WDLqOYlcV/WqGHv2qIq3G5Eyv6b8fRHlqncg6QGbv JZOMT1DHvfWYnMZ/XOcVbF1AdRfpCx4TUPuuaw4YoeS4kqghGKM3L545+Uavm5Qi 8I1GR5NL87fpFExifWrjqVgDIWGXmsHHG0TPwyWq16ALJ8IQ0jStbGdft82AEZeF jUkbt2/+aDvKsGJhqROQ/Z+QnA+F9u6NW2vZTP2zhb2S9Max1L/MHySx3WLZv4aN 72sS592+KquSMOw1068Wj+BdsIN6ag6HOaNc/o3WCRivcLd/bQbZ4+v8UoegruRW DK57voXd28lMBZI0SOU4sCLJpRctdprA8+zIsEiHKx4ln6UD+SHg3C9MGHhED5vp zRI6dFTcuzoQ3f6/LTp3zNXqBsxTWPyF7C82CphRP0BOfQT526a4D0GkAO4BpdAU Xm9tEpy1jQEyLplOWRctrSdy/e1uaqlJ3F+3/dkZEn+zfV9hpnMQ76BS8Mrei+Ke aH8K5f6Ahak4iaey69nUKe8vVhGHex3uq8oo94Ud+mMVlSeWNFvcY8Kb7ByjAcUb z3SsqTsGRHcmdJGg3Ku3FNpLEi9HkdZaAhGxENBg1lOd0oKHOEE/fsvnB83tartc Aqjan2IdjHtil5vYRiQQqqmZ372KLIpxTfle1cj0PoJgd/P52DI= =tZjO -END PGP SIGNATURE- - To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org For additional commands, e-mail: users-h...@tomcat.apache.org
Re: Servlet Threads Changing Instance Data
Jerry, On 15.08.2018 18:14, Jerry Malcolm wrote: I have a mobile app that issues several http web service calls to initialize. I was making them sequentially with no issues. I then changed to give them all separate threads so they could load asynchronously. Then the bottom fell out. I started getting empty responses and some responses with results of three or four of the calls concatenated. I traced the problem from the app back through apache through mod_jk and found the culprit to be Tomcat. I'm a seasoned Tomcat developer for over 15 years. I've never seen anything like this. But it's really scary. What I found is that sometime during the execution of one servlet call, it's thread data is swapped to thread data of another servlet call. I know this sounds like Twilight Zone. But here is a log output. At the beginning of doGet(), I generated a random text string just to keep track of the thread data/:/ Thread: ajp-nio-8009-exec-24 uid: rclebgb --> Thread: ajp-nio-8009-exec-29 uid: ceycfqd --> Thread: ajp-nio-8009-exec-29 uid: ceycfqd <-- Thread: ajp-nio-8009-exec-24 uid: ceycfqd <-- Note that when thread 24 starts I store the "rcl..." uid. Another call comes in and starts thread 29. By the time thread 24's servlet code is done, it now has thread 29's data. (The uid is just a quick variable for reference. The request object, response object, EVERYTHING is now thread 29's data). This explains why I'm getting empty responses and other response with the data for multiple requests concatenated together. The "rcl..." instance data has totally disappeared, and all of the server calls are now using the "cey..." instance data (i.e. response object). I figure this is some sort of timing/race condition that only occurs with a second call coming in while the first call is still in progress. I can go back to sending the mobile app calls serially and probably work around this. But this is a huge problem. Any ideas? (BTW... Tomcat 9.0.7) As we don't know which code generates this log output, it's hard to judge what actually causes your problem. You say "thread data" is being swapped, and the very first aspect that comes to my mind is: Servlets are inherently multithreaded, and a common pattern of bugs is if a servlet has a member variable that is used for request processing: There typically is only one Servlet object ever, thus they all share the same state, if the state is stored in a member variable. This might be directly in the servlet or in some other component or singleton somewhere. Any state and request processing must be done on the request/response pair, and properly threadsafe in every other part of your code. And most likely this is an issue that luckily shows up when you're issuing a lot of parallel threads due to parallelizing one client. It'd be a lot harder to reproduce if it were individual users, who (very) occasionally see the wrong data. Consider yourself lucky to have such a nice and reproducible issue. Olaf - To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org For additional commands, e-mail: users-h...@tomcat.apache.org
Servlet Threads Changing Instance Data
I have a mobile app that issues several http web service calls to initialize. I was making them sequentially with no issues. I then changed to give them all separate threads so they could load asynchronously. Then the bottom fell out. I started getting empty responses and some responses with results of three or four of the calls concatenated. I traced the problem from the app back through apache through mod_jk and found the culprit to be Tomcat. I'm a seasoned Tomcat developer for over 15 years. I've never seen anything like this. But it's really scary. What I found is that sometime during the execution of one servlet call, it's thread data is swapped to thread data of another servlet call. I know this sounds like Twilight Zone. But here is a log output. At the beginning of doGet(), I generated a random text string just to keep track of the thread data/:/ Thread: ajp-nio-8009-exec-24 uid: rclebgb --> Thread: ajp-nio-8009-exec-29 uid: ceycfqd --> Thread: ajp-nio-8009-exec-29 uid: ceycfqd <-- Thread: ajp-nio-8009-exec-24 uid: ceycfqd <-- Note that when thread 24 starts I store the "rcl..." uid. Another call comes in and starts thread 29. By the time thread 24's servlet code is done, it now has thread 29's data. (The uid is just a quick variable for reference. The request object, response object, EVERYTHING is now thread 29's data). This explains why I'm getting empty responses and other response with the data for multiple requests concatenated together. The "rcl..." instance data has totally disappeared, and all of the server calls are now using the "cey..." instance data (i.e. response object). I figure this is some sort of timing/race condition that only occurs with a second call coming in while the first call is still in progress. I can go back to sending the mobile app calls serially and probably work around this. But this is a huge problem. Any ideas? (BTW... Tomcat 9.0.7) Jerry/ / - To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org For additional commands, e-mail: users-h...@tomcat.apache.org