Simple Plugin performance too slow.. but only sometimes

(0) Share

Report

Posted on by Adrian Tedeschi

Hi community,

I have developed a very simple plugin, just some calculations on some Account fields (3 fields), registered at Update message, filtered by those fields, pre-operation, sync, running on D365.

Usually the plugin takes <50 to run, but sometimes it takes a long wait, >15000.

I have read around about first execution of plugin being slow after some inactivity, but can't belive this is the way, as it makes some users having to wait a long time until save completes, let's say 15 / 20 seconds, and in my oppinion the plugin useless.

Actually, this happens to me in other plugins also, but I choose this case as it's a very simple calculation, no queries, no external services, only a simple calc.

Some execution statistics:

Captura-de-pantalla-2016_2D00_12_2D00_15-a-las-10.18.17.png

Thanks in advance!!!

Plugin Execute code

            IPluginExecutionContext context = (IPluginExecutionContext)
                serviceProvider.GetService(typeof(IPluginExecutionContext));

            if (!context.InputParameters.Contains("Target")) return;
            var target = (Entity)context.InputParameters["Target"];

            Entity image;
            if(!context.PreEntityImages.TryGetValue("Target", out image))
            {
                image = new Entity("account");
            }

            //NOTHING SPECIAL HERE
            var accountWrapper = new AccountWrapper(image);
            accountWrapper.UpdateWith(target);

            //THIS CLASS JUST HAS THE CALCULATION LOGIC, INCLUDED BELOW FOR REFERENCE
            var accountNextContactLogic = new AccountNextContactLogic();
            var fechaProximoContactoNueva = accountNextContactLogic.ComputeAccountNextContactDate(accountWrapper);
            if (accountWrapper.FechaDeProximoContacto != fechaProximoContactoNueva)
            {
                target["ent_fechadeproximocontacto"] = fechaProximoContactoNueva;
            }

AccountNextContactLogic code

                var proximoContacto = (account.FechaUltimaOperacion > account.FechaUltimaActividad || !account.FechaUltimaActividad.HasValue)
                    ? account.FechaUltimaOperacion
                    : account.FechaUltimaActividad;
                //agrego frecuencia
                proximoContacto = proximoContacto?.AddDays(account.FrecuenciaContacto ?? 0);
                //verifico que no supere la fecha no contactar antes de
                if(account.NoContactarAntesDe > proximoContacto) proximoContacto = account.NoContactarAntesDe;

                return fechaProximoContactoNueva;

*This post is locked for comments

All responses (10)

Answers (0)

Suggested answer

Nithya Gopinath 17,074 on at

Like (0)

Report

RE: Simple Plugin performance too slow.. but only sometimes

Hi Andrian,

Have you gone throgh the following link. It helps you to solve some common plugin mistakes affecting its performance.

community.dynamics.com/.../common-plugins-performance-mistakes
Adrian Tedeschi on at

Like (0)

Report

RE: Simple Plugin performance too slow.. but only sometimes

Sorry for the delay. I tested the problem in a non-production environment. No logged in users (just the user I'm using for testing). No entity updates, just some trace output.

The problem is still there. The pattern seems to be inactivity time, I mean after some minutes of inactivity, the first call to the plugin takes >20 seconds. After that it runs ok.

What I've discovered is that if I don't use the tracing service to output log information, the problem seems to get solved. It's a little bit difficult to be sure, as I don't have any individual plugin execution logged and have to guess, or use the global plugin performance indicator (which is an average).

UPDATE: no, the problem wasn't solved disabling trace output. It's still there. After a while not using the plugin, it takes a long time to run again.
Adrian Tedeschi on at

Like (0)

Report

RE: Simple Plugin performance too slow.. but only sometimes

I will test it.

Meanwhile, I assume this is not a matter of locks and transactions, as this plugin doesn't make any data read/write, just some calculations with current data and setting some fields of entity being updated. As it's pre-operation, I'm not sending any update message just change some field values and let pipeline do its job.
Adrian Tedeschi on at

Like (0)

Report
RE: Simple Plugin performance too slow.. but only sometimes

at the beginning of Execute I take te current time, then I use that time to measure elapsed time in different parts of code and output it to plugin trace. like this:

var start = DateTime.Now; ... ... var elapsed = (DateTime.Now - start).ToMiliseconds(); _logger.Info($"Some text ({elapsed})");
Suggested answer

Andreas Cieslik 9,265 on at

Like (0)

Report

RE: Simple Plugin performance too slow.. but only sometimes

Referring to this document this could also occur on a productive system, when other users do queries on the same account table and data and cause a lock on database level:

blogs.msdn.microsoft.com/.../optimal-use-of-transactions-within-microsoft-dynamics-crm-plug-ins

Can you verify this behavior on a dev system without concurrent jobs and users?
Andreas Cieslik 9,265 on at

Like (0)

Report

RE: Simple Plugin performance too slow.. but only sometimes

How do you actually measure the execution times in your code?
Adrian Tedeschi on at

Like (0)

Report

RE: Simple Plugin performance too slow.. but only sometimes

Yes Andreas,

I've checked it. The problem with those statistics is that they are statistics, so they show me average times, which are not so bad, but my problem is just on some executions, where it takes a long time.

I've noticed, usually the very slow performance is after some inactivity (let's say 10 / 15 minutes without execution). Don't know if it has something to do with the problem.

Just in case I'm not seeing something, this is the current statistics info. % errors in 2% is because some bugs already solved:
Suggested answer

Andreas Cieslik 9,265 on at

Like (0)

Report

RE: Simple Plugin performance too slow.. but only sometimes

Have you used or compared it with this method:

blogs.msdn.microsoft.com/.../monitoring-and-statistics-for-sandboxed-plugins
Adrian Tedeschi on at

Like (0)

Report

RE: Simple Plugin performance too slow.. but only sometimes

Thanks Andreas,

There is just this custom plugin, the rest are system processes.

I logged running time inside the plugin, and find out that the actual running time for Execute method is much less than the plugin total time, as you can see in the image:

Actually the gap between the first two steps is too big, but nothing compared with the total plugin running time of 16000.
Suggested answer

Andreas Cieslik 9,265 on at

Like (0)

Report

RE: Simple Plugin performance too slow.. but only sometimes

Hi Adrian,

are you using any other account plugin ins and workflow?

During the long timings could find something suspecious in the system jobs list?

What happens if you remove all custom code and leave only the empty plugin execute method alone. How does it change?

If still issue is there I would recommend to open a ticket with Microsoft.

Cheers,

Andreas