We've definitely found a case of libcurl with NSS not observing timeouts.

Here's the trace:

#0 0x00000031d08e8bdf in __GI___poll (fds=fds_at_entry=0x7fd22abfc370,
nfds=nfds_at_entry=1, timeout=timeout_at_entry=5000) at
../sysdeps/unix/sysv/linux/poll.c:87
#1 0x00000031d0424d6b in pt_poll_now (op=op_at_entry=0x7fd22abfc3c0) at
../../../mozilla/nsprpub/pr/src/pthreads/ptio.c:583
#2 0x00000031d042590d in pt_Continue (op=0x7fd22abfc3c0) at
../../../mozilla/nsprpub/pr/src/pthreads/ptio.c:706
#3 pt_Recv (fd=0x7fd229e94c70, buf=0x7fd229cc404c, amount=1700,
flags=<optimized out>, timeout=4294967295) at
../../../mozilla/nsprpub/pr/src/pthreads/ptio.c:1865
#4 0x00000031d641ccce in ssl_DefRecv (ss=ss_at_entry=0x7fd229c89000,
buf=<optimized out>, len=1700, flags=flags_at_entry=0) at ssldef.c:62
#5 0x00000031d6418272 in ssl3_GatherData (flags=0, gs=<optimized
out>, ss=0x7fd229c89000) at ssl3gthr.c:59
#6 ssl3_GatherCompleteHandshake (ss=ss_at_entry=0x7fd229c89000,
flags=flags_at_entry=0) at ssl3gthr.c:318
#7 0x00000031d641880a in ssl3_GatherAppDataRecord (ss=0x7fd229c89000,
flags=0) at ssl3gthr.c:404
#8 0x00000031d6421f45 in DoRecv (flags=0, len=16384,
out=0x7fd229c5f870
"m\225\257\351\271pc\206\bx\352n\024\035\267\026ų\030\310\031\345\357\247\332t\373\240\336_\231\363\ny/\002y\236\034)n>\361ۙ\006\062\313\367\320>\255Ǵ\246[\022t\214\313G\263Ƭ\262\276\253q\363dH\341\207\023J֘\214\062\356\355\227\032\vq0\347\337\333:[V\255\204:qa\231\356\034\207:\324\\\221ǝ|\337\277\355\241\245\244@\300\314v\345Im\"\027\022\a:\002\350\021\021\037\273\210\240_at_1\341Ƶ\356.\004N\032\270\236\354$ק\254\221ţ\001\354\314\370\320\364Iw\234\242=\270\360\372i/
\301\324\021\337\064X\025\320\016&A", ss=0x7fd229c89000) at
sslsecur.c:535
#9 ssl_SecureRecv (ss=0x7fd229c89000, buf=0x7fd229c5f870
"m\225\257\351\271pc\206\bx\352n\024\035\267\026ų\030\310\031\345\357\247\332t\373\240\336_\231\363\ny/\002y\236\034)n>\361ۙ\006\062\313\367\320>\255Ǵ\246[\022t\214\313G\263Ƭ\262\276\253q\363dH\341\207\023J֘\214\062\356\355\227\032\vq0\347\337\333:[V\255\204:qa\231\356\034\207:\324\\\221ǝ|\337\277\355\241\245\244@\300\314v\345Im\"\027\022\a:\002\350\021\021\037\273\210\240_at_1\341Ƶ\356.\004N\032\270\236\354$ק\254\221ţ\001\354\314\370\320\364Iw\234\242=\270\360\372i/
\301\324\021\337\064X\025\320\016&A", len=16384, flags=0) at
sslsecur.c:1144
#10 0x00000031d6425e76 in ssl_Recv (fd=<optimized out>,
buf=0x7fd229c5f870, len=16384, flags=0, timeout=4294967295) at
sslsock.c:2071
#11 0x00000031d843fdd2 in nss_recv (conn=0x7fd229c78600,
num=<optimized out>, buf=<optimized out>, buffersize=<optimized out>,
curlcode=0x7fd22abfc57c) at nss.c:1485
#12 0x00000031d8414574 in Curl_read (conn=conn_at_entry=0x7fd229c78600,
sockfd=11, buf=0x7fd229c5f870
"m\225\257\351\271pc\206\bx\352n\024\035\267\026ų\030\310\031\345\357\247\332t\373\240\336_\231\363\ny/\002y\236\034)n>\361ۙ\006\062\313\367\320>\255Ǵ\246[\022t\214\313G\263Ƭ\262\276\253q\363dH\341\207\023J֘\214\062\356\355\227\032\vq0\347\337\333:[V\255\204:qa\231\356\034\207:\324\\\221ǝ|\337\277\355\241\245\244@\300\314v\345Im\"\027\022\a:\002\350\021\021\037\273\210\240_at_1\341Ƶ\356.\004N\032\270\236\354$ק\254\221ţ\001\354\314\370\320\364Iw\234\242=\270\360\372i/
\301\324\021\337\064X\025\320\016&A", sizerequested=16384,
n=n_at_entry=0x7fd22abfc5d8) at sendf.c:575
#13 0x00000031d8427800 in readwrite_data (done=0x7fd22abfc65f,
didwhat=<synthetic pointer>, k=0x7fd229c5f028, conn=0x7fd229c78600,
data=0x7fd229c5f000) at transfer.c:409
#14 Curl_readwrite (conn=conn_at_entry=0x7fd229c78600,
done=done_at_entry=0x7fd22abfc65f) at transfer.c:1029
#15 0x00000031d842937d in Transfer (conn=0x7fd229c78600) at transfer.c:1396
#16 Curl_do_perform (data=0x7fd229c5f000) at transfer.c:2108
#17 0x00000031d842982b in Curl_perform
(data=data_at_entry=0x7fd229c5f000) at transfer.c:2232
#18 0x00000031d8429d0c in curl_easy_perform
(curl=curl_at_entry=0x7fd229c5f000) at easy.c:541

