Kdenlive cannot render any projects (stuck in "waiting...")

Probably not. I’m just pointing out the reason for those denials. The loader tries the rpath first, and thus we get a denial.

The render queue problem seems related to this:

starting kdenlive_render process using:  "/snap/kdenlive/39/usr/bin/kdenlive_render"
Qt: Session management error: Could not open network socket
No org.kde.JobViewServer registered, trying to start kuiserver
Failed to start kuiserver

Ah very insightful, this seems to imply that the kde-frameworks-5-qt-5-15-3-core20 snap is built incorrectly, I’m not sure why it was built such that the dynamic libraries there have rpath setup to look in /snap/core20/current/… unless that content snap was built to be consumed by classic snaps somehow?

Do you see any journal denials on your system when this happens? I don’t see this message on the terminal when I tried testing kdenlive last week by just doing snap run kdenlive

Nothing interesting:

= AppArmor =
Time: Sep 29 09:55:54
Log: apparmor="DENIED" operation="dbus_method_call"  bus="session" path="/org/freedesktop/DBus" interface="org.freedesktop.DBus" member="ListNames" mask="send" name="org.freedesktop.DBus" pid=21594 label="snap.kdenlive.kdenlive" peer_label="unconfined"
DBus access

= AppArmor =
Time: Sep 29 09:55:54
Log: apparmor="DENIED" operation="dbus_method_call"  bus="session" path="/org/a11y/bus" interface="org.freedesktop.DBus.Properties" member="Get" mask="send" name="org.a11y.Bus" pid=21594 label="snap.kdenlive.kdenlive" peer_pid=7265 peer_label="unconfined"
DBus access

= AppArmor =
Time: Sep 29 09:55:54
Log: apparmor="DENIED" operation="open" profile="snap.kdenlive.kdenlive" name="/snap/core20/1081/usr/lib/x86_64-linux-gnu/libsystemd.so.0.28.0" pid=21600 comm="melt-7" requested_mask="r" denied_mask="r" fsuid=1001 ouid=0
File: /snap/core20/1081/usr/lib/x86_64-linux-gnu/libsystemd.so.0.28.0 (read)
Suggestion:
* adjust program to read necessary files from $SNAP, $SNAP_DATA, $SNAP_COMMON, $SNAP_USER_DATA or $SNAP_USER_COMMON

= AppArmor =
Time: Sep 29 09:55:54
Log: apparmor="DENIED" operation="open" profile="snap.kdenlive.kdenlive" name="/snap/core20/1081/usr/lib/x86_64-linux-gnu/libwrap.so.0.7.6" pid=21600 comm="melt-7" requested_mask="r" denied_mask="r" fsuid=1001 ouid=0
File: /snap/core20/1081/usr/lib/x86_64-linux-gnu/libwrap.so.0.7.6 (read)
Suggestion:
* adjust program to read necessary files from $SNAP, $SNAP_DATA, $SNAP_COMMON, $SNAP_USER_DATA or $SNAP_USER_COMMON

= AppArmor =
Time: Sep 29 09:55:54
Log: apparmor="DENIED" operation="open" profile="snap.kdenlive.kdenlive" name="/snap/core20/1081/usr/lib/x86_64-linux-gnu/libapparmor.so.1.6.1" pid=21600 comm="melt-7" requested_mask="r" denied_mask="r" fsuid=1001 ouid=0
File: /snap/core20/1081/usr/lib/x86_64-linux-gnu/libapparmor.so.1.6.1 (read)
Suggestion:
* adjust program to read necessary files from $SNAP, $SNAP_DATA, $SNAP_COMMON, $SNAP_USER_DATA or $SNAP_USER_COMMON

= AppArmor =
Time: Sep 29 09:55:54
Log: apparmor="DENIED" operation="open" profile="snap.kdenlive.kdenlive" name="/snap/core20/1081/usr/lib/x86_64-linux-gnu/librt-2.31.so" pid=21600 comm="melt-7" requested_mask="r" denied_mask="r" fsuid=1001 ouid=0
File: /snap/core20/1081/usr/lib/x86_64-linux-gnu/librt-2.31.so (read)
Suggestion:
* adjust program to read necessary files from $SNAP, $SNAP_DATA, $SNAP_COMMON, $SNAP_USER_DATA or $SNAP_USER_COMMON

= AppArmor =
Time: Sep 29 09:55:54
Log: apparmor="DENIED" operation="open" profile="snap.kdenlive.kdenlive" name="/snap/core20/1081/usr/lib/x86_64-linux-gnu/liblzma.so.5.2.4" pid=21600 comm="melt-7" requested_mask="r" denied_mask="r" fsuid=1001 ouid=0
File: /snap/core20/1081/usr/lib/x86_64-linux-gnu/liblzma.so.5.2.4 (read)
Suggestion:
* adjust program to read necessary files from $SNAP, $SNAP_DATA, $SNAP_COMMON, $SNAP_USER_DATA or $SNAP_USER_COMMON

= AppArmor =
Time: Sep 29 09:55:54
Log: apparmor="DENIED" operation="open" profile="snap.kdenlive.kdenlive" name="/snap/core20/1081/usr/lib/x86_64-linux-gnu/liblz4.so.1.9.2" pid=21600 comm="melt-7" requested_mask="r" denied_mask="r" fsuid=1001 ouid=0
File: /snap/core20/1081/usr/lib/x86_64-linux-gnu/liblz4.so.1.9.2 (read)
Suggestion:
* adjust program to read necessary files from $SNAP, $SNAP_DATA, $SNAP_COMMON, $SNAP_USER_DATA or $SNAP_USER_COMMON

= AppArmor =
Time: Sep 29 09:55:54
Log: apparmor="DENIED" operation="open" profile="snap.kdenlive.kdenlive" name="/snap/core20/1081/usr/lib/x86_64-linux-gnu/libgcrypt.so.20.2.5" pid=21600 comm="melt-7" requested_mask="r" denied_mask="r" fsuid=1001 ouid=0
File: /snap/core20/1081/usr/lib/x86_64-linux-gnu/libgcrypt.so.20.2.5 (read)
Suggestion:
* adjust program to read necessary files from $SNAP, $SNAP_DATA, $SNAP_COMMON, $SNAP_USER_DATA or $SNAP_USER_COMMON

= AppArmor =
Time: Sep 29 09:55:54
Log: apparmor="DENIED" operation="open" profile="snap.kdenlive.kdenlive" name="/snap/core20/1081/usr/lib/x86_64-linux-gnu/libnsl-2.31.so" pid=21600 comm="melt-7" requested_mask="r" denied_mask="r" fsuid=1001 ouid=0
File: /snap/core20/1081/usr/lib/x86_64-linux-gnu/libnsl-2.31.so (read)
Suggestion:
* adjust program to read necessary files from $SNAP, $SNAP_DATA, $SNAP_COMMON, $SNAP_USER_DATA or $SNAP_USER_COMMON

= AppArmor =
Time: Sep 29 09:55:54
Log: apparmor="DENIED" operation="open" profile="snap.kdenlive.kdenlive" name="/snap/core20/1081/usr/lib/x86_64-linux-gnu/libresolv-2.31.so" pid=21600 comm="melt-7" requested_mask="r" denied_mask="r" fsuid=1001 ouid=0
File: /snap/core20/1081/usr/lib/x86_64-linux-gnu/libresolv-2.31.so (read)
Suggestion:
* adjust program to read necessary files from $SNAP, $SNAP_DATA, $SNAP_COMMON, $SNAP_USER_DATA or $SNAP_USER_COMMON

= AppArmor =
Time: Sep 29 09:55:54
Log: apparmor="DENIED" operation="open" profile="snap.kdenlive.kdenlive" name="/snap/core20/1081/usr/lib/x86_64-linux-gnu/libgpg-error.so.0.28.0" pid=21600 comm="melt-7" requested_mask="r" denied_mask="r" fsuid=1001 ouid=0
File: /snap/core20/1081/usr/lib/x86_64-linux-gnu/libgpg-error.so.0.28.0 (read)
Suggestion:
* adjust program to read necessary files from $SNAP, $SNAP_DATA, $SNAP_COMMON, $SNAP_USER_DATA or $SNAP_USER_COMMON

