xbmc / xbmc

Kodi is an award-winning free and open source home theater/media center software and entertainment hub for digital media. With its beautiful interface and powerful skinning engine, it's available for Android, BSD, Linux, macOS, iOS, tvOS and Windows.
https://kodi.tv/
Other
18.58k stars 6.31k forks source link

kodi fails to resume with lirc + devinput + mcusb #16093

Open ossman opened 5 years ago

ossman commented 5 years ago

Bug report

Describe the bug

I've set up a new standalone Kodi system and decided to try out a simpler setup by using lirc in devinput mode for my mceusb remote (as not all keys work when going via X11).

Mostly works great. Except for one thing!

Suspending the machine by pressing the power button on the remote works fine. But it is almost impossible to resume the machine by pressing the power button on the remote again. I think I've managed to get it working just once.

Expected Behavior

Machine resumes, Kodi is back up and working.

Actual Behavior

Machine resumes, then quickly suspends again.

Possible Fix

The power key should probably be ignored for a while after resume.

To Reproduce

Steps to reproduce the behavior:

  1. Configure lirc with devinput.
  2. Add KEY_SLEEP to your Lircmap.xml (should probably open another issue for this)
  3. Start Kodi.
  4. Press power key on remote.
  5. (machine suspends)
  6. Press power key on remote again.

Debuglog

This is an idle system that gets one power key press to suspend, followed by a slight wait and then another press in an attempt to wake the system.

