问题描述
我正在尝试诊断一个问题,其中我的一些芹菜工作进程似乎挂起了几分钟。我有许多任务需要进行几个IO调用(通常是对第三方API)。在任何给定的工作中,我可能会向各种API发出数千个请求。我看过这些日志,它们没有什么共同之处:它们在urllib3
连接到远程url后挂起。
在我的作业结束时(大约需要30分钟),通常有几个任务处于挂起状态。
以下是我用来得出urllib3
是罪魁祸首的日志示例:
Jul 08 04:46:26 app/worker.1: [INFO/MainProcess] [???(???)] celery.worker.strategy: Received task: my_celery_task[734a49f6-bf6b-4423-9146-1c48366ba897]
Jul 08 04:46:28 app/worker.1: [DEBUG/Worker-11] [my_celery_task(734a49f6-bf6b-4423-9146-1c48366ba897)] src.aggregates.prospect.services.prospect_service: Beginning: Get social account data. provider_name: twitter, account_uid: some_user
Jul 08 04:46:28 app/worker.1: [INFO/Worker-11] [my_celery_task(734a49f6-bf6b-4423-9146-1c48366ba897)] requests.packages.urllib3.connectionpool: Starting new HTTPS connection (1): api.some_api.com
然后就这样了。Starting new HTTPS connection
语句之后没有记录任何内容。
这是我重新启动Worker的位置:
Jul 08 05:09:18 app/worker.1: [INFO/MainProcess] [???(???)] celery.worker.strategy: Received task: my_celery_task[734a49f6-bf6b-4423-9146-1c48366ba897]
Jul 08 05:09:19 app/worker.1: [DEBUG/Worker-4] [my_celery_task(734a49f6-bf6b-4423-9146-1c48366ba897)] src.aggregates.prospect.services.prospect_service: Beginning: Get social account data. provider_name: twitter, account_uid: some_user
Jul 08 05:09:19 app/worker.1: [DEBUG/Worker-4] [my_celery_task(734a49f6-bf6b-4423-9146-1c48366ba897)] requests.packages.urllib3.connectionpool: "GET /v2/api_call.json?username=some_user HTTP/1.1" 403 170
Jul 08 05:09:19 app/worker.1: [INFO/Worker-4] [my_celery_task(734a49f6-bf6b-4423-9146-1c48366ba897)] requests.packages.urllib3.connectionpool: Starting new HTTPS connection (1): api.some_api.com
Jul 08 05:09:19 app/worker.1: [INFO/MainProcess] [???(???)] celery.worker.job: Task my_celery_task[734a49f6-bf6b-4423-9146-1c48366ba897] succeeded in 2.265356543008238s: 32345
在这种情况下,我收到403
状态代码。所以这可能是潜在的罪魁祸首。但是,我在日志中看到,状态代码200
也发生了这种情况。
顺便说一下,我也经常在日志中看到Resetting dropped connection: api.twitter.com
。
我已确保在使用requests
库发出请求的任何地方提供timeout
10秒。
所以看起来请求已经发出,但随后就挂起了。远程服务器可能以非常慢的速度响应,因此实际上从未发生过超时,但我发现这不太可能,因为我的问题不只发生在一个特定的域中。
我用的是兔子3.1.3芹菜:3.1.11(Cipater)昆布:3.0.16 Py:3.4.0台球:3.3.0.17 Py-AMQP:1.4.5。我正在使用预叉。
我使用的是Requests==2.3.0。
那么为什么urllib3
记录Starting new HTTPS connection
语句后我的任务似乎挂起?
编辑:我添加了大量日志记录,并在下面提供了进一步的上下文
2014-07-16T02:43:53.140381+00:00 app[worker.1]: [INFO/MainProcess/2] [???(???)] celery.worker.strategy: Received task: [973c1361-43c3-41a2-9bcd-6ef850c41fcc]
2014-07-16T02:43:56.951211+00:00 app[worker.1]: [1;34m[DEBUG/Worker-28/99] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] : twitter, account_uid: some_user[0m
2014-07-16T02:43:56.951876+00:00 app[worker.1]: [INFO/Worker-28/99] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.sessions: complete: request: about to get request
2014-07-16T02:43:56.952005+00:00 app[worker.1]: [INFO/Worker-28/99] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.sessions: begin: request: about to prep request
2014-07-16T02:43:56.952897+00:00 app[worker.1]: [INFO/Worker-28/99] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.sessions: complete: request: about to prep request
2014-07-16T02:43:56.954133+00:00 app[worker.1]: [INFO/Worker-28/99] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.adapters: begin: send: about to get response not chunked
2014-07-16T02:43:56.954249+00:00 app[worker.1]: [INFO/Worker-28/99] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.packages.urllib3.connectionpool: begin: urlopen: about to get a conn from the pool
2014-07-16T02:43:56.954360+00:00 app[worker.1]: [INFO/Worker-28/99] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.packages.urllib3.connectionpool: begin: _get_conn: about to get a conn from the pool
2014-07-16T02:43:56.954482+00:00 app[worker.1]: [INFO/Worker-28/99] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.packages.urllib3.connectionpool: complete: _get_conn: about to get a conn from the pool
2014-07-16T02:43:56.954587+00:00 app[worker.1]: [INFO/Worker-28/99] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.packages.urllib3.connectionpool: begin: returning conn or self new conn
2014-07-16T02:43:56.951725+00:00 app[worker.1]: [INFO/Worker-28/99] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.sessions: begin: request: about to get request
2014-07-16T02:43:56.954692+00:00 app[worker.1]: [INFO/Worker-28/99] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.packages.urllib3.connectionpool: Starting new HTTPS connection (1): api.fullcontact.com
2014-07-16T02:43:56.954817+00:00 app[worker.1]: [INFO/Worker-28/99] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.packages.urllib3.connectionpool: begin: create connection class
2014-07-16T02:43:56.954948+00:00 app[worker.1]: [INFO/Worker-28/99] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.packages.urllib3.connectionpool: complete: just about to create connection class
2014-07-16T02:43:56.955062+00:00 app[worker.1]: [INFO/Worker-28/99] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.packages.urllib3.connectionpool: complete: returning conn or self new conn
2014-07-16T02:43:56.955166+00:00 app[worker.1]: [INFO/Worker-28/99] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.packages.urllib3.connectionpool: complete: urlopen: about to get a conn from the pool
2014-07-16T02:43:56.955290+00:00 app[worker.1]: [INFO/Worker-28/99] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.packages.urllib3.connectionpool: begin: _make_request: about to call request
2014-07-16T02:43:56.955396+00:00 app[worker.1]: [INFO/Worker-28/99] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.packages.urllib3.connection: begin: httpconection: send req
2014-07-16T02:43:56.953410+00:00 app[worker.1]: [INFO/Worker-28/99] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.sessions: begin: request: about to send
2014-07-16T02:43:56.953554+00:00 app[worker.1]: [INFO/Worker-28/99] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.adapters: begin: send: about to get conn
2014-07-16T02:43:56.953986+00:00 app[worker.1]: [INFO/Worker-28/99] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.adapters: complete: send: about to get conn
2014-07-16T02:43:56.956014+00:00 app[worker.1]: [INFO/Worker-28/99] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.packages.urllib3.connection: begin: httpconection: _send_output
2014-07-16T02:43:56.955517+00:00 app[worker.1]: [INFO/Worker-28/99] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.packages.urllib3.connection: begin: httpconection: put req
2014-07-16T02:43:56.955715+00:00 app[worker.1]: [INFO/Worker-28/99] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.packages.urllib3.connection: completed: httpconection: put req
2014-07-16T02:43:56.956146+00:00 app[worker.1]: [INFO/Worker-28/99] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.packages.urllib3.connection: begin: httpconection: send
2014-07-16T02:43:56.956309+00:00 app[worker.1]: [INFO/Worker-28/99] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.packages.urllib3.connection: begin: https verified conection: connect
2014-07-16T02:43:56.959157+00:00 app[worker.1]: [INFO/Worker-28/99] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.packages.urllib3.connection: completed: https verified : connect: set socket
2014-07-16T02:43:56.959045+00:00 app[worker.1]: [INFO/Worker-28/99] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.packages.urllib3.connection: begin: https verified : connect: set socket
2014-07-16T02:43:56.959295+00:00 app[worker.1]: [INFO/Worker-28/99] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.packages.urllib3.connection: begin: https verified : connect: resolve cert reqs
2014-07-16T02:43:56.959402+00:00 app[worker.1]: [INFO/Worker-28/99] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.packages.urllib3.connection: completed: https verified : connect: resolve cert reqs
2014-07-16T02:43:56.959508+00:00 app[worker.1]: [INFO/Worker-28/99] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.packages.urllib3.connection: begin: https verified : connect: resolve ssl ver
2014-07-16T02:43:56.959613+00:00 app[worker.1]: [INFO/Worker-28/99] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.packages.urllib3.connection: complete: https verified : connect: resolve ssl ver
2014-07-16T02:43:56.959715+00:00 app[worker.1]: [INFO/Worker-28/99] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.packages.urllib3.connection: begin: https verified : connect: ssl_wrap_socket
2014-07-16T02:43:56.959827+00:00 app[worker.1]: [INFO/Worker-28/99] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.packages.urllib3.util.ssl_: begin: ssl_wrap_socket: about to get ssl context
2014-07-16T02:43:56.960012+00:00 app[worker.1]: [INFO/Worker-28/99] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.packages.urllib3.util.ssl_: complete: ssl_wrap_socket: about to get ssl context
2014-07-16T02:43:56.960119+00:00 app[worker.1]: [INFO/Worker-28/99] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.packages.urllib3.util.ssl_: begin: ssl_wrap_socket: load verify locations
# *******************************************
# *******************************************
# This is when I restarted the job. It processed the same exact task, same parameters, same https url, etc in under 1 second.
# *******************************************
# *******************************************
2014-07-16T03:00:21.885531+00:00 app[worker.1]: [INFO/MainProcess/2] [???(???)] celery.worker.strategy: Received task: [973c1361-43c3-41a2-9bcd-6ef850c41fcc]
2014-07-16T03:00:22.009616+00:00 app[worker.1]: [INFO/Worker-9/23] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.sessions: begin: request: about to get request
2014-07-16T03:00:22.010313+00:00 app[worker.1]: [INFO/Worker-9/23] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.sessions: begin: request: about to prep request
2014-07-16T03:00:22.016669+00:00 app[worker.1]: [INFO/Worker-9/23] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.sessions: begin: request: about to send
2014-07-16T03:00:22.018419+00:00 app[worker.1]: [INFO/Worker-9/23] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.adapters: complete: send: about to get conn
2014-07-16T03:00:22.051267+00:00 app[worker.1]: [INFO/Worker-9/23] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.packages.urllib3.connection: completed: httpconection: put req
2014-07-16T03:00:22.051744+00:00 app[worker.1]: [INFO/Worker-9/23] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.packages.urllib3.connection: begin: httpconection: send
2014-07-16T03:00:22.051879+00:00 app[worker.1]: [INFO/Worker-9/23] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.packages.urllib3.connection: begin: https verified conection: connect
2014-07-16T03:00:22.072346+00:00 app[worker.1]: [INFO/Worker-9/23] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.packages.urllib3.connection: begin: https verified : connect: set socket
2014-07-16T03:00:22.103234+00:00 app[worker.1]: [INFO/Worker-9/23] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.packages.urllib3.util.ssl_: begin: ssl_wrap_socket: wrap socket with host name
2014-07-16T03:00:22.007638+00:00 app[worker.1]: [1;34m[DEBUG/Worker-9/23] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] : : twitter, account_uid: some_user[0m
2014-07-16T03:00:22.009969+00:00 app[worker.1]: [INFO/Worker-9/23] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.sessions: complete: request: about to get request
2014-07-16T03:00:22.012954+00:00 app[worker.1]: [INFO/Worker-9/23] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.sessions: complete: request: about to prep request
2014-07-16T03:00:22.017254+00:00 app[worker.1]: [INFO/Worker-9/23] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.adapters: begin: send: about to get conn
2014-07-16T03:00:22.049101+00:00 app[worker.1]: [INFO/Worker-9/23] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.adapters: begin: send: about to get response not chunked
2014-07-16T03:00:22.049241+00:00 app[worker.1]: [INFO/Worker-9/23] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.packages.urllib3.connectionpool: begin: urlopen: about to get a conn from the pool
2014-07-16T03:00:22.049361+00:00 app[worker.1]: [INFO/Worker-9/23] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.packages.urllib3.connectionpool: begin: _get_conn: about to get a conn from the pool
2014-07-16T03:00:22.049528+00:00 app[worker.1]: [INFO/Worker-9/23] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.packages.urllib3.connectionpool: complete: _get_conn: about to get a conn from the pool
2014-07-16T03:00:22.049639+00:00 app[worker.1]: [INFO/Worker-9/23] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.packages.urllib3.connectionpool: begin: returning conn or self new conn
2014-07-16T03:00:22.049756+00:00 app[worker.1]: [INFO/Worker-9/23] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.packages.urllib3.connectionpool: Starting new HTTPS connection (1): api.fullcontact.com
2014-07-16T03:00:22.049918+00:00 app[worker.1]: [INFO/Worker-9/23] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.packages.urllib3.connectionpool: begin: create connection class
2014-07-16T03:00:22.050197+00:00 app[worker.1]: [INFO/Worker-9/23] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.packages.urllib3.connectionpool: complete: just about to create connection class
2014-07-16T03:00:22.050318+00:00 app[worker.1]: [INFO/Worker-9/23] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.packages.urllib3.connectionpool: complete: returning conn or self new conn
2014-07-16T03:00:22.050425+00:00 app[worker.1]: [INFO/Worker-9/23] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.packages.urllib3.connectionpool: complete: urlopen: about to get a conn from the pool
2014-07-16T03:00:22.050587+00:00 app[worker.1]: [INFO/Worker-9/23] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.packages.urllib3.connectionpool: begin: _make_request: about to call request
2014-07-16T03:00:22.050777+00:00 app[worker.1]: [INFO/Worker-9/23] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.packages.urllib3.connection: begin: httpconection: send req
2014-07-16T03:00:22.050946+00:00 app[worker.1]: [INFO/Worker-9/23] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.packages.urllib3.connection: begin: httpconection: put req
2014-07-16T03:00:22.051546+00:00 app[worker.1]: [INFO/Worker-9/23] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.packages.urllib3.connection: begin: httpconection: _send_output
2014-07-16T03:00:22.072581+00:00 app[worker.1]: [INFO/Worker-9/23] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.packages.urllib3.connection: completed: https verified : connect: set socket
2014-07-16T03:00:22.072721+00:00 app[worker.1]: [INFO/Worker-9/23] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.packages.urllib3.connection: begin: https verified : connect: resolve cert reqs
2014-07-16T03:00:22.072911+00:00 app[worker.1]: [INFO/Worker-9/23] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.packages.urllib3.connection: completed: https verified : connect: resolve cert reqs
2014-07-16T03:00:22.073044+00:00 app[worker.1]: [INFO/Worker-9/23] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.packages.urllib3.connection: begin: https verified : connect: resolve ssl ver
2014-07-16T03:00:22.073179+00:00 app[worker.1]: [INFO/Worker-9/23] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.packages.urllib3.connection: complete: https verified : connect: resolve ssl ver
2014-07-16T03:00:22.073311+00:00 app[worker.1]: [INFO/Worker-9/23] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.packages.urllib3.connection: begin: https verified : connect: ssl_wrap_socket
2014-07-16T03:00:22.073445+00:00 app[worker.1]: [INFO/Worker-9/23] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.packages.urllib3.util.ssl_: begin: ssl_wrap_socket: about to get ssl context
2014-07-16T03:00:22.073814+00:00 app[worker.1]: [INFO/Worker-9/23] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.packages.urllib3.util.ssl_: complete: ssl_wrap_socket: about to get ssl context
2014-07-16T03:00:22.073979+00:00 app[worker.1]: [INFO/Worker-9/23] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.packages.urllib3.util.ssl_: begin: ssl_wrap_socket: load verify locations
2014-07-16T03:00:22.092134+00:00 app[worker.1]: [INFO/Worker-9/23] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.packages.urllib3.util.ssl_: complete: ssl_wrap_socket: load verify locations
2014-07-16T03:00:22.138197+00:00 app[worker.1]: [INFO/Worker-9/23] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.packages.urllib3.util.ssl_: complete: ssl_wrap_socket: wrap socket with host name
2014-07-16T03:00:22.138207+00:00 app[worker.1]: [INFO/Worker-9/23] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.packages.urllib3.connection: complete: https verified : connect: ssl_wrap_socket
2014-07-16T03:00:22.138209+00:00 app[worker.1]: [INFO/Worker-9/23] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.packages.urllib3.connection: begin: https verified : connect: match hostname
2014-07-16T03:00:22.138211+00:00 app[worker.1]: [INFO/Worker-9/23] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.packages.urllib3.connection: complete: https verified : connect: match host name
2014-07-16T03:00:22.138212+00:00 app[worker.1]: [INFO/Worker-9/23] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.packages.urllib3.connection: completed: https verified conection: connect
2014-07-16T03:00:22.138214+00:00 app[worker.1]: [INFO/Worker-9/23] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.packages.urllib3.connection: begin: httpconection: send: before sock.sendall
2014-07-16T03:00:22.138743+00:00 app[worker.1]: [INFO/Worker-9/23] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.packages.urllib3.connection: completed: httpconection: send: before sock.sendall
2014-07-16T03:00:22.138748+00:00 app[worker.1]: [INFO/Worker-9/23] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.packages.urllib3.connection: completed: httpconection: send
2014-07-16T03:00:22.138796+00:00 app[worker.1]: [INFO/Worker-9/23] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.packages.urllib3.connection: completed: httpconection: _send_output
2014-07-16T03:00:22.139094+00:00 app[worker.1]: [INFO/Worker-9/23] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.packages.urllib3.connection: completed: httpconection: send req
2014-07-16T03:00:22.139207+00:00 app[worker.1]: [INFO/Worker-9/23] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.packages.urllib3.connectionpool: complete: _make_request: about to call request
2014-07-16T03:00:22.139321+00:00 app[worker.1]: [INFO/Worker-9/23] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.packages.urllib3.connectionpool: begin: _make_request: conn.get reponse with buffer
2014-07-16T03:00:22.139925+00:00 app[worker.1]: [INFO/Worker-9/23] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.packages.urllib3.connectionpool: begin: _make_request: conn.get reponse with no buffer
2014-07-16T03:00:22.288112+00:00 app[worker.1]: [INFO/Worker-9/23] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.sessions: completest: about to send
2014-07-16T03:00:22.286453+00:00 app[worker.1]: [INFO/Worker-9/23] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.packages.urllib3.connectionpool: complete: _make_request: conn.get reponse with no buffer
2014-07-16T03:00:22.286596+00:00 app[worker.1]: [1;34m[DEBUG/Worker-9/23] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.packages.urllib3.connectionpool: "GET /v2/person.json?twitter=some_user&apiKey=5eeaece3982efd1d&style=dictionary HTTP/1.1" 403 170[0m
2014-07-16T03:00:22.286720+00:00 app[worker.1]: [INFO/Worker-9/23] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.packages.urllib3.connectionpool: begin: urlopen: about to get response from httplib
2014-07-16T03:00:22.287050+00:00 app[worker.1]: [INFO/Worker-9/23] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.packages.urllib3.connectionpool: complete: urlopen: about to get response from httplib
2014-07-16T03:00:22.287170+00:00 app[worker.1]: [INFO/Worker-9/23] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.adapters: complete: send: about to get response not chunked
2014-07-16T03:00:22.287279+00:00 app[worker.1]: [INFO/Worker-9/23] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.adapters: begin: send: about to build response
2014-07-16T03:00:22.287738+00:00 app[worker.1]: [INFO/Worker-9/23] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.adapters: complete: send: about to build response
2014-07-16T03:00:24.342182+00:00 app[worker.1]: [INFO/MainProcess/2] [???(???)] celery.worker.job: Task [973c1361-43c3-41a2-9bcd-6ef850c41fcc] succeeded in 2.4521394340554252s: 44508
最后记录的条目是
2014-07-16T02:43:56.960119+00:00 app[worker.1]: [INFO/Worker-28/99] [(973c1361-43c3-41a2-9bcd-6ef850c41fcc)] requests.packages.urllib3.util.ssl_: begin: ssl_wrap_socket: load verify locations
根据我的日志语句,the culprit is load_verify_locations。
这是requests
库中对应的代码:
if ca_certs:
try:
context.load_verify_locations(ca_certs)
# Py32 raises IOError
# Py33 raises FileNotFoundError
except Exception as e: # Reraise as SSLError
raise SSLError(e)
因此,似乎是context.load_verify_locations(ca_certs)
导致此操作挂起。为什么?
推荐答案
您是否在使用multiprocessing.dummy
模块?即线程池?
multiprocessing.dummy
或urllib3
的Pool
模块中似乎存在错误,这似乎会导致随机HTTP连接在建立后(即TCP SYN-ACK周期完成后)挂起。
当您使用Wireshark跟踪TCP请求/响应时,您会看到一个成功的TCP连接正在建立,然后在几分钟后出现TCP RST,并且在这两个连接之间没有应用程序协议通信,这就是发生此错误的迹象。
您可能希望尝试将多处理池代码切换为基于进程,即使用多处理而不是多处理.dummy。
即代替
from multiprocessing.dummy import Pool as ThreadPool
使用
from multiprocessing import Pool as ProcessPool
以上对我有效,错误消失了。
这篇关于为什么我的程序在urllib3日志启动新的HTTPS连接后挂起?的文章就介绍到这了,希望我们推荐的答案对大家有所帮助,也希望大家多多支持跟版网!