Bug 1520740 - Not shutting down on SIGTERM
Summary: Not shutting down on SIGTERM
Keywords:
Status: CLOSED RAWHIDE
Alias: None
Product: Fedora
Classification: Fedora
Component: dleyna-renderer
Version: 32
Hardware: Unspecified
OS: Unspecified
unspecified
unspecified
Target Milestone: ---
Assignee: Debarshi Ray
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2017-12-05 04:11 UTC by Robert Hancock
Modified: 2020-06-22 14:36 UTC (History)
7 users (show)

Fixed In Version:
Clone Of:
Environment:
Last Closed: 2020-06-22 14:36:04 UTC
Type: Bug
Embargoed:


Attachments (Terms of Use)


Links
System ID Private Priority Status Summary Last Updated
Github intel dleyna-renderer issues 164 0 None open Not shutting down on SIGTERM 2020-10-21 19:20:31 UTC

Description Robert Hancock 2017-12-05 04:11:58 UTC
Description of problem:
Frequently when I reboot my machine, dleyna-renderer-service fails to exit until it gets forcibly killed with SIGKILL after 90 seconds, causing a long reboot delay.

Version-Release number of selected component (if applicable):
dleyna-renderer-0.5.0-9.fc27.x86_64

How reproducible:
Often on my machine, not clear on others

Steps to Reproduce:
1. Reboot machine
2.
3.

Actual results:
Reboot delayed for 90 seconds

Expected results:
Reboot happens promptly

Additional info:
Here is the output of pstack on /usr/libexec/dleyna-renderer-service before rebooting. I've already sent it SIGTERM here which it has ignored. It seems like the soup_session_process_queue_item function is hanging in g_cond_wait.

Thread 4 (Thread 0x7f265d239700 (LWP 29626)):
#0  0x00007f26712f08bb in poll () at /lib64/libc.so.6
#1  0x00007f2671b86ed9 in g_main_context_iterate.isra () at /lib64/libglib-2.0.so.0
#2  0x00007f2671b86fec in g_main_context_iteration () at /lib64/libglib-2.0.so.0
#3  0x00007f265d24142d in dconf_gdbus_worker_thread () at /usr/lib64/gio/modules/libdconfsettings.so
#4  0x00007f2671bae4c6 in g_thread_proxy () at /lib64/libglib-2.0.so.0
#5  0x00007f26715cf609 in start_thread () at /lib64/libpthread.so.0
#6  0x00007f26712fce6f in clone () at /lib64/libc.so.6
Thread 3 (Thread 0x7f266d345700 (LWP 29619)):
#0  0x00007f26712f08bb in poll () at /lib64/libc.so.6
#1  0x00007f2671b86ed9 in g_main_context_iterate.isra () at /lib64/libglib-2.0.so.0
#2  0x00007f2671b87272 in g_main_loop_run () at /lib64/libglib-2.0.so.0
#3  0x00007f267216fb36 in gdbus_shared_thread_func () at /lib64/libgio-2.0.so.0
#4  0x00007f2671bae4c6 in g_thread_proxy () at /lib64/libglib-2.0.so.0
#5  0x00007f26715cf609 in start_thread () at /lib64/libpthread.so.0
#6  0x00007f26712fce6f in clone () at /lib64/libc.so.6
Thread 2 (Thread 0x7f266e1bb700 (LWP 29618)):
#0  0x00007f26712f08bb in poll () at /lib64/libc.so.6
#1  0x00007f2671b86ed9 in g_main_context_iterate.isra () at /lib64/libglib-2.0.so.0
#2  0x00007f2671b86fec in g_main_context_iteration () at /lib64/libglib-2.0.so.0
#3  0x00007f2671b87031 in glib_worker_main () at /lib64/libglib-2.0.so.0
#4  0x00007f2671bae4c6 in g_thread_proxy () at /lib64/libglib-2.0.so.0
#5  0x00007f26715cf609 in start_thread () at /lib64/libpthread.so.0
#6  0x00007f26712fce6f in clone () at /lib64/libc.so.6
Thread 1 (Thread 0x7f26737d2d00 (LWP 29617)):
#0  0x00007f26712f70d9 in syscall () at /lib64/libc.so.6
#1  0x00007f2671bcc54f in g_cond_wait () at /lib64/libglib-2.0.so.0
#2  0x00007f26724bea5f in soup_session_process_queue_item () at /lib64/libsoup-2.4.so.1
#3  0x00007f26724bf41e in soup_session_real_send_message () at /lib64/libsoup-2.4.so.1
#4  0x00007f2672b9dd6e in gupnp_service_info_get_introspection () at /lib64/libgupnp-1.0.so.4
#5  0x00007f26733e3761 in prv_props_update.isra () at /usr/lib64/dleyna-renderer/libdleyna-renderer-1.0.so.1
#6  0x00007f26733e501d in dlr_device_get_all_props () at /usr/lib64/dleyna-renderer/libdleyna-renderer-1.0.so.1
#7  0x00007f26731d5a8f in prv_process_task () at /lib64/libdleyna-core-1.0.so.4
#8  0x00007f2671b83597 in g_idle_dispatch () at /lib64/libglib-2.0.so.0
#9  0x00007f2671b86bb7 in g_main_context_dispatch () at /lib64/libglib-2.0.so.0
#10 0x00007f2671b86f60 in g_main_context_iterate.isra () at /lib64/libglib-2.0.so.0
#11 0x00007f2671b87272 in g_main_loop_run () at /lib64/libglib-2.0.so.0
#12 0x00007f26731d4bdc in dleyna_main_loop_start () at /lib64/libdleyna-core-1.0.so.4
#13 0x00007f267120403a in __libc_start_main () at /lib64/libc.so.6
#14 0x00005619017d19ba in _start ()

