Re: Tomcat 7 - Sporadic problem re: cookies

[Chad Stansbury]

Chris - The header logging is a good idea. We'll add that. In the meantime,
it looks like it might have been premature to indicate that "the problem
persists with HTTP/1.1". The one instance that I found was a red herring,
so to date the problem has *not* recurred since addressing the HTTP/1.0
issue.

In re: our web server and Wireshark. We have an nginx instance sitting on a
separate (web server) machine. The Wireshark was the app server, so it was
capturing the traffic from nginx to Tomcat.

At any rate, I will be sure to keep you apprised as to the status.
Hopefully the HTTP/1.1 fix addresses the problem...

Chad

On Wed, Feb 28, 2018 at 8:17 AM, Christopher Schultz <
ch...@christopherschultz.net> wrote:

> -BEGIN PGP SIGNED MESSAGE-
> Hash: SHA256
>
> Chad,
>
> On 2/27/18 9:02 PM, Chad Stansbury wrote:
> > Thanks for your response. Unfortunately it doesn't appear to be a
> > bad cookie name or value, as the identical set of cookies are
> > passed (and parsed correctly) on requests that immediately precede
> > and follow the failing request. That's pretty clear from both the
> > Wireshark and Tomcat access logs we have. What we're seeing is that
> > the client (which is a browser, usually Chrome) sends a burst of
> > requests, and occasionally one of those requests will fail as the
> > web app detects that is has no cookies even though the Wireshark
> > indicates that there are.  We even added logging to the
> > AccessLogValve to log the cookies that we're looking for, and it
> > yields an empty value... So we know that the cookie parsing is
> > either failing or the cookies get cleared following parsing, but
> > before being passed on to the AccessLogValve.
>
> Sounds like you have it at least semi-reproducible. That's great news.
>
> What about logging both the results of request.getCookies() as well as
> request.getHeader("Cookie")? If the parsing is failing, you will get
> no Cookie objects from request.getCookie(), but you should still get
> the header back from the request.
>
> If there is no header in the request... well, then maybe something is
> wrong elsewhere with the request, and Tomcat never gets to the Cookie
> header at all.
>
> > Also, as a follow-up, we corrected the HTTP/1.0 issue, and see that
> > the problem persists even with HTTP/1.1. The one thing that I
> > failed to mention on the original note is that we're running Tomcat
> > on a Windows server. So I'm not sure if that has anything to do
> > with the issue that we're seeing or not...
>
> I wouldn't expect Windows to have anything to do with it, same for
> HTTP/1.0 versus HTTP/1.1... headers haven't changed much across HTTP
> versions, and Tomcat treats those headers the same regardless of the
> advertised version of the protocol. The biggest difference between
> HTTP/1.0 and HTTP/1.1 is that HTTP/1.1 has a few required headers.
>
> > That being said, I will double-check the catalina.out to see if we
> > can find any cookie parsing related errors.
>
> That would be good. Again, it will probably only be logged a single
> time, not every time. But if you have the opportunity to bounce Tomcat
> and hit it with a load that will likely cause an error to occur, you
> ought to be able to catch an error message -- if indeed Cookie-parsing
> is the problem. Or, if request-parsing is the problem, too.
>
> One more question: are you using a reverse-proxy like httpd out in
> front? Exactly where are you sampling with Wireshark?
>
> - -chris
>
> > On Tue, Feb 27, 2018 at 3:13 PM, Christopher Schultz <
> > ch...@christopherschultz.net> wrote:
> >
> > Chad,
> >
> > On 2/27/18 9:44 AM, Chad Stansbury wrote:
>  We've been troubleshooting an issue where our web application
>  is getting a very occasional request that contains no cookies
>  even though a Wireshark on the application server shows those
>  cookies coming in on the request.
> 
>  I was able to replay the request that was captured via
>  Wireshark, and when doing so, everything goes through just
>  fine... so that rules out any sort of weird character set /
>  header parsing issues.
> 
>  Environment specifics: Tomcat v7.0.77 running the (http-bio)
>  connector
> 
>  Now here's the twist: Currently something in the site
>  infrastructure has been configured to proxy to Tomcat with
>  HTTP/1.0 instead of 1.1. We're trying to track that down and
>  address that issue (for performance reasons), but in the mean
>  time, we're wondering whether or not this is a concurrency
>  issue related to protocol caching/recycling?
> 
>  Has anyone ever seen anything like this before? Is there any
>  legitimate scenario(s) where Tomcat will *not* parse out the
>  cookies, but still route the request to the web app? Is this
>  possible an edge condition that that might be caused by the
>  use of HTTP/1.0? Could this possibly be caused by the number
>  of maxThreads exceeding the 

