LIGO Support Ticket 17225

Ticket Information
  Number:      admin 17225
  User:        anderson@ligo.caltech.edu
  Email:       skoranda__AT__gravity.phys.uwm.edu
  Status:      new
  Assigned To: tannenba

Date: Fri, 16 Nov 2007 22:15:42 -0800
From: Stuart Anderson <anderson__AT__ligo.caltech.edu>
To: condor-admin__AT__cs.wisc.edu
CC: Scott Koranda <skoranda__AT__gravity.phys.uwm.edu>
Subject: LIGO: schedd log file management
X-Seen-BY: mailfromd 4.1 granite.cs.wisc.edu

While tuning the schedd performance on a 6.9.4 pool is was observed that
this daemon may be making an order of magnitude more system calls than
are necessary to output logging information. I do not have any performance
numbers on whether this is limiting current job throughput but it does seem
rather wasteful and require unecessary synchronization points within the
kernel that may limit performance when the underlying filesystem is busy.
In particular, in the following section of strace output that appears to
be repeated for every line of logfile output, it is not immediately obvious
why any of the system calls are needed except for the one call to write().


...
open("/usr1/condor/log/SchedLog", O_WRONLY|O_APPEND) = 14
fcntl(14, F_GETFL)                      = 0x8401 (flags O_WRONLY|O_APPEND|O_LARGEFILE)
fstat(14, {st_mode=S_IFREG|0644, st_size=102877778, ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x2b9e2daa4000
lseek(14, 0, SEEK_CUR)                  = 0
lseek(14, 0, SEEK_END)                  = 102877778
getpid()                                = 13302
write(14, "11/16 21:39:55 (pid:13302) Sent "..., 71) = 71
close(14)                               = 0
munmap(0x2b9e2daa4000, 4096)            = 0
umask(022)                              = 022
...


Put another way:

Why not just leave the log file open until the daemon is done writing to it?

Why keep checking to see if the PID of this daemon is changing?

Why keep setting umask() to the same value?

Why keep allocating and freeing up 4kByte of memory for every line of output
rather than reusing the memory?


More generally, do all the Condor daemons log the same way?

Thanks.


-- 
Stuart Anderson  anderson__AT__ligo.caltech.edu
http://www.ligo.caltech.edu/~anderson

===========================================================================
Date of creation: Sat Nov 17  0:15:58 2007 (1195280161)

Subject: Actions

Assigned to tannenba by roy
===========================================================================
Date of actions: Mon Nov 19 10:26:22 2007 (1195489583)