You are not logged in.
I investigated with perl packages on two hosts concerning the "/usr/bin/perl /usr/lib/cups/drivers/foomatic list" block. After removing completely perl-clone (pacman -Rcc), the problem got resolved. Both the cups web interface and "lpinfo -m" work normally. How and why did perl-clone interfere ? don't know, don't know perl language at all, someone knowledgeable in perl should investigate.
Offline
I investigated with perl packages on two hosts concerning the "/usr/bin/perl /usr/lib/cups/drivers/foomatic list" block. After removing completely perl-clone (pacman -Rcc), the problem got resolved. Both the cups web interface and "lpinfo -m" work normally. How and why did perl-clone interfere ? don't know, don't know perl language at all, someone knowledgeable in perl should investigate.
I don't have the package perl-clone installed - so that solution would not be relevant to my cups issues. Why it matters for yours I don't know.
Mike C
Offline
The foomatic list command blocks whenever I have foomatic-db-engine installed.
I have tried removing packages and configuration, reinstalling everything again.
As soon as foomatic-db-engine is installed, it stops working.
So now I am trying to figure out how to debug foomatic...
Offline
Did you check this out? https://bbs.archlinux.org/viewtopic.php … 9#p1472149
I have foomatic-db-engine installed with no problems.
Andrew
Offline
Did you check this out? https://bbs.archlinux.org/viewtopic.php … 9#p1472149
I have foomatic-db-engine installed with no problems.
Andrew
Thanks for the tip, but no, deleting the file does not help.
Also, I am not even getting any error messages - the foomatic command simply blocks.
I narrowed it down to line 101 in /usr/lib/cups/driver/foomatic:
$db->get_overview(1, 1 + $listreadymadeppds);
I put in some debug printing before and after the line, and it clearly blocks on this exact spot.
I wonder why, or how I should continue from here...
Last edited by tachy (2015-01-02 17:05:08)
Offline
Oh, wait, the command completed!!
I left the "foomatic list" command running in the background for a very long time, grinding a core on my i7-4600U, and it finally returned.
I wonder why that specific line took so long to complete. I am timing it now...
*EDIT*
time /usr/lib/cups/driver/foomatic list
real 13m8.364s
user 13m5.553s
sys 0m0.057s
Last edited by tachy (2015-01-02 17:27:59)
Offline
Ok, I kinda found the culprit: gutenprint
Removing the gutenprint package resolved my problem, and foomatic no longer hangs for 13+ minutes.
This is how it looks:
* /usr/lib/cups/driver/foomatic line 101 calls get_overview from Foomatic::DB
* /usr/lib/perl5/vendor_perl/Foomatic/DB.pm line 1741 calls parseOverview from Foomatic::DB::filters::xml::xmlParse
* /usr/lib/perl5/vendor_perl/Foomatic/filters/xml/xmlParse.pm "hangs" during the loop starting at line 768
Below is the loop from xmlParse.pm
The driverName it "hangs" on is gutenprint-ijs.5.2
#DRIVER DRIVEN, ADD DRIVER DATA TO PRINTER
foreach my $driverName (keys %drivers) {
my $driver = $drivers{$driverName};
if (($cupsMode) && ((!$driver->{'cmd'}) &&
(!$driver->{'cmd_cmd'}))) {
next; # In CUPS mode a driver that lacks a cmd or a
# pdf_cmd (cmd_cmd) is useless and should not
# appear in overview. Note that here we do
# no need to consider that there could be
# also a ready-made PPD file (CUPS mode 2), as
# the links to the PPDs are in the printer
# entry files and here we do not have a
# printer entry.
}
foreach my $printer (@{$driver->{'printers'}}) {
if($printer->{'id'}) {
my $id = $printer->{'id'};
if (!$printers{$id}) {#create new no xml printer
$printers{$id} = $this->getNoXmlPrinter($id);
}
#add driver to printer's list of drivers
push(@{$printers{$id}->{'drivers'}}, $driverName);
#add driver data to printer
$printers{$id}->{'driverproperties'}{$driverName} = $this->getPrinterSpecificDriver($driver, $printer, 0);
}
}
delete $driver->{'printers'}; #cleans out the driver's printers array
}
I added this line at the top of the outer foreach loop to find the driverName:
print STDERR "DEBUG: driverName: $driverName\n";
Adding another debug line to the inner foreach loop reveals that the gutenprint-ijs.5.2 driver contains thousands of printers, which, for some reason, take a huge amount of time to process.
Last edited by tachy (2015-01-02 18:44:25)
Offline
Hi,
This makes sense. However, I dont have the foomatic-db package installed and do not have a /usr/lib/cups/driver/foomatic file or a /usr/lib/perl5/vendor_perl/Foomatic directory. So I assume, if the loop through the models is the culprit, that an equivalent xmlparse is occuring somewhere else. It seems I must use the gutenprint package for an acceptable driver for my Cannon MX 920 printer, so uninstalling it is not an option for me.
Perhaps removing all of the printers I don't need from the xml file itself is a possible solution. Shooting in the dark, I tried removing the extraneous printers from the xml files located at /usr/share/foomatic/db/source/driver/gutenprint-ijs.5.2.xml and /usr/share/foomatic/db/source/driver/gutenprint-ijs-simplified.5.2.xml and /usr/share/gutenprint/5.2/xml/printers.xml. However, that did not solve the extended high-cpu demand that occurs with administrative tasks. I have subsequently restored my original files. Perhaps I am looking in the wrong xml file... but darned if I can find another. More likely, I'm simply over my head.
Here is another quandry that is perhaps related. The printer is on the LAN. To see it, I start the following services: avahi-daemon.service, org.cups.cupsd.service, and cups-browsed.service. I used to have these enabled at boot but now I deliberately start them when I need to print and stop them when finished. The reason I do this is that I have found that, at shutdown, I get a hung avahi stop job about 5% of the time when these three services are running, For me, explicily starting/stopping the services is not a nuisance but there are several other Arch users on the network with independent installs that have the same random stop job hang.
Offline
Happy New Year everybody!
Had the same problem here with a Brother HL-2035 on USB2 with cups 2.0.1-1 installed.
Removing gutenprint doesn't change anything, instead modifying /etc/cups/client.conf as mentioned before (#22) was the solution for me.
Modifying /etc/cups/client.conf worked for me, see this post on another thread https://bbs.archlinux.org/viewtopic.php … 6#p1482856
Now the high CPU usage is back to normal, when:
- switching the printer on
- printing
- performing certain printer commands (i.e. lpinfo -v)
However when I'm administrating the printer via localhost:631 the CPU uses still about 96%.
Last edited by bebo42 (2015-01-04 12:39:13)
Offline
I had another look at this issue on my machine. Firstly I uninstalled gutenprint as it was not needed for my printer (Samsung MFP) but that made no difference to the high CPU issue. Then I stopped the org.cups.cupsd service that had been started by the org.cups.cupsd.socket when the printer had been switched on (and which led to the 100% CPU issue).
With the org.cups.cupsd service stopped I edited /etc/cups/client.conf to have
# see 'man client.conf'
#ServerName /run/cups/cups.sock # alternative: ServerName hostname-or-ip-address[:port] of a remote server
ServerName localhost:631
and then did
systemctl --system daemon-reload
Then since the change to the file above would presumably then not have socket activation any more I started the org.cups.cupsd service with systemctl. There was no longer any pegging of the CPU at 100%. Setting a print did start the printer which then whirred for around 20 seconds before the print came out but it printed fine with no CPU load at 100%. I also checked that going to localhost:631 in a browser worked fine, and that checking the printer on that web cups interface worked fine without high CPU load.
However if I stop the org.cups.cupsd service then switch off the printer and back on then the socket activation no longer works - but restarting org.cups.cupsd service works fine with no further 100% CPU issues.
So I don't know if this seems to point at the socket activation causing a problem which is avoided by changing the client.conf file to look at localhost:631? If so then presumably the workaround is to disable via systemctl org.cups.cupsd.socket and enable org.cups.cupsd.service so that the cups service runs at boot but socket activation is no longer running?
Perhaps some more investigation into this looking at whether switching socket activation back on brings the problems back might be worthwhile? Also is there any issue with the way the service files have been written for cups socket activation that may be behind this problem?
Last edited by mcloaked (2015-01-04 15:20:58)
Mike C
Offline
This is possibly related but needs more research into the connection with the bug in this thread, if any, since this is from almost a year ago:
Mike C
Offline
I dont have the foomatic-db package installed and do not have a /usr/lib/cups/driver/foomatic file or a /usr/lib/perl5/vendor_perl/Foomatic directory.
That file and directory are owned by foomatic-db-engine.
As for foomatic, I think it works something like this:
* The foomatic-db-engine package installs some sort of "driver interface" for CUPS that generates printer PPD files from XML. It also provides its own print spooler.
* The foomatic-db packages contains printer and driver information stored as XML. The package also contains pre-compiled PPD files for CUPS, so foomatic-db-engine is not requiered if you use CUPS.
* Some driver packages like hplip require foomatic-db-engine, maybe in order to generate some of the PPD files for CUPS (I don't know).
Looking at the gutenprint package:
* According to optional dependencies, both cups and foomatic-db-engine are supported spoolers, i.e. foomatic-db-engine is not required.
* The package contains XML files for both foomatic and gutenprint, but also pre-compiled PPD files for CUPS.
My guess is gutenprint shouldn't have to parse the XML because it provides its own PPD files for CUPS.
Problems arise when gutenprint is installed alongside both CUPS and foomatic-db-engine, because the foomatic-db-engine driver interface for CUPS will try to parse all the XML from gutenprint to generate PPD files.
So I assume, if the loop through the models is the culprit, that an equivalent xmlparse is occuring somewhere else.
I would be surprised if there was some sort of equivalent XML parsing in gutenprint, as gutenprint already contains gzipped PPDs, and AFAIK it does not try to implement a spooler system like foomatic-db-engine.
Even if you had foomatic-db (not -engine) installed, this package only contains XML for foomatic itself (not gutenprint), so it seems unlikely that gutenprint should have the same problem of trying to generate PPDs from it.
Perhaps removing all of the printers I don't need from the xml file itself is a possible solution. Shooting in the dark, I tried removing the extraneous printers from the xml files located at /usr/share/foomatic/db/source/driver/gutenprint-ijs.5.2.xml and /usr/share/foomatic/db/source/driver/gutenprint-ijs-simplified.5.2.xml and /usr/share/gutenprint/5.2/xml/printers.xml. However, that did not solve the extended high-cpu demand that occurs with administrative tasks. I have subsequently restored my original files. Perhaps I am looking in the wrong xml file... but darned if I can find another. More likely, I'm simply over my head.
If foomatic-db-engine is not installed on your system, you are not experiencing the exact same problem as me (/usr/lib/cups/driver/foomatic).
If you remove the gutenprint XML schemas located under /usr/share/foomatic/db/source/.... (look at "pacman -Ql gutenprint"), I guess this should indeed stop foomatic-db-engine from wreaking havoc and just let CUPS use the pre-compiled PPD files provided by gutenprint. But again, with foomatic-db-engine not installed on your system, these XML files should not even be in use.
If you use "top" and press [c] to toggle full command display, which process(es) consume all the CPU during administrative tasks?
Here is another quandry that is perhaps related. The printer is on the LAN. To see it, I start the following services: avahi-daemon.service, org.cups.cupsd.service, and cups-browsed.service. I used to have these enabled at boot but now I deliberately start them when I need to print and stop them when finished. The reason I do this is that I have found that, at shutdown, I get a hung avahi stop job about 5% of the time when these three services are running, For me, explicily starting/stopping the services is not a nuisance but there are several other Arch users on the network with independent installs that have the same random stop job hang.
This sounds like a completely different bug - something like the stuff @mcloaked is onto.
Last edited by tachy (2015-01-05 11:17:15)
Offline
I have a samsung ml2165w
The 100% cpu usage starts when I power off the printer... I have to stop or restart the service...
Testing the https://bbs.archlinux.org/viewtopic.php … 6#p1482856 changes now....
https://bugs.archlinux.org/task/42666
SOLUTION
to modify /etc/cups/client.conf
remove ServerName /run/cups/cups.sock and replace it with ServerName localhost:631
PD: it seems to work for me... printed a few pages, then powered it off... and no 100% cpu
PD2: no... it happened again today... lol
Last edited by luuuciano (2015-01-11 17:08:25)
I arch, you arch, he arch, she arch, we arch, they arch...
Offline
Hello all!
I had the same problem plus some after the last system upgrade. I managed to partially fix part of them but high cpu usage still persists plus the printer that used to work without a problem before the upgrade (Brother HL-2270DW, network) is not working anymore, usb hp printer is uneffected. I deleted the Brother printer, tried to reinstall it but cups could not find printer drivers although the standard ones with gutenprint and foomatic plus hl2280 from AUR were installed (I tried to reinstall it both manually and through web-interface). After playing with it for a few days, following all the advice I could find online I managed to re-install the printer but only as a usb one. When I modify it as a network (lpd or dnssd) with the same driver as for usb (hl2280) I get a message "unable to locate the printer".
As result of the last two days I don't have foomatic-db-engine.
Another thing that I found is
$ lpq
lpq: Unable to connect to server.
$ lpr /home/file.pdf
lpr: Error - scheduler not responding.
I cannot print any files but the test page, and on web-interface it doesn't show that I even sent a file to print. When I tried to send a file to print from FireFox at first it was getting printer information for a few minutes and then FF crushed, now it doesn't show Brother printer available, I can only print to file from FF. Okular gives me the list of all printers, sends file to print but actually nothing happens, the job doesn't appear in the job list.
Offline
On the cpu, my client.conf has the fix applied, but I still get the high cpu on administrative tasks.
On the missing printer:
My cannon network printer went missing in a similar fashion. I then assigned it a static ip and changed my printer connection to:
lpd://<printerIP>/PASSTHRU
Not sure why the dnssd connection stopped working, but the work-around is fine by me.
Offline
I don't think I'm having only printer problems because of lpr and lpq messages, to me it looks like the issue with cups rather than a printer.
Offline
If anyone can add diagnostic data to the bug reports at https://bugs.archlinux.org/task/42666 and/or https://www.cups.org/str.php?L4521+P-1+S-2+C0+I0+E0+Q then it would likely gain more traction towards a fix than posting here.
Mike C
Offline
I have 2 archlinux boxes. One recently updated, the other not. The first box had the high cpu problem, the other not. Comparing installed package I found the only difference was cups-filters. So I rolled back to cups-filters-1.0.61-3-x86_64.pkg.tar.xz and I have no more high cpu in the first box.
Maybe the problem is caused by cups-filters-1.0.61-4-x86_64.pkg.tar.xz.
Offline
cups-filters 1.0.61-4 was a simple .so rebuild against poppler 0.29.0 - this shouldn't cause any harm and any older version should give missing .so link error.
But for sure cups-filters could cause the load due to a different reason.
Last edited by AndyRTR (2015-01-15 20:11:29)
Offline
Tks for your answer, AndyRTR.
I confirm I'm running cups-filters 1.0.61-3 without erros:
[srs@localhost ~]$ pacman -Qs |grep cups
local/cups 2.0.1-1
local/cups-filters 1.0.61-3
local/cups-pk-helper 0.2.5-1
local/libcups 2.0.1-1
But I'm sorry. The high cpu problem was not solved, but you can hardly notice it because, when you ask for finding printer, it comes immediately. One cpu is loaded up to 100% shared between System and User for 3 our 4 minutes. Using 1.0.61-4, my printer was never found and the cpu load goes up to 100% for more than 10 minutes.
Tks again, and if you feel I can be in any help, please, let me know. I can, for instance, build up a virtual machine for testing.
Offline
Can somebody confirm if old cups-filters 1.0.61-3 solves all high load issues? Then this might be cause by miscompilation.
( I wonder how cups-filters can be involved when adding new printers - isn't the filters stuff only used when translating between the document and printer language? )
Offline
I'm running cups-filters 1.0.62-1 now and having the same behavior as 1.0.61-3. That is:
- cups can find my printer, so it is fine.
- high cpu still occurs but for "only" 3-4 minutes on one of the cpus (i run a Core I5). This can't be noticed as the all system does not slow down.
I listed the files been accessed during the high cpu load, if it can be in any help. See bellow.
I thank you again for concerning about my post.
[srs@localhost ~]$ sudo lsof -p 364
lsof: WARNING: can't stat() fuse.gvfsd-fuse file system /run/user/1000/gvfs
Output information may be incomplete.
COMMAND PID USER FD TYPE DEVICE SIZE/OFF NODE NAME
cupsd 364 root cwd DIR 8,3 4096 2 /
cupsd 364 root rtd DIR 8,3 4096 2 /
cupsd 364 root txt REG 8,3 403248 306879 /usr/bin/cupsd
cupsd 364 root mem REG 8,3 51808 263782 /usr/lib/libnss_files-2.20.so
cupsd 364 root mem REG 8,3 35216 271774 /usr/lib/libffi.so.6.0.4
cupsd 364 root mem REG 8,3 488208 271290 /usr/lib/libgmp.so.10.2.0
cupsd 364 root mem REG 8,3 191960 278982 /usr/lib/libhogweed.so.2.5
cupsd 364 root mem REG 8,3 187144 278984 /usr/lib/libnettle.so.4.7
cupsd 364 root mem REG 8,3 76272 278402 /usr/lib/libtasn1.so.6.3.2
cupsd 364 root mem REG 8,3 417008 278412 /usr/lib/libp11-kit.so.0.1.0
cupsd 364 root mem REG 8,3 14568 270701 /usr/lib/libkeyutils.so.1.5
cupsd 364 root mem REG 8,3 52208 270792 /usr/lib/libkrb5support.so.0.1
cupsd 364 root mem REG 8,3 1185568 280022 /usr/lib/libgnutls.so.28.41.3
cupsd 364 root mem REG 8,3 89024 263781 /usr/lib/libresolv-2.20.so
cupsd 364 root mem REG 8,3 72264 272054 /usr/lib/libgpg-error.so.0.13.0
cupsd 364 root mem REG 8,3 919960 272067 /usr/lib/libgcrypt.so.20.0.2
cupsd 364 root mem REG 8,3 43264 272081 /usr/lib/liblz4.so.1.5.0
cupsd 364 root mem REG 8,3 141744 271954 /usr/lib/liblzma.so.5.0.8
cupsd 364 root mem REG 8,3 31760 263819 /usr/lib/librt-2.20.so
cupsd 364 root mem REG 8,3 17320 271334 /usr/lib/libcap.so.2.24
cupsd 364 root mem REG 8,3 18736 271191 /usr/lib/libattr.so.1.1.0
cupsd 364 root mem REG 8,3 14672 263780 /usr/lib/libdl-2.20.so
cupsd 364 root mem REG 8,3 39280 263824 /usr/lib/libcrypt-2.20.so
cupsd 364 root mem REG 8,3 1067456 263807 /usr/lib/libm-2.20.so
cupsd 364 root mem REG 8,3 88592 266881 /usr/lib/libz.so.1.2.8
cupsd 364 root mem REG 8,3 14632 267061 /usr/lib/libcom_err.so.2.1
cupsd 364 root mem REG 8,3 199504 270790 /usr/lib/libk5crypto.so.3.1
cupsd 364 root mem REG 8,3 937552 270768 /usr/lib/libkrb5.so.3.3
cupsd 364 root mem REG 8,3 1984416 263808 /usr/lib/libc-2.20.so
cupsd 364 root mem REG 8,3 138248 263787 /usr/lib/libpthread-2.20.so
cupsd 364 root mem REG 8,3 313696 270787 /usr/lib/libgssapi_krb5.so.2.2
cupsd 364 root mem REG 8,3 508568 288693 /usr/lib/libcups.so.2
cupsd 364 root mem REG 8,3 68656 288605 /usr/lib/libavahi-client.so.3.2.9
cupsd 364 root mem REG 8,3 52392 288608 /usr/lib/libavahi-common.so.3.5.3
cupsd 364 root mem REG 8,3 298856 271592 /usr/lib/libdbus-1.so.3.8.9
cupsd 364 root mem REG 8,3 35384 271226 /usr/lib/libacl.so.1.1.0
cupsd 364 root mem REG 8,3 15896 295229 /usr/lib/libpaper.so.1.1.2
cupsd 364 root mem REG 8,3 55896 270840 /usr/lib/libpam.so.0.83.1
cupsd 364 root mem REG 8,3 23872 288696 /usr/lib/libcupsmime.so.1
cupsd 364 root mem REG 8,3 164104 263784 /usr/lib/ld-2.20.so
cupsd 364 root mem REG 8,3 1607616 283841 /usr/lib/locale/locale-archive
cupsd 364 root mem REG 8,3 158464 272101 /usr/lib/libsystemd.so.0.5.1
cupsd 364 root 0r CHR 1,3 0t0 1028 /dev/null
cupsd 364 root 1u unix 0xffff8800d14bbb80 0t0 11122 type=STREAM
cupsd 364 root 2u unix 0xffff8800d14bbb80 0t0 11122 type=STREAM
cupsd 364 root 3u unix 0xffff8800d5175180 0t0 12791 /run/cups/cups.sock type=STREAM
cupsd 364 root 4r CHR 1,9 0t0 1033 /dev/urandom
cupsd 364 root 5u a_inode 0,9 0 6748 [eventpoll]
cupsd 364 root 6u REG 8,3 2705 814085 /var/log/cups/access_log
cupsd 364 root 7u REG 8,3 0 815935 /var/log/cups/error_log
cupsd 364 root 8u REG 8,3 0 806465 /var/log/cups/page_log
cupsd 364 root 9r REG 8,3 68 1044074 /etc/papersize
cupsd 364 root 10u unix 0xffff8800d5d8fb80 0t0 13711 type=STREAM
cupsd 364 root 11u IPv6 12972 0t0 TCP localhost.localdomain:ipp (LISTEN)
cupsd 364 root 12u IPv4 12973 0t0 TCP localhost.localdomain:ipp (LISTEN)
cupsd 364 root 13r FIFO 0,8 0t0 12974 pipe
cupsd 364 root 14w FIFO 0,8 0t0 12974 pipe
cupsd 364 root 15u IPv6 66623 0t0 TCP localhost.localdomain:ipp->localhost.localdomain:45774 (ESTABLISHED)
cupsd 364 root 19r FIFO 0,8 0t0 23884 pipe
cupsd 364 root 20w FIFO 0,8 0t0 23884 pipe
cupsd 364 root 21u unix 0xffff88009598fb80 0t0 65918 /run/cups/cups.sock type=STREAM
cupsd 364 root 22w FIFO 0,8 0t0 23885 pipe
cupsd 364 root 23w FIFO 0,8 0t0 23886 pipe
Last edited by silviosa (2015-01-19 12:03:27)
Offline
What solved this same issue for me was to remove the Foomatic drivers.
Offline
i just want to add that i too have been facing this issue for awhile. on both my arch laptop and my arch desktop.
i've tried all the recommendations here but still get 100% cpu usage if it has to find my printer or if i have to administrate it.
i can't even print. it gets stuck with cannot locate printer. tried via usb and ethernet. the prior cups version worked. cups has worked with this printer for three years.
right now i have to boot into my hackintosh hard drive on my desktop to print stuff. this is incredibly annoying.
i tried looking in the aur for the previous 1.x version of cups but don't see it. if someone still has all the libs including 32bit cups 1.x, could you upload it to the aur?
Last edited by orlfman (2015-01-25 15:22:45)
Offline
EDIT: Deleted irrelevant jabbering...
I'm also affected by this bug, and I kept looking around for a solution.
CPU load is at 100%, when adding or modifying printers.
EDIT2:
The CPU load hits the roof when cupsd loads the backends, which only happens when one modifies or adds a printer.
Log:
D [25/Jan/2015:23:47:31 +0100] [cups-deviced] Started backend /usr/lib/cups/backend/snmp (PID 8865)
D [25/Jan/2015:23:47:31 +0100] [cups-deviced] Started backend /usr/lib/cups/backend/http (PID 8866)
D [25/Jan/2015:23:47:31 +0100] [cups-deviced] Started backend /usr/lib/cups/backend/usb (PID 8867)
D [25/Jan/2015:23:47:31 +0100] [cups-deviced] Started backend /usr/lib/cups/backend/dnssd (PID 8868)
D [25/Jan/2015:23:47:31 +0100] [cups-deviced] Started backend /usr/lib/cups/backend/socket (PID 8869)
D [25/Jan/2015:23:47:31 +0100] [cups-deviced] Started backend /usr/lib/cups/backend/https (PID 8870)
D [25/Jan/2015:23:47:31 +0100] [cups-deviced] Started backend /usr/lib/cups/backend/ipp (PID 8871)
D [25/Jan/2015:23:47:31 +0100] [cups-deviced] Started backend /usr/lib/cups/backend/smb (PID 8872)
D [25/Jan/2015:23:47:31 +0100] [cups-deviced] Started backend /usr/lib/cups/backend/serial (PID 8873)
D [25/Jan/2015:23:47:31 +0100] [cups-deviced] Started backend /usr/lib/cups/backend/parallel (PID 8874)
D [25/Jan/2015:23:47:31 +0100] [cups-deviced] Started backend /usr/lib/cups/backend/ipps (PID 8875)
D [25/Jan/2015:23:47:31 +0100] [cups-deviced] Started backend /usr/lib/cups/backend/lpd (PID 8876)
...
The part of the debug log is that involves the "modify printer" event from the web interface:
D [25/Jan/2015:23:55:45 +0100] [Client 1] POST /admin/ HTTP/1.1
D [25/Jan/2015:23:55:45 +0100] cupsdSetBusyState: newbusy="Active clients", busy="Not busy"
D [25/Jan/2015:23:55:45 +0100] [Client 1] Read: status=200
D [25/Jan/2015:23:55:45 +0100] [Client 1] Authorized as root using Basic
D [25/Jan/2015:23:55:45 +0100] [CGI] argv[0] = "/usr/lib/cups/cgi-bin/admin.cgi"
D [25/Jan/2015:23:55:45 +0100] [CGI] envp[0] = "CUPS_CACHEDIR=/var/cache/cups"
D [25/Jan/2015:23:55:45 +0100] [CGI] envp[1] = "CUPS_DATADIR=/usr/share/cups"
D [25/Jan/2015:23:55:45 +0100] [CGI] envp[2] = "CUPS_DOCROOT=/usr/share/cups/doc"
D [25/Jan/2015:23:55:45 +0100] [CGI] envp[3] = "CUPS_FONTPATH=/usr/share/cups/fonts"
D [25/Jan/2015:23:55:45 +0100] [CGI] envp[4] = "CUPS_REQUESTROOT=/var/spool/cups"
D [25/Jan/2015:23:55:45 +0100] [CGI] envp[5] = "CUPS_SERVERBIN=/usr/lib/cups"
D [25/Jan/2015:23:55:45 +0100] [CGI] envp[6] = "CUPS_SERVERROOT=/etc/cups"
D [25/Jan/2015:23:55:45 +0100] [CGI] envp[7] = "CUPS_STATEDIR=/run/cups"
D [25/Jan/2015:23:55:45 +0100] [CGI] envp[8] = "HOME=/var/spool/cups/tmp"
D [25/Jan/2015:23:55:45 +0100] [CGI] envp[9] = "PATH=/usr/lib/cups/filter:/usr/bin:/usr/bin:/bin:/usr/bin"
D [25/Jan/2015:23:55:45 +0100] [CGI] envp[10] = "SERVER_ADMIN=root@Asus-G1s"
D [25/Jan/2015:23:55:45 +0100] [CGI] envp[11] = "SOFTWARE=CUPS/2.0.1"
D [25/Jan/2015:23:55:45 +0100] [CGI] envp[12] = "TMPDIR=/var/spool/cups/tmp"
D [25/Jan/2015:23:55:45 +0100] [CGI] envp[13] = "USER=root"
D [25/Jan/2015:23:55:45 +0100] [CGI] envp[14] = "CUPS_MAX_MESSAGE=2047"
D [25/Jan/2015:23:55:45 +0100] [CGI] envp[15] = "CUPS_SERVER=/run/cups/cups.sock"
D [25/Jan/2015:23:55:45 +0100] [CGI] envp[16] = "CUPS_ENCRYPTION=IfRequested"
D [25/Jan/2015:23:55:45 +0100] [CGI] envp[17] = "IPP_PORT=631"
D [25/Jan/2015:23:55:45 +0100] [CGI] envp[18] = "AUTH_TYPE=Basic"
D [25/Jan/2015:23:55:45 +0100] [CGI] envp[19] = "LANG=en_GB.UTF8"
D [25/Jan/2015:23:55:45 +0100] [CGI] envp[20] = "REDIRECT_STATUS=1"
D [25/Jan/2015:23:55:45 +0100] [CGI] envp[21] = "GATEWAY_INTERFACE=CGI/1.1"
D [25/Jan/2015:23:55:45 +0100] [CGI] envp[22] = "SERVER_NAME=localhost"
D [25/Jan/2015:23:55:45 +0100] [CGI] envp[23] = "SERVER_PORT=631"
D [25/Jan/2015:23:55:45 +0100] [CGI] envp[24] = "REMOTE_ADDR=[v1.::1]"
D [25/Jan/2015:23:55:45 +0100] [CGI] envp[25] = "REMOTE_HOST=localhost"
D [25/Jan/2015:23:55:45 +0100] [CGI] envp[26] = "SCRIPT_NAME=/admin/"
D [25/Jan/2015:23:55:45 +0100] [CGI] envp[27] = "SCRIPT_FILENAME=/usr/share/cups/doc/admin/"
D [25/Jan/2015:23:55:45 +0100] [CGI] envp[28] = "REMOTE_USER=root"
D [25/Jan/2015:23:55:45 +0100] [CGI] envp[29] = "SERVER_PROTOCOL=HTTP/1.1"
D [25/Jan/2015:23:55:45 +0100] [CGI] envp[30] = "HTTP_COOKIE=org.cups.sid=04951f85c145f061780680dd6d36ab3e"
D [25/Jan/2015:23:55:45 +0100] [CGI] envp[31] = "HTTP_USER_AGENT=Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/39.0.2171.27 Safari/537.36"
D [25/Jan/2015:23:55:45 +0100] [CGI] envp[32] = "HTTP_REFERER=http://localhost:631/printers/Brother_MFC-620CN"
D [25/Jan/2015:23:55:45 +0100] [CGI] envp[33] = "REQUEST_METHOD=POST"
D [25/Jan/2015:23:55:45 +0100] [CGI] envp[34] = "CONTENT_LENGTH=94"
D [25/Jan/2015:23:55:45 +0100] [CGI] envp[35] = "CONTENT_TYPE=application/x-www-form-urlencoded"
D [25/Jan/2015:23:55:45 +0100] cupsdAddCert: Adding certificate for PID 15600
D [25/Jan/2015:23:55:45 +0100] [CGI] Started /usr/lib/cups/cgi-bin/admin.cgi (PID 15600)
I [25/Jan/2015:23:55:45 +0100] [Client 1] Started "/usr/lib/cups/cgi-bin/admin.cgi" (pid=15600, file=16)
D [25/Jan/2015:23:55:45 +0100] [Client 1] Waiting for CGI data.
D [25/Jan/2015:23:55:45 +0100] [CGI] admin.cgi started...
D [25/Jan/2015:23:55:45 +0100] [Client 5] Accepted from localhost (Domain)
D [25/Jan/2015:23:55:45 +0100] [Client 5] Waiting for request.
D [25/Jan/2015:23:55:45 +0100] [CGI] http=0x7f1f52f49490
D [25/Jan/2015:23:55:45 +0100] [CGI] cgiSetVariable: SECTION="admin"
D [25/Jan/2015:23:55:45 +0100] [CGI] cgiSetVariable: REFRESH_PAGE=""
D [25/Jan/2015:23:55:45 +0100] [CGI] org.cups.sid cookie is "04951f85c145f061780680dd6d36ab3e"
D [25/Jan/2015:23:55:45 +0100] [CGI] cgiSetVariable: org.cups.sid="04951f85c145f061780680dd6d36ab3e"
D [25/Jan/2015:23:55:45 +0100] [CGI] cgiSetVariable: printer_name="Brother_MFC-620CN"
D [25/Jan/2015:23:55:45 +0100] [CGI] cgiSetVariable: OP="modify-printer"
D [25/Jan/2015:23:55:45 +0100] [CGI] op="modify-printer"...
D [25/Jan/2015:23:55:45 +0100] [CGI] do_am_printer: DEVICE_URI="(null)"
D [25/Jan/2015:23:55:45 +0100] [Client 5] POST / HTTP/1.1
D [25/Jan/2015:23:55:45 +0100] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [25/Jan/2015:23:55:45 +0100] [Client 5] Read: status=200
D [25/Jan/2015:23:55:45 +0100] [Client 5] No authentication data provided.
D [25/Jan/2015:23:55:45 +0100] [Client 5] Read: status=100
D [25/Jan/2015:23:55:45 +0100] [Client 5] Read: status=100
D [25/Jan/2015:23:55:45 +0100] [Client 5] Read: status=100
D [25/Jan/2015:23:55:45 +0100] [Client 5] Read: status=100
D [25/Jan/2015:23:55:45 +0100] [Client 5] Read: status=100
D [25/Jan/2015:23:55:45 +0100] [Client 5] 2.0 Get-Printer-Attributes 1
D [25/Jan/2015:23:55:45 +0100] Get-Printer-Attributes ipp://localhost/printers/Brother_MFC-620CN
D [25/Jan/2015:23:55:45 +0100] [Client 5] Returning IPP successful-ok for Get-Printer-Attributes (ipp://localhost/printers/Brother_MFC-620CN) from localhost
D [25/Jan/2015:23:55:45 +0100] [Client 5] Content-Length: 10078
D [25/Jan/2015:23:55:45 +0100] [Client 5] cupsdSendHeader: code=200, type="application/ipp", auth_type=0
D [25/Jan/2015:23:55:45 +0100] [Client 5] con->http=0x7fc279b35ef0
D [25/Jan/2015:23:55:45 +0100] [Client 5] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=10078, response=0x7fc279aeb6b0(IPP_STATE_DATA), pipe_pid=0, file=-1
D [25/Jan/2015:23:55:45 +0100] [Client 5] Writing IPP response, ipp_state=IPP_STATE_DATA, old wused=0, new wused=0
D [25/Jan/2015:23:55:45 +0100] [Client 5] bytes=0, http_state=0, data_remaining=10078
D [25/Jan/2015:23:55:45 +0100] [Client 5] Flushing write buffer.
D [25/Jan/2015:23:55:45 +0100] [Client 5] New state is HTTP_STATE_WAITING
D [25/Jan/2015:23:55:45 +0100] [Client 5] Waiting for request.
D [25/Jan/2015:23:55:45 +0100] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [25/Jan/2015:23:55:45 +0100] [CGI] cgiSetVariable: CURRENT_DEVICE_URI="dnssd://Brother%20MFC-620CN%20(BRN_63AEC8_P1)._pdl-datastream._tcp.local/"
D [25/Jan/2015:23:55:45 +0100] [CGI] cgiSetVariable: CURRENT_DEVICE_SCHEME="dnssd"
D [25/Jan/2015:23:55:45 +0100] [CGI] Getting list of devices...
D [25/Jan/2015:23:55:45 +0100] [Client 5] POST / HTTP/1.1
D [25/Jan/2015:23:55:45 +0100] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [25/Jan/2015:23:55:45 +0100] [Client 5] Read: status=200
D [25/Jan/2015:23:55:45 +0100] [Client 5] No authentication data provided.
D [25/Jan/2015:23:55:45 +0100] [Client 5] Read: status=100
D [25/Jan/2015:23:55:45 +0100] [Client 5] Read: status=100
D [25/Jan/2015:23:55:45 +0100] [Client 5] Read: status=100
D [25/Jan/2015:23:55:45 +0100] [Client 5] Read: status=100
D [25/Jan/2015:23:55:45 +0100] [Client 5] Read: status=100
D [25/Jan/2015:23:55:45 +0100] [Client 5] 2.0 CUPS-Get-Devices 2
D [25/Jan/2015:23:55:45 +0100] CUPS-Get-Devices
D [25/Jan/2015:23:55:45 +0100] cupsdIsAuthorized: username=""
D [25/Jan/2015:23:55:45 +0100] [Client 5] Returning HTTP Unauthorized for CUPS-Get-Devices (no URI) from localhost
D [25/Jan/2015:23:55:45 +0100] [Client 5] cupsdSendHeader: code=401, type="text/html", auth_type=0
D [25/Jan/2015:23:55:45 +0100] [Client 5] WWW-Authenticate: Basic realm="CUPS", trc="y"
D [25/Jan/2015:23:55:45 +0100] [Client 6] Accepted from localhost (Domain)
D [25/Jan/2015:23:55:45 +0100] [Client 6] Waiting for request.
D [25/Jan/2015:23:55:45 +0100] [Client 7] Accepted from localhost (Domain)
D [25/Jan/2015:23:55:45 +0100] [Client 7] Waiting for request.
D [25/Jan/2015:23:55:45 +0100] [Client 6] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [25/Jan/2015:23:55:45 +0100] [Client 6] Closing connection.
D [25/Jan/2015:23:55:45 +0100] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [25/Jan/2015:23:55:45 +0100] [Client 8] Accepted from localhost (Domain)
D [25/Jan/2015:23:55:45 +0100] [Client 8] Waiting for request.
D [25/Jan/2015:23:55:45 +0100] [Client 7] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [25/Jan/2015:23:55:45 +0100] [Client 7] Closing connection.
D [25/Jan/2015:23:55:45 +0100] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [25/Jan/2015:23:55:45 +0100] [Client 8] POST / HTTP/1.1
D [25/Jan/2015:23:55:45 +0100] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [25/Jan/2015:23:55:45 +0100] [Client 8] Read: status=200
D [25/Jan/2015:23:55:45 +0100] [Client 8] Authorized as root using Local
D [25/Jan/2015:23:55:45 +0100] [Client 8] 2.0 CUPS-Get-Devices 2
D [25/Jan/2015:23:55:45 +0100] CUPS-Get-Devices
D [25/Jan/2015:23:55:45 +0100] cupsdIsAuthorized: username="root"
D [25/Jan/2015:23:55:45 +0100] [CGI] argv[0] = "/usr/lib/cups/daemon/cups-deviced"
D [25/Jan/2015:23:55:45 +0100] [CGI] argv[1] = "2"
D [25/Jan/2015:23:55:45 +0100] [CGI] argv[2] = "0"
D [25/Jan/2015:23:55:45 +0100] [CGI] argv[3] = "5"
D [25/Jan/2015:23:55:45 +0100] [CGI] argv[4] = "2"
D [25/Jan/2015:23:55:45 +0100] [CGI] argv[5] = "requested-attributes=all"
D [25/Jan/2015:23:55:45 +0100] [CGI] envp[0] = "CUPS_CACHEDIR=/var/cache/cups"
D [25/Jan/2015:23:55:45 +0100] [CGI] envp[1] = "CUPS_DATADIR=/usr/share/cups"
D [25/Jan/2015:23:55:45 +0100] [CGI] envp[2] = "CUPS_DOCROOT=/usr/share/cups/doc"
D [25/Jan/2015:23:55:45 +0100] [CGI] envp[3] = "CUPS_FONTPATH=/usr/share/cups/fonts"
D [25/Jan/2015:23:55:45 +0100] [CGI] envp[4] = "CUPS_REQUESTROOT=/var/spool/cups"
D [25/Jan/2015:23:55:45 +0100] [CGI] envp[5] = "CUPS_SERVERBIN=/usr/lib/cups"
D [25/Jan/2015:23:55:45 +0100] [CGI] envp[6] = "CUPS_SERVERROOT=/etc/cups"
D [25/Jan/2015:23:55:45 +0100] [CGI] envp[7] = "CUPS_STATEDIR=/run/cups"
D [25/Jan/2015:23:55:45 +0100] [CGI] envp[8] = "HOME=/var/spool/cups/tmp"
D [25/Jan/2015:23:55:45 +0100] [CGI] envp[9] = "PATH=/usr/lib/cups/filter:/usr/bin:/usr/bin:/bin:/usr/bin"
D [25/Jan/2015:23:55:45 +0100] [CGI] envp[10] = "SERVER_ADMIN=root@Asus-G1s"
D [25/Jan/2015:23:55:45 +0100] [CGI] envp[11] = "SOFTWARE=CUPS/2.0.1"
D [25/Jan/2015:23:55:45 +0100] [CGI] envp[12] = "TMPDIR=/var/spool/cups/tmp"
D [25/Jan/2015:23:55:45 +0100] [CGI] envp[13] = "USER=root"
D [25/Jan/2015:23:55:45 +0100] [CGI] envp[14] = "CUPS_MAX_MESSAGE=2047"
D [25/Jan/2015:23:55:45 +0100] [CGI] envp[15] = "CUPS_SERVER=/run/cups/cups.sock"
D [25/Jan/2015:23:55:45 +0100] [CGI] envp[16] = "CUPS_ENCRYPTION=IfRequested"
D [25/Jan/2015:23:55:45 +0100] [CGI] envp[17] = "IPP_PORT=631"
D [25/Jan/2015:23:55:45 +0100] [CGI] envp[18] = "AUTH_TYPE=Local"
D [25/Jan/2015:23:55:45 +0100] [CGI] envp[19] = "LANG=en_GB.UTF8"
D [25/Jan/2015:23:55:45 +0100] [CGI] envp[20] = "REDIRECT_STATUS=1"
D [25/Jan/2015:23:55:45 +0100] [CGI] envp[21] = "GATEWAY_INTERFACE=CGI/1.1"
D [25/Jan/2015:23:55:45 +0100] [CGI] envp[22] = "SERVER_NAME=localhost"
D [25/Jan/2015:23:55:45 +0100] [CGI] envp[23] = "SERVER_PORT=631"
D [25/Jan/2015:23:55:45 +0100] [CGI] envp[24] = "REMOTE_ADDR=localhost"
D [25/Jan/2015:23:55:45 +0100] [CGI] envp[25] = "REMOTE_HOST=localhost"
D [25/Jan/2015:23:55:45 +0100] [CGI] envp[26] = "SCRIPT_NAME=/"
D [25/Jan/2015:23:55:45 +0100] [CGI] envp[27] = "SCRIPT_FILENAME=/usr/share/cups/doc/"
D [25/Jan/2015:23:55:45 +0100] [CGI] envp[28] = "REMOTE_USER=root"
D [25/Jan/2015:23:55:45 +0100] [CGI] envp[29] = "SERVER_PROTOCOL=HTTP/1.1"
D [25/Jan/2015:23:55:45 +0100] [CGI] envp[30] = "HTTP_USER_AGENT=CUPS/2.0.1 (Linux 3.18.2-2-ARCH; x86_64) IPP/2.0"
D [25/Jan/2015:23:55:45 +0100] [CGI] envp[31] = "REQUEST_METHOD=POST"
D [25/Jan/2015:23:55:45 +0100] [CGI] envp[32] = "CONTENT_LENGTH=91"
D [25/Jan/2015:23:55:45 +0100] [CGI] envp[33] = "CONTENT_TYPE=application/ipp"
D [25/Jan/2015:23:55:45 +0100] cupsdAddCert: Adding certificate for PID 15601
D [25/Jan/2015:23:55:45 +0100] [CGI] Started /usr/lib/cups/daemon/cups-deviced (PID 15601)
I [25/Jan/2015:23:55:45 +0100] [Client 8] Started "/usr/lib/cups/daemon/cups-deviced" (pid=15601, file=18)
D [25/Jan/2015:23:55:45 +0100] [Client 8] Waiting for CGI data.
D [25/Jan/2015:23:55:45 +0100] [cups-deviced] Started backend /usr/lib/cups/backend/snmp (PID 15602)
D [25/Jan/2015:23:55:45 +0100] [cups-deviced] Started backend /usr/lib/cups/backend/http (PID 15603)
D [25/Jan/2015:23:55:45 +0100] [cups-deviced] Started backend /usr/lib/cups/backend/usb (PID 15604)
D [25/Jan/2015:23:55:45 +0100] [cups-deviced] Started backend /usr/lib/cups/backend/dnssd (PID 15605)
D [25/Jan/2015:23:55:45 +0100] [cups-deviced] Started backend /usr/lib/cups/backend/socket (PID 15606)
D [25/Jan/2015:23:55:45 +0100] [cups-deviced] Started backend /usr/lib/cups/backend/https (PID 15607)
D [25/Jan/2015:23:55:45 +0100] [cups-deviced] Started backend /usr/lib/cups/backend/ipp (PID 15608)
D [25/Jan/2015:23:55:45 +0100] [cups-deviced] Started backend /usr/lib/cups/backend/smb (PID 15609)
D [25/Jan/2015:23:55:45 +0100] [cups-deviced] Started backend /usr/lib/cups/backend/serial (PID 15610)
D [25/Jan/2015:23:55:45 +0100] [cups-deviced] Started backend /usr/lib/cups/backend/parallel (PID 15611)
D [25/Jan/2015:23:55:45 +0100] [cups-deviced] Started backend /usr/lib/cups/backend/ipps (PID 15612)
D [25/Jan/2015:23:55:45 +0100] [cups-deviced] Started backend /usr/lib/cups/backend/lpd (PID 15613)
D [25/Jan/2015:23:55:45 +0100] [Client 8] CGI data ready to be sent.
D [25/Jan/2015:23:55:45 +0100] [CGI] Flushed attributes...
D [25/Jan/2015:23:55:45 +0100] [cups-deviced] Found device "socket"...
D [25/Jan/2015:23:55:45 +0100] [Client 8] con->http=0x7fc279b39100
D [25/Jan/2015:23:55:45 +0100] [Client 8] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=2147483647, response=(nil)(), pipe_pid=15601, file=18
D [25/Jan/2015:23:55:45 +0100] [Client 8] Waiting for CGI data.
D [25/Jan/2015:23:55:45 +0100] [Client 8] Script header: Content-Type: application/ipp
D [25/Jan/2015:23:55:45 +0100] [Client 8] Script header:
D [25/Jan/2015:23:55:45 +0100] [Client 8] Sending status 200 for CGI.
D [25/Jan/2015:23:55:45 +0100] [Client 8] cupsdSendHeader: code=200, type="(null)", auth_type=0
D [25/Jan/2015:23:55:45 +0100] [Client 8] con->http=0x7fc279b39100
D [25/Jan/2015:23:55:45 +0100] [Client 8] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=15601, file=18
D [25/Jan/2015:23:55:45 +0100] [Client 8] Waiting for CGI data.
D [25/Jan/2015:23:55:45 +0100] [Client 8] CGI data ready to be sent.
D [25/Jan/2015:23:55:45 +0100] [CGI] Flushed attributes...
D [25/Jan/2015:23:55:45 +0100] [cups-deviced] Found device "ipps"...
D [25/Jan/2015:23:55:45 +0100] [CGI] Flushed attributes...
D [25/Jan/2015:23:55:45 +0100] [cups-deviced] Found device "lpd"...
D [25/Jan/2015:23:55:45 +0100] [CGI] Flushed attributes...
D [25/Jan/2015:23:55:45 +0100] [cups-deviced] Found device "http"...
D [25/Jan/2015:23:55:45 +0100] [cups-deviced] PID 15603 (http) exited with no errors.
D [25/Jan/2015:23:55:45 +0100] [Client 8] con->http=0x7fc279b39100
D [25/Jan/2015:23:55:45 +0100] [Client 8] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=15601, file=18
D [25/Jan/2015:23:55:45 +0100] [Client 8] Waiting for CGI data.
D [25/Jan/2015:23:55:45 +0100] [Client 8] con->http=0x7fc279b39100
D [25/Jan/2015:23:55:45 +0100] [Client 8] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=15601, file=18
D [25/Jan/2015:23:55:45 +0100] [Client 8] Waiting for CGI data.
D [25/Jan/2015:23:55:45 +0100] [CGI] cgiSetArray: device_class[0]="network"
D [25/Jan/2015:23:55:45 +0100] [CGI] cgiSetArray: device_id[0]=""
D [25/Jan/2015:23:55:45 +0100] [CGI] cgiSetArray: device_info[0]="AppSocket/HP JetDirect"
D [25/Jan/2015:23:55:45 +0100] [CGI] cgiSetArray: device_make_and_model[0]="Unknown"
D [25/Jan/2015:23:55:45 +0100] [CGI] cgiSetArray: device_uri[0]="socket"
D [25/Jan/2015:23:55:45 +0100] [CGI] cgiSetArray: device_location[0]=""
D [25/Jan/2015:23:55:45 +0100] [CGI] cgiSetArray: device_class[1]="network"
D [25/Jan/2015:23:55:45 +0100] [CGI] cgiSetArray: device_id[1]=""
D [25/Jan/2015:23:55:45 +0100] [CGI] cgiSetArray: device_info[1]="Internet Printing Protocol (ipps)"
D [25/Jan/2015:23:55:45 +0100] [CGI] cgiSetArray: device_make_and_model[1]="Unknown"
D [25/Jan/2015:23:55:45 +0100] [CGI] cgiSetArray: device_uri[1]="ipps"
D [25/Jan/2015:23:55:45 +0100] [CGI] cgiSetArray: device_location[1]=""
D [25/Jan/2015:23:55:45 +0100] [CGI] cgiSetArray: device_class[2]="network"
D [25/Jan/2015:23:55:45 +0100] [CGI] cgiSetArray: device_id[2]=""
D [25/Jan/2015:23:55:45 +0100] [CGI] cgiSetArray: device_info[2]="LPD/LPR Host or Printer"
D [25/Jan/2015:23:55:45 +0100] [CGI] cgiSetArray: device_make_and_model[2]="Unknown"
D [25/Jan/2015:23:55:45 +0100] [CGI] cgiSetArray: device_uri[2]="lpd"
D [25/Jan/2015:23:55:45 +0100] [CGI] cgiSetArray: device_location[2]=""
D [25/Jan/2015:23:55:45 +0100] [Client 8] CGI data ready to be sent.
D [25/Jan/2015:23:55:45 +0100] [CGI] Flushed attributes...
D [25/Jan/2015:23:55:45 +0100] [cups-deviced] Found device "https"...
D [25/Jan/2015:23:55:45 +0100] [Client 8] con->http=0x7fc279b39100
D [25/Jan/2015:23:55:45 +0100] [Client 8] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=15601, file=18
D [25/Jan/2015:23:55:45 +0100] [Client 8] Waiting for CGI data.
D [25/Jan/2015:23:55:45 +0100] [cups-deviced] PID 15612 (ipps) exited with no errors.
D [25/Jan/2015:23:55:45 +0100] [cups-deviced] PID 15613 (lpd) exited with no errors.
D [25/Jan/2015:23:55:45 +0100] [cups-deviced] PID 15611 (parallel) exited with no errors.
D [25/Jan/2015:23:55:45 +0100] [CGI] cgiSetArray: device_class[3]="network"
D [25/Jan/2015:23:55:45 +0100] [CGI] cgiSetArray: device_id[3]=""
D [25/Jan/2015:23:55:45 +0100] [CGI] cgiSetArray: device_info[3]="Internet Printing Protocol (http)"
D [25/Jan/2015:23:55:45 +0100] [CGI] cgiSetArray: device_make_and_model[3]="Unknown"
D [25/Jan/2015:23:55:45 +0100] [CGI] cgiSetArray: device_uri[3]="http"
D [25/Jan/2015:23:55:45 +0100] [CGI] cgiSetArray: device_location[3]=""
D [25/Jan/2015:23:55:45 +0100] [Client 8] con->http=0x7fc279b39100
D [25/Jan/2015:23:55:45 +0100] [Client 8] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=15601, file=18
D [25/Jan/2015:23:55:45 +0100] [Client 8] Waiting for CGI data.
D [25/Jan/2015:23:55:45 +0100] [cups-deviced] PID 15607 (https) exited with no errors.
D [25/Jan/2015:23:55:45 +0100] [CGI] Flushed attributes...
D [25/Jan/2015:23:55:45 +0100] [cups-deviced] Found device "smb"...
D [25/Jan/2015:23:55:45 +0100] [Client 8] CGI data ready to be sent.
D [25/Jan/2015:23:55:45 +0100] [Client 8] con->http=0x7fc279b39100
D [25/Jan/2015:23:55:45 +0100] [Client 8] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=15601, file=18
D [25/Jan/2015:23:55:45 +0100] [Client 8] Waiting for CGI data.
D [25/Jan/2015:23:55:45 +0100] [Client 8] con->http=0x7fc279b39100
D [25/Jan/2015:23:55:45 +0100] [Client 8] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=15601, file=18
D [25/Jan/2015:23:55:45 +0100] [Client 8] Waiting for CGI data.
D [25/Jan/2015:23:55:45 +0100] [CGI] cgiSetArray: device_class[4]="network"
D [25/Jan/2015:23:55:45 +0100] [CGI] cgiSetArray: device_id[4]=""
D [25/Jan/2015:23:55:45 +0100] [CGI] cgiSetArray: device_info[4]="Internet Printing Protocol (https)"
D [25/Jan/2015:23:55:45 +0100] [CGI] cgiSetArray: device_make_and_model[4]="Unknown"
D [25/Jan/2015:23:55:45 +0100] [CGI] cgiSetArray: device_uri[4]="https"
D [25/Jan/2015:23:55:45 +0100] [CGI] cgiSetArray: device_location[4]=""
D [25/Jan/2015:23:55:45 +0100] [CGI] Flushed attributes...
D [25/Jan/2015:23:55:45 +0100] [cups-deviced] Found device "ipp"...
D [25/Jan/2015:23:55:45 +0100] [cups-deviced] PID 15609 (smb) exited with no errors.
D [25/Jan/2015:23:55:45 +0100] [Client 8] CGI data ready to be sent.
D [25/Jan/2015:23:55:45 +0100] [Client 8] con->http=0x7fc279b39100
D [25/Jan/2015:23:55:45 +0100] [Client 8] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=15601, file=18
D [25/Jan/2015:23:55:45 +0100] [Client 8] Waiting for CGI data.
D [25/Jan/2015:23:55:45 +0100] [Client 8] con->http=0x7fc279b39100
D [25/Jan/2015:23:55:45 +0100] [Client 8] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=15601, file=18
D [25/Jan/2015:23:55:45 +0100] [Client 8] Waiting for CGI data.
D [25/Jan/2015:23:55:45 +0100] [CGI] cgiSetArray: device_class[5]="network"
D [25/Jan/2015:23:55:45 +0100] [CGI] cgiSetArray: device_id[5]=""
D [25/Jan/2015:23:55:45 +0100] [CGI] cgiSetArray: device_info[5]="Windows Printer via SAMBA"
D [25/Jan/2015:23:55:45 +0100] [CGI] cgiSetArray: device_make_and_model[5]="Unknown"
D [25/Jan/2015:23:55:45 +0100] [CGI] cgiSetArray: device_uri[5]="smb"
D [25/Jan/2015:23:55:45 +0100] [CGI] cgiSetArray: device_location[5]=""
D [25/Jan/2015:23:55:45 +0100] [CGI] Loading USB quirks from "/usr/share/cups/usb".
D [25/Jan/2015:23:55:45 +0100] [cups-deviced] PID 15608 (ipp) exited with no errors.
D [25/Jan/2015:23:55:45 +0100] [cups-deviced] PID 15606 (socket) exited with no errors.
D [25/Jan/2015:23:55:45 +0100] [cups-deviced] PID 15610 (serial) exited with no errors.
D [25/Jan/2015:23:55:45 +0100] [CGI] Loaded 71 quirks.
D [25/Jan/2015:23:55:45 +0100] [CGI] list_devices
D [25/Jan/2015:23:55:45 +0100] [CGI] libusb_get_device_list=11
D [25/Jan/2015:23:55:45 +0100] [cups-deviced] PID 15604 (usb) exited with no errors.
D [25/Jan/2015:23:55:46 +0100] [CGI] sent=0, count=0
D [25/Jan/2015:23:55:47 +0100] [CGI] Querying "Brother\032MFC-620CN\032\040BRN_63AEC8_P1\041._pdl-datastream._tcp.local"...
D [25/Jan/2015:23:55:47 +0100] [CGI] Querying "Brother\032MFC-620CN\032\040BRN_63AEC8_P1\041._printer._tcp.local"...
D [25/Jan/2015:23:55:47 +0100] [CGI] sent=0, count=2
D [25/Jan/2015:23:55:47 +0100] [cups-deviced] PID 15602 (snmp) exited with no errors.
D [25/Jan/2015:23:55:47 +0100] [CGI] sent=2, count=2
D [25/Jan/2015:23:55:47 +0100] [Client 8] CGI data ready to be sent.
D [25/Jan/2015:23:55:47 +0100] [CGI] Flushed attributes...
D [25/Jan/2015:23:55:47 +0100] [cups-deviced] Found device "dnssd://Brother%20MFC-620CN%20(BRN_63AEC8_P1)._printer._tcp.local/"...
D [25/Jan/2015:23:55:47 +0100] [cups-deviced] PID 15605 (dnssd) exited with no errors.
D [25/Jan/2015:23:55:47 +0100] [Client 8] con->http=0x7fc279b39100
D [25/Jan/2015:23:55:47 +0100] [Client 8] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=15601, file=18
D [25/Jan/2015:23:55:47 +0100] [Client 8] Waiting for CGI data.
D [25/Jan/2015:23:55:47 +0100] [CGI] cgiSetArray: device_class[6]="network"
D [25/Jan/2015:23:55:47 +0100] [CGI] cgiSetArray: device_id[6]=""
D [25/Jan/2015:23:55:47 +0100] [CGI] cgiSetArray: device_info[6]="Internet Printing Protocol (ipp)"
D [25/Jan/2015:23:55:47 +0100] [CGI] cgiSetArray: device_make_and_model[6]="Unknown"
D [25/Jan/2015:23:55:47 +0100] [CGI] cgiSetArray: device_uri[6]="ipp"
D [25/Jan/2015:23:55:47 +0100] [CGI] cgiSetArray: device_location[6]=""
D [25/Jan/2015:23:55:47 +0100] [CGI] cgiSetArray: device_class[7]="network"
D [25/Jan/2015:23:55:47 +0100] [CGI] cgiSetArray: device_id[7]=""
D [25/Jan/2015:23:55:47 +0100] [CGI] cgiSetArray: device_info[7]="Brother MFC-620CN (BRN_63AEC8_P1)"
D [25/Jan/2015:23:55:47 +0100] [CGI] cgiSetArray: device_make_and_model[7]="unknown"
D [25/Jan/2015:23:55:47 +0100] [CGI] cgiSetArray: device_uri[7]="dnssd://Brother%20MFC-620CN%20(BRN_63AEC8_P1)._printer._tcp.local/"
D [25/Jan/2015:23:55:47 +0100] [CGI] cgiSetArray: device_location[7]=""
D [25/Jan/2015:23:55:47 +0100] [Client 8] con->http=0x7fc279b39100
D [25/Jan/2015:23:55:47 +0100] [Client 8] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=15601, file=18
D [25/Jan/2015:23:55:47 +0100] [Client 8] Waiting for CGI data.
D [25/Jan/2015:23:55:47 +0100] [Client 8] CGI data ready to be sent.
D [25/Jan/2015:23:55:47 +0100] [Client 8] con->http=0x7fc279b39100
D [25/Jan/2015:23:55:47 +0100] [Client 8] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=15601, file=18
D [25/Jan/2015:23:55:47 +0100] [Client 8] Waiting for CGI data.
D [25/Jan/2015:23:55:47 +0100] [Client 8] Sending 0-length chunk.
D [25/Jan/2015:23:55:47 +0100] [Client 8] Flushing write buffer.
D [25/Jan/2015:23:55:47 +0100] [Client 8] New state is HTTP_STATE_WAITING
D [25/Jan/2015:23:55:47 +0100] [Client 8] Waiting for request.
D [25/Jan/2015:23:55:47 +0100] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [25/Jan/2015:23:55:47 +0100] PID 15601 (/usr/lib/cups/daemon/cups-deviced) exited with no errors.
D [25/Jan/2015:23:55:47 +0100] [CGI] Got device list!
D [25/Jan/2015:23:55:47 +0100] [CGI] cgiSetVariable: CUPS_GET_DEVICES_DONE="1"
D [25/Jan/2015:23:55:47 +0100] [CGI] cgiSetVariable: TITLE="Modify Printer"
D [25/Jan/2015:23:55:47 +0100] [CGI] cgiSetVariable: SERVER_NAME="localhost"
D [25/Jan/2015:23:55:47 +0100] [CGI] cgiSetVariable: REMOTE_USER="root"
D [25/Jan/2015:23:55:47 +0100] [CGI] cgiSetVariable: CUPS_VERSION="CUPS v2.0.1"
D [25/Jan/2015:23:55:47 +0100] [Client 1] CGI data ready to be sent.
D [25/Jan/2015:23:55:47 +0100] [Client 1] con->http=0x7fc279b24220
D [25/Jan/2015:23:55:47 +0100] [Client 1] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_LENGTH, data_remaining=2147483647, response=(nil)(), pipe_pid=15600, file=16
D [25/Jan/2015:23:55:47 +0100] [Client 1] Waiting for CGI data.
D [25/Jan/2015:23:55:47 +0100] [Client 1] Script header: Content-Type: text/html;charset=utf-8
D [25/Jan/2015:23:55:47 +0100] [Client 1] Script header:
D [25/Jan/2015:23:55:47 +0100] [Client 1] Sending status 200 for CGI.
D [25/Jan/2015:23:55:47 +0100] [Client 1] cupsdSendHeader: code=200, type="(null)", auth_type=0
D [25/Jan/2015:23:55:47 +0100] [Client 1] con->http=0x7fc279b24220
D [25/Jan/2015:23:55:47 +0100] [Client 1] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=15600, file=16
D [25/Jan/2015:23:55:47 +0100] [Client 1] Waiting for CGI data.
D [25/Jan/2015:23:55:47 +0100] [Client 1] CGI data ready to be sent.
D [25/Jan/2015:23:55:47 +0100] [Client 1] con->http=0x7fc279b24220
D [25/Jan/2015:23:55:47 +0100] [Client 1] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=15600, file=16
D [25/Jan/2015:23:55:47 +0100] [Client 1] Waiting for CGI data.
D [25/Jan/2015:23:55:47 +0100] [Client 1] con->http=0x7fc279b24220
D [25/Jan/2015:23:55:47 +0100] [Client 1] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=15600, file=16
D [25/Jan/2015:23:55:47 +0100] [Client 1] Waiting for CGI data.
D [25/Jan/2015:23:55:47 +0100] [CGI] Regular expression "[a-z]+://"
D [25/Jan/2015:23:55:47 +0100] [Client 1] CGI data ready to be sent.
D [25/Jan/2015:23:55:47 +0100] [CGI] Regular expression "[a-z]+://"
D [25/Jan/2015:23:55:47 +0100] [Client 1] con->http=0x7fc279b24220
D [25/Jan/2015:23:55:47 +0100] [Client 1] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=15600, file=16
D [25/Jan/2015:23:55:47 +0100] [Client 1] Waiting for CGI data.
D [25/Jan/2015:23:55:47 +0100] [Client 1] con->http=0x7fc279b24220
D [25/Jan/2015:23:55:47 +0100] [Client 1] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=15600, file=16
D [25/Jan/2015:23:55:47 +0100] [Client 1] Waiting for CGI data.
D [25/Jan/2015:23:55:47 +0100] [CGI] Regular expression "[a-z]+://"
D [25/Jan/2015:23:55:47 +0100] [CGI] Regular expression "[a-z]+://"
D [25/Jan/2015:23:55:47 +0100] [CGI] Regular expression "[a-z]+://"
D [25/Jan/2015:23:55:47 +0100] [CGI] Regular expression "[a-z]+://"
D [25/Jan/2015:23:55:47 +0100] [Client 1] CGI data ready to be sent.
D [25/Jan/2015:23:55:47 +0100] [CGI] Regular expression "[a-z]+://"
D [25/Jan/2015:23:55:47 +0100] [Client 1] con->http=0x7fc279b24220
D [25/Jan/2015:23:55:47 +0100] [Client 1] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=15600, file=16
D [25/Jan/2015:23:55:47 +0100] [Client 1] Waiting for CGI data.
D [25/Jan/2015:23:55:47 +0100] [CGI] Regular expression "[a-z]+://"
D [25/Jan/2015:23:55:47 +0100] [CGI] matches[0].rm_so=0
D [25/Jan/2015:23:55:47 +0100] [CGI] matches[1].rm_so=-1
D [25/Jan/2015:23:55:47 +0100] [Client 1] con->http=0x7fc279b24220
D [25/Jan/2015:23:55:47 +0100] [Client 1] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=15600, file=16
D [25/Jan/2015:23:55:47 +0100] [Client 1] Waiting for CGI data.
D [25/Jan/2015:23:55:47 +0100] [CGI] Regular expression "[a-z]+://"
D [25/Jan/2015:23:55:47 +0100] [CGI] Regular expression "[a-z]+://"
D [25/Jan/2015:23:55:47 +0100] [CGI] Regular expression "[a-z]+://"
D [25/Jan/2015:23:55:47 +0100] [CGI] Regular expression "[a-z]+://"
D [25/Jan/2015:23:55:47 +0100] [CGI] Regular expression "[a-z]+://"
D [25/Jan/2015:23:55:47 +0100] [CGI] Regular expression "[a-z]+://"
D [25/Jan/2015:23:55:47 +0100] PID 15600 (/usr/lib/cups/cgi-bin/admin.cgi) exited with no errors.
D [25/Jan/2015:23:55:47 +0100] [CGI] Regular expression "[a-z]+://"
D [25/Jan/2015:23:55:47 +0100] [Client 8] HTTP_STATE_WAITING Closing for error 32 (Broken pipe)
D [25/Jan/2015:23:55:47 +0100] [Client 8] Closing connection.
D [25/Jan/2015:23:55:47 +0100] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [25/Jan/2015:23:55:47 +0100] [Client 1] CGI data ready to be sent.
D [25/Jan/2015:23:55:47 +0100] [Client 1] con->http=0x7fc279b24220
D [25/Jan/2015:23:55:47 +0100] [Client 1] cupsdWriteClient error=0, used=0, state=HTTP_STATE_POST_SEND, data_encoding=HTTP_ENCODING_CHUNKED, data_remaining=0, response=(nil)(), pipe_pid=15600, file=16
D [25/Jan/2015:23:55:47 +0100] [Client 1] Waiting for CGI data.
D [25/Jan/2015:23:55:47 +0100] [Client 1] Sending 0-length chunk.
D [25/Jan/2015:23:55:47 +0100] [Client 1] Flushing write buffer.
D [25/Jan/2015:23:55:47 +0100] [Client 1] New state is HTTP_STATE_WAITING
D [25/Jan/2015:23:55:47 +0100] [Client 1] Waiting for request.
D [25/Jan/2015:23:55:47 +0100] cupsdSetBusyState: newbusy="Active clients", busy="Active clients"
D [25/Jan/2015:23:55:47 +0100] [CGI] Regular expression "[a-z]+://"
D [25/Jan/2015:23:55:47 +0100] [CGI] matches[0].rm_so=0
D [25/Jan/2015:23:55:47 +0100] [CGI] matches[1].rm_so=-1
Last edited by SysGhost (2015-01-25 23:10:30)
Offline