NSS seems stuck in poll loop, which has been going on for hours:
[pid 25049] poll([{fd=9, events=POLLIN|POLLPRI}], 1, 5000 <unfinished ...>
[pid 31082] <... poll resumed> ) = 0 (Timeout)
[pid 25049] <... poll resumed> ) = 0 (Timeout)
[pid 31082] poll([{fd=11, events=POLLIN|POLLPRI}], 1, 5000 <unfinished ...>
[pid 25049] poll([{fd=9, events=POLLIN|POLLPRI}], 1, 5000 <unfinished ...>
[pid 31082] <... poll resumed> ) = 0 (Timeout)
[pid 31082] poll([{fd=11, events=POLLIN|POLLPRI}], 1, 5000 <unfinished ...>
[pid 25049] <... poll resumed> ) = 0 (Timeout)
[pid 25049] poll([{fd=9, events=POLLIN|POLLPRI}], 1, 5000 <unfinished ...>
[pid 31082] <... poll resumed> ) = 0 (Timeout)
[pid 31082] poll([{fd=11, events=POLLIN|POLLPRI}], 1, 5000 <unfinished ...>
[pid 25049] <... poll resumed> ) = 0 (Timeout)

This probably shouldn't be happening with our configured timeouts:

    curl_easy_setopt(session, CURLOPT_CONNECTTIMEOUT_MS, 500);
    curl_easy_setopt(session, CURLOPT_TIMEOUT, 60 * 3);

Is this an NSS bug, or is it an issue with how libcurl uses NSS? I'm
on Fedora 17 with libcurl 7.24.0 and NSS 3.14.3.

--
David Strauss
   | david_at_davidstrauss.net
   | +1 512 577 5827 [mobile]
-------------------------------------------------------------------
List admin: http://cool.haxx.se/list/listinfo/curl-library
Etiquette:  http://curl.haxx.se/mail/etiquette.html