Loggytronic Forum

VOMP => VOMP General / MVP => Topic started by: carsten on February 15, 2008, 17:47:06

Title: Once again: D3A and no video...
Post by: carsten on February 15, 2008, 17:47:06
Hi,

was so hapy to get a second MVP. Unfortunately, it will display menus and everything, but when I start
a recording or live tv, there is only sound, no video. D3A box. 0.2.7 server and dongle with latest e-tobi
vdr setting.

Here the log, I see nothing wrong?!?

Quote17:41:25.037879 [info]   56 Core - Starting up...
17:41:25.038670 [info]   56 Core - Signal handlers set up successfully
17:41:25.038997 [info]   56 Core - Remote module initialised
17:41:25.039241 [info]   56 Core - LED module initialised
17:41:25.040147 [debug]  56 MTD - Located MTD device: /dev/mtd1
17:41:25.045411 [info]   56 Core - Mtd module initialised
17:41:25.047271 [info]   56 Core - Timers module initialised
17:41:25.048082 [info]   56 Core - Read from MTD: NTSC 720x480
17:41:25.474380 [debug]  56 Video - Setting aspect to 0
17:41:25.484346 [debug]  56 Video - Setting aspect to 0
17:41:25.984337 [debug]  56 Video - Setting aspect to 0
17:41:25.985721 [info]   56 Core - Video module initialised
17:41:26.058924 [info]   56 Core - OSD module initialised
17:41:26.067062 [debug]  56 Audio - MUTE OFF OFF OFF
17:41:26.067907 [info]   56 Core - Audio module initialised
17:41:26.068663 [info]   56 Core - VDR module initialised
17:41:26.069405 [info]   56 Core - BoxStack module initialised
17:41:26.070386 [info]   56 Core - Command module initialised
17:41:26.071153 [notice] 56 Core - Startup successful
17:41:26.072005 [debug]  56 Boxx - Construct, now 1
17:41:26.267866 [debug]  56 Boxx - Destruct, now 0
17:41:26.268714 [debug]  56 Boxx - Construct, now 1
17:41:26.323734 [debug]  56 Command - NTSC wallpaper selected
17:41:26.324901 [debug]  56 BJpeg - File opened
17:41:26.326276 [debug]  56 BJpeg - JPEG read header w=720 h=480, rot=0
17:41:26.327913 [debug]  56 BJpeg - JPEG startup done pw=720 ph=480, xo=0,yo=0, iw=720, ih=480
17:41:26.328768 [debug]  56 BJpeg - header w=720,h=480
17:41:26.887952 [debug]  56 BJpeg - Done all jpeg_read
17:41:26.888949 [debug]  56 BJpeg - jpeg shutdown done, x, y 720 480
17:41:26.889719 [debug]  56 BJpeg - deleted buffer
17:41:26.978807 [debug]  56 Boxx - Construct, now 2
17:41:26.979472 [debug]  56 Boxx - Construct, now 3
17:41:26.994774 [debug]  59 TBBoxx - Draw
17:41:27.010866 [debug]  59 VConnect - Draw done
17:41:27.031774 [notice] 59 VDR - Broadcasting for server
17:41:27.032623 [debug]  56 UDP - Starting UDP command server
17:41:27.035225 [debug]  56 UDP - UDP command server started
17:41:28.534407 [notice] 59 VConnect - Connecting to server at 192.168.7.3
17:41:28.535897 [notice] 59 Wol - Found etheraddr 00:0E:0C:C2:BD:83
17:41:28.536704 [notice] 59 Wol - Server IP set
17:41:28.537561 [debug]  59 TBBoxx - Draw
17:41:28.553758 [debug]  59 VConnect - Draw done
17:41:28.576097 [debug]  59 Command - Connected ok, doing login
17:41:28.577943 [debug]  59 VDR - vdrtime = 1203097289
17:41:28.578752 [debug]  59 VDR - offset = 3600
17:41:29.000008 [debug]  59 VDR - set clock = 0
17:41:29.000773 [debug]  59 VDR - - 1 0
17:41:29.001417 [debug]  59 VDR - - 1 0
18:41:29.002423 [debug]  59 VDR - Timezone data: MVP-1:0
18:41:29.003480 [debug]  59 TBBoxx - Draw
18:41:29.020063 [debug]  59 VConnect - Draw done
18:41:29.044894 [notice] 56 Core - Signal 23 received
18:41:29.045666 [debug]  56 Core - SIGURG caught
18:41:29.046716 [debug]  56 Command - processing message 11
18:41:29.069191 [debug]  56 Boxx - Destruct, now 2
18:41:29.070832 [debug]  56 Boxx - Destruct, now 1
18:41:29.071647 [debug]  56 Boxx - Construct, now 2
18:41:29.072415 [debug]  56 Boxx - Construct, now 3
18:41:29.086523 [debug]  56 TBBoxx - Draw
18:41:29.125493 [debug]  56 Command - Phew, no dangerous on-the-fly mode switching to do!
18:41:29.126170 [debug]  56 Command - Load power after boot
18:41:29.127835 [info]   56 Command - Config General/Power After Boot not found
18:41:29.129345 [info]   56 Command - Switching to RGB/Composite as Connection=RGB+composite
18:41:29.130818 [info]   56 Command - Config General/Remote type not found
18:41:29.132318 [info]   56 Command - Config TV/Aspect type not found, going 4:3
18:41:29.132978 [debug]  56 Video - Setting aspect to 0
18:41:29.634794 [debug]  56 Video - Setting aspect to 0
18:41:29.636619 [info]   56 Command - Setting letterbox mode
18:41:29.638171 [info]   56 Command - TCP window size not found, setting 2048
18:41:29.638976 [debug]  56 TCP - Set receive window to 2048, success(=0): 0
18:41:29.640421 [info]   56 Command - By default, enable WOL
18:41:29.642172 [info]   56 Remote - Config General/Remote keys load
18:41:29.663640 [debug]  56 Boxx - Destruct, now 2
18:41:29.665306 [debug]  56 Boxx - Destruct, now 1
18:41:29.666149 [debug]  56 Boxx - Construct, now 2
18:41:29.666945 [debug]  56 Boxx - Construct, now 3
18:41:29.667723 [debug]  56 Boxx - Construct, now 4
18:41:29.685486 [debug]  56 TBBoxx - Draw
18:41:29.716681 [debug]  56 BJpeg - File opened
18:41:29.717804 [debug]  56 BJpeg - JPEG read header w=190 h=100, rot=0
18:41:29.732254 [debug]  56 BJpeg - JPEG startup done pw=190 ph=100, xo=0,yo=0, iw=190, ih=100
18:41:29.733118 [debug]  56 BJpeg - header w=190,h=100
18:41:29.767678 [debug]  56 BJpeg - Done all jpeg_read
18:41:29.768646 [debug]  56 BJpeg - jpeg shutdown done, x, y 0 0
18:41:29.769299 [debug]  56 BJpeg - deleted buffer
18:41:29.770855 [debug]  56 Timers - Starting set timer 1
18:41:29.771813 [debug]  56 Timers - Timer set for 0x1018ae08 ref 1
18:41:29.819439 [debug]  56 Command - processing message 28
18:41:29.820111 [debug]  56 Command - processing message 28
18:41:31.085283 [debug]  56 Remote - Button 37
18:41:31.089338 [debug]  56 VDR - Have added a channel to list. 1 1 Das Erste
18:41:31.090214 [debug]  56 VDR - Have added a channel to list. 2 1 ZDF
18:41:31.091093 [debug]  56 VDR - Have added a channel to list. 3 1 NDR FS HH
18:41:31.091891 [debug]  56 VDR - Have added a channel to list. 4 1 RTL Television
18:41:31.092768 [debug]  56 VDR - Have added a channel to list. 5 1 RTL2
18:41:31.093568 [debug]  56 VDR - Have added a channel to list. 6 1 SAT.1
18:41:31.094419 [debug]  56 VDR - Have added a channel to list. 7 1 ProSieben
18:41:31.095260 [debug]  56 VDR - Have added a channel to list. 8 1 Kabel1
18:41:31.096116 [debug]  56 VDR - Have added a channel to list. 9 1 Vox
...
18:41:31.240539 [debug]  56 Boxx - Construct, now 5
18:41:31.241200 [debug]  56 Boxx - Construct, now 6
18:41:31.284323 [debug]  56 TBBoxx - Draw
18:41:31.430076 [debug]  56 Boxx - Construct, now 7
18:41:31.435288 [debug]  56 Boxx - Destruct, now 6
18:41:32.569144 [debug]  56 Remote - Button 33
18:41:33.034271 [debug]  56 Remote - Button 33
18:41:33.234317 [debug]  56 Remote - Button 33
18:41:33.448813 [debug]  56 Remote - Button 33
18:41:33.647227 [debug]  56 Remote - Button 33
18:41:33.869301 [debug]  56 Remote - Button 33
18:41:34.514300 [debug]  56 Remote - Button 37
18:41:34.515204 [debug]  56 Boxx - Construct, now 7
18:41:34.516048 [debug]  56 Boxx - Construct, now 8
18:41:34.711947 [debug]  56 VVideoLive - Do WSS: 0
18:41:34.800768 [debug]  56 VVideoLive - Delay starts here due to time taken by plugin to stop
18:41:34.802243 [debug]  56 VVideoLive - Delay ends here due to time taken by plugin to stop
18:41:34.804279 [debug]  56 Boxx - Construct, now 9
18:41:34.805095 [debug]  56 Boxx - Construct, now 10
18:41:34.835214 [debug]  56 VDR - Success got to end of getChannelSchedule
18:41:34.837564 [debug]  56 Timers - Starting set timer 1
18:41:34.838409 [debug]  56 Timers - Timer set for 0x1018a058 ref 1
18:41:34.839229 [debug]  56 TBBoxx - Draw
18:41:34.864314 [debug]  56 Timers - Starting set timer 1
18:41:34.865367 [debug]  56 Timers - Timer set for 0x1018a058 ref 2
18:41:34.893890 [debug]  56 Channel - C.7 loaded, VPid=511, numApids=1
18:41:34.894556 [debug]  56 Channel - APid 512
18:41:34.895391 [debug]  56 Player - LOCKED
18:41:34.896271 [debug]  56 Player - Switch state from 6 to 1
18:41:34.901107 [debug]  56 Audio - doMuting: user=0 sys=0
18:41:34.901899 [debug]  56 Audio - MUTE OFF OFF OFF
18:41:34.902673 [debug]  56 Audio - doMuting: user=0 sys=0
18:41:34.903322 [debug]  56 Audio - MUTE OFF OFF OFF
18:41:34.905606 [debug]  56 Player - Prebuffering...
18:41:35.538015 [debug]  61 Player - Startup Audio stream chosen c0
18:41:35.541180 [debug]  61 Demux - Aspect ratio difference signalled
18:41:35.541894 [debug]  61 Demuxer - Entering audio sync: Video PTS = 3149089895
18:41:35.542886 [debug]  61 Demuxer - Entering audio sync: Audio PTS = 3149066805
18:41:35.611928 [debug]  61 Demuxer - Leaving  audio sync: Audio PTS = 3149092725
18:41:36.177045 [debug]  61 Demux - Aspect ratio difference signalled
18:41:36.232139 [debug]  61 Player - Got >500K, prebuffering complete
18:41:36.478659 [debug]  62 Player - UNLOCKING
18:41:36.618585 [debug]  61 Demux - Aspect ratio difference signalled
18:41:36.778087 [debug]  61 Demux - Aspect ratio difference signalled
18:41:36.778803 [debug]  61 Player - Callback from demuxer
18:41:36.779721 [debug]  61 Player - TV is 4:3, ignoring aspect switching
18:41:38.859572 [debug]  58 Timers - Timer firing for client 0x1018a058 ref 1
18:41:38.860709 [debug]  64 Timers - sending timer to 0x1018a058 with parameter 1
18:41:38.861613 [debug]  64 Command - PMFOS called
18:41:38.862643 [notice] 56 Core - Signal 23 received
18:41:38.862923 [debug]  56 Core - SIGURG caught
18:41:38.863160 [debug]  56 Command - processing message 2
18:41:38.863384 [debug]  56 Command - Sending message to boxstack
18:41:38.863603 [debug]  56 BoxStack - it's for meeee!
18:41:38.880075 [debug]  56 Timers - Starting cancel timer 0x1018a058 1, list size = 3
18:41:38.881253 [debug]  56 Timers - 0x1018a058 ref 1 cancelTimer WAITING
18:41:38.882161 [debug]  64 Timers - timerEventFinished for 0x1018a058
18:41:38.882979 [debug]  64 Timers - timerEventFinished for 0x1018a058 1 - remove done
18:41:38.934769 [debug]  56 Timers - Starting cancel timer 0x1018a058 2, list size = 2
18:41:38.935480 [debug]  56 Timers - Removed timer for 0x1018a058 ref 2
18:41:38.937098 [debug]  56 Boxx - Destruct, now 9
18:41:38.938754 [debug]  56 Boxx - Destruct, now 8
18:41:48.134016 [debug]  56 Remote - Button 31
18:41:48.134311 [debug]  56 Player - LOCKED
18:41:48.134529 [debug]  56 Player - Stop called lock
18:41:48.134824 [debug]  56 Player - Switch state from 1 to 6
18:41:48.894796 [debug]  56 Player - UNLOCKING
18:41:48.895489 [debug]  56 VVideoLive - Delay starts here due to time taken by plugin to stop
18:41:49.002360 [debug]  56 VVideoLive - Delay ends here due to time taken by plugin to stop
18:41:49.178821 [debug]  56 Player - Switch state from 6 to 6
18:41:49.180088 [debug]  56 Video - Setting aspect to 0
18:41:49.180951 [debug]  56 Boxx - Destruct, now 7
18:41:49.182617 [debug]  56 Boxx - Destruct, now 6
18:41:50.083790 [debug]  56 Remote - Button 32
18:41:50.386326 [debug]  56 Remote - Button 32
18:41:50.617990 [debug]  56 Remote - Button 32
18:41:50.833195 [debug]  56 Remote - Button 32
18:41:51.090763 [debug]  56 Remote - Button 32
18:41:51.345336 [debug]  56 Remote - Button 32
18:41:51.764685 [debug]  56 Remote - Button 37
18:41:51.765422 [debug]  56 Boxx - Construct, now 7
18:41:51.766333 [debug]  56 Boxx - Construct, now 8
18:41:51.959945 [debug]  56 VVideoLive - Do WSS: 0
18:41:52.068242 [debug]  56 VVideoLive - Delay starts here due to time taken by plugin to stop
18:41:52.070266 [debug]  56 VVideoLive - Delay ends here due to time taken by plugin to stop
18:41:52.072046 [debug]  56 Boxx - Construct, now 9
18:41:52.072711 [debug]  56 Boxx - Construct, now 10
18:41:52.103190 [debug]  56 VDR - Success got to end of getChannelSchedule
18:41:52.106142 [debug]  56 Timers - Starting set timer 1
18:41:52.107118 [debug]  56 Timers - Timer set for 0x1018da40 ref 1
18:41:52.107801 [debug]  56 TBBoxx - Draw
18:41:52.132540 [debug]  56 Timers - Starting set timer 1
18:41:52.133565 [debug]  56 Timers - Timer set for 0x1018da40 ref 2
18:41:52.161248 [debug]  56 Channel - C.1 loaded, VPid=101, numApids=1
18:41:52.161918 [debug]  56 Channel - APid 102 deu
18:41:52.162840 [debug]  56 Player - LOCKED
18:41:52.163589 [debug]  56 Player - Switch state from 6 to 1
18:41:52.168409 [debug]  56 Audio - doMuting: user=0 sys=0
18:41:52.169092 [debug]  56 Audio - MUTE OFF OFF OFF
18:41:52.169895 [debug]  56 Audio - doMuting: user=0 sys=0
18:41:52.170816 [debug]  56 Audio - MUTE OFF OFF OFF
18:41:52.175557 [debug]  56 Player - Prebuffering...
18:41:52.808910 [debug]  65 Player - Startup Audio stream chosen c0
18:41:52.812351 [debug]  65 Demux - Aspect ratio difference signalled
18:41:52.813207 [debug]  65 Demuxer - Entering audio sync: Video PTS = 540406422
18:41:52.814008 [debug]  65 Demuxer - Entering audio sync: Audio PTS = 0
18:41:52.951497 [debug]  65 Demux - Aspect ratio difference signalled
18:41:53.005961 [debug]  65 Player - Got >500K, prebuffering complete
18:41:53.120661 [debug]  65 Demuxer - Leaving  audio sync: Audio PTS = 540413722
18:41:53.308813 [debug]  66 Player - UNLOCKING
18:41:53.444418 [debug]  65 Demux - Aspect ratio difference signalled
18:41:54.166686 [debug]  65 Demux - Aspect ratio difference signalled
18:41:54.167529 [debug]  65 Player - Callback from demuxer
18:41:54.168314 [debug]  65 Player - TV is 4:3, ignoring aspect switching
18:41:56.114917 [debug]  58 Timers - Timer firing for client 0x1018da40 ref 1
18:41:56.116440 [debug]  68 Timers - sending timer to 0x1018da40 with parameter 1
18:41:56.117879 [debug]  68 Command - PMFOS called
18:41:56.118766 [notice] 56 Core - Signal 23 received
18:41:56.119044 [debug]  56 Core - SIGURG caught
18:41:56.119281 [debug]  56 Command - processing message 2
18:41:56.119506 [debug]  56 Command - Sending message to boxstack
18:41:56.119725 [debug]  56 BoxStack - it's for meeee!
18:41:56.136210 [debug]  56 Timers - Starting cancel timer 0x1018da40 1, list size = 3
18:41:56.137720 [debug]  56 Timers - 0x1018da40 ref 1 cancelTimer WAITING
18:41:56.139530 [debug]  68 Timers - timerEventFinished for 0x1018da40
18:41:56.140959 [debug]  68 Timers - timerEventFinished for 0x1018da40 1 - remove done
18:41:56.195353 [debug]  56 Timers - Starting cancel timer 0x1018da40 2, list size = 2
18:41:56.196096 [debug]  56 Timers - Removed timer for 0x1018da40 ref 2
18:41:56.197678 [debug]  56 Boxx - Destruct, now 9
18:41:56.199344 [debug]  56 Boxx - Destruct, now 8
18:42:00.014772 [debug]  58 Timers - Timer firing for client 0x1018ae08 ref 1
18:42:00.015997 [debug]  69 Timers - sending timer to 0x1018ae08 with parameter 1
18:42:00.017618 [debug]  69 Timers - Starting set timer 1
18:42:00.018415 [debug]  69 Command - PMFOS called
18:42:00.019293 [notice] 56 Core - Signal 23 received
18:42:00.019572 [debug]  56 Core - SIGURG caught
18:42:00.019811 [debug]  56 Command - processing message 15
18:42:00.020038 [debug]  56 Command - Sending message to boxstack
18:42:00.020260 [debug]  56 BoxStack - it's for meeee!
18:42:00.020968 [debug]  69 Timers - timerEventFinished for 0x1018ae08
18:42:00.021915 [debug]  69 Timers - timerEventFinished RESTART for 0x1018ae08
18:42:03.714362 [debug]  56 Remote - Button 31
18:42:03.714674 [debug]  56 Player - LOCKED
18:42:03.714935 [debug]  56 Player - Stop called lock
18:42:03.715150 [debug]  56 Player - Switch state from 1 to 6
18:42:04.124813 [debug]  56 Player - UNLOCKING
18:42:04.125510 [debug]  56 VVideoLive - Delay starts here due to time taken by plugin to stop
18:42:04.233508 [debug]  56 VVideoLive - Delay ends here due to time taken by plugin to stop
18:42:04.409785 [debug]  56 Player - Switch state from 6 to 6
18:42:04.411143 [debug]  56 Video - Setting aspect to 0
18:42:04.412011 [debug]  56 Boxx - Destruct, now 7
18:42:04.413681 [debug]  56 Boxx - Destruct, now 6
18:42:06.167065 [debug]  56 Remote - Button 31
18:42:06.250693 [debug]  56 Boxx - Destruct, now 5
18:42:06.252408 [debug]  56 Boxx - Destruct, now 4
18:42:08.979368 [notice] 56 Core - Signal 2 received
18:42:08.980158 [notice] 56 Core - Interrupt signal, shutting down...
18:42:08.981638 [debug]  56 Timers - Starting cancel timer 0x1018ae08 1, list size = 1
18:42:08.982492 [debug]  56 Timers - Removed timer for 0x1018ae08 ref 1
18:42:08.983454 [debug]  56 Boxx - Destruct, now 3
18:42:08.984268 [debug]  56 Boxx - Destruct, now 2
18:42:08.985915 [debug]  56 Boxx - Destruct, now 1
18:42:08.986722 [notice] 56 Core - BoxStack module shut down
18:42:08.987511 [notice] 56 Core - Command module shut down
18:42:08.988456 [debug]  56 TCP - Have closed
18:42:08.989397 [debug]  56 VDR - Disconnect
18:42:08.989890 [notice] 56 Core - VDR module shut down
18:42:08.991267 [notice] 56 Core - OSD module shut down
18:42:08.991867 [notice] 56 Core - Audio module shut down
18:42:09.044452 [notice] 56 Core - Video module shut down
18:42:09.045160 [debug]  56 Timers - Timers shutdown start
18:42:09.046690 [debug]  56 Timers - Timers shutdown end
18:42:09.047500 [notice] 56 Core - Timers module shut down
18:42:09.048277 [notice] 56 Core - MTD module shut down
18:42:09.048923 [notice] 56 Core - LED module shut down
18:42:09.049949 [notice] 56 Core - Remote module shut down
18:42:09.050740 [notice] 56 Core - WOL module shut down
18:42:09.051497 [notice] 56 Core - Log module shutting down... bye!

