TrueHD doesn't decode?

When you return:

  1. Turning on VERBOSE logging was not requested. Please turn it back OFF until so requested. Only DEBUG was requested. VERBOSE is extremely detrimental until such time as it;s needed. VERBOSE only allows me to see 2 minutes of elapsed time.

  2. I see all the proper Notify registrations. :+1:

  3. If you’re happy with it working, so am I.

Sorry about activating Verbose debug… I turned that OFF, and did some more testing… TrueHD is transcoding properly! Wooohoo!

2019-01-25%2006_42_52-Clipboard

Two questions remain for me.

  1. Will the next upgrade of DSM and/or Plex put me back to square one?

  2. Do you see anything else of concern in the fresh set of logs attached?

Plex Media Server Logs_2019-01-25_06-43-27.zip (5.3 MB)

//Brew

Regarding DSM 7.0,

  1. I will likely not see it before you do. I might consider switching to it in late beta but because my NAS is also my production system, I must be cautious.
  2. Your metadata will always be fine. This is why I keep your data on the Plex share and not with the program itself. It also allows you to move it around if you need to (within reason)
  3. Your logs show PMS did not find the J3455’s hardware acceleration. Is this in Docker or VM?
Jan 25, 2019 06:42:07.930 [0x7f2371047700] DEBUG - Cleaning directory for session ulcsokt9yhb4z2ptgbenhbct ()
Jan 25, 2019 06:42:07.931 [0x7f2371047700] DEBUG - Starting a transcode session ulcsokt9yhb4z2ptgbenhbct at offset -1.0 (state=3)
Jan 25, 2019 06:42:07.938 [0x7f2371047700] DEBUG - TPU: hardware transcoding: enabled, but no hardware decode accelerator found
Jan 25, 2019 06:42:07.939 [0x7f2371047700] DEBUG - [Universal] Using local file path instead of URL: /volume1/Plex-Media/Our Videos/Tomb Raider.mkv
Jan 25, 2019 06:42:07.939 [0x7f2371047700] DEBUG - TPU: hardware transcoding: final decoder: , final encoder: 
Jan 25, 2019 06:42:07.943 [0x7f2371047700] DEBUG - Job running: EAE_ROOT='/volume1/Plex/tmp_transcoding/pms-70c

The J3455 CPU has an ASIC capable of transcoding HEVC video to H264. It should be detected.

