{"action":"created","issue":{"url":"https://api.github.com/repos/PowerDNS/pdns/issues/6778","repository_url":"https://api.github.com/repos/PowerDNS/pdns","labels_url":"https://api.github.com/repos/PowerDNS/pdns/issues/6778/labels{/name}","comments_url":"https://api.github.com/repos/PowerDNS/pdns/issues/6778/comments","events_url":"https://api.github.com/repos/PowerDNS/pdns/issues/6778/events","html_url":"https://github.com/PowerDNS/pdns/issues/6778","id":339314905,"node_id":"MDU6SXNzdWUzMzkzMTQ5MDU=","number":6778,"title":"Unable to load RPZ zone. Error waiting for answer from. Interrupted system call.","user":{"login":"Homas","id":13776103,"node_id":"MDQ6VXNlcjEzNzc2MTAz","avatar_url":"https://avatars1.githubusercontent.com/u/13776103?v=4","gravatar_id":"","url":"https://api.github.com/users/Homas","html_url":"https://github.com/Homas","followers_url":"https://api.github.com/users/Homas/followers","following_url":"https://api.github.com/users/Homas/following{/other_user}","gists_url":"https://api.github.com/users/Homas/gists{/gist_id}","starred_url":"https://api.github.com/users/Homas/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/Homas/subscriptions","organizations_url":"https://api.github.com/users/Homas/orgs","repos_url":"https://api.github.com/users/Homas/repos","events_url":"https://api.github.com/users/Homas/events{/privacy}","received_events_url":"https://api.github.com/users/Homas/received_events","type":"User","site_admin":false},"labels":[{"id":37446007,"node_id":"MDU6TGFiZWwzNzQ0NjAwNw==","url":"https://api.github.com/repos/PowerDNS/pdns/labels/defect","name":"defect","color":"cccccc","default":false},{"id":37445984,"node_id":"MDU6TGFiZWwzNzQ0NTk4NA==","url":"https://api.github.com/repos/PowerDNS/pdns/labels/rec","name":"rec","color":"fbca04","default":false}],"state":"open","locked":false,"assignee":null,"assignees":[],"milestone":{"url":"https://api.github.com/repos/PowerDNS/pdns/milestones/37","html_url":"https://github.com/PowerDNS/pdns/milestone/37","labels_url":"https://api.github.com/repos/PowerDNS/pdns/milestones/37/labels","id":2713612,"node_id":"MDk6TWlsZXN0b25lMjcxMzYxMg==","number":37,"title":"rec-4.1.x","description":"","creator":{"login":"aerique","id":89097,"node_id":"MDQ6VXNlcjg5MDk3","avatar_url":"https://avatars1.githubusercontent.com/u/89097?v=4","gravatar_id":"","url":"https://api.github.com/users/aerique","html_url":"https://github.com/aerique","followers_url":"https://api.github.com/users/aerique/followers","following_url":"https://api.github.com/users/aerique/following{/other_user}","gists_url":"https://api.github.com/users/aerique/gists{/gist_id}","starred_url":"https://api.github.com/users/aerique/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/aerique/subscriptions","organizations_url":"https://api.github.com/users/aerique/orgs","repos_url":"https://api.github.com/users/aerique/repos","events_url":"https://api.github.com/users/aerique/events{/privacy}","received_events_url":"https://api.github.com/users/aerique/received_events","type":"User","site_admin":false},"open_issues":11,"closed_issues":49,"state":"open","created_at":"2017-08-21T14:44:39Z","updated_at":"2018-07-09T07:08:51Z","due_on":null,"closed_at":null},"comments":2,"created_at":"2018-07-09T06:00:43Z","updated_at":"2018-07-09T19:38:00Z","closed_at":null,"author_association":"NONE","body":"- Program: Recursor\r\n- Issue type: Bug report\r\n\r\n### Short description\r\nDuring startup pdns recursor tries to download RPZ feeds and immediately closes connections.\r\n### Environment\r\n - Operating system: Ubuntu 18.04 (running in VirtualBox)\r\n - Software version: 4.1.3\r\n - Software source: PowerDNS repository\r\n\r\n### Steps to reproduce\r\n1. Configure RPZ feed(s) & syslog settings\r\n2. Start/restart service\r\n\r\n### Expected behaviour\r\nRPZ feeds are downloaded correctly from a first attempt.\r\n\r\n### Actual behaviour\r\nI'm working on RPZ distribution DNS server (https://github.com/Homas/ioc2rpz) and found that pdns recursor tries to pull RPZ feeds during startup and immediately (or a few milliseconds later) close connections with a reason  'Error connecting: Interrupted system call'. After the startup procedure RPZ feeds transferred correctly.\r\nOn other side (ioc2rpz and ISC bind) I see that pdns recursor opens a connection and ioc2rpz/bind sends data the connection is closed.\r\nIt is not happening in 100% cases but very often (70-90% cases).\r\n\r\nHere are the Recursor log:\r\n\r\n> Jul  8 07:36:42 ioc2rpz systemd[1]: Starting PowerDNS Recursor...\r\n> Jul  8 07:36:42 ioc2rpz pdns_recursor[8307]: PowerDNS Recursor 4.1.3 (C) 2001-2018 PowerDNS.COM BV\r\n> Jul  8 07:36:42 ioc2rpz pdns_recursor[8307]: Using 64-bits mode. Built using gcc 7.3.0 on May 22 2018 14:51:09 by root@caec6e15ff79.\r\n> Jul  8 07:36:42 ioc2rpz pdns_recursor[8307]: PowerDNS comes with ABSOLUTELY NO WARRANTY. This is free software, and you are welcome to redistribute it according to the terms of the GPL version 2.\r\n> Jul  8 07:36:42 ioc2rpz pdns_recursor[8307]: Reading random entropy from '/dev/urandom'\r\n> Jul  8 07:36:42 ioc2rpz pdns_recursor[8307]: If using IPv6, please raise sysctl net.ipv6.route.max_size, currently set to 4096 which is < 16384\r\n> Jul  8 07:36:42 ioc2rpz pdns_recursor[8307]: NOT using IPv6 for outgoing queries - set 'query-local-address6=::' to enable\r\n> Jul  8 07:36:42 ioc2rpz pdns_recursor[8307]: Only allowing queries from: 127.0.0.0/8, 10.0.0.0/8, 100.64.0.0/10, 169.254.0.0/16, 192.168.0.0/16, 172.16.0.0/12, ::1/128, fc00::/7, fe80::/10\r\n> **Jul  8 07:36:42 ioc2rpz pdns_recursor[8307]: Loading RPZ zone 'dns-bh.ioc2rpz' from 192.168.56.43:53**\r\n> Jul  8 07:36:42 ioc2rpz pdns_recursor[8307]: With TSIG key 'tkey_1' of algorithm 'hmac-md5'\r\n> Jul  8 07:36:42 ioc2rpz pdns_recursor[8307]: Will not send queries to: 127.0.0.0/8, 10.0.0.0/8, 100.64.0.0/10, 169.254.0.0/16, 192.168.0.0/16, 172.16.0.0/12, ::1/128, fc00::/7, fe80::/10, 0.0.0.0/8, 192.0.0.0/24, 192.0.2.0/24, 198.51.100.0/24, 203.0.113.0/24, 240.0.0.0/4, ::/96, ::ffff:0:0/96, 100::/64, 2001:db8::/32, 0.0.0.0, ::\r\n> Jul  8 07:36:42 ioc2rpz pdns_recursor[8307]: PowerDNS Recursor itself will distribute queries over threads\r\n> Jul  8 07:36:42 ioc2rpz pdns_recursor[8307]: Inserting rfc 1918 private space zones\r\n> Jul  8 07:36:42 ioc2rpz pdns_recursor[8307]: Listening for UDP queries on 127.0.0.1:53\r\n> Jul  8 07:36:42 ioc2rpz pdns_recursor[8307]: Listening for UDP queries on 192.168.56.44:53\r\n> Jul  8 07:36:42 ioc2rpz pdns_recursor[8307]: Enabled TCP data-ready filter for (slight) DoS protection\r\n> Jul  8 07:36:42 ioc2rpz pdns_recursor[8307]: Listening for TCP queries on 127.0.0.1:53\r\n> Jul  8 07:36:42 ioc2rpz pdns_recursor[8307]: Listening for TCP queries on 192.168.56.44:53\r\n> **Jul  8 07:36:42 ioc2rpz pdns_recursor[8307]: Unable to load RPZ zone 'dns-bh.ioc2rpz' from '192.168.56.43': 'Error waiting for answer from 192.168.56.43:53: Interrupted system call'. (Will try again in 10 seconds...)**\r\n> Jul  8 07:36:42 ioc2rpz pdns_recursor[8307]: Set effective group id to 114\r\n> **Jul  8 07:36:42 ioc2rpz pdns_recursor[8307]: Loading RPZ zone 'dns-bh.ioc2rpz' from 192.168.56.43:53**\r\n> Jul  8 07:36:42 ioc2rpz pdns_recursor[8307]: With TSIG key 'tkey_1' of algorithm 'hmac-md5'\r\n> **Jul  8 07:36:42 ioc2rpz pdns_recursor[8307]: Unable to load RPZ zone 'dns-bh.ioc2rpz' from '192.168.56.43': 'Error connecting: Interrupted system call'. (Will try again in 10 seconds...)**\r\n> Jul  8 07:36:42 ioc2rpz pdns_recursor[8307]: Set effective user id to 112\r\n> Jul  8 07:36:42 ioc2rpz pdns_recursor[8307]: Launching 3 threads\r\n> Jul  8 07:36:42 ioc2rpz systemd[1]: Started PowerDNS Recursor.\r\n> Jul  8 07:36:42 ioc2rpz pdns_recursor[8307]: Done priming cache with root hints\r\n> Jul  8 07:36:42 ioc2rpz pdns_recursor[8307]: message repeated 2 times: [ Done priming cache with root hints]\r\n> Jul  8 07:36:42 ioc2rpz pdns_recursor[8307]: Enabled 'epoll' multiplexer\r\n> Jul  8 07:36:42 ioc2rpz pdns_recursor[8307]: Done priming cache with root hints\r\n> **Jul  8 07:36:52 ioc2rpz pdns_recursor[8307]: Loading RPZ zone 'dns-bh.ioc2rpz' from 192.168.56.43:53**\r\n> Jul  8 07:36:52 ioc2rpz pdns_recursor[8307]: With TSIG key 'tkey_1' of algorithm 'hmac-md5'\r\n> Jul  8 07:36:52 ioc2rpz pdns_recursor[8307]: Loaded & indexed 690 policy records so far\r\n> **Jul  8 07:36:52 ioc2rpz pdns_recursor[8307]: Done: 48600 policy records active, SOA: ns1.ioc2rpz.localdomain. support.ioc2rpz.localdomain. 1531031280 86400 3600 2592000 7200**\r\n> \r\n\r\n\r\nLogs from ioc2rpz:\r\n> Jul  8 07:36:41 ioc2rpz aae893a2eeaa[796]: 2018-07-08 07:36:41 ioc2rpz tcp child started\r\n> **Jul  8 07:36:41 ioc2rpz aae893a2eeaa[796]: 2018-07-08 07:36:41 tcp/192.168.56.44:54491 query dns-bh.ioc2rpz 252 1**\r\n> Jul  8 07:36:41 ioc2rpz aae893a2eeaa[796]: 2018-07-08 07:36:41 Found Key ... 2018-07-08 07:36:41 Good timestamp ... Valid MAC\r\n> Jul  8 07:36:41 ioc2rpz aae893a2eeaa[796]: =ERROR REPORT==== 8-Jul-2018::07:36:41.956208 ===\r\n> Jul  8 07:36:41 ioc2rpz aae893a2eeaa[796]: ** Generic server <0.324.0> terminating\r\n> Jul  8 07:36:41 ioc2rpz aae893a2eeaa[796]: ** Last message in was {tcp,#Port<0.89>,\r\n> Jul  8 07:36:41 ioc2rpz aae893a2eeaa[796]:                             <<0,108,147,2,0,0,0,1,0,0,0,0,0,1,6,100,110,115,\r\n> Jul  8 07:36:41 ioc2rpz aae893a2eeaa[796]:                               45,98,104,7,105,111,99,50,114,112,122,0,0,252,0,\r\n> Jul  8 07:36:41 ioc2rpz aae893a2eeaa[796]:                               1,6,116,107,101,121,95,49,0,0,250,0,255,0,0,0,0,\r\n> Jul  8 07:36:41 ioc2rpz aae893a2eeaa[796]:                               0,58,8,104,109,97,99,45,109,100,53,7,115,105,\r\n> Jul  8 07:36:41 ioc2rpz aae893a2eeaa[796]:                               103,45,97,108,103,3,114,101,103,3,105,110,116,0,\r\n> Jul  8 07:36:41 ioc2rpz aae893a2eeaa[796]:                               0,0,91,65,191,10,1,44,0,16,34,190,225,85,182,43,\r\n> Jul  8 07:36:41 ioc2rpz aae893a2eeaa[796]:                               72,8,214,92,24,253,112,238,142,118,147,2,0,0,0,0>>}\r\n> Jul  8 07:36:41 ioc2rpz aae893a2eeaa[796]: ** When Server state == {state,#Port<0.89>,[<0.82.0>]}\r\n> Jul  8 07:36:41 ioc2rpz aae893a2eeaa[796]: ** Reason for termination ==\r\n> **Jul  8 07:36:41 ioc2rpz aae893a2eeaa[796]: ** {{badmatch,{error,closed}},**\r\n> Jul  8 07:36:41 ioc2rpz aae893a2eeaa[796]:     [{ioc2rpz,send_dns_tcp,3,[{file,\"src/ioc2rpz.erl\"},{line,88}]},\r\n> Jul  8 07:36:41 ioc2rpz aae893a2eeaa[796]:      {ioc2rpz,send_cached_zone,7,[{file,\"src/ioc2rpz.erl\"},{line,532}]},\r\n> Jul  8 07:36:41 ioc2rpz aae893a2eeaa[796]:      {ioc2rpz,parse_dns_request,3,[{file,\"src/ioc2rpz.erl\"},{line,208}]},\r\n> Jul  8 07:36:41 ioc2rpz aae893a2eeaa[796]:      {ioc2rpz,handle_info,2,[{file,\"src/ioc2rpz.erl\"},{line,58}]},\r\n> Jul  8 07:36:41 ioc2rpz aae893a2eeaa[796]:      {gen_server,try_dispatch,4,[{file,\"gen_server.erl\"},{line,637}]},\r\n> Jul  8 07:36:41 ioc2rpz aae893a2eeaa[796]:      {gen_server,handle_msg,6,[{file,\"gen_server.erl\"},{line,711}]},\r\n> Jul  8 07:36:41 ioc2rpz aae893a2eeaa[796]:      {proc_lib,init_p_do_apply,3,[{file,\"proc_lib.erl\"},{line,249}]}]}\r\n> Jul  8 07:36:41 ioc2rpz aae893a2eeaa[796]: \r\n> Jul  8 07:36:41 ioc2rpz aae893a2eeaa[796]: =CRASH REPORT==== 8-Jul-2018::07:36:41.963206 ===\r\n> Jul  8 07:36:41 ioc2rpz aae893a2eeaa[796]:   crasher:\r\n> Jul  8 07:36:41 ioc2rpz aae893a2eeaa[796]:     initial call: ioc2rpz:init/1\r\n> Jul  8 07:36:41 ioc2rpz aae893a2eeaa[796]:     pid: <0.324.0>\r\n> Jul  8 07:36:41 ioc2rpz aae893a2eeaa[796]:     registered_name: []\r\n> Jul  8 07:36:41 ioc2rpz aae893a2eeaa[796]:     exception error: no match of right hand side value {error,closed}\r\n> Jul  8 07:36:41 ioc2rpz aae893a2eeaa[796]:       in function  ioc2rpz:send_dns_tcp/3 (src/ioc2rpz.erl, line 88)\r\n> Jul  8 07:36:41 ioc2rpz aae893a2eeaa[796]:       in call from ioc2rpz:send_cached_zone/7 (src/ioc2rpz.erl, line 532)\r\n> Jul  8 07:36:41 ioc2rpz aae893a2eeaa[796]:       in call from ioc2rpz:parse_dns_request/3 (src/ioc2rpz.erl, line 208)\r\n> Jul  8 07:36:41 ioc2rpz aae893a2eeaa[796]:       in call from ioc2rpz:handle_info/2 (src/ioc2rpz.erl, line 58)\r\n> Jul  8 07:36:41 ioc2rpz aae893a2eeaa[796]:       in call from gen_server:try_dispatch/4 (gen_server.erl, line 637)\r\n> Jul  8 07:36:41 ioc2rpz aae893a2eeaa[796]:       in call from gen_server:handle_msg/6 (gen_server.erl, line 711)\r\n> Jul  8 07:36:41 ioc2rpz aae893a2eeaa[796]:     ancestors: [ioc2rpz_sup,<0.81.0>]\r\n> Jul  8 07:36:41 ioc2rpz aae893a2eeaa[796]:     message_queue_len: 1\r\n> Jul  8 07:36:41 ioc2rpz aae893a2eeaa[796]:     **messages: [{tcp_closed,#Port<0.89>}]**\r\n> Jul  8 07:36:41 ioc2rpz aae893a2eeaa[796]:     links: [<0.82.0>]\r\n> Jul  8 07:36:41 ioc2rpz aae893a2eeaa[796]:     dictionary: []\r\n> Jul  8 07:36:41 ioc2rpz aae893a2eeaa[796]:     trap_exit: false\r\n> Jul  8 07:36:41 ioc2rpz aae893a2eeaa[796]:     status: running\r\n> Jul  8 07:36:41 ioc2rpz aae893a2eeaa[796]:     heap_size: 6772\r\n> Jul  8 07:36:41 ioc2rpz aae893a2eeaa[796]:     stack_size: 27\r\n> Jul  8 07:36:41 ioc2rpz aae893a2eeaa[796]:     reductions: 58553\r\n> Jul  8 07:36:41 ioc2rpz aae893a2eeaa[796]:   neighbours:\r\n> Jul  8 07:36:41 ioc2rpz aae893a2eeaa[796]: \r\n> Jul  8 07:36:41 ioc2rpz aae893a2eeaa[796]: =SUPERVISOR REPORT==== 8-Jul-2018::07:36:41.968075 ===\r\n> Jul  8 07:36:41 ioc2rpz aae893a2eeaa[796]:     supervisor: {local,ioc2rpz_sup}\r\n> Jul  8 07:36:41 ioc2rpz aae893a2eeaa[796]:     errorContext: child_terminated\r\n> Jul  8 07:36:41 ioc2rpz aae893a2eeaa[796]:     reason: {{badmatch,{error,closed}},\r\n> Jul  8 07:36:41 ioc2rpz aae893a2eeaa[796]:              [{ioc2rpz,send_dns_tcp,3,[{file,\"src/ioc2rpz.erl\"},{line,88}]},\r\n> Jul  8 07:36:41 ioc2rpz aae893a2eeaa[796]:               {ioc2rpz,send_cached_zone,7,\r\n> Jul  8 07:36:41 ioc2rpz aae893a2eeaa[796]:                        [{file,\"src/ioc2rpz.erl\"},{line,532}]},\r\n> Jul  8 07:36:41 ioc2rpz aae893a2eeaa[796]:               {ioc2rpz,parse_dns_request,3,\r\n> Jul  8 07:36:41 ioc2rpz aae893a2eeaa[796]:                        [{file,\"src/ioc2rpz.erl\"},{line,208}]},\r\n> Jul  8 07:36:41 ioc2rpz aae893a2eeaa[796]:               {ioc2rpz,handle_info,2,[{file,\"src/ioc2rpz.erl\"},{line,58}]},\r\n> Jul  8 07:36:41 ioc2rpz aae893a2eeaa[796]:               {gen_server,try_dispatch,4,[{file,\"gen_server.erl\"},{line,637}]},\r\n> Jul  8 07:36:41 ioc2rpz aae893a2eeaa[796]:               {gen_server,handle_msg,6,[{file,\"gen_server.erl\"},{line,711}]},\r\n> Jul  8 07:36:41 ioc2rpz aae893a2eeaa[796]:               {proc_lib,init_p_do_apply,3,\r\n> Jul  8 07:36:41 ioc2rpz aae893a2eeaa[796]:                         [{file,\"proc_lib.erl\"},{line,249}]}]}\r\n> Jul  8 07:36:41 ioc2rpz aae893a2eeaa[796]:     offender: [{pid,<0.324.0>},\r\n> Jul  8 07:36:41 ioc2rpz aae893a2eeaa[796]:                {id,ioc2rpz},\r\n> Jul  8 07:36:41 ioc2rpz aae893a2eeaa[796]:                {mfargs,{ioc2rpz,start_ioc2rpz,undefined}},\r\n> Jul  8 07:36:41 ioc2rpz aae893a2eeaa[796]:                {restart_type,temporary},\r\n> Jul  8 07:36:41 ioc2rpz aae893a2eeaa[796]:                {shutdown,1000},\r\n> Jul  8 07:36:41 ioc2rpz aae893a2eeaa[796]:                {child_type,worker}]\r\n> Jul  8 07:36:51 ioc2rpz aae893a2eeaa[796]: 2018-07-08 07:36:51 ioc2rpz tcp child started\r\n> **Jul  8 07:36:51 ioc2rpz aae893a2eeaa[796]: 2018-07-08 07:36:51 tcp/192.168.56.44:54403 query dns-bh.ioc2rpz 252 1\r\n> Jul  8 07:36:51 ioc2rpz aae893a2eeaa[796]: 2018-07-08 07:36:51 Found Key ... 2018-07-08 07:36:51 Good timestamp ... Valid MAC\r\n> Jul  8 07:36:52 ioc2rpz aae893a2eeaa[796]: 2018-07-08 07:36:52 Zone \"dns-bh.ioc2rpz\" transfer time was 57 milliseconds**\r\n\r\n\r\nLogs from bind:\r\n\r\n**> Jul  9 05:50:47 ioc2rpz named[779]: client @0x7fee3ffc1020 192.168.56.45#53701/key tkey_1 (at-hosts.ioc2rpz): transfer of 'at-hosts.ioc2rpz/IN': AXFR started: TSIG tkey_1 (serial 1531100580)\r\n> Jul  9 05:50:47 ioc2rpz named[779]: client @0x7fee3ffc1020 192.168.56.45#53701/key tkey_1 (at-hosts.ioc2rpz): transfer of 'at-hosts.ioc2rpz/IN': send: socket is not connected**\r\n> Jul  9 05:50:47 ioc2rpz named[779]: client @0x7fee17fc1020 192.168.56.45#53407/key tkey_1 (at-ipv4.ioc2rpz): transfer of 'at-ipv4.ioc2rpz/IN': AXFR started: TSIG tkey_1 (serial 1531100580)\r\n> Jul  9 05:50:47 ioc2rpz named[779]: client @0x7fee17fc1020 192.168.56.45#53407/key tkey_1 (at-ipv4.ioc2rpz): transfer of 'at-ipv4.ioc2rpz/IN': **send: socket is not connected**\r\n> Jul  9 05:50:47 ioc2rpz named[779]: client @0x7fedbda416b0 192.168.56.45#51195/key tkey_1 (notracking.ioc2rpz): transfer of 'notracking.ioc2rpz/IN': AXFR started: TSIG tkey_1 (serial 1531100580)\r\n> Jul  9 05:50:47 ioc2rpz named[779]: client @0x7fedbda416b0 192.168.56.45#51195/key tkey_1 (notracking.ioc2rpz): transfer of 'notracking.ioc2rpz/IN': send: socket is not connected\r\n> Jul  9 05:50:47 ioc2rpz named[779]: client @0x7fee3ffc1020 192.168.56.45#57115/key tkey_1 (dns-bh.ioc2rpz): transfer of 'dns-bh.ioc2rpz/IN': AXFR started: TSIG tkey_1 (serial 1531100580)\r\n> Jul  9 05:50:47 ioc2rpz named[779]: client @0x7fee3ffc1020 192.168.56.45#57115/key tkey_1 (dns-bh.ioc2rpz): transfer of 'dns-bh.ioc2rpz/IN': send: socket is not connected\r\n> Jul  9 05:50:47 ioc2rpz named[779]: client @0x7fee33fc7030 192.168.56.45#37413/key tkey_1 (at-hosts.ioc2rpz): transfer of 'at-hosts.ioc2rpz/IN': AXFR started: TSIG tkey_1 (serial 1531100580)\r\n> Jul  9 05:50:47 ioc2rpz named[779]: client @0x7fee33fc7030 192.168.56.45#37413/key tkey_1 (at-hosts.ioc2rpz): transfer of 'at-hosts.ioc2rpz/IN': send: socket is not connected\r\n> Jul  9 05:50:47 ioc2rpz named[779]: client @0x7fee17fc1020 192.168.56.45#55417/key tkey_1 (at-ipv4.ioc2rpz): transfer of 'at-ipv4.ioc2rpz/IN': AXFR started: TSIG tkey_1 (serial 1531100580)\r\n> Jul  9 05:50:47 ioc2rpz named[779]: client @0x7fee17fc1020 192.168.56.45#55417/key tkey_1 (at-ipv4.ioc2rpz): transfer of 'at-ipv4.ioc2rpz/IN': send: socket is not connected\r\n> Jul  9 05:50:47 ioc2rpz named[779]: client @0x7fee57fc1020 192.168.56.45#45787/key tkey_1 (notracking.ioc2rpz): transfer of 'notracking.ioc2rpz/IN': AXFR started: TSIG tkey_1 (serial 1531100580)\r\n> Jul  9 05:50:47 ioc2rpz named[779]: client @0x7fee57fc1020 192.168.56.45#45787/key tkey_1 (notracking.ioc2rpz): transfer of 'notracking.ioc2rpz/IN': send: socket is not connected\r\n> Jul  9 05:50:47 ioc2rpz named[779]: client @0x7fedbda416b0 192.168.56.45#33745/key tkey_1 (dns-bh.ioc2rpz): transfer of 'dns-bh.ioc2rpz/IN': AXFR started: TSIG tkey_1 (serial 1531100580)\r\n> Jul  9 05:50:47 ioc2rpz named[779]: client @0x7fedbda416b0 192.168.56.45#33745/key tkey_1 (dns-bh.ioc2rpz): transfer of 'dns-bh.ioc2rpz/IN': send: socket is not connected\r\n> Jul  9 05:50:57 ioc2rpz named[779]: client @0x7fedebfc1020 192.168.56.45#33537/key tkey_1 (notracking.ioc2rpz): transfer of 'notracking.ioc2rpz/IN': AXFR started: TSIG tkey_1 (serial 1531100580)\r\n> Jul  9 05:50:57 ioc2rpz named[779]: client @0x7fedfffcd030 192.168.56.45#46345/key tkey_1 (dns-bh.ioc2rpz): transfer of 'dns-bh.ioc2rpz/IN': AXFR started: TSIG tkey_1 (serial 1531100580)\r\n> Jul  9 05:50:57 ioc2rpz named[779]: client @0x7feddbfc1020 192.168.56.45#35553/key tkey_1 (at-hosts.ioc2rpz): transfer of 'at-hosts.ioc2rpz/IN': AXFR started: TSIG tkey_1 (serial 1531100580)\r\n> Jul  9 05:50:57 ioc2rpz named[779]: client @0x7fedd3fc1020 192.168.56.45#53467/key tkey_1 (at-ipv4.ioc2rpz): transfer of 'at-ipv4.ioc2rpz/IN': AXFR started: TSIG tkey_1 (serial 1531100580)\r\n> Jul  9 05:51:02 ioc2rpz named[779]: client @0x7fedfffcd030 192.168.56.45#46345/key tkey_1 (dns-bh.ioc2rpz): transfer of 'dns-bh.ioc2rpz/IN': AXFR ended\r\n> \r\n\r\n\r\n### Other information\r\n4.1.1 has different strange behaviour. After starting up it made AXFR and immediately after that IXFR. There was a bug \"Fix IXFR skipping the additions part of the last sequence\" in 4.1.1 this is why I've upgraded to 4.1.3\r\nTo check that the issues is not related to any old libs I've deployed a new Ubuntu 18.04 VM and installed PDNS Recursor only from PowerDNS repository \r\nJust in case I'm running VirtualBox with 3 VMs on Macbook Pro. VMs connected via \"Host-only Adapter\".\r\n\r\n"},"comment":{"url":"https://api.github.com/repos/PowerDNS/pdns/issues/comments/403595741","html_url":"https://github.com/PowerDNS/pdns/issues/6778#issuecomment-403595741","issue_url":"https://api.github.com/repos/PowerDNS/pdns/issues/6778","id":403595741,"node_id":"MDEyOklzc3VlQ29tbWVudDQwMzU5NTc0MQ==","user":{"login":"rgacogne","id":1086257,"node_id":"MDQ6VXNlcjEwODYyNTc=","avatar_url":"https://avatars2.githubusercontent.com/u/1086257?v=4","gravatar_id":"","url":"https://api.github.com/users/rgacogne","html_url":"https://github.com/rgacogne","followers_url":"https://api.github.com/users/rgacogne/followers","following_url":"https://api.github.com/users/rgacogne/following{/other_user}","gists_url":"https://api.github.com/users/rgacogne/gists{/gist_id}","starred_url":"https://api.github.com/users/rgacogne/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/rgacogne/subscriptions","organizations_url":"https://api.github.com/users/rgacogne/orgs","repos_url":"https://api.github.com/users/rgacogne/repos","events_url":"https://api.github.com/users/rgacogne/events{/privacy}","received_events_url":"https://api.github.com/users/rgacogne/received_events","type":"User","site_admin":false},"created_at":"2018-07-09T19:38:00Z","updated_at":"2018-07-09T19:38:00Z","author_association":"MEMBER","body":"Right, IIRC this is the `SIGRT_1` trick used to let other threads know that they need to switch credentials when `set*id()` has been called from a thread because `POSIX` requires that all threads use the same credentials but Linux actually handles it per thread, or something like that. This probably means we should either delay the Lua parsing until after we have dropped our privileges (but that means making sure we don't need special privileges at that time) or delay the creation of the `RPZ` and `protobuf` threads until after we have dropped our privileges."}}
{"actor":{"display_login":"rgacogne"}}