Jump to content

Massive trans-coding Logfiles


Recommended Posts

Posted

It seems to be a stream from a provider where something in the video stream is changing after exactly 30 minutes.

As a test, if you disable hardware transcoding in server transcoding settings, does that help?

  • 1 month later...
  • 3 months later...
thekingswolf
Posted

this has not reoccurred for me since this happened in 2020.

  • Like 1
Posted

Thanks for the update.

  • 2 months later...
Posted

This started happening to me out of now where just now...

 

user@emby01:/var/lib/emby/logs$ ls -l
total 10242492
-rw-r--r-- 1 emby emby     1781096 Sep 28 23:03 embyserver-63768470399.txt
-rw-r--r-- 1 emby emby      143360 Sep 29 00:24 embyserver.txt
-rw-r--r-- 1 emby emby       30916 Sep 28 22:35 ffmpeg-directstream-17079cf3-84b3-4656-9d97-c693428da70a_1.txt
-rw-r--r-- 1 emby emby       44771 Sep 28 21:22 ffmpeg-transcode-31166bc0-6320-4ef0-80c9-9835d1f6a78c_1.txt
-rw-r--r-- 1 emby emby        4096 Sep 29 00:24 ffmpeg-transcode-5cee8ef7-f1e6-463b-8234-479c3bb9f26e_1graph.txt
-rw-r--r-- 1 emby emby 10485374976 Sep 29 00:24 ffmpeg-transcode-5cee8ef7-f1e6-463b-8234-479c3bb9f26e_1.txt
-rw-r--r-- 1 emby emby      169141 Sep 28 21:45 ffmpeg-transcode-91619b47-c4bb-4028-b1df-81ac4b0c194d_1.txt
-rw-r--r-- 1 emby emby      434591 Sep 28 21:36 ffmpeg-transcode-d11eca28-1f72-4afb-bd07-ad51a7261415_1.txt
-rw-r--r-- 1 emby emby      232329 Sep 28 19:59 hardware_detection-63768455960.txt

 

Did we ever find a solution?   Or did it simply stop occuring... this eats up all the disk space until emby stops.  Considering just linking logs folder to "tmp" so it doesn't fill up the main partition.

Happy2Play
Posted (edited)
2 hours ago, gizzygizmo said:

This started happening to me out of now where just now...

 

user@emby01:/var/lib/emby/logs$ ls -l
total 10242492
-rw-r--r-- 1 emby emby     1781096 Sep 28 23:03 embyserver-63768470399.txt
-rw-r--r-- 1 emby emby      143360 Sep 29 00:24 embyserver.txt
-rw-r--r-- 1 emby emby       30916 Sep 28 22:35 ffmpeg-directstream-17079cf3-84b3-4656-9d97-c693428da70a_1.txt
-rw-r--r-- 1 emby emby       44771 Sep 28 21:22 ffmpeg-transcode-31166bc0-6320-4ef0-80c9-9835d1f6a78c_1.txt
-rw-r--r-- 1 emby emby        4096 Sep 29 00:24 ffmpeg-transcode-5cee8ef7-f1e6-463b-8234-479c3bb9f26e_1graph.txt
-rw-r--r-- 1 emby emby 10485374976 Sep 29 00:24 ffmpeg-transcode-5cee8ef7-f1e6-463b-8234-479c3bb9f26e_1.txt
-rw-r--r-- 1 emby emby      169141 Sep 28 21:45 ffmpeg-transcode-91619b47-c4bb-4028-b1df-81ac4b0c194d_1.txt
-rw-r--r-- 1 emby emby      434591 Sep 28 21:36 ffmpeg-transcode-d11eca28-1f72-4afb-bd07-ad51a7261415_1.txt
-rw-r--r-- 1 emby emby      232329 Sep 28 19:59 hardware_detection-63768455960.txt

 

Did we ever find a solution?   Or did it simply stop occuring... this eats up all the disk space until emby stops.  Considering just linking logs folder to "tmp" so it doesn't fill up the main partition.

If the log file is 10GB then the transcode-temp folder must be enormous.  But more information about that session is needed.

Yes continuous watching could create large logs and fill the drive.

Edited by Happy2Play
gizzygizmo
Posted

Yeah, on my VM image and/or docker i see emby in /var/lib/emby/logs .   Most installs are going to have that on the "main" partition with /usr so it can chew up as much as 10 or 20GB if you're not watching.  

I'll see if i can find the situation that triggers this... possibly when viewing live TV which is mpeg2/TS and has to transcode on firetv.  I suspect if you leave/exit suddenly it leaves the transcode going forever.

I also eyeballed the log file, it's a lot of momentary stats that I don't think should exists.  I would think there's a flag for "quiet" or less verbose that we should be using when transcoding.  If the logs are intended to watch stats at certain intervals we may want to move this to a tmp folder location.  maybe stick it with "transcoding-temp" rather than "log".

