前几天， @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 中
点击( 此处 )折叠或打开
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 ，或者由于 hit 的 object 的 store_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 。下面这段代码就是做这件事情的（省略了无关代码）
点击( 此处 )折叠或打开
if ( NULL ! = http - > entry ) {
if ( http - > entry - > store_status = = STORE_PENDING & & http - > entry - > mem_obj )
{
if ( http - > entry - > mem_obj - > request )
{
r - > hier = http - > entry - > mem_obj - > request2 - > hier ;
}
}
}
如果是这样，按理说，只要是第一个请求回源期间，所有的请求都应该是 HIT 并且 DIRECT 才对，应该有很多的 HIT/DIRECT 才对。而实际上 日志 中的 HIT/DIRECT 并不多，这又是为什么呢？
原来，是刚才提到的 log_type 的第五处修改“ clientProcessHit 中，由于 hit 的 object 的 store_status 还不是 STORE_OK ，设成 TCP_MISS ”造成的。下面是代码
点击( 此处 )折叠或打开
if ( e - > store_status ! = STORE_OK )
{
http - > log_type = LOG_TCP_MISS ;
}
所以，很多本来是 HIT ，而 hier 又被改成了初始回源的请求的 hier 的请求， log_type 被改回了 MISS 。
接下来是亮点：
不难推断，只要 修改 hier 的 clientProcessRequest ，到将 HIT 改成 MISS 的 clientProcessHit 之间， 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
点击( 此处 )折叠或打开
if ( http - > entry - > mem_obj - > request2 )
{
r - > hier = http - > entry - > mem_obj - > request2 - > hier ;
debug ( 0 , 0 ) ( "passing hier to %p from %p, at %p\n" , r , http - > entry - > mem_obj - > request2 , http ) ;
}
然后在 HIT 改 MISS 的地方加入 日志 ，如果改了或者没改，都会 记录 http 结构的地址。
点击( 此处 )折叠或打开
if ( e - > store_status ! = STORE_OK )
{
http - > log_type = LOG_TCP_MISS ;
debug ( 0 , 0 ) ( "falling back to TCP_MISS %p\n" , http ) ;
}
else if ( http - > log_type = = LOG_TCP_HIT & & e - > mem_status = = IN_MEMORY )
{
http - > log_type = LOG_TCP_MEM_HIT ;
debug ( 0 , 0 ) ( "not falling back to TCP_MISS %p\n" , http ) ;
}
else
{
debug ( 0 , 0 ) ( "not falling back to TCP_MISS %p\n" , http ) ;
}
GC 来了，我们用 ab 打一个 url ，然后看 cache.log
绝大部分改了 hier 的请求，都改回了 MISS
点击( 此处 )折叠或打开
2013/01/09 14:53:45| passing hier to 0x5fe5170 from 0x5e4bf80, at 0x5fe4d28 2013/01/09 14:53:45| falling back to TCP_MISS 0x5fe4d28
但是，有的请求，由于 store_status 变了，就没有改回 MISS
点击( 此处 )折叠或打开
2013/01/09 15:22:47| passing hier to 0x7831910 from 0x7501f80, at 0x78314c8 2013/01/09 15:22:47| not falling back to TCP_MISS 0x78314c8
这时再看访问 日志 ，确实出现了 HIT 并且 DIRECT
点击( 此处 )折叠或打开
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，不会引起太大的不良后果，只是 日志 记得诡异了一些，但回源次数不会变多，因此不用担心。
查看更多关于Squid日志中为何会有HIT，并且DIRECT的记录？的详细内容...