Jan 25, 2019 02:46:15.704 [0x7f2391f68700] INFO - Linux version: 4.4.59+ (#23824 SMP PREEMPT Tue Dec 25 18:27:56 CST 2018), language: en-US
Jan 25, 2019 02:46:15.704 [0x7f2391f68700] INFO - Processor Intel(R) Celeron(R) CPU J3455 @ 1.50GHz

This is troubling.

  1. Stop PMS
  2. Remove 1.14.1.5488
  3. Restart DSM
  4. Reinstall PMS
  5. Have it start after installation.
  6. Play something which mandates HW trancoding.
  7. Let it play for only a few seconds then stop playback
  8. Wait 30 seconds
  9. Settings - Server - Troubleshooting - Download Logs
  10. Attach the ZIP file.

My concern here is user plex does not have access to the hardware. If need be, we can manually correct this at the DSM shell command line using SSH/Putty.

:frowning:

Not running in Docker or a VM… Native install using Package Center.

After performing steps these steps nothing set with TrueHD plays again… I had to change the audio track to something else in order to get movies to play. It seems like a setting reverted back after rebooting DSM… So then I reissued these commands and TrueHD would transcode so we need to understand why that doesn’t “stick” after a reboot:

echo fs.inotify.max_user_watches=32768 >> /etc/sysctl.conf
sysctl -p

Attached logs should show HW transcoding AND TrueHD transcoding after the above was done…
Plex Media Server Logs_2019-01-25_21-59-15.zip (4.7 MB)

PS… Are you the developer of Plex?

I am the chief cook and bottle washer when it comes to Synology boxen.
I am the author of the installer and between Trumpy and myself, we are the bulk of the Synology support although ALL the Ninjas jump in too when they see someone needing help.

With your feedback, I now know what I need do and will go find out why Syno is being stubborn.

…and you’re hilarious to boot! Thanks for all the support, I appreciate it. I’ll stick around for about 30 more min then I’m heading to bed so if you want me to test, I’m here.

You want answers?

I got answers!

  1. to the bottom of /etc.defaults/synoinfo.conf
  2. add the following lines
# Plex
s2s_watches_max="32768"

You can also just, as root,

echo ‘s2s_watches_max=“32768”’ >> /etc.defaults/synoinfo.conf

I have a very simple motto:

“When all else fails, Get a bigger hammer”

Add that line and reboot.
I do not have hardware transcoding and now I get.

sh-4.3# cat /proc/sys/fs/inotify/max_user_watches 
32768
sh-4.3#

They tried to sneak one around me in QNAP style. Nope, not gonna happen :smiley:

Go bigger with the hammer… still no luck after rebooting.

Plex Media Server Logs_2019-01-25_22-44-27.zip (4.5 MB)

See the “cat” line? Please go type that at the command line prompt on your system.
Something is rotten.

Also please verify your DSM version

Also, while there, let’s make sure it’s all looking correct.

Use tail -5 , you should get output which looks like this:

sh-4.3# tail -5 /etc.defaults/synoinfo.conf
vpn_conn_max="30"
support_share_snapshot="yes"

# Plex
s2s_watches_max="32768"
sh-4.3# 

DSM 6.2.1-23824 Update 4

sh-4.3# tail -5 /etc.defaults/synoinfo.conf
max_dr_replica=“32”
support_share_snapshot=“yes”
support_dr_replica=“yes”
support_iscsi_btrfs_lun=“yes”
‘s2s_watches_max=“32768”’

looks like a bogus character ’ in front of s2s???

OOOPS. See it?

you copied my text, You didn’t execute the command from the shell. my bad,.

Go back and edit that file. remove the single quotes (leading and trailing)

it should look as I show above, without quotes

Then wash, rinse, and repeat please

I dunno man… I’m missing something… Something doesn’t seem right.

You go get some sleep / whatever, I will go figure this out

I will NOT be defeated

Deal. thanks again.

Having taken time to experiment with what we did, and think more about what’s happening to you, there are two issues here.

We have solved, with a patch, your Notify problem.
One is still outstanding. which is intermittent.

Jan 25, 2019 22:43:20.108 [0x7fc51c623700] DEBUG - Completed: [192.168.1.131:51650] 200 GET /:/timeline?bandwidth=976&bufferedTime=0&containerKey=%2FplayQueues%2F278&duration=6072900&guid=com.plexapp.agents.imdb%3A%2F%2Ftt2911666%3Flang%3Den&key=%2Flibrary%2Fmetadata%2F84063&machineIdentifier=1e62c8b6e06f13a60ab056ecdbbe16b1b3f56d30&playbackTime=0&playQueueItemID=3292&ratingKey=84063&state=buffering&time=0 (10 live) GZIP 10ms 710 bytes (pipelined: 6)
Jan 25, 2019 22:43:20.246 [0x7fc516bff700] DEBUG - NetworkInterface: received Netlink message len=1204, type=RTM_NEWLINK, flags=0x0
Jan 25, 2019 22:43:20.246 [0x7fc516bff700] DEBUG - NetworkInterface: Netlink information message family=0, type=1, index=14, flags=0x1002, change=0xffffffff
Jan 25, 2019 22:43:20.247 [0x7fc516bff700] DEBUG - Network change.
Jan 25, 2019 22:43:20.247 [0x7fc516bff700] DEBUG - NetworkInterface: Notified of network changed (force=0)
Jan 25, 2019 22:43:20.256 [0x7fc516bff700] DEBUG - Network change notification but nothing changed.
Jan 25, 2019 22:43:20.256 [0x7fc516bff700] DEBUG - NetworkInterface: received Netlink message len=1208, type=RTM_NEWLINK, flags=0x0
Jan 25, 2019 22:43:20.256 [0x7fc516bff700] DEBUG - NetworkInterface: Netlink information message family=0, type=1, index=14, flags=0x1043, change=0x1
Jan 25, 2019 22:43:20.256 [0x7fc516bff700] DEBUG - Network change.
Jan 25, 2019 22:43:20.256 [0x7fc516bff700] DEBUG - NetworkInterface: Notified of network changed (force=0)
Jan 25, 2019 22:43:20.257 [0x7fc516bff700] DEBUG - Network change notification but nothing changed.
Jan 25, 2019 22:43:20.257 [0x7fc516bff700] DEBUG - NetworkInterface: received Netlink message len=1208, type=RTM_NEWLINK, flags=0x0
Jan 25, 2019 22:43:20.257 [0x7fc516bff700] DEBUG - NetworkInterface: Netlink information message family=0, type=1, index=14, flags=0x1003, change=0x0
Jan 25, 2019 22:43:20.257 [0x7fc516bff700] DEBUG - Network change.
Jan 25, 2019 22:43:20.257 [0x7fc516bff700] DEBUG - NetworkInterface: Notified of network changed (force=0)
Jan 25, 2019 22:43:20.258 [0x7fc516bff700] DEBUG - Network change notification but nothing changed.
Jan 25, 2019 22:43:20.269 [0x7fc516bff700] DEBUG - NetworkInterface: received Netlink message len=1208, type=RTM_NEWLINK, flags=0x0
Jan 25, 2019 22:43:20.269 [0x7fc516bff700] DEBUG - NetworkInterface: Netlink information message family=0, type=1, index=14, flags=0x1003, change=0x0
Jan 25, 2019 22:43:20.269 [0x7fc516bff700] DEBUG - Network change.
Jan 25, 2019 22:43:20.269 [0x7fc516bff700] DEBUG - NetworkInterface: Notified of network changed (force=0)
Jan 25, 2019 22:43:20.278 [0x7fc516bff700] DEBUG - Network change notification but nothing changed.
Jan 25, 2019 22:43:20.279 [0x7fc516bff700] DEBUG - NetworkInterface: received Netlink message len=1232, type=RTM_NEWLINK, flags=0x0
Jan 25, 2019 22:43:20.279 [0x7fc516bff700] DEBUG - NetworkInterface: Netlink information message family=0, type=1, index=14, flags=0x1003, change=0x0
Jan 25, 2019 22:43:20.279 [0x7fc516bff700] DEBUG - Network change.
Jan 25, 2019 22:43:20.279 [0x7fc516bff700] DEBUG - NetworkInterface: Notified of network changed (force=0)
Jan 25, 2019 22:43:20.280 [0x7fc516bff700] DEBUG - Network change notification but nothing changed.
Jan 25, 2019 22:43:20.280 [0x7fc516bff700] DEBUG - NetworkInterface: received Netlink message len=1232, type=RTM_NEWLINK, flags=0x0
Jan 25, 2019 22:43:20.281 [0x7fc516bff700] DEBUG - NetworkInterface: Netlink information message family=0, type=1, index=14, flags=0x1003, change=0x100
Jan 25, 2019 22:43:20.281 [0x7fc516bff700] DEBUG - Network change.
Jan 25, 2019 22:43:20.281 [0x7fc516bff700] DEBUG - NetworkInterface: Notified of network changed (force=0)
Jan 25, 2019 22:43:20.281 [0x7fc516bff700] DEBUG - Network change notification but nothing changed.

This resulted in PMS not being able to authenticate for the TrueHD codec right after it had authenticated you as the owner/user. Error 6 is a DNS lookup (resolve name to IP address) error.

Jan 25, 2019 22:43:29.582 [0x7fc514048700] DEBUG - HTTP requesting PUT https://plex.tv/api/servers/1e62c8b6e06f13a60ab056ecdbbe16b1b3f56d30/connectivity?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx&asyncIdentifier=4dd2605a-d1c0-4569-882b-636e5f75d61a
Jan 25, 2019 22:43:29.651 [0x7fc515bff700] ERROR - Error issuing curl_easy_perform(handle): 6
Jan 25, 2019 22:43:29.651 [0x7fc515bff700] WARN - HTTP error requesting GET https://plex.tv/api/v2/release_channels?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx (0, No error) (Couldn't resolve host 'plex.tv')

This isn’t good nor was it there previously. Your network (LAN) is going up/down like a yo-yo resulting in DNS lookup failures. My first words are to check the integrity of the connectors and ethernet cables. I have had the locking clip break off more than once or not fully lock in. Not locking in properly is usually the case and it slowly slips out over time.

Please take a look and this and verify mechanical settings.
Also, as secondary check, have DSM check for updates. This will further validate it can see the internet correctly.

OK this is getting VERY interesting. I remember when I set the NAS up about 6-7 months ago, I was in some log and recall seeing the NIC up/down messages every second. As an IT guy, It drove me nuts. I couldn’t figure it out and since everything was working so well, I assume it had to be a bug and forgot all about until you just posted this. I have a new switch and am using the cables that came from Synology. I have both NIC’s currently setup in an Active/Passive bond.

Before I change anything, do you recall where in DSM I can “watch” network link error messages? I would like to do some before/after testing with different cables and maybe even break the bond.

Now that I think about it… I remember this situation had to do with DHCP. I use fixed IP’s and do NOT see any link/up down errors. I wonder if PMS is getting goofed up due to my Active/Passive bond setup? Any chance PMS is trying to perform DNS lookups on the PASSIVE connection by chance?

If your OVS swtich (which you only need if you are using for Synology’s VM engine) is changing configuration, you will have a problem.

Are you running PMS in the their VM?

If not, you do not need the OVS for Docker. I had a user with OVS once and it was similar. Turn it off a retest

Jan 25, 2019 22:42:49.472 [0x7fc52a0e7800] DEBUG - Detected primary interface: 192.168.1.2
Jan 25, 2019 22:42:49.472 [0x7fc52a0e7800] DEBUG - Network interfaces:
Jan 25, 2019 22:42:49.472 [0x7fc52a0e7800] DEBUG -  * 1 lo (127.0.0.1) (loopback: 1)
Jan 25, 2019 22:42:49.472 [0x7fc52a0e7800] DEBUG -  * 7 ovs_bond0 (192.168.1.2) (loopback: 0)
Jan 25, 2019 22:42:49.472 [0x7fc52a0e7800] DEBUG -  * 8 docker0 (172.17.0.1) (loopback: 0)
Jan 25, 2019 22:42:49.472 [0x7fc52a0e7800] DEBUG - NetworkService: Got notification of changed network (first change: 0)