gizzygizmo
Posted

Emby did again and saved the logfile this time...  Let me know if there's anything specific you'd like, it's 9gig of basically repeating text.   It's basically a transcode that's stuck in an error loop.  I'm not sure why we're logging ffmepg details to this folder, wish we could specify an alternate location.  I'm thinking we'll have to just turn off transcoding until someone figures this one out.  Looks like it was called with incompatible parameters then repeats "unknown error" over and over.

I may try just setting up a cron job to clean these out... not sure what happens if you delete one while a transcode is currently under way.  I suspect the process would stay and consume resources until everything runs out of memory.

Starts out like this:

22:42:01.311 ffmpeg version 4.3.0-emby_2021_02_27 Copyright (c) 2000-2021 the FFmpeg developers and softworkz for Emby LLC
22:42:01.312   built with gcc 8.3.0 (crosstool-NG 1.24.0)
22:42:01.312 Execution Date: 2021-10-02 22:42:01
22:42:01.334 Input #0, matroska,webm, from '/mnt/incoming/media/TV Storage/Working/Season 01/Working - S01E04 - Quick Out Of The Gate SDTV.mkv':
22:42:01.334   Metadata:
22:42:01.334     ENCODER         : Lavf57.83.100
22:42:01.334   Duration: 00:22:09.18, start: 0.000000, bitrate: 944 kb/s
22:42:01.334     Stream #0:0: Video: h264 (Main), yuv420p(progressive), 640x480 [SAR 1:1 DAR 4:3], Level 30, 30 fps, 30 tbr, 1k tbn, 60 tbc (default)
22:42:01.334     Metadata:
22:42:01.334       HANDLER_NAME    : ISO Media file produced by Google Inc.
22:42:01.334       DURATION        : 00:22:09.063000000
22:42:01.334     Stream #0:1(eng): Audio: aac (LC), 44100 Hz, stereo, fltp (default)
22:42:01.334     Metadata:
22:42:01.334       HANDLER_NAME    : ISO Media file produced by Google Inc.
22:42:01.334       DURATION        : 00:22:09.179000000
22:42:01.694 Stream mapping:
22:42:01.694   Stream #0:0 -> #0:0 (h264 (h264_cuvid) -> h264 (h264_nvenc))
22:42:01.694   Stream #0:1 -> #0:1 (copy)
22:42:01.694 Press [q] to stop, [?] for help
22:42:01.888 Output #0, segment, to '/mnt/incoming/calico/transcode/transcoding-temp/1B48CA_%d.ts':
22:42:01.888   Metadata:
22:42:01.888     encoder         : Lavf58.35.100
22:42:01.888     Stream #0:0: Video: h264 (h264_nvenc) (High), cuda, 640x480 [SAR 1:1 DAR 4:3], q=-1--1, 2832 kb/s, 30 fps, 90k tbn, 30 tbc (default)
22:42:01.888     Metadata:
22:42:01.888       encoder         : Lavc58.62.100 h264_nvenc
22:42:01.888     Side data:
22:42:01.888       cpb: bitrate max/min/avg: 2832018/0/2832018 buffer size: 5664036 vbv_delay: N/A
22:42:01.888     Stream #0:1(eng): Audio: aac (LC), 44100 Hz, stereo, fltp (default)
22:42:01.949 [h264_cuvid @ 0xda1b40] AVHWFramesContext is already initialized with incompatible parameters
22:42:01.949 [h264_cuvid @ 0xda1b40] ctx->cvdl->cuvidParseVideoData(ctx->cuparser, &cupkt) failed -> CUDA_ERROR_UNKNOWN: unknown error
22:42:01.949 Error while decoding stream #0:0: Generic error in an external library
22:42:01.950 [h264_cuvid @ 0xda1b40] ctx->cvdl->cuvidParseVideoData(ctx->cuparser, &cupkt) failed -> CUDA_ERROR_UNKNOWN: unknown error
22:42:01.950 Error while decoding stream #0:0: Generic error in an external library

Then ultimately changes into this which repeats forever until the HDD is filled up and emby stops responding:

