QNAP TS-459 Pro+ installation issues

[moleculezz]

Hi,

I was able to get serviio running on my QNAP TS-459 Pro+ NAS, and I setup a console on a windows 7 laptop to manage it. This all worked, but I am having issues with the library. It is not recognizing anything that I have in the library. I have a bunch of movies and tv shows and none of them are visible.

I did the following when installing serviio:

1. Installed JRE QPKG
2. install lame, yasm & optware

  Code:

ipkg install lame
ipkg install yasm
ipkg install optware-devel

3. Downloaded serviio & ffmpeg from serviio.org
4. Extracted ffmpeg into /share/MD0_DATA/.qpkg/ffmpeg/
5. Modified ffmpeg configure

  Code:

if ! check_cmd type mktemp; then

to

  Code:

if true; then

6. Installed ffmpeg

  Code:

./configure --arch=x86_64 --enable-ssse3 --prefix=/opt --extra-cflags='-I/opt/include' --extra-ldflags='-L/opt/lib' --enable-static --disable-shared --disable-ffplay --disable-ffserver --enable-libmp3lame
make
make install

7. Extracted serviio into /share/MD0_DATA/.qpkg/serviio/
8. Added to JAVA_OPTS

-Dserviio.remoteHost=<nas ip> -Dffmpeg.location=/share/MD0_DATA/.qpkg/ffmpeg/ffmpeg

9. run serviio

  Code:

/share/MD0_DATA/.qpkg/serviio/bin/serviio.sh start &

10. Add path's to library

  Code:

/share/MD0_DATA/Multimedia/video/tv
/share/MD0_DATA/Multimedia/video/movies

After this I browsed using my Samsung TV & XBMC on a laptop, but nothing under those 2 path's are visible.
Can't seem to figure out what the issue is.

UPDATE: after removing -Dffmpeg.location=/share/MD0_DATA/.qpkg/ffmpeg/ffmpeg from JAVA_OPTS string. It started to pick up some movies. I tried playing it (1080p/mkv) and I get error msg "not supported file format" on my Samsung TV. I did set the correct profile for the TV.

[zip]

post the log

[moleculezz]

Ok, so I had PuTTY running when I wen't to play a movie to get some log, and immediately when I try to watch a movie, the command line gave the following output.

  Code:

[/share/MD0_DATA/.qpkg/serviio/log] # *** glibc detected *** ffmpeg: double free or corruption (!prev): 0x08333808 ***
======= Backtrace: =========
/lib/libc.so.6[0xb6d770f7]
/lib/libc.so.6(cfree+0x89)[0xb6d78de9]
/usr/lib/libavformat.so.52(av_destruct_packet+0x13)[0xb7648923]
[0x0]
======= Memory map: ========
08048000-0805b000 r-xp 00000000 09:0d 27337      /mnt/ext/opt/ffmpeg/usr/bin/ffmpeg
0805b000-0805c000 rwxp 00012000 09:0d 27337      /mnt/ext/opt/ffmpeg/usr/bin/ffmpeg
0805c000-08772000 rwxp 00000000 00:00 0          [heap]
b6000000-b6021000 rwxp 00000000 00:00 0
b6021000-b6100000 ---p 00000000 00:00 0
b613c000-b6146000 r-xp 00000000 01:00 20535      /lib/libgcc_s.so.1
b6146000-b6147000 rwxp 0000a000 01:00 20535      /lib/libgcc_s.so.1
b614d000-b6ce7000 rwxp 00000000 00:00 0
b6ce7000-b6ce9000 r-xp 00000000 01:00 20573      /lib/libdl-2.6.1.so
b6ce9000-b6ceb000 rwxp 00001000 01:00 20573      /lib/libdl-2.6.1.so
b6ceb000-b6cec000 rwxp 00000000 00:00 0
b6cec000-b6cfb000 r-xp 00000000 01:00 8856       /usr/lib/libbz2.so.1.0.4
b6cfb000-b6cfc000 rwxp 0000f000 01:00 8856       /usr/lib/libbz2.so.1.0.4
b6cfc000-b6d10000 r-xp 00000000 01:00 20533      /lib/libz.so.1.2.3.3
b6d10000-b6d11000 rwxp 00013000 01:00 20533      /lib/libz.so.1.2.3.3
b6d11000-b6e3f000 r-xp 00000000 01:00 20592      /lib/libc-2.6.1.so
b6e3f000-b6e40000 r-xp 0012d000 01:00 20592      /lib/libc-2.6.1.so
b6e40000-b6e42000 rwxp 0012e000 01:00 20592      /lib/libc-2.6.1.so
b6e42000-b6e45000 rwxp 00000000 00:00 0
b6e45000-b6e68000 r-xp 00000000 01:00 20559      /lib/libm-2.6.1.so
b6e68000-b6e6a000 rwxp 00022000 01:00 20559      /lib/libm-2.6.1.so
b6e6a000-b6e77000 r-xp 00000000 09:0d 27346      /mnt/ext/opt/ffmpeg/usr/lib/libavutil.so.49
b6e77000-b6e78000 rwxp 0000d000 09:0d 27346      /mnt/ext/opt/ffmpeg/usr/lib/libavutil.so.49
b6e78000-b6e7b000 rwxp 00000000 00:00 0
b6e7b000-b7318000 r-xp 00000000 09:0d 27340      /mnt/ext/opt/ffmpeg/usr/lib/libavcodec.so.52
b7318000-b7322000 rwxp 0049c000 09:0d 27340      /mnt/ext/opt/ffmpeg/usr/lib/libavcodec.so.52
b7322000-b762f000 rwxp 00000000 00:00 0
b762f000-b76d3000 r-xp 00000000 09:0d 27344      /mnt/ext/opt/ffmpeg/usr/lib/libavformat.so.52
b76d3000-b76d9000 rwxp 000a3000 09:0d 27344      /mnt/ext/opt/ffmpeg/usr/lib/libavformat.so.52
b76d9000-b7725000 rwxp 00000000 00:00 0
b7725000-b772b000 r-xp 00000000 09:0d 27342      /mnt/ext/opt/ffmpeg/usr/lib/libavdevice.so.52
b772b000-b772c000 rwxp 00005000 09:0d 27342      /mnt/ext/opt/ffmpeg/usr/lib/libavdevice.so.52
b7732000-b7734000 rwxp 00000000 00:00 0
b7734000-b7735000 r-xp 00000000 00:00 0          [vdso]
b7735000-b774f000 r-xp 00000000 01:00 20590      /lib/ld-2.6.1.so
b774f000-b7751000 rwxp 00019000 01:00 20590      /lib/ld-2.6.1.so
bfb7f000-bfb9c000 rw-p 00000000 00:00 0          [stack]

Here is also the log from serviio:

  Code:

2011-04-24 18:37:17,661 INFO  [MediaServer] ------------------------------------------------------------------------
2011-04-24 18:37:17,662 INFO  [MediaServer] Serviio DLNA media streaming server v 0.5.2 (rev. 4e3210bd9ff3)
2011-04-24 18:37:17,662 INFO  [MediaServer] Petr Nejedly 2009-2011
2011-04-24 18:37:17,663 INFO  [MediaServer] http://www.serviio.org
2011-04-24 18:37:17,663 INFO  [MediaServer]
2011-04-24 18:37:17,663 INFO  [MediaServer] Java 1.6.0_22-Sun Microsystems Inc.
2011-04-24 18:37:17,663 INFO  [MediaServer] OS Linux i386 2.6.33.2
2011-04-24 18:37:17,663 INFO  [MediaServer] File encoding: UTF-8
2011-04-24 18:37:17,663 INFO  [MediaServer] ------------------------------------------------------------------------
2011-04-24 18:37:17,936 INFO  [RestletServer] Starting Restlet server exposed on 192.168.1.150:23423
2011-04-24 18:37:18,061 INFO  [DBSchemaUpdateExecutor] Checking if DB schema needs to be updated
2011-04-24 18:37:20,921 INFO  [ProfilesDefinitionParser] Parsing Profiles definition
2011-04-24 18:37:21,621 INFO  [ProfilesDefinitionParser] Added profile 'Generic DLNA profile' (id=1)
2011-04-24 18:37:21,946 INFO  [ProfilesDefinitionParser] Added profile 'Samsung TV (B-series)' (id=2)
2011-04-24 18:37:22,128 INFO  [ProfilesDefinitionParser] Added profile 'XBox 360' (id=3)
2011-04-24 18:37:22,262 INFO  [ProfilesDefinitionParser] Added profile 'Playstation 3' (id=4)
2011-04-24 18:37:22,450 INFO  [ProfilesDefinitionParser] Added profile 'Samsung TV (A-series)' (id=5)
2011-04-24 18:37:22,562 INFO  [ProfilesDefinitionParser] Added profile 'DirecTV HD-DVR' (id=6)
2011-04-24 18:37:22,843 INFO  [ProfilesDefinitionParser] Added profile 'Samsung TV / player (C/D-series)' (id=7)
2011-04-24 18:37:22,914 INFO  [ProfilesDefinitionParser] Added profile 'LG BD player' (id=8)
2011-04-24 18:37:23,341 INFO  [ProfilesDefinitionParser] Added profile 'Sony Bravia TV' (id=9)
2011-04-24 18:37:24,066 INFO  [ProfilesDefinitionParser] Added profile 'Sony BD Player' (id=10)
2011-04-24 18:37:24,264 INFO  [ProfilesDefinitionParser] Added profile 'Panasonic Viera' (id=12)
2011-04-24 18:37:24,404 INFO  [ProfilesDefinitionParser] Added profile 'Toshiba Rezga' (id=13)
2011-04-24 18:37:24,455 INFO  [AbstractTranscodingDeliveryEngine] Cleaning transcode engine and its data
2011-04-24 18:37:24,521 INFO  [WebServer] Socket buffer set to 65535 bytes
2011-04-24 18:37:24,588 INFO  [WebServer] WebServer starting on port 8895
2011-04-24 18:37:24,611 INFO  [Device] Created UPnP Device with UUID: fdd7897d-5776-36c3-8389-fec009d37a24, bound address: 192.168.1.150
2011-04-24 18:37:24,664 INFO  [CompositeCacheManager] Creating cache manager from config file: /cache.ccf
2011-04-24 18:37:24,678 INFO  [ThreadPoolManager] thread_pool.default PoolConfiguration = useBoundary = [true] boundarySize = [2000] maximumPoolSize = [150] minimumPoolSize = [4] keepAliveTime = [300000] whenBlockedPolicy = [RUN] startUpSize = [4]
2011-04-24 18:37:24,686 INFO  [CompositeCacheConfigurator] Setting default auxiliaries to null
2011-04-24 18:37:24,686 INFO  [CompositeCacheConfigurator] No special CompositeCacheAttributes class defined for key [jcs.default.cacheattributes], using default class.
2011-04-24 18:37:24,690 INFO  [CompositeCacheConfigurator] setting defaultCompositeCacheAttributes to [ useLateral = true, useRemote = true, useDisk = true, maxObjs = 100, maxSpoolPerRun = -1, diskUsagePattern = 0 ]
2011-04-24 18:37:24,691 INFO  [CompositeCacheConfigurator] No special ElementAttribute class defined for key [jcs.default.elementattributes], using default class.
2011-04-24 18:37:24,691 INFO  [CompositeCacheConfigurator] setting defaultElementAttributes to [ IS_LATERAL = true, IS_SPOOL = true, IS_REMOTE = true, IS_ETERNAL = true, MaxLifeSeconds = -1, IdleTime = -1, CreateTime = 1303670244691, LastAccessTime = 1303670244691, getTimeToLiveSeconds() = -1, createTime = 1303670244691 ]
2011-04-24 18:37:24,696 INFO  [CompositeCacheConfigurator] No special ElementAttribute class defined for key [jcs.region.local_resetafterplay.elementattributes], using default class.
2011-04-24 18:37:24,732 INFO  [LRUMemoryCache] initialized LRUMemoryCache for local_resetafterplay
2011-04-24 18:37:24,732 INFO  [CompositeCache] Constructed cache with name [local_resetafterplay] and cache attributes [ useLateral = true, useRemote = true, useDisk = true, maxObjs = 1000, maxSpoolPerRun = -1, diskUsagePattern = 0 ]
2011-04-24 18:37:24,733 INFO  [CompositeCacheConfigurator] No special ElementAttribute class defined for key [jcs.region.local_default.elementattributes], using default class.
2011-04-24 18:37:24,733 INFO  [LRUMemoryCache] initialized LRUMemoryCache for local_default
2011-04-24 18:37:24,733 INFO  [CompositeCache] Constructed cache with name [local_default] and cache attributes [ useLateral = true, useRemote = true, useDisk = true, maxObjs = 1000, maxSpoolPerRun = -1, diskUsagePattern = 0 ]
2011-04-24 18:37:24,734 INFO  [CompositeCacheConfigurator] Parsed regions [local_resetafterplay, local_default]
2011-04-24 18:37:24,734 INFO  [CompositeCacheConfigurator] Finished configuration in 51 ms.
2011-04-24 18:37:24,740 INFO  [EventDispatcher] Starting EventDispatcher
2011-04-24 18:37:24,740 INFO  [EventSubscriptionExpirationChecker] Starting EventSubscriptionExpirationChecker
2011-04-24 18:37:24,741 INFO  [DiscoveryAdvertisementNotifier] Starting DiscoveryAdvertisementNotifier
2011-04-24 18:37:24,743 INFO  [DiscoverySSDPMessageListener] Starting DiscoverySSDPMessageListener using interface eth0 (eth0) and address 192.168.2.150, timeout = 0
2011-04-24 18:37:24,752 INFO  [RendererSearchSender] Searching for Renderer devices
2011-04-24 18:37:24,753 INFO  [RendererExpirationChecker] Starting RendererExpirationChecker
2011-04-24 18:37:50,333 INFO  [ContentDirectoryDefinitionParser] Parsing ContentDirectory definition
2011-04-24 18:37:50,819 INFO  [LibraryAdditionsCheckerThread] Started looking for newly added files
2011-04-24 18:37:50,847 INFO  [LibraryUpdatesCheckerThread] Started looking for updates to currently shared files
2011-04-24 18:37:51,188 INFO  [BrowsingCategoriesMessages] Loaded browsing categories message bundle for locale: en
2011-04-24 18:37:59,089 WARN  [ProcessExecutor] Process ffmpeg has a return code of 134! This is a possible error.
2011-04-24 18:37:59,516 ERROR [ResourceTransportRequestHandler] Error while processing resource, sending back 500 error. Message: FFmpeg execution failed
java.io.IOException: FFmpeg execution failed
   at org.serviio.delivery.resource.AbstractTranscodingDeliveryEngine.retrieveTranscodedResource(AbstractTranscodingDeliveryEngine.java:116)
   at org.serviio.delivery.resource.AbstractDeliveryEngine.deliver(AbstractDeliveryEngine.java:89)
   at org.serviio.delivery.MediaResourceRetrievalStrategy.retrieveResource(MediaResourceRetrievalStrategy.java:116)
   at org.serviio.upnp.webserver.ResourceTransportRequestHandler.handleRequest(ResourceTransportRequestHandler.java:115)
   at org.serviio.upnp.webserver.AbstractRequestHandler.handle(AbstractRequestHandler.java:54)
   at org.apache.http.protocol.HttpService.doService(HttpService.java:293)
   at org.serviio.upnp.webserver.ServiioHttpService.doService(ServiioHttpService.java:58)
   at org.apache.http.protocol.HttpService.handleRequest(HttpService.java:212)
   at org.serviio.upnp.webserver.WebServer$WorkerThread.run(WebServer.java:187)


[zip]

This is the problem:

  Code:

2011-04-24 18:37:59,089 WARN  [ProcessExecutor] Process ffmpeg has a return code of 134! This is a possible error.
2011-04-24 18:37:59,516 ERROR [ResourceTransportRequestHandler] Error while processing resource, sending back 500 error. Message: FFmpeg execution failed

Not sure what the error code means but basically FFmpeg cannot be executed. You could try enabling detailed log to get some more info. Is FFmpeg executable? Does the user running Serviio have access to execute it?

[moleculezz]

Not sure what the error code means but basically FFmpeg cannot be executed. You could try enabling detailed log to get some more info. Is FFmpeg executable? Does the user running Serviio have access to execute it?

How can I enable detailed log?

It seems that serviio is owned by admin. So I would think that it has rights to execute ffmpeg. I checked ls -l and it shows some ffmpeg files are owned by 1000 and some by admin. The main ffmpeg file is owned by admin and is rwxr-xr-x.

[zip]

For detailed log check link in my signature

[moleculezz]

Here is a detailed log
http://pastebin.com/WZDbd4GY

[zip]

try to execute this:

  Code:

ffmpeg -i "/share/MD0_DATA/Multimedia/video/movies/Unthinkable Extended MULTi 1080p BluRay x264 LOST/unthinkable.extended.multi.1080p.bluray.x264.mkv" -y -vcodec copy -vbsf h264_mp4toannexb -copyts -acodec ac3 -ab 192k -ac 2 -map 0:0 -map 0:1 -sn -f mpegts /tmp/Serviio/transcoding-temp-2-MPEG2TS.stf

