Apache Traffic Server 3.0正式版，我很失望！！

tao_627

研究Traffic Server已经几个月了，最初看得是2.0.1稳定版，后来看过2.1.4，直到最近，欣喜发现Apache已经发布了3.0版本。于是赶紧下载安装，搭建正向代理，调试探索，可是很失望，
因为一直显示502错误，可是，我利用2.1.4搭建正向代理，一切正常没有任何问题。下面是3.0版本的整个交互过程的信息，感兴趣的朋友可以看看，我从不说假话的：


ATS 3.0搭建正向代理出现502错误的整个交互流程：

root@tyx-System-Product-Name:/usr/local/bin# ./traffic_server
[TrafficServer] using root directory '/usr/local'
[Jul  6 08:56:36.765] {3077691088} STATUS: opened /usr/local/var/log/trafficserver/diags.log
[Jul  6 08:56:36.765] {3077691088} NOTE: updated diags config
[Jul  6 08:56:36.766] Server {3077691088} DEBUG: (http_aeua) [HttpConfig::init_aeua_filter] - Config: "/usr/local/etc/trafficserver/ae_ua.config"
[Jul  6 08:56:36.766] Server {3077691088} DEBUG: (http_aeua) [HttpConfig::init_aeua_filter] - Opening config "/usr/local/etc/trafficserver/ae_ua.config"
[Jul  6 08:56:36.766] Server {3077691088} DEBUG: (http_aeua) [HttpConfig::init_aeua_filter] - Added 0 REGEXP filters
[Jul  6 08:56:36.766] Server {3077691088} DEBUG: (http_aeua) [init_http_aeua_filter] - Total loaded 0 REGEXP for Accept-Enconding/User-Agent filtering
[Jul  6 08:56:36.768] Server {3077691088} NOTE: cache clustering disabled
[Jul  6 08:56:36.768] Server {3077691088} NOTE: clearing statistics
[Jul  6 08:56:36.770] Server {3077691088} DEBUG: (dns) ink_dns_init: called with init_called = 0
[Jul  6 08:56:36.779] Server {3077691088} DEBUG: (dns) localhost=tyx-System-Product-Name
[Jul  6 08:56:36.779] Server {3077691088} DEBUG: (dns) Round-robin nameservers = 0
[Jul  6 08:56:36.779] Server {3077691088} DEBUG: (hostdb) Storage path is /usr/local/var/trafficserver
[Jul  6 08:56:36.779] Server {3077691088} DEBUG: (hostdb) Opening host.db, size=200000
[Jul  6 08:56:36.779] Server {3077691088} WARNING: configuration changed: [hostdb.config] : reinitializing database
[Jul  6 08:56:36.779] Server {3077691088} NOTE: reconfiguring host database
[Jul  6 08:56:36.779] Server {3077691088} DEBUG: (hostdb) unable to unlink /usr/local/etc/trafficserver/internal/hostdb.config
[Jul  6 08:56:36.779] Server {3077691088} WARNING: Configured store too small, unable to reconfigure
[Jul  6 08:56:36.779] Server {3077691088} WARNING: unable to initialize database (too little storage)
: [hostdb.config] : disabling database
You may need to 'reconfigure' your cache manually.  Please refer to
the 'Configuration' chapter in the manual.

tao_627

[Jul  6 08:56:36.779] Server {3077691088} WARNING: could not initialize host database. Host database will be disabled
[Jul  6 08:56:36.779] Server {3077691088} WARNING: bad hostdb or storage configuration, hostdb disabled
[Jul  6 08:56:36.780] Server {3077691088} NOTE: cache clustering disabled
[Jul  6 08:56:36.834] Server {3057408880} WARNING: disk header different for disk /usr/local/var/trafficserver/cache.db: clearing the disk
[Jul  6 08:56:36.884] Server {3077691088} NOTE: logging initialized[7], logging_mode = 3
[Jul  6 08:56:36.887] Server {3077691088} DEBUG: (http_init) proxy.config.http.redirection_enabled = 0
[Jul  6 08:56:36.887] Server {3077691088} DEBUG: (http_init) proxy.config.http.number_of_redirections = 1
[Jul  6 08:56:36.887] Server {3077691088} DEBUG: (http_init) proxy.config.http.post_copy_size = 2048
[Jul  6 08:56:36.887] Server {3077691088} DEBUG: (http_tproxy) Primary listen socket transparency is off
[Jul  6 08:56:36.890] Server {3077691088} NOTE: traffic server running
[Jul  6 08:56:36.890] Server {3077691088} DEBUG: (dns) DNSHandler::startEvent: on thread 0
[Jul  6 08:56:36.890] Server {3077691088} DEBUG: (dns) open_con: opening connection 8.8.8.8:53
[Jul  6 08:56:36.890] Server {3077691088} DEBUG: (dns) random port = 42595
[Jul  6 08:56:36.890] Server {3077691088} DEBUG: (dns) opening connection 8.8.8.8:53 SUCCEEDED for 0
[Jul  6 08:56:36.918] Server {3058461552} NOTE: Clearing Disk: /usr/local/var/trafficserver/cache.db
[Jul  6 08:56:36.919] Server {3058461552} NOTE: clearing cache directory '/usr/local/var/trafficserver/cache.db 16384:24575'
[Jul  6 08:56:37.056] Server {3055303536} NOTE: cache enabled
[Jul  6 08:56:45.632] Server {3002059632} DEBUG: (http_tproxy) Marking accepted connect on b328c6e8 as not outbound transparent.
[Jul  6 08:56:45.632] Server {3077691088} DEBUG: (http_seq) HttpAccept:mainEvent] accepted connection
[Jul  6 08:56:45.632] Server {3077691088} DEBUG: (http_cs) [0] session born, netvc 0xa431d60
[Jul  6 08:56:45.633] Server {3077691088} DEBUG: (http_cs) [0] using accept inactivity timeout [120 seconds]
[Jul  6 08:56:45.633] Server {3077691088} DEBUG: (http_cs) [0] Starting transaction 1 using sm [0]
[Jul  6 08:56:45.633] Server {3077691088} DEBUG: (http) [0] [HttpSM::main_handler, VC_EVENT_READ_READY]
[Jul  6 08:56:45.633] Server {3077691088} DEBUG: (http) [0] [&HttpSM::state_read_client_request_header, VC_EVENT_READ_READY]
[Jul  6 08:56:45.633] Server {3077691088} DEBUG: (http) [0] done parsing client request header
[Jul  6 08:56:45.633] Server {3077691088} DEBUG: (http_trans) START HttpTransact::ModifyRequest
[Jul  6 08:56:45.633] Server {3077691088} DEBUG: (http_trans) [ink_cluster_time] local: 1309913805, highest_delta: 0, cluster: 1309913805
[Jul  6 08:56:45.633] Server {3077691088} DEBUG: (http_trans) END HttpTransact::ModifyRequest
[Jul  6 08:56:45.633] Server {3077691088} DEBUG: (http_trans) Next action HTTP_API_READ_REQUEST_HDR; HttpTransact::StartRemapRequest
[Jul  6 08:56:45.633] Server {3077691088} DEBUG: (http) [0] State Transition: STATE_UNDEFINED -> API_READ_REQUEST_HDR
[Jul  6 08:56:45.633] Server {3077691088} DEBUG: (http_trans) START HttpTransact::StartRemapRequest
[Jul  6 08:56:45.633] Server {3077691088} DEBUG: (http_trans) Before Remapping:

tao_627

+++++++++ Incoming Request +++++++++
-- State Machine Id: 0
GET http://www.baidu.com/ HTTP/1.1
Host: www.baidu.com
User-Agent: Mozilla/5.0 (Windows NT 6.1; rv:2.0.1) Gecko/20100101 Firefox/4.0.1
Accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8
Accept-Language: zh-cn,zh;q=0.5
Accept-Encoding: gzip, deflate
Accept-Charset: GB2312,utf-8;q=0.7,*;q=0.7
Keep-Alive: 115
Proxy-Connection: keep-alive
Cookie: BAIDUID=36C3F2905F6D124039D771A6F85E124A:FG=1

[Jul  6 08:56:45.653] Server {3077691088} DEBUG: (http_trans) [DecideCacheLookup] Will do cache lookup.
[Jul  6 08:56:45.653] Server {3077691088} DEBUG: (http_seq) [DecideCacheLookup] Will do cache lookup
[Jul  6 08:56:45.654] Server {3077691088} DEBUG: (http_trans) Next action CACHE_LOOKUP; NULL
[Jul  6 08:56:45.654] Server {3077691088} DEBUG: (http) [0] State Transition: HTTP_API_POST_REMAP -> CACHE_LOOKUP
[Jul  6 08:56:45.654] Server {3077691088} DEBUG: (http_seq) [HttpSM::do_cache_lookup_and_read] [0] Issuing cache lookup for URL http://www.baidu.com/
[Jul  6 08:56:45.654] Server {3077691088} DEBUG: (http_cache) [0] [&HttpCacheSM::state_cache_open_read, CACHE_EVENT_OPEN_READ_FAILED]
[Jul  6 08:56:45.654] Server {3077691088} DEBUG: (http) [0] [HttpSM::main_handler, CACHE_EVENT_OPEN_READ_FAILED]
[Jul  6 08:56:45.654] Server {3077691088} DEBUG: (http) [0] [&HttpSM::state_cache_open_read, CACHE_EVENT_OPEN_READ_FAILED]
[Jul  6 08:56:45.654] Server {3077691088} DEBUG: (http) [0] cache_open_read - CACHE_EVENT_OPEN_READ_FAILED
[Jul  6 08:56:45.654] Server {3077691088} DEBUG: (http) [state_cache_open_read] open read failed.
[Jul  6 08:56:45.654] Server {3077691088} DEBUG: (http_trans) [HttpTransact::HandleCacheOpenRead]
[Jul  6 08:56:45.654] Server {3077691088} DEBUG: (http_trans) CacheOpenRead -- miss
[Jul  6 08:56:45.654] Server {3077691088} DEBUG: (http_trans) Next action DNS_LOOKUP; OSDNSLookup
[Jul  6 08:56:45.654] Server {3077691088} DEBUG: (http) [0] State Transition: CACHE_LOOKUP -> DNS_LOOKUP
[Jul  6 08:56:45.654] Server {3077691088} DEBUG: (http_seq) [HttpStateMachineGet::do_hostdb_lookup] Doing DNS Lookup
[Jul  6 08:56:45.654] Server {3077691088} DEBUG: (http) [0] DNS lookup failed for 'www.baidu.com'
[Jul  6 08:56:45.654] Server {3077691088} DEBUG: (http_trans) [HttpTransact::OSDNSLookup] This was attempt 1
[Jul  6 08:56:45.654] Server {3077691088} DEBUG: (http_seq) [HttpTransact::OSDNSLookup] DNS Lookup unsuccessful
[Jul  6 08:56:45.654] Server {3077691088} DEBUG: (http_trans) [WUTS code generation] Hit/Miss: 49, Log: 117, Hier: 49, Status: 805
[Jul  6 08:56:45.654] Server {3077691088} DEBUG: (http_trans) Adding Server: ATS/3.0.0
+++++++++ Proxy's Response 2 +++++++++
-- State Machine Id: 0
HTTP/1.1 502 Cannot find server.
Date: Wed, 06 Jul 2011 00:56:45 GMT
Proxy-Connection: keep-alive
Server: ATS/3.0.0

[Jul  6 08:56:45.654] Server {3077691088} DEBUG: (http_trans) Next action PROXY_SEND_ERROR_CACHE_NOOP; NULL
[Jul  6 08:56:45.654] Server {3077691088} DEBUG: (http) [0] State Transition: DNS_LOOKUP -> PROXY_SEND_ERROR_CACHE_NOOP
[Jul  6 08:56:45.654] Server {3077691088} DEBUG: (http_tunnel) [0] adding producer 'internal msg'
[Jul  6 08:56:45.654] Server {3077691088} DEBUG: (http_tunnel) [0] adding consumer 'user agent'
[Jul  6 08:56:45.654] Server {3077691088} DEBUG: (http_tunnel) tunnel_run started, p_arg is NULL
[Jul  6 08:56:45.654] Server {3077691088} DEBUG: (http_tunnel) [0] consumer_handler [user agent VC_EVENT_WRITE_COMPLETE]
[Jul  6 08:56:45.654] Server {3077691088} DEBUG: (http) [0] [&HttpSM::tunnel_handler_ua, VC_EVENT_WRITE_COMPLETE]
[Jul  6 08:56:45.654] Server {3077691088} DEBUG: (http_cs) [0] session released by sm [0]
[Jul  6 08:56:45.654] Server {3077691088} DEBUG: (http_cs) [0] initiating io for next header
[Jul  6 08:56:45.654] Server {3077691088} DEBUG: (http) [0] [HttpSM::main_handler, HTTP_TUNNEL_EVENT_DONE]
[Jul  6 08:56:45.654] Server {3077691088} DEBUG: (http) [0] [&HttpSM::tunnel_handler, HTTP_TUNNEL_EVENT_DONE]
[Jul  6 08:56:45.654] Server {3077691088} DEBUG: (http_redirect) [HttpTunnel::deallocate_postdata_copy_buffers]
[Jul  6 08:56:45.654] Server {3077691088} DEBUG: (http_seq) [HttpStateMachineGet::update_stats] Logging transaction
[Jul  6 08:56:45.654] Server {3077691088} DEBUG: (http) [0] dellocating sm

tao_627

大家一定要注意1楼最后几句话，它说明traffic server无法使用hostdb，最终将导致502错误发生，我详细比较了2.1.4和3.0版本的配置文件，以及HostDB.cc和MultiCache.cc这几个文件，并进行了多次调试，最后发现它们几乎100%相同，唯一修改的地方，就是我得到502错误的地方，就是两行代码的修改，导致了这个错误。我以及成功修复了这个502错误的bug。

另外，我写的plugin，在2.1.4版本上测试没有发现问题，可是在3.0上却经常使程序退出，唯一的区别是plugin引用 的API不同，这说明3.0版本的API也存在问题。

可悲的是，现在Apache已经不再提供2.1.9等unstable版本了，而这个他们很引以为傲的3.0，却被我证实漏洞百出，令人失望。

我发这个帖子，期望有缘人共同探讨，进行技术切磋，希望Apache能引起重视，别无它意！

tao_627

是的，这个帖子是我当初研究TS时遇到的问题，早已经解决了，以后大家不用再讨论了。