22:42:01.311 ffmpeg version 4.3.0-emby_2021_02_27 Copyright (c) 2000-2021 the FFmpeg developers and softworkz for Emby LLC
22:42:01.312   built with gcc 8.3.0 (crosstool-NG 1.24.0)
22:42:01.312 Execution Date: 2021-10-02 22:42:01
22:42:01.334 Input #0, matroska,webm, from '/mnt/incoming/media/TV Storage/Working/Season 01/Working - S01E04 - Quick Out Of The Gate SDTV.mkv':
22:42:01.334   Metadata:
22:42:01.334     ENCODER         : Lavf57.83.100
22:42:01.334   Duration: 00:22:09.18, start: 0.000000, bitrate: 944 kb/s
22:42:01.334     Stream #0:0: Video: h264 (Main), yuv420p(progressive), 640x480 [SAR 1:1 DAR 4:3], Level 30, 30 fps, 30 tbr, 1k tbn, 60 tbc (default)
22:42:01.334     Metadata:
22:42:01.334       HANDLER_NAME    : ISO Media file produced by Google Inc.
22:42:01.334       DURATION        : 00:22:09.063000000
22:42:01.334     Stream #0:1(eng): Audio: aac (LC), 44100 Hz, stereo, fltp (default)
22:42:01.334     Metadata:
22:42:01.334       HANDLER_NAME    : ISO Media file produced by Google Inc.
22:42:01.334       DURATION        : 00:22:09.179000000
22:42:01.694 Stream mapping:
22:42:01.694   Stream #0:0 -> #0:0 (h264 (h264_cuvid) -> h264 (h264_nvenc))
22:42:01.694   Stream #0:1 -> #0:1 (copy)
22:42:01.694 Press [q] to stop, [?] for help
22:42:01.888 Output #0, segment, to '/mnt/incoming/calico/transcode/transcoding-temp/1B48CA_%d.ts':
22:42:01.888   Metadata:
22:42:01.888     encoder         : Lavf58.35.100
22:42:01.888     Stream #0:0: Video: h264 (h264_nvenc) (High), cuda, 640x480 [SAR 1:1 DAR 4:3], q=-1--1, 2832 kb/s, 30 fps, 90k tbn, 30 tbc (default)
22:42:01.888     Metadata:
22:42:01.888       encoder         : Lavc58.62.100 h264_nvenc
22:42:01.888     Side data:
22:42:01.888       cpb: bitrate max/min/avg: 2832018/0/2832018 buffer size: 5664036 vbv_delay: N/A
22:42:01.888     Stream #0:1(eng): Audio: aac (LC), 44100 Hz, stereo, fltp (default)
22:42:01.949 [h264_cuvid @ 0xda1b40] AVHWFramesContext is already initialized with incompatible parameters
22:42:01.949 [h264_cuvid @ 0xda1b40] ctx->cvdl->cuvidParseVideoData(ctx->cuparser, &cupkt) failed -> CUDA_ERROR_UNKNOWN: unknown error
22:42:01.949 Error while decoding stream #0:0: Generic error in an external library
22:42:01.950 [h264_cuvid @ 0xda1b40] ctx->cvdl->cuvidParseVideoData(ctx->cuparser, &cupkt) failed -> CUDA_ERROR_UNKNOWN: unknown error
22:42:01.950 Error while decoding stream #0:0: Generic error in an external library

 

Posted

@softworkz Can you take a look at this to see why this is happening?

Posted

@gizzygizmo - which Nvidia drivers did you install and from where?

Thanks,
sw

gizzygizmo
Posted

I'm using the patched ones from https://github.com/keylase/nvidia-patch (p400, wanted ability to do more than 2 streams):

user@emby01:~/nvidia-patch$ nvidia-smi -L
GPU 0: Quadro P400 (UUID: GPU-453b8cfd-9b7e-50cd-de29-1258f6fece2f)
user@emby01:~/nvidia-patch$ nvidia-smi
Thu Oct  7 08:12:39 2021       
+-----------------------------------------------------------------------------+
| NVIDIA-SMI 460.91.03    Driver Version: 460.91.03    CUDA Version: 11.2     |
|-------------------------------+----------------------+----------------------+
| GPU  Name        Persistence-M| Bus-Id        Disp.A | Volatile Uncorr. ECC |
| Fan  Temp  Perf  Pwr:Usage/Cap|         Memory-Usage | GPU-Util  Compute M. |
|                               |                      |               MIG M. |
|===============================+======================+======================|
|   0  Quadro P400         Off  | 00000000:00:10.0 Off |                  N/A |
| 38%   46C    P0    N/A /  N/A |      0MiB /  2000MiB |      0%      Default |
|                               |                      |                  N/A |
+-------------------------------+----------------------+----------------------+

You think it's driver related?  I just did a git/pull on the nvidia-path and it's up to 472 now... I could try upgrading.

gizzygizmo
Posted

Just upgraded to 470.74, removed the cronjob that deletes the ffmpeg log files... i'll see if this happens again.

 

user@emby01:~/nvidia-patch$ nvidia-smi
Thu Oct  7 08:20:12 2021       
+-----------------------------------------------------------------------------+
| NVIDIA-SMI 470.74       Driver Version: 470.74       CUDA Version: 11.4     |
|-------------------------------+----------------------+----------------------+

 

