[squid-users] Sudden but sustained high bandwidth usage

[Eliezer Croitoru]

Hey,

Thanks for the debug!.

I do not know the exact reason but I can say for sure that it's not the 
NetAPP or any other OS level issue since the AUFS\UFS cache_dir works 
fine in the same system and in a similar situation.
I will try to replicate it locally.
I do understand the issue and I will try my best to see what can be done 
from my side.

For now I will try to replicate the issue on a RAM only 
system(OS,CACHE,DISK,env..).
I think the right way now is to file a BUG in the bugzilla and continue 
following here and there since it's a major bug when comparing UFS\AUFS 
to ROCK.

If you understand that a patch\fix for such an issue is not a tiny task 
then I and you are on the same ship.

(I will try to test today but I cannot promise I will find it in such a 
hurry)

All The Bests,
Eliezer

* http://bugs.squid-cache.org/enter_bug.cgi

On 11/03/2016 18:25, Heiler Bemerguy wrote:
>
> I managed to track down with GDB one of these swapfails...
>
> Breakpoint 1, clientReplyContext::cacheHit (this=0x33bff58, result=...)
> at client_side_reply.cc:471
> 471             http->logType = LOG_TCP_SWAPFAIL_MISS;
> (gdb) l
> 466             debugs(88, 3, "clientCacheHit: request aborted");
> 467             return;
> 468         } else if (result.flags.error) {
> 469             /* swap in failure */
> 470             debugs(88, 3, "clientCacheHit: swapin failure for " <<
> http->uri);
> 471             http->logType = LOG_TCP_SWAPFAIL_MISS;
> 472             removeClientStoreReference(&sc, http);
> 473             processMiss();
> 474             return;
> 475         }
>
> (gdb) p *this
> $2 = {<Lock> = {_vptr.Lock = 0x84e668, count_ = 1}, <StoreClient> =
> {_vptr.StoreClient = 0x84e638}, purgeStatus = Http::scNone,
>    lookingforstore = 5, http = 0x1eadb398, headers_sz = 0, sc =
> 0x3034028, tempBuffer = {flags = {error = 0}, length = 0, offset = 0,
>      data = 0x0}, old_reqsize = 0, reqsize = 210, reqofs = 0, tempbuf =
> '\000' <repeats 4095 times>, flags = {storelogiccomplete = 0,
>      complete = 0, headersSent = false}, ourNode = 0xaa32198,
> holdingBuffer = {flags = {error = 0}, length = 0, offset = 0, data = 0x0},
>    reply = 0x0, old_entry = 0x0, old_sc = 0x0, deleting = false, static
> CBDATA_clientReplyContext = 24}
> (gdb) p result
> $3 = {flags = {error = 1}, length = 0, offset = 0,
>    data = 0x9ef18d8 "HTTP/1.1 200 Internal marker object\r\nServer:
> squid\r\nMime-Version: 1.0\r\nDate: Fri, 11 Mar 2016 15:57:32
> GMT\r\nContent-Type: x-squid-internal/vary\r\nExpires: Sat, 12 Mar 2016
> 19:44:12 GMT\r\nVary: Accept-En"...}
>
> It already came to client_side_reply.cc with "ERROR" set to 1...
>
> (gdb) bt
> #0  clientReplyContext::cacheHit (this=0x33bff58, result=...) at
> client_side_reply.cc:471
> #1  0x000000000064dcbd in store_client::callback (this=0x3034028,
> sz=<optimized out>, error=<optimized out>) at store_client.cc:130
> #2  0x000000000064e6c1 in store_client::startSwapin
> (this=this at entry=0x3034028) at store_client.cc:382
> #3  0x00000000006501d3 in store_client::doCopy
> (this=this at entry=0x3034028, anEntry=anEntry at entry=0xab07eb0) at
> store_client.cc:359
> #4  0x000000000065033c in storeClientCopy2 (e=0xab07eb0,
> sc=sc at entry=0x3034028) at store_client.cc:315
> #5  0x0000000000650db9 in storeClientCopy2 (sc=0x3034028, e=<optimized
> out>) at store_client.cc:281
> #6  store_client::copy (this=0x3034028, anEntry=0xab07eb0, copyRequest=...,
>      callback_fn=0x55b250 <clientReplyContext::CacheHit(void*,
> StoreIOBuffer)>, data=0x33bff58) at store_client.cc:232
> #7  0x0000000000558111 in clientReplyContext::doGetMoreData
> (this=this at entry=0x33bff58) at client_side_reply.cc:1799
> #8  0x0000000000558422 in clientReplyContext::identifyFoundObject
> (this=0x33bff58, newEntry=<optimized out>) at client_side_reply.cc:1649
> #9  0x000000000055a8b8 in clientReplyContext::cacheHit (this=0x33bff58,
> result=...) at client_side_reply.cc:525
> #10 0x000000000064dcbd in store_client::callback (this=0x51d5b08,
> sz=<optimized out>, error=<optimized out>) at store_client.cc:130
> #11 0x000000000064e1ba in store_client::readBody
> (this=this at entry=0x51d5b08, buf=<optimized out>, len=len at entry=210) at
> store_client.cc:497
> #12 0x000000000064f76b in store_client::readHeader (this=0x51d5b08,
> buf=<optimized out>, len=<optimized out>) at store_client.cc:611
> #13 0x0000000000732790 in Rock::IoState::callReaderBack (this=<optimized
> out>,
>      buf=0x9ef18d8 "HTTP/1.1 200 Internal marker object\r\nServer:
> squid\r\nMime-Version: 1.0\r\nDate: Fri, 11 Mar 2016 15:57:32
> GMT\r\nContent-Type: x-squid-internal/vary\r\nExpires: Sat, 12 Mar 2016
> 19:44:12 GMT\r\nVary: Accept-En"..., rlen=428) at rock/RockIoState.cc:143
> #14 0x0000000000726ec1 in Rock::SwapDir::readCompleted (this=<optimized
> out>, buf=<optimized out>, rlen=428, errflag=0, r=...)
>      at rock/RockSwapDir.cc:822
> #15 0x00000000006f22c0 in IpcIoFile::readCompleted (this=<optimized
> out>, readRequest=0x5417008, response=<optimized out>)
>      at DiskIO/IpcIo/IpcIoFile.cc:255
> #16 0x00000000006f6bcc in IpcIoFile::handleResponse (this=<optimized
> out>, ipcIo=...) at DiskIO/IpcIo/IpcIoFile.cc:462
> #17 0x00000000006f6fde in IpcIoFile::HandleResponses
> (when=when at entry=0x851324 "after notification") at
> DiskIO/IpcIo/IpcIoFile.cc:449
>
> ...help!
>
>