printing problem on 2.2.8a and 3.0alpha24
Joe Meslovich
joe at bridgewater.edu
Fri May 23 19:28:57 GMT 2003
I have looked into the high CPU usage problem that I have been having on
Solaris 2.6 running either 2.2.8a or 3.0. I'm not sure if I understand
exactly how it works yet, so if I'm wrong please set me on the right track
;). Anyway the high cpu usage seems to be tied to locking the specific
printer tdb after spawning the external lpq command. I see the process
open the tbd database for a specific queue. Then it spawns the child that
runs lpq. The child returns, and then the parent spins on a fcntl(29,
F_SETLKW64, 0xEFFFE6B8) command. After spinning on the lock I see time()
get called again three seconds after the last time() and it does a munmap
of the filedes for that queue and moves on to the next one. It does the
same thing for each queue it seems. I have something like 50 queues which
means it takes on the order of 150 seconds to stat all the queues. Below
is an excert of my truss of an affected process. Part of my problem is I
don't fully understand what is supposed to happen to the tdb after the
tmp file containing the lpq result is released.
Joe Meslovich
___________________________________________________
13279: open64("/usr/local/samba/var/locks/printing/adm2hp4.tdb",
O_RDWR|O_CREAT
, 0600) = 29
13279: fcntl(29, F_SETLKW64, 0xEFFFE6C0) = 0
13279: fcntl(29, F_SETLK64, 0xEFFFE6C0) = 0
13279: read(29, " T D B f i l e\n\0\0\0".., 168) = 168
13279: fstat64(29, 0xEFFFE768) = 0
13279: mmap64(0x00000000, 24576, PROT_READ|PROT_WRITE, MAP_SHARED, 29, 0)
= 0xE
F490000
13279: llseek(29, 40, SEEK_SET) = 40
13279: write(29, "\0\0\0\0", 4) = 4
13279: fcntl(29, F_SETLK64, 0xEFFFE6C0) = 0
13279: fcntl(29, F_SETLKW64, 0xEFFFE6C0) = 0
13279: fcntl(29, F_SETLKW64, 0xEFFFE6C0) = 0
13279: getuid() = 0 [0]
13279: getgid() = 0 [0]
13279: setgroups(2, 0x002E9BA8) = 0
13279: setregid(-1, 14) = 0
13279: getgid() = 0 [14]
13279: setreuid(-1, 1045) = 0
13279: getuid() = 0 [1045]
13279: fcntl(29, F_SETLKW64, 0xEFFFEA38) = 0
13279: fcntl(29, F_SETLKW64, 0xEFFFEAB0) = 0
13279: fcntl(29, F_SETLKW64, 0xEFFFE540) = 0
13279: fcntl(29, F_SETLKW64, 0xEFFFE540) = 0
13279: sigaction(SIGALRM, 0xEFFFE6C0, 0xEFFFE740) = 0
13279: alarm(10) = 0
13279: fcntl(29, F_SETLKW64, 0xEFFFE670) = 0
13279: alarm(0) = 10
13279: sigaction(SIGALRM, 0xEFFFE6C0, 0xEFFFE740) = 0
13279: fcntl(29, F_SETLKW64, 0xEFFFE540) = 0
13279: fcntl(29, F_SETLKW64, 0xEFFFE540) = 0
13279: fcntl(29, F_SETLKW64, 0xEFFFE5A0) = 0
13279: fcntl(29, F_SETLKW64, 0xEFFFE510) = 0
13279: fcntl(29, F_SETLKW64, 0xEFFFE510) = 0
13279: fcntl(29, F_SETLKW64, 0xEFFFE5A0) = 0
13279: fcntl(29, F_SETLKW64, 0xEFFFE6F0) = 0
13279: time() = 1053714407
13279: fcntl(29, F_SETLKW64, 0xEFFFE638) = 0
13279: fcntl(29, F_SETLKW64, 0xEFFFE638) = 0
13279: door_info(3, 0xEFFFDC20) = 0
13279: door_call(3, 0xEFFFDC08) = 0
13279: getpid() = 13279 [19034]
13279: lstat64("/tmp/smb.nia47z", 0xEFFFDC38) Err#2 ENOENT
13279: open64("/tmp/smb.nia47z", O_RDWR|O_CREAT|O_EXCL, 0600) = 30
13279: unlink("/tmp/smb.nia47z") = 0
13279: sigaction(SIGCLD, 0xEFFFE0F0, 0xEFFFE170) = 0
13279: fork() = 13440
.
.
.
child spawns lpq
.
.
.
13279: Received signal #18, SIGCLD, in waitid() [caught]
13279: siginfo: SIGCLD CLD_EXITED pid=13440 status=0x0000
13279: waitid(P_PID, 13440, 0xEFFFE140, WEXITED|WTRAPPED) Err#91 ERESTART
13279: setcontext(0xEFFFDE28)
13279: waitid(P_PID, 13440, 0xEFFFE140, WEXITED|WTRAPPED) = 0
13279: sigaction(SIGCLD, 0xEFFFE0F0, 0xEFFFE170) = 0
13279: llseek(30, 0, SEEK_SET) = 0
13279: fstat64(30, 0xEFFFE5F8) = 0
13279: read(30, " n o e n t r i e s\n", 11) = 11
13279: close(30) = 0
13279: fcntl(29, F_SETLKW64, 0xEFFFE648) = 0
13279: fcntl(29, F_SETLKW64, 0xEFFFE648) = 0
13279: time() = 1053714408
13279: fcntl(29, F_SETLKW64, 0xEFFFE6B8) = 0 /* this is
line 998 of truss */
13279: fcntl(29, F_SETLKW64, 0xEFFFE6B8) = 0
13279: fcntl(29, F_SETLKW64, 0xEFFFE6B8) = 0
13279: fcntl(29, F_SETLKW64, 0xEFFFE6B8) = 0
13279: fcntl(29, F_SETLKW64, 0xEFFFE6B8) = 0
13279: fcntl(29, F_SETLKW64, 0xEFFFE6B8) = 0
.
.
.
13279: fcntl(29, F_SETLKW64, 0xEFFFE728) = 0 /* at line
3704 */
13279: fcntl(29, F_SETLKW64, 0xEFFFE6B8) = 0
.
.
.
13279: fcntl(29, F_SETLKW64, 0xEFFFE6B8) = 0
13279: fcntl(29, F_SETLKW64, 0xEFFFE728) = 0 /* at line
3994 */
13279: fcntl(29, F_SETLKW64, 0xEFFFE6B8) = 0
.
.
.
13279: fcntl(29, F_SETLKW64, 0xEFFFE6B8) = 0
13279: fcntl(29, F_SETLKW64, 0xEFFFE728) = 0 /* at line
6072 */
.
. and this continues till line 1121
.
13279: fcntl(29, F_SETLKW64, 0xEFFFE6B8) = 0
13279: fcntl(29, F_SETLKW64, 0xEFFFE698) = 0
13279: fcntl(29, F_SETLKW64, 0xEFFFE698) = 0
13279: fcntl(29, F_SETLKW64, 0xEFFFE638) = 0
13279: fcntl(29, F_SETLKW64, 0xEFFFE638) = 0
13279: fcntl(29, F_SETLKW64, 0xEFFFE548) = 0
13279: fcntl(29, F_SETLKW64, 0xEFFFE5C0) = 0
13279: fcntl(29, F_SETLKW64, 0xEFFFE450) = 0
13279: fcntl(29, F_SETLKW64, 0xEFFFE4C8) = 0
13279: fcntl(29, F_SETLKW64, 0xEFFFE740) = 0
13279: fcntl(29, F_SETLKW64, 0xEFFFE740) = 0
13279: time() = 1053714411
13279: fcntl(29, F_SETLKW64, 0xEFFFE638) = 0
13279: fcntl(29, F_SETLKW64, 0xEFFFE638) = 0
13279: fcntl(29, F_SETLKW64, 0xEFFFE538) = 0
13279: fcntl(29, F_SETLK64, 0xEFFFE520) = 0
13279: fcntl(29, F_SETLK64, 0xEFFFE520) = 0
13279: fcntl(29, F_SETLKW64, 0xEFFFE490) = 0
13279: fcntl(29, F_SETLKW64, 0xEFFFE490) = 0
13279: fcntl(29, F_SETLKW64, 0xEFFFE5B0) = 0
13279: fcntl(29, F_SETLKW64, 0xEFFFEB18) = 0
13279: fcntl(29, F_SETLKW64, 0xEFFFEB90) = 0
13279: fcntl(29, F_SETLKW64, 0xEFFFEA20) = 0
13279: fcntl(29, F_SETLKW64, 0xEFFFEA98) = 0
13279: time() = 1053714411
13279: fcntl(29, F_SETLKW64, 0xEFFFE930) = 0
13279: fcntl(29, F_SETLKW64, 0xEFFFE9A8) = 0
13279: fcntl(29, F_SETLKW64, 0xEFFFEA10) = 0
13279: fcntl(29, F_SETLKW64, 0xEFFFEA88) = 0
13279: fcntl(29, F_SETLKW64, 0xEFFFE918) = 0
13279: fcntl(29, F_SETLKW64, 0xEFFFE990) = 0
13279: fcntl(9, F_SETLKW64, 0xEFFFD9F0) = 0
13279: fcntl(9, F_SETLKW64, 0xEFFFD9F0) = 0
13279: time() = 1053714411
13279: fcntl(9, F_SETLKW64, 0xEFFFC7C0) = 0
13279: fcntl(9, F_SETLKW64, 0xEFFFC838) = 0
13279: time() = 1053714411
13279: munmap(0xEF490000, 24576) = 0
13279: close(29) = 0
----------------------------------------------------------------------------
Joe Meslovich joe at bridgewater.edu
Associate Network/Systems Engineer IT Center
Tel: (540) 828 - 5343
More information about the samba-technical
mailing list