= AppArmor =
Time: Sep 29 09:55:54
Log: apparmor="DENIED" operation="open" profile="snap.kdenlive.kdenlive" name="/var/lib/snapd/hostfs/usr/lib/x86_64-linux-gnu/libOpenGL.so.0.0.0" pid=21600 comm="melt-7" requested_mask="r" denied_mask="r" fsuid=1001 ouid=0
File: /var/lib/snapd/hostfs/usr/lib/x86_64-linux-gnu/libOpenGL.so.0.0.0 (read)
Suggestions:
* adjust program to read necessary files from $SNAP, $SNAP_DATA, $SNAP_COMMON, $SNAP_USER_DATA or $SNAP_USER_COMMON
* adjust snap to use snap layouts (https://forum.snapcraft.io/t/snap-layouts/7207)

= AppArmor =
Time: Sep 29 09:55:54
Log: apparmor="DENIED" operation="dbus_method_call"  bus="session" path="/org/a11y/bus" interface="org.freedesktop.DBus.Properties" member="Get" mask="send" name="org.a11y.Bus" pid=21594 label="snap.kdenlive.kdenlive" peer_pid=7265 peer_label="unconfined"
DBus access

An interesting observation: For me, the videos get rendered just fine. It’s just that kdenlive does not get feedback from its renderer process. So that’s where we need to investigate. So probably dbus related: https://github.com/KDE/kdenlive/blob/a24b8fe294905cd2f6f562555ca5271d5bb936e8/renderer/renderjob.cpp#L273

I think it’s a dbus permission problem. If you install with devmode and set QDBUS_DEBUG=1, you can see the working communication between kdenlive_render and kdenlive.

I think it fails here:

QDBusConnectionPrivate(0x7f52e0003c00) sending message: QDBusMessage(type=MethodCall, service="org.freedesktop.DBus", path="/org/freedesktop/DBus", interface="org.freedesktop.DBus", member="ListNames", signature="", contents=() )

QDBusConnectionPrivate(0x7f52e0003c00) got message reply: QDBusMessage(type=Error, service="org.freedesktop.DBus", error name="org.freedesktop.DBus.Error.AccessDenied", error message="An AppArmor policy prevents this sender from sending this message to this recipient; type=\"method_call\", sender=\":1.286\" (uid=1001 pid=68175 comm=\"/snap/kdenlive/x4/usr/bin/kdenlive_render /snap/kd\" label=\"snap.kdenlive.kdenlive (enforce)\") interface=\"org.freedesktop.DBus\" member=\"ListNames\" error name=\"(unset)\" requested_reply=\"0\" destination=\"org.freedesktop.DBus\" (bus)", signature="s", contents=("An AppArmor policy prevents this sender from sending this message to this recipient; type="method_call", sender=":1.286" (uid=1001 pid=68175 comm="/snap/kdenlive/x4/usr/bin/kdenlive_render /snap/kd" label="snap.kdenlive.kdenlive (enforce)") interface="org.freedesktop.DBus" member="ListNames" error name="(unset)" requested_reply="0" destination="org.freedesktop.DBus" (bus)") )

which means it probably needs the system-observe interface. I tried and this seems to solve the problem. Is that an interface that makes sense for a video editor, and would autoconnect be granted?

1 Like

Yes I think system-observe is reasonable to be granted auto-connection for a video editor, if one of the snap collaborators can add system-observe to the snap and then start a forum topic in #store-requests for auto-connection we can get that moving.

I’m still very confused why the qt content snap has these rpaths set like that, it probably needs to be looked at more

1 Like

@jriddell https://invent.kde.org/packaging/snapcraft-kde-applications/-/merge_requests/2

building https://build.neon.kde.org/view/Snaps/job/focal_release_forks_kdenlive_snap_amd64/

Oh no. I proposed the change for the wrong snap :man_facepalming: (ark instead of kdenlive). Sorry. See https://invent.kde.org/packaging/snapcraft-kde-applications/-/merge_requests/3 for the real fix.

mm, indeed. Building again https://build.neon.kde.org/view/Snaps/job/focal_release_forks_kdenlive_snap_amd64/

Revision 44 solves the problem for me with system-observe connected. You should request an auto-connection and then publish it to stable.

Consider https://build.neon.kde.org/view/Snaps/job/kde-frameworks-5-qt-5-15-3-core20-release_amd64.snap/lastSuccessfulBuild/artifact/build.snapcraft.yaml

specifically

kf5:
        after: []
        plugin: nil
        build-attributes:
        - enable-patchelf

I reckon this is the culprit for those strange rpaths. This stems from https://invent.kde.org/packaging/snap-kf5/-/blob/core20/atomize-debs.rb#L205, I think.
But that seems to be an intentional addition:
https://invent.kde.org/packaging/snap-kf5/-/commit/507bb1027b2a077247dee95502ffc55abd8e3f7c

From: Jonathan Riddell jr@jriddell.org
Date: Tue, 9 Feb 2021 10:52:34 +0000
Subject: [PATCH] enable patchelf as we can not do the hack of patchelf
manually as we did in core18 (see Rakefile) cos now snapcraft is installed as
a readonly snap

Probably something for @sergiusens to comment on when he is back

requested

The auto connect was set and I had some testers who got it to work so I’ve now published this to stable again

1 Like

I can still reproduce the problem with the snap “latest/stable: 21.12.2 2022-02-10 (48)”.

The rendering also gets stuck in “waiting…”.

Kdenlive log:

Qt: Session management error: Could not open network socket
dbus[2237125]: arguments to dbus_message_new_method_call() were incorrect, assertion "_dbus_check_is_valid_path (path)" failed in file ../../../dbus/dbus-message.c line 1366.
This is normally a bug in some application using the D-Bus library.

  D-Bus not built with -rdynamic so unable to print a backtrace

journalctl log:

mars 14 09:39:01 - audit[2237125]: AVC apparmor="DENIED" operation="open" profile="snap.kdenlive.kdenlive" name="/snap/core20/1376/usr/lib/x86_64-linux-gnu/libpcre2-8.so.0.9.0" pid=2237125 comm="kdenlive_render" requested_mask="r" denied_mask="r" fsuid=1000 ouid=0
mars 14 09:39:01 - audit[2237125]: AVC apparmor="DENIED" operation="open" profile="snap.kdenlive.kdenlive" name="/snap/core20/1376/usr/lib/x86_64-linux-gnu/libpcre2-8.so.0.9.0" pid=2237125 comm="kdenlive_render" requested_mask="r" denied_mask="r" fsuid=1000 ouid=0
mars 14 09:39:01 - audit[2237125]: AVC apparmor="DENIED" operation="open" profile="snap.kdenlive.kdenlive" name="/snap/core20/1376/usr/lib/x86_64-linux-gnu/libkeyutils.so.1.8" pid=2237125 comm="kdenlive_render" requested_mask="r" denied_mask="r" fsuid=1000 ouid=0
mars 14 09:39:01 - audit[2237125]: AVC apparmor="DENIED" operation="open" profile="snap.kdenlive.kdenlive" name="/snap/core20/1376/usr/lib/x86_64-linux-gnu/libkeyutils.so.1.8" pid=2237125 comm="kdenlive_render" requested_mask="r" denied_mask="r" fsuid=1000 ouid=0
mars 14 09:39:01 - audit[2237125]: AVC apparmor="DENIED" operation="open" profile="snap.kdenlive.kdenlive" name="/snap/core20/1376/usr/lib/x86_64-linux-gnu/libkeyutils.so.1.8" pid=2237125 comm="kdenlive_render" requested_mask="r" denied_mask="r" fsuid=1000 ouid=0
mars 14 09:39:01 - audit[2237125]: AVC apparmor="DENIED" operation="open" profile="snap.kdenlive.kdenlive" name="/snap/core20/1376/usr/lib/x86_64-linux-gnu/libresolv-2.31.so" pid=2237125 comm="kdenlive_render" requested_mask="r" denied_mask="r" fsuid=1000 ouid=0
mars 14 09:39:01 - audit[2237125]: AVC apparmor="DENIED" operation="open" profile="snap.kdenlive.kdenlive" name="/snap/core20/1376/usr/lib/x86_64-linux-gnu/libresolv-2.31.so" pid=2237125 comm="kdenlive_render" requested_mask="r" denied_mask="r" fsuid=1000 ouid=0
mars 14 09:39:01 - audit[2237125]: AVC apparmor="DENIED" operation="open" profile="snap.kdenlive.kdenlive" name="/snap/core20/1376/usr/lib/x86_64-linux-gnu/libresolv-2.31.so" pid=2237125 comm="kdenlive_render" requested_mask="r" denied_mask="r" fsuid=1000 ouid=0

Kdenlive snap still getting stuck in waiting for me (latest/stable:21.12.2). The output of ‘snap run kdenlive’ at the moment of rendering is

=== REG FOCUS:  false
qml: ENDING DRAG!!!!!!!!!!!!!!!!!!!!!!

=== REG FOCUS:  false
qml: ENDING DRAG!!!!!!!!!!!!!!!!!!!!!!

qml: ENDING DRAG!!!!!!!!!!!!!!!!!!!!!!

I really wish this snap was given more attention, as the new features and optimizations of the latest version are very exciting to use.

I can confirm that kdenlive stopped working. It doesn’t get stuck in waiting; it does not react at all to clicks on the “render to file” button.

Also, trying to choose a different output file path yields:

image

Rev 46 & 48 show the same behaviour. I guess it doesn’t even start kdenlive_render. This would need some debugging to figure it.

Still have a same problem with kdenlive 21.12.2 on kubuntu 22.04 snap. But when I install it from apt woks fine.

For me, kdenlive works fine on 22.04 as long as there are clips in the timeline. The usual warning dialog if you don’t have any clips in the timeline does not appear in the snap though.

But I had a clip in my timeline. BTW I have a AMD GPU so there is no NVIDIA. Is there a command to run kdenlive on dev mode so I can send more logs for you guys?