Performance with large printer database

Patrick Spinler pspinler at yahoo.com
Tue Feb 1 07:47:39 PST 2005 

Michael Sweet wrote:
> Patrick Spinler wrote:
> 
>> ...
>> I'd offer to perform an strace/truss log for you, but I fear the disk 
>> space required. Is there a debugging build or some other client level 
>> debugging or testing I could do for you?
> 
> 
> A debug2 error_log file + the client's cupsd.conf file should provide
> all of the info that is needed.
> 

In intrest of simplicity, I removed all but one BrowsePoll entry from my 
cupsd.conf, and tried again.  Again, very similar results.

A debug2 file is, uh, large.  Is there a good location I coudl put this 
at for people to look at?

Some info:

When first invoked, the client cupsd is adding browsed printers at a 
rate of 6+ a second:

[pjs11 at patslinux01 printing]$ grep AddPrinter error_log.1_browsepoll
....
d [28/Jan/2005:16:03:14 -0600] AddPrinter("ba6a")
d [28/Jan/2005:16:03:14 -0600] AddPrinter("ba6a112aappt")
d [28/Jan/2005:16:03:15 -0600] AddPrinter("ba6b301")
d [28/Jan/2005:16:03:15 -0600] AddPrinter("bas170e")
d [28/Jan/2005:16:03:15 -0600] AddPrinter("brycetmp")
d [28/Jan/2005:16:03:15 -0600] AddPrinter("ce600test")
d [28/Jan/2005:16:03:15 -0600] AddPrinter("ch10140desk")
d [28/Jan/2005:16:03:15 -0600] AddPrinter("ch10275office")
d [28/Jan/2005:16:03:16 -0600] AddPrinter("ch10278")
....

By the time I got tired of waiting for it, the client daemon had slowed 
down a bit, to the pace of adding a browsed printer every 2 seconds:

....
d [28/Jan/2005:16:16:48 -0600] AddPrinter("ln109203")
d [28/Jan/2005:16:16:49 -0600] AddPrinter("ln109209")
d [28/Jan/2005:16:16:50 -0600] AddPrinter("ln109215")
d [28/Jan/2005:16:16:52 -0600] AddPrinter("ln109222")


I've attached the bottom 100 lines from my debug2 output, and my 
cupsd.conf.  Sorry for the wrap.

-- Pat

[pjs11 at patslinux01 printing]$ tail -100 error_log.1_browsepoll
d [28/Jan/2005:16:16:43 -0600] [cups-polld 129.176.175.75:631] Sending 2 
3 ipp://stump05.mayo.edu:631/printers/r0043919 "" "r0043919" "Local Raw 
Printer"
d [28/Jan/2005:16:16:43 -0600] [cups-polld 129.176.175.75:631] Sending 2 
3 ipp://stump05.mayo.edu:631/printers/r0044135 "" "r0044135" "Local Raw 
Printer"
d [28/Jan/2005:16:16:43 -0600] [cups-polld 129.176.175.75:631] Sending 2 
3 ipp://stump05.mayo.edu:631/printers/r0046152 "" "r0046152" "Local Raw 
Printer"
d [28/Jan/2005:16:16:43 -0600] [cups-polld 129.176.175.75:631] Sending 2 
3 ipp://stump05.mayo.edu:631/printers/r0046153 "" "r0046153" "Local Raw 
Printer"
d [28/Jan/2005:16:16:43 -0600] UpdateCUPSBrowse: (83 bytes from 
127.0.0.1) 2 3 ipp://stump05.mayo.edu:631/printers/ln109172 "" 
"ln109172" "Local Raw Printer"
d [28/Jan/2005:16:16:43 -0600] AddPrinter("ln109172")
I [28/Jan/2005:16:16:43 -0600] Added remote printer "ln109172"...
d [28/Jan/2005:16:16:43 -0600] Adding filter application/vnd.cups-raw 
printer/ln109172 0 -
d [28/Jan/2005:16:16:44 -0600] [cups-polld 129.176.175.75:631] Sending 2 
3 ipp://stump05.mayo.edu:631/printers/r0046154 "" "r0046154" "Local Raw 
Printer"
d [28/Jan/2005:16:16:44 -0600] [cups-polld 129.176.175.75:631] Sending 2 
3 ipp://stump05.mayo.edu:631/printers/r0046707 "" "r0046707" "Local Raw 
Printer"
d [28/Jan/2005:16:16:44 -0600] [cups-polld 129.176.175.75:631] Sending 2 
3 ipp://stump05.mayo.edu:631/printers/r0048199 "" "r0048199" "Local Raw 
Printer"
d [28/Jan/2005:16:16:44 -0600] [cups-polld 129.176.175.75:631] Sending 2 
3 ipp://stump05.mayo.edu:631/printers/r0048935 "" "r0048935" "Local Raw 
Printer"
d [28/Jan/2005:16:16:44 -0600] UpdateCUPSBrowse: (83 bytes from 
127.0.0.1) 2 3 ipp://stump05.mayo.edu:631/printers/ln107497 "" 
"ln107497" "Local Raw Printer"
d [28/Jan/2005:16:16:45 -0600] UpdateCUPSBrowse: (83 bytes from 
127.0.0.1) 2 3 ipp://stump05.mayo.edu:631/printers/ln109178 "" 
"ln109178" "Local Raw Printer"
d [28/Jan/2005:16:16:45 -0600] AddPrinter("ln109178")
I [28/Jan/2005:16:16:45 -0600] Added remote printer "ln109178"...
d [28/Jan/2005:16:16:45 -0600] Adding filter application/vnd.cups-raw 
printer/ln109178 0 -
d [28/Jan/2005:16:16:45 -0600] [cups-polld 129.176.175.75:631] Sending 2 
3 ipp://stump05.mayo.edu:631/printers/r0048938 "" "r0048938" "Local Raw 
Printer"
d [28/Jan/2005:16:16:45 -0600] [cups-polld 129.176.175.75:631] Sending 2 
3 ipp://stump05.mayo.edu:631/printers/r0048940 "" "r0048940" "Local Raw 
Printer"
d [28/Jan/2005:16:16:45 -0600] [cups-polld 129.176.175.75:631] Sending 2 
3 ipp://stump05.mayo.edu:631/printers/r0048946 "" "r0048946" "Local Raw 
Printer"
d [28/Jan/2005:16:16:45 -0600] [cups-polld 129.176.175.75:631] Sending 2 
3 ipp://stump05.mayo.edu:631/printers/r0049011 "" "r0049011" "Local Raw 
Printer"
d [28/Jan/2005:16:16:45 -0600] [cups-polld 129.176.175.75:631] Sending 2 
3 ipp://stump05.mayo.edu:631/printers/r0049012 "" "r0049012" "Local Raw 
Printer"
d [28/Jan/2005:16:16:45 -0600] [cups-polld 129.176.175.75:631] Sending 2 
3 ipp://stump05.mayo.edu:631/printers/r0049572 "" "r0049572" "Local Raw 
Printer"
d [28/Jan/2005:16:16:45 -0600] [cups-polld 129.176.175.75:631] Sending 2 
3 ipp://stump05.mayo.edu:631/printers/r0049573 "" "r0049573" "Local Raw 
Printer"
d [28/Jan/2005:16:16:45 -0600] UpdateCUPSBrowse: (83 bytes from 
127.0.0.1) 2 3 ipp://stump05.mayo.edu:631/printers/ln109185 "" 
"ln109185" "Local Raw Printer"
d [28/Jan/2005:16:16:45 -0600] AddPrinter("ln109185")
I [28/Jan/2005:16:16:45 -0600] Added remote printer "ln109185"...
d [28/Jan/2005:16:16:45 -0600] Adding filter application/vnd.cups-raw 
printer/ln109185 0 -
d [28/Jan/2005:16:16:46 -0600] [cups-polld 129.176.175.75:631] Sending 2 
3 ipp://stump05.mayo.edu:631/printers/r0050128 "" "r0050128" "Local Raw 
Printer"
d [28/Jan/2005:16:16:46 -0600] [cups-polld 129.176.175.75:631] Sending 2 
3 ipp://stump05.mayo.edu:631/printers/r0050284 "" "r0050284" "Local Raw 
Printer"
d [28/Jan/2005:16:16:46 -0600] [cups-polld 129.176.175.75:631] Sending 2 
3 ipp://stump05.mayo.edu:631/printers/r0050559 "" "r0050559" "Local Raw 
Printer"
d [28/Jan/2005:16:16:46 -0600] [cups-polld 129.176.175.75:631] Sending 2 
3 ipp://stump05.mayo.edu:631/printers/r0051892 "" "r0051892" "Local Raw 
Printer"
d [28/Jan/2005:16:16:46 -0600] [cups-polld 129.176.175.75:631] Sending 2 
3 ipp://stump05.mayo.edu:631/printers/r0051899 "" "r0051899" "Local Raw 
Printer"
d [28/Jan/2005:16:16:46 -0600] [cups-polld 129.176.175.75:631] Sending 2 
3 ipp://stump05.mayo.edu:631/printers/r0051916 "" "r0051916" "Local Raw 
Printer"
d [28/Jan/2005:16:16:46 -0600] [cups-polld 129.176.175.75:631] Sending 2 
3 ipp://stump05.mayo.edu:631/printers/r0053781 "" "r0053781" "Local Raw 
Printer"
d [28/Jan/2005:16:16:46 -0600] UpdateCUPSBrowse: (83 bytes from 
127.0.0.1) 2 3 ipp://stump05.mayo.edu:631/printers/ln107570 "" 
"ln107570" "Local Raw Printer"
d [28/Jan/2005:16:16:47 -0600] [cups-polld 129.176.175.75:631] Sending 2 
3 ipp://stump05.mayo.edu:631/printers/r0053782 "" "r0053782" "Local Raw 
Printer"
d [28/Jan/2005:16:16:47 -0600] [cups-polld 129.176.175.75:631] Sending 2 
3 ipp://stump05.mayo.edu:631/printers/r0054011 "" "r0054011" "Local Raw 
Printer"
d [28/Jan/2005:16:16:47 -0600] [cups-polld 129.176.175.75:631] Sending 2 
3 ipp://stump05.mayo.edu:631/printers/r0054262 "" "r0054262" "Local Raw 
Printer"
d [28/Jan/2005:16:16:47 -0600] [cups-polld 129.176.175.75:631] Sending 2 
3 ipp://stump05.mayo.edu:631/printers/r0054275 "" "r0054275" "Local Raw 
Printer"
d [28/Jan/2005:16:16:47 -0600] UpdateCUPSBrowse: (83 bytes from 
127.0.0.1) 2 3 ipp://stump05.mayo.edu:631/printers/ln109192 "" 
"ln109192" "Local Raw Printer"
d [28/Jan/2005:16:16:47 -0600] AddPrinter("ln109192")
I [28/Jan/2005:16:16:47 -0600] Added remote printer "ln109192"...
d [28/Jan/2005:16:16:47 -0600] Adding filter application/vnd.cups-raw 
printer/ln109192 0 -
d [28/Jan/2005:16:16:48 -0600] UpdateCUPSBrowse: (83 bytes from 
127.0.0.1) 2 3 ipp://stump05.mayo.edu:631/printers/ln107580 "" 
"ln107580" "Local Raw Printer"
d [28/Jan/2005:16:16:48 -0600] [cups-polld 129.176.175.75:631] Sending 2 
3 ipp://stump05.mayo.edu:631/printers/r0054303 "" "r0054303" "Local Raw 
Printer"
d [28/Jan/2005:16:16:48 -0600] [cups-polld 129.176.175.75:631] Sending 2 
3 ipp://stump05.mayo.edu:631/printers/r0054684 "" "r0054684" "Local Raw 
Printer"
d [28/Jan/2005:16:16:48 -0600] [cups-polld 129.176.175.75:631] Sending 2 
3 ipp://stump05.mayo.edu:631/printers/r0057342 "" "r0057342" "Local Raw 
Printer"
d [28/Jan/2005:16:16:48 -0600] [cups-polld 129.176.175.75:631] Sending 2 
3 ipp://stump05.mayo.edu:631/printers/r0057343 "" "r0057343" "Local Raw 
Printer"
d [28/Jan/2005:16:16:48 -0600] [cups-polld 129.176.175.75:631] Sending 2 
3 ipp://stump05.mayo.edu:631/printers/r0057344 "" "r0057344" "Local Raw 
Printer"
d [28/Jan/2005:16:16:48 -0600] [cups-polld 129.176.175.75:631] Sending 2 
3 ipp://stump05.mayo.edu:631/printers/r0057345 "" "r0057345" "Local Raw 
Printer"
d [28/Jan/2005:16:16:48 -0600] [cups-polld 129.176.175.75:631] Sending 2 
3 ipp://stump05.mayo.edu:631/printers/r0057346 "" "r0057346" "Local Raw 
Printer"
d [28/Jan/2005:16:16:48 -0600] UpdateCUPSBrowse: (83 bytes from 
127.0.0.1) 2 3 ipp://stump05.mayo.edu:631/printers/ln109203 "" 
"ln109203" "Local Raw Printer"
d [28/Jan/2005:16:16:48 -0600] AddPrinter("ln109203")
I [28/Jan/2005:16:16:48 -0600] Added remote printer "ln109203"...
d [28/Jan/2005:16:16:48 -0600] Adding filter application/vnd.cups-raw 
printer/ln109203 0 -
d [28/Jan/2005:16:16:49 -0600] [cups-polld 129.176.175.75:631] Sending 2 
3 ipp://stump05.mayo.edu:631/printers/r0057347 "" "r0057347" "Local Raw 
Printer"
d [28/Jan/2005:16:16:49 -0600] [cups-polld 129.176.175.75:631] Sending 2 
3 ipp://stump05.mayo.edu:631/printers/r0057580 "" "r0057580" "Local Raw 
Printer"
d [28/Jan/2005:16:16:49 -0600] [cups-polld 129.176.175.75:631] Sending 2 
3 ipp://stump05.mayo.edu:631/printers/r0057682 "" "r0057682" "Local Raw 
Printer"
d [28/Jan/2005:16:16:49 -0600] [cups-polld 129.176.175.75:631] Sending 2 
3 ipp://stump05.mayo.edu:631/printers/r0058033 "" "r0058033" "Local Raw 
Printer"
d [28/Jan/2005:16:16:49 -0600] [cups-polld 129.176.175.75:631] Sending 2 
3 ipp://stump05.mayo.edu:631/printers/r0058040 "" "r0058040" "Local Raw 
Printer"
d [28/Jan/2005:16:16:49 -0600] [cups-polld 129.176.175.75:631] Sending 2 
3 ipp://stump05.mayo.edu:631/printers/r0058042 "" "r0058042" "Local Raw 
Printer"
d [28/Jan/2005:16:16:49 -0600] [cups-polld 129.176.175.75:631] Sending 2 
3 ipp://stump05.mayo.edu:631/printers/r0058047 "" "r0058047" "Local Raw 
Printer"
d [28/Jan/2005:16:16:49 -0600] UpdateCUPSBrowse: (83 bytes from 
127.0.0.1) 2 3 ipp://stump05.mayo.edu:631/printers/ln109209 "" 
"ln109209" "Local Raw Printer"
d [28/Jan/2005:16:16:49 -0600] AddPrinter("ln109209")
I [28/Jan/2005:16:16:49 -0600] Added remote printer "ln109209"...
d [28/Jan/2005:16:16:49 -0600] Adding filter application/vnd.cups-raw 
printer/ln109209 0 -
d [28/Jan/2005:16:16:50 -0600] [cups-polld 129.176.175.75:631] Sending 2 
3 ipp://stump05.mayo.edu:631/printers/r0058048 "" "r0058048" "Local Raw 
Printer"
d [28/Jan/2005:16:16:50 -0600] [cups-polld 129.176.175.75:631] Sending 2 
3 ipp://stump05.mayo.edu:631/printers/r0058049 "" "r0058049" "Local Raw 
Printer"
d [28/Jan/2005:16:16:50 -0600] [cups-polld 129.176.175.75:631] Sending 2 
3 ipp://stump05.mayo.edu:631/printers/r0058051 "" "r0058051" "Local Raw 
Printer"
d [28/Jan/2005:16:16:50 -0600] [cups-polld 129.176.175.75:631] Sending 2 
3 ipp://stump05.mayo.edu:631/printers/r0058064 "" "r0058064" "Local Raw 
Printer"
d [28/Jan/2005:16:16:50 -0600] UpdateCUPSBrowse: (83 bytes from 
127.0.0.1) 2 3 ipp://stump05.mayo.edu:631/printers/ln107696 "" 
"ln107696" "Local Raw Printer"
d [28/Jan/2005:16:16:50 -0600] UpdateCUPSBrowse: (83 bytes from 
127.0.0.1) 2 3 ipp://stump05.mayo.edu:631/printers/ln109215 "" 
"ln109215" "Local Raw Printer"
d [28/Jan/2005:16:16:50 -0600] AddPrinter("ln109215")
I [28/Jan/2005:16:16:50 -0600] Added remote printer "ln109215"...
d [28/Jan/2005:16:16:50 -0600] Adding filter application/vnd.cups-raw 
printer/ln109215 0 -
d [28/Jan/2005:16:16:51 -0600] [cups-polld 129.176.175.75:631] Sending 2 
3 ipp://stump05.mayo.edu:631/printers/r0058065 "" "r0058065" "Local Raw 
Printer"
d [28/Jan/2005:16:16:51 -0600] [cups-polld 129.176.175.75:631] Sending 2 
3 ipp://stump05.mayo.edu:631/printers/r0058067 "" "r0058067" "Local Raw 
Printer"
d [28/Jan/2005:16:16:51 -0600] [cups-polld 129.176.175.75:631] Sending 2 
3 ipp://stump05.mayo.edu:631/printers/r0058087 "" "r0058087" "Local Raw 
Printer"
d [28/Jan/2005:16:16:51 -0600] [cups-polld 129.176.175.75:631] Sending 2 
3 ipp://stump05.mayo.edu:631/printers/r0058093 "" "r0058093" "Local Raw 
Printer"
d [28/Jan/2005:16:16:51 -0600] [cups-polld 129.176.175.75:631] Sending 2 
3 ipp://stump05.mayo.edu:631/printers/r0058095 "" "r0058095" "Local Raw 
Printer"
d [28/Jan/2005:16:16:51 -0600] [cups-polld 129.176.175.75:631] Sending 2 
3 ipp://stump05.mayo.edu:631/printers/r0058100 "" "r0058100" "Local Raw 
Printer"
d [28/Jan/2005:16:16:51 -0600] [cups-polld 129.176.175.75:631] Sending 2 
3 ipp://stump05.mayo.edu:631/printers/r0058101 "" "r0058101" "Local Raw 
Printer"
d [28/Jan/2005:16:16:51 -0600] UpdateCUPSBrowse: (83 bytes from 
127.0.0.1) 2 3 ipp://stump05.mayo.edu:631/printers/ln107780 "" 
"ln107780" "Local Raw Printer"
d [28/Jan/2005:16:16:52 -0600] [cups-polld 129.176.175.75:631] Sending 2 
3 ipp://stump05.mayo.edu:631/printers/r0059937 "" "r0059937" "Local Raw 
Printer"
d [28/Jan/2005:16:16:52 -0600] [cups-polld 129.176.175.75:631] Sending 2 
3 ipp://stump05.mayo.edu:631/printers/r0060445 "" "r0060445" "Local Raw 
Printer"
d [28/Jan/2005:16:16:52 -0600] [cups-polld 129.176.175.75:631] Sending 2 
3 ipp://stump05.mayo.edu:631/printers/r0060524 "" "r0060524" "Local Raw 
Printer"
d [28/Jan/2005:16:16:52 -0600] [cups-polld 129.176.175.75:631] Sending 2 
3 ipp://stump05.mayo.edu:631/printers/r0061529 "" "r0061529" "Local Raw 
Printer"
d [28/Jan/2005:16:16:52 -0600] [cups-polld 129.176.175.75:631] Sending 2 
3 ipp://stump05.mayo.edu:631/printers/r0062219 "" "r0062219" "Local Raw 
Printer"
d [28/Jan/2005:16:16:52 -0600] UpdateCUPSBrowse: (83 bytes from 
127.0.0.1) 2 3 ipp://stump05.mayo.edu:631/printers/ln109222 "" 
"ln109222" "Local Raw Printer"
d [28/Jan/2005:16:16:52 -0600] AddPrinter("ln109222")
I [28/Jan/2005:16:16:52 -0600] Added remote printer "ln109222"...
d [28/Jan/2005:16:16:52 -0600] Adding filter application/vnd.cups-raw 
printer/ln109222 0 -
I [28/Jan/2005:16:16:53 -0600] Scheduler shutting down normally.
D [28/Jan/2005:16:16:53 -0600] StopListening: closing all listen sockets.
D [28/Jan/2005:16:16:53 -0600] PauseListening: clearing input bits...
d [28/Jan/2005:16:16:53 -0600] PauseListening: Removing fd 0 from 
InputSet...
d [28/Jan/2005:16:16:53 -0600] StopPolling: removing fd 3 from InputSet.
d [28/Jan/2005:16:16:53 -0600] StopBrowsing: Removing fd 2 from InputSet...
d [28/Jan/2005:16:16:53 -0600] StopServer: Removing fd 4 from InputSet...


-------------- next part --------------
An embedded and charset-unspecified text was scrubbed...
Name: cupsd.conf
URL: <https://lists.cups.org/pipermail/cups/attachments/20050201/f635a20e/attachment-0001.ksh>

More information about the cups mailing list