Fw: [Bug 3610] New: kernel-2.6.9 breaks Amanda

Fw: [Bug 3610] New: kernel-2.6.9 breaks Amanda

[Stephen Hemminger]

http://bugme.osdl.org/show_bug.cgi?id=3610

           Summary: kernel-2.6.9 breaks Amanda
    Kernel Version: 2.6.9
            Status: NEW
          Severity: normal
             Owner: shemminger@osdl.org
         Submitter: wralph@nswc.navy.mil


Distribution: Fedora Core 2

Hardware Environment: Pentium III @800MHz, 384 MB memory, Adaptec AIC-7892A U160
SCSI controller, SEAGATE   Model: ST39204LW drive, Lite-ON LNE100TX NIC, Gateway
GP 800 computer. This machine is the Amanda tape server.

Software Environment: Amanda 2.4.4p2 Software, Fedora Core 2 environment with
vanilla 2.6.9 kernel.

Problem Description: Amanda clients exchanges UDP packets with the server giving
it a TCP port number with which to connect in order to receive files to be
dumped to tape. Under kernel-2.6.8.1 the sofware performs perfectly. Under
kernel-2.6.9, with exactly the same Amanda software, the UDP packet exchange
seems to occur, but no TCP connection between client and server occurs. The
client eventually times out with messages like:

sendbackup: time 0.000: stream_server: waiting for connection: 0.0.0.0.32951
sendbackup: time 0.000: stream_server: waiting for connection: 0.0.0.0.32952
sendbackup: time 0.000: stream_server: waiting for connection: 0.0.0.0.32953
sendbackup: time 0.000: waiting for connect on 32951, then 32952, then 32953
sendbackup: time 29.995: stream_accept: timeout after 30 seconds
sendbackup: time 29.995: timeout on data port 32951
sendbackup: time 59.990: stream_accept: timeout after 30 seconds
sendbackup: time 59.990: timeout on mesg port 32952
sendbackup: time 89.987: stream_accept: timeout after 30 seconds
sendbackup: time 89.987: timeout on index port 32953
sendbackup: time 89.987: pid 3008 finish time Thu Oct 21 12:30:38 2004

Running tcpdump on both client and server shows no TCP traffic at all. I have
completely disabled iptables in an effort to allow the traffic to pass. No
effect. Re-compiling the Amanda software had no effect. Switching back to
kernel-2.6.8.1 allows it to run normally.lspci -vvv
00:00.0 Host bridge: Intel Corp. 440BX/ZX/DX - 82443BX/ZX/DX Host bridge (rev 03)
        Control: I/O- Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr-
Stepping- SERR+ FastB2B-
        Status: Cap+ 66Mhz- UDF- FastB2B- ParErr- DEVSEL=medium >TAbort-
<TAbort- <MAbort+ >SERR- <PERR-
        Latency: 64
        Region 0: Memory at f8000000 (32-bit, prefetchable)
        Capabilities: [a0] AGP version 1.0
                Status: RQ=32 Iso- ArqSz=0 Cal=0 SBA+ ITACoh- GART64- HTrans-
64bit- FW- AGP3- Rate=x1,x2
                Command: RQ=1 ArqSz=0 Cal=0 SBA- AGP- GART64- 64bit- FW- Rate=<none>

00:01.0 PCI bridge: Intel Corp. 440BX/ZX/DX - 82443BX/ZX/DX AGP bridge (rev 03)
(prog-if 00 [Normal decode])
        Control: I/O+ Mem+ BusMaster+ SpecCycle+ MemWINV+ VGASnoop- ParErr-
Stepping- SERR+ FastB2B-
        Status: Cap- 66Mhz+ UDF- FastB2B- ParErr- DEVSEL=medium >TAbort-
<TAbort- <MAbort- >SERR- <PERR-
        Latency: 128
        Bus: primary=00, secondary=01, subordinate=01, sec-latency=64
        I/O behind bridge: 0000f000-00000fff
        Memory behind bridge: f5000000-f5ffffff
        Prefetchable memory behind bridge: fc000000-fdffffff
        BridgeCtl: Parity- SERR- NoISA+ VGA+ MAbort- >Reset- FastB2B+

00:07.0 ISA bridge: Intel Corp. 82371AB/EB/MB PIIX4 ISA (rev 02)
        Control: I/O+ Mem+ BusMaster+ SpecCycle+ MemWINV- VGASnoop- ParErr-
