I have an umbraco site running 4.0 that all of a sudden is taking an absolute age to render.
The site does contain a massive amount of nodes (It's been far more successful than expected) but now every page in the site is taking upwards of several minutes to load via browser.
I've grabbed a trace of one of the pages. and placed it here
As you can see there is one macro that is taking some time to render, but it only says 8 seconds on the trace, which is acceptable as its doing a lot of work. I can't work out why the trace says it should be taking me 9 seconds or so to see the page, but I'm waiting for over 3 minutes to see it online.
I've also popped a test file in a non_umbraco folder called test.aspx, which writes "hello world" to a literal. It too is taking aeons.
the server has been rebooted, iis restarted, and the app pool cleared out.
in web.config the debug is set to false.
Can anyone give me any other pointers to look for?
some pages, very few, make calls to brettle neatupload via .net controls that i've built, but according to the trace these arent taking up any time. I have blog4umbraco installed, but no other packages.
the oddest thing is that my test.aspx file, which does not interact with a database or umbraco in any way, is also very sluggish. I'm wondering if this means my problems are related to something other than umbraco.
I should also point out that the admin section is also excrutiatingly slow as well, it isn't just the front end that takes upwards of 4 minutes to render.
What about other file types? Static HTML files - take it they work fine, load fast? or Classic ASP (.asp) scripts?
Thinking that something is loading up in the /bin folder (application DLL) that is slowing everything down. Might be worth taking a look in there, seeing if there is anything suspect?
Take a look at the "umbracoLog" table in the database, see if there are any clues there?
One possible reason for the discrepency between the trace data and your experience is that the trace will only return information from the rendering of the .aspx page and not any latency information before or after that. So if it is taking forever to get to the page, that won't show on the trace, only the response once you get there.
Here are some other things to check:
Did you check the IIS logs to verify that it is the files themselves that are taking that time? Each call should have a time-taken field in the IIS logs, provided you are set up to log it. There might be latency somewhere else that only looks like it is coming from the files.
Did you ping and tracert the url to see how quickly it is responding at the network level? DNS issues can affect latency as well.
Do you have the same response browsing it from the server itself (if you can).
Are any other sites on that server experiencing the same latency?
Can you point a domain alias to the same location? If so, does it experience the same latency?
I've been poking in the bin folder but not seen anything obvious.
I am getting a lot of errors in the umbracoLog
At /home-page(fl)/stemmen.aspx (Referred by: http://www.xxxx.com/home-page(fl).aspx): System.Data.SqlClient.SqlException: Timeout expired. The timeout period elapsed prior to completion of the operation or the server is not responding.
and quite a few of these
Error updating item: umbraco.DataLayer.SqlHelperException: Umbraco Exception (DataLayer): SQL helper exception in ExecuteNonQuery ---> System.Data.SqlClient.SqlException: Conversion failed when converting the nvarchar value 'False' to data type int.
annoyingly the log doesn't specify where this is being caused.
Database timeouts... hmmm... could be a red-herring, but worth looking in to. Try this SQL snippet to see the recent queries:
SELECT deqs.last_execution_time AS [Time], dest.TEXT AS [Query]
FROM sys.dm_exec_query_stats AS deqs
CROSS APPLY sys.dm_exec_sql_text(deqs.sql_handle) AS dest
ORDER BY deqs.last_execution_time DESC
Hi Lee. I am writing to the database and reading from it in some controls,
I've looked in the iis logs, but nothings leaping out at me
pinging the server returns a time of 20ms, so I don't think its dns related
browsing the site from the server itself is faster, but is still slower than it should be.
I have another site on the same server which is also running more slowly than normal.
I've ran that bit of SQL and here's the latest items its bringing back
2010-06-08 12:40:03.727(@1 int)SELECT [DataInt] FROM [cmsPropertyData] WHERE [id]=@12010-06-08 12:40:03.710(@version uniqueidentifier,@propertyTypeId int)select id from cmsPropertyData where versionId=@version and propertyTypeId=@propertyTypeId
2010-06-08 12:40:03.710(@datadefinitionid int)select dbType from cmsDataType where nodeId = @datadefinitionid
2010-06-08 12:40:03.697(@nodeid int)Select ContentType from cmsContent where nodeId=@nodeid
2010-06-08 12:40:03.663(@1 int)SELECT [dataNvarchar] FROM [cmsPropertyData] WHERE [id]=@1
2010-06-08 12:40:03.663(@1 int)SELECT [createDate],[trashed],[parentId],[nodeObjectType],[nodeUser],[level],[path],[sortOrder],[uniqueID],[text] FROM [umbracoNode] WHERE [id]=@1
2010-06-08 12:40:03.663(@contextId uniqueidentifier)select userID from umbracoUserLogins where contextID = @contextId
2010-06-08 12:40:03.633(@id int)select Email from cmsMember where nodeId = @id
2010-06-08 12:40:03.260(@1 smallint)SELECT [createDate],[trashed],[parentId],[nodeObjectType],[nodeUser],[level],[path],[sortOrder],[uniqueID],[text] FROM [umbracoNode] WHERE [id]=@1
2010-06-08 12:40:03.087(@1 smallint)SELECT [xml] FROM [cmsContentXml] WHERE [nodeID]=@1
2010-06-08 12:40:03.087(@1 int)SELECT [versionId] FROM [cmsContentVersion] WHERE [contentID]=@1 ORDER BY [id] DESC
2010-06-08 12:40:02.320(@my_submission_id int,@howMany int)select top(@howMany) VoterId from eurostar_votes where SubmissionId=@my_submission_id order by id desc
2010-06-08 12:40:02.320(@type uniqueidentifier)select id from umbracoNode where ParentID = 38451 And nodeObjectType = @type order by sortOrder
2010-06-08 12:40:02.210(@1 tinyint,@2 smallint)SELECT COUNT([published]) [tmp] FROM [cmsDocument] WHERE [published]=@1 AND [nodeId]=@2
2010-06-08 12:40:02.150(@1 smallint)SELECT [masterContentType],[Alias],[icon],[thumbnail],[description] FROM [cmsContentType] WHERE [nodeid]=@1
2010-06-08 12:40:01.960(@versionId uniqueidentifier)select published, documentUser, coalesce(templateId, cmsDocumentType.templateNodeId) as templateId, text, releaseDate, expireDate, updateDate from cmsDocument inner join cmsContent on cmsDocument.nodeId = cmsContent.Nodeid left join cmsDocumentType on cmsDocumentType.contentTypeNodeId = cmsContent.contentType and cmsDocumentType.IsDefault = 1 where versionId = @versionId
2010-06-08 12:40:01.853(@id int)select LoginName from cmsMember where nodeId = @id
2010-06-08 12:40:01.837(@1 int)SELECT [xml] FROM [cmsContentXml] WHERE [nodeID]=@1
2010-06-08 12:40:01.650(@id int)select Password from cmsMember where nodeId = @id
2010-06-08 12:40:00.633(@type uniqueidentifier)select id from umbracoNode where ParentID = 18880 And nodeObjectType = @type order by sortOrder
I can't really work out from this whether these are causing timeouts though.
Might be obvious but do you have spare disk space (could be its spending all its time shuttling virtual memory around) and your physical memory? Have you checked you CPU when making a request?
Plenty of spare disk space. There is 3.47gb of ram apparently, I'm not sure if thats enough for a very heavily trafficked site. according to perfmon I have 1883mb available, again, not sure if thats enough, but the amount doesn't seem to be dipping..
According to perfmon my total anonymous users is going through the roof, could this be indicative of something holding on to the database?
Umbraco taking ages to render.
Hi
I have an umbraco site running 4.0 that all of a sudden is taking an absolute age to render.
The site does contain a massive amount of nodes (It's been far more successful than expected) but now every page in the site is taking upwards of several minutes to load via browser.
I've grabbed a trace of one of the pages. and placed it here
http://www.spaceacademy.co.uk/trace.htm
As you can see there is one macro that is taking some time to render, but it only says 8 seconds on the trace, which is acceptable as its doing a lot of work. I can't work out why the trace says it should be taking me 9 seconds or so to see the page, but I'm waiting for over 3 minutes to see it online.
I've also popped a test file in a non_umbraco folder called test.aspx, which writes "hello world" to a literal. It too is taking aeons.
the server has been rebooted, iis restarted, and the app pool cleared out.
in web.config the debug is set to false.
Can anyone give me any other pointers to look for?
Many thanks.
Shaun
Hey Shaun, yep the "Display Entries" macro is taking a long time to transform!
Are there any calls to 3rd party web-services or resources? Anything external that might be delaying the page load/render?
What custom application code (DLLs) are you using? Could any of those have been compiled in debug mode? (as opposed to 'release')
Any other packages installed, etc?
Cheers, Lee.
some pages, very few, make calls to brettle neatupload via .net controls that i've built, but according to the trace these arent taking up any time. I have blog4umbraco installed, but no other packages.
the oddest thing is that my test.aspx file, which does not interact with a database or umbraco in any way, is also very sluggish. I'm wondering if this means my problems are related to something other than umbraco.
I should also point out that the admin section is also excrutiatingly slow as well, it isn't just the front end that takes upwards of 4 minutes to render.
What about other file types? Static HTML files - take it they work fine, load fast? or Classic ASP (.asp) scripts?
Thinking that something is loading up in the /bin folder (application DLL) that is slowing everything down. Might be worth taking a look in there, seeing if there is anything suspect?
Take a look at the "umbracoLog" table in the database, see if there are any clues there?
Cheers, Lee.
One possible reason for the discrepency between the trace data and your experience is that the trace will only return information from the rendering of the .aspx page and not any latency information before or after that. So if it is taking forever to get to the page, that won't show on the trace, only the response once you get there.
Here are some other things to check:
--Chris
Thanks Lee
I've been poking in the bin folder but not seen anything obvious.
I am getting a lot of errors in the umbracoLog
At /home-page(fl)/stemmen.aspx (Referred by: http://www.xxxx.com/home-page(fl).aspx): System.Data.SqlClient.SqlException: Timeout expired. The timeout period elapsed prior to completion of the operation or the server is not responding.
and quite a few of these
Error updating item: umbraco.DataLayer.SqlHelperException: Umbraco Exception (DataLayer): SQL helper exception in ExecuteNonQuery ---> System.Data.SqlClient.SqlException: Conversion failed when converting the nvarchar value 'False' to data type int.
annoyingly the log doesn't specify where this is being caused.
I've set a performance monitor on process > virtual bytes and process > private bytes and they're both pretty high, could this be a memory leak?
Database timeouts... hmmm... could be a red-herring, but worth looking in to. Try this SQL snippet to see the recent queries:
Ref: SQL SERVER – Recently Executed T-SQL Query
See if there is anything suspect in there. But I could be sending you on a wild goose chase?! :-$
Is the database being shared with another application? Are you doing any database writes in your Macros?
Good luck, Lee.
Hi Lee. I am writing to the database and reading from it in some controls,
I've looked in the iis logs, but nothings leaping out at me
pinging the server returns a time of 20ms, so I don't think its dns related
browsing the site from the server itself is faster, but is still slower than it should be.
I have another site on the same server which is also running more slowly than normal.
I've ran that bit of SQL and here's the latest items its bringing back
2010-06-08 12:40:03.727 (@1 int)SELECT [DataInt] FROM [cmsPropertyData] WHERE [id]=@12010-06-08 12:40:03.710 (@version uniqueidentifier,@propertyTypeId int)select id from cmsPropertyData where versionId=@version and propertyTypeId=@propertyTypeId
2010-06-08 12:40:03.710 (@datadefinitionid int)select dbType from cmsDataType where nodeId = @datadefinitionid
2010-06-08 12:40:03.697 (@nodeid int)Select ContentType from cmsContent where nodeId=@nodeid
2010-06-08 12:40:03.663 (@1 int)SELECT [dataNvarchar] FROM [cmsPropertyData] WHERE [id]=@1
2010-06-08 12:40:03.663 (@1 int)SELECT [createDate],[trashed],[parentId],[nodeObjectType],[nodeUser],[level],[path],[sortOrder],[uniqueID],[text] FROM [umbracoNode] WHERE [id]=@1
2010-06-08 12:40:03.663 (@contextId uniqueidentifier)select userID from umbracoUserLogins where contextID = @contextId
2010-06-08 12:40:03.633 (@id int)select Email from cmsMember where nodeId = @id
2010-06-08 12:40:03.260 (@1 smallint)SELECT [createDate],[trashed],[parentId],[nodeObjectType],[nodeUser],[level],[path],[sortOrder],[uniqueID],[text] FROM [umbracoNode] WHERE [id]=@1
2010-06-08 12:40:03.087 (@1 smallint)SELECT [xml] FROM [cmsContentXml] WHERE [nodeID]=@1
2010-06-08 12:40:03.087 (@1 int)SELECT [versionId] FROM [cmsContentVersion] WHERE [contentID]=@1 ORDER BY [id] DESC
2010-06-08 12:40:02.320 (@my_submission_id int,@howMany int)select top(@howMany) VoterId from eurostar_votes where SubmissionId=@my_submission_id order by id desc
2010-06-08 12:40:02.320 (@type uniqueidentifier)select id from umbracoNode where ParentID = 38451 And nodeObjectType = @type order by sortOrder
2010-06-08 12:40:02.210 (@1 tinyint,@2 smallint)SELECT COUNT([published]) [tmp] FROM [cmsDocument] WHERE [published]=@1 AND [nodeId]=@2
2010-06-08 12:40:02.150 (@1 smallint)SELECT [masterContentType],[Alias],[icon],[thumbnail],[description] FROM [cmsContentType] WHERE [nodeid]=@1
2010-06-08 12:40:01.960 (@versionId uniqueidentifier)select published, documentUser, coalesce(templateId, cmsDocumentType.templateNodeId) as templateId, text, releaseDate, expireDate, updateDate from cmsDocument inner join cmsContent on cmsDocument.nodeId = cmsContent.Nodeid left join cmsDocumentType on cmsDocumentType.contentTypeNodeId = cmsContent.contentType and cmsDocumentType.IsDefault = 1 where versionId = @versionId
2010-06-08 12:40:01.853 (@id int)select LoginName from cmsMember where nodeId = @id
2010-06-08 12:40:01.837 (@1 int)SELECT [xml] FROM [cmsContentXml] WHERE [nodeID]=@1
2010-06-08 12:40:01.650 (@id int)select Password from cmsMember where nodeId = @id
2010-06-08 12:40:00.633 (@type uniqueidentifier)select id from umbracoNode where ParentID = 18880 And nodeObjectType = @type order by sortOrder
I can't really work out from this whether these are causing timeouts though.
Hey Shaun,
The SQL queries are all SELECTs, (db reads) some with an INNER JOIN, but nothing that would cause alarm bells!
Not sure what else to suggest...
Take a copy of the site and run it on a different server? See if that has the same problem?
- Lee
Might be obvious but do you have spare disk space (could be its spending all its time shuttling virtual memory around) and your physical memory? Have you checked you CPU when making a request?
Hi Peter
Plenty of spare disk space. There is 3.47gb of ram apparently, I'm not sure if thats enough for a very heavily trafficked site. according to perfmon I have 1883mb available, again, not sure if thats enough, but the amount doesn't seem to be dipping..
According to perfmon my total anonymous users is going through the roof, could this be indicative of something holding on to the database?
is working on a reply...