SIGABRTs on various places, causing issues in web ui

[zdohnal]

If I run ps-printer-app in SNAP, I sometimes get errors like

The connection was reset

The connection to the server was reset while the page was loading.

when I'm adding the new printer. I click on 'Try again', and the web ui reports "Invalid form submission.".

[zdohnal]

Now I printed test page (clicked on 'Print test page') and got:

Unable to connect

Firefox can’t establish a connection to the server at localhost:8000.

I click to 'try again', 'resend' and got 'invalid form submission' in UI, but the job is printed, however it is shown in job history as:

4 | Test Page | guest | 0 | Started at 13:51:17 | Cancel Job

[tillkamppeter]

Are able to access the web interface at all? If so, try to switch to debug mode as described in issue OpenPrinting/pappl-retrofit#2, then try to get the error again and after that attach the log file. Thanks.

[zdohnal]

Yes, I'm able to access the interface - the error happened when I was adding the printer via ps-printer-app web ui and printing test page via ui.

[tillkamppeter]

Please check the log file whether the app stops/crashes and restarts (auto-restarted by systemd after a crash?). The app always starts with Log Level set to "error", but once the log level changed it is supposed to keep it. Also check syslog for messages indicating that a crash has happened.

[zdohnal]

Ding, ding, ding, we have a winner :) yep, the ps-printer-app in SNAP gets sigabrt, but snapd immediately brings it up again - that's one way how to fight against crashes :) .

I'm trying to figure out how to get debug symbols for coredump from snap, because gdb shows only ?? on important places, but it doesn't tell which debug symbols to install... I'm using coredumpctl debug, any suggestions how I can get you better backtrace?

[tillkamppeter]

I do not really have a recipe for how to get back traces from within Snaps. You can get a shell in the Snap environment to run the executable manually

sudo snap run --shell ps-printer-app

[zdohnal]

The log is the same as in OpenPrinting/pappl-retrofit#2

The sigabrt happens somewhere around here in the log:

498 D [2022-05-18T11:51:27.496Z] [Job 4] Closed the pipes for back and side channels
499 D [2022-05-18T11:51:27.501Z] Control message: STATE: +connecting-to-device
500 D [2022-05-18T11:51:27.501Z] cfFilterExternalCUPS (socket): Looking up \"192.168.0.112\"...
501 D [2022-05-18T11:51:27.501Z] Control message: STATE: -connecting-to-device
502 D [2022-05-18T11:51:27.501Z] cfFilterExternalCUPS (socket): 192.168.0.112=192.168.0.112
503 D [2022-05-18T11:51:27.501Z] cfFilterExternalCUPS (socket): backendWaitLoop(snmp_fd=5, addr=0x55f6ef58cd08, side_cb=0x55f6ef1c136c)
504 I [2022-05-18T11:51:28.109Z] cfFilterExternalCUPS (socket): Backend (PID 138239) exited with no errors.
505 I [2022-05-18T11:51:28.113Z] cfFilterExternalCUPS (socket): Logging (PID 138240) exited with no errors.
506 D [2022-05-18T11:51:28.113Z] cfFilterPOpen: Filter function completed with status 0.

Here is the journal (the sequence is reverted - the first message came as the last)

May 18 13:51:27 fedora audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=systemd-coredump@13-138241-0 comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? >
May 18 13:51:27 fedora systemd[1]: Started Process Core Dump (PID 138241/UID 0).
May 18 13:51:27 fedora audit: BPF prog-id=352 op=LOAD
May 18 13:51:27 fedora audit: BPF prog-id=351 op=LOAD
May 18 13:51:27 fedora audit: BPF prog-id=350 op=LOAD
May 18 13:51:27 fedora ps-printer-app.ps-printer-app-server[136781]: free(): double free detected in tcache 2

There is a time difference, because I'm in CET timezone and PAPPL seems to use UTC.

[zdohnal]

I've tested the current version and I don't get the mentioned errors, closing the issue.

Thank you for the help!