Stepping- SERR- FastB2B-
        Status: Cap- 66Mhz- UDF- FastB2B+ ParErr- DEVSEL=medium >TAbort-
<TAbort- <MAbort- >SERR- <PERR-
        Latency: 0

00:07.1 IDE interface: Intel Corp. 82371AB/EB/MB PIIX4 IDE (rev 01) (prog-if 80
[Master])
        Control: I/O+ Mem- BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr-
Stepping- SERR- FastB2B-
        Status: Cap- 66Mhz- UDF- FastB2B+ ParErr- DEVSEL=medium >TAbort-
<TAbort- <MAbort- >SERR- <PERR-
        Latency: 64
        Region 4: I/O ports at 1820 [size=16]

00:07.2 USB Controller: Intel Corp. 82371AB/EB/MB PIIX4 USB (rev 01) (prog-if 00
[UHCI])
        Control: I/O+ Mem- BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr-
Stepping- SERR- FastB2B-
        Status: Cap- 66Mhz- UDF- FastB2B+ ParErr- DEVSEL=medium >TAbort-
<TAbort- <MAbort- >SERR- <PERR-
        Latency: 64
        Interrupt: pin D routed to IRQ 9
        Region 4: I/O ports at 1800 [size=32]

00:07.3 Bridge: Intel Corp. 82371AB/EB/MB PIIX4 ACPI (rev 02)
        Control: I/O+ Mem+ BusMaster- SpecCycle- MemWINV- VGASnoop- ParErr-
Stepping- SERR- FastB2B-
        Status: Cap- 66Mhz- UDF- FastB2B+ ParErr- DEVSEL=medium >TAbort-
<TAbort- <MAbort- >SERR- <PERR-
        Interrupt: pin ? routed to IRQ 9

00:0e.0 SCSI storage controller: Adaptec AIC-7892A U160/m (rev 02)
        Subsystem: Adaptec 29160 Ultra160 SCSI Controller
        Control: I/O- Mem+ BusMaster+ SpecCycle- MemWINV+ VGASnoop- ParErr-
Stepping- SERR+ FastB2B-
        Status: Cap+ 66Mhz+ UDF- FastB2B+ ParErr- DEVSEL=medium >TAbort-
<TAbort- <MAbort- >SERR- <PERR-
        Latency: 72 (10000ns min, 6250ns max), Cache Line Size 08
        Interrupt: pin A routed to IRQ 11
        BIST result: 00
        Region 0: I/O ports at 1000 [disabled]
        Region 1: Memory at f4000000 (64-bit, non-prefetchable) [size=4K]
        Capabilities: [dc] Power Management version 2
                Flags: PMEClk- DSI- D1- D2- AuxCurrent=0mA
PME(D0-,D1-,D2-,D3hot-,D3cold-)
                Status: D0 PME-Enable- DSel=0 DScale=0 PME-

00:10.0 Ethernet controller: Lite-On Communications Inc LNE100TX (rev 20)
        Subsystem: Netgear FA310TX
        Control: I/O+ Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr-
Stepping- SERR+ FastB2B-
        Status: Cap- 66Mhz- UDF- FastB2B+ ParErr- DEVSEL=medium >TAbort-
<TAbort- <MAbort- >SERR- <PERR-
        Latency: 64
        Interrupt: pin A routed to IRQ 9
        Region 0: I/O ports at 1400
        Region 1: Memory at f4001000 (32-bit, non-prefetchable) [size=256]

01:00.0 VGA compatible controller: nVidia Corporation NV5M64 [RIVA TNT2 Model
64/Model 64 Pro] (rev 15) (prog-if 00 [VGA])
        Subsystem: VISIONTEK: Unknown device 0002
        Control: I/O+ Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr-
Stepping- SERR- FastB2B-
        Status: Cap+ 66Mhz+ UDF- FastB2B+ ParErr- DEVSEL=medium >TAbort-
<TAbort- <MAbort- >SERR- <PERR-
        Latency: 64 (1250ns min, 250ns max)
        Interrupt: pin A routed to IRQ 11
        Region 0: Memory at f5000000 (32-bit, non-prefetchable)
        Region 1: Memory at fc000000 (32-bit, prefetchable) [size=32M]
        Capabilities: [60] Power Management version 1
                Flags: PMEClk- DSI- D1- D2- AuxCurrent=0mA
