博客园  :: 首页  :: 新随笔  :: 联系 :: 订阅 订阅  :: 管理

ATS 日志

Posted on 2017-06-09 17:17  bw_0927  阅读(1240)  评论(0)    收藏  举报

http://fengya90.github.io/%E8%BF%90%E7%BB%B4/2015/03/24/ats-log

http://blog.csdn.net/tao_627/article/details/45844287

http://blog.csdn.net/tao_627/article/details/45198385

http://blog.csdn.net/tao_627/article/details/48133655

 

线上日志格式定义如下

<Format = "%<cqtq> %<ttms> %<pssc> %<sssc> [%<cqtt>] %<{X-Forwarded-For}cqh> \"%<cqtx>\" %<psql> \"%<pqsi>\" %<crc>:%<phr> %<{Referer}cqh> \"%<{User-Agent}cqh>\" %<psct>"/>

实例如下：

1432194201.810 8945 200 200  [15:43:21] 211.143.88.220 "GET http://111.13.140.12:80/youku/697814A886D39744A94514B27/03000208005506A3413AA803BAF2B1552E0345-4545-BEED-FC67-17B76E3C0F6D.flv HTTP/1.1" 12979938 "*Not IP address [0]*" TCP_MEM_HIT:NONE http://v.youku.com/v_show/id_XOTEzMjM1Njgw.html?from=y1.3-idx-grid-1519-9909.86808-86807.3-1 "Mozilla/4.0 (compatible; MSIE 6.0; Windows NT 5.1; Trident/4.0;)" video/x-flv

 

1432118160.693 348 200 200 [18:36:00] 10.10.110.142 "GET http://123.126.104.80:80/sohu/s26h23eab6/v1/TmwATmw7qKINgmNVqF16q6bV0esvD6sRPVcXNhWL5m47fFoGRMNiNw.mp4?k=zjXjSK&p=XZhuOp3AjfK&r=TmI20LscWOoCNLfcWOyXwmXAyBj&q=OpCBhW7IWJodRDbsfhASotE7ZDvOfhXOfJ1HfhAHfhysvmbcWJWXfGdtZhNSqD24WYoUZDJ&cip=221.220.19.171 HTTP/1.1" 1010003 "123.126.104.80" TCP_MISS:DIRECT http://tv.sohu.com/20140502/n399076828.shtml "Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/41.0.2272.101 Safari/537.36" video/mp4

 

 

各域名字段说明如下：
{HTTP header field name}cqh  Logs the information in the requested field of the client request HTTP header

例如上面示例的<{Referer}cqh>，会把请求的Referer头信息记录下来

cqtq  

The client request timestamp, with millisecond resolution，unix timestamp，单位是毫秒

ttms  

The time Traffic Server spends processing the client request(处理该请求的总耗时，单位是毫秒，这个时间包括了ATS回源时间stms); the number of milliseconds between the time the client establishes the connection with Traffic Server and the time Traffic Server sends the last byte of the response back to the client.

pssc  

The HTTP response status code from Traffic Server to the client

sssc  

The HTTP response status code from origin server to Traffic Server

cqtt  

The client request timestamp. The time of the client request in the format hh:mm:ss, where hh is the two-digit hour in 24-hour format, mm is the two-digit minutes value,and ss is the 2-digit seconds value (for example, 16:01:19).

{X-Forwarded-For}cqh   记录X-Forwarded-For头信息

X-Forwarded-For header

cqtx 

The full HTTP client request text, minus headers; for example,GET http://www.company.com HTTP/1.0; In reverse proxy mode, Traffic Server logs the rewritten/mappedURL (according to the rules in remap.config), _not_ the pristine/unmapped URL.

psql 

The proxy response transfer length in Squid format (includes header and content length).


hii This is the incoming (interface) IP address for Traffic Server, in otherwords this is the IP address the client connected to.  当前ats是使用哪个网卡接收到的请求

pqsi 

The proxy request server IP address (0 on cache hits and parent-ip for requests to parent proxies).  如果配置了多个parent，该字段将会显示使用的是哪个parent

crc  

The cache result code; specifies how the cache responded to the request (HIT, MISS, and so on).

phr  

