The backend crashes when printing jobs from cups.

[ppywlkiqletw]

Cups version on Fedora 35 is cups-2.3.3op2-8.fc35.x86_64.

Printing a test page directly from ps-printer-app works.

Print from the Mopria app on Android works as well.

Print a test page from CUPS does not work.

In the file pappl-retrofit/print-job.c

  {
    // No extra filter needed, make print filter function be called
    // directly
    papplLogJob(job, PAPPL_LOGLEVEL_DEBUG,
                "Passing on data directly to printer");
    job_data->device_fd = filterPOpen(pr_print_filter_function, -1, nullfd,
                                      0, job_data->filter_data, device,
                                      &(job_data->device_pid));
  }

The parameter "device" is not the correct structure type as expected by "pr_print_filter_function", as far as I can tell.

[tillkamppeter]

The problem which you mention in pappl-retrofit/print-job.c is indeed a bug and leads to a reproducable crash of the server process of the Printer Application when sending a Raster-based job (PWG/Apple Raster or images) to a PostScript printer which has no *cupsFilter: ... line in its PPD file, regardless of whether one uses the CLI of the Printer Application or CUPS as client.

This I have fixed in commit 95113dc4e7. The Printer Applications in the Snap Store I am rebuilding currently. In ~1 hour the PostScript Printer Application should be ready.

But I do not understand why printing the test page with CUPS fails, as CUPS usually turns it into PDF (for me it does so), and for printing PDFs the piece of code you mention is not executed.

So I would like, independent whether this fix solves your test-page printing, if you could tell me which printer model/PPD you are printing with, and how you print a test page with CUPS (web interface, system-config-printer, GNOME Control Center, ... other tool? Command line?). You could also attach an error_log of CUPS from a job (before printing the test page again, run cupsctl --debug-logging, afterwards copy /var/log/cups/error_log into a file with a name ending with .txt, and attach the file to this issue).

[ppywlkiqletw]

I was using system-config-printer.

My printer is not actually a physical printer, but a small program listening on port 9100 and copy every received bytes to a file. The file can then be read by a PDF viewer.

The avahi data as below.

