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

Strange problem on Docker container restart #18

Closed
smebberson opened this issue Aug 18, 2016 · 6 comments
Closed

Strange problem on Docker container restart #18

smebberson opened this issue Aug 18, 2016 · 6 comments

Comments

@smebberson
Copy link

I have encountered a strange issue that only occurs on Docker container restart. The following describes the lifecycle of the Docker containers.

  • All containers brought up with docker-compose up -d.
  • DNS queries are resolved successfully through go-dnsmasq.
  • The app container throws an uncaught error and the container quits (programmed to be this way).
  • Due to the restart: always policy for the container, Docker compose brings the container up again.
  • DNS queries will no fail to resolve through go-dnsmasq.

Have you seen/heard/witnessed anything like this before?

Here are the logs for go-dnsmasq the first time around:

time="2016-08-18T01:43:04Z" level=info msg="Starting go-dnsmasq server 1.0.6" 
time="2016-08-18T01:43:04Z" level=info msg="Nameservers: [192.168.194.2:53]" 
time="2016-08-18T01:43:04Z" level=warning msg="Bad formatted hostsfile line: Duplicate hostname entry for &hosts.hostname{domain:\"5c7ec388c1b7\", ip:net.IP{0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0xff, 0xff, 0xac, 0x11, 0x0, 0x3}, ipv6:false, wildcard:false}" 
time="2016-08-18T01:43:04Z" level=warning msg="Bad formatted hostsfile line: Duplicate hostname entry for &hosts.hostname{domain:\"hq_db_1\", ip:net.IP{0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0xff, 0xff, 0xac, 0x11, 0x0, 0x3}, ipv6:false, wildcard:false}" 
time="2016-08-18T01:43:04Z" level=warning msg="Bad formatted hostsfile line: Duplicate hostname entry for &hosts.hostname{domain:\"5cf97bd512e0\", ip:net.IP{0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0xff, 0xff, 0xac, 0x11, 0x0, 0x9}, ipv6:false, wildcard:false}" 
time="2016-08-18T01:43:04Z" level=warning msg="Bad formatted hostsfile line: Duplicate hostname entry for &hosts.hostname{domain:\"hq_mq_1\", ip:net.IP{0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0xff, 0xff, 0xac, 0x11, 0x0, 0x9}, ipv6:false, wildcard:false}" 
time="2016-08-18T01:43:04Z" level=warning msg="Bad formatted hostsfile line: Duplicate hostname entry for &hosts.hostname{domain:\"hq_mq_1\", ip:net.IP{0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0xff, 0xff, 0xac, 0x11, 0x0, 0x9}, ipv6:false, wildcard:false}" 
time="2016-08-18T01:43:04Z" level=warning msg="Bad formatted hostsfile line: Duplicate hostname entry for &hosts.hostname{domain:\"5cf97bd512e0\", ip:net.IP{0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0xff, 0xff, 0xac, 0x11, 0x0, 0x9}, ipv6:false, wildcard:false}" 
time="2016-08-18T01:43:04Z" level=warning msg="Bad formatted hostsfile line: Duplicate hostname entry for &hosts.hostname{domain:\"d5e9783b412f\", ip:net.IP{0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0xff, 0xff, 0xac, 0x11, 0x0, 0x2}, ipv6:false, wildcard:false}" 
time="2016-08-18T01:43:04Z" level=warning msg="Bad formatted hostsfile line: Duplicate hostname entry for &hosts.hostname{domain:\"hq_cache_1\", ip:net.IP{0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0xff, 0xff, 0xac, 0x11, 0x0, 0x2}, ipv6:false, wildcard:false}" 
time="2016-08-18T01:43:04Z" level=warning msg="Bad formatted hostsfile line: Duplicate hostname entry for &hosts.hostname{domain:\"hq_cache_1\", ip:net.IP{0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0xff, 0xff, 0xac, 0x11, 0x0, 0x2}, ipv6:false, wildcard:false}" 
time="2016-08-18T01:43:04Z" level=warning msg="Bad formatted hostsfile line: Duplicate hostname entry for &hosts.hostname{domain:\"d5e9783b412f\", ip:net.IP{0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0xff, 0xff, 0xac, 0x11, 0x0, 0x2}, ipv6:false, wildcard:false}" 
time="2016-08-18T01:43:04Z" level=warning msg="Bad formatted hostsfile line: Duplicate hostname entry for &hosts.hostname{domain:\"hq_db_1\", ip:net.IP{0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0xff, 0xff, 0xac, 0x11, 0x0, 0x3}, ipv6:false, wildcard:false}" 
time="2016-08-18T01:43:04Z" level=warning msg="Bad formatted hostsfile line: Duplicate hostname entry for &hosts.hostname{domain:\"5c7ec388c1b7\", ip:net.IP{0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0xff, 0xff, 0xac, 0x11, 0x0, 0x3}, ipv6:false, wildcard:false}" 
time="2016-08-18T01:43:04Z" level=debug msg="Found host:ip pairs in /etc/hosts:" 
time="2016-08-18T01:43:04Z" level=debug msg="efa3615ca448 : 172.17.0.10" 
time="2016-08-18T01:43:04Z" level=debug msg="localhost : 127.0.0.1" 
time="2016-08-18T01:43:04Z" level=debug msg="localhost : ::1" 
time="2016-08-18T01:43:04Z" level=debug msg="ip6-localhost : ::1" 
time="2016-08-18T01:43:04Z" level=debug msg="ip6-loopback : ::1" 
time="2016-08-18T01:43:04Z" level=debug msg="db : 172.17.0.3" 
time="2016-08-18T01:43:04Z" level=debug msg="5c7ec388c1b7 : 172.17.0.3" 
time="2016-08-18T01:43:04Z" level=debug msg="hq_db_1 : 172.17.0.3" 
time="2016-08-18T01:43:04Z" level=debug msg="db_1 : 172.17.0.3" 
time="2016-08-18T01:43:04Z" level=debug msg="mq : 172.17.0.9" 
time="2016-08-18T01:43:04Z" level=debug msg="5cf97bd512e0 : 172.17.0.9" 
time="2016-08-18T01:43:04Z" level=debug msg="hq_mq_1 : 172.17.0.9" 
time="2016-08-18T01:43:04Z" level=debug msg="mq_1 : 172.17.0.9" 
time="2016-08-18T01:43:04Z" level=debug msg="cache : 172.17.0.2" 
time="2016-08-18T01:43:04Z" level=debug msg="d5e9783b412f : 172.17.0.2" 
time="2016-08-18T01:43:04Z" level=debug msg="hq_cache_1 : 172.17.0.2" 
time="2016-08-18T01:43:04Z" level=debug msg="cache_1 : 172.17.0.2" 
time="2016-08-18T01:43:04Z" level=info msg="Setting host nameserver to %s127.0.0.1" 
time="2016-08-18T01:43:04Z" level=info msg="Ready for queries on tcp://127.0.0.1:53" 
time="2016-08-18T01:43:04Z" level=info msg="Ready for queries on udp://127.0.0.1:53" 
time="2016-08-18T01:43:11Z" level=debug msg="Received DNS query for \"data.logentries.com.\" from \"127.0.0.1:58449\" with type 1" 
time="2016-08-18T01:43:11Z" level=debug msg="[65258] Doing initial absolute lookup" 
time="2016-08-18T01:43:11Z" level=debug msg="[65258] Querying upstream 192.168.194.2:53 for qname 'data.logentries.com.'" 
time="2016-08-18T01:43:11Z" level=debug msg="Received DNS query for \"data.logentries.com.\" from \"127.0.0.1:58449\" with type 28" 
time="2016-08-18T01:43:11Z" level=debug msg="[65473] Doing initial absolute lookup" 
time="2016-08-18T01:43:11Z" level=debug msg="[65473] Querying upstream 192.168.194.2:53 for qname 'data.logentries.com.'" 
time="2016-08-18T01:43:11Z" level=debug msg="[65473] Response code from upstream: NOERROR" 
time="2016-08-18T01:43:11Z" level=debug msg="[65473] Initial lookup yielded result. Response to client: NOERROR" 
time="2016-08-18T01:43:11Z" level=debug msg="[65473] Response time: 89.599617ms" 
time="2016-08-18T01:43:11Z" level=debug msg="[65258] Response code from upstream: NOERROR" 
time="2016-08-18T01:43:11Z" level=debug msg="[65258] Initial lookup yielded result. Response to client: NOERROR" 
time="2016-08-18T01:43:11Z" level=debug msg="[65258] Response time: 90.566553ms"

