tatsuhiro-t / spdylay

The experimental SPDY protocol version 2, 3 and 3.1 implementation in C
http://tatsuhiro-t.github.io/spdylay/
MIT License
602 stars 102 forks source link

Some Google App Sync not working on Android #112

Closed lucidfrontier45 closed 10 years ago

lucidfrontier45 commented 10 years ago

Hi, I followed your instruction to build an Android executable and it successfully ran. https://github.com/tatsuhiro-t/spdylay/blob/master/doc/android-spdy-proxy.rst

However I found some google apps (keep, drive, play newsstand) sync not working. Other HTTP or HTTPS apps like browser work fine.

How to reproduce

  1. Server PC Ubuntu 12.04(64bit), Genymotion Android 4.3 (x86)
  2. On Ubuntu, shrpx was built following the README.rst
  3. Android shrpx executable was built according you android instruction but with x86 NDK toolchains
  4. Run a squid on Ubuntu. (3128 port)
  5. On ubuntu, shrpx was initiated by shrpx -s -b 127.0.0.1,3128 -f 0.0.0.0,9092 -k --frontend-spdy-no-tls --no-via
  6. On android, shrpx was initiated by shrpx -p -b <ubuntu address>,9092 -f 0.0.0.0,8080 -k --backend-spdy-no-tls --no-via
  7. Edit android wifi settings to use 127.0.0.1:8080 as proxy
  8. Open android system setting and go to google account setting in "Accounts" tab or section.
  9. uncheck and check "Sync Keep"

It can also be reproduced by running two shrpxes in Ubuntu with "-s" and "-p" option respectively, that is, shrpx -s -b 127.0.0.1,3128 -f 127.0.0.1,9092 -k --frontend-spdy-no-tls --no-via and shrpx -p -b 127.0.0.1,9092 -f 0.0.0.0,8080 -k --backend-spdy-no-tls --no-via, and then edit the Android phone's WiFi setting to use the Ubuntu as proxy.

Any Idea? Thank you.

tatsuhiro-t commented 10 years ago

Check the log (-LINFO option) for both shrpx run and there are any suspicious errors.

I think "sync feature" is most likely performed in encrypted channel (https). If that is the case, shrpx only sees the encrypted data back and forth. Since the data are private, the server side limits the source address to make it more safer, but I'm not sure about it.

lucidfrontier45 commented 10 years ago

Check the log (-LINFO option) for both shrpx run and there are any suspicious errors.

I'll paste detail log here.

I think "sync feature" is most likely performed in encrypted channel (https). If that is the case, shrpx only sees the encrypted data back and forth. Since the data are private, the server side limits the source address to make it more safer, but I'm not sure about it.

Yes the sync is performed in https. I add that if I edit android's proxy to directly use squid as a proxy server, the sync goes well.

lucidfrontier45 commented 10 years ago

Here is the log. I think the problem is on keep-alive handling. The android http client sent the Proxy-Connection: Keep-Alive but the client side shrpx seems to respond with Connection: close. Does -p mode shrpx support keep-alive with client?

client side shrpx

[INFO] [LISTEN:0x89c0608] Accepted connection. fd=10 (shrpx_listen_handler.cc:101) [INFO] [UPSTREAM:0x89d3978] HTTP request started (shrpx_https_upstream.cc:78) [INFO] [UPSTREAM:0x89d3978] HTTP request headers completed (shrpx_https_upstream.cc:135) [INFO] [UPSTREAM:0x89d3978] HTTP request headers CONNECT www.googleapis.com:443 HTTP/1.1 Host: www.googleapis.com User-Agent: Keep/2.2.11 (Linux; Android 4.2.2; en-us; Moto X - 4.2.2 - API 17 - 720x1280 Build/JDQ39E) Google-HTTP-Java-Client/1.16.0-rc (gzip) Proxy-Connection: Keep-Alive

   (shrpx_https_upstream.cc:156)

[INFO] [CLIENT_HANDLER:0x89d38a0] Downstream connection pool is empty. Create new one (shrpx_client_handler.cc:345) [INFO] [DCONN:0x89d3bd8] Attaching to DOWNSTREAM:0x89d39b8 (shrpx_spdy_downstream_connection.cc:101) [INFO] [DCONN:0x89d3bd8] HTTP request headers :path: www.googleapis.com:443 :method: CONNECT :version: HTTP/1.1 :host: www.googleapis.com User-Agent: Keep/2.2.11 (Linux; Android 4.2.2; en-us; Moto X - 4.2.2 - API 17 - 720x1280 Build/JDQ39E) Google-HTTP-Java-Client/1.16.0-rc (gzip) via: 1.1 shrpx

   (shrpx_spdy_downstream_connection.cc:367)

[INFO] [DSPDY:0x89c07e8] HTTP response headers. stream_id=5 :status: 200 OK :version: HTTP/1.1

   (shrpx_spdy_session.cc:848)

[INFO] [DOWNSTREAM:0x89d39b8] HTTP response header completed (shrpx_https_upstream.cc:618) [INFO] [UPSTREAM:0x89d3978] HTTP response headers HTTP/1.1 200 OK Connection: close Via: 1.1 shrpx

   (shrpx_https_upstream.cc:687)

[INFO] [LISTEN:0x89c0608] Accepted connection. fd=12 (shrpx_listen_handler.cc:101) [INFO] [CLIENT_HANDLER:0x89d38a0] EOF (shrpx_client_handler.cc:83) [INFO] [CLIENT_HANDLER:0x89d38a0] Deleting (shrpx_client_handler.cc:205) [INFO] [DOWNSTREAM:0x89d39b8] Deleting (shrpx_downstream.cc:67) [INFO] [DCONN:0x89d3bd8] Deleting (shrpx_spdy_downstream_connection.cc:59) [INFO] [DCONN:0x89d3bd8] Submit RST_STREAM for DOWNSTREAM:0x89d39b8, stream_id=5 (shrpx_spdy_downstream_connection.cc:140) [INFO] [DCONN:0x89d3bd8] Deleted (shrpx_spdy_downstream_connection.cc:76) [INFO] [DOWNSTREAM:0x89d39b8] Deleted (shrpx_downstream.cc:77) [INFO] [CLIENT_HANDLER:0x89d38a0] Deleted (shrpx_client_handler.cc:238) [INFO] [UPSTREAM:0x89d5fb8] HTTP request started (shrpx_https_upstream.cc:78) [INFO] [UPSTREAM:0x89d5fb8] HTTP request headers completed (shrpx_https_upstream.cc:135) [INFO] [UPSTREAM:0x89d5fb8] HTTP request headers CONNECT www.googleapis.com:443 HTTP/1.1 Host: www.googleapis.com User-Agent: Keep/2.2.11 (Linux; Android 4.2.2; en-us; Moto X - 4.2.2 - API 17 - 720x1280 Build/JDQ39E) Google-HTTP-Java-Client/1.16.0-rc (gzip) Proxy-Connection: Keep-Alive

   (shrpx_https_upstream.cc:156)

[INFO] [CLIENT_HANDLER:0x89d5ed0] Downstream connection pool is empty. Create new one (shrpx_client_handler.cc:345) [INFO] [DCONN:0x89d6240] Attaching to DOWNSTREAM:0x89d6020 (shrpx_spdy_downstream_connection.cc:101) [INFO] [DCONN:0x89d6240] HTTP request headers :path: www.googleapis.com:443 :method: CONNECT :version: HTTP/1.1 :host: www.googleapis.com User-Agent: Keep/2.2.11 (Linux; Android 4.2.2; en-us; Moto X - 4.2.2 - API 17 - 720x1280 Build/JDQ39E) Google-HTTP-Java-Client/1.16.0-rc (gzip) via: 1.1 shrpx

   (shrpx_spdy_downstream_connection.cc:367)