[moleculezz]

Can it be that it is using a different version of ffmpeg that was already installed?
I did the following and it seems that there is more than 1 ffmpeg installed?

  Code:

[/] # find -name ffmpeg
./mnt/ext/opt/ffmpeg
./mnt/ext/opt/ffmpeg/usr/bin/ffmpeg
./share/MD0_DATA/.qpkg/Optware/share/ffmpeg
./share/MD0_DATA/.qpkg/Optware/bin/ffmpeg
./share/MD0_DATA/.qpkg/ffmpeg
./share/MD0_DATA/.qpkg/ffmpeg/ffmpeg
./usr/bin/ffmpeg


Output of what you requested:

  Code:

[/] # ffmpeg -i "/share/MD0_DATA/Multimedia/video/movies/Unthinkable Extended MU                                                                                        LTi 1080p BluRay x264 LOST/unthinkable.extended.multi.1080p.bluray.x264.mkv" -y                                                                                         -vcodec copy -vbsf h264_mp4toannexb -copyts -acodec ac3 -ab 192k -ac 2 -map 0:0                                                                                         -map 0:1 -sn -f mpegts /tmp/Serviio/transcoding-temp-2-MPEG2TS.stf
FFmpeg version 0.5, Copyright (c) 2000-2009 Fabrice Bellard, et al.
  configuration: --prefix=/opt/cross-project/x86/sys-root/usr --disable-static -                                                                                        -enable-shared
  libavutil     49.15. 0 / 49.15. 0
  libavcodec    52.20. 0 / 52.20. 0
  libavformat   52.31. 0 / 52.31. 0
  libavdevice   52. 1. 0 / 52. 1. 0
  built on Mar 30 2011 19:18:28, gcc: 4.1.3 20070929 (prerelease) (Ubuntu 4.1.2-                                                                                        16ubuntu2)
[matroska @ 0x8062290]Invalid stream 4 or size 3
[matroska @ 0x8062290]Invalid stream 5 or size 3

Seems stream 0 codec frame rate differs from container frame rate: 47.95 (27956/                                                                                        583) -> 23.98 (24000/1001)
Input #0, matroska, from '/share/MD0_DATA/Multimedia/video/movies/Unthinkable Ex                                                                                        tended MULTi 1080p BluRay x264 LOST/unthinkable.extended.multi.1080p.bluray.x264                                                                                        .mkv':
  Duration: 01:37:31.60, start: 0.000000, bitrate: N/A
    Stream #0.0(eng): Video: h264, yuv420p, 1920x1040, PAR 1:1 DAR 24:13, 23.98                                                                                         tbr, 1k tbn, 47.95 tbc
    Stream #0.1(fre): Audio: dca, 48000 Hz, 5.1, s16
    Stream #0.2(eng): Audio: dca, 48000 Hz, 5.1, s16
    Stream #0.3(fre): Subtitle: 0x0000
    Stream #0.4(fre): Subtitle: 0x0000
Output #0, mpegts, to '/tmp/Serviio/transcoding-temp-2-MPEG2TS.stf':
    Stream #0.0(eng): Video: 0x0000, yuv420p, 1920x1040 [PAR 1:1 DAR 24:13], q=2                                                                                        -31, 90k tbn, 23.98 tbc
    Stream #0.1(fre): Audio: ac3, 48000 Hz, stereo, s16, 192 kb/s
Stream mapping:
  Stream #0.0 -> #0.0
  Stream #0.1 -> #0.1
Press [q] to stop encoding
[mpegts @ 0x866c080]h264 bitstream malformated
*** glibc detected *** ffmpeg: double free or corruption (!prev): 0x08333808 ***
======= Backtrace: =========
/lib/libc.so.6[0xb6dcf0f7]
/lib/libc.so.6(cfree+0x89)[0xb6dd0de9]
/usr/lib/libavformat.so.52(av_destruct_packet+0x13)[0xb76a0923]
[0x0]
======= Memory map: ========
08048000-0805b000 r-xp 00000000 09:0d 27337      /mnt/ext/opt/ffmpeg/usr/bin/ffm                                                                                        peg
0805b000-0805c000 rw-p 00012000 09:0d 27337      /mnt/ext/opt/ffmpeg/usr/bin/ffm                                                                                        peg
0805c000-08772000 rw-p 00000000 00:00 0          [heap]
b6000000-b6021000 rw-p 00000000 00:00 0
b6021000-b6100000 ---p 00000000 00:00 0
b6194000-b619e000 r-xp 00000000 01:00 20535      /lib/libgcc_s.so.1
b619e000-b619f000 rw-p 0000a000 01:00 20535      /lib/libgcc_s.so.1
b61a5000-b6d3f000 rw-p 00000000 00:00 0
b6d3f000-b6d41000 r-xp 00000000 01:00 20573      /lib/libdl-2.6.1.so
b6d41000-b6d43000 rw-p 00001000 01:00 20573      /lib/libdl-2.6.1.so
b6d43000-b6d44000 rw-p 00000000 00:00 0
b6d44000-b6d53000 r-xp 00000000 01:00 8856       /usr/lib/libbz2.so.1.0.4
b6d53000-b6d54000 rw-p 0000f000 01:00 8856       /usr/lib/libbz2.so.1.0.4
b6d54000-b6d68000 r-xp 00000000 01:00 20533      /lib/libz.so.1.2.3.3
b6d68000-b6d69000 rw-p 00013000 01:00 20533      /lib/libz.so.1.2.3.3
b6d69000-b6e97000 r-xp 00000000 01:00 20592      /lib/libc-2.6.1.so
b6e97000-b6e98000 r--p 0012d000 01:00 20592      /lib/libc-2.6.1.so
b6e98000-b6e9a000 rw-p 0012e000 01:00 20592      /lib/libc-2.6.1.so
b6e9a000-b6e9d000 rw-p 00000000 00:00 0
b6e9d000-b6ec0000 r-xp 00000000 01:00 20559      /lib/libm-2.6.1.so
b6ec0000-b6ec2000 rw-p 00022000 01:00 20559      /lib/libm-2.6.1.so
b6ec2000-b6ecf000 r-xp 00000000 09:0d 27346      /mnt/ext/opt/ffmpeg/usr/lib/lib                                                                                        avutil.so.49
b6ecf000-b6ed0000 rw-p 0000d000 09:0d 27346      /mnt/ext/opt/ffmpeg/usr/lib/lib                                                                                        avutil.so.49
b6ed0000-b6ed3000 rw-p 00000000 00:00 0
b6ed3000-b7370000 r-xp 00000000 09:0d 27340      /mnt/ext/opt/ffmpeg/usr/lib/lib                                                                                        avcodec.so.52
b7370000-b737a000 rw-p 0049c000 09:0d 27340      /mnt/ext/opt/ffmpeg/usr/lib/lib                                                                                        avcodec.so.52
b737a000-b7687000 rw-p 00000000 00:00 0
b7687000-b772b000 r-xp 00000000 09:0d 27344      /mnt/ext/opt/ffmpeg/usr/lib/lib                                                                                        avformat.so.52
b772b000-b7731000 rw-p 000a3000 09:0d 27344      /mnt/ext/opt/ffmpeg/usr/lib/lib                                                                                        avformat.so.52
b7731000-b777d000 rw-p 00000000 00:00 0
b777d000-b7783000 r-xp 00000000 09:0d 27342      /mnt/ext/opt/ffmpeg/usr/lib/lib                                                                                        avdevice.so.52
b7783000-b7784000 rw-p 00005000 09:0d 27342      /mnt/ext/opt/ffmpeg/usr/lib/lib                                                                                        avdevice.so.52
b778a000-b778c000 rw-p 00000000 00:00 0
b778c000-b778d000 r-xp 00000000 00:00 0          [vdso]
b778d000-b77a7000 r-xp 00000000 01:00 20590      /lib/ld-2.6.1.so
b77a7000-b77a9000 rw-p 00019000 01:00 20590      /lib/ld-2.6.1.so
bfe51000-bfe6e000 rw-p 00000000 00:00 0          [stack]
Aborted


[zip]

It crashes. FFmpeg is either not correctly installed or compiled.

[moleculezz]

Ok.. I figured out that it was still using the default ffmpeg which comes preinstalled on the NAS. When I ran the one that I compiled I get the following error:

  Code:

# /opt/ffmpeg/ffmpeg
/opt/ffmpeg/ffmpeg: error while loading shared libraries: libmp3lame.so.0: cannot open shared object file: No such file or directory