Here are the go-dnsmasq logs upon automated restart (note: the first part of the logs are from the first run above but you'll see the line where go-dnsmasq restarts and it all goes bad):

time="2016-08-18T01:43:04Z" level=info msg="Starting go-dnsmasq server 1.0.6" 
time="2016-08-18T01:43:04Z" level=info msg="Nameservers: [192.168.194.2:53]" 
time="2016-08-18T01:43:04Z" level=warning msg="Bad formatted hostsfile line: Duplicate hostname entry for &hosts.hostname{domain:\"5c7ec388c1b7\", ip:net.IP{0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0xff, 0xff, 0xac, 0x11, 0x0, 0x3}, ipv6:false, wildcard:false}" 
time="2016-08-18T01:43:04Z" level=warning msg="Bad formatted hostsfile line: Duplicate hostname entry for &hosts.hostname{domain:\"hq_db_1\", ip:net.IP{0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0xff, 0xff, 0xac, 0x11, 0x0, 0x3}, ipv6:false, wildcard:false}" 
time="2016-08-18T01:43:04Z" level=warning msg="Bad formatted hostsfile line: Duplicate hostname entry for &hosts.hostname{domain:\"5cf97bd512e0\", ip:net.IP{0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0xff, 0xff, 0xac, 0x11, 0x0, 0x9}, ipv6:false, wildcard:false}" 
time="2016-08-18T01:43:04Z" level=warning msg="Bad formatted hostsfile line: Duplicate hostname entry for &hosts.hostname{domain:\"hq_mq_1\", ip:net.IP{0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0xff, 0xff, 0xac, 0x11, 0x0, 0x9}, ipv6:false, wildcard:false}" 
time="2016-08-18T01:43:04Z" level=warning msg="Bad formatted hostsfile line: Duplicate hostname entry for &hosts.hostname{domain:\"hq_mq_1\", ip:net.IP{0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0xff, 0xff, 0xac, 0x11, 0x0, 0x9}, ipv6:false, wildcard:false}" 
time="2016-08-18T01:43:04Z" level=warning msg="Bad formatted hostsfile line: Duplicate hostname entry for &hosts.hostname{domain:\"5cf97bd512e0\", ip:net.IP{0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0xff, 0xff, 0xac, 0x11, 0x0, 0x9}, ipv6:false, wildcard:false}" 
time="2016-08-18T01:43:04Z" level=warning msg="Bad formatted hostsfile line: Duplicate hostname entry for &hosts.hostname{domain:\"d5e9783b412f\", ip:net.IP{0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0xff, 0xff, 0xac, 0x11, 0x0, 0x2}, ipv6:false, wildcard:false}" 
time="2016-08-18T01:43:04Z" level=warning msg="Bad formatted hostsfile line: Duplicate hostname entry for &hosts.hostname{domain:\"hq_cache_1\", ip:net.IP{0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0xff, 0xff, 0xac, 0x11, 0x0, 0x2}, ipv6:false, wildcard:false}" 
time="2016-08-18T01:43:04Z" level=warning msg="Bad formatted hostsfile line: Duplicate hostname entry for &hosts.hostname{domain:\"hq_cache_1\", ip:net.IP{0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0xff, 0xff, 0xac, 0x11, 0x0, 0x2}, ipv6:false, wildcard:false}" 
time="2016-08-18T01:43:04Z" level=warning msg="Bad formatted hostsfile line: Duplicate hostname entry for &hosts.hostname{domain:\"d5e9783b412f\", ip:net.IP{0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0xff, 0xff, 0xac, 0x11, 0x0, 0x2}, ipv6:false, wildcard:false}" 
time="2016-08-18T01:43:04Z" level=warning msg="Bad formatted hostsfile line: Duplicate hostname entry for &hosts.hostname{domain:\"hq_db_1\", ip:net.IP{0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0xff, 0xff, 0xac, 0x11, 0x0, 0x3}, ipv6:false, wildcard:false}" 
time="2016-08-18T01:43:04Z" level=warning msg="Bad formatted hostsfile line: Duplicate hostname entry for &hosts.hostname{domain:\"5c7ec388c1b7\", ip:net.IP{0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0xff, 0xff, 0xac, 0x11, 0x0, 0x3}, ipv6:false, wildcard:false}" 
time="2016-08-18T01:43:04Z" level=debug msg="Found host:ip pairs in /etc/hosts:" 
time="2016-08-18T01:43:04Z" level=debug msg="efa3615ca448 : 172.17.0.10" 
time="2016-08-18T01:43:04Z" level=debug msg="localhost : 127.0.0.1" 
time="2016-08-18T01:43:04Z" level=debug msg="localhost : ::1" 
time="2016-08-18T01:43:04Z" level=debug msg="ip6-localhost : ::1" 
time="2016-08-18T01:43:04Z" level=debug msg="ip6-loopback : ::1" 
time="2016-08-18T01:43:04Z" level=debug msg="db : 172.17.0.3" 
time="2016-08-18T01:43:04Z" level=debug msg="5c7ec388c1b7 : 172.17.0.3" 
time="2016-08-18T01:43:04Z" level=debug msg="hq_db_1 : 172.17.0.3" 
time="2016-08-18T01:43:04Z" level=debug msg="db_1 : 172.17.0.3" 
time="2016-08-18T01:43:04Z" level=debug msg="mq : 172.17.0.9" 
time="2016-08-18T01:43:04Z" level=debug msg="5cf97bd512e0 : 172.17.0.9" 
time="2016-08-18T01:43:04Z" level=debug msg="hq_mq_1 : 172.17.0.9" 
time="2016-08-18T01:43:04Z" level=debug msg="mq_1 : 172.17.0.9" 
time="2016-08-18T01:43:04Z" level=debug msg="cache : 172.17.0.2" 
time="2016-08-18T01:43:04Z" level=debug msg="d5e9783b412f : 172.17.0.2" 
time="2016-08-18T01:43:04Z" level=debug msg="hq_cache_1 : 172.17.0.2" 
time="2016-08-18T01:43:04Z" level=debug msg="cache_1 : 172.17.0.2" 
time="2016-08-18T01:43:04Z" level=info msg="Setting host nameserver to %s127.0.0.1" 
time="2016-08-18T01:43:04Z" level=info msg="Ready for queries on tcp://127.0.0.1:53" 
time="2016-08-18T01:43:04Z" level=info msg="Ready for queries on udp://127.0.0.1:53" 
time="2016-08-18T01:43:11Z" level=debug msg="Received DNS query for \"data.logentries.com.\" from \"127.0.0.1:58449\" with type 1" 
time="2016-08-18T01:43:11Z" level=debug msg="[65258] Doing initial absolute lookup" 
time="2016-08-18T01:43:11Z" level=debug msg="[65258] Querying upstream 192.168.194.2:53 for qname 'data.logentries.com.'" 
time="2016-08-18T01:43:11Z" level=debug msg="Received DNS query for \"data.logentries.com.\" from \"127.0.0.1:58449\" with type 28" 
time="2016-08-18T01:43:11Z" level=debug msg="[65473] Doing initial absolute lookup" 
time="2016-08-18T01:43:11Z" level=debug msg="[65473] Querying upstream 192.168.194.2:53 for qname 'data.logentries.com.'" 
time="2016-08-18T01:43:11Z" level=debug msg="[65473] Response code from upstream: NOERROR" 
time="2016-08-18T01:43:11Z" level=debug msg="[65473] Initial lookup yielded result. Response to client: NOERROR" 
time="2016-08-18T01:43:11Z" level=debug msg="[65473] Response time: 89.599617ms" 
time="2016-08-18T01:43:11Z" level=debug msg="[65258] Response code from upstream: NOERROR" 
time="2016-08-18T01:43:11Z" level=debug msg="[65258] Initial lookup yielded result. Response to client: NOERROR" 
time="2016-08-18T01:43:11Z" level=debug msg="[65258] Response time: 90.566553ms" 
time="2016-08-18T01:43:31Z" level=debug msg="Received DNS query for \"data.logentries.com.\" from \"127.0.0.1:35701\" with type 1" 
time="2016-08-18T01:43:31Z" level=debug msg="[22108] Doing initial absolute lookup" 
time="2016-08-18T01:43:31Z" level=debug msg="[22108] Querying upstream 192.168.194.2:53 for qname 'data.logentries.com.'" 
time="2016-08-18T01:43:31Z" level=debug msg="Received DNS query for \"data.logentries.com.\" from \"127.0.0.1:35701\" with type 28" 
time="2016-08-18T01:43:31Z" level=debug msg="[22393] Doing initial absolute lookup" 
time="2016-08-18T01:43:31Z" level=debug msg="[22393] Querying upstream 192.168.194.2:53 for qname 'data.logentries.com.'" 
time="2016-08-18T01:43:31Z" level=debug msg="[22108] Response code from upstream: NOERROR" 
time="2016-08-18T01:43:31Z" level=debug msg="[22108] Initial lookup yielded result. Response to client: NOERROR" 
time="2016-08-18T01:43:31Z" level=debug msg="[22108] Response time: 51.940355ms" 
time="2016-08-18T01:43:31Z" level=debug msg="[22393] Response code from upstream: NOERROR" 
time="2016-08-18T01:43:31Z" level=debug msg="[22393] Initial lookup yielded result. Response to client: NOERROR" 
time="2016-08-18T01:43:31Z" level=debug msg="[22393] Response time: 53.886212ms" 
time="2016-08-18T01:43:37Z" level=info msg="Starting go-dnsmasq server 1.0.6" 
time="2016-08-18T01:43:37Z" level=info msg="Nameservers: [127.0.0.1:53]" 
time="2016-08-18T01:43:37Z" level=warning msg="Bad formatted hostsfile line: Duplicate hostname entry for &hosts.hostname{domain:\"5c7ec388c1b7\", ip:net.IP{0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0xff, 0xff, 0xac, 0x11, 0x0, 0x3}, ipv6:false, wildcard:false}" 
time="2016-08-18T01:43:37Z" level=warning msg="Bad formatted hostsfile line: Duplicate hostname entry for &hosts.hostname{domain:\"hq_db_1\", ip:net.IP{0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0xff, 0xff, 0xac, 0x11, 0x0, 0x3}, ipv6:false, wildcard:false}" 
time="2016-08-18T01:43:37Z" level=warning msg="Bad formatted hostsfile line: Duplicate hostname entry for &hosts.hostname{domain:\"5cf97bd512e0\", ip:net.IP{0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0xff, 0xff, 0xac, 0x11, 0x0, 0x9}, ipv6:false, wildcard:false}" 
time="2016-08-18T01:43:37Z" level=warning msg="Bad formatted hostsfile line: Duplicate hostname entry for &hosts.hostname{domain:\"hq_mq_1\", ip:net.IP{0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0xff, 0xff, 0xac, 0x11, 0x0, 0x9}, ipv6:false, wildcard:false}" 
time="2016-08-18T01:43:37Z" level=warning msg="Bad formatted hostsfile line: Duplicate hostname entry for &hosts.hostname{domain:\"hq_mq_1\", ip:net.IP{0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0xff, 0xff, 0xac, 0x11, 0x0, 0x9}, ipv6:false, wildcard:false}" 
time="2016-08-18T01:43:37Z" level=warning msg="Bad formatted hostsfile line: Duplicate hostname entry for &hosts.hostname{domain:\"5cf97bd512e0\", ip:net.IP{0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0xff, 0xff, 0xac, 0x11, 0x0, 0x9}, ipv6:false, wildcard:false}" 
time="2016-08-18T01:43:37Z" level=warning msg="Bad formatted hostsfile line: Duplicate hostname entry for &hosts.hostname{domain:\"d5e9783b412f\", ip:net.IP{0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0xff, 0xff, 0xac, 0x11, 0x0, 0x2}, ipv6:false, wildcard:false}" 
time="2016-08-18T01:43:37Z" level=warning msg="Bad formatted hostsfile line: Duplicate hostname entry for &hosts.hostname{domain:\"hq_cache_1\", ip:net.IP{0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0xff, 0xff, 0xac, 0x11, 0x0, 0x2}, ipv6:false, wildcard:false}" 
time="2016-08-18T01:43:37Z" level=warning msg="Bad formatted hostsfile line: Duplicate hostname entry for &hosts.hostname{domain:\"hq_cache_1\", ip:net.IP{0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0xff, 0xff, 0xac, 0x11, 0x0, 0x2}, ipv6:false, wildcard:false}" 
time="2016-08-18T01:43:37Z" level=warning msg="Bad formatted hostsfile line: Duplicate hostname entry for &hosts.hostname{domain:\"d5e9783b412f\", ip:net.IP{0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0xff, 0xff, 0xac, 0x11, 0x0, 0x2}, ipv6:false, wildcard:false}" 
time="2016-08-18T01:43:37Z" level=warning msg="Bad formatted hostsfile line: Duplicate hostname entry for &hosts.hostname{domain:\"hq_db_1\", ip:net.IP{0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0xff, 0xff, 0xac, 0x11, 0x0, 0x3}, ipv6:false, wildcard:false}" 
time="2016-08-18T01:43:37Z" level=warning msg="Bad formatted hostsfile line: Duplicate hostname entry for &hosts.hostname{domain:\"5c7ec388c1b7\", ip:net.IP{0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0xff, 0xff, 0xac, 0x11, 0x0, 0x3}, ipv6:false, wildcard:false}" 
time="2016-08-18T01:43:37Z" level=debug msg="Found host:ip pairs in /etc/hosts:" 
time="2016-08-18T01:43:37Z" level=debug msg="efa3615ca448 : 172.17.0.10" 
time="2016-08-18T01:43:37Z" level=debug msg="localhost : 127.0.0.1" 
time="2016-08-18T01:43:37Z" level=debug msg="localhost : ::1" 
time="2016-08-18T01:43:37Z" level=debug msg="ip6-localhost : ::1" 
time="2016-08-18T01:43:37Z" level=debug msg="ip6-loopback : ::1" 
time="2016-08-18T01:43:37Z" level=debug msg="db : 172.17.0.3" 
time="2016-08-18T01:43:37Z" level=debug msg="5c7ec388c1b7 : 172.17.0.3" 
time="2016-08-18T01:43:37Z" level=debug msg="hq_db_1 : 172.17.0.3" 
time="2016-08-18T01:43:37Z" level=debug msg="db_1 : 172.17.0.3" 
time="2016-08-18T01:43:37Z" level=debug msg="mq : 172.17.0.9" 
time="2016-08-18T01:43:37Z" level=debug msg="5cf97bd512e0 : 172.17.0.9" 
time="2016-08-18T01:43:37Z" level=debug msg="hq_mq_1 : 172.17.0.9" 
time="2016-08-18T01:43:37Z" level=debug msg="mq_1 : 172.17.0.9" 
time="2016-08-18T01:43:37Z" level=debug msg="cache : 172.17.0.2" 
time="2016-08-18T01:43:37Z" level=debug msg="d5e9783b412f : 172.17.0.2" 
time="2016-08-18T01:43:37Z" level=debug msg="hq_cache_1 : 172.17.0.2" 
time="2016-08-18T01:43:37Z" level=debug msg="cache_1 : 172.17.0.2" 
time="2016-08-18T01:43:37Z" level=info msg="Setting host nameserver to %s127.0.0.1" 
time="2016-08-18T01:43:37Z" level=info msg="Ready for queries on tcp://127.0.0.1:53" 
time="2016-08-18T01:43:37Z" level=info msg="Ready for queries on udp://127.0.0.1:53" 
time="2016-08-18T01:43:41Z" level=debug msg="Received DNS query for \"data.logentries.com.\" from \"127.0.0.1:47330\" with type 1" 
time="2016-08-18T01:43:41Z" level=debug msg="[60334] Doing initial absolute lookup" 
time="2016-08-18T01:43:41Z" level=debug msg="[60334] Querying upstream 127.0.0.1:53 for qname 'data.logentries.com.'" 
time="2016-08-18T01:43:41Z" level=debug msg="Received DNS query for \"data.logentries.com.\" from \"127.0.0.1:47330\" with type 28" 
time="2016-08-18T01:43:41Z" level=debug msg="[60632] Doing initial absolute lookup" 
time="2016-08-18T01:43:41Z" level=debug msg="[60632] Querying upstream 127.0.0.1:53 for qname 'data.logentries.com.'" 
time="2016-08-18T01:43:41Z" level=debug msg="Received DNS query for \"data.logentries.com.\" from \"127.0.0.1:43311\" with type 1" 
time="2016-08-18T01:43:41Z" level=debug msg="[60334] Doing initial absolute lookup" 
time="2016-08-18T01:43:41Z" level=debug msg="[60334] Querying upstream 127.0.0.1:53 for qname 'data.logentries.com.'" 
time="2016-08-18T01:43:41Z" level=debug msg="Received DNS query for \"data.logentries.com.\" from \"127.0.0.1:37126\" with type 28" 
time="2016-08-18T01:43:41Z" level=debug msg="[60632] Doing initial absolute lookup" 
time="2016-08-18T01:43:41Z" level=debug msg="[60632] Querying upstream 127.0.0.1:53 for qname 'data.logentries.com.'" 
time="2016-08-18T01:43:43Z" level=debug msg="[60334] Failed to query upstream 127.0.0.1:53 for qname 'data.logentries.com.': read udp 127.0.0.1:43311->127.0.0.1:53: i/o timeout" 
time="2016-08-18T01:43:43Z" level=debug msg="[60334] Querying upstream 127.0.0.1:53 for qname 'data.logentries.com.'" 
time="2016-08-18T01:43:43Z" level=debug msg="[60334] Failed to query upstream 127.0.0.1:53 for qname 'data.logentries.com.': read udp 127.0.0.1:43311->127.0.0.1:53: i/o timeout" 
time="2016-08-18T01:43:43Z" level=debug msg="[60334] Querying upstream 127.0.0.1:53 for qname 'data.logentries.com.'" 
time="2016-08-18T01:43:43Z" level=debug msg="[60632] Failed to query upstream 127.0.0.1:53 for qname 'data.logentries.com.': read udp 127.0.0.1:37126->127.0.0.1:53: i/o timeout" 
time="2016-08-18T01:43:43Z" level=debug msg="[60632] Querying upstream 127.0.0.1:53 for qname 'data.logentries.com.'" 
time="2016-08-18T01:43:43Z" level=debug msg="[60632] Failed to query upstream 127.0.0.1:53 for qname 'data.logentries.com.': read udp 127.0.0.1:37126->127.0.0.1:53: i/o timeout" 
time="2016-08-18T01:43:43Z" level=debug msg="[60632] Querying upstream 127.0.0.1:53 for qname 'data.logentries.com.'" 
time="2016-08-18T01:43:43Z" level=debug msg="Received DNS query for \"data.logentries.com.\" from \"127.0.0.1:37621\" with type 1" 
time="2016-08-18T01:43:43Z" level=debug msg="[60334] Doing initial absolute lookup" 
time="2016-08-18T01:43:43Z" level=debug msg="[60334] Querying upstream 127.0.0.1:53 for qname 'data.logentries.com.'" 
time="2016-08-18T01:43:43Z" level=debug msg="Received DNS query for \"data.logentries.com.\" from \"127.0.0.1:55759\" with type 28" 
time="2016-08-18T01:43:43Z" level=debug msg="[60632] Doing initial absolute lookup" 
time="2016-08-18T01:43:43Z" level=debug msg="[60632] Querying upstream 127.0.0.1:53 for qname 'data.logentries.com.'" 
time="2016-08-18T01:43:44Z" level=debug msg="Received DNS query for \"data.logentries.com.\" from \"127.0.0.1:47330\" with type 1" 
time="2016-08-18T01:43:44Z" level=debug msg="[60334] Doing initial absolute lookup" 
time="2016-08-18T01:43:44Z" level=debug msg="[60334] Querying upstream 127.0.0.1:53 for qname 'data.logentries.com.'" 
time="2016-08-18T01:43:44Z" level=debug msg="Received DNS query for \"data.logentries.com.\" from \"127.0.0.1:47330\" with type 28" 
time="2016-08-18T01:43:44Z" level=debug msg="[60632] Doing initial absolute lookup" 
time="2016-08-18T01:43:44Z" level=debug msg="[60632] Querying upstream 127.0.0.1:53 for qname 'data.logentries.com.'" 
time="2016-08-18T01:43:45Z" level=debug msg="[60632] Failed to query upstream 127.0.0.1:53 for qname 'data.logentries.com.': read udp 127.0.0.1:55759->127.0.0.1:53: i/o timeout" 
time="2016-08-18T01:43:45Z" level=error msg="[60632] Error looking up literal qname 'data.logentries.com.' with upstreams: read udp 127.0.0.1:55759->127.0.0.1:53: i/o timeout" 
time="2016-08-18T01:43:45Z" level=debug msg="[60632] Error forwarding query. Returning SRVFAIL." 
time="2016-08-18T01:43:45Z" level=debug msg="[60632] Response time: 4.001624487s" 
time="2016-08-18T01:43:45Z" level=debug msg="[60632] Failed to query upstream 127.0.0.1:53 for qname 'data.logentries.com.': read udp 127.0.0.1:55759->127.0.0.1:53: i/o timeout" 
time="2016-08-18T01:43:45Z" level=debug msg="[60632] Querying upstream 127.0.0.1:53 for qname 'data.logentries.com.'" 
time="2016-08-18T01:43:45Z" level=debug msg="[60334] Failed to query upstream 127.0.0.1:53 for qname 'data.logentries.com.': read udp 127.0.0.1:37621->127.0.0.1:53: i/o timeout" 
time="2016-08-18T01:43:45Z" level=error msg="[60334] Error looking up literal qname 'data.logentries.com.' with upstreams: read udp 127.0.0.1:37621->127.0.0.1:53: i/o timeout" 
time="2016-08-18T01:43:45Z" level=debug msg="[60334] Error forwarding query. Returning SRVFAIL." 
time="2016-08-18T01:43:45Z" level=debug msg="[60334] Response time: 4.002642232s" 
time="2016-08-18T01:43:45Z" level=debug msg="[60334] Failed to query upstream 127.0.0.1:53 for qname 'data.logentries.com.': read udp 127.0.0.1:37621->127.0.0.1:53: i/o timeout" 
time="2016-08-18T01:43:45Z" level=debug msg="[60334] Querying upstream 127.0.0.1:53 for qname 'data.logentries.com.'" 
time="2016-08-18T01:43:45Z" level=debug msg="[60632] Failed to query upstream 127.0.0.1:53 for qname 'data.logentries.com.': read udp 127.0.0.1:55759->127.0.0.1:53: i/o timeout" 
time="2016-08-18T01:43:45Z" level=error msg="[60632] Error looking up literal qname 'data.logentries.com.' with upstreams: read udp 127.0.0.1:55759->127.0.0.1:53: i/o timeout" 
time="2016-08-18T01:43:45Z" level=debug msg="[60632] Error forwarding query. Returning SRVFAIL." 
time="2016-08-18T01:43:45Z" level=debug msg="[60632] Response time: 4.0011479s" 
time="2016-08-18T01:43:45Z" level=debug msg="[60632] Failed to query upstream 127.0.0.1:53 for qname 'data.logentries.com.': read udp 127.0.0.1:55759->127.0.0.1:53: i/o timeout" 
time="2016-08-18T01:43:45Z" level=debug msg="[60632] Querying upstream 127.0.0.1:53 for qname 'data.logentries.com.'" 
time="2016-08-18T01:43:45Z" level=debug msg="[60334] Failed to query upstream 127.0.0.1:53 for qname 'data.logentries.com.': read udp 127.0.0.1:37621->127.0.0.1:53: i/o timeout" 
time="2016-08-18T01:43:45Z" level=error msg="[60334] Error looking up literal qname 'data.logentries.com.' with upstreams: read udp 127.0.0.1:37621->127.0.0.1:53: i/o timeout" 
time="2016-08-18T01:43:45Z" level=debug msg="[60334] Error forwarding query. Returning SRVFAIL." 
time="2016-08-18T01:43:45Z" level=debug msg="[60334] Response time: 4.002063546s" 
time="2016-08-18T01:43:45Z" level=debug msg="[60334] Failed to query upstream 127.0.0.1:53 for qname 'data.logentries.com.': read udp 127.0.0.1:37621->127.0.0.1:53: i/o timeout" 
time="2016-08-18T01:43:45Z" level=debug msg="[60334] Querying upstream 127.0.0.1:53 for qname 'data.logentries.com.'" 
time="2016-08-18T01:43:45Z" level=debug msg="Received DNS query for \"data.logentries.com.\" from \"127.0.0.1:52180\" with type 28" 
time="2016-08-18T01:43:45Z" level=debug msg="[60632] Doing initial absolute lookup" 
time="2016-08-18T01:43:45Z" level=debug msg="[60632] Querying upstream 127.0.0.1:53 for qname 'data.logentries.com.'" 
time="2016-08-18T01:43:45Z" level=debug msg="Received DNS query for \"data.logentries.com.\" from \"127.0.0.1:47330\" with type 28" 
time="2016-08-18T01:43:45Z" level=debug msg="[60632] Doing initial absolute lookup" 
time="2016-08-18T01:43:45Z" level=debug msg="[60632] Querying upstream 127.0.0.1:53 for qname 'data.logentries.com.'" 
time="2016-08-18T01:43:45Z" level=debug msg="Received DNS query for \"data.logentries.com.\" from \"127.0.0.1:51291\" with type 1" 
time="2016-08-18T01:43:45Z" level=debug msg="[60334] Doing initial absolute lookup" 
time="2016-08-18T01:43:45Z" level=debug msg="[60334] Querying upstream 127.0.0.1:53 for qname 'data.logentries.com.'" 
time="2016-08-18T01:43:45Z" level=debug msg="Received DNS query for \"data.logentries.com.\" from \"127.0.0.1:47330\" with type 1" 
time="2016-08-18T01:43:45Z" level=debug msg="[60334] Doing initial absolute lookup" 
time="2016-08-18T01:43:45Z" level=debug msg="[60334] Querying upstream 127.0.0.1:53 for qname 'data.logentries.com.'" 
time="2016-08-18T01:43:47Z" level=debug msg="[60632] Failed to query upstream 127.0.0.1:53 for qname 'data.logentries.com.': read udp 127.0.0.1:52180->127.0.0.1:53: i/o timeout" 
time="2016-08-18T01:43:47Z" level=debug msg="[60632] Failed to query upstream 127.0.0.1:53 for qname 'data.logentries.com.': read udp 127.0.0.1:52180->127.0.0.1:53: i/o timeout" 
time="2016-08-18T01:43:47Z" level=error msg="[60632] Error looking up literal qname 'data.logentries.com.' with upstreams: read udp 127.0.0.1:52180->127.0.0.1:53: i/o timeout" 
time="2016-08-18T01:43:47Z" level=error msg="[60632] Error looking up literal qname 'data.logentries.com.' with upstreams: read udp 127.0.0.1:52180->127.0.0.1:53: i/o timeout" 
time="2016-08-18T01:43:47Z" level=debug msg="[60632] Error forwarding query. Returning SRVFAIL." 
time="2016-08-18T01:43:47Z" level=debug msg="[60632] Error forwarding query. Returning SRVFAIL." 
time="2016-08-18T01:43:47Z" level=debug msg="[60334] Failed to query upstream 127.0.0.1:53 for qname 'data.logentries.com.': read udp 127.0.0.1:51291->127.0.0.1:53: i/o timeout" 
time="2016-08-18T01:43:47Z" level=error msg="[60334] Error looking up literal qname 'data.logentries.com.' with upstreams: read udp 127.0.0.1:51291->127.0.0.1:53: i/o timeout" 
time="2016-08-18T01:43:47Z" level=debug msg="[60334] Error forwarding query. Returning SRVFAIL." 
time="2016-08-18T01:43:47Z" level=debug msg="[60334] Failed to query upstream 127.0.0.1:53 for qname 'data.logentries.com.': read udp 127.0.0.1:51291->127.0.0.1:53: i/o timeout" 
time="2016-08-18T01:43:47Z" level=debug msg="[60334] Querying upstream 127.0.0.1:53 for qname 'data.logentries.com.'" 
time="2016-08-18T01:43:47Z" level=debug msg="[60632] Response time: 3.50003419s" 
time="2016-08-18T01:43:47Z" level=debug msg="[60632] Response time: 4.001336327s" 
time="2016-08-18T01:43:47Z" level=debug msg="[60334] Response time: 4.001803171s" 
time="2016-08-18T01:43:47Z" level=debug msg="[60632] Failed to query upstream 127.0.0.1:53 for qname 'data.logentries.com.': read udp 127.0.0.1:52180->127.0.0.1:53: i/o timeout" 
time="2016-08-18T01:43:47Z" level=debug msg="[60632] Querying upstream 127.0.0.1:53 for qname 'data.logentries.com.'" 
time="2016-08-18T01:43:47Z" level=debug msg="[60334] Failed to query upstream 127.0.0.1:53 for qname 'data.logentries.com.': read udp 127.0.0.1:51291->127.0.0.1:53: i/o timeout" 
time="2016-08-18T01:43:47Z" level=error msg="[60334] Error looking up literal qname 'data.logentries.com.' with upstreams: read udp 127.0.0.1:51291->127.0.0.1:53: i/o timeout" 
time="2016-08-18T01:43:47Z" level=debug msg="[60334] Error forwarding query. Returning SRVFAIL." 
time="2016-08-18T01:43:47Z" level=debug msg="[60334] Response time: 3.502600516s" 
time="2016-08-18T01:43:47Z" level=debug msg="[60334] Failed to query upstream 127.0.0.1:53 for qname 'data.logentries.com.': read udp 127.0.0.1:51291->127.0.0.1:53: i/o timeout" 
time="2016-08-18T01:43:47Z" level=debug msg="[60334] Querying upstream 127.0.0.1:53 for qname 'data.logentries.com.'" 
time="2016-08-18T01:43:47Z" level=debug msg="[60632] Failed to query upstream 127.0.0.1:53 for qname 'data.logentries.com.': read udp 127.0.0.1:52180->127.0.0.1:53: i/o timeout" 
time="2016-08-18T01:43:47Z" level=debug msg="[60632] Querying upstream 127.0.0.1:53 for qname 'data.logentries.com.'" 
time="2016-08-18T01:43:47Z" level=debug msg="Received DNS query for \"data.logentries.com.\" from \"127.0.0.1:42752\" with type 1" 
time="2016-08-18T01:43:47Z" level=debug msg="[60334] Doing initial absolute lookup" 
time="2016-08-18T01:43:47Z" level=debug msg="[60334] Querying upstream 127.0.0.1:53 for qname 'data.logentries.com.'" 
time="2016-08-18T01:43:47Z" level=debug msg="Received DNS query for \"data.logentries.com.\" from \"127.0.0.1:41319\" with type 28" 
time="2016-08-18T01:43:47Z" level=debug msg="[60632] Doing initial absolute lookup" 
time="2016-08-18T01:43:47Z" level=debug msg="[60632] Querying upstream 127.0.0.1:53 for qname 'data.logentries.com.'" 
time="2016-08-18T01:43:47Z" level=debug msg="Received DNS query for \"data.logentries.com.\" from \"127.0.0.1:35235\" with type 1" 
time="2016-08-18T01:43:47Z" level=debug msg="[6242] Doing initial absolute lookup" 
time="2016-08-18T01:43:47Z" level=debug msg="[6242] Querying upstream 127.0.0.1:53 for qname 'data.logentries.com.'" 
time="2016-08-18T01:43:47Z" level=debug msg="Received DNS query for \"data.logentries.com.\" from \"127.0.0.1:35235\" with type 28" 
time="2016-08-18T01:43:47Z" level=debug msg="[6447] Doing initial absolute lookup" 
time="2016-08-18T01:43:47Z" level=debug msg="[6447] Querying upstream 127.0.0.1:53 for qname 'data.logentries.com.'"

System details below:

  • Alpine Linux v3.4
  • go-dnsmasq v1.0.6
  • Docker v1.9.1, build a34a1d5 (confirmed same issues on Docker v1.10.x and v1.12.x)

Let me now if there is any other information you need.
@smebberson
Copy link
Author

Has anyone seen anything like this?

@smebberson
Copy link
Author

@janeczku, are you able to weigh in on this issue? Would you like something more specific to recreate it, like a Dockerfile for or something?

@sandytrinh
Copy link

@janeczku I'm also experiencing this same issues on my production server, any suggestions on how I can fix this?

@janeczku
Copy link
Owner

@smebberson Can you share your Dockerfile and the content of /etc/resolv.conf both from the host and container?

1 similar comment
@janeczku
Copy link
Owner

@smebberson Can you share your Dockerfile and the content of /etc/resolv.conf both from the host and container?

@janeczku
Copy link
Owner

janeczku commented Oct 2, 2016

Fixed in 0808cf7

@janeczku janeczku closed this as completed Oct 2, 2016
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
@smebberson @sandytrinh @janeczku