CUPS 1.3 performance issue in Solaris and AIX
angelb
angelb at bugarin.us
Wed Feb 27 09:30:11 PST 2008
Here's a profile of cupsd when "lpstat -p" is executed in a Solaris 10
system.
The following list is taken using dtrace profiling the cupsd PID and
probing functions to see how often and how time spent in each
functions.
I took off functions from the list as well as those with zero counts
which I thought was irrelevant to make the list shorter.
...
ippFindAttribute
value ------------- Distribution ------------- count
8192 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 11
httpSetField
value ------------- Distribution ------------- count
32768 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 5
cupsArrayAdd
value ------------- Distribution ------------- count
8192 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 34
http_write
value ------------- Distribution ------------- count
131072 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 7
ipp_read_http
value ------------- Distribution ------------- count
8192 |@ 1
32768 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 65
65536 |@@@ 5
ippWrite
value ------------- Distribution ------------- count
8192 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 342
cupsArraySave
value ------------- Distribution ------------- count
8192 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 346
cupsArrayRestore
value ------------- Distribution ------------- count
8192 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 344
httpPrintf
value ------------- Distribution ------------- count
262144 |@@@@@@@@@@@@@@@@@@@@@@@@@@@ 6
524288 |@@@@@@@@@@@@@ 3
cups_array_add
value ------------- Distribution ------------- count
32768 |@@@@@@@@ 7
65536 |@@@@@ 4
131072 |@@@@@@@@@@@@ 10
262144 |@@ 2
524288 |@@@@@@@ 6
1048576 |@@@@@ 4
cupsArrayCount
value ------------- Distribution ------------- count
8192 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1411
16384 |@ 19
compare_fds
value ------------- Distribution ------------- count
8192 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1718
16384 | 13
32768 | 3
65536 | 1
cupsArrayFirst
value ------------- Distribution ------------- count
8192 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1778
httpWrite2
value ------------- Distribution ------------- count
65536 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 343
262144 |@ 5
compare_printers
value ------------- Distribution ------------- count
8192 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 4806
16384 | 18
poll
value ------------- Distribution ------------- count
65536 | 1
131072 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 343
cupsdUnloadCompletedJobs
value ------------- Distribution ------------- count
131072 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 324
262144 |@@ 21
ippWriteIO
value ------------- Distribution ------------- count
131072 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 316
262144 |@@@ 27
find_fd
value ------------- Distribution ------------- count
262144 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 347
cupsdWriteClient
value ------------- Distribution ------------- count
262144 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 337
524288 |@ 6
cupsdCheckJobs
value ------------- Distribution ------------- count
1048576 |@ 1
2097152 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 47
cupsFilePutChar
value ------------- Distribution ------------- count
8192 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 41270
16384 | 121
32768 | 30
65536 | 17
cupsFileTell
value ------------- Distribution ------------- count
8192 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 82639
16384 | 137
32768 | 60
65536 | 42
ferror
value ------------- Distribution ------------- count
8192 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 83281
16384 | 59
32768 | 38
65536 | 47
ippAddSeparator
value ------------- Distribution ------------- count
262144 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 2704
524288 | 1
1048576 | 1
cupsdGetDateTime
value ------------- Distribution ------------- count
8192 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 40732
16384 | 118
32768 | 29
65536 | 32
1048576 |@ 527
4194304 | 1
cupsFilePuts
value ------------- Distribution ------------- count
32768 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 40404
65536 |@ 945
131072 | 88
524288 | 1
1048576 | 1
ippAddString
value ------------- Distribution ------------- count
1048576 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 2695
2097152 | 10
4194304 | 3
8388608 | 1
add_printer_state_reasons
value ------------- Distribution ------------- count
1048576 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 2666
2097152 |@ 39
4194304 | 1
16777216 | 1
write
value ------------- Distribution ------------- count
65536 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 39986
131072 |@ 1424
262144 | 22
1048576 | 1
8388608 | 6
16777216 | 3
ippAddBoolean
value ------------- Distribution ------------- count
524288 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 4423
1048576 |@@@@@@@ 988
2097152 | 3
cups_write
value ------------- Distribution ------------- count
65536 |@@@@@@@@@@@@@@ 14093
131072 |@@@@@@@@@@@@@@@@@@@@@@@@@@ 27260
262144 | 73
524288 | 1
1048576 | 3
8388608 | 6
16777216 | 3
cupsFileFlush
value ------------- Distribution ------------- count
131072 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 40867
262144 |@ 556
524288 | 4
1048576 | 3
8388608 | 5
16777216 | 4
ippAddInteger
value ------------- Distribution ------------- count
524288 |@@@@@@@@@@@@@@@@@@@@@@@@@ 4977
1048576 |@@@@@@@@@@@@@@@ 3137
2097152 | 7
_cupsStrStatistics
value ------------- Distribution ------------- count
1073741824 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 9
ippAddIntegers
value ------------- Distribution ------------- count
524288 |@@@@@@@@@@ 2706
1048576 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 8111
2097152 | 11
cupsFilePrintf
value ------------- Distribution ------------- count
262144 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 41380
524288 | 41
1048576 | 12
2097152 | 6
_ippAddAttr
value ------------- Distribution ------------- count
131072 | 345
262144 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 48371
524288 | 1
1048576 | 13
2097152 | 1
ippAddStrings
value ------------- Distribution ------------- count
524288 |@ 482
1048576 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 18447
2097152 | 20
vsnprintf
value ------------- Distribution ------------- count
131072 | 614
262144 |@@@@@@@@@@@@@@@@@@@@@ 44295
524288 |@@@@@@@@@@@@@@@@@@ 37929
1048576 | 29
2097152 | 18
4194304 | 1
8388608 | 1
_cupsStrAlloc
value ------------- Distribution ------------- count
65536 |@ 2626
131072 | 82
262144 |@ 2640
524288 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 64969
1048576 | 55
2097152 | 33
4194304 | 0
8388608 | 1
cupsdLogMessage
value ------------- Distribution ------------- count
1048576 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 40828
2097152 |@ 584
4194304 | 16
8388608 | 6
16777216 | 5
cups_array_find
value ------------- Distribution ------------- count
32768 |@ 3088
65536 |@@@@@@@@ 50193
131072 |@@@@@@@@@@@@@@@@@@@@ 120200
262144 |@ 5567
524288 |@@@@@@@@@@ 62546
1048576 | 49
2097152 | 27
8388608 | 1
cupsArrayFind
value ------------- Distribution ------------- count
65536 |@ 5343
131072 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 166934
262144 |@ 4035
524288 |@@@@@@@@@@@ 65233
1048576 | 65
2097152 | 28
8388608 | 1
copy_attribute
value ------------- Distribution ------------- count
2097152 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 29487
4194304 | 285
8388608 | 2
16777216 | 3
cupsArrayNext
value ------------- Distribution ------------- count
8192 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 7693613
16384 | 2792
32768 | 2918
65536 | 616
131072 | 14
262144 | 1
524288 | 1
1048576 | 2
2097152 | 1
cupsArrayCurrent
value ------------- Distribution ------------- count
8192 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 7679814
16384 | 14401
32768 | 6502
65536 | 1004
131072 | 13
262144 | 1
524288 | 2
1048576 | 1
4194304 | 4
33554432 | 1
copy_printer_attrs
value ------------- Distribution ------------- count
33554432 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 2624
67108864 |@ 83
copy_attrs
value ------------- Distribution ------------- count
4194304 |@@@@@@@@@@@@@@@@@@@@ 2672
8388608 | 35
33554432 |@@@@@@@@@@@@@@@@@@@@ 2704
67108864 | 3
cupsdProcessIPPRequest
value ------------- Distribution ------------- count
137438953472 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1
cupsdReadClient
value ------------- Distribution ------------- count
137438953472 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1
get_printers
value ------------- Distribution ------------- count
137438953472 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1
cupsdDoSelect
value ------------- Distribution ------------- count
8388608 |@@@@@@ 53
16777216 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 290
137438953472 | 1
cupsdSendBrowseList
value ------------- Distribution ------------- count
1073741824 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 344
# timex lpstat -p|wc
real 24.21
user 3.07
sys 0.11
2707 29777 167898
# timex lpstat -p|wc
real 23.84
user 3.09
sys 0.12
2707 29777 167898
In CUPS 1.3, it's taking a lot longer, 15-25 seconds, to list 2700
printer queues compare to CUPS 1.2 which only takes 6-7seconds in
Solaris systems. This is true for the AIX clients as well, although in
AIX, it's taking 14-15 seconds on average.
Thanks,
Angel
More information about the cups
mailing list