[getdns-users] Context.timeout in python-getdns

Daniel Kahn Gillmor dkg at fifthhorseman.net
Thu Jan 18 02:23:06 UTC 2018


On Wed 2018-01-17 21:15:46 -0500, Daniel Kahn Gillmor wrote:
> and when i strace the process, i see some remarkable things, including
> invocations of poll() with a timeout variable far greater than 15000,
> like so:
>
>     poll([{fd=5, events=POLLIN}, {fd=4, events=POLLIN}, {fd=-1}], 3, 67688)

below is a stream of strace output during a particularly long wait.
Note the series of timeouts: 72 seconds, 30 seconds, 96 seconds, 30
seconds, and finally another 96 second timeout.  all of this is within
one iteration of lookup_addresses() :/

let me know if there's better debugging information you'd want to see...

    --dkg

poll([{fd=4, events=POLLIN}], 1, 71704) = 0 (Timeout) <71.775838>
socket(AF_INET, SOCK_STREAM, IPPROTO_TCP) = 5 <0.000139>
fcntl(5, F_GETFL)                       = 0x2 (flags O_RDWR) <0.000064>
fcntl(5, F_SETFL, O_RDWR|O_NONBLOCK)    = 0 <0.000107>
connect(5, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("34.237.254.79")}, 16) = -1 EINPROGRESS (Operation now in progress) <0.000052>
close(4)                                = 0 <0.000014>
poll([{fd=5, events=POLLOUT}, {fd=-1}], 2, 29999) = 0 (Timeout) <30.029080>
close(5)                                = 0 <0.000048>
socket(AF_INET, SOCK_DGRAM, IPPROTO_IP) = 4 <0.000026>
setsockopt(4, SOL_IP, IP_MTU_DISCOVER, [5], 4) = 0 <0.000011>
bind(4, {sa_family=AF_INET, sin_port=htons(4459), sin_addr=inet_addr("0.0.0.0")}, 16) = 0 <0.000021>
fcntl(4, F_GETFL)                       = 0x2 (flags O_RDWR) <0.000011>
fcntl(4, F_SETFL, O_RDWR|O_NONBLOCK)    = 0 <0.000008>
sendto(4, "\375F\0\20\0\1\0\0\0\0\0\1\3ns2\6ittltd\3com\0\0\34\0\1\0\0)\377\377\0\0\200\0\0\0", 43, 0, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("52.207.176.29")}, 16) = 43 <0.000035>
poll([{fd=4, events=POLLIN}], 1, 96255) = 0 (Timeout) <96.351372>
socket(AF_INET, SOCK_STREAM, IPPROTO_TCP) = 5 <0.000115>
fcntl(5, F_GETFL)                       = 0x2 (flags O_RDWR) <0.000070>
fcntl(5, F_SETFL, O_RDWR|O_NONBLOCK)    = 0 <0.000039>
connect(5, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("52.207.176.29")}, 16) = -1 EINPROGRESS (Operation now in progress) <0.000035>
close(4)                                = 0 <0.000011>
poll([{fd=5, events=POLLOUT}, {fd=-1}], 2, 29999) = 0 (Timeout) <30.029168>
close(5)                                = 0 <0.000065>
socket(AF_INET, SOCK_DGRAM, IPPROTO_IP) = 4 <0.000032>
setsockopt(4, SOL_IP, IP_MTU_DISCOVER, [5], 4) = 0 <0.000071>
bind(4, {sa_family=AF_INET, sin_port=htons(59558), sin_addr=inet_addr("0.0.0.0")}, 16) = 0 <0.000017>
fcntl(4, F_GETFL)                       = 0x2 (flags O_RDWR) <0.000010>
fcntl(4, F_SETFL, O_RDWR|O_NONBLOCK)    = 0 <0.000010>
sendto(4, "\225\260\0\20\0\1\0\0\0\0\0\1\4nsg2\rnamebrightdns\3com\0\0\34\0\1\0\0)\377\377\0\0\200\0\0\0", 51, 0, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("54.208.25.173")}, 16) = 51 <0.000046>
poll([{fd=4, events=POLLIN}], 1, 886)   = 0 (Timeout) <0.886987>
socket(AF_INET, SOCK_DGRAM, IPPROTO_IP) = 5 <0.000059>
setsockopt(5, SOL_IP, IP_MTU_DISCOVER, [5], 4) = 0 <0.000082>
bind(5, {sa_family=AF_INET, sin_port=htons(51779), sin_addr=inet_addr("0.0.0.0")}, 16) = 0 <0.000016>
fcntl(5, F_GETFL)                       = 0x2 (flags O_RDWR) <0.000011>
fcntl(5, F_SETFL, O_RDWR|O_NONBLOCK)    = 0 <0.000011>
sendto(5, "$\27\0\20\0\1\0\0\0\0\0\1\4nsg2\rnamebrightdns\3com\0\0\34\0\1\0\0)\5\300\0\0\200\0\0\0", 51, 0, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("54.208.25.173")}, 16) = 51 <0.000044>
close(4)                                = 0 <0.000019>
poll([{fd=5, events=POLLIN}, {fd=-1}], 2, 886) = 1 ([{fd=5, revents=POLLIN}]) <0.815401>
recvfrom(5, "$\27\204\0\0\1\0\0\0\0\0\1\4nsg2\rnamebrightdns\3com\0\0\34\0\1\4nsg2\rnamebrightdns\3com\0\0\1\0\1\0\0\0\0\0\4\"\355\376O\0\0)\5\300\0\0\200\0\0\0", 65552, 0, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("54.208.25.173")}, [128->16]) = 89 <0.000036>
socket(AF_INET, SOCK_DGRAM, IPPROTO_IP) = 4 <0.000026>
setsockopt(4, SOL_IP, IP_MTU_DISCOVER, [5], 4) = 0 <0.000016>
bind(4, {sa_family=AF_INET, sin_port=htons(8014), sin_addr=inet_addr("0.0.0.0")}, 16) = 0 <0.000011>
fcntl(4, F_GETFL)                       = 0x2 (flags O_RDWR) <0.000009>
fcntl(4, F_SETFL, O_RDWR|O_NONBLOCK)    = 0 <0.000012>
sendto(4, "\1p\0\20\0\1\0\0\0\0\0\1\4nsg1\rnamebrightdns\3com\0\0\34\0\1\0\0)\377\377\0\0\200\0\0\0", 51, 0, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("34.194.232.55")}, 16) = 51 <0.000030>
close(5)                                = 0 <0.000016>
recvfrom(4, 0x561a85269e90, 65552, 0, 0x7ffcae1a5738, [128]) = -1 EAGAIN (Resource temporarily unavailable) <0.000022>
poll([{fd=4, events=POLLIN}], 1, 1503)  = 1 ([{fd=4, revents=POLLIN}]) <1.009433>
recvfrom(4, "\1p\204\0\0\1\0\0\0\0\0\1\4nsg1\rnamebrightdns\3com\0\0\34\0\1\4nsg1\rnamebrightdns\3com\0\0\1\0\1\0\0\0\0\0\4\"\341&\272\0\0)\377\377\0\0\200\0\0\0", 65552, 0, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("34.194.232.55")}, [128->16]) = 89 <0.000047>
socket(AF_INET, SOCK_DGRAM, IPPROTO_IP) = 5 <0.000029>
setsockopt(5, SOL_IP, IP_MTU_DISCOVER, [5], 4) = 0 <0.000019>
bind(5, {sa_family=AF_INET, sin_port=htons(32857), sin_addr=inet_addr("0.0.0.0")}, 16) = 0 <0.000022>
fcntl(5, F_GETFL)                       = 0x2 (flags O_RDWR) <0.000009>
fcntl(5, F_SETFL, O_RDWR|O_NONBLOCK)    = 0 <0.000009>
sendto(5, "Ty\0\20\0\1\0\0\0\0\0\1\3ns1\6ittltd\3com\0\0\34\0\1\0\0)\377\377\0\0\200\0\0\0", 43, 0, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("52.203.116.207")}, 16) = 43 <0.000033>
socket(AF_INET, SOCK_DGRAM, IPPROTO_IP) = 6 <0.000015>
setsockopt(6, SOL_IP, IP_MTU_DISCOVER, [5], 4) = 0 <0.000010>
bind(6, {sa_family=AF_INET, sin_port=htons(28285), sin_addr=inet_addr("0.0.0.0")}, 16) = 0 <0.000012>
fcntl(6, F_GETFL)                       = 0x2 (flags O_RDWR) <0.000009>
fcntl(6, F_SETFL, O_RDWR|O_NONBLOCK)    = 0 <0.000009>
sendto(6, "\260\212\0\20\0\1\0\0\0\0\0\1\3ns1\6ittltd\3com\0\0\1\0\1\0\0)\377\377\0\0\200\0\0\0", 43, 0, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("34.225.38.186")}, 16) = 43 <0.000023>
close(4)                                = 0 <0.000017>
recvfrom(5, 0x561a85269e90, 65552, 0, 0x7ffcae1a5738, [128]) = -1 EAGAIN (Resource temporarily unavailable) <0.000009>
recvfrom(6, 0x561a85269e90, 65552, 0, 0x7ffcae1a5738, [128]) = -1 EAGAIN (Resource temporarily unavailable) <0.000010>
poll([{fd=5, events=POLLIN}, {fd=6, events=POLLIN}], 2, 96255



More information about the Users mailing list