and server log:

QuoteFeb 15 18:41:34 kes vdr: [15580] receiver on device 1 thread started (pid=1836, tid=15580)
Feb 15 18:41:34 kes vdr: [15581] TS buffer on device 1 thread started (pid=1836, tid=15581)
Feb 15 18:41:49 kes vdr: [15581] TS buffer on device 1 thread ended (pid=1836, tid=15581)
Feb 15 18:41:49 kes vdr: [15580] buffer stats: 112048 (5%) used
Feb 15 18:41:49 kes vdr: [15580] receiver on device 1 thread ended (pid=1836, tid=15580)
Feb 15 18:41:52 kes vdr: [15582] receiver on device 1 thread started (pid=1836, tid=15582)
Feb 15 18:41:52 kes vdr: [15583] TS buffer on device 1 thread started (pid=1836, tid=15583)
Feb 15 18:42:04 kes vdr: [15583] TS buffer on device 1 thread ended (pid=1836, tid=15583)
Feb 15 18:42:04 kes vdr: [15582] buffer stats: 107912 (5%) used
Feb 15 18:42:04 kes vdr: [15582] receiver on device 1 thread ended (pid=1836, tid=15582)

Anyone an idea? Please Help!

Best Regards,
Carsten.
Title: Re: Once again: D3A and no video...
Post by: carsten on February 15, 2008, 19:40:58
Excuse me, here the more verbose log:

Quote19:05:41.297291 [info]   32 Core - Starting up...
19:05:41.298648 [info]   32 Core - Signal handlers set up successfully
19:05:41.299513 [info]   32 Core - Remote module initialised
19:05:41.300289 [info]   32 Core - LED module initialised
19:05:41.301806 [debug]  32 MTD - Located MTD device: /dev/mtd1
19:05:41.307045 [info]   32 Core - Mtd module initialised
19:05:41.308818 [info]   32 Core - Timers module initialised
19:05:41.309636 [info]   32 Core - Read from MTD: NTSC 720x480
19:05:41.761122 [debug]  32 Video - Setting aspect to 0
19:05:41.771100 [debug]  32 Video - Setting aspect to 0
19:05:42.271080 [debug]  32 Video - Setting aspect to 0
19:05:42.272473 [info]   32 Core - Video module initialised
19:05:42.346162 [info]   32 Core - OSD module initialised
19:05:42.354347 [debug]  32 Audio - MUTE OFF OFF OFF
19:05:42.355215 [info]   32 Core - Audio module initialised
19:05:42.355980 [info]   32 Core - VDR module initialised
19:05:42.356732 [info]   32 Core - BoxStack module initialised
19:05:42.357732 [info]   32 Core - Command module initialised
19:05:42.358386 [notice] 32 Core - Startup successful
19:05:42.359409 [debug]  32 Boxx - Construct, now 1
19:05:42.555346 [debug]  32 Boxx - Destruct, now 0
19:05:42.556086 [debug]  32 Boxx - Construct, now 1
19:05:42.611360 [debug]  32 Command - NTSC wallpaper selected
19:05:42.612532 [debug]  32 BJpeg - File opened
19:05:42.613909 [debug]  32 BJpeg - JPEG read header w=720 h=480, rot=0
19:05:42.615556 [debug]  32 BJpeg - JPEG startup done pw=720 ph=480, xo=0,yo=0, iw=720, ih=480
19:05:42.616415 [debug]  32 BJpeg - header w=720,h=480
19:05:43.176002 [debug]  32 BJpeg - Done all jpeg_read
19:05:43.176994 [debug]  32 BJpeg - jpeg shutdown done, x, y 720 480
19:05:43.177760 [debug]  32 BJpeg - deleted buffer
19:05:43.266696 [debug]  32 Boxx - Construct, now 2
19:05:43.267495 [debug]  32 Boxx - Construct, now 3
19:05:43.282025 [debug]  35 TBBoxx - Draw
19:05:43.298007 [debug]  35 VConnect - Draw done
19:05:43.319476 [notice] 35 VDR - Broadcasting for server
19:05:43.320328 [debug]  32 UDP - Starting UDP command server
19:05:43.322968 [debug]  32 UDP - UDP command server started
19:05:44.821146 [notice] 35 VConnect - Connecting to server at 192.168.7.3
19:05:44.822719 [notice] 35 Wol - Found etheraddr 00:0E:0C:C2:BD:83
19:05:44.823517 [notice] 35 Wol - Server IP set
19:05:44.824378 [debug]  35 TBBoxx - Draw
19:05:44.840562 [debug]  35 VConnect - Draw done
19:05:44.862764 [debug]  35 Command - Connected ok, doing login
19:05:44.864610 [debug]  35 VDR - vdrtime = 1203102344
19:05:44.865286 [debug]  35 VDR - offset = 3600
19:05:44.000009 [debug]  35 VDR - set clock = 0
19:05:44.000707 [debug]  35 VDR - - 1 0
19:05:44.001611 [debug]  35 VDR - - 1 0
20:05:44.002477 [debug]  35 VDR - Timezone data: MVP-1:0
20:05:44.003538 [debug]  35 TBBoxx - Draw
20:05:44.019938 [debug]  35 VConnect - Draw done
20:05:44.044976 [notice] 32 Core - Signal 23 received
20:05:44.045747 [debug]  32 Core - SIGURG caught
20:05:44.046821 [debug]  32 Command - processing message 11
20:05:44.069532 [debug]  32 Boxx - Destruct, now 2
20:05:44.071001 [debug]  32 Boxx - Destruct, now 1
20:05:44.071836 [debug]  32 Boxx - Construct, now 2
20:05:44.072610 [debug]  32 Boxx - Construct, now 3
20:05:44.087471 [debug]  32 TBBoxx - Draw
20:05:44.126276 [debug]  32 Command - Phew, no dangerous on-the-fly mode switching to do!
20:05:44.127092 [debug]  32 Command - Load power after boot
20:05:44.128593 [info]   32 Command - Config General/Power After Boot not found
20:05:44.130093 [info]   32 Command - Switching to RGB/Composite as Connection=RGB+composite
20:05:44.131719 [info]   32 Command - Config General/Remote type not found
20:05:44.133249 [info]   32 Command - /// Switching to TV aspect 4:3
20:05:44.134040 [debug]  32 Video - Setting aspect to 0
20:05:44.644867 [debug]  32 Video - Setting aspect to 0
20:05:44.646724 [info]   32 Command - Setting letterbox mode
20:05:44.648306 [info]   32 Command - Setting TCP window size 8192
20:05:44.649124 [debug]  32 TCP - Set receive window to 8192, success(=0): 0
20:05:44.650681 [info]   32 Command - By default, enable WOL
20:05:44.652427 [info]   32 Remote - Config General/Remote keys load
20:05:44.675804 [debug]  32 Boxx - Destruct, now 2
20:05:44.677438 [debug]  32 Boxx - Destruct, now 1
20:05:44.678304 [debug]  32 Boxx - Construct, now 2
20:05:44.679128 [debug]  32 Boxx - Construct, now 3
20:05:44.679910 [debug]  32 Boxx - Construct, now 4
20:05:44.697677 [debug]  32 TBBoxx - Draw
20:05:44.728411 [debug]  32 BJpeg - File opened
20:05:44.729554 [debug]  32 BJpeg - JPEG read header w=190 h=100, rot=0
20:05:44.743903 [debug]  32 BJpeg - JPEG startup done pw=190 ph=100, xo=0,yo=0, iw=190, ih=100
20:05:44.744650 [debug]  32 BJpeg - header w=190,h=100
20:05:44.779614 [debug]  32 BJpeg - Done all jpeg_read
20:05:44.780606 [debug]  32 BJpeg - jpeg shutdown done, x, y 0 0
20:05:44.781264 [debug]  32 BJpeg - deleted buffer
20:05:44.782976 [debug]  32 Timers - Starting set timer 1
20:05:44.783955 [debug]  32 Timers - Timer set for 0x1018ae08 ref 1
20:05:44.830787 [debug]  32 Command - processing message 28
20:05:44.831605 [debug]  32 Command - processing message 28
20:05:48.927134 [debug]  32 Remote - Button 37
20:05:48.930980 [debug]  32 VDR - Have added a channel to list. 1 1 Das Erste
20:05:48.931837 [debug]  32 VDR - Have added a channel to list. 2 1 ZDF
20:05:48.932695 [debug]  32 VDR - Have added a channel to list. 3 1 NDR FS HH
20:05:48.933487 [debug]  32 VDR - Have added a channel to list. 4 1 RTL Television
20:05:48.934348 [debug]  32 VDR - Have added a channel to list. 5 1 RTL2
20:05:48.935186 [debug]  32 VDR - Have added a channel to list. 6 1 SAT.1
20:05:48.936032 [debug]  32 VDR - Have added a channel to list. 7 1 ProSieben
20:05:48.936857 [debug]  32 VDR - Have added a channel to list. 8 1 Kabel1
20:05:48.937732 [debug]  32 VDR - Have added a channel to list. 9 1 Vox
...
20:05:49.072288 [debug]  32 Boxx - Construct, now 5
20:05:49.072535 [debug]  32 Boxx - Construct, now 6
20:05:49.113982 [debug]  32 TBBoxx - Draw
20:05:49.259493 [debug]  32 Boxx - Construct, now 7
20:05:49.264764 [debug]  32 Boxx - Destruct, now 6
20:05:50.965256 [debug]  32 Remote - Button 37
20:05:50.966146 [debug]  32 Boxx - Construct, now 7
20:05:50.966962 [debug]  32 Boxx - Construct, now 8
20:05:51.163738 [debug]  32 VVideoLive - Do WSS: 1
20:05:51.252255 [debug]  32 VVideoLive - Delay starts here due to time taken by plugin to stop
20:05:51.253771 [debug]  32 VVideoLive - Delay ends here due to time taken by plugin to stop
20:05:51.255623 [debug]  32 Boxx - Construct, now 9
20:05:51.256294 [debug]  32 Boxx - Construct, now 10
20:05:51.482397 [debug]  32 VDR - Success got to end of getChannelSchedule
20:05:51.485381 [debug]  32 Timers - Starting set timer 1
20:05:51.486370 [debug]  32 Timers - Timer set for 0x1018a058 ref 1
20:05:51.487179 [debug]  32 TBBoxx - Draw
20:05:51.513240 [debug]  32 Timers - Starting set timer 1
20:05:51.514276 [debug]  32 Timers - Timer set for 0x1018a058 ref 2
20:05:51.543572 [debug]  32 Channel - C.1 loaded, VPid=101, numApids=1
20:05:51.544248 [debug]  32 Channel - APid 102 deu
20:05:51.545091 [debug]  32 Player - LOCKED
20:05:51.545992 [debug]  32 Player - Switch state from 6 to 1
20:05:51.550842 [debug]  32 Audio - doMuting: user=0 sys=0
20:05:51.551650 [debug]  32 Audio - MUTE OFF OFF OFF
20:05:51.552316 [debug]  32 Audio - doMuting: user=0 sys=0
20:05:51.553253 [debug]  32 Audio - MUTE OFF OFF OFF
20:05:51.555673 [debug]  32 Player - Prebuffering...
20:05:52.125299 [debug]  37 Player - Startup Audio stream chosen c0
20:05:52.129575 [debug]  37 Demux - Aspect ratio difference signalled
20:05:52.130428 [debug]  37 Demuxer - Entering audio sync: Video PTS = 994006422
20:05:52.132584 [debug]  37 Demuxer - Entering audio sync: Audio PTS = 0
20:05:52.244731 [debug]  37 Player - Got >500K, prebuffering complete
20:05:52.357125 [debug]  37 Demux - Aspect ratio difference signalled
20:05:52.386994 [debug]  37 Demuxer - Leaving  audio sync: Audio PTS = 994013722
20:05:52.591506 [debug]  38 Player - UNLOCKING
20:05:52.889935 [debug]  37 Demux - Aspect ratio difference signalled
20:05:53.038826 [debug]  37 Demux - Aspect ratio difference signalled
20:05:53.039549 [debug]  37 Player - Callback from demuxer
20:05:53.040347 [debug]  37 Player - TV is 4:3, ignoring aspect switching
20:05:55.494841 [debug]  34 Timers - Timer firing for client 0x1018a058 ref 1
20:05:55.495927 [debug]  40 Timers - sending timer to 0x1018a058 with parameter 1
20:05:55.496902 [debug]  40 Command - PMFOS called
20:05:55.497788 [notice] 32 Core - Signal 23 received
20:05:55.498069 [debug]  32 Core - SIGURG caught
20:05:55.498307 [debug]  32 Command - processing message 2
20:05:55.498534 [debug]  32 Command - Sending message to boxstack
20:05:55.498755 [debug]  32 BoxStack - it's for meeee!
20:05:55.515484 [debug]  32 Timers - Starting cancel timer 0x1018a058 1, list size = 3
20:05:55.516565 [debug]  32 Timers - 0x1018a058 ref 1 cancelTimer WAITING
20:05:55.517626 [debug]  40 Timers - timerEventFinished for 0x1018a058
20:05:55.518458 [debug]  40 Timers - timerEventFinished for 0x1018a058 1 - remove done
20:05:55.574845 [debug]  32 Timers - Starting cancel timer 0x1018a058 2, list size = 2
20:05:55.575565 [debug]  32 Timers - Removed timer for 0x1018a058 ref 2
20:05:55.577338 [debug]  32 Boxx - Destruct, now 9
20:05:55.578993 [debug]  32 Boxx - Destruct, now 8
20:06:00.014890 [debug]  34 Timers - Timer firing for client 0x1018ae08 ref 1
20:06:00.027220 [debug]  41 Timers - sending timer to 0x1018ae08 with parameter 1
20:06:00.028908 [debug]  41 Timers - Starting set timer 1
20:06:00.029722 [debug]  41 Command - PMFOS called
20:06:00.030607 [notice] 32 Core - Signal 23 received
20:06:00.030888 [debug]  32 Core - SIGURG caught
20:06:00.031129 [debug]  32 Command - processing message 15
20:06:00.031358 [debug]  32 Command - Sending message to boxstack
20:06:00.031581 [debug]  32 BoxStack - it's for meeee!
20:06:00.032435 [debug]  41 Timers - timerEventFinished for 0x1018ae08
20:06:00.033249 [debug]  41 Timers - timerEventFinished RESTART for 0x1018ae08
20:06:07.459652 [debug]  32 Remote - Button 31
20:06:07.459950 [debug]  32 Player - LOCKED
20:06:07.460170 [debug]  32 Player - Stop called lock
20:06:07.460387 [debug]  32 Player - Switch state from 1 to 6
20:06:08.294865 [debug]  32 Player - UNLOCKING
20:06:08.295699 [debug]  32 VVideoLive - Delay starts here due to time taken by plugin to stop
20:06:08.408833 [debug]  32 VVideoLive - Delay ends here due to time taken by plugin to stop
20:06:08.584923 [debug]  32 Player - Switch state from 6 to 6
20:06:08.586372 [debug]  32 Video - Setting aspect to 0
20:06:08.587256 [debug]  32 Boxx - Destruct, now 7
20:06:08.588924 [debug]  32 Boxx - Destruct, now 6
20:06:12.813051 [debug]  32 Remote - Button 31
20:06:12.896870 [debug]  32 Boxx - Destruct, now 5
20:06:12.898588 [debug]  32 Boxx - Destruct, now 4
20:06:16.378279 [notice] 32 Core - Signal 2 received
20:06:16.378949 [notice] 32 Core - Interrupt signal, shutting down...
20:06:16.380589 [debug]  32 Timers - Starting cancel timer 0x1018ae08 1, list size = 1
20:06:16.381440 [debug]  32 Timers - Removed timer for 0x1018ae08 ref 1
20:06:16.382427 [debug]  32 Boxx - Destruct, now 3
20:06:16.383259 [debug]  32 Boxx - Destruct, now 2
20:06:16.384914 [debug]  32 Boxx - Destruct, now 1
20:06:16.385742 [notice] 32 Core - BoxStack module shut down
20:06:16.386545 [notice] 32 Core - Command module shut down
20:06:16.387507 [debug]  32 TCP - Have closed
20:06:16.388450 [debug]  32 VDR - Disconnect
20:06:16.388945 [notice] 32 Core - VDR module shut down
20:06:16.390319 [notice] 32 Core - OSD module shut down
20:06:16.390928 [notice] 32 Core - Audio module shut down
20:06:16.445194 [notice] 32 Core - Video module shut down
20:06:16.445872 [debug]  32 Timers - Timers shutdown start
20:06:16.447389 [debug]  32 Timers - Timers shutdown end
20:06:16.448212 [notice] 32 Core - Timers module shut down
20:06:16.448992 [notice] 32 Core - MTD module shut down
20:06:16.449764 [notice] 32 Core - LED module shut down
20:06:16.450662 [notice] 32 Core - Remote module shut down
20:06:16.451330 [notice] 32 Core - WOL module shut down
20:06:16.452228 [notice] 32 Core - Log module shutting down... bye!
Title: Re: Once again: D3A and no video...
Post by: carsten on February 15, 2008, 20:01:07
and even more verbose (is there more than -d10?)

Quote20:00:02.018480 [info]   31 Core - Starting up...
20:00:02.019315 [info]   31 Core - Signal handlers set up successfully
20:00:02.019642 [info]   31 Core - Remote module initialised
20:00:02.019881 [info]   31 Core - LED module initialised
20:00:02.020787 [debug]  31 MTD - Located MTD device: /dev/mtd1
20:00:02.026008 [info]   31 Core - Mtd module initialised
20:00:02.027946 [info]   31 Core - Timers module initialised
20:00:02.028231 [info]   31 Core - Read from MTD: NTSC 720x480
20:00:02.441058 [debug]  31 Video - Setting aspect to 0
20:00:02.451043 [debug]  31 Video - Setting aspect to 0
20:00:02.951011 [debug]  31 Video - Setting aspect to 0
20:00:02.952398 [info]   31 Core - Video module initialised
20:00:03.025562 [info]   31 Core - OSD module initialised
20:00:03.034323 [debug]  31 Audio - MUTE OFF OFF OFF
20:00:03.035049 [info]   31 Core - Audio module initialised
20:00:03.035530 [info]   31 Core - VDR module initialised
20:00:03.035991 [info]   31 Core - BoxStack module initialised
20:00:03.036697 [info]   31 Core - Command module initialised
20:00:03.037192 [notice] 31 Core - Startup successful
20:00:03.037764 [debug]  31 Boxx - Construct, now 1
20:00:03.234508 [debug]  31 Boxx - Destruct, now 0
20:00:03.235377 [debug]  31 Boxx - Construct, now 1
20:00:03.290491 [debug]  31 Command - NTSC wallpaper selected
20:00:03.291663 [debug]  31 BJpeg - File opened
20:00:03.293033 [debug]  31 BJpeg - JPEG read header w=720 h=480, rot=0
20:00:03.294692 [debug]  31 BJpeg - JPEG startup done pw=720 ph=480, xo=0,yo=0, iw=720, ih=480
20:00:03.295555 [debug]  31 BJpeg - header w=720,h=480
20:00:03.855371 [debug]  31 BJpeg - Done all jpeg_read
20:00:03.856370 [debug]  31 BJpeg - jpeg shutdown done, x, y 720 480
20:00:03.857140 [debug]  31 BJpeg - deleted buffer
20:00:03.946159 [debug]  31 Boxx - Construct, now 2
20:00:03.946829 [debug]  31 Boxx - Construct, now 3
20:00:03.961445 [debug]  34 TBBoxx - Draw
20:00:03.977369 [debug]  34 VConnect - Draw done
20:00:03.999235 [notice] 34 VDR - Broadcasting for server
20:00:04.000076 [debug]  31 UDP - Starting UDP command server
20:00:04.002699 [debug]  31 UDP - UDP command server started
20:00:05.501082 [notice] 34 VConnect - Connecting to server at 192.168.7.3
20:00:05.502683 [notice] 34 Wol - Found etheraddr 00:0E:0C:C2:BD:83
20:00:05.503480 [notice] 34 Wol - Server IP set
20:00:05.504377 [debug]  34 TBBoxx - Draw
20:00:05.521005 [debug]  34 VConnect - Draw done
20:00:05.543278 [debug]  34 Command - Connected ok, doing login
20:00:05.544943 [debug]  34 VDR - vdrtime = 1203105606
20:00:05.545734 [debug]  34 VDR - offset = 3600
20:00:06.000008 [debug]  34 VDR - set clock = 0
20:00:06.000647 [debug]  34 VDR - - 1 0
20:00:06.001427 [debug]  34 VDR - - 1 0
21:00:06.002435 [debug]  34 VDR - Timezone data: MVP-1:0
21:00:06.003379 [debug]  34 TBBoxx - Draw
21:00:06.019659 [debug]  34 VConnect - Draw done
21:00:06.044607 [notice] 31 Core - Signal 23 received
21:00:06.045378 [debug]  31 Core - SIGURG caught
21:00:06.046442 [debug]  31 Command - processing message 11
21:00:06.069159 [debug]  31 Boxx - Destruct, now 2
21:00:06.070808 [debug]  31 Boxx - Destruct, now 1
21:00:06.071509 [debug]  31 Boxx - Construct, now 2
21:00:06.072298 [debug]  31 Boxx - Construct, now 3
21:00:06.086444 [debug]  31 TBBoxx - Draw
21:00:06.128189 [debug]  31 Command - Phew, no dangerous on-the-fly mode switching to do!
21:00:06.128872 [debug]  31 Command - Load power after boot
21:00:06.130568 [info]   31 Command - Config General/Power After Boot not found
21:00:06.132140 [info]   31 Command - Switching to RGB/Composite as Connection=RGB+composite
21:00:06.133729 [info]   31 Command - Config General/Remote type not found
21:00:06.135249 [info]   31 Command - /// Switching to TV aspect 4:3
21:00:06.136033 [debug]  31 Video - Setting aspect to 0
21:00:06.644501 [debug]  31 Video - Setting aspect to 0
21:00:06.646250 [info]   31 Command - Setting letterbox mode
21:00:06.647832 [info]   31 Command - Setting TCP window size 8192
21:00:06.648636 [debug]  31 TCP - Set receive window to 8192, success(=0): 0
21:00:06.650485 [info]   31 Command - By default, enable WOL
21:00:06.652235 [info]   31 Remote - Config General/Remote keys load
21:00:06.674702 [debug]  31 Boxx - Destruct, now 2
21:00:06.676330 [debug]  31 Boxx - Destruct, now 1
21:00:06.677178 [debug]  31 Boxx - Construct, now 2
21:00:06.677984 [debug]  31 Boxx - Construct, now 3
21:00:06.678643 [debug]  31 Boxx - Construct, now 4
21:00:06.696568 [debug]  31 TBBoxx - Draw
21:00:06.727793 [debug]  31 BJpeg - File opened
21:00:06.728923 [debug]  31 BJpeg - JPEG read header w=190 h=100, rot=0
21:00:06.743447 [debug]  31 BJpeg - JPEG startup done pw=190 ph=100, xo=0,yo=0, iw=190, ih=100
21:00:06.744187 [debug]  31 BJpeg - header w=190,h=100
21:00:06.779320 [debug]  31 BJpeg - Done all jpeg_read
21:00:06.780305 [debug]  31 BJpeg - jpeg shutdown done, x, y 0 0
21:00:06.780960 [debug]  31 BJpeg - deleted buffer
21:00:06.782636 [debug]  31 Timers - Starting set timer 1
21:00:06.783615 [debug]  31 Timers - Timer set for 0x1018ae08 ref 1
21:00:06.830421 [debug]  31 Command - processing message 28
21:00:06.831099 [debug]  31 Command - processing message 28
21:00:07.645861 [debug]  31 Remote - Button 37
21:00:07.649548 [debug]  31 VDR - Have added a channel to list. 1 1 Das Erste
21:00:07.650285 [debug]  31 VDR - Have added a channel to list. 2 1 ZDF
...
21:00:07.778724 [debug]  31 Boxx - Construct, now 5
21:00:07.779390 [debug]  31 Boxx - Construct, now 6
21:00:07.844211 [debug]  31 TBBoxx - Draw
21:00:07.968112 [debug]  31 Boxx - Construct, now 7
21:00:07.973407 [debug]  31 Boxx - Destruct, now 6
21:00:09.261235 [debug]  31 Remote - Button 37
21:00:09.262119 [debug]  31 Boxx - Construct, now 7
21:00:09.262928 [debug]  31 Boxx - Construct, now 8
21:00:09.466239 [debug]  31 VVideoLive - Do WSS: 1
21:00:09.554773 [debug]  31 VVideoLive - Delay starts here due to time taken by plugin to stop
21:00:09.556344 [debug]  31 VVideoLive - Delay ends here due to time taken by plugin to stop
21:00:09.558327 [debug]  31 Boxx - Construct, now 9
21:00:09.558996 [debug]  31 Boxx - Construct, now 10
21:00:09.581549 [debug]  31 VDR - Success got to end of getChannelSchedule
21:00:09.584409 [debug]  31 Timers - Starting set timer 1
21:00:09.585472 [debug]  31 Timers - Timer set for 0x1018a058 ref 1
21:00:09.586285 [debug]  31 TBBoxx - Draw
21:00:09.611924 [debug]  31 Timers - Starting set timer 1
21:00:09.612958 [debug]  31 Timers - Timer set for 0x1018a058 ref 2
21:00:09.649541 [debug]  31 Channel - C.1 loaded, VPid=101, numApids=1
21:00:09.650219 [debug]  31 Channel - APid 102 deu
21:00:09.651115 [debug]  31 Player - LOCKED
21:00:09.651754 [debug]  31 Player - Switch state from 6 to 1
21:00:09.656781 [debug]  31 Audio - doMuting: user=0 sys=0
21:00:09.657470 [debug]  31 Audio - MUTE OFF OFF OFF
21:00:09.658395 [debug]  31 Audio - doMuting: user=0 sys=0
21:00:09.659198 [debug]  31 Audio - MUTE OFF OFF OFF
21:00:09.665342 [debug]  31 Player - Prebuffering...
21:00:10.315612 [debug]  36 Player - Startup Audio stream chosen c0
21:00:10.320882 [debug]  36 Demux - Aspect ratio difference signalled
21:00:10.321730 [debug]  36 Demuxer - Entering audio sync: Video PTS = 1287204822
21:00:10.323869 [debug]  36 Demuxer - Entering audio sync: Audio PTS = 0
21:00:10.903533 [debug]  36 Demux - Aspect ratio difference signalled
21:00:10.937379 [debug]  36 Player - Got >500K, prebuffering complete
21:00:11.100497 [debug]  36 Demuxer - Leaving  audio sync: Audio PTS = 1287220762
21:00:11.208476 [debug]  36 Demux - Aspect ratio difference signalled
21:00:11.231072 [debug]  37 Player - UNLOCKING
21:00:11.660945 [debug]  36 Demux - Aspect ratio difference signalled
21:00:11.661669 [debug]  36 Player - Callback from demuxer
21:00:11.662588 [debug]  36 Player - TV is 4:3, ignoring aspect switching
21:00:13.594480 [debug]  33 Timers - Timer firing for client 0x1018a058 ref 1
21:00:13.595599 [debug]  39 Timers - sending timer to 0x1018a058 with parameter 1
21:00:13.596563 [debug]  39 Command - PMFOS called
21:00:13.597433 [notice] 31 Core - Signal 23 received
21:00:13.597708 [debug]  31 Core - SIGURG caught
21:00:13.597945 [debug]  31 Command - processing message 2
21:00:13.598170 [debug]  31 Command - Sending message to boxstack
21:00:13.598390 [debug]  31 BoxStack - it's for meeee!
21:00:13.615362 [debug]  31 Timers - Starting cancel timer 0x1018a058 1, list size = 3
21:00:13.616546 [debug]  31 Timers - 0x1018a058 ref 1 cancelTimer WAITING
21:00:13.617319 [debug]  39 Timers - timerEventFinished for 0x1018a058
21:00:13.618268 [debug]  39 Timers - timerEventFinished for 0x1018a058 1 - remove done
21:00:13.674475 [debug]  31 Timers - Starting cancel timer 0x1018a058 2, list size = 2
21:00:13.675189 [debug]  31 Timers - Removed timer for 0x1018a058 ref 2
21:00:13.676928 [debug]  31 Boxx - Destruct, now 9
21:00:13.678612 [debug]  31 Boxx - Destruct, now 8
21:00:20.140362 [debug]  31 Remote - Button 32
21:00:20.140653 [debug]  31 Player - LOCKED
21:00:20.140870 [debug]  31 Player - Stop called lock
21:00:20.141086 [debug]  31 Player - Switch state from 1 to 6
21:00:20.584499 [debug]  31 Player - UNLOCKING
21:00:20.585199 [debug]  31 VVideoLive - Delay starts here due to time taken by plugin to stop
21:00:20.692104 [debug]  31 VVideoLive - Delay ends here due to time taken by plugin to stop
21:00:20.692790 [debug]  31 VVideoLive - Delay starts here due to time taken by plugin to stop
21:00:20.694350 [debug]  31 VVideoLive - Delay ends here due to time taken by plugin to stop
21:00:20.696309 [debug]  31 Boxx - Construct, now 9
21:00:20.696982 [debug]  31 Boxx - Construct, now 10
21:00:20.716534 [debug]  31 VDR - Success got to end of getChannelSchedule
21:00:20.719203 [debug]  31 Timers - Starting set timer 1
21:00:20.720211 [debug]  31 Timers - Timer set for 0x1018a058 ref 1
21:00:20.721022 [debug]  31 TBBoxx - Draw
21:00:20.746601 [debug]  31 Timers - Starting set timer 1
21:00:20.747618 [debug]  31 Timers - Timer set for 0x1018a058 ref 2
21:00:20.775371 [debug]  31 Channel - C.2 loaded, VPid=110, numApids=2
21:00:20.776048 [debug]  31 Channel - APid 120 deu
21:00:20.776966 [debug]  31 Channel - APid 121 2ch
21:00:20.777627 [debug]  31 Player - LOCKED
21:00:20.778399 [debug]  31 Player - Switch state from 6 to 1
21:00:20.783645 [debug]  31 Audio - doMuting: user=0 sys=0
21:00:20.784329 [debug]  31 Audio - MUTE OFF OFF OFF
21:00:20.785279 [debug]  31 Audio - doMuting: user=0 sys=0
21:00:20.786071 [debug]  31 Audio - MUTE OFF OFF OFF
21:00:20.795251 [debug]  31 Player - Prebuffering...
21:00:21.368663 [debug]  40 Player - Startup Audio stream chosen c0
21:00:21.370930 [debug]  40 Demux - Aspect ratio difference signalled
21:00:21.371777 [debug]  40 Demuxer - Entering audio sync: Video PTS = 2002165624
21:00:21.372466 [debug]  40 Demuxer - Entering audio sync: Audio PTS = 0
21:00:21.482141 [debug]  40 Player - Got >500K, prebuffering complete
21:00:21.585973 [debug]  40 Demuxer - Leaving  audio sync: Audio PTS = 2002169641
21:00:21.587344 [debug]  40 Demux - Aspect ratio difference signalled
21:00:21.777160 [debug]  41 Player - UNLOCKING
21:00:22.365538 [debug]  40 Demux - Aspect ratio difference signalled
21:00:22.536352 [debug]  40 Demux - Aspect ratio difference signalled
21:00:22.537070 [debug]  40 Player - Callback from demuxer
21:00:22.537999 [debug]  40 Player - TV is 4:3, ignoring aspect switching
21:00:24.734672 [debug]  33 Timers - Timer firing for client 0x1018a058 ref 1
21:00:24.735773 [debug]  43 Timers - sending timer to 0x1018a058 with parameter 1
21:00:24.736739 [debug]  43 Command - PMFOS called
21:00:24.737611 [notice] 31 Core - Signal 23 received
21:00:24.737886 [debug]  31 Core - SIGURG caught
21:00:24.738123 [debug]  31 Command - processing message 2
21:00:24.738348 [debug]  31 Command - Sending message to boxstack
21:00:24.738569 [debug]  31 BoxStack - it's for meeee!
21:00:24.755280 [debug]  31 Timers - Starting cancel timer 0x1018a058 1, list size = 3
21:00:24.756488 [debug]  31 Timers - 0x1018a058 ref 1 cancelTimer WAITING
21:00:24.757397 [debug]  43 Timers - timerEventFinished for 0x1018a058
21:00:24.758219 [debug]  43 Timers - timerEventFinished for 0x1018a058 1 - remove done
21:00:24.815865 [debug]  31 Timers - Starting cancel timer 0x1018a058 2, list size = 2
21:00:24.816192 [debug]  31 Timers - Removed timer for 0x1018a058 ref 2
21:00:24.817060 [debug]  31 Boxx - Destruct, now 9
21:00:24.818176 [debug]  31 Boxx - Destruct, now 8
21:00:26.582495 [debug]  31 Remote - Button 31
21:00:26.582794 [debug]  31 Player - LOCKED
21:00:26.583014 [debug]  31 Player - Stop called lock
21:00:26.583229 [debug]  31 Player - Switch state from 1 to 6
21:00:27.414509 [debug]  31 Player - UNLOCKING
21:00:27.415207 [debug]  31 VVideoLive - Delay starts here due to time taken by plugin to stop
21:00:27.519633 [debug]  31 VVideoLive - Delay ends here due to time taken by plugin to stop
21:00:27.695856 [debug]  31 Player - Switch state from 6 to 6
Title: Re: Once again: D3A and no video...
Post by: carsten on February 16, 2008, 12:01:05
Anopther hint: during playback of live or recording, as I said I only hear sound. When I then switch
channel, press ok, or change loudness, the appropriate graphics appear on screen. So video out seems
ok, there seems to be a problem with the mpeg stream which gets not decoded and displayed...

BR,
Carsten.
Title: Re: Once again: D3A and no video...
Post by: MartenR on February 17, 2008, 08:25:48
Test you mvp with the original hauppauge software and/or mvpmc, so that you can be sure that the hardware is ok.

Marten
Title: Re: Once again: D3A and no video...
Post by: carsten on February 17, 2008, 18:14:55
OK, it took me a while to a) get it b) install it and c) find a file it's willing to play back. But in fact, there is no problem to playback vide with the 3.4.25345 version.

This seems to be the same (unsolved) issue as in http://www.loggytronic.com/forum/index.php?topic=267.0 (http://www.loggytronic.com/forum/index.php?topic=267.0)

I will slowly start going deep inside the code, but actually, I am a bit rusty...

Can someone tell me in which code module I shall start...?

Thanks for any hint,
Carsten.
Title: Re: Once again: D3A and no video...
Post by: carsten on February 18, 2008, 15:46:16
Hi,

maybe a silly question, but when I understood the sources that I browsed through right, the /dev/vdec_dev
seems to be the device that is a) controlled by io commands to e.g. swithc between 4:3 and 16:9 and on
the other hand (although I haven't found the place) will receive the video streams and display them, whereas
the osd is display in a different manner.

I furthermore assume that the av_core.o module will be in charge for that device and that we don't have any
sources. So could it be that there is a different av_core.o in our dongle than in the Hauppauge dongle that
worked for me and can I simply exchange it by the working one?

Or do I have to go down even more deep inside of this box? How can it bee that there seem to be D3A boxes
working, but at least two with a very similar problem...

...just some thoughts.  :-\

BR,
Carsten.
Title: Re: Once again: D3A and no video...
Post by: carsten on April 24, 2008, 14:49:44
*** push to top ***

Chris, is there any chance that this misterious problem is going to disapear in 0.2.8 or is there
not change in code to display video?

BR,
Carsten.
Title: Re: Once again: D3A and no video...
Post by: Chris on April 25, 2008, 21:05:54
Sorry, there's nothing in the next version to specifically fix this problem. I think swapping out the modules for newer Hauppauge ones (assuming they are newer) is the way to go. Since the same vomp code works on other MVPs I don't think you will get anywhere looking at the vomp source.
Title: Re: Once again: D3A and no video...
Post by: carsten on April 26, 2008, 08:44:50
Thanks anyhow Chris.

Sorry to disagree. Video works with Haupauge and MVPMC setups that use EXACTLY the same kernel module file (crc checked).

But I will keep on working on that (low prio) as I have spent some money on the second box  8). BR, Carsten.
Title: Re: Once again: D3A and no video...
Post by: Chris on April 26, 2008, 13:01:06
Well I suppose the good news is that if MVPMC works on it, there should be nothing to stop vomp working on it. But the bad news is that as I don't have a non-working D3A, I can't really work on the problem. I wonder if MVPMC didn't work at first on this revision...
Title: Re: Once again: D3A and no video...
Post by: carsten on April 26, 2008, 13:32:58
That's a good hint. I'll investigate on that...Carsten.
Title: Re: Once again: D3A and no video...
Post by: carsten on May 22, 2008, 21:02:29
Hi,

haven't checked on your hint, but wanted to give an update on that crazy box.

I installed Mythbuntu on an experimental box with DVB-T stick. Funny enough, it
really worked. Live Video, too.

Then I tried sagetv. Damn, those folks don't have trial on linux. So I install (ehem)
Windows XP on the experimental box. Sage run there. Smart looking and feeling
GUI, I have to admit. They are completely ignorant of Hamburg when it comes to
tuning, though. Nevertheless, I tweak, it worked. Mixture of English and German.
For 100$? Oh, oh.

The so-called Media-Extender immediately booted on MVP. Nice looking.