2019-05-07 18:09:45.132 T:140524267718400   DEBUG: LIRC: - NEW 000000008001008e 00 KEY_SLEEP devinput-32 (KEY_SLEEP)
2019-05-07 18:09:45.144 T:140524276139200   DEBUG: HandleKey: rewind (0xc4) pressed, action is ShutDown()
2019-05-07 18:09:45.579 T:140524276139200   DEBUG: LogindUPowerSyscall: Received PrepareForSleep with arg 1
2019-05-07 18:09:45.579 T:140524276139200   DEBUG: ------ Window Init (DialogBusy.xml) ------
2019-05-07 18:09:45.579 T:140524276139200  NOTICE: OnSleep: Running sleep jobs
2019-05-07 18:09:45.579 T:140524276139200   DEBUG: CApplication::CloseNetworkShares: Closing all network shares
2019-05-07 18:09:45.579 T:140524276139200   DEBUG: LogindUPowerSyscall - delay lock sleep released
2019-05-07 18:09:45.579 T:140524276111104   DEBUG: CAnnouncementManager - Announcement: OnSleep from xbmc
2019-05-07 18:09:45.579 T:140524276111104   DEBUG: GOT ANNOUNCEMENT, type: 8, from xbmc, message OnSleep
2019-05-07 18:10:07.304 T:140524267718400   DEBUG: LIRC: - NEW 000000008001008e 00 KEY_SLEEP devinput-32 (KEY_SLEEP)
2019-05-07 18:10:07.334 T:140524276139200   DEBUG: LogindUPowerSyscall: Received PrepareForSleep with arg 0
2019-05-07 18:10:07.334 T:140524276139200  NOTICE: OnWake: Running resume jobs
2019-05-07 18:10:07.334 T:140524276139200   DEBUG: ------ Window Deinit (DialogBusy.xml) ------
2019-05-07 18:10:07.340 T:140524259325696   DEBUG: PulseAudio: Context authorizing
2019-05-07 18:10:07.341 T:140524259325696   DEBUG: PulseAudio: Context setting name
2019-05-07 18:10:07.343 T:140524259325696   DEBUG: PulseAudio: Context ready
2019-05-07 18:10:07.343 T:140524259325696 WARNING: Pulseaudio module module-allow-passthrough not loaded - opening PT devices might fail
2019-05-07 18:10:07.343 T:140522798704384   DEBUG: PulseAudio: Found Raven/Raven2/Fenghuang HDMI/DP Audio Controller Digital Surround 5.1 (HDMI) with devicestring alsa_output.pci-0000_38_00.1.hdmi-surround
2019-05-07 18:10:07.343 T:140524259325696  NOTICE: Found 1 Lists of Devices
2019-05-07 18:10:07.343 T:140524259325696  NOTICE: Enumerated PULSE devices:
2019-05-07 18:10:07.343 T:140524259325696  NOTICE:     Device 1
2019-05-07 18:10:07.343 T:140524259325696  NOTICE:         m_deviceName      : Default
2019-05-07 18:10:07.343 T:140524259325696  NOTICE:         m_displayName     : Default
2019-05-07 18:10:07.343 T:140524259325696  NOTICE:         m_displayNameExtra: Default Output Device (PULSEAUDIO)
2019-05-07 18:10:07.344 T:140524259325696  NOTICE:         m_deviceType      : AE_DEVTYPE_PCM
2019-05-07 18:10:07.345 T:140524259325696  NOTICE:         m_channels        : FL, FR
2019-05-07 18:10:07.345 T:140524259325696  NOTICE:         m_sampleRates     : 5512,8000,11025,16000,22050,32000,44100,48000,64000,88200,96000,176400,192000,384000
2019-05-07 18:10:07.345 T:140524259325696  NOTICE:         m_dataFormats     : AE_FMT_U8,AE_FMT_S16NE,AE_FMT_S24NE3,AE_FMT_S24NE4,AE_FMT_S32NE,AE_FMT_FLOAT
2019-05-07 18:10:07.345 T:140524259325696  NOTICE:         m_streamTypes     : No passthrough capabilities
2019-05-07 18:10:07.345 T:140524259325696  NOTICE:     Device 2
2019-05-07 18:10:07.345 T:140524259325696  NOTICE:         m_deviceName      : alsa_output.pci-0000_38_00.1.hdmi-surround
2019-05-07 18:10:07.345 T:140524259325696  NOTICE:         m_displayName     : Raven/Raven2/Fenghuang HDMI/DP Audio Controller Digital Surround 5.1 (HDMI)
2019-05-07 18:10:07.345 T:140524259325696  NOTICE:         m_displayNameExtra: HDMI / DisplayPort (PULSEAUDIO)
2019-05-07 18:10:07.345 T:140524259325696  NOTICE:         m_deviceType      : AE_DEVTYPE_PCM
2019-05-07 18:10:07.345 T:140524259325696  NOTICE:         m_channels        : FL, FR, BL, BR, FC, LFE
2019-05-07 18:10:07.345 T:140524259325696  NOTICE:         m_sampleRates     : 5512,8000,11025,16000,22050,32000,44100,48000,64000,88200,96000,176400,192000,384000
2019-05-07 18:10:07.345 T:140524259325696  NOTICE:         m_dataFormats     : AE_FMT_U8,AE_FMT_S16NE,AE_FMT_S24NE3,AE_FMT_S24NE4,AE_FMT_S32NE,AE_FMT_FLOAT
2019-05-07 18:10:07.345 T:140524259325696  NOTICE:         m_streamTypes     : No passthrough capabilities
2019-05-07 18:10:07.345 T:140524250932992    INFO: CActiveAESink::OpenSink - initialize sink
2019-05-07 18:10:07.345 T:140524250932992   DEBUG: CActiveAESink::OpenSink - trying to open device PULSE:Default
2019-05-07 18:10:07.347 T:140524250932992   DEBUG: PulseAudio: Context authorizing
2019-05-07 18:10:07.347 T:140524250932992   DEBUG: PulseAudio: Context setting name
2019-05-07 18:10:07.347 T:140524250932992   DEBUG: PulseAudio: Context ready
2019-05-07 18:10:07.363 T:140524250932992   DEBUG: PulseAudio: Stream ready
2019-05-07 18:10:07.363 T:140524250932992  NOTICE: PulseAudio: Opened device Default in pcm mode with Buffersize 150 ms
2019-05-07 18:10:07.363 T:140524250932992   DEBUG: CActiveAESink::OpenSink - PULSE Initialized:
2019-05-07 18:10:07.363 T:140524250932992   DEBUG:   Output Device : Default
2019-05-07 18:10:07.363 T:140524250932992   DEBUG:   Sample Rate   : 44100
2019-05-07 18:10:07.363 T:140524250932992   DEBUG:   Sample Format : AE_FMT_FLOAT
2019-05-07 18:10:07.363 T:140524250932992   DEBUG:   Channel Count : 2
2019-05-07 18:10:07.363 T:140524250932992   DEBUG:   Channel Layout: FL, FR
2019-05-07 18:10:07.363 T:140524250932992   DEBUG:   Frames        : 2205
2019-05-07 18:10:07.363 T:140524250932992   DEBUG:   Frame Size    : 8
2019-05-07 18:10:07.363 T:140524259325696   DEBUG: CActiveAE::ClearDiscardedBuffers - buffer pool deleted
2019-05-07 18:10:07.363 T:140524276111104   DEBUG: CAnnouncementManager - Announcement: OnWake from xbmc
2019-05-07 18:10:07.363 T:140524276111104   DEBUG: GOT ANNOUNCEMENT, type: 8, from xbmc, message OnWake
2019-05-07 18:10:07.364 T:140522798704384   DEBUG: Sink changed
2019-05-07 18:10:07.383 T:140524276139200   DEBUG: LogindUPowerSyscall - inhibit lock taken, fd 32
2019-05-07 18:10:07.383 T:140524276139200   DEBUG: HandleKey: rewind (0xc4) pressed, action is ShutDown()
2019-05-07 18:10:07.401 T:140524097881856   DEBUG: Thread JobWorker start, auto delete: true
2019-05-07 18:10:07.402 T:140524097881856    INFO: WEATHER: Downloading weather
2019-05-07 18:10:07.402 T:140523225171712   DEBUG: Thread LanguageInvoker start, auto delete: false
2019-05-07 18:10:07.402 T:140523225171712    INFO: initializing python engine.
2019-05-07 18:10:07.402 T:140523225171712   DEBUG: CPythonInvoker(8, /home/htpc/.kodi/addons/weather.yahoo/default.py): start processing
2019-05-07 18:10:07.409 T:140523225171712   DEBUG: -->Python Interpreter Initialized<--
2019-05-07 18:10:07.409 T:140523225171712   DEBUG: CPythonInvoker(8, /home/htpc/.kodi/addons/weather.yahoo/default.py): the source file to load is "/home/htpc/.kodi/addons/weather.yahoo/default.py"
2019-05-07 18:10:07.410 T:140523225171712   DEBUG: CPythonInvoker(8, /home/htpc/.kodi/addons/weather.yahoo/default.py): setting the Python path to /home/htpc/.kodi/addons/weather.yahoo:/home/htpc/.kodi/addons/script.module.certifi/lib:/home/htpc/.kodi/addons/script.module.chardet/lib:/home/htpc/.kodi/addons/script.module.idna/lib:/home/htpc/.kodi/addons/script.module.requests/lib:/home/htpc/.kodi/addons/script.module.urllib3/lib:/usr/lib/python27.zip:/usr/lib64/python2.7:/usr/lib64/python2.7/plat-linux2:/usr/lib64/python2.7/lib-tk:/usr/lib64/python2.7/lib-old:/usr/lib64/python2.7/lib-dynload:/usr/lib64/python2.7/site-packages:/usr/lib/python2.7/site-packages
2019-05-07 18:10:07.410 T:140523225171712   DEBUG: CPythonInvoker(8, /home/htpc/.kodi/addons/weather.yahoo/default.py): entering source directory /home/htpc/.kodi/addons/weather.yahoo
2019-05-07 18:10:07.410 T:140523225171712   DEBUG: CPythonInvoker(8, /home/htpc/.kodi/addons/weather.yahoo/default.py): instantiating addon using automatically obtained id of "weather.yahoo" dependent on version 2.25.0 of the xbmc.python api
2019-05-07 18:10:07.838 T:140524276139200   DEBUG: LogindUPowerSyscall: Received PrepareForSleep with arg 1
2019-05-07 18:10:07.838 T:140524276139200   DEBUG: ------ Window Init (DialogBusy.xml) ------
2019-05-07 18:10:07.838 T:140524276139200  NOTICE: OnSleep: Running sleep jobs
2019-05-07 18:10:07.838 T:140524276139200   DEBUG: CApplication::CloseNetworkShares: Closing all network shares
2019-05-07 18:10:07.839 T:140524276139200   DEBUG: LogindUPowerSyscall - delay lock sleep released
2019-05-07 18:10:07.841 T:140524276111104   DEBUG: CAnnouncementManager - Announcement: OnSleep from xbmc
2019-05-07 18:10:07.841 T:140524276111104   DEBUG: GOT ANNOUNCEMENT, type: 8, from xbmc, message OnSleep

Note that the log shows the second KEY_SLEEP right after the system wakes up. Way before Kodi has begun doing it's internal resume process.

Your Environment

Used Operating system:

ossman commented 5 years ago

The workaround I've done is to remove the mceusb module during suspend so that it cannot generate input events directly after resume:

$ cat /usr/lib/systemd/system-sleep/mceusb
#!/bin/bash
[ "$1" = "post" ] && exec /usr/sbin/modprobe mceusb
[ "$1" = "pre" ] && exec /usr/sbin/rmmod mceusb
exit 0
arnova commented 5 years ago

@ossman : This is a known issue, I had to work around this issue with a simular hack. Currently there's no easy way to fix this inside Kodi afaik.

github-actions[bot] commented 3 months ago

This issue is now marked stale because it has been open over a year without activity. Remove the stale label or add a comment to reset the stale state.