第13章 日志文件

13.1 cache.log

cache.log包含多种消息，例如Squid的配置信息、性能警告、以及严重错误。如下是cache.log的输出样本：

2003/09/29 12:09:45| Starting Squid Cache version 2.5.STABLE4 for i386-
    
unknown-freebsd4.8...
    
2003/09/29 12:09:45| Process ID 18990
    
2003/09/29 12:09:45| With 1064 file descriptors available
    
2003/09/29 12:09:45| Performing DNS Tests...
    
2003/09/29 12:09:45| Successful DNS name lookup tests...
    
2003/09/29 12:09:45| DNS Socket created at 0.0.0.0, port 1154, FD 5
    
2003/09/29 12:09:45| Adding nameserver 24.221.192.5 from /etc/resolv.conf
    
2003/09/29 12:09:45| Adding nameserver 24.221.208.5 from /etc/resolv.conf
    
2003/09/29 12:09:45| helperOpenServers: Starting 5 'redirector.pl' processes
    
2003/09/29 12:09:45| Unlinkd pipe opened on FD 15
    
2003/09/29 12:09:45| Swap maxSize 10240 KB, estimated 787 objects
    
2003/09/29 12:09:45| Target number of buckets: 39
    
2003/09/29 12:09:45| Using 8192 Store buckets
    
2003/09/29 12:09:45| Max Mem  size: 8192 KB
    
2003/09/29 12:09:45| Max Swap size: 10240 KB
    
2003/09/29 12:09:45| Rebuilding storage in /usr/local/squid/var/cache (CLEAN)
    
2003/09/29 12:09:45| Using Least Load store dir selection
    
2003/09/29 12:09:45| Set Current Directory to /usr/local/squid/var/cache
    
2003/09/29 12:09:45| Loaded Icons.
    
2003/09/29 12:09:45| Accepting HTTP connections at 0.0.0.0, port 3128, FD 16.
    
2003/09/29 12:09:45| Accepting ICP messages at 0.0.0.0, port 3130, FD 17.
    
2003/09/29 12:09:45| WCCP Disabled.
    
2003/09/29 12:09:45| Ready to serve requests.

每个cache.log条目以时间戳开始，指示消息何时产生。本示例里的日志报告了squid的版本（2.5.STABLE4），以及squid所运行的操作系统标识符（i386-unknown-freebsd4.8）。接下来是进程ID（18990）。许多cache.log条目看起来含义不明（例如Target number of buckets: 39）。大多数正常情形下，可以忽略这些不易理解的条目。另一方面，你也许该仔细看一下本质的配置细节，例如名字服务器的地址，或HTTP服务器地址。本示例日志最后陈述了Squid准备接受请求。此时Squid可以接受来自客户端的HTTP连接。

通常，cache.log增长缓慢。然而，不正常的HTTP事务或类似的事件可以导致squid发布一个debug消息。假如这样的事件经常发生（例如DOS攻击、新的病毒、磁盘意外等），日志文件会增长很快。定期轮转日志减少了用光磁盘的风险。

主要的错误和异常条件最可能报告在cache.log里。我推荐存档这些日志，以便以后回查事件的源头。当在Squid的邮件列表或类似论坛描述这些故障时，相应的cache.log非常有用。某些情形下，你也许应该调大日志的debug级别，以便其他人能更好的理解和修正你的问题。

13.1.1 debug级别

debug_options指令控制cache.log的日志级别。默认值（ALL,1）通常是最佳选择。在更高级别上，不重要的消息会混淆视线。请参考16.2节关于debug_options指令的完整描述。

请注意最高级别的debug（9或10）会对每个请求产生数千行日志，快速消耗磁盘空间和显著影响squid的性能。

可以使用squid的-X命令行选项来对所有情形激活完整的debug。假如squid拒绝启动，并且squid.conf里的debug级别不足以诊断问题时，该模式特别有用。这也是在配置文件解析器解析到debug_options指令之前，激活它的完整debug的好方法。在squid运行正常时，请勿使用-X。

对运行的squid进程，可使用squid的-k debug命令行选项来立刻激活完整debug。这个命令是循环使用的：第一次调用打开完整debug，第二次调用则关闭它。请见第5章关于-k选项的通用讨论。

如前所述，完整debug会产生难以控制的日志增长。这会使squid和操作系统运行缓慢。在极端情形下，你会发现终端session在运行第一个squid -k debug命令后，变得没有响应。在squid狂写日志的同时让操作无法进行，这情形并不好。如下技巧也许有用，它获取5秒钟的debug数据快照：

% squid -k debug; sleep 5; squid -k debug

13.1.2 转发cache.log消息到系统日志

为了让squid发送cache.log消息的拷贝到系统日志，请使用-s命令行选项。仅仅在debug级别0和1的消息会被转发。级别0的消息以syslog级别LOG_WARNING记录，级别1的消息以syslog级别LOG_NOTICE记录。所有消息使用LOCAL4的syslog设备。如下是配置syslogd的一个方法，以便这些消息能保存下来：

local4.warning                           /var/log/squid.log

在维护多个squid主机时，使用syslog来记录cache.log特别方便。可以配置每个本地syslog进程，转发这些消息到中央日志主机，这样就可在一个地方统一浏览所有cache日志。例如，可在/etc/syslogd.conf里使用如下接口：

local4.notice                            @192.168.45.1

13.1.3 dump cache.log消息到终端

-d level命令行选项指示squid去dump cache.log消息到终端（例如stderr）。level参数指明dump出的消息的最大级别。注意你只会见到出现在cache.log里的消息，它遵循于debug_options设置。例如，假如设置了debug_options ALL,1，然后运行squid -d2，你不会见到级别2的debug消息。

-d level和-N选项在debug squid问题或快速测试配置文件的改变时，特别有用。它们允许你容易启动squid和观察cache.log消息。在squid从crontab或类似的设备启动时，该选项也有用，crontab会捕获squid的标准错误并将其报告回用户。例如，可能有如下crontab，它自动重配运行中的squid进程：

