samba - Dec 2007 - SLow cups printing, lots of get-printer-attributes

Hi all,

I encounter a problem here on a samba PDC with 97 cups printers.

When on a windows client, I click right on a printer, then select
"properties", it tooks about 12 secondes to open.
When from a spreadsheet such as M$ Excel I click on print, then try to
select an imprimante from my pdc, it tooks about 30 seconds.

I did some debugging, and with an strace on the smb process, found that
for my first test (printer properties), samba ask cups 25 times per
printers for printer attributes (I also found in cups a lot of
Get-printer-attributes successful-ok).

below an exemple of this call from strace.

is there someone who know why samba test each printer 25 times ?
is there someone who knwo why samba ask for informations on other
printers when I select a defined printer ?


Except this give me really slow printing management, printing itself is
working fine ... just slow.


Thanks for any hint/help :)


15:47:40 connect(27, {sa_family=AF_FILE,
path="/var/run/cups/cups.sock"}, 26) = 0
15:47:40 time(NULL)                     = 1197643660
15:47:40 time(NULL)                     = 1197643660
15:47:40 time(NULL)                     = 1197643660
15:47:40 time(NULL)                     = 1197643660
15:47:40 time(NULL)                     = 1197643660
15:47:40 time(NULL)                     = 1197643660
15:47:40 time(NULL)                     = 1197643660
15:47:40 send(27, "POST / HTTP/1.1\r\nContent-Length:
196\r\nContent-Type: application/ipp\r\nHost: localhost\r\nUser-Agent:
CUPS/1.2.12\r\nExpect: 100-continue\r\n\r\n", 135, 0) = 135
15:47:40 time(NULL)                     = 1197643660
15:47:40 time(NULL)                     = 1197643660
15:47:40 time(NULL)                     = 1197643660
15:47:40 time(NULL)                     = 1197643660
15:47:40 time(NULL)                     = 1197643660
15:47:40 time(NULL)                     = 1197643660
15:47:40 send(27,
"\1\1\0\v\0\0\0\1\1G\0\22attributes-charset\0\niso-8859-1H\0\33attributes-natural-language\0\5en-usE\0\vprinter-uri\0\31ipp:///printers/5000-001BB\0\24requested-attributes\0\fprinter-nameB\0\0\0\fprinter-infoB\0\0\0\20printer-location\3",
196, 0) = 196
15:47:40 getrlimit(RLIMIT_NOFILE, {rlim_cur=10020, rlim_max=10020}) = 0
15:47:40 select(28, [27], NULL, NULL, {1, 0}) = 1 (in [27], left {1, 0})
15:47:40 recv(27, "HTTP/1.1 100 Continue\r\n\r\n", 2048, 0) = 25
15:47:40 time(NULL)                     = 1197643660
15:47:40 time(NULL)                     = 1197643660
15:47:40 recv(27, "HTTP/1.1 200 OK\r\nDate: Fri, 14 Dec 2007 14:47:40
GMT\r\nServer: CUPS/1.2\r\nConnection: Keep-Alive\r\nKeep-Alive:
timeout=60\r\nContent-Language: fr\r\nContent-Type:
application/ipp\r\nContent-Length: 4215\r\n\r\n", 2048, 0) = 197
15:47:40 time(NULL)                     = 1197643660
15:47:40 time(NULL)                     = 1197643660
15:47:40 time(NULL)                     = 1197643660
15:47:40 time(NULL)                     = 1197643660
15:47:40 time(NULL)                     = 1197643660
15:47:40 time(NULL)                     = 1197643660
15:47:40 time(NULL)                     = 1197643660
15:47:40 time(NULL)                     = 1197643660
15:47:40 time(NULL)                     = 1197643660
15:47:40 time(NULL)                     = 1197643660
15:47:40 recv(27,
"\1\1\0\0\0\0\0\1\1G\0\22attributes-charset\0\niso-8859-1H\0\33attributes-natural-language\0\5en-us\0041\0\24printer-current-time\0\v\7\327\f\16\16/(\0+\0\0B\0\24printer-error-policy\0\fstop-printer\"\0\31printer-is-accepting-jobs\0\1\1\"\0\21printer-is-shared\0\1\1B\0\21printer-op-policy\0\7default#\0\rprinter-state\0\4\0\0\0\3!\0\31printer-state-change-time\0\4G%\340\315A\0\25printer-state-message\0\0D\0\25printer-state-reasons\0\4none#\0\fprinter-type\0\4\0\0\0\4!\0\17printer-up-time\0\4Gb\227\214E\0\25printer-uri-supported\0&ipp://localhost:631/printers/
[...]

On Fri, Dec 14, 2007 at 03:59:02PM +0100, Emmanuel Lacour
wrote:
> Hi all,
> 
> I encounter a problem here on a samba PDC with 97 cups printers.
> 
> When on a windows client, I click right on a printer, then select
> "properties", it tooks about 12 secondes to open.
> When from a spreadsheet such as M$ Excel I click on print, then try to
> select an imprimante from my pdc, it tooks about 30 seconds.
> 
> I did some debugging, and with an strace on the smb process, found that
> for my first test (printer properties), samba ask cups 25 times per
> printers for printer attributes (I also found in cups a lot of
> Get-printer-attributes successful-ok).
> 
> below an exemple of this call from strace.
> 
> is there someone who know why samba test each printer 25 times ?
> is there someone who knwo why samba ask for informations on other
> printers when I select a defined printer ?
> 
> 
> Except this give me really slow printing management, printing itself is
> working fine ... just slow.
> 
> 
> Thanks for any hint/help :)
> 

I did some tests and found that it results from a change between 3.0.24
and 3.0.25 and it's stil there in 3.0.28.

The strace for 3.0.24 is really shorter than newer versions as it just
open the right printer and does not try to access all informations of
all printers.

Ther is a lot of changes on the printing code between 3.0.24 and 3.0.25,
but I will try to study it a little bit :/

-- 
Emmanuel Lacour