当前位置:Gxlcms > mysql > Squid日志中为何会有HIT,并且DIRECT的记录?

Squid日志中为何会有HIT,并且DIRECT的记录?

时间:2021-07-01 10:21:17 帮助过:28人阅读

前几天, @ARGV 问了这个问题《 squid 灵异 日志 》 http://chenlinux.com/2010/03/17/problem-of-squid-access-log/ 灵异乎?一般灵异吧。只要我们走近科学,没有什么不能被解释的。 首先说一下 HIT/MISS/REFRESH_HIT 这些状态是由什么决定的 其实这些状态

前几天,@ARGV问了这个问题《squid 灵异日志

http://chenlinux.com/2010/03/17/problem-of-squid-access-log/

灵异乎?一般灵异吧。只要我们走近科学,没有什么不能被解释的。

首先说一下HIT/MISS/REFRESH_HIT这些状态是由什么决定的

其实这些状态,在代码里就是http->log_type。而这个log_type的赋值主要是这么几个地方:

第一处,clientProcessRequest


点击(此处)折叠或打开

  1. http->log_type = clientProcessRequest2(http);

简单地说,找到了要访问的entry,就是TCP_HIT,没找到就是TCP_MISS

第二处,clientAccessCheckDone中,如果http_access检查没有通过,设成TCP_DENIED

第三处,clientHandleIMSReply中,根据回源IMS校验结果,可能设置成TCP_REFRESH_HIT或者TCP_REFRESH_MISS

第四处,clientCacheHit中,可能由于打开/读取磁盘文件失败,设成TCP_SWAPFAIL_MISS,也有可能由于缓存了404等报错,设成TCP_NEGATIVE_HIT,或者异步刷新的原因,设成TCP_STALE_HIT,以及由于offline模式的开启,设成TCP_OFFLINE_HIT

第五处,clientProcessHit中,应答客户端的IMS,设成TCP_IMS_HIT,或者由于hitobjectstore_status还不是STORE_OK,设成TCP_MISS

再说一下这个DIRECT是哪里来的。这是http->request->hier。一般来说,没有回源就是HIER_NONE,走DNS回源的时候设成HIER_DIRECT。如果squid里面配置了peer的话,还可能是各种PARENT,或者SIBLING

那么,一个没有回源的请求,为什么是DIRECT呢?这是因为,虽然这个请求找到了StoreEntry因而没有回源,但是这个找到的StoreEntry是由上一个请求引起回源的,而且回源还没有完成,那么clientProcessRequest里面会修改当前http->request->hier,改成真正引起回源那个请求(也就是http->entry->mem_obj->request)的hier。下面这段代码就是做这件事情的(省略了无关代码)


点击(此处)折叠或打开

  1. if (NULL != http->entry) {

  2. if (http->entry->store_status == STORE_PENDING && http->entry->mem_obj)

  3. {

  4. if (http->entry->mem_obj->request)

  5. {

  6. r->hier = http->entry->mem_obj->request2->hier;

  7. }

  8. }

  9. }


如果是这样,按理说,只要是第一个请求回源期间,所有的请求都应该是HIT并且DIRECT才对,应该有很多的HIT/DIRECT才对。而实际上日志中的HIT/DIRECT并不多,这又是为什么呢?

原来,是刚才提到的log_type的第五处修改“clientProcessHit中,由于hitobjectstore_status还不是STORE_OK,设成TCP_MISS”造成的。下面是代码

点击(此处)折叠或打开

  1. if (e->store_status != STORE_OK)

  2. {

  3. http->log_type = LOG_TCP_MISS;

  4. }


所以,很多本来是
HIT,而hier又被改成了初始回源的请求的hier的请求,log_type被改回了MISS

接下来是亮点:

不难推断,只要 修改hierclientProcessRequest,到将HIT改成MISSclientProcessHit之间,store_status突然由STORE_PENDING变成STORE_OK,就可能会产生HIT/DIRECT了。

这个突变会不会发生呢?

答案是会的。

首先从理论上,clientProcessHit是有clientProcessRequest调用storeClientCopy,然后回调到clientCacheHit,再调到clientProcessHit的,在storeClientCopy期间,所需的header可能在磁盘上,需要进入aufs的异步读取流程,再由aufs的回调调用clientCacheHit。这期间clientProcessRequest会暂时放弃主进程的控制权,这期间StoreEntry完全有机会变成STORE_OK(通过storeComplete函数)。

接下来,我们从日志上验证了这一点,首先在修改hier的代码中加入日志。那句debug(0, 0)会把http结构的地址记入cache.log


点击(此处)折叠或打开

  1. if (http->entry->mem_obj->request2)

  2. {

  3. r->hier = http->entry->mem_obj->request2->hier;

  4. debug(0, 0)("passing hier to %p from %p, at %p\n", r, http->entry->mem_obj->request2, http);

  5. }


然后在HITMISS的地方加入日志,如果改了或者没改,都会记录http结构的地址。


点击(此处)折叠或打开

  1. if (e->store_status != STORE_OK)

  2. {

  3. http->log_type = LOG_TCP_MISS;

  4. debug(0, 0)("falling back to TCP_MISS %p\n", http);

  5. }

  6. else if (http->log_type == LOG_TCP_HIT && e->mem_status == IN_MEMORY)

  7. {

  8. http->log_type = LOG_TCP_MEM_HIT;

  9. debug(0, 0)("not falling back to TCP_MISS %p\n", http);

  10. }

  11. else

  12. {

  13. debug(0, 0)("not falling back to TCP_MISS %p\n", http);

  14. }


GC来了,我们用ab打一个url,然后看cache.log

绝大部分改了hier的请求,都改回了MISS


点击(此处)折叠或打开

  1. 2013/01/09 14:53:45| passing hier to 0x5fe5170 from 0x5e4bf80, at 0x5fe4d28
  2. 2013/01/09 14:53:45| falling back to TCP_MISS 0x5fe4d28


但是,有的请求,由于store_status变了,就没有改回MISS


点击(此处)折叠或打开

  1. 2013/01/09 15:22:47| passing hier to 0x7831910 from 0x7501f80, at 0x78314c8
  2. 2013/01/09 15:22:47| not falling back to TCP_MISS 0x78314c8


这时再看访问日志,确实出现了HIT并且DIRECT


点击(此处)折叠或打开

  1. 1357716167 127.0.0.1 - - [09/Jan/2013:15:22:47 +0800] "GET http://127.0.1.4:8080/1.html?49123 HTTP/1.0" 200 3157 "-" "ApacheBench/2.3" TCP_HIT DIRECT


小小地总结一下

这个问题是squid一个小bug,不会引起太大的不良后果,只是日志记得诡异了一些,但回源次数不会变多,因此不用担心。


人气教程排行