Hang on closing - Githubissues

chainikdn commented 3 years ago

Environment

Filter version: 0.9.4
OS: e.g. Windows 10 x64
Video player: MPC-HC x64 1.9.8
SVP is running and enabled

To Reproduce

open a video
immediately (i.e. "faster than 1000 ms") close the player
the player hangs in the Task Manager forever with a <50% chance

Log

...
T  20072 @     1000: Get source frame: frameNb     28 Input queue size  6
T  27248 @     1000: Processed source frame:     34 at   11344667 ~   11678334 duration(literal)     333667 nextSourceFrameNb     34 nextOutputFrameStartTime   10677333
T  27248 @     1001: Create output frame     32 for source frame     32 at   10677333 ~   11011000 duration     333667
T  27248 @     1001: Frame time drift:          0
T  27248 @     1001: Frame handler start BeginFlush()
T  27248 @     1001: Frame handler wait for barriers
T  20072 @     1029: Delivered frame     28
T  20072 @     1029: GarbageCollect frames until     28 pre size   7 post size   6
T  20072 @     1029: Output worker thread wait for flush
T  27248 @     1029: Frame handler finish BeginFlush()
T  27248 @     1029: ReloadAviSynthScript
T  21444 @     1331: Frame handler start BeginFlush()
T  21444 @     1331: Frame handler cleanup after stop threads
T  27248 @     1474: Frame handler EndFlush()
T  27248 @     1474: Upstream propose to change input format: name NV12, width   704, height   528

avsf-hang.log

CrendKing commented 3 years ago

I tried so many times but still can't repro. I probably need the video.

CrendKing commented 3 years ago

I found a pattern in your log file that shares with https://github.com/CrendKing/avisynth_filter/issues/41. I already fixed that problem in https://github.com/CrendKing/avisynth_filter/commit/fe73211d792b8b4d827f0c35d31f77f4bee7b29b. Can you try AviSynthFilter.zip?

chainikdn commented 3 years ago

nope... to be clear - it hangs on this line: https://github.com/CrendKing/avisynth_filter/blob/0294f08588f3c0d1755b01a62f96fddc7b74059b/avisynth_filter/src/filter.cpp#L478

CrendKing commented 3 years ago

Thanks for the info. Can you also provide the log? I want to see media type that hung madVR.

chainikdn commented 3 years ago

avsf.log

CrendKing commented 3 years ago

Thanks. I'll see if I can repro.

BTW, does EVR hang too?

chainikdn commented 3 years ago

does EVR hang too?

yep... but it hangs somewhere later. last lines:

T  13056 @      848: Frame handler start BeginFlush()
T  13056 @      848: Frame handler wait for barriers
T   3320 @      848: Output worker thread wait for flush
T  13056 @      848: Frame handler finish BeginFlush()
T  13056 @      848: ReloadAviSynthScript
T  19660 @      892: Frame handler start BeginFlush()
T  19660 @      892: Frame handler cleanup after stop threads
T  13056 @     1052: Frame handler EndFlush()
T  13056 @     1052: Upstream propose to change input format: name NV12, width  1920, height  1080
T  13056 @     1052: Downstream accepts new output format: name NV12, width  1920, height  1080
T  13056 @     1057: CheckTransform() for output type: result: 1 output NV12 offered input: NV12 compatible input: NV12
T  13056 @     1057: CheckTransform() for output type: result: 1 output NV12 offered input: NV12 compatible input: NV12
T  13056 @     1057: CheckTransform() for output type: result: 1 output NV12 offered input: NV12 compatible input: NV12
T  13056 @     1128: CheckTransform() for output type: result: 1 output NV12 offered input: NV12 compatible input: NV12
T  13056 @     1128: New output format: name NV12, width  2048, height -1080

CrendKing commented 3 years ago

I think I found the cause. Try AviSynthFilter.zip.

chainikdn commented 3 years ago

no difference at all

CrendKing commented 3 years ago

Well, then I need the video for consistent repro. The problem I found only triggers on certain videos (needs immediate format change upon start, causing concurrency issue)

CrendKing commented 3 years ago

Fixed 2 other rare crashes, which involve closing player while SVP doing RC. Both should actually crash instead of hanging. I still can't make madVR hang on format change. So I need the video for better chance.

Also, can you explain how do you always close the player right while the format change is happening? How small and precise that window is? If you let it play for like 30 seconds (so format change already happened) then close, will it ever hang?

AviSynthFilter.zip

chainikdn commented 3 years ago

