Multithreading - Is the wrapper Threadsafe ?

[CanadianHusky]

Hello,

Is the underlying native library, the csharp binding and wrapper thread safe ? Or are there heavy synclocks or semaphore locks or similar ?

I am experiencing major bottleneck in .Net Framework 4.8 when using the wrapper over Task.Run() with 12/24 core CPUs
I can prepare minimal code sample if required, but in essence the comparison is between

1-
Task.Run() for Page.GetPixmap on 12 to 24 threads using the wrapper

2-
Same function (render pdf to image with same parameters), but launched as fully separate Processes using mutool.exe draw using shell Process.Start(), which is like a command line execution, again launched inside Task.Run()

Result:
the command line with Process.Start("mutool.exe") is over 10! times (not 10%) faster, despite the overhead of launching a new shell process every time.

Observations:
The shell process uses 100% CPU time as expected on all cores (Task Manager > Performance).
The wrapper hovers around 10 to 40% CPU time, the CPU is not utilized fully, despite the task being fully CPU bound.
No worthwhile Memory usage or limit or no heavy HD exists. Operation is fully CPU bound.

[MaksymTkachuk]

@CanadianHusky
Surely, there are many lock mechanisms in C# binding wrapper.
So, it could have some overhead for lock.
But, I think "10! times" is too big in comparing.
Could you please send code samples to me?
I will check it at my local.
Thanks.

[CanadianHusky]

Certainly! Here you go.
I analyzed this issue in detail for you because just saying "its slow" and not backing it up with evidence doesn't help anyone.

Imports System.IO
Imports System.Diagnostics
Imports System.Threading.Tasks
Imports mupdf.NET  'binding version 3.2.8

Module Module1

    Sub Main(args As String())
        If args.Length = 0 OrElse Not Directory.Exists(args(0)) Then
            Console.WriteLine("Usage: MU_PDF_Benchmark.exe <PDF_Folder_Path>")
            Return
        End If

        Dim inputFolder As String = args(0)
        Dim pdfFiles = Directory.GetFiles(inputFolder, "*.pdf")

        If pdfFiles.Length = 0 Then
            Console.WriteLine("No PDF files found in the specified folder.")
            Return
        End If

        ' Output folders
        Dim method1Out As String = Path.Combine(inputFolder, "method1_output")
        Dim method2Out As String = Path.Combine(inputFolder, "method2_output")
        Directory.CreateDirectory(method1Out)
        Directory.CreateDirectory(method2Out)

        Console.WriteLine("Starting Method 1 (mutool.exe)...")
        Dim sw1 As Stopwatch = Stopwatch.StartNew()
        RunMethod1(pdfFiles, method1Out)
        sw1.Stop()
        Console.WriteLine($"Method 1 done in {sw1.ElapsedMilliseconds} ms")

        Console.WriteLine("Starting Method 2 (MuPDF.NET Binding)...")
        Dim sw2 As Stopwatch = Stopwatch.StartNew()
        RunMethod2(pdfFiles, method2Out)
        sw2.Stop()
        Console.WriteLine($"Method 2 done in {sw2.ElapsedMilliseconds} ms")
    End Sub

    Sub RunMethod1(pdfFiles As String(), outputFolder As String)
        Dim mutoolPath As String = "mutool.exe" ' Ensure this is in PATH or specify full path. Using version 1.25.4
        Dim tasks As New List(Of Task)()
        Dim dpi As Integer = 144
        Dim col As String = "rgb"

        For Each file In pdfFiles
            tasks.Add(Task.Run(Sub()
                                   Dim fileName = Path.GetFileNameWithoutExtension(file)
                                   Dim outputBase = Path.Combine(outputFolder, fileName)
                                   Dim args = $"draw -o ""{outputBase}_%d.png"" -F png -r {dpi} ""{file}"" 1"  'first page only
                                   Dim psi As New ProcessStartInfo(mutoolPath, args) With {
                                       .UseShellExecute = False,
                                       .CreateNoWindow = True,
                                       .RedirectStandardOutput = False,
                                       .RedirectStandardError = False
                                   }

                                   Using proc As Process = Process.Start(psi)
                                       proc.WaitForExit()
                                   End Using
                               End Sub))
        Next

        Task.WaitAll(tasks.ToArray())
    End Sub

    Sub RunMethod2(pdfFiles As String(), outputFolder As String)
        Dim tasks As New List(Of Task)()
        Dim dpi As Integer = 144
        Dim col As String = "rgb"
        Dim ext As String = "png"
        For Each file In pdfFiles
            tasks.Add(Task.Run(Sub()
                                   Dim doc As New Document(file)
                                   Dim page As Page = doc.LoadPage(0) 'render first page only
                                   Dim pix As Pixmap = page.GetPixmap(Nothing, dpi, col)
                                   Dim imgPath As String = Path.Combine(outputFolder, $"{Path.GetFileNameWithoutExtension(file)}.{ext}")
                                   pix.Save(imgPath, ext)
                               End Sub))
        Next
        Task.WaitAll(tasks.ToArray())
    End Sub

End Module

Execution result.

2 rounds executed to see how much HD file caching makes a difference. 2nd run is tiny bit faster as expected because the drive was able to pull some files from cache instead of reading again. 3rd run and more hardly makes a difference.

mutool.exe command line is 88.2 / 14.4 = 6.1 times faster ( or 610% )
mutool.exe version 1.25.4

Test Input files are 100 Architectural CAD files with vector content and transparency, About Arch E size 36x48".
The issue is much less noticed when the input are simple, smallformat documents. It gets worse when the content is more complex and the rendering engine has more to do. Obviously the issue cannot be noticed if it is tested with a couple of files only. It needs enough input to stress the CPU & RAM.

My observations and probably the reason for the slow performance:

CPU and Memory profile during execution of mupdf.net binding.
CPU hovers around 60 to 75%. Heavy memory allocation is observed. Large chunks of memory do not seem to be freed once the page is processed. Or the pixmaps are internally copied around multiple times.

CPU and Memory profile during execution of mutool.exe command line process

mutool.exe does almost 100% CPU time very stable during entire processing and does not allocate excessive amounts of RAM.
Memory usage is very stable with much less allocate & deallocate action.

the green box is during execution of mudraw.exe after the mupdf.net binding kicks in and the memory usage keeps rising.

Based on all the above that I am seeing, I am going to bet on a memory leak during processing or too much (unnecessary?) memory (de)allocation due to copying around large bitmaps. I could be wrong. Not an expert on interop.

I appreciate your time looking into this.
My goal by posting this is to make a great library even better. I am a perfectionist and try to improve slow & inefficient things. I do not need a fix for myself personally. If more info is needed feel free to reach out.

Best Regards

[MaksymTkachuk]

@CanadianHusky
Thanks much for your detailed info.
Let me check GetPixmap() module in detail, and contact you soon.
Thanks.

[MaksymTkachuk]

Hi @CanadianHusky
I’ve worked on resolving the memory usage issue and released an updated NuGet package: 3.2.9-rc.1.
dotnet add package MuPDF.NET --version 3.2.9-rc.1
We’d appreciate it if you could test it locally and share your feedback.
Thanks!

[CanadianHusky]

Attached video file shows both methods with live CPU and RAM usage. I even closed every non essential app, all browsers to leave as much ram as possible to the mupdf.net binding, but it is so hungry that it eats up every bit of ram.
Unfortunately version 3.2.9-rc.1 shows no improvement.
Best Regards,

capture-1.mp4

[MaksymTkachuk]

@CanadianHusky
Thank you for your ongoing testing.
Just a quick note—did you call Dispose() after using the pixmap?
For example: pix.Dispose();
Thanks.

[MaksymTkachuk]

And, Document also should be closed at the end.

pix.Dispose();
doc.Close();

[CanadianHusky]

No difference in memory use or timing.
I even forced explicit Garbage Collection. Still same behavior as in Video above.

 Sub RunMethod2(pdfFiles As String(), outputFolder As String)
        Dim tasks As New List(Of Task)()
        Dim dpi As Integer = 144
        Dim col As String = "rgb"
        Dim ext As String = "png"
        For Each file In pdfFiles
            tasks.Add(Task.Run(Sub()
                                   Dim doc As New Document(file)
                                   Dim page As Page = doc.LoadPage(0) 'render first page only
                                   Dim pix As Pixmap = page.GetPixmap(Nothing, dpi, col)
                                   Dim imgPath As String = Path.Combine(outputFolder, $"{Path.GetFileNameWithoutExtension(file)}.{ext}")
                                   pix.Save(imgPath, ext)
                                   pix.Dispose()
                                   doc.Close()
                                   GC.Collect()
                               End Sub))
        Next
        Task.WaitAll(tasks.ToArray())
    End Sub

[MaksymTkachuk]

@CanadianHusky
Thank you for your testing efforts.
I’ll review the issues again and follow up soon.
Best regards.

[MaksymTkachuk]

@CanadianHusky
I created new nuget release 3.2.9-rc.2
dotnet add package MuPDF.NET --version 3.2.9-rc.2
In this version, I added Dispose() for Page.
So please update your code and test again.

pix.Dispose()
page.Dispose()
doc.Close()
GC.Collect()

Thanks.

[CanadianHusky]

No difference. Still far too heavy memory allocation, same as in the video.

Observations:
reducing DPI from 144 down to 72 makes little difference in speed or memory usage when using mupdf.net binding. Still same excessive memory usage.
144 dpi : processing speed = 88 seconds
72 dpi : processing speed = 78 seconds ( only 12 % faster )

reducing DPI from 144 down to 72 makes while using mutool.exe reduces processing time from 14.5 seconds to 5.5 seconds! 163% faster ! In other words mutool.exe is 78 / 5.5 = 14 times faster than the binding at 72dpi. Just like I originally reported, over 10x.
mupdf.net binding never hits full 100% CPU time. Are there heavy synclocks ?
mutool.exe runs at constant 100% CPU time during the entire process.
What if the problem is not in the bindings/interop but the native runtime, version difference ?
mutool.exe I use for testing is 1.25.4

[MaksymTkachuk]

@CanadianHusky
I tested the exact same code in a .NET project and didn’t observe any significant memory allocation.
In any case, I’ll continue working on improvements.
Thanks a lot!

[CanadianHusky]

In order to find the source of the problem you need to be able to recreate it on your system.
please use the attached sample file and create 100 copies of it in c:\temp
What is your test timing at 144 dpi for mutool.exe and the binding ?
The real data I use for testing is 100 different files but the below single file is representative of the rest.
You probably need to have a cpu with lots of cores. On a CPU with 2 or 4 cores the .Net framework may not spawn enough parallel threads. My cpu has 12 cores and 24 threads, firing 24 parallel tasks.
My sample code is running on .net framework 4.8, not dotnet core. I am not sure if that makes a difference but it is a different runtime.
I am curious what your speed test results are for 100 files.
Good luck

input.pdf