Arch Linux

Please do some research. I've seen such reports every now and then. Nobody could help to track down the root of this issue.

Feel free to check you (full debug enabled) logfiles and compare Arch builds vs. other distributions. I assume the bug to be in the gutenprint pkg or some missing user interaction after gutenprint installation or update (Check post-install msg!).

Ok, I'll update as things come to me. I'm using "lpinfo -m", since that is most direct. lpinfo somehow runs "/usr/bin/perl /usr/lib/cups/driver/foomatic list", which then uses 100% cpu. "/usr/lib/cups/driver/foomatic" is just a link to "/usr/bin/foomatic-ppdfile", which is the actual perl script. foomatic-ppdfile is owned by the foomatic-db-engine package, which is only a dependency of hplip, and could otherwise be removed. "lpinfo -m" runs normally with the foomatic-db-engine package removed.

What causes lpinfo to call foomatic-ppdfile? I haven't figured that out yet. It is not hardcoded into lpinfo. Simply removing foomatic-ppdfile from /usr/bin/, and leaving the rest of the foomatic-db-engine package in place, allows "lpinfo -m" to run normally.

And, what is foomatic-ppdfile doing?

Running "foomatic-ppdfile list" directly uses 100% cpu, except it does not seem to have any internal time-out mechanism, and will run indefinitely. Running "strace -f -ff -o footrace /usr/bin/foomatic-ppdfile list" continues to run but produces no further trace output after:

stat("/usr/share/foomatic/db/source/driver/xes.xml", {st_mode=S_IFREG|0644, st_size=522, ...}) = 0
stat("/usr/share/foomatic/db/source/driver/xes.xml", {st_mode=S_IFREG|0644, st_size=522, ...}) = 0
stat("/usr/share/foomatic/db/source/driver/xes.xml", {st_mode=S_IFREG|0644, st_size=522, ...}) = 0
open("/usr/share/foomatic/db/source/driver/xes.xml", O_RDONLY) = 3
lseek(3, 0, SEEK_CUR) = 0
read(3, "<driver id=\"driver/xes\">\n <name"..., 8192) = 522
read(3, "", 7670) = 0
close(3) = 0

xes.xml is the last file alphabetically. Removing xes.xml, foomatic-ppdfile does the same after the next alphabetically last file.

Running foomatic-ppdfile with the perl debugger, and interrupting the program after some time, always stops around:

[0] DB<1> c
^CFoomatic::filters::xml::xmlParse::getPrinterSpecificDriver(/usr/lib/perl5/vendor_perl/Foomatic/filters/xml/xmlParse.pm:595):
595: if (!$nonDestructive) {

then

[0] DB<0> r
scalar context return from Foomatic::filters::xml::xmlParse::getPrinterSpecificDriver: 'cmd' => 'gs -q -dPARANOIDSAFER -dNOPAUSE -dBATCH -dNOINTERPOLATE -sDEVICE=ijs -sIjsServer=ijsgutenprint.5.2 -dIjsUseOutputFD%A -sIjsParams="STP_VERSION=5.2.10,%B"%Z -sOutputFile=- -'
'combomargins' => HASH(0x4164878)
'_general' => HASH(0x4167108)
'absolute' => 0
'bottom' => 15
'left' => 10
'right' => 10
'top' => 9
'type' => 'F'
'url' => 'http://gimp-print.sourceforge.net/'
Foomatic::filters::xml::xmlParse::parseOverview(/usr/lib/perl5/vendor_perl/Foomatic/filters/xml/xmlParse.pm:782):
782: if($printer->{'id'}) {

Here, we get an idea of where the problem intersects with gutenprint.

Stepping from this line shows xmlParse.pm looping forever inside of:

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);
}
}

If this routine is suppose to be stepping through printers only once in alphabetical order, then I suspect that the list is being processed repeatedly because, by repeatedly continuing, then interrupting, then stepping, then printing $id, the printer manufacturer names can be seen repeating.

Note that /usr/lib/perl5/vendor_perl/Foomatic/filters/xml/xmlParse.pm is owned by foomatic-db-engine 3:20160105-1.

This bug seems to be specifically with the foomatic-db-engine package rather than with the cups package. Andy, where do I go from here? Can you move this bug over to foomatic-db-engine? Or should I file another bug directly in foomatic-db-engine? Or should I just file the bug up-stream?

There a foomatic mailing list but it has very low usage. http://lists.linuxfoundation.org/pipermail/printing-foomatic/ - there should be also a foomatic bug tracker somewhere to be find at linuxprinting.org.
We need to somehow catch Till Kappeters attention. He's the cups-filter and foomatic upstream dev and working and packaging for Ubuntu these days.

You can also look at how other major distributions build their foomatic/gutenprint packages. Fedora spec file, Gentoo ebuild and Debian/Ubuntu Makefiles.

I've sent a bug report upstream, to printing-foomatic@lists.linux-foundation.org and to https://bugs.linuxfoundation.org/.

Bug 1338 - foomatic-ppdfile calling xmlParse.pm infinite loop when running with gutenprint
https://bugs.linuxfoundation.org/show_bug.cgi?id=1338

I've also found an equivalent bug report,
 FS#44430  - [foomatic-db-engine] Adding new printer stalls, high CPU load foomatic list