But: Audio and AAAAAAAAH NO VIDEO!!!!!!

Next will be to desperately await a new version of vomp. Eventually, I will try to
compile a plugin and a cvs dongle. I still hope that you changed something by
chance. Somewhat they must have done differently in MVPMC.

Else, I will sell this thing at Ebay. So be carefull, folks  ;).

Yes, and I will definitely check with MVPMC.

BR,
Carsten.
Title: Re: Once again: D3A and no video...
Post by: soulianis on May 26, 2008, 17:31:41
Hi,

got the same problem unfortunately :(

@Chris:
Would you take my offer and use my MVP revision D3A to debug this problem?
If yes, how can I get your address to mail it to you?
Title: Re: Once again: D3A and no video...
Post by: carsten on May 26, 2008, 19:45:31
Had a kind of the same idea; eventually it makes sense that you do it, if you are located in UK,
thinking of postal services charges...

BR, Carsten.
Title: Re: Once again: D3A and no video...
Post by: soulianis on May 27, 2008, 11:12:03
Quote from: carsten on May 26, 2008, 19:45:31if you are located in UK
nope, Germany :D
Title: Re: Once again: D3A and no video...
Post by: carsten on May 27, 2008, 18:51:58
Dann sind wir ja zwei...

I got a response from Jon Gettler. He looked into what I have experienced and wrote:

QuoteMy understanding is that the VOMP code was derived from what I did for mvpmc.  But that was several years ago, and the code has diverged quite a bit since then.

So your description makes it sound like the VOMP code is broken.

So plenty of activity is possible  8)

I am not sure though, whether I look into this more deeply, as I have bought another E1. So aske me before you
buy an D3A over the next weeks...Although this thing somehow works...managed to view a vob file (Dolby Trailer)
with the enhanced Yaris dongle yesterday. Other VOBs have the same problem as described above.

BR,
Carsten.

Title: Re: Once again: D3A and no video...
Post by: MartenR on May 28, 2008, 06:55:54
maybe I should mention that I have a d3a that works and had never problems

Marten
Title: Re: Once again: D3A and no video...
Post by: soulianis on June 04, 2008, 11:08:06
Quote from: MartenR on May 28, 2008, 06:55:54
maybe I should mention that I have a d3a that works and had never problems

Thank you for mentioning this. Could you post your vompserver configuration? Maybe it's just some problem my configuration? Thank you!
Title: Re: Once again: D3A and no video...
Post by: MartenR on June 05, 2008, 07:16:14
Quote[General]

## Specify a log file here to enable logging

Log file = /tmp/vompserver.log

## If you have more than one vompserver running you
## can enter a name here that will appear on the
## server select list on the MVP

# Server name = My-Server

## Enable this to start the built in Bootp server enabled = yes
## Required to boot the MVP if you have not got a
## DHCP server that can tell the MVP its boot file
## name and server

Bootp server enabled = yes

## Enable this to start the built in TFTP server
## Required to boot the MVP if you have not got a
## TFTP server running elsewhere

TFTP server enabled = yes

## Base directory for TFTP server
## If you leave this blank the plugin config
## path will be used - i.e. where this file is

TFTP directory = /usr/share/vdr-plugin-vompserver
If you want, but there is not anything special it is just the default file...
Title: Re: Once again: D3A and no video...
Post by: Lutz on June 05, 2008, 07:39:00
Hi,
I have two D3A running, a friend another two, all without any probs or special configuration, they are just running since years now, with different versions of vomp; I think yours might have got a hardware problem, maybe a small one; you should consider to try another box...
Sorry
Lutz
Title: Re: Once again: D3A and no video...
Post by: muellerph on June 05, 2008, 12:48:59
Dito for me. Two D3A are running just fine.
Title: Re: Once again: D3A and no video...
Post by: carsten on June 05, 2008, 13:44:59
Hi,

I am still curious that this problem a) occured at least with four different D3A and b) does not occur at least
in the above mentioned environment.

Nevertheless, I solved it for me: bought another E1 in Ebay. Will sell the D3A, as it works with standard software.

BR,
Carsten.
Title: Re: Once again: D3A and no video...
Post by: soulianis on June 06, 2008, 12:00:24
Quote from: MartenR on June 05, 2008, 07:16:14If you want, but there is not anything special it is just the default file...

Thank you. Do you have configured something special in your Vomp-XX-XX-XX-XX-XX-XX.conf file, such as "Live priority"?
Title: Re: Once again: D3A and no video...
Post by: MartenR on June 07, 2008, 07:54:14
QuoteThank you. Do you have configured something special in your Vomp-XX-XX-XX-XX-XX-XX.conf file, such as "Live priority"?
No, it is just the default file, which vomp automatically creates, if there is no file for the current mvp.

Marten
Title: Re: Once again: D3A and no video...
Post by: soulianis on June 07, 2008, 20:50:37
Thank you.
Title: Re: Once again: D3A and no video...
Post by: soulianis on June 08, 2008, 16:41:02
Here are my logs when trying to play a recording, starting at the moment when I hit OK on "play recording".
This is the latest vompserver-0.2.7 (not the CVS version) along with vomp-dongle-0.2.7.

This is the output of vompclient -d on the MVP (part 1):

17:13:51.186330 [debug]  49 Remote - Button 37
17:13:51.196385 [debug]  49 Boxx - Destruct, now 7
17:13:51.198091 [debug]  49 Boxx - Destruct, now 6
17:13:51.198953 [debug]  49 Command - processing message 3
17:13:51.199711 [debug]  49 Command - Sending message to boxstack
17:13:51.200516 [debug]  49 BoxStack - sending message from box 0x1018f3a0 to box 0x10195288 3
17:13:51.201308 [debug]  49 VRecordingList - Got message value 3
Size = 72
00 00 00 00  00 00 00 00  00 00 00 42  55 6E 74 69  ...........BUnti
74 6C 65 64  20 32 30 30  38 20 2D 20  57 61 73 20  tled 2008 - Was
67 69 6C 74  20 69 6E 20  64 65 72 20  7A 65 69 74  gilt in der zeit
67 65 6E F6  73 73 69 73  63 68 65 6E  20 4B 75 6E  gen.ssischen Kun
73 74 3F 00  00 00 00 00                            st?.....
17:13:51.219665 [debug]  49 RecInfo - timerStart 0
17:13:51.220426 [debug]  49 RecInfo - timerEnd 0
17:13:51.221180 [debug]  49 RecInfo - resumePoint 66
17:13:51.221932 [debug]  49 RecInfo - Summary: Untitled 2008 - Was gilt in der zeitgenössischen Kunst?
17:13:51.222707 [debug]  49 RecInfo - numComponents: 0
17:13:51.223480 [debug]  49 Recording - Recording has loaded recInfo 0x1018f240
17:13:51.236565 [debug]  49 VDR - Have added a mark to list. 12
17:13:51.237400 [debug]  49 VDR - Have added a mark to list. 16992
17:13:51.238251 [debug]  49 VDR - Have added a mark to list. 17904
17:13:51.239041 [debug]  49 VDR - Have added a mark to list. 84684
17:13:51.239856 [debug]  49 VDR - Have added a mark to list. 85620
17:13:51.258214 [debug]  49 VDR - VDR said length is: 3050164396 97488
17:13:51.271237 [debug]  49 Recording - Recording has messed about and worked out radio = 0
17:13:51.272122 [debug]  49 Boxx - Construct, now 7
17:13:51.272948 [debug]  49 Boxx - Construct, now 8
17:13:51.371165 [debug]  49 VVideoRec - SM: 300 EM: 300
17:13:51.439237 [debug]  49 VVideoRec - Do WSS: 0
17:13:51.609970 [debug]  49 VVideoRec - Starting stream: /video0/Kulturzeit_extra/2008-03-17.01.25.99.99.rec at frame: 0
17:13:51.629631 [debug]  49 VDR - VDR said length is: 3050164396 97488
17:13:51.630438 [debug]  49 Player - Player has received length bytes of 3050164396
17:13:51.631234 [debug]  49 Player - Player has received length frames of 97488
17:13:51.632015 [debug]  49 Player - LOCKED
17:13:51.632761 [debug]  49 Player - Switch state from 6 to 1
17:13:51.637583 [debug]  49 Audio - doMuting: user=0 sys=0
17:13:51.638413 [debug]  49 Audio - MUTE OFF OFF OFF
17:13:51.639195 [debug]  49 Audio - doMuting: user=0 sys=0
17:13:51.639972 [debug]  49 Audio - MUTE OFF OFF OFF
17:13:51.648047 [debug]  49 Demuxer - setFrameNum 0
17:13:51.649623 [debug]  49 Player - Immediate play
17:13:51.650821 [debug]  54 VDR - VDR said new position is: 0
17:13:51.651640 [debug]  54 Player - startFeedPlay: wantedframe 0 goto 0
17:13:51.764239 [debug]  49 Boxx - Construct, now 9
17:13:51.765344 [debug]  49 VVideoRec - Draw bar clocks
17:13:51.767504 [debug]  49 VVideoRec - 0:00:00 / 1:04:59
17:13:51.771535 [debug]  49 VVideoRec - Drawing mark at frame 12
17:13:51.772401 [debug]  49 VVideoRec - Drawing mark at frame 16992
17:13:51.773272 [debug]  49 VVideoRec - Drawing mark at frame 17904
17:13:51.774135 [debug]  49 VVideoRec - Drawing mark at frame 84684
17:13:51.774978 [debug]  49 VVideoRec - Drawing mark at frame 85620
17:13:51.786023 [debug]  49 Timers - Starting cancel timer 0x1018f974 1, list size = 1
17:13:51.786735 [debug]  49 Timers - Starting set timer 1
17:13:51.787882 [debug]  49 Timers - Timer set for 0x1018f974 ref 1
17:13:51.789002 [debug]  49 Timers - Starting set timer 1
17:13:51.791340 [debug]  49 Timers - Timer set for 0x1018f974 ref 2
17:13:51.792718 [debug]  49 Boxx - Destruct, now 8
17:13:51.840056 [debug]  54 Player - Startup Audio stream chosen 0
17:13:51.840948 [debug]  54 Demux - Aspect ratio difference signalled
17:13:51.841757 [debug]  54 Demuxer - Entering audio sync: Video PTS = 36039
17:13:51.842559 [debug]  54 Demuxer - Entering audio sync: Audio PTS = 0
17:13:51.843380 [debug]  54 Demuxer - +* PTS INIT *+ 36039 0
17:13:51.998077 [debug]  51 Timers - Timer firing for client 0x1018f974 ref 2
17:13:51.999670 [debug]  57 Timers - sending timer to 0x1018f974 with parameter 2
17:13:52.000518 [debug]  57 VVideoRec - Draw bar clocks
17:13:52.002812 [debug]  57 VVideoRec - 0:05:08 / 1:04:59
17:13:52.006903 [debug]  57 VVideoRec - Drawing mark at frame 12
17:13:52.007779 [debug]  57 VVideoRec - Drawing mark at frame 16992
17:13:52.009494 [debug]  57 VVideoRec - Drawing mark at frame 17904
17:13:52.010390 [debug]  57 VVideoRec - Drawing mark at frame 84684
17:13:52.011248 [debug]  57 VVideoRec - Drawing mark at frame 85620
17:13:52.012139 [debug]  57 Command - PMFOS called
17:13:52.013025 [notice] 49 Core - Signal 23 received
17:13:52.013311 [debug]  49 Core - SIGURG caught
17:13:52.013560 [debug]  49 Command - processing message 15
17:13:52.013796 [debug]  49 Command - Sending message to boxstack
17:13:52.014023 [debug]  49 BoxStack - it's for meeee!
17:13:52.025081 [debug]  57 Timers - Starting set timer 1
17:13:52.025900 [debug]  57 Timers - timerEventFinished for 0x1018f974
17:13:52.026695 [debug]  57 Timers - timerEventFinished RESTART for 0x1018f974
17:13:52.039164 [debug]  54 Demuxer - Leaving  audio sync: Audio PTS = 37933
17:13:52.105383 [debug]  54 Demux - Aspect ratio difference signalled
17:13:52.228095 [debug]  51 Timers - Timer firing for client 0x1018f974 ref 2
17:13:52.229889 [debug]  58 Timers - sending timer to 0x1018f974 with parameter 2
17:13:52.230742 [debug]  58 VVideoRec - Draw bar clocks
17:13:52.233068 [debug]  58 VVideoRec - 0:05:08 / 1:04:59
17:13:52.237639 [debug]  58 VVideoRec - Drawing mark at frame 12
17:13:52.238600 [debug]  58 VVideoRec - Drawing mark at frame 16992
17:13:52.239485 [debug]  58 VVideoRec - Drawing mark at frame 17904
17:13:52.240337 [debug]  58 VVideoRec - Drawing mark at frame 84684
17:13:52.241183 [debug]  58 VVideoRec - Drawing mark at frame 85620
17:13:52.242063 [debug]  58 Command - PMFOS called
17:13:52.242949 [notice] 49 Core - Signal 23 received
17:13:52.243231 [debug]  49 Core - SIGURG caught
17:13:52.243478 [debug]  49 Command - processing message 15
17:13:52.243709 [debug]  49 Command - Sending message to boxstack
17:13:52.243933 [debug]  49 BoxStack - it's for meeee!
17:13:52.255997 [debug]  58 Timers - Starting set timer 1
17:13:52.256808 [debug]  58 Timers - timerEventFinished for 0x1018f974
17:13:52.257598 [debug]  58 Timers - timerEventFinished RESTART for 0x1018f974
17:13:52.336874 [debug]  54 Demux - Aspect ratio difference signalled
17:13:52.468040 [debug]  51 Timers - Timer firing for client 0x1018f974 ref 2
17:13:52.469455 [debug]  59 Timers - sending timer to 0x1018f974 with parameter 2
17:13:52.470303 [debug]  59 VVideoRec - Draw bar clocks
17:13:52.472621 [debug]  59 VVideoRec - 0:05:08 / 1:04:59
17:13:52.477184 [debug]  59 VVideoRec - Drawing mark at frame 12
17:13:52.478137 [debug]  59 VVideoRec - Drawing mark at frame 16992
17:13:52.479022 [debug]  59 VVideoRec - Drawing mark at frame 17904
17:13:52.479879 [debug]  59 VVideoRec - Drawing mark at frame 84684
17:13:52.480728 [debug]  59 VVideoRec - Drawing mark at frame 85620
17:13:52.481610 [debug]  59 Command - PMFOS called
17:13:52.482496 [notice] 49 Core - Signal 23 received
17:13:52.482777 [debug]  49 Core - SIGURG caught
17:13:52.483023 [debug]  49 Command - processing message 15
17:13:52.483254 [debug]  49 Command - Sending message to boxstack
17:13:52.483478 [debug]  49 BoxStack - it's for meeee!
17:13:52.495542 [debug]  59 Timers - Starting set timer 1
17:13:52.496355 [debug]  59 Timers - timerEventFinished for 0x1018f974
17:13:52.497145 [debug]  59 Timers - timerEventFinished RESTART for 0x1018f974
17:13:52.632028 [debug]  54 Demux - Aspect ratio difference signalled
17:13:52.632599 [debug]  54 Player - Callback from demuxer
17:13:52.633083 [debug]  54 Player - TV is 4:3, ignoring aspect switching
17:13:52.708035 [debug]  51 Timers - Timer firing for client 0x1018f974 ref 2
17:13:52.711798 [debug]  60 Timers - sending timer to 0x1018f974 with parameter 2
17:13:52.712366 [debug]  60 VVideoRec - Draw bar clocks
17:13:52.714263 [debug]  60 VVideoRec - 0:05:08 / 1:04:59
17:13:52.718941 [debug]  60 VVideoRec - Drawing mark at frame 12
17:13:52.720768 [debug]  60 VVideoRec - Drawing mark at frame 16992
17:13:52.722585 [debug]  60 VVideoRec - Drawing mark at frame 17904
17:13:52.724402 [debug]  60 VVideoRec - Drawing mark at frame 84684
17:13:52.726193 [debug]  60 VVideoRec - Drawing mark at frame 85620
17:13:52.728084 [debug]  60 Command - PMFOS called
17:13:52.729905 [notice] 49 Core - Signal 23 received
17:13:52.730530 [debug]  49 Core - SIGURG caught
17:13:52.730785 [debug]  49 Command - processing message 15
17:13:52.731017 [debug]  49 Command - Sending message to boxstack
17:13:52.731243 [debug]  49 BoxStack - it's for meeee!
17:13:52.742373 [debug]  60 Timers - Starting set timer 1
17:13:52.743513 [debug]  60 Timers - timerEventFinished for 0x1018f974
17:13:52.745261 [debug]  60 Timers - timerEventFinished RESTART for 0x1018f974
17:13:52.948040 [debug]  51 Timers - Timer firing for client 0x1018f974 ref 2
17:13:52.949755 [debug]  61 Timers - sending timer to 0x1018f974 with parameter 2
17:13:52.951820 [debug]  61 VVideoRec - Draw bar clocks
17:13:52.957706 [debug]  61 VVideoRec - 0:05:08 / 1:04:59
17:13:52.968845 [debug]  61 VVideoRec - Drawing mark at frame 12
17:13:52.970944 [debug]  61 VVideoRec - Drawing mark at frame 16992
17:13:52.973039 [debug]  61 VVideoRec - Drawing mark at frame 17904
17:13:52.975105 [debug]  61 VVideoRec - Drawing mark at frame 84684
17:13:52.977173 [debug]  61 VVideoRec - Drawing mark at frame 85620
17:13:52.979348 [debug]  61 Command - PMFOS called
17:13:52.981442 [notice] 49 Core - Signal 23 received
17:13:52.982068 [debug]  49 Core - SIGURG caught
17:13:52.982322 [debug]  49 Command - processing message 15
17:13:52.982553 [debug]  49 Command - Sending message to boxstack
17:13:52.982778 [debug]  49 BoxStack - it's for meeee!
17:13:52.995076 [debug]  61 Timers - Second rollover - CHECK FIXME
17:13:52.996485 [debug]  61 Timers - Starting set timer 1
17:13:52.997896 [debug]  61 Timers - timerEventFinished for 0x1018f974
17:13:52.999971 [debug]  61 Timers - timerEventFinished RESTART for 0x1018f974
17:13:53.208087 [debug]  51 Timers - Timer firing for client 0x1018f974 ref 2
17:13:53.209208 [debug]  62 Timers - sending timer to 0x1018f974 with parameter 2
17:13:53.210172 [debug]  62 VVideoRec - Draw bar clocks
17:13:53.212505 [debug]  62 VVideoRec - 0:05:08 / 1:04:59
17:13:53.217086 [debug]  62 VVideoRec - Drawing mark at frame 12
17:13:53.218029 [debug]  62 VVideoRec - Drawing mark at frame 16992
17:13:53.219124 [debug]  62 VVideoRec - Drawing mark at frame 17904
17:13:53.220012 [debug]  62 VVideoRec - Drawing mark at frame 84684
17:13:53.220865 [debug]  62 VVideoRec - Drawing mark at frame 85620
17:13:53.221771 [debug]  62 Command - PMFOS called
17:13:53.222669 [notice] 49 Core - Signal 23 received
17:13:53.222951 [debug]  49 Core - SIGURG caught
17:13:53.223197 [debug]  49 Command - processing message 15
17:13:53.223428 [debug]  49 Command - Sending message to boxstack
17:13:53.223652 [debug]  49 BoxStack - it's for meeee!
17:13:53.235563 [debug]  62 Timers - Starting set timer 1
17:13:53.236502 [debug]  62 Timers - timerEventFinished for 0x1018f974
17:13:53.237288 [debug]  62 Timers - timerEventFinished RESTART for 0x1018f974
17:13:53.448000 [debug]  51 Timers - Timer firing for client 0x1018f974 ref 2
17:13:53.449101 [debug]  63 Timers - sending timer to 0x1018f974 with parameter 2
17:13:53.450063 [debug]  63 VVideoRec - Draw bar clocks
17:13:53.452378 [debug]  63 VVideoRec - 0:05:08 / 1:04:59
17:13:53.456945 [debug]  63 VVideoRec - Drawing mark at frame 12
17:13:53.457804 [debug]  63 VVideoRec - Drawing mark at frame 16992
17:13:53.458930 [debug]  63 VVideoRec - Drawing mark at frame 17904
17:13:53.459809 [debug]  63 VVideoRec - Drawing mark at frame 84684
17:13:53.460664 [debug]  63 VVideoRec - Drawing mark at frame 85620
17:13:53.461547 [debug]  63 Command - PMFOS called
17:13:53.462420 [notice] 49 Core - Signal 23 received
17:13:53.462700 [debug]  49 Core - SIGURG caught
17:13:53.462945 [debug]  49 Command - processing message 15
17:13:53.463176 [debug]  49 Command - Sending message to boxstack
17:13:53.463401 [debug]  49 BoxStack - it's for meeee!
17:13:53.475299 [debug]  63 Timers - Starting set timer 1
17:13:53.475830 [debug]  63 Timers - timerEventFinished for 0x1018f974
17:13:53.476315 [debug]  63 Timers - timerEventFinished RESTART for 0x1018f974
17:13:53.678003 [debug]  51 Timers - Timer firing for client 0x1018f974 ref 2
17:13:53.679135 [debug]  64 Timers - sending timer to 0x1018f974 with parameter 2
17:13:53.679660 [debug]  64 VVideoRec - Draw bar clocks
17:13:53.681157 [debug]  64 VVideoRec - 0:05:08 / 1:04:59
17:13:53.684938 [debug]  64 VVideoRec - Drawing mark at frame 12
17:13:53.685510 [debug]  64 VVideoRec - Drawing mark at frame 16992
17:13:53.686068 [debug]  64 VVideoRec - Drawing mark at frame 17904
17:13:53.686637 [debug]  64 VVideoRec - Drawing mark at frame 84684
17:13:53.687194 [debug]  64 VVideoRec - Drawing mark at frame 85620
17:13:53.687784 [debug]  64 Command - PMFOS called
17:13:53.688399 [notice] 49 Core - Signal 23 received
17:13:53.688670 [debug]  49 Core - SIGURG caught
17:13:53.688915 [debug]  49 Command - processing message 15
17:13:53.689146 [debug]  49 Command - Sending message to boxstack
17:13:53.689371 [debug]  49 BoxStack - it's for meeee!
17:13:53.701061 [debug]  64 Timers - Starting set timer 1
17:13:53.701583 [debug]  64 Timers - timerEventFinished for 0x1018f974
17:13:53.702071 [debug]  64 Timers - timerEventFinished RESTART for 0x1018f974
17:13:53.908014 [debug]  51 Timers - Timer firing for client 0x1018f974 ref 2
17:13:53.909264 [debug]  65 Timers - sending timer to 0x1018f974 with parameter 2
17:13:53.909710 [debug]  65 VVideoRec - Draw bar clocks
17:13:53.911484 [debug]  65 VVideoRec - 0:05:08 / 1:04:59
17:13:53.915508 [debug]  65 VVideoRec - Drawing mark at frame 12
17:13:53.915813 [debug]  65 VVideoRec - Drawing mark at frame 16992
17:13:53.916118 [debug]  65 VVideoRec - Drawing mark at frame 17904
17:13:53.916423 [debug]  65 VVideoRec - Drawing mark at frame 84684
17:13:53.916718 [debug]  65 VVideoRec - Drawing mark at frame 85620
17:13:53.917044 [debug]  65 Command - PMFOS called
17:13:53.917319 [debug]  65 Timers - Second rollover - CHECK FIXME
17:13:53.917548 [debug]  65 Timers - Starting set timer 1
17:13:53.917781 [debug]  65 Timers - timerEventFinished for 0x1018f974
17:13:53.918601 [debug]  65 Timers - timerEventFinished RESTART for 0x1018f974
17:13:53.919847 [notice] 49 Core - Signal 23 received
17:13:53.920651 [debug]  49 Core - SIGURG caught
17:13:53.921436 [debug]  49 Command - processing message 15
17:13:53.922210 [debug]  49 Command - Sending message to boxstack
17:13:53.922979 [debug]  49 BoxStack - it's for meeee!
Title: Re: Once again: D3A and no video...
Post by: soulianis on June 08, 2008, 16:43:31
Output of vompclient -d on the MVP (part 2):

17:13:54.128004 [debug]  51 Timers - Timer firing for client 0x1018f974 ref 2
17:13:54.129291 [debug]  66 Timers - sending timer to 0x1018f974 with parameter 2
17:13:54.129746 [debug]  66 VVideoRec - Draw bar clocks
17:13:54.131508 [debug]  66 VVideoRec - 0:05:08 / 1:04:59
17:13:54.135536 [debug]  66 VVideoRec - Drawing mark at frame 12
17:13:54.135852 [debug]  66 VVideoRec - Drawing mark at frame 16992
17:13:54.136153 [debug]  66 VVideoRec - Drawing mark at frame 17904
17:13:54.136460 [debug]  66 VVideoRec - Drawing mark at frame 84684
17:13:54.136753 [debug]  66 VVideoRec - Drawing mark at frame 85620
17:13:54.137077 [debug]  66 Command - PMFOS called
17:13:54.137354 [debug]  66 Timers - Starting set timer 1
17:13:54.137593 [debug]  66 Timers - timerEventFinished for 0x1018f974
17:13:54.137824 [debug]  66 Timers - timerEventFinished RESTART for 0x1018f974
17:13:54.139082 [notice] 49 Core - Signal 23 received
17:13:54.139885 [debug]  49 Core - SIGURG caught
17:13:54.140685 [debug]  49 Command - processing message 15
17:13:54.141463 [debug]  49 Command - Sending message to boxstack
17:13:54.142233 [debug]  49 BoxStack - it's for meeee!
17:13:54.348003 [debug]  51 Timers - Timer firing for client 0x1018f974 ref 2
17:13:54.349083 [debug]  67 Timers - sending timer to 0x1018f974 with parameter 2
17:13:54.349528 [debug]  67 VVideoRec - Draw bar clocks
17:13:54.351293 [debug]  67 VVideoRec - 0:05:08 / 1:04:59
17:13:54.355312 [debug]  67 VVideoRec - Drawing mark at frame 12
17:13:54.355628 [debug]  67 VVideoRec - Drawing mark at frame 16992
17:13:54.355928 [debug]  67 VVideoRec - Drawing mark at frame 17904
17:13:54.356235 [debug]  67 VVideoRec - Drawing mark at frame 84684
17:13:54.356529 [debug]  67 VVideoRec - Drawing mark at frame 85620
17:13:54.356854 [debug]  67 Command - PMFOS called
17:13:54.357131 [debug]  67 Timers - Starting set timer 1
17:13:54.358232 [debug]  67 Timers - timerEventFinished for 0x1018f974
17:13:54.358527 [debug]  67 Timers - timerEventFinished RESTART for 0x1018f974
17:13:54.359584 [notice] 49 Core - Signal 23 received
17:13:54.360383 [debug]  49 Core - SIGURG caught
17:13:54.361169 [debug]  49 Command - processing message 15
17:13:54.361936 [debug]  49 Command - Sending message to boxstack
17:13:54.362705 [debug]  49 BoxStack - it's for meeee!
17:13:54.568001 [debug]  51 Timers - Timer firing for client 0x1018f974 ref 2
17:13:54.569251 [debug]  68 Timers - sending timer to 0x1018f974 with parameter 2
17:13:54.570216 [debug]  68 VVideoRec - Draw bar clocks
17:13:54.572540 [debug]  68 VVideoRec - 0:05:08 / 1:04:59
17:13:54.577119 [debug]  68 VVideoRec - Drawing mark at frame 12
17:13:54.578080 [debug]  68 VVideoRec - Drawing mark at frame 16992
17:13:54.578957 [debug]  68 VVideoRec - Drawing mark at frame 17904
17:13:54.579824 [debug]  68 VVideoRec - Drawing mark at frame 84684
17:13:54.580673 [debug]  68 VVideoRec - Drawing mark at frame 85620
17:13:54.581559 [debug]  68 Command - PMFOS called
17:13:54.582246 [debug]  68 Timers - Starting set timer 1
17:13:54.582757 [debug]  68 Timers - timerEventFinished for 0x1018f974
17:13:54.583246 [debug]  68 Timers - timerEventFinished RESTART for 0x1018f974
17:13:54.584031 [notice] 49 Core - Signal 23 received
17:13:54.584544 [debug]  49 Core - SIGURG caught
17:13:54.585034 [debug]  49 Command - processing message 15
17:13:54.585510 [debug]  49 Command - Sending message to boxstack
17:13:54.585974 [debug]  49 BoxStack - it's for meeee!
17:13:54.788027 [debug]  51 Timers - Timer firing for client 0x1018f974 ref 2
17:13:54.789127 [debug]  69 Timers - sending timer to 0x1018f974 with parameter 2
17:13:54.789656 [debug]  69 VVideoRec - Draw bar clocks
17:13:54.791536 [debug]  69 VVideoRec - 0:05:08 / 1:04:59
17:13:54.795318 [debug]  69 VVideoRec - Drawing mark at frame 12
17:13:54.795892 [debug]  69 VVideoRec - Drawing mark at frame 16992
17:13:54.796457 [debug]  69 VVideoRec - Drawing mark at frame 17904
17:13:54.797028 [debug]  69 VVideoRec - Drawing mark at frame 84684
17:13:54.797583 [debug]  69 VVideoRec - Drawing mark at frame 85620
17:13:54.798221 [debug]  69 Command - PMFOS called
17:13:54.798742 [debug]  69 Timers - Starting set timer 1
17:13:54.799236 [debug]  69 Timers - timerEventFinished for 0x1018f974
17:13:54.799725 [debug]  69 Timers - timerEventFinished RESTART for 0x1018f974
17:13:54.800510 [notice] 49 Core - Signal 23 received
17:13:54.801020 [debug]  49 Core - SIGURG caught
17:13:54.801510 [debug]  49 Command - processing message 15
17:13:54.801985 [debug]  49 Command - Sending message to boxstack
17:13:54.802451 [debug]  49 BoxStack - it's for meeee!
17:13:55.008007 [debug]  51 Timers - Timer firing for client 0x1018f974 ref 2
17:13:55.009099 [debug]  70 Timers - sending timer to 0x1018f974 with parameter 2
17:13:55.009559 [debug]  70 VVideoRec - Draw bar clocks
17:13:55.011433 [debug]  70 VVideoRec - 0:05:08 / 1:04:59
17:13:55.015531 [debug]  70 VVideoRec - Drawing mark at frame 12
17:13:55.015852 [debug]  70 VVideoRec - Drawing mark at frame 16992
17:13:55.016157 [debug]  70 VVideoRec - Drawing mark at frame 17904
17:13:55.016470 [debug]  70 VVideoRec - Drawing mark at frame 84684
17:13:55.016768 [debug]  70 VVideoRec - Drawing mark at frame 85620
17:13:55.017094 [debug]  70 Command - PMFOS called
17:13:55.017374 [debug]  70 Timers - Starting set timer 1
17:13:55.018498 [debug]  70 Timers - timerEventFinished for 0x1018f974
17:13:55.018795 [debug]  70 Timers - timerEventFinished RESTART for 0x1018f974
17:13:55.019910 [notice] 49 Core - Signal 23 received
17:13:55.020707 [debug]  49 Core - SIGURG caught
17:13:55.021509 [debug]  49 Command - processing message 15

17:13:55.022288 [debug]  49 Command - Sending message to boxstack
17:13:55.023068 [debug]  49 BoxStack - it's for meeee!
17:13:55.228004 [debug]  51 Timers - Timer firing for client 0x1018f974 ref 2
17:13:55.228689 [debug]  71 Timers - sending timer to 0x1018f974 with parameter 2
17:13:55.228983 [debug]  71 VVideoRec - Draw bar clocks
17:13:55.230617 [debug]  71 VVideoRec - 0:05:08 / 1:04:59
17:13:55.234159 [debug]  71 VVideoRec - Drawing mark at frame 12
17:13:55.234476 [debug]  71 VVideoRec - Drawing mark at frame 16992
17:13:55.234780 [debug]  71 VVideoRec - Drawing mark at frame 17904
17:13:55.235095 [debug]  71 VVideoRec - Drawing mark at frame 84684
17:13:55.235392 [debug]  71 VVideoRec - Drawing mark at frame 85620
17:13:55.235721 [debug]  71 Command - PMFOS called
17:13:55.235999 [debug]  71 Timers - Starting set timer 1
17:13:55.237105 [debug]  71 Timers - timerEventFinished for 0x1018f974
17:13:55.237400 [debug]  71 Timers - timerEventFinished RESTART for 0x1018f974
17:13:55.238627 [notice] 49 Core - Signal 23 received
17:13:55.239419 [debug]  49 Core - SIGURG caught
17:13:55.240204 [debug]  49 Command - processing message 15
17:13:55.240973 [debug]  49 Command - Sending message to boxstack
17:13:55.241744 [debug]  49 BoxStack - it's for meeee!
17:13:55.438001 [debug]  51 Timers - Timer firing for client 0x1018f974 ref 2
17:13:55.438833 [debug]  72 Timers - sending timer to 0x1018f974 with parameter 2
17:13:55.439127 [debug]  72 VVideoRec - Draw bar clocks
17:13:55.440636 [debug]  72 VVideoRec - 0:05:08 / 1:04:59
17:13:55.444576 [debug]  72 VVideoRec - Drawing mark at frame 12
17:13:55.444914 [debug]  72 VVideoRec - Drawing mark at frame 16992
17:13:55.445222 [debug]  72 VVideoRec - Drawing mark at frame 17904
17:13:55.445523 [debug]  72 VVideoRec - Drawing mark at frame 84684
17:13:55.445819 [debug]  72 VVideoRec - Drawing mark at frame 85620
17:13:55.446147 [debug]  72 Command - PMFOS called
17:13:55.446424 [debug]  72 Timers - Starting set timer 1
17:13:55.446665 [debug]  72 Timers - timerEventFinished for 0x1018f974
17:13:55.446897 [debug]  72 Timers - timerEventFinished RESTART for 0x1018f974
17:13:55.447924 [notice] 49 Core - Signal 23 received
17:13:55.448965 [debug]  49 Core - SIGURG caught
17:13:55.449752 [debug]  49 Command - processing message 15
17:13:55.450520 [debug]  49 Command - Sending message to boxstack
17:13:55.451284 [debug]  49 BoxStack - it's for meeee!
17:13:55.648000 [debug]  51 Timers - Timer firing for client 0x1018f974 ref 2
17:13:55.648682 [debug]  73 Timers - sending timer to 0x1018f974 with parameter 2
17:13:55.648973 [debug]  73 VVideoRec - Draw bar clocks
17:13:55.650736 [debug]  73 VVideoRec - 0:05:08 / 1:04:59
17:13:55.654759 [debug]  73 VVideoRec - Drawing mark at frame 12
17:13:55.655073 [debug]  73 VVideoRec - Drawing mark at frame 16992
17:13:55.655378 [debug]  73 VVideoRec - Drawing mark at frame 17904
17:13:55.655679 [debug]  73 VVideoRec - Drawing mark at frame 84684
17:13:55.655978 [debug]  73 VVideoRec - Drawing mark at frame 85620
17:13:55.656301 [debug]  73 Command - PMFOS called
17:13:55.656578 [debug]  73 Timers - Starting set timer 1
17:13:55.657522 [debug]  73 Timers - timerEventFinished for 0x1018f974
17:13:55.657812 [debug]  73 Timers - timerEventFinished RESTART for 0x1018f974
17:13:55.658760 [notice] 49 Core - Signal 23 received
17:13:55.659262 [debug]  49 Core - SIGURG caught
17:13:55.659754 [debug]  49 Command - processing message 15
17:13:55.660230 [debug]  49 Command - Sending message to boxstack
17:13:55.660696 [debug]  49 BoxStack - it's for meeee!
17:13:55.798002 [debug]  51 Timers - Timer firing for client 0x1018f974 ref 1
17:13:55.798962 [debug]  74 Timers - sending timer to 0x1018f974 with parameter 1
17:13:55.799519 [debug]  74 Timers - Starting cancel timer 0x1018f974 2, list size = 3
17:13:55.800254 [debug]  74 Timers - Removed timer for 0x1018f974 ref 2
17:13:55.807596 [debug]  74 Command - PMFOS called
17:13:55.808380 [debug]  74 Timers - timerEventFinished for 0x1018f974
17:13:55.808889 [debug]  74 Timers - timerEventFinished for 0x1018f974 1 - remove done
17:13:55.809501 [notice] 49 Core - Signal 23 received
17:13:55.810004 [debug]  49 Core - SIGURG caught
17:13:55.810500 [debug]  49 Command - processing message 15
17:13:55.810980 [debug]  49 Command - Sending message to boxstack
17:13:55.811452 [debug]  49 BoxStack - it's for meeee!
17:14:00.008006 [debug]  51 Timers - Timer firing for client 0x1018b018 ref 1
17:14:00.008876 [debug]  75 Timers - sending timer to 0x1018b018 with parameter 1
17:14:00.009896 [debug]  75 Timers - Starting set timer 1
17:14:00.010153 [debug]  75 Command - PMFOS called
17:14:00.010419 [debug]  75 Timers - timerEventFinished for 0x1018b018
17:14:00.010660 [debug]  75 Timers - timerEventFinished RESTART for 0x1018b018
17:14:00.011762 [notice] 49 Core - Signal 23 received
17:14:00.012563 [debug]  49 Core - SIGURG caught
17:14:00.013370 [debug]  49 Command - processing message 15
17:14:00.014028 [debug]  49 Command - Sending message to boxstack
17:14:00.014943 [debug]  49 BoxStack - it's for meeee!


Then nothing more was output. On the TV the screen was black. Then I pressed the BACK key on the remote:

17:14:42.302499 [debug]  49 Remote - Button 31
17:14:42.303328 [debug]  49 VVideoRec - Pre stopPlay
17:15:00.008005 [debug]  51 Timers - Timer firing for client 0x1018b018 ref 1
17:15:00.008877 [debug]  76 Timers - sending timer to 0x1018b018 with parameter 1
17:15:00.009882 [debug]  76 Timers - Starting set timer 1
17:15:00.010134 [debug]  76 Command - PMFOS called
17:15:00.010400 [debug]  76 Timers - timerEventFinished for 0x1018b018
17:15:00.010642 [debug]  76 Timers - timerEventFinished RESTART for 0x1018b018
17:15:00.011591 [notice] 49 Core - Signal 23 received
17:15:00.012535 [debug]  49 Core - SIGURG caught
Title: Re: Once again: D3A and no video...
Post by: soulianis on June 08, 2008, 16:44:30
After that, the MVP did not react anymore so I plugged the power cord :(

Here is the corresponding vompserver.log:

17:13:52.080752 [debug]  Client - Received packet, length = 56
17:13:52.080952 [debug]  Client - SwitchOp
17:13:52.093299 [debug]  Client - GRI: RP: 66
17:13:52.093372 [debug]  Client - GRI: S: Untitled 2008 - Was gilt in der zeitgenössischen Kunst?
17:13:52.093397 [debug]  Client - GRI: D1: (nil)
17:13:52.093423 [debug]  Client - recorded size as 72
17:13:52.093509 [debug]  Client - Written getrecinfo
17:13:52.093804 [debug]  Client - Waiting
17:13:52.102880 [debug]  Client - Received packet, length = 56
17:13:52.102951 [debug]  Client - SwitchOp
17:13:52.114021 [debug]  Client - recording pointer 0x88a6268
17:13:52.114382 [debug]  Client - found Mark 12
17:13:52.114414 [debug]  Client - found Mark 16992
17:13:52.114437 [debug]  Client - found Mark 17904
17:13:52.114461 [debug]  Client - found Mark 84684
17:13:52.114484 [debug]  Client - found Mark 85620
17:13:52.114507 [debug]  Client - recorded size as 20
17:13:52.114588 [debug]  Client - Written Marks list
17:13:52.114829 [debug]  Client - Waiting
17:13:52.119258 [debug]  Client - Received packet, length = 56
17:13:52.119331 [debug]  Client - SwitchOp
17:13:52.130333 [debug]  Client - recording pointer 0x827a618
17:13:52.135418 [debug]  RecPlayer - FILENAME: /video0/Kulturzeit_extra/2008-03-17.01.25.99.99.rec/001.vdr
17:13:52.135781 [debug]  RecPlayer - File 1 found, totalLength now 2097379372, numFrames = 97488
17:13:52.135952 [debug]  RecPlayer - FILENAME: /video0/Kulturzeit_extra/2008-03-17.01.25.99.99.rec/002.vdr
17:13:52.136065 [debug]  RecPlayer - File 2 found, totalLength now 3050164396, numFrames = 97488
17:13:52.136113 [debug]  RecPlayer - FILENAME: /video0/Kulturzeit_extra/2008-03-17.01.25.99.99.rec/003.vdr
17:13:52.136213 [debug]  Client - written totalLength
17:13:52.136248 [debug]  Client - Waiting
17:13:52.139935 [debug]  Client - Received packet, length = 16
17:13:52.140086 [debug]  Client - SwitchOp
17:13:52.140115 [debug]  Client - getblock pos = 0 length = 10000
17:13:52.140143 [debug]  Client - getting from recording
17:13:52.140179 [debug]  RecPlayer - openFile called for index 1 string:/video0/Kulturzeit_extra/2008-03-17.01.25.99.99.rec/001.vdr
17:13:52.140464 [debug]  Client - written ok 10000
17:13:52.140516 [debug]  Client - Waiting
17:13:52.147939 [debug]  Client - Received packet, length = 4
17:13:52.148104 [debug]  Client - SwitchOp
17:13:52.148133 [debug]  Client - STOP STREAMING RECEIVED
17:13:52.148908 [debug]  RecPlayer - destructor
17:13:52.149262 [debug]  Client - written ULONG 1
17:13:52.149298 [debug]  Client - Waiting
17:13:52.247704 [debug]  Client - Received packet, length = 24
17:13:52.247902 [debug]  Client - SwitchOp
17:13:52.248089 [debug]  Config - 2
17:13:52.248173 [debug]  Config - Config error: Section Timers not found
17:13:52.248260 [debug]  Client - Written config load failed packet
17:13:52.248290 [debug]  Client - Waiting
17:13:52.248891 [debug]  Client - Received packet, length = 22
17:13:52.248932 [debug]  Client - SwitchOp
17:13:52.249077 [debug]  Config - 2
17:13:52.249129 [debug]  Config - Config error: Section Timers not found
17:13:52.249183 [debug]  Client - Written config load failed packet
17:13:52.249284 [debug]  Client - Waiting
17:13:52.316680 [debug]  Client - Received packet, length = 16
17:13:52.316836 [debug]  Client - SwitchOp
17:13:52.317055 [debug]  Config - Config error: Key WSS not found
17:13:52.317145 [debug]  Client - Written config load failed packet
17:13:52.317174 [debug]  Client - Waiting
17:13:52.489423 [debug]  Client - Received packet, length = 56
17:13:52.489573 [debug]  Client - SwitchOp
17:13:52.501764 [debug]  Client - recording pointer 0x827a500
17:13:52.506760 [debug]  RecPlayer - FILENAME: /video0/Kulturzeit_extra/2008-03-17.01.25.99.99.rec/001.vdr
17:13:52.507127 [debug]  RecPlayer - File 1 found, totalLength now 2097379372, numFrames = 97488
17:13:52.507255 [debug]  RecPlayer - FILENAME: /video0/Kulturzeit_extra/2008-03-17.01.25.99.99.rec/002.vdr
17:13:52.507356 [debug]  RecPlayer - File 2 found, totalLength now 3050164396, numFrames = 97488
17:13:52.507409 [debug]  RecPlayer - FILENAME: /video0/Kulturzeit_extra/2008-03-17.01.25.99.99.rec/003.vdr
17:13:52.507517 [debug]  Client - written totalLength
17:13:52.507556 [debug]  Client - Waiting
17:13:52.527899 [debug]  Client - Received packet, length = 8
17:13:52.528060 [debug]  Client - SwitchOp
17:13:52.528145 [debug]  Client - Wrote posFromFrameNum reply to client
17:13:52.528179 [debug]  Client - Waiting
17:13:52.530959 [debug]  Client - Received packet, length = 16
17:13:52.530996 [debug]  Client - SwitchOp
17:13:52.531022 [debug]  Client - getblock pos = 0 length = 250000
17:13:52.531073 [debug]  Client - getting from recording
17:13:52.531117 [debug]  RecPlayer - openFile called for index 1 string:/video0/Kulturzeit_extra/2008-03-17.01.25.99.99.rec/001.vdr
17:13:52.697698 [debug]  Client - written ok 250000
17:13:52.697887 [debug]  Client - Waiting
17:13:52.754385 [debug]  Client - Received packet, length = 16
17:13:52.754567 [debug]  Client - SwitchOp
17:13:52.754655 [debug]  Client - getblock pos = 250000 length = 100000
17:13:52.754689 [debug]  Client - getting from recording
17:13:52.808422 [debug]  Client - written ok 100000
17:13:52.808585 [debug]  Client - Waiting
17:13:52.826884 [debug]  Client - Received packet, length = 16
17:13:52.826922 [debug]  Client - SwitchOp
17:13:52.826948 [debug]  Client - getblock pos = 350000 length = 100000
17:13:52.826976 [debug]  Client - getting from recording
17:13:52.887091 [debug]  Client - written ok 100000
17:13:52.887241 [debug]  Client - Waiting
17:13:52.924894 [debug]  Client - Received packet, length = 16
17:13:52.925057 [debug]  Client - SwitchOp
17:13:52.925099 [debug]  Client - getblock pos = 450000 length = 100000
17:13:52.925130 [debug]  Client - getting from recording
17:13:52.974124 [debug]  Client - written ok 100000
17:13:52.974285 [debug]  Client - Waiting
17:13:52.992513 [debug]  Client - Received packet, length = 16
17:13:52.992552 [debug]  Client - SwitchOp
17:13:52.992579 [debug]  Client - getblock pos = 550000 length = 100000
17:13:52.992606 [debug]  Client - getting from recording
17:13:53.041622 [debug]  Client - written ok 100000
17:13:53.041785 [debug]  Client - Waiting
17:13:53.058913 [debug]  Client - Received packet, length = 16
17:13:53.059066 [debug]  Client - SwitchOp
17:13:53.059094 [debug]  Client - getblock pos = 650000 length = 100000
17:13:53.059123 [debug]  Client - getting from recording
17:13:53.138089 [debug]  Client - written ok 100000
17:13:53.138267 [debug]  Client - Waiting
17:13:53.156309 [debug]  Client - Received packet, length = 16
17:13:53.156464 [debug]  Client - SwitchOp
17:13:53.156495 [debug]  Client - getblock pos = 750000 length = 100000
17:13:53.156524 [debug]  Client - getting from recording
17:13:53.205066 [debug]  Client - written ok 100000
17:13:53.205220 [debug]  Client - Waiting
17:13:53.223009 [debug]  Client - Received packet, length = 16
17:13:53.223050 [debug]  Client - SwitchOp
17:13:53.223077 [debug]  Client - getblock pos = 850000 length = 100000
17:13:53.223104 [debug]  Client - getting from recording
17:13:53.272147 [debug]  Client - written ok 100000
17:13:53.272316 [debug]  Client - Waiting
17:13:53.289224 [debug]  Client - Received packet, length = 16
17:13:53.289338 [debug]  Client - SwitchOp
17:13:53.289366 [debug]  Client - getblock pos = 950000 length = 100000
17:13:53.289395 [debug]  Client - getting from recording
17:13:53.337976 [debug]  Client - written ok 100000
17:13:53.338141 [debug]  Client - Waiting
17:13:53.386408 [debug]  Client - Received packet, length = 16
17:13:53.386572 [debug]  Client - SwitchOp
17:13:53.386603 [debug]  Client - getblock pos = 1050000 length = 100000
17:13:53.386631 [debug]  Client - getting from recording
17:13:53.435874 [debug]  Client - written ok 100000
17:13:53.435991 [debug]  Client - Waiting
17:13:53.453392 [debug]  Client - Received packet, length = 16
17:13:53.453429 [debug]  Client - SwitchOp
17:13:53.453455 [debug]  Client - getblock pos = 1150000 length = 100000
17:13:53.453483 [debug]  Client - getting from recording
17:13:53.503407 [debug]  Client - written ok 100000
17:13:53.503575 [debug]  Client - Waiting
17:13:53.521442 [debug]  Client - Received packet, length = 16
17:13:53.521492 [debug]  Client - SwitchOp
17:13:53.521518 [debug]  Client - getblock pos = 1250000 length = 100000
17:13:53.521546 [debug]  Client - getting from recording
17:13:53.571314 [debug]  Client - written ok 100000
17:13:53.571481 [debug]  Client - Waiting
17:13:53.589943 [debug]  Client - Received packet, length = 16
17:13:53.590116 [debug]  Client - SwitchOp
17:13:53.590150 [debug]  Client - getblock pos = 1350000 length = 100000
17:13:53.590180 [debug]  Client - getting from recording
17:13:53.658570 [debug]  Client - written ok 100000
17:13:53.658738 [debug]  Client - Waiting
17:13:53.675754 [debug]  Client - Received packet, length = 16
17:13:53.675801 [debug]  Client - SwitchOp
17:13:53.675887 [debug]  Client - getblock pos = 1450000 length = 100000
17:13:53.675915 [debug]  Client - getting from recording
17:13:53.725827 [debug]  Client - written ok 100000
17:13:53.726020 [debug]  Client - Waiting
17:13:53.744196 [debug]  Client - Received packet, length = 16
17:13:53.744242 [debug]  Client - SwitchOp
17:13:53.744268 [debug]  Client - getblock pos = 1550000 length = 100000
17:13:53.744296 [debug]  Client - getting from recording
17:13:53.793374 [debug]  Client - written ok 100000
17:13:53.793532 [debug]  Client - Waiting
17:13:53.810680 [debug]  Client - Received packet, length = 16
17:13:53.810835 [debug]  Client - SwitchOp
17:13:53.810898 [debug]  Client - getblock pos = 1650000 length = 100000
17:13:53.810930 [debug]  Client - getting from recording
17:13:53.884698 [debug]  Client - written ok 100000
17:13:53.884904 [debug]  Client - Waiting
17:13:53.903933 [debug]  Client - Received packet, length = 16
17:13:53.904108 [debug]  Client - SwitchOp
17:13:53.904140 [debug]  Client - getblock pos = 1750000 length = 100000
17:13:53.904170 [debug]  Client - getting from recording
17:13:53.953238 [debug]  Client - written ok 100000
17:13:53.953423 [debug]  Client - Waiting
17:13:53.970792 [debug]  Client - Received packet, length = 16
17:13:53.970978 [debug]  Client - SwitchOp
17:13:53.971020 [debug]  Client - getblock pos = 1850000 length = 100000
17:13:53.971050 [debug]  Client - getting from recording
17:13:54.020780 [debug]  Client - written ok 100000
17:13:54.020949 [debug]  Client - Waiting
17:13:54.037603 [debug]  Client - Received packet, length = 16
17:13:54.037673 [debug]  Client - SwitchOp
17:13:54.037700 [debug]  Client - getblock pos = 1950000 length = 100000
17:13:54.037728 [debug]  Client - getting from recording
17:13:54.116743 [debug]  Client - written ok 100000
17:13:54.116917 [debug]  Client - Waiting
17:13:54.134074 [debug]  Client - Received packet, length = 16
17:13:54.134114 [debug]  Client - SwitchOp
17:13:54.134140 [debug]  Client - getblock pos = 2050000 length = 100000
17:13:54.134167 [debug]  Client - getting from recording
17:13:54.184352 [debug]  Client - written ok 100000
17:13:54.184516 [debug]  Client - Waiting
17:13:54.200674 [debug]  Client - Received packet, length = 16
17:13:54.200767 [debug]  Client - SwitchOp
17:13:54.200795 [debug]  Client - getblock pos = 2150000 length = 100000
17:13:54.200947 [debug]  Client - getting from recording
17:13:54.249117 [debug]  Client - written ok 100000
17:13:54.249267 [debug]  Client - Waiting
17:15:27.253955 [debug]  TCP - TCP has closed socket
17:15:27.254148 [debug]  TCP - TCP has closed socket
17:15:27.254176 [debug]  Client - Received packet, length = 16
17:15:27.254201 [debug]  Client - Detected connection closed
17:15:27.254226 [debug]  Client - MVP client destructor
17:15:27.254698 [debug]  RecPlayer - destructor
17:15:27.255020 [debug]  Client - Clean config
17:15:27.269516 [debug]  Config - 2
17:15:27.269604 [debug]  Client - EXAMINING: 0 1 0x82736f8 /video0/Kulturzeit_extra/2008-03-17.01.25.99.99.rec
17:15:27.269658 [debug]  Client - This recording still exists


I hope this helps.

BTW: I would like to try the latest CVS version. Could anybody provide a corresponding dongle binary? So that I wouldn't have to setup the cross-compile environment? ;)
Title: Re: Once again: D3A and no video...
Post by: neeesat on June 17, 2008, 06:28:05
Just to mention that I have 2 D3A's and I got the same problem with Black screen on both.

Both are working ok with mvpmc and custom software so it is not a hardware problem.
Title: Re: Once again: D3A and no video...
Post by: laz on August 09, 2008, 13:44:02
I've just discovered this thread...

I've had a D3A that I have been using routinely with no problems for a year or so (maybe longer?). I have now just been given another D3A (labelled exactly the same as the other one) which I was going to pass on to my brother for use with vomp.

Now that I've tried to test the "newer" one, it boots fine and I get the menus which work fine (the screen dims when I move the cursor up and down on the options menu - not noticed that before the other one does it too now I look!). However, I only get audio on playback or live TV. OSD graphics are still there, though.

I haven't changed any settings and I'm swapping one device directly for the other. I was thinking it was a dud but having read this thread...

I tried rebooting it a few times and one time I got a screen full of red, purple, and black stripes instead of a black screen on playback (menus, etc. still working fine). Next reboot was back to a black screen for video playback!

All of this is with vomp 0.3.0. I'm just about to boot into windross to test the proper software...if I can get that to work with anything else I've got!

------------------------------

A bit ore testing with vompclient debug mode after reading other threads.

Playing back any recording on the "dodgy" one gives me audio for about 5 s and then silence. During the 5 s of sound, I see lots of Demuxer - +* PTS JUMP *+ 3716485174 48 and  Demuxer - DELETED REFERENCES in vompclient debug output.

After the sound has disappeared, I get lots of alternating:
VDR - Sending KA packet
VDR - Rxd correct KA reply

messages and the odd block of Timers and BoxStack messages.

I can exit "playback" by pressingthe back button, i.e. it hasn't locked up or anything.

Just tried a radio channel and that played back (audio only!) for several minutes without problems.

--------------------------------------------------------

More interesting stuff: the above was running vompclient -d

If I playback a recording WITH debug sound stops after about 5 s and the time readout on the OSD never changes from -:--:--

If I playback a recording WITHOUT debug, i.e. straight after booting it, the sounds plays for much longer (10 minutes and counting...) and the OSD time updates almost instantly and counts up as expected.

Not sure whether this is due to heaver load when running with debug or something like that but seems a bit weird!

Another thing I've just noticed...the OSD on the dodgy one is stretched vertically, compared with my other, working one! The Welcome menu is about 14.5 cm high on the dodgy one but only 12 cm high on the working one. I see the same expansion with the recordings menu and also the first Hauppauge boot screen! The vomp-MAC_ADDR.conf files on the vdr server are identical (one file copied over the other).

I'm starting to wonder whether these things are actually as identical as the labelling suggests...the outputs of dmesg are identical for the two boxes (apart from IP address and MAX address bits).
Title: Re: Once again: D3A and no video...
Post by: muellerph on August 09, 2008, 15:56:24
Quote from: laz on August 09, 2008, 13:44:02
Another thing I've just noticed...the OSD on the dodgy one is stretched vertically, compared with my other, working one! The Welcome menu is about 14.5 cm high on the dodgy one but only 12 cm high on the working one. I see the same expansion with the recordings menu and also the first Hauppauge boot screen! The vomp-MAC_ADDR.conf files on the vdr server are identical (one file copied over the other).

I'm starting to wonder whether these things are actually as identical as the labelling suggests...the outputs of dmesg are identical for the two boxes (apart from IP address and MAX address bits).
This sounds a bit like the topic:http://www.loggytronic.com/forum/index.php?topic=210.0 (http://www.loggytronic.com/forum/index.php?topic=210.0)
Title: Re: Once again: D3A and no video...
Post by: Chris on August 10, 2008, 18:33:58
Hi laz, thanks for posting.... All I can say is .. Interesting !!

Can you post a full log from the time you press play in the recordings list until it is just printing the alternating KA messages please.

Does it print lots of demuxer pts jump messages every time you try this? I would like to see a log with these messages.

Chris
Title: Re: Once again: D3A and no video...
Post by: laz on August 13, 2008, 20:45:02
I won't have a chance to do any more testing until the weekend but I will post as much as I can then (well, links to logs, etc.!).

Anything else that you can think I should try? I had my suspicions that they were subtly different internally (chip revisions, etc.?) but nothing different from dmesg on the two boxes. Will take both apart and compare chip numbers!

;)
Title: Re: Once again: D3A and no video...
Post by: laz on August 16, 2008, 13:21:10
Right...I've just created a couple of log files form the output of vompclient in debug mode:

From the working D3A (currently watching stuff with it as I type this!):
http://www.club-burniston.co.uk/vdr/d3a_debug_working.log

From the non-working D3A (SCART, network, and mains swapped from the working one):
http://www.club-burniston.co.uk/vdr/d3a_debug_novideo.log

I tried to do pretty much the same keypresses on each. I've also added a few comments in the files where I pressed play, stop, etc.

All of this is with vomp 0.3.0, although I have a build environment set up so I am happy to test vompclient patches if you can come up with anything form my logs!

:)
Title: Re: Once again: D3A and no video...
Post by: Chris on August 17, 2008, 18:29:12
laz, thanks for the log files. Mark has spotted the problem! (We really, really really hope)...

The non-working D3A is reading from the MVP that it is a NTSC model. I just forced mine to NTSC and got audio, and no video.

So, assuming you really are in the UK, add this line to your MVP config file in the [General] section:


Override Video Format = PAL


Report back what happens...!
Title: Re: Once again: D3A and no video...
Post by: carsten on August 17, 2008, 18:51:02
I'm also curious...thought I was stupid when I didn't got it to work...BR Carsten.
Title: Re: Once again: D3A and no video...
Post by: laz on August 18, 2008, 11:08:10
Aha! Sounds extremely plausible, especially with the expanded OSD I'm seeing...

I am in the UK and my working D3A was bought here. The (currently,,,) non-working one could have been bought anywhere in the world.

I will try forcing PAL later on this evening...

---------------------------------------------------------------------------

Yep! Jobs a good'un!

Works fine with that added to the vomp-{MAC}.conf file. Nice to see the feature included!

:)

Keep up the good work!