Skip to content

Strange problem on Docker container restart #18

New issue
New issue
Closed
Closed
Strange problem on Docker container restart#18
@smebberson

Description

@smebberson
smebberson
opened on Aug 18, 2016

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.

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions