News:

Want to get involved in developing SMF, then why not lend a hand on our github!

Main Menu

Page Load Times Issue

Started by MobileCS, February 16, 2018, 12:31:02 PM

Previous topic - Next topic

MobileCS

I've noticed the page load times on my forum have tripled recently. I've been doing all sorts of tests the past few days and found something interesting.

If a thread has only one post, the page load time is right where it normally should be (around 50ms).




Now if I just add a single reply to the thread, the page load time more than triples (170ms)



I can consistently reproduce these results. If I delete the reply, the load time drops back to 50ms. All posts on the forum that contain at least one reply is effected.

If you look at the screenshots, the posts only contain the word "test" and nothing else. It's not like there is a whole bunch of extra data that has to be transferred over.

Is this a bug? Any ideas where to look to solve this issue?

MobileCS

Debug information:

SMF 2.0.15

Page created in 0.006 seconds with 21 queries.

Templates: 3: index (default), Display (default), QRR (default).
Sub templates: 6: init, html_above, body_above, main, body_below, html_below.
Language files: 1: index+Modifications.english (default).
Style sheets: 0: .
Files included: 18 - 620KB. (./index.php, ./Settings.php, ./Sources/QueryString.php, ./Sources/Subs.php, ./Sources/Errors.php, ./Sources/Load.php, ./Sources/Security.php, ./Sources/Subs-Db-mysql.php, ./Sources/Subs-UsersOnlineToday.php, ./Sources/QRR.subs.php, ./Themes/default/index.template.php, ./Themes/default/languages/index.english.php, ./Themes/default/languages/Modifications.english.php, ./Sources/Display.php, ./Themes/default/Display.template.php, ./Sources/MetaTags.php, ./Themes/default/QRR.template.php)
Queries used: 21.

         SELECT variable, value
         FROM smf_settings
   in .../Sources/Load.php line 146, which took 0.00017095 seconds at 0.00061893 into request.

      SELECT data
      FROM smf_sessions
      WHERE session_id = 'ec0309259a7337c602cc76bc64af58fa'
      LIMIT 1
   in .../Sources/Load.php line 2468, which took 0.00033188 seconds at 0.00119901 into request.

            SELECT mem.*, IFNULL(a.id_attach, 0) AS id_attach, a.filename, a.attachment_type
            FROM smf_members AS mem
               LEFT JOIN smf_attachments AS a ON (a.id_member = 6)
            WHERE mem.id_member = 6
            LIMIT 1
   in .../Sources/Load.php line 389, which took 0.000103 seconds at 0.00164294 into request.

         SELECT variable, value, id_member, id_theme
         FROM smf_themes
         WHERE id_member IN (-1, 0, 6)
            AND id_theme = 1
   in .../Sources/Load.php line 1439, which took 4.387E-5 seconds at 0.00181007 into request.

         SELECT variable, value
         FROM smf_settings
   in .../Sources/Load.php line 146, which took 0.00017309 seconds at 0.00062084 into request.

      SELECT data
      FROM smf_sessions
      WHERE session_id = 'ec0309259a7337c602cc76bc64af58fa'
      LIMIT 1
   in .../Sources/Load.php line 2468, which took 0.00033998 seconds at 0.00120497 into request.

            SELECT mem.*, IFNULL(a.id_attach, 0) AS id_attach, a.filename, a.attachment_type
            FROM smf_members AS mem
               LEFT JOIN smf_attachments AS a ON (a.id_member = 6)
            WHERE mem.id_member = 6
            LIMIT 1
   in .../Sources/Load.php line 389, which took 6.413E-5 seconds at 0.00166488 into request.

         SELECT
            c.id_cat, b.name AS bname, b.description, b.num_topics, b.member_groups,
            b.id_parent, c.name AS cname, IFNULL(mem.id_member, 0) AS id_moderator,
            mem.real_name, b.id_board, b.child_level,
            b.id_theme, b.override_theme, b.count_posts, b.id_profile, b.redirect,
            b.unapproved_topics, b.unapproved_posts, t.approved, t.id_member_started
         FROM smf_boards AS b
            INNER JOIN smf_topics AS t ON (t.id_topic = 48509)
            LEFT JOIN smf_categories AS c ON (c.id_cat = b.id_cat)
            LEFT JOIN smf_moderators AS mods ON (mods.id_board = t.id_board)
            LEFT JOIN smf_members AS mem ON (mem.id_member = mods.id_member)
         WHERE b.id_board = t.id_board
   in .../Sources/Load.php line 678, which took 0.00021291 seconds at 0.00177693 into request.

         SELECT variable, value, id_member, id_theme
         FROM smf_themes
         WHERE id_member IN (-1, 0, 6)
            AND id_theme = 1
   in .../Sources/Load.php line 1439, which took 3.409E-5 seconds at 0.0020349 into request.

      SELECT
         t.num_replies, t.num_views, t.locked, ms.subject, t.is_sticky, t.id_poll,
         t.id_member_started, t.id_first_msg, t.id_last_msg, t.approved, t.unapproved_posts,
         IFNULL(lt.id_msg, IFNULL(lmr.id_msg, -1)) + 1 AS new_from
         , id_previous_board, id_previous_topic
      FROM smf_topics AS t
         INNER JOIN smf_messages AS ms ON (ms.id_msg = t.id_first_msg)
         LEFT JOIN smf_log_topics AS lt ON (lt.id_topic = 48509 AND lt.id_member = 6)
         LEFT JOIN smf_log_mark_read AS lmr ON (lmr.id_board = 5 AND lmr.id_member = 6)
      WHERE t.id_topic = 48509
      LIMIT 1
   in .../Sources/Display.php line 195, which took 0.00015903 seconds at 0.00237799 into request.

      SELECT poster_time
      FROM smf_messages
      WHERE id_msg = 653848
      LIMIT 1
   in .../Sources/Display.php line 240, which took 2.313E-5 seconds at 0.0025568 into request.

         SELECT
            lo.id_member, lo.log_time, mem.real_name, mem.member_name, mem.show_online,
            mg.online_color, mg.id_group, mg.group_name
         FROM smf_log_online AS lo
            LEFT JOIN smf_members AS mem ON (mem.id_member = lo.id_member)
            LEFT JOIN smf_membergroups AS mg ON (mg.id_group = CASE WHEN mem.id_group = 0 THEN mem.id_post_group ELSE mem.id_group END)
         WHERE INSTR(lo.url, 's:5:\"topic\";i:48509;') > 0 OR lo.session = 'ec0309259a7337c602cc76bc64af58fa'
   in .../Sources/Display.php line 406, which took 0.00023699 seconds at 0.00269699 into request.

      SELECT id_msg, id_member, approved
      FROM smf_messages
      WHERE id_topic = 48509
      ORDER BY id_msg
      LIMIT 0, 20
   in .../Sources/Display.php line 820, which took 2.503E-5 seconds at 0.00298595 into request.

   SELECT subject, body
   FROM smf_messages
   WHERE id_msg = 653847
   in .../Sources/MetaTags.php line 46, which took 2.003E-5 seconds at 0.00302792 into request.

         SELECT sent, id_topic
         FROM smf_log_notify
         WHERE (id_topic = 48509 OR id_board = 5)
            AND id_member = 6
         LIMIT 2
   in .../Sources/Display.php line 869, which took 2.003E-5 seconds at 0.00306988 into request.

            SELECT
               a.id_attach, a.id_folder, a.id_msg, a.filename, a.file_hash, IFNULL(a.size, 0) AS filesize, a.downloads, a.approved,
               a.width, a.height,
               IFNULL(thumb.id_attach, 0) AS id_thumb, thumb.width AS thumb_width, thumb.height AS thumb_height
            FROM smf_attachments AS a
               LEFT JOIN smf_attachments AS thumb ON (thumb.id_attach = a.id_thumb)
            WHERE a.id_msg IN (653847, 653848)
               AND a.attachment_type = 0
   in .../Sources/Display.php line 965, which took 2.718E-5 seconds at 0.00310683 into request.

         SELECT
         IFNULL(lo.log_time, 0) AS is_online, IFNULL(a.id_attach, 0) AS id_attach, a.filename, a.attachment_type,
         mem.signature, mem.personal_text, mem.location, mem.gender, mem.avatar, mem.id_member, mem.member_name,
         mem.real_name, mem.email_address, mem.hide_email, mem.date_registered, mem.website_title, mem.website_url,
         mem.birthdate, mem.member_ip, mem.member_ip2, mem.icq, mem.aim, mem.yim, mem.msn, mem.posts, mem.last_login,
         mem.karma_good, mem.id_post_group, mem.karma_bad, mem.lngfile, mem.id_group, mem.time_offset, mem.show_online,
         mem.buddy_list, mg.online_color AS member_group_color, IFNULL(mg.group_name, '') AS member_group,
         pg.online_color AS post_group_color, IFNULL(pg.group_name, '') AS post_group, mem.is_activated, mem.warning,
         CASE WHEN mem.id_group = 0 OR mg.stars = '' THEN pg.stars ELSE mg.stars END AS stars
         FROM smf_members AS mem
         LEFT JOIN smf_log_online AS lo ON (lo.id_member = mem.id_member)
         LEFT JOIN smf_attachments AS a ON (a.id_member = mem.id_member)
         LEFT JOIN smf_membergroups AS pg ON (pg.id_group = mem.id_post_group)
         LEFT JOIN smf_membergroups AS mg ON (mg.id_group = mem.id_group)
         WHERE mem.id_member = 6
   in .../Sources/Load.php line 1041, which took 0.00025296 seconds at 0.0031569 into request.

         SELECT *
         FROM smf_themes
         WHERE id_member = 6
   in .../Sources/Load.php line 1070, which took 2.193E-5 seconds at 0.00342798 into request.

         SELECT
            id_msg, icon, subject, poster_time, poster_ip, id_member, modified_time, modified_name, body,
            smileys_enabled, poster_name, poster_email, approved,
            id_msg_modified < 653849 AS is_read
         FROM smf_messages
         WHERE id_msg IN (653847, 653848)
         ORDER BY id_msg
   in .../Sources/Display.php line 1001, which took 2.289E-5 seconds at 0.00348091 into request.

      UPDATE smf_log_activity
      SET
         hits = hits + 1
      WHERE date = '2018-02-16'
   in .../Sources/Subs.php line 3065, which took 6.7E-5 seconds at 0.00355697 into request.

               SELECT code, filename, description
               FROM smf_smileys
   in .../Sources/Subs.php line 2524, which took 5.913E-5 seconds at 0.0040679 into request.

vbgamer45

None of those query times seem high.
It looks like a webserver issue.
Community Suite for SMF - Take your forum to the next level built for SMF, Gallery,Store,Classifieds,Downloads,more!

SMFHacks.com -  Paid Modifications for SMF

Mods:
EzPortal - Portal System for SMF
SMF Gallery Pro
SMF Store SMF Classifieds Ad Seller Pro

MobileCS

There is 0 load on the webserver.

It's strange that just replying to a post would add that much of a page load time.

butch2k

Page created in 0.006 seconds with 21 queries, it's OK, no issue with SMF. Could you check your apache/NGinX settings ? possibly the Gzip/brotly settings ? it's either the webserver taking a long time to send the page once SMF generated it or the network. Any timing details for the 0.170ms ? Connect/Waiting/content download ?


MobileCS

Here are the timing details for the request :


butch2k

What webserver are you using ? If possible post the configuration of the virtual host.

MobileCS

I'm using Nginx in front of Apache.

I just disabled gzip in Nginx and that sort of solved the issue. I now see the 50ms response time, but there is 100ms in the "receiving" column now. At least I know where the issue lies, it's just a matter of tweaking the gzip settings to see what's causing the issue.

drewactual

Quote from: MobileCS on February 17, 2018, 03:35:12 PM
I'm using Nginx in front of Apache.

I just disabled gzip in Nginx and that sort of solved the issue. I now see the 50ms response time, but there is 100ms in the "receiving" column now. At least I know where the issue lies, it's just a matter of tweaking the gzip settings to see what's causing the issue.

arantor gave me a clue about glib (if that is what you're using server side).... it cleaned my page right up.

either use the smf managed compression, or use the server side managed compression- not both. 

i found that the server side (using zlib) didn't play nicely with several functions (namely: quote, alerts, mentions), but compression enabled via SMF was fine.

two other things i've seen mess with timing on SMF side:  a bunch of noise in the DB- which is cured by running optimize tables function in admin/db area... dump your cache, too- start again..

speaking of cache's- check out the OPCache thread/topic under this one.  this single optimization is the king of speed for my site, with moving the avatars tied with pagespeed optimizations of images tying for second place.  my front page loads in less than 1.5 seconds first load, and even faster after local (client) file caches are made (done through memchached and moving away from file based sessions)

http2 and using pushes for minified and combined css and js also pushes the speed into the red.

MobileCS

1) I've never heard of glib - what is that? Did you mean zlib?

2) It's my understanding that server side compression will always use less resources than letting PHP handle it.

3) I do have OPCache, I would never run PHP (except for debugging) without it. It's makes a night and day difference.

4) I also have HTTP2 enabled in Nginx, great performance boost for web browsers that supports it.

The first load on my forum is ~220ms, most of that is connecting and TLS setup. I don't think I'm able to get it any better than that.


drewactual

1- yes, zlib... my brain and fingers don't fire in sync... bumped in the head one too many times
2- agreed in your understanding, however, at least with my site and server config, zlib makes a mess where allowing the script to compress doesn't. by mess i mean strange things happen to scripts. 

Advertisement: