[Date Prev][Date Next] [Thread Prev][Thread Next] [Date Index] [Thread Index]

Bug#689991: CUPS: error_log flooded due to AllowUser restriction



On Mon 08 Oct 2012 at 21:47:46 +0200, Sergio Gelato wrote:

 
> I've created a print queue with an
> 	AllowUser user1
> option. When submitting a print job as user1 all goes as expected, but
> if I submit it as some other user I see a flood of error messages appear
> (observed rates: 375-500 Hz, depending on the client) in
> /var/log/cups/error_log:
> 
> E [08/Oct/2012:20:31:23 +0200] Returning IPP client-error-not-authorized for Create-Job (ipp://xxx.yyy.zzz.ttt:631/printers/test1) from aaa.bbb.ccc.ddd
> 
> cupsd consumes significant amounts of CPU time while the client is trying
> to submit the job. Both the log flood and the CPU consumption stop as soon
> as I cancel the print job on the client.
> 
> Conclusion: use of AllowUser/DenyUser can lead to (often inadvertent) denial

Hello Sergio,

Thank you for your comprehensive bug report.

I've done some preliminary work on this by creating a print queue on an
Wheezy machine:

  lpadmin -p TEST-AllowUser -v /dev/null -u allow:debian -m <any_ppd_you_want>

>From the same machine I do (as user brian):

  lp -d TEST-AllowUser ~/.profile ,

which gives

  lp: Not allowed to print.

The error_log says

  E [20/Mar/2013:21:36:06 +0000] Returning IPP client-error-not-authorized for Create-Job (ipp://localhost:631/printers/TEST-AllowUser) from localhost

which looks as one would expect.

Then the same command was issued from a Sid machine. This lead to the
message flood mentioned above.


On the client:

  top - 22:10:00 up 12:42,  2 users,  load average: 0.56, 0.15, 0.09
  Tasks:  65 total,   2 running,  63 sleeping,   0 stopped,   0 zombie
  %Cpu(s): 37.6 us, 35.5 sy,  0.0 ni, 17.2 id,  0.0 wa,  0.0 hi,  9.7 si, 0.0 st
  KiB Mem:   1034180 total,   172860 used,   861320 free,    52412 buffers
  KiB Swap:        0 total,        0 used,        0 free,    62840 cached

    PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM     TIME+ COMMAND
    2121 root      20   0 11128 6784 2532 R 44.8  0.7  22:49.43 cupsd
   13420 root      20   0 19244 6684 1432 S 34.8  0.6   0:09.40 ipp

On the server:

  top - 22:15:37 up  4:45,  2 users,  load average: 0.51, 0.38, 0.20
  Tasks:  67 total,   2 running,  65 sleeping,   0 stopped,   0 zombie
  %Cpu(s): 13.0 us,  9.1 sy,  0.0 ni, 76.0 id,  0.8 wa,  0.0 hi,  1.0 si, 0.0 st
  KiB Mem:   2072492 total,   740336 used,  1332156 free,    15332 buffers
  KiB Swap:        0 total,        0 used,        0 free,   676132 cached

    PID USER      PR  NI  VIRT  RES  SHR S  %CPU %MEM    TIME+  COMMAND
   3405 root      20   0  9176 3304 2516 R  44.2  0.2   2:45.24 cupsd


So, Sergio, which one one of us is going to report this upstream? You or
I?

Regards,

Brian.


Reply to: