search

google-code-export / lusca-cache

Automatically exported from code.google.com/p/lusca-cache
0 stars 0 forks source link

tlv_unpack and ufs_rebuild, probably buffer size wrong? #77

Open GoogleCodeExporter opened 9 years ago

GoogleCodeExporter commented 9 years ago 
in ufs_build_dir.c we have 
#define>BUFSIZE><------>1024
after i change it to
#define>BUFSIZE><------>4096

I almost don't have 
2009/11/13 07:29:35| tlv_unpack: unable to unpack: passed buffer size 1024
bytes; TLV length 1149 bytes; header prefix size 5 bytes
2009/11/13 07:29:35| tlv_unpack: unable to unpack: passed buffer size 1024
bytes; TLV length 2075 bytes; header prefix size 5 bytes

Probably BUFSIZE 1024 just not enough?

Original issue reported on code.google.com by nuclear...@gmail.com on 13 Nov 2009 at 2:32

GoogleCodeExporter commented 9 years ago 
Probably even need more sometimes?
2009/11/13 05:05:58| Store rebuilding is  9.3% complete
2009/11/13 05:06:34| tlv_unpack: unable to unpack: passed buffer size 4096 
bytes; TLV
length 4103 bytes; header prefix size 5 bytes
2009/11/13 05:06:37| Store rebuilding is  9.5% complete
2009/11/13 05:07:19| Store rebuilding is  9.6% complete
2009/11/13 05:07:41| Store rebuilding is  9.7% complete
2009/11/13 05:07:59| Store rebuilding is  9.8% complete
2009/11/13 05:08:34| Store rebuilding is  9.8% complete
2009/11/13 05:09:02| tlv_unpack: unable to unpack: passed buffer size 4096 
bytes; TLV
length 4287 bytes; header prefix size 5 bytes
2009/11/13 05:09:23| Store rebuilding is 10.0% complete
2009/11/13 05:10:06| Store rebuilding is 10.1% complete
2009/11/13 05:10:23| tlv_unpack: unable to unpack: passed buffer size 4096 
bytes; TLV
length 4397 bytes; header prefix size 5 bytes
2009/11/13 05:10:46| Store rebuilding is 10.2% complete
2009/11/13 05:10:56| tlv_unpack: unable to unpack: passed buffer size 4096 
bytes; TLV
length 4434 bytes; header prefix size 5 bytes

Original comment by nuclear...@gmail.com on 13 Nov 2009 at 3:28

GoogleCodeExporter commented 9 years ago 
Its screwing up somehow either writing the TLV data out, or reading it back on 
startup.

It could be something insane such as a really, insanely long URL in the TLV. 
I'd have to add some further 
debugging to spit out the TLV fields in the log.

Original comment by adrian.c...@gmail.com on 13 Nov 2009 at 3:37

GoogleCodeExporter commented 9 years ago 
Probably just interesting information.
While i try to rebuild metadata file (forcibly deleted, cause was corrupted) 
here is
seek pattern. First directory contains a lot of very small files (around 
500000),
others - larger file. It is same HDD. I use blktrace + seekwatcher. 

trace.png - small (1024) size reads. 
trace2.png i kill other 2 ufs_rebuild used for larger files.

with 4096 byte size
trace3.png
trace4.png 

Rebuild process was extremely slow, but seems mostly because of HDD performance
limitation. Maybe i should use COSS. Or maybe on first opendir/readdir we can 
build
array with block map, sort it, and reorganize seeks to be more linear.

This is not bug report, just maybe will be interesting.

Also at the end ufs_rebuild crashed, i will try to generate core dump, and to 
get
backtrace (if i will be able to do so).

Original comment by nuclear...@gmail.com on 13 Nov 2009 at 3:35

Attachments:

GoogleCodeExporter commented 9 years ago 
I did some debug for my case, take a look please:

2009/11/19 03:12:14| tlv_unpack: excessive len in tlv_add (len=1069) value is
(http://g.ceipmsn.com/8SE/41?MI=7DDF3B3A3E644E64B255B6B544F13175-1&LV=1.2.123.0&
OS=5.1.2600&AG=430&TE=1&TV=sv1.2.123.0%7ctl100%7cbvI8.0%7calen-us%7chaW%7cco0%7c
ci5B9CBE4D%7crf1%7cts20091119031125312%7ctz-120%7csq114%7cwi2804%7crw2804%7ceuht
tp%3A%2F%2Fgoogleads.g.doubleclick.net%2Fpagead%2Fads%3fclient%3dca-pub-71998293
29352938%26format%3d125x125_as%26output%3dhtml%26h%3d125%26w%3d125%26lmt%3d12585
93084%26flash%3d10.0.22.87%26url%3dhttp%253A%252F%252Fwww.myhaircuts.com%252Fmed
ium-haircuts.shtml%26dt%3d1258593084125%26correlator%3d1258593084125%26frm%3d0%2
6ga_vid%3d1780265188.1258593084%26ga_sid%3d1258593084%26ga_hid%3d426099840%26ga_
fc%3d0%26u_tz%3d120%26u_his%3d21%26u_java%3d1%26u_h%3d864%26u_w%3d1152%26u_ah%3d
830%26u_aw%3d1152%26u_cd%3d32%26u_nplug%3d0%26u_nmime%3d0%26biw%3d1131%26bih%3d6
26%26ref%3dhttp%253A%252F%252Fwww.myhaircuts.com%252Flong-haircuts.shtml%26fu%3d
0%26ifi%3d1%26dtd%3d31%26xpc%3dRs4Tdpydpd%26p%3dhttp%253A%2F%2Fwww.myhaircuts.co
m%7ciuhttp%3A%2F%2Fwww2.glam.com%2Fapp%2Fsite%2Faffiliate%2FviewAffiliateModule.
act%3faffiliateId%3d104510419)!
2009/11/19 03:12:21| tlv_unpack: excessive len in tlv_add (len=1649) value is
(http://www.dellsupportcenter.com/global/data/manifest.zip?macid=%7b2898dc8f%2de
75e%2d4f41%2dac61%2dbdb8820ba9a8%7d&ip=%7bprivate%5fip%7d&pkey=All%20Clients%2cA
ll%20Supported%20LOBs%2cALS%5fF%2cAV%5fMcAfee%2cBadShareNames%2cBITS%5f25%2cBV%5
fA05%2cBV%5fA06%2cBV%5fA07%2cBV%5fA08%2cBV%5fA09%2cBV%5fA10%2cBV%5fA11%2cBV%5fA1
3%2cBV%5fA15%2cBV%5fA16%2cBV%5fA32%2cBV%5fA38%2cC%5fUS%2ccram%5fn%5fex%2cD%5fPC%
5fFax%5fF%2cDataSafeInactive%2cDDS%5f3%5fF%2cDDS%5fF%2cDNA%5fF%2cDot%20Net%202%2
0or%20above%2cDPC%5fT%2cDPI%20Change%2cDSC%5fARP%5f2108100%5fHigher%2cDSC%5fARP%
5f2208298%2cDSCPF22%2cDST%5fUpdate%2cDVD%5fT%2cFlsh9d%5fm%2cIE8%5fT%2cIE%5fFS%5f
small%2cIECU%5f889293%2cIECU%5f937143%2cInspiron%5f1501%5fATI%5fVideo%5fDriver%5
fVista%2cInspiron%5f1501%5fATI%5fVideo%5fDriver%5fXP%2cL%5fEN%2cLD%5fLowSpc%5fC%
2cLOB%5fStudio%5fAll%2cMan%5fF%2cMan%5fPcRecv%5fF%2cMSI31U%2cMSO%5f2003%2cMSO%5f
2007%2cNewCustomer%5f60%5fF%2cNon%2dRetail%2cNonRetail%5fwu119%2cNV%208700M%2cOS
%5fVis%2cOS%5fVisHmP%2cOSA%5f32%2dBit%2cPccClient%2cPCCWeb%5fOS%5fVis%2cPCCWeb%5
fOS%5fVis%5fF%2cPCCWeb%5fOS%5fXP%2cPCCWeb%5fOS%5fXP%5fS1%2cPCCWeb%5fOS%5fXP%5fS2
%2cPCCWeb%5fXP%5fno%5fSPs%2cPCTuneUp%5fNot%5fEx%2cPF%5fexists%2cPortableChassis%
2cPrc%5fFam%5fg5%2cPrn%5fDefNotLoc%2cQS%5fT%2cR%5fUS%2cRAM%5f2GB%2cScrnSvr%5fD%2
cSec%5fMcAfeeSecCntr%5fT%2cStudio%5f1535%5fIDT%5fSound%5fDriver%2cStudio%5f1537%
2cSysRest%5fD%2cTmpFoldFiles%2cUAD%5f936357%2cUAD%5fNVIDIA%5fMass%5fStorage%5fDr
iver%2cUAD%5fWinUpScanAuto%5fF%2cVC%5fNGG7400%5fPon%2cVC%5fResHigh%2cVR%5fLD%2cV
R%5fProc%2cWar%5fExp%2cWow6432%5fEx%2cwrc%5ff&u=%7bprivate%5fsystem%5fuser%7d&nb
=%7bprivate%5fmachine%5fname%7d&ver=2%2e2%2e08298)!
2009/11/19 03:12:22| clientTryParseRequest: FD 1842 (172.16.71.3:2955) Invalid 
Request
2009/11/19 03:12:32| squidaio_queue_request: WARNING - Queue congestion
2009/11/19 03:12:34| clientTryParseRequest: FD 1790 (172.16.191.179:24548) 
Invalid
Request
2009/11/19 03:12:34| httpAppendBody: Request not yet fully sent "POST
http://194.146.153.114:8080/update.php"
2009/11/19 03:12:42| tlv_unpack: excessive len in tlv_add (len=1038) value is
(http://www.blinkx.com/f2/player.swf?&cfg=%26autoplay%3D0%26playlistbutton%3Dtru
e%26e%3DHOS1ik9HFEBPAR5NKB2JBPNrDXIMSsOXZYqac_gHE2Mqe7GZgzl9iokwXDLpMZHDMkipx8la
TG1JIGGSNTqzAGZC9u3NsH-GyZwIvTsV_hSARrYYX2SnYJo7HkvATymmE56-7Us-4ODAbLkWB7SUaRae
7PThYx02JdxNUAOb3nYlniMmPcVLbWATsg6AbaiwnS2eMCFIxlitGzfjA3_Px9GPL3kUxX1R7BgvR1VG
cn75BgSTeBXAKvIbt0YKyYQ39u8TbsLG7S8S9HyZaHWpLZ4Np7HiNH_QSgljjOdW0ToBGY58P0sU6Hhw
BiRQHmJaghIxs53FIqhJ3bcX3WA8jzJP585ugNapCPcpaXjr99eUdIp1ujcLXLSvhj9Mn_yQoWpPpiER
wtq9BHGreWJ9r-_-nXMRSnQisKfmN2lIwH9ahTfxJTNjQQSJMsE1gVJxWlOATQLPKhrWUUOOsOuUU4yz
b0k37NwaiJ5Uf3IC6e7IiCZ7MwRRQ_RsaHRGP7vS_Ooi5P8rp60K8vmu-E_xupb93H92JG1md8y3X-Sx
hLvJ9QcWF6jeWzv9LP2Fnco6bFsPIo0n83pBysmDAtWSPPaaunKNk141gbsIWj_kJKPg8SzwgKRNf6OW
8_vgrb57u-G_tDYFewdTILzTzEP8iiTwt6lM4gzmr-HxoNv-uc6VHgd9SZxEYBr05kXgMdU55wimd-CH
yCesIjR34JFAooZ1JarFDIu3wO_EzJtGPIlKzGI1eY4oxODxuBVTKSCGQ59ESoezBe9-tofINKQmBr2a
OSxLNcq6a_UXRRd12fF8FAciTKRP6mpYATLhMkLGinf2tVebteWMzi8yzrnSE6hzTN0RcxffrgiWUNwx
N5w_HfASa1eyEs6WvtLIgHN9Vr_lGqy1l5GWH0wl_pbpQg-CKxWRYuaOM_--iNA4Hjr1ofgi7cr-OA)!
2009/11/19 03:12:42| httpAppendBody: Request not yet fully sent "POST
http://194.146.153.114:8080/update.php"
2009/11/19 03:12:42| httpAppendBody: Request not yet fully sent "POST
http://194.146.153.114:8080/update.php"
2009/11/19 03:12:42| httpAppendBody: Request not yet fully sent "POST
http://194.146.153.114:8080/update.php"
2009/11/19 03:12:45| tlv_unpack: excessive len in tlv_add (len=1037) value is
(http://cdn.mochiads.com/c/e29/ed426.swf?%63lickTAG=http%3A%2F%2Fx.mochiads.com%
2Fclk%2F1%2FMDbzj6sKKD4zBiqrzBOxmINQAAADr3icdVPLbtQwFDUdkCigUiE2iC66KWxKJnb8iBFR
KSBBBS1toSpCSJGfjZtMEo0znRZ2iAULVnwFGz6AP2DFmm9gzb5khs4UJJCta9_rc4_t-8g6Gsyqwqlc
i0ZocG68z65rMNerVOaE9umBM8NIdLKOBODsDwnOFwsSdN59ycG8hRBiBiNMORU6jFoTU4qEscBWKU4s
kRJcfPuxnAeZ__T6c2OWvn94dfPo67drEqxffTMWObgEOQkoD1AYB3EOZkwpj4-P3-czj7KmqW93u1YG
PVfq_apoAlX1Wr27J3omdbbfLsG-r1dG-mNzlGxvPtzaWN16ura78wDtrD-5YWXq3V7qyhN0AqemsZ7m
rRe1mCNkMSE0hhSKWGmLhUaIc0s1iiYuRaVEYRJTpjvP_mAuzTC1QhlZVfkpf-NGtyESEwI5ZgGDcEok
tDb6FFr3K-sKkw7qNg9m6gkRw4yTCcoc1q5vfBJODANv-gkMScggxXCK88Z7V5XjnxFFrMQWY80NY7Em
GMkwEuLWP9x8giKFhOUQQR1hzC0zsZCQRlxBBc1pHMxhk9am3_NJZW3hSpMKpdpbl9B90xOuaFcxaKq0
HsjC-SztG2XKpgU17sA1R9Mo1G78SCWwbKeKFechiSOqiGYWQ8poKEOJTvF16nRCWEhHVcfYycEof5FF
TMcWK8g0IpYKaBk2FglNMcvBnUkpFcJnf1eTb0Tj1O-T7vZmd43eQ89D-DLeCfzQrhwkbU3O7a5tLMJw
OVxGaDlu-S7sthTV0C--2MzBeRjG8SGFSIMrk765C8NgNDjPQQcFWAANLvusGm72TVEJbfqruu2oMz9b
MbMgZttGHJTa2DaY-n_7XySILbM%21&lc=_1258551964671_87860&gwidth=500&gheight=540)!

