jad3675 26 Posted October 19, 2019 Share Posted October 19, 2019 Looks what I found in dmesg. This is in the near the end of Thursday night issues I was having. I was watching a show streaming from my rclone mount. [Thu Oct 17 21:31:08 2019] INFO: task ffprobe:662 blocked for more than 120 seconds.[Thu Oct 17 21:31:08 2019] Not tainted 4.15.0-65-generic #74-Ubuntu[Thu Oct 17 21:31:08 2019] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.[Thu Oct 17 21:31:08 2019] ffprobe D 0 662 32413 0x00000004[Thu Oct 17 21:31:08 2019] Call Trace:[Thu Oct 17 21:31:08 2019] __schedule+0x24e/0x880[Thu Oct 17 21:31:08 2019] schedule+0x2c/0x80[Thu Oct 17 21:31:08 2019] request_wait_answer+0x137/0x210[Thu Oct 17 21:31:08 2019] ? wait_woken+0x80/0x80[Thu Oct 17 21:31:08 2019] __fuse_request_send+0x86/0x90[Thu Oct 17 21:31:08 2019] fuse_request_send+0x27/0x30[Thu Oct 17 21:31:08 2019] fuse_send_readpages.isra.32+0xd1/0x120[Thu Oct 17 21:31:08 2019] fuse_readpages+0xfd/0x110[Thu Oct 17 21:31:08 2019] __do_page_cache_readahead+0x1c9/0x2c0[Thu Oct 17 21:31:08 2019] ondemand_readahead+0x11a/0x2c0[Thu Oct 17 21:31:08 2019] ? ondemand_readahead+0x11a/0x2c0[Thu Oct 17 21:31:08 2019] page_cache_sync_readahead+0x2e/0x50[Thu Oct 17 21:31:08 2019] generic_file_read_iter+0x7fb/0xbf0[Thu Oct 17 21:31:08 2019] ? lru_cache_add_active_or_unevictable+0x36/0xb0[Thu Oct 17 21:31:08 2019] ? __handle_mm_fault+0x9fd/0x1290[Thu Oct 17 21:31:08 2019] fuse_file_read_iter+0x4d/0x70[Thu Oct 17 21:31:08 2019] new_sync_read+0xe4/0x130[Thu Oct 17 21:31:08 2019] __vfs_read+0x29/0x40[Thu Oct 17 21:31:08 2019] vfs_read+0x8e/0x130[Thu Oct 17 21:31:08 2019] SyS_read+0x5c/0xe0[Thu Oct 17 21:31:08 2019] do_syscall_64+0x73/0x130[Thu Oct 17 21:31:08 2019] entry_SYSCALL_64_after_hwframe+0x3d/0xa2 From the emby log, that is when 'The Good Place' stopped recording. 2019-10-17 21:31:00.065 Info LiveTV: Recording stopped: /home/dvr/shows/The Good Place (2016)/Season 4/The Good Place S04E04 Tinker, Tailor, Demon, Spy.ts2019-10-17 21:31:00.065 Info MediaSourceManager: Live stream native_ff80f93c46e0a0b178f0c4d61a5abab3_531dd78223127365bd1aa31ba1479ccd consumer count is now 02019-10-17 21:31:00.065 Info MediaSourceManager: Closing live stream 06044cf0e6f93cdae5f285c9ecfaaeb4_01413a525b3a9622ce6fdf19f7dde354_native_ff80f93c46e0a0b178f0c4d61a5abab3_531dd78223127365bd1aa31ba1479ccd 2019-10-17 21:31:07.405 Info LiveTV: Triggering refresh on /home/dvr/shows/The Good Place (2016)/Season 4/The Good Place S04E04 Tinker, Tailor, Demon, Spy.ts 2019-10-17 21:51:31.345 Error MediaEncoder: Timeout while running Ffprobe -i file:"/home/dvr/shows/The Good Place (2016)/Season 4/The Good Place S04E04 Tinker, Tailor, Demon, Spy.mkv" -threads 0 -v info -print_format json -show_streams -show_chapters -show_format -show_data "filename": "file:/home/dvr/shows/The Good Place (2016)/Season 4/The Good Place S04E04 Tinker, Tailor, Demon, Spy.mkv", Input #0, matroska,webm, from 'file:/home/dvr/shows/The Good Place (2016)/Season 4/The Good Place S04E04 Tinker, Tailor, Demon, Spy.mkv': System.Exception: System.Exception: Error running ffprobe for file:"/home/dvr/shows/The Good Place (2016)/Season 4/The Good Place S04E04 Tinker, Tailor, Demon, Spy.mkv" Of the four shows that were recorded back-to-back the last one if the only one that didn't have the ffprobe timeout (which is run shows on local storage). The timeout is due to the slow response of the storage, which I find interesting sine it includes fuser. I mark and convert recorded shows. They're recorded to local storage, then converted to mkv, and them marked with commercials. After that is done, I mv it from local storage (/home/dvr) to rclone storage. 'The Good Place' is 3.3GB in size and took 8 minutes to mv to cloud storage. 'Young Sheldon' was 2.3GB and took two minutes, but it was the first up. 'Perfect Harmony' is 3.3GB and took 15 minutes. Those high times, in my experience, are not normal for rclone moves. I'm running a test now, trying to duplicate what was going on Thursday night. John Link to comment Share on other sites More sharing options...
jad3675 26 Posted October 19, 2019 Share Posted October 19, 2019 So, I may have the answer to what is going on. I convert the .ts to .mkv and place it in the same directory where it was originally recorded, which is the 'Recorded TV Shows' library in emby - which had 'Real Time Monitoring' turned on. After the show is converted the script moves it to rclone, which is happening at the same time that emby is attempting to update the library. It would appear that rclone and fuser and ffprobe were not very happy with this combination going on at the same time. The fix (is hopefully) to turn 'Real Time Monitoring' off for the library. @@Q-Droid - thanks for the help. I really appreciate it. John Link to comment Share on other sites More sharing options...
Q-Droid 671 Posted October 19, 2019 Share Posted October 19, 2019 Is the media moved or copied after conversion? If it's moved and not needed in the library then converting to a "staging" path could prevent the contention between Emby and rclone. Link to comment Share on other sites More sharing options...
jad3675 26 Posted October 20, 2019 Share Posted October 20, 2019 Is the media moved or copied after conversion? If it's moved and not needed in the library then converting to a "staging" path could prevent the contention between Emby and rclone. It is moved. I've adjusted the script to put it in a scratch area, and I've turned off real time monitoring for the 'recorded tv' default library in emby. So far, testing looks good. Should know for sure on Thursday. John Link to comment Share on other sites More sharing options...
jeffu231 1 Posted October 20, 2019 Author Share Posted October 20, 2019 I did some more testing. I downgraded my install to 4.1.1 and did a recording and captured the following top. Then I installed the latest beta 4.3.0.15 and captured a top while recording the same channel and show as the first one. I don't recall which version I was on specifically before upgrading to 4.2 where I noticed the difference, but you can see that 4.3 is using more cpu than the 4.1 version in this simple test. I am not sure what the ramifications of downgrading might be and if it was in the state it was before, but there is a noticeable difference between the two versions. Link to comment Share on other sites More sharing options...
jad3675 26 Posted October 23, 2019 Share Posted October 23, 2019 I did some more testing. I downgraded my install to 4.1.1 and did a recording and captured the following top. Screen Shot 2019-10-20 at 11.41.39 AM.png Then I installed the latest beta 4.3.0.15 and captured a top while recording the same channel and show as the first one. Screen Shot 2019-10-20 at 11.48.39 AM.png I don't recall which version I was on specifically before upgrading to 4.2 where I noticed the difference, but you can see that 4.3 is using more cpu than the 4.1 version in this simple test. I am not sure what the ramifications of downgrading might be and if it was in the state it was before, but there is a noticeable difference between the two versions. Have you thought about installing something like Netdata to monitor this with more granularity and charts than top provdies? Or even using the free version of Datadog, like I do? John Link to comment Share on other sites More sharing options...
jad3675 26 Posted October 23, 2019 Share Posted October 23, 2019 So, to wrap up my issues that may have temporarily derailed this thread...removing the 'real time monitoring' and moving the staging location for my DVR'ed shows has helped. A lot. Here's a comparison between last Tuesday's recordings and last night's recording ending at 10pm. There's still some io.await as the system process the file, but it has improved significantly. Link to comment Share on other sites More sharing options...
Luke 37289 Posted October 23, 2019 Share Posted October 23, 2019 Thanks for the feedback. Link to comment Share on other sites More sharing options...
Recommended Posts
Create an account or sign in to comment
You need to be a member in order to leave a comment
Create an account
Sign up for a new account in our community. It's easy!
Register a new accountSign in
Already have an account? Sign in here.
Sign In Now