Date: Fri, 6 Apr 2007 19:45:10 -0700 From: Trevor Blackwell <tlb@tlb.org> To: freebsd-questions@freebsd.org Subject: Slow write with EADDR Message-ID: <427A755F-972B-4CBF-94DD-B99E5CFFAEC2@tlb.org>
next in thread | raw e-mail | index | archive | help
Doing a write with a NULL pointer takes surprisingly long to return
with an EADDR error. A short write to a file typically takes 4 uS,
but a write with a NULL pointer seems to take 1000 - 2000 uS. This is
on a 3 GHz dual Xeon running 5.4-RELEASE-p12. I don't get the same
behavior on 6.2-PRERELEASE. I wonder what it could be doing all that
time?
Here's a ktrace showing it:
4126 t_slow_write 1175913192.425918 CALL open(0x804873d,0x201,0x1ff)
4126 t_slow_write 1175913192.425934 NAMI "t_slow_write.out"
4126 t_slow_write 1175913192.425950 RET open 3
4126 t_slow_write 1175913192.425963 CALL write(0x3,0xbfbfea9c,0x100)
4126 t_slow_write 1175913192.425988 GIO fd 3 wrote 256 bytes
"\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"
4126 t_slow_write 1175913192.425993 RET write 256/0x100
4126 t_slow_write 1175913192.425998 CALL write(0x3,0,0x100)
4126 t_slow_write 1175913192.427442 RET write -1 errno 14 Bad
address
4126 t_slow_write 1175913192.427503 CALL write(0x3,0xbfbfea9c,0x100)
4126 t_slow_write 1175913192.427518 GIO fd 3 wrote 256 bytes
"\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"
4126 t_slow_write 1175913192.427520 RET write 256/0x100
4126 t_slow_write 1175913192.427526 CALL write(0x3,0,0x100)
4126 t_slow_write 1175913192.429024 RET write -1 errno 14 Bad
address
4126 t_slow_write 1175913192.429042 CALL write(0x3,0xbfbfea9c,0x100)
4126 t_slow_write 1175913192.429068 GIO fd 3 wrote 256 bytes
"\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"
4126 t_slow_write 1175913192.429070 RET write 256/0x100
4126 t_slow_write 1175913192.429076 CALL write(0x3,0,0x100)
4126 t_slow_write 1175913192.430560 RET write -1 errno 14 Bad
address
4126 t_slow_write 1175913192.430571 CALL write(0x3,0xbfbfea9c,0x100)
4126 t_slow_write 1175913192.430586 GIO fd 3 wrote 256 bytes
"\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"
4126 t_slow_write 1175913192.430588 RET write 256/0x100
4126 t_slow_write 1175913192.430593 CALL write(0x3,0,0x100)
4126 t_slow_write 1175913192.432443 RET write -1 errno 14 Bad
address
4126 t_slow_write 1175913192.432453 CALL write(0x3,0xbfbfea9c,0x100)
4126 t_slow_write 1175913192.432468 GIO fd 3 wrote 256 bytes
"\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"
4126 t_slow_write 1175913192.432470 RET write 256/0x100
4126 t_slow_write 1175913192.432475 CALL write(0x3,0,0x100)
4126 t_slow_write 1175913192.433958 RET write -1 errno 14 Bad
address
4126 t_slow_write 1175913192.433977 CALL close(0x3)
4126 t_slow_write 1175913192.433998 RET close 0
4126 t_slow_write 1175913192.434047 CALL exit(0)
Here's the little program to demo it:
------
#include <stdlib.h>
#include <stdio.h>
#include <unistd.h>
#include <fcntl.h>
#include <string.h>
int main()
{
int fd,i;
char buf[256];
fd=open("t_slow_write.out", O_WRONLY|O_CREAT, 0777);
memset(buf, 0, sizeof(buf));
for (i=0; i<5; i++) {
write(fd, buf, 256);
write(fd, NULL, 256);
}
close(fd);
}
------
Compile with gcc -o t_slow_write t_slow_write.c
--
Trevor Blackwell tlb@tlb.org http://tlb.org 650 776 7870
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?427A755F-972B-4CBF-94DD-B99E5CFFAEC2>