https://bz.apache.org/bugzilla/show_bug.cgi?id=62771

            Bug ID: 62771
           Summary: Lost Cookie header (at least) just after request parse
           Product: Tomcat 8
           Version: 8.0.24
          Hardware: All
                OS: Linux
            Status: NEW
          Severity: critical
          Priority: P2
         Component: Catalina
          Assignee: dev@tomcat.apache.org
          Reporter: linooos...@gmail.com
  Target Milestone: ----

Hi friends

I'm working with one tomat 8.0.24 in docker (openshift) with one liferay
application. I have 3 PODS up with 12 GB each one.

I make next test: simply launch 20.000 request over the same file (one static
file) in loop; i send in loop one logger JSESSIONID; when one response returns
me a new JSESSIONID, stop loop and study tomcat traces.

I have actived all needed tomcat traces, and i added next traces in class
CoyoteAdapter.java:


 protected void parseSessionCookiesId(Request request)
  {
    if (log.isDebugEnabled()) {
      log.debug(" (sn3) Begin  parseSessionCookiesId");
    }

    Context context = request.getMappingData().context;
    if ((context != null) && 
      (!context.getServletContext()
      .getEffectiveSessionTrackingModes().contains(
      SessionTrackingMode.COOKIE)))
    {
      if (log.isDebugEnabled()) {
        log.debug(" (sn3) Exit by sessiontracking cookie.");
      }

      return;
    }

    ServerCookies serverCookies = request.getServerCookies();
    int count = serverCookies.getCookieCount();

    if (log.isDebugEnabled()) {
      log.debug(" (sn3) this request have [" + count + "] cookies");
    }

    if (count <= 0)
    {
      if (log.isDebugEnabled()) {
        log.debug(" (sn3) exit with cookies zero");
      }
      return;
    }

Ok! Then, when i recevied one response that change my JSESSIONID, y obtain next
response from tomcat:

FINE: Received [GET
/combo/?browserId=firefox&minifierType=&languageId=es_ES&b=sn33672&t=1487937532000&/html/js/aui/querystring-parse/querystring-parse-min.js&/html/js/aui/aui-url/aui-url-min.js
HTTP/1.1
User-Agent: Mozilla/4.0 (compatible; MSIE 7.0; Windows NT 6.1; WOW64;
Trident/7.0; SLCC2; .NET CLR 2.0.50727; .NET CLR 3.5.30729; .NET CLR 3.0.30729;
Media Center PC 6.0; .NET4.0C; .NET4.0E; InfoPath.3)
Accept-Language: es-ES
Cookie: COOKIE_SUPPORT=true; GUEST_LANGUAGE_ID=es_ES;
JSESSIONID=540BA449FBD21CFE3F91CAFE7E6E3F74;
LFR_SESSION_STATE_20161=1524499633140 LFR_SESSION_STATE_21711=1524501937121;
COMPANY_ID=20157;
ID=68495a7a4c676f5972446677434b59425a54374341773d3d;sn3counter=3672
Referer: http://desktopccorp.aacc.gs.corp/group/espaciocorporativo/home
Cache-Control: no-cache
Pragma: no-cache
Accept: text/html, image/gif, image/jpeg, *; q=.2, */*; q=.2
Host: desktopccorp.aacc.gs.corp
X-Forwarded-Host: desktopccorp.aacc.gs.corp
X-Forwarded-Port: 80
X-Forwarded-Proto: http
Forwarded: for=180.93.30.9;host=desktopccorp.aacc.gs.corp;proto=http
X-Forwarded-For: 180.93.30.9

]

Sep 12, 2018 3:09:16 PM org.apache.catalina.connector.CoyoteAdapter
parsePathParameters
FINE: The variable [uriBC] has value [/combo/]
Sep 12, 2018 3:09:16 PM org.apache.catalina.connector.CoyoteAdapter
parsePathParameters
FINE: The variable [semicolon] has value [-1]
Sep 12, 2018 3:09:16 PM org.apache.catalina.connector.CoyoteAdapter
parsePathParameters
FINE: The variable [enc] has value [utf-8]
Sep 12, 2018 3:09:16 PM org.apache.catalina.connector.CoyoteAdapter
parseSessionCookiesId
FINE:  (sn3) Begin  parseSessionCookiesId
Sep 12, 2018 3:09:16 PM org.apache.catalina.connector.CoyoteAdapter
parseSessionCookiesId
FINE:  (sn3) this request have [0] cookies


0 cookies!! All my cookies are lost, but in Received [ trace of
AbstractNioInputBuffer you can see that Cookie: header is perfectly received!!!

Another important data is the absence of this trace (this is from one "good"
request:

FINE: Cookies: Parsing b[]: COOKIE_SUPPORT=true; GUEST_LANGUAGE_ID=es_ES;
_ga=GA1.4.1488353846.1536682028; _gid=GA1.4.887219159.1536682028;
JSESSIONID=540BA449FBD21CFE3F91CAFE7E6E3F74;
LFR_SESSION_STATE_20161=1536764659329; COMPANY_ID=20157;
ID=767a5147686e743575702b36504e64375a3679306c673d3d;
USER_UUID=6f7039446b675950595756797438326f4f724556774c3830706f4d52526f6b304a502b386c7848786955773d;
LFR_SESSION_STATE_20695=1536764942296

so, reviewing tomcat code, if y have not this trace generated for cookie parser
(i try with two, legacy and Rfc6265CookieProcessor), the unique explanation is
that THIS REQUEST HAVE NOT COOKIE HEADER CHARGED IN REQUEST COYOTE MIMEHEADERS

OK! Another clue friends! Normally when i have this error, one thread that lost
cookies, i have too this error in my tomcat log:

Caused by: java.lang.NullPointerException
        at
org.apache.catalina.connector.Request.parseCookies(Request.java:2948)
        at
org.apache.catalina.connector.Request.convertCookies(Request.java:2963)
        at org.apache.catalina.connector.Request.getCookies(Request.java:1992)
        at
org.apache.catalina.connector.RequestFacade.getCookies(RequestFacade.java:662)
        at
javax.servlet.http.HttpServletRequestWrapper.getCookies(HttpServletRequestWrapper.java:69)
        at
javax.servlet.http.HttpServletRequestWrapper.getCookies(HttpServletRequestWrapper.java:69)
        at
javax.servlet.http.HttpServletRequestWrapper.getCookies(HttpServletRequestWrapper.java:69)
        at
javax.servlet.http.HttpServletRequestWrapper.getCookies(HttpServletRequestWrapper.java:69)
        at
javax.servlet.http.HttpServletRequestWrapper.getCookies(HttpServletRequestWrapper.java:69)
        at
javax.servlet.http.HttpServletRequestWrapper.getCookies(HttpServletRequestWrapper.java:69)
        at
com.liferay.portal.kernel.util.CookieKeys._getCookieMap(CookieKeys.java:275)
        at com.liferay.portal.kernel.util.CookieKeys._get(CookieKeys.java:248)
        at
com.liferay.portal.kernel.util.CookieKeys.getCookie(CookieKeys.java:124)
        at
com.liferay.portal.util.PortalInstances._getCompanyId(PortalInstances.java:173)


Liferay (in another request) try to get all cookies return  NPE. This bug is
reported yet, is  https://bz.apache.org/bugzilla/show_bug.cgi?id=58578

But I think that is not a solution for me... the context is null, ok, but, why?
why at the same time one request fails becuouse mappend context is null, and
another request just arraived lost Cookie Header (or all headers, I don't know
exactly)???



Reviewing tomcat code I only view sense to this combination if for any reason
GC "lost his mind" and begins to call recycle() methos without control. In
different recycle() overrides I see that counter are moved in cookie parse,
context are deleted, etc... have any sense for you??

On monday i'm going to add more traces to AbstractNioInputBuffer class, for log
all parse header process and more important line:

this.headerData.headerValue = this.headers.addValue(this.buf,
this.headerData.start, this.pos - this.headerData.start);

This line that add cookie to headers. In this moment I will refersh info of
this ticket but, friends, meanwhile... any idea??? I am totally lost, more lost
than my cookies!! I test all imaginable: numThreads, backlog size,
crossContext, cookie parsers.... and no succesfull result yet

THANKS IN ADVANCE FRIENDS!

Regards,
Lino

-- 
You are receiving this mail because:
You are the assignee for the bug.
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscr...@tomcat.apache.org
For additional commands, e-mail: dev-h...@tomcat.apache.org

Reply via email to