Performance drop after update to 2.5

[suntrop]

Hi all! I updated some of my PW installations (v. 2.5.3) and one is facing performance issues.

A module (on that site) sends about 400 emails and it took usually 90 seconds. Now it takes more than 11 minutes. Before it was about 5 mails per second on average. Now it takes about 2 seconds per email. I didn't change the code – I just updated PW.

That's how my module works:

1. Editor creates a page (Newsletter template)
2. Editor adds child-pages (Section template)
3. Editor pastes into a textarea all emails/subscribers (and hit "dispatch")
4. Module grabs the Newsletter page ( $mailtemplate = $newsletter->render() )
   (template from #1, which "displays" all child pages as sections like a blog listing)
5. Module makes some edits (convert path to URL, copy convert to plain text, etc.)
6. Module constructs (via Swift mailer) email once (subject and body)
7. Send each subscriber an email (foreach array with email addresses)
   Within my foreach I only validate the email and save to a log file after sending

I really was surprised to see that big increase. I am sending those newsletters since june '14 and never was there something above 180 seconds.

Swift mailer is configured to pause after 200 mails for 5 seconds. SMTP is mandrill, which allows a lot more mails to dispatch at once. So there is no problem I think.

[netcarver]

@suntrop

Sorry to hear about the slow-down. What version of PW did you upgrade from?

[sforsman]

Hello!

Without one seeing actual code, it will be very difficult to say/guess unless you narrow down the bottleneck a bit. If you don't want to give us the code, could you clock the different stages and tell us the results?

[cstevensjr]

You should open an issue in Github so this can get prompt attention.  

A quick observation, Your subject says "Performance drop after update to 2.5", however I believe you are experiencing performance problems only on one website? Correct?  Put another way, you have not stated that your other upgrades are exhibiting any performance degradation.

[suntrop]

It was an update from v. 2.4 and I'll try to "cut down" my code to the essential part for sending emails. The other sites I updated don't have that module (hadn't put that into this context, sorry).

[sforsman]

It was an update from v. 2.4 and I'll try to "cut down" my code to the essential part for sending emails. The other sites I updated don't have that module (hadn't put that into this context, sorry).

Great, then I can try to help you. I'm certainly interested in the steps 4-7, that you described in your OP.

It would help even more if you could add the timers around the different phases of your process, like this:

$timer = "newsletter_debug";

Debug::timer($timer."1");
// Phase 1 code
Debug::saveTimer($timer."1", "Phase 1");
Debug::timer($timer."2");
// Phase 2 code
Debug::saveTimer($timer."2", "Phase 2");
Debug::timer($timer."3");
// Phase 3 code
Debug::saveTimer($timer."3", "Phase 3");
Debug::timer($timer."4");
// Phase 4 code
Debug::saveTimer($timer."4", "Phase 4");

If you can enable debug-mode, then you could copy the timers directly from your admin site. If not, then you could just save them to disk. You can do this with

file_put_contents(wire('config')->paths->logs."/timers.txt", var_export(Debug::getSavedTimers(),true), FILE_APPEND);

Then just surf to your logs -folder (site/assets/logs) and post us the contents of the timers.txt -file.

[Nico Knoll]

Never saw this Debug functions before. Great thing! Thank you!

[Soma]

Great, then I can try to help you. I'm certainly interested in the steps 4-7, that you described in your OP.

It would help even more if you could add the timers around the different phases of your process, like this:

$timer = "newsletter_debug";

Debug::timer($timer."1");
// Phase 1 code
Debug::saveTimer($timer."1", "Phase 1");
Debug::timer($timer."2");
// Phase 2 code
Debug::saveTimer($timer."2", "Phase 2");
Debug::timer($timer."3");
// Phase 3 code
Debug::saveTimer($timer."3", "Phase 3");
Debug::timer($timer."4");
// Phase 4 code
Debug::saveTimer($timer."4", "Phase 4");

If you can enable debug-mode, then you could copy the timers directly from your admin site. If not, then you could just save them to disk. You can do this with

file_put_contents(wire('config')->paths->logs."/timers.txt", var_export(Debug::getSavedTimers(),true), FILE_APPEND);

Then just surf to your logs -folder (site/assets/logs) and post us the contents of the timers.txt -file.

Or just use $log ?

$timer = Debug::timer();
...
$log->save("mylog", "phase 1: " . Debug::timer($timer));

$timer = Debug::timer();
...
$log->save("mylog", "phase 2: " . Debug::timer($timer));

Will create a log in site/assets/logs/ as mylog.txt

[suntrop]

sforsman and Soma, thanks for that – I'll try this the next days. Didn't know about those debug timers, but it looks like it gives the microtime. Will post an update the next days.

[sforsman]

Or just use $log ?

$timer = Debug::timer();
...
$log->save("mylog", "phase 1: " . Debug::timer($timer));

$timer = Debug::timer();
...
$log->save("mylog", "phase 2: " . Debug::timer($timer));

Will create a log in site/assets/logs/ as mylog.txt

Those you can't see from the debug-mode admin site's timers, which I was primarily aiming at

[Soma]

Ah nice! I think I kinda ignored or forgot the little appended note there in the timers tab. This is relatively new.

I wasn't aware of the context when writing thinking about templates!

[suntrop]

It wasn't that easy to check where it comes from. Seems the most of the time is spent on sending/waiting for my email. I don't know why this is that high now. The first email takes about 6 seconds. Following mails are ca. 1.5 to 1.9 seconds. Saving the log entry takes about .3 seconds. I am using Swiftmailer and can have a look at the EchoLogger plugin.

Thanks for the Debug::timer() It was quite nice in that situation 

[sforsman]

Just out of curiosity, does it make any difference for you if you try using Mandrill directly with one of their IP addresses? Such as 54.204.208.115.

[suntrop]

Do you mean instead of the host smtp.mandrill.com? I haven't seen that in their docs.