2 forks for md5?

I am puzzled about this. The strace output below is from CVS tip and
shows the postmaster and children during a single (local) connection
when the auth method is md5. What we see is 2 calls to clone() (that's
Linux for fork(), more or less). When the auth method is set to trust or
ident, there is only one clone(), which is what I expected.

Have I missed something, or is there a bug here? Do I need to get the
debugger out?

cheers

andrew (who hates debuggers)

4839 select(5, [3 4], NULL, NULL, {12, 827000}) = 0 (Timeout)
4839 rt_sigprocmask(SIG_SETMASK, ~[ILL TRAP ABRT BUS FPE SEGV CONT SYS RTMIN RT_1], NULL, 8) = 0
4839 time(NULL) = 1127347396
4839 rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
4839 select(5, [3 4], NULL, NULL, {60, 0}) = 1 (in [4], left {54, 411000})
4839 rt_sigprocmask(SIG_SETMASK, ~[ILL TRAP ABRT BUS FPE SEGV CONT SYS RTMIN RT_1], NULL, 8) = 0
4839 accept(4, {sa_family=AF_FILE, path=(at)}, [2]) = 6
4839 getsockname(6, {sa_family=AF_FILE, path="/tmp/.s.PGSQL.5656"}, [21]) = 0
4839 clone(child_stack=0, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0xb7efc708) = 6496
4839 close(6 <unfinished ...>
6496 close(3 <unfinished ...>
4839 <... close resumed> ) = 0
6496 <... close resumed> ) = 0
4839 time( <unfinished ...>
6496 close(4 <unfinished ...>
4839 <... time resumed> NULL) = 1127347402
6496 <... close resumed> ) = 0
4839 rt_sigprocmask(SIG_SETMASK, [], <unfinished ...>
6496 gettimeofday( <unfinished ...>
4839 <... rt_sigprocmask resumed> NULL, 8) = 0
6496 <... gettimeofday resumed> {1127347402, 573584}, NULL) = 0
4839 select(5, [3 4], NULL, NULL, {60, 0} <unfinished ...>
6496 rt_sigaction(SIGTERM, {0x81b1de0, [], SA_RESTART}, {0x818ddc0, [], SA_RESTART}, 8) = 0
6496 rt_sigaction(SIGQUIT, {0x81b1de0, [], SA_RESTART}, {0x818ddc0, [], SA_RESTART}, 8) = 0
6496 rt_sigaction(SIGALRM, {0x81b1de0, [], 0}, {SIG_IGN}, 8) = 0
6496 rt_sigprocmask(SIG_SETMASK, ~[QUIT ILL TRAP ABRT BUS FPE SEGV ALRM TERM CONT SYS RTMIN RT_1], NULL, 8) = 0
6496 socket(PF_FILE, SOCK_DGRAM, 0) = 3
6496 fcntl64(3, F_SETFD, FD_CLOEXEC) = 0
6496 connect(3, {sa_family=AF_FILE, path="/dev/log"}, 16) = 0
6496 time([1127347402]) = 1127347402
6496 stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=1267, ...}) = 0
6496 stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=1267, ...}) = 0
6496 stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=1267, ...}) = 0
6496 send(3, "<134>Sep 21 20:03:22 postgres[64"..., 115, MSG_NOSIGNAL) = 115
6496 setitimer(ITIMER_REAL, {it_interval={0, 0}, it_value={60, 0}}, NULL) = 0
6496 recv(6, "\0\0\0(\0\3\0\0user\0andrew\0database\0tem"..., 8192, 0) = 40
6496 send(6, "R\0\0\0\f\0\0\0\5\371\\\0206", 13, 0) = 13
6496 recv(6, "", 8192, 0) = 0
6496 exit_group(0) = ?
4839 <... select resumed> ) = ? ERESTARTNOHAND (To be restarted)
4839 --- SIGCHLD (Child exited) @ 0 (0) ---
4839 rt_sigprocmask(SIG_SETMASK, ~[ILL TRAP ABRT BUS FPE SEGV CONT SYS RTMIN RT_1], NULL, 8) = 0
4839 waitpid(-1, [{WIFEXITED(s) && WEXITSTATUS(s) == 0}], WNOHANG) = 6496
4839 send(5, "\2\0\0\0\20\0\0\0\0\0\0\0`\31\0\0", 16, 0) = 16
4839 waitpid(-1, 0xbfb06d2c, WNOHANG) = 0
4839 rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
4839 sigreturn() = ? (mask now [])
4839 rt_sigprocmask(SIG_SETMASK, ~[ILL TRAP ABRT BUS FPE SEGV CONT SYS RTMIN RT_1], NULL, 8) = 0
4839 time(NULL) = 1127347402
4839 rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
4839 select(5, [3 4], NULL, NULL, {60, 0}) = 1 (in [4], left {53, 697000})
4839 rt_sigprocmask(SIG_SETMASK, ~[ILL TRAP ABRT BUS FPE SEGV CONT SYS RTMIN RT_1], NULL, 8) = 0
4839 accept(4, {sa_family=AF_FILE, path=(at)}, [2]) = 6
4839 getsockname(6, {sa_family=AF_FILE, path="/tmp/.s.PGSQL.5656"}, [21]) = 0
4839 clone(child_stack=0, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0xb7efc708) = 6498
4839 close(6 <unfinished ...>
6498 close(3 <unfinished ...>
4839 <... close resumed> ) = 0
6498 <... close resumed> ) = 0
4839 time( <unfinished ...>
6498 close(4 <unfinished ...>
4839 <... time resumed> NULL) = 1127347408
6498 <... close resumed> ) = 0
4839 rt_sigprocmask(SIG_SETMASK, [], <unfinished ...>
6498 gettimeofday( <unfinished ...>
4839 <... rt_sigprocmask resumed> NULL, 8) = 0
6498 <... gettimeofday resumed> {1127347408, 879470}, NULL) = 0
4839 select(5, [3 4], NULL, NULL, {60, 0} <unfinished ...>
6498 rt_sigaction(SIGTERM, {0x81b1de0, [], SA_RESTART}, {0x818ddc0, [], SA_RESTART}, 8) = 0
6498 rt_sigaction(SIGQUIT, {0x81b1de0, [], SA_RESTART}, {0x818ddc0, [], SA_RESTART}, 8) = 0
6498 rt_sigaction(SIGALRM, {0x81b1de0, [], 0}, {SIG_IGN}, 8) = 0
6498 rt_sigprocmask(SIG_SETMASK, ~[QUIT ILL TRAP ABRT BUS FPE SEGV ALRM TERM CONT SYS RTMIN RT_1], NULL, 8) = 0
6498 socket(PF_FILE, SOCK_DGRAM, 0) = 3
6498 fcntl64(3, F_SETFD, FD_CLOEXEC) = 0
6498 connect(3, {sa_family=AF_FILE, path="/dev/log"}, 16) = 0
6498 time([1127347408]) = 1127347408
6498 stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=1267, ...}) = 0
6498 stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=1267, ...}) = 0
6498 stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=1267, ...}) = 0
6498 send(3, "<134>Sep 21 20:03:28 postgres[64"..., 115, MSG_NOSIGNAL) = 115
6498 setitimer(ITIMER_REAL, {it_interval={0, 0}, it_value={60, 0}}, NULL) = 0
6498 recv(6, "\0\0\0(\0\3\0\0user\0andrew\0database\0tem"..., 8192, 0) = 40
6498 send(6, "R\0\0\0\f\0\0\0\5YNNz", 13, 0) = 13
6498 recv(6, "p\0\0\0(md5bd5dda08808b6b81dcb7498c"..., 8192, 0) = 41
6498 setitimer(ITIMER_REAL, {it_interval={0, 0}, it_value={0, 0}}, NULL) = 0
6498 rt_sigprocmask(SIG_SETMASK, ~[ILL TRAP ABRT BUS FPE SEGV CONT SYS RTMIN RT_1], NULL, 8) = 0
6498 time([1127347408]) = 1127347408
6498 stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=1267, ...}) = 0
6498 stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=1267, ...}) = 0
6498 stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=1267, ...}) = 0
6498 send(3, "<134>Sep 21 20:03:28 postgres[64"..., 126, MSG_NOSIGNAL) = 126
6498 rt_sigaction(SIGHUP, {0x81b1ed8, [], SA_RESTART}, {0x818a71c, [], SA_RESTART}, 8) = 0
6498 rt_sigaction(SIGINT, {0x81b1df0, [], SA_RESTART}, {0x818ddc0, [], SA_RESTART}, 8) = 0
6498 rt_sigaction(SIGTERM, {0x81b1d68, [], SA_RESTART}, {0x81b1de0, [], SA_RESTART}, 8) = 0
6498 rt_sigaction(SIGQUIT, {0x81b1ce0, [], SA_RESTART}, {0x81b1de0, [], SA_RESTART}, 8) = 0
6498 rt_sigaction(SIGALRM, {0x81ac1e4, [], 0}, {0x81b1de0, [], 0}, 8) = 0
6498 rt_sigaction(SIGPIPE, {SIG_IGN}, {SIG_IGN}, 8) = 0
6498 rt_sigaction(SIGUSR1, {0x81a60ec, [], SA_RESTART}, {0x818ad60, [], SA_RESTART}, 8) = 0
6498 rt_sigaction(SIGUSR2, {0x80fab8c, [], SA_RESTART}, {0x818ae80, [], SA_RESTART}, 8) = 0
6498 rt_sigaction(SIGFPE, {0x81b1e78, [], SA_RESTART}, {SIG_DFL}, 8) = 0
6498 rt_sigaction(SIGCHLD, {SIG_DFL}, {0x818d800, [], SA_RESTART|SA_NOCLDSTOP}, 8) = 0
6498 rt_sigprocmask(SIG_SETMASK, ~[QUIT ILL TRAP ABRT BUS FPE SEGV CONT SYS RTMIN RT_1], NULL, 8) = 0
6498 open("global/pg_database", O_RDONLY|O_LARGEFILE) = 4
6498 fstat64(4, {st_mode=S_IFREG|0600, st_size=88, ...}) = 0
6498 mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7f09000
6498 read(4, "\"postgres\" 10791 1663 499 499\n\"t"..., 4096) = 88
6498 close(4) = 0
6498 munmap(0xb7f09000, 4096) = 0
6498 access("base/1", F_OK) = 0
6498 open("base/1/PG_VERSION", O_RDONLY|O_LARGEFILE) = 4
6498 fstat64(4, {st_mode=S_IFREG|0600, st_size=4, ...}) = 0
6498 mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7f09000
6498 read(4, "8.1\n", 4096) = 4
6498 close(4) = 0
6498 munmap(0xb7f09000, 4096) = 0
6498 semctl(1966103, 3, IPC_64|SETVAL, 0xbfb06d98) = 0
6498 brk(0x9857000) = 0x9857000
6498 open("base/1/pg_internal.init", O_RDONLY|O_LARGEFILE) = 4
6498 fstat64(4, {st_mode=S_IFREG|0600, st_size=58212, ...}) = 0
6498 mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7f09000
6498 read(4, "b2W\0|\0\0\0\177\6\0\0\1\0\0\0(\n\0\0\0\0\0\0\377\377\377"..., 4096) = 4096
6498 read(4, "\20\0\0\0\377\377\377\377\1\0\4\0\0\0\0\0\n\0\0\0\377\377"..., 4096) = 4096
6498 read(4, "3\n\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\1\0r\0"..., 4096) = 4096
6498 read(4, "\377\377\377\377\1pi\1\0\0\1\0\0\0\0\0h\0\0\0009\n\0\0"..., 4096) = 4096
6498 read(4, "\0\0\0\0h\0\0\0;\n\0\0stavalues2\0\0\0\0\0\0\0\0\0\0"..., 4096) = 4096
6498 read(4, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\5\0\n\0\3\t \377\0\0\0"..., 4096) = 4096
6498 read(4, "\32\0\0\0\1\0\0\0\0\0\0\0\305\7\0\0|\0\0\0btree\0\0\0\0"..., 4096) = 4096
6498 read(4, "N\1\0\0O\1\0\0P\1\0\0Q\1\0\0R\1\0\0L\1\0\0\314\3\0\0\364"..., 4096) = 4096
6498 read(4, "N\1\0\0O\1\0\0P\1\0\0Q\1\0\0R\1\0\0L\1\0\0\314\3\0\0\364"..., 4096) = 4096
6498 read(4, "\377\377\377\377\377\377\377\377\1pi\0\0\0\1\0\0\0\0\0"..., 4096) = 4096
6498 brk(0x987b000) = 0x987b000
6498 read(4, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 4096) = 4096
6498 read(4, "\0\0\0\0\32\0\0\0\377\377\377\377\4\0\3\0\0\0\0\0\377\377"..., 4096) = 4096
6498 read(4, "al\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 4096) = 4096
6498 read(4, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 4096) = 4096
6498 read(4, "\0\0\0\0h\0\0\0\356\4\0\0datallowconn\0\0\0\0\0\0\0\0"..., 4096) = 868
6498 read(4, "", 4096) = 0
6498 close(4) = 0
6498 munmap(0xb7f09000, 4096) = 0
6498 mmap2(NULL, 135168, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb72e1000
6498 gettimeofday({1127347408, 884651}, NULL) = 0
6498 send(5, "\1\0\0\0\234\0\0\0\1\0\0\0b\31\0\0\1\0\0\0\n\0\0\0\1\0"..., 156, 0) = 156
6498 rt_sigprocmask(SIG_BLOCK, NULL, ~[QUIT ILL TRAP ABRT BUS FPE KILL SEGV CONT STOP SYS RTMIN RT_1], 8) = 0
6498 rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
6498 send(6, "R\0\0\0\10\0\0\0\0S\0\0\0\36client_encoding\0SQ"..., 284, 0) = 284
6498 recv(6, "X\0\0\0\4", 8192, 0) = 5
6498 gettimeofday({1127347417, 532222}, NULL) = 0
6498 time([1127347417]) = 1127347417
6498 stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=1267, ...}) = 0
6498 stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=1267, ...}) = 0
6498 stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=1267, ...}) = 0
6498 send(3, "<134>Sep 21 20:03:37 postgres[64"..., 162, MSG_NOSIGNAL) = 162
6498 exit_group(0) = ?
4839 <... select resumed> ) = ? ERESTARTNOHAND (To be restarted)
4839 --- SIGCHLD (Child exited) @ 0 (0) ---
4839 rt_sigprocmask(SIG_SETMASK, ~[ILL TRAP ABRT BUS FPE SEGV CONT SYS RTMIN RT_1], NULL, 8) = 0
4839 waitpid(-1, [{WIFEXITED(s) && WEXITSTATUS(s) == 0}], WNOHANG) = 6498
4839 send(5, "\2\0\0\0\20\0\0\0\0\0\0\0b\31\0\0", 16, 0) = 16
4839 waitpid(-1, 0xbfb06d2c, WNOHANG) = 0
4839 rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
4839 sigreturn() = ? (mask now [])
4839 rt_sigprocmask(SIG_SETMASK, ~[ILL TRAP ABRT BUS FPE SEGV CONT SYS RTMIN RT_1], NULL, 8) = 0
4839 time(NULL) = 1127347417
4839 rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
4839 select(5, [3 4], NULL, NULL, {60, 0} <unfinished ...>