search

OpenPrinting / cups

OpenPrinting CUPS Sources
https://openprinting.github.io/cups
Apache License 2.0
1.1k stars 195 forks source link

Cups 2.4.10 is slow on Docker #1080

Closed AblionGE closed 1 month ago

AblionGE commented 1 month ago

Description

I'm building a Docker image with cups to print to network printers.

With the base image debian:stable-slim (and CUPS 2.4.2), the performances are acceptable. With ubuntu:24.10 (CUPS 2.4.10), the printing of every job is very slow.

To Reproduce

Steps to reproduce the behavior:

  1. Build the following image (the Dockerfile and the entrypoint have been simplified): docker build -t cups-docker .
#FROM debian:stable-slim
FROM ubuntu:24.10

# Update and install dependencies
RUN apt-get update -qq && apt-get upgrade -qqy && apt-get install -qqy \
    apt-utils \
    avahi-daemon \
    sudo \
    cups \
    cups-filters \
    cups-pdf \
    curl \
    gettext-base \
    libcupsimage2 \
    system-config-printer \
    printer-driver-gutenprint \
&& apt-get clean \
&& rm -rf /var/lib/apt/lists/*

# Expose ports
EXPOSE 631
EXPOSE 162

# Define volumes
VOLUME /etc/cups/

# Copy and set permissions for entrypoint script
COPY entrypoint.sh /
COPY templates/cupsd.conf /etc/cups/cupsd.conf
COPY templates/cups-files.conf /etc/cups/cups-files.conf

# Set the entrypoint
ENTRYPOINT ["/entrypoint.sh"]

And the entrypoint file:

#!/bin/bash

if [ "$(grep -ci cups_admin /etc/shadow)" -eq "0" ]; then
    echo "Adding cups_admin user..."
    useradd -r -G lpadmin -M cups_admin

    # add password
    echo "Setting password for cups_admin user..."
    echo "cups_admin:${CUPS_ADMIN_PASSWORD}" | chpasswd
fi

chown -R cups_admin:lpadmin /etc/cups

echo "Starting cupsd..."
/usr/sbin/cupsd

declare -A printer_driver=(
[hp]="lsb/usr/cupsfilters/pxlmono.ppd"
)

declare media_hp="A4"

echo "environment: ${ENV}"
csv_path="templates/printers/${ENV}.csv"
echo "CSV path: ${csv_path}"
# Read the CSV file line by line
while IFS=, read -r name protocol ipaddress port model location; do
  if [ -z "$name" ] && [ -z "$protocol" ] && [ -z "$ipaddress" ] && [ -z "$port" ] && [ -z "$model" ] && [ -z "$location" ]; then
    continue
  fi

  echo "Adding printer ${name}..."

  media_option=$([[ "$model" == "hp" ]] && echo "-o media=${media_hp}" || echo "")

  sudo -u cups_admin lpadmin -p "${name}" \
    -v "${protocol}://${ipaddress}:${port}" \
    -D "${protocol}://${ipaddress}:${port}" \
    -m "${printer_driver[$model]}" \
    -L "${location}" \
    ${media_option} \
    -E
  done < "$csv_path"

echo "Starting dbus-daemon..."
dbus-daemon --system

mkdir -p /var/cache/fontconfig
chmod 777 /var/cache/fontconfig

tail -F /var/log/cups/*
  1. My printer is accessed via socket on port 9100
  2. Run it with the following command: docker run -d --rm --name cups -p 631:631 -e CUPS_ADMIN_PASSWORD=12345678 -e ENV=$ENV -e SERVER_FQDN=$FQDN cups-docker:latest
  3. Print a job

Expected behavior

With both CUPS version, I expect to have similar performances

Actual behavior

On ubuntu 24.10 with CUPS 2.4.10, each job takes several seconds to print (even if it's just one page).

I put the logs in debug2 level and they are similar between both images except that with CUPS 2.4.10 I have ~10 more logs "Wrote XXXX bytes of print data...".

I also checked the PPD file for my printer between both tests, they are the same. But at "runtime", I have this

CUPS 2.4.2

D [17/Oct/2024:09:55:44 +0000] [Job 1] 2 filters for job:
D [17/Oct/2024:09:55:44 +0000] [Job 1] pdftopdf (application/pdf to application/vnd.cups-pdf, cost 66)
D [17/Oct/2024:09:55:44 +0000] [Job 1] gstopxl (application/vnd.cups-pdf to printer/myprinter, cost 0)

And on CUPS 2.4.10

D [17/Oct/2024:12:07:45 +0000] [Job 1] 3 filters for job:
D [17/Oct/2024:12:07:45 +0000] [Job 1] - (application/pdf to application/vnd.universal-input, cost 0)
D [17/Oct/2024:12:07:45 +0000] [Job 1] universal (application/vnd.universal-input to application/vnd.cups-pdf, cost 0)
D [17/Oct/2024:12:07:45 +0000] [Job 1] gstopxl (application/vnd.cups-pdf to printer/myprinter, cost 0)

I don't know if it makes a difference or not.

System Information:

AblionGE commented 1 month ago

There is the PPD file of my printer in CUPS 2.4.10 PPD_file.txt

zdohnal commented 1 month ago

Hi @AblionGE ,

cupsd is not the only process running during printing, especially if you use PCL XL driver - ghostscript between Debian stable and Ubuntu 24.10 is 10.0.0 and 10.03.1 and ghostscript is used for PCL XL generation, so I suspect there can be a change.

Can you enable your debug2 logs in CUPS, get the gs command line used for your job, get the input file for gstopxl filter (in general take job file - starts with 'd' - matching with job from /var/spool/cups, and call universal filter with PPD, CONTENT_TYPE and FINAL_CONTENT_TYPE env variables - PPD is path to PPD file, CONTENT_TYPE is mime type of input file - here application/pdf, and FINAL_CONTENT_TYPE is mime type which should go out of the filter, here application/vnd.cups-pdf - and call it like "/path/to/universal 1 user '' 1 '' /var/spool/cups/file > output") and then call gs with the almost same options (you change input file from stdin to your file, and "-dOutputFile" from stdout to your new file) and universal filter output and see if it takes more time or output is larger than in Debian.

Either way, we need debug2 logs from both machines, files from /var/spool/cups (starts with d) from both machines, but IMO this is not CUPS issue. Maybe libcupsfilters one (if pdftopdf generates something bad - universal filter runs internally pdftopdf filter function, which is basically pdftopdf filter, but IMO there was no changes in PDF filtering), but I bet more on ghostscript change.

zdohnal commented 1 month ago

Additionally, PXL in general is slow when processing big PDFs - if it is something like barcode in PDF format, it can work ok, but normal PDF document printing creates really large files in comparison to the input PDF. I would recommend changing the driver if your use cases are more in line with common office printing and not delivery company label printing.

AblionGE commented 1 month ago

Hi @zdohnal ,

Thanks for the fast response!

I'm configuring CUPS to print barcodes in PDF format so the driver should be fine. I already played with other drivers but the slowness was still there.

I think you pointed the right culprit.

Debian Stable

gs command from the logs

D [18/Oct/2024:06:40:02 +0000] [Job 1] Ghostscript command line: gs -dQUIET -dSAFER -dNOPAUSE -dBATCH -dNOINTERPOLATE -dNOMEDIAATTRS -dShowAcroForm -sstdout=%stderr -sOutputFile=%stdout -r600x600 -dMediaPosition=5 -dDEVICEWIDTHPOINTS=595 -dDEVICEHEIGHTPOINTS=842 -sDEVICE=pxlmono -I/usr/share/cups/fonts -c \'<</.HWMargins[12.000000 12.000000 12.000000 12.000000] /Margins[0 0]>>setpagedevice\' -f -_

Manual test

Note:

$ export PPD=/etc/cups/ppd/myprinter.ppd; export CONTENT_TYPE=application/pdf; export FINAL_CONTENT_TYPE=application/vnd.cups-pdf; /usr/lib/cups/filter/pdftopdf 1 CUPS-user '' 1 '' /var/spool/cups/d00001-001 > output

DEBUG: pdftopdf: Last filter determined by the PPD: gstopxl; FINAL_CONTENT_TYPE: application/vnd.cups-pdf => pdftopdf will log pages in page_log.
DEBUG: PDF interactive form and annotation flattening done via QPDF
DEBUG: pdftopdf: "print-scaling" IPP attribute: auto
DEBUG: pdftopdf: Print scaling mode: Do not scale, center, crop if needed
After Cropping: 595.000000 842.000000 595.000000 842.000000
PAGE: 1 1

$ ls -lh output
-rw-r--r--. 1 root root 48K Oct 18 07:19 output

$ gs -dQUIET -dSAFER -dNOPAUSE -dBATCH -dNOINTERPOLATE -dNOMEDIAATTRS -dShowAcroForm -sstdout=gsftdout -sOutputFile=gsoutputfile -r600x600 -dMediaPosition=5 -dDEVICEWIDTHPOINTS=595 -dDEVICEHEIGHTPOINTS=842 -sDEVICE=pxlmono -I/usr/share/cups/font output

$ ls -lh gsoutputfile
-rw-r--r--. 1 root root 1.4M Oct 18 07:22 gsoutputfile

Ubuntu 24.10

Note:

gs command from the logs

D [18/Oct/2024:06:44:09 +0000] [Job 1] cfFilterGhostscript: Ghostscript command line: gs -dQUIET -dSAFER -dNOPAUSE -dBATCH -dNOINTERPOLATE -dNOMEDIAATTRS -dUsePDFX3Profile -sstdout=%stderr -sOutputFile=%stdout -r600x600 -dDEVICEWIDTHPOINTS=595 -dDEVICEHEIGHTPOINTS=842 -sDEVICE=pxlmono -dcupsManualCopies -I/usr/share/cups/fonts -sOutputICCProfile=sgray.icc -c \'<</.HWMargins[11.990551 11.990551 11.990540 11.990540] /Margins[0 0]>>setpagedevice\' -f -_

Manual test

$ export PPD=/etc/cups/ppd/myprinter.ppd; export CONTENT_TYPE=application/pdf; export FINAL_CONTENT_TYPE=application/vnd.cups-pdf; /usr/lib/cups/filter/universal 1 CUPS-user '' 1 '' /var/spool/cups/d00001-001 > output

DEBUG: ppdFilterLoadPPD: Color profile qualifier determined from job and PPD data '..600dpi'
DEBUG: ppdFilterLoadPPD: No ICC profiles specified in PPD
DEBUG: ppdFilterLoadPPD: Searching for profile "600dpi/-"...
DEBUG: ppdFilterLoadPPD: Last filter determined by the PPD: gstopxl; Final data MIME type: application/vnd.cups-pdf => PDF filter will log pages in page_log.
DEBUG: ppdFilterUniversal: "*cupsFilter(2): ..." lines in the PPD file:
DEBUG: ppdFilterUniversal:    application/vnd.cups-raw application/octet-stream 0 -
DEBUG: ppdFilterUniversal:    application/vnd.cups-postscript 100 gstopxl
DEBUG: ppdFilterUniversal: PPD uses "*cupsFilter: ..." lines, so we always convert to format given by FINAL_CONTENT_TYPE
DEBUG: ppdFilterUniversal: Converting from application/pdf to application/vnd.cups-pdf
DEBUG: cfFilterUniversal: Converting from application/pdf to application/vnd.cups-pdf
DEBUG: cfFilterUniversal: Final output format for job: application/vnd.cups-pdf
DEBUG: cfFilterUniversal: Adding pdftopdf to chain
INFO: cfFilterChain: Running filter: pdftopdf
INFO: cfFilterChain: pdftopdf (PID 130) started.
DEBUG: cfFilterPDFToPDF: Forced page logging selected by options.
DEBUG: cfFilterPDFToPDF: Processing PDF input with QPDF: Page-ranges, page-set, number-up, booklet, size adjustment, ...
DEBUG: cfFilterPDFToPDF: "print-scaling" IPP attribute: auto
DEBUG: cfFilterPDFToPDF: Print scaling mode: Do not scale, center, crop if needed
DEBUG: cfFilterPDFToPDF: After Cropping: 595.000000 842.000000 595.275574 841.889771
PAGE: 1 1
DEBUG: cfFilterChain: pdftopdf completed with status 0.
INFO: cfFilterChain: pdftopdf (PID 130) exited with no errors.

$ ls -lh output
-rw-r--r--. 1 root root  48K Oct 18 06:54 output

$ gs -dQUIET -dSAFER -dNOPAUSE -dBATCH -dNOINTERPOLATE -dNOMEDIAATTRS -dUsePDFX3Profile -sstdout=gsftdout -sOutputFile=gsoutputfile -r600x600 -dDEVICEWIDTHPOINTS=595 -dDEVICEHEIGHTPOINTS=842 -sDEVICE=pxlmono -dcupsManualCopies -I/usr/share/cups/fonts -sOutputICCProfile=sgray.icc  output

$ la -lh gsoutputfile
-rw-r--r--. 1 root root 9.0M Oct 18 07:05  gsoutputfile

Analysis

Indeed, the output file from Ghostscript is much bigger on Ubuntu 24.10... So I guess that I should check on Ghostscript side?`

Thanks for the help!

zdohnal commented 1 month ago

Yep, please try - do let us know if GS upstream finds out there is an issue we have to fix in filtering - the code for that is in OpenPrinting/libcupsfilters, so if there is an issue about filtering, let us know there.

Closing for now, we can reopen later if needed.