Comment 1 Ben Liblit 2017-12-06 06:35:12 UTC
<https://github.com/intel/dleyna-renderer/issues/164> may be the corresponding upstream bug.

Comment 2 David Strauss 2018-08-16 02:49:52 UTC
I am experiencing this on Fedora 28. Bumping affected version.

Aug 15 19:39:39 t580.davidstrauss.net systemd[1]: Requested transaction contradicts existing jobs: Resource deadlock avoided
Aug 15 19:40:47 t580.davidstrauss.net systemd[1627]: dbus.service: State 'stop-final-sigterm' timed out. Killing.
Aug 15 19:40:47 t580.davidstrauss.net systemd[1627]: dbus.service: Killing process 12359 (dleyna-renderer) with signal SIGKILL.
Aug 15 19:40:47 t580.davidstrauss.net systemd[1627]: dbus.service: Failed with result 'timeout'.

Comment 3 Federico Bruni 2019-01-16 06:36:18 UTC
I am experiencing the same problem on Fedora 29:

gen 16 06:39:47 fedora systemd[1579]: dbus.service: State 'stop-final-sigterm' timed out. Killing.
gen 16 06:39:47 fedora systemd[1579]: dbus.service: Killing process 3643 (dleyna-renderer) with signal SIGKILL.
gen 16 06:39:47 fedora systemd[1579]: dbus.service: Killing process 3644 (n/a) with signal SIGKILL.
gen 16 06:39:47 fedora systemd[1579]: dbus.service: Killing process 3645 (gdbus) with signal SIGKILL.
gen 16 06:39:47 fedora systemd[1579]: dbus.service: Failed with result 'timeout'.


As suggested on upstream issue, I've removed gnome-photos, which is the application depending on dleyna-renderer.

Comment 4 Edouard Bourguignon 2019-04-10 18:25:39 UTC
Same on F30, removing gnome-photos has fixed this bug.

Comment 5 Ben Cotton 2019-05-02 19:41:38 UTC
This message is a reminder that Fedora 28 is nearing its end of life.
On 2019-May-28 Fedora will stop maintaining and issuing updates for
Fedora 28. It is Fedora's policy to close all bug reports from releases
that are no longer maintained. At that time this bug will be closed as
EOL if it remains open with a Fedora 'version' of '28'.

Package Maintainer: If you wish for this bug to remain open because you
plan to fix it in a currently maintained version, simply change the 'version' 
to a later Fedora version.

Thank you for reporting this issue and we are sorry that we were not 
able to fix it before Fedora 28 is end of life. If you would still like 
to see this bug fixed and are able to reproduce it against a later version 
of Fedora, you are encouraged  change the 'version' to a later Fedora 
version prior this bug is closed as described in the policy above.

Although we aim to fix as many bugs as possible during every release's 
lifetime, sometimes those efforts are overtaken by events. Often a 
more recent Fedora release includes newer upstream software that fixes 
bugs or makes them obsolete.

Comment 6 David Strauss 2019-05-02 20:21:43 UTC
Bumping to F30, per previous comments.

Comment 7 Jonas Jonsson 2020-03-24 09:03:57 UTC
Happens on Fedora 31 as well.

mar 24 09:41:58 jjxps systemd[2329]: dbus\x2d:1.2\x2dcom.intel.dleyna\x2drenderer.slice: Consumed 2.447s CPU time.
mar 24 09:41:58 jjxps systemd[2329]: Removed slice dbus\x2d:1.2\x2dcom.intel.dleyna\x2drenderer.slice.
mar 24 09:41:58 jjxps systemd[2329]: dbus-:1.2-com.intel.dleyna-renderer: Consumed 1.101s CPU time.
mar 24 09:41:58 jjxps systemd[2329]: Stopped dbus-:1.2-com.intel.dleyna-renderer.
mar 24 09:41:58 jjxps systemd[2329]: dbus-:1.2-com.intel.dleyna-renderer: Failed with result 'timeout'.
mar 24 09:41:58 jjxps systemd[2329]: dbus-:1.2-com.intel.dleyna-renderer: Killing process 385709 (dleyna-renderer) with signal SIGKILL.
mar 24 09:41:58 jjxps systemd[2329]: dbus-:1.2-com.intel.dleyna-renderer: State 'stop-sigterm' timed out. Killing.
mar 24 09:41:09 jjxps kernel: Console: switching to colour frame buffer device 240x67
mar 24 09:41:09 jjxps kernel: fbcon: Taking over console
mar 24 09:40:29 jjxps systemd[1]: dracut-shutdown.service: Consumed 1.873s CPU time.
mar 24 09:40:29 jjxps systemd[1]: Stopped Restore /run/initramfs on shutdown.

dleyna-renderer-0.6.0-5.fc31.x86_64

It appears that the upstream Intel project on Github is more or less dead, last commit is close to three years ago.

A fork that appears to fix this issue can be found: https://github.com/phako/dleyna-renderer

The author didn't get any response to the request of the future of the project, https://lists.01.org/hyperkitty/list/dleyna@lists.01.org/thread/RA3MDCRLSETYGRJNI432C6G6KX64AK35/

Comment 8 Markus Rathgeb 2020-04-18 10:45:41 UTC
I run into the same problem on every shutdown / reboot of my Fedora 32 machine.

Apr 18 00:35:35 m3800.localdomain systemd[1705]: gnome-session-restart-dbus.service: Child 12165 belongs to gnome-session-restart-dbus.service.
Apr 18 00:35:35 m3800.localdomain systemd[1705]: gnome-session-restart-dbus.service: Main process exited, code=exited, status=0/SUCCESS
Apr 18 00:35:35 m3800.localdomain systemd[1705]: gnome-session-restart-dbus.service: Succeeded.
Apr 18 00:35:35 m3800.localdomain systemd[1705]: gnome-session-restart-dbus.service: Service will not restart (restart setting)
Apr 18 00:35:35 m3800.localdomain systemd[1705]: gnome-session-restart-dbus.service: Changed running -> dead
Apr 18 00:35:35 m3800.localdomain systemd[1705]: gnome-session-restart-dbus.service: Consumed 5ms CPU time.
Apr 18 00:35:35 m3800.localdomain systemd[1705]: gnome-session-restart-dbus.service: Collecting.
Apr 18 00:37:05 m3800.localdomain systemd[1705]: dbus-:1.2-com.intel.dleyna-renderer: State 'stop-sigterm' timed out. Killing.
Apr 18 00:37:05 m3800.localdomain systemd[1705]: dbus-:1.2-com.intel.dleyna-renderer: Killing process 6503 (dleyna-renderer) with signal SIGKILL.
Apr 18 00:37:05 m3800.localdomain systemd[1705]: dbus-:1.2-com.intel.dleyna-renderer: Changed stop-sigterm -> stop-sigkill
Apr 18 00:37:05 m3800.localdomain systemd[1705]: Received SIGCHLD.
Apr 18 00:37:05 m3800.localdomain systemd[1705]: Child 6503 (dleyna-renderer) died (code=killed, status=9/KILL)
Apr 18 00:37:05 m3800.localdomain systemd[1705]: dbus-:1.2-com.intel.dleyna-renderer: Child 6503 belongs to dbus-:1.2-com.intel.dleyna-renderer.
Apr 18 00:37:05 m3800.localdomain systemd[1705]: dbus-:1.2-com.intel.dleyna-renderer: Main process exited, code=killed, status=9/KILL
Apr 18 00:37:05 m3800.localdomain systemd[1705]: dbus-:1.2-com.intel.dleyna-renderer: Failed with result 'timeout'.
Apr 18 00:37:05 m3800.localdomain systemd[1705]: dbus-:1.2-com.intel.dleyna-renderer: Service restart not allowed.
Apr 18 00:37:05 m3800.localdomain systemd[1705]: dbus-:1.2-com.intel.dleyna-renderer: Changed stop-sigkill -> failed
Apr 18 00:37:05 m3800.localdomain systemd[1705]: dbus-:1.2-com.intel.dleyna-renderer: Job 2084 dbus-:1.2-com.intel.dleyna-renderer/stop finished, result=done
Apr 18 00:37:05 m3800.localdomain systemd[1705]: dbus-:1.2-com.intel.dleyna-renderer: Unit entered failed state.
Apr 18 00:37:05 m3800.localdomain systemd[1705]: dbus-:1.2-com.intel.dleyna-renderer: Consumed 554ms CPU time.
Apr 18 00:37:05 m3800.localdomain systemd[1705]: dbus-:1.2-com.intel.dleyna-renderer: Control group is empty.
Apr 18 00:37:05 m3800.localdomain systemd[1705]: dbus\x2d:1.2\x2dcom.intel.dleyna\x2drenderer.slice changed active -> dead
Apr 18 00:37:05 m3800.localdomain systemd[1705]: dbus\x2d:1.2\x2dcom.intel.dleyna\x2drenderer.slice: Job 2083 dbus\x2d:1.2\x2dcom.intel.dleyna\x2drenderer.slice/stop finished, result=done
Apr 18 00:37:05 m3800.localdomain systemd[1705]: dbus\x2d:1.2\x2dcom.intel.dleyna\x2drenderer.slice: Consumed 1.142s CPU time.

Comment 9 Debarshi Ray 2020-06-22 14:36:04 UTC
This is fixed in Rawhide.


Note You need to log in before you can comment on or make changes to this bug.