externalplayer and softhddevice

dreamvdrbox · November 25, 2013 at 8:15 PM

Hello,

I am having problem with externalplayer and softhddevice. XBMC is stared normally from within VDR, but switching back (exiting XBMC) I does not start softhddevice.
In log you can see some fatal error and VDR is going to be restarted.

Any input what can it be?

Quote

Nov 25 19:57:10 vdrboxdev vdr[1288]: [1288] switching to channel 782
Nov 25 19:57:10 vdrboxdev vdr[1288]: [1801] osdteletext-receiver thread ended (pid=1288, tid=1801)
Nov 25 19:57:10 vdrboxdev vdr[1288]: [1288] buffer stats: 0 (0%) used
Nov 25 19:57:10 vdrboxdev vdr[1288]: [1314] dbus2vdr: SystemBus: emit signal /Status de.tvdr.vdr.status ChannelSwitch (2, 0, true)
Nov 25 19:57:10 vdrboxdev vdr[1288]: [1314] dbus2vdr: SystemBus: emit signal /Status de.tvdr.vdr.status ChannelSwitch (1, 0, false)
Nov 25 19:57:10 vdrboxdev vdr[1288]: [1314] dbus2vdr: SystemBus: emit signal /Status de.tvdr.vdr.status ChannelSwitch (1, 782, false)
Nov 25 19:57:10 vdrboxdev vdr[1288]: [1800] TS buffer on device 1 thread ended (pid=1288, tid=1800)
Nov 25 19:57:10 vdrboxdev vdr[1288]: [1799] buffer stats: 726620 (17%) used
Nov 25 19:57:10 vdrboxdev vdr[1288]: [1799] receiver on device 1 thread ended (pid=1288, tid=1799)
Nov 25 19:57:10 vdrboxdev vdr[1288]: [1915] osdteletext-receiver thread started (pid=1288, tid=1915, prio=high)
Nov 25 19:57:10 vdrboxdev vdr[1288]: [1314] dbus2vdr: SystemBus: emit signal /Status de.tvdr.vdr.status ChannelSwitch (2, 782, true)
Nov 25 19:57:10 vdrboxdev vdr[1288]: [1914] receiver on device 1 thread started (pid=1288, tid=1914, prio=high)
Nov 25 19:57:10 vdrboxdev vdr[1288]: [1916] TS buffer on device 1 thread started (pid=1288, tid=1916, prio=high)
Nov 25 19:57:11 vdrboxdev vdr[1288]: [1288] [softhddev]SetPlayMode: 1
Nov 25 19:57:11 vdrboxdev vdr[1288]: [softhddev] invalid PES video packet
Nov 25 19:57:11 vdrboxdev vdr[1288]: [softhddev] 2 invalid PES video packet(s)
Nov 25 19:57:11 vdrboxdev vdr[1288]: audio/alsa: using device 'hw:0,3'
Nov 25 19:57:11 vdrboxdev vdr[1288]: audio/alsa: start delay 336ms
Nov 25 19:57:11 vdrboxdev vdr[1288]: codec/video: ffmpeg/libav buggy: width or height zero
Nov 25 19:57:12 vdrboxdev vdr[1288]: video: slow down video, duping frame
Nov 25 19:57:12 vdrboxdev vdr[1288]: video/vdpau: missed frame (1/2)
Nov 25 19:57:13 vdrboxdev vdr[1288]: video: slow down video, duping frame
Nov 25 19:57:13 vdrboxdev vdr[1288]: video: 12:26:30.068 +114 354 0/\ms 41+8 v-buf
Nov 25 19:57:13 vdrboxdev vdr[1288]: video/vdpau: synced after 55 frames
Nov 25 19:57:53 vdrboxdev vdr[1288]: [1288] externalplayer-plugin: starting player: XBMC
Nov 25 19:57:53 vdrboxdev vdr[1288]: [1288] [softhddev]SetPlayMode: 0
Nov 25 19:57:53 vdrboxdev vdr[1288]: [1288] [softhddev]SetVideoDisplayFormat: 1
Nov 25 19:57:53 vdrboxdev vdr[1288]: [1288] [softhddev]GetSpuDecoder:
Nov 25 19:57:53 vdrboxdev vdr[1288]: [1288] [softhddev]SetPlayMode: 5
Nov 25 19:57:53 vdrboxdev vdr[1288]: [1288] [softhddev] play mode external
Nov 25 19:57:53 vdrboxdev vdr[1288]: [1288] externalplayer-plugin: PID of child process: 1936 executing "/usr/bin/xbmc"
Nov 25 19:57:56 vdrboxdev runvdr[229]: libpng warning: iCCP: known incorrect sRGB profile
Nov 25 19:58:56 vdrboxdev vdr[1288]: [1288] externalplayer-plugin: player not active
Nov 25 19:58:56 vdrboxdev vdr[1288]: [1288] externalplayer-plugin: shutting down player
Nov 25 19:58:56 vdrboxdev vdr[1288]: [1288] [softhddev]SetPlayMode: 0
Nov 25 19:58:56 vdrboxdev vdr[1288]: video/vdpau: VDPAU API version: 1
Nov 25 19:58:56 vdrboxdev vdr[1288]: video/vdpau: VDPAU information: NVIDIA VDPAU Driver Shared Library 331.20 Wed Oct 30 17:39:35 PDT 2013
Nov 25 19:58:56 vdrboxdev vdr[1288]: video/vdpau: high quality scaling unsupported
Nov 25 19:58:56 vdrboxdev vdr[1288]: video/vdpau: feature deinterlace temporal supported
Nov 25 19:58:56 vdrboxdev vdr[1288]: video/vdpau: feature deinterlace temporal spatial supported
Nov 25 19:58:56 vdrboxdev vdr[1288]: video/vdpau: attribute skip chroma deinterlace supported
Nov 25 19:58:56 vdrboxdev vdr[1288]: video/vdpau: 4:2:0 chroma format with 4096x4096 supported
Nov 25 19:58:56 vdrboxdev vdr[1288]: video/vdpau: 4:2:2 chroma format with 4096x4096 supported
Nov 25 19:58:56 vdrboxdev vdr[1288]: video/vdpau: 8bit BGRA format with 8192x8192 supported
Nov 25 19:58:56 vdrboxdev vdr[1288]: video/vdpau: 10bit RGBA format with 8192x8192 supported
Nov 25 19:58:56 vdrboxdev vdr[1288]: [1294] read incomplete section - len = 3, r = 4096
Nov 25 20:00:25 vdrboxdev vdr[1288]: [1288] PANIC: watchdog timer expired - exiting!
Nov 25 20:00:25 vdrboxdev runvdr[229]: vdr-radio: Radio-Plugin Backgr.Image/RDS-Text starts...
Nov 25 20:00:25 vdrboxdev vdr[1288]: [1313] fatal error, server exiting: Bad file descriptor
Nov 25 20:00:25 vdrboxdev vdr[1288]: [1313] streamdev server thread ended (pid=1288, tid=1313)
Nov 25 20:00:26 vdrboxdev vdr[1288]: [1300] radiocheck thread ended (pid=1288, tid=1300)
Nov 25 20:00:26 vdrboxdev vdr[1288]: [1299] radioimage thread ended (pid=1288, tid=1299)
Nov 25 20:00:26 vdrboxdev vdr[1288]: [1915] osdteletext-receiver thread ended (pid=1288, tid=1915)
Nov 25 20:00:26 vdrboxdev vdr[1288]: [1288] buffer stats: 0 (0%) used
Nov 25 20:00:27 vdrboxdev vdr[1288]: [1916] TS buffer on device 1 thread ended (pid=1288, tid=1916)
Nov 25 20:00:27 vdrboxdev vdr[1288]: [1914] buffer stats: 152844 (3%) used
Nov 25 20:00:27 vdrboxdev vdr[1288]: [1914] receiver on device 1 thread ended (pid=1288, tid=1914)
Nov 25 20:00:27 vdrboxdev vdr[1288]: [1288] radio: delete cRadioAudio
Nov 25 20:00:27 vdrboxdev runvdr[229]: xinit: connection to X server lost
Nov 25 20:00:28 vdrboxdev runvdr[229]: waiting for X server to shut down .(EE) Server terminated successfully (0). Closing log file.
Nov 25 20:00:29 vdrboxdev runvdr[229]: Restarting VDR and DVB by error level 1 at Mon Nov 25 20:00:29 CET 2013

Nov 25 20:00:31 vdrboxdev vdr[2019]: [2019] Entry MenuEntry, XBMC
Nov 25 20:00:31 vdrboxdev vdr[2019]: [2019] Entry Command, /usr/bin/xbmc
Nov 25 20:00:31 vdrboxdev vdr[2019]: [2019] Entry OutputMode, slave
Nov 25 20:00:31 vdrboxdev vdr[2019]: [2019] Entry InputMode, deaktivateRemotes
Nov 25 20:00:31 vdrboxdev vdr[2019]: [2019] externalplayer-plugin: error in config file: invalig keyword "deaktivateRemotes" line 5!

Display More

/usr/lib/systemd/system/vdr.service

Quote

[Unit]
Description=Video Disk Recorder
After=eventlircd.service
After=lirc.service
After=oscam.service
After=sundtek.service

[Service]
Environment=HOME=/var/lib/vdr
ExecStart=/usr/bin/runvdr
KillMode=process
ExecStopPost=/usr/lib/vdr/bin/gen-sddropin

[Install]
WantedBy=multi-user.target

Display More

externalplayer.conf

Quote

# Externalplayer-plugin example configuration.

# Syntax description: Every player block begins with "{" and end with "}".
# Each block contains several entries with th following syntax:
# <setting> = <value>;
# Each block must contain at least a MenuEntry and a Command.

# Possible Input Modes: deactivateRemotes, slave, normal (default).
# Possible Output Modes: extern (default), none, audioOnly, audioOnlyBlack.
# See MPlayer example how to set up keys in slave mode.

# dxr3player for DVD playback, LIRC/KBD/RCU remotes are deactivated for VDR.
# So dxr3player has full control over the keyboard and LIRC devices.

{
MenuEntry = "XBMC";
Command = "/usr/bin/xbmc";
OutputMode = slave;
InputMode = deaktivateRemotes;
}

Display More

Regards

gda · November 25, 2013 at 8:23 PM

Quote from dreamvdrbox

Nov 25 20:00:31 vdrboxdev vdr[2019]: [2019] externalplayer-plugin: error in config file: invalig keyword "deaktivateRemotes" line 5!

Don't know whether it is the reason, but shoudn't it be deactivateRemotes?

Gerald

dreamvdrbox · November 25, 2013 at 9:47 PM

Hello,
Thank you for pointing that, it was one of many test to have maybe a working enternalplayer.conf.
New Conf is attached and the log file does not have any more such errors:

Quote

{
MenuEntry = "XBMC";
BlockMenu = false;
Command = "/usr/bin/xbmc";
OutputMode = extern;
}

This configuration works for a two times, if I try it for the 3-rd time, it will fail with this in log:

Quote

Nov 25 21:35:07 vdrboxdev vdr[4225]: [4225] switching to channel 243
Nov 25 21:35:07 vdrboxdev vdr[4225]: [4336] osdteletext-receiver thread ended (pid=4225, tid=4336)
Nov 25 21:35:07 vdrboxdev vdr[4225]: [4225] buffer stats: 0 (0%) used
Nov 25 21:35:07 vdrboxdev vdr[4225]: [4253] dbus2vdr: SystemBus: emit signal /Status de.tvdr.vdr.status ChannelSwitch (2, 0, true)
Nov 25 21:35:07 vdrboxdev vdr[4225]: [4253] dbus2vdr: SystemBus: emit signal /Status de.tvdr.vdr.status ChannelSwitch (1, 0, false)
Nov 25 21:35:07 vdrboxdev vdr[4225]: [4253] dbus2vdr: SystemBus: emit signal /Status de.tvdr.vdr.status ChannelSwitch (1, 243, false)
Nov 25 21:35:07 vdrboxdev vdr[4225]: [4337] TS buffer on device 1 thread ended (pid=4225, tid=4337)
Nov 25 21:35:07 vdrboxdev vdr[4225]: [4335] buffer stats: 184804 (4%) used
Nov 25 21:35:07 vdrboxdev vdr[4225]: [4335] receiver on device 1 thread ended (pid=4225, tid=4335)
Nov 25 21:35:07 vdrboxdev vdr[4225]: [4565] receiver on device 1 thread started (pid=4225, tid=4565, prio=high)
Nov 25 21:35:07 vdrboxdev vdr[4225]: [4567] osdteletext-receiver thread started (pid=4225, tid=4567, prio=high)
Nov 25 21:35:07 vdrboxdev vdr[4225]: [4566] TS buffer on device 1 thread started (pid=4225, tid=4566, prio=high)
Nov 25 21:35:07 vdrboxdev vdr[4225]: [4253] dbus2vdr: SystemBus: emit signal /Status de.tvdr.vdr.status ChannelSwitch (2, 243, true)
Nov 25 21:35:08 vdrboxdev vdr[4225]: [4225] [softhddev]SetPlayMode: 1
Nov 25 21:35:08 vdrboxdev vdr[4225]: audio/alsa: using device 'hw:0,3'
Nov 25 21:35:08 vdrboxdev vdr[4225]: audio/alsa: start delay 336ms
Nov 25 21:35:09 vdrboxdev vdr[4225]: codec/video: ffmpeg/libav buggy: width or height zero
Nov 25 21:35:09 vdrboxdev vdr[4225]: video/vdpau: missed frame (1/2)
Nov 25 21:35:10 vdrboxdev vdr[4225]: video/vdpau: missed frame (4/8)
Nov 25 21:35:10 vdrboxdev vdr[4225]: video: slow down video, duping frame
Nov 25 21:35:10 vdrboxdev vdr[4225]: video: 6:47:15.854 +111 330 0/\ms 37+8 v-buf
Nov 25 21:35:10 vdrboxdev vdr[4225]: video/vdpau: synced after 36 frames
Nov 25 21:36:07 vdrboxdev vdr[4225]: [4596] epg data writer thread started (pid=4225, tid=4596, prio=low)
Nov 25 21:36:07 vdrboxdev vdr[4225]: [4596] epg data writer thread ended (pid=4225, tid=4596)
Nov 25 21:36:09 vdrboxdev vdr[4225]: video: slow down video, duping frame
Nov 25 21:36:09 vdrboxdev vdr[4225]: video: 6:48:15.214 +31 346 0/\ms 38+7 v-buf
Nov 25 21:37:02 vdrboxdev vdr[4225]: [4225] externalplayer-plugin: starting player: XBMC
Nov 25 21:37:02 vdrboxdev vdr[4225]: [4225] [softhddev]SetPlayMode: 0
Nov 25 21:37:02 vdrboxdev vdr[4225]: [4225] [softhddev]SetVideoDisplayFormat: 1
Nov 25 21:37:02 vdrboxdev vdr[4225]: [4225] [softhddev]GetSpuDecoder:
Nov 25 21:37:02 vdrboxdev vdr[4225]: [4225] [softhddev]SetPlayMode: 5
Nov 25 21:37:02 vdrboxdev vdr[4225]: [4225] [softhddev] play mode external
Nov 25 21:37:02 vdrboxdev vdr[4225]: [4225] externalplayer-plugin: PID of child process: 4621 executing "/usr/bin/xbmc"
Nov 25 21:37:05 vdrboxdev runvdr[3965]: libpng warning: iCCP: known incorrect sRGB profile
Nov 25 21:37:06 vdrboxdev dbus-daemon[185]: dbus[185]: [system] Activating via systemd: service name='org.freedesktop.Avahi' unit='dbus-org.freed....service'
Nov 25 21:37:06 vdrboxdev dbus-daemon[185]: dbus[185]: [system] Activation via systemd failed for unit 'dbus-org.freedesktop.Avahi.service': Unit...irectory.
Nov 25 21:37:06 vdrboxdev dbus[185]: [system] Activating via systemd: service name='org.freedesktop.Avahi' unit='dbus-org.freedesktop.Avahi.service'
Nov 25 21:37:06 vdrboxdev dbus[185]: [system] Activation via systemd failed for unit 'dbus-org.freedesktop.Avahi.service': Unit dbus-org.freedesk...irectory.
Nov 25 21:37:15 vdrboxdev vdr[4225]: [4225] externalplayer-plugin: player not active
Nov 25 21:37:15 vdrboxdev vdr[4225]: [4225] externalplayer-plugin: shutting down player
Nov 25 21:37:15 vdrboxdev vdr[4225]: [4225] [softhddev]SetPlayMode: 0
Nov 25 21:37:15 vdrboxdev vdr[4225]: [4231] read incomplete section - len = 2847, r = 4096
Nov 25 21:37:15 vdrboxdev vdr[4225]: video: fatal i/o error
Nov 25 21:38:44 vdrboxdev vdr[4225]: [4225] PANIC: watchdog timer expired - exiting!
Nov 25 21:38:44 vdrboxdev runvdr[3965]: vdr-radio: Radio-Plugin Backgr.Image/RDS-Text starts...
Nov 25 21:38:45 vdrboxdev vdr[4225]: [4237] radiocheck thread ended (pid=4225, tid=4237)
Nov 25 21:38:45 vdrboxdev vdr[4225]: [4252] fatal error, server exiting: Bad file descriptor
Nov 25 21:38:45 vdrboxdev vdr[4225]: [4252] streamdev server thread ended (pid=4225, tid=4252)
Nov 25 21:38:45 vdrboxdev vdr[4225]: [4236] radioimage thread ended (pid=4225, tid=4236)
Nov 25 21:38:45 vdrboxdev vdr[4225]: [4567] osdteletext-receiver thread ended (pid=4225, tid=4567)
Nov 25 21:38:45 vdrboxdev kernel: vdr[4225]: segfault at a ip 00007f9f723f6742 sp 00007fffc4ad8990 error 4 in libc-2.18.so[7f9f7237e000+1a2000]
Nov 25 21:38:45 vdrboxdev runvdr[3965]: /usr/bin/runvdr: line 738: 4225 Segmentation fault "${VDRCOMMAND[@]}"
Nov 25 21:38:45 vdrboxdev runvdr[3965]: xinit: connection to X server lost
Nov 25 21:38:46 vdrboxdev runvdr[3965]: waiting for X server to shut down .(EE) Server terminated successfully (0). Closing log file.
Nov 25 21:38:47 vdrboxdev runvdr[3965]: Restarting VDR and DVB by error level 139 at Mon Nov 25 21:38:47 CET 2013
Nov 25 21:38:47 vdrboxdev runvdr[3965]: Sending 1 processes the TERM signal.terminated.
Nov 25 21:38:47 vdrboxdev runvdr[3965]: Starting VDR at Mon Nov 25 21:38:47 CET 2013

Display More

Best Regards

seahawk1986 · November 25, 2013 at 10:10 PM

Looks like the problem Copperhead has described before. Have you tried calling /usr/lib/xbmc/xbmc.bin directly instead of using /usr/bin/xbmc (which is only a wrapper script that calls xbmc.bin)?

dreamvdrbox · November 25, 2013 at 10:12 PM

I compiled softhddevice with -DDEBUG and attached file does contain the log with Debugging.

Gfunk · November 25, 2013 at 11:15 PM

I am using the same commands in my config and have the same results. After opening xbmc the 2nd time and exiting xbmc vdr does not reopen...

Code

{
MenuEntry = "XBMC";
BlockMenu = false;
Command = "/usr/lib/xbmc/xbmc.bin";
OutputMode = extern;
}

And when using either /usr/lib/xbmc/xbmc.bin or /usr/bin/xbmc both result in segfaults after the 2nd time exiting xbmc.

Participate now!