https://bugs.dragonflybsd.org/https://bugs.dragonflybsd.org/favicon.ico?16293952082006-08-02T08:31:08ZDragonFlyBSD bugtrackerDragonFlyBSD - Bug #273: Sendmail rset command hangs socket on 1.6-Releasehttps://bugs.dragonflybsd.org/issues/273?journal_id=10332006-08-02T08:31:08Zdillon
<ul></ul><p>:We have a cluster of mail servers, one of which we have upgraded to<br />:1.6-Release (from 1.2) and then subsequently did a fresh install of 1.6<br />:on after the issue first arose.<br />:<br />:In essence, using the supplied sendmail and having the connected<br />:sendmail session issue a rset command results in that sendmail process<br />:hanging (only by issuing the telnet ^] command to get to a telnet prompt<br />:and issuing quit can the session be killed). If instead of an rset<br />:command the quit command is issued, the session will end (i.e. the<br />:telnet session terminates) but the sendmail process with "quit" appears<br />:in the process list and will not go away unless killed.<br />:<br />:Has anyone seen this odd behavior? At first I thought it was due to a<br />:milter, so I removed it from the .mc file and rebuilt sendmail.cf but no<br />:change in socket behavior. How can I help in terms of troubleshooting?<br />:<br />:Sven</p>
<pre><code>That is really odd. I wonder if it is related to the posix issues<br /> that were reported recently.</code></pre>
<pre><code>If you can repeat it easily with telnet, could you use tcpdump<br /> and ktrace (on the forked sendmail demon after you connect) to<br /> figure out what happens when you try to send it the 'rset' ?<br /> With tcpdump it should be possible to determine if the 'rset' gets<br /> transmitted, and with ktrace it should be possible to determine<br /> if sendmail sees it.</code></pre>
<pre><code>-Matt<br /> Matthew Dillon <br /> &lt;<a class="email" href="mailto:dillon@backplane.com">dillon@backplane.com</a>&gt;</code></pre> DragonFlyBSD - Bug #273: Sendmail rset command hangs socket on 1.6-Releasehttps://bugs.dragonflybsd.org/issues/273?journal_id=10352006-08-02T20:53:02Zsven
<ul></ul><p>On Tue, 2006-08-01 at 18:24 -0700, Matthew Dillon wrote:</p>
<blockquote>
<p>:We have a cluster of mail servers, one of which we have upgraded to<br />:1.6-Release (from 1.2) and then subsequently did a fresh install of 1.6<br />:on after the issue first arose.<br />:<br />:In essence, using the supplied sendmail and having the connected<br />:sendmail session issue a rset command results in that sendmail process<br />:hanging (only by issuing the telnet ^] command to get to a telnet prompt<br />:and issuing quit can the session be killed). If instead of an rset<br />:command the quit command is issued, the session will end (i.e. the<br />:telnet session terminates) but the sendmail process with "quit" appears<br />:in the process list and will not go away unless killed.<br />:<br />:Has anyone seen this odd behavior? At first I thought it was due to a<br />:milter, so I removed it from the .mc file and rebuilt sendmail.cf but no<br />:change in socket behavior. How can I help in terms of troubleshooting?<br />:<br />:Sven</p>
<p>That is really odd. I wonder if it is related to the posix issues<br />that were reported recently.</p>
<p>If you can repeat it easily with telnet, could you use tcpdump<br />and ktrace (on the forked sendmail demon after you connect) to<br />figure out what happens when you try to send it the 'rset' ?<br />With tcpdump it should be possible to determine if the 'rset' gets<br />transmitted, and with ktrace it should be possible to determine<br />if sendmail sees it.</p>
<p>-Matt<br />Matthew Dillon <br /><<a class="email" href="mailto:dillon@backplane.com">dillon@backplane.com</a>></p>
</blockquote>
<p>Based on the tcpdump it would appear that the command does get sent:<br />Transmission Control Protocol, Src Port: 38093 (38093), Dst Port: smtp<br />(25), Seq: 67, Ack: 357, Len: 6<br /> Source port: 38093 (38093)<br /> Destination port: smtp (25)<br /> Sequence number: 67 (relative sequence number)<br /> Next sequence number: 73 (relative sequence number)<br /> Acknowledgement number: 357 (relative ack number)<br /> Header length: 32 bytes<br /> Flags: 0x0018 (PSH, ACK)<br /> Window size: 6912 (scaled)<br /> Checksum: 0xfd64 [correct]<br /> Options: (12 bytes)<br />Simple Mail Transfer Protocol<br /> Command: rset\r\n<br /> Command: rset</p>
<p>Based on the ktrace it would appear that sendmail sees it, but fails to<br />write to the sendmail.st file:</p>
<pre><code>50367 sendmail RET sendto 163/0xa3<br /> 50367 sendmail CALL gettimeofday(0xbfbfba38,0)<br /> 50367 sendmail RET gettimeofday 0<br /> 50367 sendmail CALL lstat(0xbfbfb570,0xbfbfb9c0)<br /> 50367 sendmail NAMI "/var/log/sendmail.st" <br /> 50367 sendmail RET lstat 0<br /> 50367 sendmail CALL lstat(0xbfbeb020,0xbfbeafb0)<br /> 50367 sendmail NAMI "/" <br /> 50367 sendmail RET lstat 0<br /> 50367 sendmail CALL geteuid<br /> 50367 sendmail RET geteuid 0<br /> 50367 sendmail CALL lstat(0xbfbeb020,0xbfbeafb0)<br /> 50367 sendmail NAMI "/var" <br /> 50367 sendmail RET lstat 0<br /> 50367 sendmail CALL geteuid<br /> 50367 sendmail RET geteuid 0<br /> 50367 sendmail CALL lstat(0xbfbeb020,0xbfbeafb0)<br /> 50367 sendmail NAMI "/var/log" <br /> 50367 sendmail RET lstat 0<br /> 50367 sendmail CALL geteuid<br /> 50367 sendmail RET geteuid 0<br /> 50367 sendmail CALL open(0x283778a0,0x2,0x180)<br /> 50367 sendmail NAMI "/var/log/sendmail.st" <br /> 50367 sendmail RET open 7<br /> 50367 sendmail CALL fstat(0x7,0xbfbfb910)<br /> 50367 sendmail RET fstat 0<br /> 50367 sendmail CALL flock(0x7,0x2)</code></pre>
<p>Compare this to a "normal" situation (taken from a freebsd box):</p>
<pre><code>52523 sendmail RET sendto 160/0xa0<br /> 52523 sendmail CALL gettimeofday(0x7fffffffa3d0,0)<br /> 52523 sendmail RET gettimeofday 0<br /> 52523 sendmail CALL lstat(0x7fffffff9df0,0x7fffffffa340)<br /> 52523 sendmail NAMI "/var/log/sendmail.st" <br /> 52523 sendmail RET lstat 0<br /> 52523 sendmail CALL lstat(0x7fffffff1d70,0x7fffffff1cf0)<br /> 52523 sendmail NAMI "/" <br /> 52523 sendmail RET lstat 0<br /> 52523 sendmail CALL geteuid<br /> 52523 sendmail RET geteuid 0<br /> 52523 sendmail CALL lstat(0x7fffffff1d70,0x7fffffff1cf0)<br /> 52523 sendmail NAMI "/var" <br /> 52523 sendmail RET lstat 0<br /> 52523 sendmail CALL geteuid<br /> 52523 sendmail RET geteuid 0<br /> 52523 sendmail CALL lstat(0x7fffffff1d70,0x7fffffff1cf0)<br /> 52523 sendmail NAMI "/var/log" <br /> 52523 sendmail RET lstat 0<br /> 52523 sendmail CALL geteuid<br /> 52523 sendmail RET geteuid 0<br /> 52523 sendmail CALL open(0x5eb5c0,0x2,0x180)<br /> 52523 sendmail NAMI "/var/log/sendmail.st" <br /> 52523 sendmail RET open 6<br /> 52523 sendmail CALL fstat(0x6,0x7fffffffa270)<br /> 52523 sendmail RET fstat 0<br /> 52523 sendmail CALL flock(0x6,0x2)<br /> 52523 sendmail RET flock 0<br /> 52523 sendmail CALL fstat(0x6,0x7fffffffa2a0)<br /> 52523 sendmail RET fstat 0<br /> 52523 sendmail CALL read(0x6,0x7fffffffa3f0,0x5a8)<br /> 52523 sendmail GIO fd 6 read 1448 bytes<br /> 0x0000 deb1 0100 0400 0000 06e8 ce44 0000 0000 a805 0000 0000<br />0000 3100 0000 0000 0000 |...........D............1.......|<br /> 0x0020 6a00 0000 0000 0000 0300 0000 0000 0000 0000 0000 0000<br />0000 0000 0000 0000 0000 |j...............................|<br /> 0x0040 0000 0000 0000 0000 0e00 0000 0000 0000 0000 0000 0000<br />0000 2300 0000 0000 0000 |........................#.......|</code></pre>
<p>< --chop --></p>
<pre><code>52523 sendmail RET read 1448/0x5a8<br /> 52523 sendmail CALL lseek(0x6,0,0,0)<br /> 52523 sendmail RET lseek 0<br /> 52523 sendmail CALL write(0x6,0x7fffffffa3f0,0x5a8)<br /> 52523 sendmail GIO fd 6 wrote 1448 bytes<br /> 0x0000 deb1 0100 0400 0000 06e8 ce44 0000 0000 a805 0000 0000<br />0000 3200 0000 0000 0000 |...........D............2.......|</code></pre>
<p>and so on ...</p>
<p>Sven</p> DragonFlyBSD - Bug #273: Sendmail rset command hangs socket on 1.6-Releasehttps://bugs.dragonflybsd.org/issues/273?journal_id=10362006-08-03T00:04:02Zdillon
<ul></ul><p>:Based on the ktrace it would appear that sendmail sees it, but fails to<br />:write to the sendmail.st file:<br />:<br />: 50367 sendmail RET sendto 163/0xa3<br />:...<br />: 50367 sendmail RET fstat 0<br />: 50367 sendmail CALL flock(0x7,0x2)</p>
<pre><code>This is great news! It's stuck on the flock() call, which is the<br /> same problem that was reported with postfix.</code></pre>
<pre><code>Now do this. With sendmail stuck on the flock call, compile up<br /> /usr/src/test/debug/vnodeinfo.c and run vnodeinfo -a out to a file.<br /> Find the file the flock is stuck on and lets see if there is anyone<br /> else holding the lock.</code></pre>
<pre><code>NOTE! You will have to use the vnodeinfo.c from HEAD. The one in<br /> REL does not have the lock tracing code in it. And you may have<br /> to make some modifications if there are #include file snafu's.</code></pre>
<pre><code>I feel confident that we can track down this problem and fix it. What<br /> I need to know is whether that flock is being held on the vnode's blocked<br /> list without any locks held on the locked list, which would indicate a<br /> tsleep/wakeup race, or whether there is someone else holding the lock.</code></pre>
<pre><code>-Matt</code></pre> DragonFlyBSD - Bug #273: Sendmail rset command hangs socket on 1.6-Releasehttps://bugs.dragonflybsd.org/issues/273?journal_id=10592006-08-05T09:50:13Zjustin
<ul></ul><p>Appears to be fixed in the 1.6.1 release.</p>