lzo2 shows insane speed gap

Artem Belevich fbsdlist at src.cx
Tue Dec 30 00:34:06 UTC 2008


I see this performance difference on my boxes.

First one has Core2Duo(E5-something), 4GB and  runs RELENG_7/i386.
lzotest is very fast.
Second box is Core2Quad (Q9450), 8GB RAM and runs -current as of about
a week ago. lzo2 binary built from ports is *slow*. However, 32-bit
binary from the first box runs very fast.

The only interesting difference I can see in ktrace is that read and
munmap take much much longer in case of 64-bit lzotest.

Here are two excerpts from ktrace on the second box:
### 32-bit app - runs fast on both boxes.

 59657 lzotest  0.000010 CALL  open(0xffffd91b,O_RDONLY,<unused>0x1b6)
 59657 lzotest  0.000007 NAMI  "./src/lzo1_d.ch"
 59657 lzotest  0.000012 RET   open 3
 59657 lzotest  0.000005 CALL  fstat(0x3,0xffffd504)
 59657 lzotest  0.000007 STRU  struct stat {dev=102, ino=544718,
mode=-rw-r--r-- , nlink=1, uid=0, gid=0, rdev=2169160,
atime=1230595144, stime=1209559909, ctime=1230588212,
birthtime=1209559909, size=4563, blksize=4096, blocks=12, flags=0x0 }
 59657 lzotest  0.000005 RET   fstat 0
 59657 lzotest  0.000006 CALL  lseek(0x3,0,SEEK_SET,0x1)
 59657 lzotest  0.000005 RET   lseek 0
 59657 lzotest  0.000005 CALL  lseek(0x3,0x4000000,SEEK_SET,0)
 59657 lzotest  0.000005 RET   lseek 67108864/0x4000000
 59657 lzotest  0.000006 CALL  lseek(0x3,0,SEEK_SET,0)
 59657 lzotest  0.000005 RET   lseek 0
 59657 lzotest  0.000005 CALL
mmap(0,0x4000000,PROT_READ|PROT_WRITE,MAP_PRIVATE|MAP_ANON,0xffffffff,0,0)
 59657 lzotest  0.000007 RET   mmap 673185792/0x28200000
 59657 lzotest  0.000006 CALL  read(0x3,0x28196000,0x1000)
 59657 lzotest  0.000010 GIO   fd 3 read 4096 bytes
 59657 lzotest  0.000029 RET   read 4096/0x1000
 59657 lzotest  0.000028 CALL  read(0x3,0x28196000,0x1000)
 59657 lzotest  0.000010 GIO   fd 3 read 467 bytes
 59657 lzotest  0.000005 RET   read 467/0x1d3
 59657 lzotest  0.000010 CALL  read(0x3,0x28196000,0x1000)
 59657 lzotest  0.000007 GIO   fd 3 read 0 bytes
 59657 lzotest  0.000006 RET   read 0
 59657 lzotest  0.000005 CALL  close(0x3)
 59657 lzotest  0.000010 RET   close 0
 59657 lzotest  0.000025 CALL  getrusage(0,0xffffd60c)
 59657 lzotest  0.000006 RET   getrusage 0
 59657 lzotest  0.000005 CALL  getrusage(0,0xffffd628)
 59657 lzotest  0.000006 RET   getrusage 0
 59657 lzotest  0.000005 CALL  getrusage(0,0xffffd60c)
 59657 lzotest  0.000006 RET   getrusage 0
 59657 lzotest  0.000064 CALL  getrusage(0,0xffffd60c)
 59657 lzotest  0.000006 RET   getrusage 0
 59657 lzotest  0.000005 CALL  getrusage(0,0xffffd60c)
 59657 lzotest  0.000006 RET   getrusage 0
 59657 lzotest  0.000029 CALL  getrusage(0,0xffffd60c)
 59657 lzotest  0.000006 RET   getrusage 0
 59657 lzotest  0.000012 CALL  getrusage(0,0xffffd60c)
 59657 lzotest  0.000036 RET   getrusage 0
 59657 lzotest  0.000010 CALL  write(0x1,0x28194000,0x4f)
 59657 lzotest  0.000010 GIO   fd 1 wrote 79 bytes
 59657 lzotest  0.000006 RET   write 79/0x4f
 59657 lzotest  0.000006 CALL  munmap(0x28200000,0x4000000)
 59657 lzotest  0.000017 RET   munmap 0