https://drive.google.com/file/d/1BQ18Q0L1cBGRIZg99p5kZa_P32Kh9p5H/view?usp=sharing

CrendKing commented 3 years ago

I tried a new video and now repro'd.

EDIT: I need to rethink the whole multi-threading stuff. I don't particularly like the current convoluted logic, where 4 threads external threads (main, avsf output, upstream, avs+) can call into the frame handler functions and I have no control of them. This forced me to use lots of concurrency controls. And I don't think switching to coroutine would simplify this much.

CrendKing commented 3 years ago

@chainikdn Can you try this? AviSynthFilter.zip

chainikdn commented 3 years ago

not until Sunday

CrendKing commented 3 years ago

No rush. Just let me know the result. Thanks.

chainikdn commented 3 years ago

well, at least I can't make it hang the same way anymore

CrendKing commented 3 years ago

Thanks. Closing. Feel free to reopen if you find another way to repro.

chainikdn commented 3 years ago

the same behavior returned in 0.10.0...

chainikdn commented 3 years ago

... plus it now creates extra clip instances (??)

i.e. if I put just two debug lines into my plugin where "++++" marks construction and "~~~~" marks destruction 0.9.4:

++++ 7C31C5B0 <--- launch
~~~~ 7C31C5B0 <--- seek
++++ 3313DC70 
~~~~ 3313DC70 <--- close window

0.10.0:

++++ FEB13C30 <--- launch
++++ FEB16A70 <--- wtf #1
~~~~ FEB13C30 <--- seek
++++ F9BA87C0
~~~~ F9BA87C0 <--- close window
++++ FEB139E0 <--- wtf #2

CrendKing commented 3 years ago

the same behavior returned in 0.10.0...

I will take a look.

... plus it now creates extra clip instances (??)

i.e. if I put just two debug lines into my plugin where "++++" marks construction and "~~~~" marks destruction 0.9.4:
++++ 7C31C5B0 <--- launch
~~~~ 7C31C5B0 <--- seek
++++ 3313DC70 
~~~~ 3313DC70 <--- close window
0.10.0:
++++ FEB13C30 <--- launch
++++ FEB16A70 <--- wtf #1
~~~~ FEB13C30 <--- seek
++++ F9BA87C0
~~~~ F9BA87C0 <--- close window
++++ FEB139E0 <--- wtf #2

This is introduced in https://github.com/CrendKing/avisynth_filter/commit/0d38a39b53fd94490dbaf27191d81ce508560bc1. The point of having two clips instead of one is that often there is case where the filter needs to serve streaming frames while being checked for media types by upstream or downstream filters. If there is only one "AVS instance" in avsf, we have to interrupt the streaming, reload avs with proposed new media type, and answer checking questions, then reload the original media type back for streaming. Then if downstream/upstream propose to change format, we need to reload again.

With the new logic, all checkings are done in a new, background "AVS instance". This instance does not serve any frame. It is only used for format queries. If downstream/upstream propose to change format with valid media type, only then the main avs instance is updated.

Overall this is to ensure less interruption of the stream. Also should make logic simpler so that locks need to wait less to acquire.

Of course, if you found any serious performance degradation or logical issue with this change, feel free to open issue for it.

chainikdn commented 3 years ago

not so sure I like the idea... (*) but anyway, in connection with this issue - is that "background "AVS instance" supposed to be deleted? there're 4 ++++'s and only 2 ~~~~'s in the example above

(*) 1st of all there's waste of resources, for example if (when) I allocate GPU resources at the filter construction

CrendKing commented 3 years ago

Does https://github.com/CrendKing/avisynth_filter/commit/d5ca2f9ba4636b05160934b61c5b121c0ec99fd0 fix your hang problem: AviSynthFilter_Debug.zip? If yes, feel free to close the ticket.

We could discuss the dual avs instance design at length in a separate issue. Please I added some log entry to help you identify the script objects.

chainikdn commented 3 years ago

We could discuss the dual avs instance design at length in a separate issue.

sure, I just mean if those instance(s) are not properly deleted it could be the reason for "hang on closing"

BTW the filter itself is not deleted when closing the video (via File -> Close)

CrendKing commented 3 years ago

Have you tested the upload? If it no longer hangs, please close the ticket.

sure, I just mean if those instance(s) are not properly deleted it could be the reason for "hang on closing"

BTW the filter itself is not deleted when closing the video (via File -> Close)

Please move to new ticket for this topic.

chainikdn commented 3 years ago

at least I can't make it hang the same way anymore

CrendKing / avisynth_filter

Hang on closing #40

Environment

To Reproduce

Log