Posted
3 hours ago, gizzygizmo said:

You think it's driver related?  I just did a git/pull on the nvidia-path and it's up to 472 now... I could try upgrading.

Many of us use those drivers with the patch without an issue.   Doesn't rule it out but that combination works great for many of us (I use them).

  • Agree 1
Posted

It's probably not related to the patch directly, but it could be due to the patch restricting you to a certain version.

23 hours ago, cayars said:

Many of us use those drivers with the patch

@gizzygizmo You are having a "Quadro", while "many of us" means usually GeForce models, so that alone could make a difference.

Anyway, the Quadro's don't have the limitation like the GeForce models, so I wonder why you're using that patch at all?

Posted
7 minutes ago, softworkz said:

It's probably not related to the patch directly, but it could be due to the patch restricting you to a certain version.

@gizzygizmo You are having a "Quadro", while "many of us" means usually GeForce models, so that alone could make a difference.

Anyway, the Quadro's don't have the limitation like the GeForce models, so I wonder why you're using that patch at all?

Ah, sorry, the P400 is restricted, I had looked up the P4000

gizzygizmo
Posted
37 minutes ago, softworkz said:

Ah, sorry, the P400 is restricted, I had looked up the P4000

And to be honest... i don't ever have more than 2 streams anyway; so if the patch was a problem I could move back to mainstream. 

I suspect some kind of issue with a stream or certain circumstances that triggers this scenario.  I have been watching a lot of questionably encoded content lately (ripped from youtube, or direct stream from HDHomeRun mpeg2 stream).  But have yet to catch and be able to repeat this ... seems to happen when i fall asleep watching tv/movies on a firetv client and find emby not working the following day.  I've only seen it 3 times, but enough that I started trying to google/search for RCA.

Posted

@gizzygizmo - for when it re-occurs, we'd need to take a look at one of your ffmpeg logs. You never posted any.

Also we'd need to take a look at a sample file - but please only when you'd see this regularly with multiple different video files.
It's really easy to create (invalid or out-of-spec) video files that cause errors with hw transcoding, so we need to make sure that we're not spending time on investigating on-off issues.

Thanks,
sw

 

  • 2 weeks later...
Posted

I did save the ffmpeg log from when it happened again... however, it's 10G.  I can't imagine you want me to post that... i posted the details that seemed relevant (before it started repeating).  

Since the log seems to be repetition i'll try tgz'ing it and see if it gets to a size that's appropriate to upload.

Posted

@gizzygizmo - Thanks for the log.

  • Does that always happen when you try to use Nvidia hw acceleration?
  • or only sometimes?
  • Or only with a specific file(s)?

Does Nvidia hwa work at all? (sometimes at least)

Posted

I haven't tried disabling hardware acceleration yet, since my VM likely couldn't handle CPU transcoding.

This also only happens sometimes... I have yet to find some steps that will reproduce this.  When it does happen my VM's mount is filled with the log and causes a crash... It does appear the last two times I've found this it was transcoding a shoddy youtube-dl version of a 480p TV Series.

Posted
1 minute ago, gizzygizmo said:

I haven't tried disabling hardware acceleration yet, since my VM likely couldn't handle CPU transcoding.

For testing this, you could set some super-low resolution in the client, like 320p

1 minute ago, gizzygizmo said:

I haven't tried disabling hardware acceleration yet, since my VM likely couldn't handle CPU transcoding.

This also only happens sometimes... I have yet to find some steps that will reproduce this.  When it does happen my VM's mount is filled with the log and causes a crash... It does appear the last two times I've found this it was transcoding a shoddy youtube-dl version of a 480p TV Series.

You'll need to find out under which conditions this happens to occur, and when it happens, also check whether it's a persistent state or whether a subsequent transcode would work again.

As we have never seen this kind of error before, I'd rather suspect some issue with the virtualization - maybe some sleep or powerstate changes that cause this. You could also try to put the GPU board into a different PCIe slot.

Posted

I'm still not able to reproduce this but I did find an important clue... one of the series I was watching was ripped from youtube via youtubedl.  However, each episode was split into 3 portions.   I used ffmpeg and a bash script to concat the 3x videos into a single episode.   The particular episode that appears to have problems on most players is one where part 1 and part 3 were AAC but the middle part 2 is AC3 for some reason.  On systems that don't freeze or exit abruptly back to the series selection the audio goes blank after the first 1/3 portion. 

While I can't get this to reproduce the huge logfile size I suspect somehow ffmepg got stuck transcoding indefinitely due to a input stream issue.

Posted

That sounds like a bad media file to me based on what you just described.

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 account

Sign in

Already have an account? Sign in here.

Sign In Now
×
×
  • Create New...