Slow write with EADDR

[Trevor Blackwell]

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 at tlb.org    http://tlb.org   650 776 7870