[squid-users] Bug: Missing MemObject::storeId value
Heiler Bemerguy
heiler.bemerguy at cinbesa.com.br
Tue May 31 16:36:00 UTC 2016
This is the parent proxy of another one (10.1.10.101).
It was receiveing requests like these:
1464665138.326 0 10.1.10.101 UDP_MISS/000 72 ICP_QUERY
http://img.olx.com.br/thumbs/51/517630000636766.jpg - HIER_NONE/- -
1464665138.331 0 10.1.10.101 UDP_MISS/000 72 ICP_QUERY
http://img.olx.com.br/thumbs/51/515630006195751.jpg - HIER_NONE/- -
1464665138.400 68 10.1.10.101 TCP_MISS/200 2439 GET
http://img.olx.com.br/thumbs/51/515630006195751.jpg -
HIER_DIRECT/54.192.57.169 image/jpeg
1464665138.404 86 10.1.10.101 TCP_MISS/200 2221 GET
http://img.olx.com.br/thumbs/51/518630004436306.jpg -
HIER_DIRECT/54.192.57.169 image/jpeg
--
Best Regards,
Heiler Bemerguy
Network Manager - CINBESA
55 91 98151-4894/3184-1751
Em 31/05/2016 13:23, Yuri Voinov escreveu:
>
> -----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-----
>
>
>
> _______________________________________________
> squid-users mailing list
> squid-users at lists.squid-cache.org
> http://lists.squid-cache.org/listinfo/squid-users
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.squid-cache.org/pipermail/squid-users/attachments/20160531/bdf61d53/attachment-0001.html>
More information about the squid-users
mailing list