recv block forever

[zhangyuchun]

Summary.

Expected Result

don't block forever.

Actual Result

block forever

Reproduction Steps

i write a python3 spider using requests . it can run for a long time normally. but sometimes it block recv data forever . i don't this is either a python3's bug or a requests's bug. can you help me ? please ask me for more info if need, info below:

strace -p 12585:
strace: Process 12585 attached
recvfrom(5,

strack 12585:
#0 0x00007f16e10b9a3d in recv () from /lib64/libpthread.so.0
#1 0x00007f16d99d3da1 in sock_recv_impl (data=0x7ffec7c72170, s=0x7f16d3df8b28) at /root/deploy/Python-3.6.5/Modules/socketmodule.c:3064
#2 sock_call_ex (s=s@entry=0x7f16d3df8b28, data=data@entry=0x7ffec7c72170, timeout=-1000000000, err=0x0, connect=0, sock_func=0x7f16d99d1c60 <sock_recv_impl>, writing=0) at /root/deploy/Python-3.6.5/Modules/socketmodule.c:898
#3 0x00007f16d99d3f18 in sock_call (data=0x7ffec7c72170, func=0x7f16d99d1c60 <sock_recv_impl>, writing=0, s=0x7f16d3df8b28) at /root/deploy/Python-3.6.5/Modules/socketmodule.c:950
#4 sock_recv_guts (flags=, len=, cbuf=, s=0x7f16d3df8b28) at /root/deploy/Python-3.6.5/Modules/socketmodule.c:3096
#5 sock_recv_into (s=0x7f16d3df8b28, args=, kwds=) at /root/deploy/Python-3.6.5/Modules/socketmodule.c:3191
#6 0x00000000004aa107 in _PyCFunction_FastCallDict (kwargs=0x0, nargs=1, args=0x7f16d99d3e50 <sock_recv_into>, func_obj=0x7f16d3a5c9d8) at Objects/methodobject.c:231
#7 _PyCFunction_FastCallKeywords (func=func@entry=0x7f16d3a5c9d8, stack=stack@entry=0x15741d0, nargs=1, kwnames=kwnames@entry=0x0) at Objects/methodobject.c:294
#8 0x0000000000540e84 in call_function (pp_stack=pp_stack@entry=0x7ffec7c723a0, oparg=oparg@entry=1, kwnames=kwnames@entry=0x0) at Python/ceval.c:4824
#9 0x0000000000545cdc in _PyEval_EvalFrameDefault (f=, throwflag=) at Python/ceval.c:3322
#10 0x000000000053fe31 in PyEval_EvalFrameEx (throwflag=0, f=0x1574038) at Python/ceval.c:753
#11 _PyFunction_FastCall (co=co@entry=0x7f16da0a7d20, args=, args@entry=0x7ffec7c725a0, nargs=nargs@entry=2, globals=globals@entry=0x7f16da0a50d8) at Python/ceval.c:4906
#12 0x0000000000549d86 in _PyFunction_FastCallDict (func=func@entry=0x7f16da0546a8, args=args@entry=0x7ffec7c725a0, nargs=nargs@entry=2, kwargs=kwargs@entry=0x0) at Python/ceval.c:5008
#13 0x000000000045214f in _PyObject_FastCallDict (func=0x7f16da0546a8, args=0x7ffec7c725a0, nargs=2, kwargs=0x0) at Objects/abstract.c:2310
#14 0x000000000045224b in _PyObject_Call_Prepend (func=0x7f16da0546a8, obj=0x7f16d35983c8, args=0x7f16d3c77160, kwargs=0x0) at Objects/abstract.c:2373
#15 0x0000000000452002 in _PyObject_FastCallDict (func=0x7f16d3a82088, args=0x7ffec7c72690, nargs=1, kwargs=0x0) at Objects/abstract.c:2331
#16 0x0000000000453186 in PyObject_CallMethodObjArgs (callable=0x7f16d3a82088, name=) at Objects/abstract.c:2759
#17 0x00000000005bc155 in _bufferedreader_raw_read (self=self@entry=0x7f16d575dca8, start=, len=8192) at ./Modules/_io/bufferedio.c:1498
#18 0x00000000005be99c in _bufferedreader_fill_buffer (self=0x7f16d575dca8) at ./Modules/_io/bufferedio.c:1530
#19 _buffered_readline (self=self@entry=0x7f16d575dca8, limit=65537) at ./Modules/_io/bufferedio.c:1159
#20 0x00000000005bed61 in _io__Buffered_readline_impl (size=, self=0x7f16d575dca8) at ./Modules/_io/bufferedio.c:1219
#21 _io__Buffered_readline (self=0x7f16d575dca8, args=) at ./Modules/_io/clinic/bufferedio.c.h:251
#22 0x00000000004a9f89 in _PyCFunction_FastCallDict (kwargs=0x0, nargs=1, args=0x5bed20 <_io__Buffered_readline>, func_obj=0x7f16d34c9dc8) at Objects/methodobject.c:234
#23 _PyCFunction_FastCallKeywords (func=func@entry=0x7f16d34c9dc8, stack=stack@entry=0x1573f58, nargs=1, kwnames=kwnames@entry=0x0) at Objects/methodobject.c:294
#24 0x0000000000540e84 in call_function (pp_stack=pp_stack@entry=0x7ffec7c72a80, oparg=oparg@entry=1, kwnames=kwnames@entry=0x0) at Python/ceval.c:4824
#25 0x0000000000545cdc in _PyEval_EvalFrameDefault (f=, throwflag=) at Python/ceval.c:3322
#26 0x000000000053fe31 in PyEval_EvalFrameEx (throwflag=0, f=0x1573da8) at Python/ceval.c:753
#27 _PyFunction_FastCall (co=, args=, nargs=1, globals=globals@entry=0x7f16d9519240) at Python/ceval.c:4906
#28 0x0000000000540fc7 in fast_function (kwnames=0x0, nargs=, stack=, func=0x7f16d6415f28) at Python/ceval.c:4941
#29 call_function (pp_stack=pp_stack@entry=0x7ffec7c72ca0, oparg=oparg@entry=0, kwnames=kwnames@entry=0x0) at Python/ceval.c:4845
#30 0x0000000000545cdc in _PyEval_EvalFrameDefault (f=, throwflag=) at Python/ceval.c:3322
#31 0x000000000053fe31 in PyEval_EvalFrameEx (throwflag=0, f=0x1573b68) at Python/ceval.c:753
#32 _PyFunction_FastCall (co=, args=, nargs=1, globals=globals@entry=0x7f16d9519240) at Python/ceval.c:4906
#33 0x0000000000540fc7 in fast_function (kwnames=0x0, nargs=, stack=, func=0x7f16d6419048) at Python/ceval.c:4941
#34 call_function (pp_stack=pp_stack@entry=0x7ffec7c72ec0, oparg=oparg@entry=0, kwnames=kwnames@entry=0x0) at Python/ceval.c:4845
#35 0x0000000000545cdc in _PyEval_EvalFrameDefault (f=, throwflag=) at Python/ceval.c:3322
#36 0x000000000053fe31 in PyEval_EvalFrameEx (throwflag=0, f=0x1571498) at Python/ceval.c:753
#37 _PyFunction_FastCall (co=, args=, nargs=1, globals=globals@entry=0x7f16d9519240) at Python/ceval.c:4906
#38 0x0000000000540fc7 in fast_function (kwnames=0x0, nargs=, stack=, func=0x7f16d641bae8) at Python/ceval.c:4941
#39 call_function (pp_stack=pp_stack@entry=0x7ffec7c730e0, oparg=oparg@entry=0, kwnames=kwnames@entry=0x0) at Python/ceval.c:4845
#40 0x0000000000545cdc in _PyEval_EvalFrameDefault (f=, throwflag=) at Python/ceval.c:3322
#41 0x0000000000540aa1 in PyEval_EvalFrameEx (throwflag=0, f=0x1570058) at Python/ceval.c:753
#42 _PyEval_EvalCodeWithName (_co=0x7f16da061810, globals=globals@entry=0x7f16da05f048, locals=locals@entry=0x0, args=, argcount=4, kwnames=0x7f16da06a0b0, kwargs=kwargs@entry=0x156f418, kwcount=4, kwstep=kwstep@entry=1, defs=0x7f16d5d1e0e0, defcount=defcount@entry=2, kwdefs=0x0, closure=0x0, name=name@entry=0x7f16da062fb0, qualname=0x7f16da068138) at Python/ceval.c:4153
#43 0x0000000000540d9f in fast_function (kwnames=0x156f418, nargs=, stack=, func=0x7f16d5d31bf8) at Python/ceval.c:4965
#44 call_function (pp_stack=pp_stack@entry=0x7ffec7c73380, oparg=oparg@entry=7, kwnames=kwnames@entry=0x7f16da06a098) at Python/ceval.c:4845
#45 0x00000000005461cb in _PyEval_EvalFrameDefault (f=, throwflag=) at Python/ceval.c:3338
#46 0x0000000000540aa1 in PyEval_EvalFrameEx (throwflag=0, f=0x156f1a8) at Python/ceval.c:753
#47 _PyEval_EvalCodeWithName (_co=0x7f16da061ae0, globals=globals@entry=0x7f16da05f048, locals=locals@entry=0x0, args=, argcount=1, kwnames=0x7f16d56b71e0, kwargs=kwargs@entry=0x156d4e8, kwcount=10, kwstep=kwstep@entry=1, defs=0x7f16d638e8e0, defcount=defcount@entry=10, kwdefs=0x0, closure=0x0, name=name@entry=0x7f16da064ae8, qualname=0x7f16da06a170) at Python/ceval.c:4153
#48 0x0000000000540d9f in fast_function (kwnames=0x156d4e8, nargs=, stack=, func=0x7f16d5d31e18) at Python/ceval.c:4965
#49 call_function (pp_stack=pp_stack@entry=0x7ffec7c73610, oparg=oparg@entry=10, kwnames=kwnames@entry=0x7f16d56b71c8) at Python/ceval.c:4845
#50 0x00000000005461cb in _PyEval_EvalFrameDefault (f=, throwflag=) at Python/ceval.c:3338
#51 0x0000000000540aa1 in PyEval_EvalFrameEx (throwflag=0, f=0x156d2c8) at Python/ceval.c:753
#52 _PyEval_EvalCodeWithName (_co=_co@entry=0x7f16d539f660, globals=globals@entry=0x7f16d539c5a0, locals=locals@entry=0x0, args=args@entry=0x7ffec7c73870, argcount=argcount@entry=2, kwnames=kwnames@entry=0x7f16d538cee0, kwargs=kwargs@entry=0x7f16d538cee8, kwcount=10, kwcount@entry=5, kwstep=kwstep@entry=2, defs=0x7f16d53a21c0, defcount=5, kwdefs=0x0, closure=0x0, name=0x7f16e14bc420, qualname=0x7f16d539cc90) at Python/ceval.c:4153
#53 0x0000000000549ca6 in _PyFunction_FastCallDict (func=func@entry=0x7f16d53a9598, args=args@entry=0x7ffec7c73870, nargs=nargs@entry=2, kwargs=kwargs@entry=0x7f16d36d61f8) at Python/ceval.c:5057
#54 0x000000000045214f in _PyObject_FastCallDict (func=0x7f16d53a9598, args=0x7ffec7c73870, nargs=2, kwargs=0x7f16d36d61f8) at Objects/abstract.c:2310
#55 0x000000000045224b in _PyObject_Call_Prepend (func=0x7f16d53a9598, obj=0x7f16d3e052b0, args=0x7f16d38709e8, kwargs=0x7f16d36d61f8) at Objects/abstract.c:2373
#56 0x0000000000451e20 in PyObject_Call (func=func@entry=0x7f16d5337b88, args=args@entry=0x7f16d38709e8, kwargs=kwargs@entry=0x7f16d36d61f8) at Objects/abstract.c:2261
#57 0x00000000005460d2 in do_call_core (kwdict=0x7f16d36d61f8, callargs=0x7f16d38709e8, func=0x7f16d5337b88) at Python/ceval.c:5093
#58 _PyEval_EvalFrameDefault (f=, throwflag=) at Python/ceval.c:3391
#59 0x0000000000540aa1 in PyEval_EvalFrameEx (throwflag=0, f=0x15bde38) at Python/ceval.c:753
#60 _PyEval_EvalCodeWithName (_co=_co@entry=0x7f16d539b420, globals=globals@entry=0x7f16d5394900, locals=locals@entry=0x0, args=args@entry=0x7ffec7c73c20, argcount=argcount@entry=2, kwnames=kwnames@entry=0x7f16d534e690, kwargs=kwargs@entry=0x7f16d534e698, kwcount=12, kwcount@entry=6, kwstep=kwstep@entry=2, defs=0x0, defcount=0, kwdefs=0x0, closure=0x0, name=0x7f16e14bc420, qualname=0x7f16d539a9f0) at Python/ceval.c:4153
#61 0x0000000000549ca6 in _PyFunction_FastCallDict (func=func@entry=0x7f16d53aa048, args=args@entry=0x7ffec7c73c20, nargs=nargs@entry=2, kwargs=kwargs@entry=0x7f16d36d63f0) at Python/ceval.c:5057
#62 0x000000000045214f in _PyObject_FastCallDict (func=0x7f16d53aa048, args=0x7ffec7c73c20, nargs=2, kwargs=0x7f16d36d63f0) at Objects/abstract.c:2310
#63 0x000000000045224b in _PyObject_Call_Prepend (func=0x7f16d53aa048, obj=0x7f16e133c5c0, args=0x7f16d3c770f0, kwargs=0x7f16d36d63f0) at Objects/abstract.c:2373
#64 0x0000000000451e20 in PyObject_Call (func=func@entry=0x7f16d3a82a88, args=args@entry=0x7f16d3c770f0, kwargs=kwargs@entry=0x7f16d36d63f0) at Objects/abstract.c:2261
#65 0x00000000005460d2 in do_call_core (kwdict=0x7f16d36d63f0, callargs=0x7f16d3c770f0, func=0x7f16d3a82a88) at Python/ceval.c:5093
#66 _PyEval_EvalFrameDefault (f=, throwflag=) at Python/ceval.c:3391
#67 0x0000000000540aa1 in PyEval_EvalFrameEx (throwflag=0, f=0x1568dd8) at Python/ceval.c:753
#68 _PyEval_EvalCodeWithName (_co=_co@entry=0x7f16d538eed0, globals=globals@entry=0x7f16d5394900, locals=locals@entry=0x0, args=args@entry=0x7ffec7c73fd0, argcount=argcount@entry=3, kwnames=kwnames@entry=0x7f16d34f6b00, kwargs=kwargs@entry=0x7f16d34f6b08, kwcount=4, kwcount@entry=2, kwstep=kwstep@entry=2, defs=0x7f16d5744600, defcount=14, kwdefs=0x0, closure=0x0, name=0x7f16da0a45a8, qualname=0x7f16d539a470) at Python/ceval.c:4153
#69 0x0000000000549ca6 in _PyFunction_FastCallDict (func=func@entry=0x7f16d53a9b70, args=args@entry=0x7ffec7c73fd0, nargs=nargs@entry=3, kwargs=kwargs@entry=0x7f16d36d6ea0) at Python/ceval.c:5057
#70 0x000000000045214f in _PyObject_FastCallDict (func=0x7f16d53a9b70, args=0x7ffec7c73fd0, nargs=3, kwargs=0x7f16d36d6ea0) at Objects/abstract.c:2310
#71 0x000000000045224b in _PyObject_Call_Prepend (func=0x7f16d53a9b70, obj=0x7f16e133c5c0, args=0x7f16d3b744c8, kwargs=0x7f16d36d6ea0) at Objects/abstract.c:2373
#72 0x0000000000451e20 in PyObject_Call (func=func@entry=0x7f16d3a42888, args=args@entry=0x7f16d3b744c8, kwargs=kwargs@entry=0x7f16d36d6ea0) at Objects/abstract.c:2261
#73 0x00000000005460d2 in do_call_core (kwdict=0x7f16d36d6ea0, callargs=0x7f16d3b744c8, func=0x7f16d3a42888) at Python/ceval.c:5093
#74 _PyEval_EvalFrameDefault (f=, throwflag=) at Python/ceval.c:3391
#75 0x0000000000540aa1 in PyEval_EvalFrameEx (throwflag=0, f=0x7f16d5331768) at Python/ceval.c:753
#76 _PyEval_EvalCodeWithName (_co=0x7f16d538ef60, globals=globals@entry=0x7f16d5394900, locals=locals@entry=0x0, args=, argcount=2, kwnames=0x7f16e12fd1b0, kwargs=kwargs@entry=0x15c2238, kwcount=1, kwstep=kwstep@entry=1, defs=0x0, defcount=defcount@entry=0, kwdefs=0x0, closure=0x0, name=name@entry=0x7f16e14a5490, qualname=0x7f16d539a530) at Python/ceval.c:4153
#77 0x0000000000540d9f in fast_function (kwnames=0x15c2238, nargs=, stack=, func=0x7f16d53a9bf8) at Python/ceval.c:4965
#78 call_function (pp_stack=pp_stack@entry=0x7ffec7c743b0, oparg=oparg@entry=2, kwnames=kwnames@entry=0x7f16e12fd198) at Python/ceval.c:4845
#79 0x00000000005461cb in _PyEval_EvalFrameDefault (f=, throwflag=) at Python/ceval.c:3338
#80 0x000000000053fe31 in PyEval_EvalFrameEx (throwflag=0, f=0x15c2058) at Python/ceval.c:753
#81 _PyFunction_FastCall (co=, args=, nargs=4, globals=globals@entry=0x7f16e144c1b0) at Python/ceval.c:4906
#82 0x0000000000540fc7 in fast_function (kwnames=0x0, nargs=, stack=, func=0x7f16d531a378) at Python/ceval.c:4941
#83 call_function (pp_stack=pp_stack@entry=0x7ffec7c745c0, oparg=oparg@entry=4, kwnames=kwnames@entry=0x0) at Python/ceval.c:4845
#84 0x0000000000545cdc in _PyEval_EvalFrameDefault (f=, throwflag=) at Python/ceval.c:3322
#85 0x0000000000540aa1 in PyEval_EvalFrameEx (throwflag=0, f=0x12d7ab8) at Python/ceval.c:753
#86 _PyEval_EvalCodeWithName (_co=_co@entry=0x7f16e13cac00, globals=globals@entry=0x7f16e1338828, locals=locals@entry=0x7f16e1359d18, args=args@entry=0x0, argcount=argcount@entry=0, kwnames=kwnames@entry=0x0, kwargs=kwargs@entry=0x0, kwcount=kwcount@entry=0, kwstep=kwstep@entry=2, defs=defs@entry=0x0, defcount=defcount@entry=0, kwdefs=kwdefs@entry=0x0, closure=closure@entry=0x0, name=name@entry=0x0, qualname=qualname@entry=0x0) at Python/ceval.c:4153
#87 0x00000000005418e0 in PyEval_EvalCodeEx (closure=0x0, kwdefs=0x0, defcount=0, defs=0x0, kwcount=0, kws=0x0, argcount=0, args=0x0, locals=locals@entry=0x7f16e1359d18, globals=globals@entry=0x7f16e1338828, _co=_co@entry=0x7f16e13cac00) at Python/ceval.c:4174
#88 PyEval_EvalCode (co=co@entry=0x7f16e13cac00, globals=globals@entry=0x7f16e144c1b0, locals=locals@entry=0x7f16e144c1b0) at Python/ceval.c:730
#89 0x0000000000426768 in run_mod (arena=0x7f16e1466150, flags=0x7ffec7c748d0, locals=0x7f16e144c1b0, globals=0x7f16e144c1b0, filename=0x7f16e1359d18, mod=0x12e3e38) at Python/pythonrun.c:1025
#90 PyRun_FileExFlags (fp=0x1276480, filename_str=, start=, globals=0x7f16e144c1b0, locals=0x7f16e144c1b0, closeit=1, flags=0x7ffec7c748d0) at Python/pythonrun.c:978
#91 0x000000000042694d in PyRun_SimpleFileExFlags (fp=0x1276480, filename=, closeit=1, flags=0x7ffec7c748d0) at Python/pythonrun.c:420
#92 0x000000000043baea in run_file (p_cf=0x7ffec7c748d0, filename=0x12352a0 L"main.py", fp=0x1276480) at Modules/main.c:340
#93 Py_Main (argc=argc@entry=3, argv=argv@entry=0x1234010) at Modules/main.c:810
#94 0x000000000041d962 in main (argc=3, argv=) at ./Programs/python.c:69

System Information

$ python -m requests.help

{
"chardet": {
"version": "3.0.4"
},
"cryptography": {
"version": ""
},
"idna": {
"version": "2.6"
},
"implementation": {
"name": "CPython",
"version": "3.6.5"
},
"platform": {
"release": "3.10.0-693.el7.x86_64",
"system": "Linux"
},
"pyOpenSSL": {
"openssl_version": "",
"version": null
},
"requests": {
"version": "2.18.4"
},
"system_ssl": {
"version": "100020bf"
},
"urllib3": {
"version": "1.22"
},
"using_pyopenssl": false
}

ls -al /proc/12585/fd:
total 0
dr-x------ 2 root root 0 May 3 16:55 .
dr-xr-xr-x 9 root root 0 Apr 26 20:50 ..
l-wx------ 1 root root 64 May 3 16:55 0 -> /dev/null
l-wx------ 1 root root 64 May 3 16:55 1 -> /root/server/data.log
l-wx------ 1 root root 64 May 3 16:55 2 -> /root/server/data.log
lrwx------ 1 root root 64 May 3 16:55 3 -> socket:[168821]
lrwx------ 1 root root 64 May 3 16:55 4 -> socket:[168836]
lrwx------ 1 root root 64 May 3 16:55 5 -> socket:[170894]

cat /proc/12585/net/tcp:
sl local_address rem_address st tx_queue rx_queue tr tm->when retrnsmt uid timeout inode
0: 00000000:006F 00000000:0000 0A 00000000:00000000 00:00000000 00000000 0 0 15883 1 ffff8800b6168000 100 0 0 10 0
1: 0100007F:0019 00000000:0000 0A 00000000:00000000 00:00000000 00000000 0 0 19668 1 ffff8800b61687c0 100 0 0 10 0
2: 00000000:E49A 00000000:0000 0A 00000000:00000000 00:00000000 00000000 0 0 17210 1 ffff880137f60000 100 0 0 10 0
3: E5C6230A:B0D6 E6D0210A:0050 08 00000000:00000001 00:00000000 00000000 0 0 168821 1 ffff8800b616ae80 22 4 0 10 -1
4: E5C6230A:97D0 CCDB200A:0050 01 00000000:00000000 00:00000000 00000000 0 0 170894 1 ffff8800b616cd80 20 0 0 10 -1
5: E5C6230A:E49A C3C6230A:C525 01 00000000:00000000 02:0009A9F7 00000000 0 0 366844 4 ffff8800b6169f00 20 4 31 10 -1

netstat -anlp | grep python3:
tcp 1 0 10.35.198.229:45270 10.33.208.230:80 CLOSE_WAIT 12585/python3
tcp 0 0 10.35.198.229:38864 10.32.219.204:80 ESTABLISHED 12585/python3

This command is only available on Requests v2.16.4 and greater. Otherwise,
please provide some basic information about your system (Python version,
operating system, &c).

[zhangyuchun]

use timeout arg.

[bennlich]

I'm seeing the same issue, and I am using the timeout arg.

sudo strace -p 68636
strace: Process 68636 attached
recvfrom(4, 

And as far as I can tell this is happening during:

  r = requests.post(config.get('ad_url'), oauth_params, timeout=10)

in the following larger context:

  print('Fetching access token...')
  r = requests.post(config.get('ad_url'), oauth_params, timeout=10)
  data = r.json()
  if 'access_token' not in data:
      print('could not get access token', r)

  access_token = data['access_token']
  print(access_token)

My reasoning being, in my logs, I see:

Fetching access token...

And then silence.

I guess I should try to reproduce with my own client/server setup. And maybe at this point it's more likely that there's something wrong with my logging than that there's a bug like this in requests.