[Solved] Java errors and media identified as transcoded rather than streamed since 9.6.1 update

For help and support with Linux-specific issues
Forum rules
Please make sure you follow the Problem Reporting Guidelines before posting if you want a reply
ajkessel
Posts: 30
Joined: Sun Jan 20, 2019 7:06 am

[Solved] Java errors and media identified as transcoded rather than streamed since 9.6.1 update

Post by ajkessel » Mon Jun 15, 2020 9:08 am

Since upgrading to 9.6.1 (64 bit, Ubuntu Linux 20.04 Focal), many files that were previously given a verdict as "streamed" are now showing up as "transcoded." I am also seeing many Java errors like below. UMS also appears to be timing out without showing any media in the library when accessed from various clients on my LAN (e.g. VLC).

I've attached a sanitized trace log.
ums-9.6.1-debug-trace.log.gz
ums 9.6.1 trace debug log
(1.15 MiB) Downloaded 140 times
Any suggestions for how to troubleshoot?

Code: Select all

java.lang.UnsupportedOperationException: Reflective setAccessible(true) disabled
        at io.netty.util.internal.ReflectionUtil.trySetAccessible(ReflectionUtil.java:31)
        at io.netty.util.internal.PlatformDependent0$4.run(PlatformDependent0.java:233)
        at java.base/java.security.AccessController.doPrivileged(Unknown Source)
        at io.netty.util.internal.PlatformDependent0.<clinit>(PlatformDependent0.java:227)
        at io.netty.util.internal.PlatformDependent.isAndroid(PlatformDependent.java:289)
        at io.netty.util.internal.PlatformDependent.<clinit>(PlatformDependent.java:92)
        at io.netty.channel.nio.NioEventLoop.newTaskQueue0(NioEventLoop.java:279)
        at io.netty.channel.nio.NioEventLoop.newTaskQueue(NioEventLoop.java:150)
        at io.netty.channel.nio.NioEventLoop.<init>(NioEventLoop.java:138)
        at io.netty.channel.nio.NioEventLoopGroup.newChild(NioEventLoopGroup.java:146)
        at io.netty.channel.nio.NioEventLoopGroup.newChild(NioEventLoopGroup.java:37)
        at io.netty.util.concurrent.MultithreadEventExecutorGroup.<init>(MultithreadEventExecutorGroup.java:84)
        at io.netty.util.concurrent.MultithreadEventExecutorGroup.<init>(MultithreadEventExecutorGroup.java:58)
        at io.netty.channel.MultithreadEventLoopGroup.<init>(MultithreadEventLoopGroup.java:52)
        at io.netty.channel.nio.NioEventLoopGroup.<init>(NioEventLoopGroup.java:96)
        at io.netty.channel.nio.NioEventLoopGroup.<init>(NioEventLoopGroup.java:91)
        at io.netty.channel.nio.NioEventLoopGroup.<init>(NioEventLoopGroup.java:72)
        at io.netty.channel.nio.NioEventLoopGroup.<init>(NioEventLoopGroup.java:52)
        at net.pms.network.HTTPServer.start(HTTPServer.java:117)
        at net.pms.PMS.init(PMS.java:629)
        at net.pms.PMS.createInstance(PMS.java:916)
        at net.pms.PMS.main(PMS.java:1086)

User avatar
SubJunk
Lead Developer
Posts: 3281
Joined: Sun May 27, 2012 4:12 pm

Re: Java errors and media identified as transcoded rather than streamed since 9.6.1 update

Post by SubJunk » Mon Jun 15, 2020 5:53 pm

Hi ajkessel, can you please let us know which file from the logs is one that was previously streaming and now transcoding? It is possible that one of the bugs we fixed has caused this because of an incorrect renderer config, but we can't know without that extra info

ajkessel
Posts: 30
Joined: Sun Jan 20, 2019 7:06 am

Re: Java errors and media identified as transcoded rather than streamed since 9.6.1 update

Post by ajkessel » Tue Jun 16, 2020 12:56 am