PME(D0-,D1-,D2-,D3hot-,D3cold-)
                Status: D0 PME-Enable- DSel=0 DScale=0 PME-
        Capabilities: [44] AGP version 2.0
                Status: RQ=32 Iso- ArqSz=0 Cal=0 SBA- ITACoh- GART64- HTrans-
64bit- FW- AGP3- Rate=x1,x2,x4
                Command: RQ=1 ArqSz=0 Cal=0 SBA- AGP- GART64- 64bit- FW- Rate=<none>

more /proc/cpuinfo
processor       : 0
vendor_id       : GenuineIntel
cpu family      : 6
model           : 8
model name      : Pentium III (Coppermine)
stepping        : 3
cpu MHz         : 795.899
cache size      : 256 KB
fdiv_bug        : no
hlt_bug         : no
f00f_bug        : no
coma_bug        : no
fpu             : yes
fpu_exception   : yes
cpuid level     : 2
wp              : yes
flags           : fpu vme de pse tsc msr pae mce cx8 sep mtrr pge mca cmov pat
pse36 mmx fxsr sse
bogomips        : 1572.86

more /proc/modules
uhci_hcd 29136 0 - Live 0xd8997000

more /proc/iomem
00000000-0009f3ff : System RAM
0009f400-0009ffff : reserved
000a0000-000bffff : Video RAM area
000c0000-000cffff : Video ROM
000d0000-000d65ff : Adapter ROM
000e4000-000effff : Adapter ROM
000f0000-000fffff : System ROM
00100000-040fd7ff : System RAM
  00100000-003296b0 : Kernel code
  003296b1-003fbcbf : Kernel data
040fd800-040ff7ff : ACPI Tables
040ff800-040ffbff : ACPI Non-volatile Storage
040ffc00-17ffffff : System RAM
f4000000-f4000fff : 0000:00:0e.0
  f4000000-f4000fff : aic7xxx
f4001000-f40010ff : 0000:00:10.0
  f4001000-f40010ff : tulip
f5000000-f5ffffff : PCI Bus #01
  f5000000-f5ffffff : 0000:01:00.0
f8000000-fbffffff : 0000:00:00.0
fc000000-fdffffff : PCI Bus #01
  fc000000-fdffffff : 0000:01:00.0
    fc000000-fc17ffff : vesafb
fffe7000-ffffffff : reserved

0000-001f : dma1
0020-0021 : pic1
0040-0043 : timer0
0050-0053 : timer1
0060-006f : keyboard
0070-0077 : rtc
0080-008f : dma page reg
00a0-00a1 : pic2
00c0-00df : dma2
00f0-00ff : fpu
0170-0177 : ide1
01f0-01f7 : ide0
02f8-02ff : serial
0376-0376 : ide1
03c0-03df : vesafb
03f6-03f6 : ide0
03f8-03ff : serial
0cf8-0cff : PCI conf1
1000-10ff : 0000:00:0e.0
1400-14ff : 0000:00:10.0
  1400-14ff : tulip
1800-181f : 0000:00:07.2
  1800-181f : uhci_hcd
1820-182f : 0000:00:07.1
  1820-1827 : ide0
  1828-182f : ide1
7000-701f : 0000:00:07.3
8000-803f : 0000:00:07.3

more /proc/scsi/scsi
Attached devices:
Host: scsi0 Channel: 00 Id: 00 Lun: 00
  Vendor: SEAGATE  Model: ST39204LW        Rev: 0006
  Type:   Direct-Access                    ANSI SCSI revision: 03
Host: scsi0 Channel: 00 Id: 06 Lun: 00
  Vendor: SEAGATE  Model: DAT    06240-XXX Rev: 8110
  Type:   Sequential-Access                ANSI SCSI revision: 03



Steps to reproduce: Run Amanda server on kernel-2.6.9.

------- You are receiving this mail because: -------
You are the assignee for the bug, or are watching the assignee.

Re: Fw: [Bug 3610] New: kernel-2.6.9 breaks Amanda

[David S. Miller]

On Thu, 21 Oct 2004 13:37:52 -0700
Stephen Hemminger <shemminger@osdl.org> wrote:

>            Summary: kernel-2.6.9 breaks Amanda

Unfortunately, he failed to show the tcpdump traces of the UDP
traffic as he did in his lkml postings.  There you will find
checksum errors mentioned in the tcpdump output for the last
few consequetive UDP packets and I think that is a good clue
as to what may be the problem here.

