host(1) & nslookup(1) hang, but name resolution ... works??!?
brd at FreeBSD.org
Wed Nov 28 09:31:58 PST 2007
On Nov 28, 2007 8:17 AM, David Wolfskill <david at catwhisker.org> wrote:
> OK; this is weird and probably rather vaguer than anyone would like.
> I noticed this yesterday, but I needed to actually use my laptop at
> work, so I didn't really have much opportunity to poke around. I did
> some poking around this morning (on booting yesterday's CURRENT to build
> today's), and here's some background and what I found:
> * I normally run the laptop as a DHCP client.
> * In dhclient-exit-hooks, I have a bit of code that uses the just-
> acquired IP address as an argument to host(1), then parses the output
> to determine a hostname to assign to the laptop. This has been
> working for a very long time -- definitely as far back as FreeBSD 4.8;
> probably earlier than that. It still works fine in RELENG_6 &
> RELENG_7 (which I also track daily; the laptop gets a fair workout).
> * I'm presently running:
> FreeBSD g1-1.catwhisker.org 8.0-CURRENT FreeBSD 8.0-CURRENT #604: Tue Nov 27 07:17:37 PST 2007 root at g1-1.catwhisker.org.:/common/S4/obj/usr/src/sys/CANARY i386
> which is where I first noticed the issue: the invocation of host(1)
> appears to hang.
> * I tried invoking host(1) from the command line; that invocation also hung.
> * nslookup(1) also hung.
> * I tried running tcpdump(1), then invoking host(1); there was no
> indication of network traffic at all.
> * I tried running host(1) under ktrace(1); running kdump(1) with "-E"
> flag so I can see some timing, the output ends with:
> 9739 initial thread 0.010794 CALL getsockname(0x3,0xbfbfe140,0xbfbfe15c)
> 9739 initial thread 0.010820 RET getsockname 0
> 9739 initial thread 0.010837 CALL close(0x3)
> 9739 initial thread 0.010874 RET close 0
> 9739 initial thread 0.010892 CALL socket(PF_LOCAL,SOCK_STREAM,0)
> 9739 initial thread 0.010934 RET socket 3
> 9739 initial thread 0.010951 CALL close(0x3)
> 9739 initial thread 0.010982 RET close 0
> 9739 initial thread 0.012502 CALL _umtx_op(0xbfbfe0ac,0x3,0x1,0,0)
> 9739 initial thread 0.012535 RET _umtx_op 0
> 9739 initial thread 0.012552 CALL sigprocmask(SIG_BLOCK,0xbfbfe040,0x28501190)
> 9739 initial thread 0.012569 RET sigprocmask 0
> 9739 initial thread 0.012597 CALL _umtx_op(0x283168a0,0x5,0,0,0)
> 9739 initial thread 19.115591 RET _umtx_op RESTART
> 9739 initial thread 19.115650 PSIG SIGKILL SIG_DFL
> As you can see, I waited about 19 seconds before killing the host(1)
> process (with SIGKILL).
> * Despite all of this, hostname resolution is actually working -- e.g.,
> I can ping using a hostname:
> g1-1(8.0-C) ping -c 2 freefall.freebsd.org
> PING freefall.freebsd.org (22.214.171.124): 56 data bytes
> 64 bytes from 126.96.36.199: icmp_seq=0 ttl=56 time=14.120 ms
> 64 bytes from 188.8.131.52: icmp_seq=1 ttl=55 time=14.583 ms
> --- freefall.freebsd.org ping statistics ---
> 2 packets transmitted, 2 packets received, 0.0% packet loss
> round-trip min/avg/max/stddev = 14.120/14.351/14.583/0.231 ms
> which is a fairly useful thing, since I'm actually sending this
> message from my internal mailhost (vs. my laptop). (It's also
> something of which I wasn't aware yesterday at work, or I might
> have been able to report this earlier.)
> * Here's what ps(1) has to say:
> g1-1(8.0-C) ps xwwl
> UID PID PPID CPU PRI NI VSZ RSS MWCHAN STAT TT TIME COMMAND
> 1001 24683 24682 0 20 0 4500 2588 pause Is pe 0:00.06 csh
> 1001 24920 24683 0 44 0 5596 1896 umtxn I+ pe 0:00.01 host 172.17.1.1
> * The host(1) process is not killed by SIGTERM, but SIGKILL does the job.
> As noted, I'm building today's CURRENT now; if there's a change in
> the behavior, I'll send a follow-up note.
> I keep a local CVS repo mirror handy, and am not at all averse to
> testing patches.
> If there are other aspects of the behavior I might check on, please
> let me know.
There was a similar thread earlier and it looks like a file was missed
in a commit.. It has been committed since..
This is just a guess though..
More information about the freebsd-current