15 */4 * * * /usr/local/squid/sbin/squid -d1 -k reconfigure

13.2 access.log

Squid把关于HTTP事务的关键信息存放在access.log里。该文件是基于行的，也就是说每行对应一个客户端请求。squid记录客户端IP（或主机名）、请求URL、响应size、和其他信息。

Squid在access.log里记录所有HTTP访问，除了那些在还没有发送数据前就断开的连接。Squid也记录所有的ICP（非HTCP）事务，除非你使用log_icp_queries指令关闭了这个功能。第13.2.4节描述了其他影响access日志的squid.conf指令。

默认的access.log格式包含了10个域。如下是日志样本，长行分割并且缩进排版：

1066037222.011  126389 9.121.105.207 TCP_MISS/503 1055

        GET http://home.gigigaga.com/n8342133/Miho.DAT.019 -

        DIRECT/203.187.1.180 -

1066037222.011   19120 12.83.179.11 TCP_MISS/200 359

        GET http://ads.x10.com/720x300/Z2FtZ3JlZXRpbmcxLmRhd/7/AMG -

        DIRECT/63.211.210.20 text/html

1066037222.011   34173 166.181.33.71 TCP_MISS/200 559

        GET http://coursesites.blackboard.com:8081/service/collab/./1010706448190/ -

        DIRECT/216.200.107.101 application/octet-stream

1066037222.011   19287 41.51.105.27 TCP_REFRESH_MISS/200 500

        GET http://fn.yam.com/include/tsemark/show.js -

        DIRECT/210.59.224.59 application/x-javascript

1066037222.011   19395 41.51.105.27 TCP_MISS/304 274

        GET http://fnasp.yam.com/image/coin3.gif -

        DIRECT/211.72.254.133 -

1066037222.011   19074 30.208.85.76 TCP_CLIENT_REFRESH_MISS/304 197

        GET http://ads.icq.com/content/B0/0/..bC6GygEYNeHGjBUin5Azfe68m5hD1jLk$/aol -

        DIRECT/64.12.184.121 -

1066037222.011   19048 12.83.179.11 TCP_MISS/200 261

        GET http://ads.adsag.com/js.ng/...ne&cat=friendship&subcat=girltalk -

        DIRECT/209.225.54.119 application/x-javascript

1066037222.118     106 41.51.105.27 TCP_HIT/200 536

        GET http://rcm-images.amazon.com/./images/G/01/rcm/privacy.gif -

        NONE/- image/gif

1066037222.352   19475 27.34.49.248 TCP_MISS/200 12387

        GET http://espanol.geocities.com/lebastias/divulgacion/budismo-tarot.html -

        DIRECT/209.1.225.139 text/html

1066037222.352     132 144.157.100.17 TCP_MISS/504 1293

        GET http://ar.atwola.com/image/93101912/aol -

        NONE/- -

如下是对每个域的详细解释：

1.时间戳

请求完成时间，以Unix纪元（UTC 1970-01-01 00:00:00）以来的秒数表示，它是毫秒级的。squid使用这种格式而不是人工可读的时间格式，是为了简化某些日志处理程序的工作。

可以使用一个简单的perl命令来转化Unix时间戳到本地时间，例如：

perl -pe 's/^\d+\.\d+/localtime($&)/e;' access.log

2.响应时间

对HTTP事务来说，该域表明squid花了多少时间来处理请求。在squid接受到HTTP请求时开始计时，在响应完全送出后计时终止。响应时间是毫秒级的。

对ICP查询来说，响应时间通常是0。这是因为squid回答ICP查询非常迅速。甚至，squid在接受到ICP查询和发送完响应之间，不会更新进程时钟。

尽管时间值是毫秒级的，但是精度可能是10毫秒。在squid负载繁重时，计时变得没那么精确。

3.客户端地址

该域包含客户端的IP地址，或者是主机名--假如激活了log_fqdn。出于安全或隐私的理由，你可能需要使用client_netmask指令来掩盖客户端地址的一部分。然而，这样让来自同一客户端的组请求变得不可能。

4.结果/状态码

该域包含2个token，以斜杠分隔。第一个token叫结果码，它把协议和事务结果（例如TCP_HIT或UDP_DENIED）进行归类。这些是squid专有的编码，在13.2.1节里有定义。以TCP_开头的编码指HTTP请求，以UDP_开头的编码指ICP查询。

第2个token是HTTP响应状态码（例如200,304,404等）。状态码通常来自原始服务器。在某些情形下，squid可能有义务自己选择状态码。这些编码在HTTP的RFC里定义，在随后的Table 13-1里有概述。

5.传输size

该域指明传给客户端的字节数。严格的讲，它是squid告诉TCP/IP协议栈去发送给客户端的字节数。这就是说，它不包括TCP/IP头部的overhead。也请注意，传输size正常来说大于响应的Content-Length。传输size包括了HTTP响应头部，然而Content-Length不包括。

传输size可用于近似的带宽使用分析，但并非精确的HTTP实体size计算。假如需要了解响应的Content-Length，可在store.log里找到它。

6.请求方式

该域包含请求方式。因为squid客户端可能使用ICP或HTTP，请求方式就可能是HTTP-或ICP-这2种。最普通的HTTP请求方式是GET。ICP查询总以ICP_QUERY的形式被记载。请见6.1.2.8节关于squid了解的HTTP方式列表。

7.URI

该域包含来自客户端请求的URI。大多数记录下来的URI实际是URL（例如，它们有主机名）。

Squid对某些失败使用特殊的记录格式。例如Squid不能解析HTTP请求，或者不能决定URI，这时你可能见到类似于"error:invalid-request." 的字串出现在URI的位置。例如：

1066036250.603 310 192.0.34.70 NONE/400 1203 GET error:invalid-request - NONE/- -

另外在该域里，也请留心URI里的空格字符。取决于uri_whitespace设置，squid可能在日志文件里打印URI时带空格字符。若发生这种情况，则阅读access.log文件的日志分析工具可能会遇到麻烦。

在记日志时，squid删掉了在第一个问号(?)之后的所有URI字符，除非禁用了strip_query_terms指令。

8.客户端身份

Squid有2种不同的办法来决定用户的身份。一种是RFC 1413身份协议，另一种来自HTTP验证头部。

Squid试图基于ident_lookup_access规则进行身份查询，假如有的话。另外，假如使用代理验证（或在代理人模式下的规范服务验证），squid会在该域放置给定的用户名。假如2者都提供给squid一个用户名，并且你使用了原始access.log格式，那么HTTP验证名字会记录下来，RFC 1413名字会忽略掉。普通日志文件格式会把两者都独立的记录。

9.对端编码/对端主机

对端信息包含了2个token，以斜杠分隔。它仅仅与cache丢失的请求有关。第一个token指示如何选择下一跳，第二个token是下一跳的地址。对端编码列在13.2.3节里。

当squid发送一个请求到邻居cache时，对端主机地址是邻居的主机名。假如请求是直接送到原始服务器的，则squid会写成原始服务器的IP地址或主机名--假如禁用了log_ip_on_direct。NONE/-这个值指明squid不转发该请求到任何其他服务器。

10.内容类型

原始access.log的默认的最后一个域，是HTTP响应的内容类型。squid从响应的Content-Type头部获取内容类型值。假如该头部丢失了，squid使用一个横杠(-)代替。

假如激活了log_mime_headers指令，squid在每行追加2个附加的域：

11.HTTP请求头部

Squid编码HTTP请求头部，并且在一对方括号之间打印它们。方括号是必须的，因为squid不编码空格字符。编码方案稍许奇怪。回车（ASCII 13）和换行（ASCII 10）分别打印成\r和\n。其他不可打印的字符以RFC 1738风格来编码，例如Tab（ASCII 9）变成了%09。

12.HTTP响应头部

Squid编码HTTP响应头部，并且在一对方括号之间打印它们。注意这些是发往客户端的头部，可能不同于从原始服务器接受到的头部。

Squid只有在整个响应发送到客户端完成以后，才写access.log日志。这点允许squid在日志文件里包含请求和响应两者信息。然而，需要花费数分钟甚至数小时才能完成的事务，请求期间的日志在access.log里不可见。当这类型的事务呈现出性能或策略问题时，access.log可能对你没有帮助。代替的，可使用cache管理器来浏览挂起事务的列表（见14章）。

13.2.1 access.log结果编码

相应于HTTP请求，下列标签可能出现在access.log文件的第四个域。

TCP_HIT

Squid发现请求资源的貌似新鲜的拷贝，并将其立即发送到客户端。

TCP_MISS

Squid没有请求资源的cache拷贝。

TCP_REFERSH_HIT

Squid发现请求资源的貌似陈旧的拷贝，并发送确认请求到原始服务器。原始服务器返回304（未修改）响应，指示squid的拷贝仍旧是新鲜的。

TCP_REF_FAIL_HIT

Squid发现请求资源的貌似陈旧的拷贝，并发送确认请求到原始服务器。然而，原始服务器响应失败，或者返回的响应Squid不能理解。在此情形下，squid发送现有cache拷贝（很可能是陈旧的）到客户端。

TCP_REFRESH_MISS

Squid发现请求资源的貌似陈旧的拷贝，并发送确认请求到原始服务器。原始服务器响应新的内容，指示这个cache拷贝确实是陈旧的。

TCP_CLIENT_REFRESH_MISS

Squid发现了请求资源的拷贝，但客户端的请求包含了Cache-Control: no-cache指令。Squid转发客户端的请求到原始服务器，强迫cache确认。

TCP_IMS_HIT

客户端发送确认请求，Squid发现更近来的、貌似新鲜的请求资源的拷贝。Squid发送更新的内容到客户端，而不联系原始服务器。

TCP_SWAPFAIL_MISS

Squid发现请求资源的有效拷贝，但从磁盘装载它失败。这时squid发送请求到原始服务器，就如同这是个cache丢失一样。

TCP_NEGATIVE_HIT

在对原始服务器的请求导致HTTP错误时，Squid也会cache这个响应。在短时间内对这些资源的重复请求，导致了否命中。negative_ttl指令控制这些错误被cache的时间数量。请注意这些错误只在内存cache，不会写往磁盘。下列HTTP状态码可能导致否定cache（也遵循于其他约束）： 204, 305, 400, 403, 404, 405, 414, 500, 501, 502, 503, 504。

TCP_MEM_HIT

Squid在内存cache里发现请求资源的有效拷贝，并将其立即发送到客户端。注意这点并非精确的呈现了所有从内存服务的响应。例如，某些cache在内存里，但要求确认的响应，会以TCP_REFRESH_HIT, TCP_REFRESH_MISS等形式记录。

TCP_DENIED

因为http_access或http_reply_access规则，客户端的请求被拒绝了。注意被http_access拒绝的请求在第9域的值是NONE/-，然而被http_reply_access拒绝的请求，在相应地方有一个有效值。

TCP_OFFLINE_HIT

当offline_mode激活时，Squid对任何cache响应返回cache命中，而不用考虑它的新鲜程度。

TCP_REDIRECT

重定向程序告诉Squid产生一个HTTP重定向到新的URI（见11.1节）。正常的，Squid不会记录这些重定向。假如要这样做，必须在编译squid前，手工定义LOG_TCP_REDIRECTS预处理指令。

NONE

无分类的结果用于特定错误，例如无效主机名。

相应于ICP查询，下列标签可能出现在access.log文件的第四域。

UDP_HIT

Squid在cache里发现请求资源的貌似新鲜的拷贝。

UDP_MISS

Squid没有在cache里发现请求资源的貌似新鲜的拷贝。假如同一目标通过HTTP请求，就可能是个cache丢失。请对比UDP_MISS_NOFETCH。

UDP_MISS_NOFETCH

