May 272016
 

I’ve got a small Java based web project I’ve been running for the last year or so out on the InterTubes, and I’ve noticed in the logs error messages like this1

Apr 15, 2016 10:44:21 PM org.apache.coyote.http11.AbstractHttp11Processor process
INFO: Error parsing HTTP request header
Note: further occurrences of HTTP header parsing errors will be logged at DEBUG level.
java.lang.IllegalArgumentException: Invalid character (CR or LF) found in method name
at org.apache.coyote.http11.AbstractNioInputBuffer.parseRequestLine(AbstractNioInputBuffer.java:228)
at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1009)
at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:672)
at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1500)
at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:1456)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
at java.lang.Thread.run(Thread.java:745)

It wasn’t something being generated from within my code, and it wasn’t me doing testing (breaking) my code.

I went through my tomcat logs and could see no pattern to the dates or times it was happening

  • Mar 21, 2016 11:45:26 PM
  • Mar 22, 2016 8:43:27 PM
  • Mar 25, 2016 10:36:47 PM
  • Mar 26, 2016 7:18:18 PM
  • Mar 31, 2016 9:02:48 PM
  • Apr 03, 2016 7:10:14 AM
  • Apr 04, 2016 10:04:24 PM
  • Apr 05, 2016 8:16:45 PM
  • Apr 13, 2016 10:51:10 PM
  • Apr 15, 2016 10:44:21 PM

I next went to my access logs and found one of the entries

169.229.3.91 - - [15/Apr/2016:22:44:21 +1000] "-" 400 - "-" "-" null

Broken down, we can see the call was made from the IP address 169.229.3.91 and the URL they were trying to access was “-” with a 400 error response.

Huh?

So, looking looking up the IP address we find it maps to researchscan1.eecs.berkeley.edu.

$ dig -x 169.229.3.91

; <<>> DiG 9.9.5-11ubuntu1.3-Ubuntu <<>> -x 169.229.3.91
 ;; global options: +cmd
 ;; Got answer:
 ;; ->>HEADER< ;; flags: qr rd ra; QUERY: 1, ANSWER: 1, AUTHORITY: 0, ADDITIONAL: 1

;; OPT PSEUDOSECTION:
 ; EDNS: version: 0, flags:; udp: 4000
 ;; QUESTION SECTION:
 ;91.3.229.169.in-addr.arpa. IN PTR

;; ANSWER SECTION:
 91.3.229.169.in-addr.arpa. 51389 IN PTR researchscan1.eecs.berkeley.edu.

;; Query time: 5 msec
 ;; SERVER: 127.0.0.1#53(127.0.0.1)
 ;; WHEN: Mon May 23 15:49:25 AEST 2016
 ;; MSG SIZE rcvd: 99

Checking this to see if there’s a website we get the message

researchscan1.eecs.berkeley.edu

There are 5 machines doing the scanning

  1. http://researchscan0.eecs.berkeley.edu/
  2. http://researchscan1.eecs.berkeley.edu/
  3. http://researchscan2.eecs.berkeley.edu/
  4. http://researchscan3.eecs.berkeley.edu/
  5. http://researchscan4.eecs.berkeley.edu/

I emailed them and the errors have (mostly) stopped appearing in the logs.

Such is life.

1. I should point out, although this blog makes it look like I awesomely solved this in 15 minutes, it took a few weeks on and off and some deep Googling and Stack Overflow work to find the answer.
And thanks for where I work, I get to share this Confluence log has java.lang.IllegalArgumentException: Invalid character (CR or LF) found in method name.

 Tagged with: