1

I am using Tomcat 6 and I just noticed a weird thing - right after it starts, it loads my Login.jsp page. In my opinion, it should have no reason to do so, and googling this issue I found nothing. Any help would be appreciated.

Clues & Notes:

  • The reason it's Login.jsp and not something else is most probably that my web.xml lists it as the only <welcome-file>Login.jsp</welcome-file>.

  • If I print the stack trace in Login.jsp, I get this:

    java.lang.Exception
at org.apache.jsp.Login_jsp._jspService(Login_jsp.java:64)
at org.apache.jasper.runtime.HttpJspBase.service(HttpJspBase.java:70)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
at org.apache.jasper.servlet.JspServletWrapper.service(JspServletWrapper.java:388)
at org.apache.jasper.servlet.JspServlet.serviceJspFile(JspServlet.java:313)
at org.apache.jasper.servlet.JspServlet.service(JspServlet.java:260)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
at com.mycompany.StartupFilter.doFilter(StartupFilter.java:33)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:293)
at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:859)
at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:602)
at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:489)
at java.lang.Thread.run(Thread.java:722)

  • You will notice there is a custom StartupFilter, but it should probably not be the cause. So far, this looks just like any other web page load caused for example by a browser.

  • Let's examine the request that caused this: remoteAddr and remoteHost is 127.0.0.1. remotePort is -1, which is really weird. There are no parameters in the request. (Anything else I should be focusing on here?)
  • I have some scheduled threads running in the background, but they are not touching the JSP front-end.

  • Log of the start looks like this:

    Nov 07, 2013 6:45:17 PM org.apache.catalina.core.AprLifecycleListener init
INFO: The APR based Apache Tomcat Native library which allows optimal performance in production environments was not found on the java.library.path: /Users/vektor/Library/Java/Extensions:/Library/Java/Extensions:/Network/Library/Java/Extensions:/System/Library/Java/Extensions:/usr/lib/java:.
Nov 07, 2013 6:45:17 PM org.apache.tomcat.util.digester.SetPropertiesRule begin
WARNING: [SetPropertiesRule]{Server/Service/Engine/Host/Context} Setting property 'source' to 'org.eclipse.jst.jee.server:RealPadWeb' did not find a matching property.
Nov 07, 2013 6:45:17 PM org.apache.coyote.http11.Http11Protocol init
INFO: Initializing Coyote HTTP/1.1 on http-8080
Nov 07, 2013 6:45:18 PM org.apache.coyote.http11.Http11Protocol init
INFO: Initializing Coyote HTTP/1.1 on http-8443
Nov 07, 2013 6:45:18 PM org.apache.catalina.startup.Catalina load
INFO: Initialization processed in 931 ms
Nov 07, 2013 6:45:18 PM org.apache.catalina.core.StandardService start
INFO: Starting service Catalina
Nov 07, 2013 6:45:18 PM org.apache.catalina.core.StandardEngine start
INFO: Starting Servlet Engine: Apache Tomcat/6.0.35
Nov 07, 2013 6:45:19 PM org.apache.coyote.http11.Http11Protocol start
INFO: Starting Coyote HTTP/1.1 on http-8080
Nov 07, 2013 6:45:19 PM org.apache.coyote.http11.Http11Protocol start
INFO: Starting Coyote HTTP/1.1 on http-8443
Nov 07, 2013 6:45:19 PM org.apache.jk.common.ChannelSocket init
INFO: JK: ajp13 listening on /0.0.0.0:8009
Nov 07, 2013 6:45:19 PM org.apache.jk.server.JkMain start
INFO: Jk running ID=0 time=0/18  config=null
Nov 07, 2013 6:45:19 PM org.apache.catalina.startup.Catalina start
INFO: Server startup in 1622 ms
<here I found logged my System.out.println() I put in Login.jsp>

  • When I turn on the Access Log Valve, I get this line: 127.0.0.1 - - [07/Nov/2013:19:01:54 +0100] "GET / HTTP/1.1" 200 5136

  • I am using a HTTPS Connector on port 8443 that redirects to the usual 8080.
  • I tried shutting down Chrome, didn't help (a weird plugin could have been touching recently visited servers or so).
  • I am starting the server from Eclipse Juno.

This is as far as I got. Any help would be much appreciated. If you need to see any other configuration files, just let me know!

Under the fold: details

  • OS X 10.8.5 (could it be the firewall?)
  • Java 1.6.0.35
  • Tomcat 6.0.35
  • The project uses AspectJ, logging is done via Log4J 2 beta cca 9 (could it be a logging daemon thread?)
vektor
  • 3,312
  • 8
  • 41
  • 71
  • 1
    It seems an actual request, maybe it was made from your own app or the tomcat itself. Try this to gather more information http://stackoverflow.com/questions/3017188/java-tomcat-standalone-how-to-log-access-all-the-http-get-requests – aalku Nov 07 '13 at 17:54
  • Good point, I added the logged line to the question text. – vektor Nov 07 '13 at 18:02
  • How are you starting Tomcat? Does your start script send a request to check it has started maybe? – serg10 Nov 07 '13 at 18:23
  • I would suggest go to 'Login_jsp.java' at line 64 and see why it throws exception. Try to figure out what could be the cause for exception. You can see that jsp translated java file under tomcat 'work' directory. And I really believe listen and understand exception and please you should have an extra look into 'com.mycompany.StartupFilter'. – Jayasagar Nov 07 '13 at 18:25
  • @serg10 I start it from Eclipse, good point, added. – vektor Nov 07 '13 at 18:54
  • @Jayasagar: the exception is there on purpose, just to see the trace. The behavior is exactly the same without it. – vektor Nov 07 '13 at 18:55

2 Answers2

2

Tomcat doesn't do that. Eclipse's Tomcat plugin does that. After Tomcat claims to be successfully started, the Eclipse Tomcat plugin fires a request on / in order to check if that is true. As you've apparently your web application deployed on context root /, its <welcome-file> will implicitly be opened. Note thus that this doesn't happen when your web application is deployed on a fixed context path.

Ignore it. This is completely harmless. Also, this doesn't happen in real production (of course, I assume that the production server doesn't ignorantly use Eclipse solely to start the Tomcat server instance).

BalusC
  • 1,082,665
  • 372
  • 3,610
  • 3,555
  • I have just verified on my production system that this is the case - the request was not received there. Thanks a lot! Could you perhaps link a resource detailing what the Tomcat Plugin does? – vektor Nov 07 '13 at 19:15
  • You're welcome. Sorry, no link. I'm just answering from own experience a couple of years ago and observations in plugin's source code. – BalusC Nov 07 '13 at 19:16
1

Maybe you can set a breakpoint to pause the thread attending the request and use netstat command or other tools to see where does it come from. In case it is from the same process you should suspend the whole JVM and find out what thread is making the request and why.

aalku
  • 2,860
  • 2
  • 23
  • 44
  • Huh. Good point, but for some reason I don't see my Tomcat listening in `sudo netstat`. It should be on 8443 - and nothing is there. – vektor Nov 07 '13 at 18:14
  • @vektor "netstat -l -n" (listening) or "netstat -a -n" (all) – aalku Nov 07 '13 at 22:21