SubJunk wrote:
Mon Jun 15, 2020 5:53 pm
Hi ajkessel, can you please let us know which file from the logs is one that was previously streaming and now transcoding? It is possible that one of the bugs we fixed has caused this because of an incorrect renderer config, but we can't know without that extra info
I’ve figured out the difference. These are all video/mpeg container files, typically with a mpeg2video stream and an ac3 audio stream. In earlier versions of UMS, when the scanner detected an “internal subtitles candidate: Embedded”, UMS would still conclude the file was streamable. Now any file with an embedded internal subtitle candidate is marked as transcoded. I’m not aware of any of these files actually having subtitles (there is no separate subtitle stream) and in any case I don’t care about subtitles for any of them. Is this a bug or just a configuration feature that has changed? Can I mark them for streaming notwithstanding the “internal subtitles candidate”? Are there really even subtitles here? I can't find much public documentation on what "internal subtitles...embedded" actually means, and can't find a way to extract them if they actually exist.

Note I see the same behavior with 9.6.2, as well as the Java errors mentioned above.

User avatar
SubJunk
Lead Developer
Posts: 3281
Joined: Sun May 27, 2012 4:12 pm

Re: Java errors and media identified as transcoded rather than streamed since 9.6.1 update

Post by SubJunk » Tue Jun 16, 2020 9:06 am

In order to know what the situation is I just need to know a filename to look for in the logs. We have added heaps of custom logging throughout the application that is usually enough to tell us why the program is making these decisions.

ajkessel
Posts: 30
Joined: Sun Jan 20, 2019 7:06 am

Re: Java errors and media identified as transcoded rather than streamed since 9.6.1 update

Post by ajkessel » Tue Jun 16, 2020 9:37 am

SubJunk wrote:
Tue Jun 16, 2020 9:06 am
In order to know what the situation is I just need to know a filename to look for in the logs. We have added heaps of custom logging throughout the application that is usually enough to tell us why the program is making these decisions.
The log file I posted had sanitized filenames so you won't be able to find it that way. 100% of my files were streaming rather than transcoding before, now thousands are transcoding. Here's a log file excerpt for an example one. If you need more, I can regenerate log files so it's clearer which files are at issue:

Code: Select all

TRACE 2020-06-15 17:35:33.962 [Library Scanner] Matched format MPG to "/home/user/filename.vob"
TRACE 2020-06-15 17:35:34.400 [Library Scanner] MediaInfo parsing results for "/home/user/filename.vob":
  Format: "MPEG-PS"             Duration: 1:40:13.457         Overall Bitrate Mode: VBR     Overall Bitrate: 5547523
  Cover: No                     FPS: 23.976
  - Video track ID: 224
    Format: "MPEG Video"          Version: "Version 2"          Profile: "[email protected]"          Duration: 1:40:13.457
    BitRate Mode: VBR             Bitrate: 5053127              BitRate Maximum: 9800000      Width: 720
    Height: 480                   Colorimetry: 4:2:0            Chroma: 4:2:0                 PAR: 1.185
    DAR: 16:9                     Scan Type: Progressive        Scan Order: 2:3 Pulldown      FPS: 23.976
    GOP: "Variable"               Bit Depth: 8                  Delay: 266.733333             Delay Source: Container
    Delay Original: 3626000       Delay O. Source: Stream
  - Audio track ID: 189-128
    Format: "AC-3"                Duration: 1:40:13.120         BitRate Mode: CBR             Bitrate: 384000
    Channel(s): 6                 Samplerate: 48000             Delay: 233.366667             Delay Source: Container
  - Subtitle ID: 224-CC3
    Format: "EIA-608"
TRACE 2020-06-15 17:35:34.400 [Library Scanner] Parsing results for file "filename.vob": Container: MPEGPS, Size: 4169973760, Overall Bitrate: 5547523, Video Tracks: 1, Video Codec: mpeg2, Duration: 1:40:13.457, Video Resolution: 720 x 480, Display Aspect Ratio: 16:9, Pixel Aspect Ratio: 1.18 (237/200), Scan Type: Progressive, Scan Order: 2:3 Pulldown, Frame Rate: 23.976, Audio Tracks: 1 [Audio Codec: AC3, Bitrate: 384000, Channels: 6, Sample Frequency: 48000 Hz], Subtitle Tracks: 1 [Embedded, id: 224, type: UNKNOWN, lang: und], Mime Type: video/mpeg
DEBUG 2020-06-15 17:35:34.423 [Library Scanner] Starting /usr/bin/ffmpeg -ss 4 -i "/home/user/filename.vob" -an -dn -sn -vf scale=320:-2 -vframes 1 -f image2 pipe:
DEBUG 2020-06-15 17:35:34.485 [ffmpeg-6-2] ffmpeg version 4.2.2-1ubuntu1 Copyright (c) 2000-2019 the FFmpeg developers
DEBUG 2020-06-15 17:35:34.486 [ffmpeg-6-2]   built with gcc 9 (Ubuntu 9.3.0-3ubuntu1)
DEBUG 2020-06-15 17:35:34.486 [ffmpeg-6-2]   configuration: --prefix=/usr --extra-version=1ubuntu1 --toolchain=hardened --libdir=/usr/lib/x86_64-linux-gnu --incdir=/usr/include/x86_64-linux-gnu --arch=amd64 --enable-gpl --disable-stripping --enable-avresample --disable-filter=resample --enable-avisynth --enable-gnutls --enable-ladspa --enable-libaom --enable-libass --enable-libbluray --enable-libbs2b --enable-libcaca --enable-libcdio --enable-libcodec2 --enable-libflite --enable-libfontconfig --enable-libfreetype --enable-libfribidi --enable-libgme --enable-libgsm --enable-libjack --enable-libmp3lame --enable-libmysofa --enable-libopenjpeg --enable-libopenmpt --enable-libopus --enable-libpulse --enable-librsvg --enable-librubberband --enable-libshine --enable-libsnappy --enable-libsoxr --enable-libspeex --enable-libssh --enable-libtheora --enable-libtwolame --enable-libvidstab --enable-libvorbis --enable-libvpx --enable-libwavpack --enable-libwebp --enable-libx265 --enable-libxml2 --enable-libxvid --enable-libzmq --enable-libzvbi --enable-lv2 --enable-omx --enable-openal --enable-opencl --enable-opengl --enable-sdl2 --enable-libdc1394 --enable-libdrm --enable-libiec61883 --enable-nvenc --enable-chromaprint --enable-frei0r --enable-libx264 --enable-shared
DEBUG 2020-06-15 17:35:34.486 [ffmpeg-6-2]   libavutil      56. 31.100 / 56. 31.100
DEBUG 2020-06-15 17:35:34.486 [ffmpeg-6-2]   libavcodec     58. 54.100 / 58. 54.100
DEBUG 2020-06-15 17:35:34.486 [ffmpeg-6-2]   libavformat    58. 29.100 / 58. 29.100
DEBUG 2020-06-15 17:35:34.486 [ffmpeg-6-2]   libavdevice    58.  8.100 / 58.  8.100
DEBUG 2020-06-15 17:35:34.486 [ffmpeg-6-2]   libavfilter     7. 57.100 /  7. 57.100
DEBUG 2020-06-15 17:35:34.486 [ffmpeg-6-2]   libavresample   4.  0.  0 /  4.  0.  0
DEBUG 2020-06-15 17:35:34.486 [ffmpeg-6-2]   libswscale      5.  5.100 /  5.  5.100
DEBUG 2020-06-15 17:35:34.486 [ffmpeg-6-2]   libswresample   3.  5.100 /  3.  5.100
DEBUG 2020-06-15 17:35:34.486 [ffmpeg-6-2]   libpostproc    55.  5.100 / 55.  5.100
DEBUG 2020-06-15 17:35:34.490 [ffmpeg-6-2] [mpeg @ 0x55ac0d9ae780] start time for stream 2 is not set in estimate_timings_from_pts
DEBUG 2020-06-15 17:35:34.491 [ffmpeg-6-2] Input #0, mpeg, from '/home/user/filename.vob':
DEBUG 2020-06-15 17:35:34.491 [ffmpeg-6-2]   Duration: 01:40:13.52, start: 0.233367, bitrate: 5547 kb/s
DEBUG 2020-06-15 17:35:34.491 [ffmpeg-6-2]     Stream #0:0[0x1e0]: Video: mpeg2video (Main), yuv420p(tv, progressive), 720x480 [SAR 32:27 DAR 16:9], Closed Captions, 29.83 fps, 59.94 tbr, 90k tbn, 59.94 tbc
DEBUG 2020-06-15 17:35:34.491 [ffmpeg-6-2]     Stream #0:1[0x80]: Audio: ac3, 48000 Hz, 5.1(side), fltp, 384 kb/s
DEBUG 2020-06-15 17:35:34.491 [ffmpeg-6-2]     Stream #0:2[0x1bf]: Data: dvd_nav_packet
DEBUG 2020-06-15 17:35:34.491 [ffmpeg-6-2] Stream mapping:
DEBUG 2020-06-15 17:35:34.491 [ffmpeg-6-2]   Stream #0:0 -> #0:0 (mpeg2video (native) -> mjpeg (native))
DEBUG 2020-06-15 17:35:34.491 [ffmpeg-6-2] Press [q] to stop, [?] for help
DEBUG 2020-06-15 17:35:34.495 [ffmpeg-6-2] [swscaler @ 0x55ac0db4ab00] deprecated pixel format used, make sure you did set range correctly
DEBUG 2020-06-15 17:35:34.496 [ffmpeg-6-2] Output #0, image2, to 'pipe:':
DEBUG 2020-06-15 17:35:34.496 [ffmpeg-6-2]   Metadata:
DEBUG 2020-06-15 17:35:34.496 [ffmpeg-6-2]     encoder         : Lavf58.29.100
DEBUG 2020-06-15 17:35:34.496 [ffmpeg-6-2]     Stream #0:0: Video: mjpeg, yuvj420p(pc), 320x214 [SAR 107:90 DAR 16:9], q=2-31, 200 kb/s, 29.97 fps, 29.97 tbn, 29.97 tbc
DEBUG 2020-06-15 17:35:34.496 [ffmpeg-6-2]     Metadata:
DEBUG 2020-06-15 17:35:34.496 [ffmpeg-6-2]       encoder         : Lavc58.54.100 mjpeg
DEBUG 2020-06-15 17:35:34.496 [ffmpeg-6-2]     Side data:
DEBUG 2020-06-15 17:35:34.496 [ffmpeg-6-2]       cpb: bitrate max/min/avg: 0/0/200000 buffer size: 0 vbv_delay: -1
DEBUG 2020-06-15 17:35:34.498 [ffmpeg-6-2] frame=    1 fps=0.0 q=2.9 Lsize=N/A time=00:00:00.03 bitrate=N/A speed=5.37x    
DEBUG 2020-06-15 17:35:34.498 [ffmpeg-6-2] video:3kB audio:0kB subtitle:0kB other streams:0kB global headers:0kB muxing overhead: unknown
TRACE 2020-06-15 17:35:34.511 [Library Scanner] Converting byte array image source to SOURCE format and type DLNAThumbnail using the following parameters: PadToSize = False
TRACE 2020-06-15 17:35:34.517 [Library Scanner] Image conversion DLNA compliance check for JPEG_RES_320_214: The source image colors are compliant, format is non-compliant and resolution (320 x 214) is compliant.
Failures:
  JPEG DLNA compliance failed with non-typical Huffman tables
TRACE 2020-06-15 17:35:34.522 [Library Scanner] Finished converting 320×214 JPEG image. Output image resolution: 320×214, profile: JPEG_RES_320_214. Flags: Convert colors = False, Re-encode = True
TRACE 2020-06-15 17:35:34.523 [Library Scanner] Searching for thumbnail in THUMBNAILS with "SELECT * FROM THUMBNAILS WHERE MD5 = 'e1322a32bedb5f0b30f442fb6a1fbd5f' LIMIT 1" before update
TRACE 2020-06-15 17:35:34.524 [Library Scanner] File entry "e1322a32bedb5f0b30f442fb6a1fbd5f" not found in THUMBNAILS
TRACE 2020-06-15 17:35:34.527 [Library Scanner] Inserting new thumbnail with ID 4, setting the THUMBID in the FILES table
TRACE 2020-06-15 17:35:34.530 [Library Scanner] THUMBID updated to 4 for /home/user/filename.vob
TRACE 2020-06-15 17:35:34.530 [Library Scanner] Adding new child "filename.vob" with class "RealFile"
TRACE 2020-06-15 17:35:34.531 [Library Scanner] Looking for an audio track with language "eng" for "filename.vob"
TRACE 2020-06-15 17:35:34.544 [Library Scanner] Looking for an audio track with language "fre" for "filename.vob"
TRACE 2020-06-15 17:35:34.544 [Library Scanner] Looking for an audio track with language "jpn" for "filename.vob"
TRACE 2020-06-15 17:35:34.544 [Library Scanner] Looking for an audio track with language "ger" for "filename.vob"
TRACE 2020-06-15 17:35:34.544 [Library Scanner] Looking for an audio track with language "und" for "filename.vob"
TRACE 2020-06-15 17:35:34.545 [Library Scanner] Matched audio track: Audio Codec: AC3, Bitrate: 384000, Channels: 6, Sample Frequency: 48000 Hz
TRACE 2020-06-15 17:35:34.545 [Library Scanner] Searching for a match for audio language "und" with audio "eng" and subtitles "off" for "filename.vob"
TRACE 2020-06-15 17:35:34.545 [Library Scanner] Searching for a match for audio language "und" with audio "*" and subtitles "eng" for "filename.vob"
TRACE 2020-06-15 17:35:34.545 [Library Scanner] Searching for a match for audio language "und" with audio "*" and subtitles "und" for "filename.vob"
TRACE 2020-06-15 17:35:34.545 [Library Scanner] Adding internal subtitles candidate: Embedded, id: 224, type: UNKNOWN, lang: und
TRACE 2020-06-15 17:35:34.545 [Library Scanner] Looking for subtitles with the highest priority from eng, fre, jpn, ger, und
TRACE 2020-06-15 17:35:34.546 [Library Scanner] Returning subtitles with priority Embedded, id: 224, type: UNKNOWN, lang: und: {}
TRACE 2020-06-15 17:35:34.546 [Library Scanner] Matched internal subtitles track for "filename.vob": Embedded, id: 224, type: UNKNOWN, lang: und
TRACE 2020-06-15 17:35:34.547 [Library Scanner] This video has embedded subtitles that must be transcoded
TRACE 2020-06-15 17:35:34.547 [Library Scanner] Getting player for resource "filename.vob"
TRACE 2020-06-15 17:35:34.547 [Library Scanner] Returning compatible player "FFmpeg Video"
TRACE 2020-06-15 17:35:34.547 [Library Scanner] Matched support line f:.+
DEBUG 2020-06-15 17:35:34.547 [Library Scanner] Final verdict: "filename.vob" will be transcoded with player "FFmpeg Video" with mime type "video/mpeg"
TRACE 2020-06-15 17:35:34.547 [Library Scanner] Matched support line f:.+
TRACE 2020-06-15 17:35:34.547 [Library Scanner] File "filename.vob" will be sent with MIME type "MIMETYPE_AUTO"
TRACE 2020-06-15 17:35:34.547 [Library Scanner] Adding "filename.vob" to transcode folder for player: "FFmpeg Video"

User avatar
SubJunk
Lead Developer
Posts: 3281
Joined: Sun May 27, 2012 4:12 pm

Re: Java errors and media identified as transcoded rather than streamed since 9.6.1 update

Post by SubJunk » Tue Jun 16, 2020 9:59 am

Well that log snippet shows part of the picture. It shows that we have detected the subtitles correctly and determined they will need to be transcoded. We also need your configuration file and the renderer configuration file, and it would be useful to reproduce the error fully by playing one of the files before making the logs.
All of these things are in the Problem Reporting Guidelines above.
Feel free to PM the logs to me if you don't want them attached here.

ajkessel
Posts: 30
Joined: Sun Jan 20, 2019 7:06 am

Re: Java errors and media identified as transcoded rather than streamed since 9.6.1 update

Post by ajkessel » Tue Jun 16, 2020 10:22 am

SubJunk wrote:
Tue Jun 16, 2020 9:59 am
Well that log snippet shows part of the picture. It shows that we have detected the subtitles correctly and determined they will need to be transcoded. We also need your configuration file and the renderer configuration file, and it would be useful to reproduce the error fully by playing one of the files before making the logs.
All of these things are in the Problem Reporting Guidelines above.
Feel free to PM the logs to me if you don't want them attached here.
I can send the full original separately to you, but to my knowledge these files have no subtitles. ffmpeg / gst-discoverer don't show any subtitle stream, it only shows up as an "internal embedded" stream in UMS. I can't find any public documentation about what that actually means. Is it possible to tell UMS to just ignore them?

