Re: HttpServletRequest.getRemoteAddr() sometimes returns NULL on Tomcat 9.0.30 and HTTP/2 secure requests

Sat, 28 Mar 2020 07:02:10 -0700

Hi Mark, we're now on the latest 9.0.33 release and we still see this issue intermittently in our logs. Only on HTTP/2 secure requests.
Please see the attached access logs (these represent all the cases for one whole day in one single high-volume server). 
Some of the following request fields are NULL (or -1) in these examples:
- remoteAddr
- remotePort
- serverPort
- requestURI
- User-Agent
Some requests are missing some of the fields, some of the requests are missing others. What is particularly interesting is that the errors are clustered around particular timestamps, pointing to some likely issue regarding object sharing across several requests.
Please note that this is not just an issue at the AccessLogValve level. These fields contain invalid data while the request is being processed, so that is causing unexpected exceptions in our production code. The cases are few and isolated, but still this should be looked into. 

Any thoughts?

*Manuel Dominguez Sarmiento*

On 05/02/2020 14:12, Manuel Dominguez Sarmiento wrote:
Our filter is not doing anything fancy (and it has always worked correctly before we ran into this bug). In pseudo-code: 

public doFilter(request, response) {

    String ip = request.getRemoteAddr();
    boolean isProxy = isProxy(ip);
    if (isProxy) {
        String unwrappedIP = unwrapXForwardedFor(request);
        chain.doFilter(new MobileProxyHidingServletRequestWrapper(request, unwrappedIP), response); 
    } else {
        chain.doFilter(request, response);
    }
}
All that MobileProxyHidingServletRequestWrapper is override getRemoteAddr() returning unwrappedIP instead of delegating to the actual request, while unwrapXForwardedFor() does what the name suggests, which is processing X-Forwarded-For to obtain the originating IP before it hit the detected proxy. 

*Manuel Dominguez Sarmiento*

On 05/02/2020 10:28, Mark Thomas wrote:

On 04/02/2020 22:27, Manuel Dominguez Sarmiento wrote:

We are getting the NPEs in a top-of-the-chain servlet filter which
decorates HttpServletRequest.getRemoteAddr() before actual servlet
processing. Only on HTTP/2 and in a very small number of cases. Perhaps
we should test 9.0.31 and see what happens. When is this new version due
for release?

I'm just working through back-porting some changes and then I'll be
starting the release process. It 9.0.31 should be available towards the
beginning of next week.

Can you expand on what your filter is doing? When is the call made to
HttpServletRequest.getRemoteAddr() on the original request?

Mark




LOOKING FOR ALL ISSUE INSTANCES:

[root@optimus ~]# cat /home/wap/logs/access.2020-03-27.log | grep "^-"
- -1 443 [27/Mar/2020:07:53:12 -0300] "GET /us/en/country.do?method=list 
HTTP/2.0" 400 762 "-" "Mozilla/5.0 (Linux; Android 6.0; vivo 1609) 
AppleWebKit/537.36 (KHTML, like Gecko) Chrome/79.0.3945.93 Mobile Safari/537.36"
- -1 443 [27/Mar/2020:10:48:12 -0300] "GET 
/pe/es/subscriptionPlanDetail.do?id=4483&patch=false&pbid=2181&wc=46045&trk=true&atil=419634618870&btil=&ctil=ojo.pe&dtil=d&gclid=EAIaIQobChMIif6cyOW66AIVKAa5Bh3eRgI6EAEYASAAEgJuRPD_BwE
 HTTP/2.0" 400 637 "https://ojo.pe/"; "Mozilla/5.0 (Linux; Android 9; LM-X520 
Build/PKQ1.190223.001; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 
Chrome/80.0.3987.119 Mobile Safari/537.36 [FB_IAB/FB4A;FBAV/260.0.0.42.118;]"
- -1 443 [27/Mar/2020:14:39:36 -0300] "GET 
/cl/es/subscriptionPlanDetail.do?id=4120&patch=false&pbid=2131&ceid=17450&opd=false&wc=45663&trk=true&atil=380011499904&btil=&ctil=mobileapp%3A%3A2-com.appstar.callrecorder&gclid=EAIaIQobChMI-aa0_8uN6AIVZga5Bh1UBwQ5EAEYASAAEgKAxPD_BwE&entel_cl_smd_ok=32320413&c=32320413&sig=705b26c82e98b8401b74a463a68180d6&cts=1584044911681&conntype=CELLULAR&connspeed=EFFECTIVE_4G&noshim=true
 HTTP/2.0" 400 637 
