Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Unbound segmentation fault on Ubuntu 18.04 LTS #5

Closed
sheldonkwoodward opened this issue Feb 7, 2019 · 8 comments
Closed

Unbound segmentation fault on Ubuntu 18.04 LTS #5

sheldonkwoodward opened this issue Feb 7, 2019 · 8 comments

Comments

@sheldonkwoodward
Copy link

Issue

When running on Ubuntu 18.04 LTS, Unbound frequently experiences segmentation faults.

How to replicate

I have disabled systemd-resolved so I could bind the container to port 53 and in /etc/reslolv.conf, the nameserver address is set to 127.0.0.1. The container works with the always restart policy applied but still restarts frequently. I have tried this on Docker for Mac and have not experienced any of these issues. I can provide more information if needed.

Logs

Here is the minimal error log, with a more verbose log below.

=========================================
 =========================================
 === CLOUDFLARE DNS OVER TLS CONTAINER ===
 =========================================
 =========================================
 == by github.com/qdm12 - Quentin McGaw ==

Running as nonrootuser
Unbound version: 1.7.3
Unbound DNS server: cloudflare
Unbound listening UDP port: 53
Verbosity level set to 1 on 5
Verbosity details level set to 0 on 4
Malicious hostnames and ips blocking is off
[1549497232] unbound[24:0] warning: unable to initgroups nonrootuser: Operation not permitted
[1549497232] unbound[24:0] notice: init module 0: validator
[1549497232] unbound[24:0] notice: init module 1: iterator
[1549497232] unbound[24:0] info: start of service (unbound 1.7.3).
[1549497233] unbound[24:0] info: generate keytag query _ta-4a5c-4f66. NULL IN
[1549497233] unbound[24:1] info: generate keytag query _ta-4a5c-4f66. NULL IN

 =========================================
 Unbound exit with status 139
 =========================================
Segmentation fault (core dumped)

Max verbosity log

...
...
...
[1549507602] unbound[26:1] info: reply from <.> 1.1.1.1#853
[1549507602] unbound[26:1] info: incoming scrubbed packet: ;; ->>HEADER<<- opcode: QUERY, rcode: NOERROR, id: 0
;; flags: qr rd ra ; QUERY: 1, ANSWER: 0, AUTHORITY: 6, ADDITIONAL: 0
;; QUESTION SECTION:
googleapis.com.	IN	DS

;; ANSWER SECTION:

;; AUTHORITY SECTION:
ck0pojmg874ljref7efn8430qvit8bsm.com.	85662	IN	NSEC3	1 1 0 - ck0q1gin43n1arrc9osm6qpqr81h5m9a NS SOA RRSIG DNSKEY NSEC3PARAM ;{flags: optout}
ck0pojmg874ljref7efn8430qvit8bsm.com.	85662	IN	RRSIG	NSEC3 8 2 86400 20190212213240 20190205202240 16883 com. lCQD2bK8qGow5GSWWDLcSOicHflSzVEchqETJAcMBURY+th9NtHF4nR9zeFWlZN8msSxnz1aAiUeQ7jRPXxV9cwHu2yPfR3iP0i1i5GiK98alVmwS4v2ylx4khb1WgJYeE7+CR+aEzKThjCTyPEDtBEvZFf9RCHZDPL4vPk2Xwk= ;{id = 16883}
com.	3600	IN	SOA	a.gtld-servers.net. nstld.verisign-grs.com. 1549506851 1800 900 604800 86400
com.	3600	IN	RRSIG	SOA 8 1 900 20190214023411 20190207012411 16883 com. u1lnSxqnSa2v/N52C1N4EM/It7o2CRDx+WZy0LqKyLHF6+pRhZ2c+B+5+5L8NQln8ZqitD9yJyCbvIBVgmAY+0MUftFGHWsdF2FVfALogofIl6d1IatCIKTqj9LM9bBTbSL1/GeE/HdRI0OGsiKR2yyBv0rhMmJovL9pv/p4Jcs= ;{id = 16883}
6l930cninqadn9he8d1tngam03ra30ou.com.	85662	IN	NSEC3	1 1 0 - 6l960svqib6ijqo2kvbdina1oefbd9hu NS DS RRSIG ;{flags: optout}
6l930cninqadn9he8d1tngam03ra30ou.com.	85662	IN	RRSIG	NSEC3 8 2 86400 20190210055006 20190203044006 16883 com. KXUO7RaL79Dy1v5/6d50k8mtgeVVAcgfdSvcmhzlw+gX/dx+X7va42oodO8xBl86s+lpXybU3kpfEvZVYvhKOmNHGSzP/zfzE4NDPjpxp3Fx/VHi25kC5C2rum4DMpPX5kldUYvdW6/BoBLdZ7n/oJt1r/skp+G8Uby/TBuoGF0= ;{id = 16883}

;; ADDITIONAL SECTION:
;; MSG SIZE  rcvd: 753

[1549507602] unbound[26:1] debug: iter_handle processing q with state QUERY RESPONSE STATE
[1549507602] unbound[26:1] info: query response was nodata ANSWER
[1549507602] unbound[26:1] debug: iter_handle processing q with state FINISHED RESPONSE STATE
[1549507602] unbound[26:1] info: finishing processing for googleapis.com. DS IN
[1549507602] unbound[26:1] debug: mesh_run: iterator module exit state is module_finished
[1549507602] unbound[26:1] debug: validator[module 0] operate: extstate:module_wait_module event:module_event_moddone
[1549507602] unbound[26:1] info: validator operate: query googleapis.com. DS IN
[1549507602] unbound[26:1] debug: validator: nextmodule returned
[1549507602] unbound[26:1] debug: not validating response, is valrec(validation recursion lookup)
[1549507602] unbound[26:1] debug: mesh_run: validator module exit state is module_finished
[1549507602] unbound[26:1] info: validator: inform_super, sub is googleapis.com. DS IN
[1549507602] unbound[26:1] info: super is clientservices.googleapis.com. A IN
[1549507602] unbound[26:1] info: verify rrset 6l930cninqadn9he8d1tngam03ra30ou.com. NSEC3 IN
[1549507602] unbound[26:1] debug: verify sig 16883 8
[1549507602] unbound[26:1] debug: verify result: sec_status_secure
[1549507602] unbound[26:1] debug: nsec3: keysize 1024 bits, max iterations 150
[1549507602] unbound[26:1] info: ce candidate com. TYPE0 CLASS0
[1549507602] unbound[26:1] info: NSEC3s for the referral proved no DS.
[1549507602] unbound[26:1] debug: validator[module 0] operate: extstate:module_wait_subquery event:module_event_pass
[1549507602] unbound[26:1] info: validator operate: query clientservices.googleapis.com. A IN
[1549507602] unbound[26:1] debug: val handle processing q with state VAL_VALIDATE_STATE
[1549507602] unbound[26:1] info: Verified that unsigned response is INSECURE
[1549507602] unbound[26:1] debug: val handle processing q with state VAL_FINISHED_STATE
[1549507602] unbound[26:1] debug: mesh_run: validator module exit state is module_finished
[1549507602] unbound[26:1] debug: query took 0.124501 sec
[1549507602] unbound[26:1] info: mesh_run: end 0 recursion states (0 with reply, 0 detached), 0 waiting replies, 4 recursion replies sent, 0 replies dropped, 0 states jostled out
[1549507602] unbound[26:1] info: average recursion processing time 0.151196 sec
[1549507602] unbound[26:1] info: histogram of recursion processing times
[1549507602] unbound[26:1] info: [25%]=0.0873813 median[50%]=0.109227 [75%]=0.131072
[1549507602] unbound[26:1] info: lower(secs) upper(secs) recursions
[1549507602] unbound[26:1] info:    0.065536    0.131072 3
[1549507602] unbound[26:1] info:    0.262144    0.524288 1
[1549507602] unbound[26:1] debug: cache memory msg=69352 rrset=73827 infra=8402 val=69892
[1549507602] unbound[26:1] debug: svcd callbacks end
[1549507602] unbound[26:1] debug: close fd 16
[1549507643] unbound[26:1] debug: udp request from ip4 172.16.34.142 port 15491 (len 16)
[1549507643] unbound[26:0] debug: udp request from ip4 172.16.34.142 port 50122 (len 16)
[1549507643] unbound[26:1] debug: mesh_run: start
[1549507643] unbound[26:0] debug: mesh_run: start
[1549507643] unbound[26:1] debug: validator[module 0] operate: extstate:module_state_initial event:module_event_new
[1549507643] unbound[26:0] debug: validator[module 0] operate: extstate:module_state_initial event:module_event_new
[1549507643] unbound[26:1] info: validator operate: query stackoverflow.com. A IN
[1549507643] unbound[26:0] info: validator operate: query www.gravatar.com. A IN
[1549507643] unbound[26:0] debug: validator: pass to next module
[1549507643] unbound[26:0] debug: mesh_run: validator module exit state is module_wait_module
[1549507643] unbound[26:1] debug: validator: pass to next module
[1549507643] unbound[26:0] debug: iterator[module 1] operate: extstate:module_state_initial event:module_event_pass
[1549507643] unbound[26:1] debug: mesh_run: validator module exit state is module_wait_module
[1549507643] unbound[26:0] debug: process_request: new external request event
[1549507643] unbound[26:1] debug: iterator[module 1] operate: extstate:module_state_initial event:module_event_pass
[1549507643] unbound[26:0] debug: iter_handle processing q with state INIT REQUEST STATE
[1549507643] unbound[26:1] debug: process_request: new external request event
[1549507643] unbound[26:0] info: resolving www.gravatar.com. A IN
[1549507643] unbound[26:1] debug: iter_handle processing q with state INIT REQUEST STATE
[1549507643] unbound[26:0] debug: request has dependency depth of 0
[1549507643] unbound[26:1] info: resolving stackoverflow.com. A IN
[1549507643] unbound[26:1] debug: request has dependency depth of 0
[1549507643] unbound[26:0] debug: forwarding request
[1549507643] unbound[26:1] debug: forwarding request
[1549507643] unbound[26:0] debug: iter_handle processing q with state QUERY TARGETS STATE
[1549507643] unbound[26:1] debug: iter_handle processing q with state QUERY TARGETS STATE
[1549507643] unbound[26:0] info: processQueryTargets: www.gravatar.com. A IN
[1549507643] unbound[26:1] info: processQueryTargets: stackoverflow.com. A IN
[1549507643] unbound[26:0] debug: processQueryTargets: targetqueries 0, currentqueries 0 sentcount 0
[1549507643] unbound[26:1] debug: processQueryTargets: targetqueries 0, currentqueries 0 sentcount 0
[1549507643] unbound[26:0] info: DelegationPoint<.>: 0 names (0 missing), 2 addrs (0 result, 2 avail) parentNS
[1549507643] unbound[26:1] info: DelegationPoint<.>: 0 names (0 missing), 2 addrs (0 result, 2 avail) parentNS
[1549507643] unbound[26:0] debug:   [cloudflare-dns.com] ip4 1.0.0.1 port 853 (len 16)
[1549507643] unbound[26:1] debug:   [cloudflare-dns.com] ip4 1.0.0.1 port 853 (len 16)
[1549507643] unbound[26:0] debug:   [cloudflare-dns.com] ip4 1.1.1.1 port 853 (len 16)
[1549507643] unbound[26:1] debug:   [cloudflare-dns.com] ip4 1.1.1.1 port 853 (len 16)
[1549507643] unbound[26:0] debug: attempt to get extra 3 targets
[1549507643] unbound[26:1] debug: attempt to get extra 3 targets
[1549507643] unbound[26:0] debug: servselect ip4 1.1.1.1 port 853 (len 16)
[1549507643] unbound[26:1] debug: servselect ip4 1.1.1.1 port 853 (len 16)
[1549507643] unbound[26:0] debug:    rtt=200
[1549507643] unbound[26:1] debug:    rtt=200
[1549507643] unbound[26:0] debug: servselect ip4 1.0.0.1 port 853 (len 16)
[1549507643] unbound[26:1] debug: servselect ip4 1.0.0.1 port 853 (len 16)
[1549507643] unbound[26:0] debug:    rtt=289
[1549507643] unbound[26:1] debug:    rtt=289
[1549507643] unbound[26:0] debug: selrtt 200
[1549507643] unbound[26:1] debug: selrtt 200
[1549507643] unbound[26:0] info: sending query: www.gravatar.com. A IN
[1549507643] unbound[26:1] info: sending query: stackoverflow.com. A IN
[1549507643] unbound[26:0] debug: sending to target: <.> 1.0.0.1#853
[1549507643] unbound[26:1] debug: sending to target: <.> 1.1.1.1#853
[1549507643] unbound[26:0] debug: dnssec status: not expected
[1549507643] unbound[26:1] debug: dnssec status: not expected
[1549507643] unbound[26:0] debug: comm point start listening 15
[1549507643] unbound[26:1] debug: comm point start listening 16
[1549507643] unbound[26:0] debug: mesh_run: iterator module exit state is module_wait_reply
[1549507643] unbound[26:1] debug: mesh_run: iterator module exit state is module_wait_reply
[1549507643] unbound[26:0] info: mesh_run: end 1 recursion states (1 with reply, 0 detached), 1 waiting replies, 2 recursion replies sent, 0 replies dropped, 0 states jostled out
[1549507643] unbound[26:1] info: mesh_run: end 1 recursion states (1 with reply, 0 detached), 1 waiting replies, 4 recursion replies sent, 0 replies dropped, 0 states jostled out
[1549507643] unbound[26:0] info: average recursion processing time 0.099110 sec
[1549507643] unbound[26:1] info: average recursion processing time 0.151196 sec
[1549507643] unbound[26:0] info: histogram of recursion processing times
[1549507643] unbound[26:1] info: histogram of recursion processing times
[1549507643] unbound[26:0] info: [25%]=0 median[50%]=0 [75%]=0
[1549507643] unbound[26:0] info: lower(secs) upper(secs) recursions
[1549507643] unbound[26:1] info: [25%]=0.0873813 median[50%]=0.109227 [75%]=0.131072
[1549507643] unbound[26:0] info:    0.065536    0.131072 2
[1549507643] unbound[26:1] info: lower(secs) upper(secs) recursions
[1549507643] unbound[26:0] info: 0RDd mod1 rep www.gravatar.com. A IN
[1549507643] unbound[26:1] info:    0.065536    0.131072 3
[1549507643] unbound[26:0] debug: cache memory msg=69352 rrset=73827 infra=8402 val=69892
[1549507643] unbound[26:1] info:    0.262144    0.524288 1
[1549507643] unbound[26:1] info: 0RDd mod1 rep stackoverflow.com. A IN
[1549507643] unbound[26:0] debug: udp request from ip4 172.16.34.142 port 63938 (len 16)
[1549507643] unbound[26:1] debug: cache memory msg=69352 rrset=73827 infra=8402 val=69892
[1549507643] unbound[26:0] debug: mesh_run: start
[1549507643] unbound[26:0] debug: validator[module 0] operate: extstate:module_state_initial event:module_event_new
[1549507643] unbound[26:0] info: validator operate: query cdn.sstatic.net. A IN
[1549507643] unbound[26:0] debug: validator: pass to next module
[1549507643] unbound[26:0] debug: mesh_run: validator module exit state is module_wait_module
[1549507643] unbound[26:0] debug: iterator[module 1] operate: extstate:module_state_initial event:module_event_pass
[1549507643] unbound[26:0] debug: process_request: new external request event
[1549507643] unbound[26:0] debug: iter_handle processing q with state INIT REQUEST STATE
[1549507643] unbound[26:0] info: resolving cdn.sstatic.net. A IN
[1549507643] unbound[26:0] debug: request has dependency depth of 0
[1549507643] unbound[26:0] debug: forwarding request
[1549507643] unbound[26:0] debug: iter_handle processing q with state QUERY TARGETS STATE
[1549507643] unbound[26:0] info: processQueryTargets: cdn.sstatic.net. A IN
[1549507643] unbound[26:0] debug: processQueryTargets: targetqueries 0, currentqueries 0 sentcount 0
[1549507643] unbound[26:0] info: DelegationPoint<.>: 0 names (0 missing), 2 addrs (0 result, 2 avail) parentNS
[1549507643] unbound[26:0] debug:   [cloudflare-dns.com] ip4 1.0.0.1 port 853 (len 16)
[1549507643] unbound[26:0] debug:   [cloudflare-dns.com] ip4 1.1.1.1 port 853 (len 16)
[1549507643] unbound[26:0] debug: attempt to get extra 3 targets
[1549507643] unbound[26:0] debug: servselect ip4 1.1.1.1 port 853 (len 16)
[1549507643] unbound[26:0] debug:    rtt=200
[1549507643] unbound[26:0] debug: servselect ip4 1.0.0.1 port 853 (len 16)
[1549507643] unbound[26:0] debug:    rtt=289
[1549507643] unbound[26:0] debug: selrtt 200
[1549507643] unbound[26:0] info: sending query: cdn.sstatic.net. A IN
[1549507643] unbound[26:0] debug: sending to target: <.> 1.1.1.1#853
[1549507643] unbound[26:0] debug: dnssec status: not expected
[1549507643] unbound[26:0] debug: comm point start listening 17
[1549507643] unbound[26:0] debug: mesh_run: iterator module exit state is module_wait_reply
[1549507643] unbound[26:0] info: mesh_run: end 2 recursion states (2 with reply, 0 detached), 2 waiting replies, 2 recursion replies sent, 0 replies dropped, 0 states jostled out
[1549507643] unbound[26:0] info: average recursion processing time 0.099110 sec
[1549507643] unbound[26:0] info: histogram of recursion processing times
[1549507643] unbound[26:0] info: [25%]=0 median[50%]=0 [75%]=0
[1549507643] unbound[26:0] info: lower(secs) upper(secs) recursions
[1549507643] unbound[26:0] info:    0.065536    0.131072 2
[1549507643] unbound[26:0] info: 0RDd mod1 rep cdn.sstatic.net. A IN
[1549507643] unbound[26:0] info: 1RDd mod1 rep www.gravatar.com. A IN
[1549507643] unbound[26:0] debug: cache memory msg=69352 rrset=73827 infra=8402 val=69892
[1549507643] unbound[26:0] debug: comm point listen_for_rw 15 0
[1549507643] unbound[26:1] debug: comm point listen_for_rw 16 0
[1549507643] unbound[26:0] debug: comm point listen_for_rw 17 0

 =========================================
 Unbound exit with status 139
 =========================================
