RT : Large transfert with 2.6.12rc5 + realtime-preempt-2.6.12-rc5-V0.7.47-15

RT : Large transfert with 2.6.12rc5 + realtime-preempt-2.6.12-rc5-V0.7.47-15

[Serge Noiraud]

I had the same problem with rc4+47-07, rc5+47-10,47-13
I reproduce this problem with a tg3 driver and with e1000 driver.
So I think it's not a driver problem.

I try to copy an iso image from this machine to another one by scp.
after 35 to 45MB, the copy become stalled with no more transfert.
We can ping the target machine, all apparently is OK except the scp
which finish with timeout.
With ftp, the stalled state is about 100MB.
If I reboot with a standard kernel ( without RT ), no problem.

Perhaps there is a progress, in 47-15, the size is now 135-140MB

On this machine, we have an ide disk.
I have setup : hdparm 
-sh-2.05b# hdparm /dev/hda

/dev/hda:
 multcount    = 16 (on)
 IO_support   =  3 (32-bit w/sync)
 unmaskirq    =  1 (on)
 using_dma    =  1 (on)
 keepsettings =  0 (off)
 readonly     =  0 (off)
 readahead    = 256 (on)
 geometry     = 65535/16/63, sectors = 78165360, start = 0

Re: RT : Large transfert with 2.6.12rc5 + realtime-preempt-2.6.12-rc5-V0.7.47-15

[K.R. Foley]

Serge Noiraud wrote:
> I had the same problem with rc4+47-07, rc5+47-10,47-13
> I reproduce this problem with a tg3 driver and with e1000 driver.
> So I think it's not a driver problem.
> 
> I try to copy an iso image from this machine to another one by scp.
> after 35 to 45MB, the copy become stalled with no more transfert.
> We can ping the target machine, all apparently is OK except the scp
> which finish with timeout.
> With ftp, the stalled state is about 100MB.
> If I reboot with a standard kernel ( without RT ), no problem.
> 
> Perhaps there is a progress, in 47-15, the size is now 135-140MB
> 
> On this machine, we have an ide disk.
> I have setup : hdparm 
> -sh-2.05b# hdparm /dev/hda
> 
> /dev/hda:
>  multcount    = 16 (on)
>  IO_support   =  3 (32-bit w/sync)
>  unmaskirq    =  1 (on)
>  using_dma    =  1 (on)
>  keepsettings =  0 (off)
>  readonly     =  0 (off)
>  readahead    = 256 (on)
>  geometry     = 65535/16/63, sectors = 78165360, start = 0
> 

Hi,

I am not sure what might be causing this problem for you. I just tried 
to reproduce this on one of my systems but could not (scsi not ide). The 
first time it copied 450MB before the remote system ran out of space. 
After cleaning up a bit I got the whole 630MB without a hitch. Do you 
have the RT patch on both systems or just on the originating system? In 
my case its the latter. There is

-- 
    kr

Re: RT : Large transfert with 2.6.12rc5 + realtime-preempt-2.6.12-rc5-V0.7.47-15

[Serge Noiraud]

Le mar 31/05/2005 à 18:18, K.R. Foley a écrit :
> Serge Noiraud wrote:
> > I had the same problem with rc4+47-07, rc5+47-10,47-13
> > I reproduce this problem with a tg3 driver and with e1000 driver.
> > So I think it's not a driver problem.
> > 
> > I try to copy an iso image from this machine to another one by scp.
> > after 35 to 45MB, the copy become stalled with no more transfert.
> > We can ping the target machine, all apparently is OK except the scp
> > which finish with timeout.
> > With ftp, the stalled state is about 100MB.
> > If I reboot with a standard kernel ( without RT ), no problem.
> > 
> > Perhaps there is a progress, in 47-15, the size is now 135-140MB
> > 
> > On this machine, we have an ide disk.
> > I have setup : hdparm 
> > -sh-2.05b# hdparm /dev/hda
> > 
> > /dev/hda:
> >  multcount    = 16 (on)
> >  IO_support   =  3 (32-bit w/sync)
> >  unmaskirq    =  1 (on)
> >  using_dma    =  1 (on)
> >  keepsettings =  0 (off)
> >  readonly     =  0 (off)
> >  readahead    = 256 (on)
> >  geometry     = 65535/16/63, sectors = 78165360, start = 0
> > 
> 
> Hi,
> 
> I am not sure what might be causing this problem for you. I just tried 
> to reproduce this on one of my systems but could not (scsi not ide). The 
> first time it copied 450MB before the remote system ran out of space. 
> After cleaning up a bit I got the whole 630MB without a hitch. Do you 
> have the RT patch on both systems or just on the originating system? In 
> my case its the latter. There is

