Performance issues in cups 1.3

[angelb]

> > > Does anyone know if this performance issue been addressed in 1.3.6?
> >
> > We haven't added any additional tests WRT poll() since the issue
> > was limited to specific versions of HP-UX not honoring the poll()
> > timeout.
> >
> > > I'm testing 1.3.5 and running into the same problem with AIX and
> > > Solaris clients.
> >
> > It would be useful to find out where the performance bottleneck is.
> > Have you done any profiling to determine where cupsd is spending the
> > most time?
>
> Ok, I had a chance to run some statistics on one AIX 5.2 system.
>
> Running lpstat -p: (AIX 5.2)
>
> Here, cupsd is using 11.94% CPU which is spent most of its time in the
> kernel and shared libraries.
>
> Process                                Freq  Total Kernel   User Shared  Other
> =======                                ====  ===== ======   ==== ======  =====
> wait                                      2  73.95  73.95   0.00   0.00   0.00
> cupsd                                     1  11.94   6.32   0.88   4.74   0.00
> /usr/openv/netbackup/bin/bptm             1   4.63   4.55   0.00   0.08   0.00
> /opt/TWWfsw/bin/lpstat                    1   3.55   1.00   0.36   2.20   0.00
>
>
> Breakdown of CPU usage by PID:
>
> Process                   PID      TID  Total Kernel   User Shared  Other
> =======                   ===      ===  ===== ======   ==== ======  =====
> wait                    12294    12295  38.00  38.00   0.00   0.00   0.00
> wait                     8196     8197  35.95  35.95   0.00   0.00   0.00
> cupsd                  430266   999529  11.94   6.32   0.88   4.74   0.00
> v/netbackup/bin/bptm   626814   553213   4.63   4.55   0.00   0.08   0.00
>
>
> Shared Object                                                             %
> =============                                                          ======
> /usr/lib/libc.a[shr.o]                                                   5.26
> /opt/TWWfsw/cups135/lib/libcups.so                                       2.08
>
>
> Probably irrelevant(shown for completeness):
> Subroutine                                            %   Source
> ==========                                         ====== ======
> .waitproc_find_run_queue                            44.51 rnel/proc/dispatch.c
> .waitproc                                           20.04 rnel/proc/dispatch.c
>
>
> Subroutine                                            %   Source
> ==========                                         ====== ======
> ._doprnt                                             1.01 cs/lib/libc/doprnt.c
>
>
> I'm reinstalling CUPS on the other AIX system. Whenever I do an
> lpstat, cupsd dies(disappear) and no error is produced. Hopefully,
> with the reinstall, it clear things up a bit. I will also try to get
> statistics on the Solaris system.
>
> Thanks,
> Angel

Here's a profile from the other AIX 5.2 client:

Like the other AIX client, cupsd is taking much time in kernel and
share libraries.

Process                                Freq  Total Kernel   User Shared  Other
=======                                ====  ===== ======   ==== ======  =====
wait                                      2  82.45  82.45   0.00   0.00   0.00
cupsd                                     1  10.92   5.97   0.72   4.23   0.00
/opt/TWWfsw/bin/lpstat                    1   3.13   0.76   0.28   2.09   0.00


Process                   PID      TID  Total Kernel   User Shared  Other
=======                   ===      ===  ===== ======   ==== ======  =====
wait                    12294    12295  45.25  45.25   0.00   0.00   0.00
wait                     8196     8197  37.20  37.20   0.00   0.00   0.00
cupsd                 2093286  1679569  10.92   5.97   0.72   4.23   0.00
pt/TWWfsw/bin/lpstat   626692  2605281   3.13   0.76   0.28   2.09   0.00



Shared Object                                                             %
=============                                                          ======
/usr/lib/libc.a[shr.o]                                                   5.02
/opt/TWWfsw/cups135/lib/libcups.so                                       1.99




Summary(cups):

cupsd                                     1  10.92   5.97   0.72   4.23   0.00
cupsd                 2093286  1679569  10.92   5.97   0.72   4.23   0.00
/opt/TWWfsw/cups135/lib/libcups.so                                       1.99
  Profile: /opt/TWWfsw/cups135/lib/libcups.so
  Total % For All Processes (/opt/TWWfsw/cups135/lib/libcups.so) = 1.99
.cups_array_find                                     0.19 array.c
.cupsFilePrintf                                      0.15 file.c
.cupsGetDest                                         0.12 dest.c
.cupsAddDest at AF14_11                                 0.06 dest.c
.cups_write                                          0.06 file.c
.cupsFilePuts                                        0.06 file.c
.cupsArrayFind at AF28_17                               0.05 array.c
.cupsFileTell                                        0.04 file.c
.cupsFilePutChar at AF41_15                             0.04 file.c
.cupsFileFlush at AF33_26                               0.03 file.c
.cups_get_sdests                                     0.02 dest.c
.cupsArrayCurrent                                    0.01 array.c
._cupsStrFree                                        0.01 string.c
.cupsArrayCount                                      0.01 array.c
.cupsArrayNext at AF33_8                                0.01 array.c
.cups_array_add                                      0.01 array.c
.cupsFileFlush                                       0.01 file.c
.cupsFilePutChar                                     0.01 file.c

I'm working on the Solaris client; though, not sure really how to do
it yet. dtrace isn't the easiest tool to work with... :(


Thanks,
Angel