=   eth0 IPv4 testps                                        _ipps._tcp           local
   hostname = [mybox.local]
   address = [192.168.178.10]
   port = [8000]
   txt = ["Scan=F" "PaperMax=tabloid-A3" "Fax=F" "product=(Generic PostScript Printer)" "mopria-certified=1.3" "priority=0" "q
total=1" "txtvers=1" "Duplex=F" "Color=T" "TLS=1.2" "URF=V1.5,W8,SRGB24,PQ3-4-5,FN3,IS0-11-4,MT0,OB10,RS600-1200" "UUID=b23550
9e-e9a8-3e92-7c8d-6a32e54c3701" "pdl=image/pwg-raster,image/urf,application/vnd.printer-specific,application/pdf,application/p
ostscript,image/jpeg,image/png" "note=" "adminurl=http://mybox.local:8000/testps/" "ty=Generic PostScript Printer" "rp=ipp/pri
nt/testps"]

I guess that specifying "application/vnd.printer-specific" tells CUPS to send ready cooked printer data that need no further filtering.

Logging from ps-printer-app (only for Job 8 -- too big otherwise).

I [2021-11-14T07:28:26.645Z] [Job 8] Starting print job.
D [2021-11-14T07:28:26.645Z] [Job 8] Getting options for num_pages=0, color=true
D [2021-11-14T07:28:26.645Z] [Job 8] print-color-mode=auto
D [2021-11-14T07:28:26.645Z] [Job 8] new print-color-mode=color
D [2021-11-14T07:28:26.645Z] [Job 8] header.cupsWidth=4960
D [2021-11-14T07:28:26.645Z] [Job 8] header.cupsHeight=7015
D [2021-11-14T07:28:26.645Z] [Job 8] header.cupsBitsPerColor=8
D [2021-11-14T07:28:26.645Z] [Job 8] header.cupsBitsPerPixel=24
D [2021-11-14T07:28:26.645Z] [Job 8] header.cupsBytesPerLine=14880
D [2021-11-14T07:28:26.645Z] [Job 8] header.cupsColorOrder=0
D [2021-11-14T07:28:26.645Z] [Job 8] header.cupsColorSpace=19 (sRGB)
D [2021-11-14T07:28:26.645Z] [Job 8] header.cupsNumColors=3
D [2021-11-14T07:28:26.645Z] [Job 8] header.HWResolution=[600 600]
D [2021-11-14T07:28:26.645Z] [Job 8] num_pages=0
D [2021-11-14T07:28:26.645Z] [Job 8] copies=1
D [2021-11-14T07:28:26.645Z] [Job 8] finishings=0x0
D [2021-11-14T07:28:26.645Z] [Job 8] media-col.bottom-margin=423
D [2021-11-14T07:28:26.645Z] [Job 8] media-col.left-margin=423
D [2021-11-14T07:28:26.645Z] [Job 8] media-col.right-margin=423
D [2021-11-14T07:28:26.645Z] [Job 8] media-col.size=21000x29700
D [2021-11-14T07:28:26.645Z] [Job 8] media-col.size-name='iso_a4_210x297mm'
D [2021-11-14T07:28:26.645Z] [Job 8] media-col.source='auto'
D [2021-11-14T07:28:26.645Z] [Job 8] media-col.top-margin=423
D [2021-11-14T07:28:26.645Z] [Job 8] media-col.type='auto'
D [2021-11-14T07:28:26.645Z] [Job 8] orientation-requested=none
D [2021-11-14T07:28:26.645Z] [Job 8] page-ranges=1-2147483647
D [2021-11-14T07:28:26.645Z] [Job 8] print-color-mode='color'
D [2021-11-14T07:28:26.645Z] [Job 8] print-content-optimize='auto'
D [2021-11-14T07:28:26.645Z] [Job 8] print-darkness=0
D [2021-11-14T07:28:26.645Z] [Job 8] print-quality=normal
D [2021-11-14T07:28:26.645Z] [Job 8] print-scaling='auto'
D [2021-11-14T07:28:26.645Z] [Job 8] print-speed=0
D [2021-11-14T07:28:26.645Z] [Job 8] printer-resolution=600x600dpi
D [2021-11-14T07:28:26.645Z] [Job 8] Printing job in streaming mode
D [2021-11-14T07:28:26.645Z] [Job 8] Converting raster input to format: application/vnd.cups-postscript
D [2021-11-14T07:28:26.646Z] [Job 8] Adding options for finishings
D [2021-11-14T07:28:26.646Z] [Job 8] Adding option: PageSize
D [2021-11-14T07:28:26.646Z] [Job 8]   Requesting size: W=21000 H=29700 L=423 R=423 T=423 B=423 (1/100 mm)
D [2021-11-14T07:28:26.646Z] [Job 8] Adding option: InputSlot
D [2021-11-14T07:28:26.646Z] [Job 8] Adding option: MediaType
D [2021-11-14T07:28:26.646Z] [Job 8] Adding option: orientation-requested
D [2021-11-14T07:28:26.646Z] [Job 8] Adding option presets depending on requested print quality and color mode
D [2021-11-14T07:28:26.646Z] [Job 8] Presets for color printing in normal quality:
D [2021-11-14T07:28:26.646Z] [Job 8]   Adding option: ColorModel=Color
D [2021-11-14T07:28:26.646Z] [Job 8]   Adding option: Resolution=600dpi
D [2021-11-14T07:28:26.646Z] [Job 8] Adding option presets depending on requested content optimization
D [2021-11-14T07:28:26.646Z] [Job 8] Automatic content type selection ...
D [2021-11-14T07:28:26.646Z] [Job 8] Input file format: image/pwg-raster -> Content optimization: No optimization
D [2021-11-14T07:28:26.646Z] [Job 8] No presets for automatic printing
D [2021-11-14T07:28:26.646Z] [Job 8] Adding option: print-scaling
D [2021-11-14T07:28:26.646Z] [Job 8] Adding option: Duplex
D [2021-11-14T07:28:26.646Z] [Job 8] Adding option: Resolution
D [2021-11-14T07:28:26.646Z] [Job 8]   PPD option Resolution controlled by the presets
D [2021-11-14T07:28:26.646Z] [Job 8] Adding option: ColorModel
D [2021-11-14T07:28:26.646Z] [Job 8]   PPD option ColorModel controlled by the presets
D [2021-11-14T07:28:26.646Z] [Job 8] Adding option: Collate
D [2021-11-14T07:28:26.646Z] [Job 8] PPD options to be used:
D [2021-11-14T07:28:26.646Z] [Job 8]   Collate=True
D [2021-11-14T07:28:26.646Z] [Job 8]   ColorModel=Color
D [2021-11-14T07:28:26.646Z] [Job 8]   Duplex=None
D [2021-11-14T07:28:26.646Z] [Job 8]   InputSlot=Default
D [2021-11-14T07:28:26.646Z] [Job 8]   job-originating-user-name=vek
D [2021-11-14T07:28:26.646Z] [Job 8]   job-uuid=urn:uuid:272110fa-71c2-306e-6a00-e799642ab690
D [2021-11-14T07:28:26.646Z] [Job 8]   PageSize=A4
D [2021-11-14T07:28:26.646Z] [Job 8]   print-scaling=auto
D [2021-11-14T07:28:26.646Z] [Job 8]   Resolution=600dpi
D [2021-11-14T07:28:26.646Z] [Job 8]   time-at-creation=1636874906
D [2021-11-14T07:28:26.646Z] [Job 8]   time-at-processing=1636874906
D [2021-11-14T07:28:26.647Z] [Job 8] Pipes for back and side channels opened
D [2021-11-14T07:28:26.647Z] [Job 8] Passing on data directly to printer
I [2021-11-14T07:28:26.655Z] [Job 8] filterPOpen: Filter function (PID 5319) started.
D [2021-11-14T07:28:26.655Z] [Job 8] Not changing Raster input color depth on PWG/Apple Raster input
I [2021-11-14T07:28:26.655Z] [Job 8] Page 1 raster data is 4961x7016x24 (RGB)
D [2021-11-14T07:28:26.655Z] [Job 8] Getting options for num_pages=0, color=true
D [2021-11-14T07:28:26.655Z] [Job 8] print-color-mode=auto
D [2021-11-14T07:28:26.655Z] [Job 8] new print-color-mode=color
D [2021-11-14T07:28:26.655Z] [Job 8] header.cupsWidth=4960
D [2021-11-14T07:28:26.655Z] [Job 8] header.cupsHeight=7015
D [2021-11-14T07:28:26.655Z] [Job 8] header.cupsBitsPerColor=8
D [2021-11-14T07:28:26.655Z] [Job 8] header.cupsBitsPerPixel=24
D [2021-11-14T07:28:26.655Z] [Job 8] header.cupsBytesPerLine=14880
D [2021-11-14T07:28:26.655Z] [Job 8] header.cupsColorOrder=0
D [2021-11-14T07:28:26.655Z] [Job 8] header.cupsColorSpace=19 (sRGB)
D [2021-11-14T07:28:26.655Z] [Job 8] header.cupsNumColors=3
D [2021-11-14T07:28:26.655Z] [Job 8] header.HWResolution=[600 600]
D [2021-11-14T07:28:26.655Z] [Job 8] num_pages=0
D [2021-11-14T07:28:26.655Z] [Job 8] copies=1
D [2021-11-14T07:28:26.655Z] [Job 8] finishings=0x0
D [2021-11-14T07:28:26.655Z] [Job 8] media-col.bottom-margin=423
D [2021-11-14T07:28:26.655Z] [Job 8] media-col.left-margin=423
D [2021-11-14T07:28:26.655Z] [Job 8] media-col.right-margin=423
D [2021-11-14T07:28:26.655Z] [Job 8] media-col.size=21000x29700
D [2021-11-14T07:28:26.655Z] [Job 8] media-col.size-name='iso_a4_210x297mm'
D [2021-11-14T07:28:26.655Z] [Job 8] media-col.source='auto'
D [2021-11-14T07:28:26.655Z] [Job 8] media-col.top-margin=423
D [2021-11-14T07:28:26.655Z] [Job 8] media-col.type='auto'
D [2021-11-14T07:28:26.655Z] [Job 8] orientation-requested=none
D [2021-11-14T07:28:26.655Z] [Job 8] page-ranges=1-2147483647
D [2021-11-14T07:28:26.655Z] [Job 8] print-color-mode='color'
D [2021-11-14T07:28:26.656Z] [Job 8] print-content-optimize='auto'
D [2021-11-14T07:28:26.656Z] [Job 8] print-darkness=0
D [2021-11-14T07:28:26.656Z] [Job 8] print-quality=normal
D [2021-11-14T07:28:26.656Z] [Job 8] print-scaling='auto'
D [2021-11-14T07:28:26.656Z] [Job 8] print-speed=0
D [2021-11-14T07:28:26.656Z] [Job 8] printer-resolution=600x600dpi
D [2021-11-14T07:28:26.656Z] [Job 8] Not changing Raster input color depth on PWG/Apple Raster input
D [2021-11-14T07:28:31.510Z] [Job 8] Shutting down filter chain
D [2021-11-14T07:28:31.510Z] [Job 8] filterPClose: Filter function (PID 5319) exited with no errors.
D [2021-11-14T07:28:31.510Z] [Job 8] Shutting down CUPS backend
D [2021-11-14T07:28:31.510Z] [Job 8] Closed the pipes for back and side channels
I [2021-11-14T07:28:31.510Z] [Job 8] Completed, job-impressions-completed=1.
D [2021-11-14T07:28:31.510Z] [Job 8] Device read metrics: 0 requests, 0 bytes, 0 msecs
D [2021-11-14T07:28:31.510Z] [Job 8] Device write metrics: 0 requests, 0 bytes, 0 msecs
I [2021-11-14T11:30:09.255Z] [Job 8] Removing job from history.

[root@mybox common]# snap list --all
Name                     Version   Rev    Tracking       Publisher      Notes
core20                   20210928  1169   latest/stable  canonical✓     base
ghostscript-printer-app  1.0       175    latest/edge    openprinting✓  -
ps-printer-app           1.0       569    latest/edge    openprinting✓  -
snapd                    2.52.1    13640  latest/stable  canonical✓     snapd
[root@mybox common]# snap refresh 
All snaps up to date.
[root@mybox common]# 

I will test when the new ps-printer-app shows up.

[ppywlkiqletw]

The new version arrived, and printing the test page from cups now works.

I now have cups debug log on my system. It is 2500 lines long, so is there any part you will be needing?

Maybe I should also have included this snippet.

D [2021-11-15T06:53:23.381Z] [Client 1] Send-Document request: IPP/2.0 request-id=4
D [2021-11-15T06:53:23.381Z] [Client 1] Send-Document request: operation-attributes-tag
D [2021-11-15T06:53:23.381Z] [Client 1] Send-Document request:   attributes-charset charset utf-8
D [2021-11-15T06:53:23.381Z] [Client 1] Send-Document request:   attributes-natural-language naturalLanguage en-us
D [2021-11-15T06:53:23.381Z] [Client 1] Send-Document request:   printer-uri uri ipp://mybox.local:8000/ipp/print/testps
D [2021-11-15T06:53:23.381Z] [Client 1] Send-Document request:   job-id integer 14
D [2021-11-15T06:53:23.381Z] [Client 1] Send-Document request:   requesting-user-name nameWithoutLanguage anonymous
D [2021-11-15T06:53:23.381Z] [Client 1] Send-Document request:   last-document boolean true
D [2021-11-15T06:53:23.381Z] [Client 1] Send-Document request:   document-format mimeMediaType image/urf
D [2021-11-15T06:53:23.381Z] [Client 1] Send-Document request:   compression keyword gzip

The log from yesterday also specifies mimeMediaType image/urf

[tillkamppeter]

Thanks a lot for your logs.

The debug log of the Printer Application was the most helpful for me. It showed that CUPS decided to send the job in Apple Raster format instead of in PDF. I had expected that CUPS would leave it in PDF format, but I did not yet check whether system-config-printer sends the same test page as CUPS itself does via its web interface (CUPS sends a PDF-based one from cups-filters). It was good that CUPS did so, this made me seeing this bug.

Note that application/vnd.printer-specific is an internal format of the Printer Application, which I created when developing the pappl-retrofit library on which my Printer Applications are based. It prevents the Printer Application from passing through incoming jobs without pre-filtering. So if the printer is PostScript and the job is also PostScript this assures that the Printer Application passes the data through the pstops filter so that it gets embedded the PostScript control commands defined in the PPD file. The step to send off the data to the driver (or to the printer directly) is defined to take application/vnd.printer-specific as input but for CUPS this format is unknown, so CUPS sends the job in a format it knows and so PAPPL (the general Printer Application library) sees the format mis-match and calls the appropriate filtering function.

I also appreciate a lot that you are exploring the printing infrastructure without having actual printing needs (you are using an artificial, software-emulated printer) and finding bugs and reporting them. This especially helped me as that the PPD of my physical printer defines a filter and therefore does not hit this bug.

Now I want to know from you whether you are a developer, and whether you do printing-related development. Do you develop for an operating system distribution? Or for IoT devices which are supposed to send print jobs? Or do you want to get part of the OpenPrinting community and contribute to the development of the printing infrastructure?

To get more insight into what we are doing at OpenPrinting, have a look here.

By the way, I have slightly edited your posts to make them more readable, adding markdown. This especially improves the reproduction of embedded logs or code, to prevent them from being messed up by the markdown processor of this site. Click the three dots at the upper right corner of your post and then click "Edit" in the pop-up menu to see the source of your posts and what I changed, especially the added citation marks (three back ticks) around embedded logs. The actual content I did not change.

[ppywlkiqletw]

Sending the test print from the cups webpage makes no difference.

By the way, what is the easy way to enable debug tracing? I used a service file drop-in:

[vek@mybox ~]$ cat /etc/systemd/system/snap.ps-printer-app.ps-printer-app-server.service.d/override.conf
[Service]
ExecStart=
ExecStart=/usr/bin/snap run ps-printer-app.ps-printer-app-server -o log-level=debug
[vek@mybox ~]$ 

I find it quite useful to use a dummy printer, so you can test a lot without wasting a lot of paper. Eventually I will need to talk PJL+PCL to by real printer at some point in time. My Brother printer does not accept PCL without PJL.

I used to be a COBOL, Java and C developer, but now retired. Analyzing open source projects is just a hobby of mine.

[tillkamppeter]

Thanks for the info about how to modify the daemon startup process in Snaps without rebuilding them. Another way to switch a Printer Application Snap into debug mode is on the web interface. On the front page, at the left you have a button to get to the log file. On that page you can change the log level.

Could you post your little printer emulator program here?

Did you also try the Ghostscript Printer Application with your Brother printer? It supports many Brother models, also with PJL and with dedicated drivers. PostScript (BR-Script 3) Brother printers are supported by the PostScript Printer Application.

[ppywlkiqletw]

Just run 'cat' in a socket activated shell script. You could do the same with xinetd if you are old fashioned.

::::::::::::::
/etc/systemd/system/dummyprint@.service
::::::::::::::
[Unit]
Description=Dummy jetdirect print server

[Service]
ExecStart=-/usr/local/bin/dummyprint
StandardInput=socket
User=vek
::::::::::::::
/etc/systemd/system/dummyprint.socket
::::::::::::::
[Unit]
Description=Dummy jetdirect print server

[Socket]
ListenStream=9100
Accept=yes

[Install]
WantedBy=sockets.target
::::::::::::::
/usr/local/bin/dummyprint
::::::::::::::
#!/bin/sh

test -d /tmp/print || mkdir /tmp/print
cd /tmp/print || exit 1

file=$(date '+%Y%m%d-%H%M%S')

cat >$file

[ppywlkiqletw]

Did you also try the Ghostscript Printer Application with your Brother printer? It supports many Brother models, also with PJL and with dedicated drivers. PostScript (BR-Script 3) Brother printers are supported by the PostScript Printer Application.

It printer is a HL-2130. It does work; although a test yesterday got stuck in the filter chain of the printer application. One process stuck in a futex() call and the rest waiting in a read() frpm a pipe. I am not sure of enabling debug logging could have anything to do with it. Now I turned debug logging off and the printer is working.

I haven't used the printer driver from the Brother download site for many years now. It is old crap anyway.

--
Villy Kruse

[tillkamppeter]

Thanks for the info. Did the Ghostscript Printer Application auto-assign a driver/model to your printer? If so, which one? Or did you select manually? And if so, which one? If you do not remember, the web interface shows something like "Brother HL-2135, Foomatic/hl1250 (recommended)". What does it show for you?

Your printer is most probably a PCL 5e printer.

Do not use Brother's old drivers, they are awkward and probably not working well with more modern distributions.

[ppywlkiqletw]

Thanks for the info. Did the Ghostscript Printer Application auto-assign a driver/model to your printer? If so, which one? Or did you select manually? And if so, which one? If you do not remember, the web interface shows something like "Brother HL-2135, Foomatic/hl1250 (recommended)". What does it show for you?

I selected Brother HL-2140 Foomatic/hl1250 -- the same I have been using with cups.

Your printer is most probably a PCL 5e printer.

Generic PCL does not work unless it is encapsulate by PJL.

Do not use Brother's old drivers, they are awkward and probably not working well with more modern distributions.

Not to mention the drivers are 32 bit only compiled probably 10 years ago or more.

-- Villy

[ppywlkiqletw]

I forgot to mention that automatic selection gives

Unable to use that driver.

[tillkamppeter]

I have added a Brother HL-2130 entry to Foomatic now and triggered a rebuild of the Ghostscript Printer Application in the Snap Store. As soon as you get the update, your Brother printer can be auto-assigned.

[ppywlkiqletw]

I have added a Brother HL-2130 entry to Foomatic now and triggered a rebuild of the Ghostscript Printer Application in the Snap Store. As soon as you get the update, your Brother printer can be auto-assigned.

Now it auto-selects a printer driver and it works. The url

http://support.brother.com/g/s/id/linux/en/

is a dead link. I guess that does not really mater.