Strange problem on Docker container restart
Closed this issue · 6 comments
smebberson commented
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
appcontainer throws an uncaught error and the container quits (programmed to be this way). - Due to the
restart: alwayspolicy 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 commented
Has anyone seen anything like this?
smebberson commented
@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 commented
@janeczku I'm also experiencing this same issues on my production server, any suggestions on how I can fix this?
janeczku commented
@smebberson Can you share your Dockerfile and the content of /etc/resolv.conf both from the host and container?
janeczku commented
@smebberson Can you share your Dockerfile and the content of /etc/resolv.conf both from the host and container?