Segmentation fault (core dumped)
@qdm12
Copy link
Owner

qdm12 commented Feb 7, 2019 •
edited

First of all, thanks for the nice layout for the issue 👍

Just to be clear, the container fails at startup right?

The image is built every 3 days with the latest updates and malicious hostnames / ips. Maybe try docker pull qmcgaw/cloudflare-dns-server and remove -> create the container again?

The Segmentation fault is either the latest unbound binary which contains a problem or a hardware fault (likelier I guess), it should not be related to the host OS at all (I tried on both Alpine and a Linux Custom OS without problem). I had problems running it on Ubuntu regarding port binding back then however.

I tried the latest image without any problem for a few minutes at least. I also fixed a little problem regarding username to drop privileges, so the warning warning: unable to initgroups nonrootuser: Operation not permitted should no longer appear from the latest version.

@wei
Copy link
Contributor

wei commented Feb 7, 2019 •
edited

Exact same issue on Ubuntu 18.04 with the latest image binding to a non-standard port. It doesn't seem to fail at startup but rather, some time later. Settings --restart=always for now.

@sheldonkwoodward
Copy link
Author

The container does not always fail on startup. It sometimes fails after it receives a request. For example it restarted automatically after a seg fault two hours ago. Also, I have the malicious filtering turned off.

I pulled the latest version and rebuilt, I'll let it run for a while and see what happens. No crashes so far, so fingers crossed.

@sheldonkwoodward
Copy link
Author

It has been crashing still with the same segmentation fault error.

@qdm12
Copy link
Owner

qdm12 commented Feb 8, 2019

I just pushed an update to Alpine 3.9 and to Unbound 1.8.3 (from 1.7.3), so that might solve your problem. Give it a try 👍

docker pull qmcgaw/cloudflare-dns-server

@wei
Copy link
Contributor

wei commented Feb 8, 2019

Really appreciate the help. Looking good so far. Will continue monitoring.

@sheldonkwoodward
Copy link
Author

This seems to have fixed it, no crashes in over 24 hours. Thanks for the great work!

@qdm12
Copy link
Owner

qdm12 commented Nov 24, 2019

Just a little note; we had segmentation faults since the few last updates because I tried to build unbound from source and somehow it failed every 10 hours approximately. I have reverted back to the Alpine built Unbound and it should work again now. Sorry for the inconvenience!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@wei @qdm12 @sheldonkwoodward