Linux 2.6.9 latencies: 253ms in ip_tables.c:copy_entries_to_user(), 200ms in reiserfs/bitmap.c:scan_bitmap_block(), 4ms in i2c-algo-bit.c:bit_xfer()
From: Sami Farin
Date: Sun Oct 24 2004 - 16:27:11 EST
there's a script which does
grep -Fh "^[0-9]" $BLOCKLISTS | aggregate | \
while read blocked; do
iptables -A DROP_evil_in -s $blocked -j LDROPEVILIN
iptables -A DROP_evil_out -d $blocked -j LDROPEVILOUT
done
while that's running, "rtc_latencytest 1024" has max latencies of 253ms.
$BLOCKLIST has around two thousand lines.
http://safari.iki.fi/ip_tables_original_maxlat_253ms.png
from pressing sysrq+p while it was running, I guesstimated one evil spot
and added cond_resched() in there :)
http://safari.iki.fi/ip_tables_cond_resched.png
at 5s I started the script.
then there's this 200ms latency when doing "cp /dev/zero ." on reiserfs.
http://safari.iki.fi/2.6.9-no_reiserfs_cond_resched.png
sysrq+p pointed to scan_bitmap_block ... :) (I also used profile=2)
after adding cond_resched in there, max latency 2.4ms
http://safari.iki.fi/2.6.9-with_reiserfs_cond_resched.png
"cp /dev/zero ." consumes 90% CPU time in system...
reading the same file from disk needs 8% CPU.
is my partition just so fragmented or full?
EIP is at reiserfs_in_journal+0x82/0x168
EFLAGS: 00000206 Not tainted (2.6.9-exec-shield)
EAX: 00008000 EBX: 00408000 ECX: 000011b3 EDX: cf202e00
ESI: 00000005 EDI: 0000011c EBP: c73a7c2c DS: 007b ES: 007b
CR0: 8005003b CR2: b7fda000 CR3: 091cb000 CR4: 000002d0
[<c010425d>] show_regs+0x115/0x120
[<c02768b8>] sysrq_handle_showregs+0x10/0x14
[<c0276a3b>] __handle_sysrq+0x5f/0xe8
[<c0276ae1>] handle_sysrq+0x1d/0x21
[<c02709ee>] kbd_keycode+0x12e/0x2d8
[<c0270c1c>] kbd_event+0x84/0xbc
[<c02d883c>] input_event+0x3ac/0x3d0
[<c02db9da>] atkbd_report_key+0x3a/0x5c
[<c02dbf3b>] atkbd_interrupt+0x53f/0x5b8
[<c0282fb0>] serio_interrupt+0x30/0x65
[<c028357b>] i8042_interrupt+0x14b/0x15c
[<c0108230>] handle_IRQ_event+0x28/0x5c
[<c010852e>] do_IRQ+0xa2/0x114
[<c010679c>] common_interrupt+0x18/0x20
[<c01816c8>] scan_bitmap_block+0xb8/0x28c
[<c0181ac0>] scan_bitmap+0x15c/0x1ac
[<c0182ce5>] reiserfs_allocate_blocknrs+0x415/0x4f8
[<c018cf17>] reiserfs_allocate_blocks_for_region+0x187/0x1314
[<c018f356>] reiserfs_file_write+0x482/0x630
[<c014e659>] vfs_write+0xb5/0xec
[<c014e734>] sys_write+0x3c/0x68
[<c0105e2f>] syscall_call+0x7/0xb
also, there's 4ms latency every five seconds, when I am running xawtv
in stereo mode. I have BT878 and MSP3400.
http://safari.iki.fi/3.7ms-with-xawtv.png
http://safari.iki.fi/1.6ms-without-xawtv.png
turned out the culprit is msp3400 -- it checks every five secs
audio state (stereo/mono/...) which calls i2c_master_send.
http://safari.iki.fi/i2c-msp3400-cond_resched.png
http://safari.iki.fi/i2c-msp3400-cond_resched-switching_channels.png
WARNING: I don't know are those cond_rescheds safe to call,
but I haven't gotten panics because of them yet.
Someone who actually has a clue might want to tell are they safe
or where would be a better place to do cond_resched.
...uhhh, and I have low-end Celeron system running UP non-preempt kernel.
--- linux/net/ipv4/netfilter/ip_tables.c.bak 2004-10-19 23:40:28.000000000 +0300
+++ linux/net/ipv4/netfilter/ip_tables.c 2004-10-24 19:15:54.000000000 +0300
@@ -976,6 +976,7 @@ copy_entries_to_user(unsigned int total_
struct ipt_entry_match *m;
struct ipt_entry_target *t;
+ cond_resched();
e = (struct ipt_entry *)(table->private->entries + off);
if (copy_to_user(userptr + off
+ offsetof(struct ipt_entry, counters),
--- linux/fs/reiserfs/bitmap.c.condresched 2004-08-14 08:37:25.000000000 +0300
+++ linux/fs/reiserfs/bitmap.c 2004-10-20 18:12:31.000000000 +0300
@@ -155,6 +155,7 @@ static int scan_bitmap_block (struct rei
while (1) {
cont:
+ cond_resched();
if (bi->free_count < min)
return 0; // No free blocks in this bitmap
--- linux/drivers/i2c/algos/i2c-algo-bit.c.bak 2004-10-19 23:38:52.000000000 +0300
+++ linux/drivers/i2c/algos/i2c-algo-bit.c 2004-10-24 23:29:12.000000000 +0300
@@ -153,6 +153,7 @@ static int i2c_outb(struct i2c_adapter *
int ack;
struct i2c_algo_bit_data *adap = i2c_adap->algo_data;
+ cond_resched();
/* assert: scl is low */
for ( i=7 ; i>=0 ; i-- ) {
sb = c & ( 1 << i );
@@ -195,6 +196,7 @@ static int i2c_inb(struct i2c_adapter *i
unsigned char indata=0;
struct i2c_algo_bit_data *adap = i2c_adap->algo_data;
+ cond_resched();
/* assert: scl is low */
sdahi(adap);
for (i=0;i<8;i++) {
--
-
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/