Re: Tomcat 7 - Sporadic problem re: cookies

[Christopher Schultz]

-BEGIN PGP SIGNED MESSAGE-
Hash: SHA256

Chad,

On 2/27/18 9:02 PM, Chad Stansbury wrote:
> Thanks for your response. Unfortunately it doesn't appear to be a
> bad cookie name or value, as the identical set of cookies are
> passed (and parsed correctly) on requests that immediately precede
> and follow the failing request. That's pretty clear from both the
> Wireshark and Tomcat access logs we have. What we're seeing is that
> the client (which is a browser, usually Chrome) sends a burst of
> requests, and occasionally one of those requests will fail as the
> web app detects that is has no cookies even though the Wireshark
> indicates that there are.  We even added logging to the
> AccessLogValve to log the cookies that we're looking for, and it
> yields an empty value... So we know that the cookie parsing is
> either failing or the cookies get cleared following parsing, but
> before being passed on to the AccessLogValve.

Sounds like you have it at least semi-reproducible. That's great news.

What about logging both the results of request.getCookies() as well as
request.getHeader("Cookie")? If the parsing is failing, you will get
no Cookie objects from request.getCookie(), but you should still get
the header back from the request.

If there is no header in the request... well, then maybe something is
wrong elsewhere with the request, and Tomcat never gets to the Cookie
header at all.

> Also, as a follow-up, we corrected the HTTP/1.0 issue, and see that
> the problem persists even with HTTP/1.1. The one thing that I
> failed to mention on the original note is that we're running Tomcat
> on a Windows server. So I'm not sure if that has anything to do
> with the issue that we're seeing or not...

I wouldn't expect Windows to have anything to do with it, same for
HTTP/1.0 versus HTTP/1.1... headers haven't changed much across HTTP
versions, and Tomcat treats those headers the same regardless of the
advertised version of the protocol. The biggest difference between
HTTP/1.0 and HTTP/1.1 is that HTTP/1.1 has a few required headers.

> That being said, I will double-check the catalina.out to see if we
> can find any cookie parsing related errors.

That would be good. Again, it will probably only be logged a single
time, not every time. But if you have the opportunity to bounce Tomcat
and hit it with a load that will likely cause an error to occur, you
ought to be able to catch an error message -- if indeed Cookie-parsing
is the problem. Or, if request-parsing is the problem, too.

One more question: are you using a reverse-proxy like httpd out in
front? Exactly where are you sampling with Wireshark?

- -chris

> On Tue, Feb 27, 2018 at 3:13 PM, Christopher Schultz < 
> ch...@christopherschultz.net> wrote:
> 
> Chad,
> 
> On 2/27/18 9:44 AM, Chad Stansbury wrote:
 We've been troubleshooting an issue where our web application
 is getting a very occasional request that contains no cookies
 even though a Wireshark on the application server shows those
 cookies coming in on the request.
 
 I was able to replay the request that was captured via
 Wireshark, and when doing so, everything goes through just
 fine... so that rules out any sort of weird character set /
 header parsing issues.
 
 Environment specifics: Tomcat v7.0.77 running the (http-bio) 
 connector
 
 Now here's the twist: Currently something in the site 
 infrastructure has been configured to proxy to Tomcat with
 HTTP/1.0 instead of 1.1. We're trying to track that down and
 address that issue (for performance reasons), but in the mean
 time, we're wondering whether or not this is a concurrency
 issue related to protocol caching/recycling?
 
 Has anyone ever seen anything like this before? Is there any 
 legitimate scenario(s) where Tomcat will *not* parse out the 
 cookies, but still route the request to the web app? Is this 
 possible an edge condition that that might be caused by the
 use of HTTP/1.0? Could this possibly be caused by the number
 of maxThreads exceeding the `processorCache` value?