My configuration is pretty standard, attached here. I also haven't touched any renderer configuration files--it's just using whatever shipped with the latest UMS.
UMS.conf
(4.7 KiB) Downloaded 135 times

Nadahar
Posts: 1867
Joined: Tue Jun 09, 2015 5:57 pm

Re: Java errors and media identified as transcoded rather than streamed since 9.6.1 update

Post by Nadahar » Tue Jun 16, 2020 11:34 am

The snippet above shows that the file being parsed has EIA-608 subtitles:

Code: Select all

  - Subtitle ID: 224-CC3
    Format: "EIA-608"
This is a type of subtitles often used for hearing impaired in the US as far as I know: https://en.wikipedia.org/wiki/EIA-608

ajkessel
Posts: 30
Joined: Sun Jan 20, 2019 7:06 am

Re: Java errors and media identified as transcoded rather than streamed since 9.6.1 update

Post by ajkessel » Tue Jun 16, 2020 12:38 pm

Nadahar wrote:
Tue Jun 16, 2020 11:34 am
The snippet above shows that the file being parsed has EIA-608 subtitles:

Code: Select all

  - Subtitle ID: 224-CC3
    Format: "EIA-608"
This is a type of subtitles often used for hearing impaired in the US as far as I know: https://en.wikipedia.org/wiki/EIA-608
I see -- I'm attempting to remove that stream with ffmpeg -bsf:v "filter_units=remove_types=6" , but in the meantime, does it make sense that UMS by default is trying to transcode closed captions? In previous versions, all of these same media files were streamed rather than transcoded. I'm sure it's rare that users want closed captions (as opposed to subtitles); why not disable them by default and give the user the option to enable transcoding? Separate from that, is there any way for me to configure UMS so it doesn't flag these EIA-608 embedded subtitles for transcoding?

User avatar
SubJunk
Lead Developer
Posts: 3281
Joined: Sun May 27, 2012 4:12 pm

Re: Java errors and media identified as transcoded rather than streamed since 9.6.1 update

Post by SubJunk » Tue Jun 16, 2020 1:44 pm

UMS was doing the incorrect thing before, and we fixed the bug where it was streaming when had things to transcode.
We can see in the logs that the language of the subtitles isn't detected, so it should match "und", and by default UMS will attempt to transcode undefined language subtitles.
There are program settings you can change to prevent that. If you go onto the Transcoding Settings tab, and the Subtitles settings subtab, you can change the "Audio/subtitles language priority" setting to reflect what you want, or you can simply check "Disable subtitles" if you never want them.

Post Reply