The scp or ftp start on a RT machine.
The destination is an RT or Non RT machine, the problem is the same.
It's not a space problem, I have 4GB available on the destination path.
I can reproduce the phenomena at each try.
If I <CTRL C> the scp when it is stalled then relaunch the scp command, the transfert restart without problem.
I'm trying to trace this problem but I don't know how to do this.
Has someone one method ?

Re: RT : Large transfert with 2.6.12rc5 + realtime-preempt-2.6.12-rc5-V0.7.47-15

[K.R. Foley]

Serge Noiraud wrote:
> Le mar 31/05/2005 à 18:18, K.R. Foley a écrit :
> 
>>Serge Noiraud wrote:
>>
>>>I had the same problem with rc4+47-07, rc5+47-10,47-13
>>>I reproduce this problem with a tg3 driver and with e1000 driver.
>>>So I think it's not a driver problem.
>>>
>>>I try to copy an iso image from this machine to another one by scp.
>>>after 35 to 45MB, the copy become stalled with no more transfert.
>>>We can ping the target machine, all apparently is OK except the scp
>>>which finish with timeout.
>>>With ftp, the stalled state is about 100MB.
>>>If I reboot with a standard kernel ( without RT ), no problem.
>>>
>>>Perhaps there is a progress, in 47-15, the size is now 135-140MB
>>>
>>>On this machine, we have an ide disk.
>>>I have setup : hdparm 
>>>-sh-2.05b# hdparm /dev/hda
>>>
>>>/dev/hda:
>>> multcount    = 16 (on)
>>> IO_support   =  3 (32-bit w/sync)
>>> unmaskirq    =  1 (on)
>>> using_dma    =  1 (on)
>>> keepsettings =  0 (off)
>>> readonly     =  0 (off)
>>> readahead    = 256 (on)
>>> geometry     = 65535/16/63, sectors = 78165360, start = 0
>>>
>>
>>Hi,
>>
>>I am not sure what might be causing this problem for you. I just tried 
>>to reproduce this on one of my systems but could not (scsi not ide). The 
>>first time it copied 450MB before the remote system ran out of space. 
>>After cleaning up a bit I got the whole 630MB without a hitch. Do you 
>>have the RT patch on both systems or just on the originating system? In 
>>my case its the latter. There is
> 
> 
> The scp or ftp start on a RT machine.
> The destination is an RT or Non RT machine, the problem is the same.
> It's not a space problem, I have 4GB available on the destination path.
> I can reproduce the phenomena at each try.
> If I <CTRL C> the scp when it is stalled then relaunch the scp command, the transfert restart without problem.
> I'm trying to trace this problem but I don't know how to do this.
> Has someone one method ?
> 
> 

Do any of your logs provide any clues? Does this happen with just
2.6.12-rc5 and no rt-preempt patch? Does ifconfig provide any clues? How
about netstat -a? What is the state of the connection?

-- 
   kr

Re: RT : Large transfert with 2.6.12rc5+realtime-preempt-2.6.12-rc5-V0.7.47-15

[Serge Noiraud]