I recompiled it without --enable-libmp3lame and it worked.
Then I searched for libmp3.so.o and I get the following:

  Code:

[/] # find -name libmp3lame.so.0
./share/MD0_DATA/.qpkg/Optware/lib/libmp3lame.so.0


How can I get it to find lame?

[moleculezz]

I fixed that issue by creating a symlink in /usr/lib. Now I can run the compiled version of ffmpeg, but I am still getting issues with ffmpeg.

  Code:

# /share/MD0_DATA/.qpkg/Optware/ffmpeg/ffmpeg -i "/share/MD0_DATA/Multimedia/video/movies/LF.720p.BluRay.x264.TWiZTED/twiz-lf720p.mkv"
FFmpeg version 0.6.3, Copyright (c) 2000-2010 the FFmpeg developers
  built on Apr 29 2011 12:55:30 with gcc 4.2.1
  configuration: --arch=x86_64 --enable-ssse3 --prefix=/opt --extra-cflags=-I/opt/include --extra-ldflags=-L/opt/lib --enable-static --disable-shared --disable-ffplay --disable-ffserver --enable-libmp3lame
  libavutil     50.15. 1 / 50.15. 1
  libavcodec    52.72. 2 / 52.72. 2
  libavformat   52.64. 2 / 52.64. 2
  libavdevice   52. 2. 0 / 52. 2. 0
  libswscale     0.11. 0 /  0.11. 0
[matroska @ 0x8ad2420]Estimating duration from bitrate, this may be inaccurate

Seems stream 0 codec frame rate differs from container frame rate: 47.95 (5000000/104271) -> 24.00 (24/1)
Input #0, matroska, from '/share/MD0_DATA/Multimedia/video/movies/LF.720p.BluRay.x264/twiz-lf720p.mkv':
  Metadata:
    doctype         : matroska
  Duration: 01:37:40.85, start: 0.000000, bitrate: N/A
    Stream #0.0(eng): Video: h264, yuv420p, 1280x696 [PAR 1:1 DAR 160:87], 23.98 fps, 24 tbr, 1k tbn, 47.95 tbc
    Stream #0.1(eng): Audio: dca, 48000 Hz, 6 channels, s16
    Metadata:
      title           : English DTS
At least one output file must be specified


Error log:

  Code:

2011-04-29 19:01:56,331 DEBUG [ResourceTransportRequestHandler] HTTP/1.1 200 OK, headers = [[Content-Type: video/mpeg,TimeSeekRange.dlna.org: npt=0.0-5860.0/5860,Content-Length: 9000000000,Date: Fri, 29 Apr 2011 19:01:56 GMT,Server: Linux, UPnP/1.0 DLNADOC/1.50, Serviio/0.5.2,Cache-control: no-cache,contentFeatures.dlna.org: DLNA.ORG_PN=AVC_TS_MP_HD_AC3_ISO;DLNA.ORG_OP=10;DLNA.ORG_CI=1;DLNA.ORG_FLAGS=01500000000000000000000000000000,transferMode.dlna.org: Streaming,MediaInfo.sec: SEC_Duration=5860000;]]
2011-04-29 19:01:57,918 DEBUG [DiscoverySSDPMessageListener] Received a valid M-SEARCH message for search target urn:schemas-upnp-org:device:InternetGatewayDevice:1 from address /192.168.2.101:53820
2011-04-29 19:01:59,834 WARN  [ProcessExecutor] Process /share/MD0_DATA/.qpkg/ffmpeg/ffmpeg has a return code of 1! This is a possible error.
2011-04-29 19:01:59,835 DEBUG [TranscodingJobListener] Transcoding finished; successful: false
2011-04-29 19:02:00,952 DEBUG [DiscoverySSDPMessageListener] Received a valid M-SEARCH message for search target urn:schemas-upnp-org:device:InternetGatewayDevice:1 from address /192.168.2.101:53820
2011-04-29 19:02:03,919 DEBUG [DiscoverySSDPMessageListener] Received a valid M-SEARCH message for search target urn:schemas-upnp-org:device:InternetGatewayDevice:1 from address /192.168.2.101:53820
2011-04-29 19:02:25,117 DEBUG [WebServer] I/O error: Connection reset
2011-04-29 19:02:47,894 DEBUG [DiscoverySSDPMessageListener] Received a valid M-SEARCH message for search target urn:schemas-upnp-org:device:InternetGatewayDevice:1 from address /192.168.2.101:53820
2011-04-29 19:02:50,896 DEBUG [DiscoverySSDPMessageListener] Received a valid M-SEARCH message for search target urn:schemas-upnp-org:device:InternetGatewayDevice:1 from address /192.168.2.101:53820
2011-04-29 19:02:53,895 DEBUG [DiscoverySSDPMessageListener] Received a valid M-SEARCH message for search target urn:schemas-upnp-org:device:InternetGatewayDevice:1 from address /192.168.2.101:53820
2011-04-29 19:02:56,926 DEBUG [DiscoverySSDPMessageListener] Received a valid M-SEARCH message for search target urn:schemas-upnp-org:device:InternetGatewayDevice:1 from address /192.168.2.101:53820
2011-04-29 19:02:59,927 DEBUG [DiscoverySSDPMessageListener] Received a valid M-SEARCH message for search target urn:schemas-upnp-org:device:InternetGatewayDevice:1 from address /192.168.2.101:53820
2011-04-29 19:03:02,926 DEBUG [DiscoverySSDPMessageListener] Received a valid M-SEARCH message for search target urn:schemas-upnp-org:device:InternetGatewayDevice:1 from address /192.168.2.101:53820
2011-04-29 19:03:03,774 DEBUG [WebServer] Incoming connection from /192.168.2.160:2002
2011-04-29 19:03:03,775 DEBUG [ResourceTransportRequestHandler] GET /resource/6/MEDIA_ITEM/AVC_TS_MP_HD_AC3_ISO$0 HTTP/1.0, headers = [getcontentFeatures.dlna.org: 1,transferMode.dlna.org: Streaming,TimeSeekRange.dlna.org: npt=29-,Host: 192.168.2.150:8895]]
2011-04-29 19:03:03,775 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.2.160
2011-04-29 19:03:03,777 DEBUG [ResourceTransportRequestHandler] Resource request accepted. Using client 'IPAddress=/192.168.2.160, Profile=Samsung TV (B-series)'
2011-04-29 19:03:03,778 DEBUG [ResourceTransportRequestHandler] Request for resource 6 and type 'MEDIA_ITEM' received
2011-04-29 19:03:03,778 DEBUG [MediaItemDAOImpl] Reading a MediaItem (id = 6)
2011-04-29 19:03:03,780 DEBUG [VideoDAOImpl] Reading a Video (id = 6)
2011-04-29 19:03:03,782 DEBUG [VideoDeliveryEngine] Delivering item '6' for client 'IPAddress=/192.168.2.160, Profile=Samsung TV (B-series)'
2011-04-29 19:03:03,783 DEBUG [VideoDeliveryEngine] Delivering file 'twiz-littlefockers720p.mkv' using transcoding
2011-04-29 19:03:03,783 DEBUG [AbstractTranscodingDeliveryEngine] A suitable transcoding job already exists, re-use it for client 'IPAddress=/192.168.2.160, Profile=Samsung TV (B-series)'
2011-04-29 19:03:03,783 ERROR [ResourceTransportRequestHandler] Error while processing resource, sending back 500 error. Message: FFmpeg execution failed
java.io.IOException: FFmpeg execution failed
        at org.serviio.delivery.resource.AbstractTranscodingDeliveryEngine.retrieveTranscodedResource(AbstractTranscodingDeliveryEngine.java:116)
        at org.serviio.delivery.resource.AbstractDeliveryEngine.deliver(AbstractDeliveryEngine.java:89)
        at org.serviio.delivery.MediaResourceRetrievalStrategy.retrieveResource(MediaResourceRetrievalStrategy.java:116)
        at org.serviio.upnp.webserver.ResourceTransportRequestHandler.handleRequest(ResourceTransportRequestHandler.java:115)
        at org.serviio.upnp.webserver.AbstractRequestHandler.handle(AbstractRequestHandler.java:54)
        at org.apache.http.protocol.HttpService.doService(HttpService.java:293)
        at org.serviio.upnp.webserver.ServiioHttpService.doService(ServiioHttpService.java:58)
        at org.apache.http.protocol.HttpService.handleRequest(HttpService.java:212)
        at org.serviio.upnp.webserver.WebServer$WorkerThread.run(WebServer.java:187)


[zip]

Does the user running Serviio have access to execute the ffmpeg?

[moleculezz]

How do I check which user is running Serviio?

I would think that it's the admin which I am logged in as. The admin is the default user that has access to SSH terminal. Only admins have terminal access on QNAP systems.
Maybe I need to set some permissions on the folders?

I had some help from the QNAP forums to compile ffmpeg. It turns out I was compiling for x86_64, but the system was 32bit. So I restored my QNAP and compiled as x86. Still having the same issue though.
The person helping me out also adviced me to install a different version of mktemp which comes preinstalled on QNAP. I did that and that helped with not having to modify the configuration file.

  Code:

ipkg install mktemp
export PATH=/opt/bin:/opt/sbin:$PATH; ./configure --arch=x86 --enable-ssse3 --prefix=/opt --extra-cflags='-I/opt/include' --extra-ldflags='-L/opt/lib' --enable-static --disable-shared --disable-ffplay --disable-ffserver --enable-libmp3lame

I also tried to compile LAME source from the Serviio download page.

  Code:

./configure
make
make install

And then I created a symlink from that LAME version to the /user/lib/ directory.

I then start playing a movie and then after 20 secs the sound goes off and then after a few seconds it stops playing. Same thing every time.

[moleculezz]

I checked the permissions and they seem fine.

  Code:

[/] # ps -waux | grep -i serviio
29269 admin      1216 S   /bin/sh /share/MD0_DATA/.qpkg/serviio/bin/serviio.sh start
29274 admin     48372 S   /usr/local/jre/bin/java -Xmx384M -Djava.net.preferIPv4Stack=true -Dderby.system.home=/share/MD0_DATA/.qpkg/serviio/
29411 admin       572 R   grep -i serviio
[/] # ls -rlt /share/MD0_DATA/.qpkg/ffmpeg/ffmpeg
-rwxr-xr-x    1 admin    administ  6397352 May  3 21:53 /share/MD0_DATA/.qpkg/ffmpeg/ffmpeg*

[moleculezz]

try to execute this:

  Code:

ffmpeg -i "/share/MD0_DATA/Multimedia/video/movies/Unthinkable Extended MULTi 1080p BluRay x264 LOST/unthinkable.extended.multi.1080p.bluray.x264.mkv" -y -vcodec copy -vbsf h264_mp4toannexb -copyts -acodec ac3 -ab 192k -ac 2 -map 0:0 -map 0:1 -sn -f mpegts /tmp/Serviio/transcoding-temp-2-MPEG2TS.stf

I retried to execute the following after recompiling

  Code:

 # /share/MD0_DATA/.qpkg/ffmpeg/ffmpeg -i "/share/MD0_DATA/Multimedia/video/movies/unt/unt.extended.multi.1080p.bluray.x264.mkv" -y -vcodec copy -vbsf h264_mp4toannexb -copyts -acodec ac3 -ab 192k -ac 2 -map 0:0 -map 0:1 -sn -f mpegts /tmp/transcoding-temp-2-MPEG2TS.stf
FFmpeg version UNKNOWN, Copyright (c) 2000-2011 the FFmpeg developers
  built on May  3 2011 21:53:02 with gcc 4.2.1
  configuration: --arch=x86 --enable-ssse3 --prefix=/opt --extra-cflags=-I/opt/include --extra-ldflags=-L/opt/lib --enable-static --disable-shared --disable-ffplay --disable-ffserver --enable-libmp3lame
  libavutil     50.36. 0 / 50.36. 0
  libavcore      0.16. 0 /  0.16. 0
  libavcodec    52.108. 0 / 52.108. 0
  libavformat   52.92. 0 / 52.92. 0
  libavdevice   52. 2. 3 / 52. 2. 3
  libavfilter    1.72. 0 /  1.72. 0
  libswscale     0.12. 0 /  0.12. 0
[matroska,webm @ 0x8b9e4c0] Invalid stream 4 or size 3
[matroska,webm @ 0x8b9e4c0] Invalid stream 5 or size 3
[matroska,webm @ 0x8b9e4c0] Estimating duration from bitrate, this may be inaccurate

Seems stream 0 codec frame rate differs from container frame rate: 47.95 (5000000/104271) -> 23.98 (5000000/208542)
Input #0, matroska,webm, from '/share/MD0_DATA/Multimedia/video/movies/unt/unt.extended.multi.1080p.bluray.x264.mkv':
  Duration: 01:37:31.60, start: 0.000000, bitrate: 3072 kb/s
    Stream #0.0(eng): Video: h264, yuv420p, 1920x1040, PAR 1:1 DAR 24:13, 23.98 fps, 23.98 tbr, 1k tbn, 47.95 tbc
    Stream #0.1(fre): Audio: dca, 48000 Hz, 5.1, s16, 1536 kb/s
    Metadata:
      title           : French DTS 1509kbps
    Stream #0.2(eng): Audio: dca, 48000 Hz, 5.1, s16, 1536 kb/s
    Metadata:
      title           : English DTS 1509kbps
    Stream #0.3(fre): Subtitle: [0][0][0][0] / 0x0000
    Metadata:
      title           : French
    Stream #0.4(fre): Subtitle: [0][0][0][0] / 0x0000
    Metadata:
      title           : French
[ac3 @ 0x8c1ad10] No channel layout specified. The encoder will guess the layout, but it might be incorrect.
[mpegts @ 0x8c803c0] muxrate VBR, pcr every 2 pkts, sdt every 200, pat/pmt every 40 pkts
Output #0, mpegts, to '/tmp/transcoding-temp-2-MPEG2TS.stf':
  Metadata:
    encoder         : Lavf52.92.0
    Stream #0.0(eng): Video: [0][0][0][0] / 0x0000, yuv420p, 1920x1040 [PAR 1:1 DAR 24:13], q=2-31, 90k tbn, 23.98 tbc
    Stream #0.1(fre): Audio: ac3, 48000 Hz, stereo, flt, 192 kb/s
    Metadata:
      title           : French DTS 1509kbps
Stream mapping:
  Stream #0.0 -> #0.0
  Stream #0.1 -> #0.1
Press [q] to stop encoding
Input stream #0.1 frame changed from rate:48000 fmt:s16 ch:6 to rate:48000 fmt:s16 ch:2
av_interleaved_write_frame(): Operation not permitted bitrate=4908.5kbits/s


[moleculezz]

Ok after testing on my laptop running XMBC it was running with no issues, except that it had to buffer, but that's because I'm running via wifi. I did get some errors though in the log, check here:

  Code:

2011-05-04 21:33:08,318 DEBUG [DeviceDescriptionRequestHandler] Sending DeviceDescription XML back using profile 'Generic DLNA profile'
2011-05-04 21:33:08,529 DEBUG [WebServer] Incoming connection from /192.168.2.102:56980
2011-05-04 21:33:08,531 DEBUG [ServiceDescriptionRequestHandler] ServiceDescription request received for service ConnectionManager
2011-05-04 21:33:08,554 DEBUG [ServiceDescriptionRequestHandler] Sending ServiceDescription XML back
2011-05-04 21:33:08,561 DEBUG [ServiceDescriptionRequestHandler] ServiceDescription request received for service ContentDirectory
2011-05-04 21:33:08,599 DEBUG [ServiceDescriptionRequestHandler] Sending ServiceDescription XML back
2011-05-04 21:33:08,617 DEBUG [WebServer] Incoming connection from /192.168.2.102:56981
2011-05-04 21:33:08,618 DEBUG [WebServer] Incoming connection from /192.168.2.102:56982
2011-05-04 21:33:08,618 DEBUG [ServiceEventSubscriptionRequestHandler] ServiceEvent subscription request received for service ContentDirectory
2011-05-04 21:33:08,619 DEBUG [ServiceEventSubscriptionRequestHandler] ServiceEvent subscription request received for service ConnectionManager
2011-05-04 21:33:08,620 DEBUG [ServiceEventSubscriptionRequestHandler] Event subscription registered (uuid=0f174c4f-2261-4fcc-8521-d5b2b9cab7d1) for service urn:upnp-org:serviceId:ConnectionManager reporting to http://192.168.2.102:50041/fdd7897d-5776-36c3-8389-fec009d37a24/urn:upnp-org:serviceId:ConnectionManager
2011-05-04 21:33:08,621 DEBUG [ServiceEventSubscriptionRequestHandler] Event subscription registered (uuid=ec3305a2-3350-4c66-9e9b-6d8204407df4) for service urn:upnp-org:serviceId:ContentDirectory reporting to http://192.168.2.102:50041/fdd7897d-5776-36c3-8389-fec009d37a24/urn:upnp-org:serviceId:ContentDirectory
2011-05-04 21:33:08,699 DEBUG [EventDispatcher] Sending event notification #0 for subscription ec3305a2-3350-4c66-9e9b-6d8204407df4 to endpoint http://192.168.2.102:50041/fdd7897d-5776-36c3-8389-fec009d37a24/urn:upnp-org:serviceId:ContentDirectory
2011-05-04 21:33:08,728 DEBUG [RequestExecutor] Sending HTTP request to 192.168.2.102:50041
2011-05-04 21:33:08,763 DEBUG [EventDispatcher] Event notification sent and received successfully
2011-05-04 21:33:08,764 DEBUG [EventDispatcher] Sending event notification #0 for subscription 0f174c4f-2261-4fcc-8521-d5b2b9cab7d1 to endpoint http://192.168.2.102:50041/fdd7897d-5776-36c3-8389-fec009d37a24/urn:upnp-org:serviceId:ConnectionManager
2011-05-04 21:33:08,765 DEBUG [RequestExecutor] Sending HTTP request to 192.168.2.102:50041
2011-05-04 21:33:08,774 DEBUG [EventDispatcher] Event notification sent and received successfully
2011-05-04 21:33:09,027 DEBUG [WebServer] Incoming connection from /192.168.2.102:56983
2011-05-04 21:33:09,028 DEBUG [ServiceControlRequestHandler] ServiceControl request received for action '"urn:schemas-upnp-org:service:ContentDirectory:1#Browse"' from 192.168.2.102:
2011-05-04 21:33:09,028 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.2.102
2011-05-04 21:33:09,035 DEBUG [ContentDirectory] Browse() called for renderer Unrecognized device (profile 1) with parameters: objectID = V_F#FOL_R1, browseFlag = BrowseDirectChildren, filter = *, startIndex = 0, count = 30, sortCriteria =
2011-05-04 21:33:09,035 DEBUG [FolderDAOImpl] Getting number of sub-Folders in folder null
2011-05-04 21:33:09,037 DEBUG [FolderDAOImpl] Getting list of sub-Folders in folder null (from=0, count=30)
2011-05-04 21:33:09,056 DEBUG [FolderDAOImpl] Getting number of VIDEO sub-folders and media items in folder 3
2011-05-04 21:33:09,058 DEBUG [FolderDAOImpl] Getting number of VIDEO sub-folders and media items in folder 5
2011-05-04 21:33:09,086 DEBUG [FolderDAOImpl] Getting number of VIDEO sub-folders and media items in folder 4
2011-05-04 21:33:09,091 DEBUG [FolderDAOImpl] Getting number of VIDEO sub-folders and media items in folder 'root'
2011-05-04 21:33:09,101 DEBUG [LocalContentCacheDecorator] Stored entry in the cache (local_default), returning it
2011-05-04 21:33:09,107 DEBUG [ServiceControlRequestHandler] Returning OK SOAP message
2011-05-04 21:33:09,583 DEBUG [DiscoverySSDPMessageListener] Received a valid M-SEARCH message for search target urn:schemas-upnp-org:device:InternetGatewayDevice:1 from address /192.168.2.102:61252
2011-05-04 21:33:11,388 DEBUG [WebServer] Incoming connection from /192.168.2.102:56989
2011-05-04 21:33:11,389 DEBUG [ServiceControlRequestHandler] ServiceControl request received for action '"urn:schemas-upnp-org:service:ContentDirectory:1#Browse"' from 192.168.2.102:
2011-05-04 21:33:11,389 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.2.102
2011-05-04 21:33:11,396 DEBUG [ContentDirectory] Browse() called for renderer Unrecognized device (profile 1) with parameters: objectID = V_F#FOL_R1$F4, browseFlag = BrowseDirectChildren, filter = *, startIndex = 0, count = 30, sortCriteria =
2011-05-04 21:33:11,397 DEBUG [FolderDAOImpl] Getting number of sub-Folders in folder 4
2011-05-04 21:33:11,398 DEBUG [VideoDAOImpl] Retrieving list of videos for folder 4 (from=0, count=30)
2011-05-04 21:33:11,440 DEBUG [GenreDAOImpl] Reading a Genre (id = 1)
2011-05-04 21:33:11,441 DEBUG [MediaItemDAOImpl] Reading a MediaItem (id = 5)
2011-05-04 21:33:11,442 DEBUG [MediaItemDAOImpl] Getting file of media item 5
2011-05-04 21:33:11,444 DEBUG [VideoDAOImpl] Reading a Video (id = 5)
2011-05-04 21:33:11,446 DEBUG [VideoDeliveryEngine] Retrieving resource information for item 5 and profile Generic DLNA profile
2011-05-04 21:33:11,446 DEBUG [CoverImageDAOImpl] Reading a CoverImage (id = 2)
2011-05-04 21:33:11,448 DEBUG [FolderDAOImpl] Getting number of VIDEO sub-folders and media items in folder 4
2011-05-04 21:33:11,450 DEBUG [LocalContentCacheDecorator] Stored entry in the cache (local_default), returning it
2011-05-04 21:33:11,456 DEBUG [ServiceControlRequestHandler] Returning OK SOAP message
2011-05-04 21:33:12,582 DEBUG [DiscoverySSDPMessageListener] Received a valid M-SEARCH message for search target urn:schemas-upnp-org:device:InternetGatewayDevice:1 from address /192.168.2.102:61252
2011-05-04 21:33:14,142 DEBUG [WebServer] Incoming connection from /192.168.2.102:56996
2011-05-04 21:33:14,143 DEBUG [ResourceTransportRequestHandler] GET /resource/5/MEDIA_ITEM/MATROSKA$0 HTTP/1.1, headers = [User-Agent: XBMC/10.1 Git:e9e9099 (Windows; Windows 7, 64-bit (WoW) Service Pack 1 build 7601; http://www.xbmc.org),Host: 192.168.2.150:8895,Accept: */*,Referer: ,Connection: keep-alive]]
2011-05-04 21:33:14,143 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.2.102
2011-05-04 21:33:14,144 DEBUG [ResourceTransportRequestHandler] Resource request accepted. Using client 'IPAddress=/192.168.2.102, Profile=Generic DLNA profile'
2011-05-04 21:33:14,144 DEBUG [ResourceTransportRequestHandler] Request for resource 5 and type 'MEDIA_ITEM' received
2011-05-04 21:33:14,145 DEBUG [MediaItemDAOImpl] Reading a MediaItem (id = 5)
2011-05-04 21:33:14,146 DEBUG [VideoDAOImpl] Reading a Video (id = 5)
2011-05-04 21:33:14,147 DEBUG [VideoDeliveryEngine] Delivering item '5' for client 'IPAddress=/192.168.2.102, Profile=Generic DLNA profile'
2011-05-04 21:33:14,147 DEBUG [VideoDeliveryEngine] Delivering file 'unt.extended.multi.1080p.bluray.x264.mkv' in native format
2011-05-04 21:33:14,148 DEBUG [MediaItemDAOImpl] Getting file of media item 5
2011-05-04 21:33:14,150 DEBUG [MediaItemDAOImpl] Marking MediaItem (id = 5) as read
2011-05-04 21:33:14,218 DEBUG [LocalContentCacheDecorator] Cleared cache (local_resetafterplay)
2011-05-04 21:33:14,218 DEBUG [ResourceTransportRequestHandler] Creating stream entity with length: 8535886328
2011-05-04 21:33:14,218 DEBUG [ResourceTransportRequestHandler] Sending file back
2011-05-04 21:33:14,218 DEBUG [ResourceTransportRequestHandler] HTTP/1.1 200 OK, headers = [[Content-Type: video/x-matroska,Content-Length: 8535886328,Date: Wed, 04 May 2011 20:33:14 GMT,Server: Linux, UPnP/1.0 DLNADOC/1.50, Serviio/0.5.2,Cache-control: no-cache,transferMode.dlna.org: Streaming]]
2011-05-04 21:33:14,474 DEBUG [WebServer] Incoming connection from /192.168.2.102:56998
2011-05-04 21:33:14,475 DEBUG [ResourceTransportRequestHandler] GET /resource/5/MEDIA_ITEM/MATROSKA$0 HTTP/1.1, headers = [Range: bytes=8535862349-,User-Agent: XBMC/10.1 Git:e9e9099 (Windows; Windows 7, 64-bit (WoW) Service Pack 1 build 7601; http://www.xbmc.org),Host: 192.168.2.150:8895,Accept: */*,Referer: ,Connection: keep-alive]]
2011-05-04 21:33:14,475 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.2.102
2011-05-04 21:33:14,476 DEBUG [ResourceTransportRequestHandler] Resource request accepted. Using client 'IPAddress=/192.168.2.102, Profile=Generic DLNA profile'
2011-05-04 21:33:14,476 DEBUG [ResourceTransportRequestHandler] Request for resource 5 and type 'MEDIA_ITEM' received
2011-05-04 21:33:14,476 DEBUG [MediaItemDAOImpl] Reading a MediaItem (id = 5)
2011-05-04 21:33:14,478 DEBUG [VideoDAOImpl] Reading a Video (id = 5)
2011-05-04 21:33:14,480 DEBUG [VideoDeliveryEngine] Delivering item '5' for client 'IPAddress=/192.168.2.102, Profile=Generic DLNA profile'
2011-05-04 21:33:14,480 DEBUG [VideoDeliveryEngine] Delivering file 'unt.extended.multi.1080p.bluray.x264.mkv' in native format
2011-05-04 21:33:14,480 DEBUG [MediaItemDAOImpl] Getting file of media item 5
2011-05-04 21:33:14,483 DEBUG [ResourceTransportRequestHandler] Creating stream entity with length: 23979
2011-05-04 21:33:14,483 DEBUG [ResourceTransportRequestHandler] Sending file back
2011-05-04 21:33:14,483 DEBUG [ResourceTransportRequestHandler] HTTP/1.1 206 Partial Content, headers = [[Content-Type: video/x-matroska,Content-Range: bytes 8535862349-8535886327/8535886328,Content-Length: 23979,Date: Wed, 04 May 2011 20:33:14 GMT,Server: Linux, UPnP/1.0 DLNADOC/1.50, Serviio/0.5.2,Cache-control: no-cache,transferMode.dlna.org: Streaming]]
2011-05-04 21:33:14,604 DEBUG [WebServer] I/O error: Connection reset
2011-05-04 21:33:14,663 DEBUG [WebServer] Incoming connection from /192.168.2.102:56999
2011-05-04 21:33:14,672 DEBUG [ResourceTransportRequestHandler] GET /resource/5/MEDIA_ITEM/MATROSKA$0 HTTP/1.1, headers = [Range: bytes=4661-,User-Agent: XBMC/10.1 Git:e9e9099 (Windows; Windows 7, 64-bit (WoW) Service Pack 1 build 7601; http://www.xbmc.org),Host: 192.168.2.150:8895,Accept: */*,Referer: ,Connection: keep-alive]]
2011-05-04 21:33:14,673 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.2.102
2011-05-04 21:33:14,674 DEBUG [ResourceTransportRequestHandler] Resource request accepted. Using client 'IPAddress=/192.168.2.102, Profile=Generic DLNA profile'
2011-05-04 21:33:14,674 DEBUG [ResourceTransportRequestHandler] Request for resource 5 and type 'MEDIA_ITEM' received
2011-05-04 21:33:14,674 DEBUG [MediaItemDAOImpl] Reading a MediaItem (id = 5)
2011-05-04 21:33:14,675 DEBUG [VideoDAOImpl] Reading a Video (id = 5)
2011-05-04 21:33:14,677 DEBUG [VideoDeliveryEngine] Delivering item '5' for client 'IPAddress=/192.168.2.102, Profile=Generic DLNA profile'
2011-05-04 21:33:14,677 DEBUG [VideoDeliveryEngine] Delivering file 'unt.extended.multi.1080p.bluray.x264.mkv' in native format
2011-05-04 21:33:14,677 DEBUG [MediaItemDAOImpl] Getting file of media item 5
2011-05-04 21:33:14,679 DEBUG [ResourceTransportRequestHandler] Creating stream entity with length: 8535881667
2011-05-04 21:33:14,680 DEBUG [ResourceTransportRequestHandler] Sending file back
2011-05-04 21:33:14,680 DEBUG [ResourceTransportRequestHandler] HTTP/1.1 206 Partial Content, headers = [[Content-Type: video/x-matroska,Content-Range: bytes 4661-8535886327/8535886328,Content-Length: 8535881667,Date: Wed, 04 May 2011 20:33:14 GMT,Server: Linux, UPnP/1.0 DLNADOC/1.50, Serviio/0.5.2,Cache-control: no-cache,transferMode.dlna.org: Streaming]]
2011-05-04 21:33:15,616 DEBUG [DiscoverySSDPMessageListener] Received a valid M-SEARCH message for search target urn:schemas-upnp-org:device:InternetGatewayDevice:1 from address /192.168.2.102:61252
2011-05-04 21:33:15,812 DEBUG [WebServer] Incoming connection from /192.168.2.102:57002
2011-05-04 21:33:15,814 DEBUG [ResourceTransportRequestHandler] HEAD /resource/5/MEDIA_ITEM/cdart.png HTTP/1.1, headers = [User-Agent: XBMC/10.1 Git:e9e9099 (Windows; Windows 7, 64-bit (WoW) Service Pack 1 build 7601; http://www.xbmc.org),Host: 192.168.2.150:8895,Accept: */*,Referer: ,Connection: keep-alive]]
2011-05-04 21:33:15,814 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.2.102
2011-05-04 21:33:15,815 DEBUG [ResourceTransportRequestHandler] Resource request accepted. Using client 'IPAddress=/192.168.2.102, Profile=Generic DLNA profile'
2011-05-04 21:33:15,817 WARN  [ResourceTransportRequestHandler] Invalid request, sending back 400 error
org.serviio.upnp.protocol.http.transport.InvalidResourceRequestException: Invalid incoming request: HEAD /resource/5/MEDIA_ITEM/cdart.png HTTP/1.1
   at org.serviio.upnp.protocol.http.transport.RequestedResourceDescriptor.<init>(RequestedResourceDescriptor.java:67)
   at org.serviio.upnp.protocol.http.transport.AbstractProtocolHandler.getRequestedResourceDescription(AbstractProtocolHandler.java:28)
   at org.serviio.upnp.webserver.ResourceTransportRequestHandler.handleRequest(ResourceTransportRequestHandler.java:107)
   at org.serviio.upnp.webserver.AbstractRequestHandler.handle(AbstractRequestHandler.java:54)
   at org.apache.http.protocol.HttpService.doService(HttpService.java:293)
   at org.serviio.upnp.webserver.ServiioHttpService.doService(ServiioHttpService.java:58)
   at org.apache.http.protocol.HttpService.handleRequest(HttpService.java:212)
   at org.serviio.upnp.webserver.WebServer$WorkerThread.run(WebServer.java:187)
Caused by: java.lang.ArrayIndexOutOfBoundsException: 1
   at org.serviio.upnp.protocol.http.transport.RequestedResourceDescriptor.<init>(RequestedResourceDescriptor.java:64)
   ... 7 more
2011-05-04 21:33:15,881 DEBUG [WebServer] Incoming connection from /192.168.2.102:57003
2011-05-04 21:33:15,882 DEBUG [ResourceTransportRequestHandler] GET /resource/5/MEDIA_ITEM/cdart.png HTTP/1.1, headers = [Range: bytes=0-0,User-Agent: XBMC/10.1 Git:e9e9099 (Windows; Windows 7, 64-bit (WoW) Service Pack 1 build 7601; http://www.xbmc.org),Host: 192.168.2.150:8895,Accept: */*,Referer: ,Connection: keep-alive]]
2011-05-04 21:33:15,882 DEBUG [RendererDAOImpl] Reading a Renderer with ip address 192.168.2.102
2011-05-04 21:33:15,883 DEBUG [ResourceTransportRequestHandler] Resource request accepted. Using client 'IPAddress=/192.168.2.102, Profile=Generic DLNA profile'
2011-05-04 21:33:15,883 WARN  [ResourceTransportRequestHandler] Invalid request, sending back 400 error
org.serviio.upnp.protocol.http.transport.InvalidResourceRequestException: Invalid incoming request: GET /resource/5/MEDIA_ITEM/cdart.png HTTP/1.1
   at org.serviio.upnp.protocol.http.transport.RequestedResourceDescriptor.<init>(RequestedResourceDescriptor.java:67)
   at org.serviio.upnp.protocol.http.transport.AbstractProtocolHandler.getRequestedResourceDescription(AbstractProtocolHandler.java:28)
   at org.serviio.upnp.webserver.ResourceTransportRequestHandler.handleRequest(ResourceTransportRequestHandler.java:107)
   at org.serviio.upnp.webserver.AbstractRequestHandler.handle(AbstractRequestHandler.java:54)
   at org.apache.http.protocol.HttpService.doService(HttpService.java:293)
   at org.serviio.upnp.webserver.ServiioHttpService.doService(ServiioHttpService.java:58)
   at org.apache.http.protocol.HttpService.handleRequest(HttpService.java:212)
   at org.serviio.upnp.webserver.WebServer$WorkerThread.run(WebServer.java:187)
Caused by: java.lang.ArrayIndexOutOfBoundsException: 1
   at org.serviio.upnp.protocol.http.transport.RequestedResourceDescriptor.<init>(RequestedResourceDescriptor.java:64)
   ... 7 more
2011-05-04 21:33:18,616 DEBUG [DiscoverySSDPMessageListener] Received a valid M-SEARCH message for search target urn:schemas-upnp-org:device:InternetGatewayDevice:1 from address /192.168.2.102:61252
2011-05-04 21:33:21,616 DEBUG [DiscoverySSDPMessageListener] Received a valid M-SEARCH message for search target urn:schemas-upnp-org:device:InternetGatewayDevice:1 from address /192.168.2.102:61252
2011-05-04 21:33:44,613 DEBUG [DiscoveryAdvertisementNotifier] Multicasting SSDP alive using interface eth0 (eth0) and address 192.168.2.150, timeout = 0
2011-05-04 21:33:44,614 DEBUG [DiscoveryAdvertisementNotifier] Sending 6 'alive' messages describing device fdd7897d-5776-36c3-8389-fec009d37a24
2011-05-04 21:33:46,421 DEBUG [DiscoveryAdvertisementNotifier] Will advertise again in 00:01:14
2011-05-04 21:34:00,098 DEBUG [DiscoverySSDPMessageListener] Received a valid M-SEARCH message for search target upnp:rootdevice from address /192.168.2.102:4491
2011-05-04 21:34:00,099 DEBUG [DiscoverySearchResponder] Sending 1 M-SEARCH response message(s) to /192.168.2.102:4491
2011-05-04 21:34:00,104 DEBUG [DiscoverySSDPMessageListener] Received a valid M-SEARCH message for search target upnp:rootdevice from address /192.168.2.102:4491
2011-05-04 21:34:00,105 DEBUG [DiscoverySearchResponder] Sending 1 M-SEARCH response message(s) to /192.168.2.102:4491
2011-05-04 21:34:01,242 DEBUG [RepositoryDAOImpl] Reading all Repositories
2011-05-04 21:34:01,243 DEBUG [LibraryAdditionsCheckerThread] Looking for files to share in folder: /share/MD0_DATA/Multimedia/video/movies
2011-05-04 21:34:01,244 DEBUG [LibraryAdditionsCheckerThread] Looking for files to share in folder: /share/MD0_DATA/Multimedia/video/movies/unt
2011-05-04 21:34:01,264 DEBUG [LibraryAdditionsCheckerThread] Found file 'unt.extended.multi.1080p.bluray.x264.mkv', checking if it's already in the Library
2011-05-04 21:34:01,265 DEBUG [MediaItemDAOImpl] Checking if DB already contains media item unt.extended.multi.1080p.bluray.x264.mkv
2011-05-04 21:34:01,267 DEBUG [MediaItemDAOImpl] Media item unt.extended.multi.1080p.bluray.x264.mkv already exists in DB
2011-05-04 21:34:01,268 DEBUG [LibraryAdditionsCheckerThread] Looking for files to share in folder: /share/MD0_DATA/Multimedia/video/movies/LF
2011-05-04 21:34:01,288 DEBUG [LibraryAdditionsCheckerThread] Found file 'lf720p.mkv', checking if it's already in the Library
2011-05-04 21:34:01,288 DEBUG [MediaItemDAOImpl] Checking if DB already contains media item lf720p.mkv
2011-05-04 21:34:01,291 DEBUG [MediaItemDAOImpl] Media item lf720p.mkv already exists in DB
2011-05-04 21:34:01,291 DEBUG [LibraryAdditionsCheckerThread] Looking for files to share in folder: /share/MD0_DATA/Multimedia/video/movies/Forrest.Gump.1994.DVDRip.XviD.iNT-MOViERUSH
2011-05-04 21:34:01,312 DEBUG [LibraryAdditionsCheckerThread] Found file 'mrush-forrestg-cd2.avi', checking if it's already in the Library
2011-05-04 21:34:01,312 DEBUG [MediaItemDAOImpl] Checking if DB already contains media item mrush-forrestg-cd2.avi
2011-05-04 21:34:01,314 DEBUG [MediaItemDAOImpl] Media item mrush-forrestg-cd2.avi already exists in DB
2011-05-04 21:34:01,335 DEBUG [LibraryAdditionsCheckerThread] Found file 'mrush-forrestg-cd1.avi', checking if it's already in the Library
2011-05-04 21:34:01,335 DEBUG [MediaItemDAOImpl] Checking if DB already contains media item mrush-forrestg-cd1.avi
2011-05-04 21:34:01,338 DEBUG [MediaItemDAOImpl] Media item mrush-forrestg-cd1.avi already exists in DB
2011-05-04 21:34:01,339 DEBUG [RepositoryDAOImpl] Marking Repository 1 as scanned with current timestamp
2011-05-04 21:34:43,622 DEBUG [DiscoverySSDPMessageListener] Received a valid M-SEARCH message for search target urn:schemas-upnp-org:device:InternetGatewayDevice:1 from address /192.168.2.102:61252
2011-05-04 21:34:46,606 DEBUG [DiscoverySSDPMessageListener] Received a valid M-SEARCH message for search target urn:schemas-upnp-org:device:InternetGatewayDevice:1 from address /192.168.2.102:61252
2011-05-04 21:34:49,591 DEBUG [DiscoverySSDPMessageListener] Received a valid M-SEARCH message for search target urn:schemas-upnp-org:device:InternetGatewayDevice:1 from address /192.168.2.102:61252
2011-05-04 21:34:52,606 DEBUG [DiscoverySSDPMessageListener] Received a valid M-SEARCH message for search target urn:schemas-upnp-org:device:InternetGatewayDevice:1 from address /192.168.2.102:61252
2011-05-04 21:34:54,986 DEBUG [DiscoverySSDPMessageListener] Received a valid M-SEARCH message for search target upnp:rootdevice from address /192.168.2.102:4491
2011-05-04 21:34:54,987 DEBUG [DiscoverySearchResponder] Sending 1 M-SEARCH response message(s) to /192.168.2.102:4491
2011-05-04 21:34:54,987 DEBUG [DiscoverySSDPMessageListener] Received a valid M-SEARCH message for search target upnp:rootdevice from address /192.168.2.102:4491
2011-05-04 21:34:55,022 DEBUG [DiscoverySearchResponder] Sending 1 M-SEARCH response message(s) to /192.168.2.102:4491
2011-05-04 21:34:55,687 DEBUG [DiscoverySSDPMessageListener] Received a valid M-SEARCH message for search target urn:schemas-upnp-org:device:InternetGatewayDevice:1 from address /192.168.2.102:61252
2011-05-04 21:34:58,621 DEBUG [DiscoverySSDPMessageListener] Received a valid M-SEARCH message for search target urn:schemas-upnp-org:device:InternetGatewayDevice:1 from address /192.168.2.102:61252
2011-05-04 21:35:00,827 DEBUG [DiscoveryAdvertisementNotifier] Multicasting SSDP alive using interface eth0 (eth0) and address 192.168.2.150, timeout = 0
2011-05-04 21:35:00,828 DEBUG [DiscoveryAdvertisementNotifier] Sending 6 'alive' messages describing device fdd7897d-5776-36c3-8389-fec009d37a24
2011-05-04 21:35:02,633 DEBUG [DiscoveryAdvertisementNotifier] Will advertise again in 00:01:24
2011-05-04 21:35:17,749 DEBUG [WebServer] I/O error: Connection reset
2011-05-04 21:35:45,587 DEBUG [DiscoverySSDPMessageListener] Received a valid M-SEARCH message for search target urn:schemas-upnp-org:device:InternetGatewayDevice:1 from address /192.168.2.102:61252
2011-05-04 21:35:48,587 DEBUG [DiscoverySSDPMessageListener] Received a valid M-SEARCH message for search target urn:schemas-upnp-org:device:InternetGatewayDevice:1 from address /192.168.2.102:61252
2011-05-04 21:35:51,588 DEBUG [DiscoverySSDPMessageListener] Received a valid M-SEARCH message for search target urn:schemas-upnp-org:device:InternetGatewayDevice:1 from address /192.168.2.102:61252


[zip]

The errors are related to XMBC hacking retrieval of some image resources rather than following what is offered by the server. It should not affect your experience.