From 950462edc1e2570104a0284891dcd2d1d0785da8 Mon Sep 17 00:00:00 2001
From: Chen Yufei <cyf@chenyufei.info>
Date: Thu, 25 Jul 2013 21:30:07 +0800
Subject: [PATCH 01/14] Print set read deadline error message.

---
 proxy.go | 8 ++++----
 1 file changed, 4 insertions(+), 4 deletions(-)

diff --git a/proxy.go b/proxy.go
index b4c8f526..3fa0895f 100644
--- a/proxy.go
+++ b/proxy.go
@@ -742,14 +742,14 @@ func (sv *serverConn) maybeFake() bool {
 }
 
 func setConnReadTimeout(cn net.Conn, d time.Duration, msg string) {
-	if cn.SetReadDeadline(time.Now().Add(d)) != nil {
-		errl.Println("Set readtimeout:", msg)
+	if err := cn.SetReadDeadline(time.Now().Add(d)); err != nil {
+		errl.Println("Set readtimeout:", msg, err)
 	}
 }
 
 func unsetConnReadTimeout(cn net.Conn, msg string) {
-	if cn.SetReadDeadline(zeroTime) != nil {
-		errl.Println("Unset readtimeout:", msg)
+	if err := cn.SetReadDeadline(zeroTime); err != nil {
+		errl.Println("Unset readtimeout:", msg, err)
 	}
 }
 

From 4621a52b5a2952973aff0e58655c74fd4bbe50b4 Mon Sep 17 00:00:00 2001
From: Chen Yufei <cyf@chenyufei.info>
Date: Thu, 25 Jul 2013 22:57:06 +0800
Subject: [PATCH 02/14] Always try parent proxy in case of dial error.

---
 proxy.go | 30 +++++++++++++++---------------
 1 file changed, 15 insertions(+), 15 deletions(-)

diff --git a/proxy.go b/proxy.go
index 3fa0895f..15e10a26 100644
--- a/proxy.go
+++ b/proxy.go
@@ -651,22 +651,22 @@ func (c *clientConn) connect(r *Request, siteInfo *VisitCnt) (srvconn conn, err
 			errMsg = genErrMsg(r, nil, "Direct connection failed, always direct site.")
 			goto fail
 		}
+		// net.Dial does two things: DNS lookup and TCP connection.
+		// GFW may cause failure here: make it time out or reset connection.
 		// debug.Printf("type of err %v\n", reflect.TypeOf(err))
-		// GFW may cause dns lookup fail (net.DNSError),
-		// may also cause connection time out or reset (net.OpError)
-		if maybeBlocked(err) || isDNSError(err) {
-			// Try to create connection by parent proxy
-			var socksErr error
-			if srvconn, socksErr = connectByParentProxy(r.URL); socksErr == nil {
-				c.handleBlockedRequest(r, err)
-				debug.Println("direct connection failed, use parent proxy for", r)
-				return srvconn, nil
-			}
-			errMsg = genErrMsg(r, nil, "Direct and parent proxy connection failed, maybe blocked site.")
-		} else {
-			errl.Printf("direct connection for %s failed, unhandled error: %v\n", r, err)
-			errMsg = genErrMsg(r, nil, "Direct connection failed, unhandled error.")
-		}
+
+		// RST during TCP handshake is valid and would return as connection
+		// refused error. My observation is that GFW does not use RST to stop
+		// TCP handshake.
+		// To simplify things and avoid error in my observation, always try
+		// parent proxy in case of Dial error.
+		var socksErr error
+		if srvconn, socksErr = connectByParentProxy(r.URL); socksErr == nil {
+			c.handleBlockedRequest(r, err)
+			debug.Println("direct connection failed, use parent proxy for", r)
+			return srvconn, nil
+		}
+		errMsg = genErrMsg(r, nil, "Direct and parent proxy connection failed, maybe blocked site.")
 	}
 
 fail:

From 6c210012404b614c3160403aa22b8470e68341fc Mon Sep 17 00:00:00 2001
From: Chen Yufei <cyf@chenyufei.info>
Date: Fri, 26 Jul 2013 23:27:52 +0800
Subject: [PATCH 03/14] Fix response not keep alive by default.

---
 http.go | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/http.go b/http.go
index ede4d854..e896268a 100644
--- a/http.go
+++ b/http.go
@@ -146,7 +146,7 @@ type Response struct {
 	rawByte []byte
 }
 
-var zeroResponse = Response{}
+var zeroResponse = Response{Header: Header{ConnectionKeepAlive: true}}
 
 func (rp *Response) reset() {
 	b := rp.rawByte

From 35dfc9d94696dd38da48f59dc2485f939efc39ac Mon Sep 17 00:00:00 2001
From: Chen Yufei <cyf@chenyufei.info>
Date: Sat, 27 Jul 2013 12:54:56 +0800
Subject: [PATCH 04/14] Rename directionConnection to isDirect.

---
 proxy.go | 6 +++---
 1 file changed, 3 insertions(+), 3 deletions(-)

diff --git a/proxy.go b/proxy.go
index 15e10a26..89cf0f64 100644
--- a/proxy.go
+++ b/proxy.go
@@ -703,7 +703,7 @@ func newServerConn(c conn, url *URL, siteInfo *VisitCnt) *serverConn {
 	return sv
 }
 
-func (sv *serverConn) directConnection() bool {
+func (sv *serverConn) isDirect() bool {
 	return sv.connType == ctDirectConn
 }
 
@@ -712,7 +712,7 @@ func (sv *serverConn) updateVisit() {
 		return
 	}
 	sv.visited = true
-	if sv.directConnection() {
+	if sv.isDirect() {
 		sv.siteInfo.DirectVisit()
 	} else {
 		sv.siteInfo.BlockedVisit()
@@ -738,7 +738,7 @@ func (sv *serverConn) Close() error {
 }
 
 func (sv *serverConn) maybeFake() bool {
-	return sv.state == svConnected && sv.directConnection() && !sv.siteInfo.AlwaysDirect()
+	return sv.state == svConnected && sv.isDirect() && !sv.siteInfo.AlwaysDirect()
 }
 
 func setConnReadTimeout(cn net.Conn, d time.Duration, msg string) {

From b4e9c056dc547f1527808370e44f6bf4e4c1db9e Mon Sep 17 00:00:00 2001
From: Chen Yufei <cyf@chenyufei.info>
Date: Sat, 27 Jul 2013 22:58:09 +0800
Subject: [PATCH 05/14] Reset client timeout count upon getting request.

---
 http.go  | 23 +++++++++++++----------
 proxy.go | 56 ++++++++++++++++++--------------------------------------
 2 files changed, 31 insertions(+), 48 deletions(-)

diff --git a/http.go b/http.go
index e896268a..e0aafc90 100644
--- a/http.go
+++ b/http.go
@@ -12,6 +12,16 @@ import (
 	"time"
 )
 
+const (
+	statusCodeContinue = 100
+)
+
+const (
+	statusBadReq         = "400 Bad Request"
+	statusExpectFailed   = "417 Expectation Failed"
+	statusRequestTimeout = "408 Request Time-out"
+)
+
 type Header struct {
 	ContLen             int64
 	KeepAlive           time.Duration
@@ -127,15 +137,6 @@ func (r *Request) proxyRequestLine() []byte {
 	return r.raw.Bytes()[0:r.reqLnStart]
 }
 
-const (
-	statusCodeContinue = 100
-)
-
-const (
-	statusBadReq       = "400 Bad Request"
-	statusExpectFailed = "417 Expectation Failed"
-)
-
 type Response struct {
 	Status int
 	Reason []byte
@@ -447,7 +448,9 @@ func (h *Header) parseHeader(reader *bufio.Reader, raw *bytes.Buffer, url *URL)
 func parseRequest(c *clientConn, r *Request) (err error) {
 	var s []byte
 	reader := c.bufRd
-	setConnReadTimeout(c, clientConnTimeout, "parseRequest")
+	// make actual timeout a little longer than keep-alive value sent to client
+	setConnReadTimeout(c,
+		clientConnTimeout+time.Duration(c.timeoutCnt)*time.Second, "parseRequest")
 	// parse request line
 	if s, err = reader.ReadSlice('\n'); err != nil {
 		if isErrTimeout(err) {
diff --git a/proxy.go b/proxy.go
index 89cf0f64..17712c12 100644
--- a/proxy.go
+++ b/proxy.go
@@ -216,13 +216,6 @@ func isSelfURL(url string) bool {
 	return url == ""
 }
 
-func (c *clientConn) getRequest(r *Request) (err error) {
-	if err = parseRequest(c, r); err != nil {
-		return c.handleClientReadError(r, err, "parse client request")
-	}
-	return nil
-}
-
 func (c *clientConn) serveSelfURL(r *Request) (err error) {
 	if r.Method != "GET" {
 		goto end
@@ -297,15 +290,29 @@ func (c *clientConn) serve() {
 		if c.shouldCleanServerConn() {
 			c.cleanServerConn()
 		}
-		if err = c.getRequest(&r); err != nil {
-			if err == errClientTimeout {
-				continue
+
+		if err = parseRequest(c, &r); err != nil {
+			if debug {
+				debug.Printf("client: %s parse request %v\n", c.RemoteAddr(), err)
 			}
-			if err != errShouldClose {
+			if err == io.EOF || isErrConnReset(err) {
+				return
+			}
+			if err != errClientTimeout {
 				sendErrorPage(c, "404 Bad request", "Bad request", err.Error())
+				return
 			}
+			c.timeoutCnt++
+			if c.timeoutCnt < clientMaxTimeoutCnt {
+				c.cleanServerConn()
+				continue
+			}
+			sendErrorPage(c, statusRequestTimeout, statusRequestTimeout,
+				"Your browser didn't send a complete request in time.")
 			return
 		}
+		// next getRequest should start with timeout count 0
+		c.timeoutCnt = 0
 		if dbgRq {
 			if verbose {
 				dbgRq.Printf("request from client %s: %s\n%s", c.RemoteAddr(), &r, r.Verbose())
@@ -432,33 +439,6 @@ func (c *clientConn) handleServerWriteError(r *Request, sv *serverConn, err erro
 	return RetryError{err}
 }
 
-func (c *clientConn) handleClientReadError(r *Request, err error, msg string) error {
-	if err == errClientTimeout {
-		c.timeoutCnt++
-		if c.timeoutCnt >= clientMaxTimeoutCnt {
-			debug.Printf("%s client maybe has closed\n", msg)
-			return errShouldClose
-		}
-		debug.Printf("%s client read timeout\n", msg)
-		c.cleanServerConn()
-		return err
-	}
-
-	if !debug {
-		return err
-	}
-
-	if err == io.EOF {
-		debug.Printf("%s client closed connection", msg)
-	} else if isErrConnReset(err) {
-		debug.Printf("%s connection reset", msg)
-	} else {
-		// may reach here when header is larger than buffer size or got malformed HTTP request
-		debug.Printf("handleClientReadError: %s %v %v\n", msg, err, r)
-	}
-	return err
-}
-
 func (c *clientConn) handleClientWriteError(r *Request, err error, msg string) error {
 	// debug.Printf("handleClientWriteError: %s %v %v\n", msg, err, r)
 	return err

From 9e28987aac997c63b7469a104ecbba8b68fa9e58 Mon Sep 17 00:00:00 2001
From: Chen Yufei <cyf@chenyufei.info>
Date: Sun, 28 Jul 2013 00:28:14 +0800
Subject: [PATCH 06/14] Remove handleClientWriteError.

---
 proxy.go | 9 ++-------
 1 file changed, 2 insertions(+), 7 deletions(-)

diff --git a/proxy.go b/proxy.go
index 17712c12..da64df5d 100644
--- a/proxy.go
+++ b/proxy.go
@@ -439,11 +439,6 @@ func (c *clientConn) handleServerWriteError(r *Request, sv *serverConn, err erro
 	return RetryError{err}
 }
 
-func (c *clientConn) handleClientWriteError(r *Request, err error, msg string) error {
-	// debug.Printf("handleClientWriteError: %s %v %v\n", msg, err, r)
-	return err
-}
-
 func (c *clientConn) readResponse(sv *serverConn, r *Request, rp *Response) (err error) {
 	sv.initBuf()
 	defer func() {
@@ -476,7 +471,7 @@ func (c *clientConn) readResponse(sv *serverConn, r *Request, rp *Response) (err
 	r.releaseBuf()
 
 	if _, err = c.Write(rp.rawResponse()); err != nil {
-		return c.handleClientWriteError(r, err, "Write response header back to client")
+		return err
 	}
 	if dbgRep {
 		if verbose {
@@ -503,7 +498,7 @@ func (c *clientConn) readResponse(sv *serverConn, r *Request, rp *Response) (err
 			} else if isErrOpRead(err) {
 				return c.handleServerReadError(r, sv, err, "Read response body from server.")
 			} else if isErrOpWrite(err) {
-				return c.handleClientWriteError(r, err, "Write response body to client.")
+				return err
 			}
 			errl.Println("sendBody unknown network op error", reflect.TypeOf(err), r)
 			return errShouldClose

From 1ebb4d39da3bc763fc32b1e8bd013348ca98833f Mon Sep 17 00:00:00 2001
From: Chen Yufei <cyf@chenyufei.info>
Date: Sun, 28 Jul 2013 01:03:35 +0800
Subject: [PATCH 07/14] Do not take special handling on log with debug option.

---
 log.go | 8 ++------
 1 file changed, 2 insertions(+), 6 deletions(-)

diff --git a/log.go b/log.go
index 8f8aba5d..221a08a5 100644
--- a/log.go
+++ b/log.go
@@ -1,6 +1,6 @@
 package main
 
-// This trick is learnt from a post by Rob Pike
+// This logging trick is learnt from a post by Rob Pike
 // https://groups.google.com/d/msg/golang-nuts/gU7oQGoCkmg/j3nNxuS2O_sJ
 
 import (
@@ -49,11 +49,7 @@ func init() {
 
 func initLog() {
 	logFile = os.Stdout
-	if bool(debug) && !isWindows {
-		// On windows, we don't know if the terminal supports ANSI color, so
-		// does not turn color by default in debug mode
-		colorize = true
-	} else if config.LogFile != "" {
+	if config.LogFile != "" {
 		if f, err := os.OpenFile(expandTilde(config.LogFile),
 			os.O_CREATE|os.O_WRONLY|os.O_APPEND, 0600); err != nil {
 			fmt.Printf("Can't open log file, logging to stdout: %v\n", err)

From 90102b06f9d4af5d64577ecd9e1176508ed9915a Mon Sep 17 00:00:00 2001
From: Chen Yufei <cyf@chenyufei.info>
Date: Sun, 28 Jul 2013 09:47:13 +0800
Subject: [PATCH 08/14] Use debug log to print parent proxy.

---
 parent_proxy.go | 7 +++----
 1 file changed, 3 insertions(+), 4 deletions(-)

diff --git a/parent_proxy.go b/parent_proxy.go
index 23ddaaf8..ee8a1596 100644
--- a/parent_proxy.go
+++ b/parent_proxy.go
@@ -4,7 +4,6 @@ import (
 	"encoding/base64"
 	"encoding/binary"
 	"errors"
-	"fmt"
 	ss "github.com/shadowsocks/shadowsocks-go/shadowsocks"
 	"io"
 	"math/rand"
@@ -81,11 +80,11 @@ func printParentProxy() {
 	for _, pp := range parentProxy {
 		switch pc := pp.proxyConnector.(type) {
 		case *shadowsocksParent:
-			fmt.Println("\tshadowsocks: ", pc.server)
+			debug.Println("\tshadowsocks: ", pc.server)
 		case *httpParent:
-			fmt.Println("\thttp parent: ", pc.server)
+			debug.Println("\thttp parent: ", pc.server)
 		case socksParent:
-			fmt.Println("\tsocks parent: ", pc.server)
+			debug.Println("\tsocks parent: ", pc.server)
 		}
 	}
 }

From 8147afc57e6eb44fec73266ef2e31ea38d80b1cf Mon Sep 17 00:00:00 2001
From: Chen Yufei <cyf@chenyufei.info>
Date: Sun, 28 Jul 2013 10:28:42 +0800
Subject: [PATCH 09/14] Change default keep-alive value to 15s.

---
 proxy.go | 7 ++++---
 1 file changed, 4 insertions(+), 3 deletions(-)

diff --git a/proxy.go b/proxy.go
index da64df5d..5ca13577 100644
--- a/proxy.go
+++ b/proxy.go
@@ -29,6 +29,9 @@ const httpBufSize = 8192
 // holding post data.
 var httpBuf = leakybuf.NewLeakyBuf(512, httpBufSize)
 
+// If no keep-alive header in response, use this as the keep-alive value.
+const defaultServerConnTimeout = 15 * time.Second
+
 // Close client connection if no new request received in some time. To prevent
 // keeping too many idle (keep-alive) server connections, COW timeout read for
 // the initial request line after clientConnTimeout, and closes client
@@ -512,9 +515,7 @@ func (c *clientConn) readResponse(sv *serverConn, r *Request, rp *Response) (err
 	*/
 	if rp.ConnectionKeepAlive {
 		if rp.KeepAlive == time.Duration(0) {
-			// Apache 2.2 timeout defaults to 5 seconds.
-			const serverConnTimeout = 5 * time.Second
-			sv.willCloseOn = time.Now().Add(serverConnTimeout)
+			sv.willCloseOn = time.Now().Add(defaultServerConnTimeout)
 		} else {
 			sv.willCloseOn = time.Now().Add(rp.KeepAlive - time.Second)
 		}

From 76dbf0ed8068f96e8f79b79a66f9d70eb3158e32 Mon Sep 17 00:00:00 2001
From: Chen Yufei <cyf@chenyufei.info>
Date: Sun, 28 Jul 2013 00:59:01 +0800
Subject: [PATCH 10/14] Collect client&server connection count, better debug
 message.

Some debug messages now contain "client: <remote addr>", we can group debug
message by client by grep and sorting on remote addr.
---
 http.go  |   4 +-
 main.go  |   2 +
 proxy.go | 130 +++++++++++++++++++++++++++++++++++--------------------
 stat.go  |  47 ++++++++++++++++++++
 4 files changed, 133 insertions(+), 50 deletions(-)
 create mode 100644 stat.go

diff --git a/http.go b/http.go
index e0aafc90..29935759 100644
--- a/http.go
+++ b/http.go
@@ -449,7 +449,7 @@ func parseRequest(c *clientConn, r *Request) (err error) {
 	var s []byte
 	reader := c.bufRd
 	// make actual timeout a little longer than keep-alive value sent to client
-	setConnReadTimeout(c,
+	setConnReadTimeout(c.Conn,
 		clientConnTimeout+time.Duration(c.timeoutCnt)*time.Second, "parseRequest")
 	// parse request line
 	if s, err = reader.ReadSlice('\n'); err != nil {
@@ -458,7 +458,7 @@ func parseRequest(c *clientConn, r *Request) (err error) {
 		}
 		return err
 	}
-	unsetConnReadTimeout(c, "parseRequest")
+	unsetConnReadTimeout(c.Conn, "parseRequest")
 	// debug.Printf("Request line %s", s)
 
 	r.reset()
diff --git a/main.go b/main.go
index 00e5e163..2d9f6df4 100644
--- a/main.go
+++ b/main.go
@@ -50,6 +50,8 @@ func main() {
 	initSiteStat()
 	initPAC() // initPAC uses siteStat, so must init after site stat
 
+	initStat()
+
 	if len(parentProxy) == 0 {
 		info.Println("no parent proxy server, can't handle blocked sites")
 	} else {
diff --git a/proxy.go b/proxy.go
index 5ca13577..72380ef4 100644
--- a/proxy.go
+++ b/proxy.go
@@ -175,23 +175,24 @@ func (py *Proxy) Serve(done chan byte) {
 			debug.Println("client connection:", err)
 			continue
 		}
-		if debug {
-			debug.Println("new client:", conn.RemoteAddr())
-		}
 		c := newClientConn(conn, py)
 		go c.serve()
 	}
 }
 
-func newClientConn(rwc net.Conn, proxy *Proxy) *clientConn {
+func newClientConn(cli net.Conn, proxy *Proxy) *clientConn {
 	buf := httpBuf.Get()
 	c := &clientConn{
-		Conn:       rwc,
+		Conn:       cli,
 		serverConn: map[string]*serverConn{},
 		buf:        buf,
-		bufRd:      bufio.NewReaderFromBuf(rwc, buf),
+		bufRd:      bufio.NewReaderFromBuf(cli, buf),
 		proxy:      proxy,
 	}
+	if debug {
+		debug.Printf("cli(%s) connected, total %d clients\n",
+			cli.RemoteAddr(), incCliCnt())
+	}
 	return c
 }
 
@@ -204,15 +205,16 @@ func (c *clientConn) releaseBuf() {
 	}
 }
 
-func (c *clientConn) Close() error {
+func (c *clientConn) Close() {
 	c.releaseBuf()
 	for _, sv := range c.serverConn {
-		sv.Close()
+		sv.Close(c)
 	}
 	if debug {
-		debug.Printf("Client %v connection closed\n", c.RemoteAddr())
+		debug.Printf("cli(%s) closed, total %d clients\n",
+			c.RemoteAddr(), decCliCnt())
 	}
-	return c.Conn.Close()
+	c.Conn.Close()
 }
 
 func isSelfURL(url string) bool {
@@ -269,6 +271,16 @@ func (c *clientConn) shouldRetry(r *Request, sv *serverConn, re error) bool {
 	return true
 }
 
+func dbgPrintRq(c *clientConn, r *Request) {
+	if dbgRq {
+		if verbose {
+			dbgRq.Printf("cli(%s) request  %s\n%s", c.RemoteAddr(), r, r.Verbose())
+		} else {
+			dbgRq.Printf("cli(%s) request  %s\n", c.RemoteAddr(), r)
+		}
+	}
+}
+
 func (c *clientConn) serve() {
 	var r Request
 	var rp Response
@@ -296,7 +308,7 @@ func (c *clientConn) serve() {
 
 		if err = parseRequest(c, &r); err != nil {
 			if debug {
-				debug.Printf("client: %s parse request %v\n", c.RemoteAddr(), err)
+				debug.Printf("cli(%s) parse request %v\n", c.RemoteAddr(), err)
 			}
 			if err == io.EOF || isErrConnReset(err) {
 				return
@@ -316,13 +328,7 @@ func (c *clientConn) serve() {
 		}
 		// next getRequest should start with timeout count 0
 		c.timeoutCnt = 0
-		if dbgRq {
-			if verbose {
-				dbgRq.Printf("request from client %s: %s\n%s", c.RemoteAddr(), &r, r.Verbose())
-			} else {
-				dbgRq.Printf("request from client %s: %s\n", c.RemoteAddr(), &r)
-			}
-		}
+		dbgPrintRq(c, &r)
 
 		if isSelfURL(r.URL.HostPort) {
 			if err = c.serveSelfURL(&r); err != nil {
@@ -359,7 +365,7 @@ func (c *clientConn) serve() {
 	retry:
 		r.tryOnce()
 		if bool(debug) && r.isRetry() {
-			errl.Printf("%s retry request tryCnt=%d %v\n", c.RemoteAddr(), r.tryCnt, &r)
+			errl.Printf("cli(%s) retry request tryCnt=%d %v\n", c.RemoteAddr(), r.tryCnt, &r)
 		}
 		if sv, err = c.getServerConn(&r); err != nil {
 			// debug.Printf("Failed to get serverConn for %s %v\n", c.RemoteAddr(), r)
@@ -374,7 +380,7 @@ func (c *clientConn) serve() {
 
 		if r.isConnect {
 			err = sv.doConnect(&r, c)
-			sv.Close()
+			sv.Close(c)
 			if c.shouldRetry(&r, sv, err) {
 				// connection for CONNECT is not reused, no need to remove
 				goto retry
@@ -394,7 +400,9 @@ func (c *clientConn) serve() {
 		}
 
 		if !r.ConnectionKeepAlive {
-			// debug.Println("close client connection because request has no keep-alive")
+			if debug {
+				debug.Println("cli(%s) close connection", c.RemoteAddr())
+			}
 			return
 		}
 	}
@@ -417,7 +425,7 @@ func (c *clientConn) handleServerReadError(r *Request, sv *serverConn, err error
 	var errMsg string
 	if err == io.EOF {
 		if debug {
-			debug.Printf("client %s; %s read from server EOF\n", c.RemoteAddr(), msg)
+			debug.Printf("cli(%s) %s read from server EOF\n", c.RemoteAddr(), msg)
 		}
 		return RetryError{err}
 	}
@@ -442,6 +450,18 @@ func (c *clientConn) handleServerWriteError(r *Request, sv *serverConn, err erro
 	return RetryError{err}
 }
 
+func dbgPrintRep(c *clientConn, r *Request, rp *Response) {
+	if dbgRep {
+		if verbose {
+			dbgRep.Printf("cli(%s) response %s %s\n%s",
+				c.RemoteAddr(), r, rp, rp.Verbose())
+		} else {
+			dbgRep.Printf("cli(%s) response %s %s\n",
+				c.RemoteAddr(), r, rp)
+		}
+	}
+}
+
 func (c *clientConn) readResponse(sv *serverConn, r *Request, rp *Response) (err error) {
 	sv.initBuf()
 	defer func() {
@@ -476,14 +496,8 @@ func (c *clientConn) readResponse(sv *serverConn, r *Request, rp *Response) (err
 	if _, err = c.Write(rp.rawResponse()); err != nil {
 		return err
 	}
-	if dbgRep {
-		if verbose {
-			// extra space after resposne to align with request debug message
-			dbgRep.Printf("response  to client %v: %s %s\n%s", c.RemoteAddr(), r, rp, rp.Verbose())
-		} else {
-			dbgRep.Printf("response  to client %v: %s %s\n", c.RemoteAddr(), r, rp)
-		}
-	}
+	dbgPrintRep(c, r, rp)
+
 	rp.releaseBuf()
 
 	if rp.hasBody(r.Method) {
@@ -513,13 +527,21 @@ func (c *clientConn) readResponse(sv *serverConn, r *Request, rp *Response) (err
 			debug.Printf("[Finished] %v request %s %s\n", c.RemoteAddr(), r.Method, r.URL)
 		}
 	*/
+	var remoteAddr string // avoid evaluating c.RemoteAddr() in the following debug call
+	if debug {
+		remoteAddr = c.RemoteAddr().String()
+	}
 	if rp.ConnectionKeepAlive {
 		if rp.KeepAlive == time.Duration(0) {
 			sv.willCloseOn = time.Now().Add(defaultServerConnTimeout)
 		} else {
-			sv.willCloseOn = time.Now().Add(rp.KeepAlive - time.Second)
+			debug.Printf("cli(%s) server %s keep-alive %v\n",
+				remoteAddr, sv.url.HostPort, rp.KeepAlive)
+			sv.willCloseOn = time.Now().Add(rp.KeepAlive)
 		}
 	} else {
+		debug.Printf("cli(%s) server %s close connection\n",
+			remoteAddr, sv.url.HostPort)
 		c.removeServerConn(sv)
 	}
 	return
@@ -532,9 +554,6 @@ func (c *clientConn) shouldCleanServerConn() bool {
 
 // Remove all maybe closed server connection
 func (c *clientConn) cleanServerConn() {
-	if debug {
-		debug.Printf("%s client clean up idle server connection", c.RemoteAddr())
-	}
 	now := time.Now()
 	c.cleanedOn = now
 	for _, sv := range c.serverConn {
@@ -542,6 +561,10 @@ func (c *clientConn) cleanServerConn() {
 			c.removeServerConn(sv)
 		}
 	}
+	if debug {
+		debug.Printf("cli(%s) close idle connections, remains %d\n",
+			c.RemoteAddr(), len(c.serverConn))
+	}
 }
 
 func (c *clientConn) getServerConn(r *Request) (sv *serverConn, err error) {
@@ -558,7 +581,7 @@ func (c *clientConn) getServerConn(r *Request) (sv *serverConn, err error) {
 }
 
 func (c *clientConn) removeServerConn(sv *serverConn) {
-	sv.Close()
+	sv.Close(c)
 	delete(c.serverConn, sv.url.HostPort)
 }
 
@@ -573,7 +596,7 @@ func connectDirect(url *URL, siteInfo *VisitCnt) (conn, error) {
 		debug.Printf("error direct connect to: %s %v\n", url.HostPort, err)
 		return zeroConn, err
 	}
-	debug.Println("connected to", url.HostPort)
+	// debug.Println("directly connected to", url.HostPort)
 	return conn{ctDirectConn, c, nil}, nil
 }
 
@@ -588,6 +611,8 @@ func maybeBlocked(err error) bool {
 	return isErrTimeout(err) || isErrConnReset(err)
 }
 
+// Connect to requested server according to whether it's visit count.
+// If direct connection fails, try parent proxies.
 func (c *clientConn) connect(r *Request, siteInfo *VisitCnt) (srvconn conn, err error) {
 	var errMsg string
 	if config.AlwaysProxy {
@@ -662,6 +687,10 @@ func (c *clientConn) createServerConn(r *Request) (*serverConn, error) {
 		return sv, nil
 	}
 	c.serverConn[sv.url.HostPort] = sv
+	if debug {
+		debug.Printf("cli(%s) connected to %s %d concurrent connections\n",
+			c.RemoteAddr(), sv.url.HostPort, incSrvConnCnt(sv.url.HostPort))
+	}
 	// client will connect to differnet servers in a single proxy connection
 	// debug.Printf("serverConn to for client %v %v\n", c.RemoteAddr(), c.serverConn)
 	return sv, nil
@@ -702,14 +731,17 @@ func (sv *serverConn) initBuf() {
 	}
 }
 
-func (sv *serverConn) Close() error {
-	debug.Println("Closing server conn:", sv.url.HostPort)
+func (sv *serverConn) Close(c *clientConn) error {
 	sv.bufRd = nil
 	if sv.buf != nil {
 		// debug.Println("release server buffer")
 		httpBuf.Put(sv.buf)
 		sv.buf = nil
 	}
+	if debug {
+		debug.Printf("cli(%s) close connection to %s remains %d concurrent connections\n",
+			c.RemoteAddr(), sv.url.HostPort, decSrvConnCnt(sv.url.HostPort))
+	}
 	return sv.Conn.Close()
 }
 
@@ -736,11 +768,11 @@ func (sv *serverConn) setReadTimeout(msg string) {
 	if sv.siteInfo.OnceBlocked() && to > defaultReadTimeout {
 		to = minReadTimeout
 	}
-	setConnReadTimeout(sv, to, msg)
+	setConnReadTimeout(sv.Conn, to, msg)
 }
 
 func (sv *serverConn) unsetReadTimeout(msg string) {
-	unsetConnReadTimeout(sv, msg)
+	unsetConnReadTimeout(sv.Conn, msg)
 }
 
 func (sv *serverConn) maybeSSLErr(cliStart time.Time) bool {
@@ -851,7 +883,7 @@ func copyClient2Server(c *clientConn, sv *serverConn, r *Request, srvStopped not
 	defer func() {
 		if deadlineIsSet {
 			// maybe need to retry, should unset timeout here because
-			unsetConnReadTimeout(c, "cli->srv after err")
+			unsetConnReadTimeout(c.Conn, "cli->srv after err")
 		}
 		done <- 1
 	}()
@@ -880,7 +912,8 @@ func copyClient2Server(c *clientConn, sv *serverConn, r *Request, srvStopped not
 			}
 		}
 		if debug {
-			debug.Printf("cli->srv client %s released read buffer\n", c.RemoteAddr())
+			debug.Printf("cli(%s)->srv(%s) released read buffer\n",
+				c.RemoteAddr(), r.URL.HostPort)
 		}
 		c.releaseBuf()
 	}
@@ -896,11 +929,11 @@ func copyClient2Server(c *clientConn, sv *serverConn, r *Request, srvStopped not
 	for {
 		// debug.Println("cli->srv")
 		if sv.maybeFake() {
-			setConnReadTimeout(c, time.Second, "cli->srv")
+			setConnReadTimeout(c.Conn, time.Second, "cli->srv")
 			deadlineIsSet = true
 		} else if deadlineIsSet {
 			// maybeFake may trun to false after timeout, but timeout should be unset
-			unsetConnReadTimeout(c, "cli->srv before read")
+			unsetConnReadTimeout(c.Conn, "cli->srv before read")
 			deadlineIsSet = false
 		}
 		if n, err = c.Read(buf); err != nil {
@@ -942,7 +975,7 @@ func (sv *serverConn) doConnect(r *Request, c *clientConn) (err error) {
 		// debug.Printf("%s Sending CONNECT request to http proxy server\n", c.RemoteAddr())
 		if err = sv.sendHTTPProxyRequest(r, c); err != nil {
 			if debug {
-				debug.Printf("%s error sending CONNECT request to http proxy server: %v\n",
+				debug.Printf("cli(%s) error sending CONNECT request to http proxy server: %v\n",
 					c.RemoteAddr(), err)
 			}
 			return err
@@ -951,7 +984,8 @@ func (sv *serverConn) doConnect(r *Request, c *clientConn) (err error) {
 		// debug.Printf("send connection confirmation to %s->%s\n", c.RemoteAddr(), r.URL.HostPort)
 		if _, err = c.Write(connEstablished); err != nil {
 			if debug {
-				debug.Printf("%s error sending 200 Connecion established: %v\n", c.RemoteAddr(), err)
+				debug.Printf("cli(%s) error sending 200 Connecion established: %v\n",
+					c.RemoteAddr(), err)
 			}
 			return err
 		}
@@ -963,7 +997,7 @@ func (sv *serverConn) doConnect(r *Request, c *clientConn) (err error) {
 	go func() {
 		// debug.Printf("doConnect: cli(%s)->srv(%s)\n", c.RemoteAddr(), r.URL.HostPort)
 		cli2srvErr = copyClient2Server(c, sv, r, srvStopped, done)
-		sv.Close() // close sv to force read from server in copyServer2Client return
+		sv.Close(c) // close sv to force read from server in copyServer2Client return
 	}()
 
 	// debug.Printf("doConnect: srv(%s)->cli(%s)\n", r.URL.HostPort, c.RemoteAddr())
@@ -1049,7 +1083,7 @@ func (sv *serverConn) doRequest(c *clientConn, r *Request, rp *Response) (err er
 			return
 		}
 		if debug {
-			debug.Printf("%s %s body sent\n", c.RemoteAddr(), r)
+			debug.Printf("cli(%s) %s request body sent\n", c.RemoteAddr(), r)
 		}
 	}
 	r.state = rsSent
diff --git a/stat.go b/stat.go
new file mode 100644
index 00000000..ba83907a
--- /dev/null
+++ b/stat.go
@@ -0,0 +1,47 @@
+// Proxy statistics.
+
+package main
+
+import (
+	"sync"
+	"sync/atomic"
+)
+
+var status struct {
+	cliCnt          int32          // number of client connections
+	srvConnCnt      map[string]int // number of connections for each host:port
+	srvConnCntMutex sync.Mutex
+}
+
+func initStat() {
+	if !debug {
+		return
+	}
+	status.srvConnCnt = make(map[string]int)
+}
+
+func incCliCnt() int32 {
+	atomic.AddInt32(&status.cliCnt, 1)
+	return status.cliCnt
+}
+
+func decCliCnt() int32 {
+	atomic.AddInt32(&status.cliCnt, -1)
+	return status.cliCnt
+}
+
+func addSrvConnCnt(srv string, delta int) int {
+	status.srvConnCntMutex.Lock()
+	status.srvConnCnt[srv] += delta
+	cnt := status.srvConnCnt[srv]
+	status.srvConnCntMutex.Unlock()
+	return int(cnt)
+}
+
+func incSrvConnCnt(srv string) int {
+	return addSrvConnCnt(srv, 1)
+}
+
+func decSrvConnCnt(srv string) int {
+	return addSrvConnCnt(srv, -1)
+}

From 011b6064be44f6c61e4f59564d9f3390f0dd9385 Mon Sep 17 00:00:00 2001
From: Chen Yufei <cyf@chenyufei.info>
Date: Sun, 28 Jul 2013 13:52:46 +0800
Subject: [PATCH 11/14] Script to group log by client.

---
 script/log-group-by-client.sh | 17 +++++++++++++++++
 1 file changed, 17 insertions(+)
 create mode 100755 script/log-group-by-client.sh

diff --git a/script/log-group-by-client.sh b/script/log-group-by-client.sh
new file mode 100755
index 00000000..90847709
--- /dev/null
+++ b/script/log-group-by-client.sh
@@ -0,0 +1,17 @@
+#!/bin/bash
+
+if [[ $# != 1 ]]; then
+    echo "Usage: $0 <log file>"
+    exit 1
+fi
+
+log=$1
+
+#clients=`egrep 'cli\([^)]+\) connected, total' $log | cut -d ' ' -f 4`
+
+#for c in $clients; do
+    #echo $c
+#done
+
+sort --stable --key 4,4 --key 3,3 $log | sed -e "/closed, total/s,\$,\n\n," > $log-grouped
+

From 33d5c057960caf3ef697978acfdbb68006a361c6 Mon Sep 17 00:00:00 2001
From: Chen Yufei <cyf@chenyufei.info>
Date: Sun, 28 Jul 2013 15:45:43 +0800
Subject: [PATCH 12/14] Print send body debug message with client info.

---
 proxy.go | 3 +++
 1 file changed, 3 insertions(+)

diff --git a/proxy.go b/proxy.go
index 72380ef4..ee81750c 100644
--- a/proxy.go
+++ b/proxy.go
@@ -502,6 +502,9 @@ func (c *clientConn) readResponse(sv *serverConn, r *Request, rp *Response) (err
 
 	if rp.hasBody(r.Method) {
 		if err = sendBody(c, sv, nil, rp); err != nil {
+			if debug {
+				debug.Printf("cli(%s) send body %v\n", c.RemoteAddr(), err)
+			}
 			// Non persistent connection will return nil upon successful response reading
 			if err == io.EOF {
 				// For persistent connection, EOF from server is error.

From 0cf818826c445703453cf6b9788831edd4ec6bd3 Mon Sep 17 00:00:00 2001
From: Chen Yufei <cyf@chenyufei.info>
Date: Sun, 28 Jul 2013 16:56:59 +0800
Subject: [PATCH 13/14] Fix bug for close connection response with no body.

cow should add content-length: 0 header to indicate the end of close
connection responses with no body, add chunked encoding for those has body.

Safari will wait for body when cow incorrectly adds the chunked header.
As Safari limits number of concurrent connections to the proxy, it will
block on such erroneous responses.
---
 http.go | 14 +++++++++++++-
 1 file changed, 13 insertions(+), 1 deletion(-)

diff --git a/http.go b/http.go
index 29935759..414d8714 100644
--- a/http.go
+++ b/http.go
@@ -602,8 +602,20 @@ func parseResponse(sv *serverConn, r *Request, rp *Response) (err error) {
 	// Connection close, no content length specification
 	// Use chunked encoding to pass content back to client
 	if !rp.ConnectionKeepAlive && !rp.Chunking && rp.ContLen == -1 {
-		rp.raw.WriteString("Transfer-Encoding: chunked\r\n")
+		if rp.hasBody(r.Method) {
+			debug.Println("add chunked encoding to close connection response", r, rp)
+			rp.raw.WriteString("Transfer-Encoding: chunked\r\n")
+		} else {
+			debug.Println("add content-length 0 to close connection response", r, rp)
+			rp.raw.WriteString("Content-Length: 0\r\n")
+		}
 	}
+	// Check for invalid response
+	if !rp.hasBody(r.Method) && (rp.Chunking || rp.ContLen != -1) {
+		errl.Printf("response has no body, but with chunked/content-length set\n%s",
+			rp.Verbose())
+	}
+
 	// Whether COW should respond with keep-alive depends on client request,
 	// not server response.
 	if r.ConnectionKeepAlive {

From f9f9edb628d7da599e1c0969fe45e26a9e4252ed Mon Sep 17 00:00:00 2001
From: Chen Yufei <cyf@chenyufei.info>
Date: Sun, 28 Jul 2013 17:14:36 +0800
Subject: [PATCH 14/14] Bump version to 0.7.6

---
 CHANGELOG      | 7 +++++++
 README.md      | 2 +-
 config.go      | 2 +-
 install-cow.sh | 2 +-
 4 files changed, 10 insertions(+), 3 deletions(-)

diff --git a/CHANGELOG b/CHANGELOG
index 54e7b347..b3f0e241 100644
--- a/CHANGELOG
+++ b/CHANGELOG
@@ -1,3 +1,10 @@
+0.7.6 (2013-07-28)
+    * Fix bug for close connection response with no body
+    * Fix response not keep alive by default
+    * Always try parent proxy upon DNS/connection error
+    * Do not take special handling on log with debug option
+    * Add proxy status statistics in debug code
+
 0.7.5 (2013-07-25)
     * Fix crash on IPv6 client authentication
     * Provide ARMv6 binary
diff --git a/README.md b/README.md
index ef236db6..6f43ee5d 100644
--- a/README.md
+++ b/README.md
@@ -2,7 +2,7 @@
 
 COW 是一个利用二级代理自动化穿越防火墙的 HTTP 代理服务器。它能自动检测被墙网站，仅对这些网站使用二级代理。
 
-当前版本：0.7.5 [CHANGELOG](CHANGELOG)
+当前版本：0.7.6 [CHANGELOG](CHANGELOG)
 [![Build Status](https://travis-ci.org/cyfdecyf/cow.png?branch=develop)](https://travis-ci.org/cyfdecyf/cow)
 
 **欢迎在 develop branch 进行开发并发送 pull request :)**
diff --git a/config.go b/config.go
index 675d0c85..0a945ff6 100644
--- a/config.go
+++ b/config.go
@@ -15,7 +15,7 @@ import (
 )
 
 const (
-	version           = "0.7.5"
+	version           = "0.7.6"
 	defaultListenAddr = "127.0.0.1:7777"
 )
 
diff --git a/install-cow.sh b/install-cow.sh
index 7b668a7c..0a4998df 100755
--- a/install-cow.sh
+++ b/install-cow.sh
@@ -1,6 +1,6 @@
 #!/bin/bash
 
-version=0.7.5
+version=0.7.6
 
 arch=`uname -m`
 case $arch in