The proxy hierarchy route; the route Traffic Server used to retrieve the object.  动作

 

{Referer}cqh  

Referer header

{User-Agent}cqh   

User-Agent header

psct 

The content type of the document from server response header: (for example, img/gif ).

 

更详细的字段分析参见下面的参考文献[1].

参考文献
https://docs.trafficserver.apache.org/en/6.2.x/admin-guide/monitoring/logging/log-formats.en.html

 

%<chi> 客户端IP

%<caun> The username of the authenticated client. A hyphen (-) means that no authentication was required.

%<ttms> 响应时间，单位是毫秒/ms

%<cqts> 时间戳（The time of the client request since January 1, 1970 UTC (EPOCH), with second resolution.）

%<cqhm> The client request method: GET, POST, and so on.

%<cquuc> 原始的URL，即 This field records a URL before it is remapped (reverse proxy mode).

%<cqhv> HTTP版本，The client request HTTP version.

%<pssc> HTTP状态码

%<psql> 边缘server 返回的response长度，包括响应体和响应头，单位是 字节/byte

%<hii> 当前ats是使用哪个网卡接收到的请求

%<crc> 边缘server响应的状态码

%<phr> 回源server响应的状态码， 当前ats待进行的下一步动作

%<pqsi> 当前ats缓存miss,下一跳的parent的地址


 %<{Via}psh> 边缘server响应HTTP头部信息，截取Via信息

%<{Referer}cqh> 客户端请求的HTTP头部信息，截取Referer信息

%<{User-Agent}cqh> 客户端请求的HTTP头部信息，截取User-Agent信息

 

对于状态TCP_MISS:PARENT_HIT

代表当前节点miss，当前节点配置了parent，【该状态只是代表本节点miss了，并且找到了父节点，但父节点能不能响应该请求不确定】，一级一级向上，直到回源　　

假如使用了remap规则(配置了proxy.config.reverse_proxy.enabled)，当请求到达子节点是，它的remap.config将在parent规则之前处理

 

===================================================== 

一个简单的例子

CONFIG proxy.config.log.logfile_dir STRING /ats_logs
CONFIG proxy.config.log.logging_enabled INT 3
CONFIG proxy.config.log.max_space_mb_for_logs INT 25000
CONFIG proxy.config.log.max_space_mb_headroom INT 1000
CONFIG proxy.config.log.squid_log_enabled INT 1
CONFIG proxy.config.log.squid_log_is_ascii INT 1
CONFIG proxy.config.log.rolling_enabled INT 1
CONFIG proxy.config.log.rolling_interval_sec INT 60
CONFIG proxy.config.log.rolling_size_mb INT 10
CONFIG proxy.config.log.auto_delete_rolled_files INT 1

后续日志配置参照上例，详细解释见下文。

日志种类

  • Error log:记录为什么某个特殊的请求出错
  • Event log(access log ):记录每个请求的状态
  • System log:包括traffic server产生的错误或警告，ats集群通讯超时等等

system log一般就是/var/log/messages

默认情况下，Error log和Event log被创建，system information记录在系统日志里。

records.config中有相关配置项proxy.config.log.logging_enabled:

值描述
0 关闭Error log和Event log
1 只关闭Error log
2 只关闭Event log
3 Error log和Event log全开

Event log

日志目录和空间配置

日志目录：

CONFIG proxy.config.log.logfile_dir STRING /ats_logs

日志空间相关配置：

ONFIG proxy.config.log.max_space_mb_for_logs INT 25000
CONFIG proxy.config.log.max_space_mb_headroom INT 1000

日志目录分配了25000MB的大小，如果剩余空间小于1000，将会触发相应行为。例如，如果打开了自动日志删除，则会开始删除日志。

日志格式

ats提供两种类型的日志：

  • 标准格式，例如Squid和Netscape日志
  • 自定义日志

还可以选择按二进制来记录日志还是按ASCII来记录日志。

这里以标准squid格式为例:

CONFIG proxy.config.log.squid_log_enabled INT 1
CONFIG proxy.config.log.squid_log_is_ascii INT 1 #如果是0，就表示使用二进制格式日志

日志滚动(切割)

ATS可以根据时间和日志大小来切割割日志。