I have to trust that the user did try, as Andrew Morton suggested,
the 2.6.8.1 3c59x driver copied into the 2.6.9 kernel.  He said
the problem persists.

He also states he disabled netfilter (although I would have liked
him to also make sure that no netfilter modules were loaded as well).

That basically leaves us with ipv4/udp changes to look at.  There
are two potentially problem causing changesets.  That would be:

ChangeSet 1.1832.88.1 2004/09/13 20:05:28 acme@conectiva.com.br

and

ChangeSet 1.1803.16.6 2004/07/21 13:51:01 Samuel.Thibault@ens-lyon.fr

I'm mostly suspicious of the latter, because it changes the
behvaior of UDP sockets when MSG_TRUNC is specified.  Can
someone check if Amanda uses MSG_TRUNC on UDP sockets?

If the bug reporter had provided an strace of the Amanda userland
components, we'd know this already.

Re: [Bug 3610] New: kernel-2.6.9 breaks Amanda

[Stephen Hemminger]

On Thu, 21 Oct 2004 14:23:35 -0700
"David S. Miller" <davem@davemloft.net> wrote:

> On Thu, 21 Oct 2004 13:37:52 -0700
> Stephen Hemminger <shemminger@osdl.org> wrote:
> 
> >            Summary: kernel-2.6.9 breaks Amanda
> 
> Unfortunately, he failed to show the tcpdump traces of the UDP
> traffic as he did in his lkml postings.  There you will find
> checksum errors mentioned in the tcpdump output for the last
> few consequetive UDP packets and I think that is a good clue
> as to what may be the problem here.

Since it is reproducible, I already requested a tcpdump trace.

Re: Fw: [Bug 3610] New: kernel-2.6.9 breaks Amanda

[Herbert Xu]

David S. Miller <davem@davemloft.net> wrote:
> 
> ChangeSet 1.1803.16.6 2004/07/21 13:51:01 Samuel.Thibault@ens-lyon.fr
> 
> I'm mostly suspicious of the latter, because it changes the
> behvaior of UDP sockets when MSG_TRUNC is specified.  Can

Well that change made it in 2.6.8.1 so if 2.6.8.1 is working for him
then that can't be it.  That change also seems to only change the
return value.

In fact, since tcpdump is showing bad checksums, then presumably
the packet has been corrupted before it even got to us.
-- 
Visit Openswan at http://www.openswan.org/
Email: Herbert Xu ~{PmV>HI~} <herbert@gondor.apana.org.au>
Home Page: http://gondor.apana.org.au/~herbert/
PGP Key: http://gondor.apana.org.au/~herbert/pubkey.txt

Re: [Bug 3610] New: kernel-2.6.9 breaks Amanda

[Stephen Hemminger]

On Thu, 21 Oct 2004 14:23:35 -0700
"David S. Miller" <davem@davemloft.net> wrote:

> On Thu, 21 Oct 2004 13:37:52 -0700
> Stephen Hemminger <shemminger@osdl.org> wrote:
> 
> >            Summary: kernel-2.6.9 breaks Amanda
> 
> Unfortunately, he failed to show the tcpdump traces of the UDP
> traffic as he did in his lkml postings.  There you will find
> checksum errors mentioned in the tcpdump output for the last
> few consequetive UDP packets and I think that is a good clue
> as to what may be the problem here.
> 
> I have to trust that the user did try, as Andrew Morton suggested,
> the 2.6.8.1 3c59x driver copied into the 2.6.9 kernel.  He said
> the problem persists.
> 
> He also states he disabled netfilter (although I would have liked
> him to also make sure that no netfilter modules were loaded as well).
> 
> That basically leaves us with ipv4/udp changes to look at.  There
> are two potentially problem causing changesets.  That would be:
> 
> ChangeSet 1.1832.88.1 2004/09/13 20:05:28 acme@conectiva.com.br
> 
> and
> 
> ChangeSet 1.1803.16.6 2004/07/21 13:51:01 Samuel.Thibault@ens-lyon.fr
> 
> I'm mostly suspicious of the latter, because it changes the
> behvaior of UDP sockets when MSG_TRUNC is specified.  Can
> someone check if Amanda uses MSG_TRUNC on UDP sockets?

No, not in current source.

> If the bug reporter had provided an strace of the Amanda userland
> components, we'd know this already.

Reading the current source code: 
	http://prdownloads.sourceforge.net/amanda/amanda-2.4.4p3.tar.gz?download

It does sendto() then close() in the udp_send path.
Also, it suffers from the select() and blocking rcvfrom() problem.

Re: [Bug 3610] New: kernel-2.6.9 breaks Amanda

[David S. Miller]

On Thu, 21 Oct 2004 15:10:15 -0700
Stephen Hemminger <shemminger@osdl.org> wrote:

> > If the bug reporter had provided an strace of the Amanda userland
> > components, we'd know this already.
> 
> Reading the current source code: 
> 	http://prdownloads.sourceforge.net/amanda/amanda-2.4.4p3.tar.gz?download
> 
> It does sendto() then close() in the udp_send path.
> Also, it suffers from the select() and blocking rcvfrom() problem.

Not to accuse the reporter or anything, but this may be a straw-man
rigged up bug report to try and force our hands in changing the behavior
of this case.

If so, that's quite rude, because kernels have behaved that way
forever, not just in 2.6.9.

Re: [Bug 3610] New: kernel-2.6.9 breaks Amanda

[Stephen Hemminger]

> >>Problem Description: Amanda clients exchanges UDP packets with the server giving
> >>it a TCP port number with which to connect in order to receive files to be
> >>dumped to tape. Under kernel-2.6.8.1 the sofware performs perfectly. Under
> >>kernel-2.6.9, with exactly the same Amanda software, the UDP packet exchange
> >>seems to occur, but no TCP connection between client and server occurs. The
> >>client eventually times out with messages like:
> >>    
> >>
> >
> >Could you capture a tcpdump of the exchange, especially the failed connection attempt?
> >  
> >
> Here are two traces, one on the Amanada server machine, one on the 
> client machine. Not very useful, as there is no sign that the server 
> even attempts to connect to the client with a TCP connection.

Is there a firewall that is blocking the connection for some reason.
Can you successfully make a TCP connection between the two machines with some other command?
ssh, telnet, ttcp

Perhaps this is another instance of an OpenBSD firewall stomping on window scaling.

Re: [Bug 3610] New: kernel-2.6.9 breaks Amanda

[Stephen Hemminger]

Try the following patch to amanda that resolves potential
issues with UDP and blocking receive.

--- amanda-2.4.4p3/common-src/dgram.c.orig	2004-10-26 09:51:27.000000000 -0700
+++ amanda-2.4.4p3/common-src/dgram.c	2004-10-26 10:01:56.622775784 -0700
@@ -248,9 +248,31 @@
     socklen_t addrlen;
     int nfound;
     int save_errno;
+    int flags;
 
     sock = dgram->socket;
 
+    /* Need to be in non-blocking mode before doing receive,
+     * because select on Linux will return true when there is
+     * a UDP message with checksum error, but receive will
+     * then hang.
+     */
+    flags = fcntl(sock, F_GETFL);
+    if (flags < 0) {
+	    save_errno = errno;
+	    dbprintf(("%s: dgram_recv: fcntl get flags failed %s\n",
+		      debug_prefix(NULL), strerror(save_errno)));
+	    return -1;
+    }		     
+
+    if(fcntl(sock, F_SETFL, flags|O_NONBLOCK) < 0) {
+	    save_errno = errno;
+	    dbprintf(("%s: dgram_recv: fcntl set flags failed %s\n",
+		      debug_prefix(NULL), strerror(save_errno)));
+	    return -1;
+    }		     
+
+ retry:
     FD_ZERO(&ready);
     FD_SET(sock, &ready);
     to.tv_sec = timeout;
@@ -284,6 +306,7 @@
 	    nfound = -1;
 	}
 	errno = save_errno;
+	fcntl(sock, F_SETFL, flags);
 	return nfound;
     }
 
@@ -291,13 +314,19 @@
     size = recvfrom(sock, dgram->data, MAX_DGRAM, 0,
 		    (struct sockaddr *)fromaddr, &addrlen);
     if(size == -1) {
+	if (errno == EINTR || errno == EAGAIN)
+		goto retry;
 	save_errno = errno;
 	dbprintf(("%s: dgram_recv: recvfrom() failed: %s\n",
 		  debug_prefix(NULL),
 		  strerror(save_errno)));
 	errno = save_errno;
+	fcntl(sock, F_SETFL, flags);
 	return -1;
     }
+
+    fcntl(sock, F_SETFL, flags);
+
     dgram->len = size;
     dgram->data[size] = '\0';
     dgram->cur = dgram->data;