"https://wap.renxo.com/cl/es/subscriptionPlanDetail.do?id=4120&patch=false&pbid=2131&ceid=17450&opd=false&wc=45663&trk=true&atil=380011499904&btil=&ctil=mobileapp%3A%3A2-com.appstar.callrecorder&gclid=EAIaIQobChMI-aa0_8uN6AIVZga5Bh1UBwQ5EAEYASAAEgKAxPD_BwE&entel_cl_smd_ok=32320413&c=32320413&sig=705b26c82e98b8401b74a463a68180d6&cts=1584044911681&conntype=CELLULAR&connspeed=EFFECTIVE_4G";
 "Mozilla/5.0 (Linux; Android 8.1.0; SAMSUNG SM-J710MN Build/M1AJQ) 
AppleWebKit/537.36 (KHTML, like Gecko) SamsungBrowser/9.4 Chrome/67.0.3396.87 
Mobile Safari/537.36"
- -1 443 [27/Mar/2020:17:18:55 -0300] "GET 
/ar/es/subscriptionPlanDetail.do?id=4328&ceid=16242&pbid=2403&wc=48008&trk=true&atil=409370554249&btil=%2Farts%20%26%20entertainment&ctil=cuttsite.website&dtil=d&gclid=EAIaIQobChMI98zj67y76AIVT4p3Ch3riAVXEAEYASAAEgLGavD_BwE
 HTTP/2.0" 400 637 
"https://googleads.g.doubleclick.net/pagead/ads?client=ca-pub-2929318494915332&output=html&h=250&slotname=4353673900&adk=3696358127&adf=3108995893&w=300&lmt=1585340298&psa=1&guci=2.2.0.0.2.2.0.0&format=300x250&url=https%3A%2F%2Fcuttsite.website%2Fpica-3-limones-con-sal-encima-ponlo-cerca-de-tu-cama-y-veras-lo-que-pasa-en-los-proximos-15-minutos%2F&flash=0&wgl=1&dt=1585340297517&bpp=36&bdt=2610&idt=526&shv=r20200324&cbv=r20190131&ptt=9&saldr=aa&abxe=1&cookie=ID%3D7489a82afd59cfe7%3AT%3D1580676408%3AS%3DALNI_MbJWniZS34uo5D_IKexygyl9kHRXg&crv=1&prev_fmts=360x300&correlator=3721745222895&frm=20&pv=1&ga_vid=662555076.1580676587&ga_sid=1585340298&ga_hid=1508954517&ga_fc=0&iag=0&icsg=2392605966663664&dssz=43&mdo=0&mso=0&u_tz=-180&u_his=1&u_java=0&u_h=640&u_w=360&u_ah=640&u_aw=360&u_cd=24&u_nplug=0&u_nmime=0&adx=30&ady=1051&biw=360&bih=532&scr_x=0&scr_y=378&eid=21065713%2C21065715%2C44713364%2C633794031%2C410075105&oid=3&pvsid=2071045736628243&pem=677&ref=http%3A%2F%2Fm.facebook.com%2F&rx=0&eae=0&fc=896&brdim=0%2C0%2C0%2C0%2C360%2C0%2C360%2C532%2C360%2C532&vis=1&rsz=%7C%7CeEbr%7C&abl=CS&pfx=0&fu=8208&bc=31&ifi=2&uci=a!2&btvi=1&fsb=1&xpc=rweh5fjEx7&p=https%3A//cuttsite.website&dtd=565";
 "Mozilla/5.0 (Linux; Android 6.0; CAM-L03 Build/HUAWEICAM-L03; wv) 
AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/80.0.3987.132 Mobile 
Safari/537.36 [FB_IAB/FB4A;FBAV/260.0.0.42.118;]"
- -1 443 [27/Mar/2020:20:55:48 -0300] "GET 
/cl/es/subscriptionPlanDetail.do?id=4120&patch=false&pbid=2194&ceid=15401&opd=false&wc=48047&trk=true&entel_cl_smd_ok=75206403&c=75206403&sig=5f5c2883295aacb30dcd92463100b43d&cts=1585353323195&conntype=CELLULAR&connspeed=EFFECTIVE_4G
 HTTP/2.0" 400 637 "http://m.facebook.com/"; "Mozilla/5.0 (Linux; Android 8.0.0; 
LDN-LX3 Build/HUAWEILDN-LX3; wv) AppleWebKit/537.36 (KHTML, like Gecko) 
Version/4.0 Chrome/77.0.3865.116 Mobile Safari/537.36 
[FB_IAB/FB4A;FBAV/262.0.0.34.117;]"
- -1 443 [27/Mar/2020:21:22:44 -0300] "GET 
/pe/es/subscriptionPlanDetail.do?id=4481&patch=false&pbid=2077&wc=46754&trk=true
 HTTP/2.0" 400 637 "http://m.facebook.com/"; "Mozilla/5.0 (Linux; Android 9; 
Redmi Note 8 Build/PKQ1.190616.001; wv) AppleWebKit/537.36 (KHTML, like Gecko) 
Version/4.0 Chrome/80.0.3987.132 Mobile Safari/537.36 
[FB_IAB/FB4A;FBAV/261.0.0.52.126;]"
- -1 443 [27/Mar/2020:22:39:10 -0300] "GET 
/pe/es/subscriptionPlanDetail.do?id=4479&patch=false&pbid=2243&wc=46576&trk=true&atil=356198758492&btil=&ctil=www.notifresh.com&dtil=d&gclid=EAIaIQobChMI7ujVsoS86AIVTiPTCh1X7wrSEAEYASAAEgJE0_D_BwE
 HTTP/2.0" 400 637 
"https://googleads.g.doubleclick.net/pagead/ads?client=ca-pub-3136901199458158&output=html&h=300&slotname=3392932137&adk=1348254223&adf=54630664&w=360&lmt=1585363062&rafmt=1&armr=1&psa=1&guci=2.2.0.0.2.2.0.0&format=360x300&url=https%3A%2F%2Fwww.notifresh.com%2Fshare%2Fvideos%2FovU95w%2F&flash=0&fwr=1&rs=1&rh=280&rw=336&rpe=1&resp_fmts=3&sfro=1&wgl=1&dt=1585363062186&bpp=50&bdt=190&fdt=371&idt=372&shv=r20200324&cbv=r20190131&ptt=9&saldr=aa&abxe=1&correlator=3166985023535&frm=20&pv=2&ga_vid=1799828056.1585363062&ga_sid=1585363063&ga_hid=162526082&ga_fc=0&iag=0&icsg=33595567&dssz=25&mdo=0&mso=0&u_tz=-360&u_his=2&u_java=0&u_h=780&u_w=360&u_ah=780&u_aw=360&u_cd=24&u_nplug=0&u_nmime=0&adx=0&ady=75&biw=360&bih=665&scr_x=0&scr_y=0&eid=44713363&oid=3&pvsid=3334872409361851&pem=595&ref=http%3A%2F%2Fm.facebook.com%2F&rx=0&eae=0&fc=900&brdim=0%2C0%2C0%2C0%2C360%2C0%2C360%2C665%2C360%2C665&vis=1&rsz=%7C%7CeE%7C&abl=CS&pfx=0&fu=144&bc=31&ifi=1&uci=a!1&fsb=1&xpc=x6EFawm1tV&p=https%3A//www.notifresh.com&dtd=419";
 "Mozilla/5.0 (Linux; Android 9; POT-LX3 Build/HUAWEIPOT-L03; wv) 
AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/74.0.3729.157 Mobile 
Safari/537.36 [FB_IAB/FB4A;FBAV/224.0.0.33.114;]"
- -1 443 [27/Mar/2020:23:14:05 -0300] "GET 
/pe/es/subscriptionPlanDetail.do?id=4479&patch=false&pbid=2138&wc=46540&trk=true&trk=true&atil=353985833412&btil=%2Farts%20%26%20entertainment%2Ftv%20%26%20video&ctil=www.youtube.com&dtil=d&gclid=EAIaIQobChMIq-mIh4y86AIV1lQBCh02sw-9EAEYASAAEgKgn_D_BwE
 HTTP/2.0" 400 637 "-" "Mozilla/5.0 (Linux; Android 6.0.1; SAMSUNG SM-G532M 
Build/MMB29T) AppleWebKit/537.36 (KHTML, like Gecko) SamsungBrowser/8.2 
Chrome/63.0.3239.111 Mobile Safari/537.36"


LOOKING MORE CLOSELY AT THE TIMESTAMPS WHERE ABOVE ISSUES WERE FOUND:


[root@optimus ~]# cat /home/wap/logs/access.2020-03-27.log | grep "07:53:12" | 
grep " 400 "
177.79.63.158 30415 -1 [27/Mar/2020:07:53:12 -0300] "-" 400 - "-" "-"
177.79.63.158 30424 -1 [27/Mar/2020:07:53:12 -0300] "-" 400 - "-" "-"
177.158.236.125 26592 -1 [27/Mar/2020:07:53:12 -0300] "-" 400 - "-" "-"
- -1 443 [27/Mar/2020:07:53:12 -0300] "GET /us/en/country.do?method=list 
HTTP/2.0" 400 762 "-" "Mozilla/5.0 (Linux; Android 6.0; vivo 1609) 
AppleWebKit/537.36 (KHTML, like Gecko) Chrome/79.0.3945.93 Mobile Safari/537.36"


[root@optimus ~]# cat /home/wap/logs/access.2020-03-27.log | grep "10:48:12" | 
grep " 400 "
- -1 443 [27/Mar/2020:10:48:12 -0300] "GET 
/pe/es/subscriptionPlanDetail.do?id=4483&patch=false&pbid=2181&wc=46045&trk=true&atil=419634618870&btil=&ctil=ojo.pe&dtil=d&gclid=EAIaIQobChMIif6cyOW66AIVKAa5Bh3eRgI6EAEYASAAEgJuRPD_BwE
 HTTP/2.0" 400 637 "https://ojo.pe/"; "Mozilla/5.0 (Linux; Android 9; LM-X520 
Build/PKQ1.190223.001; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 
Chrome/80.0.3987.119 Mobile Safari/537.36 [FB_IAB/FB4A;FBAV/260.0.0.42.118;]"


[root@optimus ~]# cat /home/wap/logs/access.2020-03-27.log | grep "14:39:36" | 
grep " 400 "
179.7.51.190 51731 -1 [27/Mar/2020:14:39:36 -0300] "-" 400 - "-" "-"
186.11.20.40 25735 -1 [27/Mar/2020:14:39:36 -0300] "-" 400 - "-" "-"
- -1 443 [27/Mar/2020:14:39:36 -0300] "GET 
/cl/es/subscriptionPlanDetail.do?id=4120&patch=false&pbid=2131&ceid=17450&opd=false&wc=45663&trk=true&atil=380011499904&btil=&ctil=mobileapp%3A%3A2-com.appstar.callrecorder&gclid=EAIaIQobChMI-aa0_8uN6AIVZga5Bh1UBwQ5EAEYASAAEgKAxPD_BwE&entel_cl_smd_ok=32320413&c=32320413&sig=705b26c82e98b8401b74a463a68180d6&cts=1584044911681&conntype=CELLULAR&connspeed=EFFECTIVE_4G&noshim=true
 HTTP/2.0" 400 637 
"https://wap.renxo.com/cl/es/subscriptionPlanDetail.do?id=4120&patch=false&pbid=2131&ceid=17450&opd=false&wc=45663&trk=true&atil=380011499904&btil=&ctil=mobileapp%3A%3A2-com.appstar.callrecorder&gclid=EAIaIQobChMI-aa0_8uN6AIVZga5Bh1UBwQ5EAEYASAAEgKAxPD_BwE&entel_cl_smd_ok=32320413&c=32320413&sig=705b26c82e98b8401b74a463a68180d6&cts=1584044911681&conntype=CELLULAR&connspeed=EFFECTIVE_4G";
 "Mozilla/5.0 (Linux; Android 8.1.0; SAMSUNG SM-J710MN Build/M1AJQ) 
