[Rabbit-dev] Logging Usage
Luis Soltero
lsoltero at globalmarinenet.com
Fri Aug 19 09:01:02 CEST 2011
hi Robo,
one more thing... i just looked through the proxy logs for our 4.9 and 4.8 servers and I am not seeing this type of
error on them. So... it seems that these malformed header errors are an artifact of some change made in 4.10 or 4.11.
Any idea what might be causing this? they happen pretty regularly.
Thanks,
--luis
On 8/19/11 2:48 AM, Luis Soltero wrote:
>
> Hi Robo,
>
> what causes urls to get truncated as follows? They generate errors like
>
> Aug 19, 2011 1:13:30 AM rabbit.proxy.ProxyLogger setup
> INFO: Log level set to: INFO
> Aug 19, 2011 1:13:31 AM rabbit.proxy.HttpProxy setConfig
> INFO: RabbIT proxy version 4.11: Configuration loaded: ready for action.
> Aug 19, 2011 1:15:52 AM rabbit.proxy.Connection handleFailedRequestRead
> INFO: Exception when reading request
> rabbit.httpio.BadHttpHeaderException: Malformed header:F%2526ot%253DA; s_ppv=100; rvisw=1; srvisw=new%3A1; rvism=1;
> srvism=new%3A1
> at rabbit.httpio.HttpHeaderParser.readHeader(HttpHeaderParser.java:176)
> at rabbit.httpio.HttpHeaderParser.lineRead(HttpHeaderParser.java:143)
> at rabbit.httpio.LineReader.readLine(LineReader.java:43)
> at rabbit.httpio.HttpHeaderParser.handleBuffer(HttpHeaderParser.java:60)
> at rabbit.httpio.HttpHeaderReader.parseBuffer(HttpHeaderReader.java:124)
> at rabbit.httpio.HttpHeaderReader.read(HttpHeaderReader.java:112)
> at org.khelekore.rnio.impl.ChannelOpsHandler.handleRead(ChannelOpsHandler.java:105)
> at org.khelekore.rnio.impl.ChannelOpsHandler.handle(ChannelOpsHandler.java:160)
> at org.khelekore.rnio.impl.SingleSelectorRunner.handleSelects(SingleSelectorRunner.java:350)
> at org.khelekore.rnio.impl.SingleSelectorRunner.run(SingleSelectorRunner.java:204)
> at java.lang.Thread.run(Thread.java:662)
> Aug 19, 2011 1:16:53 AM rabbit.filter.ProxyAuth getError
> WARNING: Bad url: HTTP/1.1
> java.net.MalformedURLException: no protocol: HTTP/1.1
> at java.net.URL.<init>(URL.java:567)
> at java.net.URL.<init>(URL.java:464)
> at java.net.URL.<init>(URL.java:413)
> at rabbit.filter.ProxyAuth.getError(ProxyAuth.java:96)
> at rabbit.filter.ProxyAuth.doHttpInFiltering(ProxyAuth.java:53)
>
>
> spider:/usr/local/RabbitDev/rabbit/logs # grep -v test access_log.0 | grep -v CONNECT
> 96.38.22.218 - - 19/Aug/2011:06:16:53 GMT "Fwww.cnn.com%2F2011%2FUS%2F08%2F18%2Fflashmobs.police%2Findex.html&ot=A&AQE=1
> HTTP/1.1" 400 357 [0, 120]
> 96.38.22.218 - - 19/Aug/2011:06:18:58 GMT
> "start%3A%20when%20flash%20mobs%20attack&pid=cnn%3Ac%3A%2F2011%2Fus%2F08%2F18%2Fflashmobs.police%2F&pidt=1&oid=%2Fvideo%2F%3F%2Fvideo%2Fus%2F2011%2F08%2F16%2Fjk.flashmobs.maryland.cnn&oidt=1&ot=A&oi=1&AQE=1
> HTTP/1.1" 400 357 [0, 127]
> 96.38.22.218 - - 19/Aug/2011:06:20:34 GMT
> "%20Plug-In%202%20for%20NPAPI%20Browsers%3B&pid=cnn%3Asf%3A%2Fworld%2F&pidt=1&oid=http%3A%2F%2Fwww.cnn.com%2F2011%2FWORLD%2Fasiapcf%2F08%2F18%2Fafghanistan.bombing%2Findex.html%3Fhpt%3Dwo_c2&ot=A&AQE=1
> HTTP/1.1" 400 357 [0, 163]
> 96.38.22.218 - - 19/Aug/2011:06:21:01 GMT
> "%207.6.6%3BSilverlight%20Plug-In%3BJava%20Plug-In%202%20for%20NPAPI%20Browsers%3B&pid=cnn%3Asf%3A%2Fjustice%2F&pidt=1&oid=http%3A%2F%2Fwww.cnn.com%2F2011%2FWORLD%2Famericas%2F08%2F18%2Faruba.missing.woman%2Findex.html%3Fhpt%3Dju_c2&ot=A&AQE=1
> HTTP/1.1" 400 357 [0, 228]
> 96.38.22.218 - - 19/Aug/2011:06:25:02 GMT
> "3A%2Fjustice%2F&pidt=1&oid=http%3A%2F%2Fwww.cnn.com%2F2011%2FCRIME%2F08%2F18%2Fflorida.jose.baez%2Findex.html%3Fhpt%3Dju_c2&ot=A&AQE=1
> HTTP/1.1" 400 357 [0, 263]
> 96.38.22.218 - - 19/Aug/2011:06:26:56 GMT
> ".usatoday.com%2Fmoney%2Findustries%2Ffood%2Fstory%2F2011%2F08%2FBurger-King-freshens-fast-food-image-kicks-King-to-the-curb%2F50046768%2F1&c25=usat&c28=2&v29=2%3A00AM&c33=undefined&c34=undefined&c38=false&c50=usatoday&c51=39&c52=usat%20%3A%2F&s=1920x1200&c=24&j=1.7&v=Y&k=Y&bw=1447&bh=1019&p=Picasa%3BWebEx64%20General%20Plugin%20Container%3BMicrosoft%20Office%20Live%20Plug-in%3BShockwave%20Flash%3BFlip4Mac%20Windows%20Media%20Plugin%202.3.8%20%3BGoogle%20Earth%20Plug-in%3BQuickTime%20Plug-in%207.6.6%3BSilverlight%20Plug-In%3BJava%20Plug-In%202%20for%20NPAPI%20Browsers%3B&pid=usat%20%3A%2F&pidt=1&oid=usat_lede_well_b%7Clede-right-3pack-thumbs%7Cheadline%7C1&oidt=1&ot=A&oi=1&AQE=1
> HTTP/1.1" 400 357 [0, 316]
> 96.38.22.218 - - 19/Aug/2011:06:29:02 GMT
> "1.7&v=Y&k=Y&bw=1447&bh=1019&p=Picasa%3BWebEx64%20General%20Plugin%20Container%3BMicrosoft%20Office%20Live%20Plug-in%3BShockwave%20Flash%3BFlip4Mac%20Windows%20Media%20Plugin%202.3.8%20%3BGoogle%20Earth%20Plug-in%3BQuickTime%20Plug-in%207.6.6%3BSilverlight%20Plug-In%3BJava%20Plug-In%202%20for%20NPAPI%20Browsers%3B&pid=usat%20%3A%2F&pidt=1&oid=usat_lede_well_b%7Clede-right-3pack-thumbs%7Cheadline%7C2&oidt=1&ot=A&oi=1&AQE=1
> HTTP/1.1" 400 357 [0, 415]
> 96.38.22.218 - - 19/Aug/2011:06:29:29 GMT
> "lunge-on-fears-about-Europes-impact-on-US-banks%2F50044450%2F1&v21=Signed%20Out&c23=www.usatoday.com%2Fmoney%2Findustries%2Fbanking%2Fstory%2F2011%2F08%2FMarkets-plunge-on-fears-about-Europes-impact-on-US-banks%2F50044450%2F1&c25=usat&c28=2&v29=2%3A00AM&c33=undefined&c34=undefined&c38=false&c50=usatoday&c51=22&c52=usat%20%3A%2Fmoney%2Feconomy%2Fstory%2F2011%2F08%2FFear-rises-on-jobs-housing-reports%2F50047110%2F1&s=1920x1200&c=24&j=1.7&v=Y&k=Y&bw=1447&bh=1019&p=Picasa%3BWebEx64%20General%20Plugin%20Container%3BMicrosoft%20Office%20Live%20Plug-in%3BShockwave%20Flash%3BFlip4Mac%20Windows%20Media%20Plugin%202.3.8%20%3BGoogle%20Earth%20Plug-in%3BQuickTime%20Plug-in%207.6.6%3BSilverlight%20Plug-In%3BJava%20Plug-In%202%20for%20NPAPI%20Browsers%3B&pid=usat%20%3A%2Fmoney%2Feconomy%2Fstory%2F2011%2F08%2FFear-rises-on-jobs-housing-reports%2F50047110%2F1&pidt=1&oid=http%3A%2F%2Fwww.usatoday.com%2Fmoney%2Findustries%2Fbanking%2Fstory%2F2011%2F08%2FMarkets-plunge-on-fears-about-Euro_1&oidt=1&ot=A&oi=1&AQE=1
> HTTP/1.1" 400 357 [0, 435]
> 96.38.22.218 - - 19/Aug/2011:06:37:42 GMT
> "5=D%3Dc42&s=1920x1200&c=24&j=1.7&v=Y&k=Y&bw=1447&bh=1019&p=Picasa%3BWebEx64%20General%20Plugin%20Container%3BMicrosoft%20Office%20Live%20Plug-in%3BShockwave%20Flash%3BFlip4Mac%20Windows%20Media%20Plugin%202.3.8%20%3BGoogle%20Earth%20Plug-in%3BQuickTime%20Plug-in%207.6.6%3BSilverlight%20Plug-In%3BJava%20Plug-In%202%20for%20NPAPI%20Browsers%3B&AQE=1
> HTTP/1.1" 400 357 [0, 899]
> 96.38.22.218 - - 19/Aug/2011:06:37:46 GMT
> "c41=galleries&c42=2011&v44=D%3Dc41&v45=D%3Dc42&s=1920x1200&c=24&j=1.7&v=Y&k=Y&bw=1447&bh=1019&p=Picasa%3BWebEx64%20General%20Plugin%20Container%3BMicrosoft%20Office%20Live%20Plug-in%3BShockwave%20Flash%3BFlip4Mac%20Windows%20Media%20Plugin%202.3.8%20%3BGoogle%20Earth%20Plug-in%3BQuickTime%20Plug-in%207.6.6%3BSilverlight%20Plug-In%3BJava%20Plug-In%202%20for%20NPAPI%20Browsers%3B&pid=mny%3Ao%3Amoney%3A%2Fgalleries%2F2011%2Fmoneymag%2F1108%2Fgallery.best_places_job_growth.moneymag%2F&pidt=1&oid=http%3A%2F%2Fmoney.cnn.com%2Fgalleries%2F2011%2Fmoneymag%2F1108%2Fgallery.best_places_job_growth.moneymag%2F2.html&ot=A&AQE=1
> HTTP/1.1" 400 357 [0, 922]
> 96.38.22.218 - - 19/Aug/2011:06:38:01 GMT "g%2F2.html&pidt=1&oid=http%3A%2F%2Fmoney.cnn.com%2Ftechnology%2F&ot=A&AQE=1
> HTTP/1.1" 400 357 [0, 946]
> 96.38.22.218 - - 19/Aug/2011:06:38:16 GMT
> "ey.cnn.com&c30=cnnmoney&v30=D%3Dc30&c32=adbp%3Acontent&v32=D%3Dc32&c33=adbp%3Aarticle%20read&v33=D%3Dc33&c34=anonymous&v34=D%3Dc34&c35=adbp-20110802-54%7Ccore-830%3A0&c40=2%3A30%7Cfriday%7Cweekday&v40=D%3Dc40&c41=2011&c42=08&v44=D%3Dc41&v45=D%3Dc42&s=1920x1200&c=24&j=1.7&v=Y&k=Y&bw=1447&bh=1019&p=Picasa%3BWebEx64%20General%20Plugin%20Container%3BMicrosoft%20Office%20Live%20Plug-in%3BShockwave%20Flash%3BFlip4Mac%20Windows%20Media%20Plugin%202.3.8%20%3BGoogle%20Earth%20Plug-in%3BQuickTime%20Plug-in%207.6.6%3BSilverlight%20Plug-In%3BJava%20Plug-In%202%20for%20NPAPI%20Browsers%3B&AQE=1
> HTTP/1.1" 400 357 [0, 970]
> 96.38.22.218 - - 19/Aug/2011:06:39:45 GMT
> "0%3BGoogle%20Earth%20Plug-in%3BQuickTime%20Plug-in%207.6.6%3BSilverlight%20Plug-In%3BJava%20Plug-In%202%20for%20NPAPI%20Browsers%3B&pid=mny%3Ac%3Amoney%3A%2F2011%2F08%2F18%2Ftechnology%2Fgoogle_motorola%2F&pidt=1&oid=http%3A%2F%2Fmoney.cnn.com%2F2011%2F08%2F16%2Ftechnology%2Fgoogle_motorola%2Findex.htm&ot=A&AQE=1
> HTTP/1.1" 400 357 [0, 1003]
> 96.38.22.218 - - 19/Aug/2011:06:39:52 GMT
> "&v=Y&k=Y&bw=1447&bh=1019&p=Picasa%3BWebEx64%20General%20Plugin%20Container%3BMicrosoft%20Office%20Live%20Plug-in%3BShockwave%20Flash%3BFlip4Mac%20Windows%20Media%20Plugin%202.3.8%20%3BGoogle%20Earth%20Plug-in%3BQuickTime%20Plug-in%207.6.6%3BSilverlight%20Plug-In%3BJava%20Plug-In%202%20for%20NPAPI%20Browsers%3B&pid=mny%3Ac%3Amoney%3A%2F2011%2F08%2F16%2Ftechnology%2Fgoogle_motorola%2F&pidt=1&oid=http%3A%2F%2Ftech.fortune.cnn.com%2F2011%2F08%2F18%2Fwall-streets-take-on-motorola-apple-up-google-down%2F&ot=A&AQE=1
> HTTP/1.1" 400 357 [0, 1029]
>
>
>
>
> On 8/19/11 1:44 AM, Luis Soltero wrote:
>> working!
>>
>> mysql> select * from proxy_stats;
>> +----------+-------------+--------------+--------------+---------------+---------------------+
>> | username | client_read | client_write | network_read | network_write | last_access |
>> +----------+-------------+--------------+--------------+---------------+---------------------+
>> | test | 56195 | 46204 | 37402 | 24746 | 2011-08-19 05:37:06 |
>> +----------+-------------+--------------+--------------+---------------+---------------------+
>> 1 row in set (0.00 sec)
>>
>> mysql> select * from proxy_stats;
>> +----------+-------------+--------------+--------------+---------------+---------------------+
>> | username | client_read | client_write | network_read | network_write | last_access |
>> +----------+-------------+--------------+--------------+---------------+---------------------+
>> | test | 104099 | 75218 | 56873 | 36219 | 2011-08-19 05:37:20 |
>> +----------+-------------+--------------+--------------+---------------+---------------------+
>> 1 row in set (0.00 sec)
>>
>> mysql> select * from proxy_stats;
>> +----------+-------------+--------------+--------------+---------------+---------------------+
>> | username | client_read | client_write | network_read | network_write | last_access |
>> +----------+-------------+--------------+--------------+---------------+---------------------+
>> | test | 189965 | 420265 | 933861 | 91495 | 2011-08-19 05:37:38 |
>> +----------+-------------+--------------+--------------+---------------+---------------------+
>> 1 row in set (0.00 sec)
>>
>> mysql> select * from proxy_stats;
>> +----------+-------------+--------------+--------------+---------------+---------------------+
>> | username | client_read | client_write | network_read | network_write | last_access |
>> +----------+-------------+--------------+--------------+---------------+---------------------+
>> | test | 346455 | 753148 | 1503840 | 179451 | 2011-08-19 05:38:48 |
>> +----------+-------------+--------------+--------------+---------------+---------------------+
>> 1 row in set (0.00 sec)
>>
>>
>> Can you tell me more about network_write/read? Is this just the raw network read/write that is caused by the requested
>> url? in otherwords... if there is a cache hit then the network traffic is very small. if there is a cache hit then there
>> is considerably more network traffic. Is there a way to tell the amount of data that was extracted from the cache? or
>> is this built into network_X some how?
>>
>> I look forward to your response.
>>
>> --luis
>>
>>
>> On 8/17/11 4:20 PM, Robert Olofsson wrote:
>>> On Wed, 17 Aug 2011 16:06:43 -0400
>>> Luis Soltero <lsoltero at globalmarinenet.com> wrote:
>>>
>>>> It sounds like writing our own logger is probably the best way to do that but I have no idea how. Would it be possible
>>>> to create a template that we could use as a starting point. In the end we will want to execute sql statements to update
>>>> table entries in the db.
>>> Take a look at the StandardOutTrafficLogger that I made, consider it a
>>> very basic template. You probably want to look at SQLBlockFilter to
>>> see how to handle the database connection.
>>>
>>> I thought about writing an example sql traffic logger, but I did not
>>> figure out what values would be good to log in the general case.
>>>
>>> /robo
>>>
>
--
Luis Soltero, Ph.D., MCS
Director of Software Development, CTO
Global Marine Networks, LLC
StarPilot, LLC
Tel: 865-379-8723
Fax: 865-681-5017
E-Mail: lsoltero at globalmarinenet.net
Web: http://www.globalmarinenet.net
Web: http://www.starpilotllc.com
More information about the Rabbit-dev
mailing list