Server takes too long generating the umbraco.config file
Hi Guys,
I'm having an issue with a website being very slow building the umbraco.config file. It will take the server around 20 seconds rebuilding the file after every node publish and the cpu and website is struggling when it's going on.
The file built is around 18 mb in size.
To reproduce all I have to do is publish any one node.
I suspect that it might be some sort of setting on the server, because when running the website on my local IIS it will take less than a second for the exact same operation.
Is it a "busy" site (i.e., the difference between doing anything on a local machine vs. doing something on a live site with 5.000+ hits pr. minute is significant)?
The site is running Umbraco 7.5.2 on an IIS7. Totally new server.
The log shows:
umbraco.content - Save Xml to file...
umbraco.content - Saved Xml to file.
It's not busy today around 20 users at any one time. The site is heavyly cached with output donut cache, so when first the site is running, the frontend is not putting any strain on the server.
But even serving content from the cache is slow when the umbraco.config file is rebuilding
Are you still experience this issue? Our umbraco.config has 8.5MB and it's taking around 30s to rebuild it after we publish new content. We notice that it started to happen after we updated to Umbraco 7.5.3 (we had 7.4.3 before).
On my local copy and on our other servers it will take almost no time recreating the umbraco.config file. But on this one server it takes a long time.
We ended up disabling the file cache all together on the site adding this line:
<XmlCacheEnabled>False</XmlCacheEnabled>
to the /config/umbracoSettings.config file.
Now the website might be a little slower to start up after an app pool recycle, but it runs just as fine as before.
My conclusion on the problem so far is that it has something to do with the IIS/server setup. I just can't put my finger on it. Recycling the app pool might some time, but only temporarily, make the write action faster.
Also we have a minor problem uploading images to the website, which is also very slow. Again the write action to the disk, seems to be the problem.
The server setup is a virtual server but on a pretty beefy machine.
We had similar issues in the past where uploading media items, changing content would result in shutdown and a restart of the application. Because this causes file changes. The cause was a windows patch.
He isn't saying his machine is shutting down. He is saying the umbraco.config file is taking an excessively long time to regenerate. It doesn't cause the appPool to reset. As soon as you save a node it does this. We have the same problem now. It only became an issue after upgrading from 7.4.3 to 7.5.3 (now on 7.5.4)
on 7.5.3 we saw it jump from 200ms to 5 seconds. Now on 7.5.4 we are at 25+ seconds. This is all in our logs.
Edit. We can see in our logs going from 7.4.3 to 7.5.x the massive exponential jump in umbraco.config writing.
If there was an application shutdown/restart we would see that in the logs I assume regardless of debug settings. It doesn't seem to be restarting. Just taking a crazy amount of time to write to the file. We also have zero instances of application restarting.
11:31:25.396 INFO umbraco.content
Saved Xml to file.
11:30:59.952 INFO umbraco.content
Save Xml to file...
11:30:55.426 INFO Umbraco.Core.Publishing.PublishingStrategy
Content 'the content' with Id '1230' has been published.
Now what you say about server is interesting but I don't think it is the perfect answer. We are using UAAS and when we are on a faster server it still takes 5 seconds. If we are on a slower server it takes 25 seconds. Before 7.5.X we were about 200ms.
Out of curiosity we cloned our site over to another azure app and copied our database over with S0. The site is running 7.5.4 on a machine running basic 2 core/3.5 gigs memory. When we publish/unpublish a document it still takes roughly 10 seconds. That would be zero users on it, dedicated machine etc.
We think this is 7.5.4 because prior to Oct 19, 2016 we were about 200 ms to generate the umbraco.config.
Hi. I wanted to update in this forum some findings. We got a chance to try a new umbraco build from HQ but it didn't help us on our file lock/timeout issue. The very strange thing is that our local testing cannot reproduce the same issue. Even mounting the same database on a SQLExpress instance and it won't even come close to the same time lags.
Local setup
using a November 4 .bacpac file from production on SQLExpress instance on SQL2016.
update umbracoCMS and CORE to 7.5.5
update Nov4 database to 7.5.5 (success)
test articles:
goto umbraco/../articles
select article
update some content.
save and publish.
goto properties tab, click link
page loads
goto developer/..logs
result
11:12:39.041 INFO
umbraco.content Saved Xml to file.
11:12:38.663 INFO
umbraco.content
Save Xml to file...
result is <1000ms (WIN!)
Push to Azure App Service (doesn't seem to matter if it is UAAS or standalone)
Upgrade begins and finishes with success:
goto umbraco/../articles
select article
update some content.
save and publish.
goto properties tab, click link
page loads
goto developer/..logs
result
19:08:44.650 INFO umbraco.content Saved Xml to file.
19:08:13.468 INFO umbraco.content Save Xml to file...
result is > 30,000ms on some servers, 15 seconds on others, 6 on some others.
Frustrating issue.
22:49:14.798 INFO umbraco.content Saved Xml to file.
22:49:11.186 DEBUG Umbraco.Web.Scheduling.ScheduledPublishing Scheduled publishing complete (took 252ms)
22:49:11.186 DEBUG Umbraco.Web.Scheduling.BackgroundTaskRunner [ScheduledPublishing] Task added Umbraco.Web.Scheduling.ScheduledPublishing
22:49:11.170 DEBUG Umbraco.Web.WebServices.ScheduledPublishController The scheduler processed 0 items
22:49:11.155 DEBUG Umbraco.Core.Sync.DatabaseServerMessenger Complete (took 21ms)
22:49:11.122 DEBUG Umbraco.Core.Sync.DatabaseServerMessenger Syncing from database...
22:49:11.122 DEBUG Umbraco.Web.UmbracoModule Begin request: http://xxx.azurewebsites.net/umbraco/RestServices/ScheduledPublish/Index.
22:49:10.935 DEBUG Umbraco.Web.Scheduling.ScheduledPublishing Scheduled publishing executing @ http://xxx.azurewebsites.net/umbraco/RestServices/ScheduledPublish/Index
22:49:02.945 DEBUG Umbraco.Web.UmbracoModule Begin request: https://xxx.azurewebsites.net/umbraco/backoffice/UmbracoApi/Authentication/GetRemainingTimeoutSeconds.
22:49:00.428 INFO umbraco.content Save Xml to file...
22:49:00.428 DEBUG Umbraco.Web.PublishedCache.XmlPublishedCache.XmlCacheFilePersister Run now (sync).
22:49:00.428 DEBUG Umbraco.Web.PublishedCache.XmlPublishedCache.XmlCacheFilePersister Timer: release.
I've noticed a slowness in publishing after upgrading to 7.5.4 - looking into it I saw the following in the log files:
Application shutdown. Details: BinDirChangeOrDirectoryRename
_shutDownMessage=Change Notification for critical directories.
bin dir change or directory rename
HostingEnvironment initiated shutdown
Server takes too long generating the umbraco.config file
Hi Guys,
I'm having an issue with a website being very slow building the umbraco.config file. It will take the server around 20 seconds rebuilding the file after every node publish and the cpu and website is struggling when it's going on. The file built is around 18 mb in size.
To reproduce all I have to do is publish any one node.
I suspect that it might be some sort of setting on the server, because when running the website on my local IIS it will take less than a second for the exact same operation.
Anyone have any idea what is going on?
/Rune
Hi Rune,
Just a couple of starter-questions:
/Chriztian
The site is running Umbraco 7.5.2 on an IIS7. Totally new server.
The log shows: umbraco.content - Save Xml to file... umbraco.content - Saved Xml to file.
It's not busy today around 20 users at any one time. The site is heavyly cached with output donut cache, so when first the site is running, the frontend is not putting any strain on the server. But even serving content from the cache is slow when the umbraco.config file is rebuilding
Hi Rune.
Are you still experience this issue? Our umbraco.config has 8.5MB and it's taking around 30s to rebuild it after we publish new content. We notice that it started to happen after we updated to Umbraco 7.5.3 (we had 7.4.3 before).
Thanks, Diego
Hi Rune,
How long does it take when you have a exact copy of your live site and run it locally ?
Also do the logfiles show something funny ? Best is set the loglevel to debug to find out.
Dave
On my local copy and on our other servers it will take almost no time recreating the umbraco.config file. But on this one server it takes a long time.
We ended up disabling the file cache all together on the site adding this line:
to the /config/umbracoSettings.config file.
Now the website might be a little slower to start up after an app pool recycle, but it runs just as fine as before.
My conclusion on the problem so far is that it has something to do with the IIS/server setup. I just can't put my finger on it. Recycling the app pool might some time, but only temporarily, make the write action faster. Also we have a minor problem uploading images to the website, which is also very slow. Again the write action to the disk, seems to be the problem. The server setup is a virtual server but on a pretty beefy machine.
/Rune
Hi Rune,
We had similar issues in the past where uploading media items, changing content would result in shutdown and a restart of the application. Because this causes file changes. The cause was a windows patch.
You can find more info here : http://issues.umbraco.org/issue/U4-6338
Dave
He isn't saying his machine is shutting down. He is saying the umbraco.config file is taking an excessively long time to regenerate. It doesn't cause the appPool to reset. As soon as you save a node it does this. We have the same problem now. It only became an issue after upgrading from 7.4.3 to 7.5.3 (now on 7.5.4) on 7.5.3 we saw it jump from 200ms to 5 seconds. Now on 7.5.4 we are at 25+ seconds. This is all in our logs.
Edit. We can see in our logs going from 7.4.3 to 7.5.x the massive exponential jump in umbraco.config writing.
Hi Mac,
I also didn't say the machine shut down, but the application shutdown (or restart if you prefer that)
Dave
If there was an application shutdown/restart we would see that in the logs I assume regardless of debug settings. It doesn't seem to be restarting. Just taking a crazy amount of time to write to the file. We also have zero instances of application restarting.
Now what you say about server is interesting but I don't think it is the perfect answer. We are using UAAS and when we are on a faster server it still takes 5 seconds. If we are on a slower server it takes 25 seconds. Before 7.5.X we were about 200ms.
Out of curiosity we cloned our site over to another azure app and copied our database over with S0. The site is running 7.5.4 on a machine running basic 2 core/3.5 gigs memory. When we publish/unpublish a document it still takes roughly 10 seconds. That would be zero users on it, dedicated machine etc. We think this is 7.5.4 because prior to Oct 19, 2016 we were about 200 ms to generate the umbraco.config.
What version were you running before upgrading to 7.5.4?
7.4.3.
Mac McDell is right on target.
Hi. I wanted to update in this forum some findings. We got a chance to try a new umbraco build from HQ but it didn't help us on our file lock/timeout issue. The very strange thing is that our local testing cannot reproduce the same issue. Even mounting the same database on a SQLExpress instance and it won't even come close to the same time lags.
Local setup using a November 4 .bacpac file from production on SQLExpress instance on SQL2016. update umbracoCMS and CORE to 7.5.5 update Nov4 database to 7.5.5 (success) test articles: goto umbraco/../articles select article update some content. save and publish. goto properties tab, click link page loads goto developer/..logs result
11:12:39.041 INFO umbraco.content Saved Xml to file.
11:12:38.663 INFO umbraco.content Save Xml to file...
result is <1000ms (WIN!)
Push to Azure App Service (doesn't seem to matter if it is UAAS or standalone) Upgrade begins and finishes with success: goto umbraco/../articles select article update some content. save and publish. goto properties tab, click link page loads goto developer/..logs result
19:08:44.650 INFO umbraco.content Saved Xml to file.
19:08:13.468 INFO umbraco.content Save Xml to file...
result is > 30,000ms on some servers, 15 seconds on others, 6 on some others.
Frustrating issue.
I've noticed a slowness in publishing after upgrading to 7.5.4 - looking into it I saw the following in the log files:
There's a few threads and issues about this:
http://issues.umbraco.org/issue/U4-6338
https://our.umbraco.org/forum/core/general/63922-Application-shutdown-Reason-various
is working on a reply...
This forum is in read-only mode while we transition to the new forum.
You can continue this topic on the new forum by tapping the "Continue discussion" link below.