[INFO] [DSPDY:0x89c07e8] Stream stream_id=5 is being closed (shrpx_spdy_session.cc:686) [INFO] [DSPDY:0x89c07e8] HTTP response headers. stream_id=7 :status: 200 OK :version: HTTP/1.1

   (shrpx_spdy_session.cc:848)

[INFO] [DOWNSTREAM:0x89d6020] HTTP response header completed (shrpx_https_upstream.cc:618) [INFO] [UPSTREAM:0x89d5fb8] HTTP response headers HTTP/1.1 200 OK Connection: close Via: 1.1 shrpx (shrpx_https_upstream.cc:687) [INFO] [CLIENT_HANDLER:0x89d5ed0] EOF (shrpx_client_handler.cc:83) [INFO] [CLIENT_HANDLER:0x89d5ed0] Deleting (shrpx_client_handler.cc:205) [INFO] [DOWNSTREAM:0x89d6020] Deleting (shrpx_downstream.cc:67) [INFO] [DCONN:0x89d6240] Deleting (shrpx_spdy_downstream_connection.cc:59) [INFO] [DCONN:0x89d6240] Submit RST_STREAM for DOWNSTREAM:0x89d6020, stream_id=7 (shrpx_spdy_downstream_connection.cc:140) [INFO] [DCONN:0x89d6240] Deleted (shrpx_spdy_downstream_connection.cc:76) [INFO] [DOWNSTREAM:0x89d6020] Deleted (shrpx_downstream.cc:77) [INFO] [CLIENT_HANDLER:0x89d5ed0] Deleted (shrpx_client_handler.cc:238) [INFO] [DSPDY:0x89c07e8] Stream stream_id=7 is being closed (shrpx_spdy_session.cc:686)

server side shrpx

[INFO] [UPSTREAM:0x83fdc30] Received upstream SYN_STREAM stream_id=5 (shrpx_spdy_upstream.cc:147) [INFO] [UPSTREAM:0x83fdc30] HTTP request headers. stream_id=5 :host: www.googleapis.com :method: CONNECT :path: www.googleapis.com:443 :version: HTTP/1.1 user-agent: Keep/2.2.11 (Linux; Android 4.2.2; en-us; Moto X - 4.2.2 - API 17 - 720x1280 Build/JDQ39E) Google-HTTP-Java-Client/1.16.0-rc (gzip) via: 1.1 shrpx

   (shrpx_spdy_upstream.cc:216)

[INFO] [CLIENT_HANDLER:0x83fd4f0] Downstream connection pool is empty. Create new one (shrpx_client_handler.cc:345) [INFO] [DCONN:0x840f440] Attaching to DOWNSTREAM:0x8410620 (shrpx_http_downstream_connection.cc:74) [INFO] [DCONN:0x840f440] Connecting to downstream server (shrpx_http_downstream_connection.cc:93) [INFO] [DCONN:0x840f440] HTTP request headers. stream_id=5 CONNECT www.googleapis.com:443 HTTP/1.1 User-Agent: Keep/2.2.11 (Linux; Android 4.2.2; en-us; Moto X - 4.2.2 - API 17 - 720x1280 Build/JDQ39E) Google-HTTP-Java-Client/1.16.0-rc (gzip) Via: 1.1 shrpx Host: www.googleapis.com

   (shrpx_http_downstream_connection.cc:208)

[INFO] [DCONN:0x840f440] Connection established. stream_id=5 (shrpx_spdy_upstream.cc:584) [INFO] [DOWNSTREAM:0x8410620] HTTP response header completed (shrpx_spdy_upstream.cc:852) [INFO] [UPSTREAM:0x83fdc30] HTTP response headers. stream_id=5 :status: 200 OK :version: HTTP/1.1

   (shrpx_spdy_upstream.cc:895)

[INFO] [UPSTREAM:0x83fdc30] Stream stream_id=5 is being closed (shrpx_spdy_upstream.cc:99) [INFO] [DOWNSTREAM:0x8410620] Deleting (shrpx_downstream.cc:67) [INFO] [DOWNSTREAM:0x8410620] Deleted (shrpx_downstream.cc:77) [INFO] [UPSTREAM:0x83fdc30] Received upstream SYN_STREAM stream_id=7 (shrpx_spdy_upstream.cc:147) [INFO] [UPSTREAM:0x83fdc30] HTTP request headers. stream_id=7 :host: www.googleapis.com :method: CONNECT :path: www.googleapis.com:443 :version: HTTP/1.1 user-agent: Keep/2.2.11 (Linux; Android 4.2.2; en-us; Moto X - 4.2.2 - API 17 - 720x1280 Build/JDQ39E) Google-HTTP-Java-Client/1.16.0-rc (gzip) via: 1.1 shrpx

   (shrpx_spdy_upstream.cc:216)

[INFO] [CLIENT_HANDLER:0x83fd4f0] Downstream connection pool is empty. Create new one (shrpx_client_handler.cc:345) [INFO] [DCONN:0x840f310] Attaching to DOWNSTREAM:0x8410620 (shrpx_http_downstream_connection.cc:74) [INFO] [DCONN:0x840f310] Connecting to downstream server (shrpx_http_downstream_connection.cc:93) [INFO] [DCONN:0x840f310] HTTP request headers. stream_id=7 CONNECT www.googleapis.com:443 HTTP/1.1 User-Agent: Keep/2.2.11 (Linux; Android 4.2.2; en-us; Moto X - 4.2.2 - API 17 - 720x1280 Build/JDQ39E) Google-HTTP-Java-Client/1.16.0-rc (gzip) Via: 1.1 shrpx Host: www.googleapis.com

   (shrpx_http_downstream_connection.cc:208)

[INFO] [DCONN:0x840f310] Connection established. stream_id=7 (shrpx_spdy_upstream.cc:584) [INFO] [DOWNSTREAM:0x8410620] HTTP response header completed (shrpx_spdy_upstream.cc:852) [INFO] [UPSTREAM:0x83fdc30] HTTP response headers. stream_id=7 :status: 200 OK :version: HTTP/1.1

   (shrpx_spdy_upstream.cc:895)

[INFO] [UPSTREAM:0x83fdc30] Stream stream_id=7 is being closed (shrpx_spdy_upstream.cc:99) [INFO] [DOWNSTREAM:0x8410620] Deleting (shrpx_downstream.cc:67) [INFO] [DOWNSTREAM:0x8410620] Deleted (shrpx_downstream.cc:77)

tatsuhiro-t commented 10 years ago

Proxy-Connection was deprecated while ago and it is disallowed in SPDY connection. Also in this case, we made just 1 tunnel connection though several proxies, which should be retained as long as both parties keep connection open.

Android client may not like "Connection: close" in response header. Here is a patch to remove it from response header. Could you apply and test it?

diff --git a/src/shrpx_https_upstream.cc b/src/shrpx_https_upstream.cc
index 3b7794a..fe78f1e 100644
--- a/src/shrpx_https_upstream.cc
+++ b/src/shrpx_https_upstream.cc
@@ -659,7 +659,7 @@ int HttpsUpstream::on_downstream_header_complete(Downstream 
     } else if(connection_upgrade) {
       hdrs += "Connection: upgrade\r\n";
     }
-  } else {
+  } else if(!downstream->tunnel_established()) {
     hdrs += "Connection: close\r\n";
   }
   if(!get_config()->no_via) {
lucidfrontier45 commented 10 years ago

Thank you. The patch worked. Does nghttpx needs the same patch?

tatsuhiro-t commented 10 years ago

Yes. I'll port it to nghttpx.

tatsuhiro-t commented 10 years ago

FYI, fix committed via 3ecc12b