Sure it is wrong to cache any content with ? symbol, but... it works for my 
case and
most of URL's even with query symbol can be cached, if they have proper 
headers. And
it saves some bandwidth (it is extremely expensive here).

Please consider increasing buffer length :-)
Is there any standard for URI/URL length? Seems not. Maybe we can try 4096 as 
safe value?

Original comment by nuclear...@gmail.com on 19 Nov 2009 at 1:18

GoogleCodeExporter commented 9 years ago 
And sure i think good idea to not add to disk(?) cache excessively long values, 
that
won't be parsed later.

Original comment by nuclear...@gmail.com on 19 Nov 2009 at 1:24

GoogleCodeExporter commented 9 years ago 
That's interesting. So you're saying that the code is storing overly long URLs 
in there, and it's somehow messing 
up the rebuild process?

Ok. That is helpful. The TLV buffer should be big enough to store whatever 
MAXURL is. 1024 bytes is certainly 
not long enough.

As to why the content is being cached? That's a separate story, one which you 
can investigate yourself.

Original comment by adrian.c...@gmail.com on 19 Jan 2010 at 9:41

GoogleCodeExporter commented 9 years ago 
No, i am not worried why it is cached, just explaining, that it is ok for me, 
when
content with such long URL is cached.

Original comment by nuclear...@gmail.com on 19 Jan 2010 at 10:57

GoogleCodeExporter commented 9 years ago 
The TLV bug isn't easily fixable with a small patch.

The problem is this: storeClientFileRead() uses the passed in buffer from the 
store client copy (ie, 4k) to read in 
the metadata and then will overwrite the metadata with the first set of object 
reply data.

The solution to this will be to use a temporary larger buffer to read in the 
metadata (say, 16k) so it can read in 
everything needed; then free this buffer once the read has completed.

Original comment by adrian.c...@gmail.com on 10 Feb 2010 at 12:01

GoogleCodeExporter commented 9 years ago 
In the short short term, I'm going to commit the ufs_build_dir.c patch. This 
mostly
brings the store metadata reading to parity; the problem now is that overly 
large
items are being read out that can't be re-read on swapin/rebuild.

Original comment by adrian.c...@gmail.com on 29 Mar 2010 at 12:43