跟UDP_MISS类似，不同的是这里也指示了Squid不愿去处理相应的HTTP请求。假如使用了-Y命令行选项，Squid在启动并编译其内存索引时，会返回这个标签而不是UDP_MISS。

UDP_DENIED

因为icp_access规则，ICP查询被拒绝。假如超过95%的到某客户端的ICP响应是UDP_DENIED，并且客户端数据库激活了（见附录A），Squid在1小时内，停止发送任何ICP响应到该客户端。若这点发生，你也可在cache.log里见到一个警告。

UDP_INVALID

Squid接受到无效查询（例如截断的消息、无效协议版本、URI里的空格等）。Squid发送UDP_INVALID响应到客户端。

13.2.2 HTTP响应状态码

Table 13-1列出了数字HTTP响应CODE和理由短句。注意Squid和其他HTTP客户端仅仅关注这些数字值。理由短句是纯解释性的，不会影响响应的意义。对每个状态码，也提供了一个到RFC 2616的具体节的索引。注意状态码0和600是squid使用的非标准的值，不会在RFC里提到。

假如Squid从原始服务器没有接受到任何响应，你可在access.log里看到状态码0。假如Squid接受到的响应没有包含HTTP头部，就会出现状态码600。在少数情况下，某些原始服务器仅发送响应body，而忽略了任何头部。

13.2.3 access.log对端编码

下列编码可能出现在access.log的第9域。请参考10.10节关于Squid如何对cache丢失情况，选择有效的下一跳。

NONE

这指明Squid对本次请求，不会与任何其他服务器（邻居或原始服务器）通信。它通常与cache命中、拒绝请求、cache管理请求、错误、和所有的ICP查询这些类型联合出现。

DIRECT

Squid直接转发请求到原始服务器。该域的第2半部分显示原始服务器的IP地址，或主机名--假如禁止了log_ip_on_direct。

SIBLING_HIT

在姐妹cache返回ICP或HTCP命中后，Squid发送请求到姐妹cache。

PARENT_HIT

在父cache返回ICP或HTCP命中后，Squid发送请求到父cache。

DEFAULT_PARENT

Squid选择该父cache，因为其在squid.conf的cache_peer行里被标志为default。

FIRST_UP_PARENT

Squid转发请求到该父cache，因为它是位于已知活跃列表里的第一个父cache。

FIRST_PARENT_MISS

Squid转发请求到该父cache，它第一个响应ICP/HTCP丢失消息。换句话说，对这个特殊的ICP/HTCP查询，在这个特殊时刻，被选中的父cache有最佳的往返时间（RTT）。注意标准RTT可能被人工矫正过，取决于cache_peer指令的weight选项。

CLOSEST_PARENT_MISS

Squid选择该父cache，因为它报告到原始服务器的RTT最低。这点仅在2个cache都激活了netdb，并且原始服务器（或在同一子网内的其他server）返回ICMP ping消息。

CLOSEST_PARENT

这点类似CLOSEST_PARENT_MISS，除了RTT计算不是来自ICP/HTCP响应消息外。代替的，它们来自Squid保留的更老的计算方式，例如netdb交换功能。

CLOSEST_DIRECT

Squid基于netdb算法，转发请求到原始服务器。这点在满足下述任何条件时发生：

• 1）在Squid和原始服务器之间的RTT小于配置的minimum_direct_rtt值。
• 2）在Squid和原始服务器之间的标准路由跳数少于配置的minimum_direct_hops值。
• 3）在ICP/HTCP响应里返回的RTT值，指示Squid离原始服务器近于任何其他邻居。

ROUNDROBIN_PARENT

Squid转发请求到该父cache，因为设置了round-robin选项，并且它有最低的使用计数器。

CD_PARENT_HIT

Squid基于cache摘要算法（见10.7节）转发请求到该父cache。

CD_SIBLING_HIT

Squid基于cache摘要算法转发请求到该姐妹cache。

CARP

Squid选择该父cache，基于cache数组路由协议算法（见10.9节）。

ANY_PARENT

作为最后的手段，Squid选择该父cache，因为没有其他方法能选择可行的下一跳。

注意大部分上述编码可能以TIMEOUT_开头，这表明在等待ICP/HTCP响应时发生超时。例如：

1066038165.382    345 193.233.46.21 TCP_MISS/200 2836

        GET http://www.caida.org/home/./images/home.jpg

        TIMEOUT_CLOSEST_DIRECT/213.219.122.19 image/jpeg

可使用icp_query_timeout指令来调整超时。

13.2.4 影响access.log的配置指令

下列配置文件指令会影响到access.log。

13.2.4.1 log_icp_queries

该指令默认激活，导致squid记录所有的ICP查询。假如运行了一个繁忙的父cache，这点可能让access.log文件变得巨大。为了节省磁盘空间，可禁止该指令：

log_icp_queries off

假如禁止了ICP查询的日志，我建议你监视查询数量--通过cache管理器或SNMP。

13.2.4.2 emulate_httpd_log

access.log文件有2种格式：普通格式和原始格式。普通格式就如同大部分HTTP服务器（如Apache）的日志格式一样。它包含的信息少于Squid的原始格式。然而，假如运行Squid在代理人模式下（见15章），你可能想要普通日志文件格式。普通格式或许也对你现有的日志文件分析工具有用。使用该指令来激活普通格式：

emulate_httpd_log on

请见http://www.w3.org/Daemon/User/Config/Logging.html 关于该格式的描述。

13.2.4.3 log_mime_hdrs

使用log_mime_hdrs让squid记录HTTP请求和响应的头部：

log_mime_headers on

在激活时，squid追加请求和响应头部到access.log。这会在每行增加2个域。每个域都以方括号引用起来，便于分析。某些字符会被编码来保证日志文件可读。Table 13-2显示了这些编码方案。

Table 13-2. Character encoding rules for HTTP headers in access.log

13.2.4.4 log_fqdn

Squid默认把客户端IP地址放在access.log里。也可以记录可用的主机名，激活如下指令：

log_fqdn on

这点让Squid在接受到请求时，对客户端的地址发起反向DNS查询。假如在请求完成时查到了主机名，Squid就将它放在第3域。

