TCP Negotaition failed under windows for FFMPEG

[Vulpovile]

Describe the issue
TCP negotiation failed in Java 8

To Reproduce
Steps to reproduce the behavior:

1. Use Windows
2. Use FFMPEG
3. Try to process one file to another file

The files are BOTH local.

Expected behavior
It works

Logs

Dec 02, 2021 4:30:18 PM com.github.kokorin.jaffree.process.Executor$1 run
WARNING: Interrupting starter thread (Thread-1) because of exception: TCP negotiation failed
Dec 02, 2021 4:30:18 PM com.github.kokorin.jaffree.ffmpeg.FFmpegStopper sendToStdIn
INFO: Ignoring class java.io.IOException: The pipe is being closed
Exception in thread "Thread-1" com.github.kokorin.jaffree.JaffreeException: Failed to execute, was interrupted
	at com.github.kokorin.jaffree.process.ProcessHandler.interactWithProcess(ProcessHandler.java:189)
	at com.github.kokorin.jaffree.process.ProcessHandler.execute(ProcessHandler.java:147)
	at com.github.kokorin.jaffree.ffmpeg.FFmpeg.execute(FFmpeg.java:400)
	at ca.cencored.ffmpegtranscoder.FFMpegProcess.transcode(FFMpegProcess.java:215)
	at ca.cencored.ffmpegtranscoder.VideoProcessThread.run(FFMpegMainClass.java:29)
	Suppressed: com.github.kokorin.jaffree.JaffreeException: TCP negotiation failed
		at com.github.kokorin.jaffree.net.TcpServer.run(TcpServer.java:69)
		at com.github.kokorin.jaffree.process.Executor$1.run(Executor.java:83)
		at java.lang.Thread.run(Unknown Source)
	Caused by: java.net.SocketException: Connection reset
		at java.net.SocketInputStream.read(Unknown Source)
		at java.net.SocketInputStream.read(Unknown Source)
		at sun.nio.cs.StreamDecoder.readBytes(Unknown Source)
		at sun.nio.cs.StreamDecoder.implRead(Unknown Source)
		at sun.nio.cs.StreamDecoder.read(Unknown Source)
		at java.io.InputStreamReader.read(Unknown Source)
		at java.io.BufferedReader.fill(Unknown Source)
		at java.io.BufferedReader.readLine(Unknown Source)
		at java.io.BufferedReader.readLine(Unknown Source)
		at com.github.kokorin.jaffree.ffmpeg.FFmpegProgressReader.readProgress(FFmpegProgressReader.java:80)
		at com.github.kokorin.jaffree.ffmpeg.FFmpegProgressReader.negotiate(FFmpegProgressReader.java:54)
		at com.github.kokorin.jaffree.net.NegotiatingTcpServer.serve(NegotiatingTcpServer.java:44)
		at com.github.kokorin.jaffree.net.TcpServer.run(TcpServer.java:66)
		... 2 more
Caused by: java.lang.InterruptedException: sleep interrupted
	at java.lang.Thread.sleep(Native Method)
	at com.github.kokorin.jaffree.process.ProcessHandler.waitForExecutorToStop(ProcessHandler.java:321)
	at com.github.kokorin.jaffree.process.ProcessHandler.interactWithProcess(ProcessHandler.java:183)
	... 4 more

This is my code snippet:

FFmpeg ff = FFmpeg.atPath();
ff.addInput(UrlInput.fromUrl(vInput));
ff.addOutput(UrlOutput.toUrl(vOutput));
ff.setOverwriteOutput(true);
ff.addArguments("-hwaccel", "cuda");
ff.addArguments("-max_muxing_queue_size", "4096");
System.out.println("Starting processor");
if (videoData.procVideo)
{
	ff.addArguments("-vcodec", "h264_nvenc");
	String ratio = videoData.resolution.x + ":" + videoData.resolution.y;
	ff.addArguments("-vf", "scale=" + ratio + ":force_original_aspect_ratio=decrease,pad=" + ratio + ":(ow-iw)/2:(oh-ih)/2,setsar=1");
	if (videoData.procFramerate)
	{
		ff.addArguments("-r", String.valueOf(videoData.framerate));
	}
	if (videoData.procColors)
	{
		ff.addArguments("-pix_fmt", "yuv240p");
		ff.addArguments("-crf", "25");
	}
	ff.addArguments("-b:v", String.valueOf(videoData.videoBitrate));
}
else
{
	ff.addArguments("-vcodec", "copy");
}
if (videoData.procAudio)
{
	ff.addArguments("-b:a", String.valueOf(videoData.audioBitrate));
	ff.addArguments("-ac", "2");
	ff.addArguments("-ar", "44100");
	ff.addArguments("-acodec", "aac");
}
else
{
	ff.addArguments("-acodec", "copy");
}
ff.setLogLevel(LogLevel.QUIET);
final AtomicLong durationMillis = new AtomicLong();
ff.setProgressListener(new ProgressListener() {
	@Override
	public void onProgress(FFmpegProgress progress) {
		durationMillis.set(progress.getTimeMillis());
		if (videoData.length != durationMillis.get()/1000F) //Dumb place to do this
			videoData.length = durationMillis.get()/1000F;
		}
	});
ff.execute();

[kokorin]

Looks like the issue is cause by ProgressListener. Jaffree reads progress which is sent by ffmpeg to local (127.0.0.1) TCP port.
Try the same snippet but without ProgressListener.

Could you also provide logs? For that set ffmpeg log level to DEBUG and configure your logger implementation to write DEBUG logs too?

[Vulpovile]

Sorry for the long time to get back to you, I've been having a lot to do for uni. I will be trying your suggestions and posting a log ASAP.

[kokorin]

@Vulpovile could you please share some updates? I'm very interested in your findings because it could really improve Jaffree stability.

[Bloodspawns]

ff.addArguments("-pix_fmt", "yuv240p");

Not sure if this is useful to the discussion but this is a typo i'm pretty sure. It should be yuv420p. Furthermore i noticed i get the same TCP negotiation problem when FFMPEG runs into any problem and isn't able to exit correctly because of it. I also noticed it only happens with execute() but not with executeAsync(). Hope this is of some use. edit: i think it just eats most of the stacktrace with the async method and I didn't see it at first.

[herkne]

Seems there is a null-check missing:
Caused by: com.github.kokorin.jaffree.JaffreeException: Failed to execute, was interrupted
at com.github.kokorin.jaffree.process.ProcessHandler.interactWithProcess(ProcessHandler.java:205) ~[jaffree-2023.09.10.jar:?]
at com.github.kokorin.jaffree.process.ProcessHandler.execute(ProcessHandler.java:162) ~[jaffree-2023.09.10.jar:?]
at com.github.kokorin.jaffree.ffmpeg.FFmpeg.execute(FFmpeg.java:421) ~[jaffree-2023.09.10.jar:?]
at de.hkneissel.cba.ui.mp4export.ExportToM4bService$1$1.lambda$0(ExportToM4bService.java:177) ~[main/:?]
at de.hkneissel.cba.ui.mp4export.FfmpegService$1.call(FfmpegService.java:87) ~[main/:?]
at de.hkneissel.cba.ui.mp4export.FfmpegService$1.call(FfmpegService.java:1) ~[main/:?]
at java.util.concurrent.FutureTask.run(FutureTask.java:264) ~[?:?]
... 3 more
Suppressed: com.github.kokorin.jaffree.JaffreeException: TCP negotiation failed
at com.github.kokorin.jaffree.net.TcpServer.run(TcpServer.java:69) ~[jaffree-2023.09.10.jar:?]
at com.github.kokorin.jaffree.process.Executor$1.run(Executor.java:83) ~[jaffree-2023.09.10.jar:?]
at java.lang.Thread.run(Thread.java:833) ~[?:?]
Caused by: java.lang.NullPointerException: Cannot invoke "java.lang.Long.longValue()" because the return value of "com.github.kokorin.jaffree.ffmpeg.FFmpegProgress.getTime(java.util.concurrent.TimeUnit)" is null
at de.hkneissel.cba.ui.mp4export.FfmpegService$2.onProgress(FfmpegService.java:108) ~[main/:?]
at com.github.kokorin.jaffree.ffmpeg.FFmpegProgressReader.readProgress(FFmpegProgressReader.java:146) ~[jaffree-2023.09.10.jar:?]
at com.github.kokorin.jaffree.ffmpeg.FFmpegProgressReader.negotiate(FFmpegProgressReader.java:54) ~[jaffree-2023.09.10.jar:?]
at com.github.kokorin.jaffree.net.NegotiatingTcpServer.serve(NegotiatingTcpServer.java:44) ~[jaffree-2023.09.10.jar:?]
at com.github.kokorin.jaffree.net.TcpServer.run(TcpServer.java:66) ~[jaffree-2023.09.10.jar:?]
... 2 more

[kokorin]

@herkne I have checked the code and all checks are present:

public Long getTime(final TimeUnit timeUnit) {
    if (timeUnit == null) {
        throw new IllegalArgumentException("TimeUnit must be non null");
    }
    if (timeMicros == null) {
        return null;
    }
    return timeUnit.convert(timeMicros, TimeUnit.MICROSECONDS);
}

Could you check if at at de.hkneissel.cba.ui.mp4export.FfmpegService$2.onProgress(FfmpegService.java:108) ~[main/:?] there is an implicit Long to long conversion?

[herkne]

I just noticed it - my error.

[josefhernandez]

any solution for this?