> 
> My immediate thought is that the cookie name or value contains a 
> character that causes parsing to fail within Tomcat. Do you have
> any information about which cookies appear to be being ignored by
> Tomcat (that is, not passed-on to the application) versus those
> that ARE available to the application?
> 
> Tomcat will generally log cookie-parsing errors to catalina.log,
> and possibly to the application's log as well, but it may only do
> so once per Tomcat-launch to avoid filling the disk with logs. Are
> you seeing anything in the Tomcat logs which suggest that
> cookie-parsing is failing ?
> 
> Is the client a browser, or some non-human-interface device, such
> as a client-library or something like that?
> 
> -chris
>> 
>> -
>>
>> 
To unsubscribe, e-mail: 

Re: Tomcat 7 - Sporadic problem re: cookies

[Chad Stansbury]

Hello Chris -

Thanks for your response. Unfortunately it doesn't appear to be a bad
cookie name or value, as the identical set of cookies are passed (and
parsed correctly) on requests that immediately precede and follow the
failing request. That's pretty clear from both the Wireshark and Tomcat
access logs we have. What we're seeing is that the client (which is a
browser, usually Chrome) sends a burst of requests, and occasionally one of
those requests will fail as the web app detects that is has no cookies even
though the Wireshark indicates that there are.  We even added logging to
the AccessLogValve to log the cookies that we're looking for, and it yields
an empty value... So we know that the cookie parsing is either failing or
the cookies get cleared following parsing, but before being passed on to
the AccessLogValve.

Also, as a follow-up, we corrected the HTTP/1.0 issue, and see that the
problem persists even with HTTP/1.1. The one thing that I failed to mention
on the original note is that we're running Tomcat on a Windows server. So
I'm not sure if that has anything to do with the issue that we're seeing or
not...

That being said, I will double-check the catalina.out to see if we can find
any cookie parsing related errors.

Thanks, Chad

On Tue, Feb 27, 2018 at 3:13 PM, Christopher Schultz <
ch...@christopherschultz.net> wrote:

> -BEGIN PGP SIGNED MESSAGE-
> Hash: SHA256
>
> Chad,
>
> On 2/27/18 9:44 AM, Chad Stansbury wrote:
> > We've been troubleshooting an issue where our web application is
> > getting a very occasional request that contains no cookies even
> > though a Wireshark on the application server shows those cookies
> > coming in on the request.
> >
> > I was able to replay the request that was captured via Wireshark,
> > and when doing so, everything goes through just fine... so that
> > rules out any sort of weird character set / header parsing issues.
> >
> > Environment specifics: Tomcat v7.0.77 running the (http-bio)
> > connector
> >
> > Now here's the twist: Currently something in the site
> > infrastructure has been configured to proxy to Tomcat with HTTP/1.0
> > instead of 1.1. We're trying to track that down and address that
> > issue (for performance reasons), but in the mean time, we're
> > wondering whether or not this is a concurrency issue related to
> > protocol caching/recycling?
> >
> > Has anyone ever seen anything like this before? Is there any
> > legitimate scenario(s) where Tomcat will *not* parse out the
> > cookies, but still route the request to the web app? Is this
> > possible an edge condition that that might be caused by the use of
> > HTTP/1.0? Could this possibly be caused by the number of maxThreads
> > exceeding the `processorCache` value?
>
> My immediate thought is that the cookie name or value contains a
> character that causes parsing to fail within Tomcat. Do you have any
> information about which cookies appear to be being ignored by Tomcat
> (that is, not passed-on to the application) versus those that ARE
> available to the application?
>
> Tomcat will generally log cookie-parsing errors to catalina.log, and
> possibly to the application's log as well, but it may only do so once
> per Tomcat-launch to avoid filling the disk with logs. Are you seeing
> anything in the Tomcat logs which suggest that cookie-parsing is failing
> ?
>
> Is the client a browser, or some non-human-interface device, such as a
> client-library or something like that?
>
> - -chris
> -BEGIN PGP SIGNATURE-
> Comment: GPGTools - http://gpgtools.org
> Comment: Using GnuPG with Thunderbird - http://www.enigmail.net/
>
> iQIzBAEBCAAdFiEEMmKgYcQvxMe7tcJcHPApP6U8pFgFAlqVyfIACgkQHPApP6U8
> pFhh3BAAgq6+/VHzI6732NX6To6OVTvIwXw/8OB2A/jDLNwFgWfNrci/KmtSsH0w
> acYcA0D08WBsS8bHD+dHUQ2qvY+0ccyIVGCbyMpZk+du/4bsghpb3PIszSZ+Nsbm
> JNuYxeBVfNRxD2DIDT4+98N20rs5t1zX7mCyWzRT1OU31DRFgmfxkF6I0PTdTRSv
> gPzolgEtszgT7wePifE2tcn1/9J47MstEs6QGMOm9t/Q8naGMCI4DEumMeJZzH4L
> BmTXHVL69RTw8NWJ2Rhqy8jhF1ZLazl4ASE59nfXrCHa/EwNkZ6BaVS0pvqJlkQB
> fTZNvbFpx7m0NOaxGzS5m2KCKFtH1R279RnMHRHovy0ljAr4hlW26APlUhlJsYe7
> QMcm0/lyIZQd27pHhjoRzu9N5J01YotZ3rJLMzeBDI4vh1caRFtVAdyTHOdqdr+9
> 95WTTmtVRlcf7iq+9xdgIyPPCiFkdUOKFS0dc7V794yJjqOfW7ToJsEe/hZlCj5H
> 4yJGhJye3dH9rEzEgTPiIQb+mVYG9y5fJXK7XZ25pnvHNZ8+HheHXEUQdTWgW8ZI
> uHa6eitXXd0lp2xNUN2Itt58Isqn1U4cC7DsPZsH+eVSxIBrIUtx2YVDrwx7yywn
> 8K12ByKlxB7bpfBsMvmdhcZYuTp/y8q7W259117ZmCahhSwMm0k=
> =jwba
> -END PGP SIGNATURE-
>
> -
> To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org
> For additional commands, e-mail: users-h...@tomcat.apache.org
>
>


-- 
*Chad Stansbury*
Principal Engineer | D3 Banking Technology
11837 Miracle Hills Drive Suite 102 | Omaha, NE | 68154
(o)

www.D3Banking.com 

NOTICE: This electronic mail message and any files transmitted with it are
intended exclusively for the individual or entity to which it is addressed.
The 

Re: Tomcat 7 - Sporadic problem re: cookies

[Christopher Schultz]

-BEGIN PGP SIGNED MESSAGE-
Hash: SHA256

Chad,

On 2/27/18 9:44 AM, Chad Stansbury wrote:
> We've been troubleshooting an issue where our web application is
> getting a very occasional request that contains no cookies even
> though a Wireshark on the application server shows those cookies
> coming in on the request.
> 
> I was able to replay the request that was captured via Wireshark,
> and when doing so, everything goes through just fine... so that
> rules out any sort of weird character set / header parsing issues.
> 
> Environment specifics: Tomcat v7.0.77 running the (http-bio)
> connector
> 
> Now here's the twist: Currently something in the site
> infrastructure has been configured to proxy to Tomcat with HTTP/1.0
> instead of 1.1. We're trying to track that down and address that
> issue (for performance reasons), but in the mean time, we're
> wondering whether or not this is a concurrency issue related to
> protocol caching/recycling?
> 
> Has anyone ever seen anything like this before? Is there any
> legitimate scenario(s) where Tomcat will *not* parse out the
> cookies, but still route the request to the web app? Is this
> possible an edge condition that that might be caused by the use of
> HTTP/1.0? Could this possibly be caused by the number of maxThreads
> exceeding the `processorCache` value?

My immediate thought is that the cookie name or value contains a
character that causes parsing to fail within Tomcat. Do you have any
information about which cookies appear to be being ignored by Tomcat
(that is, not passed-on to the application) versus those that ARE
available to the application?

Tomcat will generally log cookie-parsing errors to catalina.log, and
possibly to the application's log as well, but it may only do so once
per Tomcat-launch to avoid filling the disk with logs. Are you seeing
anything in the Tomcat logs which suggest that cookie-parsing is failing
?

Is the client a browser, or some non-human-interface device, such as a
client-library or something like that?

- -chris
-BEGIN PGP SIGNATURE-
Comment: GPGTools - http://gpgtools.org
Comment: Using GnuPG with Thunderbird - http://www.enigmail.net/

iQIzBAEBCAAdFiEEMmKgYcQvxMe7tcJcHPApP6U8pFgFAlqVyfIACgkQHPApP6U8
pFhh3BAAgq6+/VHzI6732NX6To6OVTvIwXw/8OB2A/jDLNwFgWfNrci/KmtSsH0w
acYcA0D08WBsS8bHD+dHUQ2qvY+0ccyIVGCbyMpZk+du/4bsghpb3PIszSZ+Nsbm
JNuYxeBVfNRxD2DIDT4+98N20rs5t1zX7mCyWzRT1OU31DRFgmfxkF6I0PTdTRSv
gPzolgEtszgT7wePifE2tcn1/9J47MstEs6QGMOm9t/Q8naGMCI4DEumMeJZzH4L
BmTXHVL69RTw8NWJ2Rhqy8jhF1ZLazl4ASE59nfXrCHa/EwNkZ6BaVS0pvqJlkQB
fTZNvbFpx7m0NOaxGzS5m2KCKFtH1R279RnMHRHovy0ljAr4hlW26APlUhlJsYe7
QMcm0/lyIZQd27pHhjoRzu9N5J01YotZ3rJLMzeBDI4vh1caRFtVAdyTHOdqdr+9
95WTTmtVRlcf7iq+9xdgIyPPCiFkdUOKFS0dc7V794yJjqOfW7ToJsEe/hZlCj5H
4yJGhJye3dH9rEzEgTPiIQb+mVYG9y5fJXK7XZ25pnvHNZ8+HheHXEUQdTWgW8ZI
uHa6eitXXd0lp2xNUN2Itt58Isqn1U4cC7DsPZsH+eVSxIBrIUtx2YVDrwx7yywn
8K12ByKlxB7bpfBsMvmdhcZYuTp/y8q7W259117ZmCahhSwMm0k=
=jwba
-END PGP SIGNATURE-

-
To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org
For additional commands, e-mail: users-h...@tomcat.apache.org

Tomcat 7 - Sporadic problem re: cookies

[Chad Stansbury]

We've been troubleshooting an issue where our web application is getting a
very occasional request that contains no cookies even though a Wireshark on
the application server shows those cookies coming in on the request.

I was able to replay the request that was captured via Wireshark, and when
doing so, everything goes through just fine... so that rules out any sort
of weird character set / header parsing issues.

Environment specifics: Tomcat v7.0.77 running the (http-bio) connector

Now here's the twist: Currently something in the site infrastructure has
been configured to proxy to Tomcat with HTTP/1.0 instead of 1.1. We're
trying to track that down and address that issue (for performance reasons),
but in the mean time, we're wondering whether or not this is a concurrency
issue related to protocol caching/recycling?

Has anyone ever seen anything like this before? Is there any legitimate
scenario(s) where Tomcat will *not* parse out the cookies, but still route
the request to the web app? Is this possible an edge condition that that
might be caused by the use of HTTP/1.0? Could this possibly be caused by
the number of maxThreads exceeding the `processorCache` value?

Thanks in advance, Chad