[squid-users] Bug: Missing MemObject::storeId value

Yuri Voinov yvoinov at gmail.com
Tue May 31 16:23:52 UTC 2016 

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA256
 
This proxy uses as peer for downstreams?


31.05.2016 21:09, Heiler Bemerguy пишет:
>
>
> I disabled ICP requests to it and these "Bug: Missing
MemObject::storeId value" messages stopped... any thoughts?
>
> Known bug?
>
> --
> Best Regards,
>
> Heiler Bemerguy
> Network Manager - CINBESA
> 55 91 98151-4894/3184-1751
>
>
> Em 31/05/2016 11:49, Yuri escreveu:
>>
>> Hm. Seems related. The objects not the same in memory yet.
>>
>>
>> 31.05.2016 20:45, Heiler Bemerguy пишет:
>>>
>>>
>>> Yep I know it should/would vanish all those "Vary objects"
messages.. but what are these other "Bug: Missing MemObject::storeId
value" ?? I thought it was related...
>>>
>>> 2016/05/31 11:43:27.594 kid2| clientProcessHit: URL mismatch,
'[unknown_URI]' !=
'http://www.agenciabelem.com.br/Resize/CreateThumbnail?path=/multimidiaSGN/galeria/69379/69379_213524.jpg&maxHeight=61&maxWidth=91'
>>> 2016/05/31 11:43:28.492 kid2| clientProcessHit: URL mismatch,
'[unknown_URI]' !=
'http://www.agenciabelem.com.br/Resize/CreateThumbnail?path=/MultimidiaSGN/galeria/69395/69395_213686.jpg&maxHeight=225&maxWidth=136'
>>> 2016/05/31 11:43:46 kid1| Bug: Missing MemObject::storeId value
>>> 2016/05/31 11:43:46 kid1| mem_hdr: 0x3efe990 nodes.start() 0x19b79ef0
>>> 2016/05/31 11:43:46 kid1| mem_hdr: 0x3efe990 nodes.finish() 0x19b79ef0
>>> 2016/05/31 11:43:46 kid1| MemObject->start_ping: 0.000000
>>> 2016/05/31 11:43:46 kid1| MemObject->inmem_hi: 193
>>> 2016/05/31 11:43:46 kid1| MemObject->inmem_lo: 0
>>> 2016/05/31 11:43:46 kid1| MemObject->nclients: 0
>>> 2016/05/31 11:43:46 kid1| MemObject->reply: 0x45656e0
>>> 2016/05/31 11:43:46 kid1| MemObject->request: 0
>>> 2016/05/31 11:43:46 kid1| MemObject->logUri:
>>> 2016/05/31 11:43:46 kid1| MemObject->storeId:
>>> 2016/05/31 11:43:46.569 kid2| clientProcessHit: URL mismatch,
'[unknown_URI]' != 'http://captive.apple.com/hotspot-detect.html'
>>> 2016/05/31 11:43:52 kid2| Bug: Missing MemObject::storeId value
>>> 2016/05/31 11:43:52 kid2| mem_hdr: 0x24eafe0 nodes.start() 0x7cac320
>>> 2016/05/31 11:43:52 kid2| mem_hdr: 0x24eafe0 nodes.finish() 0x5385350
>>> 2016/05/31 11:43:52 kid2| MemObject->start_ping: 0.000000
>>> 2016/05/31 11:43:52 kid2| MemObject->inmem_hi: 10455
>>> 2016/05/31 11:43:52 kid2| MemObject->inmem_lo: 0
>>> 2016/05/31 11:43:52 kid2| MemObject->nclients: 0
>>> 2016/05/31 11:43:52 kid2| MemObject->reply: 0x2970910
>>> 2016/05/31 11:43:52 kid2| MemObject->request: 0
>>> 2016/05/31 11:43:52 kid2| MemObject->logUri:
>>> 2016/05/31 11:43:52 kid2| MemObject->storeId:
>>> 2016/05/31 11:43:52.364 kid2| clientProcessHit: URL mismatch,
'[unknown_URI]' !=
'http://cdn-00-default.nativex.com/asset/d4c6dac2-76fd-4f91-9254-9708b603f097.css'
>>> 2016/05/31 11:43:52.364 kid2| Bug: Missing MemObject::storeId value
>>> 2016/05/31 11:43:52.364 kid2| mem_hdr: 0x264c000 nodes.start() 0x311ee90
>>> 2016/05/31 11:43:52.364 kid2| mem_hdr: 0x264c000 nodes.finish()
0x6e46250
>>> 2016/05/31 11:43:52.364 kid2| MemObject->start_ping: 0.000000
>>> 2016/05/31 11:43:52.364 kid2| MemObject->inmem_hi: 12244
>>> 2016/05/31 11:43:52.364 kid2| MemObject->inmem_lo: 0
>>> 2016/05/31 11:43:52.364 kid2| MemObject->nclients: 0
>>> 2016/05/31 11:43:52.364 kid2| MemObject->reply: 0x2233a30
>>> 2016/05/31 11:43:52.364 kid2| MemObject->request: 0
>>> 2016/05/31 11:43:52.364 kid2| MemObject->logUri:
>>> 2016/05/31 11:43:52.364 kid2| MemObject->storeId:
>>> 2016/05/31 11:43:52.390 kid2| clientProcessHit: URL mismatch,
'[unknown_URI]' !=
'http://cdn-00-default.nativex.com/asset/7b4133df-f0c8-4f2d-8532-2dcf6915577b.js'
>>> 2016/05/31 11:43:52 kid3| Bug: Missing MemObject::storeId value
>>> 2016/05/31 11:43:52 kid3| mem_hdr: 0x2ac67f0 nodes.start() 0x3f5d410
>>> 2016/05/31 11:43:52 kid3| mem_hdr: 0x2ac67f0 nodes.finish() 0x1c71fc0
>>> 2016/05/31 11:43:52 kid3| MemObject->start_ping: 0.000000
>>> 2016/05/31 11:43:52 kid3| MemObject->inmem_hi: 95355
>>> 2016/05/31 11:43:52 kid3| MemObject->inmem_lo: 0
>>> 2016/05/31 11:43:52 kid3| MemObject->nclients: 0
>>> 2016/05/31 11:43:52 kid3| MemObject->reply: 0x2972cc0
>>> 2016/05/31 11:43:52 kid3| MemObject->request: 0
>>> 2016/05/31 11:43:52 kid3| MemObject->logUri:
>>> 2016/05/31 11:43:52 kid3| MemObject->storeId:
>>>
>>> --
>>> Best Regards,
>>>
>>> Heiler Bemerguy
>>> Network Manager - CINBESA
>>> 55 91 98151-4894/3184-1751
>>>
>>> Em 31/05/2016 11:39, Yuri escreveu:
>>>>
>>>> Bad test. Problem is with swapped onto disk objects exactly. So,
when we disable cache_dirs, problem is gone.
>>>>
>>>>
>>>> 31.05.2016 20:36, Heiler Bemerguy пишет:
>>>>>
>>>>>
>>>>> Just did a test here.
>>>>>
>>>>> Disabled every cache_dir and fully restarted squid 3.5.19
>>>>>
>>>>> No more "vary object loop", but these continues:
>>>>>
>>>>> 2016/05/31 11:35:13 kid2| Bug: Missing MemObject::storeId value
>>>>> 2016/05/31 11:35:13 kid2| mem_hdr: 0x3177f40 nodes.start() 0x7370880
>>>>> 2016/05/31 11:35:13 kid2| mem_hdr: 0x3177f40 nodes.finish() 0x7370880
>>>>> 2016/05/31 11:35:13 kid2| MemObject->start_ping: 0.000000
>>>>> 2016/05/31 11:35:13 kid2| MemObject->inmem_hi: 2224
>>>>> 2016/05/31 11:35:13 kid2| MemObject->inmem_lo: 0
>>>>> 2016/05/31 11:35:13 kid2| MemObject->nclients: 0
>>>>> 2016/05/31 11:35:13 kid2| MemObject->reply: 0x29711e0
>>>>> 2016/05/31 11:35:13 kid2| MemObject->request: 0
>>>>> 2016/05/31 11:35:13 kid2| MemObject->logUri:
>>>>> 2016/05/31 11:35:13 kid2| MemObject->storeId:
>>>>> 2016/05/31 11:35:14 kid1| Bug: Missing MemObject::storeId value
>>>>> 2016/05/31 11:35:14 kid1| mem_hdr: 0x3e0d990 nodes.start() 0x1ca70540
>>>>> 2016/05/31 11:35:14 kid1| mem_hdr: 0x3e0d990 nodes.finish() 0x1ca70540
>>>>> 2016/05/31 11:35:14 kid1| MemObject->start_ping: 0.000000
>>>>> 2016/05/31 11:35:14 kid1| MemObject->inmem_hi: 193
>>>>> 2016/05/31 11:35:14 kid1| MemObject->inmem_lo: 0
>>>>> 2016/05/31 11:35:14 kid1| MemObject->nclients: 0
>>>>> 2016/05/31 11:35:14 kid1| MemObject->reply: 0x45656e0
>>>>> 2016/05/31 11:35:14 kid1| MemObject->request: 0
>>>>> 2016/05/31 11:35:14 kid1| MemObject->logUri:
>>>>> 2016/05/31 11:35:14 kid1| MemObject->storeId:
>>>>> 2016/05/31 11:35:14.418 kid1| clientProcessHit: URL mismatch,
'[unknown_URI]' != 'http://captive.apple.com/hotspot-detect.html'
>>>>> 2016/05/31 11:35:14 kid2| Bug: Missing MemObject::storeId value
>>>>> 2016/05/31 11:35:14 kid2| mem_hdr: 0x336b090 nodes.start() 0x2b136d0
>>>>> 2016/05/31 11:35:14 kid2| mem_hdr: 0x336b090 nodes.finish() 0x82709c0
>>>>> 2016/05/31 11:35:14 kid2| MemObject->start_ping: 0.000000
>>>>> 2016/05/31 11:35:14 kid2| MemObject->inmem_hi: 4573
>>>>> 2016/05/31 11:35:14 kid2| MemObject->inmem_lo: 0
>>>>> 2016/05/31 11:35:14 kid2| MemObject->nclients: 0
>>>>> 2016/05/31 11:35:14 kid2| MemObject->reply: 0x26bdf50
>>>>> 2016/05/31 11:35:14 kid2| MemObject->request: 0
>>>>> 2016/05/31 11:35:14 kid2| MemObject->logUri:
>>>>> 2016/05/31 11:35:14 kid2| MemObject->storeId:
>>>>>
>>>>>
>>>>> --
>>>>> Best Regards,
>>>>>
>>>>> Heiler Bemerguy
>>>>> Network Manager - CINBESA
>>>>> 55 91 98151-4894/3184-1751
>>>>>
>>>>> Em 31/05/2016 11:14, Yuri escreveu:
>>>>>> Without collapsed_forwarding seems ok:
>>>>>>
>>>>>> https://i1.someimage.com/E8pM9tu.png
>>>>>>
>>>>>> no warnings/errors in cache.log.
>>>>>>
>>>>>> Seems Heiler right.
>>>>>>
>>>>>> 31.05.2016 19:33, joe пишет:
>>>>>>> load this link on both browser    chrome  and firefox
>>>>>>> 'http://js.statig.com.br/pub/adtags.js'
>>>>>>> keep clicking reload  on both browser  and look at your cache.log
>>>>>>> with or without collapsed_forwarding
>>>>>>>
>>>>>>>
>>>>>>> Heiler Bemerguy wrote
>>>>>>>> Yeah, I know. This kind of stuff only appeared after enabling
>>>>>>>> collapsed_forwarding, I think. Now it's off again.. but I
didn't wipe
>>>>>>>> the cache too, so I don't know.....
>>>>>>>>
>>>>>>>> 2016/05/31 10:50:24 kid2| varyEvaluateMatch: Oops. Not a Vary
match on
>>>>>>>> second attempt, 'http://js.statig.com.br/pub/adtags.js'
>>>>>>>> 'accept-encoding="gzip,%20deflate"'
>>>>>>>> 2016/05/31 10:50:24 kid2| clientProcessHit: Vary object loop!
>>>>>>>> 2016/05/31 10:50:25 kid2| Bug: Missing MemObject::storeId value
>>>>>>>> 2016/05/31 10:50:25 kid2| mem_hdr: 0x20573e10 nodes.start()
0x117e4ce0
>>>>>>>> 2016/05/31 10:50:25 kid2| mem_hdr: 0x20573e10 nodes.finish()
0x117e4ce0
>>>>>>>> 2016/05/31 10:50:25 kid2| MemObject->start_ping: 0.000000
>>>>>>>> 2016/05/31 10:50:25 kid2| MemObject->inmem_hi: 2155
>>>>>>>> 2016/05/31 10:50:25 kid2| MemObject->inmem_lo: 0
>>>>>>>> 2016/05/31 10:50:25 kid2| MemObject->nclients: 0
>>>>>>>> 2016/05/31 10:50:25 kid2| MemObject->reply: 0x7db9ce0
>>>>>>>> 2016/05/31 10:50:25 kid2| MemObject->request: 0
>>>>>>>> 2016/05/31 10:50:25 kid2| MemObject->logUri:
>>>>>>>> 2016/05/31 10:50:25 kid2| MemObject->storeId:
>>>>>>>>
>>>>>>>>
>>>>>>>> --
>>>>>>>> Best Regards,
>>>>>>>>
>>>>>>>> Heiler Bemerguy
>>>>>>>> Network Manager - CINBESA
>>>>>>>> 55 91 98151-4894/3184-1751
>>>>>>>>
>>>>>>>>
>>>>>>>> Em 31/05/2016 10:34, Yuri escreveu:
>>>>>>>>> This is too expensive action. Cold out cache will decrease
hit-ratio
>>>>>>>>> for weeks.
>>>>>>>>>
>>>>>>>>>
>>>>>>>>> Also, I suggest force reloading objects must overwrite stale
cached, no?
>>>>>>>>>
>>>>>>>>>
>>>>>>>>> 31.05.2016 19:32, Heiler Bemerguy пишет:
>>>>>>>>>>
>>>>>>>>>> I swear this bug was only rarely triggered without
>>>>>>>>>> collapsed_forwarding enabled... but I think you'll have to
wipe your
>>>>>>>>>> cache to really test it...
>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>>> --
>>>>>>>>>> Heiler Bemerguy - (91) 98151-4894
>>>>>>>>>> Assessor Técnico - CINBESA (91) 3184-1751
>>>>>>>>>>
>>>>>>>>>> Em 31/05/2016 08:00, Yuri escreveu:
>>>>>>>>>>> Heh,
>>>>>>>>>>>
>>>>>>>>>>> the issue occurs also with disabled collapsed_forwarding:
>>>>>>>>>>>
>>>>>>>>>>> 2016/05/31 16:58:12 kid1| varyEvaluateMatch: Oops. Not a
Vary match
>>>>>>>>>>> on second attempt,
>>>>>>>>>>>
'https://ru.wikipedia.org/w/load.php?debug=false&lang=ru&modules=jquery.accessKeyLabel%2Cclient%7Cmediawiki.RegExp%2Cnotify%2Cutil%7Cmediawiki.legacy.wikibits&skin=vector&version=b5e9abd3b463'
>>>>>>>>>>> 'accept-encoding="gzip,%20deflate,%20sdch,%20br"'
>>>>>>>>>>> 2016/05/31 16:58:12 kid1| clientProcessHit: Vary object loop!
>>>>>>>>>>> 2016/05/31 16:58:12 kid1| Error negotiating SSL on FD 260:
>>>>>>>>>>> error:14090086:SSL
routines:SSL3_GET_SERVER_CERTIFICATE:certificate
>>>>>>>>>>> verify failed (1/-1/0)
>>>>>>>>>>> 2016/05/31 16:58:12 kid1| varyEvaluateMatch: Oops. Not a
Vary match
>>>>>>>>>>> on second attempt,
>>>>>>>>>>>
'https://ru.wikipedia.org/w/index.php?title=MediaWiki:Secure.js&action=raw&ctype=text/javascript'
>>>>>>>>>>> 'accept-encoding="gzip,%20deflate,%20sdch,%20br",
>>>>>>>>>>>
cookie="WMF-Last-Access%3D31-May-2016%3B%20GeoIP%3DKZ%3A02%3AAlmaty%3A43.26%3A76.93%3Av4",
>>>>>>>>>>> authorization'
>>>>>>>>>>> 2016/05/31 16:58:12 kid1| clientProcessHit: Vary object loop!
>>>>>>>>>>> 2016/05/31 16:58:12 kid1| varyEvaluateMatch: Oops. Not a
Vary match
>>>>>>>>>>> on second attempt,
>>>>>>>>>>>
'https://ru.wikipedia.org/w/index.php?title=MediaWiki:Osm.js&action=raw&ctype=text/javascript'
>>>>>>>>>>> 'accept-encoding="gzip,%20deflate,%20sdch,%20br",
>>>>>>>>>>>
cookie="WMF-Last-Access%3D31-May-2016%3B%20GeoIP%3DKZ%3A02%3AAlmaty%3A43.26%3A76.93%3Av4",
>>>>>>>>>>> authorization'
>>>>>>>>>>> 2016/05/31 16:58:12 kid1| clientProcessHit: Vary object loop!
>>>>>>>>>>> 2016/05/31 16:58:13 kid1| varyEvaluateMatch: Oops. Not a
Vary match
>>>>>>>>>>> on second attempt,
>>>>>>>>>>>
'https://ru.wikipedia.org/w/index.php?title=MediaWiki:Sidebar-related.js&action=raw&ctype=text/javascript'
>>>>>>>>>>> 'accept-encoding="gzip,%20deflate,%20sdch,%20br",
>>>>>>>>>>>
cookie="WMF-Last-Access%3D31-May-2016%3B%20GeoIP%3DKZ%3A02%3AAlmaty%3A43.26%3A76.93%3Av4",
>>>>>>>>>>> authorization'
>>>>>>>>>>> 2016/05/31 16:58:13 kid1| clientProcessHit: Vary object loop!
>>>>>>>>>>> 2016/05/31 16:58:13 kid1| varyEvaluateMatch: Oops. Not a
Vary match
>>>>>>>>>>> on second attempt,
>>>>>>>>>>>
'https://ru.wikipedia.org/w/index.php?title=MediaWiki:Wikibugs.js&action=raw&ctype=text/javascript'
>>>>>>>>>>> 'accept-encoding="gzip,%20deflate,%20sdch,%20br",
>>>>>>>>>>>
cookie="WMF-Last-Access%3D31-May-2016%3B%20GeoIP%3DKZ%3A02%3AAlmaty%3A43.26%3A76.93%3Av4",
>>>>>>>>>>> authorization'
>>>>>>>>>>> 2016/05/31 16:58:13 kid1| clientProcessHit: Vary object loop!
>>>>>>>>>>> 2016/05/31 16:58:13 kid1| varyEvaluateMatch: Oops. Not a
Vary match
>>>>>>>>>>> on second attempt,
>>>>>>>>>>>
'https://ru.wikipedia.org/w/index.php?title=MediaWiki:Interwiki-links.js&action=raw&ctype=text/javascript'
>>>>>>>>>>> 'accept-encoding="gzip,%20deflate,%20sdch,%20br",
>>>>>>>>>>>
cookie="WMF-Last-Access%3D31-May-2016%3B%20GeoIP%3DKZ%3A02%3AAlmaty%3A43.26%3A76.93%3Av4",
>>>>>>>>>>> authorization'
>>>>>>>>>>> 2016/05/31 16:58:13 kid1| clientProcessHit: Vary object loop!
>>>>>>>>>>> 2016/05/31 16:58:13 kid1| varyEvaluateMatch: Oops. Not a
Vary match
>>>>>>>>>>> on second attempt,
>>>>>>>>>>>
'https://meta.wikimedia.org/w/index.php?title=MediaWiki:Wikiminiatlas.js&action=raw&ctype=text/javascript'
>>>>>>>>>>> 'accept-encoding="gzip,%20deflate,%20sdch,%20br", cookie,
>>>>>>>>>>> authorization'
>>>>>>>>>>>
>>>>>>>>>>> 3.5.19
>>>>>>>>>>>
>>>>>>>>>>>
>>> 
>>>
>>>
>>> _______________________________________________
>>> squid-users mailing list
>>> squid-users at lists.squid-cache.org
>>> http://lists.squid-cache.org/listinfo/squid-users
>>
>>
>>
>> _______________________________________________
>> squid-users mailing list
>> squid-users at lists.squid-cache.org
>> http://lists.squid-cache.org/listinfo/squid-users
>
>
>
> _______________________________________________
> squid-users mailing list
> squid-users at lists.squid-cache.org
> http://lists.squid-cache.org/listinfo/squid-users

-----BEGIN PGP SIGNATURE-----
Version: GnuPG v2
 
iQEcBAEBCAAGBQJXTbqXAAoJENNXIZxhPexGBUkH/28v8MSQP+ud24DsiMnOcOYW
1+/bz42zvnVgGBo092Th7i3ZZObCKmZ3St7wuWQPgFbVP3qoyEZYKumvK+P5+78w
YfuOWge8SG1yVwmPbQ8ge0Oq4/I19HcapFZXnHzEqN8/TbOtm04iTaaPiiKinsnq
KLpb0t9kdrTQgMZudjoDCg5y3kwGkYAMl39pAotFe2GgrBLWrP14/WTbrbmiT88a
bBD2rCjM9H2168q26AzKR/+u85gLvF6YYtN4xLn2/ahwmwu7Ak8hsJko+PeTxIeA
ae3g27/a/cQdch3GtjuDcMl8pmEk8U8rKRcHmQ63i1la3n+08FPjJcYJ2UzWAbM=
=VcAB
-----END PGP SIGNATURE-----

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.squid-cache.org/pipermail/squid-users/attachments/20160531/483dcf49/attachment-0001.html>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: 0x613DEC46.asc
Type: application/pgp-keys
Size: 2437 bytes
Desc: not available
URL: <http://lists.squid-cache.org/pipermail/squid-users/attachments/20160531/483dcf49/attachment-0001.key>

More information about the squid-users mailing list