### same file. 64-bit app (slow). Look at read/munmap

 59158 lzotest  0.000015 CALL  open(0x7fffffffe760,O_RDONLY,<unused>0x1b6)
 59158 lzotest  0.000014 NAMI  "./src/lzo1_d.ch"
 59158 lzotest  0.000024 RET   open 3
 59158 lzotest  0.000011 CALL  fstat(0x3,0x7fffffffe2d0)
 59158 lzotest  0.000011 STRU  struct stat {dev=102, ino=544718,
mode=-rw-r--r-- , nlink=1, uid=0, gid=0, rdev=2169160,
atime=1230588427, stime=1209559909, ctime=1230588212,
birthtime=1209559909, size=4563, blksize=4096, blocks=12, flags=0x0 }
 59158 lzotest  0.000007 RET   fstat 0
 59158 lzotest  0.000015 CALL  lseek(0x3,0,SEEK_CUR)
 59158 lzotest  0.000007 RET   lseek 0
 59158 lzotest  0.000006 CALL  lseek(0x3,0x4000000,SEEK_SET)
 59158 lzotest  0.000007 RET   lseek 67108864/0x4000000
 59158 lzotest  0.000007 CALL  lseek(0x3,0,SEEK_SET)
 59158 lzotest  0.000006 RET   lseek 0
 59158 lzotest  0.000008 CALL
mmap(0,0x4000000,PROT_READ|PROT_WRITE,MAP_PRIVATE|MAP_ANON,0xffffffff,0)
 59158 lzotest  0.000010 RET   mmap 11534336/0x800b00000
 59158 lzotest  0.074126 CALL  read(0x3,0x800a9e000,0x1000)
 59158 lzotest  0.000054 GIO   fd 3 read 4096 bytes
 59158 lzotest  0.000010 RET   read 4096/0x1000
 59158 lzotest  0.000007 CALL  read(0x3,0x800a9e000,0x1000)
 59158 lzotest  0.000012 GIO   fd 3 read 467 bytes
 59158 lzotest  0.000006 RET   read 467/0x1d3
 59158 lzotest  0.000007 CALL  read(0x3,0x800a9e000,0x1000)
 59158 lzotest  0.000009 GIO   fd 3 read 0 bytes
 59158 lzotest  0.000006 RET   read 0
 59158 lzotest  0.000008 CALL  close(0x3)
 59158 lzotest  0.000020 RET   close 0
 59158 lzotest  0.000029 CALL  getrusage(0,0x7fffffffe3d0)
 59158 lzotest  0.000010 RET   getrusage 0
 59158 lzotest  0.000007 CALL  getrusage(0,0x7fffffffe3e0)
 59158 lzotest  0.000007 RET   getrusage 0
 59158 lzotest  0.000007 CALL  getrusage(0,0x7fffffffe3d0)
 59158 lzotest  0.000007 RET   getrusage 0
 59158 lzotest  0.000069 CALL  getrusage(0,0x7fffffffe3d0)
 59158 lzotest  0.000007 RET   getrusage 0
 59158 lzotest  0.000006 CALL  getrusage(0,0x7fffffffe3d0)
 59158 lzotest  0.000007 RET   getrusage 0
 59158 lzotest  0.000030 CALL  getrusage(0,0x7fffffffe3d0)
 59158 lzotest  0.000006 RET   getrusage 0
 59158 lzotest  0.000014 CALL  getrusage(0,0x7fffffffe3d0)
 59158 lzotest  0.000006 RET   getrusage 0
 59158 lzotest  0.000024 CALL  write(0x1,0x800a9c000,0x4f)
 59158 lzotest  0.000030 GIO   fd 1 wrote 79 bytes
 59158 lzotest  0.000008 RET   write 79/0x4f
 59158 lzotest  0.015677 CALL  munmap(0x800b00000,0x4000000)
 59158 lzotest  0.005430 RET   munmap 0

--Artem


More information about the freebsd-hackers mailing list