Hi,
I am noticing an enormous performance difference between the first and a subsequent conversion of a PDF document. After a while of rest, it gets to the low performance again. I am using the sample DocIO_AspNetWebApi_ServiceApplication to convert word documents created in Asp.Net Core to PDF via this service in Asp.Net MVC.
To find out what is going on, I inserted some timing.
This is the conversion code:
[AcceptVerbs("Post")]
public HttpResponseMessage ConvertToPdf()
{
var timer = Stopwatch.StartNew();
HttpResponseMessage httpResponseMessage;
using (Stream stream = Request.Content.ReadAsStreamAsync().Result)
{
try
{
//Loads the Word document from stream
using (WordDocument wordDocument = new WordDocument(stream))
{
Logger.Trace("PDF Stream read in {0}ms", timer.ElapsedMilliseconds);
//Initializes the ChartToImageConverter for converting charts during Word to PDF conversion
wordDocument.ChartToImageConverter = new ChartToImageConverter
{
ScalingMode = Syncfusion.OfficeChart.ScalingMode.Normal
};
//Creates an instance of the DocToPDFConverter
var docToPdfConverter = new DocToPDFConverter();
//Converts Word document into PDF document
PdfDocument pdfDocument = docToPdfConverter.ConvertToPDF(wordDocument);
Logger.Trace("PDF converted in {0}ms", timer.ElapsedMilliseconds);
//Saves the PDF document to response stream
var memoryStream = new MemoryStream();
pdfDocument.Save(memoryStream);
Logger.Trace("PDF saved in {0}ms", timer.ElapsedMilliseconds);
memoryStream.Position = 0;
httpResponseMessage = new HttpResponseMessage(HttpStatusCode.OK)
{
Content = new StreamContent(memoryStream)
};
pdfDocument.Dispose();
}
}
catch(Exception)
{
httpResponseMessage = new HttpResponseMessage(HttpStatusCode.ExpectationFailed);
}
}
Logger.Trace("PDF Convert finished in {0}ms", timer.ElapsedMilliseconds);
return httpResponseMessage;
}
The timing collected (and I have seen worse) is
First time taking 9s:
2018-11-15 22:00:18.7342|TRACE|1.0.0.0|wordtopdf|PDF Converted in 2114ms|
2018-11-15 22:03:39.4332|RACE|1.0.0.0|wordtopdf|PDF Stream read in 3779ms|
2018-11-15 22:03:44.5702|TRACE|1.0.0.0|wordtopdf|PDF converted in 8918ms|
2018-11-15 22:03:44.9372|TRACE|1.0.0.0|wordtopdf|PDF saved in 9285ms|
The second time, same document:
2018-11-15 22:03:51.6282|TRACE|1.0.0.0|wordtopdf|PDF Stream read in 55ms|
2018-11-15 22:03:53.2232|TRACE|1.0.0.0|wordtopdf|PDF converted in 1650ms|
2018-11-15 22:03:53.3942|TRACE|1.0.0.0|wordtopdf|PDF saved in 1820ms|
2018-11-15 22:03:53.4352|TRACE|1.0.0.0|wordtopdf|PDF Convert finished in 1861ms|
This difference is not random (maybe the server busy), it repeats itself after a few minutes:
2018-11-15 22:14:57.2182|TRACE|1.0.0.0|wordtopdf|PDF Stream read in 4020ms|
2018-11-15 22:15:03.1012|TRACE|1.0.0.0|wordtopdf|PDF converted in 9904ms|
2018-11-15 22:15:03.4912|TRACE|1.0.0.0|wordtopdf|PDF saved in 10294ms|
2018-11-15 22:15:03.6272|TRACE|1.0.0.0|wordtopdf|PDF Convert finished in 10430ms|
2018-11-15 22:15:56.6192|TRACE|1.0.0.0|wordtopdf|PDF Stream read in 57ms|
2018-11-15 22:15:58.3902|TRACE|1.0.0.0|wordtopdf|PDF converted in 1827ms|
2018-11-15 22:15:58.5942|TRACE|1.0.0.0|wordtopdf|PDF saved in 2031ms|
2018-11-15 22:15:58.6252|TRACE|1.0.0.0|wordtopdf|PDF Convert finished in 2062ms|
Any idea what this can be?
