I have a question about processing within the ISAPI Redirector, in the AJP13 processing in particular is where my situation is occurring. At least that is what I think based upon what I am getting from the logs.
First let me describe my setup/config/platform. I am running Tomcat 6.0 (file version 2.0.4.0 per the 'tomcat6.exe' properties) on a Windows Server 2003 SE (SP2) with IIS 6.0 (running in "IIS 5.0 Isolation Mode) and am using the ISAPI Redirector v 1.2.26.0 dated September 10, 2008. I know my config with this is correct because IIS is passing my requests to the ISAPI filter and the pages on Tomcat are working -- to a point. I have an application that uses several Java servlets and one of the classes used in these servlets processes the data in a cookie generated by an access control product that we use called GetAccess. GetAccess uses an ISAPI filter to do access control and validation and we have it configured to preserve the users ID and name in a cookie which our application uses to make the pages personal for each user.
In the ISAPI Redirector log, I can see the cookie information being passed to the ajp13 processor. Here is a snippet of that log with this information:
(I have separated the section of the buffer where the GetAccess cookie data are located. I also replaced information that I wish to hold private with "X" and which I believe do not affect this problem.)
[Wed Jun 16 10:34:40.107 2010] [3796:1872] [debug] jk_ajp_common.c (934): sending to ajp13 pos=4 len=1104 max=8192 [Wed Jun 16 10:34:40.107 2010] [3796:1872] [debug] jk_ajp_common.c (934): 0000 12 34 04 4C 02 02 00 08 48 54 54 50 2F 31 2E 31 - .4.L....HTTP/1.1 [Wed Jun 16 10:34:40.107 2010] [3796:1872] [debug] jk_ajp_common.c (934): 0010 00 00 0D 2F 73 64 73 2F 66 61 63 65 2E 6A 73 70 - .../sds/face.jsp [Wed Jun 16 10:34:40.107 2010] [3796:1872] [debug] jk_ajp_common.c (934): 0020 00 00 0C 31 30 2E 33 32 2E 36 38 2E 32 30 38 00 - ...XX.XX.XX.208. [Wed Jun 16 10:34:40.107 2010] [3796:1872] [debug] jk_ajp_common.c (934): 0030 00 0C 31 30 2E 33 32 2E 36 38 2E 32 30 38 00 00 - ..XX.XX.XX.208.. [Wed Jun 16 10:34:40.107 2010] [3796:1872] [debug] jk_ajp_common.c (934): 0040 18 6A 63 61 73 74 65 72 62 65 74 61 2E 6A 63 70 - .XXXXXXXXXXX.XXX [Wed Jun 16 10:34:40.107 2010] [3796:1872] [debug] jk_ajp_common.c (934): 0050 65 6E 6E 65 79 2E 63 6F 6D 00 00 50 00 00 10 A0 - XXXXX.com..P.... [Wed Jun 16 10:34:40.107 2010] [3796:1872] [debug] jk_ajp_common.c (934): 0060 06 00 0A 4B 65 65 70 2D 41 6C 69 76 65 00 A0 01 - ...Keep-Alive... [Wed Jun 16 10:34:40.107 2010] [3796:1872] [debug] jk_ajp_common.c (934): 0070 01 0F 69 6D 61 67 65 2F 67 69 66 2C 20 69 6D 61 - ..image/gif,.ima [Wed Jun 16 10:34:40.107 2010] [3796:1872] [debug] jk_ajp_common.c (934): 0080 67 65 2F 78 2D 78 62 69 74 6D 61 70 2C 20 69 6D - ge/x-xbitmap,.im [Wed Jun 16 10:34:40.107 2010] [3796:1872] [debug] jk_ajp_common.c (934): 0090 61 67 65 2F 6A 70 65 67 2C 20 69 6D 61 67 65 2F - age/jpeg,.image/ [Wed Jun 16 10:34:40.107 2010] [3796:1872] [debug] jk_ajp_common.c (934): 00a0 70 6A 70 65 67 2C 20 61 70 70 6C 69 63 61 74 69 - pjpeg,.applicati [Wed Jun 16 10:34:40.107 2010] [3796:1872] [debug] jk_ajp_common.c (934): 00b0 6F 6E 2F 78 2D 73 68 6F 63 6B 77 61 76 65 2D 66 - on/x-shockwave-f [Wed Jun 16 10:34:40.107 2010] [3796:1872] [debug] jk_ajp_common.c (934): 00c0 6C 61 73 68 2C 20 61 70 70 6C 69 63 61 74 69 6F - lash,.applicatio [Wed Jun 16 10:34:40.107 2010] [3796:1872] [debug] jk_ajp_common.c (934): 00d0 6E 2F 78 2D 6D 73 2D 61 70 70 6C 69 63 61 74 69 - n/x-ms-applicati [Wed Jun 16 10:34:40.107 2010] [3796:1872] [debug] jk_ajp_common.c (934): 00e0 6F 6E 2C 20 61 70 70 6C 69 63 61 74 69 6F 6E 2F - on,.application/ [Wed Jun 16 10:34:40.107 2010] [3796:1872] [debug] jk_ajp_common.c (934): 00f0 78 2D 6D 73 2D 78 62 61 70 2C 20 61 70 70 6C 69 - x-ms-xbap,.appli [Wed Jun 16 10:34:40.107 2010] [3796:1872] [debug] jk_ajp_common.c (934): 0100 63 61 74 69 6F 6E 2F 76 6E 64 2E 6D 73 2D 78 70 - cation/vnd.ms-xp [Wed Jun 16 10:34:40.107 2010] [3796:1872] [debug] jk_ajp_common.c (934): 0110 73 64 6F 63 75 6D 65 6E 74 2C 20 61 70 70 6C 69 - sdocument,.appli [Wed Jun 16 10:34:40.107 2010] [3796:1872] [debug] jk_ajp_common.c (934): 0120 63 61 74 69 6F 6E 2F 78 61 6D 6C 2B 78 6D 6C 2C - cation/xaml+xml, [Wed Jun 16 10:34:40.107 2010] [3796:1872] [debug] jk_ajp_common.c (934): 0130 20 61 70 70 6C 69 63 61 74 69 6F 6E 2F 76 6E 64 - .application/vnd [Wed Jun 16 10:34:40.107 2010] [3796:1872] [debug] jk_ajp_common.c (934): 0140 2E 6D 73 2D 65 78 63 65 6C 2C 20 61 70 70 6C 69 - .ms-excel,.appli [Wed Jun 16 10:34:40.107 2010] [3796:1872] [debug] jk_ajp_common.c (934): 0150 63 61 74 69 6F 6E 2F 76 6E 64 2E 6D 73 2D 70 6F - cation/vnd.ms-po [Wed Jun 16 10:34:40.107 2010] [3796:1872] [debug] jk_ajp_common.c (934): 0160 77 65 72 70 6F 69 6E 74 2C 20 61 70 70 6C 69 63 - werpoint,.applic [Wed Jun 16 10:34:40.107 2010] [3796:1872] [debug] jk_ajp_common.c (934): 0170 61 74 69 6F 6E 2F 6D 73 77 6F 72 64 2C 20 2A 2F - ation/msword,.*/ [Wed Jun 16 10:34:40.107 2010] [3796:1872] [debug] jk_ajp_common.c (934): 0180 2A 00 00 0F 61 63 63 65 70 74 2D 65 6E 63 6F 64 - *...accept-encod [Wed Jun 16 10:34:40.107 2010] [3796:1872] [debug] jk_ajp_common.c (934): 0190 69 6E 67 00 00 0D 67 7A 69 70 2C 20 64 65 66 6C - ing...gzip,.defl [Wed Jun 16 10:34:40.107 2010] [3796:1872] [debug] jk_ajp_common.c (934): 01a0 61 74 65 00 00 0F 61 63 63 65 70 74 2D 6C 61 6E - ate...accept-lan [Wed Jun 16 10:34:40.107 2010] [3796:1872] [debug] jk_ajp_common.c (934): 01b0 67 75 61 67 65 00 00 05 65 6E 2D 75 73 00 A0 05 - guage...en-us... [Wed Jun 16 10:34:40.107 2010] [3796:1872] [debug] jk_ajp_common.c (934): 01c0 00 27 42 61 73 69 63 20 4D 44 41 77 4D 7A 49 31 - .'Basic.MDAwMzI1 [Wed Jun 16 10:34:40.107 2010] [3796:1872] [debug] jk_ajp_common.c (934): 01d0 4D 6A 41 33 4F 6B 4A 50 52 31 56 54 58 31 42 42 - MjA3OkJPR1VTX1BB [Wed Jun 16 10:34:40.107 2010] [3796:1872] [debug] jk_ajp_common.c (934): 01e0 55 31 4E 58 54 31 4A 45 3D 00 A0 09 00 C6 4A 53 - U1NXT1JE=.....JS [Wed Jun 16 10:34:40.107 2010] [3796:1872] [debug] jk_ajp_common.c (934): 01f0 45 53 53 49 4F 4E 49 44 3D 42 43 30 42 34 44 30 - ESSIONID=BC0B4D0 [Wed Jun 16 10:34:40.107 2010] [3796:1872] [debug] jk_ajp_common.c (934): 0200 44 33 42 33 45 41 36 39 45 31 32 41 45 36 38 42 - D3B3EA69E12AE68B [Wed Jun 16 10:34:40.107 2010] [3796:1872] [debug] jk_ajp_common.c (934): 0210 33 44 46 31 38 42 44 43 43 3B 20 41 55 54 48 5F - 3DF18BDCC;.AUTH_ [Wed Jun 16 10:34:40.107 2010] [3796:1872] [debug] jk_ajp_common.c (934): 0220 53 45 53 53 49 4F 4E 5F 49 44 3D 53 4D 53 5F 67 - SESSION_ID=SMS_g [Wed Jun 16 10:34:40.107 2010] [3796:1872] [debug] jk_ajp_common.c (934): 0230 61 73 74 67 32 38 31 5F 64 30 30 35 38 34 3A 3A - astg281_d00584:: [Wed Jun 16 10:34:40.107 2010] [3796:1872] [debug] jk_ajp_common.c (934): 0240 62 66 32 62 64 62 33 38 66 63 65 62 38 31 38 62 - bf2bdb38fceb818b [Wed Jun 16 10:34:40.107 2010] [3796:1872] [debug] jk_ajp_common.c (934): 0250 62 64 39 30 34 61 62 33 64 61 33 39 34 31 35 65 - bd904ab3da39415e
[Wed Jun 16 10:34:40.107 2010] [3796:1872] [debug] jk_ajp_common.c (934): 0260 3B 47 41 55 53 45 52 49 4E 46 4F 3D 66 69 72 73 - ;GAUSERINFO=firs [Wed Jun 16 10:34:40.107 2010] [3796:1872] [debug] jk_ajp_common.c (934): 0270 74 5F 6E 61 6D 65 3D 52 49 43 48 41 52 44 26 6C - t_name=RICHARD&l [Wed Jun 16 10:34:40.107 2010] [3796:1872] [debug] jk_ajp_common.c (934): 0280 61 73 74 5F 6E 61 6D 65 3D 43 55 52 52 59 26 6D - ast_name=CURRY&m [Wed Jun 16 10:34:40.107 2010] [3796:1872] [debug] jk_ajp_common.c (934): 0290 69 64 64 6C 65 5F 69 6E 69 74 69 61 6C 3D 47 26 - iddle_initial=G& [Wed Jun 16 10:34:40.107 2010] [3796:1872] [debug] jk_ajp_common.c (934): 02a0 63 6F 72 70 6F 72 61 74 65 5F 69 64 3D 52 47 43 - corporate_id=XXX [Wed Jun 16 10:34:40.107 2010] [3796:1872] [debug] jk_ajp_common.c (934): 02b0 55 52 52 59 00 A0 0B 00 18 6A 63 61 73 74 65 72 - XXXX.....XXXXXXX
[Wed Jun 16 10:34:40.107 2010] [3796:1872] [debug] jk_ajp_common.c (934): 02c0 62 65 74 61 2E 6A 63 70 65 6E 6E 65 79 2E 63 6F - XXXX.XXXXXXXX.XX [Wed Jun 16 10:34:40.107 2010] [3796:1872] [debug] jk_ajp_common.c (934): 02d0 6D 00 A0 0D 00 24 68 74 74 70 3A 2F 2F 6A 63 61 - X....$http://XXX [Wed Jun 16 10:34:40.107 2010] [3796:1872] [debug] jk_ajp_common.c (934): 02e0 73 74 65 72 62 65 74 61 2E 6A 63 70 65 6E 6E 65 - XXXXXXXX.XXXXXXX [Wed Jun 16 10:34:40.107 2010] [3796:1872] [debug] jk_ajp_common.c (934): 02f0 79 2E 63 6F 6D 2F 73 64 73 2F 00 A0 0E 00 91 4D - X.XXX/sds/.....M [Wed Jun 16 10:34:40.107 2010] [3796:1872] [debug] jk_ajp_common.c (934): 0300 6F 7A 69 6C 6C 61 2F 34 2E 30 20 28 63 6F 6D 70 - ozilla/4.0.(comp [Wed Jun 16 10:34:40.107 2010] [3796:1872] [debug] jk_ajp_common.c (934): 0310 61 74 69 62 6C 65 3B 20 4D 53 49 45 20 37 2E 30 - atible;.MSIE.7.0 [Wed Jun 16 10:34:40.107 2010] [3796:1872] [debug] jk_ajp_common.c (934): 0320 3B 20 57 69 6E 64 6F 77 73 20 4E 54 20 35 2E 31 - ;.Windows.NT.5.1 [Wed Jun 16 10:34:40.107 2010] [3796:1872] [debug] jk_ajp_common.c (934): 0330 3B 20 2E 4E 45 54 20 43 4C 52 20 31 2E 31 2E 34 - ;..NET.CLR.1.1.4 [Wed Jun 16 10:34:40.107 2010] [3796:1872] [debug] jk_ajp_common.c (934): 0340 33 32 32 3B 20 2E 4E 45 54 20 43 4C 52 20 32 2E - 322;..NET.CLR.2. [Wed Jun 16 10:34:40.107 2010] [3796:1872] [debug] jk_ajp_common.c (934): 0350 30 2E 35 30 37 32 37 3B 20 2E 4E 45 54 20 43 4C - 0.50727;..NET.CL [Wed Jun 16 10:34:40.107 2010] [3796:1872] [debug] jk_ajp_common.c (934): 0360 52 20 33 2E 30 2E 34 35 30 36 2E 32 31 35 32 3B - R.3.0.4506.2152; [Wed Jun 16 10:34:40.107 2010] [3796:1872] [debug] jk_ajp_common.c (934): 0370 20 2E 4E 45 54 20 43 4C 52 20 33 2E 35 2E 33 30 - ..NET.CLR.3.5.30 [Wed Jun 16 10:34:40.107 2010] [3796:1872] [debug] jk_ajp_common.c (934): 0380 37 32 39 3B 20 49 6E 66 6F 50 61 74 68 2E 31 29 - 729;.InfoPath.1) [Wed Jun 16 10:34:40.107 2010] [3796:1872] [debug] jk_ajp_common.c (934): 0390 00 00 06 75 61 2D 63 70 75 00 00 03 78 38 36 00 - ...ua-cpu...x86. [Wed Jun 16 10:34:40.107 2010] [3796:1872] [debug] jk_ajp_common.c (934): 03a0 00 04 75 73 65 72 00 00 09 30 30 30 33 32 35 32 - ..user...0003252 [Wed Jun 16 10:34:40.107 2010] [3796:1872] [debug] jk_ajp_common.c (934): 03b0 30 37 00 00 06 6C 6F 63 61 6C 65 00 00 05 65 6E - 07...locale...en [Wed Jun 16 10:34:40.107 2010] [3796:1872] [debug] jk_ajp_common.c (934): 03c0 5F 55 53 00 00 09 73 65 73 73 69 6F 6E 69 64 00 - _US...sessionid. [Wed Jun 16 10:34:40.107 2010] [3796:1872] [debug] jk_ajp_common.c (934): 03d0 00 35 53 4D 53 5F 67 61 73 74 67 32 38 31 5F 64 - .5SMS_gastg281_d [Wed Jun 16 10:34:40.107 2010] [3796:1872] [debug] jk_ajp_common.c (934): 03e0 30 30 35 38 34 3A 3A 62 66 32 62 64 62 33 38 66 - 00584::bf2bdb38f [Wed Jun 16 10:34:40.107 2010] [3796:1872] [debug] jk_ajp_common.c (934): 03f0 63 65 62 38 31 38 62 62 64 39 30 34 61 62 33 64 - ceb818bbd904ab3d [Wed Jun 16 10:34:40.107 2010] [3796:1872] [debug] jk_ajp_common.c (1395): (sds-tomcat-worker) request body to send 0 - request body to resend 0 [Wed Jun 16 10:34:40.373 2010] [3796:1872] [debug] jk_ajp_common.c (1117): received from ajp13 pos=0 len=107 max=8192 [Wed Jun 16 10:34:40.373 2010] [3796:1872] [debug] jk_ajp_common.c (1117): 0000 04 00 C8 00 02 4F 4B 00 00 02 00 0A 53 65 74 2D - .....OK.....Set- [Wed Jun 16 10:34:40.373 2010] [3796:1872] [debug] jk_ajp_common.c (1117): 0010 43 6F 6F 6B 69 65 00 00 36 4A 53 45 53 53 49 4F - Cookie..6JSESSIO [Wed Jun 16 10:34:40.373 2010] [3796:1872] [debug] jk_ajp_common.c (1117): 0020 4E 49 44 3D 39 35 39 41 37 30 32 38 37 45 30 33 - NID=959A70287E03 [Wed Jun 16 10:34:40.373 2010] [3796:1872] [debug] jk_ajp_common.c (1117): 0030 46 35 30 33 41 33 33 31 30 32 30 36 39 41 31 38 - F503A33102069A18 [Wed Jun 16 10:34:40.373 2010] [3796:1872] [debug] jk_ajp_common.c (1117): 0040 46 37 42 35 3B 20 50 61 74 68 3D 2F 73 64 73 00 - F7B5;.Path=/sds. [Wed Jun 16 10:34:40.373 2010] [3796:1872] [debug] jk_ajp_common.c (1117): 0050 00 0C 43 6F 6E 74 65 6E 74 2D 54 79 70 65 00 00 - ..Content-Type.. [Wed Jun 16 10:34:40.373 2010] [3796:1872] [debug] jk_ajp_common.c (1117): 0060 09 74 65 78 74 2F 68 74 6D 6C 00 00 00 00 00 00 - .text/html......
[Wed Jun 16 10:34:40.373 2010] [3796:1872] [debug] jk_ajp_common.c (608): status = 200 [Wed Jun 16 10:34:40.373 2010] [3796:1872] [debug] jk_ajp_common.c (615): Number of headers is = 2
I included the response from ajp13 as it seems to me that it is confirming my suspicion which is the ajp13 is cutting off my GetAccess cookie data. Here is why I think that. I modified the class that processes the cookie data to pump out console messages which Tomcat captures and puts into its stdout_yyyymmdd.log; a snippet of that log follows that includes reports the cookie data processing:
SDSUser - SDSUser(req) - Cookie Name: JSESSIONID Cookie content follows:
959A70287E03F503A33102069A18F7B5
959A70287E03F503A33102069A18F7B5
SDSUser - SDSUser(req) - Cookie Name: AUTH_SESSION_ID Cookie content follows:
SMS_gastg281_d00584
SMS_gastg281_d00584
SDSUser - SDSUser(req) - Cookie Name: GAUSERINFO Cookie content follows:
first_name
first_name
The output above shows the class first displaying all of the cookie data, then a dashed line, then it loops thru each item within the cookie. For the first two, there is only one part to the cookie. But as the buffer above being passed to the ajp13 processor shows (that portion between the "**" lines), the GetAccess cookie has several parameters separated by "&" using the keyword=value paring for each parm. The GetAccess cookie in this example hold the following data and the output from this class's processing of this data should look like this:
SDSUser - SDSUser(req) - Cookie Name: GAUSERINFO Cookie content follows:
GAUSERINFO=first_name=RICHARD&last_name=CURRY&middle_initial=G&corporate_id=XXXXXXX
first_name=RICHARD last_name=CURRY middle_initial=G corporate_id=XXXXXXX
It seems that the first "=" of the first parm is causing the ajp13 processor to stop processing the cookie and that information is not passed in the session data that gets to Tomcat and the app that needs that information.
I have reviewed the Apache Tomcat Connector Reference Guide and other related doc including the docs I have found about the AJPv13 connector but did not see anything related to this situation. I did find one message in the Tomcat Users mail archive that mentioned a similar problem; an excerpt of this follows:
" from http://mail-archives.apache.org/mod_mbox/tomcat-users/200912.mbox/%[email protected]%3e " Control character in cookie value 05 Dec 2009 13:37:32 GMT Then you'll need to worry about Base64 using '=' in cookie values. The value needs to be quoted for this to work. Tomcat will do this automatically if necessary.
I have searched the archives of several mailing lists (Gossamer Threads and Listware to name a few) and other support sites such as Code Guru and Stack Overflow and although I find a lot of information about the ISAPI Redirector this one message is the only one similar to my situation.
With your knowledge of how the ISAPI Redirector and the AJP13 processor functions, is this a valid assessment; that somewhere in this processing, the "=" in the cookie value is causing it to be chopped off? If so, where might I begin my code search in the ISAPI Redirector or AJP Connector to resolve this?
I appreciate your time and consideration of my inquiry. If you require additional information, please let me know; I will gladly provide what I can. I am excited to find a solution to this situation.