https://bugs.archlinux.org/task/44430

There is a comment on the problem and solution, which I will repeat here.

----
Comment by Chris Severance (severach) - Tuesday, 10 November 2015, 00:38 GMT
There's no reason to use strace. Use the source, Luke!

You can fix the problem by removing the following files.

# gutenprint-ijs-simplified.5.2.xml |1504797
# gutenprint-ijs.5.2.xml |3046350

sudo rm -f
/usr/share/foomatic/db/source/driver/{gutenprint-ijs-simplified.5.2.xml,gutenprint-ijs.5.2.xml}

It isn't locking up and it isn't stopping on any random printer. Due to the
large file size, processing slows to a crawl when one of the above two files are
hit. It will complete if you're willing to wait forever.

Due to the way hashes work in Perl, the printers are processed in slightly
random order which is why you see random printers in the strace list.

#/usr/lib/perl5/vendor_perl/Foomatic/filters/xml/xmlParse.pm is owned by
foomatic-db-engine 3:20151108-1

The problem is that xmlParse.pm is not coded well enough to handle XML files
this large in a reasonable amount of time. On the way to pinpointing the problem
I saw several "Shlemiel the painter's algorithms" which is likely to be the problem.

http://www.joelonsoftware.com/articles/fog0000000319.html

Conclusion: gutenprint is supplying some very large XML files which foomatic is
unable to process within the time allowed by CUPS.
----

The linked article describes the problem and offers some solutions. Here is an
excerpt:

----
Whenever something seems like it should have linear performance but it seems to
have n-squared performance, look for hidden Shlemiels. They are often hidden by
your libraries. Looking at a column of strcats or a strcat in a loop doesn't
exactly shout out "n-squared," but that is what's happening.

How do we fix this? A few smart C programmers implemented their own mystrcat as
follows:

char* mystrcat( char* dest, char* src )
{
while (*dest) dest++;
while (*dest++ = *src++);
return --dest;
}

What have we done here? At very little extra cost we're returning a pointer to
the end of the new, longer string. That way the code that calls this function
can decide to append further without rescanning the string:

char bigString[1000]; /* I never know how much to allocate... */
char *p = bigString;
bigString[0] = '\0';
p = mystrcat(p,"John, ");
p = mystrcat(p,"Paul, ");
p = mystrcat(p,"George, ");
p = mystrcat(p,"Joel ");

This is, of course, linear in performance, not n-squared, so it doesn't suffer
from degradation when you have a lot of stuff to concatenate.
----

It appears that eventually xmlParse.pm will have to be re-written or avoided. I don't understand how anybody can actually install a printer in Arch Linux, unless they have randomly failed to simultaneously install both gutenprint and hplip, for some reason. Still, it is possible to, for instance, "install" a printer using a printer driver with gutenprint removed, then remove foomatic-db-engine, install gutenprint, and "install" a printer using a gutenprint driver, and then re-install foomatic-db-engine, creating the proper set of ppd files. Of course, that is tedious and not intuitive. Alternatively, it seems that "foomatic-configure" can be run manually, after reading at
http://bzr.openprinting.org/foomatic-4.0/foomatic-db-engine/USAGE

The source USAGE file should probably be included in the Arch foomatic-db-engine package. Arch, and the Arch CUPS wiki, do not provide a lot of guidance about "installing" a printer driver, and the foomatic-configure man page is quite brief.

But then, I notice that foomatic-db-engine includes a program "foomatic-verify-xml", which, running, finds many errors. I don't know what about that, and am guessing that these errors have nothing to do with xmlParse.pm failing.

The current foomatic-db-engine bzr source ChangeLog shows:

2011-07-09 Daniel Dressler <danieru.dressler@gmail.com>

* lib/Foomatic/DB.pm, lib/Foomatic/xmlParse.pm,
lib/Foomatic/phonebook.pm: Added new code for parsing the XML
database without helper programs written in C.

So, I'm thinking that we will need to get Daniel to pass judgment on this issue, unless Till is willing to get involved.

Is this still an issue after printing packages have been restructured?

$ pacaur -S gutenprint foomatic-db-engine
... extra/gutenprint 5.2.11-3
... extra/foomatic-db-engine 4:4.0.12-2

$ pacman -Ql gutenprint|grep /usr/share/foomatic/db/source/driver/
<null>

$ lpinfo -m
<big long list>

Incidentally, I notice that the package foomatic-db-engine no longer includes the program "foomatic-verify-xml", or the file "/usr/lib/perl5/vendor_perl/Foomatic/filters/xml/xmlParse.pm", for whatever reason.

I cannot say if file "/usr/lib/perl5/vendor_perl/Foomatic/filters/xml/xmlParse.pm" has been corrected to avoid "n-squared" growth in the search space.

As it is, the files "/usr/share/foomatic/db/source/driver/{gutenprint-ijs-simplified.5.2.xml,gutenprint-ijs.5.2.xml}" are no longer included in the gutenprint package, but are now in the foomatic-db-gutenprint package. Still, after also installing the foomatic-db-gutenprint and foomatic-db-gutenprint-ppds packages, and now without "xmlParse.pm", "lpinfo -m" produces a proper list of printer drivers.

So no, no longer an issue, and this bug report can be closed.

Thanks Andy!