[-- Attachment #1: Type: text/plain, Size: 8063 bytes --]

Le mer 01/06/2005 à 13:10, K.R. Foley a écrit : 
> Serge Noiraud wrote:
> > Le mar 31/05/2005 à 18:18, K.R. Foley a écrit :
> > 
> >>Serge Noiraud wrote:
> >>
> >>>I had the same problem with rc4+47-07, rc5+47-10,47-13
> >>>I reproduce this problem with a tg3 driver and with e1000 driver.
> >>>So I think it's not a driver problem.
> >>>
> >>>I try to copy an iso image from this machine to another one by scp.
> >>>after 35 to 45MB, the copy become stalled with no more transfert.
> >>>We can ping the target machine, all apparently is OK except the scp
> >>>which finish with timeout.
> >>>With ftp, the stalled state is about 100MB.
> >>>If I reboot with a standard kernel ( without RT ), no problem.
> >>>
> >>>Perhaps there is a progress, in 47-15, the size is now 135-140MB
> >>>
> >>>On this machine, we have an ide disk.
> >>>I have setup : hdparm 
> >>>-sh-2.05b# hdparm /dev/hda
> >>>
> >>>/dev/hda:
> >>> multcount    = 16 (on)
> >>> IO_support   =  3 (32-bit w/sync)
> >>> unmaskirq    =  1 (on)
> >>> using_dma    =  1 (on)
> >>> keepsettings =  0 (off)
> >>> readonly     =  0 (off)
> >>> readahead    = 256 (on)
> >>> geometry     = 65535/16/63, sectors = 78165360, start = 0
> >>>
> >>
> >>Hi,
> >>
> >>I am not sure what might be causing this problem for you. I just tried 
> >>to reproduce this on one of my systems but could not (scsi not ide). The 
> >>first time it copied 450MB before the remote system ran out of space. 
> >>After cleaning up a bit I got the whole 630MB without a hitch. Do you 
> >>have the RT patch on both systems or just on the originating system? In 
> >>my case its the latter. There is
> > 
> > 
> > The scp or ftp start on a RT machine.
> > The destination is an RT or Non RT machine, the problem is the same.
> > It's not a space problem, I have 4GB available on the destination path.
> > I can reproduce the phenomena at each try.
> > If I <CTRL C> the scp when it is stalled then relaunch the scp command, the transfert restart without problem.
> > I'm trying to trace this problem but I don't know how to do this.
> > Has someone one method ?
> > 
> > 
> 
> Do any of your logs provide any clues? Does this happen with just
> 2.6.12-rc5 and no rt-preempt patch? Does ifconfig provide any clues? How
> about netstat -a? What is the state of the connection?

I have no problem with a 2.6.12rc5 with no RT patch.

With the RT pach :
When I get the problem, netstat -a seems ok.
The connection is established.

I progress in my tests.
runlevel = 1

cp of the iso file to another one in the same directory : no problem
I reboot in single then start only lo ( loopback )
cd /tmp
scp F1.iso localhost:/tmp/F2.iso : no problem

In runlevel > 1

dd if=/dev/zero bs=4k | ssh localhost:/dev/null
it is OK after 1 hour.

sh-2.05b# dd if=/dev/zero bs=8k | ssh 192.168.44.112 dd of=/dev/null
root@192.168.44.112's password: 
Read from remote host 192.168.44.112: Connection timed out
3565+0 records in
3564+0 records out
sh-2.05b#cat /proc/latency_trace
preemption latency trace v1.1.4 on 2.6.12-DAV06_dbg
--------------------------------------------------------------------
latency: 45 us, #64/64, CPU#0 | (M:rt VP:0, KP:1, SP:1 HP:1 #P:2)
    -----------------
    | task: ksoftirqd/0-3 (uid:0 nice:-10 policy:0 rt_prio:0)
    -----------------

                 _------=> CPU#
                / _-----=> irqs-off
               | / _----=> need-resched
               || / _---=> hardirq/softirq
               ||| / _--=> preempt-depth
               |||| /
               |||||     delay
   cmd     pid ||||| time  |   caller
      \   /    |||||   \   |   /
      dd-6389  0dn.2    2us : _raw_spin_lock (__up_mutex)
      dd-6389  0dn.3    2us : _raw_spin_lock (__up_mutex)
      dd-6389  0dn.4    3us : mutex_getprio (__up_mutex)
      dd-6389  0dn.4    4us : mutex_getprio <dd-6389> (73 73):
      dd-6389  0dn.4    4us : _raw_spin_unlock (__up_mutex)
      dd-6389  0dn.3    4us : preempt_schedule (__up_mutex)
      dd-6389  0dn.3    5us : _raw_spin_unlock (__up_mutex)
      dd-6389  0dn.2    5us : preempt_schedule (__up_mutex)
      dd-6389  0dn.2    5us : _raw_spin_unlock (__up_mutex)
      dd-6389  0dn.1    6us : preempt_schedule (__up_mutex)
      dd-6389  0dn.1    7us : smp_reschedule_interrupt (c0141a7a 0 0)
      dd-6389  0dn.1    8us < (608)
      dd-6389  0dnh1    9us : do_IRQ (c0141a7a 0 0)
      dd-6389  0d.h.   10us : _raw_spin_lock (__do_IRQ)
      dd-6389  0d.h1   11us : ack_lapic_irq (__do_IRQ)
      dd-6389  0d.h1   11us : redirect_hardirq (__do_IRQ)
      dd-6389  0d.h1   12us : _raw_spin_unlock (__do_IRQ)
      dd-6389  0d.h.   12us : handle_IRQ_event (__do_IRQ)
      dd-6389  0d.h.   12us : timer_interrupt (handle_IRQ_event)
      dd-6389  0d.h.   13us : _raw_spin_lock (timer_interrupt)
      dd-6389  0d.h1   13us : mark_offset_pmtmr (timer_interrupt)
      dd-6389  0d.h1   14us+: _raw_spin_lock (mark_offset_pmtmr)
      dd-6389  0d.h2   17us : _raw_spin_unlock (mark_offset_pmtmr)
      dd-6389  0d.h1   18us+: _raw_spin_lock_irqsave (timer_interrupt)
      dd-6389  0d.h2   20us : _raw_spin_unlock_irqrestore
(timer_interrupt)
      dd-6389  0d.h1   21us : do_timer (timer_interrupt)
      dd-6389  0d.h1   21us : _raw_spin_unlock (timer_interrupt)
      dd-6389  0d.h.   22us : _raw_spin_lock (__do_IRQ)
      dd-6389  0d.h1   22us : note_interrupt (__do_IRQ)
      dd-6389  0d.h1   23us : end_lapic_irq (__do_IRQ)
      dd-6389  0d.h1   23us : _raw_spin_unlock (__do_IRQ)
      dd-6389  0dnh1   23us : irq_exit (do_IRQ)
      dd-6389  0dn.2   24us : do_softirq (irq_exit)
      dd-6389  0d.s.   25us : __do_softirq (do_softirq)
      dd-6389  0d.s.   25us : wake_up_process (do_softirq)
      dd-6389  0d.s.   26us : try_to_wake_up (wake_up_process)
      dd-6389  0d.s.   26us : _raw_spin_lock (try_to_wake_up)
      dd-6389  0d.s1   27us : _raw_spin_unlock_irqrestore
(try_to_wake_up)
      dd-6389  0d.s.   27us : wake_up_process (do_softirq)
      dd-6389  0dn.1   28us < (608)
      dd-6389  0.n.1   29us : preempt_schedule (rt_up)
      dd-6389  0.n..   29us : preempt_schedule (pipe_writev)
      dd-6389  0dn..   29us : __schedule (preempt_schedule)
      dd-6389  0dn.1   30us : sched_clock (__schedule)
      dd-6389  0dn.1   31us : _raw_spin_lock_irq (__schedule)
      dd-6389  0dn.1   31us : _raw_spin_lock_irqsave (__schedule)
      dd-6389  0dn.2   32us : _raw_spin_unlock (__schedule)
      dd-6389  0dn.1   32us : preempt_schedule (__schedule)
      dd-6389  0dn.1   32us : _raw_spin_lock (__schedule)
      dd-6389  0dn.1   33us : preempt_schedule (_raw_spin_lock)
      dd-6389  0dn.2   34us : find_next_bit (__schedule)
      dd-6389  0d..2   36us+: trace_array (__schedule)
      dd-6389  0d..2   38us : trace_array <<...>-3> (69 6e):
      dd-6389  0d..2   38us : trace_array <dd-6389> (73 78):
      dd-6389  0d..2   39us+: trace_array (__schedule)
   <...>-3     0d..2   42us : __switch_to (__schedule)
   <...>-3     0d..2   42us : __schedule <dd-6389> (73 69):
   <...>-3     0d..2   43us : _raw_spin_unlock (__schedule)
   <...>-3     0d..1   43us : trace_stop_sched_switched (__schedule)
   <...>-3     0d..1   43us : trace_stop_sched_switched <<...>-3> (69
0):
   <...>-3     0d..1   44us : _raw_spin_lock_irqsave
(trace_stop_sched_switched)
   <...>-3     0d..1   45us : trace_stop_sched_switched (__schedule)


vim:ft=help

... Week end ...

I progress in my test. I have the same problem with rc5+47-18

I reproduce the problem on only one machine with one ide disk:

dd if=/dev/zero b=4k | ssh 192.168.44.112 dd of=/dev/null

In all cases, this command duration in 18 minutes even when I launch it
several times.

It works fine with localhost.
The target machine can be everything.
I'm trying to test with rc6+47-25

all my infos are in the script command results dd-test.bz2
which include the dd command, lspci -vv, dmesg, config, mii-tool,
ifconfig


[-- Attachment #2: dd-test.bz2 --]
[-- Type: application/x-bzip, Size: 22631 bytes --]