AppleWebKit/537.36 (KHTML, like Gecko) SamsungBrowser/9.4 Chrome/67.0.3396.87 
Mobile Safari/537.36"
177.25.212.73 61112 -1 [27/Mar/2020:14:39:36 -0300] "-" 400 - "-" "-"


[root@optimus ~]# cat /home/wap/logs/access.2020-03-27.log | grep "17:18:55" | 
grep " 400 "
- -1 443 [27/Mar/2020:17:18:55 -0300] "GET 
/ar/es/subscriptionPlanDetail.do?id=4328&ceid=16242&pbid=2403&wc=48008&trk=true&atil=409370554249&btil=%2Farts%20%26%20entertainment&ctil=cuttsite.website&dtil=d&gclid=EAIaIQobChMI98zj67y76AIVT4p3Ch3riAVXEAEYASAAEgLGavD_BwE
 HTTP/2.0" 400 637 
"https://googleads.g.doubleclick.net/pagead/ads?client=ca-pub-2929318494915332&output=html&h=250&slotname=4353673900&adk=3696358127&adf=3108995893&w=300&lmt=1585340298&psa=1&guci=2.2.0.0.2.2.0.0&format=300x250&url=https%3A%2F%2Fcuttsite.website%2Fpica-3-limones-con-sal-encima-ponlo-cerca-de-tu-cama-y-veras-lo-que-pasa-en-los-proximos-15-minutos%2F&flash=0&wgl=1&dt=1585340297517&bpp=36&bdt=2610&idt=526&shv=r20200324&cbv=r20190131&ptt=9&saldr=aa&abxe=1&cookie=ID%3D7489a82afd59cfe7%3AT%3D1580676408%3AS%3DALNI_MbJWniZS34uo5D_IKexygyl9kHRXg&crv=1&prev_fmts=360x300&correlator=3721745222895&frm=20&pv=1&ga_vid=662555076.1580676587&ga_sid=1585340298&ga_hid=1508954517&ga_fc=0&iag=0&icsg=2392605966663664&dssz=43&mdo=0&mso=0&u_tz=-180&u_his=1&u_java=0&u_h=640&u_w=360&u_ah=640&u_aw=360&u_cd=24&u_nplug=0&u_nmime=0&adx=30&ady=1051&biw=360&bih=532&scr_x=0&scr_y=378&eid=21065713%2C21065715%2C44713364%2C633794031%2C410075105&oid=3&pvsid=2071045736628243&pem=677&ref=http%3A%2F%2Fm.facebook.com%2F&rx=0&eae=0&fc=896&brdim=0%2C0%2C0%2C0%2C360%2C0%2C360%2C532%2C360%2C532&vis=1&rsz=%7C%7CeEbr%7C&abl=CS&pfx=0&fu=8208&bc=31&ifi=2&uci=a!2&btvi=1&fsb=1&xpc=rweh5fjEx7&p=https%3A//cuttsite.website&dtd=565";
 "Mozilla/5.0 (Linux; Android 6.0; CAM-L03 Build/HUAWEICAM-L03; wv) 
AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/80.0.3987.132 Mobile 
Safari/537.36 [FB_IAB/FB4A;FBAV/260.0.0.42.118;]"


[root@optimus ~]# cat /home/wap/logs/access.2020-03-27.log | grep "20:55:48" | 
grep " 400 "
- -1 443 [27/Mar/2020:20:55:48 -0300] "GET 
/cl/es/subscriptionPlanDetail.do?id=4120&patch=false&pbid=2194&ceid=15401&opd=false&wc=48047&trk=true&entel_cl_smd_ok=75206403&c=75206403&sig=5f5c2883295aacb30dcd92463100b43d&cts=1585353323195&conntype=CELLULAR&connspeed=EFFECTIVE_4G
 HTTP/2.0" 400 637 "http://m.facebook.com/"; "Mozilla/5.0 (Linux; Android 8.0.0; 
LDN-LX3 Build/HUAWEILDN-LX3; wv) AppleWebKit/537.36 (KHTML, like Gecko) 
Version/4.0 Chrome/77.0.3865.116 Mobile Safari/537.36 
[FB_IAB/FB4A;FBAV/262.0.0.34.117;]"


[root@optimus ~]# cat /home/wap/logs/access.2020-03-27.log | grep "22:39:10" | 
grep " 400 "
- -1 443 [27/Mar/2020:22:39:10 -0300] "GET 
/pe/es/subscriptionPlanDetail.do?id=4479&patch=false&pbid=2243&wc=46576&trk=true&atil=356198758492&btil=&ctil=www.notifresh.com&dtil=d&gclid=EAIaIQobChMI7ujVsoS86AIVTiPTCh1X7wrSEAEYASAAEgJE0_D_BwE
 HTTP/2.0" 400 637 
"https://googleads.g.doubleclick.net/pagead/ads?client=ca-pub-3136901199458158&output=html&h=300&slotname=3392932137&adk=1348254223&adf=54630664&w=360&lmt=1585363062&rafmt=1&armr=1&psa=1&guci=2.2.0.0.2.2.0.0&format=360x300&url=https%3A%2F%2Fwww.notifresh.com%2Fshare%2Fvideos%2FovU95w%2F&flash=0&fwr=1&rs=1&rh=280&rw=336&rpe=1&resp_fmts=3&sfro=1&wgl=1&dt=1585363062186&bpp=50&bdt=190&fdt=371&idt=372&shv=r20200324&cbv=r20190131&ptt=9&saldr=aa&abxe=1&correlator=3166985023535&frm=20&pv=2&ga_vid=1799828056.1585363062&ga_sid=1585363063&ga_hid=162526082&ga_fc=0&iag=0&icsg=33595567&dssz=25&mdo=0&mso=0&u_tz=-360&u_his=2&u_java=0&u_h=780&u_w=360&u_ah=780&u_aw=360&u_cd=24&u_nplug=0&u_nmime=0&adx=0&ady=75&biw=360&bih=665&scr_x=0&scr_y=0&eid=44713363&oid=3&pvsid=3334872409361851&pem=595&ref=http%3A%2F%2Fm.facebook.com%2F&rx=0&eae=0&fc=900&brdim=0%2C0%2C0%2C0%2C360%2C0%2C360%2C665%2C360%2C665&vis=1&rsz=%7C%7CeE%7C&abl=CS&pfx=0&fu=144&bc=31&ifi=1&uci=a!1&fsb=1&xpc=x6EFawm1tV&p=https%3A//www.notifresh.com&dtd=419";
 "Mozilla/5.0 (Linux; Android 9; POT-LX3 Build/HUAWEIPOT-L03; wv) 
AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/74.0.3729.157 Mobile 
Safari/537.36 [FB_IAB/FB4A;FBAV/224.0.0.33.114;]"


[root@optimus ~]# cat /home/wap/logs/access.2020-03-27.log | grep "23:14:05" | 
grep " 400 "
179.7.136.177 25289 -1 [27/Mar/2020:23:14:05 -0300] "-" 400 - "-" "-"
- -1 443 [27/Mar/2020:23:14:05 -0300] "GET 
/pe/es/subscriptionPlanDetail.do?id=4479&patch=false&pbid=2138&wc=46540&trk=true&trk=true&atil=353985833412&btil=%2Farts%20%26%20entertainment%2Ftv%20%26%20video&ctil=www.youtube.com&dtil=d&gclid=EAIaIQobChMIq-mIh4y86AIV1lQBCh02sw-9EAEYASAAEgKgn_D_BwE
 HTTP/2.0" 400 637 "-" "Mozilla/5.0 (Linux; Android 6.0.1; SAMSUNG SM-G532M 
Build/MMB29T) AppleWebKit/537.36 (KHTML, like Gecko) SamsungBrowser/8.2 
Chrome/63.0.3239.111 Mobile Safari/537.36"

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

Reply via email to