Re: High CPU utilization even with DMA enabled?

From: Andre Guibert de Bruet <andy_at_siliconlandmark.com>
Date: Wed, 7 May 2003 23:35:32 -0400 (EDT)
On Wed, 7 May 2003, Dan Nelson wrote:

> In the last episode (May 07), Andre Guibert de Bruet said:
> > Here's the output of top while moving a large file from one disk to
> > another on my otherwise idle desktop machine:
> >
> >   PID USERNAME    PRI NICE   SIZE    RES STATE  C   TIME   WCPU    CPU COMMAND
> >    26 root        -68 -187     0K    12K WAIT   0 141:36 79.98% 79.98% irq7: dc0 ohci0
>
> Is this line truncated?  If not, your CPU load is caused by either
> your network card or your USB interface, not your file copy.

Other than dnetc, this machine sits idle and rarely sees any network
traffic. I see this type of cpu usage even when I unplug the mouse and
unjack the cat5 from the machine. The load spike starts when the copy
starts, and stops right when it's interrupted or completes.

That line didn't get truncated. "ps -auxwww |grep irq" shows:

root     26 87.5  0.0     0   12  ??  WL   Tue10PM 188:30.50  (irq7: dc0 ohci0)
root     29  2.0  0.0     0   12  ??  WL   Tue10PM   3:58.05  (irq11: atapci1)
root     23  0.0  0.0     0   12  ??  WL   Tue10PM   0:00.00  (irq14: ata0)
root     24  0.7  0.0     0   12  ??  WL   Tue10PM   0:39.43  (irq15: ata1)
root     25  0.0  0.0     0   12  ??  WL   Tue10PM   0:00.00  (irq10: nge0 pcm0)
root     33  0.0  0.0     0   12  ??  WL   Tue10PM   0:03.44  (irq1: atkbd0)

I have WITNESS, INVARIANTS and DDB compiled in and a serial console on
this machine, is there any output that I can supply from there that could
help?

> >    24 root        -64 -183     0K    12K WAIT   0   0:27  1.22%  1.22% irq15: ata1
>
> > Now, I realize that copying a file from one disk to another requires cpu
> > cycles even with DMA enabled, but is 80% of cpu usage to be expected?
> > Also, wouldn't one expect process id 24 (irq15: ata1) to be using CPU
> > during such transfers?
>
> It is; I'd even call 1.22% cpu load a bit high, although I have no IDE
> systems to compare it against.  All it's doing is DMA'ing data.

That's what I thought. The output of ps above shows that ata1 has been
taking a good chunk of cpu. That doesn't account for process 26's massive
cpu consumption though.

dmesg shows the following ata, dc0 and usb related messages:
atapci0: <AMD 768 UDMA100 controller> port 0xb800-0xb80f at device 7.1 on pci0
ata0: at 0x1f0 irq 14 on atapci0
ata1: at 0x170 irq 15 on atapci0
atapci1: <Promise PDC20269 UDMA133 controller> port 0x8800-0x880f,0x9000-0x9003,0x9400-0x9407,0x9800-0x9803,0xa000-0xa007 mem 0xe6800000-0xe6803fff irq 11 at device 6.0 on pci2
ata2: at 0xa000 on atapci1
ata3: at 0x9400 on atapci1
ad2: 238475MB <WDC WD2500JB-34EVA0> [484521/16/63] at ata1-master UDMA100
ad4: 194481MB <Maxtor 6Y200P0> [395136/16/63] at ata2-master UDMA133
ad6: 194481MB <Maxtor 6Y200P0> [395136/16/63] at ata3-master UDMA133
dc0: <ADMtek AN985 10/100BaseTX> port 0x8400-0x84ff mem 0xe6000000-0xe60003ff at device 8.0 on pci2
dc0: Ethernet address: 00:04:5a:8a:1a:08
miibus1: <MII bus> on dc0
ohci0: <OHCI (generic) USB controller> mem 0xe7000000-0xe7000fff irq 7 at device 0.0 on pci2
usb0: OHCI version 1.0, legacy support
usb0: <OHCI (generic) USB controller> on ohci0
uhub0: AMD OHCI root hub, class 9/0, rev 1.00/1.00, addr 1

pciconf -l shows:
agp0_at_pci0:0:0:  class=0x060000 card=0x00000000 chip=0x700c1022 rev=0x11 hdr=0x00
pcib1_at_pci0:1:0: class=0x060400 card=0x00000000 chip=0x700d1022 rev=0x00 hdr=0x01
isab0_at_pci0:7:0: class=0x060100 card=0x80441043 chip=0x74401022 rev=0x05 hdr=0x00
atapci0_at_pci0:7:1:       class=0x01018a card=0x74411022 chip=0x74411022 rev=0x04 hdr=0x00
none0_at_pci0:7:3: class=0x068000 card=0x80441043 chip=0x74431022 rev=0x03 hdr=0x00
nge0_at_pci0:9:0:  class=0x020000 card=0x10641737 chip=0x0022100b rev=0x00 hdr=0x00
pcib2_at_pci0:16:0:        class=0x060400 card=0x00000000 chip=0x74481022 rev=0x05 hdr=0x01
none1_at_pci1:5:0: class=0x030000 card=0x003a121a chip=0x0005121a rev=0x01 hdr=0x00
ohci0_at_pci2:0:0: class=0x0c0310 card=0x80441043 chip=0x74491022 rev=0x07 hdr=0x00
pcm0_at_pci2:5:0:  class=0x040100 card=0x80271102 chip=0x00021102 rev=0x08 hdr=0x00
emujoy0_at_pci2:5:1:       class=0x098000 card=0x00201102 chip=0x70021102 rev=0x08 hdr=0x00
atapci1_at_pci2:6:0:       class=0x018085 card=0x4d68105a chip=0x4d69105a rev=0x02 hdr=0x00
dc0_at_pci2:8:0:   class=0x020000 card=0x05741317 chip=0x09851317 rev=0x11 hdr=0x00

Thanks for your help and time.

> Andre Guibert de Bruet | Enterprise Software Consultant >
> Silicon Landmark, LLC. | http://siliconlandmark.com/    >
Received on Wed May 07 2003 - 18:35:45 UTC

This archive was generated by hypermail 2.4.0 : Wed May 19 2021 - 11:37:06 UTC