CUPS 1.3.6 - performance issue in AIX

[angelb]

Hello all.

I got a chance to install and started testing CUPS 1.3.6:

First, here's my observation in 1.3.5:
1. When the client is set to "LogLevel debug2", it would take a very
   long time(>15min) for an lpstat to list 2700 printer queues or for
   an lpr(>9min) to print.

2. When the client is set to "LogLevel info", running an "lpstat -p",
   the cupsd daemon would die leaving no trace. The error_log file
   have no entry for it(possibly because it's in "info").

3. When the client is set to whatever LogLevel, AND, the remote.cache
   already exist, response time from lpstat(~5sec) to list all 2700
   printer queues or lpr(~3sec) to print.

Now, with CUPS 1.3.6, the problem I saw in 1.3.5 are still there.

I've installed CUPS 1.3.6 in two seperate AIX systems both of which
were used to install and test CUPS since 1.1. And CUPS 1.3.6 behaves
exactly the same in both systems.

Following are some profiling:

CUPS136:

clientA: LogLevel=info, no remote.cache
Process                                Freq  Total Kernel   User Shared  Other
=======                                ====  ===== ======   ==== ======  =====
wait                                      2  53.30  53.30   0.00   0.00   0.00
cupsd                                     1  44.07   5.30  10.53  28.24   0.00
...

  Profile: /opt/TWWfsw/cups136/lib/libcups.so

  Total % For All Processes (/opt/TWWfsw/cups136/lib/libcups.so) = 18.56

Subroutine                                            %   Source
==========                                         ====== ======
.strcmp                                              4.82 strcmp.s
.cupsArrayFind at AF28_17                               3.69 array.c
.cups_array_find                                     3.35 array.c
.ippAddStrings at AF51_25                               2.46 ipp.c
._ippAddAttr at AF39_6                                  1.23 ipp.c
._cupsStrAlloc                                       1.03 string.c
.compare_sp_items                                    0.58 string.c
.$PTRGL                                              0.55 ptrgl.s


clientB: LogLevel=info, no remote.cache
Process                                Freq  Total Kernel   User Shared  Other
=======                                ====  ===== ======   ==== ======  =====
wait                                      2  55.21  55.21   0.00   0.00   0.00
cupsd                                     1  43.57   5.53  10.68  27.37   0.00

...
  Profile: /opt/TWWfsw/cups136/lib/libcups.so

  Total % For All Processes (/opt/TWWfsw/cups136/lib/libcups.so) = 18.41

Subroutine                                            %   Source
==========                                         ====== ======
.strcmp                                              4.78 strcmp.s
.cups_array_find                                     3.76 array.c
.cupsArrayFind at AF28_17                               3.66 array.c
.ippAddStrings at AF51_25                               2.10 ipp.c
._cupsStrAlloc                                       1.09 string.c
.$PTRGL                                              0.81 ptrgl.s
._ippAddAttr at AF39_6                                  0.81 ipp.c



Now, with remote.cache exist, performance improved dramatically. I
can't say for sure how the remote.cache file influence response time
but it does.

clientA: LogLevel=info, with remote.cache

ROOT @ SAPTI01F # truss -pwall 1601708
_nsleep(0x2FF21010, 0x2FF21088) (sleeping...)
Pstatus: process is not stopped

Process                                Freq  Total Kernel   User Shared  Other
=======                                ====  ===== ======   ==== ======  =====
wait                                      2  47.83  47.83   0.00   0.00   0.00
/opt/TWWfsw/bin/lpstat                    1  28.08   7.48   1.71  18.89   0.00
cupsd                                     1  17.75   6.77   2.21   8.77   0.00
...

  Profile: /opt/TWWfsw/cups136/lib/libcups.so

  Total % For All Processes (/opt/TWWfsw/cups136/lib/libcups.so) = 12.76

Subroutine                                            %   Source
==========                                         ====== ======
.strcmp                                              3.92 strcmp.s
.cups_array_find                                     2.00 array.c
.strcasecmp                                          1.14 glink.s
.cupsGetDest                                         1.07 dest.c
.cupsAddDest at AF14_11                                 0.71 dest.c


I will also be testing CUPS 1.3.6 on two Solaris systems. From previous
testing on 1.3.5, the problem also exist in Solaris.

It would be nice if someone can test this in AIX and solaris. It is
very simple to create 2700 printer queues using a loop.


Thanks,
Angel