13.2.4.5 ident_lookup_access

该访问规则列表决定Squid是否对客户端的TCP连接发起RFC 1413身份查询。默认情况下，Squid不会发布身份查询。为了激活这点，简单的增加一个或多个规则：

acl All src 0/0

ident_lookup_access allow All

假如在请求完成时查到了答案，Squid将其放在第8域。假如同时使用了HTTP验证，从验证得到的用户名会取代身份查询答案。

13.2.4.6 log_ip_on_direct

当Squid转发cache丢失到原始服务器时，它在第9域记录原始服务器的IP地址。可以禁止这个指令，以便squid记录主机名：

log_ip_on_direct off

在此情形下，主机名来自于URI。假如URI包含了IP地址，Squid不会将其转换为主机名。

13.2.4.7 client_netmask

该指令存在主要是为了保护用户的隐私。不同于记录完整的IP地址，你也可以掩盖一些位。例如：

client_netmask 255.255.255.0

在此设置下，access.log里的所有客户端IP地址的最后一个八位组是0：

1066036246.918     35 163.11.255.0 TCP_IMS_HIT/304 266 GET http://...

1066036246.932     16 163.11.255.0 TCP_IMS_HIT/304 266 GET http://...

1066036247.616    313 140.132.252.0 TCP_MISS/200 1079 GET http://...

1066036248.598  44459 140.132.252.0 TCP_MISS/500 1531 GET http://...

1066036249.230     17 170.210.173.0 TCP_IMS_HIT/304 265 GET http://...

1066036249.752   2135 140.132.252.0 TCP_MISS/200 50230 GET http://...

1066036250.467      4 170.210.173.0 TCP_IMS_HIT/304 265 GET http://...

1066036250.762    102 163.11.255.0 TCP_IMS_HIT/304 265 GET http://...

1066036250.832     20 163.11.255.0 TCP_IMS_HIT/304 266 GET http://...

1066036251.026     74 203.91.150.0 TCP_CLIENT_REFRESH_MISS/304 267 GET http://...

13.2.4.8 strip_query_terms

该指令是另一个隐私保护功能。在记录请求前，Squid删除了查询条件。假如日志文件不幸落入坏人之手，他们不会找到任何用户名和密码。当该指令激活时，在问号(?)之后的所有字节被删除。例如，某个URI如下：

http://auto.search.msn.com/response.asp?MT=www.kimo.com.yw&srch=3&prov=&utf8

会被记录为：

http://auto.search.msn.com/response.asp?

13.2.4.9 uri_whitespace

早前我提到过出现在某些URI里的空格字符的问题。RFC申明URI必须不包括空格字符，但在实际中情况并非如此。uri_whitespace指令指明Squid如何处理这种情况。允许的设置是：strip (default), deny, allow, encode, 和chop。在这些设置里，strip,encode和chop保证URI域不包含任何空格字符（空格字符会给access.log增加多余的域）。

allow设置允许请求不加修改的通过Squid。它很可能会给重定向器和日志文件解析器带来麻烦。与之相反的是deny设置，它导致Squid拒绝这种请求。用户会接受到错误消息，但请求仍带着空格字符被记录到access.log。

假如设置为encode，Squid将空格字符按RFC 1738规范来编码。这点其实用户代理应该先做到。chop设置导致Squid把第一个空格字符后的URI都截断。

默认设置是strip，它让Squid从URI里移除空格字符。这确保日志文件解析器和重定向器工作正常，但可能会破坏某些事情，例如不正确编码的搜索引擎查询。

13.2.4.10 buffered_logs

默认情况下，Squid禁止写cache.log文件的buffer，这允许你运行tail -f 命令实时的观察日志文件变化。假如你认为这点导致不必要的性能开销，就可以禁用buffer：

buffered_logs off

然而，除非以完整debug模式运行Squid，这点可能无关紧要。注意该选项仅仅影响cache.log。其他的日志文件总使用非缓冲的写方式。

13.2.5 access.log分析工具

access.log包含很多信息，远不止你简单的浏览该文件所见。为了完整的浏览，必须使用第三方的日志文件分析包。你可在Squid的web页面的链接里，找到它们的列表。或者直接访问：http://www.squid-cache.org/Scripts/.

最流行的工具之一是Calamaris -- 一个Perl脚本，解析日志文件并产生基于文本的或HTML的报告。它提供关于会话的详细分类包括请求方式、客户端IP地址、原始服务器域名、内容类型、文件名扩展、响应size、以及更多。Calamaris也报告ICP查询会话，甚至其他cache产品的日志分析。其站点是：http://calamaris.cord.de.

Squeezer以及它的派生Squeezer2，是Squid专有的分析工具。它们提供许多统计，能帮助你了解Squid的性能，特别是在有邻居cache时。两者都产生HTML文件作为输出。squid-cache.org站点的Logfile Analysis页有这些程序的链接。

Webalyzer是另一个有用工具。它运行快速，并且产生带表格和柱形统计表的HTML页面。它原始是设计成分析原始服务器的访问日志的。尽管它能解析Squid的日志，但不会报告诸如命中率和响应时间的事件。它使用的某些条款不同于我的做法。例如，Webalyzer把任何请求叫做一个"命中"，这不同于cache命中。它也把"页面"和"文件"加以区别。更多信息请访问Webalyzer的主页：http://www.mrunix.net/webalyzer/.

13.3 store.log

store.log记录Squid关于存储或删除cache目标的决定。对每个存在cache里的目标、每个不可cache的目标、以及每个被轮换策略删除的目标，Squid都会创建相应的日志条目。该日志文件内容既包含了内存cache又包含了磁盘cache。

store.log提供了下述不能从access.log获取的内容：

• 1）某个特定的响应是否被cache。
• 2）cache目标的文件号。对UFS基础的存储机制，你可转换该文件号到路径名，并且检查cache文件的内容。
• 3）响应的内容长度：包括Content-Length值和实际的body大小。
• 4）Date, Last-Modified, 和Expires头部的值。
• 5）响应的cache关键字（例如MD5哈希值）。

如你所见，这些都是相对低级的信息，在日常管理中可能用不上。除非你要做专业的分析，或打算debug某程序，否则store.log可有可无。可以如下来禁止它：

cache_store_log none

跟其他日志文件一样，Squid将最新的日志条目写到该文件的末尾。某个给定的URI可能出现在日志文件里多次。例如，它先被cache，然后删除，接着又cache住。仅仅最近来的日志条目才反映目标的当前值。

store.log是文本基础的，看起来如下：

1067299212.411 RELEASE -1 FFFFFFFF A5964B32245AC98592D83F9B6EA10B8D 206

    1067299212 1064287906 -1 application/octet-stream 6840/6840

    GET http://download.windowsupdate.com/msdownload/update/v3-19990518/cab...

1067299212.422 SWAPOUT 02 0005FD5F 6F34570785CACABC8DD01ABA5D73B392 200

    1067299210 1057899600 -1 image/gif 1125/1125

    GET http://forum.topsportsnet.com/shf./images/nav_members1.gif

1067299212.641 RELEASE -1 FFFFFFFF B0616CB4B7280F67672A40647DD08474 200

    1067299212 -1 -1 text/html -1/67191

    GET http://www.tlava.com/

1067299212.671 RELEASE -1 FFFFFFFF 5ECD93934257594825659B596D9444BC 200

    1067299023 1034873897 1067299023 image/jpeg 3386/3386

    GET http://ebiz0.ipixmedia.com/abc/ebiz/_EBIZ_3922eabf57d44e2a4c3e7cd234a...

1067299212.786 RELEASE -1 FFFFFFFF B388F7B766B307ADEC044A4099946A21 200

    1067297755 -1 -1 text/html -1/566

    GET http://www.evenflowrocks.com/pages/100303pic15.cfm

1067299212.837 RELEASE -1 FFFFFFFF ABC862C7107F3B7E9FC2D7CA01C8E6A1 304

    1067299212 -1 1067299212 unknown -1/0

    GET http://ebiz0.ipixmedia.com/abc/ebiz/_EBIZ_3922eabf57d44e2a4c3e7cd234a...

1067299212.859 RELEASE -1 FFFFFFFF 5ED2726D4A3AD83CACC8A01CFDD6082B 304

    1066940882 1065063803 -1 application/x-javascript -1/0

    GET http://www.bellsouth.com/scripts/header_footer.js

每个日志条目包含如下13个域：

• 1. 时间戳 事件何时发生，表现为Unix纪元以来的秒数，它是毫秒级的。
• 2. 动作
• cache目标发生的动作。该域有3个可能值：SWAPOUT，RELEASE，和SO_FAIL。
  • 1）SWAPOUT在Squid成功的存储目标到磁盘时发生。某些目标例如那些消极cache的，仅保存在内存而不是磁盘，Squid不会在store.log里记录它们。
  • 2）SO_FAIL表明Squid不能完整的存储目标到磁盘。多半意味着存储机制拒绝以写方式打开新的磁盘文件。
  • 3）RELEASE在Squid从cache里删除目标，或首先就决定响应不可存储时发生。
• 3. 目录号
• 目录号是十进制小数形式，它是个到cache目录的7位索引。对没有存储到磁盘的目标，该域包含-1值。
• 4. 文件号
• 文件号是25位的标识符，内在的被squid使用。它被写成8字符的十六进制号。对UFS基础的存储机制，有算法可以转换文件号到路径名（见13.3.1节）。没有存储到磁盘的目标，没有有效的文件号。对这些目标，该域的值是FFFFFFFF。仅仅在RELEASE和SO_FAIL情况下才会出现这个值。
• 5. cache关键字 Squid使用MD5哈希值作为主要的索引来定位目标。该关键字基于请求方式、URI、和其他可能的信息计算得来。可以从cache关键字来查找store.log条目。然而请注意，目标的cache关键字可能改变。当Squid在access.log里记录TCP_REFRESH_MISS请求时，这点会发生。情况类似如下：

  1065837334.045 SWAPOUT ... 554BACBD2CB2A0C38FF9BF4B2239A9E5 ... http://blah
  
  1066031047.925 RELEASE ... 92AE17121926106EB12FA8054064CABA ... http://blah
  
  1066031048.074 SWAPOUT ... 554BACBD2CB2A0C38FF9BF4B2239A9E5 ... http://blah

  发生了什么呢？该目标原本cache在某个关键字下（554B...）。一段时间后，Squid接受到对该目标的另一请求，并转发确认请求到原始服务器。当响应以新内容返回时，Squid改变旧目标的cache关键字（92AE...），以便它能授予新目标正确的关键字（554B...）。然后旧目标删除，新目标存储到磁盘。
• 6. 状态码
• 该域显示响应的HTTP状态码，跟access.log一样。表13.1是状态码列表。
• 7. 日期
• HTTP响应的Date头部值，表现为Unix纪元以来的秒数。值-1表示Date头部不可解析，-2意味着头部完缺。
• 8. 最后修改时间
• HTTP响应的Last-Modified头部值，表现为Unix纪元以来的秒数。值-1表示Last-Modified头部不可解析，-2意味着头部完缺。
• 9. 过期时间
• HTTP响应的Expires头部值，表现为Unix纪元以来的秒数。值-1表示Expires头部不可解析，-2意味着头部完缺。
• 10. 内容类型
• HTTP响应的Content-Type头部值，排除了任何media-type参数。假如Content-Type丢失了，Squid插入值unknown。
• 11. 内容长度/大小
• 该域包含2个数字，以斜杠分开。第一个是Content-Length头部值。-1表明Content-Length头部不存在。第二个是HTTP消息body的实际大小。你可使用这2个数字来部分的验证接受到的响应，并验证原始服务器是否不正确的计算了内容长度。大多数情形下，这2个数字相等。
• 12. 方式
• 请求目标的HTTP方式，跟access.log里的一样。
• 13. URI
• 最后一个域是请求URI，跟access.log里的一样。该域也有前述章节提到的空格问题。然而，这里不必为此担忧，因为你可安全的忽略任何多余的域。
• 对许多RELEASE的条目，在最后8个域出现的是疑问号(?)。这是因为这些域的大部分值来自squid称为MemObject的结构。该结构仅在目标已被接受时，或目标被完整存储在内存时，才会出现。Squid cache里的大部分目标没有MemObject结构，因为它们仅存在于磁盘。对这些情况，Squid在相应域放置一个疑问号。

13.3.1 转换文件号到路径名

假如想要检查某个特定的cache文件，你可稍费工夫将文件号转换到路径名。另外目录号和L1和L2值也是必需的。在squid的源代码里，storeUfsDirFullPath( )函数做这个事情。可在src/fs/ufs/store_dir_ufs.c文件里找到它。如下短小的perl脚本模拟了当前算法：

#!/usr/bin/perl

$L1 = 16;

$L2 = 256;

while (<>) {

    $filn = hex($_);

    printf("%02X/%02X/%08X\n",

        (($filn / $L2) / $L2) % $L1,

        ($filn / $L2) % $L2,

        $filn);

}

这样使用它：

% echo 000DCD06 | ./fileno-to-pathname.pl

0D/CD/000DCD06

要在第N个cache_dir里找到该文件，简单的进入到相应的目录，并列出或查看该文件：

% cd /cache2

% ls -l 0D/CD/000DCD06

-rw-------  1 squid  squid  391 Jun  3 12:40 0D/CD/000DCD06

    % less 0D/CD/000DCD06

13.4 referer.log

可选的referer.log包含了来自客户端请求的Referer头部。为了使用该功能，必须在./configure时打开--enable-referer-log选项。还必须用referer_log指令来指定一个路径。例如：

referer_log /usr/local/squid/var/logs/referer.log

假如想禁止referer.log，则可设置文件名为none。

Referer头部正常情况下包含一个URI，从这个URI获取到了请求（见RFC2616的14.36节）。例如，当web浏览器发布请求到某个内嵌图片时，Referer头部被设置成包含该图片的HTML网页的URI。当你点击HTML超链接时，它也被设置。某些web站点管理员使用Referer值来查找死链接。在使用Squid作为代理人模式时，你也许发现referer.log特别有用。

referer.log格式简单，仅有4个域。如下是一些示例：

1068047502.377 3.0.168.206

    http://www.amazon.com/exec/obidos/search-handle-form/002-7230223-8205634

    http://www.amazon.com/exec/obidos/ASIN/0596001622/qid=1068047396/sr=2-1/...

1068047503.109 3.0.168.206

    http://www.amazon.com/exec/obidos/ASIN/0596001622/qid=1068047396/sr=2-1/...

    http://g-images.amazon.com/./images/G/01/gourmet/gourmet-segway.gif

1068047503.196 3.0.168.206

    http://www.amazon.com/exec/obidos/ASIN/0596001622/qid=1068047396/sr=2-1/...

    http://g-images.amazon.com/./images/G/01/marketing/cross-shop/arnold/appar...

1068047503.198 3.0.168.206

    http://www.amazon.com/exec/obidos/ASIN/0596001622/qid=1068047396/sr=2-1/...

    http://g-images.amazon.com/./images/G/01/marketing/cross-shop/arnold/appar...

1068047503.825 3.0.168.206

    http://www.amazon.com/exec/obidos/ASIN/0596001622/qid=1068047396/sr=2-1/...

    http://images.amazon.com/./images/P/B00005R8BC.01.TZZZZZZZ.jpg

1068047503.842 3.0.168.206

    http://www.amazon.com/exec/obidos/ASIN/0596001622/qid=1068047396/sr=2-1/...

    http://images.amazon.com/./images/P/0596001622.01._PE_PI_SCMZZZZZZZ_.jpg

注意缺少Referer头部的请求不会被记录。这4个域描述如下：

• 1. 时间戳
• 请求时间，表现为Unix纪元以来的秒数，是毫秒级的。

注意的是，不像access.log，referer.log在Squid接受到完整请求时，会立刻记录。这样，referer.log条目在access.log之前发生，后者等待响应完成才记录。

• 2. 客户端地址
• 客户端地址跟access.log里的一样。log_fqdn和client_netmask指令也影响该日志文件。
• 3. referer
• 来自客户端请求的Referer头部值。注意referer值可能有空格字符或其他字符，在写referer.log前Squid不会对其进行编码。
• 4. URI
• 客户端正请求的URI。它匹配access.log里的URI。

13.5 useragent.log

可选的useragent.log包含来自客户端请求的User-Agent头部值。为了使用该功能，必须在运行./configure时打开--enable-useragent-log选项。还必须使用useragent_log指令来提供一个路径名。例如：

useragent_log /usr/local/squid/var/logs/useragent.log

User-Agent头部正常情况下包含了发起请求的user-agent的描述。大多数情形下，该描述只是简单的产品名列表和版本信息。你应该清楚应用程序可以轻易的提供伪造的user-agent信息。现代user-agent提供途径可定制该描述。甚至Squid在转发请求里能改变这个User-Agent头部。

useragent.log格式相对简单，看起来如下：

3.0.168.206 [05/Nov/2003:08:51:43 -0700]

    "Mozilla/5.0 (compatible; Konqueror/3; FreeBSD)"

3.0.168.207 [05/Nov/2003:08:52:18 -0700]

    "Opera/7.21 (X11; FreeBSD i386; U)  [en]"

4.241.144.204 [05/Nov/2003:08:55:11 -0700]

    "Mozilla/5.0 (Macintosh; U; PPC Mac OS X; en-us) AppleWebKit/103u (KHTM..."

3.0.168.206 [05/Nov/2003:08:51:43 -0700]

    "Java1.3.1_01"

64.68.82.28 [05/Nov/2003:08:52:50 -0700]

    "Googlebot/2.1 (http://www.googlebot.com/bot.html)"

3.0.168.205 [05/Nov/2003:08:52:50 -0700]

    "WebZIP/4.1 (http://www.spidersoft.com)"

4.241.144.201 [05/Nov/2003:08:52:50 -0700]

    "Mozilla/4.0 (compatible; MSIE 5.0; Windows 98; DigExt; Hotbar 3.0)"

3.0.168.206 [05/Nov/2003:08:54:40 -0700]

    "Bookmark Renewal Check Agent [http://www.bookmark.ne.jp/] (Version 2.0..."

不像其他日志文件，它仅有3个域：

• 1. 客户端地址
• 跟access.log里的一样。log_fqdn和client_netmask指令也影响该日志文件。
• 2. 时间戳
• 不像其他日志文件那样，用Unix纪元以来的秒数来描述时间，这里使用人工可读的格式。它是HTTP通用日志文件格式的时间戳，看起来如下：

  [10/Jun/2003:22:38:36 -0600]

  注意方括号界定时间戳，它包含一个空格。也请注意，跟referer.log一样，这些条目在Squid接受到完整请求时，立刻被记录。
• 3. user-agent
• User-Agent头部的值。这些字串几乎总包含空格。在将其写入日志文件时，Squid不会编码User-Agent值。

13.6 swap.state

swap.state文件是目标写入cache目录、或从cache目录删除的日志写照。每个cache_dir有它自己的swap.state文件。当Squid启动时，它读取swap.state文件来重建cache目标的内存索引。这些文件对Squid管理来说，至关重要。

默认情况下，每个cache.state文件位于它相应的cache目录。这样，每个state文件自动驻留在每个cache_dir下。这点很有用－－假如你想重新排序cache_dir行，或想从cache_dir列表里删除条目的话。

如果想将它们放在其他位置，可使用cache_swap_log指令来做：

cache_swap_log /usr/local/squid/var/logs/swap.state

在此情况下，Squid对每个cache目录创建一个swap.state文件，并增加数字后缀。例如，假如有4个cache目录，Squid创建如下日志：

/usr/local/squid/var/logs/swap.state.00

/usr/local/squid/var/logs/swap.state.01

/usr/local/squid/var/logs/swap.state.02

/usr/local/squid/var/logs/swap.state.03

在这个情形下，如果你要增加、删除、或重排序cache_dir行，就必须手工重命名swap.state文件，以保持事情一致。

技术上，swap.state格式是独立于存储机制的。然而，在当前版本的Squid里，所有的存储机制使用同一种格式。swap.state文件使用修正大小（48位）的二进制格式。各个域值以主机字节顺序记录，这样在不同的操作系统之间不便迁移。表13-3描述了swap.state日志条目的各个域的说明。

Table 13-3. swap.state entry fields

13.7 轮转日志

Squid不断的写日志，假如cache非常忙，那么在一段时间后，这些日志文件可能变得很大。某些操作系统甚至限制了文件的最大size（例如2G），假如写文件超过了这个size就会报错。为了保持日志文件容易管理，以及让Squid正常工作，必须定期轮转日志。

Squid有内建的功能用于轮转日志。可通过squid -k rotate命令来调用它，然后告诉Squid对每个日志文件保持多少份旧拷贝。例如，假如设置它为7，对每个日志文件会有8个版本：1个当前的，和7个旧的。

旧日志文件以数字扩展来重命名。例如，当执行一次轮转时，Squid重命名log.6到log.7，然后是log.5到log.6，依此类推。当前log变成log.0，并且Squid创建一个新的空文件，命名为log。

每次执行squid -k rotate时，Squid轮转下述文件：cache.log, access.log, store.log, useragent.log (假如激活), 以及referer.log (假如激活)。Squid也会创建最新版本的swap.state文件。然而请注意，swap.state不会以数字扩展形式来轮转。

Squid不会自己轮转日志，最好的办法是在crontab里自动执行。例如：

0 0 * * * /usr/local/squid/sbin/squid -k rotate

假如你想编写自己的脚本来管理日志文件，Squid提供了一个有用的模式，简单的设置logfile_rotate指令为0。这样，当你运行squid -k rotate命令时，Squid简单的关闭当前日志文件，并且打开新的。如果操作系统允许重命名被其他进程打开的文件，则这点非常有用。下述shell脚本描述了一个思路：

#!/bin/sh

set -e

yesterday_secs=`perl -e 'print time -43200'`

yesterday_date=`date -r $yesterday_secs +%Y%m%d`

cd /usr/local/squid/var/logs

# rename the current log file without interrupting the logging process

mv access.log access.log.$yesterday_date

# tell Squid to close the current logs and open new ones

/usr/local/squid/sbin/squid -k rotate

# give Squid some time to finish writing swap.state files

sleep 60

mv access.log.$yesterday_date /archive/location/

    gzip -9 /archive/location/access.log.$yesterday_date

13.8 隐私和安全

Squid的日志文件特别是access.log，包含了用户的活跃记录，因此它受隐私问题支配。作为Squid管理员，你必须采取额外的小心来保证日志文件安全。最好的办法是限制访问Squid主机的人员的数量。假如这点行不通，那么就要谨慎的检查文件和目录许可，确保日志文件不会被非信任的、或未授权的用户访问。

也可利用client_netmask和strip_query_terms指令来保护用户隐私。前者让识别access.log里的用户困难；后者移除了URI查询条件以避免泄露用户私人信息。更多信息见13.2.4节。

如果想要保持历史数据相当长的时间，你也许可裁减日志来保证日志文件匿名。假如你仅对哪个URI被访问感兴趣，而不是谁访问了它们，就可从access.log里抽取出该域。这样也让文件更小，并且减少了隐私违背的风险。另一个技术是随机处理客户端IP地址。换句话说，就是创建一个过滤器，把真正的IP地址映射到假的地址，前提是同一个真IP地址总是映射到同一个假IP。假如你在使用RFC 1413身份验证协议或HTTP认证，也可考虑保持这些域匿名。