CONFIG proxy.config.log.rolling_enabled INT 1 #打开日志切割
CONFIG proxy.config.log.rolling_interval_sec INT 43200  # 切割时间间隔
CONFIG proxy.config.log.rolling_offset_hr INT 5  # 具体解释见下文
CONFIG proxy.config.log.rolling_size_mb INT 10  # 日志大小上限
CONFIG proxy.config.log.auto_delete_rolled_files INT 1  # 自动删除日志

其中proxy.config.log.rolling_enabled：

  • 0: 关闭切割
  • 1: 根据时间切割
  • 2: 根据大小切割
  • 3: 根据大小和时间切割，看哪个限制先到
  • 4: 根据大小和时间切割，要两个条件都满足

config.log.rolling_interval_sec和proxy.config.log.rolling_offset_hr共同决定切割时间。比如上述配置是每天5点和17点切割日志。

参考文献：

 

=======

http://peiqiang.net/2016/03/07/traffic-server-log.html

一：默认日志格式

(1). 没有自定义格式时，由于ats使用默认的二进制编码记录日志，因此只能使用traffic_logcat来查看日志,如下:

相当于cat,查看所有的日志:
[root@mysql trafficserver]# traffic_logcat /var/log/trafficserver/squid.blog

在/etc/trafficserver/ip_allow.config定义好允许PURGE的IP后    (PURGE: 一种http的方法)
[root@mysql trafficserver]# curl -X PURGE -v http://apke.mumayi.com/2016/02/29/3/31274/lanrentingshu_V5.5.1_mumayi_30e3a.apk
* About to connect() to apke.mumayi.com port 80 (#0)
*   Trying 61.135.153.49... connected
* Connected to apke.mumayi.com (61.135.153.49) port 80 (#0)
> PURGE /2016/02/29/3/31274/lanrentingshu_V5.5.1_mumayi_30e3a.apk HTTP/1.1
> User-Agent: curl/7.19.7 (x86_64-redhat-linux-gnu) libcurl/7.19.7 NSS/3.14.0.0 zlib/1.2.3 libidn/1.18 libssh2/1.4.2
> Host: apke.mumayi.com
> Accept: */*
>
< HTTP/1.1 200 OK
< Date: Fri, 04 Mar 2016 06:42:38 GMT
< Connection: keep-alive
< Via: http/1.1 buildhw-08.phx2.fedoraproject.org (ApacheTrafficServer/5.3.0)
< Server: ATS/5.3.0
< Content-Length: 0
<
* Connection #0 to host apke.mumayi.com left intact
* Closing connection #0
[root@mysql trafficserver]# wget -S http://apke.mumayi.com/2016/02/29/3/31274/lanrentingshu_V5.5.1_mumayi_30e3a.apk
--2016-03-04 14:42:55--  http://apke.mumayi.com/2016/02/29/3/31274/lanrentingshu_V5.5.1_mumayi_30e3a.apk
Resolving apke.mumayi.com... 61.135.153.49
Connecting to apke.mumayi.com|61.135.153.49|:80... connected.
HTTP request sent, awaiting response...
  HTTP/1.0 200 OK
  Server: ATS/5.3.0
  Date: Fri, 04 Mar 2016 06:42:54 GMT
  Content-Type: application/vnd.android.package-archive
  Content-Length: 8550063
  Last-Modified: Mon, 29 Feb 2016 12:04:47 GMT
  ETag: "56d433df-8276af"
  Expires: Fri, 11 Mar 2016 06:42:54 GMT
  Cache-Control: max-age=604800
  Accept-Ranges: bytes
  Age: 1
  Connection: keep-alive
  Via: http/1.1 buildhw-08.phx2.fedoraproject.org (ApacheTrafficServer/5.3.0)
Length: 8550063 (8.2M) [application/vnd.android.package-archive]
Saving to: “lanrentingshu_V5.5.1_mumayi_30e3a.apk”

100%[======================================================================================================================================================================================================================>] 8,550,063    816K/s   in 11s

2016-03-04 14:43:06 (748 KB/s) - “lanrentingshu_V5.5.1_mumayi_30e3a.apk” saved [8550063/8550063]

[root@mysql trafficserver]# wget -S http://apke.mumayi.com/2016/02/29/3/31274/lanrentingshu_V5.5.1_mumayi_30e3a.apk
--2016-03-04 14:43:07--  http://apke.mumayi.com/2016/02/29/3/31274/lanrentingshu_V5.5.1_mumayi_30e3a.apk
Resolving apke.mumayi.com... 61.135.153.49
Connecting to apke.mumayi.com|61.135.153.49|:80... connected.
HTTP request sent, awaiting response...
  HTTP/1.0 200 OK
  Server: ATS/5.3.0
  Date: Fri, 04 Mar 2016 06:42:54 GMT
  Content-Type: application/vnd.android.package-archive
  Content-Length: 8550063
  Last-Modified: Mon, 29 Feb 2016 12:04:47 GMT
  ETag: "56d433df-8276af"
  Expires: Fri, 11 Mar 2016 06:42:54 GMT
  Cache-Control: max-age=604800
  Accept-Ranges: bytes
  Age: 13
  Connection: keep-alive
  Via: http/1.1 buildhw-08.phx2.fedoraproject.org (ApacheTrafficServer/5.3.0)
Length: 8550063 (8.2M) [application/vnd.android.package-archive]
Saving to: “lanrentingshu_V5.5.1_mumayi_30e3a.apk.1”

100%[======================================================================================================================================================================================================================>] 8,550,063   --.-K/s   in 0.06s

2016-03-04 14:43:07 (147 MB/s) - “lanrentingshu_V5.5.1_mumayi_30e3a.apk.1” saved [8550063/8550063]




[root@mysql trafficserver]# traffic_logcat -f /var/log/trafficserver/squid.blog
1457073758.531 2 61.135.153.49 TCP_HIT/200 195 PURGE http://120.192.81.163/2016/02/29/3/31274/lanrentingshu_V5.5.1_mumayi_30e3a.apk - NONE/- -
1457073786.707 11355 61.135.153.49 TCP_MISS/200 8550491 GET http://120.192.81.163/2016/02/29/3/31274/lanrentingshu_V5.5.1_mumayi_30e3a.apk - DIRECT/120.192.81.163 application/vnd.android.package-archive
1457073787.727 73 61.135.153.49 TCP_HIT/200 8550492 GET http://120.192.81.163/2016/02/29/3/31274/lanrentingshu_V5.5.1_mumayi_30e3a.apk - NONE/- application/vnd.android.package-archive

traffic_logcat -f  相当于tail -f,
可以看到http://apke.mumayi.com/2016/02/29/3/31274/lanrentingshu_V5.5.1_mumayi_30e3a.apk这个资源，被PURGE后，先miss,接着缓存后，就hit了

(2).更改日志目录,默认日志存放在/var/log/trafficserver:

 CONFIG proxy.config.log.logfile_dir STRING /data0/log/trafficserver

(3).更改默认日志的输出格式，按照ascii码输出日志

CONFIG proxy.config.log.squid_log_is_ascii INT 1
现在可以直接使用cat/tail来查看日志了
[root@mysql trafficserver]# tail -f squid.log
1457320854.684 101 61.135.153.49 TCP_HIT/200 8550496 GET http://120.192.81.163/2016/02/29/3/31274/lanrentingshu_V5.5.1_mumayi_30e3a.apk - NONE/- application/vnd.android.package-archive
1457320856.648 74 61.135.153.49 TCP_HIT/200 8550496 GET http://120.192.81.163/2016/02/29/3/31274/lanrentingshu_V5.5.1_mumayi_30e3a.apk - NONE/- application/vnd.android.package-archive
1457320857.615 78 61.135.153.49 TCP_HIT/200 8550496 GET http://120.192.81.163/2016/02/29/3/31274/lanrentingshu_V5.5.1_mumayi_30e3a.apk - NONE/- application/vnd.android.package-archive
1457320861.788 78 61.135.153.49 TCP_HIT/200 8550496 GET http://120.192.81.163/2016/02/29/3/31274/lanrentingshu_V5.5.1_mumayi_30e3a.apk - NONE/- application/vnd.android.package-archive

(4).关闭squid格式的日志输出

CONFIG proxy.config.log.squid_log_enabled INT 0
再查看日志，发现已经没有输出了
[root@mysql trafficserver]# tail -f squid.log

二：使用自定义格式记录日志

(1).接着上文继续，开启自定义日志格式和设置日志如何存储

修改records.config，开启日志自定义功能
CONFIG proxy.config.log.custom_logs_enabled INT 1
CONFIG proxy.config.log.xml_config_file STRING logs_xml.config   ，6.1.1-rc1版本不支持命令行方式，直接修改文件；必须加，否则不会生成自定义的日志
修改logs_xml.config，设置如何保存日志，默认配置里已经给了很多的LogFormat/LogFilter/LogObject的参考例子，我们这里就简单的定义一个LogObject测试下
<LogObject>
    <Format = "squid"/>
    <Filename = "custom"/>
</LogObject>
查看日志输出
[root@mysql trafficserver]# tail -n 3 custom.log
1457328740.853 0 222.134.5.197 ERR_CONNECT_FAIL/404 588 GET http://61.135.153.49/31.mp3 - NONE/- text/html
1457328740.906 0 222.134.5.197 ERR_CONNECT_FAIL/404 588 GET http://61.135.153.49/31.mp3 - NONE/- text/html
1457328742.483 0 222.134.5.197 ERR_CONNECT_FAIL/404 588 GET http://61.135.153.49/31.mp3 - NONE/- text/html

这里简单的解释下logs_xml.config这个文件的组成，主要由LogFormats/LogFilters/LogObject定义块组成，每一块的含义如下：

LogFormat : object defines the content of the log file using printf-style format strings (看到 printf-style，就猜的出来，说的是按照一种什么风格输出日志，例如日志字段间的分隔用的是逗号分隔还是空格分隔了)

LogFilter :object defines a filter so that you include or exclude certain information from the log file (看到Filter也知道，这个部分是做过滤的，确定最后要输出什么样的信息到日志，例如可以只输出某一个域名的日志或者只输出状态码等于200的日志等等)

LogObject :object specifies all the information needed to produce a log file (这是一个总的定义块，相当于c语言最后的main函数，例如你要自定义输出一个日志，首先要定义一个LogObject,然后里面再包括LogFormat/LogFilter等其他部分；LogObject里，至少要包括Format(决定日志如何输出)和Filename(日志输出到哪)这两个部分。)

三：日志轮询

(1).使用traffic server内部的轮询机制来处理，我们线上的配置如下:

CONFIG proxy.config.log.logging_enabled INT 3
CONFIG proxy.config.log.max_secs_per_buffer INT 5
CONFIG proxy.config.log.max_space_mb_for_logs INT 60000
CONFIG proxy.config.log.max_space_mb_for_orphan_logs INT 25
CONFIG proxy.config.log.max_space_mb_headroom INT 5000

CONFIG proxy.config.log.rolling_enabled INT 3
CONFIG proxy.config.log.rolling_interval_sec INT 86400
CONFIG proxy.config.log.rolling_offset_hr INT 0
CONFIG proxy.config.log.rolling_size_mb INT 1024
CONFIG proxy.config.log.auto_delete_rolled_files INT 1

(2).也可以写自定脚本配合logrotate或者crontab来做

参考资料:

traffic server document:https://docs.trafficserver.apache.org/records.config#logging-configuration

traffic server document:https://docs.trafficserver.apache.org/en/4.2.x/admin/working-log-files.en.html

traffic server document:https://trafficserver.readthedocs.org/en/5.3.x/admin/event-logging-formats.en.html

自定义ATS日志输出内容:https://blog.zymlinux.net/index.php/archives/398

ATS 4.2.3自定义日志文件格式的方法：http://blog.csdn.net/tao_627/article/details/45198385

TrafficServer日志系统配置指南:http://jp.51studyit.com/article/details/76369.htm

 

TCP_HIT happens when squid took the requested information from the cache directories, ie, from the disk. 

TCP_MEM_HIT happens when squid took the requested information from memory, ie, RAM memory. 

https://docs.trafficserver.apache.org/en/6.2.x/admin-guide/monitoring/logging/log-formats.en.html?highlight=tcp_miss#admin-monitoring-logging-cache-result-codes 

但官方文档已经把TCP_MEM_HIT的状态去掉了