Thanks for you answer Ryan, From my unprivileged user (which is configured in httpd.conf) :
$ ./local/bin/python
Python 2.7.3 (default, Jan 2 2013, 16:53:07)
[GCC 4.7.2] on linux2
Type "help", "copyright", "credits" or "license" for more information.
>>> import requests
>>> requests.get("https://verifier.accounts.firefox.com";)
<Response [405]>
>>> s = requests.session()
>>> s.get("https://verifier.accounts.firefox.com";)
<Response [405]>
>>>
seems good. So I got a look on apache processes running as my user :
they have no proxies. I've populated /etc/apache2/envvars, rebooted the
server and now processes have proxies. According to my proxy's access log :
Oct 23 10:09:54 +02:00 [info] [] 1414051794.638 66737 192.168.10.81 TCP_MISS/200 4380 CONNECT verifier.accounts.firefox.com:443 - DIRECT/54.187.50.176 -
Looks fine. but when I try to sync, FF complains about "sync encoutered a problem".
Firefox log from bash :1414052816093 Sync.BrowserIDManager ERROR Non-authentication error in _fetchTokenForUser: Server error. 1414052816096 Sync.BrowserIDManager ERROR Background fetch for key bundle failed: TokenServerClientServerError({"now":"2014-10-23T08:26:56.093Z","message":"Server error.","cause":"general","response_body":"{\"status\": \"error\", \"errors\": [{\"location\": \"body\", \"name\": \"\", \"description\": \"Resource is not available\"}]}","response_headers":{"date":"Thu, 23 Oct 2014 08:26:52 GMT","server":"Apache/2.2.22 (Debian)","x-weave-timestamp":"1414052812.46","x-timestamp":"1414052812","content-length":"109","content-type":"application/json; charset=UTF-8","connection":"close"},"response_status":503}) 1414052816096 Sync.BrowserIDManager ERROR Could not authenticate: TokenServerClientServerError({"now":"2014-10-23T08:26:56.093Z","message":"Server error.","cause":"general","response_body":"{\"status\": \"error\", \"errors\": [{\"location\": \"body\", \"name\": \"\", \"description\": \"Resource is not available\"}]}","response_headers":{"date":"Thu, 23 Oct 2014 08:26:52 GMT","server":"Apache/2.2.22 (Debian)","x-weave-timestamp":"1414052812.46","x-timestamp":"1414052812","content-length":"109","content-type":"application/json; charset=UTF-8","connection":"close"},"response_status":503})
Sync server access-log :192.168.10.168 - - [23/Oct/2014:10:26:52 +0200] "GET /sync/token/1.0/sync/1.5 HTTP/1.1" 503 360 "-" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10.9; rv:33.0) Gecko/20100101 Firefox/33.0" 192.168.10.168 - - [23/Oct/2014:10:27:07 +0200] "GET /sync/token/1.0/sync/1.5 HTTP/1.1" 200 630 "-" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10.9; rv:33.0) Gecko/20100101 Firefox/33.0" 192.168.10.168 - - [23/Oct/2014:10:27:07 +0200] "GET /sync/storage/1.5/1/info/collections HTTP/1.1" 401 303 "-" "Firefox/33.0 FxSync/1.35.0.20141011015303.desktop" 192.168.10.168 - - [23/Oct/2014:10:27:08 +0200] "GET /sync/token/1.0/sync/1.5 HTTP/1.1" 200 629 "-" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10.9; rv:33.0) Gecko/20100101 Firefox/33.0"
Sync server error-log :[Thu Oct 23 10:26:52 2014] [error] INFO:requests.packages.urllib3.connectionpool:Resetting dropped connection: verifier.accounts.firefox.com [Thu Oct 23 10:26:52 2014] [error] INFO:mozsvc.metrics:{"code": 503, "request_time": 0.04103899002075195, "remoteAddressChain": ["192.168.3.14", "192.168.10.168"], "agent": "Mozilla/5.0 (Macintosh; Intel Mac OS X 10.9; rv:33.0) Gecko/20100101 Firefox/33.0", "token.assertion.connection_error": 1, "token.assertion.verify_failure": 1, "tokenserver.assertion.verify": 0.0384061336517334, "path": "http://ff-sync.domain.local/sync/token/1.0/sync/1.5";, "method": "GET"} [Thu Oct 23 10:27:07 2014] [error] INFO:requests.packages.urllib3.connectionpool:Starting new HTTPS connection (2): verifier.accounts.firefox.com [Thu Oct 23 10:27:07 2014] [error] INFO:mozsvc.metrics:{"tokenserver.backend.get_user": 0.003239870071411133, "code": 200, "request_time": 0.9272339344024658, "remoteAddressChain": ["192.168.3.14", "192.168.10.168"], "agent": "Mozilla/5.0 (Macintosh; Intel Mac OS X 10.9; rv:33.0) Gecko/20100101 Firefox/33.0", "tokenserver.assertion.verify": 0.9216299057006836, "token.assertion.verify_success": 1, "path": "http://ff-sync.domain.local/sync/token/1.0/sync/1.5";, "method": "GET"} [Thu Oct 23 10:27:08 2014] [error] INFO:mozsvc.metrics:{"code": 401, "request_time": 0.002434968948364258, "remoteAddressChain": ["192.168.3.14", "192.168.10.168"], "agent": "Firefox/33.0 FxSync/1.35.0.20141011015303.desktop", "path": "http://ff-sync.domain.local/sync/storage/1.5/1/info/collections";, "method": "GET"} [Thu Oct 23 10:27:08 2014] [error] INFO:mozsvc.metrics:{"tokenserver.backend.get_user": 0.002335071563720703, "code": 200, "request_time": 0.21599602699279785, "remoteAddressChain": ["192.168.3.14", "192.168.10.168"], "agent": "Mozilla/5.0 (Macintosh; Intel Mac OS X 10.9; rv:33.0) Gecko/20100101 Firefox/33.0", "tokenserver.assertion.verify": 0.21174216270446777, "token.assertion.verify_success": 1, "path": "http://ff-sync.domain.local/sync/token/1.0/sync/1.5";, "method": "GET"}
Actually, the way from FF to sync server is :FF => Apache reverse proxy (+mod_security) 192.168.10.168 => Apache on sync server (192.168.10.81) => python sync server via mod_wsgi
sync backend database is on mysql.the path in error log shows up http://ff-sync.domain.local/sync/token/1.0/sync/1.5 which is not related to public_url.
How can I troubleshoot further ? Thanks Rgds. Le 23/10/2014 04:46, Ryan Kelly a écrit :
On 20/10/2014 10:49 PM, Philippe MARASSE wrote:The server is behind an Apache reverse proxy, and *must* use a proxy to reach the Internet. Each time I try to synchronize, I have in error log : [..snip..] and tcpdump shows direct connection to 54.244.26.88 or 54.187.50.176 ?? Direct, not through proxy although environment variables http_proxy, https_proxy and no_proxy are correctly set.The tokenserver uses the python "requests" library for its outgoing connections. According to the docs it should support proxies transparently via environment variables: http://docs.python-requests.org/en/latest/user/advanced/#proxies But it may be using e.g. slightly mismatched syntax with the ones you've set. To debug, you could try using the requests library directly from your syncserver virtualenv: $> ./local/bin/python Python 2.7.5 (default, Jun 26 2014, 11:55:39) >>> >>> import requests >>> >>> # Does it work using the standard shortcut? >>> requests.get("https://verifier.accounts.firefox.com";) <Response [405]> >>> >>> s = requests.session() >>> s.get("https://verifier.accounts.firefox.com";) <Response [405]> >>> Do both of these work for you as shown above? Cheers, Ryan
-- Philippe MARASSE Responsable pôle Infrastructures - DSIO Centre Hospitalier Henri Laborit CS 10587 - 370 avenue Jacques Coeur 86021 Poitiers Cedex Tel : 05.49.44.57.19
smime.p7s
Description: Signature cryptographique S/MIME
_______________________________________________ Sync-dev mailing list [email protected] https://mail.mozilla.org/listinfo/sync-dev
