HostsFileParser: lookups during a hosts file reload miss existing entries #429

Summary

HostsFileParser reloads a changed hosts file by clearing its maps in place and then refilling them. Lookups read those maps without the lock, so a lookup that runs between the clear and the refill gets Optional.empty() for a name that is in both the old and the new file. The first read of the file has the same window. Since v3.6.4.

Impact: for each lookup that coincides with a reload, Lookup falls through to DNS (usually NXDOMAIN) for a name the hosts file defines. The window opens on every reload, and more often the lower dnsjava.hostsfile.change_check_interval_ms is and the more threads resolve.

A second, smaller bug in the same code: isEntireFileParsed is never reset, so if the file grows past dnsjava.hostsfile.max_size_bytes after a full parse, every name not already cached is reported absent until the JVM restarts.

How it was found

DNSControl routes JVM-wide DNS through dnsjava's Lookup and honours jdk.net.hosts.file via HostsFileParser. Its quality pass (OpenPojo/dnscontrol#23) added a concurrency test: 32 threads run new Lookup("racing.a.test.", Type.A).run() while the main thread rewrites the hosts file between two addresses. Every answer must be one of the two addresses. Files are replaced atomically (write aside, ATOMIC_MOVE), so half-written files are ruled out, and dnsjava.hostsfile.change_check_interval_ms=0.

Against dnsjava 3.7.0's parser (macOS, Corretto 21.0.6), runs that failed with a lookup getting no answer:

DNSControl now works around it (HostsFileWatcher): it builds a new HostsFileParser(path, false), reads it once, then swaps it into Lookup whole. Result: 0 / 20 at 3000 rewrites. We would rather drop that workaround once dnsjava's own reload is safe.

Root cause

On master (9e26eba2):

1. validateCache() L324-L326 returns without the lock while the check interval has not elapsed.
2. The reloading thread sets lastFileModificationCheckTime (L341) before reading, so every other thread takes that fast path for the whole reload.
3. readHostsFile() L351 calls createOrClearCache() L366-L374, which clears the live maps (or, on the first read, publishes new empty ones) before parseEntireHostsFile() fills them.
4. Meanwhile getAddressForHost L115 reads the map and finds nothing.

isEntireFileParsed is only ever set to true (L356), which is the second bug.

The unlocked path came from 5609998 ("Reduce lock contention and disk access in hosts file parsing", #369), first released in v3.6.4; before it, getAddressForHost was synchronized. #400 (an NPE on hostsCache) is another symptom of the same unlocked read.

Deterministic reproduction

Three tests in HostsFileParserTest (in the PR that follows). The first two pause the reload inside the file read with a spied FileSystemProvider (the same technique as the existing handleNoModificationTime) and look up in that window, using a mocked Clock to stay on the fast path. No sleeps or loops:

• testLookupDuringReloadFindsUnchangedEntry: a lookup during a reload must find an entry present in both versions.
• testLookupDuringFirstReadWaitsForIt: a lookup during the first read must wait for it instead of answering from the empty map.
• testFileGrownBeyondFullCacheSizeIsSearched: after a small file is replaced by one over the full-cache limit, names only in the new file must be found.

Against master's HostsFileParser, all 27 tests run, and only these 3 fail, with no retries, on Corretto 11.0.15, 21.0.6 and 25:

org.xbill.DNS.hosts.HostsFileParserTest.testLookupDuringReloadFindsUnchangedEntry <<< FAILURE!
java.lang.AssertionError:
Expecting Optional to contain:
  kubernetes.docker.internal./127.0.0.1
but was empty.

org.xbill.DNS.hosts.HostsFileParserTest.testLookupDuringFirstReadWaitsForIt <<< FAILURE!
java.lang.AssertionError:
Expecting Optional to contain:
  kubernetes.docker.internal./127.0.0.1
but was empty.

org.xbill.DNS.hosts.HostsFileParserTest.testFileGrownBeyondFullCacheSizeIsSearched <<< FAILURE!
java.lang.AssertionError:
Expecting Optional to contain:
  localhost-10./127.0.0.10
but was empty.

A fix with these tests follows as a PR.