Performance Logging
I just added a small http module to Rhino Commons. It is a very simple module that times how long it takes to process a page.
It only times the server-side processing, of course, but it is a great way to tell you where you need to pay attention.
It is using log4net to log the data, so you can redirect the output to a database, and from there, you can get all the data you want.
Configurating the module is very simple. Create the following table:
CREATE TABLE [dbo].[PagePerformance](
     [Id]
[int] PRIMARY KEY
IDENTITY(1,1) NOT NULL,
     [Date]
[datetime] NOT NULL,
     [Message]
[nvarchar](max) NOT NULL,
     [PageURL]
[nvarchar](max) NOT NULL,
     [Duration]
[nvarchar](50) NOT NULL,
     [StartRequest]
[datetime] NOT NULL
)
<httpModules>
     <add name="PagePerformanceModule"
           type="Rhino.Commons.HttpModules.PagePerformanceModule"/>
</httpModules>
Finally, we define in log4net.config the appender configuration:
<appender name="PagePerfAppender"
             type="log4net.Appender.AdoNetAppender">
     <bufferSize value="10" />
     <connectionType value="System.Data.SqlClient.SqlConnection, 
System.Data,
Version=2.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089" />
     <connectionString value="Data Source=localhost;Initial 
Catalog=Logs;User
ID=logger;Password=logger;" />
     <commandText value="INSERT INTO dbo.PagePerformance 
([Date],[Message],[PageUrl],[Duration],[StartRequest]) VALUES (@log_date,
@message, @pageUrl, @duration, @startRequest)" />
     <parameter>
           <parameterName value="@log_date" />
           <dbType value="DateTime" />
           <layout type="log4net.Layout.RawTimeStampLayout" />
     </parameter>
     <parameter>
           <parameterName value="@message" />
           <dbType value="String" />
           <size value="4000" />
           <layout type="log4net.Layout.PatternLayout">
                <conversionPattern value="%message" />
           </layout>
     </parameter>
     <parameter>
           <parameterName value="@pageUrl" />
           <dbType value="String" />
           <size value="2000" />
           <layout type="log4net.Layout.PatternLayout">
                <conversionPattern value="%property{page_url}"
/>
           </layout>
     </parameter>
     <parameter>
           <parameterName value="@duration" />
           <dbType value="String" />
           <size value="50" />
           <layout type="log4net.Layout.PatternLayout">
                <conversionPattern value="%property{page_duration}" />
           </layout>
     </parameter>
     <parameter>
           <parameterName value="@StartRequest" />
           <dbType value="DateTime" />
            <layout type="log4net.Layout.PatternLayout">
                <conversionPattern value="%property{start_request}" />
           </layout>
     </parameter>
</appender>
Then, all that is left is defining the logger itself:
<logger name="Rhino.Commons.HttpModules.PagePerformanceModule">
     <level value="DEBUG" />
     <appender-ref ref="PagePerfAppender" />
</logger>
how much it takes to serve each page.
Note: There is a small buffer (10 page requests) defined, to reduce the cost of the logging, so you would need to hit refresh a couple of time before you see the results in the table.

Comments
Comment preview