DNN Community Blog

The Community Blog is a personal opinion of community members and by no means the official standpoint of DNN Corp or DNN Platform. This is a place to express personal thoughts about DNNPlatform, the community and its ecosystem. Do you have useful information that you would like to share with the DNN Community in a featured article or blog? If so, please contact .

The use of the Community Blog is covered by our Community Blog Guidelines - please read before commenting or posting.


Diagnosing and Fixing Slow Pages Loading in DNN Sites

Introduction

Sometimes DNN site super users could notice some performance issues in their sites. For example, the some or many pages take a very long time to load (2 to 3 minutes or more). In some cases where the site is operating in a web-farm, the slow page loading is more noticeably visible. There are a few reasons for these symptoms and I will explain how to diagnose and fix these issues in this article.

Note: my test site and images are based on DNN Engage version 9.2.0 (under development now), but this could apply to previous releases and other products (Platform/Basic/Content) as well. Also notice that some of these enhanced logging entries were added as of DN 9.1.1. So, if your site is running an older version, you will not see some of these log entries. Also, remember to remove any extra logging details added during the investigation.

 

Diagnostics

The first thing to look for in such cases is to monitor the application pool instance ID. To enable logging this ID, there are few changes to do in the DotNetNuke.log4net.config file which is located in the site’s root folder:

<?xml version="1.0" encoding="utf-8" ?>

<log4net>

  <appender name="RollingFile" type="log4net.Appender.RollingFileAppender">

    <file value="Portals/_default/Logs/" />

    <datePattern value="yyyy.MM.dd'.log.resources'" />

    <rollingStyle value="Date" />

    <staticLogFileName value="false" />

    <appendToFile value="true" />

    <maximumFileSize value="10MB" />

    <maxSizeRollBackups value="5" />

    <lockingModel type="log4net.Appender.FileAppender+MinimalLock"/>

    <layout type="log4net.Layout.PatternLayout">

      <conversionPattern value="%d{yyyy-MM-dd HH:mm:ss.fffzzz} [%property{log4net:HostName}][D:%property{appdomain}][T:%thread][%level] %logger - %m%n" />

    </layout>

  </appender>

  <root>

    <level value="Error" />

    <appender-ref ref="RollingFile" />

  </root>

  <!-- the following are for app start/end diagnostics -->

  <logger name="DotNetNuke.Common.Initialize">

    <level value="INFO" />

  </logger>

  <logger name="DotNetNuke.Web.Common.Internal">

    <level value="ALL" />

  </logger>

  <logger name="DotNetNuke.Common.Globals">

    <level value="DEBUG" />

  </logger>

</log4net>

 

The {appdomain} variable will display the ASP.NET application domain ID of the running instance. You need to look in the log files of the site for this ID. If you notice this number keep showing higher and higher values in the logged data, then this is an indication of application being recycled very often. Each time the application is recycled, IIS (the w3wp process) will create a new instance of the application and kill the old instance. Each new instance will receive a new ID (usually the old ID + 1). It is common to see many ID’s being logged in few close lines if the site is being recycle so often. Here is an example of such logs:

2017-08-31 12:23:59.045-07:00 [DNN-PC104][D:11][T:35][INFO] DotNetNuke.Web.Common.Internal.DotNetNukeShutdownOverload - Watcher Activity: Changed. Path: C:\websites\engage\App_Data\_imagecache\22A1F9E52D7C7E020F163F900E4EAA2F1363B9E1.tmp

2017-08-31 12:25:19.362-07:00 [DNN-PC104][D:11][T:111][INFO] DotNetNuke.Web.Common.Internal.DotNetNukeHttpApplication - Application Ending

2017-08-31 12:25:19.369-07:00 [DNN-PC104][D:11][T:111][INFO] DotNetNuke.Common.Initialize - Application shutting down. Reason: The AppDomain shut down because of a change to the application level configuration.

ASP.NET Shutdown Info: IIS configuration change

HostingEnvironment initiated shutdown

HostingEnvironment caused shutdown

   at System.Environment.GetStackTrace(Exception e, Boolean needFileInfo)

   at System.Environment.get_StackTrace()

   at System.Web.Hosting.HostingEnvironment.InitiateShutdownInternal()

   at System.Web.Hosting.HostingEnvironment.InitiateShutdownWithoutDemand()

   at System.Web.Hosting.PipelineRuntime.StopProcessing()

2017-08-31 12:25:26.391-07:00 [DNN-PC104][D:11][T:111][TRACE] DotNetNuke.Web.Common.Internal.DotNetNukeHttpApplication - Disposing Lucene

2017-08-31 12:25:26.414-07:00 [DNN-PC104][D:11][T:105][INFO] DotNetNuke.Web.Common.Internal.DotNetNukeShutdownOverload - Watcher Activity: Changed. Path: C:\websites\engage\App_Data\Search

2017-08-31 12:25:26.415-07:00 [DNN-PC104][D:11][T:111][TRACE] DotNetNuke.Web.Common.Internal.DotNetNukeHttpApplication - Dumping all Application Errors

2017-08-31 12:25:26.419-07:00 [DNN-PC104][D:11][T:83][INFO] DotNetNuke.Web.Common.Internal.DotNetNukeShutdownOverload - Watcher Activity: Deleted. Path: C:\websites\engage\App_Data\Search\write.lock

2017-08-31 12:25:26.426-07:00 [DNN-PC104][D:11][T:111][TRACE] DotNetNuke.Web.Common.Internal.DotNetNukeHttpApplication - End Dumping all Application Errors

2017-08-31 12:25:26.436-07:00 [DNN-PC104][D:11][T:111][INFO] DotNetNuke.Web.Common.Internal.DotNetNukeHttpApplication - Application Ended

2017-08-31 12:25:59.926-07:00 [DNN-PC104][D:12][T:60][INFO] DotNetNuke.Web.Common.Internal.DotNetNukeHttpApplication - Application Starting (00:00:00.0000011)

2017-08-31 12:26:00.392-07:00 [DNN-PC104][D:12][T:60][INFO] DotNetNuke.Web.Common.Internal.DotNetNukeHttpApplication - Application Started (00:00:00.4678112)

2017-08-31 12:26:00.398-07:00 [DNN-PC104][D:12][T:60][INFO] DotNetNuke.Web.Common.Internal.DotNetNukeShutdownOverload - FCNMode = 2 (Modes: NotSet/Default=0, Disabled=1, Single=2)

2017-08-31 12:26:00.403-07:00 [DNN-PC104][D:12][T:60][TRACE] DotNetNuke.Web.Common.Internal.DotNetNukeShutdownOverload - DirMonCompletion count: 4

2017-08-31 12:26:00.410-07:00 [DNN-PC104][D:12][T:60][TRACE] DotNetNuke.Web.Common.Internal.DotNetNukeShutdownOverload - Added watcher for: C:\websites\engage\*.*

2017-08-31 12:26:08.913-07:00 [DNN-PC104][D:12][T:95][INFO] DotNetNuke.Common.Initialize - Application Initializing

2017-08-31 12:26:09.041-07:00 [DNN-PC104][D:12][T:83][INFO] DotNetNuke.Web.Common.Internal.DotNetNukeShutdownOverload - Watcher Activity: Deleted. Path: C:\websites\engage\App_Data\51Degrees\51Degrees-Premium.dat.02c2aef9-1e15-435e-9393-ad0e76088ae5.tmp

2017-08-31 12:26:09.056-07:00 [DNN-PC104][D:12][T:39][INFO] DotNetNuke.Web.Common.Internal.DotNetNukeShutdownOverload - Watcher Activity: Changed. Path: C:\websites\engage\App_Data\51Degrees

2017-08-31 12:26:09.063-07:00 [DNN-PC104][D:12][T:105][INFO] DotNetNuke.Web.Common.Internal.DotNetNukeShutdownOverload - Watcher Activity: Created. Path: C:\websites\engage\App_Data\51Degrees\51Degrees-Premium.dat.0c162469-075c-40b6-8cf2-8de67b5c3089.tmp

2017-08-31 12:26:09.070-07:00 [DNN-PC104][D:12][T:105][INFO] DotNetNuke.Web.Common.Internal.DotNetNukeShutdownOverload - Watcher Activity: Changed. Path: C:\websites\engage\App_Data\51Degrees\51Degrees-Premium.dat.0c162469-075c-40b6-8cf2-8de67b5c3089.tmp

2017-08-31 12:26:09.121-07:00 [DNN-PC104][D:12][T:105][INFO] DotNetNuke.Web.Common.Internal.DotNetNukeShutdownOverload - Watcher Activity: Changed. Path: C:\websites\engage\App_Data\51Degrees\51Degrees-Premium.dat.0c162469-075c-40b6-8cf2-8de67b5c3089.tmp

2017-08-31 12:26:13.463-07:00 [DNN-PC104][D:12][T:95][INFO] DotNetNuke.Common.Initialize - Application Initialized

2017-08-31 12:26:45.730-07:00 [DNN-PC104][D:12][T:8][INFO] DotNetNuke.Web.Common.Internal.DotNetNukeHttpApplication - Application Ending

2017-08-31 12:26:45.738-07:00 [DNN-PC104][D:12][T:8][INFO] DotNetNuke.Common.Initialize - Application shutting down. Reason: The AppDomain shut down because of a change to the application level configuration.

ASP.NET Shutdown Info: IIS configuration change

HostingEnvironment initiated shutdown

HostingEnvironment caused shutdown

   at System.Environment.GetStackTrace(Exception e, Boolean needFileInfo)

   at System.Environment.get_StackTrace()

   at System.Web.Hosting.HostingEnvironment.InitiateShutdownInternal()

   at System.Web.Hosting.HostingEnvironment.InitiateShutdownWithoutDemand()

   at System.Web.Hosting.PipelineRuntime.StopProcessing()

2017-08-31 12:26:45.760-07:00 [DNN-PC104][D:12][T:8][TRACE] DotNetNuke.Web.Common.Internal.DotNetNukeHttpApplication - Disposing Lucene

2017-08-31 12:26:45.769-07:00 [DNN-PC104][D:12][T:8][TRACE] DotNetNuke.Web.Common.Internal.DotNetNukeHttpApplication - Dumping all Application Errors

2017-08-31 12:26:45.774-07:00 [DNN-PC104][D:12][T:8][TRACE] DotNetNuke.Web.Common.Internal.DotNetNukeHttpApplication - End Dumping all Application Errors

2017-08-31 12:26:45.781-07:00 [DNN-PC104][D:12][T:8][INFO] DotNetNuke.Web.Common.Internal.DotNetNukeHttpApplication - Application Ended

2017-08-31 12:26:48.112-07:00 [DNN-PC104][D:13][T:28][INFO] DotNetNuke.Web.Common.Internal.DotNetNukeHttpApplication - Application Starting (00:00:00.0000007)

2017-08-31 12:26:48.580-07:00 [DNN-PC104][D:13][T:28][INFO] DotNetNuke.Web.Common.Internal.DotNetNukeHttpApplication - Application Started (00:00:00.4688888)

2017-08-31 12:26:48.585-07:00 [DNN-PC104][D:13][T:28][INFO] DotNetNuke.Web.Common.Internal.DotNetNukeShutdownOverload - FCNMode = 2 (Modes: NotSet/Default=0, Disabled=1, Single=2)

2017-08-31 12:26:48.591-07:00 [DNN-PC104][D:13][T:28][TRACE] DotNetNuke.Web.Common.Internal.DotNetNukeShutdownOverload - DirMonCompletion count: 4

2017-08-31 12:26:48.598-07:00 [DNN-PC104][D:13][T:28][TRACE] DotNetNuke.Web.Common.Internal.DotNetNukeShutdownOverload - Added watcher for: C:\websites\engage\*.*

2017-08-31 12:26:57.115-07:00 [DNN-PC104][D:13][T:95][INFO] DotNetNuke.Common.Initialize - Application Initializing

2017-08-31 12:27:01.747-07:00 [DNN-PC104][D:13][T:95][INFO] DotNetNuke.Common.Initialize - Application Initialized

2017-08-31 12:27:01.790-07:00 [DNN-PC104][D:13][T:83][INFO] DotNetNuke.Web.Common.Internal.DotNetNukeShutdownOverload - Watcher Activity: Changed. Path: C:\websites\engage\App_Data\51Degrees

2017-08-31 12:27:01.802-07:00 [DNN-PC104][D:13][T:83][INFO] DotNetNuke.Web.Common.Internal.DotNetNukeShutdownOverload - Watcher Activity: Deleted. Path: C:\websites\engage\App_Data\51Degrees\51Degrees-Premium.dat.0c162469-075c-40b6-8cf2-8de67b5c3089.tmp

2017-08-31 12:27:01.818-07:00 [DNN-PC104][D:13][T:83][INFO] DotNetNuke.Web.Common.Internal.DotNetNukeShutdownOverload - Watcher Activity: Changed. Path: C:\websites\engage\App_Data\51Degrees

2017-08-31 12:27:01.825-07:00 [DNN-PC104][D:13][T:79][INFO] DotNetNuke.Web.Common.Internal.DotNetNukeShutdownOverload - Watcher Activity: Created. Path: C:\websites\engage\App_Data\51Degrees\51Degrees-Premium.dat.42f8417f-91fb-4c41-a1be-91d10389459a.tmp

2017-08-31 12:27:01.831-07:00 [DNN-PC104][D:13][T:79][INFO] DotNetNuke.Web.Common.Internal.DotNetNukeShutdownOverload - Watcher Activity: Changed. Path: C:\websites\engage\App_Data\51Degrees\51Degrees-Premium.dat.42f8417f-91fb-4c41-a1be-91d10389459a.tmp

2017-08-31 12:27:01.882-07:00 [DNN-PC104][D:13][T:80][INFO] DotNetNuke.Web.Common.Internal.DotNetNukeShutdownOverload - Watcher Activity: Changed. Path: C:\websites\engage\App_Data\51Degrees\51Degrees-Premium.dat.42f8417f-91fb-4c41-a1be-91d10389459a.tmp

2017-08-31 12:27:36.787-07:00 [DNN-PC104][D:14][T:60][INFO] DotNetNuke.Web.Common.Internal.DotNetNukeHttpApplication - Application Starting (00:00:00.0000007)

2017-08-31 12:27:37.044-07:00 [DNN-PC104][D:14][T:60][INFO] DotNetNuke.Web.Common.Internal.DotNetNukeHttpApplication - Application Started (00:00:00.2582806)

2017-08-31 12:27:37.050-07:00 [DNN-PC104][D:14][T:60][INFO] DotNetNuke.Web.Common.Internal.DotNetNukeShutdownOverload - FCNMode = 2 (Modes: NotSet/Default=0, Disabled=1, Single=2)

2017-08-31 12:27:37.056-07:00 [DNN-PC104][D:14][T:60][TRACE] DotNetNuke.Web.Common.Internal.DotNetNukeShutdownOverload - DirMonCompletion count: 4

2017-08-31 12:27:37.064-07:00 [DNN-PC104][D:14][T:60][TRACE] DotNetNuke.Web.Common.Internal.DotNetNukeShutdownOverload - Added watcher for: C:\websites\engage\*.*

2017-08-31 12:27:39.521-07:00 [DNN-PC104][D:13][T:103][INFO] DotNetNuke.Web.Common.Internal.DotNetNukeHttpApplication - Application Ending

2017-08-31 12:27:39.528-07:00 [DNN-PC104][D:13][T:103][INFO] DotNetNuke.Common.Initialize - Application shutting down. Reason: The AppDomain shut down because of a change to the application level configuration.

ASP.NET Shutdown Info: IIS configuration change

HostingEnvironment initiated shutdown

HostingEnvironment caused shutdown

   at System.Environment.GetStackTrace(Exception e, Boolean needFileInfo)

   at System.Environment.get_StackTrace()

   at System.Web.Hosting.HostingEnvironment.InitiateShutdownInternal()

   at System.Web.Hosting.HostingEnvironment.InitiateShutdownWithoutDemand()

   at System.Web.Hosting.PipelineRuntime.StopProcessing()

2017-08-31 12:27:39.549-07:00 [DNN-PC104][D:13][T:103][TRACE] DotNetNuke.Web.Common.Internal.DotNetNukeHttpApplication - Disposing Lucene

2017-08-31 12:27:39.558-07:00 [DNN-PC104][D:13][T:103][TRACE] DotNetNuke.Web.Common.Internal.DotNetNukeHttpApplication - Dumping all Application Errors

2017-08-31 12:27:39.562-07:00 [DNN-PC104][D:13][T:103][TRACE] DotNetNuke.Web.Common.Internal.DotNetNukeHttpApplication - End Dumping all Application Errors

2017-08-31 12:27:39.567-07:00 [DNN-PC104][D:13][T:103][INFO] DotNetNuke.Web.Common.Internal.DotNetNukeHttpApplication - Application Ended

2017-08-31 12:27:43.975-07:00 [DNN-PC104][D:14][T:105][INFO] DotNetNuke.Common.Initialize - Application Initializing

2017-08-31 12:27:44.034-07:00 [DNN-PC104][D:14][T:93][INFO] DotNetNuke.Web.Common.Internal.DotNetNukeShutdownOverload - Watcher Activity: Changed. Path: C:\websites\engage\App_Data\51Degrees

2017-08-31 12:27:44.046-07:00 [DNN-PC104][D:14][T:91][INFO] DotNetNuke.Web.Common.Internal.DotNetNukeShutdownOverload - Watcher Activity: Deleted. Path: C:\websites\engage\App_Data\51Degrees\51Degrees-Premium.dat.42f8417f-91fb-4c41-a1be-91d10389459a.tmp

 

Next, if we notice an excessive recycling behavior in the site, we need to diagnose further to see what causes this. From experiencing such cases, there are few areas to look into as explained in the following sections.

Is your site running in a slow I/O environment?

This is the major reason for such issues. Such cases happen when running the site in a virtual machine (VM) or when running in a web-farm with shared storage over NAS/SAN drives over a LAN. In such cases, the I/O processes are slower than in a physical machine with local hard drive. The reason behind the restarts is that ASP.NET creates a file monitoring object for the whole web site (this is the default behavior unless overridden through the “fcnMode” configuration setting). This monitor will receive notifications from the Windows operating system when any file under the site’s root folder changes (this includes: create/write/delete operations). When the I/O subsystem is slow, it seems the OS can’t report all the events in a timely manner and combines many of these into one “overwhelming” message. ASP.NET is designed to restart/recycle the application when certain (special) files are changed or certain folders have any file changed within; for example, the “bin” folder. The “overwhelming” event will cause ASP.NET to restart the site as a precautionary measure thinking there might be some changes occured in these special files/folders.

In a DNN file there are many files being added/created/deleted; such as, cached pages, cached images, temporary files, search index files, user uploaded files, log4net log files (under /Portal/_default/logs), and few others. These will create a lot of notifications in the operating system and might trigger an “overwhelming” event that causes a site restart. 

In order to reduce the activity of such files, we need to need to move these files outside the root side. Usually this is possible for physical or on premise environment but not if you are running in a cloud environment. For cached pages, we can use in-memory instead of file system caching. For log files, we can redirect these to folder in the local file system outside the IIS site. To do this, replace this line in DotNetNuke.log4net.config file (by default it points site storage which might be the shared storage in web-farms):

       <file value="Portals/_default/Logs/" />

 

With one that points to a specific/absolute location in the physical (or VM) machine:

       <file value="C:\DNN\Logs\" />

 

This change will prevent the monitoring object from receiving change notifications of the log files as these files are not monitored anymore.

 

Is your log file size growing Noticeably?

In a standard DNN site, the log file should contain only error and no warning, informational, or more verbose log entries. Even with this setting, some sites will notice there are many errors being logged in these files daily (in some cases these files are in 10’s of MB in size). This indicates an issue that can contributes significantly to performance degradation of your site.

The first step is to identify which errors are being logged and if they can be fixed by some changes in the application (whether configuration files or database settings). Sometimes this is not a trivial tasks and requires deep knowledge of the system and the third party modules installed, when any.

One log entry found to be causing such growth is cache synchronization in paid versions of DNN. This is an HTTP module that sends web requests to other servers in a web farm when any cache entry is being invalidated. In some cases where a customer made a copy of production system into a development or one, the DNN application will add an entry of the server name in the “WebServers” table. Afterwards, the application starts sending these requests to the other server(s) listed in this table which do not exist. These requests will fail and cause the log files being updated so often which will cause lots of file changes notifications being sent to the monitoring object and leading in the end to site restarts as described above.

To resolve this issue, you need to remove the entries of non-existing servers from this table. And if you are operating a single server, then you need to delete all entries from this table. Afterwards, the DNN application will add new entries for known servers and these logs will disappear.

 

I hope these few hints help you fix restarts in you DNN site and speed page loading for a better user experience.

Comments

There are currently no comments, be the first to post one.

Comment Form

Only registered users may post comments.

NewsArchives


Aderson Oliveira (15)
Alec Whittington (11)
Alex Shirley (10)
Andrew Nurse (30)
Andy Tryba (1)
Anthony Glenwright (5)
Antonio Chagoury (28)
Ash Prasad (32)
Ben Schmidt (1)
Benjamin Hermann (25)
Benoit Sarton (9)
Beth Firebaugh (12)
Bill Walker (36)
Bob Kruger (5)
Bogdan Litescu (1)
Brian Dukes (2)
Brice Snow (1)
Bruce Chapman (20)
Bryan Andrews (1)
cathal connolly (55)
Charles Nurse (163)
Chris Hammond (211)
Chris Paterra (55)
Clinton Patterson (45)
Cuong Dang (21)
Daniel Bartholomew (2)
Daniel Mettler (154)
Dave Buckner (2)
David Poindexter (4)
David Rodriguez (3)
Dennis Shiao (1)
Doug Howell (11)
Erik van Ballegoij (30)
Ernst Peter Tamminga (74)
Geoff Barlow (10)
George Alatrash (10)
Gifford Watkins (3)
Gilles Le Pigocher (3)
Ian Robinson (7)
Israel Martinez (17)
Jan Blomquist (2)
Jan Jonas (3)
Jaspreet Bhatia (1)
Jenni Merrifield (6)
Joe Brinkman (274)
John Mitchell (1)
Jon Henning (14)
Jonathan Sheely (4)
Jordan Coopersmith (1)
Joseph Craig (2)
Kan Ma (1)
Keivan Beigi (3)
Ken Grierson (10)
Kevin Schreiner (6)
Leigh Pointer (31)
Lorraine Young (60)
Malik Khan (1)
Matthias Schlomann (15)
Mauricio Márquez (5)
Michael Doxsey (7)
Michael Tobisch (3)
Michael Washington (202)
Miguel Gatmaytan (3)
Mike Horton (19)
Mitchel Sellers (28)
Nathan Rover (3)
Navin V Nagiah (14)
Néstor Sánchez (31)
Nik Kalyani (14)
Peter Donker (54)
Philip Beadle (135)
Philipp Becker (4)
Richard Dumas (22)
Robert J Collins (5)
Roger Selwyn (8)
Ruben Lopez (1)
Ryan Martinez (1)
Salar Golestanian (4)
Sanjay Mehrotra (9)
Scott McCulloch (1)
Scott S (11)
Scott Wilkinson (3)
Scott Willhite (97)
Sebastian Leupold (80)
Shaun Walker (237)
Shawn Mehaffie (17)
Stefan Cullmann (12)
Stefan Kamphuis (12)
Steve Fabian (31)
Timo Breumelhof (24)
Tony Henrich (3)
Torsten Weggen (2)
Vicenç Masanas (27)
Vincent Nguyen (3)
Vitaly Kozadayev (6)
Will Morgenweck (40)
Will Strohl (165)
William Severance (5)

Content Layout

Subscribe to DNN Digest

Subscribe to DNN Digest

DNN Digest is our monthly email newsletter. It highlights news and content from around the DNN ecosystem, such as new modules and themes, messages from leadership, blog posts and notable tweets. Keep your finger on the pulse of the ecosystem by subscribing.  


Copyright 2018 by DNN Corp Terms of Use Privacy
What is Liquid Content?
Find Out
What is Liquid Content?
Find Out
What is Liquid Content?
Find Out